Xen devel - Feb 2012 - irq problem with 3.3-rc3 on guest

I get the backtrace below if I try to boot a PV guest running F17 Alpha 
TC2 in graphical mode. Is this a known problem?

 	Michael Young

WARNING: at drivers/xen/events.c:209 evtchn_from_irq+0x41/0x50()
Invalid irq -1!
Modules linked in:
Pid: 17, comm: xenbus Tainted: G        W 
3.3.0-0.rc3.git3.1.fc17.x86_64 #1
Call Trace:
  <IRQ>  [<ffffffff8106047f>] warn_slowpath_common+0x7f/0xc0
  [<ffffffff81060576>] warn_slowpath_fmt+0x46/0x50
  [<ffffffff8100f942>] ? check_events+0x12/0x20
  [<ffffffff813c5bf1>] evtchn_from_irq+0x41/0x50
  [<ffffffff813c6302>] notify_remote_via_irq+0x12/0x50
  [<ffffffff8137e016>] xenfb_event_handler+0x26/0x50
  [<ffffffff8110b0fc>] handle_irq_event_percpu+0x6c/0x390
  [<ffffffff8110b468>] handle_irq_event+0x48/0x70
  [<ffffffff8110e7b7>] handle_edge_irq+0x77/0x110
  [<ffffffff813c56f3>] __xen_evtchn_do_upcall+0x1c3/0x290
  [<ffffffff813c782f>] xen_evtchn_do_upcall+0x2f/0x50
  [<ffffffff816a7a3e>] xen_do_hypervisor_callback+0x1e/0x30
  <EOI>  [<ffffffff8100140a>] ? hypercall_page+0x40a/0x1000
  [<ffffffff8100140a>] ? hypercall_page+0x40a/0x1000
  [<ffffffff813c9ed7>] ? xb_read+0xd7/0x190
  [<ffffffff811a2359>] ? kmem_cache_alloc_trace+0xd9/0x240
  [<ffffffff813cb170>] ? unregister_xenbus_watch+0x1d0/0x1d0
  [<ffffffff813cb1f9>] ? xenbus_thread+0x89/0x2b0
  [<ffffffff81089ac7>] ? kthread+0xb7/0xc0
  [<ffffffff810cd02d>] ? trace_hardirqs_on+0xd/0x10
  [<ffffffff816a78f4>] ? kernel_thread_helper+0x4/0x10
  [<ffffffff8169dcb4>] ? retint_restore_args+0x13/0x13
  [<ffffffff816a78f0>] ? gs_change+0x13/0x13

On Sun, 2012-02-12 at 21:33 +0000, M A Young wrote:
> I get the backtrace below if I try to boot a PV guest running F17 Alpha 
> TC2 in graphical mode. Is this a known problem?
It came up last year https://lkml.org/lkml/2011/1/6/19 which resulted in
the WARN_ON you saw instead of a kernel crash. I''m not sure if anyone
got to the bottom of the root cause though.

That occasion was a suspend/resume thing so perhaps not really related
but it seems fishily similar.

I''ve not looked at the code recently but it seems that back then I was
of the opinion that info->update_wanted == 0 must remain true until the
irq etc was all fully setup, that might be relevant now?

Ian.
> 
>  	Michael Young
> 
> WARNING: at drivers/xen/events.c:209 evtchn_from_irq+0x41/0x50()
> Invalid irq -1!
> Modules linked in:
> Pid: 17, comm: xenbus Tainted: G        W 
> 3.3.0-0.rc3.git3.1.fc17.x86_64 #1
> Call Trace:
>   <IRQ>  [<ffffffff8106047f>] warn_slowpath_common+0x7f/0xc0
>   [<ffffffff81060576>] warn_slowpath_fmt+0x46/0x50
>   [<ffffffff8100f942>] ? check_events+0x12/0x20
>   [<ffffffff813c5bf1>] evtchn_from_irq+0x41/0x50
>   [<ffffffff813c6302>] notify_remote_via_irq+0x12/0x50
>   [<ffffffff8137e016>] xenfb_event_handler+0x26/0x50
>   [<ffffffff8110b0fc>] handle_irq_event_percpu+0x6c/0x390
>   [<ffffffff8110b468>] handle_irq_event+0x48/0x70
>   [<ffffffff8110e7b7>] handle_edge_irq+0x77/0x110
>   [<ffffffff813c56f3>] __xen_evtchn_do_upcall+0x1c3/0x290
>   [<ffffffff813c782f>] xen_evtchn_do_upcall+0x2f/0x50
>   [<ffffffff816a7a3e>] xen_do_hypervisor_callback+0x1e/0x30
>   <EOI>  [<ffffffff8100140a>] ? hypercall_page+0x40a/0x1000
>   [<ffffffff8100140a>] ? hypercall_page+0x40a/0x1000
>   [<ffffffff813c9ed7>] ? xb_read+0xd7/0x190
>   [<ffffffff811a2359>] ? kmem_cache_alloc_trace+0xd9/0x240
>   [<ffffffff813cb170>] ? unregister_xenbus_watch+0x1d0/0x1d0
>   [<ffffffff813cb1f9>] ? xenbus_thread+0x89/0x2b0
>   [<ffffffff81089ac7>] ? kthread+0xb7/0xc0
>   [<ffffffff810cd02d>] ? trace_hardirqs_on+0xd/0x10
>   [<ffffffff816a78f4>] ? kernel_thread_helper+0x4/0x10
>   [<ffffffff8169dcb4>] ? retint_restore_args+0x13/0x13
>   [<ffffffff816a78f0>] ? gs_change+0x13/0x13
> 
> 
> _______________________________________________
> Xen-devel mailing list
> Xen-devel@lists.xensource.com
> http://lists.xensource.com/xen-devel

On Mon, 13 Feb 2012, Ian Campbell wrote:
> On Sun, 2012-02-12 at 21:33 +0000, M A Young wrote:
>> I get the backtrace below if I try to boot a PV guest running F17 Alpha
>> TC2 in graphical mode. Is this a known problem?
>
> It came up last year https://lkml.org/lkml/2011/1/6/19 which resulted in
> the WARN_ON you saw instead of a kernel crash. I''m not sure if
anyone
> got to the bottom of the root cause though.
>
> That occasion was a suspend/resume thing so perhaps not really related
> but it seems fishily similar.
>
> I''ve not looked at the code recently but it seems that back then I
was
> of the opinion that info->update_wanted == 0 must remain true until the
> irq etc was all fully setup, that might be relevant now?
Yes, it does sound fishily similar. I didn''t mention that it does work
if
I do a text boot and then switch to a graphical runlevel, so it could be 
somthing happening in the wrong order, such as the framebuffer starting 
before the irq is properly set up.

 	Michael Young

On Mon, Feb 13, 2012 at 02:12:08PM +0000, M A Young
wrote:
> On Mon, 13 Feb 2012, Ian Campbell wrote:
> 
> >On Sun, 2012-02-12 at 21:33 +0000, M A Young wrote:
> >>I get the backtrace below if I try to boot a PV guest running F17
Alpha
> >>TC2 in graphical mode. Is this a known problem?
> >
> >It came up last year https://lkml.org/lkml/2011/1/6/19 which resulted
in
> >the WARN_ON you saw instead of a kernel crash. I''m not sure if
anyone
> >got to the bottom of the root cause though.
> >
> >That occasion was a suspend/resume thing so perhaps not really related
> >but it seems fishily similar.
> >
> >I''ve not looked at the code recently but it seems that back
then I was
> >of the opinion that info->update_wanted == 0 must remain true until
the
> >irq etc was all fully setup, that might be relevant now?
> 
> Yes, it does sound fishily similar. I didn''t mention that it does
work if
> I do a text boot and then switch to a graphical runlevel, so it could be 
So how does F17 do it now? Is all in the graphical mode (KMS?) and it never
tries to hit text mode (so plymouth is on by default?)
> somthing happening in the wrong order, such as the framebuffer starting 
> before the irq is properly set up.
Hm, could you instrument xen-fbfront.c and see what the flow is during
bootup and compare that when running it under F16? That might shed some
light on this.
> 
> 	Michael Young
> 
> _______________________________________________
> Xen-devel mailing list
> Xen-devel@lists.xensource.com
> http://lists.xensource.com/xen-devel

On Tue, 14 Feb 2012, Konrad Rzeszutek Wilk wrote:
> On Mon, Feb 13, 2012 at 02:12:08PM +0000, M A Young wrote:
>> On Mon, 13 Feb 2012, Ian Campbell wrote:
>>
>>> On Sun, 2012-02-12 at 21:33 +0000, M A Young wrote:
>>>> I get the backtrace below if I try to boot a PV guest running
F17 Alpha
>>>> TC2 in graphical mode. Is this a known problem?
>>>
>>> It came up last year https://lkml.org/lkml/2011/1/6/19 which
resulted in
>>> the WARN_ON you saw instead of a kernel crash. I''m not
sure if anyone
>>> got to the bottom of the root cause though.
>>>
>>> That occasion was a suspend/resume thing so perhaps not really
related
>>> but it seems fishily similar.
>>>
>>> I''ve not looked at the code recently but it seems that
back then I was
>>> of the opinion that info->update_wanted == 0 must remain true
until the
>>> irq etc was all fully setup, that might be relevant now?
>>
>> Yes, it does sound fishily similar. I didn''t mention that it
does work if
>> I do a text boot and then switch to a graphical runlevel, so it could
be
>
> So how does F17 do it now? Is all in the graphical mode (KMS?) and it never
> tries to hit text mode (so plymouth is on by default?)
I was probably wrong about that. It was a separate non-kernel bug that was 
stopping me getting a direct graphical boot. As the backtrace happens some 
time but not others I am not longer convinced about the graphical vs text 
boot link. The backtrace occurs before the line
Feb 14 20:26:31 localhost kernel: [    2.611366] Console: switching to 
colour frame buffer device 100x37
so it seems to be when the frame buffer first launches.
>> somthing happening in the wrong order, such as the framebuffer starting
>> before the irq is properly set up.
>
> Hm, could you instrument xen-fbfront.c and see what the flow is during
> bootup and compare that when running it under F16? That might shed some
> light on this.
I will have a look at what useful debugging I can put into xen-fbfront.c - 
it might be hard for me to compare it with F16 but the comparsion between 
a backtrace and non-backtrace boot might be useful.

 	Michael Young

On Tue, 14 Feb 2012, M A Young wrote:
> On Tue, 14 Feb 2012, Konrad Rzeszutek Wilk wrote:
>
>> On Mon, Feb 13, 2012 at 02:12:08PM +0000, M A Young wrote:
>>> On Mon, 13 Feb 2012, Ian Campbell wrote:
>>> 
>>>> On Sun, 2012-02-12 at 21:33 +0000, M A Young wrote:
>>>>> I get the backtrace below if I try to boot a PV guest
running F17 Alpha
>>>>> TC2 in graphical mode. Is this a known problem?
>>>> 
>>>> It came up last year https://lkml.org/lkml/2011/1/6/19 which
resulted in
>>>> the WARN_ON you saw instead of a kernel crash. I''m not
sure if anyone
>>>> got to the bottom of the root cause though.
>>>> 
>>>> That occasion was a suspend/resume thing so perhaps not really
related
>>>> but it seems fishily similar.
>>>> 
>>>> I''ve not looked at the code recently but it seems that
back then I was
>>>> of the opinion that info->update_wanted == 0 must remain
true until the
>>>> irq etc was all fully setup, that might be relevant now?
>>> 
>>> Yes, it does sound fishily similar. I didn''t mention that
it does work if
>>> I do a text boot and then switch to a graphical runlevel, so it
could be
>> 
>> So how does F17 do it now? Is all in the graphical mode (KMS?) and it
never
>> tries to hit text mode (so plymouth is on by default?)
>
> I was probably wrong about that. It was a separate non-kernel bug that was 
> stopping me getting a direct graphical boot. As the backtrace happens some 
> time but not others I am not longer convinced about the graphical vs text 
> boot link. The backtrace occurs before the line
> Feb 14 20:26:31 localhost kernel: [    2.611366] Console: switching to
colour
> frame buffer device 100x37
> so it seems to be when the frame buffer first launches.
>
>>> somthing happening in the wrong order, such as the framebuffer
starting
>>> before the irq is properly set up.
>> 
>> Hm, could you instrument xen-fbfront.c and see what the flow is during
>> bootup and compare that when running it under F16? That might shed some
>> light on this.
>
> I will have a look at what useful debugging I can put into xen-fbfront.c -
it
> might be hard for me to compare it with F16 but the comparsion between a 
> backtrace and non-backtrace boot might be useful.
My first debugging attempt gives the values
update_wanted=0 in_cons=0 in_prod=1 width=800 height=600
just before the crash occurs. I am not sure how useful this is.

 	Michael Young

> >>So how does F17 do it now? Is all in the graphical mode (KMS?) and
it never
> >>tries to hit text mode (so plymouth is on by default?)
> >
> >I was probably wrong about that. It was a separate non-kernel bug
> >that was stopping me getting a direct graphical boot. As the
> >backtrace happens some time but not others I am not longer
> >convinced about the graphical vs text boot link. The backtrace
> >occurs before the line
> >Feb 14 20:26:31 localhost kernel: [    2.611366] Console:
> >switching to colour frame buffer device 100x37
> >so it seems to be when the frame buffer first launches.
> >
> >>>somthing happening in the wrong order, such as the framebuffer
starting
> >>>before the irq is properly set up.
> >>
> >>Hm, could you instrument xen-fbfront.c and see what the flow is
during
> >>bootup and compare that when running it under F16? That might shed
some
> >>light on this.
> >
> >I will have a look at what useful debugging I can put into
> >xen-fbfront.c - it might be hard for me to compare it with F16 but
> >the comparsion between a backtrace and non-backtrace boot might be
> >useful.
> 
> My first debugging attempt gives the values
> update_wanted=0 in_cons=0 in_prod=1 width=800 height=600
> just before the crash occurs. I am not sure how useful this is.
So how are you actually trying to install F17?
I tried:
 virt-install --name F17 --ram 1024 --disk /dev/vg_guest/f17_32 --paravirt
--location http://build/tftpboot/f17-i386/

and it showed the text console, and then rebooted thinking it was complete. 
When using a manual guest config:
kernel="/root/vmlinuz-PAE"
ramdisk="/root/initrd-PAE.img"
append="console=hvc0 loglevel=8 root=http://build/tftpboot/f17-i386"
memory=1024
maxvcpus = 2
vcpus = 2
disk = [''phy:/dev/vg_guest/f17_32,xvda,w'']
vif = [ ''type=netfront, bridge=switch'' ]
vfb = [ ''vnc=1, vnclisten=0.0.0.0 ,vncunused=1'']

I get this:
  5.680395] Broadcom NetXtreme II iSCSI Driver bnx2i v2.7.0.3 (Jun 15, 2011)
[    5.681923] iscsi: registered transport (bnx2i)
[    5.696419] iscsi: registered transport (be2iscsi)
[    5.763271] dracut: FATAL: No or empty root= argument
[    5.764158] dracut: Refusing to continue
[    5.769524] dracut Warning: Signal caught!
[    5.772973] dracut Warning: dracut: FATAL: No or empty root= argument
[    5.776138] dracut Warning: dracut: Refusing to continue
[    5.782548] init used greatest stack depth: 5480 bytes left
[    5.783425] Kernel panic - not syncing: Attempted to kill init!

so is there a new syntax for the root parameter now that is a LiveCD?

On Mon, 26 Mar 2012, Konrad Rzeszutek Wilk wrote:
> So how are you actually trying to install F17?
> I tried:
> virt-install --name F17 --ram 1024 --disk /dev/vg_guest/f17_32 --paravirt
--location http://build/tftpboot/f17-i386/
>
> and it showed the text console, and then rebooted thinking it was complete.
> When using a manual guest config:
> kernel="/root/vmlinuz-PAE"
> ramdisk="/root/initrd-PAE.img"
> append="console=hvc0 loglevel=8
root=http://build/tftpboot/f17-i386"
> memory=1024
> maxvcpus = 2
> vcpus = 2
> disk = [''phy:/dev/vg_guest/f17_32,xvda,w'']
> vif = [ ''type=netfront, bridge=switch'' ]
> vfb = [ ''vnc=1, vnclisten=0.0.0.0 ,vncunused=1'']
>
> I get this:
>  5.680395] Broadcom NetXtreme II iSCSI Driver bnx2i v2.7.0.3 (Jun 15, 2011)
> [    5.681923] iscsi: registered transport (bnx2i)
> [    5.696419] iscsi: registered transport (be2iscsi)
> [    5.763271] dracut: FATAL: No or empty root= argument
> [    5.764158] dracut: Refusing to continue
> [    5.769524] dracut Warning: Signal caught!
> [    5.772973] dracut Warning: dracut: FATAL: No or empty root= argument
> [    5.776138] dracut Warning: dracut: Refusing to continue
> [    5.782548] init used greatest stack depth: 5480 bytes left
> [    5.783425] Kernel panic - not syncing: Attempted to kill init!
>
> so is there a new syntax for the root parameter now that is a LiveCD?
Yes, the F17 install image is now a liveCD so you need to specify this on 
the boot command line. This may be as simple as replacing root= 
with root=live:

 	Michael Young

On Tue, Mar 27, 2012 at 11:14:30PM +0100, M A Young
wrote:
> On Mon, 26 Mar 2012, Konrad Rzeszutek Wilk wrote:
> 
> >So how are you actually trying to install F17?
> >I tried:
> >virt-install --name F17 --ram 1024 --disk /dev/vg_guest/f17_32
--paravirt --location http://build/tftpboot/f17-i386/
> >
> >and it showed the text console, and then rebooted thinking it was
complete.
> >When using a manual guest config:
> >kernel="/root/vmlinuz-PAE"
> >ramdisk="/root/initrd-PAE.img"
> >append="console=hvc0 loglevel=8
root=http://build/tftpboot/f17-i386"
> >memory=1024
> >maxvcpus = 2
> >vcpus = 2
> >disk = ['phy:/dev/vg_guest/f17_32,xvda,w']
> >vif = [ 'type=netfront, bridge=switch' ]
> >vfb = [ 'vnc=1, vnclisten=0.0.0.0 ,vncunused=1']
> >
> >I get this:
> > 5.680395] Broadcom NetXtreme II iSCSI Driver bnx2i v2.7.0.3 (Jun 15,
2011)
> >[    5.681923] iscsi: registered transport (bnx2i)
> >[    5.696419] iscsi: registered transport (be2iscsi)
> >[    5.763271] dracut: FATAL: No or empty root= argument
> >[    5.764158] dracut: Refusing to continue
> >[    5.769524] dracut Warning: Signal caught!
> >[    5.772973] dracut Warning: dracut: FATAL: No or empty root=
argument
> >[    5.776138] dracut Warning: dracut: Refusing to continue
> >[    5.782548] init used greatest stack depth: 5480 bytes left
> >[    5.783425] Kernel panic - not syncing: Attempted to kill init!
> >
> >so is there a new syntax for the root parameter now that is a LiveCD?
> 
> Yes, the F17 install image is now a liveCD so you need to specify
> this on the boot command line. This may be as simple as replacing
> root= with root=live:
So with extra="console=hvc0 loglevel=8
root=live:http://build/tftpboot/f17-i386/LiveOS/squashfs.img"

I was able to succesfully install, but booting proved interestingly.

When trying the 'pygrub' it would complain about the 'No OS
loader', but if I ran
it on the disk (pygrub /dev/vg_guest/f17_32) it would extract the payload
properly.
(This is with xen-4.1.2-6.fc16). So I worked around by taking those images
directly:

kernel="/var/run/xend/boot/boot_kernel.jIsJmr"
ramdisk="/var/run/xend/boot/boot_ramdisk.I4rBjo"
extra="root=/dev/mapper/vg_f17-lv_root ro rd.md=0 rd.lvm.lv=vg_f17/lv_swap
SYSFONT=True  KEYTABLE=us rd.lvm.lv=vg_f17/lv_root rd.luks=0 LANG=en_US.UTF-8
rd.dm=0"

And when booting F17 either as HVM or PV, in both cases I got Xorg to
tell me:

(EE) FBDEV(0): FBIOBLANK: Invalid argument

and freeze.

The /dev/fb0 works fine thought by itslef, if do:

"exec /sbin/init 3", then login on the VNC window and
run 'fbterm' I get an nice framebuffer terminal.

@M A: Is there a BZ for this or should I open one up with Xorg?
I would think that KVM would hit the same exact problem when using the
default VGA Cirrus framebuffer.
--
xen mailing list
xen@lists.fedoraproject.org
https://admin.fedoraproject.org/mailman/listinfo/xen

On Wed, 28 Mar 2012, Konrad Rzeszutek Wilk wrote:
> So with extra="console=hvc0 loglevel=8
root=live:http://build/tftpboot/f17-i386/LiveOS/squashfs.img"
>
> I was able to succesfully install, but booting proved interestingly.
>
> When trying the 'pygrub' it would complain about the 'No OS
loader', but if I ran
> it on the disk (pygrub /dev/vg_guest/f17_32) it would extract the payload
properly.
> (This is with xen-4.1.2-6.fc16). So I worked around by taking those images
> directly:
>
> kernel="/var/run/xend/boot/boot_kernel.jIsJmr"
> ramdisk="/var/run/xend/boot/boot_ramdisk.I4rBjo"
> extra="root=/dev/mapper/vg_f17-lv_root ro rd.md=0
rd.lvm.lv=vg_f17/lv_swap SYSFONT=True  KEYTABLE=us rd.lvm.lv=vg_f17/lv_root
rd.luks=0 LANG=en_US.UTF-8 rd.dm=0"
pygrub works for me via xl. It may be a result of how you are booting the 
guest.
> And when booting F17 either as HVM or PV, in both cases I got Xorg to
> tell me:
>
> (EE) FBDEV(0): FBIOBLANK: Invalid argument
>
> and freeze.
That seems to be harmless. However I do get the "an error has
occurred"
message instead of the gdm login screen though until I removed the fprintd 
package (and the dependent fprintd-pam package).

 	Michael Young
--
xen mailing list
xen@lists.fedoraproject.org
https://admin.fedoraproject.org/mailman/listinfo/xen

On Thu, Apr 05, 2012 at 01:11:57AM +0100, M A Young
wrote:
> On Wed, 28 Mar 2012, Konrad Rzeszutek Wilk wrote:
> 
> >So with extra="console=hvc0 loglevel=8
root=live:http://build/tftpboot/f17-i386/LiveOS/squashfs.img"
> >
> >I was able to succesfully install, but booting proved interestingly.
> >
> >When trying the 'pygrub' it would complain about the 'No OS
loader', but if I ran
> >it on the disk (pygrub /dev/vg_guest/f17_32) it would extract the
payload properly.
> >(This is with xen-4.1.2-6.fc16). So I worked around by taking those
images
> >directly:
> >
> >kernel="/var/run/xend/boot/boot_kernel.jIsJmr"
> >ramdisk="/var/run/xend/boot/boot_ramdisk.I4rBjo"
> >extra="root=/dev/mapper/vg_f17-lv_root ro rd.md=0
rd.lvm.lv=vg_f17/lv_swap SYSFONT=True  KEYTABLE=us rd.lvm.lv=vg_f17/lv_root
rd.luks=0 LANG=en_US.UTF-8 rd.dm=0"
> 
> pygrub works for me via xl. It may be a result of how you are
> booting the guest.
> 
> >And when booting F17 either as HVM or PV, in both cases I got Xorg to
> >tell me:
> >
> >(EE) FBDEV(0): FBIOBLANK: Invalid argument
> >
> >and freeze.
> 
> That seems to be harmless. However I do get the "an error has
> occurred" message instead of the gdm login screen though until I
> removed the fprintd package (and the dependent fprintd-pam package).
Oh, that fixed it! How did you find out that piece of the puzzle?
> 
> 	Michael Young
> 
> _______________________________________________
> Xen-devel mailing list
> Xen-devel@lists.xen.org
> http://lists.xen.org/xen-devel
--
xen mailing list
xen@lists.fedoraproject.org
https://admin.fedoraproject.org/mailman/listinfo/xen

On Thu, 5 Apr 2012, Konrad Rzeszutek Wilk wrote:
> On Thu, Apr 05, 2012 at 01:11:57AM +0100, M A Young wrote:
>> However I do get the "an error has
>> occurred" message instead of the gdm login screen though until I
>> removed the fprintd package (and the dependent fprintd-pam package).
>
> Oh, that fixed it! How did you find out that piece of the puzzle?
Look in the gdm logs in /var/log/gdm , in particular :0-greeter.log I 
think. There are javascript errors that point the finger at fprintd.

 	Michael Young
--
xen mailing list
xen@lists.fedoraproject.org
https://admin.fedoraproject.org/mailman/listinfo/xen