1 /*
2 * Copyright (c) 2013 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 "modules/remote_bitrate_estimator/test/bwe_test_logging.h"
12
13 #if BWE_TEST_LOGGING_COMPILE_TIME_ENABLE
14
15 #include <stdarg.h>
16 #include <stdio.h>
17
18 #include <algorithm>
19
20 #include "rtc_base/checks.h"
21 #include "rtc_base/format_macros.h"
22 #include "rtc_base/platform_thread.h"
23 #include "rtc_base/strings/string_builder.h"
24
25 namespace webrtc {
26 namespace testing {
27 namespace bwe {
28
ToString(uint32_t v)29 static std::string ToString(uint32_t v) {
30 rtc::StringBuilder ss;
31 ss << v;
32 return ss.Release();
33 }
34
35 Logging::ThreadState::ThreadState() = default;
36 Logging::ThreadState::~ThreadState() = default;
37
Context(uint32_t name,int64_t timestamp_ms,bool enabled)38 Logging::Context::Context(uint32_t name, int64_t timestamp_ms, bool enabled) {
39 Logging::GetInstance()->PushState(ToString(name), timestamp_ms, enabled);
40 }
41
Context(const std::string & name,int64_t timestamp_ms,bool enabled)42 Logging::Context::Context(const std::string& name,
43 int64_t timestamp_ms,
44 bool enabled) {
45 Logging::GetInstance()->PushState(name, timestamp_ms, enabled);
46 }
47
Context(const char * name,int64_t timestamp_ms,bool enabled)48 Logging::Context::Context(const char* name,
49 int64_t timestamp_ms,
50 bool enabled) {
51 Logging::GetInstance()->PushState(name, timestamp_ms, enabled);
52 }
53
~Context()54 Logging::Context::~Context() {
55 Logging::GetInstance()->PopState();
56 }
57
GetInstance()58 Logging* Logging::GetInstance() {
59 static Logging* logging = new Logging();
60 return logging;
61 }
62
SetGlobalContext(uint32_t name)63 void Logging::SetGlobalContext(uint32_t name) {
64 MutexLock lock(&mutex_);
65 thread_map_[rtc::CurrentThreadId()].global_state.tag = ToString(name);
66 }
67
SetGlobalContext(const std::string & name)68 void Logging::SetGlobalContext(const std::string& name) {
69 MutexLock lock(&mutex_);
70 thread_map_[rtc::CurrentThreadId()].global_state.tag = name;
71 }
72
SetGlobalContext(const char * name)73 void Logging::SetGlobalContext(const char* name) {
74 MutexLock lock(&mutex_);
75 thread_map_[rtc::CurrentThreadId()].global_state.tag = name;
76 }
77
SetGlobalEnable(bool enabled)78 void Logging::SetGlobalEnable(bool enabled) {
79 MutexLock lock(&mutex_);
80 thread_map_[rtc::CurrentThreadId()].global_state.enabled = enabled;
81 }
82
Log(const char format[],...)83 void Logging::Log(const char format[], ...) {
84 MutexLock lock(&mutex_);
85 ThreadMap::iterator it = thread_map_.find(rtc::CurrentThreadId());
86 RTC_DCHECK(it != thread_map_.end());
87 const State& state = it->second.stack.top();
88 if (state.enabled) {
89 printf("%s\t", state.tag.c_str());
90 va_list args;
91 va_start(args, format);
92 vprintf(format, args);
93 va_end(args);
94 printf("\n");
95 }
96 }
97
Plot(int figure,const std::string & name,double value)98 void Logging::Plot(int figure, const std::string& name, double value) {
99 Plot(figure, name, value, 0, "-");
100 }
101
Plot(int figure,const std::string & name,double value,uint32_t ssrc)102 void Logging::Plot(int figure,
103 const std::string& name,
104 double value,
105 uint32_t ssrc) {
106 Plot(figure, name, value, ssrc, "-");
107 }
108
Plot(int figure,const std::string & name,double value,const std::string & alg_name)109 void Logging::Plot(int figure,
110 const std::string& name,
111 double value,
112 const std::string& alg_name) {
113 Plot(figure, name, value, 0, alg_name);
114 }
115
Plot(int figure,const std::string & name,double value,uint32_t ssrc,const std::string & alg_name)116 void Logging::Plot(int figure,
117 const std::string& name,
118 double value,
119 uint32_t ssrc,
120 const std::string& alg_name) {
121 MutexLock lock(&mutex_);
122 ThreadMap::iterator it = thread_map_.find(rtc::CurrentThreadId());
123 RTC_DCHECK(it != thread_map_.end());
124 const State& state = it->second.stack.top();
125 if (state.enabled) {
126 printf("PLOT\t%d\t%s:%" PRIu32 "@%s\t%f\t%f\n", figure, name.c_str(), ssrc,
127 alg_name.c_str(), state.timestamp_ms * 0.001, value);
128 }
129 }
130
PlotBar(int figure,const std::string & name,double value,int flow_id)131 void Logging::PlotBar(int figure,
132 const std::string& name,
133 double value,
134 int flow_id) {
135 MutexLock lock(&mutex_);
136 ThreadMap::iterator it = thread_map_.find(rtc::CurrentThreadId());
137 RTC_DCHECK(it != thread_map_.end());
138 const State& state = it->second.stack.top();
139 if (state.enabled) {
140 printf("BAR\t%d\t%s_%d\t%f\n", figure, name.c_str(), flow_id, value);
141 }
142 }
143
PlotBaselineBar(int figure,const std::string & name,double value,int flow_id)144 void Logging::PlotBaselineBar(int figure,
145 const std::string& name,
146 double value,
147 int flow_id) {
148 MutexLock lock(&mutex_);
149 ThreadMap::iterator it = thread_map_.find(rtc::CurrentThreadId());
150 RTC_DCHECK(it != thread_map_.end());
151 const State& state = it->second.stack.top();
152 if (state.enabled) {
153 printf("BASELINE\t%d\t%s_%d\t%f\n", figure, name.c_str(), flow_id, value);
154 }
155 }
156
PlotErrorBar(int figure,const std::string & name,double value,double ylow,double yhigh,const std::string & error_title,int flow_id)157 void Logging::PlotErrorBar(int figure,
158 const std::string& name,
159 double value,
160 double ylow,
161 double yhigh,
162 const std::string& error_title,
163 int flow_id) {
164 MutexLock lock(&mutex_);
165 ThreadMap::iterator it = thread_map_.find(rtc::CurrentThreadId());
166 RTC_DCHECK(it != thread_map_.end());
167 const State& state = it->second.stack.top();
168 if (state.enabled) {
169 printf("ERRORBAR\t%d\t%s_%d\t%f\t%f\t%f\t%s\n", figure, name.c_str(),
170 flow_id, value, ylow, yhigh, error_title.c_str());
171 }
172 }
173
PlotLimitErrorBar(int figure,const std::string & name,double value,double ylow,double yhigh,const std::string & error_title,double ymax,const std::string & limit_title,int flow_id)174 void Logging::PlotLimitErrorBar(int figure,
175 const std::string& name,
176 double value,
177 double ylow,
178 double yhigh,
179 const std::string& error_title,
180 double ymax,
181 const std::string& limit_title,
182 int flow_id) {
183 MutexLock lock(&mutex_);
184 ThreadMap::iterator it = thread_map_.find(rtc::CurrentThreadId());
185 RTC_DCHECK(it != thread_map_.end());
186 const State& state = it->second.stack.top();
187 if (state.enabled) {
188 printf("LIMITERRORBAR\t%d\t%s_%d\t%f\t%f\t%f\t%s\t%f\t%s\n", figure,
189 name.c_str(), flow_id, value, ylow, yhigh, error_title.c_str(), ymax,
190 limit_title.c_str());
191 }
192 }
193
PlotLabel(int figure,const std::string & title,const std::string & y_label,int num_flows)194 void Logging::PlotLabel(int figure,
195 const std::string& title,
196 const std::string& y_label,
197 int num_flows) {
198 MutexLock lock(&mutex_);
199 ThreadMap::iterator it = thread_map_.find(rtc::CurrentThreadId());
200 RTC_DCHECK(it != thread_map_.end());
201 const State& state = it->second.stack.top();
202 if (state.enabled) {
203 printf("LABEL\t%d\t%s\t%s\t%d\n", figure, title.c_str(), y_label.c_str(),
204 num_flows);
205 }
206 }
207
Logging()208 Logging::Logging() : thread_map_() {}
209
210 Logging::~Logging() = default;
211
State()212 Logging::State::State() : tag(""), timestamp_ms(0), enabled(true) {}
213
State(const std::string & tag,int64_t timestamp_ms,bool enabled)214 Logging::State::State(const std::string& tag,
215 int64_t timestamp_ms,
216 bool enabled)
217 : tag(tag), timestamp_ms(timestamp_ms), enabled(enabled) {}
218
MergePrevious(const State & previous)219 void Logging::State::MergePrevious(const State& previous) {
220 if (tag.empty()) {
221 tag = previous.tag;
222 } else if (!previous.tag.empty()) {
223 tag = previous.tag + "_" + tag;
224 }
225 timestamp_ms = std::max(previous.timestamp_ms, timestamp_ms);
226 enabled = previous.enabled && enabled;
227 }
228
PushState(const std::string & append_to_tag,int64_t timestamp_ms,bool enabled)229 void Logging::PushState(const std::string& append_to_tag,
230 int64_t timestamp_ms,
231 bool enabled) {
232 MutexLock lock(&mutex_);
233 State new_state(append_to_tag, timestamp_ms, enabled);
234 ThreadState* thread_state = &thread_map_[rtc::CurrentThreadId()];
235 std::stack<State>* stack = &thread_state->stack;
236 if (stack->empty()) {
237 new_state.MergePrevious(thread_state->global_state);
238 } else {
239 new_state.MergePrevious(stack->top());
240 }
241 stack->push(new_state);
242 }
243
PopState()244 void Logging::PopState() {
245 MutexLock lock(&mutex_);
246 ThreadMap::iterator it = thread_map_.find(rtc::CurrentThreadId());
247 RTC_DCHECK(it != thread_map_.end());
248 std::stack<State>* stack = &it->second.stack;
249 int64_t newest_timestamp_ms = stack->top().timestamp_ms;
250 stack->pop();
251 if (!stack->empty()) {
252 State* state = &stack->top();
253 // Update time so that next log/plot will use the latest time seen so far
254 // in this call tree.
255 state->timestamp_ms = std::max(state->timestamp_ms, newest_timestamp_ms);
256 }
257 }
258 } // namespace bwe
259 } // namespace testing
260 } // namespace webrtc
261
262 #endif // BWE_TEST_LOGGING_COMPILE_TIME_ENABLE
263