Bugzilla – Full Text Bug Listing
| Summary: | cannot use ch.qos.logback.classic.net.SMTPAppender | ||||||||
|---|---|---|---|---|---|---|---|---|---|
| Product: | [RT] Virgo | Reporter: | Eric Hough <k2eric> | ||||||
| Component: | unknown | Assignee: | Steve Powell <zteve.powell> | ||||||
| Status: | CLOSED FIXED | QA Contact: | |||||||
| Severity: | normal | ||||||||
| Priority: | P3 | CC: | glyn.normington, zteve.powell | ||||||
| Version: | 2.1.0.M05-incubation | ||||||||
| Target Milestone: | 2.1.0.RELEASE | ||||||||
| Hardware: | All | ||||||||
| OS: | Linux | ||||||||
| Whiteboard: | |||||||||
| Attachments: |
|
||||||||
|
Description
Eric Hough
Created attachment 176372 [details]
stack trace of startup error
Here's a stack trace of the error you'll get on startup
Eric, Thank you for bringing this here. Back in January when you first reported this problem, Glyn suggested you try debugging the LogAppender code with a breakpoint in the AppenderAction.begin() method. I suppose you tried that (and got confused)? Because, as you say, of the way that logback is made available in Virgo, this is started very early on (before the Kernel Starting message!) and so we are at the mercy of logback's own diagnostic facilities to get information out about this problem. I will attempt to reproduce this. Incidentally, which version of Virgo did you reproduce this on? I note that the format of the logback entries has changed in the latest one, so the serviceability.xml you attached to the Forum will no longer work in the latest release. Steve, Thanks for acknowledging this issue. > Back in January when you first reported this problem, Glyn suggested you try > debugging the LogAppender code with a breakpoint in the AppenderAction.begin() > method. I suppose you tried that (and got confused)? That's exactly what I tried. I don't have the exact details of where I got lost, but I do remember that it was due to some heavy duty classloading weirdness. I remember exceptions due to missing classes (ClassNotFoundException I believe). > I will attempt to reproduce this. Incidentally, which version of Virgo did you > reproduce this on? I note that the format of the logback entries has changed > in the latest one, so the serviceability.xml you attached to the Forum will no > longer work in the latest release. I'm running 2.1.0.M02-incubation. I saw that the format for serviceability.xml has changed since, but it appears that SMTPAppender still just takes a Layout: http://logback.qos.ch/apidocs/ch/qos/logback/classic/net/SMTPAppender.html. So the relevant piece of the serviceability.xml that I posted remains the same. Let me know how else I can help out. Thanks as always. The failure diagnosis showed that a class could not be loaded/found in the mernel/Medic implementation. This, in turn was due to an optional import of the Medic core bundle not being resolved in the kernel region (in this case an import for javax.mail). To enable these appenders (and possibly others) the bundle supporting the imprts needs to be installed into the kernel region (during startup). This is a general user/admin task, since (at least in this case) it is tailoring the logging features of the kernel. Updates have been made to the user-guide documentation to describe how to include extra bundles in the kernel region, and this appender requirement is used as an example. ----------- In this case the bundle com.springsource.javax.mail-1.4.0.jar is first copied into the lib/kernel directory. Secondly the file is included in the launcher.bundles property in the org.eclipse.virgo.kernel.launch.properties file (which is in the lib directory). The reference and creation of the SMTPAppender will then work cleanly. An explanation is included in the documentation. ----------- The difficulty of diagnosing this problem is due to an insufficient diagnosis and exception report produced in org.eclipse.virgo.medic.log.impl.logback.JoranLoggerContextConfigurer. Bug 326030 is raised for this problem. Correction: mernel/Medic should read kernel/medic in comment 4. RC1 is planned instead of milestone 5. Closing off. We have captured follow-on activity to improve the diagnostics in bug 326030. Thank you for investigating and finding a fix for this! I made the changes I'm now able to start Virgo without the exception that I previously hit. However when I try to actually invoke the appender, it silently fails. Logback has decent JXM integration, as you probably know, and only in there did I find a new Exception: ERROR in ch.qos.logback.classic.net.SMTPAppender[EMAILER] - 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_0_1004182863.1285692844851" I haven't tried this on a fresh Virgo install, so that will be my next step. I'll report back with my findings. Just wanted to give you guys an update thus far. Thanks Eric. Keep in touch as you make progress. Just tested the fix on a fresh copy of Virgo Kernel (2.1.0.M05) and still no dice in getting the emails sent out. I'll attach a screenshot of the error message that I see through JMX. To enable JMX I simply added "<jmxConfigurator />" to config/serviceability.xml. I've verified that the logging statement is being invoked, as I'm appending the message to my serviceability/logs/log.log file as well. I can zip up my test Virgo installation and send it to you if you think it would help. Created attachment 180460 [details]
screenshot of error
Reopened for investigation of last reported problem. Changing target milestone to post 2.1.0 as any fix is now too late for 2.1.0. Managed to recreate the problem on my system. Googling the error message text: no object DCH for MIME type multipart/mixed we found the following link: http://www.mail-archive.com/server-user@james.apache.org/msg00305.html which has (in a reply) the note: 'FWIW, I understand that one cause of this problem is if mail.jar and activation.jar are loaded by different class loaders.' Looking at the wiring of javax.mail (using the osgi console attached to the kernel region -- simply put osgi.console=2402 in the kernel launch properties file, and telnet localhost 2402 from a shell) we see : osgi> ss Framework is launched. id State Bundle 0 ACTIVE org.eclipse.osgi_3.6.1.R36x_v20100806 1 ACTIVE com.springsource.slf4j.api_1.6.1 2 ACTIVE com.springsource.slf4j.org.apache.commons.logging_1.6.1 3 ACTIVE com.springsource.org.aspectj.weaver_1.6.6.RELEASE 4 RESOLVED com.springsource.javax.mail_1.4.0 . . . and so we look at the wiring of javax.mail (bundle 4)... osgi> bundle 4 com.springsource.javax.mail_1.4.0 [4] Id=4, Status=RESOLVED Data Root=/Users/spowell/dev/virgo/web-server/build-web-server/target/package-expanded/virgo-web-server-2.2.0.BUILD-20101021141341/work/osgi/configuration/org.eclipse.osgi/bundles/4/data No registered services. No services in use. Exported packages com.sun.mail.handlers; version="1.4.0"[exported] com.sun.mail.iap; version="1.4.0"[exported] com.sun.mail.imap; version="1.4.0"[exported] com.sun.mail.imap.protocol; version="1.4.0"[exported] com.sun.mail.pop3; version="1.4.0"[exported] com.sun.mail.smtp; version="1.4.0"[exported] com.sun.mail.util; version="1.4.0"[exported] javax.mail; version="1.4.0"[exported] javax.mail.event; version="1.4.0"[exported] javax.mail.internet; version="1.4.0"[exported] javax.mail.search; version="1.4.0"[exported] javax.mail.util; version="1.4.0"[exported] Imported packages javax.net; version="0.0.0"<org.eclipse.osgi_3.6.1.R36x_v20100806 [0]> javax.net.ssl; version="0.0.0"<org.eclipse.osgi_3.6.1.R36x_v20100806 [0]> javax.security.auth.callback; version="0.0.0"<org.eclipse.osgi_3.6.1.R36x_v20100806 [0]> javax.security.sasl; version="0.0.0"<org.eclipse.osgi_3.6.1.R36x_v20100806 [0]> javax.activation; version="1.1.1"<org.eclipse.osgi_3.6.1.R36x_v20100806 [0]> No fragment bundles Named class space com.springsource.javax.mail; bundle-version="1.4.0"[provided] No required bundles Whereupon we notice that packages javax.mail.* are exported but javax.activation is IMPORTED from the bundle called <org.eclipse.osgi_3.6.1.R36x_v20100806 [0]>. This is the system bundle [bundle id 0]. Therefore the packages are indeed coming from different classloaders. This might not be a problem for decent programs, but in this case it might really be a problem, so what do we do? Well, we can move the javax.mail packages so that they, too, are supplied by the system bundle --we go to the java6-server.profile (in the server_home/lib directory) and we see the list of packages that are to be exported by the system bundle (notice that javax.activation is in the list -- don't worry about the versioned and unversioned entry -- this is for technical reasons). So just under these entries we can add: javax.mail;version="1.4.0",\ javax.mail.event;version="1.4.0",\ javax.mail.internet;version="1.4.0",\ javax.mail.search;version="1.4.0",\ javax.mail.util;version="1.4.0",\ which are the relevant packages exported by com.springsource.javax.mail_1.4.0.jar. Now we need to remove javax.mail from the kernel launch properties and put the javax.mail jar in the lib directory (for the server profile to find it). And re-run the test! Lo I get an email message sent to me with the subject line equal to the message. (Admittedly not formatted terribly nicely, but that is a pattern problem, probably.) So, you should be able to get further by reconfiguring the kernel as I have shown here. Let me know if this helps. I'll close this, but feel free to reopen if this approach fails. Alright! I followed your steps exactly, and they were *nearly* 100% correct. The only thing I had to do differently is to copy com.springsource.javax.mail-1.4.0.jar into lib/launcher (in your steps you had just lib). I ran my test and got an email. Awesome! Couldn't have done this without your help. Thank you kindly. And thanks for your work on Virgo - we're really enjoying using it. (In reply to comment #15) > Alright! I followed your steps exactly, and they were *nearly* 100% correct. > The only thing I had to do differently is to copy > com.springsource.javax.mail-1.4.0.jar into lib/launcher (in your steps you had > just lib). I ran my test and got an email. Awesome! Thanks for pointing this out. Please note that lib/launcher only existed in milestone 5, so Steve's instructions are 100% correct except on milestone 5. (We moved the contents of lib/launcher back to lib from milestone 6 onwards in order to make the tooling work again.) > > Couldn't have done this without your help. Thank you kindly. Thanks to Steve for persisting at recreating this. Thanks Eric for raising the issue in the first place. It was good to see it finally working with only config changes and a nice side effect was improved documentation. > And thanks for your work on Virgo - we're really enjoying using it. You're welcome. That's the best possible compliment. :-) Changing target milestone to 2.1.0.RELEASE as the instructions provided apply to that release and do not require anything from the master branch. |