[systemd-devel] Unit dovecot.service has failed

Masaru Kitajima thirstytraveler at mac.com
Wed Oct 2 20:45:43 UTC 2019


HI,

I’m using a VPS which runs CentOS Linux release 7.7.1908 (Core). And dovecot version is 2.2.36 (1f10bfa63).

I haven’t changed anything by myself, but dovecot has become unable to start up a few days ago.

After “systemctl start dovecot”, it says “failed” and I checked it.


   $ systemctl status dovecot.service    dovecot.service - Dovecot IMAP/POP3 email server
   Loaded: loaded (/usr/lib/systemd/system/dovecot.service; enabled; vendor preset: disabled)
   Active: failed (Result: timeout) since Wed. 2019-10-02 16:50:44 JST; 20s ago
       Docs: man:dovecot(1)
           http://wiki2.dovecot.org/
   Process: 1469 ExecStart=/usr/sbin/dovecot (code=exited, status=0/SUCCESS)
   Process: 1465 ExecStartPre=/usr/libexec/dovecot/prestartscript (code=exited, status=0/SUCCESS)

   Oct. 02 16:49:14 v153-127-250-223.vir.kagoya.net systemd[1]: Starting Dovecot IMAP/POP3 email server...
   Oct. 02 16:49:14 v153-127-250-223.vir.kagoya.net systemd[1]: Can't open PID file /var/run/dovecot/master.pid (yet?) after start: Too many levels of symbolic links
   Oct. 02 16:49:14 v153-127-250-223.vir.kagoya.net dovecot[1470]: master: Dovecot v2.2.36 (1f10bfa63) starting up for imap, pop3, lmtp (core dumps disabled)
   Oct. 02 16:50:44 v153-127-250-223.vir.kagoya.net systemd[1]: dovecot.service start operation timed out. Terminating.
   Oct. 02 16:50:44 v153-127-250-223.vir.kagoya.net dovecot[1470]: master: Warning: Killed with signal 15 (by pid=1 uid=0 code=kill)
   Oct. 02 16:50:44 v153-127-250-223.vir.kagoya.net systemd[1]: Failed to start Dovecot IMAP/POP3 email server.
   Oct. 02 16:50:44 v153-127-250-223.vir.kagoya.net systemd[1]: Unit dovecot.service entered failed state.
   Oct. 02 16:50:44 v153-127-250-223.vir.kagoya.net systemd[1]: dovecot.service failed.

Then I searched  /var/run/dovecot/master.pid 
   $ ls -la /var/run/dovecot/
   drwxr-xr-x  5 root    dovecot  740 Oct.  2 16:50 .
   drwxr-xr-x 21 root    root     580 Oct.  2 17:08 ..
   srw-------  1 root    root       0 Oct.  2 16:49 anvil
   srw-------  1 root    root       0 Oct.  2 16:49 anvil-auth-penalty
   srw-------  1 dovecot root       0 Oct.  2 16:49 auth-client
   srw-------  1 dovecot root       0 Oct.  2 16:49 auth-login
   srw-------  1 root    root       0 Oct.  2 16:49 auth-master
   srw-rw-rw-  1 dovecot root       0 Oct.  2 16:49 auth-userdb
   srw-------  1 dovecot root       0 Oct.  2 16:49 auth-worker
   srw-------  1 root    root       0 Oct.  2 16:49 config
   srw-------  1 root    root       0 Oct.  2 16:49 dict
   srw-------  1 root    root       0 Oct.  2 16:49 dict-async
   srw-------  1 root    root       0 Oct.  2 16:49 director-admin
   srw-------  1 root    root       0 Oct.  2 16:49 director-userdb
   srw-rw-rw-  1 root    root       0 Oct.  2 16:49 dns-client
   srw-------  1 root    root       0 Oct.  2 16:49 doveadm-server
   lrwxrwxrwx  1 root    root      25 Oct.  2 16:49 dovecot.conf -> /etc/dovecot/dovecot.conf
   drwxr-xr-x  2 root    root      40 Oct.  2 16:43 empty
   srw-------  1 root    root       0 Oct.  2 16:49 imap-hibernate
   srw-------  1 root    root       0 Oct.  2 16:49 imap-master
   srw-rw-rw-  1 root    root       0 Oct.  2 16:49 imap-urlauth
   srw-------  1 dovecot root       0 Oct.  2 16:49 imap-urlauth-worker
   srw-rw-rw-  1 root    root       0 Oct.  2 16:49 indexer
   srw-------  1 dovecot root       0 Oct.  2 16:49 indexer-worker
   srw-------  1 root    root       0 Oct.  2 16:49 ipc
   srw-rw-rw-  1 root    root       0 Oct.  2 16:49 lmtp
   srw-------  1 root    root       0 Oct.  2 16:49 log-errors
   drwxr-x---  2 root    dovenull 140 Oct.  2 16:49 login
   srw-------  1 root    root       0 Oct.  2 16:49 master
   srw-------  1 root    root       0 Oct.  2 16:49 replication-notify
   prw-------  1 root    root       0 Oct.  2 16:49 replication-notify-fifo
   srw-------  1 dovecot root       0 Oct.  2 16:49 replicator
   srw-rw-rw-  1 root    root       0 Oct.  2 16:49 ssl-params
   srw-------  1 root    root       0 Oct.  2 16:49 stats
   prw-------  1 root    root       0 Oct.  2 16:49 stats-mail
   prw-------  1 root    root       0 Oct.  2 16:49 stats-user
   drwxr-x---  2 root    dovenull  80 Oct.  2 16:49 token-login

And I noticed that it said "Too many levels of symbolic links”. As in the list above, “dovecot.conf” is a symbolic link, so I moved to " /etc/dovecot.”
   $ cd /var/run/dovecot/
   $ cd /etc/dovecot/
   $ ls -la
   drwxr-xr-x 79 root root 4096 Oct.  2 16:31 ..
   drwxr-xr-x  2 root root 4096  Sep. 27 18:43 conf.d
   -rw-r--r--  1 root root 4379  Feb. 20  2019 dovecot.conf
   -rw-r--r--  1 root root 4380  Feb. 20  2019 dovecot.conf.org
   -rw-r--r--  1 root root 1142  Jun. 20 13:51 passwd
   -rw-r--r--  1 root root  520  Aug. 16 09:34 users
   $ cd conf.d
   $ ls -la
   drwxr-xr-x 2 root root  4096  Sep. 27 18:43 .
   drwxr-xr-x 3 root root  4096  Sep. 27 18:31 ..
   -rw-r--r-- 1 root root  5392  Sep. 27 18:13 10-auth.conf
   -rw-r--r-- 1 root root  5296  Feb. 20  2019 10-auth.conf.org
   -rw-r--r-- 1 root root  1893  Apr. 30  2018 10-director.conf
   -rw-r--r-- 1 root root  3118  Jul.  4 11:32 10-logging.conf
   -rw-r--r-- 1 root root  3062  Feb. 20  2019 10-logging.conf.org
   -rw-r--r-- 1 root root 17622  Mar. 10  2019 10-mail.conf
   -rw-r--r-- 1 root root 17579  Feb. 20  2019 10-mail.conf.org
   -rw-r--r-- 1 root root  3378  Mar. 10  2019 10-master.conf
   -rw-r--r-- 1 root root  2662  Sep. 27 06:40 10-ssl.conf
   -rw-r--r-- 1 root root  2486  Feb. 20  2019 10-ssl.conf.org
   -rw-r--r-- 1 root root  1668  Apr. 30  2018 15-lda.conf
   -rw-r--r-- 1 root root  2808  Jun. 23  2017 15-mailboxes.conf
   -rw-r--r-- 1 root root  4235  Mar. 10  2019 20-imap.conf
   -rw-r--r-- 1 root root   936  Jun. 23  2017 20-lmtp.conf
   -rw-r--r-- 1 root root  4065  Apr. 30  2018 20-pop3.conf
   -rw-r--r-- 1 root root   676  Jun. 23  2017 90-acl.conf
   -rw-r--r-- 1 root root   292  Jun. 23  2017 90-plugin.conf
   -rw-r--r-- 1 root root  2597  Apr. 30  2018 90-quota.conf
   -rw-r--r-- 1 root root   499  Jun. 23  2017 auth-checkpassword.conf.ext
   -rw-r--r-- 1 root root   489  Jun. 23  2017 auth-deny.conf.ext
   -rw-r--r-- 1 root root   343  Jun. 23  2017 auth-dict.conf.ext
   -rw-r--r-- 1 root root   924  Jun. 23  2017 auth-ldap.conf.ext
   -rw-r--r-- 1 root root   561  Jun. 23  2017 auth-master.conf.ext
   -rw-r--r-- 1 root root   594  Jun. 20 13:40 auth-passwdfile.conf.ext
   -rw-r--r-- 1 root root   515  Feb. 27  2019 auth-passwdfile.conf.ext.org
   -rw-r--r-- 1 root root   788  Jun. 23  2017 auth-sql.conf.ext
   -rw-r--r-- 1 root root   624  Mar. 10  2019 auth-static.conf.ext
   -rw-r--r-- 1 root root   611  Feb. 27  2019 auth-static.conf.ext.org
   -rw-r--r-- 1 root root  2185  Apr. 30  2018 auth-system.conf.ext
   -rw-r--r-- 1 root root   330  Jun. 23  2017 auth-vpopmail.conf.ext

No more symbolic links found. So my next step was
   $ journalctl -xe
   --
   -- Unit systemd-update-utmp-runlevel.service has begun starting up.
   Oct. 02 16:44:55 MyIPAddress.vir.kagoya.net systemd[1]: Started Update UTMP about System Runlevel Changes.
   -- Subject: Unit systemd-update-utmp-runlevel.service has finished start-up
   -- Defined-By: systemd
   -- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel
   --
   -- Unit systemd-update-utmp-runlevel.service has finished starting up.
   --
   -- The start-up result is done.
   Oct. 02 16:44:55 MyIPAddress.vir.kagoya.net systemd[1]: Startup finished in 1min 31.487s.
   -- Subject: System start-up is now complete
   -- Defined-By: systemd
   -- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel
   --
   -- All system services necessary queued for starting at boot have been
   -- successfully started. Note that this does not mean that the machine is
   -- now idle as services might still be busy with completing start-up.
   --
   -- Kernel start-up required KERNEL_USEC microseconds.
   --
   -- Initial RAM disk start-up required INITRD_USEC microseconds.
   --
   -- Userspace start-up required 91487176 microseconds.
   Oct. 02 16:45:01 MyIPAddress.vir.kagoya.net crond[130]: (app) ERROR (getpwnam() failed)
   Oct. 02 16:45:01 MyIPAddress.vir.kagoya.net crond[130]: (app) ERROR (getpwnam() failed)
   Oct. 02 16:45:01 MyIPAddress.vir.kagoya.net crond[130]: (app) ERROR (getpwnam() failed)
   Oct. 02 16:45:01 MyIPAddress.vir.kagoya.net crond[130]: (app) ERROR (getpwnam() failed)
   Oct. 02 16:45:01 MyIPAddress.vir.kagoya.net crond[130]: (app) ERROR (getpwnam() failed)
   Oct. 02 16:45:01 MyIPAddress.vir.kagoya.net crond[130]: (app) ERROR (getpwnam() failed)
   Oct. 02 16:45:15 MyIPAddress.vir.kagoya.net postfix/smtpd[1376]: connect from unknown[193.56.28.183]
   Oct. 02 16:45:16 MyIPAddress.vir.kagoya.net postfix/smtpd[1376]: warning: unknown[193.56.28.183]: SASL LOGIN authentication failed: authentication failure
   Oct. 02 16:45:17 MyIPAddress.vir.kagoya.net postfix/smtpd[1376]: disconnect from unknown[193.56.28.183]
   Oct. 02 16:46:28 MyIPAddress.vir.kagoya.net /var/maillog/smtpd[1441]: connect from unknown[167.71.104.90]
   Oct. 02 16:46:41 MyIPAddress.vir.kagoya.net /var/maillog/smtpd[1441]: SSL_accept error from unknown[167.71.104.90]: lost connection
   Oct. 02 16:46:41 MyIPAddress.vir.kagoya.net /var/maillog/smtpd[1441]: lost connection after CONNECT from unknown[167.71.104.90]
   Oct. 02 16:46:41 MyIPAddress.vir.kagoya.net /var/maillog/smtpd[1441]: disconnect from unknown[167.71.104.90]
   Oct. 02 16:48:59 MyIPAddress.vir.kagoya.net postfix/smtpd[1461]: connect from unknown[193.56.28.183]
   Oct. 02 16:49:00 MyIPAddress.vir.kagoya.net postfix/smtpd[1461]: warning: unknown[193.56.28.183]: SASL LOGIN authentication failed: authentication failure
   Oct. 02 16:49:01 MyIPAddress.vir.kagoya.net postfix/smtpd[1461]: disconnect from unknown[193.56.28.183]
   Oct. 02 16:49:14 MyIPAddress.vir.kagoya.net systemd[1]: Starting Dovecot IMAP/POP3 email server...
   -- Subject: Unit dovecot.service has begun start-up
   -- Defined-By: systemd
   -- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel
   --
   -- Unit dovecot.service has begun starting up.
   Oct. 02 16:49:14 MyIPAddress.vir.kagoya.net systemd[1]: Can't open PID file /var/run/dovecot/master.pid (yet?) after start: Too many levels of symbolic links
   Oct. 02 16:49:14 MyIPAddress.vir.kagoya.net dovecot[1470]: master: Dovecot v2.2.36 (1f10bfa63) starting up for imap, pop3, lmtp (core dumps disabled)
   Oct. 02 16:50:01 MyIPAddress.vir.kagoya.net crond[130]: (app) ERROR (getpwnam() failed)
   Oct. 02 16:50:01 MyIPAddress.vir.kagoya.net crond[130]: (app) ERROR (getpwnam() failed)
   Oct. 02 16:50:01 MyIPAddress.vir.kagoya.net crond[130]: (app) ERROR (getpwnam() failed)
   Oct. 02 16:50:01 MyIPAddress.vir.kagoya.net crond[130]: (app) ERROR (getpwnam() failed)
   Oct. 02 16:50:01 MyIPAddress.vir.kagoya.net crond[130]: (app) ERROR (getpwnam() failed)
   Oct. 02 16:50:01 MyIPAddress.vir.kagoya.net crond[130]: (app) ERROR (getpwnam() failed)
   Oct. 02 16:50:44 MyIPAddress.vir.kagoya.net systemd[1]: dovecot.service start operation timed out. Terminating.
   Oct. 02 16:50:44 MyIPAddress.vir.kagoya.net dovecot[1472]: log: Warning: Killed with signal 15 (by pid=1 uid=0 code=kill)
   Oct. 02 16:50:44 MyIPAddress.vir.kagoya.net dovecot[1470]: master: Warning: Killed with signal 15 (by pid=1 uid=0 code=kill)
   Oct. 02 16:50:44 MyIPAddress.vir.kagoya.net systemd[1]: Failed to start Dovecot IMAP/POP3 email server.
   -- Subject: Unit dovecot.service has failed
   -- Defined-By: systemd
   -- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel
   --
   -- Unit dovecot.service has failed.
   --
   -- The result is failed.
   Oct. 02 16:50:44 MyIPAddress.vir.kagoya.net systemd[1]: Unit dovecot.service entered failed state.
   Oct. 02 16:50:44 MyIPAddress.vir.kagoya.net systemd[1]: dovecot.service failed.
   Oct. 02 16:52:01 MyIPAddress.vir.kagoya.net /var/maillog/smtpd[1488]: connect from unknown[167.71.104.90]
   Oct. 02 16:52:14 MyIPAddress.vir.kagoya.net /var/maillog/smtpd[1488]: SSL_accept error from unknown[167.71.104.90]: lost connection
   Oct. 02 16:52:14 MyIPAddress.vir.kagoya.net /var/maillog/smtpd[1488]: lost connection after CONNECT from unknown[167.71.104.90]
   Oct. 02 16:52:14 MyIPAddress.vir.kagoya.net /var/maillog/smtpd[1488]: disconnect from unknown[167.71.104.90]
   Oct. 02 16:52:39 MyIPAddress.vir.kagoya.net postfix/smtpd[1490]: connect from unknown[193.56.28.183]
   Oct. 02 16:52:47 MyIPAddress.vir.kagoya.net postfix/smtpd[1490]: warning: unknown[193.56.28.183]: SASL LOGIN authentication failed: authentication failure
   Oct. 02 16:52:47 MyIPAddress.vir.kagoya.net postfix/smtpd[1490]: disconnect from unknown[193.56.28.183]

As suggested here, I’m writing this. I have no idea how to fix this. And in "/var/log/messages”, there’re much more details.
But I’m not sure if it’s OK to paste 100 lines of the log, or attach it to the mail…

Anyway, is there any solutions for this problem?

Masaru

<><><><><><><><><><><><><><><><><><><><><><><><><><><><><><>
<><><><><><><><><><><><><><><><><><><><><><><><><><><><><><>
iOS Engineer / WEB Engineer / UI/UX Designer / VFX director
Masaru Kitajima

E-mail: thirstytraveler at mac.com
MMS: skull-1 at ezweb.ne.jp

Facebook: https://www.facebook.com/masaru.kitajima (Request required)
Twitter: @JR8TQH (Request required)
Instagram: @JR8TQH

+81-80-5583-9839 iPhone
<><><><><><><><><><><><><><><><><><><><><><><><><><><><><><>




More information about the systemd-devel mailing list