aws sdkを使っているとslabキャッシュが増大化していく

##メモリ使用量が増えている？
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がリリースされた頃にも行っていたが、上記のように現在も問題は解消されていないので注意が必要である。