diff options
author | 2025-03-02 18:40:11 -0500 | |
---|---|---|
committer | 2025-03-03 19:40:50 +0000 | |
commit | 193371ef11e3ed95a095e9d4169c22b18fb94af1 (patch) | |
tree | b2e775f9a1bea17f1fd3a324da7ec8890db0b954 | |
parent | e1d40bf585ef23e24145bee1cd89ae0ab8bc303d (diff) |
vppinfra: make verbose format time more verbose
Dump more cpu and reftime fields in clib time struct. Example:
DBGvpp# sh clock verbose
Time now 6.890267
cpu time 6.890267 now 22333609568369233 last 22333609568350337 since start 19981775480
reftime 6.890268 now 1740958292.416887 last 1740958285.526620 init 1740958285.526620
error 0.000000, clocks/sec 2900000000.000000, Sun, 02 Mar 2025 23:31:32 GMT
Time last barrier release 3.291883104
0: Time now 6.890387
cpu time 6.890387 now 22333609568706225 last 22333609568696497 since start 19982121640
reftime 6.890387 now 1740958292.417007 last 1740958285.526620 init 1740958285.526620
error -.000001, clocks/sec 2900000000.000000
Thread 0 offset 0.000000000 error 0.000000000
1: Time now 5.695180
cpu time 5.695180 now 22333609568926421 last 22333609568920073 since start 16516023212
reftime 5.695181 now 1740958292.417084 last 1740958286.721903 init 1740958286.721903
error -.000001, clocks/sec 2900000000.000000
Thread 1 offset 1.195283275 error -.000000114
Type: improvement
Change-Id: I383b9b1a2ef64a731bbc335cd512d565d47f0cd9
Signed-off-by: Florin Coras <fcoras@cisco.com>
-rw-r--r-- | src/vppinfra/time.c | 11 |
1 files changed, 9 insertions, 2 deletions
diff --git a/src/vppinfra/time.c b/src/vppinfra/time.c index f1736499a0a..7c0ea44b481 100644 --- a/src/vppinfra/time.c +++ b/src/vppinfra/time.c @@ -332,6 +332,7 @@ format_clib_time (u8 * s, va_list * args) clib_time_t *c = va_arg (*args, clib_time_t *); int verbose = va_arg (*args, int); f64 now, reftime, delta_reftime_in_seconds, error; + u32 indent = format_get_indent (s); /* Compute vpp elapsed time from the CPU clock */ reftime = unix_time_now (); @@ -346,8 +347,14 @@ format_clib_time (u8 * s, va_list * args) error = now - delta_reftime_in_seconds; - s = format (s, ", reftime %.6f, error %.6f, clocks/sec %.6f", - delta_reftime_in_seconds, error, c->clocks_per_second); + s = format (s, "\n%Ucpu time %.6f now %lu last %lu since start %lu \n", + format_white_space, indent, now, clib_cpu_time_now (), + c->last_cpu_time, c->total_cpu_time); + s = format (s, "%Ureftime %.6f now %.6f last %.6f init %.6f\n", + format_white_space, indent, delta_reftime_in_seconds, reftime, + c->last_verify_reference_time, c->init_reference_time); + s = format (s, "%Uerror %.6f, clocks/sec %.6f", format_white_space, indent, + error, c->clocks_per_second); return (s); } |