KVM crashes when using certain USB device

KVM crashes when using certain USB device

[G]

[-- Attachment #1: Type: text/plain, Size: 4172 bytes --]

Hello,

As the subject says, kvm crashes for me, when I'm trying to use an
Aladdin HASP USB dongle.

Short background: for over a year I have used kvm to run a Windows XP
Professional 32bit SP2 install with the EnCase software package, which
requires an Aladdin HASP USB dongle. The last working installation
used Debian unstable's kvm-72 and qemu 0.10.5 packages, together with
linux 2.6.29.4 (and Win XP 32 bit SP2, EnCase 6.13 (I have prevoiusly
also successfully used EnCase 4.22a with an older Aladdin HASP USB
dongle)). In an attempt to increase disk performance I upgraded to
kvm-87, and then my problems began.

Running kvm-87 works fine up until the point when the Aladdin HASP
driver wants to talk to the dongle. For example, I did one test run
with a clean Windows install where I installed EnCase 6.13 and the
dongle drivers, started up EnCase in Acquisition Mode, acquired the
running virtual hard disk while playing Solitaire (to keep both disk
and graphics going), and it went fine. Then, when I enter "usb_add
host:0529:0001" in the qemu monitor it takes somewhere between a few
seconds up to a minute or two before kvm crashes and dumps core.

Only installing the drivers without entering "usb_add host:0529:0001"
in the qemu monitor does not cause problems, I can keep on using the
system (as just described in previous paragraph).

Only entering "usb_add host:0529:0001" in the qemu monitor (and then
having "Found new hardware" pop up and selecting "Cancel") without
having the drivers installed does not cause problems, I can keep on
using the system.

I have tried out the things described at http://www.linux-kvm.org/page/Bugs ;
-no-kvm-irqchip and -no-kvm-pit only slows the system down, it still crashes.
-no-kvm crashes on startup (see the attached file crash3.txt).

All these test runs make me guess that the problem lies somewhere in
kvm's USB code, and is triggered by the Aladdin HASP drivers, unless
there is something fundamentally wrong with my install (the immediate
crash with -no-kvm might indicate that). I can however see nothing
obviously wrong with my install and therefore suspect kvm.

Three files, describing three different test runs (including gdb
backtraces) which all crash at some point, are attached to this mail.
They are generated on a Fujitsu Siemens Celsius workstation with an
"Intel(R) Core(TM)2 CPU 6600 @ 2.40GHz" (according to /proc/cpuinfo),
4GB RAM, running Linux 2.6.30 x86_64, and kvm-87 and qemu-kvm-0.10.5
downloaded from Sourceforce using the link on
http://www.linux-kvm.org/page/Downloads . No Debian kvm or qemu
packages installed, and I have made sure that I really use the kvm-87
kernel modules and not the ones that come with the kernel.

The exact same problems also show up when running the same kvm/qemu
versions and the same virtualized versions (of Win and EnCase), and on
both Linux 2.6.29.4 and 2.6.30, on a HP ProLiant DL380 G5 with 12GB
RAM and an Intel Xeon 5160 (don't know if it's a quad core or two dual
cores; in any case, it's four cores total). That is the intended
production system, and the system on which I have successfully been
running Windows and EnCase on older kvm versions (kvm-72 is working, I
don't remember if I've used any version before that).

qemu-kvm-0.10.5 is installed like this:
./configure
make
make install

kvm-87 is installed like this:
./configure --enable-debug
make
make install

I see nothing wrong with those installation methods, although I get no
"kvm" binary, and instead have to use qemu-system-x86_64 to run.

I'd be happy to do more test runs using any flags you want me to try
in order to pin this problem down. Unless, of course, I've done
something wrong, in which case I will gladly receive instructions on
how to correctly use kvm to get this working (but it's working with
kvm-72...). I have already tried several earlier versions of kvm such
as Debian unstable's kvm-85, kvm-83, and kvm-79, using the kvm modules
from the kernel tree, and they all crash too. But kvm-72 works with
the kvm modules from the kernel.

I can also supply more output from kvm compilation, kernel config etc.
in case that would be of any help.

Thanks in advance.

[-- Attachment #2: crash1.txt --]
[-- Type: text/plain, Size: 4373 bytes --]

Scenario: install EnCase 6.13, acquire the virtual hd in which we are running
while playing minesweeper and solitaire. No problems until I enter
	usb_add host:0529:0001
in the qemu monitor.

% qemu-system-x86_64 -no-acpi -hda WinXP_eng_32bit_kvm87.img -m 4096 -net nic -net user -usb -usbdevice tablet -monitor stdio
QEMU 0.10.50 monitor - type 'help' for more information
(qemu) usb_add host:0529:0001
husb: using sys file-system with /dev/bus/usb
husb: open device 4.4
husb: config #1 need -1
husb: 1 interfaces claimed for configuration 1
husb: grabbed usb device 4.4
(qemu) husb: config #1 need 1
husb: 1 interfaces claimed for configuration 1
husb: config #1 need 1
husb: 1 interfaces claimed for configuration 1
husb: config #1 need 1
husb: 1 interfaces claimed for configuration 1
husb: config #1 need 1
husb: 1 interfaces claimed for configuration 1
husb: config #1 need 1
husb: 1 interfaces claimed for configuration 1
Segmentation fault (core dumped)
% gdb /usr/local/bin/qemu-system-x86_64 core-qemu-system-x86-20592-1000-1000-11-1246535207 
GNU gdb 6.8-debian
Copyright (C) 2008 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.  Type "show copying"
and "show warranty" for details.
This GDB was configured as "x86_64-linux-gnu"...

warning: core file may not match specified executable file.

warning: Can't read pathname for load map: Input/output error.
Reading symbols from /lib/libm.so.6...done.
Loaded symbols for /lib/libm.so.6
Reading symbols from /usr/lib/libz.so.1...done.
Loaded symbols for /usr/lib/libz.so.1

[snip]

Loaded symbols for /usr/lib/libXfixes.so.3
Core was generated by `qemu-system-x86_64 -no-acpi -hda WinXP_eng_32bit_kvm87.img -m 4096 -net nic -ne'.
Program terminated with signal 11, Segmentation fault.
[New process 20592]
[New process 20676]
[New process 20593]
#0  0x00000000004c1f2a in async_complete (opaque=0x1fb0010) at usb-linux.c:271
271                     p->len = aurb->urb.actual_length;
(gdb) info threads
  3 process 20593  0x00007fa004671977 in ioctl () from /lib/libc.so.6
  2 process 20676  0x00007fa005552ded in pthread_cond_timedwait@@GLIBC_2.3.2 ()
   from /lib/libpthread.so.0
* 1 process 20592  0x00000000004c1f2a in async_complete (opaque=0x1fb0010)
    at usb-linux.c:271
(gdb) thread 3
[Switching to thread 3 (process 20593)]#0  0x00007fa004671977 in ioctl ()
   from /lib/libc.so.6
(gdb) bt
#0  0x00007fa004671977 in ioctl () from /lib/libc.so.6
#1  0x000000000053ee66 in kvm_run (vcpu=0xd67560, env=0xd552a0)
    at /usr/src/kvm-87/qemu-kvm.c:979
#2  0x00000000005401db in kvm_cpu_exec (env=0xd552a0)
    at /usr/src/kvm-87/qemu-kvm.c:1745
#3  0x000000000054088d in kvm_main_loop_cpu (env=0xd552a0)
    at /usr/src/kvm-87/qemu-kvm.c:1954
#4  0x00000000005409ab in ap_main_loop (_env=0xd552a0)
    at /usr/src/kvm-87/qemu-kvm.c:1989
#5  0x00007fa00554ef7a in start_thread () from /lib/libpthread.so.0
#6  0x00007fa004678a4d in clone () from /lib/libc.so.6
#7  0x0000000000000000 in ?? ()
(gdb) thread 2
[Switching to thread 2 (process 20676)]#0  0x00007fa005552ded in pthread_cond_timedwait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
(gdb) bt
#0  0x00007fa005552ded in pthread_cond_timedwait@@GLIBC_2.3.2 ()
   from /lib/libpthread.so.0
#1  0x00000000004aa9ae in cond_timedwait (cond=0xbd3340, mutex=0xbd3300, 
    ts=0x7f9efdb5d030) at posix-aio-compat.c:68
#2  0x00000000004aaf96 in aio_thread (unused=0x0) at posix-aio-compat.c:301
#3  0x00007fa00554ef7a in start_thread () from /lib/libpthread.so.0
#4  0x00007fa004678a4d in clone () from /lib/libc.so.6
#5  0x0000000000000000 in ?? ()
(gdb) thread 1
[Switching to thread 1 (process 20592)]#0  0x00000000004c1f2a in async_complete
    (opaque=0x1fb0010) at usb-linux.c:271
271                     p->len = aurb->urb.actual_length;
(gdb) bt
#0  0x00000000004c1f2a in async_complete (opaque=0x1fb0010) at usb-linux.c:271
#1  0x000000000040def9 in main_loop_wait (timeout=1000)
    at /usr/src/kvm-87/vl.c:4329
#2  0x0000000000540d8f in kvm_main_loop () at /usr/src/kvm-87/qemu-kvm.c:2139
#3  0x000000000040e56e in main_loop () at /usr/src/kvm-87/vl.c:4537
#4  0x0000000000411a6c in main (argc=15, argv=0x7fff3277d378, 
    envp=0x7fff3277d3f8) at /usr/src/kvm-87/vl.c:6419


[-- Attachment #3: crash2.txt --]
[-- Type: text/plain, Size: 4345 bytes --]

Scenario: enter
	usb_add host:0529:0001
in the qemu monitor directly after bootup, then install the Aladdin HASP SRM
drivers (version 5.70). kvm crashes while Windows is popping up bubbles in
lower right corner about new hardware, just towards the end of the driver
installation.

% qemu-system-x86_64 -no-acpi -hda WinXP_eng_32bit_kvm87.img -m 4096 -net nic -net user -usb -usbdevice tablet -monitor stdio 
QEMU 0.10.50 monitor - type 'help' for more information
(qemu) usb_add host:0529:0001
husb: using sys file-system with /dev/bus/usb
husb: open device 4.4
husb: config #1 need -1
husb: 1 interfaces claimed for configuration 1
husb: grabbed usb device 4.4
(qemu) husb: config #1 need 1
husb: 1 interfaces claimed for configuration 1
husb: config #1 need 1
husb: 1 interfaces claimed for configuration 1
husb: config #1 need 1
husb: 1 interfaces claimed for configuration 1
husb: config #1 need 1
husb: 1 interfaces claimed for configuration 1
husb: config #1 need 1
husb: 1 interfaces claimed for configuration 1
Segmentation fault (core dumped)
% gdb /usr/local/bin/qemu-system-x86_64 core-qemu-system-x86-20727-1000-1000-11-1246538055 
GNU gdb 6.8-debian
Copyright (C) 2008 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.  Type "show copying"
and "show warranty" for details.
This GDB was configured as "x86_64-linux-gnu"...

warning: core file may not match specified executable file.

warning: Can't read pathname for load map: Input/output error.
Reading symbols from /lib/libm.so.6...done.

[snip]

Loaded symbols for /usr/lib/libXfixes.so.3
Core was generated by `qemu-system-x86_64 -no-acpi -hda WinXP_eng_32bit_kvm87.img -m 4096 -net nic -ne'.
Program terminated with signal 11, Segmentation fault.
[New process 20727]
[New process 20732]
[New process 20728]
#0  0x00000000004c1f2a in async_complete (opaque=0x13aa010) at usb-linux.c:271
271                     p->len = aurb->urb.actual_length;
(gdb) info threads
  3 process 20728  0x00007f6c7ae3a977 in ioctl () from /lib/libc.so.6
  2 process 20732  0x00007f6c7bd1bded in pthread_cond_timedwait@@GLIBC_2.3.2 ()
   from /lib/libpthread.so.0
* 1 process 20727  0x00000000004c1f2a in async_complete (opaque=0x13aa010)
    at usb-linux.c:271
(gdb) thread 3
[Switching to thread 3 (process 20728)]#0  0x00007f6c7ae3a977 in ioctl ()
   from /lib/libc.so.6
(gdb) bt
#0  0x00007f6c7ae3a977 in ioctl () from /lib/libc.so.6
#1  0x000000000053ee66 in kvm_run (vcpu=0xf3d560, env=0xf2b2a0)
    at /usr/src/kvm-87/qemu-kvm.c:979
#2  0x00000000005401db in kvm_cpu_exec (env=0xf2b2a0)
    at /usr/src/kvm-87/qemu-kvm.c:1745
#3  0x000000000054088d in kvm_main_loop_cpu (env=0xf2b2a0)
    at /usr/src/kvm-87/qemu-kvm.c:1954
#4  0x00000000005409ab in ap_main_loop (_env=0xf2b2a0)
    at /usr/src/kvm-87/qemu-kvm.c:1989
#5  0x00007f6c7bd17f7a in start_thread () from /lib/libpthread.so.0
#6  0x00007f6c7ae41a4d in clone () from /lib/libc.so.6
#7  0x0000000000000000 in ?? ()
(gdb) thread 2
[Switching to thread 2 (process 20732)]#0  0x00007f6c7bd1bded in pthread_cond_timedwait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
(gdb) bt
#0  0x00007f6c7bd1bded in pthread_cond_timedwait@@GLIBC_2.3.2 ()
   from /lib/libpthread.so.0
#1  0x00000000004aa9ae in cond_timedwait (cond=0xbd3340, mutex=0xbd3300, 
    ts=0x7f6b74326030) at posix-aio-compat.c:68
#2  0x00000000004aaf96 in aio_thread (unused=0x0) at posix-aio-compat.c:301
#3  0x00007f6c7bd17f7a in start_thread () from /lib/libpthread.so.0
#4  0x00007f6c7ae41a4d in clone () from /lib/libc.so.6
#5  0x0000000000000000 in ?? ()
(gdb) thread 1 
[Switching to thread 1 (process 20727)]#0  0x00000000004c1f2a in async_complete
    (opaque=0x13aa010) at usb-linux.c:271
271                     p->len = aurb->urb.actual_length;
(gdb) bt
#0  0x00000000004c1f2a in async_complete (opaque=0x13aa010) at usb-linux.c:271
#1  0x000000000040def9 in main_loop_wait (timeout=1000)
    at /usr/src/kvm-87/vl.c:4329
#2  0x0000000000540d8f in kvm_main_loop () at /usr/src/kvm-87/qemu-kvm.c:2139
#3  0x000000000040e56e in main_loop () at /usr/src/kvm-87/vl.c:4537
#4  0x0000000000411a6c in main (argc=15, argv=0x7fffa2d41218, 
    envp=0x7fffa2d41298) at /usr/src/kvm-87/vl.c:6419


[-- Attachment #4: crash3.txt --]
[-- Type: text/plain, Size: 3594 bytes --]

Scenario: starting with -no-kvm, crashes before it even displays a window.

% qemu-system-x86_64 -no-acpi -hda WinXP_eng_32bit_kvm87.img -m 4096 -net nic -net user -usb -usbdevice tablet -monitor stdio -no-kvm
QEMU 0.10.50 monitor - type 'help' for more information
(qemu) Segmentation fault (core dumped)
% gdb /usr/local/bin/qemu-system-x86_64 core-qemu-system-x86-20721-1000-1000-11-1246537720 
GNU gdb 6.8-debian
Copyright (C) 2008 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.  Type "show copying"
and "show warranty" for details.
This GDB was configured as "x86_64-linux-gnu"...

warning: core file may not match specified executable file.

warning: Can't read pathname for load map: Input/output error.
Reading symbols from /lib/libm.so.6...done.
Loaded symbols for /lib/libm.so.6
Reading symbols from /usr/lib/libz.so.1...done.

[snip]

Loaded symbols for /usr/lib/libXfixes.so.3
Core was generated by `qemu-system-x86_64 -no-acpi -hda WinXP_eng_32bit_kvm87.img -m 4096 -net nic -ne'.
Program terminated with signal 11, Segmentation fault.
[New process 20721]
[New process 20722]
#0  0x000000000050f82d in tb_alloc_page (tb=0x7fba7df6c010, n=0, 
    page_addr=4295094272) at /usr/src/kvm-87/exec.c:1142
1142        tb->page_next[n] = p->first_tb;
(gdb) info threads
  2 process 20722  0x00007fbab644aded in pthread_cond_timedwait@@GLIBC_2.3.2 ()
   from /lib/libpthread.so.0
* 1 process 20721  0x000000000050f82d in tb_alloc_page (tb=0x7fba7df6c010, 
    n=0, page_addr=4295094272) at /usr/src/kvm-87/exec.c:1142
(gdb) thread 2
[Switching to thread 2 (process 20722)]#0  0x00007fbab644aded in pthread_cond_timedwait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
(gdb) bt
#0  0x00007fbab644aded in pthread_cond_timedwait@@GLIBC_2.3.2 ()
   from /lib/libpthread.so.0
#1  0x00000000004aa9ae in cond_timedwait (cond=0xbd3340, mutex=0xbd3300, 
    ts=0x7fb97d173030) at posix-aio-compat.c:68
#2  0x00000000004aaf96 in aio_thread (unused=0x0) at posix-aio-compat.c:301
#3  0x00007fbab6446f7a in start_thread () from /lib/libpthread.so.0
#4  0x00007fbab5570a4d in clone () from /lib/libc.so.6
#5  0x0000000000000000 in ?? ()
(gdb) thread 1
[Switching to thread 1 (process 20721)]#0  0x000000000050f82d in tb_alloc_page
    (tb=0x7fba7df6c010, n=0, page_addr=4295094272)
    at /usr/src/kvm-87/exec.c:1142
1142        tb->page_next[n] = p->first_tb;
(gdb) bt
#0  0x000000000050f82d in tb_alloc_page (tb=0x7fba7df6c010, n=0, 
    page_addr=4295094272) at /usr/src/kvm-87/exec.c:1142
#1  0x000000000050f75e in tb_link_phys (tb=0x7fba7df6c010, phys_pc=4295098352, 
    phys_page2=18446744073709551615) at /usr/src/kvm-87/exec.c:1232
#2  0x000000000050f0a4 in tb_gen_code (env=0x11f8400, pc=4294967280, 
    cs_base=4294901760, flags=68, cflags=0) at /usr/src/kvm-87/exec.c:930
#3  0x0000000000515a6d in tb_find_slow (pc=4294967280, cs_base=4294901760, 
    flags=68) at /usr/src/kvm-87/cpu-exec.c:169
#4  0x00000000005166d2 in tb_find_fast () at /usr/src/kvm-87/cpu-exec.c:190
#5  0x0000000000516358 in cpu_x86_exec (env1=0x11f8400)
    at /usr/src/kvm-87/cpu-exec.c:604
#6  0x000000000040e1b7 in qemu_cpu_exec (env=0x11f8400)
    at /usr/src/kvm-87/vl.c:4403
#7  0x000000000040e29b in tcg_cpu_exec () at /usr/src/kvm-87/vl.c:4434
#8  0x000000000040e57d in main_loop () at /usr/src/kvm-87/vl.c:4553
#9  0x0000000000411a6c in main (argc=16, argv=0x7fff7c1f1428, 
    envp=0x7fff7c1f14b0) at /usr/src/kvm-87/vl.c:6419

Re: KVM crashes when using certain USB device

[G]

Hello again,

I've continued my attempts to get the HASP dongle working, but with no success:

Downloaded kvm-72.tar.gz through kvm-87.tar.gz to find out when the
problem first appear, as kvm-72 is working. Unfortunately, kvm-72
through kvm-82 fails to compile on my Debian system with kernel 2.6.30
and gcc 4.3, and kvm-83 crashes in the same way that kvm-87 crashes.

I have also tested two other USB devices: a C-Pen (www.cpen.com) and a
GEM card reader, both successfully. So it seems it is the HASP
dongle/driver combo which is doing something naughty that makes KVM
versions newer than kvm-72 crash...

Anyone got any ideas what I might try out to find the cause for the crashes?

On Thu, Jul 2, 2009 at 5:42 PM, G<tjmadwja@gmail.com> wrote:
> Hello,
>
> As the subject says, kvm crashes for me, when I'm trying to use an
> Aladdin HASP USB dongle.
>
> Short background: for over a year I have used kvm to run a Windows XP
> Professional 32bit SP2 install with the EnCase software package, which
> requires an Aladdin HASP USB dongle. The last working installation
> used Debian unstable's kvm-72 and qemu 0.10.5 packages, together with
> linux 2.6.29.4 (and Win XP 32 bit SP2, EnCase 6.13 (I have prevoiusly
> also successfully used EnCase 4.22a with an older Aladdin HASP USB
> dongle)). In an attempt to increase disk performance I upgraded to
> kvm-87, and then my problems began.
>
> Running kvm-87 works fine up until the point when the Aladdin HASP
> driver wants to talk to the dongle. For example, I did one test run
> with a clean Windows install where I installed EnCase 6.13 and the
> dongle drivers, started up EnCase in Acquisition Mode, acquired the
> running virtual hard disk while playing Solitaire (to keep both disk
> and graphics going), and it went fine. Then, when I enter "usb_add
> host:0529:0001" in the qemu monitor it takes somewhere between a few
> seconds up to a minute or two before kvm crashes and dumps core.
>
> Only installing the drivers without entering "usb_add host:0529:0001"
> in the qemu monitor does not cause problems, I can keep on using the
> system (as just described in previous paragraph).
>
> Only entering "usb_add host:0529:0001" in the qemu monitor (and then
> having "Found new hardware" pop up and selecting "Cancel") without
> having the drivers installed does not cause problems, I can keep on
> using the system.
>
> I have tried out the things described at http://www.linux-kvm.org/page/Bugs ;
> -no-kvm-irqchip and -no-kvm-pit only slows the system down, it still crashes.
> -no-kvm crashes on startup (see the attached file crash3.txt).
>
> All these test runs make me guess that the problem lies somewhere in
> kvm's USB code, and is triggered by the Aladdin HASP drivers, unless
> there is something fundamentally wrong with my install (the immediate
> crash with -no-kvm might indicate that). I can however see nothing
> obviously wrong with my install and therefore suspect kvm.
>
> Three files, describing three different test runs (including gdb
> backtraces) which all crash at some point, are attached to this mail.
> They are generated on a Fujitsu Siemens Celsius workstation with an
> "Intel(R) Core(TM)2 CPU 6600 @ 2.40GHz" (according to /proc/cpuinfo),
> 4GB RAM, running Linux 2.6.30 x86_64, and kvm-87 and qemu-kvm-0.10.5
> downloaded from Sourceforce using the link on
> http://www.linux-kvm.org/page/Downloads . No Debian kvm or qemu
> packages installed, and I have made sure that I really use the kvm-87
> kernel modules and not the ones that come with the kernel.
>
> The exact same problems also show up when running the same kvm/qemu
> versions and the same virtualized versions (of Win and EnCase), and on
> both Linux 2.6.29.4 and 2.6.30, on a HP ProLiant DL380 G5 with 12GB
> RAM and an Intel Xeon 5160 (don't know if it's a quad core or two dual
> cores; in any case, it's four cores total). That is the intended
> production system, and the system on which I have successfully been
> running Windows and EnCase on older kvm versions (kvm-72 is working, I
> don't remember if I've used any version before that).
>
> qemu-kvm-0.10.5 is installed like this:
> ./configure
> make
> make install
>
> kvm-87 is installed like this:
> ./configure --enable-debug
> make
> make install
>
> I see nothing wrong with those installation methods, although I get no
> "kvm" binary, and instead have to use qemu-system-x86_64 to run.
>
> I'd be happy to do more test runs using any flags you want me to try
> in order to pin this problem down. Unless, of course, I've done
> something wrong, in which case I will gladly receive instructions on
> how to correctly use kvm to get this working (but it's working with
> kvm-72...). I have already tried several earlier versions of kvm such
> as Debian unstable's kvm-85, kvm-83, and kvm-79, using the kvm modules
> from the kernel tree, and they all crash too. But kvm-72 works with
> the kvm modules from the kernel.
>
> I can also supply more output from kvm compilation, kernel config etc.
> in case that would be of any help.
>
> Thanks in advance.
>

Re: KVM crashes when using certain USB device

[Jim Paris]

G wrote:
> Hello again,
> 
> I've continued my attempts to get the HASP dongle working, but with no success:
> 
> Downloaded kvm-72.tar.gz through kvm-87.tar.gz to find out when the
> problem first appear, as kvm-72 is working. Unfortunately, kvm-72
> through kvm-82 fails to compile on my Debian system with kernel 2.6.30
> and gcc 4.3, and kvm-83 crashes in the same way that kvm-87 crashes.
> 
> I have also tested two other USB devices: a C-Pen (www.cpen.com) and a
> GEM card reader, both successfully. So it seems it is the HASP
> dongle/driver combo which is doing something naughty that makes KVM
> versions newer than kvm-72 crash...
> 
> Anyone got any ideas what I might try out to find the cause for the
> crashes?

You might try uncommenting "//#define DEBUG" at the top of usb-linux.c
to get some more verbose output from qemu.

-jim

Re: KVM crashes when using certain USB device

[G]

[-- Attachment #1: Type: text/plain, Size: 1113 bytes --]

On Fri, Jul 3, 2009 at 6:18 PM, Jim Paris<jim@jtan.com> wrote:
> G wrote:
>> Hello again,
>>
>> I've continued my attempts to get the HASP dongle working, but with no success:
>>
>> Downloaded kvm-72.tar.gz through kvm-87.tar.gz to find out when the
>> problem first appear, as kvm-72 is working. Unfortunately, kvm-72
>> through kvm-82 fails to compile on my Debian system with kernel 2.6.30
>> and gcc 4.3, and kvm-83 crashes in the same way that kvm-87 crashes.
>>
>> I have also tested two other USB devices: a C-Pen (www.cpen.com) and a
>> GEM card reader, both successfully. So it seems it is the HASP
>> dongle/driver combo which is doing something naughty that makes KVM
>> versions newer than kvm-72 crash...
>>
>> Anyone got any ideas what I might try out to find the cause for the
>> crashes?
>
> You might try uncommenting "//#define DEBUG" at the top of usb-linux.c
> to get some more verbose output from qemu.

Good idea. The results from three test runs after that change are in
the attached files. The third was done while also dumping the USB bus,
and the output from that dump is also attached.

[-- Attachment #2: crash4.txt --]
[-- Type: text/plain, Size: 11549 bytes --]

Scenario: boot, install the HASP SRM drivers, after install completes issue
"usb_add host:0529:0001" command in qemu monitor, dumps core after windows
discovers qemu usb hub.

% qemu-system-x86_64 -no-acpi -hda WinXP_eng_32bit_kvm87.img -m 4096 -net nic -net user -usb -monitor stdio -usbdevice tablet
QEMU 0.10.50 monitor - type 'help' for more information
(qemu) usb_add host:0529:0001
husb: opened /proc/bus/usb/devices
husb: using proc file-system with /proc/bus/usb
husb: open device 4.4
husb: opened /proc/bus/usb/004/004
=== begin dumping device descriptor data ===
12 01 00 02 ff 00 00 08 29 05 01 00 21 03 01 02 00 01 09 02 14 00 01 01 00 80 19 09 04 00 00 00 ff 00 00 00 02 ff
=== end dumping device descriptor data ===
husb: claiming interfaces. config -1
husb: i is 18, descr_len is 38, dl 9, dt 2
husb: config #1 need -1
husb: 1 interfaces claimed for configuration 1
husb: grabbed usb device 4.4
(qemu) husb: reset device 4.4
husb: claiming interfaces. config 1
husb: i is 18, descr_len is 38, dl 9, dt 2
husb: config #1 need 1
husb: 1 interfaces claimed for configuration 1
husb: ctrl type 0x80 req 0x6 val 0x100 index 0 len 64
husb: submit ctrl. len 72 aurb 0x176ed10
husb: async completed. aurb 0x176ed10 status 0 alen 18
husb: reset device 4.4
husb: claiming interfaces. config 1
husb: i is 18, descr_len is 38, dl 9, dt 2
husb: config #1 need 1
husb: 1 interfaces claimed for configuration 1
husb: ctrl type 0x0 req 0x5 val 0x2 index 0 len 0
husb: ctrl set addr 2
husb: ctrl type 0x80 req 0x6 val 0x100 index 0 len 18
husb: submit ctrl. len 26 aurb 0x176ed10
husb: async completed. aurb 0x176ed10 status 0 alen 18
husb: ctrl type 0x80 req 0x6 val 0x200 index 0 len 9
husb: submit ctrl. len 17 aurb 0x176ed10
husb: async completed. aurb 0x176ed10 status 0 alen 9
husb: ctrl type 0x80 req 0x6 val 0x200 index 0 len 255
husb: submit ctrl. len 263 aurb 0x176ed10
husb: async completed. aurb 0x176ed10 status 0 alen 20
husb: ctrl type 0x80 req 0x6 val 0x3ee index 0 len 18
husb: submit ctrl. len 26 aurb 0x176ed10
husb: async completed. aurb 0x176ed10 status -32 alen 0
husb: ctrl type 0x80 req 0x6 val 0x3ee index 0 len 18
husb: submit ctrl. len 26 aurb 0x176ed10
husb: async completed. aurb 0x176ed10 status -32 alen 0
husb: ctrl type 0x80 req 0x6 val 0x3ee index 0 len 18
husb: submit ctrl. len 26 aurb 0x176ed10
husb: async completed. aurb 0x176ed10 status -32 alen 0
husb: reset device 4.4
husb: claiming interfaces. config 1
husb: i is 18, descr_len is 38, dl 9, dt 2
husb: config #1 need 1
husb: 1 interfaces claimed for configuration 1
husb: ctrl type 0x80 req 0x6 val 0x100 index 0 len 64
husb: submit ctrl. len 72 aurb 0x176ed10
husb: async completed. aurb 0x176ed10 status 0 alen 18
husb: reset device 4.4
husb: claiming interfaces. config 1
husb: i is 18, descr_len is 38, dl 9, dt 2
husb: config #1 need 1
husb: 1 interfaces claimed for configuration 1
husb: ctrl type 0x0 req 0x5 val 0x4 index 0 len 0
husb: ctrl set addr 4
husb: ctrl type 0x80 req 0x6 val 0x100 index 0 len 18
husb: submit ctrl. len 26 aurb 0x176ed10
husb: async completed. aurb 0x176ed10 status 0 alen 18
husb: ctrl type 0x80 req 0x6 val 0x200 index 0 len 9
husb: submit ctrl. len 17 aurb 0x176ed10
husb: async completed. aurb 0x176ed10 status 0 alen 9
husb: ctrl type 0x80 req 0x6 val 0x300 index 0 len 255
husb: submit ctrl. len 263 aurb 0x176ed10
husb: async completed. aurb 0x176ed10 status 0 alen 4
husb: ctrl type 0x80 req 0x6 val 0x302 index 1033 len 255
husb: submit ctrl. len 263 aurb 0x176ed10
husb: async completed. aurb 0x176ed10 status 0 alen 32
husb: ctrl type 0x80 req 0x6 val 0x300 index 0 len 255
husb: submit ctrl. len 263 aurb 0x176ed10
husb: async completed. aurb 0x176ed10 status 0 alen 4
husb: ctrl type 0x80 req 0x6 val 0x302 index 1033 len 255
husb: submit ctrl. len 263 aurb 0x176ed10
husb: async completed. aurb 0x176ed10 status 0 alen 32
husb: ctrl type 0x80 req 0x6 val 0x300 index 0 len 255
husb: submit ctrl. len 263 aurb 0x176ed10
husb: async completed. aurb 0x176ed10 status 0 alen 4
husb: ctrl type 0x80 req 0x6 val 0x302 index 1033 len 255
husb: submit ctrl. len 263 aurb 0x176ed10
husb: async completed. aurb 0x176ed10 status 0 alen 32
husb: ctrl type 0x80 req 0x6 val 0x300 index 0 len 255
husb: submit ctrl. len 263 aurb 0x176ed10
husb: async completed. aurb 0x176ed10 status 0 alen 4
husb: ctrl type 0x80 req 0x6 val 0x302 index 1033 len 255
husb: submit ctrl. len 263 aurb 0x176ed10
husb: async completed. aurb 0x176ed10 status 0 alen 32
husb: ctrl type 0x80 req 0x6 val 0x100 index 0 len 18
husb: submit ctrl. len 26 aurb 0x176ed10
husb: async completed. aurb 0x176ed10 status 0 alen 18
husb: ctrl type 0x80 req 0x6 val 0x200 index 0 len 9
husb: submit ctrl. len 17 aurb 0x176ed10
husb: async completed. aurb 0x176ed10 status 0 alen 9
husb: ctrl type 0x80 req 0x6 val 0x200 index 0 len 36
husb: submit ctrl. len 44 aurb 0x176ed10
husb: async completed. aurb 0x176ed10 status 0 alen 20
husb: ctrl type 0x0 req 0x9 val 0x1 index 0 len 0
husb: releasing interfaces
husb: ctrl set config 1 ret 0 errno 11
husb: claiming interfaces. config 1
husb: i is 18, descr_len is 38, dl 9, dt 2
husb: config #1 need 1
husb: 1 interfaces claimed for configuration 1
husb: ctrl type 0xc0 req 0x80 val 0x21b9 index 0 len 7
husb: submit ctrl. len 15 aurb 0x176ed10
husb: async completed. aurb 0x176ed10 status 0 alen 7
husb: ctrl type 0xc0 req 0xa0 val 0x0 index 0 len 1
husb: submit ctrl. len 9 aurb 0x176ed10
husb: async completed. aurb 0x176ed10 status 0 alen 1
husb: ctrl type 0xc0 req 0xa1 val 0x3 index 0 len 8
husb: submit ctrl. len 16 aurb 0x176ed10
husb: async completed. aurb 0x176ed10 status 0 alen 8
husb: ctrl type 0xc0 req 0xa1 val 0x1 index 0 len 47
husb: submit ctrl. len 55 aurb 0x176ed10
husb: async completed. aurb 0x176ed10 status 0 alen 47
husb: ctrl type 0xc0 req 0xa2 val 0x0 index 0 len 1985
husb: submit ctrl. len 1993 aurb 0x176ed10
husb: async completed. aurb 0x176ed10 status 0 alen 1985
husb: ctrl type 0xc0 req 0xa1 val 0x1 index 0 len 47
husb: submit ctrl. len 55 aurb 0x176ed10
husb: async completed. aurb 0x176ed10 status 0 alen 47
husb: ctrl type 0xc0 req 0xa1 val 0x0 index 0 len 3
husb: submit ctrl. len 11 aurb 0x176ed10
husb: async completed. aurb 0x176ed10 status 0 alen 3
husb: ctrl type 0xc0 req 0xa1 val 0x1 index 0 len 47
husb: submit ctrl. len 55 aurb 0x176ed10
husb: async completed. aurb 0x176ed10 status 0 alen 47
husb: ctrl type 0x40 req 0x26 val 0xcaff index 2176 len 16
husb: submit ctrl. len 24 aurb 0x176ed10
husb: async completed. aurb 0x176ed10 status 0 alen 16
husb: ctrl type 0xc0 req 0xa6 val 0x0 index 0 len 33
husb: submit ctrl. len 41 aurb 0x176ed10
husb: async completed. aurb 0x176ed10 status 0 alen 33
husb: ctrl type 0x40 req 0x26 val 0xcdff index 2304 len 8
husb: submit ctrl. len 16 aurb 0x176ed10
husb: async completed. aurb 0x176ed10 status 0 alen 8
husb: ctrl type 0xc0 req 0xa6 val 0x0 index 0 len 17
husb: submit ctrl. len 25 aurb 0x176ed10
husb: async completed. aurb 0x176ed10 status 0 alen 17
husb: ctrl type 0x40 req 0x26 val 0xcbff index 2560 len 8
husb: submit ctrl. len 16 aurb 0x176ed10
husb: async completed. aurb 0x176ed10 status 0 alen 8
husb: ctrl type 0xc0 req 0xa6 val 0x0 index 0 len 17
husb: submit ctrl. len 25 aurb 0x176ed10
husb: async completed. aurb 0x176ed10 status 0 alen 17
husb: ctrl type 0xc0 req 0xa1 val 0x2 index 0 len 14
husb: submit ctrl. len 22 aurb 0x176ed10
husb: async completed. aurb 0x176ed10 status 0 alen 14
Segmentation fault (core dumped)
% gdb /usr/local/bin/qemu-system-x86_64 core-qemu-system-x86-4848-1000-1000-11-1246698455
GNU gdb 6.8-debian
Copyright (C) 2008 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.  Type "show copying"
and "show warranty" for details.
This GDB was configured as "x86_64-linux-gnu"...

warning: core file may not match specified executable file.

warning: Can't read pathname for load map: Input/output error.
Reading symbols from /lib/libm.so.6...done.

[snip]

Loaded symbols for /usr/lib/libXfixes.so.3
Core was generated by `qemu-system-x86_64 -no-acpi -hda /home/tomhal/WinXP_eng_32bit_kvm87.img -m 4096'.
Program terminated with signal 11, Segmentation fault.
[New process 4848]
[New process 4854]
[New process 4849]
#0  0x00007f4868df01f3 in ?? () from /lib/libc.so.6
(gdb) info threads 
  3 process 4849  0x00007f4868e41977 in ioctl () from /lib/libc.so.6
  2 process 4854  0x00007f4869d17ded in pthread_cond_timedwait@@GLIBC_2.3.2 ()
   from /lib/libpthread.so.0
* 1 process 4848  0x00007f4868df01f3 in ?? () from /lib/libc.so.6
(gdb) thread 3
[Switching to thread 3 (process 4849)]#0  0x00007f4868e41977 in ioctl ()
   from /lib/libc.so.6
(gdb) bt
#0  0x00007f4868e41977 in ioctl () from /lib/libc.so.6
#1  0x000000000053f1b6 in kvm_run (vcpu=0x16d5550, env=0x16c32a0)
    at /usr/src/kvm-87/qemu-kvm.c:979
#2  0x000000000054052b in kvm_cpu_exec (env=0x16c32a0)
    at /usr/src/kvm-87/qemu-kvm.c:1745
#3  0x0000000000540bdd in kvm_main_loop_cpu (env=0x16c32a0)
    at /usr/src/kvm-87/qemu-kvm.c:1954
#4  0x0000000000540cfb in ap_main_loop (_env=0x16c32a0)
    at /usr/src/kvm-87/qemu-kvm.c:1989
#5  0x00007f4869d13f7a in start_thread () from /lib/libpthread.so.0
#6  0x00007f4868e48a4d in clone () from /lib/libc.so.6
#7  0x0000000000000000 in ?? ()
(gdb) thread 2
[Switching to thread 2 (process 4854)]#0  0x00007f4869d17ded in pthread_cond_timedwait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
(gdb) bt
#0  0x00007f4869d17ded in pthread_cond_timedwait@@GLIBC_2.3.2 ()
   from /lib/libpthread.so.0
#1  0x00000000004aa9ae in cond_timedwait (cond=0xbd3a60, mutex=0xbd3a20, 
    ts=0x7f476577e080) at posix-aio-compat.c:68
#2  0x00000000004aaf96 in aio_thread (unused=0x0) at posix-aio-compat.c:301
#3  0x00007f4869d13f7a in start_thread () from /lib/libpthread.so.0
#4  0x00007f4868e48a4d in clone () from /lib/libc.so.6
#5  0x0000000000000000 in ?? ()
(gdb) thread 1
[Switching to thread 1 (process 4848)]#0  0x00007f4868df01f3 in ?? ()
   from /lib/libc.so.6
(gdb) bt
#0  0x00007f4868df01f3 in ?? () from /lib/libc.so.6
#1  0x00007f4868df1e88 in malloc () from /lib/libc.so.6
#2  0x00007f48674d6ed1 in ?? () from /usr/lib/libxcb.so.1
#3  0x00007f48674d7498 in xcb_poll_for_event () from /usr/lib/libxcb.so.1
#4  0x00007f486935a85d in ?? () from /usr/lib/libX11.so.6
#5  0x00007f486935b177 in _XEventsQueued () from /usr/lib/libX11.so.6
#6  0x00007f486933301a in XFlush () from /usr/lib/libX11.so.6
#7  0x00007f486968162d in ?? () from /usr/lib/libSDL-1.2.so.0
#8  0x00007f48696816eb in ?? () from /usr/lib/libSDL-1.2.so.0
#9  0x00007f48696556e0 in SDL_PumpEvents () from /usr/lib/libSDL-1.2.so.0
#10 0x00007f4869655b99 in SDL_PollEvent () from /usr/lib/libSDL-1.2.so.0
#11 0x00000000004f575d in sdl_refresh (ds=0x16dd7f0) at sdl.c:511
#12 0x000000000040d556 in dpy_refresh (s=0x16dd7f0)
    at /usr/src/kvm-87/console.h:215
#13 0x000000000040d4c3 in gui_update (opaque=0x16dd7f0)
    at /usr/src/kvm-87/vl.c:3572
#14 0x0000000000408fe2 in qemu_run_timers (ptimer_head=0xbd15a0, 
    current_time=323489289) at /usr/src/kvm-87/vl.c:1260
#15 0x000000000040e0b9 in main_loop_wait (timeout=1000)
    at /usr/src/kvm-87/vl.c:4369
#16 0x00000000005410df in kvm_main_loop () at /usr/src/kvm-87/qemu-kvm.c:2139
#17 0x000000000040e56e in main_loop () at /usr/src/kvm-87/vl.c:4537
#18 0x0000000000411a6c in main (argc=15, argv=0x7fffb206cd78, 
    envp=0x7fffb206cdf8) at /usr/src/kvm-87/vl.c:6419
(gdb) 

[-- Attachment #3: crash5.txt --]
[-- Type: text/plain, Size: 9520 bytes --]

Scenario: boot, issue "usb_add host:0529:0001" command (see note in debug
output) in qemu monitor, select "Cancel" in Windows "Found new hardware"
dialog, install the HASP SRM drivers, dumps core while "Aladdin HASP HL Key"
new hardware pop-up box is still being displayed in lower right corner of
screen (near end of driver installation procedure).

% qemu-system-x86_64 -no-acpi -hda WinXP_eng_32bit_kvm87.img -m 4096 -net nic -net user -usb -monitor stdio -usbdevice tablet
QEMU 0.10.50 monitor - type 'help' for more information
(qemu) usb_add host:0529:0001
husb: opened /proc/bus/usb/devices
husb: using proc file-system with /proc/bus/usb
husb: open device 4.4
husb: opened /proc/bus/usb/004/004
=== begin dumping device descriptor data ===
12 01 00 02 ff 00 00 08 29 05 01 00 21 03 01 02 00 01 09 02 14 00 01 01 00 80 19 09 04 00 00 00 ff 00 00 00 02 ff
=== end dumping device descriptor data ===
husb: claiming interfaces. config -1
husb: i is 18, descr_len is 38, dl 9, dt 2
husb: config #1 need -1
husb: 1 interfaces claimed for configuration 1
husb: grabbed usb device 4.4
(qemu) husb: reset device 4.4
husb: claiming interfaces. config 1
husb: i is 18, descr_len is 38, dl 9, dt 2
husb: config #1 need 1
husb: 1 interfaces claimed for configuration 1
husb: ctrl type 0x80 req 0x6 val 0x100 index 0 len 64
husb: submit ctrl. len 72 aurb 0x3292f10
husb: async completed. aurb 0x3292f10 status 0 alen 18
husb: reset device 4.4
husb: claiming interfaces. config 1
husb: i is 18, descr_len is 38, dl 9, dt 2
husb: config #1 need 1
husb: 1 interfaces claimed for configuration 1
husb: ctrl type 0x0 req 0x5 val 0x2 index 0 len 0
husb: ctrl set addr 2
husb: ctrl type 0x80 req 0x6 val 0x100 index 0 len 18
husb: submit ctrl. len 26 aurb 0x3292f10
husb: async completed. aurb 0x3292f10 status 0 alen 18
husb: ctrl type 0x80 req 0x6 val 0x200 index 0 len 9
husb: submit ctrl. len 17 aurb 0x3292f10
husb: async completed. aurb 0x3292f10 status 0 alen 9
husb: ctrl type 0x80 req 0x6 val 0x200 index 0 len 255
husb: submit ctrl. len 263 aurb 0x3292f10
husb: async completed. aurb 0x3292f10 status 0 alen 20
husb: ctrl type 0x80 req 0x6 val 0x3ee index 0 len 18
husb: submit ctrl. len 26 aurb 0x3292f10
husb: async completed. aurb 0x3292f10 status -32 alen 0
husb: ctrl type 0x80 req 0x6 val 0x3ee index 0 len 18
husb: submit ctrl. len 26 aurb 0x3292f10
husb: async completed. aurb 0x3292f10 status -32 alen 0
husb: ctrl type 0x80 req 0x6 val 0x3ee index 0 len 18
husb: submit ctrl. len 26 aurb 0x3292f10
husb: async completed. aurb 0x3292f10 status -32 alen 0
husb: reset device 4.4
husb: claiming interfaces. config 1
husb: i is 18, descr_len is 38, dl 9, dt 2
husb: config #1 need 1
husb: 1 interfaces claimed for configuration 1
husb: ctrl type 0x80 req 0x6 val 0x100 index 0 len 64
husb: submit ctrl. len 72 aurb 0x3292f10
husb: async completed. aurb 0x3292f10 status 0 alen 18
husb: reset device 4.4
husb: claiming interfaces. config 1
husb: i is 18, descr_len is 38, dl 9, dt 2
husb: config #1 need 1
husb: 1 interfaces claimed for configuration 1
husb: ctrl type 0x0 req 0x5 val 0x4 index 0 len 0
husb: ctrl set addr 4
husb: ctrl type 0x80 req 0x6 val 0x100 index 0 len 18
husb: submit ctrl. len 26 aurb 0x3292f10
husb: async completed. aurb 0x3292f10 status 0 alen 18
husb: ctrl type 0x80 req 0x6 val 0x200 index 0 len 9
husb: submit ctrl. len 17 aurb 0x3292f10
husb: async completed. aurb 0x3292f10 status 0 alen 9
husb: ctrl type 0x80 req 0x6 val 0x300 index 0 len 255
husb: submit ctrl. len 263 aurb 0x3292f10
husb: async completed. aurb 0x3292f10 status 0 alen 4
husb: ctrl type 0x80 req 0x6 val 0x302 index 1033 len 255
husb: submit ctrl. len 263 aurb 0x3292f10
husb: async completed. aurb 0x3292f10 status 0 alen 32
husb: ctrl type 0x80 req 0x6 val 0x300 index 0 len 255
husb: submit ctrl. len 263 aurb 0x3292f10
husb: async completed. aurb 0x3292f10 status 0 alen 4
husb: ctrl type 0x80 req 0x6 val 0x302 index 1033 len 255
husb: submit ctrl. len 263 aurb 0x3292f10
husb: async completed. aurb 0x3292f10 status 0 alen 32

[this is where I press "Cancel" in found new hardware dialog, and start
installing the HASP SRM drivers]

husb: ctrl type 0x80 req 0x6 val 0x300 index 0 len 255
husb: submit ctrl. len 263 aurb 0x2535cf0
husb: async completed. aurb 0x2535cf0 status 0 alen 4
husb: ctrl type 0x80 req 0x6 val 0x302 index 1033 len 255
husb: submit ctrl. len 263 aurb 0x2535cf0
husb: async completed. aurb 0x2535cf0 status 0 alen 32
husb: ctrl type 0x80 req 0x6 val 0x300 index 0 len 255
husb: submit ctrl. len 263 aurb 0x2535cf0
husb: async completed. aurb 0x2535cf0 status 0 alen 4
husb: ctrl type 0x80 req 0x6 val 0x302 index 1033 len 255
husb: submit ctrl. len 263 aurb 0x2535cf0
husb: async completed. aurb 0x2535cf0 status 0 alen 32
husb: ctrl type 0x80 req 0x6 val 0x100 index 0 len 18
husb: submit ctrl. len 26 aurb 0x2535cf0
husb: async completed. aurb 0x2535cf0 status 0 alen 18
husb: ctrl type 0x80 req 0x6 val 0x200 index 0 len 9
husb: submit ctrl. len 17 aurb 0x2535cf0
husb: async completed. aurb 0x2535cf0 status 0 alen 9
husb: ctrl type 0x80 req 0x6 val 0x200 index 0 len 36
husb: submit ctrl. len 44 aurb 0x2535cf0
husb: async completed. aurb 0x2535cf0 status 0 alen 20
husb: ctrl type 0x0 req 0x9 val 0x1 index 0 len 0
husb: releasing interfaces
husb: ctrl set config 1 ret 0 errno 11
husb: claiming interfaces. config 1
husb: i is 18, descr_len is 38, dl 9, dt 2
husb: config #1 need 1
husb: 1 interfaces claimed for configuration 1
husb: ctrl type 0xc0 req 0x80 val 0x81b6 index 0 len 7
husb: submit ctrl. len 15 aurb 0x2535cf0
husb: async completed. aurb 0x2535cf0 status 0 alen 7
husb: ctrl type 0xc0 req 0xa0 val 0x0 index 0 len 1
husb: submit ctrl. len 9 aurb 0x2535cf0
husb: async completed. aurb 0x2535cf0 status 0 alen 1
husb: ctrl type 0xc0 req 0xa1 val 0x3 index 0 len 8
husb: submit ctrl. len 16 aurb 0x2535fa0
husb: async completed. aurb 0x2535fa0 status 0 alen 8
husb: ctrl type 0xc0 req 0xa1 val 0x1 index 0 len 47
husb: submit ctrl. len 55 aurb 0x2535fa0
husb: async completed. aurb 0x2535fa0 status 0 alen 47
husb: ctrl type 0xc0 req 0xa2 val 0x0 index 0 len 1985
husb: submit ctrl. len 1993 aurb 0x2535fa0
husb: async completed. aurb 0x2535fa0 status 0 alen 1985
Segmentation fault (core dumped)
% gdb /usr/local/bin/qemu-system-x86_64 core-qemu-system-x86-4862-1000-1000-11-1246698865
GNU gdb 6.8-debian
Copyright (C) 2008 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.  Type "show copying"
and "show warranty" for details.
This GDB was configured as "x86_64-linux-gnu"...

warning: core file may not match specified executable file.

warning: Can't read pathname for load map: Input/output error.
Reading symbols from /lib/libm.so.6...done.

[snip]

Loaded symbols for /usr/lib/libXfixes.so.3
Core was generated by `qemu-system-x86_64 -no-acpi -hda /home/tomhal/WinXP_eng_32bit_kvm87.img -m 4096'.
Program terminated with signal 11, Segmentation fault.
[New process 4862]
[New process 4865]
[New process 4863]
#0  0x00000000004c1f62 in async_complete (opaque=0x2535010) at usb-linux.c:271
271     usb-linux.c: No such file or directory.
        in usb-linux.c
(gdb) info threads 
  3 process 4863  0x00007fa04f56e977 in ioctl () from /lib/libc.so.6
  2 process 4865  0x00007fa050444ded in pthread_cond_timedwait@@GLIBC_2.3.2 ()
   from /lib/libpthread.so.0
* 1 process 4862  0x00000000004c1f62 in async_complete (opaque=0x2535010)
    at usb-linux.c:271
(gdb) thread 3
[Switching to thread 3 (process 4863)]#0  0x00007fa04f56e977 in ioctl ()
   from /lib/libc.so.6
(gdb) bt
#0  0x00007fa04f56e977 in ioctl () from /lib/libc.so.6
#1  0x000000000053f1b6 in kvm_run (vcpu=0x1e02550, env=0x1df02a0)
    at /usr/src/kvm-87/qemu-kvm.c:979
#2  0x000000000054052b in kvm_cpu_exec (env=0x1df02a0)
    at /usr/src/kvm-87/qemu-kvm.c:1745
#3  0x0000000000540bdd in kvm_main_loop_cpu (env=0x1df02a0)
    at /usr/src/kvm-87/qemu-kvm.c:1954
#4  0x0000000000540cfb in ap_main_loop (_env=0x1df02a0)
    at /usr/src/kvm-87/qemu-kvm.c:1989
#5  0x00007fa050440f7a in start_thread () from /lib/libpthread.so.0
#6  0x00007fa04f575a4d in clone () from /lib/libc.so.6
#7  0x0000000000000000 in ?? ()
(gdb) thread 2
[Switching to thread 2 (process 4865)]#0  0x00007fa050444ded in pthread_cond_timedwait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
(gdb) bt
#0  0x00007fa050444ded in pthread_cond_timedwait@@GLIBC_2.3.2 ()
   from /lib/libpthread.so.0
#1  0x00000000004aa9ae in cond_timedwait (cond=0xbd3a60, mutex=0xbd3a20, 
    ts=0x7f9f4beab080) at posix-aio-compat.c:68
#2  0x00000000004aaf96 in aio_thread (unused=0x0) at posix-aio-compat.c:301
#3  0x00007fa050440f7a in start_thread () from /lib/libpthread.so.0
#4  0x00007fa04f575a4d in clone () from /lib/libc.so.6
#5  0x0000000000000000 in ?? ()
(gdb) thread 1
[Switching to thread 1 (process 4862)]#0  0x00000000004c1f62 in async_complete
    (opaque=0x2535010) at usb-linux.c:271
271     in usb-linux.c
(gdb) bt
#0  0x00000000004c1f62 in async_complete (opaque=0x2535010) at usb-linux.c:271
#1  0x000000000040def9 in main_loop_wait (timeout=1000)
    at /usr/src/kvm-87/vl.c:4329
#2  0x00000000005410df in kvm_main_loop () at /usr/src/kvm-87/qemu-kvm.c:2139
#3  0x000000000040e56e in main_loop () at /usr/src/kvm-87/vl.c:4537
#4  0x0000000000411a6c in main (argc=15, argv=0x7ffffd3879b8, 
    envp=0x7ffffd387a38) at /usr/src/kvm-87/vl.c:6419
(gdb) 

[-- Attachment #4: crash6.txt --]
[-- Type: text/plain, Size: 9877 bytes --]

Scenario: boot, run "cat /sys/kernel/debug/usbmon/4u > /forensics/4.usbmon.out"
as root on the host, issue "usb_add host:0529:0001" command (see note in debug
output) in qemu monitor, select "Cancel" in Windows "Found new hardware"
dialog, install the HASP SRM drivers, dumps core while "Aladdin HASP HL Key"
new hardware pop-up box is still being displayed in lower right corner of
screen (near end of driver installation procedure), Ctrl-C the usbmon dump.

% qemu-system-x86_64 -no-acpi -hda WinXP_eng_32bit_kvm87.img -m 4096 -net nic -net user -usb -monitor stdio -usbdevice tablet
QEMU 0.10.50 monitor - type 'help' for more information
(qemu) usb_add host:0529:0001
husb: opened /proc/bus/usb/devices
husb: using proc file-system with /proc/bus/usb
husb: open device 4.4
husb: opened /proc/bus/usb/004/004
=== begin dumping device descriptor data ===
12 01 00 02 ff 00 00 08 29 05 01 00 21 03 01 02 00 01 09 02 14 00 01 01 00 80 19 09 04 00 00 00 ff 00 00 00 02 ff
=== end dumping device descriptor data ===
husb: claiming interfaces. config -1
husb: i is 18, descr_len is 38, dl 9, dt 2
husb: config #1 need -1
husb: 1 interfaces claimed for configuration 1
husb: grabbed usb device 4.4
(qemu) husb: reset device 4.4
husb: claiming interfaces. config 1
husb: i is 18, descr_len is 38, dl 9, dt 2
husb: config #1 need 1
husb: 1 interfaces claimed for configuration 1
husb: ctrl type 0x80 req 0x6 val 0x100 index 0 len 64
husb: submit ctrl. len 72 aurb 0x12b2840
husb: async completed. aurb 0x12b2840 status 0 alen 18
husb: reset device 4.4
husb: claiming interfaces. config 1
husb: i is 18, descr_len is 38, dl 9, dt 2
husb: config #1 need 1
husb: 1 interfaces claimed for configuration 1
husb: ctrl type 0x0 req 0x5 val 0x2 index 0 len 0
husb: ctrl set addr 2
husb: ctrl type 0x80 req 0x6 val 0x100 index 0 len 18
husb: submit ctrl. len 26 aurb 0x12b2840
husb: async completed. aurb 0x12b2840 status 0 alen 18
husb: ctrl type 0x80 req 0x6 val 0x200 index 0 len 9
husb: submit ctrl. len 17 aurb 0x12b2840
husb: async completed. aurb 0x12b2840 status 0 alen 9
husb: ctrl type 0x80 req 0x6 val 0x200 index 0 len 255
husb: submit ctrl. len 263 aurb 0x12b2840
husb: async completed. aurb 0x12b2840 status 0 alen 20
husb: ctrl type 0x80 req 0x6 val 0x3ee index 0 len 18
husb: submit ctrl. len 26 aurb 0x12b2840
husb: async completed. aurb 0x12b2840 status -32 alen 0
husb: ctrl type 0x80 req 0x6 val 0x3ee index 0 len 18
husb: submit ctrl. len 26 aurb 0x12b2840
husb: async completed. aurb 0x12b2840 status -32 alen 0
husb: ctrl type 0x80 req 0x6 val 0x3ee index 0 len 18
husb: submit ctrl. len 26 aurb 0x12b2840
husb: async completed. aurb 0x12b2840 status -32 alen 0
husb: reset device 4.4
husb: claiming interfaces. config 1
husb: i is 18, descr_len is 38, dl 9, dt 2
husb: config #1 need 1
husb: 1 interfaces claimed for configuration 1
husb: ctrl type 0x80 req 0x6 val 0x100 index 0 len 64
husb: submit ctrl. len 72 aurb 0x12b2840
husb: async completed. aurb 0x12b2840 status 0 alen 18
husb: reset device 4.4
husb: claiming interfaces. config 1
husb: i is 18, descr_len is 38, dl 9, dt 2
husb: config #1 need 1
husb: 1 interfaces claimed for configuration 1
husb: ctrl type 0x0 req 0x5 val 0x4 index 0 len 0
husb: ctrl set addr 4
husb: ctrl type 0x80 req 0x6 val 0x100 index 0 len 18
husb: submit ctrl. len 26 aurb 0x12b2840
husb: async completed. aurb 0x12b2840 status 0 alen 18
husb: ctrl type 0x80 req 0x6 val 0x200 index 0 len 9
husb: submit ctrl. len 17 aurb 0x12b2840
husb: async completed. aurb 0x12b2840 status 0 alen 9
husb: ctrl type 0x80 req 0x6 val 0x300 index 0 len 255
husb: submit ctrl. len 263 aurb 0x12b2840
husb: async completed. aurb 0x12b2840 status 0 alen 4
husb: ctrl type 0x80 req 0x6 val 0x302 index 1033 len 255
husb: submit ctrl. len 263 aurb 0x12b2840
husb: async completed. aurb 0x12b2840 status 0 alen 32
husb: ctrl type 0x80 req 0x6 val 0x300 index 0 len 255
husb: submit ctrl. len 263 aurb 0x12b2840
husb: async completed. aurb 0x12b2840 status 0 alen 4
husb: ctrl type 0x80 req 0x6 val 0x302 index 1033 len 255
husb: submit ctrl. len 263 aurb 0x12b2840
husb: async completed. aurb 0x12b2840 status 0 alen 32

[this is where I press "Cancel" in found new hardware dialog, and start
installing the HASP SRM drivers]

husb: ctrl type 0x80 req 0x6 val 0x300 index 0 len 255
husb: submit ctrl. len 263 aurb 0x23aefa0
husb: async completed. aurb 0x23aefa0 status 0 alen 4
husb: ctrl type 0x80 req 0x6 val 0x302 index 1033 len 255
husb: submit ctrl. len 263 aurb 0x23aefa0
husb: async completed. aurb 0x23aefa0 status 0 alen 32
husb: ctrl type 0x80 req 0x6 val 0x300 index 0 len 255
husb: submit ctrl. len 263 aurb 0x23aefa0
husb: async completed. aurb 0x23aefa0 status 0 alen 4
husb: ctrl type 0x80 req 0x6 val 0x302 index 1033 len 255
husb: submit ctrl. len 263 aurb 0x23aefa0
husb: async completed. aurb 0x23aefa0 status 0 alen 32
husb: ctrl type 0x80 req 0x6 val 0x100 index 0 len 18
husb: submit ctrl. len 26 aurb 0x23aefa0
husb: async completed. aurb 0x23aefa0 status 0 alen 18
husb: ctrl type 0x80 req 0x6 val 0x200 index 0 len 9
husb: submit ctrl. len 17 aurb 0x23aefa0
husb: async completed. aurb 0x23aefa0 status 0 alen 9
husb: ctrl type 0x80 req 0x6 val 0x200 index 0 len 36
husb: submit ctrl. len 44 aurb 0x23aefa0
husb: async completed. aurb 0x23aefa0 status 0 alen 20
husb: ctrl type 0x0 req 0x9 val 0x1 index 0 len 0
husb: releasing interfaces
husb: ctrl set config 1 ret 0 errno 11
husb: claiming interfaces. config 1
husb: i is 18, descr_len is 38, dl 9, dt 2
husb: config #1 need 1
husb: 1 interfaces claimed for configuration 1
husb: ctrl type 0xc0 req 0x80 val 0x522a index 0 len 7
husb: submit ctrl. len 15 aurb 0x23aefa0
husb: async completed. aurb 0x23aefa0 status 0 alen 7
husb: ctrl type 0xc0 req 0xa0 val 0x0 index 0 len 1
husb: submit ctrl. len 9 aurb 0x23aefa0
husb: async completed. aurb 0x23aefa0 status 0 alen 1
husb: ctrl type 0xc0 req 0xa1 val 0x3 index 0 len 8
husb: submit ctrl. len 16 aurb 0x23aefa0
husb: async completed. aurb 0x23aefa0 status 0 alen 8
husb: ctrl type 0xc0 req 0xa1 val 0x1 index 0 len 47
husb: submit ctrl. len 55 aurb 0x23aefa0
husb: async completed. aurb 0x23aefa0 status 0 alen 47
husb: ctrl type 0xc0 req 0xa2 val 0x0 index 0 len 1985
husb: submit ctrl. len 1993 aurb 0x23aefa0
husb: async completed. aurb 0x23aefa0 status 0 alen 1985
Segmentation fault (core dumped)
% gdb /usr/local/bin/qemu-system-x86_64 core-qemu-system-x86-5118-1000-1000-11-1246700231
GNU gdb 6.8-debian
Copyright (C) 2008 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.  Type "show copying"
and "show warranty" for details.
This GDB was configured as "x86_64-linux-gnu"...

warning: core file may not match specified executable file.

warning: Can't read pathname for load map: Input/output error.
Reading symbols from /lib/libm.so.6...done.

[snip]

Loaded symbols for /usr/lib/libXfixes.so.3
Core was generated by `qemu-system-x86_64 -no-acpi -hda /home/tomhal/WinXP_eng_32bit_kvm87.img -m 4096'.
Program terminated with signal 11, Segmentation fault.
[New process 5118]
[New process 5119]
[New process 5121]
#0  0x0000000000502f39 in slirp_select_poll (readfds=0x7fffb914cc00,
    writefds=0x7fffb914cb80, xfds=0x7fffb914cb00) at slirp/slirp.c:540
540     slirp/slirp.c: No such file or directory.
        in slirp/slirp.c
(gdb) info threads 
  3 process 5121  0x00007fb259986ded in pthread_cond_timedwait@@GLIBC_2.3.2 ()
   from /lib/libpthread.so.0
  2 process 5119  0x00007fb258ab0977 in ioctl () from /lib/libc.so.6
* 1 process 5118  0x0000000000502f39 in slirp_select_poll (
    readfds=0x7fffb914cc00, writefds=0x7fffb914cb80, xfds=0x7fffb914cb00)
    at slirp/slirp.c:540
(gdb) thread 3
[Switching to thread 3 (process 5121)]#0  0x00007fb259986ded in pthread_cond_timedwait@@GLIBC_2.3.2 () from /lib/libpthread.so.0
(gdb) bt
#0  0x00007fb259986ded in pthread_cond_timedwait@@GLIBC_2.3.2 ()
   from /lib/libpthread.so.0
#1  0x00000000004aa9ae in cond_timedwait (cond=0xbd3a60, mutex=0xbd3a20, 
    ts=0x7fb1553ed080) at posix-aio-compat.c:68
#2  0x00000000004aaf96 in aio_thread (unused=0x0) at posix-aio-compat.c:301
#3  0x00007fb259982f7a in start_thread () from /lib/libpthread.so.0
#4  0x00007fb258ab7a4d in clone () from /lib/libc.so.6
#5  0x0000000000000000 in ?? ()
(gdb) thread 2
[Switching to thread 2 (process 5119)]#0  0x00007fb258ab0977 in ioctl ()
   from /lib/libc.so.6
(gdb) bt
#0  0x00007fb258ab0977 in ioctl () from /lib/libc.so.6
#1  0x000000000053f1b6 in kvm_run (vcpu=0x120f550, env=0x11fd2a0)
    at /usr/src/kvm-87/qemu-kvm.c:979
#2  0x000000000054052b in kvm_cpu_exec (env=0x11fd2a0)
    at /usr/src/kvm-87/qemu-kvm.c:1745
#3  0x0000000000540bdd in kvm_main_loop_cpu (env=0x11fd2a0)
    at /usr/src/kvm-87/qemu-kvm.c:1954
#4  0x0000000000540cfb in ap_main_loop (_env=0x11fd2a0)
    at /usr/src/kvm-87/qemu-kvm.c:1989
#5  0x00007fb259982f7a in start_thread () from /lib/libpthread.so.0
#6  0x00007fb258ab7a4d in clone () from /lib/libc.so.6
#7  0x0000000000000000 in ?? ()
(gdb) thread 1
[Switching to thread 1 (process 5118)]#0  0x0000000000502f39 in slirp_select_poll (readfds=0x7fffb914cc00, writefds=0x7fffb914cb80, xfds=0x7fffb914cb00)
    at slirp/slirp.c:540
540     in slirp/slirp.c
(gdb) bt
#0  0x0000000000502f39 in slirp_select_poll (readfds=0x7fffb914cc00, 
    writefds=0x7fffb914cb80, xfds=0x7fffb914cb00) at slirp/slirp.c:540
#1  0x000000000040e020 in main_loop_wait (timeout=1000)
    at /usr/src/kvm-87/vl.c:4351
#2  0x00000000005410df in kvm_main_loop () at /usr/src/kvm-87/qemu-kvm.c:2139
#3  0x000000000040e56e in main_loop () at /usr/src/kvm-87/vl.c:4537
#4  0x0000000000411a6c in main (argc=15, argv=0x7fffb914d738, 
    envp=0x7fffb914d7b8) at /usr/src/kvm-87/vl.c:6419
(gdb) 

[-- Attachment #5: 4.usbmon.out --]
[-- Type: application/octet-stream, Size: 9764 bytes --]

ffff88032cefb380 214981080 S Ci:4:004:0 s 80 08 0000 0000 0001 1 <
ffff88032cefb380 214984925 C Ci:4:004:0 0 1 = 01
ffff88032cefbd40 218998828 S Co:4:001:0 s 23 03 0004 0001 0000 0
ffff88032cefbd40 218998840 C Co:4:001:0 0 0
ffff88032cefbd40 219205630 S Ci:4:001:0 s a3 00 0000 0001 0004 4 <
ffff88032cefbd40 219205640 C Ci:4:001:0 0 4 = 03030000
ffff88032cefbd40 219265629 S Co:4:001:0 s 23 01 0014 0001 0000 0
ffff88032cefbd40 219265635 C Co:4:001:0 0 0
ffff88032cefbd40 219265681 S Ci:4:000:0 s 80 06 0100 0000 0040 64 <
ffff88032cefbd40 219272642 C Ci:4:000:0 0 18 = 12010002 ff000008 29050100 21030102 0001
ffff88032cefbd40 219272655 S Co:4:001:0 s 23 03 0004 0001 0000 0
ffff88032cefbd40 219272665 C Co:4:001:0 0 0
ffff88032cefb980 219475630 S Ci:4:001:0 s a3 00 0000 0001 0004 4 <
ffff88032cefb980 219475639 C Ci:4:001:0 0 4 = 03030000
ffff88032cefb980 219535632 S Co:4:001:0 s 23 01 0014 0001 0000 0
ffff88032cefb980 219535636 C Co:4:001:0 0 0
ffff88032cefb980 219535638 S Co:4:000:0 s 00 05 0004 0000 0000 0
ffff88032cefb980 219538623 C Co:4:000:0 0 0
ffff88032cefb980 219555629 S Ci:4:004:0 s 80 06 0100 0000 0012 18 <
ffff88032cefb980 219561623 C Ci:4:004:0 0 18 = 12010002 ff000008 29050100 21030102 0001
ffff88032cefb980 219561636 S Ci:4:004:0 s 80 06 0200 0000 0014 20 <
ffff88032cefb980 219567621 C Ci:4:004:0 0 20 = 09021400 01010080 19090400 0000ff00 000002ff
ffff88032cefb980 219567637 S Co:4:004:0 s 00 09 0001 0000 0000 0
ffff88032cefb980 219570620 C Co:4:004:0 0 0
ffff88032cefb980 219650344 S Ci:4:004:0 s 80 06 0100 0000 0040 64 <
ffff88032cefb980 219656616 C Ci:4:004:0 0 18 = 12010002 ff000008 29050100 21030102 0001
ffff88032cefb980 219665692 S Co:4:001:0 s 23 03 0004 0001 0000 0
ffff88032cefb980 219665702 C Co:4:001:0 0 0
ffff88032cefb980 219875629 S Ci:4:001:0 s a3 00 0000 0001 0004 4 <
ffff88032cefb980 219875638 C Ci:4:001:0 0 4 = 03030000
ffff88032cefb980 219935632 S Co:4:001:0 s 23 01 0014 0001 0000 0
ffff88032cefb980 219935635 C Co:4:001:0 0 0
ffff88032cefb980 219935671 S Ci:4:000:0 s 80 06 0100 0000 0040 64 <
ffff88032cefb980 219942597 C Ci:4:000:0 0 18 = 12010002 ff000008 29050100 21030102 0001
ffff88032cefb980 219942611 S Co:4:001:0 s 23 03 0004 0001 0000 0
ffff88032cefb980 219942615 C Co:4:001:0 0 0
ffff88032cefb980 220145629 S Ci:4:001:0 s a3 00 0000 0001 0004 4 <
ffff88032cefb980 220145639 C Ci:4:001:0 0 4 = 03030000
ffff88032cefb980 220205628 S Co:4:001:0 s 23 01 0014 0001 0000 0
ffff88032cefb980 220205635 C Co:4:001:0 0 0
ffff88032cefb980 220205640 S Co:4:000:0 s 00 05 0004 0000 0000 0
ffff88032cefb980 220208578 C Co:4:000:0 0 0
ffff88032e1635c0 220225018 S Ci:4:004:0 s 80 06 0100 0000 0012 18 <
ffff88032e1635c0 220230579 C Ci:4:004:0 0 18 = 12010002 ff000008 29050100 21030102 0001
ffff88032e1635c0 220230594 S Ci:4:004:0 s 80 06 0200 0000 0014 20 <
ffff88032e1635c0 220236578 C Ci:4:004:0 0 20 = 09021400 01010080 19090400 0000ff00 000002ff
ffff88032e1635c0 220236593 S Co:4:004:0 s 00 09 0001 0000 0000 0
ffff88032e1635c0 220239577 C Co:4:004:0 0 0
ffff88032e1635c0 220352824 S Ci:4:004:0 s 80 06 0100 0000 0012 18 <
ffff88032e1635c0 220358569 C Ci:4:004:0 0 18 = 12010002 ff000008 29050100 21030102 0001
ffff88032e1635c0 220364081 S Ci:4:004:0 s 80 06 0200 0000 0009 9 <
ffff88032e1635c0 220368571 C Ci:4:004:0 0 9 = 09021400 01010080 19
ffff88032e1635c0 220373281 S Ci:4:004:0 s 80 06 0200 0000 00ff 255 <
ffff88032e1635c0 220379568 C Ci:4:004:0 0 20 = 09021400 01010080 19090400 0000ff00 000002ff
ffff88032e1635c0 220385542 S Ci:4:004:0 s 80 06 03ee 0000 0012 18 <
ffff88032e1635c0 220387568 C Ci:4:004:0 -32 0
ffff88032e1635c0 220387610 S Ci:4:004:0 s 80 06 03ee 0000 0012 18 <
ffff88032e1635c0 220390568 C Ci:4:004:0 -32 0
ffff88032e1635c0 220390684 S Ci:4:004:0 s 80 06 03ee 0000 0012 18 <
ffff88032e1635c0 220393567 C Ci:4:004:0 -32 0
ffff88032e1635c0 220403006 S Co:4:001:0 s 23 03 0004 0001 0000 0
ffff88032e1635c0 220403012 C Co:4:001:0 0 0
ffff88032e1635c0 220604997 S Ci:4:001:0 s a3 00 0000 0001 0004 4 <
ffff88032e1635c0 220605002 C Ci:4:001:0 0 4 = 03030000
ffff88032e1635c0 220664994 S Co:4:001:0 s 23 01 0014 0001 0000 0
ffff88032e1635c0 220664997 C Co:4:001:0 0 0
ffff88032e1635c0 220665033 S Ci:4:000:0 s 80 06 0100 0000 0040 64 <
ffff88032e1635c0 220671549 C Ci:4:000:0 0 18 = 12010002 ff000008 29050100 21030102 0001
ffff88032e1635c0 220671556 S Co:4:001:0 s 23 03 0004 0001 0000 0
ffff88032e1635c0 220671559 C Co:4:001:0 0 0
ffff88032e1635c0 220874995 S Ci:4:001:0 s a3 00 0000 0001 0004 4 <
ffff88032e1635c0 220875001 C Ci:4:001:0 0 4 = 03030000
ffff88032e1635c0 220934995 S Co:4:001:0 s 23 01 0014 0001 0000 0
ffff88032e1635c0 220934997 C Co:4:001:0 0 0
ffff88032e1635c0 220935000 S Co:4:000:0 s 00 05 0004 0000 0000 0
ffff88032e1635c0 220937532 C Co:4:000:0 0 0
ffff88032d826500 220956248 S Ci:4:004:0 s 80 06 0100 0000 0012 18 <
ffff88032d826500 220961532 C Ci:4:004:0 0 18 = 12010002 ff000008 29050100 21030102 0001
ffff88032d826500 220961548 S Ci:4:004:0 s 80 06 0200 0000 0014 20 <
ffff88032d826500 220967531 C Ci:4:004:0 0 20 = 09021400 01010080 19090400 0000ff00 000002ff
ffff88032d826500 220967544 S Co:4:004:0 s 00 09 0001 0000 0000 0
ffff88032d826500 220970529 C Co:4:004:0 0 0
ffff88032d826500 221056379 S Ci:4:004:0 s 80 06 0100 0000 0040 64 <
ffff88032d826500 221062523 C Ci:4:004:0 0 18 = 12010002 ff000008 29050100 21030102 0001
ffff88032d826500 221074895 S Co:4:001:0 s 23 03 0004 0001 0000 0
ffff88032d826500 221074901 C Co:4:001:0 0 0
ffff88032e061cc0 221095620 C Ii:4:001:1 0:128 1 = 02
ffff88032e061cc0 221095630 S Ii:4:001:1 -115:128 2 <
ffff88032d826500 221276250 S Ci:4:001:0 s a3 00 0000 0001 0004 4 <
ffff88032d826500 221276273 C Ci:4:001:0 0 4 = 03030000
ffff88032d826500 221336246 S Co:4:001:0 s 23 01 0014 0001 0000 0
ffff88032d826500 221336253 C Co:4:001:0 0 0
ffff88032d826500 221336295 S Ci:4:000:0 s 80 06 0100 0000 0040 64 <
ffff88032d826500 221342505 C Ci:4:000:0 0 18 = 12010002 ff000008 29050100 21030102 0001
ffff88032d826500 221342520 S Co:4:001:0 s 23 03 0004 0001 0000 0
ffff88032d826500 221342524 C Co:4:001:0 0 0
ffff88032e061cc0 221345620 C Ii:4:001:1 0:128 1 = 02
ffff88032e061cc0 221345626 S Ii:4:001:1 -115:128 2 <
ffff88032d826500 221546245 S Ci:4:001:0 s a3 00 0000 0001 0004 4 <
ffff88032d826500 221546270 C Ci:4:001:0 0 4 = 03030000
ffff88032d826500 221606244 S Co:4:001:0 s 23 01 0014 0001 0000 0
ffff88032d826500 221606250 C Co:4:001:0 0 0
ffff88032d826500 221606255 S Co:4:000:0 s 00 05 0004 0000 0000 0
ffff88032d826500 221608488 C Co:4:000:0 0 0
ffff88032e1635c0 221624995 S Ci:4:004:0 s 80 06 0100 0000 0012 18 <
ffff88032e1635c0 221630488 C Ci:4:004:0 0 18 = 12010002 ff000008 29050100 21030102 0001
ffff88032e1635c0 221630503 S Ci:4:004:0 s 80 06 0200 0000 0014 20 <
ffff88032e1635c0 221636487 C Ci:4:004:0 0 20 = 09021400 01010080 19090400 0000ff00 000002ff
ffff88032e1635c0 221636501 S Co:4:004:0 s 00 09 0001 0000 0000 0
ffff88032e1635c0 221639485 C Co:4:004:0 0 0
ffff88032e1635c0 221759324 S Ci:4:004:0 s 80 06 0100 0000 0012 18 <
ffff88032e1635c0 221764477 C Ci:4:004:0 0 18 = 12010002 ff000008 29050100 21030102 0001
ffff88032e1635c0 221770552 S Ci:4:004:0 s 80 06 0200 0000 0009 9 <
ffff88032e1635c0 221775476 C Ci:4:004:0 0 9 = 09021400 01010080 19
ffff88032e1635c0 221779773 S Ci:4:004:0 s 80 06 0300 0000 00ff 255 <
ffff88032e1635c0 221784476 C Ci:4:004:0 0 4 = 04030904
ffff88032e1635c0 221787948 S Ci:4:004:0 s 80 06 0302 0409 00ff 255 <
ffff88032e1635c0 221796475 C Ci:4:004:0 0 32 = 20034800 41005300 50002000 48004c00 20003300 2e003200 31000000 00000000
ffff88032e1635c0 221804263 S Ci:4:004:0 s 80 06 0300 0000 00ff 255 <
ffff88032e1635c0 221808474 C Ci:4:004:0 0 4 = 04030904
ffff88032e1635c0 221812454 S Ci:4:004:0 s 80 06 0302 0409 00ff 255 <
ffff88032e1635c0 221820473 C Ci:4:004:0 0 32 = 20034800 41005300 50002000 48004c00 20003300 2e003200 31000000 00000000
ffff88032e247080 305792702 S Ci:4:004:0 s 80 06 0300 0000 00ff 255 <
ffff88032e247080 305796993 C Ci:4:004:0 0 4 = 04030904
ffff88032cefb8c0 305802093 S Ci:4:004:0 s 80 06 0302 0409 00ff 255 <
ffff88032cefb8c0 305810987 C Ci:4:004:0 0 32 = 20034800 41005300 50002000 48004c00 20003300 2e003200 31000000 00000000
ffff88032cefb8c0 305819523 S Ci:4:004:0 s 80 06 0300 0000 00ff 255 <
ffff88032cefb8c0 305823984 C Ci:4:004:0 0 4 = 04030904
ffff88032cefb8c0 305828952 S Ci:4:004:0 s 80 06 0302 0409 00ff 255 <
ffff88032cefb8c0 305836984 C Ci:4:004:0 0 32 = 20034800 41005300 50002000 48004c00 20003300 2e003200 31000000 00000000
ffff88032cefb8c0 305853248 S Ci:4:004:0 s 80 06 0100 0000 0012 18 <
ffff88032cefb8c0 305858988 C Ci:4:004:0 0 18 = 12010002 ff000008 29050100 21030102 0001
ffff88032cefb5c0 305866012 S Ci:4:004:0 s 80 06 0200 0000 0009 9 <
ffff88032cefb5c0 305870982 C Ci:4:004:0 0 9 = 09021400 01010080 19
ffff88032cefb5c0 305874202 S Ci:4:004:0 s 80 06 0200 0000 0024 36 <
ffff88032cefb5c0 305880982 C Ci:4:004:0 0 20 = 09021400 01010080 19090400 0000ff00 000002ff
ffff88032cefb5c0 305888513 S Co:4:004:0 s 00 09 0001 0000 0000 0
ffff88032cefb5c0 305890982 C Co:4:004:0 0 0
ffff88032cefb5c0 305893104 S Ci:4:004:0 s c0 80 522a 0000 0007 7 <
ffff88032cefb5c0 305896983 C Ci:4:004:0 0 7 = 38a3782c 329e24
ffff88032cefb5c0 305901001 S Ci:4:004:0 s c0 a0 0000 0000 0001 1 <
ffff88032cefb5c0 305906980 C Ci:4:004:0 0 1 = 00
ffff88032ccc0a80 312893750 S Ci:4:004:0 s c0 a1 0003 0000 0008 8 <
ffff88032ccc0a80 312897529 C Ci:4:004:0 0 8 = 00001900 00000000
ffff88032ccc0a80 312900974 S Ci:4:004:0 s c0 a1 0001 0000 002f 47 <
ffff88032ccc0a80 312910525 C Ci:4:004:0 0 47 = 61b3d9bf 06010000 02ca000e 000036f2 02140002 00020000 031522c3 0b000000
ffff88032ccc0a80 312919399 S Ci:4:004:0 s c0 a2 0000 0000 07c1 1985 <
ffff88032ccc0a80 313669481 C Ci:4:004:0 0 1985 = ffc00000 00040400 ffc10004 00010001 ffc20005 00fd0002 ffc80102 00080403

Re: KVM crashes when using certain USB device

[G]

On Sat, Jul 4, 2009 at 12:01 PM, G<tjmadwja@gmail.com> wrote:
> On Fri, Jul 3, 2009 at 6:18 PM, Jim Paris<jim@jtan.com> wrote:
>> G wrote:
>>> Hello again,
>>>
>>> I've continued my attempts to get the HASP dongle working, but with no success:

[snip]

>>> Anyone got any ideas what I might try out to find the cause for the
>>> crashes?
>>
>> You might try uncommenting "//#define DEBUG" at the top of usb-linux.c
>> to get some more verbose output from qemu.
>
> Good idea. The results from three test runs after that change are in
> the attached files. The third was done while also dumping the USB bus,
> and the output from that dump is also attached.

I have now also generated USB dumps using Wireshark, which captures
the entire(?) packet contents instead of just the first 32 bytes. Is
anyone interested in analyzing them, perhaps by somehow replaying them
(similar to using tcpreplay) to generate KVM crashes on their machine?
Let me know and I'll mail/post them.

Re: KVM crashes when using certain USB device

[Jim Paris]

[-- Attachment #1: Type: text/plain, Size: 1103 bytes --]

Hi G,

> >> I've continued my attempts to get the HASP dongle working, but with no success:
...
> Good idea. The results from three test runs after that change are in
> the attached files. The third was done while also dumping the USB bus,
> and the output from that dump is also attached.

The gdb output here looks questionable.  Only the second trial seems
to have USB related stuff in the backtrace, so either gdb is wrong or
there's some memory corruption that is causing crashes elsewhere.
Maybe valgrind could help?

You can also add more debugging to the usb code to try to figure out
where things are going wrong.  See the attached patch for some printfs
that might help.

Try again with less memory on the guest, like -m 2048, just to reduce
possible problems with the 32-bit guest and address space.

I didn't see anything obviously wrong with the usbmon dumps you sent,
or the debugging that qemu printed out, but I'm not familiar with this
code.

Even though you're having problems with -no-kvm, I suspect this is an
upstream qemu issue, so you should probably try the qemu list too.

-jim

[-- Attachment #2: debug.patch --]
[-- Type: text/x-patch, Size: 1289 bytes --]

diff -urN kvm-87/usb-linux.c kvm-87-debug/usb-linux.c
--- kvm-87/usb-linux.c	2009-06-23 09:32:38.000000000 -0400
+++ kvm-87-debug/usb-linux.c	2009-07-16 03:06:22.000000000 -0400
@@ -209,16 +209,21 @@
 
 static AsyncURB *async_alloc(void)
 {
-    return (AsyncURB *) qemu_mallocz(sizeof(AsyncURB));
+    AsyncURB *aurb = (AsyncURB *) qemu_mallocz(sizeof(AsyncURB));
+    dprintf("husb: allocated %p\n", aurb);
+    return aurb;
 }
 
 static void async_free(AsyncURB *aurb)
 {
+    dprintf("husb: freeing %p\n", aurb);
     qemu_free(aurb);
 }
 
 static void async_complete_ctrl(USBHostDevice *s, USBPacket *p)
 {
+    dprintf("husb: complete ctrl, host state %d len %d\n", 
+	    s->ctrl.state, s->ctrl.len);
     switch(s->ctrl.state) {
     case CTRL_STATE_SETUP:
         if (p->len < s->ctrl.len)
@@ -266,6 +271,7 @@
                 aurb, aurb->urb.status, aurb->urb.actual_length);
 
 	if (p) {
+	    dprintf("husb: p=%p\n", p);
             switch (aurb->urb.status) {
             case 0:
                 p->len = aurb->urb.actual_length;
@@ -280,11 +286,12 @@
                 p->len = USB_RET_NAK;
                 break;
             }
-
+	    dprintf("husb: completing, p->len=%d\n", p->len);
             usb_packet_complete(p);
 	}
 
         async_free(aurb);
+
     }
 }
 

Re: KVM crashes when using certain USB device

[G]

[-- Attachment #1: Type: text/plain, Size: 2750 bytes --]

On Thu, Jul 16, 2009 at 9:15 AM, Jim Paris<jim@jtan.com> wrote:
> Hi G,
>
>> >> I've continued my attempts to get the HASP dongle working, but with no success:
> ...
>> Good idea. The results from three test runs after that change are in
>> the attached files. The third was done while also dumping the USB bus,
>> and the output from that dump is also attached.
>
> The gdb output here looks questionable.  Only the second trial seems
> to have USB related stuff in the backtrace, so either gdb is wrong or
> there's some memory corruption that is causing crashes elsewhere.

My guess is that the usb code in kvm/qemu causes memory corruption
that is triggering these crashes. The crashes are definitely caused by
my use of the HASP HL USB dongle.

> Maybe valgrind could help?

To some extent. I've run three tests using valgrind, and there are
some messages that to me seem to indicate memory errors ("Invalid read
of size 1"). However, running with valgrind doesn't give me any core
files when it crashes.

I'm not too familiar with valgrind output, I have only used it on
smaller programs I've written myself, so I don't know what to think of
the messages (and amount of messages; valgrind told me to use
--error-limit=no). I do get a bit nervous from all the complaints
about uninitialized values  and byes, but maybe it's normal for an
application of kvm's size and type.

> You can also add more debugging to the usb code to try to figure out
> where things are going wrong.  See the attached patch for some printfs
> that might help.

I have applied that patch (and also uncommented the DEBUG flag).

> Try again with less memory on the guest, like -m 2048, just to reduce
> possible problems with the 32-bit guest and address space.

Done in these test runs.

Attached to this mail is a tarball containing a bunch of files. The
first and third testrun, doing things in a different order, have
output from the qemu monitor (including all debug printf()s),
valgrind, and usb sniffs generated by wireshark. The second testrun
only have qemu monitor and valgrind output. I have inserted some
comments in the qemu monitor and valgrind files, look for square
brackets at the beginning of lines to find them.

> I didn't see anything obviously wrong with the usbmon dumps you sent,
> or the debugging that qemu printed out, but I'm not familiar with this
> code.
>
> Even though you're having problems with -no-kvm, I suspect this is an
> upstream qemu issue, so you should probably try the qemu list too.

qemu-devel@nongnu.org? I'll try to figure out the -no-kvm issue first,
so I can run any commands they might want me to run.

And thanks for your help and suggestions so far, btw.

[-- Attachment #2: test_with_valgrind.tgz --]
[-- Type: application/x-gzip, Size: 67632 bytes --]

Re: KVM crashes when using certain USB device

[Erik Rull]

Hi there,

try to switch to USB 1.1 - not the best way but this helped my Windows XP 
running and doing things like printing, formatting USB keys or using a 
Dongle (Aladin, I think, it's also HASP)
USB 2.0 was not really working well with KVM :-(

Best regards,

Erik


G wrote:
> On Thu, Jul 16, 2009 at 9:15 AM, Jim Paris<jim@jtan.com> wrote:
>> Hi G,
>>
>>>>> I've continued my attempts to get the HASP dongle working, but with no success:

Re: KVM crashes when using certain USB device

[Jim Paris]

G wrote:
> I'm not too familiar with valgrind output, I have only used it on
> smaller programs I've written myself, so I don't know what to think of
> the messages (and amount of messages; valgrind told me to use
> --error-limit=no). I do get a bit nervous from all the complaints
> about uninitialized values  and byes, but maybe it's normal for an
> application of kvm's size and type.

I'd be nervous too :)  Many of the complaints look harmless, but it's
probably worth fixing them to make the real bugs stand out more.

> > Even though you're having problems with -no-kvm, I suspect this is an
> > upstream qemu issue, so you should probably try the qemu list too.
> 
> qemu-devel@nongnu.org? I'll try to figure out the -no-kvm issue first,
> so I can run any commands they might want me to run.
> 
> And thanks for your help and suggestions so far, btw.

Here's a patch to try.  I'm not familiar with the code, but it looks
like this buffer might be too small versus the packet lengths that
you're seeing, and similar definitions in hw/usb-uhci.c.

-jim

diff -urN kvm-87-orig/usb-linux.c kvm-87/usb-linux.c
--- kvm-87-orig/usb-linux.c	2009-06-23 09:32:38.000000000 -0400
+++ kvm-87/usb-linux.c	2009-07-20 19:15:35.000000000 -0400
@@ -115,7 +115,7 @@
     uint16_t offset;
     uint8_t  state;
     struct   usb_ctrlrequest req;
-    uint8_t  buffer[1024];
+    uint8_t  buffer[2048];
 };
 
 typedef struct USBHostDevice {

Re: KVM crashes when using certain USB device

[G]

On Tue, Jul 21, 2009 at 1:23 AM, Jim Paris<jim@jtan.com> wrote:
> G wrote:

>> And thanks for your help and suggestions so far, btw.
>
> Here's a patch to try.  I'm not familiar with the code, but it looks
> like this buffer might be too small versus the packet lengths that
> you're seeing, and similar definitions in hw/usb-uhci.c.
>
> -jim
>
> diff -urN kvm-87-orig/usb-linux.c kvm-87/usb-linux.c
> --- kvm-87-orig/usb-linux.c     2009-06-23 09:32:38.000000000 -0400
> +++ kvm-87/usb-linux.c  2009-07-20 19:15:35.000000000 -0400
> @@ -115,7 +115,7 @@
>     uint16_t offset;
>     uint8_t  state;
>     struct   usb_ctrlrequest req;
> -    uint8_t  buffer[1024];
> +    uint8_t  buffer[2048];
>  };
>
>  typedef struct USBHostDevice {

Yes! Applying this patch makes the crash go away! Thank you!

In addition to enabling DEBUG and applying your debug printout
patches, I added a debug printout right above the memcpy()s in
usb-linux.c, and found that the memcpy() in do_token_in() is called
multiple time (since do_token_in() is called multiple times for the
1993 bytes usb packet I have in my usb sniff dumps), which I guess is
what's causing a buffer overflow as the offset is pushed beyond 1024
bytes. But I'm not sure.

I've looked at the code trying to figure out a better way to solve
this, now that the problem spot has been found. To me it seems that
malloc()ing and, when the need arises (the large 1993 bytes packets
I'm seeing), realloc()ing the buffer, instead of using a statically
sized buffer, would be the best solution. However, I cannot find a
suitable place to do this, so in the meantime I'll use your patch,
although I do hope the kvm developers will implement a more
stable/reliable malloc()/realloc() solution in the future. 1993 bytes
isn't far from the 2048 bytes limit, and it seems to me that there are
more places in the usb code where statically sized buffer are used
which could lead to more problems of this kind. One could of course
redefine all buffers to be 8192 bytes instead, but that would just be
a false sense of security, and perhaps some buffers need to be of a
particular size to conform to the USB specification...

The differences between the usb code in  kvm-72 (which works without a
patch) and kvm-87 are too big for me to try to find out why it works
in kvm-72.

Anyways, I'm happy. Once again, thanks.

Re: KVM crashes when using certain USB device

[Jim Paris]

G wrote:
> On Tue, Jul 21, 2009 at 1:23 AM, Jim Paris<jim@jtan.com> wrote:
> > Here's a patch to try.  I'm not familiar with the code, but it looks
> > like this buffer might be too small versus the packet lengths that
> > you're seeing, and similar definitions in hw/usb-uhci.c.
> >
> > -jim
> >
> > diff -urN kvm-87-orig/usb-linux.c kvm-87/usb-linux.c
> > --- kvm-87-orig/usb-linux.c     2009-06-23 09:32:38.000000000 -0400
> > +++ kvm-87/usb-linux.c  2009-07-20 19:15:35.000000000 -0400
> > @@ -115,7 +115,7 @@
> >     uint16_t offset;
> >     uint8_t  state;
> >     struct   usb_ctrlrequest req;
> > -    uint8_t  buffer[1024];
> > +    uint8_t  buffer[2048];
> >  };
> >
> >  typedef struct USBHostDevice {
> 
> Yes! Applying this patch makes the crash go away! Thank you!

Great!

> In addition to enabling DEBUG and applying your debug printout
> patches, I added a debug printout right above the memcpy()s in
> usb-linux.c, and found that the memcpy() in do_token_in() is called
> multiple time (since do_token_in() is called multiple times for the
> 1993 bytes usb packet I have in my usb sniff dumps), which I guess is
> what's causing a buffer overflow as the offset is pushed beyond 1024
> bytes. But I'm not sure.

Yeah, I think that's it.

> I've looked at the code trying to figure out a better way to solve
> this, now that the problem spot has been found. To me it seems that
> malloc()ing and, when the need arises (the large 1993 bytes packets
> I'm seeing), realloc()ing the buffer, instead of using a statically
> sized buffer, would be the best solution.

Dynamically sizing the buffer might get tricky.  It looks like
hw/usb-uhci.c will go up to 2048, while hw/usb-ohci.c and
hw/usb-musb.c could potentially go up to 8192.  I think bumping it to
8192 and adding an error instead of overflowing would be good enough.
I'll try to understand the code a bit more and then spin a patch.

> One could of course redefine all buffers to be 8192 bytes instead,
> but that would just be a false sense of security, and perhaps some
> buffers need to be of a particular size to conform to the USB
> specification...

USB packets don't get that large, but the host controllers can combine
them, from what I understand.  So it's more a question of what the
host controllers can do.

-jim