Hi Wangyuan,
Sorry for the delay. In case those issues are still relevant,
problem 1: AFAIU the error message comes from additional code added on top of upstream hafnium. I cannot see a question related to problem 1, can you please elaborate about what you think is an issue?
problem 2: This is probably caused by lacking "heap space", and the mm lib cannot allocate additional page tables. Did you attempt adjusting (increasing) this property for your project target: https://git.trustedfirmware.org/hafnium/project/reference.git/tree/BUILD.gn#...
Regards, Olivier.
________________________________ From: Wangyuan (ange, IT) wangyuan46@huawei.com Sent: 14 February 2023 04:32 To: hafnium hafnium@lists.trustedfirmware.org; Olivier Deprez Olivier.Deprez@arm.com; Jens Wiklander jens.wiklander@linaro.org Cc: zhouguangwei (C) zhouguangwei5@huawei.com; lingmingqiang lingmingqiang@huawei.com Subject: ffa memory problems ask for help
Hi, expert
When I built test environment with hafnium v2.7 and optee 3.20.0, then execute xtest crypto cases repeatedly, several problems happened. Could you please give us some help?
debug log is as follows:
problem 1:
regression_40VERBOSE: hafnium func 0x84000073, vm->id 0x0, args->arg1 0x50, args->arg2 0x50, args->arg3 0x0, args->arg4 0x0
Current share states:
SHARE 0x0 (from VM 0x0, attributes 0x2f, flags 0x8, tag 0, to 1 recipients [VM 0x8001: 0x6 (offset 48)]): fully sent with 1 fragments, 0 retrieved, sender's original mode: 0x7
07_ecc Test TEE Internal API Generate ECC key
VERBOSE: hafnium func 0x8400006f, vm->id 0x0, args->arg1 0x8001, args->arg2 0x0, args->arg3 0x80000000, args->arg4 0x0
E/TC:000 00 mobj_ffa_get_by_cookie:384 Populating mobj from rx buffer, cookie 0
VERBOSE: hafnium func 0x84000074, vm->id 0x8001, args->arg1 0x30, args->arg2 0x30, args->arg3 0x0, args->arg4 0x0
Current share states:
SHARE 0x0 (from VM 0x0, attributes 0x2f, flags 0x8, tag 0, to 1 recipients [VM 0x8001: 0x6 (offset 48)]): fully sent with 1 fragments, 0 retrieved, sender's original mode: 0x7
Current share states:
SHARE 0x0 (from VM 0x0, attributes 0x2f, flags 0x8, tag 0, to 1 recipients [VM 0x8001: 0x6 (offset 48)]): fully sent with 1 fragments, 1 retrieved, sender's original mode: 0x7
VERBOSE: hafnium func 0x84000065, vm->id 0x8001, args->arg1 0x0, args->arg2 0x0, args->arg3 0x0, args->arg4 0x0
D/TC:??? 00 tee_ta_init_pseudo_ta_session:296 Lookup pseudo TA cb3e5ba0-adf1-11e0-998b-0002a5d5c51b
D/TC:000 00 ldelf_load_ldelf:96 ldelf load address 0x40002000
D/LD: ldelf:134 Loading TS cb3e5ba0-adf1-11e0-998b-0002a5d5c51b
F/TC:??? 00 trace_syscall:190 syscall #3 (syscall_get_property)
F/TC:??? 00 trace_syscall:190 syscall #5 (syscall_open_ta_session)
D/TC:??? 00 ldelf_syscall_open_bin:142 Lookup user TA ELF cb3e5ba0-adf1-11e0-998b-0002a5d5c51b (Secure Storage TA)
VERBOSE: hafnium func 0x84000070, vm->id 0x8001, args->arg1 0x80010000, args->arg2 0x0, args->arg3 0x0, args->arg4 0x1
VERBOSE: hafnium func 0x84000073, vm->id 0x0, args->arg1 0x50, args->arg2 0x50, args->arg3 0x0, args->arg4 0x0
Current share states:
SHARE 0x0 (from VM 0x0, attributes 0x2f, flags 0x8, tag 0, to 1 recipients [VM 0x8001: 0x6 (offset 48)]): fully sent with 1 fragments, 1 retrieved, sender's original mode: 0x7
SHARE 0x1 (from VM 0x0, attributes 0x2f, flags 0x8, tag 0, to 1 recipients [VM 0x8001: 0x6 (offset 48)]): fully sent with 1 fragments, 0 retrieved, sender's original mode: 0x7
VERBOSE: hafnium func 0x8400006f, vm->id 0x0, args->arg1 0x8001, args->arg2 0x0, args->arg3 0x80000001, args->arg4 0x0
E/TC:000 00 mobj_ffa_get_by_cookie:384 Populating mobj from rx buffer, cookie 0x1
VERBOSE: hafnium func 0x84000074, vm->id 0x8001, args->arg1 0x30, args->arg2 0x30, args->arg3 0x0, args->arg4 0x0
Current share states:
SHARE 0x0 (from VM 0x0, attributes 0x2f, flags 0x8, tag 0, to 1 recipients [VM 0x8001: 0x6 (offset 48)]): fully sent with 1 fragments, 1 retrieved, sender's original mode: 0x7
SHARE 0x1 (from VM 0x0, attributes 0x2f, flags 0x8, tag 0, to 1 recipients [VM 0x8001: 0x6 (offset 48)]): fully sent with 1 fragments, 0 retrieved, sender's original mode: 0x7
Current share states:
SHARE 0x0 (from VM 0x0, attributes 0x2f, flags 0x8, tag 0, to 1 recipients [VM 0x8001: 0x6 (offset 48)]): fully sent with 1 fragments, 1 retrieved, sender's original mode: 0x7
SHARE 0x1 (from VM 0x0, attributes 0x2f, flags 0x8, tag 0, to 1 recipients [VM 0x8001: 0x6 (offset 48)]): fully sent with 1 fragments, 1 retrieved, sender's original mode: 0x7
VERBOSE: hafnium func 0x84000065, vm->id 0x8001, args->arg1 0x0, args->arg2 0x0, args->arg3 0x0, args->arg4 0x0
VERBOSE: hafnium func 0x84000070, vm->id 0x8001, args->arg1 0x80010000, args->arg2 0x0, args->arg3 0x0, args->arg4 0x1
VERBOSE: hafnium func 0x8400006f, vm->id 0x0, args->arg1 0x8001, args->arg2 0x0, args->arg3 0x80000001, args->arg4 0x0
VERBOSE: hafnium func 0x84000070, vm->id 0x8001, args->arg1 0x80010000, args->arg2 0x0, args->arg3 0x0, args->arg4 0x1
VERBOSE: hafnium func 0x8400006f, vm->id 0x0, args->arg1 0x8001, args->arg2 0x0, args->arg3 0x80000001, args->arg4 0x0
VERBOSE: hafnium func 0x84000070, vm->id 0x8001, args->arg1 0x80010000, args->arg2 0x0, args->arg3 0x0, args->arg4 0x1
VERBOSE: hafnium func 0x8400006f, vm->id 0x0, args->arg1 0x8001, args->arg2 0x0, args->arg3 0x80000001, args->arg4 0x0
VERBOSE: hafnium func 0x84000070, vm->id 0x8001, args->arg1 0x80010000, args->arg2 0x0, args->arg3 0x0, args->arg4 0x1
VERBOSE: hafnium func 0x8400006f, vm->id 0x0, args->arg1 0x8001, args->arg2 0x0, args->arg3 0x80000001, args->arg4 0x0
I/TC: Cipher free ctx done!
I/TC: Performing software calc!
I/TC: Aead free ctx done!
VERBOSE: hafnium func 0x84000070, vm->id 0x8001, args->arg1 0x80010000, args->arg2 0x0, args->arg3 0x0, args->arg4 0x1
VERBOSE: hafnium func 0x8400006f, vm->id 0x0, args->arg1 0x8001, args->arg2 0x0, args->arg3 0x80000001, args->arg4 0x0
I/TC: Performing software calc!
I/TC: Aead free ctx done!
VERBOSE: hafnium func 0x84000070, vm->id 0x8001, args->arg1 0x80010000, args->arg2 0x0, args->arg3 0x0, args->arg4 0x1
VERBOSE: hafnium func 0x8400006f, vm->id 0x0, args->arg1 0x8001, args->arg2 0x0, args->arg3 0x80000001, args->arg4 0x0
I/TC: Performing software calc!
I/TC: Aead free ctx done!
VERBOSE: hafnium func 0x84000070, vm->id 0x8001, args->arg1 0x80010000, args->arg2 0x0, args->arg3 0x0, args->arg4 0x1
VERBOSE: hafnium func 0x8400006f, vm->id 0x0, args->arg1 0x8001, args->arg2 0x0, args->arg3 0x80000001, args->arg4 0x0
I/TC: Performing software calc!
I/TC: Aead free ctx done!
VERBOSE: hafnium func 0x84000070, vm->id 0x8001, args->arg1 0x80010000, args->arg2 0x0, args->arg3 0x0, args->arg4 0x1
VERBOSE: hafnium func 0x8400006f, vm->id 0x0, args->arg1 0x8001, args->arg2 0x0, args->arg3 0x80000001, args->arg4 0x0
VERBOSE: hafnium func 0x84000070, vm->id 0x8001, args->arg1 0x80010000, args->arg2 0x0, args->arg3 0x0, args->arg4 0x1
VERBOSE: hafnium func 0x8400006f, vm->id 0x0, args->arg1 0x8001, args->arg2 0x0, args->arg3 0x80000001, args->arg4 0x0
VERBOSE: hafnium func 0x84000070, vm->id 0x8001, args->arg1 0x80010000, args->arg2 0x0, args->arg3 0x0, args->arg4 0x1
VERBOSE: hafnium func 0x8400006f, vm->id 0x0, args->arg1 0x8001, args->arg2 0x0, args->arg3 0x80000001, args->arg4 0x0
VERBOSE: hafnium func 0x84000070, vm->id 0x8001, args->arg1 0x80010000, args->arg2 0x0, args->arg3 0x0, args->arg4 0x1
VERBOSE: hafnium func 0x8400006f, vm->id 0x0, args->arg1 0x8001, args->arg2 0x0, args->arg3 0x80000001, args->arg4 0x0
I/TC: Cipher free ctx done!
I/TC: Performing software calc!
I/TC: Aead free ctx done!
VERBOSE: hafnium func 0x84000070, vm->id 0x8001, args->arg1 0x80010000, args->arg2 0x0, args->arg3 0x0, args->arg4 0x1
VERBOSE: hafnium func 0x8400006f, vm->id 0x0, args->arg1 0x8001, args->arg2 0x0, args->arg3 0x80000001, args->arg4 0x0
VERBOSE: hafnium func 0x84000070, vm->id 0x8001, args->arg1 0x80010000, args->arg2 0x0, args->arg3 0x0, args->arg4 0x1
VERBOSE: hafnium func 0x8400006f, vm->id 0x0, args->arg1 0x8001, args->arg2 0x0, args->arg3 0x80000001, args->arg4 0x0
D/TC:??? 00 ldelf_syscall_open_bin:146 res=0xffff0008
D/TC:??? 00 ldelf_syscall_open_bin:142 Lookup user TA ELF cb3e5ba0-adf1-11e0-998b-0002a5d5c51b (REE)
VERBOSE: hafnium func 0x84000070, vm->id 0x8001, args->arg1 0x80010000, args->arg2 0x0, args->arg3 0x0, args->arg4 0x1
VERBOSE: hafnium func 0x8400006f, vm->id 0x0, args->arg1 0x8001, args->arg2 0x0, args->arg3 0x80000001, args->arg4 0x0
VERBOSE: hafnium func 0x84000070, vm->id 0x8001, args->arg1 0x80010000, args->arg2 0x0, args->arg3 0x0, args->arg4 0x1
VERBOSE: hafnium func 0x84000073, vm->id 0x0, args->arg1 0x270, args->arg2 0x270, args->arg3 0x0, args->arg4 0x0
ERROR: arch_mm_pte_attrs error!
INFO: begin 0x7f3cf000 end 0x7f3d0000 level 0 pte 0x82084059e78 l_end 0x7f400000 entry_size 0x1000!
ERROR: mm_ptable_get_attrs_level second error!
INFO: begin 0x7f3ce000 end 0x7f3d0000 level 1 pte 0x82084052fc8 l_end 0x80000000 entry_size 0x200000!
ERROR: mm_ptable_get_attrs_level second error!
INFO: begin 0x7f3ce000 end 0x7f3d0000 level 2 pte 0x82084051008 l_end 0x8000000000 entry_size 0x40000000!
ERROR: mm_ptable_get_attrs_level second error!
INFO: begin 0x7f3ce000 end 0x7f3d0000 level 3 pte 0x82084035000 l_end 0x1000000000000 entry_size 0x8000000000!
ERROR: mm_ptable_get_attrs_level fail!
Current share states:
SHARE 0x0 (from VM 0x0, attributes 0x2f, flags 0x8, tag 0, to 1 recipients [VM 0x8001: 0x6 (offset 48)]): fully sent with 1 fragments, 1 retrieved, sender's original mode: 0x7
SHARE 0x1 (from VM 0x0, attributes 0x2f, flags 0x8, tag 0, to 1 recipients [VM 0x8001: 0x6 (offset 48)]): fully sent with 1 fragments, 1 retrieved, sender's original mode: 0x7
SHARE 0x2 (from VM 0x0, attributes 0x2f, flags 0x8, tag 0, to 1 recipients [VM 0x8001: 0x6 (offset 48)]): fully sent with 1 fragments, 0 retrieved, sender's original mode: 0x7
VERBOSE: hafnium func 0x8400006f, vm->id 0x0, args->arg1 0x8001, args->arg2 0x0, args->arg3 0x80000001, args->arg4 0x0
E/TC:000 00 mobj_ffa_get_by_cookie:384 Populating mobj from rx buffer, cookie 0x2
VERBOSE: hafnium func 0x84000074, vm->id 0x8001, args->arg1 0x30, args->arg2 0x30, args->arg3 0x0, args->arg4 0x0
Current share states:
SHARE 0x0 (from VM 0x0, attributes 0x2f, flags 0x8, tag 0, to 1 recipients [VM 0x8001: 0x6 (offset 48)]): fully sent with 1 fragments, 1 retrieved, sender's original mode: 0x7
SHARE 0x1 (from VM 0x0, attributes 0x2f, flags 0x8, tag 0, to 1 recipients [VM 0x8001: 0x6 (offset 48)]): fully sent with 1 fragments, 1 retrieved, sender's original mode: 0x7
SHARE 0x2 (from VM 0x0, attributes 0x2f, flags 0x8, tag 0, to 1 recipients [VM 0x8001: 0x6 (offset 48)]): fully sent with 1 fragments, 0 retrieved, sender's original mode: 0x7
Current share states:
SHARE 0x0 (from VM 0x0, attributes 0x2f, flags 0x8, tag 0, to 1 recipients [VM 0x8001: 0x6 (offset 48)]): fully sent with 1 fragments, 1 retrieved, sender's original mode: 0x7
SHARE 0x1 (from VM 0x0, attributes 0x2f, flags 0x8, tag 0, to 1 recipients [VM 0x8001: 0x6 (offset 48)]): fully sent with 1 fragments, 1 retrieved, sender's original mode: 0x7
SHARE 0x2 (from VM 0x0, attributes 0x2f, flags 0x8, tag 0, to 1 recipients [VM 0x8001: 0x6 (offset 48)]): fully sent with 1 fragments, 1 retrieved, sender's original mode: 0x7
VERBOSE: hafnium func 0x84000065, vm->id 0x8001, args->arg1 0x0, args->arg2 0x0, args->arg3 0x0, args->arg4 0x0
VERBOSE: hafnium func 0x84000070, vm->id 0x8001, args->arg1 0x80010000, args->arg2 0x0, args->arg3 0x0, args->arg4 0x1
VERBOSE: hafnium func 0x8400006f, vm->id 0x0, args->arg1 0x8001, args->arg2 0x0, args->arg3 0x80000001, args->arg4 0x0
D/TC:??? 00 ldelf_syscall_open_bin:146 res=0
Problem2:
VERBOSE: hafnium func 0x84000070, vm->id 0x8001, args->arg1 0x80010000, args->arg2 0x0, args->arg3 0x0, args->arg4 0x1
VERBOSE: hafnium func 0x8400006f, vm->id 0x0, args->arg1 0x8001, args->arg2 0x0, args->arg3 0x80000001, args->arg4 0x0
VERBOSE: hafnium func 0x84000070, vm->id 0x8001, args->arg1 0x80010000, args->arg2 0x0, args->arg3 0x0, args->arg4 0x1
VERBOSE: hafnium func 0x8400006f, vm->id 0x0, args->arg1 0x8001, args->arg2 0x0, args->arg3 0x80000001, args->arg4 0x0
VERBOSE: hafnium func 0x84000070, vm->id 0x8001, args->arg1 0x80010000, args->arg2 0x0, args->arg3 0x0, args->arg4 0x1
VERBOSE: hafnium func 0x8400006f, vm->id 0x0, args->arg1 0x8001, args->arg2 0x0, args->arg3 0x80000001, args->arg4 0x0
VERBOSE: hafnium func 0x84000070, vm->id 0x8001, args->arg1 0x80010000, args->arg2 0x0, args->arg3 0x0, args->arg4 0x1
VERBOSE: hafnium func 0x8400006f, vm->id 0x0, args->arg1 0x8001, args->arg2 0x0, args->arg3 0x80000001, args->arg4 0x0
I/TC: Cipher free ctx done!
I/TC: Performing software calc!
I/TC: Aead free ctx done!
VERBOSE: hafnium func 0x84000070, vm->id 0x8001, args->arg1 0x80010000, args->arg2 0x0, args->arg3 0x0, args->arg4 0x1
VERBOSE: hafnium func 0x8400006f, vm->id 0x0, args->arg1 0x8001, args->arg2 0x0, args->arg3 0x80000001, args->arg4 0x0
VERBOSE: hafnium func 0x84000070, vm->id 0x8001, args->arg1 0x80010000, args->arg2 0x0, args->arg3 0x0, args->arg4 0x1
VERBOSE: hafnium func 0x8400006f, vm->id 0x0, args->arg1 0x8001, args->arg2 0x0, args->arg3 0x80000001, args->arg4 0x0
D/TC:??? 00 ldelf_syscall_open_bin:146 res=0xffff0008
D/TC:??? 00 ldelf_syscall_open_bin:142 Lookup user TA ELF cb3e5ba0-adf1-11e0-998b-0002a5d5c51b (REE)
VERBOSE: hafnium func 0x84000070, vm->id 0x8001, args->arg1 0x80010000, args->arg2 0x0, args->arg3 0x0, args->arg4 0x1
VERBOSE: hafnium func 0x8400006f, vm->id 0x0, args->arg1 0x8001, args->arg2 0x0, args->arg3 0x80000001, args->arg4 0x0
VERBOSE: hafnium func 0x84000070, vm->id 0x8001, args->arg1 0x80010000, args->arg2 0x0, args->arg3 0x0, args->arg4 0x1
VERBOSE: hafnium func 0x84000073, vm->id 0x0, args->arg1 0x270, args->arg2 0x270, args->arg3 0x0, args->arg4 0x0
Current share states:
SHARE 0x0 (from VM 0x0, attributes 0x2f, flags 0x8, tag 0, to 1 recipients [VM 0x8001: 0x6 (offset 48)]): fully sent with 1 fragments, 1 retrieved, sender's original mode: 0x7
SHARE 0x1 (from VM 0x0, attributes 0x2f, flags 0x8, tag 0, to 1 recipients [VM 0x8001: 0x6 (offset 48)]): fully sent with 1 fragments, 1 retrieved, sender's original mode: 0x7
SHARE 0x2 (from VM 0x0, attributes 0x2f, flags 0x8, tag 0, to 1 recipients [VM 0x8001: 0x6 (offset 48)]): fully sent with 1 fragments, 0 retrieved, sender's original mode: 0x7
VERBOSE: hafnium func 0x8400006f, vm->id 0x0, args->arg1 0x8001, args->arg2 0x0, args->arg3 0x80000001, args->arg4 0x0
E/TC:000 00 mobj_ffa_get_by_cookie:384 Populating mobj from rx buffer, cookie 0x2
VERBOSE: hafnium func 0x84000074, vm->id 0x8001, args->arg1 0x30, args->arg2 0x30, args->arg3 0x0, args->arg4 0x0
Current share states:
SHARE 0x0 (from VM 0x0, attributes 0x2f, flags 0x8, tag 0, to 1 recipients [VM 0x8001: 0x6 (offset 48)]): fully sent with 1 fragments, 1 retrieved, sender's original mode: 0x7
SHARE 0x1 (from VM 0x0, attributes 0x2f, flags 0x8, tag 0, to 1 recipients [VM 0x8001: 0x6 (offset 48)]): fully sent with 1 fragments, 1 retrieved, sender's original mode: 0x7
SHARE 0x2 (from VM 0x0, attributes 0x2f, flags 0x8, tag 0, to 1 recipients [VM 0x8001: 0x6 (offset 48)]): fully sent with 1 fragments, 0 retrieved, sender's original mode: 0x7
ERROR: Failed to allocate memory for page table
VERBOSE: Insufficient memory to update recipient page table.
Current share states:
SHARE 0x0 (from VM 0x0, attributes 0x2f, flags 0x8, tag 0, to 1 recipients [VM 0x8001: 0x6 (offset 48)]): fully sent with 1 fragments, 1 retrieved, sender's original mode: 0x7
SHARE 0x1 (from VM 0x0, attributes 0x2f, flags 0x8, tag 0, to 1 recipients [VM 0x8001: 0x6 (offset 48)]): fully sent with 1 fragments, 1 retrieved, sender's original mode: 0x7
SHARE 0x2 (from VM 0x0, attributes 0x2f, flags 0x8, tag 0, to 1 recipients [VM 0x8001: 0x6 (offset 48)]): fully sent with 1 fragments, 0 retrieved, sender's original mode: 0x7
E/TC:000 00 spmc_retrieve_req:1418 Failed to fetch cookie 0x2 error code -3
E/TC:000 00 thread_spmc_populate_mobj_from_rx:1486 Failed to retrieve cookie from rx buffer 0x2
E/TC:??? 00 mobj_ffa_get_by_cookie:423 Failed to get cookie 0x2 internal_offs 0
D/TC:??? 00 thread_rpc_alloc:1261 mobj_ffa_get_by_cookie(0x2, 0): failed
D/TC:??? 00 ldelf_syscall_open_bin:146 res=0xffff000c
Can anyone figure out what the problem is and give some debugging directions? Thanks!
regards,
wangyuan