search

ldsz / plugin.audio.spotify

Unofficial spotify plugin for Kodi 19
GNU General Public License v3.0
47 stars 16 forks source link

Long pause when starting or skipping songs #5

Open Manlibear opened 3 years ago

Manlibear commented 3 years ago

When I start playing or a song or skip there is a long pause (around 10 seconds), here is the log from the time:

2021-04-16 08:50:23.525 T:3039     INFO <general>: CDVDAudioCodecFFmpeg::Open() Successful opened audio decoder pcm_s16le
2021-04-16 08:50:23.529 T:1977    ERROR <general>: plugin.audio.spotify --> b'WHOOPS!!! Running spotty still handling same request - leave it alone.'
2021-04-16 08:50:27.925 T:2965     INFO <general>: PAPlayer::ProcessStream - Stream Finished
2021-04-16 08:50:33.564 T:3039    ERROR <general>: CCurlFile::FillBuffer - Failed: Transferred a partial file(18)
2021-04-16 08:50:33.565 T:3039     INFO <general>: CDVDAudioCodecFFmpeg::GetChannelMap - FFmpeg reported 2 channels, but the layout contains 0 ignoring
2021-04-16 08:50:33.652 T:3039     INFO <general>: AudioDecoder: File is queued
2021-04-16 08:50:33.661 T:3039     INFO <general>: PAPlayer::PrepareStream - Ready
2021-04-16 08:50:33.907 T:1796    ERROR <general>: Exception ignored in: 
2021-04-16 08:50:33.907 T:1796    ERROR <general>: <Finalize object, dead>
2021-04-16 08:50:33.907 T:1796    ERROR <general>: 

2021-04-16 08:50:33.907 T:1796    ERROR <general>: Traceback (most recent call last):

2021-04-16 08:50:33.907 T:1796    ERROR <general>:   File "/usr/lib/python3.9/multiprocessing/util.py", line 224, in __call__

2021-04-16 08:50:33.907 T:1796    ERROR <general>:     
2021-04-16 08:50:33.907 T:1796    ERROR <general>: res = self._callback(*self._args, **self._kwargs)
2021-04-16 08:50:33.907 T:1796    ERROR <general>: 

2021-04-16 08:50:33.907 T:1796    ERROR <general>:   File "/usr/lib/python3.9/multiprocessing/pool.py", line 692, in _terminate_pool

2021-04-16 08:50:33.907 T:1796    ERROR <general>:     
2021-04-16 08:50:33.907 T:1796    ERROR <general>: cls._help_stuff_finish(inqueue, task_handler, len(pool))
2021-04-16 08:50:33.907 T:1796    ERROR <general>: 

2021-04-16 08:50:33.907 T:1796    ERROR <general>:   File "/usr/lib/python3.9/multiprocessing/pool.py", line 947, in _help_stuff_finish

2021-04-16 08:50:33.907 T:1796    ERROR <general>:     
2021-04-16 08:50:33.907 T:1796    ERROR <general>: inqueue.get(block=False)
2021-04-16 08:50:33.907 T:1796    ERROR <general>: 

2021-04-16 08:50:33.907 T:1796    ERROR <general>: _queue
2021-04-16 08:50:33.907 T:1796    ERROR <general>: .
2021-04-16 08:50:33.907 T:1796    ERROR <general>: Empty
2021-04-16 08:50:33.907 T:1796    ERROR <general>: : 
2021-04-16 08:50:33.907 T:1796    ERROR <general>: 
2021-04-16 08:50:33.907 T:1796    ERROR <general>: 

2021-04-16 08:50:37.936 T:1974    ERROR <general>: [16/Apr/2021:08:50:37] NATIVE_ADAPTER Traceback (most recent call last):
                                                     File "/var/lib/kodi/.kodi/addons/plugin.audio.spotify/resources/lib/cherrypy/_cpnative_server.py", line 89, in respond
                                                       self.send_response(
                                                     File "/var/lib/kodi/.kodi/addons/plugin.audio.spotify/resources/lib/cherrypy/_cpnative_server.py", line 117, in send_response
                                                       req.write(seg)
                                                     File "/var/lib/kodi/.kodi/addons/plugin.audio.spotify/resources/lib/cheroot/server.py", line 1095, in write
                                                       self.conn.wfile.write(chunk)
                                                     File "/var/lib/kodi/.kodi/addons/plugin.audio.spotify/resources/lib/cheroot/makefile.py", line 31, in write
                                                       self._flush_unlocked()
                                                     File "/var/lib/kodi/.kodi/addons/plugin.audio.spotify/resources/lib/cheroot/makefile.py", line 40, in _flush_unlocked
                                                       n = self.raw.write(bytes(self._write_buf))
                                                     File "/usr/lib/python3.9/socket.py", line 722, in write
                                                       return self._sock.send(b)
                                                   socket.timeout: timed out
jmbreuer commented 3 years ago

I can confirm that I also get long delays and log messages - I clearly remember this:

plugin.audio.spotify --> b'WHOOPS!!! Running spotty still handling same request - leave it alone.'

The message confused me/made me think that playback on the new song is not started because:

  1. either the plugin is looking whether the previous one has finished a bit too early or
  2. the previous playback takes long to clean up after sound already has long ceased.

But I didn't dig deep enough yet to figure out what it really means.

Elkropac commented 3 years ago

This happens, when in plugin access /track url, spotty binary is running, it has track_id and range variables filled in. It happens to me sometimes too. When i try to wget url from log, it downloads PCM file, without problems.

This happens almost everytime, i try to control kodi remotely using yatse, it does not happen often when i use keyboard to control plugin locally (i want to close this kodi to closet and control it remotely)