Subject: bug#62409: closed (Re: bug#62409: NetworkManager errors in system log when using shared connection)

From: [email-masked] (GNU bug Tracking System)
Date: Thu, 23 Mar 2023 21:14:02 +0000

Your bug report

#62409: NetworkManager errors in system log when using shared connection

which was filed against the guix package, has been closed.

The explanation is attached below, along with your original report.
If you require more details, please reply to [email-masked].

-- 
62409: https://debbugs.gnu.org/cgi/bugreport.cgi?bug=62409
GNU Bug Tracking System
Contact [email-masked] with problems

Subject: Re: bug#62409: NetworkManager errors in system log when using shared connection
From: Maxim Cournoyer <[email-masked]>
To: [email-masked]
Date: Thu, 23 Mar 2023 17:12:53 -0400
List-Id: <debbugs-submit.debbugs.gnu.org>

Hi,

Maxim Cournoyer <[email-masked]> writes:

> Hi,
>
> [...]
>
>> This gets repeated spuriously in /var/log/messages.  There's at least a
>> problem with /sbin/modprobe not being looked at the right place.
>> Interestingly, it also seems to trigger a crash in Jami, which does some
>> connection refreshing work on events from NetworkManager [0].
>
> I tried patching the /sbin/modprobe reference to kmod's bin/modprobe,
> but I now get:
>
> --8<---------------cut here---------------start------------->8--- Mar 23
> 16:34:02 localhost NetworkManager[404]: <error> [1679603642.2656]
> modprobe:
> '/gnu/store/liq8rjgfwaa80mrmm0lq1kq7wbh7xb6l-kmod-29/bin/modprobe
> --use-blacklist ip_tables' exited with error 256 (modprobe: FATAL:
> Module ip_tables not found in directory /lib/modules/5.15.103-gnu)
> --8<---------------cut here---------------end--------------->8---

Fixed with:

ef71e32909 origin/master services: network-manager: Set LINUX_MODULE_DIRECTORY environment variable.
e682932636 gnu: network-manager: Patch modprobe file name.

Closing!

-- 
Thanks,
Maxim

Subject: NetworkManager errors in system log when using shared connection
From: Maxim Cournoyer <[email-masked]>
To: bug-guix <[email-masked]>
Date: Thu, 23 Mar 2023 14:37:34 -0400
List-Id: <debbugs-submit.debbugs.gnu.org>

Hi,

I have setup a 'share connection with other computers' type of
connection in NetworkManager, via 'sudo -E nm-connection-editor', and it
works, e.g. to allow a device connected to my 2nd Ethernet port to get a
dynamic IP address and have access to the Internet, but, in
/var/log/messages, I see:

--8<---------------cut here---------------start------------->8---

Mar 23 14:27:32 localhost NetworkManager[6477]: <info>  [1679596052.2463] policy: auto-activating connection 'shared' (668d9954-eac2-30da-8fc0-d986ab01a36c)
Mar 23 14:27:32 localhost NetworkManager[6477]: <info>  [1679596052.2500] device (enp4s0): Activation: starting connection 'shared' (668d9954-eac2-30da-8fc0-d986ab01a36c)
Mar 23 14:27:32 localhost NetworkManager[6477]: <info>  [1679596052.2504] device (enp4s0): state change: disconnected -> prepare (reason 'none', sys-iface-state: 'managed')
Mar 23 14:27:32 localhost NetworkManager[6477]: <info>  [1679596052.2512] device (enp4s0): state change: prepare -> config (reason 'none', sys-iface-state: 'managed')
Mar 23 14:27:32 localhost NetworkManager[6477]: <info>  [1679596052.2604] device (enp4s0): state change: config -> ip-config (reason 'none', sys-iface-state: 'managed')
Mar 23 14:27:32 localhost NetworkManager[6477]: <error> [1679596052.2739] modprobe: '/sbin/modprobe --use-blacklist ip_tables' failed: Failed to execute child process “/sbin/modprobe” (No such file or directory)
Mar 23 14:27:32 localhost NetworkManager[6477]: <error> [1679596052.2784] modprobe: '/sbin/modprobe --use-blacklist iptable_nat' failed: Failed to execute child process “/sbin/modprobe” (No such file or directory)
Mar 23 14:27:32 localhost NetworkManager[6477]: <warn>  [1679596052.2887] iptables: command /gnu/store/xz1arf5cd7ssck431wmfz5y1kgr5vyir-iptables-1.8.7/sbin/iptables failed: Child process exited with code 1
Mar 23 14:27:32 localhost NetworkManager[6477]: <warn>  [1679596052.3429] iptables: command /gnu/store/xz1arf5cd7ssck431wmfz5y1kgr5vyir-iptables-1.8.7/sbin/iptables failed: Child process exited with code 1
Mar 23 14:27:32 localhost NetworkManager[6477]: <warn>  [1679596052.3636] iptables: command /gnu/store/xz1arf5cd7ssck431wmfz5y1kgr5vyir-iptables-1.8.7/sbin/iptables failed: Child process exited with code 1
Mar 23 14:27:32 localhost NetworkManager[6477]: <warn>  [1679596052.5165] iptables: command /gnu/store/xz1arf5cd7ssck431wmfz5y1kgr5vyir-iptables-1.8.7/sbin/iptables failed: Child process exited with code 1
Mar 23 14:27:32 localhost dbus-daemon[407]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
Mar 23 14:27:32 localhost NetworkManager[6477]: <warn>  [1679596052.5767] iptables: command /gnu/store/xz1arf5cd7ssck431wmfz5y1kgr5vyir-iptables-1.8.7/sbin/iptables failed: Child process exited with code 1
Mar 23 14:27:32 localhost NetworkManager[6477]: <warn>  [1679596052.5817] iptables: command /gnu/store/xz1arf5cd7ssck431wmfz5y1kgr5vyir-iptables-1.8.7/sbin/iptables failed: Child process exited with code 1
Mar 23 14:27:32 localhost NetworkManager[6477]: <info>  [1679596052.6717] dnsmasq-manager: starting dnsmasq...
Mar 23 14:27:32 localhost avahi-daemon[6618]: Joining mDNS multicast group on interface enp4s0.IPv4 with address 10.42.0.1.
Mar 23 14:27:32 localhost avahi-daemon[6618]: New relevant interface enp4s0.IPv4 for mDNS.
Mar 23 14:27:32 localhost avahi-daemon[6618]: Registering new address record for 10.42.0.1 on enp4s0.IPv4.
Mar 23 14:27:32 localhost NetworkManager[6477]: <info>  [1679596052.7182] device (enp4s0): state change: ip-config -> ip-check (reason 'none', sys-iface-state: 'managed')
Mar 23 14:27:32 localhost avahi-daemon[6618]: Joining mDNS multicast group on interface enp4s0.IPv6 with address fe80::f7c4:97a9:80a1:ae41.
Mar 23 14:27:32 localhost avahi-daemon[6618]: New relevant interface enp4s0.IPv6 for mDNS.
Mar 23 14:27:32 localhost avahi-daemon[6618]: Registering new address record for fe80::f7c4:97a9:80a1:ae41 on enp4s0.*.
Mar 23 14:27:32 localhost NetworkManager[6477]: <info>  [1679596052.7282] device (enp4s0): state change: ip-check -> secondaries (reason 'none', sys-iface-state: 'managed')
Mar 23 14:27:32 localhost NetworkManager[6477]: <info>  [1679596052.7289] device (enp4s0): state change: secondaries -> activated (reason 'none', sys-iface-state: 'managed')
Mar 23 14:27:32 localhost NetworkManager[6477]: <info>  [1679596052.7325] device (enp4s0): Activation: successful, device activated.
Mar 23 14:27:32 localhost dnsmasq[3868]: failed to create listening socket for 10.42.0.1: Address already in use
Mar 23 14:27:32 localhost dnsmasq[3868]: FAILED to start up
Mar 23 14:27:32 localhost NetworkManager[6477]: <warn>  [1679596052.7926] dnsmasq-manager: dnsmasq exited with error: Network access problem (address in use, permissions) (2)
Mar 23 14:27:32 localhost shepherd[1]: [NetworkManager]  
Mar 23 14:27:32 localhost shepherd[1]: [NetworkManager] dnsmasq: failed to create listening socket for 10.42.0.1: Address already in use 
Mar 23 14:28:03 localhost NetworkManager[6477]: <info>  [1679596083.7771] device (enp4s0): state change: activated -> failed (reason 'ip-config-unavailable', sys-iface-state: 'managed')
Mar 23 14:28:03 localhost NetworkManager[6477]: <warn>  [1679596083.7848] device (enp4s0): Activation: failed for connection 'shared'
Mar 23 14:28:03 localhost NetworkManager[6477]: <info>  [1679596083.7866] device (enp4s0): state change: failed -> disconnected (reason 'none', sys-iface-state: 'managed')
Mar 23 14:28:03 localhost dbus-daemon[407]: [system] Activating service name='org.freedesktop.nm_dispatcher' requested by ':1.20936' (uid=0 pid=6477 comm="/gnu/store/aby04j5i1bzfgm6hzjb6qcqwz9f1lcfn-networ") (using servicehelper)
Mar 23 14:28:03 localhost avahi-daemon[6618]: Withdrawing address record for fe80::f7c4:97a9:80a1:ae41 on enp4s0.
Mar 23 14:28:03 localhost avahi-daemon[6618]: Leaving mDNS multicast group on interface enp4s0.IPv6 with address fe80::f7c4:97a9:80a1:ae41.
Mar 23 14:28:03 localhost avahi-daemon[6618]: Interface enp4s0.IPv6 no longer relevant for mDNS.
Mar 23 14:28:03 localhost NetworkManager[6477]: <warn>  [1679596083.8939] iptables: command /gnu/store/xz1arf5cd7ssck431wmfz5y1kgr5vyir-iptables-1.8.7/sbin/iptables failed: Child process exited with code 1
Mar 23 14:28:03 localhost NetworkManager[6477]: <warn>  [1679596083.9044] iptables: command /gnu/store/xz1arf5cd7ssck431wmfz5y1kgr5vyir-iptables-1.8.7/sbin/iptables failed: Child process exited with code 1
Mar 23 14:28:03 localhost avahi-daemon[6618]: Withdrawing address record for 10.42.0.1 on enp4s0.
Mar 23 14:28:03 localhost avahi-daemon[6618]: Leaving mDNS multicast group on interface enp4s0.IPv4 with address 10.42.0.1.
Mar 23 14:28:03 localhost avahi-daemon[6618]: Interface enp4s0.IPv4 no longer relevant for mDNS.
Mar 23 14:28:03 localhost dbus-daemon[407]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
--8<---------------cut here---------------end--------------->8---

This gets repeated spuriously in /var/log/messages.  There's at least a
problem with /sbin/modprobe not being looked at the right place.
Interestingly, it also seems to trigger a crash in Jami, which does some
connection refreshing work on events from NetworkManager [0].

[0]  https://git.jami.net/savoirfairelinux/jami-client-qt/-/issues/1044

-- 
Thanks,
Maxim