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
24namespace webrtc {
25namespace testing {
26namespace bwe {
27
28Logging Logging::g_Logging;
29
30static std::string ToString(uint32_t v) {
31  std::stringstream ss;
32  ss << v;
33  return ss.str();
34}
35
36Logging::Context::Context(uint32_t name, int64_t timestamp_ms, bool enabled) {
37  Logging::GetInstance()->PushState(ToString(name), timestamp_ms, enabled);
38}
39
40Logging::Context::Context(const std::string& name, int64_t timestamp_ms,
41                          bool enabled) {
42  Logging::GetInstance()->PushState(name, timestamp_ms, enabled);
43}
44
45Logging::Context::Context(const char* name, int64_t timestamp_ms,
46                          bool enabled) {
47  Logging::GetInstance()->PushState(name, timestamp_ms, enabled);
48}
49
50Logging::Context::~Context() {
51  Logging::GetInstance()->PopState();
52}
53
54Logging* Logging::GetInstance() {
55  return &g_Logging;
56}
57
58void Logging::SetGlobalContext(uint32_t name) {
59  CriticalSectionScoped cs(crit_sect_.get());
60  thread_map_[rtc::CurrentThreadId()].global_state.tag = ToString(name);
61}
62
63void Logging::SetGlobalContext(const std::string& name) {
64  CriticalSectionScoped cs(crit_sect_.get());
65  thread_map_[rtc::CurrentThreadId()].global_state.tag = name;
66}
67
68void Logging::SetGlobalContext(const char* name) {
69  CriticalSectionScoped cs(crit_sect_.get());
70  thread_map_[rtc::CurrentThreadId()].global_state.tag = name;
71}
72
73void Logging::SetGlobalEnable(bool enabled) {
74  CriticalSectionScoped cs(crit_sect_.get());
75  thread_map_[rtc::CurrentThreadId()].global_state.enabled = enabled;
76}
77
78void 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
93void Logging::Plot(int figure, double value) {
94  Plot(figure, value, "-");
95}
96
97void 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
117void 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
130void 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
143void 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
160void 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
180void 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
194Logging::Logging()
195    : crit_sect_(CriticalSectionWrapper::CreateCriticalSection()),
196      thread_map_() {
197}
198
199Logging::State::State() : tag(""), timestamp_ms(0), enabled(true) {}
200
201Logging::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
208void 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
218void 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
232void 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