[Opendnssec-develop] Test the new sorter

Rick Zijlker rick.zijlker at sidn.nl
Mon Feb 1 14:17:13 UTC 2010 

Hey Björn,

Unfortunately I cannot supply a copy of the file I tested with. It's the .nl zone.

I did enable the debug output. Apparently it runs out of memory. The test server has 16 GB's of RAM. I believe the logging below shows the entire 'kill'. If not, please let me know.

Cheers,
Rick




Feb  1 14:40:34 signer1 kernel: automount invoked oom-killer: gfp_mask=0x200d2, order=0, oomkilladj=0
Feb  1 14:40:34 signer1 kernel:
Feb  1 14:40:34 signer1 kernel: Call Trace:
Feb  1 14:40:34 signer1 kernel:  [<ffffffff800c6071>] out_of_memory+0x8e/0x2f3
Feb  1 14:40:34 signer1 kernel:  [<ffffffff8002e2e3>] __wake_up+0x38/0x4f
Feb  1 14:40:34 signer1 kernel:  [<ffffffff8000f487>] __alloc_pages+0x245/0x2ce
Feb  1 14:40:34 signer1 kernel:  [<ffffffff80032759>] read_swap_cache_async+0x45/0xd8
Feb  1 14:40:34 signer1 kernel:  [<ffffffff8009fc36>] wake_bit_function+0x0/0x23
Feb  1 14:40:34 signer1 kernel:  [<ffffffff800cbd2c>] swapin_readahead+0x60/0xd3
Feb  1 14:40:34 signer1 kernel:  [<ffffffff8000925e>] __handle_mm_fault+0xacc/0xf99
Feb  1 14:40:34 signer1 kernel:  [<ffffffff80066b25>] do_page_fault+0x4cb/0x830
Feb  1 14:40:34 signer1 kernel:  [<ffffffff8005dde9>] error_exit+0x0/0x84
Feb  1 14:40:34 signer1 kernel:
Feb  1 14:40:34 signer1 kernel: Mem-info:
Feb  1 14:40:34 signer1 kernel: Node 0 DMA per-cpu:
Feb  1 14:40:34 signer1 kernel: cpu 0 hot: high 0, batch 1 used:0
Feb  1 14:40:34 signer1 kernel: cpu 0 cold: high 0, batch 1 used:0
Feb  1 14:40:34 signer1 kernel: cpu 1 hot: high 0, batch 1 used:0
Feb  1 14:40:34 signer1 kernel: cpu 1 cold: high 0, batch 1 used:0
Feb  1 14:40:34 signer1 kernel: cpu 2 hot: high 0, batch 1 used:0
Feb  1 14:40:34 signer1 kernel: cpu 2 cold: high 0, batch 1 used:0
Feb  1 14:40:34 signer1 kernel: cpu 3 hot: high 0, batch 1 used:0
Feb  1 14:40:34 signer1 kernel: cpu 3 cold: high 0, batch 1 used:0
Feb  1 14:40:34 signer1 kernel: cpu 4 hot: high 0, batch 1 used:0
Feb  1 14:40:34 signer1 kernel: cpu 4 cold: high 0, batch 1 used:0
Feb  1 14:40:34 signer1 kernel: cpu 5 hot: high 0, batch 1 used:0
Feb  1 14:40:34 signer1 kernel: cpu 5 cold: high 0, batch 1 used:0
Feb  1 14:40:35 signer1 kernel: cpu 6 hot: high 0, batch 1 used:0
Feb  1 14:40:35 signer1 kernel: cpu 6 cold: high 0, batch 1 used:0
Feb  1 14:40:35 signer1 kernel: cpu 7 hot: high 0, batch 1 used:0
Feb  1 14:40:35 signer1 kernel: cpu 7 cold: high 0, batch 1 used:0
Feb  1 14:40:35 signer1 kernel: Node 0 DMA32 per-cpu:
Feb  1 14:40:35 signer1 kernel: cpu 0 hot: high 186, batch 31 used:25
Feb  1 14:40:35 signer1 kernel: cpu 0 cold: high 62, batch 15 used:43
Feb  1 14:40:35 signer1 kernel: cpu 1 hot: high 186, batch 31 used:0
Feb  1 14:40:35 signer1 kernel: cpu 1 cold: high 62, batch 15 used:0
Feb  1 14:40:35 signer1 kernel: cpu 2 hot: high 186, batch 31 used:30
Feb  1 14:40:35 signer1 kernel: cpu 2 cold: high 62, batch 15 used:47
Feb  1 14:40:35 signer1 kernel: cpu 3 hot: high 186, batch 31 used:0
Feb  1 14:40:35 signer1 kernel: cpu 3 cold: high 62, batch 15 used:0
Feb  1 14:40:35 signer1 kernel: cpu 4 hot: high 186, batch 31 used:35
Feb  1 14:40:35 signer1 kernel: cpu 4 cold: high 62, batch 15 used:58
Feb  1 14:40:35 signer1 kernel: cpu 5 hot: high 186, batch 31 used:0
Feb  1 14:40:35 signer1 kernel: cpu 5 cold: high 62, batch 15 used:0
Feb  1 14:40:35 signer1 kernel: cpu 6 hot: high 186, batch 31 used:17
Feb  1 14:40:35 signer1 kernel: cpu 6 cold: high 62, batch 15 used:51
Feb  1 14:40:35 signer1 kernel: cpu 7 hot: high 186, batch 31 used:0
Feb  1 14:40:35 signer1 kernel: cpu 7 cold: high 62, batch 15 used:0
Feb  1 14:40:35 signer1 kernel: Node 0 Normal per-cpu:
Feb  1 14:40:35 signer1 kernel: cpu 0 hot: high 186, batch 31 used:3
Feb  1 14:40:35 signer1 kernel: cpu 0 cold: high 62, batch 15 used:42
Feb  1 14:40:35 signer1 kernel: cpu 1 hot: high 186, batch 31 used:0
Feb  1 14:40:35 signer1 kernel: cpu 1 cold: high 62, batch 15 used:0
Feb  1 14:40:35 signer1 kernel: cpu 2 hot: high 186, batch 31 used:13
Feb  1 14:40:36 signer1 kernel: cpu 2 cold: high 62, batch 15 used:14
Feb  1 14:40:36 signer1 kernel: cpu 3 hot: high 186, batch 31 used:0
Feb  1 14:40:36 signer1 kernel: cpu 3 cold: high 62, batch 15 used:0
Feb  1 14:40:36 signer1 kernel: cpu 4 hot: high 186, batch 31 used:123
Feb  1 14:40:36 signer1 kernel: cpu 4 cold: high 62, batch 15 used:46
Feb  1 14:40:36 signer1 kernel: cpu 5 hot: high 186, batch 31 used:0
Feb  1 14:40:36 signer1 kernel: cpu 5 cold: high 62, batch 15 used:0
Feb  1 14:40:36 signer1 kernel: cpu 6 hot: high 186, batch 31 used:18
Feb  1 14:40:36 signer1 kernel: cpu 6 cold: high 62, batch 15 used:14
Feb  1 14:40:36 signer1 kernel: cpu 7 hot: high 186, batch 31 used:0
Feb  1 14:40:36 signer1 kernel: cpu 7 cold: high 62, batch 15 used:0
Feb  1 14:40:36 signer1 kernel: Node 0 HighMem per-cpu: empty
Feb  1 14:40:36 signer1 kernel: Node 1 DMA per-cpu: empty
Feb  1 14:40:36 signer1 kernel: Node 1 DMA32 per-cpu: empty
Feb  1 14:40:36 signer1 kernel: Node 1 Normal per-cpu:
Feb  1 14:40:36 signer1 kernel: cpu 0 hot: high 186, batch 31 used:0
Feb  1 14:40:36 signer1 kernel: cpu 0 cold: high 62, batch 15 used:0
Feb  1 14:40:36 signer1 kernel: cpu 1 hot: high 186, batch 31 used:145
Feb  1 14:40:36 signer1 kernel: cpu 1 cold: high 62, batch 15 used:57
Feb  1 14:40:36 signer1 kernel: cpu 2 hot: high 186, batch 31 used:0
Feb  1 14:40:36 signer1 kernel: cpu 2 cold: high 62, batch 15 used:0
Feb  1 14:40:36 signer1 kernel: cpu 3 hot: high 186, batch 31 used:17
Feb  1 14:40:36 signer1 kernel: cpu 3 cold: high 62, batch 15 used:60
Feb  1 14:40:36 signer1 kernel: cpu 4 hot: high 186, batch 31 used:30
Feb  1 14:40:36 signer1 kernel: cpu 4 cold: high 62, batch 15 used:0
Feb  1 14:40:36 signer1 kernel: cpu 5 hot: high 186, batch 31 used:5
Feb  1 14:40:36 signer1 kernel: cpu 5 cold: high 62, batch 15 used:12
Feb  1 14:40:36 signer1 kernel: cpu 6 hot: high 186, batch 31 used:0
Feb  1 14:40:36 signer1 kernel: cpu 6 cold: high 62, batch 15 used:0
Feb  1 14:40:36 signer1 kernel: cpu 7 hot: high 186, batch 31 used:2
Feb  1 14:40:36 signer1 kernel: cpu 7 cold: high 62, batch 15 used:38
Feb  1 14:40:36 signer1 kernel: Node 1 HighMem per-cpu: empty
Feb  1 14:40:36 signer1 kernel: Free pages:       45216kB (0kB HighMem)
Feb  1 14:40:36 signer1 kernel: Active:2425862 inactive:1416219 dirty:0 writeback:0 unstable:0 free:11304 slab:5420 mapped-file:1543 mapped-anon:3840679 pagetables:240708
Feb  1 14:40:36 signer1 kernel: Node 0 DMA free:10880kB min:8kB low:8kB high:12kB active:0kB inactive:0kB present:10500kB pages_scanned:0 all_unreclaimable? yes
Feb  1 14:40:36 signer1 kernel: lowmem_reserve[]: 0 3502 8047 8047
Feb  1 14:40:36 signer1 kernel: Node 0 DMA32 free:21644kB min:3528kB low:4408kB high:5292kB active:1746380kB inactive:1572836kB present:3586464kB pages_scanned:7384686 all_unreclaimable? yes
Feb  1 14:40:36 signer1 kernel: lowmem_reserve[]: 0 0 4545 4545
Feb  1 14:40:36 signer1 kernel: Node 0 Normal free:4552kB min:4576kB low:5720kB high:6864kB active:2193936kB inactive:2097072kB present:4654080kB pages_scanned:8441309 all_unreclaimable? yes
Feb  1 14:40:36 signer1 kernel: lowmem_reserve[]: 0 0 0 0
Feb  1 14:40:36 signer1 kernel: Node 0 HighMem free:0kB min:128kB low:128kB high:128kB active:0kB inactive:0kB present:0kB pages_scanned:0 all_unreclaimable? no
Feb  1 14:40:36 signer1 kernel: lowmem_reserve[]: 0 0 0 0
Feb  1 14:40:36 signer1 kernel: Node 1 DMA free:0kB min:0kB low:0kB high:0kB active:0kB inactive:0kB present:0kB pages_scanned:0 all_unreclaimable? no
Feb  1 14:40:36 signer1 kernel: lowmem_reserve[]: 0 0 8080 8080
Feb  1 14:40:36 signer1 kernel: Node 1 DMA32 free:0kB min:0kB low:0kB high:0kB active:0kB inactive:0kB present:0kB pages_scanned:0 all_unreclaimable? no
Feb  1 14:40:36 signer1 kernel: lowmem_reserve[]: 0 0 8080 8080
Feb  1 14:40:36 signer1 kernel: Node 1 Normal free:8140kB min:8140kB low:10172kB high:12208kB active:5776148kB inactive:1981472kB present:8273920kB pages_scanned:13423603 all_unreclaimable? yes
Feb  1 14:40:36 signer1 kernel: lowmem_reserve[]: 0 0 0 0
Feb  1 14:40:36 signer1 kernel: Node 1 HighMem free:0kB min:128kB low:128kB high:128kB active:0kB inactive:0kB present:0kB pages_scanned:0 all_unreclaimable? no
Feb  1 14:40:36 signer1 kernel: lowmem_reserve[]: 0 0 0 0
Feb  1 14:40:36 signer1 kernel: Node 0 DMA: 4*4kB 2*8kB 2*16kB 4*32kB 3*64kB 2*128kB 0*256kB 0*512kB 2*1024kB 0*2048kB 2*4096kB = 10880kB
Feb  1 14:40:36 signer1 kernel: Node 0 DMA32: 3*4kB 0*8kB 0*16kB 2*32kB 1*64kB 0*128kB 0*256kB 0*512kB 1*1024kB 0*2048kB 5*4096kB = 21644kB
Feb  1 14:40:36 signer1 kernel: Node 0 Normal: 2*4kB 10*8kB 1*16kB 1*32kB 1*64kB 2*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 1*4096kB = 4552kB
Feb  1 14:40:36 signer1 kernel: Node 0 HighMem: empty
Feb  1 14:40:36 signer1 kernel: Node 1 DMA: empty
Feb  1 14:40:36 signer1 kernel: Node 1 DMA32: empty
Feb  1 14:40:36 signer1 kernel: Node 1 Normal: 3*4kB 4*8kB 4*16kB 1*32kB 1*64kB 2*128kB 0*256kB 1*512kB 1*1024kB 1*2048kB 1*4096kB = 8140kB
Feb  1 14:40:36 signer1 kernel: Node 1 HighMem: empty
Feb  1 14:40:36 signer1 kernel: 2181 pagecache pages
Feb  1 14:40:36 signer1 kernel: Swap cache: add 12583314, delete 12583048, find 2552/3863, race 1+2
Feb  1 14:40:36 signer1 kernel: Free swap  = 0kB
Feb  1 14:40:37 signer1 kernel: Total swap = 16779884kB
Feb  1 14:40:37 signer1 kernel: Free swap:            0kB
Feb  1 14:40:37 signer1 kernel: 4325375 pages of RAM
Feb  1 14:40:37 signer1 kernel: 216985 reserved pages
Feb  1 14:40:37 signer1 kernel: 3859 pages shared
Feb  1 14:40:37 signer1 kernel: 491 pages swap cached
Feb  1 14:40:37 signer1 kernel: Out of memory: Killed process 20064 (quicksorter).





-----Original Message-----
From: Björn Stenberg [mailto:bjorn at haxx.se] 
Sent: maandag 1 februari 2010 13:43
To: Rick Zijlker
Cc: Rickard Bellgrim; Opendnssec-develop at lists.opendnssec.org
Subject: Re: [Opendnssec-develop] Test the new sorter

Rick Zijlker wrote:
> The quicksorter keeps getting killed

Interesting. The time signature suggests it spent considerable time swapping memory to disk. That certainly sounds like a bug in quicksorter.

Try changing line 50 to "#if 1" to enable some debug output.

Is there any way I can get a copy of a file that triggers this behaviour?

-- 
Björn

More information about the Opendnssec-develop mailing list