Merge "Puller API: Unit tests."

cmds/statsd/Android.bp

@@ -250,6 +250,7 @@ cc_test {
         "tests/external/GpuStatsPuller_test.cpp",
         "tests/external/IncidentReportArgs_test.cpp",
         "tests/external/puller_util_test.cpp",
+        "tests/external/StatsCallbackPuller_test.cpp",
         "tests/external/StatsPuller_test.cpp",
         "tests/external/SurfaceflingerStatsPuller_test.cpp",
         "tests/FieldValue_test.cpp",

cmds/statsd/src/external/StatsCallbackPuller.cpp

@@ -35,8 +35,9 @@ namespace android {
 namespace os {
 namespace statsd {
 
-StatsCallbackPuller::StatsCallbackPuller(int tagId, const sp<IPullAtomCallback>& callback)
-    : StatsPuller(tagId), mCallback(callback) {
+StatsCallbackPuller::StatsCallbackPuller(int tagId, const sp<IPullAtomCallback>& callback,
+                                         int64_t timeoutNs)
+    : StatsPuller(tagId), mCallback(callback), mTimeoutNs(timeoutNs) {
     VLOG("StatsCallbackPuller created for tag %d", tagId);
 }
 
@@ -64,10 +65,9 @@ bool StatsCallbackPuller::PullInternal(vector<shared_ptr<LogEvent>>* data) {
                 {
                     lock_guard<mutex> lk(*cv_mutex);
                     for (const StatsEventParcel& parcel: output) {
-                        shared_ptr<LogEvent> event =
-                              make_shared<LogEvent>(const_cast<uint8_t*>(parcel.buffer.data()),
-                                                    parcel.buffer.size(),
-                                                    /*uid=*/ -1);
+                        shared_ptr<LogEvent> event = make_shared<LogEvent>(
+                                const_cast<uint8_t*>(parcel.buffer.data()), parcel.buffer.size(),
+                                /*uid=*/-1, /*useNewSchema=*/true);
                         sharedData->push_back(event);
                     }
                     *pullSuccess = success;
@@ -76,7 +76,8 @@ bool StatsCallbackPuller::PullInternal(vector<shared_ptr<LogEvent>>* data) {
                 cv->notify_one();
             });
 
-    // Initiate the pull.
+    // Initiate the pull. This is a oneway call to a different process, except
+    // in unit tests. In process calls are not oneway.
     Status status = mCallback->onPullAtom(mTagId, resultReceiver);
     if (!status.isOk()) {
         return false;
@@ -84,10 +85,8 @@ bool StatsCallbackPuller::PullInternal(vector<shared_ptr<LogEvent>>* data) {
 
     {
         unique_lock<mutex> unique_lk(*cv_mutex);
-        int64_t pullTimeoutNs =
-                StatsPullerManager::kAllPullAtomInfo.at({.atomTag = mTagId}).pullTimeoutNs;
         // Wait until the pull finishes, or until the pull timeout.
-        cv->wait_for(unique_lk, chrono::nanoseconds(pullTimeoutNs),
+        cv->wait_for(unique_lk, chrono::nanoseconds(mTimeoutNs),
                      [pullFinish] { return *pullFinish; });
         if (!*pullFinish) {
             // Note: The parent stats puller will also note that there was a timeout and that the
@@ -96,7 +95,7 @@ bool StatsCallbackPuller::PullInternal(vector<shared_ptr<LogEvent>>* data) {
             return true;
         } else {
             // Only copy the data if we did not timeout and the pull was successful.
-            if (pullSuccess) {
+            if (*pullSuccess) {
                 *data = std::move(*sharedData);
             }
             VLOG("StatsCallbackPuller::pull succeeded for %d", mTagId);

cmds/statsd/src/external/StatsCallbackPuller.h

@@ -27,11 +27,17 @@ namespace statsd {
 
 class StatsCallbackPuller : public StatsPuller {
 public:
-    explicit StatsCallbackPuller(int tagId, const sp<IPullAtomCallback>& callback);
+    explicit StatsCallbackPuller(int tagId, const sp<IPullAtomCallback>& callback,
+                                 int64_t timeoutNs);
 
 private:
     bool PullInternal(vector<std::shared_ptr<LogEvent> >* data) override;
     const sp<IPullAtomCallback> mCallback;
+    const int64_t mTimeoutNs;
+
+    FRIEND_TEST(StatsCallbackPullerTest, PullFail);
+    FRIEND_TEST(StatsCallbackPullerTest, PullSuccess);
+    FRIEND_TEST(StatsCallbackPullerTest, PullTimeout);
 };
 
 }  // namespace statsd

cmds/statsd/src/external/StatsPullerManager.cpp

@@ -500,10 +500,11 @@ void StatsPullerManager::RegisterPullAtomCallback(const int uid, const int32_t a
     VLOG("RegisterPullerCallback: adding puller for tag %d", atomTag);
     // TODO: linkToDeath with the callback so that we can remove it and delete the puller.
     StatsdStats::getInstance().notePullerCallbackRegistrationChanged(atomTag, /*registered=*/true);
-    kAllPullAtomInfo[{.atomTag = atomTag}] = {.additiveFields = additiveFields,
-                                              .coolDownNs = coolDownNs,
-                                              .puller = new StatsCallbackPuller(atomTag, callback),
-                                              .pullTimeoutNs = timeoutNs,
+    kAllPullAtomInfo[{.atomTag = atomTag}] = {
+            .additiveFields = additiveFields,
+            .coolDownNs = coolDownNs,
+            .puller = new StatsCallbackPuller(atomTag, callback, timeoutNs),
+            .pullTimeoutNs = timeoutNs,
     };
 }
 

cmds/statsd/src/logd/LogEvent.cpp

@@ -52,6 +52,17 @@ LogEvent::LogEvent(uint8_t* msg, uint32_t len, uint32_t uid)
 #endif
 }
 
+LogEvent::LogEvent(uint8_t* msg, uint32_t len, uint32_t uid, bool useNewSchema)
+    : mBuf(msg), mRemainingLen(len), mLogdTimestampNs(time(nullptr)), mLogUid(uid) {
+    if (useNewSchema) {
+        initNew();
+    } else {
+        mContext = create_android_log_parser((char*)msg, len);
+        init(mContext);
+        if (mContext) android_log_destroy(&mContext);  // set mContext to NULL
+    }
+}
+
 LogEvent::LogEvent(const LogEvent& event) {
     mTagId = event.mTagId;
     mLogUid = event.mLogUid;

cmds/statsd/src/logd/LogEvent.h

@@ -74,6 +74,11 @@ public:
      */
     explicit LogEvent(uint8_t* msg, uint32_t len, uint32_t uid);
 
+    /**
+     * Temp constructor to use for pulled atoms until we flip the socket schema.
+     */
+    explicit LogEvent(uint8_t* msg, uint32_t len, uint32_t uid, bool useNewSchema);
+
     /**
      * Creates LogEvent from StatsLogEventWrapper.
      */

cmds/statsd/tests/external/StatsCallbackPuller_test.cpp

@@ -0,0 +1,210 @@
+// Copyright (C) 2019 The Android Open Source Project
+//
+// Licensed under the Apache License, Version 2.0 (the "License");
+// you may not use this file except in compliance with the License.
+// You may obtain a copy of the License at
+//
+//      http://www.apache.org/licenses/LICENSE-2.0
+//
+// Unless required by applicable law or agreed to in writing, software
+// distributed under the License is distributed on an "AS IS" BASIS,
+// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+// See the License for the specific language governing permissions and
+// limitations under the License.
+
+#include "src/external/StatsCallbackPuller.h"
+
+#include <android/os/BnPullAtomCallback.h>
+#include <android/os/IPullAtomResultReceiver.h>
+#include <gmock/gmock.h>
+#include <gtest/gtest.h>
+#include <stdio.h>
+
+#include <chrono>
+#include <thread>
+#include <vector>
+
+#include "../metrics/metrics_test_helper.h"
+#include "src/stats_log_util.h"
+#include "tests/statsd_test_util.h"
+
+#ifdef __ANDROID__
+
+namespace android {
+namespace os {
+namespace statsd {
+
+using namespace testing;
+using std::make_shared;
+using std::shared_ptr;
+using std::vector;
+using std::this_thread::sleep_for;
+using testing::Contains;
+
+namespace {
+int pullTagId = -12;
+bool pullSuccess;
+vector<int64_t> values;
+int64_t pullDelayNs;
+int64_t pullTimeoutNs;
+int64_t pullCoolDownNs;
+std::thread pullThread;
+
+stats_event* createSimpleEvent(int64_t value) {
+    stats_event* event = stats_event_obtain();
+    stats_event_set_atom_id(event, pullTagId);
+    stats_event_write_int64(event, value);
+    stats_event_build(event);
+    return event;
+}
+
+void executePull(const sp<IPullAtomResultReceiver>& resultReceiver) {
+    // Convert stats_events into StatsEventParcels.
+    std::vector<android::util::StatsEventParcel> parcels;
+    for (int i = 0; i < values.size(); i++) {
+        stats_event* event = createSimpleEvent(values[i]);
+        size_t size;
+        uint8_t* buffer = stats_event_get_buffer(event, &size);
+
+        android::util::StatsEventParcel p;
+        // vector.assign() creates a copy, but this is inevitable unless
+        // stats_event.h/c uses a vector as opposed to a buffer.
+        p.buffer.assign(buffer, buffer + size);
+        parcels.push_back(std::move(p));
+        stats_event_release(event);
+    }
+
+    sleep_for(std::chrono::nanoseconds(pullDelayNs));
+    resultReceiver->pullFinished(pullTagId, pullSuccess, parcels);
+}
+
+class FakePullAtomCallback : public BnPullAtomCallback {
+public:
+    binder::Status onPullAtom(int atomTag,
+                              const sp<IPullAtomResultReceiver>& resultReceiver) override {
+        // Force pull to happen in separate thread to simulate binder.
+        pullThread = std::thread(executePull, resultReceiver);
+        return binder::Status::ok();
+    }
+};
+
+class StatsCallbackPullerTest : public ::testing::Test {
+public:
+    StatsCallbackPullerTest() {
+    }
+
+    void SetUp() override {
+        pullSuccess = false;
+        pullDelayNs = 0;
+        values.clear();
+        pullTimeoutNs = 10000000000LL;  // 10 seconds.
+        pullCoolDownNs = 1000000000;    // 1 second.
+    }
+
+    void TearDown() override {
+        if (pullThread.joinable()) {
+            pullThread.join();
+        }
+        values.clear();
+    }
+};
+}  // Anonymous namespace.
+
+TEST_F(StatsCallbackPullerTest, PullSuccess) {
+    sp<FakePullAtomCallback> cb = new FakePullAtomCallback();
+    int64_t value = 43;
+    pullSuccess = true;
+    values.push_back(value);
+
+    StatsCallbackPuller puller(pullTagId, cb, pullTimeoutNs);
+
+    vector<std::shared_ptr<LogEvent>> dataHolder;
+    int64_t startTimeNs = getElapsedRealtimeNs();
+    EXPECT_TRUE(puller.PullInternal(&dataHolder));
+    int64_t endTimeNs = getElapsedRealtimeNs();
+
+    EXPECT_EQ(1, dataHolder.size());
+    EXPECT_EQ(pullTagId, dataHolder[0]->GetTagId());
+    EXPECT_LT(startTimeNs, dataHolder[0]->GetElapsedTimestampNs());
+    EXPECT_GT(endTimeNs, dataHolder[0]->GetElapsedTimestampNs());
+    EXPECT_EQ(1, dataHolder[0]->size());
+    EXPECT_EQ(value, dataHolder[0]->getValues()[0].mValue.int_value);
+}
+
+TEST_F(StatsCallbackPullerTest, PullFail) {
+    sp<FakePullAtomCallback> cb = new FakePullAtomCallback();
+    pullSuccess = false;
+    int64_t value = 1234;
+    values.push_back(value);
+
+    StatsCallbackPuller puller(pullTagId, cb, pullTimeoutNs);
+
+    vector<std::shared_ptr<LogEvent>> dataHolder;
+    EXPECT_FALSE(puller.PullInternal(&dataHolder));
+    EXPECT_EQ(0, dataHolder.size());
+}
+
+TEST_F(StatsCallbackPullerTest, PullTimeout) {
+    sp<FakePullAtomCallback> cb = new FakePullAtomCallback();
+    pullSuccess = true;
+    pullDelayNs = 500000000;  // 500ms.
+    pullTimeoutNs = 10000;    // 10 microseconds.
+    int64_t value = 4321;
+    values.push_back(value);
+
+    StatsCallbackPuller puller(pullTagId, cb, pullTimeoutNs);
+
+    vector<std::shared_ptr<LogEvent>> dataHolder;
+    int64_t startTimeNs = getElapsedRealtimeNs();
+    // Returns true to let StatsPuller code evaluate the timeout.
+    EXPECT_TRUE(puller.PullInternal(&dataHolder));
+    int64_t endTimeNs = getElapsedRealtimeNs();
+    int64_t actualPullDurationNs = endTimeNs - startTimeNs;
+
+    // Pull should take at least the timeout amount of time, but should stop early because the delay
+    // is bigger.
+    EXPECT_LT(pullTimeoutNs, actualPullDurationNs);
+    EXPECT_GT(pullDelayNs, actualPullDurationNs);
+    EXPECT_EQ(0, dataHolder.size());
+
+    // Let the pull return and make sure that the dataHolder is not modified.
+    pullThread.join();
+    EXPECT_EQ(0, dataHolder.size());
+}
+
+// Register a puller and ensure that the timeout logic works.
+TEST_F(StatsCallbackPullerTest, RegisterAndTimeout) {
+    sp<FakePullAtomCallback> cb = new FakePullAtomCallback();
+    pullSuccess = true;
+    pullDelayNs = 500000000;  // 500 ms.
+    pullTimeoutNs = 10000;    // 10 microsseconds.
+    int64_t value = 4321;
+    values.push_back(value);
+
+    StatsPullerManager pullerManager;
+    pullerManager.RegisterPullAtomCallback(/*uid=*/-1, pullTagId, pullCoolDownNs, pullTimeoutNs,
+                                           vector<int32_t>(), cb);
+    vector<std::shared_ptr<LogEvent>> dataHolder;
+    int64_t startTimeNs = getElapsedRealtimeNs();
+    // Returns false, since StatsPuller code will evaluate the timeout.
+    EXPECT_FALSE(pullerManager.Pull(pullTagId, &dataHolder));
+    int64_t endTimeNs = getElapsedRealtimeNs();
+    int64_t actualPullDurationNs = endTimeNs - startTimeNs;
+
+    // Pull should take at least the timeout amount of time, but should stop early because the delay
+    // is bigger.
+    EXPECT_LT(pullTimeoutNs, actualPullDurationNs);
+    EXPECT_GT(pullDelayNs, actualPullDurationNs);
+    EXPECT_EQ(0, dataHolder.size());
+
+    // Let the pull return and make sure that the dataHolder is not modified.
+    pullThread.join();
+    EXPECT_EQ(0, dataHolder.size());
+}
+
+}  // namespace statsd
+}  // namespace os
+}  // namespace android
+#else
+GTEST_LOG_(INFO) << "This test does nothing.\n";
+#endif

cmds/statsd/tests/external/StatsPuller_test.cpp

@@ -35,6 +35,7 @@ using std::vector;
 using std::this_thread::sleep_for;
 using testing::Contains;
 
+namespace {
 // cooldown time 1sec.
 int pullTagId = 10014;
 
@@ -76,7 +77,9 @@ public:
     }
 };
 
-TEST_F(StatsPullerTest, PullSucces) {
+}  // Anonymous namespace.
+
+TEST_F(StatsPullerTest, PullSuccess) {
     pullData.push_back(createSimpleEvent(1111L, 33));
 
     pullSuccess = true;