Opened 11 months ago

Closed 6 months ago

#3044 closed bug (Fixed)

Restarting deluged via systemd causes errornous torrents

Reported by: krichter Owned by:
Priority: minor Milestone: 1.3.16
Component: Core Version: other (please specify)
Keywords: Cc:

Description

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

Change History (10)

comment:1 Changed 11 months ago 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.

comment:2 Changed 11 months ago 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).

comment:3 Changed 11 months ago by Cas

Need the log when shutting down...

comment:4 Changed 11 months ago 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).

comment:5 Changed 11 months ago 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

I'm on Unraid, deluge is running in a docker, and this happens when I stop that docker. 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
Last edited 11 months ago by krzaku (previous) (diff)

comment:6 Changed 11 months ago 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.

comment:7 Changed 11 months ago by Cas

  • Component changed from Unknown to Core
  • Milestone changed from needs verified to 1.3.16

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.

comment:8 Changed 11 months ago 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.

comment:9 Changed 11 months ago by Cas

Yeah I am likely to enable that setting permanently.

Disabled checking in develop: [85a1e478f]

comment:10 Changed 6 months ago by Cas

  • Resolution set to Fixed
  • Status changed from new to closed

Now also disabled in 1.3-stable: [5f0694deb]

Note: See TracTickets for help on using tickets.