glassfish
  1. glassfish
  2. GLASSFISH-6816

Mail Debug Messages are written with INFO level (only some messages -- see comments)

    Details

    • Type: Bug Bug
    • Status: Open
    • Priority: Minor Minor
    • Resolution: Unresolved
    • Affects Version/s: 9.1peur2
    • Fix Version/s: future release
    • Component/s: mail
    • Labels:
      None
    • Environment:

      Operating System: All
      Platform: All

    • Issuezilla Id:
      6,816

      Description

      When enabling the Mail Debugging, then the debug messages are written using INFO
      level:

      [#|2008-11-19T17:01:53.330+0100|INFO|sun-appserver9.1|javax.enterprise.system.stream.out|_ThreadID=24;_ThreadName=p:
      thread-pool-1; w: 5;|
      DEBUG: not loading file: C:\Programme\Java\jdk1.6.0_10\jre\lib\javamail.providers|#]

      From the view of an administrator, this is the wrong level. Since it is DEBUG
      information, it should be logged using a level of FINE, FINER or FINEST.

      INFO should stay reserved for information of higher importance, to be able to
      separate "essential" from "just debug" information.

        Activity

        Hide
        Bill Shannon added a comment -

        I'm not sure why this is happening.

        When a JavaMail resource is created, it's configured to route its debug
        output through a stream that converts the output into log messages.
        The core of MailLogOutputStream is:

        if (msg.startsWith("DEBUG"))
        logger.log(Level.FINE, msg);
        else
        logger.log(Level.FINER, msg);

        Are you using a JavaMail Session configured as a resource? Or are you creating
        your own JavaMail Session and enabling debug output? In the latter case,
        perhaps the app server is collecting all output to System.out and turning it
        into log messages at INFO level?

        Show
        Bill Shannon added a comment - I'm not sure why this is happening. When a JavaMail resource is created, it's configured to route its debug output through a stream that converts the output into log messages. The core of MailLogOutputStream is: if (msg.startsWith("DEBUG")) logger.log(Level.FINE, msg); else logger.log(Level.FINER, msg); Are you using a JavaMail Session configured as a resource? Or are you creating your own JavaMail Session and enabling debug output? In the latter case, perhaps the app server is collecting all output to System.out and turning it into log messages at INFO level?
        Hide
        mkarg added a comment -

        I am solely using a mail session created using GlassFish Admin GUI as a resource
        and enabled debugging in the admin GUI by clicking the check box. I am neither
        creating my own mail session by API, nor am I enabling debugging by API. My code
        does nothing with the JavaMail API but just ask the injected javax.mail.Session
        to create a Message object, set subject, sender, receiver and body, and then
        call Transport.send(message). Nothing more.

        So I assume it is a bug in the GlassFish code that links JavaMail to the
        MailLogOutputStream?

        Show
        mkarg added a comment - I am solely using a mail session created using GlassFish Admin GUI as a resource and enabled debugging in the admin GUI by clicking the check box. I am neither creating my own mail session by API, nor am I enabling debugging by API. My code does nothing with the JavaMail API but just ask the injected javax.mail.Session to create a Message object, set subject, sender, receiver and body, and then call Transport.send(message). Nothing more. So I assume it is a bug in the GlassFish code that links JavaMail to the MailLogOutputStream?
        Hide
        mkarg added a comment -

        Increased priority to P3 according to
        https://glassfish.dev.java.net/public/IssueTrackerPriority.html as this bug is
        neither internal nor invisible. It leads to squandered time and money for the
        administrator. From an economic view this is not acceptable in a production
        environment.

        Show
        mkarg added a comment - Increased priority to P3 according to https://glassfish.dev.java.net/public/IssueTrackerPriority.html as this bug is neither internal nor invisible. It leads to squandered time and money for the administrator. From an economic view this is not acceptable in a production environment.
        Hide
        peterwx added a comment -

        V3 uses MailLogOutputStream and most JavaMail log messages are printed at FINE
        in that server. However, the first 5 or so messages are printed to the console.

        This is because they are printed in the javax.mail.Session constructor and V3
        doesn't redirect the debug output until after Session construction is finished.
        Log output looks like this:

        INFO: DEBUG: JavaMail version 1.4.2
        INFO: DEBUG: successfully loaded resource: /META-INF/javamail.default.providers
        INFO: DEBUG: Tables of loaded providers
        INFO: DEBUG: Providers Listed By Class Name: ...
        INFO: DEBUG: Providers Listed By Protocol: ...
        INFO: DEBUG: successfully loaded resource: /META-INF/javamail.default.address.map
        FINE: DEBUG: setDebug: JavaMail version 1.4.2
        FINE: DEBUG: getProvider() returning
        javax.mail.Provider[TRANSPORT,smtps,com.sun.mail.smtp.SMTPSSLTransport,Sun
        Microsystems, Inc]
        FINE: DEBUG SMTP: useEhlo true, useAuth true
        ...

        Show
        peterwx added a comment - V3 uses MailLogOutputStream and most JavaMail log messages are printed at FINE in that server. However, the first 5 or so messages are printed to the console. This is because they are printed in the javax.mail.Session constructor and V3 doesn't redirect the debug output until after Session construction is finished. Log output looks like this: INFO: DEBUG: JavaMail version 1.4.2 INFO: DEBUG: successfully loaded resource: /META-INF/javamail.default.providers INFO: DEBUG: Tables of loaded providers INFO: DEBUG: Providers Listed By Class Name: ... INFO: DEBUG: Providers Listed By Protocol: ... INFO: DEBUG: successfully loaded resource: /META-INF/javamail.default.address.map FINE: DEBUG: setDebug: JavaMail version 1.4.2 FINE: DEBUG: getProvider() returning javax.mail.Provider[TRANSPORT,smtps,com.sun.mail.smtp.SMTPSSLTransport,Sun Microsystems, Inc] FINE: DEBUG SMTP: useEhlo true, useAuth true ...
        Hide
        peterwx added a comment -

        V2.1 behaves similarly – initial messages (from javax.mail.Session constructor)
        are printed to the console. All subsequent messages are printed at FINE level.

        Annoying, but not as widespread as hinted at. Note this can still print quite a
        bit of information in production as mail sessions could be created quite
        frequently. This depends on user's application, but a mail session object could
        conceivably be created fresh for each usage of javamail.

        Show
        peterwx added a comment - V2.1 behaves similarly – initial messages (from javax.mail.Session constructor) are printed to the console. All subsequent messages are printed at FINE level. Annoying, but not as widespread as hinted at. Note this can still print quite a bit of information in production as mail sessions could be created quite frequently. This depends on user's application, but a mail session object could conceivably be created fresh for each usage of javamail.
        Hide
        peterwx added a comment -

        I'm lowering this to P4 based on the following reasons:

        The only messages written to the console by JavaMail (and thus logged at INFO
        level) are debug messages from the javax.mail.Session constructor (and possibly
        other messages logged during session construction or requisite static
        initialization).

        Further, this only happens if debug=true (or the properly "mail.debug=true") has
        been set in the mail resource.

        Once the mail session has been constructed, all subsequent mail debug messages
        will be logged at FINE or FINER as designed.

        The correct way to enable JavaMail debug messages in GlassFish is to set the
        GlassFish JavaMail log level to the appropriate setting for the domain
        configuration in question. There is a setting for this in the web based admin
        console or you can use asadmin.

        Do not set debug=true or add a "mail.debug=true" property in the mail resource
        unless you specifically want debug messages from session construction
        (occasionally useful, but not typically).

        Show
        peterwx added a comment - I'm lowering this to P4 based on the following reasons: The only messages written to the console by JavaMail (and thus logged at INFO level) are debug messages from the javax.mail.Session constructor (and possibly other messages logged during session construction or requisite static initialization). Further, this only happens if debug=true (or the properly "mail.debug=true") has been set in the mail resource. Once the mail session has been constructed, all subsequent mail debug messages will be logged at FINE or FINER as designed. The correct way to enable JavaMail debug messages in GlassFish is to set the GlassFish JavaMail log level to the appropriate setting for the domain configuration in question. There is a setting for this in the web based admin console or you can use asadmin. Do not set debug=true or add a "mail.debug=true" property in the mail resource unless you specifically want debug messages from session construction (occasionally useful, but not typically).
        Hide
        Bill Shannon added a comment -

        The full fix for this will only come when JavaMail is converted to
        use java.util.logging directly.

        Show
        Bill Shannon added a comment - The full fix for this will only come when JavaMail is converted to use java.util.logging directly.

          People

          • Assignee:
            Bill Shannon
            Reporter:
            mkarg
          • Votes:
            0 Vote for this issue
            Watchers:
            0 Start watching this issue

            Dates

            • Created:
              Updated: