topic Re: The Android 9 system with IMx8mm chip has issues with automatic factory recovery and restart. in i.MX Processors

The Android 9 system with IMx8mm chip has issues with automatic factory recovery and restart.

Only_聆听 — Fri, 05 Apr 2024 03:47:22 GMT

Dear NXP technician:

I am experiencing a terrible problem on the Android 9.0 system with an IMX8MM processor. After running normally for a period of time, the machine inexplicably undergoes factory initialization, and after restoring factory initialization, it will fall into an infinite loop. After modifying the system time, the infinite restart will stop, but after running for a period of time, an automatic factory reset still occurs.

We have detected no obvious errors before resetting the product, and I would like to receive some advice on how to troubleshoot such issues.

thank you！

Debug logs before restarting：

[19:35:38.276]收←◆[ 186.038074] healthd: battery l=85 v=3 t=35.0 h=2 st=2 c=400 fc=4000000 cc=32 chg=a

[19:36:38.135]收←◆[ 245.900538] healthd: battery l=85 v=3 t=35.0 h=2 st=2 c=400 fc=4000000 cc=32 chg=a

[19:36:38.272]收←◆[ 246.038062] healthd: battery l=85 v=3 t=35.0 h=2 st=2 c=400 fc=4000000 cc=32 chg=a

[19:37:36.804]收←◆[ 304.573104] init: Received sys.powerctl='reboot,shell' from pid: 3921 (reboot)
[ 304.580610] init: Clear action queue and start shutdown trigger
[ 304.586875] init: processing action (shutdown_done) from (<Builtin Action>:0)
[ 304.594130] init: =====================================Reboot start, reason: reboot,shell, rebootTarget: shell
[ 304.604415] init: Reboot ending, jumping to kernel
[ 304.609313] kvm: exiting hardware virtualization
[ 304.621085] imx2-wdt 30280000.wdog: Device shutdown: Expect reboot!
[ 304.627759] ci_hdrc ci_hdrc.1: remove, state 1
[ 304.636333] usb usb1: USB disconnect, device number 1
[ 304.641524] usb 1-1: USB disconnect, device number 2
[ 304.646599] usb 1-1.2: USB disconnect, device number 3
[ 304.652863] ch341-uart ttyUSB0: ch341-uart converter now disconnected from ttyUSB0
[ 304.661231] ch341 1-1.2:1.0: device disconnected
[ 304.678621] ci_hdrc ci_hdrc.1: USB bus 1 deregistered
[ 304.686726] android_work: sent uevent USB_STATE=DISCONNECTED
[ 304.706690] reboot: Restarting system with command 'bootloader'

Logcat logs before restart：

04-02 01:36:06.475 I/chatty ( 3064): uid=1000(system) health@2.0-serv identical 4 lines
04-02 01:36:16.888 E//vendor/bin/hw/android.hardware.health@2.0-service.imx( 3064): /sys/block/mmcblk0/stat: ReadFileToString failed.
04-02 01:36:46.132 I/system_server( 3219): Background concurrent copying GC freed 189893(7MB) AllocSpace objects, 0(0B) LOS objects, 42% free, 9MB/16MB, paused 324us total 122.475ms
04-02 01:37:06.475 E//vendor/bin/hw/android.hardware.health@2.0-service.imx( 3064): /sys/block/mmcblk0/stat: ReadFileToString failed.
04-02 01:37:16.889 E/storaged( 3106): getDiskStats failed with result NOT_SUPPORTED and size 0
04-02 01:38:16.890 E/storaged( 3106): getDiskStats failed with result NOT_SUPPORTED and size 0
04-02 01:39:16.891 E/storaged( 3106): getDiskStats failed with result NOT_SUPPORTED and size 0
04-02 01:39:06.476 I/chatty ( 3064): uid=1000(system) health@2.0-serv identical 4 lines
04-02 01:39:16.891 E//vendor/bin/hw/android.hardware.health@2.0-service.imx( 3064): /sys/block/mmcblk0/stat: ReadFileToString failed.
04-02 01:39:52.543 I/system_server( 3219): Background concurrent copying GC freed 189113(6MB) AllocSpace objects, 0(0B) LOS objects, 42% free, 9MB/16MB, paused 266us total 120.259ms
04-02 01:40:06.475 E//vendor/bin/hw/android.hardware.health@2.0-service.imx( 3064): /sys/block/mmcblk0/stat: ReadFileToString failed.
04-02 01:40:16.892 E/storaged( 3106): getDiskStats failed with result NOT_SUPPORTED and size 0
04-02 01:41:16.893 E/storaged( 3106): getDiskStats failed with result NOT_SUPPORTED and size 0
04-02 01:42:16.894 E/storaged( 3106): getDiskStats failed with result NOT_SUPPORTED and size 0
04-02 01:42:06.475 I/chatty ( 3064): uid=1000(system) health@2.0-serv identical 4 lines
04-02 01:42:16.894 E//vendor/bin/hw/android.hardware.health@2.0-service.imx( 3064): /sys/block/mmcblk0/stat: ReadFileToString failed.
04-02 01:42:38.871 I/system_server( 3219): Background concurrent copying GC freed 185645(7MB) AllocSpace objects, 0(0B) LOS objects, 42% free, 9MB/16MB, paused 381us total 126.322ms
04-02 01:43:06.475 E//vendor/bin/hw/android.hardware.health@2.0-service.imx( 3064): /sys/block/mmcblk0/stat: ReadFileToString failed.
04-02 01:43:16.895 E/storaged( 3106): getDiskStats failed with result NOT_SUPPORTED and size 0
04-02 01:43:16.895 E//vendor/bin/hw/android.hardware.health@2.0-service.imx( 3064): /sys/block/mmcblk0/stat: ReadFileToString failed.
04-02 01:43:22.176 D/NetworkMonitor/NetworkAgentInfo [Ethernet () - 102]( 3219): PROBE_DNS www.google.com 2ms OK 199.16.158.182
04-02 01:43:22.176 D/NetworkMonitor/NetworkAgentInfo [Ethernet () - 102]( 3219): PROBE_DNS connectivitycheck.gstatic.com 3ms OK 203.208.49.66
04-02 01:43:22.324 D/NetworkMonitor/NetworkAgentInfo [Ethernet () - 102]( 3219): PROBE_HTTP http://connectivitycheck.gstatic.com/generate_204 time=147ms ret=204 request={User-Agent=[Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/60.0.3112.32 Safari/537.36]} headers={null=[HTTP/1.1 204 No Content], Content-Length=[0], Cross-Origin-Resource-Policy=[cross-origin], Date=[Thu, 04 Apr 2024 12:34:37 GMT], X-Android-Received-Millis=[1711993402324], X-Android-Response-Source=[NETWORK 204], X-Android-Selected-Protocol=[http/1.1], X-Android-Sent-Millis=[1711993402233]}
04-02 01:43:32.185 D/NetworkMonitor/NetworkAgentInfo [Ethernet () - 102]( 3219): PROBE_HTTPS https://www.google.com/generate_204 Probe failed with exception java.net.SocketTimeoutException: failed to connect to /199.16.158.182 (port 443) from /169.254.0.54 (port 46854) after 10000ms
04-02 01:43:35.188 D/NetworkMonitor/NetworkAgentInfo [Ethernet () - 102]( 3219): PROBE_FALLBACK http://play.googleapis.com/generate_204 Probe failed with exception java.net.SocketTimeoutException: failed to connect to /142.251.43.10 (port 80) from /169.254.0.54 (port 40640) after 10000ms
04-02 01:43:35.189 D/ConnectivityService( 3219): NetworkAgentInfo [Ethernet () - 102] validation failed
04-02 01:44:06.475 E//vendor/bin/hw/android.hardware.health@2.0-service.imx( 3064): /sys/block/mmcblk0/stat: ReadFileToString failed.
04-02 01:44:16.896 E/storaged( 3106): getDiskStats failed with result NOT_SUPPORTED and size 0
04-02 01:45:16.897 E/storaged( 3106): getDiskStats failed with result NOT_SUPPORTED and size 0
04-02 01:45:06.475 I/chatty ( 3064): uid=1000(system) health@2.0-serv identical 2 lines
04-02 01:45:16.897 E//vendor/bin/hw/android.hardware.health@2.0-service.imx( 3064): /sys/block/mmcblk0/stat: ReadFileToString failed.
04-02 01:46:02.929 I/system_server( 3219): Background concurrent copying GC freed 180681(6MB) AllocSpace objects, 0(0B) LOS objects, 42% free, 9MB/16MB, paused 269us total 121.927ms
04-02 01:46:06.475 E//vendor/bin/hw/android.hardware.health@2.0-service.imx( 3064): /sys/block/mmcblk0/stat: ReadFileToString failed.
04-02 01:46:16.898 E/storaged( 3106): getDiskStats failed with result NOT_SUPPORTED and size 0
04-02 01:47:16.899 E/storaged( 3106): getDiskStats failed with result NOT_SUPPORTED and size 0
04-02 01:48:16.900 E/storaged( 3106): getDiskStats failed with result NOT_SUPPORTED and size 0
04-02 01:48:16.900 I/chatty ( 3064): uid=1000(system) health@2.0-serv identical 5 lines
04-02 01:49:06.475 E//vendor/bin/hw/android.hardware.health@2.0-service.imx( 3064): /sys/block/mmcblk0/stat: ReadFileToString failed.
04-02 01:49:06.964 I/system_server( 3219): Background concurrent copying GC freed 187943(7MB) AllocSpace objects, 0(0B) LOS objects, 42% free, 9MB/16MB, paused 484us total 123.046ms
04-02 01:49:16.901 E//vendor/bin/hw/android.hardware.health@2.0-service.imx( 3064): /sys/block/mmcblk0/stat: ReadFileToString failed.
04-02 01:49:16.901 E/storaged( 3106): getDiskStats failed with result NOT_SUPPORTED and size 0
04-02 01:50:16.902 E/storaged( 3106): getDiskStats failed with result NOT_SUPPORTED and size 0
04-02 01:51:16.903 E/storaged( 3106): getDiskStats failed with result NOT_SUPPORTED and size 0
04-02 01:51:06.475 I/chatty ( 3064): uid=1000(system) health@2.0-serv identical 3 lines
04-02 01:51:16.902 E//vendor/bin/hw/android.hardware.health@2.0-service.imx( 3064): /sys/block/mmcblk0/stat: ReadFileToString failed.
04-02 01:51:38.593 I/system_server( 3219): Background concurrent copying GC freed 184512(6MB) AllocSpace objects, 0(0B) LOS objects, 42% free, 9MB/16MB, paused 383us total 122.905ms
04-02 01:52:06.475 E//vendor/bin/hw/android.hardware.health@2.0-service.imx( 3064): /sys/block/mmcblk0/stat: ReadFileToString failed.
04-02 01:52:16.904 E/storaged( 3106): getDiskStats failed with result NOT_SUPPORTED and size 0
04-02 01:53:16.905 E/storaged( 3106): getDiskStats failed with result NOT_SUPPORTED and size 0
04-02 01:53:48.209 D/ConnectivityService( 3219): NetworkAgentInfo [Ethernet () - 102] validation failed
04-02 01:54:00.701 E/BatteryExternalStatsWorker( 3219): no controller energy info supplied for wifi
04-02 01:54:00.701 E/BatteryExternalStatsWorker( 3219): no controller energy info supplied for bluetooth
04-02 01:54:00.701 E/BatteryExternalStatsWorker( 3219): no controller energy info supplied for telephony
04-02 01:54:06.475 E//vendor/bin/hw/android.hardware.health@2.0-service.imx( 3064): /sys/block/mmcblk0/stat: ReadFileToString failed.
04-02 01:54:16.906 E/storaged( 3106): getDiskStats failed with result NOT_SUPPORTED and size 0
04-02 01:54:16.906 E//vendor/bin/hw/android.hardware.health@2.0-service.imx( 3064): /sys/block/mmcblk0/stat: ReadFileToString failed.
04-02 01:54:33.355 I/system_server( 3219): Background concurrent copying GC freed 171243(6MB) AllocSpace objects, 5(268KB) LOS objects, 42% free, 9MB/16MB, paused 329us total 125.708ms
04-02 01:55:06.475 E//vendor/bin/hw/android.hardware.health@2.0-service.imx( 3064): /sys/block/mmcblk0/stat: ReadFileToString failed.
04-02 01:55:17.698 E/storaged( 3106): getDiskStats failed with result NOT_SUPPORTED and size 0
04-02 01:56:17.699 E/storaged( 3106): getDiskStats failed with result NOT_SUPPORTED and size 0
04-02 01:56:06.475 I/chatty ( 3064): uid=1000(system) health@2.0-serv identical 2 lines
04-02 01:56:17.699 E//vendor/bin/hw/android.hardware.health@2.0-service.imx( 3064): /sys/block/mmcblk0/stat: ReadFileToString failed.
04-02 01:57:03.066 I/system_server( 3219): Background concurrent copying GC freed 187579(7MB) AllocSpace objects, 0(0B) LOS objects, 42% free, 9MB/16MB, paused 305us total 123.137ms
04-02 01:57:06.475 E//vendor/bin/hw/android.hardware.health@2.0-service.imx( 3064): /sys/block/mmcblk0/stat: ReadFileToString failed.
04-02 01:57:17.700 E/storaged( 3106): getDiskStats failed with result NOT_SUPPORTED and size 0
04-02 01:58:17.701 E/storaged( 3106): getDiskStats failed with result NOT_SUPPORTED and size 0
04-02 01:58:06.475 I/chatty ( 3064): uid=1000(system) health@2.0-serv identical 2 lines
04-02 01:58:17.701 E//vendor/bin/hw/android.hardware.health@2.0-service.imx( 3064): /sys/block/mmcblk0/stat: ReadFileToString failed.
04-02 01:58:47.716 I/system_server( 4789): type=1400 audit(0.0:76): avc: denied { execute } for name="sh" dev="dm-0" ino=2396 scontext=u:r:system_server:s0 tcontext=u:object_r:shell_exec:s0 tclass=file permissive=1
04-02 01:58:47.716 I/system_server( 4789): type=1400 audit(0.0:77): avc: denied { read open } for path="/system/bin/sh" dev="dm-0" ino=2396 scontext=u:r:system_server:s0 tcontext=u:object_r:shell_exec:s0 tclass=file permissive=1
04-02 01:58:47.716 I/system_server( 4789): type=1400 audit(0.0:78): avc: denied { execute_no_trans } for path="/system/bin/sh" dev="dm-0" ino=2396 scontext=u:r:system_server:s0 tcontext=u:object_r:shell_exec:s0 tclass=file permissive=1
04-02 01:58:47.716 I/sh ( 4789): type=1400 audit(0.0:79): avc: denied { map } for path="/system/bin/sh" dev="dm-0" ino=2396 scontext=u:r:system_server:s0 tcontext=u:object_r:shell_exec:s0 tclass=file permissive=1
04-02 01:58:47.716 I/sh ( 4789): type=1400 audit(0.0:80): avc: denied { getattr } for path="/system/bin/sh" dev="dm-0" ino=2396 scontext=u:r:system_server:s0 tcontext=u:object_r:shell_exec:s0 tclass=file permissive=1
04-02 01:58:47.772 I/sh ( 4791): type=1400 audit(0.0:81): avc: denied { execute_no_trans } for path="/system/bin/reboot" dev="dm-0" ino=2415 scontext=u:r:system_server:s0 tcontext=u:object_r:system_file:s0 tclass=file permissive=1
04-02 01:58:48.013 E/display ( 3063): threadLoop invalid uevent remove@/devices/platform/32e50000.usb/ci_hdrc.1/usb1/1-1/1-1.2/1-1.2:1.0/ttyUSB0/tty/ttyUSB0
04-02 01:58:48.022 E/display ( 3063): threadLoop invalid uevent unbind@/devices/platform/32e50000.usb/ci_hdrc.1/usb1/1-1/1-1.2/1-1.2:1.0/ttyUSB0
04-02 01:58:48.023 E/display ( 3063): threadLoop invalid uevent remove@/devices/platform/32e50000.usb/ci_hdrc.1/usb1/1-1/1-1.2/1-1.2:1.0/ttyUSB0
04-02 01:58:48.028 E/display ( 3063): threadLoop invalid uevent unbind@/devices/platform/32e50000.usb/ci_hdrc.1/usb1/1-1/1-1.2/1-1.2:1.0
04-02 01:58:48.028 E/display ( 3063): threadLoop invalid uevent remove@/devices/platform/32e50000.usb/ci_hdrc.1/usb1/1-1/1-1.2/1-1.2:1.0
04-02 01:58:48.029 E/display ( 3063): threadLoop invalid uevent unbind@/devices/platform/32e50000.usb/ci_hdrc.1/usb1/1-1/1-1.2
04-02 01:58:48.030 E/display ( 3063): threadLoop invalid uevent remove@/devices/platform/32e50000.usb/ci_hdrc.1/usb1/1-1/1-1.2
04-02 01:58:48.031 D/UsbHostManager( 3219): Removed device at /dev/bus/usb/001/003: USB Serial
04-02 01:58:48.031 I/UsbAlsaManager( 3219): USB Audio Device Removed: null
04-02 01:58:48.032 E/display ( 3063): threadLoop invalid uevent unbind@/devices/platform/32e50000.usb/ci_hdrc.1/usb1/1-1/1-1:1.0
04-02 01:58:48.033 E/display ( 3063): threadLoop invalid uevent remove@/devices/platform/32e50000.usb/ci_hdrc.1/usb1/1-1/1-1:1.0
04-02 01:58:48.033 E/display ( 3063): threadLoop invalid uevent unbind@/devices/platform/32e50000.usb/ci_hdrc.1/usb1/1-1
04-02 01:58:48.034 E/display ( 3063): threadLoop invalid uevent remove@/devices/platform/32e50000.usb/ci_hdrc.1/usb1/1-1
04-02 01:58:48.036 D/UsbHostManager( 3219): Removed device at /dev/bus/usb/001/002 was already gone
04-02 01:58:48.036 E/display ( 3063): threadLoop invalid uevent unbind@/devices/platform/32e50000.usb/ci_hdrc.1/usb1/1-0:1.0
04-02 01:58:48.036 E/display ( 3063): threadLoop invalid uevent remove@/devices/platform/32e50000.usb/ci_hdrc.1/usb1/1-0:1.0
04-02 01:58:48.037 E/display ( 3063): threadLoop invalid uevent unbind@/devices/platform/32e50000.usb/ci_hdrc.1/usb1
04-02 01:58:48.039 E/display ( 3063): threadLoop invalid uevent remove@/devices/platform/32e50000.usb/ci_hdrc.1/usb1
04-02 01:58:48.040 D/UsbHostManager( 3219): Removed device at /dev/bus/usb/001/001 was already gone

Re: The Android 9 system with IMx8mm chip has issues with automatic factory recovery and restart.

Zhiming_Liu — Mon, 08 Apr 2024 04:16:37 GMT

Hi @Only_聆听

这是同一个问题？

https://community.nxp.com/t5/i-MX-Processors/IMX8MM-running-Android-9-0-system-restarts-randomly-watchdog/m-p/1841560#M222188

Re: The Android 9 system with IMx8mm chip has issues with automatic factory recovery and restart.

Zhiming_Liu — Mon, 08 Apr 2024 04:29:46 GMT

@Only_聆听

update_engine 在触发reboot指令，你搜一下reboot,shell，后面有对应的pid，也就是谁发出reboot指令的。log里好像不止是update_engine。

Re: The Android 9 system with IMx8mm chip has issues with automatic factory recovery and restart.

Only_聆听 — Mon, 08 Apr 2024 05:49:05 GMT

您所说的update_engine导致的重启是正常的，因为我们为了验证问题进行了OTA升级。目前我们遇到的问题是下面的log，他指向系统服务，但是这个服务挂载了很多的内容，我现在不太懂如何进一步进行排查了，望指教！

[02:40:58.261]收←◆[12605.640916] healthd: battery l=85 v=3 t=35.0 h=2 st=2 c=400 fc=4000000 cc=32 chg=a

[02:41:58.021]收←◆[12665.404888] healthd: battery l=85 v=3 t=35.0 h=2 st=2 c=400 fc=4000000 cc=32 chg=a

[02:41:58.257]收←◆[12665.640915] healthd: battery l=85 v=3 t=35.0 h=2 st=2 c=400 fc=4000000 cc=32 chg=a

[02:42:58.016]收←◆[12725.404257] healthd: battery l=85 v=3 t=35.0 h=2 st=2 c=400 fc=4000000 cc=32 chg=a

[02:42:58.252]收←◆[12725.641008] healthd: battery l=85 v=3 t=35.0 h=2 st=2 c=400 fc=4000000 cc=32 chg=a

截止这里之前，系统都是正常运行的log

[02:43:52.368]收←◆[12779.759646] type=1400 audit(1712293766.464:46): avc: denied { dac_read_search } for pid=3700 comm="main" capability=2 scontext=u:r:zygote:s0 tcontext=u:r:zygote:s0 tclass=capability permissive=1
[12779.777143] type=1400 audit(1711999837.201:47): avc: denied { execute } for pid=4127 comm="system_server" name="sh" dev="dm-0" ino=2396 scontext=u:r:system_server:s0 tcontext=u:object_r:shell_exec:s0 tclass=file permissive=1
[12779.797634] type=1400 audit(1711999837.201:47): avc: denied { execute } for pid=4127 comm="system_server" name="sh" dev="dm-0" ino=2396 scontext=u:r:system_server:s0 tcontext=u:object_r:shell_exec:s0 tclass=file permissive=1
[12779.818026] type=1400 audit(1711999837.201:48): avc: denied { read open } for pid=4127 comm="system_server" path="/system/bin/sh" dev="dm-0" ino=2396 scontext=u:r:system_server:s0 tcontext=u:object_r:shell_exec:s0 tclass=file permissive=1
[12779.821609] init: ==hd Received sys.powerctl='reboot,shell' from pid: 4129 (reboot)
[12779.839456] type=1400 audit(1711999837.201:48): avc: denied { read open } for pid=4127 comm="system_server" path="/system/bin/sh" dev="dm-0" ino=2396 scontext=u:r:system_server:s0 tcontext=u:object_r:shell_exec:s0 tclass=file permissive=1
[12779.846956] init: sys.powerctl------property_changed --------reboot,shell
[12779.868075] type=1400 audit(1711999837.201:49): avc: denied { execute_no_trans } for pid=4127 comm="system_server" path="/system/bin/sh" dev="dm-0" ino=2396 scontext=u:r:system_server:s0 tcontext=u:object_r:shell_exec:s0 tclass=file permissive=1
[12779.874828] init: sys.powerctl------init reboot--------reboot,shell
[12779.896682] type=1400 audit(1711999837.201:49): avc: denied { execute_no_trans } for pid=4127 comm="system_server" path="/system/bin/sh" dev="dm-0" ino=2396 scontext=u:r:system_server:s0 tcontext=u:object_r:shell_exec:s0 tclass=file permissive=1
[12779.902980] init: Clear action queue and start shutdown trigger
[12779.924637] type=1400 audit(1711999837.201:50): avc: denied { map } for pid=4127 comm="sh" path="/system/bin/sh" dev="dm-0" ino=2396 scontext=u:r:system_server:s0 tcontext=u:object_r:shell_exec:s0 tclass=file permissive=1
[12779.930657] init: processing action (shutdown_done) from (<Builtin Action>:0)
[12779.950280] type=1400 audit(1711999837.201:50): avc: denied { map } for pid=4127 comm="sh" path="/system/bin/sh" dev="dm-0" ino=2396 scontext=u:r:system_server:s0 tcontext=u:object_r:shell_exec:s0 tclass=file permissive=1
[12779.957345] init: =====================================Reboot start, reason: reboot,shell, rebootTarget: shell
[12779.976961] type=1400 audit(1711999837.201:51): avc: denied { getattr } for pid=4127 comm="sh" path="/system/bin/sh" dev="dm-0" ino=2396 scontext=u:r:system_server:s0 tcontext=u:object_r:shell_exec:s0 tclass=file permissive=1
[12780.007697] init: Reboot ending, jumping to kernel
[12780.012559] kvm: exiting hardware virtualization
[12780.026562] imx2-wdt 30280000.wdog: Device shutdown: Expect reboot!
[12780.033066] ci_hdrc ci_hdrc.1: remove, state 1
[12780.037557] usb usb1: USB disconnect, device number 1
[12780.042625] usb 1-1: USB disconnect, device number 2
[12780.047613] usb 1-1.2: USB disconnect, device number 3
[12780.054814] ch341-uart ttyUSB0: ch341-uart converter now disconnected from ttyUSB0
[12780.063128] ch341 1-1.2:1.0: device disconnected
[12780.078168] ci_hdrc ci_hdrc.1: USB bus 1 deregistered
[12780.084875] android_work: sent uevent USB_STATE=DISCONNECTED
[12780.115169] reboot: Restarting system with command 'bootloader'

到这里系统就重启了

[02:43:53.248]收←◆\0
[02:43:53.721]收←◆
U-Boot SPL 2018.03-dirty (Dec 21 2021 - 15:08:37 +0800)

Re: The Android 9 system with IMx8mm chip has issues with automatic factory recovery and restart.

Zhiming_Liu — Mon, 08 Apr 2024 06:11:10 GMT

系统起来之后，等一会儿把所有的pid信息都dump出来，然后等它crash（这一步可能会找到是哪个脚本），你多测试几遍。

从log看触发reboot的文件位于/dm-0下面，node编号2415。可能和这个错有关：/sys/block/mmcblk0/stat: ReadFileToString failed

Re: The Android 9 system with IMx8mm chip has issues with automatic factory recovery and restart.

Only_聆听 — Thu, 11 Apr 2024 14:52:39 GMT

您好，我们实际上排查过PID，最终是指向了系统服务，但是系统服务上挂载了很多的内容，如下图，图中圈住的两个服务是我们的软件，但是我们排除我们软件编译后，仍然复现了重启。

然后我们增加了打印，发现是这个函数调用的重启，但是我们围绕这个函数增加了很多的打印，但是其它的打印未打出来。

复现问题时候的打印

我们增加打印的位置如附件，望指导下！

Re: The Android 9 system with IMx8mm chip has issues with automatic factory recovery and restart.

Zhiming_Liu — Fri, 12 Apr 2024 00:21:46 GMT

Hi @Only_聆听

你们有自定义的shell脚本吗？或者修改过里面的shell脚本吗？

Re: The Android 9 system with IMx8mm chip has issues with automatic factory recovery and restart.

Only_聆听 — Fri, 12 Apr 2024 05:26:37 GMT

您好，并没有，所以非常奇怪，不知道哪里调用了reboot，如果方便的话，可以加下我微信li865697135

Re: The Android 9 system with IMx8mm chip has issues with automatic factory recovery and restart.

Only_聆听 — Mon, 15 Apr 2024 03:17:41 GMT

Hi 刘工：

我们现在发现同样的软件，通过USB使用uuu工具烧录的话，软件是运行正常的。但是如果通过OTA升级(A/B分区)就能复现重启问题，这是为啥？有这方面的bug记录吗？

Re: The Android 9 system with IMx8mm chip has issues with automatic factory recovery and restart.

Zhiming_Liu — Mon, 15 Apr 2024 06:05:27 GMT

Hi @Only_聆听

你们的差分包差异大吗？

Re: The Android 9 system with IMx8mm chip has issues with automatic factory recovery and restart.

Only_聆听 — Mon, 15 Apr 2024 07:48:17 GMT

Hi 刘工：

我是使用make otapackage -j100进行编译的，这应该是全包，或者我应该如何确认是不是差分包咧。

Re: The Android 9 system with IMx8mm chip has issues with automatic factory recovery and restart.

Zhiming_Liu — Tue, 16 Apr 2024 05:50:45 GMT

你试试差分OTA会不会有这个问题。或者全包OTA只改一个文件。

Re: The Android 9 system with IMx8mm chip has issues with automatic factory recovery and restart.

Only_聆听 — Mon, 22 Apr 2024 00:55:41 GMT

您好，有其他客户反馈过这种问题吗？而且我们发现重启问题和时间有一定关系，假设它正在无限重启，我们重新设定时间后，重启将停止，这是系统中有什么校验机制吗？

Re: The Android 9 system with IMx8mm chip has issues with automatic factory recovery and restart.

Zhiming_Liu — Mon, 22 Apr 2024 04:26:37 GMT

没有遇到过类似的问题，一般我们都会建议客户至少升级到Android10，Android9支持的资源太少了。重新设定时间是什么意思？默认上电的时间不是经过时间同步过的时间吗？然后你手动同步后就没问题了？

Re: The Android 9 system with IMx8mm chip has issues with automatic factory recovery and restart.

Only_聆听 — Wed, 24 Apr 2024 02:21:01 GMT

Hi Liu：

您好，我再总结和更新下这个问题的现象：

1、我们的产品从21年5月左右开始对开售卖，但是在2024年的3-4月，大量已经运行了1-3年的机器出现无限重启和被复位的情况。而且问题发生在全球不同的国家。机器发生问题的时候，很多机器都集中在同一天，例如3月6日、4-1日。

2、我们能获取到的异常机器，debug日志都显示系统服务调用了重启进程；

3、机器无限重启的间隔是1分25S，我们在40S左右就可以使用ADB，此时通过ADB命令date 040123592024.00重新设定任意系统时间，无限重启会立即暂停。但是设定时间后，静置老化仍然有可能会复现无限重启的现象。

4、我们原来以为通过USB烧录的机器不会存在问题，是升级了OTA包导致的问题，但是4-23日，客户端使用USB烧录的机器也出现了问题，证明升级OTA包只是加速了问题复现，并不是问题终因。

5、我们能否获得NXP的高效支持，论坛里面解决问题太慢了，我们可以去现场或者技术支持到我们这里。

6、我们做了很多的努力，尝试通过sys.powerctl 、property_set等关键词增加流程打印，但是收获甚微，追踪到__system_property_set和property_set函数后，就没能找到更往前的调用了，涉及到这些函数调用的函数都增加了打印，但是打印并没有打出来。

7、所有的异常机器重启前的debug串口日志如下：

[00:25:40.016]收←◆[25486.593580] type=1400 audit(1713754045.964:74): avc: denied { execute } for pid=3730 comm=4A69742074687265616420706F6F6C path=2F6465762F6173686D656D2F64616C76696B2D6A69742D636F64652D6361636865202864656C6574656429 dev="tmpfs" ino=26957 scontext=u:r:system_server:s0 tcontext=u:object_r:system_server_tmpfs:s0 tclass=file permissive=1
[25486.623585] type=1400 audit(1711993463.968:75): avc: denied { execute } for pid=4855 comm="system_server" name="sh" dev="dm-0" ino=2396 scontext=u:r:system_server:s0 tcontext=u:object_r:shell_exec:s0 tclass=file permissive=1
[25486.644680] type=1400 audit(1711993463.968:75): avc: denied { execute } for pid=4855 comm="system_server" name="sh" dev="dm-0" ino=2396 scontext=u:r:system_server:s0 tcontext=u:object_r:shell_exec:s0 tclass=file permissive=1
[25486.664849] type=1400 audit(1711993463.968:76): avc: denied { read open } for pid=4855 comm="system_server" path="/system/bin/sh" dev="dm-0" ino=2396 scontext=u:r:system_server:s0 tcontext=u:object_r:shell_exec:s0 tclass=file permissive=1
[25486.686768] type=1400 audit(1711993463.968:76): avc: denied { read open } for pid=4855 comm="system_server" path="/system/bin/sh" dev="dm-0" ino=2396 scontext=u:r:system_server:s0 tcontext=u:object_r:shell_exec:s0 tclass=file permissive=1
[25486.708249] type=1400 audit(1711993463.968:77): avc: denied { execute_no_trans } for pid=4855 comm="system_server" path="/system/bin/sh" dev="dm-0" ino=2396 scontext=u:r:system_server:s0 tcontext=u:object_r:shell_exec:s0 tclass=file permissive=1
[25486.731496] type=1400 audit(1711993463.968:77): avc: denied { execute_no_trans } for pid=4855 comm="system_server" path="/system/bin/sh" dev="dm-0" ino=2396 scontext=u:r:system_server:s0 tcontext=u:object_r:shell_exec:s0 tclass=file permissive=1
[25486.741182] init: ==hd Received sys.powerctl='reboot,shell' from pid: 4857 (reboot)
[25486.753666] type=1400 audit(1711993463.968:78): avc: denied { map } for pid=4855 comm="sh" path="/system/bin/sh" dev="dm-0" ino=2396 scontext=u:r:system_server:s0 tcontext=u:object_r:shell_exec:s0 tclass=file permissive=1
[25486.761063] init: sys.powerctl------property_changed --------reboot,shell
[25486.781210] type=1400 audit(1711993463.968:78): avc: denied { map } for pid=4855 comm="sh" path="/system/bin/sh" dev="dm-0" ino=2396 scontext=u:r:system_server:s0 tcontext=u:object_r:shell_exec:s0 tclass=file permissive=1
[25486.787505] init: sys.powerctl------init reboot--------reboot,shell
[25486.807271] type=1400 audit(1711993463.972:79): avc: denied { getattr } for pid=4855 comm="sh" path="/system/bin/sh" dev="dm-0" ino=2396 scontext=u:r:system_server:s0 tcontext=u:object_r:shell_exec:s0 tclass=file permissive=1
[25486.813691] init: Clear action queue and start shutdown trigger
[25486.839567] init: processing action (shutdown_done) from (<Builtin Action>:0)
[25486.846769] init: =====================================Reboot start, reason: reboot,shell, rebootTarget: shell
[25486.866728] init: persist.sys.boot.reason------property_changed --------reboot,shell
[25486.880762] init: Shutdown timeout: 6000 ms
[25486.886171] init: starting service 'blank_screen'...
[25486.892866] init: init.svc.blank_screen------property_changed --------running

143|evk_8mm:/ $
[00:25:40.749]收←◆[25487.326458] binder_alloc: 3196: binder_alloc_buf, no vma
[25487.331838] binder: 2950:2950 transaction failed 29189/-3, size 88-0 line 3155

[00:25:40.806]收←◆[25487.382755] binder: undelivered TRANSACTION_COMPLETE
[25487.387821] binder: undelivered transaction 24664, process died.
[25487.396821] binder: undelivered death notification, 0000eb4084a675e0

[00:25:40.906]收←◆[25487.483448] android_work: sent uevent USB_STATE=DISCONNECTED
[25487.487326] logd.daemon: 56 output lines suppressed due to ratelimiting

[00:25:41.226]收←◆[25487.803367] kvm: exiting hardware virtualization
[25487.817162] imx2-wdt 30280000.wdog: Device shutdown: Expect reboot!
[25487.824067] ci_hdrc ci_hdrc.1: remove, state 1
[25487.828605] usb usb1: USB disconnect, device number 1
[25487.833704] usb 1-1: USB disconnect, device number 2
[25487.838714] usb 1-1.2: USB disconnect, device number 3
[25487.846190] ch341-uart ttyUSB0: ch341-uart converter now disconnected from ttyUSB0
[25487.853960] ch341 1-1.2:1.0: device disconnected
[25487.864672] ci_hdrc ci_hdrc.1: USB bus 1 deregistered
[25487.886043] reboot: Restarting system with command 'shell'

Re: The Android 9 system with IMx8mm chip has issues with automatic factory recovery and restart.

Zhiming_Liu — Wed, 24 Apr 2024 05:36:35 GMT

Hi @Only_聆听

对于你说的支持方法问题，建议使用公司渠道联系到第三方代理商/NXP sales。

另外，综合你说的背景以及log看，应该和emmc老化有关系。

04-02 03:12:21.610 E//vendor/bin/hw/android.hardware.health@2.0-service.imx( 3061): /sys/block/mmcblk0/stat: ReadFileToString failed. 04-02 03:12:21.610 E/storaged( 3103): getDiskStats failed with result NOT_SUPPORTED and size 0 04-02 03:13:21.611 E/storaged( 3103): getDiskStats failed with result NOT_SUPPORTED and size 0

Re: The Android 9 system with IMx8mm chip has issues with automatic factory recovery and restart.

Only_聆听 — Wed, 24 Apr 2024 05:42:35 GMT

Hi Liu

您好，如果说跟EMMC老化有关系，在系统的机制内，会有什么服务会主动的调用重启命令？而且在不断的重启过程中，只要我更改了时间，他就能立即停止重启的现象，这明显是跟什么校验机制有关，这跟EMMC老化逻辑似乎说不通。

Re: The Android 9 system with IMx8mm chip has issues with automatic factory recovery and restart.

Only_聆听 — Thu, 25 Apr 2024 14:04:06 GMT

Hi Liu：

通过技术支持获得了一块原厂的DEMO板，然后烧录原厂提供的示例镜像，也存在您所说的报错问题。