QNAP-459 (x86) node.js installed but error states node.js unavailable

[jwalterclark]

I've tried the stable the and the developer branch of the plug-in on my x86 based NAS, but it always shows this error.

[ERROR] JavaScript runtime is not available, try installing node.js (http://nodejs.org)

I have Spotify Premium. Here is the log from a fresh install of the developer branch.

2015-02-15 10:32:47,631 (-d82b470) :  DEBUG (runtime:717) - Handling request GET /:/plugins/com.plexapp.plugins.spotify2/prefs
2015-02-15 10:32:47,636 (-d82b470) :  DEBUG (runtime:49) - Received packed state data (80 bytes)
2015-02-15 10:32:47,642 (-d82b470) :  DEBUG (runtime:814) - Found route matching /:/plugins/com.plexapp.plugins.spotify2/prefs
2015-02-15 10:32:47,660 (-d82b470) :  DEBUG (runtime:106) - Sending packed state data (109 bytes)
2015-02-15 10:32:47,661 (-d82b470) :  DEBUG (runtime:918) - Response: [200] MediaContainer, 1167 bytes
2015-02-15 10:32:58,517 (-d82b470) :  DEBUG (runtime:717) - Handling request GET /:/plugins/com.plexapp.plugins.spotify2/prefs/set?username=[REDACTED]&password=[REDACTED]
2015-02-15 10:32:58,522 (-d82b470) :  DEBUG (runtime:49) - Received packed state data (80 bytes)
2015-02-15 10:32:58,528 (-d82b470) :  DEBUG (runtime:814) - Found route matching /:/plugins/com.plexapp.plugins.spotify2/prefs/set
2015-02-15 10:32:58,531 (-d82b470) :  DEBUG (preferences:198) - Saved the user preferences
2015-02-15 10:32:58,533 (-d82b470) :  DEBUG (__init__:24) - plugin_callback - method: <unbound method SpotifyHost.preferences_updated>, kwargs: None, async: False
2015-02-15 10:32:58,534 (-d82b470) :  DEBUG (logging_handler:26) - ['cherrypy.error', 'plugin.profiles', 'spotify2.direct', 'ws4py', 'cherrypy.wsgiserver', 'plugin.stream', 'spotify.objects.base', 'spotify2.migrator', 'cerealizer', 'spotify.components.metadata', 'concurrent.futures', 'spotify', 'cherrypy', 'com.plexapp.plugins.spotify2', 'cherrypy.access.146221388', 'spotify.commands', 'cherrypy.wsgiserver.wsgiserver2', 'spotify.components', 'spotify.commands.work', 'spotify.components.connection', 'spotify.core.search_request', 'com.plexapp', 'spotify.client', 'com.plexapp.plugins', 'cherrypy.access', 'requests.packages.urllib3.poolmanager', 'pyemitter', 'spotify.core.search_response', 'spotify.objects.album', 'requests.packages.urllib3.connectionpool', 'spotify.mercury', 'spotify2', 'spotify.commands.flash', 'spotify.tunigo', 'spotify.components.authentication', 'spotify.objects.playlist', 'plugin.track', 'requests.packages.urllib3', 'concurrent', 'cherrypy.error.146221388', 'spotify.objects', 'spotify.objects.album_group', 'requests', 'spotify.mercury.request', 'requests.packages.urllib3.response', 'spotify.objects.track', 'plugin', 'spotify.objects.parser', 'requests.packages', 'spotify.core.request', 'spotify.core', 'spotify.objects.restriction', 'spotify.hermes', 'spotify.hermes.cache', 'plugin.server', 'spotify.commands.manager', 'spotify.components.base', 'spotify.tunigo.request', 'com', 'plugin.util', 'requests_futures']
2015-02-15 10:32:58,537 (-d82b470) :  DEBUG (logging_handler:31) - {'pyemitter': 20, 'plugin': 20}
2015-02-15 10:32:58,539 (-d82b470) :  DEBUG (logging_handler:40) - Piping events from "spotify2" to plex (level: DEBUG)
2015-02-15 10:32:58,541 (-d82b470) :  DEBUG (logging_handler:40) - Piping events from "cherrypy" to plex (level: DEBUG)
2015-02-15 10:32:58,542 (-d82b470) :  DEBUG (logging_handler:40) - Piping events from "plugin" to plex (level: INFO)
2015-02-15 10:32:58,544 (-d82b470) :  DEBUG (logging_handler:40) - Piping events from "pyemitter" to plex (level: INFO)
2015-02-15 10:32:58,545 (-d82b470) :  DEBUG (logging_handler:40) - Piping events from "requests" to plex (level: DEBUG)
2015-02-15 10:32:58,547 (-d82b470) :  DEBUG (logging_handler:40) - Piping events from "spotify" to plex (level: DEBUG)
2015-02-15 10:32:58,550 (-d82b470) :  DEBUG (host:114) - bundle_path: "/root/Library/Plex Media Server/Plug-ins/Spotify2.bundle/Contents"
2015-02-15 10:32:58,561 (-d82b470) :  DEBUG (runtime:106) - Sending packed state data (109 bytes)
2015-02-15 10:32:58,565 (-d82b470) :  DEBUG (runtime:918) - Response: [200] str, 0 bytes
2015-02-15 10:32:58,571 (-b382470) :  INFO (logging_handler:22) - [requests.packages.urllib3.connectionpool] Starting new HTTPS connection (1): play.spotify.com
2015-02-15 10:32:59,105 (-b382470) :  DEBUG (logging_handler:22) - [requests.packages.urllib3.connectionpool] "GET / HTTP/1.1" 200 10378
2015-02-15 10:32:59,114 (-b382470) :  DEBUG (logging_handler:22) - [spotify.components.authentication] Landing - success, code: 200, content-type: text/html
2015-02-15 10:32:59,120 (-b382470) :  DEBUG (logging_handler:22) - [spotify.components.authentication] Landing - CSRF token: ceb8ce03a28c4acad52f58df5ccab98f, tracking ID: 027147c470661dff42c3dbdad3f6f983829895a9
2015-02-15 10:32:59,380 (-d82b470) :  DEBUG (logging_handler:22) - [requests.packages.urllib3.connectionpool] "POST /xhr/json/auth.php HTTP/1.1" 200 None
2015-02-15 10:32:59,387 (-d82b470) :  DEBUG (logging_handler:22) - [spotify.components.authentication] Authenticate - success, code: 200, content-type: application/json; charset=utf-8
2015-02-15 10:32:59,391 (-d82b470) :  INFO (logging_handler:22) - [spotify.client] Connecting...
2015-02-15 10:32:59,393 (-d82b470) :  DEBUG (logging_handler:22) - [spotify.client] ap resolver: {u'override': None, u'hostname': u'apresolve.spotify.com', u'site': None}
2015-02-15 10:32:59,402 (-d82b470) :  INFO (logging_handler:22) - [requests.packages.urllib3.connectionpool] Starting new HTTP connection (1): apresolve.spotify.com
2015-02-15 10:32:59,488 (-d82b470) :  DEBUG (logging_handler:22) - [requests.packages.urllib3.connectionpool] "GET /?client=24%3A0%3A0%3A62300364 HTTP/1.1" 200 None
2015-02-15 10:32:59,492 (-d82b470) :  DEBUG (logging_handler:22) - [spotify.client] ap resolver - success, code: 200, content-type: application/json; charset=utf-8
2015-02-15 10:32:59,493 (-d82b470) :  DEBUG (logging_handler:22) - [spotify.client] Selected AP at "wss://ash1-linkap-a1.ap.spotify.com:443/"
2015-02-15 10:32:59,530 (-d82b470) :  INFO (logging_handler:22) - [spotify.components.connection] Connecting to "wss://ash1-linkap-a1.ap.spotify.com:443/"
2015-02-15 10:32:59,705 (-d24f470) :  DEBUG (logging_handler:22) - [spotify.components.connection] WebSocket "open" event
2015-02-15 10:32:59,707 (-d24f470) :  DEBUG (logging_handler:22) - [spotify.components.connection] send_connect()
2015-02-15 10:32:59,709 (-d24f470) :  DEBUG (logging_handler:22) - [spotify.components.connection] send encoded: '{"args":["201","8a51e21243ec579e434e759e15581ce369a34da5","{\\"ip\\":\\"65.190.174.207\\",\\"timestamp\\":1424014377,\\"ttl\\":900,\\"useragent\\":\\"Mozilla\\\\/5.0 (Windows NT 6.3; WOW64) AppleWebKit\\\\/537.36 (KHTML, like Gecko) Chrome\\\\/41.0.2224.3 Safari\\\\/537.36\\",\\"version\\":62300364,\\"token\\":\\"NAphCkkKDVNwb3RpZnktdXNlcnMSCnN1cGVydHJhY3kaA5gBASWtv-BUMiIKCOmZsZp1qE5SEhZJkTgn5gNkjPyJG0DZ8UiY88D0ErXnEhRN7ayX1qKejAbH-bMy_kqkUKgZew\\"}"],"name":"connect","id":"0"}'
2015-02-15 10:33:01,676 (-cf61470) :  DEBUG (logging_handler:22) - [spotify.components.connection] SpotifyConnection "connect" event: {u'id': 0, u'result': u'ok'}
2015-02-15 10:33:01,678 (-cf61470) :  DEBUG (logging_handler:22) - [spotify.components.connection] connected
2015-02-15 10:33:01,685 (-d24f470) :  DEBUG (logging_handler:22) - [spotify.commands.work] got work, payload: var t2; try { var d = new Date(); t2 = ('d'[(35725129862..toString(36<<0))[0]])(); } catch(_) { t2 = 35725129862..toString(36<<0); };this.reply('' + t2);
2015-02-15 10:33:01,689 (-d24f470) :  WARNING (logging_handler:22) - [spotify.commands.manager] Error returned from command handler, disconnecting...
2015-02-15 10:33:01,701 (-d24f470) :  ERROR (client:48) - JavaScript runtime is not available, try installing node.js (http://nodejs.org)
2015-02-15 10:33:01,704 (-b382470) :  INFO (logging_handler:22) - [requests.packages.urllib3.connectionpool] Starting new HTTP connection (1): spflash.herokuapp.com
2015-02-15 10:33:01,723 (-db19470) :  INFO (logging_handler:22) - [spotify.components.connection] Spotify connection closed
2015-02-15 10:33:01,725 (-db19470) :  DEBUG (logging_handler:22) - [spotify.components.connection] Client requested disconnect, ignoring "close" event
2015-02-15 10:33:02,094 (-b382470) :  DEBUG (logging_handler:22) - [requests.packages.urllib3.connectionpool] "GET /4591ef9/get?ping=139%20240%2073%2040%20197%20114%20207%20162%20215%20230%20255%20239%20101%20110%20247%2050%20213%2087%20158%20173 HTTP/1.1" 200 31
2015-02-15 10:33:10,297 (-c0bb470) :  DEBUG (runtime:717) - Handling request GET /music/spotify
2015-02-15 10:33:10,303 (-c0bb470) :  DEBUG (runtime:49) - Received packed state data (80 bytes)
2015-02-15 10:33:10,309 (-c0bb470) :  DEBUG (runtime:814) - Found route matching /music/spotify
2015-02-15 10:33:10,310 (-c0bb470) :  DEBUG (__init__:24) - plugin_callback - method: <unbound method SpotifyHost.main_menu>, kwargs: {}, async: False
2015-02-15 10:33:10,314 (-c0bb470) :  DEBUG (base:125) - Checking if com.plexapp.plugins.spotify2 is broken
2015-02-15 10:33:10,317 (-c0bb470) :  DEBUG (networking:172) - Requesting 'http://127.0.0.1:32400/:/plugins/com.plexapp.system/messaging/function/X1N0b3JlU2VydmljZTpJc0NoYW5uZWxCcm9rZW4_/Y2VyZWFsMQoxCmxpc3QKMApyMAo_/Y2VyZWFsMQoxCmRpY3QKMQpzMjgKY29tLnBsZXhhcHAucGx1Z2lucy5zcG90aWZ5MnMxMAppZGVudGlmaWVycjAK'
2015-02-15 10:33:10,392 (-c0bb470) :  DEBUG (runtime:106) - Sending packed state data (109 bytes)
2015-02-15 10:33:10,393 (-c0bb470) :  DEBUG (runtime:918) - Response: [200] MediaContainer, 1465 bytes
2015-02-15 10:33:10,426 (-c0bb470) :  DEBUG (runtime:717) - Handling request GET /music/spotify/messages
2015-02-15 10:33:10,431 (-c0bb470) :  DEBUG (runtime:49) - Received packed state data (80 bytes)
2015-02-15 10:33:10,437 (-c0bb470) :  DEBUG (runtime:814) - Found route matching /music/spotify/messages
2015-02-15 10:33:10,438 (-c0bb470) :  DEBUG (__init__:24) - plugin_callback - method: <unbound method SpotifyHost.messages>, kwargs: {}, async: False
2015-02-15 10:33:10,446 (-c0bb470) :  DEBUG (runtime:106) - Sending packed state data (109 bytes)
2015-02-15 10:33:10,447 (-c0bb470) :  DEBUG (runtime:918) - Response: [200] MediaContainer, 569 bytes

I installed node.js from the QNAP package store.

[/] # node --version v0.8.22

Here is node's location.

[/share/MD0_DATA/.qpkg/nodejs] # ll drwxrwxrw- 4 admin administ 4.0k Feb 15 10:02 ./ drwxrwxrwx 13 admin administ 4.0k Feb 15 10:04 ../ -rw-r--r-- 1 admin administ 118.4k Feb 15 10:02 .list -rw-r--r-- 1 admin administ 844 Mar 26 2013 .qpkg_icon.gif -rw-r--r-- 1 admin administ 1.3k Mar 26 2013 .qpkg_icon_80.gif -rw-r--r-- 1 admin administ 1.0k Mar 26 2013 .qpkg_icon_gray.gif -rwxr-xr-x 1 admin administ 774 Feb 15 10:02 .uninstall.sh drwxr-xr-x 6 admin administ 4.0k Mar 26 2013 node/ drwxr-xr-x 6 admin administ 4.0k Mar 26 2013 node_arm/ -rwxr-xr-x 1 admin administ 695 Mar 26 2013 nodejs.sh

This seems to be a similar issue to issue #30. That's why I switched to the developer branch but it doesn't seem to resolve the issue.

Thank you.

[mike-pt]

Same issue with FreeBSD as a server, maybe it as something to do with where/how node.js is installed?

[NickBolles]

same here on FreeNaS.

where node
/usr/local/bin/node
/usr/local/bin/node

is it possible its because its in /usr/local and not /bin? still running node --version (mine is v0.12.4) returns the version so the path must be correct (Path is a huge issue with node/npm on windows)

Edit: Here are my logs https://gist.github.com/sup3rb0wlz/deeca00f3afe3abca0bc#file-com-plexapp-plugins-spotify2-log

[NickBolles]

My issue was fixed by following these pretty simple instructions https://forums.plex.tv/index.php/topic/87744-install-spotify/page-5#entry788842

Just removing and re-adding, but restarting plex in between each step

[jhunterjackson]

jwalterclark - were you able to resolve this issue? I am in the same predicament. NickBolles - not sure if your fix applies, but your link from June with the instructions seems to be gone. Any help would be greatly appreciated.

[ge-ko]

Same here. QNAP NAS, Node v0.8.22 (Installed from NAS App Center), Spotify2 bundle (tried both from master and develop branches). Spotify Premium account. I get this error:

2016-01-02 13:13:30,045 (-e99c470) : ERROR (client:48) - JavaScript runtime is not available, try installing node.js (http://nodejs.org)

[d9001089]

Same here... ERROR JavaScript runtime is not available, try installing node.js (http://nodejs.org)