Mark bucket as condition_unknown properly

Previously, if the condition was unknown for the entire bucket, the bucket would be annotated with a NO_DATA rather than being dropped because CONDITION_UNKNOWN. This updates all the buckets to be dropped due to CONDITION_UNKNOWN. Note that this will make the condition unknown problem appear worse, when in reality it is making our bucket drop reasons more correct and should not have any impact on the true CONDITION_UNKNOWN. Also fix an issue where a test was failing due to a previous test leaving data persisted to disk. This fix is a hack for now, and should be properly fixed later. Bug: 158897179 Test: atest statsd_test Change-Id: Ic703600d37aa1873ec67cb1a279dcf349d48fc9f
2020-06-12 18:46:27 -07:00
parent 3a8b73a881
commit 756541526a
3 changed files with 107 additions and 10 deletions
--- a/cmds/statsd/src/metrics/ValueMetricProducer.cpp
+++ b/cmds/statsd/src/metrics/ValueMetricProducer.cpp
@@ -951,6 +951,7 @@ void ValueMetricProducer::flushCurrentBucketLocked(const int64_t& eventTimeNs,
                                                   const int64_t& nextBucketStartTimeNs) {
    if (mCondition == ConditionState::kUnknown) {
        StatsdStats::getInstance().noteBucketUnknownCondition(mMetricId);
+        invalidateCurrentBucketWithoutResetBase(eventTimeNs, BucketDropReason::CONDITION_UNKNOWN);
    }

    VLOG("finalizing bucket for %ld, dumping %d slices", (long)mCurrentBucketStartTimeNs,
--- a/cmds/statsd/tests/StatsLogProcessor_test.cpp
+++ b/cmds/statsd/tests/StatsLogProcessor_test.cpp
@@ -13,6 +13,11 @@
 // limitations under the License.

 #include "StatsLogProcessor.h"
+
+#include <gmock/gmock.h>
+#include <gtest/gtest.h>
+#include <stdio.h>
+
 #include "StatsService.h"
 #include "config/ConfigKey.h"
 #include "frameworks/base/cmds/statsd/src/stats_log.pb.h"
@@ -20,16 +25,10 @@
 #include "guardrail/StatsdStats.h"
 #include "logd/LogEvent.h"
 #include "packages/UidMap.h"
-#include "storage/StorageManager.h"
 #include "statslog_statsdtest.h"
-
-#include <gmock/gmock.h>
-#include <gtest/gtest.h>
-
+#include "storage/StorageManager.h"
 #include "tests/statsd_test_util.h"

-#include <stdio.h>
-
 using namespace android;
 using namespace testing;
 using ::ndk::SharedRefBase;
@@ -1836,6 +1835,11 @@ TEST(StatsLogProcessorTest, TestDumpReportWithoutErasingDataDoesNotUpdateTimesta
    int isolatedUid = 30;
    sp<MockUidMap> mockUidMap = makeMockUidMapForOneHost(hostUid, {isolatedUid});
    ConfigKey key(3, 4);
+
+    // TODO: All tests should not persist state on disk. This removes any reports that were present.
+    ProtoOutputStream proto;
+    StorageManager::appendConfigMetricsReport(key, &proto, /*erase data=*/true, /*isAdb=*/false);
+
    StatsdConfig config = MakeConfig(false);
    sp<StatsLogProcessor> processor =
            CreateStatsLogProcessor(1, 1, config, key, nullptr, 0, mockUidMap);
--- a/cmds/statsd/tests/metrics/ValueMetricProducer_test.cpp
+++ b/cmds/statsd/tests/metrics/ValueMetricProducer_test.cpp
@@ -3295,11 +3295,15 @@ TEST(ValueMetricProducerTest_BucketDrop, TestInvalidBucketWhenConditionEventWron
              report.value_metrics().skipped(0).start_bucket_elapsed_millis());
    EXPECT_EQ(NanoToMillis(bucket2StartTimeNs + 100),
              report.value_metrics().skipped(0).end_bucket_elapsed_millis());
-    ASSERT_EQ(1, report.value_metrics().skipped(0).drop_event_size());
+    ASSERT_EQ(2, report.value_metrics().skipped(0).drop_event_size());

    auto dropEvent = report.value_metrics().skipped(0).drop_event(0);
    EXPECT_EQ(BucketDropReason::EVENT_IN_WRONG_BUCKET, dropEvent.drop_reason());
    EXPECT_EQ(NanoToMillis(bucket2StartTimeNs - 100), dropEvent.drop_time_millis());
+
+    dropEvent = report.value_metrics().skipped(0).drop_event(1);
+    EXPECT_EQ(BucketDropReason::CONDITION_UNKNOWN, dropEvent.drop_reason());
+    EXPECT_EQ(NanoToMillis(bucket2StartTimeNs + 100), dropEvent.drop_time_millis());
 }

 /*
@@ -3615,7 +3619,7 @@ TEST(ValueMetricProducerTest_BucketDrop, TestBucketDropWhenDataUnavailable) {

    sp<ValueMetricProducer> valueProducer =
            ValueMetricProducerTestHelper::createValueProducerWithCondition(
-                    pullerManager, metric, ConditionState::kUnknown);
+                    pullerManager, metric, ConditionState::kFalse);

    // Check dump report.
    ProtoOutputStream output;
@@ -3640,6 +3644,94 @@ TEST(ValueMetricProducerTest_BucketDrop, TestBucketDropWhenDataUnavailable) {
    EXPECT_EQ(NanoToMillis(dumpReportTimeNs), dropEvent.drop_time_millis());
 }

+/*
+ * Test that all buckets are dropped due to condition unknown until the first onConditionChanged.
+ */
+TEST(ValueMetricProducerTest_BucketDrop, TestConditionUnknownMultipleBuckets) {
+    ValueMetric metric = ValueMetricProducerTestHelper::createMetricWithCondition();
+
+    sp<MockStatsPullerManager> pullerManager = new StrictMock<MockStatsPullerManager>();
+    EXPECT_CALL(*pullerManager, Pull(tagId, kConfigKey, _, _, _))
+            // Condition change to true.
+            .WillOnce(Invoke([](int tagId, const ConfigKey&, const int64_t eventTimeNs,
+                                vector<std::shared_ptr<LogEvent>>* data, bool) {
+                EXPECT_EQ(eventTimeNs, bucket2StartTimeNs + 10 * NS_PER_SEC);
+                data->clear();
+                data->push_back(CreateRepeatedValueLogEvent(
+                        tagId, bucket2StartTimeNs + 10 * NS_PER_SEC, 10));
+                return true;
+            }))
+            // Dump report requested.
+            .WillOnce(Invoke([](int tagId, const ConfigKey&, const int64_t eventTimeNs,
+                                vector<std::shared_ptr<LogEvent>>* data, bool) {
+                EXPECT_EQ(eventTimeNs, bucket2StartTimeNs + 15 * NS_PER_SEC);
+                data->clear();
+                data->push_back(CreateRepeatedValueLogEvent(
+                        tagId, bucket2StartTimeNs + 15 * NS_PER_SEC, 15));
+                return true;
+            }));
+
+    sp<ValueMetricProducer> valueProducer =
+            ValueMetricProducerTestHelper::createValueProducerWithCondition(
+                    pullerManager, metric, ConditionState::kUnknown);
+
+    // Bucket should be dropped because of condition unknown.
+    int64_t appUpgradeTimeNs = bucketStartTimeNs + 5 * NS_PER_SEC;
+    valueProducer->notifyAppUpgrade(appUpgradeTimeNs);
+
+    // Bucket also dropped due to condition unknown
+    vector<shared_ptr<LogEvent>> allData;
+    allData.clear();
+    allData.push_back(CreateRepeatedValueLogEvent(tagId, bucket2StartTimeNs + 1, 3));
+    valueProducer->onDataPulled(allData, /** succeed */ true, bucket2StartTimeNs);
+
+    // This bucket is also dropped due to condition unknown.
+    int64_t conditionChangeTimeNs = bucket2StartTimeNs + 10 * NS_PER_SEC;
+    valueProducer->onConditionChanged(true, conditionChangeTimeNs);
+
+    // Check dump report.
+    ProtoOutputStream output;
+    std::set<string> strSet;
+    int64_t dumpReportTimeNs = bucket2StartTimeNs + 15 * NS_PER_SEC; // 15 seconds
+    valueProducer->onDumpReport(dumpReportTimeNs, true /* include current bucket */, true,
+                                NO_TIME_CONSTRAINTS /* dumpLatency */, &strSet, &output);
+
+    StatsLogReport report = outputStreamToProto(&output);
+    EXPECT_TRUE(report.has_value_metrics());
+    ASSERT_EQ(0, report.value_metrics().data_size());
+    ASSERT_EQ(3, report.value_metrics().skipped_size());
+
+    EXPECT_EQ(NanoToMillis(bucketStartTimeNs),
+              report.value_metrics().skipped(0).start_bucket_elapsed_millis());
+    EXPECT_EQ(NanoToMillis(appUpgradeTimeNs),
+              report.value_metrics().skipped(0).end_bucket_elapsed_millis());
+    ASSERT_EQ(1, report.value_metrics().skipped(0).drop_event_size());
+
+    auto dropEvent = report.value_metrics().skipped(0).drop_event(0);
+    EXPECT_EQ(BucketDropReason::CONDITION_UNKNOWN, dropEvent.drop_reason());
+    EXPECT_EQ(NanoToMillis(appUpgradeTimeNs), dropEvent.drop_time_millis());
+
+    EXPECT_EQ(NanoToMillis(appUpgradeTimeNs),
+              report.value_metrics().skipped(1).start_bucket_elapsed_millis());
+    EXPECT_EQ(NanoToMillis(bucket2StartTimeNs),
+              report.value_metrics().skipped(1).end_bucket_elapsed_millis());
+    ASSERT_EQ(1, report.value_metrics().skipped(1).drop_event_size());
+
+    dropEvent = report.value_metrics().skipped(1).drop_event(0);
+    EXPECT_EQ(BucketDropReason::CONDITION_UNKNOWN, dropEvent.drop_reason());
+    EXPECT_EQ(NanoToMillis(bucket2StartTimeNs), dropEvent.drop_time_millis());
+
+    EXPECT_EQ(NanoToMillis(bucket2StartTimeNs),
+              report.value_metrics().skipped(2).start_bucket_elapsed_millis());
+    EXPECT_EQ(NanoToMillis(dumpReportTimeNs),
+              report.value_metrics().skipped(2).end_bucket_elapsed_millis());
+    ASSERT_EQ(1, report.value_metrics().skipped(2).drop_event_size());
+
+    dropEvent = report.value_metrics().skipped(2).drop_event(0);
+    EXPECT_EQ(BucketDropReason::CONDITION_UNKNOWN, dropEvent.drop_reason());
+    EXPECT_EQ(NanoToMillis(conditionChangeTimeNs), dropEvent.drop_time_millis());
+}
+
 /*
 * Test that a skipped bucket is logged when a forced bucket split occurs when the previous bucket
 * was not flushed in time.
@@ -4957,7 +5049,7 @@ TEST(ValueMetricProducerTest, TestForcedBucketSplitWhenConditionUnknownSkipsBuck
    ASSERT_EQ(1, report.value_metrics().skipped(0).drop_event_size());

    auto dropEvent = report.value_metrics().skipped(0).drop_event(0);
-    EXPECT_EQ(BucketDropReason::NO_DATA, dropEvent.drop_reason());
+    EXPECT_EQ(BucketDropReason::CONDITION_UNKNOWN, dropEvent.drop_reason());
    EXPECT_EQ(NanoToMillis(appUpdateTimeNs), dropEvent.drop_time_millis());
 }