Bug 1463172
| Summary: | [Tracing] capturing trace data failed | |||
|---|---|---|---|---|
| Product: | Red Hat Enterprise Linux 7 | Reporter: | jingzhao <jinzhao> | |
| Component: | qemu-kvm-rhev | Assignee: | Stefan Hajnoczi <stefanha> | |
| Status: | CLOSED ERRATA | QA Contact: | jingzhao <jinzhao> | |
| Severity: | high | Docs Contact: | ||
| Priority: | high | |||
| Version: | 7.4 | CC: | chayang, jsuchane, juzhang, michen, mtessun, stefanha, toneata, virt-maint | |
| Target Milestone: | rc | Keywords: | Regression | |
| Target Release: | --- | |||
| Hardware: | Unspecified | |||
| OS: | Unspecified | |||
| Whiteboard: | ||||
| Fixed In Version: | QEMU 2.10 | Doc Type: | If docs needed, set a value | |
| Doc Text: | Story Points: | --- | ||
| Clone Of: | ||||
| : | 1482515 1482516 (view as bug list) | Environment: | ||
| Last Closed: | 2018-04-11 00:26:27 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: | ||||
| Bug Depends On: | ||||
| Bug Blocks: | 1482515, 1482516 | |||
QEMU uses the new simpletrace v4 format since commit 7f1b588f. The simpletrace.py script was only partially extended to support v4 and the result is that the .stp script does not produce ringbuffer-friendly output anymore. I'll need to investigate whether to stick to v3 for simpletrace.stp or if we can make it ringbuffer-friendly. Patch posted upstream for QEMU 2.10: https://patchwork.ozlabs.org/patch/801252/ https://patchwork.ozlabs.org/patch/801249/ Patches posted on rhvirt-patches. This bug has been copied as 7.4 z-stream (EUS) bug #1482516 and now must be resolved in the current update release, set blocker flag. The following commits came into qemu-kvm-rhev-2.10.0-1.el7 via the QEMU 2.10 rebase: 840d835177 simpletrace: fix flight recorder --no-header option d6b76d6805 trace: use static event ID mapping in simpletrace.stp Verified it with qemu-kvm-rhev-2.10.0-2.el7.x86_64. Tested Result: [root@localhost ~]# /usr/share/qemu-kvm/simpletrace.py --no-header /usr/share/qemu-kvm/trace-events-all /tmp/trace.log monitor_protocol_event_queue 0.000 pid=2897 event=0x10 qdict=0x562cd3fa3600 rate=0x0 monitor_protocol_event_emit 2.484 pid=2897 event=0x10 data=0x562cd3fa3600 monitor_protocol_event_queue 34651065.642 pid=2897 event=0x1f qdict=0x562cd3fa3600 rate=0x0 monitor_protocol_event_emit 2.062 pid=2897 event=0x1f data=0x562cd3fa3600 monitor_protocol_event_queue 6309.118 pid=2897 event=0x21 qdict=0x562cd3fa3600 rate=0x0 monitor_protocol_event_emit 2.211 pid=2897 event=0x21 data=0x562cd3fa3600 Changed to verified according to the test result. 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 |
Description of problem: capturing trace data failed when executed "/usr/share/qemu-kvm/simpletrace.py --no-header /usr/share/qemu-kvm/trace-events-all /tmp/trace.log" Version-Release number of selected component (if applicable): [root@localhost ~]# rpm -qa | grep kernel-devel kernel-devel-3.10.0-685.el7.x86_64 [root@localhost ~]# uname -r 3.10.0-685.el7.x86_64 [root@localhost ~]# rpm -q systemtap systemtap-3.1-5.el7.x86_64 [root@localhost ~]# rpm -q qemu-kvm-rhev qemu-kvm-rhev-2.9.0-12.el7.x86_64 How reproducible: 2/2 Steps to Reproduce: 1. cp /usr/share/qemu-kvm/systemtap/script.d/qemu_kvm.stp /etc/systemtap/script.d/ 2. cp /usr/share/qemu-kvm/systemtap/conf.d/qemu_kvm.conf /etc/systemtap/conf.d/ 3. service systemtap start qemu_kvm 4. [root@localhost home]# chkconfig systemtap on [root@localhost home]# service systemtap status qemu_kvm qemu_kvm is running... 5. boot guest with qemu command line [1] 6. staprun -A qemu_kvm >/tmp/trace.log 7. In guest "dd if=/dev/zero of=/home/test.txt bs=1M count=1000" 8.[root@localhost ~]# /usr/share/qemu-kvm/simpletrace.py --no-header /usr/share/qemu-kvm/trace-events-all /tmp/trace.log Actual results: [root@localhost ~]# /usr/share/qemu-kvm/simpletrace.py --no-header /usr/share/qemu-kvm/trace-events-all /tmp/trace.log Traceback (most recent call last): File "/usr/share/qemu-kvm/simpletrace.py", line 221, in <module> run(Formatter()) File "/usr/share/qemu-kvm/simpletrace.py", line 196, in run process(events, sys.argv[2], analyzer, read_header=read_header) File "/usr/share/qemu-kvm/simpletrace.py", line 171, in process for rec in read_trace_records(edict, log): File "/usr/share/qemu-kvm/simpletrace.py", line 107, in read_trace_records rec = read_record(edict, idtoname, fobj) File "/usr/share/qemu-kvm/simpletrace.py", line 71, in read_record return get_record(edict, idtoname, rechdr, fobj) File "/usr/share/qemu-kvm/simpletrace.py", line 43, in get_record name = idtoname[event_id] KeyError: 17487890541996943796L Expected results: Capturing trace log correctly Additional info: Tried with qemu-kvm-rhev-2.6.0-28.el7_3.10.x86_64 and didn't hit the error message, the result are following [root@localhost ~]# /usr/share/qemu-kvm/simpletrace.py --no-header /usr/share/qemu-kvm/trace-events /tmp/trace.log monitor_protocol_event_queue 0.000 pid=18370 event=0x15 qdict=0x55f8a8530800 rate=0x0 monitor_protocol_event_emit 11.857 pid=18370 event=0x15 data=0x55f8a8530800 monitor_protocol_event_queue 7273950.737 pid=18370 event=0x1f qdict=0x55f8a9dde000 rate=0x0 monitor_protocol_event_emit 1.931 pid=18370 event=0x1f data=0x55f8a9dde000 monitor_protocol_event_queue 11065.735 pid=18370 event=0x21 qdict=0x55f8a9dde000 rate=0x0 monitor_protocol_event_emit 1.229 pid=18370 event=0x21 data=0x55f8a9dde000 monitor_protocol_event_queue 17506815.071 pid=18370 event=0x10 qdict=0x55f8a9826800 rate=0x0 monitor_protocol_event_emit 2.373 pid=18370 event=0x10 data=0x55f8a9826800 [1]/usr/libexec/qemu-kvm \ -machine q35,smm=on,accel=kvm \ -cpu Haswell-noTSX \ -nodefaults -rtc base=utc \ -m 4G \ -smp 4,sockets=4,cores=1,threads=1 \ -enable-kvm \ -uuid 990ea161-6b67-47b2-b803-19fb01d30d12 \ -k en-us \ -nodefaults \ -serial unix:/tmp/console,server,nowait \ -boot menu=on \ -qmp tcp:0:6667,server,nowait \ -vga qxl \ -chardev file,path=/home/seabios.log,id=seabios -device isa-debugcon,chardev=seabios,iobase=0x402 \ -device ioh3420,bus=pcie.0,id=root3 \ -drive file=/home/test/rhel/rhel74.qcow2,if=none,id=drive-virtio-disk0,format=qcow2,cache=none,werror=stop,rerror=stop \ -device virtio-blk-pci,drive=drive-virtio-disk0,id=virtio-disk0,bus=root3,bootindex=0 \ -device ioh3420,bus=pcie.0,id=root0,multifunction=on,chassis=1,addr=0xa.0 \ -device virtio-net-pci,netdev=tap10,mac=9a:6a:6b:6c:6d:6e,bus=root0 -netdev tap,id=tap10 \ -device ioh3420,bus=pcie.0,id=root1,chassis=11,addr=0xa.1 \ -device ioh3420,bus=pcie.0,id=root2,chassis=12,addr=0xa.2 \ -drive file=/home/test/rhel/block1.qcow2,if=none,id=drive-virtio-disk1,format=qcow2,cache=none,werror=stop,rerror=stop \ -device virtio-blk-pci,drive=drive-virtio-disk1,id=virtio-disk1,bus=root2 \ -monitor stdio \ -vnc :1 \