Приложение Netflix работает на сотнях умных телевизоров, стиков и телевизионных приставок. Я один из инженеров, которые помогают производителям запустить наше приложение на их устройствах. В этой статье обсудим особенно сложный вопрос, который помешал выходу одной телеприставки на европейский рынок.
В конце 2017 года меня позвали на созвон, чтобы обсудить проблему с приложением Netflix на новой телеприставке. Это было новое устройство Android TV с поддержкой 4K, на базе Android Open Source Project (AOSP) версии 5.0, Lollipop. Я уже несколько лет работал в Netflix и помог выпустить несколько девайсов, но это был моё первое устройство Android TV.
На связи были все четыре стороны: крупная европейская компания платного ТВ, запускающая устройство (оператор), подрядчик, интегрирующий прошивку (интегратор), поставщик системы-на-чипе (поставщик чипов) и я (Netflix).
Интегратор и Netflix уже завершили строгий процесс сертификации Netflix, но во время внутреннего испытания у оператора руководитель компании сообщил о серьёзной проблеме: воспроизведение Netflix лагало, то есть видео воспроизводилось очень короткое время, затем пауза, затем снова, затем пауза. Это происходило не всегда, но стабильно начинало лагать через нескольких дней после включения приставки. Они показали видео, оно выглядело ужасно.
Интегратор нашёл способ воспроизвести проблему: несколько раз запустить Netflix, начать воспроизведение, а затем вернуться в UI. Они предоставили скрипт для автоматизации процесса. Иногда это занимало целых пять минут, но скрипт всегда надёжно воспроизводил баг.
Тем временем инженер из компании-поставщика чипов диагностировал основную причину: приложение Netflix для Android TV под названием Ninja не успевало доставлять аудиоданные. Лаги вызваны опустошением буфера в аппаратном звуковом конвейере. Воспроизведение останавливалось, когда декодер ждал от Ninja часть аудиопотока, а затем оно возобновлялось, когда поступали новые данные. Интегратор, поставщик чипов и оператор — все думали, что проблема понятна. И все они смотрели на меня: Netflix, у вас есть ошибка в вашем приложении, и вы должны её исправить. Я слышал напряжение в голосе представителя оператора. Выпуск устройства задерживался и выходил за рамки бюджета, и они ожидали от меня результатов.
Я был настроен скептически. Это же самое приложение Ninja работает на миллионах устройств Android TV, включая умные телевизоры и другие телевизионные приставки. Если в Ninja ошибка, то почему она происходит только на этом устройстве?
Я начал с того, что сам воспроизвёл проблему с помощью скрипта от интегратора. Я связался с коллегой из компании-производителя микросхем и спросил, видел ли он что-нибудь подобное (не видел). Затем начал изучать исходный код Ninja. Нужно было найти точный код, который отвечает за доставку аудиоданных. Я во многом разобрался, но начал теряться в коде, который отвечает за воспроизведение, и мне нужна была помощь.
Я поднялся наверх и нашёл инженера, который написал аудио- и видеоконвейер Ninja, он познакомил меня с кодом. После этого я сам ещё некоторое время изучал его, чтобы окончательно понять главные части и добавить свои логи. Приложение Netflix сложное, но в упрощённом виде оно получает данные с сервера Netflix, в течение нескольких секунд буферизует видео- и аудиоданные на устройстве, а затем доставляет видео- и аудиокадры по одному на аппаратные декодеры.
Рис. 1. Упрощённый конвейер воспроизведения
Давайте на минутку поговорим об аудио/видеоконвейере в приложении Netflix. До «буфера декодера» он абсолютно одинаковый на каждой приставке и телевизоре, но перемещение данных A/V в буфер декодера устройства — это процедура, специфичная для конкретного устройства. Она выполняется в собственном потоке. Задача этой процедуры состоит в том, чтобы поддерживать буфер декодера полным, вызывая следующий кадр аудио- или видеоданных через API от Netflix. В Ninja эта работа выполняется потоком Android. Существует простой конечный автомат и некоторая логика для обработки различных состояний воспроизведения, но при нормальном воспроизведении поток копирует один кадр данных в API воспроизведения Android, а затем сообщает планировщику потока подождать 15 мс перед следующим вызовом обработчика. При создании потока Android можно запросить повторные запуски потоков, словно в цикле, но именно планировщик потоков Android вызывает обработчик, а не ваше собственное приложение.
На максимальных 60 FPS устройство должно отображать новый кадр каждые 16,66 мс, поэтому проверки через 15 мс хватает в любом случае. Поскольку интегратор определил, что проблема в аудиопотоке, я сосредоточился на конкретном обработчике, который доставлял аудиосэмплы в аудиослужбу Android.
Нужно было понять, откуда берутся лаги, то есть задержка. Я предположил, что виновата какая-то функция, вызванная обработчиком, поэтому разбросал сообщения журнала по всему обработчику и собирался легко найти код, ставший причиной лагов. Вскоре стало ясно, что в обработчике нет ничего плохого, и он несколько миллисекунд работает даже тогда, когда воспроизведение лагает.
В конце концов я сосредоточился на трёх числах: скорость передачи данных, время вызова обработчика и время передачи управления от обработчика обратно Android. Я написал скрипт для анализа выходных данных журнала и сгенерировал график ниже, на котором виден ответ.
Рис. 2. Визуализация пропускной способности аудиопотока и тайминги обработчика
Оранжевая линия — это скорость перемещения данных из буфера потоковой передачи в аудиосистему Android (байт в миллисекунду). На этой диаграмме три различных сценария:
Неизбежный вывод: оранжевая линия подтверждает выводы инженера из компании-производителя чипов. Действительно, Ninja недостаточно быстро доставляет аудиоданные.
Чтобы понять причину, давайте внимательнее изучим жёлтые и серые линии.
Жёлтая линия показывает время, проведённое в самой процедуре обработчика, вычисленное по меткам времени, записанным в начале и по завершению процедуры. Как в нормальной, так и в лагающей области время в обработчике одинаковое: около 2 мс. Всплески показывают случаи, когда время оказалось медленнее из-за выполнения других задач на устройстве.
Серая линия — время между вызовами обработчика — говорит о другом. При обычном воспроизведении обработчик вызывается примерно каждые 15 мс. В случае лагов справа обработчик вызывается примерно каждые 55 мс Между вызовами возникают лишние 40 мс, и в такой ситуации он никак не может угнаться за воспроизведением. Но почему?
Я сообщил о своём открытии интегратору и поставщику чипов (смотрите, виноват планировщик потоков Android!), но они продолжали настаивать, что решать проблему должен Netflix. Почему бы при каждом вызове обработчика не копировать больше данных? Это была справедливая критика, но реализация такого поведения повлекла бы глубокие изменения, на которые я не хотел идти, поэтому продолжил поиски первопричины. Я нырнул в исходный код Android и узнал, что потоки Android — это конструкция пользовательского пространства, а планировщик потоков для синхронизации использует системный вызов
В этот момент меня спас другой инженер из компании-поставщика чипов, который обнаружил баг, уже исправленный в следующей версии Android (Marshmallow). Оказывается, планировщик потоков Android изменяет поведение потоков в зависимости от того, работает приложение на переднем плане или в фоновом режиме. Потокам в фоновом режиме назначается дополнительная задержка 40 мс (40000000 нс).
Ошибка глубоко в ядре Android означала, что это дополнительное значение таймера сохранялось при перемещении потока на передний план. Обычно поток обработчика звука создавался, когда приложение на переднем плане, но иногда немного раньше, когда Ninja всё ещё находилась в фоновом режиме. Если такое случалось, воспроизведение начинало лагать.
Это не последняя ошибка, которую мы исправили на платформе Android, но её было труднее всех отследить. Она находилась вне приложения Netflix и даже вне конвейера воспроизведения, а все исходные данные указывали на ошибку в самом приложении Netflix.
История иллюстрирует аспект моей работы, которую я люблю: невозможно предсказать все проблемы, которые наши партнёры сбросят на меня. И я знаю, что для их решения нужно понимать множество систем, работать с отличными коллегами и постоянно подталкивать себя к изучению нового. То, что я делаю, оказывает непосредственное влияние на реальных людей и на их удовольствие от отличного продукта. Когда люди наслаждаются просмотром Netflix в своей гостиной, я знаю, что являюсь частью команды, которая сделала это возможным.
Таинственная проблема
В конце 2017 года меня позвали на созвон, чтобы обсудить проблему с приложением Netflix на новой телеприставке. Это было новое устройство Android TV с поддержкой 4K, на базе Android Open Source Project (AOSP) версии 5.0, Lollipop. Я уже несколько лет работал в Netflix и помог выпустить несколько девайсов, но это был моё первое устройство Android TV.
На связи были все четыре стороны: крупная европейская компания платного ТВ, запускающая устройство (оператор), подрядчик, интегрирующий прошивку (интегратор), поставщик системы-на-чипе (поставщик чипов) и я (Netflix).
Интегратор и Netflix уже завершили строгий процесс сертификации Netflix, но во время внутреннего испытания у оператора руководитель компании сообщил о серьёзной проблеме: воспроизведение Netflix лагало, то есть видео воспроизводилось очень короткое время, затем пауза, затем снова, затем пауза. Это происходило не всегда, но стабильно начинало лагать через нескольких дней после включения приставки. Они показали видео, оно выглядело ужасно.
Интегратор нашёл способ воспроизвести проблему: несколько раз запустить Netflix, начать воспроизведение, а затем вернуться в UI. Они предоставили скрипт для автоматизации процесса. Иногда это занимало целых пять минут, но скрипт всегда надёжно воспроизводил баг.
Тем временем инженер из компании-поставщика чипов диагностировал основную причину: приложение Netflix для Android TV под названием Ninja не успевало доставлять аудиоданные. Лаги вызваны опустошением буфера в аппаратном звуковом конвейере. Воспроизведение останавливалось, когда декодер ждал от Ninja часть аудиопотока, а затем оно возобновлялось, когда поступали новые данные. Интегратор, поставщик чипов и оператор — все думали, что проблема понятна. И все они смотрели на меня: Netflix, у вас есть ошибка в вашем приложении, и вы должны её исправить. Я слышал напряжение в голосе представителя оператора. Выпуск устройства задерживался и выходил за рамки бюджета, и они ожидали от меня результатов.
Расследование
Я был настроен скептически. Это же самое приложение Ninja работает на миллионах устройств Android TV, включая умные телевизоры и другие телевизионные приставки. Если в Ninja ошибка, то почему она происходит только на этом устройстве?
Я начал с того, что сам воспроизвёл проблему с помощью скрипта от интегратора. Я связался с коллегой из компании-производителя микросхем и спросил, видел ли он что-нибудь подобное (не видел). Затем начал изучать исходный код Ninja. Нужно было найти точный код, который отвечает за доставку аудиоданных. Я во многом разобрался, но начал теряться в коде, который отвечает за воспроизведение, и мне нужна была помощь.
Я поднялся наверх и нашёл инженера, который написал аудио- и видеоконвейер Ninja, он познакомил меня с кодом. После этого я сам ещё некоторое время изучал его, чтобы окончательно понять главные части и добавить свои логи. Приложение Netflix сложное, но в упрощённом виде оно получает данные с сервера Netflix, в течение нескольких секунд буферизует видео- и аудиоданные на устройстве, а затем доставляет видео- и аудиокадры по одному на аппаратные декодеры.
Рис. 1. Упрощённый конвейер воспроизведения
Давайте на минутку поговорим об аудио/видеоконвейере в приложении Netflix. До «буфера декодера» он абсолютно одинаковый на каждой приставке и телевизоре, но перемещение данных A/V в буфер декодера устройства — это процедура, специфичная для конкретного устройства. Она выполняется в собственном потоке. Задача этой процедуры состоит в том, чтобы поддерживать буфер декодера полным, вызывая следующий кадр аудио- или видеоданных через API от Netflix. В Ninja эта работа выполняется потоком Android. Существует простой конечный автомат и некоторая логика для обработки различных состояний воспроизведения, но при нормальном воспроизведении поток копирует один кадр данных в API воспроизведения Android, а затем сообщает планировщику потока подождать 15 мс перед следующим вызовом обработчика. При создании потока Android можно запросить повторные запуски потоков, словно в цикле, но именно планировщик потоков Android вызывает обработчик, а не ваше собственное приложение.
На максимальных 60 FPS устройство должно отображать новый кадр каждые 16,66 мс, поэтому проверки через 15 мс хватает в любом случае. Поскольку интегратор определил, что проблема в аудиопотоке, я сосредоточился на конкретном обработчике, который доставлял аудиосэмплы в аудиослужбу Android.
Нужно было понять, откуда берутся лаги, то есть задержка. Я предположил, что виновата какая-то функция, вызванная обработчиком, поэтому разбросал сообщения журнала по всему обработчику и собирался легко найти код, ставший причиной лагов. Вскоре стало ясно, что в обработчике нет ничего плохого, и он несколько миллисекунд работает даже тогда, когда воспроизведение лагает.
Ага, озарение
В конце концов я сосредоточился на трёх числах: скорость передачи данных, время вызова обработчика и время передачи управления от обработчика обратно Android. Я написал скрипт для анализа выходных данных журнала и сгенерировал график ниже, на котором виден ответ.
Рис. 2. Визуализация пропускной способности аудиопотока и тайминги обработчика
Оранжевая линия — это скорость перемещения данных из буфера потоковой передачи в аудиосистему Android (байт в миллисекунду). На этой диаграмме три различных сценария:
- Две области с высокими пиками, где скорость передачи данных достигает 500 байт в миллисекунду. Эта фаза — буферизация перед началом воспроизведения. Обработчик копирует данные быстро, как только может.
- Область посередине — это нормальное воспроизведение. Аудиоданные перемещаются со скоростью около 45 байт в миллисекунду.
- Область лагов находится справа, когда аудиоданные перемещаются со скоростью около 10 байт в миллисекунду. Это недостаточно быстро для поддержания воспроизведения.
Неизбежный вывод: оранжевая линия подтверждает выводы инженера из компании-производителя чипов. Действительно, Ninja недостаточно быстро доставляет аудиоданные.
Чтобы понять причину, давайте внимательнее изучим жёлтые и серые линии.
Жёлтая линия показывает время, проведённое в самой процедуре обработчика, вычисленное по меткам времени, записанным в начале и по завершению процедуры. Как в нормальной, так и в лагающей области время в обработчике одинаковое: около 2 мс. Всплески показывают случаи, когда время оказалось медленнее из-за выполнения других задач на устройстве.
Истинная первопричина
Серая линия — время между вызовами обработчика — говорит о другом. При обычном воспроизведении обработчик вызывается примерно каждые 15 мс. В случае лагов справа обработчик вызывается примерно каждые 55 мс Между вызовами возникают лишние 40 мс, и в такой ситуации он никак не может угнаться за воспроизведением. Но почему?
Я сообщил о своём открытии интегратору и поставщику чипов (смотрите, виноват планировщик потоков Android!), но они продолжали настаивать, что решать проблему должен Netflix. Почему бы при каждом вызове обработчика не копировать больше данных? Это была справедливая критика, но реализация такого поведения повлекла бы глубокие изменения, на которые я не хотел идти, поэтому продолжил поиски первопричины. Я нырнул в исходный код Android и узнал, что потоки Android — это конструкция пользовательского пространства, а планировщик потоков для синхронизации использует системный вызов
epoll(). Я знал, что производительность epoll() не гарантирована, поэтому подозревал, что нечто систематически на него влияет.В этот момент меня спас другой инженер из компании-поставщика чипов, который обнаружил баг, уже исправленный в следующей версии Android (Marshmallow). Оказывается, планировщик потоков Android изменяет поведение потоков в зависимости от того, работает приложение на переднем плане или в фоновом режиме. Потокам в фоновом режиме назначается дополнительная задержка 40 мс (40000000 нс).
Ошибка глубоко в ядре Android означала, что это дополнительное значение таймера сохранялось при перемещении потока на передний план. Обычно поток обработчика звука создавался, когда приложение на переднем плане, но иногда немного раньше, когда Ninja всё ещё находилась в фоновом режиме. Если такое случалось, воспроизведение начинало лагать.
Полученные уроки
Это не последняя ошибка, которую мы исправили на платформе Android, но её было труднее всех отследить. Она находилась вне приложения Netflix и даже вне конвейера воспроизведения, а все исходные данные указывали на ошибку в самом приложении Netflix.
История иллюстрирует аспект моей работы, которую я люблю: невозможно предсказать все проблемы, которые наши партнёры сбросят на меня. И я знаю, что для их решения нужно понимать множество систем, работать с отличными коллегами и постоянно подталкивать себя к изучению нового. То, что я делаю, оказывает непосредственное влияние на реальных людей и на их удовольствие от отличного продукта. Когда люди наслаждаются просмотром Netflix в своей гостиной, я знаю, что являюсь частью команды, которая сделала это возможным.
TyVik
Спасибо, показательная статья, что нужно искать первопричину. Хорошо, что ещё существуют такие специалисты. А то обычная практика, к сожалению, это придумывать костыли для костылей, которые подвешены за верёвочку.
FJCrux
Искать первопричину — это важно, но не всегда эту причину могут устранить за приемлимые время и деньги, откуда и получаются костыли. И тут вторая проблема, что после того, как причину устранили (а это может быть не скоро), те самые костыли обрасли новыми костылями