The Battle for Wesnoth  1.17.14+dev
log.cpp
Go to the documentation of this file.
1 /*
2  Copyright (C) 2004 - 2022
3  by Guillaume Melquiond <guillaume.melquiond@gmail.com>
4  Copyright (C) 2003 by David White <dave@whitevine.net>
5  Part of the Battle for Wesnoth Project https://www.wesnoth.org/
6 
7  This program is free software; you can redistribute it and/or modify
8  it under the terms of the GNU General Public License as published by
9  the Free Software Foundation; either version 2 of the License, or
10  (at your option) any later version.
11  This program is distributed in the hope that it will be useful,
12  but WITHOUT ANY WARRANTY.
13 
14  See the COPYING file for more details.
15 */
16 
17 /**
18  * @file
19  * Standard logging facilities (implementation).
20  * See also the command line switches --logdomains and --log-@<level@>="domain".
21  */
22 
23 #include "log.hpp"
24 
25 #include "filesystem.hpp"
26 #include "mt_rng.hpp"
27 
28 #include <boost/algorithm/string.hpp>
29 
30 #include <map>
31 #include <sstream>
32 #include <ctime>
33 #include <mutex>
34 #include <iostream>
35 #include <iomanip>
36 
37 static lg::log_domain log_setup("logsetup");
38 #define ERR_LS LOG_STREAM(err, log_setup)
39 #define WRN_LS LOG_STREAM(warn, log_setup)
40 #define LOG_LS LOG_STREAM(info, log_setup)
41 #define DBG_LS LOG_STREAM(debug, log_setup)
42 
43 namespace {
44 
45 class null_streambuf : public std::streambuf
46 {
47  virtual int overflow(int c) { return std::char_traits< char >::not_eof(c); }
48 public:
49  null_streambuf() {}
50 };
51 
52 } // end anonymous namespace
53 
54 static std::ostream null_ostream(new null_streambuf);
55 static int indent = 0;
56 static bool timestamp = true;
57 static bool precise_timestamp = false;
58 static std::mutex log_mutex;
59 
60 static bool is_log_dir_writable_ = true;
61 static std::ostream *output_stream_ = nullptr;
62 
63 static std::ostream& output()
64 {
65  if(output_stream_) {
66  return *output_stream_;
67  }
68  return std::cerr;
69 }
70 
71 // custom deleter needed to reset cerr and cout
72 // otherwise wesnoth segfaults on closing (such as clicking the Quit button on the main menu)
73 // seems to be that there's a final flush done outside of wesnoth's code just before exiting
74 // but at that point the output_file_ has already been cleaned up
75 static std::unique_ptr<std::ostream, void(*)(std::ostream*)> output_file_(nullptr, [](std::ostream*){
76  std::cerr.rdbuf(nullptr);
77  std::cout.rdbuf(nullptr);
78 });
79 static std::string output_file_path_ = "";
80 
81 namespace lg {
82 
83 /** Helper function for rotate_logs. */
84 bool is_not_log_file(const std::string& fn)
85 {
86  return !(boost::algorithm::istarts_with(fn, lg::log_file_prefix) &&
87  boost::algorithm::iends_with(fn, lg::log_file_suffix));
88 }
89 
90 /**
91  * Deletes old log files from the log directory.
92  */
93 void rotate_logs(const std::string& log_dir)
94 {
95  // if logging to file is disabled, don't rotate the logs
96  if(output_file_path_.empty()) {
97  return;
98  }
99 
100  std::vector<std::string> files;
101  filesystem::get_files_in_dir(log_dir, &files);
102 
103  files.erase(std::remove_if(files.begin(), files.end(), is_not_log_file), files.end());
104 
105  if(files.size() <= lg::max_logs) {
106  return;
107  }
108 
109  // Sorting the file list and deleting all but the last max_logs items
110  // should hopefully be faster than stat'ing every single file for its
111  // time attributes (which aren't very reliable to begin with).
112 
113  std::sort(files.begin(), files.end());
114 
115  for(std::size_t j = 0; j < files.size() - lg::max_logs; ++j) {
116  const std::string path = log_dir + '/' + files[j];
117  LOG_LS << "rotate_logs(): delete " << path;
118  if(!filesystem::delete_file(path)) {
119  ERR_LS << "rotate_logs(): failed to delete " << path << "!";
120  }
121  }
122 }
123 
124 /**
125  * Generates a unique log file name.
126  */
127 std::string unique_log_filename()
128 {
129  std::ostringstream o;
130  const std::time_t cur = std::time(nullptr);
131  randomness::mt_rng rng;
132 
134  << std::put_time(std::localtime(&cur), "%Y%m%d-%H%M%S-")
135  << rng.get_next_random()
137 
138  return o.str();
139 }
140 
142 {
143  std::string dummy_log = filesystem::get_logs_dir()+"/dummy.log";
144 
145  // log directory doesn't exist and can't be created
147  is_log_dir_writable_ = false;
148  return;
149  }
150 
151  // can't create and write new log files
152  try {
153  filesystem::write_file(dummy_log, " ");
154  } catch(const filesystem::io_exception&) {
155  is_log_dir_writable_ = false;
156  return;
157  }
158 
159  // confirm that file exists and was written to
160  if(filesystem::file_size(dummy_log) != 1) {
161  is_log_dir_writable_ = false;
162  }
163 
164  // can't delete files - prevents log rotation
165  if(filesystem::file_exists(dummy_log) && !filesystem::delete_file(dummy_log)) {
166  is_log_dir_writable_ = false;
167  return;
168  }
169 
170  is_log_dir_writable_ = true;
171 }
172 
174 {
176  // get the log file stream and assign cerr+cout to it
178  output_file_path_ = filesystem::get_logs_dir()+"/"+unique_log_filename();
179  output_file_.reset(filesystem::ostream_file(output_file_path_).release());
180  std::cerr.rdbuf(output_file_.get()->rdbuf());
181  std::cout.rdbuf(output_file_.get()->rdbuf());
182  }
183 }
184 
186 {
187  return is_log_dir_writable_;
188 }
189 
190 std::string& get_log_file_path()
191 {
192  return output_file_path_;
193 }
194 void set_log_file_path(const std::string& path)
195 {
196  output_file_path_ = path;
197 }
198 
199 redirect_output_setter::redirect_output_setter(std::ostream& stream)
200  : old_stream_(output_stream_)
201 {
202  output_stream_ = &stream;
203 }
204 
206 {
208 }
209 
210 typedef std::map<std::string, int> domain_map;
211 static domain_map *domains;
212 static int strict_level_ = -1;
213 void timestamps(bool t) { timestamp = t; }
214 void precise_timestamps(bool pt) { precise_timestamp = pt; }
215 
217 {
218  static logger lg("error", 0);
219  return lg;
220 }
221 
223 {
224  static logger lg("warning", 1);
225  return lg;
226 }
227 
229 {
230  static logger lg("info", 2);
231  return lg;
232 }
233 
235 {
236  static logger lg("debug", 3);
237  return lg;
238 }
239 
240 static log_domain dom("general");
241 
243 {
244  return dom;
245 }
246 
247 log_domain::log_domain(char const *name, int severity)
248  : domain_(nullptr)
249 {
250  // Indirection to prevent initialization depending on link order.
251  if (!domains) domains = new domain_map;
252  domain_ = &*domains->insert(logd(name, severity)).first;
253  domain_->second = severity;
254 }
255 
256 bool set_log_domain_severity(const std::string& name, int severity)
257 {
258  std::string::size_type s = name.size();
259  if (name == "all") {
260  for(logd &l : *domains) {
261  l.second = severity;
262  }
263  } else if (s > 2 && name.compare(s - 2, 2, "/*") == 0) {
264  for(logd &l : *domains) {
265  if (l.first.compare(0, s - 1, name, 0, s - 1) == 0)
266  l.second = severity;
267  }
268  } else {
269  domain_map::iterator it = domains->find(name);
270  if (it == domains->end())
271  return false;
272  it->second = severity;
273  }
274  return true;
275 }
276 bool set_log_domain_severity(const std::string& name, const logger &lg) {
277  return set_log_domain_severity(name, lg.get_severity());
278 }
279 
280 bool get_log_domain_severity(const std::string& name, int &severity)
281 {
282  domain_map::iterator it = domains->find(name);
283  if (it == domains->end())
284  return false;
285  severity = it->second;
286  return true;
287 }
288 
289 std::string list_logdomains(const std::string& filter)
290 {
291  std::ostringstream res;
292  for(logd &l : *domains) {
293  if(l.first.find(filter) != std::string::npos)
294  res << l.first << "\n";
295  }
296  return res.str();
297 }
298 
300  strict_level_ = severity;
301 }
302 
305 }
306 
307 static bool strict_threw_ = false;
308 
309 bool broke_strict() {
310  return strict_threw_;
311 }
312 
313 std::string get_timestamp(const std::time_t& t, const std::string& format) {
314  std::ostringstream ss;
315 
316  ss << std::put_time(std::localtime(&t), format.c_str());
317 
318  return ss.str();
319 }
320 std::string get_timespan(const std::time_t& t) {
321  std::ostringstream sout;
322  // There doesn't seem to be any library function for this
323  const std::time_t minutes = t / 60;
324  const std::time_t days = minutes / 60 / 24;
325  if(t <= 0) {
326  sout << "expired";
327  } else if(minutes == 0) {
328  sout << t << " seconds";
329  } else if(days == 0) {
330  sout << minutes / 60 << " hours, " << minutes % 60 << " minutes";
331  } else {
332  sout << days << " days, " << (minutes / 60) % 24 << " hours, " << minutes % 60 << " minutes";
333  }
334  return sout.str();
335 }
336 
337 static void print_precise_timestamp(std::ostream& out) noexcept
338 {
339  try {
340  int64_t micros = std::chrono::duration_cast<std::chrono::microseconds>(std::chrono::high_resolution_clock::now().time_since_epoch()).count();
341  std::time_t seconds = micros/1'000'000;
342  int fractional = micros-(seconds*1'000'000);
343  char c = out.fill('0');
344  out << std::put_time(std::localtime(&seconds), "%Y%m%d %H:%M:%S") << "." << std::setw(6) << fractional << ' ';
345  out.fill(c);
346  } catch(...) {}
347 }
348 
349 std::string sanitize_log(const std::string& logstr)
350 {
351  std::string str = logstr;
352 
353 #ifdef _WIN32
354  const char* user_name = getenv("USERNAME");
355 #else
356  const char* user_name = getenv("USER");
357 #endif
358 
359  if(user_name != nullptr) {
360  boost::replace_all(str, std::string("/") + user_name + "/", "/USER/");
361  boost::replace_all(str, std::string("\\") + user_name + "\\", "\\USER\\");
362  }
363 
364  return str;
365 }
366 
368  const log_domain& domain,
369  bool show_names,
370  bool do_indent,
371  bool show_timestamps,
372  bool break_strict,
373  bool auto_newline) const
374 {
375  if (severity_ > domain.domain_->second) {
376  return null_ostream;
377  } else {
378  log_in_progress stream = output();
379  if(do_indent) {
380  stream.set_indent(indent);
381  }
382  if (timestamp && show_timestamps) {
383  stream.enable_timestamp();
384  }
385  if (show_names) {
386  stream.set_prefix(formatter() << name_ << ' ' << domain.domain_->first << ": ");
387  }
388  if (!strict_threw_ && severity_ <= strict_level_ && break_strict) {
389  stream | formatter() << "Error (strict mode, strict_level = " << strict_level_ << "): wesnoth reported on channel " << name_ << " " << domain.domain_->first << std::endl;
390  strict_threw_ = true;
391  }
392  stream.set_auto_newline(auto_newline);
393  return stream;
394  }
395 }
396 
397 log_in_progress::log_in_progress(std::ostream& stream)
398  : stream_(stream)
399 {}
400 
402 {
403  std::scoped_lock lock(log_mutex);
404  for(int i = 0; i < indent; ++i)
405  stream_ << " ";
406  if(timestamp_) {
407  if(precise_timestamp) {
409  } else {
410  stream_ << get_timestamp(std::time(nullptr));
411  }
412  }
413  stream_ << prefix_ << sanitize_log(message.str());
414  if(auto_newline_) {
415  stream_ << std::endl;
416  }
417 }
418 
420  indent_ = level;
421 }
422 
424  timestamp_ = true;
425 }
426 
427 void log_in_progress::set_prefix(const std::string& prefix) {
428  prefix_ = prefix;
429 }
430 
431 void log_in_progress::set_auto_newline(bool auto_newline) {
432  auto_newline_ = auto_newline;
433 }
434 
435 void scope_logger::do_log_entry(const std::string& str) noexcept
436 {
437  str_ = str;
438  try {
439  ticks_ = std::chrono::duration_cast<std::chrono::microseconds>(std::chrono::high_resolution_clock::now().time_since_epoch()).count();
440  } catch(...) {}
441  debug()(domain_, false, true) | formatter() << "{ BEGIN: " << str_;
442  ++indent;
443 }
444 
446 {
447  long ticks = 0;
448  try {
449  ticks = std::chrono::duration_cast<std::chrono::microseconds>(std::chrono::high_resolution_clock::now().time_since_epoch()).count() - ticks_;
450  } catch(...) {}
451  --indent;
452  auto output = debug()(domain_, false, true);
453  output.set_indent(indent);
454  if(timestamp) output.enable_timestamp();
455  output | formatter() << "} END: " << str_ << " (took " << ticks << "us)";
456 }
457 
458 std::stringstream& log_to_chat()
459 {
460  static std::stringstream lg;
461  return lg;
462 }
463 
464 } // end namespace lg
static log_domain dom("general")
static int strict_level_
Definition: log.cpp:212
std::string get_timestamp(const std::time_t &t, const std::string &format)
Definition: log.cpp:313
static std::mutex log_mutex
Definition: log.cpp:58
static domain_map * domains
Definition: log.cpp:211
std::string get_timespan(const std::time_t &t)
Definition: log.cpp:320
bool delete_file(const std::string &filename)
void do_log_exit() noexcept
Definition: log.cpp:445
logger & info()
Definition: log.cpp:228
static bool file_exists(const bfs::path &fpath)
Definition: filesystem.cpp:296
void timestamps(bool t)
Definition: log.cpp:213
static std::unique_ptr< std::ostream, void(*)(std::ostream *)> output_file_(nullptr, [](std::ostream *){ std::cerr.rdbuf(nullptr);std::cout.rdbuf(nullptr);})
Definition: log.cpp:75
uint32_t get_next_random()
Get a new random number.
Definition: mt_rng.cpp:63
std::string get_logs_dir()
Definition: filesystem.cpp:840
log_in_progress(std::ostream &stream)
Definition: log.cpp:397
static lg::log_domain log_setup("logsetup")
log_domain(char const *name, int severity=1)
Definition: log.cpp:247
const std::string log_file_suffix
Definition: log.hpp:67
filesystem::scoped_ostream ostream_file(const std::string &fname, std::ios_base::openmode mode, bool create_directory)
log_in_progress operator()(const log_domain &domain, bool show_names=true, bool do_indent=false, bool show_timestamps=true, bool break_strict=true, bool auto_newline=true) const
Definition: log.cpp:367
std::pair< const std::string, int > logd
Definition: log.hpp:110
bool is_not_log_file(const std::string &fn)
Helper function for rotate_logs.
Definition: log.cpp:84
bool broke_strict()
Definition: log.cpp:309
void set_auto_newline(bool enabled)
Definition: log.cpp:431
static bool is_log_dir_writable_
Definition: log.cpp:60
static std::ostream & output()
Definition: log.cpp:63
std::string & get_log_file_path()
Definition: log.cpp:190
bool get_log_domain_severity(const std::string &name, int &severity)
Definition: log.cpp:280
std::ostringstream wrapper.
Definition: formatter.hpp:39
#define ERR_LS
Definition: log.cpp:38
std::string sanitize_log(const std::string &logstr)
Definition: log.cpp:349
bool log_dir_writable()
Definition: log.cpp:185
void get_files_in_dir(const std::string &dir, std::vector< std::string > *files, std::vector< std::string > *dirs, name_mode mode, filter_mode filter, reorder_mode reorder, file_tree_checksum *checksum)
Get a list of all files and/or directories in a given directory.
Definition: filesystem.cpp:382
#define LOG_LS
Definition: log.cpp:40
void rotate_logs(const std::string &log_dir)
Deletes old log files from the log directory.
Definition: log.cpp:93
static bool precise_timestamp
Definition: log.cpp:57
std::string path
Definition: game_config.cpp:39
logger & debug()
Definition: log.cpp:234
severity
Definition: log.hpp:73
static int indent
Definition: log.cpp:55
log_domain & general()
Definition: log.cpp:242
void do_log_entry(const std::string &str) noexcept
Definition: log.cpp:435
std::string unique_log_filename()
Generates a unique log file name.
Definition: log.cpp:127
std::map< std::string, int > domain_map
Definition: log.cpp:210
void check_log_dir_writable()
Definition: log.cpp:141
Definition: pump.hpp:40
void write_file(const std::string &fname, const std::string &data, std::ios_base::openmode mode)
Throws io_exception if an error occurs.
std::ostream * old_stream_
The previously set redirection.
Definition: log.hpp:107
std::size_t i
Definition: function.cpp:968
logger & err()
Definition: log.cpp:216
static void print_precise_timestamp(std::ostream &out) noexcept
Definition: log.cpp:337
void set_strict_severity(int severity)
Definition: log.cpp:299
An exception object used when an IO error occurs.
Definition: filesystem.hpp:53
static map_location::DIRECTION s
const unsigned max_logs
Definition: log.hpp:71
bool make_directory(const std::string &dirname)
Definition: filesystem.cpp:985
static std::ostream * output_stream_
Definition: log.cpp:61
static std::string output_file_path_
Definition: log.cpp:79
Declarations for File-IO.
bool set_log_domain_severity(const std::string &name, int severity)
Definition: log.cpp:256
int file_size(const std::string &fname)
Returns the size of a file, or -1 if the file doesn&#39;t exist.
void operator|(formatter &&message)
Definition: log.cpp:401
static bool strict_threw_
Definition: log.cpp:307
logger & warn()
Definition: log.cpp:222
double t
Definition: astarsearch.cpp:65
void enable_timestamp()
Definition: log.cpp:423
static bool timestamp
Definition: log.cpp:56
std::string list_logdomains(const std::string &filter)
Definition: log.cpp:289
std::string prefix_
Definition: log.hpp:148
Standard logging facilities (interface).
static std::ostream null_ostream(new null_streambuf)
void set_prefix(const std::string &prefix)
Definition: log.cpp:427
void set_indent(int level)
Definition: log.cpp:419
bool auto_newline_
Definition: log.hpp:149
void set_log_to_file()
Definition: log.cpp:173
mock_char c
void set_log_file_path(const std::string &path)
Definition: log.cpp:194
int get_severity() const
Returns following values depending on the logger: error: 0 warn: 1 info: 2 debug: 3 See also the lg::...
Definition: log.hpp:180
std::ostream & stream_
Definition: log.hpp:145
std::string::const_iterator iterator
Definition: tokenizer.hpp:25
const std::string log_file_prefix
Definition: log.hpp:66
void precise_timestamps(bool pt)
Definition: log.cpp:214
logd * domain_
Definition: log.hpp:115
std::stringstream & log_to_chat()
Use this to show WML errors in the ingame chat.
Definition: log.cpp:458