On Wed, May 21, 2014 at 11:33 PM, Richard Weinberger <richard.weinberger@xxxxxxxxx> wrote: > Hi! > > My backup server runs CentOS6 with kernel 2.6.32-431.17.1.el6.x86_64. > Many servers copy theirs backups to it. This setups works perfectly > fine since ages. > Today I've configured a new server which runs Kernel 3.12.20 to store > it's backups to the NFS server too. > > The backup file has around 400GiB, after 100GiB the client aborts the > copy job with EIO. > dmesg contains: > ---cut--- > RPC: AUTH_GSS upcall timed out. > Please check user daemon is running. > nfs: server 10.42.0.1 not responding, timed out > nfs: server 10.42.0.1 not responding, timed out > nfs: server 10.42.0.1 not responding, timed out > nfs: server 10.42.0.1 not responding, timed out > ---cut--- > Some times the client reports also a hung task too. > > I'm using vers=4 and tcp. > (Tried also vers=3 with udp and other combinations) > > And now the really strange part, on the NFS server the load increases up to 10. > I see lots of nfsd kernel threads consuming 100% CPU. > *sometimes* even the oom killer triggers on the NFS server. > Like: > ---cut--- > top invoked oom-killer: gfp_mask=0x800d0, order=0, oom_adj=0, oom_score_adj=0 > top cpuset=/ mems_allowed=0 > Pid: 1907, comm: top Not tainted 2.6.32-431.17.1.el6.x86_64 #1 > Call Trace: > [<ffffffff810d0211>] ? cpuset_print_task_mems_allowed+0x91/0xb0 > [<ffffffff811225c0>] ? dump_header+0x90/0x1b0 > [<ffffffff8122761c>] ? security_real_capable_noaudit+0x3c/0x70 > [<ffffffff81122a42>] ? oom_kill_process+0x82/0x2a0 > [<ffffffff8112293e>] ? select_bad_process+0x9e/0x120 > [<ffffffff81122e80>] ? out_of_memory+0x220/0x3c0 > [<ffffffff8112f79f>] ? __alloc_pages_nodemask+0x89f/0x8d0 > [<ffffffff8116e082>] ? kmem_getpages+0x62/0x170 > [<ffffffff8116ec9a>] ? fallback_alloc+0x1ba/0x270 > [<ffffffff8116e6ef>] ? cache_grow+0x2cf/0x320 > [<ffffffff8116ea19>] ? ____cache_alloc_node+0x99/0x160 > [<ffffffff8116f99b>] ? kmem_cache_alloc+0x11b/0x190 > [<ffffffff811f2910>] ? proc_alloc_inode+0x20/0xb0 > [<ffffffff811a5747>] ? alloc_inode+0x27/0xa0 > [<ffffffff811a683b>] ? new_inode+0x2b/0xb0 > [<ffffffff811f45b4>] ? proc_pid_make_inode+0x14/0xb0 > [<ffffffff811f5f11>] ? proc_pident_instantiate+0x21/0xc0 > [<ffffffff811f610e>] ? proc_pident_lookup+0x8e/0xd0 > [<ffffffff811f61aa>] ? proc_tgid_base_lookup+0x1a/0x20 > [<ffffffff811986f5>] ? do_lookup+0x1a5/0x230 > [<ffffffff81199014>] ? __link_path_walk+0x794/0xff0 > [<ffffffff81199b2a>] ? path_walk+0x6a/0xe0 > [<ffffffff81199d3b>] ? filename_lookup+0x6b/0xc0 > [<ffffffff81226076>] ? security_file_alloc+0x16/0x20 > [<ffffffff8119b214>] ? do_filp_open+0x104/0xd20 > [<ffffffff81060aa3>] ? perf_event_task_sched_out+0x33/0x70 > [<ffffffff812824f5>] ? _atomic_dec_and_lock+0x55/0x80 > [<ffffffff811a7ea2>] ? alloc_fd+0x92/0x160 > [<ffffffff811859e9>] ? do_sys_open+0x69/0x140 > [<ffffffff8100c715>] ? math_state_restore+0x45/0x60 > [<ffffffff81185b00>] ? sys_open+0x20/0x30 > [<ffffffff8100b072>] ? system_call_fastpath+0x16/0x1b > Mem-Info: > Node 0 DMA per-cpu: > CPU 0: hi: 0, btch: 1 usd: 0 > CPU 1: hi: 0, btch: 1 usd: 0 > Node 0 DMA32 per-cpu: > CPU 0: hi: 186, btch: 31 usd: 0 > CPU 1: hi: 186, btch: 31 usd: 30 > active_anon:2091 inactive_anon:56 isolated_anon:0 > active_file:208587 inactive_file:215722 isolated_file:32 > unevictable:0 dirty:213512 writeback:481 unstable:0 > free:13225 slab_reclaimable:14428 slab_unreclaimable:10804 > mapped:299 shmem:63 pagetables:444 bounce:0 > Node 0 DMA free:8220kB min:336kB low:420kB high:504kB active_anon:0kB > inactive_anon:0kB active_file:0kB inactive_file:7128kB unevictable:0kB > isolated(anon):0kB isolated(file):0kB present:15276kB mlocked:0kB > dirty:0kB writeback:0kB mapped:0kB shmem:0kB slab_reclaimable:332kB > slab_unreclaimable:0kB kernel_stack:0kB pagetables:0kB unstable:0kB > bounce:0kB writeback_tmp:0kB pages_scanned:42272 all_unreclaimable? > yes > lowmem_reserve[]: 0 1976 1976 1976 > Node 0 DMA32 free:44680kB min:44716kB low:55892kB high:67072kB > active_anon:8364kB inactive_anon:224kB active_file:834348kB > inactive_file:855676kB unevictable:0kB isolated(anon):0kB > isolated(file):256kB present:2024312kB mlocked:0kB dirty:854048kB > writeback:1924kB mapped:1196kB shmem:252kB slab_reclaimable:57380kB > slab_unreclaimable:43216kB kernel_stack:1384kB pagetables:1776kB > unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:9952 > all_unreclaimable? no > lowmem_reserve[]: 0 0 0 0 > Node 0 DMA: 5*4kB 3*8kB 3*16kB 4*32kB 1*64kB 2*128kB 0*256kB 1*512kB > 3*1024kB 2*2048kB 0*4096kB = 8220kB > Node 0 DMA32: 346*4kB 106*8kB 225*16kB 120*32kB 55*64kB 14*128kB > 10*256kB 5*512kB 2*1024kB 1*2048kB 5*4096kB = 44680kB > 424434 total pagecache pages > 0 pages in swap cache > Swap cache stats: add 0, delete 0, find 0/0 > Free swap = 0kB > Total swap = 0kB > 522224 pages RAM > 48677 pages reserved > 426546 pages shared > 31791 pages non-shared > [ pid ] uid tgid total_vm rss cpu oom_adj oom_score_adj name > [ 472] 0 472 2771 274 1 -17 -1000 udevd > [ 1272] 0 1272 6910 148 1 -17 -1000 auditd > [ 1312] 32 1312 4744 137 1 0 0 rpcbind > [ 1338] 29 1338 5837 196 0 0 0 rpc.statd > [ 1350] 0 1350 1173 101 0 0 0 mdadm > [ 1423] 0 1423 6996 254 1 0 0 rpc.mountd > [ 1459] 0 1459 6291 148 0 0 0 rpc.idmapd > [ 1471] 0 1471 126650 252 0 -17 -1000 tgtd > [ 1473] 0 1473 3722 90 0 -17 -1000 tgtd > [ 1557] 0 1557 16652 276 1 -17 -1000 sshd > [ 1565] 38 1565 7680 318 0 0 0 ntpd > [ 1606] 0 1606 29324 235 1 0 0 crond > [ 1621] 0 1621 1016 74 0 0 0 mingetty > [ 1623] 0 1623 1016 74 1 0 0 mingetty > [ 1625] 0 1625 1016 73 0 0 0 mingetty > [ 1627] 0 1627 1016 73 0 0 0 mingetty > [ 1629] 0 1629 1016 73 1 0 0 mingetty > [ 1631] 0 1631 1016 74 1 0 0 mingetty > [ 1638] 0 1638 2770 264 0 -17 -1000 udevd > [ 1639] 0 1639 2770 264 0 -17 -1000 udevd > [ 1889] 0 1889 25090 389 0 0 0 sshd > [ 1891] 500 1891 25090 368 1 0 0 sshd > [ 1892] 500 1892 27076 184 1 0 0 bash > [ 1907] 500 1907 3757 219 0 0 0 top > Out of memory: Kill process 1312 (rpcbind) score 1 or sacrifice child > Killed process 1312, UID 32, (rpcbind) total-vm:18976kB, > anon-rss:248kB, file-rss:300kB > ---cut--- > > or > > ---cut--- > collectd invoked oom-killer: gfp_mask=0x201da, order=0, oom_adj=0, > oom_score_adj=0 > collectd cpuset=/ mems_allowed=0 > Pid: 1596, comm: collectd Not tainted 2.6.32-431.17.1.el6.x86_64 #1 > Call Trace: > [<ffffffff810d0211>] ? cpuset_print_task_mems_allowed+0x91/0xb0 > [<ffffffff811225c0>] ? dump_header+0x90/0x1b0 > [<ffffffff8122761c>] ? security_real_capable_noaudit+0x3c/0x70 > [<ffffffff81122a42>] ? oom_kill_process+0x82/0x2a0 > [<ffffffff81122981>] ? select_bad_process+0xe1/0x120 > [<ffffffff81122e80>] ? out_of_memory+0x220/0x3c0 > [<ffffffff81122438>] ? try_set_zonelist_oom+0xa8/0xe0 > [<ffffffff8112f79f>] ? __alloc_pages_nodemask+0x89f/0x8d0 > [<ffffffff8116769a>] ? alloc_pages_current+0xaa/0x110 > [<ffffffff8111f9b7>] ? __page_cache_alloc+0x87/0x90 > [<ffffffff8111f39e>] ? find_get_page+0x1e/0xa0 > [<ffffffff81120957>] ? filemap_fault+0x1a7/0x500 > [<ffffffff811bea76>] ? __set_page_dirty_buffers+0x46/0xc0 > [<ffffffff81149c84>] ? __do_fault+0x54/0x530 > [<ffffffff8114a257>] ? handle_pte_fault+0xf7/0xb00 > [<ffffffffa0072360>] ? ext4_get_block+0x0/0x120 [ext4] > [<ffffffff8114ae8a>] ? handle_mm_fault+0x22a/0x300 > [<ffffffff8104a8d8>] ? __do_page_fault+0x138/0x480 > [<ffffffff811da055>] ? fcntl_setlk+0x75/0x320 > [<ffffffff8152d73e>] ? do_page_fault+0x3e/0xa0 > [<ffffffff8152aaf5>] ? page_fault+0x25/0x30 > Mem-Info: > Node 0 DMA per-cpu: > CPU 0: hi: 0, btch: 1 usd: 0 > CPU 1: hi: 0, btch: 1 usd: 0 > Node 0 DMA32 per-cpu: > CPU 0: hi: 186, btch: 31 usd: 177 > CPU 1: hi: 186, btch: 31 usd: 40 > active_anon:3664 inactive_anon:56 isolated_anon:0 > active_file:204351 inactive_file:217741 isolated_file:64 > unevictable:8 dirty:215292 writeback:777 unstable:0 > free:13232 slab_reclaimable:14527 slab_unreclaimable:10875 > mapped:631 shmem:63 pagetables:595 bounce:0 > Node 0 DMA free:8220kB min:336kB low:420kB high:504kB active_anon:0kB > inactive_anon:0kB active_file:284kB inactive_file:6844kB > unevictable:0kB isolated(anon):0kB isolated(file):0kB present:15276kB > mlocked:0kB dirty:0kB writeback:0kB mapped:0kB shmem:0kB > slab_reclaimable:332kB slab_unreclaimable:0kB kernel_stack:0kB > pagetables:0kB unstable:0kB bounce:0kB writeback_tmp:0kB > pages_scanned:59200 all_unreclaimable? yes > lowmem_reserve[]: 0 1976 1976 1976 > Node 0 DMA32 free:44708kB min:44716kB low:55892kB high:67072kB > active_anon:14656kB inactive_anon:224kB active_file:817120kB > inactive_file:864120kB unevictable:32kB isolated(anon):0kB > isolated(file):256kB present:2024312kB mlocked:32kB dirty:861168kB > writeback:3108kB mapped:2524kB shmem:252kB slab_reclaimable:57776kB > slab_unreclaimable:43500kB kernel_stack:1552kB pagetables:2380kB > unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:359776 > all_unreclaimable? no > lowmem_reserve[]: 0 0 0 0 > Node 0 DMA: 5*4kB 3*8kB 3*16kB 4*32kB 1*64kB 2*128kB 2*256kB 2*512kB > 2*1024kB 2*2048kB 0*4096kB = 8220kB > Node 0 DMA32: 177*4kB 378*8kB 85*16kB 148*32kB 11*64kB 1*128kB 1*256kB > 2*512kB 2*1024kB 1*2048kB 7*4096kB = 44708kB > 422228 total pagecache pages > 0 pages in swap cache > Swap cache stats: add 0, delete 0, find 0/0 > Free swap = 0kB > Total swap = 0kB > 522224 pages RAM > 48677 pages reserved > 426430 pages shared > 33618 pages non-shared > [ pid ] uid tgid total_vm rss cpu oom_adj oom_score_adj name > [ 472] 0 472 2771 278 1 -17 -1000 udevd > [ 1272] 0 1272 6910 175 1 -17 -1000 auditd > [ 1289] 0 1289 63855 312 0 0 0 rsyslogd > [ 1312] 32 1312 4744 173 0 0 0 rpcbind > [ 1338] 29 1338 5837 261 0 0 0 rpc.statd > [ 1350] 0 1350 1173 135 0 0 0 mdadm > [ 1423] 0 1423 6996 324 0 0 0 rpc.mountd > [ 1459] 0 1459 6291 170 0 0 0 rpc.idmapd > [ 1471] 0 1471 126650 294 0 -17 -1000 tgtd > [ 1473] 0 1473 3722 109 0 -17 -1000 tgtd > [ 1557] 0 1557 16652 279 1 -17 -1000 sshd > [ 1565] 38 1565 7680 383 0 0 0 ntpd > [ 1582] 0 1582 1530 79 1 0 0 collectdmon > [ 1583] 0 1583 271094 1445 1 0 0 collectd > [ 1606] 0 1606 29324 288 0 0 0 crond > [ 1621] 0 1621 1016 140 0 0 0 mingetty > [ 1623] 0 1623 1016 140 1 0 0 mingetty > [ 1625] 0 1625 1016 139 0 0 0 mingetty > [ 1627] 0 1627 1016 139 0 0 0 mingetty > [ 1629] 0 1629 1016 139 1 0 0 mingetty > [ 1631] 0 1631 1016 140 1 0 0 mingetty > [ 1638] 0 1638 2770 266 0 -17 -1000 udevd > [ 1639] 0 1639 2770 266 0 -17 -1000 udevd > [ 1640] 0 1640 25090 467 0 0 0 sshd > [ 1642] 500 1642 25090 384 0 0 0 sshd > [ 1643] 500 1643 27076 366 1 0 0 bash > [ 1659] 500 1659 36362 279 1 0 0 su > [ 1660] 0 1660 27107 424 1 0 0 bash > [ 1705] 0 1705 3757 329 0 0 0 top > Out of memory: Kill process 1289 (rsyslogd) score 1 or sacrifice child > Killed process 1289, UID 0, (rsyslogd) total-vm:255420kB, > anon-rss:580kB, file-rss:668kB > ---cut--- > > If I use the CentOS6 kernel (2.6.32.x) on the NFS client too, > everything works fine. > No timeout, no oom killer and the load on the NFS server is all the > time below 1. > > Looks like 3.12.x can DoS NFS servers. ;-) Just gave 3.15-rc6 a try, it happens here too. If it helps and the issue is not known I can try to find the exact release. -- Thanks, //richard -- To unsubscribe from this list: send the line "unsubscribe linux-nfs" in the body of a message to majordomo@xxxxxxxxxxxxxxx More majordomo info at http://vger.kernel.org/majordomo-info.html
