Hundreds of MB of exception logs

[Jazz]

Sometimes Deluge logs the same exception repeatedly until I manually restart it. When it happens, one CPU core runs at 100% and it can fill hundreds of megabytes of logs until I stop it.

Unhandled Error
Traceback (most recent call last):
  File "/usr/lib/python2.7/dist-packages/deluge/ui/gtkui/gtkui.py", line 294, in __init__
    reactor.run()
  File "/usr/lib/python2.7/dist-packages/twisted/internet/_glibbase.py", line 301, in run
    self._run()
  File "/usr/lib/python2.7/dist-packages/twisted/internet/_glibbase.py", line 155, in wrapper
    return callback(source, condition)
  File "/usr/lib/python2.7/dist-packages/twisted/internet/_glibbase.py", line 170, in _ioEventCallback
    source, self._doReadOrWrite, source, source, condition)
--- <exception caught here> ---
  File "/usr/lib/python2.7/dist-packages/twisted/python/log.py", line 101, in callWithLogger
    return callWithContext({"system": lp}, func, *args, **kw)
  File "/usr/lib/python2.7/dist-packages/twisted/python/log.py", line 84, in callWithContext
    return context.call({ILogContext: newCtx}, func, *args, **kw)
  File "/usr/lib/python2.7/dist-packages/twisted/python/context.py", line 118, in callWithContext
    return self.currentContext().callWithContext(ctx, func, *args, **kw)
  File "/usr/lib/python2.7/dist-packages/twisted/python/context.py", line 81, in callWithContext
    return func(*args,**kw)
  File "/usr/lib/python2.7/dist-packages/twisted/internet/posixbase.py", line 610, in _doReadOrWrite
    self._disconnectSelectable(selectable, why, inRead)
  File "/usr/lib/python2.7/dist-packages/twisted/internet/posixbase.py", line 247, in _disconnectSelectable
    self.removeReader(selectable)
  File "/usr/lib/python2.7/dist-packages/twisted/internet/_glibbase.py", line 250, in removeReader
    self._remove(reader, self._reads, self._writes, self.OUTFLAGS)
  File "/usr/lib/python2.7/dist-packages/twisted/internet/_glibbase.py", line 237, in _remove
    self._source_remove(self._sources[source])
exceptions.OverflowError: signed integer is greater than maximum

[Calum]

This looks more like a pygtk/twisted issue than Deluge related, perhaps you are running the GUI on a headless server? Please provide more system information: Contributing/BugReporting

[Jazz]

It's not an headless server. It's with Gnome on Ubuntu 16.10.

[Calum]

Ok well I can't offer much help on this and I don't see any issues myself. You should probably open a bug report for Ubuntu and see if they have any suggestions. You could ask on Twisted IRC if they have seen this error before.

[Michael D Greene]

For what it's worth, I see the same issue. When it happens, there is an affected torrent that shows Progress as "Paused 0.00%" but if I click on the Files tab all of the pieces are 100% downloaded, and on the Status / Details tabs it looks active. I am on Ubuntu 16.04.2 with Deluge 1.3.15 through the PPA.

[Calum]

@euphoria what do you see in the logs?

[Michael D Greene]

@Cas Sorry, it took a little while for it to happen again, but this is what I see in the logs, repeated over and over again, until it fills up (there aren't any differences from the ticket text as far as I can tell):

Unhandled Error
Traceback (most recent call last):
  File "/usr/lib/python2.7/dist-packages/deluge/ui/gtkui/gtkui.py", line 294, in __init__
    reactor.run()
  File "/usr/lib/python2.7/dist-packages/twisted/internet/_glibbase.py", line 301, in run
    self._run()
  File "/usr/lib/python2.7/dist-packages/twisted/internet/_glibbase.py", line 155, in wrapper
    return callback(source, condition)
  File "/usr/lib/python2.7/dist-packages/twisted/internet/_glibbase.py", line 170, in _ioEventCallback
    source, self._doReadOrWrite, source, source, condition)
--- <exception caught here> ---
  File "/usr/lib/python2.7/dist-packages/twisted/python/log.py", line 101, in callWithLogger
    return callWithContext({"system": lp}, func, *args, **kw)
  File "/usr/lib/python2.7/dist-packages/twisted/python/log.py", line 84, in callWithContext
    return context.call({ILogContext: newCtx}, func, *args, **kw)
  File "/usr/lib/python2.7/dist-packages/twisted/python/context.py", line 118, in callWithContext
    return self.currentContext().callWithContext(ctx, func, *args, **kw)
  File "/usr/lib/python2.7/dist-packages/twisted/python/context.py", line 81, in callWithContext
    return func(*args,**kw)
  File "/usr/lib/python2.7/dist-packages/twisted/internet/posixbase.py", line 610, in _doReadOrWrite
    self._disconnectSelectable(selectable, why, inRead)
  File "/usr/lib/python2.7/dist-packages/twisted/internet/posixbase.py", line 247, in _disconnectSelectable
    self.removeReader(selectable)
  File "/usr/lib/python2.7/dist-packages/twisted/internet/_glibbase.py", line 250, in removeReader
    self._remove(reader, self._reads, self._writes, self.OUTFLAGS)
  File "/usr/lib/python2.7/dist-packages/twisted/internet/_glibbase.py", line 237, in _remove
    self._source_remove(self._sources[source])
exceptions.OverflowError: signed integer is greater than maximum

Restarting Deluge the torrent shows Paused 0.00% like it did while logging the error, forcing a re-check shows that it actually did complete some pieces, and the torrent can be started normally without continuing to log.

[Calum]

Hmm ok I shall have to put a exception handler in for that but since it's twisted/gtk code I don't have a clue as to actual cause and would probably need a way to replicate to report upstream...

[Michael D Greene]

@Cas It is highly unclear to me what set of criteria causes it, but it happens to me once every 20-30 torrents or once every few weeks. I am unfamiliar with Deluge's codebase or PyGTK but generally familiar with Python and can apply any patch to help report... but I don't really know a way to reproduce it.

[Calum]

I have applied a workaround for this issue that should hopefully stop the spamming of logs: [b13da8a42a01]

[Calum]

Is your OS 32-bit or 64-bit?

[Calum]

Ticket retargeted after milestone deleted