Bug 218542

Summary: optee/mmc/tpm_ftpm_tee RPMB crash regression in 6.6.17 compared to 6.5.10
Product: Drivers Reporter: Mikko Rapeli (Linaro) (mikko.rapeli)
Component: MMC/SDAssignee: drivers_mmc-sd
Status: RESOLVED CODE_FIX    
Severity: normal CC: mikko.rapeli, sumit.garg
Priority: P3    
Hardware: ARM   
OS: Linux   
Kernel Version: Subsystem:
Regression: No Bisected commit-id:

Description Mikko Rapeli (Linaro) 2024-03-01 08:45:26 UTC
After update of our yocto based distro from kernel 6.5.10 to 6.6.17, optee from 4.0.0 to 4.1.0 and tf-a from 2.9 to 10, we see a kernel crash when loading the tpm_ftpm_tee module. Using https://gitlab.com/Linaro/trustedsubstrate/meta-ts/ ARM System Ready compatible UEFI firmware with secure boot for a number of arm64 boards.

On synquacer ARM64 board:

https://ledge.validation.linaro.org/scheduler/job/82019

[    0.000000] Linux version 6.6.17-yocto-standard (oe-user@oe-host) (aarch64-trs-linux-gcc (GCC) 13.2.0, GNU ld (GNU Binutils) 2.42.0.20240216) #1 SMP PREEMPT Wed Feb 21 00:33:47 UTC 2024
[    0.000000] KASLR enabled
[    0.000000] Machine model: Socionext Developer Box
[    0.000000] efi: EFI v2.10 by Das U-Boot
[    0.000000] efi: ESRT=0xf9c90040 TPMFinalLog=0xf9c94040 RTPROP=0xf9c92040 SMBIOS=0xf9c8e000 TPMEventLog=0xf9bf4040 INITRD=0xf9bf3040 RNG=0xf9bf2040 MEMRESERVE=0xf9bf1040 
[    0.000000] random: crng init done
...
+ tee-supplicant -d --rpmb-cid 7001004d3332353038521143780e6400
+ sleep 10
+ modprobe tpm_ftpm_tee
[   15.398930] Unable to handle kernel paging request at virtual address ffff07ed00626d7c
[   15.406913] Mem abort info:
[   15.409722]   ESR = 0x0000000096000005
[   15.413490]   EC = 0x25: DABT (current EL), IL = 32 bits
[   15.418814]   SET = 0, FnV = 0
[   15.421878]   EA = 0, S1PTW = 0
[   15.425031]   FSC = 0x05: level 1 translation fault
[   15.429922] Data abort info:
[   15.432813]   ISV = 0, ISS = 0x00000005, ISS2 = 0x00000000
[   15.438310]   CM = 0, WnR = 0, TnD = 0, TagAccess = 0
[   15.443372]   GCS = 0, Overlay = 0, DirtyBit = 0, Xs = 0
[   15.448697] swapper pgtable: 4k pages, 48-bit VAs, pgdp=00000000d9e3e000
[   15.455413] [ffff07ed00626d7c] pgd=1800000bffdf9003, p4d=1800000bffdf9003, pud=0000000000000000
[   15.464146] Internal error: Oops: 0000000096000005 [#1] PREEMPT SMP
Matched prompt #5: Oops(?: -|:)
Setting prompt string to ['\\r', 'ewaol@(.*):[/~]\\$', 'root@(.*):[/~]#', 'login:', 'Login incorrect']
Setting prompt string to ['-\\[ cut here \\]', 'Unhandled fault', 'BUG: KCSAN:', 'BUG: KASAN:', 'BUG: KFENCE:', 'Oops(?: -|:)', 'WARNING:', '(kernel BUG at|BUG:)', 'invalid opcode:', 'Kernel panic - not syncing', 'ewaol@(.*):[/~]\\$', 'root@(.*):[/~]#', 'login:', 'Login incorrect']
login-action: kernel 'oops'
[login-action] Waiting for messages, (timeout 00:36:05)
Waiting using forced prompt support (timeout 00:18:02)
[   15.470422] Modules linked in: tpm_ftpm_tee(+) tpm_tis tpm_tis_core dm_crypt dm_mod
[   15.478114] CPU: 2 PID: 250 Comm: tee-supplicant Not tainted 6.6.17-yocto-standard #1
[   15.485955] Hardware name: socionext,developer-box Socionext Developer Box/Socionext Developer Box, BIOS 2023.10 10/01/2023
[   15.497094] pstate: 80000005 (Nzcv daif -PAN -UAO -TCO -DIT -SSBS BTYPE=--)
[   15.504065] pc : __mmc_blk_ioctl_cmd+0x13c/0x580
[   15.508704] lr : __mmc_blk_ioctl_cmd+0x4ac/0x580
[   15.513331] sp : ffff80008114b8a0
[   15.516646] x29: ffff80008114ba10 x28: ffff07ed8b9602c8 x27: 0000000000000000
[   15.523798] x26: 0000000000000003 x25: ffff07ed886d8008 x24: ffff07ed00626d70
[   15.530949] x23: ffff07ed80f7ce00 x22: 0000000000000003 x21: 0000000000000000
[   15.538100] x20: ffff07ed886d8000 x19: ffff07ed88951000 x18: 0000000000000000
[   15.545252] x17: 0000000000000000 x16: 0000000000000000 x15: 0000ffff84001000
[   15.552403] x14: 0000000000000000 x13: 0000000000000000 x12: 0000000000000000
[   15.559553] x11: 071c71c71c71c71c x10: 0000000000000aa0 x9 : ffffd6ac578524d0
[   15.566704] x8 : ffff07ed82160b00 x7 : 00000000000921f2 x6 : 0000000000000400
[   15.573855] x5 : 00000000410fd030 x4 : 0000000000000000 x3 : 0000000000000000
[   15.581005] x2 : 0000000000000000 x1 : 0000000000000001 x0 : 0000000000000001
[   15.588156] Call trace:
[   15.590603]  __mmc_blk_ioctl_cmd+0x13c/0x580
[   15.594884]  mmc_blk_mq_issue_rq+0x314/0x928
[   15.599160]  mmc_mq_queue_rq+0x124/0x2b0
[   15.603088]  blk_mq_dispatch_rq_list+0x290/0x798
[   15.607717]  __blk_mq_sched_dispatch_requests+0xc0/0x588
[   15.613041]  blk_mq_sched_dispatch_requests+0x40/0x88
[   15.618102]  blk_mq_run_hw_queue+0xfc/0x1a0
[   15.622291]  blk_execute_rq+0x108/0x238
[   15.626133]  mmc_blk_ioctl_multi_cmd+0x204/0x290
[   15.630760]  mmc_rpmb_ioctl+0x70/0x88
[   15.634431]  __arm64_sys_ioctl+0xb4/0x100
[   15.638448]  invoke_syscall+0x50/0x120
[   15.642209]  el0_svc_common.constprop.0+0x48/0xf0
[   15.646923]  do_el0_svc+0x24/0x38
[   15.650246]  el0_svc+0x40/0xe8
[   15.653307]  el0t_64_sync_handler+0x120/0x130
[   15.657670]  el0t_64_sync+0x190/0x198
[   15.661344] Code: 12010000 2a010000 b90137e0 b4000078 (b9400f00) 
[   15.667447] ---[ end trace 0000000000000000 ]---
Comment 1 Mikko Rapeli (Linaro) 2024-03-01 08:48:45 UTC
Downgrading kernel back to 6.5.10 while keeping optee version at 4.1.0 etc fixes the kernel crash.
Comment 2 Mikko Rapeli (Linaro) 2024-03-01 09:18:19 UTC
On rockpi4b and same TS firmware with optee 4.1.0 and kernel 6.6.17, the fTPM optee TA panics after RPMB access fails. RPMB access AFAIK should happen via kernel drivers and tee-supplicant in userspace.

https://ledge.validation.linaro.org/scheduler/job/82017

tee-supplicant -d --rpmb-cid 880103534c4436344710565b65a08800
D/TC:? 0 tee_ta_init_session_with_context:561 Re-op+ sleep 10
en TA 7011a688-ddde-4053-a5a9-7b3c4ddf13b8
F/TC:? 0 plat_prng_add_jitter_entropy:72 0x8A
D/TC:? 0 tee_ta_close_session:463 csess 0x3015d130 id 1
D/TC:? 0 tee_ta_close_session:482 Destroy session
+ modprobe tpm_ftpm_tee
D/TC:? 0 tee_ta_init_session_with_context:561 Re-open TA bc50d971-d4c9-42c4-82cb-343fb7f37896
F/TC:? 0 trace_syscall:150 syscall #13 (syscall_get_time)
F/TC:? 0 trace_syscall:150 syscall #24 (syscall_cryp_obj_get_info)
F/TC:? 0 trace_syscall:150 syscall #53 (syscall_storage_obj_seek)
F/TC:? 0 trace_syscall:150 syscall #51 (syscall_storage_obj_write)
D/TC:? 0 dump_fh:1885 fh->filename=/71D950BCC9D4C44282CB343FB7F37896/064D5054
D/TC:? 0 dump_fh:1886 fh->rpmb_fat_address=2304
D/TC:? 0 dump_fh:1887 fh->fat_entry.start_address=4184320
D/TC:? 0 dump_fh:1888 fh->fat_entry.data_size=536
D/TC:? 0 read_fat:2140 fat_address 2304
D/TC:? 0 rpmb_fs_write_primitive:2541 Need to re-allocate
D/TC:? 0 tee_rpmb_read:1251 Read 3 blocks at index 16345
F/TC:? 0 trace_syscall:150 syscall #2 (syscall_panic)
E/TC:? 0 
E/TC:? 0 TA panicked with code 0xffff0000
E/LD:  Status of TA bc50d971-d4c9-42c4-82cb-343fb7f37896
E/LD:   arch: aarch64
E/LD:  region  0: va 0x40005000 pa 0x3061b000 size 0x002000 flags rw-s (ldelf)
E/LD:  region  1: va 0x40007000 pa 0x3061d000 size 0x008000 flags r-xs (ldelf)
E/LD:  region  2: va 0x4000f000 pa 0x30625000 size 0x001000 flags rw-s (ldelf)
E/LD:  region  3: va 0x40010000 pa 0x30626000 size 0x004000 flags rw-s (ldelf)
E/LD:  region  4: va 0x40014000 pa 0x3062a000 size 0x001000 flags r--s
E/LD:  region  5: va 0x40015000 pa 0x306b2000 size 0x011000 flags rw-s (stack)
E/LD:  region  6: va 0x40026000 pa 0x00001000 size 0x068000 flags r-xs [0]
E/LD:  region  7: va 0x4008e000 pa 0x00069000 size 0x01f000 flags rw-s [0]
E/LD:  region  8: va 0x400ad000 pa 0xe6b2a000 size 0x002000 flags rw-- (param)
E/LD:   [0] bc50d971-d4c9-42c4-82cb-343fb7f37896 @ 0x40026000
E/LD:  Call stack:
E/LD:   0x4006401c
E/LD:   0x40026b40
E/LD:   0x400271b8
E/LD:   0x40045f3c
E/LD:   0x4005efc0
E/LD:   0x40027a2c
E/LD:   0x4006a1f4
E/LD:   0x4005f170
D/TC:? 0 user_ta_enter:201 tee_user_ta_enter: TA panicked with code 0xffff0000
D/TC:? 0 release_ta_ctx:663 Releasing panicked TA ctx
D/TC:? 0 tee_ta_invoke_command:791 Error: ffff3024 of 3
[   15.861143] tpm tpm0: ftpm_tee_tpm_op_send: SUBMIT_COMMAND invoke error: 0xffff3024
[   15.861837] tpm tpm0: tpm_try_transmit: send(): error -53212
D/TC:? 0 tee_ta_invoke_command:791 Error: ffff3024 of 3
[   15.862841] tpm tpm0: ftpm_tee_tpm_op_send: SUBMIT_COMMAND invoke error: 0xffff3024
[   15.863515] tpm tpm0: tpm_try_transmit: send(): error -53212
[   15.864017] optee-ftpm optee-ta-bc50d971-d4c9-42c4-82cb-343fb7f37896: ftpm_tee_probe: tpm_chip_register failed with rc=-53212
D/TC:? 0 tee_ta_close_session:463 csess 0x3015d130 id 1
D/TC:? 0 tee_ta_close_session:482 Destroy session
D/TC:? 0 destroy_context:321 Destroy TA ctx (0x30166fe0)
[   15.866424] optee-ftpm: probe of optee-ta-bc50d971-d4c9-42c4-82cb-343fb7f37896 failed with error -53212

If kernel is downgraded from 6.6.17 to 6.5.10, then optee and fTPM TA and RPMB access and TPM2 device in userspace work correctly to encrypt the rootfs:

https://ledge.validation.linaro.org/scheduler/job/81996

I/TC: OP-TEE version: 4.1.0-dev (gcc version 13.2.0 (GCC)) #1 Fri Jan 19 17:14:14 UTC 2024 aarch64
...
[    0.000000] Linux version 6.5.10-yocto-standard (oe-user@oe-host) (aarch64-trs-linux-gcc (GCC) 13.2.0, GNU ld (GNU Binutils) 2.42.0.20240216) #1 SMP PREEMPT Tue Nov  7 02:23:29 UTC 2023
[    0.000000] KASLR disabled due to lack of seed
[    0.000000] Machine model: Radxa ROCK Pi 4B
[    0.000000] efi: EFI v2.10 by Das U-Boot
[    0.000000] efi: ESRT=0xf0ea5040 TPMFinalLog=0xf0ea9040 RTPROP=0xf0ea7040 SMBIOS=0xf0ea3000 TPMEventLog=0xeb442040 INITRD=0xeb441040 RNG=0xe5d4f040 MEMRESERVE=0xe5d4e040 
...
[    2.076412] optee: probing for conduit method.
I/TC: Reserved shared memory is enabled
I/TC: Dynamic shared memory is enabled
I/TC: Normal World virtualization support is disabled
I/TC: Asynchronous notifications are disabled
[    2.076862] optee: revision 4.1 (18b424c2)
[    2.078971] optee: dynamic shared memory is enabled
[    2.080089] optee: initialized driver
[    2.080851] Driver 'optee' was unable to register with bus_type 'arm_ffa' because the bus was not initialized.
...
+ tee-supplicant -d --rpmb-cid 880103534c4436344710565b65a08800
+ modprobe tpm_ftpm_tee
+ rngd
...
+ tpm2_createprimary -Q --hierarchy=o --key-context=prim.ctx
+ tpm2_loadexternal --key-algorithm=rsa --hierarchy=o --public=signing_key_public.pem --key-context=signing_key.ctx --name=signing_key.name
+ tpm2_startauthsession --session=session.ctx
+ tpm2_policyauthorize --session=session.ctx --policy=authorized.policy --name=signing_key.name
+ tpm2_flushcontext session.ctx
+ cat /tmp/rand_key
+ tpm2_create --hash-algorithm=sha256 --public=auth_pcr_seal_key.pub --private=auth_pcr_seal_key.priv --sealing-input=- --parent-context=prim.ctx --policy=authorized.policy
+ tpm2_load -Q --parent-context=prim.ctx --public=auth_pcr_seal_key.pub --private=auth_pcr_seal_key.priv --name=seal.name --key-context=seal.ctx
+ tpm2_evictcontrol -Q -C o -c 0x8100000a
+ tpm2_evictcontrol --hierarchy=o --object-context=seal.ctx 0x8100000a
+ cd -
+ cryptsetup -q --type luks2 --cipher aes-xts-plain --hash sha256 --use-random --uuid=6091b3a4-ce08-3020-93a6-f755a22ef03b luksFormat /dev/mmcblk1p7 --key-file /tmp/rand_key --label otaroot
+ echo 'Creating encrypted filesystem ...'
Creating encrypted filesystem ...
Comment 3 Mikko Rapeli (Linaro) 2024-03-01 09:21:20 UTC
The same optee etc firmware SW versions cause an early boot panic on AMD/Xilinx kv260: https://github.com/OP-TEE/optee_os/issues/6722

But this does not even boot into kernel so it's unrelated to the RPMB issues.
Comment 4 Mikko Rapeli (Linaro) 2024-03-01 12:11:22 UTC
Reverting this commit d3c4786b01aad8c377718f92d6d9b15906ee0a2a from kernel 6.6.17:

commit d3c4786b01aad8c377718f92d6d9b15906ee0a2a
Author:     Sumit Garg <sumit.garg@linaro.org>
AuthorDate: Thu Nov 2 13:00:55 2023 +0530
Commit:     Greg Kroah-Hartman <gregkh@linuxfoundation.org>
CommitDate: Wed Dec 13 18:45:11 2023 +0100

    tee: optee: Fix supplicant based device enumeration
    
    [ Upstream commit 7269cba53d906cf257c139d3b3a53ad272176bca ]

removes the kernel crash/oops and shows only kernel errors related to optee/ftpm:

https://ledge.validation.linaro.org/scheduler/job/82131

+ tee-supplicant -d --rpmb-cid 7001004d33323530385212b201dea300
+ sleep 10
+ modprobe tpm_ftpm_tee
E/TC:?? 0 
E/TC:?? 0 TA panicked with code 0xffff0000
E/LD:  Status of TA bc50d971-d4c9-42c4-82cb-343fb7f37896
E/LD:   arch: aarch64
E/LD:  region  0: va 0x40005000 pa 0xfc61b000 size 0x002000 flags rw-s (ldelf)
E/LD:  region  1: va 0x40007000 pa 0xfc61d000 size 0x008000 flags r-xs (ldelf)
E/LD:  region  2: va 0x4000f000 pa 0xfc625000 size 0x001000 flags rw-s (ldelf)
E/LD:  region  3: va 0x40010000 pa 0xfc626000 size 0x004000 flags rw-s (ldelf)
E/LD:  region  4: va 0x40014000 pa 0xfc62a000 size 0x001000 flags r--s
E/LD:  region  5: va 0x40015000 pa 0xfc6b2000 size 0x011000 flags rw-s (stack)
E/LD:  region  6: va 0x40026000 pa 0x881610000 size 0x002000 flags rw-- (param)
E/LD:  region  7: va 0x4005a000 pa 0x00001000 size 0x068000 flags r-xs [0]
E/LD:  region  8: va 0x400c2000 pa 0x00069000 size 0x01f000 flags rw-s [0]
E/LD:   [0] bc50d971-d4c9-42c4-82cb-343fb7f37896 @ 0x4005a000
E/LD:  Call stack:
E/LD:   0x40097dd0
E/LD:   0x4005ab40
E/LD:   0x4005b1b8
E/LD:   0x40079f3c
E/LD:   0x40092fc0
E/LD:   0x4005ba2c
E/LD:   0x4009dfac
E/LD:   0x40093170
[   15.489494] tpm tpm0: ftpm_tee_tpm_op_send: SUBMIT_COMMAND invoke error: 0xffff3024
[   15.497211] tpm tpm0: tpm_try_transmit: send(): error -53212
[   15.502993] tpm tpm0: ftpm_tee_tpm_op_send: SUBMIT_COMMAND invoke error: 0xffff3024
[   15.510676] tpm tpm0: tpm_try_transmit: send(): error -53212
[   15.516369] optee-ftpm optee-ta-bc50d971-d4c9-42c4-82cb-343fb7f37896: ftpm_tee_probe: tpm_chip_register failed with rc=-53212
[   15.527962] optee-ftpm: probe of optee-ta-bc50d971-d4c9-42c4-82cb-343fb7f37896 failed with error -53212

TPM2 devices is not found which is better than a crash/oops in kernel.
Comment 5 Sumit Garg 2024-03-01 14:40:14 UTC
Thanks for the report. The kernel crash/oops should be fixed by https://lkml.org/lkml/2024/3/1/739.

-Sumit
Comment 6 Mikko Rapeli (Linaro) 2024-03-14 06:32:51 UTC
Verified that https://lkml.org/lkml/2024/3/1/739 fixes the issue.
Comment 7 Mikko Rapeli (Linaro) 2024-03-14 06:33:33 UTC
FYI, this crash relates to MMC RPMB regression bug https://bugzilla.kernel.org/show_bug.cgi?id=218587
Comment 8 Mikko Rapeli (Linaro) 2024-04-09 09:20:48 UTC
Fixed in master v6.8 and stable tree tags v6.1.84, v6.6.24, v6.7.12.