Error on Zimbra.log

[esatk]

I m tail Zimbra.log and always watch thats error:

Mar 16 11:55:19 mail postfix/smtpd[28484]: connect from unknown[10.0.2.56]
Mar 16 11:55:19 mail saslauthd[1697]: zmauth: authenticating against elected url 'https://mail.hbglobal.com.tr:7071/service/admin/soap/' ...
Mar 16 11:55:19 mail saslauthd[1697]: zmpost: url='https://mail.hbglobal.com.tr:7071/service/admin/soap/' returned buffer->data='<soap:Envelope xmlns:soap="http://www.w3.org/2003/05/soap-envelope"><soap:Header><context xmlns="urn:zimbra"><change token="340"/></context></soap:Header><soap:Body><AuthResponse xmlns="urn:zimbraAccount"><authToken>0_b7ff22d1a6c61085d85a942ff9d25cfd53dc786a_69643d33363a61333031643735632d653166392d343165352d613736352d6264346338636666363064303b6578703d31333a313330303434323131393737313b76763d313a303b747970653d363a7a696d6272613b</authToken><lifetime>172800000</lifetime><skin>carbon</skin></AuthResponse></soap:Body></soap:Envelope>', hti->error=''
Mar 16 11:55:19 mail saslauthd[1697]: auth_zimbra: can.saglam@hbglobal.com.tr auth OK

My version is:
Release 7.0.0_GA_3077.UBUNTU8_64 UBUNTU8_64 FOSS edition.

[fyd]

Originally Posted by esatk

I m tail Zimbra.log and always watch thats error:

Mar 16 11:55:19 mail postfix/smtpd[28484]: connect from unknown[10.0.2.56]
Mar 16 11:55:19 mail saslauthd[1697]: zmauth: authenticating against elected url 'https://mail.hbglobal.com.tr:7071/service/admin/soap/' ...
Mar 16 11:55:19 mail saslauthd[1697]: zmpost: url='https://mail.hbglobal.com.tr:7071/service/admin/soap/' returned buffer->data='<soap:Envelope xmlns:soap="http://www.w3.org/2003/05/soap-envelope"><soap:Header><context xmlns="urn:zimbra"><change token="340"/></context></soap:Header><soap:Body><AuthResponse xmlns="urn:zimbraAccount"><authToken>0_b7ff22d1a6c61085d85a942ff9d25cfd53dc786a_69643d33363a61333031643735632d653166392d343165352d613736352d6264346338636666363064303b6578703d31333a313330303434323131393737313b76763d313a303b747970653d363a7a696d6272613b</authToken><lifetime>172800000</lifetime><skin>carbon</skin></AuthResponse></soap:Body></soap:Envelope>', hti->error=''
Mar 16 11:55:19 mail saslauthd[1697]: auth_zimbra: can.saglam@hbglobal.com.tr auth OK

My version is:
Release 7.0.0_GA_3077.UBUNTU8_64 UBUNTU8_64 FOSS edition.

Woh .. easy with the smiley esatk, you seem to be really angry Try to give more information on your problem. The log looks like an incoming mail. And says auth OK too. So is there any mails failing to deliver? It looks all right to me, just saying that the user is being authenticated.

[datakid]

I've seen this error in the logs as well, and it's a dupe of this:

unknow message in my zimbra server

No explanation available at the moment - but from what I've read, I would suggest that it can be safely ignored. If there is a problem, it's unlikely to be something caused by user or admin, since it's quite rare* and none of my users would even know what SOAP is. I presume it's an underlying Zimbra issue, if it even is an issue.


*(at least it is in my case - in bursts of 2-5, it happens once every fortnight on a system that's heavily used daily.)

[John Siu]

I don't think that is an error at all. They are normal log entries.

[datakid]

Ah, ok - i was thrown by the hti->error='' at the end of the SOAP lines.

If they are normal log entries, why don't they appear with more frequency, and what triggers them?

[John Siu]

Authentication log, generated by web GUI login and admin console login.

The error='' means no error code or error message as '' means empty.

[datakid]

Great - thanks for the exp.

[esatk]

Originally Posted by datakid

Ah, ok - i was thrown by the hti->error='' at the end of the SOAP lines.

If they are normal log entries, why don't they appear with more frequency, and what triggers them?

Hi dear, frequency is offen...
I m always watching Zimbra.log file, so i will see more SOAP error there.

Every 20 line later

Apr 1 08:20:09 mail saslauthd[7370]: zmauth: authenticating against elected url 'https://mail.hbglobal.com.tr:7071/service/admin/soap/' ...
Apr 1 08:20:09 mail saslauthd[7370]: zmpost: url='https://mail.hbglobal.com.tr:7071/service/admin/soap/' returned buffer->data='<soap:Envelope xmlns:soap="http://www.w3.org/2003/05/soap-envelope"><soap:Header><context xmlns="urn:zimbra"><change token="1058"/></context></soap:Header><soap:Body><AuthResponse xmlns="urn:zimbraAccount"><authToken>0_c20114495d0 b4c3229280c69e60fd828aa640e6b_69643d33363a35323062 666162332d306638382d343231662d623866362d3335333063 393935656334393b6578703d31333a31333031383038303039 3835363b76763d313a303b747970653d363a7a696d6272613b </authToken><lifetime>172799999</lifetime><skin>carbon</skin></AuthResponse></soap:Body></soap:Envelope>', hti->error=''
Apr 1 08:20:09 mail saslauthd[7370]: auth_zimbra: feyzullah.durusoy@elumatec.com.tr auth OK

[esatk]

This last logs:


Apr 1 08:20:09 mail postfix/smtpd[7957]: connect from unknown[10.0.2.54]
Apr 1 08:20:09 mail saslauthd[7370]: zmauth: authenticating against elected url 'https://mail.hbglobal.com.tr:7071/service/admin/soap/' ...
Apr 1 08:20:09 mail saslauthd[7370]: zmpost: url='https://mail.hbglobal.com.tr:7071/service/admin/soap/' returned buffer->data='<soap:Envelope xmlns:soap="http://www.w3.org/2003/05/soap-envelope"><soap:Header><context xmlns="urn:zimbra"><change token="1058"/></context></soap:Header><soap:Body><AuthResponse xmlns="urn:zimbraAccount"><authToken>0_c20114495d0 b4c3229280c69e60fd828aa640e6b_69643d33363a35323062 666162332d306638382d343231662d623866362d3335333063 393935656334393b6578703d31333a31333031383038303039 3835363b76763d313a303b747970653d363a7a696d6272613b </authToken><lifetime>172799999</lifetime><skin>carbon</skin></AuthResponse></soap:Body></soap:Envelope>', hti->error=''
Apr 1 08:20:09 mail saslauthd[7370]: auth_zimbra: feyzullah.durusoy@elumatec.com.tr auth OK
Apr 1 08:20:09 mail postfix/smtpd[7957]: D260322818F: client=unknown[10.0.2.54], sasl_method=LOGIN, sasl_username=feyzullah.durusoy@elumatec.com.tr
Apr 1 08:20:09 mail postfix/cleanup[7442]: D260322818F: message-id=<001701cbf02c$56e7cc10$04b76430$@durusoy@elumat ec.com.tr>
Apr 1 08:20:09 mail postfix/qmgr[7366]: D260322818F: from=<feyzullah.durusoy@elumatec.com.tr>, size=32502, nrcpt=1 (queue active)
Apr 1 08:20:09 mail amavis[10991]: (10991-05) ESMTP::10024 /opt/zimbra/data/amavisd/tmp/amavis-20110401T081402-10991: <feyzullah.durusoy@elumatec.com.tr> -> <ozgur.yaylali@hbglobal.com.tr> SIZE=32502 Received: from mail.hbglobal.com.tr ([127.0.0.1]) by localhost (mail.hbglobal.com.tr [127.0.0.1]) (amavisd-new, port 10024) with ESMTP for <ozgur.yaylali@hbglobal.com.tr>; Fri, 1 Apr 2011 08:20:09 +0300 (EEST)
Apr 1 08:20:09 mail amavis[10991]: (10991-05) Checking: 0V5KHNQ7elX9 MYNETS [10.0.2.54] <feyzullah.durusoy@elumatec.com.tr> -> <ozgur.yaylali@hbglobal.com.tr>
Apr 1 08:20:10 mail postfix/smtpd[9344]: connect from unknown[10.0.26.104]
Apr 1 08:20:10 mail saslauthd[7369]: zmauth: authenticating against elected url 'https://mail.hbglobal.com.tr:7071/service/admin/soap/' ...
Apr 1 08:20:10 mail saslauthd[7369]: zmpost: url='https://mail.hbglobal.com.tr:7071/service/admin/soap/' returned buffer->data='<soap:Envelope xmlns:soap="http://www.w3.org/2003/05/soap-envelope"><soap:Header><context xmlns="urn:zimbra"><change token="2104"/></context></soap:Header><soap:Body><AuthResponse xmlns="urn:zimbraAccount"><authToken>0_7cd68139d0e 6e83cb2fa43f67a4236b04d0c3b82_69643d33363a31373739 663431322d393461352d343934652d386563632d3337633266 356239333061663b6578703d31333a31333031383038303130 3430353b76763d313a303b747970653d363a7a696d6272613b </authToken><lifetime>172800000</lifetime><skin>carbon</skin></AuthResponse></soap:Body></soap:Envelope>', hti->error=''
Apr 1 08:20:10 mail saslauthd[7369]: auth_zimbra: vildan.molla@murat.com.tr auth OK
Apr 1 08:20:10 mail postfix/smtpd[9344]: 6588E2281A9: client=unknown[10.0.26.104], sasl_method=LOGIN, sasl_username=vildan.molla@murat.com.tr
Apr 1 08:20:10 mail postfix/cleanup[12215]: 6588E2281A9: message-id=<002401cbf02c$56fb05f0$04f111d0$@molla@murat.co m.tr>
Apr 1 08:20:10 mail postfix/qmgr[7366]: 6588E2281A9: from=<vildan.molla@murat.com.tr>, size=2527, nrcpt=1 (queue active)

[esatk]

I think write 2 different logs. One Authentication is OK log. One Authentication is FAIL log.

This example fail log all before logs is OK log:

Apr 1 08:26:38 mail postfix/smtpd[15315]: connect from unknown[10.0.2.254]
Apr 1 08:26:39 mail saslauthd[7364]: zmauth: authenticating against elected url 'https://mail.hbglobal.com.tr:7071/service/admin/soap/' ...
Apr 1 08:26:39 mail saslauthd[7364]: zmpost: url='https://mail.hbglobal.com.tr:7071/service/admin/soap/' returned buffer->data='<soap:Envelope xmlns:soap="http://www.w3.org/2003/05/soap-envelope"><soap:Header><context xmlns="urn:zimbra"/></soap:Header><soap:Body><soap:Fault><soap:Code><soa p:Value>soap:Sender</soap:Value></soap:Code><soap:Reason><soap:Text>authentication failed for finansyazici@hbglobal.com.tr</soap:Text></soap:Reason><soapetail><Error xmlns="urn:zimbra"><Code>account.AUTH_FAILED</Code><Trace>com.zimbra.cs.account.AccountServiceEx ception$AuthFailedServiceException: authentication failed for finansyazici@hbglobal.com.tr ExceptionId:btpool0-3004://mail.hbglobal.com.tr:7071/service/admin/soap/:1301635599055:7c7c3ebd1329a099 Code:account.AUTH_FAILED ^Iat com.zimbra.cs.account.AccountServiceException$Auth FailedServiceException.AUTH_FAILED(AccountServiceE xception.java:131) ^Iat com.zimbra.cs.account.AccountServiceException$Auth FailedServiceException.AUTH_FAILED(AccountServiceE xception.java:127) ^Ia
Apr 1 08:26:39 mail saslauthd[7364]: auth_zimbra: finansyazici@hbglobal.com.tr auth failed: authentication failed for finansyazici@hbglobal.com.tr
Apr 1 08:26:39 mail saslauthd[7364]: do_auth : auth failure: [user=finansyazici@hbglobal.com.tr] [service=smtp] [realm=hbglobal.com.tr] [mech=zimbra] [reason=Unknown]
Apr 1 08:26:39 mail postfix/smtpd[15315]: warning: unknown[10.0.2.254]: SASL LOGIN authentication failed: authentication failure