diff --git a/models/pos_prep_state.py b/models/pos_prep_state.py index 28d38ae..d279630 100644 --- a/models/pos_prep_state.py +++ b/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, - avoiding race conditions from background threads reading uncommitted data. + Optimized to minimize database calls and avoid redundant aggregations. """ 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) - prep_time = max(0, order_line.preparation_time) - svc_time = max(0, order_line.service_time) + # Use a slightly larger epsilon for -1 check to be safe with float/int conversions if any + prep_time = order_line.preparation_time + svc_time = order_line.service_time - # Fallback: if the base module hasn't set the value yet (still -1), - # compute it ourselves from the last_stage_change timestamp - if order_line.preparation_time == -1: + # Fallback timing logic + if prep_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: - svc_time = 0 # Service time may not apply if there's no service stage - + prep_time = max(0, prep_time) + 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)