Recently apache2 fails to start at boot, but can be started OK manually

[Chris Green]

On Wed, Oct 27, 2021 at 09:07:51AM +0100, Colin Law wrote:
> On Tue, 26 Oct 2021 at 14:00, Chris Green <cl at isbd.net> wrote:
> >
> > Just recently on my 21.04 system apache2 has failed to start at boot
> > time with the following errors reported by systemd:-
> >
> >     Oct 26 13:42:11 esprimo systemd[1]: Starting The Apache HTTP Server...
> > Oct 26 13:42:11 esprimo apachectl[853]: (99)Cannot assign requested address: 
> AH00072: make_sock: could not bind to address 192.168.1.3:80 
> >     Oct 26 13:42:11 esprimo apachectl[853]: no listening sockets available, shutting down
> >     Oct 26 13:42:11 esprimo apachectl[853]: AH00015: Unable to open logs
> >     Oct 26 13:42:11 esprimo apachectl[821]: Action 'start' failed.
> >     Oct 26 13:42:11 esprimo apachectl[821]: The Apache error log may have more information.
> > Oct 26 13:42:11 esprimo systemd[1]: apache2.service: Control process 
> exited, code=exited, status=1/FAILURE 
> >     Oct 26 13:42:11 esprimo systemd[1]: apache2.service: Failed with result 'exit-code'.
> >     Oct 26 13:42:11 esprimo systemd[1]: Failed to start The Apache HTTP Server.
> >
> 
> Look in syslog and check whether the network has started up by that point.
>  Start with
> grep "192.168.1.3" /var/log/syslog
> 
Hmm, it's a bit confusing but here's the result of the above grep for
the times around the reboot:-

    Oct 25 17:48:31 esprimo syncthing[814]: [BKI6D] INFO: Connection to ZGBSAI4-2LJRK3X-DTU7QC4-SAFO3QP-LFXD37N-WAFZY7H-BB3TGXO-UJX5DAU at 192.168.1.3:22000-192.168.1.92:22000/tcp-client/TLS1.3-TLS_AES_128_GCM_SHA256 closed: read timeout
    Jan  1 00:02:28 2820n.zbmc.eu 2820n: [Web]WebUI login success from IP 192.168.1.3 [Admin]
    Oct 26 13:42:11 esprimo apachectl[853]: (99)Cannot assign requested address: AH00072: make_sock: could not bind to address 192.168.1.3:80
    Oct 26 13:42:14 esprimo avahi-daemon[724]: Joining mDNS multicast group on interface enp0s25.IPv4 with address 192.168.1.3.
    Oct 26 13:42:14 esprimo avahi-daemon[724]: Registering new address record for 192.168.1.3 on enp0s25.IPv4.
    Oct 26 13:42:28 esprimo syncthing[830]: [BKI6D] INFO: Established secure connection to HKUMIOL-CCJEAQ6-EZQZQ4H-YXNADU2-364ARZZ-YVFVWZE-43HKY36-M64W5AF at 192.168.1.3:22000-192.168.1.109:43923/quic-server/TLS1.3-TLS_CHACHA20_POLY1305_SHA256

I assume that 'Jan 1' date is early in the boot sequence when the time
hasn't been set.  Ah, no it isn't it's simply that 2820n.zbmc.eu (a 
router) has the wrong date and is logging to the same syslog.  So that's
a red herring.

I can't see anything else which looks particularly relevant in syslog.  
Network Manager has run and set up networking before apache tries to
start.


-- 
Chris Green