Return-Path: Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1036482AbdD2V3O (ORCPT ); Sat, 29 Apr 2017 17:29:14 -0400 Received: from tartarus.angband.pl ([89.206.35.136]:43449 "EHLO tartarus.angband.pl" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1032894AbdD2V3J (ORCPT ); Sat, 29 Apr 2017 17:29:09 -0400 Date: Sat, 29 Apr 2017 23:28:57 +0200 From: Adam Borowski To: Tejun Heo Cc: Andre Przywara , Icenowy Zheng , Greg Kroah-Hartman , "linux-kernel@vger.kernel.org" Subject: Re: sun50i-a64-pinctrl WARN_ON drivers/base/dd.c:349 Message-ID: <20170429212857.tvdsxi4tlft3mdpj@angband.pl> References: <20170315161406.smd4na25two55jjh@angband.pl> <197431489595078@web8g.yandex.ru> <20170316010615.GA23552@kroah.com> <20170317140812.GB5078@htj.duckdns.org> <785901489760914@web50g.yandex.ru> <20170317144422.GD5078@htj.duckdns.org> <3cf02066-ca0e-05f4-6a3d-ebc6d5373caf@arm.com> <20170418072505.GE3899@wtj.duckdns.org> <3fda46eb-7fcc-4c27-98b6-7d822cce1405@arm.com> <20170428220314.GI22354@htj.duckdns.org> MIME-Version: 1.0 Content-Type: multipart/mixed; boundary="vavwmvkg6x7dyedh" Content-Disposition: inline In-Reply-To: <20170428220314.GI22354@htj.duckdns.org> X-Junkbait: aaron@angband.pl, zzyx@angband.pl User-Agent: NeoMutt/20170113 (1.7.2) X-SA-Exim-Connect-IP: X-SA-Exim-Mail-From: kilobyte@angband.pl X-SA-Exim-Scanned: No (on tartarus.angband.pl); SAEximRunCond expanded to false Sender: linux-kernel-owner@vger.kernel.org List-ID: X-Mailing-List: linux-kernel@vger.kernel.org Content-Length: 40957 Lines: 690 --vavwmvkg6x7dyedh Content-Type: text/plain; charset=us-ascii Content-Disposition: inline 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. [....] 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. [....] 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. --vavwmvkg6x7dyedh Content-Type: text/plain; charset=us-ascii Content-Disposition: attachment; filename=with-patch 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 [ 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 --vavwmvkg6x7dyedh--