admin/webrtc_m130
1
0
Fork 0
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity

Old config events are no longer removed from RtcEventLog.

Browse Source 
Time to keep old events in buffer is now changeable at runtime.
Added unit test for removing old events from buffer.

Review URL: https://codereview.webrtc.org/1303713002

Cr-Commit-Position: refs/heads/master@{#10302}
This commit is contained in:
terelius 2015-10-16 08:51:08 -07:00 committed by Commit bot
parent 6a14b9db19
commit 1adce14c87
3 changed files with 157 additions and 24 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

73
webrtc/call/rtc_event_log.cc
View File

@ -11,6 +11,7 @@
#include "webrtc/call/rtc_event_log.h"
#include <deque>
#include <vector>
#include "webrtc/base/checks.h"
#include "webrtc/base/criticalsection.h"
@ -36,6 +37,7 @@ namespace webrtc {
// No-op implementation if flag is not set.
class RtcEventLogImpl final : public RtcEventLog {
public:
void SetBufferDuration(int64_t buffer_duration_us) override {}
void StartLogging(const std::string& file_name, int duration_ms) override {}
bool StartLogging(rtc::PlatformFile log_file) override { return false; }
void StopLogging(void) override {}
@ -58,6 +60,9 @@ class RtcEventLogImpl final : public RtcEventLog {
class RtcEventLogImpl final : public RtcEventLog {
public:
RtcEventLogImpl();
void SetBufferDuration(int64_t buffer_duration_us) override;
void StartLogging(const std::string& file_name, int duration_ms) override;
bool StartLogging(rtc::PlatformFile log_file) override;
void StopLogging() override;
@ -91,10 +96,6 @@ class RtcEventLogImpl final : public RtcEventLog {
void AddRecentEvent(const rtclog::Event& event)
EXCLUSIVE_LOCKS_REQUIRED(crit_);
// Amount of time in microseconds to record log events, before starting the
// actual log.
const int recent_log_duration_us = 10000000;
rtc::CriticalSection crit_;
rtc::scoped_ptr<FileWrapper> file_ GUARDED_BY(crit_) =
rtc::scoped_ptr<FileWrapper>(FileWrapper::Create());
@ -102,10 +103,14 @@ class RtcEventLogImpl final : public RtcEventLog {
rtc::kInvalidPlatformFileValue;
rtclog::EventStream stream_ GUARDED_BY(crit_);
std::deque<rtclog::Event> recent_log_events_ GUARDED_BY(crit_);
bool currently_logging_ GUARDED_BY(crit_) = false;
int64_t start_time_us_ GUARDED_BY(crit_) = 0;
int64_t duration_us_ GUARDED_BY(crit_) = 0;
const Clock* const clock_ = Clock::GetRealTimeClock();
std::vector<rtclog::Event> config_events_ GUARDED_BY(crit_);
// Microseconds to record log events, before starting the actual log.
int64_t buffer_duration_us_ GUARDED_BY(crit_);
bool currently_logging_ GUARDED_BY(crit_);
int64_t start_time_us_ GUARDED_BY(crit_);
int64_t duration_us_ GUARDED_BY(crit_);
const Clock* const clock_;
};
namespace {
@ -148,7 +153,31 @@ rtclog::MediaType ConvertMediaType(MediaType media_type) {
} // namespace
namespace {
bool IsConfigEvent(const rtclog::Event& event) {
rtclog::Event_EventType event_type = event.type();
return event_type == rtclog::Event::VIDEO_RECEIVER_CONFIG_EVENT ||
event_type == rtclog::Event::VIDEO_SENDER_CONFIG_EVENT ||
event_type == rtclog::Event::AUDIO_RECEIVER_CONFIG_EVENT ||
event_type == rtclog::Event::AUDIO_SENDER_CONFIG_EVENT;
}
} // namespace
// RtcEventLogImpl member functions.
RtcEventLogImpl::RtcEventLogImpl()
: file_(FileWrapper::Create()),
stream_(),
buffer_duration_us_(10000000),
currently_logging_(false),
start_time_us_(0),
duration_us_(0),
clock_(Clock::GetRealTimeClock()) {
}
void RtcEventLogImpl::SetBufferDuration(int64_t buffer_duration_us) {
rtc::CritScope lock(&crit_);
buffer_duration_us_ = buffer_duration_us;
}
void RtcEventLogImpl::StartLogging(const std::string& file_name,
int duration_ms) {
@ -192,9 +221,18 @@ bool RtcEventLogImpl::StartLogging(rtc::PlatformFile log_file) {
void RtcEventLogImpl::StartLoggingLocked() {
currently_logging_ = true;
// Write all the recent events to the log file, ignoring any old events.
// Write all old configuration events to the log file.
for (auto& event : config_events_) {
StoreToFile(&event);
}
// Write all recent configuration events to the log file, and
// write all other recent events to the log file, ignoring any old events.
for (auto& event : recent_log_events_) {
if (event.timestamp_us() >= start_time_us_ - recent_log_duration_us) {
if (IsConfigEvent(event)) {
StoreToFile(&event);
config_events_.push_back(event);
} else if (event.timestamp_us() >= start_time_us_ - buffer_duration_us_) {
StoreToFile(&event);
}
}
@ -250,10 +288,6 @@ void RtcEventLogImpl::LogVideoReceiveStreamConfig(
decoder->set_name(d.payload_name);
decoder->set_payload_type(d.payload_type);
}
// TODO(terelius): We should use a separate event queue for config events.
// The current approach of storing the configuration together with the
// RTP events causes the configuration information to be removed 10s
// after the ReceiveStream is created.
HandleEvent(&event);
}
@ -289,11 +323,6 @@ void RtcEventLogImpl::LogVideoSendStreamConfig(
rtclog::EncoderConfig* encoder = sender_config->mutable_encoder();
encoder->set_name(config.encoder_settings.payload_name);
encoder->set_payload_type(config.encoder_settings.payload_type);
// TODO(terelius): We should use a separate event queue for config events.
// The current approach of storing the configuration together with the
// RTP events causes the configuration information to be removed 10s
// after the ReceiveStream is created.
HandleEvent(&event);
}
@ -404,7 +433,10 @@ void RtcEventLogImpl::StoreToFile(rtclog::Event* event) {
void RtcEventLogImpl::AddRecentEvent(const rtclog::Event& event) {
recent_log_events_.push_back(event);
while (recent_log_events_.front().timestamp_us() <
event.timestamp_us() - recent_log_duration_us) {
event.timestamp_us() - buffer_duration_us_) {
if (IsConfigEvent(recent_log_events_.front())) {
config_events_.push_back(recent_log_events_.front());
}
recent_log_events_.pop_front();
}
}
@ -431,4 +463,5 @@ bool RtcEventLog::ParseRtcEventLog(const std::string& file_name,
rtc::scoped_ptr<RtcEventLog> RtcEventLog::Create() {
return rtc::scoped_ptr<RtcEventLog>(new RtcEventLogImpl());
}
} // namespace webrtc

4
webrtc/call/rtc_event_log.h
View File

@ -36,6 +36,10 @@ class RtcEventLog {
static rtc::scoped_ptr<RtcEventLog> Create();
// Sets the time that events are stored in the internal event buffer
// before the user calls StartLogging. The default is 10 000 000 us = 10 s
virtual void SetBufferDuration(int64_t buffer_duration_us) = 0;
// Starts logging for the specified duration to the specified file.
// The logging will stop automatically after the specified duration.
// If the file already exists it will be overwritten.

104
webrtc/call/rtc_event_log_unittest.cc
View File

@ -18,6 +18,7 @@
#include "webrtc/base/buffer.h"
#include "webrtc/base/checks.h"
#include "webrtc/base/scoped_ptr.h"
#include "webrtc/base/thread.h"
#include "webrtc/call.h"
#include "webrtc/call/rtc_event_log.h"
#include "webrtc/modules/rtp_rtcp/source/rtp_sender.h"
@ -392,14 +393,14 @@ void GenerateVideoSendConfig(uint32_t extensions_bitvector,
}
}
// Test for the RtcEventLog class. Dumps some RTP packets to disk, then reads
// them back to see if they match.
// Test for the RtcEventLog class. Dumps some RTP packets and other events
// to disk, then reads them back to see if they match.
void LogSessionAndReadBack(size_t rtp_count,
size_t rtcp_count,
size_t playout_count,
uint32_t extensions_bitvector,
uint32_t csrcs_count,
unsigned random_seed) {
unsigned int random_seed) {
ASSERT_LE(rtcp_count, rtp_count);
ASSERT_LE(playout_count, rtp_count);
std::vector<rtc::Buffer> rtp_packets;
@ -476,7 +477,9 @@ void LogSessionAndReadBack(size_t rtp_count,
ASSERT_TRUE(RtcEventLog::ParseRtcEventLog(temp_filename, &parsed_stream));
// Verify the result.
// Verify that what we read back from the event log is the same as
// what we wrote down. For RTCP we log the full packets, but for
// RTP we should only log the header.
const int event_count =
config_count + playout_count + rtcp_count + rtp_count + 1;
EXPECT_EQ(event_count, parsed_stream.stream_size());
@ -546,6 +549,99 @@ TEST(RtcEventLogTest, LogSessionAndReadBack) {
}
}
// Tests that the event queue works correctly, i.e. drops old RTP, RTCP and
// debug events, but keeps config events even if they are older than the limit.
void DropOldEvents(uint32_t extensions_bitvector,
uint32_t csrcs_count,
unsigned int random_seed) {
rtc::Buffer old_rtp_packet;
rtc::Buffer recent_rtp_packet;
rtc::Buffer old_rtcp_packet;
rtc::Buffer recent_rtcp_packet;
VideoReceiveStream::Config receiver_config(nullptr);
VideoSendStream::Config sender_config(nullptr);
srand(random_seed);
// Create two RTP packets containing random data.
size_t packet_size = 1000 + rand() % 64;
old_rtp_packet.SetSize(packet_size);
GenerateRtpPacket(extensions_bitvector, csrcs_count, old_rtp_packet.data(),
packet_size);
packet_size = 1000 + rand() % 64;
recent_rtp_packet.SetSize(packet_size);
size_t recent_header_size = GenerateRtpPacket(
extensions_bitvector, csrcs_count, recent_rtp_packet.data(), packet_size);
// Create two RTCP packets containing random data.
packet_size = 1000 + rand() % 64;
old_rtcp_packet.SetSize(packet_size);
GenerateRtcpPacket(old_rtcp_packet.data(), packet_size);
packet_size = 1000 + rand() % 64;
recent_rtcp_packet.SetSize(packet_size);
GenerateRtcpPacket(recent_rtcp_packet.data(), packet_size);
// Create configurations for the video streams.
GenerateVideoReceiveConfig(extensions_bitvector, &receiver_config);
GenerateVideoSendConfig(extensions_bitvector, &sender_config);
// 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();
const std::string temp_filename =
test::OutputPath() + test_info->test_case_name() + test_info->name();
// The log file will be flushed to disk when the log_dumper goes out of scope.
{
rtc::scoped_ptr<RtcEventLog> log_dumper(RtcEventLog::Create());
// Reduce the time old events are stored to 50 ms.
log_dumper->SetBufferDuration(50000);
log_dumper->LogVideoReceiveStreamConfig(receiver_config);
log_dumper->LogVideoSendStreamConfig(sender_config);
log_dumper->LogRtpHeader(false, MediaType::AUDIO, old_rtp_packet.data(),
old_rtp_packet.size());
log_dumper->LogRtcpPacket(true, MediaType::AUDIO, old_rtcp_packet.data(),
old_rtcp_packet.size());
// Sleep 55 ms to let old events be removed from the queue.
rtc::Thread::SleepMs(55);
log_dumper->StartLogging(temp_filename, 10000000);
log_dumper->LogRtpHeader(true, MediaType::VIDEO, recent_rtp_packet.data(),
recent_rtp_packet.size());
log_dumper->LogRtcpPacket(false, MediaType::VIDEO,
recent_rtcp_packet.data(),
recent_rtcp_packet.size());
}
// Read the generated file from disk.
rtclog::EventStream parsed_stream;
ASSERT_TRUE(RtcEventLog::ParseRtcEventLog(temp_filename, &parsed_stream));
// Verify that what we read back from the event log is the same as
// what we wrote. Old RTP and RTCP events should have been discarded,
// but old configuration events should still be available.
EXPECT_EQ(5, parsed_stream.stream_size());
VerifyReceiveStreamConfig(parsed_stream.stream(0), receiver_config);
VerifySendStreamConfig(parsed_stream.stream(1), sender_config);
VerifyLogStartEvent(parsed_stream.stream(2));
VerifyRtpEvent(parsed_stream.stream(3), true, MediaType::VIDEO,
recent_rtp_packet.data(), recent_header_size,
recent_rtp_packet.size());
VerifyRtcpEvent(parsed_stream.stream(4), false, MediaType::VIDEO,
recent_rtcp_packet.data(), recent_rtcp_packet.size());
// Clean up temporary file - can be pretty slow.
remove(temp_filename.c_str());
}
TEST(RtcEventLogTest, DropOldEvents) {
// Enable all header extensions
uint32_t extensions = (1u << kNumExtensions) - 1;
uint32_t csrcs_count = 2;
DropOldEvents(extensions, csrcs_count, 141421356);
DropOldEvents(extensions, csrcs_count, 173205080);
}
} // namespace webrtc
#endif // ENABLE_RTC_EVENT_LOG