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