Temporary message delivery failure

[goetzi]

Hi,

since 3 days I have sometimes the following error for a few hours... all incoming mails are "blocked" then:

Nov 29 17:50:01 zimbra zimbramon[19900]: 19900:info: 2005-11-29 17:50:01, QUEUE: 7466 5
Nov 29 17:50:13 zimbra zimbramon[19904]: 19904:info: 2005-11-29 17:50:01, STATUS: zimbra.*my domain*.de: antispam: Running
Nov 29 17:50:13 zimbra zimbramon[19904]: 19904:info: 2005-11-29 17:50:01, STATUS: zimbra.*my domain*.de: antivirus: Running
Nov 29 17:50:13 zimbra zimbramon[19904]: 19904:info: 2005-11-29 17:50:01, STATUS: zimbra.*my domain*.de: ldap: Running
Nov 29 17:50:13 zimbra zimbramon[19904]: 19904:info: 2005-11-29 17:50:01, STATUS: zimbra.*my domain*.de: logger: Running
Nov 29 17:50:13 zimbra zimbramon[19904]: 19904:info: 2005-11-29 17:50:01, STATUS: zimbra.*my domain*.de: mailbox: Running
Nov 29 17:50:13 zimbra zimbramon[19904]: 19904:info: 2005-11-29 17:50:01, STATUS: zimbra.*my domain*.de: mta: Running
Nov 29 17:50:13 zimbra zimbramon[19904]: 19904:info: 2005-11-29 17:50:01, STATUS: zimbra.*my domain*.de: snmp: Running
Nov 29 17:50:13 zimbra zimbramon[19904]: 19904:info: 2005-11-29 17:50:01, STATUS: zimbra.*my domain*.de: spell: Running
Nov 29 17:50:13 zimbra zimbramon[19904]: 19904:info: 2005-11-29 17:50:01, DISK: zimbra.*my domain*.de: dev: /dev/ida/c0d0p3, mp: /, tot: 16139, avail: 11952
Nov 29 17:50:13 zimbra zimbramon[19904]: 19904:info: 2005-11-29 17:50:01, DISK: zimbra.*my domain*.de: dev: /dev/ida/c0d0p1, mp: /boot, tot: 97, avail: 81
Nov 29 17:50:21 zimbra postfix/qmgr[22811]: 76FDCC6D41: from=<SRS0=4M74=ZZ=3ai.net=mail@gmx.at>, size=1528702, nrcpt=1 (queue active)
Nov 29 17:50:21 zimbra postfix/qmgr[22811]: 849DAC6D44: from=<SRS0=GeeA=Z4=3ai.net=mail@gmx.at>, size=1529043, nrcpt=1 (queue active)
Nov 29 17:50:24 zimbra postfix/lmtp[20122]: 849DAC6D44: to=<michael@*my domain*.de>, relay=zimbra.*my domain*.de[192.168.0.15], delay=3272, status=deferred (host zimbra.*my domain*.de[192.168.0.15] said: 451 4.0.0 Temporary message delivery failure try again (in reply to end of DATA command))
Nov 29 17:50:24 zimbra postfix/lmtp[20121]: 76FDCC6D41: to=<michael@*my domain*.de>, relay=zimbra.*my domain*.de[192.168.0.15], delay=262478, status=deferred (host zimbra.*my domain*.de[192.168.0.15] said: 451 4.0.0 Temporary message delivery failure try again (in reply to end of DATA command))

What could this be?

[marcmac]

Are you running scheduled backups? (zmschedulebackup with no arguments will dump the backup schedule). Backups put accounts into maintenance mode, which will cause a temporary delivery failure.

Is there anything else in the logs around this time? What about /opt/zimbra/log/zimbra.log or /opt/zimbra/tomcat/logs/catalina.out?

If nothing there - comment out the "loglevel 0" line in /opt/zimbra/conf/slapd.conf and restart ldap - ldap may log something the next time it occurs.

[Daryl Jones]

I'm having a similar, but slightly different problem. 'mailq' reports that postfix has several messages queued for local delivery. Backups were not running during the time that these messages were received. Most messages are received and delivered without a problem.

4490129506B8   883537 Mon Dec 12 19:18:45  johnxx@inreach.com
(host z1.sfo2.xxxx.com[209.xx.xx.xx] said: 451 4.0.0 Temporary message delivery failure try again (in reply to end of DATA command))
dan@xxxxx.com

[goetzi]

Are you running scheduled backups? (zmschedulebackup with no arguments will dump the backup schedule). Backups put accounts into maintenance mode, which will cause a temporary delivery failure.

Not as I know
Never did something with scheduled backups, so if Zimbra doesn't do it automatically: No.

Is there anything else in the logs around this time? What about /opt/zimbra/log/zimbra.log or /opt/zimbra/tomcat/logs/catalina.out?

In /opt/zimbra/log/zimbra.log there is nothing else and /opt/zimbra/tomcat/logs/catalina.out is completely empty.

If nothing there - comment out the "loglevel 0" line in /opt/zimbra/conf/slapd.conf and restart ldap - ldap may log something the next time it occurs.

Does LDAP have an own log or will this entries be in /opt/zimbra/log/zimbra.log?

Edit: There IS an error once befor this other errors occur (don't know if it has something to do with my problem):

Dec 13 08:40:10 zimbra postfix/smtpd[28791]: connect from unknown[219.133.246.141]
Dec 13 08:40:13 zimbra postfix/smtpd[28791]: NOQUEUE: reject: RCPT from unknown[219.133.246.141]: 504 <62.2.100.203>: Helo command rejected: need fully-qualified hostname; from=<dfvdfbzsega@pamil.com> to=<popogigi1975@yahoo.com.tw> proto=SMTP helo=<62.2.100.203>

I give you a part of my zimbra.log, maybe you see other things I didn't recognise.
As you can see, most time it is NOT working. Very nasty

[KevinH]

Can you try a "zmprov ga michael@glatter-goetz.de" this should dump all the user attrs.

[Daryl Jones]

My problem appears to be related mostly to two user accounts. What should I be looking for in the output of 'zmprov ga username@domain.com'?

Also, this doesn't appear to be a temporary failure, as the mailq message indicates. The same messages are still in the Postfix deferred queue as yesterday, plus a few more of them.

[goetzi]

Can you try a "zmprov ga michael@glatter-goetz.de" this should dump all the user attrs.

[zimbra@zimbra ~]$ zmprov ga michael@glatter-goetz.de
# name michael@glatter-goetz.de
cn: michael
displayName: Michael Glatter-Götz
givenName: Michael
mail: michael@glatter-goetz.de
mail: michaelg.g@glatter-goetz.de
objectClass: organizationalPerson
objectClass: zimbraAccount
objectClass: amavisAccount
sn: Glatter-Götz
uid: michael
userPassword: {SSHA}xxxxxxxxxxxxxxxxxxxxxxxxxxxz/A
zimbraAccountStatus: active
zimbraAdminAuthTokenLifetime: 12h
zimbraAttachmentsBlocked: FALSE
zimbraAttachmentsIndexingEnabled: TRUE
zimbraAttachmentsViewInHtmlOnly: FALSE
zimbraAuthTokenLifetime: 4h
zimbraCOSId: e00428a1-0c00-11d9-836a-000d93afea2a
zimbraContactMaxNumEntries: 0
zimbraFeatureAdvancedSearchEnabled: TRUE
zimbraFeatureCalendarEnabled: TRUE
zimbraFeatureChangePasswordEnabled: TRUE
zimbraFeatureContactsEnabled: TRUE
zimbraFeatureConversationsEnabled: TRUE
zimbraFeatureFiltersEnabled: TRUE
zimbraFeatureGalEnabled: TRUE
zimbraFeatureHtmlComposeEnabled: TRUE
zimbraFeatureInitialSearchPreferenceEnabled: TRUE
zimbraFeatureSavedSearchesEnabled: TRUE
zimbraFeatureTaggingEnabled: TRUE
zimbraId: 3469abe4-5b76-11da-b235-3bfc4af89311
zimbraImapEnabled: TRUE
zimbraLastLogonTimestamp: 20051206205545Z
zimbraMailAlias: michaelg.g@glatter-goetz.de
zimbraMailDeliveryAddress: michael@glatter-goetz.de
zimbraMailHost: zimbra.glatter-goetz.de
zimbraMailIdleSessionTimeout: 0
zimbraMailMessageLifetime: 0
zimbraMailMinPollingInterval: 2m
zimbraMailQuota: 0
zimbraMailSpamLifetime: 30d
zimbraMailStatus: enabled
zimbraMailTransport: lmtp:zimbra.glatter-goetz.de:7025
zimbraMailTrashLifetime: 30d
zimbraNewMailNotificationBody: New message received at ${RECIPIENT_ADDRESS}.${NEWLINE}Sender: ${SENDER_ADDRESS}${NEWLINE}Subject: ${SUBJECT}
zimbraNewMailNotificationFrom: Postmaster <postmaster@${RECIPIENT_DOMAIN}>
zimbraNewMailNotificationSubject: New message received at ${RECIPIENT_ADDRESS}
zimbraPasswordEnforceHistory: 0
zimbraPasswordLocked: FALSE
zimbraPasswordMaxAge: 0
zimbraPasswordMaxLength: 64
zimbraPasswordMinAge: 0
zimbraPasswordMinLength: 6
zimbraPasswordModifiedTime: 20051122181044Z
zimbraPop3Enabled: TRUE
zimbraPrefAutoAddAddressEnabled: FALSE
zimbraPrefCalendarAlwaysShowMiniCal: TRUE
zimbraPrefCalendarFirstDayOfWeek: 1
zimbraPrefCalendarInitialView: week
zimbraPrefCalendarNotifyDelegatedChanges: FALSE
zimbraPrefCalendarUseQuickAdd: TRUE
zimbraPrefComposeFormat: text
zimbraPrefComposeInNewWindow: FALSE
zimbraPrefContactsInitialView: list
zimbraPrefContactsPerPage: 100
zimbraPrefDedupeMessagesSentToSelf: dedupeNone
zimbraPrefForwardIncludeOriginalText: includeBody
zimbraPrefForwardReplyInOriginalFormat: FALSE
zimbraPrefForwardReplyPrefixChar: >
zimbraPrefGroupMailBy: conversation
zimbraPrefHtmlEditorDefaultFontColor: #000000
zimbraPrefHtmlEditorDefaultFontFamily: Arial
zimbraPrefHtmlEditorDefaultFontSize: 12pt
zimbraPrefImapSearchFoldersEnabled: TRUE
zimbraPrefIncludeSpamInSearch: FALSE
zimbraPrefIncludeTrashInSearch: FALSE
zimbraPrefMailInitialSearch: in:inbox
zimbraPrefMailItemsPerPage: 100
zimbraPrefMailPollingInterval: 5m
zimbraPrefMailSignatureStyle: outlook
zimbraPrefMessageViewHtmlPreferred: TRUE
zimbraPrefReplyIncludeOriginalText: includeBody
zimbraPrefSaveToSent: TRUE
zimbraPrefSentMailFolder: sent
zimbraPrefShowFragments: FALSE
zimbraPrefShowSearchString: FALSE
zimbraPrefTimeZoneId: (GMT+01.00) Amsterdam / Berlin / Bern / Rome / Stockholm / Vienna
zimbraPrefUseKeyboardShortcuts: FALSE
zimbraPrefUseTimeZoneListInCalendar: FALSE

Maybe the german umlaut in my name (ö) is the problem?

[KevinH]

Originally Posted by goetzi

Maybe the german umlaut in my name (ö) is the problem?

Maybe. Have you ever recieved mail at this account? Do any other mail accounts work?

[KevinH]

Originally Posted by Daryl Jones

My problem appears to be related mostly to two user accounts. What should I be looking for in the output of 'zmprov ga username@domain.com'?

Also, this doesn't appear to be a temporary failure, as the mailq message indicates. The same messages are still in the Postfix deferred queue as yesterday, plus a few more of them.

Basically that the accounts are active, have plenty of quota (or unlimited). Maybe as Michael points out it's due to some special chars in the name but I doubt this.

Can those user's send a message to themselves? Do those user's use IMAP(another thread on how certian IMAP clients may deadlock the server)? Does a restart of tomcat and postqueue -f allow the queue to clear. If a tomcat restart clears it then the next time it happens please get a thread dump of tomcat "kill -QUIT <tomcat pid>". Then zip and attach the thread dump to a post from /opt/zimbra/tomcat/logs/catalina.out


You also may want to look in catalina.out for exceptions on those accounts related to mail/LMTP delivery.

[Daryl Jones]

The users can send messages to themselves from the web interface. I didn't have them try from an IMAP client.

Restarting tomcat followed by postqueue -f did not cause the messages to be delivered, however it did cause postfix to attempt delivery. There are currently 12 messages in the deferred queue. Here is a log entry when postfix attempted delivery after the postqueue -f.

Dec 13 12:15:29 z1 postfix/lmtp[3548]: 04E2929506B6: to=<lisa@xxxx.com>, relay=z1.sfo2.xxx.com[209.xxx.xxx.xxx], delay=61745, status=deferred (host z1.sfo2.xxx.com[209.xxx.xxx.xxx] said: 451 4.0.0 Temporary message delivery failure try again (in reply to end of DATA command))