Outlook 2007 deliberately loses IMAP connection

D

Dezl0ck

I have been playing with IMAP in Outlook 2007 since the beta and in my
opinion it is still broken. I have tested this on several different clients
with unsatisfactory results in Outlook. I have disabled automatic
send/receive in Outlook 2007 and Thunderbird 2.0. FlexMail 2007 for Pocket
PC has this turned off by default.

This is an excerpt from the outlook logs

IMAP: 13:26:17 [rx] + entering idle mode
IMAP: 13:26:17 [tx] DONE
IMAP: 13:26:17 [db] OnNotify: asOld = 5, asNew = 5, ae = 3
IMAP: 13:26:17 [rx] px3s OK IDLE completed
IMAP: 13:26:17 [tx] e5vp LIST "" "INBOX"
IMAP: 13:26:17 [db] OnNotify: asOld = 5, asNew = 5, ae = 3
IMAP: 13:26:17 [rx] * LIST (\Unmarked \HasChildren) "." "INBOX"
IMAP: 13:26:17 [rx] e5vp OK LIST completed
IMAP: 13:26:17 [tx] b98v LSUB "" "*"
IMAP: 13:26:17 [db] OnNotify: asOld = 5, asNew = 5, ae = 3
IMAP: 13:26:17 [rx] * LSUB (\HasNoChildren) "." "INBOX.Sent"
IMAP: 13:26:17 [rx] * LSUB (\Unmarked \HasChildren) "." "INBOX"
IMAP: 13:26:17 [rx] * LSUB (\HasNoChildren) "." "INBOX.Sent Items"
IMAP: 13:26:17 [rx] * LSUB (\HasNoChildren) "." "INBOX.Trash"
IMAP: 13:26:17 [rx] * LSUB (\HasNoChildren) "." "INBOX.UNVERIFIED"
IMAP: 13:26:17 [rx] b98v OK LSUB completed
IMAP: 13:26:17 [tx] zx42 IDLE
IMAP: 13:26:17 [db] OnNotify: asOld = 5, asNew = 5, ae = 3
IMAP: 13:26:17 [rx] + entering idle mode
IMAP: 13:26:51 [tx] Dropping connection, LOGOUT sent
IMAP: 13:26:51 [db] Connection to 'mail.xyz.com' closed.
IMAP: 13:26:51 [db] OnNotify: asOld = 5, asNew = 0, ae = 5

Notice that Outlook sends an IDLE command to the server, the server replies
that it is in IDLE mode, and then Outlook decides to log out of the server
less than 30 seconds later. What is that all about? Outlook never tries to
reconnect to the server. That indicates a defect in the expected behavior
since an IMAP client is meant to keep a connection open to 143/993 at all
times.

Thunderbird 2.0 has been up for 6 hours in my tests without having to do a
send/receive. It is continually connected to port 993 on my mail host.

122420[2c329f0]: 2c3bea8:mail.xyz.com:S-INBOX:processCurrentURL: entering
122420[2c329f0]:
2c3bea8:mail.xyz.com:S-INBOX:processCurrentURL:imap://[email protected]:993/addmsgflags%3EUID%3E.INBOX%3E8856%3E1: = currentUrl
122420[2c329f0]: 2c3bea8:mail.xyz.com:S-INBOX:SendData: 15 uid store 8856
+Flags (\Seen)

122420[2c329f0]: ReadNextLine [stream=2c154b8 nb=36 needmore=0]
122420[2c329f0]: 2c3bea8:mail.xyz.com:S-INBOX:CreateNewLineFromSocket: * 9
FETCH (UID 8856 FLAGS (\Seen))

122420[2c329f0]: ReadNextLine [stream=2c154b8 nb=24 needmore=0]
122420[2c329f0]: 2c3bea8:mail.xyz.com:S-INBOX:CreateNewLineFromSocket: 15 OK
STORE completed.

122420[2c329f0]: 2c3bea8:mail.xyz.com:S-INBOX:SendData: 16 IDLE

122420[2c329f0]: ReadNextLine [stream=2c154b8 nb=22 needmore=0]
122420[2c329f0]: 2c3bea8:mail.xyz.com:S-INBOX:CreateNewLineFromSocket: +
entering idle mode

122420[2c329f0]: 2c3bea8:mail.xyz.com:S-INBOX:SendData: DONE

122420[2c329f0]: ReadNextLine [stream=2c154b8 nb=22 needmore=0]
122420[2c329f0]: 2c3bea8:mail.xyz.com:S-INBOX:CreateNewLineFromSocket: 16 OK
IDLE completed

122420[2c329f0]: 2c3bea8:mail.xyz.com:S-INBOX:processCurrentURL: entering
122420[2c329f0]:
2c3bea8:mail.xyz.com:S-INBOX:processCurrentURL:imap://[email protected]:993/addmsgflags%3EUID%3E.INBOX%3E8856%3E2: = currentUrl
122420[2c329f0]: 2c3bea8:mail.xyz.com:S-INBOX:SendData: 17 uid store 8856
+Flags (\Answered)

122420[2c329f0]: ReadNextLine [stream=2c154b8 nb=46 needmore=0]
122420[2c329f0]: 2c3bea8:mail.xyz.com:S-INBOX:CreateNewLineFromSocket: * 9
FETCH (UID 8856 FLAGS (\Answered \Seen))

122420[2c329f0]: ReadNextLine [stream=2c154b8 nb=24 needmore=0]
122420[2c329f0]: 2c3bea8:mail.xyz.com:S-INBOX:CreateNewLineFromSocket: 17 OK
STORE completed.

122420[2c329f0]: 2c3bea8:mail.xyz.com:S-INBOX:SendData: 18 IDLE

122420[2c329f0]: ReadNextLine [stream=2c154b8 nb=22 needmore=0]
122420[2c329f0]: 2c3bea8:mail.xyz.com:S-INBOX:CreateNewLineFromSocket: +
entering idle mode

Finally my PocketPC IMAP client has been connected during this test for 3
hours using the IDLE command properly.



1322793198 - 2007.4.21 3:46:32 Timeout, reissuing IDLE
1322793198 - 2007.4.21 3:46:32 S DONE
1322793198 - 2007.4.21 3:46:32 R 5 OK IDLE completed
1322793198 - 2007.4.21 3:46:32 S 6 IDLE
1322793198 - 2007.4.21 3:46:33 R + entering idle mode
1322793198 - 2007.4.21 3:46:33 Waiting for IDLE response
1322793198 - 2007.4.21 3:46:33 R :IDLEReceive:Step 1
1322793198 - 2007.4.21 3:46:33 R :IDLEReceive:Step 2
1322793198 - 2007.4.21 3:46:33 R :IDLEReceive:Step 3
1322793198 - 2007.4.21 3:46:33 R :IDLEReceive:Step 4
1322793198 - 2007.4.21 3:46:33 R :IDLEReceive:Step 5
1322793198 - 2007.4.21 3:49:32 R :IDLEReceive:Step 6
1322793198 - 2007.4.21 3:49:32 R :IDLEReceive:Step 7
1322793198 - 2007.4.21 3:49:32 IDLE waiting returned: hStatus = -2134900716
1322793198 - 2007.4.21 3:49:32 Timeout, reissuing IDLE
1322793198 - 2007.4.21 3:49:32 S DONE
1322793198 - 2007.4.21 3:49:33 R 6 OK IDLE completed
1322793198 - 2007.4.21 3:49:33 S 7 IDLE
1322793198 - 2007.4.21 3:49:35 R + entering idle mode
1322793198 - 2007.4.21 3:49:35 Waiting for IDLE response
1322793198 - 2007.4.21 3:49:35 R :IDLEReceive:Step 1
1322793198 - 2007.4.21 3:49:35 R :IDLEReceive:Step 2
1322793198 - 2007.4.21 3:49:35 R :IDLEReceive:Step 3
1322793198 - 2007.4.21 3:49:35 R :IDLEReceive:Step 4
1322793198 - 2007.4.21 3:49:35 R :IDLEReceive:Step 5
1322793198 - 2007.4.21 3:52:35 R :IDLEReceive:Step 6
1322793198 - 2007.4.21 3:52:35 R :IDLEReceive:Step 7
1322793198 - 2007.4.21 3:52:35 IDLE waiting returned: hStatus = -2134900716
1322793198 - 2007.4.21 3:52:35 Timeout, reissuing IDLE
1322793198 - 2007.4.21 3:52:35 S DONE
1322793198 - 2007.4.21 3:52:36 R 7 OK IDLE completed
1322793198 - 2007.4.21 3:52:36 S 8 IDLE
1322793198 - 2007.4.21 3:52:36 R + entering idle mode
1322793198 - 2007.4.21 3:52:36 Waiting for IDLE response
1322793198 - 2007.4.21 3:52:36 R :IDLEReceive:Step 1
1322793198 - 2007.4.21 3:52:37 R :IDLEReceive:Step 2
1322793198 - 2007.4.21 3:52:37 R :IDLEReceive:Step 3
1322793198 - 2007.4.21 3:52:37 R :IDLEReceive:Step 4
1322793198 - 2007.4.21 3:52:37 R :IDLEReceive:Step 5
1322793198 - 2007.4.21 3:55:44 R :IDLEReceive:Step 6
1322793198 - 2007.4.21 3:55:44 R :IDLEReceive:Step 7
1322793198 - 2007.4.21 3:55:44 IDLE waiting returned: hStatus = -2134900716
1322793198 - 2007.4.21 3:55:44 Timeout, reissuing IDLE
1322793198 - 2007.4.21 3:55:44 S DONE

Outlook 2007 does not make proper use of the IDLE command since it logs out
of the server about 30 seconds after the server replies that it is IDLE. I
would expect it to be like these other two well behaved clients that keep the
connection open. I should only see a full synchronize if the open TCP
connection fails. In order to assure that outlook keeps a connection I have
to synchronize on a regular interval which is a waste of CPU and bandwidth,
in addition to not following the specifications for modern IMAP
implementation. I would like to see this registered as a bug with Microsoft
to be corrected when Office SP1 is released.
 
P

Patrick Schmid [MVP]

What IMAP timeout interval have you set?

Patrick Schmid [OneNote MVP]
--------------
http://pschmid.net
***
Outlook 2007 Performance Update: http://pschmid.net/blog/2007/04/13/105
Office 2007 RTM Issues: http://pschmid.net/blog/2006/11/13/80
***
Customize Office 2007: http://pschmid.net/office2007/customize
RibbonCustomizer Add-In: http://pschmid.net/office2007/ribboncustomizer
OneNote 2007: http://pschmid.net/office2007/onenote
***
Subscribe to my Office 2007 blog: http://pschmid.net/blog/feed

I have been playing with IMAP in Outlook 2007 since the beta and in my
opinion it is still broken. I have tested this on several different clients
with unsatisfactory results in Outlook. I have disabled automatic
send/receive in Outlook 2007 and Thunderbird 2.0. FlexMail 2007 for Pocket
PC has this turned off by default.

This is an excerpt from the outlook logs

IMAP: 13:26:17 [rx] + entering idle mode
IMAP: 13:26:17 [tx] DONE
IMAP: 13:26:17 [db] OnNotify: asOld = 5, asNew = 5, ae = 3
IMAP: 13:26:17 [rx] px3s OK IDLE completed
IMAP: 13:26:17 [tx] e5vp LIST "" "INBOX"
IMAP: 13:26:17 [db] OnNotify: asOld = 5, asNew = 5, ae = 3
IMAP: 13:26:17 [rx] * LIST (\Unmarked \HasChildren) "." "INBOX"
IMAP: 13:26:17 [rx] e5vp OK LIST completed
IMAP: 13:26:17 [tx] b98v LSUB "" "*"
IMAP: 13:26:17 [db] OnNotify: asOld = 5, asNew = 5, ae = 3
IMAP: 13:26:17 [rx] * LSUB (\HasNoChildren) "." "INBOX.Sent"
IMAP: 13:26:17 [rx] * LSUB (\Unmarked \HasChildren) "." "INBOX"
IMAP: 13:26:17 [rx] * LSUB (\HasNoChildren) "." "INBOX.Sent Items"
IMAP: 13:26:17 [rx] * LSUB (\HasNoChildren) "." "INBOX.Trash"
IMAP: 13:26:17 [rx] * LSUB (\HasNoChildren) "." "INBOX.UNVERIFIED"
IMAP: 13:26:17 [rx] b98v OK LSUB completed
IMAP: 13:26:17 [tx] zx42 IDLE
IMAP: 13:26:17 [db] OnNotify: asOld = 5, asNew = 5, ae = 3
IMAP: 13:26:17 [rx] + entering idle mode
IMAP: 13:26:51 [tx] Dropping connection, LOGOUT sent
IMAP: 13:26:51 [db] Connection to 'mail.xyz.com' closed.
IMAP: 13:26:51 [db] OnNotify: asOld = 5, asNew = 0, ae = 5

Notice that Outlook sends an IDLE command to the server, the server replies
that it is in IDLE mode, and then Outlook decides to log out of the server
less than 30 seconds later. What is that all about? Outlook never tries to
reconnect to the server. That indicates a defect in the expected behavior
since an IMAP client is meant to keep a connection open to 143/993 at all
times.

Thunderbird 2.0 has been up for 6 hours in my tests without having to do a
send/receive. It is continually connected to port 993 on my mail host.

122420[2c329f0]: 2c3bea8:mail.xyz.com:S-INBOX:processCurrentURL: entering
122420[2c329f0]:
2c3bea8:mail.xyz.com:S-INBOX:processCurrentURL:imap://[email protected]:993/addmsgflags%3EUID%3E.INBOX%3E8856%3E1: = currentUrl
122420[2c329f0]: 2c3bea8:mail.xyz.com:S-INBOX:SendData: 15 uid store 8856
+Flags (\Seen)

122420[2c329f0]: ReadNextLine [stream=2c154b8 nb=36 needmore=0]
122420[2c329f0]: 2c3bea8:mail.xyz.com:S-INBOX:CreateNewLineFromSocket: * 9
FETCH (UID 8856 FLAGS (\Seen))

122420[2c329f0]: ReadNextLine [stream=2c154b8 nb=24 needmore=0]
122420[2c329f0]: 2c3bea8:mail.xyz.com:S-INBOX:CreateNewLineFromSocket: 15 OK
STORE completed.

122420[2c329f0]: 2c3bea8:mail.xyz.com:S-INBOX:SendData: 16 IDLE

122420[2c329f0]: ReadNextLine [stream=2c154b8 nb=22 needmore=0]
122420[2c329f0]: 2c3bea8:mail.xyz.com:S-INBOX:CreateNewLineFromSocket: +
entering idle mode

122420[2c329f0]: 2c3bea8:mail.xyz.com:S-INBOX:SendData: DONE

122420[2c329f0]: ReadNextLine [stream=2c154b8 nb=22 needmore=0]
122420[2c329f0]: 2c3bea8:mail.xyz.com:S-INBOX:CreateNewLineFromSocket: 16 OK
IDLE completed

122420[2c329f0]: 2c3bea8:mail.xyz.com:S-INBOX:processCurrentURL: entering
122420[2c329f0]:
2c3bea8:mail.xyz.com:S-INBOX:processCurrentURL:imap://[email protected]:993/addmsgflags%3EUID%3E.INBOX%3E8856%3E2: = currentUrl
122420[2c329f0]: 2c3bea8:mail.xyz.com:S-INBOX:SendData: 17 uid store 8856
+Flags (\Answered)

122420[2c329f0]: ReadNextLine [stream=2c154b8 nb=46 needmore=0]
122420[2c329f0]: 2c3bea8:mail.xyz.com:S-INBOX:CreateNewLineFromSocket: * 9
FETCH (UID 8856 FLAGS (\Answered \Seen))

122420[2c329f0]: ReadNextLine [stream=2c154b8 nb=24 needmore=0]
122420[2c329f0]: 2c3bea8:mail.xyz.com:S-INBOX:CreateNewLineFromSocket: 17 OK
STORE completed.

122420[2c329f0]: 2c3bea8:mail.xyz.com:S-INBOX:SendData: 18 IDLE

122420[2c329f0]: ReadNextLine [stream=2c154b8 nb=22 needmore=0]
122420[2c329f0]: 2c3bea8:mail.xyz.com:S-INBOX:CreateNewLineFromSocket: +
entering idle mode

Finally my PocketPC IMAP client has been connected during this test for 3
hours using the IDLE command properly.



1322793198 - 2007.4.21 3:46:32 Timeout, reissuing IDLE
1322793198 - 2007.4.21 3:46:32 S DONE
1322793198 - 2007.4.21 3:46:32 R 5 OK IDLE completed
1322793198 - 2007.4.21 3:46:32 S 6 IDLE
1322793198 - 2007.4.21 3:46:33 R + entering idle mode
1322793198 - 2007.4.21 3:46:33 Waiting for IDLE response
1322793198 - 2007.4.21 3:46:33 R :IDLEReceive:Step 1
1322793198 - 2007.4.21 3:46:33 R :IDLEReceive:Step 2
1322793198 - 2007.4.21 3:46:33 R :IDLEReceive:Step 3
1322793198 - 2007.4.21 3:46:33 R :IDLEReceive:Step 4
1322793198 - 2007.4.21 3:46:33 R :IDLEReceive:Step 5
1322793198 - 2007.4.21 3:49:32 R :IDLEReceive:Step 6
1322793198 - 2007.4.21 3:49:32 R :IDLEReceive:Step 7
1322793198 - 2007.4.21 3:49:32 IDLE waiting returned: hStatus = -2134900716
1322793198 - 2007.4.21 3:49:32 Timeout, reissuing IDLE
1322793198 - 2007.4.21 3:49:32 S DONE
1322793198 - 2007.4.21 3:49:33 R 6 OK IDLE completed
1322793198 - 2007.4.21 3:49:33 S 7 IDLE
1322793198 - 2007.4.21 3:49:35 R + entering idle mode
1322793198 - 2007.4.21 3:49:35 Waiting for IDLE response
1322793198 - 2007.4.21 3:49:35 R :IDLEReceive:Step 1
1322793198 - 2007.4.21 3:49:35 R :IDLEReceive:Step 2
1322793198 - 2007.4.21 3:49:35 R :IDLEReceive:Step 3
1322793198 - 2007.4.21 3:49:35 R :IDLEReceive:Step 4
1322793198 - 2007.4.21 3:49:35 R :IDLEReceive:Step 5
1322793198 - 2007.4.21 3:52:35 R :IDLEReceive:Step 6
1322793198 - 2007.4.21 3:52:35 R :IDLEReceive:Step 7
1322793198 - 2007.4.21 3:52:35 IDLE waiting returned: hStatus = -2134900716
1322793198 - 2007.4.21 3:52:35 Timeout, reissuing IDLE
1322793198 - 2007.4.21 3:52:35 S DONE
1322793198 - 2007.4.21 3:52:36 R 7 OK IDLE completed
1322793198 - 2007.4.21 3:52:36 S 8 IDLE
1322793198 - 2007.4.21 3:52:36 R + entering idle mode
1322793198 - 2007.4.21 3:52:36 Waiting for IDLE response
1322793198 - 2007.4.21 3:52:36 R :IDLEReceive:Step 1
1322793198 - 2007.4.21 3:52:37 R :IDLEReceive:Step 2
1322793198 - 2007.4.21 3:52:37 R :IDLEReceive:Step 3
1322793198 - 2007.4.21 3:52:37 R :IDLEReceive:Step 4
1322793198 - 2007.4.21 3:52:37 R :IDLEReceive:Step 5
1322793198 - 2007.4.21 3:55:44 R :IDLEReceive:Step 6
1322793198 - 2007.4.21 3:55:44 R :IDLEReceive:Step 7
1322793198 - 2007.4.21 3:55:44 IDLE waiting returned: hStatus = -2134900716
1322793198 - 2007.4.21 3:55:44 Timeout, reissuing IDLE
1322793198 - 2007.4.21 3:55:44 S DONE

Outlook 2007 does not make proper use of the IDLE command since it logs out
of the server about 30 seconds after the server replies that it is IDLE. I
would expect it to be like these other two well behaved clients that keep the
connection open. I should only see a full synchronize if the open TCP
connection fails. In order to assure that outlook keeps a connection I have
to synchronize on a regular interval which is a waste of CPU and bandwidth,
in addition to not following the specifications for modern IMAP
implementation. I would like to see this registered as a bug with Microsoft
to be corrected when Office SP1 is released.
 
D

Dezl0ck

It was set at 30 seconds and on a hunch I upped it to 3 minutes.

The logs are still showing the approximately the same thing.

IMAP: 01:23:00 [tx] 5h10 IDLE
IMAP: 01:23:00 [db] OnNotify: asOld = 5, asNew = 5, ae = 3
IMAP: 01:23:00 [rx] + entering idle mode
IMAP: 01:23:49 [tx] Dropping connection, LOGOUT sent
IMAP: 01:23:49 [db] Connection to 'mail.xyz.com' closed.
 

Ask a Question

Want to reply to this thread or ask your own question?

You'll need to choose a username for the site, which only take a couple of moments. After that, you can post your question and our members will help you out.

Ask a Question

Top