You are viewing a plain text version of this content. The canonical link for it is here.
Posted to server-dev@james.apache.org by "Norman Maurer (JIRA)" <se...@james.apache.org> on 2010/12/09 17:36:02 UTC

[jira] Commented: (JAMES-1144) Improve logging for SMTPServer

    [ https://issues.apache.org/jira/browse/JAMES-1144?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12969796#action_12969796 ] 

Norman Maurer commented on JAMES-1144:
--------------------------------------

Done.. logs now look like this in DEBUG mode:

DEBUG 17:23:42,297 | james.smtpserver | 262 org.apache.james.smtpserver.JamesWelcomeMessageHandler disconnect=false
DEBUG 17:23:46,091 | james.smtpserver | 262 Lookup command handler for command: EHLO
DEBUG 17:23:46,093 | james.smtpserver | 262 org.apache.james.protocols.smtp.core.esmtp.EhloCmdHandler: 250 [noname. Hello test (fileserver [192.168.0.254]), AUTH LOGIN PLAIN, AUTH=LOGIN PLAIN, PIPELINING, ENHANCEDSTATUSCODES, 8BITMIME]
DEBUG 17:23:46,098 | james.smtpserver | 262 org.apache.james.protocols.smtp.core.SMTPCommandDispatcherLineHandler disconnect=false
DEBUG 17:23:54,029 | james.smtpserver | 262 Lookup command handler for command: MAIL
DEBUG 17:23:54,031 | james.smtpserver | 262 org.apache.james.smtpserver.JamesMailCmdHandler: 250 [2.1.0 Sender <> OK]
DEBUG 17:23:54,032 | james.smtpserver | 262 org.apache.james.protocols.smtp.core.SMTPCommandDispatcherLineHandler disconnect=false
DEBUG 17:24:00,775 | james.smtpserver | 262 Lookup command handler for command: RCPT
DEBUG 17:24:00,776 | james.smtpserver | 262 executing hook org.apache.james.smtpserver.AuthRequiredToRelayRcptHook
DEBUG 17:24:00,777 | james.smtpserver | 262 executing hook org.apache.james.smtpserver.log.HookResultLogger@2a36bb87
INFO  17:24:00,777 | james.smtpserver | 262 org.apache.james.smtpserver.AuthRequiredToRelayRcptHook: result=2 (DENY)
INFO  17:24:00,777 | james.smtpserver | 262 org.apache.james.smtpserver.JamesRcptCmdHandler: 530 [5.7.1 Authentication Required]
DEBUG 17:24:00,778 | james.smtpserver | 262 org.apache.james.protocols.smtp.core.SMTPCommandDispatcherLineHandler disconnect=false
DEBUG 17:24:17,828 | james.smtpserver | 262 Lookup command handler for command: RCPT
DEBUG 17:24:17,828 | james.smtpserver | 262 executing hook org.apache.james.smtpserver.AuthRequiredToRelayRcptHook
DEBUG 17:24:17,828 | james.smtpserver | 262 executing hook org.apache.james.smtpserver.log.HookResultLogger@2a36bb87
DEBUG 17:24:17,829 | james.smtpserver | 262 org.apache.james.smtpserver.AuthRequiredToRelayRcptHook: result=8 (DECLINED)
DEBUG 17:24:17,829 | james.smtpserver | 262 executing hook org.apache.james.smtpserver.SenderAuthIdentifyVerificationRcptHook
DEBUG 17:24:17,829 | james.smtpserver | 262 executing hook org.apache.james.smtpserver.log.HookResultLogger@2a36bb87
DEBUG 17:24:17,829 | james.smtpserver | 262 org.apache.james.smtpserver.SenderAuthIdentifyVerificationRcptHook: result=8 (DECLINED)
DEBUG 17:24:17,830 | james.smtpserver | 262 executing hook org.apache.james.protocols.smtp.core.PostmasterAbuseRcptHook
DEBUG 17:24:17,830 | james.smtpserver | 262 executing hook org.apache.james.smtpserver.log.HookResultLogger@2a36bb87
DEBUG 17:24:17,830 | james.smtpserver | 262 org.apache.james.protocols.smtp.core.PostmasterAbuseRcptHook: result=8 (DECLINED)
DEBUG 17:24:17,830 | james.smtpserver | 262 executing hook org.apache.james.smtpserver.fastfail.ValidRcptHandler
DEBUG 17:24:18,670 | james.smtpserver | 262 Unknown user nm check if its an alias
INFO  17:24:18,724 | james.smtpserver | 262 Rejected message. Unknown user: nm@localhost
DEBUG 17:24:18,725 | james.smtpserver | 262 executing hook org.apache.james.smtpserver.log.HookResultLogger@2a36bb87
INFO  17:24:18,726 | james.smtpserver | 262 org.apache.james.smtpserver.fastfail.ValidRcptHandler: result=2 (DENY)
INFO  17:24:18,726 | james.smtpserver | 262 org.apache.james.smtpserver.JamesRcptCmdHandler: 550 [5.1.1 Unknown user: nm@localhost]
DEBUG 17:24:18,727 | james.smtpserver | 262 org.apache.james.protocols.smtp.core.SMTPCommandDispatcherLineHandler disconnect=false
DEBUG 17:24:23,843 | james.smtpserver | 262 Lookup command handler for command: QUIT
DEBUG 17:24:23,843 | james.smtpserver | 262 org.apache.james.protocols.smtp.core.QuitCmdHandler: 221 [2.0.0 noname. Service closing transmission channel]
DEBUG 17:24:23,844 | james.smtpserver | Dispose objects while closing channel 1431702401
DEBUG 17:24:23,845 | james.smtpserver | 262 org.apache.james.protocols.smtp.core.SMTPCommandDispatcherLineHandler disconnect=false

The number after the james.smtpserver | is the smtp session id. So its possible to see what log belongs to the same transaction

> Improve logging for SMTPServer
> ------------------------------
>
>                 Key: JAMES-1144
>                 URL: https://issues.apache.org/jira/browse/JAMES-1144
>             Project: JAMES Server
>          Issue Type: Improvement
>          Components: SMTPServer
>    Affects Versions: 2.2.0, 2.3.0, 2.3.1, 2.3.2, 3.0-M1, 3.0-M2
>            Reporter: Norman Maurer
>            Assignee: Norman Maurer
>             Fix For: 3.0-M3
>
>
> We should improve the logging in SMTPServer to allow to better keep track which handlers were called in a transaction and what they returned to the client

-- 
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.


---------------------------------------------------------------------
To unsubscribe, e-mail: server-dev-unsubscribe@james.apache.org
For additional commands, e-mail: server-dev-help@james.apache.org