imapclient icon indicating copy to clipboard operation
imapclient copied to clipboard

imapclient.exceptions.ProtocolError: Server replied with a response that violates the IMAP protocol

Open dkozinn opened this issue 3 years ago • 4 comments

This seems like a duplicate of the now-closed #351. I've been able to reproduce this connected to a Dovecot server using a minimal example based on my actual code. In this case, I marked an item read then unread in an Outlook session, but I've seen this happen under other circumstances (which are hard to reproduce reliably). I've uploaded a log file at https://pastebin.com/CqEZhaKx.

If it will help, I can create an account for you to test with on this server, contact me privately and I'll set it up for you.

#!/usr/bin/env python
  
from imapclient import IMAPClient
import logging

HOST = 'mail.example.com'
USER = 'david'
PASSWORD = 'Password1'

logging.basicConfig(
    format='%(asctime)s - %(levelname)s: %(message)s',
    level=logging.DEBUG
)

try:
    server = IMAPClient(HOST)
    server.login(USER, PASSWORD)
    server.select_folder("INBOX")

    # Start IDLE mode
    server.idle()
    while True:
        responses = server.idle_check(timeout=30)

        if responses:
            server.idle_done()
            messages = server.search(["UNSEEN"])
            server.idle()
except KeyboardInterrupt:
    server.idle_done()
    server.logout
except Exception as error:
    logging.exception("Unexpected error")

dkozinn avatar Jan 17 '22 18:01 dkozinn

I've found something else that may be related: I connected with tls=FALSE and ran a network capture to see what was actually on the wire. I'm seeing these errors now:

Traceback (most recent call last):
  File "./debug-protocol-error.py", line 23, in <module>
    responses = server.idle_check(timeout=30)
  File "/home/david/.local/lib/python3.8/site-packages/imapclient/imapclient.py", line 175, in wrapper
    return func(client, *args, **kwargs)
  File "/home/david/.local/lib/python3.8/site-packages/imapclient/imapclient.py", line 940, in idle_check
    line = self._imap._get_line()
  File "/usr/lib/python3.8/imaplib.py", line 1164, in _get_line
    raise self.abort('socket error: unterminated line: %r' % line)
imaplib.IMAP4.abort: socket error: unterminated line: b'* 91 FETCH (FLAGS (\\Deleted \\Seen \\Recent)'

In the network capture, there are two packets which are re-assembled to form the message seen in the error. The only thing in the second packet is \r\n. I have not looked at the code here but is it possible that it's attempting to process a packet that hasn't been fully assembled, which presumably would be in imaplib judging from the trace?

dkozinn avatar Jan 17 '22 22:01 dkozinn

Interesting. Thanks for the excellent sleuthing so far.

It looks like the way idle_check is consuming the socket needs to be improved. There may be an assumption that complete lines will be seen in one socket read but that's not always true.

mjs avatar Jan 25 '22 10:01 mjs

So there's 2 issues going on here. The first is the ProtocolError. Looking at the pastebin, this part seems to be the key:

2022-01-17 13:10:00,862 - DEBUG: > b'EAHN4 IDLE'
2022-01-17 13:10:00,894 - DEBUG: < b'+ idling'
2022-01-17 13:10:14,597 - DEBUG: < b')'

The client starts idling and the server responds with + idling which is fine. The problem is the ) that is sent by the server 14s later. This is invalid - the line should start with * - and this is what's causing the ProtocolError.

I'm not sure what IMAPClient could better here. It seems the server sent an invalid response. IMAPClient could ignore the response but that could result in getting out of sync with the server.

mjs avatar Aug 22 '23 11:08 mjs

I've created #519 to track the "unterminated line" issue.

mjs avatar Aug 22 '23 11:08 mjs