When print starts from printer - openspoolman throws errors

[leutnantlurch]

Hello,

First of all - i'm gratefull for this application, it would solve my problem with filamentmanagment but... unfortunately I got problems running the setup smoothly.

The Printer i use: Bambu Lab X1 Carbon with AMS 1 and AMS HT
Firmware: 01.11.02.00

When i start a print from the printers display, the following errors appears in the dockerlog:

`KeyError: 'file'
Traceback (most recent call last):
  File "/home/app/mqtt_bambulab.py", line 425, in on_message
    processMessage(data)
  File "/home/app/mqtt_bambulab.py", line 283, in processMessage
    print_id = insert_print(PENDING_PRINT_METADATA["file"], PRINTER_STATE["print"]["print_type"], PENDING_PRINT_METADATA["image"])
                            ~~~~~~~~~~~~~~~~~~~~~~^^^^^^^^`

My printer throws this error:

 MQTT Command verification failed. Please update Studio (including the network plugin) or Handy to the latest version,
 then restart the software and try again.

And in openspoolman it wouldnt show the print job in the print history.

Attached are my mqtt and spoolman log.

logs.zip

My docker-compose and env file looks like this:

services:
  openspoolman:
    container_name: openspoolman-kaguya
    image: ghcr.io/drndos/openspoolman:dev
    env_file:
      - /boot/config/plugins/compose.manager/projects/Openspoolman/.env
    ports:
      - "8001:8000"
    volumes:
      - /mnt/user/appdata/openspoolman-kaguya/logs:/home/app/logs
      - /mnt/user/appdata/openspoolman-kaguya/data:/home/app/data
      - /mnt/user/appdata/openspoolman-kaguya/prints:/home/app/static/prints
    restart: unless-stopped

Yes, my printer is called Kaguya... ;)

TZ=Europe/Berlin
OPENSPOOLMAN_BASE_URL=http://192.168.1.52:8001
PRINTER_ACCESS_CODE=557******
PRINTER_ID=00M09****************
PRINTER_IP=192.168.1.172
PRINTER_NAME=KAGUYA - Bambu Lab X1 Carbon
SPOOLMAN_BASE_URL=http://192.168.1.52:7912
AUTO_SPEND=True
TRACK_LAYER_USAGE=True
SPOOL_SORTING=filament.material:asc,filament.vendor.name:asc,filament.name:asc
CLEAR_ASSIGNMENT_WHEN_EMPTY=True
COLOR_DISTANCE_TOLERANCE=40

The fields are correct in spoolman and when i start a print via bambu studio, it shows in the print history and it should consume it properly.

So my question is: is it a problem on my side or is it maybe a bug? I'm happy to help and to provide more information, if necessary.

Greetings from switzerland!

[Xento]

Thanks for the issue.

The error on the printer is "normal" because OpenSpoolman still tries to set the filament type, color and temperature and this doesn't work any more but this can be ignored.

Does the mqtt_20260102_222824.log contain the start of the print?

I think there is an issue where OpenSpoolman should download the 3mf file from the printer to get the image and the gcode to calculate the filament usage.

Can you upload a log which contains the start of the print when you select it on the printers display?

Could you take an image of your webinterface?
I only own an A1 with an AMS Lite and I would like to see how the UI looks with more than one AMS.

[leutnantlurch]

Thank you for your reply :)

I'm not sure about the printstart...soo I started just a new print, logs attached:

logs2.zip

The UI looks pretty good with multiple AMS:

And this is the print that gets consumed correctly and was send via bambu studio:

[Xento]

Could you start a print and get the logs directly after the start?
You can stop the print after the printer started the calibrations etc.
I only need the start command for the print.

[leutnantlurch]

I hope i got it now, I started a print two times, i hope you find the information you need:

logs3.zip

[leutnantlurch]

Good morning

I'm not sure if it helps and I hope I don't make the impression that i'm impatient but i want to help (im not a programmer but i hope i can help otherwise), i pulled the newest dev docker and started a print from the printer and the following error appeard in the docker log the option "store on external storage" is already set:

{"log":"[2026-01-05 08:21:13] Downloading 3MF file from FTP...\n","stream":"stdout","time":"2026-01-05T07:21:13.404841463Z"}
{"log":"[2026-01-05 08:21:13] [DEBUG] Attempting file download of: /cache/spulen_gewicht.gcode.3mf\n","stream":"stdout","time":"2026-01-05T07:21:13.404909671Z"}
{"log":"[2026-01-05 08:21:13] [DEBUG] Attempt 1: Starting download of spulen_gewicht.gcode.3mf...\n","stream":"stdout","time":"2026-01-05T07:21:13.407111853Z"}
{"log":"[2026-01-05 08:21:13] [DEBUG] Printer denied access to /cache path. Ensure external storage is setup to store print files in printer settings.\n","stream":"stdout","time":"2026-01-05T07:21:13.635733759Z"}
{"log":"[2026-01-05 08:21:13] 3MF file downloaded and saved as /tmp/tmp6wh3in81.3mf.\n","stream":"stdout","time":"2026-01-05T07:21:13.635858637Z"}
{"log":"[2026-01-05 08:21:13] The downloaded file is not a valid 3MF archive.\n","stream":"stdout","time":"2026-01-05T07:21:13.636256499Z"}
{"log":"Traceback (most recent call last):\n","stream":"stderr","time":"2026-01-05T07:21:13.637690257Z"}
{"log":"  File \"/home/app/mqtt_bambulab.py\", line 458, in on_message\n","stream":"stderr","time":"2026-01-05T07:21:13.638114406Z"}
{"log":"    processMessage(data)\n","stream":"stderr","time":"2026-01-05T07:21:13.638146282Z"}
{"log":"  File \"/home/app/mqtt_bambulab.py\", line 266, in processMessage\n","stream":"stderr","time":"2026-01-05T07:21:13.638163701Z"}
{"log":"    print_id = insert_print(PRINTER_STATE[\"print\"][\"subtask_name\"], \"cloud\", PENDING_PRINT_METADATA[\"image\"])\n","stream":"stderr","time":"2026-01-05T07:21:13.638174762Z"}
{"log":"                                                                             ~~~~~~~~~~~~~~~~~~~~~~^^^^^^^^^\n","stream":"stderr","time":"2026-01-05T07:21:13.638184502Z"}
{"log":"KeyError: 'image'\n","stream":"stderr","time":"2026-01-05T07:21:13.638196028Z"}

and now the logs filling up with the following error:

KeyError: 'file'
Traceback (most recent call last):
  File "/home/app/mqtt_bambulab.py", line 458, in on_message
    processMessage(data)
  File "/home/app/mqtt_bambulab.py", line 316, in processMessage
    print_id = insert_print(PENDING_PRINT_METADATA["file"], PRINTER_STATE["print"]["print_type"], PENDING_PRINT_METADATA["image"])
                            ~~~~~~~~~~~~~~~~~~~~~~^^^^^^^^

unfortunately i started a printjob that i need to be finished, but i deliver the mqtt logs from the start asap

[Xento]

Thanks for the update.
In the latest dev version is an fix which fixed the URL detection.
But in your case it seems that the directory /cache/ is not accessible or missing.

Do you have an SDCard inserted?

Maybe you could use WinSCP to connect to the printers FTP Server. The password is the access code.

Here is an similar issue where there is no cache directory and in this comment are the settings needed win WinSCP to connect to the FTP Server.
greghesp/ha-bambulab#1184 (comment)

[leutnantlurch]

Interesting, thank you for the link, the cache directory is indeed absent but the 3MF Files are in the root directory:

Even the file spulen_gewicht.gcode.3mf is in the root directory

When i start a print from bambu studio (not sending), the following things are in the log:

2026-01-05 10:45:57] Downloading 3MF file from cloud...
[2026-01-05 10:45:59] 3MF file downloaded and saved as /tmp/tmp6odcj1pc.3mf.
[2026-01-05 10:45:59] {'model_path': 'https://or-cloud-upload-prod.s3.us-west-2.amazonaws.com/users/1675684975/models/20260105174552.62/USff5d757d6d9a40_550944556_1.3mf?X-Amz-Algorithm=AWS4-HMAC-SHA256&X-Amz-Credential=AKIAXY6FH2ERJ3UALUNL%2F20260105%2Fus-west-2%2Fs3%2Faws4_request&X-Amz-Date=20260105T094555Z&X-Amz-Expires=3600&X-Amz-SignedHeaders=host&X-Amz-Signature=6fc6353dbdd24feadf4ab3856277973350e22efe4e21b1ccc2cb01031ba6cc61', 'file': 'USff5d757d6d9a40_550944556_1.3mf', 'plateID': '1', 'filaments': {1: {'id': 1, 'tray_info_idx': 'P36b1578', 'type': 'PETG', 'color': '#161616', 'used_g': '56.11', 'used_m': '18.51'}}, 'usage': {1: '56.11'}, 'image': '20260105104559.png', 'gcode_path': 'Metadata/plate_1.gcode', 'filamentOrder': {0: 0}}
[2026-01-05 10:45:59] [filament-tracker] Print start
[2026-01-05 10:45:59] [filament-tracker] Downloading model via HTTP(S): https://or-cloud-upload-prod.s3.us-west-2.amazonaws.com/users/1675684975/models/20260105174552.62/USff5d757d6d9a40_550944556_1.3mf?X-Amz-Algorithm=AWS4-HMAC-SHA256&X-Amz-Credential=AKIAXY6FH2ERJ3UALUNL%2F20260105%2Fus-west-2%2Fs3%2Faws4_request&X-Amz-Date=20260105T094555Z&X-Amz-Expires=3600&X-Amz-SignedHeaders=host&X-Amz-Signature=6fc6353dbdd24feadf4ab3856277973350e22efe4e21b1ccc2cb01031ba6cc61
[2026-01-05 10:45:59] Downloading 3MF file from cloud...

And the mqtt.log from the printstart when it was started through bambu studio:

mqtt.log

The SD-Card is in the printer and it gets recognized.

And here is the mqtt log when the print is started from the printer:

mqtt.log

Hahahahaha while i was writing this text, something happend:

The log:

And look which directory made an apperance:

The spooky thing is... i never sliced a qidi-xmax-spool-holder or something.... and when i start a print from the printer it still doesn't get recognized by openspoolman

What i ask myself, the code looks for a file in the cache folder, but the files in my case are in the root directory, what if we make a check if the file is not in the root directory, check the cache and when the cache is empty, throw a error? Or is my thinking wrong?

[Xento]

When I'm at home today I will try to implement a better path handling with fallbacks and multiple lookups.

[leutnantlurch]

Small update on my side: I started a print via bambu studio and it shows in the history with this weird qidi file name (don't know where this is comming from but the model is my sliced model)

I see the spool assigment doesn't work even if the spool is correctly assigned:

Maybe it has something to do with this issue.

[Xento]

I don't think so.
When the print is started over bambu studio it is send over the cloud and the 3mf file is downloaded from the cloud directly.
Maybe this is an issue because you have an AMS and an AMS HT.
This mqtt logs would be interesting, too as I don't have any where a spool is used from a second ams.

[leutnantlurch]

I don't think so. When the print is started over bambu studio it is send over the cloud and the 3mf file is downloaded from the cloud directly. Maybe this is an issue because you have an AMS and an AMS HT. This mqtt logs would be interesting, too as I don't have any where a spool is used from a second ams.

Do you need just the print start or a complete log of the print? If you need the complete log, would you tell me a way to log the complete print? Because the oldest logs gets overwritten

[Xento]

The start would help.
Maybe you could print the small multicolor testprint https://github.com/drndos/openspoolman/blob/main/tests/MQTT/Testqube_Multicolor.3mf
Just assign some filament from the AMS and one frome the AMS HT.
This should only take some minutes to print.

[leutnantlurch]

Okay therefore i need to change my PETG to PLA for that but I will do the testprint as soon as possible

In the meantime:

Print started from bambu studio - single color PETG printstart log:

logs_printstarted.zip

[leutnantlurch]

After finishing the multi color test, it seems that the AMS HT is really the issue, or in other words, the assignment of the spool doesn't work reliable:

And of course - the logs:

logs_multicolor.zip

Even the docker says,. that there is no assigned spool:

And this is the finished print:

Oh boy but when this whole thing works as intended, this is practically an automated inventory system (besides the manual assignment of the spools) :D