nginx proxy MISS

[Slawa Olhovchenkov]

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 гадит? фильтрануть его с бэкенда, что ли?

> Особенно в этом плане характерны запросы от одного клиента:
> 
> > 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. Ну и проверить, что вообще в ключе кэширования, не добавлено ли 
> там чего-либо клиентоспецифичного случайно.

вообще не модифицировалось

> Если не поможет - смотреть debug log'и, там всё должно быть 
> плюс-минус очевидно.

это продакшен, с дебаг логами боюсь все станет раком (а так бы я прямо
с них и начал бы).