* Re: aarch64 Kernel Panic Asynchronous SError Interrupt on large file IO
[not found] ` <20190815122151.bg7it6ptxwcn2vif@willie-the-truck>
@ 2019-08-15 13:59 ` Robin Murphy
[not found] ` <CA+Vb7hpi=pCC9viiof8y85Kw_vCawWQ0B6kGFALgxtZfCKoaTw@mail.gmail.com>
0 siblings, 1 reply; 14+ messages in thread
From: Robin Murphy @ 2019-08-15 13:59 UTC (permalink / raw)
To: Will Deacon, Philipp Richter
Cc: heiko, catalin.marinas, vicencb, linux-rockchip, andre.przywara,
linux-arm-kernel
On 15/08/2019 13:21, Will Deacon wrote:
> On Tue, Aug 13, 2019 at 03:36:00PM +0200, Philipp Richter wrote:
>> this my first bug kernel bug report I think, so I hope I got the right
>> contacts.
>
> Almost: I'm adding Heiko, Vicente and linux-rockchip to see if they have
> a better idea since this sounds SoC-specific to me and eerily similar to
> some kexec issues Vicente has been seeing recently.
Hmm, I'm not so sure - we're talking different SoCs here, and the kexec
problem does look to be specific to kexec (DMA left running after the
first kernel shuts down). According to the SError dump, that's an AXI
slave error on an external access, which is definitely not something I'd
expect to see part-way through a copy_from_user() operation.
From the boot log, it looks like the disks might be connected to the
USB 3.0 port - it's worth noting that USB 3.0 on RK3328 isn't strictly
supported by mainline yet, and Arch are carrying their own patch to
enable it on Rock64. Is this still reproducible using USB 2.0 (or even
SD/eMMC)?
Robin.
>
> Will
>
> --->8
>
>> I've been getting "Kernel panic - not syncing: Asynchronous SError
>> Interrupt" while transferring large files from and to my rock64 arm
>> board.
>> I am using btrfs as filesystem but an error seems to be triggered from
>> "__arch_copy_from_user". It's a bit difficult for me right now to test
>> with another filesystem but seems to be a troubleshooting option to
>> keep in mind.
>>
>> A reproducible test is to write a big file with dd to disk using
>> /dev/urandom for instance :
>>
>> sudo dd if=/dev/urandom of=/mnt/glassvault/out bs=1M count=8192 status=progress
>> 2789212160 bytes (2.8 GB, 2.6 GiB) copied, 70 s, 39.8 MB/s
>>
>> So here the system panicked at around 2.8GB written of a 8GB file.
>>
>> Backing up the root filesystem or using the external storage panics
>> the system after a while. Smaller file copies at around 1GB do not
>> trigger it.
>>
>> The error output caught via serial console :
>>
>> [ 334.414128] SError Interrupt on CPU0, code 0xbf000002 -- SError
>> [ 334.414136] CPU: 0 PID: 1774 Comm: dd Tainted: G O
>> 5.2.8-1-ARCH #1
>> [ 334.414137] Hardware name: Pine64 Rock64 (DT)
>> [ 334.414139] pstate: 20000005 (nzCv daif -PAN -UAO)
>> [ 334.414141] pc : __arch_copy_from_user+0x1bc/0x240
>> [ 334.414142] lr : copyin+0x54/0x68
>> [ 334.414144] sp : ffff000013523aa0
>> [ 334.414145] x29: ffff000013523aa0 x28: 0000000000001000
>> [ 334.414149] x27: ffff8000e112ec00 x26: 0000000000000005
>> [ 334.414152] x25: ffff000013523d50 x24: 0000000000005000
>> [ 334.414155] x23: 0000000000001000 x22: ffff800009c02000
>> [ 334.414158] x21: ffff000013523d40 x20: 00000000000d5000
>> [ 334.414161] x19: 0000000000000000 x18: 0000000000000000
>> [ 334.414164] x17: 0000000000000000 x16: 0000000000000000
>> [ 334.414167] x15: 0000000000000000 x14: 268451e20def8ac3
>> [ 334.414170] x13: e9bb458ce1212efb x12: 9f52f204714b75c4
>> [ 334.414173] x11: 0e6bc7b591c2d6e4 x10: 40d3c7db468453cb
>> [ 334.414176] x9 : 0d91295116253226 x8 : d0355f82a419091a
>> [ 334.414179] x7 : 911b47420a1c00a2 x6 : ffff800009c01150
>> [ 334.414182] x5 : ffff800009c02000 x4 : 0000000000000000
>> [ 334.414185] x3 : 0000ffffbdbc4000 x2 : 0000000000000e40
>> [ 334.414188] x1 : 0000ffffbdbc4190 x0 : ffff800009c01000
>> [ 334.414191] Kernel panic - not syncing: Asynchronous SError Interrupt
>> [ 334.414194] CPU: 0 PID: 1774 Comm: dd Tainted: G O
>> 5.2.8-1-ARCH #1
>> [ 334.414195] Hardware name: Pine64 Rock64 (DT)
>> [ 334.414197] Call trace:
>> [ 334.414198] dump_backtrace+0x0/0x168
>> [ 334.414199] show_stack+0x24/0x30
>> [ 334.414200] dump_stack+0xa8/0xcc
>> [ 334.414201] panic+0x150/0x320
>> [ 334.414203] __stack_chk_fail+0x0/0x28
>> [ 334.414204] arm64_serror_panic+0x80/0x8c
>> [ 334.414206] do_serror+0x11c/0x120
>> [ 334.414207] el1_error+0x84/0xf8
>> [ 334.414208] __arch_copy_from_user+0x1bc/0x240
>> [ 334.414210] iov_iter_copy_from_user_atomic+0xe4/0x390
>> [ 334.414212] btrfs_copy_from_user+0x68/0x120 [btrfs]
>> [ 334.414213] btrfs_buffered_write.isra.5+0x354/0x638 [btrfs]
>> [ 334.414214] btrfs_file_write_iter+0x3b0/0x4e0 [btrfs]
>> [ 334.414216] new_sync_write+0x110/0x198
>> [ 334.414217] __vfs_write+0x74/0x90
>> [ 334.414218] vfs_write+0xac/0x1b8
>> [ 334.414219] ksys_write+0x74/0xf8
>> [ 334.414221] __arm64_sys_write+0x24/0x30
>> [ 334.414222] el0_svc_handler+0xa4/0x180
>> [ 334.414223] el0_svc+0x8/0xc
>> [ 334.414252] SMP: stopping secondary CPUs
>> [ 334.414253] Kernel Offset: disabled
>> [ 334.414254] CPU features: 0x0002,20002000
>> [ 334.414256] Memory Limit: none
>>
>> My system specifications :
>> This is happening on my rock64 board :
>> - https://www.pine64.org/devices/single-board-computers/rock64/
>> - https://wiki.pine64.org/index.php/ROCK64_Main_Page
>>
>> lscpu output :
>> Architecture: aarch64
>> CPU op-mode(s): 32-bit, 64-bit
>> Byte Order: Little Endian
>> CPU(s): 4
>> On-line CPU(s) list: 0-3
>> Thread(s) per core: 1
>> Core(s) per socket: 4
>> Socket(s): 1
>> Vendor ID: ARM
>> Model: 4
>> Model name: Cortex-A53
>> Stepping: r0p4
>> CPU max MHz: 1296.0000
>> CPU min MHz: 408.0000
>> BogoMIPS: 48.00
>> Vulnerability L1tf: Not affected
>> Vulnerability Mds: Not affected
>> Vulnerability Meltdown: Not affected
>> Vulnerability Spec store bypass: Not affected
>> Vulnerability Spectre v1: Mitigation; __user pointer sanitization
>> Vulnerability Spectre v2: Not affected
>> Flags: fp asimd evtstrm aes pmull sha1 sha2
>> crc32 cpuid
>>
>> uname -a :
>> Linux rock64 5.2.8-1-ARCH #1 SMP Fri Aug 9 23:49:35 UTC 2019 aarch64 GNU/Linux
>>
>> Using the archlinux arm image :
>> https://archlinuxarm.org/platforms/armv8/rockchip/rock64
>>
>> Attached is the complete system log captured with the serial console.
>>
>> I wonder if this could be a hardware issue ?
>>
>> Thank you for your consideration.
>>
>> Best Regards,
>> Philipp Richter
>
>> INFO: PSCI Power Domain Map:
>> INFO: Domain Node : Level 2, parent_node -1, State ON (0x0)
>> INFO: Domain Node : Level 1, parent_node 0, State ON (0x0)
>> INFO: Domain Node : Level 0, parent_node 0, State ON (0x0)
>> INFO: Domain Node : Level 0, parent_node 0, State ON (0x0)
>> INFO: CPU Node : MPID 0x0, parent_node 1, State ON (0x0)
>> INFO: CPU Node : MPID 0x1, parent_node 1, State ON (0x0)
>> INFO: CPU Node : MPID 0x2, parent_node 1, State ON (0x0)
>> INFO: CPU Node : MPID 0x3, parent_node 1, State ON (0x0)
>> DDR version 1.16 20190528
>> ID:0x805 N
>> In
>> SRX
>> LPDDR3
>> 333MHz
>> Bus Width=32 Col=11 Bank=8 Row=15/15 CS=2 Die Bus-Width=32 Size=4096MB
>> ddrconfig:7
>> OUT
>> Boot1 Release Time: May 13 2019 17:34:36, version: 2.50
>> ChipType = 0x11, 316
>> mmc2:cmd19,100
>> SdmmcInit=2 0
>> BootCapSize=2000
>> UserCapSize=29820MB
>> FwPartOffset=2000 , 2000
>> SdmmcInit=0 NOT PRESENT
>> StorageInit ok = 210392
>> Raw SecureMode = 0
>> SecureInit read PBA: 0x4
>> SecureInit read PBA: 0x404
>> SecureInit read PBA: 0x804
>> SecureInit read PBA: 0xc04
>> SecureInit read PBA: 0x1004
>> SecureInit ret = 0, SecureMode = 0
>> atags_set_bootdev: ret:(0)
>> GPT 0x337a9f0 signature is wrong
>> recovery gpt...
>> GPT 0x337a9f0 signature is wrong
>> recovery gpt fail!
>> LoadTrust Addr:0x4000
>> No find bl30.bin
>> Load uboot, ReadLba = 2000
>> Load OK, addr=0x200000, size=0x9a864
>> RunBL31 0x10000
>> NOTICE: BL31: v1.3(debug):0eba775
>> NOTICE: BL31: Built : 12:11:32, Nov 23 2018
>> NOTICE: BL31:Rockchip release version: v1.3
>> INFO: ARM GICv2 driver initialized
>> INFO: Using opteed sec cpu_context!
>> INFO: boot cpu mask: 1
>> INFO: plat_rockchip_pmu_init: pd status 0xe
>> INFO: BL31: Initializing runtime services
>> INFO: BL31: Initializing BL32
>> INF [0x0] TEE-CORE:init_primary_helper:337: Initializing (1.1.0-221-gda2bcfdc #137 Mon Jun 17 03:00:04 UTC 2019 aarch64)
>>
>> INF [0x0] TEE-CORE:init_primary_helper:338: Release version: 1.4
>>
>> INF [0x0] TEE-CORE:init_teecore:83: teecore inits done
>> INFO: BL31: Preparing for EL3 exit to normal world
>> INFO: Entry point address = 0x200000
>> INFO: SPSR = 0x3c9
>>
>>
>> U-Boot 2019.07-1 (Aug 10 2019 - 10:47:59 +0000) Arch Linux ARM
>>
>> Model: Rockchip RK3328 EVB
>> DRAM: 4 GiB
>> MMC: rksdmmc@ff500000: 1, rksdmmc@ff520000: 0
>> Loading Environment from MMC... Card did not respond to voltage select!
>> *** Warning - No block device, using default environment
>>
>> In: serial@ff130000
>> Out: serial@ff130000
>> Err: serial@ff130000
>> Model: Rockchip RK3328 EVB
>> Net:
>> Warning: ethernet@ff540000 (eth0) using random MAC address - be:c7:d6:3e:93:7b
>> eth0: ethernet@ff540000
>> Hit any key to stop autoboot: 2 \b\b\b 1 \b\b\b 0
>> switch to partitions #0, OK
>> mmc0(part 0) is current device
>> Scanning mmc 0:1...
>> Found U-Boot script /boot.scr
>> 1133 bytes read in 5 ms (220.7 KiB/s)
>> ## Executing script at 00500000
>> 26501632 bytes read in 628 ms (40.2 MiB/s)
>> 49338 bytes read in 10 ms (4.7 MiB/s)
>> 10033777 bytes read in 241 ms (39.7 MiB/s)
>> ## Flattened Device Tree blob at 01f00000
>> Booting using the fdt blob at 0x1f00000
>> Loading Ramdisk to fc59b000, end fcf2ca71 ... OK
>> Loading Device Tree to 00000000fc58b000, end 00000000fc59afff ... OK
>>
>> Starting kernel ...
>>
>> [ 0.000000] Booting Linux on physical CPU 0x0000000000 [0x410fd034]
>> [ 0.000000] Linux version 5.2.8-1-ARCH (builduser@leming) (gcc version 8.3.0 (GCC)) #1 SMP Fri Aug 9 23:49:35 UTC 2019
>> [ 0.000000] Machine model: Pine64 Rock64
>> [ 0.000000] earlycon: uart8250 at MMIO32 0x00000000ff130000 (options '')
>> [ 0.000000] printk: bootconsole [uart8250] enabled
>> [ 0.000000] printk: debug: ignoring loglevel setting.
>> [ 0.000000] efi: Getting EFI parameters from FDT:
>> [ 0.000000] efi: UEFI not found.
>> [ 0.000000] cma: Reserved 64 MiB at 0x00000000f8400000
>> [ 0.000000] On node 0 totalpages: 1043968
>> [ 0.000000] DMA32 zone: 16312 pages used for memmap
>> [ 0.000000] DMA32 zone: 0 pages reserved
>> [ 0.000000] DMA32 zone: 1043968 pages, LIFO batch:63
>> [ 0.000000] psci: probing for conduit method from DT.
>> [ 0.000000] psci: PSCIv1.0 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.0
>> [ 0.000000] percpu: Embedded 31 pages/cpu s89496 r8192 d29288 u126976
>> [ 0.000000] pcpu-alloc: s89496 r8192 d29288 u126976 alloc=31*4096
>> [ 0.000000] pcpu-alloc: [0] 0 [0] 1 [0] 2 [0] 3
>> [ 0.000000] Detected VIPT I-cache on CPU0
>> [ 0.000000] Built 1 zonelists, mobility grouping on. Total pages: 1027656
>> [ 0.000000] Kernel command line: console=ttyS2,1500000 ip=192.168.0.20::192.168.0.1:255.255.255.0::eth0:none cryptdevice=UUID=70b4d35b-a2e5-446d-b317-8ef53698beb6:cryptroot root=UUID=0250489f-2c3d-499e-9ff1-8f85451622e7 rootfstype=btrfs rootflags=subvol=@rootvol rw rootwait earlycon=uart8250,mmio32,0xff130000 fsck.mode=force md_mod.start_ro=1 debug ignore_loglevel log_buf_len=16M
>> [ 0.000000] printk: log_buf_len: 16777216 bytes
>> [ 0.000000] printk: early log buf free: 260348(99%)
>> [ 0.000000] Dentry cache hash table entries: 524288 (order: 10, 4194304 bytes)
>> [ 0.000000] Inode-cache hash table entries: 262144 (order: 9, 2097152 bytes)
>> [ 0.000000] Memory: 3976792K/4175872K available (14588K kernel code, 2648K rwdata, 6688K rodata, 1920K init, 825K bss, 133544K reserved, 65536K cma-reserved)
>> [ 0.000000] random: get_random_u64 called from cache_random_seq_create+0x88/0x158 with crng_init=0
>> [ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1
>> [ 0.000000] ftrace: allocating 50612 entries in 198 pages
>> [ 0.000000] rcu: Hierarchical RCU implementation.
>> [ 0.000000] rcu: RCU restricting CPUs from NR_CPUS=8 to nr_cpu_ids=4.
>> [ 0.000000] Tasks RCU enabled.
>> [ 0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 10 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] rockchip_mmc_get_phase: invalid clk rate
>> [ 0.000000] rockchip_mmc_get_phase: invalid clk rate
>> [ 0.000000] rockchip_mmc_get_phase: invalid clk rate
>> [ 0.000000] rockchip_mmc_get_phase: invalid clk rate
>> [ 0.000000] rockchip_mmc_get_phase: invalid clk rate
>> [ 0.000000] rockchip_mmc_get_phase: invalid clk rate
>> [ 0.000000] rockchip_mmc_get_phase: invalid clk rate
>> [ 0.000000] rockchip_mmc_get_phase: invalid clk rate
>> [ 0.000000] arch_timer: cp15 timer(s) running at 24.00MHz (phys).
>> [ 0.000000] clocksource: arch_sys_counter: mask: 0xffffffffffffff max_cycles: 0x588fe9dc0, max_idle_ns: 440795202592 ns
>> [ 0.000007] sched_clock: 56 bits at 24MHz, resolution 41ns, wraps every 4398046511097ns
>> [ 0.002544] Console: colour dummy device 80x25
>> [ 0.003022] Calibrating delay loop (skipped), value calculated using timer frequency.. 48.00 BogoMIPS (lpj=240000)
>> [ 0.004007] pid_max: default: 32768 minimum: 301
>> [ 0.004710] LSM: Security Framework initializing
>> [ 0.005168] Yama: becoming mindful.
>> [ 0.005630] Mount-cache hash table entries: 8192 (order: 4, 65536 bytes)
>> [ 0.006300] Mountpoint-cache hash table entries: 8192 (order: 4, 65536 bytes)
>> [ 0.007747] *** VALIDATE proc ***
>> [ 0.008498] *** VALIDATE cgroup1 ***
>> [ 0.008846] *** VALIDATE cgroup2 ***
>> [ 0.010336] ASID allocator initialised with 32768 entries
>> [ 0.010979] rcu: Hierarchical SRCU implementation.
>> [ 0.016902] EFI services will not be available.
>> [ 0.018071] smp: Bringing up secondary CPUs ...
>> [ 0.019320] Detected VIPT I-cache on CPU1
>> [ 0.019410] CPU1: Booted secondary processor 0x0000000001 [0x410fd034]
>> [ 0.020336] Detected VIPT I-cache on CPU2
>> [ 0.020412] CPU2: Booted secondary processor 0x0000000002 [0x410fd034]
>> [ 0.021274] Detected VIPT I-cache on CPU3
>> [ 0.021345] CPU3: Booted secondary processor 0x0000000003 [0x410fd034]
>> [ 0.021488] smp: Brought up 1 node, 4 CPUs
>> [ 0.024854] SMP: Total of 4 processors activated.
>> [ 0.025305] CPU features: detected: 32-bit EL0 Support
>> [ 0.025795] CPU features: detected: CRC32 instructions
>> [ 0.026879] CPU: All CPU(s) started at EL2
>> [ 0.027293] alternatives: patching kernel code
>> [ 0.031870] devtmpfs: initialized
>> [ 0.047224] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns
>> [ 0.048180] futex hash table entries: 1024 (order: 4, 65536 bytes)
>> [ 0.052616] pinctrl core: initialized pinctrl subsystem
>> [ 0.054646] DMI not present or invalid.
>> [ 0.055662] NET: Registered protocol family 16
>> [ 0.057142] audit: initializing netlink subsys (disabled)
>> [ 0.057904] audit: type=2000 audit(0.050:1): state=initialized audit_enabled=0 res=1
>> [ 0.059460] cpuidle: using governor ladder
>> [ 0.059878] cpuidle: using governor menu
>> [ 0.061077] hw-breakpoint: found 6 breakpoint and 4 watchpoint registers.
>> [ 0.064111] DMA: preallocated 256 KiB pool for atomic allocations
>> [ 0.065680] Serial: AMBA PL011 UART driver
>> [ 0.106380] HugeTLB registered 1.00 GiB page size, pre-allocated 0 pages
>> [ 0.107028] HugeTLB registered 32.0 MiB page size, pre-allocated 0 pages
>> [ 0.107664] HugeTLB registered 2.00 MiB page size, pre-allocated 0 pages
>> [ 0.108300] HugeTLB registered 64.0 KiB page size, pre-allocated 0 pages
>> [ 2.273837] cryptd: max_cpu_qlen set to 1000
>> [ 2.291370] alg: No test for lzo-rle (lzo-rle-generic)
>> [ 2.292198] alg: No test for lzo-rle (lzo-rle-scomp)
>> [ 2.313901] ACPI: Interpreter disabled.
>> [ 2.314870] sdmmc-regulator GPIO handle specifies active low - ignored
>> [ 2.316511] vcc-host1-5v-regulator GPIO handle specifies active low - ignored
>> [ 2.319734] vgaarb: loaded
>> [ 2.321353] SCSI subsystem initialized
>> [ 2.322016] libata version 3.00 loaded.
>> [ 2.322896] usbcore: registered new interface driver usbfs
>> [ 2.323483] usbcore: registered new interface driver hub
>> [ 2.324116] usbcore: registered new device driver usb
>> [ 2.325345] pps_core: LinuxPPS API ver. 1 registered
>> [ 2.325818] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti <giometti@linux.it>
>> [ 2.326699] PTP clock support registered
>> [ 2.327442] EDAC MC: Ver: 3.0.0
>> [ 2.329247] Advanced Linux Sound Architecture Driver Initialized.
>> [ 2.330598] NetLabel: Initializing
>> [ 2.330926] NetLabel: domain hash size = 128
>> [ 2.331372] NetLabel: protocols = UNLABELED CIPSOv4 CALIPSO
>> [ 2.332002] NetLabel: unlabeled traffic allowed by default
>> [ 2.333538] clocksource: Switched to clocksource arch_sys_counter
>> [ 3.536137] VFS: Disk quotas dquot_6.6.0
>> [ 3.536616] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes)
>> [ 3.537405] *** VALIDATE hugetlbfs ***
>> [ 3.538306] pnp: PnP ACPI: disabled
>> [ 3.548776] NET: Registered protocol family 2
>> [ 3.550155] tcp_listen_portaddr_hash hash table entries: 2048 (order: 3, 32768 bytes)
>> [ 3.550985] TCP established hash table entries: 32768 (order: 6, 262144 bytes)
>> [ 3.552071] TCP bind hash table entries: 32768 (order: 7, 524288 bytes)
>> [ 3.553440] TCP: Hash tables configured (established 32768 bind 32768)
>> [ 3.554654] UDP hash table entries: 2048 (order: 4, 65536 bytes)
>> [ 3.555373] UDP-Lite hash table entries: 2048 (order: 4, 65536 bytes)
>> [ 3.556426] NET: Registered protocol family 1
>> [ 3.557771] RPC: Registered named UNIX socket transport module.
>> [ 3.558342] RPC: Registered udp transport module.
>> [ 3.558789] RPC: Registered tcp transport module.
>> [ 3.559236] RPC: Registered tcp NFSv4.1 backchannel transport module.
>> [ 3.559856] PCI: CLS 0 bytes, default 64
>> [ 3.560479] Trying to unpack rootfs image as initramfs...
>> [ 4.390556] Freeing initrd memory: 9796K
>> [ 4.392765] hw perfevents: enabled with armv8_cortex_a53 PMU driver, 7 counters available
>> [ 4.394010] kvm [1]: IPA Size Limit: 40bits
>> [ 4.396049] kvm [1]: vgic interrupt IRQ1
>> [ 4.396592] kvm [1]: Hyp mode initialized successfully
>> [ 5.273872] Initialise system trusted keyrings
>> [ 5.274576] workingset: timestamp_bits=46 max_order=20 bucket_order=0
>> [ 5.284456] zbud: loaded
>> [ 5.288244] NFS: Registering the id_resolver key type
>> [ 5.288758] Key type id_resolver registered
>> [ 5.289160] Key type id_legacy registered
>> [ 5.289554] nfs4filelayout_init: NFSv4 File Layout Driver Registering...
>> [ 5.290478] SGI XFS with ACLs, security attributes, no debug enabled
>> [ 5.304919] NET: Registered protocol family 38
>> [ 5.305369] Key type asymmetric registered
>> [ 5.305760] Asymmetric key parser 'x509' registered
>> [ 5.306314] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 242)
>> [ 5.307274] io scheduler mq-deadline registered
>> [ 5.307709] io scheduler kyber registered
>> [ 5.308386] io scheduler bfq registered
>> [ 5.319920] gpio-syscon ff100000.syscon:grf-gpio: can't read the data register offset!
>> [ 5.323397] IPMI message handler: version 39.2
>> [ 5.333151] dma-pl330 ff1f0000.dmac: Loaded driver for PL330 DMAC-241330
>> [ 5.333850] dma-pl330 ff1f0000.dmac: DBUFF-128x8bytes Num_Chans-8 Num_Peri-20 Num_Events-16
>> [ 5.341290] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled
>> [ 5.345288] printk: console [ttyS2] disabled
>> [ 5.345780] ff130000.serial: ttyS2 at MMIO 0xff130000 (irq = 14, base_baud = 1500000) is a 16550A
>> [ 5.346693] printk: console [ttyS2] enabled
>> [ 5.346693] printk: console [ttyS2] enabled
>> [ 5.347462] printk: bootconsole [uart8250] disabled
>> [ 5.347462] printk: bootconsole [uart8250] disabled
>> [ 5.350235] msm_serial: driver initialized
>> [ 5.362453] m25p80 spi0.0: gd25q128 (16384 Kbytes)
>> [ 5.381313] libphy: Fixed MDIO Bus: probed
>> [ 5.385044] dwc3 ff600000.dwc3: Failed to get clk 'ref': -2
>> [ 5.388071] dwc2 ff580000.usb: ff580000.usb supply vusb_d not found, using dummy regulator
>> [ 5.388903] dwc2 ff580000.usb: ff580000.usb supply vusb_a not found, using dummy regulator
>> [ 5.404393] dwc2 ff580000.usb: DWC OTG Controller
>> [ 5.404854] dwc2 ff580000.usb: new USB bus registered, assigned bus number 1
>> [ 5.405525] dwc2 ff580000.usb: irq 33, io mem 0xff580000
>> [ 5.406281] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 5.02
>> [ 5.407012] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
>> [ 5.407651] usb usb1: Product: DWC OTG Controller
>> [ 5.408070] usb usb1: Manufacturer: Linux 5.2.8-1-ARCH dwc2_hsotg
>> [ 5.408608] usb usb1: SerialNumber: ff580000.usb
>> [ 5.409766] hub 1-0:1.0: USB hub found
>> [ 5.410144] hub 1-0:1.0: 1 port detected
>> [ 5.412668] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver
>> [ 5.413270] ehci-pci: EHCI PCI platform driver
>> [ 5.413787] ehci-platform: EHCI generic platform driver
>> [ 5.416868] ehci-platform ff5c0000.usb: EHCI Host Controller
>> [ 5.417712] ehci-platform ff5c0000.usb: new USB bus registered, assigned bus number 2
>> [ 5.419084] ehci-platform ff5c0000.usb: irq 34, io mem 0xff5c0000
>> [ 5.443576] ehci-platform ff5c0000.usb: USB 2.0 started, EHCI 1.00
>> [ 5.444442] usb usb2: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 5.02
>> [ 5.445173] usb usb2: New USB device strings: Mfr=3, Product=2, SerialNumber=1
>> [ 5.445811] usb usb2: Product: EHCI Host Controller
>> [ 5.446245] usb usb2: Manufacturer: Linux 5.2.8-1-ARCH ehci_hcd
>> [ 5.446768] usb usb2: SerialNumber: ff5c0000.usb
>> [ 5.447967] hub 2-0:1.0: USB hub found
>> [ 5.448346] hub 2-0:1.0: 1 port detected
>> [ 5.449303] ehci-orion: EHCI orion driver
>> [ 5.449985] tegra-ehci: Tegra EHCI driver
>> [ 5.450528] ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver
>> [ 5.451156] ohci-pci: OHCI PCI platform driver
>> [ 5.451648] ohci-platform: OHCI generic platform driver
>> [ 5.452515] ohci-platform ff5d0000.usb: Generic Platform OHCI controller
>> [ 5.453442] ohci-platform ff5d0000.usb: new USB bus registered, assigned bus number 3
>> [ 5.454760] ohci-platform ff5d0000.usb: irq 35, io mem 0xff5d0000
>> [ 5.527889] usb usb3: New USB device found, idVendor=1d6b, idProduct=0001, bcdDevice= 5.02
>> [ 5.528622] usb usb3: New USB device strings: Mfr=3, Product=2, SerialNumber=1
>> [ 5.529261] usb usb3: Product: Generic Platform OHCI controller
>> [ 5.529785] usb usb3: Manufacturer: Linux 5.2.8-1-ARCH ohci_hcd
>> [ 5.530307] usb usb3: SerialNumber: ff5d0000.usb
>> [ 5.531477] hub 3-0:1.0: USB hub found
>> [ 5.531857] hub 3-0:1.0: 1 port detected
>> [ 5.532794] uhci_hcd: USB Universal Host Controller Interface driver
>> [ 5.534443] xhci-hcd xhci-hcd.0.auto: xHCI Host Controller
>> [ 5.535234] xhci-hcd xhci-hcd.0.auto: new USB bus registered, assigned bus number 4
>> [ 5.536870] xhci-hcd xhci-hcd.0.auto: hcc params 0x0220fe64 hci version 0x110 quirks 0x0000000002010010
>> [ 5.537764] xhci-hcd xhci-hcd.0.auto: irq 169, io mem 0xff600000
>> [ 5.538874] usb usb4: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 5.02
>> [ 5.539606] usb usb4: New USB device strings: Mfr=3, Product=2, SerialNumber=1
>> [ 5.540244] usb usb4: Product: xHCI Host Controller
>> [ 5.540679] usb usb4: Manufacturer: Linux 5.2.8-1-ARCH xhci-hcd
>> [ 5.541202] usb usb4: SerialNumber: xhci-hcd.0.auto
>> [ 5.542407] hub 4-0:1.0: USB hub found
>> [ 5.542788] hub 4-0:1.0: 1 port detected
>> [ 5.543652] xhci-hcd xhci-hcd.0.auto: xHCI Host Controller
>> [ 5.544430] xhci-hcd xhci-hcd.0.auto: new USB bus registered, assigned bus number 5
>> [ 5.545124] xhci-hcd xhci-hcd.0.auto: Host supports USB 3.0 SuperSpeed
>> [ 5.545803] usb usb5: We don't know the algorithms for LPM for this host, disabling LPM.
>> [ 5.546676] usb usb5: New USB device found, idVendor=1d6b, idProduct=0003, bcdDevice= 5.02
>> [ 5.547406] usb usb5: New USB device strings: Mfr=3, Product=2, SerialNumber=1
>> [ 5.548045] usb usb5: Product: xHCI Host Controller
>> [ 5.548479] usb usb5: Manufacturer: Linux 5.2.8-1-ARCH xhci-hcd
>> [ 5.549002] usb usb5: SerialNumber: xhci-hcd.0.auto
>> [ 5.550079] hub 5-0:1.0: USB hub found
>> [ 5.550457] hub 5-0:1.0: 1 port detected
>> [ 5.552054] usbcore: registered new interface driver uas
>> [ 5.552740] usbcore: registered new interface driver usb-storage
>> [ 5.553315] usbcore: registered new interface driver ums-alauda
>> [ 5.554711] usbcore: registered new interface driver ums-cypress
>> [ 5.555303] usbcore: registered new interface driver ums-datafab
>> [ 5.555873] usbcore: registered new interface driver ums_eneub6250
>> [ 5.556458] usbcore: registered new interface driver ums-freecom
>> [ 5.557031] usbcore: registered new interface driver ums-isd200
>> [ 5.557590] usbcore: registered new interface driver ums-jumpshot
>> [ 5.558168] usbcore: registered new interface driver ums-karma
>> [ 5.558723] usbcore: registered new interface driver ums-onetouch
>> [ 5.559329] usbcore: registered new interface driver ums-realtek
>> [ 5.559901] usbcore: registered new interface driver ums-sddr09
>> [ 5.560465] usbcore: registered new interface driver ums-sddr55
>> [ 5.561034] usbcore: registered new interface driver ums-usbat
>> [ 5.561679] usbcore: registered new interface driver usbserial_generic
>> [ 5.562286] usbserial: USB Serial support registered for generic
>> [ 5.565340] mousedev: PS/2 mouse device common for all mice
>> [ 5.570721] rk808 1-0018: chip id: 0x8050
>> [ 5.578919] rk808-regulator rk808-regulator: there is no dvs0 gpio
>> [ 5.579506] rk808-regulator rk808-regulator: there is no dvs1 gpio
>> [ 5.580138] DCDC_REG1: supplied by vcc_sys
>> [ 5.582764] vcc_host_5v: supplied by vcc_sys
>> [ 5.583213] vcc_host1_5v: supplied by vcc_sys
>> [ 5.583790] DCDC_REG2: supplied by vcc_sys
>> [ 5.585461] DCDC_REG3: supplied by vcc_sys
>> [ 5.586122] DCDC_REG4: supplied by vcc_sys
>> [ 5.587749] LDO_REG1: supplied by vcc_io
>> [ 5.591165] LDO_REG2: supplied by vcc_io
>> [ 5.594577] LDO_REG3: supplied by vcc_sys
>> [ 5.605089] device-mapper: uevent: version 1.0.3
>> [ 5.606034] device-mapper: ioctl: 4.40.0-ioctl (2019-01-18) initialised: dm-devel@redhat.com
>> [ 5.611360] sdhci: Secure Digital Host Controller Interface driver
>> [ 5.611911] sdhci: Copyright(c) Pierre Ossman
>> [ 5.612853] Synopsys Designware Multimedia Card Interface Driver
>> [ 5.614406] dwmmc_rockchip ff500000.dwmmc: IDMAC supports 32-bit address mode.
>> [ 5.615304] dwmmc_rockchip ff500000.dwmmc: Using internal DMA controller.
>> [ 5.615904] dwmmc_rockchip ff500000.dwmmc: Version ID is 270a
>> [ 5.616484] dwmmc_rockchip ff500000.dwmmc: DW MMC controller at irq 30,32 bit host data width,256 deep fifo
>> [ 5.617390] vcc_sd: supplied by vcc_io
>> [ 5.630692] mmc_host mmc0: Bus speed (slot 0) = 400000Hz (slot req 400000Hz, actual 400000HZ div = 0)
>> [ 5.644352] dwmmc_rockchip ff520000.dwmmc: IDMAC supports 32-bit address mode.
>> [ 5.645240] dwmmc_rockchip ff520000.dwmmc: Using internal DMA controller.
>> [ 5.645844] dwmmc_rockchip ff520000.dwmmc: Version ID is 270a
>> [ 5.646395] dwmmc_rockchip ff520000.dwmmc: DW MMC controller at irq 31,32 bit host data width,256 deep fifo
>> [ 5.647984] mmc_host mmc1: card is non-removable.
>> [ 5.661232] mmc_host mmc1: Bus speed (slot 0) = 400000Hz (slot req 400000Hz, actual 400000HZ div = 0)
>> [ 5.675543] sdhci-pltfm: SDHCI platform and OF driver helper
>> [ 5.678483] ledtrig-cpu: registered to indicate activity on CPUs
>> [ 5.679960] hidraw: raw HID events driver (C) Jiri Kosina
>> [ 5.680611] usbcore: registered new interface driver usbhid
>> [ 5.681121] usbhid: USB HID core driver
>> [ 5.686302] drop_monitor: Initializing network drop monitor service
>> [ 5.687106] Initializing XFRM netlink socket
>> [ 5.688036] NET: Registered protocol family 10
>> [ 5.722101] Segment Routing with IPv6
>> [ 5.722539] mip6: Mobile IPv6
>> [ 5.722809] NET: Registered protocol family 17
>> [ 5.723440] Key type dns_resolver registered
>> [ 5.724677] registered taskstats version 1
>> [ 5.725045] Loading compiled-in X.509 certificates
>> [ 5.725592] zswap: loaded using pool lzo/zbud
>> [ 5.726195] Key type big_key registered
>> [ 5.742637] Key type encrypted registered
>> [ 5.756585] hctosys: unable to open rtc device (rtc0)
>> [ 5.758243] vcc_sd: disabling
>> [ 5.758524] ALSA device list:
>> [ 5.758789] No soundcards found.
>> [ 5.763938] random: fast init done
>> [ 5.764394] Freeing unused kernel memory: 1920K
>> [ 5.823591] Run /init as init process
>> :: running early hook [udev]
>> [ 5.859765] mmc_host mmc1: Bus speed (slot 0) = 200000000Hz (slot req 200000000Hz, actual 200000000HZ div = 0)
>> [ 5.866872] dwmmc_rockchip ff520000.dwmmc: Successfully tuned phase to 278
>> [ 5.867852] mmc1: new HS200 MMC card at address 0001
>> [ 5.870126] mmcblk1: mmc1:0001 SDW32G 29.1 GiB
>> [ 5.871837] mmcblk1boot0: mmc1:0001 SDW32G partition 1 4.00 MiB
>> [ 5.873811] mmcblk1boot1: mmc1:0001 SDW32G partition 2 4.00 MiB
>> [ 5.874678] mmcblk1rpmb: mmc1:0001 SDW32G partition 3 4.00 MiB, chardev (235:0)
>> [ 5.876990] mmcblk1: p1 p2
>> Looking for configuration files in (higher priority first):
>> /etc/tmpfiles.d
>> /run/tmpfiles.d
>> /usr/local/lib/tmpfiles.d
>> /usr/lib/tmpfiles.d
>> Reading config file "/run/tmpfiles.d/kmod.conf"ÔÇŽ
>> Entry "/dev/btrfs-control" matches include prefix "/dev".
>> Failed to determine whether '/dev/btrfs-control' is below autofs, ignoring: No such file or directory
>> Running create action for entry c /dev/btrfs-control
>> Created char device node "/dev/btrfs-control" 1:128.
>> "/dev/btrfs-control" has correct mode 20600 already.
>> [ 5.913716] usb 5-1: new SuperSpeed Gen 1 USB device number 2 using xhci-hcd
>> Starting version 242.84-1-arch
>> :: running hook [udev]
>> :: Triggering uevents...
>> [ 5.944464] usb 5-1: New USB device found, idVendor=152d, idProduct=0567, bcdDevice= 2.00
>> [ 5.945191] usb 5-1: New USB device strings: Mfr=10, Product=11, SerialNumber=5
>> [ 5.945830] usb 5-1: Product: USB to ATA/ATAPI Bridge
>> [ 5.946271] usb 5-1: Manufacturer: JMicron
>> [ 5.946631] usb 5-1: SerialNumber: 152D00539000
>> [ 5.949430] usb-storage 5-1:1.0: USB Mass Storage device detected
>> [ 5.952289] usb-storage 5-1:1.0: Quirks match for vid 152d pid 0567: 5000000
>> [ 5.953139] scsi host0: usb-storage 5-1:1.0
>> [ 6.322668] force_sf_dma_mode is ignored if force_thresh_dma_mode is set.
>> [ 6.322721] rk_gmac-dwmac ff540000.ethernet: PTP uses main clock
>> [ 6.324301] rk_gmac-dwmac ff540000.ethernet: clock input or output? (input).
>> [ 6.324950] rk_gmac-dwmac ff540000.ethernet: TX delay(0x24).
>> [ 6.325456] rk_gmac-dwmac ff540000.ethernet: RX delay(0x18).
>> [ 6.325965] rk_gmac-dwmac ff540000.ethernet: integrated PHY? (no).
>> [ 6.327146] rk_gmac-dwmac ff540000.ethernet: cannot get clock clk_mac_speed
>> [ 6.327783] rk_gmac-dwmac ff540000.ethernet: clock input from PHY
>> [ 6.333394] rk_gmac-dwmac ff540000.ethernet: init for RGMII
>> [ 6.334445] rk_gmac-dwmac ff540000.ethernet: User ID: 0x10, Synopsys ID: 0x35
>> [ 6.335103] rk_gmac-dwmac ff540000.ethernet: DWMAC1000
>> [ 6.335573] rk_gmac-dwmac ff540000.ethernet: DMA HW capability register supported
>> [ 6.336231] rk_gmac-dwmac ff540000.ethernet: RX Checksum Offload Engine supported
>> [ 6.336887] rk_gmac-dwmac ff540000.ethernet: COE Type 2
>> [ 6.337347] rk_gmac-dwmac ff540000.ethernet: Wake-Up On Lan supported
>> [ 6.337960] rk_gmac-dwmac ff540000.ethernet: Normal descriptors
>> [ 6.338486] rk_gmac-dwmac ff540000.ethernet: Ring mode enabled
>> [ 6.339002] rk_gmac-dwmac ff540000.ethernet: Enable RX Mitigation via HW Watchdog Timer
>> [ 6.458371] libphy: stmmac: probed
>> [ 6.458699] mdio_bus stmmac-0:00: attached PHY driver [unbound] (mii_bus:phy_addr=stmmac-0:00, irq=POLL)
>> [ 6.459527] mdio_bus stmmac-0:01: attached PHY driver [unbound] (mii_bus:phy_addr=stmmac-0:01, irq=POLL)
>> :: running hook [netconf]
>> [ 6.490371] Generic PHY stmmac-0:00: attached PHY driver [Generic PHY] (mii_bus:phy_addr=stmmac-0:00, irq=POLL)
>> [ 6.512069] rk_gmac-dwmac ff540000.ethernet eth0: No Safety Features support found
>> [ 6.512758] rk_gmac-dwmac ff540000.ethernet eth0: PTP not supported by HW
>> IP-Config: eth0: 192.168.0.20/255.255.255.0
>> IP-Config: eth0: gw: 192.168.0.1 dns0: 0.0.0.0 dns1: 0.0.0.0
>> :: running hook [tinyssh]
>> Starting tinyssh
>> :: running hook [encryptssh]
>> [ 6.603123] random: cryptsetup: uninitialized urandom read (4 bytes read)
>>
>> A password is required to access the cryptroot volume:
>> [ 6.624945] random: cryptsetup: uninitialized urandom read (4 bytes read)
>> Enter passphrase for /dev/mmcblk1p2: [ 6.964242] scsi 0:0:0:0: Direct-Access SAMSUNG HD154UI 0520 PQ: 0 ANSI: 6
>> [ 6.965390] scsi 0:0:0:1: Direct-Access Hitachi HDS721010CLA332 0520 PQ: 0 ANSI: 6
>> [ 6.966471] scsi 0:0:0:2: Direct-Access SAMSUNG HD321KJ 0520 PQ: 0 ANSI: 6
>> [ 6.967557] scsi 0:0:0:3: Direct-Access HGST HTS 545050A7E680 0520 PQ: 0 ANSI: 6
>> [ 6.969619] sd 0:0:0:0: Attached scsi generic sg0 type 0
>> [ 6.971662] sd 0:0:0:1: Attached scsi generic sg1 type 0
>> [ 6.971955] sd 0:0:0:0: [sda] 2930277168 512-byte logical blocks: (1.50 TB/1.36 TiB)
>> [ 6.975507] sd 0:0:0:0: [sda] Write Protect is off
>> [ 6.975954] sd 0:0:0:0: [sda] Mode Sense: 67 00 10 08
>> [ 6.977060] sd 0:0:0:2: Attached scsi generic sg2 type 0
>> [ 6.977164] sd 0:0:0:1: [sdb] 1953525168 512-byte logical blocks: (1.00 TB/932 GiB)
>> [ 6.978816] sd 0:0:0:0: [sda] Disabling FUA
>> [ 6.979219] sd 0:0:0:0: [sda] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
>> [ 6.981187] sd 0:0:0:1: [sdb] Write Protect is off
>> [ 6.981639] sd 0:0:0:1: [sdb] Mode Sense: 67 00 10 08
>> [ 6.982610] sd 0:0:0:2: [sdc] 625142448 512-byte logical blocks: (320 GB/298 GiB)
>> [ 6.982836] sd 0:0:0:3: Attached scsi generic sg3 type 0
>> [ 6.984522] sd 0:0:0:1: [sdb] Disabling FUA
>> [ 6.984923] sd 0:0:0:1: [sdb] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
>> [ 6.986197] sd 0:0:0:2: [sdc] Write Protect is off
>> [ 6.986641] sd 0:0:0:2: [sdc] Mode Sense: 67 00 10 08
>> [ 6.988359] sd 0:0:0:2: [sdc] Disabling FUA
>> [ 6.988750] sd 0:0:0:2: [sdc] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
>> [ 6.989906] sd 0:0:0:3: [sdd] 976773168 512-byte logical blocks: (500 GB/466 GiB)
>> [ 6.990982] sd 0:0:0:3: [sdd] Write Protect is off
>> [ 6.991423] sd 0:0:0:3: [sdd] Mode Sense: 67 00 10 08
>> [ 6.992280] sd 0:0:0:3: [sdd] Disabling FUA
>> [ 6.992665] sd 0:0:0:3: [sdd] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
>> [ 8.892160] sdb: sdb1
>> [ 8.893001] sda: sda1 sda2
>> [ 8.900058] sd 0:0:0:1: [sdb] Attached SCSI disk
>> [ 8.901265] sdc: sdc1
>> [ 8.904861] sdd: sdd1 sdd2
>> [ 8.909043] sd 0:0:0:0: [sda] Attached SCSI disk
>> [ 8.910990] sd 0:0:0:2: [sdc] Attached SCSI disk
>> [ 8.912434] sd 0:0:0:3: [sdd] Attached SCSI disk
>> [ 11.684439] rk_gmac-dwmac ff540000.ethernet eth0: Link is Up - 1Gbps/Full - flow control off
>> [ 11.685233] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
>> [ 18.069675] random: tinysshd: uninitialized urandom read (32 bytes read)
>> [ 18.070281] random: tinysshd: uninitialized urandom read (32 bytes read)
>> [ 18.070869] random: tinysshd: uninitialized urandom read (32 bytes read)
>> tinysshd: Sp4K1mMd: info: connection from 192.168.0.101:49174 {main_tinysshd.c:106}
>> tinysshd: Sp4K1mMd: info: auth: root: ssh-ed25519 AAAAC3NzaC1lZDI1NTE5AAAAIHMqaXwhM3qPqU0hiTeYybGyMCocfqCT6GlLzgYSkkNG accepted {packet_auth.c:155}
>> [ 38.083543] raid6: neonx8 gen() 1662 MB/s
>> [ 38.253541] raid6: neonx8 xor() 1584 MB/s
>> [ 38.423553] raid6: neonx4 gen() 1605 MB/s
>> [ 38.593539] raid6: neonx4 xor() 1544 MB/s
>> [ 38.763531] raid6: neonx2 gen() 1226 MB/s
>> [ 38.933530] raid6: neonx2 xor() 1280 MB/s
>> [ 39.103541] raid6: neonx1 gen() 819 MB/s
>> [ 39.273544] raid6: neonx1 xor() 964 MB/s
>> [ 39.443555] raid6: int64x8 gen() 1258 MB/s
>> [ 39.613525] raid6: int64x8 xor() 822 MB/s
>> [ 39.783558] raid6: int64x4 gen() 1061 MB/s
>> [ 39.953523] raid6: int64x4 xor() 800 MB/s
>> [ 40.123545] raid6: int64x2 gen() 732 MB/s
>> [ 40.293536] raid6: int64x2 xor() 651 MB/s
>> [ 40.463529] raid6: int64x1 gen() 476 MB/s
>> [ 40.633545] raid6: int64x1 xor() 495 MB/s
>> [ 40.633920] raid6: using algorithm neonx8 gen() 1662 MB/s
>> [ 40.634390] raid6: .... xor() 1584 MB/s, rmw enabled
>> [ 40.634825] raid6: using neon recovery algorithm
>> [ 40.640476] xor: measuring software checksum speed
>> [ 40.733529] 8regs : 2551.200 MB/sec
>> [ 40.833521] 32regs : 2921.600 MB/sec
>> [ 40.933517] arm64_neon: 2579.200 MB/sec
>> [ 40.933883] xor: using function: 32regs (2921.600 MB/sec)
>> [ 41.000114] Btrfs loaded, crc32c=crc32c-generic
>> [ 41.004168] BTRFS: device label Root devid 1 transid 7598 /dev/dm-0
>> Error reading passphrase from terminal.
>> tinysshd: Sp4K1mMd: info: finished {main_tinysshd.c:287}
>> :: performing fsck on '/dev/mapper/cryptroot'
>> :: mounting '/dev/mapper/cryptroot' on real root
>> [ 41.155941] BTRFS info (device dm-0): disk space caching is enabled
>> [ 41.156513] BTRFS info (device dm-0): has skinny extents
>> [ 41.168464] BTRFS info (device dm-0): enabling ssd optimizations
>> :: running cleanup hook [tinyssh]
>> :: running cleanup hook [netconf]
>> [ 41.203478] rk_gmac-dwmac ff540000.ethernet eth0: Link is Down
>> :: running cleanup hook [udev]
>> [ 41.615555] systemd[1]: System time before build time, advancing clock.
>> [ 41.624867] systemd[1]: systemd 242.84-1-arch running in system mode. (+PAM +AUDIT -SELINUX -IMA -APPARMOR +SMACK -SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD +IDN2 -IDN +PCRE2 default-hierarchy=hybrid)
>> [ 41.626865] systemd[1]: No virtualization found in DMI
>> [ 41.627321] systemd[1]: No virtualization found in CPUID
>> [ 41.627819] systemd[1]: Virtualization XEN not found, /proc/xen does not exist
>> [ 41.628668] systemd[1]: No virtualization found in /proc/device-tree/*
>> [ 41.629421] systemd[1]: UML virtualization not found in /proc/cpuinfo.
>> [ 41.630004] systemd[1]: This platform does not support /proc/sysinfo
>> [ 41.630566] systemd[1]: Found VM virtualization none
>> [ 41.631012] systemd[1]: Detected architecture arm64.
>> [ 41.633743] systemd[1]: Mounting cgroup to /sys/fs/cgroup/hugetlb of type cgroup with options hugetlb.
>>
>> Welcome to Arch Linux ARM!
>>
>> [ 41.872853] systemd-gpt-auto-generator[657]: mmcblk1p2: Root device /dev/mmcblk1.
>> [ 41.878670] systemd-bless-boot-generator[652]: Skipping generator, not an EFI boot.
>> [ 41.882360] systemd-getty-generator[656]: Automatically adding serial getty for /dev/ttyS2.
>> [ 41.889365] systemd-hibernate-resume-generator[658]: Not running in an initrd, quitting.
>> [ 41.896703] systemd-fstab-generator[655]: Parsing /etc/fstab...
>> [ 41.898123] systemd-fstab-generator[655]: Found entry what=/dev/disk/by-uuid/0250489f-2c3d-499e-9ff1-8f85451622e7 where=/ type=btrfs makefs=no growfs=no noauto=no nofail=no
>> [ 41.900379] systemd-fstab-generator[655]: Found entry what=/dev/disk/by-uuid/0250489f-2c3d-499e-9ff1-8f85451622e7 where=/var type=btrfs makefs=no growfs=no noauto=no nofail=no
>> [ 41.902542] systemd-fstab-generator[655]: Found entry what=/dev/disk/by-uuid/0250489f-2c3d-499e-9ff1-8f85451622e7 where=/home type=btrfs makefs=no growfs=no noauto=no nofail=no
>> [ 41.904857] systemd-fstab-generator[655]: Found entry what=/dev/disk/by-uuid/01b27405-03cc-47e4-9171-aa221f71efaf where=/boot type=ext4 makefs=no growfs=no noauto=no nofail=no
>> [ 41.911126] systemd-gpt-auto-generator[657]: No suitable partition table found, ignoring.
>> [ 41.912724] systemd-fstab-generator[655]: Found entry what=proc where=/proc type=proc makefs=no growfs=no noauto=no nofail=no
>> [ 41.915293] systemd-fstab-generator[655]: Found entry what=/dev/disk/by-uuid/0250489f-2c3d-499e-9ff1-8f85451622e7 where=/mnt/system type=btrfs makefs=no growfs=no noauto=no nofail=no
>> [ 41.918223] systemd-fstab-generator[655]: Found entry what=/dev/disk/by-uuid/0250489f-2c3d-499e-9ff1-8f85451622e7 where=/mnt/btrfs type=btrfs makefs=no growfs=no noauto=yes nofail=no
>> [ 41.921076] systemd-fstab-generator[655]: Found entry what=/dev/disk/by-uuid/ff2c0deb-7819-4b85-a6d3-5d6c1b1cfb99 where=/mnt/glassvault type=btrfs makefs=no growfs=no noauto=yes nofail=yes
>> [ 41.924026] systemd-fstab-generator[655]: Found entry what=/mnt/glassvault where=/srv/nfs/glassvault type=none makefs=no growfs=no noauto=yes nofail=yes
>> [ OK ] Started Dispatch Password ÔÇŽts to Console Directory Watch.
>> [ OK ] Created slice system-serial\x2dgetty.slice.
>> [ OK ] Set up automount ArbitraryÔÇŽs File System Automount Point.
>> [ OK ] Listening on initctl Compatibility Named Pipe.
>> [ OK ] Listening on Journal Socket (/dev/log).
>> [ OK ] Listening on Process Core Dump Socket.
>> [ OK ] Listening on LVM2 poll daemon socket.
>> [ OK ] Created slice system-shadoÔÇŽocks\x2dlibev\x2dserver.slice.
>> [ OK ] Listening on Network Service Netlink Socket.
>> [ OK ] Listening on Device-mapper event daemon FIFOs.
>> [ OK ] Listening on Journal Audit Socket.
>> [ OK ] Listening on LVM2 metadata daemon socket.
>> [ OK ] Listening on RPCbind Server Activation Socket.
>> [ OK ] Reached target RPC Port Mapper.
>> [ OK ] Created slice User and Session Slice.
>> [ OK ] Reached target Slices.
>> [ OK ] Reached target Remote File Systems.
>> [ OK ] Started Forward Password RÔÇŽuests to Wall Directory Watch.
>> [ OK ] Reached target Local Encrypted Volumes.
>> [ OK ] Listening on Journal Socket.
>> Starting Create list of reÔÇŽodes for the current kernel...
>> Starting Journal Service...
>> [ 42.851473] systemd[669]: Operating on architecture: arm
>> [ 42.865047] systemd[669]: Operating on architecture: arm64
>> [ 42.869802] systemd[669]: Operating on architecture: arm
>> [ 42.870570] systemd[669]: Operating on architecture: arm64
>> [ 42.871225] systemd[669]: Operating on architecture: arm
>> [ 42.871892] systemd[669]: Operating on architecture: arm64
>> [ 42.873964] systemd[669]: Failed to add filter for chmod: Numerical argument out of domain
>> [ 42.874837] systemd[669]: Failed to add filter for mkdir: Numerical argument out of domain
>> [ 42.875724] systemd[669]: Failed to add filter for mknod: Numerical argument out of domain
>> [ 42.876602] systemd[669]: Failed to add filter for creat: Numerical argument out of domain
>> [ 42.877493] systemd[669]: Failed to add filter for chmod: Numerical argument out of domain
>> [ 42.878417] systemd[669]: Failed to add filter for mkdir: Numerical argument out of domain
>> [ 42.879461] systemd[669]: Failed to add filter for mknod: Numerical argument out of domain
>> Mounting POSIX Message [Queue File System... 42.880441] systemd[669]: Failed to add filter for creat: Numerical argument out of domain
>>
>> [ 42.881994] systemd[669]: Restricting namespace to: .
>> [ 42.882560] systemd[669]: Operating on architecture: arm
>> [ 42.883205] systemd[669]: Blocking cgroup.
>> [ 42.883835] systemd[669]: Blocking ipc.
>> [ 42.884441] systemd[669]: Blocking net.
>> [ 42.885071] systemd[669]: Blocking mnt.
>> [ 42.885718] systemd[669]: Blocking pid.
>> [ 42.886470] systemd[669]: Blocking user.
>> [ 42.887266] systemd[669]: Blocking uts.
>> [ 42.888473] systemd[669]: Operating on architecture: arm64
>> [ 42.889217] systemd[669]: Blocking cgroup.
>> Mounting NFSD configuration filesystem...[ 42.889759] systemd[669]: Blocking ipc.
>>
>> [ 42.890695] systemd[669]: Blocking net.
>> [ 42.891278] systemd[669]: Blocking mnt.
>> [ 42.891883] systemd[669]: Blocking pid.
>> [ 42.892515] systemd[669]: Blocking user.
>> [ 42.893131] systemd[669]: Blocking uts.
>> [ 42.894839] systemd[669]: Operating on architecture: arm
>> Starting Remount Root and Kernel File Systems...
>> Starting Monitoring of LVMÔÇŽmeventd or progress polling...
>> Mounting Huge Pages File System...
>> Mounting Kernel Debug File System...
>> Starting Load Kernel Modules...
>> [ OK ] Reached target Paths.
>> [ OK ] Created slice system-getty.slice.
>> [ OK ] Created slice system-systemd\x2dfsck.slice.
>> [ 43.019560] Installing knfsd (copyright (C) 1996 okir@monad.swb.de).
>> [ OK ] Reached target Swap.
>> [ 43.061827] random: crng init done
>> [ 43.062147] random: 5 urandom warning(s) missed due to ratelimiting
>> Mounting Temporary Directory (/tmp)...
>> [ OK ] Listening on udev Kernel Socket.
>> [ OK ] Listening on udev Control Socket.
>> Starting udev Coldplug all Devices...
>> [ OK ] Started Create list of reqÔÇŽ nodes for the current kernel.
>> [ OK ] Mounted POSIX Message Queue File System.
>> [ OK ] Mounted NFSD configuration filesystem.
>> [ OK ] Mounted Huge Pages File System.
>> [ OK ] Mounted Kernel Debug File System.
>> [ OK ] Mounted Temporary Directory (/tmp).
>> [ OK ] Started LVM2 metadata daemon.
>> [ OK ] Started Load Kernel Modules.
>> [ 43.379747] BTRFS info (device dm-0): force zstd compression, level 3
>> [ 43.380343] BTRFS info (device dm-0): enabling auto defrag
>> [ 43.380831] BTRFS info (device dm-0): disk space caching is enabled
>> [ OK ] Started Remount Root and Kernel File Systems.
>> Starting Create Static Device Nodes in /dev...
>> [ 43.456422] systemd[669]: Operating on architecture: arm64
>> Mounting Kernel Configuration File System...
>> Starting Apply Kernel Variables...
>> [ OK ] Started Create Static Device Nodes in /dev.
>> [ OK ] Mounted Kernel Configuration File System.
>> Starting udev Kernel Device Manager...
>> [ 43.560384] systemd[689]: Applying namespace mount on /run/systemd/unit-root/proc/sys/kernel/domainname
>> [ 43.562423] systemd[689]: Successfully mounted /run/systemd/unit-root/proc/sys/kernel/domainname to /run/systemd/unit-root/proc/sys/kernel/domainname
>> [ 43.564229] systemd[689]: Applying namespace mount on /run/systemd/unit-root/proc/sys/kernel/hostname
>> [ 43.565938] systemd[689]: Successfully mounted /run/systemd/unit-root/proc/sys/kernel/hostname to /run/systemd/unit-root/proc/sys/kernel/hostname
>> [ 43.569970] systemd[689]: Remounted /run/systemd/unit-root/proc/sys/kernel/domainname read-only.
>> [ OK ] Started Apply Kernel Variables.
>> [ 43.577304] systemd[689]: Remounted /run/systemd/unit-root/proc/sys/kernel/hostname read-only.
>> [ 43.581074] systemd[689]: Operating on architecture: arm
>> [ 43.594152] systemd[689]: Operating on architecture: arm64
>> [ 43.598579] systemd[689]: Operating on architecture: arm
>> [ 43.599557] systemd[689]: Operating on architecture: arm64
>> [ 43.600430] systemd[689]: Operating on architecture: arm
>> [ 43.601341] systemd[689]: Operating on architecture: arm64
>> [ 43.603628] systemd[689]: Failed to add filter for chmod: Numerical argument out of domain
>> [ 43.604547] systemd[689]: Failed to add filter for mkdir: Numerical argument out of domain
>> [ 43.605441] systemd[689]: Failed to add filter for mknod: Numerical argument out of domain
>> [ 43.606350] systemd[689]: Failed to add filter for creat: Numerical argument out of domain
>> [ 43.607264] systemd[689]: Failed to add filter for chmod: Numerical argument out of domain
>> [ 43.608214] systemd[689]: Failed to add filter for mkdir: Numerical argument out of domain
>> [ 43.609135] systemd[689]: Failed to add filter for mknod: Numerical argument out of domain
>> [ 43.610102] systemd[689]: Failed to add filter for creat: Numerical argument out of domain
>> [ 43.611583] systemd[689]: Operating on architecture: arm
>> [ 43.616441] systemd-journald[669]: Found cgroup2 on /sys/fs/cgroup/unified, unified hierarchy for systemd controller
>> [ 43.620916] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 43.622158] systemd-journald[669]: Fixed min_use=1.0M max_use=197.9M max_size=24.7M min_size=512.0K keep_free=296.9M n_max_files=100
>> [ 43.630406] systemd-journald[669]: Reserving 45048 entries in hash table.
>> [ 43.632304] systemd-journald[669]: Vacuuming...
>> [ 43.632849] systemd-journald[669]: Vacuuming done, freed 0B of archived journals from /run/log/journal/efd1758296a94bd09cc2ba3f0bb50427.
>> [ 43.634519] systemd-journald[669]: Flushing /dev/kmsg...
>> [ OK ] Started udev Coldplug all Devices.
>> [ 43.739307] audit: type=1130 audit(1563803537.110:2): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=systemd-udev-trigger comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
>> [ 43.791517] systemd-journald[669]: systemd-journald running as pid 669
>> [ 43.793456] systemd-journald[669]: Sent READY=1 notification.
>> [ OK ] Started Journal Service.
>> [ 43.795061] systemd-journald[669]: Sent WATCHDOG=1 notification.
>> [ 43.824274] audit: type=1130 audit(1563803537.200:3): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=systemd-journald comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
>> [ 44.076504] systemd[689]: Operating on architecture: arm64
>> [ OK ] Started udev Kernel Device Manager.
>> [ 44.252653] audit: type=1130 audit(1563803537.620:4): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=systemd-udevd comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
>> [ 44.648398] dw_wdt: probe of ff1a0000.watchdog failed with error -2
>> [ OK ] Found device /dev/ttyS2.
>> [ 44.757081] rk3328-codec ff410000.codec: spk_depop_time use default value.
>> [ 44.790519] lima ff300000.gpu: bus rate = 163840000
>> [ 44.790972] lima ff300000.gpu: mod rate = 163840000
>> [ 44.794707] lima ff300000.gpu: gp - mali450 version major 0 minor 0
>> [ 44.795567] lima ff300000.gpu: pp0 - mali450 version major 0 minor 0
>> [ 44.796240] lima ff300000.gpu: pp1 - mali450 version major 0 minor 0
>> [ 44.796902] lima ff300000.gpu: l2 cache 8K, 4-way, 64byte cache line, 128bit external bus
>> [ 44.797632] lima ff300000.gpu: l2 cache 64K, 4-way, 64byte cache line, 128bit external bus
>> [ 44.809584] [drm] Initialized lima 1.0.0 20190217 for ff300000.gpu on minor 0
>> [ 44.825769] Registered IR keymap rc-empty
>> [ 44.826345] rc rc0: gpio_ir_recv as /devices/platform/ir-receiver/rc/rc0
>> [ 44.827194] input: gpio_ir_recv as /devices/platform/ir-receiver/rc/rc0/input0
>> [ 44.834847] rc rc0: lirc_dev: driver gpio_ir_recv registered at minor = 0, raw IR receiver, no transmitter
>> [ 44.854765] rk808-rtc rk808-rtc: registered as rtc0
>> [ 44.890633] rockchip-vop ff370000.vop: Adding to iommu group 0
>> [ 44.928197] rockchip-drm display-subsystem: bound ff370000.vop (ops vop_component_ops [rockchipdrm])
>> [ 44.929475] dwhdmi-rockchip ff3c0000.hdmi: Detected HDMI TX controller v2.11a with HDCP (inno_dw_hdmi_phy2)
>> [ 44.947455] dwhdmi-rockchip ff3c0000.hdmi: registered DesignWare HDMI I2C bus driver
>> [ 44.949808] rockchip-drm display-subsystem: bound ff3c0000.hdmi (ops dw_hdmi_rockchip_ops [rockchipdrm])
>> [ 44.950657] [drm] Supports vblank timestamp caching Rev 2 (21.10.2013).
>> [ 44.951237] [drm] No driver support for vblank timestamp query.
>> [ 44.951834] [drm] Cannot find any crtc or sizes
>> [ 44.973910] [drm] Initialized rockchip 1.0.0 20140818 for display-subsystem on minor 1
>> [ OK ] Found device /dev/disk/by-ÔÇŽ5-03cc-47e4-9171-aa221f71efaf.
>> [ 45.224367] BTRFS info (device dm-0): device fsid 0250489f-2c3d-499e-9ff1-8f85451622e7 devid 1 moved old:/dev/mapper/cryptroot new:/dev/dm-0
>> [ 45.228575] BTRFS info (device dm-0): device fsid 0250489f-2c3d-499e-9ff1-8f85451622e7 devid 1 moved old:/dev/dm-0 new:/dev/mapper/cryptroot
>> [ 45.353655] Registered IR keymap rc-cec
>> [ 45.354235] rc rc1: dw_hdmi as /devices/platform/ff3c0000.hdmi/rc/rc1
>> [ 45.355089] input: dw_hdmi as /devices/platform/ff3c0000.hdmi/rc/rc1/input1
>> [ OK ] Found device /dev/disk/by-ÔÇŽf-2c3d-499e-9ff1-8f85451622e7.
>> [ 46.003691] [drm] Cannot find any crtc or sizes
>> [ 46.396387] md127: detected capacity change from 0 to 1106309687296
>> [ 46.398853] md126: detected capacity change from 0 to 1106444953600
>> [ 46.476618] async_tx: api initialized (async)
>> [ 46.506798] md/raid:md125: not clean -- starting background reconstruction
>> [ 46.507534] md/raid:md125: device md127 operational as raid disk 1
>> [ 46.508087] md/raid:md125: device md126 operational as raid disk 2
>> [ 46.508628] md/raid:md125: device sda1 operational as raid disk 0
>> [ 46.511127] md/raid:md125: raid level 5 active with 3 out of 3 devices, algorithm 2
>> [ 46.544057] md125: detected capacity change from 0 to 2212348559360
>> Starting MD array monitor...
>> [ OK ] Started MD array monitor.
>> [ 46.704045] audit: type=1130 audit(1563803540.080:5): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=mdmonitor comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
>> [ OK ] Started Monitoring of LVM2ÔÇŽ dmeventd or progress polling.
>> [ 46.883882] audit: type=1130 audit(1563803540.260:6): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=lvm2-monitor comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
>> [ OK ] Reached target Local File Systems (Pre).
>> Starting File System CheckÔÇŽ03cc-47e4-9171-aa221f71efaf...
>> Mounting /home...
>> Mounting /var...
>> Mounting /mnt/system...
>> [ OK ] Mounted /home.
>> [ OK ] Mounted /var.
>> [ OK ] Mounted /mnt/system.
>> Starting Load/Save Random Seed...
>> Starting Flush Journal to Persistent Storage...
>> [ OK ] Started Load/Save Random Seed.
>> [ 47.060046] audit: type=1130 audit(1563803540.430:7): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=systemd-random-seed comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
>> Boot: fsck 0.0% complete... [ OK ] Started File System Check ÔÇŽ5-03cc-47e4-9171-aa221f71efaf.
>> [ 47.194761] audit: type=1130 audit(1563803540.570:8): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=systemd-fsck@dev-disk-by\x2duuid-01b27405\x2d03cc\x2d47e4\x2d9171\x2daa221f71efaf comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
>> Mounting /boot...
>> [ 47.225323] EXT4-fs (mmcblk1p1): mounted filesystem with ordered data mode. Opts: (null)
>> [ OK ] Mounted /boot.
>> [ OK ] Reached target Local File Systems.
>> [ OK ] Started Flush Journal to Persistent Storage.
>> [ 47.553975] audit: type=1130 audit(1563803540.930:9): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=systemd-journal-flush comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
>> Starting Create Volatile Files and Directories...
>> [ OK ] Started Create Volatile Files and Directories.
>> [ 47.684031] audit: type=1130 audit(1563803541.060:10): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=systemd-tmpfiles-setup comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
>> Starting Update UTMP about System Boot/Shutdown...
>> Starting Network Time Synchronization...
>> Starting Entropy Harvesting Daemon...
>> Mounting RPC Pipe File System...
>> [ OK ] Mounted RPC Pipe File System.
>> [ 47.759423] audit: type=1127 audit(1563803541.130:11): pid=773 uid=0 auid=4294967295 ses=4294967295 msg=' comm="systemd-update-utmp" exe="/usr/lib/systemd/systemd-update-utmp" hostname=? addr=? terminal=? res=success'
>> [ OK ] Started Entropy Harvesting Daemon.
>> [ OK ] Reached target rpc_pipefs.target.
>> Starting NFSv4 ID-name mapping service...
>> Starting NFSv4 Client Tracking Daemon...
>> [ OK ] Started Update UTMP about System Boot/Shutdown.
>> [ OK ] Started NFSv4 Client Tracking Daemon.
>> [ OK ] Started NFSv4 ID-name mapping service.
>> [ OK ] Started Network Time Synchronization.
>> [ OK ] Reached target System Time Set.
>> [ OK ] Reached target System Time Synchronized.
>> [ OK ] Reached target System Initialization.
>> [ 48.644114] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ OK ] Started Daily Cleanup of Snapper Sna[pshots.
>> 48.645438] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 48.646953] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ OK ] Started ;39mRun root.hints monthly.
>> 48.648291] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 48.649862] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ OK ] Started Discard unused blocks once a[ week.
>> 48.651343] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 48.652826] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ OK ] Listening on D-Bus System Message Bus Socket.
>> [ 48.654536] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 48.656126] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 48.657259] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ OK ] Reached target Sockets.
>> [ OK ] Started Monthly Btrfs scrub on /mnt/glassvault.
>> [ OK ] Started Daily man-db regeneration.
>> [ OK ] Started Daily Cleanup of Temporary Directories.
>> [ OK ] Started Daily reset of dnsmasq/pi-hole query log.
>> [ OK ] Started Daily renewal of acme.sh certificates.
>> [ OK ] Reached target Basic System.
>> [ OK ] Started irqbalance daemon.
>> [ 48.894079] kauditd_printk_skb: 6 callbacks suppressed
>> [ 48.894086] audit: type=1130 audit(1565697884.849:18): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=irqbalance comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
>> [ OK ] Started Manage swap spacesÔÇŽn zram, files and partitions..
>> [ 48.933669] audit: type=1130 audit(1565697884.879:19): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=systemd-swap comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
>> [ OK ] Started D-Bus System Message Bus.
>> [ 48.955601] audit: type=1130 audit(1565697884.909:20): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=dbus comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
>> [ OK ] Started DNSCrypt-proxy client.
>> [ 48.969499] audit: type=1130 audit(1565697884.919:21): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=dnscrypt-proxy comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
>> Starting Netfilter Tables...
>> Starting GSSAPI Proxy Daemon...
>> Starting Self Monitoring aÔÇŽg Technology (SMART) Daemon...
>> Starting IPv4 Packet Filtering Framework...
>> Starting Login Service...
>> [ OK ] Started Timeline of Snapper Snapshots.
>> Starting USBGuard daemon...
>> [ OK ] Started Pi-hole FTLDNS engine.
>> [ 49.072725] audit: type=1130 audit(1565697885.019:22): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=pihole-FTL comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
>> [ OK ] Started Run periodic raid volume scrub.
>> [ OK ] Started Daily rotation of log files.
>> Starting Restore system tiÔÇŽoot and save it on shutdown...
>> [ OK ] Started Daily verification of password and group files.
>> [ OK ] Started Weekly ad-serving domains gathering.
>> [ 49.209107] bpfilter: Loaded bpfilter_umh pid 801
>> Started bpfilter
>> [ OK ] Started Netfilter Tables.
>> [ 49.223993] audit: type=1130 audit(1565697885.179:23): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=nftables comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
>> [ 49.257418] audit: type=1325 audit(1565697885.209:24): table=mangle family=2 entries=0
>> [ 49.298437] audit: type=1325 audit(1565697885.249:25): table=mangle family=2 entries=6
>> [ 49.324654] audit: type=1325 audit(1565697885.269:26): table=nat family=2 entries=0
>> [ 49.365322] audit: type=1325 audit(1565697885.319:27): table=nat family=2 entries=5
>> [ OK ] Started Restore system timÔÇŽ boot and save it on shutdown.
>> [ OK ] Started Periodically saves system time to file timer.
>> [ OK ] Reached target Timers.
>> [ OK ] Started IPv4 Packet Filtering Framework.
>> [ OK ] Reached target Network (Pre).
>> Starting Network Service...
>> [ OK ] Started SSHGuard - blocks brute-force login attempts.
>> [ OK ] Started GSSAPI Proxy Daemon.
>> [ OK ] Started USBGuard daemon.
>> [ OK ] Started Login Service.
>> [ 50.956002] wireguard: loading out-of-tree module taints kernel.
>> [ 50.961332] wireguard: WireGuard 0.0.20190702 loaded. See www.wireguard.com for information.
>> [ 50.962091] wireguard: Copyright (C) 2015-2019 Jason A. Donenfeld <Jason@zx2c4.com>. All Rights Reserved.
>> [ OK ] Started Network Service.
>> [ OK ] Reached target Network.
>> Starting The PHP FastCGI Process Manager...
>> [ OK ] Started DNS-over-HTTPS Server.
>> Starting Sets the firmwareÔÇŽr sslh transparent proxying...
>> [ OK ] Started SSL/SSH multiplexer (fork mode).
>> Starting Permit User Sessions...
>> [ OK ] Started Unbound DNS Resolver.
>> [ OK ] Reached target Host and Network Name Lookups.
>> [ OK ] Started OpenSSH Daemon.
>> Starting Wait for Network to be Configured...
>> [ 51.172034] Generic PHY stmmac-0:00: attached PHY driver [Generic PHY] (mii_bus:phy_addr=stmmac-0:00, irq=POLL)
>> [ 51.195007] rk_gmac-dwmac ff540000.ethernet eth0: No Safety Features support found
>> [ 51.195723] rk_gmac-dwmac ff540000.ethernet eth0: PTP not supported by HW
>> [ OK ] Started Permit User Sessions.
>> [ OK ] Started Serial Getty on ttyS2.
>> [ OK ] Started Getty on tty1.
>> [ OK ] Reached target Login Prompts.
>> [ OK ] Started Sets the firmware ÔÇŽfor sslh transparent proxying.
>> [ OK ] Started The PHP FastCGI Process Manager.
>> [ 53.826878] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 53.828624] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 53.831031] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 53.832480] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 53.833946] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 53.835131] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 53.837031] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 53.838244] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 54.055881] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 54.324463] rk_gmac-dwmac ff540000.ethernet eth0: Link is Up - 1Gbps/Full - flow control off
>> [ 54.325250] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
>> [ 54.327569] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ OK ] Started Self Monitoring anÔÇŽing Technology (SMART) Daemon.
>> [ 55.385487] kauditd_printk_skb: 21 callbacks suppressed
>> [ 55.385497] audit: type=1130 audit(1565697891.339:49): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=smartd comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
>>
>> Arch Linux 5.2.8-1-ARCH (ttyS2)
>>
>> rock64 login: [ 59.214222] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 62.238720] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 62.240107] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 62.241259] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 62.243201] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 62.244906] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 66.989756] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 67.454244] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 67.455689] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 67.457426] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 67.459017] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 67.460459] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 67.463440] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 67.465034] audit: type=1130 audit(1565697903.419:50): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=systemd-networkd-wait-online comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
>> [ 67.465737] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 67.468255] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 67.469798] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 67.494954] audit: type=1130 audit(1565697903.449:51): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=shadowsocks-libev-server@main comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
>> [ 67.520464] audit: type=1130 audit(1565697903.469:52): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=badvpn-udpgw comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
>> [ 67.786151] audit: type=1130 audit(1565697903.739:53): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=rpcbind comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
>> [ 67.902328] audit: type=1130 audit(1565697903.849:54): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=nfs-mountd comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
>> [ 67.936170] audit: type=1130 audit(1565697903.889:55): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=rpc-statd comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
>> [ 68.641217] audit: type=1006 audit(1565697976.049:56): pid=946 uid=0 old-auid=4294967295 auid=1000 tty=(none) old-ses=4294967295 ses=1 res=1
>> [ 68.840807] audit: type=1130 audit(1565697976.249:57): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=user-runtime-dir@1000 comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
>> [ 68.893470] audit: type=1006 audit(1565697976.299:58): pid=949 uid=0 old-auid=4294967295 auid=1000 tty=(none) old-ses=4294967295 ses=2 res=1
>> [ 69.213378] audit: type=1130 audit(1565697976.619:59): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=user@1000 comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
>> [ 69.243287] NFSD: Using UMH upcall client tracking operations.
>> [ 69.244017] NFSD: starting 90-second grace period (net f0000041)
>> [ 72.241052] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 72.244099] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 72.245874] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 72.249252] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 72.251023] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 73.124974] kauditd_printk_skb: 3 callbacks suppressed
>> [ 73.124983] audit: type=1130 audit(1565697980.539:63): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=nginx comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
>> [ 73.130861] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 73.133510] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 73.135056] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 73.136624] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 73.138327] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 82.242506] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 82.244715] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 82.246099] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 82.248165] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 82.249761] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 83.139292] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 83.634981] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 83.636562] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 83.644113] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 83.645561] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 92.243757] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 92.245343] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 92.246621] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 92.248712] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 92.250083] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 92.305936] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 92.307542] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 96.087683] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 96.089672] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 99.992391] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 99.995134] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 100.009809] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 100.011427] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 100.012874] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 100.014582] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 100.016023] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 100.017451] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 100.018886] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 100.020424] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 110.453073] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 112.246751] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 112.248255] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 112.249536] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 112.251623] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 112.253373] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 116.789143] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 116.791332] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 122.247692] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 122.249305] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 122.250627] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 122.252881] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 122.254487] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 127.256164] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 132.134131] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 132.135900] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 132.138645] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 132.140302] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 132.248524] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 132.250121] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 132.251465] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 132.254046] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 132.255420] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 137.266628] systemd-journald[669]: Sent WATCHDOG=1 notification.
>> [ 137.268381] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 137.270070] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 137.271736] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 140.616211] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 140.618868] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 142.251132] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 142.252867] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 142.254303] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 142.256375] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 145.655478] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 145.657011] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 145.658262] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 145.659373] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 145.660429] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 145.661573] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 147.393139] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 149.843874] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 149.845490] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 149.857427] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 152.252266] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 152.253929] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 152.255227] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 152.257368] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 152.258795] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 152.260030] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 162.254157] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 162.255578] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 162.256922] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 162.259009] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 162.260384] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 164.241031] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 164.243650] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 164.256993] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 164.258552] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 164.259879] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 172.260227] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 172.262468] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 172.264983] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 172.268760] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 172.270888] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 177.744261] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 181.790879] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 181.793721] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 181.795819] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 181.797566] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 181.799157] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 181.800686] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 181.802208] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 181.804161] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 181.805651] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 181.853499] BTRFS: device label glassvault devid 1 transid 158 /dev/dm-1
>> [ 182.016417] BTRFS info (device dm-1): use zstd compression, level 3
>> [ 182.016994] BTRFS info (device dm-1): enabling auto defrag
>> [ 182.017480] BTRFS info (device dm-1): using free space tree
>> [ 182.017969] BTRFS info (device dm-1): has skinny extents
>> [ 185.985238] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 185.987454] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 192.259719] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 192.261283] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 192.262602] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 192.264842] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 192.266418] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 198.948770] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 198.950491] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 198.962249] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 198.965024] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 198.969102] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 202.262706] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 202.264077] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 202.265752] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 202.267791] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 202.269168] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 207.655433] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 207.657304] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 207.664183] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 207.665886] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 207.667129] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 207.668288] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 212.264137] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 212.265989] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 212.267535] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 212.269706] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 222.266006] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 222.267594] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 222.269130] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 222.271555] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 222.273052] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 232.266074] systemd-journald[669]: Sent WATCHDOG=1 notification.
>> [ 232.268564] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 232.270050] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 232.271344] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 232.272535] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 232.274607] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 232.276380] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 232.638382] md: resync of RAID array md125
>> [ 232.645139] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 242.269536] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 242.271637] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 242.273298] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 242.276092] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 242.277783] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 243.626042] md: md125: resync done.
>> [ 243.635245] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 252.269905] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 252.271477] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 252.272766] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 252.274817] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 252.276595] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 252.277902] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 262.271635] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 262.273186] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 262.274456] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 262.276997] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 262.278409] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 264.246527] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 264.248184] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 264.259992] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 264.262711] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 269.676730] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 269.679255] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 269.681054] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 269.682571] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 269.683821] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 269.684918] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 269.689241] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 272.273301] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 272.275635] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 272.277416] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 276.946561] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 282.273887] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 282.275672] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 282.277647] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 282.281113] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 282.282677] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 292.275830] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 292.278158] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 292.279919] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 292.282723] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 292.284537] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 292.493843] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 292.497018] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 292.510796] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 292.512356] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 292.514254] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 297.744948] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 302.276998] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 302.278991] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 302.280379] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 302.282442] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 302.284106] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 302.285505] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 312.280762] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 312.283020] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 312.284825] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 312.288147] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 312.294199] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 320.099648] systemd-journald[669]: Sent WATCHDOG=1 notification.
>> [ 320.101231] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 320.103946] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 320.105550] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 322.311538] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 322.314402] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 322.316094] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 322.320394] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 322.322165] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 331.675338] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 331.677478] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 331.683766] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 331.685182] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 331.686379] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 331.688101] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 332.306306] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 332.308445] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 332.310098] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 332.316364] systemd-journald[669]: Journal effective settings seal=no compress=yes compress_threshold_bytes=512B
>> [ 334.414128] SError Interrupt on CPU0, code 0xbf000002 -- SError
>> [ 334.414136] CPU: 0 PID: 1774 Comm: dd Tainted: G O 5.2.8-1-ARCH #1
>> [ 334.414137] Hardware name: Pine64 Rock64 (DT)
>> [ 334.414139] pstate: 20000005 (nzCv daif -PAN -UAO)
>> [ 334.414141] pc : __arch_copy_from_user+0x1bc/0x240
>> [ 334.414142] lr : copyin+0x54/0x68
>> [ 334.414144] sp : ffff000013523aa0
>> [ 334.414145] x29: ffff000013523aa0 x28: 0000000000001000
>> [ 334.414149] x27: ffff8000e112ec00 x26: 0000000000000005
>> [ 334.414152] x25: ffff000013523d50 x24: 0000000000005000
>> [ 334.414155] x23: 0000000000001000 x22: ffff800009c02000
>> [ 334.414158] x21: ffff000013523d40 x20: 00000000000d5000
>> [ 334.414161] x19: 0000000000000000 x18: 0000000000000000
>> [ 334.414164] x17: 0000000000000000 x16: 0000000000000000
>> [ 334.414167] x15: 0000000000000000 x14: 268451e20def8ac3
>> [ 334.414170] x13: e9bb458ce1212efb x12: 9f52f204714b75c4
>> [ 334.414173] x11: 0e6bc7b591c2d6e4 x10: 40d3c7db468453cb
>> [ 334.414176] x9 : 0d91295116253226 x8 : d0355f82a419091a
>> [ 334.414179] x7 : 911b47420a1c00a2 x6 : ffff800009c01150
>> [ 334.414182] x5 : ffff800009c02000 x4 : 0000000000000000
>> [ 334.414185] x3 : 0000ffffbdbc4000 x2 : 0000000000000e40
>> [ 334.414188] x1 : 0000ffffbdbc4190 x0 : ffff800009c01000
>> [ 334.414191] Kernel panic - not syncing: Asynchronous SError Interrupt
>> [ 334.414194] CPU: 0 PID: 1774 Comm: dd Tainted: G O 5.2.8-1-ARCH #1
>> [ 334.414195] Hardware name: Pine64 Rock64 (DT)
>> [ 334.414197] Call trace:
>> [ 334.414198] dump_backtrace+0x0/0x168
>> [ 334.414199] show_stack+0x24/0x30
>> [ 334.414200] dump_stack+0xa8/0xcc
>> [ 334.414201] panic+0x150/0x320
>> [ 334.414203] __stack_chk_fail+0x0/0x28
>> [ 334.414204] arm64_serror_panic+0x80/0x8c
>> [ 334.414206] do_serror+0x11c/0x120
>> [ 334.414207] el1_error+0x84/0xf8
>> [ 334.414208] __arch_copy_from_user+0x1bc/0x240
>> [ 334.414210] iov_iter_copy_from_user_atomic+0xe4/0x390
>> [ 334.414212] btrfs_copy_from_user+0x68/0x120 [btrfs]
>> [ 334.414213] btrfs_buffered_write.isra.5+0x354/0x638 [btrfs]
>> [ 334.414214] btrfs_file_write_iter+0x3b0/0x4e0 [btrfs]
>> [ 334.414216] new_sync_write+0x110/0x198
>> [ 334.414217] __vfs_write+0x74/0x90
>> [ 334.414218] vfs_write+0xac/0x1b8
>> [ 334.414219] ksys_write+0x74/0xf8
>> [ 334.414221] __arm64_sys_write+0x24/0x30
>> [ 334.414222] el0_svc_handler+0xa4/0x180
>> [ 334.414223] el0_svc+0x8/0xc
>> [ 334.414252] SMP: stopping secondary CPUs
>> [ 334.414253] Kernel Offset: disabled
>> [ 334.414254] CPU features: 0x0002,20002000
>> [ 334.414256] Memory Limit: none
>
>
> _______________________________________________
> Linux-rockchip mailing list
> Linux-rockchip@lists.infradead.org
> http://lists.infradead.org/mailman/listinfo/linux-rockchip
>
_______________________________________________
linux-arm-kernel mailing list
linux-arm-kernel@lists.infradead.org
http://lists.infradead.org/mailman/listinfo/linux-arm-kernel
^ permalink raw reply [flat|nested] 14+ messages in thread
* Re: aarch64 Kernel Panic Asynchronous SError Interrupt on large file IO
[not found] ` <CA+Vb7hpi=pCC9viiof8y85Kw_vCawWQ0B6kGFALgxtZfCKoaTw@mail.gmail.com>
@ 2019-08-15 16:00 ` Philipp Richter
2019-08-16 12:01 ` Robin Murphy
0 siblings, 1 reply; 14+ messages in thread
From: Philipp Richter @ 2019-08-15 16:00 UTC (permalink / raw)
To: Robin Murphy
Cc: heiko, catalin.marinas, vicencb, linux-rockchip, andre.przywara,
Will Deacon, linux-arm-kernel
Reading from the raw eMMC block /dev/mmcblkp1 I can also produce a panic :
sudo dd if=/dev/mmcblk1 of=/dev/null bs=1M status=progress
2846883840 bytes (2.8 GB, 2.7 GiB) copied, 23 s, 124 MB/s
============
[ 428.794747] dwmmc_rockchip ff520000.dwmmc: Unexpected command
timeout, state 3
[ 428.984736] dwmmc_rockchip ff520000.dwmmc: Unexpected command
timeout, state 3
[ 429.174738] dwmmc_rockchip ff520000.dwmmc: Unexpected command
timeout, state 3
[ 429.179323] Internal error: synchronous external abort: 96000210
[#1] SMP
[ 429.179934] Modules linked in: wireguard(O) ip6_udp_tunnel
udp_tunnel lz4 lz4_compress iptable_filter iptable_raw xt_owner
iptable_nat xt_connmark iptable_mangle bpfilter rc_cec
snd_soc_hdmi_codec dw_hdmi_i2s_audio dw_hdmi_cec
snd_soc_audio_graph_cc
[ 429.186527] CPU: 0 PID: 1079 Comm: bash Tainted: G O
5.2.8-1-ARCH #1
[ 429.187193] Hardware name: Pine64 Rock64 (DT)
[ 429.187576] pstate: 20000005 (nzCv daif -PAN -UAO)
[ 429.188007] pc : copy_page_range+0x124/0x3d0
[ 429.188386] lr : dup_mm+0x3fc/0x478
[ 429.188692] sp : ffff00001277bb80
[ 429.188982] x29: ffff00001277bb80 x28: ffff8000dd17e450
[ 429.189446] x27: ffff8000dd17e470 x26: ffff8000dd17e460
[ 429.189912] x25: 0000aaaac4a01000 x24: ffff8000dca92a00
[ 429.190376] x23: ffff8000dd1fdf80 x22: ffff8000dd30c8a0
[ 429.190840] x21: ffff8000dca92a00 x20: ffff8000dd30c8a0
[ 429.191306] x19: ffff8000dd1fdf80 x18: 0000000000000000
[ 429.191771] x17: 0000000000000000 x16: 0000000000000000
[ 429.192236] x15: 0000000000000000 x14: ffff8000dd2b86d0
[ 429.192700] x13: 00000000000000f8 x12: 0000000000000000
[ 429.193165] x11: 0000000000000000 x10: ffff8000e44bde01
[ 429.193630] x9 : 0000000000100871 x8 : 0000000000000000
[ 429.194095] x7 : ffff8000e4481760 x6 : 0000000000000000
[ 429.194560] x5 : 0000aaaac49fc000 x4 : ffff0000102905c0
[ 429.195026] x3 : 0000000000000000 x2 : ffff800009c74aa8
[ 429.195491] x1 : 0000aaaac4a00fff x0 : ffff800009c74aa8
[ 429.195959] Call trace:
[ 429.196178] copy_page_range+0x124/0x3d0
[ 429.196521] dup_mm+0x3fc/0x478
[ 429.196801] copy_process.isra.4.part.5+0x143c/0x1450
[ 429.197244] _do_fork+0xec/0x410
[ 429.197529] __arm64_sys_clone+0x2c/0x38
[ 429.197877] el0_svc_handler+0xa4/0x180
[ 429.198215] el0_svc+0x8/0xc
[ 429.198474] Code: 360812e0 f9403fe0 b4000ac0 f9403fe0 (f9400000)
[ 429.199008] ---[ end trace 04beba7bac629e3f ]---
[ 429.200049] SError Interrupt on CPU1, code 0xbf000002 -- SError
[ 429.200052] CPU: 1 PID: 669 Comm: systemd-journal Tainted: G D
O 5.2.8-1-ARCH #1
[ 429.200054] Hardware name: Pine64 Rock64 (DT)
[ 429.200055] pstate: 20000005 (nzCv daif -PAN -UAO)
[ 429.200056] pc : allocate_slab+0x1d0/0x570
[ 429.200058] lr : allocate_slab+0x1e0/0x570
[ 429.200059] sp : ffff000011d8baa0
[ 429.200060] x29: ffff000011d8baa0 x28: 0000000000000003
[ 429.200063] x27: ffff7e0000276800 x26: ffff800009da6e00
[ 429.200068] x25: 0000000000000009 x24: 0000000000007bc0
[ 429.200071] x23: 0000000000000003 x22: 0000000000000003
[ 429.200075] x21: ffff800009da0000 x20: 0000000000005280
[ 429.200079] x19: ffff8000b3fa3980 x18: 0000000000000000
[ 429.200082] x17: 0000000000000000 x16: 0000000000000000
[ 429.200086] x15: 0000000000000000 x14: 0000000000000000
[ 429.200090] x13: 0000000000000000 x12: 0000000000000000
[ 429.200094] x11: 0000000000000000 x10: 0000000000000000
[ 429.200098] x9 : 0000000000000000 x8 : 0000000000000000
[ 429.200102] x7 : 00000000fee00000 x6 : 0000000000000018
[ 429.200106] x5 : 0000000000000040 x4 : 0000000000210d00
[ 429.200110] x3 : 0000000000000dc0 x2 : 0000000005a79795
[ 429.200112] x1 : 0000000000000000 x0 : ffff8000f2f35a80
[ 429.200117] Kernel panic - not syncing: Asynchronous SError
Interrupt
[ 429.200137] SMP: stopping secondary CPUs
[ 429.200139] Kernel Offset: disabled
[ 429.200140] CPU features: 0x0002,20002000
[ 429.200141] Memory Limit: none
============
Regards,
Philipp Richter
On Thu, 15 Aug 2019 at 17:35, Philipp Richter
<richterphilipp.pops@gmail.com> wrote:
>
> Yes, it's connected over the USB 3.0 port. I'll also try over USB 2.0
> as soon as possible.
>
> I first noticed the issue when my backup script froze the board, so
> this is while reading from the eMMC.
>
> My script that I invoke over ssh :
> ============
> #!/usr/bin/env bash
> IFS=$'\n\t'
> set -euo pipefail
>
> schedtool -B -n 8 "${BASHPID}"
> ionice -c 3 -p "${BASHPID}"
>
> EXCLUSION_FILE='/etc/tar-system-exclusion.txt'
> TOTAL_SIZE="$(sudo du --bytes --summarize
> --exclude-from="${EXCLUSION_FILE}" / | awk '{print $1}')"
> sudo tar --create --file - --numeric-owner --acls --xattrs
> --exclude-from="${EXCLUSION_FILE}" / | \
> pv --progress --timer --eta --fineta --rate --average-rate
> --bytes --force --size "${TOTAL_SIZE}" | \
> lz4 -z
> ============
>
> So it fails also around 2.8GB pushed and I get this panic on my serial
> console in "__memcpy" this time though :
>
> ============
> [12624.268933] SError Interrupt on CPU0, code 0xbf000002 -- SError
> [12624.268940] CPU: 0 PID: 14170 Comm: kworker/u8:4 Tainted: G
> O 5.2.8-1-ARCH #1
> [12624.268942] Hardware name: Pine64 Rock64 (DT)
> [12624.268944] Workqueue: btrfs-endio btrfs_endio_helper [btrfs]
> [12624.268946] pstate: 20000005 (nzCv daif -PAN -UAO)
> [12624.268948] pc : __memcpy+0x118/0x180
> [12624.268950] lr : btrfs_decompress_buf2page+0x124/0x228 [btrfs]
> [12624.268951] sp : ffff00001c28bb40
> [12624.268952] x29: ffff00001c28bb40 x28: ffff8000f2a2b870
> [12624.268955] x27: 0000000000001000 x26: ffff7e0000270200
> [12624.268958] x25: 0000000000001000 x24: 000000000001f000
> [12624.268961] x23: 0000000000000000 x22: 000000000001f000
> [12624.268964] x21: ffff8000fde46040 x20: 0000000000140000
> [12624.268967] x19: 0000000000001000 x18: ffff8000e830aef5
> [12624.268970] x17: 0000000000000ad3 x16: 0000000000000003
> [12624.268973] x15: 0000000000000002 x14: a8c37bfd9101e042
> [12624.268976] x13: a9425bf552800021 x12: a94153f3f0000b62
> [12624.268979] x11: f9400a80900011a4 x10: aa1603e3d63f0260
> [12624.268982] x9 : 9101c04252800021 x8 : 910003fda9b97bfd
> [12624.268985] x7 : d61f0080f9475c84 x6 : ffff800009c08390
> [12624.268988] x5 : ffff800065005050 x4 : 0000000000000000
> [12624.268990] x3 : 0000000000140000 x2 : 0000000000000c00
> [12624.268993] x1 : ffff8000dac023d0 x0 : ffff800009c08000
> [12624.268997] Kernel panic - not syncing: Asynchronous SError Interrupt
> [12624.269000] CPU: 0 PID: 14170 Comm: kworker/u8:4 Tainted: G
> O 5.2.8-1-ARCH #1
> [12624.269001] Hardware name: Pine64 Rock64 (DT)
> [12624.269003] Workqueue: btrfs-endio btrfs_endio_helper [btrfs]
> [12624.269004] Call trace:
> [12624.269006] dump_backtrace+0x0/0x168
> [12624.269007] show_stack+0x24/0x30
> [12624.269009] dump_stack+0xa8/0xcc
> [12624.269010] panic+0x150/0x320
> [12624.269011] __stack_chk_fail+0x0/0x28
> [12624.269013] arm64_serror_panic+0x80/0x8c
> [12624.269014] do_serror+0x11c/0x120
> [12624.269016] el1_error+0x84/0xf8
> [12624.269017] __memcpy+0x118/0x180
> [12624.269018] zstd_decompress_bio+0xf8/0x250 [btrfs]
> [12624.269020] end_compressed_bio_read+0x2ec/0x3f8 [btrfs]
> [12624.269021] bio_endio.part.12+0x10c/0x1a8
> [12624.269023] bio_endio+0x20/0x30
> [12624.269024] end_workqueue_fn+0x4c/0x58 [btrfs]
> [12624.269025] normal_work_helper+0x100/0x250 [btrfs]
> [12624.269027] btrfs_endio_helper+0x20/0x30 [btrfs]
> [12624.269029] process_one_work+0x1b4/0x408
> [12624.269030] worker_thread+0x54/0x4b8
> [12624.269031] kthread+0x12c/0x130
> [12624.269033] ret_from_fork+0x10/0x1c
> [12624.269068] SMP: stopping secondary CPUs
> [12624.269069] Kernel Offset: disabled
> [12624.269071] CPU features: 0x0002,20002000
> [12624.269072] Memory Limit: none
> ============
>
> Regards,
> Philipp Richter
_______________________________________________
linux-arm-kernel mailing list
linux-arm-kernel@lists.infradead.org
http://lists.infradead.org/mailman/listinfo/linux-arm-kernel
^ permalink raw reply [flat|nested] 14+ messages in thread
* Re: aarch64 Kernel Panic Asynchronous SError Interrupt on large file IO
2019-08-15 16:00 ` Philipp Richter
@ 2019-08-16 12:01 ` Robin Murphy
2019-08-16 18:54 ` Philipp Richter
0 siblings, 1 reply; 14+ messages in thread
From: Robin Murphy @ 2019-08-16 12:01 UTC (permalink / raw)
To: Philipp Richter
Cc: heiko, catalin.marinas, vicencb, linux-rockchip, andre.przywara,
Will Deacon, linux-arm-kernel
On 15/08/2019 17:00, Philipp Richter wrote:
> Reading from the raw eMMC block /dev/mmcblkp1 I can also produce a panic :
>
> sudo dd if=/dev/mmcblk1 of=/dev/null bs=1M status=progress
> 2846883840 bytes (2.8 GB, 2.7 GiB) copied, 23 s, 124 MB/s
Hmm, I'm running Arch with the same stock kernel on my RK3328 box, and
that doesn't seem to have an problem:
-----
[root@nemulon-9 ~]# dd if=/dev/mmcblk1 of=/dev/null bs=1M status=progress
15408824320 bytes (15 GB, 14 GiB) copied, 125 s, 123 MB/s
14800+0 records in
14800+0 records out
15518924800 bytes (16 GB, 14 GiB) copied, 125.868 s, 123 MB/s
[root@nemulon-9 ~]# dd if=/dev/mmcblk1 of=/dev/null bs=1M status=progress
15437135872 bytes (15 GB, 14 GiB) copied, 125 s, 123 MB/s
14800+0 records in
14800+0 records out
15518924800 bytes (16 GB, 14 GiB) copied, 125.655 s, 124 MB/s
[root@nemulon-9 ~]# dd if=/dev/mmcblk1 of=/dev/null bs=1M status=progress
15446573056 bytes (15 GB, 14 GiB) copied, 125 s, 124 MB/s
14800+0 records in
14800+0 records out
15518924800 bytes (16 GB, 14 GiB) copied, 125.576 s, 124 MB/s
[root@nemulon-9 ~]# dd if=/dev/mmcblk1 of=/dev/null bs=1M status=progress
15411970048 bytes (15 GB, 14 GiB) copied, 125 s, 123 MB/s
14800+0 records in
14800+0 records out
15518924800 bytes (16 GB, 14 GiB) copied, 125.844 s, 123 MB/s
[root@nemulon-9 ~]#
-----
and FWIW this box is running a far more antique Rock64 firmware:
-----
DDR version 1.06 20170424
In
LPDDR3
786MHz
Bus Width=32 Col=11 Bank=8 Row=15/15 CS=2 Die Bus-Width=32 Size=4096MB
ddrconfig:7
OUT
Boot1 Release Time: 2017-05-18, version: 2.43
ChipType = 0x11, 127
WR_REL_SET is 0 4
SdmmcInit=2 0
BootCapSize=2000
UserCapSize=14800MB
FwPartOffset=2000 , 2000
SdmmcInit=0 2
StorageInit ok = 23274
Raw SecureMode = 0
SecureInit read PBA: 0x4
SecureInit read PBA: 0x404
SecureInit read PBA: 0x804
SecureInit read PBA: 0xc04
SecureInit read PBA: 0x1004
SecureInit ret = 0, SecureMode = 0
LoadTrustBL
No find bl30.bin
No find bl32.bin
Load uboot, ReadLba = 2000
Load OK, addr=0x200000, size=0x9268c
RunBL31 0x10000
\x01NOTICE: BL31: v1.3(debug):f947c7e
NOTICE: BL31: Built : 09:28:45, May 31 2017
NOTICE: BL31:Rockchip release version: v1.3
INFO: ARM GICv2 driver initialized
INFO: Using opteed sec cpu_context!
INFO: boot cpu mask: 1
INFO: plat_rockchip_pmu_init: pd status 0xe
INFO: BL31: Initializing runtime services
WARNING: No OPTEE provided by BL2 boot loader, Booting device without
OPTEE initialization. SMC`s destined for OPTEE will return SMC_UNK
ERROR: Error initializing runtime service opteed_fast
INFO: BL31: Preparing for EL3 exit to normal world
INFO: Entry point address = 0x200000
INFO: SPSR = 0x3c9
U-Boot 2017.09-rc4-g22993de (Sep 14 2017 - 21:57:17 +0000), Build:
jenkins-linux-build-rock-64-118
Model: Pine64 Rock64
DRAM: 4 GiB
MMC: rksdmmc@ff500000: 1, rksdmmc@ff520000: 0
Card did not respond to voltage select!
mmc_init: -95, time 9
*** Warning - No block device, using default environment
----
[ of course it's not a Rock64 at all, but I'm lazy, that was the only
prebuilt image available at the time, and the differences aren't major
enough to prevent SD/eMMC booting :) ]
> ============
> [ 428.794747] dwmmc_rockchip ff520000.dwmmc: Unexpected command
> timeout, state 3
> [ 428.984736] dwmmc_rockchip ff520000.dwmmc: Unexpected command
> timeout, state 3
> [ 429.174738] dwmmc_rockchip ff520000.dwmmc: Unexpected command
> timeout, state 3
> [ 429.179323] Internal error: synchronous external abort: 96000210
> [#1] SMP
> [ 429.179934] Modules linked in: wireguard(O) ip6_udp_tunnel
> udp_tunnel lz4 lz4_compress iptable_filter iptable_raw xt_owner
> iptable_nat xt_connmark iptable_mangle bpfilter rc_cec
> snd_soc_hdmi_codec dw_hdmi_i2s_audio dw_hdmi_cec
> snd_soc_audio_graph_cc
> [ 429.186527] CPU: 0 PID: 1079 Comm: bash Tainted: G O
> 5.2.8-1-ARCH #1
> [ 429.187193] Hardware name: Pine64 Rock64 (DT)
> [ 429.187576] pstate: 20000005 (nzCv daif -PAN -UAO)
> [ 429.188007] pc : copy_page_range+0x124/0x3d0
> [ 429.188386] lr : dup_mm+0x3fc/0x478
> [ 429.188692] sp : ffff00001277bb80
> [ 429.188982] x29: ffff00001277bb80 x28: ffff8000dd17e450
> [ 429.189446] x27: ffff8000dd17e470 x26: ffff8000dd17e460
> [ 429.189912] x25: 0000aaaac4a01000 x24: ffff8000dca92a00
> [ 429.190376] x23: ffff8000dd1fdf80 x22: ffff8000dd30c8a0
> [ 429.190840] x21: ffff8000dca92a00 x20: ffff8000dd30c8a0
> [ 429.191306] x19: ffff8000dd1fdf80 x18: 0000000000000000
> [ 429.191771] x17: 0000000000000000 x16: 0000000000000000
> [ 429.192236] x15: 0000000000000000 x14: ffff8000dd2b86d0
> [ 429.192700] x13: 00000000000000f8 x12: 0000000000000000
> [ 429.193165] x11: 0000000000000000 x10: ffff8000e44bde01
> [ 429.193630] x9 : 0000000000100871 x8 : 0000000000000000
> [ 429.194095] x7 : ffff8000e4481760 x6 : 0000000000000000
> [ 429.194560] x5 : 0000aaaac49fc000 x4 : ffff0000102905c0
> [ 429.195026] x3 : 0000000000000000 x2 : ffff800009c74aa8
> [ 429.195491] x1 : 0000aaaac4a00fff x0 : ffff800009c74aa8
> [ 429.195959] Call trace:
> [ 429.196178] copy_page_range+0x124/0x3d0
> [ 429.196521] dup_mm+0x3fc/0x478
> [ 429.196801] copy_process.isra.4.part.5+0x143c/0x1450
> [ 429.197244] _do_fork+0xec/0x410
> [ 429.197529] __arm64_sys_clone+0x2c/0x38
> [ 429.197877] el0_svc_handler+0xa4/0x180
> [ 429.198215] el0_svc+0x8/0xc
> [ 429.198474] Code: 360812e0 f9403fe0 b4000ac0 f9403fe0 (f9400000)
This one's particularly interesting since it's synchronous. That code
dump implies that an "ldr x0, [x0]" is faulting, when x0 holds a linear
map address (i.e. directly correlated to a physical address).
> [ 429.199008] ---[ end trace 04beba7bac629e3f ]---
> [ 429.200049] SError Interrupt on CPU1, code 0xbf000002 -- SError
> [ 429.200052] CPU: 1 PID: 669 Comm: systemd-journal Tainted: G D
> O 5.2.8-1-ARCH #1
> [ 429.200054] Hardware name: Pine64 Rock64 (DT)
> [ 429.200055] pstate: 20000005 (nzCv daif -PAN -UAO)
> [ 429.200056] pc : allocate_slab+0x1d0/0x570
> [ 429.200058] lr : allocate_slab+0x1e0/0x570
> [ 429.200059] sp : ffff000011d8baa0
> [ 429.200060] x29: ffff000011d8baa0 x28: 0000000000000003
> [ 429.200063] x27: ffff7e0000276800 x26: ffff800009da6e00
> [ 429.200068] x25: 0000000000000009 x24: 0000000000007bc0
> [ 429.200071] x23: 0000000000000003 x22: 0000000000000003
> [ 429.200075] x21: ffff800009da0000 x20: 0000000000005280
> [ 429.200079] x19: ffff8000b3fa3980 x18: 0000000000000000
> [ 429.200082] x17: 0000000000000000 x16: 0000000000000000
> [ 429.200086] x15: 0000000000000000 x14: 0000000000000000
> [ 429.200090] x13: 0000000000000000 x12: 0000000000000000
> [ 429.200094] x11: 0000000000000000 x10: 0000000000000000
> [ 429.200098] x9 : 0000000000000000 x8 : 0000000000000000
> [ 429.200102] x7 : 00000000fee00000 x6 : 0000000000000018
> [ 429.200106] x5 : 0000000000000040 x4 : 0000000000210d00
> [ 429.200110] x3 : 0000000000000dc0 x2 : 0000000005a79795
> [ 429.200112] x1 : 0000000000000000 x0 : ffff8000f2f35a80
> [ 429.200117] Kernel panic - not syncing: Asynchronous SError
> Interrupt
This is less revealing, but the fact that x21 and x26 are holding
pointers to a relatively similar area of RAM does raise an eyebrow.
[...]
>> [12624.268933] SError Interrupt on CPU0, code 0xbf000002 -- SError
>> [12624.268940] CPU: 0 PID: 14170 Comm: kworker/u8:4 Tainted: G
>> O 5.2.8-1-ARCH #1
>> [12624.268942] Hardware name: Pine64 Rock64 (DT)
>> [12624.268944] Workqueue: btrfs-endio btrfs_endio_helper [btrfs]
>> [12624.268946] pstate: 20000005 (nzCv daif -PAN -UAO)
>> [12624.268948] pc : __memcpy+0x118/0x180
>> [12624.268950] lr : btrfs_decompress_buf2page+0x124/0x228 [btrfs]
>> [12624.268951] sp : ffff00001c28bb40
>> [12624.268952] x29: ffff00001c28bb40 x28: ffff8000f2a2b870
>> [12624.268955] x27: 0000000000001000 x26: ffff7e0000270200
>> [12624.268958] x25: 0000000000001000 x24: 000000000001f000
>> [12624.268961] x23: 0000000000000000 x22: 000000000001f000
>> [12624.268964] x21: ffff8000fde46040 x20: 0000000000140000
>> [12624.268967] x19: 0000000000001000 x18: ffff8000e830aef5
>> [12624.268970] x17: 0000000000000ad3 x16: 0000000000000003
>> [12624.268973] x15: 0000000000000002 x14: a8c37bfd9101e042
>> [12624.268976] x13: a9425bf552800021 x12: a94153f3f0000b62
>> [12624.268979] x11: f9400a80900011a4 x10: aa1603e3d63f0260
>> [12624.268982] x9 : 9101c04252800021 x8 : 910003fda9b97bfd
>> [12624.268985] x7 : d61f0080f9475c84 x6 : ffff800009c08390
>> [12624.268988] x5 : ffff800065005050 x4 : 0000000000000000
>> [12624.268990] x3 : 0000000000140000 x2 : 0000000000000c00
>> [12624.268993] x1 : ffff8000dac023d0 x0 : ffff800009c08000
>> [12624.268997] Kernel panic - not syncing: Asynchronous SError Interrupt
In this case, I know that x6 is the destination pointer for the memcpy
routine, and the memcpy from the first log also looks similar:
> [ 334.414179] x7 : 911b47420a1c00a2 x6 : ffff800009c01150
Again, all within a few MB of that same region. Given that we're a few
hundred bytes into the copy both times, this could well represent the
point where the first dirtied cachelines start to get written back,
provoking the bus error from the memory controller and thus an async SError.
This does start to smell like some issue with that particular area of
physical memory - either because it's been marked as Secure-only by
firmware and the controller configured to abort Non-Secure accesses, or
possibly because of an actual DRAM failure. The next thing I'd do is
have a play around with the "memtest=..." kernel parameter to see if
that can consistently find a problem, and see if the firmware change
that Heiko pointed out makes any difference.
Robin.
_______________________________________________
linux-arm-kernel mailing list
linux-arm-kernel@lists.infradead.org
http://lists.infradead.org/mailman/listinfo/linux-arm-kernel
^ permalink raw reply [flat|nested] 14+ messages in thread
* Re: aarch64 Kernel Panic Asynchronous SError Interrupt on large file IO
2019-08-16 12:01 ` Robin Murphy
@ 2019-08-16 18:54 ` Philipp Richter
2019-08-17 13:12 ` Philipp Richter
0 siblings, 1 reply; 14+ messages in thread
From: Philipp Richter @ 2019-08-16 18:54 UTC (permalink / raw)
To: Robin Murphy
Cc: heiko, catalin.marinas, vicencb, linux-rockchip, andre.przywara,
Will Deacon, linux-arm-kernel
On Fri, 16 Aug 2019 at 14:01, Robin Murphy <robin.murphy@arm.com> wrote:
>
> This does start to smell like some issue with that particular area of
> physical memory - either because it's been marked as Secure-only by
> firmware and the controller configured to abort Non-Secure accesses, or
> possibly because of an actual DRAM failure. The next thing I'd do is
> have a play around with the "memtest=..." kernel parameter to see if
> that can consistently find a problem, and see if the firmware change
> that Heiko pointed out makes any difference.
>
> Robin.
Thank you very much for this insight.
I compiled u-boot with the patch that Heiko Stübner linked to and
rewrote the images to the target locations but this didn't resolve the
problem.
I'll try some memtests but the stock Archlinux ARM kernel does not
have it enabled so I'll need to compile it in myself then I guess.
Regards,
Philipp Richter
_______________________________________________
linux-arm-kernel mailing list
linux-arm-kernel@lists.infradead.org
http://lists.infradead.org/mailman/listinfo/linux-arm-kernel
^ permalink raw reply [flat|nested] 14+ messages in thread
* Re: aarch64 Kernel Panic Asynchronous SError Interrupt on large file IO
2019-08-16 18:54 ` Philipp Richter
@ 2019-08-17 13:12 ` Philipp Richter
2019-08-19 10:07 ` Catalin Marinas
0 siblings, 1 reply; 14+ messages in thread
From: Philipp Richter @ 2019-08-17 13:12 UTC (permalink / raw)
To: Robin Murphy
Cc: heiko, catalin.marinas, vicencb, linux-rockchip, andre.przywara,
Will Deacon, linux-arm-kernel
Compiling the kernel also triggered the panic so that was hard.
I added "memtest=4" to the kernel cmdline and I'm getting very quicky
a "Internal error: synchronous external abort" panic.
============
INFO: PSCI Power Domain Map:
INFO: Domain Node : Level 2, parent_node -1, State ON (0x0)
INFO: Domain Node : Level 1, parent_node 0, State ON (0x0)
INFO: Domain Node : Level 0, parent_node 0, State ON (0x0)
INFO: Domain Node : Level 0, parent_node 0, State ON (0x0)
INFO: CPU Node : MPID 0x0, parent_node 1, State ON (0x0)
INFO: CPU Node : MPID 0x1, parent_node 1, State ON (0x0)
INFO: CPU Node : MPID 0x2, parent_node 1, State ON (0x0)
INFO: CPU Node : MPID 0x3, parent_node 1, State ON (0x0)
DDR version 1.16 20190528
ID:0x805 N
In
SRX
LPDDR3
333MHz
Bus Width=32 Col=11 Bank=8 Row=15/15 CS=2 Die Bus-Width=32 Size=4096MB
ddrconfig:7
OUT
Boot1 Release Time: May 13 2019 17:34:36, version: 2.50
ChipType = 0x11, 316
mmc2:cmd19,100
SdmmcInit=2 0
BootCapSize=2000
UserCapSize=29820MB
FwPartOffset=2000 , 2000
SdmmcInit=0 NOT PRESENT
StorageInit ok = 198645
Raw SecureMode = 0
SecureInit read PBA: 0x4
SecureInit read PBA: 0x404
SecureInit read PBA: 0x804
SecureInit read PBA: 0xc04
SecureInit read PBA: 0x1004
SecureInit ret = 0, SecureMode = 0
atags_set_bootdev: ret:(0)
GPT 0x337a9f0 signature is wrong
recovery gpt...
GPT 0x337a9f0 signature is wrong
recovery gpt fail!
LoadTrust Addr:0x4000
No find bl30.bin
Load uboot, ReadLba = 2000
Load OK, addr=0x200000, size=0x9a864
RunBL31 0x10000
NOTICE: BL31: v1.3(debug):0eba775
NOTICE: BL31: Built : 12:11:32, Nov 23 2018
NOTICE: BL31:Rockchip release version: v1.3
INFO: ARM GICv2 driver initialized
INFO: Using opteed sec cpu_context!
INFO: boot cpu mask: 1
INFO: plat_rockchip_pmu_init: pd status 0xe
INFO: BL31: Initializing runtime services
INFO: BL31: Initializing BL32
INF [0x0] TEE-CORE:init_primary_helper:337: Initializing
(1.1.0-221-gda2bcfdc #137 Mon Jun 17 03:00:04 UTC 2019 aarch64)
INF [0x0] TEE-CORE:init_primary_helper:338: Release version: 1.4
INF [0x0] TEE-CORE:init_teecore:83: teecore inits done
INFO: BL31: Preparing for EL3 exit to normal world
INFO: Entry point address = 0x200000
INFO: SPSR = 0x3c9
U-Boot 2019.07-2 (Aug 16 2019 - 18:37:30 +0000) Arch Linux ARM
Model: Rockchip RK3328 EVB
DRAM: 4 GiB
MMC: rksdmmc@ff500000: 1, rksdmmc@ff520000: 0
Loading Environment from MMC... Card did not respond to voltage select!
*** Warning - No block device, using default environment
In: serial@ff130000
Out: serial@ff130000
Err: serial@ff130000
Model: Rockchip RK3328 EVB
Net:
Warning: ethernet@ff540000 (eth0) using random MAC address - 4a:92:84:ee:d8:3b
eth0: ethernet@ff540000
Hit any key to stop autoboot: 2 1 0
switch to partitions #0, OK
mmc0(part 0) is current device
Scanning mmc 0:1...
Found U-Boot script /boot.scr
1105 bytes read in 5 ms (215.8 KiB/s)
## Executing script at 00500000
26501632 bytes read in 628 ms (40.2 MiB/s)
49338 bytes read in 12 ms (3.9 MiB/s)
10033777 bytes read in 242 ms (39.5 MiB/s)
## Flattened Device Tree blob at 01f00000
Booting using the fdt blob at 0x1f00000
Loading Ramdisk to fc59b000, end fcf2ca71 ... OK
Loading Device Tree to 00000000fc58b000, end 00000000fc59afff ... OK
Starting kernel ...
[ 0.000000] Booting Linux on physical CPU 0x0000000000 [0x410fd034]
[ 0.000000] Linux version 5.2.8-1-ARCH (alarm@rock64) (gcc version
8.3.0 (GCC)) #1 SMP Sat Aug 17 10:28:16 CEST 2019
[ 0.000000] Machine model: Pine64 Rock64
[ 0.000000] earlycon: uart8250 at MMIO32 0x00000000ff130000 (options '')
[ 0.000000] printk: bootconsole [uart8250] enabled
[ 0.000000] efi: Getting EFI parameters from FDT:
[ 0.000000] efi: UEFI not found.
[ 0.000000] cma: Reserved 64 MiB at 0x00000000f8400000
[ 0.000000] early_memtest: # of tests: 4
[ 0.000000] 0x0000000000200000 - 0x0000000002080000 pattern
aaaaaaaaaaaaaaaa
[ 0.000000] 0x0000000003a95000 - 0x00000000f8400000 pattern
aaaaaaaaaaaaaaaa
[ 0.000000] Internal error: synchronous external abort: 96000210 [#1] SMP
[ 0.000000] Modules linked in:
[ 0.000000] CPU: 0 PID: 0 Comm: swapper Not tainted 5.2.8-1-ARCH #1
[ 0.000000] Hardware name: Pine64 Rock64 (DT)
[ 0.000000] pstate: 20000085 (nzCv daIf -PAN -UAO)
[ 0.000000] pc : early_memtest+0x16c/0x23c
[ 0.000000] lr : early_memtest+0x11c/0x23c
[ 0.000000] sp : ffff000011733df0
[ 0.000000] x29: ffff000011733df0 x28: ffff0000114a6000
[ 0.000000] x27: ffff00001178b000 x26: aaaaaaaaaaaaaaaa
[ 0.000000] x25: ffff00001178b000 x24: aaaaaaaaaaaaaaaa
[ 0.000000] x23: 00000000ff000000 x22: 0000000000200000
[ 0.000000] x21: ffff0000117396c8 x20: 0000000000000003
[ 0.000000] x19: ffff00001164bcc8 x18: 0000000000000010
[ 0.000000] x17: 000000000000d080 x16: ffff7dfffe99807c
[ 0.000000] x15: ffffffffffffffff x14: 6161616161616161
[ 0.000000] x13: 616161616161206e x12: 7265747461702030
[ 0.000000] x11: 3030303034386630 x10: 3030303030303078
[ 0.000000] x9 : 30202d2030303035 x8 : ffff000010868858
[ 0.000000] x7 : 000000000000000b x6 : ffff0000119d1539
[ 0.000000] x5 : ffff8000f8400000 x4 : ffff800008400000
[ 0.000000] x3 : 0000000008400000 x2 : 0000000000000000
[ 0.000000] x1 : 0000000000000000 x0 : aaaaaaaaaaaaaaaa
[ 0.000000] Call trace:
[ 0.000000] early_memtest+0x16c/0x23c
[ 0.000000] bootmem_init+0x48/0x174
[ 0.000000] setup_arch+0x1f0/0x558
[ 0.000000] start_kernel+0x8c/0x494
[ 0.000000] Code: d2800002 d2800001 eb0400bf 54000309 (f9400080)
[ 0.000000] random: get_random_bytes called from
print_oops_end_marker+0x30/0x58 with crng_init=0
[ 0.000000] ---[ end trace 0000000000000000 ]---
[ 0.000000] Kernel panic - not syncing: Attempted to kill the idle task!
[ 0.000000] ---[ end Kernel panic - not syncing: Attempted to kill
the idle task! ]---
============
Is my board completely broken ? :(
Regards,
Philipp Richter
_______________________________________________
linux-arm-kernel mailing list
linux-arm-kernel@lists.infradead.org
http://lists.infradead.org/mailman/listinfo/linux-arm-kernel
^ permalink raw reply [flat|nested] 14+ messages in thread
* Re: aarch64 Kernel Panic Asynchronous SError Interrupt on large file IO
2019-08-17 13:12 ` Philipp Richter
@ 2019-08-19 10:07 ` Catalin Marinas
2019-08-19 10:43 ` Will Deacon
0 siblings, 1 reply; 14+ messages in thread
From: Catalin Marinas @ 2019-08-19 10:07 UTC (permalink / raw)
To: Philipp Richter
Cc: heiko, andre.przywara, Robin Murphy, vicencb, linux-rockchip,
Will Deacon, linux-arm-kernel
On Sat, Aug 17, 2019 at 03:12:41PM +0200, Philipp Richter wrote:
> I added "memtest=4" to the kernel cmdline and I'm getting very quicky
> a "Internal error: synchronous external abort" panic.
[...]
> [ 0.000000] early_memtest: # of tests: 4
> [ 0.000000] 0x0000000000200000 - 0x0000000002080000 pattern aaaaaaaaaaaaaaaa
> [ 0.000000] 0x0000000003a95000 - 0x00000000f8400000 pattern aaaaaaaaaaaaaaaa
> [ 0.000000] Internal error: synchronous external abort: 96000210 [#1] SMP
At least it's a synchronous error ;).
> [ 0.000000] pc : early_memtest+0x16c/0x23c
[...]
> [ 0.000000] Code: d2800002 d2800001 eb0400bf 54000309 (f9400080)
decodecode says:
0: d2800002 mov x2, #0x0 // #0
4: d2800001 mov x1, #0x0 // #0
8: eb0400bf cmp x5, x4
c: 54000309 b.ls 0x6c // b.plast
10:* f9400080 ldr x0, [x4] <-- trapping instruction
I guess that's the read of *p in memtest(). Writing *p probably
generates asynchronous errors it you haven't seen it yet.
> Is my board completely broken ? :(
One possibility is that you don't have any memory where you think there
is, so the mapping just doesn't translate to any valid physical
location.
Can you add some printk(addr) in do_sea() to see if it always faults on
the same address?
Another hack to hopefully track this down is to try to cope with such
synchronous aborts and hopefully you won't hit an asynchronous one
(SError). Quick hack below, only tested under kvm/qemu for booting and
passing memtest:
-----------8<-------------------------
diff --git a/arch/arm64/mm/fault.c b/arch/arm64/mm/fault.c
index 2e6f42dc5a15..47efeedeccba 100644
--- a/arch/arm64/mm/fault.c
+++ b/arch/arm64/mm/fault.c
@@ -606,6 +606,9 @@ static int do_sea(unsigned long addr, unsigned int esr, struct pt_regs *regs)
const struct fault_info *inf;
void __user *siaddr;
+ if (!user_mode(regs) && fixup_exception(regs))
+ return 0;
+
inf = esr_to_fault_info(esr);
/*
diff --git a/mm/memtest.c b/mm/memtest.c
index f53ace709ccd..e878aa6bd1aa 100644
--- a/mm/memtest.c
+++ b/mm/memtest.c
@@ -3,6 +3,7 @@
#include <linux/types.h>
#include <linux/init.h>
#include <linux/memblock.h>
+#include <linux/uaccess.h>
static u64 patterns[] __initdata = {
/* The first entry has to be 0 to leave memtest with zeroed memory */
@@ -38,6 +39,7 @@ static void __init memtest(u64 pattern, phys_addr_t start_phys, phys_addr_t size
phys_addr_t start_bad, last_bad;
phys_addr_t start_phys_aligned;
const size_t incr = sizeof(pattern);
+ mm_segment_t old_fs;
start_phys_aligned = ALIGN(start_phys, incr);
start = __va(start_phys_aligned);
@@ -45,12 +47,20 @@ static void __init memtest(u64 pattern, phys_addr_t start_phys, phys_addr_t size
start_bad = 0;
last_bad = 0;
- for (p = start; p < end; p++)
- *p = pattern;
+ old_fs = get_fs();
+ set_fs(KERNEL_DS);
+ for (p = start; p < end; p++) {
+ u64 val;
+ if (!get_user(val, p))
+ *p = pattern;
+ }
for (p = start; p < end; p++, start_phys_aligned += incr) {
- if (*p == pattern)
- continue;
+ u64 val;
+ if (!get_user(val, p)) {
+ if (val == pattern)
+ continue;
+ }
if (start_phys_aligned == last_bad + incr) {
last_bad += incr;
continue;
@@ -61,6 +71,7 @@ static void __init memtest(u64 pattern, phys_addr_t start_phys, phys_addr_t size
}
if (start_bad)
reserve_bad_mem(pattern, start_bad, last_bad + incr);
+ set_fs(old_fs);
}
static void __init do_one_pass(u64 pattern, phys_addr_t start, phys_addr_t end)
_______________________________________________
linux-arm-kernel mailing list
linux-arm-kernel@lists.infradead.org
http://lists.infradead.org/mailman/listinfo/linux-arm-kernel
^ permalink raw reply related [flat|nested] 14+ messages in thread
* Re: aarch64 Kernel Panic Asynchronous SError Interrupt on large file IO
2019-08-19 10:07 ` Catalin Marinas
@ 2019-08-19 10:43 ` Will Deacon
2019-10-05 23:45 ` Robin Murphy
0 siblings, 1 reply; 14+ messages in thread
From: Will Deacon @ 2019-08-19 10:43 UTC (permalink / raw)
To: Catalin Marinas
Cc: heiko, andre.przywara, vicencb, linux-rockchip, Philipp Richter,
Robin Murphy, linux-arm-kernel
On Mon, Aug 19, 2019 at 11:07:14AM +0100, Catalin Marinas wrote:
> On Sat, Aug 17, 2019 at 03:12:41PM +0200, Philipp Richter wrote:
> > I added "memtest=4" to the kernel cmdline and I'm getting very quicky
> > a "Internal error: synchronous external abort" panic.
> [...]
> > [ 0.000000] early_memtest: # of tests: 4
> > [ 0.000000] 0x0000000000200000 - 0x0000000002080000 pattern aaaaaaaaaaaaaaaa
> > [ 0.000000] 0x0000000003a95000 - 0x00000000f8400000 pattern aaaaaaaaaaaaaaaa
> > [ 0.000000] Internal error: synchronous external abort: 96000210 [#1] SMP
>
> At least it's a synchronous error ;).
>
> > [ 0.000000] pc : early_memtest+0x16c/0x23c
> [...]
> > [ 0.000000] Code: d2800002 d2800001 eb0400bf 54000309 (f9400080)
>
> decodecode says:
>
> 0: d2800002 mov x2, #0x0 // #0
> 4: d2800001 mov x1, #0x0 // #0
> 8: eb0400bf cmp x5, x4
> c: 54000309 b.ls 0x6c // b.plast
> 10:* f9400080 ldr x0, [x4] <-- trapping instruction
>
> I guess that's the read of *p in memtest(). Writing *p probably
> generates asynchronous errors it you haven't seen it yet.
>
> > Is my board completely broken ? :(
>
> One possibility is that you don't have any memory where you think there
> is, so the mapping just doesn't translate to any valid physical
> location.
>
> Can you add some printk(addr) in do_sea() to see if it always faults on
> the same address?
Alternatively, just run it a few more times and see if the register dump
changes. Currently we've got:
[ 0.000000] x5 : ffff8000f8400000 x4 : ffff800008400000
[ 0.000000] x3 : 0000000008400000 x2 : 0000000000000000
[ 0.000000] x1 : 0000000000000000 x0 : aaaaaaaaaaaaaaaa
so I'd guess that x3 is the faulting pa. The faulting (linear) VAs in the
originl report were 0xffff800009c74aa8 and 0xffff800009c08390, which is
still a way way off from this one :/
Looking at the TRM for the rk3328, there's 4gb of ram starting at pa 0x0,
so maybe some of it has been configured as secure or the memory controller
hasn't been properly initialised?
Will
_______________________________________________
linux-arm-kernel mailing list
linux-arm-kernel@lists.infradead.org
http://lists.infradead.org/mailman/listinfo/linux-arm-kernel
^ permalink raw reply [flat|nested] 14+ messages in thread
* Re: aarch64 Kernel Panic Asynchronous SError Interrupt on large file IO
2019-08-19 10:43 ` Will Deacon
@ 2019-10-05 23:45 ` Robin Murphy
2019-10-06 13:13 ` Heiko Stuebner
0 siblings, 1 reply; 14+ messages in thread
From: Robin Murphy @ 2019-10-05 23:45 UTC (permalink / raw)
To: Will Deacon, Catalin Marinas
Cc: heiko, andre.przywara, vicencb, linux-rockchip, Philipp Richter,
linux-arm-kernel
On 2019-08-19 11:43 am, Will Deacon wrote:
> On Mon, Aug 19, 2019 at 11:07:14AM +0100, Catalin Marinas wrote:
>> On Sat, Aug 17, 2019 at 03:12:41PM +0200, Philipp Richter wrote:
>>> I added "memtest=4" to the kernel cmdline and I'm getting very quicky
>>> a "Internal error: synchronous external abort" panic.
>> [...]
>>> [ 0.000000] early_memtest: # of tests: 4
>>> [ 0.000000] 0x0000000000200000 - 0x0000000002080000 pattern aaaaaaaaaaaaaaaa
>>> [ 0.000000] 0x0000000003a95000 - 0x00000000f8400000 pattern aaaaaaaaaaaaaaaa
>>> [ 0.000000] Internal error: synchronous external abort: 96000210 [#1] SMP
>>
>> At least it's a synchronous error ;).
>>
>>> [ 0.000000] pc : early_memtest+0x16c/0x23c
>> [...]
>>> [ 0.000000] Code: d2800002 d2800001 eb0400bf 54000309 (f9400080)
>>
>> decodecode says:
>>
>> 0: d2800002 mov x2, #0x0 // #0
>> 4: d2800001 mov x1, #0x0 // #0
>> 8: eb0400bf cmp x5, x4
>> c: 54000309 b.ls 0x6c // b.plast
>> 10:* f9400080 ldr x0, [x4] <-- trapping instruction
>>
>> I guess that's the read of *p in memtest(). Writing *p probably
>> generates asynchronous errors it you haven't seen it yet.
>>
>>> Is my board completely broken ? :(
>>
>> One possibility is that you don't have any memory where you think there
>> is, so the mapping just doesn't translate to any valid physical
>> location.
>>
>> Can you add some printk(addr) in do_sea() to see if it always faults on
>> the same address?
>
> Alternatively, just run it a few more times and see if the register dump
> changes. Currently we've got:
>
> [ 0.000000] x5 : ffff8000f8400000 x4 : ffff800008400000
> [ 0.000000] x3 : 0000000008400000 x2 : 0000000000000000
> [ 0.000000] x1 : 0000000000000000 x0 : aaaaaaaaaaaaaaaa
>
> so I'd guess that x3 is the faulting pa. The faulting (linear) VAs in the
> originl report were 0xffff800009c74aa8 and 0xffff800009c08390, which is
> still a way way off from this one :/
>
> Looking at the TRM for the rk3328, there's 4gb of ram starting at pa 0x0,
> so maybe some of it has been configured as secure or the memory controller
> hasn't been properly initialised?
FWIW I've noticed my RK3399 board doing this too, now that I've started
using it in anger. I'm using a hacky firmware comprising upstream U-Boot
munged with the Rockchip miniloader and downstream Trusted Firmware
binaries, and it looks like that mismatch is the root of this problem.
Booting a different image based on the BSP U-boot shows that that's
passing a memory node with the range 0x8400000-0x9600000 entirely carved
out, so this is presumably claimed by the secure firmware/TEE and set to
abort Non-Secure accesses.
Robin.
_______________________________________________
linux-arm-kernel mailing list
linux-arm-kernel@lists.infradead.org
http://lists.infradead.org/mailman/listinfo/linux-arm-kernel
^ permalink raw reply [flat|nested] 14+ messages in thread
* Re: aarch64 Kernel Panic Asynchronous SError Interrupt on large file IO
2019-10-05 23:45 ` Robin Murphy
@ 2019-10-06 13:13 ` Heiko Stuebner
2019-10-07 11:51 ` Robin Murphy
0 siblings, 1 reply; 14+ messages in thread
From: Heiko Stuebner @ 2019-10-06 13:13 UTC (permalink / raw)
To: Robin Murphy
Cc: Catalin Marinas, vicencb, linux-rockchip, andre.przywara,
Philipp Richter, Will Deacon, linux-arm-kernel
Am Sonntag, 6. Oktober 2019, 01:45:23 CEST schrieb Robin Murphy:
> On 2019-08-19 11:43 am, Will Deacon wrote:
> > On Mon, Aug 19, 2019 at 11:07:14AM +0100, Catalin Marinas wrote:
> >> On Sat, Aug 17, 2019 at 03:12:41PM +0200, Philipp Richter wrote:
> >>> I added "memtest=4" to the kernel cmdline and I'm getting very quicky
> >>> a "Internal error: synchronous external abort" panic.
> >> [...]
> >>> [ 0.000000] early_memtest: # of tests: 4
> >>> [ 0.000000] 0x0000000000200000 - 0x0000000002080000 pattern aaaaaaaaaaaaaaaa
> >>> [ 0.000000] 0x0000000003a95000 - 0x00000000f8400000 pattern aaaaaaaaaaaaaaaa
> >>> [ 0.000000] Internal error: synchronous external abort: 96000210 [#1] SMP
> >>
> >> At least it's a synchronous error ;).
> >>
> >>> [ 0.000000] pc : early_memtest+0x16c/0x23c
> >> [...]
> >>> [ 0.000000] Code: d2800002 d2800001 eb0400bf 54000309 (f9400080)
> >>
> >> decodecode says:
> >>
> >> 0: d2800002 mov x2, #0x0 // #0
> >> 4: d2800001 mov x1, #0x0 // #0
> >> 8: eb0400bf cmp x5, x4
> >> c: 54000309 b.ls 0x6c // b.plast
> >> 10:* f9400080 ldr x0, [x4] <-- trapping instruction
> >>
> >> I guess that's the read of *p in memtest(). Writing *p probably
> >> generates asynchronous errors it you haven't seen it yet.
> >>
> >>> Is my board completely broken ? :(
> >>
> >> One possibility is that you don't have any memory where you think there
> >> is, so the mapping just doesn't translate to any valid physical
> >> location.
> >>
> >> Can you add some printk(addr) in do_sea() to see if it always faults on
> >> the same address?
> >
> > Alternatively, just run it a few more times and see if the register dump
> > changes. Currently we've got:
> >
> > [ 0.000000] x5 : ffff8000f8400000 x4 : ffff800008400000
> > [ 0.000000] x3 : 0000000008400000 x2 : 0000000000000000
> > [ 0.000000] x1 : 0000000000000000 x0 : aaaaaaaaaaaaaaaa
> >
> > so I'd guess that x3 is the faulting pa. The faulting (linear) VAs in the
> > originl report were 0xffff800009c74aa8 and 0xffff800009c08390, which is
> > still a way way off from this one :/
> >
> > Looking at the TRM for the rk3328, there's 4gb of ram starting at pa 0x0,
> > so maybe some of it has been configured as secure or the memory controller
> > hasn't been properly initialised?
>
> FWIW I've noticed my RK3399 board doing this too, now that I've started
> using it in anger. I'm using a hacky firmware comprising upstream U-Boot
> munged with the Rockchip miniloader and downstream Trusted Firmware
> binaries,
any reason for that combination? For example the rockpro64 got ddr4 support
in upstream uboot recently.
> and it looks like that mismatch is the root of this problem.
> Booting a different image based on the BSP U-boot shows that that's
> passing a memory node with the range 0x8400000-0x9600000 entirely carved
> out, so this is presumably claimed by the secure firmware/TEE and set to
> abort Non-Secure accesses.
As TEE on PX30 is also one of my current projects, I've stumbled over that
memory issue. At least OP-TEE can get passed a location for a dtb during
startup which it then would modify to add a reserved section for its memory.
But that dtb generally is not the one, the kernel will actually use, but
instead only the one used by uboot. extlinux, tftp or whatever will normally
load and use a new dtb for the kernel which will likely not get that memory
reservation automatically?
I'm not yet sure how this is supposed to work in an all-upstream
configuration - I'm running upstream u-boot + upstream TF-A + upstream
OP-Tee in my project environment right now.
Heiko
_______________________________________________
linux-arm-kernel mailing list
linux-arm-kernel@lists.infradead.org
http://lists.infradead.org/mailman/listinfo/linux-arm-kernel
^ permalink raw reply [flat|nested] 14+ messages in thread
* Re: aarch64 Kernel Panic Asynchronous SError Interrupt on large file IO
2019-10-06 13:13 ` Heiko Stuebner
@ 2019-10-07 11:51 ` Robin Murphy
2019-10-07 13:38 ` Heiko Stübner
0 siblings, 1 reply; 14+ messages in thread
From: Robin Murphy @ 2019-10-07 11:51 UTC (permalink / raw)
To: Heiko Stuebner
Cc: Catalin Marinas, vicencb, linux-rockchip, andre.przywara,
Philipp Richter, Will Deacon, linux-arm-kernel
On 06/10/2019 14:13, Heiko Stuebner wrote:
> Am Sonntag, 6. Oktober 2019, 01:45:23 CEST schrieb Robin Murphy:
>> On 2019-08-19 11:43 am, Will Deacon wrote:
>>> On Mon, Aug 19, 2019 at 11:07:14AM +0100, Catalin Marinas wrote:
>>>> On Sat, Aug 17, 2019 at 03:12:41PM +0200, Philipp Richter wrote:
>>>>> I added "memtest=4" to the kernel cmdline and I'm getting very quicky
>>>>> a "Internal error: synchronous external abort" panic.
>>>> [...]
>>>>> [ 0.000000] early_memtest: # of tests: 4
>>>>> [ 0.000000] 0x0000000000200000 - 0x0000000002080000 pattern aaaaaaaaaaaaaaaa
>>>>> [ 0.000000] 0x0000000003a95000 - 0x00000000f8400000 pattern aaaaaaaaaaaaaaaa
>>>>> [ 0.000000] Internal error: synchronous external abort: 96000210 [#1] SMP
>>>>
>>>> At least it's a synchronous error ;).
>>>>
>>>>> [ 0.000000] pc : early_memtest+0x16c/0x23c
>>>> [...]
>>>>> [ 0.000000] Code: d2800002 d2800001 eb0400bf 54000309 (f9400080)
>>>>
>>>> decodecode says:
>>>>
>>>> 0: d2800002 mov x2, #0x0 // #0
>>>> 4: d2800001 mov x1, #0x0 // #0
>>>> 8: eb0400bf cmp x5, x4
>>>> c: 54000309 b.ls 0x6c // b.plast
>>>> 10:* f9400080 ldr x0, [x4] <-- trapping instruction
>>>>
>>>> I guess that's the read of *p in memtest(). Writing *p probably
>>>> generates asynchronous errors it you haven't seen it yet.
>>>>
>>>>> Is my board completely broken ? :(
>>>>
>>>> One possibility is that you don't have any memory where you think there
>>>> is, so the mapping just doesn't translate to any valid physical
>>>> location.
>>>>
>>>> Can you add some printk(addr) in do_sea() to see if it always faults on
>>>> the same address?
>>>
>>> Alternatively, just run it a few more times and see if the register dump
>>> changes. Currently we've got:
>>>
>>> [ 0.000000] x5 : ffff8000f8400000 x4 : ffff800008400000
>>> [ 0.000000] x3 : 0000000008400000 x2 : 0000000000000000
>>> [ 0.000000] x1 : 0000000000000000 x0 : aaaaaaaaaaaaaaaa
>>>
>>> so I'd guess that x3 is the faulting pa. The faulting (linear) VAs in the
>>> originl report were 0xffff800009c74aa8 and 0xffff800009c08390, which is
>>> still a way way off from this one :/
>>>
>>> Looking at the TRM for the rk3328, there's 4gb of ram starting at pa 0x0,
>>> so maybe some of it has been configured as secure or the memory controller
>>> hasn't been properly initialised?
>>
>> FWIW I've noticed my RK3399 board doing this too, now that I've started
>> using it in anger. I'm using a hacky firmware comprising upstream U-Boot
>> munged with the Rockchip miniloader and downstream Trusted Firmware
>> binaries,
>
> any reason for that combination? For example the rockpro64 got ddr4 support
> in upstream uboot recently.
Not really; it's just the "works well enough" setup that made distro
boot usable before the SPL support went upstream, and (other than
hacking in the CPU PLL initialisation which otherwise gets lost in that
combination) I haven't touched it since.
[ for now I've just hacked a reserved-memory node into my DT... one day
I'll get round to firmware tinkering ;) ]
>> and it looks like that mismatch is the root of this problem.
>> Booting a different image based on the BSP U-boot shows that that's
>> passing a memory node with the range 0x8400000-0x9600000 entirely carved
>> out, so this is presumably claimed by the secure firmware/TEE and set to
>> abort Non-Secure accesses.
>
> As TEE on PX30 is also one of my current projects, I've stumbled over that
> memory issue. At least OP-TEE can get passed a location for a dtb during
> startup which it then would modify to add a reserved section for its memory.
>
> But that dtb generally is not the one, the kernel will actually use, but
> instead only the one used by uboot. extlinux, tftp or whatever will normally
> load and use a new dtb for the kernel which will likely not get that memory
> reservation automatically?
>
> I'm not yet sure how this is supposed to work in an all-upstream
> configuration - I'm running upstream u-boot + upstream TF-A + upstream
> OP-Tee in my project environment right now.
As far as I understand, U-Boot is still responsible for generating the
memory node in whatever DTB it loads and passes to the kernel, so it
should still be able to adjust that accordingly. Presumably U-Boot needs
to discover any firmware/TEE reservations early on to avoid touching any
Secure memory itself, so it should just need to keep track of them until
finalising the kernel DTB.
Robin.
_______________________________________________
linux-arm-kernel mailing list
linux-arm-kernel@lists.infradead.org
http://lists.infradead.org/mailman/listinfo/linux-arm-kernel
^ permalink raw reply [flat|nested] 14+ messages in thread
* Re: aarch64 Kernel Panic Asynchronous SError Interrupt on large file IO
2019-10-07 11:51 ` Robin Murphy
@ 2019-10-07 13:38 ` Heiko Stübner
2019-10-07 14:01 ` André Przywara
0 siblings, 1 reply; 14+ messages in thread
From: Heiko Stübner @ 2019-10-07 13:38 UTC (permalink / raw)
To: Robin Murphy
Cc: Catalin Marinas, vicencb, linux-rockchip, andre.przywara,
Philipp Richter, Will Deacon, linux-arm-kernel
Am Montag, 7. Oktober 2019, 13:51:37 CEST schrieb Robin Murphy:
> On 06/10/2019 14:13, Heiko Stuebner wrote:
> > Am Sonntag, 6. Oktober 2019, 01:45:23 CEST schrieb Robin Murphy:
> >> On 2019-08-19 11:43 am, Will Deacon wrote:
> >>> On Mon, Aug 19, 2019 at 11:07:14AM +0100, Catalin Marinas wrote:
> >>>> On Sat, Aug 17, 2019 at 03:12:41PM +0200, Philipp Richter wrote:
> >>>>> I added "memtest=4" to the kernel cmdline and I'm getting very quicky
> >>>>> a "Internal error: synchronous external abort" panic.
> >>>> [...]
> >>>>> [ 0.000000] early_memtest: # of tests: 4
> >>>>> [ 0.000000] 0x0000000000200000 - 0x0000000002080000 pattern aaaaaaaaaaaaaaaa
> >>>>> [ 0.000000] 0x0000000003a95000 - 0x00000000f8400000 pattern aaaaaaaaaaaaaaaa
> >>>>> [ 0.000000] Internal error: synchronous external abort: 96000210 [#1] SMP
> >>>>
> >>>> At least it's a synchronous error ;).
> >>>>
> >>>>> [ 0.000000] pc : early_memtest+0x16c/0x23c
> >>>> [...]
> >>>>> [ 0.000000] Code: d2800002 d2800001 eb0400bf 54000309 (f9400080)
> >>>>
> >>>> decodecode says:
> >>>>
> >>>> 0: d2800002 mov x2, #0x0 // #0
> >>>> 4: d2800001 mov x1, #0x0 // #0
> >>>> 8: eb0400bf cmp x5, x4
> >>>> c: 54000309 b.ls 0x6c // b.plast
> >>>> 10:* f9400080 ldr x0, [x4] <-- trapping instruction
> >>>>
> >>>> I guess that's the read of *p in memtest(). Writing *p probably
> >>>> generates asynchronous errors it you haven't seen it yet.
> >>>>
> >>>>> Is my board completely broken ? :(
> >>>>
> >>>> One possibility is that you don't have any memory where you think there
> >>>> is, so the mapping just doesn't translate to any valid physical
> >>>> location.
> >>>>
> >>>> Can you add some printk(addr) in do_sea() to see if it always faults on
> >>>> the same address?
> >>>
> >>> Alternatively, just run it a few more times and see if the register dump
> >>> changes. Currently we've got:
> >>>
> >>> [ 0.000000] x5 : ffff8000f8400000 x4 : ffff800008400000
> >>> [ 0.000000] x3 : 0000000008400000 x2 : 0000000000000000
> >>> [ 0.000000] x1 : 0000000000000000 x0 : aaaaaaaaaaaaaaaa
> >>>
> >>> so I'd guess that x3 is the faulting pa. The faulting (linear) VAs in the
> >>> originl report were 0xffff800009c74aa8 and 0xffff800009c08390, which is
> >>> still a way way off from this one :/
> >>>
> >>> Looking at the TRM for the rk3328, there's 4gb of ram starting at pa 0x0,
> >>> so maybe some of it has been configured as secure or the memory controller
> >>> hasn't been properly initialised?
> >>
> >> FWIW I've noticed my RK3399 board doing this too, now that I've started
> >> using it in anger. I'm using a hacky firmware comprising upstream U-Boot
> >> munged with the Rockchip miniloader and downstream Trusted Firmware
> >> binaries,
> >
> > any reason for that combination? For example the rockpro64 got ddr4 support
> > in upstream uboot recently.
>
> Not really; it's just the "works well enough" setup that made distro
> boot usable before the SPL support went upstream, and (other than
> hacking in the CPU PLL initialisation which otherwise gets lost in that
> combination) I haven't touched it since.
>
> [ for now I've just hacked a reserved-memory node into my DT... one day
> I'll get round to firmware tinkering ;) ]
>
>
> >> and it looks like that mismatch is the root of this problem.
> >> Booting a different image based on the BSP U-boot shows that that's
> >> passing a memory node with the range 0x8400000-0x9600000 entirely carved
> >> out, so this is presumably claimed by the secure firmware/TEE and set to
> >> abort Non-Secure accesses.
> >
> > As TEE on PX30 is also one of my current projects, I've stumbled over that
> > memory issue. At least OP-TEE can get passed a location for a dtb during
> > startup which it then would modify to add a reserved section for its memory.
> >
> > But that dtb generally is not the one, the kernel will actually use, but
> > instead only the one used by uboot. extlinux, tftp or whatever will normally
> > load and use a new dtb for the kernel which will likely not get that memory
> > reservation automatically?
> >
> > I'm not yet sure how this is supposed to work in an all-upstream
> > configuration - I'm running upstream u-boot + upstream TF-A + upstream
> > OP-Tee in my project environment right now.
>
> As far as I understand, U-Boot is still responsible for generating the
> memory node in whatever DTB it loads and passes to the kernel, so it
> should still be able to adjust that accordingly. Presumably U-Boot needs
> to discover any firmware/TEE reservations early on to avoid touching any
> Secure memory itself, so it should just need to keep track of them until
> finalising the kernel DTB.
Yeah, that's similar to what I discovered so far :-D .
SPL loads u-boot.itb which should contain, u-boot, tf-a, tee and dt.
[vendor tf-a might do that differently though]
It passes the dt-address as param to both tf-a and optee, which then
may add stuff, like optee adding the firmware-node + reserved-memory
sections.
This dt is then the basis for the main u-boot, to be found at gd->fdt_blob.
So u-boot will need to discover and transplant optee-firmware + optee
reserved-memory sections to any later dt that gets loaded.
Which is what I'll be looking at next ;-) .
Heiko
_______________________________________________
linux-arm-kernel mailing list
linux-arm-kernel@lists.infradead.org
http://lists.infradead.org/mailman/listinfo/linux-arm-kernel
^ permalink raw reply [flat|nested] 14+ messages in thread
* Re: aarch64 Kernel Panic Asynchronous SError Interrupt on large file IO
2019-10-07 13:38 ` Heiko Stübner
@ 2019-10-07 14:01 ` André Przywara
2019-10-07 14:06 ` Heiko Stübner
0 siblings, 1 reply; 14+ messages in thread
From: André Przywara @ 2019-10-07 14:01 UTC (permalink / raw)
To: Heiko Stübner, Robin Murphy
Cc: Catalin Marinas, vicencb, linux-rockchip, Philipp Richter,
Will Deacon, linux-arm-kernel
On 07/10/2019 14:38, Heiko Stübner wrote:
> Am Montag, 7. Oktober 2019, 13:51:37 CEST schrieb Robin Murphy:
>> On 06/10/2019 14:13, Heiko Stuebner wrote:
>>> Am Sonntag, 6. Oktober 2019, 01:45:23 CEST schrieb Robin Murphy:
>>>> On 2019-08-19 11:43 am, Will Deacon wrote:
>>>>> On Mon, Aug 19, 2019 at 11:07:14AM +0100, Catalin Marinas wrote:
>>>>>> On Sat, Aug 17, 2019 at 03:12:41PM +0200, Philipp Richter wrote:
>>>>>>> I added "memtest=4" to the kernel cmdline and I'm getting very quicky
>>>>>>> a "Internal error: synchronous external abort" panic.
>>>>>> [...]
>>>>>>> [ 0.000000] early_memtest: # of tests: 4
>>>>>>> [ 0.000000] 0x0000000000200000 - 0x0000000002080000 pattern aaaaaaaaaaaaaaaa
>>>>>>> [ 0.000000] 0x0000000003a95000 - 0x00000000f8400000 pattern aaaaaaaaaaaaaaaa
>>>>>>> [ 0.000000] Internal error: synchronous external abort: 96000210 [#1] SMP
>>>>>>
>>>>>> At least it's a synchronous error ;).
>>>>>>
>>>>>>> [ 0.000000] pc : early_memtest+0x16c/0x23c
>>>>>> [...]
>>>>>>> [ 0.000000] Code: d2800002 d2800001 eb0400bf 54000309 (f9400080)
>>>>>>
>>>>>> decodecode says:
>>>>>>
>>>>>> 0: d2800002 mov x2, #0x0 // #0
>>>>>> 4: d2800001 mov x1, #0x0 // #0
>>>>>> 8: eb0400bf cmp x5, x4
>>>>>> c: 54000309 b.ls 0x6c // b.plast
>>>>>> 10:* f9400080 ldr x0, [x4] <-- trapping instruction
>>>>>>
>>>>>> I guess that's the read of *p in memtest(). Writing *p probably
>>>>>> generates asynchronous errors it you haven't seen it yet.
>>>>>>
>>>>>>> Is my board completely broken ? :(
>>>>>>
>>>>>> One possibility is that you don't have any memory where you think there
>>>>>> is, so the mapping just doesn't translate to any valid physical
>>>>>> location.
>>>>>>
>>>>>> Can you add some printk(addr) in do_sea() to see if it always faults on
>>>>>> the same address?
>>>>>
>>>>> Alternatively, just run it a few more times and see if the register dump
>>>>> changes. Currently we've got:
>>>>>
>>>>> [ 0.000000] x5 : ffff8000f8400000 x4 : ffff800008400000
>>>>> [ 0.000000] x3 : 0000000008400000 x2 : 0000000000000000
>>>>> [ 0.000000] x1 : 0000000000000000 x0 : aaaaaaaaaaaaaaaa
>>>>>
>>>>> so I'd guess that x3 is the faulting pa. The faulting (linear) VAs in the
>>>>> originl report were 0xffff800009c74aa8 and 0xffff800009c08390, which is
>>>>> still a way way off from this one :/
>>>>>
>>>>> Looking at the TRM for the rk3328, there's 4gb of ram starting at pa 0x0,
>>>>> so maybe some of it has been configured as secure or the memory controller
>>>>> hasn't been properly initialised?
>>>>
>>>> FWIW I've noticed my RK3399 board doing this too, now that I've started
>>>> using it in anger. I'm using a hacky firmware comprising upstream U-Boot
>>>> munged with the Rockchip miniloader and downstream Trusted Firmware
>>>> binaries,
>>>
>>> any reason for that combination? For example the rockpro64 got ddr4 support
>>> in upstream uboot recently.
>>
>> Not really; it's just the "works well enough" setup that made distro
>> boot usable before the SPL support went upstream, and (other than
>> hacking in the CPU PLL initialisation which otherwise gets lost in that
>> combination) I haven't touched it since.
>>
>> [ for now I've just hacked a reserved-memory node into my DT... one day
>> I'll get round to firmware tinkering ;) ]
>>
>>
>>>> and it looks like that mismatch is the root of this problem.
>>>> Booting a different image based on the BSP U-boot shows that that's
>>>> passing a memory node with the range 0x8400000-0x9600000 entirely carved
>>>> out, so this is presumably claimed by the secure firmware/TEE and set to
>>>> abort Non-Secure accesses.
>>>
>>> As TEE on PX30 is also one of my current projects, I've stumbled over that
>>> memory issue. At least OP-TEE can get passed a location for a dtb during
>>> startup which it then would modify to add a reserved section for its memory.
>>>
>>> But that dtb generally is not the one, the kernel will actually use, but
>>> instead only the one used by uboot. extlinux, tftp or whatever will normally
>>> load and use a new dtb for the kernel which will likely not get that memory
>>> reservation automatically?
>>>
>>> I'm not yet sure how this is supposed to work in an all-upstream
>>> configuration - I'm running upstream u-boot + upstream TF-A + upstream
>>> OP-Tee in my project environment right now.
>>
>> As far as I understand, U-Boot is still responsible for generating the
>> memory node in whatever DTB it loads and passes to the kernel, so it
>> should still be able to adjust that accordingly. Presumably U-Boot needs
>> to discover any firmware/TEE reservations early on to avoid touching any
>> Secure memory itself, so it should just need to keep track of them until
>> finalising the kernel DTB.
>
> Yeah, that's similar to what I discovered so far :-D .
>
> SPL loads u-boot.itb which should contain, u-boot, tf-a, tee and dt.
> [vendor tf-a might do that differently though]
>
> It passes the dt-address as param to both tf-a and optee, which then
> may add stuff, like optee adding the firmware-node + reserved-memory
> sections.
>
> This dt is then the basis for the main u-boot, to be found at gd->fdt_blob.
> So u-boot will need to discover and transplant optee-firmware + optee
> reserved-memory sections to any later dt that gets loaded.
Indeed U-Boot is mostly ignoring both /memreserve/ and /reserved-memory
for its own purposes so far. There is code
(boot_fdt_add_mem_rsv_regions()) to parse those nodes and translate them
into an lmb block, but this is then only used for relocating FDT and
initrd when loading kernels, AFAICS. I think the idea is that the most
of the memory setup (heap) is static anyway and you would take care of
not placing any U-Boot components in reserved memory regions in the
first place.
Is U-Boot actually tripping over something? Or is this just to be safe
for the future?
And I have a gut feeling the implementing no-map will be tricky, AFAIK
the page table setup is mostly static and won't change after the MMU is
enabled. Which means we would need to do it before the MMU is enabled?
Cheers,
Andre
_______________________________________________
linux-arm-kernel mailing list
linux-arm-kernel@lists.infradead.org
http://lists.infradead.org/mailman/listinfo/linux-arm-kernel
^ permalink raw reply [flat|nested] 14+ messages in thread
* Re: aarch64 Kernel Panic Asynchronous SError Interrupt on large file IO
2019-10-07 14:01 ` André Przywara
@ 2019-10-07 14:06 ` Heiko Stübner
2019-10-08 8:08 ` Heiko Stübner
0 siblings, 1 reply; 14+ messages in thread
From: Heiko Stübner @ 2019-10-07 14:06 UTC (permalink / raw)
To: André Przywara
Cc: Robin Murphy, vicencb, linux-rockchip, Catalin Marinas,
Philipp Richter, Will Deacon, linux-arm-kernel
Am Montag, 7. Oktober 2019, 16:01:05 CEST schrieb André Przywara:
> On 07/10/2019 14:38, Heiko Stübner wrote:
> > Am Montag, 7. Oktober 2019, 13:51:37 CEST schrieb Robin Murphy:
> >> On 06/10/2019 14:13, Heiko Stuebner wrote:
> >>> Am Sonntag, 6. Oktober 2019, 01:45:23 CEST schrieb Robin Murphy:
> >>>> On 2019-08-19 11:43 am, Will Deacon wrote:
> >>>>> On Mon, Aug 19, 2019 at 11:07:14AM +0100, Catalin Marinas wrote:
> >>>>>> On Sat, Aug 17, 2019 at 03:12:41PM +0200, Philipp Richter wrote:
> >>>>>>> I added "memtest=4" to the kernel cmdline and I'm getting very quicky
> >>>>>>> a "Internal error: synchronous external abort" panic.
> >>>>>> [...]
> >>>>>>> [ 0.000000] early_memtest: # of tests: 4
> >>>>>>> [ 0.000000] 0x0000000000200000 - 0x0000000002080000 pattern aaaaaaaaaaaaaaaa
> >>>>>>> [ 0.000000] 0x0000000003a95000 - 0x00000000f8400000 pattern aaaaaaaaaaaaaaaa
> >>>>>>> [ 0.000000] Internal error: synchronous external abort: 96000210 [#1] SMP
> >>>>>>
> >>>>>> At least it's a synchronous error ;).
> >>>>>>
> >>>>>>> [ 0.000000] pc : early_memtest+0x16c/0x23c
> >>>>>> [...]
> >>>>>>> [ 0.000000] Code: d2800002 d2800001 eb0400bf 54000309 (f9400080)
> >>>>>>
> >>>>>> decodecode says:
> >>>>>>
> >>>>>> 0: d2800002 mov x2, #0x0 // #0
> >>>>>> 4: d2800001 mov x1, #0x0 // #0
> >>>>>> 8: eb0400bf cmp x5, x4
> >>>>>> c: 54000309 b.ls 0x6c // b.plast
> >>>>>> 10:* f9400080 ldr x0, [x4] <-- trapping instruction
> >>>>>>
> >>>>>> I guess that's the read of *p in memtest(). Writing *p probably
> >>>>>> generates asynchronous errors it you haven't seen it yet.
> >>>>>>
> >>>>>>> Is my board completely broken ? :(
> >>>>>>
> >>>>>> One possibility is that you don't have any memory where you think there
> >>>>>> is, so the mapping just doesn't translate to any valid physical
> >>>>>> location.
> >>>>>>
> >>>>>> Can you add some printk(addr) in do_sea() to see if it always faults on
> >>>>>> the same address?
> >>>>>
> >>>>> Alternatively, just run it a few more times and see if the register dump
> >>>>> changes. Currently we've got:
> >>>>>
> >>>>> [ 0.000000] x5 : ffff8000f8400000 x4 : ffff800008400000
> >>>>> [ 0.000000] x3 : 0000000008400000 x2 : 0000000000000000
> >>>>> [ 0.000000] x1 : 0000000000000000 x0 : aaaaaaaaaaaaaaaa
> >>>>>
> >>>>> so I'd guess that x3 is the faulting pa. The faulting (linear) VAs in the
> >>>>> originl report were 0xffff800009c74aa8 and 0xffff800009c08390, which is
> >>>>> still a way way off from this one :/
> >>>>>
> >>>>> Looking at the TRM for the rk3328, there's 4gb of ram starting at pa 0x0,
> >>>>> so maybe some of it has been configured as secure or the memory controller
> >>>>> hasn't been properly initialised?
> >>>>
> >>>> FWIW I've noticed my RK3399 board doing this too, now that I've started
> >>>> using it in anger. I'm using a hacky firmware comprising upstream U-Boot
> >>>> munged with the Rockchip miniloader and downstream Trusted Firmware
> >>>> binaries,
> >>>
> >>> any reason for that combination? For example the rockpro64 got ddr4 support
> >>> in upstream uboot recently.
> >>
> >> Not really; it's just the "works well enough" setup that made distro
> >> boot usable before the SPL support went upstream, and (other than
> >> hacking in the CPU PLL initialisation which otherwise gets lost in that
> >> combination) I haven't touched it since.
> >>
> >> [ for now I've just hacked a reserved-memory node into my DT... one day
> >> I'll get round to firmware tinkering ;) ]
> >>
> >>
> >>>> and it looks like that mismatch is the root of this problem.
> >>>> Booting a different image based on the BSP U-boot shows that that's
> >>>> passing a memory node with the range 0x8400000-0x9600000 entirely carved
> >>>> out, so this is presumably claimed by the secure firmware/TEE and set to
> >>>> abort Non-Secure accesses.
> >>>
> >>> As TEE on PX30 is also one of my current projects, I've stumbled over that
> >>> memory issue. At least OP-TEE can get passed a location for a dtb during
> >>> startup which it then would modify to add a reserved section for its memory.
> >>>
> >>> But that dtb generally is not the one, the kernel will actually use, but
> >>> instead only the one used by uboot. extlinux, tftp or whatever will normally
> >>> load and use a new dtb for the kernel which will likely not get that memory
> >>> reservation automatically?
> >>>
> >>> I'm not yet sure how this is supposed to work in an all-upstream
> >>> configuration - I'm running upstream u-boot + upstream TF-A + upstream
> >>> OP-Tee in my project environment right now.
> >>
> >> As far as I understand, U-Boot is still responsible for generating the
> >> memory node in whatever DTB it loads and passes to the kernel, so it
> >> should still be able to adjust that accordingly. Presumably U-Boot needs
> >> to discover any firmware/TEE reservations early on to avoid touching any
> >> Secure memory itself, so it should just need to keep track of them until
> >> finalising the kernel DTB.
> >
> > Yeah, that's similar to what I discovered so far :-D .
> >
> > SPL loads u-boot.itb which should contain, u-boot, tf-a, tee and dt.
> > [vendor tf-a might do that differently though]
> >
> > It passes the dt-address as param to both tf-a and optee, which then
> > may add stuff, like optee adding the firmware-node + reserved-memory
> > sections.
> >
> > This dt is then the basis for the main u-boot, to be found at gd->fdt_blob.
> > So u-boot will need to discover and transplant optee-firmware + optee
> > reserved-memory sections to any later dt that gets loaded.
>
> Indeed U-Boot is mostly ignoring both /memreserve/ and /reserved-memory
> for its own purposes so far. There is code
> (boot_fdt_add_mem_rsv_regions()) to parse those nodes and translate them
> into an lmb block, but this is then only used for relocating FDT and
> initrd when loading kernels, AFAICS. I think the idea is that the most
> of the memory setup (heap) is static anyway and you would take care of
> not placing any U-Boot components in reserved memory regions in the
> first place.
> Is U-Boot actually tripping over something? Or is this just to be safe
> for the future?
It's not u-boot that is tripping but a later loaded kernel. As I've written
op-tee adds its nodes to the dt loaded by the SPL from a FIT image.
Which may not necessarily be the same dt that gets used by the later
kernel. PXE-boot for example may very well just load a different dt
from emmc / network than the one stored in the firmware image.
So the reserved memory sections will need to move over to that dt
as well if we're starting a kernel with a different dt, similar to how
u-boot will add the core memory there as well.
Heiko
> And I have a gut feeling the implementing no-map will be tricky, AFAIK
> the page table setup is mostly static and won't change after the MMU is
> enabled. Which means we would need to do it before the MMU is enabled?
>
> Cheers,
> Andre
>
_______________________________________________
linux-arm-kernel mailing list
linux-arm-kernel@lists.infradead.org
http://lists.infradead.org/mailman/listinfo/linux-arm-kernel
^ permalink raw reply [flat|nested] 14+ messages in thread
* Re: aarch64 Kernel Panic Asynchronous SError Interrupt on large file IO
2019-10-07 14:06 ` Heiko Stübner
@ 2019-10-08 8:08 ` Heiko Stübner
0 siblings, 0 replies; 14+ messages in thread
From: Heiko Stübner @ 2019-10-08 8:08 UTC (permalink / raw)
To: André Przywara
Cc: Robin Murphy, vicencb, linux-rockchip, Catalin Marinas,
Philipp Richter, Will Deacon, linux-arm-kernel
Am Montag, 7. Oktober 2019, 16:06:44 CEST schrieb Heiko Stübner:
> Am Montag, 7. Oktober 2019, 16:01:05 CEST schrieb André Przywara:
> > On 07/10/2019 14:38, Heiko Stübner wrote:
> > > Am Montag, 7. Oktober 2019, 13:51:37 CEST schrieb Robin Murphy:
> > >> On 06/10/2019 14:13, Heiko Stuebner wrote:
> > >>> Am Sonntag, 6. Oktober 2019, 01:45:23 CEST schrieb Robin Murphy:
> > >>>> On 2019-08-19 11:43 am, Will Deacon wrote:
> > >>>>> On Mon, Aug 19, 2019 at 11:07:14AM +0100, Catalin Marinas wrote:
> > >>>>>> On Sat, Aug 17, 2019 at 03:12:41PM +0200, Philipp Richter wrote:
> > >>>>>>> I added "memtest=4" to the kernel cmdline and I'm getting very quicky
> > >>>>>>> a "Internal error: synchronous external abort" panic.
> > >>>>>> [...]
> > >>>>>>> [ 0.000000] early_memtest: # of tests: 4
> > >>>>>>> [ 0.000000] 0x0000000000200000 - 0x0000000002080000 pattern aaaaaaaaaaaaaaaa
> > >>>>>>> [ 0.000000] 0x0000000003a95000 - 0x00000000f8400000 pattern aaaaaaaaaaaaaaaa
> > >>>>>>> [ 0.000000] Internal error: synchronous external abort: 96000210 [#1] SMP
> > >>>>>>
> > >>>>>> At least it's a synchronous error ;).
> > >>>>>>
> > >>>>>>> [ 0.000000] pc : early_memtest+0x16c/0x23c
> > >>>>>> [...]
> > >>>>>>> [ 0.000000] Code: d2800002 d2800001 eb0400bf 54000309 (f9400080)
> > >>>>>>
> > >>>>>> decodecode says:
> > >>>>>>
> > >>>>>> 0: d2800002 mov x2, #0x0 // #0
> > >>>>>> 4: d2800001 mov x1, #0x0 // #0
> > >>>>>> 8: eb0400bf cmp x5, x4
> > >>>>>> c: 54000309 b.ls 0x6c // b.plast
> > >>>>>> 10:* f9400080 ldr x0, [x4] <-- trapping instruction
> > >>>>>>
> > >>>>>> I guess that's the read of *p in memtest(). Writing *p probably
> > >>>>>> generates asynchronous errors it you haven't seen it yet.
> > >>>>>>
> > >>>>>>> Is my board completely broken ? :(
> > >>>>>>
> > >>>>>> One possibility is that you don't have any memory where you think there
> > >>>>>> is, so the mapping just doesn't translate to any valid physical
> > >>>>>> location.
> > >>>>>>
> > >>>>>> Can you add some printk(addr) in do_sea() to see if it always faults on
> > >>>>>> the same address?
> > >>>>>
> > >>>>> Alternatively, just run it a few more times and see if the register dump
> > >>>>> changes. Currently we've got:
> > >>>>>
> > >>>>> [ 0.000000] x5 : ffff8000f8400000 x4 : ffff800008400000
> > >>>>> [ 0.000000] x3 : 0000000008400000 x2 : 0000000000000000
> > >>>>> [ 0.000000] x1 : 0000000000000000 x0 : aaaaaaaaaaaaaaaa
> > >>>>>
> > >>>>> so I'd guess that x3 is the faulting pa. The faulting (linear) VAs in the
> > >>>>> originl report were 0xffff800009c74aa8 and 0xffff800009c08390, which is
> > >>>>> still a way way off from this one :/
> > >>>>>
> > >>>>> Looking at the TRM for the rk3328, there's 4gb of ram starting at pa 0x0,
> > >>>>> so maybe some of it has been configured as secure or the memory controller
> > >>>>> hasn't been properly initialised?
> > >>>>
> > >>>> FWIW I've noticed my RK3399 board doing this too, now that I've started
> > >>>> using it in anger. I'm using a hacky firmware comprising upstream U-Boot
> > >>>> munged with the Rockchip miniloader and downstream Trusted Firmware
> > >>>> binaries,
> > >>>
> > >>> any reason for that combination? For example the rockpro64 got ddr4 support
> > >>> in upstream uboot recently.
> > >>
> > >> Not really; it's just the "works well enough" setup that made distro
> > >> boot usable before the SPL support went upstream, and (other than
> > >> hacking in the CPU PLL initialisation which otherwise gets lost in that
> > >> combination) I haven't touched it since.
> > >>
> > >> [ for now I've just hacked a reserved-memory node into my DT... one day
> > >> I'll get round to firmware tinkering ;) ]
> > >>
> > >>
> > >>>> and it looks like that mismatch is the root of this problem.
> > >>>> Booting a different image based on the BSP U-boot shows that that's
> > >>>> passing a memory node with the range 0x8400000-0x9600000 entirely carved
> > >>>> out, so this is presumably claimed by the secure firmware/TEE and set to
> > >>>> abort Non-Secure accesses.
> > >>>
> > >>> As TEE on PX30 is also one of my current projects, I've stumbled over that
> > >>> memory issue. At least OP-TEE can get passed a location for a dtb during
> > >>> startup which it then would modify to add a reserved section for its memory.
> > >>>
> > >>> But that dtb generally is not the one, the kernel will actually use, but
> > >>> instead only the one used by uboot. extlinux, tftp or whatever will normally
> > >>> load and use a new dtb for the kernel which will likely not get that memory
> > >>> reservation automatically?
> > >>>
> > >>> I'm not yet sure how this is supposed to work in an all-upstream
> > >>> configuration - I'm running upstream u-boot + upstream TF-A + upstream
> > >>> OP-Tee in my project environment right now.
> > >>
> > >> As far as I understand, U-Boot is still responsible for generating the
> > >> memory node in whatever DTB it loads and passes to the kernel, so it
> > >> should still be able to adjust that accordingly. Presumably U-Boot needs
> > >> to discover any firmware/TEE reservations early on to avoid touching any
> > >> Secure memory itself, so it should just need to keep track of them until
> > >> finalising the kernel DTB.
> > >
> > > Yeah, that's similar to what I discovered so far :-D .
> > >
> > > SPL loads u-boot.itb which should contain, u-boot, tf-a, tee and dt.
> > > [vendor tf-a might do that differently though]
> > >
> > > It passes the dt-address as param to both tf-a and optee, which then
> > > may add stuff, like optee adding the firmware-node + reserved-memory
> > > sections.
> > >
> > > This dt is then the basis for the main u-boot, to be found at gd->fdt_blob.
> > > So u-boot will need to discover and transplant optee-firmware + optee
> > > reserved-memory sections to any later dt that gets loaded.
> >
> > Indeed U-Boot is mostly ignoring both /memreserve/ and /reserved-memory
> > for its own purposes so far. There is code
> > (boot_fdt_add_mem_rsv_regions()) to parse those nodes and translate them
> > into an lmb block, but this is then only used for relocating FDT and
> > initrd when loading kernels, AFAICS. I think the idea is that the most
> > of the memory setup (heap) is static anyway and you would take care of
> > not placing any U-Boot components in reserved memory regions in the
> > first place.
> > Is U-Boot actually tripping over something? Or is this just to be safe
> > for the future?
>
> It's not u-boot that is tripping but a later loaded kernel. As I've written
> op-tee adds its nodes to the dt loaded by the SPL from a FIT image.
>
> Which may not necessarily be the same dt that gets used by the later
> kernel. PXE-boot for example may very well just load a different dt
> from emmc / network than the one stored in the firmware image.
>
> So the reserved memory sections will need to move over to that dt
> as well if we're starting a kernel with a different dt, similar to how
> u-boot will add the core memory there as well.
Yesterday I did implement the relevant code to do this transfer in
https://patchwork.ozlabs.org/patch/1173030/
This will work with a "regular" atf + optee bringup with optee given
to TF-A as a bl32 param, as the other relevant patches do:
https://patchwork.ozlabs.org/patch/1172566/
https://patchwork.ozlabs.org/patch/1172565/
Mileage may vary with Rockchip's binary ATF+Optee combination,
as this is distributed as one image and thus likely does something
strange during the jump from ATF to Optee.
Reviews welcome ;-)
Heiko
> > And I have a gut feeling the implementing no-map will be tricky, AFAIK
> > the page table setup is mostly static and won't change after the MMU is
> > enabled. Which means we would need to do it before the MMU is enabled?
> >
> > Cheers,
> > Andre
> >
>
_______________________________________________
linux-arm-kernel mailing list
linux-arm-kernel@lists.infradead.org
http://lists.infradead.org/mailman/listinfo/linux-arm-kernel
^ permalink raw reply [flat|nested] 14+ messages in thread
end of thread, other threads:[~2019-10-08 8:09 UTC | newest]
Thread overview: 14+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
[not found] <CA+Vb7hpe_USzdCuTBHd8V-t6YeQ0oApiBrvM-D43JuhJda6eyQ@mail.gmail.com>
[not found] ` <20190815122151.bg7it6ptxwcn2vif@willie-the-truck>
2019-08-15 13:59 ` aarch64 Kernel Panic Asynchronous SError Interrupt on large file IO Robin Murphy
[not found] ` <CA+Vb7hpi=pCC9viiof8y85Kw_vCawWQ0B6kGFALgxtZfCKoaTw@mail.gmail.com>
2019-08-15 16:00 ` Philipp Richter
2019-08-16 12:01 ` Robin Murphy
2019-08-16 18:54 ` Philipp Richter
2019-08-17 13:12 ` Philipp Richter
2019-08-19 10:07 ` Catalin Marinas
2019-08-19 10:43 ` Will Deacon
2019-10-05 23:45 ` Robin Murphy
2019-10-06 13:13 ` Heiko Stuebner
2019-10-07 11:51 ` Robin Murphy
2019-10-07 13:38 ` Heiko Stübner
2019-10-07 14:01 ` André Przywara
2019-10-07 14:06 ` Heiko Stübner
2019-10-08 8:08 ` Heiko Stübner
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).