Line data Source code
1 : /** \file logManager.hpp
2 : * \brief The MagAO-X log manager.
3 : * \author Jared R. Males (jaredmales@gmail.com)
4 : *
5 : * \ingroup logger_files
6 : *
7 : * History:
8 : * - 2017-06-27 created by JRM
9 : */
10 :
11 : #ifndef logger_logManager_hpp
12 : #define logger_logManager_hpp
13 :
14 : #include <memory>
15 : #include <list>
16 :
17 : #include <thread>
18 :
19 : #include <mutex>
20 : #include <ratio>
21 :
22 : #include <mx/app/appConfigurator.hpp>
23 :
24 : #include <flatlogs/flatlogs.hpp>
25 :
26 : using namespace flatlogs;
27 :
28 : #include "../common/defaults.hpp"
29 :
30 : #include "generated/logTypes.hpp"
31 : #include "generated/logStdFormat.hpp"
32 :
33 : namespace MagAOX
34 : {
35 : namespace logger
36 : {
37 :
38 : /// The standard MagAOX log manager, used for both process logs and telemetry streams.
39 : /** Manages the formatting and queueing of the log entries.
40 : *
41 : * A log entry is made using one of the standard log types. These are formatted into a binary stream and
42 : * stored in a std::list. This occurs in the calling thread. The insertion into the list is mutex-ed, so
43 : * it is safe to make logs from different threads concurrently.
44 : *
45 : * Write-to-disk occurs in a separate thread, which
46 : * is normally set to the lowest priority so as not to interfere with higher-priority tasks. The
47 : * log thread cycles through pending log entries in the list, dispatching them to the logFile.
48 : *
49 : * The template parameter logFileT is one of the logFile types, which is used to actually write to disk.
50 : *
51 : * Example:
52 : \code
53 : logManager<logFileRaw> log;
54 : log.m_logThreadStart();
55 :
56 : //do stuff
57 :
58 : log<loop_closed>(); //An empty log, which is used to log discrete events.
59 :
60 : //more stuff happens
61 :
62 : log<text_log>("a log entry with a std::string message type");
63 :
64 : \endcode
65 : *
66 : * \todo document all the requirements of logFileT
67 : *
68 : * \tparam logFileT a logFile type with a writeLog method.
69 : *
70 : * \ingroup logger
71 : */
72 : template<class _parentT, class _logFileT>
73 : struct logManager : public _logFileT
74 : {
75 : typedef _parentT parentT;
76 : typedef _logFileT logFileT;
77 :
78 : protected:
79 : parentT * m_parent {nullptr};
80 :
81 : ///\todo Make these protected members, with appropriate access methods
82 : //-->
83 : public:
84 : std::string m_configSection {"logger"}; ///<The configuration files section name. Default is `logger`.
85 :
86 : protected:
87 : std::list<bufferPtrT> m_logQueue; ///< Log entries are stored here, and writen to the file by the log thread.
88 :
89 : std::thread m_logThread; ///< A separate thread for actually writing to the file.
90 : std::mutex m_qMutex; ///< Mutex for accessing the m_logQueue.
91 :
92 : bool m_logShutdown {false}; ///< Flag to signal the log thread to shutdown.
93 :
94 : unsigned long m_writePause {MAGAOX_default_writePause}; ///< Time, in nanoseconds, to pause between successive batch writes to the file. Default is 1e9. Configure with logger.writePause.
95 :
96 : public:
97 : logPrioT m_logLevel {logPrio::LOG_INFO}; ///< The minimum log level to actually record. Logs with level below this are rejected. Default is INFO. Configure with logger.logLevel.
98 :
99 : protected:
100 : int m_logThreadPrio {0};
101 :
102 : bool m_logThreadRunning {false};
103 : //<--end of todo
104 :
105 : public:
106 : /// Default c'tor.
107 : logManager();
108 :
109 : /// Destructor.
110 : ~logManager();
111 :
112 : /// Set the logger parent
113 : /** The parent is used for interactive presentation of log messages
114 : */
115 : void parent( parentT * p /**< [in] pointer to the parent object*/);
116 :
117 : /// Get the logger parent
118 : /**
119 : * Returns a point to the parent object.
120 : */
121 : parentT * parent();
122 :
123 : /// Set a new value of logShutdown
124 : /** Updates m_logShutdown with new value.
125 : *
126 : * \returns 0 on success
127 : * \returns -1 on error (if wp == 0).
128 : */
129 : int logShutdown( bool ls );
130 :
131 : /// Get the current value of logShutdown
132 : /** \returns the value m_logShutdown.
133 : */
134 : bool logShutdown();
135 :
136 : /// Set a new value of writePause
137 : /** Updates m_writePause with new value.
138 : *
139 : * \returns 0 on success
140 : * \returns -1 on error (if wp == 0).
141 : */
142 : int writePause( const unsigned long & wp /**< [in] the new value of writePause */);
143 :
144 : /// Get the current value of writePause
145 : /** \returns the value m_writePause.
146 : */
147 : unsigned long writePause();
148 :
149 : /// Set a new value of logLevel
150 : /** Updates m_logLevel with new value.
151 : * Will return an error and take no actions if the argument
152 : * is outside the range of the logLevels enum.
153 : *
154 : * \returns 0 on success
155 : * \returns -1 on error.
156 : */
157 : int logLevel( logPrioT newLev /**< [in] the new value of logLevel */);
158 :
159 : /// Get the current value of logLevel
160 : /** \returns the value m_logLevel
161 : */
162 : logPrioT logLevel();
163 :
164 : /// Set a new value of logThreadPrio
165 : /** Updates m_logThreadPrio with new value.
166 : * If the argument is < 0, this sets m_logThreadPrio to 0.
167 : * Will not set > 98, and returns -1 with no changes in this case.
168 : *
169 : * \returns 0 on success
170 : * \returns -1 on error (> 98).
171 : */
172 : int logThreadPrio( int newPrio /**< [in] the new value of logThreadPrio */);
173 :
174 : /// Get the current value of logThreadPrio
175 : /** \returns the value m_logThreadPrio
176 : */
177 : int logThreadPrio();
178 :
179 : /// Get status of the log thread running flag
180 : /** \returns the current value of m_logThreadRunning
181 : */
182 : bool logThreadRunning();
183 :
184 : ///Setup an application configurator for the logger section
185 : int setupConfig( mx::app::appConfigurator & config /**< [in] an application configuration to setup */);
186 :
187 : ///Load the logger section from an application configurator
188 : /**
189 : */
190 : int loadConfig( mx::app::appConfigurator & config /**< [in] an application configuration from which to load values */);
191 :
192 :
193 : ///Thread starter, called by logThreadStart on thread construction. Calls logThreadExec.
194 : static void _logThreadStart( logManager * l /**< [in] a pointer to a logger instance (normally this) */);
195 :
196 : /// Start the logger thread.
197 : int logThreadStart();
198 :
199 : /// Execute the logger thread.
200 : void logThreadExec();
201 :
202 : /// Create a log formatted log entry, filling in a buffer.
203 : /** This is where the timestamp of the log entry is set.
204 : *
205 : * \tparam logT is a log entry type
206 : *
207 : * \returns 0 on success, -1 on error.
208 : */
209 : template<typename logT>
210 : static int createLog( bufferPtrT & logBuffer, ///< [out] a shared_ptr\<logBuffer\>, which will be allocated and populated with the log entry
211 : const typename logT::messageT & msg, ///< [in] the message to log (could be of type emptyMessage)
212 : const logPrioT & level ///< [in] the level (verbosity) of this log
213 : );
214 :
215 : /// Create a log formatted log entry, filling in a buffer.
216 : /** This version has the timestamp provided.
217 : *
218 : * \tparam logT is a log entry type
219 : *
220 : * \returns 0 on success, -1 on error.
221 : */
222 : template<typename logT>
223 : static int createLog( bufferPtrT & logBuffer, ///< [out] a shared_ptr\<logBuffer\>, which will be allocated and populated with the log entry
224 : const timespecX & ts, ///< [in] the timestamp of this log entry.
225 : const typename logT::messageT & msg, ///< [in] the message to log (could be of type emptyMessage)
226 : const logPrioT & level ///< [in] the level (verbosity) of this log
227 : );
228 :
229 : /// Make a log entry, including a message.
230 : /**
231 : * \tparam logT is a log entry type
232 : */
233 : template<typename logT>
234 : void log( const typename logT::messageT & msg, ///< [in] the message to log
235 : logPrioT level = logPrio::LOG_DEFAULT ///< [in] [optional] the log level. The default is used if not specified.
236 : );
237 :
238 : /// Make a log entry, including a message.
239 : /**
240 : * \tparam logT is a log entry type
241 : */
242 : template<typename logT>
243 : void log( timespecX & ts, ///< [in] the timestamp of the log entry
244 : const typename logT::messageT & msg, ///< [in] the message to log
245 : logPrioT level = logPrio::LOG_DEFAULT ///< [in] [optional] the log level. The default is used if not specified.
246 : );
247 :
248 : /// Make a log entry with no message.
249 : /**
250 : * \tparam logT is a log entry type
251 : */
252 : template<typename logT>
253 : void log( logPrioT level = logPrio::LOG_DEFAULT /**< [in] [optional] the log level. The default is used if not specified.*/);
254 :
255 : /// Make a log entry with no message.
256 : /**
257 : * \tparam logT is a log entry type
258 : */
259 : template<typename logT>
260 : void log( timespecX & ts, ///< [in] the timestamp of the log entry
261 : logPrioT level = logPrio::LOG_DEFAULT ///< [in] [optional] the log level. The default is used if not specified.
262 : );
263 :
264 : };
265 :
266 : template<class parentT, class logFileT>
267 1194 : logManager<parentT, logFileT>::logManager()
268 : {
269 398 : }
270 :
271 : template<class parentT, class logFileT>
272 398 : logManager<parentT, logFileT>::~logManager()
273 : {
274 398 : m_logShutdown = true;
275 :
276 398 : if(m_logThread.joinable()) m_logThread.join();
277 :
278 : //One last check to see if there are any unwritten logs.
279 398 : if( !m_logQueue.empty() ) logThreadExec();
280 :
281 398 : }
282 :
283 : template<class parentT, class logFileT>
284 890 : void logManager<parentT, logFileT>::parent( parentT * p )
285 : {
286 890 : m_parent = p;
287 890 : }
288 :
289 : template<class parentT, class logFileT>
290 : parentT * logManager<parentT, logFileT>::parent()
291 : {
292 : return m_parent;
293 : }
294 :
295 : template<class parentT, class logFileT>
296 3 : int logManager<parentT, logFileT>::logShutdown( bool ls )
297 : {
298 3 : m_logShutdown = ls;
299 3 : return 0;
300 : }
301 :
302 : template<class parentT, class logFileT>
303 : bool logManager<parentT, logFileT>::logShutdown()
304 : {
305 : return m_logShutdown;
306 : }
307 :
308 : template<class parentT, class logFileT>
309 : int logManager<parentT, logFileT>::writePause( const unsigned long & wp )
310 : {
311 : if(wp == 0) return -1;
312 :
313 : m_writePause = wp;
314 :
315 : return 0;
316 : }
317 :
318 : template<class parentT, class logFileT>
319 : unsigned long logManager<parentT, logFileT>::writePause()
320 : {
321 : return m_writePause;
322 : }
323 :
324 : template<class parentT, class logFileT>
325 0 : int logManager<parentT, logFileT>::logLevel( logPrioT newLev )
326 : {
327 :
328 :
329 0 : m_logLevel = newLev;
330 :
331 0 : return 0;
332 : }
333 :
334 : template<class parentT, class logFileT>
335 0 : logPrioT logManager<parentT, logFileT>::logLevel()
336 : {
337 0 : return m_logLevel;
338 : }
339 :
340 : template<class parentT, class logFileT>
341 : int logManager<parentT, logFileT>::logThreadPrio( int newPrio )
342 : {
343 : if(newPrio > 98) return -1; //clamped at 98 for safety.
344 : if(newPrio < 0) newPrio = 0;
345 :
346 : m_logThreadPrio = newPrio;
347 : return 0;
348 : }
349 :
350 : template<class parentT, class logFileT>
351 : int logManager<parentT, logFileT>::logThreadPrio()
352 : {
353 : return m_logThreadPrio;
354 : }
355 :
356 : template<class parentT, class logFileT>
357 76 : bool logManager<parentT, logFileT>::logThreadRunning()
358 : {
359 76 : return m_logThreadRunning;
360 : }
361 :
362 : template<class parentT, class logFileT>
363 24 : int logManager<parentT, logFileT>::setupConfig( mx::app::appConfigurator & config )
364 : {
365 240 : config.add(m_configSection+".logDir","L", "logDir",mx::app::argType::Required, m_configSection, "logDir", false, "string", "The directory for log files");
366 240 : config.add(m_configSection+".logExt","", "logExt",mx::app::argType::Required, m_configSection, "logExt", false, "string", "The extension for log files");
367 240 : config.add(m_configSection+".maxLogSize","", "maxLogSize",mx::app::argType::Required, m_configSection, "maxLogSize", false, "string", "The maximum size of log files");
368 240 : config.add(m_configSection+".writePause","", "writePause",mx::app::argType::Required, m_configSection, "writePause", false, "unsigned long", "The log thread pause time in ns");
369 240 : config.add(m_configSection+".logThreadPrio", "", "logThreadPrio", mx::app::argType::Required, m_configSection, "logThreadPrio", false, "int", "The log thread priority");
370 216 : config.add(m_configSection+".logLevel","l", "logLevel",mx::app::argType::Required, m_configSection, "logLevel", false, "string", "The log level");
371 :
372 24 : return 0;
373 : }
374 :
375 : template<class parentT, class logFileT>
376 23 : int logManager<parentT, logFileT>::loadConfig( mx::app::appConfigurator & config )
377 : {
378 : //-- logDir
379 23 : std::string tmp;
380 23 : config(tmp, m_configSection+".logDir");
381 23 : if(tmp != "") this->logPath(tmp);
382 :
383 : //-- logLevel
384 23 : tmp = "";
385 23 : config(tmp, m_configSection+".logLevel");
386 23 : if(tmp != "")
387 : {
388 : logPrioT lev;
389 :
390 0 : lev = logLevelFromString(tmp);
391 :
392 0 : if( lev == logPrio::LOG_DEFAULT ) lev = logPrio::LOG_INFO;
393 0 : if( lev == logPrio::LOG_UNKNOWN )
394 : {
395 0 : std::cerr << "Unkown log level specified. Using default (INFO)\n";
396 0 : lev = logPrio::LOG_INFO;
397 : }
398 0 : logLevel(lev);
399 : }
400 :
401 :
402 : //logExt
403 23 : config(this->m_logExt, m_configSection+".logExt");
404 :
405 : //maxLogSize
406 23 : config(this->m_maxLogSize, m_configSection+".maxLogSize");
407 :
408 : //writePause
409 23 : config(m_writePause, m_configSection+".writePause");
410 :
411 : //logThreadPrio
412 23 : config(m_logThreadPrio, m_configSection+".logThreadPrio");
413 :
414 23 : return 0;
415 23 : }
416 :
417 : template<class parentT, class logFileT>
418 9 : void logManager<parentT, logFileT>::_logThreadStart( logManager * l)
419 : {
420 9 : l->logThreadExec();
421 9 : }
422 :
423 : template<class parentT, class logFileT>
424 9 : int logManager<parentT, logFileT>::logThreadStart()
425 : {
426 : try
427 : {
428 9 : m_logThread = std::thread( _logThreadStart, this);
429 : }
430 0 : catch( const std::exception & e )
431 : {
432 0 : log<software_error>({__FILE__,__LINE__, 0, 0, std::string("Exception on log thread start: ") + e.what()});
433 0 : return -1;
434 : }
435 0 : catch( ... )
436 : {
437 0 : log<software_error>({__FILE__,__LINE__, 0, 0, "Unkown exception on log thread start"});
438 0 : return -1;
439 : }
440 :
441 9 : if(!m_logThread.joinable())
442 : {
443 0 : log<software_error>({__FILE__, __LINE__, 0, 0, "Log thread did not start"});
444 0 : return -1;
445 : }
446 :
447 : //Always set the m_logThread to lowest priority
448 : sched_param sp;
449 9 : sp.sched_priority = m_logThreadPrio;
450 :
451 9 : int rv = pthread_setschedparam( m_logThread.native_handle(), SCHED_OTHER, &sp);
452 :
453 9 : if(rv != 0)
454 : {
455 0 : log<software_error>({__FILE__, __LINE__, 0, rv, std::string("Error setting thread params: ") + strerror(rv)});
456 0 : return -1;
457 : }
458 :
459 9 : return 0;
460 :
461 : }
462 :
463 : template<class parentT, class logFileT>
464 36 : void logManager<parentT, logFileT>::logThreadExec()
465 : {
466 :
467 36 : m_logThreadRunning = true;
468 :
469 36 : std::unique_lock<std::mutex> lock(m_qMutex, std::defer_lock);
470 :
471 : //Run until shutdown. If shutdown is true we keep running while the queue is not empty.
472 104 : while(!m_logShutdown || !m_logQueue.empty())
473 : {
474 68 : std::list<bufferPtrT>::iterator beg, it, er, end;
475 :
476 : //Get begin and end once, so we only process logs in the list at this point.
477 : //Do it locked so we don't have any collisions with new logs (maybe not necessary)
478 68 : lock.lock();
479 68 : beg = m_logQueue.begin();
480 68 : end = m_logQueue.end();
481 68 : lock.unlock();
482 :
483 : //Note: we're avoiding use of size() since that could be altered concurrently by a push_back.
484 68 : if( beg != end )
485 : {
486 42 : it = beg;
487 1469 : while( it != end )
488 : {
489 : //m_logFile.
490 1427 : mx::error_t errc = this->writeLog( *it );
491 1427 : if( errc != mx::error_t::noerror)
492 : {
493 0 : m_logThreadRunning = false;
494 0 : return;
495 : }
496 :
497 1427 : if(m_parent)
498 : {
499 152 : m_parent->logMessage( *it );
500 : }
501 1275 : else if( logHeader::logLevel( *it ) <= logPrio::LOG_NOTICE )
502 : {
503 577 : logStdFormat(std::cerr, *it);
504 577 : std::cerr << '\n';
505 : }
506 :
507 1427 : er = it;
508 1427 : ++it;
509 :
510 : //Erase while locked so we don't collide with a push_back.
511 1427 : lock.lock();
512 1427 : m_logQueue.erase(er);
513 1427 : lock.unlock();
514 : }
515 : }
516 :
517 : //m_logFile.
518 : ///\todo must check this for errors, and investigate how `fsyncgate` impacts us
519 68 : this->flush();
520 :
521 : //We only pause if there's nothing to do.
522 68 : if(m_logQueue.empty() && !m_logShutdown) std::this_thread::sleep_for( std::chrono::duration<unsigned long, std::nano>(m_writePause));
523 : }
524 :
525 36 : m_logThreadRunning = false;
526 36 : }
527 :
528 : template<class parentT, class logFileT>
529 : template<typename logT>
530 1427 : int logManager<parentT, logFileT>::createLog( bufferPtrT & logBuffer,
531 : const typename logT::messageT & msg,
532 : const logPrioT & level
533 : )
534 : {
535 : //Very first step is to get the current time.
536 1427 : timespecX ts;
537 1427 : ts.gettime();
538 :
539 2854 : return logHeader::createLog<logT>(logBuffer, ts, msg, level);
540 : }
541 :
542 : template<class parentT, class logFileT>
543 : template<typename logT>
544 0 : int logManager<parentT, logFileT>::createLog( bufferPtrT & logBuffer,
545 : const timespecX & ts,
546 : const typename logT::messageT & msg,
547 : const logPrioT & level
548 : )
549 : {
550 0 : return logHeader::createLog<logT>(logBuffer, ts, msg, level);
551 : }
552 :
553 : template<class parentT, class logFileT>
554 : template<typename logT>
555 1449 : void logManager<parentT, logFileT>::log( const typename logT::messageT & msg,
556 : logPrioT level
557 : )
558 : {
559 : //Step 0 check level.
560 1449 : if(level == logPrio::LOG_DEFAULT) level = logT::defaultLevel;
561 :
562 1449 : if(level > m_logLevel) return; // We do nothing with this.
563 :
564 : //Step 1 create log
565 1427 : bufferPtrT logBuffer;
566 1427 : createLog<logT>(logBuffer, msg, level);
567 :
568 : //Step 2 add log to queue
569 1427 : std::lock_guard<std::mutex> guard(m_qMutex); //Lock the mutex before pushing back.
570 1427 : m_logQueue.push_back(logBuffer);
571 :
572 :
573 1427 : }
574 :
575 : template<class parentT, class logFileT>
576 : template<typename logT>
577 0 : void logManager<parentT, logFileT>::log( timespecX & ts,
578 : const typename logT::messageT & msg,
579 : logPrioT level
580 : )
581 : {
582 : //Step 0 check level.
583 0 : if(level == logPrio::LOG_DEFAULT) level = logT::defaultLevel;
584 :
585 0 : if(level > m_logLevel) return; // We do nothing with this.
586 :
587 : //Step 1 create log
588 0 : bufferPtrT logBuffer;
589 0 : createLog<logT>(logBuffer, ts, msg, level);
590 :
591 : //Step 2 add log to queue
592 0 : std::lock_guard<std::mutex> guard(m_qMutex); //Lock the mutex before pushing back.
593 0 : m_logQueue.push_back(logBuffer);
594 :
595 0 : }
596 :
597 : template<class parentT, class logFileT>
598 : template<typename logT>
599 6 : void logManager<parentT, logFileT>::log( logPrioT level )
600 : {
601 6 : log<logT>( emptyMessage(), level );
602 6 : }
603 :
604 : template<class parentT, class logFileT>
605 : template<typename logT>
606 : void logManager<parentT, logFileT>::log( timespecX & ts,
607 : logPrioT level
608 : )
609 : {
610 : log<logT>( ts, emptyMessage(), level );
611 : }
612 :
613 : //class logFileRaw;
614 :
615 : //extern template struct logManager<logFileRaw>;
616 :
617 : } //namespace logger
618 : } //namespace MagAOX
619 :
620 : #endif //logger_logger_hpp
|
