android 4.0版本手机接受多条短信分析

手机接受多条短信分析

1. 空闲中整理下笔记，先上android 4.0 短信接收多条异常问题处理，再写 android 4.5 的。 

实例：android4.0版本以及以前版本【信息】对比机发送一条短信，手机显示收到2条信息

    测试机接受多条短信时，有时会接受到4，5条不定数目的短信信息。时间间隔不一。

2. 短信接受基本流程

    

 分析一下流程：   

 网络端向moderm发送消息， modem收到一条消息后，上报给SMS的framework，sms的framework再发送order broadcast通知上层app，

 SMS的app处理完后framework再通知modem发送ACK给网络。这是短信接收大致流程。代码后面做分析。

 **  ACK (ACK (Acknowledgement），即确认字符，在数据通信中，接收站发给发送站的一种传输类控制字符。表示发来的数据已确认接受无误。)

 注意：android 4.0 framework发送order broadcast一直到app处理完后framewrok再通知modem发送ACK，这个时间段不能超过8s（根据相关协议规定） 也即SMS的app处理这条有序广播的时间不能超过8s,  如果超过8s则不会通知modem去回复ACK，网络没收到ACK认为终端没有收到该短信，所以会再发送一次，这就是收到重复短信原因。

3.  接受部分流程及部分代码

短信接收，对于偏上层应用程序是要处理广播事件SMS_RECEIVED_ACTION，它是由Frameworks发出告诉上层有新的SMS已收到。

在Mms中，由PrivilegedSmsReceiver来处理，当收到广播SMS_RECEIVED_ACTION(android.provider.Telephony.Intents.SMS_RECEIVED_ACTION=”android.provider.Telephony.SMS_RECEIVED”)

后会启动SmsReceiverService来做具体的处理。

PrivilegedSmsReceiver .java

public class PrivilegedSmsReceiver extends SmsReceiver {

            onReceiveWithPrivilege（）；

}

SmsReceiver.java中

beginStartingService(context, intent);  会去调用 SmsReceiverService.java 进行处理。

此方法内获取一个wake lock 然后启动SmsReceiverService服务

      MmsLog.d(MmsApp.TXN_TAG, "SmsReceiver: onReceiveWithPrivilege(). Slot Id = " 

            + Integer.toString(intent.getIntExtra(EncapsulatedPhone.GEMINI_SIM_ID_KEY, -1), 10)

            +", Action = " + intent.getAction()

            +", result = " + getResultCode());

        intent.setClass(context, SmsReceiverService.class);

        intent.putExtra("result", getResultCode());

        beginStartingService(context, intent);

对应的常见log：

05-29 09:11:28.723844 20407 20407 D Mms/Txn : SmsReceiver: onReceiveWithPrivilege(). Slot Id = 0, Action = android.provider.Telephony.SMS_RECEIVED, result = -1

SmsReceiverService.java中
启动该服务后，会调用onStartCommand方法，该方法传来的Intent为Message的Obj发送一条Message
在handleMessage方法里面通过Intent判断后执行相应的操作，如handleSmsSent，handleSmsReceived，handleBootCompleted，handleServiceStateChanged接受到短信时执行handleSmsReceived方法 private void handleSmsReceived(Intent intent, int error) {        SmsMessage[] msgs = Intents.getMessagesFromIntent(intent);        该方法内通过Intents.getMessagesFromIntent(intent)方法从Intent里面取出Message[]    然后通过insertMessage(this, msgs)方法插入短信insertMessage里通过调用storeMessage方法       Uri messageUri = null;        try {            messageUri = insertMessage(this, intent, error, format);        } catch (IllegalArgumentException e) {            MmsLog.e(TAG, "Save message fail:" + e.getMessage(), e);            return;        }再在storeMessage方法执行values.put(Inbox.BODY, sms.getDisplayMessageBody())方法就可以将短信以ContentValues的形式插入数据库。storeMessage方法如果插入成功将会返回插入短信的Uri，如果此Uri不为Null，说明已经插入数据库，于是在SmsReceiverService.java 中 handleSmsReceived（）中执行MessagingNotification.updateNewMessageIndicator(this, true);该方法则会根据短信的状态，发出提示音或震动，也可以根据设置notification自此，一条新信息就成功接受了。

主要log分析掌握：

//表示接受到短信广播，来了一条短信，
05-29 09:11:28.723844 20407 20407 D Mms/Txn : SmsReceiver: onReceiveWithPrivilege(). Slot Id = 0, Action = android.provider.Telephony.SMS_RECEIVED, result = -1

//短信内容
05-29 09:11:29.820343 20407 20443 D Mms/Txn : handleSmsReceived messageUri: content://sms/35, address: [phone], body: QWERTY

4 .此问题分析关键代码及log信息：

  （1）代码可见SMSDispatcher.java

       private final BroadcastReceiver mResultReceiver = new BroadcastReceiver()   

                    if (rTime != -1) {
                    long curTime = System.currentTimeMillis();
                    Log.d(TAG, "CNMA elplased time: " + (curTime - rTime));
                    if ((curTime - rTime) / 1000 > 8) {
                        Log.d(TAG, "APP process too long");
                    } else {
                        // For a multi-part message, this only ACKs the last
                        // part.
                        // Previous parts were ACK'd as they were received.
                        acknowledgeLastIncomingSms(success, rc, null);
                    }

     收到重复短信一般都是这里发生超时

     可以在radio log搜"APP process too long"，如果有这条trace，表示发生超时了

  （2） 可以在mainLog里查看这条广播被发送出来的时间点是什么，被com.android.mms.transaction.PrivilegedSmsReceiver

    接收到的时间点又是什么，   这之间的时间差就表示过了多少时间才被SMS的app接收到。

 

如下：
------------------------------------
FW发送有序广播的时间点是08:00:31
003314 01-01 08:00:31.587   655  1047 V ActivityManager: Broadcast: Intent { act=android.provider.Telephony.SMS_RECEIVED flg=0x10 (has extras) } ordered=true userid=0

 

app在08:00:40才接收到这个广播，已经过了9s
018183 01-01 08:00:40.753  1193  1193 D ActivityThread: BDC-Calling onReceive: intent=Intent { act=android.provider.Telephony.SMS_RECEIVED flg=0x10 cmp=com.android.mms/.transaction.PrivilegedSmsReceiver (has extras) }, ordered=true, receiver=com.android.mms.transaction.PrivilegedSmsReceiver@413fda90

 

从radio log看到，超时了，不回再通知modem回复ack
04460 01-01 08:00:40.766  1000  1000 D SMS     : CNMA elplased time: 9185
04461 01-01 08:00:40.766  1000  1000 D SMS     : APP process too long
--------------------------------------

05-29 09:11:20.635894  9837  9837 V CooeeShell: SdkReceiver action = android.provider.Telephony.SMS_RECEIVED

05-29 09:11:20.851822  9837  9837 V CooeeShell: NwsR onReceive = android.provider.Telephony.SMS_RECEIVED

05-29 09:11:21.379688 20263 20263 V CooeeShell: SdkReceiver action = android.provider.Telephony.SMS_RECEIVED

05-29 09:11:21.537198 20263 20263 V CooeeShell: NwsR onReceive = android.provider.Telephony.SMS_RECEIVED

05-29 09:11:26.785888 20394 20394 V CallAlarm: onCreate()  intent-->Intent { act=android.provider.Telephony.SMS_RECEIVED flg=0x10 cmp=com.sprd.note/com.huaqin.note.CallAl

05-29 09:11:28.723844 20407 20407 D Mms/Txn : SmsReceiver: onReceiveWithPrivilege(). Slot Id = 0, Action = android.provider.Telephony.SMS_RECEIVED, result = -1

05-29 09:11:29.820343 20407 20443 D Mms/Txn : handleSmsReceived messageUri: content://sms/35, address: [phone], body: QWERTY

05-29 09:16:31.302055  9837  9837 V CooeeShell: SdkReceiver action = android.provider.Telephony.SMS_RECEIVED

05-29 09:16:31.375205  9837  9837 V CooeeShell: NwsR onReceive = android.provider.Telephony.SMS_RECEIVED

05-29 09:16:31.616181 20793 20793 V CooeeShell: SdkReceiver action = android.provider.Telephony.SMS_RECEIVED

05-29 09:16:31.688361 20793 20793 V CooeeShell: NwsR onReceive = android.provider.Telephony.SMS_RECEIVED

05-29 09:16:36.353451 20910 20910 V CallAlarm: onCreate()  intent-->Intent { act=android.provider.Telephony.SMS_RECEIVED flg=0x10 cmp=com.sprd.note/com.huaqin.note.Ca

05-29 09:16:37.561728 20922 20922 D Mms/Txn : SmsReceiver: onReceiveWithPrivilege(). Slot Id = 0, Action = android.provider.Telephony.SMS_RECEIVED, result = -1

05-29 09:22:49.574934  9837  9837 V CooeeShell: SdkReceiver action = android.provider.Telephony.SMS_RECEIVED

05-29 09:22:55.927822 21608 21632 D Mms/Txn : handleSmsReceived messageUri: content://sms/37, address: [phone], body: Wewewewewewe

05-29 09:22:49.853961 21470 21470 V CooeeShell: SdkReceiver action = android.provider.Telephony.SMS_RECEIVED

05-29 09:22:49.937389 21470 21470 V CooeeShell: NwsR onReceive = android.provider.Telephony.SMS_RECEIVED

05-29 09:22:54.860996 21595 21595 V CallAlarm: onCreate()  intent-->Intent { act=android.provider.Telephony.SMS_RECEIVED flg=0x10 cmp=com.sprd.note/com.huaqin.note.Call

05-29 09:22:55.338483 21608 21608 D Mms/Txn : SmsReceiver: onReceiveWithPrivilege(). Slot Id = 0, Action = android.provider.Telephony.SMS_RECEIVED, result = -1

 

5. 短信发生超时有两种可能：
   (1)刚开机就去接收短信，容易发生超时现象，导致接收到重复短信。

       这是因为开机初始化阶段，一定有很多广播要接收和处理，SMS_received是有序广播，容易发生超时现象。

      如果开机后去接收短信发生接收到重复短信，可以在main log里查看ActivityManager打印出来的broadcast，

      一定会看到有大量的广播被接收和处理。
      有可能客户定制了一些广播放在开机阶段去处理，如果是这种情况，需要去掉这些广播再测试看看。
      ( 如果这些广播都是系统的，都是必须要处理的，目前这种情况没有优化方案)
    
   (2）有三方应用在拦截该广播。有可能客户定制了一些apk，这些apk也在接收SMS_RECEIVED的广播，且这些apk定的优先级比较高，

      先收到这个广播，再一层一层往后传递，最后才被com.android.mms.transaction.PrivilegedSmsReceiver接收到，这中间的时间达到8s以上，

      发生 超时。
      如果是这种case，可以在mainLog里搜一下act=android.provider.Telephony.SMS_RECEIVED分别被什么app给接收到，顺序是怎样的，

      客户再自行做代码上的调整。

******android 4.5 以后版本中framework 做了更改，出现接收多条短信分析也改变了，后面会继续写出来。。。