after upgrading to Jammy and maas 3.3.4 rackd is failing with the following stacktrace

Bug #2030781 reported by Heather Lemon
12
This bug affects 2 people
Affects Status Importance Assigned to Milestone
MAAS
Triaged
Undecided
Unassigned

Bug Description

After upgrading to jammy and maas 3.3.4 rackd is throwing a stacktrace.

using debian package version/build 3.3.4-13189-g.f88272d1e-0ubuntu1~22.04.1

Jul 30 00:00:19 infra-2 sh[1611]: #011Traceback (most recent call last):
Jul 30 00:00:19 infra-2 sh[1611]: #011Failure: twisted.internet.error.MulticastJoinError: (b'\xe0\x00\x00v', b'\nN\x0c\x0c', 98, 'Address already in use')
Jul 30 00:00:19 infra-2 sh[1611]: #011
Jul 30 00:00:19 infra-2 sh[1611]: 2023-07-30 00:00:19 twisted.internet.defer: [critical] Unhandled error in Deferred:
Jul 30 00:00:19 infra-2 sh[1611]: 2023-07-30 00:00:19 twisted.internet.defer: [critical]
Jul 30 00:00:19 infra-2 sh[1611]: #011Traceback (most recent call last):
Jul 30 00:00:19 infra-2 sh[1611]: #011Failure: twisted.internet.error.MulticastJoinError: (b'\xe0\x00\x00v', b'\nd-\x0c', 98, 'Address already in use')

Jul 30 01:31:46 infra-2 sh[1588]: 2023-07-30 01:31:46 RegionServer,3237,::ffff:10.100.45.11: [info] RegionServer connection lost (HOST:IPv6Address(type='TCP', host='::ffff:10.100.45.12', port=5251, flowInfo=0, scopeID=0) PEER:IPv6Address(type='TCP', host='::ffff:10.100.45.11', port=35660, flowInfo=0, scopeID=0))
Jul 30 01:31:46 infra-2 sh[1588]: 2023-07-30 01:31:46 maasserver.ipc: [info] Worker pid:4138 lost RPC connection to ('6d4nq6', '10.100.45.12', 5251).
Jul 30 01:31:49 infra-2 sh[1611]: 2023-07-30 01:31:49 provisioningserver.utils.services: [critical] Failed to update and/or record network interface configuration: Expecting value: line 1 column 1 (char 0); interfaces: {'bondM': {<omitted for brevity..}
Jul 30 01:31:49 infra-2 sh[1611]: #011Traceback (most recent call last):
Jul 30 01:31:49 infra-2 sh[1611]: #011 File "/usr/lib/python3/dist-packages/twisted/internet/defer.py", line 857, in _runCallbacks
Jul 30 01:31:49 infra-2 sh[1611]: #011 current.result = callback( # type: ignore[misc]
Jul 30 01:31:49 infra-2 sh[1611]: #011 File "/usr/lib/python3/dist-packages/twisted/internet/defer.py", line 1750, in gotResult
Jul 30 01:31:49 infra-2 sh[1611]: #011 current_context.run(_inlineCallbacks, r, gen, status)
Jul 30 01:31:49 infra-2 sh[1611]: #011 File "/usr/lib/python3/dist-packages/twisted/internet/defer.py", line 1656, in _inlineCallbacks
Jul 30 01:31:49 infra-2 sh[1611]: #011 result = current_context.run(
Jul 30 01:31:49 infra-2 sh[1611]: #011 File "/usr/lib/python3/dist-packages/twisted/python/failure.py", line 489, in throwExceptionIntoGenerator
Jul 30 01:31:49 infra-2 sh[1611]: #011 return g.throw(self.type, self.value, self.tb)
Jul 30 01:31:49 infra-2 sh[1611]: #011--- <exception caught here> ---
Jul 30 01:31:49 infra-2 sh[1611]: #011 File "/usr/lib/python3/dist-packages/provisioningserver/utils/services.py", line 1092, in do_action
Jul 30 01:31:49 infra-2 sh[1611]: #011 yield self._updateInterfaces(interfaces)
Jul 30 01:31:49 infra-2 sh[1611]: #011 File "/usr/lib/python3/dist-packages/twisted/internet/defer.py", line 1656, in _inlineCallbacks
Jul 30 01:31:49 infra-2 sh[1611]: #011 result = current_context.run(
Jul 30 01:31:49 infra-2 sh[1611]: #011 File "/usr/lib/python3/dist-packages/twisted/python/failure.py", line 489, in throwExceptionIntoGenerator
Jul 30 01:31:49 infra-2 sh[1611]: #011 return g.throw(self.type, self.value, self.tb)
Jul 30 01:31:49 infra-2 sh[1611]: #011 File "/usr/lib/python3/dist-packages/provisioningserver/utils/services.py", line 1176, in _updateInterfaces
Jul 30 01:31:49 infra-2 sh[1611]: #011 yield self._run_refresh(
Jul 30 01:31:49 infra-2 sh[1611]: #011 File "/usr/lib/python3/dist-packages/twisted/internet/defer.py", line 1656, in _inlineCallbacks
Jul 30 01:31:49 infra-2 sh[1611]: #011 result = current_context.run(
Jul 30 01:31:49 infra-2 sh[1611]: #011 File "/usr/lib/python3/dist-packages/twisted/python/failure.py", line 489, in throwExceptionIntoGenerator
Jul 30 01:31:49 infra-2 sh[1611]: #011 return g.throw(self.type, self.value, self.tb)
Jul 30 01:31:49 infra-2 sh[1611]: #011 File "/usr/lib/python3/dist-packages/provisioningserver/utils/services.py", line 1208, in _run_refresh
Jul 30 01:31:49 infra-2 sh[1611]: #011 yield deferToThread(
Jul 30 01:31:49 infra-2 sh[1611]: #011 File "/usr/lib/python3/dist-packages/twisted/python/threadpool.py", line 244, in inContext
Jul 30 01:31:49 infra-2 sh[1611]: #011 result = inContext.theWork() # type: ignore[attr-defined]
Jul 30 01:31:49 infra-2 sh[1611]: #011 File "/usr/lib/python3/dist-packages/twisted/python/threadpool.py", line 260, in <lambda>
Jul 30 01:31:49 infra-2 sh[1611]: #011 inContext.theWork = lambda: context.call( # type: ignore[attr-defined]
Jul 30 01:31:49 infra-2 sh[1611]: #011 File "/usr/lib/python3/dist-packages/twisted/python/context.py", line 117, in callWithContext
Jul 30 01:31:49 infra-2 sh[1611]: #011 return self.currentContext().callWithContext(ctx, func, *args, **kw)
Jul 30 01:31:49 infra-2 sh[1611]: #011 File "/usr/lib/python3/dist-packages/twisted/python/context.py", line 82, in callWithContext
Jul 30 01:31:49 infra-2 sh[1611]: #011 return func(*args, **kw)
Jul 30 01:31:49 infra-2 sh[1611]: #011 File "/usr/lib/python3/dist-packages/provisioningserver/utils/twisted.py", line 203, in wrapper
Jul 30 01:31:49 infra-2 sh[1611]: #011 result = func(*args, **kwargs)
Jul 30 01:31:49 infra-2 sh[1611]: #011 File "/usr/lib/python3/dist-packages/provisioningserver/refresh/__init__.py", line 56, in refresh
Jul 30 01:31:49 infra-2 sh[1611]: #011 failed_scripts = runscripts(
Jul 30 01:31:49 infra-2 sh[1611]: #011 File "/usr/lib/python3/dist-packages/provisioningserver/refresh/__init__.py", line 170, in runscripts
Jul 30 01:31:49 infra-2 sh[1611]: #011 post_process_hook(
Jul 30 01:31:49 infra-2 sh[1611]: #011 File "/usr/lib/python3/dist-packages/provisioningserver/utils/services.py", line 1233, in _annotate_commissioning
Jul 30 01:31:49 infra-2 sh[1611]: #011 lxd_data = json.load(fp)
Jul 30 01:31:49 infra-2 sh[1611]: #011 File "/usr/lib/python3.10/json/__init__.py", line 293, in load
Jul 30 01:31:49 infra-2 sh[1611]: #011 return loads(fp.read(),
Jul 30 01:31:49 infra-2 sh[1611]: #011 File "/usr/lib/python3.10/json/__init__.py", line 346, in loads
Jul 30 01:31:49 infra-2 sh[1611]: #011 return _default_decoder.decode(s)
Jul 30 01:31:49 infra-2 sh[1611]: #011 File "/usr/lib/python3.10/json/decoder.py", line 337, in decode
Jul 30 01:31:49 infra-2 sh[1611]: #011 obj, end = self.raw_decode(s, idx=_w(s, 0).end())
Jul 30 01:31:49 infra-2 sh[1611]: #011 File "/usr/lib/python3.10/json/decoder.py", line 355, in raw_decode
Jul 30 01:31:49 infra-2 sh[1611]: #011 raise JSONDecodeError("Expecting value", s, err.value) from None
Jul 30 01:31:49 infra-2 sh[1611]: #011json.decoder.JSONDecodeError: Expecting value: line 1 column 1 (char 0)

That line comes from here: https://github.com/maas/maas/blob/3.3.0-rc2/src/provisioningserver/utils/services.py#L1219 where it tries to json load a filepath, but the filepath is None, and there is no where to see where stdout_path is being set.

What's given in the logs is incorrect json, not sure if that's just the logger output.

function call stack

# we start here:
    @inlineCallbacks
    def do_action(self):
        """Update interfaces, catching and logging errors.

        This can be overridden by subclasses to conditionally update based on
        some external configuration.
        """
        interfaces = None
        try:
            interfaces = yield maybeDeferred(self.getInterfaces)
            yield self._updateInterfaces(interfaces)
        except BaseException as e:
            msg = (
                "Failed to update and/or record network interface "
                "configuration: %s; interfaces: %r" % (e, interfaces)
            )
            log.err(None, msg)

# go get the interfaces:

    def getInterfaces(self):
        """Get the current network interfaces configuration.

        This can be overridden by subclasses.
        """
        return deferToThread(get_all_interfaces_definition)

# get_all_interfaces_definition:
interfaces = {}
....
for name, details in ipaddr_info.items():

# ipaddr_info comes from ipaddr.py
    ifaces = parse_lxd_networks(json.loads(output)["networks"])
    _update_interface_type(ifaces)

# parse_lxd_networks() comes from lxd.py and returns a dictionary of interfaces

# then we call _updateInterfaces(interfaces)
        script_stdout = Path(stdout_path)
        with script_stdout.open() as fp:
            lxd_data = json.load(fp) # we die here, fp is None

_get_resources_bin_path():
/usr/share/maas/machine-resources

# interfaces is a dictionary

path = f"{prefix}/usr/share/maas/machine-resources"

Revision history for this message
Heather Lemon (hypothetical-lemon) wrote :

Dm me for google drive link

Revision history for this message
Heather Lemon (hypothetical-lemon) wrote :

Linking a similar issue with the same errors being thrown https://bugs.launchpad.net/maas/+bug/1783912

description: updated
Revision history for this message
Heather Lemon (hypothetical-lemon) wrote :

Adding a pastebin, fairly easy reproducer.

https://pastebin.ubuntu.com/p/S7H2S8hbTh/

Changed in maas:
status: New → Triaged
Revision history for this message
Adam Collard (adam-collard) wrote :

This looks similar to bug 2029417 - please see if we can reproduce it after the fix for that lands

To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.