原由:项目中有人写了个位置上传的服务,其实一直没问题,后来不知道什么时候出现了很多抱怨,是开着app流量一下子跑掉了几个G,差点就要卖房子还移动话费了,很多同事哭笑不得的找上门来,后来PM解决了,我一直没时间弄明白,今天终于还原了这个大Bug,解决后才发现,要细心那,很多问题有可能测试都测不出来的,好的产品真是不容易啊,从产品到开发到测试都需要慎之又慎。我还差得远,积累吧。
解决问题的过程就是不断百度的过程啊。还是先贴几个总结的比较好的Blog吧。
1. eclipse的输出不够用的,利用adb logcat的命令输出到文件。
adb logcat -f > D:\log.txt adb logcat TAG:D *:S -f > D:\log.txt
-f 不好用的话试试-d。要好好设置过滤,否则出来一堆没用的log,我的有时候会不成功,还是Ubunt下的grep好用。
2. DDMS的Thread查看:说实话,信息太少,我没怎么用到
3.异常信息
06-23 16:35:59.045: W/System.err(14651): android.os.NetworkOnMainThreadException 06-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)
网络连接一直报这个异常,其实以前遇到过没仔细看没仔细想,以后可记住了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); }
像上面这个启动计时器任务放在了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(); } } };
本来看起来没问题,上传函数中会调用一个上传的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); } }
好了,问题来了,以前没有问题是正常情况,后来出问题了是因为:
线程中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这样的值吧。