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