zynqmp: 'rcu: INFO: rcu_sched detected stalls on CPUs/tasks' when OP-TEE is enabled
Closed this issue · 8 comments
ricardosalveti commented
(see #218 (comment), the issue here is ATF/trusted ram related instead)
uz3eg-iocc build https://ci.foundries.io/projects/lmp/builds/1069/other-uz3eg-iocc/artifacts/lmp-base-console-image-uz3eg-iocc.wic.gz works correctly, and the kernel is able to boot without any issues. This build uses SPL -> ATF -> U-Boot proper -> kernel/initramfs fitImage.
Once OP-TEE is enabled (without really doing much), the kernel fails to boot fully as the system stalls, giving a ton of 'rcu_sched detected stalls' messages. This behavior seems similar to https://forums.xilinx.com/t5/Embedded-Linux/zynqmp-rcu-INFO-rcu-sched-detected-stalls-on-CPUs-tasks/td-p/939934, but in that case OP-TEE doesn't seems to be enabled, so while similar it might not be the same.
Boot log without OP-TEE:
U-Boot SPL 2020.01 (Jan 01 1970 - 00:00:00 +0000)
PMUFW: v1.1
Loading new PMUFW cfg obj (2184 bytes)
EL Level: EL3
Multiboot: 0
Trying to boot from MMC2
spl_load_image_fat_os: error reading image u-boot.bin, err - -2
## Checking hash(es) for Image atf ... sha256+ OK
## Checking hash(es) for Image uboot ... sha256+ OK
## Checking hash(es) for Image ubootfdt ... sha256+ OK
## Checking hash(es) for Image optee ... sha256+ OK
NOTICE: ATF running on XCZU3EG/silicon v4/RTL5.1 at 0xfffea000
NOTICE: BL31: v2.2(release):xilinx_rebase_v2.2_2020.1
NOTICE: BL31: Built : 00:00:00, Jan 1 1970
U-Boot 2020.01 (Jan 01 1970 - 00:00:00 +0000)
Model: Avnet XCZU3EG-SFVA625 SoM
Board: Xilinx ZynqMP
DRAM: 2 GiB
PMUFW: v1.1
EL Level: EL2
Chip ID: zu3eg
NAND: 0 MiB
MMC: mmc@ff160000: 1, mmc@ff170000: 0
Loading Environment from FAT... *** Warning - bad CRC, using default environment
In: serial@ff000000
Out: serial@ff000000
Err: serial@ff000000
Bootmode: SD_MODE1
Reset reason: EXTERNAL
Net:
ZYNQ GEM: ff0e0000, mdio bus ff0e0000, phyaddr 9, interface rgmii-id
Warning: ethernet@ff0e0000 using MAC address from DT
eth0: ethernet@ff0e0000
Hit any key to stop autoboot: 0
3335 bytes read in 17 ms (191.4 KiB/s)
## Executing script at 21000000
sha256+ Using system-top.dtb
Saving Environment to FAT... sdhci_send_command: MMC: 0 busy timeout increasing to: 200 ms.
OK
358 bytes read in 21 ms (16.6 KiB/s)
11910574 bytes read in 813 ms (14 MiB/s)
## Copying 'fdt@system-top.dtb' subimage from FIT image at 10000000 ...
sha256+ Loading part 253 ... OK
## Loading kernel from FIT Image at 10000000 ...
Using 'conf@system-top.dtb' configuration
Verifying Hash Integrity ... OK
Trying 'kernel@1' kernel subimage
Description: Linux kernel
Type: Kernel Image
Compression: gzip compressed
Data Start: 0x1000010c
Data Size: 8476332 Bytes = 8.1 MiB
Architecture: AArch64
OS: Linux
Load Address: 0x00080000
Entry Point: 0x00080000
Hash algo: sha256
Hash value: 7be88190a9908bb2340fa618308f67ee56da5fc7f231f8c6924feaa1e09c7032
Verifying Hash Integrity ... sha256+ OK
## Loading ramdisk from FIT Image at 10000000 ...
Using 'conf@system-top.dtb' configuration
Verifying Hash Integrity ... OK
Trying 'ramdisk@1' ramdisk subimage
Description: initramfs-ostree-lmp-image
Type: RAMDisk Image
Compression: uncompressed
Data Start: 0x108203d4
Data Size: 3388375 Bytes = 3.2 MiB
Architecture: AArch64
OS: Linux
Load Address: 0x20000000
Entry Point: unavailable
Hash algo: sha256
Hash value: 53c9453bc068b631ea7995335a2410b438ff87e565646ccd25fd386d521ac5ac
Verifying Hash Integrity ... sha256+ OK
Loading ramdisk from 0x108203d4 to 0x20000000
## Flattened Device Tree blob at 1f000000
Booting using the fdt blob at 0x1f000000
Uncompressing Kernel Image
Loading Ramdisk to 58cc4000, end 58fff3d7 ... OK
Loading Device Tree to 000000000fff2000, end 000000000fffffff ... OK
Starting kernel ...
[ 0.000000] Booting Linux on physical CPU 0x0000000000 [0x410fd034]
[ 0.000000] Linux version 5.4.0-lmp-standard (oe-user@oe-host) (gcc version 10.2.0 (GCC)) #1 SMP PREEMPT Fri Oct 2 07:43:52 UTC 2020
[ 0.000000] Machine model: Avnet XCZU3EG-SFVA625 SoM
[ 0.000000] efi: Getting EFI parameters from FDT:
[ 0.000000] efi: UEFI not found.
[ 0.000000] cma: Reserved 256 MiB at 0x000000006fc00000
[ 0.000000] psci: probing for conduit method from DT.
[ 0.000000] psci: PSCIv1.1 detected in firmware.
[ 0.000000] psci: Using standard PSCI v0.2 function IDs
[ 0.000000] psci: MIGRATE_INFO_TYPE not supported.
[ 0.000000] psci: SMC Calling Convention v1.1
[ 0.000000] percpu: Embedded 31 pages/cpu s87384 r8192 d31400 u126976
[ 0.000000] Detected VIPT I-cache on CPU0
[ 0.000000] CPU features: detected: ARM erratum 845719
[ 0.000000] Speculative Store Bypass Disable mitigation not required
[ 0.000000] Built 1 zonelists, mobility grouping on. Total pages: 515844
[ 0.000000] Kernel command line: console=ttyPS0,115200 root=LABEL=otaroot rootfstype=ext4 ostree=/ostree/boot.1/lmp/8f7cbbc49cdf3400
b55f2a3b27bf14a7125c7fb8f7afee130ce9378dea879677/0
[ 0.000000] Dentry cache hash table entries: 262144 (order: 9, 2097152 bytes, linear)
[ 0.000000] Inode-cache hash table entries: 131072 (order: 8, 1048576 bytes, linear)
[ 0.000000] mem auto-init: stack:off, heap alloc:off, heap free:off
[ 0.000000] Memory: 1768032K/2096128K available (12348K kernel code, 1438K rwdata, 3456K rodata, 4224K init, 423K bss, 65952K reserv
ed, 262144K cma-reserved)
[ 0.000000] random: get_random_u64 called from __kmem_cache_create+0x50/0x5dc with crng_init=0
[ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1
[ 0.000000] ftrace: allocating 39722 entries in 156 pages
[ 0.000000] rcu: Preemptible hierarchical RCU implementation.
[ 0.000000] rcu: RCU restricting CPUs from NR_CPUS=256 to nr_cpu_ids=4.
[ 0.000000] 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: Adjusting CPU interface base to 0x00000000f902f000
[ 0.000000] GIC: Using split EOI/Deactivate mode
[ 0.000000] arch_timer: cp15 timer(s) running at 99.99MHz (phys).
[ 0.000000] clocksource: arch_sys_counter: mask: 0xffffffffffffff max_cycles: 0x171015c90f, max_idle_ns: 440795203080 ns
[ 0.000004] sched_clock: 56 bits at 99MHz, resolution 10ns, wraps every 4398046511101ns
[ 0.000217] Console: colour dummy device 80x25
[ 0.000246] Calibrating delay loop (skipped), value calculated using timer frequency.. 199.99 BogoMIPS (lpj=399996)
[ 0.000256] pid_max: default: 32768 minimum: 301
[ 0.000390] LSM: Security Framework initializing
[ 0.000465] Mount-cache hash table entries: 4096 (order: 3, 32768 bytes, linear)
[ 0.000483] Mountpoint-cache hash table entries: 4096 (order: 3, 32768 bytes, linear)
[ 0.024029] ASID allocator initialised with 32768 entries
[ 0.032023] rcu: Hierarchical SRCU implementation.
[ 0.041594] EFI services will not be available.
[ 0.048057] smp: Bringing up secondary CPUs ...
[ 0.080217] Detected VIPT I-cache on CPU1
[ 0.080261] CPU1: Booted secondary processor 0x0000000001 [0x410fd034]
[ 0.112258] Detected VIPT I-cache on CPU2
[ 0.112283] CPU2: Booted secondary processor 0x0000000002 [0x410fd034]
[ 0.144329] Detected VIPT I-cache on CPU3
[ 0.144354] CPU3: Booted secondary processor 0x0000000003 [0x410fd034]
[ 0.144442] smp: Brought up 1 node, 4 CPUs
[ 0.144460] SMP: Total of 4 processors activated.
[ 0.144467] CPU features: detected: 32-bit EL0 Support
[ 0.144475] CPU features: detected: CRC32 instructions
[ 0.144516] CPU: All CPU(s) started at EL2
[ 0.144536] alternatives: patching kernel code
[ 0.145726] devtmpfs: initialized
[ 0.152435] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645041785100000 ns
[ 0.152453] futex hash table entries: 1024 (order: 4, 65536 bytes, linear)
[ 0.159841] pinctrl core: initialized pinctrl subsystem
[ 0.160546] DMI not present or invalid.
[ 0.160895] NET: Registered protocol family 16
[ 0.173501] DMA: preallocated 256 KiB pool for atomic allocations
[ 0.173926] cpuidle: using governor menu
[ 0.174091] hw-breakpoint: found 6 breakpoint and 4 watchpoint registers.
[ 0.190771] HugeTLB registered 1.00 GiB page size, pre-allocated 0 pages
[ 0.190781] HugeTLB registered 32.0 MiB page size, pre-allocated 0 pages
[ 0.190788] HugeTLB registered 2.00 MiB page size, pre-allocated 0 pages
[ 0.190795] HugeTLB registered 64.0 KiB page size, pre-allocated 0 pages
[ 0.194432] cryptd: max_cpu_qlen set to 1000
[ 0.201008] iommu: Default domain type: Translated
[ 0.201143] vgaarb: loaded
[ 0.201471] SCSI subsystem initialized
[ 0.204706] usbcore: registered new interface driver usbfs
[ 0.204749] usbcore: registered new interface driver hub
[ 0.204791] usbcore: registered new device driver usb
[ 0.204861] mc: Linux media interface: v0.10
[ 0.204886] videodev: Linux video capture interface: v2.00
[ 0.204912] pps_core: LinuxPPS API ver. 1 registered
[ 0.204918] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti <giometti@linux.it>
[ 0.204933] PTP clock support registered
[ 0.205067] EDAC MC: Ver: 3.0.0
[ 0.209023] zynqmp-ipi-mbox mailbox@ff990400: Registered ZynqMP IPI mbox with TX/RX channels.
[ 0.209324] FPGA manager framework
[ 0.209549] Advanced Linux Sound Architecture Driver Initialized.
[ 0.209967] Bluetooth: Core ver 2.22
[ 0.210007] NET: Registered protocol family 31
[ 0.210013] Bluetooth: HCI device and connection manager initialized
[ 0.210025] Bluetooth: HCI socket layer initialized
[ 0.210035] Bluetooth: L2CAP socket layer initialized
[ 0.210053] Bluetooth: SCO socket layer initialized
[ 0.210462] clocksource: Switched to clocksource arch_sys_counter
[ 0.910694] NET: Registered protocol family 2
[ 0.911225] tcp_listen_portaddr_hash hash table entries: 1024 (order: 2, 16384 bytes, linear)
[ 0.911259] TCP established hash table entries: 16384 (order: 5, 131072 bytes, linear)
[ 0.911378] TCP bind hash table entries: 16384 (order: 6, 262144 bytes, linear)
[ 0.911632] TCP: Hash tables configured (established 16384 bind 16384)
[ 0.911748] UDP hash table entries: 1024 (order: 3, 32768 bytes, linear)
[ 0.911795] UDP-Lite hash table entries: 1024 (order: 3, 32768 bytes, linear)
[ 0.911985] NET: Registered protocol family 1
[ 0.912483] RPC: Registered named UNIX socket transport module.
[ 0.912490] RPC: Registered udp transport module.
[ 0.912496] RPC: Registered tcp transport module.
[ 0.912501] RPC: Registered tcp NFSv4.1 backchannel transport module.
[ 0.912515] PCI: CLS 0 bytes, default 64
[ 0.912688] Trying to unpack rootfs image as initramfs...
[ 1.095028] Freeing initrd memory: 3308K
[ 1.095615] hw perfevents: no interrupt-affinity property for /pmu, guessing.
[ 1.095922] hw perfevents: enabled with armv8_pmuv3 PMU driver, 7 counters available
[ 1.193488] Initialise system trusted keyrings
[ 1.193646] workingset: timestamp_bits=46 max_order=19 bucket_order=0
[ 1.200664] NFS: Registering the id_resolver key type
[ 1.200682] Key type id_resolver registered
[ 1.200688] Key type id_legacy registered
[ 1.200703] nfs4filelayout_init: NFSv4 File Layout Driver Registering...
[ 1.200735] jffs2: version 2.2. � 2001-2006 Red Hat, Inc.
[ 1.217897] NET: Registered protocol family 38
[ 1.217912] Key type asymmetric registered
[ 1.217919] Asymmetric key parser 'x509' registered
[ 1.217963] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 246)
[ 1.218090] io scheduler mq-deadline registered
[ 1.218098] io scheduler kyber registered
[ 1.220933] Serial: 8250/16550 driver, 4 ports, IRQ sharing disabled
[ 1.224583] cacheinfo: Unable to detect cache hierarchy for CPU 0
[ 1.231460] brd: module loaded
[ 1.239282] loop: module loaded
[ 1.241079] libphy: Fixed MDIO Bus: probed
[ 1.241110] tun: Universal TUN/TAP device driver, 1.6
[ 1.241231] CAN device driver interface
[ 1.242718] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver
[ 1.242737] ehci-pci: EHCI PCI platform driver
[ 1.242777] ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver
[ 1.242792] ohci-pci: OHCI PCI platform driver
[ 1.243111] usbcore: registered new interface driver usb-storage
[ 1.243189] usbcore: registered new interface driver usbserial_generic
[ 1.243217] usbserial: USB Serial support registered for generic
[ 1.244109] rtc_zynqmp ffa60000.rtc: registered as rtc0
[ 1.246425] device-mapper: ioctl: 4.41.0-ioctl (2019-09-16) initialised: dm-devel@redhat.com
[ 1.246711] EDAC MC: ECC not enabled
[ 1.246929] EDAC DEVICE0: Giving out device to module zynqmp-ocm-edac controller zynqmp_ocm: DEV ff960000.memory-controller (INTERRU
PT)
[ 1.247886] sdhci: Secure Digital Host Controller Interface driver
[ 1.247892] sdhci: Copyright(c) Pierre Ossman
[ 1.247927] sdhci-pltfm: SDHCI platform and OF driver helper
[ 1.248450] ledtrig-cpu: registered to indicate activity on CPUs
[ 1.248518] zynqmp_firmware_probe Platform Management API v1.1
[ 1.248526] zynqmp_firmware_probe Trustzone version v1.0
[ 1.252794] zynqmp-pinctrl firmware:zynqmp-firmware:pinctrl: zynqmp pinctrl initialized
[ 1.278737] usbcore: registered new interface driver usbhid
[ 1.278744] usbhid: USB HID core driver
[ 1.281414] ARM CCI_400_r1 PMU driver probed
[ 1.282133] fpga_manager fpga0: Xilinx ZynqMP FPGA Manager registered
[ 1.282430] usbcore: registered new interface driver snd-usb-audio
[ 1.283606] u32 classifier
[ 1.283613] input device check on
[ 1.283618] Actions configured
[ 1.284269] NET: Registered protocol family 10
[ 1.285203] Segment Routing with IPv6
[ 1.285263] sit: IPv6, IPv4 and MPLS over IPv4 tunneling driver
[ 1.285734] NET: Registered protocol family 17
[ 1.285746] can: controller area network core (rev 20170425 abi 9)
[ 1.285803] NET: Registered protocol family 29
[ 1.285811] can: raw protocol (rev 20170425)
[ 1.285817] can: broadcast manager protocol (rev 20170425 t)
[ 1.285827] can: netlink gateway (rev 20190810) max_hops=1
[ 1.285997] Key type dns_resolver registered
[ 1.286352] registered taskstats version 1
[ 1.286359] Loading compiled-in X.509 certificates
[ 1.306052] ff000000.serial: ttyPS0 at MMIO 0xff000000 (irq = 33, base_baud = 6249999) is a xuartps
[ 2.261881] printk: console [ttyPS0] enabled
[ 2.267021] ff010000.serial: ttyPS1 at MMIO 0xff010000 (irq = 34, base_baud = 6249999) is a xuartps
[ 2.276433] of-fpga-region fpga-full: FPGA Region probed
[ 2.283400] xilinx-zynqmp-dma fd500000.dma: ZynqMP DMA driver Probe success
[ 2.290621] xilinx-zynqmp-dma fd510000.dma: ZynqMP DMA driver Probe success
[ 2.297823] xilinx-zynqmp-dma fd520000.dma: ZynqMP DMA driver Probe success
[ 2.305037] xilinx-zynqmp-dma fd530000.dma: ZynqMP DMA driver Probe success
[ 2.312246] xilinx-zynqmp-dma fd540000.dma: ZynqMP DMA driver Probe success
[ 2.319452] xilinx-zynqmp-dma fd550000.dma: ZynqMP DMA driver Probe success
[ 2.326677] xilinx-zynqmp-dma fd560000.dma: ZynqMP DMA driver Probe success
[ 2.333882] xilinx-zynqmp-dma fd570000.dma: ZynqMP DMA driver Probe success
[ 2.341086] ahci-ceva fd0c0000.ahci: fd0c0000.ahci supply ahci not found, using dummy regulator
[ 2.349850] ahci-ceva fd0c0000.ahci: fd0c0000.ahci supply phy not found, using dummy regulator
[ 2.358542] ahci-ceva fd0c0000.ahci: fd0c0000.ahci supply target not found, using dummy regulator
[ 2.367568] ahci-ceva fd0c0000.ahci: AHCI 0001.0301 32 slots 2 ports 6 Gbps 0x3 impl platform mode
[ 2.376530] ahci-ceva fd0c0000.ahci: flags: 64bit ncq sntf pm clo only pmp fbs pio slum part ccc sds apst
[ 2.388133] scsi host0: ahci-ceva
[ 2.391934] scsi host1: ahci-ceva
[ 2.395424] ata1: SATA max UDMA/133 mmio [mem 0xfd0c0000-0xfd0c1fff] port 0x100 irq 30
[ 2.403340] ata2: SATA max UDMA/133 mmio [mem 0xfd0c0000-0xfd0c1fff] port 0x180 irq 30
[ 2.413601] macb ff0e0000.ethernet: Not enabling partial store and forward
[ 2.421206] libphy: MACB_mii_bus: probed
[ 2.429230] TI DP83867 ff0e0000.ethernet-ffffffff:09: attached PHY driver [TI DP83867] (mii_bus:phy_addr=ff0e0000.ethernet-ffffffff:
09, irq=POLL)
[ 2.442277] macb ff0e0000.ethernet eth0: Cadence GEM rev 0x50070106 at 0xff0e0000 irq 22 (00:0a:35:00:02:90)
[ 2.452599] xilinx-axipmon ffa00000.perf-monitor: Probed Xilinx APM
[ 2.459257] xilinx-axipmon fd0b0000.perf-monitor: Probed Xilinx APM
[ 2.465854] xilinx-axipmon fd490000.perf-monitor: Probed Xilinx APM
[ 2.472453] xilinx-axipmon ffa10000.perf-monitor: Probed Xilinx APM
[ 2.480752] dwc3 fe200000.dwc3: Failed to get clk 'ref': -2
[ 2.487804] xilinx-psgtr fd400000.zynqmp_phy: PLL lock time out
[ 2.493724] xilinx-psgtr fd400000.zynqmp_phy: Lane:2 type:0 protocol:3 pll_locked:no
[ 2.501465] phy phy-fd400000.zynqmp_phy.2: phy init failed --> -110
[ 2.507731] dwc3 fe200000.dwc3: failed to initialize core: -110
[ 2.513686] dwc3: probe of fe200000.dwc3 failed with error -110
[ 2.520852] zynqmp_pll_disable() clock disable failed for apll_int, ret = -13
[ 2.528874] at24 2-0051: 1024 byte 24c08 EEPROM, writable, 1 bytes/write
[ 2.535620] i2c i2c-0: Added multiplexed i2c bus 2
[ 2.540812] i2c i2c-0: Added multiplexed i2c bus 3
[ 2.545608] pca954x 0-0070: registered 2 multiplexed busses for I2C switch pca9543
[ 2.553206] cdns-i2c ff030000.i2c: 400 kHz mmio ff030000 irq 24
[ 2.559555] cdns-wdt fd4d0000.watchdog: Xilinx Watchdog Timer with timeout 60s
[ 2.567471] cpufreq: cpufreq_online: CPU0: Running at unlisted freq: 1099999 KHz
[ 2.574929] cpufreq: cpufreq_online: CPU0: Unlisted initial frequency changed to: 1199999 KHz
[ 2.617063] mmc0: SDHCI controller on ff160000.mmc [ff160000.mmc] using ADMA 64-bit
[ 2.659976] mmc1: SDHCI controller on ff170000.mmc [ff170000.mmc] using ADMA 64-bit
[ 2.674074] rtc_zynqmp ffa60000.rtc: setting system clock to 1970-01-01T00:00:06 UTC (6)
[ 2.682171] of_cfs_init
[ 2.684712] of_cfs_init: OK
[ 2.688904] ALSA device list:
[ 2.691871] No soundcards found.
[ 2.693599] mmc0: new HS200 MMC card at address 0001
[ 2.701020] mmcblk0: mmc0:0001 Q2J55L 7.09 GiB
[ 2.705833] mmcblk0boot0: mmc0:0001 Q2J55L partition 1 16.0 MiB
[ 2.712051] mmcblk0boot1: mmc0:0001 Q2J55L partition 2 16.0 MiB
[ 2.718129] mmcblk0rpmb: mmc0:0001 Q2J55L partition 3 4.00 MiB, chardev (243:0)
[ 2.725034] ata1: SATA link down (SStatus 0 SControl 330)
[ 2.730905] ata2: SATA link down (SStatus 0 SControl 330)
[ 2.731054] mmcblk0: p1
[ 2.740678] mmc1: new high speed SDHC card at address 5048
[ 2.744839] Freeing unused kernel memory: 4224K
[ 2.747525] mmcblk1: mmc1:5048 DDINC 14.9 GiB
[ 2.758478] mmcblk1: p1 p2
[ 2.770544] Run /init as init process
Starting version 246.2+
[ 3.109986] random: fast init done
[ 3.957557] e2fsck: otaroot: clean, 11250/44352 files, 143281/177233 blocks
[ 4.046569] EXT4-fs (mmcblk1p2): mounted filesystem with ordered data mode. Opts: (null)
[ 4.608297] systemd[1]: systemd 246.2+ running in system mode. (+PAM -AUDIT -SELINUX +IMA -APPARMOR -SMACK +SYSVINIT +UTMP -LIBCRYPT
SETUP -GCRYPT -GNUTLS +ACL +XZ -LZ4 -ZSTD +SECCOMP +BLKID -ELFUTILS +KMOD -IDN2 -IDN -PCRE2 default-hierarchy=hybrid)
[ 4.630880] systemd[1]: Detected architecture arm64.
Welcome to Linux-microPlatform 3.1-1069-74-8-g95e1914!
[ 4.696229] systemd[1]: Set hostname to <uz3eg-iocc>.
[ 4.708700] random: systemd: uninitialized urandom read (16 bytes read)
[ 4.715426] systemd[1]: Initializing machine ID from random generator.
[ 5.534923] systemd[1]: /usr/lib/systemd/system/docker.socket:6: ListenStream= references a path below legacy directory /var/run/, u
pdating /var/run/docker.sock � /run/docker.sock; please update the unit file accordingly.
[ 5.625946] systemd[1]: /usr/lib/systemd/system/ostree-remount.service:38: Standard output type syslog is obsolete, automatically up
dating to journal. Please update your unit file, and consider removing the setting altogether.
[ 5.646131] systemd[1]: /usr/lib/systemd/system/ostree-remount.service:39: Standard output type syslog+console is obsolete, automati
cally updating to journal+console. Please update your unit file, and consider removing the setting altogether.
[ 5.688494] systemd[1]: /usr/lib/systemd/system/pcscd.socket:5: ListenStream= references a path below legacy directory /var/run/, up
dating /var/run/pcscd/pcscd.comm � /run/pcscd/pcscd.comm; please update the unit file accordingly.
[ 5.719911] systemd[1]: Queued start job for default target Multi-User System.
[ 5.728401] random: systemd: uninitialized urandom read (16 bytes read)
[ 5.738548] systemd[1]: Created slice system-getty.slice.
[ OK ] Created slice system-getty.slice.
[ 5.758911] random: systemd: uninitialized urandom read (16 bytes read)
[ 5.770795] systemd[1]: Created slice system-modprobe.slice.
[ OK ] Created slice system-modprobe.slice.
[ 5.790637] random: systemd: uninitialized urandom read (16 bytes read)
[ 5.800070] systemd[1]: Created slice system-serial\x2dgetty.slice.
[ OK ] Created slice system-serial\x2dgetty.slice.
[ 5.829171] systemd[1]: Created slice User and Session Slice.
[ OK ] Created slice User and Session Slice.
[ 5.851702] systemd[1]: Started Dispatch Password Requests to Console Directory Watch.
[ OK ] Started Dispatch Password &ts to Console Directory Watch.
[ 5.875231] systemd[1]: Started Forward Password Requests to Wall Directory Watch.
[ OK ] Started Forward Password R&uests to Wall Directory Watch.
[ 5.899658] systemd[1]: Reached target Remote File Systems.
[ OK ] Reached target Remote File Systems.
[ 5.922966] systemd[1]: Reached target Slices.
[ OK ] Reached target Slices.
[ 5.938900] systemd[1]: Reached target Swap.
[ OK ] Reached target Swap.
[ 5.955310] systemd[1]: Listening on initctl Compatibility Named Pipe.
[ OK ] Listening on initctl Compatibility Named Pipe.
[ 6.024872] systemd[1]: Condition check resulted in Journal Audit Socket being skipped.
[ 6.033896] systemd[1]: Listening on Journal Socket (/dev/log).
[ OK ] Listening on Journal Socket (/dev/log).
[ 6.056483] systemd[1]: Listening on Journal Socket.
[ OK ] Listening on Journal Socket.
[ 6.071573] systemd[1]: Listening on udev Control Socket.
[ OK ] Listening on udev Control Socket.
[ 6.095226] systemd[1]: Listening on udev Kernel Socket.
[ OK ] Listening on udev Kernel Socket.
[ 6.115695] systemd[1]: Listening on User Database Manager Socket.
[ OK ] Listening on User Database Manager Socket.
[ 6.148558] systemd[1]: Mounting Huge Pages File System...
Mounting Huge Pages File System...
[ 6.166683] systemd[1]: Mounting POSIX Message Queue File System...
Mounting POSIX Message Queue File System...
[ 6.203360] systemd[1]: Mounting Kernel Debug File System...
Mounting Kernel Debug File System...
[ 6.225944] systemd[1]: Mounting Kernel Trace File System...
Mounting Kernel Trace File System...
[ 6.247520] systemd[1]: Mounting Temporary Directory (/tmp)...
Mounting Temporary Directory (/tmp)...
[ 6.267606] systemd[1]: Starting Create list of static device nodes for the current kernel...
Starting Create list of st&odes for the current kernel...
[ 6.290803] systemd[1]: Condition check resulted in Load Kernel Module drm being skipped.
[ 6.299647] systemd[1]: Condition check resulted in File System Check on Root Device being skipped.
[ 6.314711] systemd[1]: Starting Journal Service...
Starting Journal Service...
[ 6.332662] systemd[1]: Condition check resulted in Load Kernel Modules being skipped.
[ 6.341158] systemd[1]: Condition check resulted in FUSE Control File System being skipped.
[ 6.354022] systemd[1]: Mounting Kernel Configuration File System...
Mounting Kernel Configuration File System...
[ 6.378719] systemd[1]: Starting Remount Root and Kernel File Systems...
Starting Remount Root and Kernel File Systems...
[ 6.402779] EXT4-fs (mmcblk1p2): re-mounted. Opts: (null)
[ 6.407551] systemd[1]: Starting Apply Kernel Variables...
Starting Apply Kernel Variables...
[ 6.427024] systemd[1]: Starting Coldplug All udev Devices...
Starting Coldplug All udev Devices...
[ 6.450928] systemd[1]: Mounted Huge Pages File System.
[ OK ] Mounted Huge Pages File System.
[ 6.471075] systemd[1]: Started Journal Service.
[ OK ] Started Journal Service.
[ OK ] Mounted POSIX Message Queue File System.
[ OK ] Mounted Kernel Debug File System.
[ OK ] Mounted Kernel Trace File System.
[ OK ] Mounted Temporary Directory (/tmp).
[ OK ] Finished Create list of st& nodes for the current kernel.
[ OK ] Mounted Kernel Configuration File System.
[ OK ] Finished Remount Root and Kernel File Systems.
[ OK ] Finished Apply Kernel Variables.
Starting Create System Users...
[ OK ] Finished Create System Users.
Starting Create Static Device Nodes in /dev...
[ OK ] Finished Create Static Device Nodes in /dev.
[ OK ] Finished Coldplug All udev Devices.
[ OK ] Reached target Local File Systems (Pre).
Mounting /var...
Starting Rule-based Manage&for Device Events and Files...
[ OK ] Mounted /var.
Mounting /var/volatile...
Starting OSTree Remount OS/ Bind Mounts...
[ OK ] Mounted /var/volatile.
[ OK ] Finished OSTree Remount OS/ Bind Mounts.
Starting Flush Journal to Persistent Storage...
Starting Load/Save Random Seed...
[ OK ] Finished Flush Journal to Persistent Storage.
[ OK ] Started Rule-based Manager for Device Events and Files.
[ OK ] Found device /dev/ttyPS0.
[ OK ] Found device /dev/disk/by-label/boot.
[ OK ] Listening on Load/Save RF &itch Status /dev/rfkill Watch.
Mounting /var/rootdirs/mnt/boot...
[ OK ] Mounted /var/rootdirs/mnt/boot.
[ OK ] Reached target Local File Systems.
[ OK ] Started Systemd Timesync Update Fixes.
Starting Create Volatile Files and Directories...
[ OK ] Finished Create Volatile Files and Directories.
[ OK ] Started Hardware RNG Entropy Gatherer Daemon.
Starting Run pending postinsts...
Starting Rebuild Journal Catalog...
Starting Network Name Resolution...
Starting Network Time Synchronization...
Starting Update UTMP about System Boot/Shutdown...
[ OK ] Finished Update UTMP about System Boot/Shutdown.
[ OK ] Finished Rebuild Journal Catalog.
[ OK ] Finished Run pending postinsts.
Starting Update is Completed...
[ OK ] Finished Update is Completed.
[ OK ] Started Network Name Resolution.
[ OK ] Reached target Host and Network Name Lookups.
[ OK ] Started Network Time Synchronization.
[ OK ] Reached target System Initialization.
[ OK ] Started Aktualizr Lite SOTA Client path monitor.
[ OK ] Started OSTree Monitor Staged Deployment.
[ OK ] Started Daily Cleanup of Temporary Directories.
[ OK ] Reached target Paths.
[ OK ] Reached target System Time Set.
[ OK ] Reached target System Time Synchronized.
[ OK ] Reached target Timers.
[ OK ] Listening on Avahi mDNS/DNS-SD Stack Activation Socket.
[ OK ] Listening on D-Bus System Message Bus Socket.
Starting Docker Socket for the API.
[ OK ] Listening on PC/SC Smart Card Daemon Activation Socket.
Starting sshd.socket.
[ OK ] Listening on Docker Socket for the API.
[ OK ] Listening on sshd.socket.
[ OK ] Reached target Sockets.
[ OK ] Reached target Basic System.
Starting Avahi mDNS/DNS-SD Stack...
[ OK ] Started D-Bus System Message Bus.
Starting IPv6 Packet Filtering Framework...
Starting IPv4 Packet Filtering Framework...
Starting Resize root files&to fit available disk space...
Starting OpenSSH Key Generation...
Starting User Login Management...
[ OK ] Started TEE Supplicant.
[ OK ] Finished IPv6 Packet Filtering Framework.
[ OK ] Finished IPv4 Packet Filtering Framework.
[ OK ] Reached target Network (Pre).
Starting Network Manager...
[ OK ] Started Avahi mDNS/DNS-SD Stack.
[ OK ] Started User Login Management.
[ OK ] Started Network Manager.
[ OK ] Reached target Network.
Starting Network Manager Wait Online...
[ OK ] Started Respond to IPv6 Node Information Queries.
[ OK ] Started Network Router Discovery Daemon.
Starting Permit User Sessions...
Starting Hostname Service...
[ OK ] Finished Permit User Sessions.
[ OK ] Started Getty on tty1.
[ OK ] Started Serial Getty on ttyPS0.
[ OK ] Reached target Login Prompts.
[ 9.326659] random: crng init done
[ 9.330058] random: 6 urandom warning(s) missed due to ratelimiting
[ OK ] Finished Load/Save Random Seed.
[ 9.974841] EXT4-fs (mmcblk1p2): resizing filesystem from 177233 to 3903488 blocks
[ OK ] Started Hostname Service.
Starting Network Manager Script Dispatcher Service...
[ OK ] Started Network Manager Script Dispatcher Service.
[ 12.541359] macb ff0e0000.ethernet eth0: link up (1000/Full)
[ 12.548161] pps pps0: new PPS source ptp0
[ 12.553763] macb ff0e0000.ethernet: gem-ptp-timer ptp clock registered.
[ 12.566791] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
[ 13.226998] EXT4-fs (mmcblk1p2): resized filesystem to 3903488
Linux-microPlatform 3.1-1069-74-8-g95e1914 uz3eg-iocc ttyPS0
uz3eg-iocc login:
Boot log with OP-TEE enabled:
U-Boot SPL 2020.01 (Jan 01 1970 - 00:00:00 +0000)
PMUFW: v1.1
Loading new PMUFW cfg obj (2184 bytes)
EL Level: EL3
Multiboot: 0
Trying to boot from MMC2
spl_load_image_fat_os: error reading image u-boot.bin, err - -2
## Checking hash(es) for Image atf ... sha256+ OK
## Checking hash(es) for Image uboot ... sha256+ OK
## Checking hash(es) for Image ubootfdt ... sha256+ OK
## Checking hash(es) for Image optee ... sha256+ OK
NOTICE: ATF running on XCZU3EG/silicon v4/RTL5.1 at 0x1000
NOTICE: BL31: v2.2(release):xilinx_rebase_v2.2_2020.1
NOTICE: BL31: Built : 00:00:00, Jan 1 1970
I/TC:
I/TC: Non-secure external DT found
I/TC: OP-TEE version: 3.10.0-52-g9393a879 (gcc version 10.2.0 (GCC)) #1 Thu Jan 1 00:00:00 UTC 1970 aarch64
I/TC: Primary CPU initializing
I/TC: Primary CPU switching to normal world boot
U-Boot 2020.01 (Jan 01 1970 - 00:00:00 +0000)
Model: Avnet XCZU3EG-SFVA625 SoM
Board: Xilinx ZynqMP
DRAM: 2 GiB
PMUFW: v1.1
EL Level: EL2
Chip ID: zu3eg
NAND: 0 MiB
MMC: mmc@ff160000: 1, mmc@ff170000: 0
Loading Environment from FAT... OK
In: serial@ff000000
Out: serial@ff000000
Err: serial@ff000000
Net:
ZYNQ GEM: ff0e0000, mdio bus ff0e0000, phyaddr 9, interface rgmii-id
eth0: ethernet@ff0e0000
Hit any key to stop autoboot: 0
3343 bytes read in 17 ms (191.4 KiB/s)
## Executing script at 21000000
sha256+ Using system-top.dtb
358 bytes read in 22 ms (15.6 KiB/s)
11910574 bytes read in 813 ms (14 MiB/s)
## Copying 'fdt@system-top.dtb' subimage from FIT image at 10000000 ...
sha256+ Loading part 253 ... OK
## Loading kernel from FIT Image at 10000000 ...
Using 'conf@system-top.dtb' configuration
Verifying Hash Integrity ... OK
Trying 'kernel@1' kernel subimage
Description: Linux kernel
Type: Kernel Image
Compression: gzip compressed
Data Start: 0x1000010c
Data Size: 8476332 Bytes = 8.1 MiB
Architecture: AArch64
OS: Linux
Load Address: 0x00080000
Entry Point: 0x00080000
Hash algo: sha256
Hash value: 7be88190a9908bb2340fa618308f67ee56da5fc7f231f8c6924feaa1e09c7032
Verifying Hash Integrity ... sha256+ OK
## Loading ramdisk from FIT Image at 10000000 ...
Using 'conf@system-top.dtb' configuration
Verifying Hash Integrity ... OK
Trying 'ramdisk@1' ramdisk subimage
Description: initramfs-ostree-lmp-image
Type: RAMDisk Image
Compression: uncompressed
Data Start: 0x108203d4
Data Size: 3388375 Bytes = 3.2 MiB
Architecture: AArch64
OS: Linux
Load Address: 0x20000000
Entry Point: unavailable
Hash algo: sha256
Hash value: 53c9453bc068b631ea7995335a2410b438ff87e565646ccd25fd386d521ac5ac
Verifying Hash Integrity ... sha256+ OK
Loading ramdisk from 0x108203d4 to 0x20000000
## Flattened Device Tree blob at 1f000000
Booting using the fdt blob at 0x1f000000
Uncompressing Kernel Image
Loading Ramdisk to 58cc4000, end 58fff3d7 ... OK
ERROR: reserving fdt memory region failed (addr=7fc00000 size=400000)
ERROR: reserving fdt memory region failed (addr=7e000000 size=1c00000)
Loading Device Tree to 000000007bdb5000, end 000000007bdc2fff ... OK
Starting kernel ...
I/TC: Secondary CPU 1 initializing
I/TC: Secondary CPU 1 switching to normal world boot
I/TC: Secondary CPU 2 initializing
I/TC: Secondary CPU 2 switching to normal world boot
I/TC: Secondary CPU 3 initializing
I/TC: Secondary CPU 3 switching to normal world boot
[ 0.000000] Booting Linux on physical CPU 0x0000000000 [0x410fd034]
[ 0.000000] Linux version 5.4.0-lmp-standard (oe-user@oe-host) (gcc version 10.2.0 (GCC)) #1 SMP PREEMPT Fri Oct 2 07:43:52 UTC 2020
[ 0.000000] Machine model: Avnet XCZU3EG-SFVA625 SoM
[ 0.000000] efi: Getting EFI parameters from FDT:
[ 0.000000] efi: UEFI not found.
[ 0.000000] cma: Reserved 256 MiB at 0x000000006bc00000
[ 0.000000] psci: probing for conduit method from DT.
[ 0.000000] psci: PSCIv1.1 detected in firmware.
[ 0.000000] psci: Using standard PSCI v0.2 function IDs
[ 0.000000] psci: Trusted OS migration not required
[ 0.000000] psci: SMC Calling Convention v1.1
[ 0.000000] percpu: Embedded 31 pages/cpu s87384 r8192 d31400 u126976
[ 0.000000] Detected VIPT I-cache on CPU0
[ 0.000000] CPU features: detected: ARM erratum 845719
[ 0.000000] Speculative Store Bypass Disable mitigation not required
[ 0.000000] Built 1 zonelists, mobility grouping on. Total pages: 508032
[ 0.000000] Kernel command line: console=ttyPS0,115200 root=LABEL=otaroot rootfstype=ext4 ostree=/ostree/boot.1/lmp/8f7cbbc49cdf3400
b55f2a3b27bf14a7125c7fb8f7afee130ce9378dea879677/0
[ 0.000000] Dentry cache hash table entries: 262144 (order: 9, 2097152 bytes, linear)
[ 0.000000] Inode-cache hash table entries: 131072 (order: 8, 1048576 bytes, linear)
[ 0.000000] mem auto-init: stack:off, heap alloc:off, heap free:off
[ 0.000000] Memory: 1736352K/2064384K available (12348K kernel code, 1438K rwdata, 3456K rodata, 4224K init, 423K bss, 65888K reserv
ed, 262144K cma-reserved)
[ 0.000000] random: get_random_u64 called from __kmem_cache_create+0x50/0x5dc with crng_init=0
[ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1
[ 0.000000] ftrace: allocating 39722 entries in 156 pages
[ 0.000000] rcu: Preemptible hierarchical RCU implementation.
[ 0.000000] rcu: RCU restricting CPUs from NR_CPUS=256 to nr_cpu_ids=4.
[ 0.000000] 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: Adjusting CPU interface base to 0x00000000f902f000
[ 0.000000] GIC: Using split EOI/Deactivate mode
[ 0.000000] arch_timer: cp15 timer(s) running at 99.99MHz (phys).
[ 0.000000] clocksource: arch_sys_counter: mask: 0xffffffffffffff max_cycles: 0x171015c90f, max_idle_ns: 440795203080 ns
[ 0.000004] sched_clock: 56 bits at 99MHz, resolution 10ns, wraps every 4398046511101ns
[ 0.000217] Console: colour dummy device 80x25
[ 0.000245] Calibrating delay loop (skipped), value calculated using timer frequency.. 199.99 BogoMIPS (lpj=399996)
[ 0.000255] pid_max: default: 32768 minimum: 301
[ 0.000388] LSM: Security Framework initializing
[ 0.000463] Mount-cache hash table entries: 4096 (order: 3, 32768 bytes, linear)
[ 0.000481] Mountpoint-cache hash table entries: 4096 (order: 3, 32768 bytes, linear)
[ 0.024028] ASID allocator initialised with 32768 entries
[ 0.032021] rcu: Hierarchical SRCU implementation.
[ 0.041588] EFI services will not be available.
[ 0.048055] smp: Bringing up secondary CPUs ...
[ 0.087940] Detected VIPT I-cache on CPU1
[ 0.087984] CPU1: Booted secondary processor 0x0000000001 [0x410fd034]
[ 0.127983] Detected VIPT I-cache on CPU2
[ 0.128009] CPU2: Booted secondary processor 0x0000000002 [0x410fd034]
[ 0.164054] Detected VIPT I-cache on CPU3
[ 0.164079] CPU3: Booted secondary processor 0x0000000003 [0x410fd034]
[ 0.164167] smp: Brought up 1 node, 4 CPUs
[ 0.164185] SMP: Total of 4 processors activated.
[ 0.164192] CPU features: detected: 32-bit EL0 Support
[ 0.164200] CPU features: detected: CRC32 instructions
[ 0.164242] CPU: All CPU(s) started at EL2
[ 0.164261] alternatives: patching kernel code
[ 0.165462] devtmpfs: initialized
[ 0.172178] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645041785100000 ns
[ 0.172197] futex hash table entries: 1024 (order: 4, 65536 bytes, linear)
[ 0.179569] pinctrl core: initialized pinctrl subsystem
[ 0.180213] DMI not present or invalid.
[ 0.180641] NET: Registered protocol family 16
[ 0.185875] DMA: preallocated 256 KiB pool for atomic allocations
[ 0.186352] cpuidle: using governor menu
[ 0.186526] hw-breakpoint: found 6 breakpoint and 4 watchpoint registers.
[ 0.203344] HugeTLB registered 1.00 GiB page size, pre-allocated 0 pages
[ 0.203354] HugeTLB registered 32.0 MiB page size, pre-allocated 0 pages
[ 0.203361] HugeTLB registered 2.00 MiB page size, pre-allocated 0 pages
[ 0.203368] HugeTLB registered 64.0 KiB page size, pre-allocated 0 pages
[ 0.206962] cryptd: max_cpu_qlen set to 1000
[ 0.216849] iommu: Default domain type: Translated
[ 0.216981] vgaarb: loaded
[ 0.217309] SCSI subsystem initialized
[ 0.217617] usbcore: registered new interface driver usbfs
[ 0.217662] usbcore: registered new interface driver hub
[ 0.217704] usbcore: registered new device driver usb
[ 0.217771] mc: Linux media interface: v0.10
[ 0.217797] videodev: Linux video capture interface: v2.00
[ 0.217823] pps_core: LinuxPPS API ver. 1 registered
[ 0.217829] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti <giometti@linux.it>
[ 0.217845] PTP clock support registered
[ 0.217979] EDAC MC: Ver: 3.0.0
[ 0.224473] zynqmp-ipi-mbox mailbox@ff990400: Registered ZynqMP IPI mbox with TX/RX channels.
[ 0.224740] FPGA manager framework
[ 0.224980] Advanced Linux Sound Architecture Driver Initialized.
[ 0.225407] Bluetooth: Core ver 2.22
[ 0.225437] NET: Registered protocol family 31
[ 0.225443] Bluetooth: HCI device and connection manager initialized
[ 0.225456] Bluetooth: HCI socket layer initialized
[ 0.225465] Bluetooth: L2CAP socket layer initialized
[ 0.225484] Bluetooth: SCO socket layer initialized
[ 0.225875] clocksource: Switched to clocksource arch_sys_counter
[ 0.925847] NET: Registered protocol family 2
[ 0.926384] tcp_listen_portaddr_hash hash table entries: 1024 (order: 2, 16384 bytes, linear)
[ 0.926421] TCP established hash table entries: 16384 (order: 5, 131072 bytes, linear)
[ 0.926546] TCP bind hash table entries: 16384 (order: 6, 262144 bytes, linear)
[ 0.926808] TCP: Hash tables configured (established 16384 bind 16384)
[ 0.926926] UDP hash table entries: 1024 (order: 3, 32768 bytes, linear)
[ 0.926973] UDP-Lite hash table entries: 1024 (order: 3, 32768 bytes, linear)
[ 0.927166] NET: Registered protocol family 1
[ 0.927640] RPC: Registered named UNIX socket transport module.
[ 0.927647] RPC: Registered udp transport module.
[ 0.927653] RPC: Registered tcp transport module.
[ 0.927658] RPC: Registered tcp NFSv4.1 backchannel transport module.
[ 0.927671] PCI: CLS 0 bytes, default 64
[ 0.927874] Trying to unpack rootfs image as initramfs...
[ 1.109830] Freeing initrd memory: 3308K
[ 1.110448] hw perfevents: no interrupt-affinity property for /pmu, guessing.
[ 1.110746] hw perfevents: enabled with armv8_pmuv3 PMU driver, 7 counters available
[ 1.207705] Initialise system trusted keyrings
[ 1.207861] workingset: timestamp_bits=46 max_order=19 bucket_order=0
[ 1.214836] NFS: Registering the id_resolver key type
[ 1.214856] Key type id_resolver registered
[ 1.214862] Key type id_legacy registered
[ 1.214876] nfs4filelayout_init: NFSv4 File Layout Driver Registering...
[ 1.214912] jffs2: version 2.2. � 2001-2006 Red Hat, Inc.
[ 1.231495] NET: Registered protocol family 38
[ 1.231509] Key type asymmetric registered
[ 1.231516] Asymmetric key parser 'x509' registered
[ 1.231556] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 246)
[ 1.231693] io scheduler mq-deadline registered
[ 1.231701] io scheduler kyber registered
[ 1.234566] Serial: 8250/16550 driver, 4 ports, IRQ sharing disabled
[ 1.238260] cacheinfo: Unable to detect cache hierarchy for CPU 0
[ 1.245139] brd: module loaded
[ 1.252971] loop: module loaded
[ 1.258748] libphy: Fixed MDIO Bus: probed
[ 1.258775] tun: Universal TUN/TAP device driver, 1.6
[ 1.258908] CAN device driver interface
[ 1.260386] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver
[ 1.260403] ehci-pci: EHCI PCI platform driver
[ 1.260443] ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver
[ 1.260458] ohci-pci: OHCI PCI platform driver
[ 1.260777] usbcore: registered new interface driver usb-storage
[ 1.260849] usbcore: registered new interface driver usbserial_generic
[ 1.260876] usbserial: USB Serial support registered for generic
[ 1.261775] rtc_zynqmp ffa60000.rtc: registered as rtc0
[ 1.264104] device-mapper: ioctl: 4.41.0-ioctl (2019-09-16) initialised: dm-devel@redhat.com
[ 1.264358] EDAC MC: ECC not enabled
[ 1.264578] EDAC DEVICE0: Giving out device to module zynqmp-ocm-edac controller zynqmp_ocm: DEV ff960000.memory-controller (INTERRU
PT)
[ 1.265505] sdhci: Secure Digital Host Controller Interface driver
[ 1.265511] sdhci: Copyright(c) Pierre Ossman
[ 1.265546] sdhci-pltfm: SDHCI platform and OF driver helper
[ 1.266112] ledtrig-cpu: registered to indicate activity on CPUs
[ 1.266179] zynqmp_firmware_probe Platform Management API v1.1
[ 1.266187] zynqmp_firmware_probe Trustzone version v1.0
[ 1.270459] zynqmp-pinctrl firmware:zynqmp-firmware:pinctrl: zynqmp pinctrl initialized
[ 1.296553] usbcore: registered new interface driver usbhid
[ 1.296559] usbhid: USB HID core driver
[ 1.299243] ARM CCI_400_r1 PMU driver probed
[ 1.300039] fpga_manager fpga0: Xilinx ZynqMP FPGA Manager registered
[ 1.300096] optee: probing for conduit method from DT.
[ 1.300117] optee: revision 3.10 (9393a879)
[ 1.300692] optee: initialized driver
[ 1.300927] usbcore: registered new interface driver snd-usb-audio
[ 1.302146] u32 classifier
[ 1.302152] input device check on
[ 1.302158] Actions configured
[ 1.302814] NET: Registered protocol family 10
[ 1.303642] Segment Routing with IPv6
[ 1.303702] sit: IPv6, IPv4 and MPLS over IPv4 tunneling driver
[ 1.304162] NET: Registered protocol family 17
[ 1.304175] can: controller area network core (rev 20170425 abi 9)
[ 1.304232] NET: Registered protocol family 29
[ 1.304240] can: raw protocol (rev 20170425)
[ 1.304247] can: broadcast manager protocol (rev 20170425 t)
[ 1.304257] can: netlink gateway (rev 20190810) max_hops=1
[ 1.304428] Key type dns_resolver registered
[ 1.304764] registered taskstats version 1
[ 1.304770] Loading compiled-in X.509 certificates
[ 1.324535] ff000000.serial: ttyPS0 at MMIO 0xff000000 (irq = 33, base_baud = 6249999) is a xuartps
[ 2.293430] printk: console [ttyPS0] enabled
[ 2.298662] ff010000.serial: ttyPS1 at MMIO 0xff010000 (irq = 34, base_baud = 6249999) is a xuartps
[ 2.308146] of-fpga-region fpga-full: FPGA Region probed
[ 2.315161] xilinx-zynqmp-dma fd500000.dma: ZynqMP DMA driver Probe success
[ 2.322383] xilinx-zynqmp-dma fd510000.dma: ZynqMP DMA driver Probe success
[ 2.329586] xilinx-zynqmp-dma fd520000.dma: ZynqMP DMA driver Probe success
[ 2.336800] xilinx-zynqmp-dma fd530000.dma: ZynqMP DMA driver Probe success
[ 2.344010] xilinx-zynqmp-dma fd540000.dma: ZynqMP DMA driver Probe success
[ 2.351211] xilinx-zynqmp-dma fd550000.dma: ZynqMP DMA driver Probe success
[ 2.358427] xilinx-zynqmp-dma fd560000.dma: ZynqMP DMA driver Probe success
[ 2.365623] xilinx-zynqmp-dma fd570000.dma: ZynqMP DMA driver Probe success
[ 2.372835] ahci-ceva fd0c0000.ahci: fd0c0000.ahci supply ahci not found, using dummy regulator
[ 2.381596] ahci-ceva fd0c0000.ahci: fd0c0000.ahci supply phy not found, using dummy regulator
[ 2.390273] ahci-ceva fd0c0000.ahci: fd0c0000.ahci supply target not found, using dummy regulator
[ 2.399302] ahci-ceva fd0c0000.ahci: AHCI 0001.0301 32 slots 2 ports 6 Gbps 0x3 impl platform mode
[ 2.408261] ahci-ceva fd0c0000.ahci: flags: 64bit ncq sntf pm clo only pmp fbs pio slum part ccc sds apst
[ 2.419760] scsi host0: ahci-ceva
[ 2.423741] scsi host1: ahci-ceva
[ 2.427230] ata1: SATA max UDMA/133 mmio [mem 0xfd0c0000-0xfd0c1fff] port 0x100 irq 30
[ 2.435148] ata2: SATA max UDMA/133 mmio [mem 0xfd0c0000-0xfd0c1fff] port 0x180 irq 30
[ 2.445529] macb ff0e0000.ethernet: Not enabling partial store and forward
[ 2.453139] libphy: MACB_mii_bus: probed
[ 2.461164] TI DP83867 ff0e0000.ethernet-ffffffff:09: attached PHY driver [TI DP83867] (mii_bus:phy_addr=ff0e0000.ethernet-ffffffff:
09, irq=POLL)
[ 2.474212] macb ff0e0000.ethernet eth0: Cadence GEM rev 0x50070106 at 0xff0e0000 irq 22 (00:0a:35:00:02:90)
[ 2.484537] xilinx-axipmon ffa00000.perf-monitor: Probed Xilinx APM
[ 2.491181] zynqmp_pll_disable() clock disable failed for apll_int, ret = -13
[ 2.498442] xilinx-axipmon fd0b0000.perf-monitor: Probed Xilinx APM
[ 2.505046] xilinx-axipmon fd490000.perf-monitor: Probed Xilinx APM
[ 2.511646] xilinx-axipmon ffa10000.perf-monitor: Probed Xilinx APM
[ 2.519971] dwc3 fe200000.dwc3: Failed to get clk 'ref': -2
[ 2.526982] xilinx-psgtr fd400000.zynqmp_phy: PLL lock time out
[ 2.532902] xilinx-psgtr fd400000.zynqmp_phy: Lane:2 type:0 protocol:3 pll_locked:no
[ 2.540643] phy phy-fd400000.zynqmp_phy.2: phy init failed --> -110
[ 2.546909] dwc3 fe200000.dwc3: failed to initialize core: -110
[ 2.552865] dwc3: probe of fe200000.dwc3 failed with error -110
[ 2.561003] at24 2-0051: 1024 byte 24c08 EEPROM, writable, 1 bytes/write
[ 2.567746] i2c i2c-0: Added multiplexed i2c bus 2
[ 2.572933] i2c i2c-0: Added multiplexed i2c bus 3
[ 2.577737] pca954x 0-0070: registered 2 multiplexed busses for I2C switch pca9543
[ 2.585338] cdns-i2c ff030000.i2c: 400 kHz mmio ff030000 irq 24
[ 2.591796] cdns-wdt fd4d0000.watchdog: Xilinx Watchdog Timer with timeout 60s
[ 2.599721] cpufreq: cpufreq_online: CPU0: Running at unlisted freq: 1099999 KHz
[ 2.607176] cpufreq: cpufreq_online: CPU0: Unlisted initial frequency changed to: 1199999 KHz
[ 2.649389] mmc0: SDHCI controller on ff160000.mmc [ff160000.mmc] using ADMA 64-bit
[ 2.695977] mmc1: SDHCI controller on ff170000.mmc [ff170000.mmc] using ADMA 64-bit
[ 2.709527] rtc_zynqmp ffa60000.rtc: setting system clock to 1970-01-01T00:01:38 UTC (98)
[ 2.717736] of_cfs_init
[ 2.720284] of_cfs_init: OK
[ 2.724523] ALSA device list:
[ 2.727490] No soundcards found.
[ 2.733707] mmc0: new HS200 MMC card at address 0001
[ 2.739708] mmcblk0: mmc0:0001 Q2J55L 7.09 GiB
[ 2.744780] mmcblk0boot0: mmc0:0001 Q2J55L partition 1 16.0 MiB
[ 2.750989] mmcblk0boot1: mmc0:0001 Q2J55L partition 2 16.0 MiB
[ 2.757096] mmcblk0rpmb: mmc0:0001 Q2J55L partition 3 4.00 MiB, chardev (243:0)
[ 2.761423] ata1: SATA link down (SStatus 0 SControl 330)
[ 2.765791] mmc1: new high speed SDHC card at address 5048
[ 2.769860] ata2: SATA link down (SStatus 0 SControl 330)
[ 2.776517] mmcblk1: mmc1:5048 DDINC 14.9 GiB
[ 2.789242] Freeing unused kernel memory: 4224K
[ 2.790288] mmcblk0: p1
[ 2.793959] Run /init as init process
[ 2.796578] mmcblk1: p1 p2
Starting version 246.2+
[ 3.140378] random: fast init done
[ 24.217869] rcu: INFO: rcu_preempt detected stalls on CPUs/tasks:
[ 24.223964] rcu: 2-...0: (1 GPs behind) idle=3a6/1/0x4000000000000000 softirq=182/182 fqs=2626
[ 24.232734] (detected by 0, t=5254 jiffies, g=-779, q=304)
[ 24.238297] Task dump for CPU 2:
[ 24.241509] kworker/2:1 R running task 0 33 2 0x0000002a
[ 24.248559] Workqueue: events dbs_work_handler
[ 24.252992] Call trace:
[ 24.255428] __switch_to+0xf8/0x180
[ 24.258906] dbs_work_handler+0x48/0x80
[ 24.262734] process_one_work+0x1f0/0x48c
[ 24.266734] worker_thread+0x68/0x460
[ 24.270390] kthread+0x130/0x134
[ 24.273609] ret_from_fork+0x10/0x18
[ 87.237868] rcu: INFO: rcu_preempt detected stalls on CPUs/tasks:
[ 87.243953] rcu: 2-...0: (1 GPs behind) idle=3a6/1/0x4000000000000000 softirq=182/182 fqs=10499
[ 87.252812] (detected by 3, t=21007 jiffies, g=-779, q=304)
[ 87.258461] Task dump for CPU 2:
[ 87.261673] kworker/2:1 R running task 0 33 2 0x0000002a
[ 87.268717] Workqueue: events dbs_work_handler
[ 87.273147] Call trace:
[ 87.275582] __switch_to+0xf8/0x180
[ 87.279062] dbs_work_handler+0x48/0x80
[ 87.282889] process_one_work+0x1f0/0x48c
[ 87.286891] worker_thread+0x68/0x460
[ 87.290545] kthread+0x130/0x134
[ 87.293765] ret_from_fork+0x10/0x18
ricardosalveti commented
Changes in meta-lmp to enable OP-TEE on uz3eg-iocc:
diff --git a/meta-lmp-bsp/recipes-bsp/arm-trusted-firmware/arm-trusted-firmware_2020.1.bbappend b/meta-lmp-bsp/recipes-bsp/arm-trusted-firmware/arm-trusted-firmware_2020.1.bbappend
index b856881..bf4aa65 100644
--- a/meta-lmp-bsp/recipes-bsp/arm-trusted-firmware/arm-trusted-firmware_2020.1.bbappend
+++ b/meta-lmp-bsp/recipes-bsp/arm-trusted-firmware/arm-trusted-firmware_2020.1.bbappend
@@ -2,4 +2,4 @@
PROVIDES += "virtual/trusted-firmware-a"
# Enable opteed as the main SPD provider (required for optee)
-#EXTRA_OEMAKE_append_zynqmp = " SPD=opteed"
+EXTRA_OEMAKE_append_zynqmp = " SPD=opteed"
diff --git a/meta-lmp-bsp/recipes-bsp/u-boot/u-boot-ostree-scr-fit/uz/boot.cmd b/meta-lmp-bsp/recipes-bsp/u-boot/u-boot-ostree-scr-fit/uz/boot.cmd
index 7b2ab39..c38db48 100644
--- a/meta-lmp-bsp/recipes-bsp/u-boot/u-boot-ostree-scr-fit/uz/boot.cmd
+++ b/meta-lmp-bsp/recipes-bsp/u-boot/u-boot-ostree-scr-fit/uz/boot.cmd
@@ -9,11 +9,12 @@ setenv devnum 0
setenv loadaddr 0x10000000
setenv fdt_addr 0x1f000000
+setenv fdt_high 0x7e000000
setenv optee_ovl_addr 0x22000000
setenv bootcmd_load_f 'ext4load ${devtype} ${devnum}:2 ${loadaddr} "/boot"${kernel_image}'
-setenv bootcmd_tee_ovy 'imxtract ${loadaddr}#conf@${fdtfile} fdt@${fdt_file} ${fdt_addr}; fdt addr ${fdt_addr}; fdt resize 0x1000;'
-#setenv bootcmd_tee_ovy 'imxtract ${loadaddr}#conf@${fdtfile} fdt@${fdt_file} ${fdt_addr}; fdt addr ${fdt_addr}; fdt resize 0x1000; fdt apply ${optee_ovl_addr}'
+#setenv bootcmd_tee_ovy 'imxtract ${loadaddr}#conf@${fdtfile} fdt@${fdt_file} ${fdt_addr}; fdt addr ${fdt_addr}; fdt resize 0x1000;'
+setenv bootcmd_tee_ovy 'imxtract ${loadaddr}#conf@${fdtfile} fdt@${fdt_file} ${fdt_addr}; fdt addr ${fdt_addr}; fdt resize 0x1000; fdt apply ${optee_ovl_addr}'
setenv bootcmd_run 'bootm ${loadaddr}#conf@${fdt_file} ${loadaddr}#conf@${fdt_file} ${fdt_addr}'
setenv bootcmd_rollbackenv 'setenv kernel_image ${kernel_image2}; setenv bootargs ${bootargs2}'
setenv bootcmd_set_rollback 'if test ! "${rollback}" = "1"; then setenv rollback 1; setenv upgrade_available 0; saveenv; fi'
ricardosalveti commented
This is using meta-xilinx Xilinx/meta-xilinx@fa72812 and meta-xilinx-tools Xilinx/meta-xilinx-tools@d7b24fd.
ricardosalveti commented
To reproduce just write https://ci.foundries.io/projects/lmp/builds/1069/other-uz3eg-iocc/artifacts/lmp-base-console-image-uz3eg-iocc.wic.gz on a sdcard and copy over boot.bin boot.itb u-boot.itb from http://rsalveti.net/tmp/xilinx/218/ into the first (vfat) partition, replacing the older files.
Kernel config available at https://ci.foundries.io/projects/lmp/builds/1069/other-uz3eg-iocc/artifacts/other/kernel-config.
DTB available at https://ci.foundries.io/projects/lmp/builds/1069/other-uz3eg-iocc/artifacts/other/system.dtb.
ricardosalveti commented
Early boot log diff:
## Checking hash(es) for Image uboot ... sha256+ OK
## Checking hash(es) for Image ubootfdt ... sha256+ OK
## Checking hash(es) for Image optee ... sha256+ OK
-NOTICE: ATF running on XCZU3EG/silicon v4/RTL5.1 at 0xfffea000
+NOTICE: ATF running on XCZU3EG/silicon v4/RTL5.1 at 0x1000
NOTICE: BL31: v2.2(release):xilinx_rebase_v2.2_2020.1
NOTICE: BL31: Built : 00:00:00, Jan 1 1970
+I/TC:
+I/TC: Non-secure external DT found
+I/TC: OP-TEE version: 3.10.0-52-g9393a879 (gcc version 10.2.0 (GCC)) #1 Thu Jan 1 00:00:00 UTC 1970 aarch64
+I/TC: Primary CPU initializing
+I/TC: Primary CPU switching to normal world boot
One interesting piece here is that ATF gets loaded into a different offset when built with SPD or DEBUG.
ricardosalveti commented
atf/plat/xilinx/zynqmp/include/platform_def.h:
/*******************************************************************************
* BL31 specific defines.
******************************************************************************/
/*
* Put BL31 at the top of the Trusted SRAM (just below the shared memory, if
* present). BL31_BASE is calculated using the current BL31 debug size plus a
* little space for growth.
*/
#ifndef ZYNQMP_ATF_MEM_BASE
#if !DEBUG && defined(SPD_none)
# define BL31_BASE 0xfffea000
# define BL31_LIMIT 0xffffffff
#else
# define BL31_BASE 0x1000
# define BL31_LIMIT 0x7ffff
#endif
#else
# define BL31_BASE (ZYNQMP_ATF_MEM_BASE)
# define BL31_LIMIT (ZYNQMP_ATF_MEM_BASE + ZYNQMP_ATF_MEM_SIZE - 1)
# ifdef ZYNQMP_ATF_MEM_PROGBITS_SIZE
# define BL31_PROGBITS_LIMIT (ZYNQMP_ATF_MEM_BASE + ZYNQMP_ATF_MEM_PROGBITS_SIZE - 1)
# endif
#endif
ricardosalveti commented
Can confirm this is not really related to OP-TEE, can reproduce the same problem without OP-TEE by just building ATF in debug mode (which also forces it to a different offset, outside trusted sram).
So this looks like a bug in ATF itself.
ricardosalveti commented
Changed the base and offset to still get it to fit at the trusted SRAM and I'm able to confirm that it all works with OP-TEE as long it is there.
So the actual bug is getting all of this to work when ATF is allocated at dram instead.
ricardosalveti commented
Used a different offset and size for ATF (without conflicting with SPL) and everything works fine now.
ATF_MEM_BASE = "0xfffe5000"
ATF_MEM_SIZE = "0x1affe"