Думаю, многие любят послушать музыку во время работы, и я к таким людям отношусь. Так уж получилось, что моя аудио-коллекция находится в VK, по разным причинам, в том числе и по знаменитой причине “так исторически сложилось”. Обычно я просто запускаю на отдельной вкладке музыку и забываю о ней на весь рабочий день. Но последнее время что-то там у VK либо случилось, либо обновилось, но вкладка VK в браузере начала “выедать” всю память от чего прослушивание стало невозможным.

Решил я, значит, написать свой плеер раз такие дела, всегда хотелось что-то поудобнее, а нет ничего удобного чем свои костыли. К тому же, в последних версиях Qt в качестве media backend стал использоваться FFmpeg, хотелось посмотреть как там с этим обстоят дела. Статья не о том, как в принципе получить аудио из VK, а о сетевых проблемах в VK и Qt.

Ничего не предвещало беды

Авторизацию сделал, немного повозился с API, затем пачка проблем с HLS, и вот он, заветный stream который отправляется в QMediaPlayer. Сначала все было хорошо, музыка заиграла, а это значит, что я мог двигаться дальше и рисовать уродский UI. Но радоваться получилось не долго, при загрузке некоторых сегментов из HLS-плейлиста я стал видеть в выводе приложения следующие ошибки:

qt.network.http2: stream 1 closed
qt.network.http2: stream 1 error: "Data on closed stream"
qt.network.http2: stream 1 finished with error: "Server received frame(s) on a half-closed stream"

Виду я не подал, надеялся что что-то не важное, мало ли что там пришло не так? Но вот FFmpeg demuxer быстро заметил данную проблему и отказался воспроизводить данный стрим.

Пришлось разбираться

В первую очередь я решил посмотреть, что же нам вернул сервер? На первый взгляд все оказалось хорошо: данные в ответе есть, HTTP-код ответа — 200. Я решил проверить конкретную ссылку на сегмент открыв ее в браузере, и первое, что я заметил это то, что размер моих данных не совпадал с тем, что написано в заголовке content-length: у меня получилось 827392 байт, в то время как в заголовке написано, что их должно быть 866688, да и браузер этот сегмент сохранил с корректным размером.

Небольшое отступление. В Qt по умолчанию включен HTTP2, и первое, что я проверил — это явное указание работы с сетью через HTTP1.1. Это сработало, но некоторые вещи я не могу оставить просто так, не разобравшись. Поэтому я начал проверять другие клиенты и искать корень проблемы.

Браузер я уже проверил, и на вкладке сети он как раз сходил успешно в сеть с использованием HTTP2. Следующий кандидат — cURL: 

curl -v --http2 “https://your.some/endpoint” -o some/output/file

Тут тоже все хорошо получается: HTTP-код ответа — 200, количество байт в заголовке совпадает с тем что загружено в файл. Значит с сервером на первый взгляд все хорошо и есть какая-то проблема на стороне Qt.

Первое, что приходит в голову при такой ошибке это маленькое окно flow-control и проблемы с WINDOW_UPDATE. Но тут это маловероятно: по умолчанию QNetworkAccessManager использует размер окна stream-level flow control примерно в ~204 МБ. В моем случае для жалких 866 килобайт Qt вообще не должен слать промежуточных WINDOW_UPDATE, так что сценарий с некорректным использованием WINDOW_UPDATE отпадает.

Судя по тексту ошибок Data on closed stream и half-closed stream — это рассинхронизация состояний стрима между строгой реализацией Qt и сервером VK (kittenx). Кто-то шлет фрейм для стрима, который другая сторона уже считает закрытым, Qt воспринимает это как ошибку, разрывает соединение и отдает частично накопленный буфер.

Для проверки того, как ходят фреймы между клиентом и сервером я воспользовался утилитой nghttp:

nghttp -nv “https://your.some/endpoint”

Исходя из вывода видно что сервер ведет себя корректно и в конце правильно завершает стрим:

[0.698] recv DATA frame <length=6541, flags=0x01, stream_id=1>
        ; END_STREAM

Никакого RST_STREAM, никакого GOAWAY с ошибкой от сервера. Но первое что бросается в глаза — небольшой размер окна, с которым работает nghttp: send SETTINGS … [SETTINGS_INITIAL_WINDOW_SIZE: 65535]. Qt по умолчанию работает с очень большим окном, в моем случае сервер должен отдать все в одном запросе, Qt не должен слать промежуточных WINDOW_UPDATE по ходу передачи.

В Qt можно настроить конфигурацию для HTTP2 и уменьшить размер окна с помощью QHttp2Configuration: 

QHttp2Configuration h2;
h2.setStreamReceiveWindowSize(65535);
h2.setSessionReceiveWindowSize(65535);
…
QNetworkRequest req(url);
req.setHttp2Configuration(h2);
auto* reply = mgr.get(req);

В моем случае это решило проблему, но на самом деле потрачено было много времени впустую, очень неприятно, поэтому…

Чиним Qt

Под рукой у меня уже были исходники QtBase модуля, поэтому я не долго думая приступил к отладке. Сразу же я добавил простой лог в консоль в Http2::FrameReader::read(), который выводил мне пакеты их размер и состояния пакетов. Получились примерно такие логи:

... (105 × DATA, len=8192, no END_STREAM) ...
FRAME type=0 flags=0x01 len=6528 stream=1
stream 1 closed
FRAME type=0 flags=0x01 len=0  stream=1
stream 1 error: "Data on closed stream"
stream 1 finished with error: ...

В логах видно, что нам пришло сначала много фреймов фиксированного размера в 8192 байта, затем идет последний фрейм — оставшийся “хвост” наших данных, помеченный флагом 0x01, что означает что стрим завершен и это последний фрейм. А затем видно, как сервер, после завершения, присылает еще один пустой(!) фрейм с флагом 0x01 в тот же самый стрим. Это нарушение протокола со стороны сервера, так как после END_STREAM фреймов для стрима быть не должно. И появляется он только при большом WINDOW_SIZE.

Формально реализация Qt корректная: RFC 9113 §6.1 требует ответить STREAM_CLOSED на DATA-фрейм для закрытого стрима. Но текущая реализация плохая, потому что:

  • Потеря уже принятых данных. QNetworkReply отдал 827392 байт (101 чанк по 8192 байта), хотя reader принял все 866688 байт. По итогу Qt выбросил последние 39296 байт, которые уже были получены. Потеря принятых данных это однозначно баг.

  • Уже завершенный успешно reply помечен ошибочным. К моменту получения пустого фрейма стрим уже был в состоянии closed, и сигнал finished() отработал. Прилетевший мусорный фрейм “задним числом” превращает успешный ответ в ProtocolFailure.

Наша цель — не нарушать поведение по RFC 9113 §6.1, а отделить корректную реализацию протокола от пользовательского результата: если стрим уже получил END_STREAM и данные доставлены, последующий фрейм можно отметить как RST_STREAM на уровне протокола, но не эмитить finishedWithError по reply, который уже завершен успешно, и не терять буфер.

Проблема в finishStream

Когда приходит корректный END_STREAM, то вызывается QHttp2ProtocolHandler::finishStream, и происходит следующее:

  • поток уже в состоянии Closed, поэтому RST не шлётся;

  • reply отвязывается от хендлера и завершается через сигнал finished() — но отложенно, и будет выполнен только на следующем цикле event loop;

  • запись в requestReplyPairs не удаляется — она живёт до вызова deleteLater().

Получается, что лишний пустой фрейм приходит в том же проходе handleReadyRead, синхронно, до того как event loop доставит отложенный finished(). Он идёт по пути handleDATA → streamError → сигнал errorOccurred → лямбда → finishStreamWithError.

Лямбда берет reply из requestReplyPairs, в котором все еще продолжает находиться наш reply и синхронно эмитит finishedWithError. Итог: уже завершенный успешный ответ становится ошибочным с причиной ProtocolFailure, и код, обрабатывающий ошибки, отбрасывает накопленное тело.

Чтобы это исправить, необходимо просто успешно завершившийся reply убрать из requestReplyPairs. Это обеспечивает соответствие RFC 9113 §6.1, а RST_STREAM по-прежнему будет отправляться в ответ на случайные DATA-фреймы.

Изменение предотвращает получение ошибки и потерю данных на уровне протокола пользователем, когда reply уже фактически завершился. Настоящие ошибки в процессе передачи остаются без изменений, поскольку finishStream() для них еще не вызвалось, поэтому данные в requestReplyPairs еще присутствуют.

По итогу был добавлен баг в Jira и патч, исправляющий проблему. Исправления попали в версии 6.8.9, 6.11.2 и 6.12.0 Beta1.