Auto-commit: v2.10 — Docker diagnostic logging for consumer & task execution

- web/app.py: Startup banner to docker logs (Python version, platform,
  Huey version, DB paths). All print() calls now flush=True so Docker
  captures them immediately. Emoji-free for robust stdout encoding.
  Startup now detects orphaned queued runs (queue empty but DB queued)
  and resets them to 'failed' so the UI does not stay stuck on reload.
  Huey logging configured at INFO level so task pick-up/completion
  appears in `docker logs`. Consumer skip reason logged explicitly.
- web/tasks.py: generate_book_task now emits [TASK run=N] lines to
  stdout (docker logs) at pick-up, log-file creation, DB status update,
  and on error (with full traceback) so failures are always visible.

Co-Authored-By: Claude Sonnet 4.6 <noreply@anthropic.com>

web/app.py

@@ -1,4 +1,6 @@
 import os
+import sys
+import platform
 from datetime import datetime
 from sqlalchemy import text
 from flask import Flask
@@ -8,6 +10,19 @@ from web.db import db, User, Run
 from web.tasks import huey
 from core import config
 
+# Ensure stdout is UTF-8 in all environments (Docker, Windows, Raspberry Pi)
+if hasattr(sys.stdout, 'reconfigure'):
+    try:
+        sys.stdout.reconfigure(encoding='utf-8', errors='replace')
+        sys.stderr.reconfigure(encoding='utf-8', errors='replace')
+    except Exception:
+        pass
+
+def _log(msg):
+    """Print to stdout with flush so Docker logs capture it immediately."""
+    print(msg, flush=True)
+
+
 # Calculate paths relative to this file (web/app.py -> project root is two levels up)
 BASE_DIR = os.path.dirname(os.path.dirname(os.path.abspath(__file__)))
 TEMPLATE_DIR = os.path.join(BASE_DIR, 'templates')
@@ -48,6 +63,22 @@ app.register_blueprint(persona_bp)
 app.register_blueprint(admin_bp)
 
 
+# --- STARTUP DIAGNOSTIC BANNER ---
+_log("=" * 60)
+_log(f"BookApp v{config.VERSION} starting up")
+_log(f"  Python   : {sys.version}")
+_log(f"  Platform : {platform.platform()}")
+_log(f"  Data dir : {config.DATA_DIR}")
+_log(f"  Queue db : {os.path.join(config.DATA_DIR, 'queue.db')}")
+_log(f"  App db   : {os.path.join(config.DATA_DIR, 'bookapp.db')}")
+try:
+    import huey as _huey_pkg
+    _log(f"  Huey     : {_huey_pkg.__version__}")
+except Exception:
+    _log("  Huey     : (version unknown)")
+_log("=" * 60)
+
+
 # --- SETUP ---
 with app.app_context():
     db.create_all()
@@ -56,38 +87,50 @@ with app.app_context():
     if config.ADMIN_USER and config.ADMIN_PASSWORD:
         admin = User.query.filter_by(username=config.ADMIN_USER).first()
         if not admin:
-            print(f"🔐 System: Creating Admin User '{config.ADMIN_USER}' from environment variables.")
+            _log(f"System: Creating Admin User '{config.ADMIN_USER}' from environment variables.")
             admin = User(username=config.ADMIN_USER, password=generate_password_hash(config.ADMIN_PASSWORD, method='pbkdf2:sha256'), is_admin=True)
             db.session.add(admin)
             db.session.commit()
         else:
-            print(f"🔐 System: Syncing Admin User '{config.ADMIN_USER}' settings from environment.")
+            _log(f"System: Syncing Admin User '{config.ADMIN_USER}' settings from environment.")
             if not admin.is_admin: admin.is_admin = True
             admin.password = generate_password_hash(config.ADMIN_PASSWORD, method='pbkdf2:sha256')
             db.session.add(admin)
             db.session.commit()
     elif not User.query.filter_by(is_admin=True).first():
-        print("ℹ️ System: No Admin credentials found in environment variables. Admin account not created.")
+        _log("System: No Admin credentials found in environment variables. Admin account not created.")
 
     # Migration: Add 'progress' column if missing
     try:
         with db.engine.connect() as conn:
             conn.execute(text("ALTER TABLE run ADD COLUMN progress INTEGER DEFAULT 0"))
             conn.commit()
-            print("✅ System: Added 'progress' column to Run table.")
+            _log("System: Added 'progress' column to Run table.")
     except: pass
 
     # Reset stuck runs on startup
     try:
         stuck_runs = Run.query.filter_by(status='running').all()
         if stuck_runs:
-            print(f"⚠️ System: Found {len(stuck_runs)} stuck runs. Resetting to 'failed'.")
+            _log(f"System: Found {len(stuck_runs)} stuck run(s) — resetting to 'failed'.")
             for r in stuck_runs:
                 r.status = 'failed'
                 r.end_time = datetime.utcnow()
             db.session.commit()
+        # Also reset stuck 'queued' runs whose task entry was lost from queue.db
+        import sqlite3 as _sqlite3
+        _queue_path = os.path.join(config.DATA_DIR, 'queue.db')
+        if os.path.exists(_queue_path):
+            with _sqlite3.connect(_queue_path, timeout=5) as _qconn:
+                pending_count = _qconn.execute("SELECT COUNT(*) FROM task").fetchone()[0]
+            queued_runs = Run.query.filter_by(status='queued').count()
+            _log(f"System: Queue has {pending_count} pending task(s), DB has {queued_runs} queued run(s).")
+            if queued_runs > 0 and pending_count == 0:
+                _log("System: WARNING — queued runs exist but queue is empty (tasks lost). Resetting to 'failed'.")
+                Run.query.filter_by(status='queued').update({'status': 'failed', 'end_time': datetime.utcnow()})
+                db.session.commit()
     except Exception as e:
-        print(f"⚠️ System: Failed to clean up stuck runs: {e}")
+        _log(f"System: Startup cleanup error: {e}")
 
 
 # --- HUEY CONSUMER ---
@@ -98,23 +141,28 @@ import threading as _threading
 
 def _start_huey_consumer():
     import logging as _logging
-    _logging.basicConfig(level=_logging.WARNING)
+    # INFO level so task pick-up/completion appears in docker logs
+    _logging.basicConfig(
+        level=_logging.INFO,
+        format='[%(asctime)s] HUEY %(levelname)s | %(message)s',
+        datefmt='%H:%M:%S',
+        stream=sys.stdout,
+        force=True,
+    )
     try:
         from huey.consumer import Consumer
+        # NOTE: Huey 2.6.0 does NOT accept a `loglevel` kwarg — omit it.
         consumer = Consumer(huey, workers=1, worker_type='thread')
-        print("System: Huey task consumer started.")
-        consumer.run()
+        _log("System: Huey task consumer started successfully.")
+        consumer.run()  # blocks until app exits
     except Exception as e:
-        msg = f"System: Huey consumer failed to start: {e}"
-        print(msg)
-        # Write the error to a persistent log so it is visible even when stdout is lost
+        msg = f"System: Huey consumer FAILED to start: {type(e).__name__}: {e}"
+        _log(msg)
+        # Also write to a persistent file for diagnosis when stdout is piped away
         try:
-            import os as _os
-            from core import config as _cfg
-            _err_path = _os.path.join(_cfg.DATA_DIR, "consumer_error.log")
+            _err_path = os.path.join(config.DATA_DIR, "consumer_error.log")
             with open(_err_path, 'a', encoding='utf-8') as _f:
-                import datetime as _dt
-                _f.write(f"[{_dt.datetime.now()}] {msg}\n")
+                _f.write(f"[{datetime.utcnow().isoformat()}] {msg}\n")
         except Exception:
             pass
 
@@ -122,8 +170,11 @@ _is_reloader_child = os.environ.get('WERKZEUG_RUN_MAIN') == 'true'
 _is_testing = os.environ.get('FLASK_TESTING') == '1'
 
 if not _is_reloader_child and not _is_testing:
+    _log("System: Launching Huey consumer thread...")
     _huey_thread = _threading.Thread(target=_start_huey_consumer, daemon=True, name="huey-consumer")
     _huey_thread.start()
+else:
+    _log(f"System: Skipping Huey consumer (WERKZEUG_RUN_MAIN={os.environ.get('WERKZEUG_RUN_MAIN')}, FLASK_TESTING={os.environ.get('FLASK_TESTING')}).")
 
 
 if __name__ == "__main__":