Bug #116789
【BSP】【EVT3】【Boot】【偶现】设备开机后，偶现反复重启
| Status: | CLOSED | Start date: | 2023-03-07 | ||
|---|---|---|---|---|---|
| Priority: | High | Due date: | |||
| Assignee: | 移动测试一组_CDTS 刘强 | % Done: | 80% | ||
| Category: | BSP | ||||
| Target version: | VC1_FSE_0090_20230411 | ||||
| Need_Info: | -- | Found Version: | 0079 | ||
| Resolution: | -- | Degrated: | -- | ||
| Severity: | Critical | Verified Version: | 最新的mot文件，v0.1.2 | ||
| Reproducibility: | Occasionally | Fixed Version: | |||
| Test Type: | ST | Root cause: | 目前已经修复，原因为wdt喂狗失败导致，目前已经进行修改。 |
Description
【前提条件】
None
【测试步骤】
1. 设备开机后，等待设备进入屏保模式
2. 点击屏幕亮屏
3. 点击设置
【预期结果】
3 设备正常运行，进入设置界面
【实际结果】
3 设备关机-自动重启
Log: ftp://cdiot@192.168.87.46/Figure/bug/reboot/tlog_f22f620e_189_0302055454.tar.gz
History
#1 Updated by 移动测试一组_CDTS 刘强 over 2 years ago
- Category changed from SYSTEM to BSP
- Assignee changed from CD SYSTEM-夏旭 to CD BSP-陈杰
第一次复现重启后，再次点击设置不会重启
再次断电-上电后，复现反复reboot
#2 Updated by 移动测试一组_CDTS 刘强 over 2 years ago
换了电源后没有复现，可能是电源问题
#3 Updated by CD BSP-陈杰 over 2 years ago
- Assignee changed from CD BSP-陈杰 to 移动测试一组_CDTS 刘强
#4 Updated by 移动测试一组_CDTS 刘强 over 2 years ago
- Status changed from New to RESOLVED
- Root cause set to 电源问题，非软件问题，无需修改
#5 Updated by 移动测试一组_CDTS 刘强 over 2 years ago
- Status changed from RESOLVED to VERIFIED
#6 Updated by 移动测试一组_CDTS 刘强 over 2 years ago
- Status changed from VERIFIED to CLOSED
#7 Updated by 移动测试一组_CDTS 刘强 over 2 years ago
- Status changed from CLOSED to New
- Assignee changed from 移动测试一组_CDTS 刘强 to CD BSP-杜磊
今天有两台设备复现：
烧写0081版本后开机，然后重新烧写0078版本
开机后，这边反复重启，非必现
#8 Updated by 移动测试一组_CDTS 刘强 over 2 years ago
- Subject changed from 【BSP】【EVT3】【Boot】【偶现1次】设备开机后，等待设备进入屏保模式，点击屏幕亮屏，点击设置，设备自动关机重启 to 【BSP】【EVT3】【Boot】【偶现3次】设备开机后，偶现反复重启
#9 Updated by System组-RD3_CDTS 蒋富雄 over 2 years ago
突然就没log输出了请确认是否是突然断电
01-01 08:09:29.484 0 0 I afe_send_port_topology_id: AFE set topology id 0x112fc enable for port 0x9000 ret 0
01-01 08:09:29.484 0 0 I send_afe_cal_type: cal_index is 0
01-01 08:09:29.484 0 0 I send_afe_cal_type: dev_acdb_id55 is 0
01-01 08:09:29.484 0 0 I send_afe_cal_type: Sending cal_index cal 0
01-01 08:09:29.484 0 0 E send_afe_cal_type: No cal sent for cal_index 0, port_id = 0x9000! ret -22
01-01 08:09:29.493 0 0 I afe_send_hw_delay: port_id 0x9000 rate 48000 delay_usec 474 status 0
01-01 08:09:33.596 0 0 E DTC_ETH,link_delay_work_func: 3003, SQI=0, link=0
01-01 08:09:38.716 0 0 E DTC_ETH,link_delay_work_f
#10 Updated by System组-RD3_CDTS 蒋富雄 over 2 years ago
- File jiang1.log added
设备开机到动画就进行重启了，
[ 41.001531] [wifi@1][0x3178c55c][05:02:41.438266] wlan: [868:E:SME] sme_get_nss_chain_shift: 4045: Device mode 16 invalid
[Rx][14:09:28.809] [ 41.438164] [wifi@1]
[0x31f8b045][05:02:41.874891] wlan: [3550:E:wifipos] wifi_pos_process_app_reg_req: 608: Received App Req Req pid(1925186404), len(16)
[Rx][14:09:32.159] [ 44.768392] DTC_ETH,link_delay_work_func:3003, SQI=0, link=0
[Rx][14:09:35.759] [ 48.387919] audit: rate limit exceeded
[Rx][14:09:37.279] [ 49.888314] DTC_ETH,link_delay_work_func:3003, SQI=0, link=0
[14:09:38.046] [ 50.656076] thermal cooling_device4: DTC_Fan: ERROR, avg(0) out of range(1680, 2800) at stat(1)
#11 Updated by System组-RD3_CDTS 蒋富雄 over 2 years ago
- File logcat.txt
added
从logcat中看到如下log。反复重启，在动画上就重启了，由于是没断电，所以再次开机，表现就是反复重启 请fw分析
03-09 05:02:37.508 1537 1647 I ActivityManagerTiming: OnBootPhase_1000_com.android.server.media.MediaCommunicationService
03-09 05:02:37.508 1537 1647 D ActivityManagerTiming: TotalBootTime took to complete: 3819ms
03-09 05:02:37.508 1537 1647 D SystemServerInitThreadPool: Shutdown requested
03-09 05:02:37.508 1537 1647 I SystemServerTiming: WaitInitThreadPoolShutdown
03-09 05:02:37.508 1537 1647 D SystemServerInitThreadPool: Shutdown successful
#12 Updated by CD BSP-杜磊 over 2 years ago
- Category changed from BSP to CD-FW
- Status changed from New to ASSIGNED
- Assignee changed from CD BSP-杜磊 to CD FW 曹覃刚
Hi, 覃刚，
请帮忙做如上分析
#13 Updated by CDTS_Test 吴诗雨 over 2 years ago
- File logcat.txt added
#14 Updated by CDTS_Test 吴诗雨 over 2 years ago
刷到0078版本再次复现，log已上传
#15 Updated by 移动测试一组_CDTS 刘强 over 2 years ago
在使用VB版本验证满内存重启进dump问题后，重新烧写版本0068，复现开机时反复重启
#16 Updated by CDTS_TEST 王成 over 2 years ago
- Severity changed from Major to Critical
#17 Updated by 移动测试一组_CDTS 刘强 over 2 years ago
- Subject changed from 【BSP】【EVT3】【Boot】【偶现3次】设备开机后，偶现反复重启 to 【BSP】【EVT3】【Boot】【偶现】设备开机后，偶现反复重启
复现后-全擦烧写工厂可以恢复正常
复现后-不擦烧写user不能恢复正常，开机后继续反复重启
#18 Updated by CDTS_TEST 王成 over 2 years ago
- Root cause deleted (
电源问题，非软件问题，无需修改)
#19 Updated by BSP组-RD3_TSCD 贾顺旺 over 2 years ago
从日志上看都是VX1的，VC1上有复现过么？
#20 Updated by CD FW 曹覃刚 over 2 years ago
- Assignee changed from CD FW 曹覃刚 to CD FW王武军
Hi 军哥
这个问题比较严重，请帮忙先看一下
#21 Updated by 移动测试一组_CDTS 刘强 over 2 years ago
复现后如果想恢复正常的话，目前就只有两种方式：
1. 烧写工厂版本（新编的那个），后可以正常开机,再刷其他版本，还是一样会反复重启（概率）
2. 重新烧写mot文件，可以正常开机，刷其他版本也ok，再次烧写其他版本时，也会偶现这个问题
#22 Updated by CD FW王武军 over 2 years ago
【】当前状态
1) 分析fw的日志
03-09 05:02:37.508 1537 1647 I ActivityManagerTiming: OnBootPhase_1000_com.android.server.media.MediaCommunicationService
03-09 05:02:37.508 1537 1647 D ActivityManagerTiming: TotalBootTime took to complete: 3819ms
03-09 05:02:37.508 1537 1647 D SystemServerInitThreadPool: Shutdown requested
03-09 05:02:37.508 1537 1647 I SystemServerTiming: WaitInitThreadPoolShutdown
03-09 05:02:37.508 1537 1647 D SystemServerInitThreadPool: Shutdown successful
该日志的输出原因：在启动过程中相关的服务执行后，通过SystemServerInitThreadPool.shutdown
结束和回收启动过程中启动的线程池，这个日志信息是正常的日志。代码的触发大致如下：
//SystemServiceManager.java
public void startBootPhase(@NonNull TimingsTraceAndSlog t, int phase) {
if (phase <= mCurrentPhase) {
throw new IllegalArgumentException("Next phase must be larger than previous");
}
mCurrentPhase = phase;
Slog.i(TAG, "Starting phase " + mCurrentPhase);
try {
t.traceBegin("OnBootPhase_" + phase);
final int serviceLen = mServices.size();
for (int i = 0; i < serviceLen; i++) {
final SystemService service = mServices.get(i);
long time = SystemClock.elapsedRealtime();
t.traceBegin("OnBootPhase_" + phase + "_" + service.getClass().getName());
try {
service.onBootPhase(mCurrentPhase);
} catch (Exception ex) {
throw new RuntimeException("Failed to boot service "
+ service.getClass().getName()
+ ": onBootPhase threw an exception during phase "
+ mCurrentPhase, ex);
}
warnIfTooLong(SystemClock.elapsedRealtime() - time, service, "onBootPhase");
t.traceEnd();
}
} finally {
t.traceEnd();
}
if (phase == SystemService.PHASE_BOOT_COMPLETED) {
final long totalBootTime = SystemClock.uptimeMillis() - mRuntimeStartUptime;
t.logDuration("TotalBootTime", totalBootTime);
SystemServerInitThreadPool.shutdown();
}
}static void shutdown() {
http://192.168.87.66:8006/source/xref/Pre_figure_turbox-c2130c-la1.1-qssi12-dev/LA.QSSI/LINUX/android/frameworks/base/services/core/java/com/android/server/SystemServerInitThreadPool.java#143
}2）其他日志信息
日志信息是基于：logcat.txt 2023-03-09 16:40 的日志文件。本地在无限重启后的板子上并未获取到更多有用的信息。
a) 关于init进程的
03-09 05:02:37.532 2733 2733 F libc : Fatal signal 6 (SIGABRT), code -1 (SI_QUEUE) in tid 2733 (init), pid 2733 (init)
03-09 05:02:37.552 634 634 I tombstoned: received crash request for pid 2733
03-09 05:02:37.552 2742 2742 I crash_dump64: performing dump of process 2733 (target tid = 2733)
03-09 05:02:37.554 2742 2742 E DEBUG : failed to read process info: failed to open /proc/2733
03-09 05:02:37.586 2742 2742 F DEBUG : *
03-09 05:02:37.587 2742 2742 F DEBUG : Build fingerprint: 'TC/figure_CN/figure:12/SKQ1.220201.001/2403:user/test-keys'
03-09 05:02:37.587 2742 2742 F DEBUG : Revision: '0'
03-09 05:02:37.587 2742 2742 F DEBUG : ABI: 'arm64'
03-09 05:02:37.587 2742 2742 F DEBUG : Timestamp: 2023-03-09 05:02:37.554048071+0800
03-09 05:02:37.587 2742 2742 F DEBUG : Process uptime: 0s
03-09 05:02:37.587 2742 2742 F DEBUG : Cmdline: /system/bin/init second_stage
03-09 05:02:37.587 2742 2742 F DEBUG : pid: 2733, tid: 2733, name: init >>> /system/bin/init <<<
03-09 05:02:37.587 2742 2742 F DEBUG : uid: 0
03-09 05:02:37.587 2742 2742 F DEBUG : signal 6 (SIGABRT), code 1 (SI_QUEUE), fault addr -------
03-09 05:02:37.587 2742 2742 F DEBUG : x0 0000000000000000 x1 0000000000000aad x2 0000000000000006 x3 0000007fdb58b9d0
03-09 05:02:37.587 2742 2742 F DEBUG : x4 000000000000000a x5 000000000000000a x6 000000000000000a x7 000000000000000a
03-09 05:02:37.587 2742 2742 F DEBUG : x8 00000000000000f0 x9 6916d3e4140e3251 x10 0000000000000000 x11 ffffff80ffffffdf
03-09 05:02:37.587 2742 2742 F DEBUG : x12 0000000000000001 x13 3a73747069726373 x14 0000000000000010 x15 0000000000000000
03-09 05:02:37.587 2742 2742 F DEBUG : x16 0000007fa2667060 x17 0000007fa2643560 x18 0000007fad20e000 x19 0000000000000aad
03-09 05:02:37.587 2742 2742 F DEBUG : x20 0000000000000aad x21 00000000ffffffff x22 0000007fad0ce000 x23 0000007fad0ce000
03-09 05:02:37.587 2742 2742 F DEBUG : x24 0000007fdb58bca0 x25 0000007fdb58bca0 x26 0000000000000000 x27 0000007fad0ce000
03-09 05:02:37.587 2742 2742 F DEBUG : x28 0000007fa25f7d20 x29 0000007fdb58ba50
03-09 05:02:37.587 2742 2742 F DEBUG : lr 0000007fa25f395c sp 0000007fdb58b9b0 pc 0000007fa25f3988 pst 0000000000001000
03-09 05:02:37.587 2742 2742 F DEBUG : backtrace:
03-09 05:02:37.587 2742 2742 F DEBUG : #00 pc 0000000000051988 /system/lib64/bootstrap/libc.so (abort+168) (BuildId: 369edc656806aeaf384cbeb8f7a347af)
03-09 05:02:37.587 2742 2742 F DEBUG : #01 pc 0000000000015038 /system/lib64/libbase.so (android::base::DefaultAborter(char const)+16) (BuildId: 96895dcea0300fc102132e9762aef6bc)
03-09 05:02:37.587 2742 2742 F DEBUG : #02 pc 0000000000016bc4 /system/lib64/libbase.so (android::base::SetAborter(std::__1::function<void (char const*)>&&)::$_3::__invoke(char const*)+80) (BuildId: 96895dcea0300fc102132e9762aef6bc)
03-09 05:02:37.587 2742 2742 F DEBUG : #03 pc 0000000000016184 /system/lib64/libbase.so (android::base::LogMessage::~LogMessage()+368) (BuildId: 96895dcea0300fc102132e9762aef6bc)
03-09 05:02:37.587 2742 2742 F DEBUG : #04 pc 00000000000d8128 /system/bin/init (android::init::Service::SetProcessAttributesAndCaps()+716) (BuildId: 22e05086498bc9c9e3a5fc9a10a930c1)
03-09 05:02:37.587 2742 2742 F DEBUG : #05 pc 00000000000dac18 /system/bin/init (android::init::Service::Start()+7348) (BuildId: 22e05086498bc9c9e3a5fc9a10a930c1)
03-09 05:02:37.587 2742 2742 F DEBUG : #06 pc 00000000000cda20 /system/bin/init (android::init::do_start(android::init::BuiltinArguments const&)+316) (BuildId: 22e05086498bc9c9e3a5fc9a10a930c1)
03-09 05:02:37.587 2742 2742 F DEBUG : #07 pc 00000000000b16cc /system/bin/init (android::init::RunBuiltinFunction(std::__1::function<android::base::expected<void, android::base::ResultError> (android::init::BuiltinArguments const&)> const&, std::__1::vector<std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> >, std::__1::allocator<std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> > > > const&, std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char> > const&)+476) (BuildId: 22e05086498bc9c9e3a5fc9a10a930c1)
03-09 05:02:37.587 2742 2742 F DEBUG : #08 pc 00000000000b1880 /system/bin/init (android::init::Command::InvokeFunc(android::init::Subcontext*) const+284) (BuildId: 22e05086498bc9c9e3a5fc9a10a930c1)
03-09 05:02:37.587 2742 2742 F DEBUG : #09 pc 00000000000b22e4 /system/bin/init (android::init::Action::ExecuteCommand(android::init::Command const&) const+80) (BuildId: 22e05086498bc9c9e3a5fc9a10a930c1)
03-09 05:02:37.587 2742 2742 F DEBUG : #10 pc 00000000000b21d8 /system/bin/init (android::init::Action::ExecuteOneCommand(unsigned long) const+336) (BuildId: 22e05086498bc9c9e3a5fc9a10a930c1)
03-09 05:02:37.587 2742 2742 F DEBUG : #11 pc 00000000000e2d74 /system/bin/init (android::init::ActionManager::ExecuteOneCommand()+188) (BuildId: 22e05086498bc9c9e3a5fc9a10a930c1)
03-09 05:02:37.587 2742 2742 F DEBUG : #12 pc 00000000000fa6dc /system/bin/init (android::init::SecondStageMain(int, char**)+7560) (BuildId: 22e05086498bc9c9e3a5fc9a10a930c1)
03-09 05:02:37.587 2742 2742 F DEBUG : #13 pc 00000000000ac19c /system/bin/init (main+308) (BuildId: 22e05086498bc9c9e3a5fc9a10a930c1)
03-09 05:02:37.587 2742 2742 F DEBUG : #14 pc 000000000004a084 /system/lib64/bootstrap/libc.so (__libc_init+100) (BuildId: 369edc656806aeaf384cbeb8f7a347af)
03-09 05:02:37.589 1537 2080 W NativeCrashListener: Couldn't find ProcessRecord for pid 2733
b) 关于MCU升级的
03-09 05:02:50.332 2431 2590 D MCUUpdate: find 2 mcu version:figureAPP_V0.1.1_a.bin figureAPP_V0.1.1_b.bin
03-09 05:02:50.336 2431 2590 D MCUUpdate: Check MCU current version :res = 0
03-09 05:02:50.375 2431 2587 D MCUUpdate: MCU version: 86 length: 9
03-09 05:02:50.375 2431 2587 D MCUUpdate: Current version: V0.0.0, Find version: V0.1.1
03-09 05:02:50.385 2431 2590 D MCUUpdate: readBin
03-09 05:02:50.390 2431 2590 D MCUUpdate: mcu.bin : [-119, 23, -103, 59, 86, 48, 46, 49, 46, 49, 0, 0, 0, 1, 1, 0, -100, -121, 0, 0, 78, -14, -91, -59, -99, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0]
03-09 05:02:50.390 2431 2590 D MCUUpdate: readBin
03-09 05:02:50.394 2431 2590 D MCUUpdate: mcu.bin : [-119, 23, -103, 59, 86, 48, 46, 49, 46, 49, 0, 0, 0, 1, 1, 0, -100, -121, 0, 0, 113, -34, 89, -46, 101, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0]
03-09 05:02:50.395 2431 2590 D MCUUpdate: Bin Version:V0.1.1 File Name:V0.1.1
03-09 05:02:50.395 2431 2590 D MCUUpdate: strat update; mpu send 85 01
03-13 19:48:57.436 D/MCUUpdate( 2401): find 2 mcu version:figureAPP_V0.0.0_b.bin figureAPP_V0.0.0_a.bin
03-13 19:48:57.440 D/MCUUpdate( 2401): Check MCU current version :res = 0
03-13 19:48:57.472 D/MCUUpdate( 2401): MCU version: 86 length: 9
03-13 19:48:57.473 D/MCUUpdate( 2401): Current version: V0.1.1, Find version: V0.0.0
03-13 19:48:57.482 D/MCUUpdate( 2401): readBin
03-13 19:48:57.487 D/MCUUpdate( 2401): mcu.bin : [-119, 23, -103, 59, 86, 48, 46, 48, 46, 48, 0, 0, 0, 0, 0, 0, 124, -121, 0, 0, 13, 33, 31, 113, -29, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0]
03-13 19:48:57.487 D/MCUUpdate( 2401): readBin
03-13 19:48:57.488 D/MCUUpdate( 2401): mcu.bin : [-119, 23, -103, 59, 86, 48, 46, 48, 46, 48, 0, 0, 0, 0, 0, 0, 124, -121, 0, 0, 64, -26, 68, 9, 74, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0]
03-13 19:48:57.488 D/MCUUpdate( 2401): Bin Version:V0.0.0 File Name:V0.0.0
03-13 19:48:57.488 D/MCUUpdate( 2401): strat update; mpu send 85 01
MCU升级模块中存在这样的日志：
Current version: V0.0.0, Find version: V0.1.1
Current version: V0.1.1, Find version: V0.0.0
因为MCU升级后会主动重启设备，是否MCU的逻辑中存在循环升级的问题，需要确认。
#23 Updated by CD TPM-王祥林 over 2 years ago
- Category changed from CD-FW to BSP
- Assignee changed from CD FW王武军 to CD BSP-陈杰
陈杰
看一下MCU版本号不对，和升级失败的原因。
#24 Updated by CDTS_TEST 王成 over 2 years ago
- Target version set to VC1_FSE_0086_20230328
#25 Updated by CD BSP-杜磊 over 2 years ago
- Status changed from ASSIGNED to RESOLVED
- % Done changed from 0 to 80
#26 Updated by CDTS_TEST 王成 over 2 years ago
- Target version changed from VC1_FSE_0086_20230328 to VC1_FSE_0090_20230411
#27 Updated by CD BSP-陈杰 about 2 years ago
- Assignee changed from CD BSP-陈杰 to 移动测试一组_CDTS 刘强
- Verified Version set to 最新的mot文件，v0.1.2
- Root cause set to 目前已经修复，原因为wdt喂狗失败导致，目前已经进行修改。
#28 Updated by 移动测试一组_CDTS 刘强 about 2 years ago
- Status changed from RESOLVED to VERIFIED
修改mot文件后，Mot V0.1.2
验证结果：通过
https://thundersoft.feishu.cn/sheets/shtcn5ImqRt1IhgQPZiHG2kCNxe?sheet=vbV6Dw
#29 Updated by 移动测试一组_CDTS 刘强 about 2 years ago
- Status changed from VERIFIED to CLOSED