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