philippe44/LMS-Raop

Restarting Squeeze2raop after crash

Closed this issue · 12 comments

andyfw commented

I am suing LMS/PiCore player on a RPI4/8GB. There are plent of resources (cpu, mem, disk) but I am having continual (range 10 sec to 1:20) crashes when enabling the airport bridge. Disabling the plugin stops them. so I am quite sure it is an interaction between my setup and the plugin. I have an example from the log file below. I also included the output of dmesg below that which shows all the other installed versions.

The plugin seems to allow discovery of the Airplay devices on my network fine, although I have not been able to sucessfully play through any of them .... maybe because it keeps crashing.

I am also use in Shairplay which works perfectly. In fact everything does on this setup up to the the Airplay Bridge. This would be the last thing to configure to make this setup perfect. Please let me know if you need more information to look into this bug.

[15:34:39.659646] Start:1293 Binding to 192.168.124.233
[15:34:39.659992] StartActiveRemote:1185 DACP port: 52181
[15:34:39.981404] AddRaopDevice:851 [0x611140]: AppleTV with authentication (pairing must be done separately)
[15:34:39.981467] AddRaopDevice:909 [0x611140]: adding renderer (Master-Bedroom@192.168.124.146) with mac AAAA-DBDAECE3
[15:34:39.981522] raopcl_create:713 [0x7fa4009950]: using PCM coding
[15:34:39.985595] output_raop_thread_init:126 [0x5b8c78]: init output raop
[15:34:39.985654] output_init_common:290 allocating 1764000
[15:34:39.985973] mDNSsearchCallback:726 Updating configuration /usr/local/slimserver/prefs/raopbridge.xml
[15:34:39.986841] slimproto:830 squeezelite [0x5b8c78] <=> player [0x611140]
[15:34:39.986870] slimproto:831 [0x5b8c78] connecting to 192.168.124.233:3483
[15:34:39.986894] AddRaopDevice:851 [0x611f38]: AppleTV with authentication (pairing must be done separately)
[15:34:39.986951] AddRaopDevice:909 [0x611f38]: adding renderer (Living-Room@192.168.124.202) with mac AAAA-BD01AEB4
[15:34:39.987013] raopcl_create:713 [0x7fa401e340]: using PCM coding
[15:34:39.987193] slimproto:861 [0x5b8c78] connected
[15:34:39.987297] sendHELO:107 [0x5b8c78] cap: CanHTTPS=1,Model=squeezelite,ModelName=RaopBridge,AccuratePlayPoints=0,HasDigitalOut=1,MaxSampleRate=96000,aac,ogg,ops,ogf,flc,alc,wav,aif,pcm,mp3
[15:34:39.990361] output_raop_thread_init:126 [0x5bb888]: init output raop
[15:34:39.990411] output_init_common:290 allocating 1764000
[15:34:39.990752] mDNSsearchCallback:726 Updating configuration /usr/local/slimserver/prefs/raopbridge.xml
[15:34:39.991549] PlayerThread:584 [0x611140]: processing volume device:49 request:-15.31
[15:34:39.991850] AddRaopDevice:909 [0x612d30]: adding renderer (Marantz-SR5009@192.168.124.11) with mac AAAA-DF361A0E
[15:34:39.991914] raopcl_create:713 [0x7fa40251e0]: using PCM coding
[15:34:39.993788] slimproto:830 squeezelite [0x5bb888] <=> player [0x611f38]
[15:34:39.993832] slimproto:831 [0x5bb888] connecting to 192.168.124.233:3483
[15:34:39.994094] slimproto:861 [0x5bb888] connected
[15:34:39.994241] sendHELO:107 [0x5bb888] cap: CanHTTPS=1,Model=squeezelite,ModelName=RaopBridge,AccuratePlayPoints=0,HasDigitalOut=1,MaxSampleRate=96000,aac,ogg,ops,ogf,flc,alc,wav,aif,pcm,mp3
[15:34:39.995384] output_raop_thread_init:126 [0x5be498]: init output raop
[15:34:39.995435] output_init_common:290 allocating 1764000
[15:34:39.995771] mDNSsearchCallback:726 Updating configuration /usr/local/slimserver/prefs/raopbridge.xml
[15:34:39.997511] PlayerThread:584 [0x611f38]: processing volume device:49 request:-15.31
[15:34:39.998857] slimproto:830 squeezelite [0x5be498] <=> player [0x612d30]
[15:34:39.998888] slimproto:831 [0x5be498] connecting to 192.168.124.233:3483
[15:34:39.999178] slimproto:861 [0x5be498] connected
[15:34:39.999277] sendHELO:107 [0x5be498] cap: CanHTTPS=1,Model=squeezelite,ModelName=RaopBridge,AccuratePlayPoints=0,HasDigitalOut=1,MaxSampleRate=96000,aac,ogg,ops,ogf,flc,alc,wav,aif,pcm,mp3
[15:34:40.018302] process_strm:230 [0x5be498] strm command s
[15:34:40.018341] process_strm:304 [0x5be498], strm s autostart: 0 transition period: 10 transition type: 0 codec: p
[15:34:40.018442] process_strm:337 [0x5be498]: codec:p, ch:2, s:16, r:44100
[15:34:40.019557] PlayerThread:584 [0x612d30]: processing volume device:49 request:-15.31
[15:34:40.113461] process_strm:230 [0x5be498] strm command u
[15:34:40.113494] raopcl_start_at:373 [0x7fa40251e0]: set start time 1693607679.253362176 (ts:74688098646501)
[15:34:40.113559] PlayerThread:561 [0x612d30]: raop connecting ...
[15:34:40.113911] process_strm:290 [0x5be498]: unpause at: 1390565685 now: 1390565489
[15:34:40.116496] raopcl_accept_frames:424 [0x7fa40251e0]: restarting w/o pause n:1693607680.500342215, hts:74688098646501
[15:34:40.195807] check_header:117 [0x5be498]: unknown format - can't parse header
[15:34:40.197118] _output_frames:100 [0x5be498]: track start sample rate: 44100 replay_gain: 0
[15:34:40.207376] output_raop_thread:98 [0x5be498]: track actual start time:1390565684 (gap:-1)
[15:34:40.216927] raopcl_connect:996 [0x7fa40251e0]: local interface 192.168.124.233
[15:34:40.742629] exec_request:691 [0x7fa401d7d0]: Body data len 1076
[15:34:40.761360] exec_request:635 [0x7fa401d7d0]: <------ : request failed, error 500

Restarting Squeeze2raop after crash: /usr/local/slimserver/Cache/InstalledPlugins/Plugins/RaopBridge/Bin/squeeze2raop-linux-aarch64 -Z -I -x /usr/local/slimserver/prefs/raopbridge.xml

dmesg output ***********
[ 0.000000] Booting Linux on physical CPU 0x0000000000 [0x410fd083]
[ 0.000000] Linux version 5.15.35-pcpCore-v8 (pCP@SoundStation) (aarch64-linux-gnu-gcc (crosstool-NG 1.24.0.351_511442b) 10.3.0, GNU ld (crosstool-NG 1.24.0.351_511442b) 2.34) #1 SMP PREEMPT Tue Apr 26 23:22:33 EDT 2022
[ 0.000000] random: fast init done
[ 0.000000] Machine model: Raspberry Pi 4 Model B Rev 1.4
[ 0.000000] efi: UEFI not found.
[ 0.000000] Reserved memory: created CMA memory pool at 0x000000002a800000, size 64 MiB
[ 0.000000] OF: reserved mem: initialized node linux,cma, compatible id shared-dma-pool
[ 0.000000] Zone ranges:
[ 0.000000] DMA [mem 0x0000000000000000-0x000000003fffffff]
[ 0.000000] DMA32 [mem 0x0000000040000000-0x00000000ffffffff]
[ 0.000000] Normal [mem 0x0000000100000000-0x00000001ffffffff]
[ 0.000000] Movable zone start for each node
[ 0.000000] Early memory node ranges
[ 0.000000] node 0: [mem 0x0000000000000000-0x000000003e5fffff]
[ 0.000000] node 0: [mem 0x0000000040000000-0x00000000fbffffff]
[ 0.000000] node 0: [mem 0x0000000100000000-0x00000001ffffffff]
[ 0.000000] Initmem setup node 0 [mem 0x0000000000000000-0x00000001ffffffff]
[ 0.000000] On node 0, zone DMA32: 512 pages in unavailable ranges
[ 0.000000] percpu: Embedded 28 pages/cpu s77144 r8192 d29352 u114688
[ 0.000000] pcpu-alloc: s77144 r8192 d29352 u114688 alloc=28*4096
[ 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: Spectre-v2
[ 0.000000] CPU features: detected: Spectre-v3a
[ 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] CPU features: detected: ARM errata 1165522, 1319367, or 1530923
[ 0.000000] Built 1 zonelists, mobility grouping on. Total pages: 2041344
[ 0.000000] Kernel command line: coherent_pool=1M 8250.nr_uarts=0 snd_bcm2835.enable_compat_alsa=0 snd_bcm2835.enable_hdmi=1 bcm2708_fb.fbwidth=0 bcm2708_fb.fbheight=0 bcm2708_fb.fbdepth=16 bcm2708_fb.fbswap=1 smsc95xx.macaddr=DC:A6:32:C4:31:D2 vc_mem.mem_base=0x3f000000 vc_mem.mem_size=0x3f600000 host=LGpCP tz=PST8PDT,M3.2.0,M11.1.0 dwc_otg.fiq_fsm_mask=0xF dwc_otg.lpm_enable=0 console=tty1 root=/dev/ram0 rootwait quiet nortc loglevel=3 noembed smsc95xx.turbo_mode=N noswap consoleblank=0 waitusb=2
[ 0.000000] Unknown kernel command line parameters "nortc noembed noswap host=LGpCP tz=PST8PDT,M3.2.0,M11.1.0 waitusb=2", will be passed to user space.
[ 0.000000] Dentry cache hash table entries: 1048576 (order: 11, 8388608 bytes, linear)
[ 0.000000] Inode-cache hash table entries: 524288 (order: 10, 4194304 bytes, linear)
[ 0.000000] mem auto-init: stack:off, heap alloc:off, heap free:off
[ 0.000000] software IO TLB: mapped [mem 0x000000003a600000-0x000000003e600000] (64MB)
[ 0.000000] Memory: 7976396K/8296448K available (11776K kernel code, 1958K rwdata, 4112K rodata, 3776K init, 968K bss, 254516K reserved, 65536K cma-reserved)
[ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1
[ 0.000000] ftrace: allocating 36759 entries in 144 pages
[ 0.000000] ftrace: allocated 144 pages with 2 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] random: get_random_bytes called from start_kernel+0x514/0x70c with crng_init=1
[ 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.000118] Console: colour dummy device 80x25
[ 0.000144] printk: console [tty1] enabled
[ 0.000177] Calibrating delay loop (skipped), value calculated using timer frequency.. 108.00 BogoMIPS (lpj=216000)
[ 0.000187] pid_max: default: 32768 minimum: 301
[ 0.000238] LSM: Security Framework initializing
[ 0.000390] Mount-cache hash table entries: 16384 (order: 5, 131072 bytes, linear)
[ 0.000451] Mountpoint-cache hash table entries: 16384 (order: 5, 131072 bytes, linear)
[ 0.001005] cgroup: Disabling memory control group subsystem
[ 0.002146] rcu: Hierarchical SRCU implementation.
[ 0.002675] EFI services will not be available.
[ 0.002911] smp: Bringing up secondary CPUs ...
[ 0.003367] Detected PIPT I-cache on CPU1
[ 0.003409] CPU1: Booted secondary processor 0x0000000001 [0x410fd083]
[ 0.003905] Detected PIPT I-cache on CPU2
[ 0.003925] CPU2: Booted secondary processor 0x0000000002 [0x410fd083]
[ 0.004438] Detected PIPT I-cache on CPU3
[ 0.004457] CPU3: Booted secondary processor 0x0000000003 [0x410fd083]
[ 0.004516] smp: Brought up 1 node, 4 CPUs
[ 0.004524] SMP: Total of 4 processors activated.
[ 0.004528] CPU features: detected: 32-bit EL0 Support
[ 0.004532] CPU features: detected: 32-bit EL1 Support
[ 0.004537] CPU features: detected: CRC32 instructions
[ 0.018146] CPU: All CPU(s) started at EL2
[ 0.018182] alternatives: patching kernel code
[ 0.019280] devtmpfs: initialized
[ 0.023805] Enabled cp15_barrier support
[ 0.023826] Enabled setend support
[ 0.023835] KASLR enabled
[ 0.023924] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645041785100000 ns
[ 0.023940] futex hash table entries: 1024 (order: 4, 65536 bytes, linear)
[ 0.025296] pinctrl core: initialized pinctrl subsystem
[ 0.025702] DMI not present or invalid.
[ 0.025960] NET: Registered PF_NETLINK/PF_ROUTE protocol family
[ 0.027560] DMA: preallocated 1024 KiB GFP_KERNEL pool for atomic allocations
[ 0.027683] DMA: preallocated 1024 KiB GFP_KERNEL|GFP_DMA pool for atomic allocations
[ 0.028062] DMA: preallocated 1024 KiB GFP_KERNEL|GFP_DMA32 pool for atomic allocations
[ 0.028109] audit: initializing netlink subsys (disabled)
[ 0.028236] audit: type=2000 audit(0.028:1): state=initialized audit_enabled=0 res=1
[ 0.028452] thermal_sys: Registered thermal governor 'step_wise'
[ 0.028553] cpuidle: using governor menu
[ 0.028658] hw-breakpoint: found 6 breakpoint and 4 watchpoint registers.
[ 0.028739] ASID allocator initialised with 32768 entries
[ 0.028814] Serial: AMBA PL011 UART driver
[ 0.032907] bcm2835-mbox fe00b880.mailbox: mailbox enabled
[ 0.044062] raspberrypi-firmware soc:firmware: Attached to firmware from 2022-04-13T14:49:35, variant start_cd
[ 0.048069] raspberrypi-firmware soc:firmware: Firmware hash is c073992a577d160d8c30bfcf746d2208951c0537
[ 0.069877] bcm2835-dma fe007000.dma: DMA legacy API manager, dmachans=0x1
[ 0.071527] vgaarb: loaded
[ 0.071721] SCSI subsystem initialized
[ 0.071814] usbcore: registered new interface driver usbfs
[ 0.071835] usbcore: registered new interface driver hub
[ 0.071864] usbcore: registered new device driver usb
[ 0.071995] usb_phy_generic phy: supply vcc not found, using dummy regulator
[ 0.072251] pps_core: LinuxPPS API ver. 1 registered
[ 0.072256] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo Giometti giometti@linux.it
[ 0.072266] PTP clock support registered
[ 0.072911] clocksource: Switched to clocksource arch_sys_counter
[ 0.121185] VFS: Disk quotas dquot_6.6.0
[ 0.121235] VFS: Dquot-cache hash table entries: 512 (order 0, 4096 bytes)
[ 0.121310] FS-Cache: Loaded
[ 0.121431] CacheFiles: Loaded
[ 0.125696] NET: Registered PF_INET protocol family
[ 0.126250] IP idents hash table entries: 131072 (order: 8, 1048576 bytes, linear)
[ 0.128755] tcp_listen_portaddr_hash hash table entries: 4096 (order: 4, 65536 bytes, linear)
[ 0.128804] TCP established hash table entries: 65536 (order: 7, 524288 bytes, linear)
[ 0.129017] TCP bind hash table entries: 65536 (order: 8, 1048576 bytes, linear)
[ 0.129891] TCP: Hash tables configured (established 65536 bind 65536)
[ 0.130090] UDP hash table entries: 4096 (order: 5, 131072 bytes, linear)
[ 0.130154] UDP-Lite hash table entries: 4096 (order: 5, 131072 bytes, linear)
[ 0.130353] NET: Registered PF_UNIX/PF_LOCAL protocol family
[ 0.130902] RPC: Registered named UNIX socket transport module.
[ 0.130909] RPC: Registered udp transport module.
[ 0.130913] RPC: Registered tcp transport module.
[ 0.130918] RPC: Registered tcp NFSv4.1 backchannel transport module.
[ 0.130927] PCI: CLS 0 bytes, default 64
[ 0.131245] Trying to unpack rootfs image as initramfs...
[ 0.141887] hw perfevents: enabled with armv8_cortex_a72 PMU driver, 7 counters available
[ 0.142054] kvm [1]: IPA Size Limit: 44 bits
[ 0.142573] kvm [1]: vgic interrupt IRQ9
[ 0.142694] kvm [1]: Hyp mode initialized successfully
[ 0.274615] Freeing initrd memory: 5096K
[ 0.484520] Initialise system trusted keyrings
[ 0.484729] workingset: timestamp_bits=46 max_order=21 bucket_order=0
[ 0.487459] zbud: loaded
[ 0.488234] FS-Cache: Netfs 'nfs' registered for caching
[ 0.488549] NFS: Registering the id_resolver key type
[ 0.488571] Key type id_resolver registered
[ 0.488576] Key type id_legacy registered
[ 0.488619] nfs4filelayout_init: NFSv4 File Layout Driver Registering...
[ 0.488625] nfs4flexfilelayout_init: NFSv4 Flexfile Layout Driver Registering...
[ 0.489177] Key type asymmetric registered
[ 0.489184] Asymmetric key parser 'x509' registered
[ 0.489224] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 247)
[ 0.489343] io scheduler mq-deadline registered
[ 0.489349] io scheduler kyber registered
[ 0.492421] brcm-pcie fd500000.pcie: host bridge /scb/pcie@7d500000 ranges:
[ 0.492440] brcm-pcie fd500000.pcie: No bus range found for /scb/pcie@7d500000, using [bus 00-ff]
[ 0.492474] brcm-pcie fd500000.pcie: MEM 0x0600000000..0x063fffffff -> 0x00c0000000
[ 0.492507] brcm-pcie fd500000.pcie: IB MEM 0x0000000000..0x00bfffffff -> 0x0400000000
[ 0.558974] brcm-pcie fd500000.pcie: link up, 5.0 GT/s PCIe x1 (SSC)
[ 0.559147] brcm-pcie fd500000.pcie: PCI host bridge to bus 0000:00
[ 0.559155] pci_bus 0000:00: root bus resource [bus 00-ff]
[ 0.559163] pci_bus 0000:00: root bus resource [mem 0x600000000-0x63fffffff] (bus address [0xc0000000-0xffffffff])
[ 0.559202] pci 0000:00:00.0: [14e4:2711] type 01 class 0x060400
[ 0.559310] pci 0000:00:00.0: PME# supported from D0 D3hot
[ 0.560823] pci 0000:00:00.0: bridge configuration invalid ([bus 00-00]), reconfiguring
[ 0.561009] pci 0000:01:00.0: [1106:3483] type 00 class 0x0c0330
[ 0.561100] pci 0000:01:00.0: reg 0x10: [mem 0x00000000-0x00000fff 64bit]
[ 0.561377] pci 0000:01:00.0: PME# supported from D0 D3hot
[ 0.574261] pci_bus 0000:01: busn_res: [bus 01-ff] end is updated to 01
[ 0.574283] pci 0000:00:00.0: BAR 8: assigned [mem 0x600000000-0x6000fffff]
[ 0.574292] pci 0000:01:00.0: BAR 0: assigned [mem 0x600000000-0x600000fff 64bit]
[ 0.574311] pci 0000:00:00.0: PCI bridge to [bus 01]
[ 0.574320] pci 0000:00:00.0: bridge window [mem 0x600000000-0x6000fffff]
[ 0.574716] bcm2708_fb soc:fb: Unable to determine number of FBs. Disabling driver.
[ 0.574723] bcm2708_fb: probe of soc:fb failed with error -2
[ 0.579034] iproc-rng200 fe104000.rng: hwrng registered
[ 0.579194] vc-mem: phys_addr:0x00000000 mem_base=0x3f000000 mem_size:0x3f600000(1014 MiB)
[ 0.579728] gpiomem-bcm2835 fe200000.gpiomem: Initialised: Registers at 0xfe200000
[ 0.584854] brd: module loaded
[ 0.589187] loop: module loaded
[ 0.589520] Loading iSCSI transport class v2.0-870.
[ 0.591588] bcmgenet fd580000.ethernet: GENET 5.0 EPHY: 0x0000
[ 0.648976] unimac-mdio unimac-mdio.-19: Broadcom UniMAC MDIO bus
[ 0.649496] usbcore: registered new interface driver r8152
[ 0.649523] usbcore: registered new interface driver lan78xx
[ 0.649543] usbcore: registered new interface driver smsc95xx
[ 0.705720] pci 0000:00:00.0: enabling device (0000 -> 0002)
[ 0.705835] xhci_hcd 0000:01:00.0: xHCI Host Controller
[ 0.705850] xhci_hcd 0000:01:00.0: new USB bus registered, assigned bus number 1
[ 0.706226] xhci_hcd 0000:01:00.0: hcc params 0x002841eb hci version 0x100 quirks 0x00003c0000000890
[ 0.706809] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 5.15
[ 0.706818] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[ 0.706824] usb usb1: Product: xHCI Host Controller
[ 0.706830] usb usb1: Manufacturer: Linux 5.15.35-pcpCore-v8 xhci-hcd
[ 0.706835] usb usb1: SerialNumber: 0000:01:00.0
[ 0.707149] hub 1-0:1.0: USB hub found
[ 0.707209] hub 1-0:1.0: 1 port detected
[ 0.707524] xhci_hcd 0000:01:00.0: xHCI Host Controller
[ 0.707533] xhci_hcd 0000:01:00.0: new USB bus registered, assigned bus number 2
[ 0.707541] xhci_hcd 0000:01:00.0: Host supports USB 3.0 SuperSpeed
[ 0.707776] usb usb2: New USB device found, idVendor=1d6b, idProduct=0003, bcdDevice= 5.15
[ 0.707784] usb usb2: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[ 0.707790] usb usb2: Product: xHCI Host Controller
[ 0.707795] usb usb2: Manufacturer: Linux 5.15.35-pcpCore-v8 xhci-hcd
[ 0.707800] usb usb2: SerialNumber: 0000:01:00.0
[ 0.708063] hub 2-0:1.0: USB hub found
[ 0.708094] hub 2-0:1.0: 4 ports detected
[ 0.708718] dwc_otg: version 3.00a 10-AUG-2012 (platform bus)
[ 0.708825] dwc_otg: FIQ enabled
[ 0.708829] dwc_otg: NAK holdoff enabled
[ 0.708833] dwc_otg: FIQ split-transaction FSM enabled
[ 0.708838] Module dwc_common_port init
[ 0.709110] usbcore: registered new interface driver uas
[ 0.709154] usbcore: registered new interface driver usb-storage
[ 0.709247] mousedev: PS/2 mouse device common for all mice
[ 0.711308] sdhci: Secure Digital Host Controller Interface driver
[ 0.711315] sdhci: Copyright(c) Pierre Ossman
[ 0.711534] sdhci-pltfm: SDHCI platform and OF driver helper
[ 0.713625] ledtrig-cpu: registered to indicate activity on CPUs
[ 0.713852] hid: raw HID events driver (C) Jiri Kosina
[ 0.713927] usbcore: registered new interface driver usbhid
[ 0.713932] usbhid: USB HID core driver
[ 0.714106] ashmem: initialized
[ 0.717774] Initializing XFRM netlink socket
[ 0.717799] NET: Registered PF_PACKET protocol family
[ 0.717859] Key type dns_resolver registered
[ 0.718340] registered taskstats version 1
[ 0.718361] Loading compiled-in X.509 certificates
[ 0.718676] Key type ._fscrypt registered
[ 0.718682] Key type .fscrypt registered
[ 0.718686] Key type fscrypt-provisioning registered
[ 0.724475] uart-pl011 fe201000.serial: there is not valid maps for state default
[ 0.724617] uart-pl011 fe201000.serial: cts_event_workaround enabled
[ 0.724696] fe201000.serial: ttyAMA0 at MMIO 0xfe201000 (irq = 17, base_baud = 0) is a PL011 rev2
[ 0.730677] bcm2835-wdt bcm2835-wdt: Broadcom BCM2835 watchdog timer
[ 0.730877] bcm2835-power bcm2835-power: Broadcom BCM2835 power domains driver
[ 0.731388] mmc-bcm2835 fe300000.mmcnr: mmc_debug:0 mmc_debug2:0
[ 0.731395] mmc-bcm2835 fe300000.mmcnr: DMA channel allocated
[ 0.760163] of_cfs_init
[ 0.760241] of_cfs_init: OK
[ 0.795590] mmc0: SDHCI controller on fe340000.mmc [fe340000.mmc] using ADMA
[ 0.800658] Freeing unused kernel memory: 3776K
[ 0.800765] Run /init as init process
[ 0.800769] with arguments:
[ 0.800773] /init
[ 0.800777] nortc
[ 0.800780] noembed
[ 0.800784] noswap
[ 0.800787] with environment:
[ 0.800790] HOME=/
[ 0.800794] TERM=linux
[ 0.800797] host=LGpCP
[ 0.800801] tz=PST8PDT,M3.2.0,M11.1.0
[ 0.800805] waitusb=2
[ 0.838124] mmc1: new high speed SDIO card at address 0001
[ 0.895518] mmc0: new ultra high speed DDR50 SDHC card at address aaaa
[ 0.896224] mmcblk0: mmc0:aaaa SL16G 14.8 GiB
[ 0.899632] mmcblk0: p1 p2
[ 0.899957] mmcblk0: mmc0:aaaa SL16G 14.8 GiB
[ 0.972940] usb 1-1: new high-speed USB device number 2 using xhci_hcd
[ 1.123602] usb 1-1: New USB device found, idVendor=2109, idProduct=3431, bcdDevice= 4.21
[ 1.123620] usb 1-1: New USB device strings: Mfr=0, Product=1, SerialNumber=0
[ 1.123626] usb 1-1: Product: USB2.0 Hub
[ 1.125112] hub 1-1:1.0: USB hub found
[ 1.125420] hub 1-1:1.0: 4 ports detected
[ 1.424924] usb 1-1.1: new high-speed USB device number 3 using xhci_hcd
[ 1.525572] usb 1-1.1: New USB device found, idVendor=152a, idProduct=85dd, bcdDevice= 6.f2
[ 1.525581] usb 1-1.1: New USB device strings: Mfr=1, Product=3, SerialNumber=0
[ 1.525587] usb 1-1.1: Product: SMSL SU8 USB2.0
[ 1.525593] usb 1-1.1: Manufacturer: SMSL
[ 3.151406] zram: Added device: zram0
[ 3.212433] zram0: detected capacity change from 0 to 3995120
[ 3.215079] random: mkswap: uninitialized urandom read (16 bytes read)
[ 3.218800] Adding 1997556k swap on /dev/zram0. Priority:-2 extents:1 across:1997556k SSFS
[ 3.273533] squashfs: version 4.0 (2009/01/31) Phillip Lougher
[ 3.537280] EXT4-fs (mmcblk0p2): recovery complete
[ 3.538284] EXT4-fs (mmcblk0p2): mounted filesystem with ordered data mode. Opts: (null). Quota mode: none.
[ 3.597137] EXT4-fs (mmcblk0p2): mounted filesystem with ordered data mode. Opts: (null). Quota mode: none.
[ 5.507027] Can't find a SQUASHFS superblock on loop48
[ 5.539990] Can't find a SQUASHFS superblock on loop50
[ 5.605698] Can't find a SQUASHFS superblock on loop50
[ 5.657515] Can't find a SQUASHFS superblock on loop53
[ 5.717417] Can't find a SQUASHFS superblock on loop53
[ 5.761522] Can't find a SQUASHFS superblock on loop53
[ 5.825451] Can't find a SQUASHFS superblock on loop56
[ 5.941382] Can't find a SQUASHFS superblock on loop59
[ 7.422000] mc: Linux media interface: v0.10
[ 7.493739] cfg80211: Loading compiled-in X.509 certificates for regulatory database
[ 7.501572] cfg80211: Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7'
[ 7.515686] brcmfmac: F1 signature read @0x18000000=0x15264345
[ 7.521029] brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43455-sdio for chip BCM4345/6
[ 7.521119] brcmfmac mmc1:0001:1: Direct firmware load for brcm/brcmfmac43455-sdio.raspberrypi,4-model-b.bin failed with error -2
[ 7.522018] usbcore: registered new interface driver brcmfmac
[ 7.761191] brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43455-sdio for chip BCM4345/6
[ 7.761273] brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43455-sdio for chip BCM4345/6
[ 7.765723] brcmfmac: brcmf_c_preinit_dcmds: Firmware: BCM4345/6 wl0: Nov 1 2021 00:37:25 version 7.45.241 (1a2f2fa CY) FWID 01-703fd60
[ 8.691456] usb 1-1.1: 1:3 : unsupported format bits 0x100000000
[ 9.097631] usbcore: registered new interface driver snd-usb-audio
[ 9.354782] bcmgenet fd580000.ethernet: configuring instance for external RGMII (RX delay)
[ 9.355047] bcmgenet fd580000.ethernet eth0: Link is Down
[ 9.423351] Starting piCorePlayer v8.2.0 startup.
[ 9.434497] cryptd: max_cpu_qlen set to 1000
[ 9.484169] random: crng init done
[ 9.830798] brcmfmac: brcmf_cfg80211_set_power_mgmt: power save enabled
[ 23.961434] Finished piCorePlayer v8.2.0 startup.
[ 31.708944] cam-dummy-reg: disabling

To which of your AirPlay device are you trying to play? AppleTV need pairing to work.

andyfw commented

Do you have any sound at all? AFAIK, all software clones requires encryption to be enabled

andyfw commented

The entire Linux Pi crashs like it reboots??? Or does become unresponsive or sloW?

andyfw commented

oh, let's be precise then. When you say

OK, so lets clarify. I have a RPi 4 with PiCore Player, LMS, and Shairplay all installed and it works perfectly, playing music, letting me stream with my iPad, etc, Tidal, etc …. UNTIL I enable the Airplay Bridge plugin on LMS. I go from a perfectly working box to one that crashes every 10-100 seconds just by checking the box! I don’t need to do anything else to make it repeatedly crash. Unchecking it restores perfect functionality.

This clearly meant that the whole thing crashes and I was really surprised. So no, the problem is that my plugin (more precisely the "binary helper") crashes when you try to play something through LMS on shairtunes. It does not crash unless you try to play. And remember that if LMS is trying to play on that device, after every crash, it will try again and crash again. So first thing first, you have to stop all these players from LMS. Then the binary helper will start and stay idle. Then, in the plugin settings, for all your shairtunes devices, enable encryption, then try to play from LMS on one shairtunes devices.

If you still see crashes, try the binary helper (in the plugin settings) that ends with "-static" as it might simply be a missing SSL library (common issue). If it still does not work, send me the log here.

I'm adding my fully edited response again as it seems you're using email to interact with GH so you might not see my edits

oh, let's be precise then. When you say

OK, so lets clarify. I have a RPi 4 with PiCore Player, LMS, and Shairplay all installed and it works perfectly, playing music, letting me stream with my iPad, etc, Tidal, etc …. UNTIL I enable the Airplay Bridge plugin on LMS. I go from a perfectly working box to one that crashes every 10-100 seconds just by checking the box! I don’t need to do anything else to make it repeatedly crash. Unchecking it restores perfect functionality.

This clearly meant that the whole thing crashes and I was really surprised. So no, the problem is that my plugin (more precisely the "binary helper") crashes when you try to play something through LMS on shairtunes. It does not crash unless you try to play. And remember that if LMS is trying to play on that device, after every crash, it will try again and crash again. So first thing first, you have to stop all these players from LMS. Then the binary helper will start and stay idle. Then, in the plugin settings, for all your shairtunes devices, enable encryption, then try to play from LMS on one shairtunes devices.

If you still see crashes, try the binary helper (in the plugin settings) that ends with "-static" as it might simply be a missing SSL library (common issue). If it still does not work, send me the log here.

andyfw commented
andyfw commented

I'm sorry but we really don't seem to understand each other. Of course there is an issue and I know the exact line where it crashes, but if you are a software developer, you'll appreciate that this is not enough to fix the problem.

To be precise, my application crashes when the player is returning a RTSP 500 (internal server error) code to a request and the crash happens because upon such error I'm logging a string that happens to be NULL. So I can fix that (I've already done it in fact) but that will not make the player play. The player still returns a 500.

But when you tell me "the same features worked before the plugin is enabled", that does not make any sense. The purpose of the plugin is to take AirPlay devices and make them appear as SqueezeBoxes. So "before" none of your AirPlay device could have appeared as a SB, because that's the very purpose of the plugin. What "worked before" and does not "work after" ? My plugin is not crashing anything else in your system. It crashes and restarts but that's all. Unless you can explicitly describe what other feature it impacts.

And no I'm not saying "it only crashed when you use it" that would be a silly statement. When you launch the plugin, it will do a lot of things like discover AirPlay devices, create fake Squeezeboxes and register them to LMS. Then it waits for further LMS commands for each newly created player. I'm pretty sure that this part works fine even in your case.

Now, what the log tells me is that LMS when requests the fake player to play, the crash happens. What I'm trying to tell you is that some players requires encryption to be activated for playback to work and I was wondering if it would be the case of yours. What I'm also trying to tell you is that even if you don't press PLAY in LMS yourself, LMS has memorized that the last state of that fake player was "playing" so as soon as it sees it reconnecting, it will automatically request it to play, whether you, as a human, asked it explicitly to play or not. And that loop of play/crash/restart/play/crash will happen forever until you (the human) stop the player in LMS.

andyfw commented