Bug 1035445 - dhcpd service start timeout
Summary: dhcpd service start timeout
Keywords:
Status: CLOSED NOTABUG
Alias: None
Product: Fedora
Classification: Fedora
Component: systemd
Version: 20
Hardware: i686
OS: Linux
unspecified
unspecified
Target Milestone: ---
Assignee: systemd-maint
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2013-11-27 19:31 UTC by Vlad
Modified: 2013-12-13 00:30 UTC (History)
10 users (show)

Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed: 2013-12-13 00:30:29 UTC
Type: Bug


Attachments (Terms of Use)

Description Vlad 2013-11-27 19:31:14 UTC
Fedora 20, dhcp-4.2.5-26.fc20.i686

dhcpd won't start, I'm getting:
Dispatcher script timed out: Script '/etc/NetworkManager/dispatcher.d/12-dhcpd

I've tried to manually start it with systemctl start dhcpd.service and it just hangs there.

`ps ax' does 'show systemctl restart dhcpd.service' command running, but doesn't show dhcpd process itself is being started. Nothing useful in /var/log/*

SELinux is disabled.
Starting dhcpd manually produces the following output:

# /usr/sbin/dhcpd -f -d -cf /etc/dhcp/dhcpd.conf -user dhcpd -group dhcpd
Internet Systems Consortium DHCP Server 4.2.5
Copyright 2004-2013 Internet Systems Consortium.
All rights reserved.
For info, please visit https://www.isc.org/software/dhcp/
Not searching LDAP since ldap-server, ldap-port and ldap-base-dn were not specified in the config file
Wrote 0 deleted host decls to leases file.
Wrote 0 new dynamic host decls to leases file.
Wrote 58 leases to leases file.

No subnet declaration for p37p1 (67.184.72.143).
** Ignoring requests on p37p1.  If this is not what
   you want, please write a subnet declaration
   in your dhcpd.conf file for the network segment
   to which interface p37p1 is attached. **

Listening on LPF/p36p1/00:25:90:05:11:66/192.168.0.0/24
Sending on   LPF/p36p1/00:25:90:05:11:66/192.168.0.0/24
Sending on   Socket/fallback/fallback-net

Comment 1 Jiri Popelka 2013-11-27 19:42:07 UTC
So running it manually works.

And what do you see if you do
# systemctl start dhcpd
(wait a moment)
# systemctl status dhcpd
?

If you see some more relevant info in 'journalctl -r' output post it here too.

Comment 2 Vlad 2013-11-27 20:01:40 UTC
as I indicated in my original submission, `systemctl start dhcpd' never returns to console (well, I waited 5 minutes), it just stays there. Here is output from another console, while `systemctl start dhcpd' is trying to startup:

[root@nas ~]# systemctl status dhcpd
dhcpd.service - DHCPv4 Server Daemon
   Loaded: loaded (/usr/lib/systemd/system/dhcpd.service; disabled)
   Active: inactive (dead)
     Docs: man:dhcpd(8)
           man:dhcpd.conf(5)

[root@nas ~]# ps ax | grep dhcp
  422 ?        S      0:00 /sbin/dhclient -d -sf /usr/libexec/nm-dhcp-helper -pf /var/run/dhclient-p37p1.pid -lf /var/lib/NetworkManager/dhclient-feed5bf5-2f88-7d33-96e3-79c6ac5d38c9-p37p1.lease -cf /var/lib/NetworkManager/dhclient-p37p1.conf p37p1
  983 pts/1    S+     0:00 systemctl start dhcpd
  995 pts/0    S+     0:00 grep --color=auto dhcp
[root@nas ~]#

Comment 3 Vlad 2013-11-27 20:03:15 UTC
oh, and /var/log/messages as well as journalctl are absolutely silent in regards to anything related to dhcpd, while attempt to start it is being made.

Comment 4 Vlad 2013-11-27 20:14:09 UTC
Looks like something it preventing dhcp from start - I guess it's likely some problem not in dhcp itself, but rather in NetworkManager or systemd subsystem.

Comment 5 Jiri Popelka 2013-11-28 08:44:23 UTC
Vlad, could you attach your dhcpd.conf ?

Lukáš, how can we debug this ?

Comment 6 Vlad 2013-11-28 14:33:46 UTC
log-facility local7;

subnet 192.168.0.0 netmask 255.255.255.0 {
  authoritative;
  option routers 192.168.0.1;
  option broadcast-address 192.168.0.255;
  option domain-name-servers 75.75.76.76,75.75.75.75,8.8.8.8;
  option ntp-servers 0.us.pool.ntp.org,1.us.pool.ntp.org;
  option ip-forwarding off;

  pool {
      range 192.168.0.64 192.168.0.192;
      default-lease-time 3600;
      max-lease-time 7200;
      deny known-clients;
   }
}

# bunch of hosts definition all using the following template:
host xxxxx {
  hardware ethernet 7c:2f:80:xx:xx:xx;
  fixed-address 192.168.0.101;
  option host-name "xxxxxx";
}

Comment 7 Jiri Popelka 2013-11-28 15:10:36 UTC
I don't have a problem running such configuration here.

Reassigning to systemd because the daemon runs by hand but not via 'systemctl start dhcpd.service'. Guys, any idea how to debug this ?

Comment 8 Michal Schmidt 2013-11-29 10:08:25 UTC
Please provide also the output of "systemctl list-jobs" while the start operation is stuck.

Comment 9 Vlad 2013-12-01 20:05:30 UTC
 JOB UNIT                                 TYPE  STATE
 153 systemd-readahead-done.timer         start waiting
  85 multi-user.target                    start waiting
 155 systemd-update-utmp-runlevel.service start waiting
 157 ntpd.service                         start waiting
 159 crond.service                        start waiting
 178 ntpdate.service                      start running
 179 time-sync.target                     start waiting
1237 dhcpd.service                        start waiting


Btw, is there any way to temporary enable debug log level on systemd w/o passing it via kernel parameter?

Comment 10 Zbigniew Jędrzejewski-Szmek 2013-12-01 23:51:34 UTC
(In reply to Vlad from comment #9)
>  JOB UNIT                                 TYPE  STATE
>  153 systemd-readahead-done.timer         start waiting
>   85 multi-user.target                    start waiting
>  155 systemd-update-utmp-runlevel.service start waiting
>  157 ntpd.service                         start waiting
>  159 crond.service                        start waiting
>  178 ntpdate.service                      start running
>  179 time-sync.target                     start waiting
> 1237 dhcpd.service                        start waiting
OK, so things are pretty clear: ntpd.service is waiting for time-sync.target, which is waiting for ntpdate.service. (ntpd.service has After=time-sync.target). I think there's no bug here.
 
> Btw, is there any way to temporary enable debug log level on systemd w/o
> passing it via kernel parameter?
Either 'kill -SIGRTMIN+22 1' or 'systemd-analyze set-loglevel debug'.

Comment 11 Vlad 2013-12-02 00:48:54 UTC
okay, thanks. next thing, i guess, need to figure out why ntpdate is stuck


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