Re: Trying to unmap invalid handle! pending_idx: @ drivers/net/xen-netback/netback.c:998 causes kernel panic/reboot

[Armin Zentai <armin.zentai@ezit.hu>]

Hi!

On 14/07/14 13:54, Zoltan Kiss wrote:
> Hi,
>
> Based on the stack trace I think the guest sends packet with more than
> MAX_SKB_SLOTS slots, and one slot's grant mapping operation goes wrong.
> Then the error handling screws up the internal bookkeeping of pending
> slots, and tries to unmap something that is not mapped. Unfortunately it
> is quite complicated to emulate grant mapping failures in a predictable
> way.
> Armin, if we provide some patches (hopefully with a solution, but at
> least with some additional logging), would you be able to compile and
> verify it?

I can compile and install it, the verification may take a few days. 
We're building up a test system, and try to test with outgoing traffic. 
If you have any advice, about how to test the new kernel, please share 
with me (I mean large pps, or large bandwidth is the better, or try to 
update/downgrade the GPLPV drivers to a specific version).

I'm setting the loglevel to DBG.

>
> Regards,
>
> Zoltan Kiss
>
> On 14/07/14 03:25, Armin Zentai wrote:
>> Jul 13 00:46:58 node11 [157060.106323] vif vif-2-0 h14z4mzbvfrrhb:
>> Trying to unmap invalid handle! pending_idx: c
>> Jul 13 00:46:58 node11 [157060.106476] ------------[ cut here
>> ]------------
>> Jul 13 00:46:58 node11 [157060.106546] kernel BUG at
>> drivers/net/xen-netback/netback.c:998!
>> Jul 13 00:46:58 node11 [157060.106616] invalid opcode: 0000 [#1]
>
>> Jul 13 00:46:58 node11 [157060.112705] CPU: 0 PID: 0 Comm: swapper/0
>> Tainted: G            E 3.15.4 #1
>> Jul 13 00:46:58 node11 [157060.112776] Hardware name: Supermicro
>> X8DTL/X8DTL, BIOS 1.1b    03/19/2010
>> Jul 13 00:46:58 node11 [157060.112848] task: ffffffff81c1b480 ti:
>> ffffffff81c00000 task.ti: ffffffff81c00000
>> Jul 13 00:46:58 node11 [157060.112936] RIP: e030:[<ffffffffa025f61d>]
>> Jul 13 00:46:58 node11  [<ffffffffa025f61d>]
>> xenvif_idx_unmap+0x11d/0x130 [xen_netback]
>> Jul 13 00:46:58 node11 [157060.113078] RSP: e02b:ffff88008ea03d48
>> EFLAGS: 00010292
>> Jul 13 00:46:58 node11 [157060.113147] RAX: 000000000000004a RBX:
>> 000000000000000c RCX: 0000000000000000
>> Jul 13 00:46:58 node11 [157060.113234] RDX: ffff88008a40b600 RSI:
>> ffff88008ea03a18 RDI: 000000000000021b
>> Jul 13 00:46:58 node11 [157060.113321] RBP: ffff88008ea03d88 R08:
>> 0000000000000000 R09: ffff88008a40b600
>> Jul 13 00:46:58 node11 [157060.113408] R10: ffff88008a0004e8 R11:
>> 00000000000006d8 R12: ffff8800569708c0
>> Jul 13 00:46:58 node11 [157060.113495] R13: ffff88006558fec0 R14:
>> ffff8800569708c0 R15: 0000000000000001
>> Jul 13 00:46:58 node11 [157060.113589] FS:  00007f351684b700(0000)
>> GS:ffff88008ea00000(0000) knlGS:0000000000000000
>> Jul 13 00:46:58 node11 [157060.113679] CS:  e033 DS: 0000 ES: 0000 CR0:
>> 000000008005003b
>> Jul 13 00:46:58 node11 [157060.113747] CR2: 00007fc2a4372000 CR3:
>> 00000000049f3000 CR4: 0000000000002660
>> Jul 13 00:46:58 node11 [157060.113835] Stack:
>> Jul 13 00:46:58 node11 [157060.113896]  ffff880056979f90
>> Jul 13 00:46:58 node11  ff00000000000001
>> Jul 13 00:46:58 node11  ffff880b0605e000
>> Jul 13 00:46:58 node11  0000000000000000
>> Jul 13 00:46:58 node11
>> Jul 13 00:46:58 node11 [157060.114143]  ffff0000ffffffff
>> Jul 13 00:46:58 node11  00000000fffffff6
>> Jul 13 00:46:58 node11  0000000000000001
>> Jul 13 00:46:58 node11  ffff8800569769d0
>> Jul 13 00:46:58 node11
>> Jul 13 00:46:58 node11 [157060.114390]  ffff88008ea03e58
>> Jul 13 00:46:58 node11  ffffffffa02622fc
>> Jul 13 00:46:58 node11  ffff88008ea03dd8
>> Jul 13 00:46:58 node11  ffffffff810b5223
>> Jul 13 00:46:58 node11
>> Jul 13 00:46:58 node11 [157060.114637] Call Trace:
>> Jul 13 00:46:58 node11 [157060.114700]  <IRQ>
>> Jul 13 00:46:58 node11
>> Jul 13 00:46:58 node11 [157060.114750]
>> Jul 13 00:46:58 node11  [<ffffffffa02622fc>]
>> xenvif_tx_action+0x27c/0x7f0 [xen_netback]
>> Jul 13 00:46:58 node11 [157060.114927]  [<ffffffff810b5223>] ?
>> __wake_up+0x53/0x70
>> Jul 13 00:46:58 node11 [157060.114998]  [<ffffffff810ca077>] ?
>> handle_irq_event_percpu+0xa7/0x1b0
>> Jul 13 00:46:58 node11 [157060.115073]  [<ffffffffa02647d1>]
>> xenvif_poll+0x31/0x64 [xen_netback]
>> Jul 13 00:46:58 node11 [157060.115147]  [<ffffffff81653d4b>]
>> net_rx_action+0x10b/0x290
>> Jul 13 00:46:58 node11 [157060.115221]  [<ffffffff81071c73>]
>> __do_softirq+0x103/0x320
>> Jul 13 00:46:58 node11 [157060.115292]  [<ffffffff81072015>]
>> irq_exit+0x135/0x140
>> Jul 13 00:46:58 node11 [157060.115363]  [<ffffffff8144759c>]
>> xen_evtchn_do_upcall+0x3c/0x50
>> Jul 13 00:46:58 node11 [157060.115436]  [<ffffffff8175c07e>]
>> xen_do_hypervisor_callback+0x1e/0x30
>> Jul 13 00:46:58 node11 [157060.115506]  <EOI>
>> Jul 13 00:46:58 node11
>> Jul 13 00:46:58 node11 [157060.115551]
>> Jul 13 00:46:58 node11  [<ffffffff810013aa>] ?
>> xen_hypercall_sched_op+0xa/0x20
>> Jul 13 00:46:58 node11 [157060.115722]  [<ffffffff810013aa>] ?
>> xen_hypercall_sched_op+0xa/0x20
>> Jul 13 00:46:58 node11 [157060.115794]  [<ffffffff8100a200>] ?
>> xen_safe_halt+0x10/0x20
>> Jul 13 00:46:58 node11 [157060.115869]  [<ffffffff8101dbbf>] ?
>> default_idle+0x1f/0xc0
>> Jul 13 00:46:58 node11 [157060.115939]  [<ffffffff8101d38f>] ?
>> arch_cpu_idle+0xf/0x20
>> Jul 13 00:46:58 node11 [157060.116009]  [<ffffffff810b5aa1>] ?
>> cpu_startup_entry+0x201/0x360
>> Jul 13 00:46:58 node11 [157060.116084]  [<ffffffff817420a7>] ?
>> rest_init+0x77/0x80
>> Jul 13 00:46:58 node11 [157060.116156]  [<ffffffff81d3a156>] ?
>> start_kernel+0x406/0x413
>> Jul 13 00:46:58 node11 [157060.116227]  [<ffffffff81d39b6e>] ?
>> repair_env_string+0x5b/0x5b
>> Jul 13 00:46:58 node11 [157060.116298]  [<ffffffff81d39603>] ?
>> x86_64_start_reservations+0x2a/0x2c
>> Jul 13 00:46:58 node11 [157060.116373]  [<ffffffff81d3d5dc>] ?
>> xen_start_kernel+0x584/0x586
>


Thanks,
  - Armin