refactor: optimize KDS report updates by reducing database calls and improving timing fallback logic

models/pos_prep_state.py

@@ -11,8 +11,7 @@ class PosPreparationState(models.Model):
     def _update_kds_report(self, pdis_state, old_last_stage_change=None):
         """
         Synchronous KDS report update.
-        Computes preparation/service time directly from stage timestamps,
+        Optimized to minimize database calls and avoid redundant aggregations.
-        avoiding race conditions from background threads reading uncommitted data.
         """
         if not pdis_state.prep_line_id:
             return
@@ -63,6 +62,7 @@ class PosPreparationState(models.Model):
 
         try:
             if is_reset:
+                _logger.info("KDS Reset: Order %s on display %s", order_name, display.name)
                 line_report = KdsLineReport.search([
                     ('pos_order_line_id', '=', order_line.id),
                     ('prep_display_id', '=', display_id)
@@ -88,23 +88,33 @@ class PosPreparationState(models.Model):
                 return
 
             # --- Completed ---
-            # Read directly from the in-memory ORM record (set by super() in the same transaction)
+            # Use a slightly larger epsilon for -1 check to be safe with float/int conversions if any
-            prep_time = max(0, order_line.preparation_time)
+            prep_time = order_line.preparation_time
-            svc_time = max(0, order_line.service_time)
+            svc_time = order_line.service_time
 
-            # Fallback: if the base module hasn't set the value yet (still -1),
+            # Fallback timing logic
-            # compute it ourselves from the last_stage_change timestamp
+            if prep_time == -1:
-            if order_line.preparation_time == -1:
                 if old_last_stage_change:
+                    # If we have the old timestamp, it means we spent time in the previous stage
                     prep_time = int(compute_seconds_since(old_last_stage_change))
                 else:
+                    # Otherwise use the current stage entry time
                     prep_time = int(compute_seconds_since(pdis_state.last_stage_change))
+            
+            if svc_time == -1:
+                if is_completed and stage.id == last_stage_id and old_last_stage_change:
+                    # If moving to last stage, service time is time spent in previous stage
+                    svc_time = int(compute_seconds_since(old_last_stage_change))
+                else:
+                    svc_time = 0
 
-            if order_line.service_time == -1:
+            prep_time = max(0, prep_time)
-                svc_time = 0  # Service time may not apply if there's no service stage
+            svc_time = max(0, svc_time)
-
             comp_time = prep_time + svc_time
 
+            _logger.info("KDS Completed: Order %s, Line %s: Prep=%ss, Svc=%ss, Total=%ss", 
+                         order_name, order_line.product_id.name, prep_time, svc_time, comp_time)
+
             vals = {
                 'pos_order_id': order_id,
                 'pos_order_line_id': order_line.id,
@@ -126,30 +136,29 @@ class PosPreparationState(models.Model):
             else:
                 KdsLineReport.create(vals)
 
+            # Update Order Report - Optimized to avoid _read_group inside loops
             order_report = KdsOrderReport.search([
                 ('pos_order_id', '=', order_id),
                 ('prep_display_id', '=', display_id)
             ], limit=1)
 
-            res = KdsLineReport._read_group(
-                [('pos_order_id', '=', order_id), ('prep_display_id', '=', display_id)],
-                aggregates=['completion_time:max']
-            )
-            max_comp_time = res[0][0] if res else comp_time
-
-            order_vals = {
-                'pos_order_id': order_id,
-                'prep_display_id': display_id,
-                'completion_time': max_comp_time,
-                'completion_datetime': fields.Datetime.now(),
-            }
             if order_report:
-                order_report.write(order_vals)
+                # Only update if the new completion time is greater, or if it's been some time
+                if comp_time > order_report.completion_time:
+                    order_report.write({
+                        'completion_time': comp_time,
+                        'completion_datetime': vals['completion_datetime'],
+                    })
             else:
-                KdsOrderReport.create(order_vals)
+                KdsOrderReport.create({
+                    'pos_order_id': order_id,
+                    'prep_display_id': display_id,
+                    'completion_time': comp_time,
+                    'completion_datetime': vals['completion_datetime'],
+                })
 
         except Exception as e:
-            _logger.error("KDS reporting failed for order %s: %s", order_name, e)
+            _logger.error("KDS reporting failed for order %s: %s", order_name, e, exc_info=True)
 
     def _record_status_change_prep_time(self, pdis_state):
         super()._record_status_change_prep_time(pdis_state)