Re: sun50i-a64-pinctrl WARN_ON drivers/base/dd.c:349

From: Adam Borowski
Date: Sat Apr 29 2017 - 17:34:32 EST


On Fri, Apr 28, 2017 at 06:03:14PM -0400, Tejun Heo wrote:
> On Tue, Apr 18, 2017 at 10:12:16AM +0100, Andre Przywara wrote:
> > Yeah, so I stack-dumped on the zero allocations and indeed they are
> > called from cleanup functions:
> > drivers/pinctrl/pinmux.c:pinmux_generic_free_functions():
> > devm_kzalloc(sizeof(*indices) * pctldev->num_functions, ...)
> > (and another one I don't know from the top of the my head, logs at home)
> >
> > So my hunch was that once EPROBE_DEFER triggers the devres cleanup, it
> > uses some reverse list traversal to release all allocated resources
> > (backwards!), so missing those which get (appended) during the process.
> > But I don't think that would not work with the locking.
> > So I have to dig deeper tonight in my logs.
>
> If this is a valid use case, we can change devm to repeat till empty
> but it's a weird thing to do to allocate from a release function.
>
> So, something like this. Only compile tested.

I've tested this, and the results are mixed. It _does_ make the WARN go
away, but on the other hand, much later during the boot, another driver
(sun8i-emac) gets deferred and never undefers.

Without the patch, there's:
[ ok ] Synthesizing the initial hotplug events...done.
[ 6.666984] bus: 'platform': driver_probe_device: matched device 1c30000.ethernet with driver sun8i-emac
[ 6.676520] bus: 'platform': really_probe: probing driver sun8i-emac with device 1c30000.ethernet
[ 6.686479] driver: 'sun8i-emac': driver_bound: bound to device '1c30000.ethernet'
[....] [ 6.694132] bus: 'platform': really_probe: bound device 1c30000.ethernet to driver sun8i-emac
[ ok ng for /dev to be fully populated...done.
<snip>
[....] Configuring network interfaces...[ 11.414884] libphy: 1c30000.ethernet: probed
[ 11.449742] bus: 'mdio_bus': driver_probe_device: matched device 1c30000.ethernet-0:00 with driver RTL8211E Gigabit Ethernet
[ 11.461013] bus: 'mdio_bus': really_probe: probing driver RTL8211E Gigabit Ethernet with device 1c30000.ethernet-0:00
[ 11.471666] driver: 'RTL8211E Gigabit Ethernet': driver_bound: bound to device '1c30000.ethernet-0:00'
[ 11.481007] bus: 'mdio_bus': really_probe: bound device 1c30000.ethernet-0:00 to driver RTL8211E Gigabit Ethernet
[ 11.491527] RTL8211E Gigabit Ethernet 1c30000.ethernet-0:00: attached PHY driver [RTL8211E Gigabit Ethernet] (mii_bus:phy_addr=1c30000.ethernet-0:00, irq=-1)
[ 11.505608] sun8i-emac 1c30000.ethernet: device MAC address slot 0 02:ba:8f:9e:44:8f

With the patch:
[ ok ] Synthesizing the initial hotplug events...done.
[....] Waiting for /dev to be fully populated...[ 6.325314] bus: 'platform': driver_probe_device: matched device 1c30000.ethernet with driver sun8i-emac
[ 6.334842] bus: 'platform': really_probe: probing driver sun8i-emac with device 1c30000.ethernet
[ 6.344253] platform 1c30000.ethernet: Driver sun8i-emac requests probe deferral
[ 6.351662] platform 1c30000.ethernet: Added to deferred list
done.
<snip>
[....] Configuring network interfaces...Cannot find device "eth0"
ifup: failed to bring up eth0
failed.


There's a concern, though, that this second driver is not in mainline (and
won't ever be -- it's being replaced by dwmac-sun8i, but the latter is not
yet up to scratch), thus I'm not sure how relevant this is.

The second concern is that I'm using the same tree
(icenowy/sunxi64-4.11-rc7) and config (plus filesystems) as Icenowy, on the
same hardware, yet I did see this warning in versions much earlier than her,
and it doesn't go away in -next for me either. All that differs are
toolchain versions (I'm on Debian unstable) and perhaps some u-boot bits.

Because of the amount of churn in sunxi land and the driver's mainlining
status, I think it'd be good to wait after the merge window that starts
tomorrow, and re-test then.

Full console output with the patch applied attached.


Meow!


> diff --git a/drivers/base/devres.c b/drivers/base/devres.c
> index 71d5770..d2a9f34 100644
> --- a/drivers/base/devres.c
> +++ b/drivers/base/devres.c
> @@ -509,13 +509,21 @@ static int release_nodes(struct device *dev, struct list_head *first,
> int devres_release_all(struct device *dev)
> {
> unsigned long flags;
> + int cnt = 0, ret;
>
> /* Looks like an uninitialized device structure */
> if (WARN_ON(dev->devres_head.next == NULL))
> return -ENODEV;
> - spin_lock_irqsave(&dev->devres_lock, flags);
> - return release_nodes(dev, dev->devres_head.next, &dev->devres_head,
> - flags);
> +
> + /* Release callbacks may create new nodes, repeat till empty */
> + do {
> + spin_lock_irqsave(&dev->devres_lock, flags);
> + ret = release_nodes(dev, dev->devres_head.next,
> + &dev->devres_head, flags);
> + cnt += ret;
> + } while (ret);
> +
> + return cnt;
> }
>
> /**
>

--
Don't be racist. White, amber or black, all beers should be judged based
solely on their merits. Heck, even if occasionally a cider applies for a
beer's job, why not?
On the other hand, corpo lager is not a race.
INFO: PSCI Affinity Map:
INFO: AffInst: Level 0, MPID 0x0, State ON
INFO: AffInst: Level 0, MPID 0x1, State ON
INFO: AffInst: Level 0, MPID 0x2, State ON
INFO: AffInst: Level 0, MPID 0x3, State ON
HELLO! BOOT0 is starting!
boot0 commit : 045061a8bb2580cb3fa02e301f52a015040c158f

boot0 version : 4.0.0
set pll start
set pll end
rtc[0] value = 0x00000000
rtc[1] value = 0x00000000
rtc[2] value = 0x00000000
rtc[3] value = 0x00000000
rtc[4] value = 0x00000000
rtc[5] value = 0x00000000
DRAM driver version: V1.1
rsb_send_initseq: rsb clk 400Khz -> 3Mhz
PMU: AXP81X
ddr voltage = 1500 mv
DRAM Type = 3 (2:DDR2,3:DDR3,6:LPDDR2,7:LPDDR3)
DRAM clk = 672 MHz
DRAM zq value: 003b3bbb
DRAM single rank full DQ OK
DRAM size = 2048 MB
DRAM init ok
dram size =2048
card boot number = 0, boot0 copy = 0
card no is 0
sdcard 0 line count 4
[mmc]: mmc driver ver 2015-05-08 20:06
[mmc]: sdc0 spd mode error, 2
[mmc]: Wrong media type 0x00000000
[mmc]: ***Try SD card 0***
[mmc]: HSSDR52/SDR25 4 bit
[mmc]: 50000000 Hz
[mmc]: 14804 MB
[mmc]: ***SD/MMC 0 init OK!!!***
sdcard 0 init ok
The size of uboot is 0006c000.
sum=19037d2d
src_sum=19037d2d
Succeed in loading uboot from sdmmc flash.
boot0: start load other image
boot0: Loading BL3-1
Loading file 0 at address 0x40000000,size 0x00000200 success
boot0: Loading scp
Loading file 2 at address 0x00040000,size 0x0000b200 success
set arisc reset to de-assert state
Ready to disable icache.
Jump to secend Boot.
NOTICE: BL3-1: Running on A64/H64 (1689) in SRAM A2 (@0x44000)
NOTICE: Configuring SPC Controller
NOTICE: BL3-1: v1.0(debug):aa75c8da
NOTICE: BL3-1: Built : 01:57:26, Mar 21 2017
NOTICE: Configuring AXP PMIC
NOTICE: PMIC: already configured for RSB
NOTICE: PMIC: setup successful
INFO: BL3-1: Initializing runtime services
INFO: BL3-1: Preparing for EL3 exit to normal world
INFO: BL3-1: Next image address: 0x4a000000, SPSR: 0x3c9


U-Boot 2017.03-00203-gd5abcf94c7 (Mar 22 2017 - 00:45:58 +0100) Allwinner Technology

CPU: Allwinner A64 (SUN50I)
Model: Pine64+
DRAM: 2 GiB
MMC: SUNXI SD/MMC: 0
*** Warning - bad CRC, using default environment

In: serial
Out: serial
Err: serial
Net: phy interface7
eth0: ethernet@01c30000
starting USB...
USB0: USB EHCI 1.00
USB1: USB OHCI 1.0
scanning bus 0 for devices... 1 USB Device(s) found
scanning usb for storage devices... 0 Storage Device(s) found
Hit any key to stop autoboot: 0
switch to partitions #0, OK
mmc0 is current device
Scanning mmc 0:1...
Found U-Boot script /boot.scr.uimg
295 bytes read in 40 ms (6.8 KiB/s)
## Executing script at 4fc00000
13224448 bytes read in 57346 ms (224.6 KiB/s)
11552 bytes read in 277 ms (40 KiB/s)
## Flattened Device Tree blob at 4fa00000
Booting using the fdt blob at 0x4fa00000
Loading Device Tree to 0000000049ffa000, end 0000000049fffd1f ... OK

Starting kernel ...

[ 0.000000] Booting Linux on physical CPU 0x0
[ 0.000000] Linux version 4.11.0-rc7-iceconfig-00064-gf4aec3d9ff13 (kilobyte@sirius) (gcc version 6.3.0 20170415 (Debian 6.3.0-14) ) #1 SMP PREEMPT Sat Apr 29 01:29:37 CEST 2017
[ 0.000000] Boot CPU: AArch64 Processor [410fd034]
[ 0.000000] earlycon: uart0 at MMIO32 0x0000000001c28000 (options '')
[ 0.000000] bootconsole [uart0] enabled
[ 0.000000] efi: Getting EFI parameters from FDT:
[ 0.000000] efi: UEFI not found.
[ 0.000000] cma: Reserved 16 MiB at 0x00000000bf000000
[ 0.000000] On node 0 totalpages: 524288
[ 0.000000] DMA zone: 8192 pages used for memmap
[ 0.000000] DMA zone: 0 pages reserved
[ 0.000000] DMA zone: 524288 pages, LIFO batch:31
[ 0.000000] psci: probing for conduit method from DT.
[ 0.000000] psci: PSCIv0.2 detected in firmware.
[ 0.000000] psci: Using standard PSCI v0.2 function IDs
[ 0.000000] psci: Trusted OS migration not required
[ 0.000000] percpu: Embedded 23 pages/cpu @ffff80007ef86000 s56472 r8192 d29544 u94208
[ 0.000000] pcpu-alloc: s56472 r8192 d29544 u94208 alloc=23*4096
[ 0.000000] pcpu-alloc: [0] 0 [0] 1 [0] 2 [0] 3
[ 0.000000] Detected VIPT I-cache on CPU0
[ 0.000000] CPU features: enabling workaround for ARM erratum 845719
[ 0.000000] Built 1 zonelists in Zone order, mobility grouping on. Total pages: 516096
[ 0.000000] Kernel command line: console=ttyS0,115200n8 ro root=/dev/mmcblk0p5 rootwait earlycon=uart,mmio32,0x01c28000 loglevel=8
[ 0.000000] log_buf_len individual max cpu contribution: 4096 bytes
[ 0.000000] log_buf_len total cpu_extra contributions: 12288 bytes
[ 0.000000] log_buf_len min size: 16384 bytes
[ 0.000000] log_buf_len: 32768 bytes
[ 0.000000] early log buf free: 14636(89%)
[ 0.000000] PID hash table entries: 4096 (order: 3, 32768 bytes)
[ 0.000000] Dentry cache hash table entries: 262144 (order: 9, 2097152 bytes)
[ 0.000000] Inode-cache hash table entries: 131072 (order: 8, 1048576 bytes)
[ 0.000000] Memory: 2031132K/2097152K available (8764K kernel code, 562K rwdata, 2968K rodata, 576K init, 298K bss, 49636K reserved, 16384K cma-reserved)
[ 0.000000] Virtual kernel memory layout:
[ 0.000000] modules : 0xffff000000000000 - 0xffff000008000000 ( 128 MB)
[ 0.000000] vmalloc : 0xffff000008000000 - 0xffff7dffbfff0000 (129022 GB)
[ 0.000000] .text : 0xffff000008080000 - 0xffff000008910000 ( 8768 KB)
[ 0.000000] .rodata : 0xffff000008910000 - 0xffff000008c00000 ( 3008 KB)
[ 0.000000] .init : 0xffff000008c00000 - 0xffff000008c90000 ( 576 KB)
[ 0.000000] .data : 0xffff000008c90000 - 0xffff000008d1ca00 ( 563 KB)
[ 0.000000] .bss : 0xffff000008d1ca00 - 0xffff000008d672cc ( 299 KB)
[ 0.000000] fixed : 0xffff7dfffe7fd000 - 0xffff7dfffec00000 ( 4108 KB)
[ 0.000000] PCI I/O : 0xffff7dfffee00000 - 0xffff7dffffe00000 ( 16 MB)
[ 0.000000] vmemmap : 0xffff7e0000000000 - 0xffff800000000000 ( 2048 GB maximum)
[ 0.000000] 0xffff7e0000000000 - 0xffff7e0002000000 ( 32 MB actual)
[ 0.000000] memory : 0xffff800000000000 - 0xffff800080000000 ( 2048 MB)
[ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1
[ 0.000000] Preemptible hierarchical RCU implementation.
[ 0.000000] Build-time adjustment of leaf fanout to 64.
[ 0.000000] RCU restricting CPUs from NR_CPUS=64 to nr_cpu_ids=4.
[ 0.000000] RCU: Adjusting geometry for rcu_fanout_leaf=64, nr_cpu_ids=4
[ 0.000000] NR_IRQS:64 nr_irqs:64 0
[ 0.000000] GIC: Using split EOI/Deactivate mode
[ 0.000000] arm_arch_timer: Architected 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.000004] sched_clock: 56 bits at 24MHz, resolution 41ns, wraps every 4398046511097ns
[ 0.008247] Console: colour dummy device 80x25
[ 0.012708] Calibrating delay loop (skipped), value calculated using timer frequency.. 48.00 BogoMIPS (lpj=96000)
[ 0.022963] pid_max: default: 32768 minimum: 301
[ 0.027649] Security Framework initialized
[ 0.031784] Mount-cache hash table entries: 4096 (order: 3, 32768 bytes)
[ 0.038482] Mountpoint-cache hash table entries: 4096 (order: 3, 32768 bytes)
[ 0.061690] ASID allocator initialised with 65536 entries
[ 0.075226] EFI services will not be available.
[ 0.095802] smp: Bringing up secondary CPUs ...
[ 0.133579] Detected VIPT I-cache on CPU1
[ 0.133631] CPU1: Booted secondary processor [410fd034]
[ 0.165002] Detected VIPT I-cache on CPU2
[ 0.165034] CPU2: Booted secondary processor [410fd034]
[ 0.197048] Detected VIPT I-cache on CPU3
[ 0.197077] CPU3: Booted secondary processor [410fd034]
[ 0.197131] smp: Brought up 1 node, 4 CPUs
[ 0.228879] SMP: Total of 4 processors activated.
[ 0.233583] CPU features: detected feature: 32-bit EL0 Support
[ 0.239456] CPU: All CPU(s) started at EL2
[ 0.243567] alternatives: patching kernel code
[ 0.249116] devtmpfs: initialized
[ 0.254982] DMI not present or invalid.
[ 0.259008] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645041785100000 ns
[ 0.268752] futex hash table entries: 1024 (order: 5, 131072 bytes)
[ 0.275673] xor: measuring software checksum speed
[ 0.320517] 8regs : 1566.000 MB/sec
[ 0.364744] 8regs_prefetch: 1396.000 MB/sec
[ 0.409318] 32regs : 1855.000 MB/sec
[ 0.453543] 32regs_prefetch: 1618.000 MB/sec
[ 0.458158] xor: using function: 32regs (1855.000 MB/sec)
[ 0.463558] pinctrl core: initialized pinctrl subsystem
[ 0.469171] bus: 'platform': driver_probe_device: matched device reg-dummy with driver reg-dummy
[ 0.477963] bus: 'platform': really_probe: probing driver reg-dummy with device reg-dummy
[ 0.486267] driver: 'reg-dummy': driver_bound: bound to device 'reg-dummy'
[ 0.493143] bus: 'platform': really_probe: bound device reg-dummy to driver reg-dummy
[ 0.501480] NET: Registered protocol family 16
[ 0.506973] cpuidle: using governor menu
[ 0.511217] vdso: 2 pages (1 code @ ffff000008917000, 1 data @ ffff000008c95000)
[ 0.518621] hw-breakpoint: found 6 breakpoint and 4 watchpoint registers.
[ 0.526423] DMA: preallocated 256 KiB pool for atomic allocations
[ 0.532658] Serial: AMBA PL011 UART driver
[ 0.548501] HugeTLB registered 2 MB page size, pre-allocated 0 pages
[ 0.622364] raid6: int64x1 gen() 284 MB/s
[ 0.694296] raid6: int64x1 xor() 298 MB/s
[ 0.766349] raid6: int64x2 gen() 448 MB/s
[ 0.838417] raid6: int64x2 xor() 401 MB/s
[ 0.910473] raid6: int64x4 gen() 667 MB/s
[ 0.982521] raid6: int64x4 xor() 512 MB/s
[ 1.054656] raid6: int64x8 gen() 749 MB/s
[ 1.126675] raid6: int64x8 xor() 495 MB/s
[ 1.198756] raid6: neonx1 gen() 490 MB/s
[ 1.270847] raid6: neonx1 xor() 515 MB/s
[ 1.342928] raid6: neonx2 gen() 793 MB/s
[ 1.414965] raid6: neonx2 xor() 700 MB/s
[ 1.487048] raid6: neonx4 gen() 1023 MB/s
[ 1.559109] raid6: neonx4 xor() 802 MB/s
[ 1.631189] raid6: neonx8 gen() 1078 MB/s
[ 1.703247] raid6: neonx8 xor() 832 MB/s
[ 1.707516] raid6: using algorithm neonx8 gen() 1078 MB/s
[ 1.712908] raid6: .... xor() 832 MB/s, rmw enabled
[ 1.717781] raid6: using intx1 recovery algorithm
[ 1.723149] bus: 'platform': driver_probe_device: matched device vcc3v3 with driver reg-fixed-voltage
[ 1.732377] bus: 'platform': really_probe: probing driver reg-fixed-voltage with device vcc3v3
[ 1.741186] driver: 'reg-fixed-voltage': driver_bound: bound to device 'vcc3v3'
[ 1.748496] bus: 'platform': really_probe: bound device vcc3v3 to driver reg-fixed-voltage
[ 1.757221] SCSI subsystem initialized
[ 1.761137] libata version 3.00 loaded.
[ 1.765275] usbcore: registered new interface driver usbfs
[ 1.770810] usbcore: registered new interface driver hub
[ 1.776204] usbcore: registered new device driver usb
[ 1.781515] pps_core: LinuxPPS API ver. 1 registered
[ 1.786485] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti <giometti@xxxxxxxx>
[ 1.795628] PTP clock support registered
[ 1.799707] dmi: Firmware registration failed.
[ 1.804290] Advanced Linux Sound Architecture Driver Initialized.
[ 1.811143] clocksource: Switched to clocksource arch_sys_counter
[ 1.817384] VFS: Disk quotas dquot_6.6.0
[ 1.821371] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes)
[ 1.835376] NET: Registered protocol family 2
[ 1.840222] TCP established hash table entries: 16384 (order: 5, 131072 bytes)
[ 1.847603] TCP bind hash table entries: 16384 (order: 6, 262144 bytes)
[ 1.854544] TCP: Hash tables configured (established 16384 bind 16384)
[ 1.861202] UDP hash table entries: 1024 (order: 3, 32768 bytes)
[ 1.867263] UDP-Lite hash table entries: 1024 (order: 3, 32768 bytes)
[ 1.873892] NET: Registered protocol family 1
[ 1.878583] RPC: Registered named UNIX socket transport module.
[ 1.884512] RPC: Registered udp transport module.
[ 1.889228] RPC: Registered tcp transport module.
[ 1.893933] RPC: Registered tcp NFSv4.1 backchannel transport module.
[ 1.901079] kvm [1]: 8-bit VMID
[ 1.904233] kvm [1]: IDMAP page: 408f7000
[ 1.908246] kvm [1]: HYP VA range: 800000000000:ffffffffffff
[ 1.914468] kvm [1]: Hyp mode initialized successfully
[ 1.919646] kvm [1]: vgic-v2@1c84000
[ 1.923310] kvm [1]: vgic interrupt IRQ1
[ 1.927250] kvm [1]: virtual timer IRQ5
[ 1.932870] bus: 'platform': driver_probe_device: matched device alarmtimer with driver alarmtimer
[ 1.941854] bus: 'platform': really_probe: probing driver alarmtimer with device alarmtimer
[ 1.950223] driver: 'alarmtimer': driver_bound: bound to device 'alarmtimer'
[ 1.957275] bus: 'platform': really_probe: bound device alarmtimer to driver alarmtimer
[ 1.965663] audit: initializing netlink subsys (disabled)
[ 1.971197] audit: type=2000 audit(1.896:1): state=initialized audit_enabled=0 res=1
[ 1.971440] workingset: timestamp_bits=46 max_order=19 bucket_order=0
[ 1.978729] squashfs: version 4.0 (2009/01/31) Phillip Lougher
[ 1.979461] NFS: Registering the id_resolver key type
[ 1.979486] Key type id_resolver registered
[ 1.979489] Key type id_legacy registered
[ 1.979498] nfs4filelayout_init: NFSv4 File Layout Driver Registering...
[ 1.979669] SGI XFS with ACLs, security attributes, no debug enabled
[ 1.980851] 9p: Installing v9fs 9p2000 file system support
[ 1.983779] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 248)
[ 1.983787] io scheduler noop registered
[ 1.983910] io scheduler cfq registered (default)
[ 1.983913] io scheduler mq-deadline registered
[ 1.985655] bus: 'platform': driver_probe_device: matched device 1c19400.phy with driver sun4i-usb-phy
[ 1.985667] bus: 'platform': really_probe: probing driver sun4i-usb-phy with device 1c19400.phy
[ 1.985936] sun4i-usb-phy 1c19400.phy: failed to get clock usb0_phy
[ 1.986044] platform 1c19400.phy: Driver sun4i-usb-phy requests probe deferral
[ 1.986049] platform 1c19400.phy: Added to deferred list
[ 1.986350] bus: 'platform': driver_probe_device: matched device 1c20800.pinctrl with driver sun50i-a64-pinctrl
[ 1.986358] bus: 'platform': really_probe: probing driver sun50i-a64-pinctrl with device 1c20800.pinctrl
[ 1.987654] platform 1c20800.pinctrl: Driver sun50i-a64-pinctrl requests probe deferral
[ 1.987659] platform 1c20800.pinctrl: Added to deferred list
[ 1.987750] bus: 'platform': driver_probe_device: matched device 1f02c00.pinctrl with driver sun50i-a64-r-pinctrl
[ 1.987758] bus: 'platform': really_probe: probing driver sun50i-a64-r-pinctrl with device 1f02c00.pinctrl
[ 1.988820] sun50i-a64-r-pinctrl 1f02c00.pinctrl: initialized sunXi PIO driver
[ 1.988825] driver: 'sun50i-a64-r-pinctrl': driver_bound: bound to device '1f02c00.pinctrl'
[ 1.988831] bus: 'platform': really_probe: bound device 1f02c00.pinctrl to driver sun50i-a64-r-pinctrl
[ 1.989831] bus: 'platform': driver_probe_device: matched device 1c20000.clock with driver sun50i-a64-ccu
[ 1.989840] bus: 'platform': really_probe: probing driver sun50i-a64-ccu with device 1c20000.clock
[ 1.990872] driver: 'sun50i-a64-ccu': driver_bound: bound to device '1c20000.clock'
[ 1.990879] bus: 'platform': really_probe: bound device 1c20000.clock to driver sun50i-a64-ccu
[ 1.991377] xenfs: not registering filesystem on non-xen platform
[ 1.994455] Serial: 8250/16550 driver, 4 ports, IRQ sharing disabled
[ 1.995214] bus: 'platform': driver_probe_device: matched device serial8250 with driver serial8250
[ 1.995223] bus: 'platform': really_probe: probing driver serial8250 with device serial8250
[ 1.995250] driver: 'serial8250': driver_bound: bound to device 'serial8250'
[ 1.995255] bus: 'platform': really_probe: bound device serial8250 to driver serial8250
[ 1.995323] bus: 'platform': driver_probe_device: matched device 1c28000.serial with driver dw-apb-uart
[ 1.995329] bus: 'platform': really_probe: probing driver dw-apb-uart with device 1c28000.serial
[ 1.995357] dw-apb-uart 1c28000.serial: could not find pctldev for node /soc/pinctrl@1c20800/uart0@0, deferring probe
[ 1.995369] platform 1c28000.serial: Driver dw-apb-uart requests probe deferral
[ 1.995374] platform 1c28000.serial: Added to deferred list
[ 1.995819] cacheinfo: Unable to detect cache hierarchy for CPU 0
[ 2.002493] loop: module loaded
[ 2.003003] hisi_sas: driver version v1.6
[ 2.004214] libphy: Fixed MDIO Bus: probed
[ 2.004669] tun: Universal TUN/TAP device driver, 1.6
[ 2.005467] VFIO - User Level meta-driver version: 0.3
[ 2.005515] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver
[ 2.005518] ehci-platform: EHCI generic platform driver
[ 2.005554] bus: 'platform': driver_probe_device: matched device 1c1b000.usb with driver ehci-platform
[ 2.005564] bus: 'platform': really_probe: probing driver ehci-platform with device 1c1b000.usb
[ 2.005673] platform 1c1b000.usb: Driver ehci-platform requests probe deferral
[ 2.005678] platform 1c1b000.usb: Added to deferred list
[ 2.005727] ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver
[ 2.005744] ohci-platform: OHCI generic platform driver
[ 2.005772] bus: 'platform': driver_probe_device: matched device 1c1b400.usb with driver ohci-platform
[ 2.005777] bus: 'platform': really_probe: probing driver ohci-platform with device 1c1b400.usb
[ 2.005829] platform 1c1b400.usb: Driver ohci-platform requests probe deferral
[ 2.005834] platform 1c1b400.usb: Added to deferred list
[ 2.006052] usbcore: registered new interface driver uas
[ 2.006101] usbcore: registered new interface driver usb-storage
[ 2.006133] usbcore: registered new interface driver ums-alauda
[ 2.006168] usbcore: registered new interface driver ums-cypress
[ 2.006210] usbcore: registered new interface driver ums-datafab
[ 2.006245] usbcore: registered new interface driver ums_eneub6250
[ 2.006286] usbcore: registered new interface driver ums-freecom
[ 2.006319] usbcore: registered new interface driver ums-isd200
[ 2.006353] usbcore: registered new interface driver ums-jumpshot
[ 2.006391] usbcore: registered new interface driver ums-karma
[ 2.006427] usbcore: registered new interface driver ums-onetouch
[ 2.006470] usbcore: registered new interface driver ums-realtek
[ 2.006506] usbcore: registered new interface driver ums-sddr09
[ 2.006542] usbcore: registered new interface driver ums-sddr55
[ 2.006582] usbcore: registered new interface driver ums-usbat
[ 2.006682] usbcore: registered new interface driver usbserial
[ 2.006720] usbcore: registered new interface driver ftdi_sio
[ 2.006755] usbserial: USB Serial support registered for FTDI USB Serial Device
[ 2.006792] usbcore: registered new interface driver pl2303
[ 2.006822] usbserial: USB Serial support registered for pl2303
[ 2.007006] bus: 'platform': driver_probe_device: matched device 1c19000.usb with driver musb-sunxi
[ 2.007015] bus: 'platform': really_probe: probing driver musb-sunxi with device 1c19000.usb
[ 2.007095] platform 1c19000.usb: Driver musb-sunxi requests probe deferral
[ 2.007100] platform 1c19000.usb: Added to deferred list
[ 2.008128] mousedev: PS/2 mouse device common for all mice
[ 2.008408] usbcore: registered new interface driver synaptics_usb
[ 2.008789] bus: 'platform': driver_probe_device: matched device 1f00000.rtc with driver sun6i-rtc
[ 2.008798] bus: 'platform': really_probe: probing driver sun6i-rtc with device 1f00000.rtc
[ 2.009056] sun6i-rtc 1f00000.rtc: rtc core: registered rtc-sun6i as rtc0
[ 2.009061] sun6i-rtc 1f00000.rtc: RTC enabled
[ 2.009065] driver: 'sun6i-rtc': driver_bound: bound to device '1f00000.rtc'
[ 2.009071] bus: 'platform': really_probe: bound device 1f00000.rtc to driver sun6i-rtc
[ 2.009104] i2c /dev entries driver
[ 2.009183] bus: 'platform': driver_probe_device: matched device 1c2b000.i2c with driver mv64xxx_i2c
[ 2.009189] bus: 'platform': really_probe: probing driver mv64xxx_i2c with device 1c2b000.i2c
[ 2.009208] mv64xxx_i2c 1c2b000.i2c: could not find pctldev for node /soc/pinctrl@1c20800/i2c1_pins, deferring probe
[ 2.009219] platform 1c2b000.i2c: Driver mv64xxx_i2c requests probe deferral
[ 2.009223] platform 1c2b000.i2c: Added to deferred list
[ 2.009947] bus: 'platform': driver_probe_device: matched device wifi_pwrseq with driver pwrseq_simple
[ 2.009953] bus: 'platform': really_probe: probing driver pwrseq_simple with device wifi_pwrseq
[ 2.010029] driver: 'pwrseq_simple': driver_bound: bound to device 'wifi_pwrseq'
[ 2.010034] bus: 'platform': really_probe: bound device wifi_pwrseq to driver pwrseq_simple
[ 2.010183] sdhci: Secure Digital Host Controller Interface driver
[ 2.010185] sdhci: Copyright(c) Pierre Ossman
[ 2.010263] Synopsys Designware Multimedia Card Interface Driver
[ 2.010499] bus: 'platform': driver_probe_device: matched device 1c0f000.mmc with driver sunxi-mmc
[ 2.010504] bus: 'platform': really_probe: probing driver sunxi-mmc with device 1c0f000.mmc
[ 2.010522] sunxi-mmc 1c0f000.mmc: could not find pctldev for node /soc/pinctrl@1c20800/mmc0-pins, deferring probe
[ 2.010533] platform 1c0f000.mmc: Driver sunxi-mmc requests probe deferral
[ 2.010537] platform 1c0f000.mmc: Added to deferred list
[ 2.010546] bus: 'platform': driver_probe_device: matched device 1c10000.mmc with driver sunxi-mmc
[ 2.010551] bus: 'platform': really_probe: probing driver sunxi-mmc with device 1c10000.mmc
[ 2.010564] sunxi-mmc 1c10000.mmc: could not find pctldev for node /soc/pinctrl@1c20800/mmc1-pins, deferring probe
[ 2.010572] platform 1c10000.mmc: Driver sunxi-mmc requests probe deferral
[ 2.010576] platform 1c10000.mmc: Added to deferred list
[ 2.010650] sdhci-pltfm: SDHCI platform and OF driver helper
[ 2.011633] ledtrig-cpu: registered to indicate activity on CPUs
[ 2.012602] usbcore: registered new interface driver usbhid
[ 2.012604] usbhid: USB HID core driver
[ 2.013365] bus: 'platform': driver_probe_device: matched device snd-soc-dummy with driver snd-soc-dummy
[ 2.013372] bus: 'platform': really_probe: probing driver snd-soc-dummy with device snd-soc-dummy
[ 2.013413] driver: 'snd-soc-dummy': driver_bound: bound to device 'snd-soc-dummy'
[ 2.013418] bus: 'platform': really_probe: bound device snd-soc-dummy to driver snd-soc-dummy
[ 2.013944] NET: Registered protocol family 17
[ 2.014030] 9pnet: Installing 9P2000 support
[ 2.014091] Key type dns_resolver registered
[ 2.014738] registered taskstats version 1
[ 2.016126] Btrfs loaded, crc32c=crc32c-generic
[ 2.020642] platform 1c19400.phy: Retrying from deferred list
[ 2.020710] bus: 'platform': driver_probe_device: matched device 1c19400.phy with driver sun4i-usb-phy
[ 2.020719] bus: 'platform': really_probe: probing driver sun4i-usb-phy with device 1c19400.phy
[ 2.021192] driver: 'sun4i-usb-phy': driver_bound: bound to device '1c19400.phy'
[ 2.021200] bus: 'platform': really_probe: bound device 1c19400.phy to driver sun4i-usb-phy
[ 2.021214] platform 1c20800.pinctrl: Retrying from deferred list
[ 2.021263] bus: 'platform': driver_probe_device: matched device 1c20800.pinctrl with driver sun50i-a64-pinctrl
[ 2.021268] bus: 'platform': really_probe: probing driver sun50i-a64-pinctrl with device 1c20800.pinctrl
[ 2.024455] sun50i-a64-pinctrl 1c20800.pinctrl: initialized sunXi PIO driver
[ 2.024461] driver: 'sun50i-a64-pinctrl': driver_bound: bound to device '1c20800.pinctrl'
[ 2.024468] bus: 'platform': really_probe: bound device 1c20800.pinctrl to driver sun50i-a64-pinctrl
[ 2.024481] platform 1c28000.serial: Retrying from deferred list
[ 2.024603] bus: 'platform': driver_probe_device: matched device 1c28000.serial with driver dw-apb-uart
[ 2.024609] bus: 'platform': really_probe: probing driver dw-apb-uart with device 1c28000.serial
[ 2.025321] console [ttyS0] disabled
[ 2.983052] 1c28000.serial: ttyS0 at MMIO 0x1c28000 (irq = 15, base_baud = 1500000) is a U6_16550A
[ 2.992039] console [ttyS0] enabled
[ 2.992039] console [ttyS0] enabled
[ 2.999010] bootconsole [uart0] disabled
[ 2.999010] bootconsole [uart0] disabled
[ 3.007066] driver: 'dw-apb-uart': driver_bound: bound to device '1c28000.serial'
[ 3.014554] bus: 'platform': really_probe: bound device 1c28000.serial to driver dw-apb-uart
[ 3.023006] platform 1c1b000.usb: Retrying from deferred list
[ 3.028967] bus: 'platform': driver_probe_device: matched device 1c1b000.usb with driver ehci-platform
[ 3.038274] bus: 'platform': really_probe: probing driver ehci-platform with device 1c1b000.usb
[ 3.047151] ehci-platform 1c1b000.usb: EHCI Host Controller
[ 3.052745] ehci-platform 1c1b000.usb: new USB bus registered, assigned bus number 1
[ 3.060720] ehci-platform 1c1b000.usb: irq 10, io mem 0x01c1b000
[ 3.079159] ehci-platform 1c1b000.usb: USB 2.0 started, EHCI 1.00
[ 3.085692] bus: 'usb': driver_probe_device: matched device usb1 with driver usb
[ 3.093091] bus: 'usb': really_probe: probing driver usb with device usb1
[ 3.100004] bus: 'usb': driver_probe_device: matched device 1-0:1.0 with driver hub
[ 3.107662] bus: 'usb': really_probe: probing driver hub with device 1-0:1.0
[ 3.114730] hub 1-0:1.0: USB hub found
[ 3.118506] hub 1-0:1.0: 1 port detected
[ 3.122533] driver: 'hub': driver_bound: bound to device '1-0:1.0'
[ 3.128717] bus: 'usb': really_probe: bound device 1-0:1.0 to driver hub
[ 3.135477] driver: 'usb': driver_bound: bound to device 'usb1'
[ 3.141399] bus: 'usb': really_probe: bound device usb1 to driver usb
[ 3.147897] driver: 'ehci-platform': driver_bound: bound to device '1c1b000.usb'
[ 3.155294] bus: 'platform': really_probe: bound device 1c1b000.usb to driver ehci-platform
[ 3.163651] platform 1c1b400.usb: Retrying from deferred list
[ 3.169603] bus: 'platform': driver_probe_device: matched device 1c1b400.usb with driver ohci-platform
[ 3.178907] bus: 'platform': really_probe: probing driver ohci-platform with device 1c1b400.usb
[ 3.187726] ohci-platform 1c1b400.usb: Generic Platform OHCI controller
[ 3.194358] ohci-platform 1c1b400.usb: new USB bus registered, assigned bus number 2
[ 3.202226] ohci-platform 1c1b400.usb: irq 11, io mem 0x01c1b400
[ 3.271530] bus: 'usb': driver_probe_device: matched device usb2 with driver usb
[ 3.278929] bus: 'usb': really_probe: probing driver usb with device usb2
[ 3.285830] bus: 'usb': driver_probe_device: matched device 2-0:1.0 with driver hub
[ 3.293488] bus: 'usb': really_probe: probing driver hub with device 2-0:1.0
[ 3.300555] hub 2-0:1.0: USB hub found
[ 3.304330] hub 2-0:1.0: 1 port detected
[ 3.308349] driver: 'hub': driver_bound: bound to device '2-0:1.0'
[ 3.314533] bus: 'usb': really_probe: bound device 2-0:1.0 to driver hub
[ 3.321282] driver: 'usb': driver_bound: bound to device 'usb2'
[ 3.327203] bus: 'usb': really_probe: bound device usb2 to driver usb
[ 3.333702] driver: 'ohci-platform': driver_bound: bound to device '1c1b400.usb'
[ 3.341099] bus: 'platform': really_probe: bound device 1c1b400.usb to driver ohci-platform
[ 3.349457] platform 1c19000.usb: Retrying from deferred list
[ 3.355402] bus: 'platform': driver_probe_device: matched device 1c19000.usb with driver musb-sunxi
[ 3.364446] bus: 'platform': really_probe: probing driver musb-sunxi with device 1c19000.usb
[ 3.373016] bus: 'platform': driver_probe_device: matched device usb_phy_generic.0.auto with driver usb_phy_generic
[ 3.383446] bus: 'platform': really_probe: probing driver usb_phy_generic with device usb_phy_generic.0.auto
[ 3.393298] usb_phy_generic usb_phy_generic.0.auto: usb_phy_generic.0.auto supply vcc not found, using dummy regulator
[ 3.404034] driver: 'usb_phy_generic': driver_bound: bound to device 'usb_phy_generic.0.auto'
[ 3.412564] bus: 'platform': really_probe: bound device usb_phy_generic.0.auto to driver usb_phy_generic
[ 3.422146] bus: 'platform': driver_probe_device: matched device musb-hdrc.1.auto with driver musb-hdrc
[ 3.431543] bus: 'platform': really_probe: probing driver musb-hdrc with device musb-hdrc.1.auto
[ 3.440473] musb-hdrc musb-hdrc.1.auto: MUSB HDRC host driver
[ 3.446235] musb-hdrc musb-hdrc.1.auto: new USB bus registered, assigned bus number 3
[ 3.454496] bus: 'usb': driver_probe_device: matched device usb3 with driver usb
[ 3.461902] bus: 'usb': really_probe: probing driver usb with device usb3
[ 3.468804] bus: 'usb': driver_probe_device: matched device 3-0:1.0 with driver hub
[ 3.476466] bus: 'usb': really_probe: probing driver hub with device 3-0:1.0
[ 3.483532] hub 3-0:1.0: USB hub found
[ 3.487313] hub 3-0:1.0: 1 port detected
[ 3.491357] driver: 'hub': driver_bound: bound to device '3-0:1.0'
[ 3.497543] bus: 'usb': really_probe: bound device 3-0:1.0 to driver hub
[ 3.504290] driver: 'usb': driver_bound: bound to device 'usb3'
[ 3.510218] bus: 'usb': really_probe: bound device usb3 to driver usb
[ 3.516789] driver: 'musb-hdrc': driver_bound: bound to device 'musb-hdrc.1.auto'
[ 3.524283] bus: 'platform': really_probe: bound device musb-hdrc.1.auto to driver musb-hdrc
[ 3.532722] driver: 'musb-sunxi': driver_bound: bound to device '1c19000.usb'
[ 3.539860] bus: 'platform': really_probe: bound device 1c19000.usb to driver musb-sunxi
[ 3.547952] platform 1c2b000.i2c: Retrying from deferred list
[ 3.553900] bus: 'platform': driver_probe_device: matched device 1c2b000.i2c with driver mv64xxx_i2c
[ 3.563031] bus: 'platform': really_probe: probing driver mv64xxx_i2c with device 1c2b000.i2c
[ 3.572044] driver: 'mv64xxx_i2c': driver_bound: bound to device '1c2b000.i2c'
[ 3.579273] bus: 'platform': really_probe: bound device 1c2b000.i2c to driver mv64xxx_i2c
[ 3.587461] platform 1c0f000.mmc: Retrying from deferred list
[ 3.593428] bus: 'platform': driver_probe_device: matched device 1c0f000.mmc with driver sunxi-mmc
[ 3.602387] bus: 'platform': really_probe: probing driver sunxi-mmc with device 1c0f000.mmc
[ 3.611332] sunxi-mmc 1c0f000.mmc: Got CD GPIO
[ 3.655164] sunxi-mmc 1c0f000.mmc: base:0xffff00000807c000 irq:7
[ 3.661180] driver: 'sunxi-mmc': driver_bound: bound to device '1c0f000.mmc'
[ 3.668233] bus: 'platform': really_probe: bound device 1c0f000.mmc to driver sunxi-mmc
[ 3.676241] platform 1c10000.mmc: Retrying from deferred list
[ 3.682218] bus: 'platform': driver_probe_device: matched device 1c10000.mmc with driver sunxi-mmc
[ 3.691176] bus: 'platform': really_probe: probing driver sunxi-mmc with device 1c10000.mmc
[ 3.699799] platform 1c10000.mmc: Driver sunxi-mmc requests probe deferral
[ 3.706678] platform 1c10000.mmc: Added to deferred list
[ 3.712220] sun6i-rtc 1f00000.rtc: setting system clock to 2017-04-29 02:07:09 UTC (1493431629)
[ 3.721141] ALSA device list:
[ 3.724129] No soundcards found.
[ 3.727806] Waiting for root device /dev/mmcblk0p5...
[ 3.732876] driver_probe_done: probe_count = 0
[ 3.751145] driver_probe_done: probe_count = 0
[ 3.771150] driver_probe_done: probe_count = 0
[ 3.788395] mmc0: new high speed SDHC card at address 0007
[ 3.791145] driver_probe_done: probe_count = 0
[ 3.798455] bus: 'mmc': driver_probe_device: matched device mmc0:0007 with driver mmcblk
[ 3.806549] bus: 'mmc': really_probe: probing driver mmcblk with device mmc0:0007
[ 3.807149] driver_probe_done: probe_count = 1
[ 3.818766] mmcblk0: mmc0:0007 SD16G 14.5 GiB
[ 3.823145] driver_probe_done: probe_count = 1
[ 3.829954] mmcblk0: p1 p2 < p5 >
[ 3.834002] driver: 'mmcblk': driver_bound: bound to device 'mmc0:0007'
[ 3.839145] driver_probe_done: probe_count = 1
[ 3.845076] bus: 'mmc': really_probe: bound device mmc0:0007 to driver mmcblk
[ 3.852237] platform 1c10000.mmc: Retrying from deferred list
[ 3.855169] driver_probe_done: probe_count = 0
[ 3.862774] bus: 'platform': driver_probe_device: matched device 1c10000.mmc with driver sunxi-mmc
[ 3.871775] bus: 'platform': really_probe: probing driver sunxi-mmc with device 1c10000.mmc
[ 3.880476] platform 1c10000.mmc: Driver sunxi-mmc requests probe deferral
[ 3.887365] platform 1c10000.mmc: Added to deferred list
[ 3.958882] F2FS-fs (mmcblk0p5): Mounted with checkpoint version = 1a55b
[ 3.965662] VFS: Mounted root (f2fs filesystem) readonly on device 179:5.
[ 3.974611] devtmpfs: mounted
[ 3.977964] Freeing unused kernel memory: 576K
[ 4.036695] random: fast init done
INIT: version 2.88 booting

OpenRC 0.23 is starting up Linux 4.11.0-rc7-iceconfig-00064-gf4aec3d9ff13 (aarch64)

* Mounting /proc ...
[ ok ]
* Mounting /run ...
* /run/openrc: creating directory
* /run/lock: creating directory
* /run/lock: correcting owner
* Caching service dependencies ...
[ ok ]
[....] Starting the hotplug events dispatcher: systemd-udevdstarting version 232
. ok
[ ok ] Synthesizing the initial hotplug events...done.
[....] Waiting for /dev to be fully populated...[ 6.325314] bus: 'platform': driver_probe_device: matched device 1c30000.ethernet with driver sun8i-emac
[ 6.334842] bus: 'platform': really_probe: probing driver sun8i-emac with device 1c30000.ethernet
[ 6.344253] platform 1c30000.ethernet: Driver sun8i-emac requests probe deferral
[ 6.351662] platform 1c30000.ethernet: Added to deferred list
done.
Starting fake hwclock: loading system time.
Current system time: 2017-04-29 02:07:14
fake-hwclock saved clock information is in the past: 2017-04-29 02:05:57
To set system time to this saved clock anyway, use "force"
[ ok ] Activating swap...done.
[ ok ] Activating lvm and md swap...done.
[....] Checking file systems...fsck from util-linux 2.29.2
/dev/mmcblk0p1: clean, 42/25376 files, 32541/101376 blocks
done.
[ ok ] Cleaning up temporary files... /tmp.
[....] Mounting local filesystems...[ 10.041068] EXT4-fs (mmcblk0p1): mounted filesystem with ordered data mode. Opts: (null)
done.
[ ok ] Activating swapfile swap...done.
[ ok ] Cleaning up temporary files....
[ ok ] Setting kernel variables...done.
[....] Configuring network interfaces...Cannot find device "eth0"
ifup: failed to bring up eth0
failed.
Starting NBD client process: Connecting...[ 12.715295] NET: Registered protocol family 10
[ 12.723755] Segment Routing with IPv6
Error: Socket failed: Network is unreachable
Error: Socket failed: Network is unreachable
[ ok ] Cleaning up temporary files....
[info] Loading kernel module 8723bs.
modprobe: FATAL: Module 8723bs not found in directory /lib/modules/4.11.0-rc7-iceconfig-00064-gf4aec3d9ff13
INIT: Entering runlevel: 2
[ ok ] Starting enhanced syslogd: rsyslogd.
[ ok ] Starting periodic command scheduler: cron.
[ ok ] Starting MTA: exim4.
[ ok ] Starting NTP server: ntpd.
[....] Recovering schroot sessions:E: 10mount: mount: special device /srv/sbuild/snapshots/unstable-arm64-sbuild-fcca4b13-74fe-432f-9cc9-788969157840 does not exist
E: unstable-arm64-sbuild-fcca4b13-74fe-432f-9cc9-788969157840: Chroot setup failed: stage=setup-recover
[ ok ion:unstable-arm64-sbuild-fcca4b13-74fe-432f-9cc9-788969157840.
[ ok ] Starting OpenBSD Secure Shell server: sshd.

Debian GNU/Linux 9 sirius ttyS0

sirius login: [ 73.043009] random: crng init done