webrtc/logging/rtc_event_log/rtc_event_log_impl_unittest.cc
Xuanxi Leng 85abbdf526 RtcEventLogImpl: Add test cases
This change adds below test cases:
1. Keep most recent config events on start.
2. Rewrite all previous config events on restart.
3. Do not drop events when far more events than max event history logged
on logging start.

Bug: chromium:1288710
Change-Id: Ifc227e8be788d33dc2ed65f49281b3d0809231c6
Reviewed-on: https://webrtc-review.googlesource.com/c/src/+/291739
Reviewed-by: Markus Handell <handellm@webrtc.org>
Reviewed-by: Björn Terelius <terelius@webrtc.org>
Commit-Queue: Björn Terelius <terelius@webrtc.org>
Cr-Commit-Position: refs/heads/main@{#39253}
2023-02-03 09:55:33 +00:00

253 lines
9.3 KiB
C++

/*
* Copyright (c) 2023 The WebRTC project authors. All Rights Reserved.
*
* Use of this source code is governed by a BSD-style license
* that can be found in the LICENSE file in the root of the source
* tree. An additional intellectual property rights grant can be found
* in the file PATENTS. All contributing project authors may
* be found in the AUTHORS file in the root of the source tree.
*/
#include "logging/rtc_event_log/rtc_event_log_impl.h"
#include <utility>
#include <vector>
#include "test/gmock.h"
#include "test/gtest.h"
#include "test/time_controller/simulated_time_controller.h"
namespace webrtc {
namespace {
using ::testing::InSequence;
using ::testing::Mock;
using ::testing::Property;
using ::testing::Ref;
using ::testing::Return;
using ::testing::StrEq;
class MockEventEncoder : public RtcEventLogEncoder {
public:
MOCK_METHOD(std::string,
EncodeLogStart,
(int64_t /*timestamp_us*/, int64_t /*utc_time_us*/),
(override));
MOCK_METHOD(std::string,
EncodeLogEnd,
(int64_t /*timestamp_us*/),
(override));
MOCK_METHOD(std::string, OnEncode, (const RtcEvent&), ());
std::string EncodeBatch(
std::deque<std::unique_ptr<RtcEvent>>::const_iterator a,
std::deque<std::unique_ptr<RtcEvent>>::const_iterator b) override {
std::string result;
while (a != b) {
result += OnEncode(**a);
++a;
}
return result;
}
};
class FakeOutput : public RtcEventLogOutput {
public:
explicit FakeOutput(std::string& written_data)
: written_data_(written_data) {}
bool IsActive() const { return true; }
bool Write(absl::string_view data) override {
written_data_.append(std::string(data));
return true;
}
void Flush() override {}
private:
std::string& written_data_;
};
class FakeEvent : public RtcEvent {
public:
Type GetType() const override { return RtcEvent::Type::FakeEvent; }
bool IsConfigEvent() const override { return false; }
};
class FakeConfigEvent : public RtcEvent {
public:
Type GetType() const override { return RtcEvent::Type::FakeEvent; }
bool IsConfigEvent() const override { return true; }
};
class RtcEventLogImplTest : public ::testing::Test {
public:
static constexpr size_t kMaxEventsInHistory = 2;
static constexpr size_t kMaxEventsInConfigHistory = 5;
static constexpr TimeDelta kOutputPeriod = TimeDelta::Seconds(2);
static constexpr Timestamp kStartTime = Timestamp::Seconds(1);
GlobalSimulatedTimeController time_controller_{kStartTime};
std::unique_ptr<MockEventEncoder> encoder_ =
std::make_unique<MockEventEncoder>();
MockEventEncoder* encoder_ptr_ = encoder_.get();
std::unique_ptr<FakeOutput> output_ =
std::make_unique<FakeOutput>(written_data_);
FakeOutput* output_ptr_ = output_.get();
RtcEventLogImpl event_log_{std::move(encoder_),
time_controller_.GetTaskQueueFactory(),
kMaxEventsInHistory, kMaxEventsInConfigHistory};
std::string written_data_;
};
TEST_F(RtcEventLogImplTest, WritesHeaderAndEventsAndTrailer) {
EXPECT_CALL(*encoder_ptr_, EncodeLogStart(kStartTime.us(), kStartTime.us()))
.WillOnce(Return("start"));
EXPECT_CALL(*encoder_ptr_, EncodeLogEnd(kStartTime.us()))
.WillOnce(Return("stop"));
EXPECT_CALL(*encoder_ptr_, OnEncode(Property(&RtcEvent::IsConfigEvent, true)))
.WillOnce(Return("config"));
EXPECT_CALL(*encoder_ptr_,
OnEncode(Property(&RtcEvent::IsConfigEvent, false)))
.WillOnce(Return("event"));
event_log_.StartLogging(std::move(output_), kOutputPeriod.ms());
event_log_.Log(std::make_unique<FakeEvent>());
event_log_.Log(std::make_unique<FakeConfigEvent>());
event_log_.StopLogging();
Mock::VerifyAndClearExpectations(encoder_ptr_);
EXPECT_TRUE(written_data_ == "startconfigeventstop" ||
written_data_ == "starteventconfigstop");
}
TEST_F(RtcEventLogImplTest, KeepsMostRecentEventsOnStart) {
auto e2 = std::make_unique<FakeEvent>();
RtcEvent* e2_ptr = e2.get();
auto e3 = std::make_unique<FakeEvent>();
RtcEvent* e3_ptr = e3.get();
event_log_.Log(std::make_unique<FakeEvent>());
event_log_.Log(std::move(e2));
event_log_.Log(std::move(e3));
InSequence s;
EXPECT_CALL(*encoder_ptr_, OnEncode(Ref(*e2_ptr)));
EXPECT_CALL(*encoder_ptr_, OnEncode(Ref(*e3_ptr)));
event_log_.StartLogging(std::move(output_), kOutputPeriod.ms());
time_controller_.AdvanceTime(TimeDelta::Zero());
Mock::VerifyAndClearExpectations(encoder_ptr_);
}
TEST_F(RtcEventLogImplTest, KeepsConfigEventsOnStart) {
// The config-history is supposed to be unbounded and never overflow.
auto c1 = std::make_unique<FakeConfigEvent>();
RtcEvent* c1_ptr = c1.get();
auto c2 = std::make_unique<FakeConfigEvent>();
RtcEvent* c2_ptr = c2.get();
auto c3 = std::make_unique<FakeConfigEvent>();
RtcEvent* c3_ptr = c3.get();
event_log_.Log(std::move(c1));
event_log_.Log(std::move(c2));
event_log_.Log(std::move(c3));
InSequence s;
EXPECT_CALL(*encoder_ptr_, OnEncode(Ref(*c1_ptr)));
EXPECT_CALL(*encoder_ptr_, OnEncode(Ref(*c2_ptr)));
EXPECT_CALL(*encoder_ptr_, OnEncode(Ref(*c3_ptr)));
event_log_.StartLogging(std::move(output_), kOutputPeriod.ms());
time_controller_.AdvanceTime(TimeDelta::Zero());
Mock::VerifyAndClearExpectations(encoder_ptr_);
}
TEST_F(RtcEventLogImplTest, EncodesEventsOnHistoryFullPostponesLastEncode) {
auto e1 = std::make_unique<FakeEvent>();
RtcEvent* e1_ptr = e1.get();
auto e2 = std::make_unique<FakeEvent>();
RtcEvent* e2_ptr = e2.get();
auto e3 = std::make_unique<FakeEvent>();
RtcEvent* e3_ptr = e3.get();
event_log_.StartLogging(std::move(output_), kOutputPeriod.ms());
time_controller_.AdvanceTime(TimeDelta::Zero());
event_log_.Log(std::move(e1));
event_log_.Log(std::move(e2));
// Overflows and causes immediate output, and eventual output after the output
// period has passed.
event_log_.Log(std::move(e3));
InSequence s;
EXPECT_CALL(*encoder_ptr_, OnEncode(Ref(*e1_ptr)));
EXPECT_CALL(*encoder_ptr_, OnEncode(Ref(*e2_ptr)));
time_controller_.AdvanceTime(TimeDelta::Zero());
EXPECT_CALL(*encoder_ptr_, OnEncode(Ref(*e3_ptr)));
time_controller_.AdvanceTime(kOutputPeriod);
Mock::VerifyAndClearExpectations(encoder_ptr_);
}
TEST_F(RtcEventLogImplTest, RewritesAllConfigEventsOnlyOnRestart) {
auto c1 = std::make_unique<FakeConfigEvent>();
RtcEvent* c1_ptr = c1.get();
auto c2 = std::make_unique<FakeConfigEvent>();
RtcEvent* c2_ptr = c2.get();
auto c3 = std::make_unique<FakeConfigEvent>();
RtcEvent* c3_ptr = c3.get();
auto c4 = std::make_unique<FakeConfigEvent>();
RtcEvent* c4_ptr = c4.get();
auto c5 = std::make_unique<FakeConfigEvent>();
RtcEvent* c5_ptr = c5.get();
// Keep the config event before start.
event_log_.Log(std::move(c1));
// Start logging.
event_log_.StartLogging(std::make_unique<FakeOutput>(written_data_),
kOutputPeriod.ms());
event_log_.Log(std::move(c2));
event_log_.Log(std::move(c3));
event_log_.StopLogging();
time_controller_.AdvanceTime(TimeDelta::Zero());
// Restart logging.
event_log_.StartLogging(std::make_unique<FakeOutput>(written_data_),
kOutputPeriod.ms());
event_log_.Log(std::move(c4));
event_log_.Log(std::move(c5));
event_log_.Log(std::make_unique<FakeEvent>());
event_log_.StopLogging();
time_controller_.AdvanceTime(TimeDelta::Zero());
InSequence s;
// Rewrite all config events in sequence on next restart.
EXPECT_CALL(*encoder_ptr_, OnEncode(Ref(*c1_ptr)));
EXPECT_CALL(*encoder_ptr_, OnEncode(Ref(*c2_ptr)));
EXPECT_CALL(*encoder_ptr_, OnEncode(Ref(*c3_ptr)));
EXPECT_CALL(*encoder_ptr_, OnEncode(Ref(*c4_ptr)));
EXPECT_CALL(*encoder_ptr_, OnEncode(Ref(*c5_ptr)));
EXPECT_CALL(*encoder_ptr_,
OnEncode(Property(&RtcEvent::IsConfigEvent, false)))
.Times(0);
event_log_.StartLogging(std::move(output_), kOutputPeriod.ms());
time_controller_.AdvanceTime(TimeDelta::Zero());
Mock::VerifyAndClearExpectations(encoder_ptr_);
}
TEST_F(RtcEventLogImplTest, SchedulesWriteAfterOutputDurationPassed) {
event_log_.StartLogging(std::make_unique<FakeOutput>(written_data_),
kOutputPeriod.ms());
event_log_.Log(std::make_unique<FakeConfigEvent>());
event_log_.Log(std::make_unique<FakeEvent>());
EXPECT_CALL(*encoder_ptr_,
OnEncode(Property(&RtcEvent::IsConfigEvent, true)));
EXPECT_CALL(*encoder_ptr_,
OnEncode(Property(&RtcEvent::IsConfigEvent, false)));
time_controller_.AdvanceTime(kOutputPeriod);
Mock::VerifyAndClearExpectations(encoder_ptr_);
}
TEST_F(RtcEventLogImplTest, DoNotDropEventsIfHistoryFullAfterStarted) {
const size_t kNumberOfEvents = 10 * kMaxEventsInHistory;
event_log_.StartLogging(std::make_unique<FakeOutput>(written_data_),
kOutputPeriod.ms());
event_log_.Log(std::make_unique<FakeConfigEvent>());
for (size_t i = 0; i < kNumberOfEvents; i++) {
event_log_.Log(std::make_unique<FakeEvent>());
}
EXPECT_CALL(*encoder_ptr_,
OnEncode(Property(&RtcEvent::IsConfigEvent, true)));
EXPECT_CALL(*encoder_ptr_,
OnEncode(Property(&RtcEvent::IsConfigEvent, false)))
.Times(kNumberOfEvents);
time_controller_.AdvanceTime(kOutputPeriod);
Mock::VerifyAndClearExpectations(encoder_ptr_);
}
} // namespace
} // namespace webrtc