OLD | NEW |
| (Empty) |
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/video/rtc_event_log.h" | |
12 | |
13 #include <deque> | |
14 | |
15 #include "webrtc/base/checks.h" | |
16 #include "webrtc/base/criticalsection.h" | |
17 #include "webrtc/base/thread_annotations.h" | |
18 #include "webrtc/call.h" | |
19 #include "webrtc/modules/rtp_rtcp/source/byte_io.h" | |
20 #include "webrtc/system_wrappers/interface/clock.h" | |
21 #include "webrtc/system_wrappers/interface/file_wrapper.h" | |
22 | |
23 #ifdef ENABLE_RTC_EVENT_LOG | |
24 // Files generated at build-time by the protobuf compiler. | |
25 #ifdef WEBRTC_ANDROID_PLATFORM_BUILD | |
26 #include "external/webrtc/webrtc/video/rtc_event_log.pb.h" | |
27 #else | |
28 #include "webrtc/video/rtc_event_log.pb.h" | |
29 #endif | |
30 #endif | |
31 | |
32 namespace webrtc { | |
33 | |
34 #ifndef ENABLE_RTC_EVENT_LOG | |
35 | |
36 // No-op implementation if flag is not set. | |
37 class RtcEventLogImpl final : public RtcEventLog { | |
38 public: | |
39 void StartLogging(const std::string& file_name, int duration_ms) override {} | |
40 void StopLogging(void) override {} | |
41 void LogVideoReceiveStreamConfig( | |
42 const VideoReceiveStream::Config& config) override {} | |
43 void LogVideoSendStreamConfig( | |
44 const VideoSendStream::Config& config) override {} | |
45 void LogRtpHeader(bool incoming, | |
46 MediaType media_type, | |
47 const uint8_t* header, | |
48 size_t packet_length) override {} | |
49 void LogRtcpPacket(bool incoming, | |
50 MediaType media_type, | |
51 const uint8_t* packet, | |
52 size_t length) override {} | |
53 void LogAudioPlayout(uint32_t ssrc) override {} | |
54 }; | |
55 | |
56 #else // ENABLE_RTC_EVENT_LOG is defined | |
57 | |
58 class RtcEventLogImpl final : public RtcEventLog { | |
59 public: | |
60 RtcEventLogImpl(); | |
61 | |
62 void StartLogging(const std::string& file_name, int duration_ms) override; | |
63 void StopLogging() override; | |
64 void LogVideoReceiveStreamConfig( | |
65 const VideoReceiveStream::Config& config) override; | |
66 void LogVideoSendStreamConfig(const VideoSendStream::Config& config) override; | |
67 void LogRtpHeader(bool incoming, | |
68 MediaType media_type, | |
69 const uint8_t* header, | |
70 size_t packet_length) override; | |
71 void LogRtcpPacket(bool incoming, | |
72 MediaType media_type, | |
73 const uint8_t* packet, | |
74 size_t length) override; | |
75 void LogAudioPlayout(uint32_t ssrc) override; | |
76 | |
77 private: | |
78 // Stops logging and clears the stored data and buffers. | |
79 void StopLoggingLocked() EXCLUSIVE_LOCKS_REQUIRED(crit_); | |
80 // Adds a new event to the logfile if logging is active, or adds it to the | |
81 // list of recent log events otherwise. | |
82 void HandleEvent(rtclog::Event* event) EXCLUSIVE_LOCKS_REQUIRED(crit_); | |
83 // Writes the event to the file. Note that this will destroy the state of the | |
84 // input argument. | |
85 void StoreToFile(rtclog::Event* event) EXCLUSIVE_LOCKS_REQUIRED(crit_); | |
86 // Adds the event to the list of recent events, and removes any events that | |
87 // are too old and no longer fall in the time window. | |
88 void AddRecentEvent(const rtclog::Event& event) | |
89 EXCLUSIVE_LOCKS_REQUIRED(crit_); | |
90 | |
91 // Amount of time in microseconds to record log events, before starting the | |
92 // actual log. | |
93 const int recent_log_duration_us = 10000000; | |
94 | |
95 rtc::CriticalSection crit_; | |
96 rtc::scoped_ptr<FileWrapper> file_ GUARDED_BY(crit_); | |
97 rtclog::EventStream stream_ GUARDED_BY(crit_); | |
98 std::deque<rtclog::Event> recent_log_events_ GUARDED_BY(crit_); | |
99 bool currently_logging_ GUARDED_BY(crit_); | |
100 int64_t start_time_us_ GUARDED_BY(crit_); | |
101 int64_t duration_us_ GUARDED_BY(crit_); | |
102 const Clock* const clock_; | |
103 }; | |
104 | |
105 namespace { | |
106 // The functions in this namespace convert enums from the runtime format | |
107 // that the rest of the WebRtc project can use, to the corresponding | |
108 // serialized enum which is defined by the protobuf. | |
109 | |
110 // Do not add default return values to the conversion functions in this | |
111 // unnamed namespace. The intention is to make the compiler warn if anyone | |
112 // adds unhandled new events/modes/etc. | |
113 | |
114 rtclog::VideoReceiveConfig_RtcpMode ConvertRtcpMode( | |
115 newapi::RtcpMode rtcp_mode) { | |
116 switch (rtcp_mode) { | |
117 case newapi::kRtcpCompound: | |
118 return rtclog::VideoReceiveConfig::RTCP_COMPOUND; | |
119 case newapi::kRtcpReducedSize: | |
120 return rtclog::VideoReceiveConfig::RTCP_REDUCEDSIZE; | |
121 } | |
122 RTC_NOTREACHED(); | |
123 return rtclog::VideoReceiveConfig::RTCP_COMPOUND; | |
124 } | |
125 | |
126 rtclog::MediaType ConvertMediaType(MediaType media_type) { | |
127 switch (media_type) { | |
128 case MediaType::ANY: | |
129 return rtclog::MediaType::ANY; | |
130 case MediaType::AUDIO: | |
131 return rtclog::MediaType::AUDIO; | |
132 case MediaType::VIDEO: | |
133 return rtclog::MediaType::VIDEO; | |
134 case MediaType::DATA: | |
135 return rtclog::MediaType::DATA; | |
136 } | |
137 RTC_NOTREACHED(); | |
138 return rtclog::ANY; | |
139 } | |
140 | |
141 } // namespace | |
142 | |
143 // RtcEventLogImpl member functions. | |
144 RtcEventLogImpl::RtcEventLogImpl() | |
145 : file_(FileWrapper::Create()), | |
146 stream_(), | |
147 currently_logging_(false), | |
148 start_time_us_(0), | |
149 duration_us_(0), | |
150 clock_(Clock::GetRealTimeClock()) { | |
151 } | |
152 | |
153 void RtcEventLogImpl::StartLogging(const std::string& file_name, | |
154 int duration_ms) { | |
155 rtc::CritScope lock(&crit_); | |
156 if (currently_logging_) { | |
157 StopLoggingLocked(); | |
158 } | |
159 if (file_->OpenFile(file_name.c_str(), false) != 0) { | |
160 return; | |
161 } | |
162 currently_logging_ = true; | |
163 start_time_us_ = clock_->TimeInMicroseconds(); | |
164 duration_us_ = static_cast<int64_t>(duration_ms) * 1000; | |
165 // Write all the recent events to the log file, ignoring any old events. | |
166 for (auto& event : recent_log_events_) { | |
167 if (event.timestamp_us() >= start_time_us_ - recent_log_duration_us) { | |
168 StoreToFile(&event); | |
169 } | |
170 } | |
171 recent_log_events_.clear(); | |
172 // Write a LOG_START event to the file. | |
173 rtclog::Event start_event; | |
174 start_event.set_timestamp_us(start_time_us_); | |
175 start_event.set_type(rtclog::Event::DEBUG_EVENT); | |
176 auto debug_event = start_event.mutable_debug_event(); | |
177 debug_event->set_type(rtclog::DebugEvent_EventType_LOG_START); | |
178 StoreToFile(&start_event); | |
179 } | |
180 | |
181 void RtcEventLogImpl::StopLogging() { | |
182 rtc::CritScope lock(&crit_); | |
183 StopLoggingLocked(); | |
184 } | |
185 | |
186 void RtcEventLogImpl::LogVideoReceiveStreamConfig( | |
187 const VideoReceiveStream::Config& config) { | |
188 rtc::CritScope lock(&crit_); | |
189 | |
190 rtclog::Event event; | |
191 const int64_t timestamp = clock_->TimeInMicroseconds(); | |
192 event.set_timestamp_us(timestamp); | |
193 event.set_type(rtclog::Event::VIDEO_RECEIVER_CONFIG_EVENT); | |
194 | |
195 rtclog::VideoReceiveConfig* receiver_config = | |
196 event.mutable_video_receiver_config(); | |
197 receiver_config->set_remote_ssrc(config.rtp.remote_ssrc); | |
198 receiver_config->set_local_ssrc(config.rtp.local_ssrc); | |
199 | |
200 receiver_config->set_rtcp_mode(ConvertRtcpMode(config.rtp.rtcp_mode)); | |
201 | |
202 receiver_config->set_receiver_reference_time_report( | |
203 config.rtp.rtcp_xr.receiver_reference_time_report); | |
204 receiver_config->set_remb(config.rtp.remb); | |
205 | |
206 for (const auto& kv : config.rtp.rtx) { | |
207 rtclog::RtxMap* rtx = receiver_config->add_rtx_map(); | |
208 rtx->set_payload_type(kv.first); | |
209 rtx->mutable_config()->set_rtx_ssrc(kv.second.ssrc); | |
210 rtx->mutable_config()->set_rtx_payload_type(kv.second.payload_type); | |
211 } | |
212 | |
213 for (const auto& e : config.rtp.extensions) { | |
214 rtclog::RtpHeaderExtension* extension = | |
215 receiver_config->add_header_extensions(); | |
216 extension->set_name(e.name); | |
217 extension->set_id(e.id); | |
218 } | |
219 | |
220 for (const auto& d : config.decoders) { | |
221 rtclog::DecoderConfig* decoder = receiver_config->add_decoders(); | |
222 decoder->set_name(d.payload_name); | |
223 decoder->set_payload_type(d.payload_type); | |
224 } | |
225 // TODO(terelius): We should use a separate event queue for config events. | |
226 // The current approach of storing the configuration together with the | |
227 // RTP events causes the configuration information to be removed 10s | |
228 // after the ReceiveStream is created. | |
229 HandleEvent(&event); | |
230 } | |
231 | |
232 void RtcEventLogImpl::LogVideoSendStreamConfig( | |
233 const VideoSendStream::Config& config) { | |
234 rtc::CritScope lock(&crit_); | |
235 | |
236 rtclog::Event event; | |
237 const int64_t timestamp = clock_->TimeInMicroseconds(); | |
238 event.set_timestamp_us(timestamp); | |
239 event.set_type(rtclog::Event::VIDEO_SENDER_CONFIG_EVENT); | |
240 | |
241 rtclog::VideoSendConfig* sender_config = event.mutable_video_sender_config(); | |
242 | |
243 for (const auto& ssrc : config.rtp.ssrcs) { | |
244 sender_config->add_ssrcs(ssrc); | |
245 } | |
246 | |
247 for (const auto& e : config.rtp.extensions) { | |
248 rtclog::RtpHeaderExtension* extension = | |
249 sender_config->add_header_extensions(); | |
250 extension->set_name(e.name); | |
251 extension->set_id(e.id); | |
252 } | |
253 | |
254 for (const auto& rtx_ssrc : config.rtp.rtx.ssrcs) { | |
255 sender_config->add_rtx_ssrcs(rtx_ssrc); | |
256 } | |
257 sender_config->set_rtx_payload_type(config.rtp.rtx.payload_type); | |
258 | |
259 sender_config->set_c_name(config.rtp.c_name); | |
260 | |
261 rtclog::EncoderConfig* encoder = sender_config->mutable_encoder(); | |
262 encoder->set_name(config.encoder_settings.payload_name); | |
263 encoder->set_payload_type(config.encoder_settings.payload_type); | |
264 | |
265 // TODO(terelius): We should use a separate event queue for config events. | |
266 // The current approach of storing the configuration together with the | |
267 // RTP events causes the configuration information to be removed 10s | |
268 // after the ReceiveStream is created. | |
269 HandleEvent(&event); | |
270 } | |
271 | |
272 void RtcEventLogImpl::LogRtpHeader(bool incoming, | |
273 MediaType media_type, | |
274 const uint8_t* header, | |
275 size_t packet_length) { | |
276 // Read header length (in bytes) from packet data. | |
277 if (packet_length < 12u) { | |
278 return; // Don't read outside the packet. | |
279 } | |
280 const bool x = (header[0] & 0x10) != 0; | |
281 const uint8_t cc = header[0] & 0x0f; | |
282 size_t header_length = 12u + cc * 4u; | |
283 | |
284 if (x) { | |
285 if (packet_length < 12u + cc * 4u + 4u) { | |
286 return; // Don't read outside the packet. | |
287 } | |
288 size_t x_len = ByteReader<uint16_t>::ReadBigEndian(header + 14 + cc * 4); | |
289 header_length += (x_len + 1) * 4; | |
290 } | |
291 | |
292 rtc::CritScope lock(&crit_); | |
293 rtclog::Event rtp_event; | |
294 const int64_t timestamp = clock_->TimeInMicroseconds(); | |
295 rtp_event.set_timestamp_us(timestamp); | |
296 rtp_event.set_type(rtclog::Event::RTP_EVENT); | |
297 rtp_event.mutable_rtp_packet()->set_incoming(incoming); | |
298 rtp_event.mutable_rtp_packet()->set_type(ConvertMediaType(media_type)); | |
299 rtp_event.mutable_rtp_packet()->set_packet_length(packet_length); | |
300 rtp_event.mutable_rtp_packet()->set_header(header, header_length); | |
301 HandleEvent(&rtp_event); | |
302 } | |
303 | |
304 void RtcEventLogImpl::LogRtcpPacket(bool incoming, | |
305 MediaType media_type, | |
306 const uint8_t* packet, | |
307 size_t length) { | |
308 rtc::CritScope lock(&crit_); | |
309 rtclog::Event rtcp_event; | |
310 const int64_t timestamp = clock_->TimeInMicroseconds(); | |
311 rtcp_event.set_timestamp_us(timestamp); | |
312 rtcp_event.set_type(rtclog::Event::RTCP_EVENT); | |
313 rtcp_event.mutable_rtcp_packet()->set_incoming(incoming); | |
314 rtcp_event.mutable_rtcp_packet()->set_type(ConvertMediaType(media_type)); | |
315 rtcp_event.mutable_rtcp_packet()->set_packet_data(packet, length); | |
316 HandleEvent(&rtcp_event); | |
317 } | |
318 | |
319 void RtcEventLogImpl::LogAudioPlayout(uint32_t ssrc) { | |
320 rtc::CritScope lock(&crit_); | |
321 rtclog::Event event; | |
322 const int64_t timestamp = clock_->TimeInMicroseconds(); | |
323 event.set_timestamp_us(timestamp); | |
324 event.set_type(rtclog::Event::DEBUG_EVENT); | |
325 auto debug_event = event.mutable_debug_event(); | |
326 debug_event->set_type(rtclog::DebugEvent_EventType_AUDIO_PLAYOUT); | |
327 debug_event->set_local_ssrc(ssrc); | |
328 HandleEvent(&event); | |
329 } | |
330 | |
331 void RtcEventLogImpl::StopLoggingLocked() { | |
332 if (currently_logging_) { | |
333 currently_logging_ = false; | |
334 // Create a LogEnd debug event | |
335 rtclog::Event event; | |
336 int64_t timestamp = clock_->TimeInMicroseconds(); | |
337 event.set_timestamp_us(timestamp); | |
338 event.set_type(rtclog::Event::DEBUG_EVENT); | |
339 auto debug_event = event.mutable_debug_event(); | |
340 debug_event->set_type(rtclog::DebugEvent_EventType_LOG_END); | |
341 // Store the event and close the file | |
342 RTC_DCHECK(file_->Open()); | |
343 StoreToFile(&event); | |
344 file_->CloseFile(); | |
345 } | |
346 RTC_DCHECK(!file_->Open()); | |
347 stream_.Clear(); | |
348 } | |
349 | |
350 void RtcEventLogImpl::HandleEvent(rtclog::Event* event) { | |
351 if (currently_logging_) { | |
352 if (clock_->TimeInMicroseconds() < start_time_us_ + duration_us_) { | |
353 StoreToFile(event); | |
354 return; | |
355 } | |
356 StopLoggingLocked(); | |
357 } | |
358 AddRecentEvent(*event); | |
359 } | |
360 | |
361 void RtcEventLogImpl::StoreToFile(rtclog::Event* event) { | |
362 // Reuse the same object at every log event. | |
363 if (stream_.stream_size() < 1) { | |
364 stream_.add_stream(); | |
365 } | |
366 RTC_DCHECK_EQ(stream_.stream_size(), 1); | |
367 stream_.mutable_stream(0)->Swap(event); | |
368 // TODO(terelius): Doesn't this create a new EventStream per event? | |
369 // Is this guaranteed to work e.g. in future versions of protobuf? | |
370 std::string dump_buffer; | |
371 stream_.SerializeToString(&dump_buffer); | |
372 file_->Write(dump_buffer.data(), dump_buffer.size()); | |
373 } | |
374 | |
375 void RtcEventLogImpl::AddRecentEvent(const rtclog::Event& event) { | |
376 recent_log_events_.push_back(event); | |
377 while (recent_log_events_.front().timestamp_us() < | |
378 event.timestamp_us() - recent_log_duration_us) { | |
379 recent_log_events_.pop_front(); | |
380 } | |
381 } | |
382 | |
383 bool RtcEventLog::ParseRtcEventLog(const std::string& file_name, | |
384 rtclog::EventStream* result) { | |
385 char tmp_buffer[1024]; | |
386 int bytes_read = 0; | |
387 rtc::scoped_ptr<FileWrapper> dump_file(FileWrapper::Create()); | |
388 if (dump_file->OpenFile(file_name.c_str(), true) != 0) { | |
389 return false; | |
390 } | |
391 std::string dump_buffer; | |
392 while ((bytes_read = dump_file->Read(tmp_buffer, sizeof(tmp_buffer))) > 0) { | |
393 dump_buffer.append(tmp_buffer, bytes_read); | |
394 } | |
395 dump_file->CloseFile(); | |
396 return result->ParseFromString(dump_buffer); | |
397 } | |
398 | |
399 #endif // ENABLE_RTC_EVENT_LOG | |
400 | |
401 // RtcEventLog member functions. | |
402 rtc::scoped_ptr<RtcEventLog> RtcEventLog::Create() { | |
403 return rtc::scoped_ptr<RtcEventLog>(new RtcEventLogImpl()); | |
404 } | |
405 } // namespace webrtc | |
OLD | NEW |