Comment 0 for bug 2030781

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 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"