LMTP issue after upgrade to M3

[gutzeit]

After upgrading to M3 I have the following issues in the zimbra.log :

Jan 9 09:27:06 mvimap postfix/lmtp[30379]: D85C487063A: to=, relay=mvimap.foo.com[192.168.0.8], delay=1, status=deferred (host mvimap.foo.com[192.168.0.8] said: 451 4.0.0 Temporary message delivery failure try again (in reply to end of DATA command))

Can anyone tell me what this means ?

Thanks in advance.

[gutzeit]

This message occures when sending email from one machine in my network.

Full logs of this issue:

Jan 9 10:40:48 mvimap postfix/smtpd[3028]: connect from sirena.foo.com[192.168.0.240]
Jan 9 10:40:48 mvimap postfix/smtpd[3028]: 48E4C870632: client=sirena.foo.com[192.168.0.240]
Jan 9 10:40:48 mvimap postfix/cleanup[3619]: 48E4C870632: message-id=<9065142.1136796060511.JavaMail.root@sirena.foo.com>
Jan 9 10:40:48 mvimap postfix/qmgr[17666]: 48E4C870632: from=, size=4214, nrcpt=1 (queue active)
Jan 9 10:40:48 mvimap postfix/smtpd[3028]: disconnect from sirena.foo.com[192.168.0.240]
Jan 9 10:40:48 mvimap amavis[16429]: (16429-06) ESMTP::10024 /opt/zimbra/amavisd/tmp/amavis-20060109T100706-16429: -> Received: SIZE=4214 from mvimap.foo.com ([127.0.0.1]) by localhost (mvimap.foo.com [127.0.0.1]) (amavisd-new, port 10024) with ESMTP id 16429-06 for ; Mon, 9 Jan 2006 10:40:48 +0200 (IST)
Jan 9 10:40:48 mvimap amavis[16429]: (16429-06) Checking: nFLEEt2KgR6S [192.168.0.240] ->
Jan 9 10:40:48 mvimap postfix/smtpd[3623]: initializing the server-side TLS engine
Jan 9 10:40:48 mvimap postfix/smtpd[3623]: connect from localhost.localdomain[127.0.0.1]
Jan 9 10:40:48 mvimap postfix/smtpd[3623]: CD94C870646: client=localhost.localdomain[127.0.0.1]
Jan 9 10:40:48 mvimap postfix/cleanup[3619]: CD94C870646: message-id=<9065142.1136796060511.JavaMail.root@sirena.foo.com>
Jan 9 10:40:48 mvimap postfix/qmgr[17666]: CD94C870646: from=, size=4881, nrcpt=1 (queue active)
Jan 9 10:40:48 mvimap postfix/smtpd[3623]: disconnect from localhost.localdomain[127.0.0.1]
Jan 9 10:40:48 mvimap amavis[16429]: (16429-06) FWD via SMTP: -> , 250 2.6.0 Ok, id=16429-06, from MTA([127.0.0.1]:10025): 250 Ok: queued as CD94C870646
Jan 9 10:40:48 mvimap amavis[16429]: (16429-06) Passed CLEAN, LOCAL [192.168.0.240] [192.168.0.240] -> , Message-ID: <9065142.1136796060511.JavaMail.root@sirena.foo.com>, mail_id: nFLEEt2KgR6S, Hits: -3.437, 587 ms
Jan 9 10:40:48 mvimap postfix/smtp[3620]: 48E4C870632: to=, orig_to=, relay=127.0.0.1[127.0.0.1], delay=0, status=sent (250 2.6.0 Ok, id=16429-06, from MTA([127.0.0.1]:10025): 250 Ok: queued as CD94C870646)
Jan 9 10:40:48 mvimap postfix/qmgr[17666]: 48E4C870632: removed
Jan 9 10:40:48 mvimap amavis[16429]: (16429-06) extra modules loaded: Net/LDAP/Bind.pm
Jan 9 10:40:48 mvimap postfix/lmtp[3610]: CD94C870646: to=, relay=mvimap.foo.com[192.168.0.8], delay=0, status=deferred (host mvimap.foo.com[192.168.0.8] said: 451 4.0.0 Temporary message delivery failure try again (in reply to end of DATA command))



Thanks in advance.

[marcmac]

Are the MTA and the store (webmail) host the same host? Can you look in /var/log/zimbra.log and /opt/zimbra/log/zimbra.log on the store host for errors (esp. stacktraces) in the lmtp threads?

[gutzeit]

There are no errors in the files you mentioned, and yes, they share the same host. Zimbra with all of its components is installed on the same machine.

[marcmac]

You mentioned that this happens from "one machine" on your network.

Can other machines send mail to that account?

Can that machine not send mail to any account?

[gutzeit]

After investigating this issue further, it seems that the problem is the email itself. If the same email is being sent from some other server, the same error occurs.

All other mail servers I tested with accepted the email with no problem.

I've attached the content of the email.

Thanks.

[marcmac]

Any errors logged in /opt/zimbra/log/zimbra.log or /opt/zimbra/tomcat/logs/catalina.out?

[gutzeit]

I can see some errors now :

java.lang.IllegalArgumentException: Illegal daylight saving value: -7200000
at java.util.SimpleTimeZone.setDSTSavings(SimpleTimeZ one.java:792)
at com.zimbra.cs.mailbox.calendar.ICalTimeZone.initFr omICalData(ICalTimeZone.java:241)
at com.zimbra.cs.mailbox.calendar.ICalTimeZone.(ICalTimeZone.java:449)
at com.zimbra.cs.mailbox.calendar.ICalTimeZone.fromVT imeZone(ICalTimeZone.java:974)
at com.zimbra.cs.mailbox.calendar.Invite.createFromCa lendar(Invite.java:1447)
at com.zimbra.cs.mailbox.Message.create(Message.java: 331)
at com.zimbra.cs.mailbox.Mailbox.addMessageInternal(M ailbox.java:2815)
at com.zimbra.cs.mailbox.Mailbox.addMessage(Mailbox.j ava:2694)
at com.zimbra.cs.mailbox.Mailbox.addMessage(Mailbox.j ava:2686)
at com.zimbra.cs.filter.ZimbraMailAdapter.addMessage( ZimbraMailAdapter.java:338)
at com.zimbra.cs.filter.ZimbraMailAdapter.doDefaultFi ling(ZimbraMailAdapter.java:292)
at com.zimbra.cs.filter.RuleManager.applyRules(RuleMa nager.java:182)
at com.zimbra.cs.lmtpserver.ZimbraLmtpBackend.deliver MessageToLocalMailboxes(ZimbraLmtpBackend.java:221 )
at com.zimbra.cs.lmtpserver.ZimbraLmtpBackend.deliver (ZimbraLmtpBackend.java:108)
at com.zimbra.cs.lmtpserver.LmtpHandler.doDATA(LmtpHa ndler.java:420)
at com.zimbra.cs.lmtpserver.LmtpHandler.processComman d(LmtpHandler.java:197)
at com.zimbra.cs.tcpserver.ProtocolHandler.processCon nection(ProtocolHandler.java:230)
at com.zimbra.cs.tcpserver.ProtocolHandler.run(Protoc olHandler.java:197)
at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Wo rker.run(Unknown Source)
at java.lang.Thread.run(Thread.java:595)
2006-01-16 08:47:22,336 INFO [LmtpServer-2767] [] LmtpHandler - [192.168.0.8] 451 4.0.0 Temporary message delivery failure try again (DATA)


It seems that the iCal file attached to the email is causing some problems. Maybe the timezone is problematic ??? Strange cause Outlook works just fine with this file. If Zimbra fails on parsing iCal file, it does not accept the email at all ?

This is the iCal file :

-----=_Part_8_11369856.1137322167658
Content-Type: text/calendar; name=meeting.ics; method=REQUEST;
charset=US-ASCII
Content-Transfer-Encoding: 7bit

BEGIN:VCALENDAR
PRODID:Mailvision-Conferencing
METHOD:REQUEST
VERSION:2.0
BEGIN:VTIMEZONE
TZID:Asia/Jerusalem
X-LIC-LOCATION:Asia/Jerusalem
BEGIN:STANDARD
TZOFFSETFROM:+0200
TZOFFSETTO:+0200
TZNAME:IST
DTSTART:19700101T000000
END:STANDARD
END:VTIMEZONE
BEGIN:VEVENT
UID:100586
ORGANIZER:MAILTO:conference@foo.com
SUMMARY:test with schduling reminder
DTSTART;TZID=Asia/Jerusalem:20060115T111500
DTEND;TZID=Asia/Jerusalem:20060115T125700
LOCATION:Over the phone
STATUS:CONFIRMED
X-MICROSOFT-CDO-BUSYSTATUS:BUSY
X-MICROSOFT-CDO-INTENDEDSTATUS:BUSY
TRANSP:OPAQUE
ATTENDEE;ROLE=OPT-PARTICIPANT;PARTSTAT=NEEDS-ACTION;RSVP=TRUE:MAILTO:dima
@foo.net
ATTENDEE;ROLE=OPT-PARTICIPANT;PARTSTAT=NEEDS-ACTION;RSVP=TRUE:MAILTO:arie
l@foo.net
DTSTAMP:20060115T104927Z
SEQUENCE:0
END:VEVENT
END:VCALENDAR

------=_Part_8_11369856.1137322167658--

[KevinH]

This looks like bug 5027 which is fixed in the upcoming M4 release.

[gaspode]

Hmm, the bug doesn't seem to be publicly vieweable. What kind of things triggers it?

I have had problems with attachments that Zimbra can't decode (It throws an com.zimbra.cs.service.ServiceException: system failure: failed to analyze part and deferres the mail) if you have the Index attachments option for mail activated.