Hello!
On Mon, Aug 10, 2020 at 07:33:22PM +0300, Slawa Olhovchenkov wrote:
> On Mon, Aug 10, 2020 at 07:13:22PM +0300, Maxim Dounin wrote:
>
> > > > Я бы ещё внимательно посмотрел на тайминги. Непонятно, что за
> > > > времена приведены в логах, но $request_time там точно нет, а если
> > >
> > > $request_time $connection $upstream_cache_status $upstream_connect_time $upstream_response_time $upstream_bytes_received
> > >
> > > > запросы общаются с бэкендом одновременно и proxy_cache_lock не
> > >
> > > да не вопрос.
> > >
> > > > используется - то и MISS'ов может быть одновременно много, при
> > > > этом завершаться запросы могут в заметно разное время.
> > >
> > > не понимаю. вот есть первый запрос, окончился в 21:01:48, начался ну пусть в 21:01:47. апстрим отдался почти мгновенно.
> > > теперь на 5 дней должен быть хит независимо от. а в логе то хит то мисс.
> >
> > Дальше имеет смысл смотреть на:
> >
> > 1. Откуда вообще логи, с одной ли машины? Такой разброс времени
> > при логгировании можно, конечно, получить при буферизированном
> > логгировании, но выглядит подозрительно.
>
> с одной, буферезированно
>
> > 2. Что на самом деле в заголовках ответов бэкенда? Скажем,
> > наличие какого-нибудь Vary легко объясняет наблюдаемый эффект.
>
> я поищу объект в кеше на диске.
> бакэнд -- ceph radosgw, он довстаточно тупой, кмк и ничего такого
> выдавать не должен.
> у типичного объекта заголовки выглядят так:
>
> KEY:
> http://rgw/xxx....xxx/720p_00480.ts
> HTTP/1.1 200 OK
> Content-Length: 925524
> Accept-Ranges: bytes
> Last-Modified: Tue, 28 Jul 2020 11:24:38 GMT
> x-rgw-object-type: Normal
> ETag: "872d2e58236625d418f4c5b5b95938a6"
> x-amz-request-id: tx000000000000004e0151a-005f316581-a67b17a-default
> Access-Control-Allow-Origin: https://some.site
> Vary: Origin
> Access-Control-Allow-Methods: GET
> Access-Control-Expose-Headers: Content-Length,Content-Type
> Content-Type: video/MP2T
> Date: Mon, 10 Aug 2020 15:19:29 GMT
> Connection: close
>
> это что, Vary: Origin гадит? фильтрануть его с бэкенда, что ли?
Это выглядит как наиболее вероятная причина.
При наличии "Vary: Origin" запросы с разными значениями заголовка
Origin - это запросы, на которые могут быть разные ответы, и
соответственно каждое новое значение - это очередной MISS в логах.
Для лечения есть ручка "proxy_ignore_headers Vary;"
(http://nginx.org/r/proxy_ignore_headers).
> > Особенно в этом плане характерны запросы от одного клиента:
> >
> > > 85.249.93.174 :61175 [01/Aug/2020:21:02:42 +0300] "GET /720p_02815.ts HTTP/1.1" 200 616316 0.033 177157 MISS 0.000 0.005 616032
> > > 85.249.93.174 :61175 [01/Aug/2020:21:04:11 +0300] "GET /720p_02815.ts HTTP/1.1" 200 616316 0.074 177157 HIT - - -
> >
> > 3. Ну и проверить, что вообще в ключе кэширования, не добавлено ли
> > там чего-либо клиентоспецифичного случайно.
>
> вообще не модифицировалось
По умолчанию там конструкция, близкая к
$scheme$proxy_host$request_uri, и, скажем $proxy_host может
зависить от клиента, если в proxy_pass написать что-нибудь с
переменными.
> > Если не поможет - смотреть debug log'и, там всё должно быть
> > плюс-минус очевидно.
>
> это продакшен, с дебаг логами боюсь все станет раком (а так бы я прямо
> с них и начал бы).
Just in case, дебаг можно включать не для всех, а только для части
клиентов (http://nginx.org/r/debug_connection), это можно
относительно безопасно делать в том числе и в продакшне. Следя,
естественно, чтобы не включить слишком много, и чтобы место под
логи не кончалось.
--
Maxim Dounin
http://mdounin.ru/
_______________________________________________
nginx-ru mailing list
nginx-ru@nginx.org
http://mailman.nginx.org/mailman/listinfo/nginx-ru
