Music no longer playing after most recent Tidal update.
Player Opens
Can log in ok
Have reinstalled
Can browse library
Can click play/pause, can skip ahead on the track
Web browser playing works fine
Plexamp is simply not generating any audio or otherwise behaving like it’s playing.
Server status shows the connection and the current track, but plexamp never actually plays anything.
This started after the most recent update that added Tidal support.
Should be noted this appears to possibly be network related. Plexamp works at home within my network, but not at work.
However:
Were new port requirements added in this plexamp release? Does it fail if it can’t reach Tidal? The web version of Plex works fine, and connects directly.
There should be any new network or port requirements 
If you can browse, then it shouldn’t be a network issue. The server.log file as well as the mpd.log (maybe in /tmp) would be useful in diagnosing.
Thank you for your reply! I found the server.log location with lots of info, though I would want to sanitize it a bit, lots of machine names and IPs and such. It has a few hours of stuff while I horsed around with reinstalling and such.
Let me do some deliberate testing from the office tomorrow morning so the logged events are clear and I will update this thread, thank you for your help!
OK below are the contents from today in application.log and server.log If you’d like other logs please let me know where I can find them on a win10 machine - thanks!
I’ve redacted some IPs and machine names if they have my name in them. For reference I’m running Plex Media Server on a server 2016 box at home (called HOMESERVER after redaction, on internal and public port 21, connecting from work office on WORKLAPTOP.
A note here - I’m seeing entries in the logs here where my PlexAmp is trying to connect to coworker laptops, presumably because they too use Plex - This is less desirable, so it would be great if now or in the near future we could disable PlexAmp’s casting about looking for other things to-which to connect.
Otherwise I’ll list out private IPs here for comparison:
192.168.1.2 - Private IP of Plex Media Server
192.168.1.103 - Private IP assigned via DHCP reservation to my worklaptop when I work from home
application.log
Dec 07, 2018 09:11:40.180 INFO - Starting app…
Dec 07, 2018 09:11:42.481 DEBUG - Window bounds is 119 x 397.
Dec 07, 2018 09:11:42.491 INFO - Adding key mapping: MediaNextTrack -> next
Dec 07, 2018 09:11:42.494 INFO - Adding key mapping: MediaPlayPause -> playpause
Dec 07, 2018 09:11:42.494 INFO - Adding key mapping: MediaPreviousTrack -> previous
Dec 07, 2018 09:11:42.494 INFO - Adding key mapping: Shift+CommandOrControl+Space -> activate
Dec 07, 2018 09:11:42.495 INFO - Adding key mapping: Shift+Command+Control+Option+0 -> unrate
Dec 07, 2018 09:11:42.495 INFO - Adding key mapping: Shift+Command+Control+Option+1 -> rate1
Dec 07, 2018 09:11:42.495 INFO - Adding key mapping: Shift+Command+Control+Option+2 -> rate2
Dec 07, 2018 09:11:42.495 INFO - Adding key mapping: Shift+Command+Control+Option+3 -> rate3
Dec 07, 2018 09:11:42.495 INFO - Adding key mapping: Shift+Command+Control+Option+4 -> rate4
Dec 07, 2018 09:11:42.495 INFO - Adding key mapping: Shift+Command+Control+Option+5 -> rate5
Dec 07, 2018 09:11:42.496 INFO - Adding key mapping: Shift+CommandOrControl+Option+Right -> nextalbum
Dec 07, 2018 09:11:42.497 INFO - Adding key mapping: CommandOrControl+Option+Up -> volumeup
Dec 07, 2018 09:11:42.497 INFO - Adding key mapping: CommandOrControl+Option+Down -> volumedown
Dec 07, 2018 09:11:42.498 DEBUG - UPDATES: Using latest channel.
Dec 07, 2018 09:11:42.567 INFO - Checking for update
Dec 07, 2018 09:11:44.620 INFO - METRICS: Initializing.
Dec 07, 2018 09:11:45.130 INFO - Update for version 1.1.0 is not available (latest version: 1.1.0, downgrade is disallowed.
Dec 07, 2018 09:11:45.130 DEBUG - Autoupdate: Update is not available.
Dec 07, 2018 09:11:45.238 INFO - ACCOUNT: Refreshing data.
Dec 07, 2018 09:11:45.239 INFO - DEVICE: Initializing manager.
Dec 07, 2018 09:11:45.240 INFO - DEVICE: Fetching latest provider list from cloud.
Dec 07, 2018 09:11:45.241 INFO - DEVICE: Fetching latest list from cloud.
Dec 07, 2018 09:11:45.241 INFO - DEVICE: Starting connection test.
Dec 07, 2018 09:11:45.241 INFO - DEVICE: Finding best connection for Rhoserver
Dec 07, 2018 09:11:45.242 INFO - HTTP: Issuing request to https://127.0.0.1:32400/
Dec 07, 2018 09:11:45.242 INFO - HTTP: Issuing request to https://192.168.1.2:32400/
Dec 07, 2018 09:11:45.243 INFO - HTTP: Issuing request to https://PUBLIC_IP_OF_SERVER:21/
Dec 07, 2018 09:11:45.259 INFO - WebGL: Creating renderer.
Dec 07, 2018 09:11:45.261 INFO - THREE.WebGLRenderer 88
Dec 07, 2018 09:11:45.301 INFO - WebGL: Setting renderer up for Retrospect
Dec 07, 2018 09:11:45.302 INFO - setting: [object Object]
Dec 07, 2018 09:11:45.305 INFO - WebGL: Updating palette texture.
Dec 07, 2018 09:11:45.306 INFO - Crossfade will last for 18 frames.
Dec 07, 2018 09:11:45.307 INFO - WebGL: Initializing program Retrospect
Dec 07, 2018 09:11:45.362 WARN - THREE.WebGLProgram: gl.getProgramInfoLog()
C:\fakepath(114,1): warning X4000: use of potentially uninitialized variable (_webgl_19dff938713edbff)
Dec 07, 2018 09:11:45.366 INFO - WebGL: Completed initialization.
Dec 07, 2018 09:11:45.564 INFO - PLAYER: Play queue changed to 1811, refreshing.
Dec 07, 2018 09:11:45.565 INFO - HTTP: Issuing request to https://192.168.1.2:32400/playQueues/1811?window=30
Dec 07, 2018 09:11:45.565 INFO - PLAYER: Loading data on-the-fly for current track (PQID 30601), was not cached.
Dec 07, 2018 09:11:45.565 INFO - HTTP: Issuing request to https://192.168.1.2:32400/library/streams/1589275/levels?subsample=128
Dec 07, 2018 09:11:45.582 INFO - POWER: Disabling power save mode.
Dec 07, 2018 09:11:45.658 INFO - DEVICE: Server connection worked for HOMESERVER ~ https://PUBLIC_IP_OF_SERVER:21
Dec 07, 2018 09:11:45.659 INFO - HTTP: Issuing request to https://PUBLIC_IP_OF_SERVER:21/media/providers
Dec 07, 2018 09:11:45.772 INFO - IMAGE: Average brightness: 0.07699548100490206.
Dec 07, 2018 09:11:45.831 INFO - #040c4b,#5e5732,#946116,#907c58
Dec 07, 2018 09:11:45.832 INFO - IMAGE: Top luminosity range is 0.061459604990032474, min luminosity is 0.14903215460253266
Dec 07, 2018 09:11:45.832 INFO - IMAGE: Expanding by lightening.
Dec 07, 2018 09:11:45.843 INFO - DEVICE: Fast-path connection testing.
Dec 07, 2018 09:11:45.844 INFO - DEVICE: Finding best connection for Pixel 2
Dec 07, 2018 09:11:45.844 INFO - HTTP: Issuing request to http://192.168.1.124:32500/resources
Dec 07, 2018 09:11:45.844 INFO - DEVICE: Finding best connection for WORKLAPTOP
Dec 07, 2018 09:11:45.844 INFO - HTTP: Issuing request to http://PRIVATE_IP_OF_WORK_LAPTOP:36000/resources
Dec 07, 2018 09:11:45.845 INFO - DEVICE: Finding best connection for TIDAL
Dec 07, 2018 09:11:45.845 INFO - DEVICE: Skipping actual connection testing for TIDAL.
Dec 07, 2018 09:11:45.845 INFO - DEVICE: Finding best connection for Podcasts
Dec 07, 2018 09:11:45.845 INFO - DEVICE: Skipping actual connection testing for Podcasts.
Dec 07, 2018 09:11:45.845 INFO - DEVICE: Finding best connection for WORK_LAPTOP
Dec 07, 2018 09:11:45.846 INFO - HTTP: Issuing request to http://PRIVATE_IP_LAPTOP_OF_COWORKER:36000/resources
Dec 07, 2018 09:11:45.847 INFO - HTTP: Issuing request to http://192.168.1.103:36000/resources
Dec 07, 2018 09:11:45.847 INFO - DEVICE: Persisting devices.
Dec 07, 2018 09:11:45.850 INFO - DEVICE: Initialization finished in 611ms.
Dec 07, 2018 09:11:45.861 INFO - APP: Refreshing player/server menu.
Dec 07, 2018 09:11:45.867 INFO - DEVICE: Reading libraries and features from TIDAL
Dec 07, 2018 09:11:45.867 INFO - HTTP: Issuing request to https://music.provider.plex.tv/
Dec 07, 2018 09:11:45.869 INFO - DEVICE: Reading libraries and features from Podcasts
Dec 07, 2018 09:11:45.869 INFO - HTTP: Issuing request to https://podcasts.provider.plex.tv/
Dec 07, 2018 09:11:45.979 INFO - METRICS: Saving latest cloud settings for metrics.
Dec 07, 2018 09:11:46.042 INFO - DEVICE: Fetched 6 devices from the cloud.
Dec 07, 2018 09:11:46.430 WARN - DEVICE: Server connection https://127.0.0.1:32400 didn’t work for Rhoserver: connect ECONNREFUSED 127.0.0.1:32400
Dec 07, 2018 09:11:46.896 WARN - DEVICE: Player connection http://PRIVATE_IP_LAPTOP_OF_COWORKER:36000 didn’t work for WORK_LAPTOP: connect ECONNREFUSED PRIVATE_IP_LAPTOP_OF_COWORKER:36000
Dec 07, 2018 09:11:49.729 INFO - HTTP: Issuing request to https://PUBLIC_IP_OF_SERVER:21/hubs/sections/3?count=4&includeExternalMetadata=1&includeLibraryPlaylists=1&includeStations=1&excludeFields=summary
Dec 07, 2018 09:11:50.392 WARN - DEVICE: Server connection https://192.168.1.2:32400 didn’t work for Rhoserver: timeout of 5000ms exceeded
Dec 07, 2018 09:11:50.850 WARN - DEVICE: Player connection http://192.168.1.124:32500 didn’t work for Pixel 2: timeout of 5000ms exceeded
Dec 07, 2018 09:11:50.850 WARN - DEVICE: Connection testing failed for Pixel 2
Dec 07, 2018 09:11:50.850 WARN - DEVICE: Player connection http://PRIVATE_IP_OF_WORK_LAPTOP:36000 didn’t work for WORK_LAPTOP: timeout of 5000ms exceeded
Dec 07, 2018 09:11:50.851 WARN - DEVICE: Connection testing failed for WORK_LAPTOP
Dec 07, 2018 09:11:50.851 WARN - DEVICE: Player connection http://192.168.1.103:36000 didn’t work for WORK_LAPTOP: timeout of 5000ms exceeded
Dec 07, 2018 09:11:50.851 WARN - DEVICE: Connection testing failed for WORK_LAPTOP
Dec 07, 2018 09:11:50.851 INFO - APP: Refreshing player/server menu.
Dec 07, 2018 09:11:53.341 INFO - PLAYER: Issing play to player undefined for music from server c4856e96efe07e6b137425e269b4848f7229c80b
Dec 07, 2018 09:11:53.346 INFO - Requesting /player/playback/createPlayQueue?source=c4856e96efe07e6b137425e269b4848f7229c80b&uri=server%3A%2F%2Fc4856e96efe07e6b137425e269b4848f7229c80b%2Fcom.plexapp.plugins.library%2Flibrary%2Fmetadata%2F318568%2Fchildren&token=&state=playing&type=audio&protocol=https&address=192.168.1.2&port=32400&machineIdentifier=c4856e96efe07e6b137425e269b4848f7229c80b&commandID=4 from player Local.
Dec 07, 2018 09:11:53.346 INFO - HTTP: Issuing request to http://127.0.0.1:36000/player/playback/createPlayQueue?source=c4856e96efe07e6b137425e269b4848f7229c80b&uri=server%3A%2F%2Fc4856e96efe07e6b137425e269b4848f7229c80b%2Fcom.plexapp.plugins.library%2Flibrary%2Fmetadata%2F318568%2Fchildren&token=&state=playing&type=audio&protocol=https&address=192.168.1.2&port=32400&machineIdentifier=c4856e96efe07e6b137425e269b4848f7229c80b&commandID=4
Dec 07, 2018 09:11:53.522 INFO - METRICS: Sending event: client:click to https://analytics.plex.tv
Dec 07, 2018 09:11:53.555 WARN - PLAYER: Giving up on polling, index 2 didn’t match 1.
Dec 07, 2018 09:11:59.434 INFO - DEVICE: Persisting devices because Rhoserver was dirty.
Dec 07, 2018 09:11:59.434 INFO - DEVICE: Persisting devices.
Dec 07, 2018 09:12:02.179 INFO - HTTP: Issuing request to https://PUBLIC_IP_OF_SERVER:21/hubs/sections/3?count=4&includeExternalMetadata=1&includeLibraryPlaylists=1&includeStations=1&excludeFields=summary
Dec 07, 2018 09:12:03.419 INFO - HTTP: Issuing request to https://PUBLIC_IP_OF_SERVER:21/library/metadata/2747?includeRelated=1&includeExternalMetadata=1&includeStations=1&includePopularLeaves=1&excludeFields=summary&asyncAugmentMetadata=1&augmentCount=4
Dec 07, 2018 09:12:03.419 INFO - HTTP: Issuing request to https://PUBLIC_IP_OF_SERVER:21/library/metadata/2747/children?excludeFields=summary
Dec 07, 2018 09:12:03.578 INFO - METRICS: Sending event: client:view to https://analytics.plex.tv
Dec 07, 2018 09:12:03.615 INFO - HTTP: Issuing request to https://PUBLIC_IP_OF_SERVER:21/library/metadata/augmentations/101?wait=1
Dec 07, 2018 09:12:04.824 INFO - PLAYER: Issing play to player undefined for music from server c4856e96efe07e6b137425e269b4848f7229c80b
Dec 07, 2018 09:12:04.829 INFO - Requesting /player/playback/createPlayQueue?uri=server%3A%2F%2Fc4856e96efe07e6b137425e269b4848f7229c80b%2Fcom.plexapp.plugins.library%2Flibrary%2Fmetadata%2F2747%2Fchildren&shuffle=0&source=c4856e96efe07e6b137425e269b4848f7229c80b&token=&state=playing&type=audio&protocol=https&address=192.168.1.2&port=32400&machineIdentifier=c4856e96efe07e6b137425e269b4848f7229c80b&commandID=109 from player Local.
Dec 07, 2018 09:12:04.830 INFO - HTTP: Issuing request to http://127.0.0.1:36000/player/playback/createPlayQueue?uri=server%3A%2F%2Fc4856e96efe07e6b137425e269b4848f7229c80b%2Fcom.plexapp.plugins.library%2Flibrary%2Fmetadata%2F2747%2Fchildren&shuffle=0&source=c4856e96efe07e6b137425e269b4848f7229c80b&token=&state=playing&type=audio&protocol=https&address=192.168.1.2&port=32400&machineIdentifier=c4856e96efe07e6b137425e269b4848f7229c80b&commandID=109
Dec 07, 2018 09:12:04.962 INFO - METRICS: Sending event: client:click to https://analytics.plex.tv
Dec 07, 2018 09:12:05.056 WARN - PLAYER: Giving up on polling, index 3 didn’t match 2.
Dec 07, 2018 09:12:06.426 INFO - Error loading: https://PUBLIC_IP_OF_SERVER:21/hubs/sections/3?count=4&includeExternalMetadata=1&includeLibraryPlaylists=1&includeStations=1&excludeFields=summary: connect ETIMEDOUT 192.168.1.2:32400
Dec 07, 2018 09:12:06.426 INFO - Another new request came in, tossing data (looking for: 1, was: 3)
Dec 07, 2018 09:12:06.590 INFO - Error loading: https://PUBLIC_IP_OF_SERVER:21/library/streams/1589275/levels?subsample=128: connect ETIMEDOUT 192.168.1.2:32400
Dec 07, 2018 09:12:06.591 WARN - Error loading loudness data for track Dave Matthews Band / Space Between
Dec 07, 2018 09:12:06.591 INFO - PLAYER: Computed soundprint data for a track in 21033ms.
Dec 07, 2018 09:12:06.592 INFO - WebGL: Updating loudness texture.
Dec 07, 2018 09:12:06.595 INFO - WebGL: Updating palette texture.
Dec 07, 2018 09:12:06.595 INFO - Crossfade will last for 18 frames.
Dec 07, 2018 09:12:06.629 INFO - HTTP: Issuing request to https://PUBLIC_IP_OF_SERVER:21/playQueues/1811?window=30
Dec 07, 2018 09:12:06.634 INFO - Error loading: https://PUBLIC_IP_OF_SERVER:21/playQueues/1811?window=30: connect ETIMEDOUT 192.168.1.2:32400
Dec 07, 2018 09:12:06.766 INFO - Error loading: https://PUBLIC_IP_OF_SERVER:21/playQueues/1811?window=30: Request failed with status code 404
Dec 07, 2018 09:12:06.772 INFO - PLAYER: Play queue changed to 1822, refreshing.
Dec 07, 2018 09:12:06.772 INFO - HTTP: Issuing request to https://PUBLIC_IP_OF_SERVER:21/playQueues/1822?window=30
Dec 07, 2018 09:12:06.772 INFO - PLAYER: Loading data on-the-fly for current track (PQID 30969), was not cached.
Dec 07, 2018 09:12:06.774 INFO - HTTP: Issuing request to https://PUBLIC_IP_OF_SERVER:21/library/streams/1659555/levels?subsample=128
Dec 07, 2018 09:12:06.801 INFO - IMAGE: Unable to compute brightness for image.
Dec 07, 2018 09:12:06.925 INFO - Error loading: https://PUBLIC_IP_OF_SERVER:21/playQueues/1822?window=30: Request failed with status code 404
Dec 07, 2018 09:12:07.100 INFO - #4c2c1c,#4f4944,#897a6d,#ccc4b8
Dec 07, 2018 09:12:07.100 INFO - IMAGE: Top luminosity range is 0.3543635719823818, min luminosity is 0.20341559183952515
Dec 07, 2018 09:12:07.101 INFO - PLAYER: Computed soundprint data for a track in 328ms.
Dec 07, 2018 09:12:07.102 INFO - WebGL: Updating loudness texture.
Dec 07, 2018 09:12:07.102 INFO - WebGL: Updating palette texture.
Dec 07, 2018 09:12:07.102 INFO - Crossfade will last for 18 frames.
Dec 07, 2018 09:12:07.114 INFO - HTTP: Issuing request to https://PUBLIC_IP_OF_SERVER:21/playQueues/1822?window=30
Dec 07, 2018 09:12:07.232 INFO - Error loading: https://PUBLIC_IP_OF_SERVER:21/playQueues/1822?window=30: Request failed with status code 404
Dec 07, 2018 09:12:07.272 INFO - PLAYER: Play queue changed to 1823, refreshing.
Dec 07, 2018 09:12:07.272 INFO - HTTP: Issuing request to https://PUBLIC_IP_OF_SERVER:21/playQueues/1823?window=30
Dec 07, 2018 09:12:07.272 INFO - PLAYER: Loading data on-the-fly for current track (PQID 30970), was not cached.
Dec 07, 2018 09:12:07.272 INFO - HTTP: Issuing request to https://PUBLIC_IP_OF_SERVER:21/library/streams/1594755/levels?subsample=128
Dec 07, 2018 09:12:07.300 INFO - IMAGE: Unable to compute brightness for image.
Dec 07, 2018 09:12:07.474 INFO - #494240,#27a5e2,#a2d1e5,#c4c5c5
Dec 07, 2018 09:12:07.475 INFO - IMAGE: Top luminosity range is -0.03239968745122368, min luminosity is 0.5893945342106974
Dec 07, 2018 09:12:07.475 INFO - IMAGE: Expanding by darkering.
Dec 07, 2018 09:12:07.485 INFO - PLAYER: Computed soundprint data for a track in 211ms.
Dec 07, 2018 09:12:07.498 INFO - WebGL: Updating loudness texture.
Dec 07, 2018 09:12:07.498 INFO - WebGL: Updating palette texture.
Dec 07, 2018 09:12:07.498 INFO - Crossfade will last for 18 frames.
Dec 07, 2018 09:12:07.504 INFO - HTTP: Issuing request to https://PUBLIC_IP_OF_SERVER:21/playQueues/1823?window=30
Dec 07, 2018 09:12:07.636 INFO - PLAYER: Preloading metadata for next track.
Dec 07, 2018 09:12:07.636 INFO - HTTP: Issuing request to https://PUBLIC_IP_OF_SERVER:21/library/streams/1594756/levels?subsample=128
Dec 07, 2018 09:12:07.641 INFO - IMAGE: Unable to compute brightness for image.
Dec 07, 2018 09:12:07.730 INFO - #494240,#27a5e2,#a2d1e5,#c4c5c5
Dec 07, 2018 09:12:07.731 INFO - IMAGE: Top luminosity range is -0.03239968745122368, min luminosity is 0.5893945342106974
Dec 07, 2018 09:12:07.731 INFO - IMAGE: Expanding by darkering.
Dec 07, 2018 09:12:07.781 INFO - PLAYER: Computed soundprint data for a track in 145ms.
Dec 07, 2018 09:12:10.566 INFO - Requesting /player/playback/seekTo?offset=115661.20666666667&commandID=131&type=music from player Local.
Dec 07, 2018 09:12:10.566 INFO - HTTP: Issuing request to http://127.0.0.1:36000/player/playback/seekTo?offset=115661.20666666667&commandID=131&type=music
Dec 07, 2018 09:12:16.295 INFO - Requesting /player/playback/skipNext?commandID=133&type=music from player Local.
Dec 07, 2018 09:12:16.295 INFO - HTTP: Issuing request to http://127.0.0.1:36000/player/playback/skipNext?commandID=133&type=music
Dec 07, 2018 09:12:16.750 INFO - Requesting /player/playback/skipNext?commandID=134&type=music from player Local.
Dec 07, 2018 09:12:16.751 INFO - HTTP: Issuing request to http://127.0.0.1:36000/player/playback/skipNext?commandID=134&type=music
Dec 07, 2018 09:12:23.832 ERROR - PLAYER: Error issuing request to player Local: /player/timeline/poll?wait=1&includeMetadata=1&commandID=135&type=music Error: read ECONNRESET
at exports._errnoException (util.js:1050:11)
at TCP.onread (net.js:581:26)
server.log
Server.log
Dec 07, 2018 09:11:42 DEBUG - DEVICE: Loaded 6 devices.
Dec 07, 2018 09:11:42 INFO - [PUBSUB] Connecting…
Dec 07, 2018 09:11:42 DEBUG - CODEC: Checking for device identifier in C:\Users\brhodes\AppData\Local\Plexamp\Plexamp\Codecs.device-id
Dec 07, 2018 09:11:42 DEBUG - CODEC: Read 315baf45-3aa2-479c-b166-1e0b2d2365f6
Dec 07, 2018 09:11:42 DEBUG - CODEC: Initialize complete.
Dec 07, 2018 09:11:42 DEBUG - DEVICE: Initializing manager.
Dec 07, 2018 09:11:42 DEBUG - DEVICE: Fetching latest provider list from cloud.
Dec 07, 2018 09:11:42 DEBUG - DEVICE: Fetching latest list from cloud.
Dec 07, 2018 09:11:42 DEBUG - DEVICE: Starting connection test.
Dec 07, 2018 09:11:42 DEBUG - DEVICE: Finding best connection for HOMESERVER
Dec 07, 2018 09:11:42 DEBUG - HTTP: Issuing request to https://127.0.0.1:32400/
Dec 07, 2018 09:11:42 DEBUG - HTTP: Issuing request to https://192.168.1.2:32400/
Dec 07, 2018 09:11:42 DEBUG - HTTP: Issuing request to https://PUBLIC_IP_OF_SERVER:21/
Dec 07, 2018 09:11:42 INFO - [MPD] Started, now we will connect
Dec 07, 2018 09:11:42 INFO - [MPD] Connecting…
Dec 07, 2018 09:11:42 DEBUG - DEVICE: Server connection worked for HOMESERVER ~ https://PUBLIC_IP_OF_SERVER:21
Dec 07, 2018 09:11:42 DEBUG - HTTP: Issuing request to https://PUBLIC_IP_OF_SERVER:21/media/providers
Dec 07, 2018 09:11:42 DEBUG - DEVICE: Fast-path connection testing.
Dec 07, 2018 09:11:42 DEBUG - DEVICE: Finding best connection for Pixel 2
Dec 07, 2018 09:11:42 DEBUG - HTTP: Issuing request to http://192.168.1.124:32500/resources
Dec 07, 2018 09:11:42 DEBUG - DEVICE: Finding best connection for WORKLAPTOP
Dec 07, 2018 09:11:42 DEBUG - HTTP: Issuing request to http://YET_ANOTHER_PRIVATE_IP_LAPTOP_OF_COWORKER:36000/resources
Dec 07, 2018 09:11:42 DEBUG - DEVICE: Finding best connection for WORKLAPTOP
Dec 07, 2018 09:11:42 DEBUG - HTTP: Issuing request to http://PRIVATE_IP_LAPTOP_OF_COWORKER:36000/resources
Dec 07, 2018 09:11:42 DEBUG - HTTP: Issuing request to http://192.168.1.103:36000/resources
Dec 07, 2018 09:11:42 DEBUG - DEVICE: Finding best connection for TIDAL
Dec 07, 2018 09:11:42 DEBUG - DEVICE: Skipping actual connection testing for TIDAL.
Dec 07, 2018 09:11:42 DEBUG - DEVICE: Finding best connection for Podcasts
Dec 07, 2018 09:11:42 DEBUG - DEVICE: Skipping actual connection testing for Podcasts.
Dec 07, 2018 09:11:42 DEBUG - DEVICE: Persisting devices.
Dec 07, 2018 09:11:42 DEBUG - DEVICE: Initialization finished in 295ms.
Dec 07, 2018 09:11:42 DEBUG - DEVICE: Reading libraries and features from TIDAL
Dec 07, 2018 09:11:42 DEBUG - HTTP: Issuing request to https://music.provider.plex.tv/
Dec 07, 2018 09:11:42 DEBUG - DEVICE: Reading libraries and features from Podcasts
Dec 07, 2018 09:11:42 DEBUG - HTTP: Issuing request to https://podcasts.provider.plex.tv/
Dec 07, 2018 09:11:42 INFO - [PUBSUB] Connected.
Dec 07, 2018 09:11:42 INFO - [CLOUD] Registered device.
Dec 07, 2018 09:11:43 DEBUG - DEVICE: Fetched 6 devices from the cloud.
Dec 07, 2018 09:11:43 WARN - DEVICE: Server connection https://127.0.0.1:32400 didn’t work for HOMESERVER: connect ECONNREFUSED 127.0.0.1:32400
Dec 07, 2018 09:11:43 INFO - [MPD] Ready!
Dec 07, 2018 09:11:43 DEBUG - [MPD] Restoring play queue 1811 from c4856e96efe07e6b137425e269b4848f7229c80b.
Dec 07, 2018 09:11:43 DEBUG - HTTP: Issuing request to https://PUBLIC_IP_OF_SERVER:21/playQueues/1811?includeLoudnessRamps=1&own=1&X-Plex-Device-Name=WORKLAPTOP
Dec 07, 2018 09:11:43 DEBUG - METRICS: Initializing.
Dec 07, 2018 09:11:43 INFO - [EXPRESS] Listening on port 36000
Dec 07, 2018 09:11:43 DEBUG - Audio: Setting shuffled parameters with normalize: true.
Dec 07, 2018 09:11:43 DEBUG - Audio: Enabling crossfade.
Dec 07, 2018 09:11:43 DEBUG - PlayQueue: Play queue: 30601
Dec 07, 2018 09:11:43 DEBUG - PlayQueue: Audio queue:
Dec 07, 2018 09:11:43 DEBUG - PlayQueue: Adding both current and next track.
Dec 07, 2018 09:11:43 DEBUG - PlayQueue: Need codec mp3
Dec 07, 2018 09:11:43 DEBUG - PlayQueue: Sending out-of-band loudness data down to player.
Dec 07, 2018 09:11:43 DEBUG - PlayQueue: Final AudioQueue: 30601.
Dec 07, 2018 09:11:43 INFO - PlayQueue: Starting playback of track 1 at 98.305 sec.
Dec 07, 2018 09:11:43 DEBUG - [MPD] Final success restoring play queue: true
Dec 07, 2018 09:11:43 DEBUG - State changed from stopped to playing
Dec 07, 2018 09:11:43 DEBUG - METRICS: Starting new track.
Dec 07, 2018 09:11:43 DEBUG - HTTP: Issuing request to https://PUBLIC_IP_OF_SERVER:21/:/timeline?state=playing&duration=245766&time=98305&playQueueItemID=30601&key=%2Flibrary%2Fmetadata%2F301859&ratingKey=301859&playQueueID=1811&playQueueVersion=1&containerKey=%2FplayQueues%2F1811&hasMDE=1&X-Plex-Device-Name=WORKLAPTOP
Dec 07, 2018 09:11:43 INFO - [POWER] Turning power on!
Dec 07, 2018 09:11:43 WARN - DEVICE: Player connection http://PRIVATE_IP_LAPTOP_OF_COWORKER:36000 didn’t work for WORKLAPTOP: connect ECONNREFUSED PRIVATE_IP_LAPTOP_OF_COWORKER:36000
Dec 07, 2018 09:11:43 DEBUG - PROXY: Initiating proxy for stream for /library/parts/575462/1333338396/file.mp3?download=1&X-Plex-Client-Identifier=525405b5-b8f5-40ca-bd37-adc04b724282&X-Plex-Session-Identifier=3fb33a28-3b7a-433a-aee0-7b60c0326947 to HOMESERVER
Dec 07, 2018 09:11:43 DEBUG - METRICS: Saving latest cloud settings for metrics.
Dec 07, 2018 09:11:43 DEBUG - PROXY: Stream got closed after sending 49152 bytes of 4915328 bytes.
Dec 07, 2018 09:11:45 DEBUG - HTTP: Issuing request to https://PUBLIC_IP_OF_SERVER:21/photo/:/transcode/?width=32&height=32&upscale=1&url=%2Flibrary%2Fmetadata%2F218018%2Fthumb%2F1498510044
Dec 07, 2018 09:11:45 DEBUG - HTTP: Issuing request to https://PUBLIC_IP_OF_SERVER:21/photo/:/transcode/?width=250&height=250&upscale=1&url=%2Flibrary%2Fmetadata%2F218018%2Fthumb%2F1498510044
Dec 07, 2018 09:11:45 DEBUG - GET /proxy/image/c4856e96efe07e6b137425e269b4848f7229c80b?width=32&height=32&upscale=1&url=%2Flibrary%2Fmetadata%2F218018%2Fthumb%2F1498510044 200 521 - 174.387 ms
Dec 07, 2018 09:11:45 DEBUG - GET /proxy/image/c4856e96efe07e6b137425e269b4848f7229c80b?width=250&height=250&upscale=1&url=%2Flibrary%2Fmetadata%2F218018%2Fthumb%2F1498510044 200 3709 - 166.593 ms
Dec 07, 2018 09:11:47 WARN - DEVICE: Server connection https://192.168.1.2:32400 didn’t work for HOMESERVER: timeout of 5000ms exceeded
Dec 07, 2018 09:11:47 WARN - DEVICE: Player connection http://192.168.1.124:32500 didn’t work for Pixel 2: timeout of 5000ms exceeded
Dec 07, 2018 09:11:47 WARN - DEVICE: Player connection http://YET_ANOTHER_PRIVATE_IP_LAPTOP_OF_COWORKER:36000 didn’t work for WORKLAPTOP: timeout of 5000ms exceeded
Dec 07, 2018 09:11:47 WARN - DEVICE: Connection testing failed for Pixel 2
Dec 07, 2018 09:11:47 WARN - DEVICE: Connection testing failed for WORKLAPTOP
Dec 07, 2018 09:11:47 WARN - DEVICE: Player connection http://192.168.1.103:36000 didn’t work for WORKLAPTOP: timeout of 5000ms exceeded
Dec 07, 2018 09:11:47 WARN - DEVICE: Connection testing failed for WORKLAPTOP
Dec 07, 2018 09:11:53 DEBUG - METRICS: Ending last track forcefully with status stopped
Dec 07, 2018 09:11:53 DEBUG - HTTP: Issuing request to https://PUBLIC_IP_OF_SERVER:21/playQueues?includeLoudnessRamps=1&uri=server%3A%2F%2Fc4856e96efe07e6b137425e269b4848f7229c80b%2Fcom.plexapp.plugins.library%2Flibrary%2Fmetadata%2F318568%2Fchildren&type=audio&commandID=4&X-Plex-Device-Name=WORKLAPTOP
Dec 07, 2018 09:11:53 DEBUG - Audio: Setting shuffled parameters with normalize: true.
Dec 07, 2018 09:11:53 DEBUG - Audio: Enabling crossfade.
Dec 07, 2018 09:11:53 DEBUG - PlayQueue: Play queue: 30969
Dec 07, 2018 09:11:53 DEBUG - PlayQueue: Audio queue: 30601
Dec 07, 2018 09:11:53 DEBUG - PlayQueue: Adding both current and next track.
Dec 07, 2018 09:11:53 DEBUG - PROXY: Client closed, destroying proxy connection to server.
Dec 07, 2018 09:11:53 DEBUG - GET /proxy/file.mp3?source=c4856e96efe07e6b137425e269b4848f7229c80b&endpoint=%2Flibrary%2Fparts%2F575462%2F1333338396%2Ffile.mp3%3Fdownload%3D1%26X-Plex-Client-Identifier%3D525405b5-b8f5-40ca-bd37-adc04b724282%26X-Plex-Session-Identifier%3D3fb33a28-3b7a-433a-aee0-7b60c0326947 200 4915328 - 166.498 ms
Dec 07, 2018 09:11:53 DEBUG - PlayQueue: Sending out-of-band loudness data down to player.
Dec 07, 2018 09:11:53 DEBUG - PlayQueue: Ensuring we’re playing 2 in Map { 2 => 30969 }
Dec 07, 2018 09:11:53 DEBUG - PlayQueue: Final AudioQueue: 30969.
Dec 07, 2018 09:11:53 DEBUG - GET /player/playback/createPlayQueue?source=c4856e96efe07e6b137425e269b4848f7229c80b&uri=server%3A%2F%2Fc4856e96efe07e6b137425e269b4848f7229c80b%2Fcom.plexapp.plugins.library%2Flibrary%2Fmetadata%2F318568%2Fchildren&token=&state=playing&type=audio&protocol=https&address=192.168.1.2&port=32400&machineIdentifier=c4856e96efe07e6b137425e269b4848f7229c80b&commandID=4 200 2 - 164.044 ms
Dec 07, 2018 09:11:53 DEBUG - METRICS: Sending event: playback:itemend to https://analytics.plex.tv
Dec 07, 2018 09:11:53 DEBUG - METRICS: Starting new track.
Dec 07, 2018 09:11:53 DEBUG - HTTP: Issuing request to https://PUBLIC_IP_OF_SERVER:21/:/timeline?state=playing&duration=232229&playQueueItemID=30969&key=%2Flibrary%2Fmetadata%2F318569&ratingKey=318569&playQueueID=1822&playQueueVersion=1&containerKey=%2FplayQueues%2F1822&hasMDE=1&X-Plex-Device-Name=WORKLAPTOP
Dec 07, 2018 09:11:53 DEBUG - METRICS: Sending event: playback:itemstart to https://analytics.plex.tv
Dec 07, 2018 09:11:54 DEBUG - PROXY: Initiating proxy for stream for /library/parts/622014/1539270485/file.mp3?download=1&X-Plex-Client-Identifier=525405b5-b8f5-40ca-bd37-adc04b724282&X-Plex-Session-Identifier=ad27a277-cf02-49e3-b4e2-87a176145f23 to HOMESERVER
Dec 07, 2018 09:11:54 DEBUG - PROXY: Stream got closed after sending 49152 bytes of 7888493 bytes.
Dec 07, 2018 09:11:57 DEBUG - DEVICE: Persisting devices because HOMESERVER was dirty.
Dec 07, 2018 09:11:57 DEBUG - DEVICE: Persisting devices.
Dec 07, 2018 09:12:04 DEBUG - METRICS: Ending last track forcefully with status stopped
Dec 07, 2018 09:12:04 DEBUG - HTTP: Issuing request to https://PUBLIC_IP_OF_SERVER:21/playQueues?includeLoudnessRamps=1&uri=server%3A%2F%2Fc4856e96efe07e6b137425e269b4848f7229c80b%2Fcom.plexapp.plugins.library%2Flibrary%2Fmetadata%2F2747%2Fchildren&shuffle=0&type=audio&commandID=109&X-Plex-Device-Name=WORKLAPTOP
Dec 07, 2018 09:12:04 DEBUG - METRICS: Sending event: playback:itemend to https://analytics.plex.tv
Dec 07, 2018 09:12:05 DEBUG - Audio: Setting shuffled parameters with normalize: true.
Dec 07, 2018 09:12:05 DEBUG - Audio: Enabling crossfade.
Dec 07, 2018 09:12:05 DEBUG - PlayQueue: Play queue: 30970,30971
Dec 07, 2018 09:12:05 DEBUG - PlayQueue: Audio queue: 30969
Dec 07, 2018 09:12:05 DEBUG - PlayQueue: Adding both current and next track.
Dec 07, 2018 09:12:05 DEBUG - PROXY: Client closed, destroying proxy connection to server.
Dec 07, 2018 09:12:05 DEBUG - GET /proxy/file.mp3?source=c4856e96efe07e6b137425e269b4848f7229c80b&endpoint=%2Flibrary%2Fparts%2F622014%2F1539270485%2Ffile.mp3%3Fdownload%3D1%26X-Plex-Client-Identifier%3D525405b5-b8f5-40ca-bd37-adc04b724282%26X-Plex-Session-Identifier%3Dad27a277-cf02-49e3-b4e2-87a176145f23 200 7888493 - 1056.821 ms
Dec 07, 2018 09:12:05 DEBUG - PlayQueue: Sending out-of-band loudness data down to player.
Dec 07, 2018 09:12:05 DEBUG - PlayQueue: Sending out-of-band loudness data down to player.
Dec 07, 2018 09:12:05 DEBUG - PlayQueue: Ensuring we’re playing 3 in Map { 3 => 30970, 4 => 30971 }
Dec 07, 2018 09:12:05 DEBUG - PlayQueue: Final AudioQueue: 30970,30971.
Dec 07, 2018 09:12:05 DEBUG - GET /player/playback/createPlayQueue?uri=server%3A%2F%2Fc4856e96efe07e6b137425e269b4848f7229c80b%2Fcom.plexapp.plugins.library%2Flibrary%2Fmetadata%2F2747%2Fchildren&shuffle=0&source=c4856e96efe07e6b137425e269b4848f7229c80b&token=&state=playing&type=audio&protocol=https&address=192.168.1.2&port=32400&machineIdentifier=c4856e96efe07e6b137425e269b4848f7229c80b&commandID=109 200 2 - 175.004 ms
Dec 07, 2018 09:12:05 DEBUG - METRICS: Starting new track.
Dec 07, 2018 09:12:05 DEBUG - HTTP: Issuing request to https://PUBLIC_IP_OF_SERVER:21/:/timeline?state=playing&duration=258943&playQueueItemID=30970&key=%2Flibrary%2Fmetadata%2F303703&ratingKey=303703&playQueueID=1823&playQueueVersion=1&containerKey=%2FplayQueues%2F1823&hasMDE=1&X-Plex-Device-Name=WORKLAPTOP
Dec 07, 2018 09:12:05 DEBUG - METRICS: Sending event: playback:itemstart to https://analytics.plex.tv
Dec 07, 2018 09:12:05 DEBUG - PROXY: Initiating proxy for stream for /library/parts/577295/1433699335/file.mp3?download=1&X-Plex-Client-Identifier=525405b5-b8f5-40ca-bd37-adc04b724282&X-Plex-Session-Identifier=fc4d8aed-1676-423a-8fab-d7ad620a411a to HOMESERVER
Dec 07, 2018 09:12:05 DEBUG - PROXY: Stream got closed after sending 49152 bytes of 5178864 bytes.
Dec 07, 2018 09:12:10 DEBUG - GET /player/playback/seekTo?offset=115661.20666666667&commandID=131&type=music 200 2 - 0.517 ms
Dec 07, 2018 09:12:10 DEBUG - PlayQueue: Processing SEEK TO
Dec 07, 2018 09:12:16 DEBUG - GET /player/playback/skipNext?commandID=133&type=music 200 2 - 0.687 ms
Dec 07, 2018 09:12:16 DEBUG - GET /player/playback/skipNext?commandID=134&type=music 200 2 - 0.402 ms
Same situation. Plexamp will play on local network, will not play at work. Tried reinstallation, as well. Plex Media Player plays just fine, Plexamp allows you to browse media, but it won’t actually play it.
This is happening to me on Windows 10 Build 1803, Plexamp 1.1.0
Can load Plexamp, login and browse media. Press Play and the track loads, but does not start playing; the button changes to the pause icon, and you can see the waveform, but it will eventually will back out the list of media.
+1 same here, which sucks as plexamp has become my default play method
+1 same here. was working beautifully but something killed it.
Keep getting the following over and over and over in the application log…for some reason there is no update in the server log it is over a week old with no updates to it…
Dec 17, 2018 08:51:11.153 ERROR - PLAYER: Error issuing request to player Local: /player/timeline/poll?wait=0&includeMetadata=1&commandID=283&type=music Error: connect ECONNREFUSED 127.0.0.1:36000
at Object.exports._errnoException (util.js:1050:11)
at exports._exceptionWithHostPort (util.js:1073:20)
at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1097:14)
Wow, that is quite strange It sort of seems like the network connection is breaking, or MPD.exe is dying. Is this just on Windows we’re seeing the issue?
I’m a bit puzzled at the moment.
Win 10 Pro 64-bit.
Only seeing it on Win10, works fine on MacOS for me.
I have the same issue, Win 10 Pro 64-bit. Maybe relevant:
From Application.log
Dec 22, 2018 11:00:28.966 WARN - Error loading loudness data for track Hidden Brain / Alan Alda Wants Us To Have Better Conversations
Dec 22, 2018 11:00:35.573 WARN - PLAYER: Giving up on polling, index 2 didn't match 1.
[..]
Dec 22, 2018 11:00:55.574 WARN - PLAYER: Giving up on polling, index 3 didn't match 2.
From Server.log
Dec 22, 2018 11:00:28 ERROR - PlayQueue: We were missing out-of-band loudness data, not sending.
Dec 22, 2018 11:00:28 ERROR - Got exception playing media: [2@0] {addid} too many arguments for "addid"
Dec 22, 2018 11:00:28 ERROR -
{
"cause": {},
"isOperational": true
}
[..]
Dec 22, 2018 11:00:52 ERROR - Got exception playing media: [2@0] {addidwithloudness} wrong number of arguments for "addidwithloudness"
Dec 22, 2018 11:00:52 ERROR -
{
"cause": {},
"isOperational": true
}
The “index didn’t match” and “Got exception playing media” seems to occur every time I hit the play button in PlexAmp.
I fixed mine by removing
C:\Users\<USER>\AppData\Local\Plexamp
and
C:\Users\<USER>\AppData\Roaming\Plexamp
AND reinstalling Plexamp.
(Neither reinstalling alone, nor removing both folders alone, fixed it.)
Was not successful for me unfortunately 
Manually removed
C:\Users\<USER>\AppData\Local\Plexamp
&&
C:\Users\<USER>\AppData\Roaming\Plexamp
Uninstalled via Add / Remove Programs
Reinstalled 1.1.0 fresh and this fixed the issue for me.
Thank you EquateBrand!
Tried equatebrands steps a few other ways with no success. Worth noting I suppose, uninstalling from add/remove programs doesn’t work for me. I am prompted for credentials to elevate the uninstall, and then nothing.
If I manuall run Uninstall Plexamp.exe from C:\Users<userprofile>\AppData\Local\Programs\plexamp - it removes its installed directory just fine.
I also tried equatebrands fix and for me it was the same result with a connection to the library as music is browseable but playback just does not work. Would really love to get an answer on this issue. I think the issue came about in December for me after the latest update, but not for sure on that.
I do get this in the application log:
Error loading: https://myipaddr:32400/library/streams/20362/levels?subsample=128: Request failed with status code 501
Thanks @EquateBrand - uninstall alone wasn’t working for me, but removing those two folders, than an uninstall and reinstall did the trick.
