pulse-monitor/pulseox-monitor.go

package main

import (
	"fmt"
	"image"
	"os"
	"os/signal"
	"strings"
	"syscall"
	"time"

	"gocv.io/x/gocv"
)

const VERSION = "v4.0-gemini"

// Threshold for binary conversion - lower values capture fainter displays
const BINARY_THRESHOLD = 180

// Global debug flag
var DEBUG_MODE = false

// Global timing flag
var TIMING_MODE = false

func main() {
	// Check for /help flag first
	for _, arg := range os.Args[1:] {
		if arg == "/help" || arg == "--help" || arg == "-h" {
			showHelp()
			return
		}
	}

	logMessage(Console, Info, "=== Pulse-Ox Monitor %s (Unified Detection) ===", VERSION)
	logMessage(Console, Info, "")

	// Note: gocv.SetNumThreads(1) removed - not available in gocv v0.31.0
	// Small images (280x200px) don't benefit much from multi-threading anyway
	logMessage(Console, Info, "🔧 OpenCV initialized")
	logMessage(Console, Info, "")

	// Check for flags
	for _, arg := range os.Args[1:] {
		if arg == "/debug" {
			DEBUG_MODE = true
			DEBUG = true // Also enable detection.go debug
			logMessage(Console, Info, "🐛 DEBUG MODE ENABLED")
		} else if arg == "/timing" {
			TIMING_MODE = true
			logMessage(Console, Info, "⏱️  TIMING MODE ENABLED")
		}
	}

	// Check if running in single-frame test mode
	if len(os.Args) >= 2 {
		// Filter out flags
		framePath := ""
		for _, arg := range os.Args[1:] {
			if arg != "/debug" && arg != "/timing" {
				framePath = arg
				break
			}
		}
		if framePath != "" {
			runSingleFrameMode(framePath)
			return
		}
	}

	// Normal streaming mode
	runStreamingMode()
}

func showHelp() {
	logMessage(Console, Info, "=== Pulse-Ox Monitor %s ===", VERSION)
	logMessage(Console, Info, "")
	logMessage(Console, Info, "USAGE:")
	logMessage(Console, Info, "  pulseox-monitor [options] [framefile]")
	logMessage(Console, Info, "")
	logMessage(Console, Info, "OPTIONS:")
	logMessage(Console, Info, "  /help     Show this help message")
	logMessage(Console, Info, "  /debug    Enable debug mode (extra diagnostic output)")
	logMessage(Console, Info, "  /timing   Show timing table for performance analysis")
	logMessage(Console, Info, "")
	logMessage(Console, Info, "MODES:")
	logMessage(Console, Info, "  No arguments     - Run in streaming mode (RTSP camera)")
	logMessage(Console, Info, "  [framefile]      - Test mode: process single PNG file")
	logMessage(Console, Info, "")
	logMessage(Console, Info, "EXAMPLES:")
	logMessage(Console, Info, "  pulseox-monitor                           # Normal streaming")
	logMessage(Console, Info, "  pulseox-monitor /debug                    # Streaming with debug output")
	logMessage(Console, Info, "  pulseox-monitor /timing                   # Show performance timing")
	logMessage(Console, Info, "  pulseox-monitor raw_frames/thresh_*.png   # Test single frame")
	logMessage(Console, Info, "")
	logMessage(Console, Info, "OUTPUT:")
	logMessage(Console, Info, "  review/           - Processed frame images and review.html")
	logMessage(Console, Info, "  raw_frames/       - Failed recognition frames (for debugging)")
	logMessage(Console, Info, "  test_output/      - Layout detection debug images")
	logMessage(Console, Info, "  pulse-monitor_*.log - Detailed execution log")
	logMessage(Console, Info, "")
}

func runSingleFrameMode(framePath string) {
	logMessage(Console, Info, "=== Single Frame Test Mode ===")
	logMessage(Console, Info, "Loading frame: %s", framePath)
	logMessage(Console, Info, "")

	// Automatically enable DEBUG_MODE for file processing
	DEBUG_MODE = true
	DEBUG = true // detection.go debug flag
	logMessage(Console, Info, "🐛 DEBUG MODE AUTO-ENABLED (file processing)")
	logMessage(Console, Info, "")

	// In test mode, all output goes to console only (no separate file log)
	// Leave globalLogger as nil to avoid duplication when using Both target
	globalLogger = nil

	// Setup
	os.MkdirAll("test_output", 0755)
	os.MkdirAll("review", 0755)

	// Reset OCR cache
	ResetOCRCache()

	// Create frame source
	source := NewFileSource(framePath)
	defer source.Close()

	// Create processor
	processor := NewProcessor(nil, nil)
	state := NewProcessingState()

	// Process single frame with unified loop
	processFrames(source, processor, state)

	logMessage(Console, Info, "")
	logMessage(Console, Info, "✓ Single frame test complete")
	logMessage(Console, Info, "")
	logMessage(Console, Info, "=== OUTPUT FILES ===")
	logMessage(Console, Info, "Test outputs:")
	logMessage(Console, Info, "  test_output/layout_boxes.jpg - Layout visualization")
	logMessage(Console, Info, "  review/f*_spo2_full.png - SpO2 recognition")
	logMessage(Console, Info, "  review/f*_hr_full.png - HR recognition")
}

func runStreamingMode() {
	// Create log file
	logFilename := fmt.Sprintf("pulse-monitor_%s.log", time.Now().Format("20060102_150405"))
	logFile, err := os.OpenFile(logFilename, os.O_CREATE|os.O_WRONLY|os.O_APPEND, 0644)
	if err != nil {
		logMessage(Console, Warning, "Warning: Could not create log file: %v", err)
		logMessage(Console, Info, "Continuing without file logging...")
		logMessage(Console, Info, "")
		globalLogger = nil
	} else {
		defer logFile.Close()
		globalLogger = logFile
		logMessage(Both, Info, "📝 Logging to: %s", logFilename)
	}

	// Setup directories - clean output directories in streaming mode
	logMessage(Console, Info, "🗑️  Cleaning output directories...")

	logMessage(Console, Info, "   - review/... ✓")
	os.RemoveAll("review")

	logMessage(Console, Info, "   - raw_frames/... ✓")
	os.RemoveAll("raw_frames")

	logMessage(Console, Info, "   - test_output/... ✓")
	os.RemoveAll("test_output")

	os.MkdirAll("review", 0755)
	os.MkdirAll("raw_frames", 0755)
	os.MkdirAll("test_output", 0755)
	logMessage(Console, Info, "")

	// Initialize live review HTML
	if err := initReviewHTML(); err != nil {
		logMessage(Console, Warning, "Warning: Could not initialize review HTML: %v", err)
	} else {
		logMessage(Console, Info, "✅ Live review HTML initialized: review/review.html (refresh browser to see updates)")
	}

	// Start review server
	startReviewServer()
	defer stopReviewServer()

	// Load config
	config, err := LoadConfig("config.yaml")
	if err != nil {
		logMessage(Console, Error, "Error loading config: %v", err)
		return
	}

	// Reset OCR cache at startup
	ResetOCRCache()

	// Initialize timestamp OCR client (reusable)
	InitTimestampOCR()
	defer CloseTimestampOCR()

	logMessage(Console, Info, "📊 All processed frames saved to review/")
	logMessage(Console, Info, "   Press Ctrl+C to stop and generate review.html")
	logMessage(Console, Info, "")

	// Create RTSP source with reconnection handling
	logMessage(Console, Info, "Connecting to RTSP stream...")
	var source *RTSPSource
	for {
		source, err = NewRTSPSource(config.Camera.RTSPURL)
		if err == nil {
			break
		}
		logMessage(Console, Warning, "Failed to connect: %v", err)
		logMessage(Console, Info, "Retrying in 5 seconds...")
		time.Sleep(5 * time.Second)
	}
	defer source.Close()

	logMessage(Console, Info, "✓ Connected! Press Ctrl+C to stop")
	logMessage(Console, Info, "Posting to HASS: %s", config.HomeAssistant.URL)
	logMessage(Console, Info, "")

	// Send startup notification (but not if we already sent one recently)
	if !recentStartupNotification() {
		if err := sendNotification(config, "Pulse-Ox Monitor", "Monitoring started"); err != nil {
			logMessage(Both, Warning, "  Failed to send startup notification: %v", err)
		} else {
			markStartupNotification()
		}
	}

	// Setup signal handler
	sigChan := make(chan os.Signal, 1)
	signal.Notify(sigChan, os.Interrupt, syscall.SIGTERM)
	go func() {
		<-sigChan
		logMessage(Console, Info, "")
		logMessage(Console, Info, "")
		logMessage(Console, Info, "🛑 Received stop signal, finishing up...")
		source.Close() // Safe to call multiple times now (sync.Once)
	}()

	// Create processor
	processor := NewProcessor(config, logFile)
	state := NewProcessingState()

	// Run unified processing loop
	processFrames(source, processor, state)

	// Show OCR stats
	calls, cacheHits, tokens := GetOCRStats()
	cost := EstimateCost()
	logMessage(Console, Info, "")
	logMessage(Console, Info, "📊 Gemini OCR Stats:")
	logMessage(Console, Info, "   API calls: %d", calls)
	logMessage(Console, Info, "   Cache hits: %d", cacheHits)
	logMessage(Console, Info, "   Total tokens: %d", tokens)
	logMessage(Console, Info, "   Estimated cost: $%.4f", cost)

	// Close review HTML
	logMessage(Console, Info, "")
	logMessage(Console, Info, "📝 Closing review.html...")
	if err := closeReviewHTML(); err != nil {
		logMessage(Console, Error, "Error closing review HTML: %v", err)
	} else {
		logMessage(Console, Info, "✓ Review page completed: review/review.html (%d frames)", len(state.ReviewEntries))
		logMessage(Console, Info, "  Open it in browser to review recognition results")
	}
}

// interruptibleSleep sleeps for the specified duration, but checks every second if source is closed
func interruptibleSleep(source FrameSource, duration time.Duration) {
	remaining := duration
	for remaining > 0 {
		sleepTime := time.Second
		if remaining < sleepTime {
			sleepTime = remaining
		}
		time.Sleep(sleepTime)
		remaining -= sleepTime

		// Check if source was closed (Ctrl+C pressed)
		if !source.IsActive() {
			return
		}
	}
}

const startupNotificationFile = ".startup_notified"
const detectionFailNotificationFile = ".detection_fail_notified"
const missingTemplateNotificationFile = ".missing_template_notified"

// recentStartupNotification checks if we sent a startup notification in the last hour
func recentStartupNotification() bool {
	info, err := os.Stat(startupNotificationFile)
	if err != nil {
		return false // File doesn't exist
	}
	// Check if file is less than 1 hour old
	return time.Since(info.ModTime()) < 1*time.Hour
}

// markStartupNotification creates/updates the marker file
func markStartupNotification() {
	os.WriteFile(startupNotificationFile, []byte(time.Now().Format(time.RFC3339)), 0644)
}

// recentDetectionFailNotification checks if we sent a detection failure notification in the last hour
func recentDetectionFailNotification() bool {
	info, err := os.Stat(detectionFailNotificationFile)
	if err != nil {
		return false
	}
	return time.Since(info.ModTime()) < 1*time.Hour
}

// markDetectionFailNotification creates/updates the marker file
func markDetectionFailNotification() {
	os.WriteFile(detectionFailNotificationFile, []byte(time.Now().Format(time.RFC3339)), 0644)
}

// loadNotifiedMissingTemplates loads previously notified templates from file
func loadNotifiedMissingTemplates() map[int]bool {
	result := make(map[int]bool)
	data, err := os.ReadFile(missingTemplateNotificationFile)
	if err != nil {
		return result
	}
	for _, line := range strings.Split(string(data), "\n") {
		var num int
		if _, err := fmt.Sscanf(line, "%d", &num); err == nil {
			result[num] = true
		}
	}
	return result
}

// markMissingTemplateNotified adds a template to the notified list
func markMissingTemplateNotified(template int) {
	f, err := os.OpenFile(missingTemplateNotificationFile, os.O_APPEND|os.O_CREATE|os.O_WRONLY, 0644)
	if err != nil {
		return
	}
	defer f.Close()
	fmt.Fprintf(f, "%d\n", template)
}

// prepareBaseFrame converts raw camera frame to canonical base frame
// This is the ONLY place where grayscale/threshold/crop/rotate happens
// Returns: base (binary thresholded)
func prepareBaseFrame(raw gocv.Mat) gocv.Mat {
	// 1. Grayscale
	gray := gocv.NewMat()
	gocv.CvtColor(raw, &gray, gocv.ColorBGRToGray)
	defer gray.Close()
	
	// 2. Threshold to binary
	thresholded := gocv.NewMat()
	gocv.Threshold(gray, &thresholded, BINARY_THRESHOLD, 255, gocv.ThresholdBinary)
	
	// 3. Crop timestamp area (top 80px)
	if thresholded.Rows() > 80 {
		cropped := thresholded.Region(image.Rect(0, 80, thresholded.Cols(), thresholded.Rows()))
		base := cropped.Clone()
		cropped.Close()
		thresholded.Close()
		thresholded = base
	}
	
	// 4. Rotate 90 degrees clockwise
	rotated := gocv.NewMat()
	gocv.Rotate(thresholded, &rotated, gocv.Rotate90Clockwise)
	thresholded.Close()
	
	return rotated
}

// tryDetectionWithRetries attempts detection, fetching fresh frames internally if needed
// Returns the detection result only - does NOT return or modify frames
// maxRetries is the number of additional frames to try after the first failure
func tryDetectionWithRetries(source FrameSource, initialBinary gocv.Mat, maxRetries int) DetectionResult {
	// Try with the initial frame first
	result := DetectRotationAndWidth(initialBinary)
	if result.Success {
		return result
	}

	// Initial attempt failed - try a few more frames
	
	for retry := 1; retry <= maxRetries; retry++ {
		// Get a fresh frame
		frame, shouldContinue, err := source.Next()
		if err != nil || frame.Empty() || !shouldContinue {
			if !frame.Empty() {
				frame.Close()
			}
			return DetectionResult{Success: false}
		}

		// Prepare base frame (grayscale, threshold, crop, rotate)
		binary := prepareBaseFrame(frame)
		frame.Close()
		
		if binary.Empty() {
			// Timestamp extraction failed - skip this frame
			continue
		}

		// Try detection
		result = DetectRotationAndWidth(binary)
		binary.Close() // Detection works on its own copy, so we close this
		
		if result.Success {
			logMessage(Both, Info, "  Detection succeeded on retry #%d", retry)
			return result
		}
	}

	// All retries failed
	return DetectionResult{Success: false}
}

// processFrames is the UNIFIED processing loop - works for both RTSP and single-frame
func processFrames(source FrameSource, processor *Processor, state *ProcessingState) {
	logMessage(Console, Info, "Processing frames from: %s", source.Name())
	logMessage(Console, Info, "")

	for {
		loopStart := time.Now()
		logMessage(Console, Debug, "[LOOP] Starting iteration")

		// Check if we're in a detection wait period
		if !state.DetectWaitUntil.IsZero() && time.Now().Before(state.DetectWaitUntil) {
			// Keep consuming frames to prevent buffer buildup
			frame, shouldContinue, _ := source.Next()
			if !frame.Empty() {
				frame.Close()
			}
			if !shouldContinue || !source.IsActive() {
				break
			}
			continue
		}
		// Clear wait if expired
		if !state.DetectWaitUntil.IsZero() {
			logMessage(Both, Info, "⏰ Detection wait complete, resuming...")
			state.DetectWaitUntil = time.Time{}
			// Reset to stage 4 so we get 3 fast retries before next wait
			// (stages 1-6 are fast, stage 7+ are waits)
			state.DetectFailStage = 4
		}

		// Initialize timing data
		var timing TimingData
		acquireStart := time.Now()

		// Read raw frame from source
		var raw gocv.Mat
		var shouldContinue bool
		var err error

		if state.ConsecutiveFailures == 1 {
			// First failure: grab IMMEDIATE next frame (bypass skip)
			logMessage(Console, Debug, "  Using NextImmediate() due to consecutive failure")
			raw, shouldContinue, err = source.NextImmediate()
		} else {
			// Normal operation or 2nd+ failure: use normal skip
			raw, shouldContinue, err = source.Next()
		}
		timing.Acquire = time.Since(acquireStart).Milliseconds()
		logMessage(Console, Debug, "[LOOP] Frame acquired in %dms", timing.Acquire)

		if err != nil {
			logMessage(Both, Error, "Error reading frame: %v", err)
			if !shouldContinue {
				break
			}
			continue
		}
		if raw.Empty() {
			if !shouldContinue {
				break
			}
			continue
		}

		// ========== PREPARE BASE FRAME ==========
		// This is the ONLY place grayscale/threshold/crop/rotate happens
		prepareStart := time.Now()
		base := prepareBaseFrame(raw)
		
		if base.Empty() {
			// Preprocessing failed - skip frame
			raw.Close()
			if !shouldContinue {
				break
			}
			continue
		}
		timing.Preprocess = time.Since(prepareStart).Milliseconds()
		
		// Check timestamp drift every 10 frames (BEFORE closing raw, on colored frame)
		state.ProcessedCount++
		state.TimestampCheckCounter++
		if state.TimestampCheckCounter >= 10 {
			state.TimestampCheckCounter = 0
			diff, _, err := extractTimestamp(raw)
			if err != nil {
				logMessage(Both, Warning, "  Timestamp OCR failed: %v", err)
			} else if diff > 3 {
				logMessage(Both, Warning, "  Camera timestamp lag: %ds behind server", diff)
			} else if diff < -3 {
				logMessage(Both, Warning, "  Camera timestamp ahead: %ds ahead of server", -diff)
			}
			// Silent if drift is within ±3 seconds
		}
		
		raw.Close()
		
		// Save base frame for debugging (threshold to reduce file size - already done)
		var rawThresholded gocv.Mat
		if state.ProcessedCount == 1 {
			gocv.IMWrite("test_output/pre_threshold_gray.png", base)
			logMessage(Both, Info, "💾 Saved base frame to test_output/pre_threshold_gray.png")
		}
		// Clone base for raw frame saving (used on errors)
		rawThresholded = base.Clone()

		// ========== DETECTION (if needed) ==========
		if state.NeedsDetection() {
			logMessage(Both, Info, "🔍 Running detection...")

			// Try detection on this frame
			result := DetectRotationAndWidth(base)

			if !result.Success {
				// Detection failed - increment failure counter
				state.DetectFailStage++
				state.ConsecutiveFailures = 0 // Reset so we use normal frame interval, not NextImmediate
				base.Close()
				rawThresholded.Close()

				// Track when failures started
				if state.DetectionFailStart.IsZero() {
					state.DetectionFailStart = time.Now()
				}

				// Notify after 5 minutes of continuous detection failure (once per hour)
				if !state.NotifiedDetectionFailure && time.Since(state.DetectionFailStart) > 5*time.Minute {
					if !recentDetectionFailNotification() {
						state.NotifiedDetectionFailure = true
						if err := sendNotification(processor.config, "Pulse-Ox Monitor", "Detection failing for 5+ minutes - pulse-ox not visible?"); err != nil {
							logMessage(Both, Warning, "  Failed to send notification: %v", err)
						} else {
							markDetectionFailNotification()
						}
					}
				}

				switch state.DetectFailStage {
				case 1, 2, 3, 4, 5, 6:
					// Stages 1-6: Try immediately (~3 seconds at 2fps)
					logMessage(Both, Warning, "  Detection failed (#%d) - trying next frame...", state.DetectFailStage)
				case 7:
					// Stage 7: Wait 10s
					state.DetectWaitUntil = time.Now().Add(10 * time.Second)
					logMessage(Both, Warning, "  Detection failed (#%d) - waiting 10s...", state.DetectFailStage)
				case 8:
					// Stage 8: Wait 30s
					state.DetectWaitUntil = time.Now().Add(30 * time.Second)
					logMessage(Both, Warning, "  Detection failed (#%d) - waiting 30s...", state.DetectFailStage)
				default:
					// Stage 9+: Wait 60s
					state.DetectWaitUntil = time.Now().Add(60 * time.Second)
					logMessage(Both, Warning, "  Detection failed (#%d) - waiting 60s...", state.DetectFailStage)
				}

				if !shouldContinue {
					break
				}
				continue
			}

			// Detection succeeded - reset stage and store results
			if state.DetectFailStage > 0 {
				logMessage(Both, Info, "✅ Detection recovered after %d attempts", state.DetectFailStage)
			}
			state.DetectFailStage = 0
			state.DetectionFailStart = time.Time{} // Reset failure tracking
			state.NotifiedDetectionFailure = false // Allow future notifications
			state.LockedRotation = result.Rotation
			state.LockedScale = result.ScaleFactor
			state.Layout = &ScreenLayout{
				SpO2Area: result.SpO2,
				HRArea:   result.HR,
			}
			state.LayoutValid = true
			state.ConsecutiveFailures = 0

			logMessage(Both, Info, "✓ Detection complete:")
			logMessage(Both, Info, "  Rotation: %.3f°", result.Rotation)
			logMessage(Both, Info, "  Scale: %.3f (width %dpx → 860px)", result.ScaleFactor, result.Width)
			logMessage(Both, Info, "  SpO2: X[%d-%d] Y[%d-%d]",
				result.SpO2.Min.X, result.SpO2.Max.X, result.SpO2.Min.Y, result.SpO2.Max.Y)
			logMessage(Both, Info, "  HR:   X[%d-%d] Y[%d-%d]",
				result.HR.Min.X, result.HR.Max.X, result.HR.Min.Y, result.HR.Max.Y)
		}

		// ========== APPLY TRANSFORMS ==========
		// For LLM-OCR, we don't need scaling - just apply rotation if non-zero
		var scaled gocv.Mat
		if state.LockedRotation != 0 {
			// Only apply rotation, no scaling (scale factor = 1.0)
			scaled = applyTransforms(base, state.LockedRotation, 1.0)
			base.Close()
		} else {
			// No transforms needed - use base directly
			scaled = base
		}

		// Validate frame dimensions vs layout coordinates
		if state.Layout != nil {
			logMessage(Both, Debug, "Frame size: %dx%d", scaled.Cols(), scaled.Rows())
			logMessage(Both, Debug, "SpO2 area: X[%d-%d] Y[%d-%d]",
				state.Layout.SpO2Area.Min.X, state.Layout.SpO2Area.Max.X,
				state.Layout.SpO2Area.Min.Y, state.Layout.SpO2Area.Max.Y)
			logMessage(Both, Debug, "HR area: X[%d-%d] Y[%d-%d]",
				state.Layout.HRArea.Min.X, state.Layout.HRArea.Max.X,
				state.Layout.HRArea.Min.Y, state.Layout.HRArea.Max.Y)
			
			// Check bounds
			if state.Layout.SpO2Area.Max.X > scaled.Cols() || state.Layout.SpO2Area.Max.Y > scaled.Rows() ||
				state.Layout.HRArea.Max.X > scaled.Cols() || state.Layout.HRArea.Max.Y > scaled.Rows() {
				logMessage(Both, Error, "Layout coordinates exceed frame dimensions! Resetting detection.")
				state.ResetDetection()
				scaled.Close()
				rawThresholded.Close()
				continue
			}
		}

		// ========== PROCESS FRAME ==========
		logMessage(Console, Debug, "[LOOP] Starting OCR")
		timing.FrameNum = state.ProcessedCount
		result := processor.processFrame(scaled, rawThresholded, state.ProcessedCount, state, &timing)
		logMessage(Console, Debug, "[LOOP] OCR complete, status=%d", result.Status)
		scaled.Close()
		rawThresholded.Close()

		// Print timing table (header every 20 frames)
		state.TimingFrameCount++
		showHeader := (state.TimingFrameCount % 20) == 1
		printTimingTable(timing, showHeader)

		// Handle result
		switch result.Status {
		case StatusSuccess:
			state.ConsecutiveFailures = 0
			state.LowConfidenceCount = 0  // Reset on success
			if result.ShouldPost {
				hassStart := time.Now()
				processor.postReading(&result.Reading, state)
				timing.HASS = time.Since(hassStart).Milliseconds()
				timing.Total += timing.HASS
			}

		case StatusCorrupted:
			// Just log it - don't re-detect. Boxes are locked.
			state.ConsecutiveFailures++
			logMessage(LogFile, Warning, "  Corrupted frame #%d", state.ConsecutiveFailures)

		case StatusLowConfidence:
			// Just logged in processor.go - we continue anyway, boxes are locked

		case StatusNoChange:
			// Normal - don't increment failure counter

		case StatusUnstable:
			// Held for validation - don't increment failure counter
		}

		if !shouldContinue {
			break
		}

		logMessage(Console, Debug, "[LOOP] Iteration complete in %dms", time.Since(loopStart).Milliseconds())
	}
}