From: Eugene Syromyatnikov Date: Fri, 21 Apr 2017 03:16:12 +0000 (+0200) Subject: Always print raw values of time data fields X-Git-Tag: v4.17~33 X-Git-Url: https://granicus.if.org/sourcecode?a=commitdiff_plain;h=3277a2370ad53644c1b76c66abdda91d09d9107b;p=strace Always print raw values of time data fields Refactor sprinttime: implement sprinttime_nsec and sprinttime_usec that handle nanoseconds and microseconds, respectively. Always print raw values of time data fields, format string representations of time as comments. * defs.h (sprinttime): Change argument type from time_t to long long. (sprinttime_nsec, sprinttime_usec): New prototypes. * util.c (sprinttime_ex, sprinttime_nsec, sprinttime_usec): New functions. (sprinttime): Turn into a thin wrapper around sprinttime_ex. * stat.h (struct strace_stat): Add has_nsec field. * fetch_struct_stat.c (HAVE_NSEC): New macro. (fetch_struct_stat): Initialize has_nsec field with HAVE_NSEC. * fetch_struct_stat64.c (HAVE_NSEC): New macro. (fetch_struct_stat64): Initialize has_nsec field with HAVE_NSEC. * print_struct_stat.c (print_struct_stat) : Print raw values of time fields, use sprinttime_nsec to format a string representation of time, use tprints_comment to print it as a comment. * statx.c (SYS_FUNC(statx)) : Likewise. * utime.c (SYS_FUNC(utime)): Print raw values of struct utimbuf.actime and struct utimbuf.modtime fields, use sprinttime to format a string representation of time, use tprints_comment to print it as a comment. * tests/tests.h (print_time_t_nsec): Add int argument. * tests/print_time.c (print_time_t_ex): New function. (print_time_t_nsec): Add int argument, turn into a thin wrapper around print_time_t_ex. * tests/utime.c (main): Update expected output. * tests/xstatx.c [!IS_STATX] (HAVE_NSEC): New macro. [!IS_STATX] (PRINT_ST_TIME), [IS_STATX] (PRINT_FIELD_TIME): Update expected output. * NEWS: Mention this timestamps representation improvement. Co-authored-by: Dmitry V. Levin --- diff --git a/NEWS b/NEWS index ce792e2d..3e2fde09 100644 --- a/NEWS +++ b/NEWS @@ -8,6 +8,7 @@ Noteworthy changes in release ?.?? (????-??-??) * Improvements * Optimized syscall filtering. + * Improved representation of timestamps. * Enhanced decoding of sched_setattr syscall. * Added -e trace=%stat option for tracing variants of stat syscall. * Added -e trace=%lstat option for tracing variants of lstat syscall. diff --git a/defs.h b/defs.h index 5a6b5fc6..63bdb0d5 100644 --- a/defs.h +++ b/defs.h @@ -547,7 +547,9 @@ extern int printargs_d(struct tcb *); extern void addflags(const struct xlat *, uint64_t); extern int printflags64(const struct xlat *, uint64_t, const char *); extern const char *sprintflags(const char *, const struct xlat *, uint64_t); -extern const char *sprinttime(time_t); +extern const char *sprinttime(long long sec); +extern const char *sprinttime_nsec(long long sec, unsigned long long nsec); +extern const char *sprinttime_usec(long long sec, unsigned long long usec); extern void print_symbolic_mode_t(unsigned int); extern void print_numeric_umode_t(unsigned short); extern void print_numeric_long_umask(unsigned long); diff --git a/fetch_struct_stat.c b/fetch_struct_stat.c index 50d10284..b9767ed1 100644 --- a/fetch_struct_stat.c +++ b/fetch_struct_stat.c @@ -65,8 +65,10 @@ typedef struct stat struct_stat; #ifdef HAVE_STRUCT_STAT_ST_MTIME_NSEC # define TIME_NSEC(arg) zero_extend_signed_to_ull(arg) +# define HAVE_NSEC true #else # define TIME_NSEC(arg) 0 +# define HAVE_NSEC false #endif MPERS_PRINTER_DECL(bool, fetch_struct_stat, @@ -94,6 +96,7 @@ MPERS_PRINTER_DECL(bool, fetch_struct_stat, dst->atime_nsec = TIME_NSEC(buf.st_atime_nsec); dst->ctime_nsec = TIME_NSEC(buf.st_ctime_nsec); dst->mtime_nsec = TIME_NSEC(buf.st_mtime_nsec); + dst->has_nsec = HAVE_NSEC; return true; #else /* !HAVE_STRUCT_STAT */ printaddr(addr); diff --git a/fetch_struct_stat64.c b/fetch_struct_stat64.c index b7e48057..868d8094 100644 --- a/fetch_struct_stat64.c +++ b/fetch_struct_stat64.c @@ -63,8 +63,10 @@ typedef struct stat64 struct_stat64; #ifdef HAVE_STRUCT_STAT64_ST_MTIME_NSEC # define TIME_NSEC(arg) zero_extend_signed_to_ull(arg) +# define HAVE_NSEC true #else # define TIME_NSEC(arg) 0 +# define HAVE_NSEC false #endif MPERS_PRINTER_DECL(bool, fetch_struct_stat64, @@ -92,6 +94,7 @@ MPERS_PRINTER_DECL(bool, fetch_struct_stat64, dst->atime_nsec = TIME_NSEC(buf.st_atime_nsec); dst->ctime_nsec = TIME_NSEC(buf.st_ctime_nsec); dst->mtime_nsec = TIME_NSEC(buf.st_mtime_nsec); + dst->has_nsec = HAVE_NSEC; return true; #else /* !HAVE_STRUCT_STAT64 */ printaddr(addr); diff --git a/print_struct_stat.c b/print_struct_stat.c index b5e0167e..9e967b5e 100644 --- a/print_struct_stat.c +++ b/print_struct_stat.c @@ -65,11 +65,16 @@ print_struct_stat(struct tcb *tcp, const struct strace_stat *const st) } if (!abbrev(tcp)) { -#define PRINT_ST_TIME(field) \ - tprints(", st_" #field "="); \ - tprints(sprinttime(st->field)); \ - if (st->field ## _nsec) \ - tprintf(".%09llu", st->field ## _nsec) +#define PRINT_ST_TIME(field) \ + do { \ + tprintf(", st_" #field "=%lld", (long long) st->field); \ + tprints_comment(sprinttime_nsec(st->field, \ + zero_extend_signed_to_ull(st->field ## _nsec)));\ + if (st->has_nsec) \ + tprintf(", st_" #field "_nsec=%llu", \ + zero_extend_signed_to_ull( \ + st->field ## _nsec)); \ + } while (0) PRINT_ST_TIME(atime); PRINT_ST_TIME(mtime); diff --git a/stat.h b/stat.h index 092d2687..e4fd6081 100644 --- a/stat.h +++ b/stat.h @@ -45,6 +45,7 @@ struct strace_stat { unsigned long long atime_nsec; unsigned long long ctime_nsec; unsigned long long mtime_nsec; + bool has_nsec; }; #endif /* !STRACE_STAT_H */ diff --git a/statx.c b/statx.c index c53f29c2..6e913878 100644 --- a/statx.c +++ b/statx.c @@ -59,10 +59,11 @@ SYS_FUNC(statx) #define PRINT_FIELD_TIME(field) \ do { \ - tprints(", " #field "="); \ - tprints(sprinttime(stx.field.sec)); \ - if (stx.field.nsec) \ - tprintf(".%09" PRId32, stx.field.nsec); \ + tprintf(", " #field "={tv_sec=%" PRId64 \ + ", tv_nsec=%" PRIu32 "}", \ + stx.field.sec, stx.field.nsec); \ + tprints_comment(sprinttime_nsec(stx.field.sec, \ + zero_extend_signed_to_ull(stx.field.nsec))); \ } while (0) struct_statx stx; diff --git a/tests/print_time.c b/tests/print_time.c index 3d5b5545..40893d39 100644 --- a/tests/print_time.c +++ b/tests/print_time.c @@ -31,24 +31,39 @@ #include #include -void -print_time_t_nsec(const time_t t, const unsigned long long nsec) +static void +print_time_t_ex(const time_t t, const unsigned long long part_sec, + const unsigned int max_part_sec, const int width, + const int comment) { - if (t) { - const struct tm *const p = localtime(&t); - char buf[256]; - if (!p) { - perror_msg_and_fail("localtime"); - } + if ((!t && !part_sec) || part_sec > max_part_sec) + return; + + const struct tm *const p = localtime(&t); + char buf[256]; + if (!p || !strftime(buf, sizeof(buf), "%FT%T", p)) + return; + + if (comment) + fputs(" /* ", stdout); + + fputs(buf, stdout); + + if (part_sec) + printf(".%0*llu", width, part_sec); - strftime(buf, sizeof(buf), "%FT%T%z", p); + if (strftime(buf, sizeof(buf), "%z", p)) fputs(buf, stdout); - } else { - putchar('0'); - } - if (nsec) { - printf(".%09llu", nsec); - } + if (comment) + fputs(" */", stdout); + + return; +} + +void +print_time_t_nsec(const time_t t, const unsigned long long nsec, int comment) +{ + print_time_t_ex(t, nsec, 999999999, 9, comment); } diff --git a/tests/tests.h b/tests/tests.h index d7bbff45..a8ec585e 100644 --- a/tests/tests.h +++ b/tests/tests.h @@ -123,7 +123,7 @@ void print_quoted_string(const char *); void print_quoted_memory(const char *, size_t); /* Print time_t and nanoseconds in symbolic format. */ -void print_time_t_nsec(time_t, unsigned long long); +void print_time_t_nsec(time_t, unsigned long long, int); /* Read an int from the file. */ int read_int_from_file(const char *, int *); diff --git a/tests/utime.c b/tests/utime.c index a8d36645..de48307c 100644 --- a/tests/utime.c +++ b/tests/utime.c @@ -68,10 +68,10 @@ main(void) rc = k_utime("utime\nfilename", tail_u); const char *errstr = sprintrc(rc); - printf("utime(\"utime\\nfilename\", {actime="); - print_time_t_nsec(t, 0); - printf(", modtime="); - print_time_t_nsec(t, 0); + printf("utime(\"utime\\nfilename\", {actime=%lld", (long long) t); + print_time_t_nsec(t, 0, 1); + printf(", modtime=%lld", (long long) t); + print_time_t_nsec(t, 0, 1); printf("}) = %s\n", errstr); puts("+++ exited with 0 +++"); diff --git a/tests/xstatx.c b/tests/xstatx.c index eb78ffe8..79faca93 100644 --- a/tests/xstatx.c +++ b/tests/xstatx.c @@ -171,14 +171,20 @@ print_stat(const STRUCT_STAT *st) # if defined(HAVE_STRUCT_STAT_ST_MTIME_NSEC) && !OLD_STAT # define TIME_NSEC(val) zero_extend_signed_to_ull(val) +# define HAVE_NSEC 1 # else -# define TIME_NSEC(val) 0 +# define TIME_NSEC(val) 0ULL +# define HAVE_NSEC 0 # endif -# define PRINT_ST_TIME(field) \ - printf(", st_" #field "="); \ +#define PRINT_ST_TIME(field) \ + printf(", st_" #field "=%lld", \ + sign_extend_unsigned_to_ll(st->st_ ## field)); \ print_time_t_nsec(sign_extend_unsigned_to_ll(st->st_ ## field), \ - TIME_NSEC(st->st_ ## field ## _nsec)) + TIME_NSEC(st->st_ ## field ## _nsec), 1); \ + if (HAVE_NSEC) \ + printf(", st_" #field "_nsec=%llu", \ + TIME_NSEC(st->st_ ## field ## _nsec)) PRINT_ST_TIME(atime); PRINT_ST_TIME(mtime); @@ -200,10 +206,12 @@ print_stat(const STRUCT_STAT *st) else \ printf(", %s=%llu", #field, (unsigned long long) st->field) -# define PRINT_FIELD_TIME(field) \ - printf(", %s=", #field); \ - print_time_t_nsec(st->field.tv_sec, \ - zero_extend_signed_to_ull(st->field.tv_nsec)) +# define PRINT_FIELD_TIME(field) \ + printf(", %s={tv_sec=%lld, tv_nsec=%u}", \ + #field, (long long) st->field.tv_sec, \ + (unsigned) st->field.tv_nsec); \ + print_time_t_nsec(st->field.tv_sec, \ + zero_extend_signed_to_ull(st->field.tv_nsec), 1); printf("{stx_mask="); printflags(statx_masks, st->stx_mask, "STATX_???"); diff --git a/util.c b/util.c index 8bf4c577..51a02200 100644 --- a/util.c +++ b/util.c @@ -541,21 +541,62 @@ printnum_addr_klong_int(struct tcb *tcp, const kernel_ulong_t addr) } #endif /* !current_klongsize */ +/** + * Prints time to a (static internal) buffer and returns pointer to it. + * + * @param sec Seconds since epoch. + * @param part_sec Amount of second parts since the start of a second. + * @param max_part_sec Maximum value of a valid part_sec. + * @param width 1 + floor(log10(max_part_sec)). + */ +static const char * +sprinttime_ex(const long long sec, const unsigned long long part_sec, + const unsigned int max_part_sec, const int width) +{ + static char buf[sizeof(int) * 3 * 6 + sizeof(part_sec) * 3 + + sizeof("+0000")]; + + if ((sec == 0 && part_sec == 0) || part_sec > max_part_sec) + return NULL; + + time_t t = (time_t) sec; + struct tm *tmp = (sec == t) ? localtime(&t) : NULL; + if (!tmp) + return NULL; + + size_t pos = strftime(buf, sizeof(buf), "%FT%T", tmp); + if (!pos) + return NULL; + + if (part_sec > 0) { + int ret = snprintf(buf + pos, sizeof(buf) - pos, ".%0*llu", + width, part_sec); + + if (ret < 0 || (size_t) ret >= sizeof(buf) - pos) + return NULL; + + pos += ret; + } + + return strftime(buf + pos, sizeof(buf) - pos, "%z", tmp) ? buf : NULL; +} + const char * -sprinttime(time_t t) +sprinttime(long long sec) { - struct tm *tmp; - static char buf[sizeof(int) * 3 * 6 + sizeof("+0000")]; - - if (t == 0) - return "0"; - tmp = localtime(&t); - if (tmp) - strftime(buf, sizeof(buf), "%FT%T%z", tmp); - else - snprintf(buf, sizeof(buf), "%lu", (unsigned long) t); + return sprinttime_ex(sec, 0, 0, 0); +} - return buf; +const char * +sprinttime_usec(long long sec, unsigned long long usec) +{ + return sprinttime_ex(sec, usec, 999999, 6); +} + +const char * +sprinttime_nsec(long long sec, unsigned long long nsec) +{ + return sprinttime_ex(sec, nsec, 999999999, 9); } enum sock_proto diff --git a/utime.c b/utime.c index 8126b350..6ab6d892 100644 --- a/utime.c +++ b/utime.c @@ -15,8 +15,11 @@ SYS_FUNC(utime) printpath(tcp, tcp->u_arg[0]); tprints(", "); if (!umove_or_printaddr(tcp, tcp->u_arg[1], &u)) { - tprintf("{actime=%s,", sprinttime(u.actime)); - tprintf(" modtime=%s}", sprinttime(u.modtime)); + tprintf("{actime=%lld", (long long) u.actime); + tprints_comment(sprinttime(u.actime)); + tprintf(", modtime=%lld", (long long) u.modtime); + tprints_comment(sprinttime(u.modtime)); + tprints("}"); } return RVAL_DECODED;