Android RIL 调试分析全记录

以前没有调试过RIL的东西, 从零开始, 花了两周时间,终于拨号成功,这里发表出来与大家共享经验,少走弯路.

上一篇文章是一个成功拨号的Android RIL log, 这里主要结合上一篇log进行分析, 分享一些注意事项, 由于时间有限,尽量言简意概, 主要要自己尝试去实践才会有所收获。

（本文所指的log行号，是指上一篇文章所标记的行号）

1. 所要了解的一些源码及脚本文件：

android/hardware/ril/reference_ril/ (reference_ril.c)

android/hardware/ril/rild

android/extern/ppp/pppd

android/extern/ppp/chat

android/data/etc/apn-conf-sdk.xml

android/system/core/rootdir/etc/ppp/init.gprs-pppd

android/system/core/rootdir/etc/ppp/peers/cmnet

android/system/core/rootdir/etc/ppp/chat/cmtc-isp

android/vendor/xxxxx/xxxx/system.prop

reference_ril.c: RIL的一些AT命令操作，通过一些onRequest接口操作，对不同的硬件，需作一些修改调整。

apn-conf-sdk.xml: 以下是一个例子，有些不支持的APN，需要自己加上去，否则在log 中会出现类似：No APN found for carrier: 46xxx, 的错误。一般移动的TD USIM是46007,

有些是46000.

<apns version="6">

<apn carrier="Android"

mcc="310"

mnc="995"

apn="internet"

user="*"

server="*"

password="*"

mmsc="null"

/>

<apn carrier="TelKila"

mcc="310"

mnc="260"

apn="internet"

user="*"

server="*"

password="*"

mmsc="null"

/>

<apn carrier="CMCC"

mcc="460"

mnc="00"

apn="cmnet"

user="*"

server="*"

password="*"

mmsc="null"

/>

<apn carrier="CHINA MOBILE"

mcc="460"

mnc="07"

apn="cmnet"

user="*"

server="*"

password="*"

mmsc="null"

/>

</apns>

init.gprs-pppd: 调用pppd GPRS拨号的初始化脚本。

PPPD_PID=

/system/bin/setprop "net.gprs.ppp-exit" ""

/system/bin/log -t pppd "Starting pppd"

/system/xbin/pppd call cmnet $*

PPPD_EXIT=$?

PPPD_PID=$!

/system/bin/log -t pppd "pppd exited with $PPPD_EXIT"

/system/bin/setprop "net.gprs.ppp-exit" "$PPPD_EXIT"

cmnet：pppd拨号option脚本：

/dev/ttyACM2

921600

nocrtscts

nocdtrcts

local

usepeerdns

defaultroute

noipdefault

ipcp-accept-local

ipcp-accept-remote

user cmnet

password cmnet

lock

nodetach

connect "/system/xbin/chat -v -t 50 -f /system/etc/ppp/chat/cmtc-isp"

cmtc-isp：

ABORT 'BUSY'

ABORT 'NO CARRIER'

ABORT 'ERROR'

ABORT '+CME ERROR: 100'

"" AT

OK AT+CGDCONT=1,"IP","CMNET"

OK AT+CGEQREQ=1,2,128,384,0,0,0,0,"0E0","0E0",,0,0

OK AT

OK AT

OK ATS0=0

OK AT

OK AT

OK ATDT*98*1#

CONNECT

system.prop

rild.libpath=/system/lib/libreference-ril.so

rild.libargs=-d /dev/ttyACM0

2. 所要具备的调试工具：

microcom: 可在linux下通过发送AT命令调试硬件模块，在较新版本busybox中可以找到此模块。如命令：

#./microcom -t 12000 /dev/ttyACM0

注： -t 12000 为延迟退出ms时间，不宜太长时间，时间太长，会感觉 像死机，时间太短，经常会命令没输完就退出了。

ppp(pppd, chat)：可手拨号连接GPRS，如命令：

# pppd call cmnet &

3. 设备文件

1)/dev/ttyACM0, /dev/ttyACM1, /dev/ttyACM2

这是usb transceiver 模拟串口的设备文件，如果是直接串口连接，可能是/dev/ttyS0, /dev/mux0等。

2) #ifconfig ppp0

GPRS连接上后，会出现ppp0的网络接口，用如上命令可以查看ppp0网络接口属性。

4. 常用AT命令，具体可以查《中国移动宽带随e 行客户端软件A T命令接口规范》

AT+CFUN

AT+CREG

AT+CGREG

AT

AT+COPS

AT+CPIN

AT+CIMI

AT^SYSCONFIG

ATD

AT+CGDCONT

AT+CGEQREQ

AT+CSQ

5. RIL启动过程分析

如果硬件模块驱动配置成功，在/dev目录下会出现类似于ttyACM0，ttyS0等的设备文件 。

1-36行： 初始化过程，设备文件由system.prop属性文件决定，

40行： D/RILJ ( 110): [0000]> SCREEN_STATE 这里开始了第一个onRequest,

然后会开始一系列的onRequest:

40 D/RILJ ( 110): [0000]> SCREEN_STATE

49 D/RILJ ( 110): [0001]> RADIO_POWER

62 D/RILJ ( 110): [0002]> BASEBAND_VERSION

63 D/RILJ ( 110): [0003]> GET_IMEI

64 D/RILJ ( 110): [0004]> GET_IMEISV

65 D/RILJ ( 110): [0005]> REQUEST_GET_ACCESS_MODE

83 D/RILJ ( 110): [0006]> OPERATOR

84 D/RILJ ( 110): [0007]> GPRS_REGISTRATION_STATE

85 D/RILJ ( 110): [0008]> REGISTRATION_STATE

86 D/RILJ ( 110): [0009]> QUERY_NETWORK_SELECTION_MODE

87 D/RILJ ( 110): [0010]> GET_CURRENT_CALLS

88 D/RILJ ( 110): [0011]> OPERATOR

91 D/RILJ ( 110): [0012]> GPRS_REGISTRATION_STATE

96 D/RILJ ( 110): [0013]> REGISTRATION_STATE

97 D/RILJ ( 110): [0014]> QUERY_NETWORK_SELECTION_MODE

100 D/RILJ ( 110): [0015]> OPERATOR

101 D/RILJ ( 110): [0016]> GPRS_REGISTRATION_STATE

102 D/RILJ ( 110): [0017]> REGISTRATION_STATE

103 D/RILJ ( 110): [0018]> QUERY_NETWORK_SELECTION_MODE

104 D/RILJ ( 110): [0019]> SET_NETWORK_SELECTION_AUTOMATIC

105 D/RILJ ( 110): [0020]> OPERATOR

106 D/RILJ ( 110): [0021]> GPRS_REGISTRATION_STATE

107 D/RILJ ( 110): [0022]> REGISTRATION_STATE

108 D/RILJ ( 110): [0023]> QUERY_NETWORK_SELECTION_MODE

116 D/RILJ ( 110): [0024]> getIMSI:RIL_REQUEST_GET_IMSI 11 GET_IMSI

117 D/RILJ ( 110): [0025]> GET_SIM_STATUS

118 D/RILJ ( 110): [0026]> QUERY_FACILITY_LOCK

119 D/RILJ ( 110): [0027]> QUERY_FACILITY_LOCK

239 D/RILJ ( 110): [0028]> OPERATOR

240 D/RILJ ( 110): [0029]> GPRS_REGISTRATION_STATE

241 D/RILJ ( 110): [0030]> REGISTRATION_STATE

242 D/RILJ ( 110): [0031]> QUERY_NETWORK_SELECTION_MODE

248 D/RILJ ( 110): [0032]> OPERATOR

249 D/RILJ ( 110): [0033]> GPRS_REGISTRATION_STATE

250 D/RILJ ( 110): [0034]> REGISTRATION_STATE

251 D/RILJ ( 110): [0035]> QUERY_NETWORK_SELECTION_MODE

以上onRequest不一定都是必须的，如果GPRS_REGISTRATION_STATE，REGISTRATION_STATE出现的注册状态为：

AT< +CGREG: 1,1

AT< +CREG: 2,1,"a834","5692"

那么你的恭喜你网络注册成功了，如果出现

AT< +CGREG: 1,0

AT< +CREG: 2,0

那么要查一下为什么注册不成功，检查一下SIM插好没，我发现AT+CFUN=4命令有可能会影响到后来的网络注册。

如果网络没有注册，不会出现以下连接信息

295 D/GSM ( 110): [DataConnectionTracker] ***trySetupData due to gprsAttached

如果出现此条信息，那么恭喜你又进了一步，要开始下一步ppp拨号上网了，

通过 #logcat &命令，会看到

I/pppd ( 140): Starting pppd

如果拨号成功，会出现如下信息：

Serial connection established.

Using interface ppp0

Connect: ppp0 <--> /dev/ttyACM2

Remote message: Login OK

PAP authentication succeeded

local IP address 10.77.154.38

remote IP address 192.200.1.21

primary DNS address 211.136.112.50

secondary DNS address 211.136.20.203

这时候网络连接成功，radio log会出现如下信息，

327 D/GSM ( 110): [DataConnectionTracker] setState: CONNECTED

这时候就可以放松一下了，郁闷期已过，剩下的稳定性的问题可以慢慢调试了。

ping 一下www.google.com

#ping www.google.com

出现：

PING www.l.google.com (64.233.189.99) 56(84) bytes of data.

64 bytes from hkg01s01-in-f99.1e100.net (64.233.189.99): icmp_seq=1 ttl=242 time=196 ms

64 bytes from hkg01s01-in-f99.1e100.net (64.233.189.99): icmp_seq=2 ttl=242 time=189 ms

64 bytes from hkg01s01-in-f99.1e100.net (64.233.189.99): icmp_seq=3 ttl=242 time=195 ms

64 bytes from hkg01s01-in-f99.1e100.net (64.233.189.99): icmp_seq=4 ttl=242 time=199 ms

64 bytes from hkg01s01-in-f99.1e100.net (64.233.189.99): icmp_seq=5 ttl=242 time=203 ms

64 bytes from hkg01s01-in-f99.1e100.net (64.233.189.99): icmp_seq=6 ttl=242 time=196 ms

64 bytes from hkg01s01-in-f99.1e100.net (64.233.189.99): icmp_seq=7 ttl=242 time=187 ms

#ifconfig ppp0

出现ppp0接口属性。

6. 所遇问题分析总结：

1）No APN found for carrier: 46xxx

改一下apn-conf-sdk.xml文件吧，将所对应的46xxx的APN信息写入即可。

2) 网络注册失败，出现：

AT+CGREG?

+CGREG: 1,0

和

AT+CREG?

+CREG: 2,0

我发现有几种情况：

1>没插SIM卡；

2>信号不好（一般3G出现低于100的信号值，说明信号强度太差，无法注册）；

3>AT+CFUN＝4关机命令，即使后面用了AT+CFUN=1开机，可能因为开机需要时间延迟，造成无法注册，这是我发现的比较诡异的地方，需要咨询一下供应商。

3）pppd call cmnet: connect script failed! pppd exited with 8

发现出现这个错误的原因比较复杂，不一定是真正的cmnet与cmtc-isp两个脚本的问题，按我的经验发现，如果connect script failed!错误出现紧跟着Starting pppd, 那应该是

真正的脚本有问题；如果间隔时间较长，那就不应该是脚本的问题了，脚本语法问题程序很快能检查出来，通常这样的可能是通道通信的问题，rild与pppd用的同一个串

口通道，也可能造成这个错误，通常都会有2-3个通道，换成另一个tty通道就可以了，我想了如下一个办法来调试这个错误：

1>删除文件/etc/init.gprs-pppd，重启后，系统不会用pppd自动拨号；

2>手动拨号， 运行如下命令：

#pppd call cmnet &

第一次运行会出现错误：

Removed stale lock on ttyACM2 (pid 259)

Failed to open /dev/ttyACM2: I/O error

再运行一次：

Serial connection established.

Using interface ppp0

Connect: ppp0 <--> /dev/ttyACM2

Remote message: Login OK

PAP authentication succeeded

local IP address 10.77.48.209

remote IP address 192.200.1.21

primary DNS address 211.136.112.50

secondary DNS address 211.136.20.203

目前还不知道为什么这样，正在查，有高手可以指点一下。

另外出现这个问题可能还有其它原因，按出现的时间来看，我认为是比较好的一个排查问题的方法。

附：与xxxx聊天解决问题记录，以供大家参考，可能会有点用(注意，时间要从下往上看呀)

在 2010年12月24日 下午4:43，xxxx写道：

另外，还有一些问题：

我现在这种上网是跟android完全没有关系的。还没有跟上层完成数据传输。

要完成跟上层的数据传输，就必需要实现要正确的返回我刚才问你的那个问题“GET_IMEI”, "GET_IMSI"，

因为这两个返回了，android才能完成与apns-conf.xml文件中的numeric值的匹配。

麻烦指点下，我上面这个理解对不对。还有你现在的apns-conf.xml中主数据可以写入telephony.db数据库吗？

在 2010年12月24日 下午4:39，xxxx写道：

方便就留个联系方式，改天请你吃个便饭。交个朋友。

在 2010年12月24日 下午4:29，xxxx写道：

恩。这个必需的。。。

你也在深圳吧？

在 2010年12月24日 下午4:29，xxxx写道：

# ping 220.181.112.76

PING 220.181.112.76 (220.181.112.76) 56(84) bytes of data.

64 bytes from 220.181.112.76: icmp_seq=1 ttl=50 time=2646 ms

64 bytes from 220.181.112.76: icmp_seq=2 ttl=50 time=1659 ms

64 bytes from 220.181.112.76: icmp_seq=3 ttl=49 time=679 ms

64 bytes from 220.181.112.76: icmp_seq=5 ttl=49 time=185 ms

64 bytes from 220.181.112.76: icmp_seq=6 ttl=50 time=181 ms

64 bytes from 220.181.112.76: icmp_seq=7 ttl=49 time=198 ms

64 bytes from 220.181.112.76: icmp_seq=8 ttl=49 time=185 ms

64 bytes from 220.181.112.76: icmp_seq=9 ttl=50 time=202 ms

原来什么都不用设置就可以拨号成功了？和linux下面的是一样的，只是这么弄好像上层根本响应不到。

在 2010年12月24日 下午4:26，xxxx写道：

I/pppd ( 2319): Connect: ppp0 <--> /dev/ttyUSB5

D/pppd ( 2319): sent [LCP ConfReq id=0x1 <asyncmap 0x0> <magic 0x7b8e6e14> <pcomp> <accomp>]

D/pppd ( 2319): rcvd [LCP ConfReq id=0x0 <mru 1500> <asyncmap 0xffffffff> <auth pap> <magic 0x11223344> <pcomp> <accomp>]

D/pppd ( 2319): No auth is possible

D/pppd ( 2319): sent [LCP ConfRej id=0x0 <auth pap>]

D/pppd ( 2319): rcvd [LCP ConfAck id=0x1 <asyncmap 0x0> <magic 0x7b8e6e14> <pcomp> <accomp>]

D/pppd ( 2319): rcvd [LCP ConfReq id=0x1 <mru 1500> <asyncmap 0xffffffff> <magic 0x11223344> <pcomp> <accomp>]

D/pppd ( 2319): sent [LCP ConfAck id=0x1 <mru 1500> <asyncmap 0xffffffff> <magic 0x11223344> <pcomp> <accomp>]

D/pppd ( 2319): sent [CCP ConfReq id=0x1 <deflate 15> <deflate(old#) 15> <bsd v1 15>]

D/pppd ( 2319): sent [IPCP ConfReq id=0x1 <compress VJ 0f 01> <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns3 0.0.0.0>]

D/pppd ( 2319): rcvd [LCP ProtRej id=0x2 80 fd 01 01 00 0f 1a 04 78 00 18 04 78 00 15 03 2f]

D/pppd ( 2319): sent [IPCP ConfReq id=0x1 <compress VJ 0f 01> <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns3 0.0.0.0>]

D/pppd ( 2319): rcvd [IPCP ConfReq id=0x3 <addr 192.168.0.1>]

D/pppd ( 2319): sent [IPCP ConfAck id=0x3 <addr 192.168.0.1>]

D/pppd ( 2319): rcvd [IPCP ConfRej id=0x1 <compress VJ 0f 01>]

D/pppd ( 2319): sent [IPCP ConfReq id=0x2 <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns3 0.0.0.0>]

D/pppd ( 2319): rcvd [IPCP ConfNak id=0x2 <addr 10.233.0.103> <ms-dns1 120.196.165.7> <ms-dns3 221.179.38.7>]

D/pppd ( 2319): sent [IPCP ConfReq id=0x3 <addr 10.233.0.103> <ms-dns1 120.196.165.7> <ms-dns3 221.179.38.7>]

D/pppd ( 2319): rcvd [IPCP ConfAck id=0x3 <addr 10.233.0.103> <ms-dns1 120.196.165.7> <ms-dns3 221.179.38.7>]

I/pppd ( 2319): local IP address 10.233.0.103

I/pppd ( 2319): remote IP address 192.168.0.1

I/pppd ( 2319): primary DNS address 120.196.165.7

I/pppd ( 2319): secondary DNS address 221.179.38.7

兄弟，看起来是不是已经成功了啊。

在 2010年12月24日 下午4:11，xxxx写道：

我是在深圳的，你呢？

已经开始拨号了，注意以下几个设置：

1. tty端口设置，一般会有3个虚拟端口，各有用处，咨询模块厂商；

：恩。我们这个是TD模块，有5个端口，实际只用了3个，你说的BUSY这种情况应该是对的，因为我现在AT是用的ttyUSB5，刚才我的拨号脚本也是用的ttyUSB5。我觉得应该是这个问题吧。

2. 拨号脚本配置，咨询模块厂商；

：这个脚本应该不是问题，因为我在linux下面已经可以拨号上网了。用这两个脚本。

在 2010年12月24日 下午4:05，wenfeng cao <[e-mail]>写道：

已经开始拨号了，注意以下几个设置：

1. tty端口设置，一般会有3个虚拟端口，各有用处，咨询模块厂商；

2. 拨号脚本配置，咨询模块厂商；

在 2010年12月24日 下午4:01，xxxx写道：

我现在改的/etc/apns-conf.xml中已经有了中国移动的，但是/data/data//data/data/com.android.providers.telephony/databases/telephony.db中没有生成对应的记录。

然后按你说的直接拨号，提示下面的错误。。

I/pppd ( 2261): Starting pppd

I/chat ( 2265): chat_send (BUSY)

I/chat ( 2265): abort on (BUSY)

I/chat ( 2265): chat_send (NO CARRIER)

I/chat ( 2265): abort on (NO CARRIER)

I/chat ( 2265): chat_send (ERROR)

I/chat ( 2265): abort on (ERROR)

I/chat ( 2265): chat_send (AT+CGDCONT=1,"IP","cmnet")

I/chat ( 2265): send (AT+CGDCONT=1,"IP","cmnet"^M)

I/chat ( 2265): expect (OK)

I/chat ( 2265): alarm

I/chat ( 2265): Failed

E/pppd ( 2263): Connect script failed

I/pppd ( 2274): pppd exited with 8

在 2010年12月24日 下午3:38，wenfeng cao <[e-mail]>写道：

framework, java层调用过来的, 直接把中移动的加进去试试吧。

在 2010年12月24日 下午3:35，xxxx写道：

你的意思是我直接改/development/data/etc/apns-conf_sdk.xml这个文件是吧？

能否指点下，这个文件最后生成的文件系统的目录下的/system/etc/apns-conf.xml文件，跟拨号上网的关系在代码中体现在哪里啊？

也就是说我用PPPD拨号的时候，哪里调用到了这个apns-conf.xml文件中的信息了。

在 2010年12月24日 下午3:27，wenfeng cao <[e-mail]>写道：

直接找到那个配置xml文件吧，APN写数据库不一定好使，应该要修改framework!

在 2010年12月24日 下午3:25，xxxx写道：

如果这个问题不解决，在 ”设置/无线和网络设置/移动网络设置/接入点名称“ 设置里面显示不出来我设置的APN

另外，我是参考这篇文章设置的APN，但是写入数据库没有成功。很奇怪。

http://myqdroid.blog.51cto.com/2057579/389134

在 2010年12月24日 下午2:31，wenfeng cao <[e-mail]>写道：

D/AT ( 2034): AT< +CGREG: 1,1

D/AT ( 2034): AT< OK

D/AT ( 2034): AT< +CREG: 2,1,"a563","c46b"

D/AT ( 2034): AT< OK

感觉网络注册成功了，你这个应该不算什么致命错误，

试着配置ＡＰＮ，拨号看看，

你的ＡＰＮ还没有配置，直接在xml文件里里配置一下吧，

在 2010年12月24日 下午2:19，xxxx写道：

卡肯定是插了，只是SIM卡检测好像是有点问题。因为我安装了一个Hidroid的设置APN的工具，它提示“无法检测到SIM卡”，但是我的SIM ready已经打印出来了。

我给你发了一个日志文件，logcat -b radio

在 2010年12月24日 下午1:12，wenfeng cao <[e-mail]>写道：

参看我博客这段log吧，不会是没插入SIM吧，感觉IMEI你已经读到了呀

73 D/RIL ( 56): onRequest: GET_IMEI

74 D/AT ( 56): AT> AT+CGSN

75 D/GSM ( 110): Notifying: Radio On

76 D/RILJ ( 110): [UNSL]< UNSOL_RESPONSE_RADIO_STATE_CHANGED SIM_NOT_READY

77 D/RILJ ( 110): [UNSL]< UNSOL_RESPONSE_NETWORK_STATE_CHANGED

78 V/RILJ ( 110): [UNSL]< RIL_UNSOL_ACCESS_MODE_CHANGED {2}

79 D/GSM ( 110): Notifying: SIM ready

80 D/RILJ ( 110): [UNSL]< UNSOL_RESPONSE_RADIO_STATE_CHANGED SIM_READY

。。。。

在 2010年12月24日 下午1:07，wenfeng cao <[e-mail]>写道：

那是这条AT命令错误了，用microcom串口工具调一下吧，看看ＡＴ命令有没有语法问题。

AT+CGSN

在 2010年12月24日 上午10:15，xxxx写道：

Hi wenfeng,

那个问题我刚看了一下，错误是在下面这里返回的：

@reference-ril.c

case RIL_REQUEST_GET_IMEI:

p_response = NULL;

err = at_send_command_numeric("AT+CGSN", &p_response);

// 因为这里返回的err = -6 所以在这里就报错了

if (err < 0 || p_response->success == 0) {

RIL_onRequestComplete(t, RIL_E_GENERIC_FAILURE, NULL, 0);

} else {

RIL_onRequestComplete(t, RIL_E_SUCCESS,

p_response->p_intermediates->line, sizeof(char *));

}

at_response_free(p_response);

break;

目前还不太清楚具体原因是什么。。

:-(

在 2010年12月22日 下午2:43，wenfeng cao <[e-mail]>写道：

那得到com.android.internal.telephony中跟踪一下java代码，打印一下ＬＯＧ，

看一下在哪里出现异常了。

在 2010年12月22日 上午11:24，xxxx写道：

非常感谢，这么快回复我，我已经测试过了，没有问题，你看下面的LOG也已经打出来了，AT返回是正确的。只是好像上层没有收到这个数据。。

在 2010年12月22日 上午10:49，wenfeng cao <[e-mail]>写道：

用microcom串口调试工具对ＡＴ命令测试一下吧

在 2010年12月22日 上午10:06，xxxx写道：

Hi, wenfeng:

我现在在获取IMEI和IMSI的时候遇到一点问题，想请教一下：

现在的问题上层RILJ发送请求。RILD已经收到，也正确返回，但是RILJ处理响应时出现异常，LOG如下：

1. GET_IMEI出错：

D/RILJ ( 2108): [0004]> GET_IMEI

D/RIL ( 2032): onRequest: GET_IMEI

D/AT ( 2032): AT> AT+CGSN

D/AT ( 2032): AT< +CGSN: 860103005026647

D/AT ( 2032): AT< OK

D/RILJ ( 2108): [0004]< GET_IMEI error: com.android.internal.telephony.CommandException: GENERIC_FAILURE

2. GET_IMSI出错：

D/RILJ ( 2108): [0020]> getIMSI:RIL_REQUEST_GET_IMSI 11 GET_IMSI

D/RIL ( 2032): onRequest: GET_IMSI

D/AT ( 2032): AT> AT+CIMI

D/AT ( 2032): AT< +CIMI: 460077119750323

D/AT ( 2032): AT< OK

com.android.internal.telephony.CommandException: GENERIC_FAILURE

看起来这两个问题比较类似。