search

raspberrypi / linux

Kernel source tree for Raspberry Pi-provided kernel builds. Issues unrelated to the linux kernel should be posted on the community forum at https://forums.raspberrypi.com/
Other
11.07k stars 4.97k forks source link

Pi 5 and soundcards - problems and solutions #5743

Open pelwell opened 10 months ago

pelwell commented 10 months ago

Describe the bug

This issue is meant to be a common place to discuss the changes required for I2S support on Pi 5. Existing issues that cover this area are https://github.com/raspberrypi/linux/issues/5724 and https://github.com/raspberrypi/linux/issues/5741, and some of the content below is copied from them.

Pi 5 (specifically RP1) has slightly different I2S capabilities than those found on the BCM2835 family of processors. It gains the ability to do dual- and quad-lane I2S, but it has separate clock producer (master) and clock consumer (slave) blocks. This means that each overlay has to specify the correct I2S controller - producer or consumer. For most soundcards this is a fixed property, but a few of them can operate in either mode, which causes a problem.

The addition of a "slave" property was a way to solve the problem, but this requires user intervention (and knowledge). A better solution might be to give the overlays for those flexible cards two different i2s-controller properties (or a single property with two label references) - one for each scenario - and modify the driver to choose the correct one at runtime.

There can also be problems for Audio HATs with EEPROMs that have embedded overlays, rather than just including the name of an overlay. By counting how many cards use the I2S interface in producer mode and how many in consumer mode, the old label i2s was added as an alias for the clock producer block, but for some of the cards this is the wrong choice. If this is wrong for a soundcard with an embedded overlay then there is no choice but to suppress the embedded overlay and load one from the OS image instead (unless the EEPROM can be rewritten).

Putting dtoverlay= in config.txt before any other dt settings disables the loading of the overlay from the HAT EEPROM. The preferred overlay can then be loaded in the usual way. Alternatively, if all the instances of a soundcard have been programmed with the same UUID then a rule can be added to the hat_map, an example of which can be seen in #5742.

pelwell commented 10 months ago

@gtrainavicius @j-schambacher This is a more open and more efficient place to discuss the required changes than individual issues or private emails.

j-schambacher commented 10 months ago

@pelwell Thanks Phil, for aligning things here. I will summarize our findings and post here.

gtrainavicius commented 10 months ago

Full duplex mode is not working with Pisound, for example, starting audio output in one terminal:

speaker-test -c2 -D hw:pisound -r 48000 -t sine

Then starting arecord:

arecord -D hw:pisound -r 48000 -f s16_le > /dev/null

Cuts audio output off immediately, speaker-test gets stuck, and eventually gives -5 (-EIO) error. dmesg does not log anything at all at the moment this happens. Eventually I see these messages after stopping the audio commands, not sure if they're relevant:

[323831.447683] dma dma2chan2: dma2chan2 failed to stop
[323905.772971] dma dma2chan2: dma2chan2 is non-idle!
[323922.367335] dma dma2chan2: dma2chan2 failed to stop

The Jack backend does not manage to start in full duplex mode:

pi@raspberrypi:~ $ JACK_NO_AUDIO_RESERVATION=1 sudo -E /usr/bin/jackd -t 2000 -R -P 95 -d alsa -d hw:pisound -r 48000 -p 128 -n 2 -X seq -s -S

...

ALSA: poll time out, polled for 3998998 usecs, Retrying with a recovery, retry cnt = 1
ALSA: poll time out, polled for 3999003 usecs, Retrying with a recovery, retry cnt = 2
ALSA: poll time out, polled for 3998998 usecs, Retrying with a recovery, retry cnt = 3
ALSA: poll time out, polled for 3998998 usecs, Retrying with a recovery, retry cnt = 4
ALSA: poll time out, polled for 3999003 usecs, Retrying with a recovery, retry cnt = 5
ALSA: poll time out, polled for 3999001 usecs, Reached max retry cnt = 5, Exiting
JackAudioDriver::ProcessAsync: read error, stopping...

Does this issue fall under this umbrella, or should I create a dedicated one?

pelwell commented 10 months ago

You've been beaten to it: https://github.com/raspberrypi/linux/issues/5747

pelwell commented 10 months ago

5757 is a potential fix for #5747.

j-schambacher commented 10 months ago

@pelwell 1) Sorry for the delay, I was beaten up with other stuff. I was wondering how we should approach the correct controller/target setup for the new I2S module. It's a 'first come, first wins' solution. It means the first DT definition loads the respective module and pin configuration. Any later module or DT definition fails, especially the former technique where the driver switched BCLK/LRCLK between controller/target. Without additional code for the PI5 this 'autodetect' will never work. Do you agree? This means (w/o driver change), the potentially best way is your suggestion to use different DT-overlay definitions, which still is a 'challenge' for the existing HATs w/o UUID. But I wonder, why it seems sometimes the controller-module/DT is loaded before the card-DT is loaded requiring the target-module and fails. Is there any DT config which loads the I2S controller module per se?

2) Meanwhile I got the 8 channels running on the DAC side but I need to continue work on the driver side. It somehow interferes with 1) as we need to use again a different DT-overlay including additional pin configs.

j-schambacher commented 10 months ago

@pelwell I know -off topic, but I don't know where to place it best. It's not a bug or solely related to PI5. You may remember we are working on an amplifier which uses TAS575x in controller mode. Meanwhile, we have the necessary patches in the upstream kernel. https://git.kernel.org/pub/scm/linux/kernel/git/broonie/sound.git/commit/?id=736b884a7b68c4eeb66dbf75b97c8ec9b9eeff7f https://git.kernel.org/pub/scm/linux/kernel/git/broonie/sound.git/commit/?id=1f817805262c2c34142291da376d4932d3c493bc It has been merged into the 6.7-rc1. What do you suggest how and when we can pull it into the raspberry Linux?

pelwell commented 10 months ago

We're very happy to take back-ports. Just cut-and-paste that into a new issue and it will be dealt with promptly.

I hope to put together some answers and suggestions in the next day or two, but I agree that setting the pinmux is the main hurdle to choosing the I2S controller at runtime.

pelwell commented 10 months ago

Just cut-and-paste that into a new issue and it will be dealt with promptly.

On second thoughts, don't - I'll just do it

pelwell commented 10 months ago

Done.

j-schambacher commented 10 months ago

Done.

@pelwell Thanks Phil!

And I'll dig next week into the I2S issues while continuing work on the 8 channel driver. Maybe using ofchangesets like I've done on the optional headphone amp in the dacplus driver code could be an option and allow DT changes during runtime. Just thoughts so far.

clone206 commented 7 months ago

Using i-sabre-q2m overlay with an i2s reclocker HAT is limited to 192KHz sampling rates on the pi 5.

Manual/data sheet for HAT is here: https://github.com/iancanada/DocumentDownload/blob/master/FifoPi/FifoPiQ7/FifoPiQ7Manual.pdf

It specifies that you can use the overlay mentioned above or the generic i2s dac overlay (my understanding is that's the "hifiberry-dac" overlay). I have tried with both overlays and encounter the same sample rate limitation on the pi 5. Also I can't pass DoP through to my DAC over LVDS on the pi 5 whereas I can on the pi 4. Just get low level noise at 176.4KHz PCM rate.

On the pi 4 with the same kernel and overlays the HAT can accept up to 384KHz sample rates and DoP works.

clone206@streamer:~ $ uname -a
Linux streamer 6.6.16-v8-16k+ #3 SMP PREEMPT Wed Feb 14 22:08:37 PST 2024 aarch64 GNU/Linux
clone206@streamer:~ $
clone206@streamer:~ $ alsacap
*** Scanning for playback devices ***
Card 0, ID `DAC', name `I-Sabre Q2M DAC'
  Device 0, ID `I-Sabre Q2M DAC i-sabre-codec-dai-0', name `I-Sabre Q2M DAC i-sabre-codec-dai-0', 1 subdevices (1 available)
    2 channels, sampling rate 8000..384000 Hz
    Sample formats: S16_LE, S32_LE
      Subdevice 0, name `subdevice #0'
clone206@streamer:~ $
clone206@streamer:~ $ lsmod |grep sabre
snd_soc_i_sabre_codec    49152  1
regmap_i2c             49152  1 snd_soc_i_sabre_codec
snd_soc_i_sabre_q2m    49152  1
snd_soc_core          327680  5 snd_soc_i_sabre_q2m,vc4,snd_soc_hdmi_codec,designware_i2s,snd_soc_i_sabre_codec
snd_pcm               163840  8 snd_soc_i_sabre_q2m,snd_soc_hdmi_codec,designware_i2s,snd_compress,snd_soc_i_sabre_codec,snd_soc_core,snd_pcm_dmaengine

config.txt:

dtparam=i2c_arm=on
force_eeprom_read=0
#dtoverlay=i2c0-pi5,baudrate=1000000
#dtparam=i2s=on
#dtparam=spi=on
dtparam=pwr_led_trigger=default-on
dtparam=pwr_led_activelow=off
dtparam=act_led_trigger=default-on
dtparam=act_led_activelow=off
dtparam=eth_led0=14
dtparam=eth_led1=14
dtoverlay=disable-wifi
dtoverlay=disable-bt

# Enable audio (loads snd_bcm2835)
dtparam=audio=off

#dtoverlay=hifiberry-dac
dtoverlay=i-sabre-q2m,slave
#dtoverlay=i2s-dac,slave

# Additional overlays and parameters are documented
# /boot/firmware/overlays/README

# Automatically load overlays for detected cameras
#camera_auto_detect=1

# Automatically load overlays for detected DSI displays
#display_auto_detect=1

# Automatically load initramfs files, if found
auto_initramfs=1

# Enable DRM VC4 V3D driver
#dtoverlay=vc4-kms-v3d
#max_framebuffers=2

# Don't have the firmware create an initial video= setting in cmdline.txt.
# Use the kernel's default instead.
disable_fw_kms_setup=1

# Run in 64-bit mode
arm_64bit=1

# Disable compensation for displays with overscan
disable_overscan=1

# Run as fast as firmware / board allows
#arm_boost=1

[cm4]
# Enable host mode on the 2711 built-in XHCI USB controller.
# This line should be removed if the legacy DWC2 controller is required
# (e.g. for USB device mode) or if USB support is not required.
#otg_mode=1

[all]

dmesg:

[    0.000000] Booting Linux on physical CPU 0x0000000000 [0x414fd0b1]
[    0.000000] Linux version 6.6.16-v8-16k+ (clone206@streamer) (gcc (Debian 12.2.0-14) 12.2.0, GNU ld (GNU Binutils for Debian) 2.40) #3 SMP PREEMPT Wed Feb 14 22:08:37 PST 2024
[    0.000000] KASLR enabled
[    0.000000] random: crng init done
[    0.000000] Machine model: Raspberry Pi 5 Model B Rev 1.0
[    0.000000] efi: UEFI not found.
[    0.000000] Reserved memory: created CMA memory pool at 0x0000000002000000, size 64 MiB
[    0.000000] OF: reserved mem: initialized node linux,cma, compatible id shared-dma-pool
[    0.000000] OF: reserved mem: 0x0000000002000000..0x0000000005ffffff (65536 KiB) map reusable linux,cma
[    0.000000] OF: reserved mem: 0x0000000000000000..0x000000000007ffff (512 KiB) nomap non-reusable atf@0
[    0.000000] OF: reserved mem: 0x000000003fd16720..0x000000003fd16756 (0 KiB) nomap non-reusable nvram@0
[    0.000000] Zone ranges:
[    0.000000]   DMA      [mem 0x0000000000000000-0x00000000ffffffff]
[    0.000000]   DMA32    empty
[    0.000000]   Normal   empty
[    0.000000] Movable zone start for each node
[    0.000000] Early memory node ranges
[    0.000000]   node   0: [mem 0x0000000000000000-0x000000000007ffff]
[    0.000000]   node   0: [mem 0x0000000000080000-0x000000003fbfffff]
[    0.000000]   node   0: [mem 0x0000000040000000-0x00000000ffffffff]
[    0.000000] Initmem setup node 0 [mem 0x0000000000000000-0x00000000ffffffff]
[    0.000000] On node 0, zone DMA: 256 pages in unavailable ranges
[    0.000000] psci: probing for conduit method from DT.
[    0.000000] psci: PSCIv1.1 detected in firmware.
[    0.000000] psci: Using standard PSCI v0.2 function IDs
[    0.000000] psci: MIGRATE_INFO_TYPE not supported.
[    0.000000] psci: SMC Calling Convention v1.2
[    0.000000] percpu: Embedded 14 pages/cpu s183976 r8192 d37208 u229376
[    0.000000] pcpu-alloc: s183976 r8192 d37208 u229376 alloc=14*16384
[    0.000000] pcpu-alloc: [0] 0 [0] 1 [0] 2 [0] 3 
[    0.000000] Detected PIPT I-cache on CPU0
[    0.000000] CPU features: detected: Virtualization Host Extensions
[    0.000000] CPU features: detected: Hardware dirty bit management
[    0.000000] CPU features: detected: Spectre-v4
[    0.000000] CPU features: detected: Spectre-BHB
[    0.000000] CPU features: kernel page table isolation forced ON by KASLR
[    0.000000] CPU features: detected: Kernel page table isolation (KPTI)
[    0.000000] alternatives: applying boot alternatives
[    0.000000] Kernel command line: reboot=w coherent_pool=1M 8250.nr_uarts=1 pci=pcie_bus_safe snd_bcm2835.enable_compat_alsa=0 snd_bcm2835.enable_hdmi=1 bcm2708_fb.fbwidth=640 bcm2708_fb.fbheight=480 bcm2708_fb.fbdepth=16 bcm2708_fb.fbswap=1 smsc95xx.macaddr=D8:3A:DD:CE:A5:92 vc_mem.mem_base=0x3fc00000 vc_mem.mem_size=0x40000000  console=ttyAMA10,115200 console=tty1 root=PARTUUID=31574ad6-02 rootfstype=ext4 fsck.repair=yes rootwait
[    0.000000] Dentry cache hash table entries: 524288 (order: 8, 4194304 bytes, linear)
[    0.000000] Inode-cache hash table entries: 262144 (order: 7, 2097152 bytes, linear)
[    0.000000] Built 1 zonelists, mobility grouping on.  Total pages: 260864
[    0.000000] mem auto-init: stack:all(zero), heap alloc:off, heap free:off
[    0.000000] software IO TLB: area num 4.
[    0.000000] software IO TLB: mapped [mem 0x00000000fb698000-0x00000000ff698000] (64MB)
[    0.000000] Memory: 3994560K/4190208K available (13376K kernel code, 2220K rwdata, 4288K rodata, 5056K init, 1213K bss, 130112K reserved, 65536K cma-reserved)
[    0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1
[    0.000000] ftrace: allocating 43087 entries in 43 pages
[    0.000000] ftrace: allocated 43 pages with 4 groups
[    0.000000] trace event string verifier disabled
[    0.000000] rcu: Preemptible hierarchical RCU implementation.
[    0.000000] rcu:     RCU event tracing is enabled.
[    0.000000] rcu:     RCU restricting CPUs from NR_CPUS=256 to nr_cpu_ids=4.
[    0.000000]  Trampoline variant of Tasks RCU enabled.
[    0.000000]  Rude variant of Tasks RCU enabled.
[    0.000000]  Tracing variant of Tasks RCU enabled.
[    0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 25 jiffies.
[    0.000000] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=4
[    0.000000] NR_IRQS: 64, nr_irqs: 64, preallocated irqs: 0
[    0.000000] Root IRQ handler: gic_handle_irq
[    0.000000] GIC: Using split EOI/Deactivate mode
[    0.000000] rcu: srcu_init: Setting srcu_struct sizes based on contention.
[    0.000000] arch_timer: cp15 timer(s) running at 54.00MHz (phys).
[    0.000000] clocksource: arch_sys_counter: mask: 0xffffffffffffff max_cycles: 0xc743ce346, max_idle_ns: 440795203123 ns
[    0.000000] sched_clock: 56 bits at 54MHz, resolution 18ns, wraps every 4398046511102ns
[    0.000155] Console: colour dummy device 80x25
[    0.000159] printk: console [tty1] enabled
[    0.000328] Calibrating delay loop (skipped), value calculated using timer frequency.. 108.00 BogoMIPS (lpj=216000)
[    0.000336] pid_max: default: 32768 minimum: 301
[    0.000361] LSM: initializing lsm=capability,integrity
[    0.000418] Mount-cache hash table entries: 8192 (order: 2, 65536 bytes, linear)
[    0.000432] Mountpoint-cache hash table entries: 8192 (order: 2, 65536 bytes, linear)
[    0.000771] cgroup: Disabling memory control group subsystem
[    0.001169] RCU Tasks: Setting shift to 2 and lim to 1 rcu_task_cb_adjust=1.
[    0.001197] RCU Tasks Rude: Setting shift to 2 and lim to 1 rcu_task_cb_adjust=1.
[    0.001222] RCU Tasks Trace: Setting shift to 2 and lim to 1 rcu_task_cb_adjust=1.
[    0.001283] rcu: Hierarchical SRCU implementation.
[    0.001287] rcu:     Max phase no-delay instances is 1000.
[    0.001854] EFI services will not be available.
[    0.001927] smp: Bringing up secondary CPUs ...
[    0.002081] Detected PIPT I-cache on CPU1
[    0.002125] CPU1: Booted secondary processor 0x0000000100 [0x414fd0b1]
[    0.002299] Detected PIPT I-cache on CPU2
[    0.002334] CPU2: Booted secondary processor 0x0000000200 [0x414fd0b1]
[    0.002493] Detected PIPT I-cache on CPU3
[    0.002524] CPU3: Booted secondary processor 0x0000000300 [0x414fd0b1]
[    0.002551] smp: Brought up 1 node, 4 CPUs
[    0.002569] SMP: Total of 4 processors activated.
[    0.002573] CPU features: detected: 32-bit EL0 Support
[    0.002577] CPU features: detected: Data cache clean to the PoU not required for I/D coherence
[    0.002582] CPU features: detected: Common not Private translations
[    0.002586] CPU features: detected: CRC32 instructions
[    0.002590] CPU features: detected: RCpc load-acquire (LDAPR)
[    0.002594] CPU features: detected: LSE atomic instructions
[    0.002598] CPU features: detected: Privileged Access Never
[    0.002601] CPU features: detected: RAS Extension Support
[    0.002606] CPU features: detected: Speculative Store Bypassing Safe (SSBS)
[    0.002641] CPU: All CPU(s) started at EL2
[    0.002645] alternatives: applying system-wide alternatives
[    0.004507] devtmpfs: initialized
[    0.007006] Enabled cp15_barrier support
[    0.007014] Enabled setend support
[    0.007069] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645041785100000 ns
[    0.007078] futex hash table entries: 1024 (order: 2, 65536 bytes, linear)
[    0.007302] pinctrl core: initialized pinctrl subsystem
[    0.007428] DMI not present or invalid.
[    0.007580] NET: Registered PF_NETLINK/PF_ROUTE protocol family
[    0.008137] DMA: preallocated 1024 KiB GFP_KERNEL pool for atomic allocations
[    0.008187] DMA: preallocated 1024 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations
[    0.008238] DMA: preallocated 1024 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations
[    0.008258] audit: initializing netlink subsys (disabled)
[    0.008308] audit: type=2000 audit(0.008:1): state=initialized audit_enabled=0 res=1
[    0.008430] thermal_sys: Registered thermal governor 'step_wise'
[    0.008441] cpuidle: using governor menu
[    0.008508] hw-breakpoint: found 6 breakpoint and 4 watchpoint registers.
[    0.008537] ASID allocator initialised with 32768 entries
[    0.008828] Serial: AMBA PL011 UART driver
[    0.009574] bcm2835-mbox 107c013880.mailbox: mailbox enabled
[    0.009766] 107d001000.serial: ttyAMA10 at MMIO 0x107d001000 (irq = 15, base_baud = 0) is a PL011 rev2
[    0.009780] printk: console [ttyAMA10] enabled
[    0.754766] raspberrypi-firmware soc:firmware: Attached to firmware from 2024-02-08T11:34:47, variant start_cd
[    0.768820] raspberrypi-firmware soc:firmware: Firmware hash is 42e0a50b00000000000000000000000000000000
[    0.784340] Modules: 2G module region forced by RANDOMIZE_MODULE_REGION_FULL
[    0.791423] Modules: 0 pages in range for non-PLT usage
[    0.791425] Modules: 129416 pages in range for PLT usage
[    0.801194] bcm2835-dma 1000010000.dma: DMA legacy API manager, dmachans=0x1
[    0.814148] iommu: Default domain type: Translated
[    0.818967] iommu: DMA domain TLB invalidation policy: strict mode
[    0.825260] SCSI subsystem initialized
[    0.829058] usbcore: registered new interface driver usbfs
[    0.834577] usbcore: registered new interface driver hub
[    0.839917] usbcore: registered new device driver usb
[    0.845066] pps_core: LinuxPPS API ver. 1 registered
[    0.850048] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti <giometti@linux.it>
[    0.859221] PTP clock support registered
[    0.863408] vgaarb: loaded
[    0.866218] clocksource: Switched to clocksource arch_sys_counter
[    1.091972] VFS: Disk quotas dquot_6.6.0
[    1.095926] VFS: Dquot-cache hash table entries: 2048 (order 0, 16384 bytes)
[    1.103035] FS-Cache: Loaded
[    1.105959] CacheFiles: Loaded
[    1.110565] NET: Registered PF_INET protocol family
[    1.115551] IP idents hash table entries: 65536 (order: 5, 524288 bytes, linear)
[    1.124284] tcp_listen_portaddr_hash hash table entries: 2048 (order: 1, 32768 bytes, linear)
[    1.132870] Table-perturb hash table entries: 65536 (order: 4, 262144 bytes, linear)
[    1.140648] TCP established hash table entries: 32768 (order: 4, 262144 bytes, linear)
[    1.148732] TCP bind hash table entries: 32768 (order: 6, 1048576 bytes, linear)
[    1.156909] TCP: Hash tables configured (established 32768 bind 32768)
[    1.163587] MPTCP token hash table entries: 4096 (order: 2, 98304 bytes, linear)
[    1.171069] UDP hash table entries: 2048 (order: 2, 65536 bytes, linear)
[    1.177847] UDP-Lite hash table entries: 2048 (order: 2, 65536 bytes, linear)
[    1.185147] NET: Registered PF_UNIX/PF_LOCAL protocol family
[    1.190936] RPC: Registered named UNIX socket transport module.
[    1.196881] RPC: Registered udp transport module.
[    1.201601] RPC: Registered tcp transport module.
[    1.206320] RPC: Registered tcp-with-tls transport module.
[    1.211824] RPC: Registered tcp NFSv4.1 backchannel transport module.
[    1.218303] PCI: CLS 0 bytes, default 64
[    1.222381] kvm [1]: IPA Size Limit: 40 bits
[    1.226690] kvm [1]: GICV region size/alignment is unsafe, using trapping (reduced performance)
[    1.226715] Trying to unpack rootfs image as initramfs...
[    1.235455] kvm [1]: vgic interrupt IRQ9
[    1.244813] kvm [1]: VHE mode initialized successfully
[    1.250506] Initialise system trusted keyrings
[    1.255050] workingset: timestamp_bits=46 max_order=18 bucket_order=0
[    1.261547] zbud: loaded
[    1.264296] NFS: Registering the id_resolver key type
[    1.269382] Key type id_resolver registered
[    1.273583] Key type id_legacy registered
[    1.277651] nfs4filelayout_init: NFSv4 File Layout Driver Registering...
[    1.284394] nfs4flexfilelayout_init: NFSv4 Flexfile Layout Driver Registering...
[    1.291892] F2FS not supported on PAGE_SIZE(16384) != 4096
[    1.297511] Key type asymmetric registered
[    1.301624] Asymmetric key parser 'x509' registered
[    1.306539] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 247)
[    1.314080] io scheduler mq-deadline registered
[    1.318636] io scheduler kyber registered
[    1.322673] io scheduler bfq registered
[    1.330472] irq_brcmstb_l2: registered L2 intc (/soc/intc@7d503000, parent irq: 26)
[    1.338289] irq_brcmstb_l2: registered L2 intc (/soc/intc@7d508380, parent irq: 27)
[    1.346062] irq_brcmstb_l2: registered L2 intc (/soc/intc@7d508400, parent irq: 28)
[    1.353818] irq_brcmstb_l2: registered L2 intc (/soc/intc@7d517b00, parent irq: 29)
[    1.363848] bcm2708_fb soc:fb: Unable to determine number of FBs. Disabling driver.
[    1.371605] bcm2708_fb: probe of soc:fb failed with error -2
[    1.396283] Freeing initrd memory: 10848K
[    1.410127] Serial: 8250/16550 driver, 1 ports, IRQ sharing enabled
[    1.416907] 107d50c000.serial: ttyS0 at MMIO 0x107d50c000 (irq = 31, base_baud = 6000000) is a Broadcom BCM7271 UART
[    1.427808] iproc-rng200 107d208000.rng: hwrng registered
[    1.433283] vc-mem: phys_addr:0x00000000 mem_base=0x3fc00000 mem_size:0x40000000(1024 MiB)
[    1.441812] bcm2712-iommu-cache 1000005b00.iommuc: bcm2712_iommu_cache_probe
[    1.450774] brd: module loaded
[    1.455267] loop: module loaded
[    1.458559] bcm2835-power bcm2835-power: Broadcom BCM2835 power domains driver
[    1.465926] Loading iSCSI transport class v2.0-870.
[    1.471625] usbcore: registered new device driver r8152-cfgselector
[    1.477927] usbcore: registered new interface driver r8152
[    1.483438] usbcore: registered new interface driver lan78xx
[    1.489122] usbcore: registered new interface driver smsc95xx
[    1.494935] dwc_otg: version 3.00a 10-AUG-2012 (platform bus)
[    1.500720] dwc_otg: FIQ enabled
[    1.500722] dwc_otg: NAK holdoff enabled
[    1.500723] dwc_otg: FIQ split-transaction FSM enabled
[    1.500726] Module dwc_common_port init
[    1.500831] usbcore: registered new interface driver uas
[    1.506170] usbcore: registered new interface driver usb-storage
[    1.512294] mousedev: PS/2 mouse device common for all mice
[    1.525625] rpi-rtc soc:rpi_rtc: registered as rtc0
[    1.531985] rpi-rtc soc:rpi_rtc: setting system clock to 1970-01-01T00:00:10 UTC (10)
[    1.540157] bcm2835-wdt bcm2835-wdt: Poweroff handler already present!
[    1.546719] bcm2835-wdt bcm2835-wdt: Broadcom BCM2835 watchdog timer
[    1.555351] sdhci: Secure Digital Host Controller Interface driver
[    1.561558] sdhci: Copyright(c) Pierre Ossman
[    1.565969] sdhci-pltfm: SDHCI platform and OF driver helper
[    1.571810] ledtrig-cpu: registered to indicate activity on CPUs
[    1.577876] SMCCC: SOC_ID: ARCH_SOC_ID not implemented, skipping ....
[    1.584352] hid: raw HID events driver (C) Jiri Kosina
[    1.589530] usbcore: registered new interface driver usbhid
[    1.595123] usbhid: USB HID core driver
[    1.599259] hw perfevents: enabled with armv8_cortex_a76 PMU driver, 7 counters available
[    1.607634] NET: Registered PF_PACKET protocol family
[    1.612730] Key type dns_resolver registered
[    1.621952] registered taskstats version 1
[    1.626123] Loading compiled-in X.509 certificates
[    1.633562] Key type .fscrypt registered
[    1.637503] Key type fscrypt-provisioning registered
[    1.643588] brcm-pcie 1000120000.pcie: host bridge /axi/pcie@120000 ranges:
[    1.650592] brcm-pcie 1000120000.pcie:   No bus range found for /axi/pcie@120000, using [bus 00-ff]
[    1.659687] brcm-pcie 1000120000.pcie:      MEM 0x1f00000000..0x1ffffffffb -> 0x0000000000
[    1.667991] brcm-pcie 1000120000.pcie:      MEM 0x1c00000000..0x1effffffff -> 0x0400000000
[    1.676296] brcm-pcie 1000120000.pcie:   IB MEM 0x1f00000000..0x1f003fffff -> 0x0000000000
[    1.684598] brcm-pcie 1000120000.pcie:   IB MEM 0x0000000000..0x0fffffffff -> 0x1000000000
[    1.694074] brcm-pcie 1000120000.pcie: Forcing gen 2
[    1.699224] brcm-pcie 1000120000.pcie: PCI host bridge to bus 0000:00
[    1.705693] pci_bus 0000:00: root bus resource [bus 00-ff]
[    1.711200] pci_bus 0000:00: root bus resource [mem 0x1f00000000-0x1ffffffffb] (bus address [0x00000000-0xfffffffb])
[    1.721771] pci_bus 0000:00: root bus resource [mem 0x1c00000000-0x1effffffff pref] (bus address [0x400000000-0x6ffffffff])
[    1.732963] pci 0000:00:00.0: [14e4:2712] type 01 class 0x060400
[    1.739016] pci 0000:00:00.0: PME# supported from D0 D3hot
[    1.745338] pci 0000:00:00.0: bridge configuration invalid ([bus 00-00]), reconfiguring
[    1.858225] brcm-pcie 1000120000.pcie: link up, 5.0 GT/s PCIe x4 (!SSC)
[    1.864886] pci 0000:01:00.0: [1de4:0001] type 00 class 0x020000
[    1.870928] pci 0000:01:00.0: reg 0x10: [mem 0xffffc000-0xffffffff]
[    1.877225] pci 0000:01:00.0: reg 0x14: [mem 0xffc00000-0xffffffff]
[    1.883521] pci 0000:01:00.0: reg 0x18: [mem 0xffff0000-0xffffffff]
[    1.889881] pci 0000:01:00.0: supports D1
[    1.893902] pci 0000:01:00.0: PME# supported from D0 D1 D3hot D3cold
[    1.910228] pci_bus 0000:01: busn_res: [bus 01-ff] end is updated to 01
[    1.916878] pci 0000:00:00.0: BAR 8: assigned [mem 0x1f00000000-0x1f005fffff]
[    1.924045] pci 0000:01:00.0: BAR 1: assigned [mem 0x1f00000000-0x1f003fffff]
[    1.931212] pci 0000:01:00.0: BAR 2: assigned [mem 0x1f00400000-0x1f0040ffff]
[    1.938379] pci 0000:01:00.0: BAR 0: assigned [mem 0x1f00410000-0x1f00413fff]
[    1.945546] pci 0000:00:00.0: PCI bridge to [bus 01]
[    1.950529] pci 0000:00:00.0:   bridge window [mem 0x1f00000000-0x1f005fffff]
[    1.957696] pci 0000:00:00.0: Max Payload Size set to  256/ 512 (was  128), Max Read Rq  512
[    1.966178] pci 0000:01:00.0: Max Payload Size set to  256/ 256 (was  128), Max Read Rq  512
[    1.974715] pcieport 0000:00:00.0: enabling device (0000 -> 0002)
[    1.980867] pcieport 0000:00:00.0: PME: Signaling with IRQ 36
[    1.986687] pcieport 0000:00:00.0: AER: enabled with IRQ 36
[    1.992360] rp1 0000:01:00.0: bar0 len 0x4000, start 0x1f00410000, end 0x1f00413fff, flags, 0x40200
[    2.001449] rp1 0000:01:00.0: bar1 len 0x400000, start 0x1f00000000, end 0x1f003fffff, flags, 0x40200
[    2.010715] rp1 0000:01:00.0: enabling device (0000 -> 0002)
[    2.017540] rp1 0000:01:00.0: chip_id 0x20001927
[    2.047139] macb 1f00100000.ethernet eth0: Cadence GEM rev 0x00070109 at 0x1f00100000 irq 104 (d8:3a:dd:ce:a5:92)
[    2.058016] dw_axi_dmac_platform 1f00188000.dma: DesignWare AXI DMA Controller, 8 channels
[    2.066597] xhci-hcd xhci-hcd.0: xHCI Host Controller
[    2.071674] xhci-hcd xhci-hcd.0: new USB bus registered, assigned bus number 1
[    2.079377] xhci-hcd xhci-hcd.0: hcc params 0x0240fe6d hci version 0x110 quirks 0x0000000000000810
[    2.088385] xhci-hcd xhci-hcd.0: irq 129, io mem 0x1f00200000
[    2.094223] xhci-hcd xhci-hcd.0: xHCI Host Controller
[    2.099299] xhci-hcd xhci-hcd.0: new USB bus registered, assigned bus number 2
[    2.106554] xhci-hcd xhci-hcd.0: Host supports USB 3.0 SuperSpeed
[    2.112716] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 6.06
[    2.121019] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[    2.128272] usb usb1: Product: xHCI Host Controller
[    2.133167] usb usb1: Manufacturer: Linux 6.6.16-v8-16k+ xhci-hcd
[    2.139284] usb usb1: SerialNumber: xhci-hcd.0
[    2.143867] hub 1-0:1.0: USB hub found
[    2.147642] hub 1-0:1.0: 2 ports detected
[    2.151796] usb usb2: New USB device found, idVendor=1d6b, idProduct=0003, bcdDevice= 6.06
[    2.160099] usb usb2: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[    2.167354] usb usb2: Product: xHCI Host Controller
[    2.172256] usb usb2: Manufacturer: Linux 6.6.16-v8-16k+ xhci-hcd
[    2.178445] usb usb2: SerialNumber: xhci-hcd.0
[    2.183009] hub 2-0:1.0: USB hub found
[    2.186780] hub 2-0:1.0: 1 port detected
[    2.191010] xhci-hcd xhci-hcd.1: xHCI Host Controller
[    2.196203] xhci-hcd xhci-hcd.1: new USB bus registered, assigned bus number 3
[    2.203907] xhci-hcd xhci-hcd.1: hcc params 0x0240fe6d hci version 0x110 quirks 0x0000000000000810
[    2.213025] xhci-hcd xhci-hcd.1: irq 134, io mem 0x1f00300000
[    2.218858] xhci-hcd xhci-hcd.1: xHCI Host Controller
[    2.223929] xhci-hcd xhci-hcd.1: new USB bus registered, assigned bus number 4
[    2.231293] xhci-hcd xhci-hcd.1: Host supports USB 3.0 SuperSpeed
[    2.237442] usb usb3: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 6.06
[    2.245743] usb usb3: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[    2.253097] usb usb3: Product: xHCI Host Controller
[    2.257992] usb usb3: Manufacturer: Linux 6.6.16-v8-16k+ xhci-hcd
[    2.264109] usb usb3: SerialNumber: xhci-hcd.1
[    2.268763] hub 3-0:1.0: USB hub found
[    2.272535] hub 3-0:1.0: 2 ports detected
[    2.276678] usb usb4: New USB device found, idVendor=1d6b, idProduct=0003, bcdDevice= 6.06
[    2.285090] usb usb4: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[    2.292345] usb usb4: Product: xHCI Host Controller
[    2.297265] usb usb4: Manufacturer: Linux 6.6.16-v8-16k+ xhci-hcd
[    2.303509] usb usb4: SerialNumber: xhci-hcd.1
[    2.308109] hub 4-0:1.0: USB hub found
[    2.311887] hub 4-0:1.0: 1 port detected
[    2.316438] bcm2712-iommu 1000005100.iommu: bcm2712_iommu_init: DEBUG_INFO = 0x20804774
[    2.324993] platform 1000800000.codec: bcm2712_iommu_probe_device: MMU 1000005100.iommu
[    2.333036] platform 1000800000.codec: bcm2712_iommu_device_group: MMU 1000005100.iommu
[    2.341303] platform 1000800000.codec: Adding to iommu group 0
[    2.347164] platform 1000880000.pisp_be: bcm2712_iommu_probe_device: MMU 1000005100.iommu
[    2.355591] platform 1000880000.pisp_be: bcm2712_iommu_device_group: MMU 1000005100.iommu
[    2.363808] platform 1000880000.pisp_be: Adding to iommu group 0
[    2.369868] platform 1000800000.codec: bcm2712_iommu_attach_dev: MMU 1000005100.iommu
[    2.377935] platform 1000880000.pisp_be: bcm2712_iommu_attach_dev: MMU 1000005100.iommu
[    2.386000] bcm2712-iommu 1000005100.iommu: bcm2712_iommu_probe: Success
[    2.393270] bcm2712-iommu 1000005200.iommu: bcm2712_iommu_init: DEBUG_INFO = 0x20804774
[    2.401622] bcm2712-iommu 1000005200.iommu: bcm2712_iommu_probe: Success
[    2.408859] bcm2712-iommu 1000005280.iommu: bcm2712_iommu_init: DEBUG_INFO = 0x20804774
[    2.417190] bcm2712-iommu 1000005280.iommu: bcm2712_iommu_probe: Success
[    2.424405] sdhci-brcmstb 1000fff000.mmc: there is not valid maps for state default
[    2.432527] of_cfs_init
[    2.435181] mmc0: CQHCI version 5.10
[    2.438810] of_cfs_init: OK
[    2.441672] clk: Disabling unused clocks
[    2.474588] mmc0: SDHCI controller on 1000fff000.mmc [1000fff000.mmc] using ADMA 64-bit
[    2.485692] Freeing unused kernel memory: 5056K
[    2.490311] Run /init as init process
[    2.493981]   with arguments:
[    2.493983]     /init
[    2.493984]   with environment:
[    2.493986]     HOME=/
[    2.493988]     TERM=linux
[    2.579990] mmc0: new ultra high speed SDR104 SDXC card at address aaaa
[    2.587450] mmcblk0: mmc0:aaaa SC200 183 GiB
[    2.596367]  mmcblk0: p1 p2
[    2.600619] mmcblk0: mmc0:aaaa SC200 183 GiB (quirks 0x00004000)
[    2.854655] EXT4-fs (mmcblk0p2): mounted filesystem 3b614a3f-4a65-4480-876a-8a998e01ac9b ro with ordered data mode. Quota mode: none.
[    3.109006] systemd[1]: System time before build time, advancing clock.
[    3.185727] NET: Registered PF_INET6 protocol family
[    3.191107] Segment Routing with IPv6
[    3.194794] In-situ OAM (IOAM) with IPv6
[    3.228423] systemd[1]: systemd 252.22-1~deb12u1 running in system mode (+PAM +AUDIT +SELINUX +APPARMOR +IMA +SMACK +SECCOMP +GCRYPT -GNUTLS +OPENSSL +ACL +BLKID +CURL +ELFUTILS +FIDO2 +IDN2 -IDN +IPTC +KMOD +LIBCRYPTSETUP +LIBFDISK +PCRE2 -PWQUALITY +P11KIT +QRENCODE +TPM2 +BZIP2 +LZ4 +XZ +ZLIB +ZSTD -BPF_FRAMEWORK -XKBCOMMON +UTMP +SYSVINIT default-hierarchy=unified)
[    3.261279] systemd[1]: Detected architecture arm64.
[    3.277220] systemd[1]: Hostname set to <streamer>.
[    3.350659] uart-pl011 107d001000.serial: no DMA platform data
[    3.586682] systemd[1]: Queued start job for default target multi-user.target.
[    3.614841] systemd[1]: Created slice system-getty.slice - Slice /system/getty.
[    3.622578] systemd[1]: Created slice system-modprobe.slice - Slice /system/modprobe.
[    3.630768] systemd[1]: Created slice system-serial\x2dgetty.slice - Slice /system/serial-getty.
[    3.639896] systemd[1]: Created slice system-systemd\x2dfsck.slice - Slice /system/systemd-fsck.
[    3.648923] systemd[1]: Created slice user.slice - User and Session Slice.
[    3.655953] systemd[1]: Started systemd-ask-password-console.path - Dispatch Password Requests to Console Directory Watch.
[    3.667142] systemd[1]: Started systemd-ask-password-wall.path - Forward Password Requests to Wall Directory Watch.
[    3.677846] systemd[1]: Set up automount proc-sys-fs-binfmt_misc.automount - Arbitrary Executable File Formats File System Automount Point.
[    3.690496] systemd[1]: Expecting device dev-disk-by\x2dpartuuid-31574ad6\x2d01.device - /dev/disk/by-partuuid/31574ad6-01...
[    3.701901] systemd[1]: Expecting device dev-ttyAMA10.device - /dev/ttyAMA10...
[    3.709293] systemd[1]: Reached target cryptsetup.target - Local Encrypted Volumes.
[    3.717039] systemd[1]: Reached target integritysetup.target - Local Integrity Protected Volumes.
[    3.726028] systemd[1]: Reached target paths.target - Path Units.
[    3.732206] systemd[1]: Reached target slices.target - Slice Units.
[    3.738554] systemd[1]: Reached target swap.target - Swaps.
[    3.744202] systemd[1]: Reached target veritysetup.target - Local Verity Protected Volumes.
[    3.752771] systemd[1]: Listening on systemd-fsckd.socket - fsck to fsckd communication Socket.
[    3.761620] systemd[1]: Listening on systemd-initctl.socket - initctl Compatibility Named Pipe.
[    3.770656] systemd[1]: Listening on systemd-journald-audit.socket - Journal Audit Socket.
[    3.779134] systemd[1]: Listening on systemd-journald-dev-log.socket - Journal Socket (/dev/log).
[    3.788227] systemd[1]: Listening on systemd-journald.socket - Journal Socket.
[    3.798278] systemd[1]: Listening on systemd-udevd-control.socket - udev Control Socket.
[    3.806547] systemd[1]: Listening on systemd-udevd-kernel.socket - udev Kernel Socket.
[    3.814692] systemd[1]: dev-hugepages.mount - Huge Pages File System was skipped because of an unmet condition check (ConditionPathExists=/sys/kernel/mm/hugepages).
[    3.850322] systemd[1]: Mounting dev-mqueue.mount - POSIX Message Queue File System...
[    3.859235] systemd[1]: Mounting sys-kernel-debug.mount - Kernel Debug File System...
[    3.868055] systemd[1]: Mounting sys-kernel-tracing.mount - Kernel Trace File System...
[    3.876283] systemd[1]: auth-rpcgss-module.service - Kernel Module supporting RPCSEC_GSS was skipped because of an unmet condition check (ConditionPathExists=/etc/krb5.keytab).
[    3.895633] systemd[1]: Starting fake-hwclock.service - Restore / save the current clock...
[    3.907420] systemd[1]: Starting keyboard-setup.service - Set the console keyboard layout...
[    3.917039] systemd[1]: Starting kmod-static-nodes.service - Create List of Static Device Nodes...
[    3.927298] systemd[1]: Starting modprobe@configfs.service - Load Kernel Module configfs...
[    3.937115] systemd[1]: Starting modprobe@dm_mod.service - Load Kernel Module dm_mod...
[    3.946652] systemd[1]: Starting modprobe@drm.service - Load Kernel Module drm...
[    3.955110] device-mapper: ioctl: 4.48.0-ioctl (2023-03-01) initialised: dm-devel@redhat.com
[    3.955894] systemd[1]: Starting modprobe@efi_pstore.service - Load Kernel Module efi_pstore...
[    3.973659] systemd[1]: Starting modprobe@fuse.service - Load Kernel Module fuse...
[    3.982748] systemd[1]: Starting modprobe@loop.service - Load Kernel Module loop...
[    3.990661] systemd[1]: systemd-fsck-root.service - File System Check on Root Device was skipped because of an unmet condition check (ConditionPathExists=!/run/initramfs/fsck-root).
[    4.009142] fuse: init (API version 7.39)
[    4.009221] systemd[1]: Starting systemd-journald.service - Journal Service...
[    4.027971] systemd[1]: Starting systemd-modules-load.service - Load Kernel Modules...
[    4.037158] systemd[1]: Starting systemd-remount-fs.service - Remount Root and Kernel File Systems...
[    4.047952] systemd[1]: Starting systemd-udev-trigger.service - Coldplug All udev Devices...
[    4.058236] systemd[1]: Mounted dev-mqueue.mount - POSIX Message Queue File System.
[    4.067012] systemd[1]: Mounted sys-kernel-debug.mount - Kernel Debug File System.
[    4.074813] systemd[1]: Started systemd-journald.service - Journal Service.
[    4.084772] EXT4-fs (mmcblk0p2): re-mounted 3b614a3f-4a65-4480-876a-8a998e01ac9b r/w. Quota mode: none.
[    4.116133] systemd-journald[280]: Received client request to flush runtime journal.
[    4.146135] systemd-journald[280]: File /var/log/journal/9cc0b6f2ae3d48bba4b4f851cb05a2f5/system.journal corrupted or uncleanly shut down, renaming and replacing.
[    4.521431] rpi-gpiomem 107d508500.gpiomem: window base 0x107d508500 size 0x00000040
[    4.521671] rpi-gpiomem 107d508500.gpiomem: initialised 1 regions as /dev/gpiomem1
[    4.521724] rpi-gpiomem 107d517c00.gpiomem: window base 0x107d517c00 size 0x00000040
[    4.521860] rpi-gpiomem 107d517c00.gpiomem: initialised 1 regions as /dev/gpiomem2
[    4.521898] rpi-gpiomem 107d504100.gpiomem: window base 0x107d504100 size 0x00000020
[    4.521943] rpi-gpiomem 107d504100.gpiomem: initialised 1 regions as /dev/gpiomem3
[    4.521973] rpi-gpiomem 107d510700.gpiomem: window base 0x107d510700 size 0x00000020
[    4.525374] rpi-gpiomem 107d510700.gpiomem: initialised 1 regions as /dev/gpiomem4
[    4.529824] rpi-gpiomem 1f000d0000.gpiomem: window base 0x1f000d0000 size 0x00030000
[    4.530480] rpi-gpiomem 1f000d0000.gpiomem: initialised 1 regions as /dev/gpiomem0
[    4.598044] input: pwr_button as /devices/platform/pwr_button/input/input0
[    4.610067] mc: Linux media interface: v0.10
[    4.657594] videodev: Linux video capture interface: v2.00
[    4.741279] snd-rpi-i-sabre-q2m soc:sound: snd_soc_register_card() failed: -517
[    4.785887] pispbe 1000880000.pisp_be: bcm2712_iommu_of_xlate: MMU 1000005100.iommu
[    4.786001] pispbe 1000880000.pisp_be: pispbe_probe: HW version:  0x02252700
[    4.786005] pispbe 1000880000.pisp_be: pispbe_probe: BatchStatus: 0x00000000
[    4.786007] pispbe 1000880000.pisp_be: pispbe_probe: Status:      0x00000000
[    4.786009] pispbe 1000880000.pisp_be: Register nodes for group 0
[    4.794276] pispbe 1000880000.pisp_be: input device node registered as /dev/video20
[    4.794353] pispbe 1000880000.pisp_be: tdn_input device node registered as /dev/video21
[    4.794394] pispbe 1000880000.pisp_be: stitch_input device node registered as /dev/video22
[    4.794428] pispbe 1000880000.pisp_be: hog_output device node registered as /dev/video23
[    4.794462] pispbe 1000880000.pisp_be: output0 device node registered as /dev/video24
[    4.794496] pispbe 1000880000.pisp_be: output1 device node registered as /dev/video25
[    4.794528] pispbe 1000880000.pisp_be: tdn_output device node registered as /dev/video26
[    4.794559] pispbe 1000880000.pisp_be: stitch_output device node registered as /dev/video27
[    4.794591] pispbe 1000880000.pisp_be: config device node registered as /dev/video28
[    4.794824] pispbe 1000880000.pisp_be: Register nodes for group 1
[    4.794869] pispbe 1000880000.pisp_be: input device node registered as /dev/video29
[    4.794901] pispbe 1000880000.pisp_be: tdn_input device node registered as /dev/video30
[    4.794933] pispbe 1000880000.pisp_be: stitch_input device node registered as /dev/video31
[    4.794969] pispbe 1000880000.pisp_be: hog_output device node registered as /dev/video32
[    4.795006] pispbe 1000880000.pisp_be: output0 device node registered as /dev/video33
[    4.795053] pispbe 1000880000.pisp_be: output1 device node registered as /dev/video34
[    4.795604] pispbe 1000880000.pisp_be: tdn_output device node registered as /dev/video35
[    4.795707] pispbe 1000880000.pisp_be: stitch_output device node registered as /dev/video36
[    4.795794] pispbe 1000880000.pisp_be: config device node registered as /dev/video37
[    4.813714] rpivid_hevc: module is from the staging directory, the quality is unknown, you have been warned.
[    4.816478] rpivid 1000800000.codec: bcm2712_iommu_of_xlate: MMU 1000005100.iommu
[    4.819979] rpivid 1000800000.codec: Device registered as /dev/video19
[    4.849668] snd-rpi-i-sabre-q2m soc:sound: snd_soc_register_card() failed: -517
[    4.902840] snd-rpi-i-sabre-q2m soc:sound: snd_soc_register_card() failed: -517
[    4.989166] i-sabre-codec-i2c 1-0048: ASoC: error at soc_component_read_no_lock on i-sabre-codec-i2c.1-0048 for register: [0x00000001] -121
[    4.989176] snd-rpi-i-sabre-q2m soc:sound: Audiophonics Device ID : FFFFFF87
[    4.989312] i-sabre-codec-i2c 1-0048: ASoC: error at soc_component_read_no_lock on i-sabre-codec-i2c.1-0048 for register: [0x00000002] -121
[    4.989315] snd-rpi-i-sabre-q2m soc:sound: Audiophonics API revision : FFFFFF87
[    5.020407] i-sabre-codec-i2c 1-0048: ASoC: error at snd_soc_component_update_bits on i-sabre-codec-i2c.1-0048 for register: [0x00000021] -121
[    5.020577] i-sabre-codec-i2c 1-0048: ASoC: error at snd_soc_component_update_bits on i-sabre-codec-i2c.1-0048 for register: [0x00000024] -121
[    5.226836] i-sabre-codec-i2c 1-0048: ASoC: error at snd_soc_component_update_bits on i-sabre-codec-i2c.1-0048 for register: [0x00000021] -121
[    5.227406] i-sabre-codec-i2c 1-0048: ASoC: error at snd_soc_component_update_bits on i-sabre-codec-i2c.1-0048 for register: [0x00000024] -121
[    5.438920] Adding 102368k swap on /var/swap.  Priority:-2 extents:1 across:102368k SS
[    6.110989] macb 1f00100000.ethernet eth0: PHY [1f00100000.ethernet-ffffffff:01] driver [Broadcom BCM54213PE] (irq=POLL)
[    6.111002] macb 1f00100000.ethernet eth0: configuring for phy/rgmii-id link mode
[    6.114050] pps pps0: new PPS source ptp0
[    6.114102] macb 1f00100000.ethernet: gem-ptp-timer ptp clock registered.
[   10.203249] macb 1f00100000.ethernet eth0: Link is Up - 1Gbps/Full - flow control off
[   34.080815] i-sabre-codec-i2c 1-0048: ASoC: error at snd_soc_component_update_bits on i-sabre-codec-i2c.1-0048 for register: [0x00000021] -121
[ 2310.671480] i-sabre-codec-i2c 1-0048: ASoC: error at snd_soc_component_update_bits on i-sabre-codec-i2c.1-0048 for register: [0x00000021] -121
[ 2460.847834] i-sabre-codec-i2c 1-0048: ASoC: error at snd_soc_component_update_bits on i-sabre-codec-i2c.1-0048 for register: [0x00000010] -121
[ 2460.848331] i-sabre-codec-i2c 1-0048: ASoC: error at snd_soc_component_update_bits on i-sabre-codec-i2c.1-0048 for register: [0x00000021] -121
[ 2466.896601] i-sabre-codec-i2c 1-0048: ASoC: error at snd_soc_component_update_bits on i-sabre-codec-i2c.1-0048 for register: [0x00000021] -121
[ 2564.910188] i-sabre-codec-i2c 1-0048: ASoC: error at snd_soc_component_update_bits on i-sabre-codec-i2c.1-0048 for register: [0x00000010] -121
[ 2564.910666] i-sabre-codec-i2c 1-0048: ASoC: error at snd_soc_component_update_bits on i-sabre-codec-i2c.1-0048 for register: [0x00000021] -121
[ 4782.620328] i-sabre-codec-i2c 1-0048: ASoC: error at snd_soc_component_update_bits on i-sabre-codec-i2c.1-0048 for register: [0x00000021] -121
[ 4998.800404] i-sabre-codec-i2c 1-0048: ASoC: error at snd_soc_component_update_bits on i-sabre-codec-i2c.1-0048 for register: [0x00000010] -121
[ 4998.800914] i-sabre-codec-i2c 1-0048: ASoC: error at snd_soc_component_update_bits on i-sabre-codec-i2c.1-0048 for register: [0x00000021] -121
[ 5180.824831] i-sabre-codec-i2c 1-0048: ASoC: error at snd_soc_component_update_bits on i-sabre-codec-i2c.1-0048 for register: [0x00000021] -121
[ 6898.101619] i-sabre-codec-i2c 1-0048: ASoC: error at snd_soc_component_update_bits on i-sabre-codec-i2c.1-0048 for register: [0x00000021] -121
[ 8552.208407] i-sabre-codec-i2c 1-0048: ASoC: error at snd_soc_component_update_bits on i-sabre-codec-i2c.1-0048 for register: [0x00000010] -121
[ 8552.208873] i-sabre-codec-i2c 1-0048: ASoC: error at snd_soc_component_update_bits on i-sabre-codec-i2c.1-0048 for register: [0x00000021] -121
[ 8842.772392] i-sabre-codec-i2c 1-0048: ASoC: error at snd_soc_component_update_bits on i-sabre-codec-i2c.1-0048 for register: [0x00000021] -121
[ 8854.222596] i-sabre-codec-i2c 1-0048: ASoC: error at snd_soc_component_update_bits on i-sabre-codec-i2c.1-0048 for register: [0x00000010] -121
[ 8854.223049] i-sabre-codec-i2c 1-0048: ASoC: error at snd_soc_component_update_bits on i-sabre-codec-i2c.1-0048 for register: [0x00000021] -121
[ 8897.397952] i-sabre-codec-i2c 1-0048: ASoC: error at snd_soc_component_update_bits on i-sabre-codec-i2c.1-0048 for register: [0x00000021] -121
[ 8905.091242] i-sabre-codec-i2c 1-0048: ASoC: error at snd_soc_component_update_bits on i-sabre-codec-i2c.1-0048 for register: [0x00000021] -121
[ 8926.459710] i-sabre-codec-i2c 1-0048: ASoC: error at snd_soc_component_update_bits on i-sabre-codec-i2c.1-0048 for register: [0x00000021] -121
[ 8933.159147] i-sabre-codec-i2c 1-0048: ASoC: error at snd_soc_component_update_bits on i-sabre-codec-i2c.1-0048 for register: [0x00000021] -121
[ 8944.539024] i-sabre-codec-i2c 1-0048: ASoC: error at snd_soc_component_update_bits on i-sabre-codec-i2c.1-0048 for register: [0x00000021] -121
[ 8953.459598] i-sabre-codec-i2c 1-0048: ASoC: error at snd_soc_component_update_bits on i-sabre-codec-i2c.1-0048 for register: [0x00000021] -121
[ 8962.390989] i-sabre-codec-i2c 1-0048: ASoC: error at snd_soc_component_update_bits on i-sabre-codec-i2c.1-0048 for register: [0x00000021] -121
[ 8976.339409] i-sabre-codec-i2c 1-0048: ASoC: error at snd_soc_component_update_bits on i-sabre-codec-i2c.1-0048 for register: [0x00000021] -121
[ 9019.899896] i-sabre-codec-i2c 1-0048: ASoC: error at snd_soc_component_update_bits on i-sabre-codec-i2c.1-0048 for register: [0x00000021] -121
[ 9022.140564] i-sabre-codec-i2c 1-0048: ASoC: error at snd_soc_component_update_bits on i-sabre-codec-i2c.1-0048 for register: [0x00000021] -121
[ 9056.973084] i-sabre-codec-i2c 1-0048: ASoC: error at snd_soc_component_update_bits on i-sabre-codec-i2c.1-0048 for register: [0x00000021] -121
[11405.279146] i-sabre-codec-i2c 1-0048: ASoC: error at snd_soc_component_update_bits on i-sabre-codec-i2c.1-0048 for register: [0x00000021] -121
[56890.305063] systemd[1407]: memfd_create() called without MFD_EXEC or MFD_NOEXEC_SEAL set
[82854.749925] i-sabre-codec-i2c 1-0048: ASoC: error at snd_soc_component_update_bits on i-sabre-codec-i2c.1-0048 for register: [0x00000010] -121
[82854.750409] i-sabre-codec-i2c 1-0048: ASoC: error at snd_soc_component_update_bits on i-sabre-codec-i2c.1-0048 for register: [0x00000021] -121
[84163.186237] i-sabre-codec-i2c 1-0048: ASoC: error at snd_soc_component_update_bits on i-sabre-codec-i2c.1-0048 for register: [0x00000021] -121
[86754.204553] i-sabre-codec-i2c 1-0048: ASoC: error at snd_soc_component_update_bits on i-sabre-codec-i2c.1-0048 for register: [0x00000010] -121
[86754.204760] i-sabre-codec-i2c 1-0048: ASoC: error at snd_soc_component_update_bits on i-sabre-codec-i2c.1-0048 for register: [0x00000021] -121
[87187.626885] i-sabre-codec-i2c 1-0048: ASoC: error at snd_soc_component_update_bits on i-sabre-codec-i2c.1-0048 for register: [0x00000021] -121
pelwell commented 7 months ago

You say that it is "limited to 192KHz sampling rates on the pi 5" - how does this limit manifest? What happens when you play a 384kHz stream?

clone206 commented 7 months ago

You say that it is "limited to 192KHz sampling rates on the pi 5" - how does this limit manifest? What happens when you play a 384kHz stream?

The reclocker HAT fails to lock onto any incoming i2s. It cycles continuously between its two clocks as indicated by its status led's, and in addition, when using an add-on gpio display, it reads "no sig". The connected DAC's display reads "Unlock".

None of the above is the case with the pi 4, and both displays show the 384KHz rate.

pelwell commented 7 months ago

That tells us that ALSA and the drivers are all happy with the configuration, and that the failure happens when data starts to flow. I should be able to take a look at the signals using the i2s-dac overlay.

By the way:

dtoverlay=i-sabre-q2m,slave

The i-sabre-q2m overlay only works with clock producer ("master") mode - it doesn't understand any parameters (but the associated error is more of a warning). See dtoverlay -h i-sabre-q2m. The same goes for hifiberry-dac and i2s-dac.

pelwell commented 7 months ago

Just a quick note to say I looked at the signals on a logic analyser today and was able to see the way in which the frequency goes wrong. Hopefully we will have fewer infrastructure disruptions tomorrow and I'll be able to test a fix.

j-schambacher commented 7 months ago

FYI: while working on the various drivers for our sound cards, I've noted that the clock generation for the 24bit format (S24_LE) could lead to a wrong sample frequency (LRCLK). For a 1kHz sine wave you get 750Hz. I guess the ratio of bit clock and LR clock is calculated incorrectly -> 750Hz/1kHz = 24/32. Could be fixed by fixed-bit-clock-ratio of 64... but it's not the solution. I've tracked it down to the hw_params in the dwc-i2s.c, but without docs I can only guess.

pelwell commented 7 months ago

Yes, that's exactly what I'm redoing now.

pelwell commented 7 months ago

With luck, #5999 will solve both of those problems.

clone206 commented 7 months ago

With luck, #5999 will solve both of those problems.

I ran sudo rpi-update pulls/5999

No errors and rebooted, but I'm still seeing the same behavior with 352.8KHz files. Anything else I need to do, maybe in terms of the overlays, or did your PR perhaps only address 384KHz? I don't have any 384KHz handy at the moment to try.

pelwell commented 7 months ago

The PR was aimed at 384kHz. There is no good PLL value for the higher multiples of 44100 - the closest we could get with integer divisors is 355.55kHz for 32-bit stereo, or 352.29kHz for 16-bit stereo - but I can look at the failure mode with 352.8kHz.

pelwell commented 7 months ago

There is test data at various frequencies here: https://msbtechnology.com/support/bit-perfect-testing/ Do heed the warnings about 0db material!

clone206 commented 7 months ago

There is test data at various frequencies here: https://msbtechnology.com/support/bit-perfect-testing/ Do heed the warnings about 0db material!

Thanks, will give it a try!

So based on your earlier reply, am I understanding correctly that the pi 5 will never be able to support 352.8KHz i2s?

pelwell commented 7 months ago

It's worse than I thought - the options are (for 32-bit stereo):

So based on your earlier reply, am I understanding correctly that the pi 5 will never be able to support 352.8KHz i2s?

That's not the case.

  1. When running as an I2S clock consumer (i.e. with an external clock source) it can probably do any frequency you like - I would expect an audiophile product to have 2 external crystals - one for 48kHz family and one for the 44.1kHz family, or it's own tuneable PLL source.
  2. It is possible to change the PLL frequency to make 352.8kHz possible, but not without losing 384kHz. I'm also not sure how you would switch between the two on the fly.
pelwell commented 7 months ago

Out of curiosity, is it 16-, 24- or 32-bit audio that you have?

clone206 commented 7 months ago

It's worse than I thought - the options are (for 32-bit stereo):

  • 50MHz/2/64 = 390.625kHz
  • 122880000/5/64 = 384kHz
  • 153600000/7/64 = 342.86kHz

So based on your earlier reply, am I understanding correctly that the pi 5 will never be able to support 352.8KHz i2s?

That's not the case.

  1. When running as an I2S clock consumer (i.e. with an external clock source) it can probably do any frequency you like - I would expect an audiophile product to have 2 external crystals - one for 48kHz family and one for the 44.1kHz family, or it's own tuneable PLL source.
  2. It is possible to change the PLL frequency to make 352.8kHz possible, but not without losing 384kHz. I'm also not sure how you would switch between the two on the fly.

Thanks for the clarification. FWIW, I think 352.8KHz is in general more useful for an audiophile as that's the frequency that allows for DoP with dsd128. Also for anybody converting DSD to dxd that frequency would be more useful.

As far as I know, the HAT I'm currently using only works as a slave. It's basically a FIFO/reclocker, though I believe the maker has a similar HAT that works as a master.

Also, responding to your other question, this HAT can be set to convert any incoming bit depth losslessly to 32bit, and that's how I have it set. The actual file I was using to test 352.8KHz PCM is 24 bit.

Thanks again for looking into this. The pi 5 is an amazing piece of engineering, and I swear it actually sounds better with i2s HATs than the pi 4. Hoping it can be my go-to for audiophile sound.

j-schambacher commented 7 months ago

Done.

@pelwell Thanks Phil!

And I'll dig next week into the I2S issues while continuing work on the 8 channel driver. Maybe using ofchangesets like I've done on the optional headphone amp in the dacplus driver code could be an option and allow DT changes during runtime. Just thoughts so far.

@pelwell Is someone working on the clock-producer/-consumer switching? Just let me know because I need to dig into it, but probably we are only making new DT-overlays to avoid the switching in the driver.

pelwell commented 7 months ago

I'm sorry - I didn't find a nice solution, then other issues took over and it got put to one side. It's still on the list.

clone206 commented 7 months ago

Confirming 24/384 works with the version I updated to. Also 24/44.1 no longer working.

clone206 commented 7 months ago

For those of us still learning and hoping to perhaps contribute some day, is it possible to do this?

1806336000/80/64 = 352.8kHz 1806336000/147/64 = 192kHz ... 1806336000/640/64 = 44.1kHz

pelwell commented 7 months ago

It's more complicated than that:

  1. The maximum PLL frequency is 2.4GHz.
  2. There are two intermediate divisors with different ranges to choose from, both integer only, and /1 is not an option.
  3. The final divisor for clk_i2s is only 8 bits, making it all-too-easy to put the lower frequencies out of reach.

I think we're going to have to modify the clock driver to switch between a number of PLL values.

j-schambacher commented 7 months ago

@pelwell Finally - I hope - I've managed to dig into the DT, I2S module and clk_producer/clk_consumer stuff. Before going further and draw conclusions, I just want to x-check: the main reason for all older hats (providing clocks) not working lies in the formerly required GPIO settings in the HAT EEPROM applying ALT-0 (I2S producer) to the I2S0 module. The only way I've found is to use force_eeprom_read=0 and manually applying the correct overlay. Or, and I think this is the better solution, to provide all the UUIDs, because once the UUID is detected, the rest of HAT-data is completely ignored. Correct?

pelwell commented 7 months ago

@clone206 #5999 has been updated with code to change the PLL settings on demand. The auto builds have almost finished - another 10 minutes, perhaps - and then its the usual sudo rpi-update pulls/5999 to install.

pelwell commented 7 months ago

@j-schambacher The hat_map only affects the overlay side of things, finding the associated overlay and overriding any overlay (or overlay name) found in the HAT EEPROM. The GPIO settings from the EEPROM are unaffected, but I don't yet understand how they might be causing you a problem.

Can you post a dump of an EEPROM image that shows the failure?

j-schambacher commented 7 months ago

@pelwell Here is the HAT dump (from an older DAC+ Pro):

# ---------- Dump generated by eepdump handling format version 0x01 ----------
#
# --Header--
# signature=0x69502d52
# version=0x01
# reserved=0
# numatoms=3
# eeplen=1465
# ----------

# Start of atom #0 of type 0x0001 and length 37
# Vendor info
product_uuid ef586afc-2efa-47a0-be2e-95a7d952fe98
product_id 0x0000
product_ver 0x0000
vendor "HiFiBerry"   # length=9
product "DAC+"   # length=4
# End of atom. CRC16=0x8c1e

# Start of atom #1 of type 0x0002 and length 32
# GPIO map info
gpio_drive 0
gpio_slew 0
gpio_hysteresis 0
back_power 0
#        GPIO  FUNCTION  PULL
#        ----  --------  ----
setgpio  2      ALT0     UP
setgpio  3      ALT0     UP
setgpio  18      ALT0     DEFAULT
setgpio  19      ALT0     DEFAULT
setgpio  20      ALT0     DEFAULT
setgpio  21      ALT0     DEFAULT
# End of atom. CRC16=0x9700

# Start of atom #2 of type 0x0003 and length 1360
dt_blob
D0 0D FE ED 00 00 05 4E 00 00 00 38 00 00 04 9C 
00 00 00 28 00 00 00 11 00 00 00 10 00 00 00 00 
.
.
and so on

and here is the serial log showing that the GPIO config from the EEPROM is loaded trying to use the pins at I2S@a0000 (which is the I2S0). Later, when the driver tries to change the master/slave behavior it fails because of the GPIO/I2S settings.

Read bcm2712-rpi-5-b.dtb bytes    75445 hnd 0x239ba
MESS:00:00:07.116058:0: dtdebug: delete_node(/__local_fixups__)
Read /overlays/overlay_map.dtb bytes     5195 hnd 0x23be7
MESS:00:00:07.142770:0: dtdebug: using platform 'bcm2712'
MESS:00:00:07.150655:0: dtdebug: overlay map loaded
Read /overlays/hat_map.dtb bytes      489 hnd 0x23d43
Read /config.txt bytes     1384 hnd 0x23d42
MESS:00:00:07.232293:0: dtdebug: merge_fragment(/clocks,/fragment@0/__overlay__)
MESS:00:00:07.242099:0: dtdebug: merge_fragment(/clocks/dacpro_osc,/fragment@0/__overlay__/dacpro_osc)
MESS:00:00:07.248332:0: dtdebug:   +prop(compatible)
MESS:00:00:07.253491:0: dtdebug:   +prop(#clock-cells)
MESS:00:00:07.258396:0: dtdebug:   +prop(phandle)
MESS:00:00:07.262842:0: dtdebug: merge_fragment() end
MESS:00:00:07.267184:0: dtdebug: merge_fragment() end
MESS:00:00:07.281721:0: dtdebug: merge_fragment(/axi/pcie@120000/rp1/i2s@a0000,/fragment@1/__overlay__)
MESS:00:00:07.288032:0: dtdebug:   +prop(status)
MESS:00:00:07.293115:0: dtdebug: merge_fragment() end
MESS:00:00:07.306362:0: dtdebug: merge_fragment(/axi/pcie@120000/rp1/i2c@74000,/fragment@2/__overlay__)
MESS:00:00:07.312674:0: dtdebug:   +prop(#address-cells)
MESS:00:00:07.318501:0: dtdebug:   +prop(#size-cells)
MESS:00:00:07.323303:0: dtdebug:   +prop(status)
MESS:00:00:07.331139:0: dtdebug: merge_fragment(/axi/pcie@120000/rp1/i2c@74000/pcm5122@4d,/fragment@2/__overlay__/pcm5122@4d)
MESS:00:00:07.339372:0: dtdebug:   +prop(#sound-dai-cells)
MESS:00:00:07.345417:0: dtdebug:   +prop(compatible)
MESS:00:00:07.350041:0: dtdebug:   +prop(reg)
MESS:00:00:07.354151:0: dtdebug:   +prop(clocks)

In the kernel messages you find a lot of deferred probe messages. I think the problem is the GPIO setting. Is that why the new HAT+ spec does not allow type 2 atoms anymore? The listing above is for the case if the UUID is not recognized in the hat_map. Once it is found, it works fine. Also 'strange' the HAT UUID seems to be only recognized once there is also the DT-voerlay in the EERPROM defined?! The reason why I did not get it to work earlier.

clone206 commented 7 months ago

@clone206 #5999 has been updated with code to change the PLL settings on demand. The auto builds have almost finished - another 10 minutes, perhaps - and then its the usual sudo rpi-update pulls/5999 to install.

Confirming all is well after updating. The HAT locks onto anything I throw at it now. This will make a lot of audiophiles happy. Thank you!

Going to analyze the PR and hopefully learn some things.

clone206 commented 7 months ago

One minor update, I'm still seeing the issue with DoP with the updated PR. This one is curious to me since AFAIK nothing in the chain should be the wiser as the DSD bits are "smuggled" in through normal PCM packets. Still, it's minor as the HAT can directly decode the DoP and pass along the native DSD bitstream to the DAC. But it did work on the pi 4 without needing the HAT's decoder enabled.

Also, I'm getting the occasional dropout with dsd128 (352.8kHz effective PCM rate via DoP), but not when playing 352.8kHz PCM content. It seems the HAT may be struggling to decode the DoP in some way.

https://dsd-guide.com/dop-open-standard

pelwell commented 7 months ago

I think the problem is the GPIO setting. Is that why the new HAT+ spec does not allow type 2 atoms anymore?

I don't see how the kernel can be affected by the way the GPIOs and pinmux have been configured. The pinctrl driver doesn't read back the state of the registers to see if a pin is in use - that state is kept in the pinctrl framework, and all pins start out as unclaimed.

The only way I've found is to use force_eeprom_read=0 and manually applying the correct overlay

Are you saying that putting dtoverlay= at the top of config.txt doesn't help?

j-schambacher commented 7 months ago

dtoverlay= works as well. Sorry, didn't mention.

I don't see how the kernel can be affected by the way the GPIOs and pinmux have been configured. The pinctrl driver doesn't read back the state of the registers to see if a pin is in use - that state is kept in the pinctrl framework, and all pins start out as unclaimed.

Then the question remains, why the kernel can't (re)claim the IOs? I'll do some more testing and let you know.

pelwell commented 7 months ago

I'm still seeing the issue with DoP with the updated PR ... it's minor as the HAT can directly decode the DoP and pass along the native DSD bitstream to the DAC.

Also, I'm getting the occasional dropout with dsd128 (352.8kHz effective PCM rate via DoP),

Can you explain the difference between these two statements? As somebody unfamiliar with the use of digital audio they sound the same. It would help me if you could briefly outline the data flow in these scenarios (and it sounds like the first one has two versions - one where the HAT does the decoding and one where it passes the DoP through).

Unless I get a bad review comment I'll get this PR merged and treat DoP as a separate problem.

pelwell commented 7 months ago

dtoverlay= works as well. Sorry, didn't mention.

Thanks - that helps to narrow down the problem, because this line definitely does not affect the GPIO setup.

Would you mind including the entirety of the EEPROM dt_blob data? I'd like to confirm why it fails on a Pi 5.

j-schambacher commented 7 months ago

Here it is:

# ---------- Dump generated by eepdump handling format version 0x01 ----------
#
# --Header--
# signature=0x69502d52
# version=0x01
# reserved=0
# numatoms=3
# eeplen=1465
# ----------

# Start of atom #0 of type 0x0001 and length 37
# Vendor info
product_uuid ef586afc-2efa-47a0-be2e-95a7d952fe98
product_id 0x0000
product_ver 0x0000
vendor "HiFiBerry"   # length=9
product "DAC+"   # length=4
# End of atom. CRC16=0x8c1e

# Start of atom #1 of type 0x0002 and length 32
# GPIO map info
gpio_drive 0
gpio_slew 0
gpio_hysteresis 0
back_power 0
#        GPIO  FUNCTION  PULL
#        ----  --------  ----
setgpio  2      ALT0     UP
setgpio  3      ALT0     UP
setgpio  18      ALT0     DEFAULT
setgpio  19      ALT0     DEFAULT
setgpio  20      ALT0     DEFAULT
setgpio  21      ALT0     DEFAULT
# End of atom. CRC16=0x9700

# Start of atom #2 of type 0x0003 and length 1360
dt_blob
D0 0D FE ED 00 00 05 4E 00 00 00 38 00 00 04 9C 
00 00 00 28 00 00 00 11 00 00 00 10 00 00 00 00 
00 00 00 B2 00 00 04 64 00 00 00 00 00 00 00 00 
00 00 00 00 00 00 00 00 00 00 00 01 00 00 00 00 
00 00 00 03 00 00 00 0D 00 00 00 00 62 72 63 6D 
2C 62 63 6D 32 37 30 38 00 00 00 00 00 00 00 01 
66 72 61 67 6D 65 6E 74 40 30 00 00 00 00 00 03 
00 00 00 08 00 00 00 0B 2F 63 6C 6F 63 6B 73 00 
00 00 00 01 5F 5F 6F 76 65 72 6C 61 79 5F 5F 00 
00 00 00 01 64 61 63 70 72 6F 5F 6F 73 63 00 00 
00 00 00 03 00 00 00 15 00 00 00 00 68 69 66 69 
62 65 72 72 79 2C 64 61 63 70 72 6F 2D 63 6C 6B 
00 00 00 00 00 00 00 03 00 00 00 04 00 00 00 17 
00 00 00 00 00 00 00 03 00 00 00 04 00 00 00 24 
00 00 00 01 00 00 00 02 00 00 00 02 00 00 00 02 
00 00 00 01 66 72 61 67 6D 65 6E 74 40 31 00 00 
00 00 00 03 00 00 00 04 00 00 00 2C DE AD BE EF 
00 00 00 01 5F 5F 6F 76 65 72 6C 61 79 5F 5F 00 
00 00 00 03 00 00 00 05 00 00 00 33 6F 6B 61 79 
00 00 00 00 00 00 00 02 00 00 00 02 00 00 00 01 
66 72 61 67 6D 65 6E 74 40 32 00 00 00 00 00 03 
00 00 00 04 00 00 00 2C DE AD BE EF 00 00 00 01 
5F 5F 6F 76 65 72 6C 61 79 5F 5F 00 00 00 00 03 
00 00 00 04 00 00 00 3A 00 00 00 01 00 00 00 03 
00 00 00 04 00 00 00 49 00 00 00 00 00 00 00 03 
00 00 00 05 00 00 00 33 6F 6B 61 79 00 00 00 00 
00 00 00 01 70 63 6D 35 31 32 32 40 34 64 00 00 
00 00 00 03 00 00 00 04 00 00 00 55 00 00 00 00 
00 00 00 03 00 00 00 0B 00 00 00 00 74 69 2C 70 
63 6D 35 31 32 32 00 00 00 00 00 03 00 00 00 04 
00 00 00 66 00 00 00 4D 00 00 00 03 00 00 00 04 
00 00 00 6A 00 00 00 01 00 00 00 03 00 00 00 05 
00 00 00 33 6F 6B 61 79 00 00 00 00 00 00 00 02 
00 00 00 02 00 00 00 02 00 00 00 01 66 72 61 67 
6D 65 6E 74 40 33 00 00 00 00 00 03 00 00 00 04 
00 00 00 2C DE AD BE EF 00 00 00 01 5F 5F 6F 76 
65 72 6C 61 79 5F 5F 00 00 00 00 03 00 00 00 1C 
00 00 00 00 68 69 66 69 62 65 72 72 79 2C 68 69 
66 69 62 65 72 72 79 2D 64 61 63 70 6C 75 73 00 
00 00 00 03 00 00 00 04 00 00 00 71 DE AD BE EF 
00 00 00 03 00 00 00 05 00 00 00 33 6F 6B 61 79 
00 00 00 00 00 00 00 03 00 00 00 04 00 00 00 24 
00 00 00 02 00 00 00 02 00 00 00 02 00 00 00 01 
5F 5F 6F 76 65 72 72 69 64 65 73 5F 5F 00 00 00 
00 00 00 03 00 00 00 21 00 00 00 80 00 00 00 02 
68 69 66 69 62 65 72 72 79 2C 32 34 64 62 5F 64 
69 67 69 74 61 6C 5F 67 61 69 6E 3F 00 00 00 00 
00 00 00 02 00 00 00 01 5F 5F 73 79 6D 62 6F 6C 
73 5F 5F 00 00 00 00 03 00 00 00 23 00 00 00 92 
2F 66 72 61 67 6D 65 6E 74 40 30 2F 5F 5F 6F 76 
65 72 6C 61 79 5F 5F 2F 64 61 63 70 72 6F 5F 6F 
73 63 00 00 00 00 00 03 00 00 00 18 00 00 00 9D 
2F 66 72 61 67 6D 65 6E 74 40 33 2F 5F 5F 6F 76 
65 72 6C 61 79 5F 5F 00 00 00 00 02 00 00 00 01 
5F 5F 6C 6F 63 61 6C 5F 66 69 78 75 70 73 5F 5F 
00 00 00 00 00 00 00 01 66 72 61 67 6D 65 6E 74 
40 32 00 00 00 00 00 01 5F 5F 6F 76 65 72 6C 61 
79 5F 5F 00 00 00 00 01 70 63 6D 35 31 32 32 40 
34 64 00 00 00 00 00 03 00 00 00 04 00 00 00 6A 
00 00 00 00 00 00 00 02 00 00 00 02 00 00 00 02 
00 00 00 01 5F 5F 6F 76 65 72 72 69 64 65 73 5F 
5F 00 00 00 00 00 00 03 00 00 00 04 00 00 00 80 
00 00 00 00 00 00 00 02 00 00 00 02 00 00 00 01 
5F 5F 66 69 78 75 70 73 5F 5F 00 00 00 00 00 03 
00 00 00 3E 00 00 00 A3 2F 66 72 61 67 6D 65 6E 
74 40 31 3A 74 61 72 67 65 74 3A 30 00 2F 66 72 
61 67 6D 65 6E 74 40 33 2F 5F 5F 6F 76 65 72 6C 
61 79 5F 5F 3A 69 32 73 2D 63 6F 6E 74 72 6F 6C 
6C 65 72 3A 30 00 00 00 00 00 00 03 00 00 00 15 
00 00 00 A7 2F 66 72 61 67 6D 65 6E 74 40 32 3A 
74 61 72 67 65 74 3A 30 00 00 00 00 00 00 00 03 
00 00 00 15 00 00 00 AC 2F 66 72 61 67 6D 65 6E 
74 40 33 3A 74 61 72 67 65 74 3A 30 00 00 00 00 
00 00 00 02 00 00 00 02 00 00 00 09 63 6F 6D 70 
61 74 69 62 6C 65 00 74 61 72 67 65 74 2D 70 61 
74 68 00 23 63 6C 6F 63 6B 2D 63 65 6C 6C 73 00 
70 68 61 6E 64 6C 65 00 74 61 72 67 65 74 00 73 
74 61 74 75 73 00 23 61 64 64 72 65 73 73 2D 63 
65 6C 6C 73 00 23 73 69 7A 65 2D 63 65 6C 6C 73 
00 23 73 6F 75 6E 64 2D 64 61 69 2D 63 65 6C 6C 
73 00 72 65 67 00 63 6C 6F 63 6B 73 00 69 32 73 
2D 63 6F 6E 74 72 6F 6C 6C 65 72 00 32 34 64 62 
5F 64 69 67 69 74 61 6C 5F 67 61 69 6E 00 64 61 
63 70 72 6F 5F 6F 73 63 00 66 72 61 67 33 00 69 
32 73 00 69 32 63 31 00 73 6F 75 6E 64 00 
# End of atom. CRC16=0x5dcc
pelwell commented 7 months ago

The built-in overlay isn't loading properly because it is incompatible with current kernels.

You noticed the messages about deferred probing, and we can see that the cause is the dacpro clock:

pi@raspberrypi:~$ cat /sys/kernel/debug/devices_deferred
soc:sound
1-004d  i2c: wait for supplier /clocks/dacpro_osc

A quick lsmod shows that the clock driver module hasn't been loaded, and instrumenting the driver confirms that to be the case.

Why isn't it being loaded and probed? Because of a change between 4.19 and 5.4 to the way clocks are probed. Here's the original issue: https://github.com/raspberrypi/linux/issues/3481

The TL;DR is that clocks created by modules have to be instantiated by DT nodes that are either children of a simple-bus parent or children of the root (/), i.e. the root is treated as a simple-bus. The old overlay puts its clock node into /clocks, but that is now only safe for fixed clocks.

j-schambacher commented 7 months ago

Oh, thanks, Phil! And sorry for the confusion. This means I'll submit ASAP the UUIDs for the hat_map and hopefully even that old stuff gets resolved. I've totally forgotten that problem with the clocks. Do you want separate commits per UUID ? Or for now just a list/combined commit?

pelwell commented 7 months ago

All the downstream DT commits get squashed into one when we port to newer kernels, so one commit for all of them is fine.

clone206 commented 7 months ago

I'm still seeing the issue with DoP with the updated PR ... it's minor as the HAT can directly decode the DoP and pass along the native DSD bitstream to the DAC.

Also, I'm getting the occasional dropout with dsd128 (352.8kHz effective PCM rate via DoP),

Can you explain the difference between these two statements? As somebody unfamiliar with the use of digital audio they sound the same. It would help me if you could briefly outline the data flow in these scenarios (and it sounds like the first one has two versions - one where the HAT does the decoding and one where it passes the DoP through).

Unless I get a bad review comment I'll get this PR merged and treat DoP as a separate problem.

One statement makes note of the fact that I'm unable to pass DoP through to my DAC. I just get low level noise on playback and the DAC's display shows that it's interpreting the stream as PCM. But, I can set the HAT to do the decoding of the DoP, which then allows my DAC to "see" DSD and thus allows me to hear the audio.

The other statement makes note of the fact that when the HAT is decoding dsd128 (128 x 44.1K) DoP, I hear dropouts, i.e. discontinuities in the sound. Sometimes there is also a popping sound accompanying the dropout. I don't hear dropouts when the HAT is decoding dsd64 DoP, or at any PCM sample rate.

Just giving as much info as possible about symptoms. The link I posted describes how in DoP the DSD marker occupies the 8 MSBs of each PCM frame, alternating between 2 values every other sample. If I had to guess I would think something is making it difficult for the FIFO HAT to see those markers at the right time, causing buffer underruns or causing the HAT to see some samples as PCM instead of DSD.

Maybe a jittery/drifting L/R clock signal?

clone206 commented 6 months ago

Another data point. I tried with another DAC whose display gives a bit more info (and refreshes more quickly) than the DAC I was previously testing with.

Got the same symptoms described above with dsd128 content. But this time I could see that when the dropouts were happening, the DAC's screen briefly reported it was receiving 352.8kHz PCM before switching back to dsd128. Maybe this does indicate that the DoP markers aren't always seen at the right time, perhaps indicating some kind of word select timing issue.

With PCM content I could see how this could more easily go unnoticed. I do think I may have heard a few very faint pops when listening to dsd64 content as well. Maybe it's just less severe at lower rates.

pelwell commented 6 months ago

But can you account for the fact that 352.8kHz audio sounds OK? Wouldn't timing problems at that level cause samples to be scrambled?

And the waveforms look solid on a logic analyser.

clone206 commented 6 months ago

But can you account for the fact that 352.8kHz audio sounds OK? Wouldn't timing problems at that level cause samples to be scrambled?

And the waveforms look solid on a logic analyser.

To be honest I don't have a ton of 352.8kHz content. If anything at that sample rate I bet the popping would be so faint that it could easily be missed. DACs do tend to pop and have dropouts when the incoming format changes between DSD and PCM. But this problem is intermittent enough that I could see how you could get a perfect readout with a small enough sample.

BTW this doesn't happen with the same HATs on the pi 4.