Opened 10 days ago

Closed 8 days ago

Last modified 7 days ago

#446 closed баг (fixed)

перезагрузка платы VE-02 при вызове в статическую конференцию

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

Description

В плате создана статическая конференция со спикером disp@. В ходе тестов обнаружился баг: плата перезагружается при попытке вызовом спикером оператора в конференцию. Но баг воспроизводится только если перед вызовом в окончании спикера поменять URI с произвольного на URI спикера.
Эксперимент:

  1. Меняем URI окончания FXS (канал 255) с 11@192.168.0.121 на disp@192.168.0.121, нажимаем "Окей", дальше "Применить".
  2. Сразу же после этого на телефоне, подключенном к этому окончанию, набираю "022".
  3. Плата VE-02 перестает отвечать и через некоторое время перезагружается.

Прикладываю конфигурацию платы VE-02 и лог-файл с платы VE-02 с момента изменения конфигурации до перезагрузки платы.

Версия ПО VE-02: 52

Attachments (6)

config-export-VE-02.xml (1.5 KB ) - added by roman_zhur 10 days ago.
messages (16.3 KB ) - added by roman_zhur 10 days ago.
messages_log (13.4 KB ) - added by roman_zhur 9 days ago.
messages.2 (16.6 KB ) - added by roman_zhur 9 days ago.
messages3 (32.1 KB ) - added by roman_zhur 8 days ago.
messages4 (27.8 KB ) - added by roman_zhur 8 days ago.

Download all attachments as: .zip

Change History (25)

by roman_zhur, 10 days ago

Attachment: config-export-VE-02.xml added

by roman_zhur, 10 days ago

Attachment: messages added

comment:1 by alx, 9 days ago

Мне, к сожалению, не удается воспроизвести баг, однако благодаря приведенному логу я приблизительно локализовал проблемное место - судя по логу, процесс sip_ua убивается каким-то сигналом при попытке вызвать в конференцию участника в соответствии с параметром "Автоматический вызов".

Чтобы попытаться понять, в чем же проблема, я прошу провести еще несколько экспериментов.

  1. Очистить параметр "Автоматический вызов" (то есть там должна быть пустая строка) и попытаться воспроизвести баг - воспроизводится ли?
  1. Добавить в параметр "Автоматический вызов" пробел в конце (то есть должно быть $1 - "доллар"-"один"-"пробел") - воспроизводится ли баг?

comment:2 by alx, 9 days ago

Еще меня смущает упоминание спикера. Дело в том, что параметр "Спикеры" применяется только при отключении участника от конференции. При подключении он не используется, поэтому не должно быть никакой разницы, спикер ли подключается к конференции или кто-то другой... Придумал еще один эксперимент:

  1. Очистить параметр "Спикеры" (сделать пустой строкой) и попробовать воспроизвести баг - будет ли воспроизводиться?

in reply to:  1 ; comment:3 by roman_zhur, 9 days ago

  1. Если очистить "Автоматический вызов", то баг не воспроизводится.
  2. Если "Автоматический вызов" написать с пробелом, то баг воспроизводится.
  3. Если очистить "Спикеры", то баг воспроизводится.

in reply to:  3 comment:4 by alx, 9 days ago

Спасибо. Догадка в целом подтверждается, но я по-прежнему не могу понять, в чем конкретно проблема.

Чтобы точнее локализовать место падения я надобавлял отладочный вывод в sip_ua. Прошу обновить этот файл в плате и повторить тест следующим образом:

  • Зайти в плату и выполнить:
    • wget http://192.168.0.75/tmp/sip_ua;
    • chmod 755 sip_ua;
    • mv sip_ua /usr/bin/;
  • Выполнить рестарт платы;
  • Воспроизвести баг;
  • Привести здесь соответствующий фрагмент лога (от "dialing 022" и до перезагрузки).

by roman_zhur, 9 days ago

Attachment: messages_log added

comment:5 by alx, 9 days ago

О, уже интереснее. Оказывается, падает не совсем там, где я думал. Теперь ясно, что падение происходит в функции outcall()... Пошел исследовать ее код...

comment:6 by alx, 9 days ago

Ничего подозрительного в коде не заметил...

Добавил отладочный вывод в новые места. Воспроизведи, пожалуйста, баг еще раз с новым файлом sip_ua (лежит на том же месте).

Last edited 9 days ago by alx (previous) (diff)

by roman_zhur, 9 days ago

Attachment: messages.2 added

comment:7 by alx, 8 days ago

Место падения локализовано практически до одной строчки, но я не вижу в ней абсолютно ничего подозрительного. Закрадывается мысль об аппаратном дефекте платы (например "битое" ОЗУ)... Попробуй заменить плату - с другой платой VE-02 будет ли воспроизводиться баг?

Если будет, запиши туда, пожалуйста, новый sip_ua (выложил на прежнее место) и воспроизведи падение - я добавил новый отладочный вывод...

comment:8 by roman_zhur, 8 days ago

Данный баг изначально был обнаружен на другой плате VE-02. То есть сначала перезагрузку я заметил на одной плате, тестирование из этого тикета проводились на другой плате и лог messages3​ с третьей платы.

Плату заменил, заменил на ней файл sip_ua. Баг воспроизвелся, лог прилагаю.

Last edited 8 days ago by roman_zhur (previous) (diff)

by roman_zhur, 8 days ago

Attachment: messages3 added

comment:9 by san, 8 days ago

Стоит ещё заметить, что баг воспроизводится не всегда, а с некоторой вероятностью.
Иногда Роман повторяет алгоритм воспроизведения и баг воспроизводится стабильно несколько раз подряд, а иногда, наоборот, не воспроизводится долгое время.

in reply to:  9 comment:10 by alx, 8 days ago

Replying to san:

Стоит ещё заметить, что баг воспроизводится не всегда, а с некоторой вероятностью.

Да, я вижу. Например в последнем логе сначала успешный вызов, а на второй попытке - перезагрузка...

comment:11 by roman_zhur, 8 days ago

На третьей плате VE-02 количество перезагрузок выросло. Сейчас при звонке disp -> 022 и последующем звонке op1 -> disp плата так же уходит в перезагрузку.

by roman_zhur, 8 days ago

Attachment: messages4 added

comment:12 by alx, 8 days ago

После изучения логов (кроме последнего) я заметил одну "странность", и у меня возник вопрос...

Но для начала немного сопутствующей информации. Когда в конференции появляется участник, в MSP для этого создается специальный "канал", которому MSP присваивает уникальный идентификатор. Я заметил (это не документировано, но по факту всегда так), что в качестве идентификатора всегда выбирается минимальное незанятое число начиная с 1: то есть первый участник - 1, второй - 2, третий - 3 и т.д. Если, например, участник 1 уничтожается (вышел из конференции), то следующий созданный учасник получает идентификатор 1.

Так как по "историческим" причинам в нашем коде все каналы идентифицируются таймслотами (даже если они, как участники конференции, вообще не имеют отношения к шине TDM), участникам конференций дается номер таймслота путем добавления к их идентификатору числа 1000. То есть участник конференции 1 как бы имеет таймслот 1001.

А теперь к "странности". Из описания тикета я понял ситуацию так, что исходным состоянием является пустая конференция (без участников). Затем окончание 255 (disp) вызывает конференцию и становится ее первым участником. Этот участник получает идентификатор 1 и, соответственно, таймслот 1001. Затем конференция вызывает оператора (22), для чего создает второго участника, который получает идентификатор 2 и таймслот 2002. В моих экспериментах именно так и происходит.

Однако в приложенных логах я вижу другое: disp, вызывая конференцию, получает таймслот 1002, это видно, например, в строчке лога:

conference.cpp:748: ---> ConferenceParticipant[1002]: Incoming call, ts=1002, flags=0006, data=2

А вызываемый участник 22 получает таймслот 1003:

conference.cpp:748: ---> ConferenceParticipant[1003]: REFER received, ts=1003, flags=0000, data=0

это видно если не произошло "падения", например в messages3.

То есть получается, что идентификатор 1 участника конференции занят - такой участник уже существует... Возникает вопрос - почему так? Кто это? Других статических конференций (кроме 00) в конфиге платы нет. Тогда что это за участник такой и откуда взялся? До того как disp вызывает номер 022 есть еще какая-то предыстория, не упомянутая в описании тикета?

Last edited 8 days ago by alx (previous) (diff)

comment:13 by alx, 8 days ago

Возникло у меня еще одно подозрение. Для его подтверждения (или развеивания) я прошу сделать следующее: в настройках disp и 22 запретить использование SRTP и после этого попробовать воспроизвести баг.

Если воспроизведется, хочется увидеть лог двух последних попыток (то есть той, на которой плата перезагрузилась, и предыдущей тоже).

comment:14 by alx, 8 days ago

Кстати, какой телефон используется абонентом 22?

comment:15 by alx, 8 days ago

Кажется я нашел потенциальную причину падений. Попробуй, пожалуйста, воспроизвести с новым вариантом sip_ua (положил на прежнее место). Эксперимент с отключением SRTP наверное можно не проводить (т.е. вернуть все настройки как было изначально).

comment:16 by alx, 8 days ago

Я решил, что предыдущий вариант тоже был неправильным, и теперь сделал новый sip_ua - в нем таймслот участника конференции вообще не привязан к идентификатору канала, возвращаемому из MSP. Предполагаю, что падений не будет. Проверь, пожалуйста.

Last edited 8 days ago by alx (previous) (diff)

in reply to:  16 comment:17 by roman_zhur, 8 days ago

Файл заменил, падений не было.

comment:18 by alx, 8 days ago

Resolution: fixed
Status: newclosed

In 2466/sip_ua:

Исправлена ошибка: участник конференции мог изменить свой таймслот "на ходу".

Раньше таймслот участника формировался добавлением константы
(1000) к идентификатору, возвращаемому из MSP. Иногда
в процессе работы участник пересоздается (например при активации
медиапотока с SRTP), и MSP может вернуть другой идентификатор.
Изменение таймслота в ходе работы приводит к тому, что сообщения
о событиях доставляются не тому канальному окончанию, какому должно,
и впоследствии к падению и перезагрузке платы.

Теперь таймслот выбирается из пула свободных раз и навсегда при
создании объекта ConferenceParticipant и освобождается при его уничтожении.

Closes #446.

comment:19 by alx, 7 days ago

Обновленные прошивки VE-01 и VE-02 исполнения 1 уже в репозитории. Можно обновить штатным образом.

Note: See TracTickets for help on using tickets.