bamthomas / aioimaplib

Python asyncio IMAP4rev1 client library
GNU General Public License v3.0
135 stars 58 forks source link

idle_start never returns if the server closes the connection #110

Open bipface opened 2 months ago

bipface commented 2 months ago

When calling idle_start(), if the server closes the connection instead of responding with + idling, the function will hang indefinitely (regardless of the timeout arg). Tested using aioimaplib v1.1.0, python v3.11.2.

I experienced this issue when connected to imap.gmx.com, however the following code demonstrates the bug in isolation.

Log when the server responds normally (no issue):

[root:DEBUG] idle_start()
[aioimaplib.aioimaplib:DEBUG] Sending : b'EMNN3 IDLE\r\n'
[aioimaplib.aioimaplib:DEBUG] Received : b'+ idling\r\n'
[aioimaplib.aioimaplib:DEBUG] continuation line -- assuming IDLE is active : b'+ idling'
[root:DEBUG] wait_server_push()
[root:DEBUG] Timeout - wait_server_push
[aioimaplib.aioimaplib:DEBUG] connection lost: None
[root:DEBUG] onConnLost()
<process exits here>

Log when the connection is closed:

[root:DEBUG] idle_start()
[aioimaplib.aioimaplib:DEBUG] Sending : b'GGPL3 IDLE\r\n'
[aioimaplib.aioimaplib:DEBUG] Received : b'* BYE timeout\r\n'
[aioimaplib.aioimaplib:DEBUG] connection lost: None
[root:DEBUG] onConnLost()
<process is still running and never exits>

Code:

import asyncio
import logging
import logging.config
import socket
import aioimaplib
import threading
import re

async def testIdle() -> None:
    configureLogging()

    evt = threading.Event()
    svrThread = threading.Thread(target=imapServer, args=(evt,))
    svrThread.start()

    imap = aioimaplib.IMAP4(
        host='127.0.0.1',
        port=8000,
        conn_lost_cb=onConnLost,
    )

    await imap.wait_hello_from_server()
    await imap.login('foo', 'bar')
    await imap.select('INBOX')

    logging.debug('idle_start()')
    idleTask = await imap.idle_start()

    logging.debug('wait_server_push()')
    try:
        data = await imap.wait_server_push(timeout=3)
        logging.debug('wait_server_push result: %s', repr(data))
    except TimeoutError:
        logging.debug('Timeout - wait_server_push')

    evt.set()
    svrThread.join()

def onConnLost(*args) -> None:
    logging.debug('onConnLost()')

def imapServer(evt) -> None:
    svr = socket.socket(socket.AF_INET, socket.SOCK_STREAM)
    svr.setsockopt(socket.SOL_SOCKET, socket.SO_REUSEADDR, 1)
    svr.bind(('127.0.0.1', 8000))
    svr.listen(1)

    svr.settimeout(1)

    logging.debug('svr.accept()')
    client = svr.accept()[0]
    svr.close()

    client.send(b'* OK\r\n')

    data = client.recv(1024)
    m = re.fullmatch(b'^(\w+) CAPABILITY\r\n$', data)
    client.send(b'* CAPABILITY IMAP4rev1 IDLE\r\n')
    client.send(m[1] + b' OK CAPABILITY completed\r\n')

    data = client.recv(1024)
    m = re.fullmatch(b'^(\w+) LOGIN [^\r]+\r\n$', data)
    client.send(m[1] + b' OK LOGIN completed\r\n')

    data = client.recv(1024)
    m = re.fullmatch(b'^(\w+) SELECT INBOX\r\n$', data)
    client.send(m[1] + b' OK SELECT completed\r\n')

    data = client.recv(1024)
    m = re.fullmatch(b'^(\w+) IDLE\r\n$', data)
    if not m:
        raise Exception

    if False:
        # Normal response:
        client.send(b'+ idling\r\n')
        evt.wait()
        client.close()
    else:
        # Pathological response:
        client.send(b'* BYE timeout\r\n')
        client.close()
        evt.wait()

def configureLogging() -> None:
    logging.config.dictConfig({
        'version': 1,
        'disable_existing_loggers': False,
        'formatters': {
            'default': {
                'format': '[%(name)s:%(levelname)s] %(message)s',
            },
        },
        'handlers': {
            'stderr': {
                'class': 'logging.StreamHandler',
                'formatter': 'default',
                'stream': 'ext://sys.stderr',
            },
        },
        'root': {
            'level': 'DEBUG',
            'handlers': ['stderr'],
        },
    })

if __name__ == '__main__':
    asyncio.run(testIdle())