Skip to content
This repository has been archived by the owner on Jun 15, 2022. It is now read-only.

load() method times out on random albums #119

Closed
richard-ive opened this issue Mar 8, 2014 · 17 comments
Closed

load() method times out on random albums #119

richard-ive opened this issue Mar 8, 2014 · 17 comments
Labels
bug

Comments

@richard-ive
Copy link

When trying to load albums, some fail due to timeout, but there doesn't seem to be any consistency. 1/2 of the albums for one artists will work and the other 1/2 wont.

richard@raspberrypi-> python
Python 2.7.3 (default, Jan 13 2013, 11:20:46) 
[GCC 4.6.3] on linux2
Type "help", "copyright", "credits" or "license" for more information.
>>> import spotify
>>> sess = spotify.Session()
>>> sess.login('xxxxx','xxxxxxxx')
>>> sess.get_album('spotify:album:02Zb13fM8k04tRwTfMUhe9')
Album(u'spotify:album:02Zb13fM8k04tRwTfMUhe9')
>>> sess.get_album('spotify:album:02Zb13fM8k04tRwTfMUhe9').load(5)
Traceback (most recent call last):
  File "<stdin>", line 1, in <module>
  File "/usr/local/lib/python2.7/dist-packages/pyspotify-2.0.0a1-py2.7-linux-armv6l.egg/spotify/album.py", line 63, in load
    return utils.load(self, timeout=timeout)
  File "/usr/local/lib/python2.7/dist-packages/pyspotify-2.0.0a1-py2.7-linux-armv6l.egg/spotify/utils.py", line 217, in load
    raise RuntimeError('Session must be logged in to load objects')
RuntimeError: Session must be logged in to load objects
>>> sess.process_events()
1059
>>> sess.get_album('spotify:album:02Zb13fM8k04tRwTfMUhe9').load(5)
Album(u'spotify:album:02Zb13fM8k04tRwTfMUhe9')
>>> sess.get_album('spotify:album:02Zb13fM8k04tRwTfMUhe9').load(5).name
u'Welcome Reality'
>>> sess.get_album('spotify:album:3ph1ceuYuayuzoIJzPQji2').load(5).name
Traceback (most recent call last):
  File "<stdin>", line 1, in <module>
  File "/usr/local/lib/python2.7/dist-packages/pyspotify-2.0.0a1-py2.7-linux-armv6l.egg/spotify/album.py", line 63, in load
    return utils.load(self, timeout=timeout)
  File "/usr/local/lib/python2.7/dist-packages/pyspotify-2.0.0a1-py2.7-linux-armv6l.egg/spotify/utils.py", line 228, in load
    raise spotify.Timeout(timeout)
spotify.error.Timeout: Operation did not complete in 5.000s
>>> sess.get_album('spotify:album:4IBQvwIbtDluogvDe2qpaB').load(5).name
Traceback (most recent call last):
  File "<stdin>", line 1, in <module>
  File "/usr/local/lib/python2.7/dist-packages/pyspotify-2.0.0a1-py2.7-linux-armv6l.egg/spotify/album.py", line 63, in load
    return utils.load(self, timeout=timeout)
  File "/usr/local/lib/python2.7/dist-packages/pyspotify-2.0.0a1-py2.7-linux-armv6l.egg/spotify/utils.py", line 228, in load
    raise spotify.Timeout(timeout)
spotify.error.Timeout: Operation did not complete in 5.000s
>>> sess.get_album('spotify:album:5VppVyy751PTQWrfJbrJ4H').load(5).name
u'Between The Devil & The Deep Blue Sea (Special Edition)'
>>> sess.get_album('spotify:album:2cRMVS71c49Pf5SnIlJX3U').load(5).name
u'Coexist'
>>> sess.get_album('spotify:album:6mulYcpWRDAiv7KIouWvyP').load(5).name
u'ONE BY ONE'
>>> sess.get_album('spotify:album:6mulYcpWRDAiv7KIouWvyP').load(5).name
u'ONE BY ONE'
>>> sess.get_album('spotify:album:02jqf49ws9bcTvXLPGtjbT').load(5).name
Traceback (most recent call last):
  File "<stdin>", line 1, in <module>
  File "/usr/local/lib/python2.7/dist-packages/pyspotify-2.0.0a1-py2.7-linux-armv6l.egg/spotify/album.py", line 63, in load
    return utils.load(self, timeout=timeout)
  File "/usr/local/lib/python2.7/dist-packages/pyspotify-2.0.0a1-py2.7-linux-armv6l.egg/spotify/utils.py", line 228, in load
    raise spotify.Timeout(timeout)
spotify.error.Timeout: Operation did not complete in 5.000s
>>> sess.get_album('spotify:album:17orrZznh0gmxYtpNP47nK').load(5).name
u'Another Home'
>>> sess.connection_state
<ConnectionState.LOGGED_IN: 1>
>>> sess.connection_state
<ConnectionState.LOGGED_IN: 1>
>>> sess.process_events()
60000
>>> sess.connection_state
<ConnectionState.LOGGED_IN: 1>
>>> sess.connection_state
<ConnectionState.LOGGED_IN: 1>
>>> sess.process_events()
28873
>>> sess.connection_state
<ConnectionState.LOGGED_IN: 1>
>>> sess.get_album('spotify:album:5lnQLEUiVDkLbFJHXHQu9m').load(5).name
Traceback (most recent call last):
  File "<stdin>", line 1, in <module>
  File "/usr/local/lib/python2.7/dist-packages/pyspotify-2.0.0a1-py2.7-linux-armv6l.egg/spotify/album.py", line 63, in load
    return utils.load(self, timeout=timeout)
  File "/usr/local/lib/python2.7/dist-packages/pyspotify-2.0.0a1-py2.7-linux-armv6l.egg/spotify/utils.py", line 228, in load
    raise spotify.Timeout(timeout)
spotify.error.Timeout: Operation did not complete in 5.000s
>>> sess.process_events()
9489
>>> sess.connection_state
<ConnectionState.LOGGED_IN: 1>
@jodal
Copy link
Owner

jodal commented Mar 11, 2014

This may be caused by an intermittent bad connection or server problems on Spotify's side. Can you reproduce this consistently? Does the problem go away if you use a higher timeout?

@jodal jodal added 2.x labels Mar 11, 2014
@richard-ive
Copy link
Author

It appears to be consistent with 'spotify:album:3ph1ceuYuayuzoIJzPQji2' at least:

>>> import logging
>>> logging.basicConfig(level=logging.DEBUG)
>>> import spotify
>>> sess = spotify.Session()
>>> sess.login('xxxx','xx')
DEBUG:spotify.session:Log message from Spotify: 08:25:54.688 I [ap:1752] Connect                                               ing to AP ap.spotify.com:4070
>>> DEBUG:spotify.session:Log message from Spotify: 08:25:54.776 I [ap:1226] Con                                               nected to AP: 78.31.9.50:4070
>>> sess.process_events()
DEBUG:spotify.session:Notify main thread
INFO:spotify.session:Logged in
DEBUG:spotify.session:Connection state updated
DEBUG:spotify.session:Credentials blob updated: 'gL8+8Hmw1iSyEowxODOxJTiH7+CTVA684sE4xMhTmk0='
DEBUG:spotify.session:Connection state updated
DEBUG:spotify.session:Log message from Spotify: 08:26:18.818 I [offline-mgr:2082] Storage has been cleaned
1001
>>> sess.get_album('spotify:album:3ph1ceuYuayuzoIJzPQji2').load().name
DEBUG:spotify.session:Notify main thread
DEBUG:spotify.session:Metadata updated
DEBUG:spotify.session:User info updated
DEBUG:spotify.session:User info updated
DEBUG:spotify.session:Notify main thread
DEBUG:spotify.session:Metadata updated
DEBUG:spotify.session:Notify main thread
DEBUG:spotify.session:Notify main thread
DEBUG:spotify.session:Notify main thread
DEBUG:spotify.session:Notify main thread
DEBUG:spotify.session:Metadata updated
DEBUG:spotify.session:Notify main thread
DEBUG:spotify.session:Metadata updated
DEBUG:spotify.session:Notify main thread
DEBUG:spotify.session:Notify main thread
DEBUG:spotify.session:Notify main thread
DEBUG:spotify.session:Notify main thread
DEBUG:spotify.session:Notify main thread
DEBUG:spotify.session:Notify main thread
DEBUG:spotify.session:Notify main thread
DEBUG:spotify.session:Notify main thread
DEBUG:spotify.session:User info updated
DEBUG:spotify.session:Metadata updated
DEBUG:spotify.session:Notify main thread
DEBUG:spotify.session:Metadata updated
DEBUG:spotify.session:Notify main thread
DEBUG:spotify.session:Metadata updated
DEBUG:spotify.session:Notify main thread
DEBUG:spotify.session:Metadata updated
DEBUG:spotify.session:Notify main thread
DEBUG:spotify.session:Metadata updated
DEBUG:spotify.session:Notify main thread
DEBUG:spotify.session:Metadata updated
DEBUG:spotify.session:User info updated
DEBUG:spotify.session:Notify main thread
DEBUG:spotify.session:Metadata updated
DEBUG:spotify.session:Notify main thread
DEBUG:spotify.session:Metadata updated
DEBUG:spotify.session:Notify main thread
DEBUG:spotify.session:Metadata updated
DEBUG:spotify.session:Notify main thread
DEBUG:spotify.session:Metadata updated
DEBUG:spotify.session:Notify main thread
DEBUG:spotify.session:Notify main thread
DEBUG:spotify.session:Notify main thread
DEBUG:spotify.session:Metadata updated
DEBUG:spotify.session:Notify main thread
DEBUG:spotify.session:Metadata updated
DEBUG:spotify.session:Notify main thread
DEBUG:spotify.session:Metadata updated
DEBUG:spotify.session:User info updated
DEBUG:spotify.session:Notify main thread
DEBUG:spotify.session:Metadata updated
DEBUG:spotify.session:Notify main thread
DEBUG:spotify.session:Metadata updated
DEBUG:spotify.session:Notify main thread
DEBUG:spotify.session:Notify main thread
DEBUG:spotify.session:Notify main thread
DEBUG:spotify.session:Metadata updated
DEBUG:spotify.session:Notify main thread
DEBUG:spotify.session:Metadata updated
DEBUG:spotify.session:Notify main thread
DEBUG:spotify.session:Metadata updated
DEBUG:spotify.session:Notify main thread
DEBUG:spotify.session:Metadata updated
DEBUG:spotify.session:Notify main thread
DEBUG:spotify.session:Notify main thread
DEBUG:spotify.session:Notify main thread
DEBUG:spotify.session:Metadata updated
DEBUG:spotify.session:Notify main thread
DEBUG:spotify.session:Metadata updated
DEBUG:spotify.session:Notify main thread
DEBUG:spotify.session:Notify main thread
DEBUG:spotify.session:Notify main thread
DEBUG:spotify.session:Notify main thread
DEBUG:spotify.session:Notify main thread
DEBUG:spotify.session:Notify main thread
DEBUG:spotify.session:Notify main thread
DEBUG:spotify.session:Notify main thread
DEBUG:spotify.session:Notify main thread
DEBUG:spotify.session:Notify main thread
DEBUG:spotify.session:Notify main thread
DEBUG:spotify.session:Notify main thread
DEBUG:spotify.session:Notify main thread
DEBUG:spotify.session:Notify main thread
DEBUG:spotify.session:Notify main thread
DEBUG:spotify.session:Notify main thread
DEBUG:spotify.session:Notify main thread
DEBUG:spotify.session:Notify main thread
DEBUG:spotify.session:Notify main thread
DEBUG:spotify.session:Notify main thread
DEBUG:spotify.session:Notify main thread
DEBUG:spotify.session:Notify main thread
DEBUG:spotify.session:Notify main thread
DEBUG:spotify.session:Notify main thread
DEBUG:spotify.session:Notify main thread
DEBUG:spotify.session:Notify main thread
DEBUG:spotify.session:User info updated
Traceback (most recent call last):
  File "<stdin>", line 1, in <module>
  File "/usr/local/lib/python2.7/dist-packages/pyspotify-2.0.0a1-py2.7-linux-armv6l.egg/spotify/album.py", line 63, in load
    return utils.load(self, timeout=timeout)
  File "/usr/local/lib/python2.7/dist-packages/pyspotify-2.0.0a1-py2.7-linux-armv6l.egg/spotify/utils.py", line 228, in load
    raise spotify.Timeout(timeout)
spotify.error.Timeout: Operation did not complete in 10.000s
>>> sess.get_album('spotify:album:3ph1ceuYuayuzoIJzPQji2').load(30).name
DEBUG:spotify.session:Log message from Spotify: 08:27:19.372 I [offline-mgr:2030] 0 files are locked. 0 images are locked
DEBUG:spotify.session:Log message from Spotify: 08:27:19.375 I [offline-mgr:2056] 0 files unlocked. 0 images unlocked
Traceback (most recent call last):
  File "<stdin>", line 1, in <module>
  File "/usr/local/lib/python2.7/dist-packages/pyspotify-2.0.0a1-py2.7-linux-armv6l.egg/spotify/album.py", line 63, in load
    return utils.load(self, timeout=timeout)
  File "/usr/local/lib/python2.7/dist-packages/pyspotify-2.0.0a1-py2.7-linux-armv6l.egg/spotify/utils.py", line 228, in load
    raise spotify.Timeout(timeout)
spotify.error.Timeout: Operation did not complete in 30.000s
>>> sess.get_album('spotify:album:3ph1ceuYuayuzoIJzPQji2').load(60).name
DEBUG:spotify.session:Notify main thread
DEBUG:spotify.session:Notify main thread
Traceback (most recent call last):
  File "<stdin>", line 1, in <module>
  File "/usr/local/lib/python2.7/dist-packages/pyspotify-2.0.0a1-py2.7-linux-armv6l.egg/spotify/album.py", line 63, in load
    return utils.load(self, timeout=timeout)
  File "/usr/local/lib/python2.7/dist-packages/pyspotify-2.0.0a1-py2.7-linux-armv6l.egg/spotify/utils.py", line 228, in load
    raise spotify.Timeout(timeout)
spotify.error.Timeout: Operation did not complete in 60.000s
>>> sess.process_events()
55270
>>> sess.get_album('spotify:album:3ph1ceuYuayuzoIJzPQji2').load().name
Traceback (most recent call last):
  File "<stdin>", line 1, in <module>
  File "/usr/local/lib/python2.7/dist-packages/pyspotify-2.0.0a1-py2.7-linux-armv6l.egg/spotify/album.py", line 63, in load
    return utils.load(self, timeout=timeout)
  File "/usr/local/lib/python2.7/dist-packages/pyspotify-2.0.0a1-py2.7-linux-armv6l.egg/spotify/utils.py", line 228, in load
    raise spotify.Timeout(timeout)
spotify.error.Timeout: Operation did not complete in 10.000s
>>>

@jodal
Copy link
Owner

jodal commented Mar 12, 2014

I can reproduce with that album. No clue what's the reason so far. May be worth trying to reproduce with pyspotify 1.x and/or asking in #spotify on freenode.

@richard-ive
Copy link
Author

Has been reproduced by another libspotify user. Will keep this thread updated.

@jodal
Copy link
Owner

jodal commented Mar 25, 2014

Did you figure this out? Was it just a odd issue with the Spotify service?

@richard-ive
Copy link
Author

Unfortunately not. I've not been able to contact anyone at Spotify yet.

@jodal
Copy link
Owner

jodal commented Apr 9, 2014

No need to keep this issue open, but please update it anyway if you have something to add.

@jodal jodal closed this as completed Apr 9, 2014
@ghost
Copy link

ghost commented May 24, 2014

Just to note...I'm having this issue and can reproduce it at will. I can log in successfully. If the first thing I do is try to load an album it will time out. Every time. If i do anything else first the album problem doesn't show up. If the first thing i do is get an album, then a browser and load that , everything is fine. This is with Python 2.7 and pyspotify 2.0.0b3.

@jodal
Copy link
Owner

jodal commented May 24, 2014

Sounds like it should be possible to make a workaround.

@jodal jodal reopened this May 24, 2014
@ghost
Copy link

ghost commented May 28, 2014

Yeah the workaround is easy. I just wanted to make sure that the issue was known. If I can help diagnose where it's happening I'd be more than happy to help.

@jodal jodal added bug and removed question labels Jun 26, 2014
@jodal jodal added this to the v2.0.0b4 milestone Jun 26, 2014
@jodal jodal self-assigned this Jun 26, 2014
@jodal
Copy link
Owner

jodal commented Aug 11, 2014

No, but it will be before 2.0 final.

@ghost
Copy link

ghost commented Aug 11, 2014

Sorry about deleting my previous post, asking about the status, I saw the version numbers and figured it was a dumb question, but thanks for confirming. At the risk of asking another dumb question, is there any info on the next release, as far as timeframe or what bugs are preventing its release?

@jodal
Copy link
Owner

jodal commented Aug 11, 2014

The main blocker is that I want to finish my reimplementation of
Mopidy-Spotify on top of pyspotify 2 so that I've tested more of the API
surface in practice before taking it out of beta.

@ghost
Copy link

ghost commented Aug 14, 2014

I see. Let me know if there's anything I can do to contribute.

@jmmL
Copy link

jmmL commented Sep 30, 2014

I can confirm that I'm also having this issue. The workaround with

browser = album.browse()
browser.load()

works for me.

@jodal jodal modified the milestones: v2.0.0b4, v2.0.0b5 Jan 14, 2015
@jodal jodal removed their assignment Jan 15, 2015
@jodal jodal modified the milestones: v2.0.0, v2.0.0b5 Jan 26, 2015
@jodal jodal modified the milestones: v2.0.0b5, v2.0.0 Jan 26, 2015
jodal added a commit that referenced this issue Feb 15, 2015
@jodal
Add script for reproducing bug #119
adc9803
@jodal jodal removed the 2.x label Mar 25, 2015
@jodal jodal modified the milestones: v2.0.0b5, v2.0.0 Mar 25, 2015
@jodal jodal modified the milestones: v2.0.0b5, v2.0.0 May 8, 2015
jodal added a commit that referenced this issue May 25, 2015
@jodal
Cleanup bug #119 reproduction script
fb699f6
@jodal jodal removed the 1 - Ready label Jun 1, 2015
@jodal
Copy link
Owner

jodal commented Jun 1, 2015

I've been working a bit on reproducing this issue with just libspotify and C, but don't want to hold of the 2.0.0 release anymore to wait for this. If this is a pyspotify issue, and not a libspotify issue, we can fix in a later bugfix release. If this is a libspotify bug, but can be worked around with some non-intrusive change, we can do that in a bugfix release. The current workaround of using album.browse() to get the album to load is not something I want to do in pyspotify as that adds lots of extra overhead and data fetching to every album fetch.

@jodal jodal removed this from the v2.0.0 milestone Jun 1, 2015
@jodal
Copy link
Owner

jodal commented Jun 14, 2022

Closing as libspotify and pyspotify are dead. See #215 for details.

@jodal jodal closed this as not planned Won't fix, can't repro, duplicate, stale Jun 14, 2022
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Assignees
No one assigned
Labels
bug
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
3 participants
@jodal @richard-ive @jmmL