android上傳位置資訊導致的流量大爆炸問題調查

標籤：

原由：項目中有人寫了個位置上傳的服務，其實一直沒問題，後來不知道什麼時候出現了很多抱怨，是開著app流量一下子跑掉了幾個G，差點就要賣房子還移動話費了，很多同事哭笑不得的找上門來，後來PM解決了，我一直沒時間弄明白，今天終於還原了這個大Bug，解決後才發現，要細心那，很多問題有可能測試都測不出來的，好的產品真是不容易啊，從產品到開發到測試都需要慎之又慎。我還差得遠，積累吧。

解決問題的過程就是不斷百度的過程啊。還是先貼幾個總結的比較好的Blog吧。

1. eclipse的輸出不夠用的，利用adb logcat的命令輸出到檔案。

adb logcat 命令列用法

adb logcat -f > D:\log.txtadb logcat TAG:D *:S -f > D:\log.txt

-f 不好用的話試試-d。要好好設定過濾，否則出來一堆沒用的log，我的有時候會不成功，還是Ubunt下的grep好用。

2. DDMS的Thread查看：說實話，資訊太少，我沒怎麼用到

 Android的DDMS中的Threads的各個欄位的含義

3.異常資訊

06-23 16:35:59.045: W/System.err(14651): android.os.NetworkOnMainThreadException06-23 16:35:59.050: W/System.err(14651):     at android.os.StrictMode$AndroidBlockGuardPolicy.onNetwork(StrictMode.java:1148)06-23 16:35:59.050: W/System.err(14651):     at libcore.io.BlockGuardOs.connect(BlockGuardOs.java:84)06-23 16:35:59.050: W/System.err(14651):     at libcore.io.IoBridge.connectErrno(IoBridge.java:144)06-23 16:35:59.050: W/System.err(14651):     at libcore.io.IoBridge.connect(IoBridge.java:112)06-23 16:35:59.050: W/System.err(14651):     at java.net.PlainSocketImpl.connect(PlainSocketImpl.java:192)06-23 16:35:59.050: W/System.err(14651):     at java.net.PlainSocketImpl.connect(PlainSocketImpl.java:459)06-23 16:35:59.050: W/System.err(14651):     at java.net.Socket.connect(Socket.java:843)06-23 16:35:59.050: W/System.err(14651):     at org.apache.http.conn.scheme.PlainSocketFactory.connectSocket(PlainSocketFactory.java:119)06-23 16:35:59.050: W/System.err(14651):     at org.apache.http.impl.conn.DefaultClientConnectionOperator.openConnection(DefaultClientConnectionOperator.java:144)06-23 16:35:59.050: W/System.err(14651):     at org.apache.http.impl.conn.AbstractPoolEntry.open(AbstractPoolEntry.java:164)06-23 16:35:59.050: W/System.err(14651):     at org.apache.http.impl.conn.AbstractPooledConnAdapter.open(AbstractPooledConnAdapter.java:119)06-23 16:35:59.050: W/System.err(14651):     at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:360)06-23 16:35:59.050: W/System.err(14651):     at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:583)06-23 16:35:59.050: W/System.err(14651):     at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:506)06-23 16:35:59.050: W/System.err(14651):     at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:484)06-23 16:35:59.055: W/System.err(14651):     at com.cmcc.wepa.util.NetworkManager.httpConnectOpt(NetworkManager.java:185)06-23 16:35:59.055: W/System.err(14651):     at com.cmcc.wepa.home.UploadLocationThread.run(UploadLocationThread.java:90)06-23 16:35:59.055: W/System.err(14651):     at com.cmcc.wepa.location.LocationUploadService.upload(LocationUploadService.java:141)06-23 16:35:59.055: W/System.err(14651):     at com.cmcc.wepa.location.LocationUploadService.access$0(LocationUploadService.java:94)06-23 16:35:59.055: W/System.err(14651):     at com.cmcc.wepa.location.LocationUploadService$1.handleMessage(LocationUploadService.java:159)06-23 16:35:59.055: W/System.err(14651):     at android.os.Handler.dispatchMessage(Handler.java:102)06-23 16:35:59.055: W/System.err(14651):     at android.os.Looper.loop(Looper.java:136)06-23 16:35:59.055: W/System.err(14651):     at android.app.ActivityThread.main(ActivityThread.java:5314)06-23 16:35:59.055: W/System.err(14651):     at java.lang.reflect.Method.invokeNative(Native Method)06-23 16:35:59.055: W/System.err(14651):     at java.lang.reflect.Method.invoke(Method.java:515)06-23 16:35:59.055: W/System.err(14651):     at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:862)06-23 16:35:59.055: W/System.err(14651):     at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:678)06-23 16:35:59.055: W/System.err(14651):     at dalvik.system.NativeStart.main(Native Method)

View Code

網路連接一直報這個異常，其實以前遇到過沒仔細看沒仔細想，以後可記住了AndroidBlockGuardPolicy.onNetwork，碰到他的話很有可能是因為把網路請求防飛彈主線程了。Android現在的版本是不允許將網路請求這樣的耗時操作放到主線程。

4.好了，差不多了，來兩個低級錯誤，我犯過，今天是逮到同事犯了，害我找了一下午bug都沒發現這個問題，否則也不會有上面的3了。

1). 寫了線程調用忘了開始，也就是沒有.start();

2). 在主線程了傻乎乎的把.start()寫錯為.run()，這不是調用類的方法嗎，根本沒開啟線程，相當於主線程執行，不出上面的問題3才怪。

5.還有service的啟動，顯示啟動的話OnCreate是執行一次的，多次start也是，但是每次start都會執行OnStart(),因此把什麼操作放在哪個方法裡要想清楚。

    @Override    public void onStart(Intent intent, int startId)    {        // TODO Auto-generated method stub        super.onStart(intent, startId);        Log.i("TEST", "onStart  ");        task = new TimerTask()        {            @Override            public void run()            {                // TODO Auto-generated method stub                Message msg = mHandler.obtainMessage();                msg.what = 0;                mHandler.sendMessage(msg);            }        };        timer.schedule(task, 0, 30000);    }

View Code

像上面這個啟動計時器任務放在了onsStart中，我覺得不是太好，因為別的頁面這個service會被多次顯示啟動，這樣沒有必要每次都建立這個task並放在計時任務中了。話說，如果真是這樣做了，下回再執行到這個函數的時候，原來的線程任務是等執行完已經開始的就over了吧？不能立即終止吧？現在還沒有能力驗證。這樣猜想好像蠻合理的呵呵，等待高手指教。

6.最後就是我原本要解決的問題：問題5中的代碼是啟動位置上傳的，當然下面的代碼現在已經不用了因為這個寫法自找麻煩了，直接上傳就好了，幹嘛還要用handler

呢。又不關心上傳的傳回值。不過，研究bug這個還是不錯的。

上面的timer定時發送message到handler，然後handler判斷what欄位後進行upload上傳。

    private Handler mHandler = new Handler(){        @Override        public void handleMessage(Message msg)        {            // TODO Auto-generated method stub            super.handleMessage(msg);            Log.i("TEST", "handleMessage msg.what= " + msg.what);            if(msg.what == 0)            {                //Log.i("TEST", "handleMessage ");                upload();            }        }    };

View Code

本來看起來沒問題，上傳函數中會調用一個上傳的Thread進行子線程操作。這個子線程代碼

public class UploadLocationThread extends Thread{    private Handler handler;    private String memberId; // 使用者id    private String memLng; // 經度    private String menLat; // 緯度    public UploadLocationThread()    {    }    public UploadLocationThread(Handler handler, String memberId,            String memLng, String menLat)    {        super();        this.handler = handler;        this.memberId = memberId;        this.memLng = memLng;        this.menLat = menLat;    }    public String getMemberId()    {        return memberId;    }    public void setMemberId(String memberId)    {        this.memberId = memberId;    }    public String getMemLng()    {        return memLng;    }    public void setMemLng(String memLng)    {        this.memLng = memLng;    }    public String getMenLat()    {        return menLat;    }    public void setMenLat(String menLat)    {        this.menLat = menLat;    }    // 上傳位置資訊    @Override    public void run()    {        super.run();        HashMap<String, String> param = new HashMap<String, String>();        param.put("userId", memberId);        param.put("userLng", memLng);        param.put("userLat", menLat);        Message msg = handler.obtainMessage();        Log.i("TEST", "UploadLocationThread msg " + msg.what);        // 擷取返回        try        {            String result = NetworkManager.getInstance().httpConnectOpt(                    Constant.URL_UPDATE_LOCATION, param);            JSONObject obj = JSON.parseObject(result);            Log.i("TEST", "UploadLocationThread result= " + result);            Log.i("TEST", "UploadLocationThread obj= " + obj);            String code = obj.getString("code");            Log.i("TEST", "UploadLocationThread code " + code);            if (code.equals("0"))            {                msg.what = 1;            } else            {                msg.what = -1;            }        } catch (Exception e)        {            e.printStackTrace();        }        Log.i("TEST", "UploadLocationThread msg.what end = " + msg.what);        handler.sendMessage(msg);    }}

View Code

好了，問題來了，以前沒有問題是正常情況，後來出問題了是因為：

線程中Message msg = handler.obtainMessage();這個初始值logcat列印會發現，msg.what的初始值是0，然而後面的上傳網路連結異常情況根本也沒處理這個值，所以異常的場合handler.sendMessage(msg);就把msg.what = 0，給傳遞到主線程中了，回去看task中的代碼，也是msg.what=0時調用update這個沒問題，但是下面的mHandler定義也是msg.what=0時調用上傳線程，這樣timer的task中正常上傳之外，每當線程上傳有異常的情況可能就陷入死迴圈了，因為handler收到的timer和上傳線程返回的msg.what全是0。再多的流量也不能這麼玩啊。

所以，對自己特殊的業務，msg.what的值最好是離預設值遠一點啊。還有，handler的機制搞清楚，主線程收到的handler的機制等等。還有就是異常處理一定要飛各種情況想清楚。

所以子線程上傳結果沒必要用handler發msg反饋了。主線程只處理timer的就可以，而且最好改成100,200這樣的值吧。

android上傳位置資訊導致的流量大爆炸問題調查