メモリ使用量が増えている？
aws-sdkを利用したツールをAmazonLinux上で常時稼働させているとメモリのFreeな領域が減っていることがわかる。
アップデートした最新のAmazonLinux(2014/09/13)上で原因を調べた。
slabキャッシュが増大化している。
一度再起動させた直後(before)と、しばらくaws-sdkを使ったツールを実行して放置した後(after)のメモリの状況(/proc/meminfo)を比較する。
[before]
MemTotal: 3859068 kB
MemFree: 3668144 kB
Buffers: 10020 kB
Cached: 89660 kB
SwapCached: 0 kB
Active: 67960 kB
Inactive: 66148 kB
Active(anon): 34428 kB
Inactive(anon): 56 kB
Active(file): 33532 kB
Inactive(file): 66092 kB
Unevictable: 0 kB
Mlocked: 0 kB
SwapTotal: 0 kB
SwapFree: 0 kB
Dirty: 52 kB
Writeback: 0 kB
AnonPages: 34320 kB
Mapped: 14512 kB
Shmem: 64 kB
Slab: 17756 kB
SReclaimable: 10248 kB
SUnreclaim: 7508 kB
KernelStack: 848 kB
PageTables: 2268 kB
NFS_Unstable: 0 kB
Bounce: 0 kB
WritebackTmp: 0 kB
CommitLimit: 1929532 kB
Committed_AS: 99820 kB
VmallocTotal: 34359738367 kB
VmallocUsed: 7716 kB
VmallocChunk: 34359726623 kB
AnonHugePages: 0 kB
HugePages_Total: 0
HugePages_Free: 0
HugePages_Rsvd: 0
HugePages_Surp: 0
Hugepagesize: 2048 kB
DirectMap4k: 8192 kB
DirectMap2M: 3923968 kB
[after]
MemTotal: 3859068 kB
MemFree: 1862624 kB
Buffers: 15564 kB
Cached: 116060 kB
SwapCached: 0 kB
Active: 75444 kB
Inactive: 91172 kB
Active(anon): 34992 kB
Inactive(anon): 56 kB
Active(file): 40452 kB
Inactive(file): 91116 kB
Unevictable: 0 kB
Mlocked: 0 kB
SwapTotal: 0 kB
SwapFree: 0 kB
Dirty: 20 kB
Writeback: 0 kB
AnonPages: 34952 kB
Mapped: 14660 kB
Shmem: 64 kB
Slab: 1790820 kB
SReclaimable: 1783112 kB
SUnreclaim: 7708 kB
KernelStack: 848 kB
PageTables: 2348 kB
NFS_Unstable: 0 kB
Bounce: 0 kB
WritebackTmp: 0 kB
CommitLimit: 1929532 kB
Committed_AS: 100988 kB
VmallocTotal: 34359738367 kB
VmallocUsed: 7716 kB
VmallocChunk: 34359726623 kB
AnonHugePages: 0 kB
HugePages_Total: 0
HugePages_Free: 0
HugePages_Rsvd: 0
HugePages_Surp: 0
Hugepagesize: 2048 kB
DirectMap4k: 8192 kB
DirectMap2M: 3923968 kB
slabキャッシュが増大していってるのがわかる。
下記はafter時のslabtopの結果である。
[after時のslabtop]
Active / Total Objects (% used) : 9456449 / 9458084 (100.0%)
Active / Total Slabs (% used) : 449060 / 449060 (100.0%)
Active / Total Caches (% used) : 61 / 91 (67.0%)
Active / Total Size (% used) : 1776972.73K / 1777415.79K (100.0%)
Minimum / Average / Maximum Object : 0.01K / 0.19K / 8.00K
OBJS ACTIVE USE OBJ SIZE SLABS OBJ/SLAB CACHE SIZE NAME
9399537 9399537 100% 0.19K 447597 21 1790388K dentry
7776 7776 100% 0.11K 216 36 864K sysfs_dir_cache
6356 6356 100% 0.55K 227 28 3632K inode_cache
5056 4498 88% 0.06K 79 64 316K kmalloc-64
4524 4524 100% 0.10K 116 39 464K buffer_head
3472 3472 100% 0.07K 62 56 248K Acpi-ParseExt
2560 2560 100% 0.01K 5 512 20K kmalloc-8
2376 2376 100% 0.18K 108 22 432K vm_area_struct
2304 2304 100% 0.06K 36 64 144K anon_vma
2244 2244 100% 0.94K 66 34 2112K ext4_inode_cache
2210 2210 100% 0.05K 26 85 104K shared_policy_node
1792 1792 100% 0.02K 7 256 28K kmalloc-16
1792 1792 100% 0.03K 14 128 56K kmalloc-32
1764 1243 70% 0.19K 84 21 336K kmalloc-192
1734 1734 100% 0.04K 17 102 68K Acpi-Namespace
1734 1734 100% 0.04K 17 102 68K jbd2_journal_handle
1504 1070 71% 0.25K 47 32 376K kmalloc-256
1400 1400 100% 0.55K 50 28 800K radix_tree_node
864 864 100% 0.12K 27 32 108K kmalloc-128
588 588 100% 0.09K 14 42 56K kmalloc-96
576 576 100% 0.50K 18 32 288K kmalloc-512
528 528 100% 0.64K 22 24 352K shmem_inode_cache
500 477 95% 0.62K 20 25 320K proc_inode_cache
429 429 100% 0.81K 11 39 352K task_xstate
384 384 100% 1.00K 12 32 384K kmalloc-1024
systemtapによるslabキャッシュ増大箇所の調査
slabキャッシュを増大させている原因を探るため、カーネル側からdentryキャッシュを確保している箇所を調査してみる。
下記のトレース結果のfilenameが、dentryキャッシュを増大させているファイル名である。
filename is .247076926_dOeSnotExist_.db
0xffffffff81191190 : d_splice_alias+0x0/0x100 [kernel]
0xffffffffa00d7988 : ext4_lookup+0xe8/0x150 [ext4]
0xffffffff8118555d : lookup_real+0x1d/0x50 [kernel]
0xffffffff81185ae3 : __lookup_hash+0x33/0x40 [kernel]
0xffffffff8144b2df : lookup_slow+0x42/0xa7 [kernel]
0xffffffff81188778 : path_lookupat+0x778/0x800 [kernel]
0xffffffff8118882b : filename_lookup+0x2b/0xc0 [kernel]
0xffffffff8118bb24 : user_path_at_empty+0x54/0x90 [kernel]
0xffffffff8118bb71 : user_path_at+0x11/0x20 [kernel]
0xffffffff8117a743 : sys_faccessat+0xa3/0x200 [kernel]
0xffffffff8117a8b8 : sys_access+0x18/0x20 [kernel]
0xffffffff8145a367 : tracesys+0xdd/0xe2 [kernel]
0x7f2b24364997 : access+0x7/0x30 [/lib64/libc-2.17.so]
0x7f2b1b7aeb58 : PR_Access+0x28/0x90 [/lib64/libnspr4.so]
0x7f2b195b6b8a : sdb_measureAccess+0xca/0x140 [/usr/lib64/libsoftokn3.so]
0x7f2b195b88ed : sdb_init+0x2ad/0x7f0 [/usr/lib64/libsoftokn3.so]
0x7f2b195b8ff5 : s_open+0x1c5/0x200 [/usr/lib64/libsoftokn3.so]
0x7f2b195bc762 : sftk_DBInit+0x3f2/0x670 [/usr/lib64/libsoftokn3.so]
0x7f2b195a75d2 : SFTK_SlotReInit+0x162/0x260 [/usr/lib64/libsoftokn3.so]
0x7f2b195a7a56 : SFTK_SlotInit+0x206/0x3a0 [/usr/lib64/libsoftokn3.so]
0x7f2b195a854c : nsc_CommonInitialize+0x23c/0x2d0 [/usr/lib64/libsoftokn3.so]
0x7f2b195a876a : NSC_Initialize+0x3a/0x50 [/usr/lib64/libsoftokn3.so]
0x7f2b1c037716 : secmod_ModuleInit+0x56/0x450 [/usr/lib64/libnss3.so]
0x7f2b1c037cea : secmod_LoadPKCS11Module+0xfa/0x500 [/usr/lib64/libnss3.so]
0x7f2b1c0433a7 : SECMOD_LoadModule+0x107/0x2b0 [/usr/lib64/libnss3.so]
0x7f2b1c0434a0 : SECMOD_LoadModule+0x200/0x2b0 [/usr/lib64/libnss3.so]
0x7f2b1c0434a0 : SECMOD_LoadModule+0x200/0x2b0 [/usr/lib64/libnss3.so]
0x7f2b1c0134d2 : nss_Init+0x622/0xd50 [/usr/lib64/libnss3.so]
0x7f2b1c013e71 : NSS_InitContext+0xa1/0xd0 [/usr/lib64/libnss3.so]
0x7f2b1cc5077f : curl_slist_free_all+0x122bf/0x13a10 [/usr/lib64/libcurl.so.4.3.0]
0x7f2b1cc50f4d : curl_slist_free_all+0x12a8d/0x13a10 [/usr/lib64/libcurl.so.4.3.0]
0x7f2b1cc4f957 : curl_slist_free_all+0x11497/0x13a10 [/usr/lib64/libcurl.so.4.3.0]
上記のようなトレース結果が大量に出力された。
変なファイル名(上記では .247076926_dOeSnotExist_.db )がaccess(2)されているようである。
問題の特定
似たような現象をググってみると下記のような問題を発見した。
http://curl.haxx.se/mail/tracker-2013-06/0114.html
https://bugzilla.redhat.com/show_bug.cgi?id=1044666
またトレースの結果からaws-sdkからSSL通信している部分が問題のようにみえたので、nssを使わないようにしてみたところdentryキャッシュの増大を防ぐことができた。
原因はaws-sdkからSSL通信を行う際に利用されるnss関連のライブラリであることがわかった。
影響
問題となったライブラリを利用するライブラリ、アプリケーションは全て影響を受けることになる(たとえばLLなスクリプトがどこかにSSL通信する際に利用していることがある)。
対策としては、問題となっているライブラリを使わないようにしなればならない。
なおdentryキャッシュなので、下記のようなコマンドを実行すればそのキャッシュを随時捨てることはできる。
echo 2 > /proc/sys/vm/drop_caches
同様の検証をAmazon Linux AMI 2014.03がリリースされた頃にも行っていたが、上記のように現在も問題は解消されていないので注意が必要である。