PhantomJS: 一次程序運行無反應的排查過程

背景

最近剛接觸PhantomJS, 據說這工具是一個基於WebKit的服務器端JavaScript API,能夠實現絕大部分瀏覽器的操做, 火燒眉毛就想練練手.因而就簡單寫了一個程序, 簡單介紹下:javascript

需求: 經過phantomJS向一個網站發起請求, 而且記錄各資源加載的時間,名字
思路:
    1.經過 onResourceRequested,得到資源請求時間t1, 並經過資源ID,記錄在關聯數組內
    2.經過 onResourceReceived 得到資源響應時間t2, 也一樣存到關聯數組內
    2.用t2 - t1得出的, 就是資源加載花費的毫秒值
    3.由於資源ID是相關聯的,因此只須要取任意一個關聯組的url就能夠

程序源碼

test.js 內容以下:css

// 加載庫
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循環去掉, 源碼再也不重複, 直接貼結果:java

[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循環體代碼分別是:jquery

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結果: 程序卡住了!!  ----

能夠看出, 問題應該是出如今第二句獲取時間的地方, 可是這裏應該是沒問題的, 由於在實驗時, 別的時間都能順利轉換! 可是沒辦法, 只有試驗才能給出證據! 咱們將這句話拆分兩句運行linux

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在響應關聯數組取出對象, 因此咱們在上面加一句打印對象:git

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. 那就經過判斷過濾掉吧:web

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號對象, 也是有輸出的, 我們來試下:ajax

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 事件中, 代碼以下:segmentfault

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...

相關文章
相關標籤/搜索