Reuse current timestamp in sort_vector_time_span

For performance. One syscall less per log is good!

Change-Id: I7cd41affc5367e825c52cdf70fdaf83c1dc521f1

diff --git a/include/sort_vector.h b/include/sort_vector.h
index 851b52a..5cfef69 100644 (file)
--- a/include/sort_vector.h
+++ b/include/sort_vector.h
@@ -49,4 +49,4 @@ void sort_vector_pop(struct sort_vector *logs);
 dlogutil_entry_s *sort_vector_pop_ret(struct sort_vector *logs);
 void sort_vector_apply_config(struct sort_vector *logs, const struct log_config *config);
 void sort_vector_push(struct sort_vector *logs, dlogutil_entry_s *p);
-long sort_vector_time_span(struct sort_vector *logs);
+long sort_vector_time_span(struct sort_vector *logs, struct timespec mono_time);

diff --git a/src/libdlogutil/logretrieve.c b/src/libdlogutil/logretrieve.c
index 15aa5b1..20dce14 100644 (file)
--- a/src/libdlogutil/logretrieve.c
+++ b/src/libdlogutil/logretrieve.c
@@ -367,9 +367,9 @@ int do_print_once(dlogutil_state_s *state, int timeout, dlogutil_entry_s **out)
 {
        assert(!*out);
 
+       struct timespec now = { .tv_nsec = -1 };
        int end_at = -1;
        if (timeout != -1) {
-               struct timespec now;
                clock_gettime(CLOCK_MONOTONIC, &now);
                end_at = now.tv_sec * 1000 + now.tv_nsec / 1000000 + timeout;
        }
@@ -378,12 +378,13 @@ int do_print_once(dlogutil_state_s *state, int timeout, dlogutil_entry_s **out)
                && state->dump_size != DLOGUTIL_MAX_DUMP_SIZE;
 
        while (state->epoll_cnt > 0) {
-               // TODO: Reuse now somehow
-               const long last_log_age = sort_vector_time_span(&state->logs);
+               /* Note: sort_vector_time_span assumes that either now.tv_nsec == -1,
+                * or now is the current CLOCK_MONOTONIC timestamp. If you change the clock,
+                * make sure to change that function! */
+               const long last_log_age = sort_vector_time_span(&state->logs, now);
                timeout = get_timeout(state, timeout, last_log_age);
 
                if (state->need_epoll) {
-
                        int r = refill_fdi_buffers(state, timeout);
                        if (r < 0)
                                return r;
@@ -409,11 +410,11 @@ int do_print_once(dlogutil_state_s *state, int timeout, dlogutil_entry_s **out)
                if (*out)
                        return 0;
                else if (end_at != -1) {
-                       struct timespec now;
                        clock_gettime(CLOCK_MONOTONIC, &now);
                        if (end_at <= now.tv_sec * 1000 + now.tv_nsec / 1000000)
                                return TIZEN_ERROR_TIMED_OUT;
-               }
+               } else
+                       assert(now.tv_nsec == -1); // Could be now.tv_nsec = 1, but this is slightly faster
        }
 
        int r;

diff --git a/src/libdlogutil/sort_vector.c b/src/libdlogutil/sort_vector.c
index 9a723b5..445818d 100644 (file)
--- a/src/libdlogutil/sort_vector.c
+++ b/src/libdlogutil/sort_vector.c
@@ -189,7 +189,7 @@ void sort_vector_push(struct sort_vector *logs, dlogutil_entry_s *p)
        logs->end = (logs->end + 1) % logs->size;
 }
 
-long sort_vector_time_span(struct sort_vector *logs)
+long sort_vector_time_span(struct sort_vector *logs, struct timespec mono_time)
 {
        long diff_s, diff_ns;
        if (sort_vector_empty(logs))
@@ -198,7 +198,12 @@ long sort_vector_time_span(struct sort_vector *logs)
        struct timespec now, oldest;
        if (dlogutil_entry_get_timestamp(sort_vector_back(logs), logs->sort_by, &oldest) != TIZEN_ERROR_NONE)
                return -1; // report negative age to flush the invalid log immediately
-       clock_gettime(get_proper_clock(logs->sort_by), &now);
+
+       clockid_t proper_clock = get_proper_clock(logs->sort_by);
+       if (proper_clock == CLOCK_MONOTONIC && mono_time.tv_nsec != -1)
+               now = mono_time;
+       else
+               clock_gettime(proper_clock, &now);
 
        diff_s = now.tv_sec - oldest.tv_sec;
        diff_ns = now.tv_nsec - oldest.tv_nsec;

diff --git a/src/tests/logutil_neg.c b/src/tests/logutil_neg.c
index 90b9114..93b3d92 100644 (file)
--- a/src/tests/logutil_neg.c
+++ b/src/tests/logutil_neg.c
@@ -24,7 +24,7 @@ int main()
        sv.timeout = 60;
        sv.size = DEFAULT_SORT_BUFFER_SIZE;
        sort_vector_finalize(&sv);
-       assert(sort_vector_time_span(&sv) == 0);
+       assert(sort_vector_time_span(&sv, (struct timespec) { .tv_nsec = -1 }) == 0);
 
        struct fd_ops test_ops = {
                .has_log = test_has_log,

diff --git a/src/tests/logutil_pos.c b/src/tests/logutil_pos.c
index 72315a8..c93875c 100644 (file)
--- a/src/tests/logutil_pos.c
+++ b/src/tests/logutil_pos.c
@@ -40,7 +40,7 @@ int main()
        sv.timeout = 60;
        sv.size = DEFAULT_SORT_BUFFER_SIZE;
        sort_vector_finalize(&sv);
-       assert(sort_vector_time_span(&sv) == 0);
+       assert(sort_vector_time_span(&sv, (struct timespec) { .tv_nsec = -1 }) == 0);
 
        for (int i = 0; i < 10; ++i) {
                dlogutil_entry_s *ent2 = calloc(1, sizeof(dlogutil_entry_s));
@@ -50,14 +50,14 @@ int main()
                sort_vector_push(&sv, ent2);
        }
 
-       assert(sort_vector_time_span(&sv) == 110);
+       assert(sort_vector_time_span(&sv, (struct timespec) { .tv_nsec = -1 }) == 110);
 
        dlogutil_entry_s *ent3 = calloc(1, sizeof(dlogutil_entry_s));
        assert(ent3);
        ent3->sec_sent_mono = 0;
        ent3->nsec_sent_mono = 999999999;
        sort_vector_push(&sv, ent3);
-       assert(sort_vector_time_span(&sv) == 900);
+       assert(sort_vector_time_span(&sv, (struct timespec) { .tv_nsec = -1 }) == 900);
 
        struct fd_ops test_ops = {
                .has_log = test_has_log,

diff --git a/src/tests/sort_vector_neg.c b/src/tests/sort_vector_neg.c
index 0e57c41..18fe3ba 100644 (file)
--- a/src/tests/sort_vector_neg.c
+++ b/src/tests/sort_vector_neg.c
@@ -62,7 +62,7 @@ void empty_timestamp()
 
        sort_vector_finalize(&sv);
        sort_vector_push(&sv, &log);
-       assert(sort_vector_time_span(&sv) == -1);
+       assert(sort_vector_time_span(&sv, (struct timespec) { .tv_nsec = -1, }) == -1);
 }
 
 void logs_order_empty()

diff --git a/src/tests/sort_vector_pos.c b/src/tests/sort_vector_pos.c
index d5441fa..6f9c30a 100644 (file)
--- a/src/tests/sort_vector_pos.c
+++ b/src/tests/sort_vector_pos.c
@@ -221,7 +221,7 @@ void time_span_test(int32_t fir, time_t sec, long time_span)
 
        sort_vector_finalize(&sv);
        sort_vector_push(&sv, &log_A);
-       assert((unsigned long) (sort_vector_time_span(&sv)) == time_span);
+       assert((unsigned long) (sort_vector_time_span(&sv, (struct timespec) { .tv_nsec = -1 })) == time_span);
 }
 
 void call_time_span_test()
@@ -245,7 +245,7 @@ void call_time_span_test()
        time_span_test(6, 2, (unsigned long) -4000);
        time_span_test(1, 20, 19000);
 
-/*
+/*     TODO: ?
        time_span_test(0, max/2 - 1, (unsigned long) -2000);
        time_span_test(0, max/2 + 1, 0);
        time_span_test(max, 2, 3000);