>
> Please post the command-line. You need to enable the events you are
> interested in. Either use the -trace option or via the HMP monitor
> (trace-event NAME on|off)/QMP monitor (trace-event-set-state).
>
Posted below. Note that I used the same libvirtd xml with both log and ftrace
backends - and I see the events when using log backend.
>
> Did you strace -f QEMU to see if there are writes to the trace_marker
> file?
>
> If you see the write() syscalls then you need to double-check your
> commands to set up and access /sys/kernel/debug/tracing.
>
> If you do not see the write() syscalls then you need to check that you
> build QEMU with the ftrace backend and enabled the trace events you are
> interested in.
Thanks for your suggestion of using strace.
I see writes to fd 2 and 8:-
sudo strace -f -p `pidof qemu-system-x86_64` -e write 2>strace.out
$ wc -l strace.out
2117 strace.out
$ head strace.out
Process 8988 attached with 4 threads
[pid 24956] +++ exited with 0 +++
[pid 9005] write(2, "8988@1498054584.434899:blk_co_pr"..., 112) = 112
[pid 9005] write(8, "\1\0\0\0\0\0\0\0", 8) = 8
Process 24964 attached
[pid 8988] write(85, "worker", 6) = 6
[pid 24964] write(8, "\1\0\0\0\0\0\0\0", 8) = 8
[pid 9005] write(2, "8988@1498054584.441258:blk_co_pr"..., 112) = 112
[pid 24964] write(8, "\1\0\0\0\0\0\0\0", 8) = 8
[pid 9005] write(2, "8988@1498054585.063087:blk_co_pw"..., 114) = 114
$ tail strace.out
[pid 9005] write(2, "8988@1498054600.032253:paio_subm"..., 100) = 100
[pid 24964] write(8, "\1\0\0\0\0\0\0\0", 8) = 8
[pid 9005] write(2, "8988@1498054600.141628:blk_co_pw"..., 112) = 112
[pid 24964] write(8, "\1\0\0\0\0\0\0\0", 8) = 8
[pid 9005] write(2, "8988@1498054600.144293:paio_subm"..., 100) = 100
[pid 24964] write(8, "\1\0\0\0\0\0\0\0", 8) = 8
$ awk '{print $3}' strace.out | sort | uniq -c
1 +++
2 attached
4 detached
1053 write(2,
1056 write(8,
1 write(85,
I'm not sure where these fds lead to:-
$ sudo ls -l /proc/8988/fd/2
l-wx------ 1 qemu qemu 64 Jun 21 19:41 /proc/8988/fd/2 -> pipe:[705181]
$ sudo ls -l /proc/8988/fd/8
lrwx------ 1 qemu qemu 64 Jun 21 19:41 /proc/8988/fd/8 ->
anon_inode:[eventfd]
Still no ftrace events that I enabled:
$ sudo ./ftrace-kvm.sh dd-ftrace.out sleep 20
Using dd-ftrace.out as trace name. Continue?
Copying trace to dd-ftrace.out
$ wc -l dd-ftrace.out
272676 dd-ftrace.out
$ cut -b53- dd-ftrace.out | awk '{print $1}' | sort | uniq -c
7
1 h
1 irq
1185 kvm_ack_irq:
5968 kvm_apic:
5608 kvm_apic_accept_irq:
15526 kvm_emulate_insn:
60895 kvm_entry:
5608 kvm_eoi:
60912 kvm_exit:
3862 kvm_fpu:
5608 kvm_inj_virq:
5925 kvm_ioapic_set_irq:
8436 kvm_msr:
204 kvm_page_fault:
5925 kvm_pic_set_irq:
36024 kvm_pio:
4412 kvm_pv_eoi:
5925 kvm_set_irq:
36024 kvm_userspace_exit:
4618 kvm_vcpu_wakeup:
1 #P:24
1 TION
======= ========
272676
I tried strace on libvirtd and restarted the VM, but I'm not sure
what's going on:
[pid 25167] fstat(2, {st_mode=S_IFIFO|0600, st_size=0, ...}) = 0
[pid 25167] mmap(NULL, 4096, PROT_READ|PROT_WRITE,
MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f5cdff0a000
[pid 25167] write(2, "2017-06-21T14:23:18.470901Z qemu"..., 134) = 134
.
.
.
[pid 25167] write(2, "25167@1498054998.482112:bdrv_ope"..., 140) = 140
.
.
.
[pid 25167] write(2, "25167@1498054998.483315:bdrv_ope"..., 141) = 141
qemu cmd line
$ strings -1 /proc/25167/cmdline
/home/prasun/qemu-install/bin/qemu-system-x86_64
-name
guest=generic-qemu-system-x86_64,debug-threads=on
-S
-object
secret,id=masterKey0,format=raw,file=/var/lib/libvirt/qemu/domain-14-generic-qemu-system-/master-key.aes
-machine
pc-i440fx-2.9,accel=kvm,usb=off,vmport=off
-cpu
Opteron_G3
-m
1024
-realtime
mlock=off
-smp
1,sockets=1,cores=1,threads=1
-uuid
92c4ed02-0071-4876-9ed9-f18dd4435c1b
-nographic
-no-user-config
-nodefaults
-chardev
socket,id=charmonitor,path=/var/lib/libvirt/qemu/domain-14-generic-qemu-system-/monitor.sock,server,nowait
-mon
chardev=charmonitor,id=monitor,mode=control
-rtc
base=utc,driftfix=slew
-global
kvm-pit.lost_tick_policy=discard
-no-hpet
-no-shutdown
-global
PIIX4_PM.disable_s3=1
-global
PIIX4_PM.disable_s4=1
-boot
strict=on
-device
ich9-usb-ehci1,id=usb,bus=pci.0,addr=0x6.0x7
-device
ich9-usb-uhci1,masterbus=usb.0,firstport=0,bus=pci.0,multifunction=on,addr=0x6
-device
ich9-usb-uhci2,masterbus=usb.0,firstport=2,bus=pci.0,addr=0x6.0x1
-device
ich9-usb-uhci3,masterbus=usb.0,firstport=4,bus=pci.0,addr=0x6.0x2
-device
virtio-serial-pci,id=virtio-serial0,bus=pci.0,addr=0x5
-drive
file=/var/lib/libvirt/images/generic.qcow2,format=qcow2,if=none,id=drive-ide0-0-0
-device
ide-hd,bus=ide.0,unit=0,drive=drive-ide0-0-0,id=ide0-0-0,bootindex=1
-drive
if=none,id=drive-ide0-0-1,readonly=on
-device
ide-cd,bus=ide.0,unit=1,drive=drive-ide0-0-1,id=ide0-0-1
-netdev
tap,fd=26,id=hostnet0
-device
rtl8139,netdev=hostnet0,id=net0,mac=52:54:00:3d:db:fc,bus=pci.0,addr=0x3
-chardev
pty,id=charserial0
-device
isa-serial,chardev=charserial0,id=serial0
-device
intel-hda,id=sound0,bus=pci.0,addr=0x4
-device
hda-duplex,id=sound0-codec0,bus=sound0.0,cad=0
-device
virtio-balloon-pci,id=balloon0,bus=pci.0,addr=0x7
-trace
events=/home/prasun/my-trace-events
-msg
timestamp=on
Thanks
Prasun
