log_format.cc 7.7 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205
  1. //
  2. // Copyright 2022 The Abseil Authors.
  3. //
  4. // Licensed under the Apache License, Version 2.0 (the "License");
  5. // you may not use this file except in compliance with the License.
  6. // You may obtain a copy of the License at
  7. //
  8. // https://www.apache.org/licenses/LICENSE-2.0
  9. //
  10. // Unless required by applicable law or agreed to in writing, software
  11. // distributed under the License is distributed on an "AS IS" BASIS,
  12. // WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
  13. // See the License for the specific language governing permissions and
  14. // limitations under the License.
  15. #include "absl/log/internal/log_format.h"
  16. #include <string.h>
  17. #ifdef _MSC_VER
  18. #include <winsock2.h> // For timeval
  19. #else
  20. #include <sys/time.h>
  21. #endif
  22. #include <cstddef>
  23. #include <cstdint>
  24. #include <limits>
  25. #include <string>
  26. #include <type_traits>
  27. #include "absl/base/config.h"
  28. #include "absl/base/log_severity.h"
  29. #include "absl/base/optimization.h"
  30. #include "absl/log/internal/append_truncated.h"
  31. #include "absl/log/internal/config.h"
  32. #include "absl/log/internal/globals.h"
  33. #include "absl/strings/numbers.h"
  34. #include "absl/strings/str_format.h"
  35. #include "absl/strings/string_view.h"
  36. #include "absl/time/civil_time.h"
  37. #include "absl/time/time.h"
  38. #include "absl/types/span.h"
  39. namespace absl {
  40. ABSL_NAMESPACE_BEGIN
  41. namespace log_internal {
  42. namespace {
  43. // This templated function avoids compiler warnings about tautological
  44. // comparisons when log_internal::Tid is unsigned. It can be replaced with a
  45. // constexpr if once the minimum C++ version Abseil supports is C++17.
  46. template <typename T>
  47. inline std::enable_if_t<!std::is_signed<T>::value>
  48. PutLeadingWhitespace(T tid, char*& p) {
  49. if (tid < 10) *p++ = ' ';
  50. if (tid < 100) *p++ = ' ';
  51. if (tid < 1000) *p++ = ' ';
  52. if (tid < 10000) *p++ = ' ';
  53. if (tid < 100000) *p++ = ' ';
  54. if (tid < 1000000) *p++ = ' ';
  55. }
  56. template <typename T>
  57. inline std::enable_if_t<std::is_signed<T>::value>
  58. PutLeadingWhitespace(T tid, char*& p) {
  59. if (tid >= 0 && tid < 10) *p++ = ' ';
  60. if (tid > -10 && tid < 100) *p++ = ' ';
  61. if (tid > -100 && tid < 1000) *p++ = ' ';
  62. if (tid > -1000 && tid < 10000) *p++ = ' ';
  63. if (tid > -10000 && tid < 100000) *p++ = ' ';
  64. if (tid > -100000 && tid < 1000000) *p++ = ' ';
  65. }
  66. // The fields before the filename are all fixed-width except for the thread ID,
  67. // which is of bounded width.
  68. size_t FormatBoundedFields(absl::LogSeverity severity, absl::Time timestamp,
  69. log_internal::Tid tid, absl::Span<char>& buf) {
  70. constexpr size_t kBoundedFieldsMaxLen =
  71. sizeof("SMMDD HH:MM:SS.NNNNNN ") +
  72. (1 + std::numeric_limits<log_internal::Tid>::digits10 + 1) - sizeof("");
  73. if (ABSL_PREDICT_FALSE(buf.size() < kBoundedFieldsMaxLen)) {
  74. // We don't bother trying to truncate these fields if the buffer is too
  75. // short (or almost too short) because it would require doing a lot more
  76. // length checking (slow) and it should never happen. A 15kB buffer should
  77. // be enough for anyone. Instead we mark `buf` full without writing
  78. // anything.
  79. buf.remove_suffix(buf.size());
  80. return 0;
  81. }
  82. // We can't call absl::LocalTime(), localtime_r(), or anything else here that
  83. // isn't async-signal-safe. We can only use the time zone if it has already
  84. // been loaded.
  85. const absl::TimeZone* tz = absl::log_internal::TimeZone();
  86. if (ABSL_PREDICT_FALSE(tz == nullptr)) {
  87. // If a time zone hasn't been set yet because we are logging before the
  88. // logging library has been initialized, we fallback to a simpler, slower
  89. // method. Just report the raw Unix time in seconds. We cram this into the
  90. // normal time format for the benefit of parsers.
  91. auto tv = absl::ToTimeval(timestamp);
  92. int snprintf_result = absl::SNPrintF(
  93. buf.data(), buf.size(), "%c0000 00:00:%02d.%06d %7d ",
  94. absl::LogSeverityName(severity)[0], static_cast<int>(tv.tv_sec),
  95. static_cast<int>(tv.tv_usec), static_cast<int>(tid));
  96. if (snprintf_result >= 0) {
  97. buf.remove_prefix(static_cast<size_t>(snprintf_result));
  98. return static_cast<size_t>(snprintf_result);
  99. }
  100. return 0;
  101. }
  102. char* p = buf.data();
  103. *p++ = absl::LogSeverityName(severity)[0];
  104. const absl::TimeZone::CivilInfo ci = tz->At(timestamp);
  105. absl::numbers_internal::PutTwoDigits(static_cast<uint32_t>(ci.cs.month()), p);
  106. p += 2;
  107. absl::numbers_internal::PutTwoDigits(static_cast<uint32_t>(ci.cs.day()), p);
  108. p += 2;
  109. *p++ = ' ';
  110. absl::numbers_internal::PutTwoDigits(static_cast<uint32_t>(ci.cs.hour()), p);
  111. p += 2;
  112. *p++ = ':';
  113. absl::numbers_internal::PutTwoDigits(static_cast<uint32_t>(ci.cs.minute()),
  114. p);
  115. p += 2;
  116. *p++ = ':';
  117. absl::numbers_internal::PutTwoDigits(static_cast<uint32_t>(ci.cs.second()),
  118. p);
  119. p += 2;
  120. *p++ = '.';
  121. const int64_t usecs = absl::ToInt64Microseconds(ci.subsecond);
  122. absl::numbers_internal::PutTwoDigits(static_cast<uint32_t>(usecs / 10000), p);
  123. p += 2;
  124. absl::numbers_internal::PutTwoDigits(static_cast<uint32_t>(usecs / 100 % 100),
  125. p);
  126. p += 2;
  127. absl::numbers_internal::PutTwoDigits(static_cast<uint32_t>(usecs % 100), p);
  128. p += 2;
  129. *p++ = ' ';
  130. PutLeadingWhitespace(tid, p);
  131. p = absl::numbers_internal::FastIntToBuffer(tid, p);
  132. *p++ = ' ';
  133. const size_t bytes_formatted = static_cast<size_t>(p - buf.data());
  134. buf.remove_prefix(bytes_formatted);
  135. return bytes_formatted;
  136. }
  137. size_t FormatLineNumber(int line, absl::Span<char>& buf) {
  138. constexpr size_t kLineFieldMaxLen =
  139. sizeof(":] ") + (1 + std::numeric_limits<int>::digits10 + 1) - sizeof("");
  140. if (ABSL_PREDICT_FALSE(buf.size() < kLineFieldMaxLen)) {
  141. // As above, we don't bother trying to truncate this if the buffer is too
  142. // short and it should never happen.
  143. buf.remove_suffix(buf.size());
  144. return 0;
  145. }
  146. char* p = buf.data();
  147. *p++ = ':';
  148. p = absl::numbers_internal::FastIntToBuffer(line, p);
  149. *p++ = ']';
  150. *p++ = ' ';
  151. const size_t bytes_formatted = static_cast<size_t>(p - buf.data());
  152. buf.remove_prefix(bytes_formatted);
  153. return bytes_formatted;
  154. }
  155. } // namespace
  156. std::string FormatLogMessage(absl::LogSeverity severity,
  157. absl::CivilSecond civil_second,
  158. absl::Duration subsecond, log_internal::Tid tid,
  159. absl::string_view basename, int line,
  160. PrefixFormat format, absl::string_view message) {
  161. return absl::StrFormat(
  162. "%c%02d%02d %02d:%02d:%02d.%06d %7d %s:%d] %s%s",
  163. absl::LogSeverityName(severity)[0], civil_second.month(),
  164. civil_second.day(), civil_second.hour(), civil_second.minute(),
  165. civil_second.second(), absl::ToInt64Microseconds(subsecond), tid,
  166. basename, line, format == PrefixFormat::kRaw ? "RAW: " : "", message);
  167. }
  168. // This method is fairly hot, and the library always passes a huge `buf`, so we
  169. // save some bounds-checking cycles by not trying to do precise truncation.
  170. // Truncating at a field boundary is probably a better UX anyway.
  171. //
  172. // The prefix is written in three parts, each of which does a single
  173. // bounds-check and truncation:
  174. // 1. severity, timestamp, and thread ID
  175. // 2. filename
  176. // 3. line number and bracket
  177. size_t FormatLogPrefix(absl::LogSeverity severity, absl::Time timestamp,
  178. log_internal::Tid tid, absl::string_view basename,
  179. int line, PrefixFormat format, absl::Span<char>& buf) {
  180. auto prefix_size = FormatBoundedFields(severity, timestamp, tid, buf);
  181. prefix_size += log_internal::AppendTruncated(basename, buf);
  182. prefix_size += FormatLineNumber(line, buf);
  183. if (format == PrefixFormat::kRaw)
  184. prefix_size += log_internal::AppendTruncated("RAW: ", buf);
  185. return prefix_size;
  186. }
  187. } // namespace log_internal
  188. ABSL_NAMESPACE_END
  189. } // namespace absl