koinos / koinos-log-cpp / 241

Committed 03 Oct 2023 06:05PM UTC coverage: 89.961% (-0.6%) from 90.551%

Build # 241

Build Type

push

travis-pro

Committed by

web-flow

Commit Message

Merge pull request #20 from koinos/normalize-logs

Normalize logs

Run Details

18 of 18 new or added lines in 2 files covered. (100.0%)

233 of 259 relevant lines covered (89.96%)

3.55 hits per line

Source File
Press 'n' to go to next uncovered line, 'b' for previous

77.59

/libraries/log/log.cpp

#include <koinos/log.hpp>
#include <koinos/util/hex.hpp>
#include <koinos/util/random.hpp>

#include <iostream>
#include <string>

#include <boost/log/sinks/basic_sink_backend.hpp>
#include <boost/log/attributes/value_extraction.hpp>
#include <boost/log/attributes/attribute_value.hpp>
#include <boost/date_time/posix_time/posix_time.hpp>
#include <boost/date_time/posix_time/posix_time_io.hpp>

#include <google/protobuf/text_format.h>
#include <google/protobuf/io/zero_copy_stream_impl.h>

#define TRACE_STRING    "trace"
#define DEBUG_STRING    "debug"
#define INFO_STRING     "info"
#define WARNING_STRING  "warning"
#define ERROR_STRING    "error"
#define FATAL_STRING    "fatal"

#define TIMESTAMP_ATTR  "TimeStamp"
#define SERVICE_ID_ATTR "ServiceID"
#define FILE_ATTR       "File"
#define LINE_ATTR       "Line"
#define SEVERITY_ATTR   "Severity"
#define MESSAGE_ATTR    "Message"

namespace koinos {

class KoinosFieldValuePrinter : public google::protobuf::TextFormat::FastFieldValuePrinter
{
public:
   virtual void PrintBytes( const std::string& val, google::protobuf::TextFormat::BaseTextGenerator* generator ) const override
   {
      generator->PrintString( util::to_hex( val ) );
   }
};

template< bool Color, bool DateTime >
class console_sink_impl : public boost::log::sinks::basic_formatted_sink_backend< char, boost::log::sinks::synchronized_feeding >
{
   enum class color : uint8_t
   {
      green,
      yellow,
      red,
      blue
   };

   static std::string colorize( const std::string& s, color c )
   {
      if constexpr ( !Color )
         return s;

      std::string val = "";

      switch ( c )
      {
         case color::green:
            val += "\033[32m";
            break;
         case color::yellow:
            val += "\033[33m";
            break;
         case color::red:
            val += "\033[31m";
            break;
         case color::blue:
            val += "\033[34m";
            break;
      }

      val += s;
      val += "\033[0m";

      return val;
   }

public:
   static void consume( const boost::log::record_view& rec, const string_type& formatted_string )
   {
      auto level  = rec[ boost::log::trivial::severity ];
      auto svc_id = rec.attribute_values()[ SERVICE_ID_ATTR ].extract< std::string >();
      auto line   = rec.attribute_values()[ LINE_ATTR ].extract< int >();
      auto file   = rec.attribute_values()[ FILE_ATTR ].extract< std::string >();
      auto ptime  = rec.attribute_values()[ TIMESTAMP_ATTR ].extract< boost::posix_time::ptime >().get();
      auto& s     = std::clog;

      if constexpr ( DateTime )
      {
         auto time = ptime.time_of_day();
         auto date = ptime.date();

         s << date.year() << "-";
         s << std::right << std::setfill( '0' ) << std::setw( 2 ) << date.month().as_number() << "-";
         s << std::right << std::setfill( '0' ) << std::setw( 2 ) << date.day() << " ";
         s << std::right << std::setfill( '0' ) << std::setw( 2 ) << boost::date_time::absolute_value( time.hours() ) << ":";
         s << std::right << std::setfill( '0' ) << std::setw( 2 ) << boost::date_time::absolute_value( time.minutes() ) << ":";
         s << std::right << std::setfill( '0' ) << std::setw( 2 ) << boost::date_time::absolute_value( time.seconds() ) << ".";
         s << std::right << std::setfill( '0' ) << std::setw( 6 ) << boost::date_time::absolute_value( time.fractional_seconds() );
         s << " ";
      }

      s << "(" << svc_id << ")";
      s << " [" << file << ":" << line << "] ";
      s << "<";
      switch ( level.get() )
      {
         case boost::log::trivial::severity_level::trace:
            s << colorize( TRACE_STRING, color::blue );
            break;
         case boost::log::trivial::severity_level::debug:
            s << colorize( DEBUG_STRING, color::blue );
            break;
         case boost::log::trivial::severity_level::info:
            s << colorize( INFO_STRING, color::green );
            break;
         case boost::log::trivial::severity_level::warning:
            s << colorize( WARNING_STRING, color::yellow );
            break;
         case boost::log::trivial::severity_level::error:
            s << colorize( ERROR_STRING, color::red );
            break;
         case boost::log::trivial::severity_level::fatal:
            s << colorize( FATAL_STRING, color::red );
            break;
         default:
            s << colorize( "unknown", color::red );
            break;
      }
      s << ">: " << formatted_string << std::endl;
   }
};

boost::log::trivial::severity_level level_from_string( const std::string& token )
{
   boost::log::trivial::severity_level l;

   if ( token == TRACE_STRING )
   {
      l = boost::log::trivial::severity_level::trace;
   }
   else if ( token == DEBUG_STRING )
   {
      l = boost::log::trivial::severity_level::debug;
   }
   else if ( token == INFO_STRING )
   {
      l = boost::log::trivial::severity_level::info;
   }
   else if ( token == WARNING_STRING )
   {
      l = boost::log::trivial::severity_level::warning;
   }
   else if ( token == ERROR_STRING )
   {
      l = boost::log::trivial::severity_level::error;
   }
   else if ( token == FATAL_STRING )
   {
      l = boost::log::trivial::severity_level::fatal;
   }
   else
   {
      throw std::runtime_error( "invalid log level" );
   }

   return l;
}

void initialize_logging(
   const std::string& application_name,
   const std::optional< std::string >& identifier,
   const std::string& filter_level,
   const std::optional< std::filesystem::path >& log_directory,
   bool color,
   bool datetime )
{
   using console_sink                = boost::log::sinks::synchronous_sink< console_sink_impl< false, false > >;
   using console_datetime_sink       = boost::log::sinks::synchronous_sink< console_sink_impl< false, true > >;
   using color_console_sink          = boost::log::sinks::synchronous_sink< console_sink_impl< true, false > >;
   using color_console_datetime_sink = boost::log::sinks::synchronous_sink< console_sink_impl< true, true > >;

   std::string id;

   if ( identifier.has_value() )
      id = identifier.value();
   else
      id = util::random_alphanumeric( 5 );

   std::string service_id = application_name + "." + id;

   if ( color )
      if ( datetime )
         boost::log::core::get()->add_sink( boost::make_shared< color_console_datetime_sink >() );
      else
         boost::log::core::get()->add_sink( boost::make_shared< color_console_sink >() );
   else
      if ( datetime )
         boost::log::core::get()->add_sink( boost::make_shared< console_datetime_sink >() );
      else
         boost::log::core::get()->add_sink( boost::make_shared< console_sink >() );

   boost::log::register_simple_formatter_factory< boost::log::trivial::severity_level, char >( SEVERITY_ATTR );

   if ( log_directory.has_value() )
   {
      // Output message to file, rotates when file reached 1mb. Each log file
      // is capped at 1mb and total is 100mb and 100 files.
      boost::log::add_file_log(
         boost::log::keywords::file_name = log_directory->string() + "/" + application_name + ".log",
         boost::log::keywords::target_file_name = log_directory->string() + "/" + application_name + "-%Y-%m-%dT%H-%M-%S.%f.log",
         boost::log::keywords::target = log_directory->string(),
         boost::log::keywords::rotation_size = 1 * 1024 * 1024,
         boost::log::keywords::max_size = 100 * 1024 * 1024,
         boost::log::keywords::max_files = 100,
         boost::log::keywords::format = "%" TIMESTAMP_ATTR "% (%" SERVICE_ID_ATTR "%) [%" FILE_ATTR "%:%" LINE_ATTR "%] <%" SEVERITY_ATTR "%>: %" MESSAGE_ATTR "%",
         boost::log::keywords::auto_flush = true
      );
   }

   boost::log::add_common_attributes();
   boost::log::core::get()->add_global_attribute( SERVICE_ID_ATTR, boost::log::attributes::constant< std::string >( service_id ) );

   boost::log::core::get()->set_filter( boost::log::trivial::severity >= level_from_string( filter_level ) );
}

} // koinos

namespace google::protobuf
{

std::ostream& operator<<( std::ostream& os, const google::protobuf::Message& m )
{
   google::protobuf::TextFormat::Printer printer;
   printer.SetSingleLineMode( true );
   printer.SetDefaultFieldValuePrinter( new koinos::KoinosFieldValuePrinter() );
   auto ost = google::protobuf::io::OstreamOutputStream( &os );
   printer.Print( m, &ost );
   return os;
}

} // google::protobuf

1	#include <koinos/log.hpp>
2	#include <koinos/util/hex.hpp>
3	#include <koinos/util/random.hpp>
4
5	#include <iostream>
6	#include <string>
7
8	#include <boost/log/sinks/basic_sink_backend.hpp>
9	#include <boost/log/attributes/value_extraction.hpp>
10	#include <boost/log/attributes/attribute_value.hpp>
11	#include <boost/date_time/posix_time/posix_time.hpp>
12	#include <boost/date_time/posix_time/posix_time_io.hpp>
13
14	#include <google/protobuf/text_format.h>
15	#include <google/protobuf/io/zero_copy_stream_impl.h>
16
17	#define TRACE_STRING "trace"
18	#define DEBUG_STRING "debug"
19	#define INFO_STRING "info"
20	#define WARNING_STRING "warning"
21	#define ERROR_STRING "error"
22	#define FATAL_STRING "fatal"
23
24	#define TIMESTAMP_ATTR "TimeStamp"
25	#define SERVICE_ID_ATTR "ServiceID"
26	#define FILE_ATTR "File"
27	#define LINE_ATTR "Line"
28	#define SEVERITY_ATTR "Severity"
29	#define MESSAGE_ATTR "Message"
30
31	namespace koinos {
32
33	class KoinosFieldValuePrinter : public google::protobuf::TextFormat::FastFieldValuePrinter	×
34	{
35	public:
36	virtual void PrintBytes( const std::string& val, google::protobuf::TextFormat::BaseTextGenerator* generator ) const override	×
37	{
38	generator->PrintString( util::to_hex( val ) );	×
39	}	×
40	};
41
42	template< bool Color, bool DateTime >
43	class console_sink_impl : public boost::log::sinks::basic_formatted_sink_backend< char, boost::log::sinks::synchronized_feeding >
44	{
45	enum class color : uint8_t
46	{
47	green,
48	yellow,
49	red,
50	blue
51	};
52
53	static std::string colorize( const std::string& s, color c )	18✔
54	{
55	if constexpr ( !Color )
56	return s;	11✔
57
58	std::string val = "";	7✔
59
60	switch ( c )	7✔
61	{
62	case color::green:
63	val += "\033[32m";	1✔
64	break;	1✔
65	case color::yellow:
66	val += "\033[33m";	1✔
67	break;	1✔
68	case color::red:
69	val += "\033[31m";	3✔
70	break;	3✔
71	case color::blue:
72	val += "\033[34m";	2✔
73	break;	2✔
74	}
75
76	val += s;	7✔
77	val += "\033[0m";	7✔
78
79	return val;	7✔
80	}	7✔
81
82	public:
83	static void consume( const boost::log::record_view& rec, const string_type& formatted_string )	18✔
84	{
85	auto level = rec[ boost::log::trivial::severity ];	18✔
86	auto svc_id = rec.attribute_values()[ SERVICE_ID_ATTR ].extract< std::string >();	18✔
87	auto line = rec.attribute_values()[ LINE_ATTR ].extract< int >();	18✔
88	auto file = rec.attribute_values()[ FILE_ATTR ].extract< std::string >();	18✔
89	auto ptime = rec.attribute_values()[ TIMESTAMP_ATTR ].extract< boost::posix_time::ptime >().get();	18✔
90	auto& s = std::clog;	18✔
91
92	if constexpr ( DateTime )
93	{
94	auto time = ptime.time_of_day();	18✔
95	auto date = ptime.date();	18✔
96
97	s << date.year() << "-";	18✔
98	s << std::right << std::setfill( '0' ) << std::setw( 2 ) << date.month().as_number() << "-";	18✔
99	s << std::right << std::setfill( '0' ) << std::setw( 2 ) << date.day() << " ";	18✔
100	s << std::right << std::setfill( '0' ) << std::setw( 2 ) << boost::date_time::absolute_value( time.hours() ) << ":";	18✔
101	s << std::right << std::setfill( '0' ) << std::setw( 2 ) << boost::date_time::absolute_value( time.minutes() ) << ":";	18✔
102	s << std::right << std::setfill( '0' ) << std::setw( 2 ) << boost::date_time::absolute_value( time.seconds() ) << ".";	18✔
103	s << std::right << std::setfill( '0' ) << std::setw( 6 ) << boost::date_time::absolute_value( time.fractional_seconds() );	18✔
104	s << " ";	18✔
105	}
106
107	s << "(" << svc_id << ")";	18✔
108	s << " [" << file << ":" << line << "] ";	18✔
109	s << "<";	18✔
110	switch ( level.get() )	18✔
111	{
112	case boost::log::trivial::severity_level::trace:
113	s << colorize( TRACE_STRING, color::blue );	2✔
114	break;	2✔
115	case boost::log::trivial::severity_level::debug:
116	s << colorize( DEBUG_STRING, color::blue );	2✔
117	break;	2✔
118	case boost::log::trivial::severity_level::info:
119	s << colorize( INFO_STRING, color::green );	2✔
120	break;	2✔
121	case boost::log::trivial::severity_level::warning:
122	s << colorize( WARNING_STRING, color::yellow );	3✔
123	break;	3✔
124	case boost::log::trivial::severity_level::error:
125	s << colorize( ERROR_STRING, color::red );	3✔
126	break;	3✔
127	case boost::log::trivial::severity_level::fatal:
128	s << colorize( FATAL_STRING, color::red );	3✔
129	break;	3✔
130	default:
131	s << colorize( "unknown", color::red );	3✔
132	break;	3✔
133	}
134	s << ">: " << formatted_string << std::endl;	18✔
135	}	18✔
136	};
137
138	boost::log::trivial::severity_level level_from_string( const std::string& token )	3✔
139	{
140	boost::log::trivial::severity_level l;
141
142	if ( token == TRACE_STRING )	3✔
143	{
144	l = boost::log::trivial::severity_level::trace;	2✔
145	}	2✔
146	else if ( token == DEBUG_STRING )	1✔
147	{
148	l = boost::log::trivial::severity_level::debug;	×
149	}	×
150	else if ( token == INFO_STRING )	1✔
151	{
152	l = boost::log::trivial::severity_level::info;	×
153	}	×
154	else if ( token == WARNING_STRING )	1✔
155	{
156	l = boost::log::trivial::severity_level::warning;	1✔
157	}	1✔
158	else if ( token == ERROR_STRING )	×
159	{
160	l = boost::log::trivial::severity_level::error;	×
161	}	×
162	else if ( token == FATAL_STRING )	×
163	{
164	l = boost::log::trivial::severity_level::fatal;	×
165	}	×
166	else
167	{
168	throw std::runtime_error( "invalid log level" );	×
169	}
170
171	return l;	3✔
172	}	×
173
174	void initialize_logging(	3✔
175	const std::string& application_name,
176	const std::optional< std::string >& identifier,
177	const std::string& filter_level,
178	const std::optional< std::filesystem::path >& log_directory,
179	bool color,
180	bool datetime )
181	{
182	using console_sink = boost::log::sinks::synchronous_sink< console_sink_impl< false, false > >;
183	using console_datetime_sink = boost::log::sinks::synchronous_sink< console_sink_impl< false, true > >;
184	using color_console_sink = boost::log::sinks::synchronous_sink< console_sink_impl< true, false > >;
185	using color_console_datetime_sink = boost::log::sinks::synchronous_sink< console_sink_impl< true, true > >;
186
187	std::string id;	3✔
188
189	if ( identifier.has_value() )	3✔
190	id = identifier.value();	2✔
191	else
192	id = util::random_alphanumeric( 5 );	1✔
193
194	std::string service_id = application_name + "." + id;	3✔
195
196	if ( color )	3✔
197	if ( datetime )	2✔
198	boost::log::core::get()->add_sink( boost::make_shared< color_console_datetime_sink >() );	1✔
199	else
200	boost::log::core::get()->add_sink( boost::make_shared< color_console_sink >() );	×
201	else
202	if ( datetime )	2✔
203	boost::log::core::get()->add_sink( boost::make_shared< console_datetime_sink >() );	2✔
204	else
205	boost::log::core::get()->add_sink( boost::make_shared< console_sink >() );	×
206
207	boost::log::register_simple_formatter_factory< boost::log::trivial::severity_level, char >( SEVERITY_ATTR );	3✔
208
209	if ( log_directory.has_value() )	3✔
210	{
211	// Output message to file, rotates when file reached 1mb. Each log file
212	// is capped at 1mb and total is 100mb and 100 files.
213	boost::log::add_file_log(	3✔
214	boost::log::keywords::file_name = log_directory->string() + "/" + application_name + ".log",	3✔
215	boost::log::keywords::target_file_name = log_directory->string() + "/" + application_name + "-%Y-%m-%dT%H-%M-%S.%f.log",	3✔
216	boost::log::keywords::target = log_directory->string(),	3✔
217	boost::log::keywords::rotation_size = 1 * 1024 * 1024,	3✔
218	boost::log::keywords::max_size = 100 * 1024 * 1024,	3✔
219	boost::log::keywords::max_files = 100,	3✔
220	boost::log::keywords::format = "%" TIMESTAMP_ATTR "% (%" SERVICE_ID_ATTR "%) [%" FILE_ATTR "%:%" LINE_ATTR "%] <%" SEVERITY_ATTR "%>: %" MESSAGE_ATTR "%",	3✔
221	boost::log::keywords::auto_flush = true	3✔
222	);
223	}	3✔
224
225	boost::log::add_common_attributes();	3✔
226	boost::log::core::get()->add_global_attribute( SERVICE_ID_ATTR, boost::log::attributes::constant< std::string >( service_id ) );	3✔
227
228	boost::log::core::get()->set_filter( boost::log::trivial::severity >= level_from_string( filter_level ) );	3✔
229	}	3✔
230
231	} // koinos
232
233	namespace google::protobuf
234	{
235
236	std::ostream& operator<<( std::ostream& os, const google::protobuf::Message& m )	×
237	{
238	google::protobuf::TextFormat::Printer printer;	×
239	printer.SetSingleLineMode( true );	×
240	printer.SetDefaultFieldValuePrinter( new koinos::KoinosFieldValuePrinter() );	×
241	auto ost = google::protobuf::io::OstreamOutputStream( &os );	×
242	printer.Print( m, &ost );	×
243	return os;	×
244	}	×
245
246	} // google::protobuf

koinos / koinos-log-cpp / 241

Source File Press 'n' to go to next uncovered line, 'b' for previous

Source File
Press 'n' to go to next uncovered line, 'b' for previous