[
https://issues.apache.org/jira/browse/JAMES-1251?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13052580#comment-13052580
]
Norman Maurer commented on JAMES-1251:
--------------------------------------
@Nicola:
Can you enable debug logging in RemoteDelivery by adding <debug>true</debug> to
its config and then post the log here ?
> Problem sending to second MX Host
> ---------------------------------
>
> Key: JAMES-1251
> URL: https://issues.apache.org/jira/browse/JAMES-1251
> Project: JAMES Server
> Issue Type: Bug
> Components: SMTPServer
> Affects Versions: 3.0-beta1
> Environment: Linux OpenSuse 11.2
> Reporter: Nicola Salvemini
> Assignee: Norman Maurer
> Fix For: 3.0-beta1
>
>
> Hello!
> I have problems sending email with James 3.0-M3.
> Suppose to send an email to destinat...@testdomain.com and suppose
> testdomain.com domain has two mx record: mx1.tesdomain.com
> (192.168.1.1) and mx2.testdomain.com (192.168.1.2).
> If, for any reason, the destination SMTP server mx1.tesdomain.com is
> down, James does not retry to send on mx2.testdomain.com.
> As normal behavior I would expect that James tried to send on
> mx2.testdomain.com but instead, sending the next runs again on
> mx1.testdomain.com.
> Regards,
> Nicola.
> INFO 09:31:56,578 | james.smtpserver | ID=468922697 Connection established
> from localhost (127.0.0.1)
> DEBUG 09:31:56,579 | james.smtpserver | ID=468922697
> org.apache.james.smtpserver.JamesWelcomeMessageHandler disconnect=false
> DEBUG 09:32:04,761 | james.smtpserver | ID=468922697
> org.apache.james.protocols.smtp.core.SMTPCommandDispatcherLineHandler
> received: helo test
> DEBUG 09:32:04,761 | james.smtpserver | ID=468922697 Lookup command handler
> for command: HELO
> DEBUG 09:32:04,761 | james.smtpserver | ID=468922697
> org.apache.james.protocols.smtp.core.HeloCmdHandler: 250 [localhost. Hello
> test (localhost [127.0.0.1])]
> DEBUG 09:32:04,762 | james.smtpserver | ID=468922697
> org.apache.james.protocols.smtp.core.SMTPCommandDispatcherLineHandler
> disconnect=false
> DEBUG 09:32:18,984 | james.smtpserver | ID=468922697
> org.apache.james.protocols.smtp.core.SMTPCommandDispatcherLineHandler
> received: mail from:<t...@tester.local.com>
> DEBUG 09:32:18,984 | james.smtpserver | ID=468922697 Lookup command handler
> for command: MAIL
> DEBUG 09:32:18,984 | james.smtpserver | ID=468922697
> org.apache.james.smtpserver.JamesMailCmdHandler: 250 [2.1.0 Sender
> <t...@tester.local.com> OK]
> DEBUG 09:32:18,985 | james.smtpserver | ID=468922697
> org.apache.james.protocols.smtp.core.SMTPCommandDispatcherLineHandler
> disconnect=false
> DEBUG 09:32:43,287 | james.smtpserver | ID=468922697
> org.apache.james.protocols.smtp.core.SMTPCommandDispatcherLineHandler
> received: rcpt to:<destinat...@testdomain.com>
> DEBUG 09:32:43,287 | james.smtpserver | ID=468922697 Lookup command handler
> for command: RCPT
> DEBUG 09:32:43,287 | james.smtpserver | ID=468922697 executing hook
> org.apache.james.smtpserver.fastfail.ValidRcptHandler
> DEBUG 09:32:43,291 | james.smtpserver | ID=468922697 executing hook
> org.apache.james.protocols.smtp.core.log.HookResultLogger@2ae61f87
> DEBUG 09:32:43,291 | james.smtpserver | ID=468922697
> org.apache.james.smtpserver.fastfail.ValidRcptHandler: result=8 (DECLINED)
> DEBUG 09:32:43,291 | james.smtpserver | ID=468922697 executing hook
> org.apache.james.smtpserver.jmx.HookResultJMXMonitor@6a1fee11
> DEBUG 09:32:43,291 | james.smtpserver | ID=468922697 executing hook
> org.apache.james.smtpserver.AuthRequiredToRelayRcptHook
> DEBUG 09:32:43,292 | james.smtpserver | ID=468922697 executing hook
> org.apache.james.protocols.smtp.core.log.HookResultLogger@2ae61f87
> DEBUG 09:32:43,292 | james.smtpserver | ID=468922697
> org.apache.james.smtpserver.AuthRequiredToRelayRcptHook: result=8 (DECLINED)
> DEBUG 09:32:43,292 | james.smtpserver | ID=468922697 executing hook
> org.apache.james.smtpserver.jmx.HookResultJMXMonitor@6a1fee11
> DEBUG 09:32:43,292 | james.smtpserver | ID=468922697 executing hook
> org.apache.james.smtpserver.SenderAuthIdentifyVerificationRcptHook
> DEBUG 09:32:43,292 | james.smtpserver | ID=468922697 executing hook
> org.apache.james.protocols.smtp.core.log.HookResultLogger@2ae61f87
> DEBUG 09:32:43,293 | james.smtpserver | ID=468922697
> org.apache.james.smtpserver.SenderAuthIdentifyVerificationRcptHook: result=8
> (DECLINED)
> DEBUG 09:32:43,293 | james.smtpserver | ID=468922697 executing hook
> org.apache.james.smtpserver.jmx.HookResultJMXMonitor@6a1fee11
> DEBUG 09:32:43,293 | james.smtpserver | ID=468922697 executing hook
> org.apache.james.protocols.smtp.core.PostmasterAbuseRcptHook
> DEBUG 09:32:43,293 | james.smtpserver | ID=468922697 executing hook
> org.apache.james.protocols.smtp.core.log.HookResultLogger@2ae61f87
> DEBUG 09:32:43,294 | james.smtpserver | ID=468922697
> org.apache.james.protocols.smtp.core.PostmasterAbuseRcptHook: result=8
> (DECLINED)
> DEBUG 09:32:43,294 | james.smtpserver | ID=468922697 executing hook
> org.apache.james.smtpserver.jmx.HookResultJMXMonitor@6a1fee11
> DEBUG 09:32:43,294 | james.smtpserver | ID=468922697
> org.apache.james.smtpserver.JamesRcptCmdHandler: 250 [2.1.5 Recipient
> <destinat...@testdomain.com> OK]
> DEBUG 09:32:43,295 | james.smtpserver | ID=468922697
> org.apache.james.protocols.smtp.core.SMTPCommandDispatcherLineHandler
> disconnect=false
> DEBUG 09:32:46,231 | james.smtpserver | ID=468922697
> org.apache.james.protocols.smtp.core.SMTPCommandDispatcherLineHandler
> received: Data
> DEBUG 09:32:46,231 | james.smtpserver | ID=468922697 Lookup command handler
> for command: DATA
> DEBUG 09:32:46,232 | james.smtpserver | ID=468922697
> org.apache.james.smtpserver.JamesDataCmdHandler: 354 [Ok Send data ending
> with <CRLF>.<CRLF>]
> DEBUG 09:32:46,233 | james.smtpserver | ID=468922697
> org.apache.james.protocols.smtp.core.SMTPCommandDispatcherLineHandler
> disconnect=false
> DEBUG 09:32:56,470 | james.smtpserver | ID=468922697 executing james message
> handler
> org.apache.james.protocols.smtp.core.esmtp.MailSizeEsmtpExtension@7cb523dc
> DEBUG 09:32:56,470 | james.smtpserver | ID=468922697 executing hook
> org.apache.james.protocols.smtp.core.log.HookResultLogger@2ae61f87
> DEBUG 09:32:56,470 | james.smtpserver | ID=468922697
> org.apache.james.protocols.smtp.core.esmtp.MailSizeEsmtpExtension: result=8
> (DECLINED)
> DEBUG 09:32:56,471 | james.smtpserver | ID=468922697 executing hook
> org.apache.james.smtpserver.jmx.HookResultJMXMonitor@6a1fee11
> DEBUG 09:32:56,471 | james.smtpserver | ID=468922697 executing james message
> handler org.apache.james.smtpserver.AddDefaultAttributesMessageHook@3af5f6dc
> DEBUG 09:32:56,471 | james.smtpserver | ID=468922697 executing hook
> org.apache.james.protocols.smtp.core.log.HookResultLogger@2ae61f87
> DEBUG 09:32:56,471 | james.smtpserver | ID=468922697
> org.apache.james.smtpserver.AddDefaultAttributesMessageHook: result=8
> (DECLINED)
> DEBUG 09:32:56,471 | james.smtpserver | ID=468922697 executing hook
> org.apache.james.smtpserver.jmx.HookResultJMXMonitor@6a1fee11
> DEBUG 09:32:56,472 | james.smtpserver | ID=468922697 executing james message
> handler org.apache.james.smtpserver.SendMailHandler@6a2203c1
> DEBUG 09:32:56,472 | james.smtpserver | ID=468922697 sending mail
> INFO 09:32:56,491 | james.smtpserver | ID=468922697 Successfully spooled
> mail Mail1305703976470-c7e398f1-e355-4b6a-895c-4991f2ac628e from
> t...@tester.local.com on 127.0.0.1 for [destinat...@testdomain.com]
> DEBUG 09:32:56,492 | james.smtpserver | ID=468922697 executing hook
> org.apache.james.protocols.smtp.core.log.HookResultLogger@2ae61f87
> DEBUG 09:32:56,492 | james.smtpserver | ID=468922697
> org.apache.james.smtpserver.SendMailHandler: result=1 (OK)
> DEBUG 09:32:56,493 | james.smtpserver | ID=468922697 executing hook
> org.apache.james.smtpserver.jmx.HookResultJMXMonitor@6a1fee11
> DEBUG 09:32:56,494 | james.mailspooler | ==== Begin processing mail
> Mail1305703976470-c7e398f1-e355-4b6a-895c-4991f2ac628e====
> DEBUG 09:32:56,494 | james.mailprocessor | Call MailProcessor root
> DEBUG 09:32:56,502 | james.mailprocessor | Call MailProcessor transport
> DEBUG 09:32:56,518 | james.mailprocessor | End of mailetprocessor for state
> root reached
> DEBUG 09:32:56,525 | james.dnsservice | Found MX record mx1.tesdomain.com.
> DEBUG 09:32:56,526 | james.dnsservice | Found MX record mx2.tesdomain.com.
> INFO 09:32:56,578 | james.mailetcontext | Attempting delivery of
> Mail1305703976470-c7e398f1-e355-4b6a-895c-4991f2ac628e-to-mailtrend.net to
> host mx1.tesdomain.com. at 192.168.1.1 from t...@tester.local.com for
> addresses [destinat...@testdomain.com]
> DEBUG 09:33:03,222 | james.smtpserver | ID=468922697
> org.apache.james.protocols.smtp.core.SMTPCommandDispatcherLineHandler
> received: quit
> DEBUG 09:33:03,222 | james.smtpserver | ID=468922697 Lookup command handler
> for command: QUIT
> DEBUG 09:33:03,222 | james.smtpserver | ID=468922697
> org.apache.james.protocols.smtp.core.QuitCmdHandler: 221 [2.0.0 localhost.
> Service closing transmission channel]
> INFO 09:33:03,224 | james.smtpserver | ID=468922697 Connection closed for
> localhost (127.0.0.1)
> DEBUG 09:33:03,224 | james.smtpserver | ID=468922697
> org.apache.james.protocols.smtp.core.SMTPCommandDispatcherLineHandler
> disconnect=false
> INFO 09:33:56,608 | james.mailetcontext | Could not connect to SMTP host:
> 192.168.1.1, port: 25
> INFO 09:33:56,608 | james.mailetcontext | Temporary exception delivering
> mail
> (Mail1305703976470-c7e398f1-e355-4b6a-895c-4991f2ac628e-to-mailtrend.net:
> INFO 09:33:56,609 | james.mailetcontext | Storing message
> Mail1305703976470-c7e398f1-e355-4b6a-895c-4991f2ac628e-to-mailtrend.net into
> outgoing after 0 retries
> DEBUG 09:38:56,743 | james.dnsservice | Found MX record mx1.tesdomain.com.
> DEBUG 09:38:56,744 | james.dnsservice | Found MX record mx2.tesdomain.com.
> INFO 09:38:56,886 | james.mailetcontext | Attempting delivery of
> Mail1305703976470-c7e398f1-e355-4b6a-895c-4991f2ac628e-to-mailtrend.net to
> host mx1.tesdomain.com. at 192.168.1.1 from t...@tester.local.com for
> addresses [destinat...@testdomain.com]
> INFO 09:39:56,947 | james.mailetcontext | Could not connect to SMTP host:
> 192.168.1.1, port: 25
> INFO 09:39:56,947 | james.mailetcontext | Temporary exception delivering
> mail
> (Mail1305703976470-c7e398f1-e355-4b6a-895c-4991f2ac628e-to-mailtrend.net:
> INFO 09:39:56,947 | james.mailetcontext | Storing message
> Mail1305703976470-c7e398f1-e355-4b6a-895c-4991f2ac628e-to-mailtrend.net into
> outgoing after 1 retries
> DEBUG 09:44:57,027 | james.dnsservice | Found MX record mx1.tesdomain.com.
> DEBUG 09:44:57,027 | james.dnsservice | Found MX record mx2.tesdomain.com.
> INFO 09:44:57,217 | james.mailetcontext | Attempting delivery of
> Mail1305703976470-c7e398f1-e355-4b6a-895c-4991f2ac628e-to-mailtrend.net to
> host mx1.tesdomain.com. at 192.168.1.1 from t...@tester.local.com for
> addresses [destinat...@testdomain.com]
> INFO 09:45:57,254 | james.mailetcontext | Could not connect to SMTP host:
> 192.168.1.1, port: 25
> INFO 09:45:57,255 | james.mailetcontext | Temporary exception delivering
> mail
> (Mail1305703976470-c7e398f1-e355-4b6a-895c-4991f2ac628e-to-mailtrend.net:
> INFO 09:45:57,255 | james.mailetcontext | Storing message
> Mail1305703976470-c7e398f1-e355-4b6a-895c-4991f2ac628e-to-mailtrend.net into
> outgoing after 2 retries
> DEBUG 09:50:57,392 | james.dnsservice | Found MX record mx1.tesdomain.com.
> DEBUG 09:50:57,393 | james.dnsservice | Found MX record mx2.tesdomain.com.
> INFO 09:50:57,538 | james.mailetcontext | Attempting delivery of
> Mail1305703976470-c7e398f1-e355-4b6a-895c-4991f2ac628e-to-mailtrend.net to
> host mx1.tesdomain.com. at 192.168.1.1 from t...@tester.local.com for
> addresses [destinat...@testdomain.com]
--
This message is automatically generated by JIRA.
For more information on JIRA, see: http://www.atlassian.com/software/jira
---------------------------------------------------------------------
To unsubscribe, e-mail: server-dev-unsubscr...@james.apache.org
For additional commands, e-mail: server-dev-h...@james.apache.org
