Re: [PATCH v32 0/5]Timestamp synchronization of host - guest tracing session

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

Hi Stefano,

On Fri, Mar 19, 2021 at 12:08 PM Stefano De Venuto
<stefano.devenuto99@gmail.com> wrote:
>
> Hello,
>
> On 3/15/21 7:18 AM, Tzvetomir Stoyanov (VMware) wrote:
> > Basic infrastructure for host - guest timestamp synchronization and a
> > PoC implementation of PTP-like and KVM algorithms.
> I'm trying to make some analysis on traces generated by host and guest,
> so I applied this series and the related dependencies.
>
> However, when the KVM algorithm is used, the merging process
> of the two traces doesn't seem to happen properly.
>
> The output of `trace-cmd report -i trace.dat -i trace-tumbleweed.dat` is:
>
>            trace.dat: cpus=4
> trace-tumbleweed.dat: cpus=1
>            trace.dat:            sleep-23948 [002]61124758463654:
> write_msr:            c0000100, value 7f35092875c0
>            trace.dat:           <idle>-0     [000]61124760841508:
> write_msr:            c0000100, value 7f6136b75640
>            trace.dat:        CPU 0/KVM-1640  [000]61124760851620:
> write_msr:            c0011020, value 40000000000000
>            trace.dat:        CPU 0/KVM-1640  [000]61124760861778:
> read_msr:             c0000101, value ffff9b1b76c00000
>            trace.dat:        CPU 0/KVM-1640  [000]61124760862832:
> read_msr:             c0000081, value 23001000000000
>            trace.dat:        CPU 0/KVM-1640  [000]61124760864347:
> read_msr:             c0000082, value ffffffffb5400010
>            trace.dat:        CPU 0/KVM-1640  [000]61124760865225:
> read_msr:             c0000083, value ffffffffb5401670
>            .
>            .
>            .
> trace-tumbleweed.dat:   IPC I/O Parent-4313 [000]8446232460209009653:
> write_msr:            c0000100, value 7f94535c7640
> trace-tumbleweed.dat:    IPC I/O Child-4503 [000]8446348845232796661:
> write_msr:            c001011f, value 4
> trace-tumbleweed.dat:    IPC I/O Child-4503 [000]8447532508154803189:
> write_msr:            c0000100, value 7f945e8d5780
> trace-tumbleweed.dat:           <idle>-0    [000]8452336523564659701:
> write_msr:            c001011f, value 0
> trace-tumbleweed.dat:           <idle>-0    [000]8452515224268944373:
> write_msr:            6e0, value 731478a3bf62
> trace-tumbleweed.dat:           <idle>-0    [000]8452610851715789813:
> write_msr:            6e0, value 731478968f37
> trace-tumbleweed.dat:           <idle>-0    [000]8555757214338495477:
> write_msr:            6e0, value 731478853ec1
> trace-tumbleweed.dat:           <idle>-0    [000]8555904475882173429:
> write_msr:            6e0, value 7314778a60e8
> trace-tumbleweed.dat:      kworker/0:1-7351 [000]8556355589182174197:
> write_msr:            c0000100, value 7f8373573740
>
> The TimeShift information is inside the guest trace file,
> so I think this is not a transfer problem.
>
> I also tried to remove the last patch, the one related to the KVM clock,
> in order to use PTP and the two traces are merged correctly.
>
> The commands used to record are:
>
> Host:
> # trace-cmd record -C x86-tsc -e kvm:* -e msr:* -A tumbleweed:823 -e
> msr:* -C x86-tsc sleep 1

The guest trace clock is set automatically as the host, so this
command should be enough:
# trace-cmd record -C x86-tsc -e kvm:* -e msr:* -A tumbleweed:823 -e
msr:*  sleep 1

>
> Guest:
> # echo x86-tsc > /sys/kernel/tracing/trace_clock

There is no need to set manually the guest clock, it will be
overwritten by trace-cmd agent.

> # trace-cmd agent
>
> Am I doing something wrong?

All your commands and workflow look good, nothing wrong.

>
> If necessary, I can provide more info about my setup, or do more tests.

Yes, please can you send me both host and guest trace files ?
Also, it will be useful to send me the content of the KVM debug files:
    /sys/kernel/debug/kvm/<guest ID>/vcpu<*>/tsc-offset

>
>
> Thanks and Regards,
>
> Stefano

Thanks for testing this code!

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