Bug 28358 - dhcpd service times out
Summary: dhcpd service times out
Status: RESOLVED FIXED
Alias: None
Product: Mageia
Classification: Unclassified
Component: RPM Packages (show other bugs)
Version: 8
Hardware: All Linux
Priority: Normal normal
Target Milestone: ---
Assignee: All Packagers
QA Contact:
URL:
Whiteboard: feedback
Keywords:
: 24642 27815 (view as bug list)
Depends on: 28976
Blocks:
  Show dependency treegraph
 
Reported: 2021-02-15 05:26 CET by Bit Twister
Modified: 2021-07-01 03:29 CEST (History)
8 users (show)

See Also:
Source RPM: dhcp-4.4.2-8.mga8.src.rpm
CVE:
Status comment:


Attachments

Description Bit Twister 2021-02-15 05:26:00 CET
Description of problem: mga8 rc5

dhcpd.service times out



Version-Release number of selected component (if applicable):


How reproducible: Always


Steps to Reproduce:
1. sustmctl start dhcpd.service


Workaround.

In /usr/lib/systemd/system/dhcpd.service
change Type=notify to Type=forking

remove "-f " from ExecStart=/usr/sbin/dhcpd -f -cf
Comment 1 Lewis Smith 2021-02-17 20:22:54 CET
Thank you for the report and your research for the fix.

I wonder whether this is the same thing as bug 27815, although this does actually look like a new problem. Can you please look at that to judge?

That was fixed by dhcp-4.4.2-7.mga8, you are now at dhcp-4.4.2-8.mga8.

CC: (none) => lewyssmith, luigiwalser

Comment 2 David Walser 2021-02-17 20:27:18 CET
Indeed this was already fixed.  Type=notify should work now.
Comment 3 Lewis Smith 2021-02-17 20:56:57 CET
So why does he say changing it from 'notify' to 'forking' fixed his problem?

@Bit Twister
It might help to have the terminal output of
 systemctl start dhcpd.service
 systemctl status dhcpd.service
before and after your workarounds.
Comment 4 David Walser 2021-02-17 21:08:02 CET
That's not the question, the question is why notify doesn't work for him.  Forking is just a workaround.
Comment 5 Bit Twister 2021-02-17 22:36:25 CET
(In reply to Lewis Smith from comment #3)
> So why does he say changing it from 'notify' to 'forking' fixed his problem?
> 
> @Bit Twister
> It might help to have the terminal output of
>  systemctl start dhcpd.service
>  systemctl status dhcpd.service
> before and after your workarounds.

 dhcpd.service - DHCPv4 Server Daemon
     Loaded: loaded (/usr/lib/systemd/system/dhcpd.service; enabled; vendor preset: disabled)
    Drop-In: /etc/systemd/system/dhcpd.service.d
             └─xx__dhcpd.conf
     Active: failed (Result: timeout) since Wed 2021-02-17 15:27:26 CST; 4min 46s ago
       Docs: man:dhcpd(8)
             man:dhcpd.conf(5)
    Process: 18949 ExecStart=/usr/sbin/dhcpd -f -cf $CONFIGFILE -lf $LEASEFILE -user dhcpd -group dhcpd --no-pid $OPTIONS $IN>
   Main PID: 18949 (code=killed, signal=TERM)
        CPU: 13ms

after
● dhcpd.service - DHCPv4 Server Daemon
     Loaded: loaded (/usr/lib/systemd/system/dhcpd.service; enabled; vendor preset: disabled)
    Drop-In: /etc/systemd/system/dhcpd.service.d
             └─xx__dhcpd.conf
     Active: active (running) since Wed 2021-02-17 15:33:49 CST; 4s ago
       Docs: man:dhcpd(8)
             man:dhcpd.conf(5)
    Process: 19097 ExecStart=/usr/sbin/dhcpd -cf $CONFIGFILE -lf $LEASEFILE -user dhcpd -group dhcpd --no-pid $OPTIONS $INTER>
   Main PID: 19098 (dhcpd)
      Tasks: 1 (limit: 4602)
     Memory: 4.5M
        CPU: 13ms
     CGroup: /system.slice/dhcpd.service
             └─19098 /usr/sbin/dhcpd -cf /etc/dhcpd.conf -lf /var/lib/dhcpd/dhcpd.leases -user dhcpd -group dhcpd --no-pid -q>


And before you ask
 cat /etc/systemd/system/dhcpd.service.d/xx__dhcpd.conf
#
#  Created by /local/bin/dhcpd_xx_conf__changes  Wed 17 Feb 15:18 2021
# https://bugs.mageia.org/show_bug.cgi?id=28358
#

[Service]
Type=forking
ExecStart=
ExecStart=/usr/sbin/dhcpd -cf $CONFIGFILE -lf $LEASEFILE -user dhcpd -group dhcpd --no-pid $OPTIONS $INTERFACES
TimeoutSec=4
#
#*** end /etc/systemd/system/dhcpd.service.d/xx__dhcpd.conf ********
Comment 6 Lewis Smith 2021-02-18 08:42:57 CET
(In reply to David Walser from comment #4)
> That's not the question, the question is why notify doesn't work for him. 
> Forking is just a workaround.
Thanks for the explanation.

@Bit Twister
Thanks for all that information.

'dhcp' has different committers, so having to assign this globally.

CC: lewyssmith => (none)
Assignee: bugsquad => pkg-bugs

Comment 7 Daniel Tartavel 2021-04-01 13:56:47 CEST
Hi,

same problem for me, putting 'forking' instead of 'notify' works well.

CC: (none) => contact

Comment 8 David Walser 2021-05-08 16:40:21 CEST
*** Bug 24642 has been marked as a duplicate of this bug. ***

CC: (none) => rbcourt

David Walser 2021-05-08 16:41:00 CEST

CC: (none) => eatdirt

David Walser 2021-05-08 16:41:20 CEST

CC: (none) => tmb

Comment 9 David Walser 2021-05-08 16:42:51 CEST
Chris thinks there might be a bug in systemd here.  As far as I can tell, dhcp is built with systemd notify support, but it's not working.

Thomas, do you have any insight on this?
Comment 10 David Walser 2021-05-09 23:02:14 CEST
*** Bug 27815 has been marked as a duplicate of this bug. ***

CC: (none) => yves.brungard_mageia

Comment 11 David Walser 2021-05-09 23:59:48 CEST
*** Bug 27815 has been marked as a duplicate of this bug. ***
Comment 12 Chris Denice 2021-05-10 17:56:00 CEST
Two things to clarify, with our current settings (Type: notify)

1) from a properly configure /etc/dhcpd.conf, starting

systemctl start dhcpd

hangs. But looking to the process, it is indeed started, "dhcpd" runs. Looking at the command used in dhcpd.service, there is the "-f" which prevents it to run as a daemon. I think this flag should not be there. So, I remove it and:

2) without the -f flag in dhcpd.service

systemctl start dhcpd 

fails with this message:

May 10 17:48:17 cp3wks01 systemd[1]: Starting DHCPv4 Server Daemon...
May 10 17:48:17 cp3wks01 systemd[1]: dhcpd.service: Failed with result 'protocol'.
May 10 17:48:17 cp3wks01 systemd[1]: Failed to start DHCPv4 Server Daemon.

The "failed with result protocol" is weird. Ducking around, I am landing on:

https://github.com/acassen/keepalived/issues/1845

which seems to suggest a similar error was due to some bad signal handling.

3) Again, the simple route of action would be the just put back the dhcpd service to "forking" instead of "notify".

Cheers.
Comment 13 Bruno Cornec 2021-05-14 20:35:51 CEST
(In reply to Chris Denice from comment #12)
> Two things to clarify, with our current settings (Type: notify)
> 
> 1) from a properly configure /etc/dhcpd.conf, starting
> 
> systemctl start dhcpd
> 
> hangs. But looking to the process, it is indeed started, "dhcpd" runs.
> Looking at the command used in dhcpd.service, there is the "-f" which
> prevents it to run as a daemon. I think this flag should not be there. So, I
> remove it and:
> 
> 2) without the -f flag in dhcpd.service
> 
> systemctl start dhcpd 
> 
> fails with this message:
> 
> May 10 17:48:17 cp3wks01 systemd[1]: Starting DHCPv4 Server Daemon...
> May 10 17:48:17 cp3wks01 systemd[1]: dhcpd.service: Failed with result
> 'protocol'.
> May 10 17:48:17 cp3wks01 systemd[1]: Failed to start DHCPv4 Server Daemon.
> 
> The "failed with result protocol" is weird. Ducking around, I am landing on:
> 
> https://github.com/acassen/keepalived/issues/1845
> 
> which seems to suggest a similar error was due to some bad signal handling.
> 
> 3) Again, the simple route of action would be the just put back the dhcpd
> service to "forking" instead of "notify".
> 
> Cheers.

Without knowing tha BR, I did exactly the same as you after updating my Mageia 7 server to Mageia 8. I had to move from notify to forking and remove the -f so the daemon starts correctly. Similar analysis as you it indeed starts (even works) but seems to be killed by systemd after a certain amount of time.

I'd suggest to do the change for a Mageia8 update so people are not seeing that issue. I can even do it it everybody agrees it's a good thing.

Let me know.

CC: (none) => bruno

Comment 14 David Walser 2021-05-14 20:38:38 CEST
Might as well.
Comment 15 Thomas Backlund 2021-05-14 20:42:29 CEST
sorry for not responding earlier...

looking at dhcp srpm, it has a patch for systemd notify integration, but it's not applied...

I will take a look ...
Comment 16 Thomas Backlund 2021-05-14 20:54:18 CEST
 dhcp-4.4.2-9.mga8 submitted to testing
Comment 17 Thomas Backlund 2021-05-15 08:41:33 CEST
silly me.. I forgot to enable systemd config at build time...

there should soon be a dhcp-4.4.2-10.mga8 in testing
Comment 18 Aurelien Oudelet 2021-05-23 17:26:41 CEST
(In reply to Thomas Backlund from comment #17)
> silly me.. I forgot to enable systemd config at build time...
> 
> there should soon be a dhcp-4.4.2-10.mga8 in testing

$ rpm -qa | grep dhcp
dhcp-common-4.4.2-10.mga8
dhcp-server-4.4.2-10.mga8
dhcp-client-4.4.2-10.mga8

There is something wrong...
As machine reboot:

$ systemctl status dhcpd
● dhcpd.service - DHCPv4 Server Daemon
     Loaded: loaded (/usr/lib/systemd/system/dhcpd.service; enabled; vendor preset: disabled)
     Active: failed (Result: exit-code) since Sun 2021-05-23 17:14:59 CEST; 2min 8s ago
       Docs: man:dhcpd(8)
             man:dhcpd.conf(5)
    Process: 1042 ExecStart=/usr/sbin/dhcpd -f -cf $CONFIGFILE -lf $LEASEFILE -user dhcpd -group dhcpd --no-pid $OPTIONS $INTERFACES (code=exited, status=1/FAILURE)
   Main PID: 1042 (code=exited, status=1/FAILURE)
        CPU: 9ms

mai 23 17:14:59 localhost dhcpd[1042]: If you think you have received this message due to a bug rather
mai 23 17:14:59 localhost dhcpd[1042]: than a configuration issue please read the section on submitting
mai 23 17:14:59 localhost dhcpd[1042]: bugs on either our web page at www.isc.org or in the README file
mai 23 17:14:59 localhost dhcpd[1042]: before submitting a bug.  These pages explain the proper
mai 23 17:14:59 localhost dhcpd[1042]: process and the information we find helpful for debugging.
mai 23 17:14:59 localhost dhcpd[1042]: 
mai 23 17:14:59 localhost dhcpd[1042]: exiting.
mai 23 17:14:59 localhost systemd[1]: dhcpd.service: Main process exited, code=exited, status=1/FAILURE
mai 23 17:14:59 localhost systemd[1]: dhcpd.service: Failed with result 'exit-code'.
mai 23 17:14:59 localhost systemd[1]: Failed to start DHCPv4 Server Daemon.


WHY the ExecStart=/usr/sbin/dhcpd -f -cf $CONFIGFILE -lf $LEASEFILE -user dhcpd -group dhcpd --no-pid $OPTIONS $INTERFACES (code=exited, status=1/FAILURE)
??

If I start again dhcpd:

[aurelien@localhost ~]$ sudo systemctl start dhcpd
[sudo] Mot de passe de aurelien : 

[aurelien@localhost ~]$ systemctl status dhcpd
● dhcpd.service - DHCPv4 Server Daemon
     Loaded: loaded (/usr/lib/systemd/system/dhcpd.service; enabled; vendor preset: disabled)
     Active: active (running) since Sun 2021-05-23 17:17:23 CEST; 2s ago
       Docs: man:dhcpd(8)
             man:dhcpd.conf(5)
   Main PID: 2312 (dhcpd)
     Status: "Dispatching packets..."
      Tasks: 1 (limit: 4693)
     Memory: 4.4M
        CPU: 9ms
     CGroup: /system.slice/dhcpd.service
             └─2312 /usr/sbin/dhcpd -f -cf /etc/dhcpd.conf -lf /var/lib/dhcpd/dhcpd.leases -user dhcpd -group dhcpd --no-pid -q enp0s8

mai 23 17:17:23 localhost systemd[1]: Starting DHCPv4 Server Daemon...
mai 23 17:17:23 localhost dhcpd[2312]: ldap_gssapi_principal is not set,GSSAPI Authentication for LDAP will not be used
mai 23 17:17:23 localhost dhcpd[2312]: Not searching LDAP since ldap-server, ldap-port and ldap-base-dn were not specified in the config file
mai 23 17:17:23 localhost dhcpd[2312]: Source compiled to use binary-leases
mai 23 17:17:23 localhost dhcpd[2312]: Wrote 0 leases to leases file.
mai 23 17:17:23 localhost dhcpd[2312]: Server starting service.
mai 23 17:17:23 localhost systemd[1]: Started DHCPv4 Server Daemon.


Here is the content of /usr/lib/systemd/system/dhcpd.service
Something wrong in it?

[Unit]
Description=DHCPv4 Server Daemon
Documentation=man:dhcpd(8) man:dhcpd.conf(5)
Wants=network-online.target
After=network-online.target
After=time-sync.target

[Service]
Type=notify
Environment=CONFIGFILE=/etc/dhcpd.conf LEASEFILE=/var/lib/dhcpd/dhcpd.leases
EnvironmentFile=-/etc/sysconfig/dhcpd   <<=== The MINUS is OK here?
ExecStart=/usr/sbin/dhcpd -f -cf $CONFIGFILE -lf $LEASEFILE -user dhcpd -group dhcpd --no-pid $OPTIONS $INTERFACES
StandardError=null

[Install]
WantedBy=multi-user.target

CC: (none) => ouaurelien

Aurelien Oudelet 2021-05-23 17:26:53 CEST

Whiteboard: (none) => feedback

Comment 19 David Walser 2021-05-23 18:19:31 CEST
Yes, the minus is correct, it just means that the referenced file is not required.  The service unit file is correct.  You do need a valid /etc/dhcpd.conf for the service to work.
David Walser 2021-05-27 18:21:37 CEST

Depends on: (none) => 28976

Comment 20 David Walser 2021-07-01 03:29:50 CEST
Fixed in:
https://advisories.mageia.org/MGASA-2021-0307.html

Status: NEW => RESOLVED
Resolution: (none) => FIXED


Note You need to log in before you can comment on or make changes to this bug.