lotan / rhythmbox-ampache

Rhythmbox plugin to stream music from Ampache
GNU General Public License v2.0
21 stars 7 forks source link

Ampache plugin not working with Ampache 3.8.2 #7

Closed Khymick closed 8 years ago

Khymick commented 8 years ago

Hi there,

I have two different instances of Ampache running on a debian server:

The two instances are using two different mysql databases. While all works fine with the connectivity to 3.8.0-develop, the plugin only loads and shows a little part of the songs on the server. All songs on 3.8.2 are running fine through the webinterface and also from an iPhone with iSub as client.

I am having the same problem on two different systems:

If there are logs etc needed, let me know.

lotan commented 8 years ago

While logs might help

rhythmbox -D ampache

it might have something to do with the two databases you mentioned. Can you tell whether the "little part" are all the songs of either database?

The Ampache XML API is not quite as configurable as the web interface and an Ampache client might just have better access to the media.

Khymick commented 8 years ago

Find the log down (uploading doesn't work...)

What concerns your question: I did install the second instance of ampache, 3.8.2, for testing purposes: I wasn't sure if all would work fine. That's why the second instance is completely standing on it's own, including an second database. In the 3.8.2-database, all songs are present. I can see them in both the webfrontend as well as from the iSub-client on the iPhone. So I guess this should work.

Log: $ rhythmbox -D ampache

(rhythmbox:2210): libsoup-CRITICAL **: soup_server_quit: assertion 'priv->listeners != NULL' failed

(rhythmbox:2210): GLib-GObject-CRITICAL **: object SoupServer 0x23aa7a0 finalized while still in-construction

(rhythmbox:2210): GLib-GObject-CRITICAL **: Custom constructor for class SoupServer returned NULL (which is invalid). Please use GInitable instead.

(rhythmbox:2210): Gtk-WARNING **: Duplicate child name in GtkStack: Zur Wiedergabeliste hinzufügen

(rhythmbox:2210): Gtk-WARNING **: Duplicate child name in GtkStack: Zur Wiedergabeliste hinzufügen

(rhythmbox:2210): Gtk-WARNING **: Duplicate child name in GtkStack: Zur Wiedergabeliste hinzufügen

(rhythmbox:2210): Gtk-WARNING **: Duplicate child name in GtkStack: Zur Wiedergabeliste hinzufügen

(rhythmbox:2210): Gtk-WARNING **: Duplicate child name in GtkStack: Zur Wiedergabeliste hinzufügen

(rhythmbox:2210): Gtk-WARNING **: Duplicate child name in GtkStack: Zur Wiedergabeliste hinzufügen

(rhythmbox:2210): Gtk-CRITICAL **: gtk_builder_get_object: assertion 'GTK_IS_BUILDER (builder)' failed

(rhythmbox:2210): Gtk-CRITICAL **: gtk_builder_get_object: assertion 'GTK_IS_BUILDER (builder)' failed

(rhythmbox:2210): Gtk-CRITICAL **: gtk_widget_set_sensitive: assertion 'GTK_IS_WIDGET (widget)' failed

(rhythmbox:2210): Gtk-CRITICAL **: gtk_widget_set_sensitive: assertion 'GTK_IS_WIDGET (widget)' failed

(rhythmbox:2210): libdmapsharing-WARNING **: DACP browsing not started (09:45:28) [0x1945c10] [AmpacheBrowser.update] /usr/lib/rhythmbox/plugins/ampache/AmpacheBrowser.py:850: downloading handshake: https://my.ampache.local/music/server/xml.server.php?action=handshake&auth=bf18f4a96ad87e61b37915a794232e68bd46c1b97cbaba55a1b0ed92a49f5474&timestamp=1457167528&user=myuser&version=350001 (09:45:29) [0x1945c10] [AmpacheBrowser.handshake_cb] /usr/lib/rhythmbox/plugins/ampache/AmpacheBrowser.py:1094: downloading playlists: https://my.ampache.local/music/server/xml.server.php?action=playlists&auth=35d96e06eb50ce8bba1c0340dddc3436 (09:45:29) [0x1945c10] [AmpacheBrowser.update] /usr/lib/rhythmbox/plugins/ampache/AmpacheBrowser.py:850: downloading handshake: https://my.ampache.local/music/server/xml.server.php?action=handshake&auth=3b5da13f9202d0558e37362c03056faa19bae3ec0f3f047711cc520a432fa3d8&timestamp=1457167529&user=myuser&version=350001 (09:45:30) [0x1945c10] [AmpacheBrowser.download_iterate] /usr/lib/rhythmbox/plugins/ampache/AmpacheBrowser.py:653: process playlist: _songs (09:45:30) [0x1945c10] [AmpacheBrowser.download_songit=5000 (09:48:09) [0x1945c10] [AmpacheBrowser.songs_downloaded_cb] /usr/lib/rhythmbox/plugins/ampache/AmpacheBrowser.py:532: error parsing songs: :1424:47: not well-formed (invalid token) (09:48:09) [0x1945c10] [open_append_cb] /usr/lib/rhythmbox/plugins/ampache/AmpacheBrowser.py:473: write to cache file: /home/myuser/.cache/rhythmbox/ampache/_songs.xml (09:48:09) [0x1945c10] [AmpacheBrowser.download_iterate] /usr/lib/rhythmbox/plugins/ampache/AmpacheBrowser.py:688: no more playlistss_chunk] /usr/lib/rhythmbox/plugins/ampache/AmpacheBrowser.py:616: downloading songs: https://my.ampache.local/music/server/xml.server.php?action=songs&auth=35d96e06eb50ce8bba1c0340dddc3436&offset=0&limit=5000 (09:45:31) [0x1945c10] [AmpacheBrowser.handshake_cb] /usr/lib/rhythmbox/plugins/ampache/AmpacheBrowser.py:1094: downloading playlists: https://my.ampache.local/music/server/xml.server.php?action=playlists&auth=f107458e58a6fc1d83bcee06e4e8d906 (09:45:32) [0x1945c10] [AmpacheBrowser.download_iterate] /usr/lib/rhythmbox/plugins/ampache/AmpacheBrowser.py:688: no more playlists to process (09:46:53) [0x1945c10] [AmpacheBrowser.download_songs_chunk] /usr/lib/rhythmbox/plugins/ampache/AmpacheBrowser.py:616: downloading songs: https://my.ampache.local/music/server/xml.server.php?action=songs&auth=35d96e06eb50ce8bba1c0340dddc3436&offset=5000&limit=5000 (09:46:53) [0x1945c10] [AmpacheBrowser.songs_downloaded_cb] /usr/lib/rhythmbox/plugins/ampache/AmpacheBrowser.py:532: error parsing songs: :7614:47: not well-formed (invalid token) (09:46:53) [0x1945c10] [open_append_cb] /usr/lib/rhythmbox/plugins/ampache/AmpacheBrowser.py:473: write to cache file: /home/myuser/.cache/rhythmbox/ampache/_songs.xml (09:46:54) [0x1945c10] [AmpacheBrowser.download_iterate] /usr/lib/rhythmbox/plugins/ampache/AmpacheBrowser.py:688: no more playlists to process (09:48:09) [0x1945c10] [AmpacheBrowser.download_songs_chunk] /usr/lib/rhythmbox/plugins/ampache/AmpacheBrowser.py:616: downloading songs: https://my.ampache.local/music/server/xml.server.php?action=songs&auth=35d96e06eb50ce8bba1c0340dddc3436&offset=10000&lim to process (09:49:24) [0x1945c10] [AmpacheBrowser.download_songs_chunk] /usr/lib/rhythmbox/plugins/ampache/AmpacheBrowser.py:616: downloading songs: https://my.ampache.local/music/server/xml.server.php?action=songs&auth=35d96e06eb50ce8bba1c0340dddc3436&offset=15000&limit=5000 (09:49:24) [0x1945c10] [AmpacheBrowser.songs_downloaded_cb] /usr/lib/rhythmbox/plugins/ampache/AmpacheBrowser.py:532: error parsing songs: :95:27: not well-formed (invalid token) (09:49:24) [0x1945c10] [open_append_cb] /usr/lib/rhythmbox/plugins/ampache/AmpacheBrowser.py:473: write to cache file: /home/myuser/.cache/rhythmbox/ampache/_songs.xml (09:49:24) [0x1945c10] [AmpacheBrowser.download_iterate] /usr/lib/rhythmbox/plugins/ampache/AmpacheBrowser.py:688: no more playlists to process (09:49:27) [0x1945c10] [open_append_cb] /usr/lib/rhythmbox/plugins/ampache/AmpacheBrowser.py:473: write to cache file: /home/myuser/.cache/rhythmbox/ampache/_songs.xml (09:49:27) [0x1945c10] [AmpacheBrowser.download_iterate] /usr/lib/rhythmbox/plugins/ampache/AmpacheBrowser.py:688: no more playlists to process

jschurse commented 8 years ago

Hey,

I got the same Issue. I have an ampache server with version 3.8.2 and in rhytmbox only some songs are being shown. If I use for example amarok everything is working as expected.

lotan commented 8 years ago

@Khymick: Somehow the timestamps seem to be mixed up a bit which I find strange. Did you copy more than one log into your message? Nevertheless, there are a lot of 'not well-formed (invalid token)' for the XML parsing which will cause problems.

If you;re interested in debugging the issue, you can download the handshake and/or the downloading songs URIs (from the debug output of the ampache plugin) through a browser and check if the XML that the Ampache API creates is not well-formed. You might directly find a problem in the Ampache-generated XML or you might find, it's ok in which case there will be a problem in the plugin.

I will have to try out Ampache version 3.8.2 myself but Gentoo is only at 3.8.1, which still works.

ghost commented 8 years ago

@lotan I'm having this same issue on my Ampache server, I would be glad to set you up with some credentials on it so you can play with it there and not have to worry about upgrading your server.

lotan commented 8 years ago

@breaker1: Thanks for the kind offer but I'd feel like I'd be intruding.

I'm preparing the package for my distribution at the moment and either I'm missing a dependency or I've uncovered an Ampache error.

When I load the handshake URI as prescribed in my previous post I get an error:

Fatal error: Class 'Gettext\Translator' not found in /var/www/localhost/htdocs/ampache/lib/i18n.php on line 36

I had been trying to find out where to get that class and wasn't successful.

Can one of you confirm whether the handshake (the one after 'downloading handshake' in the rhythmbox ampache log) works on their system using Ampache 3.8.2?

ghost commented 8 years ago

@lotan You probably need to run composer install or composer update I can't remember which it requires. If you don't have composer check out the composer website

jschurse commented 8 years ago

@lotan ampache uses composer for the installation of dependencies https://github.com/ampache/ampache/wiki/Installation#composer did you run $ composer update

damn it, breaker1 was faster...

lotan commented 8 years ago

That's probably why my distribution hasn't updated yet. There's no mention in the build scripts about composer.

Update worked, Ampache running at 3.8.2. Thank you both!

Unfortunately, I don't have a problem. My whole catalog has been downloaded via the Ampache XML API.

To continue, I'm going to have to ask you for the handshake and the song XML.

Khymick commented 8 years ago

Did you update or a new install of 3.8.2? I am asking because there are some changes in the settings of the Ampache server 3.8.2 and I am not sure what happens when you update.

I can provide the file tomorrow. What concerns the handshake: What exactly do you mean? The url?

Von meinem iPhone gesendet

Am 07.03.2016 um 20:51 schrieb lotan notifications@github.com:

That's probably why my distribution hasn't updated yet. There's no mention in the build scripts about composer.

Update worked, Ampache running at 3.8.2. Thank you both!

Unfortunately, I don't have a problem. My whole catalog has been downloaded via the Ampache XML API.

To continue, I'm going to have to ask you for the handshake and the song XML.

— Reply to this email directly or view it on GitHub.

jschurse commented 8 years ago

@lotan handshake: https://mcpaste.de/view/493e79a7

I uploaded the xml and found one of the errors. songs: https://www.jschurse.de/songs.xml

lotan commented 8 years ago

@Khymick: I updated Ampache. But just to be sure, what settings are you talking about?

To get the handshake URI, start rhythmbox via the shell $ rhythmbox -D ampache 2>&1|grep 'downloading handshake'

Copy the URI after the downloading handshake: and paste it into the address bar of a web browser.

The browser should return an XML document which, according to errors in the log messages you've posted isn't well formed. You can either verify that claim yourself or upload/paste it here. Be aware though, that sensitive data might be in that content.

lotan commented 8 years ago

@jschurse: The handshake seems fine to me on first glance. I'd file a bug in Ampache's bug tracker for the error in your songs.xml. Can you eliminate that one instance from your Ampache database (at least temporarily)? Does the remainder work for you after that?

jschurse commented 8 years ago

@lotan I removed the ampersant and now the xml parses correctly. I will create an issue at the ampache project.

Would it be possible to also clear up the xml on the client side?

jschurse commented 8 years ago

Apperently the problem is known and allready fixed in the development version. https://github.com/ampache/ampache/issues/1171

lotan commented 8 years ago

@jschurse: Well done. In principle it would've been possible to preprocess the XML on the client side but it wouldn't have been right. In general, my impression is that Afterster is very receptive to suggestions, so problems upstream should be dealt with upstream.

jschurse commented 8 years ago

@lotan I agree with you. The problem should be fixed where the problem is.

I applied a quick patch to the lib/class/xml_data.class.php so that the ampersand gets escaped. Now the first 15000 songs load without any problems. Then I get the next error:

23:49:19) [0xf37030] [AmpacheBrowser.songs_downloaded_cb] /usr/lib/rhythmbox/plugins/ampache/AmpacheBrowser.py:580: error parsing songs: <unknown>:57617:18: not well-formed (invalid token)

If I download the referenced xml this is line 57617: <replaygain_album_peak>0.000000</replaygain_album_peak> I can´t see what´s wrong with that line. Firefox can open the document without any parsing errors.

I´m not even shure if I look at the right place since the error persists when deactivating the song. It still is in the same line and the same tag but then in another song.

Khymick commented 8 years ago

I am installing the up-to-date-devel version right at the moment which is "3.8.3-devel". At the moment, the catalogue is being created which will certainly take it´s time. I will then post the news here.

Nevertheless, here are my informations:

Handshake: <?xml version="1.0" encoding="UTF-8" ?>

Which means that the timestamp is invalid. As I am not that deep into this: How can this be possibly happen?

Greets

Khymick commented 8 years ago

Update for 3.8.3-devel: It´s getting better, more songs are now displayed, but still not all. I get the same mistake as lotan ([AmpacheBrowser.songs_downloaded_cb] /usr/lib64/rhythmbox/plugins/ampache/AmpacheBrowser.py:532: error parsing songs: :41583:19: not well-formed (invalid token)).

Sorry to ask, but how can I access the referenced xml line - in which file can it be found?

Khymick commented 8 years ago

Okay, found the file, I assume.

@lotan: May it be that it´s not a problem with the indicated line, but with the previous one? In my case, here are the two lines:

41582 <art><![CDATA[https://my.ampache.local/musicdevel/image.php?object_id=576&object_type=album&auth=1033f84f075fa5877fc29ccbbdb7629d&name=art.png]]></art> 41583 <preciserating>0</preciserating>

So, in 41582, there is an ampersand - but I am not sure if this might be the cause. What do you think?

lotan commented 8 years ago

@jschurse: I used to do well-formedness check with Xalan but nowadays I'm sure there are a lot more comfortable ways to do that. An XML editor for example.

lotan commented 8 years ago

@Khymick: Re: <![CDATA[Fehler: Der Handshake ist ungültig -Login gescheitert: Zeitstempel ungültig]]> Did you use an old handshake? One that's timed out already?

The ampersands in the CDATA section as parts of the URI are ok. Those are not your problem.

Khymick commented 8 years ago

@lotan: I did "refetch ampache library" in rhythmbox after havin configured the ampache plugin for thge 3.8.3-devel installation. When I check the new handshake with the url, I do not get the "invalid timestamp" error at the moment. So this seems to be fine.

After having refetched the library, I checked the same song stops the download of the catalogue - it is the same song. Would it help if I sent you the lines from the xml-file? From my side, I cannot see any mistake in it.

lotan commented 8 years ago

@Khymick: The auth token becomes invalid after a time configured in the Ampache configuration. If you used the handshake URI right after rhythmbox generated it in the log, that can't be the cause of the problem. That was just an idea I had.

If you want to, you can send me the XML and I'll see if I can find anything.

Khymick commented 8 years ago

Where to send?

lotan commented 8 years ago

send it to lotan_rm@gmx.de

Khymick commented 8 years ago

Sent.

jschurse commented 8 years ago

@lotan I validated the xml with two different tools but still get the error [0x11cbed0] [AmpacheBrowser.songs_downloaded_cb] /usr/lib/rhythmbox/plugins/ampache/AmpacheBrowser.py:580: error parsing songs: <unknown>:57617:18: not well-formed (invalid token)

as well as for one of the next chunk:

[0x18a7cf0] [AmpacheBrowser.songs_downloaded_cb] /usr/lib/rhythmbox/plugins/ampache/AmpacheBrowser.py:580: error parsing songs: <unknown>:22672:18: not well-formed (invalid token)

What´s even more interesting is the place where the error occures. Line 580 is only parameters for datetime.strptime:

578 handshake_clean = datetime.strptime( 579         handshake['clean'][0:18], 580         '%Y-%m-%dT%H:%M:%S')

Any idea where this could come from?

lotan commented 8 years ago

This ist completely strange. The error message is definitely generated on line 311. As I look at Khymick's log, the error message is indicated as being generated on line 532 which is wrong as well. I don't think we can take this line number seriously. What Khymick is trying to do is: dump the data that is to be parsed into a file right before it's sent to the parser and check that file. Maybe you want to try that, too.

lotan commented 8 years ago

@Khymick, @jschurse: I made a few changes in the download order, extended log messages a bit (including printing the line that the SAX parser says is not well-formed) and - specifically for you guys - I added storage of all data to be parsed for debugging purposes.

I suggest you backup your version of /usr/lib/rhythmbox/plugins/ampache/AmpacheBrowser.py and replace it with

https://raw.githubusercontent.com/lotan/rhythmbox-ampache/debug_xml_parsing/AmpacheBrowser.py

jschurse commented 8 years ago

@lotan thanks for your help!

This is the new error message:

(22:48:12) [0x2602ed0] [AmpacheBrowser.songs_downloaded_cb] /usr/lib/rhythmbox/plugins/ampache/AmpacheBrowser.py:566: parse chunk _songs[15000]... Traceback (most recent call last): File "/usr/lib/python3.5/xml/sax/expatreader.py", line 210, in feed self._parser.Parse(data, isFinal) xml.parsers.expat.ExpatError: not well-formed (invalid token): line 56132, column 18 During handling of the above exception, another exception occurred: Traceback (most recent call last): File "/usr/lib/rhythmbox/plugins/ampache/AmpacheBrowser.py", line 304, in songs_downloaded_cb parser.feed(contents) File "/usr/lib/python3.5/xml/sax/expatreader.py", line 214, in feed self._err_handler.fatalError(exc) File "/usr/lib/python3.5/xml/sax/handler.py", line 38, in fatalError raise exception xml.sax._exceptions.SAXParseException: <unknown>:56132:18: not well-formed (invalid token) During handling of the above exception, another exception occurred: Traceback (most recent call last): File "/usr/lib/rhythmbox/plugins/ampache/AmpacheBrowser.py", line 307, in songs_downloaded_cb (e, contents.split("\n")[e.getLineNumber()])) TypeError: a bytes-like object is required, not 'str'

Thanks to your addition I could locate the problem: Some real fucked up characters in attributes which I can´t even insert here.

I renamed the corresponding entries in the database via phpmyadmin and now everzthing is working fine!.

So it seems ampache does not encode the string correctly when storing information in the database. I opened another Issue at the ampache project. https://github.com/ampache/ampache/issues/1177

Thanks again for your help!

Khymick commented 8 years ago

@jschurse: Thanks for your feedback so far. Can you please give me a hint where to look for there messed up characters in the ampache db? As for me, the line indicated in my error message leads to "avaragerating", but I didn´t find this field in the db...

jschurse commented 8 years ago

@Khymick could you provide me with a screenshot of the xml where the bad characters are standing? Maybe with that context I can help you.

Khymick commented 8 years ago

Where to send? And do you mean the _songs.xml-lines that are shown as mal-formatted?

jschurse commented 8 years ago

Yes the _songs.xml. You could either upload the screenshot to an image hoster like imgur.com and post the links here if no senstive information is being shown, or mail them directly to me at: mail@jschurse.de

lotan commented 8 years ago

@jschurse: Thanks for letting me know. I'm glad you've found your problem. Your log revealed an error of mine from yesterdays efforts which is now corrected.

Khymick commented 8 years ago

@jschurse: I did send you an email, I cannot find the mistake up to now. I would really appreciate any help on this.

Khymick commented 8 years ago

So, finally, I found the problem in my installation of ampache 3.8.3-devel:

it was a "\b" string in a "comment" field of the "song_data" table. I wonder how this came up, as I can compare two different ampache installations with two different databases - and in the working database, there was no "\b" in the comment of the appropriate song.

Nevertheless, thank you all for helping me to find the cause.

lotan commented 8 years ago

Oh wow, that is a hard one to track down. Well done.

I take it the issue on plugin side is resolved and close it.