BUG with outlook

[MattiaFailla]

The following code:

from imapclient import IMAPClient

# context manager ensures the session is cleaned up
with IMAPClient(host="imap-mail.outlook.com") as client:
    client.login('[email protected]', 'password')
    client.select_folder('INBOX')

    # search criteria are passed in a straightforward way
    # (nesting is supported)
    messages = client.search(['NOT', 'DELETED'])

    # fetch selectors are passed as a simple list of strings.
    response = client.fetch(messages, ['FLAGS', 'RFC822.SIZE'])

    # `response` is keyed by message id and contains parsed,
    # converted response items.
    for message_id, data in response.items():
        print('{id}: {size} bytes, flags={flags}'.format(
            id=message_id,
            size=data[b'RFC822.SIZE'],
            flags=data[b'FLAGS']))

Is raising this error on Linux Mint 19.1 w/ Python2.x:

Traceback (most recent call last):
  File "1.py", line 13, in <module>
    response = client.fetch(messages, ['FLAGS', 'RFC822.SIZE'])
  File "/home/mattia/.local/lib/python2.7/site-packages/imapclient/imapclient.py", line 1225, in fetch
    typ, data = self._imap._command_complete('FETCH', tag)
  File "/usr/lib/python2.7/imaplib.py", line 921, in _command_complete
    raise self.error('%s command error: %s %s' % (name, typ, data))
imaplib.error: FETCH command error: BAD ['Command Error. 10']

And this one with Python 3.6.x:

Traceback (most recent call last):
  File "/usr/lib/python3.6/imaplib.py", line 979, in _command
    self.send(data + CRLF)
  File "/home/mattia/.local/lib/python3.6/site-packages/imapclient/tls.py", line 60, in send
    self.sock.sendall(data)
  File "/usr/lib/python3.6/ssl.py", line 975, in sendall
    v = self.send(byte_view[count:])
  File "/usr/lib/python3.6/ssl.py", line 944, in send
    return self._sslobj.write(data)
  File "/usr/lib/python3.6/ssl.py", line 642, in write
    return self._sslobj.write(data)
ConnectionResetError: [Errno 104] Connection reset by peer

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "1.py", line 13, in <module>
    response = client.fetch(messages, ['FLAGS', 'RFC822.SIZE'])
  File "/home/mattia/.local/lib/python3.6/site-packages/imapclient/imapclient.py", line 1224, in fetch
    tag = self._imap._command(*args)
  File "/usr/lib/python3.6/imaplib.py", line 981, in _command
    raise self.abort('socket error: %s' % val)
imaplib.abort: socket error: [Errno 104] Connection reset by peer

If you need more information I'll be happy to share.

[mjs]

I'm that's strange. Can you please confirm the version of IMAPClient that you're using? You could check this using pip list or like this in a Python shell in the environment you're running your code:

>>> import imapclient
>>> imapclient.__version__
'2.1.0'

It would also be very helpful to see the protocol logs for these failing sessions. Could you please enable logging as per https://imapclient.readthedocs.io/en/2.1.0/concepts.html#logging and get the logs to me? Please be aware that logs might contain senstive information so you might want remove passwords etc from the output before posting logs here. If in doubt, please email me at [email protected].

[MattiaFailla]

Sorry for the delay.
My version is '2.1.0'

The full log:

2019-12-27 16:19:23,380 - DEBUG: Connected to host imap-mail.outlook.com over SSL/TLS
2019-12-27 16:19:23,381 - DEBUG: > DGGH1 LOGIN **REDACTED**
2019-12-27 16:19:23,733 - DEBUG: < DGGH1 OK LOGIN completed.
2019-12-27 16:19:23,733 - DEBUG: 	matched r'(?P<tag>DGGH\d+) (?P<type>[A-Z]+) (?P<data>.*)' => ('DGGH1', 'OK', 'LOGIN completed.')
2019-12-27 16:19:23,733 - INFO: Logged in as [email protected]
2019-12-27 16:19:23,733 - DEBUG: > DGGH2 SELECT "INBOX"
2019-12-27 16:19:24,160 - DEBUG: < * 18206 EXISTS
2019-12-27 16:19:24,160 - DEBUG: 	matched r'\* (?P<data>\d+) (?P<type>[A-Z-]+)( (?P<data2>.*))?' => ('18206', 'EXISTS', None, None)
2019-12-27 16:19:24,160 - DEBUG: untagged_responses[EXISTS] 0 += ["18206"]
2019-12-27 16:19:24,161 - DEBUG: < * 0 RECENT
2019-12-27 16:19:24,161 - DEBUG: 	matched r'\* (?P<data>\d+) (?P<type>[A-Z-]+)( (?P<data2>.*))?' => ('0', 'RECENT', None, None)
2019-12-27 16:19:24,161 - DEBUG: untagged_responses[RECENT] 0 += ["0"]
2019-12-27 16:19:24,161 - DEBUG: < * FLAGS (\Seen \Answered \Flagged \Deleted \Draft $MDNSent)
2019-12-27 16:19:24,161 - DEBUG: 	matched r'\* (?P<type>[A-Z-]+)( (?P<data>.*))?' => ('FLAGS', ' (\\Seen \\Answered \\Flagged \\Deleted \\Draft $MDNSent)', '(\\Seen \\Answered \\Flagged \\Deleted \\Draft $MDNSent)')
2019-12-27 16:19:24,161 - DEBUG: untagged_responses[FLAGS] 0 += ["(\Seen \Answered \Flagged \Deleted \Draft $MDNSent)"]
2019-12-27 16:19:24,161 - DEBUG: < * OK [PERMANENTFLAGS (\Seen \Answered \Flagged \Deleted \Draft $MDNSent)] Permanent flags
2019-12-27 16:19:24,161 - DEBUG: 	matched r'\* (?P<type>[A-Z-]+)( (?P<data>.*))?' => ('OK', ' [PERMANENTFLAGS (\\Seen \\Answered \\Flagged \\Deleted \\Draft $MDNSent)] Permanent flags', '[PERMANENTFLAGS (\\Seen \\Answered \\Flagged \\Deleted \\Draft $MDNSent)] Permanent flags')
2019-12-27 16:19:24,161 - DEBUG: untagged_responses[OK] 0 += ["[PERMANENTFLAGS (\Seen \Answered \Flagged \Deleted \Draft $MDNSent)] Permanent flags"]
2019-12-27 16:19:24,161 - DEBUG: 	matched r'\[(?P<type>[A-Z-]+)( (?P<data>[^\]]*))?\]' => ('PERMANENTFLAGS', ' (\\Seen \\Answered \\Flagged \\Deleted \\Draft $MDNSent)', '(\\Seen \\Answered \\Flagged \\Deleted \\Draft $MDNSent)')
2019-12-27 16:19:24,162 - DEBUG: untagged_responses[PERMANENTFLAGS] 0 += ["(\Seen \Answered \Flagged \Deleted \Draft $MDNSent)"]
2019-12-27 16:19:24,162 - DEBUG: < * OK [UNSEEN 18206] Is the first unseen message
2019-12-27 16:19:24,162 - DEBUG: 	matched r'\* (?P<type>[A-Z-]+)( (?P<data>.*))?' => ('OK', ' [UNSEEN 18206] Is the first unseen message', '[UNSEEN 18206] Is the first unseen message')
2019-12-27 16:19:24,162 - DEBUG: untagged_responses[OK] 1 += ["[UNSEEN 18206] Is the first unseen message"]
2019-12-27 16:19:24,162 - DEBUG: 	matched r'\[(?P<type>[A-Z-]+)( (?P<data>[^\]]*))?\]' => ('UNSEEN', ' 18206', '18206')
2019-12-27 16:19:24,162 - DEBUG: untagged_responses[UNSEEN] 0 += ["18206"]
2019-12-27 16:19:24,162 - DEBUG: < * OK [UIDVALIDITY 14] UIDVALIDITY value
2019-12-27 16:19:24,162 - DEBUG: 	matched r'\* (?P<type>[A-Z-]+)( (?P<data>.*))?' => ('OK', ' [UIDVALIDITY 14] UIDVALIDITY value', '[UIDVALIDITY 14] UIDVALIDITY value')
2019-12-27 16:19:24,162 - DEBUG: untagged_responses[OK] 2 += ["[UIDVALIDITY 14] UIDVALIDITY value"]
2019-12-27 16:19:24,162 - DEBUG: 	matched r'\[(?P<type>[A-Z-]+)( (?P<data>[^\]]*))?\]' => ('UIDVALIDITY', ' 14', '14')
2019-12-27 16:19:24,163 - DEBUG: untagged_responses[UIDVALIDITY] 0 += ["14"]
2019-12-27 16:19:24,163 - DEBUG: < * OK [UIDNEXT 42260] The next unique identifier value
2019-12-27 16:19:24,163 - DEBUG: 	matched r'\* (?P<type>[A-Z-]+)( (?P<data>.*))?' => ('OK', ' [UIDNEXT 42260] The next unique identifier value', '[UIDNEXT 42260] The next unique identifier value')
2019-12-27 16:19:24,163 - DEBUG: untagged_responses[OK] 3 += ["[UIDNEXT 42260] The next unique identifier value"]
2019-12-27 16:19:24,163 - DEBUG: 	matched r'\[(?P<type>[A-Z-]+)( (?P<data>[^\]]*))?\]' => ('UIDNEXT', ' 42260', '42260')
2019-12-27 16:19:24,163 - DEBUG: untagged_responses[UIDNEXT] 0 += ["42260"]
2019-12-27 16:19:24,163 - DEBUG: < DGGH2 OK [READ-WRITE] SELECT completed.
2019-12-27 16:19:24,163 - DEBUG: 	matched r'(?P<tag>DGGH\d+) (?P<type>[A-Z]+) (?P<data>.*)' => ('DGGH2', 'OK', '[READ-WRITE] SELECT completed.')
2019-12-27 16:19:24,163 - DEBUG: 	matched r'\[(?P<type>[A-Z-]+)( (?P<data>[^\]]*))?\]' => ('READ-WRITE', None, None)
2019-12-27 16:19:24,163 - DEBUG: untagged_responses[READ-WRITE] 0 += [""]
2019-12-27 16:19:24,164 - DEBUG: > DGGH3 UID SEARCH NOT DELETED
2019-12-27 16:19:24,478 - DEBUG: < * SEARCH  42227 42229 42232 42234 42236 42239 42241 42242 42245 42248 42250 42252 42254 42258
2019-12-27 16:19:24,483 - DEBUG: 	matched r'\* (?P<type>[A-Z-]+)( (?P<data>.*))?' => ('SEARCH', ' 211 212 .......  42254 42258', '211 212 213 .......  42254 42258"]
2019-12-27 16:19:24,516 - DEBUG: < DGGH3 OK SEARCH completed.
2019-12-27 16:19:24,516 - DEBUG: 	matched r'(?P<tag>DGGH\d+) (?P<type>[A-Z]+) (?P<data>.*)' => ('DGGH3', 'OK', 'SEARCH completed.')
2019-12-27 16:19:24,517 - DEBUG: untagged_responses[SEARCH] => ['211 212 ........ ,42250,42252,42254,42258 (FLAGS RFC822.SIZE)
2019-12-27 16:19:24,676 - DEBUG: < DGGH4 BAD Command Error. 10
2019-12-27 16:19:24,676 - DEBUG: 	matched r'(?P<tag>DGGH\d+) (?P<type>[A-Z]+) (?P<data>.*)' => ('DGGH4', 'BAD', 'Command Error. 10')
2019-12-27 16:19:24,676 - DEBUG: BAD response: Command Error. 10
2019-12-27 16:19:24,676 - DEBUG: > DGGH5 LOGOUT
2019-12-27 16:19:24,678 - INFO: Could not close the connection cleanly: 'NoneType' object has no attribute 'close'
Traceback (most recent call last):
  File "imappy.py", line 21, in <module>
    response = client.fetch(messages, ['FLAGS', 'RFC822.SIZE'])
  File "/home/mattia/.local/lib/python2.7/site-packages/imapclient/imapclient.py", line 1225, in fetch
    typ, data = self._imap._command_complete('FETCH', tag)
  File "/usr/lib/python2.7/imaplib.py", line 921, in _command_complete
    raise self.error('%s command error: %s %s' % (name, typ, data))
imaplib.error: FETCH command error: BAD ['Command Error. 10']

[mjs]

Sorry for the very slow response.

If this is still an issue for you can you please print what messages looks like before the fetch() call? Something seems wrong there.

[SamirM-BE]

Hello,

This issue is quite old but I still have the same problem as MattiaFailla. The solution that I have found is to limit the number of messages to fetch.

It seems like the maximum limit for Outlook is around 1900 messages.

[MattiaFailla]

Hi everyone, I don't know if any developments have been made regarding this issue, but maybe it would be better to introduce a custom exception in this case. @mjs what do you think?