[jboss-jira] [JBoss JIRA] (JBAS-8635) MailResourceAdapter mail check triggered only once
Brad Douglas (JIRA)
jira-events at lists.jboss.org
Mon Apr 2 02:53:47 EDT 2012
[ https://issues.jboss.org/browse/JBAS-8635?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12680832#comment-12680832 ]
Brad Douglas commented on JBAS-8635:
------------------------------------
I've had a look at this in 6.1 versus our other prod config which works (4.2.3).
Firstly WorkWrapper.run() invokes Work.run() and then Work.release() in the wrapping finally block (ie in the same thread). The java doc for Work.release() clearly says that it "would be called on a separate thread other than the one currently executing the Work instance." WorkWarpper is not obeying this.
The actual failing is complex because of the concurrency issues. But I'll try and explain it. To understand you need to know
1) NewMsgsWorker uses a PriorityBlockingQueue (pollQueue) to synchronise Work (MailActivation) that needs doing.
2) NewMsgsWorker is a WorkListener of MailActivation. When the MailActivation has finished looking for emails, the NewMsgWorker will be notified via a call to it's implementation of the WorkListener.workCompleted() method, which inturn puts the MailActivation back on the pollQueue of work to watch.
Here's a list of what's happening:
Threadpool-1-thread-1:
Calls pollQueue.take() to get work - none yet so it blocks.
Thread-2:
Put a MailActivation on the queue by calling pollQueue.put().
Threadpool-1-thread-1:
Wakes and processes then sleep for configured timeout.
Check that this nor the MailActivation have been released (no requested stop).
Not released so invokes the MailActivation.
Call pollQueue.take() to get work - blocks
Threadpool-1-thread-15:
WorkWrapper.run() invoked, in turn invokes MailActivation.run(), which perfroms the check in the remote SMTP server.
When Activation.run() returns WorkWrapper.run() invokes MailActivation.release() (bad)
Invokes NewMsgsWorker.workCompleted() which puts the MailActivation back on pollQueue
Threadpool-1-thread1:
Wakes and processes then sleep for configured timeout.
Check that this nor the MailActivation have been released (is a requested stop this time)
In this case the MailActivation is released so it doesn't invoke the MailActivation - therefore the workComplete() method is not invoked and the MailActivation is not put back on the pollQueue
Calls pollQueue.take() to get work - blocks forever as nothing will put the MailActivation back on pollQueue
I beleive the call to Work.release() inside WorkWrapper.run() is the problem (and goes against javadoc usage comments) - but I'm not sure what the wider ramifications of removing it would be.
Disclaimer: This is my first time looking at this code, so I could be completely off track and happy to be corrected.
"major version upgade" is not a helpful solution.
> MailResourceAdapter mail check triggered only once
> --------------------------------------------------
>
> Key: JBAS-8635
> URL: https://issues.jboss.org/browse/JBAS-8635
> Project: Application Server 3 4 5 and 6
> Issue Type: Bug
> Security Level: Public(Everyone can see)
> Components: JCA service
> Affects Versions: 6.0.0.M5
> Environment: Win7, JBoss 6.0.0.M5, Java 1.6.0_21
> Ubuntu lucid, JBoss 6.0.0.M5, Java 1.6.0_18
> Reporter: Martin Clauss
> Assignee: Jesper Pedersen
> Fix For: No Release
>
>
> Mail check is performed correctly only once (after first timeout of pollingInterval) and then never again...
> 18:43:13,690 INFO [org.jboss.ejb3.deployers.JBossASKernel] installing bean: jboss.j2ee:ear=CTAEar.ear,jar=CTAEJB3.jar,name=MailBean,service=EJB3
> 18:43:13,690 INFO [org.jboss.ejb3.deployers.JBossASKernel] with dependencies:
> 18:43:13,690 INFO [org.jboss.ejb3.deployers.JBossASKernel] and demands:
> 18:43:13,690 INFO [org.jboss.ejb3.deployers.JBossASKernel] jboss.ejb:service=EJBTimerService; Required: Described
> 18:43:13,690 INFO [org.jboss.ejb3.deployers.JBossASKernel] and supplies:
> 18:43:13,690 INFO [org.jboss.ejb3.deployers.JBossASKernel] jndi:null
> 18:43:13,691 INFO [org.jboss.ejb3.deployers.JBossASKernel] Class:org.jboss.resource.adapter.mail.inflow.MailListener
> 18:43:13,691 INFO [org.jboss.ejb3.deployers.JBossASKernel] Added bean(jboss.j2ee:ear=CTAEar.ear,jar=CTAEJB3.jar,name=MailBean,service=EJB3) to KernelDeployment of: CTAEJB3.jar
> 18:43:13,741 INFO [org.jboss.ejb3.EJBContainer] STARTED EJB: com.contactulater.ba.MailBean ejbName: MailBean
> ****snip****
> 18:44:13,749 INFO [STDOUT] DEBUG: JavaMail version 1.4.2
> 18:44:13,760 INFO [STDOUT] DEBUG: successfully loaded resource: /META-INF/javamail.default.providers
> 18:44:13,761 INFO [STDOUT] DEBUG: Tables of loaded providers
> 18:44:13,761 INFO [STDOUT] DEBUG: Providers Listed By Class Name: {com.sun.mail.smtp.SMTPSSLTransport=javax.mail.Provider ***snip***
> 18:44:13,763 INFO [STDOUT] DEBUG: successfully loaded resource: /META-INF/javamail.default.address.map
> 18:44:13,771 INFO [STDOUT] DEBUG: setDebug: JavaMail version 1.4.2
> 18:44:13,771 INFO [STDOUT] DEBUG: getProvider() returning javax.mail.Provider[STORE,imap,com.sun.mail.imap.IMAPStore,Sun Microsystems, Inc]
> 18:44:13,772 INFO [STDOUT] DEBUG: mail.imap.fetchsize: 16384
> 18:44:13,772 INFO [STDOUT] DEBUG: mail.imap.statuscachetimeout: 1000
> 18:44:13,773 INFO [STDOUT] DEBUG: mail.imap.appendbuffersize: -1
> 18:44:13,773 INFO [STDOUT] DEBUG: mail.imap.minidletime: 10
> 18:44:13,774 INFO [STDOUT] DEBUG: trying to connect to host "127.0.0.1", port 143, isSSL false
> 18:44:13,799 INFO [STDOUT] * OK **** Cyrus IMAP4 v2.2.13-Debian-2.2.13-19 server ready
> 18:44:13,800 INFO [STDOUT] A0 CAPABILITY
> 18:44:13,820 INFO [STDOUT] * CAPABILITY IMAP4 IMAP4rev1 ACL QUOTA LITERAL+ NAMESPACE UIDPLUS ID NO_ATOMIC_RENAME UNSELECT CHILDREN MULTIAPPEND BINARY SORT THREAD=ORDEREDSUBJECT THREAD=REFERENCES ANNOTATEMORE IDLE STARTTLS
> 18:44:13,821 INFO [STDOUT] A0 OK Completed
> 18:44:13,821 INFO [STDOUT] DEBUG: protocolConnect login, host=127.0.0.1, user=jbossra, password=<non-null>
> 18:44:13,844 INFO [STDOUT] A1 OK User logged in
> 18:44:13,845 INFO [STDOUT] A2 CAPABILITY
> 18:44:13,868 INFO [STDOUT] * CAPABILITY IMAP4 IMAP4rev1 ACL QUOTA LITERAL+ NAMESPACE UIDPLUS ID NO_ATOMIC_RENAME UNSELECT CHILDREN MULTIAPPEND BINARY SORT THREAD=ORDEREDSUBJECT THREAD=REFERENCES ANNOTATEMORE IDLE LOGINDISABLED
> 18:44:13,869 INFO [STDOUT] A2 OK Completed
> 18:44:13,870 INFO [STDOUT] A3 LIST "" INBOX
> 18:44:13,889 INFO [STDOUT] * LIST (\HasChildren) "." "INBOX"
> 18:44:13,890 INFO [STDOUT] A3 OK Completed (0.000 secs 4 calls)
> 18:44:13,891 INFO [STDOUT] DEBUG: connection available -- size: 1
> 18:44:13,891 INFO [STDOUT] A4 SELECT INBOX
> 18:44:13,973 INFO [STDOUT] * FLAGS (\Answered \Flagged \Draft \Deleted \Seen)
> 18:44:13,973 INFO [STDOUT] * OK [PERMANENTFLAGS (\Answered \Flagged \Draft \Deleted \Seen \*)]
> 18:44:13,973 INFO [STDOUT] * 2 EXISTS
> 18:44:13,974 INFO [STDOUT] * 0 RECENT
> 18:44:13,974 INFO [STDOUT] * OK [UIDVALIDITY 1288029487]
> 18:44:13,974 INFO [STDOUT] * OK [UIDNEXT 4]
> 18:44:13,974 INFO [STDOUT] A4 OK [READ-WRITE] Completed
> 18:44:13,974 INFO [STDOUT] A5 SEARCH UNSEEN ALL
> 18:44:13,993 INFO [STDOUT] * SEARCH
> 18:44:13,993 INFO [STDOUT] A5 OK Completed (0 msgs in 0.000 secs)
> 18:44:13,993 INFO [STDOUT] A6 CLOSE
> 18:44:14,138 INFO [STDOUT] A6 OK Completed
> 18:44:14,138 INFO [STDOUT] DEBUG: added an Authenticated connection -- size: 1
> 18:44:14,138 INFO [STDOUT] IMAP DEBUG: IMAPProtocol noop
> 18:44:14,138 INFO [STDOUT] A7 NOOP
> 18:44:14,156 INFO [STDOUT] A7 OK Completed
> 18:44:14,156 INFO [STDOUT] A8 LOGOUT
> 18:44:14,175 INFO [STDOUT] * BYE LOGOUT received
> 18:44:14,175 INFO [STDOUT] A8 OK Completed
> 18:44:14,176 INFO [STDOUT] DEBUG: IMAPStore connection dead
> 18:44:14,176 INFO [STDOUT] DEBUG: IMAPStore cleanup, force false
> 18:44:14,176 INFO [STDOUT] DEBUG: IMAPStore cleanup done
> MDB implementation:
> @MessageDriven(activationConfig={
> @ActivationConfigProperty(propertyName="mailServer", propertyValue="127.0.0.1"),
> @ActivationConfigProperty(propertyName="mailFolder", propertyValue="INBOX"),
> @ActivationConfigProperty(propertyName="storeProtocol", propertyValue="imap"),
> @ActivationConfigProperty(propertyName="userName", propertyValue="jbossra"),
> @ActivationConfigProperty(propertyName="password", propertyValue="****"),
> @ActivationConfigProperty(propertyName="debug", propertyValue="true"),
> @ActivationConfigProperty(propertyName="starttls", propertyValue="false"),
> @ActivationConfigProperty(propertyName="pollingInterval", propertyValue="60000")
> })
> @ResourceAdapter("mail-ra.rar")
> public class MailBean implements MailListener {
> public void onMessage(Message message) {
> // Process the message
> try {
> System.out.println("Message received:"+message.getSubject());
> } catch (MessagingException e) {
> e.printStackTrace();
> }
> }
>
> }
--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators: https://issues.jboss.org/secure/ContactAdministrators!default.jspa
For more information on JIRA, see: http://www.atlassian.com/software/jira
More information about the jboss-jira
mailing list