android arm64 odex,arm64 / odex / 6.0.1: Some apps are not compiled at boot time

I just set up a new nexus 6p like the following:

Unlock

Upgrade to latest 6.0.1 mmb29p stock rom

Enable ADB debugging

Flash twrp-2.8.7.2-angler in bootloader

Flash xposed-v79-sdk23-arm64.zip in recovery

After rebooting 48 apps were optimized just fine.

But some others were not optimized on the boot but lateron, in which case it was not successful.

01-15 22:34:27.709 7105 7152 I ActivityManager: Start proc 8355:com.google.process.gapps/u0a12 for service com.google.android.gms/.clearcut.service.ClearcutLoggerService

01-15 22:34:27.710 8319 8319 E dex2oat : Failed to create oat file: /data/dalvik-cache/arm64/system@app@NfcNci@NfcNci.apk@classes.dex: Permission denied

01-15 22:34:27.710 8319 8319 I dex2oat : dex2oat took 566.510us (threads: 2)

01-15 22:34:27.712 8270 8270 W System : ClassLoader referenced unknown path: /system/priv-app/TelephonyProvider/lib/arm64

01-15 22:34:27.713 8244 8244 W art : Failed execv(/system/bin/dex2oat --runtime-arg -classpath --runtime-arg /system/framework/XposedBridge.jar --instruction-set=arm64 --instruction-set-features=smp,a53 --runtime-arg -Xnorelocate --boot-image=/system/framework/boot.art --runtime-arg -Xms64m --runtime-arg -Xmx512m -j2 --instruction-set-variant=cortex-a53 --instruction-set-features=default --dex-file=/system/app/NfcNci/oat/arm64/NfcNci.odex --oat-file=/data/dalvik-cache/arm64/system@app@NfcNci@NfcNci.apk@classes.dex) because non-0 exit status

01-15 22:34:27.713 8244 8244 W art : Entry not found

This leads to an infinitle FC loop.

Investigating the issue I did the following:

set permission of /data/dalvik-cache/arm64/ to 777

This still did not work:

01-15 22:52:09.205 5402 7721 I ActivityManager: Start proc 10156:com.android.nfc/1027 for restart com.android.nfc

01-15 22:52:09.218 10156 10156 W re-initialized>: type=1400 audit(0.0:51): avc: denied { write } for name="arm64" dev="dm-0" ino=1064963 scontext=u:r:nfc:s0 tcontext=u:object_r:dalvikcache_data_file:s0 tclass=dir permissive=0

01-15 22:52:09.265 10171 10171 E dex2oat : Failed to create oat file: /data/dalvik-cache/arm64/system@app@NfcNci@NfcNci.apk@classes.dex: Permission denied

01-15 22:52:09.258 10171 10171 W dex2oat : type=1400 audit(0.0:52): avc: denied { write } for name="arm64" dev="dm-0" ino=1064963 scontext=u:r:nfc:s0 tcontext=u:object_r:dalvikcache_data_file:s0 tclass=dir permissive=0

01-15 22:52:09.265 10171 10171 I dex2oat : dex2oat took 761.510us (threads: 2)

01-15 22:52:09.267 10156 10156 W art : Failed execv(/system/bin/dex2oat --runtime-arg -classpath --runtime-arg /system/framework/XposedBridge.jar --instruction-set=arm64 --instruction-set-features=smp,a53 --runtime-arg -Xnorelocate --boot-image=/system/framework/boot.art --runtime-arg -Xms64m --runtime-arg -Xmx512m -j2 --instruction-set-variant=cortex-a53 --instruction-set-features=default --dex-file=/system/app/NfcNci/oat/arm64/NfcNci.odex --oat-file=/data/dalvik-cache/arm64/system@app@NfcNci@NfcNci.apk@classes.dex) because non-0 exit status

01-15 22:52:09.267 10156 10156 W art : Entry not found

So now the problem is the sepolicy: dex2oat is being run as UID nfc and not system.

So lets' try after setenforce permissive:

01-15 22:57:22.227 5402 9126 I ActivityManager: Start proc 11883:com.android.nfc/1027 for restart com.android.nfc

01-15 22:57:22.248 11883 11883 W re-initialized>: type=1400 audit(0.0:243): avc: denied { write } for name="arm64" dev="dm-0" ino=1064963 scontext=u:r:nfc:s0 tcontext=u:object_r:dalvikcache_data_file:s0 tclass=dir permissive=0

01-15 22:57:22.278 11896 11896 I setenforce: type=1400 audit(0.0:244): avc: denied { setenforce } for scontext=u:r:init:s0 tcontext=u:object_r:kernel:s0 tclass=security permissive=1

01-15 22:57:22.278 349 349 W auditd : type=1404 audit(0.0:245): enforcing=0 old_enforcing=1 auid=4294967295 ses=4294967295

01-15 22:57:22.313 11895 11895 I dex2oat : /system/bin/dex2oat -j2 --dex-file=/system/app/NfcNci/oat/arm64/NfcNci.odex --oat-file=/data/dalvik-cache/arm64/system@app@NfcNci@NfcNci.apk@classes.dex

01-15 22:57:22.308 11895 11895 I dex2oat : type=1400 audit(0.0:246): avc: denied { write } for name="arm64" dev="dm-0" ino=1064963 scontext=u:r:nfc:s0 tcontext=u:object_r:dalvikcache_data_file:s0 tclass=dir permissive=1

01-15 22:57:22.308 11895 11895 I dex2oat : type=1400 audit(0.0:247): avc: denied { add_name } for name="system@app@NfcNci@NfcNci.apk@classes.dex" scontext=u:r:nfc:s0 tcontext=u:object_r:dalvikcache_data_file:s0 tclass=dir permissive=1

01-15 22:57:22.308 11895 11895 I dex2oat : type=1400 audit(0.0:248): avc: denied { create } for name="system@app@NfcNci@NfcNci.apk@classes.dex" scontext=u:r:nfc:s0 tcontext=u:object_r:dalvikcache_data_file:s0 tclass=file permissive=1

01-15 22:57:22.308 11895 11895 I dex2oat : type=1400 audit(0.0:249): avc: denied { write } for path="/data/dalvik-cache/arm64/system@app@NfcNci@NfcNci.apk@classes.dex" dev="dm-0" ino=1065162 scontext=u:r:nfc:s0 tcontext=u:object_r:dalvikcache_data_file:s0 tclass=file permissive=1

01-15 22:57:22.308 11895 11895 I dex2oat : type=1400 audit(0.0:250): avc: denied { setattr } for name="system@app@NfcNci@NfcNci.apk@classes.dex" dev="dm-0" ino=1065162 scontext=u:r:nfc:s0 tcontext=u:object_r:dalvikcache_data_file:s0 tclass=file permissive=1

01-15 22:57:22.553 11895 11895 I dex2oat : dex2oat took 241.603ms (threads: 2) arena alloc=368KB java alloc=551KB native alloc=2MB free=1372KB

01-15 22:57:22.563 372 372 I SELinux : SELinux: Loaded service_contexts from /service_contexts.

01-15 22:57:22.563 372 372 I SELinux : avc: received setenforce notice (enforcing=0)

01-15 22:57:22.575 11883 11883 I NfcService: Starting NFC service

The file could now be created, but has UID/GID of nfc/nfc:

# ls -Z /data/dalvik-cache/arm64/*Nfc*

-rw-r--r-- nfc nfc u:object_r:dalvikcache_data_file:s0 system@app@NfcNci@NfcNci.apk@classes.dex

And everything works perfectly.

The problem seems to be specific to odexed system apps for which dex2oat fails when being run on-demand.

I also tried the whole thing using various versions of SuperSU (2.66, 2.52, no SuperSU at all), to no avail so it seems to be unrelated to any other changes.