node js profile

最近的开发遇到了两次性能问题，都是大量访问下的CPU飙升，在这里记录下经验教训。

arm平台下的CPU profile

我们在一个arm平台下开发了一个nodejs程序A,它与设备B进行链接，当同时链接多个B设备且B频繁的发送数据时A机会占满CPU并进入假死状态。 于是我就搜索到了官网的一个guideEasy profiling for Node.js Applications 按照文中的方法顺利找到了性能瓶颈，Data.toLocalString() 花费了太多的CPU时间。我们在打印每行log的时候都加了个时间，而每次的AB间通讯都会打印log， 所以这个获取时间的方法使CPU彪到了100.没想到打印log竟然成为了程序的瓶颈，没有办法，只能忍痛去掉了获取时间，并且去掉了每次通讯的琐碎log。

web服务器在调用登陆时CPU飙升

这次的问题更加诡异，在用ab对web服务器压力测试时。 nodejs进程C占满四核cpu，cpu利用率到了390%。(⊙o⊙)…，简直不敢相信，一个node进程怎么会占满四核cpu呢，说好的单线程呢。 有了之前调试的经验，直接就用 node –prof 来进行cpu profile了。可是通过log分析发现最耗时不过是正常的socket读写操作。 这就奇怪了，怎么会只有十几个并发就把CPu占满了呢。 不死心的我进行了多次测试，发现每次都一样，从log文件里看不到什么异常的操作。无奈之下想到是不是代码中有同步操作，然后用 node --trace-sync-io 来查看一下。 发现还真有一个同步操作，是生产session的时候用到了uuid，这个uuid的产生是同步的。 看到这里我真是欣喜若狂啊，以为终于找到了性能瓶颈。然而当我把uuid的生产设为一个字符串常量后发现CPU依然占慢，看来这个同步操作没什么影响。 最后实在没有办法了就开始一行一行的注释登陆相关代码，看是那行代码导致的CPU飙升。幸好相关代码不是很多，很快找到了是一个加密方法引起的 crypto.pbkdf2。 这个异步的方法竟然可以占满多核cpu且不被 node -prof记录下来，这个可能是 node --prof的一个bug。 说回pbkdf2这个方法，这是一个著名的加密方法可以配置参数iterations，值越大加密结果越安全，相应越耗CPU。所以这个值设置多大要因服务器的计算能力以及对安全和并发数的取舍而定。 最重通过测试我们定在一次加密耗时10ms。修改之后的程序并发数明显上去了，cpu的占用也没那么多了。当然并发大的时候依然会占满CPU。