Dump分析系列-2:一个dump引发的Qt Webkit分析-续
起因
周五下午接到测试发来的一个dump,说发现WebKit还有崩溃,上次的崩溃已经解决了,猜测另有原因,于是,周六下午在家花了些时间分析,为强调并发和工程规范,遂记录于此文。
分析
Windbg打开dump,输入.excr直接切换到发生异常的上下文。(这里多说一句,桌面抓dump是在异常线程调用dbghelp!MiniDumpWriteDump抓的,这样直接栈回溯往往会有问题,因为MiniDumpWriteDump内部在调用GetThreadContext获取线程的上文和写Dump数据是在同一线程,那么写Dump数据读取内存时当前的上下文已经变了,获取内存数据必然有问题,而breakpad能很好工作(方式1、进程内创建线程调用MiniDumpWriteDump。方式2进程外调用MiniDumpWriteDump),关于breakpad的具体实现以后有机会再细聊. 因此要输入.excr命令直接切换到异常位置.)
进入正题,异常时栈回溯如下:
挂在了ntdll!RtlpWaitOnCriticalSection,这是系统的等待临界区的函数,EnterCriticalSection的内部实现。该指令访问了非法地址[eax+14h],此时eax是0x62e,很明显eax应该是个正确的内存地址(最低是64K(0x10000)开始),为什么变成了0x62e?
带着这个问题,反汇编分析看看eax到底是什么。
eax是esi带来的,追溯esi,如图:
esi是第一个参数,这个参数其实就是CRITICAL_SECTION(怎么知道的,简单反汇编看看就知道了,不是本文重点,不在此细说),esi的值是07e42db8,输入命令:kb,也可以论证这点。
接着看,输入命令:dt ntdll!_RTL_CRITICAL_SECTION @esi (用!cs 命令是一样的),查看临界区的结构。
上面的有用的两条指令解释如下:
mov eax, [esi] ;得到DebugInfo
inc [eax+14h] ;得到ContentionCount,(下图可知偏移0x14)
备注:ContentionCount是临界区的竞争计数器,只要调用了EnterCriticalSection就会加1。
总结下来上面的DebugInfo指针有问题,注意观察0x62e就是这样来的。说明临界区被破坏了,来看看临界区的内存:
内容确实变了,!address得知这段内存堆分配的。
查看HEAP_ENTRY,然而这里用!heap –x 得到的是错误结果,windbg插件的bug吧,如下图:
已知所在堆地址0xbb0000,输入!heap –a 0xbb0000,列出这个堆的所有segment和HEAP_ENTRY手动查找(当然也可以写个脚本),太多了,只截了需要的。
很明显这里的大小是4K,也说明上面得到了错误结果,到这里可以得出下面的结论:
1、 堆块被意外修改了?(观察临近的数据可知这种可能性很低)。
2、 这是一块新的堆块,之前的被释放了。
带着上面的问题,开始分析WebKit源码,
在线程结束时,调用了removeAllIconsOnThread,并执行sqlite查询,清理所有的图标记录,查看Qt5WebKit!sqlite3Prepare16的源码,可知db->mutex在windows上是靠CRITICAL_SCTION实现的,因为sqlite3是可跨平台,有对应的unix/linux等版本,比如采用pthread_mutex_t互斥体。
什么时候mutex会被释放?其实观察结构也知道sqlite3本身可想象成一个实例,若mutex被释放应该是关闭db的时候,代码也论证这一点:
int sqlite3_close(sqlite3 *db) => sqlite3_mutex_free(db->mutex)
那什么时候调用sqlite3_close,查看源码可知:
为节约篇幅,我不再多讲源码分析的细节,直接讲重点和结论:
IconDatabase::open会创建iconDatabaseSyncThreadStart线程,该线程会调用m_syncDB.open(m_completeDatabasePath),
好,看到这里,其实感觉这里面的并发实现并不够优雅,锁的粒度低,且有些散乱,如果同一个IconBase实例两次open可能就会导致前一次的db被close掉,打开的是新的db,而且这个db是指针传递到sqlite3里面的,上层代码根本无法改变已有的事实,那么db和db->mutex都是free后的内存(也可能堆块又被重新合并用于其它),感觉分析好像挺吻合的,再来求证看看呢。
果然发现了44号线程正在操作db,并等待(45号线程)另一个锁(Webkit的操作db的),MutexLocker databaseLock(m_database.databaseMutex())。
由此可知,45号线程打开的db被44号close掉了,并且重新创建了一个新的db,45号操作老的db还没完成,此时使用db->mutex就挂了。
下图就是能够调用到IconDatabase::open的Qt API(其中class IconDatabase : public IconDatabaseBase)
发现桌面项目在webview初始化时,会设置IconDatabase的路径,如图所示:
在设置前会判断是否已经设置过,如果为空才设置,但是如果iconDatabasePath获取的是空,就会多次调用setIconDatabasePath函数,这个函数会调用open,而open函数是在另外一个线程实现的,并且两个线程间没做同步,即不能保证调用setIconDatabasePath后,iconDatabasePath一定有值(其实这里事先我还有所怀疑,因为Qt5的窗口基本上单线程的消息机制,应该不会出现多个线程同时调用IconDatabase::open,但是看了其实现就很确定这里确实存在问题)。
当获取iconDatabasePath时,必须是db已经启用且打开,iconDatabase()是个单例。如下图所示:
IsOpen也需是调用了open之后才会设置。
那么可以推断问题场景:
cur_path = web_set->iconDatabasePath(); //第2+次可能获取为空
if (cur_path.isEmpty())
{
web_set->setIconDatabasePath(path); //调用了2+次,引发潜在bug。
}
好,走到这里,所有过程已分析清楚,总结下来其实是个潜在bug,概率不算高,但是想想测试环境都复现了,那已经算严重bug了。
解决
XXEnableLocalStorage函数增加static变量(iconDataBase是单例),用于标识setIconDatabasePath的设置状态,避免设置多次。
后话
说说工程规范问题:
Debug版本本来是用于测试,里面会有很多assert断言,尤其是一些库里面会大量使用,比如Qt。
Release版本是用于对外发布的,可能会规避掉很多问题,比如上面的问题。
其实在Qt的IconBase里有很多ASSERT,如果我们用Debug版调试,ASSERT_ICON_SYNC_THREAD宏就会捕获到当前线程和m_syncThread不等,出现了并发问题,那么这个bug就会尽早暴露出来。
桌面之前工程不规范,没用Debug版调试(因为会莫名崩溃),我解决了先前的一些问题,所以一定要遵守这个规范。总之一点:是问题都应该被解决。