Re: [PATCH v3 2/3] hvc_init(): Enforce one-time initialization.

On (Tue) 29 Nov 2011 [09:50:41], Miche Baker-Harvey wrote:

Good grief!  Sorry for the spacing mess-up!  Here's a resend with reformatting.

Amit,
We aren't using either QEMU or kvmtool, but we are using KVM.  All

So it's a different userspace?  Any chance this different userspace is
causing these problems to appear?  Esp. since I couldn't reproduce
with qemu.

the issues we are seeing happen when we try to establish multiple
virtioconsoles at boot time.  The command line isn't relevant, but I
can tell you the protocol that's passing between the host (kvm) and
the guest (see the end of this message).

We do go through the control_work_handler(), but it's not
providing synchronization.  Here's a trace of the
control_work_handler() and handle_control_message() calls; note that
there are two concurrent calls to control_work_handler().

Ah; how does that happen?  control_work_handler() should just be
invoked once, and if there are any more pending work items to be
consumed, they should be done within the loop inside
control_work_handler().

I decorated control_work_handler() with a "lifetime" marker, and
passed this value to handle_control_message(), so we can see which
control messages are being handled from which instance of
the control_work_handler() thread.

Notice that we enter control_work_handler() a second time before
the handling of the second PORT_ADD message is complete. The
first CONSOLE_PORT message is handled by the second
control_work_handler() call, but the second is handled by the first
control_work_handler() call.

root@myubuntu:~# dmesg | grep MBH
[3371055.808738] control_work_handler #1
[3371055.809372] + #1 handle_control_message PORT_ADD
[3371055.810169] - handle_control_message PORT_ADD
[3371055.810170] + #1 handle_control_message PORT_ADD
[3371055.810244]  control_work_handler #2
[3371055.810245] + #2 handle_control_message CONSOLE_PORT
[3371055.810246]  got hvc_ports_mutex
[3371055.810578] - handle_control_message PORT_ADD
[3371055.810579] + #1 handle_control_message CONSOLE_PORT
[3371055.810580]  trylock of hvc_ports_mutex failed
[3371055.811352]  got hvc_ports_mutex
[3371055.811370] - handle_control_message CONSOLE_PORT
[3371055.816609] - handle_control_message CONSOLE_PORT

So, I'm guessing the bug is that there shouldn't be two instances of
control_work_handler() running simultaneously?

Yep, I assumed we did that but apparently not.  Do you plan to chase
this one down?

		Amit