Нет CDR если нет связи с платой VE-01 по IP

[san]

От двух разных пользователей поступили жалобы что, несмотря на большое количество вызовов, файлы CDR не появляются в веб-интерфейсе. Описанная проблема возникла после того как плату SW убрали в отдельный от ve VLAN, до этого CDR появлялись в веб-интерфейсе.

1. АТС Атняшка
2. АТС Суда(r1777, ревизия VE-01 50) - Тут пользователь пошел дальше и провёл эксперимент - поменял настройки коммутатора, восстановив IP-соединение между платами, CDR начали появляться в веб-интерфейсе. Снова настроил VLAN - CDR перестали записываться. (эксперимент записан со слов пользователя в телефонном разговоре, так что может содержать неточности). На этой Атс можно попробовать воспроизвести деффект, раз у нас он не воспроизводится.

[alx]

Прошу обновить пакет sw до r1783, воспроизвести проблему (выполнить успешный звонок) и приложить сюда лог платы.

[alx]

Из приложенного журнала видно, что CDR плата SW-01 получает.

[san]

В приложенном вложении лог следующего эксперимента.
Примерно в 6-00 UTC был осуществлён вызов окончания АДАСЭ 2817, разговор длился несколько секунд, ожидалось что появится CDR запись, но запись не появилась.

[alx]

Возможно ли скачать из этой платы файл(ы) базы данных? Она хранится в файлах /usr/share/sw/storage.db*
Перед копированием базы было бы полезно выполнить рестарт swd.

[alx]

Replying to san:

ожидалось что появится CDR запись, но запись не появилась.

Уточни, пожалуйста, что значит "не появилась". Что делали, что ожидали получить в результате, и что получили вместо ожидаемого результата.

[alx]

В приложенном логе в последней CDR я вижу время ответа 5 января 1970 года. Рискну предположить, что эта дата не попадала в диапазон, заданный в веб-интерфейсе при попытке просмотра.

[san]

что значит "не появилась"

После нажатия кнопки "обновить" CDR звонка совершенного сегодня не отобразилось в CDR записях с фильтром "Сегодня"

[alx]

Как выяснилось, текущее время SW-01 передает плате VE-01 при каждой записи конфигурации. При получении этого времени плата VE-01 безусловно применяет его через вызов settimeofday(). В случае, если settimeofday() ошибку, в журнал платы VE-01 выводится соответствующее сообщение. В связи с этим было бы интересно посмотреть лог платы VE-01, предварительно установив журналу приоритет не ниже INFO, а затем записав настройки в плату. Возможно в журнале будет присутствовать сообщение "error settimg current time: *".

[alx]

Как промежуточный итог рассмотренной ситуации я вижу здесь две разные проблемы:

1. Неверное время в системных часах платы VE-01, хотя ожидалось, что время должно быть установлено при получении его от платы SW-01 по SPI (см. comment:9). Это отдельный вопрос, почему так происходит, предлагаю создать отдельный тикет.

2. Отсутствие в базе данных некоторых записей CDR. Это очень странно, так как мы видим (по приложенному журналу), что CDR в плату SW-01 приходят. Однако в приложенной базе данных присутствует только одна последняя CDR из имеющихся в журнале. В коде я вижу только два условия незаписи - если это повторное сообщение с той же самой CDR (как видно из журнала, каждая CDR приходит дважды из соображений надежности) и если не смогли распарсить полученную CDR. Но в последнем случае в журнал должно выводиться сообщение "CDR parse error: xxxxxx", чего в журнале нет.

Если CDR успешно распрарсили, она сразу записывается в базу данных. При записи в базу тоже может возникнуть ошибка, но все ошибки кроме SQLITE_BUSY приводят к выводу в журнал записи "storage.db: error inserting into cdr: xxx (xxxxxxxxx)", чего мы в журнале не видим.

Остается ошибка SQLITE_BUSY, при возникновении которой CDR, которую не смогли записать в базу данных сразу, помещается во временный список в ОЗУ, из которого они записываются в базу позже (в отдельном потоке, выполняющемся каждый час), когда база освободится. И вот здесь есть ограничение на размер списка (защита от исчерпания всей свободной памяти): если в списке уже лежит 100 CDR, новый CDR молча уничтожается. Но, как видно из приложенного журнала, 100 CDR в течение часа в плату SW-01 не поступало, следовательно, ограничение размера временного списка достигнуто не было...

Как результат - я не понимаю, почему записей нет в базе...

Предлагаю сделать специальный вариант swd, в который добавить дополнительный отладочный вывод в ключевых точках. Дать ему поработать, например, сутки, после чего снова забрать журнал и базу данных для дальнейшего анализа. Как вариант, можно установить в плату SW-01 пакет sqlite3 и смотреть содержимое базы данных прямо в SW-01. Вероятно, это будет быстрее и удобнее чем каждый раз скачивать файлы...

[alx]

В тестовой версии swd добавлен дополнительный вывод в журнал сообщений:

• об успешном парсинге CDR;
• об успешной записи принятой CDR в DB;
• об откладывании записи CDR во временный список;
• об уничтожении CDR из-за переполнения временного списка;
• об успешной повторной записи в DB CDR из временного списка.

[alx]

Проблема 1 (см. comment:10) исправлена в ​ve:r1679.

[san]

Выше прикрепил архив с файлами, а вот описание самого эксперимента:

Эксперимент:

1. Записал тестовый swd в плату
2. Перезапустил swd
3. Скачал базу old_storage
4. UTC 7:57. наблюдал в Sip_окончаниях разговор и его завершение(вызываемый 2817)
5. Перешел на вкладку CDR, сделал поиск по базе сегодня и с 1970 года.
6. Перезапустил swd
7. Скачал базу storage
8. Скачал лог

• странность 1: в логе я не вижу попытки записи CDR в 7-57
• странность 2: когда я делал поиск по базе с 1970 года я не увидел записи от эксперимента comment:4

[alx]

Пропадание CDR из базы объясняется тем, что каждый час из базы данных удаляются CDR соединений, закончившихся более 90 дней назад. Так как, как мы уже установили, в плате VE-01 системное время неправильное (5 января 1970 года), все сделанный в течение часа записи оказываются старее 90 дней и удаляются в начале очередного часа. Считаю, что этим и объясняется наблюдаемое поведение базы, на которое жаловались пользователи.