Line data Source code
1 : /*
2 : * Copyright (c) 2015 The WebRTC project authors. All Rights Reserved.
3 : *
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
6 : * tree. An additional intellectual property rights grant can be found
7 : * in the file PATENTS. All contributing project authors may
8 : * be found in the AUTHORS file in the root of the source tree.
9 : */
10 :
11 : #include "webrtc/logging/rtc_event_log/rtc_event_log.h"
12 :
13 : #include <limits>
14 : #include <vector>
15 :
16 : #include "webrtc/base/checks.h"
17 : #include "webrtc/base/constructormagic.h"
18 : #include "webrtc/base/event.h"
19 : #include "webrtc/base/swap_queue.h"
20 : #include "webrtc/base/thread_checker.h"
21 : #include "webrtc/base/timeutils.h"
22 : #include "webrtc/call/call.h"
23 : #include "webrtc/logging/rtc_event_log/rtc_event_log_helper_thread.h"
24 : #include "webrtc/modules/rtp_rtcp/include/rtp_rtcp_defines.h"
25 : #include "webrtc/modules/rtp_rtcp/source/byte_io.h"
26 : #include "webrtc/modules/rtp_rtcp/source/rtcp_packet/app.h"
27 : #include "webrtc/modules/rtp_rtcp/source/rtcp_packet/bye.h"
28 : #include "webrtc/modules/rtp_rtcp/source/rtcp_packet/common_header.h"
29 : #include "webrtc/modules/rtp_rtcp/source/rtcp_packet/extended_jitter_report.h"
30 : #include "webrtc/modules/rtp_rtcp/source/rtcp_packet/extended_reports.h"
31 : #include "webrtc/modules/rtp_rtcp/source/rtcp_packet/receiver_report.h"
32 : #include "webrtc/modules/rtp_rtcp/source/rtcp_packet/psfb.h"
33 : #include "webrtc/modules/rtp_rtcp/source/rtcp_packet/rtpfb.h"
34 : #include "webrtc/modules/rtp_rtcp/source/rtcp_packet/sdes.h"
35 : #include "webrtc/modules/rtp_rtcp/source/rtcp_packet/sender_report.h"
36 : #include "webrtc/system_wrappers/include/file_wrapper.h"
37 : #include "webrtc/system_wrappers/include/logging.h"
38 :
39 : #ifdef ENABLE_RTC_EVENT_LOG
40 : // Files generated at build-time by the protobuf compiler.
41 : #ifdef WEBRTC_ANDROID_PLATFORM_BUILD
42 : #include "external/webrtc/webrtc/logging/rtc_event_log/rtc_event_log.pb.h"
43 : #else
44 : #include "webrtc/logging/rtc_event_log/rtc_event_log.pb.h"
45 : #endif
46 : #endif
47 :
48 : namespace webrtc {
49 :
50 : #ifdef ENABLE_RTC_EVENT_LOG
51 :
52 : class RtcEventLogImpl final : public RtcEventLog {
53 : public:
54 : RtcEventLogImpl();
55 : ~RtcEventLogImpl() override;
56 :
57 : bool StartLogging(const std::string& file_name,
58 : int64_t max_size_bytes) override;
59 : bool StartLogging(rtc::PlatformFile platform_file,
60 : int64_t max_size_bytes) override;
61 : void StopLogging() override;
62 : void LogVideoReceiveStreamConfig(
63 : const VideoReceiveStream::Config& config) override;
64 : void LogVideoSendStreamConfig(const VideoSendStream::Config& config) override;
65 : void LogAudioReceiveStreamConfig(
66 : const AudioReceiveStream::Config& config) override;
67 : void LogAudioSendStreamConfig(const AudioSendStream::Config& config) override;
68 : void LogRtpHeader(PacketDirection direction,
69 : MediaType media_type,
70 : const uint8_t* header,
71 : size_t packet_length) override;
72 : void LogRtcpPacket(PacketDirection direction,
73 : MediaType media_type,
74 : const uint8_t* packet,
75 : size_t length) override;
76 : void LogAudioPlayout(uint32_t ssrc) override;
77 : void LogBwePacketLossEvent(int32_t bitrate,
78 : uint8_t fraction_loss,
79 : int32_t total_packets) override;
80 :
81 : private:
82 : void StoreEvent(std::unique_ptr<rtclog::Event>* event);
83 :
84 : // Message queue for passing control messages to the logging thread.
85 : SwapQueue<RtcEventLogHelperThread::ControlMessage> message_queue_;
86 :
87 : // Message queue for passing events to the logging thread.
88 : SwapQueue<std::unique_ptr<rtclog::Event> > event_queue_;
89 :
90 : RtcEventLogHelperThread helper_thread_;
91 : rtc::ThreadChecker thread_checker_;
92 :
93 : RTC_DISALLOW_COPY_AND_ASSIGN(RtcEventLogImpl);
94 : };
95 :
96 : namespace {
97 : // The functions in this namespace convert enums from the runtime format
98 : // that the rest of the WebRtc project can use, to the corresponding
99 : // serialized enum which is defined by the protobuf.
100 :
101 : rtclog::VideoReceiveConfig_RtcpMode ConvertRtcpMode(RtcpMode rtcp_mode) {
102 : switch (rtcp_mode) {
103 : case RtcpMode::kCompound:
104 : return rtclog::VideoReceiveConfig::RTCP_COMPOUND;
105 : case RtcpMode::kReducedSize:
106 : return rtclog::VideoReceiveConfig::RTCP_REDUCEDSIZE;
107 : case RtcpMode::kOff:
108 : RTC_NOTREACHED();
109 : return rtclog::VideoReceiveConfig::RTCP_COMPOUND;
110 : }
111 : RTC_NOTREACHED();
112 : return rtclog::VideoReceiveConfig::RTCP_COMPOUND;
113 : }
114 :
115 : rtclog::MediaType ConvertMediaType(MediaType media_type) {
116 : switch (media_type) {
117 : case MediaType::ANY:
118 : return rtclog::MediaType::ANY;
119 : case MediaType::AUDIO:
120 : return rtclog::MediaType::AUDIO;
121 : case MediaType::VIDEO:
122 : return rtclog::MediaType::VIDEO;
123 : case MediaType::DATA:
124 : return rtclog::MediaType::DATA;
125 : }
126 : RTC_NOTREACHED();
127 : return rtclog::ANY;
128 : }
129 :
130 : // The RTP and RTCP buffers reserve space for twice the expected number of
131 : // sent packets because they also contain received packets.
132 : static const int kEventsPerSecond = 1000;
133 : static const int kControlMessagesPerSecond = 10;
134 : } // namespace
135 :
136 : // RtcEventLogImpl member functions.
137 : RtcEventLogImpl::RtcEventLogImpl()
138 : // Allocate buffers for roughly one second of history.
139 : : message_queue_(kControlMessagesPerSecond),
140 : event_queue_(kEventsPerSecond),
141 : helper_thread_(&message_queue_, &event_queue_),
142 : thread_checker_() {
143 : thread_checker_.DetachFromThread();
144 : }
145 :
146 : RtcEventLogImpl::~RtcEventLogImpl() {
147 : // The RtcEventLogHelperThread destructor closes the file
148 : // and waits for the thread to terminate.
149 : }
150 :
151 : bool RtcEventLogImpl::StartLogging(const std::string& file_name,
152 : int64_t max_size_bytes) {
153 : RTC_DCHECK(thread_checker_.CalledOnValidThread());
154 : RtcEventLogHelperThread::ControlMessage message;
155 : message.message_type = RtcEventLogHelperThread::ControlMessage::START_FILE;
156 : message.max_size_bytes = max_size_bytes <= 0
157 : ? std::numeric_limits<int64_t>::max()
158 : : max_size_bytes;
159 : message.start_time = rtc::TimeMicros();
160 : message.stop_time = std::numeric_limits<int64_t>::max();
161 : message.file.reset(FileWrapper::Create());
162 : if (!message.file->OpenFile(file_name.c_str(), false)) {
163 : LOG(LS_ERROR) << "Can't open file. WebRTC event log not started.";
164 : return false;
165 : }
166 : if (!message_queue_.Insert(&message)) {
167 : LOG(LS_ERROR) << "Message queue full. Can't start logging.";
168 : return false;
169 : }
170 : helper_thread_.SignalNewEvent();
171 : LOG(LS_INFO) << "Starting WebRTC event log.";
172 : return true;
173 : }
174 :
175 : bool RtcEventLogImpl::StartLogging(rtc::PlatformFile platform_file,
176 : int64_t max_size_bytes) {
177 : RTC_DCHECK(thread_checker_.CalledOnValidThread());
178 : RtcEventLogHelperThread::ControlMessage message;
179 : message.message_type = RtcEventLogHelperThread::ControlMessage::START_FILE;
180 : message.max_size_bytes = max_size_bytes <= 0
181 : ? std::numeric_limits<int64_t>::max()
182 : : max_size_bytes;
183 : message.start_time = rtc::TimeMicros();
184 : message.stop_time = std::numeric_limits<int64_t>::max();
185 : message.file.reset(FileWrapper::Create());
186 : FILE* file_handle = rtc::FdopenPlatformFileForWriting(platform_file);
187 : if (!file_handle) {
188 : LOG(LS_ERROR) << "Can't open file. WebRTC event log not started.";
189 : // Even though we failed to open a FILE*, the platform_file is still open
190 : // and needs to be closed.
191 : if (!rtc::ClosePlatformFile(platform_file)) {
192 : LOG(LS_ERROR) << "Can't close file.";
193 : }
194 : return false;
195 : }
196 : if (!message.file->OpenFromFileHandle(file_handle)) {
197 : LOG(LS_ERROR) << "Can't open file. WebRTC event log not started.";
198 : return false;
199 : }
200 : if (!message_queue_.Insert(&message)) {
201 : LOG(LS_ERROR) << "Message queue full. Can't start logging.";
202 : return false;
203 : }
204 : helper_thread_.SignalNewEvent();
205 : LOG(LS_INFO) << "Starting WebRTC event log.";
206 : return true;
207 : }
208 :
209 : void RtcEventLogImpl::StopLogging() {
210 : RTC_DCHECK(thread_checker_.CalledOnValidThread());
211 : RtcEventLogHelperThread::ControlMessage message;
212 : message.message_type = RtcEventLogHelperThread::ControlMessage::STOP_FILE;
213 : message.stop_time = rtc::TimeMicros();
214 : while (!message_queue_.Insert(&message)) {
215 : // TODO(terelius): We would like to have a blocking Insert function in the
216 : // SwapQueue, but for the time being we will just clear any previous
217 : // messages.
218 : // Since StopLogging waits for the thread, it is essential that we don't
219 : // clear any STOP_FILE messages. To ensure that there is only one call at a
220 : // time, we require that all calls to StopLogging are made on the same
221 : // thread.
222 : LOG(LS_ERROR) << "Message queue full. Clearing queue to stop logging.";
223 : message_queue_.Clear();
224 : }
225 : LOG(LS_INFO) << "Stopping WebRTC event log.";
226 : helper_thread_.WaitForFileFinished();
227 : }
228 :
229 : void RtcEventLogImpl::LogVideoReceiveStreamConfig(
230 : const VideoReceiveStream::Config& config) {
231 : std::unique_ptr<rtclog::Event> event(new rtclog::Event());
232 : event->set_timestamp_us(rtc::TimeMicros());
233 : event->set_type(rtclog::Event::VIDEO_RECEIVER_CONFIG_EVENT);
234 :
235 : rtclog::VideoReceiveConfig* receiver_config =
236 : event->mutable_video_receiver_config();
237 : receiver_config->set_remote_ssrc(config.rtp.remote_ssrc);
238 : receiver_config->set_local_ssrc(config.rtp.local_ssrc);
239 :
240 : receiver_config->set_rtcp_mode(ConvertRtcpMode(config.rtp.rtcp_mode));
241 : receiver_config->set_remb(config.rtp.remb);
242 :
243 : for (const auto& kv : config.rtp.rtx) {
244 : rtclog::RtxMap* rtx = receiver_config->add_rtx_map();
245 : rtx->set_payload_type(kv.first);
246 : rtx->mutable_config()->set_rtx_ssrc(kv.second.ssrc);
247 : rtx->mutable_config()->set_rtx_payload_type(kv.second.payload_type);
248 : }
249 :
250 : for (const auto& e : config.rtp.extensions) {
251 : rtclog::RtpHeaderExtension* extension =
252 : receiver_config->add_header_extensions();
253 : extension->set_name(e.uri);
254 : extension->set_id(e.id);
255 : }
256 :
257 : for (const auto& d : config.decoders) {
258 : rtclog::DecoderConfig* decoder = receiver_config->add_decoders();
259 : decoder->set_name(d.payload_name);
260 : decoder->set_payload_type(d.payload_type);
261 : }
262 : StoreEvent(&event);
263 : }
264 :
265 : void RtcEventLogImpl::LogVideoSendStreamConfig(
266 : const VideoSendStream::Config& config) {
267 : std::unique_ptr<rtclog::Event> event(new rtclog::Event());
268 : event->set_timestamp_us(rtc::TimeMicros());
269 : event->set_type(rtclog::Event::VIDEO_SENDER_CONFIG_EVENT);
270 :
271 : rtclog::VideoSendConfig* sender_config = event->mutable_video_sender_config();
272 :
273 : for (const auto& ssrc : config.rtp.ssrcs) {
274 : sender_config->add_ssrcs(ssrc);
275 : }
276 :
277 : for (const auto& e : config.rtp.extensions) {
278 : rtclog::RtpHeaderExtension* extension =
279 : sender_config->add_header_extensions();
280 : extension->set_name(e.uri);
281 : extension->set_id(e.id);
282 : }
283 :
284 : for (const auto& rtx_ssrc : config.rtp.rtx.ssrcs) {
285 : sender_config->add_rtx_ssrcs(rtx_ssrc);
286 : }
287 : sender_config->set_rtx_payload_type(config.rtp.rtx.payload_type);
288 :
289 : rtclog::EncoderConfig* encoder = sender_config->mutable_encoder();
290 : encoder->set_name(config.encoder_settings.payload_name);
291 : encoder->set_payload_type(config.encoder_settings.payload_type);
292 : StoreEvent(&event);
293 : }
294 :
295 : void RtcEventLogImpl::LogAudioReceiveStreamConfig(
296 : const AudioReceiveStream::Config& config) {
297 : std::unique_ptr<rtclog::Event> event(new rtclog::Event());
298 : event->set_timestamp_us(rtc::TimeMicros());
299 : event->set_type(rtclog::Event::AUDIO_RECEIVER_CONFIG_EVENT);
300 :
301 : rtclog::AudioReceiveConfig* receiver_config =
302 : event->mutable_audio_receiver_config();
303 : receiver_config->set_remote_ssrc(config.rtp.remote_ssrc);
304 : receiver_config->set_local_ssrc(config.rtp.local_ssrc);
305 :
306 : for (const auto& e : config.rtp.extensions) {
307 : rtclog::RtpHeaderExtension* extension =
308 : receiver_config->add_header_extensions();
309 : extension->set_name(e.uri);
310 : extension->set_id(e.id);
311 : }
312 : StoreEvent(&event);
313 : }
314 :
315 : void RtcEventLogImpl::LogAudioSendStreamConfig(
316 : const AudioSendStream::Config& config) {
317 : std::unique_ptr<rtclog::Event> event(new rtclog::Event());
318 : event->set_timestamp_us(rtc::TimeMicros());
319 : event->set_type(rtclog::Event::AUDIO_SENDER_CONFIG_EVENT);
320 :
321 : rtclog::AudioSendConfig* sender_config = event->mutable_audio_sender_config();
322 :
323 : sender_config->set_ssrc(config.rtp.ssrc);
324 :
325 : for (const auto& e : config.rtp.extensions) {
326 : rtclog::RtpHeaderExtension* extension =
327 : sender_config->add_header_extensions();
328 : extension->set_name(e.uri);
329 : extension->set_id(e.id);
330 : }
331 :
332 : StoreEvent(&event);
333 : }
334 :
335 : void RtcEventLogImpl::LogRtpHeader(PacketDirection direction,
336 : MediaType media_type,
337 : const uint8_t* header,
338 : size_t packet_length) {
339 : // Read header length (in bytes) from packet data.
340 : if (packet_length < 12u) {
341 : return; // Don't read outside the packet.
342 : }
343 : const bool x = (header[0] & 0x10) != 0;
344 : const uint8_t cc = header[0] & 0x0f;
345 : size_t header_length = 12u + cc * 4u;
346 :
347 : if (x) {
348 : if (packet_length < 12u + cc * 4u + 4u) {
349 : return; // Don't read outside the packet.
350 : }
351 : size_t x_len = ByteReader<uint16_t>::ReadBigEndian(header + 14 + cc * 4);
352 : header_length += (x_len + 1) * 4;
353 : }
354 :
355 : std::unique_ptr<rtclog::Event> rtp_event(new rtclog::Event());
356 : rtp_event->set_timestamp_us(rtc::TimeMicros());
357 : rtp_event->set_type(rtclog::Event::RTP_EVENT);
358 : rtp_event->mutable_rtp_packet()->set_incoming(direction == kIncomingPacket);
359 : rtp_event->mutable_rtp_packet()->set_type(ConvertMediaType(media_type));
360 : rtp_event->mutable_rtp_packet()->set_packet_length(packet_length);
361 : rtp_event->mutable_rtp_packet()->set_header(header, header_length);
362 : StoreEvent(&rtp_event);
363 : }
364 :
365 : void RtcEventLogImpl::LogRtcpPacket(PacketDirection direction,
366 : MediaType media_type,
367 : const uint8_t* packet,
368 : size_t length) {
369 : std::unique_ptr<rtclog::Event> rtcp_event(new rtclog::Event());
370 : rtcp_event->set_timestamp_us(rtc::TimeMicros());
371 : rtcp_event->set_type(rtclog::Event::RTCP_EVENT);
372 : rtcp_event->mutable_rtcp_packet()->set_incoming(direction == kIncomingPacket);
373 : rtcp_event->mutable_rtcp_packet()->set_type(ConvertMediaType(media_type));
374 :
375 : rtcp::CommonHeader header;
376 : const uint8_t* block_begin = packet;
377 : const uint8_t* packet_end = packet + length;
378 : RTC_DCHECK(length <= IP_PACKET_SIZE);
379 : uint8_t buffer[IP_PACKET_SIZE];
380 : uint32_t buffer_length = 0;
381 : while (block_begin < packet_end) {
382 : if (!header.Parse(block_begin, packet_end - block_begin)) {
383 : break; // Incorrect message header.
384 : }
385 : const uint8_t* next_block = header.NextPacket();
386 : uint32_t block_size = next_block - block_begin;
387 : switch (header.type()) {
388 : case rtcp::SenderReport::kPacketType:
389 : case rtcp::ReceiverReport::kPacketType:
390 : case rtcp::Bye::kPacketType:
391 : case rtcp::ExtendedJitterReport::kPacketType:
392 : case rtcp::Rtpfb::kPacketType:
393 : case rtcp::Psfb::kPacketType:
394 : case rtcp::ExtendedReports::kPacketType:
395 : // We log sender reports, receiver reports, bye messages
396 : // inter-arrival jitter, third-party loss reports, payload-specific
397 : // feedback and extended reports.
398 : memcpy(buffer + buffer_length, block_begin, block_size);
399 : buffer_length += block_size;
400 : break;
401 : case rtcp::Sdes::kPacketType:
402 : case rtcp::App::kPacketType:
403 : default:
404 : // We don't log sender descriptions, application defined messages
405 : // or message blocks of unknown type.
406 : break;
407 : }
408 :
409 : block_begin += block_size;
410 : }
411 : rtcp_event->mutable_rtcp_packet()->set_packet_data(buffer, buffer_length);
412 : StoreEvent(&rtcp_event);
413 : }
414 :
415 : void RtcEventLogImpl::LogAudioPlayout(uint32_t ssrc) {
416 : std::unique_ptr<rtclog::Event> event(new rtclog::Event());
417 : event->set_timestamp_us(rtc::TimeMicros());
418 : event->set_type(rtclog::Event::AUDIO_PLAYOUT_EVENT);
419 : auto playout_event = event->mutable_audio_playout_event();
420 : playout_event->set_local_ssrc(ssrc);
421 : StoreEvent(&event);
422 : }
423 :
424 : void RtcEventLogImpl::LogBwePacketLossEvent(int32_t bitrate,
425 : uint8_t fraction_loss,
426 : int32_t total_packets) {
427 : std::unique_ptr<rtclog::Event> event(new rtclog::Event());
428 : event->set_timestamp_us(rtc::TimeMicros());
429 : event->set_type(rtclog::Event::BWE_PACKET_LOSS_EVENT);
430 : auto bwe_event = event->mutable_bwe_packet_loss_event();
431 : bwe_event->set_bitrate(bitrate);
432 : bwe_event->set_fraction_loss(fraction_loss);
433 : bwe_event->set_total_packets(total_packets);
434 : StoreEvent(&event);
435 : }
436 :
437 : void RtcEventLogImpl::StoreEvent(std::unique_ptr<rtclog::Event>* event) {
438 : if (!event_queue_.Insert(event)) {
439 : LOG(LS_ERROR) << "WebRTC event log queue full. Dropping event.";
440 : }
441 : helper_thread_.SignalNewEvent();
442 : }
443 :
444 : bool RtcEventLog::ParseRtcEventLog(const std::string& file_name,
445 : rtclog::EventStream* result) {
446 : char tmp_buffer[1024];
447 : int bytes_read = 0;
448 : std::unique_ptr<FileWrapper> dump_file(FileWrapper::Create());
449 : if (!dump_file->OpenFile(file_name.c_str(), true)) {
450 : return false;
451 : }
452 : std::string dump_buffer;
453 : while ((bytes_read = dump_file->Read(tmp_buffer, sizeof(tmp_buffer))) > 0) {
454 : dump_buffer.append(tmp_buffer, bytes_read);
455 : }
456 : dump_file->CloseFile();
457 : return result->ParseFromString(dump_buffer);
458 : }
459 :
460 : #endif // ENABLE_RTC_EVENT_LOG
461 :
462 0 : bool RtcEventLogNullImpl::StartLogging(rtc::PlatformFile platform_file,
463 : int64_t max_size_bytes) {
464 : // The platform_file is open and needs to be closed.
465 0 : if (!rtc::ClosePlatformFile(platform_file)) {
466 0 : LOG(LS_ERROR) << "Can't close file.";
467 : }
468 0 : return false;
469 : }
470 :
471 : // RtcEventLog member functions.
472 0 : std::unique_ptr<RtcEventLog> RtcEventLog::Create() {
473 : #ifdef ENABLE_RTC_EVENT_LOG
474 : return std::unique_ptr<RtcEventLog>(new RtcEventLogImpl());
475 : #else
476 0 : return std::unique_ptr<RtcEventLog>(new RtcEventLogNullImpl());
477 : #endif // ENABLE_RTC_EVENT_LOG
478 : }
479 :
480 0 : std::unique_ptr<RtcEventLog> RtcEventLog::CreateNull() {
481 0 : return std::unique_ptr<RtcEventLog>(new RtcEventLogNullImpl());
482 : }
483 :
484 : } // namespace webrtc
|
