search

neilbrown / gnubee-tools

Tools for building gnubee firmware - and maybe more.
Other
31 stars 14 forks source link

Network service fails to start #15

Closed jjakob closed 4 years ago

jjakob commented 4 years ago

On gbpc2-5.4, the networking.service fails to start after a fresh installation via config from the initramfs. The first boot after installation didn't even get an address on the connected interface (sorry, I don't have the logs). It can't bring up eth0.1. I think this is because only eth0.1@eth0 exists which is not the same name.

Then I upgraded to Debian Buster and rebooted, this is the relevant log cut out (ethblack got an address this time):

Feb 14 10:11:59 gnubee.gnubee kernel: mtk_soc_eth 1e100000.ethernet: generated random MAC address 66:24:a7:a6:63:30
Feb 14 10:11:59 gnubee.gnubee kernel: mtk_soc_eth 1e100000.ethernet eth0: mediatek frame engine at 0xbe100000, irq 21
Feb 14 10:11:59 gnubee.gnubee kernel: mtk_soc_eth 1e100000.ethernet: generated random MAC address ca:35:48:2d:09:0f
Feb 14 10:11:59 gnubee.gnubee kernel: mtk_soc_eth 1e100000.ethernet eth1: mediatek frame engine at 0xbe100000, irq 21
Feb 14 10:11:59 gnubee.gnubee kernel: mt7530 mdio-bus:00: MT7530 adapts as multi-chip module
Feb 14 10:11:59 gnubee.gnubee kernel: libphy: dsa slave smi: probed
Feb 14 10:11:59 gnubee.gnubee kernel: mt7530 mdio-bus:00 ethblack (uninitialized): PHY [dsa-0.0:00] driver [Generic PHY]
Feb 14 10:11:59 gnubee.gnubee kernel: mt7530 mdio-bus:00 ethblue (uninitialized): PHY [dsa-0.0:04] driver [Generic PHY]
Feb 14 10:11:59 gnubee.gnubee kernel: mt7530 mdio-bus:00: configuring for fixed/trgmii link mode
Feb 14 10:11:59 gnubee.gnubee kernel: mt7530 mdio-bus:00: Link is Up - 1Gbps/Full - flow control off
Feb 14 10:11:59 gnubee.gnubee kernel: DSA: tree 0 setup
Feb 14 10:12:00 gnubee.gnubee kernel: mtk_soc_eth 1e100000.ethernet eth0: configuring for fixed/rgmii link mode
Feb 14 10:12:00 gnubee.gnubee kernel: mtk_soc_eth 1e100000.ethernet eth0: Link is Up - 1Gbps/Full - flow control rx/tx
Feb 14 10:12:00 gnubee.gnubee kernel: IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
Feb 14 10:12:01 gnubee.gnubee systemd-udevd[1378]: Using default interface naming scheme 'v240'.
Feb 14 10:12:01 gnubee.gnubee systemd-udevd[1376]: Using default interface naming scheme 'v240'.
Feb 14 10:12:01 gnubee.gnubee systemd-udevd[1376]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable.
Feb 14 10:12:01 gnubee.gnubee systemd-udevd[1378]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable.
Feb 14 10:12:01 gnubee.gnubee systemd-udevd[1378]: Could not generate persistent MAC address for eth0: No such file or directory
Feb 14 10:12:01 gnubee.gnubee systemd-udevd[1371]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable.
Feb 14 10:12:01 gnubee.gnubee systemd-udevd[1370]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable.
Feb 14 10:12:03 gnubee.gnubee ifup[1405]: ifup: failed to bring up eth0.1
Feb 14 10:12:03 gnubee.gnubee systemd-timesyncd[1412]: System clock time unset or jumped backwards, restoring from recorded timestamp: Mon 2020-01-06 23:21:48 UTC
Jan 06 23:21:48 gnubee.gnubee systemd[1]: Started Network Time Synchronization.
Jan 06 23:21:48 gnubee.gnubee dhclient[1449]: Internet Systems Consortium DHCP Client 4.4.1
Jan 06 23:21:48 gnubee.gnubee ifup[1405]: Internet Systems Consortium DHCP Client 4.4.1
Jan 06 23:21:48 gnubee.gnubee ifup[1405]: Copyright 2004-2018 Internet Systems Consortium.
Jan 06 23:21:48 gnubee.gnubee ifup[1405]: All rights reserved.
Jan 06 23:21:48 gnubee.gnubee ifup[1405]: For info, please visit https://www.isc.org/software/dhcp/
Jan 06 23:21:48 gnubee.gnubee dhclient[1449]: Copyright 2004-2018 Internet Systems Consortium.
Jan 06 23:21:48 gnubee.gnubee dhclient[1449]: All rights reserved.
Jan 06 23:21:48 gnubee.gnubee dhclient[1449]: For info, please visit https://www.isc.org/software/dhcp/
Jan 06 23:21:48 gnubee.gnubee dhclient[1449]: 
Jan 06 23:21:48 gnubee.gnubee systemd[1]: Reached target System Time Synchronized.
Jan 06 23:21:48 gnubee.gnubee kernel: device eth0 entered promiscuous mode
Jan 06 23:21:48 gnubee.gnubee kernel: mt7530 mdio-bus:00 ethblack: configuring for phy/gmii link mode
Jan 06 23:21:48 gnubee.gnubee kernel: 8021q: adding VLAN 0 to HW filter on device ethblack
Jan 06 23:21:48 gnubee.gnubee systemd[1]: Reached target Swap.
Jan 06 23:21:48 gnubee.gnubee systemd[1]: Reached target System Initialization.
Jan 06 23:21:48 gnubee.gnubee systemd[1]: Reached target Basic System.
Jan 06 23:21:48 gnubee.gnubee dhclient[1449]: Listening on LPF/ethblack/90:50:5a:55:43:68
Jan 06 23:21:48 gnubee.gnubee ifup[1405]: Listening on LPF/ethblack/90:50:5a:55:43:68
Jan 06 23:21:48 gnubee.gnubee ifup[1405]: Sending on   LPF/ethblack/90:50:5a:55:43:68
Jan 06 23:21:48 gnubee.gnubee ifup[1405]: Sending on   Socket/fallback
Jan 06 23:21:48 gnubee.gnubee ifup[1405]: Created duid "\000\001\000\001%\246}\214\220PZUCh".
Jan 06 23:21:48 gnubee.gnubee dhclient[1449]: Sending on   LPF/ethblack/90:50:5a:55:43:68
Jan 06 23:21:48 gnubee.gnubee ifup[1405]: DHCPREQUEST for 10.10.0.212 on ethblack to 255.255.255.255 port 67
Jan 06 23:21:48 gnubee.gnubee dhclient[1449]: Sending on   Socket/fallback
Jan 06 23:21:48 gnubee.gnubee dhclient[1449]: Created duid "\000\001\000\001%\246}\214\220PZUCh".
Jan 06 23:21:48 gnubee.gnubee dhclient[1449]: DHCPREQUEST for 10.10.0.212 on ethblack to 255.255.255.255 port 67
Jan 06 23:21:51 gnubee.gnubee dhclient[1449]: DHCPREQUEST for 10.10.0.212 on ethblack to 255.255.255.255 port 67
Jan 06 23:21:51 gnubee.gnubee ifup[1405]: DHCPREQUEST for 10.10.0.212 on ethblack to 255.255.255.255 port 67
Jan 06 23:21:51 gnubee.gnubee kernel: mt7530 mdio-bus:00 ethblack: Link is Up - 1Gbps/Full - flow control off
Jan 06 23:21:51 gnubee.gnubee kernel: IPv6: ADDRCONF(NETDEV_CHANGE): ethblack: link becomes ready
Jan 06 23:21:58 gnubee.gnubee dhclient[1449]: DHCPREQUEST for 10.10.0.212 on ethblack to 255.255.255.255 port 67
Jan 06 23:21:58 gnubee.gnubee ifup[1405]: DHCPREQUEST for 10.10.0.212 on ethblack to 255.255.255.255 port 67
Jan 06 23:21:58 gnubee.gnubee ifup[1405]: DHCPACK of 10.10.0.212 from 10.10.0.1
Jan 06 23:21:58 gnubee.gnubee dhclient[1449]: DHCPACK of 10.10.0.212 from 10.10.0.1
Jan 06 23:21:59 gnubee.gnubee systemd[1]: Stopping Network Time Synchronization...
Jan 06 23:21:59 gnubee.gnubee systemd[1]: systemd-timesyncd.service: Succeeded.
Jan 06 23:21:59 gnubee.gnubee systemd[1]: Stopped Network Time Synchronization.
Jan 06 23:21:59 gnubee.gnubee systemd[1]: Starting Network Time Synchronization...
Jan 06 23:21:59 gnubee.gnubee ifup[1405]: Warning: The unit file, source configuration file or drop-ins of systemd-timesyncd.service changed on disk. Run 'systemctl daemon-reload' to reload units.
Jan 06 23:21:59 gnubee.gnubee systemd[1]: Started Network Time Synchronization.
Jan 06 23:22:54 gnubee.gnubee systemd-timesyncd[1481]: Synchronized to time server for the first time 10.10.0.1:123 (10.10.0.1).
Jan 06 23:22:54 gnubee.gnubee dhclient[1449]: bound to 10.10.0.212 -- renewal in 20050 seconds.
Jan 06 23:22:54 gnubee.gnubee ifup[1405]: bound to 10.10.0.212 -- renewal in 20050 seconds.
Jan 06 23:22:54 gnubee.gnubee systemd[1]: networking.service: Main process exited, code=exited, status=1/FAILURE
Jan 06 23:22:54 gnubee.gnubee systemd[1]: Failed to start Raise network interfaces.
Jan 06 23:22:54 gnubee.gnubee systemd[1]: Reached target Network.

Configuring eth1, disabling eth0.1@eth1 (moving /etc/interfaces.d/02-eth0-1 to 02-eth0-1.disabled) and restarting networking.service fixes the service:

root@gnubee:~# systemctl status networking
● networking.service - Raise network interfaces
   Loaded: loaded (/lib/systemd/system/networking.service; enabled; vendor prese
t: enabled)
   Active: failed (Result: exit-code) since Mon 2020-01-06 23:22:54 U
TC; 9min ago
     Docs: man:interfaces(5)
 Main PID: 1405 (code=exited, status=1/FAILURE)

Jan 06 23:21:58 gnubee.gnubee dhclient[1449]: DHCPREQUEST for 10.10.0.212 on eth
black to 255.255.255.255 port 67
Jan 06 23:21:58 gnubee.gnubee ifup[1405]: DHCPREQUEST for 10.10.0.212 on ethblac
k to 255.255.255.255 port 67
Jan 06 23:21:58 gnubee.gnubee ifup[1405]: DHCPACK of 10.10.0.212 from 10.10.0.1
Jan 06 23:21:58 gnubee.gnubee dhclient[1449]: DHCPACK of 10.10.0.212 from 10.10.
0.1
Jan 06 23:21:59 gnubee.gnubee ifup[1405]: Warning: The unit file, source configu
ration file or drop-ins of systemd-timesyncd.service changed on disk. Run 'syste
mctl daemon-reload' to reload units.
Jan 06 23:22:54 gnubee.gnubee dhclient[1449]: bound to 10.10.0.212 -- renewal in
 20050 seconds.
Jan 06 23:22:54 gnubee.gnubee ifup[1405]: bound to 10.10.0.212 -- renewal in 200
50 seconds.
Jan 06 23:22:54 gnubee.gnubee systemd[1]: networking.ser
root@gnubee:~# systemctl restart networking
root@gnubee:~# systemctl status networking
● networking.service - Raise network interfaces
   Loaded: loaded (/lib/systemd/system/networking.service; enabled; vendor prese
t: enabled)
   Active: active (exited) since Mon 2020-01-06 23:32:42 UTC; 3s ago
     Docs: man:interfaces(5)
  Process: 1607 ExecStart=/sbin/ifup -a --read-environment (code=exited, status=
0/SUCCESS)
 Main PID: 1607 (code=exited, status=0/SUCCESS)

Jan 06 23:32:42 gnubee.gnubee systemd[1]: Starting Raise network interfaces...
Jan 06 23:32:42 gnubee.gnubee systemd[1]: Started Raise network interfaces.
root@gnubee:~# ip addr
1: lo: <LOOPBACK,UP,LOWER_UP> mtu 65536 qdisc noqueue state UNKNOWN group default qlen 1000
    link/loopback 00:00:00:00:00:00 brd 00:00:00:00:00:00
    inet 127.0.0.1/8 scope host lo
       valid_lft forever preferred_lft forever
    inet6 ::1/128 scope host 
       valid_lft forever preferred_lft forever
2: eth0: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc pfifo_fast state UP group default qlen 1000
    link/ether 66:24:a7:a6:63:30 brd ff:ff:ff:ff:ff:ff
    inet6 fe80::6424:a7ff:fea6:6330/64 scope link 
       valid_lft forever preferred_lft forever
3: eth1: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc pfifo_fast state UP group default qlen 1000
    link/ether 90:50:5a:55:43:6a brd ff:ff:ff:ff:ff:ff
    inet 10.10.0.213/24 brd 10.10.0.255 scope global dynamic eth1
       valid_lft 42406sec preferred_lft 42406sec
    inet6 2a01:260:8028:10f0:9250:5aff:fe55:436a/64 scope global dynamic mngtmpaddr 
       valid_lft 2591963sec preferred_lft 604763sec
    inet6 fe80::9250:5aff:fe55:436a/64 scope link 
       valid_lft forever preferred_lft forever
4: ethblack@eth0: <BROADCAST,MULTICAST> mtu 1500 qdisc noqueue state DOWN group default qlen 1000
    link/ether 90:50:5a:55:43:68 brd ff:ff:ff:ff:ff:ff
5: ethblue@eth0: <BROADCAST,MULTICAST> mtu 1500 qdisc noop state DOWN group default qlen 1000
    link/ether 90:50:5a:55:43:69 brd ff:ff:ff:ff:ff:ff
6: eth0.1@eth0: <BROADCAST,MULTICAST> mtu 1500 qdisc noop state DOWN group default qlen 1000
    link/ether 66:24:a7:a6:63:30 brd ff:ff:ff:ff:ff:ff

Questions:

jjakob commented 4 years ago

The service also starts correctly if 02-eth0-1 is renamed and modified to the correct name eth0.1@eth0 instead of disabling it. eth0.1@eth0 stays down in any case (with blue or black connected) so I don't understand why it's there/should have a dhcp client on it.

neilbrown commented 4 years ago

I wouldn't expect it to bring up eth0.1. That interface only exists in old 4.4 kernels with the Ralink driver for the ethernet switch. For newer kernels with the mainline switch driver, it is ethblack that should be configured. Without logs I cannot suggest why ethblack didn't get configured (or maybe it did, but you looked in the wrong place...??).

This all works for me, so I'm going to close this bug. If you want it pursued and have logs, feel free to re-open. Thanks.