swyh-rs: Autoresume not working with BubbleUPNP and Nest Audio

I use this chain to play audio:

Audio Player -> VB-Audio Virtual HiFi Cable -> SWYH-RS -> BubbleUPNP (DLNA mode) -> Google Nest Audio Stereo Pair

When swyh-rs is started, it works correctly and audio plays just like it should. However, after about ~20 minutes of having no music playing in my audio player, something breaks and there will be no more sound coming from my speakers. In fact, the debug log generates no entry at all for when audio is resumed after that time, so I added something manually.

swyh-rs is configured like so:

• Autoresume is enabled
• Autoreconnect is enabled
• SSDP is at 10 minutes, but same issue existed with it at 1 minute
• Disable Chunked TransferEncoding is disabled
• Source is Hi-Fi Cable Input
• Output is BubbleUPNP

This is the debug log, generated with the standard version and log level set to debug.

17:27:48 [DEBUG] (1) swyh_rs::utils::audiodevices: Supported hosts:
  [Wasapi]
17:27:48 [DEBUG] (1) swyh_rs::utils::audiodevices: Available hosts:
  [Wasapi]
17:27:48 [DEBUG] (1) swyh_rs::utils::audiodevices: WASAPI
17:27:48 [DEBUG] (1) swyh_rs::utils::audiodevices:   Default Output Device:
    Some("Soundkarte (ASUS Xonar D2X Audio Device)")
17:27:48 [DEBUG] (1) swyh_rs::utils::audiodevices:   Devices: 
17:27:48 [DEBUG] (1) swyh_rs::utils::audiodevices:   1. "Hi-Fi Cable Input (VB-Audio Hi-Fi Cable)"
17:27:48 [DEBUG] (1) swyh_rs::utils::audiodevices:     All supported output stream configs:
17:27:48 [DEBUG] (1) swyh_rs::utils::audiodevices:       1.1. SupportedStreamConfigRange { channels: 2, min_sample_rate: SampleRate(44100), max_sample_rate: SampleRate(44100), buffer_size: Unknown, sample_format: F32 }
17:27:48 [DEBUG] (1) swyh_rs::utils::audiodevices:     Default output stream config:
      SupportedStreamConfig { channels: 2, sample_rate: SampleRate(44100), buffer_size: Unknown, sample_format: F32 }
17:27:48 [DEBUG] (1) swyh_rs::utils::audiodevices:   2. "Soundkarte (ASUS Xonar D2X Audio Device)"
17:27:48 [DEBUG] (1) swyh_rs::utils::audiodevices:     All supported output stream configs:
17:27:48 [DEBUG] (1) swyh_rs::utils::audiodevices:       2.1. SupportedStreamConfigRange { channels: 2, min_sample_rate: SampleRate(96000), max_sample_rate: SampleRate(96000), buffer_size: Unknown, sample_format: F32 }
17:27:48 [DEBUG] (1) swyh_rs::utils::audiodevices:     Default output stream config:
      SupportedStreamConfig { channels: 2, sample_rate: SampleRate(96000), buffer_size: Unknown, sample_format: F32 }
17:27:48 [DEBUG] (1) swyh_rs::utils::audiodevices:   3. "Mikrofon (ASUS Xonar D2X Audio Device)"
17:27:48 [DEBUG] (1) swyh_rs::utils::audiodevices:   4. "Wave (ASUS Xonar D2X Audio Device)"
17:27:48 [DEBUG] (1) swyh_rs::utils::audiodevices:   5. "Hi-Fi Cable Output (VB-Audio Hi-Fi Cable)"
17:27:48 [DEBUG] (1) swyh_rs::utils::audiodevices:   6. "Mikrofon (Steam Streaming Microphone)"
17:27:48 [DEBUG] (1) swyh_rs::utils::audiodevices:   7. "SPDIF In (ASUS Xonar D2X Audio Device)"
17:27:48 [DEBUG] (1) swyh_rs::utils::audiodevices:   8. "Stereo Mix (ASUS Xonar D2X Audio Device)"
17:27:48 [INFO] Selected audio source: Hi-Fi Cable Input (VB-Audio Hi-Fi Cable)
17:27:48 [INFO] tb_log: Setup audio sources
17:27:48 [INFO] tb_log: Now running at ABOVE_NORMAL_PRIORITY_CLASS
17:27:48 [DEBUG] (1) swyh_rs: Try capturing system audio
17:27:48 [INFO] tb_log: Capturing audio from: Hi-Fi Cable Input (VB-Audio Hi-Fi Cable)
17:27:48 [INFO] tb_log: Default audio SupportedStreamConfig { channels: 2, sample_rate: SampleRate(44100), buffer_size: Unknown, sample_format: F32 }
17:27:48 [INFO] tb_log: Starting SSDP discovery
17:27:48 [DEBUG] (4) swyh_rs::openhome::avmedia: SSDP discovery started
17:27:48 [INFO] tb_log: The streaming server is listening on http://192.168.1.99:5901/stream/swyh.wav
17:27:48 [INFO] tb_log: Sample rate: 44100, sample format: audio/l16 (PCM)
17:27:48 [DEBUG] (5) tiny_http: Server listening on 192.168.1.99:5901
17:27:48 [DEBUG] (6) tiny_http: Running accept thread
17:27:51 [DEBUG] (4) swyh_rs::openhome::avmedia: UDP response at 2631 from 192.168.1.99:50826: 
HTTP/1.1 200 OK
Ext: 
St: urn:schemas-upnp-org:service:RenderingControl:1
Server: Windows10/10.0 UPnP/1.0 BubbleUPnPServer/0.9-update38
Usn: uuid:a650210f-9d3e-1235-0000-00004d059e7e::urn:schemas-upnp-org:service:RenderingControl:1
Cache-control: max-age=1800
Location: http://192.168.1.99:49836/dev/a650210f-9d3e-1235-0000-00004d059e7e/desc.xml


17:27:51 [DEBUG] (4) swyh_rs::openhome::avmedia: SSDP Discovery: AV renderer: http://192.168.1.99:49836/dev/a650210f-9d3e-1235-0000-00004d059e7e/desc.xml
17:27:51 [INFO] SSDP discovery: new Renderer found at : http://192.168.1.99:49836/dev/a650210f-9d3e-1235-0000-00004d059e7e/desc.xml
17:27:51 [DEBUG] (4) swyh_rs::openhome::avmedia: Getting new renderer descriptions
17:27:51 [DEBUG] (4) swyh_rs::openhome::avmedia: Get service description for http://192.168.1.99:49836/dev/a650210f-9d3e-1235-0000-00004d059e7e/desc.xml
17:27:51 [INFO] sending request GET http://192.168.1.99:49836/dev/a650210f-9d3e-1235-0000-00004d059e7e/desc.xml
17:27:51 [DEBUG] (4) ureq::unit: writing prelude: GET /dev/a650210f-9d3e-1235-0000-00004d059e7e/desc.xml HTTP/1.1
Host: 192.168.1.99:49836
Accept: */*
User-Agent: swyh-rs-Rust
Content-Type: text/xml
Content-Length: 0


17:27:51 [DEBUG] (4) ureq::unit: response 200 to GET http://192.168.1.99:49836/dev/a650210f-9d3e-1235-0000-00004d059e7e/desc.xml
17:27:51 [DEBUG] (4) swyh_rs::openhome::avmedia: Service description:
17:27:51 [DEBUG] (4) swyh_rs::openhome::avmedia: <?xml version="1.0" encoding="utf-8" standalone="yes"?><root xmlns="urn:schemas-upnp-org:device-1-0"><specVersion><major>1</major><minor>0</minor></specVersion><device><deviceType>urn:schemas-upnp-org:device:MediaRenderer:1</deviceType><UDN>uuid:a650210f-9d3e-1235-0000-00004d059e7e</UDN><friendlyName>Nest Audios (DLNA)</friendlyName><manufacturer>Bubblesoft</manufacturer><manufacturerURL>http://forum.xda-developers.com/showthread.php?t=1118891</manufacturerURL><modelDescription>BubbleUPnP Google Cast DLNA renderer</modelDescription><modelName>BubbleUPnP Google Cast DLNA renderer</modelName><modelNumber>0.9-update38</modelNumber><modelURL></modelURL><serialNumber>0.9-update38</serialNumber><presentationURL>http://192.168.1.99:58050</presentationURL><dlna:X_DLNADOC xmlns:dlna="urn:schemas-dlna-org:device-1-0">DMR-1.50</dlna:X_DLNADOC><iconList><icon><mimetype>image/png</mimetype><width>98</width><height>55</height><depth>32</depth><url>/dev/a650210f-9d3e-1235-0000-00004d059e7e/icon.png</url></icon></iconList><serviceList><service><serviceType>urn:schemas-upnp-org:service:AVTransport:1</serviceType><serviceId>urn:upnp-org:serviceId:AVTransport</serviceId><controlURL>/dev/a650210f-9d3e-1235-0000-00004d059e7e/svc/upnp-org/AVTransport/action</controlURL><eventSubURL>/dev/a650210f-9d3e-1235-0000-00004d059e7e/svc/upnp-org/AVTransport/event</eventSubURL><SCPDURL>/dev/a650210f-9d3e-1235-0000-00004d059e7e/svc/upnp-org/AVTransport/desc.xml</SCPDURL></service><service><serviceType>urn:schemas-upnp-org:service:RenderingControl:1</serviceType><serviceId>urn:upnp-org:serviceId:RenderingControl</serviceId><controlURL>/dev/a650210f-9d3e-1235-0000-00004d059e7e/svc/upnp-org/RenderingControl/action</controlURL><eventSubURL>/dev/a650210f-9d3e-1235-0000-00004d059e7e/svc/upnp-org/RenderingControl/event</eventSubURL><SCPDURL>/dev/a650210f-9d3e-1235-0000-00004d059e7e/svc/upnp-org/RenderingControl/desc.xml</SCPDURL></service><service><serviceType>urn:schemas-upnp-org:service:ConnectionManager:1</serviceType><serviceId>urn:upnp-org:serviceId:ConnectionManager</serviceId><controlURL>/dev/a650210f-9d3e-1235-0000-00004d059e7e/svc/upnp-org/ConnectionManager/action</controlURL><eventSubURL>/dev/a650210f-9d3e-1235-0000-00004d059e7e/svc/upnp-org/ConnectionManager/event</eventSubURL><SCPDURL>/dev/a650210f-9d3e-1235-0000-00004d059e7e/svc/upnp-org/ConnectionManager/desc.xml</SCPDURL></service></serviceList></device></root>
17:27:51 [DEBUG] (4) swyh_rs::openhome::avmedia: Renderer Nest Audios (DLNA) BubbleUPnP Google Cast DLNA renderer ip 192.168.1.99 at urlbase http://192.168.1.99:49836/ has 3 services
17:27:51 [DEBUG] (4) swyh_rs::openhome::avmedia:   => OpenHome Playlist control url: '', AvTransport url: '/dev/a650210f-9d3e-1235-0000-00004d059e7e/svc/upnp-org/AVTransport/action'
17:27:51 [DEBUG] (4) swyh_rs::openhome::avmedia: .. urn:schemas-upnp-org:service:AVTransport:1 urn:upnp-org:serviceId:AVTransport /dev/a650210f-9d3e-1235-0000-00004d059e7e/svc/upnp-org/AVTransport/action
17:27:51 [DEBUG] (4) swyh_rs::openhome::avmedia: .. urn:schemas-upnp-org:service:RenderingControl:1 urn:upnp-org:serviceId:RenderingControl /dev/a650210f-9d3e-1235-0000-00004d059e7e/svc/upnp-org/RenderingControl/action
17:27:51 [DEBUG] (4) swyh_rs::openhome::avmedia: .. urn:schemas-upnp-org:service:ConnectionManager:1 urn:upnp-org:serviceId:ConnectionManager /dev/a650210f-9d3e-1235-0000-00004d059e7e/svc/upnp-org/ConnectionManager/action
17:27:51 [DEBUG] (4) swyh_rs::openhome::avmedia: SSDP discovery complete
17:27:51 [INFO] Found new renderer Nest Audios (DLNA) BubbleUPnP Google Cast DLNA renderer  at 192.168.1.99
17:27:51 [DEBUG] (1) swyh_rs: Pushed renderer #0 BubbleUPnP Google Cast DLNA renderer Nest Audios (DLNA), state = ON
17:27:51 [INFO] tb_log: AV Stop playing on Nest Audios (DLNA) host=192.168.1.99 port=49836
17:27:51 [DEBUG] (1) swyh_rs::openhome::avmedia: url: http://192.168.1.99:49836/dev/a650210f-9d3e-1235-0000-00004d059e7e/svc/upnp-org/AVTransport/action,
=>SOAP Action: urn:schemas-upnp-org:service:AVTransport:1#Stop,
=>SOAP xml: 
<?xml version="1.0" encoding="utf-8"?><s:Envelope s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/" xmlns:s="http://schemas.xmlsoap.org/soap/envelope/"><s:Body><u:Stop xmlns:u="urn:schemas-upnp-org:service:AVTransport:1"><InstanceID>0</InstanceID></u:Stop></s:Body></s:Envelope>
17:27:51 [INFO] sending request POST http://192.168.1.99:49836/dev/a650210f-9d3e-1235-0000-00004d059e7e/svc/upnp-org/AVTransport/action
17:27:51 [DEBUG] (1) ureq::unit: writing prelude: POST /dev/a650210f-9d3e-1235-0000-00004d059e7e/svc/upnp-org/AVTransport/action HTTP/1.1
Host: 192.168.1.99:49836
Connection: close
User-Agent: swyh-rs-Rust/0.x
Accept: */*
SOAPAction: "urn:schemas-upnp-org:service:AVTransport:1#Stop"
Content-Type: text/xml; charset="utf-8"
Content-Length: 288


17:27:51 [DEBUG] (1) ureq::unit: response 200 to POST http://192.168.1.99:49836/dev/a650210f-9d3e-1235-0000-00004d059e7e/svc/upnp-org/AVTransport/action
17:27:51 [DEBUG] (1) swyh_rs::openhome::avmedia: <=SOAP response: <?xml version="1.0" encoding="utf-8" standalone="yes"?><s:Envelope s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/" xmlns:s="http://schemas.xmlsoap.org/soap/envelope/"><s:Body><u:StopResponse xmlns:u="urn:schemas-upnp-org:service:AVTransport:1"/></s:Body></s:Envelope>

17:27:51 [INFO] tb_log: AV Start playing on Nest Audios (DLNA) host=192.168.1.99 port=49836 from 192.168.1.99 using AvTransport Play
17:27:51 [DEBUG] (1) swyh_rs::openhome::avmedia: AvTransport server URL: http://192.168.1.99:5901/stream/swyh.wav
17:27:51 [DEBUG] (1) swyh_rs::openhome::avmedia: url: http://192.168.1.99:49836/dev/a650210f-9d3e-1235-0000-00004d059e7e/svc/upnp-org/AVTransport/action,
=>SOAP Action: urn:schemas-upnp-org:service:AVTransport:1#SetAVTransportURI,
=>SOAP xml: 
<?xml version="1.0" encoding="utf-8"?><s:Envelope xmlns:s="http://schemas.xmlsoap.org/soap/envelope/" s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/"><s:Body><u:SetAVTransportURI xmlns:u="urn:schemas-upnp-org:service:AVTransport:1"><InstanceID>0</InstanceID><CurrentURI>http://192.168.1.99:5901/stream/swyh.wav</CurrentURI><CurrentURIMetaData>&lt;DIDL-Lite xmlns=&quot;urn:schemas-upnp-org:metadata-1-0/DIDL-Lite/&quot; xmlns:dc=&quot;http://purl.org/dc/elements/1.1/&quot; xmlns:upnp=&quot;urn:schemas-upnp-org:metadata-1-0/upnp/&quot;&gt;&lt;item id=&quot;1&quot; parentID=&quot;0&quot; restricted=&quot;0&quot;&gt;&lt;dc:title&gt;swyh-rs&lt;/dc:title&gt;&lt;res bitsPerSample=&quot;16&quot; nrAudioChannels=&quot;2&quot; protocolInfo=&quot;http-get:*:audio/l16;rate=44100;channels=2:DLNA.ORG_PN=LPCM&quot; sampleFrequency=&quot;44100&quot; duration=&quot;0&quot; &gt;http://192.168.1.99:5901/stream/swyh.wav&lt;/res&gt;&lt;upnp:class&gt;object.item.audioItem.musicTrack&lt;/upnp:class&gt;&lt;/item&gt;&lt;/DIDL-Lite&gt;</CurrentURIMetaData></u:SetAVTransportURI></s:Body></s:Envelope>
17:27:51 [INFO] sending request POST http://192.168.1.99:49836/dev/a650210f-9d3e-1235-0000-00004d059e7e/svc/upnp-org/AVTransport/action
17:27:51 [DEBUG] (1) ureq::unit: writing prelude: POST /dev/a650210f-9d3e-1235-0000-00004d059e7e/svc/upnp-org/AVTransport/action HTTP/1.1
Host: 192.168.1.99:49836
Connection: close
User-Agent: swyh-rs-Rust/0.x
Accept: */*
SOAPAction: "urn:schemas-upnp-org:service:AVTransport:1#SetAVTransportURI"
Content-Type: text/xml; charset="utf-8"
Content-Length: 1099


17:27:51 [DEBUG] (1) ureq::unit: response 200 to POST http://192.168.1.99:49836/dev/a650210f-9d3e-1235-0000-00004d059e7e/svc/upnp-org/AVTransport/action
17:27:51 [DEBUG] (1) swyh_rs::openhome::avmedia: <=SOAP response: <?xml version="1.0" encoding="utf-8" standalone="yes"?><s:Envelope s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/" xmlns:s="http://schemas.xmlsoap.org/soap/envelope/"><s:Body><u:SetAVTransportURIResponse xmlns:u="urn:schemas-upnp-org:service:AVTransport:1"/></s:Body></s:Envelope>

17:27:51 [DEBUG] (1) swyh_rs::openhome::avmedia: url: http://192.168.1.99:49836/dev/a650210f-9d3e-1235-0000-00004d059e7e/svc/upnp-org/AVTransport/action,
=>SOAP Action: urn:schemas-upnp-org:service:AVTransport:1#Play,
=>SOAP xml: 
<?xml version="1.0" encoding="utf-8"?><s:Envelope s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/" xmlns:s="http://schemas.xmlsoap.org/soap/envelope/"><s:Body><u:Play xmlns:u="urn:schemas-upnp-org:service:AVTransport:1"><InstanceID>0</InstanceID><Speed>1</Speed></u:Play></s:Body></s:Envelope>
17:27:51 [INFO] sending request POST http://192.168.1.99:49836/dev/a650210f-9d3e-1235-0000-00004d059e7e/svc/upnp-org/AVTransport/action
17:27:51 [DEBUG] (1) ureq::unit: writing prelude: POST /dev/a650210f-9d3e-1235-0000-00004d059e7e/svc/upnp-org/AVTransport/action HTTP/1.1
Host: 192.168.1.99:49836
Connection: close
User-Agent: swyh-rs-Rust/0.x
Accept: */*
SOAPAction: "urn:schemas-upnp-org:service:AVTransport:1#Play"
Content-Type: text/xml; charset="utf-8"
Content-Length: 304


17:27:51 [DEBUG] (1) ureq::unit: response 200 to POST http://192.168.1.99:49836/dev/a650210f-9d3e-1235-0000-00004d059e7e/svc/upnp-org/AVTransport/action
17:27:51 [DEBUG] (1) swyh_rs::openhome::avmedia: <=SOAP response: <?xml version="1.0" encoding="utf-8" standalone="yes"?><s:Envelope s:encodingStyle="http://schemas.xmlsoap.org/soap/encoding/" xmlns:s="http://schemas.xmlsoap.org/soap/envelope/"><s:Body><u:PlayResponse xmlns:u="urn:schemas-upnp-org:service:AVTransport:1"/></s:Body></s:Envelope>

17:27:52 [INFO] tb_log: Received request /stream/swyh.wav from 192.168.1.99:55306
17:27:52 [DEBUG] (8) swyh_rs: Now have 1 streaming clients
17:28:12 [INFO] tb_log: The wave_reader is now receiving samples
17:37:51 [DEBUG] (4) swyh_rs::openhome::avmedia: SSDP discovery started
17:37:53 [DEBUG] (4) swyh_rs::openhome::avmedia: UDP response at 2181 from 192.168.1.99:50826: 
HTTP/1.1 200 OK
Ext: 
St: urn:schemas-upnp-org:service:RenderingControl:1
Server: Windows10/10.0 UPnP/1.0 BubbleUPnPServer/0.9-update38
Usn: uuid:a650210f-9d3e-1235-0000-00004d059e7e::urn:schemas-upnp-org:service:RenderingControl:1
Cache-control: max-age=1800
Location: http://192.168.1.99:49836/dev/a650210f-9d3e-1235-0000-00004d059e7e/desc.xml


17:37:53 [DEBUG] (4) swyh_rs::openhome::avmedia: SSDP Discovery: AV renderer: http://192.168.1.99:49836/dev/a650210f-9d3e-1235-0000-00004d059e7e/desc.xml
17:37:54 [INFO] SSDP discovery: Skipping known Renderer at http://192.168.1.99:49836/dev/a650210f-9d3e-1235-0000-00004d059e7e/desc.xml
17:37:54 [DEBUG] (4) swyh_rs::openhome::avmedia: Getting new renderer descriptions
17:37:54 [DEBUG] (4) swyh_rs::openhome::avmedia: SSDP discovery complete
17:47:54 [DEBUG] (4) swyh_rs::openhome::avmedia: SSDP discovery started
17:47:56 [DEBUG] (4) swyh_rs::openhome::avmedia: UDP response at 1845 from 192.168.1.99:50826: 
HTTP/1.1 200 OK
Ext: 
St: urn:schemas-upnp-org:service:RenderingControl:1
Server: Windows10/10.0 UPnP/1.0 BubbleUPnPServer/0.9-update38
Usn: uuid:a650210f-9d3e-1235-0000-00004d059e7e::urn:schemas-upnp-org:service:RenderingControl:1
Cache-control: max-age=1800
Location: http://192.168.1.99:49836/dev/a650210f-9d3e-1235-0000-00004d059e7e/desc.xml


17:47:56 [DEBUG] (4) swyh_rs::openhome::avmedia: SSDP Discovery: AV renderer: http://192.168.1.99:49836/dev/a650210f-9d3e-1235-0000-00004d059e7e/desc.xml
17:47:57 [INFO] SSDP discovery: Skipping known Renderer at http://192.168.1.99:49836/dev/a650210f-9d3e-1235-0000-00004d059e7e/desc.xml
17:47:57 [DEBUG] (4) swyh_rs::openhome::avmedia: Getting new renderer descriptions
17:47:57 [DEBUG] (4) swyh_rs::openhome::avmedia: SSDP discovery complete

------------------------
Manual entry - music resumes playing around 17:57:00 but log generates no entry for that. No sound is coming from the speakers.
------------------------
17:57:22

Also, I noticed the time in the logs is off by 1 hour, but that isn’t really a problem I guess 😃