PhantomJS: 一次程序运行无反应的排查过程

bluewolf 发布于2年前
0 条问题

背景

最近刚接触PhantomJS, 听说这工具是一个基于WebKit的服务器端JavaScript API,可以实现绝大部分浏览器的操作, 迫不及待就想练练手.于是就简单写了一个程序, 简单介绍下:

需求: 通过phantomJS向一个网站发起请求, 并且记录各资源加载的时间,名字
思路:
    1.通过 onResourceRequested,获得资源请求时间t1, 并通过资源ID,记录在关联数组内
    2.通过 onResourceReceived 获得资源响应时间t2, 也同样存到关联数组内
    2.用t2 - t1得出的, 就是资源加载花费的毫秒值
    3.因为资源ID是相关联的,所以只需要取任意一个关联组的url就可以

程序源码

test.js 内容如下:

// 加载库
var page = require('webpage').create();
var system = require('system');
var req = {};  // 请求关联数组
var res = {};  // 响应关联数组
var num = 0;   // 用于记录资源数
var address = 'http://www.yaochufa.com';

// 在 onResourceRequested 事件绑定动作
page.onResourceRequested = function(request){
    num++;   
    req[request.id] = {'url': request.url, 'time': request.time};
};

// 在 onResourceReceived 事件绑定动作
page.onResourceReceived = function(response){
    res[response.id] = {'url': response.url, 'time': response.time};
};


// 开始请求
page.open(address, function(status){
    
    if(status !== 'success')
    {
        // 如果请求成功, 退出
        console.log(status);
        phantom.exit(); 
    }
    else{
        console.log('主页加载完毕');
    }
    // 根据前面记录的资源请求个数, 开始统计各资源的加载时间
    for(i=1;i<=num;i++)
    {
        // 取出请求数组的资源开始时间, 并转换成时间戳
        var req_time = new Date(req[i]['time']).getTime();

        // 取出响应数组的资源结束时间, 并转换成时间戳
        var res_time = new Date(res[i]['time']).getTime();
        
        // 作差就是加载的时间
        var diff = res_time - req_time;
        console.log('ID:s',i, 'Loadtime:', diff, 'ms');

        // 打印对应ID的url
        console.log(res[i]['url']);
    }
    phantom.exit();

});

问题重现

phantomjs test.js

# 结果输出:
ReferenceError: Can't find variable: sfCode

  http://qiniu-cdn7.jinxidao.com/assets/js/index.js?v=201704201643:1
主页加载完毕
ID:s 1 Loadtime: 73 ms
http://www.yaochufa.com/
ID:s 2 Loadtime: 50 ms
http://qiniu-cdn7.jinxidao.com/assets/css/common.css?v=201704201643
ID:s 3 Loadtime: 54 ms
http://qiniu-cdn7.jinxidao.com/assets/css/index.css?v=201704201643
ID:s 4 Loadtime: 80 ms
http://qiniu-cdn7.jinxidao.com/assets/js/jquery.js
ID:s 5 Loadtime: 78 ms
http://qiniu-cdn7.jinxidao.com/assets/js/lazyload.js
ID:s 6 Loadtime: 78 ms
http://qiniu-cdn7.jinxidao.com/assets/js/common.js?v=201704201643
ID:s 7 Loadtime: 150 ms
http://qiniu-cdn7.jinxidao.com/assets/js/index.js?v=201704201643
ID:s 8 Loadtime: 79 ms
http://qiniu-cdn7.jinxidao.com/js/user_analytics_pc.js?v=201704201643
ID:s 9 Loadtime: 154 ms
http://qiniu-cdn7.jinxidao.com/js/zhugeio_config.js?v=201704201643
ID:s 10 Loadtime: 106 ms
http://cdn7.jinxidao.com/images/icon.png?v=1.3
ID:s 11 Loadtime: 104 ms
http://cdn.jinxidao.com/images/icon/photo-app.png
ID:s 12 Loadtime: 100 ms
http://static.anquan.org/static/outer/image/hy_124x47.png
ID:s 13 Loadtime: 91 ms
http://cdn7.jinxidao.com/www/images/loading.gif
ID:s 14 Loadtime: 91 ms
http://cdn7.jinxidao.com/images/logo.png
ID:s 15 Loadtime: 94 ms
http://cdn7.jinxidao.com/www/images/weixin_code.png
ID:s 16 Loadtime: 92 ms
http://cdn7.jinxidao.com/www/images/footer-links.png
ID:s 17 Loadtime: 94 ms
http://cdn7.jinxidao.com/www/images/weixin_code.png?v=1.0
ID:s 18 Loadtime: 91 ms
http://cdn7.jinxidao.com/www/images/web-trust/alipay.png
ID:s 19 Loadtime: 91 ms
http://cdn7.jinxidao.com/www/images/web-trust/zhizhao.jpg
ID:s 20 Loadtime: 93 ms
http://cdn7.jinxidao.com/www/images/web-trust/chengxin.jpg
ID:s 21 Loadtime: 94 ms
http://cdn7.jinxidao.com/www/images/web-trust/kexin.jpg
ID:s 22 Loadtime: 87 ms
http://cdn.jinxidao.com/images/white_bg.png
ID:s 23 Loadtime: 91 ms
http://cdn.jinxidao.com/detail/appCode.png
ID:s 24 Loadtime: 94 ms
http://cdn.jinxidao.com/detail/appCode.png?v=3
ID:s 25 Loadtime: 64 ms
http://www.yaochufa.com/ajax/checkcity?v=1493041417771&callback=jQuery1113015539110638201237_1493041417766&_=1493041417767
ID:s 26 Loadtime: 64 ms
http://tj.yaochufa.com/kafkahttp/kafka/log?callback=jQuery1113015539110638201237_1493041417768&event_content=http%3A%2F%2Fwww.yaochufa.com%2F&log_id=1&app_id=4&longitude=&latitude=&user_id=&current_citycode=&upload_time=2017-04-24+21%3A43%3A37&event_time=1493041418&session_id=1493041418&current_url=http%3A%2F%2Fwww.yaochufa.com%2F&from_url=&use_agent=Mozilla%2F5.0+(Unknown%3B+Linux+x86_64)+AppleWebKit%2F538.1+(KHTML%2C+like+Gecko)+PhantomJS%2F2.1.1+Safari%2F538.1&visit_ip=114.55.70.153&cookie=38e73c28-09f1-2945-47d8-cbd70f3d72ff&arg2=&event_id=700000&_=1493041417769
ID:s 27 Loadtime: 73 ms
http://sdk.zhugeio.com/zhuge-lastest.min.js?v=2017324
ID:s 28 Loadtime: 136 ms
http://hm.baidu.com/hm.js?84c5b2688d39b4e3c23d132b53b4e79b
ID:s 29 Loadtime: 151 ms
https://apipool.zhugeio.com/web_event/?method=web_event_srv.upload&event=%7B%22type%22%3A%20%22statis%22%2C%22sdk%22%3A%20%22web%22%2C%22sdkv%22%3A%20%221.3.0%22%2C%22cn%22%3A%20%22web%22%2C%22vn%22%3A%20%221.0%22%2C%22ak%22%3A%20%22b744d4b142c942c09cdc5095ba060824%22%2C%22did%22%3A%20%2215ba0340eac38a-04e727ec2-273f781b-c0000-15ba0340ead40b%22%2C%22ts%22%3A%201493041417.903%2C%22debug%22%3A%201%2C%22data%22%3A%20%5B%0A%20%20%20%20%7B%22et%22%3A%20%22ss%22%2C%22sid%22%3A%201493041417.902%2C%22cn%22%3A%20%22web%22%2C%22vn%22%3A%20%221.0%22%2C%22pr%22%3A%20%7B%22os%22%3A%20%22Linux%22%2C%22br%22%3A%20%22Safari%22%2C%22rs%22%3A%20%221024*768%22%2C%22url%22%3A%20%22http%3A%2F%2Fwww.yaochufa.com%2F%22%7D%7D%0A%5D%7D&_=1493041417904
卡住...

前面的输出, 我们已经看到已经按照我们需求那样, 得出 资源ID, 资源加载时间, 资源URL , 但是很奇怪的事, 到了大概是30的时候, 就卡住了, 这里肯定不是程序运行完, 因为程序结尾有个退出, 如果是正常结束了, 应该就退出了.所以我觉得这个肯定有哪里出错了! 这也是让我觉得phantomJS很不好的地方, 报错也不给个明显的错误提示, 就在哪里一动不动的.

既然phantomJS不明显报错, 咱们只能一步步调试了, 之前谷歌上看到, phantomJS能够用debug模式运行, 然后通过访问特定端口来用浏览器调试, 但是在这不行, 因为浏览器压根打不开那个链接, 一直在转, 也不知道是什么原因. 所以我们这里只能用 console.log 来排错了!

因为打印输出的代码是在最后面的, 那么可以证明前面的事件是正确被执行的, 因为如果前面的事件失败了, 那么整个程序肯定是不会打印的,相反的而是会停在前面卡住了.

为了证明这一点, 咱们把 for 循环去掉, 源码不再重复, 直接贴结果:

[root@iZ23pynfq19Z phantomjs-2.1.1-linux-x86_64]# ./bin/phantomjs 4.js 
ReferenceError: Can't find variable: sfCode

  http://qiniu-cdn7.jinxidao.com/assets/js/index.js?v=201704201643:1
主页加载完毕

嗖的一声就结束了, 这就验证了我们的猜想, 出错的代码应该是在for的打印里面, 既然知道大概的访问, 咱们 for 里面的每句代码都注释掉, 一句句单独执行, for 循环体代码分别是:

for(i=1;i<=num;i++)
    {
        // 取出请求数组的资源开始时间, 并转换成时间戳
        var req_time = new Date(req[i]['time']).getTime();  
    }
    phantom.exit();

---- 试验1结果: 程序顺利输出并结束 ----

    for(i=1;i<=num;i++)
    {
        // 取出响应数组的资源结束时间, 并转换成时间戳
        var res_time = new Date(res[i]['time']).getTime();
    }
    phantom.exit();  
    
---- 试验2结果: 程序卡住了!!  ----

可以看出, 问题应该是出现在第二句获取时间的地方, 但是这里应该是没问题的, 因为在实验时, 别的时间都能顺利转换! 但是没办法, 只有试验才能给出证据! 我们将这句话拆分两句运行

for(i=1;i<=num;i++)
    {
        // 取出响应数组的资源结束时间, 并转换成时间戳
        var res_time = new Date(res[i]['time'])
        console.log(res_time);
        console.log(res_time.getTime());
    }
    phantom.exit();
    
## 程序输出:
...
Mon Apr 24 2017 22:18:58 GMT+0800 (CST)
1493043538945
Mon Apr 24 2017 22:18:58 GMT+0800 (CST)
1493043538932
Mon Apr 24 2017 22:18:58 GMT+0800 (CST)
1493043538946
Mon Apr 24 2017 22:18:59 GMT+0800 (CST)
1493043539087
卡住了...

看来问题真的出现在这问题, 但是这样还是不能看出问题啊, 因为变量都正常输出了! 思来想去都觉得找不到问题, 只能继续往上拆了, 它是通过 i 在响应关联数组取出对象, 所以我们在上面加一句打印对象:

for(i=1;i<=num;i++)
    {
        // 取出响应数组的资源结束时间, 并转换成时间戳
        console.log(res[i]['time']);
        var res_time = new Date(res[i]['time'])
        console.log(res_time);
        console.log(res_time.getTime());
    }
    phantom.exit();
    
## 程序输出:
...
Mon Apr 24 2017 22:26:21 GMT+0800 (CST)
1493043981129
{"url":"https://apipool.zhugeio.com/web_event/?method=web_event_srv.upload&event=%7B%22type%22%3A%20%22statis%22%2C%22sdk%22%3A%20%22web%22%2C%22sdkv%22%3A%20%221.3.0%22%2C%22cn%22%3A%20%22web%22%2C%22vn%22%3A%20%221.0%22%2C%22ak%22%3A%20%22b744d4b142c942c09cdc5095ba060824%22%2C%22did%22%3A%20%2215ba05b2b444b7-0c599ec6d-273f781b-c0000-15ba05b2b454b1%22%2C%22ts%22%3A%201493043981.128%2C%22debug%22%3A%201%2C%22data%22%3A%20%5B%0A%20%20%20%20%7B%22et%22%3A%20%22ss%22%2C%22sid%22%3A%201493043981.126%2C%22cn%22%3A%20%22web%22%2C%22vn%22%3A%20%221.0%22%2C%22pr%22%3A%20%7B%22os%22%3A%20%22Linux%22%2C%22br%22%3A%20%22Safari%22%2C%22rs%22%3A%20%221024*768%22%2C%22url%22%3A%20%22http%3A%2F%2Fwww.yaochufa.com%2F%22%7D%7D%0A%5D%7D&_=1493043981128","time":"2017-04-24T14:26:21.273Z"}
Mon Apr 24 2017 22:26:21 GMT+0800 (CST)
1493043981273
Mon Apr 24 2017 22:26:21 GMT+0800 (CST)
1493043981132
undefined
程序卡住..

找到原因

惊喜发现 undefined , 嗯! 应该是 undefined 没有 getTime方法 , 导致程序出错了.看了下对应的 资源ID 是30, 而对应的 url 是: https://apipool.zhugeio.com, 不过为什么这个对象是undefined呢? 而请求资源那块确实是有的, 谷歌了下, 发现这个是一个资源监控网站, 也就是类似帮别人测试资源加载速度的, 难道这个请求是没有返回的? 先不管, 既然它是undefined. 那就通过判断过滤掉吧:

for(i=1;i<=num;i++)
    {
        // 取出请求数组的资源开始时间, 并转换成时间戳
        var req_time = new Date(req[i]['time']).getTime();
        // 过滤undefned
        if(res[i])
        {
            // 取出响应数组的资源结束时间, 并转换成时间戳
            var res_time = new Date(res[i]['time']).getTime();
            // 作差就是加载的时间
            var diff = res_time - req_time;
            console.log('ID: ',i, 'Loadtime:', diff, 'ms');
            // 打印对应ID的url
            console.log(res[i]['url']);
        }
        else
        {
            console.log('ID: ' + i + ' no response');
        }

    } 
--- 程序输出 ---
.....
ID: 30 no response
ID:  31 Loadtime: 148 ms
https://apipool.zhugeio.com/web_event/?method=web_event_srv.upload&event=%7B%22type%22%3A%20%22statis%22%2C%22sdk%22%3A%20%22web%22%2C%22sdkv%22%3A%20%221.3.0%22%2C%22cn%22%3A%20%22web%22%2C%22vn%22%3A%20%221.0%22%2C%22ak%22%3A%20%22b744d4b142c942c09cdc5095ba060824%22%2C%22did%22%3A%20%2215ba0698d3a9f4-0797b7d87-273f781b-c0000-15ba0698d3b4b2%22%2C%22ts%22%3A%201493044923.712%2C%22debug%22%3A%201%2C%22data%22%3A%20%5B%0A%20%20%20%20%7B%22et%22%3A%20%22info%22%2C%22pr%22%3A%20%7B%22os%22%3A%20%22Linux%22%2C%22br%22%3A%20%22Safari%22%2C%22rs%22%3A%20%221024*768%22%2C%22url%22%3A%20%22http%3A%2F%2Fwww.yaochufa.com%2F%22%2C%22cn%22%3A%20%22web%22%2C%22vn%22%3A%20%221.0%22%7D%7D%0A%5D%7D&_=1493044923712
ID:  32 Loadtime: 37 ms
.....

可以看到, 这个脚本可以正常运行了.

不过虽然可以运行了, 还是很好奇是不是真的有资源只有请求, 而没有响应的, 然而事实并不是! 在后面的测试中, 我发现, 如果我们在 onResourceReceived 打印资源ID和对象时, 会发现, 咱们前面丢失的30号对象, 也是有输出的, 咱们来试下:

page.onResourceReceived = function(response){
    console.log('ID: ' + response.id);
    // 将对象转变成JSON字符串
    console.log(JSON.stringify(response));
    res[response.id] = {'url': response.url, 'time': response.time};
};
--- 程序输出 ---
....(前面打印耗时)

// 单独打印
ID: 30
{"contentType":null,"headers":[],"id":30,"redirectURL":null,"stage":"end","status":null,"statusText":null,"time":"2017-04-24T14:52:08.402Z","url":"https://api.zhugeio.com/v1/events/codeless/appkey/b744d4b142c942c09cdc5095ba060824/platform/3?event_url=%2F"}

...

可以看出, 资源ID:30是有响应的, 只是响应的比较慢而已, 当开始运行循环体时, 它还没完成写, 因为JS时众所周知的异步编程, 所以它并不像我们一般程序那样顺序执行, 而是通过回调的方式完成任务.

代码小优化

既然知道它也是有响应的的, 那么咱们就不能抛弃它! 因为它也是我们的一份子! 但是我们该怎么做呢? 无奈之下去看PhantomJS的官网, 看到一个示范例子里面用到一个事件: onLoadFinished , 字面意思就是 完成加载时 , 这个看起来就是我们要找的, 因为如果页面加载完毕, 那么资源方面肯定是已经收齐( 菜鸟理解 ), 那我们开始改造刚才的脚本的, 将脚本的for分离出来, 放到 onLoadFinished 事件中, 代码如下:

page.onLoadFinished = function(status){
    console.log('加载完毕, 状态: ' + status);
    for(var i=1;i<=num;i++)
    {

        var req_time = new Date(result[i].time).getTime();
        if (rest[i])
        {
            var rest_time = new Date(rest[i].time).getTime();
            var diff = rest_time - req_time;
            console.log('ID:s',i, 'Loadtime:', diff, 'ms');
        }
        else
            // 颜色提醒
            console.log('\033[31mNo such response!\033[0m');
        console.log(result[i].url);
    }

};

经过上面的改造, 脚本已经能够比较好的算出加载时间了,不过咱们有些地方还需要优化, 那就是输入地址那边, 因为地址是写死的, 所以如果我们用来测试别的站点时, 就必须要修改代码, 这简直就是一个大错误! 所以我们需要 system 库!, 完整代码如下:

// 加载库
var page = require('webpage').create();
var system = require('system');
var req = {};  // 请求关联数组
var res = {};  // 响应关联数组
var num = 0;   // 用于记录资源数
var args = system.args;
if (args.length !== 2)
{
    console.log('\033[31mUsage: Url ( http://www.baidu.com )\033[0m');
    phantom.exit();
}
var address = args[1];

// 在 onResourceRequested 事件绑定动作
page.onResourceRequested = function(request){
    num++;
    req[request.id] = {'url': request.url, 'time': request.time};
};

// 在 onResourceReceived 事件绑定动作
page.onResourceReceived = function(response){
    res[response.id] = {'url': response.url, 'time': response.time};
};

page.onLoadFinished = function(status){
    console.log('加载完毕, 状态: ' + status);
    // 根据前面记录的资源请求个数, 开始统计各资源的加载时间
    for(var i=1;i<=num;i++)
    {
     var req_time = new Date(req[i].time).getTime();
        if (res[i])
        {
            var rest_time = new Date(res[i].time).getTime();
            var diff = rest_time - req_time;
            console.log('ID:s',i, 'Loadtime:', diff, 'ms');
        }
        else
            console.log('\033[31mNo such response! ID: ' + i + '\033[0m');
        console.log(req[i].url);
    }

};

// 开始请求
page.open(address, function(status){

    if(status !== 'success')
    {
        // 如果请求成功, 退出
        console.log(status);
        phantom.exit();
    }
    else{
        console.log('主页加载完毕');
    phantom.exit();
    }

});

不过还是有时候还是会出现找不到那个响应慢的请求, 可能需要换种实现的思路或者更加贴近的事件, 不过这个用来练手真是感觉, 之前一直觉得PhantomJS卡死, 其实只是程序错了, 这次对phantomJS改观了, 这是一个不错的工具, 往后还会继续深入学习!

欢迎各位大神指点交流,转载请注明来源: https://segmentfault.com/a/11...

查看原文: PhantomJS: 一次程序运行无反应的排查过程

需要 登录 后回复方可回复, 如果你还没有账号你可以 注册 一个帐号。