[LEDE-DEV] [PATCH v2] procd: add timing to start/stop logging

[John Crispin]

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.vogel at 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