Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Playing music on DLNA device stopped and device got lost #2883

Open
1 task done
Panoramiac opened this issue Sep 7, 2024 · 12 comments
Open
1 task done

Playing music on DLNA device stopped and device got lost #2883

Panoramiac opened this issue Sep 7, 2024 · 12 comments
Labels
bug Something isn't working DLNA/UPNP

Comments

@Panoramiac
Copy link

Panoramiac commented Sep 7, 2024

What version of Music Assistant has the issue?

2.2.3

What version of the Home Assistant Integration have you got installed?

2024.8.1

Have you tried everything in the Troubleshooting FAQ and reviewed the Open and Closed Issues and Discussions to resolve this yourself?

  • Yes

The problem

We were listening to mp3s from local network share (could be mixed with YouTube music) when the music stopped. The receiver showed then a loading symbol.

In MA the receiver and the Playlist was not available any more.
The player settings showed a hour glass symbol.
Screenshot_20240907_100206_Home Assistant

How to reproduce

The DLNA player was lost some times now. To get it working, disabling and enabling the player device got it ecognised in MA again. This time the receiver must be restarted to get ist working again.

Music Providers

Local network share from Synology Smb share.

Player Providers

UPnP DLNA Denon Receiver AVR-X1300W

Full log output

I still can not download the full log. Here is the important part from HA:
2024-09-06 23:12:42.285 INFO (MainThread) [music_assistant.metadata] Metadata scanner finished.
2024-09-06 23:46:04.533 WARNING (MainThread) [async_upnp_client.profiles.profile] Failed (re-)subscribing to: uuid:16eb8363-d9b3-1696-b976-b6ad6bbac01f, reason: UpnpConnectionError('ClientConnectorError(ConnectionKey(host='192.168.178.22', port=8080, is_ssl=False, ssl=True, proxy=None, proxy_auth=None, proxy_headers_hash=None), ConnectionRefusedError(111, "Connect call failed ('192.168.178.22', 8080)"))', None)
2024-09-06 23:46:04.553 WARNING (MainThread) [async_upnp_client.profiles.profile] Failed (re-)subscribing to: uuid:9c10d87b-80ae-152f-b58c-294088fe2ca9, reason: UpnpConnectionError('ClientConnectorError(ConnectionKey(host='192.168.178.22', port=8080, is_ssl=False, ssl=True, proxy=None, proxy_auth=None, proxy_headers_hash=None), ConnectionRefusedError(111, "Connect call failed ('192.168.178.22', 8080)"))', None)
2024-09-06 23:46:04.573 WARNING (MainThread) [async_upnp_client.profiles.profile] Failed (re-)subscribing to: uuid:ed376107-0417-195d-a40e-6c96c1247718, reason: UpnpConnectionError('ClientConnectorError(ConnectionKey(host='192.168.178.22', port=8080, is_ssl=False, ssl=True, proxy=None, proxy_auth=None, proxy_headers_hash=None), ConnectionRefusedError(111, "Connect call failed ('192.168.178.22', 8080)"))', None)
2024-09-07 02:00:11.221 INFO (MainThread) [music_assistant.music] Sync task for Music Assistant completed
2024-09-07 02:00:23.065 INFO (MainThread) [music_assistant.music] Sync task for Filesystem (remote share) completed
2024-09-07 02:00:28.883 INFO (MainThread) [music_assistant.music] Sync task for YouTube Music completed
2024-09-07 02:00:28.884 INFO (MainThread) [music_assistant.metadata] Starting metadata scanner
2024-09-07 02:12:07.734 INFO (MainThread) [music_assistant.metadata] Metadata scanner finished.
2024-09-07 05:00:11.116 INFO (MainThread) [music_assistant.music] Sync task for Music Assistant completed
2024-09-07 05:00:23.845 INFO (MainThread) [music_assistant.music] Sync task for Filesystem (remote share) completed
2024-09-07 05:00:32.008 INFO (MainThread) [music_assistant.music] Sync task for YouTube Music completed
2024-09-07 05:00:32.009 INFO (MainThread) [music_assistant.metadata] Starting metadata scanner
2024-09-07 05:12:45.100 INFO (MainThread) [music_assistant.metadata] Metadata scanner finished.
2024-09-07 08:00:11.256 INFO (MainThread) [music_assistant.music] Sync task for Music Assistant completed
2024-09-07 08:00:23.925 INFO (MainThread) [music_assistant.music] Sync task for Filesystem (remote share) completed
2024-09-07 08:00:30.236 INFO (MainThread) [music_assistant.music] Sync task for YouTube Music completed
2024-09-07 08:00:30.238 INFO (MainThread) [music_assistant.metadata] Starting metadata scanner
2024-09-07 08:12:38.984 INFO (MainThread) [music_assistant.metadata] Metadata scanner finished.
2024-09-07 08:13:29.575 ERROR (MainThread) [music_assistant.dlna] Error during call cmd_stop: 'Error during async_call(), action: Stop, status: 500, upnp error: 701 (Transition not available)'
2024-09-07 09:46:17.084 ERROR (MainThread) [music_assistant] Error doing task: Task exception was never retrieved
Traceback (most recent call last):
File "/usr/local/lib/python3.12/site-packages/async_upnp_client/aiohttp.py", line 216, in _async_http_request
async with self._session.request(
File "/usr/local/lib/python3.12/site-packages/aiohttp/client.py", line 1353, in aenter
self._resp = await self._coro
^^^^^^^^^^^^^^^^
File "/usr/local/lib/python3.12/site-packages/aiohttp/client.py", line 684, in _request
await resp.start(conn)
File "/usr/local/lib/python3.12/site-packages/aiohttp/client_reqrep.py", line 994, in start
with self._timer:
File "/usr/local/lib/python3.12/site-packages/aiohttp/helpers.py", line 713, in exit
raise asyncio.TimeoutError from None
TimeoutError

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
File "/usr/local/lib/python3.12/site-packages/async_upnp_client/aiohttp.py", line 184, in async_http_request
return await self._async_http_request(http_request)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/local/lib/python3.12/site-packages/async_upnp_client/aiohttp.py", line 241, in _async_http_request
raise UpnpConnectionTimeoutError(repr(err)) from err
async_upnp_client.exceptions.UpnpConnectionTimeoutError: [Errno TimeoutError()] None

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
File "/usr/local/lib/python3.12/site-packages/music_assistant/server/providers/dlna/init.py", line 416, in poll_player
await dlna_player.device.async_update(do_ping=do_ping)
File "/usr/local/lib/python3.12/site-packages/async_upnp_client/profiles/dlna.py", line 350, in async_update
await self._async_poll_state_variables(
File "/usr/local/lib/python3.12/site-packages/async_upnp_client/profiles/profile.py", line 443, in _async_poll_state_variables
result = await action.async_call(**in_args)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/local/lib/python3.12/site-packages/async_upnp_client/client.py", line 719, in async_call
bare_response = await self.service.requester.async_http_request(request)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/local/lib/python3.12/site-packages/async_upnp_client/aiohttp.py", line 186, in async_http_request
raise UpnpConnectionError(repr(err)) from err
async_upnp_client.exceptions.UpnpConnectionError: ("UpnpConnectionTimeoutError('TimeoutError()', None)", None)

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
File "/usr/local/lib/python3.12/site-packages/music_assistant/server/controllers/players.py", line 676, in play_media
await player_prov.play_media(
File "/usr/local/lib/python3.12/site-packages/music_assistant/server/providers/dlna/init.py", line 151, in wrapper
return await func(self, *args, **kwargs)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/local/lib/python3.12/site-packages/music_assistant/server/providers/dlna/init.py", line 356, in play_media
await self.poll_player(dlna_player.udn)
File "/usr/local/lib/python3.12/site-packages/music_assistant/server/providers/dlna/init.py", line 421, in poll_player
raise PlayerUnavailableError from err
music_assistant.common.models.errors.PlayerUnavailableError

Additional information

I assume the issue to be on MA side, as I would not expect to loose the Playlist when the receiver had a problem.

What version of Home Assistant Core are your running

2024.9. 0

What type of installation are you running?

Home Assistant OS

On what type of hardware are you running?

Raspberry Pi

@marcelveldt
Copy link
Member

The connection gets lots to the receiver as you can see in your log. So this is more likely an issue with the receiver or the network. Are multiple services connecting to the receiver perhaps ?

PS: Next time attach a log as file instead of pasting a large chunk of logs in the issue reports, it makes the issue report so much harder to read that way. Thanks!

@drjjr2
Copy link

drjjr2 commented Sep 13, 2024

I am having issues with playback stopping on a DLNA player while playing a Spotify playlist. There is nothing in the logs to indicate an error.
2.3.0b22
HA 2024.8.3

music-assistant.log

@marcelveldt
Copy link
Member

I am having issues with playback stopping on a DLNA player while playing a Spotify playlist. There is nothing in the logs to indicate an error. 2.3.0b22 HA 2024.8.3

music-assistant.log

this should be resolved in 2.2.5 (or 2.3.0b24 if you're running the beta), please test it out and let us know.

@OzGav OzGav added bug Something isn't working Fix to be Confirmed and removed More info triage labels Sep 16, 2024
@OzGav
Copy link
Contributor

OzGav commented Sep 17, 2024

@panoramia please confirm this is fixed with beta 25

@Panoramiac
Copy link
Author

Panoramiac commented Sep 18, 2024

@panoramia please confirm this is fixed with beta 25

Do you mean my original issue or the issue mentioned by @drjjr2 with the Spotify playlist? I can test it later this week with the beta. I have 2.2.5 installed, as I understand, this should be fixed in this release. The beta is not required, right (in this case I would need to figure out how to install the beta in Home Assistant)?

@drjjr2
Copy link

drjjr2 commented Sep 18, 2024

I was able to workaround my issue on b24 by enabling queue flow mode on the Denon. If I disable queue flow mode, it still stops after 2 songs, even on the latest beta.

@OzGav
Copy link
Contributor

OzGav commented Sep 18, 2024

@drjjr2 Enabling flow mode is not a work around it is the solution. That is why the option is there

@Panoramiac The original issue please. That is what we need to focus on here

@drjjr2
Copy link

drjjr2 commented Sep 18, 2024

@drjjr2 Enabling flow mode is not a work around it is the solution. That is why the option is there

@Panoramiac The original issue please. That is what we need to focus on here

Can't disagree that it solved my issue. But it was not necessary for me to enable queue flow mode until recently.

@OzGav
Copy link
Contributor

OzGav commented Sep 18, 2024

Things have changed to increase the support to more devices.

@Panoramiac
Copy link
Author

Panoramiac commented Sep 22, 2024

I had time today to test the fix as I understand the Flow mode by default. When enabled, the Denon receiver will not start playing and is lost in MA. When I disable the flow mode, the Denon receiver plays the music for some time and stops again (like the original description). Tested with 2.2 .5. I could download the log and attach it.
MusicAssistant.log

Edit: I just checked the Home Assistant integration page for my Denon receiver:

If you have something else using the IP controller for your Denon AVR 3808CI, such as your URC controller, it will not work! There is either a bug or security issue with some models where only one device could be controlling the IP functionality.
https://www.home-assistant.io/integrations/denonavr/

The media stream should not be "IP-control" right? Or is the volume control IP control? In this case, the HA integration could interrupt the stream.
Edit 2: The HA integration is not installed. The Album I was using for testing yesterday was from YouTube Music. I did another test this morning. Two tracks of this alum were added to my library. When the third track, which is not part of my library should be played, the receiver was lost in an endless loop. I am now testing with a local mp3 album.

Edit3: I can confirm: that the flow mode does not work with the Denon AVR-X1300W using local files or YouTube music as a source.
MusicAssistant2.log

Edit 4: Listening to a complete local Album worked, the only weird thing was the last track, played in an endless loop (#2942). The log is not showing anything about it. The MA GUI showed all tracks in the playlist and 0 in the played list. I continue to observe it. Currently, this setting is active, but flow mode is disabled (not sure if this is used, even if it is greyed out when flow is disabled):
image

Edit 5: I noted, that the playlist in MA is not updating anymore. The played track is not moved to the played tracklist. In this screenshot "Back in Town" is currently played, Choreomania should have been moved to the played tracklist (#2940):
image

@Panoramiac
Copy link
Author

Panoramiac commented Sep 26, 2024

I tested today with 2.2.6 and the music stopped after the first track:

  1. Receiver was on standby (network control setting in standby activated)
  2. Selected an album and start playing in MA
  3. The receiver turned on and did not switch directly to the Media Stream
  4. Volume control was working, pressed play again
  5. The receiver switched to the Media stream and started playing
  6. After the first track, it stopped. The track is also not moved to the played queue
  7. Restart with the Play button is possible. The receiver was not lost, so this might be a new issue and the original problem is solved
  8. Pressing the next button starts playing the next track (The Beginning)
  9. After this track, the next track is started as expected (Everything is here and nothing is lost), but MA GUI and receiver display still shows "The Beginning", which is not moved to the played list
    image

MusicAssistant4.log

@Panoramiac
Copy link
Author

Panoramiac commented Nov 16, 2024

I tested today with 2024.11.4 (2.3.2). First I detected that the DLNA player was not ready, so I had to restart the service provider to get them working. We now have a new TV (Philips 55OLED759), which is also detected as DLNA player and was also not available in MA. When the Denon receiver was detected, I switched off the Flow Mode as this was not working at all with the Denon receiver. Then I started an album that played the first track and switched to the next two tracks as it should, the third track was then repeated in a loop. The playing overview in MA was directly lost, including the TV DLNA player:
image

Seems that the DLNA service has a basic issue, I would expect when there is an issue with one DLNA device also only this device might get lost, but not all of them.

In the log file I see the following errors

DLNA players not available

2024-11-16 11:48:38.607 ERROR (MainThread) [music_assistant.webserver] Error handling message: config/players/save: 'NoneType' object has no attribute 'has_volume_level'

Restart of DLNA service provider

click to expand
2024-11-16 11:49:41.277 WARNING (MainThread) [music_assistant.players] Error while requesting latest state from player 55OLED759/12(192.168.178.86): 'uuid:ac521fc4-1dd3-11b2-9111-d21d11b6dc4d'
2024-11-16 11:49:43.280 WARNING (MainThread) [music_assistant.players] Error while requesting latest state from player Denon AVR-X1300W: 'uuid:5f9ec1b3-ff59-19bb-8530-0005cd91b994'
2024-11-16 11:50:11.016 INFO (MainThread) [music_assistant.players] Player removed: Denon AVR-X1300W
2024-11-16 11:50:11.018 INFO (MainThread) [music_assistant.players] Player removed: 55OLED759/12(192.168.178.86)
2024-11-16 11:50:13.620 INFO (MainThread) [music_assistant] Loaded player provider UPnP/DLNA Player provider
2024-11-16 11:50:34.869 ERROR (ThreadPoolExecutor-0_1) [music_assistant] Error doing task: Task exception was never retrieved
Traceback (most recent call last):
  File "/app/venv/lib/python3.12/site-packages/aiohttp/client.py", line 663, in _request
    conn = await self._connector.connect(
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/app/venv/lib/python3.12/site-packages/aiohttp/connector.py", line 563, in connect
    proto = await self._create_connection(req, traces, timeout)
            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/app/venv/lib/python3.12/site-packages/aiohttp/connector.py", line 1032, in _create_connection
    _, proto = await self._create_direct_connection(req, traces, timeout)
               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/app/venv/lib/python3.12/site-packages/aiohttp/connector.py", line 1335, in _create_direct_connection
    transp, proto = await self._wrap_create_connection(
                    ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/app/venv/lib/python3.12/site-packages/aiohttp/connector.py", line 1091, in _wrap_create_connection
    sock = await aiohappyeyeballs.start_connection(
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/app/venv/lib/python3.12/site-packages/aiohappyeyeballs/impl.py", line 82, in start_connection
    sock = await _connect_sock(
           ^^^^^^^^^^^^^^^^^^^^
  File "/app/venv/lib/python3.12/site-packages/aiohappyeyeballs/impl.py", line 174, in _connect_sock
    await loop.sock_connect(sock, address)
  File "/usr/local/lib/python3.12/asyncio/selector_events.py", line 651, in sock_connect
    return await fut
           ^^^^^^^^^
asyncio.exceptions.CancelledError

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/app/venv/lib/python3.12/site-packages/async_upnp_client/aiohttp.py", line 217, in _async_http_request
    async with self._session.request(
               ^^^^^^^^^^^^^^^^^^^^^^
  File "/app/venv/lib/python3.12/site-packages/aiohttp/client.py", line 1359, in __aenter__
    self._resp: _RetType = await self._coro
                           ^^^^^^^^^^^^^^^^
  File "/app/venv/lib/python3.12/site-packages/aiohttp/client.py", line 579, in _request
    with timer:
         ^^^^^
  File "/app/venv/lib/python3.12/site-packages/aiohttp/helpers.py", line 749, in __exit__
    raise asyncio.TimeoutError from exc_val
TimeoutError

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/app/venv/lib/python3.12/site-packages/async_upnp_client/aiohttp.py", line 185, in async_http_request
    return await self._async_http_request(http_request)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/app/venv/lib/python3.12/site-packages/async_upnp_client/aiohttp.py", line 242, in _async_http_request
    raise UpnpConnectionTimeoutError(repr(err)) from err
async_upnp_client.exceptions.UpnpConnectionTimeoutError: [Errno TimeoutError()] None

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/app/venv/lib/python3.12/site-packages/music_assistant/server/providers/dlna/__init__.py", line 434, in on_response
    await self._device_discovered(ssdp_udn, discovery_info["location"])
  File "/app/venv/lib/python3.12/site-packages/music_assistant/server/providers/dlna/__init__.py", line 510, in _device_discovered
    await self._device_connect(dlna_player)
  File "/app/venv/lib/python3.12/site-packages/music_assistant/server/providers/dlna/__init__.py", line 526, in _device_connect
    upnp_device = await self.upnp_factory.async_create_device(dlna_player.description_url)
                  ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/app/venv/lib/python3.12/site-packages/async_upnp_client/client_factory.py", line 100, in async_create_device
    root_el = await self._async_get_device_spec(description_url)
              ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/app/venv/lib/python3.12/site-packages/async_upnp_client/client_factory.py", line 433, in _async_get_device_spec
    bare_response = await self.requester.async_http_request(request)
                    ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/app/venv/lib/python3.12/site-packages/async_upnp_client/aiohttp.py", line 187, in async_http_request
    raise UpnpConnectionError(repr(err)) from err
async_upnp_client.exceptions.UpnpConnectionError: ("UpnpConnectionTimeoutError('TimeoutError()', None)", None)
2024-11-16 11:50:35.503 WARNING (MainThread) [music_assistant.streams] Received unhandled NOTIFY request to /notify from 192.168.178.22
headers: <CIMultiDictProxy('Host': '192.168.178.20:8097', 'Content-Type': 'text/xml;charset="utf-8"', 'Content-Length': '503', 'NT': 'upnp:event', 'NTS': 'upnp:propchange', 'SID': 'uuid:719ae7ee-61de-1988-b7b4-9765cd2c9e43', 'SEQ': '0')>

2024-11-16 11:50:35.513 WARNING (MainThread) [music_assistant.streams] Received unhandled NOTIFY request to /notify from 192.168.178.22
headers: <CIMultiDictProxy('Host': '192.168.178.20:8097', 'Content-Type': 'text/xml;charset="utf-8"', 'Content-Length': '1400', 'NT': 'upnp:event', 'NTS': 'upnp:propchange', 'SID': 'uuid:9bc6f5f1-8e2a-143d-8388-73a6a46d4d13', 'SEQ': '0')>

2024-11-16 11:50:35.521 INFO (MainThread) [music_assistant.players] Player registered: uuid:5f9ec1b3-ff59-19bb-8530-0005cd91b994/Denon AVR-X1300W
2024-11-16 11:50:35.530 WARNING (MainThread) [music_assistant.streams] Received unhandled NOTIFY request to /notify from 192.168.178.22
headers: <CIMultiDictProxy('Host': '192.168.178.20:8097', 'Content-Type': 'text/xml;charset="utf-8"', 'Content-Length': '1558', 'NT': 'upnp:event', 'NTS': 'upnp:propchange', 'SID': 'uuid:27dcae4e-5f12-1e5b-996b-653b0bbbd864', 'SEQ': '0')>

2024-11-16 11:50:35.838 INFO (MainThread) [music_assistant] Loaded player provider UPnP/DLNA Player provider
2024-11-16 11:50:36.346 WARNING (MainThread) [music_assistant.players] Error while requesting latest state from player Denon AVR-X1300W: 'uuid:5f9ec1b3-ff59-19bb-8530-0005cd91b994'
2024-11-16 11:50:55.312 ERROR (MainThread) [music_assistant] Error doing task: Task exception was never retrieved
Traceback (most recent call last):
  File "/app/venv/lib/python3.12/site-packages/aiohttp/client.py", line 663, in _request
    conn = await self._connector.connect(
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/app/venv/lib/python3.12/site-packages/aiohttp/connector.py", line 563, in connect
    proto = await self._create_connection(req, traces, timeout)
            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/app/venv/lib/python3.12/site-packages/aiohttp/connector.py", line 1032, in _create_connection
    _, proto = await self._create_direct_connection(req, traces, timeout)
               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/app/venv/lib/python3.12/site-packages/aiohttp/connector.py", line 1335, in _create_direct_connection
    transp, proto = await self._wrap_create_connection(
                    ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/app/venv/lib/python3.12/site-packages/aiohttp/connector.py", line 1091, in _wrap_create_connection
    sock = await aiohappyeyeballs.start_connection(
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/app/venv/lib/python3.12/site-packages/aiohappyeyeballs/impl.py", line 82, in start_connection
    sock = await _connect_sock(
           ^^^^^^^^^^^^^^^^^^^^
  File "/app/venv/lib/python3.12/site-packages/aiohappyeyeballs/impl.py", line 174, in _connect_sock
    await loop.sock_connect(sock, address)
  File "/usr/local/lib/python3.12/asyncio/selector_events.py", line 651, in sock_connect
    return await fut
           ^^^^^^^^^
asyncio.exceptions.CancelledError

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/app/venv/lib/python3.12/site-packages/async_upnp_client/aiohttp.py", line 217, in _async_http_request
    async with self._session.request(
               ^^^^^^^^^^^^^^^^^^^^^^
  File "/app/venv/lib/python3.12/site-packages/aiohttp/client.py", line 1359, in __aenter__
    self._resp: _RetType = await self._coro
                           ^^^^^^^^^^^^^^^^
  File "/app/venv/lib/python3.12/site-packages/aiohttp/client.py", line 579, in _request
    with timer:
         ^^^^^
  File "/app/venv/lib/python3.12/site-packages/aiohttp/helpers.py", line 749, in __exit__
    raise asyncio.TimeoutError from exc_val
TimeoutError

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/app/venv/lib/python3.12/site-packages/async_upnp_client/aiohttp.py", line 185, in async_http_request
    return await self._async_http_request(http_request)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/app/venv/lib/python3.12/site-packages/async_upnp_client/aiohttp.py", line 242, in _async_http_request
    raise UpnpConnectionTimeoutError(repr(err)) from err
async_upnp_client.exceptions.UpnpConnectionTimeoutError: [Errno TimeoutError()] None

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/app/venv/lib/python3.12/site-packages/music_assistant/server/providers/dlna/__init__.py", line 434, in on_response
    await self._device_discovered(ssdp_udn, discovery_info["location"])
  File "/app/venv/lib/python3.12/site-packages/music_assistant/server/providers/dlna/__init__.py", line 510, in _device_discovered
    await self._device_connect(dlna_player)
  File "/app/venv/lib/python3.12/site-packages/music_assistant/server/providers/dlna/__init__.py", line 526, in _device_connect
    upnp_device = await self.upnp_factory.async_create_device(dlna_player.description_url)
                  ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/app/venv/lib/python3.12/site-packages/async_upnp_client/client_factory.py", line 100, in async_create_device
    root_el = await self._async_get_device_spec(description_url)
              ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/app/venv/lib/python3.12/site-packages/async_upnp_client/client_factory.py", line 433, in _async_get_device_spec
    bare_response = await self.requester.async_http_request(request)
                    ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/app/venv/lib/python3.12/site-packages/async_upnp_client/aiohttp.py", line 187, in async_http_request
    raise UpnpConnectionError(repr(err)) from err
async_upnp_client.exceptions.UpnpConnectionError: ("UpnpConnectionTimeoutError('TimeoutError()', None)", None)

Start playing the album and playing status gets lost

click to expand
2024-11-16 11:51:09.747 DEBUG (MainThread) [music_assistant.streams] Start serving audio stream for QueueItem Snow Patrol - All (library://track/17771) to Denon AVR-X1300W
2024-11-16 11:51:09.762 DEBUG (MainThread) [music_assistant.audio.media_stream] start media stream for: filesystem_smb--eixZkktY://track/Snow Patrol/Snow Patrol - 2024 - The Forest Is the Path/01 Snow Patrol - All.mp3
2024-11-16 11:51:11.100 DEBUG (MainThread) [music_assistant.audio] Getting streamdetails for library://track/17768
2024-11-16 11:51:11.102 DEBUG (MainThread) [music_assistant.audio] Getting streamdetails for library://track/17768
2024-11-16 11:51:11.156 DEBUG (MainThread) [music_assistant.audio] Getting streamdetails for library://track/17768
2024-11-16 11:51:11.156 DEBUG (MainThread) [music_assistant.audio] Getting streamdetails for library://track/17768
2024-11-16 11:51:11.351 DEBUG (MainThread) [music_assistant.audio] retrieved streamdetails for library://track/17768 in 250 milliseconds
2024-11-16 11:51:11.357 DEBUG (MainThread) [music_assistant.audio] retrieved streamdetails for library://track/17768 in 201 milliseconds
2024-11-16 11:51:11.359 DEBUG (MainThread) [music_assistant.audio] retrieved streamdetails for library://track/17768 in 203 milliseconds
2024-11-16 11:51:11.364 DEBUG (MainThread) [music_assistant.audio] retrieved streamdetails for library://track/17768 in 261 milliseconds
2024-11-16 11:51:47.970 INFO (MainThread) [music_assistant.players] Player registered: uuid:ac521fc4-1dd3-11b2-9111-d21d11b6dc4d/55OLED759/12(192.168.178.86)
2024-11-16 11:54:53.925 DEBUG (MainThread) [music_assistant.audio.media_stream] stream finished (with code 0) for filesystem_smb--eixZkktY://track/Snow Patrol/Snow Patrol - 2024 - The Forest Is the Path/01 Snow Patrol - All.mp3 - seconds streamed: 258.58666666666664
2024-11-16 11:55:23.107 DEBUG (MainThread) [music_assistant.streams] Start serving audio stream for QueueItem Snow Patrol - The Beginning (library://track/17768) to Denon AVR-X1300W
2024-11-16 11:55:23.116 DEBUG (MainThread) [music_assistant.audio.media_stream] start media stream for: filesystem_smb--eixZkktY://track/Snow Patrol/Snow Patrol - 2024 - The Forest Is the Path/02 Snow Patrol - The Beginning.mp3
2024-11-16 11:58:23.550 DEBUG (MainThread) [music_assistant.audio.media_stream] stream finished (with code 0) for filesystem_smb--eixZkktY://track/Snow Patrol/Snow Patrol - 2024 - The Forest Is the Path/02 Snow Patrol - The Beginning.mp3 - seconds streamed: 211.25333333333333
2024-11-16 11:58:54.368 DEBUG (MainThread) [music_assistant.streams] Start serving audio stream for QueueItem Snow Patrol - The Beginning (library://track/17768) to Denon AVR-X1300W
2024-11-16 11:58:54.379 DEBUG (MainThread) [music_assistant.audio.media_stream] start media stream for: filesystem_smb--eixZkktY://track/Snow Patrol/Snow Patrol - 2024 - The Forest Is the Path/02 Snow Patrol - The Beginning.mp3
2024-11-16 12:00:59.940 ERROR (MainThread) [music_assistant] Error doing task: Task exception was never retrieved
Traceback (most recent call last):
  File "/app/venv/lib/python3.12/site-packages/aiohttp/client.py", line 663, in _request
    conn = await self._connector.connect(
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/app/venv/lib/python3.12/site-packages/aiohttp/connector.py", line 563, in connect
    proto = await self._create_connection(req, traces, timeout)
            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/app/venv/lib/python3.12/site-packages/aiohttp/connector.py", line 1032, in _create_connection
    _, proto = await self._create_direct_connection(req, traces, timeout)
               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/app/venv/lib/python3.12/site-packages/aiohttp/connector.py", line 1335, in _create_direct_connection
    transp, proto = await self._wrap_create_connection(
                    ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/app/venv/lib/python3.12/site-packages/aiohttp/connector.py", line 1091, in _wrap_create_connection
    sock = await aiohappyeyeballs.start_connection(
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/app/venv/lib/python3.12/site-packages/aiohappyeyeballs/impl.py", line 82, in start_connection
    sock = await _connect_sock(
           ^^^^^^^^^^^^^^^^^^^^
  File "/app/venv/lib/python3.12/site-packages/aiohappyeyeballs/impl.py", line 174, in _connect_sock
    await loop.sock_connect(sock, address)
  File "/usr/local/lib/python3.12/asyncio/selector_events.py", line 651, in sock_connect
    return await fut
           ^^^^^^^^^
asyncio.exceptions.CancelledError

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/app/venv/lib/python3.12/site-packages/async_upnp_client/aiohttp.py", line 217, in _async_http_request
    async with self._session.request(
               ^^^^^^^^^^^^^^^^^^^^^^
  File "/app/venv/lib/python3.12/site-packages/aiohttp/client.py", line 1359, in __aenter__
    self._resp: _RetType = await self._coro
                           ^^^^^^^^^^^^^^^^
  File "/app/venv/lib/python3.12/site-packages/aiohttp/client.py", line 579, in _request
    with timer:
         ^^^^^
  File "/app/venv/lib/python3.12/site-packages/aiohttp/helpers.py", line 749, in __exit__
    raise asyncio.TimeoutError from exc_val
TimeoutError

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/app/venv/lib/python3.12/site-packages/async_upnp_client/aiohttp.py", line 185, in async_http_request
    return await self._async_http_request(http_request)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/app/venv/lib/python3.12/site-packages/async_upnp_client/aiohttp.py", line 242, in _async_http_request
    raise UpnpConnectionTimeoutError(repr(err)) from err
async_upnp_client.exceptions.UpnpConnectionTimeoutError: [Errno TimeoutError()] None

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/app/venv/lib/python3.12/site-packages/music_assistant/server/providers/dlna/__init__.py", line 434, in on_response
    await self._device_discovered(ssdp_udn, discovery_info["location"])
  File "/app/venv/lib/python3.12/site-packages/music_assistant/server/providers/dlna/__init__.py", line 510, in _device_discovered
    await self._device_connect(dlna_player)
  File "/app/venv/lib/python3.12/site-packages/music_assistant/server/providers/dlna/__init__.py", line 526, in _device_connect
    upnp_device = await self.upnp_factory.async_create_device(dlna_player.description_url)
                  ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/app/venv/lib/python3.12/site-packages/async_upnp_client/client_factory.py", line 100, in async_create_device
    root_el = await self._async_get_device_spec(description_url)
              ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/app/venv/lib/python3.12/site-packages/async_upnp_client/client_factory.py", line 433, in _async_get_device_spec
    bare_response = await self.requester.async_http_request(request)
                    ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/app/venv/lib/python3.12/site-packages/async_upnp_client/aiohttp.py", line 187, in async_http_request
    raise UpnpConnectionError(repr(err)) from err
async_upnp_client.exceptions.UpnpConnectionError: ("UpnpConnectionTimeoutError('TimeoutError()', None)", None)
2024-11-16 12:01:54.819 DEBUG (MainThread) [music_assistant.audio.media_stream] stream finished (with code 0) for filesystem_smb--eixZkktY://track/Snow Patrol/Snow Patrol - 2024 - The Forest Is the Path/02 Snow Patrol - The Beginning.mp3 - seconds streamed: 211.25333333333333
2024-11-16 12:02:25.620 DEBUG (MainThread) [music_assistant.streams] Start serving audio stream for QueueItem Snow Patrol - The Beginning (library://track/17768) to Denon AVR-X1300W
2024-11-16 12:02:25.635 DEBUG (MainThread) [music_assistant.audio.media_stream] start media stream for: filesystem_smb--eixZkktY://track/Snow Patrol/Snow Patrol - 2024 - The Forest Is the Path/02 Snow Patrol - The Beginning.mp3
2024-11-16 12:03:55.416 DEBUG (MainThread) [music_assistant.audio.media_stream] stream aborted (with code 255) for filesystem_smb--eixZkktY://track/Snow Patrol/Snow Patrol - 2024 - The Forest Is the Path/02 Snow Patrol - The Beginning.mp3 - seconds streamed: 111.0
2024-11-16 13:30:36.225 ERROR (MainThread) [music_assistant] Error doing task: Task exception was never retrieved
Traceback (most recent call last):
  File "/app/venv/lib/python3.12/site-packages/aiohttp/client.py", line 663, in _request
    conn = await self._connector.connect(
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/app/venv/lib/python3.12/site-packages/aiohttp/connector.py", line 563, in connect
    proto = await self._create_connection(req, traces, timeout)
            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/app/venv/lib/python3.12/site-packages/aiohttp/connector.py", line 1032, in _create_connection
    _, proto = await self._create_direct_connection(req, traces, timeout)
               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/app/venv/lib/python3.12/site-packages/aiohttp/connector.py", line 1335, in _create_direct_connection
    transp, proto = await self._wrap_create_connection(
                    ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/app/venv/lib/python3.12/site-packages/aiohttp/connector.py", line 1091, in _wrap_create_connection
    sock = await aiohappyeyeballs.start_connection(
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/app/venv/lib/python3.12/site-packages/aiohappyeyeballs/impl.py", line 82, in start_connection
    sock = await _connect_sock(
           ^^^^^^^^^^^^^^^^^^^^
  File "/app/venv/lib/python3.12/site-packages/aiohappyeyeballs/impl.py", line 174, in _connect_sock
    await loop.sock_connect(sock, address)
  File "/usr/local/lib/python3.12/asyncio/selector_events.py", line 651, in sock_connect
    return await fut
           ^^^^^^^^^
asyncio.exceptions.CancelledError

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/app/venv/lib/python3.12/site-packages/async_upnp_client/aiohttp.py", line 217, in _async_http_request
    async with self._session.request(
               ^^^^^^^^^^^^^^^^^^^^^^
  File "/app/venv/lib/python3.12/site-packages/aiohttp/client.py", line 1359, in __aenter__
    self._resp: _RetType = await self._coro
                           ^^^^^^^^^^^^^^^^
  File "/app/venv/lib/python3.12/site-packages/aiohttp/client.py", line 579, in _request
    with timer:
         ^^^^^
  File "/app/venv/lib/python3.12/site-packages/aiohttp/helpers.py", line 749, in __exit__
    raise asyncio.TimeoutError from exc_val
TimeoutError

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/app/venv/lib/python3.12/site-packages/async_upnp_client/aiohttp.py", line 185, in async_http_request
    return await self._async_http_request(http_request)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/app/venv/lib/python3.12/site-packages/async_upnp_client/aiohttp.py", line 242, in _async_http_request
    raise UpnpConnectionTimeoutError(repr(err)) from err
async_upnp_client.exceptions.UpnpConnectionTimeoutError: [Errno TimeoutError()] None

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/app/venv/lib/python3.12/site-packages/music_assistant/server/providers/dlna/__init__.py", line 434, in on_response
    await self._device_discovered(ssdp_udn, discovery_info["location"])
  File "/app/venv/lib/python3.12/site-packages/music_assistant/server/providers/dlna/__init__.py", line 510, in _device_discovered
    await self._device_connect(dlna_player)
  File "/app/venv/lib/python3.12/site-packages/music_assistant/server/providers/dlna/__init__.py", line 526, in _device_connect
    upnp_device = await self.upnp_factory.async_create_device(dlna_player.description_url)
                  ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/app/venv/lib/python3.12/site-packages/async_upnp_client/client_factory.py", line 100, in async_create_device
    root_el = await self._async_get_device_spec(description_url)
              ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/app/venv/lib/python3.12/site-packages/async_upnp_client/client_factory.py", line 433, in _async_get_device_spec
    bare_response = await self.requester.async_http_request(request)
                    ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/app/venv/lib/python3.12/site-packages/async_upnp_client/aiohttp.py", line 187, in async_http_request
    raise UpnpConnectionError(repr(err)) from err
async_upnp_client.exceptions.UpnpConnectionError: ("UpnpConnectionTimeoutError('TimeoutError()', None)", None)

Full log file

MusicAssistant6.log

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working DLNA/UPNP
Projects
Status: NEXT
Development

No branches or pull requests

4 participants