Custom image errors with 3.5.0

kevin-reeuwijk · 22 July 2024 17:52

I’m testing if MAAS 3.5.0 works with our CAPI provider, it has been working well up to MAAS 3.4.3. With the new 3.5.0 version I’m seeing some problems. Can you provide some hints as to what could be the issue?

This AppArmor error occurs multiple times:

Jul 22 17:07:44 maas kernel: [ 4452.055340] audit: type=1400 audit(1721668064.130:258): apparmor="DENIED" operation="open" profile="snap.maas.pebble" name="/etc/gss/mech.d/" pid=8410 comm="python3" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
J

Don’t know if this is an issue or something we can ignore?

When deploying a machine through our platform, it normally downloads the desired custom image if not available yet. But now we see the image stuck in “Queued for download”, but a machine does start deploying anyway and we see this error appear in the logs:

Jul 22 17:10:52 maas maas-regiond[8406]: maasserver: [error] ################################ Exception: Boot resource custom/u-2204-0-k-1296-0 doesn't have a complete set ################################
Jul 22 17:10:52 maas maas-regiond[8406]: maasserver: [error] Traceback (most recent call last):
Jul 22 17:10:52 maas maas-regiond[8406]:   File "/snap/maas/36363/usr/lib/python3/dist-packages/django/core/handlers/base.py", line 181, in _get_response
Jul 22 17:10:52 maas maas-regiond[8406]:     response = wrapped_callback(request, *callback_args, **callback_kwargs)
Jul 22 17:10:52 maas maas-regiond[8406]:   File "/snap/maas/36363/lib/python3.10/site-packages/maasserver/utils/views.py", line 298, in view_atomic_with_post_commit_savepoint
Jul 22 17:10:52 maas maas-regiond[8406]:     return view_atomic(*args, **kwargs)
Jul 22 17:10:52 maas maas-regiond[8406]:   File "/usr/lib/python3.10/contextlib.py", line 79, in inner
Jul 22 17:10:52 maas maas-regiond[8406]:     return func(*args, **kwds)
Jul 22 17:10:52 maas maas-regiond[8406]:   File "/snap/maas/36363/lib/python3.10/site-packages/maasserver/api/support.py", line 62, in __call__
Jul 22 17:10:52 maas maas-regiond[8406]:     response = super().__call__(request, *args, **kwargs)
Jul 22 17:10:52 maas maas-regiond[8406]:   File "/snap/maas/36363/usr/lib/python3/dist-packages/django/views/decorators/vary.py", line 20, in inner_func
Jul 22 17:10:52 maas maas-regiond[8406]:     response = func(*args, **kwargs)
Jul 22 17:10:52 maas maas-regiond[8406]:   File "/snap/maas/36363/usr/lib/python3/dist-packages/piston3/resource.py", line 196, in __call__
Jul 22 17:10:52 maas maas-regiond[8406]:     result = self.error_handler(e, request, meth, em_format)
Jul 22 17:10:52 maas maas-regiond[8406]:   File "/snap/maas/36363/usr/lib/python3/dist-packages/piston3/resource.py", line 194, in __call__
Jul 22 17:10:52 maas maas-regiond[8406]:     result = meth(request, *args, **kwargs)
Jul 22 17:10:52 maas maas-regiond[8406]:   File "/snap/maas/36363/lib/python3.10/site-packages/maasserver/api/support.py", line 371, in dispatch
Jul 22 17:10:52 maas maas-regiond[8406]:     return function(self, request, *args, **kwargs)
Jul 22 17:10:52 maas maas-regiond[8406]:   File "/snap/maas/36363/lib/python3.10/site-packages/metadataserver/api.py", line 1172, in read
Jul 22 17:10:52 maas maas-regiond[8406]:     user_data = get_curtin_userdata(request, node)
Jul 22 17:10:52 maas maas-regiond[8406]:   File "/snap/maas/36363/lib/python3.10/site-packages/maasserver/preseed.py", line 447, in get_curtin_userdata
Jul 22 17:10:52 maas maas-regiond[8406]:     args=[get_curtin_installer_url(node)],
Jul 22 17:10:52 maas maas-regiond[8406]:   File "/snap/maas/36363/lib/python3.10/site-packages/maasserver/preseed.py", line 513, in get_curtin_installer_url
Jul 22 17:10:52 maas maas-regiond[8406]:     image, xinstall_type = get_curtin_image(
Jul 22 17:10:52 maas maas-regiond[8406]:   File "/snap/maas/36363/lib/python3.10/site-packages/maasserver/preseed.py", line 478, in get_curtin_image
Jul 22 17:10:52 maas maas-regiond[8406]:     raise MissingBootImage(
Jul 22 17:10:52 maas maas-regiond[8406]: maasserver.exceptions.MissingBootImage: Boot resource custom/u-2204-0-k-1296-0 doesn't have a complete set

This is the main problem, as it makes our integration no longer work on this version. Any ideas?

alexsander-souza · 22 July 2024 18:03

you can ignore the apparmor error, it’s harmless.

about the custom image:

does the download ever complete?
how many region controllers do you have in this cluster?

kevin-reeuwijk · 22 July 2024 18:41

The download never starts; this was not a problem on 3.4.x
This is a 1-node installation, super simple.

alexsander-souza · 22 July 2024 18:58

can you get the SHA256 hash of this image and check if there’s a file named after it in /var/snap/maas/common/maas/image-storage/ ?

if it’s not there, can you try deleting and uploading this image again?

kevin-reeuwijk · 22 July 2024 18:59

In see

b98d714a0489b4cc6b291dc62d748fa0d4956ab7e37e627b97434846ec5661d6.incomplete
3f67059c210de046e985a82c99b52b64843e0fc87d8f0b41321982e28e34efa2.incomplete

in there, which likely are the 2 images that are still in this pending state. The sizes are matching to the MaaS GUI so it’s them.

kevin-reeuwijk · 22 July 2024 19:08

maas admin boot-resources read gives me

    {
        "id": 48,
        "type": "Uploaded",
        "name": "u-2204-0-k-1290-0",
        "architecture": "amd64/generic",
        "resource_uri": "/MAAS/api/2.0/boot-resources/48/",
        "last_deployed": null,
        "title": "u-2204-0-k-1290-0",
        "subarches": "generic",
        "base_image": "ubuntu/jammy"
    },
    {
        "id": 49,
        "type": "Uploaded",
        "name": "u-2204-0-k-1296-0",
        "architecture": "amd64/generic",
        "resource_uri": "/MAAS/api/2.0/boot-resources/49/",
        "last_deployed": null,
        "title": "u-2204-0-k-1296-0",
        "subarches": "generic",
        "base_image": "ubuntu/jammy"
    }

for these two images. If I do maas admin boot-resources is-importing id=48 I get

Success.
Machine-readable output follows:
false

alexsander-souza · 22 July 2024 19:09

the GUI message is misleading because MAAS cannot recover from this error alone, it’s not possible to download custom images, the user must upload them to it. the fact they are in incomplete state tell us that the upload has failed (or is still in progress)

kevin-reeuwijk · 22 July 2024 19:14

Our appliance uploads them; the error must be happening there. Let me check.

kevin-reeuwijk · 22 July 2024 19:25

Yeah I’m seeing

	Put "http://maas.dreamworx.nl:5240/MAAS/api/2.0/boot-resources/47/upload/799/": readfrom tcp 100.64.51.135:39600->192.168.250.118:5240: write tcp 100.64.51.135:39600->192.168.250.118:5240: use of closed network connection

as well as

listing images from maas: Get "http://maas.dreamworx.nl:5240/MAAS/api/2.0/boot-resources/": dial tcp 192.168.250.118:5240: connect: connection refused

alexsander-souza · 22 July 2024 19:41

anything in the system journal?
journalctl -t maas-regiond -t maas-log -t maas-temporal

kevin-reeuwijk · 22 July 2024 19:46

On our end the appliance logs

manager I0722 19:34:32.902179       1 spectrocluster_reconcile.go:975] controllers/SpectroCluster "msg"="reconcile OS Image" "spectrocluster"={"Namespace":"cluster 669eb408f9a3af6b0aebff16","Name":"test-2"}
manager I0722 19:34:32.958068       1 maas_image.go:81] controllers/SpectroCluster "msg"="image not found in maas importing" "imageURL"="https://maasgoldenimage-stage.s3.amazonaws.com/u-2204-0-k-1296-0.tar.gz" "spectrocluster"={"Namespace":"cluster-669eb408f9a3af6b0aebff16","Name":"test-2"}
manager I0722 19:38:39.788547       1 maas_image.go:161] controllers/SpectroCluster "msg"="file download complete, begin upload" "spectrocluster"={"Namespace":"cluster-669eb408f9a3af6b0aebff16","Name":"test-2"}

but the upload is still stuck or waiting so far (I wiped and started a fresh one).
On the MAAS server I see

Jul 22 19:40:38 maas maas-regiond[1237]: regiond: [info] 127.0.0.1 PUT /MAAS/api/2.0/boot-resources/51/upload/803/ HTTP/1.1 --> 200 OK (referrer: -; agent: Go-http-client/1.1)
Jul 22 19:41:37 maas maas-regiond[1240]: regiond: [info] 127.0.0.1 PUT /MAAS/api/2.0/boot-resources/50/upload/802/ HTTP/1.1 --> 200 OK (referrer: -; agent: Go-http-client/1.1)
Jul 22 19:42:43 maas maas-regiond[1240]: regiond: [info] 127.0.0.1 PUT /MAAS/api/2.0/boot-resources/51/upload/803/ HTTP/1.1 --> 200 OK (referrer: -; agent: Go-http-client/1.1)
Jul 22 19:43:28 maas maas-regiond[1240]: regiond: [info] 127.0.0.1 PUT /MAAS/api/2.0/boot-resources/50/upload/802/ HTTP/1.1 --> 200 OK (referrer: -; agent: Go-http-client/1.1)
Jul 22 19:44:49 maas maas-regiond[1237]: regiond: [info] 127.0.0.1 PUT /MAAS/api/2.0/boot-resources/51/upload/803/ HTTP/1.1 --> 200 OK (referrer: -; agent: Go-http-client/1.1)

so it seems there are chunks getting uploaded

kevin-reeuwijk · 22 July 2024 19:48

There are 2 images getting uploaded and it seems it keeps repeating. It then loses the connection

Jul 22 19:35:24 maas maas-regiond[1051]: maasserver.regiondservices.active_discovery: [info] Active network discovery: Active scanning is not enabled on any subnet. Skipping periodic scan.
Jul 22 19:39:34 maas maas-regiond[1241]: regiond: [info] 127.0.0.1 PUT /MAAS/api/2.0/boot-resources/50/upload/802/ HTTP/1.1 --> 200 OK (referrer: -; agent: Go-http-client/1.1)
Jul 22 19:40:24 maas maas-regiond[1051]: maasserver.regiondservices.active_discovery: [info] Active network discovery: Active scanning is not enabled on any subnet. Skipping periodic scan.
Jul 22 19:40:38 maas maas-regiond[1237]: regiond: [info] 127.0.0.1 PUT /MAAS/api/2.0/boot-resources/51/upload/803/ HTTP/1.1 --> 200 OK (referrer: -; agent: Go-http-client/1.1)
Jul 22 19:41:37 maas maas-regiond[1240]: regiond: [info] 127.0.0.1 PUT /MAAS/api/2.0/boot-resources/50/upload/802/ HTTP/1.1 --> 200 OK (referrer: -; agent: Go-http-client/1.1)
Jul 22 19:42:43 maas maas-regiond[1240]: regiond: [info] 127.0.0.1 PUT /MAAS/api/2.0/boot-resources/51/upload/803/ HTTP/1.1 --> 200 OK (referrer: -; agent: Go-http-client/1.1)
Jul 22 19:43:28 maas maas-regiond[1240]: regiond: [info] 127.0.0.1 PUT /MAAS/api/2.0/boot-resources/50/upload/802/ HTTP/1.1 --> 200 OK (referrer: -; agent: Go-http-client/1.1)
Jul 22 19:44:49 maas maas-regiond[1237]: regiond: [info] 127.0.0.1 PUT /MAAS/api/2.0/boot-resources/51/upload/803/ HTTP/1.1 --> 200 OK (referrer: -; agent: Go-http-client/1.1)
Jul 22 19:45:24 maas maas-regiond[1051]: maasserver.regiondservices.active_discovery: [info] Active network discovery: Active scanning is not enabled on any subnet. Skipping periodic scan.
Jul 22 19:45:32 maas maas-regiond[1237]: regiond: [info] 127.0.0.1 PUT /MAAS/api/2.0/boot-resources/50/upload/802/ HTTP/1.1 --> 200 OK (referrer: -; agent: Go-http-client/1.1)
Jul 22 19:46:43 maas maas-regiond[1240]: regiond: [info] 127.0.0.1 PUT /MAAS/api/2.0/boot-resources/51/upload/803/ HTTP/1.1 --> 200 OK (referrer: -; agent: Go-http-client/1.1)
Jul 22 19:47:30 maas maas-regiond[1241]: regiond: [info] 127.0.0.1 PUT /MAAS/api/2.0/boot-resources/50/upload/802/ HTTP/1.1 --> 200 OK (referrer: -; agent: Go-http-client/1.1)
Jul 22 19:47:31 maas maas-regiond[1237]: RegionServer,1,::ffff:192.168.250.118: [info] RegionServer connection lost (HOST:IPv6Address(type='TCP', host='::ffff:192.168.250.118', port=5250, flowInfo=0, scopeID=0) PEER:IPv6Address(type='TCP', host='::ffff:192.168.250.118', port=36470, flowInfo=0, scopeID=0))
Jul 22 19:47:31 maas maas-regiond[1237]: RegionServer,2,::ffff:192.168.250.118: [info] RegionServer connection lost (HOST:IPv6Address(type='TCP', host='::ffff:192.168.250.118', port=5250, flowInfo=0, scopeID=0) PEER:IPv6Address(type='TCP', host='::ffff:192.168.250.118', port=36478, flowInfo=0, scopeID=0))
Jul 22 19:47:31 maas maas-regiond[1051]: maasserver.ipc: [info] Worker pid:1237 lost burst connection to ('192.168.250.118', 5250).
Jul 22 19:47:31 maas maas-regiond[1051]: maasserver.ipc: [info] Worker pid:1237 lost burst connection to ('192.168.250.118', 5250).
Jul 22 19:47:31 maas maas-regiond[1237]: RegionServer,3,::ffff:192.168.250.118: [info] RegionServer connection lost (HOST:IPv6Address(type='TCP', host='::ffff:192.168.250.118', port=5250, flowInfo=0, scopeID=0) PEER:IPv6Address(type='TCP', host='::ffff:192.168.250.118', port=36488, flowInfo=0, scopeID=0))
Jul 22 19:47:31 maas maas-regiond[1051]: maasserver.ipc: [info] Worker pid:1237 lost burst connection to ('192.168.250.118', 5250).

kevin-reeuwijk · 22 July 2024 20:00

So it looks like the RegionServer crashes at some point during the upload, causing the upload from our appliance to eventually time out. It then tries again later, after logging the connection refused and use of closed network connection errors.

With 3.4.x this problem does not occur. I will revert back to a snapshot of 3.4.3 now.
You should be able to reproduce this by attempting to upload 2 images of 2GB to MAAS.

kevin-reeuwijk · 22 July 2024 20:02

More extended log output from MAAS:

Jul 22 19:35:24 maas maas-regiond[1051]: maasserver.regiondservices.active_discovery: [info] Active network discovery: Active scanning is not enabled on any subnet. Skipping periodic scan.
Jul 22 19:39:34 maas maas-regiond[1241]: regiond: [info] 127.0.0.1 PUT /MAAS/api/2.0/boot-resources/50/upload/802/ HTTP/1.1 --> 200 OK (referrer: -; agent: Go-http-client/1.1)
Jul 22 19:40:24 maas maas-regiond[1051]: maasserver.regiondservices.active_discovery: [info] Active network discovery: Active scanning is not enabled on any subnet. Skipping periodic scan.
Jul 22 19:40:38 maas maas-regiond[1237]: regiond: [info] 127.0.0.1 PUT /MAAS/api/2.0/boot-resources/51/upload/803/ HTTP/1.1 --> 200 OK (referrer: -; agent: Go-http-client/1.1)
Jul 22 19:41:37 maas maas-regiond[1240]: regiond: [info] 127.0.0.1 PUT /MAAS/api/2.0/boot-resources/50/upload/802/ HTTP/1.1 --> 200 OK (referrer: -; agent: Go-http-client/1.1)
Jul 22 19:42:43 maas maas-regiond[1240]: regiond: [info] 127.0.0.1 PUT /MAAS/api/2.0/boot-resources/51/upload/803/ HTTP/1.1 --> 200 OK (referrer: -; agent: Go-http-client/1.1)
Jul 22 19:43:28 maas maas-regiond[1240]: regiond: [info] 127.0.0.1 PUT /MAAS/api/2.0/boot-resources/50/upload/802/ HTTP/1.1 --> 200 OK (referrer: -; agent: Go-http-client/1.1)
Jul 22 19:44:49 maas maas-regiond[1237]: regiond: [info] 127.0.0.1 PUT /MAAS/api/2.0/boot-resources/51/upload/803/ HTTP/1.1 --> 200 OK (referrer: -; agent: Go-http-client/1.1)
root@maas:~# journalctl -t maas-regiond -t maas-log -t maas-temporal -f
Jul 22 19:35:24 maas maas-regiond[1051]: maasserver.regiondservices.active_discovery: [info] Active network discovery: Active scanning is not enabled on any subnet. Skipping periodic scan.
Jul 22 19:39:34 maas maas-regiond[1241]: regiond: [info] 127.0.0.1 PUT /MAAS/api/2.0/boot-resources/50/upload/802/ HTTP/1.1 --> 200 OK (referrer: -; agent: Go-http-client/1.1)
Jul 22 19:40:24 maas maas-regiond[1051]: maasserver.regiondservices.active_discovery: [info] Active network discovery: Active scanning is not enabled on any subnet. Skipping periodic scan.
Jul 22 19:40:38 maas maas-regiond[1237]: regiond: [info] 127.0.0.1 PUT /MAAS/api/2.0/boot-resources/51/upload/803/ HTTP/1.1 --> 200 OK (referrer: -; agent: Go-http-client/1.1)
Jul 22 19:41:37 maas maas-regiond[1240]: regiond: [info] 127.0.0.1 PUT /MAAS/api/2.0/boot-resources/50/upload/802/ HTTP/1.1 --> 200 OK (referrer: -; agent: Go-http-client/1.1)
Jul 22 19:42:43 maas maas-regiond[1240]: regiond: [info] 127.0.0.1 PUT /MAAS/api/2.0/boot-resources/51/upload/803/ HTTP/1.1 --> 200 OK (referrer: -; agent: Go-http-client/1.1)
Jul 22 19:43:28 maas maas-regiond[1240]: regiond: [info] 127.0.0.1 PUT /MAAS/api/2.0/boot-resources/50/upload/802/ HTTP/1.1 --> 200 OK (referrer: -; agent: Go-http-client/1.1)
Jul 22 19:44:49 maas maas-regiond[1237]: regiond: [info] 127.0.0.1 PUT /MAAS/api/2.0/boot-resources/51/upload/803/ HTTP/1.1 --> 200 OK (referrer: -; agent: Go-http-client/1.1)
Jul 22 19:45:24 maas maas-regiond[1051]: maasserver.regiondservices.active_discovery: [info] Active network discovery: Active scanning is not enabled on any subnet. Skipping periodic scan.
Jul 22 19:45:32 maas maas-regiond[1237]: regiond: [info] 127.0.0.1 PUT /MAAS/api/2.0/boot-resources/50/upload/802/ HTTP/1.1 --> 200 OK (referrer: -; agent: Go-http-client/1.1)
Jul 22 19:46:43 maas maas-regiond[1240]: regiond: [info] 127.0.0.1 PUT /MAAS/api/2.0/boot-resources/51/upload/803/ HTTP/1.1 --> 200 OK (referrer: -; agent: Go-http-client/1.1)
Jul 22 19:47:30 maas maas-regiond[1241]: regiond: [info] 127.0.0.1 PUT /MAAS/api/2.0/boot-resources/50/upload/802/ HTTP/1.1 --> 200 OK (referrer: -; agent: Go-http-client/1.1)
Jul 22 19:47:31 maas maas-regiond[1237]: RegionServer,1,::ffff:192.168.250.118: [info] RegionServer connection lost (HOST:IPv6Address(type='TCP', host='::ffff:192.168.250.118', port=5250, flowInfo=0, scopeID=0) PEER:IPv6Address(type='TCP', host='::ffff:192.168.250.118', port=36470, flowInfo=0, scopeID=0))
Jul 22 19:47:31 maas maas-regiond[1237]: RegionServer,2,::ffff:192.168.250.118: [info] RegionServer connection lost (HOST:IPv6Address(type='TCP', host='::ffff:192.168.250.118', port=5250, flowInfo=0, scopeID=0) PEER:IPv6Address(type='TCP', host='::ffff:192.168.250.118', port=36478, flowInfo=0, scopeID=0))
Jul 22 19:47:31 maas maas-regiond[1051]: maasserver.ipc: [info] Worker pid:1237 lost burst connection to ('192.168.250.118', 5250).
Jul 22 19:47:31 maas maas-regiond[1051]: maasserver.ipc: [info] Worker pid:1237 lost burst connection to ('192.168.250.118', 5250).
Jul 22 19:47:31 maas maas-regiond[1237]: RegionServer,3,::ffff:192.168.250.118: [info] RegionServer connection lost (HOST:IPv6Address(type='TCP', host='::ffff:192.168.250.118', port=5250, flowInfo=0, scopeID=0) PEER:IPv6Address(type='TCP', host='::ffff:192.168.250.118', port=36488, flowInfo=0, scopeID=0))
Jul 22 19:47:31 maas maas-regiond[1051]: maasserver.ipc: [info] Worker pid:1237 lost burst connection to ('192.168.250.118', 5250).
Jul 22 19:47:51 maas maas-regiond[1237]: twisted.internet.protocol.Factory: [info] RegionServer connection established (HOST:IPv6Address(type='TCP', host='::ffff:192.168.250.118', port=5250, flowInfo=0, scopeID=0) PEER:IPv6Address(type='TCP', host='::ffff:192.168.250.118', port=56564, flowInfo=0, scopeID=0))
Jul 22 19:47:51 maas maas-regiond[1237]: twisted.internet.protocol.Factory: [info] RegionServer connection established (HOST:IPv6Address(type='TCP', host='::ffff:192.168.250.118', port=5250, flowInfo=0, scopeID=0) PEER:IPv6Address(type='TCP', host='::ffff:192.168.250.118', port=56578, flowInfo=0, scopeID=0))
Jul 22 19:47:51 maas maas-regiond[1237]: twisted.internet.protocol.Factory: [info] RegionServer connection established (HOST:IPv6Address(type='TCP', host='::ffff:192.168.250.118', port=5250, flowInfo=0, scopeID=0) PEER:IPv6Address(type='TCP', host='::ffff:192.168.250.118', port=56582, flowInfo=0, scopeID=0))
Jul 22 19:47:51 maas maas-regiond[1237]: maasserver.rpc.regionservice: [info] Rack controller authenticated from '::ffff:192.168.250.118:56564'.
Jul 22 19:47:51 maas maas-regiond[1237]: maasserver.rpc.regionservice: [info] Rack controller authenticated from '::ffff:192.168.250.118:56578'.
Jul 22 19:47:51 maas maas-regiond[1237]: maasserver.rpc.regionservice: [info] Rack controller authenticated from '::ffff:192.168.250.118:56582'.
Jul 22 19:47:51 maas maas-log[1423]: maas.rpc.rackcontrollers: [info] Existing rack controller 'maas' running version 3.5.0-16308-g.c799a1080 has connected to region 'maas'.
Jul 22 19:47:51 maas maas-regiond[1051]: maasserver.ipc: [info] Worker pid:1237 registered RPC connection to ('7as7ey', '192.168.250.118', 5250).
Jul 22 19:47:51 maas maas-regiond[1051]: maasserver.ipc: [info] Worker pid:1237 registered RPC connection to ('7as7ey', '192.168.250.118', 5250).
Jul 22 19:47:51 maas maas-regiond[1051]: maasserver.ipc: [info] Worker pid:1237 registered RPC connection to ('7as7ey', '192.168.250.118', 5250).
Jul 22 19:47:55 maas maas-log[1423]: maas.rpc.rackcontrollers: message repeated 2 times: [ [info] Existing rack controller 'maas' running version 3.5.0-16308-g.c799a1080 has connected to region 'maas'.]
Jul 22 19:48:01 maas maas-regiond[1239]: RegionServer,1,::ffff:192.168.250.118: [info] RegionServer connection lost (HOST:IPv6Address(type='TCP', host='::ffff:192.168.250.118', port=5251, flowInfo=0, scopeID=0) PEER:IPv6Address(type='TCP', host='::ffff:192.168.250.118', port=55002, flowInfo=0, scopeID=0))
Jul 22 19:48:01 maas maas-regiond[1051]: maasserver.ipc: [info] Worker pid:1239 lost burst connection to ('192.168.250.118', 5251).
Jul 22 19:48:01 maas maas-regiond[1239]: RegionServer,2,::ffff:192.168.250.118: [info] RegionServer connection lost (HOST:IPv6Address(type='TCP', host='::ffff:192.168.250.118', port=5251, flowInfo=0, scopeID=0) PEER:IPv6Address(type='TCP', host='::ffff:192.168.250.118', port=55012, flowInfo=0, scopeID=0))
Jul 22 19:48:01 maas maas-regiond[1051]: maasserver.ipc: [info] Worker pid:1239 lost burst connection to ('192.168.250.118', 5251).
Jul 22 19:48:01 maas maas-regiond[1239]: RegionServer,3,::ffff:192.168.250.118: [info] RegionServer connection lost (HOST:IPv6Address(type='TCP', host='::ffff:192.168.250.118', port=5251, flowInfo=0, scopeID=0) PEER:IPv6Address(type='TCP', host='::ffff:192.168.250.118', port=55022, flowInfo=0, scopeID=0))
Jul 22 19:48:01 maas maas-regiond[1051]: maasserver.ipc: [info] Worker pid:1239 lost burst connection to ('192.168.250.118', 5251).
Jul 22 19:48:21 maas maas-regiond[1239]: twisted.internet.protocol.Factory: [info] RegionServer connection established (HOST:IPv6Address(type='TCP', host='::ffff:192.168.250.118', port=5251, flowInfo=0, scopeID=0) PEER:IPv6Address(type='TCP', host='::ffff:192.168.250.118', port=39990, flowInfo=0, scopeID=0))
Jul 22 19:48:21 maas maas-regiond[1239]: twisted.internet.protocol.Factory: [info] RegionServer connection established (HOST:IPv6Address(type='TCP', host='::ffff:192.168.250.118', port=5251, flowInfo=0, scopeID=0) PEER:IPv6Address(type='TCP', host='::ffff:192.168.250.118', port=39998, flowInfo=0, scopeID=0))
Jul 22 19:48:21 maas maas-regiond[1239]: twisted.internet.protocol.Factory: [info] RegionServer connection established (HOST:IPv6Address(type='TCP', host='::ffff:192.168.250.118', port=5251, flowInfo=0, scopeID=0) PEER:IPv6Address(type='TCP', host='::ffff:192.168.250.118', port=40008, flowInfo=0, scopeID=0))
Jul 22 19:48:21 maas maas-regiond[1239]: maasserver.rpc.regionservice: [info] Rack controller authenticated from '::ffff:192.168.250.118:39990'.
Jul 22 19:48:21 maas maas-regiond[1239]: maasserver.rpc.regionservice: [info] Rack controller authenticated from '::ffff:192.168.250.118:39998'.
Jul 22 19:48:21 maas maas-regiond[1239]: maasserver.rpc.regionservice: [info] Rack controller authenticated from '::ffff:192.168.250.118:40008'.
Jul 22 19:48:21 maas maas-log[1423]: maas.rpc.rackcontrollers: [info] Existing rack controller 'maas' running version 3.5.0-16308-g.c799a1080 has connected to region 'maas'.
Jul 22 19:48:21 maas maas-regiond[1051]: maasserver.ipc: [info] Worker pid:1239 registered RPC connection to ('7as7ey', '192.168.250.118', 5251).
Jul 22 19:48:21 maas maas-regiond[1051]: maasserver.ipc: [info] Worker pid:1239 registered RPC connection to ('7as7ey', '192.168.250.118', 5251).
Jul 22 19:48:21 maas maas-regiond[1051]: maasserver.ipc: [info] Worker pid:1239 registered RPC connection to ('7as7ey', '192.168.250.118', 5251).
Jul 22 19:48:25 maas maas-log[1423]: maas.rpc.rackcontrollers: message repeated 2 times: [ [info] Existing rack controller 'maas' running version 3.5.0-16308-g.c799a1080 has connected to region 'maas'.]
Jul 22 19:48:31 maas maas-regiond[1240]: RegionServer,1,::ffff:192.168.250.118: [info] RegionServer connection lost (HOST:IPv6Address(type='TCP', host='::ffff:192.168.250.118', port=5252, flowInfo=0, scopeID=0) PEER:IPv6Address(type='TCP', host='::ffff:192.168.250.118', port=35286, flowInfo=0, scopeID=0))
Jul 22 19:48:31 maas maas-regiond[1240]: RegionServer,2,::ffff:192.168.250.118: [info] RegionServer connection lost (HOST:IPv6Address(type='TCP', host='::ffff:192.168.250.118', port=5252, flowInfo=0, scopeID=0) PEER:IPv6Address(type='TCP', host='::ffff:192.168.250.118', port=35302, flowInfo=0, scopeID=0))
Jul 22 19:48:31 maas maas-regiond[1051]: maasserver.ipc: [info] Worker pid:1240 lost burst connection to ('192.168.250.118', 5252).
Jul 22 19:48:31 maas maas-regiond[1051]: maasserver.ipc: [info] Worker pid:1240 lost burst connection to ('192.168.250.118', 5252).
Jul 22 19:48:31 maas maas-regiond[1240]: RegionServer,3,::ffff:192.168.250.118: [info] RegionServer connection lost (HOST:IPv6Address(type='TCP', host='::ffff:192.168.250.118', port=5252, flowInfo=0, scopeID=0) PEER:IPv6Address(type='TCP', host='::ffff:192.168.250.118', port=35308, flowInfo=0, scopeID=0))
Jul 22 19:48:31 maas maas-regiond[1051]: maasserver.ipc: [info] Worker pid:1240 lost burst connection to ('192.168.250.118', 5252).
Jul 22 19:48:45 maas maas-regiond[1241]: regiond: [info] 127.0.0.1 PUT /MAAS/api/2.0/boot-resources/51/upload/803/ HTTP/1.1 --> 200 OK (referrer: -; agent: Go-http-client/1.1)
Jul 22 19:48:51 maas maas-regiond[1240]: twisted.internet.protocol.Factory: [info] RegionServer connection established (HOST:IPv6Address(type='TCP', host='::ffff:192.168.250.118', port=5252, flowInfo=0, scopeID=0) PEER:IPv6Address(type='TCP', host='::ffff:192.168.250.118', port=35502, flowInfo=0, scopeID=0))
Jul 22 19:48:51 maas maas-regiond[1240]: twisted.internet.protocol.Factory: [info] RegionServer connection established (HOST:IPv6Address(type='TCP', host='::ffff:192.168.250.118', port=5252, flowInfo=0, scopeID=0) PEER:IPv6Address(type='TCP', host='::ffff:192.168.250.118', port=35512, flowInfo=0, scopeID=0))
Jul 22 19:48:51 maas maas-regiond[1240]: twisted.internet.protocol.Factory: [info] RegionServer connection established (HOST:IPv6Address(type='TCP', host='::ffff:192.168.250.118', port=5252, flowInfo=0, scopeID=0) PEER:IPv6Address(type='TCP', host='::ffff:192.168.250.118', port=35516, flowInfo=0, scopeID=0))
Jul 22 19:48:51 maas maas-regiond[1240]: maasserver.rpc.regionservice: [info] Rack controller authenticated from '::ffff:192.168.250.118:35502'.
Jul 22 19:48:51 maas maas-regiond[1240]: maasserver.rpc.regionservice: [info] Rack controller authenticated from '::ffff:192.168.250.118:35512'.
Jul 22 19:48:51 maas maas-regiond[1240]: maasserver.rpc.regionservice: [info] Rack controller authenticated from '::ffff:192.168.250.118:35516'.
Jul 22 19:48:51 maas maas-log[1423]: maas.rpc.rackcontrollers: [info] Existing rack controller 'maas' running version 3.5.0-16308-g.c799a1080 has connected to region 'maas'.
Jul 22 19:48:51 maas maas-regiond[1051]: maasserver.ipc: [info] Worker pid:1240 registered RPC connection to ('7as7ey', '192.168.250.118', 5252).
Jul 22 19:48:51 maas maas-regiond[1051]: maasserver.ipc: [info] Worker pid:1240 registered RPC connection to ('7as7ey', '192.168.250.118', 5252).
Jul 22 19:48:51 maas maas-regiond[1051]: maasserver.ipc: [info] Worker pid:1240 registered RPC connection to ('7as7ey', '192.168.250.118', 5252).
Jul 22 19:48:51 maas maas-log[1423]: maas.rpc.rackcontrollers: message repeated 2 times: [ [info] Existing rack controller 'maas' running version 3.5.0-16308-g.c799a1080 has connected to region 'maas'.]
Jul 22 19:49:01 maas maas-regiond[1241]: RegionServer,1,::ffff:192.168.250.118: [info] RegionServer connection lost (HOST:IPv6Address(type='TCP', host='::ffff:192.168.250.118', port=5253, flowInfo=0, scopeID=0) PEER:IPv6Address(type='TCP', host='::ffff:192.168.250.118', port=35196, flowInfo=0, scopeID=0))
Jul 22 19:49:01 maas maas-regiond[1241]: RegionServer,2,::ffff:192.168.250.118: [info] RegionServer connection lost (HOST:IPv6Address(type='TCP', host='::ffff:192.168.250.118', port=5253, flowInfo=0, scopeID=0) PEER:IPv6Address(type='TCP', host='::ffff:192.168.250.118', port=35204, flowInfo=0, scopeID=0))
Jul 22 19:49:01 maas maas-regiond[1051]: maasserver.ipc: [info] Worker pid:1241 lost burst connection to ('192.168.250.118', 5253).
Jul 22 19:49:01 maas maas-regiond[1051]: maasserver.ipc: [info] Worker pid:1241 lost burst connection to ('192.168.250.118', 5253).
Jul 22 19:49:01 maas maas-regiond[1241]: RegionServer,3,::ffff:192.168.250.118: [info] RegionServer connection lost (HOST:IPv6Address(type='TCP', host='::ffff:192.168.250.118', port=5253, flowInfo=0, scopeID=0) PEER:IPv6Address(type='TCP', host='::ffff:192.168.250.118', port=35208, flowInfo=0, scopeID=0))
Jul 22 19:49:01 maas maas-regiond[1051]: maasserver.ipc: [info] Worker pid:1241 lost burst connection to ('192.168.250.118', 5253).
Jul 22 19:49:21 maas maas-regiond[1241]: twisted.internet.protocol.Factory: [info] RegionServer connection established (HOST:IPv6Address(type='TCP', host='::ffff:192.168.250.118', port=5253, flowInfo=0, scopeID=0) PEER:IPv6Address(type='TCP', host='::ffff:192.168.250.118', port=59102, flowInfo=0, scopeID=0))
Jul 22 19:49:21 maas maas-regiond[1241]: twisted.internet.protocol.Factory: [info] RegionServer connection established (HOST:IPv6Address(type='TCP', host='::ffff:192.168.250.118', port=5253, flowInfo=0, scopeID=0) PEER:IPv6Address(type='TCP', host='::ffff:192.168.250.118', port=59114, flowInfo=0, scopeID=0))
Jul 22 19:49:21 maas maas-regiond[1241]: twisted.internet.protocol.Factory: [info] RegionServer connection established (HOST:IPv6Address(type='TCP', host='::ffff:192.168.250.118', port=5253, flowInfo=0, scopeID=0) PEER:IPv6Address(type='TCP', host='::ffff:192.168.250.118', port=59122, flowInfo=0, scopeID=0))
Jul 22 19:49:21 maas maas-regiond[1241]: maasserver.rpc.regionservice: [info] Rack controller authenticated from '::ffff:192.168.250.118:59122'.
Jul 22 19:49:21 maas maas-regiond[1241]: maasserver.rpc.regionservice: [info] Rack controller authenticated from '::ffff:192.168.250.118:59102'.
Jul 22 19:49:21 maas maas-log[1423]: maas.rpc.rackcontrollers: [info] Existing rack controller 'maas' running version 3.5.0-16308-g.c799a1080 has connected to region 'maas'.
Jul 22 19:49:21 maas maas-regiond[1051]: maasserver.ipc: [info] Worker pid:1241 registered RPC connection to ('7as7ey', '192.168.250.118', 5253).
Jul 22 19:49:21 maas maas-regiond[1241]: maasserver.rpc.regionservice: [info] Rack controller authenticated from '::ffff:192.168.250.118:59114'.
Jul 22 19:49:21 maas maas-regiond[1051]: maasserver.ipc: [info] Worker pid:1241 registered RPC connection to ('7as7ey', '192.168.250.118', 5253).
Jul 22 19:49:21 maas maas-regiond[1051]: maasserver.ipc: [info] Worker pid:1241 registered RPC connection to ('7as7ey', '192.168.250.118', 5253).
Jul 22 19:49:25 maas maas-log[1423]: maas.rpc.rackcontrollers: message repeated 2 times: [ [info] Existing rack controller 'maas' running version 3.5.0-16308-g.c799a1080 has connected to region 'maas'.]
Jul 22 19:49:39 maas maas-regiond[1237]: regiond: [info] 127.0.0.1 PUT /MAAS/api/2.0/boot-resources/50/upload/802/ HTTP/1.1 --> 200 OK (referrer: -; agent: Go-http-client/1.1)
Jul 22 19:50:24 maas maas-regiond[1051]: maasserver.regiondservices.active_discovery: [info] Active network discovery: Active scanning is not enabled on any subnet. Skipping periodic scan.
Jul 22 19:50:53 maas maas-regiond[1239]: regiond: [info] 127.0.0.1 PUT /MAAS/api/2.0/boot-resources/51/upload/803/ HTTP/1.1 --> 200 OK (referrer: -; agent: Go-http-client/1.1)
Jul 22 19:51:32 maas maas-regiond[1237]: regiond: [info] 127.0.0.1 PUT /MAAS/api/2.0/boot-resources/50/upload/802/ HTTP/1.1 --> 200 OK (referrer: -; agent: Go-http-client/1.1)
Jul 22 19:52:52 maas maas-regiond[1237]: regiond: [info] 127.0.0.1 PUT /MAAS/api/2.0/boot-resources/51/upload/803/ HTTP/1.1 --> 200 OK (referrer: -; agent: Go-http-client/1.1)
Jul 22 19:53:42 maas maas-regiond[1237]: regiond: [info] 127.0.0.1 PUT /MAAS/api/2.0/boot-resources/50/upload/802/ HTTP/1.1 --> 200 OK (referrer: -; agent: Go-http-client/1.1)
Jul 22 19:54:54 maas maas-regiond[1241]: regiond: [info] 127.0.0.1 PUT /MAAS/api/2.0/boot-resources/51/upload/803/ HTTP/1.1 --> 200 OK (referrer: -; agent: Go-http-client/1.1)
Jul 22 19:55:24 maas maas-regiond[1051]: maasserver.regiondservices.active_discovery: [info] Active network discovery: Active scanning is not enabled on any subnet. Skipping periodic scan.
Jul 22 19:55:42 maas maas-regiond[1237]: regiond: [info] 127.0.0.1 PUT /MAAS/api/2.0/boot-resources/50/upload/802/ HTTP/1.1 --> 200 OK (referrer: -; agent: Go-http-client/1.1)
Jul 22 19:56:51 maas maas-regiond[1237]: regiond: [info] 127.0.0.1 PUT /MAAS/api/2.0/boot-resources/51/upload/803/ HTTP/1.1 --> 200 OK (referrer: -; agent: Go-http-client/1.1)
Jul 22 19:57:45 maas maas-regiond[1237]: regiond: [info] 127.0.0.1 PUT /MAAS/api/2.0/boot-resources/50/upload/802/ HTTP/1.1 --> 200 OK (referrer: -; agent: Go-http-client/1.1)
Jul 22 19:59:02 maas maas-regiond[1241]: regiond: [info] 127.0.0.1 PUT /MAAS/api/2.0/boot-resources/51/upload/803/ HTTP/1.1 --> 200 OK (referrer: -; agent: Go-http-client/1.1)
Jul 22 20:00:00 maas maas-regiond[1241]: regiond: [info] 127.0.0.1 PUT /MAAS/api/2.0/boot-resources/50/upload/802/ HTTP/1.1 --> 200 OK (referrer: -; agent: Go-http-client/1.1)
Jul 22 20:00:24 maas maas-regiond[1051]: maasserver.regiondservices.active_discovery: [info] Active network discovery: Active scanning is not enabled on any subnet. Skipping periodic scan.
Jul 22 20:01:01 maas maas-regiond[1240]: regiond: [info] 127.0.0.1 PUT /MAAS/api/2.0/boot-resources/51/upload/803/ HTTP/1.1 --> 200 OK (referrer: -; agent: Go-http-client/1.1)

alexsander-souza · 22 July 2024 20:13

before you drop the DB, can you run this query?

select
	msync."size" as "actual_size",
	mb."size",
	mb.sha256
from
	maasserver_bootresourcefilesync msync,
	maasserver_bootresourcefile mb,
	maasserver_bootresourceset mset
where
	mb.resource_set_id = mset.id
	and msync.file_id = mb.id
	and mset.resource_id = 802;

kevin-reeuwijk · 22 July 2024 20:43

maas_db=# select
        msync."size" as "actual_size",
        mb."size",
        mb.sha256
from
        maasserver_bootresourcefilesync msync,
        maasserver_bootresourcefile mb,
        maasserver_bootresourceset mset
where
        mb.resource_set_id = mset.id
        and msync.file_id = mb.id
        and mset.resource_id = 802;
 actual_size | size | sha256
-------------+------+--------
(0 rows)

kevin-reeuwijk · 22 July 2024 20:45

Probably because I already deleted the cluster deployment, so our appliance is no longer attempting to upload

alexsander-souza · 22 July 2024 20:59

sorry, the resource_id should be 50 or 51 (802 is the file id). can you try again?

kevin-reeuwijk · 22 July 2024 21:00

maas_db=# select
        msync."size" as "actual_size",
        mb."size",
        mb.sha256
from
        maasserver_bootresourcefilesync msync,
        maasserver_bootresourcefile mb,
        maasserver_bootresourceset mset
where
        mb.resource_set_id = mset.id
        and msync.file_id = mb.id
        and mset.resource_id = 52;
 actual_size |    size    |                              sha256
-------------+------------+------------------------------------------------------------------
     4194304 | 1864455060 | b98d714a0489b4cc6b291dc62d748fa0d4956ab7e37e627b97434846ec5661d6
(1 row)

kevin-reeuwijk · 22 July 2024 21:02

 actual_size |    size    |                              sha256
-------------+------------+------------------------------------------------------------------
     8388608 | 1864455060 | b98d714a0489b4cc6b291dc62d748fa0d4956ab7e37e627b97434846ec5661d6
(1 row)

it is slowly increasing. But it will never complete before the RegionServer loses its own connection again.