Boot stuck when using ih8sn and applying OTA update on LOS19

[Th0masL]

Hi,

I'm using LineageOS 19.1 on a Samsung S10e (SM-970F).

I upgraded from LineageOS v18.1 to v19.1 around 2 weeks ago, when the most up-to-date version was 2022-06-09.

I followed the precise instructions on LineageOS website, and everything was working normally.

This week I received the notification that an OTA update was available for the version 2022-06-16, so I did it.

My phone ended up in bootloop, and the only thing I was able to access was Download mode or Recovery.

No matter what I tried, I just couldn't get the system to start normally, so I had to Format Data, and re-flash with the ROM 2022-06-09.

I continued doing some testing, to try to understand what could be the reason of this failure of OTA update, and basically the only moment I was able to OTA updates is if I delete the ih8sn files created by the push.sh script.

When ih8sn is installed, my phone is stuck in bootloop after the first OTA update.

Without ih8sn installed, I was able to do the 2 OTA updates that were pending : from 2022-06-09 -> 2022-06-16 -> 2022-06-23.

I'm happy to try to do more testing, so feel free to let me know if you want me to provide some logs or things like that.

Thanks !

[Th0masL]

I think that the problem might be coming from the script 60-ih8sn.sh, which is responsible for backing up and then restoring the ih8sn files during an upgrade.

~I'll try to deploy all the ih8sn files except this upgrade script, and then I'll try to do the OTA updates to see if it works.~

~Of course, I'll then have to manually re-install ih8sn, but that's fine.~

Update: Actually the upgrade script 60-ih8sn.sh is the thing that should help to avoid breaking the OTA updates, so skipping this script is definitely not helping.

[Th0masL]

I'm posting the logs here, in case we can find something: last_log: https://pastebin.pl/view/7b03570f last_kmsg: https://pastebin.pl/view/2a9d945e

[Kaalip]

Hey, i assume you either executed these commands or used the scripts included.

adb wait-for-device root
adb wait-for-device remount
adb wait-for-device push 60-ih8sn.sh /system/addon.d/
adb wait-for-device push ih8sn /system/bin/
adb wait-for-device push ih8sn.rc /system/etc/init/
adb wait-for-device push ih8sn.conf /system/etc/

After the files are pushed onto your device before reboot you need to execute adb enable-verity Otherwise the phone will bootloop after OTA

Hope this helps.

[Th0masL]

That's correct, I've been using exactly the list of 6x top commands.

I'll give a try with the command adb enable-verity, to see if that helps, and I'll let you know

[Th0masL]

This is the message I get when I try to run adb enable-verity :

> adb enable-verity
enable-verity only works for userdebug builds

I guess I could also delete all the ih8sn files before applying the OTA upgrade, and that would do the job, right ?

Isn't the goal of the script 60-ih8sn.sh, which is supposed to make a backup of the files before the upgrade and restore them after the upgrade ? Maybe this 60-ih8sn.sh script is not working as intended on some phones/models ? :thinking:

[Kaalip]

This is the message I get when I try to run adb enable-verity :

> adb enable-verity
enable-verity only works for userdebug builds

Yes it should say that, and after it Disabling overlayfs That is what should do the trick adb remount enables the overlayFS and that is not compatible with OTA Here is more on the subject. https://android.googlesource.com/platform/system/core/+/master/fs_mgr/README.overlayfs.md

[Th0masL]

In my case it's only saying enable-verity only works for userdebug builds, and not Disabling overlayfs

[Th0masL]

Maybe the problem with the add-on script 60-ih8sn.sh can be related to this ticket https://gitlab.com/LineageOS/issues/android/-/issues/4469

[Kaalip]

Okay then your overlayFS isn't enabled, can't help you further with that then.

[Th0masL]

As expected, deleting the ih8sn files just prior to doing the OTA updates is preventing the boot loop.

I'll make a small PR on the script to be able to pass a --remove parameter that will automatically delete the few files that got created.

[Th0masL]

This comment seems very relevant to the problem : https://gitlab.com/LineageOS/issues/android/-/issues/4469#note_860943611

After OTA update addon.d files automatically changes string /tmp/backuptool.functions to postinstall/tmp/backuptool.functions which cause backuptool does not work after the next OTA update. I think that it behavior abnormal.

I think I indeed saw the problem of bootloop after OTA only starting the 2nd OTA update, so that would be spot on.

[Th0masL]

The problem seems to be that on my phone, the script /tmp/backuptool.functions that is used during the OTA update by 60-ih8sn.sh does not exist anywhere on the disk.

1|beyond0lte:/ # find / -type f -name "60-ih8sn.sh" 2>/dev/null                                                                            
/system/addon.d/60-ih8sn.sh

1|beyond0lte:/ # find / -type f -name "ih8sn" 2>/dev/null                                                                                  
/system/bin/ih8sn

1|beyond0lte:/ # find / -type f -name "ih8sn.rc" 2>/dev/null                                                                               
/system/etc/init/ih8sn.rc

1|beyond0lte:/ # find / -type f -name "backuptool.functions" 2>/dev/null                                                                   
< not found>

Is this file supposed to be present at all times ? Or is it supposed to be created dynamically during the OTA update ?

[luk1337]

It's unpacked by the OTA package.

[Th0masL]

Ok so here is what I did:

1. First install:

   • LOS 19 v2022-06-09
   • MindTheGAPPs

2. Do not install ih8sn just yet

3. Here is the content of the addon.d files before the first OTA update :

   beyond0lte:/ # ls /system/addon.d/
   30-gapps.sh  50-lineage.sh
   beyond0lte:/ # cd /system/addon.d/
   beyond0lte:/system/addon.d # grep -rni '.' -e 'backuptool.functions'
   ./30-gapps.sh:7:. /tmp/backuptool.functions
   ./50-lineage.sh:10:. /tmp/backuptool.functions

   Prior to the OTA upgrade, we can see that the path for the file backuptool.functions is in the /tmp folder, which is expected.

4. Do OTA upgrade to v2022-06-16

5. Reboot, still not install ih8sn

6. Here is the content of the addon.d files after the fist OTA update:

   beyond0lte:/ # ls /system/addon.d/
   30-gapps.sh  50-lineage.sh
   beyond0lte:/ # cd /system/addon.d/
   beyond0lte:/system/addon.d # grep -rni '.' -e 'backuptool.functions'
   ./30-gapps.sh:7:. /tmp/backuptool.functions
   ./50-lineage.sh:10:. /tmp/backuptool.functions

   After to the first OTA upgrade, the path still look good, nothing to worry here.

7. Install ih8sn, reboot

8. The phone is in bootloop, with only access to Download Mode or Recovery

9. Go to Recovery, mount the system partition, delete the ih8sn files

   beyond0lte:/ # find / -type f 2>/dev/null | grep ih8sn
   /mnt/system/system/addon.d/60-ih8sn.sh
   /mnt/system/system/etc/init/ih8sn.rc
   /mnt/system/system/etc/ih8sn.conf
   /mnt/system/system/bin/ih8sn
   
   1|beyond0lte:/ # mount -o rw,remount /mnt/system
   
   beyond0lte:/ # rm /mnt/system/system/addon.d/60-ih8sn.sh
   beyond0lte:/ # rm /mnt/system/system/etc/init/ih8sn.rc
   beyond0lte:/ # rm /mnt/system/system/etc/ih8sn.conf
   beyond0lte:/ # rm /mnt/system/system/bin/ih8sn

10. Reboot the phone

11. It starts normally and everything works

12. Which logs do you want me to give you ?

[luk1337]

adb logcat from broken boot.

[Th0masL]

I cannot run adb logcat in recovery, so I can only run adb logcat just after I deleted the ih8sn files and the phone reboot successfully.

Is it what you want ?

[luk1337]

Again, logs from android; not recovery. If you can't get android logcat then there are no useful logs that you can provide.

[Th0masL]

Yep, I'm trying to find a way to show the Android logs from within the recovery, but so far that's not working.

The only log files I can see from adb running in recovery is :

beyond0lte:/ # find / -type f 2>/dev/null | grep "\.log"                                                                                             
/tmp/recovery.log

The good news here is that I simply have to uninstall ih8sn prior to the OTA or to remove the files from adb in recovery to allow the phone to boot, so I can spend some time continuing to investigate this problem.

I'll keep searching if there's a way to get last boot's logs from within the recovery.

[Th0masL]

Any chance using what is suggested in this message help for retrieving log ?

https://forum.xda-developers.com/t/universal-flashable-logcat-guide-so-your-test-rom-build-didnt-boot.3258818/#post-64043477

[Th0masL]

I'm not really sure if I will ever be able to get logs from Android while being unable to boot, but I've did some more testing and deleting or renaming the file /system/system/etc/ih8sn.conf is enough to allow the phone to boot normally.

I assume the program is made in a way that if it can't find any config file, it exit early and is not doing anything.

Could it be that the content of the config file is the problem ?

[Th0masL]

Is there anyway we could make ih8sn to log some lines when it's starting, that we might be able to see something ?

[Th0masL]

I was able to extract some Android logs, but I'm not sure it contains what we want.

Those logs are extracted when Android has just started, just after I removed the ih8sn.conf file from ADB in Recovery Mode and rebooted to LOS.

Steps :

1. Copy the file /proc/last_kmsg to my computer using adb

   adb pull /proc/last_kmsg /tmp/

2. Convert the data to ASCII, search for any lines containing ih8sn and show the 10 lines before and 10 lines after

   strings /tmp/last_kmsg | grep -i ih8sn -C10

The result is visible here : https://pastebin.pl/view/9e036f5c

[luk1337]

Again, you want a logcat from failed boot, not last_kmsg or anything like this.

[Th0masL]

I was finally able to get a logcat from the failed boot, and the full log file has been sent to you by email.

I've logged some useful messages in the console, so have a better idea of the timing of the things :

> cat logcat_full.log | grep msg_from_thomas
06-26 02:30:23.638675 10776 10776 I msg_from_thomas: Enabled the file ih8sn.conf
06-26 02:30:48.761017 10845 10845 I msg_from_thomas: About to reboot
06-26 02:34:16.087843  9014  9014 I msg_from_thomas: Phone booted back on Android

So basically the interesting stuff is between lines timings 06-26 02:30:48.761017 and 06-26 02:34:16.087843.

If I search for ih8sn lines during this time window, here is what I find :

cat logcat_full.log | grep "06-26 02:30:48.761017" -A100000 | grep "06-26 02:34:16.087843" -B100000 | grep -i -E "ih8sn" -C2
06-26 02:33:39.987168     0     0 I [7:           init:    1] init: Parsing file /system/etc/init/hwservicemanager.rc...
06-26 02:33:39.987490     0     0 I [7:           init:    1] init: Parsing file /system/etc/init/idmap2d.rc...
06-26 02:33:39.987692     0     0 I [7:           init:    1] init: Parsing file /system/etc/init/ih8sn.rc...
06-26 02:33:39.987871     0     0 I [7:           init:    1] init: Parsing file /system/etc/init/incidentd.rc...
06-26 02:33:39.988077     0     0 I [7:           init:    1] init: Parsing file /system/etc/init/init-debug.rc...
--
06-26 02:33:40.720524     0     0 I [1:           init:    1] init: processing action (init) from (/system/etc/init/hw/init.usb.rc:27)
06-26 02:33:40.720706     0     0 I [6:           init:    1] init: processing action (init) from (/system/etc/init/audioserver.rc:62)
06-26 02:33:40.721121     0     0 I [6:           init:    1] init: processing action (init) from (/system/etc/init/ih8sn.rc:1)
06-26 02:33:40.721184     0     0 I [6:           init:    1] init: starting service 'exec 3 (/system/bin/ih8sn init)'...
06-26 02:33:40.722300     0     0 I [6:           init:    1] init: SVC_EXEC service 'exec 3 (/system/bin/ih8sn init)' pid 5287 (uid 0 gid 0+0 context u:r:su:s0) started; waiting...
06-26 02:33:40.729487     0     0 I [5:           logd: 5280] logd.auditd: start
--------- switch to main
--
--------- switch to kernel
06-26 02:33:40.732365     0     0 I [4: servicemanager: 5284] binder: 5284:5284(servicemanager:servicemanager) ioctl 40046210 7fd4ab8154 returned -22
06-26 02:33:40.732991     0     0 I [4:           init:    1] init: Service 'exec 3 (/system/bin/ih8sn init)' (pid 5287) exited with status 0 waiting took 0.011000 seconds
06-26 02:33:40.733023     0     0 I [4:           init:    1] init: Sending signal 9 to service 'exec 3 (/system/bin/ih8sn init)' (pid 5287) process group...
06-26 02:33:40.733116     0     0 I [4:           init:    1] libprocessgroup: Successfully killed process cgroup uid 0 pid 5287 in 0ms
06-26 02:33:40.733350     0     0 I [4:           init:    1] init: starting service 'exec 4 (/system/bin/ih8sn init)'...
06-26 02:33:40.734564     0     0 F [6:           init: 5291] init: cannot setexeccon('u:r:sysinit:s0') for exec 4 (/system/bin/ih8sn init): Invalid argument
06-26 02:33:40.734688     0     0 I [4:           init:    1] init: SVC_EXEC service 'exec 4 (/system/bin/ih8sn init)' pid 5291 (uid 0 gid 0+0 context u:r:sysinit:s0) started; waiting...
06-26 02:33:40.735257     0     0 I [1:           init:    1] init: Service 'exec 4 (/system/bin/ih8sn init)' (pid 5291) exited with status 6 waiting took 0.001000 seconds
06-26 02:33:40.735292     0     0 I [1:           init:    1] init: Sending signal 9 to service 'exec 4 (/system/bin/ih8sn init)' (pid 5291) process group...
06-26 02:33:40.735419     0     0 I [1:           init:    1] libprocessgroup: Successfully killed process cgroup uid 0 pid 5291 in 0ms
06-26 02:33:40.735630     0     0 I [1:           init:    1] init: processing action (init) from (/system_ext/etc/init/init.lineage-system_ext.rc:2)
--
06-26 02:33:56.987788  6737  6737 E bootstat: Failed to parse boot time record: /data/misc/bootstat/post_decrypt_time_elapsed
--------- switch to kernel
06-26 02:33:56.994519     0     0 I [7:           init:    1] init: processing action (sys.boot_completed=1) from (/system/etc/init/ih8sn.rc:5)
06-26 02:33:56.994581     0     0 I [7:           init:    1] init: starting service 'exec 21 (/system/bin/ih8sn boot_completed)'...
06-26 02:33:56.995861     0     0 I [7:           init:    1] init: SVC_EXEC service 'exec 21 (/system/bin/ih8sn boot_completed)' pid 6738 (uid 0 gid 0+0 context u:r:su:s0) started; waiting...
--------- switch to main
06-26 02:33:56.989586  6737  6737 W bootstat: LogBootEvents, atomInfo not defined for events:boot_reason,system_boot_reason,build_date,last_boot_time_utc,ro.boottime.init.cold_boot_wait,time_since_last_boot
--
06-26 02:33:56.998232     0     0 I [4:           init:    1] init: Sending signal 9 to service 'exec 20 (/system/bin/bootstat --record_boot_complete --record_boot_reason --record_time_since_factory_reset -l)' (pid 6737) process group...
06-26 02:33:56.998332     0     0 I [4:           init:    1] libprocessgroup: Successfully killed process cgroup uid 1000 pid 6737 in 0ms
06-26 02:33:56.999691     0     0 I [6:           init:    1] init: Service 'exec 21 (/system/bin/ih8sn boot_completed)' (pid 6738) exited with status 0 waiting took 0.004000 seconds
06-26 02:33:56.999706     0     0 I [6:           init:    1] init: Sending signal 9 to service 'exec 21 (/system/bin/ih8sn boot_completed)' (pid 6738) process group...
06-26 02:33:56.999781     0     0 I [6:           init:    1] libprocessgroup: Successfully killed process cgroup uid 0 pid 6738 in 0ms
06-26 02:33:56.999907     0     0 I [6:           init:    1] init: starting service 'exec 22 (/system/bin/ih8sn boot_completed)'...
06-26 02:33:57.000886     0     0 F [4:           init: 6739] init: cannot setexeccon('u:r:sysinit:s0') for exec 22 (/system/bin/ih8sn boot_completed): Invalid argument
06-26 02:33:57.001037     0     0 I [6:           init:    1] init: SVC_EXEC service 'exec 22 (/system/bin/ih8sn boot_completed)' pid 6739 (uid 0 gid 0+0 context u:r:sysinit:s0) started; waiting...
06-26 02:33:57.002150     0     0 I [0:           init:    1] init: Service 'exec 22 (/system/bin/ih8sn boot_completed)' (pid 6739) exited with status 6 waiting took 0.001000 seconds
06-26 02:33:57.002185     0     0 I [0:           init:    1] init: Sending signal 9 to service 'exec 22 (/system/bin/ih8sn boot_completed)' (pid 6739) process group...
06-26 02:33:57.002349     0     0 I [0:           init:    1] libprocessgroup: Successfully killed process cgroup uid 0 pid 6739 in 0ms
06-26 02:33:57.002561     0     0 I         : [4:android.hardwar: 5553] panel_bl_set_brightness bl-0 dim:flash plat_br:16771 br[424]:16800 nit:265(254.33) acl:on(5)

Let me know if you find anything useful.

Thanks !

[brianjmurrell]

Oh poo. I seem to have been bitten by this. I'll have to go read back on how I recover from this. :-(

[Th0masL]

I explained the recovery method in step 9 in this message above: https://github.com/luk1337/ih8sn/issues/24#issuecomment-1165590342

[brianjmurrell]

Yeah. I saw that. I don't have a recovery though. I have an A/B device. Just trying to recall/research how to boot the other slot.

[brianjmurrell]

Hrm.

$ fastboot getvar current-slot
current-slot: a
Finished. Total time: 0.002s
$ fastboot set_active b
Setting current slot to 'b'                        OKAY [  0.034s]
Finished. Total time: 0.035s
$ fastboot reboot
Rebooting                                          OKAY [  0.000s]
Finished. Total time: 0.051s

But that takes me to the Lineage Recovery. But I thought that got overwritten a long time ago with an OTA update. IOW, i thought the recovery, initially installed to install LOS was installed into one of the A/B slots and got subsequently overwritten by an OTA update.

Anyway, was able to enable ADB in Lineage Recovery and use the process in https://github.com/luk1337/ih8sn/issues/24#issuecomment-1165590342 to remove the files successfully. That doesn't seem to have resolved my bootloop though. :-( So maybe it's something other than this issue. Crap. I was hoping this would resolve it.

[brianjmurrell]

9. Go to Recovery, mount the system partition, delete the ih8sn files

   beyond0lte:/ # find / -type f 2>/dev/null | grep ih8sn
   /mnt/system/system/addon.d/60-ih8sn.sh
   /mnt/system/system/etc/init/ih8sn.rc
   /mnt/system/system/etc/ih8sn.conf
   /mnt/system/system/bin/ih8sn
   
   1|beyond0lte:/ # mount -o rw,remount /mnt/system
   
   beyond0lte:/ # rm /mnt/system/system/addon.d/60-ih8sn.sh
   beyond0lte:/ # rm /mnt/system/system/etc/init/ih8sn.rc
   beyond0lte:/ # rm /mnt/system/system/etc/ih8sn.conf
   beyond0lte:/ # rm /mnt/system/system/bin/ih8sn

Shouldn't you remount /mnt/system ro again before rebooting, or unmount it, or sync; sync to flush the cache, etc.?

10. Reboot the phone
11. It starts normally and everything works
12. Which logs do you want me to give you ?