starred/bambuddy

Fork 0

mirror of https://github.com/maziggy/bambuddy.git synced 2026-05-09 05:35:30 +02:00

[GH-ISSUE #1198] [Bug]: Completion notification reports slicer-estimated duration instead of actual print time #870

New issue

Closed

opened 2026-05-06 12:33:33 +02:00 by BreizhHardware · 1 comment

BreizhHardware commented

2026-05-06 12:33:33 +02:00

Owner

Originally created by @BurntOutHylian on GitHub (May 3, 2026).
Original GitHub issue: https://github.com/maziggy/bambuddy/issues/1198

Originally assigned to: @maziggy on GitHub.

Component

Bambuddy

Bug Description

When a print completes, the duration variable in the notification is populated from print_time_seconds — the slicer's pre-print estimate parsed from the 3MF file at archive creation.

The actual elapsed time, computed from archive.started_at and archive.completed_at, is never calculated and never included in archive_data before the notification fires. Completion notifications show the wrong time for any print that diverges from the estimate — including long prints, slow first layers, and cancelled/partial prints.

Notably, actual_filament_grams is passed correctly through archive_data (line 3254–3257 falls back to usage tracker results), but no equivalent actual_time_seconds is ever computed or passed.

[main.py:3231–3232] - archive_data is built with the slicer estimate only; actual elapsed time is never computed from archive.started_at / archive.completed_at and never added to the dict

archive_data = {
    "print_time_seconds": archive.print_time_seconds,  # ← slicer estimate, not actual

[notification_service.py:891–892] - duration is set from whatever print_time_seconds is in archive_data, with no awareness of actual elapsed time:

if archive_data.get("print_time_seconds"):
    variables["duration"] = self._format_duration(archive_data["print_time_seconds"])

Expected Behavior

Print complete notifications should reflect actual print time, and not estimated print time.

Steps to Reproduce

Live Printer Method

Start a long print (3+ hours).
Cancel a print after 2 minutes. The completion notification will say the print took however long the slicer estimated (e.g. 3 hours), not 2 minutes.

Dev Backend Method

Find a completed archive with a known time gap

sqlite3 bambuddy.db "
SELECT id, print_name,
  print_time_seconds AS slicer_sec,
  CAST((julianday(completed_at)-julianday(started_at))*86400 AS INTEGER) AS actual_sec
FROM print_archives
WHERE status='completed' AND started_at IS NOT NULL AND completed_at IS NOT NULL
ORDER BY ABS(print_time_seconds - CAST((julianday(completed_at)-julianday(started_at))*86400 AS INTEGER)) DESC
LIMIT 5;

Pick one with a large gap between slicer_sec and actual_sec. Note the ID
Trigger a completion notification for the archive ID in #2

python3 -c "
import asyncio
from backend.app.core.database import async_session
from backend.app.models.archive import PrintArchive
from sqlalchemy import select

async def check():
    async with async_session() as db:
        archive = await db.get(PrintArchive, #)  # use your archive id
        print('print_time_seconds (slicer):', archive.print_time_seconds)
        if archive.started_at and archive.completed_at:
            actual = int((archive.completed_at - archive.started_at).total_seconds())
            print('actual elapsed (from timestamps):', actual)
            print('notification would say:', archive.print_time_seconds, 'but should say:', actual)

asyncio.run(check())"

If print_time_seconds != actual elapsed, and a notification was sent at completion, the notification showed the wrong value. The log from Step 2 will confirm actual_time_seconds is absent from archive_data entirely — there's no key for it, only print_time_seconds.

Printer Model

P2S

Bambuddy Version

0.2.3.2

SpoolBuddy Version

No response

Printer Firmware Version

No response

Installation Method

Docker

Operating System

Docker

Relevant Logs / Support Package

No response

Screenshots

No response

Additional Context

I honestly didn't notice this until I started using the notifications this weekend. Had a 17 hour print. Notification came in with 18 minutes.

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 @BurntOutHylian on GitHub (May 3, 2026). Original GitHub issue: https://github.com/maziggy/bambuddy/issues/1198 Originally assigned to: @maziggy on GitHub. ### Component Bambuddy ### Bug Description When a print completes, the duration variable in the notification is populated from print_time_seconds — the slicer's pre-print estimate parsed from the 3MF file at archive creation. The actual elapsed time, computed from archive.started_at and archive.completed_at, is never calculated and never included in archive_data before the notification fires. Completion notifications show the wrong time for any print that diverges from the estimate — including long prints, slow first layers, and cancelled/partial prints. Notably, actual_filament_grams is passed correctly through archive_data (line 3254–3257 falls back to usage tracker results), but no equivalent actual_time_seconds is ever computed or passed. [main.py:3231–3232] - archive_data is built with the slicer estimate only; actual elapsed time is never computed from archive.started_at / archive.completed_at and never added to the dict ``` archive_data = { "print_time_seconds": archive.print_time_seconds, # ← slicer estimate, not actual ``` [notification_service.py:891–892] - duration is set from whatever print_time_seconds is in archive_data, with no awareness of actual elapsed time: ``` if archive_data.get("print_time_seconds"): variables["duration"] = self._format_duration(archive_data["print_time_seconds"]) ``` ### Expected Behavior Print complete notifications should reflect actual print time, and not estimated print time. ### Steps to Reproduce #### Live Printer Method 1. Start a long print (3+ hours). 2. Cancel a print after 2 minutes. The completion notification will say the print took however long the slicer estimated (e.g. 3 hours), not 2 minutes. #### Dev Backend Method 1. Find a completed archive with a known time gap ``` sqlite3 bambuddy.db " SELECT id, print_name, print_time_seconds AS slicer_sec, CAST((julianday(completed_at)-julianday(started_at))*86400 AS INTEGER) AS actual_sec FROM print_archives WHERE status='completed' AND started_at IS NOT NULL AND completed_at IS NOT NULL ORDER BY ABS(print_time_seconds - CAST((julianday(completed_at)-julianday(started_at))*86400 AS INTEGER)) DESC LIMIT 5; ``` 2. Pick one with a large gap between slicer_sec and actual_sec. Note the ID 3. Trigger a completion notification for the archive ID in #2 ``` python3 -c " import asyncio from backend.app.core.database import async_session from backend.app.models.archive import PrintArchive from sqlalchemy import select async def check(): async with async_session() as db: archive = await db.get(PrintArchive, #) # use your archive id print('print_time_seconds (slicer):', archive.print_time_seconds) if archive.started_at and archive.completed_at: actual = int((archive.completed_at - archive.started_at).total_seconds()) print('actual elapsed (from timestamps):', actual) print('notification would say:', archive.print_time_seconds, 'but should say:', actual) asyncio.run(check())" ``` 4. If print_time_seconds != actual elapsed, and a notification was sent at completion, the notification showed the wrong value. The log from Step 2 will confirm actual_time_seconds is absent from archive_data entirely — there's no key for it, only print_time_seconds. ### Printer Model P2S ### Bambuddy Version 0.2.3.2 ### SpoolBuddy Version _No response_ ### Printer Firmware Version _No response_ ### Installation Method Docker ### Operating System Docker ### Relevant Logs / Support Package _No response_ ### Screenshots _No response_ ### Additional Context I honestly didn't notice this until I started using the notifications this weekend. Had a 17 hour print. Notification came in with 18 minutes. ### 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-06 12:33:33 +02:00

closed this issue
added the
bug
label

BreizhHardware commented

2026-05-06 12:33:34 +02:00

Author

Owner

@maziggy commented on GitHub (May 3, 2026):

Confirmed and fixed in dev. Diagnosis was exactly right — the {{duration}} template variable was being formatted from print_time_seconds (the slicer estimate baked into the archive at creation), never from the actual elapsed. The companion actual_filament_grams field was already getting progress-scaled for partial prints (which is why filament was right while time was wrong), so this was a missing analogous treatment for time, not a deeper architectural issue.

Two-part fix:

main.py now computes actual_time_seconds = int((completed_at - started_at).total_seconds()) from the persisted timestamps and threads it through archive_data. notification_service.py prefers it for {{duration}}, falling back to the slicer estimate only when timestamps aren't recorded for some reason.
main.py:3172 was excluding "cancelled" status from getting completed_at set (only completed/failed/aborted got a timestamp). Audited every consumer in backend + frontend — none depend on completed_at IS NULL to mean "cancelled". Adding "cancelled" to that list means queue-UI cancellations now get correct duration in the notification, and as a knock-on benefit the statistics totals aggregation (which currently adds the full slicer estimate for completed_at IS NULL rows) now adds the actual elapsed for cancelled prints too.

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

If you find Bambuddy useful, please consider giving it a ⭐ on GitHub — it helps others discover the project!

@maziggy commented on GitHub (May 3, 2026): Confirmed and fixed in dev. Diagnosis was exactly right — the {{duration}} template variable was being formatted from print_time_seconds (the slicer estimate baked into the archive at creation), never from the actual elapsed. The companion actual_filament_grams field was already getting progress-scaled for partial prints (which is why filament was right while time was wrong), so this was a missing analogous treatment for time, not a deeper architectural issue. Two-part fix: 1. main.py now computes actual_time_seconds = int((completed_at - started_at).total_seconds()) from the persisted timestamps and threads it through archive_data. notification_service.py prefers it for {{duration}}, falling back to the slicer estimate only when timestamps aren't recorded for some reason. 2. main.py:3172 was excluding "cancelled" status from getting completed_at set (only completed/failed/aborted got a timestamp). Audited every consumer in backend + frontend — none depend on completed_at IS NULL to mean "cancelled". Adding "cancelled" to that list means queue-UI cancellations now get correct duration in the notification, and as a knock-on benefit the statistics totals aggregation (which currently adds the full slicer estimate for completed_at IS NULL rows) now adds the actual elapsed for cancelled prints too. Available/Fixed in branch dev and available with the next release or daily build. Please let me know if it works for you. ----- If you find Bambuddy useful, please consider giving it a ⭐ on [GitHub](https://github.com/maziggy/bambuddy) — it helps others discover the project!

BreizhHardware referenced this issue

2026-05-06 12:35:21 +02:00

[PR #1029] [MERGED] v0.2.3 final #1149