Discussion:
[Classpathx-javamail] Bug: duplicate message ids
Boris Folgmann
2007-04-26 08:26:01 UTC
Permalink
Hi,

I'm using log4j-1.2.13 in a tomcat webapp. I've configured log4j to send an
email for errors of category ERROR and higher. Our old configuration was
SUN's javamail-1.3.1-2jpp and tomcat5-5.0.30-11jpp. The generated message
ids were of the format

30810565.1172372608329.JavaMail.tomcat4@<fqdn of the server>

tomcat4 is the UNIX user of the tomcat5 installation. The numbers were
constantly changing, so we had no duplicate message ids.

No we moved to a new system where we use classpathx-mail-1.1-1jpp and
tomcat55-5.5.17-4jpp. The format of the message ids is now

1677625.1177554343570.JavaMail.tomcat@<only hostname of the server>

tomcat is the UNIX user of the tomcat55 installation. The numbers are not
constantly changing, so we have lots of duplicate message ids.
The problem is, that my cyrus-imapd eliminates all mails with the same
message id, so we're losing a lot of mails here.

As I don't know who creates these message ids I'm asking you if that could
be a javamail problem or a log4j problem.

Best regards,
boris
Chris Burdess
2007-04-26 08:59:46 UTC
Permalink
Post by Boris Folgmann
I'm using log4j-1.2.13 in a tomcat webapp. I've configured log4j to
send an email for errors of category ERROR and higher. Our old
configuration was
SUN's javamail-1.3.1-2jpp and tomcat5-5.0.30-11jpp. The generated
message ids were of the format
tomcat4 is the UNIX user of the tomcat5 installation. The numbers
were constantly changing, so we had no duplicate message ids.
No we moved to a new system where we use classpathx-mail-1.1-1jpp
and tomcat55-5.5.17-4jpp. The format of the message ids is now
tomcat is the UNIX user of the tomcat55 installation. The numbers
are not constantly changing, so we have lots of duplicate message ids.
The problem is, that my cyrus-imapd eliminates all mails with the
same message id, so we're losing a lot of mails here.
As I don't know who creates these message ids I'm asking you if
that could be a javamail problem or a log4j problem.
It looks like it could be a JavaMail problem. The message-id is
generated as a result of a call to the updateHeaders() method, and
should be unique for each message instance.

I can update the algorithm to use the FQDN of the host, that's not a
problem (although it means that GNU JavaMail will rely on Java 1.4 or
later, I don't think that will be a problem for most people).

If the second number is not changing, that indicates a much more
serious problem. Could you give an example of the code you're using
to create and send the messages? You're not reusing MimeMessage
object instances?
Boris Folgmann
2007-04-26 09:55:38 UTC
Permalink
Hi Chris,
Post by Chris Burdess
I can update the algorithm to use the FQDN of the host, that's not a
problem (although it means that GNU JavaMail will rely on Java 1.4 or
later, I don't think that will be a problem for most people).
Yes please, I think that would be a good idea.
Post by Chris Burdess
If the second number is not changing, that indicates a much more
serious problem. Could you give an example of the code you're using
to create and send the messages? You're not reusing MimeMessage
object instances?
Both numbers (before and after the dot) are not changing, that's why there
are real duplicate ids. It's not my code, but I found the right method in
org.apache.log4j.net.SMTPAppender I think:

/**
Send the contents of the cyclic buffer as an e-mail message.
*/
protected
void sendBuffer() {

// Note: this code already owns the monitor for this
// appender. This frees us from needing to synchronize on 'cb'.
try {
MimeBodyPart part = new MimeBodyPart();

StringBuffer sbuf = new StringBuffer();
String t = layout.getHeader();
if(t != null)
sbuf.append(t);
int len = cb.length();
for(int i = 0; i < len; i++) {
//sbuf.append(MimeUtility.encodeText(layout.format(cb.get())));
LoggingEvent event = cb.get();
sbuf.append(layout.format(event));
if(layout.ignoresThrowable()) {
String[] s = event.getThrowableStrRep();
if (s != null) {
for(int j = 0; j < s.length; j++) {
sbuf.append(s[j]);
}
}
}
}
t = layout.getFooter();
if(t != null)
sbuf.append(t);
part.setContent(sbuf.toString(), layout.getContentType());

Multipart mp = new MimeMultipart();
mp.addBodyPart(part);
msg.setContent(mp);

msg.setSentDate(new Date());
Transport.send(msg);
} catch(Exception e) {
LogLog.error("Error occured while sending e-mail notification.", e);
}
}
Chris Burdess
2007-04-26 10:17:44 UTC
Permalink
Post by Boris Folgmann
Post by Chris Burdess
I can update the algorithm to use the FQDN of the host, that's not
a problem (although it means that GNU JavaMail will rely on Java
1.4 or later, I don't think that will be a problem for most people).
Yes please, I think that would be a good idea.
Post by Chris Burdess
If the second number is not changing, that indicates a much more
serious problem. Could you give an example of the code you're
using to create and send the messages? You're not reusing
MimeMessage object instances?
Both numbers (before and after the dot) are not changing, that's
why there are real duplicate ids. It's not my code, but I found the
...
Multipart mp = new MimeMultipart();
mp.addBodyPart(part);
msg.setContent(mp);
msg.setSentDate(new Date());
Transport.send(msg);
It looks like the same message object is being reused.

I have committed a patch which should solve both these problems,
please could you test with CVS HEAD?
Boris Folgmann
2007-04-26 13:10:07 UTC
Permalink
Hi Chris,
Post by Chris Burdess
I have committed a patch which should solve both these problems,
please could you test with CVS HEAD?
Could you send me a patch against:
http://ftp.gnu.org/gnu/classpathx/mail-1.1.tar.gz
http://ftp.gnu.org/gnu/classpath/inetlib-1.1.1.tar.gz

This would be easier for me. I could simply rebuild the
classpathx-mail-1.1-1jpp RPM after including the patch. If it works, I
could then send it to jpackage.org, so that they can release the updated RPM.

cu,
boris
Chris Burdess
2007-04-26 13:25:27 UTC
Permalink
Post by Chris Burdess
I have committed a patch which should solve both these problems,
please could you test with CVS HEAD?
Could you send me a patch against: http://ftp.gnu.org/gnu/
classpathx/mail-1.1.tar.gz
http://ftp.gnu.org/gnu/classpath/inetlib-1.1.1.tar.gz
Not easily, no, not without first making a release. And I would
prefer that this gets tested first and resolves your problems before
I make a release.

You can get CVS HEAD just by doing

cvs -z3 -d:pserver:***@cvs.savannah.gnu.org:/sources/
classpathx co mail

and just build and install exactly like the TGZ.
Boris Folgmann
2007-04-27 17:09:22 UTC
Permalink
Post by Chris Burdess
Not easily, no, not without first making a release. And I would
prefer that this gets tested first and resolves your problems before
I make a release.
Tested! The hostname is now fqdn and both numbers are changing on each sent
email. But sometimes the first number is negative, e.g. -1585811037.
Overseen something in the random number code or ok?

cu,
boris
Chris Burdess
2007-04-28 07:12:31 UTC
Permalink
Post by Boris Folgmann
Tested! The hostname is now fqdn and both numbers are changing on each sent
email. But sometimes the first number is negative, e.g. -1585811037.
Overseen something in the random number code or ok?
I've fixed that too. I'll make a point release this weekend.
--
Chris Burdess
Boris Folgmann
2007-04-26 12:55:50 UTC
Permalink
Hi,
Post by Chris Burdess
to create and send the messages? You're not reusing MimeMessage
object instances?
Yes, log4j does it! msg is a member variable of SMTPAppender.
They initialize it once when the log4j user calls activateOptions() which
has to be done after setting all options on the appender but before
starting to log. See source below.

Our webapp also sends mail by itself, but doesn't reuse the MimeMessage
objects. Our message ids are unique, so your guess was right!
Our code is old, but IIRC think we've chosen to use local MimeMessage
objects so that the application scales well, since it's multi-threaded. But
is there also a restriction in the JavaMail specification, that is violated
by log4j by reusing the MimeMessage object?

If not, I suppose that Transport.send() should set the message id on each call.

Here's their code:

/**
Activate the specified options, such as the smtp host, the
recipient, from, etc. */
public
void activateOptions() {
Properties props = new Properties (System.getProperties());
if (smtpHost != null)
props.put("mail.smtp.host", smtpHost);


Session session = Session.getInstance(props, null);
//session.setDebug(true);
msg = new MimeMessage(session);

try {
if (from != null)
msg.setFrom(getAddress(from));
else
msg.setFrom();

msg.setRecipients(Message.RecipientType.TO, parseAddress(to));
if(subject != null)
msg.setSubject(subject);
} catch(MessagingException e) {
LogLog.error("Could not activate SMTPAppender options.", e );
}
}

cu,
boris
Loading...