1 // Copyright 2011 Google Inc.
2 // All rights reserved.
3 //
4 // Redistribution and use in source and binary forms, with or without
5 // modification, are permitted provided that the following conditions are
6 // met:
7 //
8 // * Redistributions of source code must retain the above copyright
9 // notice, this list of conditions and the following disclaimer.
10 // * Redistributions in binary form must reproduce the above copyright
11 // notice, this list of conditions and the following disclaimer in the
12 // documentation and/or other materials provided with the distribution.
13 // * Neither the name of Google Inc. nor the names of its contributors
14 // may be used to endorse or promote products derived from this software
15 // without specific prior written permission.
16 //
17 // THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS
18 // "AS IS" AND ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT
19 // LIMITED TO, THE IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR
20 // A PARTICULAR PURPOSE ARE DISCLAIMED. IN NO EVENT SHALL THE COPYRIGHT
21 // OWNER OR CONTRIBUTORS BE LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL,
22 // SPECIAL, EXEMPLARY, OR CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT
23 // LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES; LOSS OF USE,
24 // DATA, OR PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED AND ON ANY
25 // THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY, OR TORT
26 // (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE
27 // OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE.
28
29 #include "utils/logging/operations.hpp"
30
31 extern "C" {
32 #include <unistd.h>
33 }
34
35 #include <fstream>
36 #include <stdexcept>
37 #include <string>
38 #include <utility>
39 #include <vector>
40
41 #include "utils/datetime.hpp"
42 #include "utils/format/macros.hpp"
43 #include "utils/optional.ipp"
44 #include "utils/sanity.hpp"
45
46 namespace datetime = utils::datetime;
47 namespace fs = utils::fs;
48 namespace logging = utils::logging;
49
50 using utils::none;
51 using utils::optional;
52
53
54 /// The general idea for the application-wide logging goes like this:
55 ///
56 /// 1. The application starts. Logging is initialized to capture _all_ log
57 /// messages into memory regardless of their level by issuing a call to the
58 /// set_inmemory() function.
59 ///
60 /// 2. The application offers the user a way to select the logging level and a
61 /// file into which to store the log.
62 ///
63 /// 3. The application calls set_persistency providing a new log level and a log
64 /// file. This must be done as early as possible, to minimize the chances of an
65 /// early crash not capturing any logs.
66 ///
67 /// 4. At this point, any log messages stored into memory are flushed to disk
68 /// respecting the provided log level.
69 ///
70 /// 5. The internal state of the logging module is updated to only capture
71 /// messages that are of the provided log level (or below) and is configured to
72 /// directly send messages to disk.
73 ///
74 /// The call to set_inmemory() should only be performed by the user-facing
75 /// application. Tests should skip this call so that the logging messages go to
76 /// stderr by default, thus generating a useful log to debug the tests.
77
78
79 namespace {
80
81
82 /// Current log level.
83 static logging::level log_level = logging::level_debug;
84
85
86 /// Indicates whether set_persistency() will be called automatically or not.
87 static bool auto_set_persistency = true;
88
89
90 /// First time recorded by the logging module.
91 static optional< datetime::timestamp > first_timestamp = none;
92
93
94 /// In-memory record of log entries before persistency is enabled.
95 static std::vector< std::pair< logging::level, std::string > > backlog;
96
97
98 /// Stream to the currently open log file.
99 static std::unique_ptr< std::ofstream > logfile;
100
101
102 /// Constant string to strftime to format timestamps.
103 static const char* timestamp_format = "%Y%m%d-%H%M%S";
104
105
106 /// Converts a level to a printable character.
107 ///
108 /// \param level The level to convert.
109 ///
110 /// \return The printable character, to be used in log messages.
111 static char
level_to_char(const logging::level level)112 level_to_char(const logging::level level)
113 {
114 switch (level) {
115 case logging::level_error: return 'E';
116 case logging::level_warning: return 'W';
117 case logging::level_info: return 'I';
118 case logging::level_debug: return 'D';
119 default: UNREACHABLE;
120 }
121 }
122
123
124 } // anonymous namespace
125
126
127 /// Generates a standard log name.
128 ///
129 /// This always adds the same timestamp to the log name for a particular run.
130 /// Also, the timestamp added to the file name corresponds to the first
131 /// timestamp recorded by the module; it does not necessarily contain the
132 /// current value of "now".
133 ///
134 /// \param logdir The path to the directory in which to place the log.
135 /// \param progname The name of the program that is generating the log.
136 fs::path
generate_log_name(const fs::path & logdir,const std::string & progname)137 logging::generate_log_name(const fs::path& logdir, const std::string& progname)
138 {
139 if (!first_timestamp)
140 first_timestamp = datetime::timestamp::now();
141 // Update doc/troubleshooting.texi if you change the name format.
142 return logdir / (F("%s.%s.log") % progname %
143 first_timestamp.get().strftime(timestamp_format));
144 }
145
146
147 /// Logs an entry to the log file.
148 ///
149 /// If the log is not yet set to persistent mode, the entry is recorded in the
150 /// in-memory backlog. Otherwise, it is just written to disk.
151 ///
152 /// \param message_level The level of the entry.
153 /// \param file The file from which the log message is generated.
154 /// \param line The line from which the log message is generated.
155 /// \param user_message The raw message to store.
156 void
log(const level message_level,const char * file,const int line,const std::string & user_message)157 logging::log(const level message_level, const char* file, const int line,
158 const std::string& user_message)
159 {
160 const datetime::timestamp now = datetime::timestamp::now();
161 if (!first_timestamp)
162 first_timestamp = now;
163
164 if (auto_set_persistency) {
165 // These values are hardcoded here for testing purposes. The
166 // application should call set_inmemory() by itself during
167 // initialization to avoid this, so that it has explicit control on how
168 // the call to set_persistency() happens.
169 set_persistency("debug", fs::path("/dev/stderr"));
170 auto_set_persistency = false;
171 }
172
173 if (message_level > log_level)
174 return;
175
176 // Update doc/troubleshooting.texi if you change the log format.
177 const std::string message = F("%s %s %s %s:%s: %s") %
178 now.strftime(timestamp_format) % level_to_char(message_level) %
179 ::getpid() % file % line % user_message;
180 if (logfile.get() == NULL)
181 backlog.push_back(std::make_pair(message_level, message));
182 else {
183 INV(backlog.empty());
184 (*logfile) << message << '\n';
185 (*logfile).flush();
186 }
187 }
188
189
190 /// Sets the logging to record messages in memory for later flushing.
191 void
set_inmemory(void)192 logging::set_inmemory(void)
193 {
194 auto_set_persistency = false;
195 }
196
197
198 /// Makes the log persistent.
199 ///
200 /// Calling this function flushes the in-memory log, if any, to disk and sets
201 /// the logging module to send log entries to disk from this point onwards.
202 /// There is no way back, and the caller program should execute this function as
203 /// early as possible to ensure that a crash at startup does not discard too
204 /// many useful log entries.
205 ///
206 /// Any log entries above the provided new_level are discarded.
207 ///
208 /// \param new_level The new log level.
209 /// \param path The file to write the logs to.
210 ///
211 /// \throw std::range_error If the given log level is invalid.
212 /// \throw std::runtime_error If the given file cannot be created.
213 void
set_persistency(const std::string & new_level,const fs::path & path)214 logging::set_persistency(const std::string& new_level, const fs::path& path)
215 {
216 auto_set_persistency = false;
217
218 PRE(logfile.get() == NULL);
219
220 // Update doc/troubleshooting.info if you change the log levels.
221 if (new_level == "debug")
222 log_level = level_debug;
223 else if (new_level == "error")
224 log_level = level_error;
225 else if (new_level == "info")
226 log_level = level_info;
227 else if (new_level == "warning")
228 log_level = level_warning;
229 else
230 throw std::range_error(F("Unrecognized log level '%s'") % new_level);
231
232 logfile.reset(new std::ofstream(path.c_str()));
233 if (!(*logfile))
234 throw std::runtime_error(F("Failed to create log file %s") % path);
235
236 for (std::vector< std::pair< logging::level, std::string > >::const_iterator
237 iter = backlog.begin(); iter != backlog.end(); iter++) {
238 if ((*iter).first <= log_level)
239 (*logfile) << (*iter).second << '\n';
240 }
241 (*logfile).flush();
242 backlog.clear();
243 }
244