Can't create a network bridge on 24.10

TrueNAS General
, , ,
1

My VMs could not talk to Truenas, so I discovered I need to create a bridge. Read the Docs, watched several videos. Nothing worked. Turned off services, turned off VMs, stopped apps, unset app pool, rebooted, and tried everything else suggested on the forums. Looks like I’m not alone with this problem.

Symptoms: set my interface (eno1) to static. Rebooted. Removed the alias from eno1 and created a bridge (br0) with the same IP aliased. When settings are tested there is a 60 second blackout and then the web interface returns with reverted network settings. HELP!

System: TrueNAS SCALE ElectricEel 24.10 [release] updated from 24.04. On metal.

Here is the tail of syslog:

Nov 11 16:39:23 truenas systemd-nspawn[3612]: Debian GNU/Linux 12 docker pts/0
Nov 11 16:39:23 truenas systemd-nspawn[3612]:
Nov 11 16:39:28 truenas kernel: Initializing XFRM netlink socket
Nov 11 16:39:29 truenas kernel: br-f59bce655a23: port 1(veth2abdd4b) entered blocking state
Nov 11 16:39:29 truenas kernel: br-f59bce655a23: port 1(veth2abdd4b) entered disabled state
Nov 11 16:39:29 truenas kernel: veth2abdd4b: entered allmulticast mode
Nov 11 16:39:29 truenas kernel: veth2abdd4b: entered promiscuous mode
Nov 11 16:39:29 truenas kernel: br-f59bce655a23: port 1(veth2abdd4b) entered blocking state
Nov 11 16:39:29 truenas kernel: br-f59bce655a23: port 1(veth2abdd4b) entered forwarding state
Nov 11 16:39:29 truenas kernel: br-f59bce655a23: port 1(veth2abdd4b) entered disabled state
Nov 11 16:39:30 truenas kernel: eth0: renamed from veth33dece4
Nov 11 16:39:30 truenas kernel: br-f59bce655a23: port 1(veth2abdd4b) entered blocking state
Nov 11 16:39:30 truenas kernel: br-f59bce655a23: port 1(veth2abdd4b) entered forwarding state
Nov 11 16:40:12 truenas systemd[1]: Starting sysstat-collect.service - system activity accounting tool…
Nov 11 16:40:12 truenas systemd[1]: sysstat-collect.service: Deactivated successfully.
Nov 11 16:40:12 truenas systemd[1]: Finished sysstat-collect.service - system activity accounting tool.
Nov 11 16:45:09 truenas avahi-daemon[3864]: Withdrawing address record for 192.168.1.155 on eno1.
Nov 11 16:45:09 truenas avahi-daemon[3864]: Leaving mDNS multicast group on interface eno1.IPv4 with address 192.168.1.155.
Nov 11 16:45:09 truenas avahi-daemon[3864]: Interface eno1.IPv4 no longer relevant for mDNS.
Nov 11 16:45:09 truenas kernel: br0: port 1(eno1) entered blocking state
Nov 11 16:45:09 truenas kernel: br0: port 1(eno1) entered disabled state
Nov 11 16:45:09 truenas kernel: e1000e 0000:00:19.0 eno1: entered allmulticast mode
Nov 11 16:45:09 truenas kernel: e1000e 0000:00:19.0 eno1: left allmulticast mode
Nov 11 16:45:09 truenas nscd[2662]: 2662 monitored file /etc/resolv.conf was written to
Nov 11 16:49:09 truenas avahi-daemon[3864]: Joining mDNS multicast group on interface eno1.IPv4 with address 192.168.1.155.
Nov 11 16:49:09 truenas avahi-daemon[3864]: New relevant interface eno1.IPv4 for mDNS.
Nov 11 16:49:09 truenas avahi-daemon[3864]: Registering new address record for 192.168.1.155 on eno1.IPv4.
Nov 11 16:49:09 truenas nscd[2662]: 2662 monitored file /etc/resolv.conf was written to
Nov 11 16:49:25 truenas systemd[1]: Created slice user-950.slice - User Slice of UID 950.
Nov 11 16:49:25 truenas systemd[1]: Starting user-runtime-dir@950.service - User Runtime Directory /run/user/950…
Nov 11 16:49:25 truenas systemd[1]: Finished user-runtime-dir@950.service - User Runtime Directory /run/user/950.
Nov 11 16:49:25 truenas systemd[1]: Starting user@950.service - User Manager for UID 950…
Nov 11 16:49:25 truenas systemd-xdg-autostart-generator[7201]: Exec binary ‘/usr/libexec/at-spi-bus-launcher’ does not exist: No such file or directory
Nov 11 16:49:25 truenas systemd-xdg-autostart-generator[7201]: /etc/xdg/autostart/at-spi-dbus-bus.desktop: not generating unit, executable specified in Exec= does not exist.
Nov 11 16:49:26 truenas systemd[7187]: Queued start job for default target default.target.
Nov 11 16:49:26 truenas systemd[7187]: Created slice app.slice - User Application Slice.
Nov 11 16:49:26 truenas systemd[7187]: Reached target paths.target - Paths.
Nov 11 16:49:26 truenas systemd[7187]: Reached target timers.target - Timers.
Nov 11 16:49:26 truenas systemd[7187]: Starting dbus.socket - D-Bus User Message Bus Socket…
Nov 11 16:49:26 truenas systemd[7187]: Listening on gpg-agent-browser.socket - GnuPG cryptographic agent and passphrase cache (access for web browsers).
Nov 11 16:49:26 truenas systemd[7187]: Listening on gpg-agent-extra.socket - GnuPG cryptographic agent and passphrase cache (restricted).
Nov 11 16:49:26 truenas systemd[7187]: Listening on gpg-agent-ssh.socket - GnuPG cryptographic agent (ssh-agent emulation).
Nov 11 16:49:26 truenas systemd[7187]: Listening on gpg-agent.socket - GnuPG cryptographic agent and passphrase cache.
Nov 11 16:49:26 truenas systemd[7187]: Listening on gssuserproxy.socket - GSS User Proxy.
Nov 11 16:49:26 truenas systemd[7187]: Listening on dbus.socket - D-Bus User Message Bus Socket.
Nov 11 16:49:26 truenas systemd[7187]: Reached target sockets.target - Sockets.
Nov 11 16:49:26 truenas systemd[7187]: Reached target basic.target - Basic System.
Nov 11 16:49:26 truenas systemd[7187]: Reached target default.target - Main User Target.
Nov 11 16:49:26 truenas systemd[7187]: Startup finished in 164ms.
Nov 11 16:49:26 truenas systemd[1]: Started user@950.service - User Manager for UID 950.
Nov 11 16:49:26 truenas systemd[1]: Started session-1.scope - Session 1 of User admin.
Nov 11 16:50:06 truenas systemd[1]: Starting sysstat-collect.service - system activity accounting tool…
Nov 11 16:50:06 truenas systemd[1]: sysstat-collect.service: Deactivated successfully.
Nov 11 16:50:06 truenas systemd[1]: Finished sysstat-collect.service - system activity accounting tool.

Messages:

Nov 11 16:39:12 truenas kernel: kvm_intel: L1TF CPU bug present and SMT on, data leak possible. See CVE-2018-3646 and [http link removed] for details.
Nov 11 16:39:12 truenas kernel: bridge: filtering via arp/ip/ip6tables is no longer available by default. Update your scripts to load br_netfilter if you need this.
Nov 11 16:39:12 truenas kernel: Bridge firewalling registered
Nov 11 16:39:28 truenas kernel: Initializing XFRM netlink socket
Nov 11 16:39:29 truenas kernel: br-f59bce655a23: port 1(veth2abdd4b) entered blocking state
Nov 11 16:39:29 truenas kernel: br-f59bce655a23: port 1(veth2abdd4b) entered disabled state
Nov 11 16:39:29 truenas kernel: veth2abdd4b: entered allmulticast mode
Nov 11 16:39:29 truenas kernel: veth2abdd4b: entered promiscuous mode
Nov 11 16:39:29 truenas kernel: br-f59bce655a23: port 1(veth2abdd4b) entered blocking state
Nov 11 16:39:29 truenas kernel: br-f59bce655a23: port 1(veth2abdd4b) entered forwarding state
Nov 11 16:39:29 truenas kernel: br-f59bce655a23: port 1(veth2abdd4b) entered disabled state
Nov 11 16:39:30 truenas kernel: eth0: renamed from veth33dece4
Nov 11 16:39:30 truenas kernel: br-f59bce655a23: port 1(veth2abdd4b) entered blocking state
Nov 11 16:39:30 truenas kernel: br-f59bce655a23: port 1(veth2abdd4b) entered forwarding state
Nov 11 16:45:09 truenas kernel: br0: port 1(eno1) entered blocking state
Nov 11 16:45:09 truenas kernel: br0: port 1(eno1) entered disabled state
Nov 11 16:45:09 truenas kernel: e1000e 0000:00:19.0 eno1: entered allmulticast mode
Nov 11 16:45:09 truenas kernel: e1000e 0000:00:19.0 eno1: left allmulticast mode

WSDD.log

ERROR: error in main loop
Traceback (most recent call last):
File “/usr/bin/wsdd.py”, line 1742, in main
key.data.handle_request()
File “/usr/bin/wsdd.py”, line 1286, in handle_request
self.handle_new_address(addr, ifa_family, iface)
File “/usr/bin/wsdd.py”, line 1090, in handle_new_address
mch = MulticastHandler(addr_family, addr, interface, self.selector)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File “/usr/bin/wsdd.py”, line 79, in init
self.init_v4()
File “/usr/bin/wsdd.py”, line 173, in init_v4
self.uc_send_socket.bind((self.address, WSD_UDP_PORT))
OSError: [Errno 98] Address already in use

2

Also from middlewared.log

[2024/11/11 17:34:16] (DEBUG) UsageService.start():63 - Scheduled next run in 1890 seconds
[2024/11/11 18:05:47] (DEBUG) UsageService.start():63 - Scheduled next run in 98085 seconds
[2024/11/11 19:20:40] (ERROR) middlewared.reader():708 - Error in ShellWorkerThread.reader
Traceback (most recent call last):
File “/usr/lib/python3/dist-packages/middlewared/main.py”, line 706, in reader
).result()
^^^^^^^^
File “/usr/lib/python3.11/concurrent/futures/_base.py”, line 456, in result
return self.__get_result()
^^^^^^^^^^^^^^^^^^^
File “/usr/lib/python3.11/concurrent/futures/_base.py”, line 401, in __get_result
raise self._exception
File “/usr/lib/python3/dist-packages/aiohttp/web_ws.py”, line 315, in send_bytes
await self._writer.send(data, binary=True, compress=compress)
File “/usr/lib/python3/dist-packages/aiohttp/http_websocket.py”, line 688, in send
await self._send_frame(message, WSMsgType.BINARY, compress)
File “/usr/lib/python3/dist-packages/aiohttp/http_websocket.py”, line 601, in _send_frame
raise ConnectionResetError(“Cannot write to closing transport”)
ConnectionResetError: Cannot write to closing transport
[2024/11/11 21:20:46] (INFO) InterfaceService.configure():20 - Configuring interface ‘eno1’
[2024/11/11 21:20:46] (DEBUG) InterfaceService.configure():78 - eno1: removing 192.168.1.155/255.255.255.0
[2024/11/11 21:20:46] (INFO) InterfaceService.bridge_setup():20 - Setting up ‘br0’
[2024/11/11 21:20:46] (INFO) InterfaceService.bridge_setup():41 - Adding member interface ‘eno1’ to ‘br0’
[2024/11/11 21:20:46] (ERROR) InterfaceService.sync():1724 - Error setting up bridge br0
Traceback (most recent call last):
File “/usr/lib/python3/dist-packages/middlewared/plugins/network.py”, line 1722, in sync
await self.middleware.call(‘interface.bridge_setup’, bridge, parent_interfaces)
File “/usr/lib/python3/dist-packages/middlewared/main.py”, line 1626, in call
return await self._call(
^^^^^^^^^^^^^^^^^
File “/usr/lib/python3/dist-packages/middlewared/main.py”, line 1468, in _call
return await self.run_in_executor(prepared_call.executor, methodobj, *prepared_call.args)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File “/usr/lib/python3/dist-packages/middlewared/main.py”, line 1361, in run_in_executor
return await loop.run_in_executor(pool, functools.partial(method, *args, **kwargs))
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File “/usr/lib/python3.11/concurrent/futures/thread.py”, line 58, in run
result = self.fn(*self.args, **self.kwargs)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File “/usr/lib/python3/dist-packages/middlewared/plugins/interface/bridge.py”, line 42, in bridge_setup
iface.add_member(member)
File “/usr/lib/python3/dist-packages/middlewared/plugins/interface/netif_linux/bridge.py”, line 19, in add_member
run([“ip”, “link”, “set”, name, “master”, self.name])
File “/usr/lib/python3/dist-packages/middlewared/plugins/interface/netif_linux/utils.py”, line 24, in run
return subprocess.run(*args, **kwargs)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File “/usr/lib/python3.11/subprocess.py”, line 571, in run
raise CalledProcessError(retcode, process.args,
subprocess.CalledProcessError: Command ‘[‘ip’, ‘link’, ‘set’, ‘eno1’, ‘master’, ‘br0’]’ returned non-zero exit status 2.
[2024/11/11 21:20:46] (INFO) InterfaceService.configure():20 - Configuring interface ‘br0’
[2024/11/11 21:20:46] (DEBUG) InterfaceService.run_dhcp():1830 - Starting dhclient for br0
[2024/11/11 21:20:46] (INFO) InterfaceService.sync():1740 - Interfaces in database: eno1, br0
[2024/11/11 21:20:46] (INFO) RouteService.sync():83 - Adding IPv4 default route to 192.168.1.1
[2024/11/11 21:20:46] (ERROR) RouteService.sync():105 - Failed adding 192.168.1.1 as default gateway: NetlinkError(101, ‘Network is unreachable’)
[2024/11/11 21:24:46] (INFO) InterfaceService.configure():20 - Configuring interface ‘eno1’
[2024/11/11 21:24:46] (DEBUG) InterfaceService.configure():99 - eno1: adding 192.168.1.155/255.255.255.0
[2024/11/11 21:24:46] (INFO) InterfaceService.sync():1740 - Interfaces in database: eno1
[2024/11/11 21:24:46] (INFO) InterfaceService.unconfigure():138 - Unconfiguring interface ‘br0’
[2024/11/11 21:24:46] (INFO) RouteService.sync():83 - Adding IPv4 default route to 192.168.1.1

3

This bit here looks like it might be a bug, you should open a bug ticket.

To work around it, do you have a second NIC you can use for now? If you attach your VMs to a NIC that doesn’t have an IP address configured on the TrueNAS you can work around the problem. This topology might also be better if you are already bandwidth constrained, but it largely depends on the workload of the vms.

e.g.

Screenshot 2024-11-12 at 12.57.58 AM
Screenshot 2024-11-12 at 12.57.58 AM1306×692 24.9 KB

Screenshot 2024-11-12 at 12.58.13 AM
Screenshot 2024-11-12 at 12.58.13 AM826×842 28.3 KB

4

Remove the static configuration from eno1 and put it on the bridge br0.

5

Thanks. I thought the same thing when I saw this log. I did open a ticket last night. No second NIC here. :frowning_face:

6

That’s exactly what I did - as the part you quoted says.

7

image
image1733×925 45.8 KB

I just wanted to add this in case it looks wrong. Is it?

8

Well, Nevermind I guess.

I was going to try something today, and it just worked this time (luck 57th try)

1 Like