Reply To: [SOLVED] HiFiBerry DAC + stopped working

Max2Play Home Forums Max2Play on Raspberry PI [SOLVED] HiFiBerry DAC + stopped working Reply To: [SOLVED] HiFiBerry DAC + stopped working

20. Februar 2017 at 18:22 #27054

I have enabled dtdebug in by boot config as suggested in https://support.hifiberry.com/hc/en-us/articles/205377651-Configuring-Linux-4-x-or-higher and the output of dmesg is

[    0.000000] Booting Linux on physical CPU 0x0
[    0.000000] Initializing cgroup subsys cpuset
[    0.000000] Initializing cgroup subsys cpu
[    0.000000] Initializing cgroup subsys cpuacct
[    0.000000] Linux version 4.4.49-v7+ (dc4@dc4-XPS13-9333) (gcc version 4.9.3 (crosstool-NG crosstool-ng-1.22.0-88-g8460611) ) #968 SMP Fri Feb 17 14:22:28 GMT 2017
[    0.000000] CPU: ARMv7 Processor [410fd034] revision 4 (ARMv7), cr=10c5383d
[    0.000000] CPU: PIPT / VIPT nonaliasing data cache, VIPT aliasing instruction cache
[    0.000000] Machine model: Raspberry Pi 3 Model B Rev 1.2
[    0.000000] cma: Reserved 8 MiB at 0x36800000
[    0.000000] Memory policy: Data cache writealloc
[    0.000000] On node 0 totalpages: 225280
[    0.000000] free_area_init_node: node 0, pgdat 808c5040, node_mem_map b6036000
[    0.000000]   Normal zone: 1980 pages used for memmap
[    0.000000]   Normal zone: 0 pages reserved
[    0.000000]   Normal zone: 225280 pages, LIFO batch:31
[    0.000000] [bcm2709_smp_init_cpus] enter (9520->f3003010)
[    0.000000] [bcm2709_smp_init_cpus] ncores=4
[    0.000000] PERCPU: Embedded 13 pages/cpu @b5ff1000 s22592 r8192 d22464 u53248
[    0.000000] pcpu-alloc: s22592 r8192 d22464 u53248 alloc=13*4096
[    0.000000] pcpu-alloc: [0] 0 [0] 1 [0] 2 [0] 3
[    0.000000] Built 1 zonelists in Zone order, mobility grouping on.  Total pages: 223300
[    0.000000] Kernel command line: 8250.nr_uarts=0 dma.dmachans=0x7f35 bcm2708_fb.fbwidth=656 bcm2708_fb.fbheight=416 bcm2709.boardrev=0xa02082 bcm2709.serial=0x8b98a6f3 smsc95xx.macaddr=B8:27:EB:98:A6:F3 bcm2708_fb.fbswap=1 bcm2709.uart_clock=48000000 vc_mem.mem_base=0x3dc00000 vc_mem.mem_size=0x3f000000  dwc_otg.lpm_enable=0 console=ttyS0,115200 console=tty1 root=/dev/mmcblk0p2 rootfstype=ext4 elevator=deadline fsck.repair=yes 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: 874100K/901120K available (6357K kernel code, 432K rwdata, 1716K rodata, 476K init, 764K bss, 18828K reserved, 8192K cma-reserved)
[    0.000000] Virtual kernel memory layout:
    vector  : 0xffff0000 - 0xffff1000   (   4 kB)
    fixmap  : 0xffc00000 - 0xfff00000   (3072 kB)
    vmalloc : 0xb7800000 - 0xff800000   (1152 MB)
    lowmem  : 0x80000000 - 0xb7000000   ( 880 MB)
    modules : 0x7f000000 - 0x80000000   (  16 MB)
      .text : 0x80008000 - 0x807ea728   (8074 kB)
      .init : 0x807eb000 - 0x80862000   ( 476 kB)
      .data : 0x80862000 - 0x808ce350   ( 433 kB)
       .bss : 0x808d1000 - 0x809901ec   ( 765 kB)
[    0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1
[    0.000000] Hierarchical RCU implementation.
[    0.000000]  Build-time adjustment of leaf fanout to 32.
[    0.000000] NR_IRQS:16 nr_irqs:16 16
[    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.000008] sched_clock: 56 bits at 19MHz, resolution 52ns, wraps every 4398046511078ns
[    0.000025] Switching to timer-based delay loop, resolution 52ns
[    0.000287] Console: colour dummy device 80x30
[    0.001345] console [tty1] enabled
[    0.001389] Calibrating delay loop (skipped), value calculated using timer frequency.. 38.40 BogoMIPS (lpj=192000)
[    0.001457] pid_max: default: 32768 minimum: 301
[    0.001788] Mount-cache hash table entries: 2048 (order: 1, 8192 bytes)
[    0.001831] Mountpoint-cache hash table entries: 2048 (order: 1, 8192 bytes)
[    0.002787] Disabling cpuset control group subsystem
[    0.002845] Initializing cgroup subsys io
[    0.002896] Initializing cgroup subsys memory
[    0.002960] Initializing cgroup subsys devices
[    0.003002] Initializing cgroup subsys freezer
[    0.003045] Initializing cgroup subsys net_cls
[    0.003118] CPU: Testing write buffer coherency: ok
[    0.003204] ftrace: allocating 21245 entries in 63 pages
[    0.052482] CPU0: update cpu_capacity 1024
[    0.052551] CPU0: thread -1, cpu 0, socket 0, mpidr 80000000
[    0.052583] [bcm2709_smp_prepare_cpus] enter
[    0.052747] Setting up static identity map for 0x8240 - 0x8274
[    0.054394] [bcm2709_boot_secondary] cpu:1 started (0) 17
[    0.054611] [bcm2709_secondary_init] enter cpu:1
[    0.054655] CPU1: update cpu_capacity 1024
[    0.054661] CPU1: thread -1, cpu 1, socket 0, mpidr 80000001
[    0.055041] [bcm2709_boot_secondary] cpu:2 started (0) 17
[    0.055205] [bcm2709_secondary_init] enter cpu:2
[    0.055226] CPU2: update cpu_capacity 1024
[    0.055232] CPU2: thread -1, cpu 2, socket 0, mpidr 80000002
[    0.055591] [bcm2709_boot_secondary] cpu:3 started (0) 17
[    0.055721] [bcm2709_secondary_init] enter cpu:3
[    0.055741] CPU3: update cpu_capacity 1024
[    0.055748] CPU3: thread -1, cpu 3, socket 0, mpidr 80000003
[    0.055808] Brought up 4 CPUs
[    0.055906] SMP: Total of 4 processors activated (153.60 BogoMIPS).
[    0.055936] CPU: All CPU(s) started in HYP mode.
[    0.055963] CPU: Virtualization extensions available.
[    0.056589] devtmpfs: initialized
[    0.067650] VFP support v0.3: implementor 41 architecture 3 part 40 variant 3 rev 4
[    0.068019] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns
[    0.068743] pinctrl core: initialized pinctrl subsystem
[    0.069291] NET: Registered protocol family 16
[    0.074450] DMA: preallocated 4096 KiB pool for atomic coherent allocations
[    0.081879] hw-breakpoint: found 5 (+1 reserved) breakpoint and 4 watchpoint registers.
[    0.081951] hw-breakpoint: maximum watchpoint size is 8 bytes.
[    0.082134] Serial: AMBA PL011 UART driver
[    0.082292] uart-pl011 3f201000.uart: could not find pctldev for node /soc/gpio@7e200000/uart0_pins, deferring probe
[    0.082495] bcm2835-mbox 3f00b880.mailbox: mailbox enabled
[    0.144645] bcm2835-dma 3f007000.dma: DMA legacy API manager at f3007000, dmachans=0x1
[    0.145259] SCSI subsystem initialized
[    0.145459] usbcore: registered new interface driver usbfs
[    0.145560] usbcore: registered new interface driver hub
[    0.145673] usbcore: registered new device driver usb
[    0.152080] raspberrypi-firmware soc:firmware: Attached to firmware from 2017-02-20 13:53
[    0.179220] clocksource: Switched to clocksource arch_sys_counter
[    0.224128] FS-Cache: Loaded
[    0.224433] CacheFiles: Loaded
[    0.236765] NET: Registered protocol family 2
[    0.237637] TCP established hash table entries: 8192 (order: 3, 32768 bytes)
[    0.237775] TCP bind hash table entries: 8192 (order: 4, 65536 bytes)
[    0.237986] TCP: Hash tables configured (established 8192 bind 8192)
[    0.238102] UDP hash table entries: 512 (order: 2, 16384 bytes)
[    0.238170] UDP-Lite hash table entries: 512 (order: 2, 16384 bytes)
[    0.238421] NET: Registered protocol family 1
[    0.238782] RPC: Registered named UNIX socket transport module.
[    0.238814] RPC: Registered udp transport module.
[    0.238842] RPC: Registered tcp transport module.
[    0.238870] RPC: Registered tcp NFSv4.1 backchannel transport module.
[    0.239963] hw perfevents: enabled with armv7_cortex_a7 PMU driver, 7 counters available
[    0.241341] futex hash table entries: 1024 (order: 4, 65536 bytes)
[    0.254591] VFS: Disk quotas dquot_6.6.0
[    0.254925] VFS: Dquot-cache hash table entries: 1024 (order 0, 4096 bytes)
[    0.257119] FS-Cache: Netfs 'nfs' registered for caching
[    0.258045] NFS: Registering the id_resolver key type
[    0.258112] Key type id_resolver registered
[    0.258141] Key type id_legacy registered
[    0.260490] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 252)
[    0.260650] io scheduler noop registered
[    0.260687] io scheduler deadline registered (default)
[    0.260758] io scheduler cfq registered
[    0.263343] BCM2708FB: allocated DMA memory f6c10000
[    0.263390] BCM2708FB: allocated DMA channel 0 @ f3007000
[    0.272140] Console: switching to colour frame buffer device 82x26
[    0.280287] bcm2835-rng 3f104000.rng: hwrng registered
[    0.282692] vc-cma: Videocore CMA driver
[    0.285055] vc-cma: vc_cma_base      = 0x00000000
[    0.287425] vc-cma: vc_cma_size      = 0x00000000 (0 MiB)
[    0.289730] vc-cma: vc_cma_initial   = 0x00000000 (0 MiB)
[    0.292117] vc-mem: phys_addr:0x00000000 mem_base=0x3dc00000 mem_size:0x3f000000(1008 MiB)
[    0.311275] brd: module loaded
[    0.321928] loop: module loaded
[    0.324844] vchiq: vchiq_init_state: slot_zero = 0xb6c80000, is_master = 0
[    0.328413] Loading iSCSI transport class v2.0-870.
[    0.331204] usbcore: registered new interface driver smsc95xx
[    0.333467] dwc_otg: version 3.00a 10-AUG-2012 (platform bus)
[    0.535946] Core Release: 2.80a
[    0.538032] Setting default values for core params
[    0.540189] Finished setting default values for core params
[    0.742729] Using Buffer DMA mode
[    0.744890] Periodic Transfer Interrupt Enhancement - disabled
[    0.747127] Multiprocessor Interrupt Enhancement - disabled
[    0.749435] OTG VER PARAM: 0, OTG VER FLAG: 0
[    0.751699] Dedicated Tx FIFOs mode
[    0.754184] WARN::dwc_otg_hcd_init:1047: FIQ DMA bounce buffers: virt = 0xb6c04000 dma = 0xf6c04000 len=9024
[    0.758831] FIQ FSM acceleration enabled for :
Non-periodic Split Transactions
Periodic Split Transactions
High-Speed Isochronous Endpoints
Interrupt/Control Split Transaction hack enabled
[    0.770678] dwc_otg: Microframe scheduler enabled
[    0.770731] WARN::hcd_init_fiq:415: FIQ on core 1 at 0x80448d20
[    0.773165] WARN::hcd_init_fiq:416: FIQ ASM at 0x80449090 length 36
[    0.775533] WARN::hcd_init_fiq:441: MPHI regs_base at 0xb787e000
[    0.777885] dwc_otg 3f980000.usb: DWC OTG Controller
[    0.780213] dwc_otg 3f980000.usb: new USB bus registered, assigned bus number 1
[    0.782572] dwc_otg 3f980000.usb: irq 62, io mem 0x00000000
[    0.784888] Init: Port Power? op_state=1
[    0.787139] Init: Power Port (0)
[    0.789530] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002
[    0.791835] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[    0.794131] usb usb1: Product: DWC OTG Controller
[    0.796373] usb usb1: Manufacturer: Linux 4.4.49-v7+ dwc_otg_hcd
[    0.798637] usb usb1: SerialNumber: 3f980000.usb
[    0.801706] hub 1-0:1.0: USB hub found
[    0.803907] hub 1-0:1.0: 1 port detected
[    0.806605] dwc_otg: FIQ enabled
[    0.806615] dwc_otg: NAK holdoff enabled
[    0.806623] dwc_otg: FIQ split-transaction FSM enabled
[    0.806657] Module dwc_common_port init
[    0.806911] usbcore: registered new interface driver usb-storage
[    0.809342] mousedev: PS/2 mouse device common for all mice
[    0.813280] bcm2835-cpufreq: min=600000 max=1200000
[    0.815708] sdhci: Secure Digital Host Controller Interface driver
[    0.817968] sdhci: Copyright(c) Pierre Ossman
[    0.820517] sdhost: log_buf @ b6c07000 (f6c07000)
[    0.879250] mmc0: sdhost-bcm2835 loaded - DMA enabled (>1)
[    0.883769] mmc-bcm2835 3f300000.mmc: mmc_debug:0 mmc_debug2:0
[    0.886068] mmc-bcm2835 3f300000.mmc: DMA channel allocated
[    0.939332] sdhci-pltfm: SDHCI platform and OF driver helper
[    0.941941] ledtrig-cpu: registered to indicate activity on CPUs
[    0.944315] hidraw: raw HID events driver (C) Jiri Kosina
[    0.946748] usbcore: registered new interface driver usbhid
[    0.949069] usbhid: USB HID core driver
[    0.951884] Initializing XFRM netlink socket
[    0.954149] NET: Registered protocol family 17
[    0.956492] Key type dns_resolver registered
[    0.959148] Registering SWP/SWPB emulation handler
[    0.962145] registered taskstats version 1
[    0.964470] vc-sm: Videocore shared memory driver
[    0.966694] [vc_sm_connected_init]: start
[    0.969383] [vc_sm_connected_init]: end - returning 0
[    0.972881] 3f201000.uart: ttyAMA0 at MMIO 0x3f201000 (irq = 87, base_baud = 0) is a PL011 rev2
[    0.977572] of_cfs_init
[    0.978195] mmc0: host does not support reading read-only switch, assuming write-enable
[    0.981319] mmc0: new high speed SDHC card at address aaaa
[    0.981883] mmcblk0: mmc0:aaaa SL16G 14.8 GiB
[    0.984955]  mmcblk0: p1 p2 p3
[    0.991060] of_cfs_init: OK
[    0.999368] Indeed it is in host mode hprt0 = 00021501
[    1.003123] mmc1: queuing unknown CIS tuple 0x80 (2 bytes)
[    1.006918] mmc1: queuing unknown CIS tuple 0x80 (3 bytes)
[    1.009728] EXT4-fs (mmcblk0p2): mounted filesystem with ordered data mode. Opts: (null)
[    1.010590] mmc1: queuing unknown CIS tuple 0x80 (3 bytes)
[    1.013369] mmc1: queuing unknown CIS tuple 0x80 (7 bytes)
[    1.018675] VFS: Mounted root (ext4 filesystem) readonly on device 179:2.
[    1.029116] devtmpfs: mounted
[    1.032183] Freeing unused kernel memory: 476K (807eb000 - 80862000)
[    1.104397] mmc1: new high speed SDIO card at address 0001
[    1.179270] usb 1-1: new high-speed USB device number 2 using dwc_otg
[    1.181918] Indeed it is in host mode hprt0 = 00001101
[    1.318399] random: systemd: uninitialized urandom read (16 bytes read, 34 bits of entropy available)
[    1.327172] systemd[1]: systemd 215 running in system mode. (+PAM +AUDIT +SELINUX +IMA +SYSVINIT +LIBCRYPTSETUP +GCRYPT +ACL +XZ -SECCOMP -APPARMOR)
[    1.332777] systemd[1]: Detected architecture 'arm'.
[    1.379525] usb 1-1: New USB device found, idVendor=0424, idProduct=9514
[    1.382297] usb 1-1: New USB device strings: Mfr=0, Product=0, SerialNumber=0
[    1.385911] hub 1-1:1.0: USB hub found
[    1.388739] hub 1-1:1.0: 5 ports detected
[    1.438306] NET: Registered protocol family 10
[    1.442397] systemd[1]: Inserted module 'ipv6'
[    1.446735] systemd[1]: Set hostname to <conservatory>.
[    1.545968] random: systemd-sysv-ge: uninitialized urandom read (16 bytes read, 64 bits of entropy available)
[    1.669267] usb 1-1.1: new high-speed USB device number 3 using dwc_otg
[    1.747328] random: systemd-sysv-ge: uninitialized urandom read (16 bytes read, 72 bits of entropy available)
[    1.768091] random: systemd: uninitialized urandom read (16 bytes read, 72 bits of entropy available)
[    1.769605] usb 1-1.1: New USB device found, idVendor=0424, idProduct=ec00
[    1.769614] usb 1-1.1: New USB device strings: Mfr=0, Product=0, SerialNumber=0
[    1.780624] random: systemd: uninitialized urandom read (16 bytes read, 73 bits of entropy available)
[    1.781780] smsc95xx v1.0.4
[    1.790284] random: systemd: uninitialized urandom read (16 bytes read, 74 bits of entropy available)
[    1.810552] random: systemd: uninitialized urandom read (16 bytes read, 74 bits of entropy available)
[    1.817100] random: systemd: uninitialized urandom read (16 bytes read, 74 bits of entropy available)
[    1.823581] random: systemd: uninitialized urandom read (16 bytes read, 75 bits of entropy available)
[    1.842700] smsc95xx 1-1.1:1.0 eth0: register 'smsc95xx' at usb-3f980000.usb-1.1, smsc95xx USB 2.0 Ethernet, b8:27:eb:98:a6:f3
[    1.864082] random: systemd: uninitialized urandom read (16 bytes read, 77 bits of entropy available)
[    1.914885] systemd[1]: [/lib/systemd/system/mpd.service:17] Unknown lvalue 'ControlGroup' in section 'Service'
[    1.921734] systemd[1]: [/lib/systemd/system/mpd.service:20] Unknown lvalue 'ControlGroupAttribute' in section 'Service'
[    2.008390] systemd[1]: Cannot add dependency job for unit display-manager.service, ignoring: Unit display-manager.service failed to load: No such file or directory.
[    2.022135] systemd[1]: Starting Forward Password Requests to Wall Directory Watch.
[    2.029633] systemd[1]: Started Forward Password Requests to Wall Directory Watch.
[    2.036775] systemd[1]: Starting Remote File Systems (Pre).
[    2.044375] systemd[1]: Reached target Remote File Systems (Pre).
[    2.048035] systemd[1]: Starting Arbitrary Executable File Formats File System Automount Point.
[    2.059099] systemd[1]: Set up automount Arbitrary Executable File Formats File System Automount Point.
[    2.066037] systemd[1]: Starting Encrypted Volumes.
[    2.073053] systemd[1]: Reached target Encrypted Volumes.
[    2.076398] systemd[1]: Starting Swap.
[    2.082938] systemd[1]: Reached target Swap.
[    2.086013] systemd[1]: Expecting device dev-mmcblk0p1.device...
[    2.092231] systemd[1]: Starting Root Slice.
[    2.098207] systemd[1]: Created slice Root Slice.
[    2.101009] systemd[1]: Starting User and Session Slice.
[    2.106789] systemd[1]: Created slice User and Session Slice.
[    2.109539] systemd[1]: Starting Delayed Shutdown Socket.
[    2.115160] systemd[1]: Listening on Delayed Shutdown Socket.
[    2.117800] systemd[1]: Starting /dev/initctl Compatibility Named Pipe.
[    2.123323] systemd[1]: Listening on /dev/initctl Compatibility Named Pipe.
[    2.125910] systemd[1]: Starting Journal Socket (/dev/log).
[    2.131374] systemd[1]: Listening on Journal Socket (/dev/log).
[    2.133995] systemd[1]: Starting udev Control Socket.
[    2.139525] systemd[1]: Listening on udev Control Socket.
[    2.142195] systemd[1]: Starting udev Kernel Socket.
[    2.147661] systemd[1]: Listening on udev Kernel Socket.
[    2.150360] systemd[1]: Starting Journal Socket.
[    2.155887] systemd[1]: Listening on Journal Socket.
[    2.158619] systemd[1]: Starting System Slice.
[    2.164160] systemd[1]: Created slice System Slice.
[    2.166805] systemd[1]: Starting File System Check on Root Device...
[    2.209803] systemd[1]: Starting system-systemd\x2dfsck.slice.
[    2.215793] systemd[1]: Created slice system-systemd\x2dfsck.slice.
[    2.218553] systemd[1]: Starting system-getty.slice.
[    2.224392] systemd[1]: Created slice system-getty.slice.
[    2.227282] systemd[1]: Starting Increase datagram queue length...
[    2.235371] systemd[1]: Starting Restore / save the current clock...
[    2.248398] systemd[1]: Mounted Huge Pages File System.
[    2.251737] systemd[1]: Mounting Debug File System...
[    2.308533] systemd[1]: Starting Load Kernel Modules...
[    2.317169] systemd[1]: Starting Create list of required static device nodes for the current kernel...
[    2.329302] systemd[1]: Mounting POSIX Message Queue File System...
[    2.338980] systemd[1]: Starting udev Coldplug all Devices...
[    2.374238] systemd[1]: Started Set Up Additional Binary Formats.
[    2.378424] systemd[1]: Starting Slices.
[    2.385118] systemd[1]: Reached target Slices.
[    2.393887] systemd[1]: Mounted POSIX Message Queue File System.
[    2.399003] fuse init (API version 7.23)
[    2.403047] systemd[1]: Mounted Debug File System.
[    2.410128] systemd[1]: Started Increase datagram queue length.
[    2.425765] systemd[1]: Started Restore / save the current clock.
[    2.434061] systemd[1]: Started Load Kernel Modules.
[    2.441086] systemd[1]: Started Create list of required static device nodes for the current kernel.
[    2.453961] systemd[1]: Time has been changed
[    2.480923] systemd[1]: Started File System Check on Root Device.
[    2.507410] systemd[1]: Started udev Coldplug all Devices.
[    2.623781] systemd[1]: Starting Create Static Device Nodes in /dev...
[    2.679860] systemd[1]: Starting Apply Kernel Variables...
[    2.689132] systemd[1]: Mounting Configuration File System...
[    2.698537] systemd[1]: Mounting FUSE Control File System...
[    2.708098] systemd[1]: Starting Syslog Socket.
[    2.715202] systemd[1]: Listening on Syslog Socket.
[    2.718399] systemd[1]: Starting Journal Service...
[    2.728514] systemd[1]: Started Journal Service.
[    2.887513] systemd-udevd[140]: starting version 215
[    3.279524] bcm2835-wdt 3f100000.watchdog: Broadcom BCM2835 watchdog timer
[    3.296544] bcm2708_i2c 3f804000.i2c: BSC1 Controller at 0x3f804000 (irq 83) (baudrate 100000)
[    3.304128] gpiomem-bcm2835 3f200000.gpiomem: Initialised: Registers at 0x3f200000
[    3.450591] snd-rpi-hifiberry-dacplus soc:sound: ASoC: CODEC DAI pcm512x-hifi not registered
[    3.450619] snd-rpi-hifiberry-dacplus soc:sound: snd_soc_register_card() failed: -517
[    3.566149] EXT4-fs (mmcblk0p2): re-mounted. Opts: (null)
[    3.591013] pcm512x 1-004d: Failed to reset device: -5
[    3.591122] pcm512x: probe of 1-004d failed with error -5
[    3.626992] snd-rpi-hifiberry-dacplus soc:sound: ASoC: CODEC DAI pcm512x-hifi not registered
[    3.627003] snd-rpi-hifiberry-dacplus soc:sound: snd_soc_register_card() failed: -517
[    3.637819] usbcore: registered new interface driver brcmfmac
[    3.637840] snd-rpi-hifiberry-dacplus soc:sound: ASoC: CODEC DAI pcm512x-hifi not registered
[    3.637850] snd-rpi-hifiberry-dacplus soc:sound: snd_soc_register_card() failed: -517
[    3.794937] brcmfmac: brcmf_c_preinit_dcmds: Firmware version = wl0: May 27 2016 00:13:38 version 7.45.41.26 (r640327) FWID 01-df77e4a7
[    3.796831] random: nonblocking pool is initialized
[    3.817988] brcmfmac: brcmf_cfg80211_reg_notifier: not a ISO3166 code
[    3.866269] brcmfmac: power management disabled
[    3.871700] brcmfmac: brcmf_cfg80211_reg_notifier: not a ISO3166 code
[    3.871733] cfg80211: World regulatory domain updated:
[    3.871742] cfg80211:  DFS Master region: unset
[    3.871752] cfg80211:   (start_freq - end_freq @ bandwidth), (max_antenna_gain, max_eirp), (dfs_cac_time)
[    3.871766] cfg80211:   (2402000 KHz - 2472000 KHz @ 40000 KHz), (N/A, 2000 mBm), (N/A)
[    3.871779] cfg80211:   (2457000 KHz - 2482000 KHz @ 40000 KHz), (N/A, 2000 mBm), (N/A)
[    3.871792] cfg80211:   (2474000 KHz - 2494000 KHz @ 20000 KHz), (N/A, 2000 mBm), (N/A)
[    3.871806] cfg80211:   (5170000 KHz - 5250000 KHz @ 80000 KHz, 160000 KHz AUTO), (N/A, 2000 mBm), (N/A)
[    3.871820] cfg80211:   (5250000 KHz - 5330000 KHz @ 80000 KHz, 160000 KHz AUTO), (N/A, 2000 mBm), (0 s)
[    3.871833] cfg80211:   (5490000 KHz - 5730000 KHz @ 160000 KHz), (N/A, 2000 mBm), (0 s)
[    3.871845] cfg80211:   (5735000 KHz - 5835000 KHz @ 80000 KHz), (N/A, 2000 mBm), (N/A)
[    3.871857] cfg80211:   (57240000 KHz - 63720000 KHz @ 2160000 KHz), (N/A, 0 mBm), (N/A)
[    4.127393] systemd-journald[138]: Received request to flush runtime journal from PID 1
[    4.744182] Adding 102396k swap on /var/swap.  Priority:-1 extents:7 across:307200k SSFS
[    4.940576] smsc95xx 1-1.1:1.0 eth0: hardware isn't capable of remote wakeup
[    4.980796] brcmfmac: brcmf_add_if: ERROR: netdev:wlan0 already exists
[    4.980808] brcmfmac: brcmf_add_if: ignore IF event
[    4.985011] brcmfmac: power management disabled
[    6.535628] smsc95xx 1-1.1:1.0 eth0: link up, 100Mbps, full-duplex, lpa 0xCDE1

And the output of sudo vcdbg log msg is;


001106.835: HDMI:EDID error reading EDID block 0 attempt 0
001108.099: HDMI:EDID error reading EDID block 0 attempt 1
001109.358: HDMI:EDID error reading EDID block 0 attempt 2
001110.616: HDMI:EDID error reading EDID block 0 attempt 3
001111.875: HDMI:EDID error reading EDID block 0 attempt 4
001113.132: HDMI:EDID error reading EDID block 0 attempt 5
001114.391: HDMI:EDID error reading EDID block 0 attempt 6
001115.648: HDMI:EDID error reading EDID block 0 attempt 7
001116.907: HDMI:EDID error reading EDID block 0 attempt 8
001118.164: HDMI:EDID error reading EDID block 0 attempt 9
001119.186: HDMI:EDID giving up on reading EDID block 0
001133.011: HDMI:Setting property pixel encoding to Default
001133.031: HDMI:Setting property pixel clock type to PAL
001133.050: HDMI:Setting property content type flag to No data
001133.069: HDMI:Setting property fuzzy format match to enabled
001376.770: hdmi: HDMI:hdmi_get_state is deprecated, use hdmi_get_display_state instead
001376.806: hdmi: Setting state machine clock to 163682864 Hz
001377.859: hdmi: requested state machine clock @ 163682864 Hz, measured as 163683000 Hz
001377.876: hdmi: HDMI:>>>>>>>>>>>>>Rx sensed, reading EDID<<<<<<<<<<<<<
001378.172: hdmi: HDMI:EDID error reading EDID block 0 attempt 0
001379.432: hdmi: HDMI:EDID error reading EDID block 0 attempt 1
001380.693: hdmi: HDMI:EDID error reading EDID block 0 attempt 2
001381.954: hdmi: HDMI:EDID error reading EDID block 0 attempt 3
001383.215: hdmi: HDMI:EDID error reading EDID block 0 attempt 4
001384.476: hdmi: HDMI:EDID error reading EDID block 0 attempt 5
001385.737: hdmi: HDMI:EDID error reading EDID block 0 attempt 6
001386.998: hdmi: HDMI:EDID error reading EDID block 0 attempt 7
001388.259: hdmi: HDMI:EDID error reading EDID block 0 attempt 8
001389.520: hdmi: HDMI:EDID error reading EDID block 0 attempt 9
001390.545: hdmi: HDMI:EDID giving up on reading EDID block 0
001390.576: hdmi: HDMI: No lookup table for resolution group 0
001390.594: hdmi: HDMI: hotplug attached with DVI support
001390.625: hdmi: HDMI:hdmi_get_state is deprecated, use hdmi_get_display_state instead
001390.916: hdmi: HDMI:EDID error reading EDID block 0 attempt 0
001392.179: hdmi: HDMI:EDID error reading EDID block 0 attempt 1
001393.442: hdmi: HDMI:EDID error reading EDID block 0 attempt 2
001394.705: hdmi: HDMI:EDID error reading EDID block 0 attempt 3
001395.968: hdmi: HDMI:EDID error reading EDID block 0 attempt 4
001397.231: hdmi: HDMI:EDID error reading EDID block 0 attempt 5
001398.494: hdmi: HDMI:EDID error reading EDID block 0 attempt 6
001399.757: hdmi: HDMI:EDID error reading EDID block 0 attempt 7
001401.020: hdmi: HDMI:EDID error reading EDID block 0 attempt 8
001402.283: hdmi: HDMI:EDID error reading EDID block 0 attempt 9
001403.309: hdmi: HDMI:EDID giving up on reading EDID block 0
001405.655: hdmi: HDMI: hotplug deassert
001405.668: hdmi: HDMI: HDMI is currently off
001405.681: hdmi: HDMI: changing mode to unplugged
001405.704: hdmi: HDMI:hdmi_get_state is deprecated, use hdmi_get_display_state instead
001408.748: *** Restart logging
001409.938: Read command line from file 'cmdline.txt'
dwc_otg.lpm_enable=0 console=serial0,115200 console=tty1 root=/dev/mmcblk0p2 rootfstype=ext4 elevator=deadline fsck.repair=yes rootwait
001664.090: Loading 'kernel7.img' to 0x8000 size 0x409768
001673.650: No kernel trailer (run mkknlimg to fix) - assuming DT-capable
001681.140: Loading 'bcm2710-rpi-3-b.dtb' to 0x411768 size 0x3e78
001692.340: dtdebug: delete_node(/__local_fixups__)
001698.632: dtdebug: /aliases:i2c_vc=i2c0
001704.260: dtdebug: /__symbols__:i2c_vc=i2c0
001708.768: dtdebug: /__overrides__:i2c_vc=i2c0
001717.490: dtdebug: /__overrides__:i2c_vc_baudrate=i2c0_baudrate
001720.571: dtdebug: /aliases:i2c=i2c1
001726.412: dtdebug: /__symbols__:i2c=i2c1
001731.014: dtdebug: /__overrides__:i2c=i2c1
001734.128: dtdebug: /aliases:i2c_arm=i2c1
001739.998: dtdebug: /__symbols__:i2c_arm=i2c1
001744.628: dtdebug: /__overrides__:i2c_arm=i2c1
001753.535: dtdebug: /__overrides__:i2c_baudrate=i2c1_baudrate
001762.489: dtdebug: /__overrides__:i2c_arm_baudrate=i2c1_baudrate
001762.518: dtparam: uart0_clkrate=48000000
001765.529: dtdebug: Found override uart0_clkrate
001765.579: dtdebug:   override uart0_clkrate: cell target clock-frequency @ offset 0 (size 4)
001781.362: dtparam: audio=off
001784.516: dtdebug: Found override audio
001784.551: dtdebug:   override audio: string target 'status'
001797.387: dtdebug: Opened overlay file 'overlays/hifiberry-dacplus.dtbo'
001815.748: Loaded overlay 'hifiberry-dacplus'
001815.802: dtdebug: Found fragment 0 (offset 36)
001822.038: dtdebug: merge_fragment(/clocks,/fragment@0/__overlay__)
001827.032: dtdebug: merge_fragment(/clocks/dacpro_osc,/fragment@0/__overlay__/dacpro_osc)
001827.059: dtdebug:   +prop(compatible)
001827.841: dtdebug:   +prop(#clock-cells)
001828.720: dtdebug:   +prop(phandle)
001829.586: dtdebug: merge_fragment() end
001829.614: dtdebug: merge_fragment() end
001829.688: dtdebug: Found fragment 1 (offset 184)
001834.415: dtdebug: merge_fragment(/soc/i2s@7e203000,/fragment@1/__overlay__)
001834.441: dtdebug:   +prop(status)
001835.959: dtdebug: merge_fragment() end
001836.015: dtdebug: Found fragment 2 (offset 260)
001844.560: dtdebug: merge_fragment(/soc/i2c@7e804000,/fragment@2/__overlay__)
001844.587: dtdebug:   +prop(#address-cells)
001845.700: dtdebug:   +prop(#size-cells)
001846.820: dtdebug:   +prop(status)
001851.940: dtdebug: merge_fragment(/soc/i2c@7e804000/pcm5122@4d,/fragment@2/__overlay__/pcm5122@4d)
001851.967: dtdebug:   +prop(#sound-dai-cells)
001853.175: dtdebug:   +prop(compatible)
001854.263: dtdebug:   +prop(reg)
001855.423: dtdebug:   +prop(clocks)
001856.579: dtdebug:   +prop(status)
001857.798: dtdebug: merge_fragment() end
001857.829: dtdebug: merge_fragment() end
001857.910: dtdebug: Found fragment 3 (offset 480)
001868.699: dtdebug: merge_fragment(/soc/sound,/fragment@3/__overlay__)
001868.727: dtdebug:   +prop(compatible)
001869.618: dtdebug:   +prop(i2s-controller)
001870.921: dtdebug:   +prop(status)
001871.816: dtdebug: merge_fragment() end
001876.084: dtdebug: /aliases:serial0=uart1
001879.241: dtdebug: /aliases:serial1=uart0
001879.400: dtparam: uart1=off
001882.501: dtdebug: Found override uart1
001882.535: dtdebug:   override uart1: string target 'status'
002756.573: dtparam: arm_freq=1200000000
002759.785: dtdebug: Found override arm_freq
002759.835: dtdebug:   override arm_freq: cell target clock-frequency @ offset 0 (size 4)
002770.128: dtdebug:   override arm_freq: cell target clock-frequency @ offset 0 (size 4)
002780.503: dtdebug:   override arm_freq: cell target clock-frequency @ offset 0 (size 4)
002790.973: dtdebug:   override arm_freq: cell target clock-frequency @ offset 0 (size 4)
002803.838: dtparam: core_freq=400000000
002807.178: dtdebug: Found override core_freq
002807.226: dtdebug:   override core_freq: cell target clock-frequency @ offset 0 (size 4)
002815.989: dtparam: cache_line_size=64
002819.175: dtdebug: Found override cache_line_size
002819.223: dtdebug:   override cache_line_size: cell target cache-line-size @ offset 0 (size 4)
002831.023: dtdebug: delete_node(/hat)
002838.614: Device tree loaded to 0x2effbb00 (size 0x447e)
002844.128: gpioman: gpioman_get_pin_num: pin SDCARD_CONTROL_POWER not defined
003587.256: vchiq_core: vchiq_init_state: slot_zero = 0xf6c80000, is_master = 1
003591.461: hdmi: HDMI:hdmi_get_state is deprecated, use hdmi_get_display_state instead
003592.713: cec: setting callback (0x3DCA9D08)