Nanolog起步笔记-10-log解压过程4寻找meta续2
- 写在前面
- 重新开始trace
- readDictionaryFragment
- 读取meta头部
- 读入每个记录
- createMicroCode
- 读入头部,和文件名
- 切分format字符串
- PrintFragment
- 后记
写在前面
前面的工作,已做打下令人有信心的基础。
重新开始trace
之前我们起步就看到了 metadata ,显然这前就已加载了。
所以,只需要重走一遍代码,就能得到了。
目前的代码相当简练。走过几步后看到:
显然我们接近了。
这个第一个得到的,就是我们想要的。
先得到类型:
type=73
结转为
struct UnknownHeader {
uint8_t entryType:2;
uint8_t other:6;
};
得到:
LOG_MSGS_OR_DIC = 1,
然后我们详细分析readDictionaryFragment.
readDictionaryFragment
bool
Log::Decoder::readDictionaryFragment(FILE *fd) {
读取meta头部
在这里我们稍作停留:
能够看到一些信息。特别是,DictionaryFragment 的定义
/**
* A DictionaryFragment contains a partial mapping of unique identifiers to
* static log information on disk. Following this structure is one or more
* CompressedLogInfo. The order in which these log infos appear determine
* its unique identifier (i.e. by order of appearance starting at 0).
*/
NANOLOG_PACK_PUSH
struct DictionaryFragment {
// Byte representation of an EntryType::LOG_MSG_OR_DIC to indicate
// the start of a dictionary fragment.
uint32_t entryType:2;
// Number of bytes for this fragment (including all CompressedLogInfo)
uint32_t newMetadataBytes:30;
// Total number of FormatMetadata encountered so far in the log
// including this fragment (used as a sanity check only).
uint32_t totalMetadataEntries;
};
NANOLOG_PACK_POP
翻译一下:
DictionaryFragment 包含唯一标识符到磁盘上的静态日志信息的部分映射。此结构后面是一个或多个CompressedLogInfo。
这些日志信息的出现顺序,取决于其唯一标识符(即按从 0开始的出现顺序)。
这是比较容易理解的。因为logid或者fragment_id,就是这个id。也就是我们要找的meta record 的id.
这里得到了上图的信息。
最明显的是:(df).totalMetadataEntries=2
这与预期一致,因为我们的确,只有两次写入log。
读入每个记录
/**
* Stores the static log information associated with a log message on disk.
* Following this structure are the filename and format string.
*/
NANOLOG_PACK_PUSH
struct CompressedLogInfo {
// LogLevel severity of the original log invocation
uint8_t severity;
// File line number in which the original log invocation appeared
uint32_t linenum;
// Length of the filename that is associated with this log invocation
// and follows after this structure.
uint16_t filenameLength;
// Length of the format string that is associated with this log
// invocation and comes after filename.
uint16_t formatStringLength;
};
NANOLOG_PACK_POP
CompressedLogInfo的信息很明确。
首先,它没有数组之类的信息的位置。
其次,4个信息,简单明了:级别;行号,文件名长,format长。
所以,它是每个meta的record的头部。并不是全部的信息。
读入过程如下:
CompressedLogInfo cli;
newBytesRead += fread(&cli, 1, sizeof(CompressedLogInfo), fd);
newBytesRead += fread(filename, 1, cli.filenameLength, fd);
newBytesRead += fread(format, 1, cli.formatStringLength, fd);
然后入队和创建:
fmtId2metadata.push_back(endOfRawMetadata);
fmtId2fmtString.push_back(format);
createMicroCode(&endOfRawMetadata,
format,
filename,
cli.linenum,
cli.severity);
createMicroCode
读入头部,和文件名
跳过头部:*microCode += sizeof(FormatMetadata);
*microCode = stpcpy(*microCode, filename) + 1;
/**
* Describes a unique log message within the user sources. The order in
* which this structure appears in the log file determines the associated
* logId. Following this structure are the source filename and
* PrintFragments required for this message.
*/
NANOLOG_PACK_PUSH
struct FormatMetadata {
// Number of nibbles in the dynamic data stream used to pack() arguments
uint8_t numNibbles;
// Number of PrintFragments following this data structure
uint8_t numPrintFragments;
// Log level of the LOG statement in the original source file
uint8_t logLevel;
// Line number of the LOG statement in the original source file
uint32_t lineNumber;
// Number of bytes in filename[] (including the null character)
uint16_t filenameLength;
// Filename for the original source file containing the LOG statement
char filename[];
};
NANOLOG_PACK_POP
FormatMetadata中的信息,是前面的CompressedLogInfo 超集。因为二者作用域不同。CompressedLogInfo 更加倾向于是序列化之后的域中。
FormatMetadata相当于内存中的数据域。
一般而言元数据在程序中,有三层:最上层的有函数的类级;没有函数,但有指针的内存级;用于存盘的序列化级,最低级,要么没有指针,要么指针是转义的(例如转为相对偏移量,从文件的某个位置,一般是零)。
切分format字符串
看到这个
我们知道要切分字符串了。
首先,定位到下一个’%’
啊,这里感慨一下,连boost中的正则表达式,也成为std的一部分了。
过正则匹配split后,(这里注意google的工程师,手工将字符串定位到指定位置,然后再进行正则匹配,而不是直接用正则表达式进行查找,可见他们对效率的追求达到了极致)。
得到
type=NanoLogInternal::Log::const_char_ptr_t
代码如下,这些代码很繁琐,但实际上,如果写底层工程,复用最多的反而是这些底层代码。
/**
* Parses the <length> and <specifier> components of a printf format sub-string
* according to http://www.cplusplus.com/reference/cstdio/printf/ and returns
* a corresponding FormatType.
*
* \param length
* Length component of the printf format string
* \param specifier
* Specifier component of the printf format string
* @return
* The FormatType corresponding to the length and specifier. A value of
* MAX_FORMAT_TYPE is returned in case of error.
*/
static NanoLogInternal::Log::FormatType
getFormatType(std::string length, char specifier)
{
using namespace NanoLogInternal::Log;
// Signed Integers
if (specifier == 'd' || specifier == 'i') {
if (length.empty())
return int_t;
if (length.size() == 2) {
if (length[0] == 'h') return signed_char_t;
if (length[0] == 'l') return long_long_int_t;
}
switch(length[0]) {
case 'h': return short_int_t;
case 'l': return long_int_t;
case 'j': return intmax_t_t;
case 'z': return size_t_t;
case 't': return ptrdiff_t_t;
default : break;
}
}
// Unsigned integers
if (specifier == 'u' || specifier == 'o'
|| specifier == 'x' || specifier == 'X')
{
if (length.empty())
return unsigned_int_t;
if (length.size() == 2) {
if (length[0] == 'h') return unsigned_char_t;
if (length[0] == 'l') return unsigned_long_long_int_t;
}
switch(length[0]) {
case 'h': return unsigned_short_int_t;
case 'l': return unsigned_long_int_t;
case 'j': return uintmax_t_t;
case 'z': return size_t_t;
case 't': return ptrdiff_t_t;
default : break;
}
}
// Strings
if (specifier == 's') {
if (length.empty()) return const_char_ptr_t;
if (length[0] == 'l') return const_wchar_t_ptr_t;
}
// Pointer
if (specifier == 'p') {
if (length.empty()) return const_void_ptr_t;
}
// Floating points
if (specifier == 'f' || specifier == 'F'
|| specifier == 'e' || specifier == 'E'
|| specifier == 'g' || specifier == 'G'
|| specifier == 'a' || specifier == 'A')
{
if (length.size() == 1 && length[0] == 'L' )
return long_double_t;
else
return double_t;
}
if (specifier == 'c') {
if (length.empty()) return int_t;
if (length[0] == 'l') return wint_t_t;
}
fprintf(stderr, "Attempt to decode format specifier failed: %s%c\r\n",
length.c_str(), specifier);
return MAX_FORMAT_TYPE;
}
从我们看到,其实数据是紧密排列的:
即当前文件名"main.cc"的’\0’之后,紧跟着格式信息。
稍等啊,这里我有些偏离当前正在分析的问题的主题了,基实我要分析的是
然后根据formatString,自动换算出一个唯一标识符,作为CTF meta的event的name.
当然,也不完全偏离,解析数据时,还是要走现在的部分。
PrintFragment
/**
* Describes how to interpret the dynamic log stream and partially
* reconstruct the original log message.
*/
NANOLOG_PACK_PUSH
struct PrintFragment {
// The type of the argument to pull from the dynamic buffer to the
// partial format string (formatFragment)
uint8_t argType:5;
// Indicates that the fragment requires a dynamic width/precision
// argument in addition to one required by the format specifier.
bool hasDynamicWidth:1;
bool hasDynamicPrecision:1;
//TODO(syang0) is this necessary? The format fragment is null-terminated
// Length of the format fragment
uint16_t fragmentLength;
// A fragment of the original LOG statement that contains at most
// one format specifier.
char formatFragment[];
};
NANOLOG_PACK_POP
这里稍作笔记:
((NanoLogInternal::Log::PrintFragment *)0x7fffb70a2021)->fragmentLength=42
这里的42是指从format头到现在的位置。
可以,想象,下一次memory copy就短得多了,因为这次,包括了当前这个%号的所有的format字符串。
本轮最后,更新了父node的信息:
之后是循环遍历完后面的3个%,略。
后记
暂时本系列告一段落的。占用了大概有3天的时间。
后面我需要准备开始转为CTF的meta的工作。
在开始之前,需要先研究一下我们自己的魔改版本的nanolog,具体细节有哪些。
还要看一下业务的代码,哪些位置,是我关注的。
我们做性能分析时,是划格子,涉及到的probe点,不是越多越好,正相反,每个主动对象,我们只需要关注收跳(TTI),和每slot的所有的task的generate,push to Queuq, scheduled, finish。
以及,在processing过程中,被OS重新调度该线程的情况。
后面的工作,许多内容,与本系列关系不太大了。
当然,个人还是有所收获。特别是,以后改为内存形态的log,以及定位当前log在解压时,有错误发生的bug,有了足够的信心和了解。