Thank you for your donation!


Problem: Moode Player 6.5.2 hanged after finishing a Playlist
#1
Hi.

I am using Moode Player 6.5.2 on a RPI 3B with an Hyper Pixel 4'' touchscreen. I am connecting it via Bluetooth to a Creative D200 speaker. I connect the MPD Audio output to bluetooth in the BlueZ menu. 

I choose an Album to be played and it sounds great until the end of it.

Then, the GUI is responsive, but I cannot access the Library or play anything else. It seems that MPD is dead.

Here is the moodutil -l output:

Code:
pi@moode:~ $ moodeutl -l
20200517 201144 worker: -- Start
20200517 201144 worker: Successfully daemonized
20200517 201144 worker: Integrity check (passed)
20200517 201144 worker: Session loaded
20200517 201144 worker: Debug logging (off)
20200517 201144 worker: Device raw: (0:ALSA|1:empty|i2s:none)
20200517 201144 worker: Device cfg: (On-board audio device|0|0|PCM|0)
20200517 201144 worker: ALSA volume set to (0%)
20200517 201145 worker: -- System
20200517 201146 worker: Host     (moode)
20200517 201147 worker: moOde    (6.5.2 2020-05-03)
20200517 201147 worker: Raspbian (10.3)
20200517 201147 worker: Kernel   (4.19.115-v7+ #1305)
20200517 201147 worker: Platform (Pi-3B 1GB v1.2)
20200517 201147 worker: ARM arch (armv7l, 32-bit kernel)
20200517 201147 worker: MPD ver  (0.21.22)
20200517 201147 worker: CPU gov  (ondemand)
20200517 201147 worker: USB boot not enabled yet
20200517 201147 worker: File system not expanded yet
20200517 201147 worker: HDMI port on
20200517 201148 worker: File check (OK)
20200517 201148 worker: -- Network
20200517 201148 worker: eth0 exists
20200517 201148 worker: IP addr (192.168.8.103)
20200517 201148 worker: Netmask (255.255.255.0)
20200517 201148 worker: Gateway (192.168.8.1)
20200517 201148 worker: Pri DNS (192.168.8.10)
20200517 201148 worker: Domain  (lan)
20200517 201148 worker: wlan0 does not exist
20200517 201148 worker: -- Audio
20200517 201149 worker: ALSA outputs unmuted
20200517 201149 worker: ALSA card number (0)
20200517 201149 worker: Audio output (On-board audio device)
20200517 201149 worker: Audio formats (U8, S16_LE)
20200517 201149 worker: ALSA mixer name (PCM)
20200517 201149 worker: MPD volume control (software)
20200517 201149 worker: Hdwr volume controller exists
20200517 201149 worker: Max ALSA volume (100%)
20200517 201149 worker: Reset renderer active flags
20200517 201149 worker: -- MPD
20200517 201150 worker: MPD conf updated
20200517 201150 worker: MPD started
20200517 201150 worker: MPD accepting connections
20200517 201150 worker: Configure MPD outputs
20200517 201150 worker: MPD output 1 ALSA default (off)
20200517 201150 worker: MPD output 2 ALSA crossfeed (off)
20200517 201150 worker: MPD output 3 ALSA parametric eq (off)
20200517 201150 worker: MPD output 4 ALSA graphic eq (off)
20200517 201150 worker: MPD output 5 ALSA polarity inversion (off)
20200517 201150 worker: MPD output 6 ALSA bluetooth (on)
20200517 201150 worker: MPD output 7 HTTP stream (off)
20200517 201150 worker: MPD crossfade (off)
20200517 201150 worker: -- Feature availability
20200517 201150 worker: Source select (available)
20200517 201150 worker: Source select (source: MPD)
20200517 201150 worker: Source select (output: On-board audio device)
20200517 201150 worker: Bluetooth (available)
20200517 201150 worker: Bluetooth (started)
20200517 201156 worker: Bluetooth pairing agent (started)
20200517 201156 worker: Airplay renderer (available)
20200517 201156 worker: Spotify renderer (available)
20200517 201156 worker: Squeezelite renderer (available)
20200517 201156 worker: UPnP renderer (available)
20200517 201156 worker: DLNA server (available)
20200517 201156 worker: UPnP browser (available)
20200517 201156 worker: Audio scrobbler (available)
20200517 201156 worker: GPIO button handler (available)
20200517 201156 worker: -- Music sources
20200517 201156 worker: USB sources (none attached)
20200517 201157 worker: NAS and UPnP sources (mountall initiated)
20200517 201157 worker: -- Miscellaneous
20200517 201157 worker: USB volume knob (Off)
20200517 201157 worker: Shellinabox SSH started
20200517 201157 worker: USB auto-mounter (udisks-glue)
20200517 201157 worker: LED0 (On)
20200517 201157 worker: LED1 (On)
20200517 201157 worker: Saved MPD vol level (0)
20200517 201157 worker: Preamp volume level (0)
20200517 201157 worker: MPD volume level (95) restored
20200517 201157 worker: ALSA volume level (100%)
20200517 201157 worker: Auto-play (Off)
20200517 201157 worker: LocalUI started
20200517 201157 worker: Maintenance interval (3 hrs)
20200517 201157 worker: Screen saver activation (Never)
20200517 201158 worker: Session permissions (OK)
20200517 201158 worker: Watchdog started
20200517 201158 worker: Ready
20200518 182559 worker: Job scnblank
20200518 183213 worker: Job scnbrightness
20200518 183235 worker: Job scnbrightness
20200518 183254 worker: Job scnbrightness
20200518 183318 worker: Job scnbrightness
20200518 183425 worker: Job scnblank
20200518 192728 command/index: Connection to MPD failed
20200518 192925 command/index: Connection to MPD failed
20200518 193031 command/index: Connection to MPD failed
20200518 193228 command/index: Connection to MPD failed
20200518 193259 moode.php: MPD connect failed: cmd=(loadlib)
20200518 193300 moode.php: MPD connect failed: cmd=(lsinfo)
20200518 193301 moode.php: MPD connect failed: cmd=(lsinfo)
20200518 193302 engine-mpd: Connection to MPD failed
20200518 193304 lib-config: Connection to MPD failed
20200518 193318 engine-mpd: Connection to MPD failed
20200518 193334 moode.php: MPD connect failed: cmd=(loadlib)
20200518 193334 moode.php: MPD connect failed: cmd=(lsinfo)
20200518 193334 moode.php: MPD connect failed: cmd=(lsinfo)
20200518 193335 engine-mpd: Connection to MPD failed
20200518 193337 command/index: Connection to MPD failed
20200518 193338 command/index: Connection to MPD failed
20200518 193531 moode.php: MPD connect failed: cmd=(updvolume)
20200518 193640 moode.php: MPD connect failed: cmd=(updvolume)
20200518 193826 command/index: Connection to MPD failed
20200518 193826 moode.php: MPD connect failed: cmd=(lsinfo)
20200518 193826 command/index: Connection to MPD failed
20200518 193827 moode.php: MPD connect failed: cmd=(loadlib)
20200518 193830 engine-mpd: Connection to MPD failed
20200518 193834 moode.php: MPD connect failed: cmd=(updvolume)
20200518 193944 moode.php: MPD connect failed: cmd=(updvolume)
20200518 194137 moode.php: MPD connect failed: cmd=(updvolume)
20200518 194247 moode.php: MPD connect failed: cmd=(updvolume)
20200518 194255 moode.php: MPD connect failed: cmd=(updvolume)
20200518 194441 moode.php: MPD connect failed: cmd=(updvolume)
20200518 194550 moode.php: MPD connect failed: cmd=(updvolume)
20200518 194559 moode.php: MPD connect failed: cmd=(updvolume)
20200518 194744 moode.php: MPD connect failed: cmd=(updvolume)
20200518 194853 moode.php: MPD connect failed: cmd=(updvolume)
20200518 194902 moode.php: MPD connect failed: cmd=(updvolume)
20200518 195047 moode.php: MPD connect failed: cmd=(updvolume)
20200518 195056 engine-mpd: Connection to MPD failed
20200518 195156 moode.php: MPD connect failed: cmd=(updvolume)
20200518 195205 moode.php: MPD connect failed: cmd=(updvolume)
20200518 195350 moode.php: MPD connect failed: cmd=(updvolume)
20200518 195459 moode.php: MPD connect failed: cmd=(updvolume)
20200518 195508 moode.php: MPD connect failed: cmd=(updvolume)
20200518 195653 moode.php: MPD connect failed: cmd=(updvolume)
20200518 195802 moode.php: MPD connect failed: cmd=(updvolume)
20200518 195811 moode.php: MPD connect failed: cmd=(updvolume)
20200518 195956 moode.php: MPD connect failed: cmd=(updvolume)
20200518 200106 moode.php: MPD connect failed: cmd=(updvolume)
20200518 200114 moode.php: MPD connect failed: cmd=(updvolume)
20200518 200117 command/index: Connection to MPD failed
20200518 200224 watchdog: PHP restarted (fpm child limit > 40)
20200518 200530 engine-mpd: Connection to MPD failed
20200518 200530 engine-mpd: Connection to MPD failed
20200518 200836 engine-mpd: Connection to MPD failed
20200518 200837 engine-mpd: Connection to MPD failed
20200518 201143 engine-mpd: Connection to MPD failed
20200518 201213 engine-mpd: Connection to MPD failed
20200518 201449 engine-mpd: Connection to MPD failed
20200518 201643 moode.php: MPD connect failed: cmd=(lsinfo)
20200518 201643 moode.php: MPD connect failed: cmd=(loadlib)
20200518 201643 moode.php: MPD connect failed: cmd=(lsinfo)
20200518 201644 engine-mpd: Connection to MPD failed

And here is the dmesg output:

Code:
pi@moode:~ $ dmesg
[    0.000000] Booting Linux on physical CPU 0x0
[    0.000000] Linux version 4.19.115-v7+ (dom@buildbot) (gcc version 4.9.3 (crosstool-NG crosstool-ng-1.22.0-88-g8460611)) #1305 SMP Fri Apr 17 11:53:39 BST 2020
[    0.000000] CPU: ARMv7 Processor [410fd034] revision 4 (ARMv7), cr=10c5383d
[    0.000000] CPU: div instructions available: patching division code
[    0.000000] CPU: PIPT / VIPT nonaliasing data cache, VIPT aliasing instruction cache
[    0.000000] OF: fdt: Machine model: Raspberry Pi 3 Model B Rev 1.2
[    0.000000] Memory policy: Data cache writealloc
[    0.000000] cma: Reserved 8 MiB at 0x3ac00000
[    0.000000] On node 0 totalpages: 242688
[    0.000000]   Normal zone: 2133 pages used for memmap
[    0.000000]   Normal zone: 0 pages reserved
[    0.000000]   Normal zone: 242688 pages, LIFO batch:63
[    0.000000] random: get_random_bytes called from start_kernel+0xac/0x4b4 with crng_init=0
[    0.000000] percpu: Embedded 16 pages/cpu s36864 r8192 d20480 u65536
[    0.000000] pcpu-alloc: s36864 r8192 d20480 u65536 alloc=16*4096
[    0.000000] pcpu-alloc: [0] 0 [0] 1 [0] 2 [0] 3
[    0.000000] Built 1 zonelists, mobility grouping on.  Total pages: 240555
[    0.000000] Kernel command line: coherent_pool=1M 8250.nr_uarts=0 bcm2708_fb.fbwidth=800 bcm2708_fb.fbheight=480 bcm2708_fb.fbswap=1 vc_mem.mem_base=0x3ec00000 vc_mem.mem_size=0x40000000  net.ifnames=0 console=ttyS0,115200 console=tty1 root=PARTUUID=738a4d67-02 rootfstype=ext4 elevator=deadline fsck.repair=yes rootwait
[    0.000000] Dentry cache hash table entries: 131072 (order: 7, 524288 bytes)
[    0.000000] Inode-cache hash table entries: 65536 (order: 6, 262144 bytes)
[    0.000000] Memory: 939064K/970752K available (8192K kernel code, 656K rwdata, 2232K rodata, 1024K init, 831K bss, 23496K reserved, 8192K cma-reserved)
[    0.000000] Virtual kernel memory layout:
                  vector  : 0xffff0000 - 0xffff1000   (   4 kB)
                  fixmap  : 0xffc00000 - 0xfff00000   (3072 kB)
                  vmalloc : 0xbb800000 - 0xff800000   (1088 MB)
                  lowmem  : 0x80000000 - 0xbb400000   ( 948 MB)
                  modules : 0x7f000000 - 0x80000000   (  16 MB)
                    .text : 0x(ptrval) - 0x(ptrval)   (9184 kB)
                    .init : 0x(ptrval) - 0x(ptrval)   (1024 kB)
                    .data : 0x(ptrval) - 0x(ptrval)   ( 657 kB)
                     .bss : 0x(ptrval) - 0x(ptrval)   ( 832 kB)
[    0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1
[    0.000000] ftrace: allocating 27089 entries in 80 pages
[    0.000000] rcu: Hierarchical RCU implementation.
[    0.000000] NR_IRQS: 16, nr_irqs: 16, preallocated irqs: 16
[    0.000000] arch_timer: cp15 timer(s) running at 19.20MHz (phys).
[    0.000000] clocksource: arch_sys_counter: mask: 0xffffffffffffff max_cycles: 0x46d987e47, max_idle_ns: 440795202767 ns
[    0.000007] sched_clock: 56 bits at 19MHz, resolution 52ns, wraps every 4398046511078ns
[    0.000023] Switching to timer-based delay loop, resolution 52ns
[    0.000281] Console: colour dummy device 80x30
[    0.000899] console [tty1] enabled
[    0.000956] Calibrating delay loop (skipped), value calculated using timer frequency.. 38.40 BogoMIPS (lpj=192000)
[    0.000999] pid_max: default: 32768 minimum: 301
[    0.001372] Mount-cache hash table entries: 2048 (order: 1, 8192 bytes)
[    0.001409] Mountpoint-cache hash table entries: 2048 (order: 1, 8192 bytes)
[    0.002376] CPU: Testing write buffer coherency: ok
[    0.002876] CPU0: thread -1, cpu 0, socket 0, mpidr 80000000
[    0.003560] Setting up static identity map for 0x100000 - 0x10003c
[    0.003730] rcu: Hierarchical SRCU implementation.
[    0.004565] smp: Bringing up secondary CPUs ...
[    0.005500] CPU1: thread -1, cpu 1, socket 0, mpidr 80000001
[    0.006488] CPU2: thread -1, cpu 2, socket 0, mpidr 80000002
[    0.007416] CPU3: thread -1, cpu 3, socket 0, mpidr 80000003
[    0.007531] smp: Brought up 1 node, 4 CPUs
[    0.007614] SMP: Total of 4 processors activated (153.60 BogoMIPS).
[    0.007638] CPU: All CPU(s) started in HYP mode.
[    0.007658] CPU: Virtualization extensions available.
[    0.008670] devtmpfs: initialized
[    0.022031] VFP support v0.3: implementor 41 architecture 3 part 40 variant 3 rev 4
[    0.022310] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns
[    0.022360] futex hash table entries: 1024 (order: 4, 65536 bytes)
[    0.022975] pinctrl core: initialized pinctrl subsystem
[    0.023853] NET: Registered protocol family 16
[    0.026931] DMA: preallocated 1024 KiB pool for atomic coherent allocations
[    0.032711] hw-breakpoint: found 5 (+1 reserved) breakpoint and 4 watchpoint registers.
[    0.032746] hw-breakpoint: maximum watchpoint size is 8 bytes.
[    0.032972] Serial: AMBA PL011 UART driver
[    0.035539] bcm2835-mbox 3f00b880.mailbox: mailbox enabled
[    0.050035] raspberrypi-firmware soc:firmware: Attached to firmware from 2020-04-16 12:33, variant start
[    0.060048] raspberrypi-firmware soc:firmware: Firmware hash is 30355345c483638d3f8b013f58f0ee17094e7de2
[    0.103279] bcm2835-dma 3f007000.dma: DMA legacy API manager at (ptrval), dmachans=0x1
[    0.104963] SCSI subsystem initialized
[    0.105203] usbcore: registered new interface driver usbfs
[    0.105278] usbcore: registered new interface driver hub
[    0.105398] usbcore: registered new device driver usb
[    0.106977] clocksource: Switched to clocksource arch_sys_counter
[    0.196710] VFS: Disk quotas dquot_6.6.0
[    0.196827] VFS: Dquot-cache hash table entries: 1024 (order 0, 4096 bytes)
[    0.197034] FS-Cache: Loaded
[    0.197275] CacheFiles: Loaded
[    0.207313] NET: Registered protocol family 2
[    0.208196] tcp_listen_portaddr_hash hash table entries: 512 (order: 0, 6144 bytes)
[    0.208262] TCP established hash table entries: 8192 (order: 3, 32768 bytes)
[    0.208393] TCP bind hash table entries: 8192 (order: 4, 65536 bytes)
[    0.208597] TCP: Hash tables configured (established 8192 bind 8192)
[    0.208757] UDP hash table entries: 512 (order: 2, 16384 bytes)
[    0.208828] UDP-Lite hash table entries: 512 (order: 2, 16384 bytes)
[    0.209091] NET: Registered protocol family 1
[    0.209693] RPC: Registered named UNIX socket transport module.
[    0.209720] RPC: Registered udp transport module.
[    0.209742] RPC: Registered tcp transport module.
[    0.209764] RPC: Registered tcp NFSv4.1 backchannel transport module.
[    0.211504] hw perfevents: enabled with armv7_cortex_a7 PMU driver, 7 counters available
[    0.214606] Initialise system trusted keyrings
[    0.214813] workingset: timestamp_bits=14 max_order=18 bucket_order=4
[    0.224773] FS-Cache: Netfs 'nfs' registered for caching
[    0.225359] NFS: Registering the id_resolver key type
[    0.225405] Key type id_resolver registered
[    0.225428] Key type id_legacy registered
[    0.225459] nfs4filelayout_init: NFSv4 File Layout Driver Registering...
[    0.230952] Key type asymmetric registered
[    0.230989] Asymmetric key parser 'x509' registered
[    0.231067] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 250)
[    0.231267] io scheduler noop registered
[    0.231292] io scheduler deadline registered (default)
[    0.231518] io scheduler cfq registered
[    0.231542] io scheduler mq-deadline registered (default)
[    0.231566] io scheduler kyber registered
[    0.235142] bcm2708_fb soc:fb: FB found 1 display(s)
[    0.254866] Console: switching to colour frame buffer device 100x30
[    0.266169] bcm2708_fb soc:fb: Registered framebuffer for display 0, size 800x480
[    0.271216] bcm2835-rng 3f104000.rng: hwrng registered
[    0.274347] vc-mem: phys_addr:0x00000000 mem_base=0x3ec00000 mem_size:0x40000000(1024 MiB)
[    0.277932] vc-sm: Videocore shared memory driver
[    0.281304] gpiomem-bcm2835 3f200000.gpiomem: Initialised: Registers at 0x3f200000
[    0.295112] brd: module loaded
[    0.308470] loop: module loaded
[    0.312067] Loading iSCSI transport class v2.0-870.
[    0.315775] libphy: Fixed MDIO Bus: probed
[    0.318827] usbcore: registered new interface driver lan78xx
[    0.321837] usbcore: registered new interface driver smsc95xx
[    0.324737] dwc_otg: version 3.00a 10-AUG-2012 (platform bus)
[    0.855576] dwc_otg 3f980000.usb: base=(ptrval)
[    1.058757] Core Release: 2.80a
[    1.061589] Setting default values for core params
[    1.064493] Finished setting default values for core params
[    1.267668] Using Buffer DMA mode
[    1.270411] Periodic Transfer Interrupt Enhancement - disabled
[    1.273245] Multiprocessor Interrupt Enhancement - disabled
[    1.276118] OTG VER PARAM: 0, OTG VER FLAG: 0
[    1.279042] Dedicated Tx FIFOs mode
[    1.282344] WARN::dwc_otg_hcd_init:1074: FIQ DMA bounce buffers: virt = bad04000 dma = 0xfad04000 len=9024
[    1.288505] FIQ FSM acceleration enabled for :
              Non-periodic Split Transactions
              Periodic Split Transactions
              High-Speed Isochronous Endpoints
              Interrupt/Control Split Transaction hack enabled
[    1.303110] dwc_otg: Microframe scheduler enabled
[    1.303163] WARN::hcd_init_fiq:457: FIQ on core 1
[    1.305910] WARN::hcd_init_fiq:458: FIQ ASM at 8068fdd8 length 36
[    1.308590] WARN::hcd_init_fiq:497: MPHI regs_base at bb810000
[    1.311316] dwc_otg 3f980000.usb: DWC OTG Controller
[    1.314087] dwc_otg 3f980000.usb: new USB bus registered, assigned bus number 1
[    1.316884] dwc_otg 3f980000.usb: irq 56, io mem 0x00000000
[    1.319659] Init: Port Power? op_state=1
[    1.322404] Init: Power Port (0)
[    1.325328] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 4.19
[    1.328234] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[    1.331128] usb usb1: Product: DWC OTG Controller
[    1.333981] usb usb1: Manufacturer: Linux 4.19.115-v7+ dwc_otg_hcd
[    1.336863] usb usb1: SerialNumber: 3f980000.usb
[    1.340329] hub 1-0:1.0: USB hub found
[    1.343154] hub 1-0:1.0: 1 port detected
[    1.346502] dwc_otg: FIQ enabled
[    1.346508] dwc_otg: NAK holdoff enabled
[    1.346514] dwc_otg: FIQ split-transaction FSM enabled
[    1.346526] Module dwc_common_port init
[    1.346826] usbcore: registered new interface driver usb-storage
[    1.349825] mousedev: PS/2 mouse device common for all mice
[    1.353499] bcm2835-wdt bcm2835-wdt: Broadcom BCM2835 watchdog timer
[    1.356502] bcm2835-cpufreq: min=600000 max=1200000
[    1.359638] sdhci: Secure Digital Host Controller Interface driver
[    1.362347] sdhci: Copyright(c) Pierre Ossman
[    1.365470] sdhost-bcm2835 3f202000.mmc: could not get clk, deferring probe
[    1.368467] sdhci-pltfm: SDHCI platform and OF driver helper
[    1.372825] ledtrig-cpu: registered to indicate activity on CPUs
[    1.375896] hidraw: raw HID events driver (C) Jiri Kosina
[    1.379013] usbcore: registered new interface driver usbhid
[    1.381926] usbhid: USB HID core driver
[    1.385583] vchiq: vchiq_init_state: slot_zero = (ptrval), is_master = 0
[    1.390116] [vc_sm_connected_init]: start
[    1.399083] [vc_sm_connected_init]: end - returning 0
[    1.403120] Initializing XFRM netlink socket
[    1.406033] NET: Registered protocol family 17
[    1.409093] Key type dns_resolver registered
[    1.412427] Registering SWP/SWPB emulation handler
[    1.415850] registered taskstats version 1
[    1.418632] Loading compiled-in X.509 certificates
[    1.428134] uart-pl011 3f201000.serial: cts_event_workaround enabled
[    1.431094] 3f201000.serial: ttyAMA0 at MMIO 0x3f201000 (irq = 81, base_baud = 0) is a PL011 rev2
[    1.436095] sdhost: log_buf @ (ptrval) (fad07000)
[    1.487801] mmc0: sdhost-bcm2835 loaded - DMA enabled (>1)
[    1.492120] of_cfs_init
[    1.495236] of_cfs_init: OK
[    1.498700] Waiting for root device PARTUUID=738a4d67-02...
[    1.567216] Indeed it is in host mode hprt0 = 00021501
[    1.639478] mmc0: host does not support reading read-only switch, assuming write-enable
[    1.648556] mmc0: new high speed SDHC card at address e624
[    1.652686] mmcblk0: mmc0:e624 SU08G 7.40 GiB
[    1.659638] random: fast init done
[    1.662877]  mmcblk0: p1 p2
[    1.689157] EXT4-fs (mmcblk0p2): mounted filesystem with ordered data mode. Opts: (null)
[    1.692198] VFS: Mounted root (ext4 filesystem) readonly on device 179:2.
[    1.703819] devtmpfs: mounted
[    1.714072] Freeing unused kernel memory: 1024K
[    1.757390] Run /sbin/init as init process
[    1.777023] usb 1-1: new high-speed USB device number 2 using dwc_otg
[    1.780251] Indeed it is in host mode hprt0 = 00001101
[    2.017355] usb 1-1: New USB device found, idVendor=0424, idProduct=9514, bcdDevice= 2.00
[    2.020634] usb 1-1: New USB device strings: Mfr=0, Product=0, SerialNumber=0
[    2.024509] hub 1-1:1.0: USB hub found
[    2.027853] hub 1-1:1.0: 5 ports detected
[    2.347025] usb 1-1.1: new high-speed USB device number 3 using dwc_otg
[    2.476688] systemd[1]: System time before build time, advancing clock.
[    2.477342] usb 1-1.1: New USB device found, idVendor=0424, idProduct=ec00, bcdDevice= 2.00
[    2.483099] usb 1-1.1: New USB device strings: Mfr=0, Product=0, SerialNumber=0
[    2.485788] smsc95xx v1.0.6
[    2.580609] smsc95xx 1-1.1:1.0 eth0: register 'smsc95xx' at usb-3f980000.usb-1.1, smsc95xx USB 2.0 Ethernet, b8:27:eb:b7:b0:91
[    2.667515] NET: Registered protocol family 10
[    2.672347] Segment Routing with IPv6
[    2.726642] systemd[1]: systemd 241 running in system mode. (+PAM +AUDIT +SELINUX +IMA +APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD -IDN2 +IDN -PCRE2 default-hierarchy=hybrid)
[    2.738174] systemd[1]: Detected architecture arm.
[    2.762886] systemd[1]: Set hostname to <moode>.
[    2.769441] systemd[1]: Failed to bump fs.file-max, ignoring: Invalid argument
[    3.497286] random: systemd: uninitialized urandom read (16 bytes read)
[    3.540397] systemd[1]: /lib/systemd/system/winbind.service:8: PIDFile= references path below legacy directory /var/run/, updating /var/run/samba/winbindd.pid → /run/samba/winbindd.pid; please update the unit file accordingly.
[    3.632505] systemd[1]: /lib/systemd/system/smbd.service:9: PIDFile= references path below legacy directory /var/run/, updating /var/run/samba/smbd.pid → /run/samba/smbd.pid; please update the unit file accordingly.
[    3.683665] systemd[1]: /lib/systemd/system/nmbd.service:9: PIDFile= references path below legacy directory /var/run/, updating /var/run/samba/nmbd.pid → /run/samba/nmbd.pid; please update the unit file accordingly.
[    3.749016] random: systemd: uninitialized urandom read (16 bytes read)
[    3.758857] systemd[1]: Created slice system-getty.slice.
[    3.768077] random: systemd: uninitialized urandom read (16 bytes read)
[    3.772994] systemd[1]: Listening on Journal Socket.
[    3.787487] systemd[1]: Mounting POSIX Message Queue File System...
[    4.645399] EXT4-fs (mmcblk0p2): re-mounted. Opts: (null)
[    4.761113] systemd-journald[128]: Received request to flush runtime journal from PID 1
[    5.418871] gpio-10 (i2c@0): enforced open drain please flag it properly in DT/ACPI DSDT/board file
[    5.418946] gpio-11 (i2c@0): enforced open drain please flag it properly in DT/ACPI DSDT/board file
[    5.419408] i2c-gpio i2c@0: using lines 10 (SDA) and 11 (SCL)
[    5.499167] vc_sm_cma: module is from the staging directory, the quality is unknown, you have been warned.
[    5.504425] bcm2835_vc_sm_cma_probe: Videocore shared memory driver
[    5.504442] [vc_sm_connected_init]: start
[    5.510276] media: Linux media interface: v0.10
[    5.513846] [vc_sm_connected_init]: installed successfully
[    5.551326] videodev: Linux video capture interface: v2.00
[    5.570798] pinctrl-bcm2835 3f200000.gpio: pin gpio2 already requested by soc:fb; cannot claim for 3f804000.i2c
[    5.570816] pinctrl-bcm2835 3f200000.gpio: pin-2 (3f804000.i2c) status -22
[    5.570830] pinctrl-bcm2835 3f200000.gpio: could not request pin 2 (gpio2) from group gpio2  on device pinctrl-bcm2835
[    5.570839] i2c-bcm2835 3f804000.i2c: Error applying setting, reverse things back
[    5.570870] i2c-bcm2835: probe of 3f804000.i2c failed with error -22
[    5.631104] bcm2835_mmal_vchiq: module is from the staging directory, the quality is unknown, you have been warned.
[    5.637154] bcm2835_mmal_vchiq: module is from the staging directory, the quality is unknown, you have been warned.
[    5.646781] bcm2835_v4l2: module is from the staging directory, the quality is unknown, you have been warned.
[    5.655835] snd_bcm2835: module is from the staging directory, the quality is unknown, you have been warned.
[    5.670602] bcm2835_audio soc:audio: card created with 8 channels
[    5.694746] bcm2835_codec: module is from the staging directory, the quality is unknown, you have been warned.
[    5.708200] bcm2835-codec bcm2835-codec: Device registered as /dev/video10
[    5.708248] bcm2835-codec bcm2835-codec: Loaded V4L2 decode
[    5.716267] bcm2835-codec bcm2835-codec: Device registered as /dev/video11
[    5.716318] bcm2835-codec bcm2835-codec: Loaded V4L2 encode
[    5.723582] bcm2835-codec bcm2835-codec: Device registered as /dev/video12
[    5.723621] bcm2835-codec bcm2835-codec: Loaded V4L2 isp
[    5.729413] pinctrl-bcm2835 3f200000.gpio: pin gpio20 already requested by soc:fb; cannot claim for 3f203000.i2s
[    5.729431] pinctrl-bcm2835 3f200000.gpio: pin-20 (3f203000.i2s) status -22
[    5.729443] pinctrl-bcm2835 3f200000.gpio: could not request pin 20 (gpio20) from group gpio20  on device pinctrl-bcm2835
[    5.729453] bcm2835-i2s 3f203000.i2s: Error applying setting, reverse things back
[    5.729486] bcm2835-i2s: probe of 3f203000.i2s failed with error -22
[    6.428364] Goodix-TS 3-005d: ID 911, version: 1060
[    6.450072] input: Goodix Capacitive TouchScreen as /devices/platform/i2c@0/i2c-3/3-005d/input/input0
[    6.453172] irq: type mismatch, failed to map hwirq-27 for gpio@7e200000!
[    6.454649] Goodix-TS 3-0014: i2c test failed attempt 1: -6
[    6.487947] Goodix-TS 3-0014: i2c test failed attempt 2: -6
[    6.537040] Goodix-TS 3-0014: I2C communication failure: -6
[    8.822342] random: crng init done
[    8.822369] random: 7 urandom warning(s) missed due to ratelimiting
[    8.904948] 8021q: 802.1Q VLAN Support v1.8
[    9.115584] cfg80211: Loading compiled-in X.509 certificates for regulatory database
[    9.172260] cfg80211: Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7'
[    9.418967] smsc95xx 1-1.1:1.0 eth0: hardware isn't capable of remote wakeup
[   11.029886] smsc95xx 1-1.1:1.0 eth0: link up, 100Mbps, full-duplex, lpa 0xC1E1
[   26.136716] uart-pl011 3f201000.serial: no DMA platform data
[   30.816749] Bluetooth: Core ver 2.22
[   30.816878] NET: Registered protocol family 31
[   30.816885] Bluetooth: HCI device and connection manager initialized
[   30.818970] Bluetooth: HCI socket layer initialized
[   30.818999] Bluetooth: L2CAP socket layer initialized
[   30.819077] Bluetooth: SCO socket layer initialized
[   30.860218] Bluetooth: HCI UART driver ver 2.3
[   30.860232] Bluetooth: HCI UART protocol H4 registered
[   30.860352] Bluetooth: HCI UART protocol Three-wire (H5) registered
[   30.860594] Bluetooth: HCI UART protocol Broadcom registered
[   31.093389] Bluetooth: BNEP (Ethernet Emulation) ver 1.3
[   31.093401] Bluetooth: BNEP filters: protocol multicast
[   31.093421] Bluetooth: BNEP socket layer initialized
[   31.921210] FS-Cache: Netfs 'cifs' registered for caching
[   31.924403] Key type cifs.spnego registered
[   31.924415] Key type cifs.idmap registered
[   89.128188] input: 00:02:3C:29:BD:27 as /devices/virtual/input/input1

What could be happening?

I really love this 6.5.2 version. It's smooth, easy enough for my tiny 4'' screen and I can play via bluetooth to an external speaker.

Thanks!
Reply
#2
What 3rd party code is running to render on the 4" display?

The error below is rare and I've only encountered it during heavy testing where I refresh the Browser many, many times or repeatedly switch between Playback and the configs which is the equivalent of a Browser refresh. Each refresh starts a new PHP pool worker. They are broom'd out by PHP housekeeping over a period of time but rapid and many Browser refreshes can cause more than the limit of 40 to accumulate.

20200518 200224 watchdog: PHP restarted (fpm child limit > 40)
Reply
#3
(05-18-2020, 06:30 PM)Tim Curtis Wrote: What 3rd party code is running to render on the 4" display?

The error below is rare and I've only encountered it during heavy testing where I refresh the Browser many, many times or repeatedly switch between Playback and the configs which is the equivalent of a Browser refresh. Each refresh starts a new PHP pool worker. They are broom'd out by PHP housekeeping over a period of time but rapid and many Browser refreshes can cause more than the limit of 40 to accumulate.

20200518 200224 watchdog: PHP restarted (fpm child limit > 40)

Hi,

Thanks for answering.

The driver code is here.

https://github.com/pimoroni/hyperpixel4/...i4-i2c-fix

But, the PHP error you say is quite below the first MPD connection failed:

Code:
20200518 192728 command/index: Connection to MPD failed
20200518 192925 command/index: Connection to MPD failed
20200518 193031 command/index: Connection to MPD failed
20200518 193228 command/index: Connection to MPD failed
20200518 193259 moode.php: MPD connect failed: cmd=(loadlib)
20200518 193300 moode.php: MPD connect failed: cmd=(lsinfo)
20200518 193301 moode.php: MPD connect failed: cmd=(lsinfo)

Thanks for your help!
Reply
#4
Not the drivers but 3rd party script that renders Moode UI elements on the display.
Reply
#5
Actually I'm able to repro this: "MPD 0.21.22 hangs at end of song file playlist while playing to BT speaker"

It appears to be an MPD / BlueZ ALSA issue.
Reply
#6
After some testing this morning I can confirm that for the use case MPD -> BT Speaker when last song in Playlist ends MPD never generates an idle timeout event. It remains in its idle loop and refuses to process any protocol commands. This could be due to either an MPD bug or a bluez-alsa bug. I have no way of knowing.

The only way out is to kill the MPD process and then let watchdog.sh automatically restart it.

Code:
sudo killall -s 9 mpd

Alternatively you could add a radio station to the end of the Playlist.

-Tim
Reply
#7
(05-19-2020, 01:12 PM)Tim Curtis Wrote: After some testing this morning I can confirm that for the use case MPD -> BT Speaker when last song in Playlist ends MPD never generates an idle timeout event. It remains in its idle loop and refuses to process any protocol commands. This could be due to either an MPD bug or a bluez-alsa bug. I have no way of knowing.

The only way out is to kill the MPD process and then let watchdog.sh automatically restart it.

Code:
sudo killall -s 9 mpd

Alternatively you could add a radio station to the end of the Playlist.

-Tim

Thanks for debugging it Smile 

I'll try to add a radio station as an alternative. It is for the kids to use. It must be easy Wink

Will it be solved? Maybe, a bug report should be submitted to MPD?

Thanks!
Reply
#8
Yes, I think it could be solved but it's beyond my expertise to do so. We will need a developer to volunteer their time to create a generic repro using stock Raspbian Buster Lite, MPD and bluez-alsa. They can then determine whether the bug report should be submitted to the MPD maintainer or blues-alsa maintainer.

-Tim
Reply
#9
@dml3334
@Tim Curtis

I did some sleuthing last night.

Using the bisection technique, but on release tags rather than on individual git commits, I found that mpd-v0.21.10 is the latest version to behave properly with bluez-alsa. (Or at least it's the latest version which allows me to output to a Bluetooth speaker and recover at the end of a tracklist.)

@dml3334: I can post this binary and some instructions on dropbox or somesuch for you if you want to do a trivial bit of file substitution. You'll end up with a moOde which tells a lie in the configuration menu about the choices to switch between, but that's a small price if you really really want to output to a Bluetooth speaker. With some hackery to the moOdeUI code, you could even make moOde tell the truth.

@Tim Curtis: Assuming we can't get closure on the MPD/bluez-alsa/alsa issue, would you consider modifying the configuration scheme once again to allow a down-selection of mpd version for those who want Bluetooth output? 

Regards,
Kent

PS - now that I know the offending git commit lies between the release of v0.21.10 and v0.21.11, I can do a proper bisection. As we discussed, this may not get us anywhere with the three-way standoff of MPD, bluez-alsa, and ALSA maintainers, but inquiring minds want to know  Rolleyes
Reply
#10
Nice work :-)

The .10 release while it addresses the OP issue is 13 releases behind the current MPD .23 release and if it turns out to be bug in blues-alsa instead of MPD then all we are doing is prolonging the breakage. IMO including .10 would be a bad idea.

Maybe that batting average can get a + if you submit the issue with a bisect :-) This time it's a separate issue from the original one where MPD wouldn't even connect to BT speaker. This one is specific to what happens when playlist ends.

- no idle timeout happens
- protocol commands are not processed
- mpd must be killall -s 9 then restarted to remedy the situation

I also recall trying MPD 0.22-git and it wouldn't even connect to BT speaker. If it turns out to be an MPD issue after all and gets fixed for 0.21.y then the fix should propagate to the 0.22 code base.

-Tim
Reply


Forum Jump: