bcachefs icon indicating copy to clipboard operation
bcachefs copied to clipboard

With Encryption Enabled: "Unable to handle kernel paging request at virtual address"

Open GoogleBot42 opened this issue 2 years ago • 3 comments

Not sure if this is actually an issue with bcachefs since support for the NAS I'm running on is very new in Linux.

I can create single/multi disk file systems + mount and use them just fine. But if I add encryption even with a simple bcachefs format --encrypted /dev/sda mounting later fails.

The logs. In this example, a brand new formatted filesystem is used and is about to be mounted for the first time. I did use multiple disks but I get a very similar error with only just one and no extra options. At 113.510775 is when the system is mounted.

Let me know if more info will help.

[    0.000000] Booting Linux on physical CPU 0x0000000000 [0x410fd034]
[    0.000000] Linux version 5.15.28 (nixbld@localhost) (gcc (GCC) 9.3.0, GNU ld (GNU Binutils) 2.35.2) #1-NixOS SMP Fri Mar 11 11:22:37 UTC 2022
[    0.000000] Machine model: Kobol Helios64
[    0.000000] earlycon: uart8250 at MMIO32 0x00000000ff1a0000 (options '')
[    0.000000] printk: bootconsole [uart8250] enabled
[    0.000000] efi: UEFI not found.
[    0.000000] NUMA: No NUMA configuration found
[    0.000000] NUMA: Faking a node at [mem 0x0000000000200000-0x00000000f7ffffff]
[    0.000000] NUMA: NODE_DATA [mem 0xf77e0140-0xf77e2fff]
[    0.000000] Zone ranges:
[    0.000000]   DMA      [mem 0x0000000000200000-0x00000000f7ffffff]
[    0.000000]   DMA32    empty
[    0.000000]   Normal   empty
[    0.000000]   Device   empty
[    0.000000] Movable zone start for each node
[    0.000000] Early memory node ranges
[    0.000000]   node   0: [mem 0x0000000000200000-0x00000000f7ffffff]
[    0.000000] Initmem setup node 0 [mem 0x0000000000200000-0x00000000f7ffffff]
[    0.000000] cma: Reserved 32 MiB at 0x00000000ef800000
[    0.000000] psci: probing for conduit method from DT.
[    0.000000] psci: PSCIv1.1 detected in firmware.
[    0.000000] psci: Using standard PSCI v0.2 function IDs
[    0.000000] psci: MIGRATE_INFO_TYPE not supported.
[    0.000000] psci: SMC Calling Convention v1.2
[    0.000000] percpu: Embedded 30 pages/cpu s82200 r8192 d32488 u122880
[    0.000000] pcpu-alloc: s82200 r8192 d32488 u122880 alloc=30*4096
[    0.000000] pcpu-alloc: [0] 0 [0] 1 [0] 2 [0] 3 [0] 4 [0] 5 
[    0.000000] Detected VIPT I-cache on CPU0
[    0.000000] CPU features: detected: GIC system register CPU interface
[    0.000000] CPU features: detected: ARM erratum 845719
[    0.000000] Built 1 zonelists, mobility grouping on.  Total pages: 999432
[    0.000000] Policy zone: DMA
[    0.000000] Kernel command line: init=/nix/store/sbphzfc1flkcfhxh5jk3z7a4hkj3da32-nixos-system-s0-22.05.20220316.ed32ed9/init loglevel=4 console=ttyS2,115200n8 earlyprintk earlycon=uart8250,mmio32,0xff1a0000
[    0.000000] Unknown kernel command line parameters "earlyprintk", will be passed to user space.
[    0.000000] Dentry cache hash table entries: 524288 (order: 10, 4194304 bytes, linear)
[    0.000000] Inode-cache hash table entries: 262144 (order: 9, 2097152 bytes, linear)
[    0.000000] mem auto-init: stack:off, heap alloc:off, heap free:off
[    0.000000] Memory: 3895200K/4061184K available (19520K kernel code, 4564K rwdata, 10584K rodata, 10368K init, 633K bss, 133216K reserved, 32768K cma-reserved)
[    0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=6, Nodes=1
[    0.000000] ftrace: allocating 64159 entries in 251 pages
[    0.000000] ftrace: allocated 251 pages with 7 groups
[    0.000000] trace event string verifier disabled
[    0.000000] rcu: Hierarchical RCU implementation.
[    0.000000] rcu:     RCU event tracing is enabled.
[    0.000000] rcu:     RCU restricting CPUs from NR_CPUS=384 to nr_cpu_ids=6.
[    0.000000]  Trampoline variant of Tasks RCU enabled.
[    0.000000]  Rude variant of Tasks RCU enabled.
[    0.000000]  Tracing variant of Tasks RCU enabled.
[    0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 25 jiffies.
[    0.000000] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=6
[    0.000000] NR_IRQS: 64, nr_irqs: 64, preallocated irqs: 0
[    0.000000] GICv3: GIC: Using split EOI/Deactivate mode
[    0.000000] GICv3: 256 SPIs implemented
[    0.000000] GICv3: 0 Extended SPIs implemented
[    0.000000] GICv3: Distributor has no Range Selector support
[    0.000000] Root IRQ handler: gic_handle_irq
[    0.000000] GICv3: 16 PPIs implemented
[    0.000000] GICv3: CPU0: found redistributor 0 region 0:0x00000000fef00000
[    0.000000] ITS [mem 0xfee20000-0xfee3ffff]
[    0.000000] ITS@0x00000000fee20000: allocated 65536 Devices @680000 (flat, esz 8, psz 64K, shr 0)
[    0.000000] ITS: using cache flushing for cmd queue
[    0.000000] GICv3: using LPI property table @0x0000000000610000
[    0.000000] GIC: using cache flushing for LPI property table
[    0.000000] GICv3: CPU0: using allocated LPI pending table @0x0000000000620000
[    0.000000] GICv3: GIC: PPI partition interrupt-partition-0[0] { /cpus/cpu@0[0] /cpus/cpu@1[1] /cpus/cpu@2[2] /cpus/cpu@3[3] }
[    0.000000] GICv3: GIC: PPI partition interrupt-partition-1[1] { /cpus/cpu@100[4] /cpus/cpu@101[5] }
[    0.000000] random: get_random_bytes called from start_kernel+0x530/0x714 with crng_init=0
[    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.000001] sched_clock: 56 bits at 24MHz, resolution 41ns, wraps every 4398046511097ns
[    0.003970] Console: colour dummy device 80x25
[    0.004117] Calibrating delay loop (skipped), value calculated using timer frequency.. 48.00 BogoMIPS (lpj=96000)
[    0.004139] pid_max: default: 32768 minimum: 301
[    0.004279] LSM: Security Framework initializing
[    0.004331] landlock: Up and running.
[    0.004338] Yama: becoming mindful.
[    0.004390] LSM support for eBPF active
[    0.004470] Mount-cache hash table entries: 8192 (order: 4, 65536 bytes, linear)
[    0.004506] Mountpoint-cache hash table entries: 8192 (order: 4, 65536 bytes, linear)
[    0.007715] rcu: Hierarchical SRCU implementation.
[    0.009621] Platform MSI: interrupt-controller@fee20000 domain created
[    0.010093] PCI/MSI: /interrupt-controller@fee00000/interrupt-controller@fee20000 domain created
[    0.010370] fsl-mc MSI: interrupt-controller@fee20000 domain created
[    0.017240] EFI services will not be available.
[    0.017910] smp: Bringing up secondary CPUs ...
[    0.018800] Detected VIPT I-cache on CPU1
[    0.018855] GICv3: CPU1: found redistributor 1 region 0:0x00000000fef20000
[    0.018879] GICv3: CPU1: using allocated LPI pending table @0x0000000000630000
[    0.018955] CPU1: Booted secondary processor 0x0000000001 [0x410fd034]
[    0.019949] Detected VIPT I-cache on CPU2
[    0.019989] GICv3: CPU2: found redistributor 2 region 0:0x00000000fef40000
[    0.020008] GICv3: CPU2: using allocated LPI pending table @0x0000000000640000
[    0.020056] CPU2: Booted secondary processor 0x0000000002 [0x410fd034]
[    0.020971] Detected VIPT I-cache on CPU3
[    0.021010] GICv3: CPU3: found redistributor 3 region 0:0x00000000fef60000
[    0.021029] GICv3: CPU3: using allocated LPI pending table @0x0000000000650000
[    0.021075] CPU3: Booted secondary processor 0x0000000003 [0x410fd034]
[    0.022059] CPU features: detected: Spectre-v2
[    0.022072] CPU features: detected: Spectre-v3a
[    0.022081] CPU features: detected: Spectre-BHB
[    0.022093] CPU features: detected: ARM errata 1165522, 1319367, or 1530923
[    0.022098] Detected PIPT I-cache on CPU4
[    0.022136] GICv3: CPU4: found redistributor 100 region 0:0x00000000fef80000
[    0.022154] GICv3: CPU4: using allocated LPI pending table @0x0000000000660000
[    0.022202] CPU4: Booted secondary processor 0x0000000100 [0x410fd082]
[    0.023161] Detected PIPT I-cache on CPU5
[    0.023195] GICv3: CPU5: found redistributor 101 region 0:0x00000000fefa0000
[    0.023212] GICv3: CPU5: using allocated LPI pending table @0x0000000000670000
[    0.023251] CPU5: Booted secondary processor 0x0000000101 [0x410fd082]
[    0.023399] smp: Brought up 1 node, 6 CPUs
[    0.023435] SMP: Total of 6 processors activated.
[    0.023444] CPU features: detected: 32-bit EL0 Support
[    0.023450] CPU features: detected: 32-bit EL1 Support
[    0.023459] CPU features: detected: CRC32 instructions
[    0.058372] CPU: All CPU(s) started at EL2
[    0.058487] alternatives: patching kernel code
[    0.063125] devtmpfs: initialized
[    0.076694] KASLR disabled due to lack of seed
[    0.076898] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645041785100000 ns
[    0.076921] futex hash table entries: 2048 (order: 5, 131072 bytes, linear)
[    0.078047] pinctrl core: initialized pinctrl subsystem
[    0.079174] DMI not present or invalid.
[    0.079756] NET: Registered PF_NETLINK/PF_ROUTE protocol family
[    0.082263] DMA: preallocated 512 KiB GFP_KERNEL pool for atomic allocations
[    0.082596] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations
[    0.082963] DMA: preallocated 512 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations
[    0.083024] audit: initializing netlink subsys (disabled)
[    0.083231] audit: type=2000 audit(0.080:1): state=initialized audit_enabled=0 res=1
[    0.084590] thermal_sys: Registered thermal governor 'step_wise'
[    0.084601] thermal_sys: Registered thermal governor 'power_allocator'
[    0.085059] cpuidle: using governor menu
[    0.085323] hw-breakpoint: found 6 breakpoint and 4 watchpoint registers.
[    0.085548] ASID allocator initialised with 65536 entries
[    0.087654] Serial: AMBA PL011 UART driver
[    0.112299] OF: amba_device_add() failed (-19) for /dma-controller@ff6d0000
[    0.120186] OF: amba_device_add() failed (-19) for /dma-controller@ff6e0000
[    0.129468] platform ff770000.syscon:phy@f780: Fixing up cyclic dependency with fe330000.mmc
[    0.139210] rockchip-gpio ff720000.gpio0: probed /pinctrl/gpio0@ff720000
[    0.139915] rockchip-gpio ff730000.gpio1: probed /pinctrl/gpio1@ff730000
[    0.140528] rockchip-gpio ff780000.gpio2: probed /pinctrl/gpio2@ff780000
[    0.141199] rockchip-gpio ff788000.gpio3: probed /pinctrl/gpio3@ff788000
[    0.141794] rockchip-gpio ff790000.gpio4: probed /pinctrl/gpio4@ff790000
[    0.161758] HugeTLB registered 1.00 GiB page size, pre-allocated 0 pages
[    0.161774] HugeTLB registered 32.0 MiB page size, pre-allocated 0 pages
[    0.161782] HugeTLB registered 2.00 MiB page size, pre-allocated 0 pages
[    0.161790] HugeTLB registered 64.0 KiB page size, pre-allocated 0 pages
[    0.164343] cryptd: max_cpu_qlen set to 1000
[    0.168901] ACPI: Interpreter disabled.
[    0.172116] vcc12v_dcin_bkup: supplied by vcc12v_dcin
[    0.173027] iommu: Default domain type: Translated 
[    0.173036] iommu: DMA domain TLB invalidation policy: strict mode 
[    0.174891] vgaarb: loaded
[    0.175380] SCSI subsystem initialized
[    0.175594] libata version 3.00 loaded.
[    0.175823] usbcore: registered new interface driver usbfs
[    0.175865] usbcore: registered new interface driver hub
[    0.175906] usbcore: registered new device driver usb
[    0.177315] pps_core: LinuxPPS API ver. 1 registered
[    0.177323] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti <[email protected]>
[    0.177340] PTP clock support registered
[    0.177538] EDAC MC: Ver: 3.0.0
[    0.180113] FPGA manager framework
[    0.180229] Advanced Linux Sound Architecture Driver Initialized.
[    0.181298] clocksource: Switched to clocksource arch_sys_counter
[    0.250328] VFS: Disk quotas dquot_6.6.0
[    0.250411] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes)
[    0.250920] pnp: PnP ACPI: disabled
[    0.260567] NET: Registered PF_INET protocol family
[    0.260895] IP idents hash table entries: 65536 (order: 7, 524288 bytes, linear)
[    0.264518] tcp_listen_portaddr_hash hash table entries: 2048 (order: 3, 32768 bytes, linear)
[    0.264667] TCP established hash table entries: 32768 (order: 6, 262144 bytes, linear)
[    0.265019] TCP bind hash table entries: 32768 (order: 7, 524288 bytes, linear)
[    0.265707] TCP: Hash tables configured (established 32768 bind 32768)
[    0.266003] MPTCP token hash table entries: 4096 (order: 4, 98304 bytes, linear)
[    0.266109] UDP hash table entries: 2048 (order: 4, 65536 bytes, linear)
[    0.266249] UDP-Lite hash table entries: 2048 (order: 4, 65536 bytes, linear)
[    0.266500] NET: Registered PF_UNIX/PF_LOCAL protocol family
[    0.267142] RPC: Registered named UNIX socket transport module.
[    0.267152] RPC: Registered udp transport module.
[    0.267157] RPC: Registered tcp transport module.
[    0.267162] RPC: Registered tcp NFSv4.1 backchannel transport module.
[    0.267171] NET: Registered PF_XDP protocol family
[    0.267189] PCI: CLS 0 bytes, default 64
[    0.267599] Trying to unpack rootfs image as initramfs...
[    0.683132] Freeing initrd memory: 8644K
[    1.874839] hw perfevents: enabled with armv8_cortex_a53 PMU driver, 7 counters available
[    1.875260] hw perfevents: enabled with armv8_cortex_a72 PMU driver, 7 counters available
[    1.875762] kvm [1]: IPA Size Limit: 40 bits
[    1.877854] kvm [1]: vgic-v2@fff20000
[    1.877887] kvm [1]: GIC system register CPU interface enabled
[    1.878129] kvm [1]: vgic interrupt IRQ18
[    1.878396] kvm [1]: Hyp mode initialized successfully
[    1.884935] Initialise system trusted keyrings
[    1.885128] workingset: timestamp_bits=42 max_order=20 bucket_order=0
[    1.891427] zbud: loaded
[    1.892931] squashfs: version 4.0 (2009/01/31) Phillip Lougher
[    1.893638] NFS: Registering the id_resolver key type
[    1.893670] Key type id_resolver registered
[    1.893676] Key type id_legacy registered
[    1.893772] nfs4filelayout_init: NFSv4 File Layout Driver Registering...
[    1.893781] nfs4flexfilelayout_init: NFSv4 Flexfile Layout Driver Registering...
[    1.893955] 9p: Installing v9fs 9p2000 file system support
[    1.959317] Key type asymmetric registered
[    1.959328] Asymmetric key parser 'x509' registered
[    1.959413] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 244)
[    1.959611] io scheduler mq-deadline registered
[    1.959619] io scheduler kyber registered
[    1.969456] rockchip-usb2phy ff770000.syscon:usb2phy@e460: failed to create phy
[    1.991977] EINJ: ACPI disabled.
[    2.021383] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled
[    2.024107] printk: console [ttyS2] disabled
[    2.024184] ff1a0000.serial: ttyS2 at MMIO 0xff1a0000 (irq = 35, base_baud = 1500000) is a 16550A
[    2.024377] printk: console [ttyS2] enabled
[    2.024387] printk: bootconsole [uart8250] disabled
[    2.026672] SuperH (H)SCI(F) driver initialized
[    2.027589] msm_serial: driver initialized
[    2.030546] cacheinfo: Unable to detect cache hierarchy for CPU 0
[    2.038911] loop: module loaded
[    2.040350] megasas: 07.717.02.00-rc1
[    2.049636] tun: Universal TUN/TAP device driver, 1.6
[    2.051044] thunder_xcv, ver 1.0
[    2.051093] thunder_bgx, ver 1.0
[    2.051132] nicpf, ver 1.0
[    2.053272] hclge is initializing
[    2.053334] hns3: Hisilicon Ethernet Network Driver for Hip08 Family - version
[    2.053343] hns3: Copyright (c) 2017 Huawei Corporation.
[    2.053411] e1000: Intel(R) PRO/1000 Network Driver
[    2.053418] e1000: Copyright (c) 1999-2006 Intel Corporation.
[    2.053462] e1000e: Intel(R) PRO/1000 Network Driver
[    2.053467] e1000e: Copyright(c) 1999 - 2015 Intel Corporation.
[    2.053509] igb: Intel(R) Gigabit Ethernet Network Driver
[    2.053515] igb: Copyright (c) 2007-2014 Intel Corporation.
[    2.053557] igbvf: Intel(R) Gigabit Virtual Function Network Driver
[    2.053563] igbvf: Copyright (c) 2009 - 2012 Intel Corporation.
[    2.054130] sky2: driver version 1.30
[    2.055778] VFIO - User Level meta-driver version: 0.3
[    2.061229] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver
[    2.061262] ehci-pci: EHCI PCI platform driver
[    2.061344] ehci-platform: EHCI generic platform driver
[    2.061567] ehci-orion: EHCI orion driver
[    2.061740] ehci-exynos: EHCI Exynos driver
[    2.061898] ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver
[    2.061914] ohci-pci: OHCI PCI platform driver
[    2.061960] ohci-platform: OHCI generic platform driver
[    2.062150] ohci-exynos: OHCI Exynos driver
[    2.062928] usbcore: registered new interface driver usb-storage
[    2.067163] i2c_dev: i2c /dev entries driver
[    2.077573] dw_wdt ff848000.watchdog: No valid TOPs array specified
[    2.082212] sdhci: Secure Digital Host Controller Interface driver
[    2.082223] sdhci: Copyright(c) Pierre Ossman
[    2.083481] Synopsys Designware Multimedia Card Interface Driver
[    2.085280] sdhci-pltfm: SDHCI platform and OF driver helper
[    2.088881] ledtrig-cpu: registered to indicate activity on CPUs
[    2.090936] SMCCC: SOC_ID: ARCH_SOC_ID not implemented, skipping ....
[    2.091346] hid: raw HID events driver (C) Jiri Kosina
[    2.091917] usbcore: registered new interface driver usbhid
[    2.091925] usbhid: USB HID core driver
[    2.092250] ashmem: initialized
[    2.101089] drop_monitor: Initializing network drop monitor service
[    2.101838] NET: Registered PF_INET6 protocol family
[    2.110975] Segment Routing with IPv6
[    2.111034] In-situ OAM (IOAM) with IPv6
[    2.111127] NET: Registered PF_PACKET protocol family
[    2.111861] 9pnet: Installing 9P2000 support
[    2.111938] Key type dns_resolver registered
[    2.113234] Loading compiled-in X.509 certificates
[    2.113614] zswap: loaded using pool lzo/zbud
[    2.115991] Key type ._fscrypt registered
[    2.116006] Key type .fscrypt registered
[    2.116013] Key type fscrypt-provisioning registered
[    2.152277] vcc5v0_perdev: supplied by vcc12v_dcin_bkup
[    2.152935] vcc5v0_sys: supplied by vcc12v_dcin_bkup
[    2.153756] vcc5v0_usb: supplied by vcc5v0_perdev
[    2.164307] xhci-hcd xhci-hcd.0.auto: xHCI Host Controller
[    2.164342] xhci-hcd xhci-hcd.0.auto: new USB bus registered, assigned bus number 1
[    2.164516] xhci-hcd xhci-hcd.0.auto: hcc params 0x0220fe64 hci version 0x110 quirks 0x0000000002010010
[    2.164577] xhci-hcd xhci-hcd.0.auto: irq 56, io mem 0xfe900000
[    2.165815] hub 1-0:1.0: USB hub found
[    2.165866] hub 1-0:1.0: 1 port detected
[    2.166208] xhci-hcd xhci-hcd.0.auto: xHCI Host Controller
[    2.166226] xhci-hcd xhci-hcd.0.auto: new USB bus registered, assigned bus number 2
[    2.166244] xhci-hcd xhci-hcd.0.auto: Host supports USB 3.0 SuperSpeed
[    2.166321] usb usb2: We don't know the algorithms for LPM for this host, disabling LPM.
[    2.167090] hub 2-0:1.0: USB hub found
[    2.167142] hub 2-0:1.0: 1 port detected
[    2.168222] fan53555-regulator 0-0040: FAN53555 Option[8] Rev[1] Detected!
[    2.168916] vdd_cpu_b: supplied by vcc5v0_sys
[    2.176196] pcie_power: supplied by vcc5v0_perdev
[    2.187454] vcc3v3_sys_s3: supplied by vcc5v0_sys
[    2.190399] rk808 0-001b: chip id: 0x0
[    2.195590] rk808-regulator rk808-regulator: there is no dvs0 gpio
[    2.195625] rk808-regulator rk808-regulator: there is no dvs1 gpio
[    2.196116] DCDC_REG1: supplied by vcc5v0_sys
[    2.196641] vdd_cpu_l: supplied by vcc5v0_sys
[    2.196985] DCDC_REG3: supplied by vcc5v0_sys
[    2.197388] vcc1v8_sys_s3: supplied by vcc5v0_sys
[    2.198028] LDO_REG1: supplied by vcc5v0_sys
[    2.198379] LDO_REG2: supplied by vcc5v0_sys
[    2.198713] LDO_REG3: supplied by vcc5v0_sys
[    2.198957] vcc_sdio_s0: Bringing 3300000uV into 3000000-3000000uV
[    2.199491] vcc_sdio_s0: supplied by vcc5v0_sys
[    2.200513] LDO_REG5: supplied by vcc5v0_sys
[    2.200843] LDO_REG6: supplied by vcc5v0_sys
[    2.201195] LDO_REG7: supplied by vcc5v0_sys
[    2.201621] vcc3v0_s3: supplied by vcc5v0_sys
[    2.202450] SWITCH_REG1: supplied by vcc3v3_sys_s3
[    2.202640] SWITCH_REG2: supplied by vcc3v3_sys_s3
[    2.205334] cpufreq: cpufreq_online: CPU0: Running at unlisted initial frequency: 600000 KHz, changing to: 1416000 KHz
[    2.205448] cpu cpu0: EM: created perf domain
[    2.209679] cpufreq: cpufreq_online: CPU4: Running at unlisted initial frequency: 600000 KHz, changing to: 1800000 KHz
[    2.209735] cpu cpu4: EM: created perf domain
[    2.210878] avdd_0v9_s0: supplied by vcc1v8_sys_s3
[    2.211287] avdd_1v8_s0: supplied by vcc3v3_sys_s3
[    2.212357] vcc1v8_sys_s0: supplied by vcc1v8_sys_s3
[    2.212882] vcc3v0_sd: supplied by vcc3v3_sys_s3
[    2.213686] mmc1: CQHCI version 5.10
[    2.216982] dwmmc_rockchip fe320000.mmc: IDMAC supports 32-bit address mode.
[    2.217018] dwmmc_rockchip fe320000.mmc: Using internal DMA controller.
[    2.217027] dwmmc_rockchip fe320000.mmc: Version ID is 270a
[    2.217086] dwmmc_rockchip fe320000.mmc: DW MMC controller at irq 32,32 bit host data width,256 deep fifo
[    2.217549] dwmmc_rockchip fe320000.mmc: Got CD GPIO
[    2.230622] mmc_host mmc0: Bus speed (slot 0) = 400000Hz (slot req 400000Hz, actual 400000HZ div = 0)
[    2.239848] mmc1: SDHCI controller on fe330000.mmc [fe330000.mmc] using ADMA
[    2.242345] ALSA device list:
[    2.242356]   No soundcards found.
[    2.242538] dw-apb-uart ff1a0000.serial: forbid DMA for kernel console
[    2.250443] Freeing unused kernel memory: 10368K
[    2.257423] Run /init as init process
[    2.257427]   with arguments:
[    2.257430]     /init
[    2.257433]     earlyprintk
[    2.257436]   with environment:
[    2.257438]     HOME=/
[    2.257440]     TERM=linux
[    2.295924] random: fast init done
[    2.311580] mmc_host mmc0: Bus speed (slot 0) = 50000000Hz (slot req 50000000Hz, actual 50000000HZ div = 0)
[    2.311687] mmc0: new high speed SDHC card at address aaaa
[    2.312501] mmcblk0: mmc0:aaaa SC32G 29.7 GiB 
[    2.313136] mmc1: Command Queue Engine enabled
[    2.313154] mmc1: new HS200 MMC card at address 0001
[    2.313630] mmcblk1: mmc1:0001 AJTD4R 14.6 GiB 
[    2.315059] mmcblk1boot0: mmc1:0001 AJTD4R 4.00 MiB 
[    2.315772] mmcblk1boot1: mmc1:0001 AJTD4R 4.00 MiB 
[    2.316368] mmcblk1rpmb: mmc1:0001 AJTD4R 4.00 MiB, chardev (511:0)
[    2.320521]  mmcblk0: p1
[    2.347179] stage-1-init: [Thu Jan  1 00:00:02 UTC 1970] loading module dm_mod...
[    2.364005] device-mapper: ioctl: 4.45.0-ioctl (2021-03-22) initialised: [email protected]
[    2.368308] stage-1-init: [Thu Jan  1 00:00:02 UTC 1970] running udev...
[    2.407127] stage-1-init: [Thu Jan  1 00:00:02 UTC 1970] Starting version 249.7
[    2.429485] usb 1-1: new high-speed USB device number 2 using xhci-hcd
[    2.614732] hub 1-1:1.0: USB hub found
[    2.614858] hub 1-1:1.0: 4 ports detected
[    2.624147] stage-1-init: [Thu Jan  1 00:00:02 UTC 1970] kbd_mode: KDSKBMODE: Inappropriate ioctl for device
[    2.628858] stage-1-init: [Thu Jan  1 00:00:02 UTC 1970] starting device mapper and LVM...
[    2.633087] random: lvm: uninitialized urandom read (4 bytes read)
[    3.401540] usb 1-1.2: new high-speed USB device number 3 using xhci-hcd
[    3.553509] usb-storage 1-1.2:1.0: USB Mass Storage device detected
[    3.554572] scsi host0: usb-storage 1-1.2:1.0
[    3.559370] usbcore: registered new interface driver uas
[    3.729625] random: lvm: uninitialized urandom read (4 bytes read)
[    3.749753] usb 2-1: new SuperSpeed USB device number 2 using xhci-hcd
[    3.831088] hub 2-1:1.0: USB hub found
[    3.831444] hub 2-1:1.0: 4 ports detected
[    4.473656] usb 2-1.4: new SuperSpeed USB device number 3 using xhci-hcd
[    4.579314] scsi 0:0:0:0: Direct-Access     Mass     Storage Device   1.00 PQ: 0 ANSI: 0 CCS
[    4.581320] sd 0:0:0:0: [sda] 62333952 512-byte logical blocks: (31.9 GB/29.7 GiB)
[    4.581684] sd 0:0:0:0: [sda] Write Protect is off
[    4.581689] sd 0:0:0:0: [sda] Mode Sense: 03 00 00 00
[    4.581833] sd 0:0:0:0: [sda] No Caching mode page found
[    4.587776] sd 0:0:0:0: [sda] Assuming drive cache: write through
[    4.599766]  sda: sda1 sda2
[    4.601136] sd 0:0:0:0: [sda] Attached SCSI removable disk
[    4.919649] random: lvm: uninitialized urandom read (4 bytes read)
[    5.140681] stage-1-init: [Thu Jan  1 00:00:05 UTC 1970] waiting for device /dev/disk/by-uuid/44444444-4444-4444-8888-888888888888 to appear....
[    5.536570] stage-1-init: [Thu Jan  1 00:00:05 UTC 1970] checking /dev/disk/by-uuid/44444444-4444-4444-8888-888888888888...
[    5.539869] stage-1-init: [Thu Jan  1 00:00:05 UTC 1970] fsck (busybox 1.34.1)
[    5.543464] stage-1-init: [Thu Jan  1 00:00:05 UTC 1970] [fsck.ext4 (1) -- /mnt-root/] fsck.ext4 -a /dev/disk/by-uuid/44444444-4444-4444-8888-888888888888
[    5.567550] stage-1-init: [Thu Jan  1 00:00:05 UTC 1970] NIXOS_SD: clean, 705113/1892576 files, 4393578/7782016 blocks
[    5.588400] stage-1-init: [Thu Jan  1 00:00:05 UTC 1970] mounting /dev/disk/by-uuid/44444444-4444-4444-8888-888888888888 on /...
[    5.624404] EXT4-fs (sda2): mounted filesystem with ordered data mode. Opts: (null). Quota mode: none.
[    7.062184] EXT4-fs (sda2): re-mounted. Opts: (null). Quota mode: none.
[    7.076781] booting system configuration /nix/store/sbphzfc1flkcfhxh5jk3z7a4hkj3da32-nixos-system-s0-22.05.20220316.ed32ed9
[    7.534264] random: crng init done
[    7.584735] stage-2-init: running activation script...
[    9.291373] stage-2-init: setting up /etc...
[   12.389839] systemd[1]: System time before build time, advancing clock.
[   12.725129] systemd[1]: systemd 249.7 running in system mode (+PAM +AUDIT -SELINUX +APPARMOR +IMA +SMACK +SECCOMP +GCRYPT -GNUTLS +OPENSSL +ACL +BLKID +CURL +ELFUTILS +FIDO2 +IDN2 -IDN +IPTC +KMOD +LIBCRYPTSETUP +LIBFDISK +PCRE2 -PWQUALITY -P11KIT -QRENCODE +BZIP2 +LZ4 +XZ +ZLIB +ZSTD -XKBCOMMON +UTMP -SYSVINIT default-hierarchy=unified)
[   12.725877] systemd[1]: Detected architecture arm64.
[   14.077377] systemd[1]: Queued start job for default target Multi-User System.
[   14.083572] systemd[1]: Created slice Slice /system/getty.
[   14.104102] systemd[1]: Created slice Slice /system/modprobe.
[   14.124271] systemd[1]: Created slice Slice /system/serial-getty.
[   14.143953] systemd[1]: Created slice User and Session Slice.
[   14.162138] systemd[1]: Started Dispatch Password Requests to Console Directory Watch.
[   14.178102] systemd[1]: Started Forward Password Requests to Wall Directory Watch.
[   14.193989] systemd[1]: Reached target Local Encrypted Volumes.
[   14.209865] systemd[1]: Reached target Containers.
[   14.221982] systemd[1]: Reached target Path Units.
[   14.233863] systemd[1]: Reached target Remote File Systems.
[   14.249825] systemd[1]: Reached target Slice Units.
[   14.261917] systemd[1]: Reached target Swaps.
[   14.280324] systemd[1]: Listening on Process Core Dump Socket.
[   14.298617] systemd[1]: Listening on Journal Audit Socket.
[   14.314425] systemd[1]: Listening on Journal Socket (/dev/log).
[   14.330468] systemd[1]: Listening on Journal Socket.
[   14.362301] systemd[1]: Listening on udev Control Socket.
[   14.378365] systemd[1]: Listening on udev Kernel Socket.
[   14.398400] systemd[1]: Mounting Huge Pages File System...
[   14.414296] systemd[1]: Mounting POSIX Message Queue File System...
[   14.434007] systemd[1]: Mounting Kernel Debug File System...
[   14.450544] systemd[1]: Starting Create List of Static Device Nodes...
[   14.470806] systemd[1]: Starting Load Kernel Module configfs...
[   14.486482] systemd[1]: Starting Load Kernel Module drm...
[   14.502492] systemd[1]: Starting Load Kernel Module fuse...
[   14.517780] systemd[1]: Starting mount-pstore.service...
[   14.529830] systemd[1]: Condition check resulted in File System Check on Root Device being skipped.
[   14.536094] systemd[1]: Starting Journal Service...
[   14.551038] systemd[1]: Starting Load Kernel Modules...
[   14.566379] systemd[1]: Starting Remount Root and Kernel File Systems...
[   14.586665] systemd[1]: Starting Coldplug All udev Devices...
[   14.604420] fuse: init (API version 7.34)
[   14.607806] systemd[1]: Mounted Huge Pages File System.
[   14.626192] systemd[1]: Mounted POSIX Message Queue File System.
[   14.642141] systemd[1]: Mounted Kernel Debug File System.
[   14.659304] systemd[1]: Finished Create List of Static Device Nodes.
[   14.677865] audit: type=1130 audit(315532802.284:2): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=kmod-static-nodes comm="systemd" exe="/nix/store/41cdskfcpijjqbrpqdz645vvsda4065i-systemd-249.7/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
[   14.679158] systemd[1]: [email protected]: Deactivated successfully.
[   14.680319] systemd[1]: Finished Load Kernel Module configfs.
[   14.697711] audit: type=1130 audit(315532802.304:3): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=modprobe@configfs comm="systemd" exe="/nix/store/41cdskfcpijjqbrpqdz645vvsda4065i-systemd-249.7/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
[   14.697739] audit: type=1131 audit(315532802.304:4): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=modprobe@configfs comm="systemd" exe="/nix/store/41cdskfcpijjqbrpqdz645vvsda4065i-systemd-249.7/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
[   14.698925] systemd[1]: [email protected]: Deactivated successfully.
[   14.699992] systemd[1]: Finished Load Kernel Module drm.
[   14.717665] audit: type=1130 audit(315532802.324:5): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=modprobe@drm comm="systemd" exe="/nix/store/41cdskfcpijjqbrpqdz645vvsda4065i-systemd-249.7/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
[   14.717697] audit: type=1131 audit(315532802.324:6): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=modprobe@drm comm="systemd" exe="/nix/store/41cdskfcpijjqbrpqdz645vvsda4065i-systemd-249.7/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
[   14.718295] systemd[1]: Started Journal Service.
[   14.729871] audit: type=1130 audit(315532802.336:7): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=systemd-journald comm="systemd" exe="/nix/store/41cdskfcpijjqbrpqdz645vvsda4065i-systemd-249.7/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
[   14.749670] audit: type=1130 audit(315532802.356:8): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=modprobe@fuse comm="systemd" exe="/nix/store/41cdskfcpijjqbrpqdz645vvsda4065i-systemd-249.7/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
[   14.749701] audit: type=1131 audit(315532802.356:9): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=modprobe@fuse comm="systemd" exe="/nix/store/41cdskfcpijjqbrpqdz645vvsda4065i-systemd-249.7/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
[   14.756359] audit: type=1334 audit(315532802.360:10): prog-id=44 op=LOAD
[   14.756641] audit: type=1334 audit(315532802.360:11): prog-id=45 op=LOAD
[   14.786269] bridge: filtering via arp/ip/ip6tables is no longer available by default. Update your scripts to load br_netfilter if you need this.
[   14.889115] EXT4-fs (sda2): re-mounted. Opts: (null). Quota mode: none.
[   14.992607] systemd-journald[575]: Received client request to flush runtime journal.
[   15.008683] systemd-journald[575]: File /var/log/journal/b4f83ba55e1940fc9a6e7545518890d6/system.journal corrupted or uncleanly shut down, renaming and replacing.
[   16.726855] lm75 2-004c: supply vs not found, using dummy regulator
[   16.729498] hwmon hwmon4: temp1_input not attached to any thermal zone
[   16.729512] lm75 2-004c: hwmon4: sensor 'lm75'
[   16.917566] rockchip-pcie f8000000.pcie: host bridge /pcie@f8000000 ranges:
[   16.917637] rockchip-pcie f8000000.pcie:      MEM 0x00fa000000..0x00fbdfffff -> 0x00fa000000
[   16.917653] rockchip-pcie f8000000.pcie:       IO 0x00fbe00000..0x00fbefffff -> 0x00fbe00000
[   16.920498] mc: Linux media interface: v0.10
[   16.933714] rk808-rtc rk808-rtc: registered as rtc0
[   16.934281] rk808-rtc rk808-rtc: setting system clock to 2022-03-16T18:54:49 UTC (1647456889)
[   16.990280] videodev: Linux video capture interface: v2.00
[   16.990887] rk_gmac-dwmac fe300000.ethernet: IRQ eth_wake_irq not found
[   16.990911] rk_gmac-dwmac fe300000.ethernet: IRQ eth_lpi not found
[   16.991024] rk_gmac-dwmac fe300000.ethernet: PTP uses main clock
[   16.991349] rk_gmac-dwmac fe300000.ethernet: clock input or output? (input).
[   16.991363] rk_gmac-dwmac fe300000.ethernet: TX delay(0x28).
[   16.991371] rk_gmac-dwmac fe300000.ethernet: RX delay(0x20).
[   16.991520] rk_gmac-dwmac fe300000.ethernet: integrated PHY? (no).
[   16.991600] rk_gmac-dwmac fe300000.ethernet: cannot get clock clk_mac_speed
[   16.999645] rk_gmac-dwmac fe300000.ethernet: clock input from PHY
[   17.004688] rk_gmac-dwmac fe300000.ethernet: init for RGMII
[   17.015529] rk_gmac-dwmac fe300000.ethernet: User ID: 0x10, Synopsys ID: 0x35
[   17.015546] rk_gmac-dwmac fe300000.ethernet:         DWMAC1000
[   17.015551] rk_gmac-dwmac fe300000.ethernet: DMA HW capability register supported
[   17.015554] rk_gmac-dwmac fe300000.ethernet: RX Checksum Offload Engine supported
[   17.015558] rk_gmac-dwmac fe300000.ethernet: COE Type 2
[   17.015561] rk_gmac-dwmac fe300000.ethernet: TX Checksum insertion supported
[   17.015564] rk_gmac-dwmac fe300000.ethernet: Wake-Up On Lan supported
[   17.015650] rk_gmac-dwmac fe300000.ethernet: Normal descriptors
[   17.015654] rk_gmac-dwmac fe300000.ethernet: Ring mode enabled
[   17.015657] rk_gmac-dwmac fe300000.ethernet: Enable RX Mitigation via HW Watchdog Timer
[   17.059785] rockchip-pcie f8000000.pcie: PCI host bridge to bus 0000:00
[   17.059799] pci_bus 0000:00: root bus resource [bus 00-1f]
[   17.059804] pci_bus 0000:00: root bus resource [mem 0xfa000000-0xfbdfffff]
[   17.059809] pci_bus 0000:00: root bus resource [io  0x0000-0xfffff] (bus address [0xfbe00000-0xfbefffff])
[   17.059846] pci 0000:00:00.0: [1d87:0100] type 01 class 0x060400
[   17.059934] pci 0000:00:00.0: supports D1
[   17.059938] pci 0000:00:00.0: PME# supported from D0 D1 D3hot
[   17.064631] pci 0000:00:00.0: bridge configuration invalid ([bus 00-00]), reconfiguring
[   17.064944] pci 0000:01:00.0: [197b:0585] type 00 class 0x010601
[   17.065013] pci 0000:01:00.0: reg 0x10: initial BAR value 0x00000000 invalid
[   17.065020] pci 0000:01:00.0: reg 0x10: [io  size 0x0080]
[   17.065053] pci 0000:01:00.0: reg 0x14: initial BAR value 0x00000000 invalid
[   17.065059] pci 0000:01:00.0: reg 0x14: [io  size 0x0080]
[   17.065091] pci 0000:01:00.0: reg 0x18: initial BAR value 0x00000000 invalid
[   17.065097] pci 0000:01:00.0: reg 0x18: [io  size 0x0080]
[   17.065128] pci 0000:01:00.0: reg 0x1c: initial BAR value 0x00000000 invalid
[   17.065134] pci 0000:01:00.0: reg 0x1c: [io  size 0x0080]
[   17.065166] pci 0000:01:00.0: reg 0x20: initial BAR value 0x00000000 invalid
[   17.065172] pci 0000:01:00.0: reg 0x20: [io  size 0x0080]
[   17.065203] pci 0000:01:00.0: reg 0x24: [mem 0x00000000-0x00001fff]
[   17.065235] pci 0000:01:00.0: reg 0x30: [mem 0x00000000-0x0000ffff pref]
[   17.065271] pci 0000:01:00.0: Max Payload Size set to 256 (was 128, max 512)
[   17.065638] pci 0000:01:00.0: PME# supported from D3hot
[   17.065868] pci 0000:01:00.0: 4.000 Gb/s available PCIe bandwidth, limited by 2.5 GT/s PCIe x2 link at 0000:00:00.0 (capable of 15.752 Gb/s with 8.0 GT/s PCIe x2 link)
[   17.077032] pci_bus 0000:01: busn_res: [bus 01-1f] end is updated to 01
[   17.077093] pci 0000:00:00.0: BAR 14: assigned [mem 0xfa000000-0xfa0fffff]
[   17.077109] pci 0000:01:00.0: BAR 6: assigned [mem 0xfa000000-0xfa00ffff pref]
[   17.077118] pci 0000:01:00.0: BAR 5: assigned [mem 0xfa010000-0xfa011fff]
[   17.077139] pci 0000:01:00.0: BAR 0: no space for [io  size 0x0080]
[   17.077146] pci 0000:01:00.0: BAR 0: failed to assign [io  size 0x0080]
[   17.077153] pci 0000:01:00.0: BAR 1: no space for [io  size 0x0080]
[   17.077159] pci 0000:01:00.0: BAR 1: failed to assign [io  size 0x0080]
[   17.077165] pci 0000:01:00.0: BAR 2: no space for [io  size 0x0080]
[   17.077172] pci 0000:01:00.0: BAR 2: failed to assign [io  size 0x0080]
[   17.077179] pci 0000:01:00.0: BAR 3: no space for [io  size 0x0080]
[   17.077185] pci 0000:01:00.0: BAR 3: failed to assign [io  size 0x0080]
[   17.077191] pci 0000:01:00.0: BAR 4: no space for [io  size 0x0080]
[   17.077197] pci 0000:01:00.0: BAR 4: failed to assign [io  size 0x0080]
[   17.077205] pci 0000:00:00.0: PCI bridge to [bus 01]
[   17.077215] pci 0000:00:00.0:   bridge window [mem 0xfa000000-0xfa0fffff]
[   17.081633] rockchip-drm display-subsystem: [drm:rockchip_drm_platform_probe [rockchipdrm]] *ERROR* No available vop found for display-subsystem.
[   17.090684] pcieport 0000:00:00.0: enabling device (0000 -> 0002)
[   17.101811] pcieport 0000:00:00.0: PME: Signaling with IRQ 69
[   17.102264] ahci 0000:01:00.0: version 3.0
[   17.102307] ahci 0000:01:00.0: enabling device (0000 -> 0002)
[   17.102905] ahci 0000:01:00.0: SSS flag set, parallel bus scan disabled
[   17.103023] ahci 0000:01:00.0: AHCI 0001.0301 32 slots 5 ports 6 Gbps 0x1f impl SATA mode
[   17.103034] ahci 0000:01:00.0: flags: 64bit ncq sntf stag pm led clo pmp fbs pio slum part ccc apst boh 
[   17.109595] scsi host1: ahci
[   17.114482] scsi host2: ahci
[   17.125027] scsi host3: ahci
[   17.145665] scsi host4: ahci
[   17.146406] scsi host5: ahci
[   17.156061] ata1: SATA max UDMA/133 abar m8192@0xfa010000 port 0xfa010100 irq 70
[   17.156090] ata2: SATA max UDMA/133 abar m8192@0xfa010000 port 0xfa010180 irq 71
[   17.156099] ata3: SATA max UDMA/133 abar m8192@0xfa010000 port 0xfa010200 irq 72
[   17.156108] ata4: SATA max UDMA/133 abar m8192@0xfa010000 port 0xfa010280 irq 73
[   17.156116] ata5: SATA max UDMA/133 abar m8192@0xfa010000 port 0xfa010300 irq 74
[   17.207777] RTL8211F Gigabit Ethernet stmmac-0:00: attached PHY driver (mii_bus:phy_addr=stmmac-0:00, irq=POLL)
[   17.207809] RTL8211F Gigabit Ethernet stmmac-0:01: attached PHY driver (mii_bus:phy_addr=stmmac-0:01, irq=POLL)
[   17.633356] ata1: SATA link up 6.0 Gbps (SStatus 133 SControl 300)
[   17.650098] ata1.00: ATA-10: ST4000VN008-2DR166, SC60, max UDMA/133
[   17.650509] ata1.00: 7814037168 sectors, multi 0: LBA48 NCQ (depth 32), AA
[   17.650608] ata1.00: Features: NCQ-sndrcv
[   17.652007] ata1.00: configured for UDMA/133
[   17.652369] scsi 1:0:0:0: Direct-Access     ATA      ST4000VN008-2DR1 SC60 PQ: 0 ANSI: 5
[   17.653425] sd 1:0:0:0: [sdb] 7814037168 512-byte logical blocks: (4.00 TB/3.64 TiB)
[   17.653440] sd 1:0:0:0: [sdb] 4096-byte physical blocks
[   17.653483] sd 1:0:0:0: [sdb] Write Protect is off
[   17.653493] sd 1:0:0:0: [sdb] Mode Sense: 00 3a 00 00
[   17.653563] sd 1:0:0:0: [sdb] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
[   17.705234]  sdb: sdb1
[   17.706236] sd 1:0:0:0: [sdb] Attached SCSI disk
[   18.129356] ata2: SATA link up 6.0 Gbps (SStatus 133 SControl 300)
[   18.136102] ata2.00: ATA-10: ST4000VN008-2DR166, SC60, max UDMA/133
[   18.136512] ata2.00: 7814037168 sectors, multi 0: LBA48 NCQ (depth 32), AA
[   18.136606] ata2.00: Features: NCQ-sndrcv
[   18.138037] ata2.00: configured for UDMA/133
[   18.138511] scsi 2:0:0:0: Direct-Access     ATA      ST4000VN008-2DR1 SC60 PQ: 0 ANSI: 5
[   18.139891] sd 2:0:0:0: [sdc] 7814037168 512-byte logical blocks: (4.00 TB/3.64 TiB)
[   18.139917] sd 2:0:0:0: [sdc] 4096-byte physical blocks
[   18.139958] sd 2:0:0:0: [sdc] Write Protect is off
[   18.139967] sd 2:0:0:0: [sdc] Mode Sense: 00 3a 00 00
[   18.140033] sd 2:0:0:0: [sdc] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
[   18.202731]  sdc: sdc1
[   18.203567] sd 2:0:0:0: [sdc] Attached SCSI disk
[   18.621378] ata3: SATA link up 6.0 Gbps (SStatus 133 SControl 300)
[   18.622716] ata3.00: ATA-10: ST4000VN008-2DR166, SC60, max UDMA/133
[   18.623108] ata3.00: 7814037168 sectors, multi 0: LBA48 NCQ (depth 32), AA
[   18.623206] ata3.00: Features: NCQ-sndrcv
[   18.624643] ata3.00: configured for UDMA/133
[   18.624984] scsi 3:0:0:0: Direct-Access     ATA      ST4000VN008-2DR1 SC60 PQ: 0 ANSI: 5
[   18.626510] sd 3:0:0:0: [sdd] 7814037168 512-byte logical blocks: (4.00 TB/3.64 TiB)
[   18.626537] sd 3:0:0:0: [sdd] 4096-byte physical blocks
[   18.626589] sd 3:0:0:0: [sdd] Write Protect is off
[   18.626599] sd 3:0:0:0: [sdd] Mode Sense: 00 3a 00 00
[   18.626677] sd 3:0:0:0: [sdd] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
[   18.896158]  sdd: sdd1
[   18.896925] sd 3:0:0:0: [sdd] Attached SCSI disk
[   19.101331] ata4: SATA link up 6.0 Gbps (SStatus 133 SControl 300)
[   19.102640] ata4.00: ATA-10: ST4000VN008-2DR166, SC60, max UDMA/133
[   19.103040] ata4.00: 7814037168 sectors, multi 0: LBA48 NCQ (depth 32), AA
[   19.103137] ata4.00: Features: NCQ-sndrcv
[   19.104506] ata4.00: configured for UDMA/133
[   19.104874] scsi 4:0:0:0: Direct-Access     ATA      ST4000VN008-2DR1 SC60 PQ: 0 ANSI: 5
[   19.106292] sd 4:0:0:0: [sde] 7814037168 512-byte logical blocks: (4.00 TB/3.64 TiB)
[   19.106312] sd 4:0:0:0: [sde] 4096-byte physical blocks
[   19.106418] sd 4:0:0:0: [sde] Write Protect is off
[   19.106428] sd 4:0:0:0: [sde] Mode Sense: 00 3a 00 00
[   19.106508] sd 4:0:0:0: [sde] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
[   19.371412]  sde: sde1
[   19.372392] sd 4:0:0:0: [sde] Attached SCSI disk
[   19.581393] ata5: SATA link up 6.0 Gbps (SStatus 133 SControl 300)
[   19.586595] ata5.00: ATA-10: ST4000VN008-2DR166, SC60, max UDMA/133
[   19.587563] ata5.00: 7814037168 sectors, multi 0: LBA48 NCQ (depth 32), AA
[   19.587742] ata5.00: Features: NCQ-sndrcv
[   19.589949] ata5.00: configured for UDMA/133
[   19.590441] scsi 5:0:0:0: Direct-Access     ATA      ST4000VN008-2DR1 SC60 PQ: 0 ANSI: 5
[   19.591682] sd 5:0:0:0: [sdf] 7814037168 512-byte logical blocks: (4.00 TB/3.64 TiB)
[   19.591706] sd 5:0:0:0: [sdf] 4096-byte physical blocks
[   19.591751] sd 5:0:0:0: [sdf] Write Protect is off
[   19.591761] sd 5:0:0:0: [sdf] Mode Sense: 00 3a 00 00
[   19.591832] sd 5:0:0:0: [sdf] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
[   19.844632]  sdf: sdf1
[   19.846052] sd 5:0:0:0: [sdf] Attached SCSI disk
[   19.910124] usbcore: registered new interface driver cdc_ether
[   19.952930] 8021q: 802.1Q VLAN Support v1.8
[   19.965760] cdc_ncm 2-1.4:2.0: MAC-Address: 64:62:66:d0:02:ef
[   19.965772] cdc_ncm 2-1.4:2.0: setting rx_max = 16384
[   19.965826] cdc_ncm 2-1.4:2.0: setting tx_max = 16384
[   19.966240] cdc_ncm 2-1.4:2.0 eth1: register 'cdc_ncm' at usb-xhci-hcd.0.auto-1.4, CDC NCM, 64:62:66:d0:02:ef
[   19.966343] usbcore: registered new interface driver cdc_ncm
[   20.002665] rockchip-rga ff680000.rga: HW Version: 0x03.02
[   20.002768] rockchip-rga: probe of ff680000.rga failed with error -12
[   20.023703] rockchip_vdec: module is from the staging directory, the quality is unknown, you have been warned.
[   20.024810] rkvdec ff660000.video-codec: Adding to iommu group 1
[   20.063103] hantro_vpu: module is from the staging directory, the quality is unknown, you have been warned.
[   20.066440] hantro-vpu ff650000.video-codec: Adding to iommu group 0
[   20.067114] hantro-vpu ff650000.video-codec: registered rockchip,rk3399-vpu-enc as /dev/video1
[   20.067261] hantro-vpu ff650000.video-codec: registered rockchip,rk3399-vpu-dec as /dev/video2
[   20.075532] usbcore: registered new interface driver cdc_wdm
[   20.143530] usbcore: registered new interface driver cdc_mbim
[   20.222690] cfg80211: Loading compiled-in X.509 certificates for regulatory database
[   20.231635] cfg80211: Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7'
[   20.585330] rk_gmac-dwmac fe300000.ethernet eth0: PHY [stmmac-0:00] driver [RTL8211F Gigabit Ethernet] (irq=POLL)
[   20.586679] rk_gmac-dwmac fe300000.ethernet eth0: Register MEM_TYPE_PAGE_POOL RxQ-0
[   20.597328] rk_gmac-dwmac fe300000.ethernet eth0: No Safety Features support found
[   20.597349] rk_gmac-dwmac fe300000.ethernet eth0: PTP not supported by HW
[   20.597746] rk_gmac-dwmac fe300000.ethernet eth0: configuring for phy/rgmii link mode
[   20.758382] IPv6: ADDRCONF(NETDEV_CHANGE): eth1: link becomes ready
[   23.867181] fbcon: Taking over console
[   24.706924] rk_gmac-dwmac fe300000.ethernet eth0: Link is Up - 1Gbps/Full - flow control rx/tx
[   24.706983] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
[   28.837645] usb 2-1.3: new SuperSpeed USB device number 4 using xhci-hcd
[   28.865996] scsi host6: uas
[   28.867200] scsi 6:0:0:0: Direct-Access     TO Exter nal USB 3.0      0203 PQ: 0 ANSI: 6
[   28.870037] sd 6:0:0:0: [sdg] 976773168 512-byte logical blocks: (500 GB/466 GiB)
[   28.870062] sd 6:0:0:0: [sdg] 4096-byte physical blocks
[   28.870251] sd 6:0:0:0: [sdg] Write Protect is off
[   28.870259] sd 6:0:0:0: [sdg] Mode Sense: 53 00 00 08
[   28.870617] sd 6:0:0:0: [sdg] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
[   28.870964] sd 6:0:0:0: [sdg] Optimal transfer size 33553920 bytes not a multiple of physical block size (4096 bytes)
[   28.876365]  sdg: sdg1 sdg2 sdg3
[   28.878655] sd 6:0:0:0: [sdg] Attached SCSI disk
[  113.510775] raid6: neonx8   gen()  2531 MB/s
[  113.578767] raid6: neonx8   xor()  1860 MB/s
[  113.646765] raid6: neonx4   gen()  2568 MB/s
[  113.714757] raid6: neonx4   xor()  1864 MB/s
[  113.782762] raid6: neonx2   gen()  2455 MB/s
[  113.850750] raid6: neonx2   xor()  1736 MB/s
[  113.918749] raid6: neonx1   gen()  2131 MB/s
[  113.986742] raid6: neonx1   xor()  1464 MB/s
[  114.054738] raid6: int64x8  gen()  1751 MB/s
[  114.122745] raid6: int64x8  xor()   922 MB/s
[  114.190738] raid6: int64x4  gen()  1906 MB/s
[  114.258726] raid6: int64x4  xor()   980 MB/s
[  114.326737] raid6: int64x2  gen()  1661 MB/s
[  114.394720] raid6: int64x2  xor()   859 MB/s
[  114.462723] raid6: int64x1  gen()  1242 MB/s
[  114.530713] raid6: int64x1  xor()   658 MB/s
[  114.530732] raid6: using algorithm neonx4 gen() 2568 MB/s
[  114.530737] raid6: .... xor() 1864 MB/s, rmw enabled
[  114.530741] raid6: using neon recovery algorithm
[  114.554431] xor: measuring software checksum speed
[  114.555792]    8regs           :  7590 MB/sec
[  114.556921]    32regs          :  8742 MB/sec
[  114.558206]    arm64_neon      :  7678 MB/sec
[  114.558208] xor: using function: 32regs (8742 MB/sec)
[  114.729864] Unable to handle kernel paging request at virtual address fffffe00002f7ac0
[  114.738752] Mem abort info:
[  114.741866]   ESR = 0x96000004
[  114.745281]   EC = 0x25: DABT (current EL), IL = 32 bits
[  114.751219]   SET = 0, FnV = 0
[  114.754624]   EA = 0, S1PTW = 0
[  114.758128]   FSC = 0x04: level 0 translation fault
[  114.763577] Data abort info:
[  114.766792]   ISV = 0, ISS = 0x00000004
[  114.771075]   CM = 0, WnR = 0
[  114.774382] swapper pgtable: 4k pages, 48-bit VAs, pgdp=0000000003f7d000
[  114.781871] [fffffe00002f7ac0] pgd=0000000000000000, p4d=0000000000000000
[  114.789465] Internal error: Oops: 96000004 [#1] SMP
[  114.794903] Modules linked in: poly1305_generic libpoly1305 poly1305_neon chacha_generic chacha_neon libchacha bcachefs crc64 lz4_compress xor xor_neon zstd_compress raid6_pq cfg80211 cdc_mbim cdc_wdm hantro_vpu(C) rfkill rockchip_vdec(C) rockchip_rga 8021q cdc_ncm cdc_ether videobuf2_vmalloc garp v4l2_h264 mrp usbnet videobuf2_dma_contig v4l2_mem2mem videobuf2_dma_sg videobuf2_memops rockchipdrm videobuf2_v4l2 videobuf2_common crct10dif_ce dwmac_rk videodev dw_mipi_dsi stmmac_platform analogix_dp dw_hdmi mc cec stmmac rtc_rk808 phy_rockchip_pcie pcs_xpcs pcie_rockchip_host drm_kms_helper lm75 pwm_fan uio_pdrv_genirq rockchip_thermal uio ip6_tables xt_conntrack nf_conntrack nf_defrag_ipv6 nf_defrag_ipv4 ip6t_rpfilter ipt_rpfilter xt_pkttype xt_LOG nf_log_syslog xt_tcpudp nft_compat nft_counter nf_tables libcrc32c nfnetlink sch_fq_codel tap macvlan bridge stp llc drm fuse ip_tables x_tables uas dm_mod
[  114.884195] CPU: 4 PID: 1885 Comm: mount Tainted: G         C        5.15.28 #1-NixOS
[  114.892944] Hardware name: Kobol Helios64 (DT)
[  114.897902] pstate: 60000005 (nZCv daif -PAN -UAO -TCO -DIT -SSBS BTYPE=--)
[  114.905680] pc : flush_dcache_page+0x8/0x48
[  114.910353] lr : skcipher_walk_done+0x160/0x2c0
[  114.915414] sp : ffff80000bdeb320
[  114.919109] x29: ffff80000bdeb320 x28: 0000000000000000 x27: ffff8000019c6e88
[  114.927083] x26: ffff8000019ab060 x25: ffff80000bdeb830 x24: ffff80000ac1c000
[  114.935056] x23: ffff000004509d00 x22: 0000000000000028 x21: 0000000000000000
[  114.943029] x20: 0000000000000000 x19: ffff80000bdeb390 x18: 0000000000000000
[  114.951003] x17: 000000040044ffff x16: 00400034b5503510 x15: 0000000000000028
[  114.958975] x14: 0000000000000001 x13: 4502afdcbfa1cef6 x12: c354f96074840efd
[  114.966948] x11: 7e60788a8dfc7e14 x10: cd3c48f96bccefcc x9 : ffff800008614ba0
[  114.974920] x8 : 7e60788a8dfc7e14 x7 : cd3c48f96bccefcc x6 : 79656b2a2a686362
[  114.982892] x5 : ffff80000bdeb858 x4 : ffff80000bdeb330 x3 : 0000000000000001
[  114.990864] x2 : 0000000000000000 x1 : 0000000000000858 x0 : fffffe00002f7ac0
[  114.998837] Call trace:
[  115.001563]  flush_dcache_page+0x8/0x48
[  115.005834]  chacha_neon_stream_xor+0x110/0x1b8 [chacha_neon]
[  115.012258]  chacha_neon+0x24/0x30 [chacha_neon]
[  115.017414]  crypto_skcipher_encrypt+0x2c/0x40
[  115.022374]  do_encrypt_sg+0x50/0xa8 [bcachefs]
[  115.027490]  bch2_chacha_encrypt_key+0xa0/0x130 [bcachefs]
[  115.033667]  bch2_decrypt_sb_key+0xac/0x150 [bcachefs]
[  115.039456]  bch2_fs_encryption_init+0xe8/0x178 [bcachefs]
[  115.045632]  bch2_fs_open+0xc00/0x1318 [bcachefs]
[  115.050936]  bch2_mount+0x484/0x630 [bcachefs]
[  115.055945]  legacy_get_tree+0x38/0x68
[  115.060130]  vfs_get_tree+0x30/0xf8
[  115.064022]  path_mount+0x3d4/0xa98
[  115.067914]  do_mount+0xa0/0xb8
[  115.071416]  __arm64_sys_mount+0x114/0x2c0
[  115.075987]  invoke_syscall+0x4c/0x110
[  115.080172]  el0_svc_common.constprop.0+0x4c/0xf8
[  115.085424]  do_el0_svc+0x2c/0x90
[  115.089122]  el0_svc+0x20/0x60
[  115.092530]  el0t_64_sync_handler+0xb0/0xb8
[  115.097199]  el0t_64_sync+0x1a0/0x1a4
[  115.101288] Code: 35ffffa1 17ffffec aa1e03e9 d503201f (f9400001) 
[  115.108093] ---[ end trace 9acc69b638fa1888 ]---

GoogleBot42 avatar Mar 17 '22 00:03 GoogleBot42

On Wed, Mar 16, 2022 at 05:12:11PM -0700, Googlebot wrote:

Not sure if this is actually an issue with bcachefs since support for the NAS I'm running on is very new in Linux.

I can create single/multi disk file systems + mount and use them just fine. But if I add encryption even with a simple bcachefs format --encrypted /dev/sda mounting later fails.

The logs. In this example, a brand new formatted filesystem is used and is about to be mounted for the first time. I did use multiple disks but I get a very similar error with only just one and no extra options. At 113.510775 is when the system is mounted.

Let me know if more info will help.

[  114.781871] [fffffe00002f7ac0] pgd=0000000000000000, p4d=0000000000000000
[  114.789465] Internal error: Oops: 96000004 [#1] SMP
[  114.794903] Modules linked in: poly1305_generic libpoly1305 poly1305_neon chacha_generic chacha_neon libchacha bcachefs crc64 lz4_compress xor xor_neon zstd_compress raid6_pq cfg80211 cdc_mbim cdc_wdm hantro_vpu(C) rfkill rockchip_vdec(C) rockchip_rga 8021q cdc_ncm cdc_ether videobuf2_vmalloc garp v4l2_h264 mrp usbnet videobuf2_dma_contig v4l2_mem2mem videobuf2_dma_sg videobuf2_memops rockchipdrm videobuf2_v4l2 videobuf2_common crct10dif_ce dwmac_rk videodev dw_mipi_dsi stmmac_platform analogix_dp dw_hdmi mc cec stmmac rtc_rk808 phy_rockchip_pcie pcs_xpcs pcie_rockchip_host drm_kms_helper lm75 pwm_fan uio_pdrv_genirq rockchip_thermal uio ip6_tables xt_conntrack nf_conntrack nf_defrag_ipv6 nf_defrag_ipv4 ip6t_rpfilter ipt_rpfilter xt_pkttype xt_LOG nf_log_syslog xt_tcpudp nft_compat nft_counter nf_tables libcrc32c nfnetlink sch_fq_codel tap macvlan bridge stp llc drm fuse ip_tables x_tables uas dm_mod
[  114.884195] CPU: 4 PID: 1885 Comm: mount Tainted: G         C        5.15.28 #1-NixOS
[  114.892944] Hardware name: Kobol Helios64 (DT)
[  114.897902] pstate: 60000005 (nZCv daif -PAN -UAO -TCO -DIT -SSBS BTYPE=--)
[  114.905680] pc : flush_dcache_page+0x8/0x48
[  114.910353] lr : skcipher_walk_done+0x160/0x2c0
[  114.915414] sp : ffff80000bdeb320
[  114.919109] x29: ffff80000bdeb320 x28: 0000000000000000 x27: ffff8000019c6e88
[  114.927083] x26: ffff8000019ab060 x25: ffff80000bdeb830 x24: ffff80000ac1c000
[  114.935056] x23: ffff000004509d00 x22: 0000000000000028 x21: 0000000000000000
[  114.943029] x20: 0000000000000000 x19: ffff80000bdeb390 x18: 0000000000000000
[  114.951003] x17: 000000040044ffff x16: 00400034b5503510 x15: 0000000000000028
[  114.958975] x14: 0000000000000001 x13: 4502afdcbfa1cef6 x12: c354f96074840efd
[  114.966948] x11: 7e60788a8dfc7e14 x10: cd3c48f96bccefcc x9 : ffff800008614ba0
[  114.974920] x8 : 7e60788a8dfc7e14 x7 : cd3c48f96bccefcc x6 : 79656b2a2a686362
[  114.982892] x5 : ffff80000bdeb858 x4 : ffff80000bdeb330 x3 : 0000000000000001
[  114.990864] x2 : 0000000000000000 x1 : 0000000000000858 x0 : fffffe00002f7ac0
[  114.998837] Call trace:
[  115.001563]  flush_dcache_page+0x8/0x48
[  115.005834]  chacha_neon_stream_xor+0x110/0x1b8 [chacha_neon]
[  115.012258]  chacha_neon+0x24/0x30 [chacha_neon]
[  115.017414]  crypto_skcipher_encrypt+0x2c/0x40
[  115.022374]  do_encrypt_sg+0x50/0xa8 [bcachefs]
[  115.027490]  bch2_chacha_encrypt_key+0xa0/0x130 [bcachefs]
[  115.033667]  bch2_decrypt_sb_key+0xac/0x150 [bcachefs]
[  115.039456]  bch2_fs_encryption_init+0xe8/0x178 [bcachefs]
[  115.045632]  bch2_fs_open+0xc00/0x1318 [bcachefs]
[  115.050936]  bch2_mount+0x484/0x630 [bcachefs]
[  115.055945]  legacy_get_tree+0x38/0x68
[  115.060130]  vfs_get_tree+0x30/0xf8
[  115.064022]  path_mount+0x3d4/0xa98
[  115.067914]  do_mount+0xa0/0xb8
[  115.071416]  __arm64_sys_mount+0x114/0x2c0
[  115.075987]  invoke_syscall+0x4c/0x110
[  115.080172]  el0_svc_common.constprop.0+0x4c/0xf8
[  115.085424]  do_el0_svc+0x2c/0x90
[  115.089122]  el0_svc+0x20/0x60
[  115.092530]  el0t_64_sync_handler+0xb0/0xb8
[  115.097199]  el0t_64_sync+0x1a0/0x1a4
[  115.101288] Code: 35ffffa1 17ffffec aa1e03e9 d503201f (f9400001) 
[  115.108093] ---[ end trace 9acc69b638fa1888 ]---

Hey, thanks for the bug report.

This looks like something specific to the crypto code. I'd try it without the accelerated version chacha20 - if it works with the simple/slow C version, then that'll tell you who to bug :)

koverstreet avatar Mar 17 '22 00:03 koverstreet

Ok, how do I disable the accelerated crypto? Is there a flag in format?

GoogleBot42 avatar Mar 17 '22 01:03 GoogleBot42

On Wed, Mar 16, 2022 at 06:11:18PM -0700, Googlebot wrote:

Ok, how do I disable the accelerated crypto? Is there a flag in format?

It'll be in your kernel config

koverstreet avatar Mar 17 '22 03:03 koverstreet