nat: stuck in error loop after router restart

[lidel]

Problem

Restarting LAN router breaks uPnP?

Repro

I have a long running node (Kubo 0.34.0-rc1) that had port forwarding set up via nat module.

Once the router in my network got restarted due to unrelated DHCP changes, the go-libp2p in Kubo started logging below error in loop (every 20 seconds):

2025-03-07T16:25:50.397Z	WARN	nat	nat/nat.go:244	failed to establish port mapping: goupnp: error performing SOAP HTTP request: Post "http://192.168.50.1:44902/ctl/IPConn": dial tcp 192.168.50.1:44902: connect: connection refused
2025-03-07T16:25:50.421Z	WARN	nat	nat/nat.go:244	failed to establish port mapping: goupnp: error performing SOAP HTTP request: Post "http://192.168.50.1:44902/ctl/IPConn": dial tcp 192.168.50.1:44902: connect: connection refused
2025-03-07T16:26:10.443Z	WARN	nat	nat/nat.go:244	failed to establish port mapping: goupnp: error performing SOAP HTTP request: Post "http://192.168.50.1:44902/ctl/IPConn": dial tcp 192.168.50.1:44902: connect: connection refused
2025-03-07T16:26:10.466Z	WARN	nat	nat/nat.go:244	failed to establish port mapping: goupnp: error performing SOAP HTTP request: Post "http://192.168.50.1:44902/ctl/IPConn": dial tcp 192.168.50.1:44902: connect: connection refused
2025-03-07T16:26:30.496Z	WARN	nat	nat/nat.go:244	failed to establish port mapping: goupnp: error performing SOAP HTTP request: Post "http://192.168.50.1:44902/ctl/IPConn": dial tcp 192.168.50.1:44902: connect: connection refused
2025-03-07T16:26:30.516Z	WARN	nat	nat/nat.go:244	failed to establish port mapping: goupnp: error performing SOAP HTTP request: Post "http://192.168.50.1:44902/ctl/IPConn": dial tcp 192.168.50.1:44902: connect: connection refused
2025-03-07T16:26:50.533Z	WARN	nat	nat/nat.go:244	failed to establish port mapping: goupnp: error performing SOAP HTTP request: Post "http://192.168.50.1:44902/ctl/IPConn": dial tcp 192.168.50.1:44902: connect: connection refused
2025-03-07T16:26:50.552Z	WARN	nat	nat/nat.go:244	failed to establish port mapping: goupnp: error performing SOAP HTTP request: Post "http://192.168.50.1:44902/ctl/IPConn": dial tcp 192.168.50.1:44902: connect: connection refused

This looks like a gap in our logic, perhaps we should detect when the same :port/ctl/IPConn fails multiple times (indicating the router restarted) and trigger re-discovery to self-heal this?

Version info

• kubo 0.34.0-rc1
  • github.com/libp2p/go-libp2p v0.41.0
    • github.com/huin/goupnp v1.3.0
• Router implementation uses MiniUPnP 2.2.0

[2color]

This might be related to #3154 which was released in github.com/libp2p/go-libp2p v0.41.0, though very unlikely given the scope of changes in that PR.

Is this a new problem you noticed? It might also just be that we now bubble up and log the errors better (thanks to #3154).

[lidel]

I suspect this has always been a problem – router restarts are very rare, so perhaps nobody noticed+reported this before?