调查一起msi安装CPU hog issue

在一台机器上安装阳光宝盒时，总是会出现CPU占用太高，软件安装费时较长的问题。这台机器是win7，64位系统。阳光宝盒-天涯助手｜搜狐助手是用.Net开发的，安装程序使用vs2008制作，主要自定义动作仅包含注册BHO类。

第一步，打开windows installer服务的日志。通过start>run>gpedit.msc打开组策略编辑器，打开日志功能：

注意这个选项进入的路径是管理模板>windows组件。日志将保存在%temp%目录下，文件名以msi开头，扩展名为.log。

重新运行安装，得到下面的日志：

  
=== 记录开始: 2012/2/12  12:34:21 ===
操作 12:34:21: INSTALL.
操作开始 12:34:21: INSTALL。
操作 12:34:21: DIRCA_CheckFX.
操作开始 12:34:21: DIRCA_CheckFX。
。。。省略部分日志
操作 12:35:38: ExecuteAction.
操作开始 12:35:38: ExecuteAction。
操作 12:37:33: INSTALL.
操作开始 12:37:33: INSTALL。
操作 12:37:33: DIRCA_CheckFX.
操作开始 12:37:33: DIRCA_CheckFX。
INFO   : [02/12/2012 12:37:33:429] [CheckFX                                 ]: Custom Action is starting...
INFO   : [02/12/2012 12:37:33:430] [CheckFX                                 ]: CoInitializeEx - COM initialization Apartment Threaded...
INFO   : [02/12/2012 12:37:33:443] [CheckFX                                 ]: MsiGetPropertyW - Determine size of property 'VSDFrameworkVersion'

用时最长的一段是第7行：操作开始 12:35:38: ExecuteAction。也就是自定义动作开始，然后真正进入自定义动作时是2分钟以后，第13行： INFO : [02/12/2012 12:37:33:429] [CheckFX ]: Custom Action is starting… 有意思的是，耗时最长的这一段究竟在干什么，日志并没有记录。不过也有所收获，那就是，似乎安装程序本身并没有太多错误。仔细观察，这段期间出现了high CPU现象。对付这种问题，最好的办法就是使用process explorer，在high CPU时，它可以让我们看清当前操作停留在哪一步：

定位图中红框框住的线程，点击stack按钮，process explorer会提示当前线程的call stack给我们。可以看到，大部分函数在spp.dll模块以内。这个模块是win7下的系统安全保护模块，它和vss一起执行系统文件备份操作。

尽管不了解spp.dll究竟在做什么，但是这里似乎有了一点线索。再次查看系统日志：

发现在每次安装后不久，总会看到这个事件发生。因此，可以设想，我们的安装触发了系统还原。接下来关掉系统还原再次测试，安装迅速完成，证明了前面的猜想。

我对vss服务的性能印象中没有那么糟。这大概是个特例，应该是该机器上系统安装的某些问题引起的。