2015-07-30 12:45:18 +02:00
|
|
|
/*
|
|
|
|
|
* Copyright (c) 2015 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.
|
|
|
|
|
*/
|
|
|
|
|
|
Moved RtcEventLog files from call/ to logging/
The RtcEventLog headers need to be accessible from any place which needs
logging, and the implementation needs access to data structures that are
logged.
After a discussion in the code review, we all agreed to move the RtcEventLog implementation into its own top level directory - which I called "logging/" in expectation that other types of logging may have similar requirements. The directory contains two main build targets - "rtc_event_log_api", which is just rtc_event_log.h, that has no external dependencies and can be used from anywhere, and "rtc_event_log_impl" which contains the rest of the implementation and has many dependencies (more in the future).
The "api" target can be referenced from anywhere, while the "impl" target is only needed at the place of instantiation (currently Call, soon to be moved to PeerConnection by https://codereview.webrtc.org/2353033005/).
This change allows using RtcEventLog in the p2p/ directory, so that we
can log STUN pings and ICE state transitions.
BUG=webrtc:6393
R=kjellander@webrtc.org, kwiberg@webrtc.org, solenberg@webrtc.org, stefan@webrtc.org, terelius@webrtc.org
Review URL: https://codereview.webrtc.org/2380683005 .
Cr-Commit-Position: refs/heads/master@{#14485}
2016-10-03 18:31:22 -07:00
|
|
|
#include "webrtc/logging/rtc_event_log/rtc_event_log.h"
|
2015-07-30 12:45:18 +02:00
|
|
|
|
2017-09-06 05:18:15 -07:00
|
|
|
#include <atomic>
|
|
|
|
|
#include <deque>
|
|
|
|
|
#include <functional>
|
2016-04-22 12:40:37 -07:00
|
|
|
#include <limits>
|
2017-09-06 05:18:15 -07:00
|
|
|
#include <memory>
|
2017-07-16 16:44:08 -07:00
|
|
|
#include <utility>
|
2015-10-16 08:51:08 -07:00
|
|
|
#include <vector>
|
2015-07-30 12:45:18 +02:00
|
|
|
|
2017-04-06 05:59:10 -07:00
|
|
|
#include "webrtc/modules/audio_coding/audio_network_adaptor/include/audio_network_adaptor.h"
|
2017-04-11 00:49:44 -07:00
|
|
|
#include "webrtc/modules/remote_bitrate_estimator/include/bwe_defines.h"
|
2015-11-06 09:00:18 -08:00
|
|
|
#include "webrtc/modules/rtp_rtcp/include/rtp_rtcp_defines.h"
|
2015-09-04 03:39:42 -07:00
|
|
|
#include "webrtc/modules/rtp_rtcp/source/byte_io.h"
|
2016-10-07 07:39:54 -07:00
|
|
|
#include "webrtc/modules/rtp_rtcp/source/rtcp_packet/app.h"
|
|
|
|
|
#include "webrtc/modules/rtp_rtcp/source/rtcp_packet/bye.h"
|
|
|
|
|
#include "webrtc/modules/rtp_rtcp/source/rtcp_packet/common_header.h"
|
|
|
|
|
#include "webrtc/modules/rtp_rtcp/source/rtcp_packet/extended_jitter_report.h"
|
|
|
|
|
#include "webrtc/modules/rtp_rtcp/source/rtcp_packet/extended_reports.h"
|
|
|
|
|
#include "webrtc/modules/rtp_rtcp/source/rtcp_packet/psfb.h"
|
2017-04-06 05:59:10 -07:00
|
|
|
#include "webrtc/modules/rtp_rtcp/source/rtcp_packet/receiver_report.h"
|
2016-10-07 07:39:54 -07:00
|
|
|
#include "webrtc/modules/rtp_rtcp/source/rtcp_packet/rtpfb.h"
|
|
|
|
|
#include "webrtc/modules/rtp_rtcp/source/rtcp_packet/sdes.h"
|
|
|
|
|
#include "webrtc/modules/rtp_rtcp/source/rtcp_packet/sender_report.h"
|
2017-07-06 19:44:34 +02:00
|
|
|
#include "webrtc/rtc_base/checks.h"
|
|
|
|
|
#include "webrtc/rtc_base/constructormagic.h"
|
|
|
|
|
#include "webrtc/rtc_base/event.h"
|
2017-09-06 05:18:15 -07:00
|
|
|
#include "webrtc/rtc_base/ignore_wundef.h"
|
2017-07-06 19:44:34 +02:00
|
|
|
#include "webrtc/rtc_base/logging.h"
|
|
|
|
|
#include "webrtc/rtc_base/protobuf_utils.h"
|
2017-09-06 05:18:15 -07:00
|
|
|
#include "webrtc/rtc_base/ptr_util.h"
|
|
|
|
|
#include "webrtc/rtc_base/sequenced_task_checker.h"
|
|
|
|
|
#include "webrtc/rtc_base/task_queue.h"
|
|
|
|
|
#include "webrtc/rtc_base/thread_annotations.h"
|
2017-07-06 19:44:34 +02:00
|
|
|
#include "webrtc/rtc_base/timeutils.h"
|
2015-10-28 18:17:40 +01:00
|
|
|
#include "webrtc/system_wrappers/include/file_wrapper.h"
|
2017-09-06 05:18:15 -07:00
|
|
|
#include "webrtc/typedefs.h"
|
2015-07-30 12:45:18 +02:00
|
|
|
|
|
|
|
|
#ifdef ENABLE_RTC_EVENT_LOG
|
2017-04-07 00:59:12 -07:00
|
|
|
// *.pb.h files are generated at build-time by the protobuf compiler.
|
2017-09-06 05:18:15 -07:00
|
|
|
RTC_PUSH_IGNORING_WUNDEF()
|
2015-07-30 12:45:18 +02:00
|
|
|
#ifdef WEBRTC_ANDROID_PLATFORM_BUILD
|
Moved RtcEventLog files from call/ to logging/
The RtcEventLog headers need to be accessible from any place which needs
logging, and the implementation needs access to data structures that are
logged.
After a discussion in the code review, we all agreed to move the RtcEventLog implementation into its own top level directory - which I called "logging/" in expectation that other types of logging may have similar requirements. The directory contains two main build targets - "rtc_event_log_api", which is just rtc_event_log.h, that has no external dependencies and can be used from anywhere, and "rtc_event_log_impl" which contains the rest of the implementation and has many dependencies (more in the future).
The "api" target can be referenced from anywhere, while the "impl" target is only needed at the place of instantiation (currently Call, soon to be moved to PeerConnection by https://codereview.webrtc.org/2353033005/).
This change allows using RtcEventLog in the p2p/ directory, so that we
can log STUN pings and ICE state transitions.
BUG=webrtc:6393
R=kjellander@webrtc.org, kwiberg@webrtc.org, solenberg@webrtc.org, stefan@webrtc.org, terelius@webrtc.org
Review URL: https://codereview.webrtc.org/2380683005 .
Cr-Commit-Position: refs/heads/master@{#14485}
2016-10-03 18:31:22 -07:00
|
|
|
#include "external/webrtc/webrtc/logging/rtc_event_log/rtc_event_log.pb.h"
|
2015-07-30 12:45:18 +02:00
|
|
|
#else
|
Moved RtcEventLog files from call/ to logging/
The RtcEventLog headers need to be accessible from any place which needs
logging, and the implementation needs access to data structures that are
logged.
After a discussion in the code review, we all agreed to move the RtcEventLog implementation into its own top level directory - which I called "logging/" in expectation that other types of logging may have similar requirements. The directory contains two main build targets - "rtc_event_log_api", which is just rtc_event_log.h, that has no external dependencies and can be used from anywhere, and "rtc_event_log_impl" which contains the rest of the implementation and has many dependencies (more in the future).
The "api" target can be referenced from anywhere, while the "impl" target is only needed at the place of instantiation (currently Call, soon to be moved to PeerConnection by https://codereview.webrtc.org/2353033005/).
This change allows using RtcEventLog in the p2p/ directory, so that we
can log STUN pings and ICE state transitions.
BUG=webrtc:6393
R=kjellander@webrtc.org, kwiberg@webrtc.org, solenberg@webrtc.org, stefan@webrtc.org, terelius@webrtc.org
Review URL: https://codereview.webrtc.org/2380683005 .
Cr-Commit-Position: refs/heads/master@{#14485}
2016-10-03 18:31:22 -07:00
|
|
|
#include "webrtc/logging/rtc_event_log/rtc_event_log.pb.h"
|
2015-07-30 12:45:18 +02:00
|
|
|
#endif
|
2017-09-06 05:18:15 -07:00
|
|
|
RTC_POP_IGNORING_WUNDEF()
|
2015-07-30 12:45:18 +02:00
|
|
|
#endif
|
|
|
|
|
|
|
|
|
|
namespace webrtc {
|
|
|
|
|
|
2016-07-04 07:06:55 -07:00
|
|
|
#ifdef ENABLE_RTC_EVENT_LOG
|
2015-07-30 12:45:18 +02:00
|
|
|
|
2017-09-06 05:18:15 -07:00
|
|
|
namespace {
|
|
|
|
|
const int kEventsInHistory = 10000;
|
|
|
|
|
|
|
|
|
|
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;
|
|
|
|
|
}
|
|
|
|
|
|
|
|
|
|
// TODO(eladalon): This class exists because C++11 doesn't allow transferring a
|
|
|
|
|
// unique_ptr to a lambda (a copy constructor is required). We should get
|
|
|
|
|
// rid of this when we move to C++14.
|
|
|
|
|
template <typename T>
|
|
|
|
|
class ResourceOwningTask final : public rtc::QueuedTask {
|
|
|
|
|
public:
|
|
|
|
|
ResourceOwningTask(std::unique_ptr<T> resource,
|
|
|
|
|
std::function<void(std::unique_ptr<T>)> handler)
|
|
|
|
|
: resource_(std::move(resource)), handler_(handler) {}
|
|
|
|
|
|
|
|
|
|
bool Run() override {
|
|
|
|
|
handler_(std::move(resource_));
|
|
|
|
|
return true;
|
|
|
|
|
}
|
|
|
|
|
|
|
|
|
|
private:
|
|
|
|
|
std::unique_ptr<T> resource_;
|
|
|
|
|
std::function<void(std::unique_ptr<T>)> handler_;
|
|
|
|
|
};
|
|
|
|
|
} // namespace
|
|
|
|
|
|
2015-07-30 12:45:18 +02:00
|
|
|
class RtcEventLogImpl final : public RtcEventLog {
|
2017-06-28 06:40:51 -07:00
|
|
|
friend std::unique_ptr<RtcEventLog> RtcEventLog::Create();
|
|
|
|
|
|
2015-07-30 12:45:18 +02:00
|
|
|
public:
|
2016-04-22 12:40:37 -07:00
|
|
|
~RtcEventLogImpl() override;
|
2015-10-16 08:51:08 -07:00
|
|
|
|
2016-04-22 12:40:37 -07:00
|
|
|
bool StartLogging(const std::string& file_name,
|
|
|
|
|
int64_t max_size_bytes) override;
|
|
|
|
|
bool StartLogging(rtc::PlatformFile platform_file,
|
|
|
|
|
int64_t max_size_bytes) override;
|
2015-07-30 12:45:18 +02:00
|
|
|
void StopLogging() override;
|
2017-05-22 03:26:49 -07:00
|
|
|
void LogVideoReceiveStreamConfig(const rtclog::StreamConfig& config) override;
|
2017-05-22 04:08:28 -07:00
|
|
|
void LogVideoSendStreamConfig(const rtclog::StreamConfig& config) override;
|
2017-05-22 09:36:28 -07:00
|
|
|
void LogAudioReceiveStreamConfig(const rtclog::StreamConfig& config) override;
|
2017-05-22 10:12:26 -07:00
|
|
|
void LogAudioSendStreamConfig(const rtclog::StreamConfig& config) override;
|
2016-01-21 05:42:04 -08:00
|
|
|
void LogRtpHeader(PacketDirection direction,
|
2015-07-30 12:45:18 +02:00
|
|
|
const uint8_t* header,
|
2015-09-04 03:39:42 -07:00
|
|
|
size_t packet_length) override;
|
2017-02-27 02:18:46 -08:00
|
|
|
void LogRtpHeader(PacketDirection direction,
|
|
|
|
|
const uint8_t* header,
|
|
|
|
|
size_t packet_length,
|
|
|
|
|
int probe_cluster_id) override;
|
2016-01-21 05:42:04 -08:00
|
|
|
void LogRtcpPacket(PacketDirection direction,
|
2015-07-30 12:45:18 +02:00
|
|
|
const uint8_t* packet,
|
|
|
|
|
size_t length) override;
|
2015-09-17 16:30:16 +02:00
|
|
|
void LogAudioPlayout(uint32_t ssrc) override;
|
2017-02-20 05:14:41 -08:00
|
|
|
void LogLossBasedBweUpdate(int32_t bitrate_bps,
|
2015-11-05 12:02:15 -08:00
|
|
|
uint8_t fraction_loss,
|
|
|
|
|
int32_t total_packets) override;
|
2017-02-20 05:14:41 -08:00
|
|
|
void LogDelayBasedBweUpdate(int32_t bitrate_bps,
|
2017-02-17 03:38:28 -08:00
|
|
|
BandwidthUsage detector_state) override;
|
2017-01-24 04:54:59 -08:00
|
|
|
void LogAudioNetworkAdaptation(
|
2017-04-06 05:59:10 -07:00
|
|
|
const AudioEncoderRuntimeConfig& config) override;
|
2017-02-27 02:18:46 -08:00
|
|
|
void LogProbeClusterCreated(int id,
|
|
|
|
|
int bitrate_bps,
|
|
|
|
|
int min_probes,
|
|
|
|
|
int min_bytes) override;
|
|
|
|
|
void LogProbeResultSuccess(int id, int bitrate_bps) override;
|
|
|
|
|
void LogProbeResultFailure(int id,
|
|
|
|
|
ProbeFailureReason failure_reason) override;
|
2015-07-30 12:45:18 +02:00
|
|
|
|
|
|
|
|
private:
|
2017-09-06 05:18:15 -07:00
|
|
|
void StartLoggingInternal(std::unique_ptr<FileWrapper> file,
|
|
|
|
|
int64_t max_size_bytes);
|
|
|
|
|
|
|
|
|
|
RtcEventLogImpl(); // Creation is done by RtcEventLog::Create.
|
2017-06-28 06:40:51 -07:00
|
|
|
|
2017-07-16 16:44:08 -07:00
|
|
|
void StoreEvent(std::unique_ptr<rtclog::Event> event);
|
2017-02-27 02:18:46 -08:00
|
|
|
void LogProbeResult(int id,
|
|
|
|
|
rtclog::BweProbeResult::ResultType result,
|
|
|
|
|
int bitrate_bps);
|
2016-06-08 07:20:29 -07:00
|
|
|
|
2017-09-06 05:18:15 -07:00
|
|
|
// Appends an event to the output protobuf string, returning true on success.
|
|
|
|
|
// Fails and returns false in case the limit on output size prevents the
|
|
|
|
|
// event from being added; in this case, the output string is left unchanged.
|
|
|
|
|
bool AppendEventToString(rtclog::Event* event,
|
|
|
|
|
ProtoString* output_string) RTC_WARN_UNUSED_RESULT;
|
2017-06-28 06:40:51 -07:00
|
|
|
|
2017-09-06 05:18:15 -07:00
|
|
|
void LogToMemory(std::unique_ptr<rtclog::Event> event);
|
2016-04-22 12:40:37 -07:00
|
|
|
|
2017-09-06 05:18:15 -07:00
|
|
|
void StartLogFile();
|
|
|
|
|
void LogToFile(std::unique_ptr<rtclog::Event> event);
|
|
|
|
|
void StopLogFile(int64_t stop_time);
|
2016-04-22 12:40:37 -07:00
|
|
|
|
2017-09-06 05:18:15 -07:00
|
|
|
// Observe a limit on the number of concurrent logs, so as not to run into
|
|
|
|
|
// OS-imposed limits on open files and/or threads/task-queues.
|
|
|
|
|
// TODO(eladalon): Known issue - there's a race over |log_count_|.
|
|
|
|
|
static std::atomic<int> log_count_;
|
|
|
|
|
|
|
|
|
|
// 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_;
|
|
|
|
|
|
|
|
|
|
// History containing all past configuration events.
|
|
|
|
|
std::vector<std::unique_ptr<rtclog::Event>> config_history_
|
|
|
|
|
ACCESS_ON(task_queue_);
|
|
|
|
|
|
|
|
|
|
// History containing the most recent (non-configuration) events (~10s).
|
|
|
|
|
std::deque<std::unique_ptr<rtclog::Event>> history_ ACCESS_ON(task_queue_);
|
|
|
|
|
|
|
|
|
|
std::unique_ptr<FileWrapper> file_ ACCESS_ON(task_queue_);
|
|
|
|
|
|
|
|
|
|
size_t max_size_bytes_ ACCESS_ON(task_queue_);
|
|
|
|
|
size_t written_bytes_ 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.
|
|
|
|
|
rtc::TaskQueue task_queue_;
|
2016-04-22 12:40:37 -07:00
|
|
|
|
2016-12-20 05:03:58 -08:00
|
|
|
RTC_DISALLOW_COPY_AND_ASSIGN(RtcEventLogImpl);
|
2015-07-30 12:45:18 +02:00
|
|
|
};
|
|
|
|
|
|
|
|
|
|
namespace {
|
|
|
|
|
// The functions in this namespace convert enums from the runtime format
|
|
|
|
|
// that the rest of the WebRtc project can use, to the corresponding
|
|
|
|
|
// serialized enum which is defined by the protobuf.
|
|
|
|
|
|
2015-10-02 02:36:56 -07:00
|
|
|
rtclog::VideoReceiveConfig_RtcpMode ConvertRtcpMode(RtcpMode rtcp_mode) {
|
2015-07-30 12:45:18 +02:00
|
|
|
switch (rtcp_mode) {
|
2015-10-02 02:36:56 -07:00
|
|
|
case RtcpMode::kCompound:
|
2015-07-30 12:45:18 +02:00
|
|
|
return rtclog::VideoReceiveConfig::RTCP_COMPOUND;
|
2015-10-02 02:36:56 -07:00
|
|
|
case RtcpMode::kReducedSize:
|
2015-07-30 12:45:18 +02:00
|
|
|
return rtclog::VideoReceiveConfig::RTCP_REDUCEDSIZE;
|
2015-10-02 02:36:56 -07:00
|
|
|
case RtcpMode::kOff:
|
|
|
|
|
RTC_NOTREACHED();
|
|
|
|
|
return rtclog::VideoReceiveConfig::RTCP_COMPOUND;
|
2015-07-30 12:45:18 +02:00
|
|
|
}
|
|
|
|
|
RTC_NOTREACHED();
|
|
|
|
|
return rtclog::VideoReceiveConfig::RTCP_COMPOUND;
|
|
|
|
|
}
|
|
|
|
|
|
2017-02-20 05:14:41 -08:00
|
|
|
rtclog::DelayBasedBweUpdate::DetectorState ConvertDetectorState(
|
2017-02-17 03:38:28 -08:00
|
|
|
BandwidthUsage state) {
|
|
|
|
|
switch (state) {
|
|
|
|
|
case BandwidthUsage::kBwNormal:
|
2017-02-20 05:14:41 -08:00
|
|
|
return rtclog::DelayBasedBweUpdate::BWE_NORMAL;
|
2017-02-17 03:38:28 -08:00
|
|
|
case BandwidthUsage::kBwUnderusing:
|
2017-02-20 05:14:41 -08:00
|
|
|
return rtclog::DelayBasedBweUpdate::BWE_UNDERUSING;
|
2017-02-17 03:38:28 -08:00
|
|
|
case BandwidthUsage::kBwOverusing:
|
2017-02-20 05:14:41 -08:00
|
|
|
return rtclog::DelayBasedBweUpdate::BWE_OVERUSING;
|
2017-02-17 03:38:28 -08:00
|
|
|
}
|
|
|
|
|
RTC_NOTREACHED();
|
2017-02-20 05:14:41 -08:00
|
|
|
return rtclog::DelayBasedBweUpdate::BWE_NORMAL;
|
2017-02-17 03:38:28 -08:00
|
|
|
}
|
|
|
|
|
|
2017-02-27 02:18:46 -08:00
|
|
|
rtclog::BweProbeResult::ResultType ConvertProbeResultType(
|
|
|
|
|
ProbeFailureReason failure_reason) {
|
|
|
|
|
switch (failure_reason) {
|
|
|
|
|
case kInvalidSendReceiveInterval:
|
|
|
|
|
return rtclog::BweProbeResult::INVALID_SEND_RECEIVE_INTERVAL;
|
|
|
|
|
case kInvalidSendReceiveRatio:
|
|
|
|
|
return rtclog::BweProbeResult::INVALID_SEND_RECEIVE_RATIO;
|
|
|
|
|
case kTimeout:
|
|
|
|
|
return rtclog::BweProbeResult::TIMEOUT;
|
|
|
|
|
}
|
|
|
|
|
RTC_NOTREACHED();
|
|
|
|
|
return rtclog::BweProbeResult::SUCCESS;
|
|
|
|
|
}
|
|
|
|
|
|
2015-10-16 08:51:08 -07:00
|
|
|
} // namespace
|
|
|
|
|
|
2017-09-06 05:18:15 -07:00
|
|
|
std::atomic<int> RtcEventLogImpl::log_count_(0);
|
2017-06-28 06:40:51 -07:00
|
|
|
|
2016-12-20 05:03:58 -08:00
|
|
|
RtcEventLogImpl::RtcEventLogImpl()
|
2017-09-06 05:18:15 -07:00
|
|
|
: file_(FileWrapper::Create()),
|
|
|
|
|
max_size_bytes_(std::numeric_limits<decltype(max_size_bytes_)>::max()),
|
|
|
|
|
written_bytes_(0),
|
|
|
|
|
task_queue_("rtc_event_log") {}
|
2015-10-16 08:51:08 -07:00
|
|
|
|
2016-04-22 12:40:37 -07:00
|
|
|
RtcEventLogImpl::~RtcEventLogImpl() {
|
2017-09-06 05:18:15 -07:00
|
|
|
RTC_DCHECK_CALLED_SEQUENTIALLY(&owner_sequence_checker_);
|
|
|
|
|
|
|
|
|
|
// If we're logging to the file, this will stop that. Blocking function.
|
|
|
|
|
StopLogging();
|
|
|
|
|
|
|
|
|
|
int count = std::atomic_fetch_sub(&RtcEventLogImpl::log_count_, 1) - 1;
|
2017-06-28 06:40:51 -07:00
|
|
|
RTC_DCHECK_GE(count, 0);
|
2015-10-16 08:51:08 -07:00
|
|
|
}
|
2015-07-30 12:45:18 +02:00
|
|
|
|
2016-04-22 12:40:37 -07:00
|
|
|
bool RtcEventLogImpl::StartLogging(const std::string& file_name,
|
|
|
|
|
int64_t max_size_bytes) {
|
2017-09-06 05:18:15 -07:00
|
|
|
RTC_DCHECK_CALLED_SEQUENTIALLY(&owner_sequence_checker_);
|
|
|
|
|
|
|
|
|
|
auto file = rtc::WrapUnique<FileWrapper>(FileWrapper::Create());
|
|
|
|
|
if (!file->OpenFile(file_name.c_str(), false)) {
|
2016-05-27 02:22:51 -07:00
|
|
|
LOG(LS_ERROR) << "Can't open file. WebRTC event log not started.";
|
2016-04-22 12:40:37 -07:00
|
|
|
return false;
|
2015-07-30 12:45:18 +02:00
|
|
|
}
|
2017-09-06 05:18:15 -07:00
|
|
|
|
|
|
|
|
StartLoggingInternal(std::move(file), max_size_bytes);
|
|
|
|
|
|
2016-04-22 12:40:37 -07:00
|
|
|
return true;
|
2015-10-16 02:22:18 -07:00
|
|
|
}
|
|
|
|
|
|
2016-04-22 12:40:37 -07:00
|
|
|
bool RtcEventLogImpl::StartLogging(rtc::PlatformFile platform_file,
|
|
|
|
|
int64_t max_size_bytes) {
|
2017-09-06 05:18:15 -07:00
|
|
|
RTC_DCHECK_CALLED_SEQUENTIALLY(&owner_sequence_checker_);
|
|
|
|
|
|
|
|
|
|
auto file = rtc::WrapUnique<FileWrapper>(FileWrapper::Create());
|
2016-04-22 12:40:37 -07:00
|
|
|
FILE* file_handle = rtc::FdopenPlatformFileForWriting(platform_file);
|
|
|
|
|
if (!file_handle) {
|
2016-05-27 02:22:51 -07:00
|
|
|
LOG(LS_ERROR) << "Can't open file. WebRTC event log not started.";
|
|
|
|
|
// Even though we failed to open a FILE*, the platform_file is still open
|
|
|
|
|
// and needs to be closed.
|
|
|
|
|
if (!rtc::ClosePlatformFile(platform_file)) {
|
|
|
|
|
LOG(LS_ERROR) << "Can't close file.";
|
|
|
|
|
}
|
2016-04-22 12:40:37 -07:00
|
|
|
return false;
|
2015-10-16 02:22:18 -07:00
|
|
|
}
|
2017-09-06 05:18:15 -07:00
|
|
|
if (!file->OpenFromFileHandle(file_handle)) {
|
2016-05-27 02:22:51 -07:00
|
|
|
LOG(LS_ERROR) << "Can't open file. WebRTC event log not started.";
|
2015-10-16 02:22:18 -07:00
|
|
|
return false;
|
|
|
|
|
}
|
2017-09-06 05:18:15 -07:00
|
|
|
|
|
|
|
|
StartLoggingInternal(std::move(file), max_size_bytes);
|
|
|
|
|
|
2015-10-16 02:22:18 -07:00
|
|
|
return true;
|
|
|
|
|
}
|
|
|
|
|
|
2015-07-30 12:45:18 +02:00
|
|
|
void RtcEventLogImpl::StopLogging() {
|
2017-09-06 05:18:15 -07:00
|
|
|
RTC_DCHECK_CALLED_SEQUENTIALLY(&owner_sequence_checker_);
|
|
|
|
|
|
2016-05-27 02:22:51 -07:00
|
|
|
LOG(LS_INFO) << "Stopping WebRTC event log.";
|
2017-09-06 05:18:15 -07:00
|
|
|
|
|
|
|
|
const int64_t stop_time = rtc::TimeMicros();
|
|
|
|
|
|
|
|
|
|
rtc::Event file_finished(true, false);
|
|
|
|
|
|
|
|
|
|
task_queue_.PostTask([this, stop_time, &file_finished]() {
|
|
|
|
|
RTC_DCHECK_RUN_ON(&task_queue_);
|
|
|
|
|
if (file_->is_open()) {
|
|
|
|
|
StopLogFile(stop_time);
|
|
|
|
|
}
|
|
|
|
|
file_finished.Set();
|
|
|
|
|
});
|
|
|
|
|
|
|
|
|
|
file_finished.Wait(rtc::Event::kForever);
|
|
|
|
|
|
|
|
|
|
LOG(LS_INFO) << "WebRTC event log successfully stopped.";
|
2015-07-30 12:45:18 +02:00
|
|
|
}
|
|
|
|
|
|
|
|
|
|
void RtcEventLogImpl::LogVideoReceiveStreamConfig(
|
2017-05-22 03:26:49 -07:00
|
|
|
const rtclog::StreamConfig& config) {
|
2016-04-22 12:40:37 -07:00
|
|
|
std::unique_ptr<rtclog::Event> event(new rtclog::Event());
|
2016-12-20 05:03:58 -08:00
|
|
|
event->set_timestamp_us(rtc::TimeMicros());
|
2016-04-22 12:40:37 -07:00
|
|
|
event->set_type(rtclog::Event::VIDEO_RECEIVER_CONFIG_EVENT);
|
2015-07-30 12:45:18 +02:00
|
|
|
|
|
|
|
|
rtclog::VideoReceiveConfig* receiver_config =
|
2016-04-22 12:40:37 -07:00
|
|
|
event->mutable_video_receiver_config();
|
2017-05-22 03:26:49 -07:00
|
|
|
receiver_config->set_remote_ssrc(config.remote_ssrc);
|
|
|
|
|
receiver_config->set_local_ssrc(config.local_ssrc);
|
2015-07-30 12:45:18 +02:00
|
|
|
|
2017-05-22 03:26:49 -07:00
|
|
|
// TODO(perkj): Add field for rsid.
|
|
|
|
|
receiver_config->set_rtcp_mode(ConvertRtcpMode(config.rtcp_mode));
|
|
|
|
|
receiver_config->set_remb(config.remb);
|
2015-07-30 12:45:18 +02:00
|
|
|
|
2017-05-22 03:26:49 -07:00
|
|
|
for (const auto& e : config.rtp_extensions) {
|
2015-07-30 12:45:18 +02:00
|
|
|
rtclog::RtpHeaderExtension* extension =
|
|
|
|
|
receiver_config->add_header_extensions();
|
2016-05-26 11:24:55 -07:00
|
|
|
extension->set_name(e.uri);
|
2015-07-30 12:45:18 +02:00
|
|
|
extension->set_id(e.id);
|
|
|
|
|
}
|
|
|
|
|
|
2017-05-22 03:26:49 -07:00
|
|
|
for (const auto& d : config.codecs) {
|
2015-07-30 12:45:18 +02:00
|
|
|
rtclog::DecoderConfig* decoder = receiver_config->add_decoders();
|
|
|
|
|
decoder->set_name(d.payload_name);
|
|
|
|
|
decoder->set_payload_type(d.payload_type);
|
2017-05-22 03:26:49 -07:00
|
|
|
if (d.rtx_payload_type != 0) {
|
|
|
|
|
rtclog::RtxMap* rtx = receiver_config->add_rtx_map();
|
|
|
|
|
rtx->set_payload_type(d.payload_type);
|
|
|
|
|
rtx->mutable_config()->set_rtx_ssrc(config.rtx_ssrc);
|
|
|
|
|
rtx->mutable_config()->set_rtx_payload_type(d.rtx_payload_type);
|
|
|
|
|
}
|
2015-07-30 12:45:18 +02:00
|
|
|
}
|
2017-07-16 16:44:08 -07:00
|
|
|
StoreEvent(std::move(event));
|
2015-07-30 12:45:18 +02:00
|
|
|
}
|
|
|
|
|
|
|
|
|
|
void RtcEventLogImpl::LogVideoSendStreamConfig(
|
2017-05-22 04:08:28 -07:00
|
|
|
const rtclog::StreamConfig& config) {
|
2016-04-22 12:40:37 -07:00
|
|
|
std::unique_ptr<rtclog::Event> event(new rtclog::Event());
|
2016-12-20 05:03:58 -08:00
|
|
|
event->set_timestamp_us(rtc::TimeMicros());
|
2016-04-22 12:40:37 -07:00
|
|
|
event->set_type(rtclog::Event::VIDEO_SENDER_CONFIG_EVENT);
|
2015-07-30 12:45:18 +02:00
|
|
|
|
2016-04-22 12:40:37 -07:00
|
|
|
rtclog::VideoSendConfig* sender_config = event->mutable_video_sender_config();
|
2015-07-30 12:45:18 +02:00
|
|
|
|
2017-05-22 04:08:28 -07:00
|
|
|
// TODO(perkj): rtclog::VideoSendConfig should only contain one SSRC.
|
|
|
|
|
sender_config->add_ssrcs(config.local_ssrc);
|
|
|
|
|
if (config.rtx_ssrc != 0) {
|
|
|
|
|
sender_config->add_rtx_ssrcs(config.rtx_ssrc);
|
2015-07-30 12:45:18 +02:00
|
|
|
}
|
|
|
|
|
|
2017-05-22 04:08:28 -07:00
|
|
|
for (const auto& e : config.rtp_extensions) {
|
2015-07-30 12:45:18 +02:00
|
|
|
rtclog::RtpHeaderExtension* extension =
|
|
|
|
|
sender_config->add_header_extensions();
|
2016-05-26 11:24:55 -07:00
|
|
|
extension->set_name(e.uri);
|
2015-07-30 12:45:18 +02:00
|
|
|
extension->set_id(e.id);
|
|
|
|
|
}
|
|
|
|
|
|
2017-05-22 04:08:28 -07:00
|
|
|
// TODO(perkj): rtclog::VideoSendConfig should contain many possible codec
|
|
|
|
|
// configurations.
|
|
|
|
|
for (const auto& codec : config.codecs) {
|
|
|
|
|
sender_config->set_rtx_payload_type(codec.rtx_payload_type);
|
|
|
|
|
rtclog::EncoderConfig* encoder = sender_config->mutable_encoder();
|
|
|
|
|
encoder->set_name(codec.payload_name);
|
|
|
|
|
encoder->set_payload_type(codec.payload_type);
|
|
|
|
|
|
|
|
|
|
if (config.codecs.size() > 1) {
|
|
|
|
|
LOG(WARNING) << "LogVideoSendStreamConfig currently only supports one "
|
|
|
|
|
<< "codec. Logging codec :" << codec.payload_name;
|
|
|
|
|
break;
|
|
|
|
|
}
|
2015-07-30 12:45:18 +02:00
|
|
|
}
|
|
|
|
|
|
2017-07-16 16:44:08 -07:00
|
|
|
StoreEvent(std::move(event));
|
2015-07-30 12:45:18 +02:00
|
|
|
}
|
|
|
|
|
|
2016-10-10 05:12:51 -07:00
|
|
|
void RtcEventLogImpl::LogAudioReceiveStreamConfig(
|
2017-05-22 09:36:28 -07:00
|
|
|
const rtclog::StreamConfig& config) {
|
2016-10-10 05:12:51 -07:00
|
|
|
std::unique_ptr<rtclog::Event> event(new rtclog::Event());
|
2016-12-20 05:03:58 -08:00
|
|
|
event->set_timestamp_us(rtc::TimeMicros());
|
2016-10-10 05:12:51 -07:00
|
|
|
event->set_type(rtclog::Event::AUDIO_RECEIVER_CONFIG_EVENT);
|
|
|
|
|
|
|
|
|
|
rtclog::AudioReceiveConfig* receiver_config =
|
|
|
|
|
event->mutable_audio_receiver_config();
|
2017-05-22 09:36:28 -07:00
|
|
|
receiver_config->set_remote_ssrc(config.remote_ssrc);
|
|
|
|
|
receiver_config->set_local_ssrc(config.local_ssrc);
|
2016-10-10 05:12:51 -07:00
|
|
|
|
2017-05-22 09:36:28 -07:00
|
|
|
for (const auto& e : config.rtp_extensions) {
|
2016-10-10 05:12:51 -07:00
|
|
|
rtclog::RtpHeaderExtension* extension =
|
|
|
|
|
receiver_config->add_header_extensions();
|
|
|
|
|
extension->set_name(e.uri);
|
|
|
|
|
extension->set_id(e.id);
|
|
|
|
|
}
|
2017-07-16 16:44:08 -07:00
|
|
|
StoreEvent(std::move(event));
|
2016-10-10 05:12:51 -07:00
|
|
|
}
|
|
|
|
|
|
|
|
|
|
void RtcEventLogImpl::LogAudioSendStreamConfig(
|
2017-05-22 10:12:26 -07:00
|
|
|
const rtclog::StreamConfig& config) {
|
2016-10-10 05:12:51 -07:00
|
|
|
std::unique_ptr<rtclog::Event> event(new rtclog::Event());
|
2016-12-20 05:03:58 -08:00
|
|
|
event->set_timestamp_us(rtc::TimeMicros());
|
2016-10-10 05:12:51 -07:00
|
|
|
event->set_type(rtclog::Event::AUDIO_SENDER_CONFIG_EVENT);
|
|
|
|
|
|
|
|
|
|
rtclog::AudioSendConfig* sender_config = event->mutable_audio_sender_config();
|
|
|
|
|
|
2017-05-22 10:12:26 -07:00
|
|
|
sender_config->set_ssrc(config.local_ssrc);
|
2016-10-10 05:12:51 -07:00
|
|
|
|
2017-05-22 10:12:26 -07:00
|
|
|
for (const auto& e : config.rtp_extensions) {
|
2016-10-10 05:12:51 -07:00
|
|
|
rtclog::RtpHeaderExtension* extension =
|
|
|
|
|
sender_config->add_header_extensions();
|
|
|
|
|
extension->set_name(e.uri);
|
|
|
|
|
extension->set_id(e.id);
|
|
|
|
|
}
|
|
|
|
|
|
2017-07-16 16:44:08 -07:00
|
|
|
StoreEvent(std::move(event));
|
2016-10-10 05:12:51 -07:00
|
|
|
}
|
|
|
|
|
|
2016-01-21 05:42:04 -08:00
|
|
|
void RtcEventLogImpl::LogRtpHeader(PacketDirection direction,
|
2015-07-30 12:45:18 +02:00
|
|
|
const uint8_t* header,
|
2015-09-04 03:39:42 -07:00
|
|
|
size_t packet_length) {
|
2017-05-30 03:52:10 -07:00
|
|
|
LogRtpHeader(direction, header, packet_length, PacedPacketInfo::kNotAProbe);
|
2017-02-27 02:18:46 -08:00
|
|
|
}
|
|
|
|
|
|
|
|
|
|
void RtcEventLogImpl::LogRtpHeader(PacketDirection direction,
|
|
|
|
|
const uint8_t* header,
|
|
|
|
|
size_t packet_length,
|
|
|
|
|
int probe_cluster_id) {
|
2015-09-04 03:39:42 -07:00
|
|
|
// Read header length (in bytes) from packet data.
|
|
|
|
|
if (packet_length < 12u) {
|
|
|
|
|
return; // Don't read outside the packet.
|
|
|
|
|
}
|
|
|
|
|
const bool x = (header[0] & 0x10) != 0;
|
|
|
|
|
const uint8_t cc = header[0] & 0x0f;
|
|
|
|
|
size_t header_length = 12u + cc * 4u;
|
|
|
|
|
|
|
|
|
|
if (x) {
|
|
|
|
|
if (packet_length < 12u + cc * 4u + 4u) {
|
|
|
|
|
return; // Don't read outside the packet.
|
|
|
|
|
}
|
|
|
|
|
size_t x_len = ByteReader<uint16_t>::ReadBigEndian(header + 14 + cc * 4);
|
|
|
|
|
header_length += (x_len + 1) * 4;
|
|
|
|
|
}
|
|
|
|
|
|
2016-04-22 12:40:37 -07:00
|
|
|
std::unique_ptr<rtclog::Event> rtp_event(new rtclog::Event());
|
2016-12-20 05:03:58 -08:00
|
|
|
rtp_event->set_timestamp_us(rtc::TimeMicros());
|
2016-04-22 12:40:37 -07:00
|
|
|
rtp_event->set_type(rtclog::Event::RTP_EVENT);
|
|
|
|
|
rtp_event->mutable_rtp_packet()->set_incoming(direction == kIncomingPacket);
|
|
|
|
|
rtp_event->mutable_rtp_packet()->set_packet_length(packet_length);
|
|
|
|
|
rtp_event->mutable_rtp_packet()->set_header(header, header_length);
|
2017-02-27 02:18:46 -08:00
|
|
|
if (probe_cluster_id != PacedPacketInfo::kNotAProbe)
|
|
|
|
|
rtp_event->mutable_rtp_packet()->set_probe_cluster_id(probe_cluster_id);
|
2017-07-16 16:44:08 -07:00
|
|
|
StoreEvent(std::move(rtp_event));
|
2015-07-30 12:45:18 +02:00
|
|
|
}
|
|
|
|
|
|
2016-01-21 05:42:04 -08:00
|
|
|
void RtcEventLogImpl::LogRtcpPacket(PacketDirection direction,
|
2015-07-30 12:45:18 +02:00
|
|
|
const uint8_t* packet,
|
|
|
|
|
size_t length) {
|
2016-04-22 12:40:37 -07:00
|
|
|
std::unique_ptr<rtclog::Event> rtcp_event(new rtclog::Event());
|
2016-12-20 05:03:58 -08:00
|
|
|
rtcp_event->set_timestamp_us(rtc::TimeMicros());
|
2016-04-22 12:40:37 -07:00
|
|
|
rtcp_event->set_type(rtclog::Event::RTCP_EVENT);
|
|
|
|
|
rtcp_event->mutable_rtcp_packet()->set_incoming(direction == kIncomingPacket);
|
2015-11-06 09:00:18 -08:00
|
|
|
|
2016-10-07 07:39:54 -07:00
|
|
|
rtcp::CommonHeader header;
|
2015-11-06 09:00:18 -08:00
|
|
|
const uint8_t* block_begin = packet;
|
|
|
|
|
const uint8_t* packet_end = packet + length;
|
|
|
|
|
RTC_DCHECK(length <= IP_PACKET_SIZE);
|
|
|
|
|
uint8_t buffer[IP_PACKET_SIZE];
|
|
|
|
|
uint32_t buffer_length = 0;
|
|
|
|
|
while (block_begin < packet_end) {
|
2016-10-07 07:39:54 -07:00
|
|
|
if (!header.Parse(block_begin, packet_end - block_begin)) {
|
2015-11-06 09:00:18 -08:00
|
|
|
break; // Incorrect message header.
|
|
|
|
|
}
|
2016-10-07 07:39:54 -07:00
|
|
|
const uint8_t* next_block = header.NextPacket();
|
|
|
|
|
uint32_t block_size = next_block - block_begin;
|
|
|
|
|
switch (header.type()) {
|
|
|
|
|
case rtcp::SenderReport::kPacketType:
|
|
|
|
|
case rtcp::ReceiverReport::kPacketType:
|
|
|
|
|
case rtcp::Bye::kPacketType:
|
|
|
|
|
case rtcp::ExtendedJitterReport::kPacketType:
|
|
|
|
|
case rtcp::Rtpfb::kPacketType:
|
|
|
|
|
case rtcp::Psfb::kPacketType:
|
|
|
|
|
case rtcp::ExtendedReports::kPacketType:
|
2015-11-06 09:00:18 -08:00
|
|
|
// We log sender reports, receiver reports, bye messages
|
|
|
|
|
// inter-arrival jitter, third-party loss reports, payload-specific
|
|
|
|
|
// feedback and extended reports.
|
|
|
|
|
memcpy(buffer + buffer_length, block_begin, block_size);
|
|
|
|
|
buffer_length += block_size;
|
|
|
|
|
break;
|
2016-10-07 07:39:54 -07:00
|
|
|
case rtcp::Sdes::kPacketType:
|
|
|
|
|
case rtcp::App::kPacketType:
|
2015-11-06 09:00:18 -08:00
|
|
|
default:
|
|
|
|
|
// We don't log sender descriptions, application defined messages
|
|
|
|
|
// or message blocks of unknown type.
|
|
|
|
|
break;
|
|
|
|
|
}
|
|
|
|
|
|
|
|
|
|
block_begin += block_size;
|
|
|
|
|
}
|
2016-04-22 12:40:37 -07:00
|
|
|
rtcp_event->mutable_rtcp_packet()->set_packet_data(buffer, buffer_length);
|
2017-07-16 16:44:08 -07:00
|
|
|
StoreEvent(std::move(rtcp_event));
|
2015-07-30 12:45:18 +02:00
|
|
|
}
|
|
|
|
|
|
2015-09-17 16:30:16 +02:00
|
|
|
void RtcEventLogImpl::LogAudioPlayout(uint32_t ssrc) {
|
2016-04-22 12:40:37 -07:00
|
|
|
std::unique_ptr<rtclog::Event> event(new rtclog::Event());
|
2016-12-20 05:03:58 -08:00
|
|
|
event->set_timestamp_us(rtc::TimeMicros());
|
2016-04-22 12:40:37 -07:00
|
|
|
event->set_type(rtclog::Event::AUDIO_PLAYOUT_EVENT);
|
|
|
|
|
auto playout_event = event->mutable_audio_playout_event();
|
2015-10-08 18:07:41 +02:00
|
|
|
playout_event->set_local_ssrc(ssrc);
|
2017-07-16 16:44:08 -07:00
|
|
|
StoreEvent(std::move(event));
|
2015-07-30 12:45:18 +02:00
|
|
|
}
|
|
|
|
|
|
2017-02-20 05:14:41 -08:00
|
|
|
void RtcEventLogImpl::LogLossBasedBweUpdate(int32_t bitrate_bps,
|
2015-11-05 12:02:15 -08:00
|
|
|
uint8_t fraction_loss,
|
|
|
|
|
int32_t total_packets) {
|
2016-04-22 12:40:37 -07:00
|
|
|
std::unique_ptr<rtclog::Event> event(new rtclog::Event());
|
2016-12-20 05:03:58 -08:00
|
|
|
event->set_timestamp_us(rtc::TimeMicros());
|
2017-02-20 05:14:41 -08:00
|
|
|
event->set_type(rtclog::Event::LOSS_BASED_BWE_UPDATE);
|
|
|
|
|
auto bwe_event = event->mutable_loss_based_bwe_update();
|
|
|
|
|
bwe_event->set_bitrate_bps(bitrate_bps);
|
2015-11-05 12:02:15 -08:00
|
|
|
bwe_event->set_fraction_loss(fraction_loss);
|
|
|
|
|
bwe_event->set_total_packets(total_packets);
|
2017-07-16 16:44:08 -07:00
|
|
|
StoreEvent(std::move(event));
|
2016-06-08 07:20:29 -07:00
|
|
|
}
|
|
|
|
|
|
2017-02-20 05:14:41 -08:00
|
|
|
void RtcEventLogImpl::LogDelayBasedBweUpdate(int32_t bitrate_bps,
|
2017-02-17 03:38:28 -08:00
|
|
|
BandwidthUsage detector_state) {
|
|
|
|
|
std::unique_ptr<rtclog::Event> event(new rtclog::Event());
|
|
|
|
|
event->set_timestamp_us(rtc::TimeMicros());
|
2017-02-20 05:14:41 -08:00
|
|
|
event->set_type(rtclog::Event::DELAY_BASED_BWE_UPDATE);
|
|
|
|
|
auto bwe_event = event->mutable_delay_based_bwe_update();
|
|
|
|
|
bwe_event->set_bitrate_bps(bitrate_bps);
|
2017-02-17 03:38:28 -08:00
|
|
|
bwe_event->set_detector_state(ConvertDetectorState(detector_state));
|
2017-07-16 16:44:08 -07:00
|
|
|
StoreEvent(std::move(event));
|
2017-02-17 03:38:28 -08:00
|
|
|
}
|
|
|
|
|
|
2017-01-24 04:54:59 -08:00
|
|
|
void RtcEventLogImpl::LogAudioNetworkAdaptation(
|
2017-04-06 05:59:10 -07:00
|
|
|
const AudioEncoderRuntimeConfig& config) {
|
2017-01-24 04:54:59 -08:00
|
|
|
std::unique_ptr<rtclog::Event> event(new rtclog::Event());
|
|
|
|
|
event->set_timestamp_us(rtc::TimeMicros());
|
|
|
|
|
event->set_type(rtclog::Event::AUDIO_NETWORK_ADAPTATION_EVENT);
|
|
|
|
|
auto audio_network_adaptation = event->mutable_audio_network_adaptation();
|
|
|
|
|
if (config.bitrate_bps)
|
|
|
|
|
audio_network_adaptation->set_bitrate_bps(*config.bitrate_bps);
|
|
|
|
|
if (config.frame_length_ms)
|
|
|
|
|
audio_network_adaptation->set_frame_length_ms(*config.frame_length_ms);
|
|
|
|
|
if (config.uplink_packet_loss_fraction) {
|
|
|
|
|
audio_network_adaptation->set_uplink_packet_loss_fraction(
|
|
|
|
|
*config.uplink_packet_loss_fraction);
|
|
|
|
|
}
|
|
|
|
|
if (config.enable_fec)
|
|
|
|
|
audio_network_adaptation->set_enable_fec(*config.enable_fec);
|
|
|
|
|
if (config.enable_dtx)
|
|
|
|
|
audio_network_adaptation->set_enable_dtx(*config.enable_dtx);
|
|
|
|
|
if (config.num_channels)
|
|
|
|
|
audio_network_adaptation->set_num_channels(*config.num_channels);
|
2017-07-16 16:44:08 -07:00
|
|
|
StoreEvent(std::move(event));
|
2017-01-24 04:54:59 -08:00
|
|
|
}
|
|
|
|
|
|
2017-02-27 02:18:46 -08:00
|
|
|
void RtcEventLogImpl::LogProbeClusterCreated(int id,
|
|
|
|
|
int bitrate_bps,
|
|
|
|
|
int min_probes,
|
|
|
|
|
int min_bytes) {
|
|
|
|
|
std::unique_ptr<rtclog::Event> event(new rtclog::Event());
|
|
|
|
|
event->set_timestamp_us(rtc::TimeMicros());
|
|
|
|
|
event->set_type(rtclog::Event::BWE_PROBE_CLUSTER_CREATED_EVENT);
|
|
|
|
|
|
|
|
|
|
auto probe_cluster = event->mutable_probe_cluster();
|
|
|
|
|
probe_cluster->set_id(id);
|
|
|
|
|
probe_cluster->set_bitrate_bps(bitrate_bps);
|
|
|
|
|
probe_cluster->set_min_packets(min_probes);
|
|
|
|
|
probe_cluster->set_min_bytes(min_bytes);
|
2017-07-16 16:44:08 -07:00
|
|
|
StoreEvent(std::move(event));
|
2017-02-27 02:18:46 -08:00
|
|
|
}
|
|
|
|
|
|
|
|
|
|
void RtcEventLogImpl::LogProbeResultSuccess(int id, int bitrate_bps) {
|
|
|
|
|
LogProbeResult(id, rtclog::BweProbeResult::SUCCESS, bitrate_bps);
|
|
|
|
|
}
|
|
|
|
|
|
|
|
|
|
void RtcEventLogImpl::LogProbeResultFailure(int id,
|
|
|
|
|
ProbeFailureReason failure_reason) {
|
|
|
|
|
rtclog::BweProbeResult::ResultType result =
|
|
|
|
|
ConvertProbeResultType(failure_reason);
|
|
|
|
|
LogProbeResult(id, result, -1);
|
|
|
|
|
}
|
|
|
|
|
|
|
|
|
|
void RtcEventLogImpl::LogProbeResult(int id,
|
|
|
|
|
rtclog::BweProbeResult::ResultType result,
|
|
|
|
|
int bitrate_bps) {
|
|
|
|
|
std::unique_ptr<rtclog::Event> event(new rtclog::Event());
|
|
|
|
|
event->set_timestamp_us(rtc::TimeMicros());
|
|
|
|
|
event->set_type(rtclog::Event::BWE_PROBE_RESULT_EVENT);
|
|
|
|
|
|
|
|
|
|
auto probe_result = event->mutable_probe_result();
|
|
|
|
|
probe_result->set_id(id);
|
|
|
|
|
probe_result->set_result(result);
|
|
|
|
|
if (result == rtclog::BweProbeResult::SUCCESS)
|
|
|
|
|
probe_result->set_bitrate_bps(bitrate_bps);
|
2017-07-16 16:44:08 -07:00
|
|
|
StoreEvent(std::move(event));
|
2017-02-27 02:18:46 -08:00
|
|
|
}
|
|
|
|
|
|
2017-09-06 05:18:15 -07:00
|
|
|
void RtcEventLogImpl::StartLoggingInternal(std::unique_ptr<FileWrapper> file,
|
|
|
|
|
int64_t max_size_bytes) {
|
|
|
|
|
LOG(LS_INFO) << "Starting WebRTC event log.";
|
|
|
|
|
|
|
|
|
|
max_size_bytes = (max_size_bytes <= 0)
|
|
|
|
|
? std::numeric_limits<decltype(max_size_bytes)>::max()
|
|
|
|
|
: max_size_bytes;
|
|
|
|
|
auto file_handler = [this,
|
|
|
|
|
max_size_bytes](std::unique_ptr<FileWrapper> file) {
|
|
|
|
|
RTC_DCHECK_RUN_ON(&task_queue_);
|
|
|
|
|
if (!file_->is_open()) {
|
|
|
|
|
max_size_bytes_ = max_size_bytes;
|
|
|
|
|
file_ = std::move(file);
|
|
|
|
|
StartLogFile();
|
|
|
|
|
} else {
|
|
|
|
|
// Already started. Ignore message and close file handle.
|
|
|
|
|
file->CloseFile();
|
|
|
|
|
}
|
|
|
|
|
};
|
|
|
|
|
task_queue_.PostTask(rtc::MakeUnique<ResourceOwningTask<FileWrapper>>(
|
|
|
|
|
std::move(file), file_handler));
|
|
|
|
|
}
|
|
|
|
|
|
2017-07-16 16:44:08 -07:00
|
|
|
void RtcEventLogImpl::StoreEvent(std::unique_ptr<rtclog::Event> event) {
|
2017-09-06 05:18:15 -07:00
|
|
|
RTC_DCHECK(event);
|
|
|
|
|
|
|
|
|
|
auto event_handler = [this](std::unique_ptr<rtclog::Event> rtclog_event) {
|
|
|
|
|
RTC_DCHECK_RUN_ON(&task_queue_);
|
|
|
|
|
if (file_->is_open()) {
|
|
|
|
|
LogToFile(std::move(rtclog_event));
|
|
|
|
|
} else {
|
|
|
|
|
LogToMemory(std::move(rtclog_event));
|
|
|
|
|
}
|
|
|
|
|
};
|
|
|
|
|
|
|
|
|
|
task_queue_.PostTask(rtc::MakeUnique<ResourceOwningTask<rtclog::Event>>(
|
|
|
|
|
std::move(event), event_handler));
|
|
|
|
|
}
|
|
|
|
|
|
|
|
|
|
bool RtcEventLogImpl::AppendEventToString(rtclog::Event* event,
|
|
|
|
|
ProtoString* output_string) {
|
|
|
|
|
RTC_DCHECK_RUN_ON(&task_queue_);
|
|
|
|
|
|
|
|
|
|
// Even though we're only serializing a single event during this call, what
|
|
|
|
|
// we intend to get is a list of events, with a tag and length preceding
|
|
|
|
|
// each actual event. To produce that, we serialize a list of a single event.
|
|
|
|
|
// If we later serialize additional events, the resulting ProtoString will
|
|
|
|
|
// be a proper concatenation of all those events.
|
|
|
|
|
|
|
|
|
|
rtclog::EventStream event_stream;
|
|
|
|
|
event_stream.add_stream();
|
|
|
|
|
|
|
|
|
|
// As a tweak, we swap the new event into the event-stream, write that to
|
|
|
|
|
// file, then swap back. This saves on some copying.
|
|
|
|
|
rtclog::Event* output_event = event_stream.mutable_stream(0);
|
|
|
|
|
output_event->Swap(event);
|
|
|
|
|
|
|
|
|
|
bool appended;
|
|
|
|
|
size_t potential_new_size =
|
|
|
|
|
written_bytes_ + output_string->size() + event_stream.ByteSize();
|
|
|
|
|
if (potential_new_size <= max_size_bytes_) {
|
|
|
|
|
event_stream.AppendToString(output_string);
|
|
|
|
|
appended = true;
|
|
|
|
|
} else {
|
|
|
|
|
appended = false;
|
|
|
|
|
}
|
|
|
|
|
|
|
|
|
|
// When the function returns, the original Event will be unchanged.
|
|
|
|
|
output_event->Swap(event);
|
|
|
|
|
|
|
|
|
|
return appended;
|
|
|
|
|
}
|
|
|
|
|
|
|
|
|
|
void RtcEventLogImpl::LogToMemory(std::unique_ptr<rtclog::Event> event) {
|
|
|
|
|
RTC_DCHECK_RUN_ON(&task_queue_);
|
|
|
|
|
RTC_DCHECK(!file_->is_open());
|
|
|
|
|
|
|
|
|
|
if (IsConfigEvent(*event.get())) {
|
|
|
|
|
config_history_.push_back(std::move(event));
|
|
|
|
|
} else {
|
|
|
|
|
history_.push_back(std::move(event));
|
|
|
|
|
if (history_.size() > kEventsInHistory) {
|
|
|
|
|
history_.pop_front();
|
|
|
|
|
}
|
|
|
|
|
}
|
|
|
|
|
}
|
|
|
|
|
|
|
|
|
|
void RtcEventLogImpl::StartLogFile() {
|
|
|
|
|
RTC_DCHECK_RUN_ON(&task_queue_);
|
|
|
|
|
RTC_DCHECK(file_->is_open());
|
|
|
|
|
|
|
|
|
|
ProtoString output_string;
|
|
|
|
|
|
|
|
|
|
// Create and serialize the LOG_START event.
|
|
|
|
|
// The timestamp used will correspond to when logging has started. The log
|
|
|
|
|
// may contain events earlier than the LOG_START event. (In general, the
|
|
|
|
|
// timestamps in the log are not monotonic.)
|
|
|
|
|
rtclog::Event start_event;
|
|
|
|
|
start_event.set_timestamp_us(rtc::TimeMicros());
|
|
|
|
|
start_event.set_type(rtclog::Event::LOG_START);
|
|
|
|
|
bool appended = AppendEventToString(&start_event, &output_string);
|
|
|
|
|
|
|
|
|
|
// Serialize the config information for all old streams, including streams
|
|
|
|
|
// which were already logged to previous files.
|
|
|
|
|
for (auto& event : config_history_) {
|
|
|
|
|
if (!appended) {
|
|
|
|
|
break;
|
|
|
|
|
}
|
|
|
|
|
appended = AppendEventToString(event.get(), &output_string);
|
|
|
|
|
}
|
|
|
|
|
|
|
|
|
|
// Serialize the events in the event queue.
|
|
|
|
|
while (appended && !history_.empty()) {
|
|
|
|
|
appended = AppendEventToString(history_.front().get(), &output_string);
|
|
|
|
|
if (appended) {
|
|
|
|
|
// Known issue - if writing to the file fails, these events will have
|
|
|
|
|
// been lost. If we try to open a new file, these events will be missing
|
|
|
|
|
// from it.
|
|
|
|
|
history_.pop_front();
|
|
|
|
|
}
|
|
|
|
|
}
|
|
|
|
|
|
|
|
|
|
// Write to file.
|
|
|
|
|
if (!file_->Write(output_string.data(), output_string.size())) {
|
|
|
|
|
LOG(LS_ERROR) << "FileWrapper failed to write WebRtcEventLog file.";
|
|
|
|
|
// The current FileWrapper implementation closes the file on error.
|
|
|
|
|
RTC_DCHECK(!file_->is_open());
|
|
|
|
|
return;
|
|
|
|
|
}
|
|
|
|
|
written_bytes_ += output_string.size();
|
|
|
|
|
|
|
|
|
|
if (!appended) {
|
|
|
|
|
RTC_DCHECK(file_->is_open());
|
|
|
|
|
StopLogFile(rtc::TimeMicros());
|
|
|
|
|
}
|
|
|
|
|
}
|
|
|
|
|
|
|
|
|
|
void RtcEventLogImpl::LogToFile(std::unique_ptr<rtclog::Event> event) {
|
|
|
|
|
RTC_DCHECK_RUN_ON(&task_queue_);
|
|
|
|
|
RTC_DCHECK(file_->is_open());
|
|
|
|
|
|
|
|
|
|
ProtoString output_string;
|
|
|
|
|
|
|
|
|
|
bool appended = AppendEventToString(event.get(), &output_string);
|
|
|
|
|
|
|
|
|
|
if (IsConfigEvent(*event.get())) {
|
|
|
|
|
config_history_.push_back(std::move(event));
|
|
|
|
|
}
|
|
|
|
|
|
|
|
|
|
if (!appended) {
|
|
|
|
|
RTC_DCHECK(file_->is_open());
|
|
|
|
|
history_.push_back(std::move(event));
|
|
|
|
|
StopLogFile(rtc::TimeMicros());
|
|
|
|
|
return;
|
|
|
|
|
}
|
|
|
|
|
|
|
|
|
|
// Write string to file.
|
|
|
|
|
if (file_->Write(output_string.data(), output_string.size())) {
|
|
|
|
|
written_bytes_ += output_string.size();
|
|
|
|
|
} else {
|
|
|
|
|
LOG(LS_ERROR) << "FileWrapper failed to write WebRtcEventLog file.";
|
|
|
|
|
// The current FileWrapper implementation closes the file on error.
|
|
|
|
|
RTC_DCHECK(!file_->is_open());
|
2015-07-30 12:45:18 +02:00
|
|
|
}
|
2017-09-06 05:18:15 -07:00
|
|
|
}
|
|
|
|
|
|
|
|
|
|
void RtcEventLogImpl::StopLogFile(int64_t stop_time) {
|
|
|
|
|
RTC_DCHECK_RUN_ON(&task_queue_);
|
|
|
|
|
RTC_DCHECK(file_->is_open());
|
|
|
|
|
|
|
|
|
|
ProtoString output_string;
|
|
|
|
|
|
|
|
|
|
rtclog::Event end_event;
|
|
|
|
|
end_event.set_timestamp_us(stop_time);
|
|
|
|
|
end_event.set_type(rtclog::Event::LOG_END);
|
|
|
|
|
bool appended = AppendEventToString(&end_event, &output_string);
|
|
|
|
|
|
|
|
|
|
if (appended) {
|
|
|
|
|
if (!file_->Write(output_string.data(), output_string.size())) {
|
|
|
|
|
LOG(LS_ERROR) << "FileWrapper failed to write WebRtcEventLog file.";
|
|
|
|
|
// The current FileWrapper implementation closes the file on error.
|
|
|
|
|
RTC_DCHECK(!file_->is_open());
|
|
|
|
|
}
|
|
|
|
|
written_bytes_ += output_string.size();
|
|
|
|
|
}
|
|
|
|
|
|
|
|
|
|
max_size_bytes_ = std::numeric_limits<decltype(max_size_bytes_)>::max();
|
|
|
|
|
written_bytes_ = 0;
|
|
|
|
|
|
|
|
|
|
file_->CloseFile();
|
|
|
|
|
RTC_DCHECK(!file_->is_open());
|
2015-07-30 12:45:18 +02:00
|
|
|
}
|
|
|
|
|
|
|
|
|
|
bool RtcEventLog::ParseRtcEventLog(const std::string& file_name,
|
|
|
|
|
rtclog::EventStream* result) {
|
|
|
|
|
char tmp_buffer[1024];
|
|
|
|
|
int bytes_read = 0;
|
2016-03-12 06:10:44 -08:00
|
|
|
std::unique_ptr<FileWrapper> dump_file(FileWrapper::Create());
|
FileWrapper[Impl] modifications and actually remove the "Impl" class.
This is a somewhat involved refactoring of this class. Here's an overview of the changes:
* FileWrapper can now be used as a regular class and instances allocated on the stack.
* The type now has support for move semantics and copy isn't allowed.
* New public ctor with FILE* that can be used instead of OpenFromFileHandle.
* New static Open() method. The intent of this is to allow opening a file and getting back a FileWrapper instance. Using this method instead of Create(), will allow us in the future to make the FILE* member pointer, to be const and simplify threading (get rid of the lock).
* Rename the Open() method to is_open() and make it inline.
* The FileWrapper interface is no longer a pure virtual interface. There's only one implementation so there's no need to go through a vtable for everything.
* Functionality offered by the class, is now reduced. No support for looping (not clear if that was actually useful to users of that flag), no need to implement the 'read_only_' functionality in the class, since file APIs implement that already, no support for *not* managing the file handle (this wasn't used). OpenFromFileHandle always "manages" the file.
* Delete the unused WriteText() method and don't support opening files in text mode. Text mode is only different on Windows and on Windows it translates \n to \r\n, which means that files such as log files, could have a slightly different format on Windows than other platforms. Besides, tools on Windows can handle UNIX line endings.
* Remove FileName(), change Trace code to manage its own path.
* Rename id_ member variable to file_.
* Removed the open_ member variable since the same functionality can be gotten from just checking the file pointer.
* Don't call CloseFile inside of Write. Write shouldn't be changing the state of the class beyond just attempting to write.
* Remove concept of looping from FileWrapper and never close inside of Read()
* Changed stream base classes to inherit from a common base class instead of both defining the Rewind method. Ultimately, Id' like to remove these interfaces and just have FileWrapper.
* Remove read_only param from OpenFromFileHandle
* Renamed size_in_bytes_ to position_, since it gets set to 0 when Rewind() is called (and the size actually does not change).
* Switch out rw lock for CriticalSection. The r/w lock was only used for reading when checking the open_ flag.
BUG=
Review-Url: https://codereview.webrtc.org/2054373002
Cr-Commit-Position: refs/heads/master@{#13155}
2016-06-15 10:30:14 -07:00
|
|
|
if (!dump_file->OpenFile(file_name.c_str(), true)) {
|
2015-07-30 12:45:18 +02:00
|
|
|
return false;
|
|
|
|
|
}
|
2017-04-07 00:59:12 -07:00
|
|
|
ProtoString dump_buffer;
|
2015-07-30 12:45:18 +02:00
|
|
|
while ((bytes_read = dump_file->Read(tmp_buffer, sizeof(tmp_buffer))) > 0) {
|
|
|
|
|
dump_buffer.append(tmp_buffer, bytes_read);
|
|
|
|
|
}
|
|
|
|
|
dump_file->CloseFile();
|
|
|
|
|
return result->ParseFromString(dump_buffer);
|
|
|
|
|
}
|
|
|
|
|
|
|
|
|
|
#endif // ENABLE_RTC_EVENT_LOG
|
|
|
|
|
|
|
|
|
|
// RtcEventLog member functions.
|
2016-12-20 05:03:58 -08:00
|
|
|
std::unique_ptr<RtcEventLog> RtcEventLog::Create() {
|
2016-04-22 12:40:37 -07:00
|
|
|
#ifdef ENABLE_RTC_EVENT_LOG
|
2017-09-06 05:18:15 -07:00
|
|
|
// TODO(eladalon): Known issue - there's a race over |log_count_| here.
|
2017-06-28 06:40:51 -07:00
|
|
|
constexpr int kMaxLogCount = 5;
|
2017-09-06 05:18:15 -07:00
|
|
|
int count = 1 + std::atomic_fetch_add(&RtcEventLogImpl::log_count_, 1);
|
2017-06-28 06:40:51 -07:00
|
|
|
if (count > kMaxLogCount) {
|
|
|
|
|
LOG(LS_WARNING) << "Denied creation of additional WebRTC event logs. "
|
|
|
|
|
<< count - 1 << " logs open already.";
|
2017-09-06 05:18:15 -07:00
|
|
|
std::atomic_fetch_sub(&RtcEventLogImpl::log_count_, 1);
|
2017-06-28 06:40:51 -07:00
|
|
|
return std::unique_ptr<RtcEventLog>(new RtcEventLogNullImpl());
|
|
|
|
|
}
|
2016-12-20 05:03:58 -08:00
|
|
|
return std::unique_ptr<RtcEventLog>(new RtcEventLogImpl());
|
2016-04-22 12:40:37 -07:00
|
|
|
#else
|
2017-09-06 05:18:15 -07:00
|
|
|
return CreateNull();
|
2016-04-22 12:40:37 -07:00
|
|
|
#endif // ENABLE_RTC_EVENT_LOG
|
2015-07-30 12:45:18 +02:00
|
|
|
}
|
2015-10-16 08:51:08 -07:00
|
|
|
|
2016-07-04 07:06:55 -07:00
|
|
|
std::unique_ptr<RtcEventLog> RtcEventLog::CreateNull() {
|
|
|
|
|
return std::unique_ptr<RtcEventLog>(new RtcEventLogNullImpl());
|
|
|
|
|
}
|
|
|
|
|
|
2015-07-30 12:45:18 +02:00
|
|
|
} // namespace webrtc
|