search

NetworkConfiguration / dhcpcd

DHCP / IPv4LL / IPv6RA / DHCPv6 client.
https://roy.marples.name/projects/dhcpcd
BSD 2-Clause "Simplified" License
348 stars 112 forks source link

Probabilistic acquisition of IP address using dhcpcd_6.11.5 failed. #310

Open cmz1256877806 opened 7 months ago

cmz1256877806 commented 7 months ago

WiFi failed to obtain IP address probabilistically as STA mode. The detailed log is as follows.

cmz1256877806 commented 7 months ago

The log of successfully obtaining the IP address is as follows： 行 12: Mar 27 15:15:34.1411.137982 app0_server[19704]: fb_util.c do_system_call(454): system call: dhcpcd wlan0 -b --noipv4ll 行 13: Mar 27 15:15:34.1538.152645 dhcpcd[18207]: dhcpcd-6.11.5 starting 行 13: Mar 27 15:15:34.1538.152645 dhcpcd[18207]: dhcpcd-6.11.5 starting 行 18: Mar 27 15:15:34.1784.177624 dhcpcd[18207]: forking to background 行 19: Mar 27 15:15:34.1799.178917 dhcpcd[18207]: forked to background, child pid 18208 行 20: Mar 27 15:15:34.1799.178965 dhcpcd[18208]: wlan0: executing /usr/libexec/dhcpcd-run-hooks' PREINIT 行 20: Mar 27 15:15:34.1799.178965 dhcpcd[18208]: wlan0: executing/usr/libexec/dhcpcd-run-hooks' PREINIT 行 21: Mar 27 15:15:34.2283.219696 dhcpcd[18208]: wlan0: executing /usr/libexec/dhcpcd-run-hooks' NOCARRIER 行 21: Mar 27 15:15:34.2283.219696 dhcpcd[18208]: wlan0: executing/usr/libexec/dhcpcd-run-hooks' NOCARRIER 行 22: Mar 27 15:15:34.2572.256955 dhcpcd[18208]: wlan0: waiting for carrier 行 23: Mar 27 15:15:34.2790.278680 app0_server[19704]: [WIFI] fibo_ial_wifi_api.cpp ial_wifi_start_dhcpcd(4624): [start dhcpcd trace !][ret= 0] 行 23: Mar 27 15:15:34.2790.278680 app0_server[19704]: [WIFI] fibo_ial_wifi_api.cpp ial_wifi_start_dhcpcd(4624): [start dhcpcd trace !][ret= 0] 行 108: Mar 27 15:15:35.0620.59683 dhcpcd[18208]: wlan0: carrier acquired 行 113: Mar 27 15:15:35.0746.74105 dhcpcd[18208]: wlan0: executing /usr/libexec/dhcpcd-run-hooks' CARRIER 行 113: Mar 27 15:15:35.0746.74105 dhcpcd[18208]: wlan0: executing/usr/libexec/dhcpcd-run-hooks' CARRIER 行 114: Mar 27 15:15:35.0938.93359 dhcpcd[18208]: error writing DUID: /etc/dhcpcd.duid: Read-only file system 行 114: Mar 27 15:15:35.0938.93359 dhcpcd[18208]: error writing DUID: /etc/dhcpcd.duid: Read-only file system 行 115: Mar 27 15:15:35.0939.93500 dhcpcd[18208]: DUID 00:03:00:01:50:c3:a2:29:57:8c 行 116: Mar 27 15:15:35.0939.93543 dhcpcd[18208]: wlan0: IAID a2:29:57:8c 行 117: Mar 27 15:15:35.0940.93700 dhcpcd[18208]: error writing secret: /etc/dhcpcd.secret: Read-only file system 行 117: Mar 27 15:15:35.0940.93700 dhcpcd[18208]: error writing secret: /etc/dhcpcd.secret: Read-only file system 行 118: Mar 27 15:15:35.0940.93749 dhcpcd[18208]: wlan0: ipv6_start: Read-only file system 行 119: Mar 27 15:15:35.0942.93791 dhcpcd[18208]: wlan0: delaying IPv4 for 1.0 seconds 行 140: Mar 27 15:15:36.1105.108524 dhcpcd[18208]: wlan0: soliciting a DHCP lease 行 141: Mar 27 15:15:36.1106.108698 dhcpcd[18208]: wlan0: sending DISCOVER (xid 0x66306e5d), next in 4.7 seconds 行 142: Mar 27 15:15:36.1222.121381 dhcpcd[18208]: wlan0: offered 192.168.225.15 from 192.168.225.1 行 143: Mar 27 15:15:36.1223.121549 dhcpcd[18208]: wlan0: sending REQUEST (xid 0x66306e5d), next in 4.4 seconds 行 144: Mar 27 15:15:36.1427.142282 dhcpcd[18208]: wlan0: acknowledged 192.168.225.15 from 192.168.225.1 行 145: Mar 27 15:15:36.1434.143019 dhcpcd[18208]: wlan0: probing address 192.168.225.15/24 行 147: Mar 27 15:15:36.1892.188507 dhcpcd[18208]: wlan0: probing for 192.168.225.15 行 148: Mar 27 15:15:36.1893.188667 dhcpcd[18208]: wlan0: ARP probing 192.168.225.15 (1 of 3), next in 1.9 seconds 行 179: Mar 27 15:15:38.1216.109188 dhcpcd[18208]: wlan0: ARP probing 192.168.225.15 (2 of 3), next in 1.9 seconds 行 199: Mar 27 15:15:40.0301.28477 dhcpcd[18208]: wlan0: ARP probing 192.168.225.15 (3 of 3), next in 2.0 seconds 行 208: Mar 27 15:15:42.0467.30301 dhcpcd[18208]: wlan0: DAD completed for 192.168.225.15 行 209: Mar 27 15:15:42.0469.30460 dhcpcd[18208]: wlan0: leased 192.168.225.15 for 4200 seconds 行 210: Mar 27 15:15:42.0470.30544 dhcpcd[18208]: wlan0: renew in 2100 seconds, rebind in 3675 seconds 行 211: Mar 27 15:15:42.0470.30612 dhcpcd[18208]: wlan0: writing lease /var/db/dhcpcd-wlan0-BY9HMBRKT8PF5D5H_5G.lease' 行 211: Mar 27 15:15:42.0470.30612 dhcpcd[18208]: wlan0: writing lease/var/db/dhcpcd-wlan0-BY9HMBRKT8PF5D5H_5G.lease' 行 212: Mar 27 15:15:42.0471.30747 dhcpcd[18208]: dhcp_bind: write_lease: Read-only file system 行 213: Mar 27 15:15:42.0471.30930 dhcpcd[18208]: wlan0: adding IP address 192.168.225.15/24 broadcast 192.168.225.255 行 214: Mar 27 15:15:42.0472.31782 dhcpcd[18208]: wlan0: adding route to 192.168.225.0/24 行 215: Mar 27 15:15:42.0473.32118 dhcpcd[18208]: wlan0: adding default route via 192.168.225.1 行 216: Mar 27 15:15:42.0473.32343 dhcpcd[18208]: wlan0: ARP announcing 192.168.225.15 (1 of 2), next in 2.0 seconds 行 221: Mar 27 15:15:42.0501.48533 dhcpcd[18208]: wlan0: executing /usr/libexec/dhcpcd-run-hooks' BOUND 行 221: Mar 27 15:15:42.0501.48533 dhcpcd[18208]: wlan0: executing/usr/libexec/dhcpcd-run-hooks' BOUND

cmz1256877806 commented 7 months ago

The log of failure to obtain IP address is as follows： 行 26087: Mar 27 15:16:21.2054.205037 app0_server[19704]: fb_util.c do_system_call(454): system call: dhcpcd wlan0 -b --noipv4ll 行 26088: Mar 27 15:16:21.2213.220217 dhcpcd[18682]: dhcpcd-6.11.5 starting 行 26088: Mar 27 15:16:21.2213.220217 dhcpcd[18682]: dhcpcd-6.11.5 starting 行 26093: Mar 27 15:16:21.2439.243696 dhcpcd[18682]: forking to background 行 26094: Mar 27 15:16:21.2451.244889 dhcpcd[18682]: forked to background, child pid 18683 行 26095: Mar 27 15:16:21.2484.244951 dhcpcd[18683]: wlan0: executing /usr/libexec/dhcpcd-run-hooks' PREINIT 行 26095: Mar 27 15:16:21.2484.244951 dhcpcd[18683]: wlan0: executing/usr/libexec/dhcpcd-run-hooks' PREINIT 行 26096: Mar 27 15:16:21.2608.260502 dhcpcd[18683]: wlan0: executing /usr/libexec/dhcpcd-run-hooks' NOCARRIER 行 26096: Mar 27 15:16:21.2608.260502 dhcpcd[18683]: wlan0: executing/usr/libexec/dhcpcd-run-hooks' NOCARRIER 行 26097: Mar 27 15:16:21.3106.310354 dhcpcd[18683]: wlan0: waiting for carrier 行 26098: Mar 27 15:16:21.3263.325993 app0_server[19704]: [WIFI] fibo_ial_wifi_api.cpp ial_wifi_start_dhcpcd(4624): [start dhcpcd trace !][ret= 0] 行 26098: Mar 27 15:16:21.3263.325993 app0_server[19704]: [WIFI] fibo_ial_wifi_api.cpp ial_wifi_start_dhcpcd(4624): [start dhcpcd trace !][ret= 0] 行 26126: Mar 27 15:16:22.1162.114372 dhcpcd[18683]: wlan0: carrier acquired 行 26131: Mar 27 15:16:22.1225.122154 dhcpcd[18683]: wlan0: executing /usr/libexec/dhcpcd-run-hooks' CARRIER 行 26131: Mar 27 15:16:22.1225.122154 dhcpcd[18683]: wlan0: executing/usr/libexec/dhcpcd-run-hooks' CARRIER 行 26132: Mar 27 15:16:22.1409.140203 dhcpcd[18683]: error writing DUID: /etc/dhcpcd.duid: Read-only file system 行 26132: Mar 27 15:16:22.1409.140203 dhcpcd[18683]: error writing DUID: /etc/dhcpcd.duid: Read-only file system 行 26133: Mar 27 15:16:22.1410.140329 dhcpcd[18683]: DUID 00:03:00:01:50:c3:a2:29:57:8c 行 26134: Mar 27 15:16:22.1410.140364 dhcpcd[18683]: wlan0: IAID a2:29:57:8c 行 26135: Mar 27 15:16:22.1411.140508 dhcpcd[18683]: error writing secret: /etc/dhcpcd.secret: Read-only file system 行 26135: Mar 27 15:16:22.1411.140508 dhcpcd[18683]: error writing secret: /etc/dhcpcd.secret: Read-only file system 行 26136: Mar 27 15:16:22.1411.140552 dhcpcd[18683]: wlan0: ipv6_start: Read-only file system 行 26137: Mar 27 15:16:22.1411.140591 dhcpcd[18683]: wlan0: delaying IPv4 for 0.5 seconds 行 26143: Mar 27 15:16:22.6403.638513 dhcpcd[18683]: wlan0: soliciting a DHCP lease 行 26144: Mar 27 15:16:22.6404.638696 dhcpcd[18683]: wlan0: sending DISCOVER (xid 0xfb262f78), next in 3.8 seconds 行 26145: Mar 27 15:16:22.6576.656873 dhcpcd[18683]: wlan0: offered 192.168.225.15 from 192.168.225.1 行 26146: Mar 27 15:16:22.6577.657032 dhcpcd[18683]: wlan0: sending REQUEST (xid 0xfb262f78), next in 4.3 seconds 行 26148: Mar 27 15:16:22.6804.679663 dhcpcd[18683]: wlan0: acknowledged 192.168.225.15 from 192.168.225.1 行 26149: Mar 27 15:16:22.6807.679830 dhcpcd[18683]: wlan0: probing address 192.168.225.15/24 行 26150: Mar 27 15:16:22.7265.719137 dhcpcd[18683]: wlan0: probing for 192.168.225.15 行 26151: Mar 27 15:16:22.7267.719295 dhcpcd[18683]: wlan0: ARP probing 192.168.225.15 (1 of 3), next in 2.0 seconds 行 26184: Mar 27 15:16:24.6955.693884 dhcpcd[18683]: wlan0: ARP probing 192.168.225.15 (2 of 3), next in 1.7 seconds 行 26189: Mar 27 15:16:26.3960.388664 dhcpcd[18683]: wlan0: ARP probing 192.168.225.15 (3 of 3), next in 2.0 seconds 行 26194: Mar 27 15:16:26.6178.617516 dhcpcd[18683]: wlan0: carrier lost 行 26198: Mar 27 15:16:26.6217.617966 dhcpcd[18683]: wlan0: executing /usr/libexec/dhcpcd-run-hooks' NOCARRIER 行 26198: Mar 27 15:16:26.6217.617966 dhcpcd[18683]: wlan0: executing/usr/libexec/dhcpcd-run-hooks' NOCARRIER 行 26206: Mar 27 15:16:26.6793.678692 dhcpcd[18683]: wlan0: executing /usr/libexec/dhcpcd-run-hooks' EXPIRE 行 26206: Mar 27 15:16:26.6793.678692 dhcpcd[18683]: wlan0: executing/usr/libexec/dhcpcd-run-hooks' EXPIRE

rsmarples commented 7 months ago

You should try a more modern dhcpcd as it's has a lot of carrier fixes (which looks like the root cause of your error) and ensure it's state directory is writeable.

cmz1256877806 commented 7 months ago

Can the above log determine that the issue lies specifically with dhcpcd-6.11.5 itself rather than being caused by some other factors? Additionally, are there any recommended versions available?

cmz1256877806 commented 7 months ago

//and ensure it's state directory is writeable. ---> Which directories need to be writable, please?

rsmarples commented 7 months ago

Can the above log determine that the issue lies specifically with dhcpcd-6.11.5 itself rather than being caused by some other factors? Additionally, are there any recommended versions available?

No, we cannot determine that. It could be that the kernel says the carrier really is down. You can determine the carrier state by using the ip a command and posting the results.

I always recommend the latest dhcpcd release which is currently 10.0.6