The ALog logging system was originally developed for use in server applications. The first implementation of ALog was performed in 2013, at that time I could not even think that after seven years I would write an article about it on Habr. But, apparently, all by chance ... Now I don’t even remember what I was looking for on the Internet, when I came across the article Comparison of logging libraries . I decided to skim through it for informational purposes. As I got acquainted with the material, the thought arose in my head: "Where is my logger in this 'table of ranks' ?" To find out, a small project LoggerTest was created to test logging systems.
Asynchronous logger
Before moving on to the tests, I need to say a few words about ALog 1 . It is an asynchronous logging system designed for use in highly loaded multithreaded applications. As a rule, such applications run on server stations, which determines the specifics of the logger itself. By and large, there are two features:
The logger has no memory limit (usually servers do not run out of RAM) 2
The cost of calling a logger in worker threads should be minimal. This characteristic is important for any program, but for a server one - especially where the cost of processor resources can be quite high.
[ 1 ] ALog is not a standalone library, it is just a few modules in a general purpose library.
[2] ALog , ARM- .
Spdlog. :
Spdlog - ;
( , );
, P7 , .
::
G3log . , . P7. P7, .
ALog -. ALog , . .
Spdlog G3log , - ALog, .
P7 , ALog, - . . P7 , .
-:
ALog -----------------------------------------------------
15.10.2020 19:39:23.981457 DEBUG2 LWP18876 [alog_test.cpp:35 LoggerTest]
Spdlog ---------------------------------------------------
[2020-10-15 20:22:55.165] [trace] LWP19519 [spdlog_test.cpp:76 LoggerTest]
G3log -----------------------------------------------------
2020/10/15 20:24:48 836329 DEBUG [g3log_test.cpp->thread_func:36]
OS: Ubuntu 20.04
Compiler: GCC 8.4.0 C++14
CPU: Intel Core i7 2700K, 4 , 8 (4.5GHz, )
RAM: 32Gb (DDR3-1600, XMP 8-8-8-24-2N)
SSD: Samsung 860 Pro 512Gb3
: 5
: 5 000 000
[3] : HDD (TOSHIBA HDWD120) SSD.
. , . - . , . , , .
:
Logging time - , ;
Flush time - , ( , Logging time).
:
Memory usage (max/average) - ( );
CPU usage (max/average) - . 100% ( ).
:
P7 1 (/P7.Pool=1048576). P7 , - ;
Spdlog 3 . . Logging time.
async_overflow_policy::block
, "" .
4 ( : release, -O2)
|
|
ALog |
G3log |
P7 |
Spdlog |
|---|---|---|---|---|
Logging time (sec) |
1.325060 |
2.91048 |
4.27096 |
2.489934 |
Flush time (sec) |
3.051857 |
23.1829 |
4.66385 |
2.489951 |
Logging per/sec |
3788071 |
1720496 |
1170852 |
2008105 |
Flush per/sec |
1638855 |
215697 |
1072226 |
2008092 |
Memory usage (max, MB) |
1468 |
2343 |
86 |
1170 |
Memory usage (avg, MB) |
1302 |
2310 |
85 |
1095 |
CPU usage (max, %) |
106 |
87 |
57 |
100 |
CPU usage (avg, %) |
39 |
18 |
37 |
67 |
Flush time ALog Spdlog. , Flush time Spdlog - . : , 3 * 10^6. " " , Spdlog, . Spdlog 1170 . , .
4 ( : debug, -O0)
|
|
ALog |
G3log |
P7 |
Spdlog |
|---|---|---|---|---|
Logging time (sec) |
3.080949 |
5.59882 |
4.69356 |
7.591786 |
Flush time (sec) |
4.717017 |
38.5406 |
5.05907 |
7.591814 |
Logging per/sec |
1625193 |
893396 |
1065342 |
658611 |
Flush per/sec |
1060223 |
129736 |
988428 |
658609 |
Memory usage (max, MB) |
1241 |
1840 |
57 |
1170 |
Memory usage (avg, MB) |
1071 |
1811 |
56 |
1130 |
CPU usage (max, %) |
106 |
100 |
58 |
118 |
CPU usage (avg, %) |
44 |
21 |
36 |
73 |
debug- . , , ( ), . , , Linux.
1 ( : release, -O2)
|
|
ALog |
G3log |
P7 |
Spdlog |
|---|---|---|---|---|
Logging time (sec) |
3.936475 |
8.43987 |
1.93741 |
3.090048 |
Flush time (sec) |
4.029064 |
22.5557 |
2.32743 |
3.090063 |
Logging per/sec |
1270377 |
596768 |
2580784 |
1618186 |
Flush per/sec |
1241177 |
221687 |
2148340 |
1618178 |
Memory usage (max, MB) |
84 |
1353 |
53 |
392 |
Memory usage (avg, MB) |
55 |
1350 |
52 |
383 |
CPU usage (max, %) |
50 |
64 |
21 |
64 |
CPU usage (avg, %) |
25 |
21 |
11 |
44 |
P7 -. 5 . ~1.9 ! .
ALog Spdlog Logging time. Valgrind "", std::vsnprintf(). ++17 std::vsnprintf(). Spdlog , (~0.15 ). ALog : 44 , 33%.
Spdlog 1 . , 1170 392 . Logging time. : Spdlog ++17 ( 0.1 ) Logging time, .
, . ALog , , Logging time - .
?! , , . : , , - . , , ALog. .
: , . , LoggerDemo . :
Demo 01: "Hello world";
Demo 02: ;
Demo 03: ;
Demo 04: - , -;
Demo 05: - -4;
Demo 06: log_format ( )
QtCreator 4.12 . QBS.
: Windows , , .
: ALog - , SharedTools. :
ALog - 5:
logger - ;
config - ;
format - .
ALog SharedTools. , SharedTools.
[4] Demo 5 Qt-framework.
[5] cpp/h , h-.
,
, ( -), . , , (), . .
.
. , , , . , "" . "" :
void prog_abort()
{
log_error << "Program aborted";
alog::logger().flush();
alog::logger().waitingFlush();
alog::logger().stop();
abort();
}
(sink)
(sink): ALog Saver (: , : / ). .
, stdout. -, syslog. , , syslog , .
: ALog : <<
. , , , , .
, . , : , . - saver- .
: , . -, .
TaskLog
.
struct TaskLog
{
int taskId;
int userId;
string status;
};
6.
namespace alog {
Line& operator<< (Line& line, const TaskLog& tl)
{
if (line.toLogger())
line << "TaskId: " << tl.taskId
<< "; UserId: " << tl.userId
<< "; Status: " << tl.success;
return line;
}
} // namespace alog
saver-a . , saver . :
TaskLog tl {10, 20, "success"};
log_info << "Task complete. " << tl;
- : 15.10.2020 19:39:23 INFO LWP18876 [example.cpp:35] Task complete. TaskId: 10; UserId: 20; Status: success
: TASK_ID, USER_ID, STATUS
. , saver-a , .
, : - . "" - . ALog - alog::Line
:
{ //Block for alog::Line
alog::Line logLine = log_verbose << "Threshold ";
if (threshold > 0.5)
logLine << "exceeded";
else
logLine << "is normal";
logLine << " (current value: " << threshold << ")";
}
. <<
. TaskLog
:
TaskLog tl {10, 20, "success"};
log_info << log_format("Task complete. %?", tl);
:
log_info << "Task complete." << log_format(" %?", tl);
[6] () .
ALog : , . , .
stdout :
alog::logger().addSaverStdOut(alog::Level::Info);
:
const char* saverName = "default";
const char* filePath = "/tmp/logger-demo.log";
alog::Level logLevel = alog::Level::Debug;
bool logContinue = true;
{ //Block for SaverPtr
SaverPtr saver {new SaverFile(saverName, filePath, logLevel, logContinue)};
logger().addSaver(saver);
}
. , , , . . yaml-. ALog yaml-cpp.
:
### YAML syntax ###
#
logger:
# . : error, warning, info,
# verbose, debug, debug2. info
level: verbose
# log- .
# (: true/false). 'false', log-
# ,
#
continue: true
#
file: /var/opt/application/log/application.log
# Windows
file_win: ProgramData/application/log/application.log
#
conf: /etc/application/application.logger.conf
# Windows
conf_win: ProgramData/application/config/application.logger.conf
filters:
#
- name: default
type: module_name
mode: exclude
modules: [
VideoCap,
VideoJitter,
]
saver 7, /var/opt/application/log/application.log
. logger.conf
logger.filters
, .
Demo 05 saver . , :
// -
std::time_t configBaseModify = 0;
// -
std::time_t configLoggerModify = 0;
void init()
{
//
configBaseModify = config::baseModifyTime();
configLoggerModify = config::loggerModifyTime();
}
// -
void configModifyTimer()
{
bool modify = false;
std::time_t configModify = config::baseModifyTime();
if (configBaseModify != configModify)
{
modify = true;
configBaseModify = configModify;
config::base().rereadFile();
log_verbose << "Config file was reread: " << config::base().filePath();
alog::configDefaultSaver();
}
configModify = config::loggerModifyTime();
if (configLoggerModify != configModify)
{
modify = true;
configLoggerModify = configModify;
alog::configExtensionSavers();
}
if (modify)
alog::printSaversInfo();
}
[7] saver-a 'default'
ALog 1 , . Debug2
( ). , 1 . -. saver-a .
alog::logger()
, .
, . , , . , , , .
ALog, , . :
enum Level {None = 0, Error = 1, Warning = 2, Info = 3, Verbose = 4, Debug = 5, Debug2 = 6};
Debug2
- , .
, . , ALog , - , saver-. saver-, . , , , .
, . - , . , . :
, , ;
.1 . , . , ;
(. .1). - , - ;
- , , -.
: " ". , P7 - . - , .
: " , - ". , , , . , , . -? :
, . ;
, , - .
ALog , . - , . , , -.
- - . , , . - .
.
, saver-, . , , . () :
|
|
|---|---|
module_name |
|
log_level |
( ) |
func_name |
( , ) |
file_name:line |
(: ) |
thread_id |
|
content |
|
. " ", …
alog::logger().debug(alog_line_location, "Module1") << "Message";
- .
//
#define log_error_m alog::logger().error (alog_line_location, "Module1")
#define log_warn_m alog::logger().warn (alog_line_location, "Module1")
#define log_info_m alog::logger().info (alog_line_location, "Module1")
#define log_verbose_m alog::logger().verbose (alog_line_location, "Module1")
#define log_debug_m alog::logger().debug (alog_line_location, "Module1")
#define log_debug2_m alog::logger().debug2 (alog_line_location, "Module1")
...
void moduleFunc1()
{
for (int i = 0; i < 10; ++i)
{
log_debug_m << "Func1. Message " << i;
usleep(10);
}
}
...
//
#undef log_error_m
#undef log_warn_m
#undef log_info_m
#undef log_verbose_m
#undef log_debug_m
#undef log_debug2_m
cpp- #undef
, . - .
, . Linux UTF-8. QString , UTF-16 UTF-8. .
ALog -, logrotate.
ALog, . , - ALog .
:
if (alog::logger().level() == alog::Level::Debug2)
{
log_debug2_m << "Message was sent to socket"
<< ". Id: " << message->id()
<< ". Command: " << CommandNameLog(message->command())
<< ". Type: " << message->type()
<< ". ExecStatus: " << message->execStatus();
}
. , . , . :
log_debug2_m << "Message was sent to socket";
std::string s = ".../python/example1.py";
const char* file = alog::__file__cache(s);
alog::logger().info(file, 0, 10, "Python") << "Message from python-script";
ALog __FILE__
, . : . , __FILE__
. ( ) ( ) . , ALog. alog::__file__cache()
, , .
. , - . 8. , , , , .
logmvnc()
Intel Movidius Neural Compute Stick:
void logmvnc(enum mvLog_t level, const char* file, int line, const char* func,
const char* format, ...) asm ("logmvnc");
void logmvnc(enum mvLog_t level, const char* file, int line, const char* func,
const char* format, ...)
{
va_list args;
va_start(args, format);
int len;
char buff[1024] = {0};
auto removeLastN = [&len, &buff]()
{
if ((len < int(sizeof(buff))) && (buff[len - 1] == '\n'))
buff[len - 1] = '\0';
};
switch (level)
{
case MVLOG_DEBUG:
if (alog::logger().level() == alog::Level::Debug2)
{
len = vsnprintf(buff, sizeof(buff) - 1, format, args);
removeLastN();
alog::logger().debug2(file, func, line, "Movidius") << buff;
}
break;
case MVLOG_WARN:
{
len = vsnprintf(buff, sizeof(buff) - 1, format, args);
removeLastN();
alog::logger().warn(file, func, line, "Movidius") << buff;
}
break;
case MVLOG_ERROR:
case MVLOG_FATAL:
case MVLOG_LAST:
{
len = vsnprintf(buff, sizeof(buff) - 1, format, args);
removeLastN();
alog::logger().error(file, func, line, "Movidius") << buff;
}
break;
default:
{
// LEVEL_INFO
len = vsnprintf(buff, sizeof(buff) - 1, format, args);
removeLastN();
alog::logger().info(file, func, line, "Movidius") << buff;
}
}
va_end(args);
}
[8] .
, , ALog , . . , , . - , - . : LoggerTest LoggerDemo. , - - , , . . LoggerTest - , , , - .