Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

FS#957 - ath10k: firmware loading causes very long boot time on Archer C2600 #5922

Closed
openwrt-bot opened this issue Aug 13, 2017 · 9 comments
Labels

Comments

@openwrt-bot
Copy link

nopnopnop:

An Archer C2600 v1.1 boots very slowly. A few minutes pass between power on and the first replies to ping.

LEDE commit: df3295f

It's the same after every reboot and power on operation.

I had to power cycle the router after flashing a newer version of LEDE built from trunk. It didn't seem to boot automatically after flashing.

Full kernel log:
[ 0.000000] Booting Linux on physical CPU 0x0
[ 0.000000] Linux version 4.9.40 (wrt@ed3110359c81) (gcc version 5.4.0 (LEDE GCC 5.4.0 r4651-a6f6f8d) ) #0 SMP Fri Aug 11 16:12:56 2017
[ 0.000000] CPU: ARMv7 Processor [512f04d0] revision 0 (ARMv7), cr=10c5787d
[ 0.000000] CPU: div instructions available: patching division code
[ 0.000000] CPU: PIPT / VIPT nonaliasing data cache, PIPT instruction cache
[ 0.000000] OF: fdt:Machine model: TP-Link Archer C2600
[ 0.000000] Memory policy: Data cache writealloc
[ 0.000000] On node 0 totalpages: 122880
[ 0.000000] free_area_init_node: node 0, pgdat c079d000, node_mem_map ddc39000
[ 0.000000] Normal zone: 960 pages used for memmap
[ 0.000000] Normal zone: 0 pages reserved
[ 0.000000] Normal zone: 122880 pages, LIFO batch:31
[ 0.000000] percpu: Embedded 13 pages/cpu @ddc06000 s21068 r8192 d23988 u53248
[ 0.000000] pcpu-alloc: s21068 r8192 d23988 u53248 alloc=134096
[ 0.000000] pcpu-alloc: [0] 0 [0] 1
[ 0.000000] Built 1 zonelists in Zone order, mobility grouping on. Total pages: 121920
[ 0.000000] Kernel command line:
[ 0.000000] Bootloader command line (ignored): console=ttyHSL1,115200n8 root=mtd:rootfs rootfstype=squashfs
[ 0.000000] PID hash table entries: 2048 (order: 1, 8192 bytes)
[ 0.000000] Dentry cache hash table entries: 65536 (order: 6, 262144 bytes)
[ 0.000000] Inode-cache hash table entries: 32768 (order: 5, 131072 bytes)
[ 0.000000] Memory: 481048K/491520K available (3862K kernel code, 246K rwdata, 1236K rodata, 240K init, 242K bss, 10472K reserved, 0K cma-reserved, 0K highmem)
[ 0.000000] Virtual kernel memory layout:
[ 0.000000] vector : 0xffff0000 - 0xffff1000 ( 4 kB)
[ 0.000000] fixmap : 0xffc00000 - 0xfff00000 (3072 kB)
[ 0.000000] vmalloc : 0xde800000 - 0xff800000 ( 528 MB)
[ 0.000000] lowmem : 0xc0000000 - 0xde000000 ( 480 MB)
[ 0.000000] pkmap : 0xbfe00000 - 0xc0000000 ( 2 MB)
[ 0.000000] modules : 0xbf000000 - 0xbfe00000 ( 14 MB)
[ 0.000000] .text : 0xc0208000 - 0xc05cdc20 (3864 kB)
[ 0.000000] .init : 0xc0724000 - 0xc0760000 ( 240 kB)
[ 0.000000] .data : 0xc0760000 - 0xc079d900 ( 247 kB)
[ 0.000000] .bss : 0xc079f000 - 0xc07db828 ( 243 kB)
[ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=2, Nodes=1
[ 0.000000] Hierarchical RCU implementation.
[ 0.000000] RCU restricting CPUs from NR_CPUS=4 to nr_cpu_ids=2.
[ 0.000000] RCU: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=2
[ 0.000000] NR_IRQS:16 nr_irqs:16 16
[ 0.000000] clocksource: dg_timer: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 305801671480 ns
[ 0.000008] sched_clock: 32 bits at 6MHz, resolution 160ns, wraps every 343597383600ns
[ 0.000022] Switching to timer-based delay loop, resolution 160ns
[ 0.000224] Calibrating delay loop (skipped), value calculated using timer frequency.. 12.50 BogoMIPS (lpj=62500)
[ 0.000245] pid_max: default: 32768 minimum: 301
[ 0.000351] Mount-cache hash table entries: 1024 (order: 0, 4096 bytes)
[ 0.000364] Mountpoint-cache hash table entries: 1024 (order: 0, 4096 bytes)
[ 0.001015] CPU: Testing write buffer coherency: ok
[ 0.001302] Setting up static identity map for 0x42208280 - 0x422082d8
[ 0.004610] Brought up 2 CPUs
[ 0.004627] SMP: Total of 2 processors activated (25.00 BogoMIPS).
[ 0.004636] CPU: All CPU(s) started in SVC mode.
[ 0.016579] VFP support v0.3: implementor 51 architecture 64 part 4d variant 2 rev 0
[ 0.016766] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns
[ 0.016792] futex hash table entries: 512 (order: 3, 32768 bytes)
[ 0.016871] pinctrl core: initialized pinctrl subsystem
[ 0.018176] NET: Registered protocol family 16
[ 0.018425] DMA: preallocated 256 KiB pool for atomic coherent allocations
[ 0.041430] cpuidle: using governor ladder
[ 0.072446] cpuidle: using governor menu
[ 0.074598] qcom_rpm 108000.rpm: could not find pctldev for node /soc/pinmux@800000/i2c4_pinmux, deferring probe
[ 0.125127] msm_bus_fabric_init_driver
[ 0.126271] usbcore: registered new interface driver usbfs
[ 0.126372] usbcore: registered new interface driver hub
[ 0.126460] usbcore: registered new device driver usb
[ 0.126519] pps_core: LinuxPPS API ver. 1 registered
[ 0.126531] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti giometti@linux.it
[ 0.126563] PTP clock support registered
[ 0.128572] clocksource: Switched to clocksource dg_timer
[ 0.132624] NET: Registered protocol family 2
[ 0.133219] TCP established hash table entries: 4096 (order: 2, 16384 bytes)
[ 0.133267] TCP bind hash table entries: 4096 (order: 3, 32768 bytes)
[ 0.133326] TCP: Hash tables configured (established 4096 bind 4096)
[ 0.133379] UDP hash table entries: 256 (order: 1, 8192 bytes)
[ 0.133403] UDP-Lite hash table entries: 256 (order: 1, 8192 bytes)
[ 0.133597] NET: Registered protocol family 1
[ 0.133650] PCI: CLS 0 bytes, default 64
[ 0.135132] No memory allocated for crashlog
[ 0.135436] workingset: timestamp_bits=30 max_order=17 bucket_order=0
[ 0.141817] squashfs: version 4.0 (2009/01/31) Phillip Lougher
[ 0.141834] jffs2: version 2.2 (NAND) (SUMMARY) (LZMA) (RTIME) (CMODE_PRIORITY) (c) 2001-2006 Red Hat, Inc.
[ 0.148445] io scheduler noop registered
[ 0.148465] io scheduler deadline registered (default)
[ 0.149994] 1b500000.pci supply vdda not found, using dummy regulator
[ 0.150101] 1b500000.pci supply vdda_phy not found, using dummy regulator
[ 0.150198] 1b500000.pci supply vdda_refclk not found, using dummy regulator
[ 0.151016] OF: PCI: host bridge /soc/pci@1b500000 ranges:
[ 0.151061] OF: PCI: IO 0x0fe00000..0x0fefffff -> 0x0fe00000
[ 0.151089] OF: PCI: MEM 0x08000000..0x0fdfffff -> 0x08000000
[ 0.259343] qcom-pcie 1b500000.pci: link up
[ 0.261430] qcom-pcie 1b500000.pci: PCI host bridge to bus 0000:00
[ 0.261452] pci_bus 0000:00: root bus resource [bus 00-ff]
[ 0.261472] pci_bus 0000:00: root bus resource [io 0x0000-0xfffff] (bus address [0xfe00000-0xfefffff])
[ 0.261488] pci_bus 0000:00: root bus resource [mem 0x08000000-0x0fdfffff]
[ 0.261504] pci_bus 0000:00: scanning bus
[ 0.261550] pci 0000:00:00.0: [17cb:0101] type 01 class 0x060400
[ 0.261644] pci 0000:00:00.0: calling pci_fixup_ide_bases+0x0/0x3c
[ 0.261713] pci 0000:00:00.0: supports D1
[ 0.261724] pci 0000:00:00.0: PME# supported from D0 D1 D3hot
[ 0.261743] pci 0000:00:00.0: PME# disabled
[ 0.262022] pci_bus 0000:00: fixups for bus
[ 0.262043] PCI: bus0: Fast back to back transfers disabled
[ 0.262063] pci 0000:00:00.0: scanning [bus 01-01] behind bridge, pass 0
[ 0.262206] pci_bus 0000:01: scanning bus
[ 0.262381] pci 0000:01:00.0: [168c:0040] type 00 class 0x028000
[ 0.262611] pci 0000:01:00.0: reg 0x10: [mem 0x00000000-0x001fffff 64bit]
[ 0.263062] pci 0000:01:00.0: calling pci_fixup_ide_bases+0x0/0x3c
[ 0.263701] pci 0000:01:00.0: PME# supported from D0 D3hot D3cold
[ 0.263742] pci 0000:01:00.0: PME# disabled
[ 0.264090] pci_bus 0000:01: fixups for bus
[ 0.264159] PCI: bus1: Fast back to back transfers disabled
[ 0.264173] pci_bus 0000:01: bus scan returning with max=01
[ 0.264191] pci 0000:00:00.0: scanning [bus 01-01] behind bridge, pass 1
[ 0.264207] pci_bus 0000:00: bus scan returning with max=01
[ 0.264345] pci 0000:00:00.0: fixup irq: got 133
[ 0.264355] pci 0000:00:00.0: assigning IRQ 133
[ 0.264436] pci 0000:01:00.0: fixup irq: got 133
[ 0.264446] pci 0000:01:00.0: assigning IRQ 133
[ 0.264512] pci 0000:00:00.0: BAR 8: assigned [mem 0x08000000-0x081fffff]
[ 0.264537] pci 0000:01:00.0: BAR 0: assigned [mem 0x08000000-0x081fffff 64bit]
[ 0.264666] pci 0000:00:00.0: PCI bridge to [bus 01]
[ 0.264689] pci 0000:00:00.0: bridge window [mem 0x08000000-0x081fffff]
[ 0.265112] aer 0000:00:00.0:pcie002: service driver aer loaded
[ 0.265505] 1b700000.pci supply vdda not found, using dummy regulator
[ 0.265607] 1b700000.pci supply vdda_phy not found, using dummy regulator
[ 0.265690] 1b700000.pci supply vdda_refclk not found, using dummy regulator
[ 0.266481] OF: PCI: host bridge /soc/pci@1b700000 ranges:
[ 0.266515] OF: PCI: IO 0x31e00000..0x31efffff -> 0x31e00000
[ 0.266538] OF: PCI: MEM 0x2e000000..0x31dfffff -> 0x2e000000
[ 0.376805] qcom-pcie 1b700000.pci: link up
[ 0.378847] qcom-pcie 1b700000.pci: PCI host bridge to bus 0001:00
[ 0.378866] pci_bus 0001:00: root bus resource [bus 00-ff]
[ 0.378883] pci_bus 0001:00: root bus resource [mem 0x2e000000-0x31dfffff]
[ 0.378897] pci_bus 0001:00: scanning bus
[ 0.378935] pci 0001:00:00.0: [17cb:0101] type 01 class 0x060400
[ 0.379010] pci 0001:00:00.0: calling pci_fixup_ide_bases+0x0/0x3c
[ 0.379069] pci 0001:00:00.0: supports D1
[ 0.379079] pci 0001:00:00.0: PME# supported from D0 D1 D3hot
[ 0.379092] pci 0001:00:00.0: PME# disabled
[ 0.379339] pci_bus 0001:00: fixups for bus
[ 0.379356] PCI: bus0: Fast back to back transfers disabled
[ 0.379372] pci 0001:00:00.0: scanning [bus 01-01] behind bridge, pass 0
[ 0.379503] pci_bus 0001:01: scanning bus
[ 0.379675] pci 0001:01:00.0: [168c:0040] type 00 class 0x028000
[ 0.379899] pci 0001:01:00.0: reg 0x10: [mem 0x00000000-0x001fffff 64bit]
[ 0.380345] pci 0001:01:00.0: calling pci_fixup_ide_bases+0x0/0x3c
[ 0.380983] pci 0001:01:00.0: PME# supported from D0 D3hot D3cold
[ 0.381023] pci 0001:01:00.0: PME# disabled
[ 0.381366] pci_bus 0001:01: fixups for bus
[ 0.381437] PCI: bus1: Fast back to back transfers disabled
[ 0.381451] pci_bus 0001:01: bus scan returning with max=01
[ 0.381467] pci 0001:00:00.0: scanning [bus 01-01] behind bridge, pass 1
[ 0.381483] pci_bus 0001:00: bus scan returning with max=01
[ 0.381542] pcieport 0000:00:00.0: fixup irq: got 133
[ 0.381551] pcieport 0000:00:00.0: assigning IRQ 133
[ 0.381628] pci 0000:01:00.0: fixup irq: got 133
[ 0.381637] pci 0000:01:00.0: assigning IRQ 133
[ 0.381766] pci 0001:00:00.0: fixup irq: got 166
[ 0.381776] pci 0001:00:00.0: assigning IRQ 166
[ 0.381855] pci 0001:01:00.0: fixup irq: got 166
[ 0.381865] pci 0001:01:00.0: assigning IRQ 166
[ 0.381920] pci 0001:00:00.0: BAR 8: assigned [mem 0x2e000000-0x2e1fffff]
[ 0.381942] pci 0001:01:00.0: BAR 0: assigned [mem 0x2e000000-0x2e1fffff 64bit]
[ 0.382065] pci 0001:00:00.0: PCI bridge to [bus 01]
[ 0.382085] pci 0001:00:00.0: bridge window [mem 0x2e000000-0x2e1fffff]
[ 0.382420] aer 0001:00:00.0:pcie002: service driver aer loaded
[ 0.385112] L2 @ QSB rate. Forcing new rate.
[ 0.385306] L2 @ 384000 KHz
[ 0.385480] CPU0 @ 800000 KHz
[ 0.385492] CPU1 @ QSB rate. Forcing new rate.
[ 0.385619] CPU1 @ 384000 KHz
[ 0.388294] gsbi 16300000.gsbi: GSBI port protocol: 6 crci: 0
[ 0.389820] gsbi 1a200000.gsbi: GSBI port protocol: 3 crci: 0
[ 0.391319] Serial: 8250/16550 driver, 2 ports, IRQ sharing disabled
[ 0.392196] msm_serial 16340000.serial: msm_serial: detected port #0
[ 0.392303] msm_serial 16340000.serial: uartclk = 7372800
[ 0.392380] 16340000.serial: ttyMSM0 at MMIO 0x16340000 (irq = 167, base_baud = 460800) is a MSM
[ 0.392417] msm_serial: console setup on port #0
[ 1.101648] console [ttyMSM0] enabled
[ 1.106364] msm_serial: driver initialized
[ 1.117864] loop: module loaded
[ 1.119399] spi_qup 1a280000.spi: IN:block:16, fifo:64, OUT:block:16, fifo:64
[ 1.121388] m25p80 spi32766.0: mx25u25635f (32768 Kbytes)
[ 1.127347] 25 ofpart partitions found on MTD device spi32766.0
[ 1.132612] Creating 25 MTD partitions on "spi32766.0":
[ 1.138225] 0x000000000000-0x000000020000 : "SBL1"
[ 1.144723] 0x000000020000-0x000000040000 : "MIBIB"
[ 1.149359] 0x000000040000-0x000000060000 : "SBL2"
[ 1.154061] 0x000000060000-0x000000090000 : "SBL3"
[ 1.159019] 0x000000090000-0x0000000a0000 : "DDRCONFIG"
[ 1.163688] 0x0000000a0000-0x0000000b0000 : "SSD"
[ 1.169147] 0x0000000b0000-0x0000000e0000 : "TZ"
[ 1.173692] 0x0000000e0000-0x000000100000 : "RPM"
[ 1.178611] 0x000000100000-0x000000170000 : "fs-uboot"
[ 1.183040] 0x000000170000-0x0000001b0000 : "uboot-env"
[ 1.188001] 0x0000001b0000-0x0000001f0000 : "radio"
[ 1.193178] 0x0000001f0000-0x0000003f0000 : "os-image"
[ 1.197992] 0x0000003f0000-0x000001ef0000 : "rootfs"
[ 1.203237] mtd: device 12 (rootfs) set to be root filesystem
[ 1.207550] 1 squashfs-split partitions found on MTD device rootfs
[ 1.213036] 0x000000720000-0x000001ef0000 : "rootfs_data"
[ 1.220117] 0x000001ef0000-0x000001ef0200 : "default-mac"
[ 1.225759] 0x000001ef0200-0x000001ef0400 : "pin"
[ 1.230953] 0x000001ef0400-0x000001f00000 : "product-info"
[ 1.235832] 0x000001f00000-0x000001f10000 : "partition-table"
[ 1.241070] 0x000001f10000-0x000001f20000 : "soft-version"
[ 1.246785] 0x000001f20000-0x000001f30000 : "support-list"
[ 1.252229] 0x000001f30000-0x000001f40000 : "profile"
[ 1.257610] 0x000001f40000-0x000001f50000 : "default-config"
[ 1.262853] 0x000001f50000-0x000001f90000 : "user-config"
[ 1.268837] 0x000001f90000-0x000001fd0000 : "qos-db"
[ 1.273768] 0x000001fd0000-0x000001fe0000 : "usb-config"
[ 1.279163] 0x000001fe0000-0x000002000000 : "log"
[ 1.284950] libphy: GPIO Bitbanged MDIO: probed
[ 1.313593] switch0: Atheros AR8337 rev. 2 switch registered on gpio-0
[ 2.229691] libphy: Fixed MDIO Bus: probed
[ 2.229724] libphy: mdio_driver_register: qca8k
[ 2.234739] stmmac - user ID: 0x10, Synopsys ID: 0x37
[ 2.237110] Ring mode enabled
[ 2.242393] DMA HW capability register supported
[ 2.245268] Enhanced/Alternate descriptors
[ 2.250909] Enabled extended descriptors
[ 2.253868] RX Checksum Offload Engine supported
[ 2.258036] COE Type 2
[ 2.262783] TX Checksum insertion supported
[ 2.264979] Wake-Up On Lan supported
[ 2.269564] Enable RX Mitigation via HW Watchdog Timer
[ 2.274957] stmmac - user ID: 0x10, Synopsys ID: 0x37
[ 2.278088] Ring mode enabled
[ 2.283385] DMA HW capability register supported
[ 2.286247] Enhanced/Alternate descriptors
[ 2.291889] Enabled extended descriptors
[ 2.294846] RX Checksum Offload Engine supported
[ 2.299085] COE Type 2
[ 2.303698] TX Checksum insertion supported
[ 2.305958] Wake-Up On Lan supported
[ 2.310549] Enable RX Mitigation via HW Watchdog Timer
[ 2.314809] i2c /dev entries driver
[ 2.320000] Calibration not found.
[ 2.322545] qcom-tsens 900000.thermal-sensor: tsens calibration failed
[ 2.327080] Speed bin: 0
[ 2.332608] PVS bin: 1
[ 2.337010] cpuidle: enable-method property 'qcom,kpss-acc-v1' found operations
[ 2.337438] cpuidle: enable-method property 'qcom,kpss-acc-v1' found operations
[ 2.345199] sdhci: Secure Digital Host Controller Interface driver
[ 2.351943] sdhci: Copyright(c) Pierre Ossman
[ 2.358131] sdhci-pltfm: SDHCI platform and OF driver helper
[ 2.364315] NET: Registered protocol family 10
[ 2.369828] NET: Registered protocol family 17
[ 2.372837] 8021q: 802.1Q VLAN Support v1.8
[ 2.377021] Registering SWP/SWPB emulation handler
[ 2.393395] qcom_rpm 108000.rpm: RPM firmware 3.0.16777342
[ 2.405014] s1a: Bringing 0uV into 1050000-1050000uV
[ 2.405353] s1b: Bringing 0uV into 1050000-1050000uV
[ 2.409420] s2a: Bringing 0uV into 800000-800000uV
[ 2.414274] s2b: Bringing 0uV into 800000-800000uV
[ 2.421672] of: dev_pm_opp_of_cpumask_add_table: couldn't find opp table for cpu:0, -19
[ 2.423884] of: dev_pm_opp_of_cpumask_add_table: couldn't find opp table for cpu:1, -19
[ 2.431926] hctosys: unable to open rtc device (rtc0)
[ 2.444233] random: fast init done
[ 2.446697] VFS: Mounted root (squashfs filesystem) readonly on device 31:12.
[ 2.446929] Freeing unused kernel memory: 240K (c0724000 - c0760000)
[ 2.453814] This architecture does not have kernel memory protection.
[ 2.707162] random: crng init done
[ 3.231184] init: Console is alive
[ 3.231461] init: - watchdog -
[ 5.606708] kmodloader: loading kernel modules from /etc/modules-boot.d/

[ 5.631388] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver
[ 5.633440] SCSI subsystem initialized
[ 5.639085] libata version 3.00 loaded.
[ 5.642247] ehci-platform: EHCI generic platform driver
[ 5.644920] ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver
[ 5.646703] ohci-platform: OHCI generic platform driver
[ 5.779028] xhci-hcd xhci-hcd.0.auto: xHCI Host Controller
[ 5.779102] xhci-hcd xhci-hcd.0.auto: new USB bus registered, assigned bus number 1
[ 5.783630] xhci-hcd xhci-hcd.0.auto: hcc params 0x0228f065 hci version 0x100 quirks 0x02010010
[ 5.791104] xhci-hcd xhci-hcd.0.auto: irq 169, io mem 0x11000000
[ 5.800675] hub 1-0:1.0: USB hub found
[ 5.805951] hub 1-0:1.0: 1 port detected
[ 5.809967] xhci-hcd xhci-hcd.0.auto: xHCI Host Controller
[ 5.813547] xhci-hcd xhci-hcd.0.auto: new USB bus registered, assigned bus number 2
[ 5.819138] usb usb2: We don't know the algorithms for LPM for this host, disabling LPM.
[ 5.827189] hub 2-0:1.0: USB hub found
[ 5.834860] hub 2-0:1.0: 1 port detected
[ 5.838811] xhci-hcd xhci-hcd.1.auto: xHCI Host Controller
[ 5.842376] xhci-hcd xhci-hcd.1.auto: new USB bus registered, assigned bus number 3
[ 5.847853] xhci-hcd xhci-hcd.1.auto: hcc params 0x0228f065 hci version 0x100 quirks 0x02010010
[ 5.855350] xhci-hcd xhci-hcd.1.auto: irq 170, io mem 0x10000000
[ 5.864823] hub 3-0:1.0: USB hub found
[ 5.870249] hub 3-0:1.0: 1 port detected
[ 5.874063] xhci-hcd xhci-hcd.1.auto: xHCI Host Controller
[ 5.877781] xhci-hcd xhci-hcd.1.auto: new USB bus registered, assigned bus number 4
[ 5.883276] usb usb4: We don't know the algorithms for LPM for this host, disabling LPM.
[ 5.891474] hub 4-0:1.0: USB hub found
[ 5.899091] hub 4-0:1.0: 1 port detected
[ 5.905669] kmodloader: done loading kernel modules from /etc/modules-boot.d/*
[ 5.915271] init: - preinit -
[ 8.784757] dwmac1000: Master AXI performs any burst length
[ 8.784800] ipq806x-gmac-dwmac 37400000.ethernet eth1: IEEE 1588-2008 Advanced Timestamp supported
[ 8.789313] ipq806x-gmac-dwmac 37400000.ethernet eth1: registered PTP clock
[ 8.798340] IPv6: ADDRCONF(NETDEV_UP): eth1: link is not ready
[ 9.849572] ipq806x-gmac-dwmac 37400000.ethernet eth1: Link is Up - 1Gbps/Full - flow control off
[ 9.850016] IPv6: ADDRCONF(NETDEV_CHANGE): eth1: link becomes ready
[ 11.337086] jffs2: notice: (172) jffs2_build_xattr_subsystem: complete building xattr subsystem, 0 of xdatum (0 unchecked, 0 orphan) and 0 of xref (0 dead, 0 orphan) found.
[ 11.342074] mount_root: overlay filesystem has not been fully initialized yet
[ 19.443404] mount_root: switching to jffs2 overlay
[ 20.027552] urandom-seed: Seed file not found (/etc/urandom.seed)
[ 20.125058] procd: - early -
[ 20.125155] procd: - watchdog -
[ 20.855207] procd: - watchdog -
[ 20.855660] procd: - ubus -
[ 21.013192] procd: - init -
[ 21.220998] kmodloader: loading kernel modules from /etc/modules.d/*
[ 21.224980] ip6_tables: (C) 2000-2006 Netfilter Core Team
[ 21.230352] Netfilter messages via NETLINK v0.30.
[ 21.232750] ip_set: protocol 6
[ 21.248739] Loading modules backported from Linux version wt-2017-01-31-0-ge882dff19e7f
[ 21.248767] Backport generated by backports.git backports-20160324-13-g24da7d3c
[ 21.273162] ath10k_pci 0000:01:00.0: enabling device (0140 -> 0142)
[ 21.273254] ath10k_pci 0000:01:00.0: enabling bus mastering
[ 21.273734] ath10k_pci 0000:01:00.0: pci irq msi oper_irq_mode 2 irq_mode 0 reset_mode 0
[ 21.451476] ath10k_pci 0000:01:00.0: Direct firmware load for ath10k/pre-cal-pci-0000:01:00.0.bin failed with error -2
[ 21.451523] ath10k_pci 0000:01:00.0: Falling back to user helper
[ 82.190159] ath10k_pci 0000:01:00.0: qca99x0 hw2.0 target 0x01000000 chip_id 0x003b01ff sub 168c:0002
[ 82.190206] ath10k_pci 0000:01:00.0: kconfig debug 0 debugfs 1 tracing 0 dfs 1 testmode 1
[ 82.202490] ath10k_pci 0000:01:00.0: firmware ver 10.4.1.00030-1 api 5 features no-p2p crc32 d2901e01
[ 82.262895] ath10k_pci 0000:01:00.0: board_file api 2 bmi_id 1:1 crc32 08fa09f2
[ 83.526583] ath10k_pci 0000:01:00.0: htt-ver 2.2 wmi-op 6 htt-op 4 cal pre-cal-file max-sta 512 raw 0 hwcrypto 1
[ 83.652156] ath: EEPROM regdomain: 0x0
[ 83.652168] ath: EEPROM indicates default country code should be used
[ 83.652177] ath: doing EEPROM country->regdmn map search
[ 83.652192] ath: country maps to regdmn code: 0x3a
[ 83.652203] ath: Country alpha2 being used: US
[ 83.652212] ath: Regpair used: 0x3a
[ 83.658954] ath10k_pci 0001:01:00.0: enabling device (0140 -> 0142)
[ 83.659078] ath10k_pci 0001:01:00.0: enabling bus mastering
[ 83.659656] ath10k_pci 0001:01:00.0: pci irq msi oper_irq_mode 2 irq_mode 0 reset_mode 0
[ 83.851129] ath10k_pci 0001:01:00.0: Direct firmware load for ath10k/pre-cal-pci-0001:01:00.0.bin failed with error -2
[ 83.851177] ath10k_pci 0001:01:00.0: Falling back to user helper
[ 146.529172] ath10k_pci 0001:01:00.0: Direct firmware load for ath10k/cal-pci-0001:01:00.0.bin failed with error -2
[ 146.529225] ath10k_pci 0001:01:00.0: Falling back to user helper
[ 148.442922] firmware ath10k!cal-pci-0001:01:00.0.bin: firmware_loading_store: map pages failed
[ 148.443191] ath10k_pci 0001:01:00.0: qca99x0 hw2.0 target 0x01000000 chip_id 0x003b01ff sub 168c:0002
[ 148.450573] ath10k_pci 0001:01:00.0: kconfig debug 0 debugfs 1 tracing 0 dfs 1 testmode 1
[ 148.467441] ath10k_pci 0001:01:00.0: firmware ver 10.4.1.00030-1 api 5 features no-p2p crc32 d2901e01
[ 150.756223] ath10k_pci 0001:01:00.0: board id is not exist in otp, ignore it
[ 150.756261] ath10k_pci 0001:01:00.0: failed to fetch board data for bus=pci,vendor=168c,device=0040,subsystem-vendor=168c,subsystem-device=0002¦¦0¦MM¦M
[ 150.756261] |¦¦0¦OB¦¦?V¦i¦ from ath10k/QCA99X0/hw2.0/board-2.bin
[ 150.779488] ath10k_pci 0001:01:00.0: board_file api 1 bmi_id N/A crc32 7e56fd07
[ 154.239465] ath10k_pci 0001:01:00.0: htt-ver 2.2 wmi-op 6 htt-op 4 cal otp max-sta 512 raw 0 hwcrypto 1
[ 154.321987] ath: EEPROM regdomain: 0x0
[ 154.321998] ath: EEPROM indicates default country code should be used
[ 154.322006] ath: doing EEPROM country->regdmn map search
[ 154.322019] ath: country maps to regdmn code: 0x3a
[ 154.322029] ath: Country alpha2 being used: US
[ 154.322037] ath: Regpair used: 0x3a
[ 154.343783] u32 classifier
[ 154.343812] input device check on
[ 154.345381] Actions configured
[ 154.351096] Mirror/redirect action on
[ 154.376532] nf_conntrack version 0.5.0 (8192 buckets, 32768 max)
[ 154.382627] ip_tables: (C) 2000-2006 Netfilter Core Team
[ 154.449334] xt_time: kernel timezone is -0000
[ 154.452587] PPP generic driver version 2.4.2
[ 154.453312] NET: Registered protocol family 24
[ 154.458218] kmodloader: done loading kernel modules from /etc/modules.d/*
[ 160.176657] dwmac1000: Master AXI performs any burst length
[ 160.176699] ipq806x-gmac-dwmac 37400000.ethernet eth1: IEEE 1588-2008 Advanced Timestamp supported
[ 160.181264] ipq806x-gmac-dwmac 37400000.ethernet eth1: registered PTP clock
[ 160.190248] IPv6: ADDRCONF(NETDEV_UP): eth1: link is not ready
[ 160.203216] br-lan: port 1(eth1.1) entered blocking state
[ 160.203254] br-lan: port 1(eth1.1) entered disabled state
[ 160.208744] device eth1.1 entered promiscuous mode
[ 160.213779] device eth1 entered promiscuous mode
[ 160.222254] IPv6: ADDRCONF(NETDEV_UP): br-lan: link is not ready
[ 160.249642] dwmac1000: Master AXI performs any burst length
[ 160.249708] ipq806x-gmac-dwmac 37200000.ethernet eth0: IEEE 1588-2008 Advanced Timestamp supported
[ 160.254249] ipq806x-gmac-dwmac 37200000.ethernet eth0: registered PTP clock
[ 160.263416] IPv6: ADDRCONF(NETDEV_UP): eth0: link is not ready
[ 160.274620] IPv6: ADDRCONF(NETDEV_UP): eth0.2: link is not ready
[ 160.723730] ath: EEPROM regdomain: 0x8282
[ 160.723738] ath: EEPROM indicates we should expect a country code
[ 160.723744] ath: doing EEPROM country->regdmn map search
[ 160.723749] ath: country maps to regdmn code: 0x3
[ 160.723753] ath: Country alpha2 being used: RO
[ 160.723756] ath: Regpair used: 0x3
[ 160.723761] ath: regdomain 0x8282 dynamically updated by user
[ 160.723784] ath: EEPROM regdomain: 0x8282
[ 160.723787] ath: EEPROM indicates we should expect a country code
[ 160.723791] ath: doing EEPROM country->regdmn map search
[ 160.723795] ath: country maps to regdmn code: 0x3
[ 160.723798] ath: Country alpha2 being used: RO
[ 160.723801] ath: Regpair used: 0x3
[ 160.723804] ath: regdomain 0x8282 dynamically updated by user
[ 161.211214] ipq806x-gmac-dwmac 37400000.ethernet eth1: Link is Up - 1Gbps/Full - flow control off
[ 161.215063] IPv6: ADDRCONF(NETDEV_CHANGE): eth1: link becomes ready
[ 161.219807] br-lan: port 1(eth1.1) entered blocking state
[ 161.225167] br-lan: port 1(eth1.1) entered forwarding state
[ 161.231029] IPv6: ADDRCONF(NETDEV_CHANGE): br-lan: link becomes ready
[ 161.289604] ipq806x-gmac-dwmac 37200000.ethernet eth0: Link is Up - 1Gbps/Full - flow control off
[ 161.289674] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
[ 161.298014] IPv6: ADDRCONF(NETDEV_CHANGE): eth0.2: link becomes ready
[ 163.765320] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready
[ 163.768030] br-lan: port 2(wlan0) entered blocking state
[ 163.770168] br-lan: port 2(wlan0) entered disabled state
[ 163.776025] device wlan0 entered promiscuous mode
[ 163.781083] br-lan: port 2(wlan0) entered blocking state
[ 163.785504] br-lan: port 2(wlan0) entered forwarding state
[ 163.794081] br-lan: port 2(wlan0) entered disabled state
[ 228.479624] IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
[ 228.479750] br-lan: port 2(wlan0) entered blocking state
[ 228.485043] br-lan: port 2(wlan0) entered forwarding state

@openwrt-bot
Copy link
Author

bjonglez:

The very high boot time seems related to loading the ath10k firmware.

Are you sure ath10k-firmware-qca99x0 is present in your image? Can you also reproduce this issue with a trunk image from downloads.lede-project.org?

You can try ath10k-firmware-qca99x0-ct and see if it makes a difference, but it may be an issue with the partitions.

@openwrt-bot
Copy link
Author

bjonglez:

ath10k is apparently supposed to work fine on this device: lede-project/source#1153 (comment)

@openwrt-bot
Copy link
Author

nopnopnop:

The ath10k firmware for qca9980 is selected in the menu. I'm sure it's included. I'll check and post a comment.

@openwrt-bot
Copy link
Author

nopnopnop:

ls /rom/lib/firmware/ath10k/QCA99X0/hw2.0/
board-2.bin board.bin firmware-5.bin

The firmware seems to be included. I've booted the router again and it took less to boot. This seems to be a bug.

@openwrt-bot
Copy link
Author

nopnopnop:

Is there something I can do to speed this up?

@openwrt-bot
Copy link
Author

bjonglez:

Maybe try posting in lede-project/source#1153 to get people's attention?

@openwrt-bot
Copy link
Author

bjonglez:

I just flashed a brand new Archer C2600(UN) v1.1 with LEDE 17.01.2. The first boot was quite fast: although the power LED kept blinking for several minutes (because of the jffs2 filesystem being initialized), it was already possible to SSH in.

The second boot took between 20 and 30 seconds, which I think is normal.

@openwrt-bot
Copy link
Author

bjonglez:

Below is my kernel boot log. Compared to yours, it's almost the same, but where it takes 134 seconds for you, it takes 4 seconds for me.

Do you have the same issue with LEDE 17.01.2? What about trunk images from the build bots, as opposed to an image you built yourself?

[ 4.691239] init: - preinit - [ 8.489929] ipq806x-gmac-dwmac 37400000.ethernet eth1: Link is Up - 1Gbps/Full - flow control off [ 10.573136] jffs2: notice: (154) jffs2_build_xattr_subsystem: complete building xattr subsystem, 0 of xdatum (0 unchecked, 0 orphan) and 0 of xref (0 dead, 0 orphan) found. [ 10.594834] mount_root: switching to jffs2 overlay [ 10.612784] urandom-seed: Seeding with /etc/urandom.seed [ 10.698538] procd: - early - [ 10.698602] procd: - watchdog - [ 11.383145] procd: - ubus - [ 11.440041] procd: - init - [ 11.593062] kmodloader: loading kernel modules from /etc/modules.d/* [ 11.594840] ip6_tables: (C) 2000-2006 Netfilter Core Team [ 11.601304] Loading modules backported from Linux version wt-2017-01-31-0-ge882dff19e7f [ 11.603771] Backport generated by backports.git backports-20160324-13-g24da7d3c [ 11.624666] ath10k_pci 0000:01:00.0: enabling device (0140 -> 0142) [ 11.624749] ath10k_pci 0000:01:00.0: enabling bus mastering [ 11.625192] ath10k_pci 0000:01:00.0: pci irq msi oper_irq_mode 2 irq_mode 0 reset_mode 0 [ 11.763343] ath10k_pci 0000:01:00.0: Direct firmware load for ath10k/pre-cal-pci-0000:01:00.0.bin failed with error -2 [ 11.763396] ath10k_pci 0000:01:00.0: Falling back to user helper [ 11.822168] firmware ath10k!pre-cal-pci-0000:01:00.0.bin: firmware_loading_store: map pages failed [ 12.435963] ath10k_pci 0000:01:00.0: qca99x0 hw2.0 target 0x01000000 chip_id 0x003b01ff sub 168c:0002 [ 12.436007] ath10k_pci 0000:01:00.0: kconfig debug 0 debugfs 1 tracing 0 dfs 1 testmode 1 [ 12.447051] ath10k_pci 0000:01:00.0: firmware ver 10.4.1.00030-1 api 5 features no-p2p crc32 d2901e01 [ 12.452910] ath10k_pci 0000:01:00.0: failed to fetch board data for bus=pci,vendor=168c,device=0040,subsystem-vendor=168c,subsystem-device=0002 from ath10k/QCA99X0/hw2.0/board-2.bin [ 12.461796] ath10k_pci 0000:01:00.0: board_file api 1 bmi_id N/A crc32 7e56fd07 [ 13.644878] ath10k_pci 0000:01:00.0: htt-ver 2.2 wmi-op 6 htt-op 4 cal file max-sta 512 raw 0 hwcrypto 1 [ 13.715133] ath: EEPROM regdomain: 0x0 [ 13.715150] ath: EEPROM indicates default country code should be used [ 13.715163] ath: doing EEPROM country->regdmn map search [ 13.715180] ath: country maps to regdmn code: 0x3a [ 13.715193] ath: Country alpha2 being used: US [ 13.715204] ath: Regpair used: 0x3a [ 13.721154] ath10k_pci 0001:01:00.0: enabling device (0140 -> 0142) [ 13.721272] ath10k_pci 0001:01:00.0: enabling bus mastering [ 13.721816] ath10k_pci 0001:01:00.0: pci irq msi oper_irq_mode 2 irq_mode 0 reset_mode 0 [ 13.849568] ath10k_pci 0001:01:00.0: Direct firmware load for ath10k/pre-cal-pci-0001:01:00.0.bin failed with error -2 [ 13.849608] ath10k_pci 0001:01:00.0: Falling back to user helper [ 13.905493] firmware ath10k!pre-cal-pci-0001:01:00.0.bin: firmware_loading_store: map pages failed [ 13.909662] ath10k_pci 0001:01:00.0: qca99x0 hw2.0 target 0x01000000 chip_id 0x003b01ff sub 168c:0002 [ 13.913354] ath10k_pci 0001:01:00.0: kconfig debug 0 debugfs 1 tracing 0 dfs 1 testmode 1 [ 13.925091] ath10k_pci 0001:01:00.0: firmware ver 10.4.1.00030-1 api 5 features no-p2p crc32 d2901e01 [ 13.931125] ath10k_pci 0001:01:00.0: failed to fetch board data for bus=pci,vendor=168c,device=0040,subsystem-vendor=168c,subsystem-device=0002 from ath10k/QCA99X0/hw2.0/board-2.bin [ 13.940175] ath10k_pci 0001:01:00.0: board_file api 1 bmi_id N/A crc32 7e56fd07 [ 15.124185] ath10k_pci 0001:01:00.0: htt-ver 2.2 wmi-op 6 htt-op 4 cal file max-sta 512 raw 0 hwcrypto 1 [ 15.195161] ath: EEPROM regdomain: 0x0 [ 15.195178] ath: EEPROM indicates default country code should be used [ 15.195191] ath: doing EEPROM country->regdmn map search [ 15.195208] ath: country maps to regdmn code: 0x3a [ 15.195223] ath: Country alpha2 being used: US [ 15.195234] ath: Regpair used: 0x3a

@openwrt-bot
Copy link
Author

nopnopnop:

I've rebooted a few times. I have flashed a new build.

I can't reproduce this issue.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

No branches or pull requests

1 participant