Line data Source code
1 : /** \file logdump.hpp
2 : * \brief A simple utility to dump MagAO-X binary logs to stdout.
3 : *
4 : * \ingroup logdump_files
5 : */
6 :
7 : #ifndef logdump_hpp
8 : #define logdump_hpp
9 :
10 : #include <iostream>
11 : #include <cstring>
12 : #include <filesystem>
13 :
14 : #include <mx/mxError.hpp>
15 : #include <mx/ioutils/fileUtils.hpp>
16 :
17 : #include "../../libMagAOX/libMagAOX.hpp"
18 : using namespace MagAOX::logger;
19 :
20 : using namespace flatlogs;
21 :
22 : /** \defgroup logdump logdump: MagAO-X Log Reader
23 : * \brief Read a MagAO-X binary log file.
24 : *
25 : * <a href="../handbook/utils/logdump.html">Utility Documentation</a>
26 : *
27 : * \ingroup utils
28 : *
29 : */
30 :
31 : /** \defgroup logdump_files logdump Files
32 : * \ingroup logdump
33 : */
34 :
35 : /// An application to dump MagAo-X binary logs to the terminal.
36 : /** \todo document this
37 : * \todo add config for colors, both on/off and options to change.
38 : *
39 : * \ingroup logdump
40 : */
41 : class logdump : public mx::app::application
42 : {
43 : typedef mx::verbose::vvv verboseT;
44 :
45 : protected:
46 : std::string m_dir;
47 : std::string m_ext;
48 : std::string m_file;
49 :
50 : bool m_time{ false };
51 : bool m_jsonMode{ false };
52 :
53 : unsigned long m_pauseTime{ 250 }; /// When following, pause time to check for new data. msec. Default is 250 msec.
54 : int m_fileCheckInterval{
55 : 20 }; /// When following, number of loops to wait before checking for a new file. Default is 4.
56 :
57 : std::vector<std::string> m_prefixes;
58 :
59 : size_t m_nfiles{ 0 }; /// Number of files to dump. Default is 0, unless following then the default is 1.
60 :
61 : bool m_follow{ false };
62 :
63 : logPrioT m_level{ logPrio::LOG_DEFAULT };
64 :
65 : std::vector<eventCodeT> m_codes;
66 :
67 : void printLogBuff( const logPrioT &lvl, const eventCodeT &ec, const msgLenT &len, bufferPtrT &logBuff );
68 : void printLogJson( const msgLenT &len, bufferPtrT &logBuff );
69 :
70 : public:
71 : virtual void setupConfig();
72 :
73 : virtual void loadConfig();
74 :
75 : virtual int execute();
76 :
77 : virtual int gettimes( std::vector<std::string> &logs );
78 : };
79 :
80 0 : void logdump::setupConfig()
81 : {
82 0 : config.add( "pauseTime",
83 : "p",
84 : "pauseTime",
85 : argType::Required,
86 : "",
87 : "pauseTime",
88 : false,
89 : "int",
90 : "When following, time in milliseconds to pause before checking for new entries." );
91 0 : config.add( "fileCheckInterval",
92 : "",
93 : "fileCheckInterval",
94 : argType::Required,
95 : "",
96 : "fileCheckInterval",
97 : false,
98 : "int",
99 : "When following, number of pause intervals between checks for new files." );
100 :
101 0 : config.add( "dir",
102 : "d",
103 : "dir",
104 : argType::Required,
105 : "",
106 : "dir",
107 : false,
108 : "string",
109 : "Directory to search for logs. MagAO-X default is normally used." );
110 0 : config.add( "ext",
111 : "e",
112 : "ext",
113 : argType::Required,
114 : "",
115 : "ext",
116 : false,
117 : "string",
118 : "The file extension of log files. MagAO-X default is normally used." );
119 0 : config.add( "nfiles",
120 : "n",
121 : "nfiles",
122 : argType::Required,
123 : "",
124 : "nfiles",
125 : false,
126 : "int",
127 : "Number of log files to dump. If 0, then all matching files dumped. Default: 0, 1 if following." );
128 0 : config.add( "follow",
129 : "f",
130 : "follow",
131 : argType::True,
132 : "",
133 : "follow",
134 : false,
135 : "bool",
136 : "Follow the log, printing new entries as they appear." );
137 0 : config.add( "level",
138 : "L",
139 : "level",
140 : argType::Required,
141 : "",
142 : "level",
143 : false,
144 : "int/string",
145 : "Minimum log level to dump, either an integer or a string. -1/TELEMETRY [the default], 0/DEFAULT, "
146 : "1/D1/DBG1/DEBUG2, 2/D2/DBG2/DEBUG1,3/INFO,4/WARNING,5/ERROR,6/CRITICAL,7/FATAL. Note that only the "
147 : "mininum unique string is required." );
148 0 : config.add( "code",
149 : "C",
150 : "code",
151 : argType::Required,
152 : "",
153 : "code",
154 : false,
155 : "int",
156 : "The event code, or vector of codes, to dump. If not specified, all codes are dumped. See "
157 : "logCodes.hpp for a complete list of codes." );
158 0 : config.add( "file",
159 : "F",
160 : "file",
161 : argType::Required,
162 : "",
163 : "file",
164 : false,
165 : "string",
166 : "A single file to process. If no / are found in name it will look in the specified directory (or "
167 : "MagAO-X default)." );
168 0 : config.add( "time",
169 : "T",
170 : "time",
171 : argType::True,
172 : "",
173 : "time",
174 : false,
175 : "bool",
176 : "time span mode: prints the ISO 8601 UTC timestamps of the first and last entry, the elapsed time in "
177 : "seconds, and the number of records in the file as a space-delimited string" );
178 0 : config.add( "json",
179 : "J",
180 : "json",
181 : argType::True,
182 : "",
183 : "json",
184 : false,
185 : "bool",
186 : "JSON mode: emits one JSON document per line for each record in the log" );
187 0 : }
188 :
189 0 : void logdump::loadConfig()
190 : {
191 0 : config( m_pauseTime, "pauseTime" );
192 0 : config( m_fileCheckInterval, "fileCheckInterval" );
193 :
194 : // Get default log dir
195 0 : std::string tmpstr = mx::sys::getEnv( MAGAOX_env_path );
196 0 : if( tmpstr == "" )
197 : {
198 0 : tmpstr = MAGAOX_path;
199 : }
200 0 : m_dir = tmpstr + "/" + MAGAOX_logRelPath;
201 : ;
202 :
203 : // Now check for config option for dir
204 0 : config( m_dir, "dir" );
205 :
206 0 : m_ext = ".";
207 0 : m_ext += MAGAOX_default_logExt;
208 0 : config( m_ext, "ext" );
209 : ///\todo need to check for lack of "." and error or fix
210 :
211 0 : config( m_file, "file" );
212 :
213 0 : if( m_file == "" && config.nonOptions.size() < 1 )
214 : {
215 0 : std::cerr << "logdump: need application name. Try logdump -h for help.\n";
216 : }
217 :
218 0 : if( m_file == "" && config.nonOptions.size() > 1 )
219 : {
220 0 : std::cerr << "logdump: only one application at a time supported. Try logdump -h for help.\n";
221 : }
222 :
223 0 : m_prefixes.resize( config.nonOptions.size() );
224 0 : for( size_t i = 0; i < config.nonOptions.size(); ++i )
225 : {
226 0 : m_prefixes[i] = config.nonOptions[i];
227 : }
228 :
229 0 : if( config.isSet( "time" ) )
230 0 : m_time = true;
231 0 : if( config.isSet( "json" ) )
232 0 : m_jsonMode = true;
233 :
234 0 : config( m_follow, "follow" );
235 :
236 0 : if( m_follow )
237 0 : m_nfiles = 1; // default to 1 if follow is set.
238 0 : config( m_nfiles, "nfiles" );
239 :
240 0 : tmpstr = "";
241 0 : config( tmpstr, "level" );
242 0 : if( tmpstr != "" )
243 : {
244 0 : m_level = logLevelFromString( tmpstr );
245 : }
246 :
247 0 : config( m_codes, "code" );
248 :
249 0 : std::cerr << m_codes.size() << "\n";
250 0 : }
251 :
252 0 : int logdump::execute()
253 : {
254 :
255 0 : if( m_file == "" && m_prefixes.size() != 1 )
256 0 : return -1; // error message will have been printed in loadConfig.
257 :
258 0 : std::vector<std::string> subdirs, logs;
259 :
260 0 : if( m_file != "" )
261 : {
262 0 : if( m_file.find( '/' ) == std::string::npos )
263 : {
264 :
265 0 : std::string devName, YYYY, MM, DD, hh, mm, ss, nn;
266 0 : mx_error_check_rv(MagAOX::file::parseFilePath( devName, YYYY, MM, DD, hh, mm, ss, nn, m_file ),-1);
267 :
268 0 : m_file = m_dir + '/' + devName + '/' + YYYY + '_' + MM + '_' + DD + '/' + m_file;
269 0 : }
270 :
271 0 : logs.push_back( m_file );
272 : }
273 : else
274 : {
275 0 : mx_error_check_rv(mx::ioutils::getFileNames(subdirs, m_dir + "/" + m_prefixes[0], "", "", "" ),-1);
276 :
277 0 : if( m_follow )
278 : {
279 0 : mx_error_check_rv(mx::ioutils::getFileNames(logs, subdirs.back(), m_prefixes[0], "", m_ext ), -1);
280 : }
281 : else
282 : {
283 0 : for( size_t d = 0; d < subdirs.size(); ++d )
284 : {
285 : // get subdir vectors one at a time and append to build the whole list
286 0 : std::vector<std::string> tlogs;
287 0 : mx_error_check_rv(mx::ioutils::getFileNames(tlogs, subdirs[d], m_prefixes[0], "", m_ext ),-1);
288 0 : logs.insert( logs.end(), tlogs.begin(), tlogs.end() );
289 0 : }
290 : }
291 : }
292 :
293 : ///\todo if follow is set, then should nfiles default to 1 unless explicitly set?
294 0 : if( m_nfiles == 0 )
295 : {
296 0 : m_nfiles = logs.size();
297 : }
298 :
299 0 : if( m_nfiles > logs.size() )
300 0 : m_nfiles = logs.size();
301 :
302 0 : if( m_time )
303 : {
304 0 : return gettimes( logs );
305 : }
306 :
307 0 : bool firstRun = true; // for only showing latest entries on first run when following.
308 :
309 0 : for( size_t i = logs.size() - m_nfiles; i < logs.size(); ++i )
310 : {
311 0 : std::string fname = logs[i];
312 : FILE *fin;
313 :
314 0 : bufferPtrT head( (char *) ::operator new(logHeader::maxHeadSize));
315 :
316 0 : bufferPtrT logBuff;
317 :
318 0 : fin = fopen( fname.c_str(), "rb" );
319 :
320 : //--> get size here!!
321 0 : off_t finSize = mx::ioutils::fileSize( fileno( fin ) );
322 :
323 0 : std::cerr << fname << "\n";
324 :
325 0 : off_t totNrd = 0;
326 :
327 0 : size_t buffSz = 0;
328 0 : while( !feof( fin ) ) //<--This should be an exit condition controlled by loop logic, not feof.
329 : {
330 : int nrd;
331 :
332 : ///\todo check for errors on all reads . . .
333 :
334 : // Read next header
335 0 : nrd = fread( head.get(), sizeof( char ), logHeader::minHeadSize, fin );
336 0 : if( nrd == 0 )
337 : {
338 : // If we're following and on the last log file, wait for more to show up.
339 0 : if( m_follow == true && i == logs.size() - 1 )
340 : {
341 0 : int check = 0;
342 0 : firstRun = false; // from now on we show all logs
343 0 : while( nrd == 0 )
344 : {
345 0 : std::this_thread::sleep_for( std::chrono::duration<unsigned long, std::milli>( m_pauseTime ) );
346 0 : clearerr( fin );
347 0 : nrd = fread( head.get(), sizeof( char ), logHeader::minHeadSize, fin );
348 0 : if( nrd > 0 )
349 0 : break;
350 :
351 0 : ++check;
352 0 : if( check >= m_fileCheckInterval )
353 : {
354 : // Check if a new sub-directory exists now.
355 0 : size_t old_subdirs_sz = subdirs.size();
356 0 : mx_error_check_rv(mx::ioutils::getFileNames( subdirs, m_dir + "/" + m_prefixes[0], "", "", "" ),-1);
357 0 : if( subdirs.size() > old_subdirs_sz )
358 : {
359 : // new subdirs(s) detected;
360 0 : break;
361 : }
362 :
363 : // Check if a new file exists now.
364 0 : size_t old_logs_sz = logs.size();
365 :
366 0 : mx_error_check_rv(mx::ioutils::getFileNames( logs, subdirs.back(), m_prefixes[0], "", m_ext ),-1);
367 :
368 0 : if( logs.size() > old_logs_sz )
369 : {
370 : // new file(s) detected;
371 0 : break;
372 : }
373 0 : check = 0;
374 : }
375 : }
376 : }
377 : else
378 : {
379 0 : break;
380 : }
381 : }
382 :
383 : // We got here without any data, probably means time to get a new file.
384 0 : if( nrd == 0 )
385 0 : break;
386 :
387 0 : totNrd += nrd;
388 :
389 0 : if( logHeader::msgLen0( head ) == logHeader::MAX_LEN0 - 1 )
390 : {
391 : // Intermediate size message, read two more bytes
392 0 : nrd = fread( head.get() + logHeader::minHeadSize, sizeof( char ), sizeof( msgLen1T ), fin );
393 : }
394 0 : else if( logHeader::msgLen0( head ) == logHeader::MAX_LEN0 )
395 : {
396 : // Large size message: read 8 more bytes
397 0 : nrd = fread( head.get() + logHeader::minHeadSize, sizeof( char ), sizeof( msgLen2T ), fin );
398 : }
399 :
400 0 : logPrioT lvl = logHeader::logLevel( head );
401 0 : eventCodeT ec = logHeader::eventCode( head );
402 0 : msgLenT len = logHeader::msgLen( head );
403 :
404 : // Here: check if lvl, eventCode, etc, match what we want.
405 : // If not, fseek and loop.
406 0 : if( lvl > m_level )
407 : {
408 0 : fseek( fin, len, SEEK_CUR );
409 0 : continue;
410 : }
411 :
412 0 : if( m_codes.size() > 0 )
413 : {
414 0 : bool found = false;
415 0 : for( size_t c = 0; c < m_codes.size(); ++c )
416 : {
417 0 : if( m_codes[c] == ec )
418 : {
419 0 : found = true;
420 0 : break;
421 : }
422 : }
423 :
424 0 : if( !found )
425 : {
426 0 : fseek( fin, len, SEEK_CUR );
427 0 : continue;
428 : }
429 : }
430 :
431 0 : size_t hSz = logHeader::headerSize( head );
432 :
433 0 : if( (size_t)hSz + (size_t)len > buffSz )
434 : {
435 0 : logBuff = bufferPtrT( (char *) ::operator new(hSz + len));
436 : }
437 0 : memcpy( logBuff.get(), head.get(), hSz );
438 :
439 : ///\todo what do we do if nrd not equal to expected size?
440 0 : nrd = fread( logBuff.get() + hSz, sizeof( char ), len, fin );
441 : // If not following, exit loop without printing the incomplete log entry (go on to next file).cd
442 : // If following, wait for it, but also be checking for new log file in case of crash
443 :
444 0 : totNrd += nrd;
445 :
446 0 : if( m_follow && firstRun && finSize > 512 && totNrd < finSize - 512 )
447 : {
448 : // firstRun = false;
449 0 : continue;
450 : }
451 :
452 0 : if( !logVerify( ec, logBuff, len ) )
453 : {
454 0 : std::cerr << "Log " << fname << " failed verification on code=" << ec
455 0 : << " at byte=" << totNrd - len - hSz << ". File possibly corrupt. Exiting." << std::endl;
456 0 : return -1;
457 : }
458 :
459 0 : if( m_jsonMode )
460 : {
461 0 : printLogJson( len, logBuff );
462 : }
463 : else
464 : {
465 0 : printLogBuff( lvl, ec, len, logBuff );
466 : }
467 : }
468 :
469 0 : fclose( fin );
470 0 : }
471 :
472 0 : return 0;
473 0 : }
474 :
475 0 : inline void logdump::printLogBuff( const logPrioT &lvl, const eventCodeT &ec, const msgLenT &len, bufferPtrT &logBuff )
476 : {
477 : static_cast<void>( len ); // be unused
478 :
479 0 : if( ec == eventCodes::GIT_STATE )
480 : {
481 0 : if( git_state::repoName( logHeader::messageBuffer( logBuff ) ) == "MagAOX" )
482 : {
483 0 : for( int i = 0; i < 80; ++i )
484 0 : std::cout << '-';
485 0 : std::cout << "\n\t\t\t\t SOFTWARE RESTART\n";
486 0 : for( int i = 0; i < 80; ++i )
487 0 : std::cout << '-';
488 0 : std::cout << '\n';
489 : }
490 : }
491 :
492 0 : if( lvl < logPrio::LOG_INFO )
493 : {
494 0 : if( lvl == logPrio::LOG_EMERGENCY )
495 : {
496 0 : std::cout << "\033[104m\033[91m\033[5m\033[1m";
497 : }
498 :
499 0 : if( lvl == logPrio::LOG_ALERT )
500 : {
501 0 : std::cout << "\033[101m\033[5m";
502 : }
503 :
504 0 : if( lvl == logPrio::LOG_CRITICAL )
505 : {
506 0 : std::cout << "\033[41m\033[1m";
507 : }
508 :
509 0 : if( lvl == logPrio::LOG_ERROR )
510 : {
511 0 : std::cout << "\033[91m\033[1m";
512 : }
513 :
514 0 : if( lvl == logPrio::LOG_WARNING )
515 : {
516 0 : std::cout << "\033[93m\033[1m";
517 : }
518 :
519 0 : if( lvl == logPrio::LOG_NOTICE )
520 : {
521 0 : std::cout << "\033[1m";
522 : }
523 : }
524 :
525 0 : logStdFormat( std::cout, logBuff );
526 :
527 0 : std::cout << "\033[0m";
528 0 : std::cout << std::endl;
529 0 : }
530 :
531 0 : inline void logdump::printLogJson( const msgLenT &len, bufferPtrT &logBuff )
532 : {
533 : static_cast<void>( len ); // be unused
534 0 : logJsonFormat( std::cout, logBuff );
535 0 : std::cout << std::endl;
536 0 : }
537 :
538 0 : int logdump::gettimes( std::vector<std::string> &logs )
539 : {
540 0 : for( size_t i = logs.size() - m_nfiles; i < logs.size(); ++i )
541 : {
542 0 : std::string fname = logs[i];
543 : FILE *fin;
544 :
545 0 : bufferPtrT head( (char *) ::operator new(logHeader::maxHeadSize) );
546 :
547 0 : fin = fopen( fname.c_str(), "rb" );
548 :
549 : //--> get size here!!
550 : // off_t finSize = mx::ioutils::fileSize( fileno(fin) );
551 :
552 0 : off_t totNrd = 0;
553 :
554 : // size_t buffSz = 0;
555 :
556 : // Read firs header
557 :
558 : int nrd;
559 :
560 : ///\todo check for errors on all reads . . .
561 :
562 : // Read next header
563 0 : nrd = fread( head.get(), sizeof( char ), logHeader::minHeadSize, fin );
564 0 : if( nrd == 0 )
565 : {
566 0 : std::cerr << "got no header\n";
567 0 : return 0;
568 : }
569 :
570 0 : if( logHeader::msgLen0( head ) == logHeader::MAX_LEN0 - 1 )
571 : {
572 : // Intermediate size message, read two more bytes
573 0 : nrd = fread( head.get() + logHeader::minHeadSize, sizeof( char ), sizeof( msgLen1T ), fin );
574 : }
575 0 : else if( logHeader::msgLen0( head ) == logHeader::MAX_LEN0 )
576 : {
577 : // Large size message: read 8 more bytes
578 0 : nrd = fread( head.get() + logHeader::minHeadSize, sizeof( char ), sizeof( msgLen2T ), fin );
579 : }
580 :
581 : // logPrioT lvl = logHeader::logLevel(head);
582 : // eventCodeT ec = logHeader::eventCode(head);
583 0 : msgLenT len = logHeader::msgLen( head );
584 0 : timespecX ts0 = logHeader::timespec( head );
585 : // size_t hSz = logHeader::headerSize(head);
586 :
587 0 : uint32_t nRecords = 1;
588 0 : fseek( fin, len, SEEK_CUR );
589 :
590 0 : timespecX ts;
591 :
592 0 : while( !feof( fin ) ) //<--This should be an exit condition controlled by loop logic, not feof.
593 : {
594 : int nrd;
595 :
596 : // Read next header
597 0 : nrd = fread( head.get(), sizeof( char ), logHeader::minHeadSize, fin );
598 0 : if( nrd == 0 )
599 : {
600 0 : break;
601 : }
602 0 : nRecords += 1;
603 :
604 : // We got here without any data, probably means time to get a new file.
605 0 : if( nrd == 0 )
606 0 : break;
607 :
608 0 : totNrd += nrd;
609 :
610 0 : if( logHeader::msgLen0( head ) == logHeader::MAX_LEN0 - 1 )
611 : {
612 : // Intermediate size message, read two more bytes
613 0 : nrd = fread( head.get() + logHeader::minHeadSize, sizeof( char ), sizeof( msgLen1T ), fin );
614 : }
615 0 : else if( logHeader::msgLen0( head ) == logHeader::MAX_LEN0 )
616 : {
617 : // Large size message: read 8 more bytes
618 0 : nrd = fread( head.get() + logHeader::minHeadSize, sizeof( char ), sizeof( msgLen2T ), fin );
619 : }
620 :
621 : // lvl = logHeader::logLevel(head);
622 : // ec = logHeader::eventCode(head);
623 0 : len = logHeader::msgLen( head );
624 0 : ts = logHeader::timespec( head );
625 : // hSz = logHeader::headerSize(head);
626 :
627 0 : fseek( fin, len, SEEK_CUR );
628 : }
629 :
630 0 : fclose( fin );
631 :
632 0 : double t0 = ts0.time_s + ts0.time_ns / 1e9;
633 0 : double t = ts.time_s + ts.time_ns / 1e9;
634 :
635 0 : std::cout << fname << " " << ts0.ISO8601DateTimeStrX() << "Z " << ts.ISO8601DateTimeStrX() << "Z " << t - t0
636 0 : << " " << nRecords << std::endl;
637 0 : }
638 :
639 0 : return 0;
640 : }
641 :
642 : #endif // logdump_hpp
|
