| OLD | NEW |
|---|
| (Empty) |
| 1 /* | |
| 2 * Copyright (c) 2016 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/call/rtc_event_log_helper_thread.h" | |
| 12 | |
| 13 #include <algorithm> | |
| 14 | |
| 15 #include "webrtc/base/checks.h" | |
| 16 #include "webrtc/system_wrappers/include/logging.h" | |
| 17 | |
| 18 #ifdef ENABLE_RTC_EVENT_LOG | |
| 19 | |
| 20 namespace webrtc { | |
| 21 | |
| 22 namespace { | |
| 23 const int kEventsInHistory = 10000; | |
| 24 | |
| 25 bool IsConfigEvent(const rtclog::Event& event) { | |
| 26 rtclog::Event_EventType event_type = event.type(); | |
| 27 return event_type == rtclog::Event::VIDEO_RECEIVER_CONFIG_EVENT || | |
| 28 event_type == rtclog::Event::VIDEO_SENDER_CONFIG_EVENT || | |
| 29 event_type == rtclog::Event::AUDIO_RECEIVER_CONFIG_EVENT || | |
| 30 event_type == rtclog::Event::AUDIO_SENDER_CONFIG_EVENT; | |
| 31 } | |
| 32 } // namespace | |
| 33 | |
| 34 // RtcEventLogImpl member functions. | |
| 35 RtcEventLogHelperThread::RtcEventLogHelperThread( | |
| 36 SwapQueue<ControlMessage>* message_queue, | |
| 37 SwapQueue<std::unique_ptr<rtclog::Event>>* event_queue, | |
| 38 const Clock* const clock) | |
| 39 : message_queue_(message_queue), | |
| 40 event_queue_(event_queue), | |
| 41 history_(kEventsInHistory), | |
| 42 config_history_(), | |
| 43 file_(FileWrapper::Create()), | |
| 44 thread_(&ThreadOutputFunction, this, "RtcEventLog thread"), | |
| 45 max_size_bytes_(std::numeric_limits<int64_t>::max()), | |
| 46 written_bytes_(0), | |
| 47 start_time_(0), | |
| 48 stop_time_(std::numeric_limits<int64_t>::max()), | |
| 49 has_recent_event_(false), | |
| 50 most_recent_event_(), | |
| 51 output_string_(), | |
| 52 wake_periodically_(false, false), | |
| 53 wake_from_hibernation_(false, false), | |
| 54 file_finished_(false, false), | |
| 55 clock_(clock) { | |
| 56 RTC_DCHECK(message_queue_); | |
| 57 RTC_DCHECK(event_queue_); | |
| 58 RTC_DCHECK(clock_); | |
| 59 thread_.Start(); | |
| 60 } | |
| 61 | |
| 62 RtcEventLogHelperThread::~RtcEventLogHelperThread() { | |
| 63 ControlMessage message; | |
| 64 message.message_type = ControlMessage::TERMINATE_THREAD; | |
| 65 message.stop_time = clock_->TimeInMicroseconds(); | |
| 66 while (!message_queue_->Insert(&message)) { | |
| 67 // We can't destroy the event log until we have stopped the thread, | |
| 68 // so clear the message queue and try again. Note that if we clear | |
| 69 // any STOP_FILE events, then the threads calling StopLogging would likely | |
| 70 // wait indefinitely. However, there should not be any such calls as we | |
| 71 // are executing the destructor. | |
| 72 LOG(LS_WARNING) << "Clearing message queue to terminate thread."; | |
| 73 message_queue_->Clear(); | |
| 74 } | |
| 75 wake_from_hibernation_.Set(); | |
| 76 wake_periodically_.Set(); // Wake up the output thread. | |
| 77 thread_.Stop(); // Wait for the thread to terminate. | |
| 78 } | |
| 79 | |
| 80 void RtcEventLogHelperThread::WaitForFileFinished() { | |
| 81 wake_from_hibernation_.Set(); | |
| 82 wake_periodically_.Set(); | |
| 83 file_finished_.Wait(rtc::Event::kForever); | |
| 84 } | |
| 85 | |
| 86 void RtcEventLogHelperThread::SignalNewEvent() { | |
| 87 wake_from_hibernation_.Set(); | |
| 88 } | |
| 89 | |
| 90 bool RtcEventLogHelperThread::AppendEventToString(rtclog::Event* event) { | |
| 91 rtclog::EventStream event_stream; | |
| 92 event_stream.add_stream(); | |
| 93 event_stream.mutable_stream(0)->Swap(event); | |
| 94 // We create a new event stream per event but because of the way protobufs | |
| 95 // are encoded, events can be merged by concatenating them. Therefore, | |
| 96 // it will look like a single stream when we read it back from file. | |
| 97 bool stop = true; | |
| 98 if (written_bytes_ + static_cast<int64_t>(output_string_.size()) + | |
| 99 event_stream.ByteSize() <= | |
| 100 max_size_bytes_) { | |
| 101 event_stream.AppendToString(&output_string_); | |
| 102 stop = false; | |
| 103 } | |
| 104 // Swap the event back so that we don't mix event types in the queues. | |
| 105 event_stream.mutable_stream(0)->Swap(event); | |
| 106 return stop; | |
| 107 } | |
| 108 | |
| 109 bool RtcEventLogHelperThread::LogToMemory() { | |
| 110 RTC_DCHECK(!file_->is_open()); | |
| 111 bool message_received = false; | |
| 112 | |
| 113 // Process each event earlier than the current time and append it to the | |
| 114 // appropriate history_. | |
| 115 int64_t current_time = clock_->TimeInMicroseconds(); | |
| 116 if (!has_recent_event_) { | |
| 117 has_recent_event_ = event_queue_->Remove(&most_recent_event_); | |
| 118 } | |
| 119 while (has_recent_event_ && | |
| 120 most_recent_event_->timestamp_us() <= current_time) { | |
| 121 if (IsConfigEvent(*most_recent_event_)) { | |
| 122 config_history_.push_back(std::move(most_recent_event_)); | |
| 123 } else { | |
| 124 history_.push_back(std::move(most_recent_event_)); | |
| 125 } | |
| 126 has_recent_event_ = event_queue_->Remove(&most_recent_event_); | |
| 127 message_received = true; | |
| 128 } | |
| 129 return message_received; | |
| 130 } | |
| 131 | |
| 132 void RtcEventLogHelperThread::StartLogFile() { | |
| 133 RTC_DCHECK(file_->is_open()); | |
| 134 bool stop = false; | |
| 135 output_string_.clear(); | |
| 136 | |
| 137 // Create and serialize the LOG_START event. | |
| 138 rtclog::Event start_event; | |
| 139 start_event.set_timestamp_us(start_time_); | |
| 140 start_event.set_type(rtclog::Event::LOG_START); | |
| 141 AppendEventToString(&start_event); | |
| 142 | |
| 143 // Serialize the config information for all old streams. | |
| 144 for (auto& event : config_history_) { | |
| 145 AppendEventToString(event.get()); | |
| 146 } | |
| 147 | |
| 148 // Serialize the events in the event queue. | |
| 149 while (!history_.empty() && !stop) { | |
| 150 stop = AppendEventToString(history_.front().get()); | |
| 151 if (!stop) { | |
| 152 history_.pop_front(); | |
| 153 } | |
| 154 } | |
| 155 | |
| 156 // Write to file. | |
| 157 if (!file_->Write(output_string_.data(), output_string_.size())) { | |
| 158 LOG(LS_ERROR) << "FileWrapper failed to write WebRtcEventLog file."; | |
| 159 // The current FileWrapper implementation closes the file on error. | |
| 160 RTC_DCHECK(!file_->is_open()); | |
| 161 return; | |
| 162 } | |
| 163 written_bytes_ += output_string_.size(); | |
| 164 | |
| 165 // Free the allocated memory since we probably won't need this amount of | |
| 166 // space again. | |
| 167 output_string_.clear(); | |
| 168 output_string_.shrink_to_fit(); | |
| 169 | |
| 170 if (stop) { | |
| 171 RTC_DCHECK(file_->is_open()); | |
| 172 StopLogFile(); | |
| 173 } | |
| 174 } | |
| 175 | |
| 176 bool RtcEventLogHelperThread::LogToFile() { | |
| 177 RTC_DCHECK(file_->is_open()); | |
| 178 output_string_.clear(); | |
| 179 bool message_received = false; | |
| 180 | |
| 181 // Append each event older than both the current time and the stop time | |
| 182 // to the output_string_. | |
| 183 int64_t current_time = clock_->TimeInMicroseconds(); | |
| 184 int64_t time_limit = std::min(current_time, stop_time_); | |
| 185 if (!has_recent_event_) { | |
| 186 has_recent_event_ = event_queue_->Remove(&most_recent_event_); | |
| 187 } | |
| 188 bool stop = false; | |
| 189 while (!stop && has_recent_event_ && | |
| 190 most_recent_event_->timestamp_us() <= time_limit) { | |
| 191 stop = AppendEventToString(most_recent_event_.get()); | |
| 192 if (!stop) { | |
| 193 if (IsConfigEvent(*most_recent_event_)) { | |
| 194 config_history_.push_back(std::move(most_recent_event_)); | |
| 195 } | |
| 196 has_recent_event_ = event_queue_->Remove(&most_recent_event_); | |
| 197 } | |
| 198 message_received = true; | |
| 199 } | |
| 200 | |
| 201 // Write string to file. | |
| 202 if (!file_->Write(output_string_.data(), output_string_.size())) { | |
| 203 LOG(LS_ERROR) << "FileWrapper failed to write WebRtcEventLog file."; | |
| 204 // The current FileWrapper implementation closes the file on error. | |
| 205 RTC_DCHECK(!file_->is_open()); | |
| 206 return message_received; | |
| 207 } | |
| 208 written_bytes_ += output_string_.size(); | |
| 209 | |
| 210 // We want to stop logging if we have reached the file size limit. We also | |
| 211 // want to stop logging if the remaining events are more recent than the | |
| 212 // time limit, or in other words if we have terminated the loop despite | |
| 213 // having more events in the queue. | |
| 214 if ((has_recent_event_ && most_recent_event_->timestamp_us() > stop_time_) || | |
| 215 stop) { | |
| 216 RTC_DCHECK(file_->is_open()); | |
| 217 StopLogFile(); | |
| 218 } | |
| 219 return message_received; | |
| 220 } | |
| 221 | |
| 222 void RtcEventLogHelperThread::StopLogFile() { | |
| 223 RTC_DCHECK(file_->is_open()); | |
| 224 output_string_.clear(); | |
| 225 | |
| 226 rtclog::Event end_event; | |
| 227 // This function can be called either because we have reached the stop time, | |
| 228 // or because we have reached the log file size limit. Therefore, use the | |
| 229 // current time if we have not reached the time limit. | |
| 230 end_event.set_timestamp_us( | |
| 231 std::min(stop_time_, clock_->TimeInMicroseconds())); | |
| 232 end_event.set_type(rtclog::Event::LOG_END); | |
| 233 AppendEventToString(&end_event); | |
| 234 | |
| 235 if (written_bytes_ + static_cast<int64_t>(output_string_.size()) <= | |
| 236 max_size_bytes_) { | |
| 237 if (!file_->Write(output_string_.data(), output_string_.size())) { | |
| 238 LOG(LS_ERROR) << "FileWrapper failed to write WebRtcEventLog file."; | |
| 239 // The current FileWrapper implementation closes the file on error. | |
| 240 RTC_DCHECK(!file_->is_open()); | |
| 241 } | |
| 242 written_bytes_ += output_string_.size(); | |
| 243 } | |
| 244 | |
| 245 max_size_bytes_ = std::numeric_limits<int64_t>::max(); | |
| 246 written_bytes_ = 0; | |
| 247 start_time_ = 0; | |
| 248 stop_time_ = std::numeric_limits<int64_t>::max(); | |
| 249 output_string_.clear(); | |
| 250 file_->CloseFile(); | |
| 251 RTC_DCHECK(!file_->is_open()); | |
| 252 } | |
| 253 | |
| 254 void RtcEventLogHelperThread::ProcessEvents() { | |
| 255 ControlMessage message; | |
| 256 | |
| 257 while (true) { | |
| 258 bool message_received = false; | |
| 259 // Process control messages. | |
| 260 while (message_queue_->Remove(&message)) { | |
| 261 switch (message.message_type) { | |
| 262 case ControlMessage::START_FILE: | |
| 263 if (!file_->is_open()) { | |
| 264 max_size_bytes_ = message.max_size_bytes; | |
| 265 start_time_ = message.start_time; | |
| 266 stop_time_ = message.stop_time; | |
| 267 file_.swap(message.file); | |
| 268 StartLogFile(); | |
| 269 } else { | |
| 270 // Already started. Ignore message and close file handle. | |
| 271 message.file->CloseFile(); | |
| 272 } | |
| 273 message_received = true; | |
| 274 break; | |
| 275 case ControlMessage::STOP_FILE: | |
| 276 if (file_->is_open()) { | |
| 277 stop_time_ = message.stop_time; | |
| 278 LogToFile(); // Log remaining events from message queues. | |
| 279 } | |
| 280 // LogToFile might stop on it's own so we need to recheck the state. | |
| 281 if (file_->is_open()) { | |
| 282 StopLogFile(); | |
| 283 } | |
| 284 file_finished_.Set(); | |
| 285 message_received = true; | |
| 286 break; | |
| 287 case ControlMessage::TERMINATE_THREAD: | |
| 288 if (file_->is_open()) { | |
| 289 StopLogFile(); | |
| 290 } | |
| 291 return; | |
| 292 } | |
| 293 } | |
| 294 | |
| 295 // Write events to file or memory. | |
| 296 if (file_->is_open()) { | |
| 297 message_received |= LogToFile(); | |
| 298 } else { | |
| 299 message_received |= LogToMemory(); | |
| 300 } | |
| 301 | |
| 302 // Accumulate a new batch of events instead of processing them one at a | |
| 303 // time. | |
| 304 if (message_received) { | |
| 305 wake_periodically_.Wait(100); | |
| 306 } else { | |
| 307 wake_from_hibernation_.Wait(rtc::Event::kForever); | |
| 308 } | |
| 309 } | |
| 310 } | |
| 311 | |
| 312 bool RtcEventLogHelperThread::ThreadOutputFunction(void* obj) { | |
| 313 RtcEventLogHelperThread* helper = static_cast<RtcEventLogHelperThread*>(obj); | |
| 314 helper->ProcessEvents(); | |
| 315 return false; | |
| 316 } | |
| 317 | |
| 318 } // namespace webrtc | |
| 319 | |
| 320 #endif // ENABLE_RTC_EVENT_LOG | |
| OLD | NEW |
|---|
Chromium Code Reviews
Issue 2380683005:
Moved RtcEventLog files from call/ to logging/ (new top level dir) (Closed)
