Opened 8 years ago

Closed 8 years ago

Last modified 8 years ago

#10238 closed Bugs (fixed)

syslog pri part error in custom severity (init_from_stream)

Reported by: anonymous Owned by: Andrey Semashev
Milestone: To Be Determined Component: log
Version: Boost 1.55.0 Severity: Problem
Keywords: Cc:

Description

Hi all, I'm trying to tune logging from settings to be able to send message to Syslog, TextFile and Console. I use %Severity% keyword in all these cases. My task is get text value of severity in TextFile and Console, and to get correct format of message in Syslog.

During executing the code below I've got an error pri part in SyslogViewer [ #TextFile - OK <DEBUG>[2014-Jul-24 10:27:28.611879] This is a debug severity record <INFO>[2014-Jul-24 10:27:28.627501] This is a info severity record <WARNING>[2014-Jul-24 10:27:28.658746] This is a warning severity record <ERROR>[2014-Jul-24 10:27:28.674369] This is a error severity record <CRITICAL>[2014-Jul-24 10:27:28.705613] This is a critical severity record

#Syslog - ERROR PRI PART <14> Jul 24 10:27:28 10.10.10.73 test.exe This is a debug severity record <14> Jul 24 10:27:28 10.10.10.73 test.exe This is a info severity record <14> Jul 24 10:27:28 10.10.10.73 test.exe This is a warning severity record <14> Jul 24 10:27:28 10.10.10.73 test.exe This is a error severity record <14> Jul 24 10:27:28 10.10.10.73 test.exe This is a critical severity record ] Every record has Syslog pri part equals to <14>. That is mistake!

P.S. If I use int instead of enum as severity level, everything is ok in Syslog, but in this case I can not get text values of %Severity% in TextFile and Console [ #TextFile - I need %Severity% as text here <15>[2014-Jul-24 10:27:28.611879] This is a debug severity record <14>[2014-Jul-24 10:27:28.627501] This is a info severity record <12>[2014-Jul-24 10:27:28.658746] This is a warning severity record <11>[2014-Jul-24 10:27:28.674369] This is a error severity record <10>[2014-Jul-24 10:27:28.705613] This is a critical severity record

#Syslog <15> Jul 24 10:44:16 MaZhorWork fmod_test.exe This is a debug severity record <14> Jul 24 10:44:16 MaZhorWork fmod_test.exe This is a info severity record <12> Jul 24 10:44:17 MaZhorWork fmod_test.exe This is a warning severity record <11> Jul 24 10:44:17 MaZhorWork fmod_test.exe This is a error severity record <10> Jul 24 10:44:17 MaZhorWork fmod_test.exe This is a critical severity record ]

P.S.2. In my opinion problem is in $(BOOST_ROOT_55)\libs\log\src\init_from_settings.cpp, line 453:

	// For now we use only the default level mapping. Will add support for configuration later.
	backend->set_severity_mapper(sinks::syslog::direct_severity_mapping< >(log::aux::default_attribute_names::severity()));

My code that I tried

//Here we define our application severity levels.
typedef enum TSysLogSeverity
{
	slEmergency = boost::log::sinks::syslog::emergency,                
	slAlert = boost::log::sinks::syslog::alert,                    
	slCritical = boost::log::sinks::syslog::critical,                 
	slError = boost::log::sinks::syslog::error,                    
	slWarning = boost::log::sinks::syslog::warning,                  
	slNotice = boost::log::sinks::syslog::notice,                   
	slInfo = boost::log::sinks::syslog::info,                     
	slDebug = boost::log::sinks::syslog::debug                     
};

// The operator is used for regular stream formatting
std::ostream& operator<< (std::ostream& strm, TSysLogSeverity level)
{
	static const char* strings[] =
	{
		"EMERGENCY",
		"ALERT",
		"CRITICAL",
		"ERROR",
		"WARNING",
		"NOTICE",
		"INFO",
		"DEBUG"
	};

	if (static_cast< std::size_t >(level) < sizeof(strings) / sizeof(*strings))
		strm << strings[level];
	else
		strm << level;

	return strm;
}

std::istream& operator>>(std::istream& i, TSysLogSeverity &level) {
	std::string s_tmp;
	i >> s_tmp;

	static const char* strings[] =
	{
		"EMERGENCY",
		"ALERT",
		"CRITICAL",
		"ERROR",
		"WARNING",
		"NOTICE",
		"INFO",
		"DEBUG"
	};

	bool bFound = false;
	const std::size_t i_array_size = sizeof(strings) / sizeof(*strings);
	for (int k = 0; k < i_array_size ; k++)
	{
		if (s_tmp == std::string(strings[k]))
		{
			level = TSysLogSeverity(k);
			bFound = true;
			break;
		}
	}

	if (!bFound)
	{
		level = TSysLogSeverity(std::stoul(s_tmp));
	}

	return i;
}

// Attribute value tag type
struct severity_tag;

// The operator is used when putting the severity level to log
boost::log::formatting_ostream& operator<<
	(
	boost::log::formatting_ostream& strm,
	boost::log::to_log_manip< TSysLogSeverity, severity_tag > const& manip
	)
{
	static const char* strings[] =
	{
		"EMERGENCY",
		"ALERT",
		"CRITICAL",
		"ERROR",
		"WARNING",
		"NOTICE",
		"INFO",
		"DEBUG"
	};

	TSysLogSeverity level = manip.get();
	if (static_cast< std::size_t >(level) < sizeof(strings) / sizeof(*strings))
		strm << strings[level];
	else
		strm << static_cast< int >(level);

	return strm;
}

//  Global logger declaration
BOOST_LOG_INLINE_GLOBAL_LOGGER_DEFAULT(test_lg, src::severity_logger_mt<TSysLogSeverity>)

void try_logging()
{
	

	src::severity_logger_mt<TSysLogSeverity>& lg = test_lg::get();
	BOOST_LOG_SEV(lg, slDebug) << "This is a debug severity record";
	BOOST_LOG_SEV(lg, slInfo) << "This is a info severity record";
	BOOST_LOG_SEV(lg, slWarning) << "This is a warning severity record";
	BOOST_LOG_SEV(lg, slError) << "This is a error severity record";
	BOOST_LOG_SEV(lg, slCritical) << "This is a critical severity record";

	
}

int _tmain(int argc, _TCHAR* argv[])
{
	try
	{
		
		boost::filesystem::path p(argv[0]);
		p = p.replace_extension(".ini");
		
		// Open the file
		std::ifstream settings(p.string());
		if (!settings.is_open())
		{
			throw std::runtime_error("Could not open <" + p.string() + "> file");
		}

		boost::log::register_simple_formatter_factory<TSysLogSeverity, char >(boost::log::aux::default_attribute_names::severity());
  		boost::log::register_simple_filter_factory<TSysLogSeverity>(boost::log::aux::default_attribute_names::severity());

		// Read the settings and initialize logging library
		logging::init_from_stream(settings);

		src::severity_logger_mt<TSysLogSeverity>& lg = test_lg::get();

 		// Add some attributes
 		logging::add_common_attributes();

		// Try logging
		try_logging();

	}
	catch (std::exception& e)
	{
		std::cout << "FAILURE: " << e.what() << std::endl;
	}

	_getch();
	return 0;
}

Change History (5)

comment:1 by anonymous, 8 years ago

I'm sorry for bad formatting, because it's my first ticket to boost. Here is detailed output that i've got

1) Using enum as severity level

#TextFile - OK
<DEBUG>[2014-Jul-24 10:27:28.611879]  This is a debug severity record
<INFO>[2014-Jul-24 10:27:28.627501]  This is a info severity record
<WARNING>[2014-Jul-24 10:27:28.658746]  This is a warning severity record
<ERROR>[2014-Jul-24 10:27:28.674369]  This is a error severity record
<CRITICAL>[2014-Jul-24 10:27:28.705613]  This is a critical severity record

#Syslog - ERROR PRI PART
<14> Jul  24 10:27:28 10.10.10.73 test.exe This is a debug severity record
<14> Jul  24 10:27:28 10.10.10.73 test.exe This is a info severity record
<14> Jul  24 10:27:28 10.10.10.73 test.exe This is a warning severity record
<14> Jul  24 10:27:28 10.10.10.73 test.exe This is a error severity record
<14> Jul  24 10:27:28 10.10.10.73 test.exe This is a critical severity record

2) using int as severity level

#TextFile - I need %Severity% as text here
<15>[2014-Jul-24 10:27:28.611879]  This is a debug severity record
<14>[2014-Jul-24 10:27:28.627501]  This is a info severity record
<12>[2014-Jul-24 10:27:28.658746]  This is a warning severity record
<11>[2014-Jul-24 10:27:28.674369]  This is a error severity record
<10>[2014-Jul-24 10:27:28.705613]  This is a critical severity record

#Syslog
<15> Jul  24 10:44:16 MaZhorWork fmod_test.exe This is a debug severity record
<14> Jul  24 10:44:16 MaZhorWork fmod_test.exe This is a info severity record
<12> Jul  24 10:44:17 MaZhorWork fmod_test.exe This is a warning severity record
<11> Jul  24 10:44:17 MaZhorWork fmod_test.exe This is a error severity record
<10> Jul  24 10:44:17 MaZhorWork fmod_test.exe This is a critical severity record

comment:2 by alexander.zhornyak@…, 8 years ago

Hi all, I'm trying to tune logging from settings to be able to send message to Syslog, TextFile_, Console. I use %Severity% keyword in all these cases. My task is get text value of severity in TextFile_, Console, to get correct format of message in Syslog.

During executing the code below I've got an error pri part in Syslog.

#TextFile - OK
<DEBUG>[2014-Jul-24 10:27:28.611879]  This is a debug severity record
<INFO>[2014-Jul-24 10:27:28.627501]  This is a info severity record
<WARNING>[2014-Jul-24 10:27:28.658746]  This is a warning severity record
<ERROR>[2014-Jul-24 10:27:28.674369]  This is a error severity record
<CRITICAL>[2014-Jul-24 10:27:28.705613]  This is a critical severity record

#Syslog - ERROR PRI PART
<14> Jul  24 10:27:28 10.10.10.73 test.exe This is a debug severity record
<14> Jul  24 10:27:28 10.10.10.73 test.exe This is a info severity record
<14> Jul  24 10:27:28 10.10.10.73 test.exe This is a warning severity record
<14> Jul  24 10:27:28 10.10.10.73 test.exe This is a error severity record
<14> Jul  24 10:27:28 10.10.10.73 test.exe This is a critical severity record

Every record has Syslog pri part equals to <14>. That is mistake!

P.S. If I use int instead of enum as severity level, everything is ok in Syslog, but in this case I can not get text values of %Severity% in TextFile_ and Console

#TextFile - I need %Severity% as text here
<15>[2014-Jul-24 10:27:28.611879]  This is a debug severity record
<14>[2014-Jul-24 10:27:28.627501]  This is a info severity record
<12>[2014-Jul-24 10:27:28.658746]  This is a warning severity record
<11>[2014-Jul-24 10:27:28.674369]  This is a error severity record
<10>[2014-Jul-24 10:27:28.705613]  This is a critical severity record

#Syslog - OK
<15> Jul  24 10:44:16 MaZhorWork fmod_test.exe This is a debug severity record
<14> Jul  24 10:44:16 MaZhorWork fmod_test.exe This is a info severity record
<12> Jul  24 10:44:17 MaZhorWork fmod_test.exe This is a warning severity record
<11> Jul  24 10:44:17 MaZhorWork fmod_test.exe This is a error severity record
<10> Jul  24 10:44:17 MaZhorWork fmod_test.exe This is a critical severity record

P.S.2. In my opinion problem is in $(BOOST_ROOT_55)\libs\log\src\init_from_settings.cpp, line 453:

	// For now we use only the default level mapping. Will add support for configuration later.
	backend->set_severity_mapper(sinks::syslog::direct_severity_mapping< >(log::aux::default_attribute_names::severity()));

My code that I tried

//Here we define our application severity levels.
typedef enum TSysLogSeverity
{
	slEmergency = boost::log::sinks::syslog::emergency,                
	slAlert = boost::log::sinks::syslog::alert,                    
	slCritical = boost::log::sinks::syslog::critical,                 
	slError = boost::log::sinks::syslog::error,                    
	slWarning = boost::log::sinks::syslog::warning,                  
	slNotice = boost::log::sinks::syslog::notice,                   
	slInfo = boost::log::sinks::syslog::info,                     
	slDebug = boost::log::sinks::syslog::debug                     
};

// The operator is used for regular stream formatting
std::ostream& operator<< (std::ostream& strm, TSysLogSeverity level)
{
	static const char* strings[] =
	{
		"EMERGENCY",
		"ALERT",
		"CRITICAL",
		"ERROR",
		"WARNING",
		"NOTICE",
		"INFO",
		"DEBUG"
	};

	if (static_cast< std::size_t >(level) < sizeof(strings) / sizeof(*strings))
		strm << strings[level];
	else
		strm << level;

	return strm;
}

std::istream& operator>>(std::istream& i, TSysLogSeverity &level) {
	std::string s_tmp;
	i >> s_tmp;

	static const char* strings[] =
	{
		"EMERGENCY",
		"ALERT",
		"CRITICAL",
		"ERROR",
		"WARNING",
		"NOTICE",
		"INFO",
		"DEBUG"
	};

	bool bFound = false;
	const std::size_t i_array_size = sizeof(strings) / sizeof(*strings);
	for (int k = 0; k < i_array_size ; k++)
	{
		if (s_tmp == std::string(strings[k]))
		{
			level = TSysLogSeverity(k);
			bFound = true;
			break;
		}
	}

	if (!bFound)
	{
		level = TSysLogSeverity(std::stoul(s_tmp));
	}

	return i;
}

// Attribute value tag type
struct severity_tag;

// The operator is used when putting the severity level to log
boost::log::formatting_ostream& operator<<
	(
	boost::log::formatting_ostream& strm,
	boost::log::to_log_manip< TSysLogSeverity, severity_tag > const& manip
	)
{
	static const char* strings[] =
	{
		"EMERGENCY",
		"ALERT",
		"CRITICAL",
		"ERROR",
		"WARNING",
		"NOTICE",
		"INFO",
		"DEBUG"
	};

	TSysLogSeverity level = manip.get();
	if (static_cast< std::size_t >(level) < sizeof(strings) / sizeof(*strings))
		strm << strings[level];
	else
		strm << static_cast< int >(level);

	return strm;
}

//  Global logger declaration
BOOST_LOG_INLINE_GLOBAL_LOGGER_DEFAULT(test_lg, src::severity_logger_mt<TSysLogSeverity>)

void try_logging()
{
	

	src::severity_logger_mt<TSysLogSeverity>& lg = test_lg::get();
	BOOST_LOG_SEV(lg, slDebug) << "This is a debug severity record";
	BOOST_LOG_SEV(lg, slInfo) << "This is a info severity record";
	BOOST_LOG_SEV(lg, slWarning) << "This is a warning severity record";
	BOOST_LOG_SEV(lg, slError) << "This is a error severity record";
	BOOST_LOG_SEV(lg, slCritical) << "This is a critical severity record";

	
}

int _tmain(int argc, _TCHAR* argv[])
{
	try
	{
		
		boost::filesystem::path p(argv[0]);
		p = p.replace_extension(".ini");
		
		// Open the file
		std::ifstream settings(p.string());
		if (!settings.is_open())
		{
			throw std::runtime_error("Could not open <" + p.string() + "> file");
		}

		boost::log::register_simple_formatter_factory<TSysLogSeverity, char >(boost::log::aux::default_attribute_names::severity());
  		boost::log::register_simple_filter_factory<TSysLogSeverity>(boost::log::aux::default_attribute_names::severity());

		// Read the settings and initialize logging library
		logging::init_from_stream(settings);

		src::severity_logger_mt<TSysLogSeverity>& lg = test_lg::get();

 		// Add some attributes
 		logging::add_common_attributes();

		// Try logging
		try_logging();

	}
	catch (std::exception& e)
	{
		std::cout << "FAILURE: " << e.what() << std::endl;
	}

	_getch();
	return 0;
}

comment:3 by Andrey Semashev, 8 years ago

Resolution: fixed
Status: newclosed

This is a known limitation. The library needs a severity mapping to convert from your enum to syslog::level values. When the library is initialized from file or settings it does not know about your enum and currently assumes the severity attribute values to be ints. When you pass your enum as the severity levels the library is not able to extract it from log records and defaults to the 'info' level.

To work around the problem you'll have to create the sink yourself and specify the mapping of your enum to syslog severity levels (see the example). In order to integrate with the settings parser, your code that creates the sink has to be registered as a sink factory as described here.

comment:4 by alexander.zhornyak@…, 8 years ago

Thank you for your answer. But there is a question why you can not put enum severity value directly to Pri without mapping, simply converting to int? If it is possible, it would be greate to have such flag at syslog backend as "direct to int" mapping.

comment:5 by Andrey Semashev, 8 years ago

You cannot extract an attribute value from a log record without knowing its type. Since the library is compiled separately, it has no knowledge of your enum and cannot extract it from log records. That's the same reason why you have to register filters and formatters before parsing.

Note: See TracTickets for help on using tickets.