A common thread sync issue analysis of android application

Android应用中, 很多问题都是因为线程同步而引起, 本例涉及应用的其它方面很少, 是一个典型的线程同步问题.

A common thread sync issue.

[Symptom]
07-01 02:14:58.549 14861  2415 W dalvikvm: threadid=20: thread exiting with uncaught exception (group=0x40adc9f0)
07-01 02:14:58.619 14861  2415 E AndroidRuntime: FATAL EXCEPTION: CallLogContentHelper.UiUpdaterExecutor
07-01 02:14:58.619 14861  2415 E AndroidRuntime: java.lang.NullPointerException
07-01 02:14:58.619 14861  2415 E AndroidRuntime:  at com.xxxxx.android.socialphonebook.util.CallLogContentHelper$1.run(CallLogContentHelper.java:167)
07-01 02:14:58.619 14861  2415 E AndroidRuntime:  at com.xxxxx.android.socialphonebook.util.CallLogContentHelper$UiUpdaterExecutor$1.run(CallLogContentHelper.java:453)
07-01 02:14:58.619 14861  2415 E AndroidRuntime:  at java.lang.Thread.run(Thread.java:856)

[Root Cause]
In CallLogContentHelper.java
    private Runnable mCommandQuery;

The CallLogContentHelper use (mSyncEnable && mListener != null) as the condition to notify the listener after querySync completing.
    public CallLogContentHelper(ContentResolver contentResolver, OnQueryCompleteListener listener) {
        this(contentResolver);
        mListener = listener;
        mExecutor = new UiUpdaterExecutor();
        mCommandQuery = new Runnable() {
            public void run() {
                String selection = Calls.DATE + " > " + getCutoffDate().getTime();
                Cursor cursor = null;
                try {
                    cursor = querySync(selection, null); // do blocking query actually. time wasted.
                } catch (Exception e) {
                    SpbLog.d(TAG, "querySync(" + selection + ") failed. " + e);
                    // cursor is already null
                }
  #### synchronized(mLockListener) patches here ####
                if (cursor != null) {
166                    if (mSyncEnable && mListener != null) {
      ### point 1 ###
167                        mListener.onQueryComplete(cursor);    ********
                    } else {
                        cursor.close();
                    }
                }
            }
        };
    }

    /**
     * queryAsync Method used for asynchronous queries
     * For this method to work the OnQueryCompleteListener listener must be set
     */
    public void queryAsync() {
        synchronized (mLock) {
            if (mListener != null && mExecutor != null){
                mExecutor.execute(mCommandQuery);
            }
        }
    }

    private Cursor querySync(String selection, String[] selectionArgs) {
        SpbLog.d(TAG, "CallLogContentHelper query");
        Cursor[] cursors = new Cursor[2];
        cursors[0] = mContentResolver.query(Calls.CONTENT_URI_WITH_VOICEMAIL, CALL_LOG_PROJECTION,
                selection, selectionArgs, Calls.DEFAULT_SORT_ORDER);

        if (mVoipIsInstallled) {
            cursors[1] = mContentResolver.query(VoIPCalls.CONTENT_URI, VOIP_CALL_LOG_PROJECTION,
                    selection, selectionArgs, Calls.DEFAULT_SORT_ORDER);
        }

        return new CallLogMergeCursor(cursors);
   }

But mListener is not well synchronized in release method.
    public void release() {
        synchronized (mLock) {
            if (mExecutor != null) {
                mExecutor.tryStop();
                mExecutor = null;
            }
        }
 #### synchronized(mLockListener) patches here ####
        mListener = null;    ********
    }

UiUpdaterExecutor is an inner class of CallLogContentHelper used to update ui as its name indicates.
It executes the passed in Runnable command in itself thread using the same trick as Thread's target.run().
    static class UiUpdaterExecutor implements Executor {

        private boolean mFinish = false;

        private int mQueue;

        private Runnable mCommand;

        private Object mLock;

        public UiUpdaterExecutor() {
            mQueue = 0;
            mLock = new Object();
            Thread thread = new Thread(runner, "CallLogContentHelper.UiUpdaterExecutor");
            thread.setPriority(Thread.MIN_PRIORITY);
            thread.start();
        }

        public void execute(Runnable command) {
            SpbLog.d(TAG, "UiUpdaterExecutor execute");
            this.mCommand = command;
            synchronized (mLock) {
                mQueue = 1;
                mLock.notifyAll();
            }
        }

        public void tryStop() {
            mFinish = true;
            synchronized (mLock) {
                mLock.notifyAll();
            }
        }

        private Runnable runner = new Runnable() {
            public void run() {
                while (!mFinish) {
                    boolean doExecute = false;
                    synchronized (mLock) { **** UiUpdaterExecutor owner lock. ****
                        if (mQueue <= 0) {
                            try {
                                mLock.wait();
                            } catch (InterruptedException e) {
                                // Do nothing
                            }
                        } else {
                            mQueue--;
                            doExecute = true;
                        }
                    }
                    if (doExecute) {
                        SpbLog.d(TAG, "UiUpdaterExecutor commnad run");
                        mCommand.run(); **********
                    }
                }
                SpbLog.d(TAG, "UiUpdaterExecutor finished");
            }
        };
    }

So, after CallLogContentHelper object is constructed, the execute thread is running and waiting for commnad.
When CallLogContentHelper::queryAsync is called in main thread and returns immediately, command is delivered to executor and command.run() method is executed in executor thread.
The database query is relatively a time wasted process.

Say the executor thread evaluates mListener != null and is scheduled out at ### point 1 ###.
Now, the main thread or another thread calls CallLogContentHelper::release() and assigns mListener with null.
When the executor thread continues to run, mListener is null and the java.lang.NullPointerException arise.
 
More accrutely, the executor thread is absolutely immune from the CallLogContentHelper object's lock.

The CallLogContentHelper::release() is usaully called in activity's or service's onDestroy(). 
In normal use, the crash may not happens.
But the crash possibility much increase in automation test, because the activity may be created and destroyed very quickly.
 
The reference solution is to use a synchronized lock to protect the mListener.
synchronized(mLockListener) {}.