v1-r can't install custom OTA update
- /e/ version: v1-r branch from 14.10.
- Device model(s): axolotl
- Device rooted: no
Summary
I built /e/OS from the v1-r branch for a LineageOS supported device (axolotl) and added a custom OTA URL. When trying to update, I get the following error though
E update_engine: [ERROR:utils.cc(626)] Opening block device /dev/block/bootdevice/by-name/vbmeta_vendor_a: Permission denied (13) W update_engine: type=1400 audit(0.0:3591): avc: denied { read } for name="sde22" dev="tmpfs" ino=22545 scontext=u:r:update_engine:s0 tcontext=u:object_r:block_device:s0 tclass=blk_file permissive=0
The problem
Steps to reproduce
- build with community docker image for axolotl and set OTA_URL env variable (custom keys)
- install /e/OS on device
- build update again (same keys)
- try to update using updater app
What is the current behavior?
Installation aborts with "Installationsfehler".
What is the expected correct behavior?
The update is completely installed.
Technical informations
Relevant logs (adb logcat)
10-18 19:27:45.818 16625 16625 D UpdaterService: Starting service
10-18 19:27:45.821 1307 1307 I update_engine: [INFO:update_attempter_android.cc(524)] Disabling performance mode.
10-18 19:27:45.828 1307 1307 I update_engine: [INFO:update_attempter_android.cc(282)] Using this install plan:
10-18 19:27:45.829 1307 1307 I update_engine: [INFO:install_plan.cc(91)] InstallPlan: resume, version: , source_slot: B, target_slot: A, url: file:///data/lineageos_updates/e-0.19-r-20211018-UNOFFICIAL-axolotl.zip, payload: (size: 991916227, metadata_size: 153846, metadata signature: , hash: A420EE2FACDAAA65A32D4469B74AF84F8F7E745C92EB4B3AB544A38203639583, payload type: unknown), hash_checks_mandatory: true, powerwash_required: false, switch_slot_on_reboot: true, run_post_install: true, is_rollback: false, write_verity: true
10-18 19:27:45.831 1307 1307 I update_engine: [INFO:metrics_utils.cc(371)] Payload Attempt Number = 3
10-18 19:27:45.834 1307 1307 I update_engine: [INFO:metrics_utils.cc(388)] Update Monotonic Timestamp Start = 1/1/1970 3:55:53 GMT
10-18 19:27:45.836 1307 1307 I update_engine: [INFO:metrics_utils.cc(397)] Update Boot Timestamp Start = 1/1/1970 3:57:15 GMT
10-18 19:27:45.837 1307 1307 I update_engine: [INFO:update_attempter_android.cc(662)] Scheduling an action processor start.
10-18 19:27:45.839 1307 1307 I update_engine: [INFO:action_processor.cc(51)] ActionProcessor: starting UpdateBootFlagsAction
10-18 19:27:45.840 1307 1307 I update_engine: [INFO:update_boot_flags_action.cc(36)] Already updated boot flags. Skipping.
10-18 19:27:45.841 1307 1307 I update_engine: [INFO:action_processor.cc(116)] ActionProcessor: finished UpdateBootFlagsAction with code ErrorCode::kSuccess
10-18 19:27:45.842 1307 1307 I update_engine: [INFO:action_processor.cc(143)] ActionProcessor: starting NoOpAction
10-18 19:27:45.843 1307 1307 I update_engine: [INFO:action_processor.cc(116)] ActionProcessor: finished NoOpAction with code ErrorCode::kSuccess
10-18 19:27:45.848 1307 1307 I update_engine: [INFO:action_processor.cc(143)] ActionProcessor: starting InstallPlanAction
10-18 19:27:45.849 1307 1307 I update_engine: [INFO:action_processor.cc(116)] ActionProcessor: finished InstallPlanAction with code ErrorCode::kSuccess
10-18 19:27:45.851 1307 1307 I update_engine: [INFO:action_processor.cc(143)] ActionProcessor: starting DownloadAction
10-18 19:27:45.853 1307 1307 I update_engine: [INFO:install_plan.cc(91)] InstallPlan: resume, version: , source_slot: B, target_slot: A, url: file:///data/lineageos_updates/e-0.19-r-20211018-UNOFFICIAL-axolotl.zip, payload: (size: 991916227, metadata_size: 153846, metadata signature: , hash: A420EE2FACDAAA65A32D4469B74AF84F8F7E745C92EB4B3AB544A38203639583, payload type: unknown), hash_checks_mandatory: true, powerwash_required: false, switch_slot_on_reboot: true, run_post_install: true, is_rollback: false, write_verity: true
10-18 19:27:45.857 1307 1307 I update_engine: [INFO:prefs.cc(122)] update-state-payload-index not present in /data/misc/update_engine/prefs
10-18 19:27:45.858 1307 1307 I update_engine: [INFO:download_action.cc(199)] Marking new slot as unbootable
10-18 19:27:46.060 1475 1475 D NotificationService: 0|org.lineageos.updater|10|null|10093: granting content://settings/system/notification_sound
10-18 19:27:46.061 1475 1475 D NotificationService: 0|org.lineageos.updater|10|null|10093: granting content://settings/system/notification_sound
10-18 19:27:47.309 1307 1307 I update_engine: [INFO:multi_range_http_fetcher.cc(45)] starting first transfer
10-18 19:27:47.311 1307 1307 I update_engine: [INFO:multi_range_http_fetcher.cc(74)] starting transfer of range 1596+154113
10-18 19:27:47.314 1307 1307 I update_engine: [INFO:delta_performer.cc(209)] Completed 0/? operations, 16384/991916227 bytes downloaded (0%), overall progress 0%
10-18 19:27:47.318 1307 1307 I update_engine: [INFO:delta_performer.cc(520)] Manifest size in payload matches expected value from Omaha
10-18 19:27:47.320 1307 1307 I update_engine: [INFO:delta_performer.cc(1693)] Verifying using certificates: /system/etc/security/otacerts.zip
10-18 19:27:47.323 1307 1307 I update_engine: [INFO:payload_verifier.cc(102)] signature blob size = 267
10-18 19:27:47.324 1307 1307 I update_engine: [INFO:payload_verifier.cc(118)] Truncating the signature to its unpadded size: 256.
10-18 19:27:47.326 1307 1307 I update_engine: [INFO:payload_verifier.cc(129)] Verified correct signature 1 out of 1 signatures.
10-18 19:27:47.327 1307 1307 I update_engine: [INFO:payload_metadata.cc(224)] Metadata hash signature matches value in Omaha response.
10-18 19:27:47.343 1307 1307 I update_engine: [INFO:delta_performer.cc(1728)] Detected a 'full' payload.
10-18 19:27:47.354 1307 1307 I update_engine: [INFO:delta_performer.cc(982)] Using previously prepared partitions for update. hash = pCDuL6zaqmWjLURpt0r4T49+dFyS60s6tUSjggNjlYM=WQ37QDPfKypYpjZK3dHWTHEoift3/kN3jO9c5lNr6JA=
10-18 19:27:47.381 1307 1307 I update_engine: [INFO:delta_performer.cc(1002)] PreparePartitionsForUpdate done.
10-18 19:27:47.389 1307 1307 I update_engine: [INFO:dynamic_partition_control_android.cc(319)] Loaded metadata from slot A in /dev/block/bootdevice/by-name/super
10-18 19:27:47.390 1307 1307 I update_engine: [INFO:dynamic_partition_control_android.cc(943)] boot_a is not in super partition metadata.
10-18 19:27:47.391 1307 1307 I update_engine: [INFO:dynamic_partition_control_android.cc(319)] Loaded metadata from slot B in /dev/block/bootdevice/by-name/super
10-18 19:27:47.393 1307 1307 I update_engine: [INFO:dynamic_partition_control_android.cc(319)] Loaded metadata from slot A in /dev/block/bootdevice/by-name/super
10-18 19:27:47.396 1307 1307 I update_engine: [INFO:dynamic_partition_control_android.cc(943)] dtbo_a is not in super partition metadata.
10-18 19:27:47.397 1307 1307 I update_engine: [INFO:dynamic_partition_control_android.cc(319)] Loaded metadata from slot B in /dev/block/bootdevice/by-name/super
10-18 19:27:47.399 1307 1307 I update_engine: [INFO:dynamic_partition_control_android.cc(319)] Loaded metadata from slot A in /dev/block/bootdevice/by-name/super
10-18 19:27:47.400 1307 1307 I update_engine: [INFO:dynamic_partition_control_android.cc(943)] recovery_a is not in super partition metadata.
10-18 19:27:47.402 1307 1307 I update_engine: [INFO:dynamic_partition_control_android.cc(319)] Loaded metadata from slot B in /dev/block/bootdevice/by-name/super
10-18 19:27:47.404 1307 1307 I update_engine: [INFO:dynamic_partition_control_android.cc(319)] Loaded metadata from slot A in /dev/block/bootdevice/by-name/super
10-18 19:27:47.463 1307 1307 I update_engine: [libfs_mgr]Created logical partition product_a on device /dev/block/dm-0
10-18 19:27:47.466 1307 1307 I update_engine: [INFO:dynamic_partition_control_android.cc(173)] Succesfully mapped product_a to device mapper (force_writable = 1); device path at /dev/block/dm-0
10-18 19:27:47.469 1307 1307 I update_engine: [INFO:dynamic_partition_control_android.cc(319)] Loaded metadata from slot A in /dev/block/bootdevice/by-name/super
10-18 19:27:47.502 1307 1307 I update_engine: [libfs_mgr]Created logical partition system_a on device /dev/block/dm-1
10-18 19:27:47.505 1307 1307 I update_engine: [INFO:dynamic_partition_control_android.cc(173)] Succesfully mapped system_a to device mapper (force_writable = 1); device path at /dev/block/dm-1
10-18 19:27:47.509 1307 1307 I update_engine: [INFO:dynamic_partition_control_android.cc(319)] Loaded metadata from slot A in /dev/block/bootdevice/by-name/super
10-18 19:27:47.553 1307 1307 I update_engine: [libfs_mgr]Created logical partition system_ext_a on device /dev/block/dm-2
10-18 19:27:47.556 1307 1307 I update_engine: [INFO:dynamic_partition_control_android.cc(173)] Succesfully mapped system_ext_a to device mapper (force_writable = 1); device path at /dev/block/dm-2
10-18 19:27:47.560 1307 1307 I update_engine: [INFO:dynamic_partition_control_android.cc(319)] Loaded metadata from slot A in /dev/block/bootdevice/by-name/super
10-18 19:27:47.622 1307 1307 I update_engine: [libfs_mgr]Created logical partition vendor_a on device /dev/block/dm-8
10-18 19:27:47.627 1307 1307 I update_engine: [INFO:dynamic_partition_control_android.cc(173)] Succesfully mapped vendor_a to device mapper (force_writable = 1); device path at /dev/block/dm-8
10-18 19:27:47.631 1307 1307 I update_engine: [INFO:dynamic_partition_control_android.cc(319)] Loaded metadata from slot A in /dev/block/bootdevice/by-name/super
10-18 19:27:47.633 1307 1307 I update_engine: [INFO:dynamic_partition_control_android.cc(943)] vbmeta_a is not in super partition metadata.
10-18 19:27:47.635 1307 1307 I update_engine: [INFO:dynamic_partition_control_android.cc(319)] Loaded metadata from slot B in /dev/block/bootdevice/by-name/super
10-18 19:27:47.638 1307 1307 I update_engine: [INFO:dynamic_partition_control_android.cc(319)] Loaded metadata from slot A in /dev/block/bootdevice/by-name/super
10-18 19:27:47.640 1307 1307 I update_engine: [INFO:dynamic_partition_control_android.cc(943)] vbmeta_system_a is not in super partition metadata.
10-18 19:27:47.641 1307 1307 I update_engine: [INFO:dynamic_partition_control_android.cc(319)] Loaded metadata from slot B in /dev/block/bootdevice/by-name/super
10-18 19:27:47.644 1307 1307 I update_engine: [INFO:dynamic_partition_control_android.cc(319)] Loaded metadata from slot A in /dev/block/bootdevice/by-name/super
10-18 19:27:47.645 1307 1307 I update_engine: [INFO:dynamic_partition_control_android.cc(943)] vbmeta_vendor_a is not in super partition metadata.
10-18 19:27:47.647 1307 1307 I update_engine: [INFO:dynamic_partition_control_android.cc(319)] Loaded metadata from slot B in /dev/block/bootdevice/by-name/super
10-18 19:27:47.649 1307 1307 I update_engine: [INFO:delta_performer.cc(451)] PartitionInfo new boot sha256: lTHDXzNRVBu9pf79Yvmtvda/+AKT+Rw5xxemWRPkqjU= size: 67108864
10-18 19:27:47.653 1307 1307 I update_engine: [INFO:delta_performer.cc(451)] PartitionInfo new dtbo sha256: Ut1q3BK2T2xXRIa21ctgxihGckTPSqF/cQOr+AzvSIw= size: 8388608
10-18 19:27:47.655 1307 1307 I update_engine: [INFO:delta_performer.cc(451)] PartitionInfo new recovery sha256: FiWV2G0q5Iv0Hh7dQu88sIE/f8WnxHqbUz7ixH6HTdQ= size: 100663296
10-18 19:27:47.656 1307 1307 I update_engine: [INFO:delta_performer.cc(451)] PartitionInfo new product sha256: R1pj9za4qVhyv5kir2/RB5aCwIiAz24t7p93j/L7KT8= size: 1761636352
10-18 19:27:47.657 1307 1307 I update_engine: [INFO:delta_performer.cc(451)] PartitionInfo new system sha256: +sIhGUUDKn7/TVuD56OQIpn2HpHyoL37Br/x0/pYjjU= size: 2390618112
10-18 19:27:47.658 1307 1307 I update_engine: [INFO:delta_performer.cc(451)] PartitionInfo new system_ext sha256: 3fbbvpaz6Bm8nr9HaPhTxjHxVdhCFQYd4zZcpewhm/c= size: 743063552
10-18 19:27:47.659 1307 1307 I update_engine: [INFO:delta_performer.cc(451)] PartitionInfo new vendor sha256: xKbgImlAl+hjXIMZjL8AWnGWlKaoAvCY0IPY7oE2RyU= size: 706043904
10-18 19:27:47.660 1307 1307 I update_engine: [INFO:delta_performer.cc(451)] PartitionInfo new vbmeta sha256: Nlpg9HBXssfU1iF+CQwbjg8w5RxNEKBqXVgKE1QysqA= size: 8192
10-18 19:27:47.661 1307 1307 I update_engine: [INFO:delta_performer.cc(451)] PartitionInfo new vbmeta_system sha256: sdTKUCkOSAv9j7ZCE9YfOREzJJ7+/IYQG5gYxLviA9o= size: 4096
10-18 19:27:47.662 1307 1307 I update_engine: [INFO:delta_performer.cc(451)] PartitionInfo new vbmeta_vendor sha256: qjB3riHW3SinUrwU8PHIfYpdCwOzQaHafNKlpdtW6bs= size: 4096
10-18 19:27:47.664 1307 1307 I update_engine: [INFO:delta_performer.cc(209)] Resuming after 2759/2760 operations (99%), 991913976/991916227 bytes downloaded (99%), overall progress 98%
10-18 19:27:47.666 1307 1307 I update_engine: [INFO:delta_performer.cc(660)] Starting to apply update payload operations
10-18 19:27:47.667 1307 1307 I update_engine: [INFO:delta_performer.cc(385)] Opening /dev/block/bootdevice/by-name/vbmeta_vendor_a partition without O_DSYNC
10-18 19:27:47.668 1307 1307 E update_engine: [ERROR:utils.cc(626)] Opening block device /dev/block/bootdevice/by-name/vbmeta_vendor_a: Permission denied (13)
10-18 19:27:47.664 1307 1307 W update_engine: type=1400 audit(0.0:3591): avc: denied { read } for name="sde22" dev="tmpfs" ino=22545 scontext=u:r:update_engine:s0 tcontext=u:object_r:block_device:s0 tclass=blk_file permissive=0
10-18 19:27:47.672 1307 1307 I update_engine: [INFO:delta_performer.cc(128)] Caching writes.
10-18 19:27:47.673 1307 1307 E update_engine: [ERROR:delta_performer.cc(139)] Unable to open file /dev/block/bootdevice/by-name/vbmeta_vendor_a: Permission denied (13)
10-18 19:27:47.671 1307 1307 W update_engine: type=1400 audit(0.0:3592): avc: denied { read write } for name="sde22" dev="tmpfs" ino=22545 scontext=u:r:update_engine:s0 tcontext=u:object_r:block_device:s0 tclass=blk_file permissive=0
10-18 19:27:47.675 1307 1307 E update_engine: [ERROR:delta_performer.cc(390)] Unable to open target partition vbmeta_vendor on slot A, file /dev/block/bootdevice/by-name/vbmeta_vendor_a
10-18 19:27:47.676 1307 1307 E update_engine: [ERROR:download_action.cc(336)] Error ErrorCode::kInstallDeviceOpenError (7) in DeltaPerformer's Write method when processing the received payload -- Terminating processing
10-18 19:27:47.677 1307 1307 I update_engine: [INFO:multi_range_http_fetcher.cc(177)] Received transfer terminated.
10-18 19:27:47.678 1307 1307 I update_engine: [INFO:multi_range_http_fetcher.cc(129)] TransferEnded w/ code 200
10-18 19:27:47.679 1307 1307 I update_engine: [INFO:multi_range_http_fetcher.cc(131)] Terminating.
10-18 19:27:47.700 1307 1307 I update_engine: [INFO:action_processor.cc(116)] ActionProcessor: finished DownloadAction with code ErrorCode::kInstallDeviceOpenError
10-18 19:27:47.702 1307 1307 I update_engine: [INFO:action_processor.cc(121)] ActionProcessor: Aborting processing due to failure.
10-18 19:27:47.703 1307 1307 I update_engine: [INFO:update_attempter_android.cc(536)] Processing Done.
10-18 19:27:47.704 1307 1307 I update_engine: [INFO:dynamic_partition_control_android.cc(263)] Destroying [product_a, system_a, system_ext_a, vendor_a] from device mapper
10-18 19:27:47.732 1307 1307 I update_engine: [libfs_mgr]Unmapped logical partition product_a
10-18 19:27:47.735 1307 1307 I update_engine: [INFO:dynamic_partition_control_android.cc(240)] Skip UnmapUpdateSnapshot(product_a) because metadata is not mounted
10-18 19:27:47.737 1307 1307 I update_engine: [INFO:dynamic_partition_control_android.cc(249)] Successfully unmapped product_a from device mapper.
10-18 19:27:47.765 1307 1307 I update_engine: [libfs_mgr]Unmapped logical partition system_a
10-18 19:27:47.769 1307 1307 I update_engine: [INFO:dynamic_partition_control_android.cc(240)] Skip UnmapUpdateSnapshot(system_a) because metadata is not mounted
10-18 19:27:47.770 1307 1307 I update_engine: [INFO:dynamic_partition_control_android.cc(249)] Successfully unmapped system_a from device mapper.
10-18 19:27:47.786 1307 1307 I update_engine: [libfs_mgr]Unmapped logical partition system_ext_a
10-18 19:27:47.788 1307 1307 I update_engine: [INFO:dynamic_partition_control_android.cc(240)] Skip UnmapUpdateSnapshot(system_ext_a) because metadata is not mounted
10-18 19:27:47.789 1307 1307 I update_engine: [INFO:dynamic_partition_control_android.cc(249)] Successfully unmapped system_ext_a from device mapper.
10-18 19:27:47.819 1307 1307 I update_engine: [libfs_mgr]Unmapped logical partition vendor_a
10-18 19:27:47.822 1307 1307 I update_engine: [INFO:dynamic_partition_control_android.cc(240)] Skip UnmapUpdateSnapshot(vendor_a) because metadata is not mounted
10-18 19:27:47.824 1307 1307 I update_engine: [INFO:dynamic_partition_control_android.cc(249)] Successfully unmapped vendor_a from device mapper.
10-18 19:27:47.829 1307 1307 I update_engine: [INFO:metrics_reporter_android.cc(131)] Current update attempt downloads 0 bytes data