[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
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:
quoted
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.
quoted
[ 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.
quoted
[ 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
On 06.06.2016 05:57, Herbert Xu wrote:
On Sat, Jun 04, 2016 at 09:35:27AM +0200, Phil Sutter wrote:
quoted
[Cc'ing other interested parties, therefore full-quoting.]
Hi Helge,
On Fri, Jun 03, 2016 at 10:22:26PM +0200, Helge Deller wrote:
quoted
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
On 07.06.2016 16:16, Herbert Xu wrote:
On Tue, Jun 07, 2016 at 04:13:50PM +0200, Helge Deller wrote:
quoted
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