I have been using getmail over davmail to connect to a Microsoft mailbox. I noticed that IMAP retrieval is very slow, even when there are no new messages. It seems getmail retrieves the entire message body even when it already saw them before (although it detects they were already seen and does not duplicate them in the local mailbox). With an inbox containing 438 messages, all seen, and it takes about 4-6 min for getmail to execute in IMAP, while the POP3 implementation takes a fraction of second. Other IMAP software also took 4-6 min to synchronise the full mailbox, and then a fraction of second to check for new messages.
- fetchmail uses the trick of searching for unread messages only (which is a major limitation of fetchmail, does not keep an independent list of which messages were read)
- thunderbird sends a NOOP to keep connection alive and ask for updates.
Would there be a way to avoid getmail downloading the body of each UID everytime, since it knows which UID have been seen already?
Below the davmail logs (simplified for 2 messages out of 438, the first and the last).
getmail configuration
verbose = 3
read_all = false
delete = false
delete_after = 50
message_log = ~/.getmail/log
recieved = true
delivered = true
#[retriever]
#type = SimplePOP3Retriever
#server = localhost
#username = [email protected]
#password = ********
#port = 1110
[retriever]
type = SimpleIMAPRetriever
server = localhost
username = [email protected]
password = ********
port = 1143
[destination]
type = MDA_external
path = /usr/bin/procmail
arguments = ("-f", "%(sender)", "-m", "~/.procmail/procmail.rc")
getmail / SimplePOP3Retriever
2021-02-21 02:00:42,270 DEBUG [davmail.pop.PopServer] davmail - Connection from /0:0:0:0:0:0:0:1 on port 1110
2021-02-21 02:00:42,270 INFO [davmail.pop.PopServer] davmail.connection - CONNECT - 0:0:0:0:0:0:0:1:47776
2021-02-21 02:00:42,460 DEBUG [PopConnection-47776] davmail.exchange.ExchangeSession - Test configuration status: 401
2021-02-21 02:00:42,460 DEBUG [PopConnection-47776] davmail - > +OK DavMail 5.5.1-3299 POP ready at Sun Feb 21 02:00:42 WET 2021
2021-02-21 02:00:42,460 DEBUG [PopConnection-47776] davmail - < USER [email protected]
2021-02-21 02:00:42,460 DEBUG [PopConnection-47776] davmail - > +OK USER : [email protected]
2021-02-21 02:00:42,460 DEBUG [PopConnection-47776] davmail - < PASS ********
2021-02-21 02:00:42,460 DEBUG [PopConnection-47776] davmail.exchange.ExchangeSession - Got session davmail.exchange.ews.EwsExchangeSession@239cd145 from cache
2021-02-21 02:00:42,508 INFO [PopConnection-47776] davmail.connection - LOGON - 0:0:0:0:0:0:0:1:47776 [email protected]
2021-02-21 02:00:42,508 DEBUG [PopConnection-47776] davmail - > +OK PASS
2021-02-21 02:00:42,508 DEBUG [PopConnection-47776] davmail - < UIDL
2021-02-21 02:00:42,603 DEBUG [PopConnection-47776] davmail - Downloaded 128 KBytes from /ews/exchange.asmx
2021-02-21 02:00:42,626 DEBUG [PopConnection-47776] davmail - Downloaded 256 KBytes from /ews/exchange.asmx
2021-02-21 02:00:42,634 DEBUG [PopConnection-47776] davmail.exchange.ExchangeSession - Folder INBOX - Search items current count: 438 fetchCount: 500 highest uid: 74132 lowest uid: 73170
2021-02-21 02:00:42,636 DEBUG [PopConnection-47776] davmail.exchange.ExchangeSession - Message IMAP uid: 74132 uid: AAAAAJzu0G7W0uhCtiCT9NHNMTIBACDiK+8eQQtEtlMP5JWHh+QAAcBiJP4AAA== ItemId: AAMkADJhMjg5ZWUwLTIwNzctNGQwNS1hOTUwLWJkYzcyZmQ0NWY2MwBGAAAAAACc7tBu1tLoQrYgk/TRzTEyBwBORi0QtGx8RKJz6lAORO9kAAAAAAAOAAAg4ivvHkELRLZTD+SVh4fkAAHAYiT+AAA= ChangeKey: CwAAABYAAAAg4ivvHkELRLZTD+SVh4fkAAG/fmaT
2021-02-21 02:00:42,636 DEBUG [PopConnection-47776] davmail - > +OK 438 messages (243095857 octets)
2021-02-21 02:00:42,636 DEBUG [PopConnection-47776] davmail - > 1 AAAAAJzu0G7W0uhCtiCT9NHNMTIBACDiK+8eQQtEtlMP5JWHh+QAAbqgu4EAAA==
[...]
2021-02-21 02:00:42,639 DEBUG [PopConnection-47776] davmail - > 438 AAAAAJzu0G7W0uhCtiCT9NHNMTIBACDiK+8eQQtEtlMP5JWHh+QAAcBiJP4AAA==
2021-02-21 02:00:42,639 DEBUG [PopConnection-47776] davmail - > .
2021-02-21 02:00:42,679 DEBUG [PopConnection-47776] davmail - < LIST
2021-02-21 02:00:42,679 DEBUG [PopConnection-47776] davmail - > +OK 438 messages (243095857 octets)
2021-02-21 02:00:42,679 DEBUG [PopConnection-47776] davmail - > 1 72188
[...]
2021-02-21 02:00:42,685 DEBUG [PopConnection-47776] davmail - > 438 49233
2021-02-21 02:00:42,685 DEBUG [PopConnection-47776] davmail - > .
2021-02-21 02:00:42,688 DEBUG [PopConnection-47776] davmail - < UIDL
2021-02-21 02:00:42,689 DEBUG [PopConnection-47776] davmail - > +OK 438 messages (243095857 octets)
2021-02-21 02:00:42,689 DEBUG [PopConnection-47776] davmail - > 1 AAAAAJzu0G7W0uhCtiCT9NHNMTIBACDiK+8eQQtEtlMP5JWHh+QAAbqgu4EAAA==
[...]
2021-02-21 02:00:42,693 DEBUG [PopConnection-47776] davmail - > 438 AAAAAJzu0G7W0uhCtiCT9NHNMTIBACDiK+8eQQtEtlMP5JWHh+QAAcBiJP4AAA==
2021-02-21 02:00:42,693 DEBUG [PopConnection-47776] davmail - > .
2021-02-21 02:00:42,694 DEBUG [PopConnection-47776] davmail - < LIST
2021-02-21 02:00:42,694 DEBUG [PopConnection-47776] davmail - > +OK 438 messages (243095857 octets)
2021-02-21 02:00:42,694 DEBUG [PopConnection-47776] davmail - > 1 72188
[...]
2021-02-21 02:00:42,696 DEBUG [PopConnection-47776] davmail - > 438 49233
2021-02-21 02:00:42,696 DEBUG [PopConnection-47776] davmail - > .
2021-02-21 02:00:42,766 DEBUG [PopConnection-47776] davmail - < QUIT
2021-02-21 02:00:42,766 DEBUG [PopConnection-47776] davmail.exchange.ExchangeSession - Delete messages in Trash not modified since Sat Jan 02 02:00:42 WET 2021
2021-02-21 02:00:42,816 DEBUG [PopConnection-47776] davmail - > +OK Bye
2021-02-21 02:00:42,816 INFO [PopConnection-47776] davmail.connection - DISCONNECT - 0:0:0:0:0:0:0:1:47776
Thunderbird IMAP
2021-02-20 23:10:27,853 DEBUG [ImapConnection-38306] davmail - < 8 noop
2021-02-20 23:10:27,909 DEBUG [ImapConnection-38306] davmail - noop on INBOX
2021-02-20 23:10:27,959 DEBUG [ImapConnection-38306] davmail - > 8 OK noop completed
2021-02-20 23:10:27,959 DEBUG [ImapConnection-38306] davmail - < 9 UID fetch 74133:* (FLAGS)
2021-02-20 23:10:28,008 DEBUG [ImapConnection-38306] davmail - > 9 OK UID FETCH completed
Fetchmail IMAP
fetchmail -vvv -f ~/.fetchmailrc
set logfile fetchmail.log
poll localhost protocol IMAP port 1143
user "[email protected]" pass "********" is "USERNAME" preconnect "date >> fetchmail.log"
no ssl
sslproto ''
keep
no rewrite
mda "/usr/bin/procmail -f %F -m ~/.procmail/procmail.rc";
2021-02-21 01:46:27,951 DEBUG [davmail.imap.ImapServer] davmail - Connection from /0:0:0:0:0:0:0:1 on port 1143
2021-02-21 01:46:27,951 INFO [davmail.imap.ImapServer] davmail.connection - CONNECT - 0:0:0:0:0:0:0:1:42112
2021-02-21 01:46:28,135 DEBUG [ImapConnection-42112] davmail.exchange.ExchangeSession - Test configuration status: 401
2021-02-21 01:46:28,135 DEBUG [ImapConnection-42112] davmail - > * OK [CAPABILITY IMAP4REV1 AUTH=LOGIN MOVE SPECIAL-USE] IMAP4rev1 DavMail 5.5.1-3299 server ready
2021-02-21 01:46:28,135 DEBUG [ImapConnection-42112] davmail - < A0001 CAPABILITY
2021-02-21 01:46:28,135 DEBUG [ImapConnection-42112] davmail - > * CAPABILITY IMAP4REV1 AUTH=LOGIN MOVE SPECIAL-USE
2021-02-21 01:46:28,136 DEBUG [ImapConnection-42112] davmail - > A0001 OK CAPABILITY completed
2021-02-21 01:46:28,136 DEBUG [ImapConnection-42112] davmail - < LOGIN ********
2021-02-21 01:46:28,136 DEBUG [ImapConnection-42112] davmail.exchange.ExchangeSession - Got session davmail.exchange.ews.EwsExchangeSession@239cd145 from cache
2021-02-21 01:46:28,320 INFO [ImapConnection-42112] davmail.connection - LOGON - 0:0:0:0:0:0:0:1:42112 [email protected]
2021-02-21 01:46:28,320 DEBUG [ImapConnection-42112] davmail - > A0002 OK Authenticated
2021-02-21 01:46:28,320 DEBUG [ImapConnection-42112] davmail - < A0003 SELECT "INBOX"
2021-02-21 01:46:28,528 DEBUG [ImapConnection-42112] davmail - Downloaded 128 KBytes from /ews/exchange.asmx
2021-02-21 01:46:28,548 DEBUG [ImapConnection-42112] davmail - Downloaded 256 KBytes from /ews/exchange.asmx
2021-02-21 01:46:28,568 DEBUG [ImapConnection-42112] davmail - Downloaded 384 KBytes from /ews/exchange.asmx
2021-02-21 01:46:28,585 DEBUG [ImapConnection-42112] davmail.exchange.ExchangeSession - Folder INBOX - Search items current count: 438 fetchCount: 500 highest uid: 74132 lowest uid: 73170
[...]
2021-02-21 01:46:28,585 DEBUG [ImapConnection-42112] davmail.exchange.ExchangeSession - Message IMAP uid: 73170 uid: AAAAAJzu0G7W0uhCtiCT9NHNMTIBACDiK+8eQQtEtlMP5JWHh+QAAbqgu4EAAA== ItemId: AAMkADJhMjg5ZWUwLTIwNzctNGQwNS1hOTUwLWJkYzcyZmQ0NWY2MwBGAAAAAACc7tBu1tLoQrYgk/TRzTEyBwBORi0QtGx8RKJz6lAORO9kAAAAAAAOAAAg4ivvHkELRLZTD+SVh4fkAAG6oLuBAAA= ChangeKey: CQAAABYAAAAg4ivvHkELRLZTD+SVh4fkAAG5v7lm
2021-02-21 01:46:28,587 DEBUG [ImapConnection-42112] davmail.exchange.ExchangeSession - Message IMAP uid: 74132 uid: AAAAAJzu0G7W0uhCtiCT9NHNMTIBACDiK+8eQQtEtlMP5JWHh+QAAcBiJP4AAA== ItemId: AAMkADJhMjg5ZWUwLTIwNzctNGQwNS1hOTUwLWJkYzcyZmQ0NWY2MwBGAAAAAACc7tBu1tLoQrYgk/TRzTEyBwBORi0QtGx8RKJz6lAORO9kAAAAAAAOAAAg4ivvHkELRLZTD+SVh4fkAAHAYiT+AAA= ChangeKey: CwAAABYAAAAg4ivvHkELRLZTD+SVh4fkAAG/fmaT
2021-02-21 01:46:28,588 DEBUG [ImapConnection-42112] davmail - > * 438 EXISTS
2021-02-21 01:46:28,588 DEBUG [ImapConnection-42112] davmail - > * 0 RECENT
2021-02-21 01:46:28,588 DEBUG [ImapConnection-42112] davmail - > * OK [UIDVALIDITY 1]
2021-02-21 01:46:28,588 DEBUG [ImapConnection-42112] davmail - > * OK [UIDNEXT 74134]
2021-02-21 01:46:28,588 DEBUG [ImapConnection-42112] davmail - > * FLAGS (\Answered \Deleted \Draft \Flagged \Seen $Forwarded Junk)
2021-02-21 01:46:28,588 DEBUG [ImapConnection-42112] davmail - > * OK [PERMANENTFLAGS (\Answered \Deleted \Draft \Flagged \Seen $Forwarded Junk \*)]
2021-02-21 01:46:28,588 DEBUG [ImapConnection-42112] davmail - > A0003 OK [READ-WRITE] SELECT completed
2021-02-21 01:46:28,588 DEBUG [ImapConnection-42112] davmail - < A0004 SEARCH UNSEEN UNDELETED
2021-02-21 01:46:28,762 DEBUG [ImapConnection-42112] davmail - > * SEARCH
2021-02-21 01:46:28,762 DEBUG [ImapConnection-42112] davmail - > A0004 OK SEARCH completed
2021-02-21 01:46:28,804 DEBUG [ImapConnection-42112] davmail - < A0005 LOGOUT
2021-02-21 01:46:28,804 DEBUG [ImapConnection-42112] davmail - > * BYE Closing connection
2021-02-21 01:46:28,804 DEBUG [ImapConnection-42112] davmail - > A0005 OK LOGOUT completed
2021-02-21 01:46:28,804 INFO [ImapConnection-42112] davmail.connection - DISCONNECT - 0:0:0:0:0:0:0:1:42112
getmail IMAP
2021-02-21 01:23:57,027 DEBUG [davmail.imap.ImapServer] davmail - Connection from /0:0:0:0:0:0:0:1 on port 1143
2021-02-21 01:23:57,027 INFO [davmail.imap.ImapServer] davmail.connection - CONNECT - 0:0:0:0:0:0:0:1:41838
2021-02-21 01:23:57,218 DEBUG [ImapConnection-41838] davmail.exchange.ExchangeSession - Test configuration status: 401
2021-02-21 01:23:57,219 DEBUG [ImapConnection-41838] davmail - > * OK [CAPABILITY IMAP4REV1 AUTH=LOGIN MOVE SPECIAL-USE] IMAP4rev1 DavMail 5.5.1-3299 server ready
2021-02-21 01:23:57,219 DEBUG [ImapConnection-41838] davmail - < PPPN0 CAPABILITY
2021-02-21 01:23:57,219 DEBUG [ImapConnection-41838] davmail - > * CAPABILITY IMAP4REV1 AUTH=LOGIN MOVE SPECIAL-USE
2021-02-21 01:23:57,219 DEBUG [ImapConnection-41838] davmail - > PPPN0 OK CAPABILITY completed
2021-02-21 01:23:57,220 DEBUG [ImapConnection-41838] davmail - < LOGIN ********
2021-02-21 01:23:57,220 DEBUG [ImapConnection-41838] davmail.exchange.ExchangeSession - Got session davmail.exchange.ews.EwsExchangeSession@239cd145 from cache
2021-02-21 01:23:57,267 INFO [ImapConnection-41838] davmail.connection - LOGON - 0:0:0:0:0:0:0:1:41838 [email protected]
2021-02-21 01:23:57,267 DEBUG [ImapConnection-41838] davmail - > PPPN1 OK Authenticated
2021-02-21 01:23:57,267 DEBUG [ImapConnection-41838] davmail - < PPPN2 CAPABILITY
2021-02-21 01:23:57,267 DEBUG [ImapConnection-41838] davmail - > * CAPABILITY IMAP4REV1 AUTH=LOGIN MOVE SPECIAL-USE
2021-02-21 01:23:57,267 DEBUG [ImapConnection-41838] davmail - > PPPN2 OK CAPABILITY completed
2021-02-21 01:23:57,269 DEBUG [ImapConnection-41838] davmail - < PPPN3 SELECT INBOX
2021-02-21 01:23:57,495 DEBUG [ImapConnection-41838] davmail - Downloaded 128 KBytes from /ews/exchange.asmx
2021-02-21 01:23:57,524 DEBUG [ImapConnection-41838] davmail - Downloaded 256 KBytes from /ews/exchange.asmx
2021-02-21 01:23:57,554 DEBUG [ImapConnection-41838] davmail - Downloaded 385 KBytes from /ews/exchange.asmx
2021-02-21 01:23:57,578 DEBUG [ImapConnection-41838] davmail.exchange.ExchangeSession - Folder INBOX - Search items current count: 438 fetchCount: 500 highest uid: 74132 lowest uid: 73170
2021-02-21 01:23:57,578 DEBUG [ImapConnection-41838] davmail.exchange.ExchangeSession - Message IMAP uid: 73170 uid: AAAAAJzu0G7W0uhCtiCT9NHNMTIBACDiK+8eQQtEtlMP5JWHh+QAAbqgu4EAAA== ItemId: AAMkADJhMjg5ZWUwLTIwNzctNGQwNS1hOTUwLWJkYzcyZmQ0NWY2MwBGAAAAAACc7tBu1tLoQrYgk/TRzTEyBwBORi0QtGx8RKJz6lAORO9kAAAAAAAOAAAg4ivvHkELRLZTD+SVh4fkAAG6oLuBAAA= ChangeKey: CQAAABYAAAAg4ivvHkELRLZTD+SVh4fkAAG5v7lm
2021-02-21 01:23:57,580 DEBUG [ImapConnection-41838] davmail.exchange.ExchangeSession - Message IMAP uid: 74132 uid: AAAAAJzu0G7W0uhCtiCT9NHNMTIBACDiK+8eQQtEtlMP5JWHh+QAAcBiJP4AAA== ItemId: AAMkADJhMjg5ZWUwLTIwNzctNGQwNS1hOTUwLWJkYzcyZmQ0NWY2MwBGAAAAAACc7tBu1tLoQrYgk/TRzTEyBwBORi0QtGx8RKJz6lAORO9kAAAAAAAOAAAg4ivvHkELRLZTD+SVh4fkAAHAYiT+AAA= ChangeKey: CwAAABYAAAAg4ivvHkELRLZTD+SVh4fkAAG/fmaT
2021-02-21 01:23:57,581 DEBUG [ImapConnection-41838] davmail - > * 438 EXISTS
2021-02-21 01:23:57,581 DEBUG [ImapConnection-41838] davmail - > * 37 RECENT
2021-02-21 01:23:57,581 DEBUG [ImapConnection-41838] davmail - > * OK [UIDVALIDITY 1]
2021-02-21 01:23:57,581 DEBUG [ImapConnection-41838] davmail - > * OK [UIDNEXT 74134]
2021-02-21 01:23:57,581 DEBUG [ImapConnection-41838] davmail - > * FLAGS (\Answered \Deleted \Draft \Flagged \Seen $Forwarded Junk)
2021-02-21 01:23:57,581 DEBUG [ImapConnection-41838] davmail - > * OK [PERMANENTFLAGS (\Answered \Deleted \Draft \Flagged \Seen $Forwarded Junk \*)]
2021-02-21 01:23:57,581 DEBUG [ImapConnection-41838] davmail - > PPPN3 OK [READ-WRITE] SELECT completed
2021-02-21 01:23:57,625 DEBUG [ImapConnection-41838] davmail - < PPPN4 FETCH 1:438 (UID RFC822.SIZE)
2021-02-21 01:23:57,673 DEBUG [ImapConnection-41838] davmail.imap.ImapConnection - * 1 FETCH (UID 73170
2021-02-21 01:23:57,757 DEBUG [ImapConnection-41838] davmail.exchange.ExchangeSession - Downloaded full message content for IMAP UID 73170 (12399 bytes)
2021-02-21 01:23:57,757 DEBUG [ImapConnection-41838] davmail - > RFC822.SIZE 12399)
2021-02-21 01:24:02,732 DEBUG [ImapConnection-41838] davmail.exchange.MessageLoadThread - Load large message 5035KB uid AAAAAJzu0G7W0uhCtiCT9NHNMTIBACDiK+8eQQtEtlMP5JWHh+QAAbqgu6UAAA== imapUid 73252 in a separate thread
2021-02-21 01:24:03,075 DEBUG [ImapConnection-41838-LoadMessage] davmail - Downloaded 128 KBytes from /ews/exchange.asmx
2021-02-21 01:24:07,810 DEBUG [ImapConnection-41838] davmail.exchange.MessageLoadThread - Still loading uid AAAAAJzu0G7W0uhCtiCT9NHNMTIBACDiK+8eQQtEtlMP5JWHh+QAAbqgu6UAAA== imapUid 73252
[...]
2021-02-21 01:27:36,402 DEBUG [ImapConnection-41838-LoadMessage] davmail - Downloaded 7175 KBytes from /ews/exchange.asmx
2021-02-21 01:27:37,135 DEBUG [ImapConnection-41838] davmail.imap.ImapConnection - * 438 FETCH (UID 74132
2021-02-21 01:27:37,203 DEBUG [ImapConnection-41838] davmail.exchange.ExchangeSession - Downloaded full message content for IMAP UID 74132 (14731 bytes)
2021-02-21 01:27:37,203 DEBUG [ImapConnection-41838] davmail - > RFC822.SIZE 14731)
2021-02-21 01:27:37,203 DEBUG [ImapConnection-41838] davmail - > PPPN4 OK FETCH completed
2021-02-21 01:27:37,243 DEBUG [ImapConnection-41838] davmail - < PPPN5 CLOSE
2021-02-21 01:27:37,296 DEBUG [ImapConnection-41838] davmail - > PPPN5 OK CLOSE completed
2021-02-21 01:27:37,305 DEBUG [ImapConnection-41838] davmail - < PPPN6 LOGOUT
2021-02-21 01:27:37,305 DEBUG [ImapConnection-41838] davmail - > * BYE Closing connection
2021-02-21 01:27:37,305 DEBUG [ImapConnection-41838] davmail - > PPPN6 OK LOGOUT completed
2021-02-21 01:27:37,305 INFO [ImapConnection-41838] davmail.connection - DISCONNECT - 0:0:0:0:0:0:0:1:41838