Issue 1: Print Start Notification - Estimated Time Unknown

Problem: At print start, the MQTT mc_remaining_time was often 0 or unavailable because the printer hadn't fully processed the gcode yet.

  Solution: Modified the notification system to prioritize the print_time_seconds from the 3MF file parsing (which is always available after archive creation) over the
  MQTT remaining time.

  Files changed:
  - backend/app/services/notification_service.py:
    - Added optional archive_data parameter to on_print_start() method
    - Added priority logic: archive data > MQTT remaining_time > raw_data mc_remaining_time
  - backend/app/main.py:
    - Created _send_print_start_notification() helper function
    - Moved notification sending to AFTER archive creation (when print_time_seconds is available)
    - Added fallback notification sending at early return points (auto_archive disabled, file not found, etc.)

  Issue 2: Timelapse Auto-Assignment

  Problem: Timelapses couldn't be auto-assigned reliably because printer dates could be off in LAN-only mode, making timestamp matching unreliable.

  Solution: Track whether timelapse recording was active during the print via MQTT, and if so, auto-fetch the most recent timelapse file on print completion.

  Files changed:
  - backend/app/services/bambu_mqtt.py:
    - Added _timelapse_during_print instance variable
    - Track when timelapse is active during a print (in both data and xcam parsing)
    - Reset the flag on new print start
    - Include timelapse_was_active in the print complete callback data
  - backend/app/main.py:
    - Added timelapse auto-scan logic in on_print_complete()
    - If timelapse_was_active is True and status is "completed":
        - Wait 5 seconds for timelapse to finalize
      - Scan printer's timelapse directory
      - Find most recent file by mtime
      - Verify it was modified within 30 minutes of print completion
      - Download and attach to archive
      - Send WebSocket update
This commit is contained in:
maziggy
2025-12-12 15:35:46 +01:00
parent 3a0890145b
commit ee2b674278
3 changed files with 189 additions and 15 deletions
+138 -8
View File
@@ -298,14 +298,17 @@ async def on_ams_change(printer_id: int, ams_data: list):
logging.getLogger(__name__).warning(f"Spoolman AMS sync failed: {e}")
async def on_print_start(printer_id: int, data: dict):
"""Handle print start - archive the 3MF file immediately."""
import logging
logger = logging.getLogger(__name__)
async def _send_print_start_notification(
printer_id: int,
data: dict,
archive_data: dict | None = None,
logger=None,
):
"""Helper to send print start notification with optional archive data."""
if logger is None:
import logging
logger = logging.getLogger(__name__)
await ws_manager.send_print_start(printer_id, data)
# Send print start notifications FIRST (before any early returns)
try:
async with async_session() as db:
from backend.app.models.printer import Printer
@@ -314,10 +317,23 @@ async def on_print_start(printer_id: int, data: dict):
)
printer = result.scalar_one_or_none()
printer_name = printer.name if printer else f"Printer {printer_id}"
await notification_service.on_print_start(printer_id, printer_name, data, db)
await notification_service.on_print_start(
printer_id, printer_name, data, db, archive_data=archive_data
)
except Exception as e:
logger.warning(f"Notification on_print_start failed: {e}")
async def on_print_start(printer_id: int, data: dict):
"""Handle print start - archive the 3MF file immediately."""
import logging
logger = logging.getLogger(__name__)
await ws_manager.send_print_start(printer_id, data)
# Track if notification was sent (to avoid sending twice)
notification_sent = False
# Smart plug automation: turn on plug when print starts
try:
async with async_session() as db:
@@ -335,6 +351,9 @@ async def on_print_start(printer_id: int, data: dict):
printer = result.scalar_one_or_none()
if not printer or not printer.auto_archive:
# Send notification without archive data (auto-archive disabled)
if not notification_sent:
await _send_print_start_notification(printer_id, data, logger=logger)
return
# Get the filename and subtask_name
@@ -344,6 +363,9 @@ async def on_print_start(printer_id: int, data: dict):
logger.info(f"Print start detected - filename: {filename}, subtask: {subtask_name}")
if not filename and not subtask_name:
# Send notification without archive data (no filename)
if not notification_sent:
await _send_print_start_notification(printer_id, data, logger=logger)
return
# Check if this is an expected print from reprint/scheduled
@@ -417,6 +439,11 @@ async def on_print_start(printer_id: int, data: dict):
"status": "printing",
})
# Send notification with archive data (reprint/scheduled)
if not notification_sent:
archive_data = {"print_time_seconds": archive.print_time_seconds}
await _send_print_start_notification(printer_id, data, archive_data, logger)
return # Skip creating a new archive
# Check if there's already a "printing" archive for this printer/file
@@ -450,6 +477,10 @@ async def on_print_start(printer_id: int, data: dict):
logger.info(f"Recorded starting energy for existing archive {existing_archive.id}: {energy['total']} kWh")
except Exception as e:
logger.warning(f"Failed to record starting energy for existing archive: {e}")
# Send notification with archive data (existing archive)
if not notification_sent:
archive_data = {"print_time_seconds": existing_archive.print_time_seconds}
await _send_print_start_notification(printer_id, data, archive_data, logger)
return
# Build list of possible 3MF filenames to try
@@ -543,6 +574,9 @@ async def on_print_start(printer_id: int, data: dict):
if not downloaded_filename or not temp_path:
logger.warning(f"Could not find 3MF file for print: {filename or subtask_name}")
# Send notification without archive data (file not found)
if not notification_sent:
await _send_print_start_notification(printer_id, data, logger=logger)
return
try:
@@ -591,6 +625,12 @@ async def on_print_start(printer_id: int, data: dict):
"print_name": archive.print_name,
"status": archive.status,
})
# Send notification with archive data (new archive created)
if not notification_sent:
archive_data = {"print_time_seconds": archive.print_time_seconds}
await _send_print_start_notification(printer_id, data, archive_data, logger)
notification_sent = True
finally:
if temp_path and temp_path.exists():
temp_path.unlink()
@@ -913,6 +953,96 @@ async def on_print_complete(printer_id: int, data: dict):
import logging
logging.getLogger(__name__).warning(f"Maintenance notification check failed: {e}")
# Auto-scan for timelapse if recording was active during the print
if archive_id and data.get("timelapse_was_active") and data.get("status") == "completed":
logger.info(f"[TIMELAPSE] Timelapse was active during print, auto-scanning for archive {archive_id}")
try:
# Small delay to allow timelapse file to be finalized
await asyncio.sleep(5)
async with async_session() as db:
from backend.app.models.printer import Printer
from backend.app.models.archive import PrintArchive
from backend.app.services.archive import ArchiveService
from backend.app.services.bambu_ftp import list_files_async, download_file_bytes_async
from pathlib import Path
import re
from datetime import timedelta
# Get archive
service = ArchiveService(db)
archive = await service.get_archive(archive_id)
if not archive:
logger.warning(f"[TIMELAPSE] Archive {archive_id} not found")
elif archive.timelapse_path:
logger.info(f"[TIMELAPSE] Archive {archive_id} already has timelapse attached")
elif not archive.printer_id:
logger.warning(f"[TIMELAPSE] Archive {archive_id} has no printer")
else:
# Get printer
result = await db.execute(select(Printer).where(Printer.id == archive.printer_id))
printer = result.scalar_one_or_none()
if printer:
# Scan timelapse directory on printer
files = []
for timelapse_path in ["/timelapse", "/timelapse/video"]:
try:
files = await list_files_async(printer.ip_address, printer.access_code, timelapse_path)
if files:
break
except Exception:
continue
if files:
mp4_files = [f for f in files if not f.get("is_directory") and f.get("name", "").endswith(".mp4")]
# Strategy: Find most recent timelapse by mtime
# Since we know timelapse was active during this print, use the most recent file
if mp4_files:
# Sort by mtime descending
mp4_files_with_mtime = [f for f in mp4_files if f.get("mtime")]
if mp4_files_with_mtime:
mp4_files_with_mtime.sort(key=lambda x: x.get("mtime"), reverse=True)
most_recent = mp4_files_with_mtime[0]
# Verify the file was modified within reasonable time of print completion
file_mtime = most_recent.get("mtime")
archive_completed = archive.completed_at or datetime.now()
if file_mtime and abs(file_mtime - archive_completed) < timedelta(minutes=30):
# Download and attach
logger.info(f"[TIMELAPSE] Downloading timelapse {most_recent['name']} for archive {archive_id}")
remote_path = most_recent.get('path') or f"/timelapse/{most_recent['name']}"
timelapse_data = await download_file_bytes_async(
printer.ip_address, printer.access_code, remote_path
)
if timelapse_data:
success = await service.attach_timelapse(
archive_id, timelapse_data, most_recent["name"]
)
if success:
logger.info(f"[TIMELAPSE] Successfully attached timelapse to archive {archive_id}")
await ws_manager.send_archive_updated({
"id": archive_id,
"timelapse_attached": True,
})
else:
logger.warning(f"[TIMELAPSE] Failed to attach timelapse to archive {archive_id}")
else:
logger.warning(f"[TIMELAPSE] Failed to download timelapse file")
else:
logger.info(f"[TIMELAPSE] Most recent timelapse mtime too far from print completion")
else:
logger.info(f"[TIMELAPSE] No timelapse files with mtime found")
else:
logger.info(f"[TIMELAPSE] No timelapse files found on printer")
else:
logger.warning(f"[TIMELAPSE] Printer not found for archive {archive_id}")
except Exception as e:
import logging
logging.getLogger(__name__).warning(f"Timelapse auto-scan failed: {e}")
# Update queue item if this was a scheduled print
try:
async with async_session() as db:
+14 -1
View File
@@ -250,6 +250,7 @@ class BambuMQTTClient:
self._previous_gcode_file: str | None = None
self._was_running: bool = False # Track if we've seen RUNNING state for current print
self._completion_triggered: bool = False # Prevent duplicate completion triggers
self._timelapse_during_print: bool = False # Track if timelapse was active during this print
self._message_log: deque[MQTTLogEntry] = deque(maxlen=100)
self._logging_enabled: bool = False
self._last_message_time: float = 0.0 # Track when we last received a message
@@ -624,6 +625,9 @@ class BambuMQTTClient:
self.state.ipcam = xcam_data.get("ipcam_record") == "enable"
if "timelapse" in xcam_data:
self.state.timelapse = xcam_data.get("timelapse") == "enable"
# Track if timelapse was ever active during this print
if self.state.timelapse and self._was_running:
self._timelapse_during_print = True
# Skip spaghetti_detector boolean field - we read from cfg bitmask above
if "print_halt" in xcam_data:
@@ -1247,6 +1251,9 @@ class BambuMQTTClient:
if "timelapse" in data:
logger.debug(f"[{self.serial_number}] timelapse field: {data['timelapse']}")
self.state.timelapse = data["timelapse"] is True
# Track if timelapse was ever active during this print
if self.state.timelapse and self._was_running:
self._timelapse_during_print = True
# Parse ipcam/live view status
if "ipcam" in data:
@@ -1377,6 +1384,8 @@ class BambuMQTTClient:
# Reset completion tracking for new print
self._was_running = True
self._completion_triggered = False
# Reset timelapse tracking - will be set to True if timelapse is detected during print
self._timelapse_during_print = False
if (is_new_print or is_file_change) and self.on_print_start:
logger.info(
@@ -1421,15 +1430,19 @@ class BambuMQTTClient:
logger.info(
f"[{self.serial_number}] PRINT COMPLETE detected - state: {self.state.state}, "
f"status: {status}, file: {self._previous_gcode_file or current_file}, "
f"subtask: {self.state.subtask_name}, was_running: {self._was_running}"
f"subtask: {self.state.subtask_name}, was_running: {self._was_running}, "
f"timelapse_during_print: {self._timelapse_during_print}"
)
timelapse_was_active = self._timelapse_during_print
self._completion_triggered = True
self._was_running = False
self._timelapse_during_print = False # Reset for next print
self.on_print_complete({
"status": status,
"filename": self._previous_gcode_file or current_file,
"subtask_name": self.state.subtask_name,
"raw_data": data,
"timelapse_was_active": timelapse_was_active,
})
self._previous_gcode_state = self.state.state
+37 -6
View File
@@ -549,9 +549,22 @@ class NotificationService:
)
async def on_print_start(
self, printer_id: int, printer_name: str, data: dict, db: AsyncSession
self,
printer_id: int,
printer_name: str,
data: dict,
db: AsyncSession,
archive_data: dict | None = None,
):
"""Handle print start event - send notifications to relevant providers."""
"""Handle print start event - send notifications to relevant providers.
Args:
printer_id: The printer ID
printer_name: The printer name
data: MQTT event data with filename, subtask_name, remaining_time, raw_data
db: Database session
archive_data: Optional archive data with print_time_seconds from 3MF parsing
"""
logger.info(f"on_print_start called for printer {printer_id} ({printer_name})")
providers = await self._get_providers_for_event(db, "on_print_start", printer_id)
if not providers:
@@ -566,12 +579,30 @@ class NotificationService:
else:
filename = self._clean_filename(data.get("filename", "Unknown"))
# remaining_time can be passed directly, or look in raw_data at top level
# mc_remaining_time is in minutes in MQTT data
estimated_time = data.get("remaining_time")
# Priority for estimated_time:
# 1. Archive's print_time_seconds from 3MF parsing (most reliable)
# 2. MQTT remaining_time (may be 0 at print start)
# 3. raw_data mc_remaining_time
estimated_time = None
# Try archive data first (from 3MF parsing - most reliable)
if archive_data and archive_data.get("print_time_seconds"):
estimated_time = archive_data["print_time_seconds"]
logger.debug(f"Using print_time_seconds from archive: {estimated_time}")
# Fall back to MQTT remaining_time
if estimated_time is None:
estimated_time = data.get("remaining_time")
if estimated_time:
logger.debug(f"Using remaining_time from MQTT: {estimated_time}")
# Last resort: raw_data mc_remaining_time (in minutes, convert to seconds)
if estimated_time is None:
raw_time = data.get("raw_data", {}).get("mc_remaining_time")
estimated_time = raw_time * 60 if raw_time else None
if raw_time:
estimated_time = raw_time * 60
logger.debug(f"Using mc_remaining_time from raw_data: {estimated_time}")
time_str = self._format_duration(estimated_time)
variables = {