关于RILJ多次发出GET_CURRENT_CALLS请求的问题分析

本文来自本文来自http://blog.csdn.net/linyongan 

在刚接触Qcril的时候，特别是在研究接电话和打电话的流程的时候，可能会有小伙伴跟我一样，被RILJ发出的GET_CURRENT_CALLS请求搞晕了。有时候会RILJ会多次发出GET_CURRENT_CALLS请求，两次或者三次，不确定。
举个例子，每次出现GET_CURRENT_CALLS error之后，RILJ会再发出一次GET_CURRENT_CALLS请求，所以，我们先假设“GET_CURRENT_CALLS error会导致RILJ重新发出GET_CURRENT_CALLS请求”，下面我们就根据代码去验证一下呗。

---

---

下面是打电话的一段log

09-09 17:32:03.599 D/RILJ    ( 2795): [UNSL]< UNSOL_RESPONSE_CALL_STATE_CHANGED
09-09 17:32:03.607 D/RILJ    ( 2795): [UNSL]< UNSOL_RESPONSE_CALL_STATE_CHANGED
09-09 17:32:03.686 D/RILJ    ( 2795): [5658]> GET_CURRENT_CALLS
09-09 17:32:03.688 D/RILJ    ( 2795): [5659]> GET_CURRENT_CALLS
09-09 17:32:03.691 D/RilRequest( 2795): [5659]< GET_CURRENT_CALLS error: 
com.android.internal.telephony.CommandException: GENERIC_FAILURE ret=
09-09 17:32:03.693 I/RILQ    (  268): (0/268):RIL[0][event] 
qcril_qmi_get_call_list_to_send: RILVI: calls rep:[qmi call id 1, 
android call id 1, qmi call state 3] reported/skipped 1/0 calls
09-09 17:32:03.696 V/RILJ    ( 2795): Incoming UUS : NOT present!
09-09 17:32:03.696 D/RILJ    ( 2795): InCall VoicePrivacy is disabled
09-09 17:32:03.696 D/RILJ    ( 2795): [5658]< GET_CURRENT_CALLS  
[id=1,ACTIVE,toa=129,norm,mo,0,voc,noevp,,cli=1,,0] 
09-09 17:32:03.745 D/CdmaCallTracker( 2795): Event EVENT_POLL_CALLS_RESULT Received
09-09 17:32:03.745 D/CdmaCallTracker( 2795): Event EVENT_POLL_CALLS_RESULT Received
09-09 17:32:03.751 D/CallStateMonitor( 2795): handleMessage(10)
09-09 17:32:03.751 D/CallNotifier( 2795): PHONE_ENHANCED_VP_OFF...
09-09 17:32:03.752 I/Timeline( 2795): Timeline: Activity_idle id: 
android.os.BinderProxy@41bd7cc0 time:5637716
09-09 17:32:03.995 D/RILJ    ( 2795): [5660]> GET_CURRENT_CALLS
09-09 17:32:03.999 I/RILQ    (  268): (0/268):RIL[0][event] 
qcril_qmi_get_call_list_to_send: RILVI: calls rep:
[qmi call id 1, android call id 1, qmi call state 3] 
reported/skipped 1/0 calls
09-09 17:32:04.001 V/RILJ    ( 2795): Incoming UUS : NOT present!
09-09 17:32:04.002 D/RILJ    ( 2795): InCall VoicePrivacy is disabled
09-09 17:32:04.002 D/RILJ    ( 2795): [5660]< GET_CURRENT_CALLS 
[id=1,ACTIVE,toa=129,norm,mo,0,voc,noevp,,cli=1,,0] 
09-09 17:32:04.002 D/CdmaCallTracker( 2795): Event EVENT_POLL_CALLS_RESULT Received

从上面log可以看到，连续发出两次GET_CURRENT_CALLS请求之后，后面紧跟着会发出第三次，而且第二次查询失败了：

09-09 17:32:03.691 D/RilRequest( 2795): [5659]< GET_CURRENT_CALLS error: 
com.android.internal.telephony.CommandException: 
GENERIC_FAILURE ret=

首先，RILRequest是RILJ的内部类，在RILJ的processSolicited方法里也有：

   if (error != 0) {
       switch (rr.mRequest) {
         case RIL_REQUEST_ENTER_SIM_PIN:
         case RIL_REQUEST_ENTER_SIM_PIN2:
         case RIL_REQUEST_CHANGE_SIM_PIN:
         case RIL_REQUEST_CHANGE_SIM_PIN2:
         case RIL_REQUEST_SET_FACILITY_LOCK:
           if (mIccStatusChangedRegistrants != null) {
              if (RILJ_LOGD) {
              riljLog("ON some errors fakeSimStatusChanged: reg count="
                      + mIccStatusChangedRegistrants.size());
              }
              mIccStatusChangedRegistrants.notifyRegistrants();
            }
         break;
     }
    rr.onError(error, ret);
} 

当RILJ发出去的请求出错之后会进入这个if语句，最后进入RILRequest的onError方法。

 void onError(int error, Object ret) {
        CommandException ex;
        ex = CommandException.fromRilErrno(error);
        if (RIL.RILJ_LOGD) Rlog.d(LOG_TAG, serialString() + "< "
            + RIL.requestToString(mRequest)
            + " error: " + ex + " ret=" + RIL.retToString(mRequest, ret));

        if (mResult != null) {
            AsyncResult.forMessage(mResult, ret, ex);
            mResult.sendToTarget();
        }

        if (mParcel != null) {
            mParcel.recycle();
            mParcel = null;
        }
}

看到了吧，是在onError方法里打印出出错的log，mResult != null，所以下一步会回到CdmaCallTracker的handleMessage方法里，这个例子是打电话，所以这里处理的是EVENT_POLL_CALLS_RESULT的逻辑，下面这两行log也证明了会进入这里。

public void handleMessage (Message msg) {
     ...
   case EVENT_POLL_CALLS_RESULT:{
        Rlog.d(LOG_TAG, "Event EVENT_POLL_CALLS_RESULT Received");
        ar = (AsyncResult)msg.obj;
        if(msg == mLastRelevantPoll) {
          if(DBG_POLL) 
          log("handle EVENT_POLL_CALL_RESULT: set needsPoll=F");
          mNeedsPoll = false;
          mLastRelevantPoll = null;
          handlePollCalls((AsyncResult)msg.obj);
        }
     }
     break;
     ...
}


09-09 17:32:03.745 D/CdmaCallTracker( 2795): Event EVENT_POLL_CALLS_RESULT Received
09-09 17:32:03.745 D/CdmaCallTracker( 2795): Event EVENT_POLL_CALLS_RESULT Received

最后会进入handlePollCalls方法里。

protected void handlePollCalls(AsyncResult ar) {
        List polledCalls;
        if (ar.exception == null) {
            polledCalls = (List)ar.result;
        } else if (isCommandExceptionRadioNotAvailable(ar.exception)) {
            // just a dummy empty ArrayList to cause the loop
            // to hang up all the calls
            polledCalls = new ArrayList();
        } else {
            // Radio probably wasn't ready--try again in a bit
            // But don't keep polling if the channel is closed
            pollCallsAfterDelay();
            return;
        }
}

GET_CURRENT_CALLS error对应的是CommandException，所以跳过if和else if，进入else里，也就是进入pollCallsAfterDelay方法里，pollCallsAfterDelay方法在CdmaCallTracker的父类CallTracker中实现

 protected void pollCallsAfterDelay() {
        Message msg = obtainMessage();
        msg.what = EVENT_REPOLL_AFTER_DELAY;
        sendMessageDelayed(msg, POLL_DELAY_MSEC);
}

POLL_DELAY_MSEC的值是250，也就是说RILJ在250秒之后会重新发出GET_CURRENT_CALLS请求，所以我们最开始的假设是正确的！！！也就是说，在GET_CURRENT_CALLS失败之后，RILJ会重新发出GET_CURRENT_CALLS请求！

09-09 17:32:03.745 D/CdmaCallTracker( 2795): Event EVENT_POLL_CALLS_RESULT Received
...
09-09 17:32:03.995 D/RILJ    ( 2795): [5660]> GET_CURRENT_CALLS

从log中也可以看到“17:32:03.745”与“17:32:03.995”相差了250毫秒，我们上面的代码分析也是正确的！
这个问题也就讲到这里啦~