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/logging/rtc_event_log/rtc_event_log.h" | 11 #include "webrtc/logging/rtc_event_log/rtc_event_log.h" |
12 | 12 |
13 #include <atomic> | |
14 #include <deque> | |
15 #include <functional> | |
16 #include <limits> | 13 #include <limits> |
17 #include <memory> | |
18 #include <utility> | 14 #include <utility> |
19 #include <vector> | 15 #include <vector> |
20 | 16 |
| 17 #include "webrtc/logging/rtc_event_log/rtc_event_log_helper_thread.h" |
21 #include "webrtc/modules/audio_coding/audio_network_adaptor/include/audio_networ
k_adaptor.h" | 18 #include "webrtc/modules/audio_coding/audio_network_adaptor/include/audio_networ
k_adaptor.h" |
22 #include "webrtc/modules/remote_bitrate_estimator/include/bwe_defines.h" | 19 #include "webrtc/modules/remote_bitrate_estimator/include/bwe_defines.h" |
23 #include "webrtc/modules/rtp_rtcp/include/rtp_rtcp_defines.h" | 20 #include "webrtc/modules/rtp_rtcp/include/rtp_rtcp_defines.h" |
24 #include "webrtc/modules/rtp_rtcp/source/byte_io.h" | 21 #include "webrtc/modules/rtp_rtcp/source/byte_io.h" |
25 #include "webrtc/modules/rtp_rtcp/source/rtcp_packet/app.h" | 22 #include "webrtc/modules/rtp_rtcp/source/rtcp_packet/app.h" |
26 #include "webrtc/modules/rtp_rtcp/source/rtcp_packet/bye.h" | 23 #include "webrtc/modules/rtp_rtcp/source/rtcp_packet/bye.h" |
27 #include "webrtc/modules/rtp_rtcp/source/rtcp_packet/common_header.h" | 24 #include "webrtc/modules/rtp_rtcp/source/rtcp_packet/common_header.h" |
28 #include "webrtc/modules/rtp_rtcp/source/rtcp_packet/extended_jitter_report.h" | 25 #include "webrtc/modules/rtp_rtcp/source/rtcp_packet/extended_jitter_report.h" |
29 #include "webrtc/modules/rtp_rtcp/source/rtcp_packet/extended_reports.h" | 26 #include "webrtc/modules/rtp_rtcp/source/rtcp_packet/extended_reports.h" |
30 #include "webrtc/modules/rtp_rtcp/source/rtcp_packet/psfb.h" | 27 #include "webrtc/modules/rtp_rtcp/source/rtcp_packet/psfb.h" |
31 #include "webrtc/modules/rtp_rtcp/source/rtcp_packet/receiver_report.h" | 28 #include "webrtc/modules/rtp_rtcp/source/rtcp_packet/receiver_report.h" |
32 #include "webrtc/modules/rtp_rtcp/source/rtcp_packet/rtpfb.h" | 29 #include "webrtc/modules/rtp_rtcp/source/rtcp_packet/rtpfb.h" |
33 #include "webrtc/modules/rtp_rtcp/source/rtcp_packet/sdes.h" | 30 #include "webrtc/modules/rtp_rtcp/source/rtcp_packet/sdes.h" |
34 #include "webrtc/modules/rtp_rtcp/source/rtcp_packet/sender_report.h" | 31 #include "webrtc/modules/rtp_rtcp/source/rtcp_packet/sender_report.h" |
| 32 #include "webrtc/rtc_base/atomicops.h" |
35 #include "webrtc/rtc_base/checks.h" | 33 #include "webrtc/rtc_base/checks.h" |
36 #include "webrtc/rtc_base/constructormagic.h" | 34 #include "webrtc/rtc_base/constructormagic.h" |
37 #include "webrtc/rtc_base/event.h" | 35 #include "webrtc/rtc_base/event.h" |
38 #include "webrtc/rtc_base/ignore_wundef.h" | |
39 #include "webrtc/rtc_base/logging.h" | 36 #include "webrtc/rtc_base/logging.h" |
40 #include "webrtc/rtc_base/protobuf_utils.h" | 37 #include "webrtc/rtc_base/protobuf_utils.h" |
41 #include "webrtc/rtc_base/ptr_util.h" | 38 #include "webrtc/rtc_base/swap_queue.h" |
42 #include "webrtc/rtc_base/sequenced_task_checker.h" | 39 #include "webrtc/rtc_base/thread_checker.h" |
43 #include "webrtc/rtc_base/task_queue.h" | |
44 #include "webrtc/rtc_base/thread_annotations.h" | |
45 #include "webrtc/rtc_base/timeutils.h" | 40 #include "webrtc/rtc_base/timeutils.h" |
46 #include "webrtc/system_wrappers/include/file_wrapper.h" | 41 #include "webrtc/system_wrappers/include/file_wrapper.h" |
47 #include "webrtc/typedefs.h" | |
48 | 42 |
49 #ifdef ENABLE_RTC_EVENT_LOG | 43 #ifdef ENABLE_RTC_EVENT_LOG |
50 // *.pb.h files are generated at build-time by the protobuf compiler. | 44 // *.pb.h files are generated at build-time by the protobuf compiler. |
51 RTC_PUSH_IGNORING_WUNDEF() | |
52 #ifdef WEBRTC_ANDROID_PLATFORM_BUILD | 45 #ifdef WEBRTC_ANDROID_PLATFORM_BUILD |
53 #include "external/webrtc/webrtc/logging/rtc_event_log/rtc_event_log.pb.h" | 46 #include "external/webrtc/webrtc/logging/rtc_event_log/rtc_event_log.pb.h" |
54 #else | 47 #else |
55 #include "webrtc/logging/rtc_event_log/rtc_event_log.pb.h" | 48 #include "webrtc/logging/rtc_event_log/rtc_event_log.pb.h" |
56 #endif | 49 #endif |
57 RTC_POP_IGNORING_WUNDEF() | |
58 #endif | 50 #endif |
59 | 51 |
60 namespace webrtc { | 52 namespace webrtc { |
61 | 53 |
62 #ifdef ENABLE_RTC_EVENT_LOG | 54 #ifdef ENABLE_RTC_EVENT_LOG |
63 | 55 |
64 namespace { | |
65 const int kEventsInHistory = 10000; | |
66 | |
67 bool IsConfigEvent(const rtclog::Event& event) { | |
68 rtclog::Event_EventType event_type = event.type(); | |
69 return event_type == rtclog::Event::VIDEO_RECEIVER_CONFIG_EVENT || | |
70 event_type == rtclog::Event::VIDEO_SENDER_CONFIG_EVENT || | |
71 event_type == rtclog::Event::AUDIO_RECEIVER_CONFIG_EVENT || | |
72 event_type == rtclog::Event::AUDIO_SENDER_CONFIG_EVENT; | |
73 } | |
74 | |
75 // TODO(eladalon): This class exists because C++11 doesn't allow transferring a | |
76 // unique_ptr to a lambda (a copy constructor is required). We should get | |
77 // rid of this when we move to C++14. | |
78 template <typename T> | |
79 class ResourceOwningTask final : public rtc::QueuedTask { | |
80 public: | |
81 ResourceOwningTask(std::unique_ptr<T> resource, | |
82 std::function<void(std::unique_ptr<T>)> handler) | |
83 : resource_(std::move(resource)), handler_(handler) {} | |
84 | |
85 bool Run() override { | |
86 handler_(std::move(resource_)); | |
87 return true; | |
88 } | |
89 | |
90 private: | |
91 std::unique_ptr<T> resource_; | |
92 std::function<void(std::unique_ptr<T>)> handler_; | |
93 }; | |
94 } // namespace | |
95 | |
96 class RtcEventLogImpl final : public RtcEventLog { | 56 class RtcEventLogImpl final : public RtcEventLog { |
97 friend std::unique_ptr<RtcEventLog> RtcEventLog::Create(); | 57 friend std::unique_ptr<RtcEventLog> RtcEventLog::Create(); |
98 | 58 |
99 public: | 59 public: |
100 ~RtcEventLogImpl() override; | 60 ~RtcEventLogImpl() override; |
101 | 61 |
102 bool StartLogging(const std::string& file_name, | 62 bool StartLogging(const std::string& file_name, |
103 int64_t max_size_bytes) override; | 63 int64_t max_size_bytes) override; |
104 bool StartLogging(rtc::PlatformFile platform_file, | 64 bool StartLogging(rtc::PlatformFile platform_file, |
105 int64_t max_size_bytes) override; | 65 int64_t max_size_bytes) override; |
(...skipping 22 matching lines...) Expand all Loading... |
128 const AudioEncoderRuntimeConfig& config) override; | 88 const AudioEncoderRuntimeConfig& config) override; |
129 void LogProbeClusterCreated(int id, | 89 void LogProbeClusterCreated(int id, |
130 int bitrate_bps, | 90 int bitrate_bps, |
131 int min_probes, | 91 int min_probes, |
132 int min_bytes) override; | 92 int min_bytes) override; |
133 void LogProbeResultSuccess(int id, int bitrate_bps) override; | 93 void LogProbeResultSuccess(int id, int bitrate_bps) override; |
134 void LogProbeResultFailure(int id, | 94 void LogProbeResultFailure(int id, |
135 ProbeFailureReason failure_reason) override; | 95 ProbeFailureReason failure_reason) override; |
136 | 96 |
137 private: | 97 private: |
138 void StartLoggingInternal(std::unique_ptr<FileWrapper> file, | 98 // Private constructor to ensure that creation is done by RtcEventLog::Create. |
139 int64_t max_size_bytes); | 99 RtcEventLogImpl(); |
140 | |
141 RtcEventLogImpl(); // Creation is done by RtcEventLog::Create. | |
142 | 100 |
143 void StoreEvent(std::unique_ptr<rtclog::Event> event); | 101 void StoreEvent(std::unique_ptr<rtclog::Event> event); |
144 void LogProbeResult(int id, | 102 void LogProbeResult(int id, |
145 rtclog::BweProbeResult::ResultType result, | 103 rtclog::BweProbeResult::ResultType result, |
146 int bitrate_bps); | 104 int bitrate_bps); |
147 | 105 |
148 // Appends an event to the output protobuf string, returning true on success. | 106 static volatile int log_count_; |
149 // Fails and returns false in case the limit on output size prevents the | |
150 // event from being added; in this case, the output string is left unchanged. | |
151 bool AppendEventToString(rtclog::Event* event, | |
152 ProtoString* output_string) RTC_WARN_UNUSED_RESULT; | |
153 | 107 |
154 void LogToMemory(std::unique_ptr<rtclog::Event> event); | 108 // Message queue for passing control messages to the logging thread. |
| 109 SwapQueue<RtcEventLogHelperThread::ControlMessage> message_queue_; |
155 | 110 |
156 void StartLogFile(); | 111 // Message queue for passing events to the logging thread. |
157 void LogToFile(std::unique_ptr<rtclog::Event> event); | 112 SwapQueue<std::unique_ptr<rtclog::Event> > event_queue_; |
158 void StopLogFile(int64_t stop_time); | |
159 | 113 |
160 // Observe a limit on the number of concurrent logs, so as not to run into | 114 RtcEventLogHelperThread helper_thread_; |
161 // OS-imposed limits on open files and/or threads/task-queues. | 115 rtc::ThreadChecker thread_checker_; |
162 // TODO(eladalon): Known issue - there's a race over |log_count_|. | |
163 static std::atomic<int> log_count_; | |
164 | |
165 // RtcEventLogImpl's can happen from any thread (typically through a factory), | |
166 // but starting/stopping the log, as well as StartLogFile's destructor, are | |
167 // expected to happen all from the same thread/queue. | |
168 rtc::SequencedTaskChecker owner_sequence_checker_; | |
169 | |
170 // History containing all past configuration events. | |
171 std::vector<std::unique_ptr<rtclog::Event>> config_history_ | |
172 ACCESS_ON(task_queue_); | |
173 | |
174 // History containing the most recent (non-configuration) events (~10s). | |
175 std::deque<std::unique_ptr<rtclog::Event>> history_ ACCESS_ON(task_queue_); | |
176 | |
177 std::unique_ptr<FileWrapper> file_ ACCESS_ON(task_queue_); | |
178 | |
179 size_t max_size_bytes_ ACCESS_ON(task_queue_); | |
180 size_t written_bytes_ ACCESS_ON(task_queue_); | |
181 | |
182 // Keep this last to ensure it destructs first, or else tasks living on the | |
183 // queue might access other members after they've been torn down. | |
184 rtc::TaskQueue task_queue_; | |
185 | 116 |
186 RTC_DISALLOW_COPY_AND_ASSIGN(RtcEventLogImpl); | 117 RTC_DISALLOW_COPY_AND_ASSIGN(RtcEventLogImpl); |
187 }; | 118 }; |
188 | 119 |
189 namespace { | 120 namespace { |
190 // The functions in this namespace convert enums from the runtime format | 121 // The functions in this namespace convert enums from the runtime format |
191 // that the rest of the WebRtc project can use, to the corresponding | 122 // that the rest of the WebRtc project can use, to the corresponding |
192 // serialized enum which is defined by the protobuf. | 123 // serialized enum which is defined by the protobuf. |
193 | 124 |
194 rtclog::VideoReceiveConfig_RtcpMode ConvertRtcpMode(RtcpMode rtcp_mode) { | 125 rtclog::VideoReceiveConfig_RtcpMode ConvertRtcpMode(RtcpMode rtcp_mode) { |
(...skipping 31 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... |
226 return rtclog::BweProbeResult::INVALID_SEND_RECEIVE_INTERVAL; | 157 return rtclog::BweProbeResult::INVALID_SEND_RECEIVE_INTERVAL; |
227 case kInvalidSendReceiveRatio: | 158 case kInvalidSendReceiveRatio: |
228 return rtclog::BweProbeResult::INVALID_SEND_RECEIVE_RATIO; | 159 return rtclog::BweProbeResult::INVALID_SEND_RECEIVE_RATIO; |
229 case kTimeout: | 160 case kTimeout: |
230 return rtclog::BweProbeResult::TIMEOUT; | 161 return rtclog::BweProbeResult::TIMEOUT; |
231 } | 162 } |
232 RTC_NOTREACHED(); | 163 RTC_NOTREACHED(); |
233 return rtclog::BweProbeResult::SUCCESS; | 164 return rtclog::BweProbeResult::SUCCESS; |
234 } | 165 } |
235 | 166 |
| 167 // The RTP and RTCP buffers reserve space for twice the expected number of |
| 168 // sent packets because they also contain received packets. |
| 169 static const int kEventsPerSecond = 1000; |
| 170 static const int kControlMessagesPerSecond = 10; |
236 } // namespace | 171 } // namespace |
237 | 172 |
238 std::atomic<int> RtcEventLogImpl::log_count_(0); | 173 volatile int RtcEventLogImpl::log_count_ = 0; |
239 | 174 |
| 175 // RtcEventLogImpl member functions. |
240 RtcEventLogImpl::RtcEventLogImpl() | 176 RtcEventLogImpl::RtcEventLogImpl() |
241 : file_(FileWrapper::Create()), | 177 // Allocate buffers for roughly one second of history. |
242 max_size_bytes_(std::numeric_limits<decltype(max_size_bytes_)>::max()), | 178 : message_queue_(kControlMessagesPerSecond), |
243 written_bytes_(0), | 179 event_queue_(kEventsPerSecond), |
244 task_queue_("rtc_event_log") { | 180 helper_thread_(&message_queue_, &event_queue_), |
245 // RtcEventLog is created by a factory, then potentially used on another | 181 thread_checker_() { |
246 // thread or TaskQueue. However, whichever thread/queue is starting/stopping, | 182 thread_checker_.DetachFromThread(); |
247 // is also expected to be the (final) owner, and be in charge of destruction. | |
248 owner_sequence_checker_.Detach(); | |
249 } | 183 } |
250 | 184 |
251 RtcEventLogImpl::~RtcEventLogImpl() { | 185 RtcEventLogImpl::~RtcEventLogImpl() { |
252 RTC_DCHECK_CALLED_SEQUENTIALLY(&owner_sequence_checker_); | 186 // The RtcEventLogHelperThread destructor closes the file |
253 | 187 // and waits for the thread to terminate. |
254 // If we're logging to the file, this will stop that. Blocking function. | 188 int count = rtc::AtomicOps::Decrement(&RtcEventLogImpl::log_count_); |
255 StopLogging(); | |
256 | |
257 int count = std::atomic_fetch_sub(&RtcEventLogImpl::log_count_, 1) - 1; | |
258 RTC_DCHECK_GE(count, 0); | 189 RTC_DCHECK_GE(count, 0); |
259 } | 190 } |
260 | 191 |
261 bool RtcEventLogImpl::StartLogging(const std::string& file_name, | 192 bool RtcEventLogImpl::StartLogging(const std::string& file_name, |
262 int64_t max_size_bytes) { | 193 int64_t max_size_bytes) { |
263 RTC_DCHECK_CALLED_SEQUENTIALLY(&owner_sequence_checker_); | 194 RTC_DCHECK(thread_checker_.CalledOnValidThread()); |
264 | 195 RtcEventLogHelperThread::ControlMessage message; |
265 auto file = rtc::WrapUnique<FileWrapper>(FileWrapper::Create()); | 196 message.message_type = RtcEventLogHelperThread::ControlMessage::START_FILE; |
266 if (!file->OpenFile(file_name.c_str(), false)) { | 197 message.max_size_bytes = max_size_bytes <= 0 |
| 198 ? std::numeric_limits<int64_t>::max() |
| 199 : max_size_bytes; |
| 200 message.start_time = rtc::TimeMicros(); |
| 201 message.stop_time = std::numeric_limits<int64_t>::max(); |
| 202 message.file.reset(FileWrapper::Create()); |
| 203 if (!message.file->OpenFile(file_name.c_str(), false)) { |
267 LOG(LS_ERROR) << "Can't open file. WebRTC event log not started."; | 204 LOG(LS_ERROR) << "Can't open file. WebRTC event log not started."; |
268 return false; | 205 return false; |
269 } | 206 } |
270 | 207 if (!message_queue_.Insert(&message)) { |
271 StartLoggingInternal(std::move(file), max_size_bytes); | 208 LOG(LS_ERROR) << "Message queue full. Can't start logging."; |
272 | 209 return false; |
| 210 } |
| 211 helper_thread_.SignalNewEvent(); |
| 212 LOG(LS_INFO) << "Starting WebRTC event log."; |
273 return true; | 213 return true; |
274 } | 214 } |
275 | 215 |
276 bool RtcEventLogImpl::StartLogging(rtc::PlatformFile platform_file, | 216 bool RtcEventLogImpl::StartLogging(rtc::PlatformFile platform_file, |
277 int64_t max_size_bytes) { | 217 int64_t max_size_bytes) { |
278 RTC_DCHECK_CALLED_SEQUENTIALLY(&owner_sequence_checker_); | 218 RTC_DCHECK(thread_checker_.CalledOnValidThread()); |
279 | 219 RtcEventLogHelperThread::ControlMessage message; |
280 auto file = rtc::WrapUnique<FileWrapper>(FileWrapper::Create()); | 220 message.message_type = RtcEventLogHelperThread::ControlMessage::START_FILE; |
| 221 message.max_size_bytes = max_size_bytes <= 0 |
| 222 ? std::numeric_limits<int64_t>::max() |
| 223 : max_size_bytes; |
| 224 message.start_time = rtc::TimeMicros(); |
| 225 message.stop_time = std::numeric_limits<int64_t>::max(); |
| 226 message.file.reset(FileWrapper::Create()); |
281 FILE* file_handle = rtc::FdopenPlatformFileForWriting(platform_file); | 227 FILE* file_handle = rtc::FdopenPlatformFileForWriting(platform_file); |
282 if (!file_handle) { | 228 if (!file_handle) { |
283 LOG(LS_ERROR) << "Can't open file. WebRTC event log not started."; | 229 LOG(LS_ERROR) << "Can't open file. WebRTC event log not started."; |
284 // Even though we failed to open a FILE*, the platform_file is still open | 230 // Even though we failed to open a FILE*, the platform_file is still open |
285 // and needs to be closed. | 231 // and needs to be closed. |
286 if (!rtc::ClosePlatformFile(platform_file)) { | 232 if (!rtc::ClosePlatformFile(platform_file)) { |
287 LOG(LS_ERROR) << "Can't close file."; | 233 LOG(LS_ERROR) << "Can't close file."; |
288 } | 234 } |
289 return false; | 235 return false; |
290 } | 236 } |
291 if (!file->OpenFromFileHandle(file_handle)) { | 237 if (!message.file->OpenFromFileHandle(file_handle)) { |
292 LOG(LS_ERROR) << "Can't open file. WebRTC event log not started."; | 238 LOG(LS_ERROR) << "Can't open file. WebRTC event log not started."; |
293 return false; | 239 return false; |
294 } | 240 } |
295 | 241 if (!message_queue_.Insert(&message)) { |
296 StartLoggingInternal(std::move(file), max_size_bytes); | 242 LOG(LS_ERROR) << "Message queue full. Can't start logging."; |
297 | 243 return false; |
| 244 } |
| 245 helper_thread_.SignalNewEvent(); |
| 246 LOG(LS_INFO) << "Starting WebRTC event log."; |
298 return true; | 247 return true; |
299 } | 248 } |
300 | 249 |
301 void RtcEventLogImpl::StopLogging() { | 250 void RtcEventLogImpl::StopLogging() { |
302 RTC_DCHECK_CALLED_SEQUENTIALLY(&owner_sequence_checker_); | 251 RTC_DCHECK(thread_checker_.CalledOnValidThread()); |
303 | 252 RtcEventLogHelperThread::ControlMessage message; |
| 253 message.message_type = RtcEventLogHelperThread::ControlMessage::STOP_FILE; |
| 254 message.stop_time = rtc::TimeMicros(); |
| 255 while (!message_queue_.Insert(&message)) { |
| 256 // TODO(terelius): We would like to have a blocking Insert function in the |
| 257 // SwapQueue, but for the time being we will just clear any previous |
| 258 // messages. |
| 259 // Since StopLogging waits for the thread, it is essential that we don't |
| 260 // clear any STOP_FILE messages. To ensure that there is only one call at a |
| 261 // time, we require that all calls to StopLogging are made on the same |
| 262 // thread. |
| 263 LOG(LS_ERROR) << "Message queue full. Clearing queue to stop logging."; |
| 264 message_queue_.Clear(); |
| 265 } |
304 LOG(LS_INFO) << "Stopping WebRTC event log."; | 266 LOG(LS_INFO) << "Stopping WebRTC event log."; |
305 | 267 helper_thread_.WaitForFileFinished(); |
306 const int64_t stop_time = rtc::TimeMicros(); | |
307 | |
308 rtc::Event file_finished(true, false); | |
309 | |
310 task_queue_.PostTask([this, stop_time, &file_finished]() { | |
311 RTC_DCHECK_RUN_ON(&task_queue_); | |
312 if (file_->is_open()) { | |
313 StopLogFile(stop_time); | |
314 } | |
315 file_finished.Set(); | |
316 }); | |
317 | |
318 file_finished.Wait(rtc::Event::kForever); | |
319 | |
320 LOG(LS_INFO) << "WebRTC event log successfully stopped."; | |
321 } | 268 } |
322 | 269 |
323 void RtcEventLogImpl::LogVideoReceiveStreamConfig( | 270 void RtcEventLogImpl::LogVideoReceiveStreamConfig( |
324 const rtclog::StreamConfig& config) { | 271 const rtclog::StreamConfig& config) { |
325 std::unique_ptr<rtclog::Event> event(new rtclog::Event()); | 272 std::unique_ptr<rtclog::Event> event(new rtclog::Event()); |
326 event->set_timestamp_us(rtc::TimeMicros()); | 273 event->set_timestamp_us(rtc::TimeMicros()); |
327 event->set_type(rtclog::Event::VIDEO_RECEIVER_CONFIG_EVENT); | 274 event->set_type(rtclog::Event::VIDEO_RECEIVER_CONFIG_EVENT); |
328 | 275 |
329 rtclog::VideoReceiveConfig* receiver_config = | 276 rtclog::VideoReceiveConfig* receiver_config = |
330 event->mutable_video_receiver_config(); | 277 event->mutable_video_receiver_config(); |
(...skipping 280 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... |
611 event->set_type(rtclog::Event::BWE_PROBE_RESULT_EVENT); | 558 event->set_type(rtclog::Event::BWE_PROBE_RESULT_EVENT); |
612 | 559 |
613 auto probe_result = event->mutable_probe_result(); | 560 auto probe_result = event->mutable_probe_result(); |
614 probe_result->set_id(id); | 561 probe_result->set_id(id); |
615 probe_result->set_result(result); | 562 probe_result->set_result(result); |
616 if (result == rtclog::BweProbeResult::SUCCESS) | 563 if (result == rtclog::BweProbeResult::SUCCESS) |
617 probe_result->set_bitrate_bps(bitrate_bps); | 564 probe_result->set_bitrate_bps(bitrate_bps); |
618 StoreEvent(std::move(event)); | 565 StoreEvent(std::move(event)); |
619 } | 566 } |
620 | 567 |
621 void RtcEventLogImpl::StartLoggingInternal(std::unique_ptr<FileWrapper> file, | |
622 int64_t max_size_bytes) { | |
623 LOG(LS_INFO) << "Starting WebRTC event log."; | |
624 | |
625 max_size_bytes = (max_size_bytes <= 0) | |
626 ? std::numeric_limits<decltype(max_size_bytes)>::max() | |
627 : max_size_bytes; | |
628 auto file_handler = [this, | |
629 max_size_bytes](std::unique_ptr<FileWrapper> file) { | |
630 RTC_DCHECK_RUN_ON(&task_queue_); | |
631 if (!file_->is_open()) { | |
632 max_size_bytes_ = max_size_bytes; | |
633 file_ = std::move(file); | |
634 StartLogFile(); | |
635 } else { | |
636 // Already started. Ignore message and close file handle. | |
637 file->CloseFile(); | |
638 } | |
639 }; | |
640 task_queue_.PostTask(rtc::MakeUnique<ResourceOwningTask<FileWrapper>>( | |
641 std::move(file), file_handler)); | |
642 } | |
643 | |
644 void RtcEventLogImpl::StoreEvent(std::unique_ptr<rtclog::Event> event) { | 568 void RtcEventLogImpl::StoreEvent(std::unique_ptr<rtclog::Event> event) { |
645 RTC_DCHECK(event); | 569 RTC_DCHECK(event.get() != nullptr); |
646 | 570 if (!event_queue_.Insert(&event)) { |
647 auto event_handler = [this](std::unique_ptr<rtclog::Event> rtclog_event) { | 571 LOG(LS_ERROR) << "WebRTC event log queue full. Dropping event."; |
648 RTC_DCHECK_RUN_ON(&task_queue_); | |
649 if (file_->is_open()) { | |
650 LogToFile(std::move(rtclog_event)); | |
651 } else { | |
652 LogToMemory(std::move(rtclog_event)); | |
653 } | |
654 }; | |
655 | |
656 task_queue_.PostTask(rtc::MakeUnique<ResourceOwningTask<rtclog::Event>>( | |
657 std::move(event), event_handler)); | |
658 } | |
659 | |
660 bool RtcEventLogImpl::AppendEventToString(rtclog::Event* event, | |
661 ProtoString* output_string) { | |
662 RTC_DCHECK_RUN_ON(&task_queue_); | |
663 | |
664 // Even though we're only serializing a single event during this call, what | |
665 // we intend to get is a list of events, with a tag and length preceding | |
666 // each actual event. To produce that, we serialize a list of a single event. | |
667 // If we later serialize additional events, the resulting ProtoString will | |
668 // be a proper concatenation of all those events. | |
669 | |
670 rtclog::EventStream event_stream; | |
671 event_stream.add_stream(); | |
672 | |
673 // As a tweak, we swap the new event into the event-stream, write that to | |
674 // file, then swap back. This saves on some copying. | |
675 rtclog::Event* output_event = event_stream.mutable_stream(0); | |
676 output_event->Swap(event); | |
677 | |
678 bool appended; | |
679 size_t potential_new_size = | |
680 written_bytes_ + output_string->size() + event_stream.ByteSize(); | |
681 if (potential_new_size <= max_size_bytes_) { | |
682 event_stream.AppendToString(output_string); | |
683 appended = true; | |
684 } else { | |
685 appended = false; | |
686 } | 572 } |
687 | 573 helper_thread_.SignalNewEvent(); |
688 // When the function returns, the original Event will be unchanged. | |
689 output_event->Swap(event); | |
690 | |
691 return appended; | |
692 } | |
693 | |
694 void RtcEventLogImpl::LogToMemory(std::unique_ptr<rtclog::Event> event) { | |
695 RTC_DCHECK_RUN_ON(&task_queue_); | |
696 RTC_DCHECK(!file_->is_open()); | |
697 | |
698 if (IsConfigEvent(*event.get())) { | |
699 config_history_.push_back(std::move(event)); | |
700 } else { | |
701 history_.push_back(std::move(event)); | |
702 if (history_.size() > kEventsInHistory) { | |
703 history_.pop_front(); | |
704 } | |
705 } | |
706 } | |
707 | |
708 void RtcEventLogImpl::StartLogFile() { | |
709 RTC_DCHECK_RUN_ON(&task_queue_); | |
710 RTC_DCHECK(file_->is_open()); | |
711 | |
712 ProtoString output_string; | |
713 | |
714 // Create and serialize the LOG_START event. | |
715 // The timestamp used will correspond to when logging has started. The log | |
716 // may contain events earlier than the LOG_START event. (In general, the | |
717 // timestamps in the log are not monotonic.) | |
718 rtclog::Event start_event; | |
719 start_event.set_timestamp_us(rtc::TimeMicros()); | |
720 start_event.set_type(rtclog::Event::LOG_START); | |
721 bool appended = AppendEventToString(&start_event, &output_string); | |
722 | |
723 // Serialize the config information for all old streams, including streams | |
724 // which were already logged to previous files. | |
725 for (auto& event : config_history_) { | |
726 if (!appended) { | |
727 break; | |
728 } | |
729 appended = AppendEventToString(event.get(), &output_string); | |
730 } | |
731 | |
732 // Serialize the events in the event queue. | |
733 while (appended && !history_.empty()) { | |
734 appended = AppendEventToString(history_.front().get(), &output_string); | |
735 if (appended) { | |
736 // Known issue - if writing to the file fails, these events will have | |
737 // been lost. If we try to open a new file, these events will be missing | |
738 // from it. | |
739 history_.pop_front(); | |
740 } | |
741 } | |
742 | |
743 // Write to file. | |
744 if (!file_->Write(output_string.data(), output_string.size())) { | |
745 LOG(LS_ERROR) << "FileWrapper failed to write WebRtcEventLog file."; | |
746 // The current FileWrapper implementation closes the file on error. | |
747 RTC_DCHECK(!file_->is_open()); | |
748 return; | |
749 } | |
750 written_bytes_ += output_string.size(); | |
751 | |
752 if (!appended) { | |
753 RTC_DCHECK(file_->is_open()); | |
754 StopLogFile(rtc::TimeMicros()); | |
755 } | |
756 } | |
757 | |
758 void RtcEventLogImpl::LogToFile(std::unique_ptr<rtclog::Event> event) { | |
759 RTC_DCHECK_RUN_ON(&task_queue_); | |
760 RTC_DCHECK(file_->is_open()); | |
761 | |
762 ProtoString output_string; | |
763 | |
764 bool appended = AppendEventToString(event.get(), &output_string); | |
765 | |
766 if (IsConfigEvent(*event.get())) { | |
767 config_history_.push_back(std::move(event)); | |
768 } | |
769 | |
770 if (!appended) { | |
771 RTC_DCHECK(file_->is_open()); | |
772 history_.push_back(std::move(event)); | |
773 StopLogFile(rtc::TimeMicros()); | |
774 return; | |
775 } | |
776 | |
777 // Write string to file. | |
778 if (file_->Write(output_string.data(), output_string.size())) { | |
779 written_bytes_ += output_string.size(); | |
780 } else { | |
781 LOG(LS_ERROR) << "FileWrapper failed to write WebRtcEventLog file."; | |
782 // The current FileWrapper implementation closes the file on error. | |
783 RTC_DCHECK(!file_->is_open()); | |
784 } | |
785 } | |
786 | |
787 void RtcEventLogImpl::StopLogFile(int64_t stop_time) { | |
788 RTC_DCHECK_RUN_ON(&task_queue_); | |
789 RTC_DCHECK(file_->is_open()); | |
790 | |
791 ProtoString output_string; | |
792 | |
793 rtclog::Event end_event; | |
794 end_event.set_timestamp_us(stop_time); | |
795 end_event.set_type(rtclog::Event::LOG_END); | |
796 bool appended = AppendEventToString(&end_event, &output_string); | |
797 | |
798 if (appended) { | |
799 if (!file_->Write(output_string.data(), output_string.size())) { | |
800 LOG(LS_ERROR) << "FileWrapper failed to write WebRtcEventLog file."; | |
801 // The current FileWrapper implementation closes the file on error. | |
802 RTC_DCHECK(!file_->is_open()); | |
803 } | |
804 written_bytes_ += output_string.size(); | |
805 } | |
806 | |
807 max_size_bytes_ = std::numeric_limits<decltype(max_size_bytes_)>::max(); | |
808 written_bytes_ = 0; | |
809 | |
810 file_->CloseFile(); | |
811 RTC_DCHECK(!file_->is_open()); | |
812 } | 574 } |
813 | 575 |
814 bool RtcEventLog::ParseRtcEventLog(const std::string& file_name, | 576 bool RtcEventLog::ParseRtcEventLog(const std::string& file_name, |
815 rtclog::EventStream* result) { | 577 rtclog::EventStream* result) { |
816 char tmp_buffer[1024]; | 578 char tmp_buffer[1024]; |
817 int bytes_read = 0; | 579 int bytes_read = 0; |
818 std::unique_ptr<FileWrapper> dump_file(FileWrapper::Create()); | 580 std::unique_ptr<FileWrapper> dump_file(FileWrapper::Create()); |
819 if (!dump_file->OpenFile(file_name.c_str(), true)) { | 581 if (!dump_file->OpenFile(file_name.c_str(), true)) { |
820 return false; | 582 return false; |
821 } | 583 } |
822 ProtoString dump_buffer; | 584 ProtoString dump_buffer; |
823 while ((bytes_read = dump_file->Read(tmp_buffer, sizeof(tmp_buffer))) > 0) { | 585 while ((bytes_read = dump_file->Read(tmp_buffer, sizeof(tmp_buffer))) > 0) { |
824 dump_buffer.append(tmp_buffer, bytes_read); | 586 dump_buffer.append(tmp_buffer, bytes_read); |
825 } | 587 } |
826 dump_file->CloseFile(); | 588 dump_file->CloseFile(); |
827 return result->ParseFromString(dump_buffer); | 589 return result->ParseFromString(dump_buffer); |
828 } | 590 } |
829 | 591 |
830 #endif // ENABLE_RTC_EVENT_LOG | 592 #endif // ENABLE_RTC_EVENT_LOG |
831 | 593 |
832 // RtcEventLog member functions. | 594 // RtcEventLog member functions. |
833 std::unique_ptr<RtcEventLog> RtcEventLog::Create() { | 595 std::unique_ptr<RtcEventLog> RtcEventLog::Create() { |
834 #ifdef ENABLE_RTC_EVENT_LOG | 596 #ifdef ENABLE_RTC_EVENT_LOG |
835 // TODO(eladalon): Known issue - there's a race over |log_count_| here. | |
836 constexpr int kMaxLogCount = 5; | 597 constexpr int kMaxLogCount = 5; |
837 int count = 1 + std::atomic_fetch_add(&RtcEventLogImpl::log_count_, 1); | 598 int count = rtc::AtomicOps::Increment(&RtcEventLogImpl::log_count_); |
838 if (count > kMaxLogCount) { | 599 if (count > kMaxLogCount) { |
839 LOG(LS_WARNING) << "Denied creation of additional WebRTC event logs. " | 600 LOG(LS_WARNING) << "Denied creation of additional WebRTC event logs. " |
840 << count - 1 << " logs open already."; | 601 << count - 1 << " logs open already."; |
841 std::atomic_fetch_sub(&RtcEventLogImpl::log_count_, 1); | 602 rtc::AtomicOps::Decrement(&RtcEventLogImpl::log_count_); |
842 return std::unique_ptr<RtcEventLog>(new RtcEventLogNullImpl()); | 603 return std::unique_ptr<RtcEventLog>(new RtcEventLogNullImpl()); |
843 } | 604 } |
844 return std::unique_ptr<RtcEventLog>(new RtcEventLogImpl()); | 605 return std::unique_ptr<RtcEventLog>(new RtcEventLogImpl()); |
845 #else | 606 #else |
846 return CreateNull(); | 607 return std::unique_ptr<RtcEventLog>(new RtcEventLogNullImpl()); |
847 #endif // ENABLE_RTC_EVENT_LOG | 608 #endif // ENABLE_RTC_EVENT_LOG |
848 } | 609 } |
849 | 610 |
850 std::unique_ptr<RtcEventLog> RtcEventLog::CreateNull() { | 611 std::unique_ptr<RtcEventLog> RtcEventLog::CreateNull() { |
851 return std::unique_ptr<RtcEventLog>(new RtcEventLogNullImpl()); | 612 return std::unique_ptr<RtcEventLog>(new RtcEventLogNullImpl()); |
852 } | 613 } |
853 | 614 |
854 } // namespace webrtc | 615 } // namespace webrtc |
OLD | NEW |