starred/bambuddy-maziggy-1

Fork 0

mirror of https://github.com/maziggy/bambuddy.git synced 2026-05-09 08:25:54 +02:00

[GH-ISSUE #897] [Bug]: Failed SQLite state updates create "ghost" jobs, causing UI to show false double-assignments #618

New issue

Closed

opened 2026-05-07 00:12:08 +02:00 by BreizhHardware · 2 comments

BreizhHardware commented

2026-05-07 00:12:08 +02:00

Owner

Originally created by @stringham on GitHub (Apr 5, 2026).
Original GitHub issue: https://github.com/maziggy/bambuddy/issues/897

Originally assigned to: @maziggy on GitHub.

Bug Description

When a print physically finishes, a background task attempts to update the job state in the database from printing to completed. If this update fails due to an SQLite lock, the job becomes a "ghost" job permanently stuck in the printing state.

When the user subsequently clears the build plate via the API, the queue dispatcher sees the physical hardware is ready and correctly dispatches the next job. However, because the previous job's state was never resolved, the database now has multiple jobs concurrently marked as printing on the exact same printer_id. This causes the print queue to look like the printer has been double-assigned, even though physically only one job is running.

Expected Behavior

Background tasks handling state changes (like print completion and runtime tracking) need retry logic if they hit an SQLite database is locked error. The database state must accurately reflect reality so that finished prints reliably transition out of the printing state.

Steps to Reproduce

Because this relies on a database concurrency lock, it is difficult to reproduce manually, but the sequence of events is:

Job A physically finishes on the printer.
Bambuddy's background worker attempts to update Job A to completed and update runtime stats.
An SQLite lock prevents the database write, leaving Job A stuck as printing in the DB.
The user uses the API to 'Clear the Plate'.
The queue dispatcher reads the physical 'Idle/Ready' state and properly dispatches Job B.
The database now incorrectly shows both Job A and Job B as printing on the same printer.

Printer Model

P1S

Bambuddy Version

v0.2.2.2

Printer Firmware Version

01.09.01.00

Installation Method

Docker

Operating System

Linux (Ubuntu/Debian)

Relevant Logs / Support Package

I was able to track this exact sequence of events down in my database and application logs.

The False Double Assignment:
Job 287 successfully finished printing physically, but was never cleared from the database. When I cleared the plate roughly three hours later, Job 291 was correctly dispatched to the idle printer (Printer 1).

Querying the database for active jobs shows the ghost job collision:
select id, printer_id, target_model, archive_id, library_file_id, position, plate_id, status, started_at, created_at from print_queue where status="printing" order by id desc;

id	printer_id	target_model	archive_id	library_file_id	position	plate_id	status	started_at	created_at
292	2	P1S	246	4	11	1	`printing`	2026-04-05 16:48:09.818015	2026-04-05 02:27:17
291	1	P1S	245	5	10	10	`printing`	2026-04-05 16:46:06.499217	2026-04-05 02:27:00
290	3	P1S	244	5	9	9	`printing`	2026-04-05 16:44:26.513284	2026-04-05 02:27:00
287	1	P1S	241	5	6	6	`printing`	2026-04-05 13:58:34.058061	2026-04-05 02:26:59

Job 291 is the new job actually printing, job 287 is the ghost job that is physically finished.

The Root Cause (SQLite Locks):
Checking the docker logs during the dispatch window reveals the background workers hitting OperationalError: database is locked exactly when state updates are attempting to process:

2026-04-05 10:45:56,880 WARNING [backend.app.main] Runtime tracking failed: (sqlite3.OperationalError) database is locked
[SQL: UPDATE printers SET runtime_seconds=?, last_runtime_update=?, updated_at=CURRENT_TIMESTAMP WHERE printers.id = ?]

2026-04-05 10:47:12,372 WARNING [backend.app.main] Runtime tracking failed: (sqlite3.OperationalError) database is locked
[SQL: UPDATE printers SET runtime_seconds=?, last_runtime_update=?, updated_at=CURRENT_TIMESTAMP WHERE printers.id = ?]

2026-04-05 10:47:12,372 WARNING [backend.app.main] AMS history recording failed: (sqlite3.OperationalError) database is locked
[SQL: INSERT INTO ams_sensor_history (printer_id, ams_id, humidity, humidity_raw, temperature) VALUES (?, ?, ?, ?, ?) RETURNING id, recorded_at]

Path Extraction Errors:
During this same window, there is a recurring path parsing error. The system seems to be trying to extract print times by passing the root /app/data directory instead of a specific file path. I am not sure if this is contributing to the database lock or preventing job resolution, but it happens concurrently:

2026-04-05 10:47:12,245 WARNING [backend.app.api.routes.print_queue] Failed to extract print time from /app/data: [Errno 21] Is a directory: '/app/data'

Screenshots

No response

Additional Context

No response

Checklist

I have searched existing issues to ensure this bug hasn't already been reported
I am using the latest version of Bambuddy
My printer is set to LAN Only mode
My printer has Developer Mode enabled

Originally created by @stringham on GitHub (Apr 5, 2026). Original GitHub issue: https://github.com/maziggy/bambuddy/issues/897 Originally assigned to: @maziggy on GitHub. ### Bug Description When a print physically finishes, a background task attempts to update the job state in the database from `printing` to `completed`. If this update fails due to an SQLite lock, the job becomes a "ghost" job permanently stuck in the `printing` state. When the user subsequently clears the build plate via the API, the queue dispatcher sees the physical hardware is ready and correctly dispatches the next job. However, because the previous job's state was never resolved, the database now has multiple jobs concurrently marked as `printing` on the exact same `printer_id`. This causes the print queue to look like the printer has been double-assigned, even though physically only one job is running. ### Expected Behavior Background tasks handling state changes (like print completion and runtime tracking) need retry logic if they hit an SQLite database is locked error. The database state must accurately reflect reality so that finished prints reliably transition out of the printing state. ### Steps to Reproduce Because this relies on a database concurrency lock, it is difficult to reproduce manually, but the sequence of events is: 1. Job A physically finishes on the printer. 2. Bambuddy's background worker attempts to update Job A to completed and update runtime stats. 3. An SQLite lock prevents the database write, leaving Job A stuck as printing in the DB. 4. The user uses the API to 'Clear the Plate'. 5. The queue dispatcher reads the physical 'Idle/Ready' state and properly dispatches Job B. 6. The database now incorrectly shows both Job A and Job B as printing on the same printer. ### Printer Model P1S ### Bambuddy Version v0.2.2.2 ### Printer Firmware Version 01.09.01.00 ### Installation Method Docker ### Operating System Linux (Ubuntu/Debian) ### Relevant Logs / Support Package I was able to track this exact sequence of events down in my database and application logs. **The False Double Assignment:** Job 287 successfully finished printing physically, but was never cleared from the database. When I cleared the plate roughly three hours later, Job 291 was correctly dispatched to the idle printer (Printer 1). Querying the database for active jobs shows the ghost job collision: `select id, printer_id, target_model, archive_id, library_file_id, position, plate_id, status, started_at, created_at from print_queue where status="printing" order by id desc;` | id | printer_id | target_model | archive_id | library_file_id | position | plate_id | status | started_at | created_at | | :--- | :--- | :--- | :--- | :--- | :--- | :--- | :--- | :--- | :--- | | **292** | 2 | P1S | 246 | 4 | 11 | 1 | `printing` | 2026-04-05 16:48:09.818015 | 2026-04-05 02:27:17 | | **291** | 1 | P1S | 245 | 5 | 10 | 10 | `printing` | 2026-04-05 16:46:06.499217 | 2026-04-05 02:27:00 | | **290** | 3 | P1S | 244 | 5 | 9 | 9 | `printing` | 2026-04-05 16:44:26.513284 | 2026-04-05 02:27:00 | | **287** | 1 | P1S | 241 | 5 | 6 | 6 | `printing` | 2026-04-05 13:58:34.058061 | 2026-04-05 02:26:59 | Job 291 is the new job actually printing, job 287 is the ghost job that is physically finished. **The Root Cause (SQLite Locks):** Checking the docker logs during the dispatch window reveals the background workers hitting OperationalError: database is locked exactly when state updates are attempting to process: ``` 2026-04-05 10:45:56,880 WARNING [backend.app.main] Runtime tracking failed: (sqlite3.OperationalError) database is locked [SQL: UPDATE printers SET runtime_seconds=?, last_runtime_update=?, updated_at=CURRENT_TIMESTAMP WHERE printers.id = ?] 2026-04-05 10:47:12,372 WARNING [backend.app.main] Runtime tracking failed: (sqlite3.OperationalError) database is locked [SQL: UPDATE printers SET runtime_seconds=?, last_runtime_update=?, updated_at=CURRENT_TIMESTAMP WHERE printers.id = ?] 2026-04-05 10:47:12,372 WARNING [backend.app.main] AMS history recording failed: (sqlite3.OperationalError) database is locked [SQL: INSERT INTO ams_sensor_history (printer_id, ams_id, humidity, humidity_raw, temperature) VALUES (?, ?, ?, ?, ?) RETURNING id, recorded_at] ``` **Path Extraction Errors:** During this same window, there is a recurring path parsing error. The system seems to be trying to extract print times by passing the root /app/data directory instead of a specific file path. I am not sure if this is contributing to the database lock or preventing job resolution, but it happens concurrently: ``` 2026-04-05 10:47:12,245 WARNING [backend.app.api.routes.print_queue] Failed to extract print time from /app/data: [Errno 21] Is a directory: '/app/data' ``` ### Screenshots _No response_ ### Additional Context _No response_ ### Checklist - [x] I have searched existing issues to ensure this bug hasn't already been reported - [x] I am using the latest version of Bambuddy - [x] My printer is set to LAN Only mode - [x] My printer has Developer Mode enabled

BreizhHardware

2026-05-07 00:12:08 +02:00

closed this issue
added the
bug
label

BreizhHardware commented

2026-05-07 00:12:09 +02:00

Author

Owner

@maziggy commented on GitHub (Apr 7, 2026):

Thank you very much for your investigations and this perfect bug report :)

@maziggy commented on GitHub (Apr 7, 2026): Thank you very much for your investigations and this perfect bug report :)

BreizhHardware commented

2026-05-07 00:12:09 +02:00

Author

Owner

@maziggy commented on GitHub (Apr 7, 2026):

Available/Fixed in branch dev and available with the next release or daily build. Please let me know if it works now.

@maziggy commented on GitHub (Apr 7, 2026): Available/Fixed in branch dev and available with the next release or daily build. Please let me know if it works now.