Thank you for your donation!


Cloudsmith graciously provides open-source package management and distribution for our project.


Problem: MPD and CamillaDSP errors
#1
There seems to be an issue with the way that CamillaDSP works on Moode. I haven't tested this outside of Moode so no idea if the issue rests purely in CamillaDSP or if its related to the way that Moode handles MPD and CamillaDSP.

The hardware is:
RP4 with USB DAC/audio interface, 4 channel output Motu M4.

CamillaDSP is setup to have:
2 channel input to 4 channel output mixer and a couple of filters. The pipeline is 2 input channels to 3 output channels with a filter on each of the 3 channels. Samplerate is 96000, chunksize is 2048 as per CamillaDSP github for samplerate of 96000.

Issue is reproduced by playing a track for about 10-15sec and then going to another track. Instead of playing the next track an error pops up. The error is 'MPD error Failed to open audio output". Pressing play straight after the error results in playback resuming.

Playing a track for less than 10sec, or longer than about 20sec does not result in the MPD error. But, there is a CamillaDSP error when playing a track for less than 10sec.

CamillaDSP logs:

Code:
2023-01-15 02:32:52.280360 INFO [src/bin.rs:420] Capture finished
2023-01-15 02:32:52.344207 INFO [src/bin.rs:410] Playback finished
2023-01-15 02:32:52.522939 INFO [src/bin.rs:711] CamillaDSP version 1.0.3
2023-01-15 02:32:52.523046 INFO [src/bin.rs:712] Running on linux, aarch64
2023-01-15 02:32:52.555524 INFO [src/alsadevice.rs:161] Starting playback from Prepared state
2023-01-15 02:33:02.760712 WARN [src/alsadevice.rs:157] Prepare playback after buffer underrun
2023-01-15 02:33:02.867833 WARN [src/alsadevice.rs:192] Wait timed out, playback device takes too long to drain buffer
2023-01-15 02:33:02.867957 WARN [src/alsadevice.rs:213] Retrying playback, error: ALSA function 'snd_pcm_writei' failed with error 'EAGAIN: Try again'
2023-01-15 02:33:02.889353 ERROR [src/bin.rs:344] Playback error: ALSA function 'snd_pcm_writei' failed with error 'EAGAIN: Try again'
2023-01-15 02:33:02.973876 WARN [src/alsadevice.rs:192] Wait timed out, playback device takes too long to drain buffer
2023-01-15 02:33:02.974003 WARN [src/alsadevice.rs:213] Retrying playback, error: ALSA function 'snd_pcm_writei' failed with error 'EAGAIN: Try again'
Jan 15 13:33 : output: Failed to play on "ALSA Default" (alsa): snd_pcm_poll_descriptors_revents() failed: No such device
Jan 15 13:33 : exception: Failed to open audio output
2023-01-15 02:33:15.488663 INFO [src/bin.rs:711] CamillaDSP version 1.0.3
2023-01-15 02:33:15.488845 INFO [src/bin.rs:712] Running on linux, aarch64
2023-01-15 02:33:15.517145 INFO [src/alsadevice.rs:161] Starting playback from Prepared state


Play a track for less than 10sec then go to next track:
Code:
2023-01-15 02:34:35.307898 WARN [src/alsadevice.rs:157] Prepare playback after buffer underrun

Play a track for 15 seconds and then go to next track:
Code:
2023-01-15 02:36:33.436529 WARN [src/alsadevice.rs:192] Wait timed out, playback device takes too long to drain buffer
2023-01-15 02:36:33.436684 WARN [src/alsadevice.rs:213] Retrying playback, error: ALSA function 'snd_pcm_writei' failed with error 'EAGAIN: Try again'
2023-01-15 02:36:33.461511 ERROR [src/bin.rs:344] Playback error: ALSA function 'snd_pcm_writei' failed with error 'EAGAIN: Try again'
2023-01-15 02:36:33.546379 WARN [src/alsadevice.rs:192] Wait timed out, playback device takes too long to drain buffer
2023-01-15 02:36:33.546543 WARN [src/alsadevice.rs:213] Retrying playback, error: ALSA function 'snd_pcm_writei' failed with error 'EAGAIN: Try again'
Jan 15 13:36 : output: Failed to play on "ALSA Default" (alsa): snd_pcm_poll_descriptors_revents() failed: No such device
Jan 15 13:36 : exception: Failed to open audio output
2023-01-15 02:36:35.821694 INFO [src/bin.rs:711] CamillaDSP version 1.0.3
2023-01-15 02:36:35.821805 INFO [src/bin.rs:712] Running on linux, aarch64
2023-01-15 02:36:35.830732 INFO [src/alsadevice.rs:161] Starting playback from Prepared state



Is the issue related to the way that Moode handles MPD or CamillaDSP when starting a new track?
Reply
#2
I know very little about DSP or Camilla but from your post the 'buffer under-runs' seem to be a feature.
Have you increased the buffer in the audio set-up ? mpd-settings.

Someone more conversant than I will be along soon I expect :-)
----------
bob
Reply
#3
(01-15-2023, 04:35 AM)DRONE7 Wrote: I know very little about DSP or Camilla but from your post the 'buffer under-runs' seem to be a feature.
Have you increased the buffer in the audio set-up ? mpd-settings.

Someone more conversant than I will be along soon I expect :-)

I did increase it to 16MB. Decreasing it back to 4MB doesn't fix the problem. It changes how long I can play the track before skipping for the error to occur. Here is a CamillaDSP log example with 4MB MPD buffer and going from track to track.


Code:
2023-01-15 05:00:09.538654 WARN [src/alsadevice.rs:157] Prepare playback after buffer underrun
2023-01-15 05:01:15.571565 WARN [src/alsadevice.rs:157] Prepare playback after buffer underrun
2023-01-15 05:01:15.678317 WARN [src/alsadevice.rs:192] Wait timed out, playback device takes too long to drain buffer
2023-01-15 05:01:15.678431 WARN [src/alsadevice.rs:213] Retrying playback, error: ALSA function 'snd_pcm_writei' failed with error 'EAGAIN: Try again'
2023-01-15 05:01:15.700147 ERROR [src/bin.rs:344] Playback error: ALSA function 'snd_pcm_writei' failed with error 'EAGAIN: Try again'
2023-01-15 05:01:15.784286 WARN [src/alsadevice.rs:192] Wait timed out, playback device takes too long to drain buffer
2023-01-15 05:01:15.784408 WARN [src/alsadevice.rs:213] Retrying playback, error: ALSA function 'snd_pcm_writei' failed with error 'EAGAIN: Try again'
Jan 15 16:01 : output: Failed to play on "ALSA Default" (alsa): snd_pcm_poll_descriptors_revents() failed: No such device
Jan 15 16:01 : exception: Failed to open audio output
2023-01-15 05:01:30.609982 INFO [src/bin.rs:711] CamillaDSP version 1.0.3
2023-01-15 05:01:30.610103 INFO [src/bin.rs:712] Running on linux, aarch64
2023-01-15 05:01:30.630748 INFO [src/alsadevice.rs:161] Starting playback from Prepared state


The question, really, is why are buffer underruns occurring AND resulting in MPD error in Moode. When I was playing with CamillaDSP settings I noticed that at least one of them does not apply on Moode when I select Apply to DSP. It seems to apply but then if I choose Fetch from DSP then the wrong value is returned. So Moode's interface/implementation to CamillaDSP is not generic.
Reply
#4
Reboot and post the startup log.

Code:
moodeutl -l
Enjoy the Music!
moodeaudio.org | Mastodon Feed | GitHub
Reply
#5
(01-15-2023, 12:04 PM)Tim Curtis Wrote: Reboot and post the startup log.

Code:
moodeutl -l

*Not sure why SMB does not auto mount on start up but manually mounting it via GUI is fine. It auto mounts after a while. Maybe because I am using a USB hub with ethernet adapter? But that is not the main issue.
Code:
20230115 175347 worker: --
20230115 175347 worker: -- Start moOde 8 series
20230115 175347 worker: --
20230115 175347 worker: Successfully daemonized
20230115 175349 worker: File check (OK)
20230115 175350 worker: Session vacuumed
20230115 175350 worker: Session loaded
20230115 175350 worker: Debug logging (OFF)
20230115 175350 worker: --
20230115 175350 worker: -- Audio debug
20230115 175350 worker: --
20230115 175350 worker: ALSA cards: (0:Loopback | 1:b1 | 2:Headphones | 3:M4
20230115 175350 worker: MPD config: (3:M4 | mixer:(PCM) | card:3)
20230115 175350 worker: ALSA mixer actual (PCM)
20230115 175350 worker: ALSA PCM volume set to (amixer: Unable to find simple control 'PCM',0)
20230115 175350 worker: --
20230115 175350 worker: -- System
20230115 175350 worker: --
20230115 175351 worker: Host      (mooderp4)
20230115 175351 worker: moOde     (8.2.4 2022-12-27)
20230115 175351 worker: RaspiOS   (11.6)
20230115 175351 worker: Kernel    (5.15.76-v8+ #1597)
20230115 175351 worker: Platform  (Pi-4B 1.2 4GB)
20230115 175351 worker: ARM arch  (aarch64, 64-bit)
20230115 175351 worker: MPD ver   (0.23.11)
20230115 175351 worker: CPU gov   (ondemand)
20230115 175351 worker: USB boot  (enabled)
20230115 175351 worker: File sys  (expanded)
20230115 175351 worker: HDMI port (On)
20230115 175352 worker: Sys LED0  (On)
20230115 175352 worker: Sys LED1  (On)
20230115 175352 worker: --
20230115 175352 worker: -- Network
20230115 175352 worker: --
20230115 175352 worker: eth0 adapter exists
20230115 175352 worker: eth0 check for address (Off)
20230115 175352 worker: eth0 address not assigned
20230115 175352 worker: wlan0 adapter does not exist
20230115 175352 worker: apd0 router mode (Off)
20230115 175352 worker: No active network interface
20230115 175352 worker: --
20230115 175352 worker: -- Software update
20230115 175352 worker: --
20230115 175352 worker: Automatic check (On)
20230115 175352 worker: Unable to check: No IP address or AP mode is On
20230115 175352 worker: --
20230115 175352 worker: -- Audio config
20230115 175352 worker: --
20230115 175352 worker: MPD conf update skipped (USB device)
20230115 175352 worker: ALSA card number (3)
20230115 175352 worker: MPD audio output (M4)
20230115 175352 worker: Audio formats (S32_LE)
20230115 175352 worker: ALSA mixer name (PCM)
20230115 175352 worker: MPD mixer type (software)
20230115 175352 worker: Hdwr volume controller not detected
20230115 175352 worker: ALSA output mode (Default: plughw)
20230115 175352 worker: ALSA loopback (Off)
20230115 175352 worker: Reset renderer active flags
20230115 175352 worker: CamillaDSP (MOTU4.yml)
20230115 175352 worker: --
20230115 175352 worker: -- File sharing
20230115 175352 worker: --
20230115 175352 worker: SMB file sharing (Off)
20230115 175352 worker: NFS file sharing (Off)
20230115 175352 worker: --
20230115 175352 worker: -- MPD startup
20230115 175352 worker: --
20230115 175352 worker: MPD started
20230115 175352 worker: MPD accepting connections
20230115 175352 worker: MPD output 1 ALSA Default (On)
20230115 175352 worker: MPD output 2 ALSA Bluetooth (Off)
20230115 175352 worker: MPD output 3 HTTP Server (Off)
20230115 175352 worker: MPD crossfade (off)
20230115 175352 worker: MPD ignore CUE files (yes)
20230115 175352 worker: --
20230115 175352 worker: -- Music sources
20230115 175352 worker: --
20230115 175352 worker: USB sources
20230115 175352 worker: No drives found
20230115 175352 worker: NAS sources
20230115 175352 worker: MusicOnNAS
20230115 175354 worker: Try (mount -t cifs "//192.168.1.21/Music/" -o username="Guest",password="",rsize=61440,wsize=65536,iocharset=utf8,ro,noserverino,dir_mode=0777,file_mode=0777 "/mnt/NAS/Music")
20230115 175354 worker: Err (mount error(101): Network is unreachable
Refer to the mount.cifs(8) manual page (e.g. man mount.cifs) and kernel log messages (dmesg))
20230115 175354 worker: Mount all submitted
20230115 175354 worker: --
20230115 175354 worker: -- Feature availability
20230115 175354 worker: --
20230115 175354 worker: Input select (available)
20230115 175354 worker: Input (MPD)
20230115 175354 worker: Output (M4)
20230115 175354 worker: Bluetooth (available: started)
20230115 175354 worker: Pairing agent (started)
20230115 175356 worker: AirPlay renderer (available: started)
20230115 175356 worker: Spotify renderer (available)
20230115 175356 worker: Squeezelite (available)
20230115 175356 worker: RoonBridge renderer (not installed)
20230115 175356 worker: Multiroom sender (available)
20230115 175356 worker: Multiroom receiver (available)
20230115 175356 worker: UPnP renderer (available: started)
20230115 175356 worker: DLNA server (available: started)
20230115 175356 worker: GPIO button handler (available: started)
20230115 175356 worker: Stream recorder (n/a)
20230115 175356 worker: HTTPS-Only mode (n/a)
20230115 175356 worker: --
20230115 175356 worker: -- Other
20230115 175356 worker: --
20230115 175356 worker: USB volume knob (Off)
20230115 175356 worker: USB auto-mounter (udisks-glue)
20230115 175356 worker: Saved MPD vol level (0)
20230115 175356 worker: Preamp volume level (0)
20230115 175357 worker: MPD volume level (12) restored
20230115 175357 worker: ALSA volume level (None)
20230115 175357 worker: Auto-play (Off)
20230115 175357 worker: LocalUI (Off)
20230115 175357 worker: CoverView toggle (Off)
20230115 175357 worker: On-screen keyboard (Off)
20230115 175357 worker: Library scope (all)
20230115 175357 worker: View reset to playback
20230115 175357 worker: Maintenance interval (360 minutes)
20230115 175357 worker: Screen saver activation (Never)
20230115 175357 worker: Session permissions (OK)
20230115 175357 worker: Mount monitor started
20230115 175357 worker: Watchdog started
20230115 175357 worker: Ready

That's a fresh reboot, and I was able to get the MPD error to occur after this reboot.
Reply
#6
(01-16-2023, 12:27 AM)gwurb Wrote:
(01-15-2023, 12:04 PM)Tim Curtis Wrote: Reboot and post the startup log.

Code:
moodeutl -l

*Not sure why SMB does not auto mount on start up but manually mounting it via GUI is fine. It auto mounts after a while. Maybe because I am using a USB hub with ethernet adapter? But that is not the main issue.
Code:
20230115 175347 worker: --
20230115 175347 worker: -- Start moOde 8 series
20230115 175347 worker: --
20230115 175347 worker: Successfully daemonized
20230115 175349 worker: File check (OK)
20230115 175350 worker: Session vacuumed
20230115 175350 worker: Session loaded
20230115 175350 worker: Debug logging (OFF)
20230115 175350 worker: --
20230115 175350 worker: -- Audio debug
20230115 175350 worker: --
20230115 175350 worker: ALSA cards: (0:Loopback | 1:b1 | 2:Headphones | 3:M4
20230115 175350 worker: MPD config: (3:M4 | mixer:(PCM) | card:3)
20230115 175350 worker: ALSA mixer actual (PCM)
20230115 175350 worker: ALSA PCM volume set to (amixer: Unable to find simple control 'PCM',0)
20230115 175350 worker: --
20230115 175350 worker: -- System
20230115 175350 worker: --
20230115 175351 worker: Host      (mooderp4)
20230115 175351 worker: moOde     (8.2.4 2022-12-27)
20230115 175351 worker: RaspiOS   (11.6)
20230115 175351 worker: Kernel    (5.15.76-v8+ #1597)
20230115 175351 worker: Platform  (Pi-4B 1.2 4GB)
20230115 175351 worker: ARM arch  (aarch64, 64-bit)
20230115 175351 worker: MPD ver   (0.23.11)
20230115 175351 worker: CPU gov   (ondemand)
20230115 175351 worker: USB boot  (enabled)
20230115 175351 worker: File sys  (expanded)
20230115 175351 worker: HDMI port (On)
20230115 175352 worker: Sys LED0  (On)
20230115 175352 worker: Sys LED1  (On)
20230115 175352 worker: --
20230115 175352 worker: -- Network
20230115 175352 worker: --
20230115 175352 worker: eth0 adapter exists
20230115 175352 worker: eth0 check for address (Off)
20230115 175352 worker: eth0 address not assigned
20230115 175352 worker: wlan0 adapter does not exist
20230115 175352 worker: apd0 router mode (Off)
20230115 175352 worker: No active network interface
20230115 175352 worker: --
20230115 175352 worker: -- Software update
20230115 175352 worker: --
20230115 175352 worker: Automatic check (On)
20230115 175352 worker: Unable to check: No IP address or AP mode is On
20230115 175352 worker: --
20230115 175352 worker: -- Audio config
20230115 175352 worker: --
20230115 175352 worker: MPD conf update skipped (USB device)
20230115 175352 worker: ALSA card number (3)
20230115 175352 worker: MPD audio output (M4)
20230115 175352 worker: Audio formats (S32_LE)
20230115 175352 worker: ALSA mixer name (PCM)
20230115 175352 worker: MPD mixer type (software)
20230115 175352 worker: Hdwr volume controller not detected
20230115 175352 worker: ALSA output mode (Default: plughw)
20230115 175352 worker: ALSA loopback (Off)
20230115 175352 worker: Reset renderer active flags
20230115 175352 worker: CamillaDSP (MOTU4.yml)
20230115 175352 worker: --
20230115 175352 worker: -- File sharing
20230115 175352 worker: --
20230115 175352 worker: SMB file sharing (Off)
20230115 175352 worker: NFS file sharing (Off)
20230115 175352 worker: --
20230115 175352 worker: -- MPD startup
20230115 175352 worker: --
20230115 175352 worker: MPD started
20230115 175352 worker: MPD accepting connections
20230115 175352 worker: MPD output 1 ALSA Default (On)
20230115 175352 worker: MPD output 2 ALSA Bluetooth (Off)
20230115 175352 worker: MPD output 3 HTTP Server (Off)
20230115 175352 worker: MPD crossfade (off)
20230115 175352 worker: MPD ignore CUE files (yes)
20230115 175352 worker: --
20230115 175352 worker: -- Music sources
20230115 175352 worker: --
20230115 175352 worker: USB sources
20230115 175352 worker: No drives found
20230115 175352 worker: NAS sources
20230115 175352 worker: MusicOnNAS
20230115 175354 worker: Try (mount -t cifs "//192.168.1.21/Music/" -o username="Guest",password="",rsize=61440,wsize=65536,iocharset=utf8,ro,noserverino,dir_mode=0777,file_mode=0777 "/mnt/NAS/Music")
20230115 175354 worker: Err (mount error(101): Network is unreachable
Refer to the mount.cifs(8) manual page (e.g. man mount.cifs) and kernel log messages (dmesg))
20230115 175354 worker: Mount all submitted
20230115 175354 worker: --
20230115 175354 worker: -- Feature availability
20230115 175354 worker: --
20230115 175354 worker: Input select (available)
20230115 175354 worker: Input (MPD)
20230115 175354 worker: Output (M4)
20230115 175354 worker: Bluetooth (available: started)
20230115 175354 worker: Pairing agent (started)
20230115 175356 worker: AirPlay renderer (available: started)
20230115 175356 worker: Spotify renderer (available)
20230115 175356 worker: Squeezelite (available)
20230115 175356 worker: RoonBridge renderer (not installed)
20230115 175356 worker: Multiroom sender (available)
20230115 175356 worker: Multiroom receiver (available)
20230115 175356 worker: UPnP renderer (available: started)
20230115 175356 worker: DLNA server (available: started)
20230115 175356 worker: GPIO button handler (available: started)
20230115 175356 worker: Stream recorder (n/a)
20230115 175356 worker: HTTPS-Only mode (n/a)
20230115 175356 worker: --
20230115 175356 worker: -- Other
20230115 175356 worker: --
20230115 175356 worker: USB volume knob (Off)
20230115 175356 worker: USB auto-mounter (udisks-glue)
20230115 175356 worker: Saved MPD vol level (0)
20230115 175356 worker: Preamp volume level (0)
20230115 175357 worker: MPD volume level (12) restored
20230115 175357 worker: ALSA volume level (None)
20230115 175357 worker: Auto-play (Off)
20230115 175357 worker: LocalUI (Off)
20230115 175357 worker: CoverView toggle (Off)
20230115 175357 worker: On-screen keyboard (Off)
20230115 175357 worker: Library scope (all)
20230115 175357 worker: View reset to playback
20230115 175357 worker: Maintenance interval (360 minutes)
20230115 175357 worker: Screen saver activation (Never)
20230115 175357 worker: Session permissions (OK)
20230115 175357 worker: Mount monitor started
20230115 175357 worker: Watchdog started
20230115 175357 worker: Ready

That's a fresh reboot, and I was able to get the MPD error to occur after this reboot.


To remove USB hub as an issue I plugged everything straight into RPI4 (ethernet cable into ethernet port RPI4 and MOTU M4 into RPI4). Can still get MPD error to occur but it's harder to get it to trigger. Logs:


Code:
2023-01-16 00:41:42.104062 INFO [src/bin.rs:711] CamillaDSP version 1.0.3
2023-01-16 00:41:42.104212 INFO [src/bin.rs:712] Running on linux, aarch64
2023-01-16 00:41:42.156105 INFO [src/alsadevice.rs:161] Starting playback from Prepared state
2023-01-16 00:43:07.963380 WARN [src/alsadevice.rs:157] Prepare playback after buffer underrun
2023-01-16 00:43:28.142895 WARN [src/alsadevice.rs:157] Prepare playback after buffer underrun
2023-01-16 00:43:28.252391 WARN [src/alsadevice.rs:192] Wait timed out, playback device takes too long to drain buffer
2023-01-16 00:43:28.252518 WARN [src/alsadevice.rs:213] Retrying playback, error: ALSA function 'snd_pcm_writei' failed with error 'EAGAIN: Try again'
2023-01-16 00:43:28.274262 ERROR [src/bin.rs:344] Playback error: ALSA function 'snd_pcm_writei' failed with error 'EAGAIN: Try again'
2023-01-16 00:43:28.358275 WARN [src/alsadevice.rs:192] Wait timed out, playback device takes too long to drain buffer
2023-01-16 00:43:28.358362 WARN [src/alsadevice.rs:213] Retrying playback, error: ALSA function 'snd_pcm_writei' failed with error 'EAGAIN: Try again'
Jan 16 11:43 : output: Failed to play on "ALSA Default" (alsa): snd_pcm_poll_descriptors_revents() failed: No such device
Jan 16 11:43 : exception: Failed to open audio output

Code:
20230116 114008 worker: --
20230116 114008 worker: -- Start moOde 8 series
20230116 114008 worker: --
20230116 114008 worker: Successfully daemonized
20230116 114010 worker: File check (OK)
20230116 114011 worker: Session vacuumed
20230116 114011 worker: Session loaded
20230116 114011 worker: Debug logging (OFF)
20230116 114011 worker: --
20230116 114011 worker: -- Audio debug
20230116 114011 worker: --
20230116 114011 worker: ALSA cards: (0:Loopback | 1:b1 | 2:Headphones | 3:M4
20230116 114011 worker: MPD config: (3:M4 | mixer:(PCM) | card:3)
20230116 114011 worker: ALSA mixer actual (PCM)
20230116 114011 worker: ALSA PCM volume set to (amixer: Unable to find simple control 'PCM',0)
20230116 114011 worker: --
20230116 114011 worker: -- System
20230116 114011 worker: --
20230116 114012 worker: Host      (mooderp4)
20230116 114012 worker: moOde     (8.2.4 2022-12-27)
20230116 114012 worker: RaspiOS   (11.6)
20230116 114012 worker: Kernel    (5.15.76-v8+ #1597)
20230116 114012 worker: Platform  (Pi-4B 1.2 4GB)
20230116 114012 worker: ARM arch  (aarch64, 64-bit)
20230116 114012 worker: MPD ver   (0.23.11)
20230116 114012 worker: CPU gov   (ondemand)
20230116 114012 worker: USB boot  (enabled)
20230116 114012 worker: File sys  (expanded)
20230116 114012 worker: HDMI port (On)
20230116 114012 worker: Sys LED0  (On)
20230116 114012 worker: Sys LED1  (On)
20230116 114012 worker: --
20230116 114012 worker: -- Network
20230116 114012 worker: --
20230116 114012 worker: eth0 adapter exists
20230116 114012 worker: eth0 check for address (Off)
20230116 114012 worker: eth0 address not assigned
20230116 114012 worker: wlan0 adapter does not exist
20230116 114012 worker: apd0 router mode (Off)
20230116 114012 worker: No active network interface
20230116 114012 worker: --
20230116 114012 worker: -- Software update
20230116 114012 worker: --
20230116 114012 worker: Automatic check (On)
20230116 114012 worker: Unable to check: No IP address or AP mode is On
20230116 114012 worker: --
20230116 114012 worker: -- Audio config
20230116 114012 worker: --
20230116 114012 worker: MPD conf update skipped (USB device)
20230116 114012 worker: ALSA card number (3)
20230116 114012 worker: MPD audio output (M4)
20230116 114013 worker: Audio formats (S32_LE)
20230116 114013 worker: ALSA mixer name (PCM)
20230116 114013 worker: MPD mixer type (software)
20230116 114013 worker: Hdwr volume controller not detected
20230116 114013 worker: ALSA output mode (Default: plughw)
20230116 114013 worker: ALSA loopback (Off)
20230116 114013 worker: Reset renderer active flags
20230116 114013 worker: CamillaDSP (MOTU4.yml)
20230116 114013 worker: --
20230116 114013 worker: -- File sharing
20230116 114013 worker: --
20230116 114013 worker: SMB file sharing (Off)
20230116 114013 worker: NFS file sharing (Off)
20230116 114013 worker: --
20230116 114013 worker: -- MPD startup
20230116 114013 worker: --
20230116 114013 worker: MPD started
20230116 114013 worker: MPD accepting connections
20230116 114013 worker: MPD output 1 ALSA Default (On)
20230116 114013 worker: MPD output 2 ALSA Bluetooth (Off)
20230116 114013 worker: MPD output 3 HTTP Server (Off)
20230116 114013 worker: MPD crossfade (off)
20230116 114013 worker: MPD ignore CUE files (yes)
20230116 114013 worker: --
20230116 114013 worker: -- Music sources
20230116 114013 worker: --
20230116 114013 worker: USB sources
20230116 114013 worker: No drives found
20230116 114013 worker: NAS sources
20230116 114013 worker: MusicOnNAS
20230116 114014 worker: Try (mount -t cifs "//192.168.1.21/Music/" -o username="Guest",password="",rsize=61440,wsize=65536,iocharset=utf8,ro,noserverino,dir_mode=0777,file_mode=0777 "/mnt/NAS/Music")
20230116 114014 worker: Err (mount error(101): Network is unreachable
Refer to the mount.cifs(8) manual page (e.g. man mount.cifs) and kernel log messages (dmesg))
20230116 114014 worker: Mount all submitted
20230116 114014 worker: --
20230116 114014 worker: -- Feature availability
20230116 114014 worker: --
20230116 114014 worker: Input select (available)
20230116 114014 worker: Input (MPD)
20230116 114014 worker: Output (M4)
20230116 114015 worker: Bluetooth (available: started)
20230116 114015 worker: Pairing agent (started)
20230116 114039 worker: AirPlay renderer (available: started)
20230116 114039 worker: Spotify renderer (available)
20230116 114039 worker: Squeezelite (available)
20230116 114039 worker: RoonBridge renderer (not installed)
20230116 114039 worker: Multiroom sender (available)
20230116 114039 worker: Multiroom receiver (available)
20230116 114039 worker: UPnP renderer (available: started)
20230116 114039 worker: DLNA server (available: started)
20230116 114039 worker: GPIO button handler (available: started)
20230116 114039 worker: Stream recorder (n/a)
20230116 114039 worker: HTTPS-Only mode (n/a)
20230116 114039 worker: --
20230116 114039 worker: -- Other
20230116 114039 worker: --
20230116 114039 worker: USB volume knob (Off)
20230116 114039 worker: USB auto-mounter (udisks-glue)
20230116 114039 worker: Saved MPD vol level (0)
20230116 114039 worker: Preamp volume level (0)
20230116 114039 worker: MPD volume level (14) restored
20230116 114039 worker: ALSA volume level (None)
20230116 114039 worker: Auto-play (Off)
20230116 114039 worker: LocalUI (Off)
20230116 114039 worker: CoverView toggle (Off)
20230116 114039 worker: On-screen keyboard (Off)
20230116 114039 worker: Library scope (all)
20230116 114039 worker: View reset to playback
20230116 114039 worker: Maintenance interval (360 minutes)
20230116 114039 worker: Screen saver activation (Never)
20230116 114039 worker: Session permissions (OK)
20230116 114039 worker: Mount monitor started
20230116 114039 worker: Watchdog started
20230116 114039 worker: Ready
Reply
#7
The moOde startup log suggests some sort of network issue. An Ethernet connected Pi should get an IP address from Router almost instantly during the Linux part of system startup and before moOde startup but the moOde startup log shows "eth0 address not assigned".

Code:
20230116 114012 worker: eth0 adapter exists
20230116 114012 worker: eth0 check for address (Off)
20230116 114012 worker: eth0 address not assigned
20230116 114012 worker: wlan0 adapter does not exist
20230116 114012 worker: apd0 router mode (Off)
20230116 114012 worker: No active network interface

You could try turning on "Wait for Ethernet" in System config and leave the timeout at 90 sec default. This will cause moOde startup to wait up to 90 seconds for an Ethernet address to be assigned but this may just mask an underlying network issue.

The lines from Camilla in the MPD log indicate no audio device detected.

Code:
Jan 16 11:43 : output: Failed to play on "ALSA Default" (alsa): snd_pcm_poll_descriptors_revents() failed: No such device
Jan 16 11:43 : exception: Failed to open audio output
Enjoy the Music!
moodeaudio.org | Mastodon Feed | GitHub
Reply
#8
(01-16-2023, 01:16 AM)Tim Curtis Wrote: The moOde startup log suggests some sort of network issue. An Ethernet connected Pi should get an IP address from Router almost instantly during the Linux part of system startup and before moOde startup but the moOde startup log shows "eth0 address not assigned".

Code:
20230116 114012 worker: eth0 adapter exists
20230116 114012 worker: eth0 check for address (Off)
20230116 114012 worker: eth0 address not assigned
20230116 114012 worker: wlan0 adapter does not exist
20230116 114012 worker: apd0 router mode (Off)
20230116 114012 worker: No active network interface

You could try turning on "Wait for Ethernet" in System config and leave the timeout at 90 sec default. This will cause moOde startup to wait up to 90 seconds for an Ethernet address to be assigned but this may just mask an underlying network issue.

The lines from Camilla in the MPD log indicate no audio device detected.

Code:
Jan 16 11:43 : output: Failed to play on "ALSA Default" (alsa): snd_pcm_poll_descriptors_revents() failed: No such device
Jan 16 11:43 : exception: Failed to open audio output

No USB hub in the chain anymore...

The wait for ethernet works...

Code:
20230116 122918 worker: --
20230116 122918 worker: -- Start moOde 8 series
20230116 122918 worker: --
20230116 122918 worker: Successfully daemonized
20230116 122920 worker: File check (OK)
20230116 122921 worker: Session vacuumed
20230116 122921 worker: Session loaded
20230116 122921 worker: Debug logging (OFF)
20230116 122921 worker: --
20230116 122921 worker: -- Audio debug
20230116 122921 worker: --
20230116 122921 worker: ALSA cards: (0:Loopback | 1:b1 | 2:Headphones | 3:M4
20230116 122921 worker: MPD config: (3:M4 | mixer:(PCM) | card:3)
20230116 122921 worker: ALSA mixer actual (PCM)
20230116 122921 worker: ALSA PCM volume set to (amixer: Unable to find simple control 'PCM',0)
20230116 122921 worker: --
20230116 122921 worker: -- System
20230116 122921 worker: --
20230116 122922 worker: Host      (mooderp4)
20230116 122922 worker: moOde     (8.2.4 2022-12-27)
20230116 122922 worker: RaspiOS   (11.6)
20230116 122922 worker: Kernel    (5.15.76-v8+ #1597)
20230116 122922 worker: Platform  (Pi-4B 1.2 4GB)
20230116 122922 worker: ARM arch  (aarch64, 64-bit)
20230116 122922 worker: MPD ver   (0.23.11)
20230116 122922 worker: CPU gov   (ondemand)
20230116 122922 worker: USB boot  (enabled)
20230116 122922 worker: File sys  (expanded)
20230116 122923 worker: HDMI port (On)
20230116 122923 worker: Sys LED0  (On)
20230116 122923 worker: Sys LED1  (On)
20230116 122923 worker: --
20230116 122923 worker: -- Network
20230116 122923 worker: --
20230116 122923 worker: eth0 adapter exists
20230116 122923 worker: eth0 check for address (On)
20230116 122923 worker: eth0 address check (90 secs)
20230116 122923 worker: eth0 check 0 for IP address
20230116 122925 worker: eth0 check 1 for IP address
20230116 122927 worker: eth0 check 2 for IP address
20230116 122929 worker: eth0 check 3 for IP address
20230116 122931 worker: eth0 check 4 for IP address
20230116 122952 worker: IP addr (192.168.1.28)
20230116 122952 worker: Netmask (255.255.255.0)
20230116 122952 worker: Gateway (192.168.1.1)
20230116 122952 worker: Pri DNS (192.168.1.1)
20230116 122952 worker: Domain  ()
20230116 122952 worker: wlan0 adapter does not exist
20230116 122952 worker: apd0 router mode (Off)
20230116 122952 worker: --
20230116 122952 worker: -- Software update
20230116 122952 worker: --
20230116 122952 worker: Automatic check (On)
20230116 122952 worker: Checking for available update...
20230116 122952 worker: Software is up to date
20230116 122952 worker: --
20230116 122952 worker: -- Audio config
20230116 122952 worker: --
20230116 122952 worker: MPD conf update skipped (USB device)
20230116 122952 worker: ALSA card number (3)
20230116 122952 worker: MPD audio output (M4)
20230116 122953 worker: Audio formats (S32_LE)
20230116 122953 worker: ALSA mixer name (PCM)
20230116 122953 worker: MPD mixer type (software)
20230116 122953 worker: Hdwr volume controller not detected
20230116 122953 worker: ALSA output mode (Default: plughw)
20230116 122953 worker: ALSA loopback (Off)
20230116 122953 worker: Reset renderer active flags
20230116 122953 worker: CamillaDSP (MOTU4.yml)
20230116 122953 worker: --
20230116 122953 worker: -- File sharing
20230116 122953 worker: --
20230116 122953 worker: SMB file sharing (Off)
20230116 122953 worker: NFS file sharing (Off)
20230116 122953 worker: --
20230116 122953 worker: -- MPD startup
20230116 122953 worker: --
20230116 122953 worker: MPD started
20230116 122953 worker: MPD accepting connections
20230116 122953 worker: MPD output 1 ALSA Default (On)
20230116 122953 worker: MPD output 2 ALSA Bluetooth (Off)
20230116 122953 worker: MPD output 3 HTTP Server (Off)
20230116 122953 worker: MPD crossfade (off)
20230116 122953 worker: MPD ignore CUE files (yes)
20230116 122953 worker: --
20230116 122953 worker: -- Music sources
20230116 122953 worker: --
20230116 122953 worker: USB sources
20230116 122953 worker: No drives found
20230116 122953 worker: NAS sources
20230116 122953 worker: Music


I don't know why the system suddenly decides that there is no audio device detected. Can you think of anything that Moode is doing that may be contributing?

CamillaDSP log for most recent reboot
Code:
2023-01-16 01:33:18.627324 INFO [src/bin.rs:711] CamillaDSP version 1.0.3
2023-01-16 01:33:18.627439 INFO [src/bin.rs:712] Running on linux, aarch64
2023-01-16 01:33:18.658983 INFO [src/alsadevice.rs:161] Starting playback from Prepared state
Jan 16 12:33 : ffmpeg/mov,mp4,m4a,3gp,3g2,mj2: stream 0, timescale not set
Jan 16 12:33 : ffmpeg/mov,mp4,m4a,3gp,3g2,mj2: stream 0, timescale not set
2023-01-16 01:33:58.403430 WARN [src/alsadevice.rs:157] Prepare playback after buffer underrun
2023-01-16 01:33:58.510386 WARN [src/alsadevice.rs:192] Wait timed out, playback device takes too long to drain buffer
2023-01-16 01:33:58.510499 WARN [src/alsadevice.rs:213] Retrying playback, error: ALSA function 'snd_pcm_writei' failed with error 'EAGAIN: Try again'
2023-01-16 01:33:58.531963 ERROR [src/bin.rs:344] Playback error: ALSA function 'snd_pcm_writei' failed with error 'EAGAIN: Try again'
2023-01-16 01:33:58.616497 WARN [src/alsadevice.rs:192] Wait timed out, playback device takes too long to drain buffer
2023-01-16 01:33:58.616750 WARN [src/alsadevice.rs:213] Retrying playback, error: ALSA function 'snd_pcm_writei' failed with error 'EAGAIN: Try again'
2023-01-16 01:33:58.723168 WARN [src/alsadevice.rs:192] Wait timed out, playback device takes too long to drain buffer
2023-01-16 01:33:58.723287 WARN [src/alsadevice.rs:213] Retrying playback, error: ALSA function 'snd_pcm_writei' failed with error 'EAGAIN: Try again'
Jan 16 12:33 : output: Failed to play on "ALSA Default" (alsa): snd_pcm_poll_descriptors_revents() failed: No such device
Jan 16 12:33 : exception: Failed to open audio output
2023-01-16 01:34:31.370157 INFO [src/bin.rs:711] CamillaDSP version 1.0.3
2023-01-16 01:34:31.370299 INFO [src/bin.rs:712] Running on linux, aarch64
2023-01-16 01:34:31.384324 INFO [src/alsadevice.rs:161] Starting playback from Prepared state
2023-01-16 01:34:32.580022 INFO [src/bin.rs:420] Capture finished
2023-01-16 01:34:32.643805 INFO [src/bin.rs:410] Playback finished
Reply
#9
Maybe some issue with the USB connection between Pi and audio device for example not enough power, bad cable etc.
Enjoy the Music!
moodeaudio.org | Mastodon Feed | GitHub
Reply
#10
(01-16-2023, 02:19 AM)Tim Curtis Wrote: Maybe some issue with the USB connection between Pi and audio device for example not enough power, bad cable etc.

But why would it only cause a problem on track change when the previous song has only been playing for a particular amount of time?

I might try asking on diyaudio camilladsp thread.
Reply


Forum Jump: