Debian Bug report logs - #1000191
dovecot-core: Job for dovecot.service failed because the control process exited with error code (after dist-upgrade)

Reply or subscribe to this bug.

Display info messages

Message #5 received at [email protected] (full text, mbox, reply):

From: Michael Hatzold <[email protected]>

To: Debian Bug Tracking System <[email protected]>

Subject: dovecot-core: Job for dovecot.service failed because the control process exited with error code (after dist-upgrade)

Date: Fri, 19 Nov 2021 13:55:09 +0100

Package: dovecot-core
Version: 1:2.3.16+dfsg1-3
Severity: normal

Dear Maintainer,

*** Reporter, please consider answering these questions, where appropriate ***

   * What led up to the situation?
apt dist-upgrade
   * What exactly did you do (or not do) that was effective (or
     ineffective)?
apt dist-upgrade
   * What was the outcome of this action?
distupgrade went through, but when restaring the necceccary systemd.services
all went wel except fpr dovecot.service.
This is a long-standing bug. imap wont work after dist-upgrade unless you
reboot  or you manually execute:

"systemctl stop dovecot.service"
"systemctl start dovecot.service"

So it is above all an annoying bug, as all other services get restarted without
error.

   * What outcome did you expect instead?

 "systemctl status dovecot.service" should work.

*** End of the template - remove these template lines ***

messages:

Prüfe Prozesse...
Prüfe Kandidaten...
Scanning processor microcode...
Prüfe Linux-Kernel...

Der laufende Kernel ist aktuell.

Der Prozessor Mikrocode ist aktuell.

Dienste werden neu gestartet...
 systemctl restart apt-cacher-ng.service avahi-daemon.service colord.service
connman.service cups.service dovecot.service dun>
Job for dovecot.service failed because the control process exited with error
code.
See "systemctl status dovecot.service" and "journalctl -xeu dovecot.service"
for details.
Dienste deren Neustart verschoben wurde:
 systemctl restart ModemManager.service
 systemctl restart bluetooth.service
 /etc/needrestart/restart.d/dbus.service
 systemctl restart sddm.service
 systemctl restart systemd-logind.service
 systemctl restart [email protected]
 systemctl restart wpa_supplicant.service


----------------------------------------

# journalctl -xeu dovecot.service
░░ Subject: Resources consumed by unit runtime
░░ Defined-By: systemd
░░ Support: https://www.debian.org/support
░░
░░ The unit dovecot.service completed and consumed the indicated resources.
Nov 15 01:15:31 neutower systemd[1]: Starting Dovecot IMAP/POP3 email server...
░░ Subject: A start job for unit dovecot.service has begun execution
░░ Defined-By: systemd
░░ Support: https://www.debian.org/support
░░
░░ A start job for unit dovecot.service has begun execution.
░░
░░ The job identifier is 4759.
Nov 15 01:15:31 neutower dovecot[162036]: Error: bind(192.168.2.13, 143)
failed: Cannot assign requested address
Nov 15 01:15:31 neutower dovecot[162036]: Error: service(imap-login):
listen(192.168.2.13, 143) failed: Cannot assign request>
Nov 15 01:15:31 neutower dovecot[162036]: master: Error: bind(192.168.2.13,
143) failed: Cannot assign requested address
Nov 15 01:15:31 neutower dovecot[162036]: master: Error: service(imap-login):
listen(192.168.2.13, 143) failed: Cannot assign>
Nov 15 01:15:31 neutower dovecot[162036]: master: Fatal: Failed to start
listeners
Nov 15 01:15:31 neutower dovecot[162036]: Fatal: Failed to start listeners
Nov 15 01:15:31 neutower systemd[1]: dovecot.service: Main process exited,
code=exited, status=89/n/a
░░ Subject: Unit process exited
░░ Defined-By: systemd
░░ Support: https://www.debian.org/support

░░ An ExecStart= process belonging to unit dovecot.service has exited.
░░
░░ The process' exit code is 'exited' and its exit status is 89.
Nov 15 01:15:31 neutower systemd[1]: dovecot.service: Failed with result 'exit-
code'.
░░ Subject: Unit failed
░░ Defined-By: systemd
░░ Support: https://www.debian.org/support
░░
░░ The unit dovecot.service has entered the 'failed' state with result 'exit-
code'.
Nov 15 01:15:31 neutower systemd[1]: Failed to start Dovecot IMAP/POP3 email
server.
░░ Subject: A start job for unit dovecot.service has failed
░░ Defined-By: systemd
░░ Support: https://www.debian.org/support
░░
░░ A start job for unit dovecot.service has finished with a failure.
░░
░░ The job identifier is 4759 and the job result is failed.
lines 4840-4867/4867 (END)



__________________________________________________________



-- Package-specific info:

dovecot configuration
---------------------
# 2.3.16 (7e2e900c1a): /etc/dovecot/dovecot.conf
# Pigeonhole version 0.5.16 (09c29328)
# OS: Linux 5.15.2-4-siduction-amd64 x86_64 Debian bookworm/sid 
# Hostname: neutower.picasso
base_dir = /var/run/dovecot/
disable_plaintext_auth = no
listen = 127.0.0.1 192.168.2.13
log_timestamp = "%Y-%m-%d %H:%M:%S "
mail_privileged_group = mail
passdb {
  driver = pam
}
protocols = imap
service auth {
  user = root
}
ssl = no
userdb {
  driver = passwd
}
protocol pop3 {
  pop3_uidl_format = %08Xu%08Xv
}

-- System Information:
Debian Release: bookworm/sid
  APT prefers unstable
  APT policy: (500, 'unstable'), (500, 'stable'), (1, 'experimental')
Architecture: amd64 (x86_64)
Foreign Architectures: i386

Kernel: Linux 5.15.2-4-siduction-amd64 (SMP w/2 CPU threads; PREEMPT)
Kernel taint flags: TAINT_PROPRIETARY_MODULE, TAINT_OOT_MODULE
Locale: LANG=de_DE.UTF-8, LC_CTYPE=de_DE.UTF-8 (charmap=UTF-8), LANGUAGE not set
Shell: /bin/sh linked to /usr/bin/dash
Init: systemd (via /run/systemd/system)
LSM: AppArmor: enabled

Versions of packages dovecot-core depends on:
ii  adduser              3.118
ii  init-system-helpers  1.60
ii  libapparmor1         3.0.3-6
ii  libbz2-1.0           1.0.8-4
ii  libc6                2.32-4
ii  libcap2              1:2.44-1
ii  libcrypt1            1:4.4.26-1
ii  libexttextcat-2.0-0  3.4.5-1
ii  libicu67             67.1-7
ii  liblua5.3-0          5.3.6-1
ii  liblz4-1             1.9.3-2
ii  liblzma5             5.2.5-2
ii  libpam-runtime       1.4.0-10
ii  libpam0g             1.4.0-10
ii  libsodium23          1.0.18-1
ii  libssl1.1            1.1.1l-1
ii  libstemmer0d         2.2.0-1
ii  libsystemd0          249.6-3
ii  libtirpc3            1.3.2-2
ii  libwrap0             7.6.q-31
ii  libzstd1             1.4.8+dfsg-3
ii  lsb-base             11.1.0
ii  openssl              1.1.1l-1
ii  ssl-cert             1.1.1
ii  ucf                  3.0043
ii  zlib1g               1:1.2.11.dfsg-2

dovecot-core recommends no packages.

Versions of packages dovecot-core suggests:
pn  dovecot-gssapi        <none>
ii  dovecot-imapd         1:2.3.16+dfsg1-3
pn  dovecot-ldap          <none>
pn  dovecot-lmtpd         <none>
pn  dovecot-lucene        <none>
pn  dovecot-managesieved  <none>
pn  dovecot-mysql         <none>
pn  dovecot-pgsql         <none>
pn  dovecot-pop3d         <none>
ii  dovecot-sieve         1:2.3.16+dfsg1-3
pn  dovecot-solr          <none>
pn  dovecot-sqlite        <none>
pn  dovecot-submissiond   <none>
pn  ntp                   <none>

Versions of packages dovecot-core is related to:
ii  dovecot-core [dovecot-common]  1:2.3.16+dfsg1-3
pn  dovecot-dev                    <none>
pn  dovecot-gssapi                 <none>
ii  dovecot-imapd                  1:2.3.16+dfsg1-3
pn  dovecot-ldap                   <none>
pn  dovecot-lmtpd                  <none>
pn  dovecot-managesieved           <none>
pn  dovecot-mysql                  <none>
pn  dovecot-pgsql                  <none>
pn  dovecot-pop3d                  <none>
ii  dovecot-sieve                  1:2.3.16+dfsg1-3
pn  dovecot-sqlite                 <none>

-- no debconf information

Message #12 received at [email protected] (full text, mbox, reply):

From: Noah Meyerhans <[email protected]>

To: Michael Hatzold <[email protected]>, [email protected]

Subject: Re: Bug#1000191: dovecot-core: Job for dovecot.service failed because the control process exited with error code (after dist-upgrade)

Date: Fri, 19 Nov 2021 09:46:24 -0800

Control: tags -1 + moreinfo

On Fri, Nov 19, 2021 at 01:55:09PM +0100, Michael Hatzold wrote:
> 
>    * What led up to the situation?
> apt dist-upgrade
>    * What exactly did you do (or not do) that was effective (or
>      ineffective)?
> apt dist-upgrade
>    * What was the outcome of this action?
> distupgrade went through, but when restaring the necceccary systemd.services
> all went wel except fpr dovecot.service.
> This is a long-standing bug. imap wont work after dist-upgrade unless you
> reboot  or you manually execute:

I am not able to reproduce this on an upgrade from a basic bullseye
installation to bookworm.  Prior to the upgrade I have:

admin@ip-10-0-0-111:~$ systemctl status dovecot.service
● dovecot.service - Dovecot IMAP/POP3 email server
     Loaded: loaded (/lib/systemd/system/dovecot.service; enabled; vendor preset: enabled)
     Active: active (running) since Fri 2021-11-19 17:20:00 UTC; 1min 12s ago
       Docs: man:dovecot(1)
             http://wiki2.dovecot.org/
   Main PID: 593 (dovecot)
      Tasks: 4 (limit: 4444)
     Memory: 5.0M
        CPU: 32ms
     CGroup: /system.slice/dovecot.service
             ├─593 /usr/sbin/dovecot -F
             ├─606 dovecot/anvil
             ├─607 dovecot/log
             └─609 dovecot/config

Nov 19 17:20:00 ip-10-0-0-111 systemd[1]: Starting Dovecot IMAP/POP3 email server...
Nov 19 17:20:00 ip-10-0-0-111 dovecot[593]: master: Dovecot v2.3.13 (89f716dc2) starting up for imap (core dumps disabled)
Nov 19 17:20:00 ip-10-0-0-111 systemd[1]: Started Dovecot IMAP/POP3 email server.
admin@ip-10-0-0-111:~$ dpkg -l | grep dovecot
ii  dovecot-core                     1:2.3.13+dfsg1-2               amd64        secure POP3/IMAP server - core files
ii  dovecot-imapd                    1:2.3.13+dfsg1-2               amd64        secure POP3/IMAP server - IMAP daemon
ii  dovecot-sieve                    1:2.3.13+dfsg1-2               amd64        secure POP3/IMAP server - Sieve filters support

admin@ip-10-0-0-111:~$ sudo sed -i 's,bullseye,bookworm,' /etc/apt/sources.list
admin@ip-10-0-0-111:~$ sudo apt update
admin@ip-10-0-0-111:~$ sudo apt -y dist-upgrade
...
Setting up dovecot-core (1:2.3.16+dfsg1-3) ...
Replacing config file /etc/dovecot/dovecot.conf with new version
Replacing config file /etc/dovecot/dovecot-dict-sql.conf.ext with new version
Replacing config file /etc/dovecot/conf.d/10-logging.conf with new version
Replacing config file /etc/dovecot/conf.d/10-ssl.conf with new version
dovecot.socket is a disabled or a static unit not running, not starting it.
...
Setting up dovecot-imapd (1:2.3.16+dfsg1-3) ...
...
Setting up dovecot-sieve (1:2.3.16+dfsg1-3) ...
...
Processing triggers for dovecot-core (1:2.3.16+dfsg1-3) ...

During this process, I had an IMAP (mutt) client connected, and it
received a disconnect due to the server shutting down for restart during
the trigger processing.  After that the client was able to reconnect
with no additional work on the server to make this possible.

systemctl on the server showed the following after the upgrade and
client reconnect:

admin@ip-10-0-0-111:~$ systemctl status dovecot.service
● dovecot.service - Dovecot IMAP/POP3 email server
     Loaded: loaded (/lib/systemd/system/dovecot.service; enabled; vendor preset: enabled)
     Active: active (running) since Fri 2021-11-19 17:27:03 UTC; 5min ago
       Docs: man:dovecot(1)
             https://doc.dovecot.org/
   Main PID: 24660 (dovecot)
     Status: "v2.3.16 (7e2e900c1a) running"
      Tasks: 7 (limit: 4444)
     Memory: 5.3M
        CPU: 43ms
     CGroup: /system.slice/dovecot.service
             ├─24660 /usr/sbin/dovecot -F
             ├─24661 dovecot/anvil
             ├─24662 dovecot/log
             ├─24663 dovecot/config
             ├─24667 dovecot/imap-login
             ├─24668 dovecot/stats
             └─24670 dovecot/imap

Nov 19 17:27:03 ip-10-0-0-111 systemd[1]: Starting Dovecot IMAP/POP3 email server...
Nov 19 17:27:03 ip-10-0-0-111 dovecot[24660]: master: Dovecot v2.3.16 (7e2e900c1a) starting up for imap (core dumps disabled)
Nov 19 17:27:03 ip-10-0-0-111 systemd[1]: Started Dovecot IMAP/POP3 email server.
Nov 19 17:27:35 ip-10-0-0-111 dovecot[24662]: imap-login: Login: user=<admin>, method=PLAIN, rip=73.140.205.249, lip=10.0.0.> 
> # journalctl -xeu dovecot.service
> ░░ Subject: Resources consumed by unit runtime
> ░░ Defined-By: systemd
> ░░ Support: https://www.debian.org/support
> ░░
> ░░ The unit dovecot.service completed and consumed the indicated resources.
> Nov 15 01:15:31 neutower systemd[1]: Starting Dovecot IMAP/POP3 email server...
> ░░ Subject: A start job for unit dovecot.service has begun execution
> ░░ Defined-By: systemd
> ░░ Support: https://www.debian.org/support
> ░░
> ░░ A start job for unit dovecot.service has begun execution.
> ░░
> ░░ The job identifier is 4759.
> Nov 15 01:15:31 neutower dovecot[162036]: Error: bind(192.168.2.13, 143)
> failed: Cannot assign requested address
> Nov 15 01:15:31 neutower dovecot[162036]: Error: service(imap-login):
> listen(192.168.2.13, 143) failed: Cannot assign request>
> Nov 15 01:15:31 neutower dovecot[162036]: master: Error: bind(192.168.2.13,
> 143) failed: Cannot assign requested address
> Nov 15 01:15:31 neutower dovecot[162036]: master: Error: service(imap-login):
> listen(192.168.2.13, 143) failed: Cannot assign>
> Nov 15 01:15:31 neutower dovecot[162036]: master: Fatal: Failed to start
> listeners
> Nov 15 01:15:31 neutower dovecot[162036]: Fatal: Failed to start listeners
> Nov 15 01:15:31 neutower systemd[1]: dovecot.service: Main process exited,
> code=exited, status=89/n/a
> ░░ Subject: Unit process exited

This indicates that we did try to restart dovecot on your system, but
that it didn't start because something else was bound to port 143.  It
would be interesting to know what that is.  Wsa it the old dovecot
process that didn't shut down for some reason?  Was it systemd? (Can you
show the output of `systemctl status dovecot.socket`?)

Those logs only show what happened when dovecot tried to start. It would
be interesting to see earlier logs corresponding with dovecot attempting
to shut down during the 'restart' operation.

Does `systemctl restart dovecot.service` work for you generally (outside
the context of an apt operation)?

noah

Send a report that this bug log contains spam.