Crash on exit

[murks]

This is what I see when I exit alot regularly (using d or q):

0: [search] for "tag:inbox AND NOT tag:killed" (55824 threads) total messages: 5646Unhandled error in Deferred:
Unhandled Error
Traceback (most recent call last):
File "/usr/lib/python2.7/site-packages/urwid/main_loop.py", line 449, in process_input
k = self._topmost_widget.keypress(self.screen_size, k)
File "/usr/lib/python2.7/site-packages/alot/ui.py", line 52, in keypress
self.ui.apply_command(cmd)
File "/usr/lib/python2.7/site-packages/alot/ui.py", line 454, in apply_command
cmd.apply(self)
File "/usr/lib/python2.7/site-packages/twisted/internet/defer.py", line 1141, in unwindGenerator
return _inlineCallbacks(None, f(_args, *_kwargs), Deferred())
--- ---
File "/usr/lib/python2.7/site-packages/twisted/internet/defer.py", line 1020, in _inlineCallbacks
result = g.send(result)
File "/usr/lib/python2.7/site-packages/alot/commands/globals.py", line 41, in apply
ui.exit()
File "/usr/lib/python2.7/site-packages/alot/ui.py", line 193, in exit
raise urwid.ExitMainLoop()
urwid.main_loop.ExitMainLoop:

[pazz]

is this with editor_spawn = False and editor_in_thread = True? in that case alot and your editor
are both writing/reading from the same terminal...

[murks]

This seems to happen always, even with the default settings (happened before I wrote a config file).
python2 2.7.2
twisted 11.0.0

[pazz]

it looks like the unhandeled error is actually the urwid.ExitMainLoop, which is the correct way
to successfully terminate urwid.
This shouldn't run in a deferred though...

[pazz]

could you post a debug log please?
simply do a alot -l debug.log -d debug, hit q and post the contents of that file?
thanks

[murks]

Sadly, alot -l debug.log -d debug doesn't create a debug.log file. I tried with all other debug levels as well, same result. Seems like logging doesn't work here.

[pazz]

this is weird. I'm beginning to think there's something seriously broken with your python environment..
don't hate me: do you have write permissions in the current dir?
also, could you veryfy the python version from inside alot's pyshell please?

>>> import sys
>>> sys.version

thanks,
/p

[murks]

It's usually my home directory, so yes, my user does have write permissions, no one else has.
The disk isn't full either, there are a few GB left :)

import sys
sys.version
'2.7.2 (default, Nov 21 2011, 17:25:27) \n[GCC 4.6.2]'

matches what my package management system says: python2 2.7.2

One possible cause:
python 3.2.2
on Arch python already refers to python3, so if you have shebangs that say just python and expect python2, well, that could be a problem :)
Just an idea though.

EDIT:
I had a look, only found init.py, changed that, but no change in behavior.
Also tried with the line from the old git PKGBUILD:
sed -i -e "s|#![ ]/usr/bin/python$|#!/usr/bin/python2|"
-e "s|#![ ]/usr/bin/env python$|#!/usr/bin/env python2|"
$(find ./ -name '*.py')
While init.py was changed, still the same behavior.

So while the python shebang that assumes python2 might be a problem on arch, it doesn't appear to be the cause of this particular problem. Anyway, can you safely change all references to python2 or will this break debian?

[pazz]

python2 and python3 seem to be arch specific. all other distis use /usr/bin/python to softlink to their prefered version.
the idea of using /usr/bin/env python was to abstract from these issues. but it seems debian (as arch) will need
to replace this for packaging. but this is another issue.

if sys.version from inside alot says 2.7 then 2.7 it is. but i'm totally baffled by you not being able to log at all
but not having any import logging errors..

[teythoon]

You can check your logging module by running

% python -c 'import logging; logging.basicConfig(level = logging.DEBUG, filename = "debug.log"); logging.debug("huhu")'
% cat debug.log
DEBUG:root:huhu

or you could strace the python process running alot:

% strace -e trace=open,stat,creat alot -d debug -l debug.log 2> alot.strace
% grep debug.log alot.strace

Well, thist was the moment I realized that alot fails to create logfiles on my system as well. I'm running debian wheezy by the way. Not sure what's happening, I tried stracing my alot process, then dropping into the python shell and reconfigure the logging by hand but nothing happens, no open, no write if I log something. Very strange indeed.

[pazz]

I remember having some problems with logging before:
If you for example add a statement logging.debug('foo') to any sourcefile which imports logging
(outside of any class/function defs that is, so that it gets fired when the module is imported),

Then as a result logging does not work as expected:
I know that only after alot.init.main, in which the path of the logfile gets set, i can expect that anything
gets written to this file. So I cannot expect this new logline to show up.
However, nothing gets logged at all in this case.

[murks]

In case it could help, here's my strace: https://gist.github.com/4af6e681ece81462465b

[pazz]

i was just going to add my strace with working logging as a gist for comparison, but its too large (>500kb) to upload it :)
so here it is: http://homepages.inf.ed.ac.uk/s0976898/alot.strace

[murks]

Noticed something? Even your strace shows the "Unhandled error in Deferred" :)

[pazz]

i forgot to comment on this yes:
Although the trace shows this exception, my interface terminates successfully.
Raising urwid.main_loop.ExitMainLoop is the correct way to terminate an urwid interface.

@murks: whats your urwid version?

[murks]

alot terminates for me too, but it shows the trace each time, which imho shouldn't be. So the difference is that the trace is shown on my system but not on yours? Should it be shown? I'm somewhat confused.

urwid is from git, checkout from 20111212

[pazz]

@teythoon: i just tried to use your strace command to have a look if
other tools written in urwid yield this exception when exiting: Turns out that
they don't even start the interface in this environment:

strace -e trace=open,stat,creat bpython > bpython.strace

yields lots of stuff on stdout, but never starts. Same thing for urwids palette_test.py
script. I suspect this is because there, an ordinary SelectEventLoop is used,
whereas alot uses TwistedEventLoop.
Maybe we should reconsider the order in which twisted's "reactor" is stopped and
this urwid.main_loop.ExitMainLoop is raised?

[teythoon]

Quoting Patrick Totzke (2011-12-17 20:24:53)

@teythoon: i just tried to use your strace command to have a look if
other tools written in urwid yield this exception when exiting: Turns out that
they don't even start the interface in this environment:

strace -e trace=open,stat,creat bpython > bpython.strace

yields lots of stuff on stdout, but never starts. Same thing for urwids palette_test.py
script. I suspect this is because there, an ordinary SelectEventLoop is used,
whereas alot uses TwistedEventLoop.

Hm, no. strace writes to stderr, you are redirecting stdout. But then
urwid/ncurses/termcap detects that stdout isn't connected to a capable
terminal and doesn't output anything. Try alot >/tmp/foo vs
alot 2>/tmp/foo.

Maybe we should reconsider the order in which twisted's "reactor" is stopped and
this urwid.main_loop.ExitMainLoop is raised?

I've no idea.

Justus

[pazz]

@teythoon doh! stupid me :)

try branch issue-156-exitmainloop. I asked around in the urwid irc, and apparently,
one doesn't need to raise this exception if one shuts down twisteds reactor manually (like i do).
with this patch I don't have any uncaught exceptions in my strace, but the interface shuts down
as expected.

[murks]

I tried issue-156-exitmainloop and alot shuts down without throwing the error. I also generated a strace, no error there either. I consider this fixed, thanks :)

There's still no log, I think this deserves its own issue.

[pazz]

ok, i'll merge this into testing & master, thanks