移动终端彩信问题分析总结

      在日常项目通讯方面的开发中，经常遇到彩信发送或接收失败问题，本文将基于MTK及QCOM平台就此类问题进行分析总结。

1、MTK平台
此类问题的log信息可分为三个方面：app logs、radio logs、net logs.
app logs的分析方法：
1）通过搜索关键字'Mms/Txn’，可知信息应用收发彩信的过程。举例如下：
05-27 16:53:03.325769  2676  2676 D Mms/Txn : Enter send(). subId = 5 //开始发送
05-27 16:53:04.145637  2676  2676 D Mms/Txn : mms is sending, uri = content://mms/19 //发送中

//发送处理过程
05-27 16:53:04.366993  2676  2676 D Mms/Txn : Creating TransactionService
05-27 16:53:04.423810  2676  4635 D Mms/Txn : launchTransaction subId = 5
05-27 16:53:04.425258  2676  4635 D Mms/Txn : TRANSACTION REQUEST: SEND_TRANSACTION
05-27 16:53:04.427793  2676  4635 V Mms/Txn : process Transaction
05-27 16:53:04.441166  2676  4637 D Mms/Txn : send MMS with param, mUri = content://mms/19, subId = 5
05-27 16:53:11.943095  2676  4635 D Mms/Txn : EVENT_TRANSACTION_PROCESSED
//网络响应
05-27 16:53:11.943326  2676  4635 D Mms/Txn : handleTransactionProcessed(), error type = 1, uri = content://mms/19
05-27 16:53:11.954736  2676  4635 V Mms/Txn : set Transaction Fail. fail Type=1
05-27 16:53:11.954819  2676  4635 D Mms/Txn : set Transaction Fail. :Send
05-27 16:53:12.272506  2676  4635 D Mms/Txn : update: result=FAILED //失败
这部分log来自于main_log中。

2）通过搜索关键字'MmsService’，可知信息应用中pdp连接过程。举例如下：
05-27 16:53:07.701636  1595  4639 D MmsService: [SendRequest@7178a7d] APN name is mms
05-27 16:53:07.702175  1595  4639 I MmsService: [SendRequest@7178a7d] Loading APN using name mms
05-27 16:53:07.720823  1595  4639 I MmsService: [SendRequest@7178a7d] Using APN [type=mms mmsc=http://mms.:38090/was mmsproxy=41.151.254.162 mmsport=8080 name=8.ta mms apn=mms bearer_bitmask=0 protocol=IP roaming_protocol=IP authtype=-1 proxy=41.151.254.162 port=8080]
05-27 16:53:07.725440  1595  4639 D MmsService: [SendRequest@7178a7d] HTTP: POST http://mms.[28], proxy=41.151.254.162:8080, PDU size=430
05-27 16:53:07.725579  1595  4639 D MmsServicePluginManager: getMmsPlugin, type = 2
05-27 16:53:07.757153  1595  4639 I MmsService: [SendRequest@7178a7d] HTTP: User-Agent=Android-Mms/0.1
05-27 16:53:07.757308  1595  4639 I MmsService: [SendRequest@7178a7d] HTTP: UaProfUrl=http://www.google.com/oha/rdf/ua-profile-kila.xml
05-27 16:53:11.886264  1595  4639 D MmsService: [SendRequest@7178a7d] HTTP: 200 OK
05-27 16:53:11.887153  1595  4639 D MmsService: [SendRequest@7178a7d] HTTP: response size= 90
//到此为止，终端处理发送完成。

05-27 16:53:11.887980  1595  4639 D MmsService: checkResponse get response  = 130
05-27 16:53:11.888094  1595  4639 D MmsService: [SendRequest@7178a7d] MmsNetworkManager: release, count=0
05-27 16:53:11.889515  1595  4639 D MmsService: [SendRequest@7178a7d] pdp connect FAIL. result = 1
//网络反馈结果
这部分log来自于main_log中，sys_log中也有关于MmsService的其它信息。

radio logs的分析方法：
1）通过搜索关键字'trySetupData’，可知telephony中pdp连接过程。举例如下：
05-27 16:51:46.304058  1595  1595 D DCT     : [0]onTrySetupData: reason=dataEnabled

05-27 16:52:03.715310  1595  1595 D DCT     : [0]trySetupData: Create from mAllApnSettings : [[ApnSettingV3] TelkomSA, 1632, 65502, internet, , , , , , -1, default | supl, IP, IP, true, 0, 0, 0, false, 0, 0, 0, 0, , ][[ApnSettingV3] 8.ta mms, 1633, 65502, mms, 41.151.254.162, http://mms.:38090/was, 41.151.254.162, 8080, 8080, -1, mms, IP, IP, true, 0, 0, 0, false, 0, 0, 0, 0, , ]
05-27 16:52:03.715424  1595  1595 D DCT     : [0]trySetupData: call setupData, waitingApns : [[ApnSettingV3] TelkomSA, 1632, 65502, internet, , , , , , -1, default | supl, IP, IP, true, 0, 0, 0, false, 0, 0, 0, 0, , ]
05-27 16:52:03.715642  1595  1595 D DCT     : [0]setupData: apnContext={mApnType=default mState=IDLE mWaitingApns={[[ApnSettingV3] TelkomSA, 1632, 65502, internet, , , , , , -1, default | supl, IP, IP, true, 0, 0, 0, false, 0, 0, 0, 0, , ]} mWaitingApnsPermanentFailureCountDown=1 mApnSetting={null} mReason=dataEnabled mDataEnabled=true mDependencyMet=true}

05-27 16:52:03.755364  1595  1595 D DCT     : [0]setupData: dcac=DC-1 apnSetting=[ApnSettingV3] TelkomSA, 1632, 65502, internet, , , , , , -1, default | supl, IP, IP, true, 0, 0, 0, false, 0, 0, 0, 0, ,

05-27 16:52:03.769424  1595  1752 D DC-1    : onConnect: carrier='TelkomSA' APN='internet' proxy='' port=''

05-27 16:52:03.820058  1595  1595 D DCT     : [0]trySetupData: X retValue=true

2）通过搜索关键字'SETUP_DATA_CALL’，可知RIL中pdp连接过程。举例如下：
//终端请求
05-27 16:52:03.770016  1595  1752 D RILJ    : [9328]> SETUP_DATA_CALL 13 0 internet   0 IP 1 [SUB0]
//网络响应
05-27 16:52:13.366334  1595  1732 D RILJ    : [9328]< SETUP_DATA_CALL DataCallResponse: {version=10 status=0 retry=0 cid=0 active=2 type=IP ifname=ccmni0 mtu=0 addresses=[102.249.98.186] dnses=[196.43.38.190,196.43.42.190] gateways=[102.249.98.186] pcscf=[]} [SUB0]

net logs的分析方法：
通过在wireShark搜索栏中输入'mmse’，可抓取MMS的交互帧消息。举例如下：
360    55.329872    10.150.43.27    41.151.254.162    MMSE/SMIL    862    MMS m-send-req (text/plain)
368    56.685525    41.151.254.162    10.150.43.27    MMSE    402    MMS m-send-conf
点击查看帧消息即可。

2、QCOM平台
此类问题的log信息可分为三个方面：app logs、radio logs、QXDM logs.
app logs的分析方法：
1）通过搜索关键字'/Mms-debug’，可知信息应用收发彩信的过程。举例如下：
06-19 18:50:39.114 D/Mms-debug(32140): send MMS button clicked
06-19 18:50:41.211 D/Mms-debug(32140): sendMsimMessage subscription: 1
06-19 18:50:41.212 D/Mms-debug(32140): Send mmsUri: content://mms/drafts/24
06-19 18:50:42.723 D/Mms-debug(32140): Creating TransactionService
06-19 18:50:43.009 D/Mms-debug(32140): launchTransaction: sending message { when=-2h8m39s202ms what=1 arg1=1 obj=transactionType: 2 uri: content://mms/24 pushData: null mmscUrl: null proxyAddress: null proxyPort: 0 subId: 1 target=com.android.mms.transaction.TransactionService$ServiceHandler }
06-19 18:50:43.084 D/Mms-debug(32140): handle EVENT_TRANSACTION_REQUEST: transactionType=2 SEND_TRANSACTION

//发送处理过程
06-19 18:50:43.085 D/Mms-debug(32140): processTransaction: call beginMmsConnectivity on subId = 1
06-19 18:51:23.544 D/Mms-debug(32140): onNewIntent: launch transaction...

//网络反馈
06-19 18:51:43.106 D/Mms-debug(32140): Handling incoming message: { when=-16ms what=7 obj=1 target=com.android.mms.transaction.TransactionService$ServiceHandler } = EVENT_MMS_PDP_ACTIVATION_TIMEOUT
06-19 18:51:43.106 D/Mms-debug(32140): PDP activation timer expired, declare failure sub: 1
06-19 18:51:43.106 D/Mms-debug(32140): onPDPTimeout Remove req sub1
06-19 18:51:43.348 D/Mms-debug(32140): Transaction failed: 1

//尝试重新连接
06-19 18:51:43.318 D/Mms     (32140): set retry alarm
06-19 18:51:43.318 D/Mms-debug(32140): update transaction 1
06-19 18:51:43.318 D/Mms-debug(32140): update: endMmsConnectivity
06-19 18:51:43.770 I/Mms     (32140): isLastRetry retryIndex=1 limit=5

//连接成功
06-19 18:52:19.287 D/Mms-debug(32140): onMmsPdpConnected subId = 1

2）通过搜索关键字'MmsService’，可知信息应用中pdp配置。举例如下：
06-19 18:51:22.979 D/MmsService( 1724): getCarrierConfigValues
06-19 18:51:22.979 I/MmsService( 1724): mms config for sub 1: Bundle[{httpSocketTimeout=60000, aliasMinChars=2, smsToMmsTextThreshold=-1, enableSMSDeliveryReports=true, maxMessageTextSize=-1, supportMmsContentDisposition=true, enabledTransID=false, aliasEnabled=false, supportHttpCharsetHeader=false, allowAttachAudio=true, smsToMmsTextLengthThreshold=-1, recipientLimit=2147483647, uaProfTagName=x-wap-profile, aliasMaxChars=48, maxImageHeight=480, enableMMSDeliveryReports=false, userAgent=, mmsCloseConnection=false, config_cellBroadcastAppLinks=true, maxSubjectLength=40, httpParams=, enableGroupMms=true, emailGatewayNumber=, maxMessageSize=307200, naiSuffix=, enableMMSReadReports=false, maxImageWidth=640, uaProfUrl=, enabledMMS=true, enabledNotifyWapMMSC=false, sendMultipartSmsAsSeparateMessages=false, enableMultipartSMS=true}]

radio logs的分析方法：
1）通过搜索关键字'trySetupData’，可知telephony中pdp连接过程。举例如下：
06-19 18:50:50.062 D/QtiGsmDCT( 1724): [0]onTrySetupData: apnContext={mApnType=mms mState=SCANNING mWaitingApns={[[ApnSettingV3] APN_NAME_CUMMS, 1579, 46001, 3gwap, 10.0.0.172, http://mmsc., 10.0.0.172, 80, 80, -1, mms | default, IPV4V6, IPV4V6, true, 0, 0, 0, false, 0, 0, 0, 0, , , false]} mApnSetting={[ApnSettingV3] APN_NAME_CUMMS, 1579, 46001, 3gwap, 10.0.0.172, http://mmsc., 10.0.0.172, 80, 80, -1, mms | default, IPV4V6, IPV4V6, true, 0, 0, 0, false, 0, 0, 0, 0, , , false} mReason=dataEnabled mDataEnabled=true mDependencyMet=true}
06-19 18:50:50.067 D/QtiGsmDCT( 1724): [0]trySetupData for APN type mms, reason: dataEnabled. Data allowed, reason: NORMAL
06-19 18:50:50.067 D/QtiGsmDCT( 1724): [0]setupData: apnContext={mApnType=mms mState=SCANNING mWaitingApns={[[ApnSettingV3] APN_NAME_CUMMS, 1579, 46001, 3gwap, 10.0.0.172, http://mmsc., 10.0.0.172, 80, 80, -1, mms | default, IPV4V6, IPV4V6, true, 0, 0, 0, false, 0, 0, 0, 0, , , false]} mApnSetting={[ApnSettingV3] APN_NAME_CUMMS, 1579, 46001, 3gwap, 10.0.0.172, http://mmsc., 10.0.0.172, 80, 80, -1, mms | default, IPV4V6, IPV4V6, true, 0, 0, 0, false, 0, 0, 0, 0, , , false} mReason=dataEnabled mDataEnabled=true mDependencyMet=true}
06-19 18:50:50.067 D/QtiGsmDCT( 1724): [0]apnSetting: [ApnSettingV3] APN_NAME_CUNET, 1577, 46001, 3gnet, , , , , 80, -1, default | supl, IPV4V6, IPV4V6, true, 0, 0, 0, false, 0, 0, 0, 0, , , false
06-19 18:50:50.067 D/QtiGsmDCT( 1724): [0]apnSetting: [ApnSettingV3] APN_NAME_CUMMS, 1579, 46001, 3gwap, 10.0.0.172, http://mmsc., 10.0.0.172, 80, 80, -1, mms | default, IPV4V6, IPV4V6, true, 0, 0, 0, false, 0, 0, 0, 0, , , false

06-19 18:50:50.073 D/QtiGsmDCT( 1724): [0]setupData: dcac=DC-3 apnSetting=[ApnSettingV3] APN_NAME_CUMMS, 1579, 46001, 3gwap, 10.0.0.172, http://mmsc., 10.0.0.172, 80, 80, -1, mms | default, IPV4V6, IPV4V6, true, 0, 0, 0, false, 0, 0, 0, 0, , , false gen#=35
06-19 18:50:50.073 D/GsmCdmaPhone( 1724): [GsmCdmaPhone] getDataConnectionState apnType=mms ret=CONNECTING
06-19 18:50:50.081 D/DC-3    ( 1724): onConnect: carrier='APN_NAME_CUMMS' APN='3gwap' proxy='10.0.0.172' port='80'

06-19 18:50:50.143 D/QtiGsmDCT( 1724): [0]trySetupData: X retValue=true

06-19 18:50:50.743 D/DC-3    ( 1724): DcActivatingState onSetupConnectionCompleted result=ERR_RilError  SetupResult.mFailCause=INSUFFICIENT_RESOURCES
06-19 18:50:50.743 D/DC-3    ( 1724): DcActivatingState: ERR_RilError  delay=-2 result=ERR_RilError  SetupResult.mFailCause=INSUFFICIENT_RESOURCES result.isRestartRadioFail=false isPermanentFailure=false
06-19 18:50:50.744 D/QtiGsmDCT( 1724): [0]onDataSetupComplete: error apn=3gwap cause=INSUFFICIENT_RESOURCES

06-19 18:50:50.746 D/QtiGsmDCT( 1724): [0]onDataSetupCompleteError: Try next APN. delay = 11474

2）通过搜索关键字'SETUP_DATA_CALL’，可知RIL中pdp连接过程。举例如下：
//终端请求
06-19 18:52:13.624 D/RILJ    ( 1724): [9842]> SETUP_DATA_CALL,radioTechnology=9,isRoaming=false,allowRoaming=false,DataProfile=0/3gwap/IPV4V6/0///0/0/0/0/true/3/IPV4V6/0/0///false [SUB0]

//网络响应
06-19 18:52:18.952 D/RILJ    ( 1724): [9842]< SETUP_DATA_CALL DataCallResponse: { status=0 retry=-1 cid=1 active=2 type=IPV4V6 ifname=rmnet_data1 mtu=1500 addresses=[10.226.37.184/28] dnses=[] gateways=[10.226.37.185] pcscf=[]} [SUB0]