Stuck while running the occlum demo hello_c on Intel CPU with fake TPM

basic information

OS & kernel

cat /etc/os-release
NAME="Ubuntu"
VERSION="20.04.6 LTS (Focal Fossa)"
ID=ubuntu
ID_LIKE=debian
PRETTY_NAME="Ubuntu 20.04.6 LTS"
VERSION_ID="20.04"
HOME_URL="https://www.ubuntu.com/"
SUPPORT_URL="https://help.ubuntu.com/"
BUG_REPORT_URL="https://bugs.launchpad.net/ubuntu/"
PRIVACY_POLICY_URL="https://www.ubuntu.com/legal/terms-and-policies/privacy-policy"
VERSION_CODENAME=focal
UBUNTU_CODENAME=focal
tee@tee:/data/hyperenclave-driver$ uname -a
Linux tee 5.4.0-88-generic #99-Ubuntu SMP Thu Sep 23 17:29:00 UTC 2021 x86_64 x86_64 x86_64 GNU/Linux

cpu

lscpu
Architecture:                    x86_64
CPU op-mode(s):                  32-bit, 64-bit
Byte Order:                      Little Endian
Address sizes:                   39 bits physical, 48 bits virtual
CPU(s):                          4
On-line CPU(s) list:             0-3
Thread(s) per core:              1
Core(s) per socket:              4
Socket(s):                       1
NUMA node(s):                    1
Vendor ID:                       GenuineIntel
CPU family:                      6
Model:                           167
Model name:                      Intel(R) Xeon(R) E-2314 CPU @ 2.80GHz
Stepping:                        1
CPU MHz:                         3500.000
BogoMIPS:                        5616.00
Virtualization:                  VT-x
L1d cache:                       192 KiB
L1i cache:                       128 KiB
L2 cache:                        2 MiB
L3 cache:                        8 MiB
NUMA node0 CPU(s):               0-3
Vulnerability Itlb multihit:     Not affected
Vulnerability L1tf:              Not affected
Vulnerability Mds:               Not affected
Vulnerability Meltdown:          Not affected
Vulnerability Spec store bypass: Mitigation; Speculative Store Bypass disabled via prctl and seccomp
Vulnerability Spectre v1:        Mitigation; usercopy/swapgs barriers and __user pointer sanitization
Vulnerability Spectre v2:        Mitigation; Enhanced IBRS, IBPB conditional, RSB filling
Vulnerability Srbds:             Not affected
Vulnerability Tsx async abort:   Not affected
Flags:                           fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush dts acpi mmx fxsr sse sse2 ss ht tm pbe syscall nx pdpe1gb rdtscp lm constant_tsc art arch_perfmon pebs bts rep_good n
                             opl xtopology nonstop_tsc cpuid aperfmperf tsc_known_freq pni pclmulqdq dtes64 monitor ds_cpl vmx smx est tm2 ssse3 sdbg fma cx16 xtpr pdcm pcid sse4_1 sse4_2 x2apic movbe popcnt tsc_deadline_timer
                             aes xsave avx f16c rdrand lahf_lm abm 3dnowprefetch cpuid_fault invpcid_single ssbd ibrs ibpb stibp ibrs_enhanced tpr_shadow vnmi flexpriority ept vpid ept_ad fsgsbase tsc_adjust bmi1 avx2 smep bmi2
                              erms invpcid mpx avx512f avx512dq rdseed adx smap avx512ifma clflushopt intel_pt avx512cd sha_ni avx512bw avx512vl xsaveopt xsavec xgetbv1 xsaves dtherm ida arat pln pts avx512vbmi umip pku ospke a
                             vx512_vbmi2 gfni vaes vpclmulqdq avx512_vnni avx512_bitalg avx512_vpopcntdq rdpid md_clear flush_l1d arch_capabilities

lsmem


lsmem
RANGE                                  SIZE  STATE REMOVABLE  BLOCK
0x0000000000000000-0x000000006fffffff  1.8G online       yes   0-13
0x0000000200000000-0x0000000487ffffff 10.1G online       yes 64-144

Memory block size: 128M Total online memory: 11.9G Total offline memory: 0B

* cmdline
```bash
cat /proc/cmdline
BOOT_IMAGE=/boot/vmlinuz-5.4.0-88-generic root=UUID=80266541-2151-4cde-87c2-6aed3ef445c7 ro memmap=4G$0x100000000 intel_iommu=off intremap=off no5lvl quiet splash vt.handoff=7

steps

install enable_rdfsbase following enable_rdfsbase

dmesg|grep -i enable_rd
[  547.012158] enable_rdfsbase: loading out-of-tree module taints kernel.
[  547.012184] enable_rdfsbase: module verification failed: signature and/or required key missing - tainting kernel
[  547.012316] enable_rdfsbase: Loaded
[  547.012324] Modules linked in: enable_rdfsbase(OE+) xt_conntrack xt_MASQUERADE nf_conntrack_netlink nfnetlink xfrm_user xfrm_algo ip6table_nat ip6table_filter ip6_tables iptable_nat nf_nat nf_conntrack nf_defrag_ipv6 nf_defrag_ipv4 libcrc32c xt_addrtype iptable_filter bpfilter br_netfilter bridge stp llc aufs overlay nls_iso8859_1 binfmt_misc kvm_intel kvm crct10dif_pclmul crc32_pclmul ghash_clmulni_intel input_leds aesni_intel ipmi_ssif crypto_simd cryptd glue_helper ipmi_si video ipmi_devintf ipmi_msghandler acpi_pad sch_fq_codel msr parport_pc ppdev lp parport drm efi_pstore ip_tables x_tables autofs4 hid_generic usbhid hid tg3 ahci libahci
[  547.012350]  set_cr4_fsgsbase+0x3f/0x50 [enable_rdfsbase]
[  547.012375] enable_rdfsbase: RDFSBASE and its friends are now enabled on CPU 0
[  547.012377] enable_rdfsbase: RDFSBASE and its friends are now enabled on CPU 1
[  547.012377] enable_rdfsbase: RDFSBASE and its friends are now enabled on CPU 2
[  547.012379] enable_rdfsbase: RDFSBASE and its friends are now enabled on CPU 3
tee@tee:/data/enable_rdfsbase$ lsmod |grep enable
enable_rdfsbase        16384  0

./start_hyperenclave.sh

/data/hyperenclave/scripts$ ./start_hyperenclave.sh

dmesg

[  547.012374] ---[ end trace 4175d4fa27f271d1 ]---
[  547.012375] enable_rdfsbase: RDFSBASE and its friends are now enabled on CPU 0
[  547.012377] enable_rdfsbase: RDFSBASE and its friends are now enabled on CPU 1
[  547.012377] enable_rdfsbase: RDFSBASE and its friends are now enabled on CPU 2
[  547.012379] enable_rdfsbase: RDFSBASE and its friends are now enabled on CPU 3
[  607.358689] HE: cpu_vendor_detect: 39. Vendor ID: GenuineIntel
[  607.366435] HE: get_convertible_memory: 136. BIOS E820 table from firmware: [0x0000000000000000 -> 0x00000000000a0000], type: System RAM
[  607.366436] HE: get_convertible_memory: 136. BIOS E820 table from firmware: [0x00000000000a0000 -> 0x0000000000100000], type: Reserved
[  607.366436] HE: get_convertible_memory: 136. BIOS E820 table from firmware: [0x0000000000100000 -> 0x0000000064600000], type: System RAM
[  607.366437] HE: get_convertible_memory: 136. BIOS E820 table from firmware: [0x0000000064600000 -> 0x0000000068600000], type: Reserved
[  607.366437] HE: get_convertible_memory: 136. BIOS E820 table from firmware: [0x0000000068600000 -> 0x000000006e6ff000], type: System RAM
[  607.366438] HE: get_convertible_memory: 136. BIOS E820 table from firmware: [0x000000006e6ff000 -> 0x000000006fbff000], type: Reserved
[  607.366438] HE: get_convertible_memory: 136. BIOS E820 table from firmware: [0x000000006fbff000 -> 0x000000006fcff000], type: ACPI Non-volatile Storage
[  607.366439] HE: get_convertible_memory: 136. BIOS E820 table from firmware: [0x000000006fcff000 -> 0x000000006feff000], type: ACPI Tables
[  607.366439] HE: get_convertible_memory: 136. BIOS E820 table from firmware: [0x000000006feff000 -> 0x000000006ff00000], type: System RAM
[  607.366440] HE: get_convertible_memory: 136. BIOS E820 table from firmware: [0x000000006ff00000 -> 0x000000007c000000], type: Reserved
[  607.366440] HE: get_convertible_memory: 136. BIOS E820 table from firmware: [0x0000000080000000 -> 0x0000000090000000], type: Reserved
[  607.366441] HE: get_convertible_memory: 136. BIOS E820 table from firmware: [0x00000000fe010000 -> 0x00000000fe011000], type: Reserved
[  607.366441] HE: get_convertible_memory: 136. BIOS E820 table from firmware: [0x00000000fed20000 -> 0x00000000fed80000], type: Reserved
[  607.366441] HE: get_convertible_memory: 136. BIOS E820 table from firmware: [0x0000000100000000 -> 0x0000000484000000], type: System RAM
[  607.366442] HE: get_convertible_memory: 213. Convertible Memory[ 0]: 0x0000000000000000 -> 0x00000000000a0000
[  607.366443] HE: get_convertible_memory: 213. Convertible Memory[ 1]: 0x0000000000100000 -> 0x0000000064600000
[  607.366443] HE: get_convertible_memory: 213. Convertible Memory[ 2]: 0x0000000068600000 -> 0x000000006e6ff000
[  607.366444] HE: get_convertible_memory: 213. Convertible Memory[ 3]: 0x000000006feff000 -> 0x000000006ff00000
[  607.366444] HE: get_convertible_memory: 213. Convertible Memory[ 4]: 0x0000000100000000 -> 0x0000000484000000
[  607.366445] HE: get_convertible_memory: 218. Convertible Memory size: 0x3ee6a0000
[  607.366445] HE: get_valid_rsrv_mem: 285. Reserved Memory[ 0]: 0x100000000 -> 0x200000000
[  607.366446] HE: get_valid_rsrv_mem: 290. Reserved Memory size: 0x100000000
[  607.366450] HE: mem_test: 48. Memory[0x100000000 - 0x200000000] test begin
[  608.061435] HE: mem_test: 78. Memory[0x100000000 - 0x200000000] test pass
[  610.143925] HE: get_hv_heap_size: 375. Hypervisor heap size: 0x43800000
[  610.143926] HE: get_hv_cmrm_size: 387. Hypervisor cmrm size: 0x6c60000
[  610.143926] HE: get_hv_frame_size: 400. Hypervisor frame size: 0x1c00000
[  610.143926] HE: get_hypervisor_size: 413. Hv_core_and_percpu_size: 0x815000, Hypervisor size: 0x80000000
[  610.143927] HE: he_cmd_enable: 302. hypervisor size: 0x80000000
[  610.210058] HE: he_cmd_enable: 352. config_size: 1508
[  610.226679] HE: add_epc_pages: 43. total_epc_pages: 0x80000, free_epc_pages: 0x80000
[  610.226680] HE: init_enclave_page: 317. epc ranges: [0x180000000-0x200000000], 0x80000000
[  610.226681] HE: init_enclave_page: 333. Initialized EPC ranges size: 0x80000000
[  610.226682] HE: he_cmd_enable: 383. config_header load_addr: 0xffffff0000815000
[  610.226703] HE: he_cmd_enable: 404. mem_region load_addr: 0xffffff0000815124
[  610.226704] HE: inspect_tpm: 206. using fake tpm
[  610.226704] HE: he_cmd_enable: 411. tpm mmio type=8,size=0 pa=ffffffff
[  610.516066] HE: init_cmrm: 448. Initialize [0x0 -> 0x484000000]'s CMRM
[  610.516194] HE: he_cmd_enable: 483. The hyperenclave is opening.
[  620.549690] [0] Activating hypervisor on CPU 0...
[  620.549690] [1] Init HHBox log feature ok
[  620.549691] [1] Init HHBox crash feature ok
[  620.549691] [1] tpm_detect starting....
[  620.549691] [1] fake tpm is detected and initialized
[  620.549691] [1] FAKE TPM: tpm signing key pub x
[  620.549691] [1] C29974C9F1090FA4A10E9990620E91828B593A7211E2468450E3DC96DD5933FB
[  620.549691] [1] size= :0x20
[  620.549692] [1] FAKE TPM: tpm signing key pub y
[  620.549692] [1] 402206ECCC5479289F33668EAAB85527ABBBB9F7B41CEB71551027D57AF28267
[  620.549692] [1] size= :0x20
[  620.549692] [1] FAKE TPM: root secret is generated and sealed
[  620.549692] [1] FAKE TPM: hypervisor AK pub x=
[  620.549692] [1] 3D9BB7BA028C5F97AC5AB1619336D9ED23E86858DDBDC23B510D5F0EBA8FF338
[  620.549693] [1] size= :0x20
[  620.549693] [1] FAKE TPM: hypervisor AK pub y=
[  620.549693] [1] 0B28428BDA30B2800FCB032ABCED81071B5F0DCB1A02B22AFF56B7DD22E52522
[  620.549693] [1] size= :0x20
[  620.549693] [1] FAKE TPM: hash of he_ak_pub extended to PCR 13:
[  620.549694] [1] AAA056CA1F030B7BD6C4089C2AEEC36D01173B46E0FD2B4C1BD2C14649B66539
[  620.549694] [1] size= :0x20
[  620.549694] [1] HyperEnclave: root of trust initialized!
[  620.549694] [1] Activating hypervisor on CPU 1...
[  620.549694] [2] Activating hypervisor on CPU 2...
[  620.549695] [3] Activating hypervisor on CPU 3...

run the hello_c

root@tee:~/occlum/demos/hello_c/occlum_instance# occlum run /bin/hello_world

Then it got stuck


OCCLUM_LOG_LEVEL=trace occlum run /bin/hello_world
[2024-07-24T02:45:44.572Z][DEBUG][T0][#0] lookup_inode: cwd: "/", path: "/etc/resolv.conf"
[2024-07-24T02:45:44.573Z][DEBUG][T0][#0] convert_to_abs_path: cwd: "/", path: "/etc/resolv.conf"
[2024-07-24T02:45:44.573Z][DEBUG][T0][#0] lookup_inode: cwd: "/", path: "/etc/hostname"
[2024-07-24T02:45:44.573Z][DEBUG][T0][#0] convert_to_abs_path: cwd: "/", path: "/etc/hostname"
[2024-07-24T02:45:44.573Z][DEBUG][T0][#0] lookup_inode: cwd: "/", path: "/etc/hosts"
[2024-07-24T02:45:44.573Z][DEBUG][T0][#0] convert_to_abs_path: cwd: "/", path: "/etc/hosts"
[2024-07-24T02:45:44.573Z][TRACE][T0][#0] env_checked from env untrusted: []
[2024-07-24T02:45:44.573Z][TRACE][T0][#0] env_merged = ["OCCLUM=yes"]  (default env and untrusted env)
[2024-07-24T02:45:44.573Z][DEBUG][T0][#0] lookup_inode: cwd: "/", path: "/bin/init"
[2024-07-24T02:45:44.573Z][DEBUG][T0][#0] convert_to_abs_path: cwd: "/", path: "/bin/init"
[2024-07-24T02:45:44.574Z][TRACE][T0][#0] PT_INTERP offset = 568, count = 25
[2024-07-24T02:45:44.574Z][TRACE][T0][#0] interpreter = Some("/lib/ld-musl-x86_64.so.1")
[2024-07-24T02:45:44.574Z][TRACE][T0][#0] ldso_path = "/lib/ld-musl-x86_64.so.1"
[2024-07-24T02:45:44.574Z][DEBUG][T0][#0] lookup_inode: cwd: "/", path: "/lib/ld-musl-x86_64.so.1"
[2024-07-24T02:45:44.574Z][DEBUG][T0][#0] convert_to_abs_path: cwd: "/", path: "/lib/ld-musl-x86_64.so.1"
[2024-07-24T02:45:44.574Z][TRACE][T0][#0] interpreter = None
[2024-07-24T02:45:44.574Z][DEBUG][T0][#0] allocated rsrv addr is 0x7f87063ad000, len is 0x12c00000
[2024-07-24T02:45:44.574Z][TRACE][T0][#0] find free range, free list = [VMRange { start: 0x7f87063ad000, end: 0x7f8718fad000, size: 0x12c00000 }]
[2024-07-24T02:45:44.574Z][TRACE][T0][#0] after find free range, free list = [VMRange { start: 0x7f87063ad000, end: 0x7f8706400000, size: 0x53000 }, VMRange { start: 0x7f8706800000, end: 0x7f8718fad000, size: 0x127ad000 }]
[2024-07-24T02:45:44.574Z][TRACE][T0][#0] allocate a new single vma chunk: range = VMRange { start: 0x7f8706400000, end: 0x7f8706800000, size: 0x400000 }, Single VMA chunk: SgxMutex { data: VMArea { range: VMRange { start: 0x7f8706400000, end: 0x7f8706800000, size: 0x400000 }, perms: READ | WRITE | EXEC | DEFAULT | ALL, file_backed: Some(FileBacked { file: INodeFile { inode: ???, abs_path: /bin/init, pos: 0, access_mode: O_RDONLY, status_flags: 0o0 }, offset: 0, write_back: false }), pid: 0 }, poisoned: false, .. }
[2024-07-24T02:45:44.576Z][TRACE][T0][#0] elf range = VMRange { start: 0x7f8706400000, end: 0x7f8706800000, size: 0x400000 }
[2024-07-24T02:45:44.576Z][TRACE][T0][#0] find free range, free list = [VMRange { start: 0x7f87063ad000, end: 0x7f8706400000, size: 0x53000 }, VMRange { start: 0x7f8706800000, end: 0x7f8718fad000, size: 0x127ad000 }]
[2024-07-24T02:45:44.576Z][TRACE][T0][#0] after find free range, free list = [VMRange { start: 0x7f87063ad000, end: 0x7f8706400000, size: 0x53000 }, VMRange { start: 0x7f8706c00000, end: 0x7f8718fad000, size: 0x123ad000 }]
[2024-07-24T02:45:44.576Z][TRACE][T0][#0] allocate a new single vma chunk: range = VMRange { start: 0x7f8706800000, end: 0x7f8706c00000, size: 0x400000 }, Single VMA chunk: SgxMutex { data: VMArea { range: VMRange { start: 0x7f8706800000, end: 0x7f8706c00000, size: 0x400000 }, perms: READ | WRITE | EXEC | DEFAULT | ALL, file_backed: Some(FileBacked { file: INodeFile { inode: ???, abs_path: /lib/ld-musl-x86_64.so.1, pos: 0, access_mode: O_RDONLY, status_flags: 0o0 }, offset: 0, write_back: false }), pid: 0 }, poisoned: false, .. }
[2024-07-24T02:45:44.578Z][TRACE][T0][#0] elf range = VMRange { start: 0x7f8706800000, end: 0x7f8706c00000, size: 0x400000 }
[2024-07-24T02:45:44.578Z][TRACE][T0][#0] find free range, free list = [VMRange { start: 0x7f87063ad000, end: 0x7f8706400000, size: 0x53000 }, VMRange { start: 0x7f8706c00000, end: 0x7f8718fad000, size: 0x123ad000 }]
[2024-07-24T02:45:44.578Z][TRACE][T0][#0] after find free range, free list = [VMRange { start: 0x7f87063ad000, end: 0x7f8706400000, size: 0x53000 }, VMRange { start: 0x7f8708c00000, end: 0x7f8718fad000, size: 0x103ad000 }]
[2024-07-24T02:45:44.578Z][TRACE][T0][#0] allocate a new single vma chunk: range = VMRange { start: 0x7f8706c00000, end: 0x7f8708c00000, size: 0x2000000 }, Single VMA chunk: SgxMutex { data: VMArea { range: VMRange { start: 0x7f8706c00000, end: 0x7f8708c00000, size: 0x2000000 }, perms: READ | WRITE | DEFAULT, file_backed: None, pid: 0 }, poisoned: false, .. }
[2024-07-24T02:45:44.578Z][TRACE][T0][#0] heap range = VMRange { start: 0x7f8706c00000, end: 0x7f8708c00000, size: 0x2000000 }
[2024-07-24T02:45:44.578Z][TRACE][T0][#0] find free range, free list = [VMRange { start: 0x7f87063ad000, end: 0x7f8706400000, size: 0x53000 }, VMRange { start: 0x7f8708c00000, end: 0x7f8718fad000, size: 0x103ad000 }]
[2024-07-24T02:45:44.578Z][TRACE][T0][#0] after find free range, free list = [VMRange { start: 0x7f87063ad000, end: 0x7f8706400000, size: 0x53000 }, VMRange { start: 0x7f8709000000, end: 0x7f8718fad000, size: 0xffad000 }]
[2024-07-24T02:45:44.578Z][TRACE][T0][#0] allocate a new single vma chunk: range = VMRange { start: 0x7f8708c00000, end: 0x7f8709000000, size: 0x400000 }, Single VMA chunk: SgxMutex { data: VMArea { range: VMRange { start: 0x7f8708c00000, end: 0x7f8709000000, size: 0x400000 }, perms: READ | WRITE | DEFAULT, file_backed: None, pid: 0 }, poisoned: false, .. }
[2024-07-24T02:45:44.578Z][TRACE][T0][#0] stack range = VMRange { start: 0x7f8708c00000, end: 0x7f8709000000, size: 0x400000 }
[2024-07-24T02:45:44.578Z][TRACE][T0][#0] new process sigmask = SigSet { [] }
[2024-07-24T02:45:44.578Z][TRACE][T0][#0] new process sig_dispositions = SigDispositions (only none-default is shown) {}
[2024-07-24T02:45:44.578Z][DEBUG][T0][#0] process group:ProcessGrp { inner: RwLock { inner: RwLockInner { status: AtomicRwLockStatus(0), rw_waiters: 0 }, data: PgrpInner { pgid: 1, process_group: {1: Process { pid: 1, exec_path: "/bin/init", ppid: Some(0), pgid: 1, inner: ProcessInner::Live { status: Running, child_pids: [], thread_tids: [1] } }}, leader_process: Some(Process { pid: 1, exec_path: "/bin/init", ppid: Some(0), pgid: 1, inner: ProcessInner::Live { status: Running, child_pids: [], thread_tids: [1] } }) } } }
[2024-07-24T02:45:44.578Z][DEBUG][T0][#0] non idle process all pgrp: [ProcessGrp { inner: RwLock { inner: RwLockInner { status: AtomicRwLockStatus(0), rw_waiters: 0 }, data: PgrpInner { pgid: 0, process_group: {}, leader_process: Some(Process { pid: 0, exec_path: "", ppid: None, pgid: 0, inner: ProcessInner::Live { status: Running, child_pids: [1], thread_tids: [0] } }) } } }, ProcessGrp { inner: RwLock { inner: RwLockInner { status: AtomicRwLockStatus(0), rw_waiters: 0 }, data: PgrpInner { pgid: 1, process_group: {1: Process { pid: 1, exec_path: "/bin/init", ppid: Some(0), pgid: 1, inner: ProcessInner::Live { status: Running, child_pids: [], thread_tids: [1] } }}, leader_process: Some(Process { pid: 1, exec_path: "/bin/init", ppid: Some(0), pgid: 1, inner: ProcessInner::Live { status: Running, child_pids: [], thread_tids: [1] } }) } } }]
[2024-07-24T02:45:44.578Z][ INFO][T0][#0] Process created: elf = /bin/init, pid = 1

HyperEnclave / hyperenclave

Stuck while running the occlum demo hello_c on Intel CPU with fake TPM #19