[Qemu-devel] [Bug 1222034] Re: QEMU + SPICE + AUDIO = FAILURE

[will <renevant@internode.on.net>]

Here is the dmesg that occurs inside the guest using any recent qemu
upstream build for me:

[  248.943541] input: spice vdagent tablet as /devices/virtual/input/input6
[  677.164385] input: spice vdagent tablet as /devices/virtual/input/input7
[183308.532032] INFO: rcu_sched self-detected stall on CPU { 1}  (t=22338 jiffies g=1183551 c=1183550 q=30)
[183308.532032] sending NMI to all CPUs:
[183308.532032] NMI backtrace for cpu 1
[183308.532032] CPU: 1 PID: 2765 Comm: alsa-sink-ID 22 Tainted: G        W    3.10-2-amd64 #1 Debian 3.10.7-1
[183308.532032] Hardware name: Bochs Bochs, BIOS Bochs 01/01/2011
[183308.532032] task: ffff88007b1a3840 ti: ffff88007b1b2000 task.ti: ffff88007b1b2000
[183308.532032] RIP: 0010:[<ffffffff8102e321>]  [<ffffffff8102e321>] native_write_msr_safe+0x6/0x9
[183308.532032] RSP: 0018:ffff88007fd03e18  EFLAGS: 00000046
[183308.532032] RAX: 0000000000000400 RBX: 0000000000000001 RCX: 0000000000000830
[183308.532032] RDX: 0000000000000001 RSI: 0000000000000400 RDI: 0000000000000830
[183308.532032] RBP: 000000000000b0ca R08: ffffffff81693c40 R09: ffffffff814f1e2a
[183308.532032] R10: 0000000000000000 R11: ffff880000000000 R12: 0000000000000002
[183308.532032] R13: ffffffff81693c40 R14: 0000000000000001 R15: 0000000000080000
[183308.532032] FS:  00007f0cb7b1f700(0000) GS:ffff88007fd00000(0000) knlGS:0000000000000000
[183308.532032] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[183308.532032] CR2: 00007f0cbd234000 CR3: 000000007b3e0000 CR4: 00000000000406e0
[183308.532032] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[183308.532032] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
[183308.532032] Stack:
[183308.532032]  ffffffff8102a739 ffffffff8102a85c 0000000000000086 0000000000002710
[183308.532032]  ffff88007fd0e8e0 ffffffff8163cd00 ffff88007fd0e2b0 ffff88007b1b2000
[183308.532032]  0000000000000001 ffffffff8102829b ffffffff8163cd00 ffffffff810a0a53
[183308.532032] Call Trace:
[183308.532032]  <IRQ>
[183308.532032]  [<ffffffff8102a739>] ? paravirt_write_msr+0xb/0xe
[183308.532032]  [<ffffffff8102a85c>] ? __x2apic_send_IPI_mask+0x70/0xa5
[183308.532032]  [<ffffffff8102829b>] ? arch_trigger_all_cpu_backtrace+0x4d/0x7e
[183308.532032]  [<ffffffff810a0a53>] ? rcu_check_callbacks+0x1a4/0x4bb
[183308.532032]  [<ffffffff81079937>] ? tick_sched_do_timer+0x25/0x25
[183308.532032]  [<ffffffff810484b7>] ? update_process_times+0x31/0x5c
[183308.532032]  [<ffffffff8107969b>] ? tick_sched_handle+0x3e/0x4a
[183308.532032]  [<ffffffff81079967>] ? tick_sched_timer+0x30/0x4c
[183308.532032]  [<ffffffff81059923>] ? __run_hrtimer+0xac/0x151
[183308.532032]  [<ffffffff8105a196>] ? hrtimer_interrupt+0xbd/0x19e
[183308.532032]  [<ffffffff81027840>] ? smp_apic_timer_interrupt+0x6d/0x7e
[183308.532032]  [<ffffffff8138b9dd>] ? apic_timer_interrupt+0x6d/0x80
[183308.532032]  <EOI>
[183308.532032]  [<ffffffffa01b1648>] ? snd_timer_user_append_to_tqueue+0x3f/0x3f [snd_timer]
[183308.532032]  [<ffffffffa0200905>] ? arch_local_irq_enable+0x4/0x8 [snd_pcm]
[183308.532032]  [<ffffffffa0202299>] ? snd_pcm_action_lock_irq+0x91/0x9d [snd_pcm]
[183308.532032]  [<ffffffffa0204070>] ? snd_pcm_common_ioctl1+0x3f2/0xaed [snd_pcm]
[183308.532032]  [<ffffffffa01d2a95>] ? snd_ctl_ioctl+0x2eb/0x65f [snd]
[183308.532032]  [<ffffffff810f901d>] ? kfree+0x50/0x6f
[183308.532032]  [<ffffffffa0204c11>] ? snd_pcm_playback_ioctl1+0x230/0x24d [snd_pcm]
[183308.532032]  [<ffffffff81114e49>] ? do_filp_open+0x2a/0x6e
[183308.532032]  [<ffffffffa0204c54>] ? snd_pcm_playback_ioctl+0x26/0x29 [snd_pcm]
[183308.532032]  [<ffffffff81115f74>] ? vfs_ioctl+0x1b/0x25
[183308.532032]  [<ffffffff81116795>] ? do_vfs_ioctl+0x3e8/0x42a
[183308.532032]  [<ffffffff8107d0b7>] ? SyS_futex+0x133/0x165
[183308.532032]  [<ffffffff8110a6b5>] ? fput+0xe/0xb6
[183308.532032]  [<ffffffff81116825>] ? SyS_ioctl+0x4e/0x79
[183308.532032]  [<ffffffff8138ade9>] ? system_call_fastpath+0x16/0x1b
[183308.532032] Code: 0f 01 f9 48 c1 e2 20 89 0f 48 09 c2 48 89 d0 c3 89 f9 0f 32 31 ff 48 c1 e2 20 89 c0 89 3e 48 09 c2 48 89 d0 c3 89 f0 89 f9 0f 30 <31> c0 c3 89 f9 0f 33 48 c1 e2 20 89 c0 48 09 c2 48 89 d0 c3 66
[183308.535258] NMI backtrace for cpu 0
[183308.535258] CPU: 0 PID: 0 Comm: swapper/0 Tainted: G        W    3.10-2-amd64 #1 Debian 3.10.7-1
[183308.535258] Hardware name: Bochs Bochs, BIOS Bochs 01/01/2011
[183308.535258] task: ffffffff81613400 ti: ffffffff81600000 task.ti: ffffffff81600000
[183308.535258] RIP: 0010:[<ffffffffa01f1a67>]  [<ffffffffa01f1a67>] azx_get_position+0x4d/0x259 [snd_hda_intel]
[183308.535258] RSP: 0018:ffff88007fc03dd8  EFLAGS: 00000046
[183308.535258] RAX: ffffc900003b8160 RBX: ffff88007bfd9de8 RCX: 0000000000000000
[183308.535258] RDX: 0000000000000000 RSI: 0000000000000000 RDI: ffff880037287000
[183308.535258] RBP: 0000000000001200 R08: ffff88007cc00050 R09: 0000000000000034
[183308.535258] R10: 0000000000000001 R11: 0000000000000000 R12: ffff880037287000
[183308.535258] R13: ffff88007b7e4780 R14: 0000000000000074 R15: ffff88007cad4400
[183308.535258] FS:  00007f6045ffd700(0000) GS:ffff88007fc00000(0000) knlGS:0000000000000000
[183308.535258] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
[183308.535258] CR2: 00007f1f10013000 CR3: 0000000059a83000 CR4: 00000000000406f0
[183308.535258] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[183308.535258] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
[183308.535258] Stack:
[183308.535258]  ffffffff811bcb21 ffff880037384478 ffff88007cad4400 ffff88007fc03ea8
[183308.535258]  0000000000000086 0000000000000007 0000000000000000 ffff88007bd41400
[183308.535258]  ffffffffa01f1d3c ffff88007cad4400 ffffffffa0207c07 ffff88007fd13f40
[183308.535258] Call Trace:
[183308.535258]  <IRQ>
[183308.535258]  [<ffffffff811bcb21>] ? __cfq_slice_expired+0x20c/0x23f
[183308.535258]  [<ffffffffa01f1d3c>] ? azx_pcm_pointer+0x20/0x3a [snd_hda_intel]
[183308.535258]  [<ffffffffa0207c07>] ? snd_pcm_update_hw_ptr0+0x38/0x316 [snd_pcm]
[183308.535258]  [<ffffffff8102e18f>] ? kvm_clock_read+0x1b/0x1c
[183308.535258]  [<ffffffff8107338b>] ? timekeeping_get_ns.constprop.10+0xd/0x31
[183308.535258]  [<ffffffff81073615>] ? ktime_get+0x5f/0x6b
[183308.535258]  [<ffffffff8102a739>] ? paravirt_write_msr+0xb/0xe
[183308.535258]  [<ffffffffa0207fca>] ? snd_pcm_period_elapsed+0xe5/0xf4 [snd_pcm]
[183308.535258]  [<ffffffffa01f39b4>] ? azx_interrupt+0xc0/0x15a [snd_hda_intel]
[183308.535258]  [<ffffffff81099734>] ? handle_irq_event_percpu+0x49/0x1a4
[183308.535258]  [<ffffffff810998c1>] ? handle_irq_event+0x32/0x4b
[183308.535258]  [<ffffffff8109bc61>] ? handle_edge_irq+0xa2/0xcc
[183308.535258]  [<ffffffff8100e93e>] ? handle_irq+0x18/0x20
[183308.535258]  [<ffffffff8100e657>] ? do_IRQ+0x40/0x95
[183308.535258]  [<ffffffff81385d2d>] ? common_interrupt+0x6d/0x6d
[183308.535258]  <EOI>
[183308.535258]  [<ffffffff8102e385>] ? native_safe_halt+0x2/0x3
[183308.535258]  [<ffffffff810133f6>] ? default_idle+0x17/0x3f
[183308.535258]  [<ffffffff81072590>] ? cpu_startup_entry+0x10d/0x187
[183308.535258]  [<ffffffff816b3d3d>] ? start_kernel+0x3e8/0x3f3
[183308.535258]  [<ffffffff816b3777>] ? repair_env_string+0x54/0x54
[183308.535258]  [<ffffffff816b3598>] ? x86_64_start_kernel+0xf2/0xfd
[183308.535258] Code: ce 49 8b 44 cd 18 4c 8d 71 74 48 89 44 24 08 42 8b 44 b7 08 83 f8 01 74 0b 83 f8 03 0f 85 a6 00 00 00 eb 0c 48 8b 43 58 8b 68 04 <e9> dd 00 00 00 48 8b 43 58 8b 48 04 48 8b 43 68 89 cd 83 78 3c
[183398.171091] [sched_delayed] sched: RT throttling activated
[183460.564042] INFO: rcu_sched detected stalls on CPUs/tasks: { 0} (detected by 1, t=38280 jiffies, g=1183551, c=1183550, q=569)
[183460.564042] sending NMI to all CPUs:
[183460.564042] NMI backtrace for cpu 1
[183460.564042] CPU: 1 PID: 2765 Comm: alsa-sink-ID 22 Tainted: G        W    3.10-2-amd64 #1 Debian 3.10.7-1
[183460.564042] Hardware name: Bochs Bochs, BIOS Bochs 01/01/2011
[183460.564042] task: ffff88007b1a3840 ti: ffff88007b1b2000 task.ti: ffff88007b1b2000
[183460.564042] RIP: 0010:[<ffffffff8102e321>]  [<ffffffff8102e321>] native_write_msr_safe+0x6/0x9
[183460.564042] RSP: 0018:ffff88007fd03e18  EFLAGS: 00000046
[183460.564042] RAX: 0000000000000400 RBX: 0000000000000001 RCX: 0000000000000830
[183460.564042] RDX: 0000000000000001 RSI: 0000000000000400 RDI: 0000000000000830
[183460.564042] RBP: 000000000000b0ca R08: ffffffff81693c40 R09: ffffffff814f1e2a
[183460.564042] R10: 0000000000000000 R11: 0000000000000200 R12: 0000000000000002
[183460.564042] R13: ffffffff81693c40 R14: 0000000000000001 R15: 0000000000080000
[183460.564042] FS:  00007f0cb7b1f700(0000) GS:ffff88007fd00000(0000) knlGS:0000000000000000
[183460.564042] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[183460.564042] CR2: 00007f4ccff00000 CR3: 000000007b3e0000 CR4: 00000000000406e0
[183460.564042] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[183460.564042] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
[183460.564042] Stack:
[183460.564042]  ffffffff8102a739 ffffffff8102a85c 0000000000000086 0000000000002710
[183460.564042]  ffff88007fd0e8e0 ffffffff8163cd00 0000000000000001 ffff88007b1b2000
[183460.564042]  ffffffff8163cdc0 ffffffff8102829b ffffffff8163cd00 ffffffff810a0c8b
[183460.564042] Call Trace:
[183460.564042]  <IRQ>
[183460.564042]  [<ffffffff8102a739>] ? paravirt_write_msr+0xb/0xe
[183460.564042]  [<ffffffff8102a85c>] ? __x2apic_send_IPI_mask+0x70/0xa5
[183460.564042]  [<ffffffff8102829b>] ? arch_trigger_all_cpu_backtrace+0x4d/0x7e
[183460.564042]  [<ffffffff810a0c8b>] ? rcu_check_callbacks+0x3dc/0x4bb
[183460.564042]  [<ffffffff81079937>] ? tick_sched_do_timer+0x25/0x25
[183460.564042]  [<ffffffff810484b7>] ? update_process_times+0x31/0x5c
[183460.564042]  [<ffffffff8107969b>] ? tick_sched_handle+0x3e/0x4a
[183460.564042]  [<ffffffff81079967>] ? tick_sched_timer+0x30/0x4c
[183460.564042]  [<ffffffff81059923>] ? __run_hrtimer+0xac/0x151
[183460.564042]  [<ffffffff8105a196>] ? hrtimer_interrupt+0xbd/0x19e
[183460.564042]  [<ffffffff81027840>] ? smp_apic_timer_interrupt+0x6d/0x7e
[183460.564042]  [<ffffffff8138b9dd>] ? apic_timer_interrupt+0x6d/0x80
[183460.564042]  <EOI>
[183460.564042]  [<ffffffffa0200905>] ? arch_local_irq_enable+0x4/0x8 [snd_pcm]
[183460.564042]  [<ffffffffa02023d8>] ? snd_pcm_stream_unlock_irq+0x18/0x19 [snd_pcm]
[183460.564042]  [<ffffffffa02025e9>] ? snd_pcm_hwsync+0x58/0x5d [snd_pcm]
[183460.564042]  [<ffffffffa020432e>] ? snd_pcm_common_ioctl1+0x6b0/0xaed [snd_pcm]
[183460.564042]  [<ffffffffa01d2a95>] ? snd_ctl_ioctl+0x2eb/0x65f [snd]
[183460.564042]  [<ffffffff810f901d>] ? kfree+0x50/0x6f
[183460.564042]  [<ffffffffa0204c11>] ? snd_pcm_playback_ioctl1+0x230/0x24d [snd_pcm]
[183460.564042]  [<ffffffff811181b6>] ? spin_unlock+0x5/0x6
[183460.564042]  [<ffffffff81119658>] ? dput+0x27/0xf3
[183460.564042]  [<ffffffffa0204c54>] ? snd_pcm_playback_ioctl+0x26/0x29 [snd_pcm]
[183460.564042]  [<ffffffff81115f74>] ? vfs_ioctl+0x1b/0x25
[183460.564042]  [<ffffffff81116795>] ? do_vfs_ioctl+0x3e8/0x42a
[183460.564042]  [<ffffffff8105eae9>] ? mmdrop+0xd/0x1c
[183460.564042]  [<ffffffff8105f734>] ? finish_task_switch+0x81/0xaa
[183460.564042]  [<ffffffff81384e35>] ? __schedule+0x4dc/0x532
[183460.564042]  [<ffffffff81116825>] ? SyS_ioctl+0x4e/0x79
[183460.564042]  [<ffffffff8138ade9>] ? system_call_fastpath+0x16/0x1b
[183460.564042] Code: 0f 01 f9 48 c1 e2 20 89 0f 48 09 c2 48 89 d0 c3 89 f9 0f 32 31 ff 48 c1 e2 20 89 c0 89 3e 48 09 c2 48 89 d0 c3 89 f0 89 f9 0f 30 <31> c0 c3 89 f9 0f 33 48 c1 e2 20 89 c0 48 09 c2 48 89 d0 c3 66
[183459.216873] NMI backtrace for cpu 0
[183459.216873] CPU: 0 PID: 0 Comm: swapper/0 Tainted: G        W    3.10-2-amd64 #1 Debian 3.10.7-1
[183459.216873] Hardware name: Bochs Bochs, BIOS Bochs 01/01/2011
[183459.216873] task: ffffffff81613400 ti: ffffffff81600000 task.ti: ffffffff81600000
[183459.216873] RIP: 0010:[<ffffffffa01f1c84>]  [<ffffffffa01f1c84>] azx_position_ok+0x11/0xa9 [snd_hda_intel]
[183459.216873] RSP: 0018:ffff88007fc03da0  EFLAGS: 00000002
[183459.216873] RAX: ffffc900003b8000 RBX: ffff88007bfd9de8 RCX: ffffc900003b8160
[183459.216873] RDX: 000000000000541c RSI: ffff88007bfd9de8 RDI: ffff880037287000
[183459.216873] RBP: 000000000164e960 R08: ffff88007cc00050 R09: 0000000000000034
[183459.216873] R10: 0000000000000103 R11: 000000000000b8a3 R12: ffff880037287000
[183459.216873] R13: 0000000000000007 R14: 0000000080000080 R15: ffff880037287208
[183459.216873] FS:  00007f6045ffd700(0000) GS:ffff88007fc00000(0000) knlGS:0000000000000000
[183459.216873] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
[183459.216873] CR2: 00007f1f10013000 CR3: 0000000059a83000 CR4: 00000000000406f0
[183459.216873] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[183459.216873] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
[183459.216873] Stack:
[183459.216873]  ffff880037287000 ffff88007bfd9de8 ffff880037287044 ffffffffa01f399a
[183459.216873]  ffff88007befe3c0 0000000000000032 ffff88007a4a9800 0000000000000000
[183459.216873]  ffffffff81601fd8 0000000000000000 ffffffff81099734 000000000000080b
[183459.216873] Call Trace:
[183459.216873]  <IRQ>
[183459.216873]  [<ffffffffa01f399a>] ? azx_interrupt+0xa6/0x15a [snd_hda_intel]
[183459.216873]  [<ffffffff81099734>] ? handle_irq_event_percpu+0x49/0x1a4
[183459.216873]  [<ffffffff810998c1>] ? handle_irq_event+0x32/0x4b
[183459.216873]  [<ffffffff8109bc61>] ? handle_edge_irq+0xa2/0xcc
[183459.216873]  [<ffffffff8100e93e>] ? handle_irq+0x18/0x20
[183459.216873]  [<ffffffff8100e657>] ? do_IRQ+0x40/0x95
[183459.216873]  [<ffffffff81385d2d>] ? common_interrupt+0x6d/0x6d
[183459.216873]  [<ffffffff81060626>] ? ttwu_do_wakeup+0xf/0xc1
[183459.216873]  [<ffffffff8104196f>] ? arch_local_irq_enable+0x4/0x8
[183459.216873]  [<ffffffff8104215e>] ? __do_softirq+0x8e/0x205
[183459.216873]  [<ffffffff8104239f>] ? irq_exit+0x3e/0x81
[183459.216873]  [<ffffffff81027845>] ? smp_apic_timer_interrupt+0x72/0x7e
[183459.216873]  [<ffffffff8138b9dd>] ? apic_timer_interrupt+0x6d/0x80
[183459.216873]  <EOI>
[183459.216873]  [<ffffffff8102e385>] ? native_safe_halt+0x2/0x3
[183459.216873]  [<ffffffff810133f6>] ? default_idle+0x17/0x3f
[183459.216873]  [<ffffffff81072590>] ? cpu_startup_entry+0x10d/0x187
[183459.216873]  [<ffffffff816b3d3d>] ? start_kernel+0x3e8/0x3f3
[183459.216873]  [<ffffffff816b3777>] ? repair_env_string+0x54/0x54
[183459.216873]  [<ffffffff816b3598>] ? x86_64_start_kernel+0xf2/0xfd
[183459.216873] Code: 00 00 4d 85 ed 75 d4 eb f0 48 83 c4 10 89 e8 5b 5d 41 5c 41 5d 41 5e 41 5f c3 41 54 49 89 fc 55 53 48 89 f3 48 8b 47 38 8b 68 30 <48> 8b 46 50 31 d2 b9 03 00 00 00 2b 6e 48 48 01 c0 48 f7 f1 48

-- 
You received this bug notification because you are a member of qemu-
devel-ml, which is subscribed to QEMU.
https://bugs.launchpad.net/bugs/1222034

Title:
  QEMU + SPICE + AUDIO = FAILURE

Status in QEMU:
  New

Bug description:
  Hello it's my first time doing this, since the major round of
  timer/block changes in August I have not been able to have audio
  working in any guest with the spice protocol.

  64 bit linux , AMD SVM, IOMMUv1  ASUS M5A99FX PRO R2.0

  Example command line:

  qemu-system-x86_64 -m 1024 -cdrom Sabayon_Linux_DAILY_x86_Xfce.iso
  -soundhw hda -vga qxl -spice port=5999,addr=0.0.0.0,disable-ticketing
  -enable-kvm -device virtio-serial-pci -device
  virtserialport,chardev=spicechannel0,name=com.redhat.spice.0 -chardev
  spicevmc,id=spicechannel0,name=vdagent

  Any time the guest tries to access the emulated hardware it will hang
  for a very long period of time and play no audio through spice. It
  doesn't seem to matter what guest (x86_64 or x86) I run (the above is
  just one example) and it also doesn't matter what sound hardware I
  choose to emulate or which command line method I use to specify it (ie
  -soundhw doesn't work and neither does -device) or whether a vdagent
  service has been configured correctly inside the guest or not.

  This issue does not happen with the 1.6.0 release.

  If you are unable to replicate this I will go to the trouble of
  getting the race message that happens in the guest but I am assuming
  at this point that my configuration is not exotic and it should be
  very easy to see the issue.

To manage notifications about this bug go to:
https://bugs.launchpad.net/qemu/+bug/1222034/+subscriptions