Cyrus-imap is an error-prone program. To debug it, you need to edit /etc/imap.conf to add “debug:1″ and create a user directory in /var/log/imap/log/admin to log the protocol messages. You need to know the log sequences for successful cases:
Sep 14 11:30:32 domainhostseotool pop3[18018]: executed
Sep 14 11:30:39 domainhostseotool pop3s[18001]: accepted connection
(here, the pop3 server accepts the connection from Thunderbird client which is doing server test during account configuration.)
Sep 14 11:30:39 domainhostseotool master[18020]: about to exec /usr/lib/cyrus-imapd/pop3d
Sep 14 11:30:39 domainhostseotool pop3s[18020]: executed
Sep 14 11:30:39 domainhostseotool postfix/smtpd[18021]: warning: dict_nis_init: NIS domain name not set – NIS lookups disabled
Sep 14 11:30:39 domainhostseotool postfix/smtpd[18021]: warning: valid_hostname: misplaced delimiter: .
Sep 14 11:30:39 domainhostseotool postfix/smtpd[18021]: connect from unknown[83.95.11.99]
(here, postfix smtpd accepts connection from Thunderbird client which is testing outgoing server)
Sep 14 11:30:40 domainhostseotool pop3s[18001]: skiplist: checkpointed /var/lib/imap/tls_sessions.db (127 records, 23576 bytes) in 0 seconds
Sep 14 11:30:40 domainhostseotool pop3s[18001]: imapd:Loading hard-coded DH parameters
Sep 14 11:30:40 domainhostseotool pop3s[18001]: SSL_accept() incomplete -> wait
Sep 14 11:30:43 domainhostseotool pop3s[18001]: SSL_accept() succeeded -> done
(here, the ssl handshake is completed successfully.)
Sep 14 11:30:43 domainhostseotool pop3s[18001]: starttls: TLSv1.2 with cipher ECDHE-RSA-AES128-GCM-SHA256 (128/128 bits new) no authentication
Sep 14 11:30:45 domainhostseotool pop3s[18001]: counts: retr=<0> top=<0> dele=<0>
Sep 14 11:30:47 domainhostseotool postfix/smtpd[18021]: improper command pipelining after EHLO from unknown[83.95.11.99]: QUIT\r\n
(here, Thunderbird has successfully verified the outgoing smtp server configuration.)
Sep 14 11:30:53 domainhostseotool postfix/smtpd[18021]: disconnect from unknown[83.95.11.99]
Sep 14 11:32:13 domainhostseotool pop3s[18001]: counts: retr=<0> top=<0> dele=<0>
Sep 14 11:32:13 domainhostseotool master[17993]: process 18001 exited, status 0
Sep 14 11:33:28 domainhostseotool pop3s[18020]: accepted connection
Sep 14 11:33:28 domainhostseotool master[18026]: about to exec /usr/lib/cyrus-imapd/pop3d
Sep 14 11:33:28 domainhostseotool pop3s[18026]: executed
Sep 14 11:33:28 domainhostseotool pop3s[18020]: imapd:Loading hard-coded DH parameters
Sep 14 11:33:28 domainhostseotool pop3s[18020]: SSL_accept() incomplete -> wait
Sep 14 11:33:28 domainhostseotool pop3s[18020]: SSL_accept() succeeded -> done
(ssl connection is successful)
Sep 14 11:33:28 domainhostseotool pop3s[18020]: starttls: TLSv1.2 with cipher ECDHE-RSA-AES128-GCM-SHA256 (128/128 bits new) no authentication
Sep 14 11:33:30 domainhostseotool pop3s[18020]: login: . [83.95.11.99] admin PLAIN+TLS User logged in SESSIONID=<domainhostseotool.com-18020-1600097608-1>
(Thunderbird has successfully logged in, which mean the configuration for incoming pop3 server is correct.)
Sep 14 11:33:30 domainhostseotool pop3s[18020]: fetching user_deny.db entry for ‘admin’
Sep 14 11:33:30 domainhostseotool pop3s[18020]: USAGE admin user: 0.024996 sys: 0.014997
Sep 14 11:33:30 domainhostseotool pop3s[18020]: counts: retr=<0> top=<0> dele=<0>
Sep 14 11:33:31 domainhostseotool pop3s[18026]: accepted connection
(now, Thunderbird connects pop3s server again to retrieve emails)
Sep 14 11:33:32 domainhostseotool pop3s[18026]: imapd:Loading hard-coded DH parameters
Sep 14 11:33:32 domainhostseotool pop3s[18026]: SSL_accept() incomplete -> wait
Sep 14 11:33:34 domainhostseotool pop3s[18026]: SSL_accept() succeeded -> done
Sep 14 11:33:34 domainhostseotool pop3s[18026]: starttls: TLSv1.2 with cipher ECDHE-RSA-AES128-GCM-SHA256 (128/128 bits new) no authentication
Sep 14 11:34:19 domainhostseotool pop3s[18026]: login: . [83.95.11.99] admin PLAIN+TLS User logged in SESSIONID=<domainhostseotool.com-18026-1600097611-1>
(user logs in successfully)
Sep 14 11:34:19 domainhostseotool pop3s[18026]: fetching user_deny.db entry for ‘admin’
Sep 14 11:34:19 domainhostseotool pop3s[18026]: fetching user_deny.db entry for ‘admin’
(Thunderbird is retrieving emails)
Sep 14 11:34:20 domainhostseotool pop3s[18026]: fetching user_deny.db entry for ‘admin’
Sep 14 11:34:21 domainhostseotool pop3s[18026]: fetching user_deny.db entry for ‘admin’
Sep 14 11:34:21 domainhostseotool pop3s[18026]: fetching user_deny.db entry for ‘admin’
Sep 14 11:34:23 domainhostseotool pop3s[18026]: fetching user_deny.db entry for ‘admin’
Sep 14 11:34:25 domainhostseotool pop3s[18026]: fetching user_deny.db entry for ‘admin’
Sep 14 11:34:25 domainhostseotool pop3s[18026]: USAGE admin user: 0.026995 sys: 0.009998
Sep 14 11:34:25 domainhostseotool pop3s[18026]: counts: retr=<3> top=<0> dele=<0>
(Thunderbird has retrieved 3 emails)
Sep 14 11:34:28 domainhostseotool postfix/anvil[15876]: statistics: max connection rate 1/60s for (smtps:83.95.11.99) at Sep 14 11:27:30
Sep 14 11:34:28 domainhostseotool postfix/anvil[15876]: statistics: max connection count 1 for (smtps:83.95.11.99) at Sep 14 11:27:30
Sep 14 11:34:28 domainhostseotool postfix/anvil[15876]: statistics: max cache size 2 at Sep 14 11:31:08
Sep 14 11:34:55 domainhostseotool pop3s[18020]: counts: retr=<0> top=<0> dele=<0>
Sep 14 11:34:55 domainhostseotool master[17993]: process 18020 exited, status 0
