I just upgraded index.js and will report back soon… thanks again!
Looks like this fixed it… it sat idle overnight, timed out on the current song I had paused after the buffer ran out with an error (rightfully), and paused. Clicking play once more started the stream without issue.
Thanks!
Version 2.5.2 is available from the Plugin menu.
One additional thing I’ve noticed that is just for awareness as I don’t think it’s causing much issue. I’ve seen a message pop up that says something like “Where’s the fire? Slow down” repeatedly displayed in green when a song times out and it tried to advance passed it…
Thanks again
I put that message in there to catch someone pressing media buttons too quickly. It basically tries to enforce a small delay (can’t recall the exact delay but a fraction of a second). I just didn’t want someone to change tracks too rapidly for the Volumio interface.
I could take it out. It might not be necessary at all.
So you’re seeing this as tracks expire? I guess you’re moving the current position backward in the queue?
It’s kind of a balancing act when that happens. I toyed with just clearing the tracks in front but I wasn’t sure how users would feel. It isn’t exactly clear how long the track data remains valid. If the tracks aren’t cleared from the queue and the plugins reaches expired tracks, they just disappear, but it can be a cascade of consecutively skipped tracks.
I tried to handle that in a slower, more regular fashion.
I’ve only noticed it when I need to pause it in the middle of a song for awhile - in fact it actually just happened again while I was on the phone. When it starts back, the song plays until the buffer runs out or ends, then it goes into this loop alerting me:
“Song by Singer timed out. Advancing Track”
“Where’s the fire? Slow down!”
loop
Pushing pause, then play a few times straightens it out…
@gfisher Thanks for that. I’ll try and duplicate it here.
So to clarify: Pause track for a while, say 10-15 minutes, hit Play. it goes to the end of the buffer, the plugin tries to advance and gets stuck in a loop? Wow, I thought that was working but I haven’t tried it in a while. I haven’t really listened to Pandora in a few weeks.
that sounds right… I noticed I can turn on Dev logging. If you can’t reproduce, would it help if I did that to capture it?
Do you mean the log window in http://volumio.local/dev ? I know it will show up the in main systemd log, but you have to SSH to the machine to do that.
If you’re asking if by checking that if more debug information (from Volumio) will show up in the systemd log, that might be the case, but it won’t affect the amount of logging that my plugin produces.
Hi,
I am living outside US, how can I enjoy Pandora radio ?
Thanks
@truckershitch I updated to 2.5.2 plugin, now I see pandora on the music sources menu, but when I select it I get ‘No items’
Here is what I see in the log:
Sep 19 20:35:35 volumio volumio[901]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Sep 19 20:35:35 volumio volumio[901]: info: CoreCommandRouter::volumioPushQueue
Sep 19 20:35:39 volumio volumio[901]: info: CoreCommandRouter::volumioGetVisibleSources
Sep 19 20:35:39 volumio volumio[901]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Sep 19 20:35:45 volumio volumio[901]: info: CoreCommandRouter::executeOnPlugin: pandora , handleBrowseUri
Sep 19 20:35:45 volumio volumio[901]: info: [1600547745601] ControllerPandora::handleBrowseUri
Sep 19 20:35:54 volumio volumio[901]: error: error
Sep 19 20:36:44 volumio volumio[901]: error: error
Sep 19 20:37:34 volumio volumio[901]: error: error
Sep 19 20:37:41 volumio volumio[901]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Sep 19 20:38:12 volumio volumio[901]: info: [1600547892938] ControllerPandora::ExpireOldTracks::reaper
Sep 19 20:38:22 volumio volumio[901]: info: CoreCommandRouter::executeOnPlugin: pandora , handleBrowseUri
Sep 19 20:38:22 volumio volumio[901]: info: [1600547902933] ControllerPandora::handleBrowseUri
Sep 19 20:38:22 volumio volumio[901]: info: CorePlayQueue::getQueue
Sep 19 20:38:22 volumio volumio[901]: info: CorePlayQueue::getTrack 10
Sep 19 20:38:24 volumio volumio[901]: error: error
Sep 19 20:39:14 volumio volumio[901]: error: error
@Lintbf You will need to access Pandora from a VPN, from a server running in the USA. There are other ways but that’s probably the easiest. That’s beyond the scope of my support but you can just do a little research to figure out how to do it. There may be free ones available, I am not sure.
@Jim_Edwards I need to see more the of the log to try and figure out what is gong on.
Are you seeing a sucessful login message from Volumio? (green pop-up toast in the upper-right hand corner of the screen when the plugin starts)
First, unload the plugin (switch it off from the Plugin menu). Then turn it back on. Verify your email and password are correct and that you are receiving the green ‘Login Successful’ message when you save your settings. It could be that when Volumio is started that you aren’t seeing a bad login message.
You could also try just uninstalling the plugin and reinstalling it to be sure the slate is clean. That will wipe out the configuration file and you can try again fresh. There aren’t many settings in that file anyway, so you won’t really lose anything.
So if that fails for you, then go ahead and reboot your Volumio machine. Then get a log by connecting via SSH and running this:
journalctl -b --no-pager > volumio.log
I need to see the log from when the plugin starts to load. The plugin starts right after that and it should show an error if one occurs. What you see in the log there (I believe) is that the menu for the Pandora plugin wasn’t generated for some reason. It’s not getting a station list, and I think that’s because it can’t connect/authorize with the Pandora servers and your credentials.
I changed my password to something incorrect, the error message in that case was obvious.
I changed it back and rebooted the system and collected the log as you suggested, but the forum won’t let me add it as an attachment.
Here is a link to the file in google drive. volumio.log
So here’s what I get from grep -i pandora volumio.log
(and it looks like the plugin does a few things more than once – I’ll have to look at it again):
Sep 19 22:42:59 volumio volumio[1018]: info: Loading plugin "pandora"...
Sep 19 22:42:59 volumio volumio[1018]: info: Applying required configuration parameters for plugin pandora
Sep 19 22:42:59 volumio volumio[1018]: info: PLUGIN START: pandora
Sep 19 22:42:59 volumio volumio[1018]: info: [1600555379772] ControllerPandora::checkConfValidity
Sep 19 22:42:59 volumio volumio[1018]: info: [1600555379773] ControllerPandora::initialSetup
Sep 19 22:42:59 volumio volumio[1018]: info: [1600555379774] ControllerPandora::PandoraHandler::init
Sep 19 22:42:59 volumio volumio[1018]: info: [1600555379774] ControllerPandora::PreventAuthTimeout
Sep 19 22:42:59 volumio volumio[1018]: info: [1600555379774] ControllerPandora::PandoraHandler::pandoraLoginAndGetStations
Sep 19 22:42:59 volumio volumio[1018]: info: [1600555379778] ControllerPandora::flushPandora
Sep 19 22:42:59 volumio volumio[1018]: info: [1600555379787] CoreMusicLibrary::Adding element Pandora Radio
Sep 19 22:43:00 volumio volumio[1018]: info: [1600555380876] [Pandora] Logged in
Sep 19 22:43:01 volumio volumio[1018]: info: [1600555381354] ControllerPandora::PandoraHandler::fillStationData
Sep 19 22:43:01 volumio volumio[1018]: info: [1600555381354] [Pandora] PreventAuthTimeout: Refreshed Pandora authorization
Sep 19 22:44:09 volumio volumio[30353]: info: Loading plugin "pandora"...
Sep 19 22:44:10 volumio volumio[30353]: info: Applying required configuration parameters for plugin pandora
Sep 19 22:44:10 volumio volumio[30353]: info: [1600555450885] ControllerPandora::checkConfValidity
Sep 19 22:44:16 volumio volumio[30353]: info: [1600555456478] ControllerPandora::initialSetup
Sep 19 22:44:16 volumio volumio[30353]: info: [1600555456482] ControllerPandora::PandoraHandler::init
Sep 19 22:44:16 volumio volumio[30353]: info: [1600555456487] ControllerPandora::PreventAuthTimeout
Sep 19 22:44:16 volumio volumio[30353]: info: [1600555456488] ControllerPandora::PandoraHandler::pandoraLoginAndGetStations
Sep 19 22:44:16 volumio volumio[30353]: info: [1600555456509] ControllerPandora::flushPandora
Sep 19 22:44:16 volumio volumio[30353]: info: [1600555456560] CoreMusicLibrary::Adding element Pandora Radio
Sep 19 22:44:18 volumio volumio[30353]: info: [1600555458253] [Pandora] Logged in
Sep 19 22:44:18 volumio volumio[30353]: info: [1600555458732] ControllerPandora::PandoraHandler::fillStationData
Sep 19 22:44:18 volumio volumio[30353]: info: [1600555458733] [Pandora] PreventAuthTimeout: Refreshed Pandora authorization
I got your original message in my email. It appears that the login isn’t occurring (as I said, when it does, you should get a green ‘Pandora Login Successful’ message). I’m waiting to gain access approval to the file you posted to try and figure it out.
You might want to uninstall and reinstall the plugin from the Volumio Plugins menu. If you tried to just replace index.js as I suggested, maybe I gave out bad advice. Best to make sure that you have the latest source, although the previous version was working for me just fine before. Using the menu should nuke it and put things the way they are on my machine.
By the way, what machine are you running this on? I think the plugin should work on just about any Volumio machine since it’s all in node.js (Javascript) but you never know. I’m on a Pi 3B+ here.
I’m not super-familiar with the way that Volumio starts up, but the following lines seem indicative of a network problem:
Sep 19 22:08:30 volumio networking[403]: Configuring network interfaces.../etc/network/interfaces:9: misplaced option
Sep 19 22:08:30 volumio networking[403]: ifquery: couldn't read interfaces file "/etc/network/interfaces"
Sep 19 22:08:30 volumio networking[403]: /etc/network/interfaces:9: misplaced option
Sep 19 22:08:30 volumio networking[403]: ifquery: couldn't read interfaces file "/etc/network/interfaces"
Sep 19 22:08:30 volumio networking[403]: /etc/network/interfaces:9: misplaced option
Sep 19 22:08:30 volumio networking[403]: ifup: couldn't read interfaces file "/etc/network/interfaces"
Sep 19 22:08:30 volumio networking[403]: failed.
Further down, there is a DNS issue trying to resolve NTP servers:
Sep 19 22:08:37 volumio ntpd_intres[696]: host name not found: 1.debian.pool.ntp.org
Sep 19 22:08:37 volumio ntpd_intres[696]: host name not found: 2.debian.pool.ntp.org
Sep 19 22:08:37 volumio ntpd_intres[696]: host name not found: 3.debian.pool.ntp.org
Then this occurs:
Sep 19 22:08:40 volumio dhcpcd[512]: dhcpcd[595]: wlan0: offered 192.168.10.48 from 192.168.10.1
Sep 19 22:08:40 volumio dhcpcd[595]: wlan0: leased 192.168.10.48 for 86400 seconds
Sep 19 22:08:40 volumio avahi-daemon[513]: Joining mDNS multicast group on interface wlan0.IPv4 with address 192.168.10.48.
Sep 19 22:08:40 volumio dhcpcd[512]: dhcpcd[595]: wlan0: leased 192.168.10.48 for 86400 seconds
Sep 19 22:08:40 volumio avahi-daemon[513]: New relevant interface wlan0.IPv4 for mDNS.
Sep 19 22:08:40 volumio dhcpcd[595]: wlan0: adding host route to 192.168.10.48 via 127.0.0.1
Sep 19 22:08:40 volumio avahi-daemon[513]: Registering new address record for 192.168.10.48 on wlan0.IPv4.
Sep 19 22:08:40 volumio dhcpcd[595]: wlan0: adding route to 192.168.10.0/24
Sep 19 22:08:40 volumio dhcpcd[595]: wlan0: adding default route via 192.168.10.1
Sep 19 22:08:40 volumio dhcpcd[512]: dhcpcd[595]: wlan0: adding host route to 192.168.10.48 via 127.0.0.1
Sep 19 22:08:40 volumio dhcpcd[512]: dhcpcd[595]: wlan0: adding route to 192.168.10.0/24
Sep 19 22:08:40 volumio dhcpcd[512]: dhcpcd[595]: wlan0: adding default route via 192.168.10.1
Sep 19 22:08:40 volumio dhcpcd[512]: dhcpcd[595]: forked to background, child pid 871
Sep 19 22:08:40 volumio dhcpcd[595]: forked to background, child pid 871
Sep 19 22:08:40 volumio systemd[1]: Started LSB: IPv4 DHCP client with IPv4LL support.
Sep 19 22:08:41 volumio wireless.js[649]: trying...
Sep 19 22:08:41 volumio sudo[873]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwgetid -r
Sep 19 22:08:41 volumio sudo[873]: pam_unix(sudo:session): session opened for user root by (uid=0)
Sep 19 22:08:41 volumio sudo[873]: pam_unix(sudo:session): session closed for user root
Sep 19 22:08:41 volumio wireless.js[649]: Connected to: ----network3583
Sep 19 22:08:41 volumio wireless.js[649]: ----
Sep 19 22:08:41 volumio sudo[882]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Sep 19 22:08:41 volumio sudo[882]: pam_unix(sudo:session): session opened for user root by (uid=0)
Sep 19 22:08:41 volumio sudo[882]: pam_unix(sudo:session): session closed for user root
Sep 19 22:08:41 volumio wireless.js[649]: ... joined AP, wlan0 IPv4 is 192.168.10.48, ipV6 is undefined
Sep 19 22:08:41 volumio wireless.js[649]: It's done! AP
which makes me suspect there was some kind of recovery. It seems odd to me.
Also, it looks like this part occurs twice:
Sep 19 22:08:41 volumio volumio-streaming-daemon[892]: ############################
Sep 19 22:08:41 volumio volumio-streaming-daemon[892]: # Volumio Streaming Daemon #
Sep 19 22:08:41 volumio volumio-streaming-daemon[892]: # Running on port 7777 #
Sep 19 22:08:41 volumio volumio-streaming-daemon[892]: ############################
Sep 19 22:08:41 volumio volumio-streaming-daemon[892]: Environment: production
and
Sep 19 22:09:34 volumio volumio-streaming-daemon[1119]: ############################
Sep 19 22:09:34 volumio volumio-streaming-daemon[1119]: # Volumio Streaming Daemon #
Sep 19 22:09:34 volumio volumio-streaming-daemon[1119]: # Running on port 7777 #
Sep 19 22:09:34 volumio volumio-streaming-daemon[1119]: ############################
Sep 19 22:09:34 volumio volumio-streaming-daemon[1119]: Environment: production
I’m not a Volumio expert but something seems wrong to me. It looks like Spotify connected in your log, however.
As a sanity check, can you try to play something innocuous, like Web Radio from the main menu? Any stream would do. Also, just try ping google.com or maybe ping pandora.com for a small connectivity test.
Maybe the fastest thing to do, if you have a spare microSD card lying around, is just to flash the latest stable image to it and see if that works.
I don’t think this applies, but try connecting with the Ethernet port also.
It could be that those network errors were occurring before Volumio took over… I’m really not sure. Definitely take a look at /etc/network/interfaces as that threw an error for some reason.
The /etc/network/interfaces file has been that way for a while and pandora was working prior to 9/16. All of the other plugins work fine including spotify and webradio. Only pandora is being a problem.
volumio@volumio:~$ ping pandora.com
PING (208.85.40.20) 56(84) bytes of data.
64 bytes from www.pandora.com (208.85.40.20): icmp_seq=1 ttl=245 time=48.7 ms
@Jim_Edwards
I’m not sure what’s going on in your case. It appears that there is an error logging in but my code isn’t catching the exception. No one else has chimed in with a ‘me too’ message here in the forum (and if someone is lurking out there, go ahead and let us know!)
Either Pandora is accepting your credentials and failing to get a viable station list, or the server is rejecting your credentials for some reason. And the error is just being walked over – that can happen if my code didn’t anticipate an error. One thing I can think of, and this is kind of a long shot, is that one of your Pandora stations is not being parsed from bad quoting, a Japanese character, or something of that nature. But I’m not sure.
To rule that last one out, you could create a dummy Pandora account. That’s pretty easy to do.
If you’re feeling adventurous, you might try the example code for the anesidora npm module. There is a small chunk of code that tests basic functionality and it runs in your browser. Check that out: https://npm.runkit.com/anesidora
The thing is, that web site will just narrow down that it works from a virtual environment. If you have the knack, you might consider using that snippet in an index.js file locally on your Raspberry Pi. That would be a better test case.
I can produce something like this, but I can’t do it today – I have a bit of a busy afternoon.
I did a fresh SD card with a new install of volumio, same problem. I prepended the log to
same file: volumio.log
@Jim_Edwards
The log you posted still points to a Pandora login failure. It turns out that there was a bug in my error handing routine, but a problem with the plugin would not have occurred unless something went wrong. Your Pandora stations were never downloaded.
The code should now display an error message on a login failure instead of just skipping by. There should be an error toast message in red now when there is a failure and a message sent to the log.
I just pushed the commit to GitHub. You can just swap out the index.js if you like or you can clone my fork and install as described in Readme.md. The link is in the first post of this thread.
Everyone else: The only change made is to the error trapping routine. You can grab it if you want but I made no other changes, and as long as the plugin is working for you, there is no immediate need to upgrade. I want to take another look at the plugin initialization before I file a pull request to merge this with master.
And the error is
error: [1600782189925] [Pandora] Other Login Error [1010] See https://6xq.net/pandora-apidoc/json/errorcodes/
1010 PARTNER_NOT_AUTHORIZED
this is all the info I can find, any idea how to resolve?
It appears to be in the pandora-one flag. If I deactivate it, pandora works.
From the subscription page:
Current Plan: Pandora Premium