thr3ads.net - dovecot - [Dovecot] 2.0beta4 doesn't respond to DONE after untagged FETCH during IDLE [Apr 2010]

If this information is useful, please help other people find it:
Share via:

Daniel I. Applebaum

2010-Apr-16 13:39 UTC

[Dovecot] 2.0beta4 doesn't respond to DONE after untagged FETCH during IDLE

Using K-9 Mail to IDLE on a test folder "MyIncTmp".  When there is a 
flag change on a message in the folder, which generates an untagged 
FETCH, K-9 Mail responds with a DONE, but dovecot does not exit IDLE 
state (LOG 1).  However, if a new message is delivered, generating an 
untagged EXISTS, K-9 Mail responds the same way, with a DONE, and 
dovecot does exit IDLE state. (LOG 2)  You can also see in LOG 1 that 
the "OK Still here" continues to be sent, corroborating that dovecot
is
still in IDLE state.

I hope this information is helpful.

Sincerely,
Dan.


LOG 1: failure to exit IDLE after untagged FETCH
04-16 08:25:48.911: VERBOSE/k9(10160): Sending IMAP command IDLE on 
connection conn1127686952
04-16 08:25:48.921: VERBOSE/k9(10160): conn1127686952>>> 13 IDLE
04-16 08:25:48.921: VERBOSE/k9(10160): Sent IMAP command IDLE with tag 
13 for conn1127686952
04-16 08:25:49.191: VERBOSE/k9(10160): <<< #+# [idling]
04-16 08:25:49.201: VERBOSE/k9(10160): conn1127686952<<<#+# [idling]
04-16 08:25:49.201: VERBOSE/k9(10160): Got async response: #+# [idling]
04-16 08:25:49.201: DEBUG/k9(10160): Idling 
dantest:MyIncTmp/Thread-24/conn1127686952
04-16 08:25:49.201: DEBUG/k9(10160): Considering releasing WakeLock for 
Pushing
04-16 08:25:49.201: DEBUG/k9(10160): Releasing WakeLock for Pushing for 
thread Thread-24
04-16 08:25:54.491: VERBOSE/k9(10160): <<< #null# [16, FETCH, [FLAGS, 
[\Seen, \Recent]]]
04-16 08:25:54.491: VERBOSE/k9(10160): conn1127686952<<<#null# [16, 
FETCH, [FLAGS, [\Seen, \Recent]]]
04-16 08:25:54.491: VERBOSE/k9(10160): Got async response: #null# [16, 
FETCH, [FLAGS, [\Seen, \Recent]]]
04-16 08:25:54.501: DEBUG/k9(10160): Acquired WakeLock for Pushing for 
thread Thread-24
04-16 08:25:54.501: DEBUG/k9(10160): Got useful async untagged response: 
#null# [16, FETCH, [FLAGS, [\Seen, \Recent]]] for 
dantest:MyIncTmp/Thread-24/conn1127686952
04-16 08:25:54.501: VERBOSE/k9(10160): conn1127686952>>> DONE
04-16 08:26:54.571: DEBUG/k9(10160): Acquired WakeLock for Pushing for 
thread Thread-24
04-16 08:26:54.581: ERROR/k9(10160): Error 'Read timed out'
04-16 08:26:54.581: ERROR/k9(10160): java.net.SocketTimeoutException: 
Read timed out
04-16 08:27:00.141: VERBOSE/k9(10160): Sending IMAP command NOOP on 
connection conn1127686952
04-16 08:27:00.141: VERBOSE/k9(10160): conn1127686952>>> 14 NOOP
04-16 08:27:00.141: VERBOSE/k9(10160): Sent IMAP command NOOP with tag 
14 for conn1127686952
04-16 08:27:26.651: VERBOSE/k9(10160): conn1127686952<<<#null# [OK, 
Still, here]


LOG 2: successful exit from IDLE after untagged EXISTS
04-16 08:28:35.271: INFO/k9(10160): About to IDLE for 
dantest:MyIncTmp/Thread-24/conn1126759992
04-16 08:28:35.271: VERBOSE/k9(10160): Sending IMAP command IDLE on 
connection conn1126759992
04-16 08:28:35.281: VERBOSE/k9(10160): conn1126759992>>> 10 IDLE
04-16 08:28:35.281: VERBOSE/k9(10160): Sent IMAP command IDLE with tag 
10 for conn1126759992
04-16 08:28:35.531: VERBOSE/k9(10160): <<< #+# [idling]
04-16 08:28:35.531: VERBOSE/k9(10160): conn1126759992<<<#+# [idling]
04-16 08:28:35.531: VERBOSE/k9(10160): Got async response: #+# [idling]
04-16 08:28:35.531: DEBUG/k9(10160): Idling 
dantest:MyIncTmp/Thread-24/conn1126759992
04-16 08:28:35.531: DEBUG/k9(10160): Considering releasing WakeLock for 
Pushing
04-16 08:28:35.531: DEBUG/k9(10160): Releasing WakeLock for Pushing for 
thread Thread-24
04-16 08:28:51.621: VERBOSE/k9(10160): <<< #null# [18, EXISTS]
04-16 08:28:51.621: VERBOSE/k9(10160): conn1126759992<<<#null# [18,
EXISTS]
04-16 08:28:51.621: VERBOSE/k9(10160): Got async response: #null# [18, 
EXISTS]
04-16 08:28:51.621: DEBUG/k9(10160): Acquired WakeLock for Pushing for 
thread Thread-24
04-16 08:28:51.631: DEBUG/k9(10160): Got useful async untagged response: 
#null# [18, EXISTS] for dantest:MyIncTmp/Thread-24/conn1126759992
04-16 08:28:51.631: VERBOSE/k9(10160): conn1126759992>>> DONE
04-16 08:28:51.631: VERBOSE/k9(10160): <<< #null# [1, RECENT]
04-16 08:28:51.631: VERBOSE/k9(10160): conn1126759992<<<#null# [1,
RECENT]
04-16 08:28:51.631: VERBOSE/k9(10160): Got async response: #null# [1, 
RECENT]
04-16 08:28:51.901: VERBOSE/k9(10160): <<< #10# [OK, Idle, completed.]
04-16 08:28:51.901: VERBOSE/k9(10160): conn1126759992<<<#10# [OK, Idle,
completed.]
04-16 08:28:51.901: VERBOSE/k9(10160): Got async response: #10# [OK, 
Idle, completed.]

Daniel I. Applebaum

2010-Apr-16 13:56 UTC

head link

[Dovecot] RETRACT: Re: 2.0beta4 doesn't respond to DONE after untagged FETCH during IDLE

Having applied Timo's patch to my "OK Still here" problem and
removing
mine, I am no longer having the problem with exiting IDLE after 
receiving an untagged FETCH.  I'm not sure how the two are related, but 
for whatever reason, this problem isn't happening anymore.  If it 
happens again, I'll raise the issue again.  In the meantime, I have no 
reason to believe it a problem with 2.0beta4.

Sorry for the confusion.

Dan.



Daniel I. Applebaum wrote:> Using K-9 Mail to IDLE on a test folder "MyIncTmp".  When there
is a
> flag change on a message in the folder, which generates an untagged 
> FETCH, K-9 Mail responds with a DONE, but dovecot does not exit IDLE 
> state (LOG 1).  However, if a new message is delivered, generating an 
> untagged EXISTS, K-9 Mail responds the same way, with a DONE, and 
> dovecot does exit IDLE state. (LOG 2)  You can also see in LOG 1 that 
> the "OK Still here" continues to be sent, corroborating that
dovecot is
> still in IDLE state.
> 
> I hope this information is helpful.
> 
> Sincerely,
> Dan.
> 
> 
> LOG 1: failure to exit IDLE after untagged FETCH
> 04-16 08:25:48.911: VERBOSE/k9(10160): Sending IMAP command IDLE on 
> connection conn1127686952
> 04-16 08:25:48.921: VERBOSE/k9(10160): conn1127686952>>> 13 IDLE
> 04-16 08:25:48.921: VERBOSE/k9(10160): Sent IMAP command IDLE with tag 
> 13 for conn1127686952
> 04-16 08:25:49.191: VERBOSE/k9(10160): <<< #+# [idling]
> 04-16 08:25:49.201: VERBOSE/k9(10160): conn1127686952<<<#+#
[idling]
> 04-16 08:25:49.201: VERBOSE/k9(10160): Got async response: #+# [idling]
> 04-16 08:25:49.201: DEBUG/k9(10160): Idling 
> dantest:MyIncTmp/Thread-24/conn1127686952
> 04-16 08:25:49.201: DEBUG/k9(10160): Considering releasing WakeLock for 
> Pushing
> 04-16 08:25:49.201: DEBUG/k9(10160): Releasing WakeLock for Pushing for 
> thread Thread-24
> 04-16 08:25:54.491: VERBOSE/k9(10160): <<< #null# [16, FETCH,
[FLAGS,
> [\Seen, \Recent]]]
> 04-16 08:25:54.491: VERBOSE/k9(10160): conn1127686952<<<#null#
[16,
> FETCH, [FLAGS, [\Seen, \Recent]]]
> 04-16 08:25:54.491: VERBOSE/k9(10160): Got async response: #null# [16, 
> FETCH, [FLAGS, [\Seen, \Recent]]]
> 04-16 08:25:54.501: DEBUG/k9(10160): Acquired WakeLock for Pushing for 
> thread Thread-24
> 04-16 08:25:54.501: DEBUG/k9(10160): Got useful async untagged response: 
> #null# [16, FETCH, [FLAGS, [\Seen, \Recent]]] for 
> dantest:MyIncTmp/Thread-24/conn1127686952
> 04-16 08:25:54.501: VERBOSE/k9(10160): conn1127686952>>> DONE
> 04-16 08:26:54.571: DEBUG/k9(10160): Acquired WakeLock for Pushing for 
> thread Thread-24
> 04-16 08:26:54.581: ERROR/k9(10160): Error 'Read timed out'
> 04-16 08:26:54.581: ERROR/k9(10160): java.net.SocketTimeoutException: 
> Read timed out
> 04-16 08:27:00.141: VERBOSE/k9(10160): Sending IMAP command NOOP on 
> connection conn1127686952
> 04-16 08:27:00.141: VERBOSE/k9(10160): conn1127686952>>> 14 NOOP
> 04-16 08:27:00.141: VERBOSE/k9(10160): Sent IMAP command NOOP with tag 
> 14 for conn1127686952
> 04-16 08:27:26.651: VERBOSE/k9(10160): conn1127686952<<<#null#
[OK,
> Still, here]
> 
> 
> LOG 2: successful exit from IDLE after untagged EXISTS
> 04-16 08:28:35.271: INFO/k9(10160): About to IDLE for 
> dantest:MyIncTmp/Thread-24/conn1126759992
> 04-16 08:28:35.271: VERBOSE/k9(10160): Sending IMAP command IDLE on 
> connection conn1126759992
> 04-16 08:28:35.281: VERBOSE/k9(10160): conn1126759992>>> 10 IDLE
> 04-16 08:28:35.281: VERBOSE/k9(10160): Sent IMAP command IDLE with tag 
> 10 for conn1126759992
> 04-16 08:28:35.531: VERBOSE/k9(10160): <<< #+# [idling]
> 04-16 08:28:35.531: VERBOSE/k9(10160): conn1126759992<<<#+#
[idling]
> 04-16 08:28:35.531: VERBOSE/k9(10160): Got async response: #+# [idling]
> 04-16 08:28:35.531: DEBUG/k9(10160): Idling 
> dantest:MyIncTmp/Thread-24/conn1126759992
> 04-16 08:28:35.531: DEBUG/k9(10160): Considering releasing WakeLock for 
> Pushing
> 04-16 08:28:35.531: DEBUG/k9(10160): Releasing WakeLock for Pushing for 
> thread Thread-24
> 04-16 08:28:51.621: VERBOSE/k9(10160): <<< #null# [18, EXISTS]
> 04-16 08:28:51.621: VERBOSE/k9(10160): conn1126759992<<<#null#
[18, EXISTS]
> 04-16 08:28:51.621: VERBOSE/k9(10160): Got async response: #null# [18, 
> EXISTS]
> 04-16 08:28:51.621: DEBUG/k9(10160): Acquired WakeLock for Pushing for 
> thread Thread-24
> 04-16 08:28:51.631: DEBUG/k9(10160): Got useful async untagged response: 
> #null# [18, EXISTS] for dantest:MyIncTmp/Thread-24/conn1126759992
> 04-16 08:28:51.631: VERBOSE/k9(10160): conn1126759992>>> DONE
> 04-16 08:28:51.631: VERBOSE/k9(10160): <<< #null# [1, RECENT]
> 04-16 08:28:51.631: VERBOSE/k9(10160): conn1126759992<<<#null# [1,
RECENT]
> 04-16 08:28:51.631: VERBOSE/k9(10160): Got async response: #null# [1, 
> RECENT]
> 04-16 08:28:51.901: VERBOSE/k9(10160): <<< #10# [OK, Idle,
completed.]
> 04-16 08:28:51.901: VERBOSE/k9(10160): conn1126759992<<<#10# [OK,
Idle,
> completed.]
> 04-16 08:28:51.901: VERBOSE/k9(10160): Got async response: #10# [OK, 
> Idle, completed.]
> 
>

Daniel I. Applebaum

2010-Apr-16 14:38 UTC

head link

[Dovecot] RETRACT: Re: 2.0beta4 doesn't respond to DONE after untagged FETCH during IDLE

Having applied Timo's patch to my "OK Still here" problem and
removing
mine, I am no longer having the problem with exiting IDLE after
receiving an untagged FETCH.  I'm not sure how the two are related, but
for whatever reason, this problem isn't happening anymore.  If it
happens again, I'll raise the issue again.  In the meantime, I have no
reason to believe it a problem with 2.0beta4.

Sorry for the confusion.

Dan.



Daniel I. Applebaum wrote:> Using K-9 Mail to IDLE on a test folder "MyIncTmp".  When there
is a
> flag change on a message in the folder, which generates an untagged 
> FETCH, K-9 Mail responds with a DONE, but dovecot does not exit IDLE 
> state (LOG 1).  However, if a new message is delivered, generating an 
> untagged EXISTS, K-9 Mail responds the same way, with a DONE, and 
> dovecot does exit IDLE state. (LOG 2)  You can also see in LOG 1 that 
> the "OK Still here" continues to be sent, corroborating that
dovecot is
> still in IDLE state.
> 
> I hope this information is helpful.
> 
> Sincerely,
> Dan.
> 
> 
> LOG 1: failure to exit IDLE after untagged FETCH
> 04-16 08:25:48.911: VERBOSE/k9(10160): Sending IMAP command IDLE on 
> connection conn1127686952
> 04-16 08:25:48.921: VERBOSE/k9(10160): conn1127686952>>> 13 IDLE
> 04-16 08:25:48.921: VERBOSE/k9(10160): Sent IMAP command IDLE with tag 
> 13 for conn1127686952
> 04-16 08:25:49.191: VERBOSE/k9(10160): <<< #+# [idling]
> 04-16 08:25:49.201: VERBOSE/k9(10160): conn1127686952<<<#+#
[idling]
> 04-16 08:25:49.201: VERBOSE/k9(10160): Got async response: #+# [idling]
> 04-16 08:25:49.201: DEBUG/k9(10160): Idling 
> dantest:MyIncTmp/Thread-24/conn1127686952
> 04-16 08:25:49.201: DEBUG/k9(10160): Considering releasing WakeLock for 
> Pushing
> 04-16 08:25:49.201: DEBUG/k9(10160): Releasing WakeLock for Pushing for 
> thread Thread-24
> 04-16 08:25:54.491: VERBOSE/k9(10160): <<< #null# [16, FETCH,
[FLAGS,
> [\Seen, \Recent]]]
> 04-16 08:25:54.491: VERBOSE/k9(10160): conn1127686952<<<#null#
[16,
> FETCH, [FLAGS, [\Seen, \Recent]]]
> 04-16 08:25:54.491: VERBOSE/k9(10160): Got async response: #null# [16, 
> FETCH, [FLAGS, [\Seen, \Recent]]]
> 04-16 08:25:54.501: DEBUG/k9(10160): Acquired WakeLock for Pushing for 
> thread Thread-24
> 04-16 08:25:54.501: DEBUG/k9(10160): Got useful async untagged response: 
> #null# [16, FETCH, [FLAGS, [\Seen, \Recent]]] for 
> dantest:MyIncTmp/Thread-24/conn1127686952
> 04-16 08:25:54.501: VERBOSE/k9(10160): conn1127686952>>> DONE
> 04-16 08:26:54.571: DEBUG/k9(10160): Acquired WakeLock for Pushing for 
> thread Thread-24
> 04-16 08:26:54.581: ERROR/k9(10160): Error 'Read timed out'
> 04-16 08:26:54.581: ERROR/k9(10160): java.net.SocketTimeoutException: 
> Read timed out
> 04-16 08:27:00.141: VERBOSE/k9(10160): Sending IMAP command NOOP on 
> connection conn1127686952
> 04-16 08:27:00.141: VERBOSE/k9(10160): conn1127686952>>> 14 NOOP
> 04-16 08:27:00.141: VERBOSE/k9(10160): Sent IMAP command NOOP with tag 
> 14 for conn1127686952
> 04-16 08:27:26.651: VERBOSE/k9(10160): conn1127686952<<<#null#
[OK,
> Still, here]
> 
> 
> LOG 2: successful exit from IDLE after untagged EXISTS
> 04-16 08:28:35.271: INFO/k9(10160): About to IDLE for 
> dantest:MyIncTmp/Thread-24/conn1126759992
> 04-16 08:28:35.271: VERBOSE/k9(10160): Sending IMAP command IDLE on 
> connection conn1126759992
> 04-16 08:28:35.281: VERBOSE/k9(10160): conn1126759992>>> 10 IDLE
> 04-16 08:28:35.281: VERBOSE/k9(10160): Sent IMAP command IDLE with tag 
> 10 for conn1126759992
> 04-16 08:28:35.531: VERBOSE/k9(10160): <<< #+# [idling]
> 04-16 08:28:35.531: VERBOSE/k9(10160): conn1126759992<<<#+#
[idling]
> 04-16 08:28:35.531: VERBOSE/k9(10160): Got async response: #+# [idling]
> 04-16 08:28:35.531: DEBUG/k9(10160): Idling 
> dantest:MyIncTmp/Thread-24/conn1126759992
> 04-16 08:28:35.531: DEBUG/k9(10160): Considering releasing WakeLock for 
> Pushing
> 04-16 08:28:35.531: DEBUG/k9(10160): Releasing WakeLock for Pushing for 
> thread Thread-24
> 04-16 08:28:51.621: VERBOSE/k9(10160): <<< #null# [18, EXISTS]
> 04-16 08:28:51.621: VERBOSE/k9(10160): conn1126759992<<<#null#
[18, EXISTS]
> 04-16 08:28:51.621: VERBOSE/k9(10160): Got async response: #null# [18, 
> EXISTS]
> 04-16 08:28:51.621: DEBUG/k9(10160): Acquired WakeLock for Pushing for 
> thread Thread-24
> 04-16 08:28:51.631: DEBUG/k9(10160): Got useful async untagged response: 
> #null# [18, EXISTS] for dantest:MyIncTmp/Thread-24/conn1126759992
> 04-16 08:28:51.631: VERBOSE/k9(10160): conn1126759992>>> DONE
> 04-16 08:28:51.631: VERBOSE/k9(10160): <<< #null# [1, RECENT]
> 04-16 08:28:51.631: VERBOSE/k9(10160): conn1126759992<<<#null# [1,
RECENT]
> 04-16 08:28:51.631: VERBOSE/k9(10160): Got async response: #null# [1, 
> RECENT]
> 04-16 08:28:51.901: VERBOSE/k9(10160): <<< #10# [OK, Idle,
completed.]
> 04-16 08:28:51.901: VERBOSE/k9(10160): conn1126759992<<<#10# [OK,
Idle,
> completed.]
> 04-16 08:28:51.901: VERBOSE/k9(10160): Got async response: #10# [OK, 
> Idle, completed.]
> 
>

Reasonably Related Threads

Search for more seemingly similar threads

dovecot - Apr 2010 - 2.0beta4 doesn't respond to DONE after untagged FETCH during IDLE

[Dovecot] 2.0beta4 doesn't respond to DONE after untagged FETCH during IDLE

[Dovecot] RETRACT: Re: 2.0beta4 doesn't respond to DONE after untagged FETCH during IDLE

[Dovecot] RETRACT: Re: 2.0beta4 doesn't respond to DONE after untagged FETCH during IDLE

Reasonably Related Threads