| Message ID | 20210320183829.1318-16-dwagner@suse.de |
|---|---|
| State | New |
| Headers | show |
| Series | JSON cleanups and more tests updated | expand |
On Sat, 20 Mar 2021, Daniel Wagner wrote: > For the JSON output records a timestamp when the test ended. > Let's introduce a new API to record a timestamp when the test > starts. We could put this into rt_init() but in this case we > would meassure also the time test needs to setup or warm up. > > Signed-off-by: Daniel Wagner <dwagner@suse.de> > --- > src/include/rt-utils.h | 2 ++ > src/lib/rt-utils.c | 34 ++++++++++++++++++++++++---------- > 2 files changed, 26 insertions(+), 10 deletions(-) > > diff --git a/src/include/rt-utils.h b/src/include/rt-utils.h > index 115791c55185..42c2772262db 100644 > --- a/src/include/rt-utils.h > +++ b/src/include/rt-utils.h > @@ -82,6 +82,8 @@ static inline int64_t calctime(struct timespec t) > > void rt_init(int argc, char *argv[]); > > +void rt_test_start(void); > + > void rt_write_json(const char *filename, > void (*cb)(FILE *, void *), > void *data); > diff --git a/src/lib/rt-utils.c b/src/lib/rt-utils.c > index f736a3449bf7..efb5d1d9e866 100644 > --- a/src/lib/rt-utils.c > +++ b/src/lib/rt-utils.c > @@ -30,6 +30,7 @@ > > #define TRACEBUFSIZ 1024 > #define MAX_COMMAND_LINE 4096 > +#define MAX_TS_SIZE 64 > > static char debugfileprefix[MAX_PATH]; > static char *fileprefix; > @@ -37,6 +38,7 @@ static int trace_fd = -1; > static int tracemark_fd = -1; > static __thread char tracebuf[TRACEBUFSIZ]; > static char test_cmdline[MAX_COMMAND_LINE]; > +static char ts_start[MAX_TS_SIZE]; > > /* > * Finds the tracing directory in a mounted debugfs > @@ -514,17 +516,32 @@ void rt_init(int argc, char *argv[]) > } > } > > +static void get_timestamp(char *tsbuf) > +{ > + struct timeval tv; > + struct tm *tm; > + time_t t; > + > + gettimeofday(&tv, NULL); > + t = tv.tv_sec; > + tm = localtime(&t); > + /* RFC 2822-compliant date format */ > + strftime(tsbuf, MAX_TS_SIZE, "%a, %d %b %Y %T %z", tm); > +} > + > +void rt_test_start(void) > +{ > + get_timestamp(ts_start); > +} > + > void rt_write_json(const char *filename, > void (*cb)(FILE *, void *), > void *data) > { > unsigned char buf[1]; > struct utsname uts; > - struct timeval tv; > - char tsbuf[64]; > - struct tm *tm; > + char ts_end[MAX_TS_SIZE]; > FILE *f, *s; > - time_t t; > size_t n; > int rt = 0; > > @@ -536,11 +553,7 @@ void rt_write_json(const char *filename, > err_exit(errno, "Failed to open '%s'\n", filename); > } > > - gettimeofday(&tv, NULL); > - t = tv.tv_sec; > - tm = localtime(&t); > - /* RFC 2822-compliant date format */ > - strftime(tsbuf, sizeof(tsbuf), "%a, %d %b %Y %T %z", tm); > + get_timestamp(ts_end); > > s = fopen("/sys/kernel/realtime", "r"); > if (s) { > @@ -557,7 +570,8 @@ void rt_write_json(const char *filename, > fprintf(f, " \"file_version\": 1,\n"); > fprintf(f, " \"cmdline:\": \"%s\",\n", test_cmdline); > fprintf(f, " \"rt_test_version:\": \"%1.2f\",\n", VERSION); > - fprintf(f, " \"finished\": \"%s\",\n", tsbuf); > + fprintf(f, " \"start_time\": \"%s\",\n", ts_start); > + fprintf(f, " \"end_time\": \"%s\",\n", ts_end); > fprintf(f, " \"sysinfo\": {\n"); > fprintf(f, " \"sysname\": \"%s\",\n", uts.sysname); > fprintf(f, " \"nodename\": \"%s\",\n", uts.nodename); > -- > 2.30.2 > > I don't really like this. I think it looks "good" in the json output, but I don't think it is providing any kind of meaningful data. My fear is that users will try to assign some kind of significance to these numbers in relation to the tests. I'm letting it in anyway, maybe people will tell me I'm wrong and they like it, but recording my objection for now anyway. Signed-off-by: John Kacur <jkacur@redhat.com>
On Fri, May 07, 2021 at 12:40:20PM -0400, John Kacur wrote: > I don't really like this. I think it looks "good" in the json output, but > I don't think it is providing any kind of meaningful data. My fear is that > users will try to assign some kind of significance to these numbers in > relation to the tests. The idea is that you are able to compare timestamps in the further logs and see if anything is out of the ordinary is logged when the test was executed.
diff --git a/src/include/rt-utils.h b/src/include/rt-utils.h index 115791c55185..42c2772262db 100644 --- a/src/include/rt-utils.h +++ b/src/include/rt-utils.h @@ -82,6 +82,8 @@ static inline int64_t calctime(struct timespec t) void rt_init(int argc, char *argv[]); +void rt_test_start(void); + void rt_write_json(const char *filename, void (*cb)(FILE *, void *), void *data); diff --git a/src/lib/rt-utils.c b/src/lib/rt-utils.c index f736a3449bf7..efb5d1d9e866 100644 --- a/src/lib/rt-utils.c +++ b/src/lib/rt-utils.c @@ -30,6 +30,7 @@ #define TRACEBUFSIZ 1024 #define MAX_COMMAND_LINE 4096 +#define MAX_TS_SIZE 64 static char debugfileprefix[MAX_PATH]; static char *fileprefix; @@ -37,6 +38,7 @@ static int trace_fd = -1; static int tracemark_fd = -1; static __thread char tracebuf[TRACEBUFSIZ]; static char test_cmdline[MAX_COMMAND_LINE]; +static char ts_start[MAX_TS_SIZE]; /* * Finds the tracing directory in a mounted debugfs @@ -514,17 +516,32 @@ void rt_init(int argc, char *argv[]) } } +static void get_timestamp(char *tsbuf) +{ + struct timeval tv; + struct tm *tm; + time_t t; + + gettimeofday(&tv, NULL); + t = tv.tv_sec; + tm = localtime(&t); + /* RFC 2822-compliant date format */ + strftime(tsbuf, MAX_TS_SIZE, "%a, %d %b %Y %T %z", tm); +} + +void rt_test_start(void) +{ + get_timestamp(ts_start); +} + void rt_write_json(const char *filename, void (*cb)(FILE *, void *), void *data) { unsigned char buf[1]; struct utsname uts; - struct timeval tv; - char tsbuf[64]; - struct tm *tm; + char ts_end[MAX_TS_SIZE]; FILE *f, *s; - time_t t; size_t n; int rt = 0; @@ -536,11 +553,7 @@ void rt_write_json(const char *filename, err_exit(errno, "Failed to open '%s'\n", filename); } - gettimeofday(&tv, NULL); - t = tv.tv_sec; - tm = localtime(&t); - /* RFC 2822-compliant date format */ - strftime(tsbuf, sizeof(tsbuf), "%a, %d %b %Y %T %z", tm); + get_timestamp(ts_end); s = fopen("/sys/kernel/realtime", "r"); if (s) { @@ -557,7 +570,8 @@ void rt_write_json(const char *filename, fprintf(f, " \"file_version\": 1,\n"); fprintf(f, " \"cmdline:\": \"%s\",\n", test_cmdline); fprintf(f, " \"rt_test_version:\": \"%1.2f\",\n", VERSION); - fprintf(f, " \"finished\": \"%s\",\n", tsbuf); + fprintf(f, " \"start_time\": \"%s\",\n", ts_start); + fprintf(f, " \"end_time\": \"%s\",\n", ts_end); fprintf(f, " \"sysinfo\": {\n"); fprintf(f, " \"sysname\": \"%s\",\n", uts.sysname); fprintf(f, " \"nodename\": \"%s\",\n", uts.nodename);
For the JSON output records a timestamp when the test ended. Let's introduce a new API to record a timestamp when the test starts. We could put this into rt_init() but in this case we would meassure also the time test needs to setup or warm up. Signed-off-by: Daniel Wagner <dwagner@suse.de> --- src/include/rt-utils.h | 2 ++ src/lib/rt-utils.c | 34 ++++++++++++++++++++++++---------- 2 files changed, 26 insertions(+), 10 deletions(-)