## 日志检查


### 测试用例

[机场优化测试用例](https://bytedance.larkoffice.com/sheets/W28ns1pGhhvweAtFLZEcOH6PnJe?sheet=BUTOSG)

### 李阳
did  3687099404745305
```log
07-03 08:44:49.757  5894  6490 E MatrixTeaManager: MatrixOnesSdk: getDeviceId 有值，立即回调 3687099404745305
```

### Sensor 指标
起飞和降落识别准确, 误差不超过1分钟.

bytedanceSensor 起飞和降落
07-03 11:16:25.093  9870 10201 D NetworkBrainStateMachine.IdleState: EVENT_AIRPORT_ENTER
07-03 14:54:17.653  9870 10201 D NetworkBrainStateMachine.AirportState: EVENT_AIRPORT_EXIT

CA111航班07-03实际起飞和降落
起飞: 11:15
着陆: 14:54

![CA111 07-03 liyang](./did_liyang/CA111_07-03_liyang.png)


### GPS 指标
- 测试用例里没有强调在设置或下拉菜单里开启GPS, 导致依赖GPS的机场数据库sqlite查询失效, 只能使用fallback NFL 频率.

```log
07-03 11:16:25.094  9870 10201 E NetworkBrainStateMachine.AirportState: [EVENT_AIRPORT] skip fill cellular context location, reason=latest resolved location is empty, oemAirportState=FLYING(1)
07-03 11:16:25.115  9870 10201 D NetworkBrainStateMachine.AirportState: [EVENT_AIRPORT] request location dispatched, reason=enter
07-03 11:47:12.369  3634  3634 W LocationManagerService: location noteOp with location off - 1000/android
07-03 12:55:18.965  8413   794 E CommSenseLog: <StarLocation-util> [getCurLocation] mLocationManager is null or provider is disabled
```

[] 当前机场优化依赖GPS, 因此GPS的开关状态, 每次GPS请求后的成功失败结果, 应该也做成埋点.



### 埋点功能
- 测试用例里没有强调落地后连接 wifi, 导致埋点没有正确上报.

```log
07-03 14:56:17.740  9870 10201 I AirportStatsUtils: [EVENT_AIRPORT] report airport PB, bytes=505, oemWakeupType=-1, 
oemGroundTs=20260703 14:54:17, 
oemFlyingTs=20260703 11:16:25, 
oemLandingTs=N/A, 
qcomWakeupType=-1, qcomInFlightTs=N/A, qcomLandingTs=N/A, 
autoRadioOffActions=0, nflCmapiUpdateActions=2, manualRadioOffActions=0, slowOosScanActions=26, sqliteLookupActions=0, landingOptActions=0, sensorRegisterActions=0, 
networkRecoveryBeginTs=20260703 14:54:17, DdsSlot=0, 
Slot0InServiceMs=-1/-1/N/N/A/20260701 00:49:38, 
Slot1InServiceMs=-1/-1/N/N/A/20260701 00:49:38, 
takeoffContext=event=1@20260703 11:16:25, hasResolvedGeo=false, hasLocation=false, servingCells=2, inServiceCells=2, lteNflSize=-1, nrNflSize=-1, landingContext=event=0@20260703 14:54:17, hasResolvedGeo=false, hasLocation=false, servingCells=2, inServiceCells=1, lteNflSize=-1, nrNflSize=-1
```

[] 修改 radioservice, 删除给modemdebug 发送 pb 的逻辑.
```log
07-03 10:33:33.962  9870  9870 I AirportStatsUtils: [EVENT_AIRPORT] send airport PB to ModemDebug, reason=dashboard_request, bytes=286, reportTs=20260703 06:33:04
```

### AP 优化逻辑


[x] 检查异常的反复设置 slow scan 行为的原因
原因: `manualRadioOffActions=0`, 这次测试时, 用户没有手动开启飞行模式. 在空中,服务状态并不是预期的长时间稳定无信号, 而是有零星的信号, 导致 OosTimmr 被不断重启, 因此看到多次设置 slow scan 的行为.

[] 修改方案: 如果已经设置过一次Slow Scan, 并且没有恢复. 不需要重复设置.

详情:
```log
07-03 11:25:10.735  9870 10201 D NetworkBrainStateMachine.AirportState: [EVENT_AIRPORT] setOutOfServiceScanState slot=0 scanState=0
07-03 11:25:10.745  9870 10201 D NetworkBrainStateMachine.AirportState: [EVENT_AIRPORT] setOutOfServiceScanState slot=1 scanState=0
07-03 11:25:10.746  9870 10201 D NetworkBrainStateMachine.AirportState: [EVENT_AIRPORT] TIMER skip airport auto radio-off ON because cloud control disabled
07-03 11:40:12.350  9870 10201 D NetworkBrainStateMachine.AirportState: [EVENT_AIRPORT] setOutOfServiceScanState slot=0 scanState=0
07-03 11:40:12.357  9870 10201 D NetworkBrainStateMachine.AirportState: [EVENT_AIRPORT] setOutOfServiceScanState slot=1 scanState=0
07-03 11:40:12.360  9870 10201 D NetworkBrainStateMachine.AirportState: [EVENT_AIRPORT] TIMER skip airport auto radio-off ON because cloud control disabled
07-03 11:46:25.183  9870 10201 D NetworkBrainStateMachine.AirportState: [EVENT_AIRPORT] request location dispatched, reason=periodic
07-03 12:16:25.276  9870 10201 D NetworkBrainStateMachine.AirportState: [EVENT_AIRPORT] request location dispatched, reason=periodic
07-03 12:17:47.289  9870 10201 D NetworkBrainStateMachine.AirportState: [EVENT_AIRPORT] setOutOfServiceScanState slot=0 scanState=0
07-03 12:17:47.298  9870 10201 D NetworkBrainStateMachine.AirportState: [EVENT_AIRPORT] setOutOfServiceScanState slot=1 scanState=0
07-03 12:17:47.302  9870 10201 D NetworkBrainStateMachine.AirportState: [EVENT_AIRPORT] TIMER skip airport auto radio-off ON because cloud control disabled
07-03 12:26:45.091  9870 10201 D NetworkBrainStateMachine.AirportState: [EVENT_AIRPORT] setOutOfServiceScanState slot=0 scanState=0
07-03 12:26:45.095  9870 10201 D NetworkBrainStateMachine.AirportState: [EVENT_AIRPORT] setOutOfServiceScanState slot=1 scanState=0
07-03 12:26:45.097  9870 10201 D NetworkBrainStateMachine.AirportState: [EVENT_AIRPORT] TIMER skip airport auto radio-off ON because cloud control disabled
07-03 12:46:25.341  9870 10201 D NetworkBrainStateMachine.AirportState: [EVENT_AIRPORT] request location dispatched, reason=periodic
07-03 12:53:40.946  9870 10201 D NetworkBrainStateMachine.AirportState: [EVENT_AIRPORT] setOutOfServiceScanState slot=0 scanState=0
07-03 12:53:40.948  9870 10201 D NetworkBrainStateMachine.AirportState: [EVENT_AIRPORT] setOutOfServiceScanState slot=1 scanState=0
07-03 12:53:40.949  9870 10201 D NetworkBrainStateMachine.AirportState: [EVENT_AIRPORT] TIMER skip airport auto radio-off ON because cloud control disabled
07-03 13:01:48.140  9870 10201 D NetworkBrainStateMachine.AirportState: [EVENT_AIRPORT] setOutOfServiceScanState slot=0 scanState=0
07-03 13:01:48.143  9870 10201 D NetworkBrainStateMachine.AirportState: [EVENT_AIRPORT] setOutOfServiceScanState slot=1 scanState=0
07-03 13:01:48.145  9870 10201 D NetworkBrainStateMachine.AirportState: [EVENT_AIRPORT] TIMER skip airport auto radio-off ON because cloud control disabled
07-03 13:11:49.381  9870 10201 D NetworkBrainStateMachine.AirportState: [EVENT_AIRPORT] setOutOfServiceScanState slot=0 scanState=0
07-03 13:11:49.385  9870 10201 D NetworkBrainStateMachine.AirportState: [EVENT_AIRPORT] setOutOfServiceScanState slot=1 scanState=0
07-03 13:11:49.390  9870 10201 D NetworkBrainStateMachine.AirportState: [EVENT_AIRPORT] TIMER skip airport auto radio-off ON because cloud control disabled
07-03 13:16:25.435  9870 10201 D NetworkBrainStateMachine.AirportState: [EVENT_AIRPORT] request location dispatched, reason=periodic
07-03 13:29:01.168  9870 10201 D NetworkBrainStateMachine.AirportState: [EVENT_AIRPORT] setOutOfServiceScanState slot=0 scanState=0
07-03 13:29:01.174  9870 10201 D NetworkBrainStateMachine.AirportState: [EVENT_AIRPORT] setOutOfServiceScanState slot=1 scanState=0
07-03 13:29:01.176  9870 10201 D NetworkBrainStateMachine.AirportState: [EVENT_AIRPORT] TIMER skip airport auto radio-off ON because cloud control disabled
```

```java
// Internal: manage OOS timer based on inService changes
private void onCellServiceChanged(boolean inService) {
    Boolean last = mLastInService;
    mLastInService = inService;
    if (isCurrentRadioOffEnabled()) {
        cancelOosTimer();
        if (DEBUG) {
            Log.d(TAG, "[EVENT_AIRPORT] skip OOS handling because radio-off state is already ON");
        }
        return;
    }
    if (inService) {
        // In service -> cancel the OOS timer
        cancelOosTimer();
    } else {
        // OOS: only start on state edge (inService -> OOS)
        if ((last == null || last) && mCurrScenarioType == MobilityScenario.AIRPORT) {
            startOosTimer();
        }
    }

private void startOosTimer() {
    removeMessages(EVENT_AIRPORT_RADIO_POWER_OFF_TIMER);
    sendMessageDelayed(EVENT_AIRPORT_RADIO_POWER_OFF_TIMER,
            Airport.INFLIGHT_OOS_DURATION_TIME_MS);
    mOosTimerRunning = true;
}

void cancelOosTimer() {
    if (mOosTimerRunning) {
        removeMessages(EVENT_AIRPORT_RADIO_POWER_OFF_TIMER);
        mOosTimerRunning = false;
    }
}

case EVENT_AIRPORT_RADIO_POWER_OFF_TIMER:
    // Timer fires: if airport mode is still enabled then apply the configured airport auto action.
    if (!mAirportModeEnabled) return HANDLED;
    mOosTimerRunning = false;
    if (mAirportOutOfServiceScanEnabled) {
        setOutOfServiceScanState(OutOfServiceScan.SCAN_STATE_SLOW);
    }
    applyAirportAutoRadioOffAction(true, "TIMER");
    return HANDLED;

```

### 能豪

### Sensor 指标
bytedance sensor 起飞降落时间

```log
07-03 13:04:10.041  2004  4521 I sensors-hal: handle_sns_std_sensor_event:58, oem_flight_mode_event: ts=79357483856197, type=1.000000
07-03 13:04:10.046  9832  9992 D NetworkBrainStateMachine.IdleState: EVENT_AIRPORT_ENTER
07-03 14:45:34.433  2004  4521 I sensors-hal: handle_sns_std_sensor_event:58, oem_flight_mode_event: ts=85441875115500, type=0.000000
07-03 14:45:34.441  9832  9992 D NetworkBrainStateMachine.AirportState: EVENT_AIRPORT_EXIT
```

实际起飞降落时间
11:22 起飞, 14:48 落地
![CX347](./did_能豪/CX347_07-03_nenghao.png)

### GPS 指标

```log
07-03 13:04:10.067  9832  9992 D NetworkBrainStateMachine.AirportState: [EVENT_AIRPORT] request location dispatched, reason=enter
07-03 13:34:10.144  9832  9992 D NetworkBrainStateMachine.AirportState: [EVENT_AIRPORT] request location dispatched, reason=periodic
07-03 14:04:10.245  9832  9992 D NetworkBrainStateMachine.AirportState: [EVENT_AIRPORT] request location dispatched, reason=periodic
07-03 14:34:10.342  9832  9992 D NetworkBrainStateMachine.AirportState: [EVENT_AIRPORT] request location dispatched, reason=periodic
07-03 14:45:34.441  9832  9992 D NetworkBrainStateMachine.AirportState: [EVENT_AIRPORT] request location dispatched, reason=landing_exit_OEM_GROUND
07-03 14:45:34.443  9832  9992 D NetworkBrainStateMachine.AirportState: [EVENT_AIRPORT] request location dispatched, reason=exit

// 没有打开 GPS 开关
07-03 14:46:13.481  3748  3748 W LocationManagerService: location noteOp with location off - 1000/android
07-03 11:23:43.204  8328 28657 E CommSenseLog: <StarLocation-util> [getCurLocation] mLocationManager is null or provider is disabled
```

过滤产物：
`/home/bytedance/disk2T/Logs_2T_1/log_sns/log_airport_2026/test_data/after_merge/log_beijing_shenzhen_test_0703/did_能豪/dut_n1/runs/20260706_181715_v1.0.0/merged_all_aplog_filter`

输入与处理：
- AP 输入为 `aplog` + `aplog.001` 到 `aplog.016` 共 17 个分片，已按时间排序合并为 `runs/20260706_181715_v1.0.0/merged_all_aplog.txt`，大小约 167MB。
- 合并时显式使用 `--no-archive`，未移动 `input/` 下原始分片。
- 本次 AP 日志覆盖到 `07-03 14:46:39` 左右；radio on 是 `14:46:12`，因此日志没有覆盖 45s secondary timeout 与 120s report timeout 的触发时间点。

结论：
- 机场传感器触发链路正常：`13:04:10` 收到 `oem_flight_mode_event type=1` 并进入 `EVENT_AIRPORT_ENTER`；`14:45:34` 收到 `type=0` 并退出 `EVENT_AIRPORT_EXIT`。
- 位置链路失败仍是明确问题：机场状态机在进入、周期、降落退出时均发起 `request location dispatched`，但过滤产物中没有生成 `opt_airport_recv_location.txt`，说明没有匹配到 `location received`。
- 定位失败有系统侧证据：`LocationManagerService: location noteOp with location off - 1000/android`，以及 `StarLocation-util [getCurLocation] mLocationManager is null or provider is disabled`。因此本轮无法填充地理位置更像是定位开关关闭或 provider disabled，而不是 airport 状态机未请求。
- 降落后 PHONE0 恢复正常：`14:46:15` 后 `DATA_REGISTRATION_STATE` 与 `VOICE_REGISTRATION_STATE` 均恢复为 `REG_ROAMING, rat: LTE, registeredPlmn: 45400`。
- PHONE1 未恢复：`reg_sim2_data_reg_rat.txt` 和 `reg_sim2_voice_reg_rat.txt` 全部为 `NOT_REG_MT_SEARCHING_OP, rat: UNKNOWN`，到 `14:46:12` radio on 后仍未看到恢复。
- airport post-exit 上报仍在等待闭环：`14:46:12` 开始 `wait secondary slot recovery for 45000ms` 和 `wait post-exit report max timeout for 120000ms`；`14:46:15` 只捕获到 `slot=0` landing serving cell，并保持 `slot0Recovered=true, slot1Recovered=false`。由于日志在 `14:46:39` 结束，不能判断后续是否触发 secondary timeout 或强制上报。

关键证据：
```log





07-03 14:46:12.252  9832  9992 D NetworkBrainStateMachine.AirportState: [EVENT_AIRPORT] wait secondary slot recovery for 45000ms
07-03 14:46:12.252  9832  9992 D NetworkBrainStateMachine.AirportState: [EVENT_AIRPORT] wait post-exit report max timeout for 120000ms
07-03 14:46:15.828  9832  9992 D NetworkBrainStateMachine.AirportState: [EVENT_AIRPORT] capture landing serving cell slot=0, reason=DUALSIM_SNAPSHOT_CHANGED, eventTs=1783061134435, sampleTs=1783061175825
07-03 14:46:15.828  9832  9992 D NetworkBrainStateMachine.AirportState: [EVENT_AIRPORT] keep pending airport report, reason=DUALSIM_SNAPSHOT_CHANGED_SLOT_0, ddsSlot=0, slot0Recovered=true, slot1Recovered=false, secondaryWaitTimeout=false, reportTimeout=false, nrWaitTimeout=false, manualPending=false

07-03 14:46:15.839  6388  6672 D RILJ    : [3423]< DATA_REGISTRATION_STATE RegStateResult{regState: REG_ROAMING, rat: LTE, reasonForDenial: NONE, cellIdentity: CellIdentity.lte(CellIdentityLte{mcc: 454, mnc: 00, ci: 106163212, pci: 275, tac: 1111, earfcn: 1400, operatorNames: OperatorInfo{alphaLong:  CSL , alphaShort:  CSL , operatorNumeric: 45400, status: 2}, bandwidth: 20000, additionalPlmns: [], csgInfo: null, bands: [BAND_3]}), registeredPlmn: 45400, accessTechnologySpecificInfo: AccessTechnologySpecificInfo.eutranInfo(EutranRegistrationInfo{lteVopsInfo: LteVopsInfo{isVopsSupported: true, isEmcBearerSupported: true}, nrIndicators: NrIndicators{isEndcAvailable: true, isDcNrRestricted: false, isNrAvailable: true}, lteAttachResultType: 0, extraInfo: 0})} [PHONE0]
07-03 14:46:12.363  6388  7184 D RILJ    : [3379]< DATA_REGISTRATION_STATE RegStateResult{regState: NOT_REG_MT_SEARCHING_OP, rat: UNKNOWN, reasonForDenial: NONE, cellIdentity: CellIdentity.noinit(false), registeredPlmn: , accessTechnologySpecificInfo: AccessTechnologySpecificInfo.noinit(false)} [PHONE1]
```

后续建议：
- 复测时多保留 radio on 后至少 3 分钟 AP log，才能确认 `POST_EXIT_SECONDARY_TIMEOUT`、`AFTER_EXIT_POST_EXIT_REPORT_TIMEOUT` 与 PB 上报结果。
- 机场位置链路建议补充 request 后的失败原因日志或 PB 字段，例如 location off、provider disabled、permission denied、no cached location、callback timeout。
- 双卡恢复逻辑建议在 pending report 中明确记录 secondary slot 未注册原因，避免只看到 `slot1Recovered=false` 而缺少注册态真值。


### TODO