Intermittent IP Problem with Ethernet Gadget

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 is 0x0, but sometimes it is 0x2.
  • 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 and 50: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!

I think the most you can do is capture the packets in tcpdump
tcpdump -i usb0 -evn udp port 67 or icmp
If you see the packets leaving, you can rule out the firewall from the OpenWrt side, as tcpdump captures on the medium.
Just in case, since I had a similar problem lately, post the iptables-save -c -t filter

1 Like

hi, what the make and model?

Thanks for the response.

Here is what I get from ``iptables-save -c -t filter`` on a try where I couldnt get IP
# Generated by iptables-save v1.8.3 on Thu Jan  7 17:22:04 2021
*filter
:INPUT ACCEPT [0:0]
:FORWARD DROP [0:0]
:OUTPUT ACCEPT [0:0]
:forwarding_lan_rule - [0:0]
:forwarding_rule - [0:0]
:forwarding_wan_rule - [0:0]
:input_lan_rule - [0:0]
:input_rule - [0:0]
:input_wan_rule - [0:0]
:output_lan_rule - [0:0]
:output_rule - [0:0]
:output_wan_rule - [0:0]
:reject - [0:0]
:syn_flood - [0:0]
:zone_lan_dest_ACCEPT - [0:0]
:zone_lan_forward - [0:0]
:zone_lan_input - [0:0]
:zone_lan_output - [0:0]
:zone_lan_src_ACCEPT - [0:0]
:zone_wan_dest_ACCEPT - [0:0]
:zone_wan_dest_REJECT - [0:0]
:zone_wan_forward - [0:0]
:zone_wan_input - [0:0]
:zone_wan_output - [0:0]
:zone_wan_src_REJECT - [0:0]
[0:0] -A INPUT -i lo -m comment --comment "!fw3" -j ACCEPT
[51:10492] -A INPUT -m comment --comment "!fw3: Custom input rule chain" -j input_rule
[35:6241] -A INPUT -m conntrack --ctstate RELATED,ESTABLISHED -m comment --comment "!fw3" -j ACCEPT
[0:0] -A INPUT -p tcp -m tcp --tcp-flags FIN,SYN,RST,ACK SYN -m comment --comment "!fw3" -j syn_flood
[12:3948] -A INPUT -i br-lan -m comment --comment "!fw3" -j zone_lan_input
[4:303] -A INPUT -i wlan0 -m comment --comment "!fw3" -j zone_wan_input
[0:0] -A INPUT -i eth0 -m comment --comment "!fw3" -j zone_wan_input
[0:0] -A FORWARD -m comment --comment "!fw3: Custom forwarding rule chain" -j forwarding_rule
[0:0] -A FORWARD -m conntrack --ctstate RELATED,ESTABLISHED -m comment --comment "!fw3" -j ACCEPT
[0:0] -A FORWARD -i br-lan -m comment --comment "!fw3" -j zone_lan_forward
[0:0] -A FORWARD -i wlan0 -m comment --comment "!fw3" -j zone_wan_forward
[0:0] -A FORWARD -i eth0 -m comment --comment "!fw3" -j zone_wan_forward
[0:0] -A FORWARD -m comment --comment "!fw3" -j reject
[0:0] -A OUTPUT -o lo -m comment --comment "!fw3" -j ACCEPT
[59:7171] -A OUTPUT -m comment --comment "!fw3: Custom output rule chain" -j output_rule
[27:1879] -A OUTPUT -m conntrack --ctstate RELATED,ESTABLISHED -m comment --comment "!fw3" -j ACCEPT
[12:3940] -A OUTPUT -o br-lan -m comment --comment "!fw3" -j zone_lan_output
[20:1352] -A OUTPUT -o wlan0 -m comment --comment "!fw3" -j zone_wan_output
[0:0] -A OUTPUT -o eth0 -m comment --comment "!fw3" -j zone_wan_output
[0:0] -A reject -p tcp -m comment --comment "!fw3" -j REJECT --reject-with tcp-reset
[3:267] -A reject -m comment --comment "!fw3" -j REJECT --reject-with icmp-port-unreachable
[0:0] -A syn_flood -p tcp -m tcp --tcp-flags FIN,SYN,RST,ACK SYN -m limit --limit 25/sec --limit-burst 50 -m comment --comment "!fw3" -j RETURN
[0:0] -A syn_flood -m comment --comment "!fw3" -j DROP
[12:3940] -A zone_lan_dest_ACCEPT -o br-lan -m comment --comment "!fw3" -j ACCEPT
[0:0] -A zone_lan_forward -m comment --comment "!fw3: Custom lan forwarding rule chain" -j forwarding_lan_rule
[0:0] -A zone_lan_forward -p tcp -m comment --comment "!fw3: ping my_computer" -j zone_wan_dest_ACCEPT
[0:0] -A zone_lan_forward -p udp -m comment --comment "!fw3: ping my_computer" -j zone_wan_dest_ACCEPT
[0:0] -A zone_lan_forward -p icmp -m comment --comment "!fw3: ping my_computer" -j zone_wan_dest_ACCEPT
[0:0] -A zone_lan_forward -p igmp -m comment --comment "!fw3: ping my_computer" -j zone_wan_dest_ACCEPT
[0:0] -A zone_lan_forward -m comment --comment "!fw3: Zone lan to wan forwarding policy" -j zone_wan_dest_ACCEPT
[0:0] -A zone_lan_forward -m conntrack --ctstate DNAT -m comment --comment "!fw3: Accept port forwards" -j ACCEPT
[0:0] -A zone_lan_forward -m comment --comment "!fw3" -j zone_lan_dest_ACCEPT
[12:3948] -A zone_lan_input -m comment --comment "!fw3: Custom lan input rule chain" -j input_lan_rule
[0:0] -A zone_lan_input -m conntrack --ctstate DNAT -m comment --comment "!fw3: Accept port redirections" -j ACCEPT
[12:3948] -A zone_lan_input -m comment --comment "!fw3" -j zone_lan_src_ACCEPT
[12:3940] -A zone_lan_output -m comment --comment "!fw3: Custom lan output rule chain" -j output_lan_rule
[12:3940] -A zone_lan_output -m comment --comment "!fw3" -j zone_lan_dest_ACCEPT
[12:3948] -A zone_lan_src_ACCEPT -i br-lan -m conntrack --ctstate NEW,UNTRACKED -m comment --comment "!fw3" -j ACCEPT
[0:0] -A zone_wan_dest_ACCEPT -o wlan0 -m conntrack --ctstate INVALID -m comment --comment "!fw3: Prevent NAT leakage" -j DROP
[20:1352] -A zone_wan_dest_ACCEPT -o wlan0 -m comment --comment "!fw3" -j ACCEPT
[0:0] -A zone_wan_dest_ACCEPT -o eth0 -m conntrack --ctstate INVALID -m comment --comment "!fw3: Prevent NAT leakage" -j DROP
[0:0] -A zone_wan_dest_ACCEPT -o eth0 -m comment --comment "!fw3" -j ACCEPT
[0:0] -A zone_wan_dest_REJECT -o wlan0 -m comment --comment "!fw3" -j reject
[0:0] -A zone_wan_dest_REJECT -o eth0 -m comment --comment "!fw3" -j reject
[0:0] -A zone_wan_forward -m comment --comment "!fw3: Custom wan forwarding rule chain" -j forwarding_wan_rule
[0:0] -A zone_wan_forward -p esp -m comment --comment "!fw3: Allow-IPSec-ESP" -j zone_lan_dest_ACCEPT
[0:0] -A zone_wan_forward -p udp -m udp --dport 500 -m comment --comment "!fw3: Allow-ISAKMP" -j zone_lan_dest_ACCEPT
[0:0] -A zone_wan_forward -m conntrack --ctstate DNAT -m comment --comment "!fw3: Accept port forwards" -j ACCEPT
[0:0] -A zone_wan_forward -m comment --comment "!fw3" -j zone_wan_dest_REJECT
[4:303] -A zone_wan_input -m comment --comment "!fw3: Custom wan input rule chain" -j input_wan_rule
[0:0] -A zone_wan_input -p udp -m udp --dport 68 -m comment --comment "!fw3: Allow-DHCP-Renew" -j ACCEPT
[0:0] -A zone_wan_input -p icmp -m icmp --icmp-type 8 -m comment --comment "!fw3: Allow-Ping" -j ACCEPT
[1:36] -A zone_wan_input -p igmp -m comment --comment "!fw3: Allow-IGMP" -j ACCEPT
[0:0] -A zone_wan_input -m conntrack --ctstate DNAT -m comment --comment "!fw3: Accept port redirections" -j ACCEPT
[3:267] -A zone_wan_input -m comment --comment "!fw3" -j zone_wan_src_REJECT
[20:1352] -A zone_wan_output -m comment --comment "!fw3: Custom wan output rule chain" -j output_wan_rule
[20:1352] -A zone_wan_output -m comment --comment "!fw3" -j zone_wan_dest_ACCEPT
[3:267] -A zone_wan_src_REJECT -i wlan0 -m comment --comment "!fw3" -j reject
[0:0] -A zone_wan_src_REJECT -i eth0 -m comment --comment "!fw3" -j reject
COMMIT
# Completed on Thu Jan  7 17:22:04 2021

Sadly, I dont really know what I'm looking for in there.

With tcpdump, I could still see the pings going to the computer
...
21:30:14.589441 50:bc:ca:27:92:b1 > 12:34:56:78:9a:bc, ethertype IPv4 (0x0800), length 98: (tos 0x0, ttl 64, id 61326, offset 0, flags [DF], proto ICMP (1), length 84)
    192.168.30.1 > 192.168.30.30: ICMP echo request, id 5937, seq 45, length 64
21:30:15.589958 50:bc:ca:27:92:b1 > 12:34:56:78:9a:bc, ethertype IPv4 (0x0800), length 98: (tos 0x0, ttl 64, id 61379, offset 0, flags [DF], proto ICMP (1), length 84)
    192.168.30.1 > 192.168.30.30: ICMP echo request, id 5937, seq 46, length 64
...

so from what you said, I think that means it is not being stopped by firewall.

I'm also going to try to tcpdump while the connection is being made so that I can see the discover and offer conversation.

thanks for the info

for my hardware that is running OpenWrt?

It's also custom-made, based on an imx6ul processor.

i have two usb gadgets, both running openwrt firmware, never a problem.
not custom hardware running custom firmware.

Nice. As I mentioned, it works for me the majority of the time as well.

I'm pretty sure my problem is quite specific to my situation. I was just hoping to get some advice from people who have more time and experience with this stuff than I do. Right now I don't really have any good ideas on how to identify this issue in software so that I can reload the module and fix it.

  • It shows up properly in dhcp.leases and the arp table, so I can't identify it from there.
  • I can't ping it, even when it connects properly (may possibly have to do with the computer I'm connecting it to), so I can't ping it to check if it's live

Only things I can think of to identify the issue is happening are

  • Have a script that watches the syslog for the issue (which is terrible)
  • Maybe watch the traffic with tcpdump or something and identify it that way

So after comparing the the dhcp conversations where one got an IP and one did not, it looks like maybe the reply with the offer is not getting to the usb0 interface.

I don't know how or why that would happen but here's why I think that

I started tcpdump immediately after the usb0 interface came up until I was able to capture both a case of it working and of it not working.

The captures are line for line the same (except for timestamps, etc.) until the successful one receives a DHCP reply.

tcpdump from successful one
19:20:42.984048 50:bc:ca:27:92:b1 > ff:ff:ff:ff:ff:ff, ethertype IPv4 (0x0800), length 390: (tos 0x0, ttl 64, id 22748, offset 0, flags [none], proto UDP (17), length 376)
    0.0.0.0.68 > 255.255.255.255.67: BOOTP/DHCP, Request from 50:bc:ca:27:92:b1, length 348, xid 0x889f5495, Flags [none]
	  Client-Ethernet-Address 50:bc:ca:27:92:b1
	  Vendor-rfc1048 Extensions
	    Magic Cookie 0x63825363
	    DHCP-Message Option 53, length 1: Discover
	    Client-ID Option 61, length 19: hardware-type 255, ca:27:92:b1:00:01:00:01:27:8a:11:f1:3e:91:d6:fb:03:16
	    SLP-NA Option 80, length 0""
	    NOAUTO Option 116, length 1: Y
	    MSZ Option 57, length 2: 1472
	    Vendor-Class Option 60, length 44: "dhcpcd-7.2.2:Linux-4.14.195:armv7l:Freescale"
	    Hostname Option 12, length 7: "OpenWrt"
	    T145 Option 145, length 1: 1
	    Parameter-Request Option 55, length 14: 
	      Subnet-Mask, Classless-Static-Route, Static-Route, Default-Gateway
	      Domain-Name-Server, Hostname, Domain-Name, MTU
	      BR, Lease-Time, Server-ID, RN
	      RB, Option 119
19:20:43.845928 50:bc:ca:27:92:b1 > ff:ff:ff:ff:ff:ff, ethertype IPv4 (0x0800), length 390: (tos 0x0, ttl 64, id 11831, offset 0, flags [none], proto UDP (17), length 376)
    0.0.0.0.68 > 255.255.255.255.67: BOOTP/DHCP, Request from 50:bc:ca:27:92:b1, length 348, xid 0x6d2325f, Flags [none]
	  Client-Ethernet-Address 50:bc:ca:27:92:b1
	  Vendor-rfc1048 Extensions
	    Magic Cookie 0x63825363
	    DHCP-Message Option 53, length 1: Discover
	    Client-ID Option 61, length 19: hardware-type 255, ca:27:92:b1:00:01:00:01:27:8a:11:f1:3e:91:d6:fb:03:16
	    SLP-NA Option 80, length 0""
	    NOAUTO Option 116, length 1: Y
	    MSZ Option 57, length 2: 1472
	    Vendor-Class Option 60, length 44: "dhcpcd-7.2.2:Linux-4.14.195:armv7l:Freescale"
	    Hostname Option 12, length 7: "OpenWrt"
	    T145 Option 145, length 1: 1
	    Parameter-Request Option 55, length 14: 
	      Subnet-Mask, Classless-Static-Route, Static-Route, Default-Gateway
	      Domain-Name-Server, Hostname, Domain-Name, MTU
	      BR, Lease-Time, Server-ID, RN
	      RB, Option 119
19:20:44.309628 a4:bb:6d:fc:fe:e7 > ff:ff:ff:ff:ff:ff, ethertype IPv4 (0x0800), length 343: (tos 0xc0, ttl 64, id 0, offset 0, flags [DF], proto UDP (17), length 329)
    0.0.0.0.68 > 255.255.255.255.67: BOOTP/DHCP, Request from a4:bb:6d:fc:fe:e7, length 301, xid 0xaa8163d7, secs 1, Flags [none]
	  Client-Ethernet-Address a4:bb:6d:fc:fe:e7
	  Vendor-rfc1048 Extensions
	    Magic Cookie 0x63825363
	    DHCP-Message Option 53, length 1: Discover
	    Client-ID Option 61, length 7: ether a4:bb:6d:fc:fe:e7
	    Parameter-Request Option 55, length 17: 
	      Subnet-Mask, Time-Zone, Domain-Name-Server, Hostname
	      Domain-Name, MTU, BR, Classless-Static-Route
	      Default-Gateway, Static-Route, YD, YS
	      NTP, Option 119, Classless-Static-Route-Microsoft, Option 252
	      RP
	    MSZ Option 57, length 2: 576
	    Requested-IP Option 50, length 4: 192.168.30.30
	    Hostname Option 12, length 17: "my-redacted-name"
19:20:46.775281 a4:bb:6d:fc:fe:e7 > ff:ff:ff:ff:ff:ff, ethertype IPv4 (0x0800), length 343: (tos 0xc0, ttl 64, id 0, offset 0, flags [DF], proto UDP (17), length 329)
    0.0.0.0.68 > 255.255.255.255.67: BOOTP/DHCP, Request from a4:bb:6d:fc:fe:e7, length 301, xid 0x237c9e1e, secs 2, Flags [none]
	  Client-Ethernet-Address a4:bb:6d:fc:fe:e7
	  Vendor-rfc1048 Extensions
	    Magic Cookie 0x63825363
	    DHCP-Message Option 53, length 1: Discover
	    Client-ID Option 61, length 7: ether a4:bb:6d:fc:fe:e7
	    Parameter-Request Option 55, length 17: 
	      Subnet-Mask, Time-Zone, Domain-Name-Server, Hostname
	      Domain-Name, MTU, BR, Classless-Static-Route
	      Default-Gateway, Static-Route, YD, YS
	      NTP, Option 119, Classless-Static-Route-Microsoft, Option 252
	      RP
	    MSZ Option 57, length 2: 576
	    Requested-IP Option 50, length 4: 192.168.30.30
	    Hostname Option 12, length 17: "my-redacted-name"
19:20:46.780667 50:bc:ca:27:92:b1 > a4:bb:6d:fc:fe:e7, ethertype IPv4 (0x0800), length 342: (tos 0xc0, ttl 64, id 54425, offset 0, flags [none], proto UDP (17), length 328)
    192.168.30.1.67 > 192.168.30.30.68: BOOTP/DHCP, Reply, length 300, xid 0x237c9e1e, secs 2, Flags [none]
	  Your-IP 192.168.30.30
	  Server-IP 192.168.30.1
	  Client-Ethernet-Address a4:bb:6d:fc:fe:e7
	  Vendor-rfc1048 Extensions
	    Magic Cookie 0x63825363
	    DHCP-Message Option 53, length 1: Offer
	    Server-ID Option 54, length 4: 192.168.30.1
	    Lease-Time Option 51, length 4: 43200
	    RN Option 58, length 4: 21600
	    RB Option 59, length 4: 37800
	    Subnet-Mask Option 1, length 4: 255.255.255.0
	    BR Option 28, length 4: 192.168.30.255
	    Default-Gateway Option 3, length 4: 192.168.30.1
	    Domain-Name-Server Option 6, length 4: 192.168.30.1
	    Domain-Name Option 15, length 3: "lan"
...
Where the successful one gets the reply, the other gets
19:22:04.021062 a4:bb:6d:fc:fe:e7 > ff:ff:ff:ff:ff:ff, ethertype IPv4 (0x0800), length 343: (tos 0xc0, ttl 64, id 0, offset 0, flags [DF], proto UDP (17), length 329)
    0.0.0.0.68 > 255.255.255.255.67: BOOTP/DHCP, Request from a4:bb:6d:fc:fe:e7, length 301, xid 0x15c3ad1d, secs 7, Flags [none]
	  Client-Ethernet-Address a4:bb:6d:fc:fe:e7
	  Vendor-rfc1048 Extensions
	    Magic Cookie 0x63825363
	    DHCP-Message Option 53, length 1: Discover
	    Client-ID Option 61, length 7: ether a4:bb:6d:fc:fe:e7
	    Parameter-Request Option 55, length 17: 
	      Subnet-Mask, Time-Zone, Domain-Name-Server, Hostname
	      Domain-Name, MTU, BR, Classless-Static-Route
	      Default-Gateway, Static-Route, YD, YS
	      NTP, Option 119, Classless-Static-Route-Microsoft, Option 252
	      RP
	    MSZ Option 57, length 2: 576
	    Requested-IP Option 50, length 4: 192.168.30.30
	    Hostname Option 12, length 17: "my-redacted-name"

The tcpdump of the one that fails never shows it getting a Reply at all. In fact it's constant.

Ignoring the first 2 messages, which are the same as in the successful attempt, there are always 5 of

these
19:22:29.177668 a4:bb:6d:fc:fe:e7 > ff:ff:ff:ff:ff:ff, ethertype IPv4 (0x0800), length 343: (tos 0xc0, ttl 64, id 0, offset 0, flags [DF], proto UDP (17), length 329)
    0.0.0.0.68 > 255.255.255.255.67: BOOTP/DHCP, Request from a4:bb:6d:fc:fe:e7, length 301, xid 0x6bc28f34, secs 32, Flags [none]
	  Client-Ethernet-Address a4:bb:6d:fc:fe:e7
	  Vendor-rfc1048 Extensions
	    Magic Cookie 0x63825363
	    DHCP-Message Option 53, length 1: Discover
	    Client-ID Option 61, length 7: ether a4:bb:6d:fc:fe:e7
	    Parameter-Request Option 55, length 17: 
	      Subnet-Mask, Time-Zone, Domain-Name-Server, Hostname
	      Domain-Name, MTU, BR, Classless-Static-Route
	      Default-Gateway, Static-Route, YD, YS
	      NTP, Option 119, Classless-Static-Route-Microsoft, Option 252
	      RP
	    MSZ Option 57, length 2: 576
	    Requested-IP Option 50, length 4: 192.168.30.30
	    Hostname Option 12, length 17: "my-redacted-name"

followed by one of

these
19:22:40.529958 a4:bb:6d:fc:fe:e7 > ff:ff:ff:ff:ff:ff, ethertype IPv4 (0x0800), length 343: (tos 0xc0, ttl 64, id 0, offset 0, flags [DF], proto UDP (17), length 329)
    0.0.0.0.68 > 255.255.255.255.67: BOOTP/DHCP, Request from a4:bb:6d:fc:fe:e7, length 301, xid 0xcb120806, secs 1, Flags [none]
	  Client-Ethernet-Address a4:bb:6d:fc:fe:e7
	  Vendor-rfc1048 Extensions
	    Magic Cookie 0x63825363
	    DHCP-Message Option 53, length 1: Request
	    Client-ID Option 61, length 7: ether a4:bb:6d:fc:fe:e7
	    Parameter-Request Option 55, length 17: 
	      Subnet-Mask, Time-Zone, Domain-Name-Server, Hostname
	      Domain-Name, MTU, BR, Classless-Static-Route
	      Default-Gateway, Static-Route, YD, YS
	      NTP, Option 119, Classless-Static-Route-Microsoft, Option 252
	      RP
	    MSZ Option 57, length 2: 576
	    Requested-IP Option 50, length 4: 192.168.30.30
	    Hostname Option 12, length 17: "my-redacted-name"

The fact that it's consistent makes me think it really is not ever getting the reply for some reason.

Oh yeah, I also changed the host address to a4:bb:6d:fc:fe:e7 to check something

I wanted to check if there were any other rules that might drop some packets but it looks clean.

These are not pings, they are ICMP unreachables

I wouldn't exactly call it successful. The first client sent out 2 discovery packets, no response. The second client sent out 2 packets, only to get a reply to the last one.Which means the first one got also lost.
Have you checked the interface for drops, errors etc? ip -s link

1 Like

by successful, I just meant the one that was able to get an IP and an internet connection.

Oh you're right, must of copied the wrong part.

Here is what they look like
21:30:14.589441 50:bc:ca:27:92:b1 > 12:34:56:78:9a:bc, ethertype IPv4 (0x0800), length 98: (tos 0x0, ttl 64, id 61326, offset 0, flags [DF], proto ICMP (1), length 84)
    192.168.30.1 > 192.168.30.30: ICMP echo request, id 5937, seq 45, length 64
21:30:15.589958 50:bc:ca:27:92:b1 > 12:34:56:78:9a:bc, ethertype IPv4 (0x0800), length 98: (tos 0x0, ttl 64, id 61379, offset 0, flags [DF], proto ICMP (1), length 84)
    192.168.30.1 > 192.168.30.30: ICMP echo request, id 5937, seq 46, length 64

I'll check for drops and stuff like that in a couple mins and get back to you.

The ping is also not successful, but it depends on the firewall from the host side. It might not be permitted.

1 Like

Yeah, that's my guess. Unfortunately I'm not allowed to change anything on that computer (nor do I even have access to useful logs).

I may not have checked for interface drops, but I may have finally found an indicator for the bug.

doing ip neigh show seems to provide what I need. (and probably a hint toward the actual problem or something)

ip neigh show gives me this when the device was successfully retrieved an IP

192.168.30.30 dev br-lan lladdr 12:34:56:78:9a:bc ref 1 used 0/0/0 probes 1 REACHABLE
192.168.0.1 dev usb0  used 0/0/0 probes 6 FAILED
192.168.0.1 dev wlan0 lladdr d8:07:b6:42:e0:e4 ref 1 used 0/0/0 probes 1 REACHABLE
fe80::5a96:2eb:a0c1:ee25 dev br-lan lladdr 50:bc:ca:27:92:b1 used 0/0/0 probes 0 STALE
fe80::b62f:5a1a:2b6f:d533 dev wlan0 lladdr 00:25:ca:2c:68:23 used 0/0/0 probes 0 STALE

It appears that the entry for 12:34:56:78:9a:bc will be REACHABLE if the computer actually gets the IP.

When it does not, it seems the output is either DELAY or it does not have an entry.

I don't know if this command is reliably right about this, but if it can consistently have that behavior, than I should be able to use it to automatically detect and fix this!

Thanks for all your input!

This command is basically showing the arp table, so the client got the IP from DHCP and successfully advertised it to the network either as an arp reply or gratuitous arp.

My suggestion is to connect there another device, which is under your control, and troubleshoot without restrictions.

2 Likes

Thanks for explaining it for me, I was just gonna research it myself!

I have tested with other devices a while back. I never had issues on windows and almost never had them on linux.

Unfortunately this may be a bug with this device and I don't really have the ability to fix it on that end. That makes identifying and solving it on the OpenWRT side my best option.

Thanks for all of your help!

This topic was automatically closed 10 days after the last reply. New replies are no longer allowed.