[SOLVED] UPnP - CamillaDSP

[bitlab]

@caseyjones and @klausimausi04 slowly making progress.
The easiest way to reproduce the problem is using a playlist with radio stations (with different samplerates) and then just toggle between the stations in the list.

So we can take entire upnp subsystem and upmpdcli out of the picture. Leaves the mpd http input module and alsa_cdsp plugin.

[klausimausi04]

Thank you, Bitlab, for continuing to find the error.

[bitlab]

@caseyjones and @klausimausi04 looks like I finally found the cause of the problem: the curl input plugin.
And to be specific it seems not the code om the mpd curl plugin in itself, but the used version of libcurl which does do the heafty lifting for the http transport.

It concerns the following installed curl packages:

• libcurl3-gnutls/stable,now 7.64.0-4+deb10u2 armhf [installed,automatic]
  

Now the cause seems to be known, it is easier to search in the right direction of simular issues:

• https://github.com/MusicPlayerDaemon/MPD/issues/584
  
• https://github.com/curl/curl/issues/4063
  

For test I rebuilded an upstream version if libcurl3-gnutls which seems to fix the issue (tested with the radio playlist case)
Only this isn't a final solution because it breaks some of the other tools like git.
So we are not there yet, but at least a step further again.

[Tim Curtis]

This nice fix to libcurl3 from @bitlab has been incorporated into upcoming moOde 7.3.0 release. It's installed and configured so that MPD is the only process that uses it and thus it does not break other utilities that expect the original libcurl3l :-)

[klausimausi04]

Hi Tim,
thank you very much for this message!
Also Bitlab, thank you for your work!

Kind regards
Klaus

[caseyjones]

Great news and good work! Now the 10000$ question.... WHEN 7.3.0!?

[TRiNGT3]

Just revisiting this, not sure if there's been further feedback from OP following the release of 7.3.0 to confirm that it resolved for them.

For my setup at least, the issue still persists even when applying the 7.3.0 release (previously 7.2.1)

In short, enabling C-DSP, the UPnP renderer fails if I interrupt the stream via the control point (stop, re-play current track, scrub/scan current track, play next track)

Restarting the UPnP renderer will stream ok without fuss and will continue streaming without issue if I don't interrupt it. The only action that won't cause a UPnP renderer failure is pause and resume.

In my case:

• Issue only occurs if I introduce C-DSP into the mix,
  
• Issue occurs even when reverting back to the stock config flat yml for testing purposes,
  
• Pause and resume are the only actions I can perform on the control point without triggering a UPnP renderer failure,
  
• No issues when streaming without C-DSP. Wanting to take advantage of C-DSP as it offer more granular EQ'ing for headphone use over the built-in Parametric EQ which only offers peaking filters; lacking low/high shelf filters. No issues whatsoever using the built-in Parametric EQ,
  
• Running 'sudo systemctl restart upmpdcli' command fixes the issue temporarily,
  

• Control point/software: Win 10 PC, Foobar2000 with UPnP MediaRenderer Output component over WiFi to moode
  
  

Outputs for system info start-up log and sudo systemctl status upmpdcli (when the problem occurred), and moodeutl -l:-

Code:

M O O D E   S T A R T U P   L O G

20210629 182908 worker: -- Start
20210629 182908 worker: Successfully daemonized
20210629 182908 worker: Integrity check (passed)
20210629 182909 worker: File check (OK)
20210629 182909 worker: Session vacuumed
20210629 182909 worker: Session loaded
20210629 182909 worker: Debug logging (OFF)
20210629 182909 worker: -- Audio debug
20210629 182909 worker: ALSA cards: (0:sndrpihifiberry | 1:empty | 2:empty | 3:empty
20210629 182909 worker: MPD config: (0:HiFiBerry Digi+ Pro | mixer:(none) | card:0)
20210629 182909 worker: ALSA mixer actual (none)
20210629 182909 worker: ALSA volume (none)
20210629 182909 worker: -- System
20210629 182910 worker: Host     (moOde)
20210629 182910 worker: moOde    (7.3.0 2021-06-25)
20210629 182910 worker: RaspiOS  (10.6)
20210629 182910 worker: Kernel   (5.4.77-v7l+ #1371)
20210629 182910 worker: Platform (Pi-4B 1.2 4GB)
20210629 182910 worker: ARM arch (armv7l, 32-bit kernel)
20210629 182910 worker: MPD ver  (0.22.8_p0x3)
20210629 182910 worker: CPU gov  (ondemand)
20210629 182910 worker: USB boot not available
20210629 182910 worker: File system expanded
20210629 182910 worker: HDMI port off
20210629 182910 worker: -- Network
20210629 182911 worker: eth0 exists
20210629 182911 worker: eth0 wait 0 for IP address
20210629 182914 worker: eth0 wait 1 for IP address
20210629 182917 worker: eth0 wait 2 for IP address
20210629 182920 worker: eth0 wait 3 for IP address
20210629 182923 worker: eth0 wait 4 for IP address
20210629 182943 worker: eth0 address not assigned
20210629 182943 worker: wlan0 exists
20210629 182943 worker: wifi country (X)
20210629 182943 worker: wlan0 trying SSID (X)
20210629 182943 worker: IP addr (192.168.X.X)
20210629 182943 worker: Netmask (255.255.255.0)
20210629 182943 worker: Gateway (192.168.X.X)
20210629 182943 worker: Pri DNS (1.1.1.1)
20210629 182943 worker: Domain  (modem)
20210629 182943 worker: Pi integrated wlan0 power save disabled
20210629 182943 worker: -- Audio config
20210629 182943 worker: MPD conf updated
20210629 182943 worker: ALSA card number (0)
20210629 182943 worker: MPD audio output (HiFiBerry Digi+ Pro)
20210629 182943 worker: Audio formats (S16_LE, S24_LE)
20210629 182943 worker: ALSA mixer name (none)
20210629 182943 worker: MPD volume control (none)
20210629 182944 worker: Hdwr volume controller not detected
20210629 182944 worker: ALSA output mode (Default: plughw)
20210629 182944 worker: ALSA loopback (Off)
20210629 182944 worker: Reset renderer active flags
20210629 182944 worker: CamillaDSP (flat.yml)
20210629 182944 worker: -- MPD startup
20210629 182944 worker: MPD started
20210629 182944 worker: MPD accepting connections
20210629 182944 worker: MPD output 1 ALSA Default (on)
20210629 182944 worker: MPD output 2 ALSA Bluetooth (off)
20210629 182944 worker: MPD output 3 HTTP Server (off)
20210629 182944 worker: MPD crossfade (off)
20210629 182944 worker: MPD ignore CUE files (yes)
20210629 182944 worker: -- Feature availability
20210629 182944 worker: Source select (available)
20210629 182944 worker: Source select (source: MPD)
20210629 182944 worker: Source select (output: HiFiBerry Digi+ Pro)
20210629 182944 worker: Bluetooth (available)
20210629 182944 worker: Airplay renderer (available)
20210629 182944 worker: Spotify renderer (available)
20210629 182944 worker: Squeezelite (available)
20210629 182944 worker: RoonBridge renderer (not installed)
20210629 182944 worker: UPnP renderer (available: started)
20210629 182944 worker: DLNA server (available)
20210629 182944 worker: UPnP browser (available)
20210629 182944 worker: GPIO button handler (available)
20210629 182944 worker: Stream recorder (n/a)
20210629 182944 worker: -- Music sources
20210629 182944 worker: USB sources (none attached)
20210629 182944 worker: NAS and UPnP sources (none configured)
20210629 182944 worker: -- Other
20210629 182944 worker: USB volume knob (Off)
20210629 182945 worker: Shellinabox SSH started
20210629 182945 worker: USB auto-mounter (udisks-glue)
20210629 182945 worker: LED0 (Off)
20210629 182945 worker: LED1 (Off)
20210629 182945 worker: Saved MPD vol level (0)
20210629 182945 worker: Preamp volume level (0)
20210629 182945 worker: MPD volume level (0) restored
20210629 182945 worker: ALSA volume level (None)
20210629 182945 worker: Auto-play (Off)
20210629 182945 worker: Maintenance interval (3 hours)
20210629 182945 worker: Screen saver activation (Never)
20210629 182945 worker: Session permissions (OK)
20210629 182945 worker: Watchdog started
20210629 182945 worker: Ready

Code:

pi@moOde:~ $ sudo systemctl status upmpdcli
● upmpdcli.service - UPnP Renderer front-end to MPD
  Loaded: loaded (/lib/systemd/system/upmpdcli.service; disabled; vendor preset: enabled)                                                                                                                        
  Active: active (running) since Tue 2021-06-29 18:29:44 AEST; 6min ago
Main PID: 910 (upmpdcli)                                                                                                                                                                                          
   Tasks: 9 (limit: 4915)                                                                                                                                                                                        
  CGroup: /system.slice/upmpdcli.service                                                                                                                                                                          
          └─910 /usr/bin/upmpdcli -c /etc/upmpdcli.conf                                                                                                                                                          
                                                                                                                                                                                                                 
Jun 29 18:29:45 moOde upmpdcli[910]: :3:src/mediaserver/contentdirectory.cxx:189::ContentDirectory: not creating entry for uprcl because neither uprcluser nor uprclautostart are defined in the configuration    
Jun 29 18:29:45 moOde upmpdcli[910]: :3:libupnpp/upnpplib.cxx:229::LibUPnP: Using IPV4 192.168.x.x port 49152 IPV6  port 49152                                                                                  
Jun 29 18:32:58 moOde upmpdcli[910]: :3:src/mpdcli.cxx:148::MPDCli::startEventLoop: already started                                                                                                                
Jun 29 18:33:59 moOde upmpdcli[910]: :2:src/mpdcli.cxx:224::MPDCli::eventloop: mpd_run_idle_mask returned 0                                                                                                        
Jun 29 18:33:59 moOde upmpdcli[910]: :2:src/mpdcli.cxx:311::mpd_run_stop(m_conn) failed: Connection reset by peer                                                                                                  
Jun 29 18:33:59 moOde upmpdcli[910]: :2:src/mpdcli.cxx:114::MPDCli::openconn: mpd_connection_new failed: Connection refused                                                                                        
Jun 29 18:33:59 moOde upmpdcli[910]: :2:libupnpp/device/device.cxx:446::UpnpDevice: Action failed:  code -911                                                                                                      
Jun 29 18:33:59 moOde upmpdcli[910]: :2:libupnpp/device/device.cxx:446::UpnpDevice: Action failed:  code -911                                                                                                      
Jun 29 18:33:59 moOde upmpdcli[910]: :2:libupnpp/device/device.cxx:446::UpnpDevice: Action failed:  code -911                                                                                                      
Jun 29 18:33:59 moOde upmpdcli[910]: :2:libupnpp/device/device.cxx:446::UpnpDevice: Action failed:  code -911                                                                                  

Code:

pi@moOde:~ $ moodeutl -l
20210629 182908 worker: -- Start                                                                                                                                                                                  
20210629 182908 worker: Successfully daemonized                                                                                                                                                                    
20210629 182908 worker: Integrity check (passed)                                                                                                                                                                  
20210629 182909 worker: File check (OK)                                                                                                                                                                            
20210629 182909 worker: Session vacuumed                                                                                                                                                                          
20210629 182909 worker: Session loaded                                                                                                                                                                            
20210629 182909 worker: Debug logging (OFF)                                                                                                                                                                        
20210629 182909 worker: -- Audio debug                                                                                                                                                                            
20210629 182909 worker: ALSA cards: (0:sndrpihifiberry | 1:empty | 2:empty | 3:empty                                                                                                                              
20210629 182909 worker: MPD config: (0:HiFiBerry Digi+ Pro | mixer:(none) | card:0)                                                                                                                                
20210629 182909 worker: ALSA mixer actual (none)                                                                                                                                                                  
20210629 182909 worker: ALSA volume (none)                                                                                                                                                                        
20210629 182909 worker: -- System                                                                                                                                                                                  
20210629 182910 worker: Host     (moOde)                                                                                                                                                                          
20210629 182910 worker: moOde    (7.3.0 2021-06-25)                                                                                                                                                                
20210629 182910 worker: RaspiOS  (10.6)                                                                                                                                                                            
20210629 182910 worker: Kernel   (5.4.77-v7l+ #1371)                                                                                                                                                              
20210629 182910 worker: Platform (Pi-4B 1.2 4GB)                                                                                                                                                                  
20210629 182910 worker: ARM arch (armv7l, 32-bit kernel)                                                                                                                                                          
20210629 182910 worker: MPD ver  (0.22.8_p0x3)                                                                                                                                                                    
20210629 182910 worker: CPU gov  (ondemand)                                                                                                                                                                        
20210629 182910 worker: USB boot not available                                                                                                                                                                    
20210629 182910 worker: File system expanded                                                                                                                                                                      
20210629 182910 worker: HDMI port off                                                                                                                                                                              
20210629 182910 worker: -- Network                                                                                                                                                                                
20210629 182911 worker: eth0 exists                                                                                                                                                                                
20210629 182911 worker: eth0 wait 0 for IP address                                                                                                                                                                
20210629 182914 worker: eth0 wait 1 for IP address                                                                                                                                                                
20210629 182917 worker: eth0 wait 2 for IP address                                                                                                                                                                
20210629 182920 worker: eth0 wait 3 for IP address                                                                                                                                                                
20210629 182923 worker: eth0 wait 4 for IP address                                                                                                                                                                
20210629 182943 worker: eth0 address not assigned                                                                                                                                                                  
20210629 182943 worker: wlan0 exists                                                                                                                                                                              
20210629 182943 worker: wifi country (X)                                                                                                                                                                          
20210629 182943 worker: wlan0 trying SSID (X)                                                                                                                                                          
20210629 182943 worker: IP addr (192.168.X.X)                                                                                                                                                                    
20210629 182943 worker: Netmask (255.255.255.0)                                                                                                                                                                    
20210629 182943 worker: Gateway (192.168.X.X)                                                                                                                                                                      
20210629 182943 worker: Pri DNS (1.1.1.1)                                                                                                                                                                          
20210629 182943 worker: Domain  (modem)                                                                                                                                                                            
20210629 182943 worker: Pi integrated wlan0 power save disabled                                                                                                                                                    
20210629 182943 worker: -- Audio config                                                                                                                                                                            
20210629 182943 worker: MPD conf updated                                                                                                                                                                          
20210629 182943 worker: ALSA card number (0)                                                                                                                                                                      
20210629 182943 worker: MPD audio output (HiFiBerry Digi+ Pro)                                                                                                                                                    
20210629 182943 worker: Audio formats (S16_LE, S24_LE)                                                                                                                                                            
20210629 182943 worker: ALSA mixer name (none)                                                                                                                                                                    
20210629 182943 worker: MPD volume control (none)                                                                                                                                                                  
20210629 182944 worker: Hdwr volume controller not detected                                                                                                                                                        
20210629 182944 worker: ALSA output mode (Default: plughw)                                                                                                                                                        
20210629 182944 worker: ALSA loopback (Off)                                                                                                                                                                        
20210629 182944 worker: Reset renderer active flags                                                                                                                                                                
20210629 182944 worker: CamillaDSP (flat.yml)                                                                                                                                                                      
20210629 182944 worker: -- MPD startup                                                                                                                                                                            
20210629 182944 worker: MPD started                                                                                                                                                                                
20210629 182944 worker: MPD accepting connections                                                                                                                                                                  
20210629 182944 worker: MPD output 1 ALSA Default (on)                                                                                                                                                            
20210629 182944 worker: MPD output 2 ALSA Bluetooth (off)                                                                                                                                                          
20210629 182944 worker: MPD output 3 HTTP Server (off)                                                                                                                                                            
20210629 182944 worker: MPD crossfade (off)                                                                                                                                                                        
20210629 182944 worker: MPD ignore CUE files (yes)                                                                                                                                                                
20210629 182944 worker: -- Feature availability                                                                                                                                                                    
20210629 182944 worker: Source select (available)                                                                                                                                                                  
20210629 182944 worker: Source select (source: MPD)                                                                                                                                                                
20210629 182944 worker: Source select (output: HiFiBerry Digi+ Pro)                                                                                                                                                
20210629 182944 worker: Bluetooth (available)                                                                                                                                                                      
20210629 182944 worker: Airplay renderer (available)                                                                                                                                                              
20210629 182944 worker: Spotify renderer (available)                                                                                                                                                              
20210629 182944 worker: Squeezelite (available)                                                                                                                                                                    
20210629 182944 worker: RoonBridge renderer (not installed)                                                                                                                                                        
20210629 182944 worker: UPnP renderer (available: started)                                                                                                                                                        
20210629 182944 worker: DLNA server (available)                                                                                                                                                                    
20210629 182944 worker: UPnP browser (available)                                                                                                                                                                  
20210629 182944 worker: GPIO button handler (available)                                                                                                                                                            
20210629 182944 worker: Stream recorder (n/a)                                                                                                                                                                      
20210629 182944 worker: -- Music sources                                                                                                                                                                          
20210629 182944 worker: USB sources (none attached)                                                                                                                                                                
20210629 182944 worker: NAS and UPnP sources (none configured)                                                                                                                                                    
20210629 182944 worker: -- Other                                                                                                                                                                                  
20210629 182944 worker: USB volume knob (Off)                                                                                                                                                                      
20210629 182945 worker: Shellinabox SSH started                                                                                                                                                                    
20210629 182945 worker: USB auto-mounter (udisks-glue)                                                                                                                                                            
20210629 182945 worker: LED0 (Off)                                                                                                                                                                                
20210629 182945 worker: LED1 (Off)                                                                                                                                                                                
20210629 182945 worker: Saved MPD vol level (0)                                                                                                                                                                    
20210629 182945 worker: Preamp volume level (0)                                                                                                                                                                    
20210629 182945 worker: MPD volume level (0) restored                                                                                                                                                              
20210629 182945 worker: ALSA volume level (None)                                                                                                                                                                  
20210629 182945 worker: Auto-play (Off)                                                                                                                                                                            
20210629 182945 worker: Maintenance interval (3 hours)                                                                                                                                                            
20210629 182945 worker: Screen saver activation (Never)                                                                                                                                                            
20210629 182945 worker: Session permissions (OK)                                                                                                                                                                  
20210629 182945 worker: Watchdog started                                                                                                                                                                          
20210629 182945 worker: Ready                                                                                                                                                                                      
20210629 183401 watchdog: Error: MPD restarted (check syslog for errors)                                                                                                                                          
20210629 183402 moode.php: MPD connect failed: cmd=(playlist)                                                                                                                                                      
20210629 183900 watchdog: Error: MPD restarted (check syslog for errors)                                                                                                                                          
20210629 183901 moode.php: MPD connect failed: cmd=(playlist)                                                                                                                                                      
20210629 184654 moode.php: MPD connect failed: cmd=(playlist)                                                                                                                                                      
20210629 184656 watchdog: Error: MPD restarted (check syslog for errors)                                                                                                                                          
20210629 185018 watchdog: Error: MPD restarted (check syslog for errors)                                                                                                                                          
20210629 185018 moode.php: MPD connect failed: cmd=(playlist)                                                                                                                                                      
20210629 185125 watchdog: Error: MPD restarted (check syslog for errors)                                                                                                                                          
20210629 185300 moode.php: MPD connect failed: cmd=(playlist)                                                                                                                                                      
20210629 185303 watchdog: Error: MPD restarted (check syslog for errors)                                                                                                                                          
20210629 185530 worker: Job upnpsvc                                                                                                                                                                                
20210629 185606 moode.php: MPD connect failed: cmd=(playlist)                                                                                                                                                      
20210629 185606 watchdog: Error: MPD restarted (check syslog for errors)                                                                                                                                          
20210629 185612 worker: Job upnpsvc                                                                                                                                                                                
20210629 185654 moode.php: MPD connect failed: cmd=(playlist)                                                                                                                                                      
20210629 185655 watchdog: Error: MPD restarted (check syslog for errors)                                                                                                                                          
20210629 185658 worker: Job upnpsvc                                                                                                                                                                                
20210629 185720 watchdog: Error: MPD restarted (check syslog for errors)                                                                                                                                          
20210629 185725 worker: Job upnpsvc                                                                                                                                                                                
20210629 185750 watchdog: Error: MPD restarted (check syslog for errors)                                                                                                                                          
20210629 185752 worker: Job upnpsvc                                                                                                                                                                                
20210629 185808 watchdog: Error: MPD restarted (check syslog for errors)                                                                                                                                          
20210629 185809 moode.php: MPD connect failed: cmd=(playlist)                                                                                                                                                      
20210629 185813 worker: Job upnpsvc                                                                                                                                                                                
20210629 185909 watchdog: Error: MPD restarted (check syslog for errors)                                                                                                                                          
20210629 185922 worker: Job upnpsvc                                                                                                                                                                                
20210629 190041 worker: Job alsa_output_mode                                                                                                                                                                      
20210629 190059 watchdog: Error: MPD restarted (check syslog for errors)                                                                                                                                          
20210629 190148 worker: Job upnpsvc                                                                                                                                                                                
20210629 190215 worker: Job alsa_output_mode                                                                                                                                                                      
20210629 193503 moode.php: MPD connect failed: cmd=(playlist)                                                                                                                                                      
20210629 193504 watchdog: Error: MPD restarted (check syslog for errors)                                                                                                                                          
20210629 194841 worker: Job upnpsvc                                                                                                                                                                                
20210629 195308 moode.php: MPD connect failed: cmd=(playlist)                                                                                                                                                      
20210629 195311 watchdog: Error: MPD restarted (check syslog for errors)                                                                                                                                          
20210629 195314 worker: Job upnpsvc                                                                                                                                                                                
20210629 195455 watchdog: Error: MPD restarted (check syslog for errors)                                                                                                                                          
20210629 195455 moode.php: MPD connect failed: cmd=(playlist)                                                                                                                                                      
20210629 195506 worker: Job upnpsvc                                                                                                                                                                                
20210629 195556 moode.php: MPD connect failed: cmd=(playlist)                                                                                                                                                      
20210629 195556 watchdog: Error: MPD restarted (check syslog for errors)                                                                                                                                          
20210629 195603 worker: Job upnpsvc                                                                                                                                                                                
20210629 195715 watchdog: Error: MPD restarted (check syslog for errors)                                                                                                                                          
20210629 195716 moode.php: MPD connect failed: cmd=(playlist)                                                                                                                                                      
20210629 195721 worker: Job upnpsvc                                                                                                                                                                                
20210629 195851 moode.php: MPD connect failed: cmd=(playlist)                                                                                                                                                      
20210629 195853 watchdog: Error: MPD restarted (check syslog for errors)                                                                                                                                          
20210629 195909 worker: Job upnpsvc                                                                                                                                                                                
20210629 200043 moode.php: MPD connect failed: cmd=(playlist)                                                                                                                                                      
20210629 200043 watchdog: Error: MPD restarted (check syslog for errors)                                                                                                                                          
20210629 200236 worker: Job upnpsvc                                                                                                                                                                                
20210629 200613 moode.php: MPD connect failed: cmd=(playlist)                                                                                                                                                      
20210629 200613 watchdog: Error: MPD restarted (check syslog for errors)                                                                                                                                          

When the UPnP renderer fails, I also observed the following error message, see attached.

I'm going to continue testing but if there's any suggestions, please let me know.

[the_bertrum]

Are you using OpenHome or AV?

[TheOldPresbyope]

@TRiNGT3

I am not a regular UPnP user but in a quick sanity check with stock moOde 7.3.0 on a WiFi-connected RPi4B outputting audio via a USB-BT transceiver to Sennheiser earphones and C-DSP set to 'flat' configuration:

1. UPnP renderer enabled in UPnP-A/V service mode.

Using mconnectPlayerLite on my iPad, I can select, play, and stop a track, jump among tracks, etc., without a problem.

2. UPnP renderer enabled in OpenHome service mode.

Using LUMIN on my iPad, I can do the same.


Certainly, this is not a definitive test but I can do no more ATM.

Good luck.

Regards,
Kent

[the_bertrum]

I concur with the findings of @TheOldPresbyope, I've tested quite extensively with the UPnP renderers and various EQ functions on all the 7 series releases (test release and general release), they all have been working well when released into the wild.
I have seen problems of this kind when the moOde renderer has changed (upgrade, switch UPnP type, just rebooted even) and a control point that was attached previously seems to need refreshing. In some cases normal service is only resumed after the control point, moOde and the router between have all been rebooted.