Opened 8 years ago

Closed 8 years ago

#202 closed баг (готово)

Предположительная потеря дескриптора соединения

Reported by: alx Owned by: alx
Priority: высокий Milestone: 1 очередь
Component: VE-01 Keywords:
Cc:

Description

  1. Окончание FXO получает вызывной сигнал и отправляет вызов группе 803.
  2. Телефоны 101, 102, 103, 104 и 201 звенят.
  3. На телефоне 103 снимается трубка.
  4. Устанавливается соединение, остальные телефоны звенеть перестают.
  5. абонент 103 нажимает flash, однако признаков посылки REINVITE в логе нет, у окончания FXO по-прежнему остается активный RTP поток!
  6. абонент 103 получает CallDisconnect от FXO (неизвестно как сформированный).
  7. абонент 103 вызывает 102.
  8. аппарат 102 звенит.
  9. практически одновременно абонент 103 кладет трубку, абонент 102 снимает трубку.
  10. Устанавливается соединение 103 <--> 102.
  11. 103 получает CallDisconnect для нового соединения и отправляет BYE, который не доставляется прокси-сервером (Message failed).
  12. через некоторое время абонент 102 (который, видимо, ничего не слышал в трубке) кладет трубку.

В результате всего этого остается неотбитое соединение канального окончания FXO, которое при этом рефрешится по UPDATE/200 OK!

Судя по всему, при нажатии flash абонентом 103 соединение не было переведено на hold, но и отбито тоже не было. Оно осталось существовать в виде дескриптора соединения, "привязанного" к каналу 3, в то время как канал 3 об этом соединении ничего не знает.

При каждом рефреше сессии канал 3 получал уведомление о получении ответа 200.

Change History (5)

comment:1 by alx, 8 years ago

Лог:

Nov 10 10:52:01 sip_ua[513]: fxo.cpp:338: ---> ts=33, state=Idle: CAS event, ts=33, flags=0000, data=7
Nov 10 10:52:02 sip_ua[513]: fxo.cpp:338: ---> ts=33, state=Ringing: CAS event, ts=33, flags=0000, data=15
Nov 10 10:52:06 sip_ua[513]: fxo.cpp:338: ---> ts=33, state=Ringing: CAS event, ts=33, flags=0000, data=7
Nov 10 10:52:06 sip_ua[513]: fxo.cpp:296: ts 33: dialing 801@192.168.0.4
Nov 10 10:52:06 sip_ua[513]: user_agent.cpp:2477: --> ua_dial_out() "223-41-86" <sip:fxo1@192.168.0.4> -> sip:801@192.168.0.4 ()...
Nov 10 10:52:07 sip_ua[535]: user_agent.cpp:1488: INVITE received: sip:101@127.0.0.1:6060;transport=udp (Call-ID: 103541810@(null))
Nov 10 10:52:07 sip_ua[513]: fxs.cpp:407: ---> ts=1, state=Idle: Incoming call, ts=-1, flags=0001, data=80
Nov 10 10:52:07 sip_ua[535]: user_agent.cpp:1488: INVITE received: sip:102@127.0.0.1:6060;transport=udp (Call-ID: 103541810@(null))
Nov 10 10:52:07 sip_ua[513]: fxs.cpp:909: channel 1: ringing
Nov 10 10:52:07 sip_ua[535]: user_agent.cpp:1488: INVITE received: sip:103@127.0.0.1:6060;transport=udp (Call-ID: 103541810@(null))
Nov 10 10:52:07 sip_ua[513]: user_agent.cpp:2828: Call 80 routed to TS 1
Nov 10 10:52:07 sip_ua[513]: fxs.cpp:407: ---> ts=1, state=Ringing: Incoming call, ts=-1, flags=0001, data=82
Nov 10 10:52:07 sip_ua[513]: fxs.cpp:407: ---> ts=2, state=Idle: Incoming call, ts=-1, flags=0001, data=82
Nov 10 10:52:07 sip_ua[535]: user_agent.cpp:1488: INVITE received: sip:104@127.0.0.1:6060;transport=udp (Call-ID: 103541810@(null))
Nov 10 10:52:07 sip_ua[535]: user_agent.cpp:1615: ---> ringing with status code 180
Nov 10 10:52:07 sip_ua[535]: user_agent.cpp:1615: ---> ringing with status code 180
Nov 10 10:52:07 sip_ua[513]: fxs.cpp:909: channel 2: ringing
Nov 10 10:52:07 sip_ua[513]: user_agent.cpp:2828: Call 82 routed to TS 2
Nov 10 10:52:07 sip_ua[513]: fxs.cpp:407: ---> ts=1, state=Ringing: Incoming call, ts=-1, flags=0001, data=84
Nov 10 10:52:07 sip_ua[513]: fxs.cpp:407: ---> ts=2, state=Ringing: Incoming call, ts=-1, flags=0001, data=84
Nov 10 10:52:07 sip_ua[513]: fxs.cpp:407: ---> ts=3, state=Idle: Incoming call, ts=-1, flags=0001, data=84
Nov 10 10:52:07 sip_ua[513]: fxs.cpp:909: channel 3: ringing
Nov 10 10:52:07 sip_ua[513]: user_agent.cpp:2828: Call 84 routed to TS 3
Nov 10 10:52:07 sip_ua[513]: fxs.cpp:407: ---> ts=1, state=Ringing: Incoming call, ts=-1, flags=0001, data=86
Nov 10 10:52:07 sip_ua[513]: fxs.cpp:407: ---> ts=2, state=Ringing: Incoming call, ts=-1, flags=0001, data=86
Nov 10 10:52:07 sip_ua[513]: fxs.cpp:407: ---> ts=3, state=Ringing: Incoming call, ts=-1, flags=0001, data=86
Nov 10 10:52:07 sip_ua[513]: fxs.cpp:407: ---> ts=4, state=Idle: Incoming call, ts=-1, flags=0001, data=86
Nov 10 10:52:07 sip_ua[535]: user_agent.cpp:1615: ---> ringing with status code 180
Nov 10 10:52:07 sip_ua[513]: fxs.cpp:909: channel 4: ringing
Nov 10 10:52:07 sip_ua[513]: user_agent.cpp:2828: Call 86 routed to TS 4
Nov 10 10:52:07 sip_ua[513]: fxo.cpp:338: ---> ts=33, state=Calling: Remote is ringing, ts=33, flags=0000, data=79
Nov 10 10:52:07 sip_ua[513]: fxo.cpp:338: ---> ts=33, state=Calling: Remote is ringing, ts=33, flags=0000, data=79
Nov 10 10:52:07 sip_ua[513]: fxo.cpp:338: ---> ts=33, state=Calling: Remote is ringing, ts=33, flags=0000, data=79
Nov 10 10:52:07 sip_ua[513]: fxo.cpp:338: ---> ts=33, state=Calling: CAS event, ts=33, flags=0000, data=15
Nov 10 10:52:07 sip_ua[535]: user_agent.cpp:1615: ---> ringing with status code 180
Nov 10 10:52:07 sip_ua[513]: fxo.cpp:338: ---> ts=33, state=Calling: Remote is ringing, ts=33, flags=0000, data=79
Nov 10 10:52:07 sip_ua[535]: user_agent.cpp:1615: ---> ringing with status code 180
Nov 10 10:52:07 sip_ua[513]: fxo.cpp:338: ---> ts=33, state=Calling: Remote is ringing, ts=33, flags=0000, data=79
Nov 10 10:52:11 sip_ua[513]: fxo.cpp:338: ---> ts=33, state=Calling: CAS event, ts=33, flags=0000, data=7
Nov 10 10:52:11 sip_ua[513]: fxs.cpp:407: ---> ts=3, state=Ringing: CAS event, ts=3, flags=0000, data=7
Nov 10 10:52:11 sip_ua[513]: comcerto.cpp:3779: channel 3: answer
Nov 10 10:52:11 sip_ua[513]: fxs.cpp:407: ---> ts=3, state=Connected: RTP parameters, ts=3, flags=0000, data=84
Nov 10 10:52:11 sip_ua[513]: comcerto.cpp:4553: --> ts 3: 192.168.0.4[10006] --> 192.168.0.4[10066]
Nov 10 10:52:11 sip_ua[513]: comcerto.cpp:4554: --> ts 3: codec PCMA, VAD is off
Nov 10 10:52:11 sip_ua[513]: comcerto.cpp:4555: --> audio pt: 8/8, event pt: 101/101, VBD pt: 98/98
Nov 10 10:52:11 sip_ua[513]: comcerto.cpp:4655: ts 3: starting RTP stream to 02:ad:c3:00:00:b4
Nov 10 10:52:11 sip_ua[513]: fxs.cpp:407: ---> ts=3, state=Connected: Statistics received, ts=3, flags=0000, data=0
Nov 10 10:52:11 sip_ua[513]: fxs.cpp:407: ---> ts=3, state=Connected: Statistics received, ts=3, flags=0000, data=0
Nov 10 10:52:11 sip_ua[513]: fxo.cpp:338: ---> ts=33, state=Calling: RTP parameters, ts=33, flags=0000, data=79
Nov 10 10:52:11 sip_ua[513]: comcerto.cpp:4553: --> ts 33: 192.168.0.4[10066] --> 192.168.0.4[10006]
Nov 10 10:52:11 sip_ua[513]: comcerto.cpp:4554: --> ts 33: codec PCMA, VAD is off
Nov 10 10:52:11 sip_ua[513]: comcerto.cpp:4555: --> audio pt: 8/8, event pt: 101/101, VBD pt: 98/98
Nov 10 10:52:11 sip_ua[513]: comcerto.cpp:4655: ts 33: starting RTP stream to 02:ad:c3:00:00:b4
Nov 10 10:52:12 sip_ua[513]: fxo.cpp:338: ---> ts=33, state=Calling: Call answered, ts=33, flags=0000, data=79
Nov 10 10:52:12 sip_ua[513]: fxs.cpp:407: ---> ts=4, state=Ringing: Call disconnected, ts=4, flags=0000, data=86
Nov 10 10:52:12 sip_ua[513]: fxs.cpp:407: ---> ts=4, state=Idle: Call disconnected, ts=4, flags=0000, data=86
Nov 10 10:52:12 sip_ua[513]: fxs.cpp:407: ---> ts=1, state=Ringing: Call disconnected, ts=1, flags=0000, data=80
Nov 10 10:52:12 sip_ua[513]: fxs.cpp:407: ---> ts=1, state=Idle: Call disconnected, ts=1, flags=0000, data=80
Nov 10 10:52:12 sip_ua[513]: fxs.cpp:407: ---> ts=2, state=Ringing: Call disconnected, ts=2, flags=0000, data=82
Nov 10 10:52:12 sip_ua[513]: fxs.cpp:407: ---> ts=2, state=Idle: Call disconnected, ts=2, flags=0000, data=82
Nov 10 10:52:12 sip_ua[513]: fxo.cpp:338: ---> ts=33, state=Connected: CAS event, ts=33, flags=0000, data=15
Nov 10 10:52:12 sip_ua[513]: fxo.cpp:338: ---> ts=33, state=Connected: Statistics received, ts=33, flags=0000, data=0
Nov 10 10:52:12 sip_ua[513]: fxo.cpp:338: ---> ts=33, state=Connected: Statistics received, ts=33, flags=0000, data=0
Nov 10 10:52:16 sip_ua[513]: fxs.cpp:407: ---> ts=3, state=Connected: Statistics received, ts=3, flags=0000, data=0
Nov 10 10:52:16 sip_ua[513]: fxs.cpp:407: ---> ts=3, state=Connected: Statistics received, ts=3, flags=0000, data=0
Nov 10 10:52:17 sip_ua[513]: fxo.cpp:338: ---> ts=33, state=Connected: Statistics received, ts=33, flags=0000, data=0
Nov 10 10:52:17 sip_ua[513]: fxo.cpp:338: ---> ts=33, state=Connected: Statistics received, ts=33, flags=0000, data=0
Nov 10 10:52:21 sip_ua[513]: fxs.cpp:407: ---> ts=3, state=Connected: Statistics received, ts=3, flags=0000, data=0
Nov 10 10:52:21 sip_ua[513]: fxs.cpp:407: ---> ts=3, state=Connected: Statistics received, ts=3, flags=0000, data=0
Nov 10 10:52:22 sip_ua[513]: fxo.cpp:338: ---> ts=33, state=Connected: Statistics received, ts=33, flags=0000, data=0
Nov 10 10:52:22 sip_ua[513]: fxo.cpp:338: ---> ts=33, state=Connected: Statistics received, ts=33, flags=0000, data=0
Nov 10 10:52:24 sip_ua[513]: fxs.cpp:407: ---> ts=3, state=Connected: CAS event, ts=3, flags=0000, data=15
Nov 10 10:52:24 sip_ua[513]: fxs.cpp:407: ---> ts=3, state=Connected: CAS event, ts=3, flags=0000, data=7
Nov 10 10:52:24 sip_ua[513]: fxs.cpp:301: ==> flash pressed
Nov 10 10:52:24 sip_ua[513]: fxs.cpp:407: ---> ts=3, state=Dialtone: Call disconnected, ts=3, flags=0000, data=84
Nov 10 10:52:25 sip_ua[513]: fxs.cpp:407: ---> ts=3, state=Dialtone: DTMF detected, ts=3, flags=0000, data=1
Nov 10 10:52:25 sip_ua[513]: fxs.cpp:407: ---> ts=3, state=Dialing: Tone completed, ts=3, flags=0000, data=3
Nov 10 10:52:25 sip_ua[513]: fxs.cpp:407: ---> ts=3, state=Dialing: Tone detected, ts=3, flags=0000, data=255
Nov 10 10:52:26 sip_ua[513]: fxs.cpp:407: ---> ts=3, state=Dialing: DTMF detected, ts=3, flags=0000, data=0
Nov 10 10:52:26 sip_ua[513]: fxs.cpp:407: ---> ts=3, state=Dialing: Tone detected, ts=3, flags=0000, data=255
Nov 10 10:52:27 sip_ua[513]: fxo.cpp:338: ---> ts=33, state=Connected: Statistics received, ts=33, flags=0000, data=0
Nov 10 10:52:27 sip_ua[513]: fxo.cpp:338: ---> ts=33, state=Connected: Statistics received, ts=33, flags=0000, data=0
Nov 10 10:52:27 sip_ua[513]: fxs.cpp:407: ---> ts=3, state=Dialing: DTMF detected, ts=3, flags=0000, data=2
Nov 10 10:52:27 sip_ua[513]: fxs.cpp:233: ts 3: dialing 102
Nov 10 10:52:27 sip_ua[513]: user_agent.cpp:2477: --> ua_dial_out() "Верещагин А. Н." <sip:103@192.168.0.4> -> sip:102@192.168.0.4 ()...
Nov 10 10:52:27 sip_ua[535]: user_agent.cpp:1488: INVITE received: sip:102@127.0.0.1:6060;transport=udp (Call-ID: 169033737@(null))
Nov 10 10:52:27 sip_ua[513]: fxs.cpp:407: ---> ts=1, state=Idle: Incoming call, ts=-1, flags=0001, data=90
Nov 10 10:52:27 sip_ua[513]: fxs.cpp:407: ---> ts=2, state=Idle: Incoming call, ts=-1, flags=0001, data=90
Nov 10 10:52:27 sip_ua[513]: fxs.cpp:909: channel 2: ringing
Nov 10 10:52:27 sip_ua[513]: user_agent.cpp:2828: Call 90 routed to TS 2
Nov 10 10:52:27 sip_ua[513]: fxs.cpp:407: ---> ts=3, state=Calling: Tone detected, ts=3, flags=0000, data=255
Nov 10 10:52:27 sip_ua[535]: user_agent.cpp:1615: ---> ringing with status code 180
Nov 10 10:52:27 sip_ua[513]: fxs.cpp:407: ---> ts=3, state=Calling: Remote is ringing, ts=3, flags=0000, data=89
Nov 10 10:52:28 sip_ua[513]: fxs.cpp:407: ---> ts=3, state=Calling: CAS event, ts=3, flags=0000, data=15
Nov 10 10:52:28 sip_ua[513]: fxs.cpp:407: ---> ts=2, state=Ringing: CAS event, ts=2, flags=0000, data=7
Nov 10 10:52:28 sip_ua[513]: comcerto.cpp:3779: channel 2: answer
Nov 10 10:52:28 sip_ua[513]: fxs.cpp:407: ---> ts=2, state=Connected: RTP parameters, ts=2, flags=0000, data=90
Nov 10 10:52:28 sip_ua[513]: comcerto.cpp:4553: --> ts 2: 192.168.0.4[10004] --> 192.168.0.4[10006]
Nov 10 10:52:28 sip_ua[513]: comcerto.cpp:4554: --> ts 2: codec PCMA, VAD is off
Nov 10 10:52:28 sip_ua[513]: comcerto.cpp:4555: --> audio pt: 8/8, event pt: 101/101, VBD pt: 98/98
Nov 10 10:52:28 sip_ua[513]: comcerto.cpp:4655: ts 2: starting RTP stream to 02:ad:c3:00:00:b4
Nov 10 10:52:29 sip_ua[513]: fxs.cpp:407: ---> ts=3, state=Calling: RTP parameters, ts=3, flags=0000, data=89
Nov 10 10:52:29 sip_ua[513]: comcerto.cpp:4553: --> ts 3: 192.168.0.4[10006] --> 192.168.0.4[10004]
Nov 10 10:52:29 sip_ua[513]: comcerto.cpp:4554: --> ts 3: codec PCMA, VAD is off
Nov 10 10:52:29 sip_ua[513]: comcerto.cpp:4555: --> audio pt: 8/8, event pt: 101/101, VBD pt: 98/98
Nov 10 10:52:29 sip_ua[513]: comcerto.cpp:4655: ts 3: starting RTP stream to 02:ad:c3:00:00:b4
Nov 10 10:52:29 sip_ua[513]: fxs.cpp:407: ---> ts=3, state=Calling: Call answered, ts=3, flags=0000, data=89
Nov 10 10:52:29 sip_ua[513]: fxs.cpp:407: ---> ts=2, state=Connected: Statistics received, ts=2, flags=0000, data=0
Nov 10 10:52:29 sip_ua[513]: fxs.cpp:407: ---> ts=2, state=Connected: Statistics received, ts=2, flags=0000, data=0
Nov 10 10:52:29 sip_ua[513]: fxs.cpp:407: ---> ts=3, state=Connected: Tone completed, ts=3, flags=0000, data=3
Nov 10 10:52:29 sip_ua[513]: fxs.cpp:407: ---> ts=3, state=Connected: Statistics received, ts=3, flags=0000, data=0
Nov 10 10:52:29 sip_ua[513]: fxs.cpp:407: ---> ts=3, state=Connected: Statistics received, ts=3, flags=0000, data=0
Nov 10 10:52:29 sip_ua[602]: repro.cpp:510: --> duration=1, [FXS]tel:103@192.168.0.4: ---> [FXS]tel:102@192.168.0.4:
Nov 10 10:52:29 sip_ua[602]: repro.cpp:556: --> CDR: {"answer":1478775148,"duration":1,"hangup":1478775149,"org-host":"192.168.0.4","org-name":"Верещагин А. Н.","org-scheme":"tel","org-type":"FXS","org-user":"103","to-host":"192.168.0.4","t
Nov 10 10:52:29 sip_ua[513]: fxs.cpp:407: ---> ts=3, state=Idle: Call disconnected, ts=3, flags=0000, data=89
Nov 10 10:52:29 sip_ua[513]: fxs.cpp:407: ---> ts=3, state=Idle: Message failed, ts=3, flags=0000, data=89
Nov 10 10:52:30 sip_ua[602]: repro.cpp:510: --> duration=1478775150, []:@: ---> []:@:
Nov 10 10:52:30 sip_ua[602]: repro.cpp:556: --> CDR: {"answer":0,"duration":1478775150,"hangup":1478775150,"org-host":"","org-scheme":"","org-user":"","to-host":"","to-scheme":"","to-user":"","type":""}
Nov 10 10:52:32 sip_ua[513]: fxo.cpp:338: ---> ts=33, state=Connected: Statistics received, ts=33, flags=0000, data=0
Nov 10 10:52:32 sip_ua[513]: fxo.cpp:338: ---> ts=33, state=Connected: Statistics received, ts=33, flags=0000, data=0
Nov 10 10:52:32 sip_ua[602]: repro.cpp:510: --> duration=1478775152, []:@: ---> []:@:
Nov 10 10:52:32 sip_ua[602]: repro.cpp:556: --> CDR: {"answer":0,"duration":1478775152,"hangup":1478775152,"org-host":"","org-scheme":"","org-user":"","to-host":"","to-scheme":"","to-user":"","type":""}
Nov 10 10:52:34 sip_ua[513]: fxs.cpp:407: ---> ts=2, state=Connected: Statistics received, ts=2, flags=0000, data=0
Nov 10 10:52:34 sip_ua[513]: fxs.cpp:407: ---> ts=2, state=Connected: Statistics received, ts=2, flags=0000, data=0
Nov 10 10:52:37 sip_ua[513]: fxo.cpp:338: ---> ts=33, state=Connected: Statistics received, ts=33, flags=0000, data=0
Nov 10 10:52:37 sip_ua[513]: fxo.cpp:338: ---> ts=33, state=Connected: Statistics received, ts=33, flags=0000, data=0
Nov 10 10:52:39 sip_ua[513]: fxs.cpp:407: ---> ts=2, state=Connected: Statistics received, ts=2, flags=0000, data=0
Nov 10 10:52:39 sip_ua[513]: fxs.cpp:407: ---> ts=2, state=Connected: Statistics received, ts=2, flags=0000, data=0
Nov 10 10:52:42 sip_ua[513]: fxo.cpp:338: ---> ts=33, state=Connected: Statistics received, ts=33, flags=0000, data=0
Nov 10 10:52:42 sip_ua[513]: fxo.cpp:338: ---> ts=33, state=Connected: Statistics received, ts=33, flags=0000, data=0
Nov 10 10:52:43 sip_ua[513]: fxs.cpp:407: ---> ts=3, state=Idle: ACK received, ts=3, flags=0000, data=84
Nov 10 10:52:44 sip_ua[513]: fxs.cpp:407: ---> ts=2, state=Connected: Statistics received, ts=2, flags=0000, data=0
Nov 10 10:52:44 sip_ua[513]: fxs.cpp:407: ---> ts=2, state=Connected: Statistics received, ts=2, flags=0000, data=0
Nov 10 10:52:47 sip_ua[513]: fxo.cpp:338: ---> ts=33, state=Connected: Statistics received, ts=33, flags=0000, data=0
Nov 10 10:52:47 sip_ua[513]: fxo.cpp:338: ---> ts=33, state=Connected: Statistics received, ts=33, flags=0000, data=0
Nov 10 10:52:49 sip_ua[513]: fxs.cpp:407: ---> ts=2, state=Connected: Statistics received, ts=2, flags=0000, data=0
Nov 10 10:52:49 sip_ua[513]: fxs.cpp:407: ---> ts=2, state=Connected: Statistics received, ts=2, flags=0000, data=0
Nov 10 10:52:52 sip_ua[513]: fxo.cpp:338: ---> ts=33, state=Connected: Statistics received, ts=33, flags=0000, data=0
Nov 10 10:52:52 sip_ua[513]: fxo.cpp:338: ---> ts=33, state=Connected: Statistics received, ts=33, flags=0000, data=0
Nov 10 10:52:54 sip_ua[513]: fxs.cpp:407: ---> ts=2, state=Connected: Statistics received, ts=2, flags=0000, data=0
Nov 10 10:52:54 sip_ua[513]: fxs.cpp:407: ---> ts=2, state=Connected: Statistics received, ts=2, flags=0000, data=0
Nov 10 10:52:57 sip_ua[513]: fxo.cpp:338: ---> ts=33, state=Connected: Statistics received, ts=33, flags=0000, data=0
Nov 10 10:52:57 sip_ua[513]: fxo.cpp:338: ---> ts=33, state=Connected: Statistics received, ts=33, flags=0000, data=0
Nov 10 10:52:59 sip_ua[513]: fxs.cpp:407: ---> ts=2, state=Connected: Statistics received, ts=2, flags=0000, data=0
Nov 10 10:52:59 sip_ua[513]: fxs.cpp:407: ---> ts=2, state=Connected: Statistics received, ts=2, flags=0000, data=0
Nov 10 10:53:00 sip_ua[513]: fxs.cpp:407: ---> ts=2, state=Connected: CAS event, ts=2, flags=0000, data=15
Nov 10 10:53:01 sip_ua[602]: repro.cpp:510: --> duration=1478775181, []:@: ---> []:@:
Nov 10 10:53:01 sip_ua[602]: repro.cpp:556: --> CDR: {"answer":0,"duration":1478775181,"hangup":1478775181,"org-host":"","org-scheme":"","org-user":"","to-host":"","to-scheme":"","to-user":"","type":""}
Nov 10 10:53:01 sip_ua[535]: user_agent.cpp:2318: ---> BYE received
Nov 10 10:53:01 sip_ua[513]: fxs.cpp:407: ---> ts=2, state=Idle: Call disconnected, ts=2, flags=0000, data=90
Nov 10 10:53:01 sip_ua[513]: fxs.cpp:407: ---> ts=2, state=Idle: Message failed, ts=2, flags=0000, data=90
Nov 10 10:53:02 sip_ua[513]: fxo.cpp:338: ---> ts=33, state=Connected: Statistics received, ts=33, flags=0000, data=0
Nov 10 10:53:02 sip_ua[513]: fxo.cpp:338: ---> ts=33, state=Connected: Statistics received, ts=33, flags=0000, data=0
Nov 10 10:53:07 sip_ua[513]: fxo.cpp:338: ---> ts=33, state=Connected: Statistics received, ts=33, flags=0000, data=0
Nov 10 10:53:07 sip_ua[513]: fxo.cpp:338: ---> ts=33, state=Connected: Statistics received, ts=33, flags=0000, data=0
Nov 10 10:53:12 sip_ua[513]: fxo.cpp:338: ---> ts=33, state=Connected: Statistics received, ts=33, flags=0000, data=0
Nov 10 10:53:12 sip_ua[513]: fxo.cpp:338: ---> ts=33, state=Connected: Statistics received, ts=33, flags=0000, data=0
Nov 10 10:53:17 sip_ua[513]: fxo.cpp:338: ---> ts=33, state=Connected: Statistics received, ts=33, flags=0000, data=0
Nov 10 10:53:17 sip_ua[513]: fxo.cpp:338: ---> ts=33, state=Connected: Statistics received, ts=33, flags=0000, data=0
Nov 10 10:53:22 sip_ua[513]: fxo.cpp:338: ---> ts=33, state=Connected: Statistics received, ts=33, flags=0000, data=0
Nov 10 10:53:22 sip_ua[513]: fxo.cpp:338: ---> ts=33, state=Connected: Statistics received, ts=33, flags=0000, data=0
Nov 10 10:53:27 sip_ua[513]: fxo.cpp:338: ---> ts=33, state=Connected: Statistics received, ts=33, flags=0000, data=0
Nov 10 10:53:27 sip_ua[513]: fxo.cpp:338: ---> ts=33, state=Connected: Statistics received, ts=33, flags=0000, data=0
Nov 10 10:53:32 sip_ua[513]: fxo.cpp:338: ---> ts=33, state=Connected: Statistics received, ts=33, flags=0000, data=0
Nov 10 10:53:32 sip_ua[513]: fxo.cpp:338: ---> ts=33, state=Connected: Statistics received, ts=33, flags=0000, data=0
Nov 10 10:53:37 sip_ua[513]: fxo.cpp:338: ---> ts=33, state=Connected: Statistics received, ts=33, flags=0000, data=0
Nov 10 10:53:37 sip_ua[513]: fxo.cpp:338: ---> ts=33, state=Connected: Statistics received, ts=33, flags=0000, data=0
Nov 10 10:53:41 sip_ua[535]: user_agent.cpp:2094: ---> UPDATE in call received
Nov 10 10:53:42 sip_ua[513]: fxs.cpp:407: ---> ts=3, state=Idle: Message answered 2xx, ts=3, flags=0000, data=84
Nov 10 10:53:42 sip_ua[513]: fxo.cpp:338: ---> ts=33, state=Connected: Statistics received, ts=33, flags=0000, data=0
Nov 10 10:53:42 sip_ua[513]: fxo.cpp:338: ---> ts=33, state=Connected: Statistics received, ts=33, flags=0000, data=0
Nov 10 10:53:47 sip_ua[513]: fxo.cpp:338: ---> ts=33, state=Connected: Statistics received, ts=33, flags=0000, data=0
Nov 10 10:53:47 sip_ua[513]: fxo.cpp:338: ---> ts=33, state=Connected: Statistics received, ts=33, flags=0000, data=0
Nov 10 10:53:52 sip_ua[513]: fxo.cpp:338: ---> ts=33, state=Connected: Statistics received, ts=33, flags=0000, data=0
Nov 10 10:53:52 sip_ua[513]: fxo.cpp:338: ---> ts=33, state=Connected: Statistics received, ts=33, flags=0000, data=0
Nov 10 10:53:57 sip_ua[513]: fxo.cpp:338: ---> ts=33, state=Connected: Statistics received, ts=33, flags=0000, data=0

comment:2 by alx, 8 years ago

По пункту 5: REINVITE был послан, но не дошел до получателя из-за ошибки прокси (No other DNS entries to try (7,111)). Это и было причиной одностороннего CallDisconnect, в результате которого канальное окончание FXS "забыло" о соединении, при том что дескриптор остался существовать.

comment:3 by alx, 8 years ago

Установлено, что иногда сообщения не проходят через прокси из-за того что по каким-то причинам прокси выбирает для отправки сообщения шлюзу транспорт TCP, которого у шлюза нет. Замечено, что это происходит довольно редко и касается только запросов.

Варианты решения:

  1. Добавить шлюзу транспорт TCP.
  2. Заменить шлюзу существующий транспорт UDP на транспорт TCP.
  3. Изменить настройки транспортов прокси-сервера таким образом, чтобы внешние (существующие) транспорты слушали только внешние адреса, и дополнительно добавить специальный транспорт для связи со шлюзом на адресе 127.0.0.1 в надежде что для отправки на адрес 127.0.0.1 всегда будет выбираться именно он.

comment:4 by alx, 8 years ago

Установлено, что в TransportSelector::transmit() иногда вызывается с target 127.0.0.1:6060 и протоколом TCP. Откуда происходит вызов, пока непонятно.

В качестве временного решения применен такой патч:

  • TransportSelector.cxx

    old new  
    822822
    823823      if (msg->isRequest())
    824824      {
     825         if(target.isV4() && target.isLoopback() && target.getPort() == 6060) {
     826            target.setType(UDP);
     827         }
    825828         transport = findTransportByVia(msg, target, source);
    826829         if (!transport)
    827830         {

Проблему потери сообщений из-за выбора неверного транспорта он решает.

comment:5 by alx, 8 years ago

Resolution: → готово
Status: new → closed

Патч включен в дерево сборки проекта.

Note: See TracTickets for help on using tickets.