Skip to main content

Advanced Debugging of SMTP Protocol Inside Sonatype Lifecycle IQ Server

Updated

Sonatype server products have features that send email messages using SMTP.

A server administrator might need a way to perform low level diagnosis of issues encountered sending these messages, from within our products.

Enabling Sonatype Server SMTP Logging

Sonatype server products send email using using Java Mail APIs. These APIs have a standard mechanism to turn on low level logging using system properties.

The general steps to enable this logging are:

Configure Java system properties and restart the Sonatype product. 
The following JavaMail system properties take boolean values: "true" or "false

Name Description
mail.debug The initial debug mode. Default is false.
mail.debug.auth Include protocol authentication commands (including usernames and passwords) in the debug output. Default is false.
mail.debug.auth.username Include the user name in non-protocol debug output. Default is true.
mail.debug.auth.password Include the password in non-protocol debug output. Default is false.


IMPORTANT: If you set the system property mail.debug.auth.password=true, then that this can actually log the plain text password the SMTP request is sending to your mail server into the Sonatype server application log.
System properties are specified as part of the "java" command used to launch the product.

java -Dmail.debug=true ...

Sample appication logging:

2021-12-02 14:17:09,455-0400 DEBUG [dw-102 - POST /api/v2/config/mail/test/test%40example.com?timestamp=1638469029434] admin com.sonatype.insight.brain.service.InsightMail - Sending mail to test@example.com using server 127.0.0.1:1025.
2021-12-02 14:17:09,514-0400 DEBUG [dw-102 - POST /api/v2/config/mail/test/test%40example.com?timestamp=1638469029434] admin com.sun.mail.smtp - need username and password for authentication
2021-12-02 14:17:09,514-0400 DEBUG [dw-102 - POST /api/v2/config/mail/test/test%40example.com?timestamp=1638469029434] admin com.sun.mail.smtp - protocolConnect returning false, host=127.0.0.1, user=example, password=null
2021-12-02 14:17:09,514-0400 DEBUG [dw-102 - POST /api/v2/config/mail/test/test%40example.com?timestamp=1638469029434] admin com.sun.mail.smtp - useEhlo true, useAuth true
2021-12-02 14:17:09,515-0400 DEBUG [dw-102 - POST /api/v2/config/mail/test/test%40example.com?timestamp=1638469029434] admin com.sun.mail.smtp - trying to connect to host "127.0.0.1", port 1025, isSSL false
2021-12-02 14:17:09,519-0400 DEBUG [dw-102 - POST /api/v2/config/mail/test/test%40example.com?timestamp=1638469029434] admin com.sun.mail.util.socket - getSocket, host 127.0.0.1, port 1025, prefix mail.smtp, useSSL false
2021-12-02 14:17:09,519-0400 TRACE [dw-102 - POST /api/v2/config/mail/test/test%40example.com?timestamp=1638469029434] admin com.sun.mail.util.socket - create socket: prefix mail.smtp, localaddr null, localport 0, host 127.0.0.1, port 1025, connection timeout 60000, timeout 60000, socket factory null, useSSL false
2021-12-02 14:17:09,520-0400 TRACE [dw-102 - POST /api/v2/config/mail/test/test%40example.com?timestamp=1638469029434] admin com.sun.mail.util.socket - set socket read timeout 60000
2021-12-02 14:17:09,520-0400 TRACE [dw-102 - POST /api/v2/config/mail/test/test%40example.com?timestamp=1638469029434] admin com.sun.mail.util.socket - connecting...
2021-12-02 14:17:09,520-0400 TRACE [dw-102 - POST /api/v2/config/mail/test/test%40example.com?timestamp=1638469029434] admin com.sun.mail.util.socket - success!
2021-12-02 14:17:09,524-0400 TRACE [dw-102 - POST /api/v2/config/mail/test/test%40example.com?timestamp=1638469029434] admin com.sun.mail.smtp.protocol - 220 mailhog.example ESMTP MailHog
2021-12-02 14:17:09,524-0400 DEBUG [dw-102 - POST /api/v2/config/mail/test/test%40example.com?timestamp=1638469029434] admin com.sun.mail.smtp - connected to host "127.0.0.1", port: 1025
2021-12-02 14:17:09,527-0400 TRACE [dw-102 - POST /api/v2/config/mail/test/test%40example.com?timestamp=1638469029434] admin com.sun.mail.smtp.protocol - EHLO localhost
2021-12-02 14:17:09,530-0400 TRACE [dw-102 - POST /api/v2/config/mail/test/test%40example.com?timestamp=1638469029434] admin com.sun.mail.smtp.protocol - 250-Hello localhost
2021-12-02 14:17:09,530-0400 TRACE [dw-102 - POST /api/v2/config/mail/test/test%40example.com?timestamp=1638469029434] admin com.sun.mail.smtp.protocol - 250-PIPELINING
2021-12-02 14:17:09,530-0400 TRACE [dw-102 - POST /api/v2/config/mail/test/test%40example.com?timestamp=1638469029434] admin com.sun.mail.smtp.protocol - 250 AUTH PLAIN
2021-12-02 14:17:09,530-0400 DEBUG [dw-102 - POST /api/v2/config/mail/test/test%40example.com?timestamp=1638469029434] admin com.sun.mail.smtp - Found extension "PIPELINING", arg ""
2021-12-02 14:17:09,531-0400 DEBUG [dw-102 - POST /api/v2/config/mail/test/test%40example.com?timestamp=1638469029434] admin com.sun.mail.smtp - Found extension "AUTH", arg "PLAIN"
2021-12-02 14:17:09,531-0400 DEBUG [dw-102 - POST /api/v2/config/mail/test/test%40example.com?timestamp=1638469029434] admin com.sun.mail.smtp - protocolConnect login, host=127.0.0.1, user=admin, password=admin123
2021-12-02 14:17:09,531-0400 DEBUG [dw-102 - POST /api/v2/config/mail/test/test%40example.com?timestamp=1638469029434] admin com.sun.mail.smtp - Attempt to authenticate using mechanisms: LOGIN PLAIN DIGEST-MD5 NTLM XOAUTH2
2021-12-02 14:17:09,531-0400 DEBUG [dw-102 - POST /api/v2/config/mail/test/test%40example.com?timestamp=1638469029434] admin com.sun.mail.smtp - mechanism LOGIN not supported by server
2021-12-02 14:17:09,532-0400 DEBUG [dw-102 - POST /api/v2/config/mail/test/test%40example.com?timestamp=1638469029434] admin com.sun.mail.smtp - Using mechanism PLAIN
2021-12-02 14:17:09,532-0400 TRACE [dw-102 - POST /api/v2/config/mail/test/test%40example.com?timestamp=1638469029434] admin com.sun.mail.smtp.protocol - AUTH PLAIN YWRtaW4AYWRtaW4AYWRtaW4xMjM=
2021-12-02 14:17:09,535-0400 TRACE [dw-102 - POST /api/v2/config/mail/test/test%40example.com?timestamp=1638469029434] admin com.sun.mail.smtp.protocol - 235 Authentication successful

Configure SMTP Logging in Sonatype Lifecycle

  1. Consult help on how to set the required Javamail system properties:
    Setting Java system properties for Sonatype Lifecycle
  2. After restart of the application, configure the com.sun.mail logger level to TRACE level.
    How to change Logger Levels in Sonatype Lifecycle
  3. Trigger an action that triggers a mail message send attempt using SMTP - using the in-product test feature is easiest.
    Test Email Configuration in Sonatype Lifecycle

 

Related articles