instruction: 0.982
network: 0.979
assembly: 0.978
device: 0.976
socket: 0.970
other: 0.965
mistranslation: 0.945
boot: 0.943
graphic: 0.942
semantic: 0.934
vnc: 0.912
KVM: 0.891

QEMU + SPICE + AUDIO = FAILURE

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  M5A99X EVO R2.0


Example command line:

qemu-system-x86_64 -m 1024 -cdrom /common/stor8/torrents/Sabayon_Linux_DAILY_x86_Xfce.iso -soundhw hda -vga qxl -spice port=5999,addr=0.0.0.0,disable-ticketing  -enable-kvm



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. 

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.

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


That above example is from a debian x64 guest.

Looking through old bug tickets... can you still reproduce this issue with the latest version of QEMU and a recent guest kernel? Or could we close this ticket nowadays?

[Expired for QEMU because there has been no activity for 60 days.]