OPTEE loading issue: optee_os not responding to SMCCC commands

[wangxiang-github]

Background

I've added a new platform Intel Stratix10 to OPTEE_OS which comes from Intel's socfpga chip. I would like to support OPTEE functionality based on this platform, ATF using Intel's official Intel platform repo(https://github.com/altera-opensource/arm-trusted-firmware/tree/socfpga_v2.7.0). I've implemented the intel platform configuration and releted files(e.g. main.c, conf.mk, platform_config.h, sub.mk) under the core/arch/arm/plat-intel folder. Then wait for the yocto to fininsh compiling, flash WIC file to the SD card, and boot it up with the following initialization process:

U-Boot SPL 2021.04-yocto-1.0 (Sep 02 2021 - 08:43:37 +0000)
Reset state: Cold
MPU         1200000 kHz
L3 main     400000 kHz
Main VCO    2400000 kHz
Per VCO     2000000 kHz
EOSC1       25000 kHz
HPS MMC     50000 kHz
UART        100000 kHz
DDR: Warning: DRAM size from device tree mismatch with hardware.
DDR: 1024 MiB
SDRAM-ECC: Initialized success with 322 ms
QSPI: Reference clock at 400000 kHz
board_init_r
spl_init
WDT:   Started with servicing (10s timeout)
Trying to boot from MMC1
get_aligned_image_size: filename=u-boot.itb
fit read sector 0, sectors=1500, dst=0x000000003fa006a0, count=1500, size=1500
arch/arm/mach-socfpga/board.c,board_fit_config_name_match: Intel SoC64 FPGA
Selecting config 'Intel SoC64 FPGA',node=1072
## Checking hash(es) for config conf ... OK
firmware: 'atf',node=328
load_addr=0x1000
get_aligned_image_size: filename=u-boot.itb
External data: dst=0x1000, offset=0x9c42c, size=0xf029
## Checking hash(es) for Image atf ... crc32+ OK
Image OS is ARM Trusted Firmware(os=25)
spl_load_simple_fit: firmware_node = 328
loadables: 'uboot',node=100
spl_load_simple_fit: index = 0 , node = 100
load_addr=0x200000
get_aligned_image_size: filename=u-boot.itb
External data: dst=0x200000, offset=0x5dc, size=0x9be50
## Checking hash(es) for Image uboot ... crc32+ OK
Loadable is 'U-Boot',os_type=17
fdt: 'fdt',node=848
spl_fit_append_fdt: node=848, load_addr=0x29be50
load_addr=0x29be50
get_aligned_image_size: filename=u-boot.itb
External data: dst=0x29be80, offset=0x148bc8, size=0x37cb
## Checking hash(es) for Image fdt ... crc32+ OK
loadables: 'uboot',node=100
loadables: 'optee',node=592
spl_load_simple_fit: index = 1 , node = 592
load_addr=0x3e000000
get_aligned_image_size: filename=u-boot.itb
External data: dst=0x3e000000, offset=0xab458, size=0x9d770
## Checking hash(es) for Image optee ... crc32+ OK
Loadable is 'Trusted Execution Environment',os_type=26
loadables: 'optee',node=592
spl_load_simple_fit: index = 2 , node = -7
Jumping to U-Boot via ARM Trusted Firmware
spl_invoke_atf: optee(bl32) node=136, entry point=0x3e000000
spl_invoke_atf: uboot(bl33) node=248, entry point=0x200000
NOTICE:  bl32:type=0x1,version=0x1,size=0x58,attr=0x0,pc=0x3e000000,spsr=0x3c5
NOTICE:  bl33:type=0x1,version=0x1,size=0x58,attr=0x1,pc=0x200000,spsr=0x3c9
NOTICE:  CurrentEl=0x3, MODE_EL=3
NOTICE:  sctlr_el=0xc5183a
NOTICE:  BL31: v2.7.0(debug):QPDS22.1STD_REL_GSRD_PR-dirty
NOTICE:  BL31: Built : 05:59:58, Oct 21 2022
INFO:    ARM GICv2 driver initialized
INFO:    BL31: Initializing runtime services
NOTICE:  bl31_plat_get_next_image_ep_info: type=0.[0-SECURE, 1-NON_SECURE]
NOTICE:  type=0x1, version=0x1, size=0x58, attr=0x0, pc=0x3e000000, spsr=0x3c5
NOTICE:  opteed_setup: opteed_rw=0x0, opteed_pageable_part=0x0, opteed_mem_limit=0x0,dt_addr=0x0
NOTICE:  opteed_init_optee_ep_state: arg0=0x0, arg1=0x0, arg2=0x0, spsr=0x3c5, pc=0x3e000000
WARNING: BL31: cortex_a53: CPU workaround for 855873 was missing!
WARNING: BL31: cortex_a53: CPU workaround for 1530924 was missing!
INFO:    BL31: Initializing BL32
NOTICE:  bl31_plat_get_next_image_ep_info: type=0.[0-SECURE, 1-NON_SECURE]
NOTICE:  type=0x1, version=0x1, size=0x58, attr=0x4, pc=0x3e000000, spsr=0x3c5
NOTICE:  opteed_init: pc=0x3e000000, spsr=0x3c5
I/TC:
I/TC: OP-TEE version: 3.16.0-36-g0398557f7-dev (gcc version 11.3.0 (GCC)) #1 Fri 13 Oct 2023 03:34:30 PM UTC aarch64
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
I/TC: CFG_TEE_CORE_NB_CORE = 4
I/TC: Primary CPU switching to normal world boot
NOTICE:  opteed_smc_handler:enter, is_caller_non_secure(flags=0x0)=0x0
NOTICE:  opteed_smc_handler:smc_fid = 0xbe000000
NOTICE:  opteed_smc_handler:x1=0x3e0018ac,x2=0x3e09c860,x3=0x8000000000,x4=0x3e0d0060
NOTICE:  TEESMC_OPTEED_RETURN_ENTRY_DONE
NOTICE:  opteed_smc_handler: x1=0x3e0018ac
NOTICE:  optee_vector_table(0x3e0018ac) is not NULL
NOTICE:  optee_entrypoint_test:ctx->state=1[0-OFF,1-ON]
NOTICE:  opteed_init_optee_ep_state: arg0=0x0, arg1=0x0, arg2=0x0, spsr=0x3c5, pc=0x3e0018b4
NOTICE:  optee_entrypoint_test:linear_id=0, optee_on_entrypoint.pc=0x3e0018b4, spsr=0x3c5
NOTICE:  first enter optee os finished!
NOTICE:  bl31_prepare_next_image_entry: image_type = 1[0-SECURE, 1-NON_SECURE]
NOTICE:  bl31_plat_get_next_image_ep_info: type=1.[0-SECURE, 1-NON_SECURE]
NOTICE:  type=0x1, version=0x1, size=0x58, attr=0x1, pc=0x200000, spsr=0x3c9
INFO:    BL31: Preparing for EL3 exit to normal world
INFO:    Entry point address = 0x200000
INFO:    SPSR = 0x3c9

U-Boot 2021.04-yocto-1.0(Sep 02 2021 - 08:43:37 +0000)

CPU:   Intel FPGA SoCFPGA Platform (ARMv8 64bit Cortex-A53)
Model: SoCFPGA SoCDK
DRAM:  1 GiB
WDT:   Started with servicing (10s timeout)
MMC:   dwmmc0@ff808000: 0
Loading Environment from MMC... *** Warning - bad CRC, using default environment

In:    serial1@ffc02100
Out:   serial1@ffc02100
Err:   serial1@ffc02100
Net:
Warning: ethernet@ff800000 (eth0) using random MAC address - 2e:e0:0f:f7:09:f9
eth0: ethernet@ff800000Could not get PHY for ethernet@ff802000: addr -1

Hit any key to stop autoboot:  0
2606 bytes read in 2 ms (1.2 MiB/s)
## Executing script at 02100000
crc32+ 46804992 bytes read in 2123 ms (21 MiB/s)
INFO:    Error in response: 1f0003ff
.............................................FPGA reconfiguration OK!
31540638 bytes read in 1434 ms (21 MiB/s)
## Loading kernel from FIT Image at 02000000 ...
   Using 'conf' configuration
   Verifying Hash Integrity ... OK
   Trying 'kernel' kernel subimage
     Description:  Linux Kernel
     Type:         Kernel Image
     Compression:  uncompressed
     Data Start:   0x020000bc
     Data Size:    31517184 Bytes = 30.1 MiB
     Architecture: AArch64
     OS:           Linux
     Load Address: 0x04200000
     Entry Point:  0x04200000
     Hash algo:    crc32
     Hash value:   f123f1e5
   Verifying Hash Integrity ... crc32+ OK
## Loading fdt from FIT Image at 02000000 ...
   Using 'conf' configuration
   Verifying Hash Integrity ... OK
   Trying 'fdt' fdt subimage
     Description:  Linux DTB
     Type:         Flat Device Tree
     Compression:  uncompressed
     Data Start:   0x03e0eb94
     Data Size:    21594 Bytes = 21.1 KiB
     Architecture: AArch64
     Hash algo:    crc32
     Hash value:   bd26acc5
   Verifying Hash Integrity ... crc32+ OK
   Booting using the fdt blob at 0x3e0eb94
   Loading Kernel Image
   Loading Device Tree to 000000003fa2f000, end 000000003fa37459 ... OK
SF: Detected n25q00a with page size 256 Bytes, erase size 4 KiB, total 128 MiB
Enabling QSPI at Linux DTB...
INFO:    Error in response: 1f00000c
RSU: Firmware or flash content not supporting RSU
INFO:    Error in response: 1f00000c
RSU: Firmware or flash content not supporting RSU
INFO:    Error in response: 1f00000c
RSU: Firmware or flash content not supporting RSU
INFO:    Error in response: 1f00000c
RSU: Firmware or flash content not supporting RSU

Starting kernel ...

Deasserting all peripheral resets
[    0.000000] Booting Linux on physical CPU 0x0000000000 [0x410fd034]
[    0.000000] Linux version 5.10.179-altera (oe-user@oe-host) (aarch64-linux-gcc (GCC) 11.3.0, GNU ld (GNU Binutils) 2.38.20220708) #1 SMP PREEMPT Tue Sep 12 15:38:24 UTC 2023
[    0.000000] Machine model: SoCFPGA SoCDK
[    0.000000] efi: UEFI not found.
[    0.000000] Reserved memory: created DMA memory pool at 0x0000000000000000, size 16 MiB
[    0.000000] OF: reserved mem: initialized node svcbuffer@0, compatible id shared-dma-pool
[    0.000000] earlycon: uart0 at MMIO32 0x00000000ffc02100 (options '115200n8')
[    0.000000] printk: bootconsole [uart0] enabled
[    0.000000] NUMA: No NUMA configuration found
[    0.000000] NUMA: Faking a node at [mem 0x0000000000000000-0x000000003fffffff]
[    0.000000] NUMA: NODE_DATA [mem 0x3fdebb00-0x3fdedfff]
[    0.000000] Zone ranges:
[    0.000000]   DMA      [mem 0x0000000000000000-0x000000003fffffff]
[    0.000000]   DMA32    empty
[    0.000000]   Normal   empty
[    0.000000] Movable zone start for each node
[    0.000000] Early memory node ranges
[    0.000000]   node   0: [mem 0x0000000000000000-0x0000000000ffffff]
[    0.000000]   node   0: [mem 0x0000000001000000-0x000000003fffffff]
[    0.000000] Initmem setup node 0 [mem 0x0000000000000000-0x000000003fffffff]
[    0.000000] cma: Reserved 32 MiB at 0x000000003c000000
[    0.000000] psci: probing for conduit method from DT.
[    0.000000] psci: __invoke_psci_fn_smc: function_id=0x84000000, arg0=0x0,arg1=0x0,arg2=0x0
NOTICE:  std_svc_smc_handler: smc_fid=0x84000000,x1=0x0,x2=0x0,x3=0x0,x4=0x0,flags=1
NOTICE:  psci_smc_handler(AARCH32): r1=0x0,r2=0x0,r3=0x0
[    0.000000] psci: PSCIv1.1 detected in firmware.
[    0.000000] psci: Using standard PSCI v0.2 function IDs
[    0.000000] psci: __invoke_psci_fn_smc: function_id=0x84000006, arg0=0x0,arg1=0x0,arg2=0x0
NOTICE:  std_svc_smc_handler: smc_fid=0x84000006,x1=0x0,x2=0x0,x3=0x0,x4=0x0,flags=1
NOTICE:  psci_smc_handler(AARCH32): r1=0x0,r2=0x0,r3=0x0
[    0.000000] psci: Trusted OS migration not required
[    0.000000] psci: __invoke_psci_fn_smc: function_id=0x8400000a, arg0=0x80000000,arg1=0x0,arg2=0x0
NOTICE:  std_svc_smc_handler: smc_fid=0x8400000a,x1=0x80000000,x2=0x0,x3=0x0,x4=0x0,flags=1
NOTICE:  psci_smc_handler(AARCH32): r1=0x80000000,r2=0x0,r3=0x0
[    0.000000] psci: __invoke_psci_fn_smc: function_id=0x80000000, arg0=0x0,arg1=0x0,arg2=0x0
[    0.000000] psci: SMC Calling Convention v1.2
[    0.000000] psci: __invoke_psci_fn_smc: function_id=0x8400000a, arg0=0xc4000001,arg1=0x0,arg2=0x0
NOTICE:  std_svc_smc_handler: smc_fid=0x8400000a,x1=0xc4000001,x2=0x0,x3=0x0,x4=0x0,flags=1
NOTICE:  psci_smc_handler(AARCH32): r1=0xc4000001,r2=0x0,r3=0x0
[    0.000000] psci: __invoke_psci_fn_smc: function_id=0x8400000a, arg0=0xc400000e,arg1=0x0,arg2=0x0
NOTICE:  std_svc_smc_handler: smc_fid=0x8400000a,x1=0xc400000e,x2=0x0,x3=0x0,x4=0x0,flags=1
NOTICE:  psci_smc_handler(AARCH32): r1=0xc400000e,r2=0x0,r3=0x0
[    0.000000] psci: __invoke_psci_fn_smc: function_id=0x8400000a, arg0=0xc4000012,arg1=0x0,arg2=0x0
NOTICE:  std_svc_smc_handler: smc_fid=0x8400000a,x1=0xc4000012,x2=0x0,x3=0x0,x4=0x0,flags=1
NOTICE:  psci_smc_handler(AARCH32): r1=0xc4000012,r2=0x0,r3=0x0
[    0.000000] percpu: Embedded 23 pages/cpu s56664 r8192 d29352 u94208
[    0.000000] Detected VIPT I-cache on CPU0
[    0.000000] CPU features: detected: ARM erratum 845719
[    0.000000] Built 1 zonelists, mobility grouping on.  Total pages: 258048
[    0.000000] Policy zone: DMA
[    0.000000] Kernel command line: earlycon panic=-1 console=ttyS0,115200 earlyprintk uio_pdrv_genirq.of_id=generic-uio root=/dev/mmcblk0p2 rw rootwait
[    0.000000] Dentry cache hash table entries: 131072 (order: 8, 1048576 bytes, linear)
[    0.000000] Inode-cache hash table entries: 65536 (order: 7, 524288 bytes, linear)
[    0.000000] mem auto-init: stack:off, heap alloc:off, heap free:off
[    0.000000] Memory: 947616K/1048576K available (14400K kernel code, 2810K rwdata, 7556K rodata, 5888K init, 512K bss, 68192K reserved, 32768K cma-reserved)
[    0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1
[    0.000000] rcu: Preemptible hierarchical RCU implementation.
[    0.000000] rcu:     RCU event tracing is enabled.
[    0.000000] rcu:     RCU restricting CPUs from NR_CPUS=256 to nr_cpu_ids=4.
[    0.000000]  Trampoline variant of Tasks RCU enabled.
[    0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 25 jiffies.
[    0.000000] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=4
[    0.000000] NR_IRQS: 64, nr_irqs: 64, preallocated irqs: 0
[    0.000000] GIC: Using split EOI/Deactivate mode
[    0.000000] arch_timer: cp15 timer(s) running at 400.00MHz (phys).
[    0.000000] clocksource: arch_sys_counter: mask: 0xffffffffffffff max_cycles: 0x5c4093a7d1, max_idle_ns: 440795210635 ns
[    0.000004] sched_clock: 56 bits at 400MHz, resolution 2ns, wraps every 4398046511103ns
[    0.008518] Console: colour dummy device 80x25
[    0.013028] Calibrating delay loop (skipped), value calculated using timer frequency.. 800.00 BogoMIPS (lpj=1600000)
[    0.023512] pid_max: default: 32768 minimum: 301
[    0.028178] LSM: Security Framework initializing
[    0.032831] Mount-cache hash table entries: 2048 (order: 2, 16384 bytes, linear)
[    0.040204] Mountpoint-cache hash table entries: 2048 (order: 2, 16384 bytes, linear)
[    0.049554] rcu: Hierarchical SRCU implementation.
[    0.055578] EFI services will not be available.
[    0.060316] smp: Bringing up secondary CPUs ...
[    0.065172] boot_secondary: CPU = 1
[    0.068644] psci: cpu_psci_cpu_boot: CPU = 1
[    0.072906] psci: psci_cpu_on: cpuid=0x1, entry_point=0x50091dc
[    0.078804] psci: __invoke_psci_fn_smc: function_id=0xc4000003, arg0=0x1,arg1=0x50091dc,arg2=0x0
NOTICE:  std_svc_smc_handler: smc_fid=0xc4000003,x1=0x1,x2=0x50091dc,x3=0x0,x4=0x0,flags=1
NOTICE:  psci_smc_handler:AARCH64
NOTICE:  psci_cpu_on: enter
NOTICE:  cpu is exist
NOTICE:  pc=0x50091dc, spsr=0x3c9
NOTICE:  psci_cpu_on_start: target_cpu=0x1
NOTICE:  socfpga_pwr_domain_on: mpidr: 0x1
NOTICE:  rc = 0
NOTICE:  CurrentEl=0x3, MODE_EL=3
NOTICE:  sctlr_el=0xc5183a
NOTICE:  psci_warmboot_entrypoint start
NOTICE:  psci_cpu_on_finish:cpu_idx=1
NOTICE:  opteed_cpu_on_finish_handler: linear_id=1, optee_ctx->state=0[0-OFF,1-ON]
NOTICE:  opteed_init_optee_ep_state: arg0=0x0, arg1=0x0, arg2=0x0, spsr=0x3c5, pc=0x3e0018b4
NOTICE:  opteed_cpu_on_finish_handler: entry=0x3e0018b4

The initialization process gets stuck at the end of the line, then wait 6 or 7 seconds for the intel socfpga to reset and repeat the process again. I've confirmed that the CPU boot method is PSCI:

cpus {
    #address-cells = <1>;
    #size-cells = <0>;

    cpu0: cpu@0 {
        compatible = "arm,cortex-a53", "arm,armv8";
        device_type = "cpu";
        enable-method = "psci";
        reg = <0x0>;
    };

    cpu1: cpu@1 {
        compatible = "arm,cortex-a53", "arm,armv8";
        device_type = "cpu";
        enable-method = "psci";
        reg = <0x1>;
    };

    cpu2: cpu@2 {
        compatible = "arm,cortex-a53", "arm,armv8";
        device_type = "cpu";
        enable-method = "psci";
        reg = <0x2>;
    };

    cpu3: cpu@3 {
        compatible = "arm,cortex-a53", "arm,armv8";
        device_type = "cpu";
        enable-method = "psci";
        reg = <0x3>;
    };
};

psci {
    compatible = "arm,psci-0.2";
    method = "smc";
};

Very strangely, the optee.dmp file shows the correct call address (0x3e0018b4 the last line of the initialization process), but optee doesn't run at this address:

So, I don't know why optee_os doesn't response the SMCCC here, I would appreciate it if you know how to solve this problem! Best Regards!

[jenswi-linaro]

Perhaps the secondary cores crash in OP-TEE before they are able to report something. You could try printing a single character on the UART with a few assembly instructions just after the entry address to see how far you get.

[wangxiang-github]

Hi jenswi-linaro, thanks for your interest in this issue, I tried to print a single character in the optee_os, but nothing printed. there is my changes:

Actually, I've thought about this, secondary boot maybe be crashed somewhere, but I designed a test to verify sencondary boot process, I added an SMC call to the ATF and simulated a scene that kernel launch the SMP call:

extern uintptr_t std_svc_smc_handler(uint32_t smc_fid, u_register_t x1, u_register_t x2, u_register_t x3, u_register_t x4, void *cookie, void *handle, u_register_t flags);
struct optee_res_arm_smccc {
    unsigned long a0;
    unsigned long a1;
    unsigned long a2;
    unsigned long a3;
};

void cpu_on_secondary_prehandle(void)
{
    struct optee_res_arm_smccc handle;

    NOTICE("secondary bootup init\n");

    std_svc_smc_handler(0xc4000003, 0x1, 0x50091dc, 0x0, 0x0, NULL, &handle, 1);
    mdelay(100);
    std_svc_smc_handler(0xc4000003, 0x2, 0x50091dc, 0x0, 0x0, NULL, &handle, 1);
    //mdelay(100);
    //std_svc_smc_handler(0xc4000003, 0x3, 0x50091dc, 0x0, 0x0, NULL, &handle, 1);
}

Function cpu_on_secondary_prehandle is called from bl31_main at the end of the line, then, during ATF initialization, I get the secondary boot log.

NOTICE:  opteed_smc_handler:enter, is_caller_non_secure(flags=0x0)=0x0
NOTICE:  opteed_smc_handler:smc_fid = 0xbe000000
NOTICE:  opteed_smc_handler:x1=0x3e0018ac,x2=0x3e09c860,x3=0x8000000000,x4=0x3e0ceba0
NOTICE:  TEESMC_OPTEED_RETURN_ENTRY_DONE
NOTICE:  opteed_smc_handler: x1=0x3e0018ac
NOTICE:  optee_vector_table(0x3e0018ac) is not NULL
NOTICE:  optee_entrypoint_test:ctx->state=1[0-OFF,1-ON]
NOTICE:  opteed_init_optee_ep_state: arg0=0x0, arg1=0x0, arg2=0x0, spsr=0x3c5, pc=0x3e0018b4
NOTICE:  optee_entrypoint_test:linear_id=0, optee_on_entrypoint.pc=0x3e0018b4, spsr=0x3c5
NOTICE:  first enter optee os finished!
NOTICE:  bl31_prepare_next_image_entry: image_type = 1[0-SECURE, 1-NON_SECURE]
NOTICE:  bl31_plat_get_next_image_ep_info: type=1.[0-SECURE, 1-NON_SECURE]
NOTICE:  type=0x1, version=0x1, size=0x58, attr=0x1, pc=0x200000, spsr=0x3c9
INFO:    BL31: Preparing for EL3 exit to normal world
INFO:    Entry point address = 0x200000
INFO:    SPSR = 0x3c9
NOTICE:  secondary bootup init
NOTICE:  std_svc_smc_handler: smc_fid=0xc4000003,x1=0x1,x2=0x50091dc,x3=0x0,x4=0x0,flags=1
NOTICE:  psci_smc_handler:AARCH64
NOTICE:  psci_cpu_on: enter
NOTICE:  cpu is exist
NOTICE:  pc=0x50091dc, spsr=0x3c5
NOTICE:  psci_cpu_on_start: target_cpu=0x1
NOTICE:  socfpga_pwr_domain_on: mpidr: 0x1
NOTICE:  rc = 0
NOTICE:  CurrentEl=0x3, MODE_EL=3
NOTICE:  sctlr_el=0xc5183a
NOTICE:  psci_warmboot_entrypoint start
NOTICE:  psci_cpu_on_finish:cpu_idx=1
NOTICE:  opteed_cpu_on_finish_handler: linear_id=1, optee_ctx->state=0[0-OFF,1-ON]
NOTICE:  opteed_init_optee_ep_state: arg0=0x0, arg1=0x0, arg2=0x0, spsr=0x3c5, pc=0x3e0018b4
NOTICE:  opteed_cpu_on_finish_handler: entry=0x3e0018b4
I/TC: Secondary CPU 1 initializing
I/TC: Secondary CPU 1 switching to normal world boot
NOTICE:  opteed_smc_handler:enter, is_caller_non_secure(flags=0x0)=0x0
NOTICE:  opteed_smc_handler:smc_fid = 0xbe000001
NOTICE:  opteed_smc_handler:x1=0x0,x2=0x3e0229f8,x3=0x8000000100,x4=0x3e0c9e40
NOTICE:  TEESMC_OPTEED_RETURN_ON_DONE
NOTICE:  psci_warmboot_entrypoint end
NOTICE:  std_svc_smc_handler: smc_fid=0xc4000003,x1=0x2,x2=0x50091dc,x3=0x0,x4=0x0,flags=1
NOTICE:  psci_smc_handler:AARCH64
NOTICE:  psci_cpu_on: enter
NOTICE:  cpu is exist
NOTICE:  pc=0x50091dc, spsr=0x3c5
NOTICE:  psci_cpu_on_start: target_cpu=0x2
NOTICE:  socfpga_pwr_domain_on: mpidr: 0x2
NOTICE:  rc = 0
NOTICE:  CurrentEl=0x3, MODE_EL=3
NOTICE:  sctlr_el=0xc5183a
NOTICE:  psci_warmboot_entrypoint start
NOTICE:  psci_cpu_on_finish:cpu_idx=2
NOTICE:  opteed_cpu_on_finish_handler: linear_id=2, optee_ctx->state=0[0-OFF,1-ON]
NOTICE:  opteed_init_optee_ep_state: arg0=0x0, arg1=0x0, arg2=0x0, spsr=0x3c5, pc=0x3e0018b4
NOTICE:  opteed_cpu_on_finish_handler: entry=0x3e0018b4
I/TC: Secondary CPU 2 initializing
I/TC: Secondary CPU 2 switching to normal world boot
NOTICE:  opteed_smc_handler:enter, is_caller_non_secure(flags=0x0)=0x0
NOTICE:  opteed_smc_handler:smc_fid = 0xbe000001
NOTICE:  opteed_smc_handler:x1=0x0,x2=0x3e0229f8,x3=0x8000000200,x4=0x3e0ca680
NOTICE:  TEESMC_OPTEED_RETURN_ON_DONE
NOTICE:  psci_warmboot_entrypoint end

I can see the secondary print in the ATF initilize log:

I/TC: Secondary CPU 1 initializing
I/TC: Secondary CPU 1 switching to normal world boot

so I guess secondary boot should be fine, and SMP call will go through in this case, but it will eventually gets stuck in the Optee driver:

[    1.139218] usbcore: registered new interface driver usb-storage
[    1.147367] i2c /dev entries driver
[    1.152376] optee: probing for conduit method.
NOTICE:  opteed_smc_handler:enter, is_caller_non_secure(flags=0x1)=0x1
NOTICE:  opteed_smc_handler:smc_fid = 0xbf00ff01
NOTICE:  opteed_smc_handler:x1=0x0,x2=0x0,x3=0x0,x4=0x0
NOTICE:  opteed_smc_handler: call fast_smc_entry->0x3e0018b0

Similarly, address 0x3e0018b0 is the entry point address for function vector_fast_smc_entry, but optee can't run with this address either. It looks like optee can not work once a state transition occurs (EL0 to EL3). so I don't understand this point.

[jenswi-linaro]

It's no surprise that you didn't get anything printed with that change, the stack pointer isn't initialized at that stage.

It looks like optee can not work once a state transition occurs (EL0 to EL3). so I don't understand this point.

It seems that the problem lies outside of OP-TEE. Perhaps the memory where OP-TEE is loaded becomes corrupted by the normal world?

[wangxiang-github]

Maybe so, intel's socfpga silicon didn't have bl32 address layout originally, I added it manualy, maybe it doesn't work.

[jenswi-linaro]

OK, there's your problem. You need to find and/or configure some secure memory where OP-TEE can reside.

[wangxiang-github]

I am not so sure about this, However, I have a qustion, if bl32 start address is fine, then theoretically, when an SMC call occurs, OPTEE should jump to the thread_vector_table table to get the entry point address (e.g., 0x3e0018b4) to run the corresponding function (vector_cpu_on_entry) , instead of getting stuck in this place, right?

[jenswi-linaro]

Yes, I believe you've even demonstrated that above.

[github-actions[bot]]

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.