Hello all,
Firstly, I've got a pretty heavily customized openWRT that I built from source and all that, so I've got some clue what I'm doin. I am not, however, an expert with Linux or networking.
So I'm using my device as a USB ethernet gadget (uses the g_ether kmod). Usually, it connects fine and gives and IP to the host; however, occasionally it will not (sometimes once in 10, sometimes once in 30 tries). From the syslog, it appears that openWRT is trying to give the host an IP, but the host is not accepting it for some reason.
syslog
...
Wed Jan 6 22:32:49 2021 user.info kernel: kmodloader: loading kernel modules from /etc/modules.d/g_ether*
Wed Jan 6 22:32:49 2021 kern.warn kernel: using random self ethernet address
Wed Jan 6 22:32:49 2021 kern.warn kernel: using random host ethernet address
Wed Jan 6 22:32:49 2021 kern.info kernel: using host ethernet address: 5e:bc:ca:27:92:b1
Wed Jan 6 22:32:49 2021 kern.info kernel: using self ethernet address: 50:bc:ca:27:92:b1
Wed Jan 6 22:32:49 2021 kern.info kernel: usb0: HOST MAC 5e:bc:ca:27:92:b1
Wed Jan 6 22:32:49 2021 kern.info kernel: usb0: MAC 50:bc:ca:27:92:b1
Wed Jan 6 22:32:49 2021 kern.warn kernel: using random self ethernet address
Wed Jan 6 22:32:49 2021 kern.warn kernel: using random host ethernet address
Wed Jan 6 22:32:49 2021 kern.info kernel: g_ether gadget: Ethernet Gadget, version: Memorial Day 2008
Wed Jan 6 22:32:49 2021 kern.info kernel: g_ether gadget: g_ether ready
Wed Jan 6 22:32:49 2021 kern.info kernel: br-lan: port 1(usb0) entered blocking state
Wed Jan 6 22:32:49 2021 kern.info kernel: br-lan: port 1(usb0) entered disabled state
Wed Jan 6 22:32:49 2021 kern.info kernel: device usb0 entered promiscuous mode
Wed Jan 6 22:32:50 2021 daemon.notice netifd: Interface 'lan' is enabled
Wed Jan 6 22:32:50 2021 daemon.notice netifd: Interface 'lan' is setting up now
Wed Jan 6 22:32:50 2021 kern.info kernel: IPv6: ADDRCONF(NETDEV_UP): br-lan: link is not ready
Wed Jan 6 22:32:50 2021 daemon.notice netifd: Interface 'lan' is now up
Wed Jan 6 22:32:50 2021 user.info kernel: kmodloader: done loading kernel modules from /etc/modules.d/g_ether*
Wed Jan 6 22:32:50 2021 daemon.info [1733]: usb0: IAID ca:27:92:b1
Wed Jan 6 22:32:50 2021 daemon.info [1733]: usb0: adding address fe80::efbf:a261:156d:3852
Wed Jan 6 22:32:50 2021 daemon.err [1733]: ipv6_addaddr1: Permission denied
Wed Jan 6 22:32:50 2021 daemon.info [1733]: usb0: carrier lost
Wed Jan 6 22:32:50 2021 user.notice ModemManager: hotplug: add network interface usb0: event processed
Wed Jan 6 22:32:50 2021 user.notice ModemManager: hotplug: event reported: action=add, name=usb0, subsystem=net
Wed Jan 6 22:32:50 2021 daemon.info [1733]: br-lan: waiting for carrier
Wed Jan 6 22:32:50 2021 daemon.info [1733]: usb0: carrier acquired
Wed Jan 6 22:32:50 2021 daemon.info [1733]: usb0: IAID ca:27:92:b1
Wed Jan 6 22:32:50 2021 daemon.err [1733]: usb0: IAID conflicts with one assigned to br-lan
Wed Jan 6 22:32:50 2021 daemon.info [1733]: br-lan: new hardware address: 1a:4d:ea:8a:fb:e2
Wed Jan 6 22:32:50 2021 daemon.info [1733]: br-lan: new hardware address: 50:bc:ca:27:92:b1
Wed Jan 6 22:32:50 2021 daemon.info [1733]: usb0: carrier lost
Wed Jan 6 22:32:50 2021 kern.info kernel: g_ether gadget: high-speed config #1: CDC Ethernet (ECM)
Wed Jan 6 22:32:50 2021 kern.info kernel: br-lan: port 1(usb0) entered blocking state
Wed Jan 6 22:32:50 2021 kern.info kernel: br-lan: port 1(usb0) entered forwarding state
Wed Jan 6 22:32:50 2021 daemon.notice netifd: Network device 'usb0' link is up
Wed Jan 6 22:32:50 2021 daemon.notice netifd: bridge 'br-lan' link is up
Wed Jan 6 22:32:50 2021 daemon.notice netifd: Interface 'lan' has link connectivity
Wed Jan 6 22:32:50 2021 kern.info kernel: IPv6: ADDRCONF(NETDEV_CHANGE): br-lan: link becomes ready
Wed Jan 6 22:32:50 2021 user.notice firewall: Reloading firewall due to ifup of lan (br-lan)
Wed Jan 6 22:32:50 2021 daemon.info [1733]: usb0: carrier acquired
Wed Jan 6 22:32:50 2021 user.notice ModemManager: hotplug: error: parent device sysfspath not found
Wed Jan 6 22:32:50 2021 daemon.info [1733]: usb0: IAID ca:27:92:b1
Wed Jan 6 22:32:50 2021 daemon.err [1733]: usb0: IAID conflicts with one assigned to br-lan
Wed Jan 6 22:32:50 2021 daemon.info [1733]: br-lan: carrier acquired
Wed Jan 6 22:32:50 2021 daemon.info [1733]: br-lan: IAID ca:27:92:b1
Wed Jan 6 22:32:50 2021 daemon.err [1733]: br-lan: IAID conflicts with one assigned to usb0
Wed Jan 6 22:32:50 2021 daemon.info [1733]: br-lan: adding address fe80::efbf:a261:156d:3852
Wed Jan 6 22:32:51 2021 user.notice ModemManager: hotplug: add network interface br-lan: event processed
Wed Jan 6 22:32:51 2021 user.notice ModemManager: hotplug: event reported: action=add, name=br-lan, subsystem=net
Wed Jan 6 22:32:51 2021 daemon.info [1733]: usb0: soliciting a DHCP lease
Wed Jan 6 22:32:51 2021 daemon.info [1733]: usb0: soliciting an IPv6 router
Wed Jan 6 22:32:51 2021 user.notice ModemManager: hotplug: error: parent device sysfspath not found
Wed Jan 6 22:32:51 2021 daemon.err odhcpd[1829]: Failed to send to ff02::1%lan@br-lan (Address not available)
Wed Jan 6 22:32:51 2021 daemon.info [1733]: br-lan: soliciting a DHCP lease
Wed Jan 6 22:32:51 2021 daemon.info [1733]: br-lan: soliciting an IPv6 router
Wed Jan 6 22:32:52 2021 daemon.info dnsmasq[3722]: exiting on receipt of SIGTERM
Wed Jan 6 22:32:52 2021 daemon.info dnsmasq[4026]: started, version 2.80 cachesize 150
Wed Jan 6 22:32:52 2021 daemon.info dnsmasq[4026]: DNS service limited to local subnets
Wed Jan 6 22:32:52 2021 daemon.info dnsmasq[4026]: compile time options: IPv6 GNU-getopt no-DBus no-i18n no-IDN DHCP no-DHCPv6 no-Lua TFTP no-conntrack no-ipset no-auth no-DNSSEC no-ID loop-detect inotify dumpfile
Wed Jan 6 22:32:52 2021 daemon.info dnsmasq-dhcp[4026]: DHCP, IP range 192.168.30.100 -- 192.168.30.249, lease time 12h
Wed Jan 6 22:32:52 2021 daemon.info dnsmasq[4026]: using local addresses only for domain test
Wed Jan 6 22:32:52 2021 daemon.info dnsmasq[4026]: using local addresses only for domain onion
Wed Jan 6 22:32:52 2021 daemon.info dnsmasq[4026]: using local addresses only for domain localhost
Wed Jan 6 22:32:52 2021 daemon.info dnsmasq[4026]: using local addresses only for domain local
Wed Jan 6 22:32:52 2021 daemon.info dnsmasq[4026]: using local addresses only for domain invalid
Wed Jan 6 22:32:52 2021 daemon.info dnsmasq[4026]: using local addresses only for domain bind
Wed Jan 6 22:32:52 2021 daemon.info dnsmasq[4026]: using local addresses only for domain lan
Wed Jan 6 22:32:52 2021 daemon.warn dnsmasq[4026]: no servers found in /tmp/resolv.conf.auto, will retry
Wed Jan 6 22:32:52 2021 daemon.info dnsmasq[4026]: read /etc/hosts - 4 addresses
Wed Jan 6 22:32:52 2021 daemon.info dnsmasq[4026]: read /tmp/hosts/odhcpd - 0 addresses
Wed Jan 6 22:32:52 2021 daemon.info dnsmasq[4026]: read /tmp/hosts/dhcp.cfg01411c - 2 addresses
Wed Jan 6 22:32:52 2021 daemon.info dnsmasq-dhcp[4026]: read /etc/ethers - 0 addresses
Wed Jan 6 22:32:52 2021 daemon.info dnsmasq[4026]: read /etc/hosts - 4 addresses
Wed Jan 6 22:32:52 2021 daemon.info dnsmasq[4026]: read /tmp/hosts/odhcpd - 0 addresses
Wed Jan 6 22:32:52 2021 daemon.info dnsmasq[4026]: read /tmp/hosts/dhcp.cfg01411c - 2 addresses
Wed Jan 6 22:32:52 2021 daemon.info dnsmasq-dhcp[4026]: read /etc/ethers - 0 addresses
Wed Jan 6 22:32:52 2021 daemon.info dnsmasq-dhcp[4026]: DHCPDISCOVER(br-lan) 192.168.30.30 5e:bc:ca:27:92:b1
Wed Jan 6 22:32:52 2021 daemon.info dnsmasq-dhcp[4026]: DHCPOFFER(br-lan) 192.168.30.30 5e:bc:ca:27:92:b1
Wed Jan 6 22:32:55 2021 daemon.info dnsmasq-dhcp[4026]: DHCPDISCOVER(br-lan) 192.168.30.30 5e:bc:ca:27:92:b1
Wed Jan 6 22:32:55 2021 daemon.info dnsmasq-dhcp[4026]: DHCPOFFER(br-lan) 192.168.30.30 5e:bc:ca:27:92:b1
Wed Jan 6 22:32:56 2021 daemon.info [1733]: usb0: probing for an IPv4LL address
Wed Jan 6 22:32:56 2021 daemon.info [1733]: br-lan: probing for an IPv4LL address
Wed Jan 6 22:32:59 2021 daemon.info dnsmasq-dhcp[4026]: DHCPDISCOVER(br-lan) 192.168.30.30 5e:bc:ca:27:92:b1
Wed Jan 6 22:32:59 2021 daemon.info dnsmasq-dhcp[4026]: DHCPOFFER(br-lan) 192.168.30.30 5e:bc:ca:27:92:b1
Wed Jan 6 22:33:00 2021 daemon.info [1733]: usb0: using IPv4LL address 169.254.177.77
Wed Jan 6 22:33:00 2021 daemon.info [1733]: usb0: adding route to 169.254.0.0/16
Wed Jan 6 22:33:00 2021 daemon.info [1733]: usb0: adding default route
Wed Jan 6 22:33:01 2021 daemon.info [1733]: br-lan: using IPv4LL address 169.254.177.77
Wed Jan 6 22:33:01 2021 daemon.info [1733]: br-lan: adding route to 169.254.0.0/16
Wed Jan 6 22:33:04 2021 daemon.warn [1733]: br-lan: no IPv6 Routers available
Wed Jan 6 22:33:07 2021 daemon.info dnsmasq-dhcp[4026]: DHCPDISCOVER(br-lan) 192.168.30.30 5e:bc:ca:27:92:b1
Wed Jan 6 22:33:07 2021 daemon.info dnsmasq-dhcp[4026]: DHCPOFFER(br-lan) 192.168.30.30 5e:bc:ca:27:92:b1
Wed Jan 6 22:33:24 2021 daemon.info dnsmasq-dhcp[4026]: DHCPDISCOVER(br-lan) 192.168.30.30 5e:bc:ca:27:92:b1
Wed Jan 6 22:33:24 2021 daemon.info dnsmasq-dhcp[4026]: DHCPOFFER(br-lan) 192.168.30.30 5e:bc:ca:27:92:b1
Wed Jan 6 22:33:36 2021 daemon.info dnsmasq-dhcp[4026]: DHCPREQUEST(br-lan) 192.168.30.30 5e:bc:ca:27:92:b1
Wed Jan 6 22:33:36 2021 daemon.info dnsmasq-dhcp[4026]: DHCPACK(br-lan) 192.168.30.30 5e:bc:ca:27:92:b1 my-computer
Wed Jan 6 22:33:38 2021 daemon.info dnsmasq-dhcp[4026]: DHCPDISCOVER(br-lan) 192.168.30.30 5e:bc:ca:27:92:b1
Wed Jan 6 22:33:38 2021 daemon.info dnsmasq-dhcp[4026]: DHCPOFFER(br-lan) 192.168.30.30 5e:bc:ca:27:92:b1
Wed Jan 6 22:33:40 2021 daemon.info dnsmasq-dhcp[4026]: DHCPDISCOVER(br-lan) 192.168.30.30 5e:bc:ca:27:92:b1
Wed Jan 6 22:33:40 2021 daemon.info dnsmasq-dhcp[4026]: DHCPOFFER(br-lan) 192.168.30.30 5e:bc:ca:27:92:b1
Wed Jan 6 22:33:45 2021 daemon.info dnsmasq-dhcp[4026]: DHCPDISCOVER(br-lan) 192.168.30.30 5e:bc:ca:27:92:b1
Wed Jan 6 22:33:45 2021 daemon.info dnsmasq-dhcp[4026]: DHCPOFFER(br-lan) 192.168.30.30 5e:bc:ca:27:92:b1
Wed Jan 6 22:33:54 2021 daemon.info dnsmasq-dhcp[4026]: DHCPDISCOVER(br-lan) 192.168.30.30 5e:bc:ca:27:92:b1
Wed Jan 6 22:33:54 2021 daemon.info dnsmasq-dhcp[4026]: DHCPOFFER(br-lan) 192.168.30.30 5e:bc:ca:27:92:b1
Wed Jan 6 22:34:11 2021 daemon.info dnsmasq-dhcp[4026]: DHCPDISCOVER(br-lan) 192.168.30.30 5e:bc:ca:27:92:b1
Wed Jan 6 22:34:11 2021 daemon.info dnsmasq-dhcp[4026]: DHCPOFFER(br-lan) 192.168.30.30 5e:bc:ca:27:92:b1
Wed Jan 6 22:34:21 2021 daemon.info dnsmasq-dhcp[4026]: DHCPREQUEST(br-lan) 192.168.30.30 5e:bc:ca:27:92:b1
Wed Jan 6 22:34:21 2021 daemon.info dnsmasq-dhcp[4026]: DHCPACK(br-lan) 192.168.30.30 5e:bc:ca:27:92:b1 my-computer
Wed Jan 6 22:34:23 2021 daemon.info dnsmasq-dhcp[4026]: DHCPDISCOVER(br-lan) 192.168.30.30 5e:bc:ca:27:92:b1
Wed Jan 6 22:34:23 2021 daemon.info dnsmasq-dhcp[4026]: DHCPOFFER(br-lan) 192.168.30.30 5e:bc:ca:27:92:b1
Wed Jan 6 22:34:25 2021 daemon.info dnsmasq-dhcp[4026]: DHCPDISCOVER(br-lan) 192.168.30.30 5e:bc:ca:27:92:b1
Wed Jan 6 22:34:25 2021 daemon.info dnsmasq-dhcp[4026]: DHCPOFFER(br-lan) 192.168.30.30 5e:bc:ca:27:92:b1
Wed Jan 6 22:34:29 2021 daemon.info dnsmasq-dhcp[4026]: DHCPDISCOVER(br-lan) 192.168.30.30 5e:bc:ca:27:92:b1
Wed Jan 6 22:34:29 2021 daemon.info dnsmasq-dhcp[4026]: DHCPOFFER(br-lan) 192.168.30.30 5e:bc:ca:27:92:b1
Wed Jan 6 22:34:37 2021 daemon.info dnsmasq-dhcp[4026]: DHCPDISCOVER(br-lan) 192.168.30.30 5e:bc:ca:27:92:b1
Wed Jan 6 22:34:37 2021 daemon.info dnsmasq-dhcp[4026]: DHCPOFFER(br-lan) 192.168.30.30 5e:bc:ca:27:92:b1
Wed Jan 6 22:34:53 2021 daemon.info dnsmasq-dhcp[4026]: DHCPDISCOVER(br-lan) 192.168.30.30 5e:bc:ca:27:92:b1
Wed Jan 6 22:34:53 2021 daemon.info dnsmasq-dhcp[4026]: DHCPOFFER(br-lan) 192.168.30.30 5e:bc:ca:27:92:b1
Wed Jan 6 22:35:06 2021 daemon.info dnsmasq-dhcp[4026]: DHCPREQUEST(br-lan) 192.168.30.30 5e:bc:ca:27:92:b1
Wed Jan 6 22:35:06 2021 daemon.info dnsmasq-dhcp[4026]: DHCPACK(br-lan) 192.168.30.30 5e:bc:ca:27:92:b1 my-computer
Wed Jan 6 22:35:08 2021 daemon.info dnsmasq-dhcp[4026]: DHCPDISCOVER(br-lan) 192.168.30.30 5e:bc:ca:27:92:b1
Wed Jan 6 22:35:08 2021 daemon.info dnsmasq-dhcp[4026]: DHCPOFFER(br-lan) 192.168.30.30 5e:bc:ca:27:92:b1
Wed Jan 6 22:35:10 2021 daemon.info dnsmasq-dhcp[4026]: DHCPDISCOVER(br-lan) 192.168.30.30 5e:bc:ca:27:92:b1
Wed Jan 6 22:35:10 2021 daemon.info dnsmasq-dhcp[4026]: DHCPOFFER(br-lan) 192.168.30.30 5e:bc:ca:27:92:b1
Wed Jan 6 22:35:14 2021 daemon.info dnsmasq-dhcp[4026]: DHCPDISCOVER(br-lan) 192.168.30.30 5e:bc:ca:27:92:b1
Wed Jan 6 22:35:14 2021 daemon.info dnsmasq-dhcp[4026]: DHCPOFFER(br-lan) 192.168.30.30 5e:bc:ca:27:92:b1
Wed Jan 6 22:35:23 2021 daemon.info dnsmasq-dhcp[4026]: DHCPDISCOVER(br-lan) 192.168.30.30 5e:bc:ca:27:92:b1
Wed Jan 6 22:35:23 2021 daemon.info dnsmasq-dhcp[4026]: DHCPOFFER(br-lan) 192.168.30.30 5e:bc:ca:27:92:b1
Wed Jan 6 22:35:39 2021 daemon.info dnsmasq-dhcp[4026]: DHCPDISCOVER(br-lan) 192.168.30.30 5e:bc:ca:27:92:b1
Wed Jan 6 22:35:39 2021 daemon.info dnsmasq-dhcp[4026]: DHCPOFFER(br-lan) 192.168.30.30 5e:bc:ca:27:92:b1
That log starts where I loaded the kernel module. (I used kmodloader so that it would follow the options that I put in /etc/modules.d/g_ether
). The DHCP spam stops for a short time, then resumes.
Here is the relevant portion of my network configuration incase it's useful
config interface 'lan'
option type 'bridge'
option ifname 'usb0'
option proto 'static'
option ipaddr '192.168.30.1'
option netmask '255.255.255.0'
option ip6assign '60'
Some maybe helpful things to note:
- I can see the
my-computer
device in the arp table and in/tmp/dhcp.leases
. - Usually the
flags
field in the arp table is0x0
, but sometimes it is0x2
. - I can never ping the device from openWRT. Even when it gets the IP and can use the internet and all that.
- I've already tried static and dhcp for IP to no avail
- I set the host and device address to
5e:bc:ca:27:92:b1
and50:bc:ca:27:92:b1
because I was hoping that the randomly generated ones for the ethernet gadget were the issue.
Honestly, I think this issue has a lot to do with the computer I'm plugging into, as it is very restricted in what it can do. Despite that, I know that I can get an IP if I just reload the g_ether
module. As such, what I hope to learn from you all is either a way to make it so the situation doesn't occur in the first place, or some way to identify the issue other then scraping the syslog.
Thanks for any help you can give!