'Unable To Play Selected File' on most tracks from Grooveshark

Thanks for the report Jacek. So it seems you can reliably reproduce the bug. Can you try running moovida from a terminal with the following command and attach the resulting log file to see if we can extract some more information on what's going on?

    ELISA_DEBUG=grooveshark*:5 moovida &> moovida.log

I agree that when a track in the playlist fails to play, (after displaying an error message) the player should go to the next track instead of going back to the list view.

Here is the log. I tried actualy to get _any_ song to play this time,
so that you would be able to see 'normal' behaviour in the log as
well, but unfortunately i did not succeed this morning :(

--
Jacek C. Wojdel <email address hidden>
One of these days I'm gonna change my evil ways, one of these days...

I can reproduce fairly reliably from home.
Here is the interesting bit of log:

DEBUG MainThread grooveshark_tracks_preview_list_controller oct. 18 15:07:47 start playing (elisa/plugins/grooveshark/actions.py:146)
DEBUG MainThread grooveshark_resource_provider oct. 18 15:07:47 sending request: {"header": {"sessionID": "b9989eabde12ad58122060c463c63c16"}, "method": "song.getStreamUrlEx", "parameters": {"songID": 86312}} (elisa/plugins/grooveshark/resource_provider.py:298)
DEBUG MainThread grooveshark_resource_provider oct. 18 15:07:48 sending request: {"header": {"sessionID": "b9989eabde12ad58122060c463c63c16"}, "method": "song.getStreamUrlEx", "parameters": {"songID": 86312}} (elisa/plugins/grooveshark/resource_provider.py:298)
DEBUG MainThread grooveshark_track_model oct. 18 15:07:48 caching playable model (elisa/plugins/grooveshark/models.py:231)
DEBUG MainThread grooveshark_tracks_preview_list_controller oct. 18 15:07:48 successfully downloaded first track (elisa/plugins/grooveshark/actions.py:149)
DEBUG MainThread grooveshark_track_model oct. 18 15:07:48 returning prefetched playable model (elisa/plugins/grooveshark/models.py:288)
DEBUG MainThread grooveshark_track_model oct. 18 15:07:48 deleting cached model (elisa/plugins/grooveshark/models.py:283)
WARN MainThread default oct. 18 15:07:48 Gstreamer Impossible d'ouvrir la ressource en lecture.:gstsouphttpsrc.c(980): gst_soup_http_src_parse_status (): /GstPlayBin:playbin2/GstSoupHTTPSrc:source:
400 Bad Request (elisa/plugins/poblesec/player_video.py:611)

Here is the TCP stream of the request for a stream that fails to play:

GET /stream.php?streamKey=00cc27a80d38102d9512 HTTP/1.1

Host: stream27b.grooveshark.com

Connection: close

icy-metadata: 1

transferMode.dlna.org: Streaming

User-Agent: GStreamer souphttpsrc libsoup/2.26.0

HTTP/1.1 400 Bad Request

X-Powered-By: PHP/5.1.6

Content-type: text/html

Content-Length: 0

Connection: close

Date: Sun, 18 Oct 2009 13:12:02 GMT

Server: lighttpd/1.5.0

And here is the TCP stream of the request for a stream that plays successfully:

GET http://stream27b.grooveshark.com/stream.php?streamKey=00cc27a80d38102d9512 HTTP/1.1
Host: stream27b.grooveshark.com
Connection: Keep-Alive

HTTP/1.1 200 OK
X-Powered-By: PHP/5.1.6
Cache-Control: no-cache, no-store, must-revalidate
Pragma: no-cache
Expires: Sat, 26 Jul 1997 05:00:00 GMT
Content-Type: audio/mpeg
ETag: "523414398"
Accept-Ranges: bytes
Last-Modified: Sun, 04 Oct 2009 04:03:12 GMT
Content-Length: 6236288
Connection: close
Date: Sun, 18 Oct 2009 13:12:01 GMT
Server: lighttpd/1.5.0

I can reproduce from the office as well, and I'm observing the same behaviour.

For songs that play successfully, the corresponding HTTP request has the following form:

    GET http://stream27b.grooveshark.com/stream.php?streamKey=1e09bb120ed9102db1f7 HTTP/1.1

    Host: stream27b.grooveshark.com

    Connection: Keep-Alive

    HTTP/1.1 200 OK

    X-Powered-By: PHP/5.1.6

    Cache-Control: no-cache, no-store, must-revalidate

    Pragma: no-cache

    Expires: Sat, 26 Jul 1997 05:00:00 GMT

    Content-Type: audio/mpeg

    ETag: "1483539035"

    Accept-Ranges: bytes

    Last-Modified: Sat, 10 Oct 2009 01:04:22 GMT

    Content-Length: 5681280

    Connection: close

    Date: Tue, 20 Oct 2009 14:57:50 GMT

    Server: lighttpd/1.5.0

And for songs that fail to play, the corresponding HTTP request has the following form:

    GET /stream.php?streamKey=1e09bb120ed9102db1f7 HTTP/1.1

    Host: stream27b.grooveshark.com

    Connection: close

    icy-metadata: 1

    transferMode.dlna.org: Streaming

    User-Agent: GStreamer souphttpsrc libsoup/2.26.0

    HTTP/1.1 400 Bad Request

    X-Powered-By: PHP/5.1.6

    Content-type: text/html

    Content-Length: 0

    Connection: close

    Date: Tue, 20 Oct 2009 14:57:51 GMT

    Server: lighttpd/1.5.0

It looks like for some reason souphttpsrc issues two different types of requests. The first one does a GET on the full URL of the stream with a Keep-Alive header, the second one does a GET on the relative path of the stream only with a close header, and other additional headers such as icy-metadata, transferMode.dlna.org and User-Agent.

The thing is, I have no clue as to why the requests issued are different. Setting GST_DEBUG to souphttpsrc:5 doesn't show any difference in the logs between the two requests (except the response).

Some more investigation: it seems that the icy-metadata header is not the culprit. It is issued when the "iradio-mode" property of the souphttpsrc element is set to true. Getting the same stream with and without this property using gst-launch works in both cases. It also looks like doing a request on the relative path of the resource rather than the full URI doesn't affect the result, nor do the presence of the transferMode.dlna.org and User-Agent headers.
Here is the dump of the TCP stream for the following pipeline in gst-launch:

    souphttpsrc location=http://stream29.grooveshark.com/stream.php?streamKey=0d2a34d8bd9611de9770 ! filesink location=/home/osomon/temp/boudiou.mp3

    GET /stream.php?streamKey=0d2a34d8bd9611de9770 HTTP/1.1
    Host: stream29.grooveshark.com
    Connection: close
    transferMode.dlna.org: Streaming
    User-Agent: GStreamer souphttpsrc libsoup/2.26.0

    HTTP/1.1 200 OK
    X-Powered-By: PHP/5.1.6
    Cache-Control: no-cache, no-store, must-revalidate
    Pragma: no-cache
    Expires: Sat, 26 Jul 1997 05:00:00 GMT
    Content-Type: audio/mpeg
    ETag: "69546903"
    Accept-Ranges: bytes
    Last-Modified: Tue, 13 Oct 2009 02:36:13 GMT
    Content-Length: 4618663
    Connection: close
    Date: Tue, 20 Oct 2009 16:33:09 GMT
    Server: lighttpd/1.5.0

The error received is a 400 "Bad Request", meaning that the request could not be understood by the server due to malformed syntax. The only sort of explanation I can come up with at the moment is that at some point the streamKey parameter becomes invalid. Although in that case I would expect the server to return a 404 code.

It looks like some changes were done on the server, but that doesn't improve the situation for the end-user. The error code returned is now a 404 ("Not Found").

On latest bzr revision I can try to play a single song 3 times in quick succession and get 3 different errors, these being http 302, 400 and occasionally will get the original error mentioned above ("Could not open the resource for reading").

It seems completely random which error will pop up.

I also tried what noisyme just said and got very similar results. One particular issue that I wanted to make emphasis in is that the error 400 is always coming after either the original Gstreamer Error or the new 302 error (i.e. when I try to reproduce a song multiple times, at first I get either the Gstreamer error or the 302 error and from then on, I only get the error 400. It has that behaviour for each file I tried on my playlists, on the section 'popular' or using the search menu)

I've investigated and it looks like the model pre-fetching mechanism is to blame. Pre-fetching a model invalidates the URL (it's a one-shot URL), despite the "clever" mechanism meant to avoid this. Disabling the mechanism seems to fix the issue here.
I still need to understand why this mechanism was here in the first place, though. It looks to me like it was introduced to work around a bug on grooveshark's side where invalid URLs were returned, which was fixed since then.

People interested in testing, grab the attached egg file, drop it in ~/.moovida/plugins/ on linux or in %USERPROFILE%\.moovida\plugins\ on windows, test, and report the results here. Thanks.

It turns out that this patched version of the plugin is not enough to fix things.
Revision 1599 of lp:moovida introduced this bad regression that messes the URLs containing parameters (that is, "?" or "=" characters). See bug #491874.

I've just updated Moovida a couple hours ago and it works flawlessly, when using the Grooveshark plugin. I tried private lists, popular songs and searches. Thank you very much Olivier!

Thanks to everyone who helped spotting, understanding, fixing the issue and testing the fix!

Yes, indeed, everything works fine now. Thanks!

--
Jacek C. Wojdel <email address hidden>
One of these days I'm gonna change my evil ways, one of these days...