failedrequest / netmap

Automatically exported from code.google.com/p/netmap
0 stars 0 forks source link

virtio_net crashes in ubuntu VM after restart of application #55

Open GoogleCodeExporter opened 9 years ago

GoogleCodeExporter commented 9 years ago
What steps will reproduce the problem?
1. netmap compiled with kernel 3.13.1 using virtio_net on virtualbox VM ubuntu 
14.04
2. start application ... stop it
3. start application again (crash vm)

What is the expected output? What do you see instead?
see vm chrash

What version of the product are you using? On what operating system?
latest, ubuntu 14.04 /kernel 3.13.1

Please provide any additional information below.
dmesg:
[  325.444858] 995.134649 [2720] netmap_attach             success for eth2 tx 
1/256 rx 1/256 queues/slots
[  325.444868] 995.134661 [ 571] virtio_netmap_attach      virtio attached 
txq=1, txd=256 rxq=1, rxd=256
[  325.445237] 995.135029 [2720] netmap_attach             success for eth3 tx 
1/256 rx 1/256 queues/slots
[  325.445245] 995.135038 [ 571] virtio_netmap_attach      virtio attached 
txq=1, txd=256 rxq=1, rxd=256
[  325.575316] device eth2 entered promiscuous mode
[  325.587147] device eth3 entered promiscuous mode
[  496.969356] audit_printk_skb: 117 callbacks suppressed
[  496.969360] type=1006 audit(1433755166.655:76): pid=3302 uid=0 old 
auid=4294967295 new auid=1000 old ses=4294967295 new ses=1 res=1
[  502.969406] type=1006 audit(1433755172.655:77): pid=3358 uid=0 old 
auid=4294967295 new auid=1000 old ses=4294967295 new ses=2 res=1
[  544.605612] 214.295403 [ 547] virtio_netmap_config      virtio config txq=1, 
txd=256 rxq=1, rxd=256
[  544.605619] 214.295414 [1207] netmap_mem_global_config  reconfiguring
[  544.631976] wharf: page allocation failure: order:0, mode:0x8020
[  544.631983] CPU: 0 PID: 3436 Comm: wharf Tainted: GF          O 3.13.1 #3
[  544.631985] Hardware name: innotek GmbH VirtualBox/VirtualBox, BIOS 
VirtualBox 12/01/2006
[  544.631988]  0000000000000000 ffff88001812b9d0 ffffffff817048c5 
0000000000008020
[  544.631993]  ffff88001812ba58 ffffffff81150b3b ffff88003ffece28 
0000000000000010
[  544.631997]  0000000000000000 00000000ffffffff 0000000000000001 
ffff88003ffeb000
[  544.632000] Call Trace:
[  544.632010]  [<ffffffff817048c5>] dump_stack+0x45/0x56
[  544.632158]  [<ffffffff81150b3b>] warn_alloc_failed+0xeb/0x140
[  544.632165]  [<ffffffff811552ba>] __alloc_pages_nodemask+0x95a/0xb30
[  544.632172]  [<ffffffff811936f3>] alloc_pages_current+0xa3/0x160
[  544.632180]  [<ffffffffa01ede6b>] netmap_mem_finalize_all+0x10b/0x5b0 
[netmap]
[  544.632186]  [<ffffffffa01ed7bd>] ? netmap_mem_global_config+0xcd/0x120 
[netmap]
[  544.632192]  [<ffffffffa01ee3a8>] netmap_mem_global_finalize+0x58/0x70 
[netmap]
[  544.632197]  [<ffffffffa01ef5f9>] netmap_mem_finalize+0x69/0x1b0 [netmap]
[  544.632213]  [<ffffffffa01f8ffe>] netmap_do_regif+0x9e/0x1f0 [netmap]
[  544.632219]  [<ffffffffa01fa408>] netmap_ioctl+0x468/0x6e0 [netmap]
[  544.632225]  [<ffffffff81172299>] ? __do_fault+0x3d9/0x4e0
[  544.632240]  [<ffffffffa01fb380>] linux_netmap_ioctl+0xb0/0x140 [netmap]
[  544.632246]  [<ffffffff8101a743>] ? native_sched_clock+0x13/0x80
[  544.632251]  [<ffffffff8101a743>] ? native_sched_clock+0x13/0x80
[  544.632264]  [<ffffffff8101a7b9>] ? sched_clock+0x9/0x10
[  544.632271]  [<ffffffff8109aabd>] ? sched_clock_local+0x1d/0x80
[  544.632277]  [<ffffffff811cc240>] do_vfs_ioctl+0x2e0/0x4c0
[  544.632281]  [<ffffffff8109b704>] ? vtime_account_user+0x54/0x60
[  544.632295]  [<ffffffff811cc4a1>] SyS_ioctl+0x81/0xa0
[  544.632300]  [<ffffffff817154ff>] tracesys+0xe1/0xe6
[  544.632303] Mem-Info:
[  544.632306] Node 0 DMA per-cpu:
[  544.632310] CPU    0: hi:    0, btch:   1 usd:   0
[  544.632320] CPU    1: hi:    0, btch:   1 usd:   0
[  544.632323] CPU    2: hi:    0, btch:   1 usd:   0
[  544.632325] CPU    3: hi:    0, btch:   1 usd:   0
[  544.632327] CPU    4: hi:    0, btch:   1 usd:   0
[  544.632330] CPU    5: hi:    0, btch:   1 usd:   0
[  544.632332] CPU    6: hi:    0, btch:   1 usd:   0
[  544.632335] CPU    7: hi:    0, btch:   1 usd:   0
[  544.632337] Node 0 DMA32 per-cpu:
[  544.632348] CPU    0: hi:  186, btch:  31 usd:  48
[  544.632351] CPU    1: hi:  186, btch:  31 usd:  35
[  544.632353] CPU    2: hi:  186, btch:  31 usd: 117
[  544.632355] CPU    3: hi:  186, btch:  31 usd: 173
[  544.632358] CPU    4: hi:  186, btch:  31 usd: 184
[  544.632360] CPU    5: hi:  186, btch:  31 usd:  99
[  544.632363] CPU    6: hi:  186, btch:  31 usd: 108
[  544.632373] CPU    7: hi:  186, btch:  31 usd: 161
[  544.632377] active_anon:61416 inactive_anon:6905 isolated_anon:0
[  544.632377]  active_file:47008 inactive_file:47041 isolated_file:0
[  544.632377]  unevictable:0 dirty:6 writeback:0 unstable:0
[  544.632377]  free:5142 slab_reclaimable:5951 slab_unreclaimable:6044
[  544.632377]  mapped:24384 shmem:451 pagetables:5044 bounce:0
[  544.632377]  free_cma:0
[  544.632381] Node 0 DMA free:4140kB min:704kB low:880kB high:1056kB 
active_anon:1680kB inactive_anon:1932kB active_file:2744kB inactive_file:2804kB 
unevictable:0kB isolated(anon):0kB isolated(file):0kB present:15992kB 
managed:15908kB mlocked:0kB dirty:0kB writeback:0kB mapped:1480kB shmem:4kB 
slab_reclaimable:280kB slab_unreclaimable:432kB kernel_stack:40kB 
pagetables:308kB unstable:0kB bounce:0kB free_cma:0kB writeback_tmp:0kB 
pages_scanned:11 all_unreclaimable? no
[  544.632386] lowmem_reserve[]: 0 974 974 974
[  544.632389] Node 0 DMA32 free:16428kB min:44348kB low:55432kB high:66520kB 
active_anon:243984kB inactive_anon:25688kB active_file:185288kB 
inactive_file:185360kB unevictable:0kB isolated(anon):0kB isolated(file):0kB 
present:1032128kB managed:1001232kB mlocked:0kB dirty:24kB writeback:0kB 
mapped:96056kB shmem:1800kB slab_reclaimable:23524kB slab_unreclaimable:23744kB 
kernel_stack:2704kB pagetables:19868kB unstable:0kB bounce:0kB free_cma:0kB 
writeback_tmp:0kB pages_scanned:32 all_unreclaimable? no
[  544.632402] lowmem_reserve[]: 0 0 0 0
[  544.632405] Node 0 DMA: 3*4kB (UM) 2*8kB (UM) 4*16kB (UM) 7*32kB (UM) 8*64kB 
(M) 2*128kB (UM) 2*256kB (UM) 1*512kB (U) 0*1024kB 1*2048kB (R) 0*4096kB = 
4156kB
[  544.632415] Node 0 DMA32: 1222*4kB (EM) 951*8kB (M) 0*16kB 0*32kB 0*64kB 
0*128kB 0*256kB 0*512kB 0*1024kB 0*2048kB 1*4096kB (R) = 16592kB
[  544.632434] Node 0 hugepages_total=0 hugepages_free=0 hugepages_surp=0 
hugepages_size=2048kB
[  544.632436] 94583 total pagecache pages
[  544.632439] 0 pages in swap cache
[  544.632442] Swap cache stats: add 0, delete 0, find 0/0
[  544.632444] Free swap  = 1046524kB
[  544.632454] Total swap = 1046524kB
[  544.632460] 214.322253 [ 911] netmap_finalize_obj_allocator Unable to create 
cluster at 120226 for 'netmap_buf' allocator
[  544.639068] 214.328848 [ 176] virtio_netmap_clean_used_rings got 1 used bufs 
on queue tx-0
[  544.639077] 214.328870 [ 187] virtio_netmap_clean_used_rings got 0 used bufs 
on queue rx-0
[  544.639130] 214.328915 [ 523] virtio_netmap_init_buffers added 255 inbufs on 
queue 0
[  544.639241] 214.329034 [ 547] virtio_netmap_config      virtio config txq=1, 
txd=256 rxq=1, rxd=256
[  544.639267] 214.329061 [ 176] virtio_netmap_clean_used_rings got 1 used bufs 
on queue tx-0
[  544.639271] 214.329065 [ 187] virtio_netmap_clean_used_rings got 0 used bufs 
on queue rx-0
[  544.639315] 214.329101 [ 523] virtio_netmap_init_buffers added 255 inbufs on 
queue 0
[  563.369419] type=1006 audit(1433755233.055:78): pid=3448 uid=0 old 
auid=4294967295 new auid=1000 old ses=4294967295 new ses=3 res=1
[ 1117.969220] 787.659011 [ 176] virtio_netmap_clean_used_rings got 0 used bufs 
on queue tx-0
[ 1117.969242] 787.659025 [ 187] virtio_netmap_clean_used_rings got 7 used bufs 
on queue rx-0
[ 1117.969254] 787.659046 [ 258] virtio_netmap_reg         detached 0 pending 
bufs on queue tx-0
[ 1117.969322] 787.659114 [ 270] virtio_netmap_reg         detached 248 pending 
bufs on queue rx-0
[ 1117.969414] 787.659206 [ 176] virtio_netmap_clean_used_rings got 0 used bufs 
on queue tx-0
[ 1117.969425] 787.659218 [ 187] virtio_netmap_clean_used_rings got 0 used bufs 
on queue rx-0
[ 1117.969438] 787.659231 [ 258] virtio_netmap_reg         detached 0 pending 
bufs on queue tx-0
[ 1117.969559] 787.659353 [ 270] virtio_netmap_reg         detached 255 pending 
bufs on queue rx-0
[ 1125.146275] 794.836066 [ 547] virtio_netmap_config      virtio config txq=1, 
txd=256 rxq=1, rxd=256
[ 1125.146323] 794.836116 [ 176] virtio_netmap_clean_used_rings got 0 used bufs 
on queue tx-0
[ 1125.146330] 794.836125 [ 187] virtio_netmap_clean_used_rings got 0 used bufs 
on queue rx-0
[ 1125.146457] ------------[ cut here ]------------
[ 1125.146463] kernel BUG at /usr/netmap-release/LINUX/virtio_net.c:1442!
[ 1125.146467] invalid opcode: 0000 [#1] SMP
[ 1125.146471] Modules linked in: virtio_net(OF) e1000(F) netmap(OF) 
snd_intel8x0 snd_ac97_codec ac97_bus snd_pcm snd_page_alloc snd_seq_midi 
snd_seq_midi_event snd_rawmidi rfcomm bnep snd_seq bluetooth snd_seq_device 
snd_timer joydev snd serio_raw video soundcore mac_hid i2c_piix4 parport_pc 
ppdev lp parport hid_generic usbhid hid ahci libahci psmouse [last unloaded: 
e1000]
[ 1125.146504] CPU: 0 PID: 5748 Comm: wharf Tainted: GF          O 3.13.1 #3
[ 1125.146508] Hardware name: innotek GmbH VirtualBox/VirtualBox, BIOS 
VirtualBox 12/01/2006
[ 1125.146519] task: ffff88002d5097f0 ti: ffff8800235a4000 task.ti: 
ffff8800235a4000
[ 1125.146522] RIP: 0010:[<ffffffffa001821b>]  [<ffffffffa001821b>] 
free_unused_bufs+0x18b/0x190 [virtio_net]
[ 1125.146530] RSP: 0018:ffff8800235a5c30  EFLAGS: 00010282
[ 1125.146544] RAX: ffff88003dbb9c00 RBX: ffff880012c96880 RCX: ffff880018098000
[ 1125.146547] RDX: 00000000ffffff08 RSI: 0000000000000100 RDI: ffff880012c97000
[ 1125.146550] RBP: ffff8800235a5c58 R08: 0000000000000000 R09: 0000000000000008
[ 1125.146552] R10: ffff88003fbe9f60 R11: ffff8800235a592e R12: 0000000000000000
[ 1125.146555] R13: ffff880012c97000 R14: 0000000000000000 R15: 000077ff80000000
[ 1125.146558] FS:  00007f49962a1780(0000) GS:ffff88003fc00000(0000) 
knlGS:0000000000000000
[ 1125.146567] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 1125.146570] CR2: 00007f4994613c50 CR3: 000000001d545000 CR4: 00000000000006f0
[ 1125.146574] Stack:
[ 1125.146576]  ffff88002d080000 ffff880012c96000 ffff880012c96880 
ffff8800183ae000
[ 1125.146581]  000000000000003c ffff8800235a5cb0 ffffffffa00197ce 
ffff8800235a5cc0
[ 1125.146591]  ffffffff00000001 0000000200000001 0000000200000001 
ffff88002d080000
[ 1125.146595] Call Trace:
[ 1125.146602]  [<ffffffffa00197ce>] virtio_netmap_reg+0x7e/0x270 [virtio_net]
[ 1125.146610]  [<ffffffffa01f706c>] netmap_hw_register+0x1c/0x30 [netmap]
[ 1125.146617]  [<ffffffffa01f90cc>] netmap_do_regif+0x16c/0x1f0 [netmap]
[ 1125.146630]  [<ffffffffa01fa408>] netmap_ioctl+0x468/0x6e0 [netmap]
[ 1125.146637]  [<ffffffff81172299>] ? __do_fault+0x3d9/0x4e0
[ 1125.146643]  [<ffffffffa01fb380>] linux_netmap_ioctl+0xb0/0x140 [netmap]
[ 1125.146650]  [<ffffffff8101a743>] ? native_sched_clock+0x13/0x80
[ 1125.146661]  [<ffffffff8101a743>] ? native_sched_clock+0x13/0x80
[ 1125.146667]  [<ffffffff8101a7b9>] ? sched_clock+0x9/0x10
[ 1125.146679]  [<ffffffff8109aabd>] ? sched_clock_local+0x1d/0x80
[ 1125.146764]  [<ffffffff811cc240>] do_vfs_ioctl+0x2e0/0x4c0
[ 1125.146772]  [<ffffffff8109b704>] ? vtime_account_user+0x54/0x60
[ 1125.146778]  [<ffffffff811cc4a1>] SyS_ioctl+0x81/0xa0
[ 1125.146784]  [<ffffffff817154ff>] tracesys+0xe1/0xe6
[ 1125.146787] Code: 80 75 22 e8 38 0d 14 e1 e9 81 ff ff ff 0f 1f 00 48 89 c7 
e8 88 5a 5e e1 e9 71 ff ff ff 48 89 c1 e9 57 ff ff ff 48 8b 7f 30 eb d8 <0f> 0b 
0f 1f 00 0f 1f 44 00 00 55 48 89 e5 53 48 89 fb 48 8b 3f
[ 1125.146810] RIP  [<ffffffffa001821b>] free_unused_bufs+0x18b/0x190 
[virtio_net]
[ 1125.146814]  RSP <ffff8800235a5c30>
[ 1125.146817] ---[ end trace e1718ad948332cf1 ]---

Original issue reported on code.google.com by thescien...@gmail.com on 8 Jun 2015 at 9:45