Bug#993083: deluged: Deluged throws Critical errors due to unhandled errors after updating to Python3.9

Jonas Andradas

unread,

Aug 27, 2021, 6:00:04 AM8/27/21

to

Package: deluged
Version: 2.0.3-3.1
Severity: important
X-Debbugs-Cc: j.and...@gmail.com

Dear Maintainer,

since updating my system to Debian 11 "bullseye", which updated Python
to version 3.9, deluged (and deluge-web and deluge-console) have stopped
working as expected.

I have tried using the init.d scripts to start the service and also
manually (as de debian-deluged user), with the same results, explained
below:

* The daemon starts and listens on the daemon port (for management)
and in a random port for incoming connections (despite
listening_ports are defined in the configuration file, these are not
used)

* The process starts logging critical errors to
/var/log/deluge/daemon.log, such as the following ones:

11:34:37 [INFO ][deluge.configmanager:52 ] Setting config directory to: /var/lib/deluged/config
11:34:37 [CRITICAL][twisted :154 ] Unhandled error in Deferred:
11:34:38 [CRITICAL][twisted :154 ] Unhandled error in Deferred:
11:34:38 [CRITICAL][twisted :154 ] Unhandled error in Deferred:
11:34:38 [CRITICAL][twisted :154 ] Unhandled error in Deferred:
11:34:38 [CRITICAL][twisted :154 ] Unhandled error in Deferred:
11:34:38 [INFO ][twisted :154 ] Factory (TLS) starting on 58846
11:34:38 [INFO ][twisted :154 ] Starting factory <twisted.internet.protocol.Factory object at 0x7f5c1a1260a0>
11:34:38 [CRITICAL][twisted :154 ] Unhandled error in Deferred:
11:35:08 [CRITICAL][twisted :154 ] Unhandled error in Deferred:

* Whenever interaction with the daemon is attempted via deluge-console
or deluge-web, nothing is logged and, despite these connections seem
to be successful (e.g. the client seems to interact with the backend
server, any added torrents or settings changed are not persisted.

* The torrents are not processed nor downloaded.

-- System Information:
Debian Release: 11.0
APT prefers stable-security
APT policy: (500, 'stable-security'), (500, 'stable')
Architecture: amd64 (x86_64)

Kernel: Linux 5.11.22-2-pve (SMP w/6 CPU threads)
Kernel taint flags: TAINT_PROPRIETARY_MODULE, TAINT_FIRMWARE_WORKAROUND, TAINT_OOT_MODULE
Locale: LANG=en_GB.UTF-8, LC_CTYPE=en_GB.UTF-8 (charmap=UTF-8), LANGUAGE not set
Shell: /bin/sh linked to /bin/dash
Init: systemd (via /run/systemd/system)

Versions of packages deluged depends on:
ii adduser 3.118
ii deluge-common 2.0.3-3.1
ii lsb-base 11.1.0
ii python3 3.9.2-3
ii python3-libtorrent 1.2.9-0.3

deluged recommends no packages.

deluged suggests no packages.

-- Configuration Files:
/etc/default/deluged changed:
ENABLE_DELUGED=1

-- no debconf information

Rob

unread,

Sep 4, 2021, 2:40:03 PM9/4/21

to

Hello,

I can confirm this is happening as well, the journal output is slightly
more informative than the deluged log:

Sep 04 18:32:06 testvm deluged[2132]: Unhandled error in Deferred:
Sep 04 18:32:06 testvm deluged[2132]: Traceback (most recent call last):
Sep 04 18:32:06 testvm deluged[2132]: File
"/usr/lib/python3/dist-packages/deluge/core/daemon_entry.py", line 112,
in run_daemon
Sep 04 18:32:06 testvm deluged[2132]: daemon = Daemon(
Sep 04 18:32:06 testvm deluged[2132]: File
"/usr/lib/python3/dist-packages/deluge/core/daemon.py", line 94, in
__init__
Sep 04 18:32:06 testvm deluged[2132]: log.info('Deluge daemon %s',
get_version())
Sep 04 18:32:06 testvm deluged[2132]: File
"/usr/lib/python3/dist-packages/twisted/internet/defer.py", line 1613,
in unwindGenerator
Sep 04 18:32:06 testvm deluged[2132]: return
_cancellableInlineCallbacks(gen)
Sep 04 18:32:06 testvm deluged[2132]: File
"/usr/lib/python3/dist-packages/twisted/internet/defer.py", line 1529,
in _cancellableInlineCallbacks
Sep 04 18:32:06 testvm deluged[2132]: _inlineCallbacks(None, g,
status)
Sep 04 18:32:06 testvm deluged[2132]: --- <exception caught here> ---
Sep 04 18:32:06 testvm deluged[2132]: File
"/usr/lib/python3/dist-packages/twisted/internet/defer.py", line 1418,
in _inlineCallbacks
Sep 04 18:32:06 testvm deluged[2132]: result = g.send(result)
Sep 04 18:32:06 testvm deluged[2132]: File
"/usr/lib/python3/dist-packages/deluge/log.py", line 69, in info
Sep 04 18:32:06 testvm deluged[2132]: yield
LoggingLoggerClass.info(self, msg, *args, **kwargs)
Sep 04 18:32:06 testvm deluged[2132]: File
"/usr/lib/python3.9/logging/__init__.py", line 1442, in info
Sep 04 18:32:06 testvm deluged[2132]: self._log(INFO, msg, args,
**kwargs)
Sep 04 18:32:06 testvm deluged[2132]: File
"/usr/lib/python3.9/logging/__init__.py", line 1573, in _log
Sep 04 18:32:06 testvm deluged[2132]: fn, lno, func, sinfo =
self.findCaller(stack_info, stacklevel)
Sep 04 18:32:06 testvm deluged[2132]: builtins.TypeError: findCaller()
takes from 1 to 2 positional arguments but 3 were given
Sep 04 18:32:06 testvm deluged[2132]: Temporarily disabling observer
LegacyLogObserverWrapper(<bound method TwistedLoggingObserver.emit of
<deluge.log.TwistedLoggingObserver object at 0x7fef143b84c0>>) due to
exception: [Failure instance: Traceback: <class 'TypeError'>:
findCaller() t
akes from 1 to 2 positional arguments but 3 were given
Sep 04 18:32:06 testvm deluged[2132]:
/usr/lib/python3/dist-packages/pkg_resources/_vendor/pyparsing.py:646:__getattr__
Sep 04 18:32:06 testvm deluged[2132]:
/usr/lib/python3/dist-packages/twisted/internet/defer.py:962:__del__
Sep 04 18:32:06 testvm deluged[2132]:
/usr/lib/python3/dist-packages/twisted/logger/_logger.py:190:failure
Sep 04 18:32:06 testvm deluged[2132]:
/usr/lib/python3/dist-packages/twisted/logger/_logger.py:144:emit
Sep 04 18:32:06 testvm deluged[2132]: --- <exception caught here> ---
Sep 04 18:32:06 testvm deluged[2132]:
/usr/lib/python3/dist-packages/twisted/logger/_observer.py:131:__call__
Sep 04 18:32:06 testvm deluged[2132]:
/usr/lib/python3/dist-packages/twisted/logger/_legacy.py:93:__call__
Sep 04 18:32:06 testvm deluged[2132]:
/usr/lib/python3/dist-packages/deluge/log.py:204:emit
Sep 04 18:32:06 testvm deluged[2132]:
/usr/lib/python3.9/logging/__init__.py:1489:critical
Sep 04 18:32:06 testvm deluged[2132]:
/usr/lib/python3.9/logging/__init__.py:1573:_log
Sep 04 18:32:06 testvm deluged[2132]: ]

It seems like it's bumping into something like this:
https://stackoverflow.com/questions/60859773/flask-logging-error-typeerror-findcaller-takes-from-1-to-2-position-argument.

If you fix that error (i.e. you patch
/usr/lib/python3/dist-packages/deluge/log.py:89 to be: `def
findCaller(self, stack_info=False, stackLevel=1):` then that will fix
the deluged logging which then means that /var/log/deluged/daemon.log
will be full of actually useful information; that said I think this is
actually an upstream issue with deluged, rather than a Debian problem.

On this test VM I have here, it looks like the error I get is:
```
9:25:43 [INFO ][deluge.configmanager:52 ] Setting config directory
to: /var/lib/deluged/config
19:25:44 [INFO ][deluge.core.daemon :94 ] Deluge daemon
2.0.3
19:25:44 [INFO ][deluge.core.core :339 ] Successfully
loaded session.state: /var/lib/deluged/config/session.state
19:25:44 [WARNING ][deluge.core.core :337 ] Unable to load
/var/lib/deluged/config/session.state.bak: [Errno 2] No such file or
directory: '/var/lib/deluged/config/session.state.bak'
19:25:44 [INFO ][deluge.core.alertmanager :148 ] Alert Queue
Size set to 10000
19:25:44 [INFO ][deluge.core.rpcserver :402 ] Starting
DelugeRPC server localhost:58846
19:25:44 [ERROR ][deluge.core.daemon_entry :132 ] Unable to start
deluged: [('SSL routines', 'SSL_CTX_use_certificate', 'ee key too
small')]
19:25:44 [INFO ][deluge.core.daemon_entry :137 ] Exiting...
```

So presumably there are 2 problems; this one may be a debian issue.

-Rob

Rob

unread,

Sep 4, 2021, 3:00:03 PM9/4/21

to

OK so I think I've got to the bottom of it.

If you:
- purge all deluge packages (i.e. rm -R /var/lib/deluged)
- reinstall all the packages
- then patch the log.py as mentioned previously

It then seems to be in a working state, so I think:

A: The Debian upgrade leaves some incompatible configuration/ssl stuff?
B: Deluge 2.0.3 is broken under python 3.9

It does look like there's a change upstream that's not released yet
which
fixes it judging by the fact this line is different:
https://git.deluge-torrent.org/deluge/tree/deluge/log.py?h=develop#n91

-Rob

Eric Van Buggenhaut

unread,

Sep 6, 2021, 7:00:03 PM9/6/21

to

Rob pointed to the exact source of the bug. I was unable to start
deluged daemon until I patched

/usr/lib/python3/dist-packages/deluge/log.py

Rob

unread,

Sep 10, 2021, 5:30:03 PM9/10/21

to

See attached for patch

log.py.diff

Rob

unread,

Sep 10, 2021, 5:40:04 PM9/10/21

to

Actually, totally munged that 1 line change somehow.

Corrected Patch attached.

log.py.patch

Diederik de Haas

unread,

Nov 18, 2021, 5:40:04 AM11/18/21

to

That would be this commit, which is not (yet) part of any release:
https://git.deluge-torrent.org/deluge/commit/?h=develop&id=351664ec071daa04161577c6a1c949ed0f2c3206

signature.asc

MichaIng

unread,

Dec 10, 2021, 12:30:03 PM12/10/21

to

Indeed it would be great if this patch could be applied to the Deluge
v2.0.3 package on Debian Bullseye. Here the related pull request, in
case it contains additional information:
https://github.com/deluge-torrent/deluge/pull/271

Best regards,

Micha

Daniel Baumann

unread,

Feb 19, 2023, 4:00:04 PM2/19/23

to

close 993083 2.1.1-1
thanks

Hi,

this is fixed in the upload of deluge 2.1.1, hence closing the bug.

Regards,
Daniel