@cryptotaxi247 / netdata-1 / commits / 784ed6050

fixed a bug in the interpolation algorithm that was showing unrealistic values under certain conditions; fixes #981

Costa Tsaousis (ktsaou) committed Sep 22, 2016 at 02:17 UTC 784ed60500457e249ed3893398430ce2246eb488
2 files changed +155 -59
src/rrd.c
+62 -55
@@ -988,7 +988,7 @@ unsigned long long rrdset_done(RRDSET *st)
988
989 RRDDIM *rd, *last;
990 int oldstate, store_this_entry = 1, first_entry = 0;
991 - unsigned long long last_ut, now_ut, next_ut, stored_entries = 0;
991 + unsigned long long last_stored_ut, now_collect_ut, last_collect_ut, next_store_ut, stored_entries = 0;
992
993 if(unlikely(pthread_setcancelstate(PTHREAD_CANCEL_DISABLE, &oldstate) != 0))
994 error("Cannot set pthread cancel state to DISABLE.");
@@ -1014,6 +1014,7 @@ unsigned long long rrdset_done(RRDSET *st)
1014 // it is the first entry
1015 // set the last_collected_time to now
1016 gettimeofday(&st->last_collected_time, NULL);
1017 + last_collect_ut = st->last_collected_time.tv_sec * 1000000ULL + st->last_collected_time.tv_usec - (st->update_every * 1000000);
1018
1019 // the first entry should not be stored
1020 store_this_entry = 0;
@@ -1024,7 +1025,8 @@ unsigned long long rrdset_done(RRDSET *st)
1025 else {
1026 // it is not the first entry
1027 // calculate the proper last_collected_time, using usec_since_last_update
1027 - unsigned long long ut = st->last_collected_time.tv_sec * 1000000ULL + st->last_collected_time.tv_usec + st->usec_since_last_update;
1028 + last_collect_ut = st->last_collected_time.tv_sec * 1000000ULL + st->last_collected_time.tv_usec;
1029 + unsigned long long ut = last_collect_ut + st->usec_since_last_update;
1030 st->last_collected_time.tv_sec = (time_t) (ut / 1000000ULL);
1031 st->last_collected_time.tv_usec = (suseconds_t) (ut % 1000000ULL);
1032 }
@@ -1064,21 +1066,18 @@ unsigned long long rrdset_done(RRDSET *st)
1066 }
1067
1068 // these are the 3 variables that will help us in interpolation
1067 - // last_ut = the last time we added a value to the storage
1068 - // now_ut = the time the current value is taken at
1069 - // next_ut = the time of the next interpolation point
1070 - last_ut = st->last_updated.tv_sec * 1000000ULL + st->last_updated.tv_usec;
1071 - now_ut = st->last_collected_time.tv_sec * 1000000ULL + st->last_collected_time.tv_usec;
1072 - next_ut = (st->last_updated.tv_sec + st->update_every) * 1000000ULL;
1073 -
1074 - if(unlikely(!first_entry && now_ut < next_ut)) {
1075 - if(unlikely(st->debug)) debug(D_RRD_STATS, "%s: THIS IS IN THE SAME INTERPOLATION POINT", st->name);
1076 - }
1069 + // last_stored_ut = the last time we added a value to the storage
1070 + // now_collect_ut = the time the current value has been collected
1071 + // next_store_ut = the time of the next interpolation point
1072 + last_stored_ut = st->last_updated.tv_sec * 1000000ULL + st->last_updated.tv_usec;
1073 + now_collect_ut = st->last_collected_time.tv_sec * 1000000ULL + st->last_collected_time.tv_usec;
1074 + next_store_ut = (st->last_updated.tv_sec + st->update_every) * 1000000ULL;
1075
1076 if(unlikely(st->debug)) {
1079 - debug(D_RRD_STATS, "%s: last ut = %0.3Lf (last updated time)", st->name, (long double)last_ut/1000000.0);
1080 - debug(D_RRD_STATS, "%s: now ut = %0.3Lf (current update time)", st->name, (long double)now_ut/1000000.0);
1081 - debug(D_RRD_STATS, "%s: next ut = %0.3Lf (next interpolation point)", st->name, (long double)next_ut/1000000.0);
1077 + debug(D_RRD_STATS, "%s: last_collect_ut = %0.3Lf (last collection time)", st->name, (long double)last_collect_ut/1000000.0);
1078 + debug(D_RRD_STATS, "%s: now_collect_ut = %0.3Lf (current collection time)", st->name, (long double)now_collect_ut/1000000.0);
1079 + debug(D_RRD_STATS, "%s: last_stored_ut = %0.3Lf (last updated time)", st->name, (long double)last_stored_ut/1000000.0);
1080 + debug(D_RRD_STATS, "%s: next_store_ut = %0.3Lf (next interpolation point)", st->name, (long double)next_store_ut/1000000.0);
1081 }
1082
1083 if(unlikely(!st->counter_done)) {
@@ -1090,7 +1089,7 @@ unsigned long long rrdset_done(RRDSET *st)
1089 // calculate totals and count the dimensions
1090 int dimensions;
1091 st->collected_total = 0;
1093 - for( rd = st->dimensions, dimensions = 0 ; likely(rd) ; rd = rd->next, dimensions++ )
1092 + for( rd = st->dimensions, dimensions = 0 ; rd ; rd = rd->next, dimensions++ )
1093 if(likely(rd->updated)) st->collected_total += rd->collected_value;
1094
1095 uint32_t storage_flags = SN_EXISTS;
@@ -1098,7 +1097,7 @@ unsigned long long rrdset_done(RRDSET *st)
1097 // process all dimensions to calculate their values
1098 // based on the collected figures only
1099 // at this stage we do not interpolate anything
1101 - for( rd = st->dimensions ; likely(rd) ; rd = rd->next ) {
1100 + for( rd = st->dimensions ; rd ; rd = rd->next ) {
1101
1102 if(unlikely(!rd->updated)) {
1103 rd->calculated_value = 0;
@@ -1177,7 +1176,7 @@ unsigned long long rrdset_done(RRDSET *st)
1176 rd->last_collected_value = rd->collected_value;
1177 }
1178
1180 - rd->calculated_value =
1179 + rd->calculated_value +=
1180 (calculated_number)(rd->collected_value - rd->last_collected_value)
1181 * (calculated_number)rd->multiplier
1182 / (calculated_number)rd->divisor;
@@ -1267,21 +1266,26 @@ unsigned long long rrdset_done(RRDSET *st)
1266 // at this point we have all the calculated values ready
1267 // it is now time to interpolate values on a second boundary
1268
1270 - unsigned long long first_ut = last_ut;
1271 - long long iterations = (now_ut - last_ut) / (st->update_every * 1000000ULL);
1272 - if((now_ut % (st->update_every * 1000000ULL)) == 0) iterations++;
1269 + if(unlikely(now_collect_ut < next_store_ut)) {
1270 + // this is collected in the same interpolation point
1271 + if(unlikely(st->debug)) debug(D_RRD_STATS, "%s: THIS IS IN THE SAME INTERPOLATION POINT", st->name);
1272 + }
1273 +
1274 + unsigned long long first_ut = last_stored_ut;
1275 + long long iterations = (now_collect_ut - last_stored_ut) / (st->update_every * 1000000ULL);
1276 + if((now_collect_ut % (st->update_every * 1000000ULL)) == 0) iterations++;
1277
1274 - for( ; likely(next_ut <= now_ut) ; next_ut += st->update_every * 1000000ULL, iterations-- ) {
1278 + for( ; next_store_ut <= now_collect_ut ; next_store_ut += st->update_every * 1000000ULL, iterations-- ) {
1279 #ifdef NETDATA_INTERNAL_CHECKS
1276 - if(iterations < 0) { error("%s: iterations calculation wrapped! first_ut = %llu, last_ut = %llu, next_ut = %llu, now_ut = %llu", st->name, first_ut, last_ut, next_ut, now_ut); }
1280 + if(iterations < 0) { error("%s: iterations calculation wrapped! first_ut = %llu, last_stored_ut = %llu, next_store_ut = %llu, now_collect_ut = %llu", st->name, first_ut, last_stored_ut, next_store_ut, now_collect_ut); }
1281 #endif
1282
1283 if(unlikely(st->debug)) {
1280 - debug(D_RRD_STATS, "%s: last ut = %0.3Lf (last updated time)", st->name, (long double)last_ut/1000000.0);
1281 - debug(D_RRD_STATS, "%s: next ut = %0.3Lf (next interpolation point)", st->name, (long double)next_ut/1000000.0);
1284 + debug(D_RRD_STATS, "%s: last_stored_ut = %0.3Lf (last updated time)", st->name, (long double)last_stored_ut/1000000.0);
1285 + debug(D_RRD_STATS, "%s: next_store_ut = %0.3Lf (next interpolation point)", st->name, (long double)next_store_ut/1000000.0);
1286 }
1287
1284 - st->last_updated.tv_sec = (time_t) (next_ut / 1000000ULL);
1288 + st->last_updated.tv_sec = (time_t) (next_store_ut / 1000000ULL);
1289 st->last_updated.tv_usec = 0;
1290
1291 for( rd = st->dimensions ; likely(rd) ; rd = rd->next ) {
@@ -1291,8 +1295,8 @@ unsigned long long rrdset_done(RRDSET *st)
1295 case RRDDIM_INCREMENTAL:
1296 new_value = (calculated_number)
1297 ( rd->calculated_value
1294 - * (calculated_number)(next_ut - last_ut)
1295 - / (calculated_number)(now_ut - last_ut)
1298 + * (calculated_number)(next_store_ut - last_collect_ut)
1299 + / (calculated_number)(now_collect_ut - last_collect_ut)
1300 );
1301
1302 if(unlikely(st->debug))
@@ -1304,10 +1308,11 @@ unsigned long long rrdset_done(RRDSET *st)
1308 , st->id, rd->name
1309 , new_value
1310 , rd->calculated_value
1307 - , (next_ut - last_ut)
1308 - , (now_ut - last_ut)
1311 + , (next_store_ut - last_stored_ut)
1312 + , (now_collect_ut - last_stored_ut)
1313 );
1314
1315 + last_collect_ut = next_store_ut;
1316 rd->calculated_value -= new_value;
1317 new_value += rd->last_calculated_value;
1318 rd->last_calculated_value = 0;
@@ -1331,8 +1336,8 @@ unsigned long long rrdset_done(RRDSET *st)
1336
1337 new_value = (calculated_number)
1338 ( ( (rd->calculated_value - rd->last_calculated_value)
1334 - * (calculated_number)(next_ut - first_ut)
1335 - / (calculated_number)(now_ut - first_ut)
1339 + * (calculated_number)(next_store_ut - last_collect_ut)
1340 + / (calculated_number)(now_collect_ut - last_collect_ut)
1341 )
1342 + rd->last_calculated_value
1343 );
@@ -1346,22 +1351,15 @@ unsigned long long rrdset_done(RRDSET *st)
1351 , st->id, rd->name
1352 , new_value
1353 , rd->calculated_value, rd->last_calculated_value
1349 - , (next_ut - first_ut)
1350 - , (now_ut - first_ut), rd->last_calculated_value
1354 + , (next_store_ut - first_ut)
1355 + , (now_collect_ut - first_ut), rd->last_calculated_value
1356 );
1352 -
1353 - // this is wrong
1354 - // it fades the value towards the target
1355 - // while we know the calculated value is different
1356 - // if(likely(next_ut + st->update_every * 1000000ULL > now_ut)) rd->calculated_value = new_value;
1357 }
1358 break;
1359 }
1360
1361 - if(unlikely(!store_this_entry)) {
1362 - // store_this_entry = 1;
1361 + if(unlikely(!store_this_entry))
1362 continue;
1364 - }
1363
1364 if(likely(rd->updated && rd->counter > 1 && iterations < st->gap_when_lost_iterations_above)) {
1365 rd->values[st->current_entry] = pack_storage_number(new_value, storage_flags );
@@ -1419,25 +1417,34 @@ unsigned long long rrdset_done(RRDSET *st)
1417
1418 st->counter++;
1419 st->current_entry = ((st->current_entry + 1) >= st->entries) ? 0 : st->current_entry + 1;
1422 - last_ut = next_ut;
1420 + last_stored_ut = next_store_ut;
1421 }
1422
1425 - // align next interpolation to last collection point
1426 - if(likely(stored_entries || !store_this_entry)) {
1427 - st->last_updated.tv_sec = st->last_collected_time.tv_sec;
1428 - st->last_updated.tv_usec = st->last_collected_time.tv_usec;
1429 - st->last_collected_total = st->collected_total;
1430 - }
1423 + st->last_collected_total = st->collected_total;
1424
1432 - for( rd = st->dimensions; likely(rd) ; rd = rd->next ) {
1425 + for( rd = st->dimensions; rd ; rd = rd->next ) {
1426 if(unlikely(!rd->updated)) continue;
1427
1435 - if(likely(stored_entries || !store_this_entry)) {
1436 - if(unlikely(st->debug)) debug(D_RRD_STATS, "%s/%s: setting last_collected_value (old: " COLLECTED_NUMBER_FORMAT ") to last_collected_value (new: " COLLECTED_NUMBER_FORMAT ")", st->id, rd->name, rd->last_collected_value, rd->collected_value);
1437 - rd->last_collected_value = rd->collected_value;
1428 + if(unlikely(st->debug)) debug(D_RRD_STATS, "%s/%s: setting last_collected_value (old: " COLLECTED_NUMBER_FORMAT ") to last_collected_value (new: " COLLECTED_NUMBER_FORMAT ")", st->id, rd->name, rd->last_collected_value, rd->collected_value);
1429 + rd->last_collected_value = rd->collected_value;
1430 +
1431 + switch(rd->algorithm) {
1432 + case RRDDIM_INCREMENTAL:
1433 + if(unlikely(!first_entry)) {
1434 + if(unlikely(st->debug)) debug(D_RRD_STATS, "%s/%s: setting last_calculated_value (old: " CALCULATED_NUMBER_FORMAT ") to last_calculated_value (new: " CALCULATED_NUMBER_FORMAT ")", st->id, rd->name, rd->last_calculated_value + rd->calculated_value, rd->calculated_value);
1435 + rd->last_calculated_value += rd->calculated_value;
1436 + }
1437 + else {
1438 + if(unlikely(st->debug)) debug(D_RRD_STATS, "%s: THIS IS THE FIRST POINT", st->name);
1439 + }
1440 + break;
1441
1439 - if(unlikely(st->debug)) debug(D_RRD_STATS, "%s/%s: setting last_calculated_value (old: " CALCULATED_NUMBER_FORMAT ") to last_calculated_value (new: " CALCULATED_NUMBER_FORMAT ")", st->id, rd->name, rd->last_calculated_value, rd->calculated_value);
1440 - rd->last_calculated_value = rd->calculated_value;
1442 + case RRDDIM_ABSOLUTE:
1443 + case RRDDIM_PCENT_OVER_ROW_TOTAL:
1444 + case RRDDIM_PCENT_OVER_DIFF_TOTAL:
1445 + if(unlikely(st->debug)) debug(D_RRD_STATS, "%s/%s: setting last_calculated_value (old: " CALCULATED_NUMBER_FORMAT ") to last_calculated_value (new: " CALCULATED_NUMBER_FORMAT ")", st->id, rd->name, rd->last_calculated_value, rd->calculated_value);
1446 + rd->last_calculated_value = rd->calculated_value;
1447 + break;
1448 }
1449
1450 rd->calculated_value = 0;
src/unit_test.c
+93 -4
@@ -736,6 +736,72 @@ struct test test13 = {
736 NULL // results2
737 };
738
739 +// --------------------------------------------------------------------------------------------------------------------
740 +// test14
741 +
742 +struct feed_values test14_feed[] = {
743 + { 0, 0x015397dc42151c41ULL },
744 + { 13573000, 0x015397e612e3ff5dULL },
745 + { 29969000, 0x015397f905ecdaa8ULL },
746 + { 29958000, 0x0153980c2a6cb5e4ULL },
747 + { 30054000, 0x0153981f4032fb83ULL },
748 + { 34952000, 0x015398355efadaccULL },
749 + { 25046000, 0x01539845ba4b09f8ULL },
750 + { 29947000, 0x0153985948bf381dULL },
751 + { 30054000, 0x0153986c5b9c27e2ULL },
752 + { 29942000, 0x0153987f888982d0ULL },
753 +};
754 +
755 +calculated_number test14_results[] = {
756 + 23.1383300, 21.8515600, 21.8804600, 21.7788000, 22.0112200, 22.4386100, 22.0906100, 21.9150800
757 +};
758 +
759 +struct test test14 = {
760 + "test14", // name
761 + "issue #981 with real data",
762 + 30, // update_every
763 + 8, // multiplier
764 + 1000000000, // divisor
765 + RRDDIM_INCREMENTAL, // algorithm
766 + 10, // feed entries
767 + 8, // result entries
768 + test14_feed, // feed
769 + test14_results, // results
770 + NULL, // feed2
771 + NULL // results2
772 +};
773 +struct feed_values test14b_feed[] = {
774 + { 0, 0 },
775 + { 13573000, 13573000 },
776 + { 29969000, 13573000 + 29969000 },
777 + { 29958000, 13573000 + 29969000 + 29958000 },
778 + { 30054000, 13573000 + 29969000 + 29958000 + 30054000 },
779 + { 34952000, 13573000 + 29969000 + 29958000 + 30054000 + 34952000 },
780 + { 25046000, 13573000 + 29969000 + 29958000 + 30054000 + 34952000 + 25046000 },
781 + { 29947000, 13573000 + 29969000 + 29958000 + 30054000 + 34952000 + 25046000 + 29947000 },
782 + { 30054000, 13573000 + 29969000 + 29958000 + 30054000 + 34952000 + 25046000 + 29947000 + 30054000 },
783 + { 29942000, 13573000 + 29969000 + 29958000 + 30054000 + 34952000 + 25046000 + 29947000 + 30054000 + 29942000 },
784 +};
785 +
786 +calculated_number test14b_results[] = {
787 + 1000000, 1000000, 1000000, 1000000, 1000000, 1000000, 1000000, 1000000
788 +};
789 +
790 +struct test test14b = {
791 + "test14b", // name
792 + "issue #981 with dummy data",
793 + 30, // update_every
794 + 1, // multiplier
795 + 1, // divisor
796 + RRDDIM_INCREMENTAL, // algorithm
797 + 10, // feed entries
798 + 8, // result entries
799 + test14b_feed, // feed
800 + test14b_results, // results
801 + NULL, // feed2
802 + NULL // results2
803 +};
804 +
805 // --------------------------------------------------------------------------------------------------------------------
806
807 int run_test(struct test *test)
@@ -749,7 +815,7 @@ int run_test(struct test *test)
815 snprintfz(name, 100, "unittest-%s", test->name);
816
817 // create the chart
752 - RRDSET *st = rrdset_create("netdata", name, name, "netdata", NULL, "Unit Testing", "a value", 1, 1, RRDSET_TYPE_LINE);
818 + RRDSET *st = rrdset_create("netdata", name, name, "netdata", NULL, "Unit Testing", "a value", 1, test->update_every, RRDSET_TYPE_LINE);
819 RRDDIM *rd = rrddim_add(st, "dim1", NULL, test->multiplier, test->divisor, test->algorithm);
820
821 RRDDIM *rd2 = NULL;
@@ -759,12 +825,20 @@ int run_test(struct test *test)
825 st->debug = 1;
826
827 // feed it with the test data
828 + time_t time_now = 0, time_start = time(NULL);
829 unsigned long c;
830 + collected_number last = 0;
831 for(c = 0; c < test->feed_entries; c++) {
832 if(debug_flags) fprintf(stderr, "\n\n");
833
834 if(c) {
767 - fprintf(stderr, " > %s: feeding position %lu, after %llu microseconds\n", test->name, c+1, test->feed[c].microseconds);
835 + time_now += test->feed[c].microseconds;
836 + fprintf(stderr, " > %s: feeding position %lu, after %0.3f seconds (%0.3f seconds from start), delta " CALCULATED_NUMBER_FORMAT ", rate " CALCULATED_NUMBER_FORMAT "\n",
837 + test->name, c+1,
838 + (float)test->feed[c].microseconds / 1000000.0,
839 + (float)time_now / 1000000.0,
840 + ((calculated_number)test->feed[c].value - (calculated_number)last) * (calculated_number)test->multiplier / (calculated_number)test->divisor,
841 + (((calculated_number)test->feed[c].value - (calculated_number)last) * (calculated_number)test->multiplier / (calculated_number)test->divisor) / (calculated_number)test->feed[c].microseconds * (calculated_number)1000000);
842 rrdset_next_usec(st, test->feed[c].microseconds);
843 }
844 else {
@@ -773,6 +847,7 @@ int run_test(struct test *test)
847
848 fprintf(stderr, " >> %s with value " COLLECTED_NUMBER_FORMAT "\n", rd->name, test->feed[c].value);
849 rrddim_set(st, "dim1", test->feed[c].value);
850 + last = test->feed[c].value;
851
852 if(rd2) {
853 fprintf(stderr, " >> %s with value " COLLECTED_NUMBER_FORMAT "\n", rd2->name, test->feed2[c]);
@@ -785,6 +860,7 @@ int run_test(struct test *test)
860 if(!c) {
861 fprintf(stderr, " > %s: fixing first collection time to be %llu microseconds to second boundary\n", test->name, test->feed[c].microseconds);
862 rd->last_collected_time.tv_usec = st->last_collected_time.tv_usec = st->last_updated.tv_usec = test->feed[c].microseconds;
863 + // time_start = st->last_collected_time.tv_sec;
864 }
865 }
866
@@ -801,14 +877,21 @@ int run_test(struct test *test)
877 calculated_number v = unpack_storage_number(rd->values[c]);
878 calculated_number n = test->results[c];
879 int same = (roundl(v * 10000000.0) == roundl(n * 10000000.0))?1:0;
804 - fprintf(stderr, " %s/%s: checking position %lu, expecting value " CALCULATED_NUMBER_FORMAT ", found " CALCULATED_NUMBER_FORMAT ", %s\n", test->name, rd->name, c+1, n, v, (same)?"OK":"### E R R O R ###");
880 + fprintf(stderr, " %s/%s: checking position %lu (at %lu secs), expecting value " CALCULATED_NUMBER_FORMAT ", found " CALCULATED_NUMBER_FORMAT ", %s\n",
881 + test->name, rd->name, c+1,
882 + (rrdset_first_entry_t(st) + c * st->update_every) - time_start,
883 + n, v, (same)?"OK":"### E R R O R ###");
884 +
885 if(!same) errors++;
886
887 if(rd2) {
888 v = unpack_storage_number(rd2->values[c]);
889 n = test->results2[c];
890 same = (roundl(v * 10000000.0) == roundl(n * 10000000.0))?1:0;
811 - fprintf(stderr, " %s/%s: checking position %lu, expecting value " CALCULATED_NUMBER_FORMAT ", found " CALCULATED_NUMBER_FORMAT ", %s\n", test->name, rd2->name, c+1, n, v, (same)?"OK":"### E R R O R ###");
891 + fprintf(stderr, " %s/%s: checking position %lu (at %lu secs), expecting value " CALCULATED_NUMBER_FORMAT ", found " CALCULATED_NUMBER_FORMAT ", %s\n",
892 + test->name, rd2->name, c+1,
893 + (rrdset_first_entry_t(st) + c * st->update_every) - time_start,
894 + n, v, (same)?"OK":"### E R R O R ###");
895 if(!same) errors++;
896 }
897 }
@@ -857,6 +940,12 @@ int run_all_mockup_tests(void)
940 if(run_test(&test13))
941 return 1;
942
943 + if(run_test(&test14))
944 + return 1;
945 +
946 + if(run_test(&test14b))
947 + return 1;
948 +
949 return 0;
950 }
951