From bc5eaaa8b52ba717c0bc8a0c8ca2792e16780f3e Mon Sep 17 00:00:00 2001
From: cort <cort@vesta.k0usy.org>
Date: Fri, 3 Oct 2025 12:57:07 -0500
Subject: [PATCH] Fix RX hang time bug and make all log messages consistent

Critical bug fix:
- RX terminator was not setting end_time, causing hang_duration=0.00s
- Added current_stream.end_time = time() to RX terminator handler
- This fixes hang times ending immediately instead of waiting 10s

Log message consistency:
- Changed all TX logs to use 'dst=' instead of 'tgid=' to match RX
- Added 'entering hang time' message to TX terminator to match RX
- All stream end logs now have identical format

Before fix:
- TX hang time completed: hang_duration=10.52s (correct)

After fix:
- Both RX and TX should show hang_duration=10.00s

Example logs:
- RX stream started: src=..., dst=...
- TX stream started: from repeater X, src=..., dst=...
- RX stream ended: reason=terminator - entering hang time (10.0s)
- TX stream ended: reason=terminator - entering hang time (10.0s)
- RX hang time completed: hang_duration=10.00s
- TX hang time completed: hang_duration=10.00s
---
 hblink4/hblink.py | 9 ++++++---
 1 file changed, 6 insertions(+), 3 deletions(-)

diff --git a/hblink4/hblink.py b/hblink4/hblink.py
index de0ec2e..2eb2b3e 100644
--- a/hblink4/hblink.py
+++ b/hblink4/hblink.py
@@ -1539,6 +1539,7 @@ class HBProtocol(DatagramProtocol):
         if _is_terminator and current_stream and not current_stream.ended:
             # DMR terminator detected - end stream immediately and start hang time
             current_stream.ended = True
+            current_stream.end_time = time()  # Critical: set end_time for hang calculation!
             hang_time = CONFIG.get('global', {}).get('stream_hang_time', 10.0)
             duration = time() - current_stream.start_time
             LOGGER.info(f'RX stream ended on repeater {int.from_bytes(repeater_id, "big")} slot {_slot}: '
@@ -1700,7 +1701,7 @@ class HBProtocol(DatagramProtocol):
             LOGGER.info(f'TX stream started on repeater {int.from_bytes(repeater.repeater_id, "big")} slot {slot}: '
                        f'from repeater {source_repeater_id}, '
                        f'src={int.from_bytes(rf_src, "big")}, '
-                       f'tgid={int.from_bytes(dst_id, "big")}')
+                       f'dst={int.from_bytes(dst_id, "big")}')
             
             # Emit stream_start event for dashboard
             self._events.emit('stream_start', {
@@ -1725,14 +1726,16 @@ class HBProtocol(DatagramProtocol):
             duration = current_time - current_stream.start_time
             current_stream.end_time = current_time
             current_stream.ended = True
+            hang_time = CONFIG.get('global', {}).get('stream_hang_time', 10.0)
             
             # Log at INFO level with consistent format
             LOGGER.info(f'TX stream ended on repeater {int.from_bytes(repeater.repeater_id, "big")} slot {slot}: '
                        f'src={int.from_bytes(rf_src, "big")}, '
-                       f'tgid={int.from_bytes(dst_id, "big")}, '
+                       f'dst={int.from_bytes(dst_id, "big")}, '
                        f'duration={duration:.2f}s, '
                        f'packets={current_stream.packet_count}, '
-                       f'reason=terminator')
+                       f'reason=terminator - '
+                       f'entering hang time ({hang_time}s)')
             
             # Emit stream_end event for dashboard
             self._events.emit('stream_end', {