Android:处理程序的消息在工作线程结束时延迟

Question

我在服务内部使用一个线程，它执行一些繁重的处理，我想在此处理期间更新 GUI( Activity )。为此，我将消息从线程发送到处理程序，并从处理程序更新 GUI。但问题是只有当工作线程终止时，处理程序才会收到消息，就好像消息队列被阻塞一样。我使用服务的原因是因为即使应用程序未显示，该过程也应该继续。

应用程序的目标是通过发送预定义命令列表来测试 NFC 芯片 (ISO15693)。所以发送命令是由线程完成的，并且对于每个命令，结果被发送到处理程序。

这是我的代码:

申请

public class ISO15693Application extends Application {
...
    //Handler receiving messages from Worker thread
    final RunTestHandler runTestHandler = new RunTestHandler(ISO15693Application.this);    
    static class RunTestHandler extends Handler {
        //Avoid leak with handler        
        //See http://stackoverflow.com/questions/11407943/this-handler-class-should-be-static-or-leaks-might-occur-incominghandler
        private final WeakReference<ISO15693Application> mApplication; 

        RunTestHandler(ISO15693Application isoApp) {
            mApplication = new WeakReference<ISO15693Application>(isoApp);
        }

        @Override
        public void handleMessage(Message msg) {
            // TODO Auto-generated method stub
            super.handleMessage(msg);

            ISO15693Application isoApp = mApplication.get();

            switch(msg.what){
            case MSG_TEST_RESULT:
                NfcVResponse r = (NfcVResponse) msg.obj;
                if(r != null){
                    Log.i(TAG, "handleMessage Thread id : " + Thread.currentThread().getId());
                    isoApp.onTestResult((NfcVResponse) msg.obj, msg.arg1);
                }                    
                break;

            case MSG_TEST_STARTED:
                isoApp.onTestStarted(msg.arg1);
                break;
            case MSG_TEST_TERMINATED:
                isoApp.onTestTerminated();
                break;
            case MSG_ABORTED:
                isoApp.onTestAborted();
                break;

            }
        }
    }


    public void onTestResult(NfcVResponse response, int currentCommand) {        
        Log.i(TAG, "onTestResult. Command: " + response.getCommand().toString() 
                + " Status: " + response.getStatus());

        if(testResultCallback != null){
            testResultCallback.onTestResult(response);
        }
    }

    //Called when user click on "Run" button
    public synchronized void runTest(HashMap<Integer, List<Byte>> testMap){

        this.testMap = testMap;        

        //Start last test result activity
        Intent intent = new Intent(getApplicationContext(), TestResultsActivity.class);
        intent.setAction(ISO15693Application.INTENT_ACTION_TEST_STARTED);
        intent.setFlags(Intent.FLAG_ACTIVITY_NEW_TASK);
        startActivity(intent);

        //Start service responsible to run the test.
        runTestHandler.postDelayed(new Runnable() {            
            @Override
            public void run() {
                startTestService();                
            }
        }, 500);

    }

    /*
     * This function will be called by ISO15693Service.Runner to run the test in another thread. 
     * Messages are sent to runTestHandler to indicate start, progress and end .  
     */
    public synchronized void _runTest() {

        boolean tagLost = false;
        commandList = buildTest(testMap);

        int total = commandList.size();
        Message startMsg = new Message();
        startMsg.what = MSG_TEST_STARTED;
        startMsg.arg1 = total;
        runTestHandler.sendMessage(startMsg);

        Log.d(TAG, "Start test Thread id: " + Thread.currentThread().getId());

        for(int index = 0;index < total; index++){
            NfcVCommand cmd = commandList.get(index);
            NfcVResponse response = NfcVHelper.sendCommand(getNfcV(), cmd);

            switch(response.getStatus()){
            case NfcHelper.NFC_STATUS_OK:
                Log.i(TAG, "Command sent successfully");
                break;
            case NfcHelper.NFC_STATUS_NO_TAG:
                //Tag has been lost, try to reconnect
                Log.i(TAG, "Tag has been lost, reconnect");
                ...
                break;
            case NfcHelper.NFC_STATUS_ERROR:                
            default:
                Log.i(TAG, "Error when sent command " + response.getResponseString());
                break;
            }

            Message msg = new Message();        
            msg.what = MSG_TEST_RESULT;
            msg.arg1 = index;
            msg.arg2 = total;
            msg.obj = response;
            //Update UI with last command result            
            runTestHandler.sendMessage(msg);

            //Even if waiting a short moment to let the message queue processing
            //messages are handled only when the worker thread ends.
            //The only difference is in the log message : 
            //I/Choreographer(26709): Skipped 34 frames!  The application may be doing too much work on its main thread.
            //The number of Skipped frams is bigger according to time waited. 
            /*try {
                Thread.sleep(100);
            } catch (InterruptedException e1) {                
            }*/

            //Check tag lost and user cancellation
            ...
        }

        //Add results to db
        ...        
        runTestHandler.sendEmptyMessage(MSG_TEST_TERMINATED);        
    }
}

服务

public class ISO15693Service extends Service {

    @Override
    public void onCreate() {
        Log.d(TAG, "onCreate");
        //Create updater thread
        this.testRunner = null;
        //get application to access preferences
        isoApp =  (ISO15693Application) getApplication();

        super.onCreate();
    }

    @Override
    public void onDestroy() {

        super.onDestroy();
        Log.d(TAG, "onDestroy");

        if(this.testRunner != null){        
            this.testRunner.interrupt();
            this.testRunner = null;
        }
        this.runFlag = false;
        this.isoApp.setTestRunning(false);
    }

    @Override
    public int onStartCommand(Intent intent, int flags, int startId) {        
        Log.d(TAG, "onStartCommand");
        //not already running ? 
        if(!this.runFlag){
            try{
                this.testRunner = new Runner();
                this.runFlag = true;
                this.isoApp.setTestRunning(true);    
                this.testRunner.start();                            
            } catch(IllegalThreadStateException e){                
            }
        }        
        return super.onStartCommand(intent, flags, startId);
    }


    @Override
    public IBinder onBind(Intent intent) {
        // TODO Auto-generated method stub
        return null;
    }

    private class Runner extends Thread{

        Runner(){
            super("Runner class");
        }

        @Override
        public void run() {
            super.run();
            ISO15693Service is = ISO15693Service.this;
            ISO15693Application isoApp = (ISO15693Application) is.getApplication();

            Log.d(TAG, "Runner.run() Thread id: " + Thread.currentThread().getId());

            isoApp._runTest();
            is.runFlag = false;
            isoApp.setTestRunning(false);            
        }
    }

}

TestResultActivity(显示结果的 Activity )

public class TestResultsActivity extends ISO15693BaseActivity
implements ISO15693Application.TestResultCallback{

    ...

    @Override
    protected void onCreate(Bundle savedInstanceState) {
        super.onCreate(savedInstanceState);
        setContentView(R.layout.activity_test_results);

        mainLayout = (LinearLayout) findViewById(R.id.resultLayout);
        progressBar = (ProgressBar) findViewById(R.id.progressBar);
        ...
    }    

    @Override
    public void onResume() {    
        super.onResume();
        isoApp.setTestResultCallback(this);
    }

    @Override
    public void onPause() {
        super.onPause();
        //Disable callback if activity is not at foreground
        isoApp.setTestResultCallback(null);
    }

    //Add command result to the main layout 
    @Override
    public void onTestResult(final NfcVResponse response) {
        if(mainLayout != null){
            LayoutParams params = new LayoutParams(LayoutParams.MATCH_PARENT, LayoutParams.WRAP_CONTENT);
            TestResultView rv = new TestResultView(TestResultsActivity.this, response);
            mainLayout.addView(rv, params);                    
        }
        progressBar.setProgress(progress++);

    }

    @Override
    public void onTestStarted() {
        Log.i(TAG, "onTestStarted");

        Log.d(TAG, "GUI Thread id: " + Thread.currentThread().getId());
        mainLayout.removeAllViews();
        progress = 0;
        progressBar.setVisibility(View.VISIBLE);
        progressBar.setMax(isoApp.getTestInfo().nbCommands);        
    }

    @Override
    public void onTestTerminated() {
        Log.i(TAG, "onTestTerminated");        
        progressBar.setVisibility(View.GONE);                

    }
}

这是日志，我们可以看到“handleMessage”和“onTestResult”仅在最后一次“sendCommand”调用之后才被调用。但它们应该被直接处理，或者可能有一个小的延迟，但不能像现在这样延迟。请注意，消息发送到处理程序的时刻对应于日志中的“命令发送成功”或“发送命令时出错...”行。

还有消息“跳过 34 帧!应用程序可能在其主线程上做了太多工作。”我认为问题出在这里，此消息表明 GUI 在 34 帧期间已被卡住。但我不明白为什么，因为所有“繁重的处理”都是在另一个线程(id 69595)而不是 GUI 线程中完成的。我还尝试在每个命令处理之间等待(100-1000 毫秒)，但这没有任何改变，只是跳过了更多的“帧”。

12-16 10:43:19.600: I/ISO15693Application(26709): Activity TestResultsActivity created
12-16 10:43:19.615: D/TestResultsActivity(26709): GUI Thread id: 1
12-16 10:43:20.145: D/ISO15693Service(26709): onCreate
12-16 10:43:20.145: D/ISO15693Service(26709): onStartCommand
12-16 10:43:20.145: D/ISO15693Application(26709): Build Test Thread id: 69595
12-16 10:43:20.150: I/ISO15693Application(26709): Test started: 8 commands
12-16 10:43:20.150: I/TestResultsActivity(26709): onTestStarted
12-16 10:43:20.150: D/TestResultsActivity(26709): GUI Thread id: 1
12-16 10:43:20.150: D/ISO15693Application(26709): Start test Thread id: 69595
12-16 10:43:20.150: D/NfcVHelper(26709): SendCommand Thread id: 69595
12-16 10:43:20.150: D/NfcVHelper(26709): Send command : 00 20 10 
12-16 10:43:20.185: D/NfcVHelper(26709): Response : 00 5a a5 5a a5 
12-16 10:43:20.185: I/ISO15693Application(26709): Command sent successfully
12-16 10:43:20.185: D/NfcVHelper(26709): SendCommand Thread id: 69595
12-16 10:43:20.185: D/NfcVHelper(26709): Send command : 00 21 10 5a a5 5a a5 
12-16 10:43:20.245: D/NfcVHelper(26709): Response : 00 
12-16 10:43:20.245: I/ISO15693Application(26709): Command sent successfully
12-16 10:43:20.245: D/NfcVHelper(26709): SendCommand Thread id: 69595
12-16 10:43:20.245: D/NfcVHelper(26709): Send command : 00 23 01 02 
12-16 10:43:20.290: D/NfcVHelper(26709): Response : 00 00 00 00 00 00 00 00 00 00 00 00 00 
12-16 10:43:20.290: I/ISO15693Application(26709): Command sent successfully
12-16 10:43:20.290: D/NfcVHelper(26709): SendCommand Thread id: 69595
12-16 10:43:20.290: D/NfcVHelper(26709): Send command : 00 27 af 
12-16 10:43:20.330: D/NfcVHelper(26709): Response : 00 
12-16 10:43:20.330: I/ISO15693Application(26709): Command sent successfully
12-16 10:43:20.330: D/NfcVHelper(26709): SendCommand Thread id: 69595
12-16 10:43:20.330: D/NfcVHelper(26709): Send command : 00 29 d5 
12-16 10:43:20.375: D/NfcVHelper(26709): Response : 00 
12-16 10:43:20.375: I/ISO15693Application(26709): Command sent successfully
12-16 10:43:20.375: D/NfcVHelper(26709): SendCommand Thread id: 69595
12-16 10:43:20.375: D/NfcVHelper(26709): Send command : 00 2b 
12-16 10:43:20.410: D/NfcVHelper(26709): Response : 00 xx xx xx xx xx xx xx xx xx xx xx xx xx xx 
12-16 10:43:20.410: I/ISO15693Application(26709): Command sent successfully
12-16 10:43:20.410: D/NfcVHelper(26709): SendCommand Thread id: 69595
12-16 10:43:20.410: D/NfcVHelper(26709): Send command : 00 2c 00 00 
12-16 10:43:20.450: D/NfcVHelper(26709): Response : 00 01 
12-16 10:43:20.450: I/ISO15693Application(26709): Command sent successfully
12-16 10:43:20.450: D/NfcVHelper(26709): SendCommand Thread id: 69595
12-16 10:43:20.450: D/NfcVHelper(26709): Send command : 00 a5 16 
12-16 10:43:20.505: W/System.err(26709): android.nfc.TagLostException: Tag was lost.
12-16 10:43:20.505: W/System.err(26709):    at android.nfc.TransceiveResult.getResponseOrThrow(TransceiveResult.java:48)
12-16 10:43:20.505: W/System.err(26709):    at android.nfc.tech.BasicTagTechnology.transceive(BasicTagTechnology.java:151)
12-16 10:43:20.505: W/System.err(26709):    at android.nfc.tech.NfcV.transceive(NfcV.java:115)
12-16 10:43:20.505: W/System.err(26709):    at em.marin.nfc.NfcVHelper.sendCommand(NfcVHelper.java:283)
12-16 10:43:20.505: W/System.err(26709):    at em.marin.iso15693test.ISO15693Application._runTest(ISO15693Application.java:447)
12-16 10:43:20.505: W/System.err(26709):    at em.marin.iso15693test.ISO15693Service$Runner.run(ISO15693Service.java:88)
12-16 10:43:20.505: I/ISO15693Application(26709): Error when sent command IO Exception occured during transmission of the command
12-16 10:43:20.730: I/Choreographer(26709): Skipped 34 frames!  The application may be doing too much work on its main thread.
12-16 10:43:20.795: I/ISO15693Application(26709): handleMessage Thread id : 1
12-16 10:43:20.795: I/ISO15693Application(26709): onTestResult. Command: Read Single Block Status: 0
12-16 10:43:20.820: I/ISO15693Application(26709): handleMessage Thread id : 1
12-16 10:43:20.820: I/ISO15693Application(26709): onTestResult. Command: Write Single Block Status: 0
12-16 10:43:20.830: I/ISO15693Application(26709): handleMessage Thread id : 1
12-16 10:43:20.830: I/ISO15693Application(26709): onTestResult. Command: Read Multiple Blocks Status: 0
12-16 10:43:20.845: I/ISO15693Application(26709): handleMessage Thread id : 1
12-16 10:43:20.845: I/ISO15693Application(26709): onTestResult. Command: Write AFI Status: 0
12-16 10:43:20.855: I/ISO15693Application(26709): handleMessage Thread id : 1
12-16 10:43:20.855: I/ISO15693Application(26709): onTestResult. Command: Write DSFI Status: 0
12-16 10:43:20.865: I/ISO15693Application(26709): handleMessage Thread id : 1
12-16 10:43:20.865: I/ISO15693Application(26709): onTestResult. Command: Get System Information Status: 0
12-16 10:43:20.875: I/ISO15693Application(26709): handleMessage Thread id : 1
12-16 10:43:20.875: I/ISO15693Application(26709): onTestResult. Command: Get Multiple Block Security Status Status: 0
12-16 10:43:20.885: I/ISO15693Application(26709): handleMessage Thread id : 1
12-16 10:43:20.885: I/ISO15693Application(26709): onTestResult. Command: Read Sig Status: 1
12-16 10:43:20.890: I/ISO15693Application(26709): Test has been terminated successfully
12-16 10:43:20.890: I/TestResultsActivity(26709): onTestTerminated
12-16 10:43:20.955: D/ISO15693Service(26709): onDestroy

我希望我的解释很清楚。应用程序的体系结构可能看起来很奇怪，但我尽量将 GUI 和处理分开。当然，欢迎提出任何改进或更好实践的建议。

我在这个论坛和其他论坛上搜索了很长时间以找到类似的问题，但我没有找到，所以如果这个问题已经被问到，我提前道歉。也为我的英语感到抱歉，那不是我的母语。

Answer 1

从 _runTest() 方法中删除 synchronized 关键字。您正在同步整个 Application 对象，它似乎会阻塞 UI 线程，直到您完成 _runTest() 方法，通过for 循环。

您发布的Application 类代码中的方法不需要同步。这适用于 runTest()，尤其是 _runTest()(buildTest(testMap) 它是一个私有(private)方法，很可能只能从 _runTest()，对吧？)。