Android OTA upgrade failed

VulcainMan · January 28, 2022, 9:13am

Dear Khadas team, @jasonl, @tenk.wang, @goenjoy

We are currently planning to build IPTV/eHealth solutions powered by Khadas VIM3 running Android. We are currently tuning Khadas’s AOSP 9.0 tree in order to fit our needs and until now, things are moving forward as we expect.

In our context, the products will may be deployed at any location then we need to be able to distribute system updates via the OTA mechanism in order to allow end users to update devices easily. As a first step, we would like to update the system via an OTA package stored on the sdcard and use Khadas’ OTAUpgrade2 app. When we do that, the upgrade start and progress then suddendly stop and reboot when Android popup reach 20%.

Here are the logs got via logcat during upgrade

01-28 08:35:39.582 4615 18084 D OTA : copyFile/storage/emulated/0/kvim3-ota-eng.bob.zipto/data/cache/update.zip
01-28 08:35:39.588 4615 18084 D OTA : enter updateWithBCB
01-28 08:35:39.592 4615 18084 D OTA : updateWithBCB
01-28 08:35:39.964 4782 4782 W ServiceManagement: Waited one second for android.hardware.radio@1.0::IRadio/slot1. Waiting another…
01-28 08:35:40.613 18104 18104 I /system/bin/uncrypt: received command: [–update_package=@/cache/recovery/block.map
01-28 08:35:40.613 18104 18104 I /system/bin/uncrypt: --locale=en-US
01-28 08:35:40.613 18104 18104 I /system/bin/uncrypt: ] (59)
01-28 08:35:40.623 18104 18104 I /system/bin/uncrypt: received 0, exiting now
01-28 08:35:18.324 4615 4615 I chatty : uid=1000(system) com.droidlogic.otaupgrade identical 20 lines
01-28 08:35:18.341 4615 4615 D ViewRootImpl[MainActivity]: updatePointerIcon called with position out of bounds
01-28 08:35:40.627 3749 4248 I RecoverySystemService: uncrypt setup bcb successfully finished.
01-28 08:35:40.651 3749 3765 D ShutdownThread: Notifying thread to start shutdown longPressBehavior=1
01-28 08:35:40.691 3512 3512 E Layer : layer [Dim Layer for - Task=4#0] computeScreenBounds - NO PARENT [0, 0, 1920, 1080]
01-28 08:35:40.702 3749 18105 I ShutdownThread: Sending shutdown broadcast…
01-28 08:35:40.705 3749 3749 W SyncManager: Writing sync state before shutdown…
01-28 08:35:40.712 3495 3540 D MesonHwc: wait for vsync success, (0xa6ea1590) peroid: 16680500
01-28 08:35:40.713 3512 3512 E Layer : layer [Dim Layer for - Task=4#0] computeScreenBounds - NO PARENT [0, 0, 1920, 1080]
01-28 08:35:40.721 3494 3494 I gralloc : framebuffer hal alread move to hwcomposer
01-28 08:35:40.723 3749 3772 I EntropyMixer: Writing entropy…
01-28 08:35:40.724 3512 3778 I gralloc : ddebug, pair (share_fd=118, user_hnd=12, ion_client=30)
01-28 08:35:40.724 3494 3696 I gralloc : framebuffer hal alread move to hwcomposer
01-28 08:35:40.726 3512 3778 I gralloc : ddebug, pair (share_fd=123, user_hnd=13, ion_client=30)
01-28 08:35:40.726 3494 3695 I gralloc : framebuffer hal alread move to hwcomposer
01-28 08:35:40.729 3512 3778 I gralloc : ddebug, pair (share_fd=126, user_hnd=14, ion_client=30)
01-28 08:35:40.730 3512 3512 E Layer : layer [Dim Layer for - Task=4#0] computeScreenBounds - NO PARENT [0, 0, 1920, 1080]
01-28 08:35:40.732 3749 18054 D mali_winsys: EGLint new_window_surface(egl_winsys_display *, void *, EGLSurface, EGLConfig, egl_winsys_surface **, EGLBoolean) returns 0x3000
01-28 08:35:40.734 3512 3551 I gralloc : ddebug, free share_fd=126, user_hnd=0x14, ion client=30
01-28 08:35:40.735 3494 18106 I gralloc : framebuffer hal alread move to hwcomposer
01-28 08:35:40.738 3512 3551 I gralloc : ddebug, pair (share_fd=126, user_hnd=14, ion_client=30)
01-28 08:35:40.741 3749 18054 I gralloc : ddebug, pair (share_fd=268, user_hnd=2, ion_client=174)
01-28 08:35:40.747 3512 3512 E Layer : layer [Dim Layer for - Task=4#0] computeScreenBounds - NO PARENT [0, 0, 1920, 1080]
01-28 08:35:40.763 3749 3749 I StatsCompanionService: StatsCompanionService noticed a shutdown.
01-28 08:35:40.797 3512 3512 E Layer : layer [Dim Layer for - Task=4#0] computeScreenBounds - NO PARENT [0, 0, 1920, 1080]
01-28 08:35:40.798 3512 3551 I gralloc : ddebug, free share_fd=123, user_hnd=0x13, ion client=30
01-28 08:35:40.799 3494 18106 I gralloc : framebuffer hal alread move to hwcomposer
01-28 08:35:40.801 3512 3551 I gralloc : ddebug, pair (share_fd=123, user_hnd=13, ion_client=30)
01-28 08:35:40.802 3749 18054 I gralloc : ddebug, pair (share_fd=271, user_hnd=4, ion_client=174)
01-28 08:35:40.814 3512 3512 E Layer : layer [Dim Layer for - Task=4#0] computeScreenBounds - NO PARENT [0, 0, 1920, 1080]
01-28 08:35:40.814 3512 3512 E Layer : layer [Dim Layer for - mAboveAppWindowsContainers#0] computeScreenBounds - NO PARENT [0, 0, 1920, 1080]
01-28 08:35:40.830 3512 3512 E Layer : layer [Dim Layer for - Task=4#0] computeScreenBounds - NO PARENT [0, 0, 1920, 1080]
01-28 08:35:40.830 3512 3512 E Layer : layer [Dim Layer for - mAboveAppWindowsContainers#0] computeScreenBounds - NO PARENT [0, 0, 1920, 1080]
01-28 08:35:40.831 3495 3689 I gralloc : ddebug, pair (share_fd=62, user_hnd=1, ion_client=34)
01-28 08:35:40.847 3512 3512 E Layer : layer [Dim Layer for - Task=4#0] computeScreenBounds - NO PARENT [0, 0, 1920, 1080]
01-28 08:35:40.847 3512 3512 E Layer : layer [Dim Layer for - mAboveAppWindowsContainers#0] computeScreenBounds - NO PARENT [0, 0, 1920, 1080]
01-28 08:35:40.863 3512 3512 E Layer : layer [Dim Layer for - Task=4#0] computeScreenBounds - NO PARENT [0, 0, 1920, 1080]
01-28 08:35:40.863 3512 3512 E Layer : layer [Dim Layer for - mAboveAppWindowsContainers#0] computeScreenBounds - NO PARENT [0, 0, 1920, 1080]
01-28 08:35:40.878 3749 18105 D ShutdownTiming: SendShutdownBroadcast took to complete: 176ms
01-28 08:35:40.878 3749 18105 I ShutdownThread: Shutting down activity manager…
01-28 08:35:40.880 3512 3512 E Layer : layer [Dim Layer for - Task=4#0] computeScreenBounds - NO PARENT [0, 0, 1920, 1080]
01-28 08:35:40.880 3512 3512 E Layer : layer [Dim Layer for - mAboveAppWindowsContainers#0] computeScreenBounds - NO PARENT [0, 0, 1920, 1080]
01-28 08:35:40.888 3749 18105 W AppOps : Writing app ops before shutdown…
01-28 08:35:40.895 3749 18105 I UsageStatsService: User[0] Flushing usage stats to disk
01-28 08:35:40.897 3512 3777 I gralloc : ddebug, free share_fd=118, user_hnd=0x12, ion client=30
01-28 08:35:40.897 3512 3512 E Layer : layer [Dim Layer for - Task=4#0] computeScreenBounds - NO PARENT [0, 0, 1920, 1080]
01-28 08:35:40.897 3512 3512 E Layer : layer [Dim Layer for - mAboveAppWindowsContainers#0] computeScreenBounds - NO PARENT [0, 0, 1920, 1080]
01-28 08:35:40.897 3494 18106 I gralloc : framebuffer hal alread move to hwcomposer
01-28 08:35:40.903 3512 3777 I gralloc : ddebug, pair (share_fd=120, user_hnd=12, ion_client=30)
01-28 08:35:40.904 3749 18054 I gralloc : ddebug, pair (share_fd=273, user_hnd=6, ion_client=174)
01-28 08:35:40.915 3512 3512 E Layer : layer [Dim Layer for - Task=4#0] computeScreenBounds - NO PARENT [0, 0, 1920, 1080]
01-28 08:35:40.915 3512 3512 E Layer : layer [Dim Layer for - mAboveAppWindowsContainers#0] computeScreenBounds - NO PARENT [0, 0, 1920, 1080]
01-28 08:35:40.916 3495 3689 I gralloc : ddebug, pair (share_fd=73, user_hnd=c, ion_client=34)
01-28 08:35:40.925 3749 18105 W BatteryStats: Writing battery stats before shutdown…
01-28 08:35:40.929 3508 3508 D WifiHAL : In DebugCommand::handleResponse
01-28 08:35:40.929 3508 3508 D WifiHAL : len = 4, expected len = 4
01-28 08:35:40.945 3508 3508 D WifiHAL : In DebugCommand::handleResponse
01-28 08:35:40.945 3508 3508 D WifiHAL : len = 4, expected len = 4
01-28 08:35:40.946 3512 3512 E Layer : layer [Dim Layer for - Task=4#0] computeScreenBounds - NO PARENT [0, 0, 1920, 1080]
01-28 08:35:40.946 3512 3512 E Layer : layer [Dim Layer for - mAboveAppWindowsContainers#0] computeScreenBounds - NO PARENT [0, 0, 1920, 1080]
01-28 08:35:40.947 3495 3689 I gralloc : ddebug, pair (share_fd=75, user_hnd=d, ion_client=34)
01-28 08:35:40.953 3512 3512 E Layer : layer [Dim Layer for - Task=4#0] computeScreenBounds - NO PARENT [0, 0, 1920, 1080]
01-28 08:35:40.953 3512 3512 E Layer : layer [Dim Layer for - mAboveAppWindowsContainers#0] computeScreenBounds - NO PARENT [0, 0, 1920, 1080]
01-28 08:35:40.964 4782 4782 W ServiceManagement: Waited one second for android.hardware.radio@1.0::IRadio/slot1. Waiting another…
01-28 08:35:40.924 3508 3508 I wifi@1.0-servic: type=1400 audit(0.0:1128): avc: denied { getattr } for path=“/data/vendor/wifi/wid_fp” dev=“mmcblk0p20” ino=391805 scontext=u:r:hal_wifi_default:s0 tcontext=u:object_r:vendor_data_file:s0 tclass=file permissive=1
01-28 08:35:40.980 3749 3768 E BatteryExternalStatsWorker: no controller energy info supplied for telephony
01-28 08:35:40.981 3512 3512 E Layer : layer [Dim Layer for - Task=4#0] computeScreenBounds - NO PARENT [0, 0, 1920, 1080]
01-28 08:35:40.981 3512 3512 E Layer : layer [Dim Layer for - mAboveAppWindowsContainers#0] computeScreenBounds - NO PARENT [0, 0, 1920, 1080]
01-28 08:35:40.984 3503 3503 I PowerHAL: geNumberOfPlatformModes
01-28 08:35:40.991 3749 18105 W ProcessStatsService: Writing process stats before shutdown…
01-28 08:35:40.996 3749 3866 E TaskPersister: File error accessing recents directory (directory doesn’t exist?).
01-28 08:35:40.996 3749 18105 D ShutdownTiming: ShutdownActivityManager took to complete: 118ms
01-28 08:35:40.996 3749 18105 I ShutdownThread: Shutting down package manager…
01-28 08:35:40.998 3512 3512 E Layer : layer [Dim Layer for - Task=4#0] computeScreenBounds - NO PARENT [0, 0, 1920, 1080]
01-28 08:35:40.998 3512 3512 E Layer : layer [Dim Layer for - mAboveAppWindowsContainers#0] computeScreenBounds - NO PARENT [0, 0, 1920, 1080]
01-28 08:35:41.014 3512 3512 E Layer : layer [Dim Layer for - Task=4#0] computeScreenBounds - NO PARENT [0, 0, 1920, 1080]
01-28 08:35:41.015 3512 3512 E Layer : layer [Dim Layer for - mAboveAppWindowsContainers#0] computeScreenBounds - NO PARENT [0, 0, 1920, 1080]
01-28 08:35:41.022 3749 18105 D ShutdownTiming: ShutdownPackageManager took to complete: 26ms
01-28 08:35:41.023 3749 18112 I ShutdownThread: Waiting for Radio…
01-28 08:35:41.023 3749 18112 I ShutdownThread: Radio shutdown complete.
01-28 08:35:41.024 3749 18105 D ShutdownTiming: ShutdownRadios took to complete: 2ms
01-28 08:35:41.024 3749 18105 I ShutdownThread: Calling uncrypt and monitoring the progress…
01-28 08:35:41.965 4782 4782 W ServiceManagement: Waited one second for android.hardware.radio@1.0::IRadio/slot1. Waiting another…
01-28 08:35:42.032 18114 18114 I /system/bin/uncrypt: update package is “/data/cache/update.zip”
01-28 08:35:42.033 18114 18114 I /system/bin/uncrypt: encryptable: no
01-28 08:35:42.033 18114 18114 I /system/bin/uncrypt: encrypted: no
01-28 08:35:42.033 18114 18114 I /system/bin/uncrypt: writing block map /cache/recovery/block.map
01-28 08:35:42.033 3749 18113 I RecoverySystemService: uncrypt read status: 0
01-28 08:35:42.035 18114 18114 I /system/bin/uncrypt: block size: 4096 bytes
01-28 08:35:42.035 18114 18114 I /system/bin/uncrypt: file size: 403861541 bytes, 98600 blocks
01-28 08:35:42.039 3749 18113 I RecoverySystemService: uncrypt read status: 1
01-28 08:35:42.043 3749 18113 I RecoverySystemService: uncrypt read status: 2
01-28 08:35:42.048 3749 18113 I RecoverySystemService: uncrypt read status: 3
01-28 08:35:42.051 3749 18113 I RecoverySystemService: uncrypt read status: 4
01-28 08:35:42.053 3749 18113 I RecoverySystemService: uncrypt read status: 5
01-28 08:35:42.055 3749 18113 I RecoverySystemService: uncrypt read status: 6
01-28 08:35:42.058 3749 18113 I RecoverySystemService: uncrypt read status: 7
01-28 08:35:42.060 3749 18113 I RecoverySystemService: uncrypt read status: 8
01-28 08:35:42.062 3749 18113 I RecoverySystemService: uncrypt read status: 9
01-28 08:35:42.064 3749 18113 I RecoverySystemService: uncrypt read status: 10
01-28 08:35:42.067 3749 18113 I RecoverySystemService: uncrypt read status: 11
01-28 08:35:42.069 3749 18113 I RecoverySystemService: uncrypt read status: 12
01-28 08:35:42.071 3749 18113 I RecoverySystemService: uncrypt read status: 13
01-28 08:35:42.073 3749 18113 I RecoverySystemService: uncrypt read status: 14
01-28 08:35:42.074 3749 18113 I RecoverySystemService: uncrypt read status: 15
01-28 08:35:42.075 3749 18113 I RecoverySystemService: uncrypt read status: 16
01-28 08:35:42.077 3749 18113 I RecoverySystemService: uncrypt read status: 17
01-28 08:35:42.078 3749 18113 I RecoverySystemService: uncrypt read status: 18
01-28 08:35:42.080 3749 18113 I RecoverySystemService: uncrypt read status: 19
01-28 08:35:42.081 3749 18113 I RecoverySystemService: uncrypt read status: 20
01-28 08:35:42.082 3749 18113 I RecoverySystemService: uncrypt read status: 21
01-28 08:35:42.084 3749 18113 I RecoverySystemService: uncrypt read status: 22
01-28 08:35:42.085 3749 18113 I RecoverySystemService: uncrypt read status: 23
01-28 08:35:42.087 3749 18113 I RecoverySystemService: uncrypt read status: 24
01-28 08:35:42.088 3749 18113 I RecoverySystemService: uncrypt read status: 25
01-28 08:35:42.089 3749 18113 I RecoverySystemService: uncrypt read status: 26
01-28 08:35:42.091 3749 18113 I RecoverySystemService: uncrypt read status: 27
01-28 08:35:42.092 3749 18113 I RecoverySystemService: uncrypt read status: 28
01-28 08:35:42.094 3749 18113 I RecoverySystemService: uncrypt read status: 29
01-28 08:35:42.095 3749 18113 I RecoverySystemService: uncrypt read status: 30
01-28 08:35:42.096 3749 18113 I RecoverySystemService: uncrypt read status: 31
01-28 08:35:42.097 3749 18113 I RecoverySystemService: uncrypt read status: 32
01-28 08:35:42.098 3749 18113 I RecoverySystemService: uncrypt read status: 33
01-28 08:35:42.099 3749 18113 I RecoverySystemService: uncrypt read status: 34
01-28 08:35:42.100 3749 18113 I RecoverySystemService: uncrypt read status: 35
01-28 08:35:42.101 3749 18113 I RecoverySystemService: uncrypt read status: 36
01-28 08:35:42.102 3749 18113 I RecoverySystemService: uncrypt read status: 37
01-28 08:35:42.103 3749 18113 I RecoverySystemService: uncrypt read status: 38
01-28 08:35:42.104 3749 18113 I RecoverySystemService: uncrypt read status: 39
01-28 08:35:42.105 3749 18113 I RecoverySystemService: uncrypt read status: 40
01-28 08:35:42.106 3749 18113 I RecoverySystemService: uncrypt read status: 41
01-28 08:35:42.107 3749 18113 I RecoverySystemService: uncrypt read status: 42
01-28 08:35:42.108 3749 18113 I RecoverySystemService: uncrypt read status: 43
01-28 08:35:42.109 3749 18113 I RecoverySystemService: uncrypt read status: 44
01-28 08:35:42.110 3749 18113 I RecoverySystemService: uncrypt read status: 45
01-28 08:35:42.111 3749 18113 I RecoverySystemService: uncrypt read status: 46
01-28 08:35:42.112 3749 18113 I RecoverySystemService: uncrypt read status: 47
01-28 08:35:42.113 3749 18113 I RecoverySystemService: uncrypt read status: 48
01-28 08:35:42.114 3749 18113 I RecoverySystemService: uncrypt read status: 49
01-28 08:35:42.115 3749 18113 I RecoverySystemService: uncrypt read status: 50
01-28 08:35:42.116 3749 18113 I RecoverySystemService: uncrypt read status: 51
01-28 08:35:42.117 3749 18113 I RecoverySystemService: uncrypt read status: 52
01-28 08:35:42.118 3749 18113 I RecoverySystemService: uncrypt read status: 53
01-28 08:35:42.119 3749 18113 I RecoverySystemService: uncrypt read status: 54
01-28 08:35:42.120 3749 18113 I RecoverySystemService: uncrypt read status: 55
01-28 08:35:42.121 3749 18113 I RecoverySystemService: uncrypt read status: 56
01-28 08:35:42.122 3749 18113 I RecoverySystemService: uncrypt read status: 57
01-28 08:35:42.123 3749 18113 I RecoverySystemService: uncrypt read status: 58
01-28 08:35:42.124 3749 18113 I RecoverySystemService: uncrypt read status: 59
01-28 08:35:42.125 3749 18113 I RecoverySystemService: uncrypt read status: 60
01-28 08:35:42.126 3749 18113 I RecoverySystemService: uncrypt read status: 61
01-28 08:35:42.126 3749 18113 I RecoverySystemService: uncrypt read status: 62
01-28 08:35:42.127 3749 18113 I RecoverySystemService: uncrypt read status: 63
01-28 08:35:42.128 3749 18113 I RecoverySystemService: uncrypt read status: 64
01-28 08:35:42.129 3749 18113 I RecoverySystemService: uncrypt read status: 65
01-28 08:35:42.130 3495 3540 D MesonHwc: wait for vsync success, (0xa6ea1590) peroid: 16697125
01-28 08:35:42.130 3749 18113 I RecoverySystemService: uncrypt read status: 66
01-28 08:35:42.131 3749 18113 I RecoverySystemService: uncrypt read status: 67
01-28 08:35:42.132 3749 18113 I RecoverySystemService: uncrypt read status: 68
01-28 08:35:42.133 3749 18113 I RecoverySystemService: uncrypt read status: 69
01-28 08:35:42.133 3749 18113 I RecoverySystemService: uncrypt read status: 70
01-28 08:35:42.134 3749 18113 I RecoverySystemService: uncrypt read status: 71
01-28 08:35:42.135 3749 18113 I RecoverySystemService: uncrypt read status: 72
01-28 08:35:42.136 3749 18113 I RecoverySystemService: uncrypt read status: 73
01-28 08:35:42.137 3749 18113 I RecoverySystemService: uncrypt read status: 74
01-28 08:35:42.138 3749 18113 I RecoverySystemService: uncrypt read status: 75
01-28 08:35:42.139 3749 18113 I RecoverySystemService: uncrypt read status: 76
01-28 08:35:42.140 3749 18113 I RecoverySystemService: uncrypt read status: 77
01-28 08:35:42.140 3749 18113 I RecoverySystemService: uncrypt read status: 78
01-28 08:35:42.141 3749 18113 I RecoverySystemService: uncrypt read status: 79
01-28 08:35:42.142 3749 18113 I RecoverySystemService: uncrypt read status: 80
01-28 08:35:42.143 3749 18113 I RecoverySystemService: uncrypt read status: 81
01-28 08:35:42.144 3749 18113 I RecoverySystemService: uncrypt read status: 82
01-28 08:35:42.145 3749 18113 I RecoverySystemService: uncrypt read status: 83
01-28 08:35:42.146 3749 18113 I RecoverySystemService: uncrypt read status: 84
01-28 08:35:42.147 3749 18113 I RecoverySystemService: uncrypt read status: 85
01-28 08:35:42.147 3749 18113 I RecoverySystemService: uncrypt read status: 86
01-28 08:35:42.148 3749 18113 I RecoverySystemService: uncrypt read status: 87
01-28 08:35:42.149 3749 18113 I RecoverySystemService: uncrypt read status: 88
01-28 08:35:42.150 3749 18113 I RecoverySystemService: uncrypt read status: 89
01-28 08:35:42.151 3749 18113 I RecoverySystemService: uncrypt read status: 90
01-28 08:35:42.152 3749 18113 I RecoverySystemService: uncrypt read status: 91
01-28 08:35:42.153 3749 18113 I RecoverySystemService: uncrypt read status: 92
01-28 08:35:42.153 3749 18113 I RecoverySystemService: uncrypt read status: 93
01-28 08:35:42.155 3749 18113 I RecoverySystemService: uncrypt read status: 94
01-28 08:35:42.155 3749 18113 I RecoverySystemService: uncrypt read status: 95
01-28 08:35:42.156 3749 18113 I RecoverySystemService: uncrypt read status: 96
01-28 08:35:42.157 3749 18113 I RecoverySystemService: uncrypt read status: 97
01-28 08:35:42.158 3749 18113 I RecoverySystemService: uncrypt read status: 98
01-28 08:35:42.159 3749 18113 I RecoverySystemService: uncrypt read status: 99
01-28 08:35:42.165 3749 18113 I RecoverySystemService: uncrypt read status: 100
01-28 08:35:42.165 3749 18113 I RecoverySystemService: uncrypt successfully finished.
01-28 08:35:42.165 3749 18105 D ShutdownTiming: SystemServerShutdown took to complete: 1465ms
01-28 08:35:42.165 18114 18114 I /system/bin/uncrypt: received 0, exiting now
01-28 08:35:42.166 3749 18105 I ShutdownThread: Rebooting, reason: recovery-update
01-28 08:35:42.193 4289 4289 E wpa_supplicant: nl80211: Failed to open /proc/sys/net/ipv4/conf/p2p-dev-wlan0/drop_unicast_in_l2_multicast: No such file or directory
01-28 08:35:42.193 4289 4289 E wpa_supplicant: nl80211: Failed to set IPv4 unicast in multicast filter
01-28 08:35:42.194 4289 4289 E wpa_supplicant: nl80211: Failed to open /proc/sys/net/ipv4/conf/p2p-dev-wlan0/drop_unicast_in_l2_multicast: No such file or directory
01-28 08:35:42.194 4289 4289 E wpa_supplicant: nl80211: Failed to set IPv4 unicast in multicast filter
01-28 08:35:42.194 4289 4289 I wpa_supplicant: nl80211: deinit ifname=p2p-dev-wlan0 disabled_11b_rates=0
01-28 08:35:42.203 3378 3378 I ServiceManager: service ‘android.service.gatekeeper.IGateKeeperService’ died
01-28 08:35:42.203 3378 3378 I ServiceManager: service ‘perfprofd’ died
01-28 08:35:42.204 3578 3578 I wificond: wificond is about to exit
01-28 08:35:42.204 3578 3578 I wificond: Unsubscribe scan result for interface with index: 8
01-28 08:35:42.210 3378 3378 I ServiceManager: service ‘thermalservice’ died
01-28 08:35:42.218 3749 3851 E UsbPortManager: Usb hal service died cookie: 1000
01-28 08:35:42.227 18116 18116 E /system/bin/blank_screen: Failed to shut off screen for type 0
01-28 08:35:42.238 3378 3378 I ServiceManager: service ‘storaged’ died
01-28 08:35:42.238 3378 3378 I ServiceManager: service ‘storaged_pri’ died
01-28 08:35:42.238 3378 3378 I ServiceManager: service ‘media.audio_flinger’ died
01-28 08:35:42.238 3378 3378 I ServiceManager: service ‘media.audio_policy’ died
01-28 08:35:42.238 3378 3378 I ServiceManager: service ‘media.sound_trigger_hw’ died
01-28 08:35:42.291 3378 3378 I ServiceManager: service ‘secure_element’ died
01-28 08:35:42.366 3512 3550 I gralloc : ddebug, free share_fd=93, user_hnd=0xd, ion client=30
01-28 08:35:42.366 3512 3550 I gralloc : ddebug, free share_fd=88, user_hnd=0xf, ion client=30
01-28 08:35:42.389 4289 4289 E wpa_supplicant: Could not read interface p2p-dev-wlan0 flags: No such device
01-28 08:35:42.389 4289 4289 I wpa_supplicant: p2p-dev-wlan0: CTRL-EVENT-TERMINATING
01-28 08:35:42.410 3378 3378 I ServiceManager: service ‘wificond’ died
01-28 08:35:42.410 3378 3378 I ServiceManager: service ‘netd’ died
01-28 08:35:42.411 3378 3378 I ServiceManager: service ‘media.drm’ died
01-28 08:35:42.411 3378 3378 I ServiceManager: service ‘media.extractor’ died
01-28 08:35:42.411 3378 3378 I ServiceManager: service ‘media.extractor.update’ died
01-28 08:35:42.411 3378 3378 I ServiceManager: service ‘incident’ died
01-28 08:35:42.411 3378 3378 I ServiceManager: service ‘media.camera’ died
01-28 08:35:42.411 3378 3378 I ServiceManager: service ‘installd’ died
01-28 08:35:42.411 3378 3378 I ServiceManager: service ‘drm.drmManager’ died
01-28 08:35:42.411 3378 3378 I ServiceManager: service ‘stats’ died
01-28 08:35:42.411 3378 3378 I ServiceManager: service ‘media.player’ died
01-28 08:35:42.411 3378 3378 I ServiceManager: service ‘media.resource_manager’ died
01-28 08:35:42.411 3378 3378 I ServiceManager: service ‘android.security.keystore’ died
01-28 08:35:42.411 3378 3378 I ServiceManager: service ‘media.metrics’ died
01-28 08:35:42.434 4289 4289 I wpa_supplicant: nl80211: deinit ifname=wlan0 disabled_11b_rates=0
01-28 08:35:42.450 4289 4289 I wpa_supplicant: wlan0: CTRL-EVENT-TERMINATING
01-28 08:35:42.714 3378 3378 I ServiceManager: service ‘vold’ died

As far as I understand, the following line indicates that the system reboots on recovery in order to proceed to upgrade.

01-28 08:35:42.166 3749 18105 I ShutdownThread: Rebooting, reason: recovery-update

But the issue is that it never wakes up… The bootloader seems OK since it displays the boot image but, after something like 5 seconds in reboots again and again.

The images used to built the OTA package are fine because they work if you flash them via the USB_Burning_Tool.

My guess, but correct me if I’m wrong, is that something is broken concerning the recovery. Any idea how to move forward ?

int00h · February 2, 2022, 11:05am

Hi, did you solve your problem?

VulcainMan · February 3, 2022, 8:26am

Unfortunately not until now. Are you experiencing something similar ?

int00h · February 3, 2022, 8:54am

Yes, link
and I still can’t solve this problem.
20% problem

and
in my case, the android recovery did not start

VulcainMan · February 3, 2022, 3:03pm

Indeed, I guess we’re in the same boat. Waiting for Khadas team to get back from vacation !

jasonl · February 12, 2022, 1:48am

Hi,VulcainMan,sorry for the late reply,for the ota problem,can you provider the following details
1.what is the firmware before you do ota update?
2.what is the firmware you used to update?
how can i reproduce the problem?

VulcainMan · February 14, 2022, 9:21am

Hi @jasonl,

No problem, everybody need to take rest ! Below are my answers:

This is a custom firmware based on official khadas AOSP 9 build tree (https://github.com/khadas/android_manifest.git). We’ve introduced minor modifications (apps, boot animation, etc…), nothing really major
We uses as a first try to update using the same firmware
Do you want me to provide you the firmware and the steps I do in order for you to reproduce ?

Thanks for your usual support !

jasonl · February 14, 2022, 9:26am

Hi @VulcainMan ,
yes ,it is better to provide me the firmware and the steps

VulcainMan · February 14, 2022, 9:53am

Thanks for your reactivity, here is the link to download the firmware: WeTransfer - Send Large Files & Share Photos Online - Up to 2GB Free

Below is the procedure to reproduce the issue:

Flash the firwmare using AML_Burning tool on a VIM3
Copy the firmware on the VIM3’s internal storage (/sdcard) using ADB
Start the OTAUpgrade app
Select the firmware on the internal storage
Confirm
The VIM3 reboots after reaching 20% then it enters an infinite reboot loop

Please let me know if you need additionnal details

jasonl · February 14, 2022, 10:03am

ok ，i will try to reproduce the issue

jasonl · February 15, 2022, 2:02am

@VulcainMan about the ota issue,you just update the latest code ,the following commit can solve the issue

VulcainMan · February 16, 2022, 7:54am

Thanks for the feedback @jasonl, I’ll check that next week (I’m currently working remotely without VIM3 available) and let you know if it fix the issue.

VulcainMan · March 29, 2022, 3:56pm

Thanks @jasonl, it works like a charm !