Login not calling callback

[brandtabbott]

Not sure what is wrong, but something is wrong as of this morning. An invalid login attempt successfully ends up in the callback function I pass to login with an error, but a successful login never gets called. Here is a debug log (the spotify-web reply(["undefined"]) +0ms seems off to me).

spotify-web Spotify#login("1233221008", "**********") +0ms
  spotify-web GET "https://play.spotify.com/" +3ms
  spotify-web landing page: 200 status code, "text/html" content-type +875ms
  spotify-web Spotify.Web.Login() +32ms
  spotify-web login CSRF token: "4a1e041f366b08b84f9b2c5f9169f44f", tracking ID: "c9c215298ff016923bc8849dca3a8fa244973c18" +1ms
  spotify-web POST "https://play.spotify.com/xhr/json/auth.php" +0ms
  spotify-web auth 200 status code, "application/json; charset=utf-8" content-type +357ms
  spotify-web ap resolver {"hostname":"apresolve.spotify.com","site":null,"override":null} +0ms
  spotify-web GET "http://apresolve.spotify.com" +1ms
  spotify-web ap resolver 200 status code, "application/json; charset=utf-8" content-type +510ms
  spotify-web WS "wss://sjc1-linkap-a5.ap.spotify.com:443/" +0ms
  spotify-web WebSocket "open" event +297ms
  spotify-web connect() +0ms
  spotify-web sendCommand("connect", ["201","55b9e421c541c80d4b5f3da4b2c8b50e2753019a","{\"ip\":\"216.66.77.2\",\"timestamp\":1398445799,\"ttl\":900,\"useragent\":\"Mozilla\\/5.0 (Chrome\\/13.37 compatible-ish) spotify-web\\/1.1.1\",\"version\":62300244,\"token\":\"NAphCkkKDVNwb3RpZnktdXNlcnMSCjEyMzMxMzg1NTQaA5gBASVrmlpTMiIKCAGZGeoMEsCEEhZ6bQa_mxYwcwEIfE3XEbq2HHVNsv-qEhT6TR0mb8_Do08bhz3cGxlwu5pnTA\"}"]) +0ms
  spotify-web storing callback function for message id 0 +0ms
  spotify-web sending command: {"name":"connect","id":"0","args":["201","55b9e421c541c80d4b5f3da4b2c8b50e2753019a","{\"ip\":\"216.66.77.2\",\"timestamp\":1398445799,\"ttl\":900,\"useragent\":\"Mozilla\\/5.0 (Chrome\\/13.37 compatible-ish) spotify-web\\/1.1.1\",\"version\":62300244,\"token\":\"NAphCkkKDVNwb3RpZnktdXNlcnMSCjEyMzMxMzg1NTQaA5gBASVrmlpTMiIKCAGZGeoMEsCEEhZ6bQa_mxYwcwEIfE3XEbq2HHVNsv-qEhT6TR0mb8_Do08bhz3cGxlwu5pnTA\"}"]} +0ms
  spotify-web WebSocket "message" event: {"id":0,"result":"ok"} +217ms
  spotify-web starting heartbeat every 180 seconds +1ms
  spotify-web sendCommand("sp/user_info", []) +0ms
  spotify-web storing callback function for message id 1 +0ms
  spotify-web sending command: {"name":"sp/user_info","id":"1","args":[]} +0ms
  spotify-web sendCommand("sp/log", [41,1,0,0,0,0]) +0ms
  spotify-web sending command: {"name":"sp/log","id":"2","args":[41,1,0,0,0,0]} +0ms
  spotify-web WebSocket "message" event: {"message":["do_work","var t2; try{ var d=new Date(); t2=d[(35725129862..toString(36<<0))[0]];}catch(_) {};this.reply('' + t2);"]} +1ms
  spotify-web got "do_work" payload: "var t2; try{ var d=new Date(); t2=d[(35725129862..toString(36<<0))[0]];}catch(_) {};this.reply('' + t2);" +0ms
  spotify-web reply(["undefined"]) +0ms
  spotify-web sendCommand("sp/work_done", ["undefined"]) +0ms
  spotify-web storing callback function for message id 3 +0ms
  spotify-web sending command: {"name":"sp/work_done","id":"3","args":["undefined"]} +0ms
  spotify-web WebSocket "message" event: {"message":["ping_flash2","230 57 16 18 189 125 80 235 71 206 210 34 164 142 83 22 72 66 24 235"]} +2ms
  spotify-web received flash ping "230 57 16 18 189 125 80 235 71 206 210 34 164 142 83 22 72 66 24 235", sending pong: "131 91 207 151 125 201 235 54 27 142" +0ms
  spotify-web sendCommand("sp/pong_flash2", ["131 91 207 151 125 201 235 54 27 142"]) +0ms
  spotify-web sending command: {"name":"sp/pong_flash2","id":"4","args":["131 91 207 151 125 201 235 54 27 142"]} +0ms
  spotify-web WebSocket "message" event: {"id":3,"result":"ok"} +60ms
  spotify-web "sp/work_done" ACK +1ms
  spotify-web WebSocket "close" event +1s
  spotify-web disconnect() +0ms

[TooTallNate]

Well I wouldn't consider the reply(["undefined"]) itself a red flag... that payload varies each time and sometimes it just simply evaluates to undefined (I got 23 just a second ago though).

But yes indeed, you are right, things seem to be broken again :( It looks like the server-side is closing the WebSocket connection shortly after doing the sp/pong_flash2 call. /cc @adammw

[adammw]

I think the key has changed. Calling document.querySelector('[id*=_player]').sp_run("230 57 16 18 189 125 80 235 71 206 210 34 164 142 83 22 72 66 24 235") produces a different pong value. I'll have a look at digging up the key later tonight, I don't think I still have the scripts I used to do it originally so I'll have to write a new one.

[fuzeman]

Pretty sure the new key is:

[[7, 203], [15, 15], [1, 96], [19, 93], [3, 165], [14, 130], [12, 16], [4, 6], [6, 225], [13, 37]]

[adammw]

@fuzeman nice work extracting the new key! seems to work for me.

[brandtabbott]

Good work @fuzeman! It would be cool to know what hash algorithm is being used, or what algorithm you used to generate that key. :)

[fuzeman]

Just grabbed a few valid ping + pongs from the web player by inspecting the websocket traffic and created this to find the correct key: https://gist.github.com/fuzeman/77741d3b8bfc2b4b5bf2

[stephanepericat]

Same issue is happening again...

[Hozwok]

I confirm.
Login doesn't call callback ...

[denolfe]

See #87

[juanmito]

Hi.

I think it's happening again.