Cloudflare рассказала, как шесть недель искала почти невидимый баг в hyper — популярной HTTP-библиотеке для Rust. Ошибка проявлялась неприятно: сервис возвращал 200 OK, в логах не было явных сбоев, но клиент получал не весь ответ. Например, вместо нескольких мегабайт данных доходили только первые сотни килобайт.
В итоге причина оказалась не в бизнес-логике, не в обработке изображений и не в клиентском коде. Данные терялись на уровне соединения: hyper мог закрыть сокет до того, как полностью вытолкнул тело ответа из внутреннего буфера.
Где всплыл баг
Проблему нашли в сервисе Cloudflare Images. Он написан на Rust, работает на edge-сети Cloudflare и использует hyper для обработки HTTP-соединений.
Сценарий был такой: разработчик через Workers обращался к Images binding — программному интерфейсу для обработки изображений. В одном из пользовательских пайплайнов изображение сначала собиралось из нескольких крупных исходников, а затем дополнительно сжималось, перекодировалось и масштабировалось через другой слой обработки.
Снаружи всё выглядело странно. Внутренний слой возвращал HTTP 200, заголовок Content-Length обещал несколько мегабайт, но тело ответа оказывалось обрезанным. В одном из случаев вместо ожидаемых 3,3 МБ до клиента дошло около 200 КБ.
Если бы ошибка была обычной — тайм-аут, падение процесса, некорректный статус, исключение в логах, — её нашли бы быстрее. Но система считала, что всё прошло успешно.
Почему проблема появилась не сразу
Незадолго до этого Cloudflare изменила архитектуру Images binding. Раньше данные шли через внутренний промежуточный сервис FL, который обрабатывает входящий трафик в сети Cloudflare. Позже его заменили более прямым локальным взаимодействием: сервисы стали общаться через Unix-сокеты на одной машине.
Сам баг при этом не появился из-за новой архитектуры. По словам Cloudflare, он существовал в hyper годами и затрагивал несколько мажорных версий библиотеки. Новая схема просто изменила поведение чтения с другой стороны сокета. Старый промежуточный слой, вероятно, забирал данные достаточно быстро, и буфер сокета почти никогда не заполнялся. Новый читатель иногда задерживался на несколько миллисекунд — этого хватило, чтобы гонка начала проявляться.
Получилась классическая инженерная ловушка: систему ускорили и упростили, а заодно вытащили наружу старый баг, который раньше прятался в таймингах.
Как искали причину
Команда Cloudflare сначала шла обычным путём: собирала воспроизведение, проверяла версии hyper, смотрела тайм-ауты, изучала трассировки, исключала слой за слоем.
Важные наблюдения были такие:
-
баг воспроизводился только на больших ответах;
-
локально и через
curlего долго не удавалось поймать; -
проблема появлялась только в полном production-пути, с реальной конкуренцией и настоящим клиентом Workers runtime;
-
обрезание происходило до внешнего слоя обработки изображений;
-
сервис Images успевал обработать запрос и считал, что отправил корректный ответ.
Один из первых надёжных сигналов был связан с размером данных. При сбое до клиента доходило примерно столько, сколько помещалось в буфер сокета в production-окружении. Это сузило область поиска: данные не «ломались» при обработке изображения, а застревали где-то между внутренним буфером hyper и сокетом.
strace показал то, чего не было в логах
Прикладные логи и трассировки говорили: ответ отправлен, статус 200, ошибок нет. Поэтому Cloudflare пошла ниже — на уровень системных вызовов.
К процессу Images подключили strace, чтобы увидеть, что реально происходит с сокетом: сколько байт записано, когда вызван shutdown, не закрывал ли соединение клиент.
Тут и нашлась разница между успешным и неуспешным запросом.
В успешном случае процесс много раз вызывал sendto, постепенно записывая тело ответа в сокет, и только после этого закрывал сторону записи:
sendto(...) = 219264sendto(...) = 292352sendto(...) = 292352...shutdown(..., SHUT_WR) = 0
В неуспешном случае всё выглядело иначе:
sendto(...) = 219264shutdown(..., SHUT_WR) = 0
То есть сервис записывал только первый кусок ответа — около 219 КБ — и сразу закрывал соединение. Остальные мегабайты оставались во внутреннем буфере hyper и так и не доходили до клиента.
Важно, что клиент при этом не закрывал соединение сам. Сокет закрывал именно сервис Images, потому что hyper считал работу завершённой.
Ошибка была в одном отброшенном результате
Внутри hyper жизненный цикл HTTP/1-соединения управляется циклом, который читает запросы, пишет ответы, сбрасывает буфер записи в сокет и решает, когда можно завершать соединение.
Упрощённо проблемный участок выглядел так:
let _ = self.poll_flush(cx)?;
На первый взгляд строка безобидная. Но в Rust запись let = ... отбрасывает результат выражения. В данном случае отбрасывался результат pollflush.
А poll_flush может вернуть Poll::Pending. Это означает: данные ещё не полностью вытолкнуты в сокет, нужно подождать, пока сокет снова станет доступен для записи.
Именно это и происходило при больших ответах. hyper успевал положить весь ответ во внутренний буфер и считал, что с точки зрения кодирования работа закончена. Затем пытался сбросить данные в сокет. Сокет принимал первый кусок, заполнялся и возвращал Poll::Pending.
Но результат Poll::Pending отбрасывался. Цикл продолжал выполнение, решал, что больше читать нечего, и доходил до закрытия соединения. Данные ещё лежали в буфере, но сокет уже закрывали.
Почему curl не помог
Отдельно интересно, почему простые проверки через curl не воспроизводили проблему.
curl быстро читает данные по мере их поступления. Из-за этого буфер сокета не заполнялся, poll_flush завершался сразу, и отброшенный результат не имел значения.
В production-пути читатель иногда задерживался буквально на несколько миллисекунд. Этого хватало, чтобы буфер успел заполниться, poll_flush вернул Poll::Pending, а hyper пошёл закрывать соединение раньше времени.
То есть баг жил не в «больших картинках» как таковых. Большой ответ просто повышал вероятность попасть в узкое окно между частичной записью и преждевременным shutdown.
Как исправили
Сначала Cloudflare проверила простой вариант: перед завершением цикла убедиться, что сброс буфера действительно завершён.
Логика была такой:
let flush_result = self.poll_flush(cx)?;if flush_result.is_pending() { return Poll::Pending;}
Если данные ещё не ушли в сокет, задача возвращает Poll::Pending. Асинхронная среда выполнения позже разбудит её, когда сокет снова будет готов к записи.
Но для upstream-исправления этот вариант оказался слишком грубым. Он мог повлиять на другие операции в том же соединении и создать лишнее обратное давление. Особенно это важно для keep-alive-соединений, где одно соединение обслуживает несколько последовательных запросов.
Финальное исправление сделали точечнее: перед реальным закрытием сокета hyper должен сначала полностью сбросить оставшиеся данные из буфера.
ready!(self.poll_flush(cx)?);Pin::new(&mut self.io).poll_shutdown(cx)
Так цикл обработки соединения остаётся прежним, но в момент закрытия появляется дополнительная гарантия: если в буфере ещё есть данные, соединение не будет закрыто раньше времени.
Cloudflare добавила к исправлению детерминированный тест: специальная обёртка над TCP-потоком принимала первый кусок данных, а затем возвращала Poll::Pending, имитируя заполненный буфер сокета. Без исправления hyper вызывал shutdown, пока часть ответа ещё лежала в буфере. С исправлением — ждал.
Что из этого полезно вынести
История хороша не только самим багом, но и способом расследования.
Первый вывод: статус 200 OK ещё не означает, что клиент получил весь ответ. Если Content-Length обещает одно, а тело доходит частично, искать приходится ниже прикладной логики — в соединении, буферах и системных вызовах.
Второй вывод: наблюдаемость на уровне приложения не всегда видит ошибки транспортного слоя. Логи могут говорить «ответ отправлен», потому что приложение действительно передало данные библиотеке. Но это ещё не значит, что данные ушли в сокет и дошли до читателя.
Третий вывод: оптимизация архитектуры может проявить старые гонки. Cloudflare не «сломала» hyper новой схемой соединений. Она изменила тайминги настолько, что редкий баг стал воспроизводимым.
Исправление уже внесли в hyperium/hyper; оно должно попасть в будущий релиз библиотеки. До этого Cloudflare использует внутреннюю версию с патчем.
Редкий случай, когда баг искали шесть недель, а исправление в итоге свелось к нескольким строкам. Но именно такие истории хорошо напоминают: между «мы записали ответ» и «клиент получил все байты» есть ещё ядро, буферы, асинхронная среда выполнения и пара миллисекунд, которые иногда решают всё.
Если хотите глубже разобраться в расследовании production-инцидентов и низкоуровневой отладке, приходите на бесплатные уроки OTUS — их проводят преподаватели-практикующие эксперты.
-
24 июня 20:00. «Инцидент-менеджмент в SRE. Как быстро находить, устранять и предотвращать сбои в системе». Записаться
-
8 июля 20:00. «Продвинутое использование отладчика GDB». Записаться
ссылка на оригинал статьи https://habr.com/ru/articles/1051330/