Release after the year of development

Обычно, в последний рабочий день года люди бегут в магазины за подарками близким, горячительными напитками и ингридиентами для праздничного Оливье. Но это история про нормальных людей, которые не релизят апдейт инфраструктуры что разрабатывался весь 2017 год в последнюю неделю. А мы сделали именно так. У нас было 3 новых сервиса, новый стек видеостриминговой платформы, обновление команды и новое железо всех сортов и расцветок. Не то чтобы я не понимал что это плохая идея, но если уж взялся отвечать за результат и отправился в плавание, то как капитан корабля ты готов принять участь приготовленную тебе айбергом.

И вот, 31.12.2017, два дня в поисках проблемы с обрывом стримов позади, результата нет, а ты смотришь на шампанское в бокале и думаешь как раскопать этот блэкбокс. Поиск занял еще не один день, а завершился недельным хакатоном нон-стоп, Go vs Node, в результате чего за эту неделю было полностью переписано ядро видеостриминга что и генерировало проблемы.

Transcript

1. Релиз после года разработки: debug под новогодний звон бокалов и 40 дней поиска решения Дмитрий Меньшиков Aurora Technologies
2. [ИГРАЕТ МУЗЫКА]
3. https://t.me/dmitry_menshikov https://t.me/noTieinIT https://fb.com/d.menshikov http://dmenshikov.com Мы всегда ищем талантливых инженеров, тех у кого от таких историй мурашки по коже! Пишите в телегу! Решение проблем – это всегда зона роста! Мой канал Моя телега
4. История доступна онлайн http://dmenshikov.com https://speakerdeck.com/woz Link to post: http://bit.ly/2IrzVqD
5. RTMP cc Icons made by Freepik from www.flaticon.com ingest Старый флоу
6. RTMP cc Icons made by Freepik from www.flaticon.com ingest transcoder RTMP Старый флоу
7. RTMP cc Icons made by Freepik from www.flaticon.com ingest origin transcoder RTMP Старый флоу RTMP
8. RTMP cc Icons made by Freepik from www.flaticon.com ingest origin transcoder RTMP Старый флоу RTMP JPEG JPEG
9. RTMP cc Icons made by Freepik from www.flaticon.com edge ingest origin transcoder RTMP Старый флоу RTMP JPEG JPEG RTMP HLS DASH
10. RTMP cc Icons made by Freepik from www.flaticon.com edge ingest origin transcoder RTMP Старый флоу RTMP JPEG JPEG RTMP RTMP HLS DASH
11. Почему решили переписывать???
12. RTMP cc Icons made by Freepik from www.flaticon.com edge ingest origin transcoder RTMP Новый флоу RTMP JPEG JPEG RTMP RTMP HLS DASH
13. RTMP cc Icons made by Freepik from www.flaticon.com ingest Новый флоу
14. RTMP cc Icons made by Freepik from www.flaticon.com ingest RTMP Новый флоу pimp
15. RTMP cc Icons made by Freepik from www.flaticon.com ingest RTMP Новый флоу pimp
16. RTMP cc Icons made by Freepik from www.flaticon.com ingest Новый флоу pimp crabscoder RTMP jss
17. RTMP cc Icons made by Freepik from www.flaticon.com ingest RTMP Новый флоу pimp crabscoder RTMP origin RTMP jss RTMP
18. RTMP cc Icons made by Freepik from www.flaticon.com ingest origin RTMP Новый флоу RTMP pimp crabscoder jss RTMP RTMP
19. RTMP cc Icons made by Freepik from www.flaticon.com edge ingest origin RTMP Новый флоу RTMP JPEG RTMP HLS DASH pimp crabscoder jss RTMP RTMP
20. RTMP cc Icons made by Freepik from www.flaticon.com edge ingest origin RTMP Новый флоу RTMP JPEG RTMP RTMP HLS DASH pimp crabscoder jss HLS RTMP RTMP
21. RTMP cc Icons made by Freepik from www.flaticon.com edge ingest origin RTMP Новый флоу RTMP JPEG RTMP RTMP HLS DASH pimp crabscoder jss HLS RTMP RTMP
24. crabscoder
25. Не все потоки на одном и том же Wowza ingest сервере испытывали проблемы Факты
26. Не все потоки на одном и том же Wowza ingest сервере испытывали проблемы На Wowza origin в логах streamTimeout[origin/streamName]: Resetting connection: wowz://10.2.1.174:1935/origin/streamName Факты
27. Не все потоки на одном и том же Wowza ingest сервере испытывали проблемы На Wowza origin в логах streamTimeout[origin/streamName]: Resetting connection: wowz://10.2.1.174:1935/origin/streamName У сапорта рост жалоб от партнеров на принудительное дисконнекты стримеров Факты
28. Не все потоки на одном и том же Wowza ingest сервере испытывали проблемы На Wowza origin в логах streamTimeout[origin/streamName]: Resetting connection: wowz://10.2.1.174:1935/origin/streamName У сапорта рост жалоб от партнеров на принудительное дисконнекты стримеров В логах найдены SIGPIPE на транскодерах, что трактовали как следствие обрыва на Wowza ingest Факты
29. Не все потоки на одном и том же Wowza ingest сервере испытывали проблемы На Wowza origin в логах streamTimeout[origin/streamName]: Resetting connection: wowz://10.2.1.174:1935/origin/streamName У сапорта рост жалоб от партнеров на принудительное дисконнекты стримеров В логах найдены SIGPIPE на транскодерах, что трактовали как следствие обрыва на Wowza ingest Количество дисконектов с ingest выросло на том же обьеме трафика Факты
30. Кто виноват? Виноваты разработчики или софт Виноват датацентр или сеть, потери на канале Виноваты админы, сервера, маршрутизаторы
31. Кто виноват? Виноваты разработчики или софт Виноват датацентр или сеть, потери на канале Виноваты админы, сервера, маршрутизаторы
32. План действий Восстановить карту всех действий и везде: подключения, отключения, просмотры, статусы Diff Wowza модулей, фронтенда клиентов, изменений настроек HW/SW. Еще раз пересмотреть метрики Снифинг трафика и профайлинг Проверить свою бизнес логику Поспрашивать датацентр
33. Подозрение на сеть Dec 28 15:08:34 w-e-3 consul[22751]: memberlist: Failed TCP fallback ping: read tcp 10.2.0.229:39386- >192.168.8.3:8301: i/o timeout...
34. RTMP ingest RTMP Анализ FPS $ ffprobe -i rtmp://host:port/path -show_frames [FRAME] media_type=video stream_index=0 key_frame=1 pkt_dts_time=117.285000 pkt_duration_time=0.033000 pkt_size=32358 width=854 height=480 [/FRAME] ...
35. Анализ FPS
36. Анализ FPS 1) Фреймы выкидываются пачками 2) Потом нет фреймов 3) Судя по DTS стримеры либо генерируют плохой стрим, либо Wowza паузит прием данных
37. Wowza ???
38. Wowza
39. Нам поможет strace!
40. $ strace -c -f -p123 % time seconds usecs/call calls errors syscall ------ ----------- ----------- --------- --------- ---------------- 98.27 164058.185756 129258 1269232 328380 futex 0.96 1607.779169 10882 147742 epoll_wait 0.26 437.918455 283 1546081 198 write 0.20 339.308117 86119 3940 poll 0.15 245.116958 247 991033 clock_gettime 0.09 148.213531 3293634 45 41 restart_syscall 0.05 89.647620 280 319628 144406 read 0.00 4.673533 268 17416 lseek 0.00 1.546572 239 6478 getrusage 0.00 1.316333 243 5408 346 epoll_ctl
41. 26477 13:58:09 futex(0x7f4d70064904, FUTEX_WAIT_PRIVATE, 1432479, NULL <unfinished ...> 30942 13:58:09 read(125, <unfinished ...> 20197 13:58:09 write(178, "\307", 1 <unfinished ...> 13033 13:58:09 epoll_ctl(132, EPOLL_CTL_MOD, 159, {EPOLLIN, {u32=159, u64=159}} <unfinished ...> 9900 13:58:09 write(145, "\307", 1 <unfinished ...> 21229 13:58:09 <... write resumed> ) = 104 <0.000134> 26477 13:58:09 <... futex resumed> ) = 0 <0.000125> 30942 13:58:09 read(125, <unfinished ...> 20197 13:58:09 write(178, "\343g\265c\177\232\365~\376\307w\337e\314\6\210~\344\34\246\263"..., 512 <unfinished ...> 13033 13:58:09 epoll_wait(132, <unfinished ...>
42. 26477 13:58:09 futex(0x7f4d70064904, FUTEX_WAIT_PRIVATE, 1432479, NULL <unfinished ...> 30942 13:58:09 read(125, <unfinished ...> 20197 13:58:09 write(178, "\307", 1 <unfinished ...> 13033 13:58:09 epoll_ctl(132, EPOLL_CTL_MOD, 159, {EPOLLIN, {u32=159, u64=159}} <unfinished ...> 9900 13:58:09 write(145, "\307", 1 <unfinished ...> 21229 13:58:09 <... write resumed> ) = 104 <0.000134> 26477 13:58:09 <... futex resumed> ) = 0 <0.000125> 30942 13:58:09 read(125, <unfinished ...> 20197 13:58:09 write(178, "\343g\265c\177\232\365~\376\307w\337e\314\6\210~\344\34\246\263"..., 512 <unfinished ...> 13033 13:58:09 epoll_wait(132, <unfinished ...>
43. 26477 13:58:09 futex(0x7f4d70064904, FUTEX_WAIT_PRIVATE, 1432479, NULL <unfinished ...> 30942 13:58:09 read(125, <unfinished ...> 20197 13:58:09 write(178, "\307", 1 <unfinished ...> 13033 13:58:09 epoll_ctl(132, EPOLL_CTL_MOD, 159, {EPOLLIN, {u32=159, u64=159}} <unfinished ...> 9900 13:58:09 write(145, "\307", 1 <unfinished ...> 21229 13:58:09 <... write resumed> ) = 104 <0.000134> 26477 13:58:09 <... futex resumed> ) = 0 <0.000125> 30942 13:58:09 read(125, <unfinished ...> 20197 13:58:09 write(178, "\343g\265c\177\232\365~\376\307w\337e\314\6\210~\344\34\246\263"..., 512 <unfinished ...> 13033 13:58:09 epoll_wait(132, <unfinished ...> Видео в RTMP потоках начинается после команды createStream
44. Количество вызовов read по fd=99
45. Количество вызовов read… Еще ближе
46. Количество вызовов read и write
47. Прочитано байт функцией read
48. Время выполнения функции read
49. Записано байт функцией write
50. Время выполнения функции write
51. Кривая настройка ОС!
52. Тюнинг TCP стека и OS net.core.rmem_* и net.ipv4.tcp_rmem – память для буферов чтения net.core.wmem_* и net.ipv4.tcp_wmem – память для буферов записи net.core.somaxconn – размер очереди установленных соединений ожидающих обработки accept() net.core.netdev_max_backlog – макс размер очереди фреймов после копирования с ring buffer NIC fs.file-max – макс количество открытых файлов net.ipv4.tcp_sack, net.ipv4.tcp_dack, net.ipv4.tcp_fack – управление TCP Acknowledgement
53. Тюнинг TCP стека и OS http://bit.ly/2LKagvg - Performance Tuning on Linux — TCP https://red.ht/35aozRQ - Red Hat Enterprise Linux Network Performance Tuning Guide http://bit.ly/30Jimsr - Tuning Linux to reach maximum performance on 10 Gbps network
54. NIC tuning, IRQ, SoftIRQ /proc/interrupts - IRQ SoftIRQ NAPI ksoftirqd ethtool Просто цикл статей года! http://bit.ly/2OgrKRQ
55. Нам поможет perf и flame graph
56. perf + flame graph
57. perf + flame graph http://bit.ly/2o4Cwjx - Brandan Gregg blog http://bit.ly/356zdsu - Java in Flames, отличное введение для начинающих
58. Vzkernel 6 + Broadcom 5720 1G NIC
59. Vzkernel 6 + Broadcom 5720 1G NIC
60. Чтение ядра и драйвера, %#$& tg3 драйвер при проблемах DMA (direct memory access) не ведет статистику и не пишет о проблемах При ошибках DMA пакеты могут приходить битыми, теряться DMA debug появился только в ядре Linux 3.9 perf показал, что много времени уходит на debug_dma_map_page В коде драйвера много комментариев про известные и нерешенные проблемы с DMA Читать сорсы надо после психологической подготовки
61. Чтение ядра и драйвера, %#$& tg3 драйвер при проблемах DMA (direct memory access) не ведет статистику и не пишет о проблемах При ошибках DMA пакеты могут приходить битыми, теряться DMA debug появился только в ядре Linux 3.9 perf показал, что много времени уходит на debug_dma_map_page В коде драйвера много комментариев про известные и нерешенные проблемы с DMA Читать сорсы надо после психологической подготовки Братан, последню гривню бросаю, атвичаю! Это все кривой NIC, DMA и драйвер!
62. А как дела на других системах? Например, на EC2?
63. EC2, xennet
64. А как дела на других системах? Например, на EC2? Братан, ставь другую OS и карту! Intel X540 10G, например, есть на складе!
65. X540 10G У Intel X540 10G есть трекинг количества ошибок DMA Ошибки видны в ethtool: rx_page_failed и tx_page_failed Есть поддержка дебага, пишет в /sys/kernel/debug/ixgbe Еще пишет в dmesg ”TX DMA map failed” при ошибках
66. Vzkernel 7 + Intel X540 10G NIC
67. Vzkernel 7 + Intel X540 10G NIC
68. Vzkernel 7 + Intel X540 10G NIC
69. Не помогло, снова фризы Ну хоть sockperf погоняем
70. Для замеров есть iperf, но у него есть недостатки sockperf гибче: кастомные размеры пакетов, параметры соединений, например TCP_NODELAY Пакеты по 14 байт: 75 usec avg latency Пакеты по 512 байт: 87 usec avg latency
71. Для замеров есть iperf, но у него есть недостатки sockperf гибче: кастомные размеры пакетов, параметры соединений, например TCP_NODELAY Пакеты по 14 байт: 75 usec avg latency Пакеты по 512 байт: 87 usec avg latency
72. Нам ничего не поможет!
73. https://github.com/LCMApps/video-quality-tools video-quality-tools Может задетектить даже перегруз CPU у пользователя! Разработан нами с любовью! Анализирует состояние live потока в RTMP, HLS, DASH Следит за fps, bitrate, как на encoder, так и по доставке по сети
74. https://github.com/LCMApps/video-quality-tools video-quality-tools Ставь star на Github! Нам приятно!
75. Centos 6 vs Centos 7
78. Давай шаг назад! Снова тыкать палкой в транскодер!
79. На транскодере начинаем перехватывать трафик (pcap) Релизим обновленный транскодер Ставим paranoid debug level на транскодер, с записью пакетов даже
81. [root@w-o-8.am /]# time curl vss-w-o-3:1935 real 0m0.109s user 0m0.003s sys 0m0.001s [root@w-o-8.am /]# time curl vss-w-o-3:1935 real 0m7.008s user 0m0.003s sys 0m0.001s Потыкали Wowza origin
82. Parsed host : 10.2.1.174 Parsed app : origin RTMP_Connect0, failed to connect socket. 4 (Interrupted system call) rtmp://10.2.1.174/origin/117687be99efe796800e098e36b79f7e_ bc2_hd: Unknown error occurred [AVIOContext @ 0x18d9cc0] Statistics: 152844 bytes read, 0 seeks RTMP_SendPacket: fd=5, size=34 Invoking deleteStream Exiting normally, received signal 15. Логи транскодера
83. video-quality-tools
84. Пазл сложился Стало ясно почему на графиках обрыв произошел раньше чем поток деградировал на ingest SIGPIPE на транскодере возникали из-за origin Стало понятно почему тюнинг Centos 7 не дал результат
87. RTMP Wowza-edge Wowza-edge Wowza-edge RTMP RTMP Wowza-origin
88. RTMP Wowza-edge Wowza-edge Wowza-edge RTMP RTMP Wowza-origin 200x 200x 200x
89. RTMP Wowza-edge Wowza-edge Wowza-edge RTMP RTMP Wowza-origin 200x 200x 200x
90. За неделю был переписан ingest, origin, edge На базе nginx-rtmp-module
91. Ретроспектива Готовить инструменты для поиска проблем заранее
92. Ретроспектива Готовить инструменты для поиска проблем заранее Перед серьезными релизами начинать собирать метрики до ввода в эксплуатацию подсистем и смотреть на изменения метрик
93. Ретроспектива Готовить инструменты для поиска проблем заранее Перед серьезными релизами начинать собирать метрики до ввода в эксплуатацию подсистем и смотреть на изменения метрик Я забрался слишком глубоко, дойдя до кода драйверов. Оглядываться стоит чаще.
94. Ретроспектива Готовить инструменты для поиска проблем заранее Перед серьезными релизами начинать собирать метрики до ввода в эксплуатацию подсистем и смотреть на изменения метрик Я забрался слишком глубоко, дойдя до кода драйверов. Оглядываться стоит чаще. Повышать квалификацию команды и больше инвестировать в обучение
95. Ретроспектива Готовить инструменты для поиска проблем заранее Перед серьезными релизами начинать собирать метрики до ввода в эксплуатацию подсистем и смотреть на изменения метрик Я забрался слишком глубоко, дойдя до кода драйверов. Оглядываться стоит чаще. Повышать квалификацию команды и больше инвестировать в обучение Это был невероятный опыт и неимоверный трип
96. А как дела на других системах? Например, на EC2? Ах да… Главный партнер получил прирост конверсии на +57%
97. История доступна онлайн http://dmenshikov.com https://speakerdeck.com/woz Link to post: http://bit.ly/2IrzVqD
98. https://t.me/dmitry_menshikov https://t.me/noTieinIT https://fb.com/d.menshikov http://dmenshikov.com Мы всегда ищем талантливых инженеров, тех у кого от таких историй мурашки по коже! Пишите в телегу! Решение проблем – это всегда зона роста! Мой канал Моя телега