Mercurial > hg > orthanc
comparison Core/Logging.cpp @ 1495:fbe40117eb21
improve the performance of the internal logger
author | Sebastien Jodogne <s.jodogne@gmail.com> |
---|---|
date | Thu, 06 Aug 2015 18:19:32 +0200 |
parents | a13581480b1f |
children | 46b2794042d6 |
comparison
equal
deleted
inserted
replaced
1494:a13581480b1f | 1495:fbe40117eb21 |
---|---|
92 /********************************************************* | 92 /********************************************************* |
93 * Use internal logger, not Google Log | 93 * Use internal logger, not Google Log |
94 *********************************************************/ | 94 *********************************************************/ |
95 | 95 |
96 #include "OrthancException.h" | 96 #include "OrthancException.h" |
97 #include "Enumerations.h" | |
97 #include "Toolbox.h" | 98 #include "Toolbox.h" |
98 | 99 |
99 #include <fstream> | 100 #include <fstream> |
100 #include <boost/filesystem.hpp> | 101 #include <boost/filesystem.hpp> |
101 #include <boost/thread.hpp> | 102 #include <boost/thread.hpp> |
107 #endif | 108 #endif |
108 | 109 |
109 | 110 |
110 namespace | 111 namespace |
111 { | 112 { |
112 struct NullStream : public std::ostream | 113 struct LoggingState |
113 { | 114 { |
114 NullStream() : std::ios(0), std::ostream(0) | 115 bool infoEnabled_; |
116 bool traceEnabled_; | |
117 | |
118 std::ostream* error_; | |
119 std::ostream* warning_; | |
120 std::ostream* info_; | |
121 | |
122 std::auto_ptr<std::ofstream> errorFile_; | |
123 std::auto_ptr<std::ofstream> warningFile_; | |
124 std::auto_ptr<std::ofstream> infoFile_; | |
125 | |
126 LoggingState() : | |
127 infoEnabled_(false), | |
128 traceEnabled_(false), | |
129 error_(&std::cerr), | |
130 warning_(&std::cerr), | |
131 info_(&std::cerr) | |
115 { | 132 { |
116 } | 133 } |
117 }; | 134 }; |
118 } | 135 } |
119 | 136 |
120 | 137 |
121 static boost::mutex mutex_; | 138 |
122 static bool infoEnabled_ = false; | 139 static std::auto_ptr<LoggingState> loggingState_; |
123 static bool traceEnabled_ = false; | 140 static boost::mutex loggingMutex_; |
124 | 141 |
125 static std::ostream* error_ = &std::cerr; | 142 |
126 static std::ostream* warning_ = &std::cerr; | |
127 static std::ostream* info_ = &std::cerr; | |
128 static NullStream null_; | |
129 | |
130 static std::auto_ptr<std::ofstream> errorFile_; | |
131 static std::auto_ptr<std::ofstream> warningFile_; | |
132 static std::auto_ptr<std::ofstream> infoFile_; | |
133 | 143 |
134 namespace Orthanc | 144 namespace Orthanc |
135 { | 145 { |
136 namespace Logging | 146 namespace Logging |
137 { | 147 { |
199 } | 209 } |
200 | 210 |
201 | 211 |
202 void Initialize() | 212 void Initialize() |
203 { | 213 { |
204 infoEnabled_ = false; | 214 boost::mutex::scoped_lock lock(loggingMutex_); |
205 traceEnabled_ = false; | 215 loggingState_.reset(new LoggingState); |
206 } | 216 } |
207 | 217 |
208 void Finalize() | 218 void Finalize() |
209 { | 219 { |
210 errorFile_.reset(NULL); | 220 boost::mutex::scoped_lock lock(loggingMutex_); |
211 warningFile_.reset(NULL); | 221 loggingState_.reset(NULL); |
212 infoFile_.reset(NULL); | |
213 } | 222 } |
214 | 223 |
215 void EnableInfoLevel(bool enabled) | 224 void EnableInfoLevel(bool enabled) |
216 { | 225 { |
217 boost::mutex::scoped_lock lock(mutex_); | 226 boost::mutex::scoped_lock lock(loggingMutex_); |
218 infoEnabled_ = enabled; | 227 assert(loggingState_.get() != NULL); |
228 | |
229 loggingState_->infoEnabled_ = enabled; | |
219 } | 230 } |
220 | 231 |
221 void EnableTraceLevel(bool enabled) | 232 void EnableTraceLevel(bool enabled) |
222 { | 233 { |
223 boost::mutex::scoped_lock lock(mutex_); | 234 boost::mutex::scoped_lock lock(loggingMutex_); |
224 traceEnabled_ = enabled; | 235 assert(loggingState_.get() != NULL); |
236 | |
237 loggingState_->traceEnabled_ = enabled; | |
225 | 238 |
226 if (enabled) | 239 if (enabled) |
227 { | 240 { |
228 // Also enable the "INFO" level when trace-level debugging is enabled | 241 // Also enable the "INFO" level when trace-level debugging is enabled |
229 infoEnabled_ = true; | 242 loggingState_->infoEnabled_ = true; |
230 } | 243 } |
231 } | 244 } |
232 | 245 |
233 void SetTargetFolder(const std::string& path) | 246 void SetTargetFolder(const std::string& path) |
234 { | 247 { |
235 boost::mutex::scoped_lock lock(mutex_); | 248 boost::mutex::scoped_lock lock(loggingMutex_); |
236 PrepareLogFile(error_, errorFile_, "ERROR", path); | 249 assert(loggingState_.get() != NULL); |
237 PrepareLogFile(warning_, warningFile_, "WARNING", path); | 250 |
238 PrepareLogFile(info_, infoFile_, "INFO", path); | 251 PrepareLogFile(loggingState_->error_, loggingState_->errorFile_, "ERROR", path); |
252 PrepareLogFile(loggingState_->warning_, loggingState_->warningFile_, "WARNING", path); | |
253 PrepareLogFile(loggingState_->info_, loggingState_->infoFile_, "INFO", path); | |
239 } | 254 } |
240 | 255 |
241 InternalLogger::InternalLogger(const char* level, | 256 InternalLogger::InternalLogger(const char* level, |
242 const char* file, | 257 const char* file, |
243 int line) : | 258 int line) : |
244 lock_(mutex_) | 259 lock_(loggingMutex_), |
245 { | 260 stream_(&null_) // By default, logging to "/dev/null" is simulated |
246 char c; | 261 { |
247 | 262 if (loggingState_.get() == NULL) |
248 if (strcmp(level, "ERROR") == 0) | 263 { |
249 { | 264 fprintf(stderr, "ERROR: Trying to log a message after the finalization of the logging engine\n"); |
250 stream_ = error_; | 265 return; |
251 c = 'E'; | 266 } |
252 } | 267 |
253 else if (strcmp(level, "WARNING") == 0) | 268 LogLevel l = StringToLogLevel(level); |
254 { | 269 |
255 stream_ = warning_; | 270 if ((l == LogLevel_Info && !loggingState_->infoEnabled_) || |
256 c = 'W'; | 271 (l == LogLevel_Trace && !loggingState_->traceEnabled_)) |
257 } | 272 { |
258 else if (strcmp(level, "INFO") == 0) | 273 // This logging level is disabled, directly exit and unlock |
259 { | 274 // the mutex to speed-up things. The stream is set to "/dev/null" |
260 stream_ = infoEnabled_ ? info_ : &null_; | 275 lock_.unlock(); |
261 c = 'I'; | 276 return; |
262 } | 277 } |
263 else if (strcmp(level, "TRACE") == 0) | 278 |
264 { | 279 // Compute the header of the line, temporary release the lock as |
265 stream_ = traceEnabled_ ? info_ : &null_; | 280 // this is a time-consuming operation |
266 c = 'T'; | 281 lock_.unlock(); |
267 } | 282 std::string header; |
268 else | 283 |
269 { | |
270 // Unknown logging level | |
271 throw OrthancException(ErrorCode_InternalError); | |
272 } | |
273 | |
274 if (stream_ != &null_) | |
275 { | 284 { |
276 boost::filesystem::path path(file); | 285 boost::filesystem::path path(file); |
277 boost::posix_time::ptime now = boost::posix_time::microsec_clock::local_time(); | 286 boost::posix_time::ptime now = boost::posix_time::microsec_clock::local_time(); |
278 boost::posix_time::time_duration duration = now.time_of_day(); | 287 boost::posix_time::time_duration duration = now.time_of_day(); |
279 | 288 |
297 | 306 |
298 In this implementation, "threadid" is not printed. | 307 In this implementation, "threadid" is not printed. |
299 **/ | 308 **/ |
300 | 309 |
301 char date[32]; | 310 char date[32]; |
302 sprintf(date, "%c%02d%02d %02d:%02d:%02d.%06d ", c, | 311 sprintf(date, "%c%02d%02d %02d:%02d:%02d.%06d ", |
312 level[0], | |
303 now.date().month().as_number(), | 313 now.date().month().as_number(), |
304 now.date().day().as_number(), | 314 now.date().day().as_number(), |
305 duration.hours(), | 315 duration.hours(), |
306 duration.minutes(), | 316 duration.minutes(), |
307 duration.seconds(), | 317 duration.seconds(), |
308 static_cast<int>(duration.fractional_seconds())); | 318 static_cast<int>(duration.fractional_seconds())); |
309 | 319 |
310 *stream_ << date << path.filename().string() << ":" << line << "] "; | 320 header = std::string(date) + path.filename().string() + ":" + boost::lexical_cast<std::string>(line) + "] "; |
311 } | 321 } |
322 | |
323 | |
324 // The header is computed, we now re-lock the mutex to access | |
325 // the stream objects. Pay attention that "loggingState_", | |
326 // "infoEnabled_" or "traceEnabled_" might have changed while | |
327 // the mutex was unlocked. | |
328 lock_.lock(); | |
329 | |
330 if (loggingState_.get() == NULL) | |
331 { | |
332 fprintf(stderr, "ERROR: Trying to log a message after the finalization of the logging engine\n"); | |
333 return; | |
334 } | |
335 | |
336 switch (l) | |
337 { | |
338 case LogLevel_Error: | |
339 stream_ = loggingState_->error_; | |
340 break; | |
341 | |
342 case LogLevel_Warning: | |
343 stream_ = loggingState_->warning_; | |
344 break; | |
345 | |
346 case LogLevel_Info: | |
347 if (loggingState_->infoEnabled_) | |
348 { | |
349 stream_ = loggingState_->info_; | |
350 } | |
351 | |
352 break; | |
353 | |
354 case LogLevel_Trace: | |
355 if (loggingState_->traceEnabled_) | |
356 { | |
357 stream_ = loggingState_->info_; | |
358 } | |
359 | |
360 break; | |
361 | |
362 default: | |
363 throw OrthancException(ErrorCode_InternalError); | |
364 } | |
365 | |
366 if (stream_ == &null_) | |
367 { | |
368 // The logging is disabled for this level. The stream is the | |
369 // "null_" member of this object, so we can release the global | |
370 // mutex. | |
371 lock_.unlock(); | |
372 } | |
373 | |
374 (*stream_) << header; | |
312 } | 375 } |
313 } | 376 } |
314 } | 377 } |
315 | 378 |
316 #endif | 379 #endif |