diff --git a/cmds/statsd/Android.bp b/cmds/statsd/Android.bp index 17427a20b90e7..484f82330055e 100644 --- a/cmds/statsd/Android.bp +++ b/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", diff --git a/cmds/statsd/src/external/StatsCallbackPuller.cpp b/cmds/statsd/src/external/StatsCallbackPuller.cpp index f5b1e7f78736f..0e6b677abb46c 100644 --- a/cmds/statsd/src/external/StatsCallbackPuller.cpp +++ b/cmds/statsd/src/external/StatsCallbackPuller.cpp @@ -35,8 +35,9 @@ namespace android { namespace os { namespace statsd { -StatsCallbackPuller::StatsCallbackPuller(int tagId, const sp& callback) - : StatsPuller(tagId), mCallback(callback) { +StatsCallbackPuller::StatsCallbackPuller(int tagId, const sp& 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>* data) { { lock_guard lk(*cv_mutex); for (const StatsEventParcel& parcel: output) { - shared_ptr event = - make_shared(const_cast(parcel.buffer.data()), - parcel.buffer.size(), - /*uid=*/ -1); + shared_ptr event = make_shared( + const_cast(parcel.buffer.data()), parcel.buffer.size(), + /*uid=*/-1, /*useNewSchema=*/true); sharedData->push_back(event); } *pullSuccess = success; @@ -76,7 +76,8 @@ bool StatsCallbackPuller::PullInternal(vector>* 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>* data) { { unique_lock 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>* 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); diff --git a/cmds/statsd/src/external/StatsCallbackPuller.h b/cmds/statsd/src/external/StatsCallbackPuller.h index ce506c7f97850..d943f9d189c56 100644 --- a/cmds/statsd/src/external/StatsCallbackPuller.h +++ b/cmds/statsd/src/external/StatsCallbackPuller.h @@ -27,11 +27,17 @@ namespace statsd { class StatsCallbackPuller : public StatsPuller { public: - explicit StatsCallbackPuller(int tagId, const sp& callback); + explicit StatsCallbackPuller(int tagId, const sp& callback, + int64_t timeoutNs); private: bool PullInternal(vector >* data) override; const sp mCallback; + const int64_t mTimeoutNs; + + FRIEND_TEST(StatsCallbackPullerTest, PullFail); + FRIEND_TEST(StatsCallbackPullerTest, PullSuccess); + FRIEND_TEST(StatsCallbackPullerTest, PullTimeout); }; } // namespace statsd diff --git a/cmds/statsd/src/external/StatsPullerManager.cpp b/cmds/statsd/src/external/StatsPullerManager.cpp index 615af89e3186f..9ee627efa841e 100644 --- a/cmds/statsd/src/external/StatsPullerManager.cpp +++ b/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, }; } diff --git a/cmds/statsd/src/logd/LogEvent.cpp b/cmds/statsd/src/logd/LogEvent.cpp index 67022a078b015..36f4623c4dcb8 100644 --- a/cmds/statsd/src/logd/LogEvent.cpp +++ b/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; diff --git a/cmds/statsd/src/logd/LogEvent.h b/cmds/statsd/src/logd/LogEvent.h index 1ff95f7240aca..596d623debe56 100644 --- a/cmds/statsd/src/logd/LogEvent.h +++ b/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. */ diff --git a/cmds/statsd/tests/external/StatsCallbackPuller_test.cpp b/cmds/statsd/tests/external/StatsCallbackPuller_test.cpp new file mode 100644 index 0000000000000..2b0590d11f547 --- /dev/null +++ b/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 +#include +#include +#include +#include + +#include +#include +#include + +#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 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& resultReceiver) { + // Convert stats_events into StatsEventParcels. + std::vector 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& 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 cb = new FakePullAtomCallback(); + int64_t value = 43; + pullSuccess = true; + values.push_back(value); + + StatsCallbackPuller puller(pullTagId, cb, pullTimeoutNs); + + vector> 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 cb = new FakePullAtomCallback(); + pullSuccess = false; + int64_t value = 1234; + values.push_back(value); + + StatsCallbackPuller puller(pullTagId, cb, pullTimeoutNs); + + vector> dataHolder; + EXPECT_FALSE(puller.PullInternal(&dataHolder)); + EXPECT_EQ(0, dataHolder.size()); +} + +TEST_F(StatsCallbackPullerTest, PullTimeout) { + sp 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> 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 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(), cb); + vector> 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/cmds/statsd/tests/external/StatsPuller_test.cpp b/cmds/statsd/tests/external/StatsPuller_test.cpp index 76e2097a90b88..c40719a17f625 100644 --- a/cmds/statsd/tests/external/StatsPuller_test.cpp +++ b/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;