added debug code to track data collection duration discards
Costa Tsaousis (ktsaou) committed
Jul 18, 2018 at 02:58 UTC
30d7499919a8e9d47efe1f3535039378d6a43af5
1 file changed
+34
-2
src/rrdset.c
+34
-2
@@ -726,14 +726,36 @@ inline void rrdset_next_usec(RRDSET *st, usec_t microseconds) {
726
struct timeval now;
727
now_realtime_timeval(&now);
728
729
+ #ifdef NETDATA_INTERNAL_CHECKS
730
+ char *discard_reason = "UNDEFINED";
731
+ usec_t discarded = microseconds;
732
+ #endif
733
+
734
+ if(unlikely(rrdset_flag_check(st, RRDSET_FLAG_SYNC_CLOCK))) {
735
+ // the chart needs to be re-synced to current time
736
+ rrdset_flag_clear(st, RRDSET_FLAG_SYNC_CLOCK);
737
+
738
+ // discard the microseconds supplied
739
+ microseconds = 0;
740
+
741
+ #ifdef NETDATA_INTERNAL_CHECKS
742
+ discard_reason = "SYNC CLOCK FLAG";
743
+ #endif
744
+ }
745
+
746
if(unlikely(!st->last_collected_time.tv_sec)) {
747
// the first entry
748
microseconds = st->update_every * USEC_PER_SEC;
749
+ #ifdef NETDATA_INTERNAL_CHECKS
750
+ discard_reason = "FIRST DATA COLLECTION";
751
+ #endif
752
}
733
- else if(unlikely(!microseconds || rrdset_flag_check(st, RRDSET_FLAG_SYNC_CLOCK))) {
753
+ else if(unlikely(!microseconds)) {
754
// no dt given by the plugin
755
microseconds = dt_usec(&now, &st->last_collected_time);
736
- rrdset_flag_clear(st, RRDSET_FLAG_SYNC_CLOCK);
756
+ #ifdef NETDATA_INTERNAL_CHECKS
757
+ discard_reason = "NO USEC GIVEN BY COLLECTOR";
758
+ #endif
759
}
760
else {
761
// microseconds has the time since the last collection
@@ -752,12 +774,18 @@ inline void rrdset_next_usec(RRDSET *st, usec_t microseconds) {
774
last_updated_time_align(st);
775
776
microseconds = st->update_every * USEC_PER_SEC;
777
+ #ifdef NETDATA_INTERNAL_CHECKS
778
+ discard_reason = "COLLECTION TIME IN FUTURE";
779
+ #endif
780
}
781
else if(unlikely((usec_t)since_last_usec > (usec_t)(st->update_every * 5 * USEC_PER_SEC))) {
782
// oops! the database is too far behind
783
info("RRD database for chart '%s' on host '%s' is %0.5" LONG_DOUBLE_MODIFIER " secs in the past (counter #%zu, update #%zu). Adjusting it to current time.", st->id, st->rrdhost->hostname, (LONG_DOUBLE)since_last_usec / USEC_PER_SEC, st->counter, st->counter_done);
784
785
microseconds = (usec_t)since_last_usec;
786
+ #ifdef NETDATA_INTERNAL_CHECKS
787
+ discard_reason = "COLLECTION TIME TOO FAR IN THE PAST";
788
+ #endif
789
}
790
791
#ifdef NETDATA_INTERNAL_CHECKS
@@ -788,6 +816,10 @@ inline void rrdset_next_usec(RRDSET *st, usec_t microseconds) {
816
#ifdef NETDATA_INTERNAL_CHECKS
817
debug(D_RRD_CALLS, "rrdset_next_usec() for chart %s with microseconds %llu", st->name, microseconds);
818
rrdset_debug(st, "NEXT: %llu microseconds", microseconds);
819
+
820
+ if(discarded && discarded != microseconds)
821
+ info("host '%s', chart '%s': discarded data collection time of %llu usec, replaced with %llu usec, reason: '%s'", st->rrdhost->hostname, st->id, discarded, microseconds, discard_reason);
822
+
823
#endif
824
825
st->usec_since_last_update = microseconds;