logger_benchmark.cc 5.9 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253
  1. // Copyright The OpenTelemetry Authors
  2. // SPDX-License-Identifier: Apache-2.0
  3. #include <benchmark/benchmark.h>
  4. #include <stdint.h>
  5. #include <algorithm>
  6. #include <condition_variable>
  7. #include <cstddef>
  8. #include <functional>
  9. #include <mutex>
  10. #include <thread>
  11. #include <utility>
  12. #include <vector>
  13. #include "opentelemetry/common/key_value_iterable_view.h"
  14. #include "opentelemetry/logs/event_id.h"
  15. #include "opentelemetry/logs/logger.h"
  16. #include "opentelemetry/logs/logger_provider.h"
  17. #include "opentelemetry/logs/provider.h"
  18. #include "opentelemetry/logs/severity.h"
  19. #include "opentelemetry/nostd/shared_ptr.h"
  20. #include "opentelemetry/nostd/string_view.h"
  21. using opentelemetry::logs::EventId;
  22. using opentelemetry::logs::Provider;
  23. using opentelemetry::logs::Severity;
  24. namespace
  25. {
  26. constexpr int64_t kMaxIterations = 1000000000;
  27. class Barrier
  28. {
  29. public:
  30. explicit Barrier(std::size_t iCount) : mThreshold(iCount), mCount(iCount) {}
  31. void Wait()
  32. {
  33. std::unique_lock<std::mutex> lLock{mMutex};
  34. auto lGen = mGeneration;
  35. if (!--mCount)
  36. {
  37. mGeneration++;
  38. mCount = mThreshold;
  39. mCond.notify_all();
  40. }
  41. else
  42. {
  43. mCond.wait(lLock, [this, lGen] { return lGen != mGeneration; });
  44. }
  45. }
  46. private:
  47. std::mutex mMutex;
  48. std::condition_variable mCond;
  49. std::size_t mThreshold;
  50. std::size_t mCount;
  51. std::size_t mGeneration{0};
  52. };
  53. static void ThreadRoutine(Barrier &barrier,
  54. benchmark::State &state,
  55. int thread_id,
  56. const std::function<void()> &func)
  57. {
  58. barrier.Wait();
  59. if (thread_id == 0)
  60. {
  61. state.ResumeTiming();
  62. }
  63. barrier.Wait();
  64. func();
  65. if (thread_id == 0)
  66. {
  67. state.PauseTiming();
  68. }
  69. barrier.Wait();
  70. }
  71. void MultiThreadRunner(benchmark::State &state, const std::function<void()> &func)
  72. {
  73. uint32_t num_threads = std::thread::hardware_concurrency();
  74. Barrier barrier(num_threads);
  75. std::vector<std::thread> threads;
  76. threads.reserve(num_threads);
  77. for (uint32_t i = 0; i < num_threads; i++)
  78. {
  79. threads.emplace_back(ThreadRoutine, std::ref(barrier), std::ref(state), i, func);
  80. }
  81. for (auto &thread : threads)
  82. {
  83. thread.join();
  84. }
  85. }
  86. static void BM_UnstructuredLog(benchmark::State &state)
  87. {
  88. auto lp = Provider::GetLoggerProvider();
  89. auto logger = lp->GetLogger("UnstructuredLog");
  90. for (auto _ : state)
  91. {
  92. state.PauseTiming();
  93. MultiThreadRunner(state, [&logger]() {
  94. for (int64_t i = 0; i < kMaxIterations; i++)
  95. {
  96. logger->Trace("This is a simple unstructured log message");
  97. }
  98. });
  99. state.ResumeTiming();
  100. }
  101. }
  102. BENCHMARK(BM_UnstructuredLog);
  103. static void BM_StructuredLogWithTwoAttributes(benchmark::State &state)
  104. {
  105. auto lp = Provider::GetLoggerProvider();
  106. auto logger = lp->GetLogger("StructuredLog");
  107. for (auto _ : state)
  108. {
  109. state.PauseTiming();
  110. MultiThreadRunner(state, [&logger]() {
  111. for (int64_t i = 0; i < kMaxIterations; i++)
  112. {
  113. logger->Trace(
  114. "This is a simple structured log message from {process_id}:{thread_id}",
  115. opentelemetry::common::MakeAttributes({{"process_id", 12347}, {"thread_id", 12348}}));
  116. }
  117. });
  118. state.ResumeTiming();
  119. }
  120. }
  121. BENCHMARK(BM_StructuredLogWithTwoAttributes);
  122. static void BM_StructuredLogWithEventIdAndTwoAttributes(benchmark::State &state)
  123. {
  124. auto lp = Provider::GetLoggerProvider();
  125. auto logger = lp->GetLogger("StructuredLogWithEventId");
  126. for (auto _ : state)
  127. {
  128. state.PauseTiming();
  129. MultiThreadRunner(state, [&logger]() {
  130. for (int64_t i = 0; i < kMaxIterations; i++)
  131. {
  132. logger->Trace(
  133. 0x12345678, "This is a simple structured log message from {process_id}:{thread_id}",
  134. opentelemetry::common::MakeAttributes({{"process_id", 12347}, {"thread_id", 12348}}));
  135. }
  136. });
  137. state.ResumeTiming();
  138. }
  139. }
  140. BENCHMARK(BM_StructuredLogWithEventIdAndTwoAttributes);
  141. static void BM_StructuredLogWithEventIdStructAndTwoAttributes(benchmark::State &state)
  142. {
  143. auto lp = Provider::GetLoggerProvider();
  144. auto logger = lp->GetLogger("StructuredLogWithEventId");
  145. const EventId function_name_event_id{0x12345678, "Company.Component.SubComponent.FunctionName"};
  146. for (auto _ : state)
  147. {
  148. state.PauseTiming();
  149. MultiThreadRunner(state, [&logger, &function_name_event_id]() {
  150. for (int64_t i = 0; i < kMaxIterations; i++)
  151. {
  152. logger->Trace(
  153. function_name_event_id,
  154. "Simulate function enter trace message from {process_id}:{thread_id}",
  155. opentelemetry::common::MakeAttributes({{"process_id", 12347}, {"thread_id", 12348}}));
  156. }
  157. });
  158. state.ResumeTiming();
  159. }
  160. }
  161. BENCHMARK(BM_StructuredLogWithEventIdStructAndTwoAttributes);
  162. static void BM_EnabledOnSeverityReturnFalse(benchmark::State &state)
  163. {
  164. auto lp = Provider::GetLoggerProvider();
  165. auto logger = lp->GetLogger("UnstructuredLogWithEnabledReturnFalse");
  166. for (auto _ : state)
  167. {
  168. state.PauseTiming();
  169. MultiThreadRunner(state, [&logger]() {
  170. for (int64_t i = 0; i < kMaxIterations; i++)
  171. {
  172. if (logger->Enabled(Severity::kTrace))
  173. {
  174. logger->Trace("This log line would not be called");
  175. }
  176. }
  177. });
  178. state.ResumeTiming();
  179. }
  180. }
  181. BENCHMARK(BM_EnabledOnSeverityReturnFalse);
  182. static void BM_EnabledOnSeverityAndEventIdReturnFalse(benchmark::State &state)
  183. {
  184. auto lp = Provider::GetLoggerProvider();
  185. auto logger = lp->GetLogger("UnstructuredLogWithEnabledReturnFalse");
  186. for (auto _ : state)
  187. {
  188. state.PauseTiming();
  189. MultiThreadRunner(state, [&logger]() {
  190. for (int64_t i = 0; i < kMaxIterations; i++)
  191. {
  192. if (logger->Enabled(Severity::kTrace, 0x12345678))
  193. {
  194. logger->Trace("This log line would not be called");
  195. }
  196. }
  197. });
  198. state.ResumeTiming();
  199. }
  200. }
  201. BENCHMARK(BM_EnabledOnSeverityAndEventIdReturnFalse);
  202. } // namespace
  203. int main(int argc, char **argv)
  204. {
  205. benchmark::Initialize(&argc, argv);
  206. benchmark::RunSpecifiedBenchmarks();
  207. }