Жизнь инженера Netflix — дело о лишних 40 мс

Приложение Netflix работает на сотнях смарт-телевизоров, потоковых пультах и приставках платного ТВ. Инженер-партнёр помогает производителям устройств запустить приложение Netflix на их устройствах. В этой статье я расскажу об одной особенно сложной проблеме, которая заблокировала запуск устройства в Европе.

---

Как начались странности

Ближе к концу 2017 года я участвовал в конференции-связи, где обсуждали проблему с приложением Netflix на новой ТВ-приставке. Эта приставка была новым устройством Android с воспроизведением 4K на базе Android Open Source Project (AOSP) 5.0 — «Lollipop». В Netflix я имел дело с несколькими устройствами, но это было моё первое устройство Android TV.

В этой конференции участвовали все четыре игрока рынка: крупная европейская компания платного телевидения (оператор), эта компания запускала устройство; подрядчик, который интегрировал прошивку ТВ-приставки (интегратор); производитель микросхем; я представлял Netflix.

Интегратор и Netflix уже закончили строгую сертификацию Netflix, но во время внутреннего испытания оператора телеканалов один из руководителей компании рассказал о серьёзной проблеме: воспроизведение Netflix на его устройстве прерывалось, то есть видео проигрывалось совсем недолго, затем останавливалось, проигрывалось и снова прерывалось. Случалось это не всегда, но, как правило, спустя несколько дней после включения устройства. На представленной видеозаписи баг выглядел ужасно.

Интегратор нашёл способ воспроизвести проблему: нужно было несколько раз запустить Netflix, начать воспроизведение, затем вернуться в пользовательский интерфейс устройства. Нам дали сценарий, чтобы повторять ситуацию автоматически. Иногда воспроизведение ситуации с помощью скрипта занимало пять минут, но баг проявлялся всегда.

Тем временем полевой инженер производителя микросхем диагностировал причину проблемы: приложение Netflix, Ninja для Android-TV, медленно подавало аудиоданные. Видео останавливалось из-за истощения буфера в конвейере аудиоустройства. Ролик замирал, пока декодер ждал данных от Ninja. Когда новые данные поступали, проигрыватель оживал.

Интегратор, производитель микросхем и оператор решили, что проблема выявлена, их сообщение мне было ясным: Netflix, это ошибка в вашем приложении, исправьте её. В голосах я слышал напряжение. Выход ТВ-приставки на рынок запоздал, устройство превысило свой бюджет, и люди ждали результатов.

Расследование

Я был настроен скептически. То же самое приложение Ninja работает на миллионах устройств Android TV, включая смарт-ТВ и другие приставки. Если ошибка в Ninja, то почему она проявляется только на Android 5.0?

С помощью скрипта от интегратора я воспроизвёл проблему сам. Связался со своим коллегой у продавца микросхем, спросил, видел ли он что-то подобное раньше (он не видел). Затем я начал читать исходный код Ninja, потому что хотел найти фрагмент, который передавал данные. Я многое разузнал, но запутался в коде воспроизведения и нуждался в помощи.

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


Рисунок 1 — Упрощённый конвейер воспроизведения

Давайте поговорим об аудио/видеоконвейере. Всё, вплоть до буфера декодера, одинаково на всех телевизионных приставках и смарт-ТВ, но перемещение аудио- и видеоданных в буфер декодера — это процедура, которая зависит от устройства и работает в собственном потоке. Задача процедуры перемещения — поддерживать заполненность буфера декодера через вызов API Netflix, этот вызов предоставляет следующий кадр аудио- или видеоданных. 

В Ninja эта работа выполнялась с помощью Android Thread. Есть простой конечный автомат и логика для обработки разных состояний воспроизведения, но при нормальном воспроизведении поток копирует один кадр данных в API воспроизведения Android, а затем сообщает планировщику потоков, что он должен подождать 15 мс и снова вызвать обработчика. Когда вы создаёте поток Android, можно запросить, чтобы поток запускался повторно, как если бы в цикле; но это планировщик потоков Android и он вызывает обработчика, а не ваше собственное приложение.

Чтобы воспроизвести видео со скоростью 60 кадров в секунду (наивысшей чистотой кадров в Netflix), устройство должно отображать новый кадр каждые 16,66 мс, поэтому наличие нового сэмпла проверяется каждые 15 мс. Этого времени достаточно, чтобы опережать любой видеопоток Netflix. 

Интегратор определил, что проблема кроется в аудиопотоке, поэтому я сосредоточился на конкретном обработчике потока, который доставлял аудиосэмплы в аудиосервис Android. Где же лишние миллисекунды? 

Я предположил, что виновата какая-то вызванная обработчиком функция, поэтому прописал логирование по всему обработчику, предполагая, что код-виновник станет очевиден. Вскоре стало ясно, что в обработчике не было ничего плохого: даже когда воспроизведение прерывалось, он отрабатывал за несколько миллисекунд.

Прозрение

В конце концов я обратил внимание на три цифры: скорость передачи данных, время вызова обработчика и время, когда он передаёт управление обратно в Android. Я написал сценарий, чтобы проанализировать вывод логирования, и построил график, который ответил на мой вопрос.


Рисунок 2 — Визуализация пропускной способности аудио и синхронизации обработчика потоков

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

1. Две высокие шипованные части, где скорость передачи данных достигает 500 байт/мс. Эта фаза буферизации, перед началом воспроизведения. Обработчик копирует данные так быстро, как только может.
   
2. Область посередине — это нормальное воспроизведение. Аудиоданные перемещаются со скоростью около 45 байт/мс.
   
3. Область заикания находится справа, где аудиоданные движутся со скоростью ближе 10 байт/мс. Это недостаточно быстро, чтобы воспроизведение продолжалось.
   

Неизбежный вывод — оранжевая линия подтверждает то, что рассказал инженер производителя микросхем: Ninja медленно передаёт данные. Чтобы понять причину, давайте посмотрим, о чём свидетельствуют жёлтые и серые линии. Жёлтая линия показывает время, проведённое в самой подпрограмме обработчика, это время рассчитывалось по записанным вверху и внизу обработчика отметкам. 
И при нормальном воспроизведении, и при воспроизведении с заиканием время в обработчике было одинаковым: около 2 мс. Пики показывают случаи, когда выполнение замедлялось из-за затрат на другие задачи устройства.

Корень проблемы

Серая линия, время между вызовами обработчика, свидетельствует о другом. Когда видео проигрывается нормально, видно, что обработчик вызывается каждые 15 мс. Когда видео прерывается (справа), обработчик вызывается примерно каждые 55 мс. Между вызовами есть лишние 40 мс, а значит, успеть за воспроизведением невозможно. Но почему?

Я рассказал о своём открытии интегратору и производителю микросхем (посмотрите, виноват планировщик потоков Android!). Но они продолжали сопротивляться: почему бы вам просто не копировать новые данные, когда вызывается обработчик? Критика была справедливой, но, если переписать код таким образом, это повлечёт за собой больше изменений, чем я был готов внести, поэтому я решил продолжить поиск первопричины. 

Я погрузился в исходный код Android и узнал, что потоки Android — это конструкция пользовательского пространства, а планировщик потоков, чтобы определять время, использует системный вызов epoll(). Производительность epoll() не гарантируется, поэтому я подозревал, что на эту функцию влияет что-то системное.
И здесь меня спас другой инженер поставщика микросхем, который обнаружил ошибку; эту ошибку исправили в следующей версии Android — Marshmallow. Планировщик потоков Android изменяет поведение потоков в зависимости от того, работает ли приложение в фоновом режиме или на переднем плане. Потокам в фоновом режиме задается дополнительное время ожидания в 40000000 нс. Ошибка в глубине самой Android означала, что дополнительное время возникает, когда поток перемещается на передний план. 

Обычно поток обработчика звука создавался, когда приложение выполнялось на переднем плане, но иногда поток создавался немного раньше. Такое случалось, когда приложение Ninja работало в фоновом режиме — и тогда проигрыватель останавливался.

Извлеченные уроки

Это была не последняя исправленная на этой платформе ошибка, но именно её было труднее всего отследить. Баг скрывался за пределами Netflix, не в конвейере воспроизведения; вместе с тем все исходные данные указывали на ошибку в приложении Netflix.

Эта история показывает одну из сторон моей любимой работы: я не могу предугадать все проблемы, которые наши партнёры перебросят мне, кроме того, я знаю, что для разрешения проблем мне нужно разбираться в нескольких системах, работать с замечательными коллегами и постоянно заставлять себя узнавать что-то новое. Моя работа прямо влияет на людей, на их удовольствие от отличного продукта. Я понимаю, что, когда люди наслаждаются Netflix в своей гостиной, именно я — тот человек в команде, который делает это возможным.

---

• Профессия Data Scientist
• Профессия Data Analyst