Android 切换prefer APN后建立PDN的日志分析
代码流程
| 流程 | 参考日志 |
|---|---|
| 匹配SIM APN | DPM-0 : Found 8 data profiles. profiles = [[DataProfile |
| 通过RILJ同步APN到Modem | DPM-0 : updateDataProfilesAtModem: RILJ : [5021]> SET_DATA_PROFILE with data profiles : [PHONE0] RILJ : [5021]< SET_DATA_PROFILE [PHONE0] |
| DataProfileManager获取选中上网APN | DPM-0 : getPreferredDataProfileFromDb DPM-0 : Changed preferred data profile to [DataProfile |
| DataProfileManager获取网络请求使用的APN | DPM-0 : getApnSettingForNetworkRequest: |
| TelephonyNetworkFactory处理应用网络请求 | TelephonyNetworkFactory[0]: got request NetworkRequest [ REQUEST id=168, [ Transports: SATELLITE Capabilities: INTERNET&TRUSTED&NOT_VCN_MANAGED Uid: 10152 RequestorUid: 10152 RequestorPkg: com.google.android.apps.messaging UnderlyingNetworks: Null] ] TelephonyNetworkFactory[0]: onNeedNetworkFor [NetworkRequest [ REQUEST id=168, [ Transports: SATELLITE Capabilities: INTERNET&TRUSTED&NOT_VCN_MANAGED Uid: 10152 RequestorUid: 10152 RequestorPkg: com.google.android.apps.messaging UnderlyingNetworks: Null] ], mPriority=20, state=UNSATISFIED, mAttachedDataNetwork=null, isMetered=true, created time=17:10:57.663, evaluation result=null] shouldApply true |
| DataNetworkController处理网络请求（评估&发起PDN） | DNC-0 : onAddNetworkRequest: added [NetworkRequest [ REQUEST id=168, DNC-0 : Data evaluation: evaluation reason:NEW_REQUEST, Data disallowed reasons: DATA_NETWORK_TRANSPORT_NOT_ALLOWED, candidate profile=null, time=17:10:57.674, network type=LTE, reg state=HOME, [NetworkRequest [ REQUEST id=168, [ Transports: SATELLITE 其他evaluation reason： - RETRY_AFTER_DISCONNECTED， - DATA_PROFILES_CHANGED， - DATA_CONFIG_CHANGED， DNC-0 : onSetupDataNetwork: dataProfile=[DataProfile=[ApnSetting] testcarriername, 6652, 50501, testapn, DNC-0 : Creating data network on WWAN with [DataProfile=[ApnSetting] testcarriername, 6652, 50501, testapn, |
| （期间状态变更的通知广播） | TelephonyRegistry: notifyDataConnectionForSubscriber: phoneId=0 subId=1 state: CONNECTING, transport: WWAN, id: -1, netId: 129, network type: LTE, APN Setting: [ApnSetting] testcarriername, 6652, 50501, testapn |
| 由DNC转到对应的DataNetwork处理PDN请求 | DN-129-C: ConnectingState: setupData: accessNetwork=EUTRAN, [DataProfile=[ApnSetting] testcarriername, 6652, 50501, testapn, 
当系统收到 //若已有PDN满足请求，会成功分配，无需新PDN setup DN-129-C: ConnectingState: Successfully attached network request [NetworkRequest [ BACKGROUND_REQUEST id=2, [ Transports: CELLULAR Capabilities: INTERNET&NOT_RESTRICTED&TRUSTED&NOT_VPN&NOT_VCN_MANAGED&NOT_BANDWIDTH_CONSTRAINED RequestorUid: 1000 RequestorPkg: android UnderlyingNetworks: Null] ], mPriority=20, state=SATISFIED, mAttachedDataNetwork=DN-129-C, isMetered=true, created time=14:06:11.241 |
| 通过RILJ将PDN请求下发modem并返回结果 | RILJ : [5058]> SETUP_DATA_CALL,reason=NORMAL,accessNetworkType=EUTRAN,dataProfile=[DataProfile=[ApnSetting] testcarriername, 6652, 50501, testapn, RmmDcEvent: [0][requestSetupDataCall] apn=testapn, apnIndex=5, profile=default, protocol=IP DataServiceCallback: onSetupDataCallComplete RILJ : [5058]< SETUP_DATA_CALL DataCallResponse: { cause=SERVICE_OPTION_NOT_SUBSCRIBED(0x21) retry=720000 cid=-1 |
| DataNetworkController收到PDN建立响应结果 | DNC-0 : onDataNetworkSetupDataFailed: [DataNetwork: DN-129-C, Telstra.test, state=null], cause=SERVICE_OPTION_NOT_SUBSCRIBED(0x21) |
| DataRetryManager处理PDN建立失败结果，发起重连 | DRM-0 : onEvaluateDataSetupRetry: [DataProfile=[ApnSetting] testcarriername, 6652, 50501, testapn, DRM-0 : Add throttling entry [DataThrottlingEntry: dataProfile=[DataProfile=[ApnSetting] |
| 切换APN | CarrierResolver: [updatePreferApn] from:xxxx to:testapn |
| 重新发起PDN建立，会断开已有连接，后面的请求在PDN建立成功后分配 | |
| 应用释放网络请求 | TelephonyNetworkFactory[0]: onReleaseNetworkFor [NetworkRequest [ REQUEST id=168, [ Transports: SATELLITE Capabilities: INTERNET&TRUSTED&NOT_VCN_MANAGED Uid: 10152 RequestorUid: 10152 RequestorPkg: com.google.android.apps.messaging UnderlyingNetworks: Null] ], mPriority=20, state=UNSATISFIED, mAttachedDataNetwork=null, isMetered=true, created time=17:11:32.393, evaluation result=null] applied true |
常见问题/误区
Q：为什么PDN没有建立成功DataNetwork就可以“Successfully attached network request”？
A：TelephonyRegistry负责通知数据连接状态变化，CONNECTING状态表示正在尝试建立数据连接（PDN），某请求在特定ID的DataNetwork中Successfully attached 仅表示某个应用的网络请求已绑定到了相应的DataNetwork实例，不表示 PDN 已激活。
1. DN-ID-C是DataNetwork 实例的唯一标识符，由DataNetworkController在响应网络请求时动态创建，ID是自增计数器（如DN-130-C）。
2. 当系统收到 NetworkRequest（如默认上网请求）且当前无匹配的活跃 DataNetwork 时，会创建新实例并进入 ConnectingState。
Q：那么TelephonyRegistry、TNA（TelephonyNetworkAgent）DN、DNC、DSM、DRM（DataRetryManager）等对象/管理类的工作先后顺序是什么？调用链关系如何？
- TNA-130 : TelephonyNetworkAgent created, nc=[ Transports: CELLULAR Capabilities:
- TelephonyRegistry: notifyDataConnectionForSubscriber: phoneId=0 subId=1 state: CONNECTING, transport: WWAN, id: -1, netId: 130, network type: LTE
- RILJ : [5085]< SETUP_DATA_CALL DataCallResponse
- DataServiceCallback: onSetupDataCallComplete
- DSM-C-0 : onSetupDataCallComplete. resultCode = 0, response = DataCallResponse
- DN-130-C: ConnectingState: onSetupResponse: resultCode=RESULT_SUCCESS,
日志分析
// 用户在界面新增APN并切换选中
04-01 20:10:48.410602 16039 16039 D ApnEditor: name: testapn: Telstra.testmcc: 505mnc01
04-01 20:10:55.181980 16039 16039 D ApnSettings: onPreciseDataConnectionStateChanged: state=5 mRestoreDefaultApnMode=false
04-01 20:10:55.181849 16039 16039 D ApnSettings: setPreferApnChecked, APN = 5120 //回到APN列表界面自动选中的
04-01 20:10:56.864038 16039 16039 D ApnSettings: onPreferenceChange(): Preference - test Telstra.test, newValue - 6652, newValue type - clas