John Crispin <j...@phrozen.org> writes: > On 17/01/18 10:54, Koen Vandeputte wrote: >> >> >> On 2018-01-17 10:43, Karl Vogel wrote: >>> Shows how long an initd task took, for example: >>> >>> procd: stop /etc/init.d/dropbear running - took 0.088824s >>> procd: Update service dnsmasq >>> procd: Update instance dnsmasq::dnsmasq >>> procd: running /etc/init.d/dnsmasq running >>> procd: start /etc/init.d/dnsmasq running >>> procd: stop /etc/init.d/dnsmasq running - took 0.092586s >>> >>> Signed-off-by: Karl Vogel <karl.vo...@gmail.com> >>> --- >>> rcS.c | 7 ++++++- >>> 1 file changed, 6 insertions(+), 1 deletion(-) >>> >>> diff --git a/rcS.c b/rcS.c >>> index dd3b76d..acfb6a0 100644 >>> --- a/rcS.c >>> +++ b/rcS.c >>> @@ -37,6 +37,7 @@ static struct runqueue q, r; >>> struct initd { >>> struct ustream_fd fd; >>> struct runqueue_process proc; >>> + struct timeval tv_start; >>> char *file; >>> char *param; >>> }; >>> @@ -70,6 +71,7 @@ static void q_initd_run(struct runqueue *q, struct >>> runqueue_task *t) >>> int pipefd[2]; >>> pid_t pid; >>> + gettimeofday(&s->tv_start, NULL); >>> DEBUG(2, "start %s %s \n", s->file, s->param); >>> if (pipe(pipefd) == -1) { >>> ERROR("Failed to create pipe: %m\n"); >>> @@ -106,8 +108,11 @@ static void q_initd_run(struct runqueue *q, >>> struct runqueue_task *t) >>> static void q_initd_complete(struct runqueue *q, struct >>> runqueue_task *p) >>> { >>> struct initd *s = container_of(p, struct initd, proc.task); >>> + struct timeval tv_stop, tv_res; >>> - DEBUG(2, "stop %s %s \n", s->file, s->param); >>> + gettimeofday(&tv_stop, NULL); >>> + timersub(&tv_stop, &s->tv_start, &tv_res); >>> + DEBUG(2, "stop %s %s - took %lu.%06lus\n", s->file, s->param, >>> tv_res.tv_sec, tv_res.tv_usec); >>> ustream_free(&s->fd.stream); >>> close(s->fd.fd.fd); >>> free(s); >> Isn't it better to use a monotonic time source here to measure elapsed >> time? >> |This way you avoid racing issues should NTP sync kick in during >> execution. >> >> >> |||clock_gettime(CLOCK_MONOTONIC, ...)|||| > > that occurred to me aswell as i was just testing the patch inside a vm :-) > > John
I considered that, but then it would require a bit more logic to do the subtract, as clock_gettime uses a timespec not a timeval. Nothing impossible ofcourse, but didn't want to increase the size too much for debug output that isn't active in 99.9% of the installations. clock_gettime(CLOCK_MONOTONIC, ... ) is also affected by NTP and adjtime(), so even that won't be 100% when the clock is adjusted. Karl _______________________________________________ Lede-dev mailing list Lede-dev@lists.infradead.org http://lists.infradead.org/mailman/listinfo/lede-dev