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

[Adam Borowski <kilobyte@angband.pl>]

[-- Attachment #1: Type: text/plain, Size: 5028 bytes --]

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.

[-- Attachment #2: with-patch --]
[-- Type: text/plain, Size: 35698 bytes --]

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@linux.it>
[    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