Deluged takes forever to stop

tedd · 2020-03-07 03:04:57

My deluged systemd service takes about 5 minutes to stop either via systemctl stop deluged.service or on shutdown.

It starts and runs fine. There is a /usr/bin/python /usr/bin/deluged process with four deluged child processes.

When stopping, I can see the deluged log file confirms 'daemon shutdown successfully', but only two of the child processes terminate. Two more are still there and the systemctl stop deluged command hangs until 5 minutes elapses or I manually run a sudo killall -9 deluged.

Last edited by tedd (2020-03-07 03:05:33)

tedd · 2020-03-13 06:15:24

Bump.

No one got any idea why systemd is not stopping all processes?

No one got any troubleshooting tips?

teckk · 2020-03-13 13:23:07

Don't bump like that. They won't like it.

https://www.linuxquestions.org/question … 175671099/

tedd · 2020-03-13 22:02:20

I will bump like that because it's been a week with no-one replying.

I don't understand your suggestion. I am not killing deluged manually, I'm using systemctl stop deluged.service as I said in my initial post. The operation times out after five minutes because only two of the four deluged processes are stopped.

2ManyDogs · 2020-03-13 22:40:40

No, you will not bump like that when no one replies. Ignoring the Code of Conduct is a good way to earn a ban.

https://wiki.archlinux.org/index.php/Co … ct#Bumping

tedd · 2020-03-14 01:10:37

From the rules:

...Posting a single word or useless message (bumping) to attract attention to your thread is not allowed...

I did not post a single word or useless message.

...If people are reading your thread without answering or offering help, you may try supplying more details, or ask to be pointed in the right direction.

I did ask to be pointed in the right direction.

willemw · 2020-03-14 08:52:11

Not sure why 5 minutes instead of the default 90 seconds, but deluged.service is configured that way:

File /usr/lib/systemd/system/deluged.service

# Time to wait before forcefully stopped.
TimeoutStopSec=300

File /etc/systemd/system.conf

#DefaultTimeoutStopSec=90s

If you want, you can override that value, for example:

File /etc/systemd/system/deluged.service.d/override.conf

[Service]
# Time to wait before forcefully stopped.
TimeoutStopSec=10

Last edited by willemw (2020-03-14 08:55:14)

tedd · 2020-03-14 10:11:56

Thank you willemw. I tried your suggestion. It works as a workaround and I had a little distraction (running out of disk space causes a lot of weird things to fail in non-obvious ways).

Fixing the disk space problem makes the other weird things go away, but deluged still doesn't get stopped cleanly by systemctl stop deluged. At least it takes less time now.

Editing to say that there seems to be a variable number of sibling deluged processes when the daemon is running. E.g.: right now there are eight. Last time I tried, there's still only two that don't stop.

Last edited by tedd (2020-03-14 10:19:06)

CarbonChauvinist · 2020-03-14 14:14:57

So far, besides griping about being told not to bump posts, you've still to post any real pertinent details to go by.

If this is something you're determined to get to the bottom of -- help us help you.

Post outputs of the following:

systemctl cat deluged.service
systemd-delta
systemctl list-unit-files --state enabled
systemctl status deluged.service (when attempting to stop and the service is hanging)
journalctl -b _PID=XXX (get PID from command above)
and also a full journal from an affected boot (use a paste service)

Did you even read the suggestion in post #3? (i.e. does `systemctl kill deluged` present different behavior?)

tedd · 2020-03-15 09:32:41

Thanks CarbonChauvinist. Outputs following.

systemctl cat deluged.service:

# /usr/lib/systemd/system/deluged.service
[Unit]
Description=Deluge Bittorrent Client Daemon
Documentation=man:deluged
After=network-online.target

[Service]
Type=simple
UMask=007

ExecStart=/usr/bin/deluged -d

Restart=on-failure

# Time to wait before forcefully stopped.
TimeoutStopSec=300

[Install]
WantedBy=multi-user.target

# /etc/systemd/system/deluged.service.d/override.conf
[Service]
ExecStart=
ExecStart=/usr/bin/deluged -d -L info -l /var/log/deluge.log
Nice=1
TimeoutStopSec=90s

# /usr/lib/systemd/system/deluged.service.d/user.conf
# Override service user
[Service]
User=deluge
Group=deluge

systemd-delta:

[EXTENDED]   /usr/lib/systemd/system/deluge-web.service → /usr/lib/systemd/system/deluge-web.service.d/user.conf
[EXTENDED]   /usr/lib/systemd/system/deluged.service → /etc/systemd/system/deluged.service.d/override.conf
[EXTENDED]   /usr/lib/systemd/system/deluged.service → /usr/lib/systemd/system/deluged.service.d/user.conf
[EXTENDED]   /usr/lib/systemd/system/remote-fs-pre.target → /etc/systemd/system/remote-fs-pre.target.d/override.conf

4 overridden configuration files found.

systemctl list-unit-files --state enabled:

UNIT FILE                 STATE   VENDOR PRESET
autovt@.service           enabled disabled     
cronie.service            enabled disabled     
deluge-web.service        enabled disabled     
deluged.service           enabled disabled     
dhcpcd.service            enabled disabled     
dovecot.service           enabled disabled     
fake-hwclock.service      enabled disabled     
getty@.service            enabled enabled      
haveged.service           enabled disabled     
sshd.service              enabled disabled     
systemd-timesyncd.service enabled enabled      
uptimed.service           enabled disabled     
remote-fs.target          enabled enabled      
fake-hwclock-save.timer   enabled disabled     

14 unit files listed.

systemctl status deluged.service:

● deluged.service - Deluge Bittorrent Client Daemon
     Loaded: loaded (/usr/lib/systemd/system/deluged.service; enabled; vendor preset: disabled)
    Drop-In: /etc/systemd/system/deluged.service.d
             └─override.conf
             /usr/lib/systemd/system/deluged.service.d
             └─user.conf
     Active: failed (Result: timeout) since Sun 2020-03-15 19:03:33 AEST; 1min 16s ago
       Docs: man:deluged
    Process: 1554 ExecStart=/usr/bin/deluged -d -L info -l /var/log/deluge.log (code=killed, signal=KILL)
   Main PID: 1554 (code=killed, signal=KILL)

Mar 15 19:01:50 [hostname] systemd[1]: Started Deluge Bittorrent Client Daemon.
Mar 15 19:02:03 [hostname] systemd[1]: Stopping Deluge Bittorrent Client Daemon...
Mar 15 19:03:33 [hostname] systemd[1]: deluged.service: State 'stop-sigterm' timed out. Killing.
Mar 15 19:03:33 [hostname] systemd[1]: deluged.service: Killing process 1554 (deluged) with signal SIGKILL.
Mar 15 19:03:33 [hostname] systemd[1]: deluged.service: Main process exited, code=killed, status=9/KILL
Mar 15 19:03:33 [hostname] systemd[1]: deluged.service: Failed with result 'timeout'.
Mar 15 19:03:33 [hostname] systemd[1]: Stopped Deluge Bittorrent Client Daemon.

journalctl -b _PID=1554 gives no log entries.
journalctl -f -b -u deluged output is same as in systemctl status.

I don't feel comfortable giving out an entire system log without sanitising it and I don't have the time for that. If you would tell me what you are looking for I would be happy to oblige.

Running systemctl kill deluged on its own doesn't end all deluged child processes but the command does end straight away. Then running systemctl stop deluged stops the rest and finishes quickly.

CarbonChauvinist · 2020-03-15 22:43:48

Hmm, not sure. All looks okay I guess. It looks like you've manually overridden the nice level as well as the exec start line. The exec start line changes seem trivial as they're just adding logging options I guess, but why did you override nice?

Is the user.conf override a default provided by the package? Does the same thing happen if you disable or stop the deluge-web.service first? What happens if you revert all changes back to the package defaults (`systemctl revert deluged.service`)? Making sure to 'systemctl daemon-reload'.

My thought is there are still additional clients connected to the daemon. That's why I'd like you to try disabling the deluge-web.service and test stopping. Have you by chance also started a systemd user instance of the service? Check to make sure that's not the case.

Also is this new behavior? Did it behave differently originally and just recently started hanging on stop?

Maybe post the contents of /var/log/deluge.log so others better versed can look.

tedd · 2020-03-16 07:43:57

I overrode nice because deluged takes a lot of cpu on this old machine, and there are other tasks that need more priority. I just checked from the Arch package and the user.conf override is provided by the package.

The change to ExecStart was just to add logging, as I don't think deluge logs anything anywhere by default. It certainly doesn't log to journal as I've confirmed after running the below steps.

All the changes to the unit file were made long before the daemon started this problem, though I just did the following:

systemctl revert deluged.service
systemctl kill deluged
systemctl stop deluged
systemctl daemon-reload
systemctl stop deluge-web
systemctl disable deluge-web
systemctl mask deluge-web

So systemctl cat deluged now looks like this:

# /usr/lib/systemd/system/deluged.service
[Unit]
Description=Deluge Bittorrent Client Daemon
Documentation=man:deluged
After=network-online.target

[Service]
Type=simple
UMask=007

ExecStart=/usr/bin/deluged -d

Restart=on-failure

# Time to wait before forcefully stopped.
TimeoutStopSec=300

[Install]
WantedBy=multi-user.target

# /usr/lib/systemd/system/deluged.service.d/user.conf
# Override service user
[Service]
User=deluge
Group=deluge

But running

systemctl start deluged
systemctl stop deluged

Still gives the same behaviour. deluge-web on the same machine is not running during this, nor are there any other deluge clients elsewhere on the network.

Yes, this is new behaviour. I don't restart the machine often, but deluged has been affecting shutdown for at least the last couple of weeks. I can't remember what configuration I've been changing on this machine except for running pacman -Syu.

To my knowledge, I don't run another instance of deluged. I'm not sure exactly how to check my user, but a systemctl list-units --user doesn't show anything deluge, nor are there any other processes of the same name running at any time, underneath the parent '/usr/bin/deluged -d -L info -l /var/log/deluge.log', which is as user 'deluge'.

This is the output of /var/log/deluge.log after undoing the troubleshooting changes above.
All lines appear soon after the command is entered. Nothing more is added when systemd finally kills the remaining processes that are hanging.
Edit: To be clear, I re-enabled and started deluge-web but did not connect to it.

17:38:12.255 [INFO    ][deluge.core.authmanager       :236 ] Successfully loaded auth: /srv/deluge/.config/deluge/auth
17:38:12.263 [INFO    ][deluge.core.torrentmanager    :806 ] Loading torrent state: /srv/deluge/.config/deluge/state/torrents.state
17:38:12.271 [INFO    ][deluge.core.torrentmanager    :822 ] Successfully loaded /srv/deluge/.config/deluge/state/torrents.state
17:38:12.274 [INFO    ][deluge.core.torrentmanager    :1069] Opening torrents.fastresume for load: /srv/deluge/.config/deluge/state/torrents.fastresume
17:38:12.278 [INFO    ][deluge.core.torrentmanager    :1080] Successfully loaded torrents.fastresume: /srv/deluge/.config/deluge/state/torrents.fastresume
[snip]
17:38:12.596 [INFO    ][deluge.core.torrentmanager    :885 ] Finished loading 3 torrents in 0:00:00.333414
17:38:13.456 [INFO    ][deluge.core.torrentmanager    :1612] on_alert_external_ip: [my IP]
17:38:59.274 [INFO    ][twisted                       :154 ] Received SIGTERM, shutting down.
17:38:59.283 [INFO    ][deluge.core.daemon            :176 ] Deluge daemon shutting down, waiting for components to shutdown...
17:38:59.326 [INFO    ][deluge.core.core              :307 ] Saving the session.state at: /srv/deluge/.config/deluge/session.state
17:38:59.694 [INFO    ][twisted                       :154 ] (TLS Port [my port] Closed)
17:38:59.699 [INFO    ][twisted                       :154 ] Stopping factory <twisted.internet.protocol.Factory object at 0xb32d6a78>
17:38:59.708 [INFO    ][twisted                       :154 ] Main loop terminated.
17:38:59.713 [INFO    ][deluge.core.daemon            :168 ] Deluge daemon shutdown successfully
17:38:59.716 [INFO    ][deluge.core.daemon_entry      :137 ] Exiting...

Incidentally, why is it that ExecStart require a ExecStart= line before a change in overrides? Are there other directives that require the same?

Last edited by tedd (2020-03-16 07:47:41)

CarbonChauvinist · 2020-03-16 16:19:56

Thanks @tedd for the thorough details. I don't see anything immedately striking re: the logs.

I may just be muddying the waters here, it's been a while since I've torrented anything so have no real experience with Deulge for some time now. I did see that this is a python 2 bitorrent client?

ArchWiki wrote:

Deluge is a full-featured BitTorrent application written in Python 2

I've also seen at least one other report, now closed and for a systemd user service, but with similar issues. Perhaps this is happening since the clean up of the python2 packages?

tedd wrote:

Incidentally, why is it that ExecStart require a ExecStart= line before a change in overrides? Are there other directives that require the same?

My understanding is that the first `ExecStart=` line is to clear out what may have been set originally. It needs to be explicitly cleared first because ExecStart is an additive setting, you can specify multiple ExecStart lines which are each processed in order they appear.

man systemd.service(5) wrote:

ExecStart=
Commands with their arguments that are executed when this service is started. For each of the specified commands, the first argument must be an absolute and literal path to an executable.
When Type is not oneshot, only one command may and must be given. When Type=oneshot is used, none or more than one command may be specified. Multiple command lines may be concatenated in a single directive by separating them with semicolons (these semicolons must be passed as separate words). Alternatively, this directive may be specified more than once with the same effect. Lone semicolons may be escaped as "\;". If the empty string is assigned to this option, the list of commands to start is reset, prior assignments of this option will have no effect. If no ExecStart= is specified, then the service must have RemainAfterExit=yes set.
...
If more than one command is specified, the commands are invoked sequentially in the order they appear in the unit file. If one of the commands fails (and is not prefixed with "-"), other lines are not executed, and the unit is considered failed.

Maniaxx · 2020-03-16 18:05:22

Do you see high i/o or cpu load when the processes hang? Did you try a different client?

tedd · 2020-03-17 06:47:09

CarbonChauvinist wrote:

I may just be muddying the waters here, it's been a while since I've torrented anything so have no real experience with Deulge for some time now. I did see that this is a python 2 bitorrent client?

Deluge 2.0 is a rewrite for Python 3, which has been in Arch since about June 2019. I've been running deluged as a daemon since the 1.3 days (Feb 2017) and have been regularly keeping up with Arch packages since. 2.x has not been a problem for me until this, apart from no built MacOS or Windows clients (hence the web client).
Would it be possible that some part of deluge is still requiring Python 2, and when Arch dropped Python 2 would cause a fault like this?

Release notes for Deluge 2.0

...
Migrated to Python 3 with minimal support retained for Python 2.7.
...

Would this mean a bug report is next?

maniaxx wrote:

Do you see high i/o or cpu load when the processes hang? Did you try a different client?

No, there is no high i/o or cpu usage after the first lot of deluged child processes end. The remaining two aren't doing anything. I did not try a different client because the daemon has this behaviour even with no clients, as in my previous post.

willemw · 2020-03-17 08:04:52

Reported issue: FS#65859 - deluge fails to shutdown and must be SIGKILL to stop

tedd · 2020-03-17 11:05:13

Thanks willemw.

That debug log in the bug report is not mine. Did you find this issue too?

willemw · 2020-03-17 17:06:57

Someone else reported that Arch issue.

You can vote for that issue to give it more attention.

I do have the issue, which probably started after installing the latest deluge package version.

tedd · 2020-03-18 10:55:02

Thank you everyone for your assistance.

Arch Linux

#1 2020-03-07 03:04:57

Deluged takes forever to stop

#2 2020-03-13 06:15:24

Re: Deluged takes forever to stop

#3 2020-03-13 13:23:07

Re: Deluged takes forever to stop

#4 2020-03-13 22:02:20

Re: Deluged takes forever to stop

#5 2020-03-13 22:40:40

Re: Deluged takes forever to stop

#6 2020-03-14 01:10:37

Re: Deluged takes forever to stop

#7 2020-03-14 08:52:11

Re: Deluged takes forever to stop

#8 2020-03-14 10:11:56

Re: Deluged takes forever to stop

#9 2020-03-14 14:14:57

Re: Deluged takes forever to stop

#10 2020-03-15 09:32:41

Re: Deluged takes forever to stop

#11 2020-03-15 22:43:48

Re: Deluged takes forever to stop

#12 2020-03-16 07:43:57

Re: Deluged takes forever to stop

#13 2020-03-16 16:19:56

Re: Deluged takes forever to stop

#14 2020-03-16 18:05:22

Re: Deluged takes forever to stop

#15 2020-03-17 06:47:09

Re: Deluged takes forever to stop

#16 2020-03-17 08:04:52

Re: Deluged takes forever to stop

#17 2020-03-17 11:05:13

Re: Deluged takes forever to stop

#18 2020-03-17 17:06:57

Re: Deluged takes forever to stop

#19 2020-03-18 10:55:02

Re: Deluged takes forever to stop

Board footer