Re: [PATCH v28 0/8] Timestamp synchronization of host - guest tracing session

[Tzvetomir Stoyanov <tz.stoyanov@gmail.com>]

On Tue, Feb 9, 2021 at 5:28 PM Dario Faggioli <dfaggioli@suse.com> wrote:
>
> On Tue, 2021-02-09 at 15:00 +0200, Tzvetomir Stoyanov wrote:
> > On Tue, Feb 9, 2021 at 2:24 PM Dario Faggioli <dfaggioli@suse.com>
> > wrote:
> > >
> > > So, the timestamps seems still a bit apart to me. Is this fine, and
> > > hence there is some more post-processing that I should do (and, if
> > > yes,
> > > what?). Or should they be already in sync?
> >
> > The timestamps, recorded in both files are not synchronised. That's
> > why you are seeing the original timestamps. The offsets between both
> > clocks are recorded in the metadata of the guest trace file.
> >
> Ah, sure! So I was right about me being missing something: I was
> missing this. :-)
>
> > You can verify
> > this using "trace-cmd dump --options trace-guest.dat" and
> > "trace-cmd dump --options trace.dat"
> > When both files are opened together, then that metadata is used to
> > align
> > guest's timestamps to the host time.
> >
> Right.
>
> >  Currently trace-cmd report does not
> > have support for opening more trace files as a session, yet. This is
> > in our
> > short todo list.
> >
> Ok, is there a WiP already, or someone working on it? I'm asking
> because maybe I can help.

None is working on that yet, any help is highly appreciated :) I just
created an issue in Bugzilla  for that:
https://bugzilla.kernel.org/show_bug.cgi?id=211657

>
> In fact, I am helping some University students with their theses, and
> I'm planning to have them doing something in the area of virtualization
> tracing. In fact, I will have quite a few other questions in the
> upcoming days (hoping you guys don't mind)... But, IAC, something like
> this could be a place from where to start.
>
> >
> > Currently using KernelShark2-beta is the only way to display host and
> > guests tracing files, as a session. There is logic for synchronising
> > timestamps,
> > using metadata from the files. What repo are you using for getting
> > the
> > KernelShark2-beta ?
> > Yordan can give more details on that.
> >
> Yes, I was already using the right repo (https://github.com/yordan-
> karadzhov/kernel-shark-v2.beta ) but missed a rebase/update. And in
> fact, Yordan pointed me to it, and know things are a lot better (still
> not perfect, but that's for the other thread).
>
> > > "Negotiated ptp time sync protocol with guest (null)"
> >
> > That "null" really bothers me, as I cannot reproduce it. The logic
> > for
> > getting the
> > guest name, cid and port uses "/proc/<qemu pid>/cmdline". Please, can
> > you send
> > me that string, from /proc/...
> >
> Sure. Brace yourself, though. It's a qemu command line, and you know
> that qemu command line are, well, a bit long ;-P
>
> /usr/bin/qemu-system-x86_64-nameguest=tumbleweed-jeos,debug-threads=on-

That "-nameguest=tumbleweed-jeos" is the thing that we are looking for
while trying
to figure out the name of the quest, but looks like we should improve
our parser or
better find a more reliable way for getting that information.

> S-
> objectsecret,id=masterKey0,format=raw,file=/var/lib/libvirt/qemu/domain
> -1-tumbleweed-jeos/master-key.aes-machinepc-q35-
> 5.2,accel=kvm,usb=off,dump-guest-core=off,memory-backend=pc.ram-
> cpuSkylake-Server-IBRS,ss=on,vmx=on,pdcm=on,hypervisor=on,tsc-
> adjust=on,clflushopt=on,umip=on,md-clear=on,stibp=on,arch-
> capabilities=on,ssbd=on,xsaves=on,ibpb=on,amd-stibp=on,amd-
> ssbd=on,pschange-mc-no=on,pku=off-m4096-objectmemory-backend-
> ram,id=pc.ram,size=4294967296-overcommitmem-lock=off-
> smp1,sockets=1,cores=1,threads=1-uuid57a61f7b-506e-49d8-a8d7-
> 63b5baae8534-no-user-config-nodefaults-
> chardevsocket,id=charmonitor,fd=29,server,nowait-
> monchardev=charmonitor,id=monitor,mode=control-
> rtcbase=utc,driftfix=slew-globalkvm-pit.lost_tick_policy=delay-no-hpet-
> no-shutdown-globalICH9-LPC.disable_s3=1-globalICH9-LPC.disable_s4=1-
> bootstrict=on-devicepcie-root-
> port,port=0x10,chassis=1,id=pci.1,bus=pcie.0,multifunction=on,addr=0x2-
> devicepcie-root-
> port,port=0x11,chassis=2,id=pci.2,bus=pcie.0,addr=0x2.0x1-devicepcie-
> root-port,port=0x12,chassis=3,id=pci.3,bus=pcie.0,addr=0x2.0x2-
> devicepcie-root-
> port,port=0x13,chassis=4,id=pci.4,bus=pcie.0,addr=0x2.0x3-devicepcie-
> root-port,port=0x14,chassis=5,id=pci.5,bus=pcie.0,addr=0x2.0x4-
> devicepcie-root-
> port,port=0x15,chassis=6,id=pci.6,bus=pcie.0,addr=0x2.0x5-devicepcie-
> root-port,port=0x16,chassis=7,id=pci.7,bus=pcie.0,addr=0x2.0x6-
> deviceqemu-xhci,p2=15,p3=15,id=usb,bus=pci.2,addr=0x0-devicevirtio-
> serial-pci,id=virtio-serial0,bus=pci.3,addr=0x0-
> blockdev{"driver":"file","filename":"/var/lib/libvirt/images/openSUSE-
> Tumbleweed-JeOS.x86_64-15.1.0-kvm-and-xen-
> Snapshot20210205.qcow2","node-name":"libvirt-1-storage","auto-read-
> only":true,"discard":"unmap"}-blockdev{"node-name":"libvirt-1-
> format","read-only":false,"driver":"qcow2","file":"libvirt-1-
> storage","backing":null}-devicevirtio-blk-
> pci,bus=pci.4,addr=0x0,drive=libvirt-1-format,id=virtio-
> disk0,bootindex=1-netdevtap,fd=31,id=hostnet0,vhost=on,vhostfd=32-
> devicevirtio-net-
> pci,netdev=hostnet0,id=net0,mac=52:54:00:77:d6:ea,bus=pci.1,addr=0x0-
> chardevpty,id=charserial0-deviceisa-
> serial,chardev=charserial0,id=serial0-
> chardevsocket,id=charchannel0,fd=33,server,nowait-
> devicevirtserialport,bus=virtio-
> serial0.0,nr=1,chardev=charchannel0,id=channel0,name=org.qemu.guest_age
> nt.0-deviceusb-tablet,id=input0,bus=usb.0,port=1-
> spiceport=5900,addr=0.0.0.0,disable-ticketing,seamless-migration=on-
> deviceqxl-
> vga,id=video0,ram_size=67108864,vram_size=67108864,vram64_size_mb=0,vga
> mem_mb=16,max_outputs=1,bus=pcie.0,addr=0x1-devicevirtio-balloon-
> pci,id=balloon0,bus=pci.5,addr=0x0-objectrng-
> random,id=objrng0,filename=/dev/urandom-devicevirtio-rng-
> pci,rng=objrng0,id=rng0,bus=pci.6,addr=0x0-
> sandboxon,obsolete=deny,elevateprivileges=deny,spawn=deny,resourcecontr
> ol=deny-devicevhost-vsock-pci,id=vsock0,guest-
> cid=3,vhostfd=26,bus=pci.7,addr=0x0-msgtimestamp=ontoolbox-dario
>
> > or just "ps afx | grep qemu",
> >
> Also a mess. But here you go:
>
> # ps afx | grep qemu
> 12952 ?        S      0:00  |   |   \_ ssh -l root -T -e none --
> 192.168.0.31 sh -c 'which virt-ssh-helper 1>/dev/null 2>&1; if test $?
> = 0; then     virt-ssh-helper 'qemu:///system'; else    if 'nc' -q 2>&1
> | grep "requires an argument" >/dev/null 2>&1; then ARG=-q0;else
> ARG=;fi;'nc' $ARG -U /var/run/libvirt/libvirt-sock; fi'
>  8758 pts/9    S+     0:00  |   |   |               \_ grep --
> color=auto qemu
>  9168 ?        Sl   224:55  |   \_ /usr/bin/qemu-system-x86_64 -name
> guest=tumbleweed-jeos,debug-threads=on -S -object
> secret,id=masterKey0,format=raw,file=/var/lib/libvirt/qemu/domain-1-
> tumbleweed-jeos/master-key.aes -machine pc-q35-
> 5.2,accel=kvm,usb=off,dump-guest-core=off,memory-backend=pc.ram -cpu
> Skylake-Server-IBRS,ss=on,vmx=on,pdcm=on,hypervisor=on,tsc-
> adjust=on,clflushopt=on,umip=on,md-clear=on,stibp=on,arch-
> capabilities=on,ssbd=on,xsaves=on,ibpb=on,amd-stibp=on,amd-
> ssbd=on,pschange-mc-no=on,pku=off -m 4096 -object memory-backend-
> ram,id=pc.ram,size=4294967296 -overcommit mem-lock=off -smp
> 1,sockets=1,cores=1,threads=1 -uuid 57a61f7b-506e-49d8-a8d7-
> 63b5baae8534 -no-user-config -nodefaults -chardev
> socket,id=charmonitor,fd=29,server,nowait -mon
> chardev=charmonitor,id=monitor,mode=control -rtc base=utc,driftfix=slew
> -global kvm-pit.lost_tick_policy=delay -no-hpet -no-shutdown -global
> ICH9-LPC.disable_s3=1 -global ICH9-LPC.disable_s4=1 -boot strict=on -
> device pcie-root-
> port,port=0x10,chassis=1,id=pci.1,bus=pcie.0,multifunction=on,addr=0x2
> -device pcie-root-
> port,port=0x11,chassis=2,id=pci.2,bus=pcie.0,addr=0x2.0x1 -device pcie-
> root-port,port=0x12,chassis=3,id=pci.3,bus=pcie.0,addr=0x2.0x2 -device
> pcie-root-port,port=0x13,chassis=4,id=pci.4,bus=pcie.0,addr=0x2.0x3 -
> device pcie-root-
> port,port=0x14,chassis=5,id=pci.5,bus=pcie.0,addr=0x2.0x4 -device pcie-
> root-port,port=0x15,chassis=6,id=pci.6,bus=pcie.0,addr=0x2.0x5 -device
> pcie-root-port,port=0x16,chassis=7,id=pci.7,bus=pcie.0,addr=0x2.0x6 -
> device qemu-xhci,p2=15,p3=15,id=usb,bus=pci.2,addr=0x0 -device virti876714o-
> serial-pci,id=virtio-serial0,bus=pci.3,addr=0x0 -blockdev
> {"driver":"file","filename":"/var/lib/libvirt/images/openSUSE-
> Tumbleweed-JeOS.x86_64-15.1.0-kvm-and-xen-
> Snapshot20210205.qcow2","node-name":"libvirt-1-storage","auto-read-
> only":true,"discard":"unmap"} -blockdev {"node-name":"libvirt-1-
> format","read-only":false,"driver":"qcow2","file":"libvirt-1-
> storage","backing":null} -device virtio-blk-
> pci,bus=pci.4,addr=0x0,drive=libvirt-1-format,id=virtio-
> disk0,bootindex=1 -netdev tap,fd=31,id=hostnet0,vhost=on,vhostfd=32 -
> device virtio-net-
> pci,netdev=hostnet0,id=net0,mac=52:54:00:77:d6:ea,bus=pci.1,addr=0x0 -
> chardev pty,id=charserial0 -device isa-
> serial,chardev=charserial0,id=serial0 -chardev
> socket,id=charchannel0,fd=33,server,nowait -device
> virtserialport,bus=virtio-
> serial0.0,nr=1,chardev=charchannel0,id=channel0,name=org.qemu.guest_age
> nt.0 -device usb-tablet,id=input0,bus=usb.0,port=1 -spice
> port=5900,addr=0.0.0.0,disable-ticketing,seamless-migration=on -device
> qxl-
> vga,id=video0,ram_size=67108864,vram_size=67108864,vram64_size_mb=0,vga
> mem_mb=16,max_outputs=1,bus=pcie.0,addr=0x1 -device virtio-balloon-
> pci,id=balloon0,bus=pci.5,addr=0x0 -object rng-
> random,id=objrng0,filename=/dev/urandom -device virtio-rng-
> pci,rng=objrng0,id=rng0,bus=pci.6,addr=0x0 -sandbox
> on,obsolete=deny,elevateprivileges=deny,spawn=deny,resourcecontrol=deny
> -device vhost-vsock-pci,id=vsock0,guest-
> cid=3,vhostfd=26,bus=pci.7,addr=0x0 -msg timestamp=on
>
> It's a bit of an unusual setup, as the VM (and hence QEMU too) is
> running inside a podman container. But it seems the info you're after
> is indeed present on the commandline.
>
> > to see
> > what is wrong with
> > our parsing logic.
> > Also, if you have any ideas how to get name, cid and port of running
> > libvirt VMs -
> > please share. The current approach parsing the qemu command line is a
> > work
> > around, not a final solution.
> >
> Mmm... not sure. I'll have a look at the code where you go and fetch
> it, and see if anything comes to mind.

Thanks a lot, Dario!

>
> Thanks and Regards
> --
> Dario Faggioli, Ph.D
> http://about.me/dario.faggioli
> Virtualization Software Engineer
> SUSE Labs, SUSE https://www.suse.com/
> -------------------------------------------------------------------
> <<This happens because _I_ choose it to happen!>> (Raistlin Majere)



-- 
Tzvetomir (Ceco) Stoyanov
VMware Open Source Technology Center