nonolog起步笔记-3-尝试解析log
- 第一次解析
- sample中的nano二进制log在哪里
- compressedLog
- ./decompressor decompress /tmp/logFile
- compressedLog是什么鬼
- 下断分析
第一次解析
sample中的nano二进制log在哪里
如下图
手工执行的结果如下,不看代码,还真不知道,被放到/tmp/logFile了
root@edit:/data/nano/NanoLog/sample# ./sampleApplication
The total time spent invoking NANO_LOG with no parameters 1000 times took 0.00 seconds (30.89 ns/message average)
Flushing the log statements to disk took an additional 0.02 secs
Wrote 1002 events (0.00 MB) in 0.018 seconds (0.000 seconds spent compressing)
There were 3 file flushes and the final sync time was 0.000005 sec
Compression Thread was active for 0.000 out of 0.017 seconds (1.67 %)
On average, that's
0.19 MB/s or 5338.92 ns/byte w/ processing
0.19 MB/s or 5327.12 ns/byte disk throughput (min)
0.00 MB per flush with 3.3 bytes/event
17775.10 ns/event in total
39.31 ns/event compressing
The compression ratio was 4.82-4.82x (16090 bytes in, 3336 bytes out, 0 pad bytes)
==== NanoLog Configuration ====
StagingBuffer size: 1 MB
Output Buffer size: 67 MB
Release Threshold : 0 MB
Idle Poll Interval: 1 µs
IO Poll Interval : 1 µs
compressedLog
特别是根目录,自动放了一个文件,叫compressedLog
我一直以为是这个文档,解了半天,没解开,看了代码才知道。
我们开始试一下吧:
./decompressor decompress /tmp/logFile
...
2024-12-09 15:10:33.000820122 main.cc:88 NOTICE[0]: Simple log message with 0 parameters
2024-12-09 15:10:33.000820143 main.cc:88 NOTICE[0]: Simple log message with 0 parameters
# Decompression Complete after printing 1002 log messages
root@edit:/data/nano/NanoLog/sample# ./decompressor decompress /tmp/logFile
好的,这样就得到我们想要的效果。
compressedLog是什么鬼
即然我们看到了,不如来研究一下,为什么会生成这样的一空文件
在代码中找compressedLog,
然后找DEFAULT_LOG_FILE,很快就定位了这个位置:
下断分析
注意,这里的断点,很可能不停,如果出现在这样的情况,一定要手工重编runtime目录的内容,直到./sample/libNanoLog.a 与runtime下的md5相同了。当然,注意两边都要改为O0。
然后我们将call stack向上一级,就能看到:
原因在这里:
这里定义了一个全局变量,所以,在main进入前,就在磁盘上生成了这个空文件。
RuntimeLogger RuntimeLogger::nanoLogSingleton;
这里是可以考虑改进一下。
我稍解释一下,为什么这个问题,有点困难:
因为google的nanolog,作者希望,这个nanolog体系,用户是不需要显示初始化的。
所以,服务端的服务线程,在Runtimelogger的构造函数就已经创建。
创建的时候,就意味着,需要可以操作异步IO,这里是必须有句柄的。
而sample示例中的setlogFile,要晚一会对能登场,因为那是在main()进入后的事了。
我们来看一下相关的代码:
setlogFile最后会走到这里:
然后,会重启server端服务线程!先关闭,然后启动。
// Documentation in NanoLog.h
void
RuntimeLogger::setLogFile_internal(const char *filename) {
// Check if it exists and is readable/writeable
if (access(filename, F_OK) == 0 && access(filename, R_OK | W_OK) != 0) {
std::string err = "Unable to read/write from new log file: ";
err.append(filename);
throw std::ios_base::failure(err);
}
// Try to open the file
int newFd = open(filename, NanoLogConfig::FILE_PARAMS, 0666);
if (newFd < 0) {
std::string err = "Unable to open file new log file: '";
err.append(filename);
err.append("': ");
err.append(strerror(errno));
throw std::ios_base::failure(err);
}
// Everything seems okay, stop the background thread and change files
sync();
// Stop the compression thread completely
{
std::lock_guard<std::mutex> lock(nanoLogSingleton.condMutex);
compressionThreadShouldExit = true;
workAdded.notify_all();
}
if (compressionThread.joinable())
compressionThread.join();
if (outputFd > 0)
close(outputFd);
outputFd = newFd;
// Relaunch thread
nextInvocationIndexToBePersisted = 0; // Reset the dictionary
compressionThreadShouldExit = false;
#ifndef BENCHMARK_DISCARD_ENTRIES_AT_STAGINGBUFFER
compressionThread = std::thread(&RuntimeLogger::compressionThreadMain, this);
#endif
}
所以,如果稳妥一点的做法,
是自己写一个初始化函数,我们的项目中就是这样做的。
注释掉构造函数中的线程启动这一句,
只在setlogfile中启动。