Re: Неконтроллируемый объем кеша Nginx

[Roman Arutyunyan]

On 06 May 2015, at 13:39, vlakas <nginx-forum at nginx.us> wrote:

> Здравствуйте.
> 
> Дебаг лог, во время повторения инцидента можно получить по ссылке:
> https://mega.co.nz/#!VI5DBbiI!GZDPBbfkyTCCmY8J0r9KFuov4UYldNegvN1SvtOYPVs
> (1.3 GB)
> 
> Проблема была обнаружена 5 мая около 22:50 (лог в себ включает сообщения на
> временном промежутке 22:45 - 22:55).

Какое время прошло от старта nginx?

Судя по логу, вы релоадили nginx и, вероятно, даже меняли число воркеров.
Это так?  Если этого не делать, проблема также появляется?

> В самом логе вижу множество следующих сообщений:
> 2015/05/05 22:49:42 [debug] 6696#0: http file cache forced expire: #1 1
> 31dd5198
> 2015/05/05 22:49:42 [debug] 6696#0: http file cache forced expire: #1 1
> bdb466de
> 2015/05/05 22:49:42 [debug] 6696#0: http file cache forced expire: #1 1
> 3207dd39
> 2015/05/05 22:49:42 [debug] 6696#0: http file cache forced expire: #1 1
> b417f542
> 2015/05/05 22:49:42 [debug] 6696#0: http file cache forced expire: #1 1
> 14a73e73
> 
> При чем неоднократно повторяющихся. Если искать по hash id (напр.,
> 31dd5198), нахожу только эти сообщения и ничего больше.

Это и есть основная проблема.  У вас есть возможность поискать эту строку
в более ранних логах?  Cache manager очищает кеш в порядке lru, так что
этот файл появился в кеше некоторое время назад и успел с тех пор стать
самым старым.

Что касается поиска файла, соответствующего ключу, я вам в прошлый раз дал
не совсем верный алгоритм.  Надо искать чуть иначе, вот пример из вашего же лога:

2015/05/05 22:45:33 [debug] 6696#0: http file cache forced expire: #0 1 b139cb65
2015/05/05 22:45:33 [debug] 6696#0: http file cache expire: "/opt2/nginx-cache-images1/c8/de/0ac4a89e20a39c1fb139cb65c2ffdec8"

b139cb65 -> /opt2/nginx-cache-images1/c8/de/0ac4a89e20a39c1f b139cb65 c2ffdec8

> Меня интересует, что в вышеприведенных логах означает 4-е поле (6696#0).
> Могу предположить, что это привязка к процессу cache manager, но не уверен.

Это pid процесса (на ‘#0' не обращайте внимания).

> Если фильтровать логи по этому полю, нахожу следующее:
> 2015/05/05 22:48:16 [debug] 6696#0: shmtx lock
> 2015/05/05 22:48:16 [debug] 6696#0: shmtx unlock
> 2015/05/05 22:48:16 [debug] 6696#0: shmtx wake 634
> 2015/05/05 22:48:16 [debug] 6696#0: http file cache size: 20975604
> 2015/05/05 22:48:16 [debug] 6696#0: http file cache forced expire
> 2015/05/05 22:48:16 [debug] 6696#0: malloc: 00000000026BAA20:65
> 2015/05/05 22:48:16 [debug] 6696#0: shmtx lock
> 2015/05/05 22:48:16 [debug] 6696#0: http file cache forced expire: #0 1
> a3397f6c
> 2015/05/05 22:48:16 [debug] 6696#0: shmtx unlock
> 
> Я так понимаю, это удачная очистка кеша. И следующее:
> 2015/05/05 22:48:16 [debug] 6696#0: shmtx lock
> 2015/05/05 22:48:16 [debug] 6696#0: shmtx unlock
> 2015/05/05 22:48:16 [debug] 6696#0: shmtx wake 625
> 2015/05/05 22:48:16 [debug] 6696#0: http file cache size: 20975581
> 2015/05/05 22:48:16 [debug] 6696#0: http file cache forced expire
> 2015/05/05 22:48:16 [debug] 6696#0: malloc: 00000000026BAA20:65
> 2015/05/05 22:48:16 [debug] 6696#0: shmtx lock
> 2015/05/05 22:48:16 [debug] 6696#0: http file cache forced expire: #1 1
> dd87e60a
> 2015/05/05 22:48:16 [debug] 6696#0: http file cache forced expire: #0 1
> 93a2ff07
> 2015/05/05 22:48:16 [debug] 6696#0: shmtx unlock
> 
> И еще:
> 2015/05/05 22:48:16 [debug] 6696#0: shmtx wake 571
> 2015/05/05 22:48:16 [debug] 6696#0: http file cache expire:
> "/opt2/nginx-cache-images1/2f/ee/093821fba4c1bf6f947a291d0dcfee2f"
> 2015/05/05 22:48:16 [debug] 6696#0: shmtx lock
> 2015/05/05 22:48:16 [debug] 6696#0: slab free: 00007F66BE5FF380
> 2015/05/05 22:48:16 [debug] 6696#0: shmtx unlock
> 2015/05/05 22:48:16 [debug] 6696#0: shmtx wake 570
> 2015/05/05 22:48:16 [debug] 6696#0: shmtx lock
> 2015/05/05 22:48:16 [debug] 6696#0: shmtx unlock
> 2015/05/05 22:48:16 [debug] 6696#0: shmtx wake 569
> 2015/05/05 22:48:16 [debug] 6696#0: http file cache size: 20975519
> 2015/05/05 22:48:16 [debug] 6696#0: http file cache forced expire
> 2015/05/05 22:48:16 [debug] 6696#0: malloc: 00000000026BAA20:65
> 2015/05/05 22:48:16 [debug] 6696#0: shmtx lock
> 2015/05/05 22:48:16 [debug] 6696#0: http file cache forced expire: #1 1
> dd87e60a
> 2015/05/05 22:48:16 [debug] 6696#0: http file cache forced expire: #1 1
> 8bc7932f
> 2015/05/05 22:48:16 [debug] 6696#0: http file cache forced expire: #0 1
> 91e3b5df
> 2015/05/05 22:48:16 [debug] 6696#0: shmtx unlock
> 
> Во время инцидента с uptime'мом воркеров аномалий не обнаружено.
> 
> P.S. Такая же версия nginx работает также на Ubuntu 12 LTS. В этом случае
> проблем не было обнаружено.

Конфигурации и действия, которые вы производите с nginx, одинаковы?