isc-dhcp-client sends DHCPDISCOVER *before* wpa_supplicant authenticates/associates/connects.
Hi all. I'm running a freshly-installed minimal stretch box. It
connects wirelessly to my lan and it's a dhcp client, so
/etc/network/interfaces contains:
iface myInterface inet dhcp
wpa-ssid mySsid
wpa-psk myPsk
It works (almost) perfectly! For ages I've been baffled by why my dhcp
server never responds to clients' first DHCPDISCOVER messages, but a
quick look at the log shows why:
22:58:04 wpa_supplicant[2819]: Successfully initialized wpa_supplicant
22:58:04 kernel: iwlwifi 0000:24:00.0: L1 Enabled - LTR Disabled
22:58:04 kernel: iwlwifi 0000:24:00.0: L1 Enabled - LTR Disabled
22:58:04 kernel: iwlwifi 0000:24:00.0: Radio type=0x0-0x3-0x1
22:58:04 kernel: iwlwifi 0000:24:00.0: L1 Enabled - LTR Disabled
22:58:04 kernel: iwlwifi 0000:24:00.0: L1 Enabled - LTR Disabled
22:58:04 kernel: iwlwifi 0000:24:00.0: Radio type=0x0-0x3-0x1
22:58:04 dhclient[2830]: Internet Systems Consortium DHCP Client 4.3.5
22:58:04 dhclient[2830]: Copyright 2004-2016 Internet Systems Consortium.
22:58:04 dhclient[2830]: All rights reserved.
22:58:04 dhclient[2830]: For info, please visit
https://www.isc.org/software/dhcp/
22:58:04 dhclient[2830]:
22:58:05 dhclient[2830]: Listening on LPF/wlo1/<clientmac>
22:58:05 dhclient[2830]: Sending on LPF/wlo1/<clientmac>
22:58:05 dhclient[2830]: Sending on Socket/fallback
22:58:05 dhclient[2830]: DHCPDISCOVER on wlo1 to 255.255.255.255 port
67 interval 4
22:58:08 wpa_supplicant[2820]: wlo1: SME: Trying to authenticate with
<bssid> (SSID='<ssid>' freq=5180 MHz)
22:58:08 kernel: wlo1: authenticate with <bssid>
22:58:08 kernel: wlo1: send auth to <bssid> (try 1/3)
22:58:08 wpa_supplicant[2820]: wlo1: Trying to associate with <bssid>
(SSID='<ssid>' freq=5180 MHz)
22:58:08 kernel: wlo1: authenticated
22:58:08 kernel: wlo1: associate with <bssid> (try 1/3)
22:58:08 kernel: wlo1: RX AssocResp from <bssid> (capab=0x11 status=0 aid=1)
22:58:08 wpa_supplicant[2820]: wlo1: Associated with <bssid>
22:58:08 kernel: wlo1: associated
22:58:08 wpa_supplicant[2820]: wlo1: WPA: Key negotiation completed
with <bssid> [PTK=CCMP GTK=CCMP]
22:58:08 kernel: IPv6: ADDRCONF(NETDEV_CHANGE): wlo1: link becomes ready
22:58:08 wpa_supplicant[2820]: wlo1: CTRL-EVENT-CONNECTED - Connection
to <bssid> completed [id=0 id_str=]
22:58:09 dhclient[2830]: DHCPDISCOVER on wlo1 to 255.255.255.255 port
67 interval 7
22:58:09 dhclient[2830]: DHCPREQUEST of 192.168.0.15 on wlo1 to
255.255.255.255 port 67
22:58:09 dhclient[2830]: DHCPOFFER of 192.168.0.15 from 192.168.0.1
22:58:09 dhclient[2830]: DHCPACK of 192.168.0.15 from 192.168.0.1
As you can see, *after* wpa_supplicant has successfully authenticated,
associated and connected (all of which it does perfectly on the first
attempt), the following DHCPDISCOVER is "processed" correctly. Which
then begs the question: why send a DHCPDISCOVER at 22:58:05 given that
it's guaranteed to fail?
Questions:
1) Is this a bug?
2) If it's a bug, in which package?
3) Are there any quick-and-dirty workarounds until it's fixed? Is
there a hack to serialize dhclient so that it waits until after the
CTRL-EVENT-CONNECTED (perhaps based on systemd)?
With kind regards...
Reply to: