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