一. 问题描述
前面写过一篇关于打印日志时,日志内容中包含float数据就会崩溃的文章R6002 floating point support not loaded,今天又遇到了打印日志崩溃的情况,定位到这次还是崩溃在StringCchVPrintfA这个函数。这是个系统API的崩溃,遇到系统API的崩溃当然是先排查调用方式是否有问题,然后排查参数数据是否有问题,最后才排查API是否有BUG。
二. 问题分析
这个API很熟悉,通过可变参数格式化字符串的API,函数原型如下:
HRESULT StringCchVPrintf(
_Out_ LPTSTR pszDest,
_In_ size_t cchDest,
_In_ LPCTSTR pszFormat,
_In_ va_list argList
);
确定调用方式没问题之后,分析传入的参数数据是否有问题。
首先怀疑的是pszDest,cchDest参数是否传错了,导致访问了非法的内存区域,仔细核对之后也没有传错,缓冲区够用呢。
argList参数的用法也没啥问题,一直这么使用的。
最后只剩下pszFormat参数了,打印其值如下:select * from netbar_member where memberName like '滭jj';
看到这个包含乱码的串,心里基本确定问题就出在pszFormat上面了。
打印日志的代码简化后如下:
std::string strName = "sjj";
TraceMsg("select * from netbar_member where memberName like '%%%s%%';", strName.c_str());
一个简单的模糊查询SQL,本想打印如下输出:
select * from netbar_member where memberName like '%sjj%';
对比%%%s%%
和滭jj
,发现本该存在的前后2个%不见了,sjj中的s也不见了。该日志对比其他日志,特殊之处在于输出了%号,刚好%s又是可以输出地址空间内容的。猜测是输出%时转义引起的,导致%s输出了其他地址空间的内容,运气好能输出乱码,运气不好直接非法访问,程序崩溃。
TraceMsg函数调用伪代码:
TraceMsg(const char* lpFormat, ...);
|
|
\ /
Log_Message(const char* lpFormat, ...);
|
|
\ /
LogToFile(const char* lpFormat, ....);
一条日志经过了3次格式化,虽然性能不高,但问题也不大,不至于乱码和崩溃。
分析函数调用的参数,参数数据如下:
TraceMsg("select * from netbar_member where memberName like '%%%s%%';", "sjj");
|
|
\ /
Log_Message("select * from netbar_member where memberName like '%sjj%';");
|
|
\ /
LogToFile("select * from netbar_member where memberName like '滭jj';");
看到这里终于明白了,TraceMsg传递给Log_Message函数的lpFormat参数为:select * from netbar_member where memberName like '%sjj%';
,这个memberName比较特殊,刚好ssj中的s和%组合成了一个有效的%s。
由于调用Log_Message时未给...
可变参数传值,默认会根据lpFormat参数的地址来取一个地址让%s进行输出。具体计算方式参考va_start
宏定义:
#define va_start _crt_va_start
#define _crt_va_start(ap,v) ( ap = (va_list)_ADDRESSOF(v) + _INTSIZEOF(v) )
这个地址的内容是未知的,所以就可能出现乱码或崩溃。
三. 解决方案
仔细想想,发现问题其实出在函数Log_Message把select * from netbar_member where memberName like '%sjj%'
作为了StringCchVPrintfA
函数的pszFormat
参数。
其实程序想要的是原样输出该串,%sjj%
中的%和s只是碰巧在一起了,再次充当了%s的角色。
原样输出还不简单:Log_Message("%s", "select * from netbar_member where memberName like '%sjj%';");
这样不就OK了么,哈哈。
四. 验证
为了验证这个问题,写了一个小程序,多次嵌套格式化字符串。在DbgView中,可以看到输出的内容不是预期的:select * from netbar_member where memberName like '%sjj%';
。
#include <windows.h>
#include <tchar.h>
#include <strsafe.h>
#include <string>
void TraceMsg1(const char *lpFormat, ...);
void TraceMsg2(const char *lpFormat, ...);
void TraceMsg3(const char *lpFormat, ...);
void TraceMsg1(const char *lpFormat, ...) {
if (!lpFormat)
return;
OutputDebugStringA(lpFormat);
OutputDebugStringA("\n");
char pMsgBuffer[512] = { 0 };
va_list arglist;
va_start(arglist, lpFormat);
StringCchVPrintfA(pMsgBuffer, 512, lpFormat, arglist);
va_end(arglist);
TraceMsg2(pMsgBuffer); // 改成这样程序正常:TraceMsg2("%s", pMsgBuffer);
}
void TraceMsg2(const char *lpFormat, ...) {
if (!lpFormat)
return;
OutputDebugStringA(lpFormat);
OutputDebugStringA("\n");
char pMsgBuffer[512] = { 0 };
va_list arglist;
va_start(arglist, lpFormat);
StringCchVPrintfA(pMsgBuffer, 512, lpFormat, arglist);
va_end(arglist);
TraceMsg3(pMsgBuffer); // 改成这样程序正常:TraceMsg3("%s", pMsgBuffer);
}
void TraceMsg3(const char *lpFormat, ...) {
if (!lpFormat)
return;
OutputDebugStringA(lpFormat);
OutputDebugStringA("\n");
char pMsgBuffer[512] = { 0 };
va_list arglist;
va_start(arglist, lpFormat);
StringCchVPrintfA(pMsgBuffer, 512, lpFormat, arglist);
va_end(arglist);
OutputDebugStringA(pMsgBuffer);
}
int _tmain(int argc, _TCHAR* argv[])
{
std::string strName = "sjj";
TraceMsg1("select * from netbar_member where memberName like '%%%s%%';", strName.c_str());
getchar();
return 0;
}
五. 总结
在调用StringCchVPrintf、vsprintf、vswprintf、_vstprintf、printf这样的一系列函数输出固定字符串时,一定不要将固定字符串传入到pszFormat参数,如:
StringCchVPrintf(szBuf, 512, "我想输出单纯的%s,我是错误的格式示范"); // 错误的
这个时候,单纯的%s
中的%s
已经不在单纯。
正确的做法是:
StringCchVPrintf(szBuf, 512, "%s", "我想输出单纯的%s,我是正确的格式示范");
同理,这样的调用也是错误的、危险的:
std::string strInfo = GetInfo();
printf(strInfo.c_str());