imaplib2 : imap.gmail.com handler BYE response: System error

Question

I'm renovating a python script that checks IMAP for new emails and sends a push notification if there's a new email. The problem is that every few hours I'm getting a crash. At first I couldn't really understand what's going on but then I found about M.debug = 4 that gave me a nice output but I still can't understand what is causing the problem. I've posted my script and the debug output from normal behavior till the crash, hoping that someone with better understanding in python can tell me what is going on and how can I fix it.

Edit:

I've edited my code as suggested in the answers to this:

while True:
    try:
      [call function that does all your logic]
    except imaplib2.IMAP4.abort:
      print("Disconnected.  Trying again.")

or this:

    while True:
        try:
          [call function that does all your logic]
except (imaplib2.IMAP4.abort, imaplib2.IMAP4.error) as e: 
      print("Disconnected.  Trying again.")

But I'm still getting a crash after an undetermined period of time and the exception will never get caught. print("Disconnected. Trying again.") will never execute.

The code:

    #!/usr/local/bin/python2.7
    print "Content-type: text/html\r\n\r\n";

    import socket, ssl, json, struct, re
    import imaplib2, time
    from threading import *

    # enter gmail login details here
    USER="[email protected]"
    PASSWORD="password"
    # enter device token here
    deviceToken = 'my device token x x x x x'
    deviceToken = deviceToken.replace(' ','').decode('hex')
    currentBadgeNum = -1

    def getUnseen():
        (resp, data) = M.status("INBOX", '(UNSEEN)')
        print data
        return int(re.findall("UNSEEN (\d)*\)", data[0])[0])    

    def sendPushNotification(badgeNum):
        global currentBadgeNum, deviceToken
        if badgeNum != currentBadgeNum:
            currentBadgeNum = badgeNum
            thePayLoad = {
                 'aps': {
                      'alert':'Hello world!',
                      'sound':'',
                      'badge': badgeNum,
                      },
                 'test_data': { 'foo': 'bar' },
                 }
            theCertfile = 'certif.pem'
            theHost = ('gateway.push.apple.com', 2195)

            data = json.dumps(thePayLoad)
            theFormat = '!BH32sH%ds' % len(data)
            theNotification = struct.pack(theFormat, 0, 32, deviceToken, len(data), data)

            ssl_sock = ssl.wrap_socket(socket.socket(socket.AF_INET, socket.SOCK_STREAM), certfile=theCertfile)
            ssl_sock.connect(theHost)
            ssl_sock.write(theNotification)
            ssl_sock.close()
            print "Sent Push alert."

    # This is the threading object that does all the waiting on 
    # the event
    class Idler(object):
        def __init__(self, conn):
            self.thread = Thread(target=self.idle)
            self.M = conn
            self.event = Event()

        def start(self):
            self.thread.start()

        def stop(self):
            # This is a neat trick to make thread end. Took me a 
            # while to figure that one out!
            self.event.set()

        def join(self):
            self.thread.join()

        def idle(self):
            # Starting an unending loop here
            while True:
                # This is part of the trick to make the loop stop 
                # when the stop() command is given
                if self.event.isSet():
                    return
                self.needsync = False
                # A callback method that gets called when a new 
                # email arrives. Very basic, but that's good.
                def callback(args):
                    if not self.event.isSet():
                        self.needsync = True
                        self.event.set()
                # Do the actual idle call. This returns immediately, 
                # since it's asynchronous.
                self.M.idle(callback=callback)
                # This waits until the event is set. The event is 
                # set by the callback, when the server 'answers' 
                # the idle call and the callback function gets 
                # called.
                self.event.wait()
                # Because the function sets the needsync variable,
                # this helps escape the loop without doing 
                # anything if the stop() is called. Kinda neat 
                # solution.
                if self.needsync:
                    self.event.clear()
                    self.dosync()

        # The method that gets called when a new email arrives. 
        # Replace it with something better.
        def dosync(self):
            print "Got an event!"
            numUnseen = getUnseen()
            sendPushNotification(numUnseen)

    # Had to do this stuff in a try-finally, since some testing 
    # went a little wrong.....
while True:
    try:
        # Set the following two lines to your creds and server
        M = imaplib2.IMAP4_SSL("imap.gmail.com")
        M.login(USER, PASSWORD)
        M.debug = 4
        # We need to get out of the AUTH state, so we just select 
        # the INBOX.
        M.select("INBOX")
        numUnseen = getUnseen()
        sendPushNotification(numUnseen)

        typ, data = M.fetch(1, '(RFC822)')
        raw_email = data[0][1]

        import email
        email_message = email.message_from_string(raw_email)
        print email_message['Subject']

        #print M.status("INBOX", '(UNSEEN)')
        # Start the Idler thread
        idler = Idler(M)
        idler.start()


        # Sleep forever, one minute at a time
        while True:
            time.sleep(60)
    except imaplib2.IMAP4.abort:
      print("Disconnected.  Trying again.")   
    finally:
        # Clean up.
        #idler.stop() #Commented out to see the real error
        #idler.join() #Commented out to see the real error
        #M.close()    #Commented out to see the real error
        # This is important!
        M.logout()

... ... ...

  43:54.43 imap.gmail.com handler _request_pop(continuation, (True, 'idling')) = CHPJ127
  43:54.43 imap.gmail.com handler None:CHPJ127.ready.set
  43:54.43 Thread-4 continuation => True, idling
  43:54.43 Thread-4 server IDLE started, timeout in 1740.00 secs
  43:54.43 Thread-4 state_change_pending.release
  57:13.60 imap.gmail.com reader < * BYE System error\r\n
  57:13.63 imap.gmail.com handler server IDLE finished
  57:13.63 imap.gmail.com handler BYE response: System error
  57:13.63 imap.gmail.com writer > DONE\r\n
  **57:13.63 imap.gmail.com handler terminating: 'connection terminated'**
  57:13.63 imap.gmail.com writer finished
  57:13.63 imap.gmail.com handler last 20 log messages:
  51:49.77 Thread-4 [sync] IDLE ()
  20:50.18 Thread-4 [async] STATUS ('INBOX', '(UNSEEN)')
  20:50.51 Thread-4 [sync] IDLE ()
  49:50.79 Thread-4 [async] STATUS ('INBOX', '(UNSEEN)')
  49:51.02 Thread-4 [sync] IDLE ()
  18:51.33 Thread-4 [async] STATUS ('INBOX', '(UNSEEN)')
  18:51.49 Thread-4 [sync] IDLE ()
  47:51.80 Thread-4 [async] STATUS ('INBOX', '(UNSEEN)')
  47:51.96 Thread-4 [sync] IDLE ()
  16:52.26 Thread-4 [async] STATUS ('INBOX', '(UNSEEN)')
  16:52.63 Thread-4 [sync] IDLE ()
  45:53.08 Thread-4 [async] STATUS ('INBOX', '(UNSEEN)')
  45:53.24 Thread-4 [sync] IDLE ()
  14:53.54 Thread-4 [async] STATUS ('INBOX', '(UNSEEN)')
  14:53.69 Thread-4 [sync] IDLE ()
  43:53.96 Thread-4 [async] STATUS ('INBOX', '(UNSEEN)')
  43:54.17 Thread-4 [sync] IDLE ()
  57:13.63 imap.gmail.com handler BYE response: System error
  57:13.63 imap.gmail.com handler terminating: 'connection terminated'
  57:13.63 imap.gmail.com writer finished
Got an event!
  57:13.63 imap.gmail.com handler state_change_free.set
  57:13.63 Thread-4 [async] STATUS ('INBOX', '(UNSEEN)')
  57:13.63 imap.gmail.com handler finished
  57:13.63 Thread-4 state_change_pending.acquire
  57:13.63 Thread-4 state_change_pending.release
Exception in thread Thread-4:
Traceback (most recent call last):
  File "/usr/local/lib/python2.7/threading.py", line 551, in __bootstrap_inner
    self.run()
  File "/usr/local/lib/python2.7/threading.py", line 504, in run
    self.__target(*self.__args, **self.__kwargs)
  File "shaserver.py", line 111, in idle
    self.dosync()
  File "shaserver.py", line 117, in dosync
    numUnseen = getUnseen()
  File "shaserver.py", line 35, in getUnseen
    (resp, data) = M.status("INBOX", '(UNSEEN)')
  File "/home/boombe/lib/python2.7/imaplib2/imaplib2.py", line 1121, in status
    return self._simple_command(name, mailbox, names, **kw)
  File "/home/boombe/lib/python2.7/imaplib2/imaplib2.py", line 1607, in _simple_command
    return self._command_complete(self._command(name, *args), kw)
  File "/home/boombe/lib/python2.7/imaplib2/imaplib2.py", line 1295, in _command
    self._check_bye()
  File "/home/boombe/lib/python2.7/imaplib2/imaplib2.py", line 1229, in _check_bye
    raise self.abort(bye[-1])
abort: System error

  57:13.70 imap.gmail.com reader finished

... ... ...

Sometimes I get this:

03:09.29 Thread-4 [sync] IDLE ()
  05:53.25 imap.gmail.com reader socket error: <type 'exceptions.IOError'> - Error Hang up
  05:53.25 imap.gmail.com reader finished
  05:53.26 imap.gmail.com handler terminating: "socket error: <type 'exceptions.IOError'> - Error Hang up"
  05:53.26 imap.gmail.com handler last 20 log messages:
  07:07.66 Thread-4 [sync] IDLE ()
  36:07.78 Thread-4 [async] STATUS ('INBOX', '(UNSEEN)')
  36:07.83 Thread-4 [async] SEARCH ('ALL',)
  36:07.88 Thread-4 [async] FETCH ('1', '(RFC822.HEADER)')
  36:08.09 Thread-4 [sync] IDLE ()
  05:08.19 Thread-4 [async] STATUS ('INBOX', '(UNSEEN)')
  05:08.25 Thread-4 [async] SEARCH ('ALL',)
  05:08.42 Thread-4 [async] FETCH ('1', '(RFC822.HEADER)')
  05:08.48 Thread-4 [sync] IDLE ()
  34:08.58 Thread-4 [async] STATUS ('INBOX', '(UNSEEN)')
  34:08.68 Thread-4 [async] SEARCH ('ALL',)
  34:08.79 Thread-4 [async] FETCH ('1', '(RFC822.HEADER)')
  34:08.94 Thread-4 [sync] IDLE ()
  03:09.05 Thread-4 [async] STATUS ('INBOX', '(UNSEEN)')
  03:09.16 Thread-4 [async] SEARCH ('ALL',)
  03:09.21 Thread-4 [async] FETCH ('1', '(RFC822.HEADER)')
  03:09.29 Thread-4 [sync] IDLE ()
  05:53.25 imap.gmail.com reader socket error: <type 'exceptions.IOError'> - Error Hang up
  05:53.25 imap.gmail.com reader finished
  05:53.26 imap.gmail.com handler terminating: "socket error: <type 'exceptions.IOError'> - Error Hang up"
  05:53.26 imap.gmail.com writer finished
Got an event!
  05:53.26 Thread-4 [async] STATUS ('INBOX', '(UNSEEN)')
  05:53.26 Thread-4 state_change_pending.acquire
  05:53.26 Thread-4 server IDLE finished
  05:53.26 Thread-4 state_change_pending.release
  05:53.26 Thread-4 _get_untagged_response(READ-ONLY) => ['']
  05:53.26 imap.gmail.com handler state_change_free.set
  05:53.26 imap.gmail.com handler finished
Exception in thread Thread-4:
Traceback (most recent call last):
  File "/usr/local/lib/python2.7/threading.py", line 551, in __bootstrap_inner
    self.run()
  File "/usr/local/lib/python2.7/threading.py", line 504, in run
    self.__target(*self.__args, **self.__kwargs)
  File "shaserver.py", line 229, in idle
    self.dosync()
  File "shaserver.py", line 235, in dosync
    numUnseen = getUnseen()
  File "shaserver.py", line 150, in getUnseen
    (resp, data) = M.status("INBOX", '(UNSEEN)')
  File "/home/boombe/lib/python2.7/imaplib2/imaplib2.py", line 1121, in status
    return self._simple_command(name, mailbox, names, **kw)
  File "/home/boombe/lib/python2.7/imaplib2/imaplib2.py", line 1607, in _simple_command
    return self._command_complete(self._command(name, *args), kw)
  File "/home/boombe/lib/python2.7/imaplib2/imaplib2.py", line 1305, in _command
    raise self.abort('connection closed')
abort: connection closed

Answer 1

That's because the exception is thrown in another thread and in another place which is not guarded by the except block. Just look at the backtrace -- you'll see that it starts within the threading.py (and there's no exception handling in there). Continue via the dosync and getUnseen methods -- again, no exception handling.

So that explains why is your try/except block ineffective -- that's because you've explicitly asked to execute that code in another thread. What remains to be explained is why are you getting the exception in the first place. One reason might be that you are hitting the timeout which is typically associated with the IDLE command -- see RFC 2177 for details (it's a short read) which will tell you that you're supposed to break your idling every 29 minutes. Another possibility is that gmail simply doesn't like you -- maybe they don't feel like sustaining clients which are connected for too long. I have no data to back up that speculation, though.

But the most important question remains -- why are you using threads at all? As someone who has implemented and IMAP client from scratch (btw., it started in Python many years ago), I am completely sure that threading is not required to talk IMAP efficiently. In your particular use case, you appear to be running one thread just for the IDLE command while spending the time of the main thread in an endless wait. That in itself is something I don't understand, but perhaps you have some important reason for that -- maybe you really need to offload some IMAP processing to another thread after all. However, please consider moving any IMAP related activity to that thread in that case -- because right now, one of your threads is performing the initial SELECT and some data fetching, and only after that it trasnfers the IMAP connection to another thread for the IDLE. That is just evil.

To the basic need of threading -- an architecture which worked well for me was making use of the asynchronous nature of the IMAP protocol. I'm not sure how well would it play with the imaplib2 library, maybe it doesn't have support for truly asynchronous IMAP processing. In that case, I'd strongly consider just using IMAP in a borin, blocking synchronous manner where each and every operation really waits for completion of the command. Yes, some of them will run for a long time -- if you absolutely need to perform some activity while you're e.g. waiting for that IDLE to finish after 29 minutes, then it might be a good idea to defer the IMAP processing to another thread. But you should be pretty certain that this is what you really require before you go that way.