ImapIdleChannelAdapter does not re-establish connection

[krzychu]

Hi SI users,

I've observed a strange behavior of imap-idle-channel-adapter. After running let's say 1 or 2 days it stops re-establishing connection with MS Exchange server.

Sample log file:

2011-10-05 10:52:36,448 [task-scheduler-10] WARN  o.s.i.mail.ImapIdleChannelAdapter - error occurred in idle task
javax.mail.FolderClosedException: * BYE JavaMail Exception: java.net.SocketTimeoutException: Read timed out
	at com.sun.mail.imap.IMAPFolder.throwClosedException(IMAPFolder.java:2451) ~[mail.jar:1.4.1]
	at com.sun.mail.imap.IMAPFolder.idle(IMAPFolder.java:2243) ~[mail.jar:1.4.1]
	at org.springframework.integration.mail.ImapMailReceiver.waitForNewMessages(ImapMailReceiver.java:100) ~[spring-integration-mail-2.0.5.RELEASE.jar:na]
	at org.springframework.integration.mail.ImapIdleChannelAdapter$IdleTask.run(ImapIdleChannelAdapter.java:166) ~[spring-integration-mail-2.0.5.RELEASE.jar:na]
	at org.springframework.integration.mail.ImapIdleChannelAdapter$1$1.run(ImapIdleChannelAdapter.java:113) [spring-integration-mail-2.0.5.RELEASE.jar:na]
	at org.springframework.scheduling.support.DelegatingErrorHandlingRunnable.run(DelegatingErrorHandlingRunnable.java:51) [spring-context-3.0.5.RELEASE.jar:3.0.5.RELEASE]
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441) [na:1.6.0_22]
	at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303) [na:1.6.0_22]
	at java.util.concurrent.FutureTask.run(FutureTask.java:138) [na:1.6.0_22]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:98) [na:1.6.0_22]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:206) [na:1.6.0_22]
	at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886) [na:1.6.0_22]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908) [na:1.6.0_22]
	at java.lang.Thread.run(Thread.java:662) [na:1.6.0_22]
2011-10-05 10:52:36,449 [task-scheduler-10] WARN  o.s.i.mail.ImapIdleChannelAdapter - Failed to execute IDLE task. Will atempt to resubmit in 10000 milliseconds
java.lang.IllegalStateException: Failure in 'idle' task. Will resubmit
	at org.springframework.integration.mail.ImapIdleChannelAdapter$IdleTask.run(ImapIdleChannelAdapter.java:192) ~[spring-integration-mail-2.0.5.RELEASE.jar:na]
	at org.springframework.integration.mail.ImapIdleChannelAdapter$1$1.run(ImapIdleChannelAdapter.java:113) ~[spring-integration-mail-2.0.5.RELEASE.jar:na]
	at org.springframework.scheduling.support.DelegatingErrorHandlingRunnable.run(DelegatingErrorHandlingRunnable.java:51) [spring-context-3.0.5.RELEASE.jar:3.0.5.RELEASE]
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441) [na:1.6.0_22]
	at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303) [na:1.6.0_22]
	at java.util.concurrent.FutureTask.run(FutureTask.java:138) [na:1.6.0_22]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:98) [na:1.6.0_22]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:206) [na:1.6.0_22]
	at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886) [na:1.6.0_22]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908) [na:1.6.0_22]
	at java.lang.Thread.run(Thread.java:662) [na:1.6.0_22]
Caused by: javax.mail.FolderClosedException: * BYE JavaMail Exception: java.net.SocketTimeoutException: Read timed out
	at com.sun.mail.imap.IMAPFolder.throwClosedException(IMAPFolder.java:2451) ~[mail.jar:1.4.1]
	at com.sun.mail.imap.IMAPFolder.idle(IMAPFolder.java:2243) ~[mail.jar:1.4.1]
	at org.springframework.integration.mail.ImapMailReceiver.waitForNewMessages(ImapMailReceiver.java:100) ~[spring-integration-mail-2.0.5.RELEASE.jar:na]
	at org.springframework.integration.mail.ImapIdleChannelAdapter$IdleTask.run(ImapIdleChannelAdapter.java:166) ~[spring-integration-mail-2.0.5.RELEASE.jar:na]
	... 10 common frames omitted
2011-10-05 10:57:46,497 [task-scheduler-9] WARN  o.s.i.mail.ImapIdleChannelAdapter - error occurred in idle task
javax.mail.FolderClosedException: * BYE JavaMail Exception: java.net.SocketTimeoutException: Read timed out
	at com.sun.mail.imap.IMAPFolder.throwClosedException(IMAPFolder.java:2451) ~[mail.jar:1.4.1]
	at com.sun.mail.imap.IMAPFolder.idle(IMAPFolder.java:2243) ~[mail.jar:1.4.1]
	at org.springframework.integration.mail.ImapMailReceiver.waitForNewMessages(ImapMailReceiver.java:100) ~[spring-integration-mail-2.0.5.RELEASE.jar:na]
	at org.springframework.integration.mail.ImapIdleChannelAdapter$IdleTask.run(ImapIdleChannelAdapter.java:166) ~[spring-integration-mail-2.0.5.RELEASE.jar:na]
	at org.springframework.integration.mail.ImapIdleChannelAdapter$1$1.run(ImapIdleChannelAdapter.java:113) [spring-integration-mail-2.0.5.RELEASE.jar:na]
	at org.springframework.scheduling.support.DelegatingErrorHandlingRunnable.run(DelegatingErrorHandlingRunnable.java:51) [spring-context-3.0.5.RELEASE.jar:3.0.5.RELEASE]
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441) [na:1.6.0_22]
	at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303) [na:1.6.0_22]
	at java.util.concurrent.FutureTask.run(FutureTask.java:138) [na:1.6.0_22]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:98) [na:1.6.0_22]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:206) [na:1.6.0_22]
	at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886) [na:1.6.0_22]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908) [na:1.6.0_22]
	at java.lang.Thread.run(Thread.java:662) [na:1.6.0_22]
2011-10-05 10:57:46,498 [task-scheduler-9] WARN  o.s.i.mail.ImapIdleChannelAdapter - Failed to execute IDLE task. Will atempt to resubmit in 10000 milliseconds
java.lang.IllegalStateException: Failure in 'idle' task. Will resubmit
	at org.springframework.integration.mail.ImapIdleChannelAdapter$IdleTask.run(ImapIdleChannelAdapter.java:192) ~[spring-integration-mail-2.0.5.RELEASE.jar:na]
	at org.springframework.integration.mail.ImapIdleChannelAdapter$1$1.run(ImapIdleChannelAdapter.java:113) ~[spring-integration-mail-2.0.5.RELEASE.jar:na]
	at org.springframework.scheduling.support.DelegatingErrorHandlingRunnable.run(DelegatingErrorHandlingRunnable.java:51) [spring-context-3.0.5.RELEASE.jar:3.0.5.RELEASE]
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:441) [na:1.6.0_22]
	at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303) [na:1.6.0_22]
	at java.util.concurrent.FutureTask.run(FutureTask.java:138) [na:1.6.0_22]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:98) [na:1.6.0_22]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:206) [na:1.6.0_22]
	at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886) [na:1.6.0_22]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908) [na:1.6.0_22]
	at java.lang.Thread.run(Thread.java:662) [na:1.6.0_22]
Caused by: javax.mail.FolderClosedException: * BYE JavaMail Exception: java.net.SocketTimeoutException: Read timed out
	at com.sun.mail.imap.IMAPFolder.throwClosedException(IMAPFolder.java:2451) ~[mail.jar:1.4.1]
	at com.sun.mail.imap.IMAPFolder.idle(IMAPFolder.java:2243) ~[mail.jar:1.4.1]
	at org.springframework.integration.mail.ImapMailReceiver.waitForNewMessages(ImapMailReceiver.java:100) ~[spring-integration-mail-2.0.5.RELEASE.jar:na]
	at org.springframework.integration.mail.ImapIdleChannelAdapter$IdleTask.run(ImapIdleChannelAdapter.java:166) ~[spring-integration-mail-2.0.5.RELEASE.jar:na]
	... 10 common frames omitted
2011-10-05 11:01:32,937 [task-scheduler-4] INFO  o.s.i.mail.ImapMailReceiver - attempting to receive mail from folder [INBOX]
2011-10-05 11:01:33,194 [SimpleAsyncTaskExecutor-2] WARN  c.r.p.i.SubjectBasedMessageSelector - Subject does not match: xxxxxx
2011-10-05 13:30:39,209 [ajp-10.112.196.9-8009-10] INFO  o.s.ldap.core.LdapTemplate - The returnObjFlag of supplied SearchControls is not set but a ContextMapper is used - setting flag to true

As you can see it tries to re-establish the connection every 5 minutes and when it receives an e-mail at 11:01 it hangs. It seems that it remains in the blocked state and the only way to reconnect to MS Exchange is by restarting the adapter (via control bus) or restarting app server itself.

I would like to add that I set up the mail.imap.timeout parameter to 300000 milisec in order to give adapter a chance to reconnect after 5 minutes.

Has anybody faced similar issues with imap-idle-channel-adapter?

Help is needed since described issue happens on production environment

Regards,
Krzysztof

[oleg.zhurakousky]

I think someone had reported something similar and it was fixed. Also there was some refactoring done last week to that module. Could you please run it against the lates snapshot and see if the problem is still there?

[krzychu]

Hi Oleg,

Thanks for your response. Did you remember in which version It was fixed? Currently we're running 2.0.5 version on production and problem occurred a few days ago. I will run it against the latest snapshot version and let you know.

Regards,
Krzysztof

[Mark Fisher]

The issue that I believe Oleg refers to is here: https://jira.springsource.org/browse/INT-2104

The change was applied to the master branch here (soon to be 2.1.0.M2): https://github.com/SpringSource/spri...aa1920e010e1f0

And it was applied to the maint branch here (soon to be 2.0.6): https://github.com/SpringSource/spri...8fb30aa11fa589

You could grab either the '2.1.0.BUILD-SNAPSHOT' version of the '2.0.6.BUILD-SNAPSHOT' version.

Hope that helps.
-Mark

[krzychu]

Hi Mark,

Right, it has to be https://jira.springsource.org/browse/INT-2104, As I can see in Jira the fix was applied to 2.1.0.M1 which was already released. Do you think that 2.1.0.M1 is stable enough to use it on prod or should I rather move back to 2.0.4 version in which the described issue was not present.

BTW, Any ideas when the 2.0.6 version will be released?

Regards,
Krzysztof

[Mark Fisher]

I would not recommend using a Milestone in production. Other than features that are still in development (which you probably wouldn't be using yet), it should be relatively stable, but the idea behind our milestone phases is that anything *can* change until we get into the RCs. Our goal is to have Spring Integration 2.1 GA in November.

We will most likely release 2.0.6 as soon as possible after 2.1 GA since it might contain more backported fixes between now and the time the GA is ready.

I guess I'd recommend using 2.0.4 if there is nothing else in 2.0.5 that you really needed, and then as soon as 2.0.6 is available you could skip ahead. Another thing you can try is downgrading just the mail module to 2.0.4. It wouldn't be an officially supported configuration, and it can add a bit extra to your Maven configuration, but that module is fairly independent. If you can run some tests and that seems okay, it might be a temporary option to consider.

We would definitely like to hear from you if you get a chance to test the 2.0.6.BUILD-SNAPSHOT version as well.

Hope that helps.
-Mark

[krzychu]

I will downgrade to 2.0.4 then. If I get a chance to test the 2.0.6.BUILD-SNAPSHOT version I will let you know.

Ragards,
Krzysztof

[krzychu]

Hi Mark,

It seems that it was fixed in 2.0.6.BUILD-SNAPSHOT version. Any ideas when the official 2.0.6 will be released?

Regards,
Krzysztof

[oleg.zhurakousky]

I am pretty sure its in 2.0.5. Can you try?

[krzychu]

Hi Oleg,

This issue has been observed in 2.0.5 that's why I decided to downgrade to 2.0.4.

According to what https://jira.springsource.org/browse/INT-2104 says it was fixed in 2.0.6.

I've seen that all issues assigned to 2.0.6 have been already fixed. Any date of official release?

Regards,
Krzysztof