Sistem pencatatan ALog pada awalnya dikembangkan untuk digunakan dalam aplikasi server. Implementasi ALog pertama kali dilakukan pada tahun 2013, saat itu saya bahkan tidak menyangka setelah tujuh tahun saya akan menulis artikel tentang hal itu di Habr. Tapi, ternyata, semua kebetulan ... Sekarang saya bahkan tidak ingat apa yang saya cari di Internet, ketika saya menemukan artikel Perbandingan perpustakaan logging . Saya memutuskan untuk membacanya untuk tujuan informasional. Ketika saya berkenalan dengan materi tersebut, muncul pikiran di kepala saya: "Di mana logger saya di 'tabel peringkat' ini ?" Untuk mengetahuinya, proyek kecil LoggerTest dibuat untuk menguji sistem logging.
Logger asinkron
, ALog1. , . , , . :
( ) 2
. , - , .
[1] ALog , .
[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 - , , , - .