search

fuzeman / Spotify2.bundle

Spotify music streaming for Plex (all platforms)
76 stars 45 forks source link

Can't use the plugin, always returns Login Failed #30

Closed mpeterson closed 9 years ago

mpeterson commented 10 years ago

I'm a pro subscriber. Using master version (v0.4.4) on a QNAP ARM (TS-219p)

The log can be seen here:

2014-06-13 01:18:07,751 (-4c02bb70) :  DEBUG (runtime:717) - Handling request GET /music/spotify
2014-06-13 01:18:07,765 (-4c02bb70) :  DEBUG (runtime:814) - Found route matching /music/spotify
2014-06-13 01:18:07,786 (-4c02bb70) :  DEBUG (base:123) - Checking if com.plexapp.plugins.spotify2 is broken
2014-06-13 01:18:07,804 (-4c02bb70) :  DEBUG (networking:172) - Requesting 'http://127.0.0.1:32400/:/plugins/com.plexapp.system/messaging/function/X1N0b3JlU2VydmljZTpJc0NoYW5uZWxCcm9rZW4_/Y2VyZWFsMQoxCmxpc3QKMApyMAo_/Y2VyZWFsMQoxCmRpY3QKMQpzMjgKY29tLnBsZXhhcHAucGx1Z2lucy5zcG90aWZ5MnMxMAppZGVudGlmaWVycjAK'
2014-06-13 01:18:07,895 (-4c02bb70) :  DEBUG (runtime:918) - Response: [200] MediaContainer, 1069 bytes
2014-06-13 01:18:17,432 (-4c02bb70) :  DEBUG (runtime:717) - Handling request GET /music/spotify/playlists
2014-06-13 01:18:17,447 (-4c02bb70) :  DEBUG (runtime:814) - Found route matching /music/spotify/playlists
2014-06-13 01:18:17,451 (-4c02bb70) :  WARNING (utils:103) - Connection failed, reconnecting...
2014-06-13 01:18:17,477 (-4c02bb70) :  INFO (logging_handler:16) - [requests.packages.urllib3.connectionpool] Starting new HTTPS connection (1): play.spotify.com
2014-06-13 01:18:18,516 (-4c02bb70) :  DEBUG (logging_handler:16) - [requests.packages.urllib3.connectionpool] "GET / HTTP/1.1" 200 10364
2014-06-13 01:18:18,918 (-4c02bb70) :  DEBUG (logging_handler:16) - [requests.packages.urllib3.connectionpool] "POST /xhr/json/auth.php HTTP/1.1" 200 None
2014-06-13 01:18:19,095 (-4c02bb70) :  INFO (logging_handler:16) - [requests.packages.urllib3.connectionpool] Starting new HTTP connection (1): apresolve.spotify.com
2014-06-13 01:18:19,525 (-4c02bb70) :  DEBUG (logging_handler:16) - [requests.packages.urllib3.connectionpool] "GET /?client=24%3A0%3A0%3A62300281 HTTP/1.1" 200 None
2014-06-13 01:18:19,553 (-4c02bb70) :  INFO (spotify:55) - Connecting to wss://ash1-linkap-a3.ap.spotify.com/
2014-06-13 01:18:20,562 (-4ba4fb70) :  INFO (spotify:55) - Logging in
2014-06-13 01:18:20,565 (-4ba4fb70) :  DEBUG (spotify:55) - sent {"args":["201","aab390dbd9477dc3b6b43eabe3e0270bfc040ae2","{\"ip\":\"186.137.12.172\",\"timestamp\":1402633098,\"ttl\":900,\"useragent\":\"Mozilla\\/5.0 (Macintosh; Intel Mac OS X 10_9_1) AppleWebKit\\/537.36 (KHTML, like Gecko) Chrome\\/31.0.1650.63 Safari\\/537.36\",\"version\":62300281,\"token\":\"NAplCk0KDVNwb3RpZnktdXNlcnMSDm1pY2hlbHBldGVyc29uGgOYAQElDn-aUzIiCgiI-HryIF7-TxIW7w7-8q9iqMuEgCNCjwb6DAYQO6s6axIUVxUUND68hG32ttzRVIfwNt3h7vg\"}"],"name":"connect","id":"0"}
2014-06-13 01:18:20,774 (-4ba4fb70) :  DEBUG (spotify:55) - recv {"id":0,"result":"ok"}
2014-06-13 01:18:20,777 (-4ba4fb70) :  DEBUG (spotify:55) - Unhandled command response with id 0
2014-06-13 01:18:20,782 (-4ba4fb70) :  DEBUG (spotify:55) - recv {"message":["do_work","var t2=0; try{ for(var i=0; i<7200941293..toString(32<<0).length;i++) t2 = t2+(~-~-~-~-~-~-~-~-~-~-~-~'X'['XXX']);}catch(_) {}; this.reply('' + t2);"]}
2014-06-13 01:18:20,785 (-4ba4fb70) :  DEBUG (spotify:55) - Got do_work message, payload: var t2=0; try{ for(var i=0; i<7200941293..toString(32<<0).length;i++) t2 = t2+(~-~-~-~-~-~-~-~-~-~-~-~'X'['XXX']);}catch(_) {}; this.reply('' + t2);
2014-06-13 01:18:30,581 (-4c02bb70) :  DEBUG (runtime:918) - Response: [200] MessageContainer, 114 bytes
2014-06-13 01:18:44,835 (-4c02bb70) :  DEBUG (runtime:717) - Handling request GET /music/spotify
2014-06-13 01:18:44,849 (-4c02bb70) :  DEBUG (runtime:814) - Found route matching /music/spotify
2014-06-13 01:18:44,858 (-4c02bb70) :  DEBUG (base:123) - Checking if com.plexapp.plugins.spotify2 is broken
2014-06-13 01:18:44,866 (-4c02bb70) :  DEBUG (networking:172) - Requesting 'http://127.0.0.1:32400/:/plugins/com.plexapp.system/messaging/function/X1N0b3JlU2VydmljZTpJc0NoYW5uZWxCcm9rZW4_/Y2VyZWFsMQoxCmxpc3QKMApyMAo_/Y2VyZWFsMQoxCmRpY3QKMQpzMjgKY29tLnBsZXhhcHAucGx1Z2lucy5zcG90aWZ5MnMxMAppZGVudGlmaWVycjAK'
2014-06-13 01:18:44,956 (-4c02bb70) :  DEBUG (runtime:918) - Response: [200] MediaContainer, 1069 bytes
2014-06-13 01:19:27,810 (-4c02bb70) :  DEBUG (runtime:717) - Handling request GET /:/plugins/com.plexapp.plugins.spotify2/prefs
2014-06-13 01:19:28,138 (-4c02bb70) :  DEBUG (runtime:814) - Found route matching /:/plugins/com.plexapp.plugins.spotify2/prefs
2014-06-13 01:19:28,201 (-4c02bb70) :  DEBUG (runtime:918) - Response: [200] MediaContainer, 511 bytes
2014-06-13 01:20:17,377 (-4c02bb70) :  DEBUG (runtime:717) - Handling request GET /:/plugins/com.plexapp.plugins.spotify2/prefs/set?displayAlbumYear=false
2014-06-13 01:20:17,409 (-4c02bb70) :  DEBUG (runtime:814) - Found route matching /:/plugins/com.plexapp.plugins.spotify2/prefs/set
2014-06-13 01:20:17,416 (-4c02bb70) :  DEBUG (preferences:198) - Saved the user preferences
2014-06-13 01:20:17,472 (-4c02bb70) :  INFO (logging_handler:16) - [requests.packages.urllib3.connectionpool] Starting new HTTPS connection (1): play.spotify.com
2014-06-13 01:20:18,546 (-4c02bb70) :  DEBUG (logging_handler:16) - [requests.packages.urllib3.connectionpool] "GET / HTTP/1.1" 200 10364
2014-06-13 01:20:18,874 (-4c02bb70) :  DEBUG (logging_handler:16) - [requests.packages.urllib3.connectionpool] "POST /xhr/json/auth.php HTTP/1.1" 200 None
2014-06-13 01:20:19,051 (-4c02bb70) :  INFO (logging_handler:16) - [requests.packages.urllib3.connectionpool] Starting new HTTP connection (1): apresolve.spotify.com
2014-06-13 01:20:19,455 (-4c02bb70) :  DEBUG (logging_handler:16) - [requests.packages.urllib3.connectionpool] "GET /?client=24%3A0%3A0%3A62300281 HTTP/1.1" 200 None
2014-06-13 01:20:19,482 (-4c02bb70) :  INFO (spotify:55) - Connecting to wss://sjc1-linkap-a3.ap.spotify.com/
2014-06-13 01:20:20,601 (-4ba4fb70) :  INFO (spotify:55) - Logging in
2014-06-13 01:20:20,604 (-4ba4fb70) :  DEBUG (spotify:55) - sent {"args":["201","d744924945beece62d99606d52aac755c5e3e5d3","{\"ip\":\"186.137.12.172\",\"timestamp\":1402633218,\"ttl\":900,\"useragent\":\"Mozilla\\/5.0 (Macintosh; Intel Mac OS X 10_9_1) AppleWebKit\\/537.36 (KHTML, like Gecko) Chrome\\/31.0.1650.63 Safari\\/537.36\",\"version\":62300281,\"token\":\"NAplCk0KDVNwb3RpZnktdXNlcnMSDm1pY2hlbHBldGVyc29uGgOYAQElhn-aUzIiCghdWPmF-by6eBIWJP_40EFEZNxCFToA63P0b2BvxTmBthIUaSx7jLU1yEekHQRMzI27ygyLeKo\"}"],"name":"connect","id":"0"}
2014-06-13 01:20:20,919 (-4ba4fb70) :  DEBUG (spotify:55) - recv {"id":0,"result":"ok"}
2014-06-13 01:20:20,922 (-4ba4fb70) :  DEBUG (spotify:55) - Unhandled command response with id 0
2014-06-13 01:20:20,927 (-4ba4fb70) :  DEBUG (spotify:55) - recv {"message":["do_work","var t2=0; try{ for(var i=0; i<7200941293..toString(32<<0).length;i++) t2 = t2+(~-~-~-~-~-~-~-~-~-~-~-~'X'['XXX']);}catch(_) {}; this.reply('' + t2);"]}
2014-06-13 01:20:20,930 (-4ba4fb70) :  DEBUG (spotify:55) - Got do_work message, payload: var t2=0; try{ for(var i=0; i<7200941293..toString(32<<0).length;i++) t2 = t2+(~-~-~-~-~-~-~-~-~-~-~-~'X'['XXX']);}catch(_) {}; this.reply('' + t2);
2014-06-13 01:20:30,617 (-4c02bb70) :  DEBUG (runtime:918) - Response: [200] str, 0 bytes
2014-06-13 01:20:30,722 (-4c02bb70) :  DEBUG (runtime:717) - Handling request GET /music/spotify
2014-06-13 01:20:30,734 (-4c02bb70) :  DEBUG (runtime:814) - Found route matching /music/spotify
2014-06-13 01:20:30,743 (-4c02bb70) :  DEBUG (base:123) - Checking if com.plexapp.plugins.spotify2 is broken
2014-06-13 01:20:30,751 (-4c02bb70) :  DEBUG (networking:172) - Requesting 'http://127.0.0.1:32400/:/plugins/com.plexapp.system/messaging/function/X1N0b3JlU2VydmljZTpJc0NoYW5uZWxCcm9rZW4_/Y2VyZWFsMQoxCmxpc3QKMApyMAo_/Y2VyZWFsMQoxCmRpY3QKMQpzMjgKY29tLnBsZXhhcHAucGx1Z2lucy5zcG90aWZ5MnMxMAppZGVudGlmaWVycjAK'
2014-06-13 01:20:30,842 (-4c02bb70) :  DEBUG (runtime:918) - Response: [200] MediaContainer, 1069 bytes
2014-06-13 01:20:43,919 (-4c02bb70) :  DEBUG (runtime:717) - Handling request GET /music/spotify/playlists
2014-06-13 01:20:43,933 (-4c02bb70) :  DEBUG (runtime:814) - Found route matching /music/spotify/playlists
2014-06-13 01:20:43,937 (-4c02bb70) :  WARNING (utils:103) - Connection failed, reconnecting...
2014-06-13 01:20:43,962 (-4c02bb70) :  INFO (logging_handler:16) - [requests.packages.urllib3.connectionpool] Starting new HTTPS connection (1): play.spotify.com
2014-06-13 01:20:44,963 (-4c02bb70) :  DEBUG (logging_handler:16) - [requests.packages.urllib3.connectionpool] "GET / HTTP/1.1" 200 10364
2014-06-13 01:20:45,300 (-4c02bb70) :  DEBUG (logging_handler:16) - [requests.packages.urllib3.connectionpool] "POST /xhr/json/auth.php HTTP/1.1" 200 None
2014-06-13 01:20:45,481 (-4c02bb70) :  INFO (logging_handler:16) - [requests.packages.urllib3.connectionpool] Starting new HTTP connection (1): apresolve.spotify.com
2014-06-13 01:20:45,844 (-4c02bb70) :  DEBUG (logging_handler:16) - [requests.packages.urllib3.connectionpool] "GET /?client=24%3A0%3A0%3A62300281 HTTP/1.1" 200 None
2014-06-13 01:20:45,901 (-4c02bb70) :  INFO (spotify:55) - Connecting to wss://ash1-linkap-a2.ap.spotify.com/
2014-06-13 01:20:46,935 (-4ba4fb70) :  INFO (spotify:55) - Logging in
2014-06-13 01:20:46,938 (-4ba4fb70) :  DEBUG (spotify:55) - sent {"args":["201","86a7967a859c1877b6b84ddabc06e2f0aab811b9","{\"ip\":\"186.137.12.172\",\"timestamp\":1402633245,\"ttl\":900,\"useragent\":\"Mozilla\\/5.0 (Macintosh; Intel Mac OS X 10_9_1) AppleWebKit\\/537.36 (KHTML, like Gecko) Chrome\\/31.0.1650.63 Safari\\/537.36\",\"version\":62300281,\"token\":\"NAplCk0KDVNwb3RpZnktdXNlcnMSDm1pY2hlbHBldGVyc29uGgOYAQEloX-aUzIiCgjiVlIR1loBSBIWZ1Kd5WS6_y2aaR50p0t5ORWNLghy1hIUZWm-p-Z98DHM6EpuviAwDjIpRrc\"}"],"name":"connect","id":"0"}
2014-06-13 01:20:47,189 (-4ba4fb70) :  DEBUG (spotify:55) - recv {"id":0,"result":"ok"}
2014-06-13 01:20:47,192 (-4ba4fb70) :  DEBUG (spotify:55) - Unhandled command response with id 0
2014-06-13 01:20:47,197 (-4ba4fb70) :  DEBUG (spotify:55) - recv {"message":["do_work","var t2; try { var d = new Date(); t2 = ('d'[(35725129862..toString(36<<0))[0]])(); } catch(_) { t2 = 35725129862..toString(36<<0); };this.reply('' + t2);"]}
2014-06-13 01:20:47,211 (-4ba4fb70) :  DEBUG (spotify:55) - Got do_work message, payload: var t2; try { var d = new Date(); t2 = ('d'[(35725129862..toString(36<<0))[0]])(); } catch(_) { t2 = 35725129862..toString(36<<0); };this.reply('' + t2);
2014-06-13 01:20:56,951 (-4c02bb70) :  DEBUG (runtime:918) - Response: [200] MessageContainer, 114 bytes
mpeterson commented 10 years ago

Doing a search renders this log:

2014-06-13 01:24:26,491 (-4c02bb70) :  DEBUG (runtime:717) - Handling request GET /music/spotify
2014-06-13 01:24:26,509 (-4c02bb70) :  DEBUG (runtime:814) - Found route matching /music/spotify
2014-06-13 01:24:26,518 (-4c02bb70) :  DEBUG (base:123) - Checking if com.plexapp.plugins.spotify2 is broken
2014-06-13 01:24:26,525 (-4c02bb70) :  DEBUG (networking:172) - Requesting 'http://127.0.0.1:32400/:/plugins/com.plexapp.system/messaging/function/X1N0b3JlU2VydmljZTpJc0NoYW5uZWxCcm9rZW4_/Y2VyZWFsMQoxCmxpc3QKMApyMAo_/Y2VyZWFsMQoxCmRpY3QKMQpzMjgKY29tLnBsZXhhcHAucGx1Z2lucy5zcG90aWZ5MnMxMAppZGVudGlmaWVycjAK'
2014-06-13 01:24:26,618 (-4c02bb70) :  DEBUG (runtime:918) - Response: [200] MediaContainer, 1069 bytes
2014-06-13 01:26:08,821 (-4c02bb70) :  DEBUG (runtime:717) - Handling request GET /music/spotify/search?query=abc
2014-06-13 01:26:08,834 (-4c02bb70) :  DEBUG (runtime:814) - Found route matching /music/spotify/search
2014-06-13 01:26:08,842 (-4c02bb70) :  INFO (search:58) - Search query: "abc", type: all, limit: 7, plain: False
2014-06-13 01:26:28,852 (-4ba4fb70) :  DEBUG (runtime:717) - Handling request GET /music/spotify
2014-06-13 01:26:28,864 (-4ba4fb70) :  DEBUG (runtime:814) - Found route matching /music/spotify
2014-06-13 01:26:28,874 (-4ba4fb70) :  DEBUG (base:123) - Checking if com.plexapp.plugins.spotify2 is broken
2014-06-13 01:26:28,881 (-4ba4fb70) :  DEBUG (networking:172) - Requesting 'http://127.0.0.1:32400/:/plugins/com.plexapp.system/messaging/function/X1N0b3JlU2VydmljZTpJc0NoYW5uZWxCcm9rZW4_/Y2VyZWFsMQoxCmxpc3QKMApyMAo_/Y2VyZWFsMQoxCmRpY3QKMQpzMjgKY29tLnBsZXhhcHAucGx1Z2lucy5zcG90aWZ5MnMxMAppZGVudGlmaWVycjAK'
2014-06-13 01:26:28,971 (-4ba4fb70) :  DEBUG (runtime:918) - Response: [200] MediaContainer, 1069 bytes
2014-06-13 01:26:38,881 (-4c02bb70) :  CRITICAL (runtime:883) - Exception (most recent call last):
  File "/share/MD0_DATA/.qpkg/PlexMediaServer/Library/Plex Media Server/Plug-ins/Framework.bundle/Contents/Resources/Versions/2/Python/Framework/components/runtime.py", line 843, in handle_request
    result = f(**d)
  File "/root/Library/Plex Media Server/Plug-ins/Spotify2.bundle/Contents/Code/__init__.py", line 59, in search
    return sp_search.run(**kwargs)
  File "/share/MD0_DATA/.qpkg/PlexMediaServer/Library/Plex Media Server/Plug-ins/Framework.bundle/Contents/Resources/Versions/2/Python/Framework/code/sandbox.py", line 19, in _apply
    return apply(f, args, kwargs)
  File "/root/Library/Plex Media Server/Plug-ins/Spotify2.bundle/Contents/Code/search.py", line 59, in run
    result = self.client.search(query, type, max_results=limit)
  File "/root/Library/Plex Media Server/Plug-ins/Spotify2.bundle/Contents/Code/client.py", line 43, in search
    return self.spotify.search(query, query_type, max_results, offset)
  File "/root/Library/Plex Media Server/Plug-ins/Spotify2.bundle/Contents/Libraries/Shared/spotify_web/friendly.py", line 464, in search
    return SpotifySearch(self, query, query_type=query_type, max_results=max_results, offset=offset)
  File "/root/Library/Plex Media Server/Plug-ins/Spotify2.bundle/Contents/Libraries/Shared/spotify_web/search.py", line 12, in __init__
    self.populate()
  File "/root/Library/Plex Media Server/Plug-ins/Spotify2.bundle/Contents/Libraries/Shared/spotify_web/search.py", line 16, in populate
    xml = xml[38:]  # trim UTF8 declaration
TypeError: 'bool' object has no attribute '__getitem__'
fuzeman commented 10 years ago

Do you have node.js installed on your server? currently this is required on *nix systems for part of the authentication process with Spotify.

Either grab it from apt/yum, or install the binary manually (see this post https://forums.plex.tv/index.php/topic/107169-rel-spotify2/page-6#entry658621)

mpeterson commented 10 years ago

Yes, node.js is installed and on the $PATH.

[~] # node --version
v0.10.15
fuzeman commented 10 years ago

It seems to be failing right where it uses node, so something must be failing there.

Could you switch to the develop branch? there is a large number of improvements/features coming and more details will be logged when there is a problem using node now.

Download here: develop.zip

Might need to delete the current "Spotify2.bundle" in your "Plug-ins" directory first (instead of just dropping the new one into the folder) otherwise there can be conflicts with the old code-base.

helluvamatt commented 9 years ago

Same log as @mpeterson.

Can confirm develop branch works.