NetworkManager errors in system log when using shared connection

  • Done
  • quality assurance status badge
Details
One participant
  • Maxim Cournoyer
Owner
unassigned
Submitted by
Maxim Cournoyer
Severity
normal
M
M
Maxim Cournoyer wrote on 23 Mar 2023 19:37
(name . bug-guix)(address . bug-guix@gnu.org)
87o7oje2kx.fsf@gmail.com
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:

Toggle snippet (46 lines)
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'

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].


--
Thanks,
Maxim
M
M
Maxim Cournoyer wrote on 23 Mar 2023 21:36
(address . 62409@debbugs.gnu.org)
87r0tf2ojm.fsf@gmail.com
Hi,

[...]

Toggle quote (5 lines)
> 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:

Toggle snippet (7 lines)
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)

--
Thanks,
Maxim
M
M
Maxim Cournoyer wrote on 23 Mar 2023 22:12
(address . 62409-done@debbugs.gnu.org)
87o7oj2mui.fsf@gmail.com
Hi,

Maxim Cournoyer <maxim.cournoyer@gmail.com> writes:

Toggle quote (20 lines)
> 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
Closed
?
Your comment

This issue is archived.

To comment on this conversation send an email to 62409@debbugs.gnu.org

To respond to this issue using the mumi CLI, first switch to it
mumi current 62409
Then, you may apply the latest patchset in this issue (with sign off)
mumi am -- -s
Or, compose a reply to this issue
mumi compose
Or, send patches to this issue
mumi send-email *.patch