Bug 1451015

Summary: Qemu core dump when do 'quit ' in HMP via ide drive.
Product: Red Hat Enterprise Linux 7 Reporter: CongLi <coli>
Component: qemu-kvm-rhevAssignee: Dr. David Alan Gilbert <dgilbert>
Status: CLOSED ERRATA QA Contact: aihua liang <aliang>
Severity: unspecified Docs Contact:
Priority: unspecified    
Version: 7.4CC: armbru, chayang, jsnow, juzhang, knoel, lolyu, michen, mrezanin, virt-maint
Target Milestone: rc   
Target Release: ---   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: qemu-kvm-rhev-2.10.0-1.el7 Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2018-04-11 00:19:31 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:

Description CongLi 2017-05-15 14:51:06 UTC
Description of problem:
Qemu core dump when do 'quit ' in HMP via ide drive.

gdb bt info:
Core was generated by `/usr/libexec/qemu-kvm -S -name virt-tests-vm1 -nodefaults -chardev socket,id=qm'.
Program terminated with signal 11, Segmentation fault.
#0  bdrv_inc_in_flight (bs=bs@entry=0x0) at block/io.c:508
508	    atomic_inc(&bs->in_flight);
(gdb) bt
#0  0x0000556ee7e2fd40 in bdrv_inc_in_flight (bs=bs@entry=0x0) at block/io.c:508
#1  0x0000556ee7e24c77 in blk_aio_prwv (blk=0x556ee96701e0, offset=offset@entry=65884160, bytes=2048, qiov=qiov@entry=0x556eebea2f00, co_entry=co_entry@entry=0x556ee7e243f0 <blk_aio_read_entry>, flags=flags@entry=
    0, cb=cb@entry=0x556ee7d2eca0 <ide_buffered_readv_cb>, opaque=opaque@entry=0x556eebea2ee0) at block/block-backend.c:1145
#2  0x0000556ee7e24cf5 in blk_aio_preadv (blk=<optimized out>, offset=offset@entry=65884160, qiov=qiov@entry=0x556eebea2f00, flags=flags@entry=0, cb=cb@entry=0x556ee7d2eca0 <ide_buffered_readv_cb>, opaque=opaque@entry=0x556eebea2ee0) at block/block-backend.c:1250
#3  0x0000556ee7d31c2d in ide_buffered_readv (s=s@entry=0x556eeb574a68, sector_num=128680, iov=iov@entry=0x556eeb574d60, nb_sectors=nb_sectors@entry=4, cb=cb@entry=0x556ee7d35130 <cd_read_sector_cb>, opaque=opaque@entry=0x556eeb574a68) at hw/ide/core.c:637
#4  0x0000556ee7d34151 in ide_atapi_cmd_reply_end (s=0x556eeb574a68)
    at hw/ide/atapi.c:198
#5  0x0000556ee7d34151 in ide_atapi_cmd_reply_end (s=0x556eeb574a68)
    at hw/ide/atapi.c:272
#6  0x0000556ee7d2f5a4 in ide_data_readw (opaque=<optimized out>, addr=<optimized out>)
    at hw/ide/core.c:2262
#7  0x0000556ee7bd9a00 in portio_read (opaque=0x556ee9626380, addr=0, size=2)
    at /usr/src/debug/qemu-2.9.0/ioport.c:180
#8  0x0000556ee7be41ac in memory_region_read_accessor (mr=0x556ee9626380, addr=0, value=0x7f3e806ea7a0, size=2, shift=0, mask=65535, attrs=...)
---Type <return> to continue, or q <return> to quit---
    at /usr/src/debug/qemu-2.9.0/memory.c:435
#9  0x0000556ee7be1b39 in access_with_adjusted_size (addr=addr@entry=0, value=value@entry=0x7f3e806ea7a0, size=size@entry=2, access_size_min=<optimized out>, access_size_max=<optimized out>, access=access@entry=
    0x556ee7be4180 <memory_region_read_accessor>, mr=mr@entry=0x556ee9626380, attrs=attrs@entry=...) at /usr/src/debug/qemu-2.9.0/memory.c:592
#10 0x0000556ee7be4f46 in memory_region_dispatch_read (attrs=..., size=2, pval=0x7f3e806ea7a0, addr=0, mr=0x556ee9626380) at /usr/src/debug/qemu-2.9.0/memory.c:1238
#11 0x0000556ee7be4f46 in memory_region_dispatch_read (mr=mr@entry=0x556ee9626380, addr=addr@entry=0, pval=pval@entry=0x7f3e806ea7a0, size=size@entry=2, attrs=attrs@entry=...)
    at /usr/src/debug/qemu-2.9.0/memory.c:1269
#12 0x0000556ee7b98432 in address_space_read_continue (as=as@entry=0x556ee846fb60 <address_space_io>, addr=addr@entry=496, attrs=..., 
    attrs@entry=..., buf=buf@entry=0x7f3ea49f53fe <udev_device_set_sysattr_value+254> "\017\210|", len=len@entry=2, addr1=0, l=2, mr=0x556ee9626380)
    at /usr/src/debug/qemu-2.9.0/exec.c:2844
#13 0x0000556ee7b984e7 in address_space_read_full (as=0x556ee846fb60 <address_space_io>, addr=496, 
    addr@entry=0, attrs=..., buf=buf@entry=0x7f3ea49f53fe <udev_device_set_sysattr_value+254> "\017\210|", len=len@entry=2) at /usr/src/debug/qemu-2.9.0/exec.c:2895
#14 0x0000556ee7b9864e in address_space_rw (len=2, buf=0x7f3ea49f53fe <udev_device_set_sysattr_value+254> "\017\210|", attrs=..., addr=0, as=<optimized out>)
---Type <return> to continue, or q <return> to quit---
    at /usr/src/debug/qemu-2.9.0/include/exec/memory.h:1718
#15 0x0000556ee7b9864e in address_space_rw (as=<optimized out>, addr=addr@entry=496, attrs=..., 
    attrs@entry=..., buf=buf@entry=0x7f3ea49f53fe <udev_device_set_sysattr_value+254> "\017\210|", len=len@entry=2, is_write=is_write@entry=false)
    at /usr/src/debug/qemu-2.9.0/exec.c:2909
#16 0x0000556ee7be0c5a in kvm_cpu_exec (count=512, size=2, direction=<optimized out>, data=<optimized out>, attrs=..., port=496) at /usr/src/debug/qemu-2.9.0/kvm-all.c:1825
#17 0x0000556ee7be0c5a in kvm_cpu_exec (cpu=cpu@entry=0x556ee9ac4000)
    at /usr/src/debug/qemu-2.9.0/kvm-all.c:2054
#18 0x0000556ee7bce202 in qemu_kvm_cpu_thread_fn (arg=0x556ee9ac4000)
    at /usr/src/debug/qemu-2.9.0/cpus.c:1118
#19 0x00007f3e8bd3ae25 in start_thread (arg=0x7f3e806ed700) at pthread_create.c:308
#20 0x00007f3e8ba6834d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:113


Version-Release number of selected component (if applicable):
qemu-kvm-rhev-2.9.0-4.el7.x86_64
kernel-3.10.0-666.el7.x86_64

How reproducible:
1 / 50 

Steps to Reproduce:
1. Boot up a Win8.1.32 guest with ide drive, do 'cont' then 'quit' in HMP.
# sh qemu.sh 
QEMU 2.9.0 monitor - type 'help' for more information
(qemu) pulseaudio: pa_context_connect() failed
pulseaudio: Reason: Connection refused
pulseaudio: Failed to initialize PA contextaudio: Could not init `pa' audio driver
ALSA lib confmisc.c:767:(parse_card) cannot find card '0'
ALSA lib conf.c:4528:(_snd_config_evaluate) function snd_func_card_driver returned error: No such file or directory
ALSA lib confmisc.c:392:(snd_func_concat) error evaluating strings
ALSA lib conf.c:4528:(_snd_config_evaluate) function snd_func_concat returned error: No such file or directory
ALSA lib confmisc.c:1246:(snd_func_refer) error evaluating name
ALSA lib conf.c:4528:(_snd_config_evaluate) function snd_func_refer returned error: No such file or directory
ALSA lib conf.c:5007:(snd_config_expand) Evaluate error: No such file or directory
ALSA lib pcm.c:2501:(snd_pcm_open_noupdate) Unknown PCM default
alsa: Could not initialize DAC
alsa: Failed to open `default':
alsa: Reason: No such file or directory
ALSA lib confmisc.c:767:(parse_card) cannot find card '0'
ALSA lib conf.c:4528:(_snd_config_evaluate) function snd_func_card_driver returned error: No such file or directory
ALSA lib confmisc.c:392:(snd_func_concat) error evaluating strings
ALSA lib conf.c:4528:(_snd_config_evaluate) function snd_func_concat returned error: No such file or directory
ALSA lib confmisc.c:1246:(snd_func_refer) error evaluating name
ALSA lib conf.c:4528:(_snd_config_evaluate) function snd_func_refer returned error: No such file or directory
ALSA lib conf.c:5007:(snd_config_expand) Evaluate error: No such file or directory
ALSA lib pcm.c:2501:(snd_pcm_open_noupdate) Unknown PCM default
alsa: Could not initialize DAC
alsa: Failed to open `default':
alsa: Reason: No such file or directory
audio: Failed to create voice `dac'
ALSA lib confmisc.c:767:(parse_card) cannot find card '0'
ALSA lib conf.c:4528:(_snd_config_evaluate) function snd_func_card_driver returned error: No such file or directory
ALSA lib confmisc.c:392:(snd_func_concat) error evaluating strings
ALSA lib conf.c:4528:(_snd_config_evaluate) function snd_func_concat returned error: No such file or directory
ALSA lib confmisc.c:1246:(snd_func_refer) error evaluating name
ALSA lib conf.c:4528:(_snd_config_evaluate) function snd_func_refer returned error: No such file or directory
ALSA lib conf.c:5007:(snd_config_expand) Evaluate error: No such file or directory
ALSA lib pcm.c:2501:(snd_pcm_open_noupdate) Unknown PCM default
alsa: Could not initialize ADC
alsa: Failed to open `default':
alsa: Reason: No such file or directory
ALSA lib confmisc.c:767:(parse_card) cannot find card '0'
ALSA lib conf.c:4528:(_snd_config_evaluate) function snd_func_card_driver returned error: No such file or directory
ALSA lib confmisc.c:392:(snd_func_concat) error evaluating strings
ALSA lib conf.c:4528:(_snd_config_evaluate) function snd_func_concat returned error: No such file or directory
ALSA lib confmisc.c:1246:(snd_func_refer) error evaluating name
ALSA lib conf.c:4528:(_snd_config_evaluate) function snd_func_refer returned error: No such file or directory
ALSA lib conf.c:5007:(snd_config_expand) Evaluate error: No such file or directory
ALSA lib pcm.c:2501:(snd_pcm_open_noupdate) Unknown PCM default
alsa: Could not initialize ADC
alsa: Failed to open `default':
alsa: Reason: No such file or directory
audio: Failed to create voice `adc'
VNC server running on ::1:5900

(qemu) c
(qemu) q
qemu.sh: line 39: 29658 Segmentation fault      (core dumped) /usr/libexec/qemu-kvm -S -name 'virt-tests-vm1' -nodefaults -chardev socket,id=qmp_id_qmpmonitor1,path=/var/tmp/avocado_su48pO/monitor-qmpmonitor1-20170515-095412-hdoEpKIX,server,nowait -mon chardev=qmp_id_qmpmonitor1,mode=control -chardev socket,id=qmp_id_catch_monitor,path=/var/tmp/avocado_su48pO/monitor-catch_monitor-20170515-095412-hdoEpKIX,server,nowait -mon chardev=qmp_id_catch_monitor,mode=control -device pvpanic,ioport=0x505,id=idK9Ihoh -chardev socket,id=serial_id_serial0,path=/var/tmp/avocado_su48pO/serial-serial0-20170515-095412-hdoEpKIX,server,nowait -device isa-serial,chardev=serial_id_serial0 -chardev socket,id=seabioslog_id_20170515-095412-hdoEpKIX,path=/var/tmp/avocado_su48pO/seabios-20170515-095412-hdoEpKIX,server,nowait -device isa-debugcon,chardev=seabioslog_id_20170515-095412-hdoEpKIX,iobase=0x402 -device nec-usb-xhci,id=usb1,bus=pci.0,addr=0x4 -device ahci,id=ahci,addr=0x5 -drive file='/home/kvm_autotest_root/images/win8-32.1.qcow2',if=none,id=ahci0,media=disk,cache=none,snapshot=off,format=qcow2,aio=threads -device ide-drive,bus=ahci.0,drive=ahci0 -device e1000,mac=9a:47:48:49:4a:4b,id=idwhlZaR,netdev=id1yl3ZD,bus=pci.0,addr=0x3 -netdev tap,id=id1yl3ZD -m 4096 -smp 4,maxcpus=4,cores=2,threads=1,sockets=2 -cpu 'SandyBridge',+sep -M pc-i440fx-rhel7.0.0 -drive file='/home/kvm_autotest_root/iso/ISO/Win8.1/en_windows_8.1_enterprise_with_update_x86_dvd_6050710.iso',index=1,if=none,id=drive-ide0-0-0,media=cdrom,format=raw -device ide-drive,bus=ide.0,unit=0,drive=drive-ide0-0-0 -drive file='/home/kvm_autotest_root/iso/windows/winutils.iso',index=2,if=none,id=drive-ide0-0-1,media=cdrom,format=raw -device ide-drive,bus=ide.0,unit=1,drive=drive-ide0-0-1 -drive file='/root/autounattend.iso',index=3,if=none,id=drive-ide0-1-0,media=cdrom,format=raw -device ide-drive,bus=ide.1,unit=0,drive=drive-ide0-1-0 -device usb-tablet,id=usb-tablet1,bus=usb1.0,port=1 -vga qxl -global qxl-vga.vram_size=33554432 -rtc base=localtime,clock=host,driftfix=slew -boot order=cdn,once=d,menu=off -device virtio-serial-pci,id=virtio-serial0 -device intel-hda,id=intel-hda0 -device hda-duplex,id=hda-duplex0 -enable-kvm -monitor stdio
2.
3.

Actual results:
Qemu core dump.

Expected results:
Qemu should not core dump.

Additional info:
1. Qemu CML (the CML is old as I was reproducing an old bug on latest qemu):
/usr/libexec/qemu-kvm \
    -S \
    -name 'virt-tests-vm1' \
    -nodefaults \
    -chardev socket,id=qmp_id_qmpmonitor1,path=/var/tmp/avocado_su48pO/monitor-qmpmonitor1-20170515-095412-hdoEpKIX,server,nowait \
    -mon chardev=qmp_id_qmpmonitor1,mode=control  \
    -chardev socket,id=qmp_id_catch_monitor,path=/var/tmp/avocado_su48pO/monitor-catch_monitor-20170515-095412-hdoEpKIX,server,nowait \
    -mon chardev=qmp_id_catch_monitor,mode=control \
    -device pvpanic,ioport=0x505,id=idK9Ihoh  \
    -chardev socket,id=serial_id_serial0,path=/var/tmp/avocado_su48pO/serial-serial0-20170515-095412-hdoEpKIX,server,nowait \
    -device isa-serial,chardev=serial_id_serial0  \
    -chardev socket,id=seabioslog_id_20170515-095412-hdoEpKIX,path=/var/tmp/avocado_su48pO/seabios-20170515-095412-hdoEpKIX,server,nowait \
    -device isa-debugcon,chardev=seabioslog_id_20170515-095412-hdoEpKIX,iobase=0x402 \
    -device nec-usb-xhci,id=usb1,bus=pci.0,addr=0x4 \
    -device ahci,id=ahci,addr=0x5 \
    -drive file='/home/kvm_autotest_root/images/win8-32.1.qcow2',if=none,id=ahci0,media=disk,cache=none,snapshot=off,format=qcow2,aio=threads \
    -device ide-drive,bus=ahci.0,drive=ahci0 \
    -device e1000,mac=9a:47:48:49:4a:4b,id=idwhlZaR,netdev=id1yl3ZD,bus=pci.0,addr=0x3  \
    -netdev tap,id=id1yl3ZD \
    -m 4096 \
    -smp 4,maxcpus=4,cores=2,threads=1,sockets=2 \
    -cpu 'SandyBridge',+sep \
    -M pc-i440fx-rhel7.0.0 \
    -drive file='/home/kvm_autotest_root/iso/ISO/Win8.1/en_windows_8.1_enterprise_with_update_x86_dvd_6050710.iso',index=1,if=none,id=drive-ide0-0-0,media=cdrom,format=raw \
    -device ide-drive,bus=ide.0,unit=0,drive=drive-ide0-0-0 \
    -drive file='/home/kvm_autotest_root/iso/windows/winutils.iso',index=2,if=none,id=drive-ide0-0-1,media=cdrom,format=raw \
    -device ide-drive,bus=ide.0,unit=1,drive=drive-ide0-0-1 \
    -drive file='/root/autounattend.iso',index=3,if=none,id=drive-ide0-1-0,media=cdrom,format=raw \
    -device ide-drive,bus=ide.1,unit=0,drive=drive-ide0-1-0 \
    -device usb-tablet,id=usb-tablet1,bus=usb1.0,port=1 \
    -vga qxl \
    -global qxl-vga.vram_size=33554432 \
    -rtc base=localtime,clock=host,driftfix=slew  \
    -boot order=cdn,once=d,menu=off   \
    -device virtio-serial-pci,id=virtio-serial0 \
    -device intel-hda,id=intel-hda0 \
    -device hda-duplex,id=hda-duplex0 \
    -enable-kvm \
    -monitor stdio \
    -vnc :0

2. Host info:
# free -m
              total        used        free      shared  buff/cache   available
Mem:          39920         596       33864          17        5459       38796
Swap:         20095           0       20095

processor	: 23
vendor_id	: GenuineIntel
cpu family	: 6
model		: 45
model name	: Intel(R) Xeon(R) CPU E5-2620 0 @ 2.00GHz
stepping	: 7
microcode	: 0x710
cpu MHz		: 1266.562
cache size	: 15360 KB
physical id	: 1
siblings	: 12
core id		: 5
cpu cores	: 6
apicid		: 43
initial apicid	: 43
fpu		: yes
fpu_exception	: yes
cpuid level	: 13
wp		: yes
flags		: fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush dts acpi mmx fxsr sse sse2 ss ht tm pbe syscall nx pdpe1gb rdtscp lm constant_tsc arch_perfmon pebs bts rep_good nopl xtopology nonstop_tsc aperfmperf eagerfpu pni pclmulqdq dtes64 monitor ds_cpl vmx smx est tm2 ssse3 cx16 xtpr pdcm pcid dca sse4_1 sse4_2 x2apic popcnt tsc_deadline_timer aes xsave avx lahf_lm epb tpr_shadow vnmi flexpriority ept vpid xsaveopt dtherm ida arat pln pts
bogomips	: 4004.81
clflush size	: 64
cache_alignment	: 64
address sizes	: 46 bits physical, 48 bits virtual
power management:

Comment 3 Dr. David Alan Gilbert 2017-05-16 15:59:11 UTC
The core is fun; I don't think the main thread is there any more, thread 1 looks like vcpu to me.

I think hmp's quit goes to qmp_quit that goes to qemu_system_shutdown_request (with no_shutdown=0) 
main_loop_should_exit should happen, I don't think it does a RUN_STATE_SHUTDOWN.
Then in main() I see:

    main_loop();
    replay_disable_events();
    iothread_stop_all();

    bdrv_close_all();
    pause_all_vcpus();

so perhaps that IO request for the CD happens between the bdrv_close_all() and the pause_all_vcpus() ???
But there again if that was the case we'd still have this thread.

Comment 4 Dr. David Alan Gilbert 2017-07-13 16:34:30 UTC
I managed to recreate the problem on a Linux guest doing heavy CD access - once in 349 runs (fortunately automated), failed at the same bdrv_inc_in_flight

Comment 5 Dr. David Alan Gilbert 2017-07-13 19:02:11 UTC
Posted upstream:
  vl.c/exit: pause cpus before closing block devices

Comment 6 Dr. David Alan Gilbert 2017-08-16 08:52:12 UTC
*** Bug 1481945 has been marked as a duplicate of this bug. ***

Comment 7 Dr. David Alan Gilbert 2017-08-17 16:26:33 UTC
This is fixed upstream by commit 452589b6b47e8dc6353d
(and then fix cbaddb25b20060fa0b0a for a test that broke)

These are in v2.10.0-rc3 that we should pickup at some point

Comment 9 aihua liang 2017-10-10 03:48:57 UTC
Verified, the problem has been resolved, so set its status to "Verified".

Test Version:
 kernel version:3.10.0-718.el7.x86_64
 qemu-kvm-rhev version:qemu-kvm-rhev-2.10.0-1.el7.x86_64

Test Steps:
 1.Start guest with qemu cmd:
/usr/libexec/qemu-kvm \
-name 'avocado-vt-vm1'  \
-sandbox off  \
-machine pc \
-nodefaults  \
-vga std  \
-chardev socket,id=qmp_id_qmpmonitor1,path=/var/tmp/monitor-qmpmonitor1-20170124-161452-WcepYpO8,server,nowait \
-mon chardev=qmp_id_qmpmonitor1,mode=control  \
-device virtio-scsi-pci,id=scsi0,bus=pci.0,addr=03 \
-drive id=drive_image1,if=none,snapshot=off,aio=native,cache=none,format=qcow2,file=/home/kvm_autotest_root/images/win8-64.1-virtio.qcow2 \
-device ide-hd,id=image1,drive=drive_image1,bus=ide.0 \
-device virtio-net-pci,mac=9a:b2:b3:b4:b5:b6,id=iduCv1Ln,vectors=4,netdev=idKgexFk,bus=pci.0,addr=05  \
-netdev tap,id=idKgexFk,vhost=on \
-m 4096  \
-smp 4,maxcpus=4,cores=2,threads=1,sockets=2  \
-cpu host \
-vnc :1  \
-rtc base=localtime,clock=host,driftfix=slew  \
-enable-kvm \
-monitor stdio \

 2.Quit during guest boot up
(qemu)quit

Test result:
 qemu quit successfully.

Comment 10 aihua liang 2017-10-13 12:42:30 UTC
Has verified for 1000 times, the problem has been resolved.

Comment 11 aihua liang 2018-02-07 03:49:19 UTC
Test it with kernel:3.10.0-844.el7.x86_64 + qemu-kvm-rhev:qemu-kvm-rhev-2.10.0-19.el7.x86_64, and run for 1000 times, don't hit this issue.

Comment 13 errata-xmlrpc 2018-04-11 00:19:31 UTC
Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory, and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://access.redhat.com/errata/RHSA-2018:1104