RESOLVED: session.state corrupt on deluged stop

General support for problems installing or using Deluge
Post Reply
rotational
New User
New User
Posts: 4
Joined: Wed May 31, 2023 12:58 am

RESOLVED: session.state corrupt on deluged stop

Post by rotational »

update: resolved below: viewtopic.php?p=236458#p236458

Been using Deluge for a couple of years on headless linux servers without issue. Recently had to rebuild and am having the following issue:

Ubuntu 22.04 x64
Deluge 2.1.1 via PPA
Config and systemd unit files as per site documentation: https://deluge.readthedocs.io/en/latest ... rvice.html

On deluged daemon stop, an apparently corrupt session.state file is written to the config folder. When the daemon is restarted, it hangs during startup:

Code: Select all

20:46:56 [INFO    ][deluge.core.daemon            :91  ] Deluge daemon 2.1.1
20:46:56 [INFO    ][deluge.core.core              :334 ] Successfully loaded session.state: /var/lib/deluge/.config/deluge/session.state
20:46:56 [WARNING ][deluge.core.core              :332 ] Unable to load /var/lib/deluge/.config/deluge/session.state.bak: [Errno 2] No such file or directory: '/var/lib/deluge/.config/deluge/session.state.bak'
20:46:56 [INFO    ][deluge.core.alertmanager      :138 ] Alert Queue Size set to 10000
20:46:56 [INFO    ][deluge.core.rpcserver         :410 ] Starting DelugeRPC server localhost:58846
20:46:56 [INFO    ][deluge.core.daemon            :151 ] Deluge daemon starting...
Attempting to stop the service when it is in the state will also hang, and the process must be manually killed - which will also lead to the server hanging during shutdown if I forget to fix the problem between reboots.

This happens regardless of a manual or automatic (i.e. reboot) stop of the service.

The torrent state files don't appear to have any issues, and in-process torrents resume as expected once the daemon is running normally again.

Completely stopping/killing the daemon and removing the session.state file corrects the problem until the daemon is stopped again and the problem repeats. It is consistent, reproducible every time the daemon is stopped. When functioning normally, the daemon appears to shut down cleanly, does not report anything unusual when it is stopped, and stops immediately as expected:

Code: Select all

20:55:27 [INFO    ][deluge.core.daemon            :91  ] Deluge daemon 2.1.1
20:55:27 [WARNING ][deluge.core.core              :332 ] Unable to load /var/lib/deluge/.config/deluge/session.state: [Errno 2] No such file or directory: '/var/lib/deluge/.config/deluge/session.state'
20:55:27 [WARNING ][deluge.core.core              :332 ] Unable to load /var/lib/deluge/.config/deluge/session.state.bak: [Errno 2] No such file or directory: '/var/lib/deluge/.config/deluge/session.state.bak'
20:55:27 [INFO    ][deluge.core.alertmanager      :138 ] Alert Queue Size set to 10000
20:55:27 [INFO    ][deluge.core.rpcserver         :410 ] Starting DelugeRPC server localhost:58846
20:55:27 [INFO    ][deluge.core.daemon            :151 ] Deluge daemon starting...
20:55:27 [INFO    ][deluge.core.authmanager       :224 ] Opening auth for load: /var/lib/deluge/.config/deluge/auth
20:55:27 [INFO    ][deluge.core.authmanager       :232 ] Successfully loaded auth: /var/lib/deluge/.config/deluge/auth
20:55:27 [INFO    ][deluge.core.torrentmanager    :811 ] Loading torrent state: /var/lib/deluge/.config/deluge/state/torrents.state
20:55:27 [INFO    ][deluge.core.torrentmanager    :824 ] Successfully loaded /var/lib/deluge/.config/deluge/state/torrents.state
20:55:27 [INFO    ][deluge.core.torrentmanager    :1071] Opening torrents.fastresume for load: /var/lib/deluge/.config/deluge/state/torrents.fastresume
20:55:27 [INFO    ][deluge.core.torrentmanager    :1082] Successfully loaded torrents.fastresume: /var/lib/deluge/.config/deluge/state/torrents.fastresume
20:55:27 [INFO    ][deluge.core.torrentmanager    :673 ] Torrent ubuntu-22.04.2-live-server-amd64.iso from user "localclient" loaded
20:55:27 [INFO    ][deluge.core.torrentmanager    :887 ] Finished loading 1 torrents in 0:00:00.302412
20:55:30 [INFO    ][deluge.core.rpcserver         :179 ] Deluge Client connection made from: 127.0.0.1:60240
20:55:30 [INFO    ][deluge.core.rpcserver         :179 ] Deluge Client connection made from: 127.0.0.1:60244
20:55:30 [INFO    ][deluge.core.rpcserver         :205 ] Deluge client disconnected: [('SSL routines', '', 'unexpected eof while reading')]
20:55:30 [INFO    ][deluge.core.rpcserver         :205 ] Deluge client disconnected: [('SSL routines', '', 'unexpected eof while reading')]
20:55:31 [WARNING ][deluge.core.torrentmanager    :1621] on_alert_performance: ubuntu-22.04.2-live-server-amd64.iso: performance warning: max outstanding piece requests reached, outstanding_request_limit_reached
20:55:31 [WARNING ][deluge.core.torrentmanager    :1621] on_alert_performance: ubuntu-22.04.2-live-server-amd64.iso: performance warning: max outstanding piece requests reached, outstanding_request_limit_reached
20:55:31 [INFO    ][deluge.core.rpcserver         :179 ] Deluge Client connection made from: 127.0.0.1:60260
20:55:31 [INFO    ][deluge.core.rpcserver         :205 ] Deluge client disconnected: [('SSL routines', '', 'unexpected eof while reading')]
20:55:32 [WARNING ][deluge.core.torrentmanager    :1621] on_alert_performance: ubuntu-22.04.2-live-server-amd64.iso: performance warning: max outstanding piece requests reached, outstanding_request_limit_reached
20:55:32 [WARNING ][deluge.core.torrentmanager    :1621] on_alert_performance: ubuntu-22.04.2-live-server-amd64.iso: performance warning: max outstanding piece requests reached, outstanding_request_limit_reached
20:55:33 [WARNING ][deluge.core.torrentmanager    :1621] on_alert_performance: ubuntu-22.04.2-live-server-amd64.iso: performance warning: max outstanding piece requests reached, outstanding_request_limit_reached
20:55:33 [INFO    ][deluge.core.rpcserver         :179 ] Deluge Client connection made from: 127.0.0.1:60270
20:55:33 [INFO    ][deluge.core.rpcserver         :205 ] Deluge client disconnected: [('SSL routines', '', 'unexpected eof while reading')]
20:55:34 [WARNING ][deluge.core.torrentmanager    :1621] on_alert_performance: ubuntu-22.04.2-live-server-amd64.iso: performance warning: max outstanding piece requests reached, outstanding_request_limit_reached
20:55:35 [WARNING ][deluge.core.torrentmanager    :1621] on_alert_performance: ubuntu-22.04.2-live-server-amd64.iso: performance warning: max outstanding piece requests reached, outstanding_request_limit_reached
20:55:35 [INFO    ][deluge.core.rpcserver         :179 ] Deluge Client connection made from: 127.0.0.1:60272
20:55:35 [INFO    ][deluge.core.rpcserver         :205 ] Deluge client disconnected: [('SSL routines', '', 'unexpected eof while reading')]
20:55:37 [INFO    ][deluge.core.rpcserver         :179 ] Deluge Client connection made from: 127.0.0.1:60274
20:55:37 [INFO    ][deluge.core.rpcserver         :205 ] Deluge client disconnected: [('SSL routines', '', 'unexpected eof while reading')]
20:55:39 [INFO    ][deluge.core.rpcserver         :179 ] Deluge Client connection made from: 127.0.0.1:42154
20:55:39 [INFO    ][deluge.core.rpcserver         :205 ] Deluge client disconnected: [('SSL routines', '', 'unexpected eof while reading')]
20:55:41 [INFO    ][deluge.core.rpcserver         :179 ] Deluge Client connection made from: 127.0.0.1:42166
20:55:41 [INFO    ][deluge.core.rpcserver         :205 ] Deluge client disconnected: [('SSL routines', '', 'unexpected eof while reading')]
20:55:43 [INFO    ][deluge.core.rpcserver         :179 ] Deluge Client connection made from: 127.0.0.1:42174
20:55:43 [INFO    ][deluge.core.rpcserver         :205 ] Deluge client disconnected: [('SSL routines', '', 'unexpected eof while reading')]
20:55:45 [INFO    ][deluge.core.rpcserver         :179 ] Deluge Client connection made from: 127.0.0.1:42188
20:55:45 [INFO    ][deluge.core.rpcserver         :205 ] Deluge client disconnected: [('SSL routines', '', 'unexpected eof while reading')]
20:55:46 [INFO    ][deluge.core.rpcserver         :179 ] Deluge Client connection made from: 127.0.0.1:42192
20:56:09 [INFO    ][deluge.core.core              :597 ] Removing 1 torrents from core.
20:56:09 [INFO    ][deluge.core.torrentmanager    :770 ] Torrent ubuntu-22.04.2-live-server-amd64.iso removed by user: localclient
21:06:09 [INFO    ][deluge.core.daemon            :173 ] Deluge daemon shutting down, waiting for components to shutdown...
21:06:09 [INFO    ][deluge.core.core              :303 ] Saving the session.state at: /var/lib/deluge/.config/deluge/session.state
21:06:09 [INFO    ][deluge.core.rpcserver         :205 ] Deluge client disconnected: [('SSL routines', '', 'unexpected eof while reading')]
21:06:09 [INFO    ][deluge.core.daemon            :165 ] Deluge daemon shutdown successfully
21:06:09 [INFO    ][deluge.core.daemon_entry      :134 ] Exiting...

Code: Select all

○ deluged.service - Deluge Bittorrent Client Daemon
     Loaded: loaded (/etc/systemd/system/deluged.service; enabled; vendor preset: enabled)
    Drop-In: /etc/systemd/system.control/deluged.service.d
             └─50-MemoryMax.conf
             /etc/systemd/system/deluged.service.d
             └─override.conf
     Active: inactive (dead) since Tue 2023-05-30 21:06:09 EDT; 10min ago
       Docs: man:deluged
    Process: 7266 ExecStart=/usr/bin/deluged -d -l /var/log/deluge/daemon.log -L info (code=exited, status=0/SUCCESS)
   Main PID: 7266 (code=exited, status=0/SUCCESS)
        CPU: 20.054s

May 30 20:55:26 agamemnon systemd[1]: Started Deluge Bittorrent Client Daemon.
May 30 21:06:09 agamemnon systemd[1]: Stopping Deluge Bittorrent Client Daemon...
May 30 21:06:09 agamemnon systemd[1]: deluged.service: Deactivated successfully.
May 30 21:06:09 agamemnon systemd[1]: Stopped Deluge Bittorrent Client Daemon.
May 30 21:06:09 agamemnon systemd[1]: deluged.service: Consumed 20.054s CPU time.
Other that this single issue, Deluge works perfectly for what I need as it has for years. Please let me know what other info I can provide to help figure this out.

Thanks!!
Last edited by rotational on Thu Jun 01, 2023 11:52 pm, edited 1 time in total.
mhertz
Moderator
Moderator
Posts: 2195
Joined: Wed Jan 22, 2014 5:05 am
Location: Denmark

Re: session.state corrupt on deluged stop

Post by mhertz »

Please try with completely fresh config i.e. rename old to end in -bak or whatever(with daemon closed), to get it cleanly regenerated, so no 3'rd party plugins etc. I can see you use systemd memory-limiting too(/'etc/systemd/system.control/deluged.service.d/50-MemoryMax.conf'), please disable, for testing I mean, to isolate.

In your example that works good, then you have repeat(2 secs interval) connect/disconnects made to daemon from something seemingly, with some ssl fault seemingly.

Not really good at troubleshootijng these kinda issues myself to be honest, but just a few select thoughts, and sorry not much direct help to offer, but could be some too low memory-limiting for libtorrent, or some plugin/script interferring, but just a vague guess merely.
rotational
New User
New User
Posts: 4
Joined: Wed May 31, 2023 12:58 am

Re: session.state corrupt on deluged stop

Post by rotational »

Hi there, thanks for replying! Here's what I did:

All deluge packages removed with apt purge
deluge user home cleaned out
MaxMemory override removed (This shouldn't have been there anyway)
deluge installed via PPA (version 2.1.1-0~202207101304~ubuntu22.04.1)
debug logging enabled for daemon
deluge-web service NOT enabled

deluged was enabled and started with out-of-the-box settings, and no default settings were ever changed.

Unfortunately, same behavior. After starting and then shutting down the daemon the first time, it hangs on the next startup attempt. As before, the first shutdown appears clean:

Code: Select all

21:01:51 [DEBUG   ][deluge.core.alertmanager      :125 ] Handling alert: session_stats_alert
21:01:51 [INFO    ][deluge.core.daemon            :173 ] Deluge daemon shutting down, waiting for components to shutdown...
21:01:51 [DEBUG   ][deluge.core.core              :213 ] Core stopping...
21:01:51 [INFO    ][deluge.core.core              :303 ] Saving the session.state at: /var/lib/deluge/.config/deluge/session.state
21:01:51 [DEBUG   ][deluge.core.torrentmanager    :980 ] Creating the temporary file: /var/lib/deluge/.config/deluge/state/torrents.state.tmp
21:01:51 [DEBUG   ][deluge.core.torrentmanager    :990 ] Creating backup of torrents.state at: /var/lib/deluge/.config/deluge/state/torrents.state.bak
21:01:51 [DEBUG   ][deluge.core.torrentmanager    :1000] Saving torrents.state to: /var/lib/deluge/.config/deluge/state/torrents.state
21:01:51 [DEBUG   ][deluge.core.daemon            :163 ] Remove pid file: /var/lib/deluge/.config/deluge/deluged.pid
21:01:51 [INFO    ][deluge.core.daemon            :165 ] Deluge daemon shutdown successfully
21:01:51 [INFO    ][deluge.core.daemon_entry      :134 ] Exiting...
The debug log stops here during the subsequent startup:

Code: Select all

21:02:18 [INFO    ][deluge.core.daemon            :151 ] Deluge daemon starting...
21:02:18 [DEBUG   ][deluge.core.daemon            :154 ] Storing pid 2925 & port 58846 in: /var/lib/deluge/.config/deluge/deluged.pid
21:02:18 [DEBUG   ][deluge.core.preferencesmanager:171 ] Config key: send_info set to False..
21:02:18 [DEBUG   ][deluge.core.preferencesmanager:372 ] Sending anonymous stats..
21:02:18 [DEBUG   ][deluge.core.preferencesmanager:171 ] Config key: listen_ports set to [6881, 6891]..
21:02:18 [DEBUG   ][deluge.core.preferencesmanager:217 ] Listen Interface: 0.0.0.0, Ports: [62121, 62121] with use_sys_port: False
21:02:18 [DEBUG   ][deluge.core.preferencesmanager:171 ] Config key: listen_interface set to ..
21:02:18 [DEBUG   ][deluge.core.preferencesmanager:217 ] Listen Interface: 0.0.0.0, Ports: [62121, 62121] with use_sys_port: False
21:02:18 [DEBUG   ][deluge.core.preferencesmanager:171 ] Config key: outgoing_interface set to ..
21:02:18 [DEBUG   ][deluge.core.preferencesmanager:171 ] Config key: random_port set to True..
21:02:18 [DEBUG   ][deluge.core.preferencesmanager:217 ] Listen Interface: 0.0.0.0, Ports: [62121, 62121] with use_sys_port: False
21:02:18 [DEBUG   ][deluge.core.preferencesmanager:171 ] Config key: outgoing_ports set to [0, 0]..
21:02:18 [DEBUG   ][deluge.core.preferencesmanager:253 ] Outgoing port set to 0 with range: 0
21:02:18 [DEBUG   ][deluge.core.preferencesmanager:171 ] Config key: random_outgoing_ports set to True..
21:02:18 [DEBUG   ][deluge.core.preferencesmanager:253 ] Outgoing port set to 0 with range: 0
21:02:18 [DEBUG   ][deluge.core.preferencesmanager:171 ] Config key: torrentfiles_location set to /var/lib/deluge/Downloads..
21:02:18 [DEBUG   ][deluge.core.preferencesmanager:171 ] Config key: dht set to True..
It writes nothing further to the log, including when attempting to stop the daemon.

Code: Select all

● deluged.service - Deluge Bittorrent Client Daemon
     Loaded: loaded (/etc/systemd/system/deluged.service; enabled; vendor preset: enabled)
    Drop-In: /etc/systemd/system/deluged.service.d
             └─override.conf
     Active: deactivating (stop-sigterm) since Wed 2023-05-31 21:04:20 EDT; 55s ago
       Docs: man:deluged
   Main PID: 2925 (deluged)
      Tasks: 3 (limit: 18877)
     Memory: 36.1M
        CPU: 575ms
     CGroup: /system.slice/deluged.service
             └─2925 /usr/bin/python3 /usr/bin/deluged -d -l /var/log/deluge/daemon.log -L debug
It eventually fails and is killed:

Code: Select all

× deluged.service - Deluge Bittorrent Client Daemon
     Loaded: loaded (/etc/systemd/system/deluged.service; enabled; vendor preset: enabled)
    Drop-In: /etc/systemd/system/deluged.service.d
             └─override.conf
     Active: failed (Result: timeout) since Wed 2023-05-31 21:09:20 EDT; 5min ago
       Docs: man:deluged
    Process: 2925 ExecStart=/usr/bin/deluged -d -l /var/log/deluge/daemon.log -L debug (code=killed, signal=KILL)
   Main PID: 2925 (code=killed, signal=KILL)
        CPU: 580ms

May 31 21:02:17 agamemnon systemd[1]: Started Deluge Bittorrent Client Daemon.
May 31 21:04:20 agamemnon systemd[1]: Stopping Deluge Bittorrent Client Daemon...
May 31 21:09:20 agamemnon systemd[1]: deluged.service: State 'stop-sigterm' timed out. Killing.
May 31 21:09:20 agamemnon systemd[1]: deluged.service: Killing process 2925 (deluged) with signal SIGKILL.
May 31 21:09:20 agamemnon systemd[1]: deluged.service: Killing process 2929 (deluged) with signal SIGKILL.
May 31 21:09:20 agamemnon systemd[1]: deluged.service: Killing process 2930 (deluged) with signal SIGKILL.
May 31 21:09:20 agamemnon systemd[1]: deluged.service: Main process exited, code=killed, status=9/KILL
May 31 21:09:20 agamemnon systemd[1]: deluged.service: Failed with result 'timeout'.
May 31 21:09:20 agamemnon systemd[1]: Stopped Deluge Bittorrent Client Daemon.
Additional attempts to start the daemon all stop at at the same place - setting DHT to true - until the session.state file is removed.

I'm definitely at a bit of a loss!
mhertz
Moderator
Moderator
Posts: 2195
Joined: Wed Jan 22, 2014 5:05 am
Location: Denmark

Re: session.state corrupt on deluged stop

Post by mhertz »

I'm sorry, I don't know - appreciate the thorough logging and verboseness though btw! :)

Apparently deluged hangs at shutdown, as you state/found - it's not because writing faulty session.state though - that warning in first post's log, is normal upon first run, and others if fail closing correct, and is just about the bak file not being there, so irrelevant, and I see that too here. Just adding for completeness.

Personally I couldn't reproduce this in an ubuntu 22.04.2 x64 VM, with same setup as you - I did find a report likeminded, without resort unfortunetly.

You can lower the default TimeoutStopSec from 300 to 90 or 30 or lower in your systemd file for deluged, just so it gets killed and you don't have to do so manually. Again just for completeness. (Afterwards do 'sudo systemctl daemon-reload, not sure if needed but atleast won't hurt')

Sorry couldn't give you any actual help mate :(

If was me, then I would try changing libtorrent version - the PPA for deluge doesn't have a libtorrent for ubuntu 22.04, so you get the one from ubuntu repo's i.e. libtorrent 2.0.5(well maybe would have gotten regardless, as newer) - You can if wanted run e.g. this command 'sudo pip3 install -U libtorrent'('-U' needed because otherwise fails because already installed), to get the latest i.e 2.0.9, and it will be picked up propperly automatically, in place of the 2.0.5 also installed. Also could try the little more tested/supported libtorrent 1.2.19 with 'sudo pip3 install -U libtorrent==1.2.*'. You need python3-pip for this if not already(can be installed with apt).

Last, I would personally myself try to troubleshoot if was systemd related or not too, i.e. try if running deluged manually and then stopping it with the console-ui i.e. 'deluge-console halt' worked - you can run from deluge user easilly with e.g. 'sudo -u deluge deluged' and 'sudo -u deluge deluge-console halt'. If worked, then could start deluged from a startup file or something, instead of systemd. Downgrading deluge itself also is a possibility of-course - for troubleshooting I mean, but would rather do the other tests first myself.

Good luck!
rotational
New User
New User
Posts: 4
Joined: Wed May 31, 2023 12:58 am

Re: session.state corrupt on deluged stop

Post by rotational »

mhertz wrote: Thu Jun 01, 2023 4:57 pm If was me, then I would try changing libtorrent version - the PPA for deluge doesn't have a libtorrent for ubuntu 22.04, so you get the one from ubuntu repo's i.e. libtorrent 2.0.5(well maybe would have gotten regardless, as newer) - You can if wanted run e.g. this command 'sudo pip3 install -U libtorrent'('-U' needed because otherwise fails because already installed), to get the latest i.e 2.0.9, and it will be picked up propperly automatically, in place of the 2.0.5 also installed. Also could try the little more tested/supported libtorrent 1.2.19 with 'sudo pip3 install -U libtorrent==1.2.*'. You need python3-pip for this if not already(can be installed with apt).
If it were you, you would have just fixed it for yourself :lol: This appears to have been exactly the problem. After upgrading libtorrent to 2.0.9 the daemon is behaving perfectly.

THANK YOU!
User avatar
ambipro
Moderator
Moderator
Posts: 418
Joined: Thu May 19, 2022 3:33 am
Contact:

Re: session.state corrupt on deluged stop

Post by ambipro »

rotational wrote: Thu Jun 01, 2023 11:50 pm
If it were you, you would have just fixed it for yourself :lol: This appears to have been exactly the problem. After upgrading libtorrent to 2.0.9 the daemon is behaving perfectly.

THANK YOU!
Three cheers for @mhertz once again!
mhertz
Moderator
Moderator
Posts: 2195
Joined: Wed Jan 22, 2014 5:05 am
Location: Denmark

Re: RESOLVED: session.state corrupt on deluged stop

Post by mhertz »

Thanks for making me smile @you-two-good-people, lol, but in all seriousness, much thanks to both of you class-acts, appreciate that/you-guys :)

Great job rotational, very happy to hear you fixed it buddy.

Ambipro, you too bro!
rotational
New User
New User
Posts: 4
Joined: Wed May 31, 2023 12:58 am

Re: RESOLVED: session.state corrupt on deluged stop

Post by rotational »

I almost forgot, I owe you a second Thank You mhertz - under libtorrent 2.0.9 I was seeing tracker SSL verification failures, and your post here contained the solution:

viewtopic.php?p=234350#p234350

So thank you again!
mhertz
Moderator
Moderator
Posts: 2195
Joined: Wed Jan 22, 2014 5:05 am
Location: Denmark

Re: RESOLVED: session.state corrupt on deluged stop

Post by mhertz »

You're most welcome my friend, glad to hear that, and thanks for your kind post buddy, appreciated :)
Post Reply