Re: zero size buf in output при proxy cache

[Maxim Dounin]

Hello!

On Tue, Feb 16, 2016 at 02:00:33PM -0500, iprok wrote:

> Здравствуйте!
> 
> На видеостриминговой системе используем два уровня проксей (эджи и
> ориджины). Эджи проксируют клиентов на ориджины, ориджины проксируют эджи на
> сервера-источники видео. Видео отдается в формате HLS: это плейлисты
> (текстовые файлы) и чанки видео (видео-файлы в формате ts).
> 
> В локейшенах, проксирующих чанки, на ориджинах и эджах регулярно, хоть и
> относительно не часто (пара десятков за сутки), проскакивают ошибки "zero
> size buf in output". Мне кажется причиной является одна из директив:
>                 proxy_cache_use_stale updating;
>                 proxy_cache_lock on;
> так как до их появления таких ошибок не было.
> 
> nginx в основном 1.8.1, но проявиляется так же и на 1.9.11, логи ниже делал
> на последней. Используем пакеты для debian8 из репозитория на nginx.org.
> 
> Если смотреть access.log, то чанк в помент проявления этой ошибки отдается
> частично, но с кодом 200 (размер в логе меньше реального размера), при
> следующем запросе отдается нормально, и ошибка не проявляется.
> 
> Лог кратко (debug.log внизу, здесь и далее в логах вырезана приватная
> информация, так как ошибка вопроизводится только в продакшене):
> 
> 2016/02/14 11:09:20 [alert] 30161#30161: *1388932 zero size buf in output
> t:0 r:0 f:0 0000000002387520 0000000002387520-0000000002389356
> 0000000000000000 0-0 while sending to client, client: HIDDENIPV4, server:
> e6.mysite.com, request: "GET /place1/stream/cam13_low-5743015560.ts
> HTTP/1.1", upstream:
> "https://[HIDDENIPV6]:443/place1/video/cam13_low-5743015560.ts", host:
> "e6.mysite.com", referrer: "https://mysite.com/"
> 2016/02/14 11:09:23 [alert] 30160#30160: *1389653 zero size buf in output
> t:0 r:0 f:0 00000000022BBC50 00000000022BBC50-00000000022BF185
> 0000000000000000 0-0 while sending to client, client: HIDDENIPV4, server:
> e6.mysite.com, request: "GET /place1/stream/cam13_hi-5297110020.ts
> HTTP/1.1", upstream:
> "https://HIDDENIPV4:443/place1/video/cam13_hi-5297110020.ts", host:
> "e6.mysite.com", referrer: "https://mysite.com/"

[...]

> Сразу выкладываю debug.log (18 мегабайт в распакованном виде): 
> https://kinetiksoft.com/thecloud/index.php/s/5ldvsZFiC2NjpXJ
> Я обрезал только 10 секунд, за которые произошли две ошибки из краткого лога
> в начале сообщения.

Судя по логам, проблема возникает тогда, когда клиент закрывает 
соединение до получения ответа целиком.  В обоих случаях перед 
alert'ом про "zero size buf" в логах видно такое:

2016/02/14 11:09:20 [info] 30161#30161: *1388932 epoll_wait() reported that client prematurely closed connection (32: Broken pipe) while reading upstream, client: HIDDENIPV4, server: e6.mysite.com, request: "GET /place1/stream/cam13_low-5743015560.ts HTTP/1.1", upstream: "https://[HIDDENIPV6]:443/place1/video/cam13_low-5743015560.ts", host: "e6.mysite.com", referrer: "https://mysite.com/"
2016/02/14 11:09:23 [info] 30160#30160: *1389653 epoll_wait() reported that client prematurely closed connection while reading upstream, client: HIDDENIPV4, server: e6.mysite.com, request: "GET /place1/stream/cam13_hi-5297110020.ts HTTP/1.1", upstream: "https://HIDDENIPV4:443/place1/video/cam13_hi-5297110020.ts", host: "e6.mysite.com", referrer: "https://mysite.com/"

В этом случае nginx продолжает загружать файл с бекенда в кеш, а 
после окончания загрузки - пытается отправить последний буфер.  И, 
видимо, где-то вместе с этим буфером проталкивает в цепочке 
фильтров что-то, что ранее счёл свободным (из-за ошибки записи 
клиенту), но по факту оно застряло где-то в цепочке фильтров.

Что именно там происходит и как это поправить - надо смотреть 
подробнее.  Для начала было бы неплохо убедиться, что сторонних 
модулей не используется, а если используются - то проверить, 
воспроизводится ли проблема без них.  Кроме того, хотелось бы 
увидеть вывод "nginx -V".

(Отмечу также, что в целом ошибка выглядит безвредно - собственно, 
логгируемая ошибка и есть основной его эффект.  В остальном всё 
работает штатно.)

-- 
Maxim Dounin
http://nginx.org/