Skip to content

Fix repeater telemetry loss due to race condition in timeout handlers#63

Merged
MrAlders0n merged 3 commits intodevfrom
copilot/debug-session-pings-issue
Dec 19, 2025
Merged

Fix repeater telemetry loss due to race condition in timeout handlers#63
MrAlders0n merged 3 commits intodevfrom
copilot/debug-session-pings-issue

Conversation

Copy link
Contributor

Copilot AI commented Dec 19, 2025

Session Pings log displayed "none" for repeaters despite debug logs showing successful detection (e.g., path=4e, SNR=11.5 and path=77, SNR=9.75).

Root Cause

Two 7-second timeouts fired sequentially:

  1. startRepeaterTracking() set a timeout that called stopRepeaterTracking(), clearing the collected data
  2. sendPing() set another timeout that called stopRepeaterTracking() to retrieve results, but found an empty array due to isListening = false

Changes

  • Removed duplicate timeout from startRepeaterTracking()
  • Single timeout in sendPing() now handles both stopping and retrieval atomically
  • Display exact SNR values as received (not rounded to integers)

Before:

// startRepeaterTracking()
state.repeaterTracking.listenTimeout = setTimeout(() => {
  stopRepeaterTracking();  // Premature cleanup
}, 7000);

// sendPing()
setTimeout(() => {
  const repeaters = stopRepeaterTracking();  // Returns []
  updatePingLogWithRepeaters(logEntry, repeaters);
}, 7000);

// formatRepeaterTelemetry()
return repeaters.map(r => `${r.repeaterId}(${Math.round(r.snr)})`).join(',');

After:

// startRepeaterTracking()
// Note: Timeout managed by caller

// sendPing()
setTimeout(() => {
  const repeaters = stopRepeaterTracking();  // Returns collected data
  updatePingLogWithRepeaters(logEntry, repeaters);
}, 7000);

// formatRepeaterTelemetry()
return repeaters.map(r => `${r.repeaterId}(${r.snr})`).join(',');

Session log now populates correctly with exact SNR values: 2025-12-19T04:59:55.537Z | 45.26900,-75.77755 | 4e(11.5),77(9.75)

Original prompt

The last PR seems to be working base don console logging,

However the session ping log shows this
Session Pings
2025-12-19T04:59:55.537Z | 45.26900,-75.77755 | none

[DEBUG] Starting 7000ms cooldown
wardrive.js:18 [DEBUG] Scheduling MeshMapper API post in 7000ms
wardrive.js:18 [DEBUG] Calculating Haversine distance: (45.26900, -75.77755) to (45.26900, -75.77755)
wardrive.js:18 [DEBUG] Haversine distance calculated: 0.00m
wardrive.js:18 [DEBUG] Calculating Haversine distance: (45.26900, -75.77755) to (45.26900, -75.77755)
wardrive.js:18 [DEBUG] Haversine distance calculated: 0.00m
wardrive.js:18 [DEBUG] Received rx_log entry: SNR=11.5, RSSI=-36
wardrive.js:18 [DEBUG] Parsed packet: header=0x15, route_type=FLOOD, payload_type=GRP_TXT, path_len=1
wardrive.js:18 [DEBUG] Header validation passed: 0x15
wardrive.js:18 [DEBUG] Message correlation check: packet_channel_hash=0x81, expected=0x81
wardrive.js:18 [DEBUG] Channel hash match confirmed - this is a message on our channel
wardrive.js:18 [DEBUG] [MESSAGE_CORRELATION] Starting message content verification...
wardrive.js:18 [DEBUG] [MESSAGE_CORRELATION] Channel key available, attempting decryption...
wardrive.js:18 [DEBUG] [DECRYPT] Starting GroupText payload decryption
wardrive.js:18 [DEBUG] [DECRYPT] Payload length: 67 bytes
wardrive.js:18 [DEBUG] [DECRYPT] Channel key length: 16 bytes
wardrive.js:18 [DEBUG] [DECRYPT] Channel hash: 0x81
wardrive.js:18 [DEBUG] [DECRYPT] Cipher MAC: a37c
wardrive.js:18 [DEBUG] [DECRYPT] Encrypted data length: 64 bytes
wardrive.js:18 [DEBUG] [DECRYPT] Encrypted data preview (first 32 bytes): 640cd519e3cd2365d2dee2dc72210449d79ff9216519d973f80ce73cb4685cbf...
wardrive.js:18 [DEBUG] [DECRYPT] Using aes-js library for AES-ECB decryption
wardrive.js:18 [DEBUG] [DECRYPT] Decrypting 64 bytes with AES-ECB...
wardrive.js:18 [DEBUG] [DECRYPT] Decryption completed successfully
wardrive.js:18 [DEBUG] [DECRYPT] Decrypted data length: 64 bytes
wardrive.js:18 [DEBUG] [DECRYPT] Decrypted data preview (first 32 bytes): cb db 44 69 00 4d 72 41 6c 64 65 72 73 30 6e 3a 20 40 5b 4d 61 70 70 65 72 42 6f 74 5d 20 34 35...
wardrive.js:18 [DEBUG] [DECRYPT] Timestamp: 1766120395 (2025-12-19T04:59:55.000Z)
wardrive.js:18 [DEBUG] [DECRYPT] Flags: 0x00
wardrive.js:18 [DEBUG] [DECRYPT] Message bytes length: 59
wardrive.js:18 [DEBUG] [DECRYPT] ✅ Message decrypted successfully: "MrAlders0n: @[MapperBot] 45.26900, -75.77755"
wardrive.js:18 [DEBUG] [DECRYPT] Message length: 44 characters
wardrive.js:18 [DEBUG] [MESSAGE_CORRELATION] Decryption successful, comparing content...
wardrive.js:18 [DEBUG] [MESSAGE_CORRELATION] Decrypted: "MrAlders0n: @[MapperBot] 45.26900, -75.77755" (44 chars)
wardrive.js:18 [DEBUG] [MESSAGE_CORRELATION] Expected: "@[MapperBot] 45.26900, -75.77755" (32 chars)
wardrive.js:18 [DEBUG] [MESSAGE_CORRELATION] ✅ Message contained in decrypted text (with sender prefix) - this is an echo of our ping!
wardrive.js:18 [DEBUG] Repeater echo accepted: path=4e, SNR=11.5, path_length=1
wardrive.js:18 [DEBUG] Adding new repeater echo: path=4e, SNR=11.5
wardrive.js:18 [DEBUG] Received rx_log entry: SNR=9.75, RSSI=-21
wardrive.js:18 [DEBUG] Parsed packet: header=0x15, route_type=FLOOD, payload_type=GRP_TXT, path_len=1
wardrive.js:18 [DEBUG] Header validation passed: 0x15
wardrive.js:18 [DEBUG] Message correlation check: packet_channel_hash=0x81, expected=0x81
wardrive.js:18 [DEBUG] Channel hash match confirmed - this is a message on our channel
wardrive.js:18 [DEBUG] [MESSAGE_CORRELATION] Starting message content verification...
wardrive.js:18 [DEBUG] [MESSAGE_CORRELATION] Channel key available, attempting decryption...
wardrive.js:18 [DEBUG] [DECRYPT] Starting GroupText payload decryption
wardrive.js:18 [DEBUG] [DECRYPT] Payload length: 67 bytes
wardrive.js:18 [DEBUG] [DECRYPT] Channel key length: 16 bytes
wardrive.js:18 [DEBUG] [DECRYPT] Channel hash: 0x81
wardrive.js:18 [DEBUG] [DECRYPT] Cipher MAC: a37c
wardrive.js:18 [DEBUG] [DECRYPT] Encrypted data length: 64 bytes
wardrive.js:18 [DEBUG] [DECRYPT] Encrypted data preview (first 32 bytes): 640cd519e3cd2365d2dee2dc72210449d79ff9216519d973f80ce73cb4685cbf...
wardrive.js:18 [DEBUG] [DECRYPT] Using aes-js library for AES-ECB decryption
wardrive.js:18 [DEBUG] [DECRYPT] Decrypting 64 bytes with AES-ECB...
wardrive.js:18 [DEBUG] [DECRYPT] Decryption completed successfully
wardrive.js:18 [DEBUG] [DECRYPT] Decrypted data length: 64 bytes
wardrive.js:18 [DEBUG] [DECRYPT] Decrypted data preview (first 32 bytes): cb db 44 69 00 4d 72 41 6c 64 65 72 73 30 6e 3a 20 40 5b 4d 61 70 70 65 72 42 6f 74 5d 20 34 35...
wardrive.js:18 [DEBUG] [DECRYPT] Timestamp: 1766120395 (2025-12-19T04:59:55.000Z)
wardrive.js:18 [DEBUG] [DECRYPT] Flags: 0x00
wardrive.js:18 [DEBUG] [DECRYPT] Message bytes length: 59
wardrive.js:18 [DEBUG] [DECRYPT] ✅ Message decrypted successfully: "MrAlders0n: @[MapperBot] 45.26900, -75.77755"
wardrive.js:18 [DEBUG] [DECRYPT] Message length: 44 characters
wardrive.js:18 [DEBUG] [MESSAGE_CORRELA...


💬 We'd love your input! Share your thoughts on Copilot coding agent in our 2 minute survey.

Co-authored-by: MrAlders0n <55921894+MrAlders0n@users.noreply.github.com>
Copilot AI changed the title [WIP] Fix session ping log output for accuracy Fix repeater telemetry loss due to race condition in timeout handlers Dec 19, 2025
Copilot AI requested a review from MrAlders0n December 19, 2025 05:07
@MrAlders0n
Copy link
Collaborator

@copilot I dont want to round up the SNR, put the exact SNR values as received

Co-authored-by: MrAlders0n <55921894+MrAlders0n@users.noreply.github.com>
Copy link
Contributor Author

Copilot AI commented Dec 19, 2025

@copilot I dont want to round up the SNR, put the exact SNR values as received

Changed to display exact SNR values. The session log will now show repeaters like 4e(11.5),77(9.75) instead of 4e(12),77(10).

Commit: 0e02cf1

@MrAlders0n MrAlders0n marked this pull request as ready for review December 19, 2025 05:10
@MrAlders0n MrAlders0n merged commit 53bb3c6 into dev Dec 19, 2025
@MrAlders0n MrAlders0n deleted the copilot/debug-session-pings-issue branch December 20, 2025 05:36
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants