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

boot failure with sdhost overlay #1205

Closed
ali1234 opened this issue Nov 20, 2015 · 9 comments
Closed

boot failure with sdhost overlay #1205

ali1234 opened this issue Nov 20, 2015 · 9 comments

Comments

@ali1234
Copy link
Contributor

ali1234 commented Nov 20, 2015

I tried to boot with both the sdio and sdhost overlays on Raspberry Pi 2. In both cases the SD hardware was correctly detected and the kernel was able to determine the partitions on the SD card, but then everything failed with IRQ timeouts. I don't have anything connected to the SD pins on the GPIO header, but this should not matter when only using the sdhost overlay, should it?

My kernel is about two weeks old, but I don't see any related changes. I'll try with the latest one and provide full logs if this is not expected behavior.

Logs snippets. During a normal boot I see this:

[    3.062641] sdhci: Secure Digital Host Controller Interface driver
[    3.070371] sdhci: Copyright(c) Pierre Ossman
[    3.076739] mmc-bcm2835 3f300000.mmc: mmc_debug:0 mmc_debug2:0
[    3.084146] mmc-bcm2835 3f300000.mmc: DMA channels allocated
[    3.128112] sdhci-pltfm: SDHCI platform and OF driver helper
[    3.140439] ledtrig-cpu: registered to indicate activity on CPUs

[    3.206327] mmc0: host does not support reading read-only switch, assuming write-enable
[    3.206475] mmc0: new SD card at address 99d6
[    3.207106] mmcblk0: mmc0:99d6 SU02G 1.89 GiB 
[    3.211098]  mmcblk0: p1 p2

When booting with sdhost or sdio I see this:

[    3.062679] sdhci: Secure Digital Host Controller Interface driver
[    3.070408] sdhci: Copyright(c) Pierre Ossman
[    3.168041] mmc0: sdhost-bcm2835 loaded - DMA enabled (>1)
[    3.177423] mmc-bcm2835 3f300000.mmc: mmc_debug:0 mmc_debug2:0
[    3.188017] mmc-bcm2835 3f300000.mmc: DMA channels allocated
[    3.228100] sdhci-pltfm: SDHCI platform and OF driver helper
[    3.235970] ledtrig-cpu: registered to indicate activity on CPUs
[    3.238092] Indeed it is in host mode hprt0 = 00021501
[    3.245971] mmc0: host does not support reading read-only switch, assuming write-enable
[    3.246085] mmc0: new SD card at address 99d6
[    3.246746] mmcblk0: mmc0:99d6 SU02G 1.89 GiB 
[    3.248301]  mmcblk0: p1 p2

[   13.947935] mmc0: timeout waiting for hardware interrupt.
[   13.955232] mmc0: cmd op 25 arg 0x37a18000 flags 0xb5 - resp 00000900 00000000 00000000 00000000, err 0
[   13.968303] mmc0: data blocks 8 blksz 200 - err 0
[   13.974824] mmc0:>stop op 12 arg 0x0 flags 0x49d - resp 00000000 00000000 00000000 00000000, err 0
[   13.987422] mmc0: =========== REGISTER DUMP ===========
[   13.994504] mmc0: SDCMD  0x0000080c
[   13.999848] mmc0: SDARG  0x00000000
[   14.005154] mmc0: SDTOUT 0x00bebc20
[   14.010437] mmc0: SDCDIV 0x00000008
[   14.015650] mmc0: SDRSP0 0x00000c00
[   14.020785] mmc0: SDRSP1 0x00000c0e
[   14.025861] mmc0: SDRSP2 0x7fffffff
[   14.030875] mmc0: SDRSP3 0x0002400c
[   14.035817] mmc0: SDHSTS 0x00000000
[   14.040701] mmc0: SDVDD  0x00000001
[   14.045543] mmc0: SDEDM  0x00010801
[   14.050307] mmc0: SDHCFG 0x0000040e
[   14.055010] mmc0: SDHBCT 0x00000006
[   14.059623] mmc0: SDHBLC 0x00000001
[   14.064169] mmc0: ===========================================

... this repeats forever and the root filesystem never comes up.

@ali1234
Copy link
Contributor Author

ali1234 commented Nov 20, 2015

Now tested with latest kernel. Here is the full kernel log:

Uncompressing Linux... done, booting the kernel.
[    0.000000] Booting Linux on physical CPU 0xf00
[    0.000000] Initializing cgroup subsys cpuset
[    0.000000] Initializing cgroup subsys cpu
[    0.000000] Initializing cgroup subsys cpuacct
[    0.000000] Linux version 4.1.13-v7+ (al@al-desktop) (gcc version 4.8.3 20140106 (prerelease) (crosstool-NG linaro-1.13.1-4.8-2014.01 - Linaro GCC 2013.11) ) #3 SMP PREEMPT Fri Nov 20 06:43:32 GMT 2015
[    0.000000] CPU: ARMv7 Processor [410fc075] revision 5 (ARMv7), cr=10c5387d
[    0.000000] CPU: PIPT / VIPT nonaliasing data cache, VIPT aliasing instruction cache
[    0.000000] Machine model: Raspberry Pi 2 Model B
[    0.000000] cma: Reserved 8 MiB at 0x3a000000
[    0.000000] Memory policy: Data cache writealloc
[    0.000000] [bcm2709_smp_init_cpus] enter (9420->f3003010)
[    0.000000] [bcm2709_smp_init_cpus] ncores=4
[    0.000000] PERCPU: Embedded 13 pages/cpu @ba9e3000 s20608 r8192 d24448 u53248
[    0.000000] Built 1 zonelists in Zone order, mobility grouping on.  Total pages: 239540
[    0.000000] Kernel command line: dma.dmachans=0x7f35 bcm2708_fb.fbwidth=656 bcm2708_fb.fbheight=416 bcm2709.boardrev=0xa01041 bcm2709.serial=0x3c5da33a smsc95xx.macaddr=B8:27:EB:5D:A3:3A bcm2708_fb.fbswap=1 bcm2709.disk_led_gpio=47 bcm2709.disk_led_active_low=0 sdhci-bcm2708.emmc_clock_freq=250000000 vc_mem.mem_base=0x3dc00000 vc_mem.mem_size=0x3f000000  dwc_otg.lpm_enable=0 console=ttyAMA0,115200 kgdboc=ttyAMA0,115200 console=tty1 elevator=deadline root=/dev/mmcblk0p2 rootfstype=ext4 rootwait
[    0.000000] PID hash table entries: 4096 (order: 2, 16384 bytes)
[    0.000000] Dentry cache hash table entries: 131072 (order: 7, 524288 bytes)
[    0.000000] Inode-cache hash table entries: 65536 (order: 6, 262144 bytes)
[    0.000000] Memory: 933556K/966656K available (5967K kernel code, 534K rwdata, 1652K rodata, 420K init, 757K bss, 24908K reserved, 8192K cma-reserved)
[    0.000000] Virtual kernel memory layout:
[    0.000000]     vector  : 0xffff0000 - 0xffff1000   (   4 kB)
[    0.000000]     fixmap  : 0xffc00000 - 0xfff00000   (3072 kB)
[    0.000000]     vmalloc : 0xbb800000 - 0xff000000   (1080 MB)
[    0.000000]     lowmem  : 0x80000000 - 0xbb000000   ( 944 MB)
[    0.000000]     modules : 0x7f000000 - 0x80000000   (  16 MB)
[    0.000000]       .text : 0x80008000 - 0x80778f64   (7620 kB)
[    0.000000]       .init : 0x80779000 - 0x807e2000   ( 420 kB)
[    0.000000]       .data : 0x807e2000 - 0x80867b6c   ( 535 kB)
[    0.000000]        .bss : 0x8086a000 - 0x8092779c   ( 758 kB)
[    0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1
[    0.000000] Preemptible hierarchical RCU implementation.
[    0.000000]  Additional per-CPU info printed with stalls.
[    0.000000] NR_IRQS:608
[    0.000000] Architected cp15 timer(s) running at 19.20MHz (virt).
[    0.000000] clocksource arch_sys_counter: mask: 0xffffffffffffff max_cycles: 0x46d987e47, max_idle_ns: 440795202767 ns
[    0.000011] sched_clock: 56 bits at 19MHz, resolution 52ns, wraps every 4398046511078ns
[    0.000032] Switching to timer-based delay loop, resolution 52ns
[    0.000306] Console: colour dummy device 80x30
[    0.002072] console [tty1] enabled
[    0.002136] Calibrating delay loop (skipped), value calculated using timer frequency.. 38.40 BogoMIPS (lpj=192000)
[    0.002237] pid_max: default: 32768 minimum: 301
[    0.002607] Mount-cache hash table entries: 2048 (order: 1, 8192 bytes)
[    0.002673] Mountpoint-cache hash table entries: 2048 (order: 1, 8192 bytes)
[    0.003995] Initializing cgroup subsys blkio
[    0.004077] Initializing cgroup subsys memory
[    0.004144] Initializing cgroup subsys devices
[    0.004203] Initializing cgroup subsys freezer
[    0.004279] Initializing cgroup subsys net_cls
[    0.004385] CPU: Testing write buffer coherency: ok
[    0.004507] ftrace: allocating 20235 entries in 60 pages
[    0.053989] CPU0: update cpu_capacity 1024
[    0.054071] CPU0: thread -1, cpu 0, socket 15, mpidr 80000f00
[    0.054118] [bcm2709_smp_prepare_cpus] enter
[    0.054281] Setting up static identity map for 0x8240 - 0x8274
[    0.113872] [bcm2709_boot_secondary] cpu:1 started (0) 18
[    0.114302] [bcm2709_secondary_init] enter cpu:1
[    0.114352] CPU1: update cpu_capacity 1024
[    0.114360] CPU1: thread -1, cpu 1, socket 15, mpidr 80000f01
[    0.133849] [bcm2709_boot_secondary] cpu:2 started (0) 17
[    0.134200] [bcm2709_secondary_init] enter cpu:2
[    0.134229] CPU2: update cpu_capacity 1024
[    0.134237] CPU2: thread -1, cpu 2, socket 15, mpidr 80000f02
[    0.153894] [bcm2709_boot_secondary] cpu:3 started (0) 16
[    0.154148] [bcm2709_secondary_init] enter cpu:3
[    0.154176] CPU3: update cpu_capacity 1024
[    0.154184] CPU3: thread -1, cpu 3, socket 15, mpidr 80000f03
[    0.154280] Brought up 4 CPUs
[    0.154415] SMP: Total of 4 processors activated (153.60 BogoMIPS).
[    0.154457] CPU: All CPU(s) started in SVC mode.
[    0.155470] devtmpfs: initialized
[    0.180120] VFP support v0.3: implementor 41 architecture 2 part 30 variant 7 rev 5
[    0.180488] clocksource jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns
[    0.181616] pinctrl core: initialized pinctrl subsystem
[    0.182450] NET: Registered protocol family 16
[    0.188221] DMA: preallocated 4096 KiB pool for atomic coherent allocations
[    0.189475] bcm2709.uart_clock = 3000000
[    0.195205] hw-breakpoint: found 5 (+1 reserved) breakpoint and 4 watchpoint registers.
[    0.195278] hw-breakpoint: maximum watchpoint size is 8 bytes.
[    0.195510] Serial: AMBA PL011 UART driver
[    0.195740] 3f201000.uart: ttyAMA0 at MMIO 0x3f201000 (irq = 83, base_baud = 0) is a PL011 rev2
[    0.696820] console [ttyAMA0] enabled
[    0.701093] bcm2835-mbox 3f00b880.mailbox: mailbox enabled
[    0.776329] bcm2708-dmaengine 3f007000.dma: DMA legacy API manager at f3007000, dmachans=0xf35
[    0.785087] bcm2708-dmaengine 3f007000.dma: Initialized 7 DMA channels (+ 1 legacy)
[    0.793513] bcm2708-dmaengine 3f007000.dma: Load BCM2835 DMA engine driver
[    0.800439] bcm2708-dmaengine 3f007000.dma: dma_debug:0
[    0.806422] SCSI subsystem initialized
[    0.810460] usbcore: registered new interface driver usbfs
[    0.816071] usbcore: registered new interface driver hub
[    0.821560] usbcore: registered new device driver usb
[    0.827346] raspberrypi-firmware soc:firmware: Attached to firmware from 2015-02-12 17:30
[    1.337967] Switched to clocksource arch_sys_counter
[    1.392371] FS-Cache: Loaded
[    1.395647] CacheFiles: Loaded
[    1.410401] NET: Registered protocol family 2
[    1.416078] TCP established hash table entries: 8192 (order: 3, 32768 bytes)
[    1.423347] TCP bind hash table entries: 8192 (order: 4, 65536 bytes)
[    1.430063] TCP: Hash tables configured (established 8192 bind 8192)
[    1.436554] UDP hash table entries: 512 (order: 2, 16384 bytes)
[    1.442584] UDP-Lite hash table entries: 512 (order: 2, 16384 bytes)
[    1.449345] NET: Registered protocol family 1
[    1.454148] RPC: Registered named UNIX socket transport module.
[    1.460168] RPC: Registered udp transport module.
[    1.464898] RPC: Registered tcp transport module.
[    1.469657] RPC: Registered tcp NFSv4.1 backchannel transport module.
[    1.476555] Trying to unpack rootfs image as initramfs...
[    2.120713] Freeing initrd memory: 5940K (baa23000 - baff0000)
[    2.133889] hw perfevents: enabled with armv7_cortex_a7 PMU driver, 5 counters available
[    2.143625] futex hash table entries: 1024 (order: 4, 65536 bytes)
[    2.165637] VFS: Disk quotas dquot_6.6.0
[    2.170121] VFS: Dquot-cache hash table entries: 1024 (order 0, 4096 bytes)
[    2.179720] FS-Cache: Netfs 'nfs' registered for caching
[    2.186214] NFS: Registering the id_resolver key type
[    2.191401] Key type id_resolver registered
[    2.195609] Key type id_legacy registered
[    2.202393] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 252)
[    2.210086] io scheduler noop registered
[    2.214045] io scheduler deadline registered (default)
[    2.219592] io scheduler cfq registered
[    2.226245] BCM2708FB: allocated DMA memory fa400000
[    2.231308] BCM2708FB: allocated DMA channel 0 @ f3007000
[    2.243156] Console: switching to colour frame buffer device 82x26
[    2.255019] Serial: 8250/16550 driver, 0 ports, IRQ sharing disabled
[    2.263802] KGDB: Registered I/O driver kgdboc
[    2.298752] vc-cma: Videocore CMA driver
[    2.304356] vc-cma: vc_cma_base      = 0x00000000
[    2.310721] vc-cma: vc_cma_size      = 0x00000000 (0 MiB)
[    2.317681] vc-cma: vc_cma_initial   = 0x00000000 (0 MiB)
[    2.324826] vc-mem: phys_addr:0x00000000 mem_base=0x3dc00000 mem_size:0x3f000000(1008 MiB)
[    2.351880] brd: module loaded
[    2.365335] loop: module loaded
[    2.371103] vchiq: vchiq_init_state: slot_zero = 0xba480000, is_master = 0
[    2.380519] bcm2835_vchiq 3f00b840.vchiq: failed to set channelbase
[    2.388763] vchiq: could not load vchiq
[    2.394195] bcm2835_vchiq: probe of 3f00b840.vchiq failed with error -1209795328
[    2.404728] Loading iSCSI transport class v2.0-870.
[    2.412120] usbcore: registered new interface driver smsc95xx
[    2.419574] dwc_otg: version 3.00a 10-AUG-2012 (platform bus)
[    2.627292] Core Release: 2.80a
[    2.632088] Setting default values for core params
[    2.638543] Finished setting default values for core params
[    2.846130] Using Buffer DMA mode
[    2.851043] Periodic Transfer Interrupt Enhancement - disabled
[    2.858524] Multiprocessor Interrupt Enhancement - disabled
[    2.865740] OTG VER PARAM: 0, OTG VER FLAG: 0
[    2.871794] Dedicated Tx FIFOs mode
[    2.877362] WARN::dwc_otg_hcd_init:1047: FIQ DMA bounce buffers: virt = 0xba414000 dma = 0xfa414000 len=9024
[    2.890688] FIQ FSM acceleration enabled for :
[    2.890688] Non-periodic Split Transactions
[    2.890688] Periodic Split Transactions
[    2.890688] High-Speed Isochronous Endpoints
[    2.914259] WARN::hcd_init_fiq:412: FIQ on core 1 at 0x80402e88
[    2.921861] WARN::hcd_init_fiq:413: FIQ ASM at 0x804031e4 length 36
[    2.929759] WARN::hcd_init_fiq:438: MPHI regs_base at 0xbb89a000
[    2.937368] dwc_otg 3f980000.usb: DWC OTG Controller
[    2.943964] dwc_otg 3f980000.usb: new USB bus registered, assigned bus number 1
[    2.952942] dwc_otg 3f980000.usb: irq 32, io mem 0x00000000
[    2.960151] Init: Port Power? op_state=1
[    2.965608] Init: Power Port (0)
[    2.970655] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002
[    2.979062] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[    2.987858] usb usb1: Product: DWC OTG Controller
[    2.994127] usb usb1: Manufacturer: Linux 4.1.13-v7+ dwc_otg_hcd
[    3.001712] usb usb1: SerialNumber: 3f980000.usb
[    3.008760] hub 1-0:1.0: USB hub found
[    3.014083] hub 1-0:1.0: 1 port detected
[    3.020483] usbcore: registered new interface driver usb-storage
[    3.028286] mousedev: PS/2 mouse device common for all mice
[    3.036248] bcm2835-cpufreq: min=600000 max=900000
[    3.042894] sdhci: Secure Digital Host Controller Interface driver
[    3.050629] sdhci: Copyright(c) Pierre Ossman
[    3.148077] mmc0: sdhost-bcm2835 loaded - DMA enabled (>1)
[    3.157487] mmc-bcm2835 3f300000.mmc: mmc_debug:0 mmc_debug2:0
[    3.164942] mmc-bcm2835 3f300000.mmc: DMA channels allocated
[    3.208153] sdhci-pltfm: SDHCI platform and OF driver helper
[    3.215963] ledtrig-cpu: registered to indicate activity on CPUs
[    3.218113] Indeed it is in host mode hprt0 = 00021501
[    3.230572] hidraw: raw HID events driver (C) Jiri Kosina
[    3.237567] mmc0: host does not support reading read-only switch, assuming write-enable
[    3.237792] usbcore: registered new interface driver usbhid
[    3.237796] usbhid: USB HID core driver
[    3.238169] Initializing XFRM netlink socket
[    3.238208] NET: Registered protocol family 17
[    3.238376] Key type dns_resolver registered
[    3.238852] Registering SWP/SWPB emulation handler
[    3.239890] registered taskstats version 1
[    3.240203] vc-sm: Videocore shared memory driver
[    3.297716] mmc0: new SD card at address 99d6
[    3.298551] Freeing unused kernel memory: 420K (80779000 - 807e2000)
[    3.312432] mmcblk0: mmc0:99d6 SU02G 1.89 GiB 
[    3.314006]  mmcblk0: p1 p2
[    3.387434] systemd-udevd[79]: starting version 215
[    3.397351] random: systemd-udevd urandom read with 15 bits of entropy available
[    3.398117] usb 1-1: new high-speed USB device number 2 using dwc_otg
[    3.399424] Indeed it is in host mode hprt0 = 00001101
[    3.598581] usb 1-1: New USB device found, idVendor=0424, idProduct=9514
[    3.607213] usb 1-1: New USB device strings: Mfr=0, Product=0, SerialNumber=0
[    3.617282] hub 1-1:1.0: USB hub found
[    3.622980] hub 1-1:1.0: 5 ports detected
[    3.908101] usb 1-1.1: new high-speed USB device number 3 using dwc_otg
[    4.028348] usb 1-1.1: New USB device found, idVendor=0424, idProduct=ec00
[    4.037105] usb 1-1.1: New USB device strings: Mfr=0, Product=0, SerialNumber=0
[    4.049359] smsc95xx v1.0.4
[    4.112221] smsc95xx 1-1.1:1.0 eth0: register 'smsc95xx' at usb-3f980000.usb-1.1, smsc95xx USB 2.0 Ethernet, b8:27:eb:5d:a3:3a
[   13.927996] mmc0: timeout waiting for hardware interrupt.
[   13.935338] mmc0: cmd op 25 arg 0x37a18000 flags 0xb5 - resp 00000900 00000000 00000000 00000000, err 0
[   13.948412] mmc0: data blocks 8 blksz 200 - err 0
[   13.954962] mmc0:>stop op 12 arg 0x0 flags 0x49d - resp 00000000 00000000 00000000 00000000, err 0
[   13.967626] mmc0: =========== REGISTER DUMP ===========
[   13.974740] mmc0: SDCMD  0x0000080c
[   13.980116] mmc0: SDARG  0x00000000
[   13.985455] mmc0: SDTOUT 0x00bebc20
[   13.990766] mmc0: SDCDIV 0x00000008
[   13.996006] mmc0: SDRSP0 0x00000c00
[   14.001169] mmc0: SDRSP1 0x00000c0e
[   14.006275] mmc0: SDRSP2 0x7fffffff
[   14.011308] mmc0: SDRSP3 0x0002400c
[   14.016266] mmc0: SDHSTS 0x00000000
[   14.021147] mmc0: SDVDD  0x00000001
[   14.025984] mmc0: SDEDM  0x00010801
[   14.030756] mmc0: SDHCFG 0x0000040e
[   14.035453] mmc0: SDHBCT 0x00000006
[   14.040063] mmc0: SDHBLC 0x00000001
[   14.044605] mmc0: ===========================================
[   24.068011] mmc0: timeout waiting for hardware interrupt.
[   24.074454] mmc0:>cmd op 13 arg 0x99d60000 flags 0x195 - resp 00000000 00000000 00000000 00000000, err 0
[   24.086001] mmc0: =========== REGISTER DUMP ===========
[   24.092247] mmc0: SDCMD  0x0000000d
[   24.096709] mmc0: SDARG  0x99d60000
[   24.101135] mmc0: SDTOUT 0x00bebc20
[   24.105569] mmc0: SDCDIV 0x00000008
[   24.110004] mmc0: SDRSP0 0x00000900
[   24.114435] mmc0: SDRSP1 0x00000d1f
[   24.118864] mmc0: SDRSP2 0x7fffffff
[   24.123295] mmc0: SDRSP3 0x00030007
[   24.127727] mmc0: SDHSTS 0x00000000
[   24.132156] mmc0: SDVDD  0x00000001
[   24.136581] mmc0: SDEDM  0x00010801
[   24.141007] mmc0: SDHCFG 0x0000040e
[   24.145439] mmc0: SDHBCT 0x00000006
[   24.149864] mmc0: SDHBLC 0x00000001
[   24.154285] mmc0: ===========================================
[   24.161112] mmcblk0: error -110 sending status command, retrying
[   34.188009] mmc0: timeout waiting for hardware interrupt.
[   34.194461] mmc0:>cmd op 13 arg 0x99d60000 flags 0x195 - resp 00000000 00000000 00000000 00000000, err 0
[   34.205972] mmc0: =========== REGISTER DUMP ===========
[   34.212226] mmc0: SDCMD  0x0000000d
[   34.216714] mmc0: SDARG  0x99d60000
[   34.221203] mmc0: SDTOUT 0x00bebc20
[   34.225691] mmc0: SDCDIV 0x00000008
[   34.230179] mmc0: SDRSP0 0x00000900
[   34.234666] mmc0: SDRSP1 0x00000d1f
[   34.239155] mmc0: SDRSP2 0xffffffff
[   34.243643] mmc0: SDRSP3 0x0002400f
[   34.248130] mmc0: SDHSTS 0x00000000
[   34.252617] mmc0: SDVDD  0x00000001
[   34.257104] mmc0: SDEDM  0x00010801
[   34.261592] mmc0: SDHCFG 0x0000040e
[   34.266079] mmc0: SDHBCT 0x00000006
[   34.270567] mmc0: SDHBLC 0x00000001
[   34.275056] mmc0: ===========================================
[   34.281911] mmcblk0: error -110 sending status command, retrying
[   44.307960] mmc0: timeout waiting for hardware interrupt.
[   44.314410] mmc0:>cmd op 13 arg 0x99d60000 flags 0x195 - resp 00000000 00000000 00000000 00000000, err 0
[   44.325921] mmc0: =========== REGISTER DUMP ===========
[   44.332174] mmc0: SDCMD  0x0000000d
[   44.336662] mmc0: SDARG  0x99d60000
[   44.341151] mmc0: SDTOUT 0x00bebc20
[   44.345639] mmc0: SDCDIV 0x00000008
[   44.350128] mmc0: SDRSP0 0x00000900
[   44.354616] mmc0: SDRSP1 0x00000d1f
[   44.359104] mmc0: SDRSP2 0xffffffff
[   44.363592] mmc0: SDRSP3 0x0002400f
[   44.368079] mmc0: SDHSTS 0x00000000
[   44.372568] mmc0: SDVDD  0x00000001
[   44.377056] mmc0: SDEDM  0x00010801
[   44.381545] mmc0: SDHCFG 0x0000040e
[   44.386032] mmc0: SDHBCT 0x00000006
[   44.390521] mmc0: SDHBLC 0x00000001
[   44.395009] mmc0: ===========================================
[   44.401847] mmcblk0: error -110 sending status command, aborting
[   54.428009] mmc0: timeout waiting for hardware interrupt.
[   54.434457] mmc0:>cmd op 13 arg 0x99d60000 flags 0x195 - resp 00000000 00000000 00000000 00000000, err 0
[   54.445970] mmc0: =========== REGISTER DUMP ===========
[   54.452223] mmc0: SDCMD  0x0000000d
[   54.456712] mmc0: SDARG  0x99d60000
[   54.461202] mmc0: SDTOUT 0x00bebc20
[   54.465690] mmc0: SDCDIV 0x00000008
[   54.470178] mmc0: SDRSP0 0x00000900
[   54.474665] mmc0: SDRSP1 0x00000d1f
[   54.479153] mmc0: SDRSP2 0xffffffff
[   54.483641] mmc0: SDRSP3 0x0002400f
[   54.488128] mmc0: SDHSTS 0x00000000
[   54.492615] mmc0: SDVDD  0x00000001
[   54.497104] mmc0: SDEDM  0x00010801
[   54.501592] mmc0: SDHCFG 0x0000040e
[   54.506080] mmc0: SDHBCT 0x00000006
[   54.510569] mmc0: SDHBLC 0x00000001
[   54.515056] mmc0: ===========================================
[   64.528009] mmc0: timeout waiting for hardware interrupt.
[   64.534453] mmc0:>cmd op 13 arg 0x99d60000 flags 0x195 - resp 00000000 00000000 00000000 00000000, err 0
[   64.546002] mmc0: =========== REGISTER DUMP ===========
[   64.552250] mmc0: SDCMD  0x0000000d
[   64.556715] mmc0: SDARG  0x99d60000
[   64.561144] mmc0: SDTOUT 0x00bebc20
[   64.565577] mmc0: SDCDIV 0x00000008
[   64.570008] mmc0: SDRSP0 0x00000900
[   64.574437] mmc0: SDRSP1 0x00000d1f
[   64.578862] mmc0: SDRSP2 0xffffffff
[   64.583290] mmc0: SDRSP3 0x0002400f
[   64.587720] mmc0: SDHSTS 0x00000000
[   64.592148] mmc0: SDVDD  0x00000001
[   64.596573] mmc0: SDEDM  0x00010801
[   64.600998] mmc0: SDHCFG 0x0000040e
[   64.605430] mmc0: SDHBCT 0x00000006
[   64.609854] mmc0: SDHBLC 0x00000001
[   64.614274] mmc0: ===========================================
[   64.765970] random: nonblocking pool is initialized
[   74.648010] mmc0: timeout waiting for hardware interrupt.
[   74.654451] mmc0:>cmd op 13 arg 0x99d60000 flags 0x195 - resp 00000000 00000000 00000000 00000000, err 0
[   74.665949] mmc0: =========== REGISTER DUMP ===========
[   74.672196] mmc0: SDCMD  0x0000000d
[   74.676679] mmc0: SDARG  0x99d60000
[   74.681161] mmc0: SDTOUT 0x00bebc20
[   74.685644] mmc0: SDCDIV 0x00000008
[   74.690128] mmc0: SDRSP0 0x00000900
[   74.694611] mmc0: SDRSP1 0x00000d1f
[   74.699093] mmc0: SDRSP2 0xffffffff
[   74.703576] mmc0: SDRSP3 0x0002400f
[   74.708060] mmc0: SDHSTS 0x00000000
[   74.712545] mmc0: SDVDD  0x00000001
[   74.717030] mmc0: SDEDM  0x00010801
[   74.721515] mmc0: SDHCFG 0x0000040e
[   74.725998] mmc0: SDHBCT 0x00000006
[   74.730481] mmc0: SDHBLC 0x00000001
[   74.734967] mmc0: ===========================================
[   84.768010] mmc0: timeout waiting for hardware interrupt.
[   84.774449] mmc0:>cmd op 13 arg 0x99d60000 flags 0x195 - resp 00000000 00000000 00000000 00000000, err 0
[   84.786000] mmc0: =========== REGISTER DUMP ===========
[   84.792247] mmc0: SDCMD  0x0000000d
[   84.796712] mmc0: SDARG  0x99d60000
[   84.801141] mmc0: SDTOUT 0x00bebc20
[   84.805574] mmc0: SDCDIV 0x00000008
[   84.810005] mmc0: SDRSP0 0x00000900
[   84.814434] mmc0: SDRSP1 0x00000d1f
[   84.818857] mmc0: SDRSP2 0xffffffff
[   84.823287] mmc0: SDRSP3 0x0002400f
[   84.827715] mmc0: SDHSTS 0x00000000
[   84.832141] mmc0: SDVDD  0x00000001
[   84.836565] mmc0: SDEDM  0x00010801
[   84.840989] mmc0: SDHCFG 0x0000040e
[   84.845418] mmc0: SDHBCT 0x00000006
[   84.849842] mmc0: SDHBLC 0x00000001
[   84.854260] mmc0: ===========================================
[   84.861615] mmc0: card 99d6 removed
[   84.861730] ------------[ cut here ]------------
[   84.861758] WARNING: CPU: 0 PID: 111 at fs/block_dev.c:56 __blkdev_put+0x1b0/0x1ec()
[   84.861767] Modules linked in:
[   84.861780] CPU: 0 PID: 111 Comm: fsck.ext4 Not tainted 4.1.13-v7+ #3
[   84.861784] Hardware name: BCM2709
[   84.861823] [<800183dc>] (unwind_backtrace) from [<80013da0>] (show_stack+0x20/0x24)
[   84.861844] [<80013da0>] (show_stack) from [<8055a4ac>] (dump_stack+0x98/0xe0)
[   84.861867] [<8055a4ac>] (dump_stack) from [<80026a48>] (warn_slowpath_common+0x8c/0xc8)
[   84.861889] [<80026a48>] (warn_slowpath_common) from [<80026b40>] (warn_slowpath_null+0x2c/0x34)
[   84.861909] [<80026b40>] (warn_slowpath_null) from [<8017ca3c>] (__blkdev_put+0x1b0/0x1ec)
[   84.861930] [<8017ca3c>] (__blkdev_put) from [<8017d268>] (blkdev_put+0x54/0x140)
[   84.861949] [<8017d268>] (blkdev_put) from [<8017d414>] (blkdev_close+0x28/0x30)
[   84.861968] [<8017d414>] (blkdev_close) from [<80146240>] (__fput+0x90/0x1cc)
[   84.861984] [<80146240>] (__fput) from [<801463f4>] (____fput+0x18/0x1c)
[   84.862003] [<801463f4>] (____fput) from [<80040af8>] (task_work_run+0xc0/0xf0)
[   84.862025] [<80040af8>] (task_work_run) from [<80013614>] (do_work_pending+0xa8/0xc8)
[   84.862044] [<80013614>] (do_work_pending) from [<8000f984>] (work_pending+0xc/0x20)
[   84.862051] ---[ end trace 523104a12fc86831 ]---
[   95.148018] mmc0: timeout waiting for hardware interrupt.
[   95.155279] mmc0:>cmd op 52 arg 0xc00 flags 0x195 - resp 00000000 00000000 00000000 00000000, err 0
[   95.167882] mmc0: =========== REGISTER DUMP ===========
[   95.174903] mmc0: SDCMD  0x00004034
[   95.180137] mmc0: SDARG  0x00000c00
[   95.185310] mmc0: SDTOUT 0x00f00000
[   95.190394] mmc0: SDCDIV 0x0000026f
[   95.195395] mmc0: SDRSP0 0xffffffff
[   95.200313] mmc0: SDRSP1 0x00003f7f
[   95.205186] mmc0: SDRSP2 0x00000000
[   95.210007] mmc0: SDRSP3 0x00000000
[   95.214791] mmc0: SDHSTS 0x00000040
[   95.219547] mmc0: SDVDD  0x00000001
[   95.224276] mmc0: SDEDM  0x00010800
[   95.228957] mmc0: SDHCFG 0x0000040a
[   95.233592] mmc0: SDHBCT 0x00000000
[   95.238183] mmc0: SDHBLC 0x00000000
[   95.242688] mmc0: ===========================================
[  105.267985] mmc0: timeout waiting for hardware interrupt.
[  105.274465] mmc0:>cmd op 52 arg 0x80000c08 flags 0x195 - resp 00000000 00000000 00000000 00000000, err 0
[  105.286011] mmc0: =========== REGISTER DUMP ===========
[  105.292249] mmc0: SDCMD  0x00004034
[  105.296703] mmc0: SDARG  0x80000c08
[  105.301122] mmc0: SDTOUT 0x00f00000
[  105.305548] mmc0: SDCDIV 0x0000026f
[  105.309977] mmc0: SDRSP0 0xffffffff
[  105.314406] mmc0: SDRSP1 0x0000ff7f
[  105.318832] mmc0: SDRSP2 0x0fffffff
[  105.323253] mmc0: SDRSP3 0x00000000
[  105.327679] mmc0: SDHSTS 0x00000040
[  105.332111] mmc0: SDVDD  0x00000001
[  105.336545] mmc0: SDEDM  0x00010800
[  105.340982] mmc0: SDHCFG 0x0000040a
[  105.345421] mmc0: SDHBCT 0x00000000
[  105.349856] mmc0: SDHBLC 0x00000000
[  105.354281] mmc0: ===========================================

@pelwell
Copy link
Contributor

pelwell commented Nov 20, 2015

That doesn't match my experience or understanding.

If your description is correct, I can see an anomaly in your logs - the sdhost overlay should disable the bcm2835-mmc driver, but I can see that both are loaded. A failure to disable the mmc driver (and interface) could leave sdhost driver running but unable to access the SDCard interface since the pins are still mapped to the mmc interface.

Please retest with a stock kernel.

I initially read your problem as being trying to run both at the same time. On re-reading I can see that this may not be the case, but here's my analysis anyway.

The sdhost overlay does three things:

  1. adds a device node for the sdhost driver
  2. maps the SDCard pins (48-53) to the sdhost interface
  3. disables the mmc driver

The sdio overlay does all of those, but also:
4) maps pins 22-27 to the mmc interface
5) re-enables the mmc driver

The sdio overlay actually includes the sdhost overlay so all 5 steps are present, but the end result is effectively 1+2+4.

As you may have worked out by now, order of application is important where overlays overlap.

dtoverlay=sdhost
dtoverlay=sdio

is equivalent to

dtoverlay=sdio

but

dtoverlay=sdio
dtoverlay=sdhost

should be equivalent to

dtoverlay=sdhost

This overlap is hinted at in the README, although it isn't spelled out:

Name:   sdhost
Info:   Selects the bcm2835-sdhost SD/MMC driver, optionally with overclock

vs

Name:   sdio
Info:   Selects the bcm2835-sdhost SD/MMC driver, optionally with overclock,
        and enables SDIO via GPIOs 22-27.

I have just tried all four configurations and, without actually trying to use the GPIO pins for sdio, my experience is sdhost+sdio=sdio, and sdio+sdhost=sdhost.

@ali1234
Copy link
Contributor Author

ali1234 commented Nov 20, 2015

The last log I posted is from a stock kernel which I built this morning according to the cross compiling instructions at https://www.raspberrypi.org/documentation/linux/kernel/building.md
and using commit f2e0b81

When I use a kernel fetched by rpi-update the problem does not happen, but this gives me an extremely out of date kernel version. Here is the log when using such a kernel:

config.txt

[pi2]
kernel=kernel7.img
initramfs initrd.img-3.18.0-trunk-rpi2 followkernel
dtparam=i2c_arm=on
dtoverlay=sdhost

kernel log:

Uncompressing Linux... done, booting the kernel.
[    0.000000] Booting Linux on physical CPU 0xf00
[    0.000000] Initializing cgroup subsys cpu
[    0.000000] Initializing cgroup subsys cpuacct
[    0.000000] Linux version 3.18.13-v7+ (dc4@dc4-XPS13-9333) (gcc version 4.8.3 20140303 (prerelease) (crosstool-NG linaro-1.13.1+bzr2650 - Linaro GCC 2014.03) ) #790 SMP PREEMPT Wed May 20 19:56:14 BST 2015
[    0.000000] CPU: ARMv7 Processor [410fc075] revision 5 (ARMv7), cr=10c5387d
[    0.000000] CPU: PIPT / VIPT nonaliasing data cache, VIPT aliasing instruction cache
[    0.000000] Machine model: Raspberry Pi 2 Model B
[    0.000000] cma: Reserved 8 MiB at 0x3a000000
[    0.000000] Memory policy: Data cache writealloc
[    0.000000] [bcm2709_smp_init_cpus] enter (8620->f3003010)
[    0.000000] [bcm2709_smp_init_cpus] ncores=4
[    0.000000] PERCPU: Embedded 10 pages/cpu @ba9f3000 s11456 r8192 d21312 u40960
[    0.000000] Built 1 zonelists in Zone order, mobility grouping on.  Total pages: 239776
[    0.000000] Kernel command line: dma.dmachans=0x7f35 bcm2708_fb.fbwidth=656 bcm2708_fb.fbheight=416 bcm2709.boardrev=0xa01041 bcm2709.serial=0x3c5da33a smsc95xx.macaddr=B8:27:EB:5D:A3:3A bcm2708_fb.fbswap=1 bcm2709.disk_led_gpio=47 bcm2709.disk_led_active_low=0 sdhci-bcm2708.emmc_clock_freq=250000000 vc_mem.mem_base=0x3dc00000 vc_mem.mem_size=0x3f000000  dwc_otg.lpm_enable=0 console=ttyAMA0,115200 kgdboc=ttyAMA0,115200 console=tty1 elevator=deadline root=/dev/mmcblk0p2 rootfstype=ext4 rootwait
[    0.000000] PID hash table entries: 4096 (order: 2, 16384 bytes)
[    0.000000] Dentry cache hash table entries: 131072 (order: 7, 524288 bytes)
[    0.000000] Inode-cache hash table entries: 65536 (order: 6, 262144 bytes)
[    0.000000] Memory: 934864K/966656K available (5739K kernel code, 397K rwdata, 1756K rodata, 384K init, 763K bss, 31792K reserved)
[    0.000000] Virtual kernel memory layout:
[    0.000000]     vector  : 0xffff0000 - 0xffff1000   (   4 kB)
[    0.000000]     fixmap  : 0xffc00000 - 0xffe00000   (2048 kB)
[    0.000000]     vmalloc : 0xbb800000 - 0xff000000   (1080 MB)
[    0.000000]     lowmem  : 0x80000000 - 0xbb000000   ( 944 MB)
[    0.000000]     modules : 0x7f000000 - 0x80000000   (  16 MB)
[    0.000000]       .text : 0x80008000 - 0x80759fd4   (7496 kB)
[    0.000000]       .init : 0x8075a000 - 0x807ba000   ( 384 kB)
[    0.000000]       .data : 0x807ba000 - 0x8081d6bc   ( 398 kB)
[    0.000000]        .bss : 0x8081d6bc - 0x808dc494   ( 764 kB)
[    0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1
[    0.000000] Preemptible hierarchical RCU implementation.
[    0.000000] NR_IRQS:608
[    0.000000] Architected cp15 timer(s) running at 19.20MHz (virt).
[    0.000015] sched_clock: 56 bits at 19MHz, resolution 52ns, wraps every 3579139424256ns
[    0.000038] Switching to timer-based delay loop, resolution 52ns
[    0.000335] Console: colour dummy device 80x30
[    0.001795] console [tty1] enabled
[    0.001844] Calibrating delay loop (skipped), value calculated using timer frequency.. 38.40 BogoMIPS (lpj=192000)
[    0.001927] pid_max: default: 32768 minimum: 301
[    0.002333] Mount-cache hash table entries: 2048 (order: 1, 8192 bytes)
[    0.002396] Mountpoint-cache hash table entries: 2048 (order: 1, 8192 bytes)
[    0.003656] Initializing cgroup subsys memory
[    0.003744] Initializing cgroup subsys devices
[    0.003816] Initializing cgroup subsys freezer
[    0.003870] Initializing cgroup subsys net_cls
[    0.003919] Initializing cgroup subsys blkio
[    0.004032] CPU: Testing write buffer coherency: ok
[    0.004147] ftrace: allocating 19681 entries in 58 pages
[    0.052910] CPU0: update cpu_capacity 1024
[    0.052990] CPU0: thread -1, cpu 0, socket 15, mpidr 80000f00
[    0.053031] [bcm2709_smp_prepare_cpus] enter
[    0.053183] Setting up static identity map for 0x52c838 - 0x52c86c
[    0.112810] [bcm2709_boot_secondary] cpu:1 started (0) 17
[    0.113127] CPU1: Booted secondary processor
[    0.113135] [bcm2709_secondary_init] enter cpu:1
[    0.113186] CPU1: update cpu_capacity 1024
[    0.113195] CPU1: thread -1, cpu 1, socket 15, mpidr 80000f01
[    0.132800] [bcm2709_boot_secondary] cpu:2 started (0) 18
[    0.133049] CPU2: Booted secondary processor
[    0.133056] [bcm2709_secondary_init] enter cpu:2
[    0.133087] CPU2: update cpu_capacity 1024
[    0.133095] CPU2: thread -1, cpu 2, socket 15, mpidr 80000f02
[    0.152833] [bcm2709_boot_secondary] cpu:3 started (0) 18
[    0.153075] CPU3: Booted secondary processor
[    0.153082] [bcm2709_secondary_init] enter cpu:3
[    0.153110] CPU3: update cpu_capacity 1024
[    0.153118] CPU3: thread -1, cpu 3, socket 15, mpidr 80000f03
[    0.153214] Brought up 4 CPUs
[    0.153336] SMP: Total of 4 processors activated (153.60 BogoMIPS).
[    0.153370] CPU: All CPU(s) started in SVC mode.
[    0.154355] devtmpfs: initialized
[    0.179316] VFP support v0.3: implementor 41 architecture 2 part 30 variant 7 rev 5
[    0.181315] pinctrl core: initialized pinctrl subsystem
[    0.184867] NET: Registered protocol family 16
[    0.190537] DMA: preallocated 4096 KiB pool for atomic coherent allocations
[    0.191754] bcm2709.uart_clock = 3000000
[    0.194979] hw-breakpoint: found 5 (+1 reserved) breakpoint and 4 watchpoint registers.
[    0.195036] hw-breakpoint: maximum watchpoint size is 8 bytes.
[    0.195099] mailbox: Broadcom VideoCore Mailbox driver
[    0.195239] bcm2708_vcio: mailbox at f300b880
[    0.195640] bcm_power: Broadcom power driver
[    0.195678] bcm_power_open() -> 0
[    0.195704] bcm_power_request(0, 8)
[    0.696384] bcm_mailbox_read -> 00000080, 0
[    0.696417] bcm_power_request -> 0
[    0.696575] Serial: AMBA PL011 UART driver
[    0.696727] dev:f1: ttyAMA0 at MMIO 0x3f201000 (irq = 83, base_baud = 0) is a PL011 rev3
[    1.206798] console [ttyAMA0] enabled
[    1.286132] SCSI subsystem initialized
[    1.290156] usbcore: registered new interface driver usbfs
[    1.295829] usbcore: registered new interface driver hub
[    1.301296] usbcore: registered new device driver usb
[    1.308288] Switched to clocksource arch_sys_counter
[    1.343128] FS-Cache: Loaded
[    1.346362] CacheFiles: Loaded
[    1.361089] NET: Registered protocol family 2
[    1.366745] TCP established hash table entries: 8192 (order: 3, 32768 bytes)
[    1.373999] TCP bind hash table entries: 8192 (order: 4, 65536 bytes)
[    1.380726] TCP: Hash tables configured (established 8192 bind 8192)
[    1.387208] TCP: reno registered
[    1.390497] UDP hash table entries: 512 (order: 2, 16384 bytes)
[    1.396484] UDP-Lite hash table entries: 512 (order: 2, 16384 bytes)
[    1.403238] NET: Registered protocol family 1
[    1.408251] RPC: Registered named UNIX socket transport module.
[    1.414230] RPC: Registered udp transport module.
[    1.418971] RPC: Registered tcp transport module.
[    1.423688] RPC: Registered tcp NFSv4.1 backchannel transport module.
[    1.430506] Trying to unpack rootfs image as initramfs...
[    2.070846] Freeing initrd memory: 5940K (baa23000 - baff0000)
[    2.083762] hw perfevents: enabled with armv7_cortex_a7 PMU driver, 5 counters available
[    2.092281] bcm2708_dma: DMA manager at f3007000
[    2.097090] vc-mem: phys_addr:0x00000000 mem_base=0x3dc00000 mem_size:0x3f000000(1008 MiB)
[    2.107000] futex hash table entries: 1024 (order: 4, 65536 bytes)
[    2.113518] audit: initializing netlink subsys (disabled)
[    2.119101] audit: type=2000 audit(1.909:1): initialized
[    2.140721] VFS: Disk quotas dquot_6.5.2
[    2.145028] Dquot-cache hash table entries: 1024 (order 0, 4096 bytes)
[    2.154639] FS-Cache: Netfs 'nfs' registered for caching
[    2.161003] NFS: Registering the id_resolver key type
[    2.166138] Key type id_resolver registered
[    2.170400] Key type id_legacy registered
[    2.175561] msgmni has been set to 1853
[    2.181150] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 252)
[    2.188867] io scheduler noop registered
[    2.192822] io scheduler deadline registered (default)
[    2.198350] io scheduler cfq registered
[    2.205144] BCM2708FB: allocated DMA memory fa400000
[    2.210196] BCM2708FB: allocated DMA channel 0 @ f3007000
[    2.221197] Console: switching to colour frame buffer device 82x26
[    2.233166] bcm2708-dmaengine bcm2708-dmaengine: Load BCM2835 DMA engine driver
[    2.242485] uart-pl011 dev:f1: no DMA platform data
[    2.249068] kgdb: Registered I/O driver kgdboc.
[    2.278866] vc-cma: Videocore CMA driver
[    2.284348] vc-cma: vc_cma_base      = 0x00000000
[    2.290624] vc-cma: vc_cma_size      = 0x00000000 (0 MiB)
[    2.297540] vc-cma: vc_cma_initial   = 0x00000000 (0 MiB)
[    2.316262] brd: module loaded
[    2.326817] loop: module loaded
[    2.332246] vchiq: vchiq_init_state: slot_zero = 0xba480000, is_master = 0
[    2.341423] Loading iSCSI transport class v2.0-870.
[    2.348838] usbcore: registered new interface driver smsc95xx
[    2.356171] dwc_otg: version 3.00a 10-AUG-2012 (platform bus)
[    2.563795] Core Release: 2.80a
[    2.568395] Setting default values for core params
[    2.574662] Finished setting default values for core params
[    2.782149] Using Buffer DMA mode
[    2.786935] Periodic Transfer Interrupt Enhancement - disabled
[    2.794302] Multiprocessor Interrupt Enhancement - disabled
[    2.801447] OTG VER PARAM: 0, OTG VER FLAG: 0
[    2.807330] Dedicated Tx FIFOs mode
[    2.812582] WARN::dwc_otg_hcd_init:1047: FIQ DMA bounce buffers: virt = 0xba414000 dma = 0xfa414000 len=9024
[    2.825482] FIQ FSM acceleration enabled for :
[    2.825482] Non-periodic Split Transactions
[    2.825482] Periodic Split Transactions
[    2.825482] High-Speed Isochronous Endpoints
[    2.848433] WARN::hcd_init_fiq:412: FIQ on core 1 at 0x803db62c
[    2.855982] WARN::hcd_init_fiq:413: FIQ ASM at 0x803db988 length 36
[    2.863888] WARN::hcd_init_fiq:438: MPHI regs_base at 0xbb80a000
[    2.871497] dwc_otg bcm2708_usb: DWC OTG Controller
[    2.877979] dwc_otg bcm2708_usb: new USB bus registered, assigned bus number 1
[    2.886857] dwc_otg bcm2708_usb: irq 32, io mem 0x00000000
[    2.893973] Init: Port Power? op_state=1
[    2.899455] Init: Power Port (0)
[    2.904490] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002
[    2.912894] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[    2.921719] usb usb1: Product: DWC OTG Controller
[    2.927970] usb usb1: Manufacturer: Linux 3.18.13-v7+ dwc_otg_hcd
[    2.935657] usb usb1: SerialNumber: bcm2708_usb
[    2.942675] hub 1-0:1.0: USB hub found
[    2.948004] hub 1-0:1.0: 1 port detected
[    2.954345] usbcore: registered new interface driver usb-storage
[    2.962138] mousedev: PS/2 mouse device common for all mice
[    2.969836] bcm2835-cpufreq: min=600000 max=900000
[    2.976473] sdhci: Secure Digital Host Controller Interface driver
[    2.984211] sdhci: Copyright(c) Pierre Ossman
[    3.010542] DMA channels allocated for the SDHost driver
[    3.068330] Load BCM2835 SDHost driver
[    3.096360] sdhci-pltfm: SDHCI platform and OF driver helper
[    3.104218] ledtrig-cpu: registered to indicate activity on CPUs
[    3.112038] hidraw: raw HID events driver (C) Jiri Kosina
[    3.119289] usbcore: registered new interface driver usbhid
[    3.126438] usbhid: USB HID core driver
[    3.132149] TCP: cubic registered
[    3.137025] Initializing XFRM netlink socket
[    3.142870] NET: Registered protocol family 17
[    3.149010] Key type dns_resolver registered
[    3.155199] Registering SWP/SWPB emulation handler
[    3.162339] registered taskstats version 1
[    3.168202] vc-sm: Videocore shared memory driver
[    3.174561] Indeed it is in host mode hprt0 = 00021501
[    3.188300] [vc_sm_connected_init]: start
[    3.204194] [vc_sm_connected_init]: end - returning 0
[    3.212454] Freeing unused kernel memory: 384K (8075a000 - 807ba000)
[    3.256570] mmc0: host does not support reading read-only switch, assuming write-enable
[    3.268091] mmc0: new SD card at address 99d6
[    3.276442] mmcblk0: mmc0:99d6 SU02G 1.89 GiB 
[    3.285384]  mmcblk0: p1 p2
[    3.303897] systemd-udevd[79]: starting version 215
[    3.313530] random: systemd-udevd urandom read with 5 bits of entropy available
[    3.358541] usb 1-1: new high-speed USB device number 2 using dwc_otg
[    3.378402] Indeed it is in host mode hprt0 = 00001101
[    3.578715] usb 1-1: New USB device found, idVendor=0424, idProduct=9514
[    3.587203] usb 1-1: New USB device strings: Mfr=0, Product=0, SerialNumber=0
[    3.597192] hub 1-1:1.0: USB hub found
[    3.602829] hub 1-1:1.0: 5 ports detected
[    3.859531] EXT4-fs (mmcblk0p2): mounted filesystem with ordered data mode. Opts: (null)
[    3.888499] usb 1-1.1: new high-speed USB device number 3 using dwc_otg
[    4.009758] usb 1-1.1: New USB device found, idVendor=0424, idProduct=ec00
[    4.020292] usb 1-1.1: New USB device strings: Mfr=0, Product=0, SerialNumber=0
[    4.032418] smsc95xx v1.0.4
[    4.092176] smsc95xx 1-1.1:1.0 eth0: register 'smsc95xx' at usb-bcm2708_usb-1.1, smsc95xx USB 2.0 Ethernet, b8:27:eb:5d:a3:3a
[    4.586853] systemd[1]: systemd 215 running in system mode. (+PAM +AUDIT +SELINUX +IMA +SYSVINIT +LIBCRYPTSETUP +GCRYPT +ACL +XZ -SECCOMP -APPARMOR)
[    4.604806] systemd[1]: Detected architecture 'arm'.
[    4.809870] NET: Registered protocol family 10
[    4.818191] systemd[1]: Inserted module 'ipv6'
[    4.826782] systemd[1]: Set hostname to <al-jessie>.
[    5.369105] systemd[1]: Cannot add dependency job for unit display-manager.service, ignoring: Unit display-manager.service failed to load: No such file or directory.
[    5.392848] systemd[1]: Expecting device dev-ttyAMA0.device...
[    5.403473] systemd[1]: Starting Forward Password Requests to Wall Directory Watch.
[    5.415305] systemd[1]: Started Forward Password Requests to Wall Directory Watch.
[    5.426827] systemd[1]: Starting Remote File Systems (Pre).
[    5.436826] systemd[1]: Reached target Remote File Systems (Pre).
[    5.445031] systemd[1]: Starting Dispatch Password Requests to Console Directory Watch.
[    5.457107] systemd[1]: Started Dispatch Password Requests to Console Directory Watch.
[    5.469044] systemd[1]: Starting Paths.
[    5.477314] systemd[1]: Reached target Paths.
[    5.483792] systemd[1]: Starting Encrypted Volumes.
[    5.493148] systemd[1]: Reached target Encrypted Volumes.
[    5.500734] systemd[1]: Starting Arbitrary Executable File Formats File System Automount Point.
[    5.516375] systemd[1]: Set up automount Arbitrary Executable File Formats File System Automount Point.
[    5.529866] systemd[1]: Starting Swap.
[    5.537838] systemd[1]: Reached target Swap.
[    5.544075] systemd[1]: Expecting device dev-mmcblk0p1.device...
[    5.554211] systemd[1]: Starting Root Slice.
[    5.562608] systemd[1]: Created slice Root Slice.
[    5.569146] systemd[1]: Starting User and Session Slice.
[    5.578562] systemd[1]: Created slice User and Session Slice.
[    5.586121] systemd[1]: Starting /dev/initctl Compatibility Named Pipe.
[    5.597039] systemd[1]: Listening on /dev/initctl Compatibility Named Pipe.
[    5.605957] systemd[1]: Starting Delayed Shutdown Socket.
[    5.615614] systemd[1]: Listening on Delayed Shutdown Socket.
[    5.623266] systemd[1]: Starting Journal Socket (/dev/log).
[    5.632941] systemd[1]: Listening on Journal Socket (/dev/log).
[    5.640699] systemd[1]: Starting udev Control Socket.
[    5.649714] systemd[1]: Listening on udev Control Socket.
[    5.656942] systemd[1]: Starting udev Kernel Socket.
[    5.665868] systemd[1]: Listening on udev Kernel Socket.
[    5.673033] systemd[1]: Starting Journal Socket.
[    5.681713] systemd[1]: Listening on Journal Socket.
[    5.688568] systemd[1]: Starting System Slice.
[    5.697054] systemd[1]: Created slice System Slice.
[    5.703794] systemd[1]: Starting File System Check on Root Device...
[    5.717480] systemd[1]: Starting system-getty.slice.
[    5.727106] systemd[1]: Created slice system-getty.slice.
[    5.734378] systemd[1]: Starting system-serial\x2dgetty.slice.
[    5.744713] systemd[1]: Created slice system-serial\x2dgetty.slice.
[    5.753109] systemd[1]: Starting Increase datagram queue length...
[    5.766815] systemd[1]: Starting Restore / save the current clock...
[    5.792776] systemd[1]: Starting Load Kernel Modules...
[    5.807023] systemd[1]: Starting udev Coldplug all Devices...
[    5.821732] systemd[1]: Mounted Huge Pages File System.
[    5.830189] systemd[1]: Starting Create list of required static device nodes for the current kernel...
[    5.920365] systemd[1]: Started Set Up Additional Binary Formats.
[    5.929882] systemd[1]: Mounting POSIX Message Queue File System...
[    5.946314] systemd[1]: Mounting Debug File System...
[    5.964495] systemd[1]: Starting Slices.
[    5.975699] systemd[1]: Reached target Slices.
[    5.989540] systemd[1]: Started Increase datagram queue length.
[    6.008511] systemd[1]: Started Create list of required static device nodes for the current kernel.
[    6.027390] systemd[1]: Mounted POSIX Message Queue File System.
[    6.040153] systemd[1]: Mounted Debug File System.
[    6.052292] systemd[1]: Started Load Kernel Modules.
[    6.069622] systemd[1]: Started File System Check on Root Device.
[    6.095991] systemd[1]: Started Restore / save the current clock.
[    6.108874] systemd[1]: Started udev Coldplug all Devices.
[    6.119795] systemd[1]: Time has been changed
[    6.317542] systemd[1]: Starting Remount Root and Kernel File Systems...
[    6.333480] systemd[1]: Mounting Configuration File System...
[    6.348463] systemd[1]: Mounted FUSE Control File System.
[    6.356542] systemd[1]: Starting Apply Kernel Variables...
[    6.360974] EXT4-fs (mmcblk0p2): re-mounted. Opts: errors=remount-ro
[    6.379572] systemd[1]: Starting Create Static Device Nodes in /dev...
[    6.395423] systemd[1]: Starting Syslog Socket.
[    6.404972] systemd[1]: Listening on Syslog Socket.
[    6.412020] systemd[1]: Starting Journal Service...
[    6.428140] systemd[1]: Started Journal Service.
[    6.631047] systemd-udevd[170]: starting version 215
[    7.087447] bcm2708_i2c 3f804000.i2c: BSC1 Controller at 0x3f804000 (irq 79) (baudrate 100000)
[    7.309642] FAT-fs (mmcblk0p1): Volume was not properly unmounted. Some data may be corrupt. Please run fsck.
[    7.423855] systemd-journald[165]: Received request to flush runtime journal from PID 1
[    8.020992] smsc95xx 1-1.1:1.0 eth0: hardware isn't capable of remote wakeup
[    8.030490] IPv6: ADDRCONF(NETDEV_UP): eth0: link is not ready
[    9.648955] smsc95xx 1-1.1:1.0 eth0: link up, 100Mbps, full-duplex, lpa 0xCDE1
[    9.661338] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready

Raspbian GNU/Linux 8 al-jessie ttyAMA0

al-jessie login: [   17.066480] random: nonblocking pool is initialized

@pelwell
Copy link
Contributor

pelwell commented Nov 20, 2015

For some reason, you are not running the latest rpi-update kernel. If you have a spare SD card, download and install the latest Raspbian, run rpi-update, then try loading the overlay. This will establish a baseline.

@ali1234
Copy link
Contributor Author

ali1234 commented Nov 20, 2015

Just realised this is because I did "rpi-update next" instead of "rpi-update". Retesting now.

@ali1234
Copy link
Contributor Author

ali1234 commented Nov 20, 2015

With rpi-update kernel:

Uncompressing Linux... done, booting the kernel.
[    0.000000] Booting Linux on physical CPU 0xf00
[    0.000000] Initializing cgroup subsys cpuset
[    0.000000] Initializing cgroup subsys cpu
[    0.000000] Initializing cgroup subsys cpuacct
[    0.000000] Linux version 4.1.13-v7+ (dc4@dc4-XPS13-9333) (gcc version 4.8.3 20140303 (prerelease) (crosstool-NG linaro-1.13.1+bzr2650 - Linaro GCC 2014.03) ) #826 SMP PREEMPT Fri Nov 13 20:19:03 GMT 2015
[    0.000000] CPU: ARMv7 Processor [410fc075] revision 5 (ARMv7), cr=10c5387d
[    0.000000] CPU: PIPT / VIPT nonaliasing data cache, VIPT aliasing instruction cache
[    0.000000] Machine model: Raspberry Pi 2 Model B Rev 1.1
[    0.000000] cma: Reserved 8 MiB at 0x3a000000
[    0.000000] Memory policy: Data cache writealloc
[    0.000000] [bcm2709_smp_init_cpus] enter (9420->f3003010)
[    0.000000] [bcm2709_smp_init_cpus] ncores=4
[    0.000000] PERCPU: Embedded 13 pages/cpu @ba9e3000 s20608 r8192 d24448 u53248
[    0.000000] Built 1 zonelists in Zone order, mobility grouping on.  Total pages: 239540
[    0.000000] Kernel command line: dma.dmachans=0x7f35 bcm2708_fb.fbwidth=656 bcm2708_fb.fbheight=416 bcm2709.boardrev=0xa01041 bcm2709.serial=0x3c5da33a smsc95xx.macaddr=B8:27:EB:5D:A3:3A bcm2708_fb.fbswap=1 bcm2709.disk_led_gpio=47 bcm2709.disk_led_active_low=0 sdhci-bcm2708.emmc_clock_freq=250000000 vc_mem.mem_base=0x3dc00000 vc_mem.mem_size=0x3f000000  dwc_otg.lpm_enable=0 console=ttyAMA0,115200 kgdboc=ttyAMA0,115200 console=tty1 elevator=deadline root=/dev/mmcblk0p2 rootfstype=ext4 rootwait
[    0.000000] PID hash table entries: 4096 (order: 2, 16384 bytes)
[    0.000000] Dentry cache hash table entries: 131072 (order: 7, 524288 bytes)
[    0.000000] Inode-cache hash table entries: 65536 (order: 6, 262144 bytes)
[    0.000000] Memory: 933556K/966656K available (5967K kernel code, 534K rwdata, 1652K rodata, 420K init, 757K bss, 24908K reserved, 8192K cma-reserved)
[    0.000000] Virtual kernel memory layout:
[    0.000000]     vector  : 0xffff0000 - 0xffff1000   (   4 kB)
[    0.000000]     fixmap  : 0xffc00000 - 0xfff00000   (3072 kB)
[    0.000000]     vmalloc : 0xbb800000 - 0xff000000   (1080 MB)
[    0.000000]     lowmem  : 0x80000000 - 0xbb000000   ( 944 MB)
[    0.000000]     modules : 0x7f000000 - 0x80000000   (  16 MB)
[    0.000000]       .text : 0x80008000 - 0x80778f64   (7620 kB)
[    0.000000]       .init : 0x80779000 - 0x807e2000   ( 420 kB)
[    0.000000]       .data : 0x807e2000 - 0x80867b6c   ( 535 kB)
[    0.000000]        .bss : 0x8086a000 - 0x8092779c   ( 758 kB)
[    0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1
[    0.000000] Preemptible hierarchical RCU implementation.
[    0.000000]  Additional per-CPU info printed with stalls.
[    0.000000] NR_IRQS:608
[    0.000000] Architected cp15 timer(s) running at 19.20MHz (phys).
[    0.000000] clocksource arch_sys_counter: mask: 0xffffffffffffff max_cycles: 0x46d987e47, max_idle_ns: 440795202767 ns
[    0.000011] sched_clock: 56 bits at 19MHz, resolution 52ns, wraps every 4398046511078ns
[    0.000033] Switching to timer-based delay loop, resolution 52ns
[    0.000317] Console: colour dummy device 80x30
[    0.002120] console [tty1] enabled
[    0.002185] Calibrating delay loop (skipped), value calculated using timer frequency.. 38.40 BogoMIPS (lpj=192000)
[    0.002286] pid_max: default: 32768 minimum: 301
[    0.002662] Mount-cache hash table entries: 2048 (order: 1, 8192 bytes)
[    0.002727] Mountpoint-cache hash table entries: 2048 (order: 1, 8192 bytes)
[    0.004035] Initializing cgroup subsys blkio
[    0.004115] Initializing cgroup subsys memory
[    0.004183] Initializing cgroup subsys devices
[    0.004245] Initializing cgroup subsys freezer
[    0.004321] Initializing cgroup subsys net_cls
[    0.004432] CPU: Testing write buffer coherency: ok
[    0.004548] ftrace: allocating 20235 entries in 60 pages
[    0.054223] CPU0: update cpu_capacity 1024
[    0.054307] CPU0: thread -1, cpu 0, socket 15, mpidr 80000f00
[    0.054353] [bcm2709_smp_prepare_cpus] enter
[    0.054517] Setting up static identity map for 0x8240 - 0x8274
[    0.114094] [bcm2709_boot_secondary] cpu:1 started (0) 17
[    0.114530] [bcm2709_secondary_init] enter cpu:1
[    0.114583] CPU1: update cpu_capacity 1024
[    0.114592] CPU1: thread -1, cpu 1, socket 15, mpidr 80000f01
[    0.134065] [bcm2709_boot_secondary] cpu:2 started (0) 18
[    0.134421] [bcm2709_secondary_init] enter cpu:2
[    0.134454] CPU2: update cpu_capacity 1024
[    0.134462] CPU2: thread -1, cpu 2, socket 15, mpidr 80000f02
[    0.154109] [bcm2709_boot_secondary] cpu:3 started (0) 17
[    0.154367] [bcm2709_secondary_init] enter cpu:3
[    0.154395] CPU3: update cpu_capacity 1024
[    0.154403] CPU3: thread -1, cpu 3, socket 15, mpidr 80000f03
[    0.154497] Brought up 4 CPUs
[    0.154631] SMP: Total of 4 processors activated (153.60 BogoMIPS).
[    0.154672] CPU: All CPU(s) started in HYP mode.
[    0.154708] CPU: Virtualization extensions available.
[    0.155719] devtmpfs: initialized
[    0.180288] VFP support v0.3: implementor 41 architecture 2 part 30 variant 7 rev 5
[    0.180648] clocksource jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns
[    0.181779] pinctrl core: initialized pinctrl subsystem
[    0.182617] NET: Registered protocol family 16
[    0.188422] DMA: preallocated 4096 KiB pool for atomic coherent allocations
[    0.189683] bcm2709.uart_clock = 3000000
[    0.195202] hw-breakpoint: found 5 (+1 reserved) breakpoint and 4 watchpoint registers.
[    0.195275] hw-breakpoint: maximum watchpoint size is 8 bytes.
[    0.195519] Serial: AMBA PL011 UART driver
[    0.195732] 3f201000.uart: ttyAMA0 at MMIO 0x3f201000 (irq = 83, base_baud = 0) is a PL011 rev2
[    0.702788] console [ttyAMA0] enabled
[    0.707065] bcm2835-mbox 3f00b880.mailbox: mailbox enabled
[    0.786579] bcm2708-dmaengine 3f007000.dma: DMA legacy API manager at f3007000, dmachans=0xf35
[    0.795340] bcm2708-dmaengine 3f007000.dma: Initialized 7 DMA channels (+ 1 legacy)
[    0.803760] bcm2708-dmaengine 3f007000.dma: Load BCM2835 DMA engine driver
[    0.810686] bcm2708-dmaengine 3f007000.dma: dma_debug:0
[    0.816668] SCSI subsystem initialized
[    0.820714] usbcore: registered new interface driver usbfs
[    0.826328] usbcore: registered new interface driver hub
[    0.831824] usbcore: registered new device driver usb
[    0.837608] raspberrypi-firmware soc:firmware: Attached to firmware from 2015-11-18 15:43
[    0.873184] Switched to clocksource arch_sys_counter
[    0.927438] FS-Cache: Loaded
[    0.930730] CacheFiles: Loaded
[    0.945463] NET: Registered protocol family 2
[    0.951155] TCP established hash table entries: 8192 (order: 3, 32768 bytes)
[    0.958419] TCP bind hash table entries: 8192 (order: 4, 65536 bytes)
[    0.965134] TCP: Hash tables configured (established 8192 bind 8192)
[    0.971624] UDP hash table entries: 512 (order: 2, 16384 bytes)
[    0.977653] UDP-Lite hash table entries: 512 (order: 2, 16384 bytes)
[    0.984410] NET: Registered protocol family 1
[    0.989217] RPC: Registered named UNIX socket transport module.
[    0.995237] RPC: Registered udp transport module.
[    0.999967] RPC: Registered tcp transport module.
[    1.004724] RPC: Registered tcp NFSv4.1 backchannel transport module.
[    1.011623] Trying to unpack rootfs image as initramfs...
[    1.659432] Freeing initrd memory: 5940K (baa23000 - baff0000)
[    1.672400] hw perfevents: enabled with armv7_cortex_a7 PMU driver, 5 counters available
[    1.682073] futex hash table entries: 1024 (order: 4, 65536 bytes)
[    1.704290] VFS: Disk quotas dquot_6.6.0
[    1.708629] VFS: Dquot-cache hash table entries: 1024 (order 0, 4096 bytes)
[    1.718200] FS-Cache: Netfs 'nfs' registered for caching
[    1.724728] NFS: Registering the id_resolver key type
[    1.729873] Key type id_resolver registered
[    1.734111] Key type id_legacy registered
[    1.740869] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 252)
[    1.748571] io scheduler noop registered
[    1.752530] io scheduler deadline registered (default)
[    1.758075] io scheduler cfq registered
[    1.764730] BCM2708FB: allocated DMA memory fa400000
[    1.769759] BCM2708FB: allocated DMA channel 0 @ f3007000
[    1.780930] Console: switching to colour frame buffer device 82x26
[    1.792520] Serial: 8250/16550 driver, 0 ports, IRQ sharing disabled
[    1.801277] KGDB: Registered I/O driver kgdboc
[    1.853952] vc-cma: Videocore CMA driver
[    1.859558] vc-cma: vc_cma_base      = 0x00000000
[    1.865947] vc-cma: vc_cma_size      = 0x00000000 (0 MiB)
[    1.872907] vc-cma: vc_cma_initial   = 0x00000000 (0 MiB)
[    1.880048] vc-mem: phys_addr:0x00000000 mem_base=0x3dc00000 mem_size:0x3f000000(1008 MiB)
[    1.907230] brd: module loaded
[    1.920666] loop: module loaded
[    1.926359] vchiq: vchiq_init_state: slot_zero = 0xba480000, is_master = 0
[    1.936571] Loading iSCSI transport class v2.0-870.
[    1.944027] usbcore: registered new interface driver smsc95xx
[    1.951360] dwc_otg: version 3.00a 10-AUG-2012 (platform bus)
[    2.158957] Core Release: 2.80a
[    2.163592] Setting default values for core params
[    2.169901] Finished setting default values for core params
[    2.377415] Using Buffer DMA mode
[    2.382228] Periodic Transfer Interrupt Enhancement - disabled
[    2.389654] Multiprocessor Interrupt Enhancement - disabled
[    2.396813] OTG VER PARAM: 0, OTG VER FLAG: 0
[    2.402705] Dedicated Tx FIFOs mode
[    2.408064] WARN::dwc_otg_hcd_init:1047: FIQ DMA bounce buffers: virt = 0xba414000 dma = 0xfa414000 len=9024
[    2.421118] FIQ FSM acceleration enabled for :
[    2.421118] Non-periodic Split Transactions
[    2.421118] Periodic Split Transactions
[    2.421118] High-Speed Isochronous Endpoints
[    2.444391] WARN::hcd_init_fiq:412: FIQ on core 1 at 0x80402c54
[    2.451941] WARN::hcd_init_fiq:413: FIQ ASM at 0x80402fb0 length 36
[    2.459850] WARN::hcd_init_fiq:438: MPHI regs_base at 0xbb89a000
[    2.467485] dwc_otg 3f980000.usb: DWC OTG Controller
[    2.474101] dwc_otg 3f980000.usb: new USB bus registered, assigned bus number 1
[    2.483043] dwc_otg 3f980000.usb: irq 32, io mem 0x00000000
[    2.490257] Init: Port Power? op_state=1
[    2.495739] Init: Power Port (0)
[    2.500766] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002
[    2.509170] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[    2.517991] usb usb1: Product: DWC OTG Controller
[    2.524264] usb usb1: Manufacturer: Linux 4.1.13-v7+ dwc_otg_hcd
[    2.531822] usb usb1: SerialNumber: 3f980000.usb
[    2.538859] hub 1-0:1.0: USB hub found
[    2.544253] hub 1-0:1.0: 1 port detected
[    2.550548] usbcore: registered new interface driver usb-storage
[    2.558339] mousedev: PS/2 mouse device common for all mice
[    2.566280] bcm2835-cpufreq: min=600000 max=900000
[    2.572879] sdhci: Secure Digital Host Controller Interface driver
[    2.580611] sdhci: Copyright(c) Pierre Ossman
[    2.683300] mmc0: sdhost-bcm2835 loaded - DMA enabled (>1)
[    2.690605] sdhci-pltfm: SDHCI platform and OF driver helper
[    2.698484] ledtrig-cpu: registered to indicate activity on CPUs
[    2.706503] hidraw: raw HID events driver (C) Jiri Kosina
[    2.713765] usbcore: registered new interface driver usbhid
[    2.720920] usbhid: USB HID core driver
[    2.726677] Initializing XFRM netlink socket
[    2.732526] NET: Registered protocol family 17
[    2.738745] Key type dns_resolver registered
[    2.743334] Indeed it is in host mode hprt0 = 00021501
[    2.751734] Registering SWP/SWPB emulation handler
[    2.759110] registered taskstats version 1
[    2.764773] mmc0: host does not support reading read-only switch, assuming write-enable
[    2.765039] vc-sm: Videocore shared memory driver
[    2.765051] [vc_sm_connected_init]: start
[    2.765781] [vc_sm_connected_init]: end - returning 0
[    2.794609] mmc0: new SD card at address 99d6
[    2.795305] Freeing unused kernel memory: 420K (80779000 - 807e2000)
[    2.809243] mmcblk0: mmc0:99d6 SU02G 1.89 GiB 
[    2.810808]  mmcblk0: p1 p2
[    2.884210] systemd-udevd[81]: starting version 215
[    2.894258] random: systemd-udevd urandom read with 10 bits of entropy available
[    2.923279] usb 1-1: new high-speed USB device number 2 using dwc_otg
[    2.935555] Indeed it is in host mode hprt0 = 00001101
[    3.133762] usb 1-1: New USB device found, idVendor=0424, idProduct=9514
[    3.142390] usb 1-1: New USB device strings: Mfr=0, Product=0, SerialNumber=0
[    3.155748] hub 1-1:1.0: USB hub found
[    3.161846] hub 1-1:1.0: 5 ports detected
[    3.436699] EXT4-fs (mmcblk0p2): mounted filesystem with ordered data mode. Opts: (null)
[    3.448489] usb 1-1.1: new high-speed USB device number 3 using dwc_otg
[    3.553853] usb 1-1.1: New USB device found, idVendor=0424, idProduct=ec00
[    3.565164] usb 1-1.1: New USB device strings: Mfr=0, Product=0, SerialNumber=0
[    3.578640] smsc95xx v1.0.4
[    3.637375] smsc95xx 1-1.1:1.0 eth0: register 'smsc95xx' at usb-3f980000.usb-1.1, smsc95xx USB 2.0 Ethernet, b8:27:eb:5d:a3:3a
[    4.036546] systemd[1]: systemd 215 running in system mode. (+PAM +AUDIT +SELINUX +IMA +SYSVINIT +LIBCRYPTSETUP +GCRYPT +ACL +XZ -SECCOMP -APPARMOR)
[    4.054611] systemd[1]: Detected architecture 'arm'.
[    4.262809] NET: Registered protocol family 10
[    4.271266] systemd[1]: Inserted module 'ipv6'
[    4.279879] systemd[1]: Set hostname to <al-jessie>.
[    4.401980] uart-pl011 3f201000.uart: no DMA platform data
[    4.785471] systemd[1]: Cannot add dependency job for unit display-manager.service, ignoring: Unit display-manager.service failed to load: No such file or directory.
[    4.809206] systemd[1]: Expecting device dev-ttyAMA0.device...
[    4.819922] systemd[1]: Starting Forward Password Requests to Wall Directory Watch.
[    4.831747] systemd[1]: Started Forward Password Requests to Wall Directory Watch.
[    4.843377] systemd[1]: Starting Remote File Systems (Pre).
[    4.853426] systemd[1]: Reached target Remote File Systems (Pre).
[    4.861580] systemd[1]: Starting Dispatch Password Requests to Console Directory Watch.
[    4.873731] systemd[1]: Started Dispatch Password Requests to Console Directory Watch.
[    4.885776] systemd[1]: Starting Paths.
[    4.894188] systemd[1]: Reached target Paths.
[    4.900672] systemd[1]: Starting Encrypted Volumes.
[    4.910200] systemd[1]: Reached target Encrypted Volumes.
[    4.917834] systemd[1]: Starting Arbitrary Executable File Formats File System Automount Point.
[    4.933652] systemd[1]: Set up automount Arbitrary Executable File Formats File System Automount Point.
[    4.947188] systemd[1]: Starting Swap.
[    4.955250] systemd[1]: Reached target Swap.
[    4.961452] systemd[1]: Expecting device dev-mmcblk0p1.device...
[    4.971626] systemd[1]: Starting Root Slice.
[    4.980088] systemd[1]: Created slice Root Slice.
[    4.986679] systemd[1]: Starting User and Session Slice.
[    4.996132] systemd[1]: Created slice User and Session Slice.
[    5.003779] systemd[1]: Starting /dev/initctl Compatibility Named Pipe.
[    5.014747] systemd[1]: Listening on /dev/initctl Compatibility Named Pipe.
[    5.023712] systemd[1]: Starting Delayed Shutdown Socket.
[    5.033435] systemd[1]: Listening on Delayed Shutdown Socket.
[    5.041060] systemd[1]: Starting Journal Socket (/dev/log).
[    5.050799] systemd[1]: Listening on Journal Socket (/dev/log).
[    5.058640] systemd[1]: Starting udev Control Socket.
[    5.067720] systemd[1]: Listening on udev Control Socket.
[    5.075033] systemd[1]: Starting udev Kernel Socket.
[    5.084073] systemd[1]: Listening on udev Kernel Socket.
[    5.091216] systemd[1]: Starting Journal Socket.
[    5.099961] systemd[1]: Listening on Journal Socket.
[    5.106870] systemd[1]: Starting System Slice.
[    5.115476] systemd[1]: Created slice System Slice.
[    5.122181] systemd[1]: Starting File System Check on Root Device...
[    5.136060] systemd[1]: Starting system-getty.slice.
[    5.146112] systemd[1]: Created slice system-getty.slice.
[    5.153494] systemd[1]: Starting system-serial\x2dgetty.slice.
[    5.164431] systemd[1]: Created slice system-serial\x2dgetty.slice.
[    5.172680] systemd[1]: Starting Increase datagram queue length...
[    5.187924] systemd[1]: Starting Restore / save the current clock...
[    5.239724] systemd[1]: Starting Load Kernel Modules...
[    5.255976] systemd[1]: Starting udev Coldplug all Devices...
[    5.274477] systemd[1]: Mounted Huge Pages File System.
[    5.282318] systemd[1]: Starting Create list of required static device nodes for the current kernel...
[    5.379092] systemd[1]: Started Set Up Additional Binary Formats.
[    5.388751] systemd[1]: Mounting POSIX Message Queue File System...
[    5.404766] systemd[1]: Mounting Debug File System...
[    5.419733] systemd[1]: Starting Slices.
[    5.428717] systemd[1]: Reached target Slices.
[    5.448765] systemd[1]: Started Increase datagram queue length.
[    5.505593] systemd[1]: Started Create list of required static device nodes for the current kernel.
[    5.522887] systemd[1]: Mounted POSIX Message Queue File System.
[    5.534997] systemd[1]: Mounted Debug File System.
[    5.552321] systemd[1]: Started File System Check on Root Device.
[    5.565372] systemd[1]: Started Restore / save the current clock.
[    5.578300] systemd[1]: Started Load Kernel Modules.
[    5.589993] systemd[1]: Started udev Coldplug all Devices.
[    5.611358] systemd[1]: Time has been changed
[    5.809014] systemd[1]: Mounting Configuration File System...
[    5.823031] systemd[1]: Mounted FUSE Control File System.
[    5.831051] systemd[1]: Starting Apply Kernel Variables...
[    5.845636] systemd[1]: Starting Remount Root and Kernel File Systems...
[    5.862040] systemd[1]: Starting Create Static Device Nodes in /dev...
[    5.878115] systemd[1]: Starting Syslog Socket.
[    5.887817] systemd[1]: Listening on Syslog Socket.
[    5.894191] EXT4-fs (mmcblk0p2): re-mounted. Opts: errors=remount-ro
[    5.903119] systemd[1]: Starting Journal Service...
[    5.919283] systemd[1]: Started Journal Service.
[    6.088131] systemd-udevd[178]: starting version 215
[    6.358406] gpiomem-bcm2835 3f200000.gpiomem: Initialised: Registers at 0x3f200000
[    6.434918] bcm2708_i2c 3f804000.i2c: BSC1 Controller at 0x3f804000 (irq 79) (baudrate 100000)
[    6.685509] FAT-fs (mmcblk0p1): Volume was not properly unmounted. Some data may be corrupt. Please run fsck.
[    6.806266] systemd-journald[176]: Received request to flush runtime journal from PID 1
[    7.395978] smsc95xx 1-1.1:1.0 eth0: hardware isn't capable of remote wakeup
[    7.405482] IPv6: ADDRCONF(NETDEV_UP): eth0: link is not ready
[    8.999773] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
[    9.008667] smsc95xx 1-1.1:1.0 eth0: link up, 100Mbps, full-duplex, lpa 0xCDE1

Raspbian GNU/Linux 8 al-jessie ttyAMA0

al-jessie login: [   16.679311] random: nonblocking pool is initialized

@pelwell
Copy link
Contributor

pelwell commented Nov 20, 2015

Now you just have to work out why your kernel is different. Did you update the .dtbs?

@ali1234
Copy link
Contributor Author

ali1234 commented Nov 20, 2015

Well, after reinstalling my own kernel, now it works too. I did install all dtbs and modules, so it must have been a firmware mismatch?

How exactly am I supposed to get a matching firmware for a custom built kernel?

@ali1234
Copy link
Contributor Author

ali1234 commented Nov 20, 2015

Seems like the answer is SKIP_KERNEL=1 rpi-update to get the latest firmware without the kernel.

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

No branches or pull requests

2 participants