offlineimap hangs

[Edd Barrett]

On Sun, Jan 11, 2015 at 04:44:23AM +0300, Eygene Ryabinkin wrote:
> Can you, please, kill offlineimap with SIGQUIT: it will print the full
> backtrace of all threads to the stderr.  It will be interesting to see
> the output.

I (accidentally) found one scenario where the hang occurs. I apply the
SIGQUIT approach below.

First background. I have a script which runs offlineimap and mu (the
mail indexer) in a loop with a 180 second sleep in each iteration.

Last night I suspended my laptop, and when it woke this morning, offlineimap
was hanging:

---8<---
OfflineIMAP 6.5.6
  Licensed under the GNU GPL v2+ (v2 or any later version)
Account sync XXXXX:
 *** Processing account XXXXX
 Establishing connection to XXXXX:993
Traceback (most recent call last):
  File "/home/edd/source/passout/passout.py", line 111, in <module>
    entrypoint()
  File "/home/edd/source/passout/passout.py", line 108, in entrypoint
    args.func(args, expand=True)
  File "/home/edd/.local/lib/python2.7/site-packages/argspander/__init__.py", line 74, in _inner
    return func(*func_args)
  File "/home/edd/source/passout/passout.py", line 41, in cmd_stdout
    print(passout.get_password(cfg, pass_name))
  File "/home/edd/source/passout/passout/__init__.py", line 100, in get_password
    (out, err))
passout.PassOutError: gpg returned non-zero
STDOUT: 
STDERR: gpg: cancelled by user
gpg: encrypted with 2048-bit RSA key, ID XXXXXXXX, created XXXX-XX-XX
      "Edd Barrett <XXXXXXXXXXXXXXXX>"
gpg: public key decryption failed: Operation cancelled
gpg: decryption failed: No secret key

Enter password for account 'XXXXX': 
^CTerminating NOW (this may take a few seconds)...
^CTerminating NOW (this may take a few seconds)...
--->8---

What is happening here is, offlineimap was either mid-sync or due to sync
during suspend. The stack trace you see is my password manager attempting to
decrypt a password from disk and send it back to offlineimap (via
remotepasseval). The password manager is communicating with gpg-agent, which
may need to prompt the user to unlock the GPG keychain (via pinentry-gtk2 in
my case). I suppose this can time out, or perhaps it had probems connecting
to the X server whilst X was resuming.

Anyway, after this, offlineimap is hung in the way I described in my first
mail.

I sent it a SIGQUIT:

---8<---
# Thread #0 (id=9702286294272), Account sync XXXXX
File: "/usr/local/lib/python2.7/threading.py", line 783, in __bootstrap self.__bootstrap_inner()
File: "/usr/local/lib/python2.7/threading.py", line 810, in __bootstrap_inner self.run()
File: "/usr/local/lib/python2.7/site-packages/offlineimap/threadutil.py", line 229, in run ExitNotifyThread.run(self)
File: "/usr/local/lib/python2.7/site-packages/offlineimap/threadutil.py", line 158, in run Thread.run(self)
File: "/usr/local/lib/python2.7/threading.py", line 763, in run self.__target(*self.__args, **self.__kwargs)
File: "/usr/local/lib/python2.7/site-packages/offlineimap/accounts.py", line 241, in syncrunner self.__sync()
File: "/usr/local/lib/python2.7/site-packages/offlineimap/accounts.py", line 303, in __sync remoterepos.getfolders()
File: "/usr/local/lib/python2.7/site-packages/offlineimap/repository/IMAP.py", line 322, in getfolders imapobj = self.imapserver.acquireconnection()
File: "/usr/local/lib/python2.7/site-packages/offlineimap/imapserver.py", line 418, in acquireconnection self.__authn_helper(imapobj)
File: "/usr/local/lib/python2.7/site-packages/offlineimap/imapserver.py", line 327, in __authn_helper if func(imapobj):
File: "/usr/local/lib/python2.7/site-packages/offlineimap/imapserver.py", line 253, in __authn_plain imapobj.authenticate('PLAIN', self.__plainhandler)
File: "/usr/local/lib/python2.7/site-packages/offlineimap/imaplib2.py", line 648, in authenticate typ, dat = self._simple_command('AUTHENTICATE', mechanism.upper())
File: "/usr/local/lib/python2.7/site-packages/offlineimap/imaplib2.py", line 1615, in _simple_command return self._command_complete(self._command(name, *args), kw)
File: "/usr/local/lib/python2.7/site-packages/offlineimap/imaplib2.py", line 1343, in _command ok, data = crqb.get_response('command: %s => %%s' % name)
File: "/usr/local/lib/python2.7/site-packages/offlineimap/imaplib2.py", line 170, in get_response self.ready.wait()
File: "/usr/local/lib/python2.7/threading.py", line 621, in wait self.__cond.wait(timeout)
File: "/usr/local/lib/python2.7/threading.py", line 340, in wait waiter.acquire()

# Thread #1 (id=9700364648960), Sync Runner
File: "/usr/local/lib/python2.7/threading.py", line 783, in __bootstrap self.__bootstrap_inner()
File: "/usr/local/lib/python2.7/threading.py", line 810, in __bootstrap_inner self.run()
File: "/usr/local/lib/python2.7/site-packages/offlineimap/threadutil.py", line 158, in run Thread.run(self)
File: "/usr/local/lib/python2.7/threading.py", line 763, in run self.__target(*self.__args, **self.__kwargs)
File: "/usr/local/lib/python2.7/site-packages/offlineimap/syncmaster.py", line 37, in syncitall syncaccount(threads, config, accountname)
File: "/usr/local/lib/python2.7/site-packages/offlineimap/syncmaster.py", line 29, in syncaccount thread.start()
File: "/usr/local/lib/python2.7/site-packages/offlineimap/threadutil.py", line 224, in start instancelimitedsems[self.instancename].acquire()
File: "/usr/local/lib/python2.7/threading.py", line 468, in acquire self.__cond.wait()
File: "/usr/local/lib/python2.7/threading.py", line 340, in wait waiter.acquire()

# Thread #2 (id=9701371553504), MainThread
File: "/usr/local/bin/offlineimap", line 23, in <module> oi.run()
File: "/usr/local/lib/python2.7/site-packages/offlineimap/init.py", line 50, in run self.__sync(options)
File: "/usr/local/lib/python2.7/site-packages/offlineimap/init.py", line 382, in __sync threadutil.exitnotifymonitorloop(threadutil.threadexited)
File: "/usr/local/lib/python2.7/site-packages/offlineimap/threadutil.py", line 109, in exitnotifymonitorloop thrd = exitthreads.get(True, 60)
File: "/usr/local/lib/python2.7/Queue.py", line 177, in get self.not_empty.wait(remaining)
File: "/usr/local/lib/python2.7/threading.py", line 359, in wait _sleep(delay)
File: "/usr/local/lib/python2.7/site-packages/offlineimap/init.py", line 359, in sig_handler stacktrace.dump (sys.stderr)
File: "/usr/local/lib/python2.7/site-packages/offlineimap/utils/stacktrace.py", line 20, in dump for f, lno, name, line in traceback.extract_stack (stack):
Abort trap (core dumped) 
--->8---

Looks like some kind of deadlock between threads?

This is 6.5.6 on OpenBSD/amd64.

-- 
Best Regards
Edd Barrett

http://www.theunixzoo.co.uk