| Message ID | 20190319155536.19381-9-tstoyanov@vmware.com (mailing list archive) |
|---|---|
| State | Superseded |
| Headers | show |
| Series | trace-cmd: Timetamps sync between host and guest machines, relying on vsock events. | expand |
On Tue, Mar 19, 2019 at 5:56 PM Tzvetomir Stoyanov <tstoyanov@vmware.com> wrote: > +static unsigned long long timestamp_correct(unsigned long long ts, > + struct tracecmd_input *handle) > +{ > + int min, mid, max; > + > + if (handle->ts_offset) > + return ts + handle->ts_offset; > + if (!handle->ts_corr_count || !handle->ts_corr) > + return ts; > + > + /* We have one sample, nothing to calc here */ > + if (handle->ts_corr_count == 1) > + return ts + handle->ts_corr[0].offset; > + > + /* We have two samples, nothing to search here */ > + if (handle->ts_corr_count == 2) > + return timestamp_correction_calc(ts, &handle->ts_corr[0], > + &handle->ts_corr[1]); > + > + /* We have more than two samples */ > + min = 0; > + max = handle->ts_corr_count-1; > + mid = (min + max)/2; > + while (min <= max) { > + if (ts >= handle->ts_corr[mid].time && > + (mid == handle->ts_corr_count-1 || > + ts < handle->ts_corr[mid+1].time)) > + break; > + if (ts < handle->ts_corr[mid].time) { > + if (mid == 0) > + break; > + min = mid-1; > + } else if (ts >= handle->ts_corr[mid+1].time) > + max = mid + 1; > + mid = (min + max)/2; > + } > + > + if (mid >= handle->ts_corr_count-2) > + return timestamp_correction_calc(ts, &handle->ts_corr[handle->ts_corr_count-2], > + &handle->ts_corr[handle->ts_corr_count-1]); > + > + return timestamp_correction_calc(ts, &handle->ts_corr[mid], > + &handle->ts_corr[mid+1]); We can handle the edge cases first (ts is out of range) which would simplify the search. Something like (untested): if (ts <= handle->ts_corr[0]) { return timestamp_correction_calc(ts, &handle->ts_corr[0], &handle->ts_corr[1]); } else if (ts >= handle->ts_corr[handle->ts_corr_count-1]) { return timestamp_correction_calc(ts, &handle->ts_corr[handle->ts_corr_count-2], &handle->ts_corr[handle->ts_corr_count-1]); } min = 0; max = handle->ts_corr_count-1; mid = (min + max) / 2; while (min <= max) { if (ts < handle->ts_corr[mid].time) min = mid - 1; else if (ts > handle->ts_corr[mid].time) max = mid + 1; else break; mid = (min + max) / 2; } return timestamp_correction_calc(ts, &handle->ts_corr[mid], &handle->ts_corr[mid+1]); Too bad there's no lower_bound() in libc and bsearch() doesn't quite cut it here. > +} > + > /* > * Page is mapped, now read in the page header info. > */ > @@ -1049,7 +1116,7 @@ static int update_page_info(struct tracecmd_input *handle, int cpu) > kbuffer_subbuffer_size(kbuf)); > return -1; > } > - handle->cpu_data[cpu].timestamp = kbuffer_timestamp(kbuf) + handle->ts_offset; > + handle->cpu_data[cpu].timestamp = timestamp_correct(kbuffer_timestamp(kbuf), handle); > > if (handle->ts2secs) > handle->cpu_data[cpu].timestamp *= handle->ts2secs; > @@ -1776,7 +1843,7 @@ read_again: > goto read_again; > } > > - handle->cpu_data[cpu].timestamp = ts + handle->ts_offset; > + handle->cpu_data[cpu].timestamp = timestamp_correct(ts, handle); > > if (handle->ts2secs) { > handle->cpu_data[cpu].timestamp *= handle->ts2secs; > @@ -2101,6 +2168,42 @@ void tracecmd_set_ts2secs(struct tracecmd_input *handle, > handle->use_trace_clock = false; > } > > +static int tsync_offset_cmp(const void *a, const void *b) > +{ > + struct ts_offset_sample *ts_a = (struct ts_offset_sample *)a; > + struct ts_offset_sample *ts_b = (struct ts_offset_sample *)b; > + > + if (ts_a->time > ts_b->time) > + return 1; > + if (ts_a->time < ts_b->time) > + return -1; > + return 0; > +} > + > +static void tsync_offset_load(struct tracecmd_input *handle, char *buf) > +{ > + int i, j; > + long long *buf8 = (long long *)buf; > + > + for (i = 0; i < handle->ts_corr_count; i++) { > + handle->ts_corr[i].time = tep_read_number(handle->pevent, > + buf8+i, 8); > + handle->ts_corr[i].offset = tep_read_number(handle->pevent, > + buf8+handle->ts_corr_count+i, 8); > + } > + qsort(handle->ts_corr, > + handle->ts_corr_count, sizeof(struct ts_offset_sample), > + tsync_offset_cmp); > + /* Filter possible samples with equal time */ > + for (i = 0, j = 0; i < handle->ts_corr_count; i++) { > + if (i == 0 || > + handle->ts_corr[i].time != handle->ts_corr[i-1].time) { > + handle->ts_corr[j++].time = handle->ts_corr[i].time; > + handle->ts_corr[j++].offset = handle->ts_corr[i].offset; `j` needs to be increment only once here. How about: if (i == 0 || handle->ts_corr[i].time != handle->ts_corr[i-1].time) handle->ts_corr[j++] = handle->ts_corr[i]; Thanks! -- Slavi
On Tue, Mar 19, 2019 at 5:56 PM Tzvetomir Stoyanov <tstoyanov@vmware.com> wrote: > > The TRACECMD_OPTION_TIME_SHIFT is used when synchronizing trace time stamps between > two trace.dat files. It contains multiple long long (time, offset) pairs, describing > time stamps _offset_, measured in the given local _time_. The content of the option > buffer is: > first 4 bytes - integer, count of timestamp offsets > long long array of size _count_, local time in which the offset is measured > long long array of size _count_, offset of the time stamps > > Signed-off-by: Tzvetomir Stoyanov <tstoyanov@vmware.com> > --- > include/trace-cmd/trace-cmd.h | 1 + > lib/trace-cmd/trace-input.c | 127 +++++++++++++++++++++++++++++++++- > 2 files changed, 126 insertions(+), 2 deletions(-) > > diff --git a/include/trace-cmd/trace-cmd.h b/include/trace-cmd/trace-cmd.h > index f7c043a..5552396 100644 > --- a/include/trace-cmd/trace-cmd.h > +++ b/include/trace-cmd/trace-cmd.h > @@ -82,6 +82,7 @@ enum { > TRACECMD_OPTION_HOOK, > TRACECMD_OPTION_OFFSET, > TRACECMD_OPTION_CPUCOUNT, > + TRACECMD_OPTION_TIME_SHIFT, > }; > > enum { > diff --git a/lib/trace-cmd/trace-input.c b/lib/trace-cmd/trace-input.c > index 0a6e820..04f222d 100644 > --- a/lib/trace-cmd/trace-input.c > +++ b/lib/trace-cmd/trace-input.c > @@ -75,6 +75,11 @@ struct input_buffer_instance { > size_t offset; > }; > > +struct ts_offset_sample { > + long long time; > + long long offset; > +}; > + > struct tracecmd_input { > struct tep_handle *pevent; > struct tep_plugin_list *plugin_list; > @@ -92,6 +97,8 @@ struct tracecmd_input { > bool use_pipe; > struct cpu_data *cpu_data; > long long ts_offset; > + int ts_corr_count; > + struct ts_offset_sample *ts_corr; Nit: ts_corr_count -> ts_samples_count ts_corr -> ts_samples
On Tue, Mar 19, 2019 at 8:00 PM Slavomir Kaslev <kaslevs@vmware.com> wrote: > > On Tue, Mar 19, 2019 at 5:56 PM Tzvetomir Stoyanov <tstoyanov@vmware.com> wrote: > > > > The TRACECMD_OPTION_TIME_SHIFT is used when synchronizing trace time stamps between > > two trace.dat files. It contains multiple long long (time, offset) pairs, describing > > time stamps _offset_, measured in the given local _time_. The content of the option > > buffer is: > > first 4 bytes - integer, count of timestamp offsets > > long long array of size _count_, local time in which the offset is measured > > long long array of size _count_, offset of the time stamps > > > > Signed-off-by: Tzvetomir Stoyanov <tstoyanov@vmware.com> > > --- > > include/trace-cmd/trace-cmd.h | 1 + > > lib/trace-cmd/trace-input.c | 127 +++++++++++++++++++++++++++++++++- > > 2 files changed, 126 insertions(+), 2 deletions(-) > > > > diff --git a/include/trace-cmd/trace-cmd.h b/include/trace-cmd/trace-cmd.h > > index f7c043a..5552396 100644 > > --- a/include/trace-cmd/trace-cmd.h > > +++ b/include/trace-cmd/trace-cmd.h > > @@ -82,6 +82,7 @@ enum { > > TRACECMD_OPTION_HOOK, > > TRACECMD_OPTION_OFFSET, > > TRACECMD_OPTION_CPUCOUNT, > > + TRACECMD_OPTION_TIME_SHIFT, > > }; > > > > enum { > > diff --git a/lib/trace-cmd/trace-input.c b/lib/trace-cmd/trace-input.c > > index 0a6e820..04f222d 100644 > > --- a/lib/trace-cmd/trace-input.c > > +++ b/lib/trace-cmd/trace-input.c > > @@ -75,6 +75,11 @@ struct input_buffer_instance { > > size_t offset; > > }; > > > > +struct ts_offset_sample { > > + long long time; > > + long long offset; > > +}; > > + > > struct tracecmd_input { > > struct tep_handle *pevent; > > struct tep_plugin_list *plugin_list; > > @@ -92,6 +97,8 @@ struct tracecmd_input { > > bool use_pipe; > > struct cpu_data *cpu_data; > > long long ts_offset; > > + int ts_corr_count; > > + struct ts_offset_sample *ts_corr; > > Nit: > ts_corr_count -> ts_samples_count > ts_corr -> ts_samples Thanks Slavi
diff --git a/include/trace-cmd/trace-cmd.h b/include/trace-cmd/trace-cmd.h index f7c043a..5552396 100644 --- a/include/trace-cmd/trace-cmd.h +++ b/include/trace-cmd/trace-cmd.h @@ -82,6 +82,7 @@ enum { TRACECMD_OPTION_HOOK, TRACECMD_OPTION_OFFSET, TRACECMD_OPTION_CPUCOUNT, + TRACECMD_OPTION_TIME_SHIFT, }; enum { diff --git a/lib/trace-cmd/trace-input.c b/lib/trace-cmd/trace-input.c index 0a6e820..04f222d 100644 --- a/lib/trace-cmd/trace-input.c +++ b/lib/trace-cmd/trace-input.c @@ -75,6 +75,11 @@ struct input_buffer_instance { size_t offset; }; +struct ts_offset_sample { + long long time; + long long offset; +}; + struct tracecmd_input { struct tep_handle *pevent; struct tep_plugin_list *plugin_list; @@ -92,6 +97,8 @@ struct tracecmd_input { bool use_pipe; struct cpu_data *cpu_data; long long ts_offset; + int ts_corr_count; + struct ts_offset_sample *ts_corr; double ts2secs; char * cpustats; char * uname; @@ -1028,6 +1035,66 @@ static void free_next(struct tracecmd_input *handle, int cpu) free_record(record); } +static inline unsigned long long +timestamp_correction_calc(unsigned long long ts, struct ts_offset_sample *min, + struct ts_offset_sample *max) +{ + long long tscor = min->offset + + (((((long long)ts) - min->time)* + (max->offset-min->offset))/(max->time-min->time)); + + if (tscor < 0) + return ts - llabs(tscor); + + return ts + tscor; + +} + +static unsigned long long timestamp_correct(unsigned long long ts, + struct tracecmd_input *handle) +{ + int min, mid, max; + + if (handle->ts_offset) + return ts + handle->ts_offset; + if (!handle->ts_corr_count || !handle->ts_corr) + return ts; + + /* We have one sample, nothing to calc here */ + if (handle->ts_corr_count == 1) + return ts + handle->ts_corr[0].offset; + + /* We have two samples, nothing to search here */ + if (handle->ts_corr_count == 2) + return timestamp_correction_calc(ts, &handle->ts_corr[0], + &handle->ts_corr[1]); + + /* We have more than two samples */ + min = 0; + max = handle->ts_corr_count-1; + mid = (min + max)/2; + while (min <= max) { + if (ts >= handle->ts_corr[mid].time && + (mid == handle->ts_corr_count-1 || + ts < handle->ts_corr[mid+1].time)) + break; + if (ts < handle->ts_corr[mid].time) { + if (mid == 0) + break; + min = mid-1; + } else if (ts >= handle->ts_corr[mid+1].time) + max = mid + 1; + mid = (min + max)/2; + } + + if (mid >= handle->ts_corr_count-2) + return timestamp_correction_calc(ts, &handle->ts_corr[handle->ts_corr_count-2], + &handle->ts_corr[handle->ts_corr_count-1]); + + return timestamp_correction_calc(ts, &handle->ts_corr[mid], + &handle->ts_corr[mid+1]); +} + /* * Page is mapped, now read in the page header info. */ @@ -1049,7 +1116,7 @@ static int update_page_info(struct tracecmd_input *handle, int cpu) kbuffer_subbuffer_size(kbuf)); return -1; } - handle->cpu_data[cpu].timestamp = kbuffer_timestamp(kbuf) + handle->ts_offset; + handle->cpu_data[cpu].timestamp = timestamp_correct(kbuffer_timestamp(kbuf), handle); if (handle->ts2secs) handle->cpu_data[cpu].timestamp *= handle->ts2secs; @@ -1776,7 +1843,7 @@ read_again: goto read_again; } - handle->cpu_data[cpu].timestamp = ts + handle->ts_offset; + handle->cpu_data[cpu].timestamp = timestamp_correct(ts, handle); if (handle->ts2secs) { handle->cpu_data[cpu].timestamp *= handle->ts2secs; @@ -2101,6 +2168,42 @@ void tracecmd_set_ts2secs(struct tracecmd_input *handle, handle->use_trace_clock = false; } +static int tsync_offset_cmp(const void *a, const void *b) +{ + struct ts_offset_sample *ts_a = (struct ts_offset_sample *)a; + struct ts_offset_sample *ts_b = (struct ts_offset_sample *)b; + + if (ts_a->time > ts_b->time) + return 1; + if (ts_a->time < ts_b->time) + return -1; + return 0; +} + +static void tsync_offset_load(struct tracecmd_input *handle, char *buf) +{ + int i, j; + long long *buf8 = (long long *)buf; + + for (i = 0; i < handle->ts_corr_count; i++) { + handle->ts_corr[i].time = tep_read_number(handle->pevent, + buf8+i, 8); + handle->ts_corr[i].offset = tep_read_number(handle->pevent, + buf8+handle->ts_corr_count+i, 8); + } + qsort(handle->ts_corr, + handle->ts_corr_count, sizeof(struct ts_offset_sample), + tsync_offset_cmp); + /* Filter possible samples with equal time */ + for (i = 0, j = 0; i < handle->ts_corr_count; i++) { + if (i == 0 || + handle->ts_corr[i].time != handle->ts_corr[i-1].time) { + handle->ts_corr[j++].time = handle->ts_corr[i].time; + handle->ts_corr[j++].offset = handle->ts_corr[i].offset; + } + } +} + static int handle_options(struct tracecmd_input *handle) { long long offset; @@ -2111,6 +2214,7 @@ static int handle_options(struct tracecmd_input *handle) struct input_buffer_instance *buffer; struct hook_list *hook; char *buf; + int tsync; int cpus; for (;;) { @@ -2155,6 +2259,25 @@ static int handle_options(struct tracecmd_input *handle) offset = strtoll(buf, NULL, 0); handle->ts_offset += offset; break; + case TRACECMD_OPTION_TIME_SHIFT: + /* + * int (4 bytes) count of timestamp offsets. + * long long array of size [count] of times, + * when the offsets were calculated. + * long long array of size [count] of timestamp offsets. + */ + if (handle->flags & TRACECMD_FL_IGNORE_DATE) + break; + handle->ts_corr_count = tep_read_number(handle->pevent, + buf, 4); + tsync = (sizeof(long long)*handle->ts_corr_count); + if (size != (4+(2*tsync))) + break; + handle->ts_corr = malloc(2*tsync); + if (!handle->ts_corr) + return -ENOMEM; + tsync_offset_load(handle, buf+4); + break; case TRACECMD_OPTION_CPUSTAT: buf[size-1] = '\n'; cpustats = realloc(cpustats, cpustats_size + size + 1);
The TRACECMD_OPTION_TIME_SHIFT is used when synchronizing trace time stamps between two trace.dat files. It contains multiple long long (time, offset) pairs, describing time stamps _offset_, measured in the given local _time_. The content of the option buffer is: first 4 bytes - integer, count of timestamp offsets long long array of size _count_, local time in which the offset is measured long long array of size _count_, offset of the time stamps Signed-off-by: Tzvetomir Stoyanov <tstoyanov@vmware.com> --- include/trace-cmd/trace-cmd.h | 1 + lib/trace-cmd/trace-input.c | 127 +++++++++++++++++++++++++++++++++- 2 files changed, 126 insertions(+), 2 deletions(-)