DHCP errors after backup

storm · July 20, 2022, 10:05am

Hello,

I keep on getting DHCP errors after the machine resumes from the backup.
Processing: syslog…
syslog.txt (1.2 MB)

That is the complete syslog. You can see that at around 6am something happens to the DHCP.

If i reboot the machine it will start working again. But i need this to work right after the backups because it manages my internal basic networking services and it contains some records about my external machines too.

I can’t really understand where is the problem.

If you could please help

Thank you

knebb · July 21, 2022, 10:38am

Hi,

are you sure, anyone will:

download an attachment from an unknown source to its own computer?
read the full (!) syslog.txt to find issue, especially when not knowing what to look for?

Post the part from the syslog which is important and describe the issue you are having in a more detailed way!

/KNEBB

storm · July 25, 2022, 7:06am

You are correct, thank you for pointing it out… i posted this a little bit out of frustration because i cannot point out the reason for this error…
Anyway, the machine goes down for a backup at around 6:30am when it gets back up the first relevant error message is this

Jul 25 06:38:02 ucsdc systemd[1]: univention-self-service-invitation.service: Main process exited, code=exited, status=1/FAILURE
Jul 25 06:38:02 ucsdc systemd[1]: univention-self-service-invitation.service: Failed with result ‘exit-code’.
Jul 25 06:38:02 ucsdc nmbd[650]: Starting NetBIOS name server: nmbd.
Jul 25 06:38:02 ucsdc systemd[1]: Started LSB: Samba NetBIOS nameserver (nmbd).
Jul 25 06:38:04 ucsdc slapd[955]: slapd starting
Jul 25 06:38:04 ucsdc slapd[677]: Starting ldap server(s): slapd …done.
Jul 25 06:38:05 ucsdc samba4[936]: rndc: connect failed: 127.0.0.1#953: connection refused

This rndc error pops up even after bind9 has started then after like a minute this happens:

Jul 25 06:38:52 ucsdc named[935]: loading configuration: shutting down
Jul 25 06:38:52 ucsdc named[935]: exiting (due to fatal error)
Jul 25 06:38:52 ucsdc named[935]: …/…/…/bin/named/client.c:3516: unexpected error:
Jul 25 06:38:52 ucsdc named[935]: isc_socket_accept() failed: shutting down
Jul 25 06:38:52 ucsdc named[935]: …/…/…/bin/named/client.c:3516: unexpected error:
Jul 25 06:38:52 ucsdc named[935]: isc_socket_accept() failed: shutting down
Jul 25 06:38:52 ucsdc named[935]: …/…/…/bin/named/client.c:3516: unexpected error:
Jul 25 06:38:52 ucsdc named[935]: isc_socket_accept() failed: shutting down
Jul 25 06:38:52 ucsdc named[935]: samba_dlz: shutting down
Jul 25 06:38:52 ucsdc systemd[1]: bind9.service: Main process exited, code=exited, status=1/FAILURE
Jul 25 06:38:52 ucsdc systemd[1]: bind9.service: Failed with result ‘exit-code’.
Jul 25 06:38:52 ucsdc systemd[1]: Failed to start BIND Domain Name Server with samba4 backend.
Jul 25 06:38:52 ucsdc systemd[1]: Reached target Host and Network Name Lookups.
Jul 25 06:38:52 ucsdc systemd[1]: Starting ISC DHCP Server for IPv4…
Jul 25 06:38:52 ucsdc systemd[1]: Starting Postfix Mail Transport Agent (instance -)…
Jul 25 06:38:52 ucsdc systemd[1]: Started Nagios Remote Plugin Executor.
Jul 25 06:38:52 ucsdc systemd[1]: Starting LSB: Univention Updater…
Jul 25 06:38:53 ucsdc univention-maintenance[1760]: Checking network for Univention maintenance…ldap[ucsdc.2gnetworks.it]…done.
Jul 25 06:38:53 ucsdc systemd[1]: Started LSB: Univention Updater.
Jul 25 06:38:53 ucsdc nrpe[1759]: add_ipv4_to_acl: Error, ip-address >ucsdc.2gnetworks.it< incorrect length

This triggers the DHCP error apparently:

Jul 25 06:39:05 ucsdc systemd[1]: univention-s4-connector.service: Can’t open PID file /run/univention-s4-connector (yet?) after start: No such file or directory
Jul 25 06:39:05 ucsdc systemd[1]: univention-s4-connector.service: Supervising process 1878 which is not our child. We’ll most likely not notice when it exits.
Jul 25 06:39:05 ucsdc systemd[1]: Started LSB: Univention S4 Connector.
Jul 25 06:39:08 ucsdc systemd[1]: Started Postfix Mail Transport Agent (instance -).
Jul 25 06:39:08 ucsdc systemd[1]: Starting Postfix Mail Transport Agent…
Jul 25 06:39:08 ucsdc systemd[1]: Started Postfix Mail Transport Agent.
Jul 25 06:39:11 ucsdc qemu-ga: info: guest-ping called
Jul 25 06:39:12 ucsdc dhcpd[1761]: Configuration file errors encountered – exiting
Jul 25 06:39:12 ucsdc dhcpd[1761]:
Jul 25 06:39:12 ucsdc systemd[1]: isc-dhcp-server.service: Control process exited, code=exited, status=1/FAILURE
Jul 25 06:39:12 ucsdc dhcpd[1761]: If you think you have received this message due to a bug rather
Jul 25 06:39:12 ucsdc systemd[1]: isc-dhcp-server.service: Failed with result ‘exit-code’.
Jul 25 06:39:12 ucsdc dhcpd[1761]: than a configuration issue please read the section on submitting
Jul 25 06:39:12 ucsdc systemd[1]: Failed to start ISC DHCP Server for IPv4.
Jul 25 06:39:12 ucsdc dhcpd[1761]: bugs on either our web page at www.isc.org or in the README file
Jul 25 06:39:12 ucsdc dhcpd[1761]: before submitting a bug. These pages explain the proper
Jul 25 06:39:12 ucsdc dhcpd[1761]: process and the information we find helpful for debugging.
Jul 25 06:39:12 ucsdc dhcpd[1761]:
Jul 25 06:39:12 ucsdc dhcpd[1761]: exiting.

A:

systemctl restart bind9

seems to solve the problem but it shouldn’t be there in the first place. In my first post you can find a complete syslog if needed. I am unable to figure out why this happens.

Ofcourse if bind doesn’t work none of my internal machines can access the internet and some external services linked to my DC won’t work either.

thanks a lot again

knebb · August 30, 2022, 11:52am

Sorry, I have not seen your reply earlier.
Anyways. I quoted the most important part. First is a message from Sambe not being able to connect through rndc. AFAIK this can be ignored as usually Samba does not control the bind9 through rndc. Not sure, though.

Second is an error from the bind9/ named process as there seems to be an unexpected error. The isc_socket_accept usually comes up, when there is already a named-process running… so the new process cannot access the network port an therefore exists.

Independently from the above there is an error in your DHCP configuration so the dhcp-server does not start. I doubt it starts when doing it manually. So from my point of view this has nothing to do with the scheduled backup. Monitor your services an see if they are up and running all day. Stop/Start/Restart them to see if they continue to run or if they get configuration errors. If they do, go further the track of figuring out why there are configuration errors.

/KNEBB