noaione / spotilava

An implementation of Native Spotify player for Lavalink/Lavaplayer with Webserver as is intermediary.
MIT License
6 stars 0 forks source link

[Bug] Lavalink throws an error and stream stops #12

Open Hydro001 opened 2 years ago

Hydro001 commented 2 years ago

Describe the bug Lavalink throws an error after playing for something like 2 minutes (Even though the music i gave below is like 4 minutes long) and the stream stops :

Lavalink logs :

PS C:\Users\Hydro\Documents\Projects\Bots\Test> java -jar .\Lavalink.jar
2022-11-16 15:47:53.184  INFO 5632 --- [           main] lavalink.server.Launcher                 : Starting Launcher using Java 17.0.4.1 on DESKTOP-O0QE9EJ with PID 5632 (C:\Users\Hydro\Documents\Projects\Bots\Test\Lavalink.jar started by Hydro in C:\Users\Hydro\Documents\Projects\Bots\Test)
2022-11-16 15:47:53.186  INFO 5632 --- [           main] lavalink.server.Launcher                 : No active profile set, falling back to 1 default profile: "default"
2022-11-16 15:47:53.781  INFO 5632 --- [           main] lavalink.server.Launcher                 : Started Launcher in 0.884 seconds (JVM running for 1.156)
2022-11-16 15:47:53.782  INFO 5632 --- [           main] lavalink.server.Launcher                 : You can safely ignore the big red warning about illegal reflection. See https://github.com/freyacodes/Lavalink/issues/295
2022-11-16 15:47:53.817  INFO 5632 --- [           main] lavalink.server.Launcher                 :

       .   _                  _ _       _    __ _ _
      /\\ | | __ ___   ____ _| (_)_ __ | | __\ \ \ \
     ( ( )| |/ _` \ \ / / _` | | | '_ \| |/ / \ \ \ \
      \\/ | | (_| |\ V / (_| | | | | | |   <   ) ) ) )
       '  |_|\__,_| \_/ \__,_|_|_|_| |_|_|\_\ / / / /
    =========================================/_/_/_/

        Version:        3.6.2
        Build time:     08.11.2022 09:02:53 UTC
        Branch          HEAD
        Commit:         4782f1f
        Commit time:    08.11.2022 09:01:14 UTC
        JVM:            17.0.4.1
        Lavaplayer      1.3.99.1-original

2022-11-16 15:47:53.821  INFO 5632 --- [           main] lavalink.server.Launcher                 : No active profile set, falling back to 1 default profile: "default"
2022-11-16 15:47:54.225  WARN 5632 --- [           main] io.undertow.websockets.jsr               : UT026010: Buffer pool was not set on WebSocketDeploymentInfo, the default pool will be used
2022-11-16 15:47:54.238  INFO 5632 --- [           main] io.undertow.servlet                      : Initializing Spring embedded WebApplicationContext
2022-11-16 15:47:54.238  INFO 5632 --- [           main] w.s.c.ServletWebServerApplicationContext : Root WebApplicationContext: initialization completed in 414 ms
2022-11-16 15:47:54.380  INFO 5632 --- [           main] c.s.d.l.tools.GarbageCollectionMonitor   : GC monitoring enabled, reporting results every 2 minutes.
2022-11-16 15:47:54.400  INFO 5632 --- [           main] c.s.d.l.s.y.YoutubeAccessTokenTracker    : Updating YouTube master token (current is null).
2022-11-16 15:47:54.520  INFO 5632 --- [           main] lavalink.server.config.KoeConfiguration  : OS: WINDOWS, Arch: X86_64
2022-11-16 15:47:54.520  INFO 5632 --- [           main] lavalink.server.config.KoeConfiguration  : Enabling JDA-NAS
2022-11-16 15:47:54.523  INFO 5632 --- [           main] c.s.l.c.natives.NativeLibraryLoader      : Native library udpqueue: loading with filter null
2022-11-16 15:47:54.527  INFO 5632 --- [           main] c.s.l.c.natives.NativeLibraryLoader      : Native library udpqueue: successfully loaded.
2022-11-16 15:47:54.542  WARN 5632 --- [           main] l.server.config.SentryConfiguration      : Turning off sentry
2022-11-16 15:47:54.703  INFO 5632 --- [           main] io.undertow                              : starting server: Undertow - 2.2.16.Final
2022-11-16 15:47:54.711  INFO 5632 --- [           main] org.xnio                                 : XNIO version 3.8.6.Final
2022-11-16 15:47:54.716  INFO 5632 --- [           main] org.xnio.nio                             : XNIO NIO Implementation Version 3.8.6.Final
2022-11-16 15:47:54.758  INFO 5632 --- [           main] org.jboss.threads                        : JBoss Threads version 3.1.0.Final
2022-11-16 15:47:54.787  INFO 5632 --- [           main] o.s.b.w.e.undertow.UndertowWebServer     : Undertow started on port(s) 49500 (http)
2022-11-16 15:47:54.789  INFO 5632 --- [           main] lavalink.server.Launcher                 : Started Launcher in 1.004 seconds (JVM running for 2.165)
2022-11-16 15:47:54.790  INFO 5632 --- [           main] lavalink.server.Launcher                 : Lavalink is ready to accept connections.
2022-11-16 15:47:54.855  INFO 5632 --- [onPool-worker-1] c.s.d.l.s.y.YoutubeAccessTokenTracker    : Updating YouTube master token succeeded, new token is hidden.
2022-11-16 15:48:09.836  INFO 5632 --- [  XNIO-1 task-1] io.undertow.servlet                      : Initializing Spring DispatcherServlet 'dispatcherServlet'
2022-11-16 15:48:09.836  INFO 5632 --- [  XNIO-1 task-1] o.s.web.servlet.DispatcherServlet        : Initializing Servlet 'dispatcherServlet'
2022-11-16 15:48:09.836  INFO 5632 --- [  XNIO-1 task-1] o.s.web.servlet.DispatcherServlet        : Completed initialization in 0 ms
2022-11-16 15:48:09.847  INFO 5632 --- [  XNIO-1 task-2] l.server.io.HandshakeInterceptorImpl     : Incoming connection from /[0:0:0:0:0:0:0:1]:55414
2022-11-16 15:48:09.853  INFO 5632 --- [  XNIO-1 task-1] l.server.player.AudioLoaderRestHandler   : Got request to load for identifier "http://127.0.0.1:37784/2YvPExdxrJittKb0cNlcft/listen?q=normal"
2022-11-16 15:48:09.882  INFO 5632 --- [  XNIO-1 task-2] lavalink.server.io.SocketServer          : Connection successfully established from shoukakubot/3.2.2 (https://github.com/Deivu/Shoukaku)
2022-11-16 15:48:10.235  INFO 5632 --- [ader-2-thread-1] lavalink.server.player.AudioLoader       : Loaded track Unknown title
2022-11-16 15:48:10.474  INFO 5632 --- [   XNIO-1 I/O-4] lavalink.server.io.SocketServer          : {"op":"voiceUpdate","guildId":"hidden","sessionId":"hidden","event":{"token":"hidden","guild_id":"hidden","endpoint":"hidden"}}
2022-11-16 15:48:10.522  INFO 5632 --- [   XNIO-1 I/O-4] lavalink.server.io.SocketServer          : {"op":"play","guildId":"hidden","track":"hidden","noReplace":true,"pause":false}
2022-11-16 15:48:11.504  INFO 5632 --- [back-1-thread-1] c.s.l.c.natives.NativeLibraryLoader      : Native library libmpg123-0: loading with filter com.sedmelluq.discord.lavaplayer.natives.ConnectorNativeLibLoader$$Lambda$822/0x00000008012cc088@2a686440
2022-11-16 15:48:11.507  INFO 5632 --- [back-1-thread-1] c.s.l.c.natives.NativeLibraryLoader      : Native library libmpg123-0: successfully loaded.
2022-11-16 15:48:11.508  INFO 5632 --- [back-1-thread-1] c.s.l.c.natives.NativeLibraryLoader      : Native library connector: loading with filter null
2022-11-16 15:48:11.523  INFO 5632 --- [back-1-thread-1] c.s.l.c.natives.NativeLibraryLoader      : Native library connector: successfully loaded.
2022-11-16 15:50:41.036 ERROR 5632 --- [back-1-thread-1] c.s.d.l.t.p.LocalAudioTrackExecutor      : Error in playback of http://127.0.0.1:37784/2YvPExdxrJittKb0cNlcft/listen?q=normal

com.sedmelluq.discord.lavaplayer.tools.FriendlyException: Something went wrong when decoding the track.
        at com.sedmelluq.discord.lavaplayer.tools.ExceptionTools.wrapUnfriendlyExceptions(ExceptionTools.java:44) ~[lavaplayer-1.3.99.1.jar!/:na]
        at com.sedmelluq.discord.lavaplayer.track.playback.LocalAudioTrackExecutor.executeProcessingLoop(LocalAudioTrackExecutor.java:293) ~[lavaplayer-1.3.99.1.jar!/:na]
        at com.sedmelluq.discord.lavaplayer.container.ogg.OggAudioTrack.process(OggAudioTrack.java:39) ~[lavaplayer-1.3.99.1.jar!/:na]
        at com.sedmelluq.discord.lavaplayer.track.DelegatedAudioTrack.processDelegate(DelegatedAudioTrack.java:25) ~[lavaplayer-1.3.99.1.jar!/:na]
        at com.sedmelluq.discord.lavaplayer.source.http.HttpAudioTrack.process(HttpAudioTrack.java:53) ~[lavaplayer-1.3.99.1.jar!/:na]
        at com.sedmelluq.discord.lavaplayer.track.playback.LocalAudioTrackExecutor.execute(LocalAudioTrackExecutor.java:104) ~[lavaplayer-1.3.99.1.jar!/:na]
        at com.sedmelluq.discord.lavaplayer.player.DefaultAudioPlayerManager.lambda$executeTrack$1(DefaultAudioPlayerManager.java:354) ~[lavaplayer-1.3.99.1.jar!/:na]
        at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) ~[na:na]
        at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) ~[na:na]
        at java.base/java.lang.Thread.run(Thread.java:833) ~[na:na]
        Suppressed: com.sedmelluq.discord.lavaplayer.tools.exception.EnvironmentInformation:
  lavaplayer.version: 1.3.99.1-original
  os.arch: amd64
  os.name: Windows 10
  os.version: 10.0
  java.vendor: Oracle Corporation
  java.version: 17.0.4.1
  java.runtime.version: 17.0.4.1+1-LTS-2
  java.vm.version: 17.0.4.1+1-LTS-2
Caused by: java.lang.IllegalStateException: Passing input failed with error -135.
        at com.sedmelluq.discord.lavaplayer.natives.vorbis.VorbisDecoder.input(VorbisDecoder.java:69) ~[lavaplayer-1.3.99.1.jar!/:na]
        at com.sedmelluq.discord.lavaplayer.container.ogg.vorbis.OggVorbisTrackHandler.provideFromBuffer(OggVorbisTrackHandler.java:84) ~[lavaplayer-1.3.99.1.jar!/:na]
        at com.sedmelluq.discord.lavaplayer.container.ogg.vorbis.OggVorbisTrackHandler.provideFrames(OggVorbisTrackHandler.java:76) ~[lavaplayer-1.3.99.1.jar!/:na]
        at com.sedmelluq.discord.lavaplayer.container.ogg.OggAudioTrack.processTrackLoop(OggAudioTrack.java:58) ~[lavaplayer-1.3.99.1.jar!/:na]
        at com.sedmelluq.discord.lavaplayer.container.ogg.OggAudioTrack.lambda$process$0(OggAudioTrack.java:41) ~[lavaplayer-1.3.99.1.jar!/:na]
        at com.sedmelluq.discord.lavaplayer.track.playback.LocalAudioTrackExecutor.executeProcessingLoop(LocalAudioTrackExecutor.java:275) ~[lavaplayer-1.3.99.1.jar!/:na]
        ... 8 common frames omitted

PS C:\Users\Hydro\Documents\Projects\Bots\Test> 2022-11-16 15:52:21.592  INFO 5632 --- [ionShutdownHook] io.undertow                              : stopping server: Undertow - 2.2.16.Final
2022-11-16 15:52:21.593 ERROR 5632 --- [   XNIO-1 I/O-4] org.xnio.listener                        : XNIO001007: A channel event listener threw an exception

java.util.concurrent.RejectedExecutionException: XNIO007007: Thread is terminating
        at org.xnio.nio.WorkerThread.execute(WorkerThread.java:620) ~[xnio-nio-3.8.6.Final.jar!/:3.8.6.Final]
        at io.undertow.websockets.jsr.UndertowSession$3.handleEvent(UndertowSession.java:396) ~[undertow-websockets-jsr-2.2.16.Final.jar!/:2.2.16.Final]
        at io.undertow.websockets.jsr.UndertowSession$3.handleEvent(UndertowSession.java:388) ~[undertow-websockets-jsr-2.2.16.Final.jar!/:2.2.16.Final]
        at org.xnio.ChannelListeners.invokeChannelListener(ChannelListeners.java:92) ~[xnio-api-3.8.6.Final.jar!/:3.8.6.Final]
        at io.undertow.server.protocol.framed.AbstractFramedChannel$FrameCloseListener.handleEvent(AbstractFramedChannel.java:1081) ~[undertow-core-2.2.16.Final.jar!/:2.2.16.Final]
        at io.undertow.server.protocol.framed.AbstractFramedChannel$FrameCloseListener.handleEvent(AbstractFramedChannel.java:994) ~[undertow-core-2.2.16.Final.jar!/:2.2.16.Final]
        at org.xnio.ChannelListeners.invokeChannelListener(ChannelListeners.java:92) ~[xnio-api-3.8.6.Final.jar!/:3.8.6.Final]
        at org.xnio.conduits.WriteReadyHandler$ChannelListenerHandler.terminated(WriteReadyHandler.java:70) ~[xnio-api-3.8.6.Final.jar!/:3.8.6.Final]
        at org.xnio.nio.NioSocketConduit.writeTerminated(NioSocketConduit.java:204) ~[xnio-nio-3.8.6.Final.jar!/:3.8.6.Final]
        at org.xnio.nio.NioSocketConduit.terminateWrites(NioSocketConduit.java:193) ~[xnio-nio-3.8.6.Final.jar!/:3.8.6.Final]
        at org.xnio.nio.NioSocketConduit.truncateWrites(NioSocketConduit.java:198) ~[xnio-nio-3.8.6.Final.jar!/:3.8.6.Final]
        at io.undertow.conduits.IdleTimeoutConduit.truncateWrites(IdleTimeoutConduit.java:387) ~[undertow-core-2.2.16.Final.jar!/:2.2.16.Final]
        at org.xnio.conduits.ConduitStreamSinkChannel.close(ConduitStreamSinkChannel.java:186) ~[xnio-api-3.8.6.Final.jar!/:3.8.6.Final]
        at org.xnio.IoUtils.safeClose(IoUtils.java:152) ~[xnio-api-3.8.6.Final.jar!/:3.8.6.Final]
        at org.xnio.conduits.WriteReadyHandler$ChannelListenerHandler.forceTermination(WriteReadyHandler.java:57) ~[xnio-api-3.8.6.Final.jar!/:3.8.6.Final]
        at org.xnio.nio.NioSocketConduit.forceTermination(NioSocketConduit.java:108) ~[xnio-nio-3.8.6.Final.jar!/:3.8.6.Final]
        at org.xnio.nio.WorkerThread.run(WorkerThread.java:507) ~[xnio-nio-3.8.6.Final.jar!/:3.8.6.Final]

2022-11-16 15:52:21.594  INFO 5632 --- [ionShutdownHook] io.undertow.servlet                      : Destroying Spring FrameworkServlet 'dispatcherServlet'
2022-11-16 15:52:21.594  INFO 5632 --- [ionShutdownHook] c.s.d.l.tools.GarbageCollectionMonitor   : GC monitoring disabled.

Spotilava logs:

(venv) PS C:\Users\Hydro\Documents\Projects\Spotilava> py app.py
[2022-11-16 15:47:34 DESKTOP-O0QE9EJ][INFO] (root[2508]): <module>: App: Initiating spotilava webserver...
C:\Users\Hydro\Documents\Projects\Spotilava\app.py:82: DeprecationWarning: There is no current event loop
  loop = asyncio.get_event_loop()
[2022-11-16 15:47:34 +0100] [2508] [INFO]
  ┌─────────────────────────────────────────────────────────────┐
  │                        Sanic v22.9.1                        │
  │              Goin' Fast @ http://0.0.0.0:37784              │
  ├───────────────────────┬─────────────────────────────────────┤
  │                       │     mode: production, single worker │
  │     ▄███ █████ ██     │   server: sanic, HTTP/1.1           │
  │    ██                 │   python: 3.10.8                    │
  │     ▀███████ ███▄     │ platform: Windows-10-10.0.19045-SP0 │
  │                 ██    │ packages: sanic-routing==22.8.0     │
  │    ████ ████████▀     │                                     │
  │                       │                                     │
  │ Build Fast. Run Fast. │                                     │
  └───────────────────────┴─────────────────────────────────────┘

[2022-11-16 15:47:34 DESKTOP-O0QE9EJ][INFO] (sanic.root[2508]): display:
  ┌─────────────────────────────────────────────────────────────┐
  │                        Sanic v22.9.1                        │
  │              Goin' Fast @ http://0.0.0.0:37784              │
  ├───────────────────────┬─────────────────────────────────────┤
  │                       │     mode: production, single worker │
  │     ▄███ █████ ██     │   server: sanic, HTTP/1.1           │
  │    ██                 │   python: 3.10.8                    │
  │     ▀███████ ███▄     │ platform: Windows-10-10.0.19045-SP0 │
  │                 ██    │ packages: sanic-routing==22.8.0     │
  │    ████ ████████▀     │                                     │
  │                       │                                     │
  │ Build Fast. Run Fast. │                                     │
  └───────────────────────┴─────────────────────────────────────┘

[2022-11-16 15:47:34 +0100] [2508] [WARNING] Sanic is running in PRODUCTION mode. Consider using '--debug' or '--dev' while actively developing your application.
[2022-11-16 15:47:34 DESKTOP-O0QE9EJ][WARNING] (sanic.error[2508]): _helper: Sanic is running in PRODUCTION mode. Consider using '--debug' or '--dev' while actively developing your application.
[2022-11-16 15:47:34 DESKTOP-O0QE9EJ][INFO] (root[13840]): <module>: App: Initiating spotilava webserver...
[2022-11-16 15:47:35 DESKTOP-O0QE9EJ][INFO] (root[12108]): <module>: App: Initiating spotilava webserver...
[2022-11-16 15:47:35 DESKTOP-O0QE9EJ][INFO] (root[12108]): connect_spotify: App: Creating spotify wrapper...
[2022-11-16 15:47:35 DESKTOP-O0QE9EJ][INFO] (SpotifyWrapper[12108]): __init__: Spotify: Using saved credentials <C:\Users\Hydro\Documents\Projects\Spotilava\config\spotify.json>
[2022-11-16 15:47:35 DESKTOP-O0QE9EJ][INFO] (SpotifyWrapper[12108]): create: Spotify: Fetching random access point
[2022-11-16 15:47:35 DESKTOP-O0QE9EJ][INFO] (root[12108]): connect_tidal: App: Tidal is disabled.
[2022-11-16 15:47:35 +0100] [12108] [INFO] Starting worker [12108]
[2022-11-16 15:47:35 DESKTOP-O0QE9EJ][INFO] (sanic.server[12108]): _run_server_forever: Starting worker [12108]
[2022-11-16 15:47:35 DESKTOP-O0QE9EJ][INFO] (SpotifyWrapper[12108]): create: Spotify: Creating session
[2022-11-16 15:47:35 DESKTOP-O0QE9EJ][INFO] (Librespot:Session[12108]): __init__: Created new session! device_id: hidden, ap: hidden
[2022-11-16 15:47:35 DESKTOP-O0QE9EJ][INFO] (SpotifyWrapper[12108]): create: Spotify: Connecting to session <None> [LIBRESpotify-Spotilava]
[2022-11-16 15:47:36 DESKTOP-O0QE9EJ][INFO] (Librespot:Session[12108]): connect: Connection successfully!
[2022-11-16 15:47:36 DESKTOP-O0QE9EJ][INFO] (SpotifyWrapper[12108]): create: Spotify: Connected, authenticating...
[2022-11-16 15:47:36 DESKTOP-O0QE9EJ][INFO] (Librespot:Session[12108]): run: Session.Receiver started
[2022-11-16 15:47:36 DESKTOP-O0QE9EJ][INFO] (Librespot:Session[12108]): run: Skipping 02
[2022-11-16 15:47:36 DESKTOP-O0QE9EJ][INFO] (Librespot:Session[12108]): run: Received license_version: 0
[2022-11-16 15:47:36 DESKTOP-O0QE9EJ][INFO] (Librespot:Session[12108]): run: Received country_code: FR
[2022-11-16 15:47:36 DESKTOP-O0QE9EJ][INFO] (Librespot:Session[12108]): run: Skipping 1f
[2022-11-16 15:47:36 DESKTOP-O0QE9EJ][INFO] (Librespot:Session[12108]): run: Skipping 69
[2022-11-16 15:47:36 DESKTOP-O0QE9EJ][INFO] (Librespot:Session[12108]): run: Skipping unknown command cmd: 0x75, payload: b'\x00\x00\x00'
[2022-11-16 15:47:36 DESKTOP-O0QE9EJ][INFO] (Librespot:Session[12108]): authenticate: Authenticated as hidden!
[2022-11-16 15:47:36 DESKTOP-O0QE9EJ][INFO] (SpotifyWrapper[12108]): create: Spotify: Authenticated
[2022-11-16 15:48:09 DESKTOP-O0QE9EJ][INFO] (Routes.Tracks[12108]): get_track_listen: TrackListen: Received request for track <2YvPExdxrJittKb0cNlcft>
[2022-11-16 15:48:09 DESKTOP-O0QE9EJ][INFO] (SpotifyWrapper[12108]): get_track: SpotifyTrack: Fetching track <2YvPExdxrJittKb0cNlcft>
[2022-11-16 15:48:10 DESKTOP-O0QE9EJ][INFO] (Spotilava:Player:AutoFallbackAudioQuality[12108]): get_file: Selected audio format OGG_VORBIS_160
[2022-11-16 15:48:10 DESKTOP-O0QE9EJ][INFO] (SpotifyWrapper[12108]): get_track: SpotifyTrack: Fetching track <2YvPExdxrJittKb0cNlcft> complete, now fetching stream...
[2022-11-16 15:48:10 DESKTOP-O0QE9EJ][INFO] (SpotifyWrapper[12108]): get_track: SpotifyTrack: Track <2YvPExdxrJittKb0cNlcft> loaded, returning data
[2022-11-16 15:48:10 DESKTOP-O0QE9EJ][INFO] (Internals.Spotify[12108]): should_inject_metadata: MetaInjectTest: Checking bytes header for OggS...
[2022-11-16 15:48:10 DESKTOP-O0QE9EJ][INFO] (Internals.Spotify[12108]): should_inject_metadata: MetaInjectTest: Found OggS header, injecting metadata...
[2022-11-16 15:48:10 DESKTOP-O0QE9EJ][WARNING] (Internals.Spotify[12108]): inject_ogg_metadata: OggInject: Unable to open track/episode <2YvPExdxrJittKb0cNlcft>
Traceback (most recent call last):
  File "C:\Users\Hydro\Documents\Projects\Spotilava\venv\lib\site-packages\mutagen\ogg.py", line 534, in load
    self.tags = self._Tags(fileobj, self.info)
  File "C:\Users\Hydro\Documents\Projects\Spotilava\venv\lib\site-packages\mutagen\oggvorbis.py", line 109, in __init__
    page = OggPage(fileobj)
  File "C:\Users\Hydro\Documents\Projects\Spotilava\venv\lib\site-packages\mutagen\ogg.py", line 117, in __init__
    raise error("unable to read full data")
mutagen.ogg.error: unable to read full data

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "C:\Users\Hydro\Documents\Projects\Spotilava\internals\spotify\client.py", line 644, in inject_ogg_metadata
    ogg_metadata = OggVorbis(io_bita)
  File "C:\Users\Hydro\Documents\Projects\Spotilava\venv\lib\site-packages\mutagen\_file.py", line 47, in __init__
    self.load(*args, **kwargs)
  File "C:\Users\Hydro\Documents\Projects\Spotilava\venv\lib\site-packages\mutagen\_util.py", line 155, in wrapper
    return func(self, h, *args, **kwargs)
  File "C:\Users\Hydro\Documents\Projects\Spotilava\venv\lib\site-packages\mutagen\ogg.py", line 537, in load
    reraise(self._Error, e, sys.exc_info()[2])
  File "C:\Users\Hydro\Documents\Projects\Spotilava\venv\lib\site-packages\mutagen\_util.py", line 42, in reraise
    raise tp(value).with_traceback(tb)
  File "C:\Users\Hydro\Documents\Projects\Spotilava\venv\lib\site-packages\mutagen\ogg.py", line 534, in load
    self.tags = self._Tags(fileobj, self.info)
  File "C:\Users\Hydro\Documents\Projects\Spotilava\venv\lib\site-packages\mutagen\oggvorbis.py", line 109, in __init__
    page = OggPage(fileobj)
  File "C:\Users\Hydro\Documents\Projects\Spotilava\venv\lib\site-packages\mutagen\ogg.py", line 117, in __init__
    raise error("unable to read full data")
mutagen.oggvorbis.OggVorbisHeaderError: unable to read full data
[2022-11-16 15:48:10 DESKTOP-O0QE9EJ][INFO] (Routes.Tracks[12108]): get_track_listen: TrackListen: Sending track <2YvPExdxrJittKb0cNlcft>
[2022-11-16 15:48:10 DESKTOP-O0QE9EJ][INFO] (Routes.Tracks[12108]): track_stream: TrackListen: Streaming track <2YvPExdxrJittKb0cNlcft> with bytes 0-4516092
[2022-11-16 15:48:10 DESKTOP-O0QE9EJ][INFO] (Routes.Tracks[12108]): get_track_listen: TrackListen: Received request for track <2YvPExdxrJittKb0cNlcft>
[2022-11-16 15:48:10 DESKTOP-O0QE9EJ][INFO] (SpotifyWrapper[12108]): get_track: SpotifyTrack: Fetching track <2YvPExdxrJittKb0cNlcft>
[2022-11-16 15:48:10 DESKTOP-O0QE9EJ][INFO] (Spotilava:Player:AutoFallbackAudioQuality[12108]): get_file: Selected audio format OGG_VORBIS_160
[2022-11-16 15:48:11 DESKTOP-O0QE9EJ][INFO] (SpotifyWrapper[12108]): get_track: SpotifyTrack: Fetching track <2YvPExdxrJittKb0cNlcft> complete, now fetching stream...
[2022-11-16 15:48:11 DESKTOP-O0QE9EJ][INFO] (SpotifyWrapper[12108]): get_track: SpotifyTrack: Track <2YvPExdxrJittKb0cNlcft> loaded, returning data
[2022-11-16 15:48:11 DESKTOP-O0QE9EJ][INFO] (Internals.Spotify[12108]): should_inject_metadata: MetaInjectTest: Checking bytes header for OggS...
[2022-11-16 15:48:11 DESKTOP-O0QE9EJ][INFO] (Internals.Spotify[12108]): should_inject_metadata: MetaInjectTest: Found OggS header, injecting metadata...
[2022-11-16 15:48:11 DESKTOP-O0QE9EJ][WARNING] (Internals.Spotify[12108]): inject_ogg_metadata: OggInject: Unable to open track/episode <2YvPExdxrJittKb0cNlcft>
Traceback (most recent call last):
  File "C:\Users\Hydro\Documents\Projects\Spotilava\venv\lib\site-packages\mutagen\ogg.py", line 534, in load
    self.tags = self._Tags(fileobj, self.info)
  File "C:\Users\Hydro\Documents\Projects\Spotilava\venv\lib\site-packages\mutagen\oggvorbis.py", line 109, in __init__
    page = OggPage(fileobj)
  File "C:\Users\Hydro\Documents\Projects\Spotilava\venv\lib\site-packages\mutagen\ogg.py", line 117, in __init__
    raise error("unable to read full data")
mutagen.ogg.error: unable to read full data

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "C:\Users\Hydro\Documents\Projects\Spotilava\internals\spotify\client.py", line 644, in inject_ogg_metadata
    ogg_metadata = OggVorbis(io_bita)
  File "C:\Users\Hydro\Documents\Projects\Spotilava\venv\lib\site-packages\mutagen\_file.py", line 47, in __init__
    self.load(*args, **kwargs)
  File "C:\Users\Hydro\Documents\Projects\Spotilava\venv\lib\site-packages\mutagen\_util.py", line 155, in wrapper
    return func(self, h, *args, **kwargs)
  File "C:\Users\Hydro\Documents\Projects\Spotilava\venv\lib\site-packages\mutagen\ogg.py", line 537, in load
    reraise(self._Error, e, sys.exc_info()[2])
  File "C:\Users\Hydro\Documents\Projects\Spotilava\venv\lib\site-packages\mutagen\_util.py", line 42, in reraise
    raise tp(value).with_traceback(tb)
  File "C:\Users\Hydro\Documents\Projects\Spotilava\venv\lib\site-packages\mutagen\ogg.py", line 534, in load
    self.tags = self._Tags(fileobj, self.info)
  File "C:\Users\Hydro\Documents\Projects\Spotilava\venv\lib\site-packages\mutagen\oggvorbis.py", line 109, in __init__
    page = OggPage(fileobj)
  File "C:\Users\Hydro\Documents\Projects\Spotilava\venv\lib\site-packages\mutagen\ogg.py", line 117, in __init__
    raise error("unable to read full data")
mutagen.oggvorbis.OggVorbisHeaderError: unable to read full data
[2022-11-16 15:48:11 DESKTOP-O0QE9EJ][INFO] (Routes.Tracks[12108]): get_track_listen: TrackListen: Sending track <2YvPExdxrJittKb0cNlcft>
[2022-11-16 15:48:11 DESKTOP-O0QE9EJ][INFO] (Routes.Tracks[12108]): track_stream: TrackListen: Streaming track <2YvPExdxrJittKb0cNlcft> with bytes 0-4516092
[2022-11-16 15:50:40 DESKTOP-O0QE9EJ][INFO] (Routes.Tracks[12108]): get_track_listen: TrackListen: Received request for track <2YvPExdxrJittKb0cNlcft>
[2022-11-16 15:50:40 DESKTOP-O0QE9EJ][INFO] (SpotifyWrapper[12108]): get_track: SpotifyTrack: Fetching track <2YvPExdxrJittKb0cNlcft>
[2022-11-16 15:50:40 DESKTOP-O0QE9EJ][INFO] (Spotilava:Player:AutoFallbackAudioQuality[12108]): get_file: Selected audio format OGG_VORBIS_160
[2022-11-16 15:50:40 DESKTOP-O0QE9EJ][INFO] (SpotifyWrapper[12108]): get_track: SpotifyTrack: Fetching track <2YvPExdxrJittKb0cNlcft> complete, now fetching stream...
[2022-11-16 15:50:40 DESKTOP-O0QE9EJ][INFO] (SpotifyWrapper[12108]): get_track: SpotifyTrack: Track <2YvPExdxrJittKb0cNlcft> loaded, returning data
[2022-11-16 15:50:40 DESKTOP-O0QE9EJ][INFO] (Internals.Spotify[12108]): should_inject_metadata: MetaInjectTest: Checking bytes header for OggS...
[2022-11-16 15:50:40 DESKTOP-O0QE9EJ][INFO] (Internals.Spotify[12108]): should_inject_metadata: MetaInjectTest: Found OggS header, injecting metadata...
[2022-11-16 15:50:40 DESKTOP-O0QE9EJ][WARNING] (Internals.Spotify[12108]): inject_ogg_metadata: OggInject: Unable to open track/episode <2YvPExdxrJittKb0cNlcft>
Traceback (most recent call last):
  File "C:\Users\Hydro\Documents\Projects\Spotilava\venv\lib\site-packages\mutagen\ogg.py", line 534, in load
    self.tags = self._Tags(fileobj, self.info)
  File "C:\Users\Hydro\Documents\Projects\Spotilava\venv\lib\site-packages\mutagen\oggvorbis.py", line 109, in __init__
    page = OggPage(fileobj)
  File "C:\Users\Hydro\Documents\Projects\Spotilava\venv\lib\site-packages\mutagen\ogg.py", line 117, in __init__
    raise error("unable to read full data")
mutagen.ogg.error: unable to read full data

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "C:\Users\Hydro\Documents\Projects\Spotilava\internals\spotify\client.py", line 644, in inject_ogg_metadata
    ogg_metadata = OggVorbis(io_bita)
  File "C:\Users\Hydro\Documents\Projects\Spotilava\venv\lib\site-packages\mutagen\_file.py", line 47, in __init__
    self.load(*args, **kwargs)
  File "C:\Users\Hydro\Documents\Projects\Spotilava\venv\lib\site-packages\mutagen\_util.py", line 155, in wrapper
    return func(self, h, *args, **kwargs)
  File "C:\Users\Hydro\Documents\Projects\Spotilava\venv\lib\site-packages\mutagen\ogg.py", line 537, in load
    reraise(self._Error, e, sys.exc_info()[2])
  File "C:\Users\Hydro\Documents\Projects\Spotilava\venv\lib\site-packages\mutagen\_util.py", line 42, in reraise
    raise tp(value).with_traceback(tb)
  File "C:\Users\Hydro\Documents\Projects\Spotilava\venv\lib\site-packages\mutagen\ogg.py", line 534, in load
    self.tags = self._Tags(fileobj, self.info)
  File "C:\Users\Hydro\Documents\Projects\Spotilava\venv\lib\site-packages\mutagen\oggvorbis.py", line 109, in __init__
    page = OggPage(fileobj)
  File "C:\Users\Hydro\Documents\Projects\Spotilava\venv\lib\site-packages\mutagen\ogg.py", line 117, in __init__
    raise error("unable to read full data")
mutagen.oggvorbis.OggVorbisHeaderError: unable to read full data
[2022-11-16 15:50:40 DESKTOP-O0QE9EJ][INFO] (Routes.Tracks[12108]): get_track_listen: TrackListen: Sending track <2YvPExdxrJittKb0cNlcft>
[2022-11-16 15:50:40 DESKTOP-O0QE9EJ][INFO] (Routes.Tracks[12108]): track_stream: TrackListen: Streaming track <2YvPExdxrJittKb0cNlcft> with bytes 2789376-4516092

To Reproduce Steps to reproduce the behavior:

Expected behavior Play the song till the end without crashing.

Screenshots I gave the logs above.

Additional context I replaced potentially sensitive information with "hidden".

Thanks for this amazing project and have a nice day. 👍