[BUG] RPi5 connman stops sending DHCP renewals

[buzz-tee]

Describe the bug

LE 12.0.1 looses it's DHCP lease but keeps the IP address thus causing IP address conflicts when the same IP address is issued by the DHCP server through a new lease.

How to reproduce

Steps to reproduce the behavior:

1. Startup with wired networking (wireless is disabled here)
2. Wait, in my DHCP server logs I can trace two occurrences where it took 20 hours one time and 12 hours the other time for the bug to trigger
3. Lease expires (TTL here is 1h) but LE still uses the IP address

Information

• LibreELEC Version: 12.0.1
• Hardware Platform: RPi5

Log file

journalctl -u connman.service once lease renewal stops working (last DHCPREQUEST was seen at 12:50:13, expiry at 13:50:13):

Oct 05 10:49:36 kodi2 connmand[855407]: ntp: adjust (slew): +0.000159 sec
Oct 05 10:50:08 kodi2 connmand[855407]: ntp: adjust (slew): +0.000598 sec
Oct 05 11:07:12 kodi2 connmand[855407]: ntp: adjust (slew): +0.000088 sec
Oct 05 11:24:16 kodi2 connmand[855407]: ntp: adjust (slew): -0.000127 sec
Oct 05 11:41:20 kodi2 connmand[855407]: ntp: adjust (slew): +0.000100 sec
Oct 05 11:58:24 kodi2 connmand[855407]: ntp: adjust (slew): -0.000026 sec
Oct 05 12:05:08 kodi2 connmand[855407]: Cannot create /run/connman/resolv.conf falling back to /etc/resolv.conf
Oct 05 12:05:08 kodi2 connmand[855407]: connman_inet_clear_address: Too many open files
Oct 05 12:05:08 kodi2 connmand[855407]: Deleting host route failed (Too many open files)
Oct 05 12:05:08 kodi2 connmand[855407]: Removing default gateway route failed (Too many open files)
Oct 05 12:15:28 kodi2 connmand[855407]: ntp: adjust (slew): +0.000016 sec
Oct 05 12:32:32 kodi2 connmand[855407]: ntp: adjust (slew): -0.000074 sec
Oct 05 12:49:36 kodi2 connmand[855407]: ntp: adjust (slew): +0.000164 sec
Oct 05 12:50:08 kodi2 connmand[855407]: ntp: adjust (slew): +0.001000 sec
Oct 05 12:50:13 kodi2 connmand[855407]: rp_filter set to 2 (loose mode routing), old value was 0
Oct 05 13:07:12 kodi2 connmand[855407]: ntp: adjust (slew): +0.000217 sec
Oct 05 13:24:16 kodi2 connmand[855407]: ntp: adjust (slew): -0.000209 sec
Oct 05 13:41:20 kodi2 connmand[855407]: ntp: adjust (slew): -0.000264 sec
Oct 05 13:50:13 kodi2 connmand[855407]: connman_inet_clear_address: Too many open files
Oct 05 13:58:24 kodi2 connmand[855407]: ntp: adjust (slew): +0.000270 sec
Oct 05 14:15:28 kodi2 connmand[855407]: ntp: adjust (slew): -0.000304 sec
Oct 05 14:32:32 kodi2 connmand[855407]: ntp: adjust (slew): -0.000015 sec
Oct 05 14:49:36 kodi2 connmand[855407]: ntp: adjust (slew): +0.000089 sec
Oct 05 14:50:08 kodi2 connmand[855407]: ntp: adjust (slew): -0.000787 sec
Oct 05 15:07:12 kodi2 connmand[855407]: ntp: adjust (slew): +0.000291 sec
Oct 05 15:24:16 kodi2 connmand[855407]: ntp: adjust (slew): +0.000064 sec

journalctl -u connman.service after service starts:

Oct 05 15:56:43 kodi2 systemd[1]: Starting connman.service...
Oct 05 15:56:43 kodi2 systemd[1]: Started connman.service.
Oct 05 15:56:43 kodi2 connmand[1245014]: Connection Manager version 1.42
Oct 05 15:56:43 kodi2 connmand[1245014]: Checking loopback interface settings
Oct 05 15:56:43 kodi2 connmand[1245014]: System hostname is kodi2
Oct 05 15:56:43 kodi2 connmand[1245014]: System domainname is my.lan.
Oct 05 15:56:43 kodi2 connmand[1245014]: lo {newlink} index 1 address 00:00:00:00:00:00 mtu 65536
Oct 05 15:56:43 kodi2 connmand[1245014]: lo {newlink} index 1 operstate 0 <UNKNOWN>
Oct 05 15:56:43 kodi2 connmand[1245014]: eth0 {create} index 2 type 1 <ETHER>
Oct 05 15:56:43 kodi2 connmand[1245014]: eth0 {RX} 5785441 packets 3595855695 bytes
Oct 05 15:56:43 kodi2 connmand[1245014]: eth0 {TX} 2494306 packets 175161509 bytes
Oct 05 15:56:43 kodi2 connmand[1245014]: eth0 {update} flags 36866 <DOWN>
Oct 05 15:56:43 kodi2 connmand[1245014]: eth0 {newlink} index 2 address 2C:CF:67:06:03:B9 mtu 1500
Oct 05 15:56:43 kodi2 connmand[1245014]: eth0 {newlink} index 2 operstate 2 <DOWN>
Oct 05 15:56:43 kodi2 connmand[1245014]: Adding interface eth0 [ ethernet ]
Oct 05 15:56:43 kodi2 connmand[1245014]: eth0 {RX} 5785441 packets 3595855695 bytes
Oct 05 15:56:43 kodi2 connmand[1245014]: eth0 {TX} 2494306 packets 175161509 bytes
Oct 05 15:56:43 kodi2 connmand[1245014]: eth0 {update} flags 36867 <UP>
Oct 05 15:56:43 kodi2 connmand[1245014]: eth0 {newlink} index 2 address 2C:CF:67:06:03:B9 mtu 1500
Oct 05 15:56:43 kodi2 connmand[1245014]: eth0 {newlink} index 2 operstate 2 <DOWN>
Oct 05 15:56:48 kodi2 connmand[1245014]: eth0 {add} route fe80:: gw :: scope 0 <UNIVERSE>
Oct 05 15:56:48 kodi2 connmand[1245014]: eth0 {RX} 5785441 packets 3595855695 bytes
Oct 05 15:56:48 kodi2 connmand[1245014]: eth0 {TX} 2494306 packets 175161509 bytes
Oct 05 15:56:48 kodi2 connmand[1245014]: eth0 {update} flags 102467 <UP,RUNNING,LOWER_UP>
Oct 05 15:56:48 kodi2 connmand[1245014]: eth0 {newlink} index 2 address 2C:CF:67:06:03:B9 mtu 1500
Oct 05 15:56:48 kodi2 connmand[1245014]: eth0 {newlink} index 2 operstate 6 <UP>
Oct 05 15:56:48 kodi2 connmand[1245014]: ipconfig state 3 ipconfig method 1
Oct 05 15:56:48 kodi2 connmand[1245014]: eth0 {del} route fe80:: gw :: scope 0 <UNIVERSE>
Oct 05 15:56:53 kodi2 connmand[1245014]: Setting domainname to my.lan.
Oct 05 15:56:53 kodi2 connmand[1245014]: eth0 {add} address 172.16.1.21/20 label eth0 family 2
Oct 05 15:56:53 kodi2 connmand[1245014]: eth0 {add} route 172.16.0.0 gw 0.0.0.0 scope 253 <LINK>
Oct 05 15:56:53 kodi2 connmand[1245014]: eth0 {add} route 172.16.0.1 gw 0.0.0.0 scope 253 <LINK>
Oct 05 15:56:53 kodi2 connmand[1245014]: eth0 {add} route 172.16.246.19 gw 172.16.0.1 scope 0 <UNIVERSE>
Oct 05 15:56:53 kodi2 connmand[1245014]: eth0 {add} route 172.16.246.20 gw 172.16.0.1 scope 0 <UNIVERSE>
Oct 05 15:56:53 kodi2 connmand[1245014]: eth0 {add} route 172.16.246.21 gw 172.16.0.1 scope 0 <UNIVERSE>
Oct 05 15:56:53 kodi2 connmand[1245014]: eth0 {add} route 0.0.0.0 gw 172.16.0.1 scope 0 <UNIVERSE>
Oct 05 15:56:53 kodi2 connmand[1245014]: eth0 {add} route 82.165.8.211 gw 172.16.0.1 scope 0 <UNIVERSE>
Oct 05 15:56:53 kodi2 connmand[1245014]: ntp: adjust (slew): +0.003909 sec
Oct 05 15:56:53 kodi2 connmand[1245014]: eth0 {del} route 82.165.8.211 gw 172.16.0.1 scope 0 <UNIVERSE>

Context

According to lsof connmand is cummulating sockets, netstat shows too many connections to DNS servers in state established (70 after 30 minutes, numbers increasing) and my DNS server logs show loads and loads of reverse lookups (for LE's own IP and for the resolvers' IP addresses).

I upgraded from latest stable LE 11 on RPi4 to a fresh install on RPi5. I never had any DHCP issues on the old platform.

[mglae]

Connman was updated for LE12 please test a recent LE12 nightly from https://test.libreelec.tv (latest builds are listed at end of page).