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.1Feb 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.1Feb 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 123Feb 10 22:08:31 raspberrypi ntpd[634]: Listen normally on 3 eth0 192.168.2.10 UDP 123Feb 10 22:08:31 raspberrypi ntpd[634]: Listen normally on 4 lo ::1 UDP 123Feb 10 22:08:31 raspberrypi ntpd[634]: Listen normally on 5 eth0 fe80::5451:ee7b:51eb:6a2c UDP 123Feb 10 22:08:31 raspberrypi ntpd[634]: peers refreshedFeb 10 22:08:31 raspberrypi ntpd[634]: Listening on routing socket on fd #22 for interface updatesFeb 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 whatFeb 10 22:08:31 raspberrypi dhcpd:    you want, please write a subnet declarationFeb 10 22:08:31 raspberrypi dhcpd:    in your dhcpd.conf file for the network segmentFeb 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 ratherFeb 10 22:08:31 raspberrypi dhcpd: than a configuration issue please read the section on submittingFeb 10 22:08:31 raspberrypi dhcpd: bugs on either our web page at www.isc.org or in the README fileFeb 10 22:08:31 raspberrypi dhcpd: before submitting a bug.  These pages explain the properFeb 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 readyFeb 10 22:08:31 raspberrypi dhcpcd[604]: wlan0: carrier acquiredFeb 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:91Feb 10 22:08:31 raspberrypi dhcpcd[604]: wlan0: using static address 192.168.10.1/24Feb 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/24Feb 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 routerFeb 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:91Feb 10 21:56:30 raspberrypi dhcpcd[605]: wlan0: soliciting an IPv6 routerFeb 10 21:56:30 raspberrypi dhcpcd[605]: wlan0: using static address 192.168.10.1/24Feb 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/24Feb 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 availableFeb 10 21:56:32 raspberrypi hostapd: wlan0: STA d4:f4:6f:04:f3:49 IEEE 802.11: associatedFeb 10 21:56:32 raspberrypi hostapd: wlan0: STA d4:f4:6f:04:f3:49 RADIUS: starting accounting session 56BB337E-00000000Feb 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.1Feb 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 123Feb 10 21:56:35 raspberrypi ntpd[635]: Listen normally on 7 wlan0 fe80::e49a:83c8:afde:dccb UDP 123Feb 10 21:56:35 raspberrypi ntpd[635]: peers refreshedFeb 10 21:56:36 raspberrypi dhcpd: DHCPREQUEST for 192.168.10.101 from d4:f4:6f:04:f3:49 (Yasuo-iPhone6) via wlan0Feb 10 21:56:36 raspberrypi dhcpd: DHCPACK on 192.168.10.101 to d4:f4:6f:04:f3:49 via wlan0Feb 10 21:56:45 raspberrypi systemd[1]: Time has been changedFeb 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を起動するという方法もありましたが、こちらの方法の方がスマートではないかと思います。”””

コメントをどうぞ

メールアドレスが公開されることはありません。 が付いている欄は必須項目です