OLD | NEW |
1 /* | 1 /* |
2 * Copyright (c) 2015 The WebRTC project authors. All Rights Reserved. | 2 * Copyright (c) 2015 The WebRTC project authors. All Rights Reserved. |
3 * | 3 * |
4 * Use of this source code is governed by a BSD-style license | 4 * Use of this source code is governed by a BSD-style license |
5 * that can be found in the LICENSE file in the root of the source | 5 * that can be found in the LICENSE file in the root of the source |
6 * tree. An additional intellectual property rights grant can be found | 6 * tree. An additional intellectual property rights grant can be found |
7 * in the file PATENTS. All contributing project authors may | 7 * in the file PATENTS. All contributing project authors may |
8 * be found in the AUTHORS file in the root of the source tree. | 8 * be found in the AUTHORS file in the root of the source tree. |
9 */ | 9 */ |
10 | 10 |
11 #include "webrtc/call/rtc_event_log.h" | 11 #include "webrtc/call/rtc_event_log.h" |
12 | 12 |
13 #include <deque> | 13 #include <limits> |
14 #include <vector> | 14 #include <vector> |
15 | 15 |
16 #include "webrtc/base/checks.h" | 16 #include "webrtc/base/checks.h" |
17 #include "webrtc/base/criticalsection.h" | 17 #include "webrtc/base/constructormagic.h" |
18 #include "webrtc/base/thread_annotations.h" | 18 #include "webrtc/base/event.h" |
| 19 #include "webrtc/base/swap_queue.h" |
| 20 #include "webrtc/base/thread_checker.h" |
19 #include "webrtc/call.h" | 21 #include "webrtc/call.h" |
| 22 #include "webrtc/call/rtc_event_log_helper_thread.h" |
20 #include "webrtc/modules/rtp_rtcp/include/rtp_rtcp_defines.h" | 23 #include "webrtc/modules/rtp_rtcp/include/rtp_rtcp_defines.h" |
21 #include "webrtc/modules/rtp_rtcp/source/byte_io.h" | 24 #include "webrtc/modules/rtp_rtcp/source/byte_io.h" |
22 #include "webrtc/modules/rtp_rtcp/source/rtcp_utility.h" | 25 #include "webrtc/modules/rtp_rtcp/source/rtcp_utility.h" |
23 #include "webrtc/system_wrappers/include/clock.h" | 26 #include "webrtc/system_wrappers/include/clock.h" |
24 #include "webrtc/system_wrappers/include/file_wrapper.h" | 27 #include "webrtc/system_wrappers/include/file_wrapper.h" |
| 28 #include "webrtc/system_wrappers/include/logging.h" |
25 | 29 |
26 #ifdef ENABLE_RTC_EVENT_LOG | 30 #ifdef ENABLE_RTC_EVENT_LOG |
27 // Files generated at build-time by the protobuf compiler. | 31 // Files generated at build-time by the protobuf compiler. |
28 #ifdef WEBRTC_ANDROID_PLATFORM_BUILD | 32 #ifdef WEBRTC_ANDROID_PLATFORM_BUILD |
29 #include "external/webrtc/webrtc/call/rtc_event_log.pb.h" | 33 #include "external/webrtc/webrtc/call/rtc_event_log.pb.h" |
30 #else | 34 #else |
31 #include "webrtc/call/rtc_event_log.pb.h" | 35 #include "webrtc/call/rtc_event_log.pb.h" |
32 #endif | 36 #endif |
33 #endif | 37 #endif |
34 | 38 |
35 namespace webrtc { | 39 namespace webrtc { |
36 | 40 |
37 #ifndef ENABLE_RTC_EVENT_LOG | 41 #ifndef ENABLE_RTC_EVENT_LOG |
38 | 42 |
39 // No-op implementation if flag is not set. | 43 // No-op implementation if flag is not set. |
40 class RtcEventLogImpl final : public RtcEventLog { | 44 class RtcEventLogNullImpl final : public RtcEventLog { |
41 public: | 45 public: |
42 void SetBufferDuration(int64_t buffer_duration_us) override {} | 46 bool StartLogging(const std::string& file_name, |
43 void StartLogging(const std::string& file_name, int duration_ms) override {} | 47 int64_t max_size_bytes) override { |
44 bool StartLogging(rtc::PlatformFile log_file) override { return false; } | 48 return false; |
45 void StopLogging(void) override {} | 49 } |
| 50 bool StartLogging(rtc::PlatformFile platform_file, |
| 51 int64_t max_size_bytes) override { |
| 52 return false; |
| 53 } |
| 54 void StopLogging() override {} |
46 void LogVideoReceiveStreamConfig( | 55 void LogVideoReceiveStreamConfig( |
47 const VideoReceiveStream::Config& config) override {} | 56 const VideoReceiveStream::Config& config) override {} |
48 void LogVideoSendStreamConfig( | 57 void LogVideoSendStreamConfig( |
49 const VideoSendStream::Config& config) override {} | 58 const VideoSendStream::Config& config) override {} |
50 void LogRtpHeader(PacketDirection direction, | 59 void LogRtpHeader(PacketDirection direction, |
51 MediaType media_type, | 60 MediaType media_type, |
52 const uint8_t* header, | 61 const uint8_t* header, |
53 size_t packet_length) override {} | 62 size_t packet_length) override {} |
54 void LogRtcpPacket(PacketDirection direction, | 63 void LogRtcpPacket(PacketDirection direction, |
55 MediaType media_type, | 64 MediaType media_type, |
56 const uint8_t* packet, | 65 const uint8_t* packet, |
57 size_t length) override {} | 66 size_t length) override {} |
58 void LogAudioPlayout(uint32_t ssrc) override {} | 67 void LogAudioPlayout(uint32_t ssrc) override {} |
59 void LogBwePacketLossEvent(int32_t bitrate, | 68 void LogBwePacketLossEvent(int32_t bitrate, |
60 uint8_t fraction_loss, | 69 uint8_t fraction_loss, |
61 int32_t total_packets) override {} | 70 int32_t total_packets) override {} |
62 }; | 71 }; |
63 | 72 |
64 #else // ENABLE_RTC_EVENT_LOG is defined | 73 #else // ENABLE_RTC_EVENT_LOG is defined |
65 | 74 |
66 class RtcEventLogImpl final : public RtcEventLog { | 75 class RtcEventLogImpl final : public RtcEventLog { |
67 public: | 76 public: |
68 RtcEventLogImpl(); | 77 explicit RtcEventLogImpl(const Clock* clock); |
| 78 ~RtcEventLogImpl() override; |
69 | 79 |
70 void SetBufferDuration(int64_t buffer_duration_us) override; | 80 bool StartLogging(const std::string& file_name, |
71 void StartLogging(const std::string& file_name, int duration_ms) override; | 81 int64_t max_size_bytes) override; |
72 bool StartLogging(rtc::PlatformFile log_file) override; | 82 bool StartLogging(rtc::PlatformFile platform_file, |
| 83 int64_t max_size_bytes) override; |
73 void StopLogging() override; | 84 void StopLogging() override; |
74 void LogVideoReceiveStreamConfig( | 85 void LogVideoReceiveStreamConfig( |
75 const VideoReceiveStream::Config& config) override; | 86 const VideoReceiveStream::Config& config) override; |
76 void LogVideoSendStreamConfig(const VideoSendStream::Config& config) override; | 87 void LogVideoSendStreamConfig(const VideoSendStream::Config& config) override; |
77 void LogRtpHeader(PacketDirection direction, | 88 void LogRtpHeader(PacketDirection direction, |
78 MediaType media_type, | 89 MediaType media_type, |
79 const uint8_t* header, | 90 const uint8_t* header, |
80 size_t packet_length) override; | 91 size_t packet_length) override; |
81 void LogRtcpPacket(PacketDirection direction, | 92 void LogRtcpPacket(PacketDirection direction, |
82 MediaType media_type, | 93 MediaType media_type, |
83 const uint8_t* packet, | 94 const uint8_t* packet, |
84 size_t length) override; | 95 size_t length) override; |
85 void LogAudioPlayout(uint32_t ssrc) override; | 96 void LogAudioPlayout(uint32_t ssrc) override; |
86 void LogBwePacketLossEvent(int32_t bitrate, | 97 void LogBwePacketLossEvent(int32_t bitrate, |
87 uint8_t fraction_loss, | 98 uint8_t fraction_loss, |
88 int32_t total_packets) override; | 99 int32_t total_packets) override; |
89 | 100 |
90 private: | 101 private: |
91 // Starts logging. This function assumes the file_ has been opened succesfully | 102 // Message queue for passing control messages to the logging thread. |
92 // and that the start_time_us_ and _duration_us_ have been set. | 103 SwapQueue<RtcEventLogHelperThread::ControlMessage> message_queue_; |
93 void StartLoggingLocked() EXCLUSIVE_LOCKS_REQUIRED(crit_); | |
94 // Stops logging and clears the stored data and buffers. | |
95 void StopLoggingLocked() EXCLUSIVE_LOCKS_REQUIRED(crit_); | |
96 // Adds a new event to the logfile if logging is active, or adds it to the | |
97 // list of recent log events otherwise. | |
98 void HandleEvent(rtclog::Event* event) EXCLUSIVE_LOCKS_REQUIRED(crit_); | |
99 // Writes the event to the file. Note that this will destroy the state of the | |
100 // input argument. | |
101 void StoreToFile(rtclog::Event* event) EXCLUSIVE_LOCKS_REQUIRED(crit_); | |
102 // Adds the event to the list of recent events, and removes any events that | |
103 // are too old and no longer fall in the time window. | |
104 void AddRecentEvent(const rtclog::Event& event) | |
105 EXCLUSIVE_LOCKS_REQUIRED(crit_); | |
106 | 104 |
107 rtc::CriticalSection crit_; | 105 // Message queue for passing events to the logging thread. |
108 std::unique_ptr<FileWrapper> file_ GUARDED_BY(crit_) = | 106 SwapQueue<std::unique_ptr<rtclog::Event> > event_queue_; |
109 std::unique_ptr<FileWrapper>(FileWrapper::Create()); | |
110 rtc::PlatformFile platform_file_ GUARDED_BY(crit_) = | |
111 rtc::kInvalidPlatformFileValue; | |
112 rtclog::EventStream stream_ GUARDED_BY(crit_); | |
113 std::deque<rtclog::Event> recent_log_events_ GUARDED_BY(crit_); | |
114 std::vector<rtclog::Event> config_events_ GUARDED_BY(crit_); | |
115 | 107 |
116 // Microseconds to record log events, before starting the actual log. | 108 rtc::Event wake_up_; |
117 int64_t buffer_duration_us_ GUARDED_BY(crit_); | 109 rtc::Event stopped_; |
118 bool currently_logging_ GUARDED_BY(crit_); | 110 |
119 int64_t start_time_us_ GUARDED_BY(crit_); | |
120 int64_t duration_us_ GUARDED_BY(crit_); | |
121 const Clock* const clock_; | 111 const Clock* const clock_; |
| 112 |
| 113 RtcEventLogHelperThread helper_thread_; |
| 114 rtc::ThreadChecker thread_checker_; |
| 115 |
| 116 RTC_DISALLOW_IMPLICIT_CONSTRUCTORS(RtcEventLogImpl); |
122 }; | 117 }; |
123 | 118 |
124 namespace { | 119 namespace { |
125 // The functions in this namespace convert enums from the runtime format | 120 // The functions in this namespace convert enums from the runtime format |
126 // that the rest of the WebRtc project can use, to the corresponding | 121 // that the rest of the WebRtc project can use, to the corresponding |
127 // serialized enum which is defined by the protobuf. | 122 // serialized enum which is defined by the protobuf. |
128 | 123 |
129 // Do not add default return values to the conversion functions in this | |
130 // unnamed namespace. The intention is to make the compiler warn if anyone | |
131 // adds unhandled new events/modes/etc. | |
132 | |
133 rtclog::VideoReceiveConfig_RtcpMode ConvertRtcpMode(RtcpMode rtcp_mode) { | 124 rtclog::VideoReceiveConfig_RtcpMode ConvertRtcpMode(RtcpMode rtcp_mode) { |
134 switch (rtcp_mode) { | 125 switch (rtcp_mode) { |
135 case RtcpMode::kCompound: | 126 case RtcpMode::kCompound: |
136 return rtclog::VideoReceiveConfig::RTCP_COMPOUND; | 127 return rtclog::VideoReceiveConfig::RTCP_COMPOUND; |
137 case RtcpMode::kReducedSize: | 128 case RtcpMode::kReducedSize: |
138 return rtclog::VideoReceiveConfig::RTCP_REDUCEDSIZE; | 129 return rtclog::VideoReceiveConfig::RTCP_REDUCEDSIZE; |
139 case RtcpMode::kOff: | 130 case RtcpMode::kOff: |
140 RTC_NOTREACHED(); | 131 RTC_NOTREACHED(); |
141 return rtclog::VideoReceiveConfig::RTCP_COMPOUND; | 132 return rtclog::VideoReceiveConfig::RTCP_COMPOUND; |
142 } | 133 } |
143 RTC_NOTREACHED(); | 134 RTC_NOTREACHED(); |
144 return rtclog::VideoReceiveConfig::RTCP_COMPOUND; | 135 return rtclog::VideoReceiveConfig::RTCP_COMPOUND; |
145 } | 136 } |
146 | 137 |
147 rtclog::MediaType ConvertMediaType(MediaType media_type) { | 138 rtclog::MediaType ConvertMediaType(MediaType media_type) { |
148 switch (media_type) { | 139 switch (media_type) { |
149 case MediaType::ANY: | 140 case MediaType::ANY: |
150 return rtclog::MediaType::ANY; | 141 return rtclog::MediaType::ANY; |
151 case MediaType::AUDIO: | 142 case MediaType::AUDIO: |
152 return rtclog::MediaType::AUDIO; | 143 return rtclog::MediaType::AUDIO; |
153 case MediaType::VIDEO: | 144 case MediaType::VIDEO: |
154 return rtclog::MediaType::VIDEO; | 145 return rtclog::MediaType::VIDEO; |
155 case MediaType::DATA: | 146 case MediaType::DATA: |
156 return rtclog::MediaType::DATA; | 147 return rtclog::MediaType::DATA; |
157 } | 148 } |
158 RTC_NOTREACHED(); | 149 RTC_NOTREACHED(); |
159 return rtclog::ANY; | 150 return rtclog::ANY; |
160 } | 151 } |
161 | 152 |
162 } // namespace | 153 // The RTP and RTCP buffers reserve space for twice the expected number of |
163 | 154 // sent packets because they also contain received packets. |
164 namespace { | 155 static const int kEventsPerSecond = 1000; |
165 bool IsConfigEvent(const rtclog::Event& event) { | 156 static const int kControlMessagesPerSecond = 10; |
166 rtclog::Event_EventType event_type = event.type(); | |
167 return event_type == rtclog::Event::VIDEO_RECEIVER_CONFIG_EVENT || | |
168 event_type == rtclog::Event::VIDEO_SENDER_CONFIG_EVENT || | |
169 event_type == rtclog::Event::AUDIO_RECEIVER_CONFIG_EVENT || | |
170 event_type == rtclog::Event::AUDIO_SENDER_CONFIG_EVENT; | |
171 } | |
172 } // namespace | 157 } // namespace |
173 | 158 |
174 // RtcEventLogImpl member functions. | 159 // RtcEventLogImpl member functions. |
175 RtcEventLogImpl::RtcEventLogImpl() | 160 RtcEventLogImpl::RtcEventLogImpl(const Clock* clock) |
176 : file_(FileWrapper::Create()), | 161 // Allocate buffers for roughly one second of history. |
177 stream_(), | 162 : message_queue_(kControlMessagesPerSecond), |
178 buffer_duration_us_(10000000), | 163 event_queue_(kEventsPerSecond), |
179 currently_logging_(false), | 164 wake_up_(false, false), |
180 start_time_us_(0), | 165 stopped_(false, false), |
181 duration_us_(0), | 166 clock_(clock), |
182 clock_(Clock::GetRealTimeClock()) { | 167 helper_thread_(&message_queue_, |
| 168 &event_queue_, |
| 169 &wake_up_, |
| 170 &stopped_, |
| 171 clock), |
| 172 thread_checker_() { |
| 173 thread_checker_.DetachFromThread(); |
183 } | 174 } |
184 | 175 |
185 void RtcEventLogImpl::SetBufferDuration(int64_t buffer_duration_us) { | 176 RtcEventLogImpl::~RtcEventLogImpl() { |
186 rtc::CritScope lock(&crit_); | 177 // The RtcEventLogHelperThread destructor closes the file |
187 buffer_duration_us_ = buffer_duration_us; | 178 // and waits for the thread to terminate. |
188 } | 179 } |
189 | 180 |
190 void RtcEventLogImpl::StartLogging(const std::string& file_name, | 181 bool RtcEventLogImpl::StartLogging(const std::string& file_name, |
191 int duration_ms) { | 182 int64_t max_size_bytes) { |
192 rtc::CritScope lock(&crit_); | 183 RTC_DCHECK(thread_checker_.CalledOnValidThread()); |
193 if (currently_logging_) { | 184 RtcEventLogHelperThread::ControlMessage message; |
194 StopLoggingLocked(); | 185 message.message_type = RtcEventLogHelperThread::ControlMessage::START_FILE; |
195 } | 186 message.max_size_bytes = max_size_bytes; |
196 if (file_->OpenFile(file_name.c_str(), false) != 0) { | 187 message.start_time = clock_->TimeInMicroseconds(); |
197 return; | 188 message.stop_time = std::numeric_limits<int64_t>::max(); |
198 } | 189 message.file.reset(FileWrapper::Create()); |
199 start_time_us_ = clock_->TimeInMicroseconds(); | 190 if (message.file->OpenFile(file_name.c_str(), false) != 0) { |
200 duration_us_ = static_cast<int64_t>(duration_ms) * 1000; | |
201 StartLoggingLocked(); | |
202 } | |
203 | |
204 bool RtcEventLogImpl::StartLogging(rtc::PlatformFile log_file) { | |
205 rtc::CritScope lock(&crit_); | |
206 | |
207 if (currently_logging_) { | |
208 StopLoggingLocked(); | |
209 } | |
210 RTC_DCHECK(platform_file_ == rtc::kInvalidPlatformFileValue); | |
211 | |
212 FILE* file_stream = rtc::FdopenPlatformFileForWriting(log_file); | |
213 if (!file_stream) { | |
214 rtc::ClosePlatformFile(log_file); | |
215 return false; | 191 return false; |
216 } | 192 } |
217 | 193 if (!message_queue_.Insert(&message)) { |
218 if (file_->OpenFromFileHandle(file_stream, true, false) != 0) { | 194 LOG(LS_WARNING) << "Message queue full. Can't start logging."; |
219 rtc::ClosePlatformFile(log_file); | |
220 return false; | 195 return false; |
221 } | 196 } |
222 platform_file_ = log_file; | |
223 // Set the start time and duration to keep logging for 10 minutes. | |
224 start_time_us_ = clock_->TimeInMicroseconds(); | |
225 duration_us_ = 10 * 60 * 1000000; | |
226 StartLoggingLocked(); | |
227 return true; | 197 return true; |
228 } | 198 } |
229 | 199 |
230 void RtcEventLogImpl::StartLoggingLocked() { | 200 bool RtcEventLogImpl::StartLogging(rtc::PlatformFile platform_file, |
231 currently_logging_ = true; | 201 int64_t max_size_bytes) { |
232 | 202 RTC_DCHECK(thread_checker_.CalledOnValidThread()); |
233 // Write all old configuration events to the log file. | 203 RtcEventLogHelperThread::ControlMessage message; |
234 for (auto& event : config_events_) { | 204 message.message_type = RtcEventLogHelperThread::ControlMessage::START_FILE; |
235 StoreToFile(&event); | 205 message.max_size_bytes = max_size_bytes; |
| 206 message.start_time = clock_->TimeInMicroseconds(); |
| 207 message.stop_time = std::numeric_limits<int64_t>::max(); |
| 208 message.file.reset(FileWrapper::Create()); |
| 209 FILE* file_handle = rtc::FdopenPlatformFileForWriting(platform_file); |
| 210 if (!file_handle) { |
| 211 return false; |
236 } | 212 } |
237 // Write all recent configuration events to the log file, and | 213 if (message.file->OpenFromFileHandle(file_handle, true, false) != 0) { |
238 // write all other recent events to the log file, ignoring any old events. | 214 return false; |
239 for (auto& event : recent_log_events_) { | |
240 if (IsConfigEvent(event)) { | |
241 StoreToFile(&event); | |
242 config_events_.push_back(event); | |
243 } else if (event.timestamp_us() >= start_time_us_ - buffer_duration_us_) { | |
244 StoreToFile(&event); | |
245 } | |
246 } | 215 } |
247 recent_log_events_.clear(); | 216 if (!message_queue_.Insert(&message)) { |
248 // Write a LOG_START event to the file. | 217 LOG(LS_WARNING) << "Message queue full. Can't start logging."; |
249 rtclog::Event start_event; | 218 return false; |
250 start_event.set_timestamp_us(start_time_us_); | 219 } |
251 start_event.set_type(rtclog::Event::LOG_START); | 220 return true; |
252 StoreToFile(&start_event); | |
253 } | 221 } |
254 | 222 |
255 void RtcEventLogImpl::StopLogging() { | 223 void RtcEventLogImpl::StopLogging() { |
256 rtc::CritScope lock(&crit_); | 224 RTC_DCHECK(thread_checker_.CalledOnValidThread()); |
257 StopLoggingLocked(); | 225 RtcEventLogHelperThread::ControlMessage message; |
| 226 message.message_type = RtcEventLogHelperThread::ControlMessage::STOP_FILE; |
| 227 message.stop_time = clock_->TimeInMicroseconds(); |
| 228 while (!message_queue_.Insert(&message)) { |
| 229 // TODO(terelius): We would like to have a blocking Insert function in the |
| 230 // SwapQueue, but for the time being we will just clear any previous |
| 231 // messages. |
| 232 // Since StopLogging waits for the thread, it is essential that we don't |
| 233 // clear any STOP_FILE messages. To ensure that there is only one call at a |
| 234 // time, we require that all calls to StopLogging are made on the same |
| 235 // thread. |
| 236 LOG(LS_WARNING) << "Message queue full. Clearing queue to stop logging."; |
| 237 message_queue_.Clear(); |
| 238 } |
| 239 wake_up_.Set(); // Request the output thread to wake up. |
| 240 stopped_.Wait(rtc::Event::kForever); // Wait for the log to stop. |
258 } | 241 } |
259 | 242 |
260 void RtcEventLogImpl::LogVideoReceiveStreamConfig( | 243 void RtcEventLogImpl::LogVideoReceiveStreamConfig( |
261 const VideoReceiveStream::Config& config) { | 244 const VideoReceiveStream::Config& config) { |
262 rtc::CritScope lock(&crit_); | 245 std::unique_ptr<rtclog::Event> event(new rtclog::Event()); |
263 | 246 event->set_timestamp_us(clock_->TimeInMicroseconds()); |
264 rtclog::Event event; | 247 event->set_type(rtclog::Event::VIDEO_RECEIVER_CONFIG_EVENT); |
265 event.set_timestamp_us(clock_->TimeInMicroseconds()); | |
266 event.set_type(rtclog::Event::VIDEO_RECEIVER_CONFIG_EVENT); | |
267 | 248 |
268 rtclog::VideoReceiveConfig* receiver_config = | 249 rtclog::VideoReceiveConfig* receiver_config = |
269 event.mutable_video_receiver_config(); | 250 event->mutable_video_receiver_config(); |
270 receiver_config->set_remote_ssrc(config.rtp.remote_ssrc); | 251 receiver_config->set_remote_ssrc(config.rtp.remote_ssrc); |
271 receiver_config->set_local_ssrc(config.rtp.local_ssrc); | 252 receiver_config->set_local_ssrc(config.rtp.local_ssrc); |
272 | 253 |
273 receiver_config->set_rtcp_mode(ConvertRtcpMode(config.rtp.rtcp_mode)); | 254 receiver_config->set_rtcp_mode(ConvertRtcpMode(config.rtp.rtcp_mode)); |
274 receiver_config->set_remb(config.rtp.remb); | 255 receiver_config->set_remb(config.rtp.remb); |
275 | 256 |
276 for (const auto& kv : config.rtp.rtx) { | 257 for (const auto& kv : config.rtp.rtx) { |
277 rtclog::RtxMap* rtx = receiver_config->add_rtx_map(); | 258 rtclog::RtxMap* rtx = receiver_config->add_rtx_map(); |
278 rtx->set_payload_type(kv.first); | 259 rtx->set_payload_type(kv.first); |
279 rtx->mutable_config()->set_rtx_ssrc(kv.second.ssrc); | 260 rtx->mutable_config()->set_rtx_ssrc(kv.second.ssrc); |
280 rtx->mutable_config()->set_rtx_payload_type(kv.second.payload_type); | 261 rtx->mutable_config()->set_rtx_payload_type(kv.second.payload_type); |
281 } | 262 } |
282 | 263 |
283 for (const auto& e : config.rtp.extensions) { | 264 for (const auto& e : config.rtp.extensions) { |
284 rtclog::RtpHeaderExtension* extension = | 265 rtclog::RtpHeaderExtension* extension = |
285 receiver_config->add_header_extensions(); | 266 receiver_config->add_header_extensions(); |
286 extension->set_name(e.name); | 267 extension->set_name(e.name); |
287 extension->set_id(e.id); | 268 extension->set_id(e.id); |
288 } | 269 } |
289 | 270 |
290 for (const auto& d : config.decoders) { | 271 for (const auto& d : config.decoders) { |
291 rtclog::DecoderConfig* decoder = receiver_config->add_decoders(); | 272 rtclog::DecoderConfig* decoder = receiver_config->add_decoders(); |
292 decoder->set_name(d.payload_name); | 273 decoder->set_name(d.payload_name); |
293 decoder->set_payload_type(d.payload_type); | 274 decoder->set_payload_type(d.payload_type); |
294 } | 275 } |
295 HandleEvent(&event); | 276 if (!event_queue_.Insert(&event)) { |
| 277 LOG(LS_WARNING) << "Config queue full. Not logging config event."; |
| 278 } |
296 } | 279 } |
297 | 280 |
298 void RtcEventLogImpl::LogVideoSendStreamConfig( | 281 void RtcEventLogImpl::LogVideoSendStreamConfig( |
299 const VideoSendStream::Config& config) { | 282 const VideoSendStream::Config& config) { |
300 rtc::CritScope lock(&crit_); | 283 std::unique_ptr<rtclog::Event> event(new rtclog::Event()); |
| 284 event->set_timestamp_us(clock_->TimeInMicroseconds()); |
| 285 event->set_type(rtclog::Event::VIDEO_SENDER_CONFIG_EVENT); |
301 | 286 |
302 rtclog::Event event; | 287 rtclog::VideoSendConfig* sender_config = event->mutable_video_sender_config(); |
303 event.set_timestamp_us(clock_->TimeInMicroseconds()); | |
304 event.set_type(rtclog::Event::VIDEO_SENDER_CONFIG_EVENT); | |
305 | |
306 rtclog::VideoSendConfig* sender_config = event.mutable_video_sender_config(); | |
307 | 288 |
308 for (const auto& ssrc : config.rtp.ssrcs) { | 289 for (const auto& ssrc : config.rtp.ssrcs) { |
309 sender_config->add_ssrcs(ssrc); | 290 sender_config->add_ssrcs(ssrc); |
310 } | 291 } |
311 | 292 |
312 for (const auto& e : config.rtp.extensions) { | 293 for (const auto& e : config.rtp.extensions) { |
313 rtclog::RtpHeaderExtension* extension = | 294 rtclog::RtpHeaderExtension* extension = |
314 sender_config->add_header_extensions(); | 295 sender_config->add_header_extensions(); |
315 extension->set_name(e.name); | 296 extension->set_name(e.name); |
316 extension->set_id(e.id); | 297 extension->set_id(e.id); |
317 } | 298 } |
318 | 299 |
319 for (const auto& rtx_ssrc : config.rtp.rtx.ssrcs) { | 300 for (const auto& rtx_ssrc : config.rtp.rtx.ssrcs) { |
320 sender_config->add_rtx_ssrcs(rtx_ssrc); | 301 sender_config->add_rtx_ssrcs(rtx_ssrc); |
321 } | 302 } |
322 sender_config->set_rtx_payload_type(config.rtp.rtx.payload_type); | 303 sender_config->set_rtx_payload_type(config.rtp.rtx.payload_type); |
323 | 304 |
324 rtclog::EncoderConfig* encoder = sender_config->mutable_encoder(); | 305 rtclog::EncoderConfig* encoder = sender_config->mutable_encoder(); |
325 encoder->set_name(config.encoder_settings.payload_name); | 306 encoder->set_name(config.encoder_settings.payload_name); |
326 encoder->set_payload_type(config.encoder_settings.payload_type); | 307 encoder->set_payload_type(config.encoder_settings.payload_type); |
327 HandleEvent(&event); | 308 if (!event_queue_.Insert(&event)) { |
| 309 LOG(LS_WARNING) << "Config queue full. Not logging config event."; |
| 310 } |
328 } | 311 } |
329 | 312 |
330 void RtcEventLogImpl::LogRtpHeader(PacketDirection direction, | 313 void RtcEventLogImpl::LogRtpHeader(PacketDirection direction, |
331 MediaType media_type, | 314 MediaType media_type, |
332 const uint8_t* header, | 315 const uint8_t* header, |
333 size_t packet_length) { | 316 size_t packet_length) { |
334 // Read header length (in bytes) from packet data. | 317 // Read header length (in bytes) from packet data. |
335 if (packet_length < 12u) { | 318 if (packet_length < 12u) { |
336 return; // Don't read outside the packet. | 319 return; // Don't read outside the packet. |
337 } | 320 } |
338 const bool x = (header[0] & 0x10) != 0; | 321 const bool x = (header[0] & 0x10) != 0; |
339 const uint8_t cc = header[0] & 0x0f; | 322 const uint8_t cc = header[0] & 0x0f; |
340 size_t header_length = 12u + cc * 4u; | 323 size_t header_length = 12u + cc * 4u; |
341 | 324 |
342 if (x) { | 325 if (x) { |
343 if (packet_length < 12u + cc * 4u + 4u) { | 326 if (packet_length < 12u + cc * 4u + 4u) { |
344 return; // Don't read outside the packet. | 327 return; // Don't read outside the packet. |
345 } | 328 } |
346 size_t x_len = ByteReader<uint16_t>::ReadBigEndian(header + 14 + cc * 4); | 329 size_t x_len = ByteReader<uint16_t>::ReadBigEndian(header + 14 + cc * 4); |
347 header_length += (x_len + 1) * 4; | 330 header_length += (x_len + 1) * 4; |
348 } | 331 } |
349 | 332 |
350 rtc::CritScope lock(&crit_); | 333 std::unique_ptr<rtclog::Event> rtp_event(new rtclog::Event()); |
351 rtclog::Event rtp_event; | 334 rtp_event->set_timestamp_us(clock_->TimeInMicroseconds()); |
352 rtp_event.set_timestamp_us(clock_->TimeInMicroseconds()); | 335 rtp_event->set_type(rtclog::Event::RTP_EVENT); |
353 rtp_event.set_type(rtclog::Event::RTP_EVENT); | 336 rtp_event->mutable_rtp_packet()->set_incoming(direction == kIncomingPacket); |
354 rtp_event.mutable_rtp_packet()->set_incoming(direction == kIncomingPacket); | 337 rtp_event->mutable_rtp_packet()->set_type(ConvertMediaType(media_type)); |
355 rtp_event.mutable_rtp_packet()->set_type(ConvertMediaType(media_type)); | 338 rtp_event->mutable_rtp_packet()->set_packet_length(packet_length); |
356 rtp_event.mutable_rtp_packet()->set_packet_length(packet_length); | 339 rtp_event->mutable_rtp_packet()->set_header(header, header_length); |
357 rtp_event.mutable_rtp_packet()->set_header(header, header_length); | 340 if (!event_queue_.Insert(&rtp_event)) { |
358 HandleEvent(&rtp_event); | 341 LOG(LS_WARNING) << "RTP queue full. Not logging RTP packet."; |
| 342 } |
359 } | 343 } |
360 | 344 |
361 void RtcEventLogImpl::LogRtcpPacket(PacketDirection direction, | 345 void RtcEventLogImpl::LogRtcpPacket(PacketDirection direction, |
362 MediaType media_type, | 346 MediaType media_type, |
363 const uint8_t* packet, | 347 const uint8_t* packet, |
364 size_t length) { | 348 size_t length) { |
365 rtc::CritScope lock(&crit_); | 349 std::unique_ptr<rtclog::Event> rtcp_event(new rtclog::Event()); |
366 rtclog::Event rtcp_event; | 350 rtcp_event->set_timestamp_us(clock_->TimeInMicroseconds()); |
367 rtcp_event.set_timestamp_us(clock_->TimeInMicroseconds()); | 351 rtcp_event->set_type(rtclog::Event::RTCP_EVENT); |
368 rtcp_event.set_type(rtclog::Event::RTCP_EVENT); | 352 rtcp_event->mutable_rtcp_packet()->set_incoming(direction == kIncomingPacket); |
369 rtcp_event.mutable_rtcp_packet()->set_incoming(direction == kIncomingPacket); | 353 rtcp_event->mutable_rtcp_packet()->set_type(ConvertMediaType(media_type)); |
370 rtcp_event.mutable_rtcp_packet()->set_type(ConvertMediaType(media_type)); | |
371 | 354 |
372 RTCPUtility::RtcpCommonHeader header; | 355 RTCPUtility::RtcpCommonHeader header; |
373 const uint8_t* block_begin = packet; | 356 const uint8_t* block_begin = packet; |
374 const uint8_t* packet_end = packet + length; | 357 const uint8_t* packet_end = packet + length; |
375 RTC_DCHECK(length <= IP_PACKET_SIZE); | 358 RTC_DCHECK(length <= IP_PACKET_SIZE); |
376 uint8_t buffer[IP_PACKET_SIZE]; | 359 uint8_t buffer[IP_PACKET_SIZE]; |
377 uint32_t buffer_length = 0; | 360 uint32_t buffer_length = 0; |
378 while (block_begin < packet_end) { | 361 while (block_begin < packet_end) { |
379 if (!RtcpParseCommonHeader(block_begin, packet_end - block_begin, | 362 if (!RtcpParseCommonHeader(block_begin, packet_end - block_begin, |
380 &header)) { | 363 &header)) { |
(...skipping 25 matching lines...) Expand all Loading... |
406 case RTCPUtility::PT_APP: | 389 case RTCPUtility::PT_APP: |
407 FALLTHROUGH(); | 390 FALLTHROUGH(); |
408 default: | 391 default: |
409 // We don't log sender descriptions, application defined messages | 392 // We don't log sender descriptions, application defined messages |
410 // or message blocks of unknown type. | 393 // or message blocks of unknown type. |
411 break; | 394 break; |
412 } | 395 } |
413 | 396 |
414 block_begin += block_size; | 397 block_begin += block_size; |
415 } | 398 } |
416 rtcp_event.mutable_rtcp_packet()->set_packet_data(buffer, buffer_length); | 399 rtcp_event->mutable_rtcp_packet()->set_packet_data(buffer, buffer_length); |
417 HandleEvent(&rtcp_event); | 400 if (!event_queue_.Insert(&rtcp_event)) { |
| 401 LOG(LS_WARNING) << "RTCP queue full. Not logging RTCP packet."; |
| 402 } |
418 } | 403 } |
419 | 404 |
420 void RtcEventLogImpl::LogAudioPlayout(uint32_t ssrc) { | 405 void RtcEventLogImpl::LogAudioPlayout(uint32_t ssrc) { |
421 rtc::CritScope lock(&crit_); | 406 std::unique_ptr<rtclog::Event> event(new rtclog::Event()); |
422 rtclog::Event event; | 407 event->set_timestamp_us(clock_->TimeInMicroseconds()); |
423 event.set_timestamp_us(clock_->TimeInMicroseconds()); | 408 event->set_type(rtclog::Event::AUDIO_PLAYOUT_EVENT); |
424 event.set_type(rtclog::Event::AUDIO_PLAYOUT_EVENT); | 409 auto playout_event = event->mutable_audio_playout_event(); |
425 auto playout_event = event.mutable_audio_playout_event(); | |
426 playout_event->set_local_ssrc(ssrc); | 410 playout_event->set_local_ssrc(ssrc); |
427 HandleEvent(&event); | 411 if (!event_queue_.Insert(&event)) { |
| 412 LOG(LS_WARNING) << "Playout queue full. Not logging ACM playout."; |
| 413 } |
428 } | 414 } |
429 | 415 |
430 void RtcEventLogImpl::LogBwePacketLossEvent(int32_t bitrate, | 416 void RtcEventLogImpl::LogBwePacketLossEvent(int32_t bitrate, |
431 uint8_t fraction_loss, | 417 uint8_t fraction_loss, |
432 int32_t total_packets) { | 418 int32_t total_packets) { |
433 rtc::CritScope lock(&crit_); | 419 std::unique_ptr<rtclog::Event> event(new rtclog::Event()); |
434 rtclog::Event event; | 420 event->set_timestamp_us(clock_->TimeInMicroseconds()); |
435 event.set_timestamp_us(clock_->TimeInMicroseconds()); | 421 event->set_type(rtclog::Event::BWE_PACKET_LOSS_EVENT); |
436 event.set_type(rtclog::Event::BWE_PACKET_LOSS_EVENT); | 422 auto bwe_event = event->mutable_bwe_packet_loss_event(); |
437 auto bwe_event = event.mutable_bwe_packet_loss_event(); | |
438 bwe_event->set_bitrate(bitrate); | 423 bwe_event->set_bitrate(bitrate); |
439 bwe_event->set_fraction_loss(fraction_loss); | 424 bwe_event->set_fraction_loss(fraction_loss); |
440 bwe_event->set_total_packets(total_packets); | 425 bwe_event->set_total_packets(total_packets); |
441 HandleEvent(&event); | 426 if (!event_queue_.Insert(&event)) { |
442 } | 427 LOG(LS_WARNING) << "BWE loss queue full. Not logging BWE update."; |
443 | |
444 void RtcEventLogImpl::StopLoggingLocked() { | |
445 if (currently_logging_) { | |
446 currently_logging_ = false; | |
447 // Create a LogEnd event | |
448 rtclog::Event event; | |
449 event.set_timestamp_us(clock_->TimeInMicroseconds()); | |
450 event.set_type(rtclog::Event::LOG_END); | |
451 // Store the event and close the file | |
452 RTC_DCHECK(file_->Open()); | |
453 StoreToFile(&event); | |
454 file_->CloseFile(); | |
455 if (platform_file_ != rtc::kInvalidPlatformFileValue) { | |
456 rtc::ClosePlatformFile(platform_file_); | |
457 platform_file_ = rtc::kInvalidPlatformFileValue; | |
458 } | |
459 } | |
460 RTC_DCHECK(!file_->Open()); | |
461 stream_.Clear(); | |
462 } | |
463 | |
464 void RtcEventLogImpl::HandleEvent(rtclog::Event* event) { | |
465 if (currently_logging_) { | |
466 if (clock_->TimeInMicroseconds() < start_time_us_ + duration_us_) { | |
467 StoreToFile(event); | |
468 return; | |
469 } | |
470 StopLoggingLocked(); | |
471 } | |
472 AddRecentEvent(*event); | |
473 } | |
474 | |
475 void RtcEventLogImpl::StoreToFile(rtclog::Event* event) { | |
476 // Reuse the same object at every log event. | |
477 if (stream_.stream_size() < 1) { | |
478 stream_.add_stream(); | |
479 } | |
480 RTC_DCHECK_EQ(stream_.stream_size(), 1); | |
481 stream_.mutable_stream(0)->Swap(event); | |
482 // TODO(terelius): Doesn't this create a new EventStream per event? | |
483 // Is this guaranteed to work e.g. in future versions of protobuf? | |
484 std::string dump_buffer; | |
485 stream_.SerializeToString(&dump_buffer); | |
486 file_->Write(dump_buffer.data(), dump_buffer.size()); | |
487 } | |
488 | |
489 void RtcEventLogImpl::AddRecentEvent(const rtclog::Event& event) { | |
490 recent_log_events_.push_back(event); | |
491 while (recent_log_events_.front().timestamp_us() < | |
492 event.timestamp_us() - buffer_duration_us_) { | |
493 if (IsConfigEvent(recent_log_events_.front())) { | |
494 config_events_.push_back(recent_log_events_.front()); | |
495 } | |
496 recent_log_events_.pop_front(); | |
497 } | 428 } |
498 } | 429 } |
499 | 430 |
500 bool RtcEventLog::ParseRtcEventLog(const std::string& file_name, | 431 bool RtcEventLog::ParseRtcEventLog(const std::string& file_name, |
501 rtclog::EventStream* result) { | 432 rtclog::EventStream* result) { |
502 char tmp_buffer[1024]; | 433 char tmp_buffer[1024]; |
503 int bytes_read = 0; | 434 int bytes_read = 0; |
504 std::unique_ptr<FileWrapper> dump_file(FileWrapper::Create()); | 435 std::unique_ptr<FileWrapper> dump_file(FileWrapper::Create()); |
505 if (dump_file->OpenFile(file_name.c_str(), true) != 0) { | 436 if (dump_file->OpenFile(file_name.c_str(), true) != 0) { |
506 return false; | 437 return false; |
507 } | 438 } |
508 std::string dump_buffer; | 439 std::string dump_buffer; |
509 while ((bytes_read = dump_file->Read(tmp_buffer, sizeof(tmp_buffer))) > 0) { | 440 while ((bytes_read = dump_file->Read(tmp_buffer, sizeof(tmp_buffer))) > 0) { |
510 dump_buffer.append(tmp_buffer, bytes_read); | 441 dump_buffer.append(tmp_buffer, bytes_read); |
511 } | 442 } |
512 dump_file->CloseFile(); | 443 dump_file->CloseFile(); |
513 return result->ParseFromString(dump_buffer); | 444 return result->ParseFromString(dump_buffer); |
514 } | 445 } |
515 | 446 |
516 #endif // ENABLE_RTC_EVENT_LOG | 447 #endif // ENABLE_RTC_EVENT_LOG |
517 | 448 |
518 // RtcEventLog member functions. | 449 // RtcEventLog member functions. |
519 std::unique_ptr<RtcEventLog> RtcEventLog::Create() { | 450 std::unique_ptr<RtcEventLog> RtcEventLog::Create(const Clock* clock) { |
520 return std::unique_ptr<RtcEventLog>(new RtcEventLogImpl()); | 451 #ifdef ENABLE_RTC_EVENT_LOG |
| 452 return std::unique_ptr<RtcEventLog>(new RtcEventLogImpl(clock)); |
| 453 #else |
| 454 return std::unique_ptr<RtcEventLog>(new RtcEventLogNullImpl()); |
| 455 #endif // ENABLE_RTC_EVENT_LOG |
521 } | 456 } |
522 | 457 |
523 } // namespace webrtc | 458 } // namespace webrtc |
OLD | NEW |