Puller API: Unit tests.
Tests 4 key things: A successful pull, a failed pull and two timeout
cases.
Timeout case 1: StatsPullerCallback should stop early and return true.
Timeout case 2: StatsCallback should note that the pull timed out,
notify statsd stats, and return false.
Test: bit statsd_test:*
Bug: 145310627
Change-Id: Id87089f04e1cf54a622b3f15585341ecdcd21f7f
diff --git a/bin/Android.bp b/bin/Android.bp
index 17427a2..484f823 100644
--- a/bin/Android.bp
+++ b/bin/Android.bp
@@ -250,6 +250,7 @@
"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",
diff --git a/bin/src/external/StatsCallbackPuller.cpp b/bin/src/external/StatsCallbackPuller.cpp
index f5b1e7f..0e6b677 100644
--- a/bin/src/external/StatsCallbackPuller.cpp
+++ b/bin/src/external/StatsCallbackPuller.cpp
@@ -35,8 +35,9 @@
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 @@
{
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 @@
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 @@
{
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 @@
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);
diff --git a/bin/src/external/StatsCallbackPuller.h b/bin/src/external/StatsCallbackPuller.h
index ce506c7..d943f9d 100644
--- a/bin/src/external/StatsCallbackPuller.h
+++ b/bin/src/external/StatsCallbackPuller.h
@@ -27,11 +27,17 @@
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
diff --git a/bin/src/external/StatsPullerManager.cpp b/bin/src/external/StatsPullerManager.cpp
index b5bad05..b7f3b8a 100644
--- a/bin/src/external/StatsPullerManager.cpp
+++ b/bin/src/external/StatsPullerManager.cpp
@@ -497,10 +497,11 @@
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,
};
}
diff --git a/bin/src/logd/LogEvent.cpp b/bin/src/logd/LogEvent.cpp
index 67022a0..36f4623 100644
--- a/bin/src/logd/LogEvent.cpp
+++ b/bin/src/logd/LogEvent.cpp
@@ -52,6 +52,17 @@
#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;
diff --git a/bin/src/logd/LogEvent.h b/bin/src/logd/LogEvent.h
index 1ff95f7..596d623 100644
--- a/bin/src/logd/LogEvent.h
+++ b/bin/src/logd/LogEvent.h
@@ -75,6 +75,11 @@
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.
*/
static void createLogEvents(const StatsLogEventWrapper& statsLogEventWrapper,
diff --git a/bin/tests/external/StatsCallbackPuller_test.cpp b/bin/tests/external/StatsCallbackPuller_test.cpp
new file mode 100644
index 0000000..2b0590d
--- /dev/null
+++ b/bin/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
diff --git a/bin/tests/external/StatsPuller_test.cpp b/bin/tests/external/StatsPuller_test.cpp
index 76e2097..c40719a 100644
--- a/bin/tests/external/StatsPuller_test.cpp
+++ b/bin/tests/external/StatsPuller_test.cpp
@@ -35,6 +35,7 @@
using std::this_thread::sleep_for;
using testing::Contains;
+namespace {
// cooldown time 1sec.
int pullTagId = 10014;
@@ -76,7 +77,9 @@
}
};
-TEST_F(StatsPullerTest, PullSucces) {
+} // Anonymous namespace.
+
+TEST_F(StatsPullerTest, PullSuccess) {
pullData.push_back(createSimpleEvent(1111L, 33));
pullSuccess = true;