Revert "Revert "Encode log events periodically instead of for every event.""
This reverts commit 33c5c7f5e4f018a5103770021328fc530d451d75.
Reason for revert: Fix broken API change.
TBR=sprang@webrtc.org,solenberg@webrtc.org
TBRing because only pc/ and api/ have changed since last LGTMed version.
Original change's description:
> Revert "Encode log events periodically instead of for every event."
>
> This reverts commit b154c27e72fddb6c0d7cac69a9c68fff22154519.
>
> Reason for revert: Broke the internal project.
>
> Original change's description:
> > Encode log events periodically instead of for every event.
> >
> > Updated unit test to take output_period and random seed as parameters.
> > Updated the peerconnection interface to allow passing in an output_period.
> >
> > This is in preparation of some upcoming CLs that will change the format
> > to store batches of delta-encoded values.
> >
> >
> > Bug: webrtc:8111
> > Change-Id: Id5d9844dfad8d8edad346cd7cbebc7eadaaa5416
> > Reviewed-on: https://webrtc-review.googlesource.com/22600
> > Commit-Queue: Björn Terelius <terelius@webrtc.org>
> > Reviewed-by: Elad Alon <eladalon@webrtc.org>
> > Reviewed-by: Tommi <tommi@webrtc.org>
> > Reviewed-by: Erik Språng <sprang@webrtc.org>
> > Reviewed-by: Fredrik Solenberg <solenberg@webrtc.org>
> > Cr-Commit-Position: refs/heads/master@{#20736}
>
> Change-Id: I2257c46c014adb8c7c4fb28538635cabed1f2229
> Bug: webrtc:8111
> Reviewed-on: https://webrtc-review.googlesource.com/24160
> Reviewed-by: Zhi Huang <zhihuang@webrtc.org>
> Commit-Queue: Zhi Huang <zhihuang@webrtc.org>
> Cr-Commit-Position: refs/heads/master@{#20738}
Bug: webrtc:8111
Change-Id: Ie69862cd52d11c1e15adeb6e2caacafe16863c80
Reviewed-on: https://webrtc-review.googlesource.com/24620
Commit-Queue: Björn Terelius <terelius@webrtc.org>
Reviewed-by: Elad Alon <eladalon@webrtc.org>
Reviewed-by: Zhi Huang <zhihuang@webrtc.org>
Reviewed-by: Tommi <tommi@webrtc.org>
Reviewed-by: Björn Terelius <terelius@webrtc.org>
Cr-Commit-Position: refs/heads/master@{#20811}diff --git a/api/peerconnectioninterface.h b/api/peerconnectioninterface.h
index c95cc7d..a682459 100644
--- a/api/peerconnectioninterface.h
+++ b/api/peerconnectioninterface.h
@@ -859,8 +859,10 @@
// Start RtcEventLog using an existing output-sink. Takes ownership of
// |output| and passes it on to Call, which will take the ownership. If the
- // operation fails the output will be closed and deallocated.
- virtual bool StartRtcEventLog(std::unique_ptr<RtcEventLogOutput> output) {
+ // operation fails the output will be closed and deallocated. The event log
+ // will send serialized events to the output object every |output_period_ms|.
+ virtual bool StartRtcEventLog(std::unique_ptr<RtcEventLogOutput> output,
+ int64_t output_period_ms) {
return false;
}
diff --git a/api/peerconnectionproxy.h b/api/peerconnectionproxy.h
index 78fe402..36ee50f 100644
--- a/api/peerconnectionproxy.h
+++ b/api/peerconnectionproxy.h
@@ -111,7 +111,10 @@
PROXY_METHOD0(IceConnectionState, ice_connection_state)
PROXY_METHOD0(IceGatheringState, ice_gathering_state)
PROXY_METHOD2(bool, StartRtcEventLog, rtc::PlatformFile, int64_t)
- PROXY_METHOD1(bool, StartRtcEventLog, std::unique_ptr<RtcEventLogOutput>)
+ PROXY_METHOD2(bool,
+ StartRtcEventLog,
+ std::unique_ptr<RtcEventLogOutput>,
+ int64_t);
PROXY_METHOD0(void, StopRtcEventLog)
PROXY_METHOD0(void, Close)
END_PROXY_MAP()
diff --git a/logging/rtc_event_log/mock/mock_rtc_event_log.h b/logging/rtc_event_log/mock/mock_rtc_event_log.h
index 6a4cdbd..6f69169 100644
--- a/logging/rtc_event_log/mock/mock_rtc_event_log.h
+++ b/logging/rtc_event_log/mock/mock_rtc_event_log.h
@@ -20,10 +20,11 @@
class MockRtcEventLog : public RtcEventLog {
public:
- virtual bool StartLogging(std::unique_ptr<RtcEventLogOutput> output) {
- return StartLoggingProxy(output.get());
+ virtual bool StartLogging(std::unique_ptr<RtcEventLogOutput> output,
+ int64_t output_period_ms) {
+ return StartLoggingProxy(output.get(), output_period_ms);
}
- MOCK_METHOD1(StartLoggingProxy, bool(RtcEventLogOutput*));
+ MOCK_METHOD2(StartLoggingProxy, bool(RtcEventLogOutput*, int64_t));
MOCK_METHOD0(StopLogging, void());
diff --git a/logging/rtc_event_log/rtc_event_log.cc b/logging/rtc_event_log/rtc_event_log.cc
index 7e17e6b..53096de 100644
--- a/logging/rtc_event_log/rtc_event_log.cc
+++ b/logging/rtc_event_log/rtc_event_log.cc
@@ -28,6 +28,7 @@
#include "rtc_base/logging.h"
#include "rtc_base/ptr_util.h"
#include "rtc_base/safe_conversions.h"
+#include "rtc_base/safe_minmax.h"
#include "rtc_base/sequenced_task_checker.h"
#include "rtc_base/task_queue.h"
#include "rtc_base/thread_annotations.h"
@@ -87,7 +88,8 @@
// TODO(eladalon): We should change these name to reflect that what we're
// actually starting/stopping is the output of the log, not the log itself.
- bool StartLogging(std::unique_ptr<RtcEventLogOutput> output) override;
+ bool StartLogging(std::unique_ptr<RtcEventLogOutput> output,
+ int64_t output_period_ms) override;
void StopLogging() override;
void Log(std::unique_ptr<RtcEvent> event) override;
@@ -113,6 +115,8 @@
void StopLoggingInternal() RTC_RUN_ON(&task_queue_);
+ void ScheduleOutput() RTC_RUN_ON(&task_queue_);
+
// Make sure that the event log is "managed" - created/destroyed, as well
// as started/stopped - from the same thread/task-queue.
rtc::SequencedTaskChecker owner_sequence_checker_;
@@ -130,8 +134,15 @@
std::unique_ptr<RtcEventLogEncoder> event_encoder_ RTC_ACCESS_ON(task_queue_);
std::unique_ptr<RtcEventLogOutput> event_output_ RTC_ACCESS_ON(task_queue_);
- // Keep this last to ensure it destructs first, or else tasks living on the
- // queue might access other members after they've been torn down.
+ size_t num_config_events_written_ RTC_ACCESS_ON(task_queue_);
+ int64_t output_period_ms_ RTC_ACCESS_ON(task_queue_);
+ int64_t last_output_ms_ RTC_ACCESS_ON(task_queue_);
+ bool output_scheduled_ RTC_ACCESS_ON(task_queue_);
+
+ // Since we are posting tasks bound to |this|, it is critical that the event
+ // log and it's members outlive the |task_queue_|. Keep the "task_queue_|
+ // last to ensure it destructs first, or else tasks living on the queue might
+ // access other members after they've been torn down.
rtc::TaskQueue task_queue_;
RTC_DISALLOW_COPY_AND_ASSIGN(RtcEventLogImpl);
@@ -142,6 +153,10 @@
: max_size_bytes_(std::numeric_limits<decltype(max_size_bytes_)>::max()),
written_bytes_(0),
event_encoder_(std::move(event_encoder)),
+ num_config_events_written_(0),
+ output_period_ms_(kImmediateOutput),
+ last_output_ms_(rtc::TimeMillis()),
+ output_scheduled_(false),
task_queue_("rtc_event_log") {}
RtcEventLogImpl::~RtcEventLogImpl() {
@@ -154,10 +169,15 @@
RTC_DCHECK_GE(count, 0);
}
-bool RtcEventLogImpl::StartLogging(std::unique_ptr<RtcEventLogOutput> output) {
+bool RtcEventLogImpl::StartLogging(std::unique_ptr<RtcEventLogOutput> output,
+ int64_t output_period_ms) {
RTC_DCHECK_CALLED_SEQUENTIALLY(&owner_sequence_checker_);
+ RTC_DCHECK(output_period_ms == kImmediateOutput || output_period_ms > 0);
+
if (!output->IsActive()) {
+ // TODO(eladalon): We may want to remove the IsActive method. Otherwise
+ // we probably want to be consistent and terminate any existing output.
return false;
}
@@ -170,10 +190,12 @@
// to comply with LogToOutput()'s signature - but it's a small problem.
RtcEventLoggingStarted start_event;
+ // Binding to |this| is safe because |this| outlives the |task_queue_|.
auto start = [this, start_event](std::unique_ptr<RtcEventLogOutput> output) {
RTC_DCHECK_RUN_ON(&task_queue_);
RTC_DCHECK(output->IsActive());
event_output_ = std::move(output);
+ num_config_events_written_ = 0;
LogToOutput(rtc::MakeUnique<RtcEventLoggingStarted>(start_event));
LogEventsFromMemoryToOutput();
};
@@ -191,8 +213,13 @@
rtc::Event output_stopped(true, false);
+ // Binding to |this| is safe because |this| outlives the |task_queue_|.
task_queue_.PostTask([this, &output_stopped]() {
RTC_DCHECK_RUN_ON(&task_queue_);
+ if (event_output_) {
+ RTC_DCHECK(event_output_->IsActive());
+ LogEventsFromMemoryToOutput();
+ }
StopLoggingInternal();
output_stopped.Set();
});
@@ -205,19 +232,53 @@
void RtcEventLogImpl::Log(std::unique_ptr<RtcEvent> event) {
RTC_DCHECK(event);
+ // Binding to |this| is safe because |this| outlives the |task_queue_|.
auto event_handler = [this](std::unique_ptr<RtcEvent> unencoded_event) {
RTC_DCHECK_RUN_ON(&task_queue_);
- if (event_output_) {
- LogToOutput(std::move(unencoded_event));
- } else {
- LogToMemory(std::move(unencoded_event));
- }
+ LogToMemory(std::move(unencoded_event));
+ if (event_output_)
+ ScheduleOutput();
};
task_queue_.PostTask(rtc::MakeUnique<ResourceOwningTask<RtcEvent>>(
std::move(event), event_handler));
}
+void RtcEventLogImpl::ScheduleOutput() {
+ RTC_DCHECK(event_output_ && event_output_->IsActive());
+ if (history_.size() >= kMaxEventsInHistory) {
+ // We have to emergency drain the buffer. We can't wait for the scheduled
+ // output task because there might be other event incoming before that.
+ LogEventsFromMemoryToOutput();
+ return;
+ }
+
+ if (output_period_ms_ == kImmediateOutput) {
+ // We are already on the |task_queue_| so there is no reason to post a task
+ // if we want to output immediately.
+ LogEventsFromMemoryToOutput();
+ return;
+ }
+
+ if (!output_scheduled_) {
+ output_scheduled_ = true;
+ // Binding to |this| is safe because |this| outlives the |task_queue_|.
+ auto output_task = [this]() {
+ RTC_DCHECK_RUN_ON(&task_queue_);
+ if (event_output_) {
+ RTC_DCHECK(event_output_->IsActive());
+ LogEventsFromMemoryToOutput();
+ }
+ output_scheduled_ = false;
+ };
+ int64_t now_ms = rtc::TimeMillis();
+ int64_t time_since_output_ms = now_ms - last_output_ms_;
+ uint32_t delay = rtc::SafeClamp(output_period_ms_ - time_since_output_ms, 0,
+ output_period_ms_);
+ task_queue_.PostDelayedTask(output_task, delay);
+ }
+}
+
bool RtcEventLogImpl::AppendEventToString(const RtcEvent& event,
std::string* output_string) {
RTC_DCHECK_RUN_ON(&task_queue_);
@@ -239,14 +300,13 @@
}
void RtcEventLogImpl::LogToMemory(std::unique_ptr<RtcEvent> event) {
- RTC_DCHECK(!event_output_);
-
std::deque<std::unique_ptr<RtcEvent>>& container =
event->IsConfigEvent() ? config_history_ : history_;
const size_t container_max_size =
event->IsConfigEvent() ? kMaxEventsInConfigHistory : kMaxEventsInHistory;
if (container.size() >= container_max_size) {
+ RTC_DCHECK(!event_output_); // Shouldn't lose events if we have an output.
container.pop_front();
}
container.push_back(std::move(event));
@@ -254,17 +314,21 @@
void RtcEventLogImpl::LogEventsFromMemoryToOutput() {
RTC_DCHECK(event_output_ && event_output_->IsActive());
+ last_output_ms_ = rtc::TimeMillis();
std::string output_string;
- // Serialize the config information for all old streams, including streams
- // which were already logged to previous outputs.
+ // Serialize all stream configurations that haven't already been written to
+ // this output. |num_config_events_written_| is used to track which configs we
+ // have already written. (Note that the config may have been written to
+ // previous outputs; configs are not discarded.)
bool appended = true;
- for (auto& event : config_history_) {
- if (!AppendEventToString(*event, &output_string)) {
- appended = false;
+ while (num_config_events_written_ < config_history_.size()) {
+ appended = AppendEventToString(*config_history_[num_config_events_written_],
+ &output_string);
+ if (!appended)
break;
- }
+ ++num_config_events_written_;
}
// Serialize the events in the event queue.
diff --git a/logging/rtc_event_log/rtc_event_log.h b/logging/rtc_event_log/rtc_event_log.h
index c1c71f0..89b4fc1 100644
--- a/logging/rtc_event_log/rtc_event_log.h
+++ b/logging/rtc_event_log/rtc_event_log.h
@@ -13,6 +13,7 @@
#include <memory>
#include <string>
+#include <utility>
#include "api/rtceventlogoutput.h"
#include "logging/rtc_event_log/events/rtc_event.h"
@@ -26,6 +27,7 @@
class RtcEventLog {
public:
enum : size_t { kUnlimitedOutput = 0 };
+ enum : int64_t { kImmediateOutput = 0 };
// TODO(eladalon): Two stages are upcoming.
// 1. Extend this to actually support the new encoding.
@@ -49,7 +51,8 @@
// Starts logging to a given output. The output might be limited in size,
// and may close itself once it has reached the maximum size.
- virtual bool StartLogging(std::unique_ptr<RtcEventLogOutput> output) = 0;
+ virtual bool StartLogging(std::unique_ptr<RtcEventLogOutput> output,
+ int64_t output_period_ms) = 0;
// Stops logging to file and waits until the file has been closed, after
// which it would be permissible to read and/or modify it.
@@ -62,7 +65,8 @@
// No-op implementation is used if flag is not set, or in tests.
class RtcEventLogNullImpl : public RtcEventLog {
public:
- bool StartLogging(std::unique_ptr<RtcEventLogOutput> output) override {
+ bool StartLogging(std::unique_ptr<RtcEventLogOutput> output,
+ int64_t output_period_ms) override {
return false;
}
void StopLogging() override {}
diff --git a/logging/rtc_event_log/rtc_event_log_unittest.cc b/logging/rtc_event_log/rtc_event_log_unittest.cc
index 3d4abb3..fbef901 100644
--- a/logging/rtc_event_log/rtc_event_log_unittest.cc
+++ b/logging/rtc_event_log/rtc_event_log_unittest.cc
@@ -12,6 +12,7 @@
#include <memory>
#include <ostream>
#include <string>
+#include <tuple>
#include <utility>
#include <vector>
@@ -299,10 +300,12 @@
rtc::Optional<float>(prng->Rand<float>());
}
-class RtcEventLogSessionDescription {
+class RtcEventLogSession
+ : public ::testing::TestWithParam<std::tuple<uint64_t, int64_t>> {
public:
- explicit RtcEventLogSessionDescription(unsigned int random_seed)
- : prng(random_seed) {}
+ RtcEventLogSession()
+ : prng(std::get<0>(GetParam())),
+ output_period_ms(std::get<1>(GetParam())) {}
void GenerateSessionDescription(size_t incoming_rtp_count,
size_t outgoing_rtp_count,
size_t incoming_rtcp_count,
@@ -328,9 +331,10 @@
std::vector<rtclog::StreamConfig> sender_configs;
std::vector<EventType> event_types;
Random prng;
+ int64_t output_period_ms;
};
-void RtcEventLogSessionDescription::GenerateSessionDescription(
+void RtcEventLogSession::GenerateSessionDescription(
size_t incoming_rtp_count,
size_t outgoing_rtp_count,
size_t incoming_rtcp_count,
@@ -403,12 +407,14 @@
}
}
-void RtcEventLogSessionDescription::WriteSession() {
+void RtcEventLogSession::WriteSession() {
// Find the name of the current test, in order to use it as a temporary
// filename.
auto test_info = ::testing::UnitTest::GetInstance()->current_test_info();
+ std::string test_name = test_info->name();
+ std::replace(test_name.begin(), test_name.end(), '/', '_');
const std::string temp_filename =
- test::OutputPath() + test_info->test_case_name() + test_info->name();
+ test::OutputPath() + "RtcEventLogTest_" + test_name;
rtc::ScopedFakeClock fake_clock;
fake_clock.SetTimeMicros(prng.Rand<uint32_t>());
@@ -432,7 +438,8 @@
fake_clock.AdvanceTimeMicros(prng.Rand(1, 1000));
if (i == event_types.size() / 2)
log_dumper->StartLogging(
- rtc::MakeUnique<RtcEventLogOutputFile>(temp_filename, 10000000));
+ rtc::MakeUnique<RtcEventLogOutputFile>(temp_filename, 10000000),
+ output_period_ms);
switch (event_types[i]) {
case EventType::kIncomingRtp:
RTC_CHECK(incoming_rtp_written < incoming_rtp_packets.size());
@@ -516,18 +523,19 @@
// Read the file and verify that what we read back from the event log is the
// same as what we wrote down.
-void RtcEventLogSessionDescription::ReadAndVerifySession() {
+void RtcEventLogSession::ReadAndVerifySession() {
// Find the name of the current test, in order to use it as a temporary
// filename.
auto test_info = ::testing::UnitTest::GetInstance()->current_test_info();
+ std::string test_name = test_info->name();
+ std::replace(test_name.begin(), test_name.end(), '/', '_');
const std::string temp_filename =
- test::OutputPath() + test_info->test_case_name() + test_info->name();
+ test::OutputPath() + "RtcEventLogTest_" + test_name;
// Read the generated file from disk.
ParsedRtcEventLog parsed_log;
ASSERT_TRUE(parsed_log.ParseFile(temp_filename));
- EXPECT_GE(1000u, event_types.size() +
- 2); // The events must fit in the message queue.
+ EXPECT_GE(5000u, event_types.size() + 2); // The events must fit.
EXPECT_EQ(event_types.size() + 2, parsed_log.GetNumberOfEvents());
size_t incoming_rtp_read = 0;
@@ -630,7 +638,7 @@
remove(temp_filename.c_str());
}
-void RtcEventLogSessionDescription::PrintExpectedEvents(std::ostream& stream) {
+void RtcEventLogSession::PrintExpectedEvents(std::ostream& stream) {
for (size_t i = 0; i < event_types.size(); i++) {
auto it = event_type_to_string.find(event_types[i]);
RTC_CHECK(it != event_type_to_string.end());
@@ -649,72 +657,122 @@
stream << std::endl;
}
-TEST(RtcEventLogTest, LogSessionAndReadBack) {
+TEST_P(RtcEventLogSession, LogSessionAndReadBack) {
RtpHeaderExtensionMap extensions;
- RtcEventLogSessionDescription session(321 /*Random seed*/);
- session.GenerateSessionDescription(3, // Number of incoming RTP packets.
- 2, // Number of outgoing RTP packets.
- 1, // Number of incoming RTCP packets.
- 1, // Number of outgoing RTCP packets.
- 0, // Number of playout events.
- 0, // Number of BWE loss events.
- 0, // Number of BWE delay events.
- extensions, // No extensions.
- 0); // Number of contributing sources.
- session.WriteSession();
- session.ReadAndVerifySession();
+ GenerateSessionDescription(3, // Number of incoming RTP packets.
+ 2, // Number of outgoing RTP packets.
+ 1, // Number of incoming RTCP packets.
+ 1, // Number of outgoing RTCP packets.
+ 0, // Number of playout events.
+ 0, // Number of BWE loss events.
+ 0, // Number of BWE delay events.
+ extensions, // No extensions.
+ 0); // Number of contributing sources.
+ WriteSession();
+ ReadAndVerifySession();
}
-TEST(RtcEventLogTest, LogSessionAndReadBackWith2Extensions) {
+TEST_P(RtcEventLogSession, LogSessionAndReadBackWith2Extensions) {
RtpHeaderExtensionMap extensions;
extensions.Register(kRtpExtensionAbsoluteSendTime,
kAbsoluteSendTimeExtensionId);
extensions.Register(kRtpExtensionTransportSequenceNumber,
kTransportSequenceNumberExtensionId);
- RtcEventLogSessionDescription session(3141592653u /*Random seed*/);
- session.GenerateSessionDescription(4, 4, 1, 1, 0, 0, 0, extensions, 0);
- session.WriteSession();
- session.ReadAndVerifySession();
+ GenerateSessionDescription(4, 4, 1, 1, 0, 0, 0, extensions, 0);
+ WriteSession();
+ ReadAndVerifySession();
}
-TEST(RtcEventLogTest, LogSessionAndReadBackWithAllExtensions) {
+TEST_P(RtcEventLogSession, LogSessionAndReadBackWithAllExtensions) {
RtpHeaderExtensionMap extensions;
for (uint32_t i = 0; i < kNumExtensions; i++) {
extensions.Register(kExtensionTypes[i], kExtensionIds[i]);
}
- RtcEventLogSessionDescription session(2718281828u /*Random seed*/);
- session.GenerateSessionDescription(5, 4, 1, 1, 3, 2, 2, extensions, 2);
- session.WriteSession();
- session.ReadAndVerifySession();
+ GenerateSessionDescription(5, 4, 1, 1, 3, 2, 2, extensions, 2);
+ WriteSession();
+ ReadAndVerifySession();
}
-TEST(RtcEventLogTest, LogSessionAndReadBackAllCombinations) {
- // Try all combinations of header extensions and up to 2 CSRCS.
- for (uint32_t extension_selection = 0;
- extension_selection < (1u << kNumExtensions); extension_selection++) {
- RtpHeaderExtensionMap extensions;
- for (uint32_t i = 0; i < kNumExtensions; i++) {
- if (extension_selection & (1u << i)) {
- extensions.Register(kExtensionTypes[i], kExtensionIds[i]);
- }
- }
- for (uint32_t csrcs_count = 0; csrcs_count < 3; csrcs_count++) {
- RtcEventLogSessionDescription session(extension_selection * 3 +
- csrcs_count + 1 /*Random seed*/);
- session.GenerateSessionDescription(
- 2 + extension_selection, // Number of incoming RTP packets.
- 2 + extension_selection, // Number of outgoing RTP packets.
- 1 + csrcs_count, // Number of incoming RTCP packets.
- 1 + csrcs_count, // Number of outgoing RTCP packets.
- 3 + csrcs_count, // Number of playout events.
- 1 + csrcs_count, // Number of BWE loss events.
- 2 + csrcs_count, // Number of BWE delay events.
- extensions, // Bit vector choosing extensions.
- csrcs_count); // Number of contributing sources.
- session.WriteSession();
- session.ReadAndVerifySession();
- }
+TEST_P(RtcEventLogSession, LogLongSessionAndReadBack) {
+ RtpHeaderExtensionMap extensions;
+ for (uint32_t i = 0; i < kNumExtensions; i++) {
+ extensions.Register(kExtensionTypes[i], kExtensionIds[i]);
}
+ GenerateSessionDescription(1000, 1000, 250, 250, 200, 100, 100, extensions,
+ 1);
+ WriteSession();
+ ReadAndVerifySession();
}
+TEST(RtcEventLogTest, CircularBufferKeepsMostRecentEvents) {
+ constexpr size_t kNumEvents = 20000;
+ constexpr int64_t kStartTime = 1000000;
+
+ auto test_info = ::testing::UnitTest::GetInstance()->current_test_info();
+ std::string test_name = test_info->name();
+ std::replace(test_name.begin(), test_name.end(), '/', '_');
+ const std::string temp_filename =
+ test::OutputPath() + "RtcEventLogTest_" + test_name;
+
+ rtc::ScopedFakeClock fake_clock;
+ fake_clock.SetTimeMicros(kStartTime);
+
+ // When log_dumper goes out of scope, it causes the log file to be flushed
+ // to disk.
+ std::unique_ptr<RtcEventLog> log_dumper(
+ RtcEventLog::Create(RtcEventLog::EncodingType::Legacy));
+
+ for (size_t i = 0; i < kNumEvents; i++) {
+ // The purpose of the test is to verify that the log can handle
+ // more events than what fits in the internal circular buffer. The exact
+ // type of events does not matter so we chose AudioPlayouts for simplicity.
+ // We use the index as an ssrc to get a strict relationship between the ssrc
+ // and the timestamp. We use this for some basic consistency checks when we
+ // read back.
+ log_dumper->Log(rtc::MakeUnique<RtcEventAudioPlayout>(i));
+ fake_clock.AdvanceTimeMicros(10000);
+ }
+ log_dumper->StartLogging(
+ rtc::MakeUnique<RtcEventLogOutputFile>(temp_filename, 10000000),
+ RtcEventLog::kImmediateOutput);
+ log_dumper->StopLogging();
+
+ // Read the generated file from disk.
+ ParsedRtcEventLog parsed_log;
+ ASSERT_TRUE(parsed_log.ParseFile(temp_filename));
+ // If the following fails, it probably means that kNumEvents isn't larger
+ // than the size of the cyclic buffer in the event log. Try increasing
+ // kNumEvents.
+ EXPECT_LT(parsed_log.GetNumberOfEvents(), kNumEvents);
+ // We expect a start event, some number of playouts events and a stop event.
+ EXPECT_GT(parsed_log.GetNumberOfEvents(), 2u);
+
+ RtcEventLogTestHelper::VerifyLogStartEvent(parsed_log, 0);
+ rtc::Optional<int64_t> last_timestamp;
+ rtc::Optional<uint32_t> last_ssrc;
+ for (size_t i = 1; i < parsed_log.GetNumberOfEvents() - 1; i++) {
+ EXPECT_EQ(parsed_log.GetEventType(i),
+ ParsedRtcEventLog::EventType::AUDIO_PLAYOUT_EVENT);
+ uint32_t ssrc;
+ parsed_log.GetAudioPlayout(i, &ssrc);
+ int64_t timestamp = parsed_log.GetTimestamp(i);
+ EXPECT_LT(ssrc, kNumEvents);
+ EXPECT_EQ(static_cast<int64_t>(kStartTime + 10000 * ssrc), timestamp);
+ if (last_ssrc)
+ EXPECT_EQ(ssrc, *last_ssrc + 1);
+ if (last_timestamp)
+ EXPECT_EQ(timestamp, *last_timestamp + 10000);
+ last_ssrc = ssrc;
+ last_timestamp = timestamp;
+ }
+ RtcEventLogTestHelper::VerifyLogEndEvent(parsed_log,
+ parsed_log.GetNumberOfEvents() - 1);
+}
+
+INSTANTIATE_TEST_CASE_P(
+ RtcEventLogTest,
+ RtcEventLogSession,
+ ::testing::Combine(::testing::Values(1234567, 7654321),
+ ::testing::Values(RtcEventLog::kImmediateOutput, 1, 5)));
+
} // namespace webrtc
diff --git a/pc/peerconnection.cc b/pc/peerconnection.cc
index 53c891e..e4864c9 100644
--- a/pc/peerconnection.cc
+++ b/pc/peerconnection.cc
@@ -1956,19 +1956,23 @@
? RtcEventLog::kUnlimitedOutput
: rtc::saturated_cast<size_t>(max_size_bytes);
return StartRtcEventLog(
- rtc::MakeUnique<RtcEventLogOutputFile>(file, max_size));
+ rtc::MakeUnique<RtcEventLogOutputFile>(file, max_size),
+ webrtc::RtcEventLog::kImmediateOutput);
}
-bool PeerConnection::StartRtcEventLog(
- std::unique_ptr<RtcEventLogOutput> output) {
+bool PeerConnection::StartRtcEventLog(std::unique_ptr<RtcEventLogOutput> output,
+ int64_t output_period_ms) {
// TODO(eladalon): In C++14, this can be done with a lambda.
struct Functor {
- bool operator()() { return pc->StartRtcEventLog_w(std::move(output)); }
+ bool operator()() {
+ return pc->StartRtcEventLog_w(std::move(output), output_period_ms);
+ }
PeerConnection* const pc;
std::unique_ptr<RtcEventLogOutput> output;
+ const int64_t output_period_ms;
};
- return worker_thread()->Invoke<bool>(RTC_FROM_HERE,
- Functor{this, std::move(output)});
+ return worker_thread()->Invoke<bool>(
+ RTC_FROM_HERE, Functor{this, std::move(output), output_period_ms});
}
void PeerConnection::StopRtcEventLog() {
@@ -3203,11 +3207,12 @@
}
bool PeerConnection::StartRtcEventLog_w(
- std::unique_ptr<RtcEventLogOutput> output) {
+ std::unique_ptr<RtcEventLogOutput> output,
+ int64_t output_period_ms) {
if (!event_log_) {
return false;
}
- return event_log_->StartLogging(std::move(output));
+ return event_log_->StartLogging(std::move(output), output_period_ms);
}
void PeerConnection::StopRtcEventLog_w() {
diff --git a/pc/peerconnection.h b/pc/peerconnection.h
index 0b00588..2b36a86 100644
--- a/pc/peerconnection.h
+++ b/pc/peerconnection.h
@@ -177,7 +177,8 @@
RTC_DEPRECATED bool StartRtcEventLog(rtc::PlatformFile file,
int64_t max_size_bytes) override;
- bool StartRtcEventLog(std::unique_ptr<RtcEventLogOutput> output) override;
+ bool StartRtcEventLog(std::unique_ptr<RtcEventLogOutput> output,
+ int64_t output_period_ms) override;
void StopRtcEventLog() override;
void Close() override;
@@ -505,7 +506,8 @@
// Starts output of an RTC event log to the given output object.
// This function should only be called from the worker thread.
- bool StartRtcEventLog_w(std::unique_ptr<RtcEventLogOutput> output);
+ bool StartRtcEventLog_w(std::unique_ptr<RtcEventLogOutput> output,
+ int64_t output_period_ms);
// Stops recording an RTC event log.
// This function should only be called from the worker thread.
diff --git a/pc/peerconnection_integrationtest.cc b/pc/peerconnection_integrationtest.cc
index 2fc471c..90aad09 100644
--- a/pc/peerconnection_integrationtest.cc
+++ b/pc/peerconnection_integrationtest.cc
@@ -3521,7 +3521,8 @@
ON_CALL(*output, IsActive()).WillByDefault(testing::Return(true));
ON_CALL(*output, Write(::testing::_)).WillByDefault(testing::Return(true));
EXPECT_CALL(*output, Write(::testing::_)).Times(::testing::AtLeast(1));
- EXPECT_TRUE(caller()->pc()->StartRtcEventLog(std::move(output)));
+ EXPECT_TRUE(caller()->pc()->StartRtcEventLog(
+ std::move(output), webrtc::RtcEventLog::kImmediateOutput));
caller()->AddAudioVideoMediaStream();
caller()->CreateAndSetAndSignalOffer();
diff --git a/pc/peerconnectioninterface_unittest.cc b/pc/peerconnectioninterface_unittest.cc
index b0423a3..409fa91 100644
--- a/pc/peerconnectioninterface_unittest.cc
+++ b/pc/peerconnectioninterface_unittest.cc
@@ -3246,7 +3246,8 @@
rtc::PlatformFile file = 0;
int64_t max_size_bytes = 1024;
EXPECT_FALSE(pc_->StartRtcEventLog(
- rtc::MakeUnique<webrtc::RtcEventLogOutputFile>(file, max_size_bytes)));
+ rtc::MakeUnique<webrtc::RtcEventLogOutputFile>(file, max_size_bytes),
+ webrtc::RtcEventLog::kImmediateOutput));
pc_->StopRtcEventLog();
}
diff --git a/video/video_quality_test.cc b/video/video_quality_test.cc
index 198b73c..512a9bb 100644
--- a/video/video_quality_test.cc
+++ b/video/video_quality_test.cc
@@ -1800,9 +1800,11 @@
if (!params.logging.rtc_event_log_name.empty()) {
event_log_ = RtcEventLog::Create(clock_, RtcEventLog::EncodingType::Legacy);
- bool event_log_started =
- event_log_->StartLogging(rtc::MakeUnique<RtcEventLogOutputFile>(
+ std::unique_ptr<RtcEventLogOutputFile> output(
+ rtc::MakeUnique<RtcEventLogOutputFile>(
params.logging.rtc_event_log_name, RtcEventLog::kUnlimitedOutput));
+ bool event_log_started = event_log_->StartLogging(
+ std::move(output), RtcEventLog::kImmediateOutput);
RTC_DCHECK(event_log_started);
}
diff --git a/voice_engine/channel.cc b/voice_engine/channel.cc
index c870ece..20dc87f 100644
--- a/voice_engine/channel.cc
+++ b/voice_engine/channel.cc
@@ -65,7 +65,8 @@
public:
RtcEventLogProxy() : event_log_(nullptr) {}
- bool StartLogging(std::unique_ptr<RtcEventLogOutput> output) override {
+ bool StartLogging(std::unique_ptr<RtcEventLogOutput> output,
+ int64_t output_period_ms) override {
RTC_NOTREACHED();
return false;
}
