[PHREAKSCRIPT-52] res_alarmsystem: IP loss reported even if no outage

← All Issues || New Issue →

Sort Normal || Priority

Details

Sometimes an IP_LOST event is triggered followed by an IP_RESTORED event in the same second. This is less frequent than it used to be, but it remains that these are not real outages, and should not be reported as such.

Improve the loss detection logic to really check if we've lost connection - it should generally NOT be possible for IP loss to be reported one second followed by a restored event in the same second. In theory, no outage should be reported even if every other packet is lost, we'd need to see consistent loss in a row to report an outage.

Update: Successive packet loss is required to trigger this behavior, but the most problematic aspect is really that LOSS is immediately followed by RESTORED in the same second.

[2024-10-21 09:21:12.952] DEBUG[104753]: res_alarmsystem.c:1158 send_event_ip: Sending event by IP: 'REDACTED*REDACTED***8**#'
[2024-10-21 09:21:12.993] DEBUG[104753]: res_alarmsystem.c:1619 process_server_ack: Received ACK 6 from server
[2024-10-21 09:21:16.998] DEBUG[104753]: res_alarmsystem.c:1158 send_event_ip: Sending event by IP: 'REDACTED*REDACTED***8**#'
[2024-10-21 09:21:17.016] DEBUG[104753]: res_alarmsystem.c:1619 process_server_ack: Received ACK 6 from server
[2024-10-21 09:21:21.020] DEBUG[104753]: res_alarmsystem.c:1158 send_event_ip: Sending event by IP: 'REDACTED*REDACTED***8**#'
[2024-10-21 09:21:25.024] DEBUG[104753]: res_alarmsystem.c:1158 send_event_ip: Sending event by IP: 'REDACTED*REDACTED***8**#'
[2024-10-21 09:21:25.070] DEBUG[104753]: res_alarmsystem.c:1619 process_server_ack: Received ACK 6 from server
[2024-10-21 09:21:29.074] DEBUG[104753]: res_alarmsystem.c:1158 send_event_ip: Sending event by IP: 'REDACTED*REDACTED***8**#'
[2024-10-21 09:21:29.092] DEBUG[104753]: res_alarmsystem.c:1619 process_server_ack: Received ACK 6 from server
[2024-10-21 09:21:33.096] DEBUG[104753]: res_alarmsystem.c:1158 send_event_ip: Sending event by IP: 'REDACTED*REDACTED***8**#'
[2024-10-21 09:21:37.100] DEBUG[104753]: res_alarmsystem.c:1158 send_event_ip: Sending event by IP: 'REDACTED*REDACTED***8**#'
[2024-10-21 09:21:37.120] DEBUG[104753]: res_alarmsystem.c:1619 process_server_ack: Received ACK 6 from server
[2024-10-21 09:21:41.125] DEBUG[104753]: res_alarmsystem.c:1158 send_event_ip: Sending event by IP: 'REDACTED*REDACTED***8**#'
[2024-10-21 09:21:41.168] DEBUG[104753]: res_alarmsystem.c:1619 process_server_ack: Received ACK 6 from server
[2024-10-21 09:21:45.172] DEBUG[104753]: res_alarmsystem.c:1158 send_event_ip: Sending event by IP: 'REDACTED*REDACTED***8**#'
[2024-10-21 09:21:45.217] DEBUG[104753]: res_alarmsystem.c:1619 process_server_ack: Received ACK 6 from server
[2024-10-21 09:21:49.221] DEBUG[104753]: res_alarmsystem.c:1158 send_event_ip: Sending event by IP: 'REDACTED*REDACTED***8**#'
[2024-10-21 09:21:49.242] DEBUG[104753]: res_alarmsystem.c:1619 process_server_ack: Received ACK 6 from server
[2024-10-21 09:21:53.246] DEBUG[104753]: res_alarmsystem.c:1158 send_event_ip: Sending event by IP: 'REDACTED*REDACTED***8**#'
[2024-10-21 09:21:53.292] DEBUG[104753]: res_alarmsystem.c:1619 process_server_ack: Received ACK 6 from server
[2024-10-21 09:21:57.296] DEBUG[104753]: res_alarmsystem.c:1158 send_event_ip: Sending event by IP: 'REDACTED*REDACTED***8**#'
[2024-10-21 09:21:57.324] DEBUG[104753]: res_alarmsystem.c:1619 process_server_ack: Received ACK 6 from server
[2024-10-21 09:22:01.328] DEBUG[104753]: res_alarmsystem.c:1158 send_event_ip: Sending event by IP: 'REDACTED*REDACTED***8**#'
[2024-10-21 09:22:01.354] DEBUG[104753]: res_alarmsystem.c:1619 process_server_ack: Received ACK 6 from server
[2024-10-21 09:22:05.358] DEBUG[104753]: res_alarmsystem.c:1158 send_event_ip: Sending event by IP: 'REDACTED*REDACTED***8**#'
[2024-10-21 09:22:09.362] DEBUG[104753]: res_alarmsystem.c:1158 send_event_ip: Sending event by IP: 'REDACTED*REDACTED***8**#'
[2024-10-21 09:22:09.380] DEBUG[104753]: res_alarmsystem.c:1619 process_server_ack: Received ACK 6 from server
[2024-10-21 09:22:13.384] DEBUG[104753]: res_alarmsystem.c:1158 send_event_ip: Sending event by IP: 'REDACTED*REDACTED***8**#'
[2024-10-21 09:22:13.404] DEBUG[104753]: res_alarmsystem.c:1619 process_server_ack: Received ACK 6 from server
[2024-10-21 09:22:17.408] DEBUG[104753]: res_alarmsystem.c:1158 send_event_ip: Sending event by IP: 'REDACTED*REDACTED***8**#'
[2024-10-21 09:22:17.440] DEBUG[104753]: res_alarmsystem.c:1619 process_server_ack: Received ACK 6 from server
[2024-10-21 09:22:21.445] DEBUG[104753]: res_alarmsystem.c:1158 send_event_ip: Sending event by IP: 'REDACTED*REDACTED***8**#'
[2024-10-21 09:22:21.492] DEBUG[104753]: res_alarmsystem.c:1619 process_server_ack: Received ACK 6 from server
[2024-10-21 09:22:25.496] DEBUG[104753]: res_alarmsystem.c:1158 send_event_ip: Sending event by IP: 'REDACTED*REDACTED***8**#'
[2024-10-21 09:22:29.501] DEBUG[104753]: res_alarmsystem.c:1158 send_event_ip: Sending event by IP: 'REDACTED*REDACTED***8**#'
[2024-10-21 09:22:29.520] DEBUG[104753]: res_alarmsystem.c:1619 process_server_ack: Received ACK 6 from server
[2024-10-21 09:22:33.523] DEBUG[104753]: res_alarmsystem.c:1158 send_event_ip: Sending event by IP: 'REDACTED*REDACTED***8**#'
[2024-10-21 09:22:33.541] DEBUG[104753]: res_alarmsystem.c:1619 process_server_ack: Received ACK 6 from server
[2024-10-21 09:22:37.545] DEBUG[104753]: res_alarmsystem.c:1158 send_event_ip: Sending event by IP: 'REDACTED*REDACTED***8**#'
[2024-10-21 09:22:37.564] DEBUG[104753]: res_alarmsystem.c:1619 process_server_ack: Received ACK 6 from server
[2024-10-21 09:22:41.568] DEBUG[104753]: res_alarmsystem.c:1158 send_event_ip: Sending event by IP: 'REDACTED*REDACTED***8**#'
[2024-10-21 09:22:45.572] DEBUG[104753]: res_alarmsystem.c:1158 send_event_ip: Sending event by IP: 'REDACTED*REDACTED***8**#'
[2024-10-21 09:22:49.576] DEBUG[104753]: res_alarmsystem.c:1721 client_thread: Time is 1729516969, but haven't gotten an ACK since 1729516957
[2024-10-21 09:22:49.576] NOTICE[104753]: res_alarmsystem.c:1255 set_ip_connected: Client 'home' is now OFFLINE
[2024-10-21 09:22:49.576] DEBUG[104753]: res_alarmsystem.c:1197 generate_event: Client 'REDACTED', seqno 0, timestamp 2249, event INTERNET_LOST, sensor , data ''
[2024-10-21 09:22:49.577] DEBUG[104753]: res_alarmsystem.c:820 spawn_dialplan: Executing async client dialplan iplost@alarm
[2024-10-21 09:22:49.577] DEBUG[104753]: res_alarmsystem.c:766 orig_app_dialplan: Spawning dialplan: iplost@alarm -> Wait(999999)
[2024-10-21 09:22:49.579] DEBUG[104753]: res_alarmsystem.c:1158 send_event_ip: Sending event by IP: 'REDACTED*REDACTED***8**#'
[2024-10-21 09:22:49.580]     -- Called iplost@alarm
[2024-10-21 09:22:49.626] NOTICE[104753]: res_alarmsystem.c:1255 set_ip_connected: Client 'home' is now ONLINE
[2024-10-21 09:22:49.626] DEBUG[104753]: res_alarmsystem.c:1197 generate_event: Client 'REDACTED', seqno 0, timestamp 2249, event INTERNET_RESTORED, sensor , data ''
[2024-10-21 09:22:49.627] DEBUG[104753]: res_alarmsystem.c:820 spawn_dialplan: Executing async client dialplan iprestored@alarm
[2024-10-21 09:22:49.627] DEBUG[104753]: res_alarmsystem.c:766 orig_app_dialplan: Spawning dialplan: iprestored@alarm -> Wait(999999)
[2024-10-21 09:22:49.628] DEBUG[104753]: res_alarmsystem.c:1619 process_server_ack: Received ACK 6 from server
[2024-10-21 09:22:49.629]     -- Called iprestored@alarm
[2024-10-21 09:22:49.655]     -- Executing [iplost@alarm:2] Hangup("Local/iplost@alarm-0000046f;2", "") in new stack
[2024-10-21 09:22:49.656]   == Spawn extension (alarm, iplost, 2) exited non-zero on 'Local/iplost@alarm-0000046f;2'
[2024-10-21 09:22:49.688]     -- Executing [iprestored@alarm:2] Hangup("Local/iprestored@alarm-00000470;2", "") in new stack
[2024-10-21 09:22:49.689]   == Spawn extension (alarm, iprestored, 2) exited non-zero on 'Local/iprestored@alarm-00000470;2'
[2024-10-21 09:22:53.632] DEBUG[104753]: res_alarmsystem.c:1158 send_event_ip: Sending event by IP: 'REDACTED*REDACTED***8**#'
[2024-10-21 09:22:53.676] DEBUG[104753]: res_alarmsystem.c:1619 process_server_ack: Received ACK 6 from server
[2024-10-21 09:22:57.680] DEBUG[104753]: res_alarmsystem.c:1158 send_event_ip: Sending event by IP: 'REDACTED*REDACTED***8**#'
[2024-10-21 09:22:57.700] DEBUG[104753]: res_alarmsystem.c:1619 process_server_ack: Received ACK 6 from server
[2024-10-21 09:23:01.704] DEBUG[104753]: res_alarmsystem.c:1158 send_event_ip: Sending event by IP: 'REDACTED*REDACTED***8**#'
[2024-10-21 09:23:01.723] DEBUG[104753]: res_alarmsystem.c:1619 process_server_ack: Received ACK 6 from server

Comments

You must be logged in to leave a comment.