Understanding And Troubleshooting Authentication Log Events

Revision as of 10:32, 20 June 2016 by Jorge de la Cruz (talk | contribs)
(diff) ← Older revision | Latest revision (diff) | Newer revision → (diff)
  1. Zimbra Tech Center
  2. Certified
  3. Understanding And Troubleshooting Authentication Log Events

Understanding And Troubleshooting Authentication Log Events

   KB 21882        Last updated on 2016-06-20  




0.00
(0 votes)

Purpose

Understanding And Troubleshooting Authentication Log Events

Resolution

IMAP And Authenticated SMTP [SSL] Example

  • For the examples below, the ZCS server being used has an ip address of 10.137.27.32 .
  • Note, I included the client IP address [10.16.245.217] of the IMAP client and also the -C2 flag for egrep to show 2 lines proceeding and after the match for ip and username. I also trimmed the output using the time I did the initial IMAP setup and used the -F option for grep because of the : character. [ | grep -F 'Jun 4 08:4' ]

Using the test account above, ajcody@ , I configured it to use IMAP [Use SSL option] and authenticated SMTP [SSL and "password" option] with Apple's Mail.App. My initially login creates these authentication events below.

First, to give you a general impression what logs will hold information on a username and the ip address the client is connection from. The -l option for grep/egrep will just list the files names that have a math to the search. 

[root@zcs723 log]# egrep -l 'ajcody|10.16.245.217' /opt/zimbra/log/*
/opt/zimbra/log/2013_05_31.trace.log  << Because of my ZWC login session
/opt/zimbra/log/2013_06_04.trace.log  << Because of my ZWC login session
/opt/zimbra/log/access_log.2013-05-31 << Because of my ZWC login session
/opt/zimbra/log/access_log.2013-06-04 << Because of my ZWC login session
/opt/zimbra/log/audit.log
/opt/zimbra/log/mailbox.log

[root@zcs723 log]# egrep -l 'ajcody|10.16.245.217' /var/log/*
## Removed not related matches because I've sshd into the server
/var/log/maillog
/var/log/maillog-20130602
/var/log/messages
/var/log/messages-20130602
/var/log/zimbra.log

Now to see what the events are. In the /opt/zimbra/log/audit.log file we have: 

# grep egrep -C2 'ajcody|10.16.245.217' /opt/zimbra/log/audit.log | grep -F 'Jun  4 08:4'
    [cut out prior events]
2013-06-04 08:43:01,943 INFO  [ImapServer-1] [ip=10.16.245.217;ua=Mac OS X Mail/6.2 (1499);] 
  security - cmd=Auth; account=ajcody@zcs723.EXAMPLE.com; protocol=imap;
2013-06-04 08:43:04,031 INFO  [ImapServer-2] [ip=10.16.245.217;ua=Mac OS X Mail/6.2 (1499);] 
  security - cmd=Auth; account=ajcody@zcs723.EXAMPLE.com; protocol=imap;
2013-06-04 08:43:07,078 INFO  [ImapServer-3] [ip=10.16.245.217;ua=Mac OS X Mail/6.2 (1499);] 
  security - cmd=Auth; account=ajcody@zcs723.EXAMPLE.com; protocol=imap;
2013-06-04 08:43:09,437 INFO  [ImapServer-4] [ip=10.16.245.217;ua=Mac OS X Mail/6.2 (1499);] 
  security - cmd=Auth; account=ajcody@zcs723.EXAMPLE.com; protocol=imap;
2013-06-04 08:43:11,645 INFO  [ImapServer-5] [ip=10.16.245.217;ua=Mac OS X Mail/6.2 (1499);] 
  security - cmd=Auth; account=ajcody@zcs723.EXAMPLE.com; protocol=imap;

And in the /var/log/zimbra.log : 

[root@zcs723 log]# egrep -C2 'ajcody|10.16.245.217' zimbra.log | grep -F 'Jun  4 08:4'
    [cut out prior events]
Jun  4 08:42:07 zcs723 zmmailboxdmgr[1389]: status requested
Jun  4 08:42:07 zcs723 zmmailboxdmgr[1389]: status OK
Jun  4 08:42:27 zcs723 postfix/smtpd[1487]: connect from unknown[10.16.245.217]
Jun  4 08:42:28 zcs723 postfix/smtpd[1487]: setting up TLS connection from unknown[10.16.245.217]
Jun  4 08:42:30 zcs723 postfix/smtpd[1487]: SSL_accept error from unknown[10.16.245.217]: -1
Jun  4 08:42:30 zcs723 postfix/smtpd[1487]: lost connection after STARTTLS from unknown[10.16.245.217]
Jun  4 08:42:30 zcs723 postfix/smtpd[1487]: disconnect from unknown[10.16.245.217]
Jun  4 08:42:30 zcs723 postfix/smtpd[1487]: connect from unknown[10.16.245.217]
Jun  4 08:42:31 zcs723 postfix/smtpd[1487]: setting up TLS connection from unknown[10.16.245.217]
Jun  4 08:42:31 zcs723 postfix/smtpd[1487]: Anonymous TLS connection established from unknown[10.16.245.217]: 
  TLSv1 with cipher AES128-SHA (128/128 bits)
Jun  4 08:42:32 zcs723 postfix/smtpd[1497]: connect from unknown[10.16.245.217]
Jun  4 08:42:32 zcs723 postfix/smtpd[1497]: setting up TLS connection from unknown[10.16.245.217]
Jun  4 08:42:32 zcs723 postfix/smtpd[1497]: Anonymous TLS connection established from unknown[10.16.245.217]: 
  TLSv1 with cipher AES128-SHA (128/128 bits)
--
Jun  4 08:42:33 zcs723 saslauthd[8077]: auth_zimbra: ajcody auth OK
Jun  4 08:42:34 zcs723 postfix/smtpd[1497]: disconnect from unknown[10.16.245.217]
Jun  4 08:42:34 zcs723 postfix/smtpd[1487]: lost connection after EHLO from unknown[10.16.245.217]
Jun  4 08:42:34 zcs723 postfix/smtpd[1487]: disconnect from unknown[10.16.245.217]
Jun  4 08:43:01 zcs723 zmmailboxdmgr[1583]: status requested
Jun  4 08:43:01 zcs723 zmmailboxdmgr[1583]: status OK
--
Jun  4 08:45:08 zcs723 zmmailboxdmgr[2353]: status requested
Jun  4 08:45:08 zcs723 zmmailboxdmgr[2353]: status OK
Jun  4 08:45:54 zcs723 postfix/anvil[1489]: statistics: max connection rate 3/60s for 
  (smtp:10.16.245.217) at Jun  4 08:42:32
Jun  4 08:45:54 zcs723 postfix/anvil[1489]: statistics: max connection count 2 for 
  (smtp:10.16.245.217) at Jun  4 08:42:32
Jun  4 08:45:54 zcs723 postfix/anvil[1489]: statistics: max cache size 1 at Jun  4 08:42:27
Jun  4 08:46:07 zcs723 zmmailboxdmgr[2706]: status requested

In the /opt/zimbra/log/mailbox.log : 

[root@zcs723 log]# egrep -C2 'ajcody|10.16.245.217' mailbox.log | grep -F 'Jun  4 08:4'

2013-06-04 08:43:00,343 INFO  [ImapServer-1] [] imap - [10.16.245.217] connected
2013-06-04 08:43:01,999 INFO  [ImapServer-1] [name=ajcody@zcs723.EXAMPLE.com;ip=10.16.245.217;
  ua=Mac OS X Mail/6.2 (1499);] imap - user ajcody@zcs723.EXAMPLE.com authenticated, mechanism=PLAIN [TLS]
2013-06-04 08:43:02,640 INFO  [ImapServer-2] [] imap - [10.16.245.217] connected
2013-06-04 08:43:04,031 INFO  [ImapServer-2] [name=ajcody@zcs723.EXAMPLE.com;
  ip=10.16.245.217;ua=Mac OS X Mail/6.2 (1499);] 
  imap - user ajcody@zcs723.EXAMPLE.com authenticated, mechanism=PLAIN [TLS]
2013-06-04 08:43:04,721 WARN  [ImapServer-2] [name=ajcody@zcs723.EXAMPLE.com;
  ip=10.16.245.217;ua=Mac OS X Mail/6.2 (1499);] 
  ConfigurationFactory - No configuration found. Configuring ehcache from ehcache-failsafe.xml  
  found in the classpath: 
  jar:file:/opt/zimbra/jetty-6.1.22.z6/webapps/service/WEB-INF/lib/ehcache-core-2.5.1.jar!/ehcache-failsafe.xml
2013-06-04 08:43:05,010 WARN  [ImapServer-2] [name=ajcody@zcs723.EXAMPLE.com;
  ip=10.16.245.217;ua=Mac OS X Mail/6.2 (1499);] 
  ConfigurationFactory - No configuration found. Configuring ehcache from ehcache-failsafe.xml  
  found in the classpath: 
  jar:file:/opt/zimbra/jetty-6.1.22.z6/webapps/service/WEB-INF/lib/ehcache-core-2.5.1.jar!/ehcache-failsafe.xml
2013-06-04 08:43:05,420 INFO  [ImapServer-2] [name=ajcody@zcs723.EXAMPLE.com;
  ip=10.16.245.217;ua=Mac OS X Mail/6.2 (1499);] 
  imap - selected folder INBOX
2013-06-04 08:43:05,922 INFO  [ImapServer-3] [] imap - [10.16.245.217] connected
2013-06-04 08:43:07,390 INFO  [ImapServer-3] [name=ajcody@zcs723.EXAMPLE.com;
  ip=10.16.245.217;ua=Mac OS X Mail/6.2 (1499);] 
  imap - user ajcody@zcs723.EXAMPLE.com authenticated, mechanism=PLAIN [TLS]
2013-06-04 08:43:08,220 INFO  [ImapServer-4] [] imap - [10.16.245.217] connected
2013-06-04 08:43:09,437 INFO  [ImapServer-4] [name=ajcody@zcs723.EXAMPLE.com;
  ip=10.16.245.217;ua=Mac OS X Mail/6.2 (1499);] 
  imap - user ajcody@zcs723.EXAMPLE.com authenticated, mechanism=PLAIN [TLS]
2013-06-04 08:43:10,395 INFO  [ImapServer-1] [] imap - dropping connection for user 
  ajcody@zcs723.EXAMPLE.com (server-initiated)
2013-06-04 08:43:10,395 INFO  [ImapServer-1] [] ProtocolHandler - Handler exiting normally
2013-06-04 08:43:10,447 INFO  [ImapServer-5] [] imap - [10.16.245.217] connected
2013-06-04 08:43:11,645 INFO  [ImapServer-5] [name=ajcody@zcs723.EXAMPLE.com;
  ip=10.16.245.217;ua=Mac OS X Mail/6.2 (1499);] 
  imap - user ajcody@zcs723.EXAMPLE.com authenticated, mechanism=PLAIN [TLS]
2013-06-04 08:43:12,521 INFO  [ImapServer-3] [name=ajcody@zcs723.EXAMPLE.com;
  ip=10.16.245.217;ua=Mac OS X Mail/6.2 (1499);] imap - selected folder Contacts
2013-06-04 08:43:12,685 INFO  [ImapServer-4] [name=ajcody@zcs723.EXAMPLE.com;
  ip=10.16.245.217;ua=Mac OS X Mail/6.2 (1499);] imap - selected folder Emailed Contacts
2013-06-04 08:43:13,813 INFO  [ImapServer-3] [name=ajcody@zcs723.EXAMPLE.com;
  ip=10.16.245.217;ua=Mac OS X Mail/6.2 (1499);] imap - selected folder Junk
2013-06-04 08:43:13,971 INFO  [ImapServer-5] [name=ajcody@zcs723.EXAMPLE.com;
  ip=10.16.245.217;ua=Mac OS X Mail/6.2 (1499);] imap - selected folder Sent
2013-06-04 08:43:15,614 INFO  [ImapServer-3] [name=ajcody@zcs723.EXAMPLE.com;
  ip=10.16.245.217;ua=Mac OS X Mail/6.2 (1499);] imap - selected folder Trash
2013-06-04 08:43:16,694 INFO  [ImapServer-4] [name=ajcody@zcs723.EXAMPLE.com;mid=15;
  ip=10.16.245.217;ua=Mac OS X Mail/6.2 (1499);] imap - selected folder Chats
2013-06-04 08:43:17,211 INFO  [ImapServer-3] [name=ajcody@zcs723.EXAMPLE.com;
  ip=10.16.245.217;ua=Mac OS X Mail/6.2 (1499);] imap - selected folder Emailed Contacts
2013-06-04 08:43:17,344 INFO  [ImapServer-2] [name=ajcody@zcs723.EXAMPLE.com;mid=15;
  ip=10.16.245.217;ua=Mac OS X Mail/6.2 (1499);] imap - selected folder Drafts
2013-06-04 08:43:17,358 INFO  [ImapServer-3] [name=ajcody@zcs723.EXAMPLE.com;mid=15;
  ip=10.16.245.217;ua=Mac OS X Mail/6.2 (1499);] imap - selected folder INBOX
2013-06-04 08:43:17,840 INFO  [ImapServer-4] [name=ajcody@zcs723.EXAMPLE.com;
  ip=10.16.245.217;ua=Mac OS X Mail/6.2 (1499);] imap - selected folder Emailed Contacts
2013-06-04 08:44:00,813 INFO  [MailboxPurge] [name=ajcody@zcs723.EXAMPLE.com;mid=15;] 
  purge - Purging messages.
2013-06-04 08:44:41,428 INFO  [btpool0-28://zcs723.EXAMPLE.com/service/soap/NoOpRequest] 
  [name=ajcody2@zcs723.EXAMPLE.com;mid=16;ip=10.16.245.217;ua=ZimbraWebClient - [unknown] (Win)/0.0;] 
  soap - NoOpRequest elapsed=0
2013-06-04 08:45:00,818 INFO  [MailboxPurge] [name=ajcody2@zcs723.EXAMPLE.com;mid=16;] 
  purge - Purging messages.

The /var/log/messages and /var/log/maillog had the same events: 

[root@zcs723 log]# egrep -C2 'ajcody|10.16.245.217' /var/log/messages | grep -F 'Jun  4 08:42'
Jun  4 08:42:07 zcs723 zmmailboxdmgr[1389]: status requested
Jun  4 08:42:07 zcs723 zmmailboxdmgr[1389]: status OK
Jun  4 08:42:27 zcs723 postfix/smtpd[1487]: connect from unknown[10.16.245.217]
Jun  4 08:42:28 zcs723 postfix/smtpd[1487]: setting up TLS connection from unknown[10.16.245.217]
Jun  4 08:42:30 zcs723 postfix/smtpd[1487]: SSL_accept error from unknown[10.16.245.217]: -1
Jun  4 08:42:30 zcs723 postfix/smtpd[1487]: lost connection after STARTTLS from unknown[10.16.245.217]
Jun  4 08:42:30 zcs723 postfix/smtpd[1487]: disconnect from unknown[10.16.245.217]
Jun  4 08:42:30 zcs723 postfix/smtpd[1487]: connect from unknown[10.16.245.217]
Jun  4 08:42:31 zcs723 postfix/smtpd[1487]: setting up TLS connection from unknown[10.16.245.217]
Jun  4 08:42:31 zcs723 postfix/smtpd[1487]: Anonymous TLS connection established 
  from unknown[10.16.245.217]: TLSv1 with cipher AES128-SHA (128/128 bits)
Jun  4 08:42:32 zcs723 postfix/smtpd[1497]: connect from unknown[10.16.245.217]
Jun  4 08:42:32 zcs723 postfix/smtpd[1497]: setting up TLS connection from unknown[10.16.245.217]
Jun  4 08:42:32 zcs723 postfix/smtpd[1497]: Anonymous TLS connection established 
  from unknown[10.16.245.217]: TLSv1 with cipher AES128-SHA (128/128 bits)
Jun  4 08:42:34 zcs723 postfix/smtpd[1497]: disconnect from unknown[10.16.245.217]
Jun  4 08:42:34 zcs723 postfix/smtpd[1487]: lost connection after EHLO from unknown[10.16.245.217]
Jun  4 08:42:34 zcs723 postfix/smtpd[1487]: disconnect from unknown[10.16.245.217]
Jun  4 08:45:54 zcs723 postfix/anvil[1489]: statistics: max connection rate 3/60s 
  for (smtp:10.16.245.217) at Jun  4 08:42:32
Jun  4 08:45:54 zcs723 postfix/anvil[1489]: statistics: max connection count 2 
  for (smtp:10.16.245.217) at Jun  4 08:42:32
Jun  4 08:45:54 zcs723 postfix/anvil[1489]: statistics: max cache size 1 at Jun  4 08:42:27

[root@zcs723 log]# egrep -C2 'ajcody|10.16.245.217' /var/log/maillog | grep -F 'Jun  4 08:42'
Jun  4 08:42:07 zcs723 zmmailboxdmgr[1389]: status requested
Jun  4 08:42:07 zcs723 zmmailboxdmgr[1389]: status OK
Jun  4 08:42:27 zcs723 postfix/smtpd[1487]: connect from unknown[10.16.245.217]
Jun  4 08:42:28 zcs723 postfix/smtpd[1487]: setting up TLS connection from unknown[10.16.245.217]
Jun  4 08:42:30 zcs723 postfix/smtpd[1487]: SSL_accept error from unknown[10.16.245.217]: -1
Jun  4 08:42:30 zcs723 postfix/smtpd[1487]: lost connection after STARTTLS from unknown[10.16.245.217]
Jun  4 08:42:30 zcs723 postfix/smtpd[1487]: disconnect from unknown[10.16.245.217]
Jun  4 08:42:30 zcs723 postfix/smtpd[1487]: connect from unknown[10.16.245.217]
Jun  4 08:42:31 zcs723 postfix/smtpd[1487]: setting up TLS connection from unknown[10.16.245.217]
Jun  4 08:42:31 zcs723 postfix/smtpd[1487]: Anonymous TLS connection established 
  from unknown[10.16.245.217]: TLSv1 with cipher AES128-SHA (128/128 bits)
Jun  4 08:42:32 zcs723 postfix/smtpd[1497]: connect from unknown[10.16.245.217]
Jun  4 08:42:32 zcs723 postfix/smtpd[1497]: setting up TLS connection from unknown[10.16.245.217]
Jun  4 08:42:32 zcs723 postfix/smtpd[1497]: Anonymous TLS connection established 
  from unknown[10.16.245.217]: TLSv1 with cipher AES128-SHA (128/128 bits)
Jun  4 08:42:34 zcs723 postfix/smtpd[1497]: disconnect from unknown[10.16.245.217]
Jun  4 08:42:34 zcs723 postfix/smtpd[1487]: lost connection after EHLO from unknown[10.16.245.217]
Jun  4 08:42:34 zcs723 postfix/smtpd[1487]: disconnect from unknown[10.16.245.217]
Jun  4 08:45:54 zcs723 postfix/anvil[1489]: statistics: max connection rate 3/60s 
  for (smtp:10.16.245.217) at Jun  4 08:42:32
Jun  4 08:45:54 zcs723 postfix/anvil[1489]: statistics: max connection count 2 
  for (smtp:10.16.245.217) at Jun  4 08:42:32
Jun  4 08:45:54 zcs723 postfix/anvil[1489]: statistics: max cache size 1 at Jun  4 08:42:27

IMAP Test Via Telnet And Logging Events Of It - Proxy Included


### TELNET FROM CLIENT ###
# telnet zcs806.DOMAIN.com 143 
Trying 192.168.27.36...
Connected to zcs806.DOMAIN.com.
Escape character is '^]'.
* OK IMAP4 ready
01 LOGIN proxylogtest@zcs806.DOMAIN.com [REPLACE WITH ACCT PASSWORD]
01 OK [CAPABILITY IMAP4rev1 ACL BINARY CATENATE CHILDREN CONDSTORE ENABLE ESEARCH ESORT 
I18NLEVEL=1 ID IDLE LIST-EXTENDED LIST-STATUS LITERAL+ LOGIN-REFERRALS MULTIAPPEND 
NAMESPACE QRESYNC QUOTA RIGHTS=ektx SASL-IR SEARCHRES SORT THREAD=ORDEREDSUBJECT 
UIDPLUS UNSELECT WITHIN XLIST] LOGIN completed
01 logout

### LOGS ON ZCS SERVER ###

[zimbra@zcs806 log]$ egrep "192\.168\.27\.37|proxylogtest" *

nginx.log:2014/02/28 09:32:16 [info] 25611#0: *2595 client 192.168.27.37 connected to 0.0.0.0:143
nginx.log:2014/02/28 09:32:38 [info] 25611#0: *2595 client logged in, client: 192.168.27.37, 
       server: 0.0.0.0:143, login: "proxylogtest@zcs806.DOMAIN.com", upstream: 192.168.27.36:7993 
       (192.168.27.37:45080-192.168.27.36:143) <=> (192.168.27.36:53326-192.168.27.36:7993)

audit.log:2014-02-28 09:32:35,532 INFO  [ImapSSLServer-13] [ip=192.168.27.36;oip=192.168.27.37;
       via=192.168.27.36(nginx/1.2.0-zimbra);ua=Zimbra/8.0.6_GA_5922;] security - cmd=Auth; 
       account=proxylogtest@zcs806.DOMAIN.com; protocol=imap;

mailbox.log:2014-02-28 09:32:35,527 INFO  [ImapSSLServer-13] [ip=192.168.27.36;oip=192.168.27.37;   
      via=192.168.27.36(nginx/1.2.0-zimbra);ua=Zimbra/8.0.6_GA_5922;] imap - ID elapsed=8
mailbox.log:2014-02-28 09:32:35,743 INFO  [ImapSSLServer-13] [ip=192.168.27.36;oip=192.168.27.37;
      via=192.168.27.36(nginx/1.2.0-zimbra);ua=Zimbra/8.0.6_GA_5922;] mailbox - Creating database 
      mboxgroup50
mailbox.log:2014-02-28 09:32:37,986 INFO  [ImapSSLServer-13] [ip=192.168.27.36;oip=192.168.27.37;
      via=192.168.27.36(nginx/1.2.0-zimbra);ua=Zimbra/8.0.6_GA_5922;] mailbox - 
      Creating mailbox with id 50 and group id 50 for proxylogtest@zcs806.DOMAIN.com.
mailbox.log:2014-02-28 09:32:37,986 INFO  [ImapSSLServer-13] [ip=192.168.27.36;oip=192.168.27.37;
      via=192.168.27.36(nginx/1.2.0-zimbra);ua=Zimbra/8.0.6_GA_5922;] cache - initializing folder 
      and tag caches for mailbox 50
mailbox.log:2014-02-28 09:32:37,987 INFO  [ImapSSLServer-13] [ip=192.168.27.36;oip=192.168.27.37;
      via=192.168.27.36(nginx/1.2.0-zimbra);ua=Zimbra/8.0.6_GA_5922;] mailop - adding folder ROOT: 
      id=11, parentId=11.
mailbox.log:2014-02-28 09:32:38,010 INFO  [ImapSSLServer-13] [ip=192.168.27.36;oip=192.168.27.37;
      via=192.168.27.36(nginx/1.2.0-zimbra);ua=Zimbra/8.0.6_GA_5922;] mailop - adding folder Tags: 
      id=8, parentId=11.
mailbox.log:2014-02-28 09:32:38,011 INFO  [ImapSSLServer-13] [ip=192.168.27.36;oip=192.168.27.37;
      via=192.168.27.36(nginx/1.2.0-zimbra);ua=Zimbra/8.0.6_GA_5922;] mailop - adding folder 
      Conversations: id=9, parentId=11.
mailbox.log:2014-02-28 09:32:38,011 INFO  [ImapSSLServer-13] [ip=192.168.27.36;oip=192.168.27.37;
      via=192.168.27.36(nginx/1.2.0-zimbra);ua=Zimbra/8.0.6_GA_5922;] mailop - adding folder 
      Comments: id=17, parentId=11.
mailbox.log:2014-02-28 09:32:38,012 INFO  [ImapSSLServer-13] [ip=192.168.27.36;oip=192.168.27.37;
      via=192.168.27.36(nginx/1.2.0-zimbra);ua=Zimbra/8.0.6_GA_5922;] mailop - adding folder 
      USER_ROOT: id=1, parentId=11.
mailbox.log:2014-02-28 09:32:38,012 INFO  [ImapSSLServer-13] [ip=192.168.27.36;oip=192.168.27.37;
      via=192.168.27.36(nginx/1.2.0-zimbra);ua=Zimbra/8.0.6_GA_5922;] mailop - adding folder Inbox: 
      id=2, parentId=1.
mailbox.log:2014-02-28 09:32:38,013 INFO  [ImapSSLServer-13] [ip=192.168.27.36;oip=192.168.27.37;
      via=192.168.27.36(nginx/1.2.0-zimbra);ua=Zimbra/8.0.6_GA_5922;] mailop - adding folder Trash: 
      id=3, parentId=1.
mailbox.log:2014-02-28 09:32:38,013 INFO  [ImapSSLServer-13] [ip=192.168.27.36;oip=192.168.27.37;
      via=192.168.27.36(nginx/1.2.0-zimbra);ua=Zimbra/8.0.6_GA_5922;] mailop - adding folder Junk: 
      id=4, parentId=1.
mailbox.log:2014-02-28 09:32:38,014 INFO  [ImapSSLServer-13] [ip=192.168.27.36;oip=192.168.27.37;
      via=192.168.27.36(nginx/1.2.0-zimbra);ua=Zimbra/8.0.6_GA_5922;] mailop - adding folder Sent: 
      id=5, parentId=1.
mailbox.log:2014-02-28 09:32:38,014 INFO  [ImapSSLServer-13] [ip=192.168.27.36;oip=192.168.27.37;
      via=192.168.27.36(nginx/1.2.0-zimbra);ua=Zimbra/8.0.6_GA_5922;] mailop - adding folder Drafts: 
      id=6, parentId=1.
mailbox.log:2014-02-28 09:32:38,015 INFO  [ImapSSLServer-13] [ip=192.168.27.36;oip=192.168.27.37;
      via=192.168.27.36(nginx/1.2.0-zimbra);ua=Zimbra/8.0.6_GA_5922;] mailop - adding folder Contacts: 
      id=7, parentId=1.
mailbox.log:2014-02-28 09:32:38,023 INFO  [ImapSSLServer-13] [ip=192.168.27.36;oip=192.168.27.37;
      via=192.168.27.36(nginx/1.2.0-zimbra);ua=Zimbra/8.0.6_GA_5922;] mailop - adding folder Calendar: 
      id=10, parentId=1.
mailbox.log:2014-02-28 09:32:38,023 INFO  [ImapSSLServer-13] [ip=192.168.27.36;oip=192.168.27.37;
      via=192.168.27.36(nginx/1.2.0-zimbra);ua=Zimbra/8.0.6_GA_5922;] mailop - adding folder Tasks: 
      id=15, parentId=1.
mailbox.log:2014-02-28 09:32:38,024 INFO  [ImapSSLServer-13] [ip=192.168.27.36;oip=192.168.27.37;
      via=192.168.27.36(nginx/1.2.0-zimbra);ua=Zimbra/8.0.6_GA_5922;] mailop - adding folder 
      Emailed Contacts: id=13, parentId=1.
mailbox.log:2014-02-28 09:32:38,024 INFO  [ImapSSLServer-13] [ip=192.168.27.36;oip=192.168.27.37;
      via=192.168.27.36(nginx/1.2.0-zimbra);ua=Zimbra/8.0.6_GA_5922;] mailop - adding folder 
      Chats: id=14, parentId=1.
mailbox.log:2014-02-28 09:32:38,025 INFO  [ImapSSLServer-13] [ip=192.168.27.36;oip=192.168.27.37;
      via=192.168.27.36(nginx/1.2.0-zimbra);ua=Zimbra/8.0.6_GA_5922;] mailop - adding folder 
      Briefcase: id=16, parentId=1.
mailbox.log:2014-02-28 09:32:38,038 INFO  [Index-8] [name=proxylogtest@zcs806.DOMAIN.com;mid=50;] 
      index - Batch complete processed=0,failed=0,elapsed=1 (0.00 items/sec)
mailbox.log:2014-02-28 09:32:38,071 INFO  [ImapSSLServer-13] [ip=192.168.27.36;oip=192.168.27.37;
      via=192.168.27.36(nginx/1.2.0-zimbra);ua=Zimbra/8.0.6_GA_5922;] index - OpenLuceneIndex 
      impl=NIOFSDirectory,dir=/opt/zimbra/index/0/50/index/0
mailbox.log:2014-02-28 09:32:38,071 INFO  [ImapSSLServer-13] [ip=192.168.27.36;oip=192.168.27.37;
      via=192.168.27.36(nginx/1.2.0-zimbra);ua=Zimbra/8.0.6_GA_5922;] mbxmgr - Mailbox 50 
      account 0028aab0-3d17-4c51-aad8-da7500247079 CREATED
mailbox.log:2014-02-28 09:32:38,079 INFO  [ImapSSLServer-13] [name=proxylogtest@zcs806.DOMAIN.com;
      ip=192.168.27.36;oip=192.168.27.37;via=192.168.27.36(nginx/1.2.0-zimbra);ua=Zimbra/8.0.6_GA_5922;] 
      imap - user proxylogtest@zcs806.DOMAIN.com authenticated, mechanism=LOGIN [TLS]
mailbox.log:2014-02-28 09:32:38,079 INFO  [ImapSSLServer-13] [name=proxylogtest@zcs806.DOMAIN.com;
      ip=192.168.27.36;oip=192.168.27.37;via=192.168.27.36(nginx/1.2.0-zimbra);ua=Zimbra/8.0.6_GA_5922;] 
      imap - LOGIN elapsed=2550
mailbox.log:2014-02-28 09:32:46,258 WARN  [ImapSSLServer-16] [name=proxylogtest@zcs806.DOMAIN.com;
      ip=192.168.27.36;oip=192.168.27.37;via=192.168.27.36(nginx/1.2.0-zimbra);ua=Zimbra/8.0.6_GA_5922;] 
      imap - BAD parse error: command not implemented
mailbox.log:2014-02-28 09:32:46,258 INFO  [ImapSSLServer-16] [name=proxylogtest@zcs806.DOMAIN.com;
      ip=192.168.27.36;oip=192.168.27.37;via=192.168.27.36(nginx/1.2.0-zimbra);ua=Zimbra/8.0.6_GA_5922;] 
      imap - EXIT elapsed=1
mailbox.log:2014-02-28 09:32:48,648 WARN  [ImapSSLServer-13] [name=proxylogtest@zcs806.DOMAIN.com;
      ip=192.168.27.36;oip=192.168.27.37;via=192.168.27.36(nginx/1.2.0-zimbra);ua=Zimbra/8.0.6_GA_5922;] 
      imap - BAD parse error: command not implemented
mailbox.log:2014-02-28 09:32:48,648 INFO  [ImapSSLServer-13] [name=proxylogtest@zcs806.DOMAIN.com;
      ip=192.168.27.36;oip=192.168.27.37;via=192.168.27.36(nginx/1.2.0-zimbra);ua=Zimbra/8.0.6_GA_5922;] 
      imap - QUIT elapsed=1

IMAP Login Via Openssl - LOGIN TLS - Proxy Included

You would run from the CLI: 

 openssl s_client -crlf -connect zcs806.DOMAIN.com:993

Once it shows "* OK IMAP4 ready" you'll be able to give the login command: 

tag login proxylogtest@zcs806.DOMAIN.com PASSWORD

Another good example of this is at Access IMAP server from the command line using OpenSSL

The log events for this are: 

$ egrep "192\.168\.27\.37|proxylogtest" * | grep "28 10"

audit.log:2014-02-28 10:37:51,207 INFO  [ImapSSLServer-13] [ip=192.168.27.36;oip=192.168.27.37;
    via=192.168.27.36(nginx/1.2.0-zimbra); ua=Zimbra/8.0.6_GA_5922;] security - cmd=Auth; 
    account=proxylogtest@zcs806.DOMAIN.com; protocol=imap;

mailbox.log:2014-02-28 10:37:51,204 INFO  [ImapSSLServer-13] [ip=192.168.27.36;oip=192.168.27.37;
    via=192.168.27.36(nginx/1.2.0-zimbra); ua=Zimbra/8.0.6_GA_5922;] imap - ID elapsed=1
mailbox.log:2014-02-28 10:37:51,207 INFO  [ImapSSLServer-13] [name=proxylogtest@zcs806.DOMAIN.com;
    ip=192.168.27.36;oip=192.168.27.37; via=192.168.27.36(nginx/1.2.0-zimbra);ua=Zimbra/8.0.6_GA_5922;] 
    imap - user proxylogtest@zcs806.DOMAIN.com authenticated, mechanism=LOGIN [TLS]
mailbox.log:2014-02-28 10:37:51,207 INFO  [ImapSSLServer-13] [name=proxylogtest@zcs806.DOMAIN.com;
    ip=192.168.27.36;oip=192.168.27.37; via=192.168.27.36(nginx/1.2.0-zimbra);ua=Zimbra/8.0.6_GA_5922;] 
    imap - LOGIN elapsed=2
mailbox.log:2014-02-28 10:38:10,132 INFO  [ImapSSLServer-13] [name=proxylogtest@zcs806.DOMAIN.com;
    ip=192.168.27.36;oip=192.168.27.37; via=192.168.27.36(nginx/1.2.0-zimbra);ua=Zimbra/8.0.6_GA_5922;] 
    imap - LIST elapsed=12

nginx.log:2014/02/28 10:32:01 [info] 25609#0: *2602 client 192.168.27.37 connected to 0.0.0.0:993
nginx.log:2014/02/28 10:37:07 [info] 25609#0: *2603 client 192.168.27.37 connected to 0.0.0.0:993
nginx.log:2014/02/28 10:37:51 [info] 25609#0: *2603 client logged in, client: 192.168.27.37, server: 0.0.0.0:993, 
    login: "proxylogtest@zcs806.DOMAIN.com", upstream: 192.168.27.36:7993 
    (192.168.27.37:41009-192.168.27.36:993) <=> (192.168.27.36:53613-192.168.27.36:7993)

Additional Content

  • No related content.
Verified Against: Zimbra Collaboration 8.6, 8.5, 8.0 Date Created: 04/16/2015
Article ID: https://wiki.zimbra.com/index.php?title=Understanding_And_Troubleshooting_Authentication_Log_Events Date Modified: 2016-06-20



Try Zimbra

Try Zimbra Collaboration with a 60-day free trial.
Get it now »

Want to get involved?

You can contribute in the Community, Wiki, Code, or development of Zimlets.
Find out more. »

Other help Resources

User Help Page »
Official Forums »
Zimbra Documentation Page »

Looking for a Video?

Visit our YouTube channel to get the latest webinars, technology news, product overviews, and so much more.
Go to the YouTube channel »


Wiki/KB reviewed by SME1 SME2 Copyeditor Last edit by Jorge de la Cruz
Retrieved from "http://wiki.zimbra.com/index.php?title=Understanding_And_Troubleshooting_Authentication_Log_Events&oldid=62137"
Jump to: navigation, search