Ошибки при снятии вызова с окончания FXS

[alx]

Постуаил вызов на канальное окончание FXS (номер 322). Затем вызов был снят. При снятии вызова в логе появились ошибки, связанные с попыткой манипуляций с уже уничтоженным каналом.

Oct 12 05:03:13 comcerto daemon.info sip_ua[549]: repro.cpp:435: doSessionAccounting(): Session Created 'branch=z9hG4bK3UjQB9c14ymUK'
Oct 12 05:03:13 comcerto daemon.info sip_ua[513]: user_agent.cpp:1987: INVITE received: sip:322@127.0.0.1:6060;transport=udp (Call-ID: f6a1197d-487e-1237-f5b3-fcaa1433616b@(null))
Oct 12 05:03:13 comcerto daemon.info sip_ua[489]: fxs.cpp:419: ---> ts=1, state=Idle: Incoming call, ts=-1, flags=0001, data=55
Oct 12 05:03:13 comcerto daemon.info sip_ua[489]: fxs.cpp:419: ---> ts=2, state=Idle: Incoming call, ts=-1, flags=0001, data=55
Oct 12 05:03:13 comcerto daemon.info sip_ua[489]: fxs.cpp:419: ---> ts=3, state=Idle: Incoming call, ts=-1, flags=0001, data=55
Oct 12 05:03:13 comcerto daemon.info sip_ua[489]: fxs.cpp:419: ---> ts=4, state=Idle: Incoming call, ts=-1, flags=0001, data=55
Oct 12 05:03:13 comcerto daemon.info sip_ua[489]: fxs.cpp:419: ---> ts=5, state=Idle: Incoming call, ts=-1, flags=0001, data=55
Oct 12 05:03:13 comcerto daemon.info sip_ua[489]: fxs.cpp:419: ---> ts=6, state=Idle: Incoming call, ts=-1, flags=0001, data=55
Oct 12 05:03:13 comcerto daemon.info sip_ua[489]: fxs.cpp:419: ---> ts=7, state=Idle: Incoming call, ts=-1, flags=0001, data=55
Oct 12 05:03:13 comcerto daemon.info sip_ua[489]: fxs.cpp:419: ---> ts=8, state=Idle: Incoming call, ts=-1, flags=0001, data=55
Oct 12 05:03:13 comcerto daemon.info sip_ua[489]: fxs.cpp:419: ---> ts=9, state=Idle: Incoming call, ts=-1, flags=0001, data=55
Oct 12 05:03:13 comcerto daemon.info sip_ua[489]: fxs.cpp:419: ---> ts=10, state=Idle: Incoming call, ts=-1, flags=0001, data=55
Oct 12 05:03:13 comcerto daemon.info sip_ua[489]: fxs.cpp:419: ---> ts=11, state=Idle: Incoming call, ts=-1, flags=0001, data=55
Oct 12 05:03:13 comcerto daemon.info sip_ua[489]: fxs.cpp:419: ---> ts=12, state=Idle: Incoming call, ts=-1, flags=0001, data=55
Oct 12 05:03:13 comcerto daemon.info sip_ua[489]: fxs.cpp:419: ---> ts=13, state=Idle: Incoming call, ts=-1, flags=0001, data=55
Oct 12 05:03:13 comcerto daemon.info sip_ua[489]: fxs.cpp:419: ---> ts=14, state=Idle: Incoming call, ts=-1, flags=0001, data=55
Oct 12 05:03:13 comcerto daemon.info sip_ua[489]: fxs.cpp:962: channel 14: ringing
Oct 12 05:03:13 comcerto daemon.info sip_ua[489]: user_agent.cpp:3484: Call 55 routed to TS 14
Oct 12 05:03:14 comcerto daemon.info sip_ua[513]: user_agent.cpp:1987: INVITE received: sip:323@127.0.0.1:6060;transport=udp (Call-ID: f6a1197d-487e-1237-f5b3-fcaa1433616b@(null))
Oct 12 05:03:14 comcerto daemon.info sip_ua[489]: fxs.cpp:419: ---> ts=1, state=Idle: Incoming call, ts=-1, flags=0001, data=57
Oct 12 05:03:14 comcerto daemon.info sip_ua[489]: fxs.cpp:419: ---> ts=2, state=Idle: Incoming call, ts=-1, flags=0001, data=57
Oct 12 05:03:14 comcerto daemon.info sip_ua[489]: fxs.cpp:419: ---> ts=3, state=Idle: Incoming call, ts=-1, flags=0001, data=57
Oct 12 05:03:14 comcerto daemon.info sip_ua[489]: fxs.cpp:419: ---> ts=4, state=Idle: Incoming call, ts=-1, flags=0001, data=57
Oct 12 05:03:14 comcerto daemon.info sip_ua[489]: fxs.cpp:419: ---> ts=5, state=Idle: Incoming call, ts=-1, flags=0001, data=57
Oct 12 05:03:14 comcerto daemon.info sip_ua[489]: fxs.cpp:419: ---> ts=6, state=Idle: Incoming call, ts=-1, flags=0001, data=57
Oct 12 05:03:14 comcerto daemon.info sip_ua[489]: fxs.cpp:419: ---> ts=7, state=Idle: Incoming call, ts=-1, flags=0001, data=57
Oct 12 05:03:14 comcerto daemon.info sip_ua[489]: fxs.cpp:419: ---> ts=8, state=Idle: Incoming call, ts=-1, flags=0001, data=57
Oct 12 05:03:14 comcerto daemon.info sip_ua[489]: fxs.cpp:419: ---> ts=9, state=Idle: Incoming call, ts=-1, flags=0001, data=57
Oct 12 05:03:14 comcerto daemon.info sip_ua[489]: fxs.cpp:419: ---> ts=10, state=Idle: Incoming call, ts=-1, flags=0001, data=57
Oct 12 05:03:14 comcerto daemon.info sip_ua[489]: fxs.cpp:419: ---> ts=11, state=Idle: Incoming call, ts=-1, flags=0001, data=57
Oct 12 05:03:14 comcerto daemon.info sip_ua[513]: user_agent.cpp:1987: INVITE received: sip:324@127.0.0.1:6060;transport=udp (Call-ID: f6a1197d-487e-1237-f5b3-fcaa1433616b@(null))
Oct 12 05:03:14 comcerto daemon.info sip_ua[489]: fxs.cpp:962: channel 15: ringing
Oct 12 05:03:14 comcerto daemon.info sip_ua[489]: user_agent.cpp:3484: Call 57 routed to TS 15
Oct 12 05:03:14 comcerto daemon.info sip_ua[489]: fxs.cpp:419: ---> ts=1, state=Idle: Incoming call, ts=-1, flags=0001, data=59
Oct 12 05:03:14 comcerto daemon.info sip_ua[489]: fxs.cpp:419: ---> ts=2, state=Idle: Incoming call, ts=-1, flags=0001, data=59
Oct 12 05:03:14 comcerto daemon.info sip_ua[489]: fxs.cpp:419: ---> ts=3, state=Idle: Incoming call, ts=-1, flags=0001, data=59
Oct 12 05:03:14 comcerto daemon.info sip_ua[489]: fxs.cpp:419: ---> ts=4, state=Idle: Incoming call, ts=-1, flags=0001, data=59
Oct 12 05:03:14 comcerto daemon.info sip_ua[489]: fxs.cpp:419: ---> ts=5, state=Idle: Incoming call, ts=-1, flags=0001, data=59
Oct 12 05:03:14 comcerto daemon.info sip_ua[489]: fxs.cpp:419: ---> ts=6, state=Idle: Incoming call, ts=-1, flags=0001, data=59
Oct 12 05:03:14 comcerto daemon.info sip_ua[489]: fxs.cpp:419: ---> ts=7, state=Idle: Incoming call, ts=-1, flags=0001, data=59
Oct 12 05:03:14 comcerto daemon.info sip_ua[489]: fxs.cpp:419: ---> ts=8, state=Idle: Incoming call, ts=-1, flags=0001, data=59
Oct 12 05:03:14 comcerto daemon.info sip_ua[489]: fxs.cpp:419: ---> ts=9, state=Idle: Incoming call, ts=-1, flags=0001, data=59
Oct 12 05:03:14 comcerto daemon.info sip_ua[489]: fxs.cpp:419: ---> ts=10, state=Idle: Incoming call, ts=-1, flags=0001, data=59
Oct 12 05:03:14 comcerto daemon.info sip_ua[489]: fxs.cpp:419: ---> ts=11, state=Idle: Incoming call, ts=-1, flags=0001, data=59
Oct 12 05:03:14 comcerto daemon.info sip_ua[489]: fxs.cpp:419: ---> ts=12, state=Idle: Incoming call, ts=-1, flags=0001, data=59
Oct 12 05:03:14 comcerto daemon.info sip_ua[489]: fxs.cpp:419: ---> ts=13, state=Idle: Incoming call, ts=-1, flags=0001, data=59
Oct 12 05:03:14 comcerto daemon.info sip_ua[489]: fxs.cpp:419: ---> ts=14, state=Ringing: Incoming call, ts=-1, flags=0001, data=59
Oct 12 05:03:14 comcerto daemon.info sip_ua[489]: fxs.cpp:419: ---> ts=15, state=Ringing: Incoming call, ts=-1, flags=0001, data=59
Oct 12 05:03:14 comcerto daemon.info sip_ua[489]: fxs.cpp:419: ---> ts=17, state=Idle: Incoming call, ts=-1, flags=0001, data=59
Oct 12 05:03:14 comcerto daemon.info sip_ua[489]: fxs.cpp:962: channel 17: ringing
Oct 12 05:03:14 comcerto daemon.info sip_ua[489]: user_agent.cpp:3484: Call 59 routed to TS 17
Oct 12 05:03:15 comcerto daemon.info sip_ua[489]: fxo.cpp:270: ---> ts=35, state=Connected: Statistics received, ts=35, flags=0000, data=0
Oct 12 05:03:15 comcerto daemon.info sip_ua[489]: fxo.cpp:270: ---> ts=35, state=Connected: Statistics received, ts=35, flags=0000, data=0
Oct 12 05:03:16 comcerto daemon.info sip_ua[489]: fxo.cpp:270: ---> ts=33, state=Connected: Statistics received, ts=33, flags=0000, data=0
Oct 12 05:03:16 comcerto daemon.info sip_ua[489]: fxo.cpp:270: ---> ts=33, state=Connected: Statistics received, ts=33, flags=0000, data=0
Oct 12 05:03:16 comcerto daemon.info sip_ua[489]: fxs.cpp:419: ---> ts=14, state=Ringing: Caller ID sending complete, ts=14, flags=0000, data=0
Oct 12 05:03:16 comcerto daemon.info sip_ua[489]: fxs.cpp:419: ---> ts=15, state=Ringing: Caller ID sending complete, ts=15, flags=0000, data=0
Oct 12 05:03:16 comcerto daemon.info sip_ua[489]: fxs.cpp:419: ---> ts=17, state=Ringing: Caller ID sending complete, ts=17, flags=0000, data=0
Oct 12 05:03:20 comcerto daemon.info sip_ua[489]: fxo.cpp:270: ---> ts=35, state=Connected: Statistics received, ts=35, flags=0000, data=0
Oct 12 05:03:20 comcerto daemon.info sip_ua[489]: fxo.cpp:270: ---> ts=35, state=Connected: Statistics received, ts=35, flags=0000, data=0
Oct 12 05:03:20 comcerto daemon.info sip_ua[549]: repro.cpp:578: doSessionAccounting(): Session Established 'branch=z9hG4bK3UjQB9c14ymUK'
Oct 12 05:03:21 comcerto daemon.info sip_ua[489]: fxs.cpp:419: ---> ts=14, state=Ringing: Call disconnected, ts=14, flags=0000, data=55
Oct 12 05:03:21 comcerto daemon.err sip_ua[489]: comcerto.cpp:5156: ts 14: PassThru(): invalid channelId (-1)
Oct 12 05:03:21 comcerto daemon.err sip_ua[489]: comcerto.cpp:4357: ts 14: RTPMonitorEna() failed (result=-1)
Oct 12 05:03:21 comcerto daemon.err sip_ua[489]: comcerto.cpp:5156: ts 14: PassThru(): invalid channelId (-1)
Oct 12 05:03:21 comcerto daemon.err sip_ua[489]: comcerto.cpp:4312: ts 14: set_RTCP() failed (result=-1)
Oct 12 05:03:21 comcerto daemon.err sip_ua[489]: comcerto.cpp:5156: ts 14: PassThru(): invalid channelId (-1)
Oct 12 05:03:21 comcerto daemon.err sip_ua[489]: comcerto.cpp:4333: ts 14: set_RTCPStatTmr() failed (result=-1)
Oct 12 05:03:21 comcerto daemon.err sip_ua[489]: comcerto.cpp:5156: ts 14: PassThru(): invalid channelId (-1)
Oct 12 05:03:21 comcerto daemon.err sip_ua[489]: comcerto.cpp:3798: ts 14: setInfoTimer() failed (result=-1)
Oct 12 05:03:21 comcerto daemon.err sip_ua[489]: comcerto.cpp:5156: ts 14: PassThru(): invalid channelId (-1)
Oct 12 05:03:21 comcerto daemon.err sip_ua[489]: comcerto.cpp:6502: ts 14: VCEOPT failed (result=-1)
Oct 12 05:03:24 comcerto daemon.info sip_ua[489]: fxo.cpp:270: ---> ts=35, state=Connected: Call Progress detected, ts=35, flags=0000, data=53
Oct 12 05:03:24 comcerto daemon.info sip_ua[489]: fxo.cpp:270: ---> ts=35, state=Connected: Call Progress detected, ts=35, flags=0000, data=53
Oct 12 05:03:25 comcerto daemon.info sip_ua[489]: fxo.cpp:270: ---> ts=35, state=Connected: Statistics received, ts=35, flags=0000, data=0
Oct 12 05:03:25 comcerto daemon.info sip_ua[489]: fxo.cpp:270: ---> ts=35, state=Connected: Statistics received, ts=35, flags=0000, data=0
Oct 12 05:03:26 comcerto daemon.info sip_ua[489]: fxo.cpp:270: ---> ts=33, state=Connected: Statistics received, ts=33, flags=0000, data=0
Oct 12 05:03:26 comcerto daemon.info sip_ua[489]: fxo.cpp:270: ---> ts=33, state=Connected: Statistics received, ts=33, flags=0000, data=0
Oct 12 05:03:27 comcerto daemon.info sip_ua[489]: fxo.cpp:270: ---> ts=35, state=Connected: Call Progress detected, ts=35, flags=0000, data=53
Oct 12 05:03:27 comcerto daemon.info sip_ua[549]: repro.cpp:516: doSessionAccounting(): Session Ended 'branch=z9hG4bK1840233808'
Oct 12 05:03:27 comcerto daemon.info sip_ua[549]: repro.cpp:534: --> duration=36, []sip:503@192.168.0.4:5060 ---> [FXO]tel:83522439150@192.168.0.4:5060
Oct 12 05:03:27 comcerto daemon.info sip_ua[549]: repro.cpp:701: --> CDR: {"answer":1539320571,"duration":36,"hangup":1539320607,"org-host":"192.168.0.4","org-name":"Верещагин А. Н.","org-port":"5060","org-scheme":"sip","org-user":"503","to-host":"192.168.0.4",
Oct 12 05:03:27 comcerto daemon.info sip_ua[513]: user_agent.cpp:2763: ---> BYE in call received
Oct 12 05:03:27 comcerto daemon.info sip_ua[489]: fxo.cpp:270: ---> ts=33, state=Connected: Call disconnected, ts=33, flags=0000, data=51
Oct 12 05:03:28 comcerto daemon.info sip_ua[489]: fxo.cpp:270: ---> ts=35, state=Connected: Call Progress detected, ts=35, flags=0000, data=53
Oct 12 05:03:28 comcerto daemon.info sip_ua[489]: fxo.cpp:270: ---> ts=33, state=Idle: Call Progress detected, ts=33, flags=0000, data=51
Oct 12 05:03:28 comcerto daemon.info sip_ua[489]: fxo.cpp:270: ---> ts=35, state=Connected: Call Progress detected, ts=35, flags=0000, data=53
Oct 12 05:03:29 comcerto daemon.info sip_ua[489]: fxo.cpp:270: ---> ts=35, state=Connected: Call Progress detected, ts=35, flags=0000, data=53
Oct 12 05:03:30 comcerto daemon.info sip_ua[489]: fxo.cpp:270: ---> ts=35, state=Connected: Statistics received, ts=35, flags=0000, data=0
Oct 12 05:03:30 comcerto daemon.info sip_ua[489]: fxo.cpp:270: ---> ts=35, state=Connected: Statistics received, ts=35, flags=0000, data=0
Oct 12 05:03:31 comcerto daemon.info sip_ua[489]: fxo.cpp:270: ---> ts=35, state=Connected: Call Progress detected, ts=35, flags=0000, data=53

[alx]

Причиной оказались модификации кода, еще не закомиченные в репозиторий: stopRTP() стала вызываться повторно для уже уничтоженного канала (что и было задумано). В код stopRTP() будет добавлена проверка существования канала.