I coded an IMAP handler and an event listener as I understood it should be done, but I don't see any events firing, despite filling up the inbox with new emails. What could be my problem?
I set up the store to idle until someone closes the mailbox:
public void run() {
boolean logged = false;
synchronized (emailListener) {
while (!isCancelled) {
try {
if (isListening) {
throw new EtlSystemException(
null,
"Disallowed attempt to "
+ "start email listener - listening status already set",
null, null);
} else {
isListening = true;
}
if (imapProperties == null) {
imapProperties = new Properties();
imapProperties.put("mail.debug", "true");
}
Session session =
javax.mail.Session.getInstance(imapProperties);
session.setDebug(true);
store = (IMAPStore) session.getStore(imapProtocol);
store.connect(imapHost, imapUser, imapPassword);
inbox = (IMAPFolder) store.getFolder("INBOX");
if (inbox == null) {
throw new NonEtlSystemException(null, "No inbox in "
+ this.imapUser,
null, null);
}
inbox.open(Folder.READ_WRITE);
inbox.addMessageCountListener(emailListener);
// While the listener is registered, we loop over idle().
// Only stop if the inbox is closed, or thread interrupted
while (inbox.isOpen()) {
log.debug("store idling...");
inbox.idle();
}
// if any system errors occur processing the emails, stop
// the thread
if (!emailListener.getStatusOK()) {
break;
}
} catch (MessagingException e) {
lastThrowable = e;
} catch (Throwable throwable) {
lastThrowable = throwable;
break;
} finally {
close();
if (lastThrowable != null) {
if (!logged) {
EtlAlert alert = new EtlAlert(lastThrowable);
log.error(alert.getSysLogText(),
alert.getThrowable());
auditLogService.addEvent(alert.getEcnCode(),
alert.getEcnName(),
new Date(),
alert.getUserGpn(),
alert.getUserName(),
alert.getEventType(),
alert.getAuditLogText());
logged = true;
}
if (lastThrowable instanceof MessagingException) {
try {
log.info("Waiting for IMAP server recovery ... "
+ "checks every " + WAIT_AT_IMAP_ERROR
+ "ms ");
Thread.sleep(WAIT_AT_IMAP_ERROR);
} catch (InterruptedException e1) {
}
}
}
}
}
}
log.debug("thread dying now");
}
and this is how I'm testing it:
@Test
public void testImapHandler() {
try {
// launch ImapHandler
ImapHandler imapHandler =
new ImapHandler(new EmailListener());
imapHandler.setConfig(host, protocol, imapUser, imapPass);
// now the listener starts listening in a separate thread
Thread test = new Thread(imapHandler, "ImapHandler");
test.start();
// send a test email to inbox
int startCount = imapHandler.getProcessedMessageCount();
sendTestEmail();
// wait for a bit
Thread.sleep(60000);
// stop it
log.debug("stopping listener on thread [" + test.getName() + "]");
test.interrupt();
imapHandler.closeAndTerminate(); // this forces it out of idling
test.join();
// test listener count to see if it raised an email event
int finalCount = imapHandler.getProcessedMessageCount();
assertNotSame("start with " + startCount + ", ended with "
+ finalCount, startCount, finalCount);
} catch (final InterruptedException e) {
}
}
The imapHandler.closeAndTerminate() method closes the inbox and store, which forces store.idle() to stop blocking. The IMAPHandler class is used as a singleton and the store and inbox are kept as memvars, just for this purpose.
This is the debug log from the IMAP session:
DEBUG: JavaMail version 1.5.0-b01
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,Oracle], com.sun.mail.smtp.SMTPTransport=javax.mail.Provider[TRANSPORT,smtp,com.sun.mail.smtp.SMTPTransport,Oracle], com.sun.mail.imap.IMAPSSLStore=javax.mail.Provider[STORE,imaps,com.sun.mail.imap.IMAPSSLStore,Oracle], com.sun.mail.pop3.POP3SSLStore=javax.mail.Provider[STORE,pop3s,com.sun.mail.pop3.POP3SSLStore,Oracle], com.sun.mail.imap.IMAPStore=javax.mail.Provider[STORE,imap,com.sun.mail.imap.IMAPStore,Oracle], com.sun.mail.pop3.POP3Store=javax.mail.Provider[STORE,pop3,com.sun.mail.pop3.POP3Store,Oracle]}
DEBUG: Providers Listed By Protocol: {imaps=javax.mail.Provider[STORE,imaps,com.sun.mail.imap.IMAPSSLStore,Oracle], imap=javax.mail.Provider[STORE,imap,com.sun.mail.imap.IMAPStore,Oracle], smtps=javax.mail.Provider[TRANSPORT,smtps,com.sun.mail.smtp.SMTPSSLTransport,Oracle], pop3=javax.mail.Provider[STORE,pop3,com.sun.mail.pop3.POP3Store,Oracle], pop3s=javax.mail.Provider[STORE,pop3s,com.sun.mail.pop3.POP3SSLStore,Oracle], smtp=javax.mail.Provider[TRANSPORT,smtp,com.sun.mail.smtp.SMTPTransport,Oracle]}
DEBUG: successfully loaded resource: /META-INF/javamail.default.address.map
DEBUG: setDebug: JavaMail version 1.5.0-b01
DEBUG: getProvider() returning javax.mail.Provider[STORE,imaps,com.sun.mail.imap.IMAPSSLStore,Oracle]
DEBUG IMAPS: mail.imap.fetchsize: 16384
DEBUG IMAPS: mail.imap.ignorebodystructuresize: false
DEBUG IMAPS: mail.imap.statuscachetimeout: 1000
DEBUG IMAPS: mail.imap.appendbuffersize: -1
DEBUG IMAPS: mail.imap.minidletime: 10
DEBUG IMAPS: disable AUTH=PLAIN
DEBUG IMAPS: disable AUTH=NTLM
DEBUG IMAPS: trying to connect to host "webmail", port 993, isSSL true
* OK The Microsoft Exchange IMAP4 service is ready.
A0 CAPABILITY
* CAPABILITY IMAP4 IMAP4rev1 AUTH=NTLM AUTH=GSSAPI AUTH=PLAIN UIDPLUS CHILDREN IDLE NAMESPACE LITERAL+
A0 OK CAPABILITY completed.
DEBUG IMAPS: AUTH: NTLM
DEBUG IMAPS: AUTH: GSSAPI
DEBUG IMAPS: AUTH: PLAIN
DEBUG IMAPS: protocolConnect login, host=webmail, user=826, password=<non-null>
DEBUG IMAPS: LOGIN command trace suppressed
DEBUG IMAPS: LOGIN command result: A1 OK LOGIN completed.
A2 CAPABILITY
* CAPABILITY IMAP4 IMAP4rev1 AUTH=NTLM AUTH=GSSAPI AUTH=PLAIN UIDPLUS CHILDREN IDLE NAMESPACE LITERAL+
A2 OK CAPABILITY completed.
DEBUG IMAPS: AUTH: NTLM
DEBUG IMAPS: AUTH: GSSAPI
DEBUG IMAPS: AUTH: PLAIN
DEBUG IMAPS: connection available -- size: 1
A3 SELECT INBOX
* 42 EXISTS
* 2 RECENT
* FLAGS (\Seen \Answered \Flagged \Deleted \Draft $MDNSent)
* OK [PERMANENTFLAGS (\Seen \Answered \Flagged \Deleted \Draft $MDNSent)] Permanent flags
* OK [UNSEEN 3] Is the first unseen message
* OK [UIDVALIDITY 71441] UIDVALIDITY value
* OK [UIDNEXT 46] The next unique identifier value
A3 OK [READ-WRITE] SELECT completed.
17:54:34.132 [ImapHandler] DEBUG (ImapHandler.java:205) runListener() - store idling...
A4 IDLE
+ IDLE accepted, awaiting DONE command.
* 35 FETCH (FLAGS (\Seen))
17:55:33.320 [main] DEBUG (ImapTest.java:96) testImapHandler() - stopping listener on thread [ImapHandler]
DONE
A4 OK IDLE completed.
DEBUG IMAPS: IMAPProtocol noop
A5 NOOP
A5 OK NOOP completed.
A6 CLOSE
A6 OK CLOSE completed.
DEBUG IMAPS: added an Authenticated connection -- size: 1
DEBUG IMAPS: IMAPProtocol noop
A7 NOOP
A7 OK NOOP completed.
A8 LOGOUT
* BYE Microsoft Exchange Server 2010 IMAP4 server signing off.
A8 OK LOGOUT completed.
DEBUG IMAPS: IMAPStore connection dead
DEBUG IMAPS: IMAPStore cleanup, force false
DEBUG IMAPS: IMAPStore cleanup done
17:55:33.342 [ImapHandler] DEBUG (ImapHandler.java:188) run() - thread dying now
You can see from the log4j log statements in between the IMAP logging that the Store.idle() command was running for a full minute, during which time the test email was sent by the test thread.
Any other relevant info I can think of:
Exchange 2010
Tomcat 7
Javamail 1.5.0-b01
jdk 1.7.0-55
