Hi,
I've been trying to track down an issue we've started seeing on a bunch of NFS clients where the percentage of CPU time spent by the system has increased for the past month (it was previously using roughly equal system/user time, while now the system time is around 3x the user time).? The information that I have is as follows:
- After rebooting the server, the user/system CPU times look good (roughly equal)
- After 24 hours of heavy activity the system CPU time increases to around 3-4x the user CPU time
- If I run "echo 2 > /proc/sys/vm/drop_caches" the system CPU time drops back down to roughly the same as user
The main difference that I can see in slabtop between a system running at high load and "normal" load is the number of nfs_inode_cache objects (as shown below).? I tried to increase the ihash_entries and dhash_entries kernel parameters, but this did not fix the problem.? I have not found any other suggestions on how to resolve issues caused by large nfs inode caches.
I have tried various kernels between 3.0.0 and 3.2.4, and the machines are currently running a 3.0.22 kernel.? The machines have 8GB RAM, and have 3 NFSv4 mounts and one NFSv3 mount (with the majority of the files that they access being on one of the NFSv4 mount points, being a maildir style mail spool).
I have increased /proc/sys/vm/vfs_cache_pressure to 10000, which has resolved the problem for now, however I believe that the reason we started seeing the issue is that we added a lot of extra users onto the system, resulting in access to a larger number of files for each of the clients. I am not confident that future growth will stay below whatever threshold we had exceeded to cause the excessive system CPU load, since the problem seemed to appear at around 1,000,000 nfs_inode_cache entries in slabtop, and the NFS clients are floating between 500,000 and 900,000 inode_cache entries.
Help please :), and please let me know if I can provide any more information to assist in debugging.
Regards
Steven
Running slabtop on a system with high load looks like this:
? OBJS ACTIVE? USE OBJ SIZE? SLABS OBJ/SLAB CACHE SIZE NAME
2266249 1645904? 72%??? 0.06K? 38411?????? 59??? 153644K size-64
1236390 1218245? 98%??? 1.02K 412130??????? 3?? 1648520K nfs_inode_cache
569180 569180 100%??? 0.19K? 28459?????? 20??? 113836K dentry
190512 184467? 96%??? 0.03K?? 1701????? 112????? 6804K size-32
159026? 83040? 52%??? 0.10K?? 4298?????? 37???? 17192K buffer_head
95520? 76484? 80%??? 0.12K?? 3184?????? 30???? 12736K size-128
78001? 63551? 81%??? 0.55K? 11143??????? 7???? 44572K radix_tree_node
76956? 62898? 81%??? 0.17K?? 3498?????? 22???? 13992K vm_area_struct
74690? 58327? 78%??? 0.05K??? 970?????? 77????? 3880K anon_vma_chain
45680? 36644? 80%??? 0.19K?? 2284?????? 20????? 9136K size-192
33571? 27043? 80%??? 0.06K??? 569?????? 59????? 2276K anon_vma
15980? 11500? 71%??? 0.19K??? 799?????? 20????? 3196K filp
12048? 12046? 99%??? 0.08K??? 251?????? 48????? 1004K sysfs_dir_cache
12024?? 7628? 63%??? 0.64K?? 2004??????? 6????? 8016K proc_inode_cache
11856?? 6964? 58%??? 0.30K??? 912?????? 13????? 3648K nf_conntrack_ffffffff817fdd80
? 5745?? 5293? 92%??? 0.79K?? 1149??????? 5????? 4596K ext3_inode_cache
? 5385?? 3334? 61%??? 0.25K??? 359?????? 15????? 1436K tw_sock_TCP
? 5250?? 4540? 86%?? ?0.25K??? 350?????? 15????? 1400K ip_dst_cache
? 4956?? 2259? 45%??? 0.06K???? 84?????? 59?????? 336K tcp_bind_bucket
? 4180?? 3637? 87%??? 0.19K??? 209?????? 20?????? 836K inet_peer_cache
? 3975?? 3909? 98%??? 0.07K???? 75?????? 53?????? 300K Acpi-Operand
? 2852?? 2808? 98%??? 0.04K???? 31?????? 92?????? 124K Acpi-Namespace
? 2600?? 1969? 75%??? 0.19K??? 130?????? 20?????? 520K cred_jar
? 2385?? 1844? 77%??? 0.07K???? 45?????? 53?????? 180K eventpoll_pwq
? 2370?? 1847? 77%??? 0.12K???? 79?????? 30?????? 316K eventpoll_epi
? 1980?? 1562? 78%??? 1.00K??? 495??????? 4????? 1980K size-1024
Running slabtop on a system after dropping the caches looks like this:
? OBJS ACTIVE? USE OBJ SIZE? SLABS OBJ/SLAB CACHE SIZE NAME
298953? 80291? 26%??? 0.06K?? 5067?????? 59???? 20268K size-64
134976 101836? 75%??? 0.10K?? 3648?????? 37???? 14592K buffer_head
77418? 61207? 79%??? 0.17K?? 3519?????? 22???? 14076K vm_area_struct
74382? 57858? 77%??? 0.05K??? 966?????? 77????? 3864K anon_vma_chain
69690? 24347? 34%??? 0.12K?? 2323?????? 30????? 9292K size-128
50624? 14700? 29%??? 0.03K??? 452? ????112????? 1808K size-32
47800? 47800 100%??? 0.19K?? 2390?????? 20????? 9560K dentry
36834? 36834 100%??? 1.02K? 12278??????? 3???? 49112K nfs_inode_cache
33394? 26657? 79%??? 0.06K??? 566?????? 59????? 2264K anon_vma
21665?? 7895? 36%??? 0.55K?? 3095??????? 7???? 12380K radix_tree_node
19820? 11786? 59%??? 0.19K??? 991?????? 20????? 3964K size-192
15040? 10977? 72%??? 0.19K??? 752?????? 20????? 3008K filp
12883?? 7901? 61%??? 0.30K??? 991?????? 13????? 3964K nf_conntrack_ffffffff817fdd80
12096? 12052? 99%??? 0.08K??? 252?????? 48????? 1008K sysfs_dir_cache
? 5250?? 4043? 77%??? 0.25K??? 350?????? 15????? 1400K ip_dst_cache
? 5115?? 3150? 61%??? 0.25K??? 341?????? 15????? 1364K tw_sock_TCP
? 4130?? 2219? 53%??? 0.06K???? 70?????? 59?????? 280K tcp_bind_bucket
? 4120?? 3481? 84%??? 0.19K??? 206?????? 20?????? 824K inet_peer_cache
? 3990?? 3987? 99%??? 0.79K??? 798??????? 5????? 3192K ext3_inode_cache
? 3975?? 3909? 98%??? 0.07K???? 75?????? 53?????? 300K Acpi-Operand
? 2852?? 2808? 98%??? 0.04K???? 31?????? 92?????? 124K Acpi-Namespace
? 2740?? 1849? 67%??? 0.19K??? 137?????? 20?????? 548K cred_jar
? 2332?? 1784? 76%??? 0.07K???? 44?????? 53?????? 176K eventpoll_pwq
? 2310?? 1765? 76%??? 0.12K???? 77?????? 30?????? 308K eventpoll_epi
? 2055?? 1181? 57%??? 0.25K??? 137?????? 15?????? 548K skbuff_head_cache
? 1986?? 1899? 95%??? 0.64K??? 331??????? 6????? 1324K proc_inode_cache
T24gVGh1LCAyMDEyLTAzLTAxIGF0IDA4OjUyICswODAwLCBTdGV2ZW4gV2lsdG9uIHdyb3RlOg0K
PiBIaSwNCj4gDQo+IEkndmUgYmVlbiB0cnlpbmcgdG8gdHJhY2sgZG93biBhbiBpc3N1ZSB3ZSd2
ZSBzdGFydGVkIHNlZWluZyBvbiBhIGJ1bmNoIG9mIE5GUyBjbGllbnRzIHdoZXJlIHRoZSBwZXJj
ZW50YWdlIG9mIENQVSB0aW1lIHNwZW50IGJ5IHRoZSBzeXN0ZW0gaGFzIGluY3JlYXNlZCBmb3Ig
dGhlIHBhc3QgbW9udGggKGl0IHdhcyBwcmV2aW91c2x5IHVzaW5nIHJvdWdobHkgZXF1YWwgc3lz
dGVtL3VzZXIgdGltZSwgd2hpbGUgbm93IHRoZSBzeXN0ZW0gdGltZSBpcyBhcm91bmQgM3ggdGhl
IHVzZXIgdGltZSkuICBUaGUgaW5mb3JtYXRpb24gdGhhdCBJIGhhdmUgaXMgYXMgZm9sbG93czoN
Cj4gDQo+IC0gQWZ0ZXIgcmVib290aW5nIHRoZSBzZXJ2ZXIsIHRoZSB1c2VyL3N5c3RlbSBDUFUg
dGltZXMgbG9vayBnb29kIChyb3VnaGx5IGVxdWFsKQ0KPiAtIEFmdGVyIDI0IGhvdXJzIG9mIGhl
YXZ5IGFjdGl2aXR5IHRoZSBzeXN0ZW0gQ1BVIHRpbWUgaW5jcmVhc2VzIHRvIGFyb3VuZCAzLTR4
IHRoZSB1c2VyIENQVSB0aW1lDQo+IC0gSWYgSSBydW4gImVjaG8gMiA+IC9wcm9jL3N5cy92bS9k
cm9wX2NhY2hlcyIgdGhlIHN5c3RlbSBDUFUgdGltZSBkcm9wcyBiYWNrIGRvd24gdG8gcm91Z2hs
eSB0aGUgc2FtZSBhcyB1c2VyDQo+IA0KPiBUaGUgbWFpbiBkaWZmZXJlbmNlIHRoYXQgSSBjYW4g
c2VlIGluIHNsYWJ0b3AgYmV0d2VlbiBhIHN5c3RlbSBydW5uaW5nIGF0IGhpZ2ggbG9hZCBhbmQg
Im5vcm1hbCIgbG9hZCBpcyB0aGUgbnVtYmVyIG9mIG5mc19pbm9kZV9jYWNoZSBvYmplY3RzIChh
cyBzaG93biBiZWxvdykuICBJIHRyaWVkIHRvIGluY3JlYXNlIHRoZSBpaGFzaF9lbnRyaWVzIGFu
ZCBkaGFzaF9lbnRyaWVzIGtlcm5lbCBwYXJhbWV0ZXJzLCBidXQgdGhpcyBkaWQgbm90IGZpeCB0
aGUgcHJvYmxlbS4gIEkgaGF2ZSBub3QgZm91bmQgYW55IG90aGVyIHN1Z2dlc3Rpb25zIG9uIGhv
dyB0byByZXNvbHZlIGlzc3VlcyBjYXVzZWQgYnkgbGFyZ2UgbmZzIGlub2RlIGNhY2hlcy4NCj4g
DQo+IEkgaGF2ZSB0cmllZCB2YXJpb3VzIGtlcm5lbHMgYmV0d2VlbiAzLjAuMCBhbmQgMy4yLjQs
IGFuZCB0aGUgbWFjaGluZXMgYXJlIGN1cnJlbnRseSBydW5uaW5nIGEgMy4wLjIyIGtlcm5lbC4g
IFRoZSBtYWNoaW5lcyBoYXZlIDhHQiBSQU0sIGFuZCBoYXZlIDMgTkZTdjQgbW91bnRzIGFuZCBv
bmUgTkZTdjMgbW91bnQgKHdpdGggdGhlIG1ham9yaXR5IG9mIHRoZSBmaWxlcyB0aGF0IHRoZXkg
YWNjZXNzIGJlaW5nIG9uIG9uZSBvZiB0aGUgTkZTdjQgbW91bnQgcG9pbnRzLCBiZWluZyBhIG1h
aWxkaXIgc3R5bGUgbWFpbCBzcG9vbCkuDQo+IA0KPiBJIGhhdmUgaW5jcmVhc2VkIC9wcm9jL3N5
cy92bS92ZnNfY2FjaGVfcHJlc3N1cmUgdG8gMTAwMDAsIHdoaWNoIGhhcyByZXNvbHZlZCB0aGUg
cHJvYmxlbSBmb3Igbm93LCBob3dldmVyIEkgYmVsaWV2ZSB0aGF0IHRoZSByZWFzb24gd2Ugc3Rh
cnRlZCBzZWVpbmcgdGhlIGlzc3VlIGlzIHRoYXQgd2UgYWRkZWQgYSBsb3Qgb2YgZXh0cmEgdXNl
cnMgb250byB0aGUgc3lzdGVtLCByZXN1bHRpbmcgaW4gYWNjZXNzIHRvIGEgbGFyZ2VyIG51bWJl
ciBvZiBmaWxlcyBmb3IgZWFjaCBvZiB0aGUgY2xpZW50cy4gIEkgYW0gbm90IGNvbmZpZGVudCB0
aGF0IGZ1dHVyZSBncm93dGggd2lsbCBzdGF5IGJlbG93IHdoYXRldmVyIHRocmVzaG9sZCB3ZSBo
YWQgZXhjZWVkZWQgdG8gY2F1c2UgdGhlIGV4Y2Vzc2l2ZSBzeXN0ZW0gQ1BVIGxvYWQsIHNpbmNl
IHRoZSBwcm9ibGVtIHNlZW1lZCB0byBhcHBlYXIgYXQgYXJvdW5kIDEsMDAwLDAwMCBuZnNfaW5v
ZGVfY2FjaGUgZW50cmllcyBpbiBzbGFidG9wLCBhbmQgdGhlIE5GUyBjbGllbnRzIGFyZSBmbG9h
dGluZyBiZXR3ZWVuIDUwMCwwMDAgYW5kIDkwMCwwMDAgaW5vZGVfY2FjaGUgZW50cmllcy4NCj4g
DQo+IEhlbHAgcGxlYXNlIDopLCBhbmQgcGxlYXNlIGxldCBtZSBrbm93IGlmIEkgY2FuIHByb3Zp
ZGUgYW55IG1vcmUgaW5mb3JtYXRpb24gdG8gYXNzaXN0IGluIGRlYnVnZ2luZy4NCg0KVGhpcyBs
b29rcyBsaWtlIG1vcmUgb2YgYSBwcm9ibGVtIGZvciB0aGUgbWVtb3J5IG1hbmFnZW1lbnQgZm9s
a3MgcmF0aGVyDQp0aGFuIHRoZSBORlMgdGVhbS4gVGhlIE5GUyBjbGllbnQgaGFzIHZlcnkgbGlt
aXRlZCBjb250cm9sIG92ZXIgdGhlDQpjYWNoaW5nIG9mIGlub2Rlcy4NCg0KT25lIHRoaW5nIHRo
YXQgeW91IG1pZ2h0IHRyeSBkb2luZyBpcyB0dXJuaW5nIG9mZiByZWFkZGlycGx1cyAodXNpbmcg
dGhlDQotb25vcmRpcnBsdXMgbW91bnQgb3B0aW9uKSBhbmQgc2VlaW5nIGlmIHRoYXQgY2F1c2Vz
IGZld2VyIGlub2RlcyB0byBiZQ0KY3JlYXRlZCBpbiB0aGUgZmlyc3QgcGxhY2UuDQoNCkNoZWVy
cw0KICBUcm9uZA0KLS0gDQpUcm9uZCBNeWtsZWJ1c3QNCkxpbnV4IE5GUyBjbGllbnQgbWFpbnRh
aW5lcg0KDQpOZXRBcHANClRyb25kLk15a2xlYnVzdEBuZXRhcHAuY29tDQp3d3cubmV0YXBwLmNv
bQ0KDQo=