CustomLogFormatter.cpp 11 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282283284285286287288289290291292293294295296297298299300301302303304305306307308309310311312313314315316317318319320321322323324325326327328329330331332333334335336337338339
  1. /*
  2. * Copyright 2017-present Facebook, Inc.
  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. * http://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 <folly/logging/CustomLogFormatter.h>
  17. #include <folly/Format.h>
  18. #include <folly/logging/LogLevel.h>
  19. #include <folly/logging/LogMessage.h>
  20. #include <folly/portability/Time.h>
  21. #include <algorithm>
  22. namespace {
  23. using folly::LogLevel;
  24. using folly::StringPiece;
  25. StringPiece getGlogLevelName(LogLevel level) {
  26. if (level < LogLevel::INFO) {
  27. return "VERBOSE";
  28. } else if (level < LogLevel::WARN) {
  29. return "INFO";
  30. } else if (level < LogLevel::ERR) {
  31. return "WARNING";
  32. } else if (level < LogLevel::CRITICAL) {
  33. return "ERROR";
  34. } else if (level < LogLevel::DFATAL) {
  35. return "CRITICAL";
  36. }
  37. return "FATAL";
  38. }
  39. StringPiece getResetSequence(LogLevel level) {
  40. if (level >= LogLevel::INFO && level < LogLevel::WARN) {
  41. return "\033[0m";
  42. } else {
  43. return "";
  44. }
  45. }
  46. StringPiece getColorSequence(LogLevel level) {
  47. if (level < LogLevel::INFO) {
  48. return "\033[1;30m"; // BOLD/BRIGHT BLACK ~ GREY
  49. } else if (level < LogLevel::WARN) {
  50. return ""; // NO COLOR
  51. } else if (level < LogLevel::ERR) {
  52. return "\033[33m"; // YELLOW
  53. } else if (level < LogLevel::CRITICAL) {
  54. return "\033[31m"; // RED
  55. }
  56. return "\033[1;41m"; // BOLD ON RED BACKGROUND
  57. }
  58. struct FormatKeys {
  59. const StringPiece key;
  60. const std::size_t argIndex;
  61. const std::size_t width;
  62. constexpr FormatKeys(
  63. StringPiece key_,
  64. std::size_t argIndex_,
  65. std::size_t width_ = 0)
  66. : key(key_), argIndex(argIndex_), width(width_) {}
  67. };
  68. /**
  69. * The first part of pairs in this array are the key names and the second part
  70. * of the pairs are the argument index for folly::format().
  71. *
  72. * NOTE: This array must be sorted by key name, since we use std::lower_bound
  73. * to search in it.
  74. *
  75. * TODO: Support including thread names and thread context info.
  76. */
  77. constexpr std::array<FormatKeys, 11> formatKeys{{
  78. FormatKeys(/* key */ "D", /* argIndex */ 2, /* width */ 2),
  79. FormatKeys(/* key */ "FILE", /* argIndex */ 8),
  80. FormatKeys(/* key */ "FUN", /* argIndex */ 9),
  81. FormatKeys(/* key */ "H", /* argIndex */ 3, /* width */ 2),
  82. FormatKeys(/* key */ "L", /* argIndex */ 0, /* width */ 1),
  83. FormatKeys(/* key */ "LINE", /* argIndex */ 10, /* width */ 4),
  84. FormatKeys(/* key */ "M", /* argIndex */ 4, /* width */ 2),
  85. FormatKeys(/* key */ "S", /* argIndex */ 5, /* width */ 2),
  86. FormatKeys(/* key */ "THREAD", /* argIndex */ 7, /* width */ 5),
  87. FormatKeys(/* key */ "USECS", /* argIndex */ 6, /* width */ 6),
  88. FormatKeys(/* key */ "m", /* argIndex */ 1, /* width */ 2),
  89. }};
  90. constexpr int messageIndex = formatKeys.size();
  91. } // namespace
  92. namespace folly {
  93. CustomLogFormatter::CustomLogFormatter(StringPiece format, bool colored)
  94. : colored_(colored) {
  95. parseFormatString(format);
  96. }
  97. void CustomLogFormatter::parseFormatString(StringPiece input) {
  98. std::size_t estimatedWidth = 0;
  99. functionNameCount_ = 0;
  100. fileNameCount_ = 0;
  101. // Replace all format keys to numbers to improve performance and to use
  102. // varying value types (which is not possible using folly::vformat()).
  103. std::string output;
  104. output.reserve(input.size());
  105. const char* varNameStart = nullptr;
  106. enum StateEnum {
  107. LITERAL,
  108. FMT_NAME,
  109. FMT_MODIFIERS,
  110. } state = LITERAL;
  111. for (const char* p = input.begin(); p < input.end(); ++p) {
  112. switch (state) {
  113. case LITERAL:
  114. output.append(p, 1);
  115. // In case of `{{` or `}}`, copy it as it is and only increment the
  116. // estimatedWidth once as it will result to a single character in
  117. // output.
  118. if ((p + 1) != input.end() /* ensure not last character */ &&
  119. (0 == memcmp(p, "}}", 2) || 0 == memcmp(p, "{{", 2))) {
  120. output.append(p + 1, 1);
  121. estimatedWidth++;
  122. p++;
  123. }
  124. // If we see a single open curly brace, it denotes a start of a format
  125. // name and so we change the state to FMT_NAME and do not increment
  126. // estimatedWidth as it won't be in the output.
  127. else if (*p == '{') {
  128. varNameStart = p + 1;
  129. state = FMT_NAME;
  130. }
  131. // In case it is just a regular literal, just increment estimatedWidth
  132. // by one and move on to the next character.
  133. else {
  134. estimatedWidth++;
  135. }
  136. break;
  137. // In case we have started processing a format name/key
  138. case FMT_NAME:
  139. // Unless it is the end of the format name/key, do nothing and scan over
  140. // the name/key. When it is the end of the format name/key, look up
  141. // the argIndex for it and replace the name/key with that index.
  142. if (*p == ':' || *p == '}') {
  143. StringPiece varName(varNameStart, p);
  144. auto item = std::lower_bound(
  145. formatKeys.begin(),
  146. formatKeys.end(),
  147. varName,
  148. [](const auto& a, const auto& b) { return a.key < b; });
  149. if (UNLIKELY(item == formatKeys.end() || item->key != varName)) {
  150. throw std::runtime_error(folly::to<std::string>(
  151. "unknown format argument \"", varName, "\""));
  152. }
  153. output.append(folly::to<std::string>(item->argIndex));
  154. output.append(p, 1);
  155. // Based on the format key, increment estimatedWidth with the
  156. // estimate of how many characters long the value of the format key
  157. // will be. If it is a FILE or a FUN, the width will be variable
  158. // depending on the values of those fields.
  159. estimatedWidth += item->width;
  160. if (item->key == "FILE") {
  161. fileNameCount_++;
  162. } else if (item->key == "FUN") {
  163. functionNameCount_++;
  164. }
  165. // Figure out if there are modifiers that follow the key or if we
  166. // continue processing literals.
  167. if (*p == ':') {
  168. state = FMT_MODIFIERS;
  169. } else {
  170. state = LITERAL;
  171. }
  172. }
  173. break;
  174. // In case we have started processing a format modifier (after :)
  175. case FMT_MODIFIERS:
  176. // Modifiers are just copied as is and are not considered to determine
  177. // the estimatedWidth.
  178. output.append(p, 1);
  179. if (*p == '}') {
  180. state = LITERAL;
  181. }
  182. break;
  183. }
  184. }
  185. if (state != LITERAL) {
  186. throw std::runtime_error("unterminated format string");
  187. }
  188. // Append a single space after the header format if header is not empty.
  189. if (!output.empty()) {
  190. output.append(" ");
  191. estimatedWidth++;
  192. }
  193. logFormat_ = output;
  194. staticEstimatedWidth_ = estimatedWidth;
  195. // populate singleLineLogFormat_ with the padded line format.
  196. if (colored_) {
  197. singleLineLogFormat_ = folly::to<std::string>(
  198. "{",
  199. messageIndex + 1,
  200. "}",
  201. logFormat_,
  202. "{",
  203. messageIndex,
  204. "}{",
  205. messageIndex + 2,
  206. "}\n");
  207. } else {
  208. singleLineLogFormat_ =
  209. folly::to<std::string>(logFormat_, "{", messageIndex, "}\n");
  210. }
  211. }
  212. std::string CustomLogFormatter::formatMessage(
  213. const LogMessage& message,
  214. const LogCategory* /* handlerCategory */) {
  215. // Get the local time info
  216. struct tm ltime;
  217. auto timeSinceEpoch = message.getTimestamp().time_since_epoch();
  218. auto epochSeconds =
  219. std::chrono::duration_cast<std::chrono::seconds>(timeSinceEpoch);
  220. std::chrono::microseconds usecs =
  221. std::chrono::duration_cast<std::chrono::microseconds>(timeSinceEpoch) -
  222. epochSeconds;
  223. time_t unixTimestamp = epochSeconds.count();
  224. if (!localtime_r(&unixTimestamp, &ltime)) {
  225. memset(&ltime, 0, sizeof(ltime));
  226. }
  227. auto basename = message.getFileBaseName();
  228. // Most common logs will be single line logs and so we can format the entire
  229. // log string including the message at once.
  230. if (!message.containsNewlines()) {
  231. return folly::sformat(
  232. singleLineLogFormat_,
  233. getGlogLevelName(message.getLevel())[0],
  234. ltime.tm_mon + 1,
  235. ltime.tm_mday,
  236. ltime.tm_hour,
  237. ltime.tm_min,
  238. ltime.tm_sec,
  239. usecs.count(),
  240. message.getThreadID(),
  241. basename,
  242. message.getFunctionName(),
  243. message.getLineNumber(),
  244. // NOTE: THE FOLLOWING ARGUMENTS ALWAYS NEED TO BE THE LAST 3:
  245. message.getMessage(),
  246. // If colored logs are enabled, the singleLineLogFormat_ will contain
  247. // placeholders for the color and the reset sequences. If not, then
  248. // the following params will just be ignored by the folly::sformat().
  249. getColorSequence(message.getLevel()),
  250. getResetSequence(message.getLevel()));
  251. }
  252. // If the message contains multiple lines, ensure that the log header is
  253. // prepended before each message line.
  254. else {
  255. const auto headerFormatter = folly::format(
  256. logFormat_,
  257. getGlogLevelName(message.getLevel())[0],
  258. ltime.tm_mon + 1,
  259. ltime.tm_mday,
  260. ltime.tm_hour,
  261. ltime.tm_min,
  262. ltime.tm_sec,
  263. usecs.count(),
  264. message.getThreadID(),
  265. basename,
  266. message.getFunctionName(),
  267. message.getLineNumber());
  268. // Estimate header length. If this still isn't long enough the string will
  269. // grow as necessary, so the code will still be correct, but just slightly
  270. // less efficient than if we had allocated a large enough buffer the first
  271. // time around.
  272. size_t headerLengthGuess = staticEstimatedWidth_ +
  273. (fileNameCount_ * basename.size()) +
  274. (functionNameCount_ * message.getFunctionName().size());
  275. // Format the data into a buffer.
  276. std::string buffer;
  277. // If colored logging is supported, then process the color based on
  278. // the level of the message.
  279. if (colored_) {
  280. buffer.append(getColorSequence(message.getLevel()).toString());
  281. }
  282. StringPiece msgData{message.getMessage()};
  283. // Make a guess at how many lines will be in the message, just to make an
  284. // initial buffer allocation. If the guess is too small then the string
  285. // will reallocate and grow as necessary, it will just be slightly less
  286. // efficient than if we had guessed enough space.
  287. size_t numLinesGuess = 4;
  288. buffer.reserve((headerLengthGuess * numLinesGuess) + msgData.size());
  289. size_t idx = 0;
  290. while (true) {
  291. auto end = msgData.find('\n', idx);
  292. if (end == StringPiece::npos) {
  293. end = msgData.size();
  294. }
  295. auto line = msgData.subpiece(idx, end - idx);
  296. headerFormatter.appendTo(buffer);
  297. buffer.append(line.data(), line.size());
  298. buffer.push_back('\n');
  299. if (end == msgData.size()) {
  300. break;
  301. }
  302. idx = end + 1;
  303. }
  304. // If colored logging is supported and the current message is a color other
  305. // than the default, then RESET colors after printing message.
  306. if (colored_) {
  307. buffer.append(getResetSequence(message.getLevel()).toString());
  308. }
  309. return buffer;
  310. }
  311. }
  312. } // namespace folly