Bug#976194: opensmtpd: Fails to start on boot with systemd
Interesting: smtpd tries to listen on 127.0.0.1 twice. I can reproduce this by adding two identical entries to my /etc/hosts, i.e., by having 127.0.0.1 localhost 127.0.0.1 localhost in my /etc/hosts. By any chance, does your /etc/hosts contain multiple entries for localhost? In any case, I'll forward this bug upstream now that I can reproduce it. Best, Ryan Here is my /etc/hosts, which I believe is untouched since install: 127.0.0.1 localhost 127.0.1.1 mydomainname.tld mydomainame # The following lines are desirable for IPv6 capable hosts ::1 localhost ip6-localhost ip6-loopback ff02::1 ip6-allnodes ff02::2 ip6-allrouters Thanks, Yvan
Bug#976194: opensmtpd: Fails to start on boot with systemd
Control: forwarded -1 https://github.com/OpenSMTPD/OpenSMTPD/issues/1106 On Wed, Dec 09, 2020 at 04:05:02PM +0100, Yvan Masson wrote: > Le 09/12/2020 à 13:54, Ryan Kavanagh a écrit : > > Dear Yvan, > > > > On Tue, Dec 01, 2020 at 11:46:08AM +0100, Yvan Masson wrote: > > >smtpd[473]: pony express: listen: Address already in use > > > > Could you please send me a copy of /etc/smtpd.conf? In particular, I'm > > curious what "listen on" stanzas you have? > > I have a very simple configuration: > > listen on localhost > > [...] > > déc. 09 15:56:56 myserver smtpd[463]: debug: smtp: listen on 127.0.0.1 port > 25 flags 0x400 pki "" ca "" > déc. 09 15:56:56 myserver smtpd[463]: debug: smtp: listen on 127.0.0.1 port > 25 flags 0x400 pki "" ca "" Interesting: smtpd tries to listen on 127.0.0.1 twice. I can reproduce this by adding two identical entries to my /etc/hosts, i.e., by having 127.0.0.1 localhost 127.0.0.1 localhost in my /etc/hosts. By any chance, does your /etc/hosts contain multiple entries for localhost? In any case, I'll forward this bug upstream now that I can reproduce it. Best, Ryan -- |)|/ Ryan Kavanagh | GPG: 4E46 9519 ED67 7734 268F |\|\ https://rak.ac | BD95 8F7B F8FC 4A11 C97A signature.asc Description: PGP signature
Bug#976194: opensmtpd: Fails to start on boot with systemd
Le 09/12/2020 à 13:54, Ryan Kavanagh a écrit : Dear Yvan, On Tue, Dec 01, 2020 at 11:46:08AM +0100, Yvan Masson wrote: smtpd[473]: pony express: listen: Address already in use Could you please send me a copy of /etc/smtpd.conf? In particular, I'm curious what "listen on" stanzas you have? I have a very simple configuration: listen on localhost table aliases file:/etc/aliases table secrets file:/etc/smtpd.secrets accept for local \ alias \ deliver to mbox accept for domain foo.com \ relay via secure+auth://user@mail-provider:587 \ auth \ as m...@foo.com Also, could you please send the verbose output of opensmtpd starting up at boot? It should be sufficient to 1) Edit /lib/systemd/system/opensmtpd.service and change ExecStart=/usr/sbin/smtpd to ExecStart=/usr/sbin/smtpd -v 2) systemctl daemon-reload 3) reboot 4) Extract the verbose output from the failed start. I think the following should do it: journalctl -b -0 "_SYSTEMD_UNIT=opensmtpd.service" Thanks for the detailed instructions. The log is attached. Thanks, Ryan You are welcome! -- Logs begin at Wed 2020-12-09 15:56:49 CET, end at Wed 2020-12-09 15:58:23 CET. -- déc. 09 15:56:55 myserver smtpd[435]: debug: init ssl-tree déc. 09 15:56:55 myserver smtpd[435]: debug: init ca-tree déc. 09 15:56:55 myserver smtpd[435]: debug: init ssl-tree déc. 09 15:56:55 myserver smtpd[435]: debug: using "fs" queue backend déc. 09 15:56:55 myserver smtpd[435]: debug: using "ramqueue" scheduler backend déc. 09 15:56:55 myserver smtpd[435]: debug: using "ram" stat backend déc. 09 15:56:55 myserver smtpd[435]: info: OpenSMTPD 6.0.3-portable starting déc. 09 15:56:56 myserver smtpd[462]: debug: init ssl-tree déc. 09 15:56:56 myserver smtpd[462]: debug: init ca-tree déc. 09 15:56:56 myserver smtpd[462]: debug: init ssl-tree déc. 09 15:56:56 myserver smtpd[462]: debug: using "fs" queue backend déc. 09 15:56:56 myserver smtpd[462]: debug: using "ramqueue" scheduler backend déc. 09 15:56:56 myserver smtpd[462]: debug: using "ram" stat backend déc. 09 15:56:56 myserver smtpd[462]: setup_peer: lookup -> control[461] fd=5 déc. 09 15:56:56 myserver smtpd[462]: setup_peer: lookup -> pony express[463] fd=6 déc. 09 15:56:56 myserver smtpd[462]: setup_peer: lookup -> queue[464] fd=7 déc. 09 15:56:56 myserver smtpd[461]: debug: init ssl-tree déc. 09 15:56:56 myserver smtpd[461]: debug: init ca-tree déc. 09 15:56:56 myserver smtpd[461]: debug: init ssl-tree déc. 09 15:56:56 myserver smtpd[461]: debug: using "fs" queue backend déc. 09 15:56:56 myserver smtpd[461]: debug: using "ramqueue" scheduler backend déc. 09 15:56:56 myserver smtpd[461]: debug: using "ram" stat backend déc. 09 15:56:56 myserver smtpd[461]: setup_peer: control -> klondike[460] fd=5 déc. 09 15:56:56 myserver smtpd[461]: setup_peer: control -> lookup[462] fd=6 déc. 09 15:56:56 myserver smtpd[461]: setup_peer: control -> pony express[463] fd=7 déc. 09 15:56:56 myserver smtpd[461]: setup_peer: control -> queue[464] fd=8 déc. 09 15:56:56 myserver smtpd[461]: setup_peer: control -> scheduler[465] fd=9 déc. 09 15:56:56 myserver smtpd[463]: debug: init ssl-tree déc. 09 15:56:56 myserver smtpd[463]: debug: init ca-tree déc. 09 15:56:56 myserver smtpd[463]: debug: init ssl-tree déc. 09 15:56:56 myserver smtpd[463]: debug: using "fs" queue backend déc. 09 15:56:56 myserver smtpd[463]: debug: using "ramqueue" scheduler backend déc. 09 15:56:56 myserver smtpd[463]: debug: using "ram" stat backend déc. 09 15:56:56 myserver smtpd[463]: setup_peer: pony express -> control[461] fd=5 déc. 09 15:56:56 myserver smtpd[463]: setup_peer: pony express -> klondike[460] fd=6 déc. 09 15:56:56 myserver smtpd[463]: setup_peer: pony express -> lookup[462] fd=7 déc. 09 15:56:56 myserver smtpd[463]: setup_peer: pony express -> queue[464] fd=8 déc. 09 15:56:56 myserver smtpd[460]: debug: init ssl-tree déc. 09 15:56:56 myserver smtpd[460]: debug: init ca-tree déc. 09 15:56:56 myserver smtpd[460]: debug: init ssl-tree déc. 09 15:56:56 myserver smtpd[460]: debug: using "fs" queue backend déc. 09 15:56:56 myserver smtpd[460]: debug: using "ramqueue" scheduler backend déc. 09 15:56:56 myserver smtpd[460]: debug: using "ram" stat backend déc. 09 15:56:56 myserver smtpd[460]: setup_peer: klondike -> control[461] fd=5 déc. 09 15:56:56 myserver smtpd[460]: setup_peer: klondike -> pony express[463] fd=6 déc. 09 15:56:56 myserver smtpd[459]: setup_done: ca[460] done déc. 09 15:56:56 myserver smtpd[459]: setup_done: control[461] done déc. 09 15:56:56 myserver smtpd[459]: setup_done: lka[462] done déc. 09 15:56:56 myserver smtpd[462]: setup_proc: lookup done déc. 09 15:56:56 myserver smtpd[459]: setup_done: pony[463] done déc. 09 15:56:56 myserver smtpd[463]: setup_proc: pony express done déc. 09 15:56:56 myserver smtpd[461]: setup_proc: control done déc. 09 15:56:56 myserver smtpd[460]: setup_proc: klondike done déc. 09 15:56:56 myserver smtpd[464]: debug: init ssl-tree déc. 09
Bug#976194: opensmtpd: Fails to start on boot with systemd
Dear Yvan, On Tue, Dec 01, 2020 at 11:46:08AM +0100, Yvan Masson wrote: > smtpd[473]: pony express: listen: Address already in use Could you please send me a copy of /etc/smtpd.conf? In particular, I'm curious what "listen on" stanzas you have? Also, could you please send the verbose output of opensmtpd starting up at boot? It should be sufficient to 1) Edit /lib/systemd/system/opensmtpd.service and change ExecStart=/usr/sbin/smtpd to ExecStart=/usr/sbin/smtpd -v 2) systemctl daemon-reload 3) reboot 4) Extract the verbose output from the failed start. I think the following should do it: journalctl -b -0 "_SYSTEMD_UNIT=opensmtpd.service" Thanks, Ryan -- |)|/ Ryan Kavanagh | GPG: 4E46 9519 ED67 7734 268F |\|\ https://rak.ac | BD95 8F7B F8FC 4A11 C97A signature.asc Description: PGP signature
Bug#976194: opensmtpd: Fails to start on boot with systemd
Package: opensmtpd Version: 6.0.3p1-5+deb10u4 Severity: normal Dear Maintainer, My issue is very similar to #779269: opensmtpd fails to automatically start on boot with the following messages (extracted from journalctl): systemd[1]: Starting OpenSMTPD SMTP server... smtpd[437]: info: OpenSMTPD 6.0.3-portable starting systemd[1]: Started OpenSMTPD SMTP server. smtpd[473]: pony express: listen: Address already in use smtpd[469]: smtpd: process lka socket closed systemd[1]: opensmtpd.service: Main process exited, code=exited, status=1/FAILURE systemd[1]: opensmtpd.service: Failed with result 'exit-code'. Also, as suggested in #779269, running `systemctl restart opensmtpd` works. Note that I had the same issue on Stretch before re-installing the system with Buster. I did not do any tests, but one idea that comes to my mind is that this issue arises when using a bridge configuration. Here is my /etc/network/interfaces: source /etc/network/interfaces.d/* # The loopback network interface auto lo iface lo inet loopback auto br0 iface br0 inet static bridge_ports enp9s0 address 192.168.1.2/24 gateway 192.168.1.254 dns-nameserver 80.67.169.12 80.67.169.40 Regards, Yvan -- System Information: Debian Release: 10.6 APT prefers stable-updates APT policy: (500, 'stable-updates'), (500, 'stable') Architecture: amd64 (x86_64) Kernel: Linux 4.19.0-12-amd64 (SMP w/2 CPU cores) Locale: LANG=fr_FR.UTF-8, LC_CTYPE=fr_FR.UTF-8 (charmap=UTF-8), LANGUAGE=fr_FR.UTF-8 (charmap=UTF-8) Shell: /bin/sh linked to /usr/bin/dash Init: systemd (via /run/systemd/system) LSM: AppArmor: enabled Versions of packages opensmtpd depends on: ii adduser3.118 ii debconf [debconf-2.0] 1.5.71 ii ed 1.10-2.1 ii libasr01.0.2-1 ii libc6 2.28-10 ii libdb5.3 5.3.28+dfsg1-0.5 ii libevent-2.1-6 2.1.8-stable-4 ii libpam0g 1.3.1-5 ii libssl1.1 1.1.1d-0+deb10u3 ii lsb-base 10.2019051400 ii zlib1g 1:1.2.11.dfsg-1 Versions of packages opensmtpd recommends: pn opensmtpd-extras Versions of packages opensmtpd suggests: ii ca-certificates 20200601~deb10u1 -- Configuration Files: /etc/smtpd.conf changed [not included] -- debconf information excluded
