SMTPAppender OSGi-Problem within Glassfish v3.1.1 (Apache Felix)

[cinhtau]

Hi @all, I try to use SMTPAppender for logging errors to respective users via E-Mail in OSGi. My configuration is:

• OS: Ubuntu Linux 10.04.03 LTS
• Application Environment: Glassfish 3.1.1 using Apache Felix
• Logback: tried logback classic Version 0.29 and current Version 1.0 leading to same results

Glassfish has following bundles

g! lb mail
START LEVEL 10
   ID|State      |Level|Name
  227|Resolved   |    1|JavaMail API (1.4.4)

I write following BundleActivator (I switch the real addresses with stubs), sending an email via SMTPAppender and Java Mail from scratch.

package de.sgbs.log;

import java.util.logging.Level;

import javax.mail.Message;
import javax.mail.MessagingException;
import javax.mail.Session;
import javax.mail.Transport;
import javax.mail.internet.InternetAddress;
import javax.mail.internet.MimeMessage;

import org.osgi.framework.BundleActivator;
import org.osgi.framework.BundleContext;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.slf4j.Marker;
import org.slf4j.MarkerFactory;

import ch.qos.logback.classic.LoggerContext;
import ch.qos.logback.classic.joran.JoranConfigurator;
import ch.qos.logback.core.joran.spi.JoranException;

public class Activator implements BundleActivator {

    private final static Logger logger = LoggerFactory.getLogger(Activator.class); 

	@Override
	public void start(BundleContext context) throws Exception {
	    try {
	        LoggerContext lc = (LoggerContext) LoggerFactory.getILoggerFactory();
	        JoranConfigurator configurator = new JoranConfigurator();
	        configurator.setContext(lc);
	        lc.reset();
	        lc.putProperty("application-name", Activator.class.getSimpleName());
	        configurator.doConfigure("logback.xml");	        	       
	        Marker notifyAdmin = MarkerFactory.getMarker("NOTIFY_ADMIN");
	        logger.error(notifyAdmin,
	          "This is a serious an error requiring the admin's attention",
	           new Exception("Just testing"));
	        
	      } catch (JoranException ex) {
	        java.util.logging.Logger.getLogger(Activator.class.getName()).log(Level.SEVERE, null, ex);
	      }
	    
	    sendEMail();
	}

	private void sendEMail() throws MessagingException {
	    java.util.Properties props = new java.util.Properties();
        props.put("mail.smtp.host", "smtp");
        props.put("mail.smtp.port", "25");
        Session session = Session.getDefaultInstance(props, null);

        // Construct the message
        Message msg = new MimeMessage(session);
        msg.setFrom(new InternetAddress("[e-mail]"));
        msg.setRecipient(Message.RecipientType.TO, new InternetAddress("[e-mail]"));
        msg.setSubject("Test");
        msg.setText("Hello user, you got an error:");

        // Send the message
        Transport.send(msg);        
    }

    @Override
	public void stop(BundleContext context) {
	    logger.info("Goodbye Community!");
	}
}

My logback.xml

 
    
      NOTIFY_ADMIN
      TRANSACTION_FAILURE
    
    smtp
    [e-mail]
    
    [e-mail]
    TESTING: %logger{20} - %m
    
      %date %-5level %logger{35} - %message%n
           
  

Sending from scratch works. SMTPAppender raises an error. This error is given on the osgi console:

10:14:46,850 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [EMAIL] to Logger[ROOT]
10:14:47,048 |-ERROR in ch.qos.logback.classic.net.SMTPAppender[EMAIL] - Error occured while sending e-mail notification. javax.mail.MessagingException: IOException while sending message;
  nested exception is:
	javax.activation.UnsupportedDataTypeException: no object DCH for MIME type multipart/mixed; 
	boundary="----=_Part_5_17758761.1325668486851"
	at javax.mail.MessagingException: IOException while sending message
	at 	at com.sun.mail.smtp.SMTPTransport.sendMessage(SMTPTransport.java:1141)
	at 	at javax.mail.Transport.send0(Transport.java:195)
	at 	at javax.mail.Transport.send(Transport.java:124)
	at 	at ch.qos.logback.core.net.SMTPAppenderBase.sendBuffer(SMTPAppenderBase.java:343)
	at 	at ch.qos.logback.core.net.SMTPAppenderBase.append(SMTPAppenderBase.java:179)
	at 	at ch.qos.logback.core.AppenderBase.doAppend(AppenderBase.java:85)
	at 	at ch.qos.logback.core.spi.AppenderAttachableImpl.appendLoopOnAppenders(AppenderAttachableImpl.java:64)
	at 	at ch.qos.logback.classic.Logger.appendLoopOnAppenders(Logger.java:285)
	at 	at ch.qos.logback.classic.Logger.callAppenders(Logger.java:272)
	at 	at ch.qos.logback.classic.Logger.buildLoggingEventAndAppend(Logger.java:473)
	at 	at ch.qos.logback.classic.Logger.filterAndLog_0_Or3Plus(Logger.java:427)
	at 	at ch.qos.logback.classic.Logger.error(Logger.java:610)
	at 	at de.sgbs.log.Activator.start(Activator.java:37)
	at 	at org.apache.felix.framework.util.SecureAction.startActivator(SecureAction.java:629)
...
Caused by: javax.activation.UnsupportedDataTypeException: no object DCH for MIME type multipart/mixed; 
	boundary="----=_Part_5_17758761.1325668486851"
	at 	at javax.activation.ObjectDataContentHandler.writeTo(DataHandler.java:877)
	at 	at javax.activation.DataHandler.writeTo(DataHandler.java:302)
	at 	at javax.mail.internet.MimeBodyPart.writeTo(MimeBodyPart.java:1476)
	at 	at javax.mail.internet.MimeMessage.writeTo(MimeMessage.java:1772)
	at 	at com.sun.mail.smtp.SMTPTransport.sendMessage(SMTPTransport.java:1099)
	at 	... 47 common frames omitted
10:14:47,049 |-INFO in ch.qos.logback.classic.net.SMTPAppender[EMAIL] - SMTPAppender [EMAIL] is tracking [1] buffers

First I thought MIME type multipart/mixed is the cause. I checked my SMTP Server Settings, sending email is ok. I tried googlemail. It's working too. I found another resource with the same error message. Could it be an classloader problem? Could someone help me to pinpoint the problem? Thanks in advance.

[Thorbjørn Ravn Andersen-4]

Some parts of this message have been removed. Learn more about Nabble's security policy.

I did a google search for the exception text and found that this problem has been reported by others.  You might find

 

http://stackoverflow.com/questions/1969667/send-a-mail-from-java5-and-java6

 

relevant.

 

/Thorbjørn

 

From: logback-user-bounces@... [mailto:logback-user-bounces@...] On Behalf Of cinhtau
Sent: 4. januar 2012 11:14
To: logback-user@...
Subject: [logback-user] SMTPAppender OSGi-Problem within Glassfish v3.1.1 (Apache Felix)

 

Hi @all, I try to use SMTPAppender for logging errors to respective users via E-Mail in OSGi. My configuration is:

• OS: Ubuntu Linux 10.04.03 LTS
• Application Environment: Glassfish 3.1.1 using Apache Felix
• Logback: tried logback classic Version 0.29 and current Version 1.0 leading to same results

Glassfish has following bundles

g! lb mail

START LEVEL 10

   ID|State      |Level|Name

  227|Resolved   |    1|JavaMail API (1.4.4)

I write following BundleActivator (I switch the real addresses with stubs), sending an email via SMTPAppender and Java Mail from scratch.

package de.sgbs.log;

import java.util.logging.Level;

import javax.mail.Message;

import javax.mail.MessagingException;

import javax.mail.Session;

import javax.mail.Transport;

import javax.mail.internet.InternetAddress;

import javax.mail.internet.MimeMessage;

import org.osgi.framework.BundleActivator;

import org.osgi.framework.BundleContext;

import org.slf4j.Logger;

import org.slf4j.LoggerFactory;

import org.slf4j.Marker;

import org.slf4j.MarkerFactory;

import ch.qos.logback.classic.LoggerContext;

import ch.qos.logback.classic.joran.JoranConfigurator;

import ch.qos.logback.core.joran.spi.JoranException;

public class Activator implements BundleActivator {

    private final static Logger logger = LoggerFactory.getLogger(Activator.class); 

        @Override

        public void start(BundleContext context) throws Exception {

            try {

                LoggerContext lc = (LoggerContext) LoggerFactory.getILoggerFactory();

                JoranConfigurator configurator = new JoranConfigurator();

                configurator.setContext(lc);

                lc.reset();

                lc.putProperty("application-name", Activator.class.getSimpleName());

                configurator.doConfigure("logback.xml");                            

                Marker notifyAdmin = MarkerFactory.getMarker("NOTIFY_ADMIN");

                logger.error(notifyAdmin,

                  "This is a serious an error requiring the admin's attention",

                   new Exception("Just testing"));

              } catch (JoranException ex) {

                java.util.logging.Logger.getLogger(Activator.class.getName()).log(Level.SEVERE, null, ex);

              }

            sendEMail();

        }

        private void sendEMail() throws MessagingException {

            java.util.Properties props = new java.util.Properties();

        props.put("mail.smtp.host", "smtp");

        props.put("mail.smtp.port", "25");

        Session session = Session.getDefaultInstance(props, null);

        // Construct the message

        Message msg = new MimeMessage(session);

        msg.setFrom(new InternetAddress("me@..."));

        msg.setRecipient(Message.RecipientType.TO, new InternetAddress("foo@..."));

        msg.setSubject("Test");

        msg.setText("Hello user, you got an error:");

        // Send the message

        Transport.send(msg);        

    }

    @Override

        public void stop(BundleContext context) {

            logger.info("Goodbye Community!");

        }

}

My logback.xml

      NOTIFY_ADMIN

      TRANSACTION_FAILURE

    smtp

    foo@...

    me@...

    TESTING: %logger{20} - %m

      %date %-5level %logger{35} - %message%n

Sending from scratch works. SMTPAppender raises an error. This error is given on the osgi console:

10:14:46,850 |-INFO in ch.qos.logback.core.joran.action.AppenderRefAction - Attaching appender named [EMAIL] to Logger[ROOT]

10:14:47,048 |-ERROR in ch.qos.logback.classic.net.SMTPAppender[EMAIL] - Error occured while sending e-mail notification. javax.mail.MessagingException: IOException while sending message;

  nested exception is:

        javax.activation.UnsupportedDataTypeException: no object DCH for MIME type multipart/mixed; 

        boundary="----=_Part_5_17758761.1325668486851"

        at javax.mail.MessagingException: IOException while sending message

        at      at com.sun.mail.smtp.SMTPTransport.sendMessage(SMTPTransport.java:1141)

        at      at javax.mail.Transport.send0(Transport.java:195)

        at      at javax.mail.Transport.send(Transport.java:124)

        at      at ch.qos.logback.core.net.SMTPAppenderBase.sendBuffer(SMTPAppenderBase.java:343)

        at      at ch.qos.logback.core.net.SMTPAppenderBase.append(SMTPAppenderBase.java:179)

        at      at ch.qos.logback.core.AppenderBase.doAppend(AppenderBase.java:85)

        at      at ch.qos.logback.core.spi.AppenderAttachableImpl.appendLoopOnAppenders(AppenderAttachableImpl.java:64)

        at      at ch.qos.logback.classic.Logger.appendLoopOnAppenders(Logger.java:285)

        at      at ch.qos.logback.classic.Logger.callAppenders(Logger.java:272)

        at      at ch.qos.logback.classic.Logger.buildLoggingEventAndAppend(Logger.java:473)

        at      at ch.qos.logback.classic.Logger.filterAndLog_0_Or3Plus(Logger.java:427)

        at      at ch.qos.logback.classic.Logger.error(Logger.java:610)

        at      at de.sgbs.log.Activator.start(Activator.java:37)

        at      at org.apache.felix.framework.util.SecureAction.startActivator(SecureAction.java:629)

...

Caused by: javax.activation.UnsupportedDataTypeException: no object DCH for MIME type multipart/mixed; 

        boundary="----=_Part_5_17758761.1325668486851"

        at      at javax.activation.ObjectDataContentHandler.writeTo(DataHandler.java:877)

        at      at javax.activation.DataHandler.writeTo(DataHandler.java:302)

        at      at javax.mail.internet.MimeBodyPart.writeTo(MimeBodyPart.java:1476)

        at      at javax.mail.internet.MimeMessage.writeTo(MimeMessage.java:1772)

        at      at com.sun.mail.smtp.SMTPTransport.sendMessage(SMTPTransport.java:1099)

        at      ... 47 common frames omitted

10:14:47,049 |-INFO in ch.qos.logback.classic.net.SMTPAppender[EMAIL] - SMTPAppender [EMAIL] is tracking [1] buffers

First I thought MIME type multipart/mixed is the cause. I checked my SMTP Server Settings, sending email is ok. I tried googlemail. It's working too. I found another resource with the same error message. Could it be an classloader problem? Could someone help me to pinpoint the problem? Thanks in advance.

---

View this message in context: SMTPAppender OSGi-Problem within Glassfish v3.1.1 (Apache Felix)
Sent from the Logback User mailing list archive at Nabble.com.

_______________________________________________
Logback-user mailing list
Logback-user@...
http://mailman.qos.ch/mailman/listinfo/logback-user

[cinhtau]

Thorbjørn Ravn Andersen-4 wrote:

I did a google search for the exception text and found that this problem has
been reported by others.  You might find

http://stackoverflow.com/questions/1969667/send-a-mail-from-java5-and-java6
relevant.

Thorbjørn

Thank you. But this isn't the core problem

I add the option -Djavax.activation.debug=true and this is printed out.
<pre>
14:57:55,872 |-INFO in ch.qos.logback.classic.net.SMTPAppender[EMAIL] - SMTPAppender [EMAIL] is tracking [1] buffers
MailcapCommandMap: createDataContentHandler for text/plain
  search DB #1
  search fallback DB #1
MailcapCommandMap: createDataContentHandler for text/plain
  search DB #1
  search fallback DB #1
MailcapCommandMap: createDataContentHandler for multipart/mixed
  search DB #1
  search fallback DB #1
14:57:55,913 |-ERROR in ch.qos.logback.classic.net.SMTPAppender[EMAIL] - Error occurred while sending e-mail notification. javax.mail.MessagingException: IOException while sending message;
  nested exception is:
        javax.activation.UnsupportedDataTypeException: no object DCH for MIME type multipart/mixed;
        boundary="----=_Part_4_29409898.1325685475873"
        at javax.mail.MessagingException: IOException while sending message
        at at com.sun.mail.smtp.SMTPTransport.sendMessage(SMTPTransport.java:1141)
        at at javax.mail.Transport.send0(Transport.java:195)
        at at javax.mail.Transport.send(Transport.java:124)
        at at ch.qos.logback.core.net.SMTPAppenderBase.sendBuffer(SMTPAppenderBase.java:352)
        at at ch.qos.logback.core.net.SMTPAppenderBase$SenderRunnable.run(SMTPAppenderBase.java:600)
        at at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
        at at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
        at at java.lang.Thread.run(Thread.java:662)
Caused by: javax.activation.UnsupportedDataTypeException: no object DCH for MIME type multipart/mixed;
        boundary="----=_Part_4_29409898.1325685475873"
        at at javax.activation.ObjectDataContentHandler.writeTo(DataHandler.java:877)
        at at javax.activation.DataHandler.writeTo(DataHandler.java:302)
        at at javax.mail.internet.MimeBodyPart.writeTo(MimeBodyPart.java:1476)
        at at javax.mail.internet.MimeMessage.writeTo(MimeMessage.java:1772)
        at at com.sun.mail.smtp.SMTPTransport.sendMessage(SMTPTransport.java:1099)
        at ... 7 common frames omitted
</pre>

As I told, sending from scratch is ok. If I use SMTPAppender it might be a classloading problem of SMTPAppender, or at least I assume it. Have to look at the source (ch.qos.logback.core.net.SMTPAppenderBase.sendBuffer(SMTPAppenderBase.java:352)) then.