Music stops playing - Githubissues

gieljnssns commented 2 years ago

What version of Music Assistant has the issue?

2022.11.0

The problem

Sometimes my music suddenly stops playing

How to reproduce

Play a playlist from spotify through a sonos group

Relevant log output

None

Additional information

This are all sonos players

What version of Home Assistant Core are your running

2022.11.3

What type of installation are you running?

Home Assistant OS

On what type of hardware are you running?

Generic x86-64 (e.g. Intel NUC)

erkr commented 2 years ago

The next MA release contains a major refactoring of buffering/streaming. Let's park this issue and check that update once available (December time frame)

erkr commented 2 years ago

I today noticed the same issue using Spotify on chromecast devices. But I see timeouts in the log:

Logger: homeassistant
Source: /usr/src/homeassistant/homeassistant/runner.py:96 
First occurred: 12:19:17 (2 occurrences) 
Last logged: 14:39:52

Error doing job: Task exception was never retrieved
Traceback (most recent call last):
  File "/usr/local/lib/python3.10/site-packages/music_assistant/helpers/process.py", line 110, in readexactly
    return await self._proc.stdout.readexactly(n)
  File "/usr/local/lib/python3.10/asyncio/streams.py", line 708, in readexactly
    await self._wait_for_data('readexactly')
  File "/usr/local/lib/python3.10/asyncio/streams.py", line 502, in _wait_for_data
    await self._waiter
asyncio.exceptions.CancelledError

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.10/site-packages/music_assistant/controllers/streams.py", line 524, in _queue_stream_runner
    async for chunk in ffmpeg_proc.iter_chunked(self.output_chunksize):
  File "/usr/local/lib/python3.10/site-packages/music_assistant/helpers/process.py", line 91, in iter_chunked
    chunk = await self.readexactly(n)
  File "/usr/local/lib/python3.10/site-packages/music_assistant/helpers/process.py", line 109, in readexactly
    async with _timeout(timeout):
  File "/usr/local/lib/python3.10/site-packages/async_timeout/__init__.py", line 129, in __aexit__
    self._do_exit(exc_type)
  File "/usr/local/lib/python3.10/site-packages/async_timeout/__init__.py", line 212, in _do_exit
    raise asyncio.TimeoutError
asyncio.exceptions.TimeoutError

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.10/site-packages/music_assistant/controllers/streams.py", line 496, in _queue_stream_runner
    async with AsyncProcess(ffmpeg_args, True) as ffmpeg_proc:
  File "/usr/local/lib/python3.10/site-packages/music_assistant/helpers/process.py", line 76, in __aexit__
    await self._attached_task
  File "/usr/local/lib/python3.10/site-packages/music_assistant/controllers/streams.py", line 500, in writer
    async for audio_chunk in self._get_queue_stream():
  File "/usr/local/lib/python3.10/site-packages/music_assistant/controllers/streams.py", line 670, in _get_queue_stream
    async for chunk in get_media_stream(
  File "/usr/local/lib/python3.10/site-packages/music_assistant/helpers/audio.py", line 410, in get_media_stream
    async for chunk in ffmpeg_proc.iter_chunked(chunk_size):
  File "/usr/local/lib/python3.10/site-packages/music_assistant/helpers/process.py", line 91, in iter_chunked
    chunk = await self.readexactly(n)
  File "/usr/local/lib/python3.10/site-packages/music_assistant/helpers/process.py", line 109, in readexactly
    async with _timeout(timeout):
  File "/usr/local/lib/python3.10/site-packages/async_timeout/__init__.py", line 129, in __aexit__
    self._do_exit(exc_type)
  File "/usr/local/lib/python3.10/site-packages/async_timeout/__init__.py", line 212, in _do_exit
    raise asyncio.TimeoutError
asyncio.exceptions.TimeoutError

@gieljnssns don't you have them in your log?

gieljnssns commented 2 years ago

I haven't seen something like this in my log. I keep an eye on this when it happens again. Do you have debug enabled?

gieljnssns commented 2 years ago

found this in my log

Logger: music_assistant.stream
Source: runner.py:119
First occurred: 19 november 2022 om 18:27:52 (2 occurrences)
Last logged: 16:10:49

Got stream request for unknown or finished stream: 8f33bc8db7274de6abd8c5cf47048da9
Got stream request for unknown or finished stream: ee4341ebd2e94eb4893d11537cb3894c

But it wasn't when my error occurs.

gieljnssns commented 2 years ago

Something else i have frequently, When I'm playing music on a sonos group, the music stops on one of the slaves for a couple seconds and then resumes... Nothing in my logs on the moment this happens...

OzGav commented 2 years ago

Thanks. As @erkr suggested above. Let’s wait until next month for the next release and see what we find then.

gieljnssns commented 1 year ago

I have some debugging in this case The music stops playing at 12:53:30 Keuken (192.168.79.84) is coordinator, move is client

2022-12-16 11:04:20.286 INFO (MainThread) [music_assistant.db] Database connected.
2022-12-16 11:04:21.633 DEBUG (MainThread) [music_assistant.event] background_job_updated Cleanup cache
2022-12-16 11:04:22.425 DEBUG (MainThread) [music_assistant.music.spotify] Retrieved Spotify token using librespot in 0.79 seconds
2022-12-16 11:04:22.615 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/me took 0.13 seconds
2022-12-16 11:04:22.615 INFO (MainThread) [music_assistant.music.spotify] Succesfully logged in to Spotify as gieljnssns
2022-12-16 11:04:22.616 DEBUG (MainThread) [music_assistant.event] background_job_updated Cleanup removed items from database
2022-12-16 11:04:22.645 INFO (MainThread) [music_assistant.stream] Started stream server on port 8095
2022-12-16 11:04:22.645 DEBUG (MainThread) [music_assistant.event] background_job_updated Cleanup cache
2022-12-16 11:04:22.645 DEBUG (MainThread) [music_assistant.event] background_job_updated Cleanup removed items from database
2022-12-16 11:04:24.717 INFO (MainThread) [music_assistant] Finished job [Cleanup cache] in 2.07 seconds.
2022-12-16 11:04:24.718 DEBUG (MainThread) [music_assistant.event] background_job_finished Cleanup cache
2022-12-16 11:04:24.734 INFO (MainThread) [music_assistant] Finished job [Cleanup removed items from database] in 2.09 seconds.
2022-12-16 11:04:24.735 DEBUG (MainThread) [music_assistant.event] background_job_finished Cleanup removed items from database
2022-12-16 11:04:27.550 DEBUG (MainThread) [music_assistant.event] background_job_updated Library sync for provider Spotify
2022-12-16 11:04:27.551 DEBUG (MainThread) [music_assistant.event] background_job_updated Library sync for provider Tune-in Radio
2022-12-16 11:04:27.551 DEBUG (MainThread) [music_assistant.event] background_job_updated Library sync for provider Filesystem
2022-12-16 11:04:27.551 DEBUG (MainThread) [music_assistant.event] background_job_updated Library sync for provider URL
2022-12-16 11:04:27.557 DEBUG (MainThread) [music_assistant.event] background_job_updated Library sync for provider Spotify
2022-12-16 11:04:27.557 DEBUG (MainThread) [music_assistant.event] background_job_updated Library sync for provider Tune-in Radio
2022-12-16 11:04:27.557 DEBUG (MainThread) [music_assistant.event] background_job_updated Library sync for provider Filesystem
2022-12-16 11:04:27.562 DEBUG (MainThread) [music_assistant.music.spotify] Start sync of artist items.
2022-12-16 11:04:27.563 DEBUG (MainThread) [music_assistant.music.tunein] Start sync of radio items.
2022-12-16 11:04:27.696 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/me/following took 0.13 seconds
2022-12-16 11:04:29.815 DEBUG (MainThread) [music_assistant.event] queue_added media_player.move
2022-12-16 11:04:29.816 INFO (MainThread) [music_assistant.players] Player registered: media_player.move/Move
2022-12-16 11:04:29.816 DEBUG (MainThread) [music_assistant.event] player_added media_player.move
2022-12-16 11:04:29.820 DEBUG (MainThread) [music_assistant.event] queue_added media_player.living_2
2022-12-16 11:04:29.820 INFO (MainThread) [music_assistant.players] Player registered: media_player.living_2/Living
2022-12-16 11:04:29.820 DEBUG (MainThread) [music_assistant.event] player_added media_player.living_2
2022-12-16 11:04:29.822 DEBUG (MainThread) [music_assistant.event] queue_updated media_player.keuken
2022-12-16 11:04:29.822 DEBUG (MainThread) [music_assistant.event] player_updated media_player.keuken
2022-12-16 11:04:29.827 DEBUG (MainThread) [music_assistant.event] queue_updated media_player.move
2022-12-16 11:04:29.828 DEBUG (MainThread) [music_assistant.event] player_updated media_player.move
2022-12-16 11:04:29.873 DEBUG (MainThread) [music_assistant.event] queue_added media_player.2c
2022-12-16 11:04:29.874 INFO (MainThread) [music_assistant.players] Player registered: media_player.2c/2C
2022-12-16 11:04:29.874 DEBUG (MainThread) [music_assistant.event] player_added media_player.2c
2022-12-16 11:04:29.974 DEBUG (MainThread) [music_assistant.event] queue_added media_player.keuken
2022-12-16 11:04:29.975 INFO (MainThread) [music_assistant.players] Player registered: media_player.keuken/Keuken
2022-12-16 11:04:29.975 DEBUG (MainThread) [music_assistant.event] player_added media_player.keuken
2022-12-16 11:04:29.987 DEBUG (MainThread) [music_assistant.event] queue_added media_player.badkamer
2022-12-16 11:04:29.987 INFO (MainThread) [music_assistant.players] Player registered: media_player.badkamer/Badkamer
2022-12-16 11:04:29.987 DEBUG (MainThread) [music_assistant.event] player_added media_player.badkamer
2022-12-16 11:04:30.439 INFO (MainThread) [music_assistant] Finished job [Library sync for provider Filesystem] in 2.88 seconds.
2022-12-16 11:04:30.439 DEBUG (MainThread) [music_assistant.event] background_job_finished Library sync for provider Filesystem
2022-12-16 11:04:30.439 DEBUG (MainThread) [music_assistant.event] background_job_updated Library sync for provider URL
2022-12-16 11:04:30.440 INFO (MainThread) [music_assistant] Finished job [Library sync for provider URL] in 0.0 seconds.
2022-12-16 11:04:30.440 DEBUG (MainThread) [music_assistant.event] background_job_finished Library sync for provider URL
2022-12-16 11:04:30.452 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/me/following?type=artist&after=1JjP30v8j95bAMZN3ws8Kb&limit=50 took 0.09 seconds
2022-12-16 11:04:30.962 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/me/following?type=artist&after=3Z2vMxQUmTucDgRCVfJNxu&limit=50 took 0.08 seconds
2022-12-16 11:04:31.549 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/me/following?type=artist&after=4t1k4AAHMJOOPnRSjQj0u4&limit=50 took 0.14 seconds
2022-12-16 11:04:31.908 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/me/following?type=artist&after=6uDRvRGnKQW5lktOjbNmDs&limit=50 took 0.06 seconds
2022-12-16 11:04:32.062 DEBUG (MainThread) [music_assistant.music.spotify] Start sync of album items.
2022-12-16 11:04:32.264 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/me/albums took 0.2 seconds
2022-12-16 11:04:32.306 DEBUG (MainThread) [music_assistant.music.spotify] Start sync of track items.
2022-12-16 11:04:32.439 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/me/tracks took 0.13 seconds
2022-12-16 11:04:32.588 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/me/tracks took 0.15 seconds
2022-12-16 11:04:32.985 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/me/tracks took 0.13 seconds
2022-12-16 11:04:34.884 DEBUG (MainThread) [music_assistant.music.spotify] Start sync of playlist items.
2022-12-16 11:04:35.081 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/me/playlists took 0.2 seconds
2022-12-16 11:04:35.231 INFO (MainThread) [music_assistant] Finished job [Library sync for provider Spotify] in 7.67 seconds.
2022-12-16 11:04:35.231 DEBUG (MainThread) [music_assistant.event] background_job_finished Library sync for provider Spotify
2022-12-16 11:04:38.973 INFO (MainThread) [music_assistant] Finished job [Library sync for provider Tune-in Radio] in 11.42 seconds.
2022-12-16 11:04:38.973 DEBUG (MainThread) [music_assistant.event] background_job_finished Library sync for provider Tune-in Radio
2022-12-16 11:04:52.773 DEBUG (MainThread) [music_assistant.event] queue_updated media_player.living_2
2022-12-16 11:04:52.774 DEBUG (MainThread) [music_assistant.event] player_updated media_player.living_2
2022-12-16 11:04:52.775 DEBUG (MainThread) [music_assistant.event] queue_updated media_player.badkamer
2022-12-16 11:04:52.776 DEBUG (MainThread) [music_assistant.event] player_updated media_player.badkamer
2022-12-16 11:04:52.777 DEBUG (MainThread) [music_assistant.event] queue_updated media_player.2c
2022-12-16 11:04:52.777 DEBUG (MainThread) [music_assistant.event] player_updated media_player.2c
2022-12-16 11:41:52.219 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/tracks/1VGujxZOADSTxfr3SG6K4o took 0.14 seconds
2022-12-16 11:41:52.238 DEBUG (MainThread) [music_assistant.players.stream] Starting Queue audio stream for Queue Keuken (PCM format: s16le - sample rate: 44100)
2022-12-16 11:41:52.238 INFO (MainThread) [music_assistant.players.stream] Start Streaming queue track: spotify://track/1VGujxZOADSTxfr3SG6K4o (DOWN - Steeple) for queue Keuken - crossfade: False
2022-12-16 11:41:52.238 DEBUG (MainThread) [music_assistant.event] queue_updated media_player.keuken
2022-12-16 11:41:52.272 DEBUG (MainThread) [music_assistant.helpers.audio] start media stream for: spotify://track/1VGujxZOADSTxfr3SG6K4o
2022-12-16 11:41:52.272 DEBUG (MainThread) [music_assistant.helpers.audio] writer started for spotify://track/1VGujxZOADSTxfr3SG6K4o
2022-12-16 11:41:52.358 DEBUG (MainThread) [music_assistant.stream] Got GET request to /00e430d93dea4d8d82f4f75015201f14.flac from 192.168.79.84
2022-12-16 11:41:52.359 DEBUG (MainThread) [music_assistant.players.stream] client connected: 192.168.79.84
2022-12-16 11:41:52.359 DEBUG (MainThread) [music_assistant.players.stream] 1 clients connected
2022-12-16 11:41:52.387 DEBUG (MainThread) [music_assistant.event] player_updated media_player.move
2022-12-16 11:41:54.833 DEBUG (MainThread) [music_assistant.event] queue_updated media_player.keuken
2022-12-16 11:41:54.838 DEBUG (MainThread) [music_assistant.event] queue_updated media_player.keuken
2022-12-16 11:41:54.840 DEBUG (MainThread) [music_assistant.event] player_updated media_player.keuken
2022-12-16 11:41:54.842 DEBUG (MainThread) [music_assistant.event] queue_updated media_player.move
2022-12-16 11:41:54.845 DEBUG (MainThread) [music_assistant.event] player_updated media_player.move
2022-12-16 11:41:55.117 DEBUG (MainThread) [music_assistant.event] queue_updated media_player.keuken
2022-12-16 11:42:02.536 DEBUG (MainThread) [music_assistant.helpers.audio] writer finished for spotify://track/1VGujxZOADSTxfr3SG6K4o
2022-12-16 11:42:16.518 DEBUG (MainThread) [music_assistant.helpers.audio] finished media stream for: spotify://track/1VGujxZOADSTxfr3SG6K4o
2022-12-16 11:42:16.535 DEBUG (MainThread) [music_assistant.players.stream] end of track reached - chunk_num: 254 - crossfade_buffer: 5.357460317460317 - stream_duration: 253 - player_buffer: 226.0 - process_time: 24.29
2022-12-16 11:42:16.570 DEBUG (MainThread) [music_assistant.helpers.audio] stripped silence of pcm chunk. size before: 945056 - after: 776600
2022-12-16 11:42:16.580 DEBUG (MainThread) [music_assistant.players.stream] Finished Streaming queue track: spotify://track/1VGujxZOADSTxfr3SG6K4o (DOWN - Steeple) on queue Keuken
2022-12-16 11:42:16.721 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/tracks/3BxiRlvUrBJjb1237gXhsJ took 0.12 seconds
2022-12-16 11:42:16.732 INFO (MainThread) [music_assistant.players.stream] Start Streaming queue track: spotify://track/3BxiRlvUrBJjb1237gXhsJ (Lycus - Tempest) for queue Keuken - crossfade: False
2022-12-16 11:42:16.733 DEBUG (MainThread) [music_assistant.event] queue_updated media_player.keuken
2022-12-16 11:42:16.762 DEBUG (MainThread) [music_assistant.helpers.audio] start media stream for: spotify://track/3BxiRlvUrBJjb1237gXhsJ
2022-12-16 11:42:16.763 DEBUG (MainThread) [music_assistant.helpers.audio] writer started for spotify://track/3BxiRlvUrBJjb1237gXhsJ
2022-12-16 11:46:07.845 DEBUG (MainThread) [music_assistant.event] queue_updated media_player.keuken
2022-12-16 11:46:07.951 DEBUG (MainThread) [music_assistant.event] queue_updated media_player.keuken
2022-12-16 11:58:37.601 DEBUG (MainThread) [music_assistant.helpers.audio] writer finished for spotify://track/3BxiRlvUrBJjb1237gXhsJ
2022-12-16 11:59:50.988 DEBUG (MainThread) [music_assistant.helpers.audio] finished media stream for: spotify://track/3BxiRlvUrBJjb1237gXhsJ
2022-12-16 11:59:51.015 DEBUG (MainThread) [music_assistant.event] background_job_updated Analyze audio for spotify://track/3BxiRlvUrBJjb1237gXhsJ
2022-12-16 11:59:51.015 DEBUG (MainThread) [music_assistant.players.stream] end of track reached - chunk_num: 1236 - crossfade_buffer: 5.1066666666666665 - stream_duration: 1235 - player_buffer: 405.4024943310658 - process_time: 1054.28
2022-12-16 11:59:51.019 DEBUG (MainThread) [music_assistant.event] background_job_updated Analyze audio for spotify://track/3BxiRlvUrBJjb1237gXhsJ
2022-12-16 11:59:51.020 DEBUG (MainThread) [music_assistant.helpers.audio] Start analyzing track spotify://track/3BxiRlvUrBJjb1237gXhsJ
2022-12-16 11:59:51.077 DEBUG (MainThread) [music_assistant.helpers.audio] stripped silence of pcm chunk. size before: 900816 - after: 0
2022-12-16 11:59:51.077 DEBUG (MainThread) [music_assistant.players.stream] Finished Streaming queue track: spotify://track/3BxiRlvUrBJjb1237gXhsJ (Lycus - Tempest) on queue Keuken
2022-12-16 11:59:51.237 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/tracks/3UXlNmWG0HIM6GvAfhpywS took 0.15 seconds
2022-12-16 11:59:51.238 DEBUG (MainThread) [music_assistant.event] background_job_updated Add spotify://track/3UXlNmWG0HIM6GvAfhpywS to database
2022-12-16 11:59:51.240 DEBUG (MainThread) [music_assistant.event] background_job_updated Add spotify://track/3UXlNmWG0HIM6GvAfhpywS to database
2022-12-16 11:59:51.317 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/albums/0wSgAHUpCnIyfb7eSQym8o took 0.07 seconds
2022-12-16 11:59:51.317 DEBUG (MainThread) [music_assistant.event] background_job_updated Add spotify://album/0wSgAHUpCnIyfb7eSQym8o to database
2022-12-16 11:59:51.318 DEBUG (MainThread) [music_assistant.event] background_job_updated Add spotify://album/0wSgAHUpCnIyfb7eSQym8o to database
2022-12-16 11:59:51.384 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/artists/4sAFcrI2hgMwNT9Sz2XTjv took 0.06 seconds
2022-12-16 11:59:51.384 DEBUG (MainThread) [music_assistant.event] background_job_updated Add spotify://artist/4sAFcrI2hgMwNT9Sz2XTjv to database
2022-12-16 11:59:51.447 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/artists/4sAFcrI2hgMwNT9Sz2XTjv took 0.06 seconds
2022-12-16 11:59:51.447 DEBUG (MainThread) [music_assistant] Ignored duplicate job: Add spotify://artist/4sAFcrI2hgMwNT9Sz2XTjv to database
2022-12-16 11:59:51.464 DEBUG (MainThread) [music_assistant.music.artist] added Regarde Les Hommes Tomber to database
2022-12-16 11:59:51.489 DEBUG (MainThread) [music_assistant.music.album] added Exile to database
2022-12-16 11:59:51.492 DEBUG (MainThread) [music_assistant.music.album] Trying to match album Exile on provider Filesystem
2022-12-16 11:59:51.515 DEBUG (MainThread) [music_assistant.music.album] updated Exile in database: 353
2022-12-16 11:59:51.516 DEBUG (MainThread) [music_assistant.music.album] Could not find match for Album Exile on provider Filesystem
2022-12-16 11:59:51.534 DEBUG (MainThread) [music_assistant.music.track] added A Sheep Among the Wolves to database: 2006
2022-12-16 11:59:51.537 DEBUG (MainThread) [music_assistant.music.track] Trying to match track A Sheep Among the Wolves on provider Spotify
2022-12-16 11:59:52.380 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/albums/0wSgAHUpCnIyfb7eSQym8o took 0.13 seconds
2022-12-16 11:59:52.444 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/tracks/3UXlNmWG0HIM6GvAfhpywS took 0.12 seconds
2022-12-16 11:59:52.450 INFO (MainThread) [music_assistant.players.stream] Start Streaming queue track: spotify://track/3UXlNmWG0HIM6GvAfhpywS (Regarde Les Hommes Tomber - A Sheep Among the Wolves) for queue Keuken - crossfade: False
2022-12-16 11:59:52.450 DEBUG (MainThread) [music_assistant.event] queue_updated media_player.keuken
2022-12-16 11:59:52.459 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/search took 0.36 seconds
2022-12-16 11:59:52.479 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/albums/0wSgAHUpCnIyfb7eSQym8o/tracks took 0.08 seconds
2022-12-16 11:59:52.481 DEBUG (MainThread) [music_assistant.helpers.audio] start media stream for: spotify://track/3UXlNmWG0HIM6GvAfhpywS
2022-12-16 11:59:52.482 DEBUG (MainThread) [music_assistant.helpers.audio] writer started for spotify://track/3UXlNmWG0HIM6GvAfhpywS
2022-12-16 11:59:52.606 DEBUG (MainThread) [music_assistant.music.track] updated A Sheep Among the Wolves in database: 2006
2022-12-16 11:59:52.607 DEBUG (MainThread) [music_assistant.music.track] added L'exil to database: 2007
2022-12-16 11:59:52.608 DEBUG (MainThread) [music_assistant.music.track] Trying to match track A Sheep Among the Wolves on provider Filesystem
2022-12-16 11:59:52.643 DEBUG (MainThread) [music_assistant.music.track] Could not find match for Track A Sheep Among the Wolves on provider Filesystem
2022-12-16 11:59:52.644 DEBUG (MainThread) [music_assistant.music.track] updated A Sheep Among the Wolves in database: 2006
2022-12-16 11:59:52.645 DEBUG (MainThread) [music_assistant.event] media_item_added database://track/2006
2022-12-16 11:59:52.645 INFO (MainThread) [music_assistant] Finished job [Add spotify://track/3UXlNmWG0HIM6GvAfhpywS to database] in 1.41 seconds.
2022-12-16 11:59:52.646 DEBUG (MainThread) [music_assistant.event] background_job_finished Add spotify://track/3UXlNmWG0HIM6GvAfhpywS to database
2022-12-16 11:59:52.646 DEBUG (MainThread) [music_assistant.event] background_job_updated Add spotify://artist/4sAFcrI2hgMwNT9Sz2XTjv to database
2022-12-16 11:59:52.687 DEBUG (MainThread) [music_assistant.music.track] added Embrace the Flames to database: 2008
2022-12-16 11:59:52.724 DEBUG (MainThread) [music_assistant.music.track] added They Came... to database: 2009
2022-12-16 11:59:52.773 DEBUG (MainThread) [music_assistant.music.track] added To Take Us to database: 2010
2022-12-16 11:59:52.808 DEBUG (MainThread) [music_assistant.music.track] added Thou Shall Lie Down to database: 2011
2022-12-16 11:59:52.837 DEBUG (MainThread) [music_assistant.music.track] added The Incandescent March to database: 2012
2022-12-16 11:59:52.842 DEBUG (MainThread) [music_assistant.event] media_item_added database://album/353
2022-12-16 11:59:52.842 INFO (MainThread) [music_assistant] Finished job [Add spotify://album/0wSgAHUpCnIyfb7eSQym8o to database] in 1.52 seconds.
2022-12-16 11:59:52.842 DEBUG (MainThread) [music_assistant.event] background_job_finished Add spotify://album/0wSgAHUpCnIyfb7eSQym8o to database
2022-12-16 11:59:53.178 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/artists/4sAFcrI2hgMwNT9Sz2XTjv/albums?include_groups=album,single,compilation took 0.07 seconds
2022-12-16 11:59:53.180 DEBUG (MainThread) [music_assistant.audiodb] Lookup MusicbrainzID for Artist Regarde Les Hommes Tomber on TheAudioDb
2022-12-16 11:59:53.302 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/artists/4sAFcrI2hgMwNT9Sz2XTjv took 0.04 seconds
2022-12-16 11:59:53.416 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/artists/4sAFcrI2hgMwNT9Sz2XTjv/top-tracks took 0.08 seconds
2022-12-16 11:59:53.418 DEBUG (MainThread) [music_assistant.musicbrainz] searching musicbrainz for Regarde Les Hommes Tomber                 (albumname: None - album_upc: None - trackname: None - track_isrc: FR33T2054902)
2022-12-16 11:59:53.556 DEBUG (MainThread) [music_assistant.musicbrainz] searching musicbrainz for Regarde Les Hommes Tomber                 (albumname: None - album_upc: None - trackname: None - track_isrc: FR33T2054901)
2022-12-16 11:59:54.481 DEBUG (MainThread) [music_assistant.musicbrainz] searching musicbrainz for Regarde Les Hommes Tomber                 (albumname: None - album_upc: None - trackname: None - track_isrc: FR33T2054903)
2022-12-16 11:59:55.492 DEBUG (MainThread) [music_assistant.musicbrainz] searching musicbrainz for Regarde Les Hommes Tomber                 (albumname: None - album_upc: None - trackname: None - track_isrc: FR33T2054904)
2022-12-16 11:59:56.496 DEBUG (MainThread) [music_assistant.musicbrainz] searching musicbrainz for Regarde Les Hommes Tomber                 (albumname: None - album_upc: None - trackname: None - track_isrc: FR33T2054907)
2022-12-16 11:59:57.536 DEBUG (MainThread) [music_assistant.musicbrainz] searching musicbrainz for Regarde Les Hommes Tomber                 (albumname: None - album_upc: None - trackname: None - track_isrc: FR33T2054905)
2022-12-16 11:59:58.505 DEBUG (MainThread) [music_assistant.musicbrainz] searching musicbrainz for Regarde Les Hommes Tomber                 (albumname: None - album_upc: None - trackname: None - track_isrc: FR33T2054906)
2022-12-16 11:59:59.520 DEBUG (MainThread) [music_assistant.musicbrainz] searching musicbrainz for Regarde Les Hommes Tomber                 (albumname: None - album_upc: None - trackname: None - track_isrc: FR9W11524996)
2022-12-16 12:00:00.534 DEBUG (MainThread) [music_assistant.musicbrainz] searching musicbrainz for Regarde Les Hommes Tomber                 (albumname: None - album_upc: None - trackname: None - track_isrc: FR9W11611582)
2022-12-16 12:00:01.562 DEBUG (MainThread) [music_assistant.musicbrainz] searching musicbrainz for Regarde Les Hommes Tomber                 (albumname: None - album_upc: None - trackname: None - track_isrc: FR9W11524997)
2022-12-16 12:00:02.558 DEBUG (MainThread) [music_assistant.musicbrainz] searching musicbrainz for Regarde Les Hommes Tomber                 (albumname: None - album_upc: None - trackname: A New Order - track_isrc: None)
2022-12-16 12:00:03.601 DEBUG (MainThread) [music_assistant.musicbrainz] Got MusicbrainzArtistId for Regarde Les Hommes Tomber after search on trackname A New Order --> 3eb0dd85-bbb5-43f5-9731-12c50a4865ba
2022-12-16 12:00:03.601 DEBUG (MainThread) [music_assistant.fanarttv] Fetching metadata for Artist Regarde Les Hommes Tomber on Fanart.tv
2022-12-16 12:00:03.805 DEBUG (MainThread) [music_assistant.audiodb] Fetching metadata for Artist Regarde Les Hommes Tomber on TheAudioDb
2022-12-16 12:00:03.913 DEBUG (MainThread) [music_assistant.music.artist] updated Regarde Les Hommes Tomber in database: 442
2022-12-16 12:00:03.918 DEBUG (MainThread) [music_assistant.music.artist] Trying to match artist Regarde Les Hommes Tomber on provider Filesystem
2022-12-16 12:00:04.280 DEBUG (MainThread) [music_assistant.music.artist] Could not find match for Artist Regarde Les Hommes Tomber on provider Filesystem
2022-12-16 12:00:04.283 DEBUG (MainThread) [music_assistant.event] media_item_updated database://artist/442
2022-12-16 12:00:04.283 INFO (MainThread) [music_assistant] Finished job [Add spotify://artist/4sAFcrI2hgMwNT9Sz2XTjv to database] in 11.64 seconds.
2022-12-16 12:00:04.283 DEBUG (MainThread) [music_assistant.event] background_job_finished Add spotify://artist/4sAFcrI2hgMwNT9Sz2XTjv to database
2022-12-16 12:00:14.779 DEBUG (MainThread) [music_assistant.helpers.audio] Integrated loudness of spotify://track/3BxiRlvUrBJjb1237gXhsJ is: -9.4
2022-12-16 12:00:14.780 INFO (MainThread) [music_assistant] Finished job [Analyze audio for spotify://track/3BxiRlvUrBJjb1237gXhsJ] in 23.76 seconds.
2022-12-16 12:00:14.780 DEBUG (MainThread) [music_assistant.event] background_job_finished Analyze audio for spotify://track/3BxiRlvUrBJjb1237gXhsJ
2022-12-16 12:04:21.634 DEBUG (MainThread) [music_assistant.event] background_job_updated Cleanup cache
2022-12-16 12:04:21.635 DEBUG (MainThread) [music_assistant.event] background_job_updated Cleanup cache
2022-12-16 12:04:23.678 INFO (MainThread) [music_assistant] Finished job [Cleanup cache] in 2.04 seconds.
2022-12-16 12:04:23.678 DEBUG (MainThread) [music_assistant.event] background_job_finished Cleanup cache
2022-12-16 12:06:37.605 DEBUG (MainThread) [music_assistant.event] queue_updated media_player.keuken
2022-12-16 12:06:37.688 DEBUG (MainThread) [music_assistant.event] queue_updated media_player.keuken
2022-12-16 12:08:36.850 DEBUG (MainThread) [music_assistant.helpers.audio] writer finished for spotify://track/3UXlNmWG0HIM6GvAfhpywS
2022-12-16 12:10:16.356 DEBUG (MainThread) [music_assistant.helpers.audio] finished media stream for: spotify://track/3UXlNmWG0HIM6GvAfhpywS
2022-12-16 12:10:16.386 DEBUG (MainThread) [music_assistant.event] background_job_updated Analyze audio for spotify://track/3UXlNmWG0HIM6GvAfhpywS
2022-12-16 12:10:16.386 DEBUG (MainThread) [music_assistant.players.stream] end of track reached - chunk_num: 438 - crossfade_buffer: 5.64 - stream_duration: 437 - player_buffer: 212.40249433106578 - process_time: 623.93
2022-12-16 12:10:16.389 DEBUG (MainThread) [music_assistant.event] background_job_updated Analyze audio for spotify://track/3UXlNmWG0HIM6GvAfhpywS
2022-12-16 12:10:16.390 DEBUG (MainThread) [music_assistant.helpers.audio] Start analyzing track spotify://track/3UXlNmWG0HIM6GvAfhpywS
2022-12-16 12:10:16.436 DEBUG (MainThread) [music_assistant.helpers.audio] stripped silence of pcm chunk. size before: 994896 - after: 959616
2022-12-16 12:10:16.452 DEBUG (MainThread) [music_assistant.players.stream] Finished Streaming queue track: spotify://track/3UXlNmWG0HIM6GvAfhpywS (Regarde Les Hommes Tomber - A Sheep Among the Wolves) on queue Keuken
2022-12-16 12:10:17.400 DEBUG (MainThread) [music_assistant.music.spotify] Retrieved Spotify token using librespot in 0.93 seconds
2022-12-16 12:10:17.400 INFO (MainThread) [music_assistant.music.spotify] Succesfully logged in to Spotify as gieljnssns
2022-12-16 12:10:17.547 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/tracks/0sluGMFZwv54E49EiT9fpR took 0.15 seconds
2022-12-16 12:10:17.548 DEBUG (MainThread) [music_assistant.event] background_job_updated Add spotify://track/0sluGMFZwv54E49EiT9fpR to database
2022-12-16 12:10:17.550 DEBUG (MainThread) [music_assistant.event] background_job_updated Add spotify://track/0sluGMFZwv54E49EiT9fpR to database
2022-12-16 12:10:17.568 DEBUG (MainThread) [music_assistant.music.spotify] Retrieved Spotify token using librespot in 1.17 seconds
2022-12-16 12:10:17.569 INFO (MainThread) [music_assistant.music.spotify] Succesfully logged in to Spotify as gieljnssns
2022-12-16 12:10:17.639 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/albums/1aHI4Wf76A56D9be19dH9s took 0.08 seconds
2022-12-16 12:10:17.640 DEBUG (MainThread) [music_assistant.event] background_job_updated Add spotify://album/1aHI4Wf76A56D9be19dH9s to database
2022-12-16 12:10:17.641 DEBUG (MainThread) [music_assistant.event] background_job_updated Add spotify://album/1aHI4Wf76A56D9be19dH9s to database
2022-12-16 12:10:17.703 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/artists/0HMp1acohafGJGRKroPGaj took 0.05 seconds
2022-12-16 12:10:17.704 DEBUG (MainThread) [music_assistant.event] background_job_updated Add spotify://artist/0HMp1acohafGJGRKroPGaj to database
2022-12-16 12:10:17.785 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/artists/0HMp1acohafGJGRKroPGaj took 0.06 seconds
2022-12-16 12:10:17.785 DEBUG (MainThread) [music_assistant] Ignored duplicate job: Add spotify://artist/0HMp1acohafGJGRKroPGaj to database
2022-12-16 12:10:17.807 DEBUG (MainThread) [music_assistant.music.artist] added Purple Hill Witch to database
2022-12-16 12:10:17.839 DEBUG (MainThread) [music_assistant.music.artist] updated Purple Hill Witch in database: 443
2022-12-16 12:10:17.867 DEBUG (MainThread) [music_assistant.music.album] added Purple Hill Witch to database
2022-12-16 12:10:17.871 DEBUG (MainThread) [music_assistant.music.album] Trying to match album Purple Hill Witch on provider Filesystem
2022-12-16 12:10:17.909 DEBUG (MainThread) [music_assistant.music.album] updated Purple Hill Witch in database: 354
2022-12-16 12:10:17.911 DEBUG (MainThread) [music_assistant.music.album] Could not find match for Album Purple Hill Witch on provider Filesystem
2022-12-16 12:10:17.938 DEBUG (MainThread) [music_assistant.music.track] added The Landing to database: 2013
2022-12-16 12:10:17.942 DEBUG (MainThread) [music_assistant.music.track] Trying to match track The Landing on provider Spotify
2022-12-16 12:10:18.474 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/tracks/0sluGMFZwv54E49EiT9fpR took 0.07 seconds
2022-12-16 12:10:18.494 INFO (MainThread) [music_assistant.players.stream] Start Streaming queue track: spotify://track/0sluGMFZwv54E49EiT9fpR (Purple Hill Witch - The Landing) for queue Keuken - crossfade: False
2022-12-16 12:10:18.494 DEBUG (MainThread) [music_assistant.event] queue_updated media_player.keuken
2022-12-16 12:10:18.530 DEBUG (MainThread) [music_assistant.helpers.audio] start media stream for: spotify://track/0sluGMFZwv54E49EiT9fpR
2022-12-16 12:10:18.530 DEBUG (MainThread) [music_assistant.helpers.audio] writer started for spotify://track/0sluGMFZwv54E49EiT9fpR
2022-12-16 12:10:18.788 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/albums/1aHI4Wf76A56D9be19dH9s took 0.13 seconds
2022-12-16 12:10:18.816 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/search took 0.24 seconds
2022-12-16 12:10:18.841 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/albums/1aHI4Wf76A56D9be19dH9s/tracks took 0.05 seconds
2022-12-16 12:10:18.936 DEBUG (MainThread) [music_assistant.music.track] added Queen of the Hill to database: 2014
2022-12-16 12:10:18.967 DEBUG (MainThread) [music_assistant.music.track] added Astral Booze to database: 2015
2022-12-16 12:10:18.994 DEBUG (MainThread) [music_assistant.music.track] added The Final Procession to database: 2016
2022-12-16 12:10:19.032 DEBUG (MainThread) [music_assistant.music.track] added Karmanjaka to database: 2017
2022-12-16 12:10:19.085 DEBUG (MainThread) [music_assistant.music.track] updated The Landing in database: 2013
2022-12-16 12:10:19.131 DEBUG (MainThread) [music_assistant.music.track] added Aldebaranian Voyage (Into the Sun) to database: 2018
2022-12-16 12:10:19.186 DEBUG (MainThread) [music_assistant.music.track] added Purple Hill Witch to database: 2019
2022-12-16 12:10:19.195 DEBUG (MainThread) [music_assistant.event] media_item_added database://album/354
2022-12-16 12:10:19.196 INFO (MainThread) [music_assistant] Finished job [Add spotify://album/1aHI4Wf76A56D9be19dH9s to database] in 1.55 seconds.
2022-12-16 12:10:19.196 DEBUG (MainThread) [music_assistant.event] background_job_finished Add spotify://album/1aHI4Wf76A56D9be19dH9s to database
2022-12-16 12:10:19.197 DEBUG (MainThread) [music_assistant.event] background_job_updated Add spotify://artist/0HMp1acohafGJGRKroPGaj to database
2022-12-16 12:10:19.627 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/artists/0HMp1acohafGJGRKroPGaj/albums?include_groups=album,single,compilation took 0.05 seconds
2022-12-16 12:10:19.631 DEBUG (MainThread) [music_assistant.audiodb] Lookup MusicbrainzID for Artist Purple Hill Witch on TheAudioDb
2022-12-16 12:10:19.642 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/search took 0.23 seconds
2022-12-16 12:10:19.760 DEBUG (MainThread) [music_assistant.music.track] updated The Landing in database: 2013
2022-12-16 12:10:19.763 DEBUG (MainThread) [music_assistant.music.track] Trying to match track The Landing on provider Filesystem
2022-12-16 12:10:19.769 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/artists/0HMp1acohafGJGRKroPGaj took 0.05 seconds
2022-12-16 12:10:19.796 DEBUG (MainThread) [music_assistant.music.track] Could not find match for Track The Landing on provider Filesystem
2022-12-16 12:10:19.799 DEBUG (MainThread) [music_assistant.event] media_item_added database://track/2013
2022-12-16 12:10:19.799 INFO (MainThread) [music_assistant] Finished job [Add spotify://track/0sluGMFZwv54E49EiT9fpR to database] in 2.25 seconds.
2022-12-16 12:10:19.799 DEBUG (MainThread) [music_assistant.event] background_job_finished Add spotify://track/0sluGMFZwv54E49EiT9fpR to database
2022-12-16 12:10:19.875 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/artists/0HMp1acohafGJGRKroPGaj/top-tracks took 0.07 seconds
2022-12-16 12:10:19.878 DEBUG (MainThread) [music_assistant.musicbrainz] searching musicbrainz for Purple Hill Witch                 (albumname: None - album_upc: None - trackname: None - track_isrc: DEW271301585)
2022-12-16 12:10:19.999 DEBUG (MainThread) [music_assistant.musicbrainz] searching musicbrainz for Purple Hill Witch                 (albumname: None - album_upc: None - trackname: None - track_isrc: DEW271301584)
2022-12-16 12:10:20.937 DEBUG (MainThread) [music_assistant.musicbrainz] searching musicbrainz for Purple Hill Witch                 (albumname: None - album_upc: None - trackname: None - track_isrc: DEW271301583)
2022-12-16 12:10:21.960 DEBUG (MainThread) [music_assistant.musicbrainz] searching musicbrainz for Purple Hill Witch                 (albumname: None - album_upc: None - trackname: None - track_isrc: DEW271305590)
2022-12-16 12:10:22.963 DEBUG (MainThread) [music_assistant.musicbrainz] searching musicbrainz for Purple Hill Witch                 (albumname: None - album_upc: None - trackname: None - track_isrc: DEW271301588)
2022-12-16 12:10:23.972 DEBUG (MainThread) [music_assistant.musicbrainz] searching musicbrainz for Purple Hill Witch                 (albumname: None - album_upc: None - trackname: None - track_isrc: DEW271301589)
2022-12-16 12:10:24.978 DEBUG (MainThread) [music_assistant.musicbrainz] searching musicbrainz for Purple Hill Witch                 (albumname: None - album_upc: None - trackname: None - track_isrc: DEW271305591)
2022-12-16 12:10:25.984 DEBUG (MainThread) [music_assistant.musicbrainz] searching musicbrainz for Purple Hill Witch                 (albumname: None - album_upc: None - trackname: None - track_isrc: DEW271301586)
2022-12-16 12:10:26.978 DEBUG (MainThread) [music_assistant.musicbrainz] searching musicbrainz for Purple Hill Witch                 (albumname: None - album_upc: None - trackname: None - track_isrc: DEW271301587)
2022-12-16 12:10:27.986 DEBUG (MainThread) [music_assistant.musicbrainz] searching musicbrainz for Purple Hill Witch                 (albumname: None - album_upc: None - trackname: None - track_isrc: DEW271305592)
2022-12-16 12:10:28.999 DEBUG (MainThread) [music_assistant.musicbrainz] searching musicbrainz for Purple Hill Witch                 (albumname: None - album_upc: None - trackname: The Final Procession - track_isrc: None)
2022-12-16 12:10:30.061 DEBUG (MainThread) [music_assistant.musicbrainz] searching musicbrainz for Purple Hill Witch                 (albumname: None - album_upc: None - trackname: Astral Booze - track_isrc: None)
2022-12-16 12:10:31.022 DEBUG (MainThread) [music_assistant.musicbrainz] Got MusicbrainzArtistId for Purple Hill Witch after search on trackname Astral Booze --> ca86dc7f-a3cc-40e1-a172-958183e2569e
2022-12-16 12:10:31.022 DEBUG (MainThread) [music_assistant.fanarttv] Fetching metadata for Artist Purple Hill Witch on Fanart.tv
2022-12-16 12:10:31.190 DEBUG (MainThread) [music_assistant.audiodb] Fetching metadata for Artist Purple Hill Witch on TheAudioDb
2022-12-16 12:10:31.274 DEBUG (MainThread) [music_assistant.music.artist] updated Purple Hill Witch in database: 443
2022-12-16 12:10:31.276 DEBUG (MainThread) [music_assistant.music.artist] Trying to match artist Purple Hill Witch on provider Filesystem
2022-12-16 12:10:31.533 DEBUG (MainThread) [music_assistant.music.artist] Could not find match for Artist Purple Hill Witch on provider Filesystem
2022-12-16 12:10:31.535 DEBUG (MainThread) [music_assistant.event] media_item_updated database://artist/443
2022-12-16 12:10:31.535 INFO (MainThread) [music_assistant] Finished job [Add spotify://artist/0HMp1acohafGJGRKroPGaj to database] in 12.34 seconds.
2022-12-16 12:10:31.535 DEBUG (MainThread) [music_assistant.event] background_job_finished Add spotify://artist/0HMp1acohafGJGRKroPGaj to database
2022-12-16 12:10:31.842 DEBUG (MainThread) [music_assistant.helpers.audio] Integrated loudness of spotify://track/3UXlNmWG0HIM6GvAfhpywS is: -5.4
2022-12-16 12:10:31.842 INFO (MainThread) [music_assistant] Finished job [Analyze audio for spotify://track/3UXlNmWG0HIM6GvAfhpywS] in 15.45 seconds.
2022-12-16 12:10:31.842 DEBUG (MainThread) [music_assistant.event] background_job_finished Analyze audio for spotify://track/3UXlNmWG0HIM6GvAfhpywS
2022-12-16 12:10:55.190 DEBUG (MainThread) [music_assistant.players] Creating snapshot...
2022-12-16 12:10:58.264 DEBUG (MainThread) [music_assistant.players.stream] client disconnected: 192.168.79.84
2022-12-16 12:10:58.311 DEBUG (MainThread) [music_assistant.event] queue_updated media_player.keuken
2022-12-16 12:10:58.320 DEBUG (MainThread) [music_assistant.event] player_updated media_player.keuken
2022-12-16 12:10:58.328 DEBUG (MainThread) [music_assistant.event] queue_updated media_player.move
2022-12-16 12:10:58.331 DEBUG (MainThread) [music_assistant.event] player_updated media_player.move
2022-12-16 12:10:58.339 DEBUG (MainThread) [music_assistant.event] queue_updated media_player.keuken
2022-12-16 12:10:58.345 DEBUG (MainThread) [music_assistant.event] player_updated media_player.keuken
2022-12-16 12:11:01.303 DEBUG (MainThread) [music_assistant.event] player_updated media_player.keuken
2022-12-16 12:11:01.304 DEBUG (MainThread) [music_assistant.event] player_updated media_player.move
2022-12-16 12:11:02.436 DEBUG (MainThread) [music_assistant.event] queue_updated media_player.keuken
2022-12-16 12:11:02.442 DEBUG (MainThread) [music_assistant.event] player_updated media_player.keuken
2022-12-16 12:11:02.449 DEBUG (MainThread) [music_assistant.event] player_updated media_player.move
2022-12-16 12:11:02.497 DEBUG (MainThread) [music_assistant.event] queue_updated media_player.keuken
2022-12-16 12:11:02.502 DEBUG (MainThread) [music_assistant.event] player_updated media_player.keuken
2022-12-16 12:11:02.650 DEBUG (MainThread) [music_assistant.event] queue_updated media_player.keuken
2022-12-16 12:11:02.653 DEBUG (MainThread) [music_assistant.event] player_updated media_player.keuken
2022-12-16 12:11:02.654 DEBUG (MainThread) [music_assistant.event] queue_updated media_player.move
2022-12-16 12:11:02.658 DEBUG (MainThread) [music_assistant.event] player_updated media_player.move
2022-12-16 12:11:03.296 DEBUG (MainThread) [music_assistant.helpers.audio] media stream aborted for: spotify://track/0sluGMFZwv54E49EiT9fpR
2022-12-16 12:11:03.297 DEBUG (MainThread) [music_assistant.event] background_job_updated Analyze audio for spotify://track/0sluGMFZwv54E49EiT9fpR
2022-12-16 12:11:03.297 DEBUG (MainThread) [music_assistant.event] background_job_updated Analyze audio for spotify://track/0sluGMFZwv54E49EiT9fpR
2022-12-16 12:11:03.298 DEBUG (MainThread) [music_assistant.helpers.audio] Start analyzing track spotify://track/0sluGMFZwv54E49EiT9fpR
2022-12-16 12:11:05.961 DEBUG (MainThread) [music_assistant.players.stream] Stream job 00e430d93dea4d8d82f4f75015201f14 cleaned up
2022-12-16 12:11:05.961 DEBUG (MainThread) [music_assistant.players.stream] Stream job 00e430d93dea4d8d82f4f75015201f14 cleaned up
2022-12-16 12:11:06.679 DEBUG (MainThread) [music_assistant.event] queue_updated media_player.keuken
2022-12-16 12:11:06.682 DEBUG (MainThread) [music_assistant.event] player_updated media_player.keuken
2022-12-16 12:11:06.683 DEBUG (MainThread) [music_assistant.event] queue_updated media_player.move
2022-12-16 12:11:06.684 DEBUG (MainThread) [music_assistant.event] player_updated media_player.move
2022-12-16 12:11:07.007 DEBUG (MainThread) [music_assistant.helpers.audio] Integrated loudness of spotify://track/0sluGMFZwv54E49EiT9fpR is: -8.4
2022-12-16 12:11:07.008 INFO (MainThread) [music_assistant] Finished job [Analyze audio for spotify://track/0sluGMFZwv54E49EiT9fpR] in 3.71 seconds.
2022-12-16 12:11:07.008 DEBUG (MainThread) [music_assistant.event] background_job_finished Analyze audio for spotify://track/0sluGMFZwv54E49EiT9fpR
2022-12-16 12:11:07.747 DEBUG (MainThread) [music_assistant.event] queue_items_updated media_player.keuken
2022-12-16 12:11:07.747 DEBUG (MainThread) [music_assistant.event] queue_updated media_player.keuken
2022-12-16 12:11:07.779 DEBUG (MainThread) [music_assistant.event] queue_items_updated media_player.keuken
2022-12-16 12:11:07.987 DEBUG (MainThread) [music_assistant.event] queue_updated media_player.keuken
2022-12-16 12:11:08.229 DEBUG (MainThread) [music_assistant.event] queue_updated media_player.keuken
2022-12-16 12:11:08.232 DEBUG (MainThread) [music_assistant.event] player_updated media_player.keuken
2022-12-16 12:11:08.235 DEBUG (MainThread) [music_assistant.event] player_updated media_player.move
2022-12-16 12:11:08.974 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/tracks/3UXlNmWG0HIM6GvAfhpywS took 0.2 seconds
2022-12-16 12:11:08.993 DEBUG (MainThread) [music_assistant.players.stream] Starting Queue audio stream for Queue Keuken (PCM format: s16le - sample rate: 44100)
2022-12-16 12:11:09.017 DEBUG (MainThread) [music_assistant.players] Restored snapshot...
2022-12-16 12:11:09.018 DEBUG (MainThread) [music_assistant.stream] Got GET request to /f1c466bc94aa4d5bbdabe2fa6404c4ab.flac from 192.168.79.84
2022-12-16 12:11:09.019 DEBUG (MainThread) [music_assistant.players.stream] client connected: 192.168.79.84
2022-12-16 12:11:09.019 DEBUG (MainThread) [music_assistant.players.stream] 1 clients connected
2022-12-16 12:11:09.022 DEBUG (MainThread) [music_assistant.event] queue_updated media_player.keuken
2022-12-16 12:11:09.023 DEBUG (MainThread) [music_assistant.event] player_updated media_player.keuken
2022-12-16 12:11:09.075 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/tracks/3UXlNmWG0HIM6GvAfhpywS took 0.07 seconds
2022-12-16 12:11:09.082 INFO (MainThread) [music_assistant.players.stream] Start Streaming queue track: spotify://track/3UXlNmWG0HIM6GvAfhpywS (Regarde Les Hommes Tomber - A Sheep Among the Wolves) for queue Keuken - crossfade: False
2022-12-16 12:11:09.082 DEBUG (MainThread) [music_assistant.event] queue_updated media_player.keuken
2022-12-16 12:11:09.109 DEBUG (MainThread) [music_assistant.helpers.audio] start media stream for: spotify://track/3UXlNmWG0HIM6GvAfhpywS
2022-12-16 12:11:09.109 DEBUG (MainThread) [music_assistant.helpers.audio] writer started for spotify://track/3UXlNmWG0HIM6GvAfhpywS
2022-12-16 12:11:10.472 DEBUG (MainThread) [music_assistant.event] queue_updated media_player.keuken
2022-12-16 12:11:10.479 DEBUG (MainThread) [music_assistant.event] player_updated media_player.keuken
2022-12-16 12:11:10.482 DEBUG (MainThread) [music_assistant.event] queue_updated media_player.move
2022-12-16 12:11:10.485 DEBUG (MainThread) [music_assistant.event] player_updated media_player.move
2022-12-16 12:11:14.853 DEBUG (MainThread) [music_assistant.helpers.audio] writer finished for spotify://track/3UXlNmWG0HIM6GvAfhpywS
2022-12-16 12:11:19.263 DEBUG (MainThread) [music_assistant.helpers.audio] finished media stream for: spotify://track/3UXlNmWG0HIM6GvAfhpywS
2022-12-16 12:11:19.278 DEBUG (MainThread) [music_assistant.players.stream] end of track reached - chunk_num: 180 - crossfade_buffer: 5.612607709750567 - stream_duration: 179 - player_buffer: 166.0 - process_time: 10.19
2022-12-16 12:11:19.316 DEBUG (MainThread) [music_assistant.helpers.audio] stripped silence of pcm chunk. size before: 990064 - after: 954784
2022-12-16 12:11:19.328 DEBUG (MainThread) [music_assistant.players.stream] Finished Streaming queue track: spotify://track/3UXlNmWG0HIM6GvAfhpywS (Regarde Les Hommes Tomber - A Sheep Among the Wolves) on queue Keuken
2022-12-16 12:11:19.414 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/tracks/0sluGMFZwv54E49EiT9fpR took 0.07 seconds
2022-12-16 12:11:19.420 INFO (MainThread) [music_assistant.players.stream] Start Streaming queue track: spotify://track/0sluGMFZwv54E49EiT9fpR (Purple Hill Witch - The Landing) for queue Keuken - crossfade: False
2022-12-16 12:11:19.420 DEBUG (MainThread) [music_assistant.event] queue_updated media_player.keuken
2022-12-16 12:11:19.460 DEBUG (MainThread) [music_assistant.helpers.audio] start media stream for: spotify://track/0sluGMFZwv54E49EiT9fpR
2022-12-16 12:11:19.461 DEBUG (MainThread) [music_assistant.helpers.audio] writer started for spotify://track/0sluGMFZwv54E49EiT9fpR
2022-12-16 12:12:58.152 DEBUG (MainThread) [music_assistant.helpers.audio] writer finished for spotify://track/0sluGMFZwv54E49EiT9fpR
2022-12-16 12:14:11.467 DEBUG (MainThread) [music_assistant.event] queue_updated media_player.keuken
2022-12-16 12:14:11.534 DEBUG (MainThread) [music_assistant.event] queue_updated media_player.keuken
2022-12-16 12:14:45.985 DEBUG (MainThread) [music_assistant.helpers.audio] finished media stream for: spotify://track/0sluGMFZwv54E49EiT9fpR
2022-12-16 12:14:46.013 DEBUG (MainThread) [music_assistant.players.stream] end of track reached - chunk_num: 279 - crossfade_buffer: 5.906666666666666 - stream_duration: 278 - player_buffer: 237.41260770975055 - process_time: 206.59
2022-12-16 12:14:46.063 DEBUG (MainThread) [music_assistant.helpers.audio] stripped silence of pcm chunk. size before: 1041936 - after: 690576
2022-12-16 12:14:46.071 DEBUG (MainThread) [music_assistant.players.stream] Finished Streaming queue track: spotify://track/0sluGMFZwv54E49EiT9fpR (Purple Hill Witch - The Landing) on queue Keuken
2022-12-16 12:14:46.235 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/tracks/7hGX9uaGHKo75dg3aiUJ2L took 0.15 seconds
2022-12-16 12:14:46.235 DEBUG (MainThread) [music_assistant.event] background_job_updated Add spotify://track/7hGX9uaGHKo75dg3aiUJ2L to database
2022-12-16 12:14:46.237 DEBUG (MainThread) [music_assistant.event] background_job_updated Add spotify://track/7hGX9uaGHKo75dg3aiUJ2L to database
2022-12-16 12:14:46.313 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/albums/3rik25Bas4Gyt2VZXWiSTc took 0.06 seconds
2022-12-16 12:14:46.314 DEBUG (MainThread) [music_assistant.event] background_job_updated Add spotify://album/3rik25Bas4Gyt2VZXWiSTc to database
2022-12-16 12:14:46.316 DEBUG (MainThread) [music_assistant.event] background_job_updated Add spotify://album/3rik25Bas4Gyt2VZXWiSTc to database
2022-12-16 12:14:46.424 DEBUG (MainThread) [music_assistant.music.album] added Grievances to database
2022-12-16 12:14:46.436 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/tracks/7hGX9uaGHKo75dg3aiUJ2L took 0.09 seconds
2022-12-16 12:14:46.467 INFO (MainThread) [music_assistant.players.stream] Start Streaming queue track: spotify://track/7hGX9uaGHKo75dg3aiUJ2L (Kowloon Walled City - White Walls) for queue Keuken - crossfade: False
2022-12-16 12:14:46.468 DEBUG (MainThread) [music_assistant.event] queue_updated media_player.keuken
2022-12-16 12:14:46.492 DEBUG (MainThread) [music_assistant.helpers.audio] start media stream for: spotify://track/7hGX9uaGHKo75dg3aiUJ2L
2022-12-16 12:14:46.493 DEBUG (MainThread) [music_assistant.helpers.audio] writer started for spotify://track/7hGX9uaGHKo75dg3aiUJ2L
2022-12-16 12:14:46.531 DEBUG (MainThread) [music_assistant.music.track] added White Walls to database: 2020
2022-12-16 12:14:46.536 DEBUG (MainThread) [music_assistant.music.track] Trying to match track White Walls on provider Spotify
2022-12-16 12:14:46.554 DEBUG (MainThread) [music_assistant.music.album] updated Grievances in database: 355
2022-12-16 12:14:46.559 DEBUG (MainThread) [music_assistant.music.album] Trying to match album Grievances on provider Filesystem
2022-12-16 12:14:46.585 DEBUG (MainThread) [music_assistant.music.album] Could not find match for Album Grievances on provider Filesystem
2022-12-16 12:14:46.768 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/search took 0.22 seconds
2022-12-16 12:14:47.304 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/search took 0.21 seconds
2022-12-16 12:14:47.391 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/albums/3rik25Bas4Gyt2VZXWiSTc took 0.13 seconds
2022-12-16 12:14:47.406 DEBUG (MainThread) [music_assistant.music.track] updated White Walls in database: 2020
2022-12-16 12:14:47.408 DEBUG (MainThread) [music_assistant.music.track] Trying to match track White Walls on provider Filesystem
2022-12-16 12:14:47.430 DEBUG (MainThread) [music_assistant.music.track] Could not find match for Track White Walls on provider Filesystem
2022-12-16 12:14:47.433 DEBUG (MainThread) [music_assistant.event] media_item_added database://track/2020
2022-12-16 12:14:47.433 INFO (MainThread) [music_assistant] Finished job [Add spotify://track/7hGX9uaGHKo75dg3aiUJ2L to database] in 1.2 seconds.
2022-12-16 12:14:47.433 DEBUG (MainThread) [music_assistant.event] background_job_finished Add spotify://track/7hGX9uaGHKo75dg3aiUJ2L to database
2022-12-16 12:14:47.472 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/albums/3rik25Bas4Gyt2VZXWiSTc/tracks took 0.07 seconds
2022-12-16 12:14:47.532 DEBUG (MainThread) [music_assistant.music.track] added Your Best Years to database: 2021
2022-12-16 12:14:47.580 DEBUG (MainThread) [music_assistant.music.track] added Grievances to database: 2022
2022-12-16 12:14:47.634 DEBUG (MainThread) [music_assistant.music.track] added Backlit to database: 2023
2022-12-16 12:14:47.682 DEBUG (MainThread) [music_assistant.music.track] added The Grift to database: 2024
2022-12-16 12:14:47.719 DEBUG (MainThread) [music_assistant.music.track] updated White Walls in database: 2020
2022-12-16 12:14:47.746 DEBUG (MainThread) [music_assistant.music.track] added True Believer to database: 2025
2022-12-16 12:14:47.780 DEBUG (MainThread) [music_assistant.music.track] added Daughters and Sons to database: 2026
2022-12-16 12:14:47.783 DEBUG (MainThread) [music_assistant.event] media_item_updated database://album/355
2022-12-16 12:14:47.784 INFO (MainThread) [music_assistant] Finished job [Add spotify://album/3rik25Bas4Gyt2VZXWiSTc to database] in 1.47 seconds.
2022-12-16 12:14:47.784 DEBUG (MainThread) [music_assistant.event] background_job_finished Add spotify://album/3rik25Bas4Gyt2VZXWiSTc to database
2022-12-16 12:17:35.453 DEBUG (MainThread) [music_assistant.helpers.audio] writer finished for spotify://track/7hGX9uaGHKo75dg3aiUJ2L
2022-12-16 12:18:47.892 DEBUG (MainThread) [music_assistant.event] queue_updated media_player.keuken
2022-12-16 12:18:47.972 DEBUG (MainThread) [music_assistant.event] queue_updated media_player.keuken
2022-12-16 12:19:29.743 DEBUG (MainThread) [music_assistant.helpers.audio] finished media stream for: spotify://track/7hGX9uaGHKo75dg3aiUJ2L
2022-12-16 12:19:29.762 DEBUG (MainThread) [music_assistant.event] background_job_updated Analyze audio for spotify://track/7hGX9uaGHKo75dg3aiUJ2L
2022-12-16 12:19:29.762 DEBUG (MainThread) [music_assistant.players.stream] end of track reached - chunk_num: 287 - crossfade_buffer: 5.56 - stream_duration: 286 - player_buffer: 238.32743764172335 - process_time: 283.29
2022-12-16 12:19:29.764 DEBUG (MainThread) [music_assistant.event] background_job_updated Analyze audio for spotify://track/7hGX9uaGHKo75dg3aiUJ2L
2022-12-16 12:19:29.764 DEBUG (MainThread) [music_assistant.helpers.audio] Start analyzing track spotify://track/7hGX9uaGHKo75dg3aiUJ2L
2022-12-16 12:19:29.799 DEBUG (MainThread) [music_assistant.helpers.audio] stripped silence of pcm chunk. size before: 980784 - after: 876452
2022-12-16 12:19:29.810 DEBUG (MainThread) [music_assistant.players.stream] Finished Streaming queue track: spotify://track/7hGX9uaGHKo75dg3aiUJ2L (Kowloon Walled City - White Walls) on queue Keuken
2022-12-16 12:19:29.957 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/tracks/5rLhMDfqCVSIffjNf2xYbJ took 0.13 seconds
2022-12-16 12:19:29.958 DEBUG (MainThread) [music_assistant.event] background_job_updated Add spotify://track/5rLhMDfqCVSIffjNf2xYbJ to database
2022-12-16 12:19:29.960 DEBUG (MainThread) [music_assistant.event] background_job_updated Add spotify://track/5rLhMDfqCVSIffjNf2xYbJ to database
2022-12-16 12:19:30.038 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/albums/4IG4E3m4wYVkuLzSVF8beM took 0.06 seconds
2022-12-16 12:19:30.038 DEBUG (MainThread) [music_assistant.event] background_job_updated Add spotify://album/4IG4E3m4wYVkuLzSVF8beM to database
2022-12-16 12:19:30.039 DEBUG (MainThread) [music_assistant.event] background_job_updated Add spotify://album/4IG4E3m4wYVkuLzSVF8beM to database
2022-12-16 12:19:30.112 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/artists/0nsphA9KDqbJ64duYRoEBi took 0.06 seconds
2022-12-16 12:19:30.113 DEBUG (MainThread) [music_assistant.event] background_job_updated Add spotify://artist/0nsphA9KDqbJ64duYRoEBi to database
2022-12-16 12:19:30.158 DEBUG (MainThread) [music_assistant.fanarttv] Fetching metadata for Album Black Heaven on Fanart.tv
2022-12-16 12:19:30.184 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/artists/0nsphA9KDqbJ64duYRoEBi took 0.05 seconds
2022-12-16 12:19:30.184 DEBUG (MainThread) [music_assistant] Ignored duplicate job: Add spotify://artist/0nsphA9KDqbJ64duYRoEBi to database
2022-12-16 12:19:30.241 DEBUG (MainThread) [music_assistant.music.artist] added Earthless to database
2022-12-16 12:19:30.298 DEBUG (MainThread) [music_assistant.music.album] added Black Heaven to database
2022-12-16 12:19:30.326 DEBUG (MainThread) [music_assistant.music.track] added Gifted by the Wind to database: 2027
2022-12-16 12:19:30.352 DEBUG (MainThread) [music_assistant.music.track] Trying to match track Gifted by the Wind on provider Spotify
2022-12-16 12:19:30.388 DEBUG (MainThread) [music_assistant.music.album] updated Black Heaven in database: 356
2022-12-16 12:19:30.393 DEBUG (MainThread) [music_assistant.music.album] Trying to match album Black Heaven on provider Filesystem
2022-12-16 12:19:30.422 DEBUG (MainThread) [music_assistant.music.album] Could not find match for Album Black Heaven on provider Filesystem
2022-12-16 12:19:31.090 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/albums/4IG4E3m4wYVkuLzSVF8beM took 0.11 seconds
2022-12-16 12:19:31.100 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/search took 0.27 seconds
2022-12-16 12:19:31.180 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/tracks/5rLhMDfqCVSIffjNf2xYbJ took 0.12 seconds
2022-12-16 12:19:31.185 DEBUG (MainThread) [music_assistant.music.track] updated Gifted by the Wind in database: 2027
2022-12-16 12:19:31.188 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/albums/4IG4E3m4wYVkuLzSVF8beM/tracks took 0.05 seconds
2022-12-16 12:19:31.190 DEBUG (MainThread) [music_assistant.music.track] Trying to match track Gifted by the Wind on provider Filesystem
2022-12-16 12:19:31.193 INFO (MainThread) [music_assistant.players.stream] Start Streaming queue track: spotify://track/5rLhMDfqCVSIffjNf2xYbJ (Earthless - Gifted by the Wind) for queue Keuken - crossfade: False
2022-12-16 12:19:31.193 DEBUG (MainThread) [music_assistant.event] queue_updated media_player.keuken
2022-12-16 12:19:31.208 DEBUG (MainThread) [music_assistant.helpers.audio] start media stream for: spotify://track/5rLhMDfqCVSIffjNf2xYbJ
2022-12-16 12:19:31.208 DEBUG (MainThread) [music_assistant.helpers.audio] writer started for spotify://track/5rLhMDfqCVSIffjNf2xYbJ
2022-12-16 12:19:31.291 DEBUG (MainThread) [music_assistant.music.track] updated Gifted by the Wind in database: 2027
2022-12-16 12:19:31.294 DEBUG (MainThread) [music_assistant.music.track] Could not find match for Track Gifted by the Wind on provider Filesystem
2022-12-16 12:19:31.296 DEBUG (MainThread) [music_assistant.event] media_item_added database://track/2027
2022-12-16 12:19:31.297 INFO (MainThread) [music_assistant] Finished job [Add spotify://track/5rLhMDfqCVSIffjNf2xYbJ to database] in 1.34 seconds.
2022-12-16 12:19:31.297 DEBUG (MainThread) [music_assistant.event] background_job_finished Add spotify://track/5rLhMDfqCVSIffjNf2xYbJ to database
2022-12-16 12:19:31.297 DEBUG (MainThread) [music_assistant.event] background_job_updated Add spotify://artist/0nsphA9KDqbJ64duYRoEBi to database
2022-12-16 12:19:31.297 DEBUG (MainThread) [music_assistant.fanarttv] Fetching metadata for Artist Earthless on Fanart.tv
2022-12-16 12:19:31.327 DEBUG (MainThread) [music_assistant.music.track] added End to End to database: 2028
2022-12-16 12:19:31.338 DEBUG (MainThread) [music_assistant.audiodb] Fetching metadata for Artist Earthless on TheAudioDb
2022-12-16 12:19:31.372 DEBUG (MainThread) [music_assistant.music.track] added Electric Flame to database: 2029
2022-12-16 12:19:31.417 DEBUG (MainThread) [music_assistant.music.track] added Volt Rush to database: 2030
2022-12-16 12:19:31.437 DEBUG (MainThread) [music_assistant.music.artist] updated Earthless in database: 444
2022-12-16 12:19:31.442 DEBUG (MainThread) [music_assistant.music.artist] Trying to match artist Earthless on provider Filesystem
2022-12-16 12:19:31.462 DEBUG (MainThread) [music_assistant.music.track] added Black Heaven to database: 2031
2022-12-16 12:19:31.494 DEBUG (MainThread) [music_assistant.music.track] added Sudden End to database: 2032
2022-12-16 12:19:31.496 DEBUG (MainThread) [music_assistant.event] media_item_updated database://album/356
2022-12-16 12:19:31.497 INFO (MainThread) [music_assistant] Finished job [Add spotify://album/4IG4E3m4wYVkuLzSVF8beM to database] in 1.46 seconds.
2022-12-16 12:19:31.497 DEBUG (MainThread) [music_assistant.event] background_job_finished Add spotify://album/4IG4E3m4wYVkuLzSVF8beM to database
2022-12-16 12:19:31.886 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/artists/0nsphA9KDqbJ64duYRoEBi took 0.06 seconds
2022-12-16 12:19:32.076 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/artists/0nsphA9KDqbJ64duYRoEBi/top-tracks took 0.08 seconds
2022-12-16 12:19:32.451 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/artists/0nsphA9KDqbJ64duYRoEBi/albums?include_groups=album,single,compilation took 0.05 seconds
2022-12-16 12:19:32.777 DEBUG (MainThread) [music_assistant.music.artist] Could not find match for Artist Earthless on provider Filesystem
2022-12-16 12:19:32.779 DEBUG (MainThread) [music_assistant.event] media_item_updated database://artist/444
2022-12-16 12:19:32.780 INFO (MainThread) [music_assistant] Finished job [Add spotify://artist/0nsphA9KDqbJ64duYRoEBi to database] in 1.48 seconds.
2022-12-16 12:19:32.780 DEBUG (MainThread) [music_assistant.event] background_job_finished Add spotify://artist/0nsphA9KDqbJ64duYRoEBi to database
2022-12-16 12:19:43.970 DEBUG (MainThread) [music_assistant.helpers.audio] Integrated loudness of spotify://track/7hGX9uaGHKo75dg3aiUJ2L is: -5.8
2022-12-16 12:19:43.970 INFO (MainThread) [music_assistant] Finished job [Analyze audio for spotify://track/7hGX9uaGHKo75dg3aiUJ2L] in 14.21 seconds.
2022-12-16 12:19:43.971 DEBUG (MainThread) [music_assistant.event] background_job_finished Analyze audio for spotify://track/7hGX9uaGHKo75dg3aiUJ2L
2022-12-16 12:23:34.419 DEBUG (MainThread) [music_assistant.event] queue_updated media_player.keuken
2022-12-16 12:23:34.510 DEBUG (MainThread) [music_assistant.event] queue_updated media_player.keuken
2022-12-16 12:24:19.704 DEBUG (MainThread) [music_assistant.helpers.audio] writer finished for spotify://track/5rLhMDfqCVSIffjNf2xYbJ
2022-12-16 12:26:03.219 DEBUG (MainThread) [music_assistant.helpers.audio] finished media stream for: spotify://track/5rLhMDfqCVSIffjNf2xYbJ
2022-12-16 12:26:03.242 DEBUG (MainThread) [music_assistant.event] background_job_updated Analyze audio for spotify://track/5rLhMDfqCVSIffjNf2xYbJ
2022-12-16 12:26:03.243 DEBUG (MainThread) [music_assistant.players.stream] end of track reached - chunk_num: 389 - crossfade_buffer: 5.72 - stream_duration: 388 - player_buffer: 233.29598639455799 - process_time: 392.05
2022-12-16 12:26:03.244 DEBUG (MainThread) [music_assistant.event] background_job_updated Analyze audio for spotify://track/5rLhMDfqCVSIffjNf2xYbJ
2022-12-16 12:26:03.245 DEBUG (MainThread) [music_assistant.helpers.audio] Start analyzing track spotify://track/5rLhMDfqCVSIffjNf2xYbJ
2022-12-16 12:26:03.280 DEBUG (MainThread) [music_assistant.helpers.audio] stripped silence of pcm chunk. size before: 1009008 - after: 693528
2022-12-16 12:26:03.292 DEBUG (MainThread) [music_assistant.players.stream] Finished Streaming queue track: spotify://track/5rLhMDfqCVSIffjNf2xYbJ (Earthless - Gifted by the Wind) on queue Keuken
2022-12-16 12:26:03.441 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/tracks/0xbavqZPPWB3h1iK2QR7Xf took 0.14 seconds
2022-12-16 12:26:03.442 DEBUG (MainThread) [music_assistant.event] background_job_updated Add spotify://track/0xbavqZPPWB3h1iK2QR7Xf to database
2022-12-16 12:26:03.443 DEBUG (MainThread) [music_assistant.event] background_job_updated Add spotify://track/0xbavqZPPWB3h1iK2QR7Xf to database
2022-12-16 12:26:03.518 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/albums/51M3dERfSRwM7xhk8SezRy took 0.06 seconds
2022-12-16 12:26:03.519 DEBUG (MainThread) [music_assistant.event] background_job_updated Add spotify://album/51M3dERfSRwM7xhk8SezRy to database
2022-12-16 12:26:03.522 DEBUG (MainThread) [music_assistant.event] background_job_updated Add spotify://album/51M3dERfSRwM7xhk8SezRy to database
2022-12-16 12:26:03.613 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/artists/3qg85LFImCJ1zIefm6urwC took 0.06 seconds
2022-12-16 12:26:03.614 DEBUG (MainThread) [music_assistant.event] background_job_updated Add spotify://artist/3qg85LFImCJ1zIefm6urwC to database
2022-12-16 12:26:03.671 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/artists/3qg85LFImCJ1zIefm6urwC took 0.05 seconds
2022-12-16 12:26:03.672 DEBUG (MainThread) [music_assistant] Ignored duplicate job: Add spotify://artist/3qg85LFImCJ1zIefm6urwC to database
2022-12-16 12:26:03.692 DEBUG (MainThread) [music_assistant.music.artist] added Locrian to database
2022-12-16 12:26:03.734 DEBUG (MainThread) [music_assistant.music.artist] updated Locrian in database: 445
2022-12-16 12:26:03.761 DEBUG (MainThread) [music_assistant.music.album] added Return to Annihilation to database
2022-12-16 12:26:03.766 DEBUG (MainThread) [music_assistant.music.album] Trying to match album Return to Annihilation on provider Filesystem
2022-12-16 12:26:03.811 DEBUG (MainThread) [music_assistant.music.album] updated Return to Annihilation in database: 357
2022-12-16 12:26:03.814 DEBUG (MainThread) [music_assistant.music.album] Could not find match for Album Return to Annihilation on provider Filesystem
2022-12-16 12:26:03.841 DEBUG (MainThread) [music_assistant.music.track] added Exiting the Hall of Vapor and Light to database: 2033
2022-12-16 12:26:03.847 DEBUG (MainThread) [music_assistant.music.track] Trying to match track Exiting the Hall of Vapor and Light on provider Spotify
2022-12-16 12:26:04.541 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/search took 0.23 seconds
2022-12-16 12:26:04.588 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/albums/51M3dERfSRwM7xhk8SezRy took 0.12 seconds
2022-12-16 12:26:04.625 DEBUG (MainThread) [music_assistant.music.track] updated Exiting the Hall of Vapor and Light in database: 2033
2022-12-16 12:26:04.633 DEBUG (MainThread) [music_assistant.music.track] Trying to match track Exiting the Hall of Vapor and Light on provider Filesystem
2022-12-16 12:26:04.639 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/tracks/0xbavqZPPWB3h1iK2QR7Xf took 0.07 seconds
2022-12-16 12:26:04.652 INFO (MainThread) [music_assistant.players.stream] Start Streaming queue track: spotify://track/0xbavqZPPWB3h1iK2QR7Xf (Locrian - Exiting the Hall of Vapor and Light) for queue Keuken - crossfade: False
2022-12-16 12:26:04.652 DEBUG (MainThread) [music_assistant.event] queue_updated media_player.keuken
2022-12-16 12:26:04.684 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/albums/51M3dERfSRwM7xhk8SezRy/tracks took 0.06 seconds
2022-12-16 12:26:04.685 DEBUG (MainThread) [music_assistant.helpers.audio] start media stream for: spotify://track/0xbavqZPPWB3h1iK2QR7Xf
2022-12-16 12:26:04.688 DEBUG (MainThread) [music_assistant.helpers.audio] writer started for spotify://track/0xbavqZPPWB3h1iK2QR7Xf
2022-12-16 12:26:04.795 DEBUG (MainThread) [music_assistant.music.track] Could not find match for Track Exiting the Hall of Vapor and Light on provider Filesystem
2022-12-16 12:26:04.797 DEBUG (MainThread) [music_assistant.music.track] added Eternal Return to database: 2034
2022-12-16 12:26:04.800 DEBUG (MainThread) [music_assistant.event] media_item_added database://track/2033
2022-12-16 12:26:04.801 INFO (MainThread) [music_assistant] Finished job [Add spotify://track/0xbavqZPPWB3h1iK2QR7Xf to database] in 1.36 seconds.
2022-12-16 12:26:04.801 DEBUG (MainThread) [music_assistant.event] background_job_finished Add spotify://track/0xbavqZPPWB3h1iK2QR7Xf to database
2022-12-16 12:26:04.802 DEBUG (MainThread) [music_assistant.event] background_job_updated Add spotify://artist/3qg85LFImCJ1zIefm6urwC to database
2022-12-16 12:26:04.880 DEBUG (MainThread) [music_assistant.music.track] added A Visitation From the Wrath of Heaven to database: 2035
2022-12-16 12:26:04.931 DEBUG (MainThread) [music_assistant.music.track] added Two Moons to database: 2036
2022-12-16 12:26:04.979 DEBUG (MainThread) [music_assistant.music.track] added Return to Annihilation to database: 2037
2022-12-16 12:26:05.009 DEBUG (MainThread) [music_assistant.music.track] updated Exiting the Hall of Vapor and Light in database: 2033
2022-12-16 12:26:05.064 DEBUG (MainThread) [music_assistant.music.track] added Panorama of Mirrors to database: 2038
2022-12-16 12:26:05.114 DEBUG (MainThread) [music_assistant.music.track] added Obsolete Elegies to database: 2039
2022-12-16 12:26:05.119 DEBUG (MainThread) [music_assistant.event] media_item_added database://album/357
2022-12-16 12:26:05.120 INFO (MainThread) [music_assistant] Finished job [Add spotify://album/51M3dERfSRwM7xhk8SezRy to database] in 1.6 seconds.
2022-12-16 12:26:05.120 DEBUG (MainThread) [music_assistant.event] background_job_finished Add spotify://album/51M3dERfSRwM7xhk8SezRy to database
2022-12-16 12:26:05.481 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/artists/3qg85LFImCJ1zIefm6urwC/albums?include_groups=album,single,compilation took 0.17 seconds
2022-12-16 12:26:05.482 DEBUG (MainThread) [music_assistant.audiodb] Lookup MusicbrainzID for Artist Locrian on TheAudioDb
2022-12-16 12:26:05.594 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/artists/3qg85LFImCJ1zIefm6urwC took 0.05 seconds
2022-12-16 12:26:05.675 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/artists/3qg85LFImCJ1zIefm6urwC/top-tracks took 0.08 seconds
2022-12-16 12:26:05.677 DEBUG (MainThread) [music_assistant.musicbrainz] searching musicbrainz for Locrian                 (albumname: None - album_upc: None - trackname: None - track_isrc: US2641320401)
2022-12-16 12:26:05.788 DEBUG (MainThread) [music_assistant.musicbrainz] searching musicbrainz for Locrian                 (albumname: None - album_upc: None - trackname: None - track_isrc: USA2P1554330)
2022-12-16 12:26:06.750 DEBUG (MainThread) [music_assistant.musicbrainz] searching musicbrainz for Locrian                 (albumname: None - album_upc: None - trackname: None - track_isrc: USN682227701)
2022-12-16 12:26:07.741 DEBUG (MainThread) [music_assistant.musicbrainz] searching musicbrainz for Locrian                 (albumname: None - album_upc: None - trackname: None - track_isrc: USN682227702)
2022-12-16 12:26:08.766 DEBUG (MainThread) [music_assistant.musicbrainz] searching musicbrainz for Locrian                 (albumname: None - album_upc: None - trackname: None - track_isrc: USN682227703)
2022-12-16 12:26:09.751 DEBUG (MainThread) [music_assistant.musicbrainz] searching musicbrainz for Locrian                 (albumname: None - album_upc: None - trackname: None - track_isrc: USN682227704)
2022-12-16 12:26:10.759 DEBUG (MainThread) [music_assistant.musicbrainz] searching musicbrainz for Locrian                 (albumname: None - album_upc: None - trackname: None - track_isrc: US2641320403)
2022-12-16 12:26:11.817 DEBUG (MainThread) [music_assistant.musicbrainz] searching musicbrainz for Locrian                 (albumname: None - album_upc: None - trackname: None - track_isrc: US2641320404)
2022-12-16 12:26:12.765 DEBUG (MainThread) [music_assistant.musicbrainz] searching musicbrainz for Locrian                 (albumname: None - album_upc: None - trackname: None - track_isrc: US2641320402)
2022-12-16 12:26:13.772 DEBUG (MainThread) [music_assistant.musicbrainz] searching musicbrainz for Locrian                 (albumname: None - album_upc: None - trackname: None - track_isrc: US2641320405)
2022-12-16 12:26:14.773 DEBUG (MainThread) [music_assistant.musicbrainz] searching musicbrainz for Locrian                 (albumname: None - album_upc: None - trackname: Eternal Return - track_isrc: None)
2022-12-16 12:26:15.822 DEBUG (MainThread) [music_assistant.musicbrainz] Got MusicbrainzArtistId for Locrian after search on trackname Eternal Return --> cef918f7-5f8d-4816-a629-7969eab19394
2022-12-16 12:26:15.823 DEBUG (MainThread) [music_assistant.fanarttv] Fetching metadata for Artist Locrian on Fanart.tv
2022-12-16 12:26:15.985 DEBUG (MainThread) [music_assistant.audiodb] Fetching metadata for Artist Locrian on TheAudioDb
2022-12-16 12:26:16.102 DEBUG (MainThread) [music_assistant.music.artist] updated Locrian in database: 445
2022-12-16 12:26:16.106 DEBUG (MainThread) [music_assistant.music.artist] Trying to match artist Locrian on provider Filesystem
2022-12-16 12:26:16.608 DEBUG (MainThread) [music_assistant.music.artist] Could not find match for Artist Locrian on provider Filesystem
2022-12-16 12:26:16.610 DEBUG (MainThread) [music_assistant.event] media_item_updated database://artist/445
2022-12-16 12:26:16.610 INFO (MainThread) [music_assistant] Finished job [Add spotify://artist/3qg85LFImCJ1zIefm6urwC to database] in 11.81 seconds.
2022-12-16 12:26:16.610 DEBUG (MainThread) [music_assistant.event] background_job_finished Add spotify://artist/3qg85LFImCJ1zIefm6urwC to database
2022-12-16 12:26:19.524 DEBUG (MainThread) [music_assistant.helpers.audio] Integrated loudness of spotify://track/5rLhMDfqCVSIffjNf2xYbJ is: -8.0
2022-12-16 12:26:19.524 INFO (MainThread) [music_assistant] Finished job [Analyze audio for spotify://track/5rLhMDfqCVSIffjNf2xYbJ] in 16.28 seconds.
2022-12-16 12:26:19.524 DEBUG (MainThread) [music_assistant.event] background_job_finished Analyze audio for spotify://track/5rLhMDfqCVSIffjNf2xYbJ
2022-12-16 12:27:48.667 DEBUG (MainThread) [music_assistant.helpers.audio] writer finished for spotify://track/0xbavqZPPWB3h1iK2QR7Xf
2022-12-16 12:28:40.540 DEBUG (MainThread) [music_assistant.helpers.audio] finished media stream for: spotify://track/0xbavqZPPWB3h1iK2QR7Xf
2022-12-16 12:28:40.555 DEBUG (MainThread) [music_assistant.event] background_job_updated Analyze audio for spotify://track/0xbavqZPPWB3h1iK2QR7Xf
2022-12-16 12:28:40.556 DEBUG (MainThread) [music_assistant.players.stream] end of track reached - chunk_num: 315 - crossfade_buffer: 5.96 - stream_duration: 314 - player_buffer: 388.2275510204083 - process_time: 155.9
2022-12-16 12:28:40.557 DEBUG (MainThread) [music_assistant.event] background_job_updated Analyze audio for spotify://track/0xbavqZPPWB3h1iK2QR7Xf
2022-12-16 12:28:40.558 DEBUG (MainThread) [music_assistant.helpers.audio] Start analyzing track spotify://track/0xbavqZPPWB3h1iK2QR7Xf
2022-12-16 12:28:40.596 DEBUG (MainThread) [music_assistant.helpers.audio] stripped silence of pcm chunk. size before: 1051344 - after: 0
2022-12-16 12:28:40.597 DEBUG (MainThread) [music_assistant.players.stream] Finished Streaming queue track: spotify://track/0xbavqZPPWB3h1iK2QR7Xf (Locrian - Exiting the Hall of Vapor and Light) on queue Keuken
2022-12-16 12:28:40.755 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/tracks/55ULypZ2fc5beOgg8akgrx took 0.15 seconds
2022-12-16 12:28:40.756 DEBUG (MainThread) [music_assistant.event] background_job_updated Add spotify://track/55ULypZ2fc5beOgg8akgrx to database
2022-12-16 12:28:40.758 DEBUG (MainThread) [music_assistant.event] background_job_updated Add spotify://track/55ULypZ2fc5beOgg8akgrx to database
2022-12-16 12:28:40.845 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/albums/0BTlvO9PL2ftNGSM0x8Oln took 0.07 seconds
2022-12-16 12:28:40.846 DEBUG (MainThread) [music_assistant.event] background_job_updated Add spotify://album/0BTlvO9PL2ftNGSM0x8Oln to database
2022-12-16 12:28:40.849 DEBUG (MainThread) [music_assistant.event] background_job_updated Add spotify://album/0BTlvO9PL2ftNGSM0x8Oln to database
2022-12-16 12:28:40.920 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/artists/3kDriIhqNulTiUuGfLR3Wd took 0.05 seconds
2022-12-16 12:28:40.920 DEBUG (MainThread) [music_assistant.event] background_job_updated Add spotify://artist/3kDriIhqNulTiUuGfLR3Wd to database
2022-12-16 12:28:40.949 DEBUG (MainThread) [music_assistant.music.artist] added Saviours to database
2022-12-16 12:28:40.975 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/artists/3kDriIhqNulTiUuGfLR3Wd took 0.05 seconds
2022-12-16 12:28:40.975 DEBUG (MainThread) [music_assistant] Ignored duplicate job: Add spotify://artist/3kDriIhqNulTiUuGfLR3Wd to database
2022-12-16 12:28:40.997 DEBUG (MainThread) [music_assistant.music.album] added Palace of Vision to database
2022-12-16 12:28:41.018 DEBUG (MainThread) [music_assistant.music.track] added Cursed Night to database: 2040
2022-12-16 12:28:41.024 DEBUG (MainThread) [music_assistant.music.track] Trying to match track Cursed Night on provider Spotify
2022-12-16 12:28:41.052 DEBUG (MainThread) [music_assistant.music.album] updated Palace of Vision in database: 358
2022-12-16 12:28:41.056 DEBUG (MainThread) [music_assistant.music.album] Trying to match album Palace of Vision on provider Filesystem
2022-12-16 12:28:41.080 DEBUG (MainThread) [music_assistant.music.album] Could not find match for Album Palace of Vision on provider Filesystem
2022-12-16 12:28:41.672 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/tracks/55ULypZ2fc5beOgg8akgrx took 0.06 seconds
2022-12-16 12:28:41.694 INFO (MainThread) [music_assistant.players.stream] Start Streaming queue track: spotify://track/55ULypZ2fc5beOgg8akgrx (Saviours - Cursed Night) for queue Keuken - crossfade: False
2022-12-16 12:28:41.694 DEBUG (MainThread) [music_assistant.event] queue_updated media_player.keuken
2022-12-16 12:28:41.725 DEBUG (MainThread) [music_assistant.helpers.audio] start media stream for: spotify://track/55ULypZ2fc5beOgg8akgrx
2022-12-16 12:28:41.726 DEBUG (MainThread) [music_assistant.helpers.audio] writer started for spotify://track/55ULypZ2fc5beOgg8akgrx
2022-12-16 12:28:41.840 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/albums/0BTlvO9PL2ftNGSM0x8Oln took 0.06 seconds
2022-12-16 12:28:41.920 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/albums/0BTlvO9PL2ftNGSM0x8Oln/tracks took 0.05 seconds
2022-12-16 12:28:42.003 DEBUG (MainThread) [music_assistant.music.track] added The Mountain to database: 2041
2022-12-16 12:28:42.057 DEBUG (MainThread) [music_assistant.music.track] added Flesh of Fire to database: 2042
2022-12-16 12:28:42.102 DEBUG (MainThread) [music_assistant.music.track] added Devil's Crown to database: 2043
2022-12-16 12:28:42.125 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/search took 0.19 seconds
2022-12-16 12:28:42.160 DEBUG (MainThread) [music_assistant.music.track] added Palace of Vision to database: 2044
2022-12-16 12:28:42.212 DEBUG (MainThread) [music_assistant.music.track] updated Cursed Night in database: 2040
2022-12-16 12:28:42.223 DEBUG (MainThread) [music_assistant.music.track] Trying to match track Cursed Night on provider Filesystem
2022-12-16 12:28:42.243 DEBUG (MainThread) [music_assistant.music.track] added Burning Shrine to database: 2045
2022-12-16 12:28:42.290 DEBUG (MainThread) [music_assistant.music.track] Could not find match for Track Cursed Night on provider Filesystem
2022-12-16 12:28:42.308 DEBUG (MainThread) [music_assistant.event] media_item_added database://track/2040
2022-12-16 12:28:42.309 INFO (MainThread) [music_assistant] Finished job [Add spotify://track/55ULypZ2fc5beOgg8akgrx to database] in 1.55 seconds.
2022-12-16 12:28:42.310 DEBUG (MainThread) [music_assistant.event] background_job_finished Add spotify://track/55ULypZ2fc5beOgg8akgrx to database
2022-12-16 12:28:42.310 DEBUG (MainThread) [music_assistant.event] background_job_updated Add spotify://artist/3kDriIhqNulTiUuGfLR3Wd to database
2022-12-16 12:28:42.327 DEBUG (MainThread) [music_assistant.music.track] added Hell's Floor to database: 2046
2022-12-16 12:28:42.395 DEBUG (MainThread) [music_assistant.music.track] added The Beast Remains to database: 2047
2022-12-16 12:28:42.432 DEBUG (MainThread) [music_assistant.music.track] updated Cursed Night in database: 2040
2022-12-16 12:28:42.461 DEBUG (MainThread) [music_assistant.music.track] added The Seeker to database: 2048
2022-12-16 12:28:42.463 DEBUG (MainThread) [music_assistant.event] media_item_added database://album/358
2022-12-16 12:28:42.463 INFO (MainThread) [music_assistant] Finished job [Add spotify://album/0BTlvO9PL2ftNGSM0x8Oln to database] in 1.61 seconds.
2022-12-16 12:28:42.464 DEBUG (MainThread) [music_assistant.event] background_job_finished Add spotify://album/0BTlvO9PL2ftNGSM0x8Oln to database
2022-12-16 12:28:42.678 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/artists/3kDriIhqNulTiUuGfLR3Wd/albums?include_groups=album,single,compilation took 0.06 seconds
2022-12-16 12:28:42.680 DEBUG (MainThread) [music_assistant.audiodb] Lookup MusicbrainzID for Artist Saviours on TheAudioDb
2022-12-16 12:28:42.836 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/artists/3kDriIhqNulTiUuGfLR3Wd took 0.05 seconds
2022-12-16 12:28:42.958 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/artists/3kDriIhqNulTiUuGfLR3Wd/top-tracks took 0.08 seconds
2022-12-16 12:28:42.960 DEBUG (MainThread) [music_assistant.musicbrainz] searching musicbrainz for Saviours                 (albumname: None - album_upc: None - trackname: None - track_isrc: FR1PP1501220)
2022-12-16 12:28:43.075 DEBUG (MainThread) [music_assistant.musicbrainz] searching musicbrainz for Saviours                 (albumname: None - album_upc: None - trackname: None - track_isrc: USKDO0800004)
2022-12-16 12:28:44.019 DEBUG (MainThread) [music_assistant.musicbrainz] searching musicbrainz for Saviours                 (albumname: None - album_upc: None - trackname: None - track_isrc: USKDO0900234)
2022-12-16 12:28:45.028 DEBUG (MainThread) [music_assistant.musicbrainz] searching musicbrainz for Saviours                 (albumname: None - album_upc: None - trackname: None - track_isrc: USKDO0800001)
2022-12-16 12:28:46.037 DEBUG (MainThread) [music_assistant.musicbrainz] searching musicbrainz for Saviours                 (albumname: None - album_upc: None - trackname: None - track_isrc: USKDO0800003)
2022-12-16 12:28:47.028 DEBUG (MainThread) [music_assistant.musicbrainz] searching musicbrainz for Saviours                 (albumname: None - album_upc: None - trackname: None - track_isrc: FR1PP1501230)
2022-12-16 12:28:48.028 DEBUG (MainThread) [music_assistant.musicbrainz] searching musicbrainz for Saviours                 (albumname: None - album_upc: None - trackname: None - track_isrc: FR1PP1501300)
2022-12-16 12:28:49.036 DEBUG (MainThread) [music_assistant.musicbrainz] searching musicbrainz for Saviours                 (albumname: None - album_upc: None - trackname: None - track_isrc: USKDO1113105)
2022-12-16 12:28:50.033 DEBUG (MainThread) [music_assistant.musicbrainz] searching musicbrainz for Saviours                 (albumname: None - album_upc: None - trackname: None - track_isrc: USKDO1113102)
2022-12-16 12:28:51.034 DEBUG (MainThread) [music_assistant.musicbrainz] searching musicbrainz for Saviours                 (albumname: None - album_upc: None - trackname: None - track_isrc: FR1PP1501250)
2022-12-16 12:28:52.045 DEBUG (MainThread) [music_assistant.musicbrainz] searching musicbrainz for Saviours                 (albumname: None - album_upc: None - trackname: The Mountain - track_isrc: None)
2022-12-16 12:28:53.063 DEBUG (MainThread) [music_assistant.musicbrainz] Got MusicbrainzArtistId for Saviours after search on trackname The Mountain --> daed79fe-1d3f-48e4-98e0-12fd503e2310
2022-12-16 12:28:53.063 DEBUG (MainThread) [music_assistant.fanarttv] Fetching metadata for Artist Saviours on Fanart.tv
2022-12-16 12:28:53.192 DEBUG (MainThread) [music_assistant.audiodb] Fetching metadata for Artist Saviours on TheAudioDb
2022-12-16 12:28:53.286 DEBUG (MainThread) [music_assistant.music.artist] updated Saviours in database: 446
2022-12-16 12:28:53.291 DEBUG (MainThread) [music_assistant.music.artist] Trying to match artist Saviours on provider Filesystem
2022-12-16 12:28:53.616 DEBUG (MainThread) [music_assistant.music.artist] Could not find match for Artist Saviours on provider Filesystem
2022-12-16 12:28:53.617 DEBUG (MainThread) [music_assistant.event] media_item_updated database://artist/446
2022-12-16 12:28:53.618 INFO (MainThread) [music_assistant] Finished job [Add spotify://artist/3kDriIhqNulTiUuGfLR3Wd to database] in 11.31 seconds.
2022-12-16 12:28:53.618 DEBUG (MainThread) [music_assistant.event] background_job_finished Add spotify://artist/3kDriIhqNulTiUuGfLR3Wd to database
2022-12-16 12:28:53.778 DEBUG (MainThread) [music_assistant.helpers.audio] Integrated loudness of spotify://track/0xbavqZPPWB3h1iK2QR7Xf is: -13.9
2022-12-16 12:28:53.779 INFO (MainThread) [music_assistant] Finished job [Analyze audio for spotify://track/0xbavqZPPWB3h1iK2QR7Xf] in 13.22 seconds.
2022-12-16 12:28:53.779 DEBUG (MainThread) [music_assistant.event] background_job_finished Analyze audio for spotify://track/0xbavqZPPWB3h1iK2QR7Xf
2022-12-16 12:30:01.230 DEBUG (MainThread) [music_assistant.event] queue_updated media_player.keuken
2022-12-16 12:30:01.363 DEBUG (MainThread) [music_assistant.event] queue_updated media_player.keuken
2022-12-16 12:30:55.787 DEBUG (MainThread) [music_assistant.helpers.audio] writer finished for spotify://track/55ULypZ2fc5beOgg8akgrx
2022-12-16 12:32:29.597 DEBUG (MainThread) [music_assistant.helpers.audio] finished media stream for: spotify://track/55ULypZ2fc5beOgg8akgrx
2022-12-16 12:32:29.612 DEBUG (MainThread) [music_assistant.event] background_job_updated Analyze audio for spotify://track/55ULypZ2fc5beOgg8akgrx
2022-12-16 12:32:29.613 DEBUG (MainThread) [music_assistant.players.stream] end of track reached - chunk_num: 176 - crossfade_buffer: 5.504648526077098 - stream_duration: 175 - player_buffer: 329.2275510204083 - process_time: 227.91
2022-12-16 12:32:29.614 DEBUG (MainThread) [music_assistant.event] background_job_updated Analyze audio for spotify://track/55ULypZ2fc5beOgg8akgrx
2022-12-16 12:32:29.615 DEBUG (MainThread) [music_assistant.helpers.audio] Start analyzing track spotify://track/55ULypZ2fc5beOgg8akgrx
2022-12-16 12:32:29.653 DEBUG (MainThread) [music_assistant.helpers.audio] stripped silence of pcm chunk. size before: 971020 - after: 320960
2022-12-16 12:32:29.657 DEBUG (MainThread) [music_assistant.players.stream] Finished Streaming queue track: spotify://track/55ULypZ2fc5beOgg8akgrx (Saviours - Cursed Night) on queue Keuken
2022-12-16 12:32:29.816 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/tracks/1MWafeRy5fy10cNB89WsMQ took 0.15 seconds
2022-12-16 12:32:29.817 DEBUG (MainThread) [music_assistant.event] background_job_updated Add spotify://track/1MWafeRy5fy10cNB89WsMQ to database
2022-12-16 12:32:29.818 DEBUG (MainThread) [music_assistant.event] background_job_updated Add spotify://track/1MWafeRy5fy10cNB89WsMQ to database
2022-12-16 12:32:29.894 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/albums/5F31T85C7m0rAnsJerFzFj took 0.06 seconds
2022-12-16 12:32:29.895 DEBUG (MainThread) [music_assistant.event] background_job_updated Add spotify://album/5F31T85C7m0rAnsJerFzFj to database
2022-12-16 12:32:29.896 DEBUG (MainThread) [music_assistant.event] background_job_updated Add spotify://album/5F31T85C7m0rAnsJerFzFj to database
2022-12-16 12:32:29.971 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/artists/67GYw25WS7K7D1i8djaE6l took 0.05 seconds
2022-12-16 12:32:29.971 DEBUG (MainThread) [music_assistant.event] background_job_updated Add spotify://artist/67GYw25WS7K7D1i8djaE6l to database
2022-12-16 12:32:30.039 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/artists/67GYw25WS7K7D1i8djaE6l took 0.04 seconds
2022-12-16 12:32:30.039 DEBUG (MainThread) [music_assistant] Ignored duplicate job: Add spotify://artist/67GYw25WS7K7D1i8djaE6l to database
2022-12-16 12:32:30.103 DEBUG (MainThread) [music_assistant.music.artist] added Rorcal to database
2022-12-16 12:32:30.144 DEBUG (MainThread) [music_assistant.music.artist] updated Rorcal in database: 447
2022-12-16 12:32:30.173 DEBUG (MainThread) [music_assistant.music.album] added Creon to database
2022-12-16 12:32:30.179 DEBUG (MainThread) [music_assistant.music.album] Trying to match album Creon on provider Filesystem
2022-12-16 12:32:30.225 DEBUG (MainThread) [music_assistant.music.album] updated Creon in database: 359
2022-12-16 12:32:30.228 DEBUG (MainThread) [music_assistant.music.album] Could not find match for Album Creon on provider Filesystem
2022-12-16 12:32:30.254 DEBUG (MainThread) [music_assistant.music.track] added Εὐρυδίκη to database: 2049
2022-12-16 12:32:30.260 DEBUG (MainThread) [music_assistant.music.track] Trying to match track Εὐρυδίκη on provider Spotify
2022-12-16 12:32:30.748 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/tracks/1MWafeRy5fy10cNB89WsMQ took 0.07 seconds
2022-12-16 12:32:30.759 INFO (MainThread) [music_assistant.players.stream] Start Streaming queue track: spotify://track/1MWafeRy5fy10cNB89WsMQ (Rorcal - Εὐρυδίκη) for queue Keuken - crossfade: False
2022-12-16 12:32:30.759 DEBUG (MainThread) [music_assistant.event] queue_updated media_player.keuken
2022-12-16 12:32:30.800 DEBUG (MainThread) [music_assistant.helpers.audio] start media stream for: spotify://track/1MWafeRy5fy10cNB89WsMQ
2022-12-16 12:32:30.800 DEBUG (MainThread) [music_assistant.helpers.audio] writer started for spotify://track/1MWafeRy5fy10cNB89WsMQ
2022-12-16 12:32:31.045 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/search took 0.21 seconds
2022-12-16 12:32:31.050 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/albums/5F31T85C7m0rAnsJerFzFj took 0.13 seconds
2022-12-16 12:32:31.103 DEBUG (MainThread) [music_assistant.music.track] updated Εὐρυδίκη in database: 2049
2022-12-16 12:32:31.107 DEBUG (MainThread) [music_assistant.music.track] Trying to match track Εὐρυδίκη on provider Filesystem
2022-12-16 12:32:31.108 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/albums/5F31T85C7m0rAnsJerFzFj/tracks took 0.05 seconds
2022-12-16 12:32:31.194 DEBUG (MainThread) [music_assistant.music.track] added Πολυνείκης to database: 2050
2022-12-16 12:32:31.200 DEBUG (MainThread) [music_assistant.music.track] Could not find match for Track Εὐρυδίκη on provider Filesystem
2022-12-16 12:32:31.203 DEBUG (MainThread) [music_assistant.event] media_item_added database://track/2049
2022-12-16 12:32:31.203 INFO (MainThread) [music_assistant] Finished job [Add spotify://track/1MWafeRy5fy10cNB89WsMQ to database] in 1.39 seconds.
2022-12-16 12:32:31.204 DEBUG (MainThread) [music_assistant.event] background_job_finished Add spotify://track/1MWafeRy5fy10cNB89WsMQ to database
2022-12-16 12:32:31.204 DEBUG (MainThread) [music_assistant.event] background_job_updated Add spotify://artist/67GYw25WS7K7D1i8djaE6l to database
2022-12-16 12:32:31.234 DEBUG (MainThread) [music_assistant.music.track] added Ἀντιγόνη to database: 2051
2022-12-16 12:32:31.261 DEBUG (MainThread) [music_assistant.music.track] added Αἵμων to database: 2052
2022-12-16 12:32:31.290 DEBUG (MainThread) [music_assistant.music.track] updated Εὐρυδίκη in database: 2049
2022-12-16 12:32:31.294 DEBUG (MainThread) [music_assistant.event] media_item_added database://album/359
2022-12-16 12:32:31.294 INFO (MainThread) [music_assistant] Finished job [Add spotify://album/5F31T85C7m0rAnsJerFzFj to database] in 1.4 seconds.
2022-12-16 12:32:31.294 DEBUG (MainThread) [music_assistant.event] background_job_finished Add spotify://album/5F31T85C7m0rAnsJerFzFj to database
2022-12-16 12:32:31.733 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/artists/67GYw25WS7K7D1i8djaE6l/albums?include_groups=album,single,compilation took 0.06 seconds
2022-12-16 12:32:31.740 DEBUG (MainThread) [music_assistant.audiodb] Lookup MusicbrainzID for Artist Rorcal on TheAudioDb
2022-12-16 12:32:31.881 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/artists/67GYw25WS7K7D1i8djaE6l took 0.04 seconds
2022-12-16 12:32:31.996 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/artists/67GYw25WS7K7D1i8djaE6l/top-tracks took 0.07 seconds
2022-12-16 12:32:32.003 DEBUG (MainThread) [music_assistant.musicbrainz] searching musicbrainz for Rorcal                 (albumname: None - album_upc: None - trackname: None - track_isrc: CHA011900656)
2022-12-16 12:32:32.134 DEBUG (MainThread) [music_assistant.musicbrainz] searching musicbrainz for Rorcal                 (albumname: None - album_upc: None - trackname: None - track_isrc: CHA011900658)
2022-12-16 12:32:33.068 DEBUG (MainThread) [music_assistant.musicbrainz] searching musicbrainz for Rorcal                 (albumname: None - album_upc: None - trackname: None - track_isrc: CHA011900657)
2022-12-16 12:32:34.063 DEBUG (MainThread) [music_assistant.musicbrainz] searching musicbrainz for Rorcal                 (albumname: None - album_upc: None - trackname: None - track_isrc: CHA011900655)
2022-12-16 12:32:35.075 DEBUG (MainThread) [music_assistant.musicbrainz] searching musicbrainz for Rorcal                 (albumname: None - album_upc: None - trackname: None - track_isrc: CHA012000567)
2022-12-16 12:32:35.079 DEBUG (MainThread) [music_assistant.helpers.audio] Integrated loudness of spotify://track/55ULypZ2fc5beOgg8akgrx is: -8.3
2022-12-16 12:32:35.081 INFO (MainThread) [music_assistant] Finished job [Analyze audio for spotify://track/55ULypZ2fc5beOgg8akgrx] in 5.47 seconds.
2022-12-16 12:32:35.081 DEBUG (MainThread) [music_assistant.event] background_job_finished Analyze audio for spotify://track/55ULypZ2fc5beOgg8akgrx
2022-12-16 12:32:36.088 DEBUG (MainThread) [music_assistant.musicbrainz] searching musicbrainz for Rorcal                 (albumname: None - album_upc: None - trackname: None - track_isrc: CHA012000568)
2022-12-16 12:32:37.077 DEBUG (MainThread) [music_assistant.musicbrainz] searching musicbrainz for Rorcal                 (albumname: None - album_upc: None - trackname: None - track_isrc: CHA011900659)
2022-12-16 12:32:38.083 DEBUG (MainThread) [music_assistant.musicbrainz] searching musicbrainz for Rorcal                 (albumname: None - album_upc: None - trackname: None - track_isrc: CHA011900660)
2022-12-16 12:32:39.088 DEBUG (MainThread) [music_assistant.musicbrainz] searching musicbrainz for Rorcal                 (albumname: None - album_upc: None - trackname: None - track_isrc: USQY51585375)
2022-12-16 12:32:40.108 DEBUG (MainThread) [music_assistant.musicbrainz] searching musicbrainz for Rorcal                 (albumname: None - album_upc: None - trackname: None - track_isrc: USQY51585374)
2022-12-16 12:32:41.106 DEBUG (MainThread) [music_assistant.musicbrainz] searching musicbrainz for Rorcal                 (albumname: None - album_upc: None - trackname: She Drained You of Your Innocence and You Poisoned Her with It - track_isrc: None)
2022-12-16 12:32:42.175 DEBUG (MainThread) [music_assistant.musicbrainz] Got MusicbrainzArtistId for Rorcal after search on trackname She Drained You of Your Innocence and You Poisoned Her with It --> 27030b71-0eb7-4dc9-93f5-6f43b9970d73
2022-12-16 12:32:42.175 DEBUG (MainThread) [music_assistant.fanarttv] Fetching metadata for Artist Rorcal on Fanart.tv
2022-12-16 12:32:42.365 DEBUG (MainThread) [music_assistant.audiodb] Fetching metadata for Artist Rorcal on TheAudioDb
2022-12-16 12:32:42.472 DEBUG (MainThread) [music_assistant.music.artist] updated Rorcal in database: 447
2022-12-16 12:32:42.477 DEBUG (MainThread) [music_assistant.music.artist] Trying to match artist Rorcal on provider Filesystem
2022-12-16 12:32:43.005 DEBUG (MainThread) [music_assistant.music.artist] Could not find match for Artist Rorcal on provider Filesystem
2022-12-16 12:32:43.007 DEBUG (MainThread) [music_assistant.event] media_item_updated database://artist/447
2022-12-16 12:32:43.008 INFO (MainThread) [music_assistant] Finished job [Add spotify://artist/67GYw25WS7K7D1i8djaE6l to database] in 11.8 seconds.
2022-12-16 12:32:43.008 DEBUG (MainThread) [music_assistant.event] background_job_finished Add spotify://artist/67GYw25WS7K7D1i8djaE6l to database
2022-12-16 12:35:09.684 DEBUG (MainThread) [music_assistant.event] queue_updated media_player.keuken
2022-12-16 12:35:09.786 DEBUG (MainThread) [music_assistant.event] queue_updated media_player.keuken
2022-12-16 12:38:02.941 DEBUG (MainThread) [music_assistant.event] queue_updated media_player.keuken
2022-12-16 12:38:03.043 DEBUG (MainThread) [music_assistant.event] queue_updated media_player.keuken
2022-12-16 12:45:20.434 DEBUG (MainThread) [music_assistant.helpers.audio] writer finished for spotify://track/1MWafeRy5fy10cNB89WsMQ
2022-12-16 12:46:09.675 DEBUG (MainThread) [music_assistant.helpers.audio] finished media stream for: spotify://track/1MWafeRy5fy10cNB89WsMQ
2022-12-16 12:46:09.698 DEBUG (MainThread) [music_assistant.event] background_job_updated Analyze audio for spotify://track/1MWafeRy5fy10cNB89WsMQ
2022-12-16 12:46:09.699 DEBUG (MainThread) [music_assistant.players.stream] end of track reached - chunk_num: 748 - crossfade_buffer: 5.373242630385487 - stream_duration: 747 - player_buffer: 253.04705215419517 - process_time: 818.94
2022-12-16 12:46:09.700 DEBUG (MainThread) [music_assistant.event] background_job_updated Analyze audio for spotify://track/1MWafeRy5fy10cNB89WsMQ
2022-12-16 12:46:09.701 DEBUG (MainThread) [music_assistant.helpers.audio] Start analyzing track spotify://track/1MWafeRy5fy10cNB89WsMQ
2022-12-16 12:46:09.740 DEBUG (MainThread) [music_assistant.helpers.audio] stripped silence of pcm chunk. size before: 947840 - after: 0
2022-12-16 12:46:09.740 DEBUG (MainThread) [music_assistant.players.stream] Finished Streaming queue track: spotify://track/1MWafeRy5fy10cNB89WsMQ (Rorcal - Εὐρυδίκη) on queue Keuken
2022-12-16 12:46:09.893 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/tracks/39Y9mtxVmt5TFG5SYQdkFC took 0.14 seconds
2022-12-16 12:46:09.893 DEBUG (MainThread) [music_assistant.event] background_job_updated Add spotify://track/39Y9mtxVmt5TFG5SYQdkFC to database
2022-12-16 12:46:09.895 DEBUG (MainThread) [music_assistant.event] background_job_updated Add spotify://track/39Y9mtxVmt5TFG5SYQdkFC to database
2022-12-16 12:46:09.968 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/albums/1TwPSp1lv5Vi9PKO9YPgYS took 0.05 seconds
2022-12-16 12:46:09.968 DEBUG (MainThread) [music_assistant.event] background_job_updated Add spotify://album/1TwPSp1lv5Vi9PKO9YPgYS to database
2022-12-16 12:46:09.969 DEBUG (MainThread) [music_assistant.event] background_job_updated Add spotify://album/1TwPSp1lv5Vi9PKO9YPgYS to database
2022-12-16 12:46:10.038 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/artists/3vXdcEXbg9wysccGlh4LkD took 0.05 seconds
2022-12-16 12:46:10.038 DEBUG (MainThread) [music_assistant.event] background_job_updated Add spotify://artist/3vXdcEXbg9wysccGlh4LkD to database
2022-12-16 12:46:10.084 DEBUG (MainThread) [music_assistant.fanarttv] Fetching metadata for Album Bestial on Fanart.tv
2022-12-16 12:46:10.096 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/artists/3vXdcEXbg9wysccGlh4LkD took 0.04 seconds
2022-12-16 12:46:10.097 DEBUG (MainThread) [music_assistant] Ignored duplicate job: Add spotify://artist/3vXdcEXbg9wysccGlh4LkD to database
2022-12-16 12:46:10.164 DEBUG (MainThread) [music_assistant.music.artist] added Black Cobra to database
2022-12-16 12:46:10.219 DEBUG (MainThread) [music_assistant.music.album] added Bestial to database
2022-12-16 12:46:10.250 DEBUG (MainThread) [music_assistant.music.track] added El Equis to database: 2053
2022-12-16 12:46:10.254 DEBUG (MainThread) [music_assistant.music.track] Trying to match track El Equis on provider Spotify
2022-12-16 12:46:10.338 DEBUG (MainThread) [music_assistant.music.album] updated Bestial in database: 360
2022-12-16 12:46:10.344 DEBUG (MainThread) [music_assistant.music.album] Trying to match album Bestial on provider Filesystem
2022-12-16 12:46:10.371 DEBUG (MainThread) [music_assistant.music.album] Could not find match for Album Bestial on provider Filesystem
2022-12-16 12:46:10.833 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/tracks/39Y9mtxVmt5TFG5SYQdkFC took 0.07 seconds
2022-12-16 12:46:10.848 INFO (MainThread) [music_assistant.players.stream] Start Streaming queue track: spotify://track/39Y9mtxVmt5TFG5SYQdkFC (Black Cobra - El Equis) for queue Keuken - crossfade: False
2022-12-16 12:46:10.848 DEBUG (MainThread) [music_assistant.event] queue_updated media_player.keuken
2022-12-16 12:46:10.885 DEBUG (MainThread) [music_assistant.helpers.audio] start media stream for: spotify://track/39Y9mtxVmt5TFG5SYQdkFC
2022-12-16 12:46:10.886 DEBUG (MainThread) [music_assistant.helpers.audio] writer started for spotify://track/39Y9mtxVmt5TFG5SYQdkFC
2022-12-16 12:46:10.967 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/albums/1TwPSp1lv5Vi9PKO9YPgYS took 0.05 seconds
2022-12-16 12:46:11.189 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/albums/1TwPSp1lv5Vi9PKO9YPgYS/tracks took 0.13 seconds
2022-12-16 12:46:11.252 DEBUG (MainThread) [music_assistant.music.track] added One Nine to database: 2054
2022-12-16 12:46:11.268 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/search took 0.28 seconds
2022-12-16 12:46:11.297 DEBUG (MainThread) [music_assistant.music.track] added Thrown From Great Heights to database: 2055
2022-12-16 12:46:11.326 DEBUG (MainThread) [music_assistant.music.track] updated El Equis in database: 2053
2022-12-16 12:46:11.332 DEBUG (MainThread) [music_assistant.music.track] Trying to match track El Equis on provider Filesystem
2022-12-16 12:46:11.361 DEBUG (MainThread) [music_assistant.music.track] updated El Equis in database: 2053
2022-12-16 12:46:11.379 DEBUG (MainThread) [music_assistant.music.track] Could not find match for Track El Equis on provider Filesystem
2022-12-16 12:46:11.388 DEBUG (MainThread) [music_assistant.event] media_item_added database://track/2053
2022-12-16 12:46:11.389 INFO (MainThread) [music_assistant] Finished job [Add spotify://track/39Y9mtxVmt5TFG5SYQdkFC to database] in 1.49 seconds.
2022-12-16 12:46:11.389 DEBUG (MainThread) [music_assistant.event] background_job_finished Add spotify://track/39Y9mtxVmt5TFG5SYQdkFC to database
2022-12-16 12:46:11.390 DEBUG (MainThread) [music_assistant.event] background_job_updated Add spotify://artist/3vXdcEXbg9wysccGlh4LkD to database
2022-12-16 12:46:11.394 DEBUG (MainThread) [music_assistant.fanarttv] Fetching metadata for Artist Black Cobra on Fanart.tv
2022-12-16 12:46:11.412 DEBUG (MainThread) [music_assistant.music.track] added Beneath to database: 2056
2022-12-16 12:46:11.440 DEBUG (MainThread) [music_assistant.music.track] added Omniscient to database: 2057
2022-12-16 12:46:11.457 DEBUG (MainThread) [music_assistant.audiodb] Fetching metadata for Artist Black Cobra on TheAudioDb
2022-12-16 12:46:11.487 DEBUG (MainThread) [music_assistant.music.track] added The Cry Of Melora to database: 2058
2022-12-16 12:46:11.519 DEBUG (MainThread) [music_assistant.music.track] added Broken On The Wheel to database: 2059
2022-12-16 12:46:11.568 DEBUG (MainThread) [music_assistant.music.track] added Sugar Water to database: 2060
2022-12-16 12:46:11.583 DEBUG (MainThread) [music_assistant.music.artist] updated Black Cobra in database: 448
2022-12-16 12:46:11.585 DEBUG (MainThread) [music_assistant.music.artist] Trying to match artist Black Cobra on provider Filesystem
2022-12-16 12:46:11.615 DEBUG (MainThread) [music_assistant.music.track] added El Doce De Octubre to database: 2061
2022-12-16 12:46:11.668 DEBUG (MainThread) [music_assistant.music.track] added Sombra De Bestia to database: 2062
2022-12-16 12:46:11.716 DEBUG (MainThread) [music_assistant.music.track] added Kay-Dur-Twenty to database: 2063
2022-12-16 12:46:11.722 DEBUG (MainThread) [music_assistant.event] media_item_updated database://album/360
2022-12-16 12:46:11.723 INFO (MainThread) [music_assistant] Finished job [Add spotify://album/1TwPSp1lv5Vi9PKO9YPgYS to database] in 1.75 seconds.
2022-12-16 12:46:11.724 DEBUG (MainThread) [music_assistant.event] background_job_finished Add spotify://album/1TwPSp1lv5Vi9PKO9YPgYS to database
2022-12-16 12:46:11.807 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/artists/3vXdcEXbg9wysccGlh4LkD took 0.04 seconds
2022-12-16 12:46:12.019 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/artists/3vXdcEXbg9wysccGlh4LkD/top-tracks took 0.1 seconds
2022-12-16 12:46:12.404 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/artists/3vXdcEXbg9wysccGlh4LkD/albums?include_groups=album,single,compilation took 0.05 seconds
2022-12-16 12:46:12.491 DEBUG (MainThread) [music_assistant.music.artist] Could not find match for Artist Black Cobra on provider Filesystem
2022-12-16 12:46:12.493 DEBUG (MainThread) [music_assistant.event] media_item_updated database://artist/448
2022-12-16 12:46:12.493 INFO (MainThread) [music_assistant] Finished job [Add spotify://artist/3vXdcEXbg9wysccGlh4LkD to database] in 1.1 seconds.
2022-12-16 12:46:12.493 DEBUG (MainThread) [music_assistant.event] background_job_finished Add spotify://artist/3vXdcEXbg9wysccGlh4LkD to database
2022-12-16 12:46:44.778 DEBUG (MainThread) [music_assistant.helpers.audio] Integrated loudness of spotify://track/1MWafeRy5fy10cNB89WsMQ is: -7.8
2022-12-16 12:46:44.778 INFO (MainThread) [music_assistant] Finished job [Analyze audio for spotify://track/1MWafeRy5fy10cNB89WsMQ] in 35.08 seconds.
2022-12-16 12:46:44.779 DEBUG (MainThread) [music_assistant.event] background_job_finished Analyze audio for spotify://track/1MWafeRy5fy10cNB89WsMQ
2022-12-16 12:47:55.760 DEBUG (MainThread) [music_assistant.helpers.audio] writer finished for spotify://track/39Y9mtxVmt5TFG5SYQdkFC
2022-12-16 12:48:46.761 DEBUG (MainThread) [music_assistant.helpers.audio] finished media stream for: spotify://track/39Y9mtxVmt5TFG5SYQdkFC
2022-12-16 12:48:46.777 DEBUG (MainThread) [music_assistant.event] background_job_updated Analyze audio for spotify://track/39Y9mtxVmt5TFG5SYQdkFC
2022-12-16 12:48:46.778 DEBUG (MainThread) [music_assistant.players.stream] end of track reached - chunk_num: 190 - crossfade_buffer: 5.36 - stream_duration: 189 - player_buffer: 280.04705215419517 - process_time: 155.93
2022-12-16 12:48:46.779 DEBUG (MainThread) [music_assistant.event] background_job_updated Analyze audio for spotify://track/39Y9mtxVmt5TFG5SYQdkFC
2022-12-16 12:48:46.779 DEBUG (MainThread) [music_assistant.helpers.audio] Start analyzing track spotify://track/39Y9mtxVmt5TFG5SYQdkFC
2022-12-16 12:48:46.811 DEBUG (MainThread) [music_assistant.helpers.audio] stripped silence of pcm chunk. size before: 945504 - after: 910224
2022-12-16 12:48:46.821 DEBUG (MainThread) [music_assistant.players.stream] Finished Streaming queue track: spotify://track/39Y9mtxVmt5TFG5SYQdkFC (Black Cobra - El Equis) on queue Keuken
2022-12-16 12:48:47.001 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/tracks/6u04aBSTpZDO8MuYC5e3DN took 0.17 seconds
2022-12-16 12:48:47.002 DEBUG (MainThread) [music_assistant.event] background_job_updated Add spotify://track/6u04aBSTpZDO8MuYC5e3DN to database
2022-12-16 12:48:47.003 DEBUG (MainThread) [music_assistant.event] background_job_updated Add spotify://track/6u04aBSTpZDO8MuYC5e3DN to database
2022-12-16 12:48:47.076 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/albums/3EF6FyEZwc1P1xtnWwDyan took 0.06 seconds
2022-12-16 12:48:47.077 DEBUG (MainThread) [music_assistant.event] background_job_updated Add spotify://album/3EF6FyEZwc1P1xtnWwDyan to database
2022-12-16 12:48:47.079 DEBUG (MainThread) [music_assistant.event] background_job_updated Add spotify://album/3EF6FyEZwc1P1xtnWwDyan to database
2022-12-16 12:48:47.152 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/artists/5GX4XzIgGGH93KvmLu85ZV took 0.05 seconds
2022-12-16 12:48:47.153 DEBUG (MainThread) [music_assistant.event] background_job_updated Add spotify://artist/5GX4XzIgGGH93KvmLu85ZV to database
2022-12-16 12:48:47.195 DEBUG (MainThread) [music_assistant.music.artist] added Spelljammer to database
2022-12-16 12:48:47.227 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/artists/5GX4XzIgGGH93KvmLu85ZV took 0.06 seconds
2022-12-16 12:48:47.227 DEBUG (MainThread) [music_assistant] Ignored duplicate job: Add spotify://artist/5GX4XzIgGGH93KvmLu85ZV to database
2022-12-16 12:48:47.246 DEBUG (MainThread) [music_assistant.music.album] added Abyssal Trip to database
2022-12-16 12:48:47.271 DEBUG (MainThread) [music_assistant.music.track] added Silent Rift to database: 2064
2022-12-16 12:48:47.275 DEBUG (MainThread) [music_assistant.music.track] Trying to match track Silent Rift on provider Spotify
2022-12-16 12:48:47.304 DEBUG (MainThread) [music_assistant.music.album] updated Abyssal Trip in database: 361
2022-12-16 12:48:47.309 DEBUG (MainThread) [music_assistant.music.album] Trying to match album Abyssal Trip on provider Filesystem
2022-12-16 12:48:47.335 DEBUG (MainThread) [music_assistant.music.album] Could not find match for Album Abyssal Trip on provider Filesystem
2022-12-16 12:48:47.911 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/tracks/6u04aBSTpZDO8MuYC5e3DN took 0.07 seconds
2022-12-16 12:48:47.918 INFO (MainThread) [music_assistant.players.stream] Start Streaming queue track: spotify://track/6u04aBSTpZDO8MuYC5e3DN (Spelljammer - Silent Rift) for queue Keuken - crossfade: False
2022-12-16 12:48:47.919 DEBUG (MainThread) [music_assistant.event] queue_updated media_player.keuken
2022-12-16 12:48:47.954 DEBUG (MainThread) [music_assistant.helpers.audio] start media stream for: spotify://track/6u04aBSTpZDO8MuYC5e3DN
2022-12-16 12:48:47.955 DEBUG (MainThread) [music_assistant.helpers.audio] writer started for spotify://track/6u04aBSTpZDO8MuYC5e3DN
2022-12-16 12:48:48.204 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/albums/3EF6FyEZwc1P1xtnWwDyan took 0.1 seconds
2022-12-16 12:48:48.264 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/albums/3EF6FyEZwc1P1xtnWwDyan/tracks took 0.05 seconds
2022-12-16 12:48:48.318 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/search took 0.29 seconds
2022-12-16 12:48:48.356 DEBUG (MainThread) [music_assistant.music.track] added Bellwether to database: 2065
2022-12-16 12:48:48.426 DEBUG (MainThread) [music_assistant.music.track] updated Silent Rift in database: 2064
2022-12-16 12:48:48.431 DEBUG (MainThread) [music_assistant.music.track] Trying to match track Silent Rift on provider Filesystem
2022-12-16 12:48:48.446 DEBUG (MainThread) [music_assistant.music.track] added Lake to database: 2066
2022-12-16 12:48:48.466 DEBUG (MainThread) [music_assistant.music.track] Could not find match for Track Silent Rift on provider Filesystem
2022-12-16 12:48:48.482 DEBUG (MainThread) [music_assistant.event] media_item_added database://track/2064
2022-12-16 12:48:48.484 INFO (MainThread) [music_assistant] Finished job [Add spotify://track/6u04aBSTpZDO8MuYC5e3DN to database] in 1.48 seconds.
2022-12-16 12:48:48.484 DEBUG (MainThread) [music_assistant.event] background_job_finished Add spotify://track/6u04aBSTpZDO8MuYC5e3DN to database
2022-12-16 12:48:48.486 DEBUG (MainThread) [music_assistant.event] background_job_updated Add spotify://artist/5GX4XzIgGGH93KvmLu85ZV to database
2022-12-16 12:48:48.496 DEBUG (MainThread) [music_assistant.music.track] added Among the Holy to database: 2067
2022-12-16 12:48:48.553 DEBUG (MainThread) [music_assistant.music.track] added Abyssal Trip to database: 2068
2022-12-16 12:48:48.602 DEBUG (MainThread) [music_assistant.music.track] added Peregrine to database: 2069
2022-12-16 12:48:48.659 DEBUG (MainThread) [music_assistant.music.track] updated Silent Rift in database: 2064
2022-12-16 12:48:48.664 DEBUG (MainThread) [music_assistant.event] media_item_added database://album/361
2022-12-16 12:48:48.665 INFO (MainThread) [music_assistant] Finished job [Add spotify://album/3EF6FyEZwc1P1xtnWwDyan to database] in 1.59 seconds.
2022-12-16 12:48:48.666 DEBUG (MainThread) [music_assistant.event] background_job_finished Add spotify://album/3EF6FyEZwc1P1xtnWwDyan to database
2022-12-16 12:48:48.895 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/artists/5GX4XzIgGGH93KvmLu85ZV/albums?include_groups=album,single,compilation took 0.05 seconds
2022-12-16 12:48:48.895 DEBUG (MainThread) [music_assistant.audiodb] Lookup MusicbrainzID for Artist Spelljammer on TheAudioDb
2022-12-16 12:48:49.078 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/artists/5GX4XzIgGGH93KvmLu85ZV took 0.05 seconds
2022-12-16 12:48:49.192 DEBUG (MainThread) [music_assistant.music.spotify] Processing GET/artists/5GX4XzIgGGH93KvmLu85ZV/top-tracks took 0.08 seconds
2022-12-16 12:48:49.200 DEBUG (MainThread) [music_assistant.musicbrainz] searching musicbrainz for Spelljammer                 (albumname: None - album_upc: None - trackname: None - track_isrc: USYBL2002089)
2022-12-16 12:48:49.321 DEBUG (MainThread) [music_assistant.musicbrainz] searching musicbrainz for Spelljammer                 (albumname: None - album_upc: None - trackname: None - track_isrc: USYBL1500638)
2022-12-16 12:48:50.258 DEBUG (MainThread) [music_assistant.musicbrainz] searching musicbrainz for Spelljammer                 (albumname: None - album_upc: None - trackname: None - track_isrc: USYBL2002092)
2022-12-16 12:48:51.278 DEBUG (MainThread) [music_assistant.musicbrainz] searching musicbrainz for Spelljammer                 (albumname: None - album_upc: None - trackname: None - track_isrc: USYBL1500637)
2022-12-16 12:48:52.278 DEBUG (MainThread) [music_assistant.musicbrainz] searching musicbrainz for Spelljammer                 (albumname: None - album_upc: None - trackname: None - track_isrc: USYBL1500639)
2022-12-16 12:48:53.033 DEBUG (MainThread) [music_assistant.helpers.audio] Integrated loudness of spotify://track/39Y9mtxVmt5TFG5SYQdkFC is: -6.4
2022-12-16 12:48:53.033 INFO (MainThread) [music_assistant] Finished job [Analyze audio for spotify://track/39Y9mtxVmt5TFG5SYQdkFC] in 6.25 seconds.
2022-12-16 12:48:53.033 DEBUG (MainThread) [music_assistant.event] background_job_finished Analyze audio for spotify://track/39Y9mtxVmt5TFG5SYQdkFC
2022-12-16 12:48:53.276 DEBUG (MainThread) [music_assistant.musicbrainz] searching musicbrainz for Spelljammer                 (albumname: None - album_upc: None - trackname: None - track_isrc: USYBL1500640)
2022-12-16 12:48:54.298 DEBUG (MainThread) [music_assistant.musicbrainz] searching musicbrainz for Spelljammer                 (albumname: None - album_upc: None - trackname: None - track_isrc: USYBL2002090)
2022-12-16 12:48:55.292 DEBUG (MainThread) [music_assistant.musicbrainz] searching musicbrainz for Spelljammer                 (albumname: None - album_upc: None - trackname: None - track_isrc: USYBL2002088)
2022-12-16 12:48:56.281 DEBUG (MainThread) [music_assistant.musicbrainz] searching musicbrainz for Spelljammer                 (albumname: None - album_upc: None - trackname: None - track_isrc: USYBL2002091)
2022-12-16 12:48:57.290 DEBUG (MainThread) [music_assistant.musicbrainz] searching musicbrainz for Spelljammer                 (albumname: None - album_upc: None - trackname: None - track_isrc: USYBL2002093)
2022-12-16 12:48:58.304 DEBUG (MainThread) [music_assistant.musicbrainz] searching musicbrainz for Spelljammer                 (albumname: None - album_upc: None - trackname: Lake - track_isrc: None)
2022-12-16 12:48:59.323 DEBUG (MainThread) [music_assistant.musicbrainz] Got MusicbrainzArtistId for Spelljammer after search on trackname Lake --> 0939392c-b743-4ce6-b497-61fe1c88474d
2022-12-16 12:48:59.323 DEBUG (MainThread) [music_assistant.fanarttv] Fetching metadata for Artist Spelljammer on Fanart.tv
2022-12-16 12:48:59.477 DEBUG (MainThread) [music_assistant.audiodb] Fetching metadata for Artist Spelljammer on TheAudioDb
2022-12-16 12:48:59.617 DEBUG (MainThread) [music_assistant.music.artist] updated Spelljammer in database: 449
2022-12-16 12:48:59.622 DEBUG (MainThread) [music_assistant.music.artist] Trying to match artist Spelljammer on provider Filesystem
2022-12-16 12:49:00.014 DEBUG (MainThread) [music_assistant.music.artist] Could not find match for Artist Spelljammer on provider Filesystem
2022-12-16 12:49:00.016 DEBUG (MainThread) [music_assistant.event] media_item_updated database://artist/449
2022-12-16 12:49:00.016 INFO (MainThread) [music_assistant] Finished job [Add spotify://artist/5GX4XzIgGGH93KvmLu85ZV to database] in 11.53 seconds.
2022-12-16 12:49:00.016 DEBUG (MainThread) [music_assistant.event] background_job_finished Add spotify://artist/5GX4XzIgGGH93KvmLu85ZV to database
2022-12-16 12:50:24.514 DEBUG (MainThread) [music_assistant.event] queue_updated media_player.keuken
2022-12-16 12:50:24.592 DEBUG (MainThread) [music_assistant.event] queue_updated media_player.keuken
2022-12-16 12:53:18.136 DEBUG (MainThread) [music_assistant.players.stream] client disconnected: 192.168.79.84
2022-12-16 12:53:23.155 DEBUG (MainThread) [music_assistant.helpers.audio] media stream aborted for: spotify://track/6u04aBSTpZDO8MuYC5e3DN
2022-12-16 12:53:23.156 DEBUG (MainThread) [music_assistant.event] background_job_updated Analyze audio for spotify://track/6u04aBSTpZDO8MuYC5e3DN
2022-12-16 12:53:23.156 DEBUG (MainThread) [music_assistant.event] background_job_updated Analyze audio for spotify://track/6u04aBSTpZDO8MuYC5e3DN
2022-12-16 12:53:23.157 DEBUG (MainThread) [music_assistant.helpers.audio] Start analyzing track spotify://track/6u04aBSTpZDO8MuYC5e3DN
2022-12-16 12:53:25.587 DEBUG (MainThread) [music_assistant.players.stream] Stream job f1c466bc94aa4d5bbdabe2fa6404c4ab cleaned up
2022-12-16 12:53:29.132 DEBUG (MainThread) [music_assistant.helpers.audio] Integrated loudness of spotify://track/6u04aBSTpZDO8MuYC5e3DN is: -9.9
2022-12-16 12:53:29.133 INFO (MainThread) [music_assistant] Finished job [Analyze audio for spotify://track/6u04aBSTpZDO8MuYC5e3DN] in 5.98 seconds.
2022-12-16 12:53:29.133 DEBUG (MainThread) [music_assistant.event] background_job_finished Analyze audio for spotify://track/6u04aBSTpZDO8MuYC5e3DN
2022-12-16 12:53:30.561 DEBUG (MainThread) [music_assistant.event] queue_updated media_player.keuken
2022-12-16 12:53:30.564 DEBUG (MainThread) [music_assistant.event] player_updated media_player.keuken
2022-12-16 12:53:30.576 DEBUG (MainThread) [music_assistant.event] queue_updated media_player.move
2022-12-16 12:53:30.581 DEBUG (MainThread) [music_assistant.event] player_updated media_player.move
2022-12-16 12:58:34.311 DEBUG (MainThread) [music_assistant.event] queue_updated media_player.living_2
2022-12-16 12:58:34.316 DEBUG (MainThread) [music_assistant.event] player_updated media_player.living_2
2022-12-16 12:58:34.354 DEBUG (MainThread) [music_assistant.event] player_updated media_player.living_2
2022-12-16 12:58:36.316 DEBUG (MainThread) [music_assistant.event] player_updated media_player.living_2
2022-12-16 12:58:36.561 DEBUG (MainThread) [music_assistant.event] player_updated media_player.living_2
2022-12-16 12:58:36.833 DEBUG (MainThread) [music_assistant.event] player_updated media_player.living_2
2022-12-16 12:58:37.081 DEBUG (MainThread) [music_assistant.event] player_updated media_player.living_2
2022-12-16 13:04:21.637 DEBUG (MainThread) [music_assistant.event] background_job_updated Cleanup cache
2022-12-16 13:04:21.637 DEBUG (MainThread) [music_assistant.event] background_job_updated Cleanup cache
2022-12-16 13:04:23.757 INFO (MainThread) [music_assistant] Finished job [Cleanup cache] in 2.12 seconds.
2022-12-16 13:04:23.757 DEBUG (MainThread) [music_assistant.event] background_job_finished Cleanup cache

gieljnssns commented 1 year ago

This is another, it is a different error, but the music also stops playing

2022-12-27 10:59:30.026 DEBUG (MainThread) [music_assistant.event] queue_updated media_player.keuken
2022-12-27 10:59:49.036 DEBUG (MainThread) [music_assistant.event] queue_updated media_player.keuken
2022-12-27 11:00:56.027 DEBUG (MainThread) [music_assistant.event] queue_updated media_player.keuken
2022-12-27 11:04:08.242 DEBUG (MainThread) [music_assistant.players.stream] client disconnected: 192.168.79.84
2022-12-27 11:04:09.314 DEBUG (MainThread) [custom_components.mass.player_controls.media_player.move] state_changed - old: playing - new: paused
2022-12-27 11:04:09.314 DEBUG (MainThread) [music_assistant.event] queue_updated media_player.move
2022-12-27 11:04:09.316 DEBUG (MainThread) [music_assistant.event] player_updated media_player.move
2022-12-27 11:04:09.318 DEBUG (MainThread) [custom_components.mass.player_controls.media_player.keuken] state_changed - old: playing - new: paused
2022-12-27 11:04:09.318 DEBUG (MainThread) [music_assistant.event] queue_updated media_player.keuken
2022-12-27 11:04:09.319 DEBUG (MainThread) [music_assistant.event] player_updated media_player.keuken
2022-12-27 11:04:09.320 DEBUG (MainThread) [custom_components.mass.player_controls.media_player.2c] state_changed - old: playing - new: paused
2022-12-27 11:04:09.320 DEBUG (MainThread) [music_assistant.event] queue_updated media_player.2c
2022-12-27 11:04:09.321 DEBUG (MainThread) [music_assistant.event] player_updated media_player.2c
2022-12-27 11:04:09.323 DEBUG (MainThread) [custom_components.mass.player_controls.media_player.2c] on_child_update [media_player.move] {'state'}
2022-12-27 11:04:09.323 DEBUG (MainThread) [custom_components.mass.player_controls.media_player.keuken] on_child_update [media_player.move] {'state'}
2022-12-27 11:04:09.326 DEBUG (MainThread) [custom_components.mass.player_controls.media_player.move] on_child_update [media_player.keuken] {'state'}
2022-12-27 11:04:09.326 DEBUG (MainThread) [custom_components.mass.player_controls.media_player.2c] on_child_update [media_player.keuken] {'state'}
2022-12-27 11:04:09.330 DEBUG (MainThread) [custom_components.mass.player_controls.media_player.move] on_child_update [media_player.2c] {'state'}
2022-12-27 11:04:09.330 DEBUG (MainThread) [custom_components.mass.player_controls.media_player.keuken] on_child_update [media_player.2c] {'state'}
2022-12-27 11:04:13.248 DEBUG (MainThread) [music_assistant.helpers.audio] media stream aborted for: tunein://radio/s309321
2022-12-27 11:04:15.249 ERROR (MainThread) [homeassistant] Error doing job: Task exception was never retrieved
Traceback (most recent call last):
  File "/usr/local/lib/python3.10/site-packages/music_assistant/controllers/streams.py", line 524, in _queue_stream_runner
    async for chunk in ffmpeg_proc.iter_chunked(self.output_chunksize):
  File "/usr/local/lib/python3.10/site-packages/music_assistant/helpers/process.py", line 91, in iter_chunked
    chunk = await self.readexactly(n)
  File "/usr/local/lib/python3.10/site-packages/music_assistant/helpers/process.py", line 110, in readexactly
    return await self._proc.stdout.readexactly(n)
  File "/usr/local/lib/python3.10/asyncio/streams.py", line 708, in readexactly
    await self._wait_for_data('readexactly')
  File "/usr/local/lib/python3.10/asyncio/streams.py", line 502, in _wait_for_data
    await self._waiter
asyncio.exceptions.CancelledError

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/lib/python3.10/site-packages/music_assistant/controllers/streams.py", line 496, in _queue_stream_runner
    async with AsyncProcess(ffmpeg_args, True) as ffmpeg_proc:
  File "/usr/local/lib/python3.10/site-packages/music_assistant/helpers/process.py", line 76, in __aexit__
    await self._attached_task
  File "/usr/local/lib/python3.10/site-packages/music_assistant/controllers/streams.py", line 500, in writer
    async for audio_chunk in self._get_queue_stream():
  File "/usr/local/lib/python3.10/site-packages/music_assistant/controllers/streams.py", line 670, in _get_queue_stream
    async for chunk in get_media_stream(
  File "/usr/local/lib/python3.10/site-packages/music_assistant/helpers/audio.py", line 387, in get_media_stream
    async with AsyncProcess(
  File "/usr/local/lib/python3.10/site-packages/music_assistant/helpers/process.py", line 76, in __aexit__
    await self._attached_task
  File "/usr/local/lib/python3.10/site-packages/music_assistant/helpers/audio.py", line 397, in writer
    async for audio_chunk in music_prov.get_audio_stream(
  File "/usr/local/lib/python3.10/site-packages/music_assistant/music_providers/tunein/tunein.py", line 202, in get_audio_stream
    async for chunk in get_radio_stream(
  File "/usr/local/lib/python3.10/site-packages/music_assistant/helpers/audio.py", line 456, in get_radio_stream
    stream_title = stream_title.group(1).decode()
UnicodeDecodeError: 'utf-8' codec can't decode byte 0xc6 in position 16: invalid continuation byte
2022-12-27 11:04:15.750 DEBUG (MainThread) [music_assistant.players.stream] Stream job 060d81899152452db44a0ac070dd6ce7 cleaned up

OzGav commented 1 year ago

Thanks. Hang on to these errors. We will see if they are still present in the next version of MA.

MysticNynja commented 1 year ago

When is the next version coming out? I am using YouTube Music and in its current state I still haven't been able to listen to a full album without at least 1 song cutting out.

OzGav commented 1 year ago

Still a few weeks away

MysticNynja commented 1 year ago

Ok just as long as it wasn't released and I'm still getting the errors. Thanks!

erkr commented 1 year ago

The next release is a huge overhaul, both the architecture and a lot of new features. I understood it will take another month or so before it can be released.

MysticNynja commented 1 year ago

Ok I would love to see what it can do and I will report my bugs I found so far after its release. I feel like if I did it now it would be a bunch of "wait for the new release" and I completely understand that.

erkr commented 1 year ago

Yes that is probably true 🤓 Issues related to regression caused by core updates are still handled

TheNuggMaster commented 1 year ago

Is this still occuring? As i understand a new version came out... I'm new and seem to be having this issue, though with yt music and google cast devices - trying to figure out if it's the same thing as you and if the update fixed it in your case

MysticNynja commented 1 year ago

I haven't used this since the update. I'll check this afternoon and reply here.

erkr commented 1 year ago

Hi, the new version 2.0 is still under development and not yet released. The recent release versions are only patch versions to keep related MA working with new HA versions. The playback stability issues are know and will be resolved when the new MA 2 is ready. MA 2.0 will introduce an add on. Add ons run in their own isolated proces. That will make MA more stable

TheNuggMaster commented 1 year ago

Hi @erkr , thanks for the info - it seems i misinterpreted something. I'll anxiously await the release of MA 2.0 then! Sounds like it'll solve more than one issue i've been having, can't wait. Cheers

OzGav commented 1 year ago

@gieljnssns please advise if this is resolved in v2

gieljnssns commented 1 year ago

Will try tomorrow

gieljnssns commented 1 year ago

Solved

music-assistant / hass-music-assistant

Music stops playing #996

What version of Music Assistant has the issue?

The problem

How to reproduce

Relevant log output

Additional information

What version of Home Assistant Core are your running

What type of installation are you running?

On what type of hardware are you running?