Context Navigation

← Previous Ticket
Next Ticket →

#257 closed баг (fixed)

Самопроизвольное завершение ESL соединения

Reported by:	dimag	Owned by:	alx
Priority:	blocker	Milestone:	2 очередь
Component:	MC04-SoftSwitch	Keywords:	ESL connection
Cc:	alx

Description

В версии 279 диспетчерской добавьте пользователей 1 и 122 на телефоне cisco в конференцию "Диспетчерская".
Отбейте пользователя 122. Если все будет благополучно, то конференция завершиться, соединение с ESL будет сохранено.
Повторите данное действие несколько раз, пока не произойдет самопроизвольный разрыв ESL соединения. После чего приходиться перезагружать всё, приэтом пропадают также и другие созданные конференции.

Данный дефект проявлялся и а Вариной программе.

Change History (14)

comment:1 by san, 8 years ago

Priority:	major → blocker

follow-up: 3 comment:2 by dimag, 8 years ago

Также данная ситуация возникает при попытке выполнить команду api create_uuid

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

Требуется больше информации.

Во-первых, непонятно, что значит "приходиться перезагружать всё". Что именно "всё"? И почему это приходится делать? От досады? :)

Во-вторых, хотелось бы видеть вывод tcpdump'а в момент потери соединения ESL.

В-третьих, не помешал бы подробный лог коммутатора в момент потери соединения (и непосредственно ему предшествующие).

Replying to dimag:

Также данная ситуация возникает при попытке выполнить команду api create_uuid

У меня не получается воспроизвести. Выполнил эту команду 100 раз, каждый раз получал UUID, соединение не пропало...

comment:4 by dimag, 8 years ago

Приходиться перезагружать всё, так как происходит обрыв соедения. В таком случае надо перезагрузить список и состояние пользователей, конференций, происходящих вызовов. Если этого не делать, то будет выводиться неверная информация, за время разрыва соединения может всё поменяться.
Обычно подобная ситуация возникает отбоя конференции после отключения предпоследнего пользователя при нажатие на кнопку "Отключить пользователя".
После этого часто при добавление нового пользователя в новую конференцию при вызове api create_uuid или при вызове функции esl_recv_event_timed происходит разрыв соединения, handle.connected становиться равной false, функция esl_recv_event_timed возвращает E_FAIL.

comment:5 by dimag, 8 years ago

Я проделал следующие действия: добавил пользователей 2, 122 в диспетчерскую, отключил пользователя 122 из Диспетчерской, сразу после этого произошёл обрыв связи. После получения сообщения conference::maintenance - stop-recording, обычно все обрывы происходят после прихода данного сообщения.
a=sendrecv
a=rtpmap:0 PCMU/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16

--end msg--
10:35:26.542 CPJSIPSUA .........Call 0 state=CONNECTING
10:35:26.544 pjsua_core.c .RX 401 bytes Request msg ACK/cseq=94678799 (rdata02C3CAA4) from UDP 192.168.0.63:5060:
ACK sip:2@192.168.0.90:5060;ob SIP/2.0
Via: SIP/2.0/UDP 192.168.0.63;rport;branch=z9hG4bKBt0cFcBg9e4Uc
Max-Forwards: 70
From: "╨Ф╨╕╤Б╨┐╨╡╤В╤З╨╡╤А╤Б╨║╨░╤П" <sip:2@192.168.0.63>;tag=78K2gaDUg11tB
To: <sip:2@192.168.0.90:5060;ob>;tag=64be44e4f1ac4850be3be7bed047db29
Call-ID: 9768ca57-d24c-1234-3b87-902b3433882b
CSeq: 94678799 ACK
Contact: <sip:mod_sofia@192.168.0.63:5060>
Content-Length: 0

--end msg--
10:35:26.545 CPJSIPSUA ...Call 0 state=CONFIRMED
PRESENCE_IN - outbound-2@192.168.0.63-answered
CHANNEL_CALLSTATE - CS_CONSUME_MEDIA-ACTIVE-answered
CS_CONSUME_MEDIA-ACTIVE
CHANNEL_CALLSTATE - CS_HANGUP-HANGUP-outbound-HANGUP
PRESENCE_IN - outbound-2@192.168.0.63-CS_ROUTING - answered
CUSTOM - conference::maintenance - conference-create - 0 - -
Events Processed - 5
MainAppFrameWindow3::RefreshUserListState()
PRESENCE_IN - outbound-0@192.168.0.63-
MainAppFrameWindow3::RefreshConferencesListState(const QString &sConference)
MainAppFrameWindow3::RefreshParicipantsState(const QString &sConference)
CUSTOM - conference::maintenance - add-member - 0 - 2@192.168.0.63 - 2
MainAppFrameWindow3::RefreshParicipantsState(const QString &sConference)CUSTOM -
conference::maintenance - video-floor-change - 0 - -
CUSTOM - conference::maintenance - floor-change - 0 - 2@192.168.0.63 - 2
Events Processed - 4
MainAppFrameWindow3::RefreshUserListState()
MainAppFrameWindow3::RefreshConferencesListState(const QString &sConference)
MainAppFrameWindow3::RefreshParicipantsState(const QString &sConference)
10:35:27.199 strm058D7D4C VAD re-enabled
CUSTOM - conference::maintenance - play-file-done - 0 - -
CUSTOM - sofia::register - test12
PRESENCE_IN - outbound-122@192.168.0.63-CS_ROUTING - ringing
MainAppFrameWindow3::RefreshConferencesListState(const QString &sConference)
MainAppFrameWindow3::RefreshParicipantsState(const QString &sConference)
CHANNEL_CALLSTATE - CS_CONSUME_MEDIA-RINGING-ringing
CS_CONSUME_MEDIA-RINGING
MainAppFrameWindow3::RefreshUserListState()
MainAppFrameWindow3::RefreshParicipantsState(const QString &sConference)
CUSTOM - conference::maintenance - start-talking - 0 - 2@192.168.0.63 - 2
api status is OK
HEARTBEAT -
PRESENCE_IN - outbound-122@192.168.0.63-answered
CHANNEL_CALLSTATE - CS_CONSUME_MEDIA-ACTIVE-answered
CS_CONSUME_MEDIA-ACTIVE
CHANNEL_CALLSTATE - CS_HANGUP-HANGUP-outbound-HANGUP
PRESENCE_IN - outbound-122@192.168.0.63-CS_ROUTING - answered
Events Processed - 4
MainAppFrameWindow3::RefreshUserListState()
MainAppFrameWindow3::RefreshParicipantsState(const QString &sConference)PRESENCE_IN -
inbound-0@192.168.0.63-
CUSTOM - conference::maintenance - add-member - 0 - 122@192.168.0.63 - 122
CUSTOM - conference::maintenance - start-recording - 0 - -
Events Processed - 3
MainAppFrameWindow3::RefreshUserListState()
MainAppFrameWindow3::RefreshConferencesListState(const QString &sConference)
MainAppFrameWindow3::RefreshParicipantsState(const QString &sConference)
CUSTOM - conference::maintenance - play-file-done - 0 - -
CUSTOM - conference::maintenance - stop-talking - 0 - 2@192.168.0.63 - 2
CUSTOM - conference::maintenance - start-talking - 0 - 2@192.168.0.63 - 2
CUSTOM - conference::maintenance - stop-talking - 0 - 2@192.168.0.63 - 2
PRESENCE_IN - outbound-0@192.168.0.63-
CUSTOM - conference::maintenance - del-member - 0 - 122@192.168.0.63 - 122
Events Processed - 2
MainAppFrameWindow3::RefreshUserListState()
PRESENCE_IN - outbound-0@192.168.0.63-
MainAppFrameWindow3::RefreshConferencesListState(const QString &sConference)CUSTOM -
conference::maintenance - MainAppFrameWindow3::RefreshParicipantsState(const QString &sConference)conference-destroy - 0 - -

CUSTOM - conference::maintenance - stop-recording - 0 - -
Events Processed - 3

comment:6 by alx, 8 years ago

Вывод tcpdump при потере соединения:

08:49:13.280209 IP 192.168.0.63.8021 > 192.168.0.90.51019: Flags [P.], seq 54081:54133, ack 917, win 63, options [nop,nop,TS val 152232121 ecr 676407], length 52
08:49:13.280259 IP 192.168.0.63.8021 > 192.168.0.90.51019: Flags [.], seq 54133:55581, ack 917, win 63, options [nop,nop,TS val 152232121 ecr 676407], length 1448
08:49:13.280380 IP 192.168.0.63.8021 > 192.168.0.90.51019: Flags [P.], seq 55581:56598, ack 917, win 63, options [nop,nop,TS val 152232121 ecr 676407], length 1017
08:49:13.280568 IP 192.168.0.90.51019 > 192.168.0.63.8021: Flags [.], ack 56598, win 16652, options [nop,nop,TS val 676410 ecr 152232121], length 0
08:49:13.467313 IP 192.168.0.63.8021 > 192.168.0.90.51019: Flags [F.], seq 56598, ack 917, win 63, options [nop,nop,TS val 152232167 ecr 676410], length 0
08:49:13.467447 IP 192.168.0.90.51019 > 192.168.0.63.8021: Flags [.], ack 56599, win 16652, options [nop,nop,TS val 676428 ecr 152232167], length 0
08:49:13.477386 IP 192.168.0.90.51019 > 192.168.0.63.8021: Flags [P.], seq 917:927, ack 56599, win 16652, options [nop,nop,TS val 676429 ecr 152232167], length 10
08:49:13.477411 IP 192.168.0.63.8021 > 192.168.0.90.51019: Flags [R], seq 1057376487, win 0, length 0
08:49:13.477416 IP 192.168.0.90.51019 > 192.168.0.63.8021: Flags [P.], seq 927:929, ack 56599, win 16652, options [nop,nop,TS val 676429 ecr 152232167], length 2

in reply to: description comment:7 by san, 8 years ago

Акцентирую внимание на фразе
Replying to dimag:

приэтом пропадают также и другие созданные конференции.

Тоже замечал что после этой "потери соединения" перестают существовать и другие конференции присутствовавшие на сервере.

comment:8 by dimag, 8 years ago

я запускал fs_cli для 192.168.0.63. При этом при разрыве соединения происходит также и завершение работы программы fs_cli, то есть разываются все ESL соединения. Последние строки выведенные fs_cli.
2016-08-01 12:46:39.088867 [INFO] mod_dialplan_xml.c:637 Processing Диспетчерская <2>->0 in context conference
2016-08-01 12:46:39.088867 [DEBUG] switch_core_state_machine.c:700 (loopback/test11-a) Running State Change CS_DESTROY
2016-08-01 12:46:39.088867 [DEBUG] switch_core_state_machine.c:710 (loopback/test11-a) State DESTROY
2016-08-01 12:46:39.088867 [DEBUG] switch_core_state_machine.c:181 loopback/test11-a Standard DESTROY
2016-08-01 12:46:39.088867 [DEBUG] switch_core_state_machine.c:710 (loopback/test11-a) State DESTROY going to sleep
Dialplan: sofia/internal/test11@192.168.0.118:39668 parsing [conference->Call extention to conference] continue=false
Dialplan: sofia/internal/test11@192.168.0.118:39668 Absolute Condition [Call extention to conference]
Dialplan: sofia/internal/test11@192.168.0.118:39668 Action execute_extension(${dialed_user} XML answered)
Dialplan: sofia/internal/test11@192.168.0.118:39668 Action answer()
Dialplan: sofia/internal/test11@192.168.0.118:39668 Action conference(${destination_number}@default)
2016-08-01 12:46:39.088867 [INFO] switch_channel.c:3127 sofia/internal/test11@192.168.0.118:39668 Flipping CID from "Диспетчерская" <2> to "Outbound Call" <test11>
2016-08-01 12:46:39.088867 [DEBUG] switch_core_state_machine.c:286 (sofia/internal/test11@192.168.0.118:39668) State Change CS_ROUTING -> CS_EXECUTE
2016-08-01 12:46:39.088867 [DEBUG] switch_core_state_machine.c:602 (sofia/internal/test11@192.168.0.118:39668) State ROUTING going to sleep
2016-08-01 12:46:39.088867 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/test11@192.168.0.118:39668) Running State Change CS_EXECUTE
2016-08-01 12:46:39.088867 [DEBUG] switch_core_state_machine.c:609 (sofia/internal/test11@192.168.0.118:39668) State EXECUTE
2016-08-01 12:46:39.088867 [DEBUG] mod_sofia.c:197 sofia/internal/test11@192.168.0.118:39668 SOFIA EXECUTE
2016-08-01 12:46:39.088867 [DEBUG] switch_core_state_machine.c:328 sofia/internal/test11@192.168.0.118:39668 Standard EXECUTE
EXECUTE sofia/internal/test11@192.168.0.118:39668 execute_extension(test11 XML answered)
2016-08-01 12:46:39.088867 [INFO] mod_dialplan_xml.c:637 Processing Outbound Call <test11>->test11 in context answered
Dialplan: sofia/internal/test11@192.168.0.118:39668 parsing [answered->Stop-alarm] continue=false
Dialplan: sofia/internal/test11@192.168.0.118:39668 Regex (FAIL) [Stop-alarm] ${hash(select/alarms/${destination_number})}() =~ /1/ break=on-false
EXECUTE sofia/internal/test11@192.168.0.118:39668 answer()
EXECUTE sofia/internal/test11@192.168.0.118:39668 conference(0@default)
2016-08-01 12:46:39.088867 [DEBUG] conference_member.c:1654 Raw Codec Activation Success L16@8000hz 1 channel 20ms
2016-08-01 12:46:39.088867 [DEBUG] conference_member.c:1701 Raw Codec Activation Success L16@8000hz 1 channel 20ms
2016-08-01 12:46:39.088867 [DEBUG] switch_core_codec.c:221 sofia/internal/test11@192.168.0.118:39668 Push codec L16:100
2016-08-01 12:46:39.088867 [DEBUG] conference_member.c:128 sofia/internal/test11@192.168.0.118:39668 binding '#' to 'hangup'
2016-08-01 12:46:39.088867 [INFO] switch_ivr_async.c:214 Digit parser mod_conference: Setting realm to 'conf'
2016-08-01 12:46:39.088867 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding #/conf/0 callback: 0x7f848a53f2a0 data: 0x7f841402a538
2016-08-01 12:46:39.088867 [DEBUG] conference_loop.c:1101 Setup timer soft success interval: 20 samples: 160
2016-08-01 12:46:39.088867 [INFO] mod_conference.c:353 Auto recording file: /var/lib/freeswitch/recordings/0_2016-08-01-12-46-39.wav
2016-08-01 12:46:39.088867 [DEBUG] conference_record.c:274 Setup timer success interval: 20 samples: 160
2016-08-01 12:46:39.228865 [DEBUG] switch_rtp.c:6670 Correct audio ip/port confirmed.
2016-08-01 12:46:45.108898 [INFO] conference_loop.c:1400 Channel leaving conference, cause: NONE
2016-08-01 12:46:45.108898 [DEBUG] switch_core_codec.c:246 sofia/internal/test12@192.168.1.67:5060 Restore previous codec PCMU:0.
2016-08-01 12:46:45.108898 [DEBUG] switch_ivr_play_say.c:1467 Codec Activated L16@8000hz 1 channels 20ms
2016-08-01 12:46:45.128897 [NOTICE] mod_conference.c:726 Hangup sofia/internal/test11@192.168.0.118:39668 [CS_EXECUTE] [NORMAL_CLEARING]
обратите внимание на последующие строки.
2016-08-01 12:46:45.128897 [DEBUG] mod_conference.c:776 Write Lock ON
2016-08-01 12:46:45.128897 [INFO] conference_record.c:388 Recording of /var/lib/freeswitch/recordings/0_2016-08-01-12-46-39.wav Stopped
freeswitch@…>

comment:9 by alx, 8 years ago

Replying to san:

приэтом пропадают также и другие созданные конференции.

Там не только конференции пропадают, все хуже и прозаичнее:

kernel: [623857.763049] freeswitch[28135]: segfault at 18 ip 00007f887a446336 sp 00007f880fb130d0 error 4 in libfreeswitch.so.1.0.0[7f887a380000+48a000]
systemd[1]: freeswitch.service: Main process exited, code=killed, status=11/SEGV

follow-up: 12 comment:10 by alx, 8 years ago

Кажется, мы наткнулись на этот баг: https://freeswitch.org/jira/browse/FS-9314

Изменил в конфигурации конференций параметр "video-mode" с "mux" на "passthrough", падения прекратились (сделал 10 тестов).

comment:11 by dimag, 8 years ago

Resolution:	→ fixed
Status:	new → closed

Протестировал все ситуации при которых у меня возникала это ошибка в r289.
Ошибка не воспроизвелась. Можно закрывать ошибку.

in reply to: 10 ; follow-up: 13 comment:12 by san, 8 years ago

Replying to alx:

Изменил в конфигурации конференций параметр "video-mode" с "mux" на "passthrough"

Алексей, напиши ещё в каком из конфиг файлов этот параметр, имя файла

in reply to: 12 comment:13 by alx, 8 years ago

Replying to san:

Алексей, напиши ещё в каком из конфиг файлов этот параметр, имя файла

autoload_configs/conference.conf.xml

comment:14 by san, 6 years ago

Milestone:	Текущее → 2 очередь

Milestone renamed

Note: See TracTickets for help on using tickets.

Download in other formats: