Android: Handler在工作线程结束时的消息延迟

4
我正在使用一个线程在服务内部执行一些繁重的处理,并希望在此处理过程中更新GUI (活动)。为了实现这一点,我从线程向处理程序发送消息,并从处理程序更新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 https://dev59.com/T2gu5IYBdhLWcg3wUlnt
        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(显示结果的活动)

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-1000ms),但这没有改变任何东西,除了更多的“帧”被跳过。
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和处理分离。当然,欢迎任何改进或更好的做法建议。

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


你可以在Activity中使用Broadcast Receiver来更新UI,在Service中触发Receiver。 - wolverine
这是否意味着在使用处理程序时,这是一种预期的行为?我真的想了解我的代码出了什么问题。无论如何,感谢您提供的解决方案建议,我会尝试。但我必须找到一种解决方案来将NfcVResponse对象传递给广播消息,这就是我选择Handler而不是Broadcast消息的原因。 - Gojir4
非常奇怪,我尝试使用BroadcastReceiver,它只在我第一次启动时起作用,然后现在我和使用handler时一样的行为... - Gojir4
尝试从_runTest()中删除synchronized关键字,看看效果如何。 - user
是的,在删除“synchronized”后它可以工作,谢谢Luksprog。您能将其添加为答案,以便我可以接受它吗?您能解释一下这种行为吗?似乎我不理解“synchronized”的工作原理。 - Gojir4
1个回答

2
_runTest()方法中删除synchronized关键字。你正在对整个Application对象进行同步,这似乎会阻塞UI线程,直到你完成_runTest()方法,使通过for循环的处理程序发送的所有消息都增加。
你在发布的Application类代码中的方法不需要同步。这适用于runTest()和特别是_runTest()(buildTest(testMap)是一个私有方法,很可能只从_runTest()调用,对吗?)。

谢谢,这就是解决方案。我误解了“synchronized”关键字的作用,我以为它只是避免函数在并行调用两次,但实际上它会阻塞整个对象。现在我明白了为什么我的GUI被阻塞了。你说得也对,我不需要同步这些函数,我可以检查线程是否正在运行并且不调用它们。非常感谢。 - Gojir4

网页内容由stack overflow 提供, 点击上面的
可以查看英文原文,
原文链接