You are not logged in.

#1 2020-04-19 16:58:25

Zod
Member
From: Hoosiertucky
Registered: 2019-03-10
Posts: 630

(Solved) DHCPCD 9.0.1-2 upgrade breaks IP configuration

****See end of this OP**********


Downgrade to 8.1.7-1 fixes it.

Full journalctl -b -1 output...http://ix.io/2iHX

[Edit] I use dhcpcd with IWD because I find the builtin unreliable.

When I look at status when it's broke...

Apr 19 12:04:11 carlos dhcpcd[866]: ps_dostop: Connection refused

journalctl -b -1 | grep dhcpcd

Apr 19 12:04:10 carlos dhcpcd[868]: ps_start: Address family not supported by protocol
Apr 19 12:04:10 carlos dhcpcd[866]: dev: loaded udev
Apr 19 12:04:10 carlos systemd[1]: Started dhcpcd on all interfaces.
Apr 19 12:04:10 carlos kernel: audit: type=1130 audit(1587312250.762:24): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=dhcpcd comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Apr 19 12:04:10 carlos audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=dhcpcd comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Apr 19 12:04:11 carlos dhcpcd[866]: enp0s25: waiting for carrier
Apr 19 12:04:11 carlos dhcpcd[866]: wlan0: waiting for carrier
Apr 19 12:04:11 carlos dhcpcd[866]: ps_dostop: Connection refused
Apr 19 12:04:11 carlos dhcpcd[866]: dhcpcd exited
Apr 19 12:04:11 carlos dhcpcd[921]: dhcpcd not running
Apr 19 12:04:11 carlos systemd[1]: dhcpcd.service: Control process exited, code=exited, status=1/FAILURE
Apr 19 12:04:11 carlos dhcpcd[921]: dhcpcd not running
Apr 19 12:04:11 carlos systemd[1]: dhcpcd.service: Failed with result 'exit-code'.
Apr 19 12:04:11 carlos audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=dhcpcd comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=failed'

journalctl -b -1

Apr 19 12:04:10 carlos systemd[1]: Started zfs-scrub@big_disk.timer.                                                                                                                                          
Apr 19 12:04:10 carlos systemd[1]: Reached target Timers.                                                                                                                                                     
Apr 19 12:04:10 carlos systemd[1]: Listening on D-Bus System Message Bus Socket.                                                                                                                              
Apr 19 12:04:10 carlos systemd[1]: Listening on Libvirt local socket.                                                                                                                                         
Apr 19 12:04:10 carlos systemd[1]: Listening on Libvirt admin socket.                                                                                                                                         
Apr 19 12:04:10 carlos systemd[1]: Listening on Libvirt local read-only socket.                                                                                                                               
Apr 19 12:04:10 carlos systemd[1]: Listening on Virtual machine lock manager socket.                                                                                                                          
Apr 19 12:04:10 carlos systemd[1]: Listening on Virtual machine log manager socket.                                                                                                                           
Apr 19 12:04:10 carlos systemd[1]: Reached target Sockets.                                                                                                                                                    
Apr 19 12:04:10 carlos systemd[1]: Reached target Basic System.                                                                                                                                               
Apr 19 12:04:10 carlos systemd[1]: Started D-Bus System Message Bus.                                                                                                                                          
Apr 19 12:04:10 carlos audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 ms>                                                                                                                 
Apr 19 12:04:10 carlos systemd[1]: Starting dhcpcd on all interfaces...                                                                                                                                       
Apr 19 12:04:10 carlos systemd[1]: Starting Wireless service...                                                                                                                                               
Apr 19 12:04:10 carlos systemd[1]: Starting dhcpcd on all interfaces...
Apr 19 12:04:10 carlos systemd[1]: Starting Wireless service...
Apr 19 12:04:10 carlos audit: AUDIT1334 prog-id=7 op=LOAD
Apr 19 12:04:10 carlos audit: AUDIT1334 prog-id=8 op=LOAD
Apr 19 12:04:10 carlos systemd[1]: Starting Login Service...
Apr 19 12:04:10 carlos kernel: audit: type=1334 audit(1587312250.452:18): prog-id=7 op=LOAD
Apr 19 12:04:10 carlos audit: AUDIT1334 prog-id=9 op=LOAD
Apr 19 12:04:10 carlos audit: AUDIT1334 prog-id=10 op=LOAD
Apr 19 12:04:10 carlos systemd[1]: Starting Virtual Machine and Container Registration Service...
Apr 19 12:04:10 carlos dhcpcd[768]: dhcpcd-9.0.1 starting
Apr 19 12:04:10 carlos kernel: NET: Registered protocol family 38
Apr 19 12:04:10 carlos dhcpcd[868]: ps_inet_startcb: ipv6nd_open: Address family not supported by protocol
Apr 19 12:04:10 carlos dhcpcd[868]: ps_start: Address family not supported by protocol
Apr 19 12:04:10 carlos dhcpcd[868]: ps_inet_startcb: ipv6nd_open: Address family not supported by protocol
Apr 19 12:04:10 carlos dhcpcd[868]: ps_start: Address family not supported by protocol
Apr 19 12:04:10 carlos dhcpcd[866]: dev: loaded udev
Apr 19 12:04:10 carlos systemd[1]: Started Virtual Machine and Container Registration Service.
Apr 19 12:04:10 carlos iwd[769]: Wireless daemon version 1.7
Apr 19 12:04:10 carlos iwd[769]: Loaded configuration from /etc/iwd/main.conf
Apr 19 12:04:10 carlos kernel: 8021q: 802.1Q VLAN Support v1.8
Apr 19 12:04:10 carlos audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=systemd-machined comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Apr 19 12:04:10 carlos systemd[1]: Started Wireless service.
Apr 19 12:04:10 carlos iwd[769]: netconfig: Network configuration is disabled.
Apr 19 12:04:10 carlos audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=iwd comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Apr 19 12:04:10 carlos iwd[769]: rfkill id 1 can't be matched to a wiphy
Apr 19 12:04:10 carlos iwd[769]: Wiphy: 0, Name: phy0
Apr 19 12:04:10 carlos iwd[769]:         Permanent Address: 24:77:03:4f:ff:64
Apr 19 12:04:10 carlos iwd[769]:         Bands: 2.4 GHz 5 GHz
Apr 19 12:04:10 carlos iwd[769]:         Ciphers: CCMP TKIP
Apr 19 12:04:10 carlos iwd[769]:         Supported iftypes: ad-hoc station
Apr 19 12:04:10 carlos systemd[1]: Started dhcpcd on all interfaces.
Apr 19 12:04:10 carlos systemd[1]: Reached target Network.
Apr 19 12:04:10 carlos kernel: kauditd_printk_skb: 3 callbacks suppressed
Apr 19 12:04:10 carlos kernel: audit: type=1130 audit(1587312250.758:22): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=systemd-machined comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr>
Apr 19 12:04:10 carlos kernel: audit: type=1130 audit(1587312250.762:23): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=iwd comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=?>
Apr 19 12:04:10 carlos kernel: audit: type=1130 audit(1587312250.762:24): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=dhcpcd comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? termina>
Apr 19 12:04:10 carlos audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=dhcpcd comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Apr 19 12:04:10 carlos systemd[1]: Starting Network Time Service...
Apr 19 12:04:10 carlos systemd[1]: Starting Permit User Sessions...
Apr 19 12:04:10 carlos systemd-udevd[335]: Using default interface naming scheme 'v245'.
Apr 19 12:04:10 carlos kernel: iwlwifi 0000:25:00.0: Radio type=0x0-0x3-0x1
Apr 19 12:04:10 carlos systemd[1]: Finished Permit User Sessions.
Apr 19 12:04:10 carlos audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=systemd-user-sessions comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=succ>
Apr 19 12:04:10 carlos kernel: audit: type=1130 audit(1587312250.825:25): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=systemd-user-sessions comm="systemd" exe="/usr/lib/systemd/systemd" hostname=?>
Apr 19 12:04:10 carlos systemd[1]: Started LXDE Display Manager.
Apr 19 12:04:10 carlos audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=lxdm comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Apr 19 12:04:10 carlos kernel: audit: type=1130 audit(1587312250.832:26): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=lxdm comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=>
Apr 19 12:04:10 carlos systemd-logind[770]: New seat seat0.
Apr 19 12:04:10 carlos systemd-logind[770]: Watching system buttons on /dev/input/event2 (Power Button)
Apr 19 12:04:11 carlos systemd-logind[770]: Watching system buttons on /dev/input/event1 (Lid Switch)
Apr 19 12:04:11 carlos systemd-logind[770]: Watching system buttons on /dev/input/event0 (Sleep Button)
Apr 19 12:04:11 carlos kernel: iwlwifi 0000:25:00.0: Radio type=0x0-0x3-0x1
Apr 19 12:04:11 carlos ntpd[897]: ntpd 4.2.8p14@1.3728-o Wed Mar 18 13:44:46 UTC 2020 (1): Starting
Apr 19 12:04:11 carlos ntpd[897]: Command line: /usr/bin/ntpd -g -u ntp:ntp
Apr 19 12:04:11 carlos ntpd[897]: ----------------------------------------------------
Apr 19 12:04:11 carlos ntpd[897]: ntp-4 is maintained by Network Time Foundation,
Apr 19 12:04:11 carlos ntpd[897]: Inc. (NTF), a non-profit 501(c)(3) public-benefit
Apr 19 12:04:11 carlos ntpd[897]: corporation.  Support and training for ntp-4 are
Apr 19 12:04:11 carlos ntpd[897]: available at https://www.nwtime.org/support
Apr 19 12:04:11 carlos ntpd[897]: ----------------------------------------------------
Apr 19 12:04:11 carlos dhcpcd[866]: enp0s25: waiting for carrier
Apr 19 12:04:11 carlos dhcpcd[866]: wlan0: waiting for carrier
Apr 19 12:04:11 carlos dhcpcd[866]: ps_dostop: Connection refused
Apr 19 12:04:11 carlos dhcpcd[866]: dhcpcd exited
Apr 19 12:04:11 carlos ntpd[918]: proto: precision = 0.088 usec (-23)
Apr 19 12:04:11 carlos ntpd[918]: basedate set to 2020-03-06
Apr 19 12:04:11 carlos ntpd[918]: gps base set to 2020-03-08 (week 2096)
Apr 19 12:04:11 carlos systemd-udevd[335]: ethtool: autonegotiation is unset or enabled, the speed and duplex are not writable.
Apr 19 12:04:11 carlos dhcpcd[921]: dhcpcd not running
Apr 19 12:04:11 carlos systemd[1]: dhcpcd.service: Control process exited, code=exited, status=1/FAILURE
Apr 19 12:04:11 carlos dhcpcd[921]: dhcpcd not running
Apr 19 12:04:11 carlos systemd[1]: dhcpcd.service: Failed with result 'exit-code'.
Apr 19 12:04:11 carlos audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=dhcpcd comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=failed'
Apr 19 12:04:11 carlos kernel: audit: type=1131 audit(1587312251.395:27): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=dhcpcd comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? termina>
Apr 19 12:04:11 carlos ntpd[918]: Listen and drop on 0 v4wildcard 0.0.0.0:123
Apr 19 12:04:11 carlos systemd-logind[770]: Watching system buttons on /dev/input/event4 (AT Translated Set 2 keyboard)
Apr 19 12:04:11 carlos ntpd[918]: Listen normally on 1 lo 127.0.0.1:123
Apr 19 12:04:11 carlos systemd-logind[770]: Watching system buttons on /dev/input/event16 (HP WMI hotkeys)
Apr 19 12:04:11 carlos ntpd[918]: Listening on routing socket on fd #18 for interface updates
Apr 19 12:04:11 carlos ntpd[918]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized
Apr 19 12:04:11 carlos ntpd[918]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized
Apr 19 12:04:11 carlos systemd[1]: Started Login Service.
Apr 19 12:04:11 carlos audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=systemd-logind comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Apr 19 12:04:11 carlos kernel: audit: type=1130 audit(1587312251.432:28): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=systemd-logind comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=?>
Apr 19 12:04:11 carlos systemd[1]: Started Virtualization daemon.
Apr 19 12:04:11 carlos audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=libvirtd comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Apr 19 12:04:11 carlos kernel: audit: type=1130 audit(1587312251.482:29): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=libvirtd comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? termi>
Apr 19 12:04:11 carlos systemd[1]: Started Network Time Service.
Apr 19 12:04:11 carlos audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=ntpd comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
Apr 19 12:04:11 carlos kernel: audit: type=1130 audit(1587312251.502:30): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=ntpd comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=>
Apr 19 12:04:11 carlos systemd[1]: Reached target Multi-User System.
Apr 19 12:04:11 carlos systemd[1]: Reached target Graphical Interface.
Apr 19 12:04:11 carlos systemd[1]: Startup finished in 6.289s (kernel) + 12.844s (userspace) = 19.134s.
Apr 19 12:04:11 carlos kernel: wlan0: authenticate with 48:77:46:41:5d:ad
Apr 19 12:04:11 carlos kernel: wlan0: send auth to 48:77:46:41:5d:ad (try 1/3)
Apr 19 12:04:11 carlos kernel: wlan0: authenticated
Apr 19 12:04:11 carlos kernel: wlan0: associate with 48:77:46:41:5d:ad (try 1/3)
Apr 19 12:04:11 carlos kernel: wlan0: RX AssocResp from 48:77:46:41:5d:ad (capab=0x511 status=0 aid=6)
Apr 19 12:04:11 carlos kernel: wlan0: associated
Apr 19 12:04:11 carlos kernel: wlan0: Limiting TX power to 30 (30 - 0) dBm as advertised by 48:77:46:41:5d:ad
Apr 19 12:04:14 carlos systemd-udevd[335]: ethtool: autonegotiation is unset or enabled, the speed and duplex are not writable.
Apr 19 12:04:14 carlos kernel: bridge: filtering via arp/ip/ip6tables is no longer available by default. Update your scripts to load br_netfilter if you need this.
Apr 19 12:04:14 carlos kernel: tun: Universal TUN/TAP device driver, 1.6
Apr 19 12:04:14 carlos audit: ANOM_PROMISCUOUS dev=virbr0-nic prom=256 old_prom=0 auid=4294967295 uid=0 gid=0 ses=4294967295
Apr 19 12:04:14 carlos kernel: virbr0: port 1(virbr0-nic) entered blocking state
Apr 19 12:04:14 carlos kernel: virbr0: port 1(virbr0-nic) entered disabled state
Apr 19 12:04:14 carlos kernel: device virbr0-nic entered promiscuous mode
Apr 19 12:04:14 carlos kernel: audit: type=1700 audit(1587312254.625:31): dev=virbr0-nic prom=256 old_prom=0 auid=4294967295 uid=0 gid=0 ses=4294967295
Apr 19 12:04:14 carlos systemd-udevd[332]: Using default interface naming scheme 'v245'.
Apr 19 12:04:14 carlos systemd-udevd[332]: ethtool: autonegotiation is unset or enabled, the speed and duplex are not writable.
Apr 19 12:04:14 carlos audit: NETFILTER_CFG table=filter family=2 entries=0

pacman.log..

[2020-04-19T11:01:17-0400] [PACMAN] Running 'pacman -Syu'
[2020-04-19T11:01:17-0400] [PACMAN] synchronizing package lists
[2020-04-19T11:01:18-0400] [PACMAN] starting full system upgrade
[2020-04-19T11:01:54-0400] [ALPM] transaction started
[2020-04-19T11:01:54-0400] [ALPM] upgraded bind-tools (9.16.1-2 -> 9.16.2-1)
[2020-04-19T11:01:54-0400] [ALPM] upgraded systemd-libs (245.4-2 -> 245.5-1)
[2020-04-19T11:01:55-0400] [ALPM] upgraded systemd (245.4-2 -> 245.5-1)
[2020-04-19T11:01:56-0400] [ALPM] upgraded dhcpcd (8.1.7-1 -> 9.0.1-2)
[2020-04-19T11:01:56-0400] [ALPM] upgraded harfbuzz (2.6.4-2 -> 2.6.5-1)
[2020-04-19T11:01:57-0400] [ALPM] upgraded fluxbox (1.3.7-5 -> 1.3.7-6)
[2020-04-19T11:01:57-0400] [ALPM] upgraded iwd (1.6-1 -> 1.7-1)
[2020-04-19T11:01:57-0400] [ALPM] upgraded llvm-libs (9.0.1-3 -> 10.0.0-1)
[2020-04-19T11:01:57-0400] [ALPM] upgraded mesa (20.0.4-1 -> 20.0.4-2)
[2020-04-19T11:02:09-0400] [ALPM] upgraded python-urllib3 (1.25.8-2 -> 1.25.9-1)
[2020-04-19T11:02:09-0400] [ALPM] upgraded systemd-sysvcompat (245.4-2 -> 245.5-1)
[2020-04-19T11:02:09-0400] [ALPM] upgraded xfsprogs (5.5.0-1 -> 5.6.0-1)
[2020-04-19T11:02:09-0400] [ALPM] transaction completed
[

edit:
resolv.conf while it's broke..

# Generated by dhcpcd from wlan0.dhcp
# /etc/resolv.conf.head can replace this line

resolv.conf after downgrade..

# Generated by dhcpcd from wlan0.dhcp
# /etc/resolv.conf.head can replace this line
domain Home
nameserver 192.168.1.1
# /etc/resolv.conf.tail can replace this line

There is this but I don't think it's the same thing..
https://bugs.archlinux.org/task/66231?s … &closedto=

I had an IP address, just no name resolution.

Edit: Added bug report..
https://bugs.archlinux.org/task/66313

Reported upstream.

Edit: Edited post subject
Installed 9.0.1-3 and rebooted- no IP address

downgraded to 9.0.1-2 and rebooted-no IP address

downgraded to 8.1.7-1 and rebooted- Fixed.


EDIT: 9.0.1-4 (testing) Fixes it.

Last edited by Zod (2020-04-20 16:33:41)

Offline

#2 2020-04-20 11:34:13

quimkaos
Member
Registered: 2014-09-27
Posts: 56

Re: (Solved) DHCPCD 9.0.1-2 upgrade breaks IP configuration

I can confirm.
I'm using NetworkManager, but i remember that at install time i first installed dhcpcd, so NetworkManager is using the dhcpcd client and not it's internal dhcp client.
Downgrading to 8.1.7 solved the problem.
Probably i can uninstall dhcpcd(?).

Offline

#3 2020-04-20 11:37:28

arojas
Developer
From: Spain
Registered: 2011-10-09
Posts: 2,099

Re: (Solved) DHCPCD 9.0.1-2 upgrade breaks IP configuration

quimkaos wrote:

I can confirm.
I'm using NetworkManager, but i remember that at install time i first installed dhcpcd, so NetworkManager is using the dhcpcd client and not it's internal dhcp client.
Downgrading to 8.1.7 solved the problem.
Probably i can uninstall dhcpcd(?).

NetworkManager doesn't support dhcpcd 9, this is a different issue.

Offline

#4 2020-04-20 12:13:17

quimkaos
Member
Registered: 2014-09-27
Posts: 56

Re: (Solved) DHCPCD 9.0.1-2 upgrade breaks IP configuration

@arojas Thank you for the info

and uninstalling dhcpcd solved my issue

Offline

Board footer

Powered by FluxBB