Здравствуйте.
Дебаг лог, во время повторения инцидента можно получить по ссылке: https://mega.co.nz/#!VI5DBbiI!GZDPBbfkyTCCmY8J0r9KFuov4UYldNegvN1SvtOYPVs (1.3 GB)
Проблема была обнаружена 5 мая около 22:50 (лог в себ включает сообщения на временном промежутке 22:45 - 22:55).
В самом логе вижу множество следующих сообщений:
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), нахожу только эти сообщения и ничего больше.
Меня интересует, что в вышеприведенных логах означает 4-е поле (6696#0). Могу предположить, что это привязка к процессу cache manager, но не уверен.
Если фильтровать логи по этому полю, нахожу следующее:
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. В этом случае проблем не было обнаружено.
