nginx proxy MISS

Maxim Dounin mdounin на mdounin.ru
Пн Авг 10 16:13:22 UTC 2020


Hello!

On Mon, Aug 10, 2020 at 04:04:11PM +0300, Slawa Olhovchenkov wrote:

> On Mon, Aug 10, 2020 at 03:40:58PM +0300, Maxim Dounin wrote:
> 
> > Hello!
> > 
> > On Mon, Aug 10, 2020 at 11:22:57AM +0300, Slawa Olhovchenkov wrote:
> > 
> > > On Mon, Aug 10, 2020 at 03:26:25AM +0300, Maxim Dounin wrote:
> > > 
> > > > Hello!
> > > > 
> > > > On Mon, Aug 10, 2020 at 12:13:09AM +0300, Slawa Olhovchenkov wrote:
> > > > 
> > > > > Есть файл, не меняется, заголовков про expire не имеет.
> > > > > 
> > > > > Response: {'status': 200, 'headers': {'content-length': '615700', 'x-rgw-object-type': 'Normal', 'accept-ranges': 'bytes', 'last-modified': 'Wed, 08 Jul 2020 01:35:48 GMT', 'connection': 'Keep-Alive', 'etag': '"1f722dbb169b83ea4f5897d638d39c8d"', 'x-amz-request-id':
> > > > >  'tx00000000000000451618a-005f306158-a6edb7b-default', 'date': 'Sun, 09 Aug 2020 20:49:28 GMT', 'content-type': 'video/MP2T'}, 'reason': 'OK'}
> > > > >  
> > > > > 188.242.226.75 :62964 [30/Jul/2020:21:01:48 +0300]  "GET /720p_02815.ts HTTP/1.1" 200 616330 MISS 0.000 0.016 616206
> > > > > 212.164.64.179 :6700 [30/Jul/2020:21:01:50 +0300]   "GET /720p_02815.ts HTTP/1.1" 200 616330 HIT - - -
> > > > > 109.94.87.178 :56019 [30/Jul/2020:21:01:51 +0300]   "GET /720p_02815.ts HTTP/1.1" 200 616330 HIT - - -
> > > > > 165.225.66.51 :3581 [30/Jul/2020:21:01:46 +0300]    "GET /720p_02815.ts HTTP/1.1" 200 616330 MISS 0.000 0.043 616196
> > > > > 176.59.135.87 :41598 [30/Jul/2020:21:01:47 +0300]   "GET /720p_02815.ts HTTP/1.1" 200 616330 HIT - - -
> > > > > 178.184.45.0 :45255 [30/Jul/2020:21:01:50 +0300]    "GET /720p_02815.ts HTTP/1.1" 200 616330 HIT - - -
> > > > > 85.26.233.17 :6656 [30/Jul/2020:21:01:59 +0300]     "GET /720p_02815.ts HTTP/1.1" 200 616330 HIT - - -
> > > > > 91.214.220.143 :43841 [30/Jul/2020:21:01:59 +0300]  "GET /720p_02815.ts HTTP/1.1" 200 616330 HIT - - -
> > > > > 128.71.141.232 :57462 [30/Jul/2020:21:02:31 +0300]  "GET /720p_02815.ts HTTP/1.1" 200 616330 HIT - - -
> > > > > 5.167.161.39 :64139 [30/Jul/2020:21:02:36 +0300]    "GET /720p_02815.ts HTTP/1.1" 200 616316 HIT - - -
> > > > > 95.105.98.204 :49869 [30/Jul/2020:21:02:34 +0300]   "GET /720p_02815.ts HTTP/1.1" 200 616316 MISS 0.000 0.020 616032
> > > > > 
> > > > > какие причины могут быть для возникновения MISS?
> > > > > 
> > > > > зона не заполнена даже наполовину.
> > > > > proxy_cache_path /cache keys_zone=RGW:1000m levels=2:2 max_size=6000g inactive=10d use_temp_path=off;
> > > > 
> > > > Если выше показаны заголовки ответа бэкенда, то я в первую очередь 
> > > > не вижу, почему бы этому файлу кэшироваться.  То есть - каковы 
> > > > причины для возникновения HIT?
> > > > 
> > > > В отсутствии явно заданных заголовков Cache-Control / Expire / 
> > > > X-Accel-Expire - единственная возможная причина кэширования это 
> > > > директива proxy_cache_valid, если она в конфиге есть - то 
> > > > вероятнее всего отвечает на оба вопроса.
> > > 
> > > proxy_cache_valid      200  5d;
> > 
> > Я бы ещё внимательно посмотрел на тайминги.  Непонятно, что за 
> > времена приведены в логах, но $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 легко объясняет наблюдаемый эффект.  
Особенно в этом плане характерны запросы от одного клиента:

> 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'и, там всё должно быть 
плюс-минус очевидно.

-- 
Maxim Dounin
http://mdounin.ru/


Подробная информация о списке рассылки nginx-ru