Opened 6 years ago

Closed 6 years ago

Last modified 3 years ago

#318 closed баг (fixed)

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

Reported by: alx Owned by: alx
Priority: средний Milestone: 1 очередь
Component: any Keywords:
Cc:

Description

На нашей АТС 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

Attachments (1)

BUG2.txt​ (19.1 KB ) - added by alx 6 years ago.

Download all attachments as: .zip

Change History (5)

by alx, 6 years ago

Attachment: BUG2.txt​ added

comment:1 by alx, 6 years ago

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

comment:2 by alx, 6 years ago

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

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

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

Last edited 3 years ago by alx (previous) (diff)

in reply to:  2 comment:3 by alx, 6 years ago

Replying to alx:

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

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

comment:4 by alx, 6 years ago

Resolution: → fixed
Status: new → closed

In 1592/sip_ua:

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

Note: See TracTickets for help on using tickets.