search

Saiyato / volumio-lastfm-plugin

Plugin to scrobble music played in Volumio 2.x to LastFM.
7 stars 8 forks source link

Can't get the plugin to work #8

Closed webodan closed 6 years ago

webodan commented 6 years ago

Hi,

I've been trying to get the last version of this plugin available on volumio2 to work, but no matter what I did, it simply never got to scrobble. I've added the api key and secret using the web interface and all, but nope, it won't scrobble. I've also tried editing the config.json and UIConfig.json API_KEY, API_SECRET, username and password "value" fields with those credentials over ssh (since they were empty and I thought it would be causing the issue. auth token was also empty but I don't have that value), disabling the plugin and enabling it again... but to no avail.

Is the plugin working at all? i'm out of options at this point.

Saiyato commented 6 years ago

Hi webodan,

Yes the plugin does work, can you tell me what you tried? Which service you are using and on what platform?

Also did you enable extra logging and what does it say?

webodan commented 6 years ago

Hi Saiyato,

I've tried playing mp3 files from a USB HDD and a DLNA share I have on a different Pi as well as webradio streams. I know for a fact that the files have the proper tags since they scrobble fine on my computer when I use Foobar2000. I'm running the latest version of volumio and of this plugin on a Raspberry Pi1 B+. I don't know the location of any log files related to this specific plugin, but I'm attaching Volumio's to this post in case it is the one you're asking for.

volumio.log

Saiyato commented 6 years ago

Hi,

I'm seeing the following, which means the plugin is active:

2018-02-03T13:50:12.315Z - info: STATE SERVICE {"status":"play","position":0,"seek":859,"duration":321,"samplerate":"44.1 KHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"isStreaming":false,"title":"State Of Mind","artist":"Air","album":null,"uri":"http://x.x.x.x:yyyy/MediaItems/2362.mp3","trackType":"mp3"}
2018-02-03T13:50:15.408Z - info: [LastFM] starting new timer for 32100 milliseconds [Air - State Of Mind].

The following line indicates the end of playback: 2018-02-03T13:55:32.158Z - info: --------------------------------------------------------------------// [LastFM] new state has been pushed; status: stop | service: mpd | duration: 0 | title: | previous title: State Of Mind

13:50:15 - 13:55:32 = 5:16 = 316 seconds, the duration propagated by MPD is 321 seconds, if you setup the scrobbler to scrobble at 100% it will never scrobble. The state is read four seconds after the start of playback, which is weird, but not something I can solve (I only use the states that are being SENT, I don't fetch them. Even then it could come to a mismatch, since playback started 4 seconds earlier and 316 + 4 still doesn't match 321.

Does it update your 'now playing'? If so, try setting it to scrobble at 90% or even 80% of the song.

webodan commented 6 years ago

I've had it until now in 50% of the song. I'm gonna follow your advice and enable the plugin (i disabled it since it wasn't working),set it to 90% through the web interface, and try playing something.

And no, up until now it was not updating my now playing or even scrobbling the song at all.

Saiyato commented 6 years ago

Ok, that's problematic. If it doesn't update your 'now playing' on LastFM, scrobbles will never reflect there. You didn't accidentally made a typo in your API key and secret? These are absolutely necessary for the token.

Also, for the time being, can you enable debug logging in the plugin? The log you sent was the one I need.

webodan commented 6 years ago

Nope, I'm certain I didn't typo. I typed both of them one character at a time (copypasting them at first did not work) then copied each of them and pasted them into the search feature on the browser. They matched.

As I said, I even went as far as to put them myself to the json files over ssh. But it simply seems to ignore my input.

There, I've just played another one (this one was 1:14 in length, and hosted in my DLNA drive). Didn't scrobble.

Another odd thing that i noticed is that I can't change the volume from the web interface when the plugin is installed and enabled. It only happens with DLNA files though (the youtube plugin does allow me to do this) so maybe that's another bug entirely.

In Pi Musicbox on this same hardware scrobbling did work (but having a DLNA share didn't, so I prefer volumio). I don't think I messed anything up.

Saiyato commented 6 years ago

Hmmm good point, were you able to enable the debug logging? That should clarify a little bit better where it goes south. It should at the very least confirm that the session key is obtained.

I must say I'm not too savvy when it comes to DLNA setups, what is your setup? I will then try to setup a similar environment for testing.

While typing I'm seeing an error in the logfile:

2018-02-03T13:50:15.508Z - info: [LastFM] could not process current state: {"status":"play","title":"State Of Mind","artist":"Air","album":null,"albumart":"http://x.x.x.x:yyyy/AlbumArt/39-2362.jpg","uri":"http://x.x.x.x:yyyy/dir/2362.mp3","trackType":"mp3","seek":859,"duration":321,"samplerate":"44.1 KHz","bitdepth":"24 bit","channels":2,"random":false,"repeat":false,"repeatSingle":false,"consume":false,"volume":60,"mute":false,"stream":false,"updatedb":false,"volatile":true,"service":"mpd"}

This is weird, will see if I can trace where this happens.

webodan commented 6 years ago

My setup is the following:

Raspberry Pi 1 B+ running Volumio as the client (got it set up near my bed) with a PCM2704 USB DAC I got off wish and Cheapo Sony headphones for it.

Raspberry Pi2 B+ running Raspbian, connected to a 2TB USB HDD running MiniDLNA to share its filesystem (in my living room, this is the server, holds up all the media on it). I don't simply plug in the hard drive to my Pi1 because I'm interested in sharing both video and audio to various devices on my home network and it's also the most powerful Pi I have spare. Plus that Pi2 is doing sort of domotic stuff as well as DLNA and SMB sharing (has a webcam conencted and a CRT TV to display the video off of it).

DLNA is actually pretty nice, but over USB 2 to a large selection of files, it's quite a nuisance to set up. It's also really slow to scan over such a large filesystem (updating the database always takes around 40 minutes for my overclocked Pi2 to complete). I recommend you just share those files from the local microSD card to shorten testing time. And get acquainted with MiniDLNA (it's cumbersome at first, but once you're used to its shortcomings, it's really great to share media content transparently in case you don't have a router that supports DLNA sharing of large hard drives as is my case). I can even share videos to an old XBOX 1 using this method.

Lastly, of course, all of their ips are set statically and with OpenDNS (I don't usually use name resolution, for some reason it's slow in my network and sometimes leads to resolution problems).

Regarding your other question, yeah i did enable debug logging and the first log i sent here should have it enabled-

Tell me how it goes for you. Thank you very much for your support.

Saiyato commented 6 years ago

Good morning,

I'm missing some important entry in your log, the 'trying to authenticate' which should be enabled by debug logging. I've also just update the package with a spop PR. Can you try this version?

Else I will try to incorporate more logging.

webodan commented 6 years ago

Can I just download this plugin as zip and upload it to Volumio? Will do that in a bit.

BTW some more testing, I had to reflash my SD card anew after some errors I had unrelated to this plugin and it still doesn't scrobble. Just to rule out a possible data corruption issue that could be causing my problem.

Saiyato commented 6 years ago

No, you don't need to create a zip-file yourself, just download the zip from the repo. Go to 'code' and download "volumio-lastfm-plugin.zip"

webodan commented 6 years ago

Hi man, sorry for the delay.

Something else broke off: After deleting the old and uploading the new plugin into the system, I couldn't get into the web interface. I tried rebooting the node process that I assumed was running this part, by killing it then running it again, and this is what I get:

info: Loading plugin "youtube"... info: Loading plugin "albumart"... info: Plugin example_plugin is not enabled info: Loading plugin "updater_comm"... info: Plugin mpdemulation is not enabled info: Loading plugin "rest_api"... info: Loading plugin "websocket"... info: Loading plugin "lastfm"... /data/plugins/miscellanea/lastfm/index.js:219 else if (state.status == 'pause') ^^^^ SyntaxError: Unexpected token else at createScript (vm.js:56:10) at Object.runInThisContext (vm.js:97:10) at Module._compile (module.js:542:28) at Object.Module._extensions..js (module.js:579:10) at Module.load (module.js:487:32) at tryModuleLoad (module.js:446:12) at Function.Module._load (module.js:438:3) at Module.require (module.js:497:17) at require (internal/module.js:20:19) at PluginManager.loadPlugin (/volumio/app/pluginmanager.js:117:25) at /volumio/app/pluginmanager.js:218:30 at Array.forEach (native) at HashMap. (/volumio/app/pluginmanager.js:217:17) at HashMap.forEach (/volumio/node_modules/hashmap/hashmap.js:157:10) at HashMap.proto.(anonymous function) [as forEach] (/volumio/node_modules/hashmap/hashmap.js:169:7) at PluginManager.loadPlugins (/volumio/app/pluginmanager.js:215:17)

How can I remove the plugin and (hopefully) try to reinstall it just in case it was just a bad install? I only have SSH right now.

Saiyato commented 6 years ago

The 'hard' remove is to delete the folder /data/plugins/miscellanea/lastfm, then restart volumio and you should be fine.

webodan commented 6 years ago

Good, I was able to go back and install it graphically (this time it did install properly), but now i get "No Configuration Available" in the plugin's Settings.

tail of volumio.log:

2018-02-04T16:58:38.709Z - info: Enabling plugin lastfm 2018-02-04T16:58:38.729Z - info: Loading plugin "lastfm"... 2018-02-04T16:58:38.785Z - info: Error: SyntaxError: Unexpected token else 2018-02-04T16:58:39.892Z - info: Enabling plugin lastfm 2018-02-04T16:58:39.911Z - info: Loading plugin "lastfm"... 2018-02-04T16:58:39.955Z - info: Error: SyntaxError: Unexpected token else 2018-02-04T16:58:42.551Z - info: CoreCommandRouter::getUIConfigOnPlugin 2018-02-04T16:59:12.341Z - info: [{"prettyName":"LastFM Scrobbler","name":"lastfm","category":"miscellanea","version":"1.1.12","icon":"fa-lastfm","enabled":true,"active":false},{"prettyName":"Youtube Playback","name":"youtube","category":"music_service","version":"0.0.5","icon":"fa-youtube","enabled":true,"active":true}] 2018-02-04T16:59:13.925Z - info: CoreCommandRouter::getUIConfigOnPlugin 2018-02-04T16:59:15.165Z - info: [{"prettyName":"LastFM Scrobbler","name":"lastfm","category":"miscellanea","version":"1.1.12","icon":"fa-lastfm","enabled":true,"active":false},{"prettyName":"Youtube Playback","name":"youtube","category":"music_service","version":"0.0.5","icon":"fa-youtube","enabled":true,"active":true}] 2018-02-04T16:59:38.027Z - info: CoreCommandRouter::getUIConfigOnPlugin 2018-02-04T17:00:53.267Z - info: [{"prettyName":"LastFM Scrobbler","name":"lastfm","category":"miscellanea","version":"1.1.12","icon":"fa-lastfm","enabled":true,"active":false},{"prettyName":"Youtube Playback","name":"youtube","category":"music_service","version":"0.0.5","icon":"fa-youtube","enabled":true,"active":true}]

It kept killing my web interface, so I had to fire up another rm on the plugin folder as you taught me so it would boot up again. That plugin zip file is definitely faulty.

Saiyato commented 6 years ago

I just re-imaged my Pi and installed the plugin, I'm not seeing your behavior. Can you also delete the old config please? It's located here: /data/configuration/miscellanea/lastfm

webodan commented 6 years ago

OK, Here's what I just did:

😕

I don't know what it is, but it doesn't want me to use your new plugin (uploading volumio-lastfm-plugin.zip breaks it). killing the process, then running it manually gave me the same terminal output as my previous message.

Anything else I can tinker with?

Saiyato commented 6 years ago

Hmmm... not that I know of, maybe the image for the Pi1 differs from the Pi2. I will have to rig up a Pi1 to test, maybe the installed node modules are different.

Saiyato commented 6 years ago

Just rigged up a Pi1 (much slower than my Pi2) and it installs fine the first time, the image I'm using is 2.348. Can you post the log file of a fresh image, installation and opening the settings page please?

webodan commented 6 years ago

OK, did the following:

it doesnt' like me :(

I could not retrieve the log file (it was empty). However, killing the process then running it again allows me to get logging from SSH, so i'll just copy and paste this. Here it comes:

(deleted the volumio2 system startup thingy because it fucks up with the text formatting in github)

info: Plugin folders cleanup info: Scanning into folder /volumio/app/plugins/ info: Scanning category audio_interface info: Scanning category miscellanea info: Scanning category music_service info: Scanning category plugins.json info: Scanning category system_controller info: Scanning category user_interface info: Scanning into folder /data/plugins/ info: Scanning category miscellanea info: Plugin folders cleanup completed info: Loading plugins from folder /volumio/app/plugins/ info: Loading plugins from folder /data/plugins/ info: Loading plugin "system"... info: Loading plugin "appearance"... info: Loading plugin "network"... info: Loading plugin "services"... info: Loading plugin "alsa_controller"... info: Loading plugin "wizard"... info: Loading plugin "volumio_command_line_client"... info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam info: Loading plugin "upnp"... info: [1517858890197] Starting Upmpd Daemon info: CoreCommandRouter::executeOnPlugin: system , registerCallback info: Loading plugin "mpd"... info: Loading plugin "upnp_browser"... info: Loading plugin "networkfs"... info: CoreCommandRouter::executeOnPlugin: system , registerCallback info: Loading plugin "alarm-clock"... info: Loading plugin "airplay_emulation"... info: [1517858903774] Starting Shairport Sync info: Loading plugin "last_100"... info: Loading plugin "webradio"... info: Loading plugin "i2s_dacs"... info: I2S DAC not set, start Auto-detection info: Loading plugin "volumiodiscovery"... WARNING The program 'node' uses the Apple Bonjour compatibility layer of Avahi. WARNING Please fix your application to use the native API of Avahi! WARNING For more information see http://0pointer.de/avahi-compat?s=libdns_sd&e=node WARNING The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi. WARNING Please fix your application to use the native API of Avahi! WARNING For more information see http://0pointer.de/avahi-compat?s=libdns_sd&e=node&f=DNSServiceRegister info: Applying required configuration parameters for plugin volumiodiscovery Discovery: StartAdv! undefined Discovery: Started advertising... Volumio - undefined info: CoreCommandRouter::executeOnPlugin: system , registerCallback info: Loading plugin "albumart"... info: Plugin example_plugin is not enabled info: Loading plugin "updater_comm"... info: Plugin mpdemulation is not enabled info: Loading plugin "rest_api"... info: Loading plugin "websocket"... info: Loading plugin "lastfm"... /data/plugins/miscellanea/lastfm/index.js:219 else if (state.status == 'pause') ^^^^ SyntaxError: Unexpected token else at createScript (vm.js:56:10) at Object.runInThisContext (vm.js:97:10) at Module._compile (module.js:542:28) at Object.Module._extensions..js (module.js:579:10) at Module.load (module.js:487:32) at tryModuleLoad (module.js:446:12) at Function.Module._load (module.js:438:3) at Module.require (module.js:497:17) at require (internal/module.js:20:19) at PluginManager.loadPlugin (/volumio/app/pluginmanager.js:117:25) at /volumio/app/pluginmanager.js:218:30 at Array.forEach (native) at HashMap. (/volumio/app/pluginmanager.js:217:17) at HashMap.forEach (/volumio/node_modules/hashmap/hashmap.js:157:10) at HashMap.proto.(anonymous function) [as forEach] (/volumio/node_modules/hashmap/hashmap.js:169:7) at PluginManager.loadPlugins (/volumio/app/pluginmanager.js:215:17) volumio@volumio:~$

Saiyato commented 6 years ago

This does indicate some sort of corruption, but I can't reproduce it. You did download the zipfile from the code section on Github right?

webodan commented 6 years ago

Yeah man, right from there. Tried different SD cards as well. It only seems to happen with this.

If it can be of use I could upload one of the failing sd card images to google drive so you could test it. I'm as weirded out as you are.

Saiyato commented 6 years ago

That might help yes, I've just successfully installed the plugin by using 'search plugin', my PR got merged yesterday. Works as designed, so I'm flat out of ideas.

webodan commented 6 years ago

I just tried to install the scrobbler plugin using the search plugin function and it does install, but the settings (api key secret username and password fields) will not get saved (they stay blank). At least we got one step further I guess

Should I send you a sd card dump with this to tinker with?

Saiyato commented 6 years ago

Yes please, did you by any chance play with the directories and their settings? Also, if you are prepping the image, remove all passwords etc ;)

marctruston commented 6 years ago

My Plugin worked great, but today, after a new volumio setup, configuration didn't save anything at all. I didn't read the whole thread, but it sounded kind of simillar. I looked up the new empty config file /data/configuration/miscellanea/lastfm/config.json in the file was a comma missing after the webradioscrobblethreshold bracket ... added that and now it works fine. maybe it helps.

Saiyato commented 6 years ago

I see yes! Sorry, added it to PR151 to be merged into Volumio

webodan commented 6 years ago

Hey man, you can close this.

I found out what the problem was: it was in the firmware of the pi! i was using a firmware based in 4.9.65+ that I had installed after experiencing some issues running rpi-update and I guess i broke it this way, because after upgrading today again to the current 4.14.31, and then reinstalling volumio from scratch, it scrobbles just fine!

Saiyato commented 6 years ago

Awesome, glad it worked out for you.