dhcpcd failing since last upgrade

This forum is for discussion about general software issues.

dhcpcd failing since last upgrade

Postby dtralara » Wed Apr 15, 2020 3:12 pm

Since last upgrade, dhcpcd fails to get an address from my router

$this->bbcode_second_pass_code('', '
dhcpcd --version
dhcpcd 8.1.7
Copyright (c) 2006-2019 Roy Marples
Compiled in features: INET ARP ARPing IPv4LL INET6 DHCPv6 AUTH
')

The relevant log entries are as follows

$this->bbcode_second_pass_code('', '
systemctl status dhcpcd
● dhcpcd.service - dhcpcd on all interfaces
Loaded: loaded (/usr/lib/systemd/system/dhcpcd.service; enabled; vendor preset: disabled)
Active: active (running) since Wed 2020-04-15 16:19:23 CEST; 18min ago
Process: 258 ExecStart=/usr/bin/dhcpcd -q -b (code=exited, status=0/SUCCESS)
Main PID: 273 (dhcpcd)
Memory: 980.0K
CGroup: /system.slice/dhcpcd.service
└─273 /usr/bin/dhcpcd -q -b

Apr 15 16:27:56 alarm dhcpcd[273]: eth0: checksum failure from 192.168.183.137
Apr 15 16:29:01 alarm dhcpcd[273]: eth0: checksum failure from 192.168.183.137
Apr 15 16:30:04 alarm dhcpcd[273]: eth0: checksum failure from 192.168.183.137
Apr 15 16:31:08 alarm dhcpcd[273]: eth0: checksum failure from 192.168.183.137
Apr 15 16:32:11 alarm dhcpcd[273]: eth0: checksum failure from 192.168.183.137
Apr 15 16:33:15 alarm dhcpcd[273]: eth0: checksum failure from 192.168.183.137
Apr 15 16:34:20 alarm dhcpcd[273]: eth0: checksum failure from 192.168.183.137
Apr 15 16:35:24 alarm dhcpcd[273]: eth0: checksum failure from 192.168.183.137
Apr 15 16:36:29 alarm dhcpcd[273]: eth0: checksum failure from 192.168.183.137
Apr 15 16:37:32 alarm dhcpcd[273]: eth0: checksum failure from 192.168.183.137
')

$this->bbcode_second_pass_code('', '
sudo journalctl -b0 | grep dhcpcd
Apr 15 16:19:22 alarm systemd[1]: Starting dhcpcd on all interfaces...
Apr 15 16:19:22 alarm dhcpcd[258]: dev: loaded udev
Apr 15 16:19:23 alarm dhcpcd[258]: forked to background, child pid 273
Apr 15 16:19:23 alarm systemd[1]: Started dhcpcd on all interfaces.
Apr 15 16:19:23 alarm dhcpcd[273]: eth0: waiting for carrier
Apr 15 16:19:23 alarm dhcpcd[273]: eth0: carrier acquired
Apr 15 16:19:23 alarm dhcpcd[273]: DUID 00:01:00:01:22:3a:02:79:10:7b:ef:88:07:6b
Apr 15 16:19:23 alarm dhcpcd[273]: eth0: IAID ef:88:07:6b
Apr 15 16:19:23 alarm dhcpcd[273]: eth0: carrier lost
Apr 15 16:19:25 alarm dhcpcd[273]: eth0: carrier acquired
Apr 15 16:19:25 alarm dhcpcd[273]: eth0: IAID ef:88:07:6b
Apr 15 16:19:25 alarm dhcpcd[273]: eth0: soliciting a DHCP lease (requesting 192.168.1.109)
Apr 15 16:19:25 alarm dhcpcd[273]: eth0: checksum failure from 192.168.183.137
Apr 15 16:19:30 alarm dhcpcd[273]: eth0: checksum failure from 192.168.183.137
Apr 15 16:19:38 alarm dhcpcd[273]: eth0: checksum failure from 192.168.183.137
Apr 15 16:19:55 alarm dhcpcd[273]: eth0: checksum failure from 192.168.183.137
Apr 15 16:20:28 alarm dhcpcd[273]: eth0: checksum failure from 192.168.183.137
Apr 15 16:21:32 alarm dhcpcd[273]: eth0: checksum failure from 192.168.183.137
Apr 15 16:22:36 alarm dhcpcd[273]: eth0: checksum failure from 192.168.183.137
Apr 15 16:23:40 alarm dhcpcd[273]: eth0: checksum failure from 192.168.183.137
Apr 15 16:24:44 alarm dhcpcd[273]: eth0: checksum failure from 192.168.183.137
Apr 15 16:25:48 alarm dhcpcd[273]: eth0: checksum failure from 192.168.183.137
')

I have no idea of where this private network address (192.168.183.137) comes from...

The dhcpcd configuration file is pretty standard (I just added a 'request' option). Just in case it helps, here it is http://ix.io/2iaa

Downgrading to the previous version in the cache and restarting the service solves the connection problem for me.
$this->bbcode_second_pass_code('', '
sudo pacman -U /var/cache/pacman/pkg/dhcpcd-8.1.6-1-arm.pkg.tar.xz
sudo systemctl restart dhcpcd.service
')

$this->bbcode_second_pass_code('', '
dhcpcd --version
dhcpcd 8.1.6
Copyright (c) 2006-2019 Roy Marples
Compiled in features: INET ARP ARPing IPv4LL INET6 DHCPv6 AUTH
')

$this->bbcode_second_pass_code('', '
● dhcpcd.service - dhcpcd on all interfaces
Loaded: loaded (/usr/lib/systemd/system/dhcpcd.service; enabled; vendor preset: disabled)
Active: active (running) since Wed 2020-04-15 16:47:39 CEST; 17min ago
Process: 1230 ExecStart=/usr/bin/dhcpcd -q -b (code=exited, status=0/SUCCESS)
Main PID: 1233 (dhcpcd)
Memory: 632.0K
CGroup: /system.slice/dhcpcd.service
└─1233 /usr/bin/dhcpcd -q -b

Apr 15 16:47:39 alarm systemd[1]: Started dhcpcd on all interfaces.
Apr 15 16:47:39 alarm dhcpcd[1233]: DUID 00:01:00:01:22:3a:02:79:10:7b:ef:88:07:6b
Apr 15 16:47:39 alarm dhcpcd[1233]: eth0: IAID ef:88:07:6b
Apr 15 16:47:40 alarm dhcpcd[1233]: eth0: soliciting a DHCP lease (requesting 192.168.1.109)
Apr 15 16:47:40 alarm dhcpcd[1233]: eth0: offered 192.168.1.109 from 192.168.1.1
Apr 15 16:47:40 alarm dhcpcd[1233]: eth0: probing address 192.168.1.109/24
Apr 15 16:47:45 alarm dhcpcd[1233]: eth0: leased 192.168.1.109 for 86400 seconds
Apr 15 16:47:45 alarm dhcpcd[1233]: eth0: adding route to 192.168.1.0/24
Apr 15 16:47:45 alarm dhcpcd[1233]: eth0: adding default route via 192.168.1.1
Apr 15 16:47:45 alarm dhcpcd[1233]: if_sendnetlink: NETLINK_GET_STRICT_CHK: Protocol not available
')
dtralara
 
Posts: 18
Joined: Wed Apr 15, 2020 2:27 pm

Re: dhcpcd failing since last upgrade

Postby summers » Thu Apr 16, 2020 4:00 pm

there seem two schools of thought. Those that use systemd, and think it the way forward, and those that think systemd is the work of the devil, and like using stand alone executables. I'm in the systemd camp, as when set up well I find it more reliable. In particular systemd has its on dhcp client and server.

To do a dhcp server, in a file like /etc/systemd/network/usb0.network have something like:
$this->bbcode_second_pass_code('', '[Match]
Name=usb0

[Network]
DNS=192.168.2.1
DHCPServer=true

[Address]
Address=192.168.7.18/30

[Route]
Gateway=192.168.7.17

[DHCPServer]
EmitDNS=false
EmitNTP=false
EmitSIP=false
EmitRouter=false
')
Notice it knows the gateway, and dns server - becuase as its the dhcp server it needs to.

To do a client in a file /etc/systemd/network/eth0.network have:
$this->bbcode_second_pass_code('', '[Match]
Name=eth0

[Network]
DHCP=yes
')
So thats simple, just what interface to run on, and do everything via dhcp.

So on wifi you'll want a client. On ethernet, if plugging into a router you'll need a client, if plugging direct into another computer you'll need a server.

Then make sure the relevent parts of systemd are enabled. Its on the arch network wiki page.
summers
 
Posts: 995
Joined: Sat Sep 06, 2014 12:56 pm

Re: dhcpcd failing since last upgrade

Postby dtralara » Fri Apr 17, 2020 1:08 pm

I might switch to systemd-netword now. But I was hoping that I could try to pinpoint why this version of dhcpcd stopped working all of a sudden on my system and maybe file a bug report if necessary..

- dhcpcd 8.1.6 worked,
- dhcpcd 8.1.7 works on my x86 system,
- dhcpcd 8.1.7 fails on my armv5tel NAS with weird errors in the log...

I wish I could solve this riddle before switching to systemd-netword. Any idea on things I could check ?

One error in particular keeps bugging me
$this->bbcode_second_pass_code('', '
Apr 15 16:19:25 alarm dhcpcd[273]: eth0: checksum failure from 192.168.183.137)
')
because I don't know where this address comes from.
dtralara
 
Posts: 18
Joined: Wed Apr 15, 2020 2:27 pm

Re: dhcpcd failing since last upgrade

Postby summers » Fri Apr 17, 2020 2:46 pm

Its what it thinks the server on the far end gave out.

IIRC dhcpcd you can pass some flags to do more logging/debugging - if so it may give more details. Been some time though since I last did it this way so I could be getting in wrong (and maybe thinking of ppp logging ...)

Suggest also running dhcpcd from the command line, then you can see more of whats going on ...
summers
 
Posts: 995
Joined: Sat Sep 06, 2014 12:56 pm

Re: dhcpcd failing since last upgrade

Postby dtralara » Fri Apr 17, 2020 5:01 pm

From the command line, and with the debugging option, I get:
$this->bbcode_second_pass_code('', '
sudo dhcpcd -d
dhcpcd-8.1.7 starting
udev: starting
dev: loaded udev
eth0: executing `/usr/lib/dhcpcd/dhcpcd-run-hooks' PREINIT
eth0: executing `/usr/lib/dhcpcd/dhcpcd-run-hooks' CARRIER
DUID 00:01:00:01:22:3a:02:79:10:7b:ef:88:07:6b
eth0: IAID ef:88:07:6b
eth0: delaying IPv4 for 0.8 seconds
eth0: soliciting a DHCP lease (requesting 192.168.1.109)
eth0: sending DISCOVER (xid 0x1553df3), next in 5.0 seconds
eth0: checksum failure from 192.168.183.137
eth0: sending DISCOVER (xid 0x1553df3), next in 7.4 seconds
eth0: checksum failure from 192.168.183.137
eth0: sending DISCOVER (xid 0x1553df3), next in 16.6 seconds
eth0: checksum failure from 192.168.183.137
eth0: sending DISCOVER (xid 0x1553df3), next in 31.9 seconds
eth0: checksum failure from 192.168.183.137
timed out
forking to background
forked to background, child pid 8582
')
So, it doesn't say much more...

For reference, with the previous version (and even for the version 8.1.7 on my x86 arch computer) I get something like this:
$this->bbcode_second_pass_code('', '
dhcpcd-8.1.6 starting
udev: starting
dev: loaded udev
eth0: executing `/usr/lib/dhcpcd/dhcpcd-run-hooks' PREINIT
eth0: executing `/usr/lib/dhcpcd/dhcpcd-run-hooks' CARRIER
DUID 00:01:00:01:22:3a:02:79:10:7b:ef:88:07:6b
eth0: IAID ef:88:07:6b
eth0: delaying IPv4 for 0.8 seconds
eth0: soliciting a DHCP lease (requesting 192.168.1.109)
eth0: sending DISCOVER (xid 0x195b0c77), next in 3.7 seconds
eth0: offered 192.168.1.109 from 192.168.1.1
eth0: sending REQUEST (xid 0x195b0c77), next in 3.6 seconds
eth0: acknowledged 192.168.1.109 from 192.168.1.1
eth0: probing address 192.168.1.109/24
eth0: probing for 192.168.1.109
eth0: ARP probing 192.168.1.109 (1 of 3), next in 1.5 seconds
eth0: ARP probing 192.168.1.109 (2 of 3), next in 1.3 seconds
eth0: ARP probing 192.168.1.109 (3 of 3), next in 2.0 seconds
eth0: DAD completed for 192.168.1.109
eth0: leased 192.168.1.109 for 86400 seconds
eth0: renew in 43200 seconds, rebind in 75600 seconds
eth0: writing lease `/var/lib/dhcpcd/eth0.lease'
eth0: adding IP address 192.168.1.109/24 broadcast 192.168.1.255
eth0: adding route to 192.168.1.0/24
eth0: adding default route via 192.168.1.1
eth0: ARP announcing 192.168.1.109 (1 of 2), next in 2.0 seconds
eth0: executing `/usr/lib/dhcpcd/dhcpcd-run-hooks' BOUND
forking to background
forked to background, child pid 800
')

Should I file a bug report somewhere? Or maybe write somewhere else in this forum (package section)?
It seems to be specific to ARM.
I feel simultaneously too bored to give up and too incompetent to investigate without guidance...
dtralara
 
Posts: 18
Joined: Wed Apr 15, 2020 2:27 pm

Re: dhcpcd failing since last upgrade

Postby summers » Sat Apr 18, 2020 10:05 am

Hmmm - that looks very odd. I'd be tempted to post those two logs direct to dhcpcd. Don't know if they have a mail list or something - but obviously something going very wrong.

I guess post to the mail list here: https://roy.marples.name/projects/dhcpcd/#mailing-lists
summers
 
Posts: 995
Joined: Sat Sep 06, 2014 12:56 pm

Re: dhcpcd failing since last upgrade

Postby dtralara » Tue Apr 21, 2020 6:08 pm

Just a quick follow up.

I sent a message the dhcpcd discuss mailing list.
https://roy.marples.name/archives/dhcpc ... 02929.html

There was in fact a bug, due to the "BOOTP structure no longer being aligned correctly".

The issue has been fixed with versions 8.1.9 and 9.0.2 of dhcpcd.
dtralara
 
Posts: 18
Joined: Wed Apr 15, 2020 2:27 pm


Return to General

Who is online

Users browsing this forum: Google [Bot] and 2 guests