linux js脚本无法响应,PhantomJS: 一次程序运行无反应的排查过程

背景

最近刚接触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改观了, 这是一个不错的工具, 往后还会继续深入学习!