dhcpcd-discuss

How does dhcpcd work and play with others question - just where is the problem?

JED

Sat Mar 31 15:15:53 2018

I'm trying to use a raspberry pi as a wifi hotspot that uses a cell modem for traffic for a cabin in the North Woods(tm). I got it all working fine then made a mistake - I updated the software so I could move to the latest greatest Pi 3 B+ and that broke something. I don't want to be forever forbidden updates and I'd like to use new Pi so I'm trying to figure out the cause.

Before, when I issued the correct mmcli commands to enable and connect to the cell network, dhcpcd noticed the connection and, I think, moved the IP address into networking. AFTER the standard "apt-get upgrade"
it quit doing that.

Before, it just worked if I waited or kicked it. Now, even if I kick it with "dhcpcd -n wwan0" it remains "waiting for carrier". Also, before, when the cell modem wasn't connected, dhcpcd would say "carrier acquired" and assign a funny address to wwan0 and now it doesn't.

My question is "Where do I look for the problem?" dhcpcd didn't change but somehow its behavior changed, so who is it talking to?

Before, with no cell connection:
Mar 14 11:34:50 rasp9Cabin dhcpcd[314]: wwan0: waiting for carrier
Mar 14 11:34:50 rasp9Cabin dhcpcd[314]: wwan0: carrier acquired
Mar 14 11:34:50 rasp9Cabin dhcpcd[314]: wwan0: IAID 74:60:7b:fc
Mar 14 11:34:50 rasp9Cabin dhcpcd[314]: wwan0: adding address fe80::b06b:eeda:f6a9:d9d3
Mar 14 11:34:50 rasp9Cabin dhcpcd[314]: wwan0: soliciting an IPv6 router
Mar 14 11:34:50 rasp9Cabin dhcpcd[314]: wwan0: soliciting a DHCP lease
Mar 14 11:34:55 rasp9Cabin dhcpcd[314]: wwan0: probing for an IPv4LL address
Mar 14 11:35:00 rasp9Cabin dhcpcd[314]: wwan0: using IPv4LL address 169.254.229.120
Mar 14 11:35:00 rasp9Cabin dhcpcd[314]: wwan0: adding route to 169.254.0.0/16
Mar 14 11:35:03 rasp9Cabin dhcpcd[314]: wwan0: no IPv6 Routers available
If I'd pull out the cell modem, it would figure that out, too, and remove the address and route. Only THEN would I see the carrier lost message.

Now, with no cell connection:
Mar 30 12:04:10 rasp9Cabin dhcpcd-run-hooks[678]: wwan0: starting wpa_supplicant
Mar 30 12:04:11 rasp9Cabin dhcpcd[376]: wwan0: waiting for carrier
Mar 30 12:04:11 rasp9Cabin dhcpcd[376]: wwan0: carrier acquired
Mar 30 12:04:11 rasp9Cabin dhcpcd[376]: wwan0: IAID 9b:eb:4f:f3
Mar 30 12:04:11 rasp9Cabin dhcpcd[376]: wwan0: adding address fe80::af46:cc7d:140c:53a5
Mar 30 12:04:11 rasp9Cabin dhcpcd[376]: wwan0: carrier lost
Mar 30 12:04:11 rasp9Cabin dhcpcd[376]: wwan0: deleting address fe80::af46:cc7d:140c:53a5

Is the wpa_supplicant line a hint?

Of course, ifconfig before showed the 169.x address and now it doesn't.

Can you please point me in the right direction? I THINK I checked the version of dhcpcd both before and after and it didn't change but I'm not sure anymore. I've been working on this for quite a while.

Now, when I use commands to modem manager through mmcli to bring up the link, I get this:
Mar 30 10:30:02 rasp9Cabin ModemManager[342]: <info>  Modem /org/freedesktop/ModemManager1/Modem/0: state changed (disabled -> enabling)
Mar 30 10:30:02 rasp9Cabin ModemManager[342]: <warn>  (ttyUSB1): port attributes not fully set
Mar 30 10:30:02 rasp9Cabin ModemManager[342]: <info>  Modem /org/freedesktop/ModemManager1/Modem/0: 3GPP Registration state changed (unknown -> registering)
Mar 30 10:30:02 rasp9Cabin ModemManager[342]: <info>  Modem /org/freedesktop/ModemManager1/Modem/0: 3GPP Registration state changed (registering -> home)
Mar 30 10:30:02 rasp9Cabin ModemManager[342]: <info>  Modem /org/freedesktop/ModemManager1/Modem/0: state changed (enabling -> registered)
Mar 30 10:30:05 rasp9Cabin ModemManager[342]: <info>  Modem /org/freedesktop/ModemManager1/Modem/0: state changed (registered -> connecting)
Mar 30 10:30:05 rasp9Cabin ModemManager[342]: [/dev/cdc-wdm0] Allocating new client ID...
Mar 30 10:30:05 rasp9Cabin ModemManager[342]: [/dev/cdc-wdm0] Registered 'wds' (version 1.12) client with ID '1'
Mar 30 10:30:05 rasp9Cabin ModemManager[342]: <info>  QMI IPv4 Settings:
Mar 30 10:30:05 rasp9Cabin ModemManager[342]: <info>      Address: 10.219.135.158/30
Mar 30 10:30:05 rasp9Cabin ModemManager[342]: <info>      Gateway: 10.219.135.157
Mar 30 10:30:05 rasp9Cabin ModemManager[342]: <info>      DNS #1: 172.20.192.179
Mar 30 10:30:05 rasp9Cabin ModemManager[342]: <info>      DNS #2: 172.20.192.180
Mar 30 10:30:05 rasp9Cabin ModemManager[342]: <info>         MTU: 1500
Mar 30 10:30:05 rasp9Cabin ModemManager[342]: <info>  Modem /org/freedesktop/ModemManager1/Modem/0: state changed (connecting -> connected)
Here I wait and wait. This USED to work. Finally I act:
Mar 30 10:30:56 rasp9Cabin dhcpcd[862]: sending commands to master dhcpcd process
Mar 30 10:30:56 rasp9Cabin dhcpcd[377]: control command: dhcpcd -n wwan0
Mar 30 10:30:56 rasp9Cabin dhcpcd-run-hooks[870]: wwan0: reconfiguring wpa_supplicant
Mar 30 10:30:56 rasp9Cabin dhcpcd[377]: wwan0: waiting for carrier

And it never says anything else. Before, it saw address and used it WITHOUT me kicking dhcpcd with the -n wwan0 command. Does this mean the change is in wpa_supplicant's response?

Again, where to I look for the change? There isn't much info online about using dhcpcd to do this. Most setups turn dhcpcd off for the interface and use the old networking setups.

Versions didn't change: dhcpcd 6.11.5 wpa_supplicant v2.4

Before update, when connection made and everything works: (restored copy before updates to recreate)
Mar 30 13:02:47 rasp9Cabin ModemManager[332]: [/dev/cdc-wdm0] Registered 'wds' (version 1.12) client with ID '1'
Mar 30 13:02:47 rasp9Cabin ModemManager[332]: <info>  QMI IPv4 Settings:
Mar 30 13:02:47 rasp9Cabin ModemManager[332]: <info>      Address: 10.239.248.73/30
Mar 30 13:02:47 rasp9Cabin ModemManager[332]: <info>      Gateway: 10.239.248.74
Mar 30 13:02:47 rasp9Cabin ModemManager[332]: <info>      DNS #1: 172.20.192.179
Mar 30 13:02:47 rasp9Cabin ModemManager[332]: <info>      DNS #2: 172.20.192.180
Mar 30 13:02:47 rasp9Cabin ModemManager[332]: <info>         MTU: 1500
Mar 30 13:02:47 rasp9Cabin ModemManager[332]: <info>  Modem /org/freedesktop/ModemManager1/Modem/0: state changed (connecting -> connected)
Mar 30 13:03:38 rasp9Cabin dhcpcd[374]: wwan0: offered 10.239.248.73 from 10.239.248.74
Mar 30 13:03:38 rasp9Cabin dhcpcd[374]: wwan0: probing address 10.239.248.73/30
Mar 30 13:03:42 rasp9Cabin dhcpcd[374]: wwan0: leased 10.239.248.73 for 7200 seconds
Mar 30 13:03:42 rasp9Cabin dhcpcd[374]: wwan0: adding route to 10.239.248.72/30
Mar 30 13:03:42 rasp9Cabin dhcpcd[374]: wwan0: changing default route via 10.239.248.74
Mar 30 13:03:42 rasp9Cabin avahi-daemon[351]: Registering new address record for 10.239.248.73 on wwan0.IPv4.
Mar 30 13:03:42 rasp9Cabin dnsmasq[495]: reading /run/dnsmasq/resolv.conf
Mar 30 13:03:42 rasp9Cabin dnsmasq[495]: using nameserver 172.20.192.179#53
Mar 30 13:03:42 rasp9Cabin dnsmasq[495]: using nameserver 172.20.192.180#53
Mar 30 13:03:42 rasp9Cabin avahi-daemon[351]: Withdrawing address record for 169.254.36.205 on wwan0.
Mar 30 13:03:42 rasp9Cabin avahi-daemon[351]: Leaving mDNS multicast group on interface wwan0.IPv4 with address 169.254.36.205.
Mar 30 13:03:42 rasp9Cabin avahi-daemon[351]: Joining mDNS multicast group on interface wwan0.IPv4 with address 10.239.248.73.
Mar 30 13:03:42 rasp9Cabin dhcpcd[374]: wwan0: deleting route to 169.254.0.0/16




Archive administrator: postmaster@marples.name