UnicodeDecodeError when logging to file

[Vladimir Berezhnoy]

On latest git master

$ deluged --do-not-daemonize -L debug -l /home/non7top/.config/deluge/deluged.log
Traceback (most recent call last):
  File "/usr/lib/python2.7/logging/__init__.py", line 865, in emit
    stream.write(fs % msg.encode("UTF-8"))
UnicodeDecodeError: 'ascii' codec can't decode byte 0xd0 in position 104: ordinal not in range(128)
Logged from file alertmanager.py, line 124
Traceback (most recent call last):
  File "/usr/lib/python2.7/logging/__init__.py", line 865, in emit
    stream.write(fs % msg.encode("UTF-8"))
UnicodeDecodeError: 'ascii' codec can't decode byte 0xd0 in position 106: ordinal not in range(128)
Logged from file alertmanager.py, line 124
Traceback (most recent call last):
  File "/usr/lib/python2.7/logging/__init__.py", line 865, in emit
    stream.write(fs % msg.encode("UTF-8"))
UnicodeDecodeError: 'ascii' codec can't decode byte 0xd0 in position 107: ordinal not in range(128)
Logged from file alertmanager.py, line 124
Traceback (most recent call last):
  File "/usr/lib/python2.7/logging/__init__.py", line 865, in emit
    stream.write(fs % msg.encode("UTF-8"))
UnicodeDecodeError: 'ascii' codec can't decode byte 0xd0 in position 104: ordinal not in range(128)
Logged from file alertmanager.py, line 124
Traceback (most recent call last):
  File "/usr/lib/python2.7/logging/__init__.py", line 865, in emit
    stream.write(fs % msg.encode("UTF-8"))
UnicodeDecodeError: 'ascii' codec can't decode byte 0xd0 in position 104: ordinal not in range(128)
Logged from file alertmanager.py, line 124
Traceback (most recent call last):
  File "/usr/lib/python2.7/logging/__init__.py", line 865, in emit
    stream.write(fs % msg.encode("UTF-8"))
UnicodeDecodeError: 'ascii' codec can't decode byte 0xd0 in position 107: ordinal not in range(128)
Logged from file alertmanager.py, line 124
Traceback (most recent call last):
  File "/usr/lib/python2.7/logging/__init__.py", line 865, in emit
    stream.write(fs % msg.encode("UTF-8"))
UnicodeDecodeError: 'ascii' codec can't decode byte 0xd0 in position 106: ordinal not in range(128)
Logged from file alertmanager.py, line 124
Traceback (most recent call last):
  File "/usr/lib/python2.7/logging/__init__.py", line 865, in emit
    stream.write(fs % msg.encode("UTF-8"))
UnicodeDecodeError: 'ascii' codec can't decode byte 0xd0 in position 104: ordinal not in range(128)
Logged from file alertmanager.py, line 124
^C^CUnhandled error in Deferred:
Unhandled Error
Traceback (most recent call last):
  File "/usr/lib/python2.7/site-packages/twisted/internet/defer.py", line 286, in addCallbacks
    self._runCallbacks()
  File "/usr/lib/python2.7/site-packages/twisted/internet/defer.py", line 542, in _runCallbacks
    current.result = callback(current.result, *args, **kw)
  File "/usr/lib/python2.7/site-packages/deluge/component.py", line 275, in on_depends_started
    return self.components[name]._component_start()
  File "/usr/lib/python2.7/site-packages/deluge/component.py", line 126, in _component_start
    d = maybeDeferred(self.start)
--- <exception caught here> ---
  File "/usr/lib/python2.7/site-packages/twisted/internet/defer.py", line 133, in maybeDeferred
    result = f(*args, **kw)
  File "/usr/lib/python2.7/site-packages/deluge/core/torrentmanager.py", line 216, in start
    self.load_state()
  File "/usr/lib/python2.7/site-packages/deluge/core/torrentmanager.py", line 677, in load_state
    resume_data=resume_data.get(torrent_state.torrent_id))
  File "/usr/lib/python2.7/site-packages/deluge/core/torrentmanager.py", line 505, in add
    torrent = Torrent(handle, options, state, filename, magnet, owner)
  File "/usr/lib/python2.7/site-packages/deluge/core/torrent.py", line 192, in __init__
    self.set_options(self.options)
  File "/usr/lib/python2.7/site-packages/deluge/core/torrent.py", line 247, in set_options
    OPTIONS_FUNCS[key](value)
  File "/usr/lib/python2.7/site-packages/deluge/core/torrent.py", line 381, in set_file_priorities
    self.set_prioritize_first_last(self.options["prioritize_first_last_pieces"])
  File "/usr/lib/python2.7/site-packages/deluge/core/torrent.py", line 316, in set_prioritize_first_last
    slices = ti.map_block(n, 0, ti.piece_size(n))
exceptions.KeyboardInterrupt:

[Calum]

This is weird as I would have expected a logging problem in alertmanager to have appeared long before now.

What version of libtorrent are you using? Is this repeatable or a one-off occurrence?

[Vladimir Berezhnoy]

dev-lang/python 2.7.2-r3 net-libs/rb_libtorrent 0.15.6

I believe the error appears for torrents which have cyrillic in their names and the issue does not re-appear when I run 'deluged --do-not-daemonize -L debug'

I've added line 'print ("TEST", alert.message())' in alertmanager.py and here is the output of relevant lines

('TEST', '\xd0\x93\xd0\xb0\xd1\x80\xd1\x80\xd0\xb8 \xd0\x9f\xd0\xbe\xd1\x82\xd1\x82\xd0\xb5\xd1\x80 \xd0\xb8 \xd1\x82\xd0\xb0\xd0\xb9\xd0\xbd\xd0\xb0\xd1\x8f \xd0\xba\xd0\xbe\xd0\xbc\xd0\xbd\xd0\xb0\xd1\x82\xd0\xb0 (Harry Potter and the Chamber of Secrets - Extended Cut).2002.BDRip.1080p.-MySiLU.mkv: state changed to: downloading')
Traceback (most recent call last):
  File "/usr/lib/python2.7/logging/__init__.py", line 865, in emit
    stream.write(fs % msg.encode("UTF-8"))
UnicodeDecodeError: 'ascii' codec can't decode byte 0xd0 in position 82: ordinal not in range(128)
Logged from file alertmanager.py, line 125

Hope this helps

[Vladimir Berezhnoy]

I changed line 124 in alertmanager.py to following and error is gone and correct cyrillic torrent names are shown in log file. Apparently there was a double utf-8->utf-8 conversion.

log.debug("%s: %s", alert_type, alert.message().decode("utf8"))

[Calum]

I thought so, encoding again in the python logging results in the unicode error and I realised that in git master logging code was changed. The new code specifies 'utf8' encoding to file so that's why it fails.

Could you try this workaround instead: ​https://github.com/cas--/Deluge/commit/710dc495b2a7

[Vladimir Berezhnoy]

The workaround worked just fine

[Calum]

I think this will have to be the actual fix since we cannot guarantee that logging messages passed in other parts of our code will pass unicode.

[Vladimir Berezhnoy]

Please commit to master

[Vladimir Berezhnoy]

Please commit to master. The patch cleanely applies to latest git master.

[Calum]

I decided to change all the alert messages strings to be utf8 instead and will commit the code soon.

[Bro]

Fixed in ​4b99a39779df58a759c7bb26fca96fdc3ac2bfab

[Calum]

Milestone renamed