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