Re: Postfix fails after upgrade from bullseye to bookworm
Am Fri, Jan 20, 2023 at 08:28:10PM +0100 schrieb Sven Joachim:
> On 2023-01-20 13:39 -0500, Greg Wooledge wrote:
>
> > On Fri, Jan 20, 2023 at 07:17:37PM +0100, Sven Joachim wrote:
Hello Community,
> >> It seems that postfix's startup time has greatly regressed, on my laptop
> >> there are very long delays both at boot:
> >>
> >> ,----
> >> | $ systemd-analyze blame | head -n1
> >> | 33.340s postfix@-.service
> >> `----
> >
> > A delay that's a multiple of 30 seconds is very often a DNS lookup
> > failure. I would imagine your postfix configuration is trying to
> > perform a DNS lookup on some hostname or other, and that this is
> > happening before you're actually "online", for whatever definition of
> > "online" is relevant here.
>
> That should be NetworkManager-wait-online.service. In the logs I see
> that systemd starts the postfix service directly after reaching
> network-online.target, as it is supposed to do. The mystery is why it
> takes another 30+ seconds before any messages from postfix itself appear
> in the logs.
>
> > That's a total guess, though. Find your logfiles and read them to see
> > what's actually going on.
>
> Here is what I see in the journal when I restart postfix.service:
>
> ,----
> | Jan 20 20:16:06 myhost postfix/postfix-script[1470]: stopping the Postfix mail system
> | Jan 20 20:16:06 myhost postfix/master[1307]: terminating on signal 15
> | Jan 20 20:16:06 myhost systemd[1]: postfix@-.service: Deactivated successfully.
> | Jan 20 20:16:06 myhost systemd[1]: Stopped Postfix Mail Transport Agent (instance -).
> | Jan 20 20:16:06 myhost systemd[1]: postfix@-.service: Consumed 36.372s CPU time.
> | Jan 20 20:16:06 myhost systemd[1]: Starting Postfix Mail Transport Agent (instance -)...
> | Jan 20 20:16:41 myhost postfix[1800]: Postfix is using backwards-compatible default settings
> | Jan 20 20:16:41 myhost postfix[1800]: See http://www.postfix.org/COMPATIBILITY_README.html for details
> | Jan 20 20:16:41 myhost postfix[1800]: To disable backwards compatibility use "postconf compatibility_level=3.6" and "pos\
> | tfix reload"
> | Jan 20 20:16:42 myhost postfix/postfix-script[2026]: starting the Postfix mail system
> | Jan 20 20:16:42 myhost postfix/master[2028]: daemon started -- version 3.7.3, configuration /etc/postfix
> | Jan 20 20:16:42 myhost systemd[1]: Started Postfix Mail Transport Agent (instance -).
> | Jan 20 20:16:42 myhost systemd[1]: Starting Postfix Mail Transport Agent...
> | Jan 20 20:16:42 myhost systemd[1]: Finished Postfix Mail Transport Agent.
> `----
I have observed something comparable, but with fetchmail for email
and unbound as a dns resover. Both are started by systemd at almost
the same time. But it takes some time for unbound to fetch keys and so
on. Before unbound is really ready fetchmail has started its first
poll, but without success because the mail servers ip could not be
resolved.
I am only a hobbyist. But may be something similar is happening in the
discussed issue. May be it is worth to have a look how the dns lookup
is set up and how it is starting.
Please just ignore be if this proposal makes no sense.
At work I am no admin :-).
> I have left nothing out, so WTH is postfix waiting for in these 35
> seconds?
>
> Cheers,
> Sven
BTW: I have resolved my issue by starting fetchmail via systemd by a
wrapper script which probes the dns resolution of the mail server
before starting fetchmail.
Kind regards,
Christoph
--
Ist die Katze gesund
schmeckt sie dem Hund.
Reply to: