Нет реакции на BYE

[alx]

На нашей АТС 192.168.0.4 был принят входящий вызов от канального окончания FXO (ts=33) и передан на FreeSwitch 192.168.0.13. Оттуда был сделан новый вызов к абоненту АТС (ts=1).

После окончания разговора абонент АТС в 12:58:28 положил трубку, и в сторону FreeSwitch ушло сообщение BYE. В ответ в 12:58:29 был получен ответ "200 OK". В свою очередь, FreeSwitch послал нашей АТС BYE чтобы закончить сессию с FXO, но это сообщение почему-то игнорировалось шлюзом: судя по логу, libeXosip не генерировал никакого события, соответственно, на BYE не было никакого ответа.

В 12:58:32 канальное окончание FXO детектировало "Занято" в абонентской линии, и отправило BYE в сторону FreeSwitch. Но теперь уже от прокси-сервера не было ответа "100 Trying". Попытки отправки запросов продолжались до 12:58:36, когда прокси-сервер, наконец, ответил "100 Trying". Попытки отправки BYE продолжались до 12:59:01, когда, наконец, от прокси шлюзу не пришло "200 OK".

Вот как выглядел лог:

Apr  2 12:58:21 comcerto daemon.info sip_ua[551]: fxo.cpp:320: ---> ts=33, state=Connected: TDM Call Progress detected, ts=33, flags=0000, data=53
Apr  2 12:58:21 comcerto daemon.info sip_ua[551]: fxo.cpp:320: ---> ts=33, state=Connected: TDM Call Progress detected, ts=33, flags=0000, data=53
Apr  2 12:58:21 comcerto daemon.info sip_ua[551]: fxs.cpp:446: ---> ts=1, state=Connected: Statistics received, ts=1, flags=0000, data=0
Apr  2 12:58:21 comcerto daemon.info sip_ua[551]: fxs.cpp:446: ---> ts=1, state=Connected: Statistics received, ts=1, flags=0000, data=0
Apr  2 12:58:24 comcerto daemon.info sip_ua[551]: fxo.cpp:320: ---> ts=33, state=Connected: TDM Call Progress detected, ts=33, flags=0000, data=53
Apr  2 12:58:24 comcerto daemon.info sip_ua[551]: fxo.cpp:320: ---> ts=33, state=Connected: Statistics received, ts=33, flags=0000, data=0
Apr  2 12:58:24 comcerto daemon.info sip_ua[551]: fxo.cpp:320: ---> ts=33, state=Connected: Statistics received, ts=33, flags=0000, data=0
Apr  2 12:58:26 comcerto daemon.info sip_ua[551]: fxs.cpp:446: ---> ts=1, state=Connected: Statistics received, ts=1, flags=0000, data=0
Apr  2 12:58:26 comcerto daemon.info sip_ua[551]: fxs.cpp:446: ---> ts=1, state=Connected: Statistics received, ts=1, flags=0000, data=0
Apr  2 12:58:28 comcerto daemon.info sip_ua[551]: fxs.cpp:446: ---> ts=1, state=Connected: CAS event, ts=1, flags=0000, data=15
Apr  2 12:58:29 comcerto daemon.debug sip_ua[551]: comcerto.cpp:6513: ts 1: stopping RTP stream
Apr  2 12:58:29 comcerto daemon.info sip_ua[617]: repro.cpp:513: doSessionAccounting(): Session Ended 'branch=z9hG4bK1873538607'
Apr  2 12:58:29 comcerto daemon.info sip_ua[617]: repro.cpp:531: --> duration=603, []sip:83424176134@192.168.0.13: ---> [FXS]sip:301@192.168.0.4:
Apr  2 12:58:29 comcerto daemon.info sip_ua[617]: repro.cpp:698: --> CDR: {"answer":1554209306,"duration":603,"hangup":1554209909,"org-host":"192.168.0.13","org-name":"83424176134","org-scheme":"sip","org-user":"83424176134","to-host":"192.168.0.4","to-name":"Никули
Apr  2 12:58:29 comcerto daemon.info sip_ua[551]: fxs.cpp:446: ---> ts=1, state=Idle: Call disconnected, ts=1, flags=0000, data=196
Apr  2 12:58:29 comcerto daemon.debug sip_ua[578]: user_agent.cpp:1984: ---> transport 0: SIP event 16 (2xx received for request!): cid=196, did=-1, tid=251, rid=0, sid=0, nid=0
Apr  2 12:58:29 comcerto daemon.info sip_ua[551]: fxs.cpp:446: ---> ts=1, state=Idle: Message answered 2xx, ts=1, flags=0000, data=196
Apr  2 12:58:29 comcerto daemon.info sip_ua[617]: repro.cpp:513: doSessionAccounting(): Session Ended 'branch=z9hG4bK8FX3vcaUFgNBg'
Apr  2 12:58:29 comcerto daemon.info sip_ua[617]: repro.cpp:531: --> duration=645, [FXO]tel:83424176134@192.168.0.4: ---> []sip:ivr-705@192.168.0.13:
Apr  2 12:58:29 comcerto daemon.info sip_ua[617]: repro.cpp:698: --> CDR: {"answer":1554209264,"duration":645,"hangup":1554209909,"org-host":"192.168.0.4","org-scheme":"tel","org-type":"FXO","org-user":"83424176134","to-host":"192.168.0.13","to-scheme":"sip","to-user":"iv
Apr  2 12:58:29 comcerto daemon.info sip_ua[551]: fxo.cpp:320: ---> ts=33, state=Connected: Statistics received, ts=33, flags=0000, data=0
Apr  2 12:58:29 comcerto daemon.info sip_ua[551]: fxo.cpp:320: ---> ts=33, state=Connected: Statistics received, ts=33, flags=0000, data=0
Apr  2 12:58:31 comcerto daemon.info sip_ua[551]: fxo.cpp:320: ---> ts=33, state=Connected: TDM Call Progress detected, ts=33, flags=0000, data=52
Apr  2 12:58:31 comcerto daemon.info sip_ua[551]: fxo.cpp:320: ---> ts=33, state=Connected: TDM Call Progress detected, ts=33, flags=0000, data=52
Apr  2 12:58:32 comcerto daemon.info sip_ua[551]: fxo.cpp:320: ---> ts=33, state=Connected: TDM Call Progress detected, ts=33, flags=0000, data=52
Apr  2 12:58:32 comcerto daemon.debug sip_ua[551]: comcerto.cpp:6513: ts 33: stopping RTP stream
Apr  2 12:58:32 comcerto daemon.info sip_ua[551]: fxo.cpp:320: ---> ts=33, state=Idle: Call disconnected, ts=33, flags=0000, data=191
Apr  2 12:58:34 comcerto daemon.debug sip_ua[578]: user_agent.cpp:1984: ---> transport 0: SIP event 22 (Call Context is released!): cid=196, did=0, tid=0, rid=0, sid=0, nid=0
Apr  2 12:59:01 comcerto daemon.debug sip_ua[578]: user_agent.cpp:1984: ---> transport 0: SIP event 16 (2xx received for request!): cid=191, did=-1, tid=252, rid=0, sid=0, nid=0
Apr  2 12:59:01 comcerto daemon.info sip_ua[551]: fxo.cpp:320: ---> ts=33, state=Idle: Message answered 2xx, ts=33, flags=0000, data=191
Apr  2 12:59:16 comcerto daemon.debug sip_ua[578]: user_agent.cpp:1984: ---> transport 0: SIP event 22 (Call Context is released!): cid=191, did=0, tid=0, rid=0, sid=0, nid=0

[alx]

Здесь​ обмен SIP-сообщениями.

[alx]

Как видно из трассировки, BYE от FreeSwitch передается на адрес 192.168.0.4.6060 вместо 127.0.0.1:6060.

Замечено, что у канальных окончаний была настроена функция Session Timer. Если соединение разрывается до того как lineXosip2 хотя бы один раз отправит UPDATE, то проблемы нет. Предполагаемая причина проблемы - неверный домен в поле Contact сообщения UPDATE, которое генерирует libeXosip чтобы "освежить" таймер.

Предлагаемое решение - пропатчить libeXosip так, чтобы UPDATE генерировались всегда с адресом 127.0.0.1 в поле Contact.

[alx]

Replying to alx:

Предлагаемое решение - пропатчить libeXosip так, чтобы UPDATE генерировались всегда с адресом 127.0.0.1 в поле Contact.

Да, это помогает.

[alx]

In 1592/sip_ua:

Исправлена ошибка: при использовании Session Timer библиотека libeXosip2
самостоятельно генерировала UPDATE или INVITE для обновления таймера,
при этом в поле Contact ставила адрес внешнего интерфейса. В результате
последующие запросы в этом диалоге адресовались другой стороной на неверный
адрес и не доходили до шлюза. Теперь домен в поле Contact всегда устанавливается
в "127.0.0.1". Closes #318.