[Deluge] #3044: Restarting deluged via systemd causes errornous torrents
Deluge
----------------------+------------------------------------
Reporter: krichter | Owner:
Type: bug | Status: new
Priority: minor | Milestone: needs verified
Component: Unknown | Version: other (please specify)
Keywords: |
----------------------+------------------------------------
I'm managing `deluged` with the following `systemd` unit:
{{{
[Unit]
Description=Deluge Bittorrent daemon
Requires=network.target
[Service]
Type=simple
#forking
User=debian-deluged
Group=debian-deluged
LimitNOFILE=500000
ExecStart=/usr/bin/deluged --do-not-daemonize --config
/var/lib/deluge/deluged/ --logfile /var/log/deluged/deluged.log
[Install]
WantedBy=multi-user.target
}}}
When I restart `deluged` with `sudo systemctl stop deluged.service` a
random number of torrents is marked errornous and has to be force-
rechecked.
#3028 is about corruption happening when the torrents are moved which is
not the case in this issue - assuming that there's no move happening
during restart.
experienced with 2.0.0.dev7019+fefe742+201705201502~ubuntu17.04.1 on
Ubuntu 17.04
--
Ticket URL: <http://dev.deluge-torrent.org/ticket/3044>
Deluge <http://deluge-torrent.org/>
Deluge Project
Deluge
Reporter: krichter | Owner:
Type: bug | Status: new
Priority: minor | Milestone: needs verified
Component: Unknown | Version: other (please specify)
-----------------------+------------------------------------
Comment (by Cas):
Did you see the stop timer on the wiki page:
http://dev.deluge-
torrent.org/wiki/UserGuide/Service/systemd#DelugeDaemondelugedService
Also you have not provided any logs so no idea what is occurring on
`stop`.
--
Ticket URL: <http://dev.deluge-torrent.org/ticket/3044#comment:1>
Deluge
Reporter: krichter | Owner:
Type: bug | Status: new
Priority: minor | Milestone: needs verified
Component: Unknown | Version: other (please specify)
-----------------------+------------------------------------
Comment (by krichter):
> Did you see the stop timer on the wiki page:
>
> http://dev.deluge-
torrent.org/wiki/UserGuide/Service/systemd#DelugeDaemondelugedService
I added it now (I always forget that `deluge` doesn't maintain the
`systemd` unit in its package), but that doesn't change the issue.
> Also you have not provided any logs so no idea what is occurring on
stop.
Right, the log reveals
{{{
15:09:54.830 [ERROR ][deluge.core.torrentmanager :1158]
on_alert_fastresume_rejected: manjaro-xfce-17.0.1-stable-i686.iso fast
resume rejected. stat(/var/lib/deluge/complete/manjaro-
xfce-17.0.1-stable-i686.iso): mismatching file timestamp
15:09:58.231 [ERROR ][deluge.core.torrentmanager :1158]
on_alert_fastresume_rejected: manjaro-gnome-17.0.1-stable-i686.iso fast
resume rejected. stat(/var/lib/deluge/complete/manjaro-
gnome-17.0.1-stable-i686.iso): mismatching file timestamp
}}}
which I naively assume is the reason for failure. The file with
mismatching timestamp correspond to the errornous files I see in `deluge-
gtk`. I'm using different ZFS datasets for the incomplete/download and
complete directory (0.6.5.9-5ubuntu4 on Ubuntu 17.04).
--
Ticket URL: <http://dev.deluge-torrent.org/ticket/3044#comment:2>
Deluge
Reporter: krichter | Owner:
Type: bug | Status: new
Priority: minor | Milestone: needs verified
Component: Unknown | Version: other (please specify)
-----------------------+------------------------------------
Comment (by Cas):
Need the log when shutting down...
--
Ticket URL: <http://dev.deluge-torrent.org/ticket/3044#comment:3>
Deluge
Reporter: krichter | Owner:
Type: bug | Status: new
Priority: minor | Milestone: needs verified
Component: Unknown | Version: other (please specify)
-----------------------+------------------------------------
Comment (by krichter):
> Need the log when shutting down...
Until #3045 is fixed, I'll provide it at
https://richtercloud.de:451/index.php/s/n5Un0j7xVcjxiTo (might not be
available at all time because my WiFi "router" has trouble with port
forwarding).
--
Ticket URL: <http://dev.deluge-torrent.org/ticket/3044#comment:4>
Deluge
Reporter: krichter | Owner:
Type: bug | Status: new
Priority: minor | Milestone: needs verified
Component: Unknown | Version: other (please specify)
-----------------------+------------------------------------
Comment (by krzaku):
Same issue, same log line:
{{{
[ERROR ] 02:00:53 torrentmanager:1147 on_alert_fastresume_rejected:
Star.Trek.The.Next.Generation.S01-07.COMPLETE.1080p.BluRay.x264-MULTiGRP
fast resume rejected: mismatching file timestamp
}}}
This only happens for torrents that aren't fully downloaded yet. I'd
provide a log but it contains a lot of private data that I wouldn't want
posted online.
I noticed that when the error occurs, in logs there is no information
about specific torrents saving resume data:
{{{
[DEBUG ] 11:10:43 torrentmanager:1117 on_alert_save_resume_data
[DEBUG ] 11:10:43 torrentmanager:769 Opening torrents fastresume file
for load.
[INFO ] 11:10:43 torrentmanager:780 Successfully loaded fastresume
file: /config/state/torrents.fastresume
[DEBUG ] 11:10:43 torrentmanager:821 Creating backup of fastresume at:
/config/state/torrents.fastresume.bak
[INFO ] 11:10:43 torrentmanager:826 Saving the fastresume at:
/config/state/torrents.fastresume
[DEBUG ] 11:10:43 alertmanager:124 portmap_log_alert: NAT-PMP: ==> port
map [ mapping: 2 action: add proto: udp local: 58946 external: 58946 ttl:
3600 ]
[DEBUG ] 11:10:44 alertmanager:124 portmap_log_alert: UPnP: broadcasting
search for rootdevice
[DEBUG ] 11:10:44 alertmanager:124 portmap_log_alert: UPnP: HTTP method
m-search from 192.168.1.10:52336
[DEBUG ] 11:10:44 alertmanager:124 portmap_log_alert: UPnP: HTTP method
m-search from 192.168.1.10:1900
[DEBUG ] 11:10:44 alertmanager:124 portmap_log_alert: UPnP: HTTP method
m-search from 192.168.1.10:1900
[INFO ] 11:10:45 daemon:196 Waiting for components to shutdown..
[DEBUG ] 11:10:45 core:163 Core stopping...
[DEBUG ] 11:10:45 torrentmanager:732 Creating backup of state at:
/config/state/torrents.state.bak
[INFO ] 11:10:45 torrentmanager:737 Saving the state at:
/config/state/torrents.state
}}}
Notice how after on_alert_save_resume_data there are no torrents, while I
usually have a line like that for every running torrent:
{{{
[DEBUG ] 11:04:35 alertmanager:124 save_resume_data_alert: nnn resume
data generated
[DEBUG ] 11:04:35 torrentmanager:1117 on_alert_save_resume_data
}}}
--
Ticket URL: <http://dev.deluge-torrent.org/ticket/3044#comment:5>
Deluge
Reporter: krichter | Owner:
Type: bug | Status: new
Priority: minor | Milestone: needs verified
Component: Unknown | Version: other (please specify)
-----------------------+------------------------------------
Comment (by Cas):
With timestamp error I suspect that something (perhaps libtorrent) is
touching the torrents after resume is written. I think that checking for
timestamp has been removed from latest versions of libtorrent.
I shall look into catching and ignoring it.
--
Ticket URL: <http://dev.deluge-torrent.org/ticket/3044#comment:6>
Deluge
Reporter: krichter | Owner:
Type: bug | Status: new
Component: Core | Version: other (please specify)
Resolution: | Keywords:
-----------------------+------------------------------------
Changes (by Cas):
* component: Unknown => Core
* milestone: needs verified => 1.3.16
Comment:
So there is an option in the lt_config plugins `ignore_resume_timestamps`
that you can enable if the data is not being modified, just the file
timestamps.
What I might do is skip sending these particular torrents to Error state
in the next release. This wouldn't stop them needing rechecking (if
`ignore_resume_timestamps` setting is false) as it's part of libtorrent
code.
--
Ticket URL: <http://dev.deluge-torrent.org/ticket/3044#comment:7>
Deluge
Reporter: krichter | Owner:
Type: bug | Status: new
Component: Core | Version: other (please specify)
Resolution: | Keywords:
-----------------------+------------------------------------
Comment (by krzaku):
That fixed it for me, the torrents no longer end up needing a recheck.
Although ltConfig might not always be there, so I think it'd be a good
idea to add this option to Deluge itself.
--
Ticket URL: <http://dev.deluge-torrent.org/ticket/3044#comment:8>
Deluge
Reporter: krichter | Owner:
Type: bug | Status: new
Component: Core | Version: other (please specify)
Resolution: | Keywords:
-----------------------+------------------------------------
Comment (by Cas):
Yeah I am likely to enable that setting permanently.
Disabled checking in develop: [85a1e478f]
--
Ticket URL: <http://dev.deluge-torrent.org/ticket/3044#comment:9>
Deluge
Reporter: krichter | Owner:
Type: bug | Status: closed
Priority: minor | Milestone: 1.3.16
Component: Core | Version: other (please specify)
-----------------------+------------------------------------
Changes (by Cas):
* status: new => closed
* resolution: => Fixed
Comment:
Now also disabled in 1.3-stable: [5f0694deb]
--
Ticket URL: <http://dev.deluge-torrent.org/ticket/3044#comment:10>