Bug#820752: nfs-kernel-server: nfs server fails to start: nfds module can not be loaded: failed to allocate reply cache

2016-04-11 Thread J Mo


No special VM settings. The system had an uptime of 17 days.

The hardware is slightly odd, being a Zotac ZBox Nano CI320, which uses 
the Intel N2930, but it's stable and I have not had any other problems 
worth noting.


I upgraded and rebooted to linux-image-4.4.0-1-amd64 and now the issue 
is gone. Not sure if it's because of the fresh reboot or the upgrade.


Thanks Ben



On 4/11/16 20:05, Ben Hutchings wrote:

Control: reassign -1 src:linux 4.3.3-7
Control: severity -1 normal
Control: tag -1 unreproducible moreinfo

On Mon, 2016-04-11 at 17:43 -0700, J Mo wrote:

Package: nfs-kernel-server
Version: 1:1.2.8-9
Severity: grave
Justification: renders package unusable

Relatively new system and I'm trying to get nfsd working, but it fails.

It failed for you, but generally it works.


After looking at journalctl, it seems that the nfsd module can not be loaded:

Apr 11 17:37:50.511723 myhost kernel: Installing knfsd (copyright (C) 1996 
o...@monad.swb.de).
Apr 11 17:37:50.511864 myhost kernel: modprobe: page allocation failure: 
order:4, mode:0x2040d0

That's an allocation of 64 KiB with mode GFP_KERNEL | __GFP_COMP |
__GFP_NOTRACK.

[...]

Apr 11 17:37:50.513675 myhost kernel: Node 0 DMA free:15896kB min:20kB low:24kB 
high:28kB active_anon:0kB inactive_anon:0kB active_file:0kB inactive_file:0kB 
unevictable:0kB isolated(anon):0kB isolated(file):0kB present:15984kB 
managed:15900kB mlocked:0kB dirty:0kB writeback:0kB mapped:0kB shmem:0kB 
slab_reclaimable:4kB slab_unreclaimable:0kB kernel_stack:0kB pagetables:0kB 
unstable:0kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB 
writeback_tmp:0kB pages_scanned:0 all_unreclaimable? yes
Apr 11 17:37:50.513742 myhost kernel: lowmem_reserve[]: 0 2870 7861 7861
Apr 11 17:37:50.513811 myhost kernel: Node 0 DMA32 free:703004kB min:4112kB 
low:5140kB high:6168kB active_anon:13524kB inactive_anon:17448kB 
active_file:500576kB inactive_file:512192kB unevictable:0kB isolated(anon):0kB 
isolated(file):0kB present:3018236kB managed:2942260kB mlocked:0kB dirty:0kB 
writeback:0kB mapped:16376kB shmem:5232kB slab_reclaimable:1151992kB 
slab_unreclaimable:29404kB kernel_stack:1152kB pagetables:4056kB unstable:0kB 
bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB writeback_tmp:0kB 
pages_scanned:0 all_unreclaimable? no
Apr 11 17:37:50.514824 myhost kernel: lowmem_reserve[]: 0 0 4990 4990
Apr 11 17:37:50.514899 myhost kernel: Node 0 Normal free:315912kB min:7152kB 
low:8940kB high:10728kB active_anon:33964kB inactive_anon:21560kB 
active_file:1120576kB inactive_file:1447708kB unevictable:0kB 
isolated(anon):0kB isolated(file):0kB present:5242880kB managed:5110500kB 
mlocked:0kB dirty:16kB writeback:0kB mapped:32176kB shmem:15280kB 
slab_reclaimable:2083336kB slab_unreclaimable:48188kB kernel_stack:1440kB 
pagetables:6980kB unstable:0kB bounce:0kB free_pcp:188kB local_pcp:0kB 
free_cma:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
Apr 11 17:37:50.516638 myhost kernel: lowmem_reserve[]: 0 0 0 0
Apr 11 17:37:50.516721 myhost kernel: Node 0 DMA: 2*4kB (UE) 2*8kB (UE) 2*16kB 
(UE) 1*32kB (E) 3*64kB (UE) 2*128kB (UE) 2*256kB (UE) 1*512kB (E) 2*1024kB (UE) 
2*2048kB (EM) 2*4096kB (M) = 15896kB
Apr 11 17:37:50.516789 myhost kernel: Node 0 DMA32: 105486*4kB (UEM) 32237*8kB 
(UEM) 1411*16kB (UEM) 30*32kB (UEM) 0*64kB 0*128kB 0*256kB 0*512kB 0*1024kB 
0*2048kB 0*4096kB = 703376kB
Apr 11 17:37:50.516856 myhost kernel: Node 0 Normal: 64405*4kB (UEM) 6948*8kB 
(UEM) 161*16kB (UEM) 5*32kB (EM) 0*64kB 0*128kB 0*256kB 0*512kB 0*1024kB 
0*2048kB 0*4096kB = 315940kB
Apr 11 17:37:50.516924 myhost kernel: Node 0 hugepages_total=0 hugepages_free=0 
hugepages_surp=0 hugepages_size=2048kB
Apr 11 17:37:50.516992 myhost kernel: 901921 total pagecache pages
Apr 11 17:37:50.517064 myhost kernel: 1530 pages in swap cache
Apr 11 17:37:50.517128 myhost kernel: Swap cache stats: add 15480, delete 
13950, find 36006575/36008881
Apr 11 17:37:50.517194 myhost kernel: Free swap  = 3874448kB
Apr 11 17:37:50.517257 myhost kernel: Total swap = 3906556kB

[...]

Strange.  The system had lots of RAM and swap available.  The Normal
zone was fragmented so no 64 KiB blocks were immediately available, but
this allocation could have waited for defragmentation if needed.

(Such fragmentation only occurs after the system has been running for
some time, so I'm confident nfsd will successfully load if you try
loading it shortly after booting.)

Do you have any VM settings in /etc/sysctl.conf or /etc/sysctl.d?

Ben.





Bug#820752: nfs-kernel-server: nfs server fails to start: nfds module can not be loaded: failed to allocate reply cache

2016-04-11 Thread Ben Hutchings
Control: reassign -1 src:linux 4.3.3-7
Control: severity -1 normal
Control: tag -1 unreproducible moreinfo

On Mon, 2016-04-11 at 17:43 -0700, J Mo wrote:
> Package: nfs-kernel-server
> Version: 1:1.2.8-9
> Severity: grave
> Justification: renders package unusable
> 
> Relatively new system and I'm trying to get nfsd working, but it fails.

It failed for you, but generally it works.

> After looking at journalctl, it seems that the nfsd module can not be loaded:
> 
> Apr 11 17:37:50.511723 myhost kernel: Installing knfsd (copyright (C) 1996 
> o...@monad.swb.de).
> Apr 11 17:37:50.511864 myhost kernel: modprobe: page allocation failure: 
> order:4, mode:0x2040d0

That's an allocation of 64 KiB with mode GFP_KERNEL | __GFP_COMP |
__GFP_NOTRACK.

[...]
> Apr 11 17:37:50.513675 myhost kernel: Node 0 DMA free:15896kB min:20kB 
> low:24kB high:28kB active_anon:0kB inactive_anon:0kB active_file:0kB 
> inactive_file:0kB unevictable:0kB isolated(anon):0kB isolated(file):0kB 
> present:15984kB managed:15900kB mlocked:0kB dirty:0kB writeback:0kB 
> mapped:0kB shmem:0kB slab_reclaimable:4kB slab_unreclaimable:0kB 
> kernel_stack:0kB pagetables:0kB unstable:0kB bounce:0kB free_pcp:0kB 
> local_pcp:0kB free_cma:0kB writeback_tmp:0kB pages_scanned:0 
> all_unreclaimable? yes
> Apr 11 17:37:50.513742 myhost kernel: lowmem_reserve[]: 0 2870 7861 7861
> Apr 11 17:37:50.513811 myhost kernel: Node 0 DMA32 free:703004kB min:4112kB 
> low:5140kB high:6168kB active_anon:13524kB inactive_anon:17448kB 
> active_file:500576kB inactive_file:512192kB unevictable:0kB 
> isolated(anon):0kB isolated(file):0kB present:3018236kB managed:2942260kB 
> mlocked:0kB dirty:0kB writeback:0kB mapped:16376kB shmem:5232kB 
> slab_reclaimable:1151992kB slab_unreclaimable:29404kB kernel_stack:1152kB 
> pagetables:4056kB unstable:0kB bounce:0kB free_pcp:0kB local_pcp:0kB 
> free_cma:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
> Apr 11 17:37:50.514824 myhost kernel: lowmem_reserve[]: 0 0 4990 4990
> Apr 11 17:37:50.514899 myhost kernel: Node 0 Normal free:315912kB min:7152kB 
> low:8940kB high:10728kB active_anon:33964kB inactive_anon:21560kB 
> active_file:1120576kB inactive_file:1447708kB unevictable:0kB 
> isolated(anon):0kB isolated(file):0kB present:5242880kB managed:5110500kB 
> mlocked:0kB dirty:16kB writeback:0kB mapped:32176kB shmem:15280kB 
> slab_reclaimable:2083336kB slab_unreclaimable:48188kB kernel_stack:1440kB 
> pagetables:6980kB unstable:0kB bounce:0kB free_pcp:188kB local_pcp:0kB 
> free_cma:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
> Apr 11 17:37:50.516638 myhost kernel: lowmem_reserve[]: 0 0 0 0
> Apr 11 17:37:50.516721 myhost kernel: Node 0 DMA: 2*4kB (UE) 2*8kB (UE) 
> 2*16kB (UE) 1*32kB (E) 3*64kB (UE) 2*128kB (UE) 2*256kB (UE) 1*512kB (E) 
> 2*1024kB (UE) 2*2048kB (EM) 2*4096kB (M) = 15896kB
> Apr 11 17:37:50.516789 myhost kernel: Node 0 DMA32: 105486*4kB (UEM) 
> 32237*8kB (UEM) 1411*16kB (UEM) 30*32kB (UEM) 0*64kB 0*128kB 0*256kB 0*512kB 
> 0*1024kB 0*2048kB 0*4096kB = 703376kB
> Apr 11 17:37:50.516856 myhost kernel: Node 0 Normal: 64405*4kB (UEM) 6948*8kB 
> (UEM) 161*16kB (UEM) 5*32kB (EM) 0*64kB 0*128kB 0*256kB 0*512kB 0*1024kB 
> 0*2048kB 0*4096kB = 315940kB
> Apr 11 17:37:50.516924 myhost kernel: Node 0 hugepages_total=0 
> hugepages_free=0 hugepages_surp=0 hugepages_size=2048kB
> Apr 11 17:37:50.516992 myhost kernel: 901921 total pagecache pages
> Apr 11 17:37:50.517064 myhost kernel: 1530 pages in swap cache
> Apr 11 17:37:50.517128 myhost kernel: Swap cache stats: add 15480, delete 
> 13950, find 36006575/36008881
> Apr 11 17:37:50.517194 myhost kernel: Free swap  = 3874448kB
> Apr 11 17:37:50.517257 myhost kernel: Total swap = 3906556kB
[...]

Strange.  The system had lots of RAM and swap available.  The Normal
zone was fragmented so no 64 KiB blocks were immediately available, but
this allocation could have waited for defragmentation if needed.

(Such fragmentation only occurs after the system has been running for
some time, so I'm confident nfsd will successfully load if you try
loading it shortly after booting.)

Do you have any VM settings in /etc/sysctl.conf or /etc/sysctl.d?

Ben.

-- 
Ben Hutchings
This sentence contradicts itself - no actually it doesn't.

signature.asc
Description: This is a digitally signed message part


Processed: Re: Bug#820752: nfs-kernel-server: nfs server fails to start: nfds module can not be loaded: failed to allocate reply cache

2016-04-11 Thread Debian Bug Tracking System
Processing control commands:

> reassign -1 src:linux 4.3.3-7
Bug #820752 [nfs-kernel-server] nfs-kernel-server: nfs server fails to start: 
nfds module can not be loaded: failed to allocate reply cache
Bug reassigned from package 'nfs-kernel-server' to 'src:linux'.
No longer marked as found in versions nfs-utils/1:1.2.8-9.
Ignoring request to alter fixed versions of bug #820752 to the same values 
previously set
Bug #820752 [src:linux] nfs-kernel-server: nfs server fails to start: nfds 
module can not be loaded: failed to allocate reply cache
Marked as found in versions linux/4.3.3-7.
> severity -1 normal
Bug #820752 [src:linux] nfs-kernel-server: nfs server fails to start: nfds 
module can not be loaded: failed to allocate reply cache
Severity set to 'normal' from 'grave'
> tag -1 unreproducible moreinfo
Bug #820752 [src:linux] nfs-kernel-server: nfs server fails to start: nfds 
module can not be loaded: failed to allocate reply cache
Added tag(s) moreinfo and unreproducible.

-- 
820752: http://bugs.debian.org/cgi-bin/bugreport.cgi?bug=820752
Debian Bug Tracking System
Contact ow...@bugs.debian.org with problems



Bug#820752: nfs-kernel-server: nfs server fails to start: nfds module can not be loaded: failed to allocate reply cache

2016-04-11 Thread J Mo
Package: nfs-kernel-server
Version: 1:1.2.8-9
Severity: grave
Justification: renders package unusable

Relatively new system and I'm trying to get nfsd working, but it fails.

After looking at journalctl, it seems that the nfsd module can not be loaded:

Apr 11 17:37:50.511723 myhost kernel: Installing knfsd (copyright (C) 1996 
o...@monad.swb.de).
Apr 11 17:37:50.511864 myhost kernel: modprobe: page allocation failure: 
order:4, mode:0x2040d0
Apr 11 17:37:50.511949 myhost kernel: CPU: 3 PID: 15440 Comm: modprobe Not 
tainted 4.3.0-1-amd64 #1 Debian 4.3.3-7
Apr 11 17:37:50.512036 myhost kernel: Hardware name: Motherboard by ZOTAC 
ZBOX-CI320NANO series/ZBOX-CI320NANO series, BIOS B219P026 05/19/2015
Apr 11 17:37:50.512118 myhost kernel:   2423ca77 
812ddcf9 002040d0
Apr 11 17:37:50.512185 myhost kernel:  81164947 8802362120c0 
002040d0 
Apr 11 17:37:50.512251 myhost kernel:  2423ca77 0004 
2423ca77 8802362120c0
Apr 11 17:37:50.512316 myhost kernel: Call Trace:
Apr 11 17:37:50.512380 myhost kernel:  [] ? 
dump_stack+0x40/0x57
Apr 11 17:37:50.512445 myhost kernel:  [] ? 
warn_alloc_failed+0xf7/0x150
Apr 11 17:37:50.512514 myhost kernel:  [] ? 
__alloc_pages_nodemask+0x2e8/0xa10
Apr 11 17:37:50.512579 myhost kernel:  [] ? 
kmem_getpages+0x5b/0x100
Apr 11 17:37:50.512660 myhost kernel:  [] ? 
fallback_alloc+0x1ae/0x1f0
Apr 11 17:37:50.512728 myhost kernel:  [] ? 
nfsd_reply_cache_init+0xa4/0x100 [nfsd]
Apr 11 17:37:50.512793 myhost kernel:  [] ? 
__kmalloc+0x17c/0x1c0
Apr 11 17:37:50.512862 myhost kernel:  [] ? 
trace_event_define_fields_nfsd_stateid_class+0xab/0xab [nfsd]
Apr 11 17:37:50.512927 myhost kernel:  [] ? 
nfsd_reply_cache_init+0xa4/0x100 [nfsd]
Apr 11 17:37:50.512992 myhost kernel:  [] ? 
init_nfsd+0x4b/0xf55 [nfsd]
Apr 11 17:37:50.513059 myhost kernel:  [] ? 
do_one_initcall+0xb2/0x200
Apr 11 17:37:50.513123 myhost kernel:  [] ? 
do_init_module+0x5b/0x1dc
Apr 11 17:37:50.513195 myhost kernel:  [] ? 
load_module+0x2173/0x2780
Apr 11 17:37:50.513259 myhost kernel:  [] ? 
__symbol_put+0x60/0x60
Apr 11 17:37:50.513323 myhost kernel:  [] ? 
kernel_read+0x4b/0x70
Apr 11 17:37:50.513388 myhost kernel:  [] ? 
SyS_finit_module+0xae/0xe0
Apr 11 17:37:50.513460 myhost kernel:  [] ? 
system_call_fast_compare_end+0xc/0x67
Apr 11 17:37:50.513528 myhost kernel: Mem-Info:
Apr 11 17:37:50.513599 myhost kernel: active_anon:11872 inactive_anon:9752 
isolated_anon:0
 active_file:405288 inactive_file:489975 
isolated_file:0
 unevictable:0 dirty:4 writeback:0 
unstable:0
 slab_reclaimable:808833 
slab_unreclaimable:19398
 mapped:12138 shmem:5128 pagetables:2759 
bounce:0
 free:258703 free_pcp:49 free_cma:0
Apr 11 17:37:50.513675 myhost kernel: Node 0 DMA free:15896kB min:20kB low:24kB 
high:28kB active_anon:0kB inactive_anon:0kB active_file:0kB inactive_file:0kB 
unevictable:0kB isolated(anon):0kB isolated(file):0kB present:15984kB 
managed:15900kB mlocked:0kB dirty:0kB writeback:0kB mapped:0kB shmem:0kB 
slab_reclaimable:4kB slab_unreclaimable:0kB kernel_stack:0kB pagetables:0kB 
unstable:0kB bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB 
writeback_tmp:0kB pages_scanned:0 all_unreclaimable? yes
Apr 11 17:37:50.513742 myhost kernel: lowmem_reserve[]: 0 2870 7861 7861
Apr 11 17:37:50.513811 myhost kernel: Node 0 DMA32 free:703004kB min:4112kB 
low:5140kB high:6168kB active_anon:13524kB inactive_anon:17448kB 
active_file:500576kB inactive_file:512192kB unevictable:0kB isolated(anon):0kB 
isolated(file):0kB present:3018236kB managed:2942260kB mlocked:0kB dirty:0kB 
writeback:0kB mapped:16376kB shmem:5232kB slab_reclaimable:1151992kB 
slab_unreclaimable:29404kB kernel_stack:1152kB pagetables:4056kB unstable:0kB 
bounce:0kB free_pcp:0kB local_pcp:0kB free_cma:0kB writeback_tmp:0kB 
pages_scanned:0 all_unreclaimable? no
Apr 11 17:37:50.514824 myhost kernel: lowmem_reserve[]: 0 0 4990 4990
Apr 11 17:37:50.514899 myhost kernel: Node 0 Normal free:315912kB min:7152kB 
low:8940kB high:10728kB active_anon:33964kB inactive_anon:21560kB 
active_file:1120576kB inactive_file:1447708kB unevictable:0kB 
isolated(anon):0kB isolated(file):0kB present:5242880kB managed:5110500kB 
mlocked:0kB dirty:16kB writeback:0kB mapped:32176kB shmem:15280kB 
slab_reclaimable:2083336kB slab_unreclaimable:48188kB kernel_stack:1440kB 
pagetables:6980kB unstable:0kB bounce:0kB free_pcp:188kB local_pcp:0kB 
free_cma:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
Apr 11 17:37:50.516638 myhost kernel: lowmem_reserve[]: 0 0 0 0
Apr 11 17:37:50.516721 myhost kernel: Node 0 DMA: 2*4kB (UE) 2*8kB (UE) 2*16kB 
(UE) 1*32kB (E) 3*64kB (UE) 2*128kB (UE) 2*256kB (UE) 1*512kB (E) 2*1024kB (UE) 
2*2048kB (EM) 2*4096kB (M) = 15896kB
Apr 11 17:37:50.516789 myhost