title: Transactional POP3 Mailbox access with Spring Integration
body: <p>We want to use Spring Integration 2.1.1 to read mail off a POP3 mailbox transactionally.  The transactionality is so that we can read an email message and persist it to Oracle and remove from the mailbox. In the event of a transaction rollback we want the email to remain in the mailbox (i.e. not be deleted).</p>
  
  <p>Our problem is that, despite being in a transaction (more detail on that in a second) the mailbox is opened, the mail is retrieved, marked for deletion and the connection closed irrespective of the rest of the transaction.  This means it is too late to not delete the mail if something fails later on (as the connection is closed and the mailbox gone into UPDATE state which permanently removes the email).</p>
  
  <p>We've been attempting to do this by creating a transactional polling inbound-channel-adaptor:</p>
  
  <pre><code>&lt;!-- This inbound channel adaptor interfaces to the sendmail POP3 queue --&gt;
  &lt;int-mail:inbound-channel-adapter id="pop3PollingChannelAdaptor" 
                                    store-uri="pop3://myuser:myuser@100.100.100.100/inbox" 
                                    channel="receiveInboundEmailChannel" 
                                    should-delete-messages="true"              
                                    auto-startup="true" 
                                    java-mail-properties="javaMailProperties"&gt;
      &lt;!-- Will poll every 20 seconds --&gt;            
      &lt;int:poller fixed-rate="10000" 
                  max-messages-per-poll="1"&gt;
          &lt;int:transactional transaction-manager="txManager"
                             isolation="DEFAULT"
                             propagation="REQUIRED"
                             read-only="false"
                             timeout="100000" /&gt;
      &lt;/int:poller&gt;
  &lt;/int-mail:inbound-channel-adapter&gt;
  </code></pre>
  
  <p>Which puts messages on an inbound email channel:
      </p>
  
  <p>Which is in turn listened to by a outbound-channel-adapter (endpoint):</p>
  
  <pre><code>&lt;int:outbound-channel-adapter channel="receiveInboundEmailChannel" 
                                ref="inboundEmailMessageEndpoint" 
                                method="processMessage" /&gt;
  </code></pre>
  
  <p>The implementation of the endpoint currently keeps things really simple. We don't go anywhere near a database at the moment, instead we just throw an exception if we want to trigger a rollback.</p>
  
  <pre><code>@MessageEndpoint
  public class InboundEmailMessageEndpoint {
      @Transactional(propagation = Propagation.MANDATORY)
      public void processMessage(Message&lt;MimeMessage&gt; message) {
  
          MimeMessage mailMessage =  message.getPayload();
  
          // We throw exceptions here to cause a rollback if we need to during investigation...
      }
  }
  </code></pre>
  
  <p>Looking at all of the logs, we can see our problem in context (note how POP3 "sayonara's" before the rest of our work in the endpoint begins, and most importantly, before the surrounding transaction commits / rolls back):</p>
  
  <pre><code>15:32:25.256 INFO  [main][org.springframework.transaction.jta.JtaTransactionManager]     Using JTA UserTransaction: com.atomikos.icatch.jta.UserTransactionImp@3228a1
  15:32:25.256 INFO  [main][org.springframework.transaction.jta.JtaTransactionManager] Using JTA TransactionManager: com.atomikos.icatch.jta.UserTransactionManager@10980e7
  15:32:25.422 DEBUG [task-scheduler-1][com.atomikos.icatch.imp.BaseTransactionManager] getCompositeTransaction() returning NULL!
  15:32:25.422 DEBUG [task-scheduler-1][com.atomikos.icatch.imp.BaseTransactionManager] getCompositeTransaction() returning NULL!
  15:32:25.423 DEBUG [task-scheduler-1][org.springframework.transaction.jta.JtaTransactionManager] Creating new transaction with name [org.springframework.integration.endpoint.AbstractPollingEndpoint$1.call]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT,timeout_100000
  15:32:25.423 DEBUG [task-scheduler-1][com.atomikos.icatch.imp.BaseTransactionManager] getCompositeTransaction() returning NULL!
  15:32:25.423 WARN  [task-scheduler-1][com.atomikos.icatch.imp.TransactionServiceImp] Attempt to create a transaction with a timeout that exceeds com.atomikos.icatch.max_timeout - truncating to: 300000
  15:32:25.423 DEBUG [task-scheduler-1][com.atomikos.icatch.imp.CoordinatorImp] Coordinator 10.9.21.7.tm0000100022 entering state: ACTIVE
  15:32:25.425 DEBUG [task-scheduler-1][com.atomikos.icatch.imp.thread.TaskManager] TaskManager: initializing...
  15:32:25.426 INFO  [task-scheduler-1][com.atomikos.icatch.imp.thread.TaskManager] THREADS: using JDK thread pooling...
  15:32:25.428 DEBUG [task-scheduler-1][com.atomikos.icatch.imp.thread.TaskManager] THREADS: using executor class com.atomikos.icatch.imp.thread.Java15ExecutorFactory$Executor
  15:32:25.428 DEBUG [task-scheduler-1][com.atomikos.icatch.imp.thread.Java15ExecutorFactory] (1.5) executing task: com.atomikos.timing.PooledAlarmTimer@18c4a7f
  15:32:25.429 DEBUG [task-scheduler-1][com.atomikos.icatch.imp.thread.ThreadFactory] ThreadFactory: creating new thread: Atomikos:0
  15:32:25.429 DEBUG [task-scheduler-1][com.atomikos.icatch.imp.TransactionServiceImp] Creating composite transaction: 10.9.21.7.tm0000100022
  15:32:25.433 INFO  [task-scheduler-1][com.atomikos.icatch.imp.BaseTransactionManager] createCompositeTransaction ( 100000000 ): created new ROOT transaction with id 10.9.21.7.tm0000100022
  DEBUG: JavaMail version 1.4.4
  DEBUG: successfully loaded resource: /META-INF/javamail.default.providers
  DEBUG: Tables of loaded providers
  DEBUG: Providers Listed By Class Name: {com.sun.mail.smtp.SMTPSSLTransport=javax.mail.Provider[TRANSPORT,smtps,com.sun.mail.smtp.SMTPSSLTransport,Sun Microsystems, Inc], com.sun.mail.smtp.SMTPTransport=javax.mail.Provider[TRANSPORT,smtp,com.sun.mail.smtp.SMTPTransport,Sun Microsystems, Inc], com.sun.mail.imap.IMAPSSLStore=javax.mail.Provider[STORE,imaps,com.sun.mail.imap.IMAPSSLStore,Sun Microsystems, Inc], com.sun.mail.pop3.POP3SSLStore=javax.mail.Provider[STORE,pop3s,com.sun.mail.pop3.POP3SSLStore,Sun Microsystems, Inc], com.sun.mail.imap.IMAPStore=javax.mail.Provider[STORE,imap,com.sun.mail.imap.IMAPStore,Sun Microsystems, Inc], com.sun.mail.pop3.POP3Store=javax.mail.Provider[STORE,pop3,com.sun.mail.pop3.POP3Store,Sun Microsystems, Inc]}
  DEBUG: Providers Listed By Protocol: {imaps=javax.mail.Provider[STORE,imaps,com.sun.mail.imap.IMAPSSLStore,Sun Microsystems, Inc], imap=javax.mail.Provider[STORE,imap,com.sun.mail.imap.IMAPStore,Sun Microsystems, Inc], smtps=javax.mail.Provider[TRANSPORT,smtps,com.sun.mail.smtp.SMTPSSLTransport,Sun Microsystems, Inc], pop3=javax.mail.Provider[STORE,pop3,com.sun.mail.pop3.POP3Store,Sun Microsystems, Inc], pop3s=javax.mail.Provider[STORE,pop3s,com.sun.mail.pop3.POP3SSLStore,Sun Microsystems, Inc], smtp=javax.mail.Provider[TRANSPORT,smtp,com.sun.mail.smtp.SMTPTransport,Sun Microsystems, Inc]}
  DEBUG: successfully loaded resource: /META-INF/javamail.default.address.map
  DEBUG: getProvider() returning javax.mail.Provider[STORE,pop3,com.sun.mail.pop3.POP3Store,Sun Microsystems, Inc]
  DEBUG POP3: mail.pop3.rsetbeforequit: false
  DEBUG POP3: mail.pop3.disabletop: false
  DEBUG POP3: mail.pop3.forgettopheaders: false
  DEBUG POP3: mail.pop3.cachewriteto: false
  DEBUG POP3: mail.pop3.filecache.enable: false
  DEBUG POP3: mail.pop3.keepmessagecontent: false
  DEBUG POP3: mail.pop3.starttls.enable: false
  DEBUG POP3: mail.pop3.starttls.required: false
  15:32:25.446 DEBUG [task-scheduler-1][org.springframework.integration.mail.Pop3MailReceiver] connecting to store [pop3://devmail9:*****@100.100.100.100/inbox]
  DEBUG POP3: mail.pop3.apop.enable: false
  DEBUG POP3: mail.pop3.disablecapa: false
  DEBUG POP3: connecting to host "100.100.100.100", port 110, isSSL false
  S: +OK POP3 xxxxx.xxxx.xxxx.xxx.xxx.uk v4.39 server ready
  C: CAPA
  S: -ERR Unknown command in AUTHORIZATION state
  C: USER myuser
  S: +OK User name accepted, password please
  C: PASS myuser
  S: +OK Mailbox open, 3 messages
  15:32:25.564 DEBUG [task-scheduler-1][org.springframework.integration.mail.Pop3MailReceiver] opening folder [pop3://myuser:*****@100.100.100.100/inbox]
  C: STAT
  S: +OK 3 5956
  15:32:25.569 INFO  [task-scheduler-1][org.springframework.integration.mail.Pop3MailReceiver] attempting to receive mail from folder [inbox]
  C: NOOP
  S: +OK No-op to you too!
  15:32:25.591 DEBUG [task-scheduler-1][org.springframework.integration.mail.Pop3MailReceiver] found 1 new messages
  C: TOP 1 0
  S: +OK Top of message follows
  Received: from xxxxx.xxxx.xxxx.xxx.xxx.uk ([100.100.100.100]) by     xxxxx.xxxx.xxxx.xxx.xxx.uk (AIX5.2/8.11.6p2/8.11.0) with ESMTP id q57EUrG1544330 for C:    LIST 1
  
  ....
  
  S: +OK 1 1996
  15:32:25.604 DEBUG [task-scheduler-1][org.springframework.integration.mail.Pop3MailReceiver] Recieved 1 messages
  15:32:26.097 DEBUG [task-scheduler-1][org.springframework.integration.mail.Pop3MailReceiver] USER flags are not supported by this mail server. Flagging message with system flag
  DEBUG POP3: streaming msg 1
  C: RETR 1
  S: +OK 1996 octets
  Received: from xxxxx.xxxx.xxxx.xxx.xxx.uk ([100.100.100.100]) by GLA610.crown.copfs.gsi.gov.uk (AIX5.2/8.11.6p2/8.11.0) with ESMTP id q57EUrG1544330 for &lt;myuser@xxxxx.xxxx.xxxx.xxx.xxx.uk&gt;; Thu, 7 Jun 2012 15:30:53 +0100
  
  ....
  
  DEBUG POP3: streaming msg 1
  C: RETR 1
  S: +OK 1996 octets
  Received: from xxxxx.xxxx.xxxx.xxx.xxx.uk ([100.100.100.100]) by xxxxx.xxxx.xxxx.xxx.xxx.uk (AIX5.2/8.11.6p2/8.11.0) with ESMTP id q57EUrG1544330 for &lt;myuser@xxxxx.xxxx.xxxx.xxx.xxx.uk&gt;; Thu, 7 Jun 2012 15:30:53 +0100
  
  ....
  
  .
  C: NOOP
  S: +OK No-op to you too!
  C: DELE 1
  S: +OK Message deleted
  C: QUIT
  S: +OK Sayonara
  15:32:26.672 DEBUG [task-scheduler-1][org.springframework.integration.mail.MailReceivingMessageSource] received mail message [javax.mail.internet.MimeMessage@ef4504]
  15:32:26.696 DEBUG [task-scheduler-1][com.atomikos.icatch.imp.BaseTransactionManager] getCompositeTransaction()  returning instance with id 10.9.21.7.tm0000100022
  15:32:26.697 DEBUG [task-scheduler-1][com.atomikos.icatch.imp.BaseTransactionManager] getCompositeTransaction()  returning instance with id 10.9.21.7.tm0000100022
  15:32:26.697 DEBUG [task-scheduler-1][org.springframework.transaction.jta.JtaTransactionManager] Participating in existing transaction
  15:32:26.716 INFO  [task-scheduler-1][xx.xxx.xxx.xxx.channel.email.InboundEmailMessageEndpoint] In InboundEmailMessageEndpoint.  processing MailMessage (Subject): 7777777777777777777
  15:32:26.735 DEBUG [task-scheduler-1][com.atomikos.icatch.imp.BaseTransactionManager] getCompositeTransaction()  returning instance with id 10.9.21.7.tm0000100022
  15:32:26.735 DEBUG [task-scheduler-1][com.atomikos.icatch.imp.BaseTransactionManager] getCompositeTransaction()  returning instance with id 10.9.21.7.tm0000100022
  15:32:26.735 DEBUG [task-scheduler-1][org.springframework.transaction.jta.JtaTransactionManager] Initiating transaction commit
  15:32:26.735 DEBUG [task-scheduler-1][com.atomikos.icatch.imp.BaseTransactionManager] getCompositeTransaction()  returning instance with id 10.9.21.7.tm0000100022
  15:32:26.735 DEBUG [task-scheduler-1][com.atomikos.icatch.imp.BaseTransactionManager] getCompositeTransaction()  returning instance with id 10.9.21.7.tm0000100022
  15:32:26.735 DEBUG [task-scheduler-1][com.atomikos.icatch.imp.BaseTransactionManager] getCompositeTransaction()  returning instance with id 10.9.21.7.tm0000100022
  15:32:26.735 DEBUG [task-scheduler-1][com.atomikos.icatch.imp.BaseTransactionManager] getCompositeTransaction()  returning instance with id 10.9.21.7.tm0000100022
  15:32:26.736 INFO  [task-scheduler-1][com.atomikos.icatch.imp.CompositeTransactionImp] commit() done (by application) of transaction 10.9.21.7.tm0000100022
  15:32:26.736 DEBUG [task-scheduler-1][com.atomikos.icatch.imp.CoordinatorImp] Coordinator 10.9.21.7.tm0000100022 entering state: COMMITTING
  15:32:26.740 DEBUG [task-scheduler-1][com.atomikos.icatch.imp.CoordinatorImp] Coordinator 10.9.21.7.tm0000100022 entering state: TERMINATED
  15:32:26.741 DEBUG [task-scheduler-1][com.atomikos.icatch.imp.CoordinatorImp] Coordinator 10.9.21.7.tm0000100022 : stopping timer...
  15:32:26.741 DEBUG [task-scheduler-1][com.atomikos.icatch.imp.CoordinatorImp] Coordinator 10.9.21.7.tm0000100022 : disposing statehandler TERMINATED...
  15:32:26.741 DEBUG [task-scheduler-1][com.atomikos.icatch.imp.CoordinatorImp] Coordinator 10.9.21.7.tm0000100022 : disposed.
  </code></pre>