Ticket #2007 (closed bug: fixed)

Opened 17 months ago

Last modified 4 months ago

UnicodeDecodeError when logging to file

Reported by: non7top Owned by: Cas
Priority: minor Milestone: 1.4.0
Component: core Version: master (git branch)
Keywords: Cc:

Description

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:

Attachments

0001-fix-unicode-error-in-logger.patch (1.0 KB) - added by non7top 11 months ago.

Change History

Changed 17 months ago by Cas

  • component changed from other to core
  • milestone changed from Future to 1.4.0

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?

Changed 17 months ago by non7top

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

Changed 17 months ago by non7top

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"))

Changed 17 months ago by Cas

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

Changed 17 months ago by non7top

The workaround worked just fine

Changed 17 months ago by Cas

  • status changed from new to assigned
  • owner set to Cas

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.

Changed 15 months ago by non7top

Please commit to master

Changed 11 months ago by non7top

Changed 11 months ago by non7top

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

Changed 11 months ago by Cas

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

Changed 4 months ago by bro

  • status changed from assigned to closed
  • resolution set to fixed
Note: See TracTickets for help on using tickets.