From be3444f1198baeeaaae3ee325ca8b934ddfeb36b Mon Sep 17 00:00:00 2001 From: Lennart Poettering Date: Wed, 24 Apr 2024 12:01:14 +0200 Subject: [PATCH] execute: make ExecStatus dump more useful by showing passed time Let's show the runtimes of our commands and preparations for them. It's actually quite interesting, we sometimes are irritatingly slow with our handoffs. --- src/core/execute.c | 33 +++++++++++++++++++++++++++------ 1 file changed, 27 insertions(+), 6 deletions(-) diff --git a/src/core/execute.c b/src/core/execute.c index 7528629739..05a7f907a9 100644 --- a/src/core/execute.c +++ b/src/core/execute.c @@ -1877,21 +1877,42 @@ void exec_status_dump(const ExecStatus *s, FILE *f, const char *prefix) { if (dual_timestamp_is_set(&s->start_timestamp)) fprintf(f, "%sStart Timestamp: %s\n", - prefix, FORMAT_TIMESTAMP(s->start_timestamp.realtime)); + prefix, FORMAT_TIMESTAMP_STYLE(s->start_timestamp.realtime, TIMESTAMP_US)); - if (dual_timestamp_is_set(&s->handoff_timestamp)) + if (dual_timestamp_is_set(&s->handoff_timestamp) && dual_timestamp_is_set(&s->start_timestamp) && + s->handoff_timestamp.monotonic > s->start_timestamp.monotonic) + fprintf(f, + "%sHandoff Timestamp: %s since start\n", + prefix, + FORMAT_TIMESPAN(usec_sub_unsigned(s->handoff_timestamp.monotonic, s->start_timestamp.monotonic), 1)); + else fprintf(f, "%sHandoff Timestamp: %s\n", - prefix, FORMAT_TIMESTAMP(s->handoff_timestamp.realtime)); + prefix, FORMAT_TIMESTAMP_STYLE(s->handoff_timestamp.realtime, TIMESTAMP_US)); + + if (dual_timestamp_is_set(&s->exit_timestamp)) { + + if (dual_timestamp_is_set(&s->handoff_timestamp) && s->exit_timestamp.monotonic > s->handoff_timestamp.monotonic) + fprintf(f, + "%sExit Timestamp: %s since handoff\n", + prefix, + FORMAT_TIMESPAN(usec_sub_unsigned(s->exit_timestamp.monotonic, s->handoff_timestamp.monotonic), 1)); + else if (dual_timestamp_is_set(&s->start_timestamp) && s->exit_timestamp.monotonic > s->start_timestamp.monotonic) + fprintf(f, + "%sExit Timestamp: %s since start\n", + prefix, + FORMAT_TIMESPAN(usec_sub_unsigned(s->exit_timestamp.monotonic, s->start_timestamp.monotonic), 1)); + else + fprintf(f, + "%sExit Timestamp: %s\n", + prefix, FORMAT_TIMESTAMP_STYLE(s->exit_timestamp.realtime, TIMESTAMP_US)); - if (dual_timestamp_is_set(&s->exit_timestamp)) fprintf(f, - "%sExit Timestamp: %s\n" "%sExit Code: %s\n" "%sExit Status: %i\n", - prefix, FORMAT_TIMESTAMP(s->exit_timestamp.realtime), prefix, sigchld_code_to_string(s->code), prefix, s->status); + } } void exec_command_dump(ExecCommand *c, FILE *f, const char *prefix) {