Проблема с сохранением видео

snark13

Member
После апгрейда WCS с версии 572 на 1222 перестал вызываться on_record_hook.sh на окончание записи фрагмента видео
При изучении логов - обнаружено что при закрытии файлов с записью возникает исключение и дальше соответственно скрипт не отрабатывает

Фрагмент логов -

Code:
09:16:30,048 ERROR         FileRecorder - CommonFileRecorderThread-1 Failed to close writer /usr/local/FlashphonerWebCallServer/records/D15H-{startTimeMillis}-{endTimeMillis}.ts
java.lang.RuntimeException: getCreationModificationTime not supported
        at com.flashphoner.media.output.ffmpeg.IJavaWriter.getCreationModificationTime(Unknown Source)
        at com.flashphoner.media.output.ffmpeg.JavaFileOutputWriter.getCreationModificationTime(Unknown Source)
        at com.flashphoner.media.output.ffmpeg.FileRecorder.closeCurrentWriter(Unknown Source)
        at com.flashphoner.media.output.ffmpeg.FileRecorder.reInit(Unknown Source)
        at com.flashphoner.media.output.ffmpeg.FileRecorder.startNewRecordOnKeyFrame(Unknown Source)
        at com.flashphoner.media.output.ffmpeg.FileRecorder.writeVideo(Unknown Source)
        at com.flashphoner.media.output.ffmpeg.CommonFileRecorderThread.feedWriter(Unknown Source)
        at com.flashphoner.media.output.ffmpeg.CommonFileRecorderThread.run(Unknown Source)
Такое происходит на каждый сегмент который сохраняется

Версия Java -

Code:
root@wcs-demo-2:/usr/local/FlashphonerWebCallServer/logs/server_logs# java --version
java 14.0.2 2020-07-14
Java(TM) SE Runtime Environment (build 14.0.2+12-46)
Java HotSpot(TM) 64-Bit Server VM (build 14.0.2+12-46, mixed mode, sharing)
настройки записи -

Code:
record_rotation=30
# record_h264_to_ts=true
record_formats=h264-ts,vp8-webm
stream_record_policy_template={streamName}-{startTimeMillis}-{endTimeMillis}
record_rotation_index_enabled=false
on_record_hook_script=/usr/local/FlashphonerWebCallServer/bin/on_record_hook.sh
Сами же файлы в /usr/local/FlashphonerWebCallServer/records сохраняются успешно с правильными именами - например - D15H-1653383727982-1653383758033.ts

Апдейты -
Смена Java на 17.0.2 не дала никаких результатов - та же ошибка.
Хост - Ubuntu 20.4.1 LTS
 
Last edited:

Max

Administrator
Staff member
Здравствуйте.

На эту проблему заведены два бага: WCS-3460, WCS-3496
Релиз планируется на этой неделе.

После релиза, описание будет доступно в Release Notes
Таже отпишем в эту тему.
 

Max

Administrator
Staff member
Проблема исправлена в сборке 5.2.1227. Обращаем внимание. что для скачивания из РФ может потребоваться VPN, в этом случае команда webcallserver update работать не будет, необходимо скачать пакет сборки через VPN и обновить в соответствии с документацией
 

snark13

Member
После апгрейда на версию 1244 команда записи стала отрабатываться корректно, но возникла другая проблема.
После нескольких дней онлайна на сервере начинают лавинообразно образовываться заблокированные треды. При этом команда старта записи как раз отработаться не может и тред который ее принимает (REST запрос) присоединяется к заблокированным -

Вот пример поиска по слову "HTTP-pool-3-thread-3166" в текущем логе -
Code:
10:30:12,556 INFO         RestApiRouter - HTTP-pool-3-thread-3166 Use controller class com.flashphoner.rest.server.rest_v2.RestRecorderController with path /rest-api/recorder/startup
10:30:12,556 INFO  stRecorderController - HTTP-pool-3-thread-3166 handleRequest /rest-api/recorder/startup params:{mediaSessionId=f9a65e08-180f-492d-810a-644c0bd88559}
235:HTTP-pool-3-thread-3166:BLOCKED:12611
235:HTTP-pool-3-thread-3166:BLOCKED:12613
235:HTTP-pool-3-thread-3166:BLOCKED:143080
235:HTTP-pool-3-thread-3166:BLOCKED:143082
235:HTTP-pool-3-thread-3166:BLOCKED:254894
236:HTTP-pool-3-thread-3166:BLOCKED:254897
236:HTTP-pool-3-thread-3166:BLOCKED:264609
236:HTTP-pool-3-thread-3166:BLOCKED:264610
а вот сколько раз встречается ":BLOCKED:" в текущих логах -

Code:
root@wcs-demo-2:/usr/local/FlashphonerWebCallServer-5.2.1244/logs/server_logs# for fn in *; do echo -n "$fn : "; grep ":BLOCKED:" $fn | wc -l; done
flashphoner.log : 85715
flashphoner.log.2022-06-14-11 : 0
flashphoner.log.2022-06-14-12 : 0
flashphoner.log.2022-06-14-13 : 0
flashphoner.log.2022-06-14-14 : 0
flashphoner.log.2022-06-14-15 : 0
flashphoner.log.2022-06-14-16 : 0
flashphoner.log.2022-06-14-17 : 0
flashphoner.log.2022-06-14-18 : 0
flashphoner.log.2022-06-14-19 : 0
flashphoner.log.2022-06-14-20 : 0
flashphoner.log.2022-06-14-21 : 0
flashphoner.log.2022-06-14-22 : 0
flashphoner.log.2022-06-14-23 : 0
flashphoner.log.2022-06-15-00 : 465
flashphoner.log.2022-06-15-01 : 0
flashphoner.log.2022-06-15-02 : 0
flashphoner.log.2022-06-15-03 : 0
flashphoner.log.2022-06-15-04 : 0
flashphoner.log.2022-06-15-05 : 0
flashphoner.log.2022-06-15-06 : 0
flashphoner.log.2022-06-15-07 : 0
flashphoner.log.2022-06-15-08 : 0
flashphoner.log.2022-06-15-09 : 0
flashphoner.log.2022-06-15-10 : 0
flashphoner.log.2022-06-15-11 : 0
flashphoner.log.2022-06-15-12 : 0
flashphoner.log.2022-06-15-13 : 0
flashphoner.log.2022-06-15-14 : 0
flashphoner.log.2022-06-15-15 : 0
flashphoner.log.2022-06-15-16 : 0
flashphoner.log.2022-06-15-17 : 0
flashphoner.log.2022-06-15-18 : 0
flashphoner.log.2022-06-15-19 : 0
flashphoner.log.2022-06-15-20 : 0
flashphoner.log.2022-06-15-21 : 0
flashphoner.log.2022-06-15-22 : 0
flashphoner.log.2022-06-15-23 : 0
flashphoner.log.2022-06-16-00 : 906
flashphoner.log.2022-06-16-01 : 687
flashphoner.log.2022-06-16-02 : 1
flashphoner.log.2022-06-16-03 : 37076
flashphoner.log.2022-06-16-04 : 49434
flashphoner.log.2022-06-16-05 : 29197
flashphoner.log.2022-06-16-06 : 73793
flashphoner.log.2022-06-16-07 : 83995
flashphoner.log.2022-06-16-08 : 92612
flashphoner.log.2022-06-16-09 : 102382
Сервер тестовый, малонагруженный.
Логи и конфиг приаттачиваю
 

Max

Administrator
Staff member
Здравствуйте.

Для того чтобы проверить блокировки, пришлите пожалуйста файл jstack.log:

jstack `pidof java` > jstack.log

pidof java - это PID процесса сервера

jstack - это стандартная утилита JDK /usr/java/default/bin/jstack

Также можете снять репорт как показано здесь

cd /usr/local/FlashphonerWebCallServer/tools
sudo ./report.sh --sysinfo --conf --tar
 

Max

Administrator
Staff member
Логи и конфиг приаттачиваю
К сожалению, архив не скачивается по предоставленной ссылке.
Поэтому:
1. Обновите тестовый сервер до последней сборки 5.2.1257 или выше
2. Соберите отчет, как показано здесь (туда попадет конфигурация и jstack в том числе):
Code:
cd /usr/local/FlashphonerWebCallServer/tools
sudo ./report.sh --sysinfo --conf --tar
 

snark13

Member
Прошу прощения за задержку - мы временно откатились на 972 билд (в первом сообщении был некорректно указан 572).
Мы попробуем проапгрейдитьи собрать логи и отчеты как вы указали (пока нет возможности выделить под это серверы).

На 972-ом билде периодически возникает так же другая проблемная ситуация с записью сессий -
В какой-то момент сервер перестает записывать сессии, на запрос /rest-api/recorder/find_all возвращает 404, на комманды стартовать запись отвечает что комманда исполнена но реально она игнорируется и на следующий запрос /rest-api/recorder/find_all опять 404 и так по кругу. На продакшен серверах логи выключенны (только ERROR и по ним ничего не видно).
Интересно что проблема возникает сразу на всех серверах которые обслуживают камеры (их у нас было три) и работа восстановилась только после рестарта WCS серверов.
На тестовых сервера (мало нагруженных) это так же происходит одновременно но все восстанавливается через 10-15 минут
Пример лога тестового сервера - в 0:01:21 запрос в первый раз вернул 404, записи остановились... статус проверялся каждую минуту и каждый раз пробовали восстановить запись для трех потоков... запись восстановилась только в 0:11:46

Возможно что эта проблема уже известна и пофикшена
 

Attachments

Max

Administrator
Staff member
По логу похоже на утечку ресурсов в результате блокировки тредов. Сборка 5.2.972 сильно устарела, с тем пор было несколько фиксов в части захвата RTSP потоков, также были фиксы в части утечек ресурсов.
Поэтому рекомендуем обновиться до актуальной сборки и проверить, воспроизводится ли проблема.
 

snark13

Member
Постараемся на этой неделе запустить на тестовых серверах актуальные версии.
 

Max

Administrator
Staff member
Добрый день.
На новом сервере по словам заказчика возникла ситуация с остановкой записи видео. К сожалению сказать в какой момент это возникло я не могу, снять jstack тоже - заказчик перестартовал WCS. Собрал репорт архив (дополнив его логами за несколько прошедших дней) -
В дальнейшем, пожалуйста, направляйте отчеты или ссылки на них только с помощью формы. Сообщение пришлось удалить, т.к. отчет, доступный по прямой ссылке, может содержать данные лицензии.
В логах видно, что перед перезапуском остановилась запись только одного потока, причем только косвенным образом: приходит очередной запрос /recorder/find_all, затем /recorder/startup
1658799032903.png

Возможной причиной остановки записи в этом случае может быть и остановка медиаданных самого потока (всего активных RTSP потоков по периодическим запросам авторизации видно 4). К сожалению, клиентские логи этого потока недоступны.
Этот лог отличается от тех, которые Вы предоставляли ранее, где в основном логе было явно видно большое количество процессорных потоков, вставших в блокировку. Выглядит так, что проблема была только с одним RTSP потоком, но, имея в логе только идентификатор медиасессии, нельзя сказать, какой именно это был поток, с какой камеры.
В отчете видно, что периодически сильно нагружается CPU сервера (наличие файлов logs/DistributorDump*.jstack), сборщик мусора при этом работает нормально, видно, что утечек памяти из Java Heap нет.
Рекомендации будут следующими:
1. Увеличить число ядер CPU до 8 (сейчас 4)
2. Настроить использование ZGC: Настройка Z Garbage Collector (ZGC). На сервере уже используется JDK 14, так что обновлять JDK не нужно, hugepages также можно не настраивать.
 
Top