* Re: rhashtable - rhashtable_insert_fast failed
[not found] <5751E702.5040909@gmx.de>
@ 2016-06-04 7:35 ` Phil Sutter
2016-06-04 18:05 ` Helge Deller
2016-06-06 3:57 ` Herbert Xu
0 siblings, 2 replies; 8+ messages in thread
From: Phil Sutter @ 2016-06-04 7:35 UTC (permalink / raw)
To: Helge Deller; +Cc: netdev, Herbert Xu, Thomas Graf
[Cc'ing other interested parties, therefore full-quoting.]
Hi Helge,
On Fri, Jun 03, 2016 at 10:22:26PM +0200, Helge Deller wrote:
> Hi Phil,
>
> I'm testing 4.7.0-rc1-64bit on a parisc/hppa machine and get
> those message with CONFIG_TEST_RHASHTABLE=y.
>
> Is this expected/normal ?
No, this shouldn't happen. Can you possibly bisect the issue?
Cheers, Phil
>
> Helge
>
> [ 11.004021] Running rhashtable test nelem=8, max_size=0, shrinking=0
> [ 11.060013] Test 00:
> [ 11.181391] Adding 50000 keys
> [ 11.299533] Info: encountered resize
> [ 11.344499] Info: encountered resize
> [ 11.392971] Info: encountered resize
> [ 11.447632] Traversal complete: counted=50628, nelems=50000, entries=50000, table-jumps=3
> [ 11.556024] Test failed: Total count mismatch ^^^
> [ 11.647150] Traversal complete: counted=50000, nelems=50000, entries=50000, table-jumps=0
> [ 11.760022] Deleting 50000 keys
> [ 11.822941] Duration of test: 596000000 ns
> [ 11.876057] Test 01:
> [ 11.919907] Adding 50000 keys
> [ 12.024027] Info: encountered resize
> [ 12.024767] Info: encountered resize
> [ 12.072981] Info: encountered resize
> [ 12.169265] Traversal complete: counted=53763, nelems=50000, entries=50000, table-jumps=3
> [ 12.172021] Test failed: Total count mismatch ^^^
> [ 12.377004] Traversal complete: counted=50000, nelems=50000, entries=50000, table-jumps=0
> [ 12.380022] Deleting 50000 keys
> [ 12.552900] Duration of test: 596000000 ns
> [ 12.556069] Test 02:
> [ 12.650017] Adding 50000 keys
> [ 12.746381] Info: encountered resize
> [ 12.792486] Info: encountered resize
> [ 12.840977] Info: encountered resize
> [ 12.894604] Traversal complete: counted=52831, nelems=50000, entries=50000, table-jumps=3
> [ 13.004025] Test failed: Total count mismatch ^^^
> [ 13.094046] Traversal complete: counted=50000, nelems=50000, entries=50000, table-jumps=0
> [ 13.204022] Deleting 50000 keys
> [ 13.269555] Duration of test: 576000000 ns
> [ 13.324062] Test 03:
> [ 13.366586] Adding 50000 keys
> [ 13.466624] Info: encountered resize
> [ 13.468255] Info: encountered resize
> [ 13.516485] Info: encountered resize
> [ 13.564977] Info: encountered resize
> [ 13.662159] Traversal complete: counted=52381, nelems=50000, entries=50000, table-jumps=4
> [ 13.664022] Test failed: Total count mismatch ^^^
> [ 13.870009] Traversal complete: counted=50000, nelems=50000, entries=50000, table-jumps=0
> [ 13.876015] Deleting 50000 keys
> [ 14.045912] Duration of test: 640000000 ns
> [ 14.048065] Average test time: 602000000
> [ 14.104017] Testing concurrent rhashtable access from 10 threads
> [ 14.537134] thread[6]: rhashtable_insert_fast failed
> [ 14.540722] thread[5]: rhashtable_insert_fast failed
> [ 14.540747] thread[1]: rhashtable_insert_fast failed
> [ 14.540757] thread[3]: rhashtable_insert_fast failed
> [ 14.540767] thread[0]: rhashtable_insert_fast failed
> [ 14.540862] thread[7]: rhashtable_insert_fast failed
> [ 14.540873] thread[9]: rhashtable_insert_fast failed
> [ 14.540874] thread[2]: rhashtable_insert_fast failed
> [ 14.540874] thread[4]: rhashtable_insert_fast failed
> [ 14.676061] Test failed: thread 0 returned: -12
> [ 14.676102] Test failed: thread 1 returned: -12
> [ 14.676120] thread[8]: rhashtable_insert_fast failed
> [ 14.676153] Test failed: thread 2 returned: -12
> [ 14.676176] Test failed: thread 3 returned: -12
> [ 14.676199] Test failed: thread 4 returned: -12
> [ 14.676224] Test failed: thread 5 returned: -12
> [ 15.516892] Test failed: thread 6 returned: -12
> [ 15.644271] Test failed: thread 7 returned: -12
> [ 15.708319] Test failed: thread 8 returned: -12
> [ 15.772074] Test failed: thread 9 returned: -12
> [ 15.832013] Started 10 threads, 10 failed
^ permalink raw reply [flat|nested] 8+ messages in thread
* Re: rhashtable - rhashtable_insert_fast failed
2016-06-04 7:35 ` rhashtable - rhashtable_insert_fast failed Phil Sutter
@ 2016-06-04 18:05 ` Helge Deller
2016-06-06 3:57 ` Herbert Xu
1 sibling, 0 replies; 8+ messages in thread
From: Helge Deller @ 2016-06-04 18:05 UTC (permalink / raw)
To: Phil Sutter, Linux Kernel Network Developers, Herbert Xu,
linux-parisc@vger.kernel.org
Cc: tgraf@suug.ch, Mikulas Patocka
Hi Phil,
On 04.06.2016 09:35, Phil Sutter wrote:
> [Cc'ing other interested parties, therefore full-quoting.]
> On Fri, Jun 03, 2016 at 10:22:26PM +0200, Helge Deller wrote:
>> I'm testing 4.7.0-rc1-64bit on a parisc/hppa machine and get
>> those message with CONFIG_TEST_RHASHTABLE=y.
>>
>> Is this expected/normal ?
>
> No, this shouldn't happen. Can you possibly bisect the issue?
I did some more testing.
>> [ 11.004021] Running rhashtable test nelem=8, max_size=0, shrinking=0
>> [ 11.060013] Test 00:
>> [ 11.181391] Adding 50000 keys
>> [ 11.299533] Info: encountered resize
>> [ 11.344499] Info: encountered resize
>> [ 11.392971] Info: encountered resize
>> [ 11.447632] Traversal complete: counted=50628, nelems=50000, entries=50000, table-jumps=3
>> [ 11.556024] Test failed: Total count mismatch ^^^
I still see this randomly on my boxes.
Still need to check further.
>> [ 11.647150] Traversal complete: counted=50000, nelems=50000, entries=50000, table-jumps=0
>> [ 11.760022] Deleting 50000 keys
>> [ 11.822941] Duration of test: 596000000 ns
>> [ 11.876057] Test 01:
>> [ 11.919907] Adding 50000 keys
>> [ 12.024027] Info: encountered resize
>> [ 12.024767] Info: encountered resize
>> [ 12.072981] Info: encountered resize
>> [ 12.169265] Traversal complete: counted=53763, nelems=50000, entries=50000, table-jumps=3
>> [ 12.172021] Test failed: Total count mismatch ^^^
>> [ 12.377004] Traversal complete: counted=50000, nelems=50000, entries=50000, table-jumps=0
>> [ 12.380022] Deleting 50000 keys
>> [ 12.552900] Duration of test: 596000000 ns
>> [ 12.556069] Test 02:
>> [ 12.650017] Adding 50000 keys
>> [ 12.746381] Info: encountered resize
>> [ 12.792486] Info: encountered resize
>> [ 12.840977] Info: encountered resize
>> [ 12.894604] Traversal complete: counted=52831, nelems=50000, entries=50000, table-jumps=3
>> [ 13.004025] Test failed: Total count mismatch ^^^
>> [ 13.094046] Traversal complete: counted=50000, nelems=50000, entries=50000, table-jumps=0
>> [ 13.204022] Deleting 50000 keys
>> [ 13.269555] Duration of test: 576000000 ns
>> [ 13.324062] Test 03:
>> [ 13.366586] Adding 50000 keys
>> [ 13.466624] Info: encountered resize
>> [ 13.468255] Info: encountered resize
>> [ 13.516485] Info: encountered resize
>> [ 13.564977] Info: encountered resize
>> [ 13.662159] Traversal complete: counted=52381, nelems=50000, entries=50000, table-jumps=4
>> [ 13.664022] Test failed: Total count mismatch ^^^
>> [ 13.870009] Traversal complete: counted=50000, nelems=50000, entries=50000, table-jumps=0
>> [ 13.876015] Deleting 50000 keys
>> [ 14.045912] Duration of test: 640000000 ns
>> [ 14.048065] Average test time: 602000000
>> [ 14.104017] Testing concurrent rhashtable access from 10 threads
>> [ 14.537134] thread[6]: rhashtable_insert_fast failed
>> [ 14.540722] thread[5]: rhashtable_insert_fast failed
>> [ 14.540747] thread[1]: rhashtable_insert_fast failed
>> [ 14.540757] thread[3]: rhashtable_insert_fast failed
>> [ 14.540767] thread[0]: rhashtable_insert_fast failed
>> [ 14.540862] thread[7]: rhashtable_insert_fast failed
>> [ 14.540873] thread[9]: rhashtable_insert_fast failed
>> [ 14.540874] thread[2]: rhashtable_insert_fast failed
>> [ 14.540874] thread[4]: rhashtable_insert_fast failed
>> [ 14.676061] Test failed: thread 0 returned: -12
>> [ 14.676102] Test failed: thread 1 returned: -12
>> [ 14.676120] thread[8]: rhashtable_insert_fast failed
>> [ 14.676153] Test failed: thread 2 returned: -12
>> [ 14.676176] Test failed: thread 3 returned: -12
>> [ 14.676199] Test failed: thread 4 returned: -12
>> [ 14.676224] Test failed: thread 5 returned: -12
>> [ 15.516892] Test failed: thread 6 returned: -12
>> [ 15.644271] Test failed: thread 7 returned: -12
>> [ 15.708319] Test failed: thread 8 returned: -12
>> [ 15.772074] Test failed: thread 9 returned: -12
>> [ 15.832013] Started 10 threads, 10 failed
Those -12 error messages seem to indicate, that there is memory
pressure on my box (ENOMEM), right?
That might be true for parisc right now as reported by Mikulas at
http://www.spinics.net/lists/linux-parisc/msg07066.html
and fixed by this patch:
http://marc.info/?l=linux-mm&m=146468933302010&w=2
which I applied then.
Additionally I enabled the enomem_retry kernel option.
With those changes I get:
[ 71.752666] Testing concurrent rhashtable access from 10 threads
[ 72.548724] 8812 insertions retried after -ENOMEM
[ 72.611804] 8799 insertions retried after -ENOMEM
[ 72.674785] 8906 insertions retried after -ENOMEM
[ 72.737836] 8895 insertions retried after -ENOMEM
[ 72.800804] 9337 insertions retried after -ENOMEM
[ 72.863843] 11122 insertions retried after -ENOMEM
[ 72.927993] 11163 insertions retried after -ENOMEM
[ 72.992219] 11121 insertions retried after -ENOMEM
[ 73.056331] 11011 insertions retried after -ENOMEM
[ 73.120492] 11121 insertions retried after -ENOMEM
[ 73.621555] thread[4]: 8799 insertions retried due to memory pressure
[ 73.709060] thread[5]: 8906 insertions retried due to memory pressure
[ 73.804561] thread[3]: 8895 insertions retried due to memory pressure
[ 73.894631] thread[1]: 9337 insertions retried due to memory pressure
[ 73.988483] thread[0]: 11122 insertions retried due to memory pressure
[ 74.087575] thread[7]: 11163 insertions retried due to memory pressure
[ 74.180283] thread[6]: 11121 insertions retried due to memory pressure
[ 74.276768] thread[2]: 11121 insertions retried due to memory pressure
[ 74.367538] thread[9]: 11011 insertions retried due to memory pressure
[ 74.472908] thread[8]: 8812 insertions retried due to memory pressure
[ 79.281516] Started 10 threads, 0 failed
I'll try to investigate further on this.
Helge
^ permalink raw reply [flat|nested] 8+ messages in thread
* Re: rhashtable - rhashtable_insert_fast failed
2016-06-04 7:35 ` rhashtable - rhashtable_insert_fast failed Phil Sutter
2016-06-04 18:05 ` Helge Deller
@ 2016-06-06 3:57 ` Herbert Xu
2016-06-07 14:13 ` Helge Deller
1 sibling, 1 reply; 8+ messages in thread
From: Herbert Xu @ 2016-06-06 3:57 UTC (permalink / raw)
To: Phil Sutter, Helge Deller, netdev, Thomas Graf
On Sat, Jun 04, 2016 at 09:35:27AM +0200, Phil Sutter wrote:
> [Cc'ing other interested parties, therefore full-quoting.]
>
> Hi Helge,
>
> On Fri, Jun 03, 2016 at 10:22:26PM +0200, Helge Deller wrote:
> > Hi Phil,
> >
> > I'm testing 4.7.0-rc1-64bit on a parisc/hppa machine and get
> > those message with CONFIG_TEST_RHASHTABLE=y.
> >
> > Is this expected/normal ?
>
> No, this shouldn't happen. Can you possibly bisect the issue?
This reminds me that I do still have to tackle the multi-page
kmalloc issue. This may or may not be the problem here. Enabling
warnings at the kmalloc call should be an easy way to check.
Thanks,
--
Email: Herbert Xu <herbert@gondor.apana.org.au>
Home Page: http://gondor.apana.org.au/~herbert/
PGP Key: http://gondor.apana.org.au/~herbert/pubkey.txt
^ permalink raw reply [flat|nested] 8+ messages in thread
* Re: rhashtable - rhashtable_insert_fast failed
2016-06-06 3:57 ` Herbert Xu
@ 2016-06-07 14:13 ` Helge Deller
2016-06-07 14:16 ` Herbert Xu
0 siblings, 1 reply; 8+ messages in thread
From: Helge Deller @ 2016-06-07 14:13 UTC (permalink / raw)
To: Herbert Xu, Phil Sutter, netdev@vger.kernel.org, Thomas Graf
On 06.06.2016 05:57, Herbert Xu wrote:
> On Sat, Jun 04, 2016 at 09:35:27AM +0200, Phil Sutter wrote:
>> [Cc'ing other interested parties, therefore full-quoting.]
>>
>> Hi Helge,
>>
>> On Fri, Jun 03, 2016 at 10:22:26PM +0200, Helge Deller wrote:
>>> Hi Phil,
>>>
>>> I'm testing 4.7.0-rc1-64bit on a parisc/hppa machine and get
>>> those message with CONFIG_TEST_RHASHTABLE=y.
>>>
>>> Is this expected/normal ?
>>
>> No, this shouldn't happen. Can you possibly bisect the issue?
>
> This reminds me that I do still have to tackle the multi-page
> kmalloc issue. This may or may not be the problem here. Enabling
> warnings at the kmalloc call should be an easy way to check.
What warnings do you mean specifically? Some specific CONFIG_ option ?
I enabled a few debug CONFIG options and get:
[ 0.000000] parisc_cache_init: Only equivalent aliasing supported!
[ 0.000000] Memory Ranges:
[ 0.000000] 0) Start 0x0000000000000000 End 0x000000003fffffff Size 1024 MB
[ 0.000000] 1) Start 0x0000000100000000 End 0x00000001ffdfffff Size 4094 MB
[ 0.000000] 2) Start 0x0000004040000000 End 0x00000040ffffffff Size 3072 MB
[ 0.000000] Total Memory: 8190 MB
[ 0.000000] percpu: Embedded 14 pages/cpu @0000000043c64000 s19168 r8192 d29984 u57344
[ 0.000000] SMP: bootstrap CPU ID is 0
[ 0.000000] Built 3 zonelists in Zone order, mobility grouping on. Total pages: 2067975
[ 0.000000] Kernel command line: HOME=/ root=/dev/sda5 pa64_root=sda5 c3k=sda5 c8k_root=sda5 ip=bootp panic_timeout=60 panic=-1 hugepages=100 console=ttyS0 TERM=vt1x
[ 0.000000] log_buf_len individual max cpu contribution: 4096 bytes
[ 0.000000] log_buf_len total cpu_extra contributions: 126976 bytes
[ 0.000000] log_buf_len min size: 131072 bytes
[ 0.000000] log_buf_len: 262144 bytes
[ 0.000000] early log buf free: 127768(97%)
[ 0.000000] PID hash table entries: 4096 (order: 3, 32768 bytes)
[ 0.000000] Dentry cache hash table entries: 1048576 (order: 11, 8388608 bytes)
[ 0.000000] Inode-cache hash table entries: 524288 (order: 10, 4194304 bytes)
[ 0.000000] allocated 16781312 bytes of page_ext
[ 0.000000] Backtrace:
[ 0.000000] [<0000000040313ef4>] __free_pages+0xdc/0xf0
[ 0.000000] [<0000000040112be4>] 0x40112be4
[ 0.000000] [<0000000040119098>] 0x40119098
[ 0.000000] [<0000000040105594>] 0x40105594
[ 0.000000] [<0000000040101458>] 0x40101458
[ 0.000000] [<0000000040213388>] _raw_spin_trylock+0x0/0x58
[ 0.000000]
[ 0.000000]
[ 0.000000] Bad Address (null pointer deref?): Code=15 regs=0000000040e03640 (Addr=80000492b273b000)
[ 0.000000] CPU: 0 PID: 0 Comm: swapper Not tainted 4.7.0-rc2-64bit+ #428
[ 0.000000] task: 0000000040ef08c0 ti: 0000000040e03000 task.ti: 0000000040e03000
[ 0.000000]
[ 0.000000] YZrvWESTHLNXBCVMcbcbcbcbOGFRQPDI
[ 0.000000] PSW: 00001000000001001111101100001110 Not tainted
[ 0.000000] r00-03 000000ff0804fb0e 0000000040d62590 0000000040311328 0000000040e03520
[ 0.000000] r04-07 0000000040cefd90 0000000000000008 00000001437f2000 0000000000000004
[ 0.000000] r08-11 0000000000000000 0000000000000040 0000000000000000 0000000040e10fc0
[ 0.000000] r12-15 00000001437f2020 0000000000000001 0000000000000010 00000001437f9000
[ 0.000000] r16-19 0000000000007000 00000001437f2000 0000000000000009 0000000000000000
[ 0.000000] r20-23 0000000000000001 0000000000000001 0000000000100000 0000000000000cd0
[ 0.000000] r24-27 0000000000000000 00000000001ffcc0 924924924db99c00 0000000040cefd90
[ 0.000000] r28-31 92492492b273b000 0000000040e03610 0000000040e03640 0000000044a6d000
[ 0.000000] sr00-03 0000000000000000 0000000000000000 0000000000000000 0000000000000000
[ 0.000000] sr04-07 0000000000000000 0000000000000000 0000000000000000 0000000000000000
[ 0.000000]
[ 0.000000] IASQ: 0000000000000000 0000000000000000 IAOQ: 0000000040311330 0000000040311334
[ 0.000000] IIR: 0f8010dc ISR: 0000000012492000 IOR: 80000492b273b000
[ 0.000000] CPU: 0 CR30: 0000000040e03000 CR31: ffffffffffffffff
[ 0.000000] ORIG_R28: 0000000040cefd90
[ 0.000000] IAOQ[0]: __free_pages_ok+0x9a0/0xd28
[ 0.000000] IAOQ[1]: __free_pages_ok+0x9a4/0xd28
[ 0.000000] RP(r2): __free_pages_ok+0x998/0xd28
[ 0.000000] Backtrace:
[ 0.000000] [<0000000040313ef4>] __free_pages+0xdc/0xf0
[ 0.000000] [<0000000040112be4>] 0x40112be4
[ 0.000000] [<0000000040119098>] 0x40119098
[ 0.000000] [<0000000040105594>] 0x40105594
[ 0.000000] [<0000000040101458>] 0x40101458
[ 0.000000] [<0000000040213388>] _raw_spin_trylock+0x0/0x58
Helge
^ permalink raw reply [flat|nested] 8+ messages in thread
* Re: rhashtable - rhashtable_insert_fast failed
2016-06-07 14:13 ` Helge Deller
@ 2016-06-07 14:16 ` Herbert Xu
2016-06-07 14:47 ` Helge Deller
0 siblings, 1 reply; 8+ messages in thread
From: Herbert Xu @ 2016-06-07 14:16 UTC (permalink / raw)
To: Helge Deller; +Cc: Phil Sutter, netdev@vger.kernel.org, Thomas Graf
On Tue, Jun 07, 2016 at 04:13:50PM +0200, Helge Deller wrote:
>
> What warnings do you mean specifically? Some specific CONFIG_ option ?
Look for GFP_NOWARN in lib/rhashtable.c and delete it.
Cheers,
--
Email: Herbert Xu <herbert@gondor.apana.org.au>
Home Page: http://gondor.apana.org.au/~herbert/
PGP Key: http://gondor.apana.org.au/~herbert/pubkey.txt
^ permalink raw reply [flat|nested] 8+ messages in thread
* Re: rhashtable - rhashtable_insert_fast failed
2016-06-07 14:16 ` Herbert Xu
@ 2016-06-07 14:47 ` Helge Deller
2016-06-08 2:39 ` Herbert Xu
0 siblings, 1 reply; 8+ messages in thread
From: Helge Deller @ 2016-06-07 14:47 UTC (permalink / raw)
To: Herbert Xu; +Cc: Phil Sutter, netdev@vger.kernel.org, Thomas Graf
On 07.06.2016 16:16, Herbert Xu wrote:
> On Tue, Jun 07, 2016 at 04:13:50PM +0200, Helge Deller wrote:
>>
>> What warnings do you mean specifically? Some specific CONFIG_ option ?
>
> Look for GFP_NOWARN in lib/rhashtable.c and delete it.
Ok, removed it.
It generates a kernel warning:
[ 0.000000] Linux version 4.7.0-rc2-64bit+ (deller@p100.box) (gcc version 4.9.2 20150212 (Red Hat Cross 4.9.2-5) (GCC) ) #429 SMP Tue Jun 7 16:44:43 CEST 2016
[ 0.000000] unwind_init: start = 0x40cbfcb8, end = 0x40d15008, entries = 21813
[ 0.000000] FP[0] enabled: Rev 1 Model 20
[ 0.000000] The 64-bit Kernel has started...
[ 0.000000] Kernel default page size is 4 KB. Huge pages enabled with 1 MB physical and 2 MB virtual size.
[ 0.000000] bootconsole [ttyB0] enabled
[ 0.000000] Initialized PDC Console for debugging.
[ 0.000000] Determining PDC firmware type: 64 bit PAT.
[ 0.000000] model 000088a0 00000491 00000000 00000002 56bc8caf01697bbe 100000f0 00000008 000000b2 000000b2
[ 0.000000] vers 00000301
[ 0.000000] CPUID vers 20 rev 4 (0x00000284)
[ 0.000000] capabilities 0x35
[ 0.000000] model 9000/785/C8000
[ 0.000000] parisc_cache_init: Only equivalent aliasing supported!
[ 0.000000] Memory Ranges:
[ 0.000000] 0) Start 0x0000000000000000 End 0x000000003fffffff Size 1024 MB
[ 0.000000] 1) Start 0x0000000100000000 End 0x00000001ffdfffff Size 4094 MB
[ 0.000000] 2) Start 0x0000004040000000 End 0x00000040ffffffff Size 3072 MB
[ 0.000000] Total Memory: 8190 MB
[ 0.000000] percpu: Embedded 14 pages/cpu @0000000043c60000 s18144 r8192 d31008 u57344
[ 0.000000] SMP: bootstrap CPU ID is 0
[ 0.000000] Built 3 zonelists in Zone order, mobility grouping on. Total pages: 2067975
[ 0.000000] Kernel command line: HOME=/ root=/dev/sda5 pa64_root=sda5 c3k=sda5 c8k_root=sda5 ip=bootp panic_timeout=60 panic=-1 hugepages=100 console=ttyS0 TERM=vt1x
[ 0.000000] log_buf_len individual max cpu contribution: 4096 bytes
[ 0.000000] log_buf_len total cpu_extra contributions: 126976 bytes
[ 0.000000] log_buf_len min size: 131072 bytes
[ 0.000000] log_buf_len: 262144 bytes
[ 0.000000] early log buf free: 127768(97%)
[ 0.000000] PID hash table entries: 4096 (order: 3, 32768 bytes)
[ 0.000000] Dentry cache hash table entries: 1048576 (order: 11, 8388608 bytes)
[ 0.000000] Inode-cache hash table entries: 524288 (order: 10, 4194304 bytes)
[ 0.000000] Memory: 8210068K/8386560K available (8720K kernel code, 3259K rwdata, 1284K rodata, 1024K init, 16148K bss, 176492K reserved, 0K cma-reserved)
[ 0.000000] SLUB: HWalign=16, Order=0-3, MinObjects=0, CPUs=32, Nodes=8
[ 0.000000] Hierarchical RCU implementation.
[ 0.000000] Build-time adjustment of leaf fanout to 64.
[ 0.000000] NR_IRQS:128
[ 0.000000] clocksource: cr16: mask: 0xffffffffffffffff max_cycles: 0xcf914c9718, max_idle_ns: 440795231327 ns
[ 0.000000] Console: colour dummy device 160x64
[ 0.196000] Calibrating delay loop... 1795.07 BogoMIPS (lpj=3590144)
[ 0.260010] pid_max: default: 32768 minimum: 301
[ 0.296333] Mount-cache hash table entries: 16384 (order: 5, 131072 bytes)
[ 0.356020] Mountpoint-cache hash table entries: 16384 (order: 5, 131072 bytes)
[ 0.544764] Brought up 1 CPUs
[ 0.587520] devtmpfs: initialized
[ 0.633614] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645041785100000 ns
[ 0.636234] xor: measuring software checksum speed
[ 0.864013] 8regs : 4355.000 MB/sec
[ 0.956012] 8regs_prefetch: 3824.000 MB/sec
[ 1.052012] 32regs : 3616.000 MB/sec
[ 1.144012] 32regs_prefetch: 3335.000 MB/sec
[ 1.148013] xor: using function: 8regs (4355.000 MB/sec)
[ 1.276455] NET: Registered protocol family 16
[ 1.288884] Searching for devices...
[ 1.492016] Found devices:
[ 1.496019] 1. Crestone Peak Slow at 0xfffffffffe780000 [128] { 0, 0x0, 0x88a, 0x00004 }
[ 1.636015] 2. Crestone Peak Slow at 0xfffffffffe781000 [129] { 0, 0x0, 0x88a, 0x00004 }
[ 1.744015] 3. Memory at 0xfffffffffed08000 [8] { 1, 0x0, 0x0b6, 0x00009 }
[ 1.750399] 4. Pluto BC McKinley Port at 0xfffffffffed00000 [0] { 12, 0x0, 0x880, 0x0000c }
[ 1.944015] 5. Mercury PCI Bridge at 0xfffffffffed20000 [0/0] { 13, 0x0, 0x783, 0x0000a }
[ 2.052016] 6. Mercury PCI Bridge at 0xfffffffffed24000 [0/2] { 13, 0x0, 0x783, 0x0000a }
[ 2.160016] 7. Mercury PCI Bridge at 0xfffffffffed26000 [0/3] { 13, 0x0, 0x783, 0x0000a }
[ 2.268016] 8. Quicksilver AGP Bridge at 0xfffffffffed28000 [0/4] { 13, 0x0, 0x784, 0x0000a }
[ 2.380015] 9. BMC IPMI Mgmt Ctlr at 0xfffffff0f05b0000 [16] { 15, 0x0, 0x004, 0x000c0 }
[ 2.488015] 10. Crestone Peak Core RS-232 at 0xfffffff0f05e0000 [17] { 10, 0x0, 0x076, 0x000ad }
[ 2.604015] 11. Crestone Peak Core RS-232 at 0xfffffff0f05e2000 [18] { 10, 0x0, 0x076, 0x000ad }
[ 2.720014] Enabling PDC_PAT chassis codes support v0.05
<Cpu0> 38000c6400e00000 a0e008101100c000 CC_PAT_ENCODED_FIELD_MAJOR_FWD_PROG
<Cpu0> 36000c6a00e00000 0000000000000420 CC_PAT_DATA_FIELD_MAJOR_FWD_PROG
[ 3.632486] Releasing cpu 1 now, hpa=fffffffffe781000
<Cpu1> 0000099101e00000 0000000000000000 CC_BOOT_OS_RENDEZVOUS
<Cpu1> 0100142901e00000 fffffff0f0e0ac00 CC_CPU_INTRIGUE_LDB
[ 4.076430] CPU(s): 2 out of 2 PA8800 (Mako) at 900.000000 MHz online
[ 4.169071] Setting cache flush threshold to 32768 kB
[ 4.237795] Setting TLB flush threshold to 452 kB
[ 4.432102] SBA found Pluto 2.3 at 0xfffffffffed00000
[ 4.564076] sba_ioc_init_pluto: reserving 512Mb of IOVA space for agpgart
[ 4.668065] Mercury version TR3.2 (0x32) found at 0xfffffffffed20000
[ 4.776028] LBA: lmmio_space [0xffffffff80000000-0xffffffff9fffffff] - new
[ 4.880290] LBA 0:0: PCI host bridge to bus 0000:00
[ 4.888030] pci_bus 0000:00: root bus resource [io 0x0000-0xffff]
[ 4.952024] pci_bus 0000:00: root bus resource [mem 0xffffffff80000000-0xffffffff9fffffff] (bus address [0x80000000-0x9fffffff])
[ 5.036041] pci_bus 0000:00: root bus resource [bus 00-07]
[ 5.264066] Mercury version TR3.2 (0x32) found at 0xfffffffffed24000
[ 5.388266] LBA 0:2: PCI host bridge to bus 0000:40
[ 5.396032] pci_bus 0000:40: root bus resource [io 0x10000-0x1ffff] (bus address [0x0000-0xffff])
[ 5.460021] pci_bus 0000:40: root bus resource [mem 0xffffffffa0000000-0xffffffffafffffff] (bus address [0xa0000000-0xafffffff])
[ 5.576043] pci_bus 0000:40: root bus resource [bus 40-47]
[ 5.808067] Mercury version TR3.2 (0x32) found at 0xfffffffffed26000
[ 5.932300] LBA 0:3: PCI host bridge to bus 0000:60
[ 5.940034] pci_bus 0000:60: root bus resource [io 0x20000-0x2ffff] (bus address [0x0000-0xffff])
[ 6.004022] pci_bus 0000:60: root bus resource [mem 0xffffffffb0000000-0xffffffffbfffffff] (bus address [0xb0000000-0xbfffffff])
[ 6.124039] pci_bus 0000:60: root bus resource [bus 60-67]
[ 6.356068] Quicksilver version TR1.0 (0x10) found at 0xfffffffffed28000
[ 6.468030] LBA: lmmio_space [0xffffffffc0000000-0xffffffffdfffffff] - new
[ 6.572270] LBA 0:4: PCI host bridge to bus 0000:80
[ 6.580031] pci_bus 0000:80: root bus resource [io 0x30000-0x3ffff] (bus address [0x0000-0xffff])
[ 6.644044] pci_bus 0000:80: root bus resource [mem 0xffffffffc0000000-0xffffffffdfffffff] (bus address [0xc0000000-0xdfffffff])
[ 6.764021] pci_bus 0000:80: root bus resource [bus 80-87]
[ 6.916809] iosapic: no IRTE for 0000:80:00.1 (IRQ not connected?)
<Cpu0> 0300108200e00000 0000000000000000 CC_PROCS_ENTRY_IN
<Cpu0> 0300030700e00000 0000000000000000 CC_SYSTEM_STATE_RUNNING_OK
[ 7.072024] powersw: Soft power switch at 0xfffffff0f042e278 enabled.
[ 7.583433] HugeTLB registered 2 MB page size, pre-allocated 100 pages
[ 7.736022] raid6: int64x1 gen() 794 MB/s
[ 7.860078] raid6: int64x1 xor() 387 MB/s
[ 7.984019] raid6: int64x2 gen() 995 MB/s
[ 8.108020] raid6: int64x2 xor() 507 MB/s
[ 8.232060] raid6: int64x4 gen() 1064 MB/s
[ 8.356051] raid6: int64x4 xor() 578 MB/s
[ 8.480050] raid6: int64x8 gen() 847 MB/s
[ 8.604067] raid6: int64x8 xor() 500 MB/s
[ 8.608013] raid6: using algorithm int64x4 gen() 1064 MB/s
[ 8.664013] raid6: .... xor() 578 MB/s, rmw enabled
[ 8.736019] raid6: using intx1 recovery algorithm
[ 8.800276] vgaarb: setting as boot device: PCI:0000:80:00.0
[ 8.804000] vgaarb: device added: PCI:0000:80:00.0,decodes=io+mem,owns=io+mem,locks=none
[ 8.860020] vgaarb: loaded
[ 9.044021] vgaarb: bridge control possible 0000:80:00.0
[ 9.080249] SCSI subsystem initialized
[ 9.151535] usbcore: registered new interface driver usbfs
[ 9.200100] usbcore: registered new interface driver hub
[ 9.274369] usbcore: registered new device driver usb
[ 9.341849] VFS: Disk quotas dquot_6.6.0
[ 9.408118] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes)
[ 9.557155] NET: Registered protocol family 2
[ 9.560903] TCP established hash table entries: 65536 (order: 7, 524288 bytes)
[ 9.616962] TCP bind hash table entries: 65536 (order: 8, 1048576 bytes)
[ 9.713570] TCP: Hash tables configured (established 65536 bind 65536)
[ 9.888046] UDP hash table entries: 4096 (order: 5, 131072 bytes)
[ 9.892236] UDP-Lite hash table entries: 4096 (order: 5, 131072 bytes)
[ 9.972665] NET: Registered protocol family 1
[ 10.258610] Chassis warnings not supported.
[ 10.264193] Performance monitoring counters enabled for Crestone Peak Slow
[ 10.320423] futex hash table entries: 8192 (order: 6, 262144 bytes)
[ 10.413326] workingset: timestamp_bits=58 max_order=21 bucket_order=0
[ 10.590934] fuse init (API version 7.24)
[ 10.648062] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 252)
[ 10.648062] io scheduler noop registered
[ 10.744211] io scheduler cfq registered (default)
[ 10.796028] Running rhashtable test nelem=8, max_size=0, shrinking=0
[ 10.860014] Test 00:
[ 10.981084] Adding 50000 keys
[ 11.092793] Info: encountered resize
[ 11.140488] Info: encountered resize
[ 11.188775] Info: encountered resize
[ 11.240676] Traversal complete: counted=50203, nelems=50000, entries=50000, table-jumps=3
[ 11.348023] Test failed: Total count mismatch ^^^
[ 11.440190] Traversal complete: counted=50000, nelems=50000, entries=50000, table-jumps=0
[ 11.552025] Deleting 50000 keys
[ 11.615540] Duration of test: 592000000 ns
[ 11.672058] Test 01:
[ 11.712580] Adding 50000 keys
[ 11.851248] Info: encountered resize
[ 11.904127] Traversal complete: counted=74577, nelems=50000, entries=50000, table-jumps=1
[ 12.012014] Test failed: Total count mismatch ^^^
[ 12.103710] Traversal complete: counted=50000, nelems=50000, entries=50000, table-jumps=0
[ 12.216024] Deleting 50000 keys
[ 12.279099] Duration of test: 524000000 ns
[ 12.336060] Test 02:
[ 12.376097] Adding 50000 keys
[ 12.486214] Info: encountered resize
[ 12.545793] Traversal complete: counted=82769, nelems=50000, entries=50000, table-jumps=1
[ 12.548102] Test failed: Total count mismatch ^^^
[ 12.746026] Traversal complete: counted=50000, nelems=50000, entries=50000, table-jumps=0
[ 12.752035] Deleting 50000 keys
[ 12.921413] Duration of test: 508000000 ns
[ 12.924059] Test 03:
[ 13.018407] Adding 50000 keys
[ 13.129482] Info: encountered resize
[ 13.176495] Info: encountered resize
[ 13.224956] Info: encountered resize
[ 13.277490] Traversal complete: counted=50997, nelems=50000, entries=50000, table-jumps=3
[ 13.388024] Test failed: Total count mismatch ^^^
[ 13.477015] Traversal complete: counted=50000, nelems=50000, entries=50000, table-jumps=0
[ 13.588026] Deleting 50000 keys
[ 13.652371] Duration of test: 592000000 ns
[ 13.708072] Average test time: 554000000
[ 13.760017] Testing concurrent rhashtable access from 10 threads
[ 14.154764] thread[3]: rhashtable_insert_fast failed
[ 14.158143] ------------[ cut here ]------------
[ 14.158187] WARNING: CPU: 1 PID: 44 at /home/cvs/parisc/git-kernel/linus-linux-2.6/mm/page_alloc.c:3584 __alloc_pages_nodemask+0x28c/0x1188
[ 14.158195] Modules linked in:
[ 14.158207] CPU: 1 PID: 44 Comm: rhashtable_thra Not tainted 4.7.0-rc2-64bit+ #429
[ 14.158215] task: 000000007f78cd00 ti: 000000007efc8000 task.ti: 000000007efc8000
[ 14.158217]
[ 14.158220] YZrvWESTHLNXBCVMcbcbcbcbOGFRQPDI
[ 14.158223] PSW: 00001000000001101111111100001111 Not tainted
[ 14.158229] r00-03 000000ff0806ff0f 0000000040c72e10 000000004030a608 000000007efc8780
[ 14.158235] r04-07 0000000040c4f610 000000000208d020 000000000208d020 000000000000000b
[ 14.158240] r08-11 0000000040e101e0 000000007efc8788 0000000010574328 0000000000000004
[ 14.158246] r12-15 0000000000000000 0000000040cbee10 000000007e000000 0000000040f4f408
[ 14.158251] r16-19 fffffffffffff000 0000000000000001 0000000040c95e10 0000000000000000
[ 14.158257] r20-23 0000000040e0f0a8 00000000000bc9e7 0000000000000101 0000000000000004
[ 14.158262] r24-27 0000000000000000 0000000000000000 0000000040e10fe0 0000000040c4f610
[ 14.158268] r28-31 0000000040e972ad 000000007efc8aa0 000000007efc8960 0000000000000001
[ 14.158273] sr00-03 0000000000000000 0000000000000000 0000000000000000 0000000000000000
[ 14.158278] sr04-07 0000000000000000 0000000000000000 0000000000000000 0000000000000000
[ 14.158281]
[ 14.158285] IASQ: 0000000000000000 0000000000000000 IAOQ: 000000004030a66c 000000004030a670
[ 14.158290] IIR: 03ffe01f ISR: 0000000010040000 IOR: 00000003a5e972ad
[ 14.158294] CPU: 1 CR30: 000000007efc8000 CR31: dcf9aef3f81fe80f
[ 14.158297] ORIG_R28: 0000000000000001
[ 14.158303] IAOQ[0]: __alloc_pages_nodemask+0x28c/0x1188
[ 14.158309] IAOQ[1]: __alloc_pages_nodemask+0x290/0x1188
[ 14.158314] RP(r2): __alloc_pages_nodemask+0x228/0x1188
[ 14.158318] Backtrace:
[ 14.158341] [<0000000040281380>] sched_clock_local+0x60/0x120
[ 14.158356] [<0000000040332ed0>] kmalloc_order+0x40/0xe8
[ 14.158365] [<000000004036fee4>] __kmalloc+0xfc/0x2c0
[ 14.158377] [<00000000406f72ec>] bucket_table_alloc+0x84/0x308
[ 14.158387] [<00000000406f84b8>] rhashtable_insert_rehash+0x90/0x1a0
[ 14.158396] [<00000000406fbf34>] insert_retry.isra.9.constprop.13+0x2a4/0x478
[ 14.158403] [<00000000406fc260>] threadfunc+0x158/0x600
[ 14.158411] [<000000004026e958>] kthread+0x1d0/0x1f8
[ 14.158421] [<0000000040205020>] end_fault_vector+0x20/0xc0
[ 14.158456] [<00000000406e77a4>] memcpy+0x3c/0x58
[ 14.158464] [<00000000406e75c4>] pa_memcpy+0x44/0xb8
[ 14.158471] [<00000000406e77a4>] memcpy+0x3c/0x58
[ 14.158479] [<00000000402c1860>] update_wall_time+0x9e0/0xa60
[ 14.158486] [<00000000402c1eb8>] xtime_update+0xa8/0xc8
[ 14.158494] [<000000004021888c>] timer_interrupt+0x23c/0x278
[ 14.158503] [<00000000402a0c18>] handle_irq_event_percpu+0x238/0x288
[ 14.158505]
[ 14.158529] ---[ end trace b1d2d69d40940990 ]---
[ 14.158537] thread[2]: rhashtable_insert_fast failed
[ 14.158563] thread[0]: rhashtable_insert_fast failed
[ 14.158674] Test failed: thread 0 returned: -12
[ 14.158695] thread[8]: rhashtable_insert_fast failed
[ 14.158705] thread[4]: rhashtable_insert_fast failed
[ 14.158715] thread[6]: rhashtable_insert_fast failed
[ 15.489784] Test failed: thread 2 returned: -12
[ 18.181317] Test failed: thread 3 returned: -12
[ 18.300098] Test failed: thread 4 returned: -12
[ 18.360078] Test failed: thread 6 returned: -12
[ 18.420264] Test failed: thread 8 returned: -12
[ 18.480071] Started 10 threads, 6 failed
^ permalink raw reply [flat|nested] 8+ messages in thread
* Re: rhashtable - rhashtable_insert_fast failed
2016-06-07 14:47 ` Helge Deller
@ 2016-06-08 2:39 ` Herbert Xu
2016-10-02 9:49 ` Helge Deller
0 siblings, 1 reply; 8+ messages in thread
From: Herbert Xu @ 2016-06-08 2:39 UTC (permalink / raw)
To: Helge Deller; +Cc: Phil Sutter, netdev@vger.kernel.org, Thomas Graf
On Tue, Jun 07, 2016 at 04:47:28PM +0200, Helge Deller wrote:
> On 07.06.2016 16:16, Herbert Xu wrote:
> > On Tue, Jun 07, 2016 at 04:13:50PM +0200, Helge Deller wrote:
> >>
> >> What warnings do you mean specifically? Some specific CONFIG_ option ?
> >
> > Look for GFP_NOWARN in lib/rhashtable.c and delete it.
>
> Ok, removed it.
> It generates a kernel warning:
Thanks. This is exactly the problem that I'm yet to fix, namely
we're trying to allocate a hash table that's too big to be done
using physically contiguous memory.
--
Email: Herbert Xu <herbert@gondor.apana.org.au>
Home Page: http://gondor.apana.org.au/~herbert/
PGP Key: http://gondor.apana.org.au/~herbert/pubkey.txt
^ permalink raw reply [flat|nested] 8+ messages in thread
* Re: rhashtable - rhashtable_insert_fast failed
2016-06-08 2:39 ` Herbert Xu
@ 2016-10-02 9:49 ` Helge Deller
0 siblings, 0 replies; 8+ messages in thread
From: Helge Deller @ 2016-10-02 9:49 UTC (permalink / raw)
To: Herbert Xu; +Cc: Phil Sutter, netdev@vger.kernel.org, Thomas Graf
Hi Herbert,
On 08.06.2016 04:39, Herbert Xu wrote:
> On Tue, Jun 07, 2016 at 04:47:28PM +0200, Helge Deller wrote:
>> On 07.06.2016 16:16, Herbert Xu wrote:
>>> On Tue, Jun 07, 2016 at 04:13:50PM +0200, Helge Deller wrote:
>>>>
>>>> What warnings do you mean specifically? Some specific CONFIG_ option ?
>>>
>>> Look for GFP_NOWARN in lib/rhashtable.c and delete it.
>>
>> Ok, removed it.
>> It generates a kernel warning:
>
> Thanks. This is exactly the problem that I'm yet to fix, namely
> we're trying to allocate a hash table that's too big to be done
> using physically contiguous memory.
I'm still seeing this problem with v4.8-rc8
Helge
^ permalink raw reply [flat|nested] 8+ messages in thread
end of thread, other threads:[~2016-10-02 9:49 UTC | newest]
Thread overview: 8+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
[not found] <5751E702.5040909@gmx.de>
2016-06-04 7:35 ` rhashtable - rhashtable_insert_fast failed Phil Sutter
2016-06-04 18:05 ` Helge Deller
2016-06-06 3:57 ` Herbert Xu
2016-06-07 14:13 ` Helge Deller
2016-06-07 14:16 ` Herbert Xu
2016-06-07 14:47 ` Helge Deller
2016-06-08 2:39 ` Herbert Xu
2016-10-02 9:49 ` Helge Deller
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).