search

OP-TEE / optee_os

Trusted side of the TEE
Other
1.58k stars 1.06k forks source link

Giving more SRAM to OP-TEE on STM32MP157 #5971

Closed johndoe31415 closed 1 year ago

johndoe31415 commented 1 year ago

This is a followup of the performance investigation in #5915. The summary is: OP-TEE, to run with good performance, would like to have around 384 kiB of RAM because otherwise frequent evictions of the pager make everything quite slow.

The STM32MP1 is a Cortex-A that has an internal Cortex-M4 companion. There is 256 kiB of SYSRAM which OP-TEE usually runs in (see STM RM0436 Rev 6 pg 158 for the memory map), starting at 0x2ffc0000 (until 0x2fffffff). The SRAM which is usually dedicated to the M4 is split into four peripherals, SRAM1, SRAM2, SRAM3 and SRAM4. They have sizes 128, 128, 64, and 64 kiB. SRAM1 starts by default at 0x1000000, BUT there is a RAM alias starting at 0x3000000 (right after the SYSRAM) in which SRAM1, 2, 3 and 4 are also mapped.

So, in theory, we could have a contiguous SRAM memory area of 384 kiB (SYSRAM + SRAM1), where 0x2ffc0000 to 0x2fffffff is occupied by SYSRAM followed directly by the SRAM1 alias 0x30000000 to 0x3001ffff.

Can we access SRAM1 from OP-TEE/TZ? I believe so. While for SYSRAM it is relatively straightforward by programming decprot of the ETZPC (see page 1117 of RM0436) , the four SRAMs are marked as "Securable IP" behind an "AHB stub". I.e., SRAM is connected to the AHB, but it is "extended w/ security". I currently am completely uncertain what this "stub" looks like or how it would work.

Later in the RM, page 1125, it lists SRAM to be connected to the MLAHB as a type 3 peripheral ("securable and MCU isolation support") with a default configuration of 0b11. Table 92 on page 1120 shows type 3 peripherals wiht a decprot configuration of 0b11 are by default non-secure, but that means that secure write is possible (only that additionally non-secure write would also be possible).

So it is my understanding that in the default configuration after bootup, SRAM1 should be read/writable from the secure world (obviously this wouldn't yet be secure because the insecure world could also access the memory, but good enough for trying out if it works in principle).

My understanding of OP-TEE on the STM32MP1 is the following: the memory layout is so that OP-TEE starts at SYSRAM (_start at 0x2ffc0000) and the pagable data is located in pages that follow right after SYSRAM (i.e., in my case 0x30000000 where coincidentally the actual physical RAM is located I want to use). As far as I understand the linker script is generated during the OP-TEE build and also the MMU is programmed according to the page layout.

So, in theory, I thought I could get away with something as simple as making OP-TEE believe that it simply has 384 kiB of SYSRAM; my thinking was that it would insert a 1:1 logical/physical MMU mapping on the address space from 0x2ffc0000 to 0x3001ffff (SYSRAM + SRAM1) and would simply start the .text_pageable section at 0x30020000.

Firstly, I was surprised that CFG_TZSRAM_SIZE defaults to 0x3f000 or 252 kiB (one page less than available). I'm assuming one page is reserved for the non-secure portion of the SYSRAM (I believe this is where SCSI_SHM is located?). Simply moving this up from 0x3f000 to 0x5f000 (380 kiB) did not work, since it then fails the compile time assertion:

    COMPILE_TIME_ASSERT(((SYSRAM_BASE + SYSRAM_SIZE) <= CFG_TZSRAM_START) ||
                ((SYSRAM_BASE <= CFG_TZSRAM_START) &&
                 (SYSRAM_SEC_SIZE >= CFG_TZSRAM_SIZE)));

I believe this assertion is caused because it is assumed that OP-TEE only ever resides in SYSRAM. I took it out and moved CFG_STM32MP1_SCMI_SHM_BASE to 0x3001f000, which then in turn causes the SYSRAM_SEC_SIZE to automatically become equal to SYSRAM_SIZE. This is what we want since we don't want a "SHM hole" in our memory, but rather a contiguous SRAM area (and the SHM possibly at the very end).

The next step was to attempt to configure the SRAM to allow only access from OP-TEE right in init_stem32p1_drivers: 

    res = stm32_firewall_set_config(MCUSRAM_BASE, 0x20000, sec_cfg);
    if (res)
        panic("Unable to secure SRAM1");

This panics, however, unable to secure SRAM1. In principle, this should work but I believe I'm missing something. If I do not try to secure SRAM1, I get stuck in a bootloop (not sure where it hangs, but eventually I run into a watchdog reset).

Again so much rabbit hole for relatively little effort. But I do think what I'm attempting should be doable and actually fairly easy. It would have great performance benefits on STM32MP1 and would certainly be worthwhile, I believe. Any support would be greatly appreciated to point me in the right direciton. Thanks!

johndoe31415 commented 1 year ago

One more idea that I had: The SYSRAM is usually partitioned into SEC and NS parts where the NS parts is used for the SCMI SHM communication. SYSRAM can be partioned like this, but SRAM1 to the best of my knowledge cannot. So possibly this could be the reason for it hanging? I've tried disabling the SCMI PTA, but that didn't change anything, but also I'm entirely unsure how the SCMI subsystem works.

etienne-lms commented 1 year ago

Hi @johndoe31415,

You're right, there are some internal RAMs that can be assigned to secure world and their physical address ranges are contiguous SYSRAM. So yes, you can assign all thoses to OP-TEE and set, for example, CFG_TZSRAM_SIZE to 256kB (SYSRAM) + 128K+128K+64k+64K (SRAM1/2/3/4) ending up with 640kB of secure internal RAM. This is not the configuration currently released as STM32MP15 platforms initially expect one can use these SRAMs for companion Cortex-M4.

As you mention, using such a layout together with SCMI requires SCMI shared memory to not be located at SYSRAM last 4kB page. It could be moved to SRAM4 (if not secured) or simply SCMI config changed to use OP-TEE generic shared memory: remove shmem property (if used) from U-Boot/Linux DTS files and hack into _optee_os/.../plat-stm32/scmiserver.c to not map and use SYSRAM as SCMI shared mem.

To help you achieving this, I've created a (somewhat hacky) change (branch stm32-wider-sram) in my optee_os.git fork you can freely pick and use. Note that this change applies to mainline OP-TEE source tree, not the source tree you are using, but I think you'll find your way with. I did not think about upstreaming such a setup but if one thinks there is interest in, I could clean it up and submit to the upstream. (edited: fixed patch ref)

johndoe31415 commented 1 year ago

Hi @etienne-lms , this looks incredibly helpful, thanks a bunch!

I've spent all night backporting your patch to 3.16, with somewhat success. I do have a cleanly compiling version that I believe could work, but unfortunately in the process I somehow broke DTB initialization of the device. Therefore, the RNG does not get initialized and the whole system panics. I'm currently trying to figure out from where this code is called and why it might fail.

The stm32_etzpc.c has seen major refactoring and looks very different in your version. Instead of cherrypicking pieces, I simply transplanted the whole driver to 3.16, which worked surprisingly well. I believe, however, that in there were some init calls that I also removed. Need to take a closer look.

My initial approach was not to worry about it and remove the RNG initialization altogether, butchering it just to attempt if it works at all. But this has led to more and more problems down the road (Panic: "E/TC:0 0 probe_dt_drivers:727 Probe sequence result: 0x80000000"). I need to fix initialization of DTB-declared peripherals properly to be able to test this.

It also appears you're on an MP13 while I'm on MP15, so I've had to change a few peripheral names. I also could have introduced an error there. Do I need to initialize all of them or can I just omit those that have a NS configuration since that should be the default, shouldn't it?

I've also been thinking about the SCMI memory. Using SRAM4 as NS doesn't seem too appealing to me because it would take away a whole 64 kiB block only for the single needed page. But doesn't the SYSRAM partitioning allow for S and NS parts to be configured independently? So the SCMI SHM page could be the very first page of SYSRAM (as opposed to be the last page), configured NS, and then following it there would be contiguously configured secure memory, with a nice granularaty (SYSRAM + 0-5 SRAMs). That would mean there is also more memory for the M4 if operation of both the A and M4 are required in the application.

EDIT: I believe the problem could be that the old etzpc driver (3.16) has, if I understand it correctly, essentially peripheral addresses (and their initialization?!) hardcoded in the driver itself, while the newer version seems to read it out of the DT. Could be that my DT is only missing the required fields, so I'm investigating the TF-A differences in DT now.

EDIT2: I'm cautiously optimistic becuase when I previously tried to increase the log level, it would never load the image at all. Now I can use core level 3 logging without any issue. So I do believe I have way more RAM available now. I only need to figure out how to get it to boot to measure performance. The DTB failed probe list seems to be empty, however. Don't really understand what is going on.

NOTICE:  BL2: Booting BL32
INFO:    Entry point address = 0x2ffc0000
INFO:    SPSR = 0x1d3
I/TC: Early console on UART#4
D/TC:0   add_phys_mem:596 TEE_SHMEM_START type NSEC_SHM 0xde000000 size 0x00200000
D/TC:0   add_phys_mem:596 TA_RAM_START type TA_RAM 0xde200000 size 0x01e00000
D/TC:0   add_phys_mem:596 VCORE_INIT_RX_PA type INIT_RAM_RX 0x2ffec000 size 0x00074000
D/TC:0   add_phys_mem:596 VCORE_UNPG_RW_PA type TEE_RAM_RW 0x2ffd1000 size 0x0001b000
D/TC:0   add_phys_mem:596 VCORE_UNPG_RX_PA type TEE_RAM_RX 0x2ffc0000 size 0x00011000
D/TC:0   add_phys_mem:596 TEE_RAM_START type ROM_SEC 0x2ffc0000 size 0x000a0000
D/TC:0   add_phys_mem:596 DDR_BASE type RAM_NSEC 0xc0000000 size 0x00001000
D/TC:0   add_phys_mem:596 ROUNDDOWN(0xa0021000ul, CORE_MMU_PGDIR_SIZE) type IO_SEC 0xa0000000 size 0x00200000
D/TC:0   add_phys_mem:596 ROUNDDOWN(0x54000000, CORE_MMU_PGDIR_SIZE) type IO_SEC 0x54000000 size 0x00200000
D/TC:0   add_phys_mem:596 ROUNDDOWN(0x50000000, CORE_MMU_PGDIR_SIZE) type IO_SEC 0x50000000 size 0x00200000
D/TC:0   add_phys_mem:596 ROUNDDOWN(0x5c000000, CORE_MMU_PGDIR_SIZE) type IO_SEC 0x5c000000 size 0x00200000
D/TC:0   add_phys_mem:596 ROUNDDOWN(0x5a000000, CORE_MMU_PGDIR_SIZE) type IO_SEC 0x5a000000 size 0x00200000
D/TC:0   add_phys_mem:596 ROUNDDOWN(0x50020000, CORE_MMU_PGDIR_SIZE) type IO_SEC 0x50000000 size 0x00200000
D/TC:0   add_phys_mem:610 Physical mem map overlaps 0x50000000
D/TC:0   add_phys_mem:596 ROUNDDOWN(0x54000000, CORE_MMU_PGDIR_SIZE) type IO_NSEC 0x54000000 size 0x00200000
D/TC:0   add_phys_mem:596 ROUNDDOWN(0x50000000, CORE_MMU_PGDIR_SIZE) type IO_NSEC 0x50000000 size 0x00200000
D/TC:0   add_phys_mem:596 ROUNDDOWN(0x5c000000, CORE_MMU_PGDIR_SIZE) type IO_NSEC 0x5c000000 size 0x00200000
D/TC:0   add_phys_mem:596 ROUNDDOWN(0x5a000000, CORE_MMU_PGDIR_SIZE) type IO_NSEC 0x5a000000 size 0x00200000
D/TC:0   add_phys_mem:596 ROUNDDOWN(0x50020000, CORE_MMU_PGDIR_SIZE) type IO_NSEC 0x50000000 size 0x00200000
D/TC:0   add_phys_mem:610 Physical mem map overlaps 0x50000000
D/TC:0   add_phys_mem:596 ROUNDDOWN(0x44000000, CORE_MMU_PGDIR_SIZE) type IO_NSEC 0x44000000 size 0x00200000
D/TC:0   add_phys_mem:596 ROUNDDOWN(0x40000000, CORE_MMU_PGDIR_SIZE) type IO_NSEC 0x40000000 size 0x00200000
D/TC:0   add_va_space:636 type RES_VASPACE size 0x00a00000
D/TC:0   add_va_space:636 type SHM_VASPACE size 0x02000000
D/TC:0   dump_mmap_table:751 type TA_RAM       va 0x29800000..0x2b5fffff pa 0xde200000..0xdfffffff size 0x01e00000 (pgdir)
D/TC:0   dump_mmap_table:751 type NSEC_SHM     va 0x2b800000..0x2b9fffff pa 0xde000000..0xde1fffff size 0x00200000 (pgdir)
D/TC:0   dump_mmap_table:751 type IO_SEC       va 0x2ba00000..0x2bbfffff pa 0xa0000000..0xa01fffff size 0x00200000 (pgdir)
D/TC:0   dump_mmap_table:751 type IO_NSEC      va 0x2bc00000..0x2bdfffff pa 0x5c000000..0x5c1fffff size 0x00200000 (pgdir)
D/TC:0   dump_mmap_table:751 type IO_SEC       va 0x2be00000..0x2bffffff pa 0x5c000000..0x5c1fffff size 0x00200000 (pgdir)
D/TC:0   dump_mmap_table:751 type IO_SEC       va 0x2c000000..0x2c1fffff pa 0x5a000000..0x5a1fffff size 0x00200000 (pgdir)
D/TC:0   dump_mmap_table:751 type IO_NSEC      va 0x2c200000..0x2c3fffff pa 0x5a000000..0x5a1fffff size 0x00200000 (pgdir)
D/TC:0   dump_mmap_table:751 type IO_SEC       va 0x2c400000..0x2c5fffff pa 0x54000000..0x541fffff size 0x00200000 (pgdir)
D/TC:0   dump_mmap_table:751 type IO_NSEC      va 0x2c600000..0x2c7fffff pa 0x54000000..0x541fffff size 0x00200000 (pgdir)
D/TC:0   dump_mmap_table:751 type IO_NSEC      va 0x2c800000..0x2c9fffff pa 0x50000000..0x501fffff size 0x00200000 (pgdir)
D/TC:0   dump_mmap_table:751 type IO_SEC       va 0x2ca00000..0x2cbfffff pa 0x50000000..0x501fffff size 0x00200000 (pgdir)
D/TC:0   dump_mmap_table:751 type IO_NSEC      va 0x2cc00000..0x2cdfffff pa 0x44000000..0x441fffff size 0x00200000 (pgdir)
D/TC:0   dump_mmap_table:751 type IO_NSEC      va 0x2ce00000..0x2cffffff pa 0x40000000..0x401fffff size 0x00200000 (pgdir)
D/TC:0   dump_mmap_table:751 type RES_VASPACE  va 0x2d000000..0x2d9fffff pa 0x00000000..0x009fffff size 0x00a00000 (pgdir)
D/TC:0   dump_mmap_table:751 type SHM_VASPACE  va 0x2dc00000..0x2fbfffff pa 0x00000000..0x01ffffff size 0x02000000 (pgdir)
D/TC:0   dump_mmap_table:751 type RAM_NSEC     va 0x2ff1f000..0x2ff1ffff pa 0xc0000000..0xc0000fff size 0x00001000 (smallpg)
D/TC:0   dump_mmap_table:751 type ROM_SEC      va 0x2ff20000..0x2ffbffff pa 0x2ffc0000..0x3005ffff size 0x000a0000 (smallpg)
D/TC:0   dump_mmap_table:751 type TEE_RAM_RX   va 0x2ffc0000..0x2ffd0fff pa 0x2ffc0000..0x2ffd0fff size 0x00011000 (smallpg)
D/TC:0   dump_mmap_table:751 type TEE_RAM_RW   va 0x2ffd1000..0x2ffebfff pa 0x2ffd1000..0x2ffebfff size 0x0001b000 (smallpg)
D/TC:0   dump_mmap_table:751 type INIT_RAM_RX  va 0x2ffec000..0x3005ffff pa 0x2ffec000..0x3005ffff size 0x00074000 (smallpg)
D/TC:0   dump_mmap_table:751 type PAGER_VASPACE va 0x30060000..0x301bffff pa 0x00000000..0x0015ffff size 0x00160000 (smallpg)
D/TC:0   core_mmu_xlat_table_alloc:513 xlat tables used 1 / 4
D/TC:0   core_mmu_xlat_table_alloc:513 xlat tables used 2 / 4
D/TC:0   core_mmu_xlat_table_alloc:513 xlat tables used 3 / 4
I/TC: 
I/TC: Pager is enabled. Hashes: 3040 bytes
D/TC:0 0 init_runtime:467 Checking hashes of pageable area
D/TC:0 0 init_runtime:473 hash pg_idx 0 hash 0x2ffeb418 page 0x29800000
D/TC:0 0 init_runtime:473 hash pg_idx 1 hash 0x2ffeb438 page 0x29801000
D/TC:0 0 init_runtime:473 hash pg_idx 2 hash 0x2ffeb458 page 0x29802000
D/TC:0 0 init_runtime:473 hash pg_idx 3 hash 0x2ffeb478 page 0x29803000
D/TC:0 0 init_runtime:473 hash pg_idx 4 hash 0x2ffeb498 page 0x29804000
D/TC:0 0 init_runtime:473 hash pg_idx 5 hash 0x2ffeb4b8 page 0x29805000
D/TC:0 0 init_runtime:473 hash pg_idx 6 hash 0x2ffeb4d8 page 0x29806000
D/TC:0 0 init_runtime:473 hash pg_idx 7 hash 0x2ffeb4f8 page 0x29807000
D/TC:0 0 init_runtime:473 hash pg_idx 8 hash 0x2ffeb518 page 0x29808000
D/TC:0 0 init_runtime:473 hash pg_idx 9 hash 0x2ffeb538 page 0x29809000
D/TC:0 0 init_runtime:473 hash pg_idx 10 hash 0x2ffeb558 page 0x2980a000
D/TC:0 0 init_runtime:473 hash pg_idx 11 hash 0x2ffeb578 page 0x2980b000
D/TC:0 0 init_runtime:473 hash pg_idx 12 hash 0x2ffeb598 page 0x2980c000
D/TC:0 0 init_runtime:473 hash pg_idx 13 hash 0x2ffeb5b8 page 0x2980d000
D/TC:0 0 init_runtime:473 hash pg_idx 14 hash 0x2ffeb5d8 page 0x2980e000
D/TC:0 0 init_runtime:473 hash pg_idx 15 hash 0x2ffeb5f8 page 0x2980f000
D/TC:0 0 init_runtime:473 hash pg_idx 16 hash 0x2ffeb618 page 0x29810000
D/TC:0 0 init_runtime:473 hash pg_idx 17 hash 0x2ffeb638 page 0x29811000
D/TC:0 0 init_runtime:473 hash pg_idx 18 hash 0x2ffeb658 page 0x29812000
D/TC:0 0 init_runtime:473 hash pg_idx 19 hash 0x2ffeb678 page 0x29813000
D/TC:0 0 init_runtime:473 hash pg_idx 20 hash 0x2ffeb698 page 0x29814000
D/TC:0 0 init_runtime:473 hash pg_idx 21 hash 0x2ffeb6b8 page 0x29815000
D/TC:0 0 init_runtime:473 hash pg_idx 22 hash 0x2ffeb6d8 page 0x29816000
D/TC:0 0 init_runtime:473 hash pg_idx 23 hash 0x2ffeb6f8 page 0x29817000
D/TC:0 0 init_runtime:473 hash pg_idx 24 hash 0x2ffeb718 page 0x29818000
D/TC:0 0 init_runtime:473 hash pg_idx 25 hash 0x2ffeb738 page 0x29819000
D/TC:0 0 init_runtime:473 hash pg_idx 26 hash 0x2ffeb758 page 0x2981a000
D/TC:0 0 init_runtime:473 hash pg_idx 27 hash 0x2ffeb778 page 0x2981b000
D/TC:0 0 init_runtime:473 hash pg_idx 28 hash 0x2ffeb798 page 0x2981c000
D/TC:0 0 init_runtime:473 hash pg_idx 29 hash 0x2ffeb7b8 page 0x2981d000
D/TC:0 0 init_runtime:473 hash pg_idx 30 hash 0x2ffeb7d8 page 0x2981e000
D/TC:0 0 init_runtime:473 hash pg_idx 31 hash 0x2ffeb7f8 page 0x2981f000
D/TC:0 0 init_runtime:473 hash pg_idx 32 hash 0x2ffeb818 page 0x29820000
D/TC:0 0 init_runtime:473 hash pg_idx 33 hash 0x2ffeb838 page 0x29821000
D/TC:0 0 init_runtime:473 hash pg_idx 34 hash 0x2ffeb858 page 0x29822000
D/TC:0 0 init_runtime:473 hash pg_idx 35 hash 0x2ffeb878 page 0x29823000
D/TC:0 0 init_runtime:473 hash pg_idx 36 hash 0x2ffeb898 page 0x29824000
D/TC:0 0 init_runtime:473 hash pg_idx 37 hash 0x2ffeb8b8 page 0x29825000
D/TC:0 0 init_runtime:473 hash pg_idx 38 hash 0x2ffeb8d8 page 0x29826000
D/TC:0 0 init_runtime:473 hash pg_idx 39 hash 0x2ffeb8f8 page 0x29827000
D/TC:0 0 init_runtime:473 hash pg_idx 40 hash 0x2ffeb918 page 0x29828000
D/TC:0 0 init_runtime:473 hash pg_idx 41 hash 0x2ffeb938 page 0x29829000
D/TC:0 0 init_runtime:473 hash pg_idx 42 hash 0x2ffeb958 page 0x2982a000
D/TC:0 0 init_runtime:473 hash pg_idx 43 hash 0x2ffeb978 page 0x2982b000
D/TC:0 0 init_runtime:473 hash pg_idx 44 hash 0x2ffeb998 page 0x2982c000
D/TC:0 0 init_runtime:473 hash pg_idx 45 hash 0x2ffeb9b8 page 0x2982d000
D/TC:0 0 init_runtime:473 hash pg_idx 46 hash 0x2ffeb9d8 page 0x2982e000
D/TC:0 0 init_runtime:473 hash pg_idx 47 hash 0x2ffeb9f8 page 0x2982f000
D/TC:0 0 init_runtime:473 hash pg_idx 48 hash 0x2ffeba18 page 0x29830000
D/TC:0 0 init_runtime:473 hash pg_idx 49 hash 0x2ffeba38 page 0x29831000
D/TC:0 0 init_runtime:473 hash pg_idx 50 hash 0x2ffeba58 page 0x29832000
D/TC:0 0 init_runtime:473 hash pg_idx 51 hash 0x2ffeba78 page 0x29833000
D/TC:0 0 init_runtime:473 hash pg_idx 52 hash 0x2ffeba98 page 0x29834000
D/TC:0 0 init_runtime:473 hash pg_idx 53 hash 0x2ffebab8 page 0x29835000
D/TC:0 0 init_runtime:473 hash pg_idx 54 hash 0x2ffebad8 page 0x29836000
D/TC:0 0 init_runtime:473 hash pg_idx 55 hash 0x2ffebaf8 page 0x29837000
D/TC:0 0 init_runtime:473 hash pg_idx 56 hash 0x2ffebb18 page 0x29838000
D/TC:0 0 init_runtime:473 hash pg_idx 57 hash 0x2ffebb38 page 0x29839000
D/TC:0 0 init_runtime:473 hash pg_idx 58 hash 0x2ffebb58 page 0x2983a000
D/TC:0 0 init_runtime:473 hash pg_idx 59 hash 0x2ffebb78 page 0x2983b000
D/TC:0 0 init_runtime:473 hash pg_idx 60 hash 0x2ffebb98 page 0x2983c000
D/TC:0 0 init_runtime:473 hash pg_idx 61 hash 0x2ffebbb8 page 0x2983d000
D/TC:0 0 init_runtime:473 hash pg_idx 62 hash 0x2ffebbd8 page 0x2983e000
D/TC:0 0 init_runtime:473 hash pg_idx 63 hash 0x2ffebbf8 page 0x2983f000
D/TC:0 0 init_runtime:473 hash pg_idx 64 hash 0x2ffebc18 page 0x29840000
D/TC:0 0 init_runtime:473 hash pg_idx 65 hash 0x2ffebc38 page 0x29841000
D/TC:0 0 init_runtime:473 hash pg_idx 66 hash 0x2ffebc58 page 0x29842000
D/TC:0 0 init_runtime:473 hash pg_idx 67 hash 0x2ffebc78 page 0x29843000
D/TC:0 0 init_runtime:473 hash pg_idx 68 hash 0x2ffebc98 page 0x29844000
D/TC:0 0 init_runtime:473 hash pg_idx 69 hash 0x2ffebcb8 page 0x29845000
D/TC:0 0 init_runtime:473 hash pg_idx 70 hash 0x2ffebcd8 page 0x29846000
D/TC:0 0 init_runtime:473 hash pg_idx 71 hash 0x2ffebcf8 page 0x29847000
D/TC:0 0 init_runtime:473 hash pg_idx 72 hash 0x2ffebd18 page 0x29848000
D/TC:0 0 init_runtime:473 hash pg_idx 73 hash 0x2ffebd38 page 0x29849000
D/TC:0 0 init_runtime:473 hash pg_idx 74 hash 0x2ffebd58 page 0x2984a000
D/TC:0 0 init_runtime:473 hash pg_idx 75 hash 0x2ffebd78 page 0x2984b000
D/TC:0 0 init_runtime:473 hash pg_idx 76 hash 0x2ffebd98 page 0x2984c000
D/TC:0 0 init_runtime:473 hash pg_idx 77 hash 0x2ffebdb8 page 0x2984d000
D/TC:0 0 init_runtime:473 hash pg_idx 78 hash 0x2ffebdd8 page 0x2984e000
D/TC:0 0 init_runtime:473 hash pg_idx 79 hash 0x2ffebdf8 page 0x2984f000
D/TC:0 0 init_runtime:473 hash pg_idx 80 hash 0x2ffebe18 page 0x29850000
D/TC:0 0 init_runtime:473 hash pg_idx 81 hash 0x2ffebe38 page 0x29851000
D/TC:0 0 init_runtime:473 hash pg_idx 82 hash 0x2ffebe58 page 0x29852000
D/TC:0 0 init_runtime:473 hash pg_idx 83 hash 0x2ffebe78 page 0x29853000
D/TC:0 0 init_runtime:473 hash pg_idx 84 hash 0x2ffebe98 page 0x29854000
D/TC:0 0 init_runtime:473 hash pg_idx 85 hash 0x2ffebeb8 page 0x29855000
D/TC:0 0 init_runtime:473 hash pg_idx 86 hash 0x2ffebed8 page 0x29856000
D/TC:0 0 init_runtime:473 hash pg_idx 87 hash 0x2ffebef8 page 0x29857000
D/TC:0 0 init_runtime:473 hash pg_idx 88 hash 0x2ffebf18 page 0x29858000
D/TC:0 0 init_runtime:473 hash pg_idx 89 hash 0x2ffebf38 page 0x29859000
D/TC:0 0 init_runtime:473 hash pg_idx 90 hash 0x2ffebf58 page 0x2985a000
D/TC:0 0 init_runtime:473 hash pg_idx 91 hash 0x2ffebf78 page 0x2985b000
D/TC:0 0 init_runtime:473 hash pg_idx 92 hash 0x2ffebf98 page 0x2985c000
D/TC:0 0 init_runtime:473 hash pg_idx 93 hash 0x2ffebfb8 page 0x2985d000
D/TC:0 0 init_runtime:473 hash pg_idx 94 hash 0x2ffebfd8 page 0x2985e000
D/TC:0 0 tee_pager_set_alias_area:388 0x30120000 - 0x301c0000
D/TC:0 0 tee_pager_add_core_region:633 0x2ffec000 - 0x3004b000 : type 0
D/TC:0 0 tee_pager_add_pages:1830 0x2ffec000 - 0x2ffef000 : 0
D/TC:0 0 pager_add_alias_page:572 0x2ffec000
D/TC:0 0 pager_add_alias_page:572 0x2ffed000
D/TC:0 0 pager_add_alias_page:572 0x2ffee000
D/TC:0 0 tee_pager_add_pages:1830 0x2ffef000 - 0x3004b000 : 1
D/TC:0 0 pager_add_alias_page:572 0x2ffef000
D/TC:0 0 pager_add_alias_page:572 0x2fff0000
D/TC:0 0 pager_add_alias_page:572 0x2fff1000
D/TC:0 0 pager_add_alias_page:572 0x2fff2000
D/TC:0 0 pager_add_alias_page:572 0x2fff3000
D/TC:0 0 pager_add_alias_page:572 0x2fff4000
D/TC:0 0 pager_add_alias_page:572 0x2fff5000
D/TC:0 0 pager_add_alias_page:572 0x2fff6000
D/TC:0 0 pager_add_alias_page:572 0x2fff7000
D/TC:0 0 pager_add_alias_page:572 0x2fff8000
D/TC:0 0 pager_add_alias_page:572 0x2fff9000
D/TC:0 0 pager_add_alias_page:572 0x2fffa000
D/TC:0 0 pager_add_alias_page:572 0x2fffb000
D/TC:0 0 pager_add_alias_page:572 0x2fffc000
D/TC:0 0 pager_add_alias_page:572 0x2fffd000
D/TC:0 0 pager_add_alias_page:572 0x2fffe000
D/TC:0 0 pager_add_alias_page:572 0x2ffff000
D/TC:0 0 pager_add_alias_page:572 0x30000000
D/TC:0 0 pager_add_alias_page:572 0x30001000
D/TC:0 0 pager_add_alias_page:572 0x30002000
D/TC:0 0 pager_add_alias_page:572 0x30003000
D/TC:0 0 pager_add_alias_page:572 0x30004000
D/TC:0 0 pager_add_alias_page:572 0x30005000
D/TC:0 0 pager_add_alias_page:572 0x30006000
D/TC:0 0 pager_add_alias_page:572 0x30007000
D/TC:0 0 pager_add_alias_page:572 0x30008000
D/TC:0 0 pager_add_alias_page:572 0x30009000
D/TC:0 0 pager_add_alias_page:572 0x3000a000
D/TC:0 0 pager_add_alias_page:572 0x3000b000
D/TC:0 0 pager_add_alias_page:572 0x3000c000
D/TC:0 0 pager_add_alias_page:572 0x3000d000
D/TC:0 0 pager_add_alias_page:572 0x3000e000
D/TC:0 0 pager_add_alias_page:572 0x3000f000
D/TC:0 0 pager_add_alias_page:572 0x30010000
D/TC:0 0 pager_add_alias_page:572 0x30011000
D/TC:0 0 pager_add_alias_page:572 0x30012000
D/TC:0 0 pager_add_alias_page:572 0x30013000
D/TC:0 0 pager_add_alias_page:572 0x30014000
D/TC:0 0 pager_add_alias_page:572 0x30015000
D/TC:0 0 pager_add_alias_page:572 0x30016000
D/TC:0 0 pager_add_alias_page:572 0x30017000
D/TC:0 0 pager_add_alias_page:572 0x30018000
D/TC:0 0 pager_add_alias_page:572 0x30019000
D/TC:0 0 pager_add_alias_page:572 0x3001a000
D/TC:0 0 pager_add_alias_page:572 0x3001b000
D/TC:0 0 pager_add_alias_page:572 0x3001c000
D/TC:0 0 pager_add_alias_page:572 0x3001d000
D/TC:0 0 pager_add_alias_page:572 0x3001e000
D/TC:0 0 pager_add_alias_page:572 0x3001f000
D/TC:0 0 pager_add_alias_page:572 0x30020000
D/TC:0 0 pager_add_alias_page:572 0x30021000
D/TC:0 0 pager_add_alias_page:572 0x30022000
D/TC:0 0 pager_add_alias_page:572 0x30023000
D/TC:0 0 pager_add_alias_page:572 0x30024000
D/TC:0 0 pager_add_alias_page:572 0x30025000
D/TC:0 0 pager_add_alias_page:572 0x30026000
D/TC:0 0 pager_add_alias_page:572 0x30027000
D/TC:0 0 pager_add_alias_page:572 0x30028000
D/TC:0 0 pager_add_alias_page:572 0x30029000
D/TC:0 0 pager_add_alias_page:572 0x3002a000
D/TC:0 0 pager_add_alias_page:572 0x3002b000
D/TC:0 0 pager_add_alias_page:572 0x3002c000
D/TC:0 0 pager_add_alias_page:572 0x3002d000
D/TC:0 0 pager_add_alias_page:572 0x3002e000
D/TC:0 0 pager_add_alias_page:572 0x3002f000
D/TC:0 0 pager_add_alias_page:572 0x30030000
D/TC:0 0 pager_add_alias_page:572 0x30031000
D/TC:0 0 pager_add_alias_page:572 0x30032000
D/TC:0 0 pager_add_alias_page:572 0x30033000
D/TC:0 0 pager_add_alias_page:572 0x30034000
D/TC:0 0 pager_add_alias_page:572 0x30035000
D/TC:0 0 pager_add_alias_page:572 0x30036000
D/TC:0 0 pager_add_alias_page:572 0x30037000
D/TC:0 0 pager_add_alias_page:572 0x30038000
D/TC:0 0 pager_add_alias_page:572 0x30039000
D/TC:0 0 pager_add_alias_page:572 0x3003a000
D/TC:0 0 pager_add_alias_page:572 0x3003b000
D/TC:0 0 pager_add_alias_page:572 0x3003c000
D/TC:0 0 pager_add_alias_page:572 0x3003d000
D/TC:0 0 pager_add_alias_page:572 0x3003e000
D/TC:0 0 pager_add_alias_page:572 0x3003f000
D/TC:0 0 pager_add_alias_page:572 0x30040000
D/TC:0 0 pager_add_alias_page:572 0x30041000
D/TC:0 0 pager_add_alias_page:572 0x30042000
D/TC:0 0 pager_add_alias_page:572 0x30043000
D/TC:0 0 pager_add_alias_page:572 0x30044000
D/TC:0 0 pager_add_alias_page:572 0x30045000
D/TC:0 0 pager_add_alias_page:572 0x30046000
D/TC:0 0 pager_add_alias_page:572 0x30047000
D/TC:0 0 pager_add_alias_page:572 0x30048000
D/TC:0 0 pager_add_alias_page:572 0x30049000
D/TC:0 0 pager_add_alias_page:572 0x3004a000
D/TC:0 0 tee_pager_add_pages:1830 0x3004b000 - 0x30060000 : 1
D/TC:0 0 pager_add_alias_page:572 0x3004b000
D/TC:0 0 pager_add_alias_page:572 0x3004c000
D/TC:0 0 pager_add_alias_page:572 0x3004d000
D/TC:0 0 pager_add_alias_page:572 0x3004e000
D/TC:0 0 pager_add_alias_page:572 0x3004f000
D/TC:0 0 pager_add_alias_page:572 0x30050000
D/TC:0 0 pager_add_alias_page:572 0x30051000
D/TC:0 0 pager_add_alias_page:572 0x30052000
D/TC:0 0 pager_add_alias_page:572 0x30053000
D/TC:0 0 pager_add_alias_page:572 0x30054000
D/TC:0 0 pager_add_alias_page:572 0x30055000
D/TC:0 0 pager_add_alias_page:572 0x30056000
D/TC:0 0 pager_add_alias_page:572 0x30057000
D/TC:0 0 pager_add_alias_page:572 0x30058000
D/TC:0 0 pager_add_alias_page:572 0x30059000
D/TC:0 0 pager_add_alias_page:572 0x3005a000
D/TC:0 0 pager_add_alias_page:572 0x3005b000
D/TC:0 0 pager_add_alias_page:572 0x3005c000
D/TC:0 0 pager_add_alias_page:572 0x3005d000
D/TC:0 0 pager_add_alias_page:572 0x3005e000
D/TC:0 0 pager_add_alias_page:572 0x3005f000
D/TC:0 0 tee_pager_add_pages:1830 0x2ffc0000 - 0x2ffc0000 : 1
I/TC: Pager pool size: 460kB
D/TC:0 0 tee_pager_add_pages:1830 0x3004b000 - 0x3004e000 : 1
D/TC:0 0 tee_pager_add_core_region:633 0x3004c000 - 0x3004e000 : type 2
D/TC:0 0 tee_pager_add_pages:1830 0x3004e000 - 0x30051000 : 1
D/TC:0 0 tee_pager_add_core_region:633 0x3004f000 - 0x30051000 : type 2
D/TC:0 0 tee_pager_add_pages:1830 0x30051000 - 0x30054000 : 1
D/TC:0 0 tee_pager_add_core_region:633 0x30052000 - 0x30054000 : type 2
D/TC:0 0 tee_pager_add_core_region:633 0x30054000 - 0x30055000 : type 2
D/TC:0 0 tee_pager_add_core_region:633 0x30055000 - 0x30056000 : type 2
D/TC:0 0 tee_pager_add_core_region:633 0x30056000 - 0x30057000 : type 2
D/TC:0 0 tee_pager_add_core_region:633 0x30057000 - 0x30058000 : type 2
D/TC:0 0 tee_pager_add_core_region:633 0x30058000 - 0x30059000 : type 2
D/TC:0 0 tee_pager_add_core_region:633 0x30059000 - 0x3005a000 : type 2
I/TC: Non-secure external DT found
D/TC:0 0 discover_nsec_memory:1185 No non-secure memory found in FDT
D/TC:0 0 carve_out_phys_mem:300 No need to carve out 0x2ffc0000 size 0xa0000
D/TC:0 0 add_optee_dt_node:710 OP-TEE Device Tree node already exists!
I/TC: Embedded DTB found
I/TC: OP-TEE version: upstream/tag/3.16.0-stm32mp-r1-33-g7da557d01-dev (gcc version 11.3.0 (Ubuntu 11.3.0-6ubuntu1)) #1 Sa 22. Apr 09:14:03 UTC 2023 arm
I/TC: Yep, this is definitely the correct build.
I/TC: WARNING: This OP-TEE configuration might be insecure!
I/TC: WARNING: Please check https://optee.readthedocs.io/en/latest/architecture/porting_guidelines.html
I/TC: Primary CPU initializing
D/TC:0 0 call_preinitcalls:21 level 2 mobj_mapped_shm_init()
D/TC:0 0 mobj_mapped_shm_init:463 Shared memory address range: 2dc00000, 2fc00000
D/TC:0 0 call_initcalls:40 level 1 register_time_source()
D/TC:0 0 call_initcalls:40 level 1 teecore_init_pub_ram()
D/TC:0 0 call_initcalls:40 level 1 initialize_bsec()
D/TC:0 0 save_dt_nvmem_layout:860 nvmem[1] = cfg0_otp 0 8
D/TC:0 0 save_dt_nvmem_layout:860 nvmem[2] = part_number_otp 1 8
D/TC:0 0 save_dt_nvmem_layout:860 nvmem[3] = monotonic_otp 4 32
D/TC:0 0 save_dt_nvmem_layout:860 nvmem[4] = nand_otp 9 32
D/TC:0 0 save_dt_nvmem_layout:860 nvmem[5] = uid_otp 13 96
D/TC:0 0 save_dt_nvmem_layout:860 nvmem[6] = package_otp 16 32
D/TC:0 0 save_dt_nvmem_layout:860 nvmem[7] = hw2_otp 18 32
D/TC:0 0 save_dt_nvmem_layout:860 nvmem[8] = calib 23 16
D/TC:0 0 save_dt_nvmem_layout:844 Misaligned nvmem calib@5e: ignored
D/TC:0 0 save_dt_nvmem_layout:860 nvmem[9] = pkh_otp 24 256
D/TC:0 0 save_dt_nvmem_layout:860 nvmem[10] = mac 57 64
D/TC:0 0 save_dt_nvmem_layout:860 nvmem[11] = board_id 59 32
D/TC:0 0 call_initcalls:40 level 1 clk_dt_probe()
D/TC:0 0 clk_dt_probe:201 Probing clocks from devicetree
D/TC:0 0 get_osc_freq_from_dt:1436 Osc clk-hsi: 64000000 Hz
D/TC:0 0 get_osc_freq_from_dt:1436 Osc clk-hse: 24000000 Hz
D/TC:0 0 get_osc_freq_from_dt:1436 Osc clk-csi: 4000000 Hz
D/TC:0 0 get_osc_freq_from_dt:1436 Osc clk-lsi: 32000 Hz
D/TC:0 0 get_osc_freq_from_dt:1436 Osc clk-lse: 32768 Hz
D/TC:0 0 get_osc_freq_from_dt:1442 Osc i2s_ckin: no frequency info
D/TC:0 0 get_osc_freq_from_dt:1442 Osc ck_usbo_48m: no frequency info
D/TC:0 0 stm32mp1_clk_fdt_init:1475 Ignore source clocks configuration from DT
D/TC:0 0 stm32mp1_clk_fdt_init:1479 Ignore clock divisors configuration from DT
D/TC:0 0 stm32mp1_clk_fdt_init:1483 Ignore peripheral clocks tree configuration from DT
D/TC:0 0 stm32mp1_clk_fdt_init:1497 Ignore PLL0 configurations from DT
D/TC:0 0 stm32mp1_clk_fdt_init:1497 Ignore PLL1 configurations from DT
D/TC:0 0 stm32mp1_clk_fdt_init:1497 Ignore PLL2 configurations from DT
D/TC:0 0 stm32mp1_clk_fdt_init:1497 Ignore PLL3 configurations from DT
I/TC: DT clock tree configurations were ignored
D/TC:0 0 clk_register:108 Registered clock (null), freq 266500000
D/TC:0 0 clk_register:108 Registered clock (null), freq 266500000
D/TC:0 0 clk_register:108 Registered clock (null), freq 266500000
D/TC:0 0 clk_register:108 Registered clock (null), freq 266500000
D/TC:0 0 clk_register:108 Registered clock (null), freq 533000000
D/TC:0 0 clk_register:108 Registered clock (null), freq 533000000
D/TC:0 0 clk_register:108 Registered clock (null), freq 133250000
D/TC:0 0 clk_register:108 Registered clock (null), freq 133250000
D/TC:0 0 clk_register:108 Registered clock (null), freq 266500000
D/TC:0 0 clk_register:108 Registered clock (null), freq 133250000
D/TC:0 0 clk_register:108 Registered clock (null), freq 133250000
D/TC:0 0 clk_register:108 Registered clock spi6, freq 64000000
D/TC:0 0 clk_register:108 Registered clock i2c4, freq 64000000
D/TC:0 0 clk_register:108 Registered clock i2c6, freq 64000000
D/TC:0 0 clk_register:108 Registered clock usart1, freq 64000000
D/TC:0 0 clk_register:108 Registered clock rtcapb, freq 66625000
D/TC:0 0 clk_register:108 Registered clock (null), freq 66625000
D/TC:0 0 clk_register:108 Registered clock (null), freq 66625000
D/TC:0 0 clk_register:108 Registered clock (null), freq 66625000
D/TC:0 0 clk_register:108 Registered clock iwdg, freq 66625000
D/TC:0 0 clk_register:108 Registered clock (null), freq 66625000
D/TC:0 0 clk_register:108 Registered clock (null), freq 24000000
D/TC:0 0 clk_register:108 Registered clock gpioz, freq 266500000
D/TC:0 0 clk_register:108 Registered clock crpy1, freq 266500000
D/TC:0 0 clk_register:108 Registered clock hash1, freq 266500000
D/TC:0 0 clk_register:108 Registered clock rng1, freq 32000
D/TC:0 0 clk_register:108 Registered clock bkpsram, freq 266500000
D/TC:0 0 clk_register:108 Registered clock (null), freq 266500000
D/TC:0 0 clk_register:108 Registered clock rtc, freq 32768
D/TC:0 0 clk_register:108 Registered clock gpioa, freq 0
D/TC:0 0 clk_register:108 Registered clock gpiob, freq 0
D/TC:0 0 clk_register:108 Registered clock gpioc, freq 0
D/TC:0 0 clk_register:108 Registered clock gpiod, freq 0
D/TC:0 0 clk_register:108 Registered clock gpioe, freq 0
D/TC:0 0 clk_register:108 Registered clock gpiof, freq 0
D/TC:0 0 clk_register:108 Registered clock gpiog, freq 0
D/TC:0 0 clk_register:108 Registered clock gpioh, freq 0
D/TC:0 0 clk_register:108 Registered clock gpioi, freq 0
D/TC:0 0 clk_register:108 Registered clock gpioj, freq 0
D/TC:0 0 clk_register:108 Registered clock gpiok, freq 0
D/TC:0 0 clk_register:108 Registered clock (null), freq 208877928
D/TC:0 0 clk_register:108 Registered clock (null), freq 24000000
D/TC:0 0 clk_register:108 Registered clock (null), freq 24000000
D/TC:0 0 clk_register:108 Registered clock (null), freq 24000000
D/TC:0 0 clk_register:108 Registered clock (null), freq 24000000
D/TC:0 0 clk_register:108 Registered clock (null), freq 24000000
D/TC:0 0 clk_register:108 Registered clock (null), freq 24000000
D/TC:0 0 clk_register:108 Registered clock (null), freq 208877928
D/TC:0 0 clk_register:108 Registered clock (null), freq 24000000
D/TC:0 0 clk_register:108 Registered clock syscfg, freq 0
D/TC:0 0 clk_register:108 Registered clock (null), freq 0
D/TC:0 0 clk_register:108 Registered clock (null), freq 0
D/TC:0 0 clk_register:108 Registered clock dbg, freq 0
D/TC:0 0 clk_register:108 Registered clock hse, freq 24000000
D/TC:0 0 clk_register:108 Registered clock csi, freq 4000000
D/TC:0 0 clk_register:108 Registered clock lsi, freq 32000
D/TC:0 0 clk_register:108 Registered clock lse, freq 32768
D/TC:0 0 clk_register:108 Registered clock hsi, freq 64000000
D/TC:0 0 clk_register:108 Registered clock (null), freq 12000000
D/TC:0 0 clk_register:108 Registered clock (null), freq 650000000
D/TC:0 0 clk_register:108 Registered clock (null), freq 650000000
D/TC:0 0 clk_register:108 Registered clock (null), freq 650000000
D/TC:0 0 clk_register:108 Registered clock (null), freq 266500000
D/TC:0 0 clk_register:108 Registered clock pll2q, freq 533000000
D/TC:0 0 clk_register:108 Registered clock pll2r, freq 533000000
D/TC:0 0 clk_register:108 Registered clock (null), freq 208877929
D/TC:0 0 clk_register:108 Registered clock pll3q, freq 24573874
D/TC:0 0 clk_register:108 Registered clock pll3r, freq 11290698
D/TC:0 0 clk_register:108 Registered clock (null), freq 266500000
D/TC:0 0 clk_register:108 Registered clock (null), freq 650000000
D/TC:0 0 clk_register:108 Registered clock mcu, freq 208877929
D/TC:0 0 probe_driver_node:378 element: stm32mp1_clock on node rcc@50000000 initialized
D/TC:0 0 call_initcalls:40 level 2 init_debug()
D/TC:0 0 stm32_bsec_find_otp_in_nvmem_layout:655 nvmem cfg0_otp = 0: 0 8
D/TC:0 0 call_initcalls:40 level 2 probe_dt_drivers_early()
D/TC:0 0 add_node_to_probe:573 element: cpu0-opp-table on node stm32mp1-cpu-opp
D/TC:0 0 add_node_to_probe:573 element: soc on node simple-bus
D/TC:0 0 add_node_to_probe:573 element: vin on node fixed-regulator
D/TC:0 0 probe_driver_node:378 element: fixed-regulator on node vin initialized
D/TC:0 0 add_node_to_probe:573 element: timer@44006000 on node stm32-timer
D/TC:0 0 add_node_to_probe:573 element: pwr@50001000 on node stm32mp1-pwr-regu
D/TC:0 0 add_node_to_probe:573 element: watchdog@5a002000 on node stm32-iwdg
D/TC:0 0 add_node_to_probe:573 element: rtc@5c004000 on node stm32-rtc
D/TC:0 0 add_node_to_probe:573 element: tamp@5c00a000 on node stm32-tamp
D/TC:0 0 add_node_to_probe:573 element: tzc@5c006000 on node stm32mp1-tzc400
D/TC:0 0 add_node_to_probe:573 element: pin-controller@50002000 on node stm32_gpio
D/TC:0 0 add_node_to_probe:573 element: pin-controller-z@54004000 on node stm32_gpio
D/TC:0 0 probe_driver_node:378 element: simple-bus on node soc initialized
D/TC:0 0 regulator_get_by_phandle:54 phandle 4 not found
D/TC:0 0 probe_driver_node:384 element: stm32mp1-cpu-opp on node cpu0-opp-table deferred 1 time(s)
D/TC:0 0 regulator_get_by_phandle:54 phandle 4 not found
D/TC:0 0 probe_driver_node:384 element: stm32mp1-cpu-opp on node cpu0-opp-table deferred 2 time(s)
D/TC:0 0 _fdt_stm32_gpio_controller:697 Bank name gpio@54004000
D/TC:0 0 _fdt_stm32_gpio_controller:717 GPIO bank Z assigned to non-secure
D/TC:0 0 stm32_gpio_probe:903 Registered GPIO bank Z (8 pins) @2c404000
D/TC:0 0 probe_driver_node:378 element: stm32_gpio on node pin-controller-z@54004000 initialized
D/TC:0 0 _fdt_stm32_gpio_controller:697 Bank name gpio@50002000
D/TC:0 0 _fdt_stm32_gpio_controller:697 Bank name gpio@50003000
D/TC:0 0 _fdt_stm32_gpio_controller:697 Bank name gpio@50004000
D/TC:0 0 _fdt_stm32_gpio_controller:697 Bank name gpio@50005000
D/TC:0 0 _fdt_stm32_gpio_controller:697 Bank name gpio@50006000
D/TC:0 0 _fdt_stm32_gpio_controller:697 Bank name gpio@50007000
D/TC:0 0 _fdt_stm32_gpio_controller:697 Bank name gpio@50008000
D/TC:0 0 _fdt_stm32_gpio_controller:697 Bank name gpio@50009000
D/TC:0 0 _fdt_stm32_gpio_controller:697 Bank name gpio@5000a000
D/TC:0 0 stm32_gpio_probe:903 Registered GPIO bank Z (8 pins) @2c404000
D/TC:0 0 stm32_gpio_probe:903 Registered GPIO bank A (16 pins) @2c802000
D/TC:0 0 stm32_gpio_probe:903 Registered GPIO bank B (16 pins) @2c803000
D/TC:0 0 stm32_gpio_probe:903 Registered GPIO bank C (16 pins) @2c804000
D/TC:0 0 stm32_gpio_probe:903 Registered GPIO bank D (16 pins) @2c805000
D/TC:0 0 stm32_gpio_probe:903 Registered GPIO bank E (16 pins) @2c806000
D/TC:0 0 stm32_gpio_probe:903 Registered GPIO bank F (16 pins) @2c807000
D/TC:0 0 stm32_gpio_probe:903 Registered GPIO bank G (16 pins) @2c808000
D/TC:0 0 stm32_gpio_probe:903 Registered GPIO bank H (16 pins) @2c809000
D/TC:0 0 stm32_gpio_probe:903 Registered GPIO bank I (12 pins) @2c80a000
D/TC:0 0 probe_driver_node:378 element: stm32_gpio on node pin-controller@50002000 initialized
D/TC:0 0 tzc_set_driverdata:113 TZC400 Filters 2 Regions 8
D/TC:0 0 stm32mp1_tzc_probe:482 0x0xc0000000 - 0x0xddffffff : Sec access 0 NS access 0x87fb87fb
D/TC:0 0 tzc_dump_state:473 region 0
D/TC:0 0 tzc_dump_state:476 region_base: 0x0000000000000000
D/TC:0 0 tzc_dump_state:479 region_top: 0x00000000ffffffff
D/TC:0 0 tzc_dump_state:481 secure rw: TZC_REGION_S_NONE
D/TC:0 0 tzc_dump_state:486 filter 0 enable
D/TC:0 0 tzc_dump_state:486 filter 1 enable
D/TC:0 0 tzc_dump_state:473 region 1
D/TC:0 0 tzc_dump_state:476 region_base: 0x00000000de200000
D/TC:0 0 tzc_dump_state:479 region_top: 0x00000000dfffffff
D/TC:0 0 tzc_dump_state:481 secure rw: TZC_REGION_S_RDWR
D/TC:0 0 tzc_dump_state:486 filter 0 enable
D/TC:0 0 tzc_dump_state:486 filter 1 enable
D/TC:0 0 tzc_dump_state:473 region 2
D/TC:0 0 tzc_dump_state:476 region_base: 0x00000000de000000
D/TC:0 0 tzc_dump_state:479 region_top: 0x00000000de1fffff
D/TC:0 0 tzc_dump_state:481 secure rw: TZC_REGION_S_NONE
D/TC:0 0 tzc_dump_state:486 filter 0 enable
D/TC:0 0 tzc_dump_state:486 filter 1 enable
D/TC:0 0 tzc_dump_state:473 region 3
D/TC:0 0 tzc_dump_state:476 region_base: 0x00000000c0000000
D/TC:0 0 tzc_dump_state:479 region_top: 0x00000000ddffffff
D/TC:0 0 tzc_dump_state:481 secure rw: TZC_REGION_S_NONE
D/TC:0 0 tzc_dump_state:486 filter 0 enable
D/TC:0 0 tzc_dump_state:486 filter 1 enable
D/TC:0 0 gic_it_set_cpu_mask:330 cpu_mask: writing 0xff to 0x2ba21824
D/TC:0 0 gic_it_set_cpu_mask:332 cpu_mask: 0x3
D/TC:0 0 gic_it_set_prio:341 prio: writing 0x1 to 0x2ba21424
D/TC:0 0 probe_driver_node:378 element: stm32mp1-tzc400 on node tzc@5c006000 initialized
D/TC:0 0 stm32_tamp_parse_passive_conf:1083 Passive conf from dt: precharge=0, nb_sample=0, clk_div=32768
D/TC:0 0 stm32_tamp_parse_active_conf:1199 Active conf from dt: no filter clk_div=1
D/TC:0 0 gic_it_set_cpu_mask:330 cpu_mask: writing 0xff00 to 0x2ba218e4
D/TC:0 0 gic_it_set_cpu_mask:332 cpu_mask: 0x300
D/TC:0 0 gic_it_set_prio:341 prio: writing 0x1 to 0x2ba214e5
D/TC:0 0 probe_driver_node:378 element: stm32-tamp on node tamp@5c00a000 initialized
D/TC:0 0 probe_driver_node:378 element: stm32-rtc on node rtc@5c004000 initialized
D/TC:0 0 stm32mp_iwdg_iomem2instance:555 Base 5a002000
D/TC:0 0 stm32_bsec_find_otp_in_nvmem_layout:655 nvmem hw2_otp = 6: 18 32
D/TC:0 0 gic_it_set_cpu_mask:330 cpu_mask: writing 0xff000000 to 0x2ba218b4
D/TC:0 0 gic_it_set_cpu_mask:332 cpu_mask: 0x3000000
D/TC:0 0 gic_it_set_prio:341 prio: writing 0x1 to 0x2ba214b7
D/TC:0 0 probe_driver_node:378 element: stm32-iwdg on node watchdog@5a002000 initialized
D/TC:0 0 probe_driver_node:378 element: stm32mp1-pwr-regu on node pwr@50001000 initialized
D/TC:0 0 probe_driver_node:378 element: stm32-timer on node timer@44006000 initialized
D/TC:0 0 regulator_get_by_phandle:54 phandle 4 not found
D/TC:0 0 probe_driver_node:384 element: stm32mp1-cpu-opp on node cpu0-opp-table deferred 3 time(s)
D/TC:0 0 process_probe_list:522 Unresolved dependencies after 3 rounds, 3 deferred
D/TC:0 0 probe_dt_drivers_early:706 Deferred drivers probing
D/TC:0 0 print_probe_list:332 Probe list: 1 elements
D/TC:0 0 print_probe_list:334 |- Driver stm32mp1-cpu-opp probes on node cpu0-opp-table
D/TC:0 0 print_probe_list:338 `- Probe list end
D/TC:0 0 print_probe_list:344 Failed list: 0 elements
D/TC:0 0 print_probe_list:349 `- Failed list end
D/TC:0 0 call_initcalls:40 level 3 platform_banner()
I/TC: Platform stm32mp1: flavor PLATFORM_FLAVOR - DT stm32mp157c-jb0.dts
D/TC:0 0 call_initcalls:40 level 3 init_etzpc_from_dt()
D/TC:0 0 init_device_from_hw_config:306 ETZPC revison 0x0232, per_sec 96, ahb_sec 0, tzma 2
D/TC:0 0 call_initcalls:40 level 3 check_ta_store()
D/TC:0 0 check_ta_store:408 TA store: "early TA"
D/TC:0 0 check_ta_store:408 TA store: "Secure Storage TA"
D/TC:0 0 check_ta_store:408 TA store: "REE"
D/TC:0 0 call_initcalls:40 level 3 early_ta_init()
I/TC: Early TA f04a0fe7-1f5d-4b9b-abf7-619b85b4ce8c size 54984
D/TC:0 0 call_initcalls:40 level 3 verify_pseudo_tas_conformance()
D/TC:0 0 call_initcalls:40 level 3 mobj_init()
D/TC:0 0 call_initcalls:40 level 3 default_mobj_init()
D/TC:0 0 call_initcalls:40 level 3 tee_cryp_init()
D/TC:0 0 tee_pager_add_core_region:633 0x3005a000 - 0x30066000 : type 2
E/TC:0 0 tee_cryp_init:210 JOEDBG calling plat_rng_init from cryp_init
E/TC:0 0 plat_rng_init:273 JOEDBG plat_rng_init VA=0 PA=0
E/TC:0 0 plat_rng_init:276 WARNING RNG DISABLED
D/TC:0 0 call_initcalls:40 level 4 init_console_from_dt()
D/TC:0 0 register_periph_iomem:271 IO for non-secure resource 0x40010000
I/TC: DTB enables console (non-secure)
D/TC:0 0 call_initcalls:40 level 4 tee_fs_init_key_manager()
D/TC:0 0 call_initcalls:40 level 5 stm32mp1_iocomp()
D/TC:0 0 call_initcalls:40 level 5 init_pm_support()
D/TC:0 0 call_initcalls:40 level 5 probe_dt_drivers()
D/TC:0 0 regulator_get_by_phandle:54 phandle 4 not found
D/TC:0 0 probe_driver_node:384 element: stm32mp1-cpu-opp on node cpu0-opp-table deferred 4 time(s)
D/TC:0 0 process_probe_list:522 Unresolved dependencies after 4 rounds, 4 deferred
E/TC:0 0 probe_dt_drivers:727 Probe sequence result: 0x80000000
D/TC:0 0 print_probe_list:332 Probe list: 1 elements
D/TC:0 0 print_probe_list:334 |- Driver stm32mp1-cpu-opp probes on node cpu0-opp-table
D/TC:0 0 print_probe_list:338 `- Probe list end
D/TC:0 0 print_probe_list:344 Failed list: 0 elements
D/TC:0 0 print_probe_list:349 `- Failed list end
E/TC:0 0 Panic
D/TC:0 0 stm32_bsec_find_otp_in_nvmem_layout:655 nvmem part_number_otp = 1: 1 8

Note that "E/TC:0 0 plat_rng_init:276 WARNING RNG DISABLED" is where I simply replaced the panic() inside plat_rng_init() with EMSG to get it to continue booting, but that didn't really help.

johndoe31415 commented 1 year ago

Hello again @etienne-lms! I am incredibly happy to report success 🥳

While I did not have a lot of luck in backporting to 3.16 (ran into more and more issues, first with the RNG, then with the DTB/clocks/etc), backporting to 3.19 was super easy, I could essentially just do a few manual tweaks of your patch https://github.com/etienne-lms/optee_os/commits/stm32-wider-sram and it worked out of the box.

The results are amost a TENFOLD increase in performance. I can now perform a full TLS handshake with P-256 based client certificates (keys in OP-TEE) in roughly 650ms when it previously took 5 seconds. This added RAM is an absolute GAMECHANGER and makes deployment of OP-TEE viable.

I cannot stress enough how important this is for practical purposes. This is a super, super valuable patch. I really hope it makes it into an official patchset (be it vanilla OP-TEE or the STM fork), since I do believe many people would like to sacrifice one or two chunks of MCUSRAM for this kind of performance gain.

Thanks again for your incredible support and patience. I love learning more about these technical issues and it certainly has given me significantly more insight into how it all fits together. Have a great weekend!

ricardosalveti commented 1 year ago

Nice, great stuff, it would be definitely useful to have the option of using the extra sram via config options upstream (we do have customers that could take advantage of using it).

github-actions[bot] commented 1 year ago

This issue has been marked as a stale issue because it has been open (more than) 30 days with no activity. Remove the stale label or add a comment, otherwise this issue will automatically be closed in 5 days. Note, that you can always re-open a closed issue at any time.

etienne-lms commented 1 year ago

@johndoe31415, I've created https://github.com/OP-TEE/optee_os/pull/6086 to allow STM32MP15 OP-TEE pager to leverage SoC SRAMs.

ch-f commented 1 year ago

Great work! Thank you for sharing.

I'm facing a similar issue where a TLS connection takes way too long. However, I require the M4 firmware to remain operational for IPC mailbox data sharing with Linux and for controlling some I2C stuff.

So is it possible to allocate only SRAM3 and SRAM4 to OP-TEE?

By doing this, I hope to improve the TLS connection speed, even if just slightly (+128K RAM). What do you think?