趣味的なIT・ネットの話題

Raspberry PiでIoTなIT:起動時dhcpcdによる無線LANインターフェースへのIP割り当てが遅くてisc-dhcp-serverが起動に失敗する

Raspberry Piをアクセスポイント化するための仕上げとしてisc-dhcp-serverをインストールしたところ、serverコマンドだと起動できるのに、起動時には起動できないという問題が発生。

pi@raspberrypi:~ $ ps ax | grep dhcp
  604 ?        Ss     0:00 /sbin/dhcpcd -q -w
  715 pts/0    S+     0:00 grep --color=auto dhcp

色々と分析してみると、起動時にwlan0のIP割り当てよりも早くDHCPサーバーが起動開始してしまい、作動対象のwlan0が存在していなくて、起動に失敗している模様。

Feb 10 22:08:31 raspberrypi dhcpd: Internet Systems Consortium DHCP Server 4.3.1
Feb 10 22:08:31 raspberrypi dhcpd: Copyright 2004-2014 Internet Systems Consortium.
Feb 10 22:08:31 raspberrypi dhcpd: All rights reserved.
Feb 10 22:08:31 raspberrypi dhcpd: For info, please visit https://www.isc.org/software/dhcp/
Feb 10 22:08:31 raspberrypi dhcpd: Internet Systems Consortium DHCP Server 4.3.1
Feb 10 22:08:31 raspberrypi dhcpd: Copyright 2004-2014 Internet Systems Consortium.
Feb 10 22:08:31 raspberrypi dhcpd: All rights reserved.
Feb 10 22:08:31 raspberrypi dhcpd: For info, please visit https://www.isc.org/software/dhcp/
Feb 10 22:08:31 raspberrypi dhcpd: Wrote 1 leases to leases file.
Feb 10 22:08:31 raspberrypi ntpd[634]: Listen normally on 2 lo 127.0.0.1 UDP 123
Feb 10 22:08:31 raspberrypi ntpd[634]: Listen normally on 3 eth0 192.168.2.10 UDP 123
Feb 10 22:08:31 raspberrypi ntpd[634]: Listen normally on 4 lo ::1 UDP 123
Feb 10 22:08:31 raspberrypi ntpd[634]: Listen normally on 5 eth0 fe80::5451:ee7b:51eb:6a2c UDP 123
Feb 10 22:08:31 raspberrypi ntpd[634]: peers refreshed
Feb 10 22:08:31 raspberrypi ntpd[634]: Listening on routing socket on fd #22 for interface updates
Feb 10 22:08:31 raspberrypi dhcpd: 
Feb 10 22:08:31 raspberrypi dhcpd: No subnet declaration for wlan0 (no IPv4 addresses).
Feb 10 22:08:31 raspberrypi dhcpd: ** Ignoring requests on wlan0.  If this is not what
Feb 10 22:08:31 raspberrypi dhcpd:    you want, please write a subnet declaration
Feb 10 22:08:31 raspberrypi dhcpd:    in your dhcpd.conf file for the network segment
Feb 10 22:08:31 raspberrypi dhcpd:    to which interface wlan0 is attached. **
Feb 10 22:08:31 raspberrypi dhcpd: 
Feb 10 22:08:31 raspberrypi dhcpd: 
Feb 10 22:08:31 raspberrypi dhcpd: Not configured to listen on any interfaces!
Feb 10 22:08:31 raspberrypi dhcpd: 
Feb 10 22:08:31 raspberrypi dhcpd: If you think you have received this message due to a bug rather
Feb 10 22:08:31 raspberrypi dhcpd: than a configuration issue please read the section on submitting
Feb 10 22:08:31 raspberrypi dhcpd: bugs on either our web page at www.isc.org or in the README file
Feb 10 22:08:31 raspberrypi dhcpd: before submitting a bug.  These pages explain the proper
Feb 10 22:08:31 raspberrypi dhcpd: process and the information we find helpful for debugging..
Feb 10 22:08:31 raspberrypi dhcpd: 
Feb 10 22:08:31 raspberrypi dhcpd: exiting.
Feb 10 22:08:31 raspberrypi kernel: [   17.255254] IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
Feb 10 22:08:31 raspberrypi dhcpcd[604]: wlan0: carrier acquired
Feb 10 22:08:31 raspberrypi hostapd[607]: Starting advanced IEEE 802.11 management: hostapd.
Feb 10 22:08:31 raspberrypi systemd[1]: Started LSB: Advanced IEEE 802.11 management daemon.
Feb 10 22:08:31 raspberrypi dhcpcd[604]: wlan0: IAID c5:5d:34:91
Feb 10 22:08:31 raspberrypi dhcpcd[604]: wlan0: using static address 192.168.10.1/24
Feb 10 22:08:31 raspberrypi avahi-daemon[349]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.10.1.
Feb 10 22:08:31 raspberrypi avahi-daemon[349]: New relevant interface wlan0.IPv4 for mDNS.
Feb 10 22:08:31 raspberrypi dhcpcd[604]: wlan0: adding route to 192.168.10.0/24
Feb 10 22:08:31 raspberrypi avahi-daemon[349]: Registering new address record for 192.168.10.1 on wlan0.IPv4.
Feb 10 22:08:31 raspberrypi dhcpcd[604]: wlan0: soliciting an IPv6 router
Feb 10 22:08:33 raspberrypi isc-dhcp-server[610]: Starting ISC DHCP server: dhcpdcheck syslog for diagnostics. ... failed!
Feb 10 22:08:33 raspberrypi isc-dhcp-server[610]: failed!

rc3.dのスクリプトの順序を変えてみたのですが、その程度では間に合わないようです。そこで非常にローテクで美しくないのですが、その場的対策として、sleepで無理矢理起動開始を遅くします。

pi@raspberrypi:~ $ sudo nano /etc/init.d/isc-dhcp-server

start-stop-daemonの前に5秒待ちを挿入しました。

case "$1" in
        start)
                test_config
                log_daemon_msg "Starting $DESC" "$NAME"
                sleep 5
                start-stop-daemon --start --quiet --pidfile "$DHCPD_PID" \
                        --exec /usr/sbin/dhcpd -- \
                        -q $OPTIONS -cf "$DHCPD_CONF" -pf "$DHCPD_PID" $INTERFA$
                sleep 2

これで起動をしたところ、isc-dhcp-serverのプロセスが生き残っていました。

pi@raspberrypi:~ $ ps ax | grep dhcp
  605 ?        Ss     0:00 /sbin/dhcpcd -q -w
  682 ?        Ss     0:00 /usr/sbin/dhcpd -q -cf /etc/dhcp/dhcpd.conf -pf /var/run/dhcpd.pid wlan0
  713 pts/0    S+     0:00 grep --color=auto dhcp

ログを見るとisc-dhcp-serverの起動開始よりも4秒早くwlan0のIP割り当てが完了しています。

Feb 10 21:56:30 raspberrypi dhcpcd[605]: wlan0: IAID c5:5d:34:91
Feb 10 21:56:30 raspberrypi dhcpcd[605]: wlan0: soliciting an IPv6 router
Feb 10 21:56:30 raspberrypi dhcpcd[605]: wlan0: using static address 192.168.10.1/24
Feb 10 21:56:30 raspberrypi avahi-daemon[345]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.10.1.
Feb 10 21:56:30 raspberrypi dhcpcd[605]: wlan0: adding route to 192.168.10.0/24
Feb 10 21:56:30 raspberrypi avahi-daemon[345]: New relevant interface wlan0.IPv4 for mDNS.
Feb 10 21:56:30 raspberrypi avahi-daemon[345]: Registering new address record for 192.168.10.1 on wlan0.IPv4.
Feb 10 21:56:31 raspberrypi dhcpcd[605]: eth0: no IPv6 Routers available
Feb 10 21:56:32 raspberrypi hostapd: wlan0: STA d4:f4:6f:04:f3:49 IEEE 802.11: associated
Feb 10 21:56:32 raspberrypi hostapd: wlan0: STA d4:f4:6f:04:f3:49 RADIUS: starting accounting session 56BB337E-00000000
Feb 10 21:56:32 raspberrypi hostapd: wlan0: STA d4:f4:6f:04:f3:49 WPA: pairwise key handshake completed (RSN)
Feb 10 21:56:34 raspberrypi dhcpd: Internet Systems Consortium DHCP Server 4.3.1
Feb 10 21:56:34 raspberrypi dhcpd: Copyright 2004-2014 Internet Systems Consortium.
Feb 10 21:56:34 raspberrypi dhcpd: All rights reserved.
Feb 10 21:56:34 raspberrypi dhcpd: For info, please visit https://www.isc.org/software/dhcp/
Feb 10 21:56:34 raspberrypi dhcpd: Wrote 1 leases to leases file.
Feb 10 21:56:34 raspberrypi dhcpd: Server starting service.
Feb 10 21:56:35 raspberrypi ntpd[635]: Listen normally on 6 wlan0 192.168.10.1 UDP 123
Feb 10 21:56:35 raspberrypi ntpd[635]: Listen normally on 7 wlan0 fe80::e49a:83c8:afde:dccb UDP 123
Feb 10 21:56:35 raspberrypi ntpd[635]: peers refreshed
Feb 10 21:56:36 raspberrypi dhcpd: DHCPREQUEST for 192.168.10.101 from d4:f4:6f:04:f3:49 (Yasuo-iPhone6) via wlan0
Feb 10 21:56:36 raspberrypi dhcpd: DHCPACK on 192.168.10.101 to d4:f4:6f:04:f3:49 via wlan0
Feb 10 21:56:45 raspberrypi systemd[1]: Time has been changed
Feb 10 21:56:45 raspberrypi isc-dhcp-server[611]: Starting ISC DHCP server: dhcpd.
Feb 10 21:56:45 raspberrypi systemd[1]: Started LSB: DHCP server.
Feb 10 21:56:45 raspberrypi systemd[1]: Starting Multi-User System.

これで無事DHCPサーバーのインストールが完了です。毎回手動で起動するとかやってられないですよね。起動プロセスの最後にさらにもう一回isc-dhcp-serverを起動するという方法もありましたが、こちらの方法の方がスマートではないかと思います。


Facebooktwitterpinterestlinkedinmail
納得したらすぐにシェア!