FolderClosedException when downloading large file attachments #8577

jayChrono · 2023-03-18T06:56:08Z

In what version(s) of Spring Integration are you seeing this issue?
v6.0.3

Describe the bug
When downloading a large file attachment downstream, the IMAP folder can be closed in subsequent AbstractMailSender.receive() when there are no more messagesToReturn throwing a FolderClosedException.

From the documentation,

Starting with version 5.5.11, the folder is closed automatically after AbstractMailReceiver.receive() if no messages received or all of them are filtered out independently of the autoCloseFolder flag. In this case there is nothing to produce downstream for possible logic around IntegrationMessageHeaderAccessor.CLOSEABLE_RESOURCE header.

And indeed lines 384-386 in AbstractMailReceiver describes this behaviour.

  if (this.autoCloseFolder || ObjectUtils.isEmpty(messagesToReturn)) {
  	closeFolder();
  }

To Reproduce

Create IntegrationFlow with Mail.imapIdleAdapter() and autoCloseFolder(false)
Attach a MessageHandler that runs the MimeBodyPart.saveFile() function
Put an email in the mailbox with a large (1MB) file attachment

Expected behavior
Expect to save attachments regardless of size (save for mail server limits).

Sample
Here's the trace of the error:

DEBUG 24076 --- [scheduling-1] o.s.integration.mail.ImapMailReceiver    : opening folder [imaps://xxxxxxxx%[email protected]:993/Test]
DEBUG 24076 --- [scheduling-1] com.sun.mail.imap                        : connection available -- size: 1
 INFO 24076 --- [scheduling-1] com.sun.mail.imap.messagecache           : create cache of size 3
DEBUG 24076 --- [scheduling-1] com.sun.mail.imap.messagecache           : create message number 3
DEBUG 24076 --- [scheduling-1] com.sun.mail.imap                        : IMAPProtocol noop
DEBUG 24076 --- [scheduling-1] o.s.integration.mail.ImapMailReceiver    : attempting to receive mail from folder [Test]
DEBUG 24076 --- [scheduling-1] o.s.integration.mail.ImapMailReceiver    : found 1 new messages
DEBUG 24076 --- [scheduling-1] o.s.integration.mail.ImapMailReceiver    : Received 1 messages
DEBUG 24076 --- [scheduling-1] o.s.integration.mail.ImapMailReceiver    : USER flags are not supported by this mail server. Flagging message with system flag
DEBUG 24076 --- [scheduling-1] o.s.i.mail.ImapIdleChannelAdapter        : received 1 mail messages
DEBUG 24076 --- [scheduling-1] o.s.i.mail.ImapIdleChannelAdapter        : Task completed successfully. Re-scheduling it again right away.
DEBUG 24076 --- [scheduling-1] o.s.i.mail.ImapIdleChannelAdapter        : waiting for mail
DEBUG 24076 --- [scheduling-1] com.sun.mail.imap.connectionpool         : getStoreProtocol() - no connections in the pool, creating a new one
DEBUG 24076 --- [scheduling-1] com.sun.mail.imap                        : AUTH: PLAIN
DEBUG 24076 --- [scheduling-1] com.sun.mail.imap                        : AUTH: XOAUTH2
 INFO 24076 --- [pool-2-thread-1] com.sai.invoice.handler.EmailHandler     : Processing email: CSCpass.pdf
DEBUG 24076 --- [scheduling-1] com.sun.mail.imap                        : AUTH: PLAIN
DEBUG 24076 --- [scheduling-1] com.sun.mail.imap                        : AUTH: XOAUTH2
DEBUG 24076 --- [scheduling-1] com.sun.mail.imap.connectionpool         : getStoreProtocol() -- storeConnectionInUse
DEBUG 24076 --- [scheduling-1] com.sun.mail.imap                        : IMAPProtocol noop
DEBUG 24076 --- [scheduling-1] com.sun.mail.imap.connectionpool         : releaseStoreProtocol()
DEBUG 24076 --- [scheduling-1] o.s.integration.mail.ImapMailReceiver    : attempting to receive mail from folder [Test]
DEBUG 24076 --- [scheduling-1] o.s.integration.mail.ImapMailReceiver    : found 0 new messages
DEBUG 24076 --- [scheduling-1] o.s.integration.mail.ImapMailReceiver    : Received 0 messages
DEBUG 24076 --- [scheduling-1] com.sun.mail.imap.connectionpool         : connection pool current size: 1   pool size: 1
DEBUG 24076 --- [scheduling-1] com.sun.mail.imap                        : pool is full, not adding an Authenticated connection
DEBUG 24076 --- [scheduling-1] o.s.i.mail.ImapIdleChannelAdapter        : received 0 mail messages
DEBUG 24076 --- [scheduling-1] o.s.i.mail.ImapIdleChannelAdapter        : Task completed successfully. Re-scheduling it again right away.
DEBUG 24076 --- [scheduling-1] o.s.i.mail.ImapIdleChannelAdapter        : waiting for mail
DEBUG 24076 --- [scheduling-1] com.sun.mail.imap.connectionpool         : getStoreProtocol() - connection available -- size: 1
DEBUG 24076 --- [scheduling-1] com.sun.mail.imap.connectionpool         : getStoreProtocol() -- storeConnectionInUse
DEBUG 24076 --- [scheduling-1] com.sun.mail.imap                        : IMAPProtocol noop
DEBUG 24076 --- [scheduling-1] com.sun.mail.imap.connectionpool         : releaseStoreProtocol()
DEBUG 24076 --- [scheduling-1] com.sun.mail.imap.connectionpool         : getStoreProtocol() borrowing a connection
DEBUG 24076 --- [scheduling-1] com.sun.mail.imap.connectionpool         : getStoreProtocol() - connection available -- size: 1
DEBUG 24076 --- [scheduling-1] com.sun.mail.imap.connectionpool         : getStoreProtocol() -- storeConnectionInUse
DEBUG 24076 --- [scheduling-1] com.sun.mail.imap.connectionpool         : releaseFolderStoreProtocol()
DEBUG 24076 --- [scheduling-1] o.s.integration.mail.ImapMailReceiver    : opening folder [imaps://xxxxxxxx%[email protected]:993/Test]
DEBUG 24076 --- [scheduling-1] com.sun.mail.imap                        : connection available -- size: 1
 INFO 24076 --- [scheduling-1] com.sun.mail.imap.messagecache           : create cache of size 3
DEBUG 24076 --- [scheduling-1] o.s.integration.mail.ImapMailReceiver    : opening folder [imaps://xxxxxxxx%[email protected]:993/Test]
DEBUG 24076 --- [scheduling-1] com.sun.mail.imap                        : connection available -- size: 1
 INFO 24076 --- [scheduling-1] com.sun.mail.imap.messagecache           : create cache of size 3
DEBUG 24076 --- [scheduling-1] com.sun.mail.imap.messagecache           : create message number 3
DEBUG 24076 --- [scheduling-1] com.sun.mail.imap                        : IMAPProtocol noop
DEBUG 24076 --- [scheduling-1] o.s.integration.mail.ImapMailReceiver    : attempting to receive mail from folder [Test]
DEBUG 24076 --- [scheduling-1] o.s.integration.mail.ImapMailReceiver    : found 1 new messages
DEBUG 24076 --- [scheduling-1] o.s.integration.mail.ImapMailReceiver    : Received 1 messages
DEBUG 24076 --- [scheduling-1] o.s.integration.mail.ImapMailReceiver    : USER flags are not supported by this mail server. Flagging message with system flag
DEBUG 24076 --- [scheduling-1] o.s.i.mail.ImapIdleChannelAdapter        : received 1 mail messages
DEBUG 24076 --- [scheduling-1] o.s.i.mail.ImapIdleChannelAdapter        : Task completed successfully. Re-scheduling it again right away.
DEBUG 24076 --- [scheduling-1] o.s.i.mail.ImapIdleChannelAdapter        : waiting for mail
DEBUG 24076 --- [scheduling-1] com.sun.mail.imap.connectionpool         : getStoreProtocol() - no connections in the pool, creating a new one
DEBUG 24076 --- [scheduling-1] com.sun.mail.imap                        : AUTH: PLAIN
DEBUG 24076 --- [scheduling-1] com.sun.mail.imap                        : AUTH: XOAUTH2
 INFO 24076 --- [pool-2-thread-1] com.sai.invoice.handler.EmailHandler     : Processing email: CSCpass.pdf
DEBUG 24076 --- [scheduling-1] com.sun.mail.imap                        : AUTH: PLAIN
DEBUG 24076 --- [scheduling-1] com.sun.mail.imap                        : AUTH: XOAUTH2
DEBUG 24076 --- [scheduling-1] com.sun.mail.imap.connectionpool         : getStoreProtocol() -- storeConnectionInUse
DEBUG 24076 --- [scheduling-1] com.sun.mail.imap                        : IMAPProtocol noop
DEBUG 24076 --- [scheduling-1] com.sun.mail.imap.connectionpool         : releaseStoreProtocol()
DEBUG 24076 --- [scheduling-1] o.s.integration.mail.ImapMailReceiver    : attempting to receive mail from folder [Test]
DEBUG 24076 --- [scheduling-1] o.s.integration.mail.ImapMailReceiver    : found 0 new messages
DEBUG 24076 --- [scheduling-1] o.s.integration.mail.ImapMailReceiver    : Received 0 messages
DEBUG 24076 --- [scheduling-1] com.sun.mail.imap.connectionpool         : connection pool current size: 1   pool size: 1
DEBUG 24076 --- [scheduling-1] com.sun.mail.imap                        : pool is full, not adding an Authenticated connection
DEBUG 24076 --- [scheduling-1] o.s.i.mail.ImapIdleChannelAdapter        : received 0 mail messages
DEBUG 24076 --- [scheduling-1] o.s.i.mail.ImapIdleChannelAdapter        : Task completed successfully. Re-scheduling it again right away.
DEBUG 24076 --- [scheduling-1] o.s.i.mail.ImapIdleChannelAdapter        : waiting for mail
DEBUG 24076 --- [scheduling-1] com.sun.mail.imap.connectionpool         : getStoreProtocol() - connection available -- size: 1
DEBUG 24076 --- [scheduling-1] com.sun.mail.imap.connectionpool         : getStoreProtocol() -- storeConnectionInUse
DEBUG 24076 --- [scheduling-1] com.sun.mail.imap                        : IMAPProtocol noop
DEBUG 24076 --- [scheduling-1] com.sun.mail.imap.connectionpool         : releaseStoreProtocol()
DEBUG 24076 --- [scheduling-1] com.sun.mail.imap.connectionpool         : getStoreProtocol() borrowing a connection
DEBUG 24076 --- [scheduling-1] com.sun.mail.imap.connectionpool         : getStoreProtocol() - connection available -- size: 1
DEBUG 24076 --- [scheduling-1] com.sun.mail.imap.connectionpool         : getStoreProtocol() -- storeConnectionInUse
DEBUG 24076 --- [scheduling-1] com.sun.mail.imap.connectionpool         : releaseFolderStoreProtocol()
DEBUG 24076 --- [scheduling-1] o.s.integration.mail.ImapMailReceiver    : opening folder [imaps://xxxxxxxx%[email protected]:993/Test]
DEBUG 24076 --- [scheduling-1] com.sun.mail.imap                        : connection available -- size: 1
 INFO 24076 --- [scheduling-1] com.sun.mail.imap.messagecache           : create cache of size 3
Exception in thread "pool-2-thread-1" org.springframework.messaging.MessageDeliveryException: Dispatcher failed to deliver Message, failedMessage=GenericMessage [payload=com.sun.mail.imap.IMAPMessage@5aa05613, headers={closeableResource=org.springframework.integration.mail.AbstractMailReceiver$$Lambda$1130/0x000000080120a400@1a40dd23, id=cb4d7cf2-a087-e331-6cf4-a7db82d52a4e, timestamp=1679122099504}]
	at org.springframework.integration.support.utils.IntegrationUtils.wrapInDeliveryExceptionIfNecessary(IntegrationUtils.java:166)
	at org.springframework.integration.dispatcher.AbstractDispatcher.tryOptimizedDispatch(AbstractDispatcher.java:119)
	at org.springframework.integration.dispatcher.UnicastingDispatcher.doDispatch(UnicastingDispatcher.java:133)
	at org.springframework.integration.dispatcher.UnicastingDispatcher.dispatch(UnicastingDispatcher.java:106)
	at org.springframework.integration.channel.AbstractSubscribableChannel.doSend(AbstractSubscribableChannel.java:72)
	at org.springframework.integration.channel.AbstractMessageChannel.sendInternal(AbstractMessageChannel.java:373)
	at org.springframework.integration.channel.AbstractMessageChannel.send(AbstractMessageChannel.java:327)
	at org.springframework.integration.channel.AbstractMessageChannel.send(AbstractMessageChannel.java:297)
	at org.springframework.messaging.core.GenericMessagingTemplate.doSend(GenericMessagingTemplate.java:187)
	at org.springframework.messaging.core.GenericMessagingTemplate.doSend(GenericMessagingTemplate.java:166)
	at org.springframework.messaging.core.GenericMessagingTemplate.doSend(GenericMessagingTemplate.java:47)
	at org.springframework.messaging.core.AbstractMessageSendingTemplate.send(AbstractMessageSendingTemplate.java:109)
	at org.springframework.integration.endpoint.MessageProducerSupport.lambda$sendMessage$1(MessageProducerSupport.java:262)
	at io.micrometer.observation.Observation.observe(Observation.java:492)
	at org.springframework.integration.endpoint.MessageProducerSupport.sendMessage(MessageProducerSupport.java:262)
	at org.springframework.integration.mail.ImapIdleChannelAdapter.lambda$prepareSendingTask$0(ImapIdleChannelAdapter.java:223)
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
	at java.base/java.lang.Thread.run(Thread.java:833)
Caused by: org.springframework.messaging.MessagingException: Could not process email: {closeableResource=org.springframework.integration.mail.AbstractMailReceiver$$Lambda$1130/0x000000080120a400@1a40dd23, id=cb4d7cf2-a087-e331-6cf4-a7db82d52a4e, timestamp=1679122099504}
	at com.sai.invoice.handler.EmailHandler.handleMessage(EmailHandler.java:67)
	at org.springframework.integration.dispatcher.AbstractDispatcher.tryOptimizedDispatch(AbstractDispatcher.java:115)
	... 17 more
Caused by: java.io.IOException: jakarta.mail.FolderClosedException
	at com.sun.mail.imap.IMAPInputStream.fill(IMAPInputStream.java:141)
	at com.sun.mail.imap.IMAPInputStream.read(IMAPInputStream.java:245)
	at com.sun.mail.imap.IMAPInputStream.read(IMAPInputStream.java:272)
	at com.sun.mail.util.BASE64DecoderStream.getByte(BASE64DecoderStream.java:341)
	at com.sun.mail.util.BASE64DecoderStream.decode(BASE64DecoderStream.java:232)
	at com.sun.mail.util.BASE64DecoderStream.read(BASE64DecoderStream.java:124)
	at java.base/java.io.FilterInputStream.read(FilterInputStream.java:106)
	at jakarta.mail.internet.MimeBodyPart.saveFile(MimeBodyPart.java:960)
	at com.sai.invoice.handler.EmailHandler.handleBodyPart(EmailHandler.java:81)
	at com.sai.invoice.handler.EmailHandler.handleMessage(EmailHandler.java:55)
	... 18 more
Caused by: jakarta.mail.FolderClosedException
	... 28 more

The text was updated successfully, but these errors were encountered:

jayChrono · 2023-03-18T06:58:33Z

Forgot to add, simply removing the ObjectUtils.isEmpty(messagesToReturn) predicate on line 384 appears to correct the problem. But it may have been added to resolve another issue.

artembilan · 2023-03-20T14:25:33Z

Try with this ImapIdleChannelAdapter.setSendingTaskExecutor(new SyncTaskExecutor()).
This way we are going to be blocked at this point:

		Object[] mailMessages = ImapIdleChannelAdapter.this.mailReceiver.receive();
						logger.debug(() -> "received " + mailMessages.length + " mail messages");
						for (Object mailMessage : mailMessages) {
							Runnable messageSendingTask = createMessageSendingTask(mailMessage);
							if (isRunning()) {
								ImapIdleChannelAdapter.this.sendingTaskExecutor.execute(messageSendingTask);
							}
						}

And therefore we won't go to the next idle cylce until we finish with the current one.

I'm not sure what was the reason initially to have a processing task as an async one, but that is indeed may cause the problem you've just described.

I also not sure how to fix it yet, but we definitely cannot keep the folder opened all the time.

jayChrono · 2023-03-20T23:58:00Z

The SyncTaskExecutor works but this will still occur by default (async). I believe the intention was to provide the the closeable resource in the message header (retrievable by StaticMessageHeaderAccessor.getCloseableResource()). Of course, this still requires the store folder to remain open until the closeable resource is closed.

artembilan · 2023-03-22T18:13:07Z

If we don't have messages to emit, therefore there is nothing we can attach that CloseableResource into headers.

I'm looking into the logic of the ImapIdleChannelAdapter to see if we really need that async hand-off for producing messages...

artembilan · 2023-03-22T19:39:07Z

OK. Too many questions to the ImapIdleChannelAdapter internals.
Pushing this to the next milestone.

Fixes spring-projects#8577 When we process mail messages in async manner, it is possible that we end up in a race condition situation where the next idle cycle closes the folder. It is possible to reopen the folder, but feels better to block the current idle cycle until we are done with the message and therefore keep folder opened. * Deprecate `ImapIdleChannelAdapter.sendingTaskExecutor` in favor of an `ExecutorChannel` as an output for this channel adapter or similar async hand-off downstream. * Make use of `shouldReconnectAutomatically` as it is advertised for this channel adapter * Optimize the proxy creation for message sending task

Fixes spring-projects#8577 When we process mail messages in async manner, it is possible that we end up in a race condition situation where the next idle cycle closes the folder. It is possible to reopen the folder, but feels better to block the current idle cycle until we are done with the message and therefore keep folder opened. * Deprecate `ImapIdleChannelAdapter.sendingTaskExecutor` in favor of an `ExecutorChannel` as an output for this channel adapter or similar async hand-off downstream. * Make a default one as a `SyncTaskExecutor` to make a sense of this deprecation

* GH-8577: Deprecate ImapIdleCA.sendingTaskExecutor Fixes #8577 When we process mail messages in async manner, it is possible that we end up in a race condition situation where the next idle cycle closes the folder. It is possible to reopen the folder, but feels better to block the current idle cycle until we are done with the message and therefore keep folder opened. * Deprecate `ImapIdleChannelAdapter.sendingTaskExecutor` in favor of an `ExecutorChannel` as an output for this channel adapter or similar async hand-off downstream. * Make a default one as a `SyncTaskExecutor` to make a sense of this deprecation * Fix language in docs Co-authored-by: Gary Russell <[email protected]> --------- Co-authored-by: Gary Russell <[email protected]>

* GH-8577: Revise `ImapIdleChannelAdapter` logic Fixes #8577 When we process mail messages in async manner, it is possible that we end up in a race condition situation where the next idle cycle closes the folder. It is possible to reopen the folder, but feels better to block the current idle cycle until we are done with the message and therefore keep folder opened. * Deprecate `ImapIdleChannelAdapter.sendingTaskExecutor` in favor of an `ExecutorChannel` as an output for this channel adapter or similar async hand-off downstream. * Make use of `shouldReconnectAutomatically` as it is advertised for this channel adapter * Optimize the proxy creation for message sending task * * Remove `ImapIdleChannelAdapter.sendingTaskExecutor` * Fix language in docs Co-authored-by: Gary Russell <[email protected]> --------- Co-authored-by: Gary Russell <[email protected]>

jayChrono added status: waiting-for-triage The issue need to be evaluated and its future decided type: bug labels Mar 18, 2023

artembilan added the in: mail label Mar 20, 2023

artembilan removed the status: waiting-for-triage The issue need to be evaluated and its future decided label Mar 22, 2023

artembilan added this to the 6.1.0-RC1 milestone Mar 22, 2023

artembilan mentioned this issue Mar 28, 2023

GH-8577: Revise ImapIdleChannelAdapter logic #8588

Merged

artembilan mentioned this issue Mar 28, 2023

GH-8577: Deprecate ImapIdleCA.sendingTaskExecutor #8589

Merged

garyrussell closed this as completed in #8588 Mar 29, 2023

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Uh oh!

FolderClosedException when downloading large file attachments #8577

FolderClosedException when downloading large file attachments #8577

jayChrono commented Mar 18, 2023 •

edited by artembilan

Loading

jayChrono commented Mar 18, 2023

Uh oh!

artembilan commented Mar 20, 2023

Uh oh!

jayChrono commented Mar 20, 2023

Uh oh!

artembilan commented Mar 22, 2023

Uh oh!

artembilan commented Mar 22, 2023

Uh oh!

FolderClosedException when downloading large file attachments #8577

FolderClosedException when downloading large file attachments #8577

Comments

jayChrono commented Mar 18, 2023 • edited by artembilan Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

jayChrono commented Mar 18, 2023

Uh oh!

artembilan commented Mar 20, 2023

Uh oh!

jayChrono commented Mar 20, 2023

Uh oh!

artembilan commented Mar 22, 2023

Uh oh!

artembilan commented Mar 22, 2023

Uh oh!

jayChrono commented Mar 18, 2023 •

edited by artembilan

Loading