Plexamp Headless RPI No Connection to Server

Plex Labs
1

I have installed plexamp headless on a fresh Raspi OS 64 bit. Node is installed. I can access the webgui. When I click play on a song, album, artist, or playlist, I get an infinite spinning circle.

plexamp
plexamp840×595 3.82 KB

Systemd shows : "DEVICE: No provider for source 8827705a313d5e5e28b906eab0babaad28a2f8bd "

The logs show: "
May 06, 2022 18:00:49.940 [0xa7ea5d80] DEBUG - Networking: Create request 27: (GET https://192-168-1-3.xxxxxxxxxxxxxxxxxxxxxxxxx.plex.direct:32400/media/providers?includePreferences=1).

May 06, 2022 18:00:49.940 [Javascript] INFO - DEVICE: Server connection worked for plex ~ https://xx-xx-xx-xx.exxxxxxxxxxxxxxxxxxxxxxxxxx.plex.direct:32400

May 06, 2022 18:00:50.018 [0x89ffb180] DEBUG - Networking: Completed request 27: (GET https://192-168-1-3.xxxxxxxxxxxxxxxxxxxxxx.plex.direct:32400/media/providers?includePreferences=1) with code 200 (have 36060 bytes) in 78 ms.

May 06, 2022 18:00:50.020 [Javascript] INFO - DEVICE: Found 7 libraries from plex:

I have tried the full OS and Lite. Any guidance would be appreciated.

I have searched the forums and Reddit and have not found a solution. Thank you.

2

Please post full logs.

3

Last full log.

May 06, 2022 18:00:39.802 [Javascript] INFO - Starting Plexamp 4.2.2-beta.1 - linux 5.15.32-v8+
May 06, 2022 18:00:39.805 [Javascript] INFO - METRICS: Initializing.
May 06, 2022 18:00:39.808 [Javascript] INFO - USER: Refreshing users.
May 06, 2022 18:00:39.810 [Javascript] INFO - Autoupdate: Identifier desktop should check: false.
May 06, 2022 18:00:39.811 [Javascript] INFO - DEVICE: Initializing device manager.
May 06, 2022 18:00:39.827 [Javascript] INFO - DEVICE: Loaded 10 devices.
May 06, 2022 18:00:39.832 [0xa7ea5d80] DEBUG - Networking: Create request 1: (GET https://plex.tv/api/users).
May 06, 2022 18:00:39.833 [Javascript] INFO - DEVICE: Initializing manager.
May 06, 2022 18:00:39.835 [Javascript] INFO - DEVICE: Fetching latest provider list from cloud.
May 06, 2022 18:00:39.837 [Javascript] INFO - DEVICE: Fetching latest list from cloud.
May 06, 2022 18:00:39.839 [Javascript] INFO - DEVICE: Fetching latest cloud player list from https://sonos.plex.tv
May 06, 2022 18:00:39.839 [Javascript] INFO - DEVICE: Starting connection test.
May 06, 2022 18:00:39.842 [0xa7ea5d80] DEBUG - Networking: Create request 2: (GET https://plex.tv/media/providers).
May 06, 2022 18:00:39.842 [0xa7ea5d80] DEBUG - Networking: Create request 3: (GET https://plex.tv/api/resources?includeHttps=1&includeRelay=1).
May 06, 2022 18:00:39.843 [0xa7ea5d80] DEBUG - Networking: Create request 4: (GET https://sonos.plex.tv/resources).
May 06, 2022 18:00:39.843 [Javascript] INFO - DEVICE: Fast-path connection testing.
May 06, 2022 18:00:39.846 [Javascript] INFO - DEVICE: Finding best connection for ALCATEL ONE TOUCH 903 a1d4df6a8a5549d1-com-plexapp-android.
May 06, 2022 18:00:39.850 [0xa7ea5d80] DEBUG - Networking: Create request 5: (GET http://10.6.0.2:32500/resources).
May 06, 2022 18:00:39.850 [Javascript] INFO - DEVICE: Finding best connection for Android fe464b5f-299f-4a8c-b865-462feadd7956.
May 06, 2022 18:00:39.851 [0xa7ea5d80] DEBUG - Networking: Create request 6: (GET http://192.168.1.88:40715/resources).
May 06, 2022 18:00:39.851 [Javascript] INFO - DEVICE: Finding best connection for BRAVIA 4K 2015 dc4bf1c1be17b036-com-plexapp-android.
May 06, 2022 18:00:39.852 [0xa7ea5d80] DEBUG - Networking: Create request 7: (GET http://10.0.0.118:32500/resources).
May 06, 2022 18:00:39.852 [Javascript] INFO - DEVICE: Finding best connection for Chrome qdw2sfsxbdpw2928a96c385y.
May 06, 2022 18:00:39.853 [0xa7ea5d80] DEBUG - Networking: Create request 8: (GET https://192-168-1-3.xxxxxxxxxxxxxxxxxxxxxxxxxx.plex.direct:32400/resources).
May 06, 2022 18:00:39.854 [0xa7ea5d80] DEBUG - Networking: Create request 9: (GET https://xx-xxx-xx-xx.xxxxxxxxxxxxxxxxxxxxxxxxxx.plex.direct:32400/resources).
May 06, 2022 18:00:39.854 [Javascript] INFO - DEVICE: Finding best connection for plexamp 2017b8a1-7189-4bee-9b04-968ba77bf2fb.
May 06, 2022 18:00:39.855 [0xa7ea5d80] DEBUG - Networking: Create request 10: (GET http://192.168.1.54:32500/resources).
May 06, 2022 18:00:39.855 [Javascript] INFO - DEVICE: Finding best connection for pi_amp 316a4c3c-537c-4522-bb9a-672ec53e5b00.
May 06, 2022 18:00:39.855 [0x89ffb180] DEBUG - Networking: Completed request 10: (GET http://192.168.1.54:32500/resources) with code -7 (have 0 bytes) in 0 ms.
May 06, 2022 18:00:39.856 [0xa7ea5d80] DEBUG - Networking: Create request 11: (GET http://192.168.1.250:32500/resources).
May 06, 2022 18:00:39.856 [Javascript] INFO - DEVICE: Finding best connection for plexamp e5252b0e-9456-4a84-9f01-fec7f297a09c.
May 06, 2022 18:00:39.857 [0xa7ea5d80] DEBUG - Networking: Create request 12: (GET http://192.168.1.250:32500/resources).
May 06, 2022 18:00:39.858 [Javascript] INFO - DEVICE: Persisting 10 devices.
May 06, 2022 18:00:39.872 [Javascript] INFO - DEVICE: Initialization finished in 39ms.
May 06, 2022 18:00:39.873 [0xa7ea5d80] DEBUG - Networking: Create request 13: (GET https://plex.tv/api/v2/user/privacy.json).
May 06, 2022 18:00:39.875 [Javascript] INFO - ACCOUNT: Refreshing data.
May 06, 2022 18:00:39.880 [0xa7ea5d80] DEBUG - Networking: Create request 14: (GET https://plex.tv/users/account.json?X-Plex-Device-Name=plexamp).
May 06, 2022 18:00:39.914 [Javascript] WARNING - DEVICE: Player connection http://192.168.1.54:32500 didn't work for plexamp: HTTP status -7
May 06, 2022 18:00:39.914 [Javascript] WARNING - DEVICE: Connection testing failed for plexamp
May 06, 2022 18:00:39.931 [Javascript] INFO - LRUCache: Loading 0 entries into Images cache.
May 06, 2022 18:00:39.932 [Javascript] INFO - LRUCache: Loading 0 entries into Palette cache.
May 06, 2022 18:00:39.932 [Javascript] INFO - LRUCache: Loading 0 entries into Loudness cache.
May 06, 2022 18:00:39.932 [Javascript] INFO - App: Device manager, settings and cache initialized in 123ms.
May 06, 2022 18:00:39.935 [Javascript] INFO - Sync: Loaded in 2ms.
May 06, 2022 18:00:39.935 [Javascript] INFO - App: Offline store initialized in 3ms.
May 06, 2022 18:00:39.943 [Javascript] INFO - Audio: Initializing.
May 06, 2022 18:00:39.944 [Javascript] INFO - Audio: Binding settings.
May 06, 2022 18:00:39.944 [0x89ffb180] DEBUG - Networking: Completed request 6: (GET http://192.168.1.88:40715/resources) with code -7 (have 0 bytes) in 93 ms.
May 06, 2022 18:00:39.944 [Javascript] INFO - Audio: Setting player info.
May 06, 2022 18:00:39.946 [0x89ffb180] DEBUG - Networking: Completed request 8: (GET https://192-168-1-3.xxxxxxxxxxxxxxxxxxxxxxxxxx.plex.direct:32400/resources) with code 200 (have 355 bytes) in 92 ms.
May 06, 2022 18:00:39.946 [0x89ffb180] DEBUG - Networking: Completed request 9: (GET https://xx-xxx-xx-xx.xxxxxxxxxxxxxxxxxxxxxxxxxx.plex.direct:32400/resources) with code 200 (have 355 bytes) in 92 ms.
May 06, 2022 18:00:39.947 [0x8b7fe180] DEBUG - BASS: Starting up.
May 06, 2022 18:00:39.947 [0x8b7fe180] DEBUG - BASS: Created bass audio renderer.
May 06, 2022 18:00:39.993 [0x8b7fe180] INFO - BASS: Device 1: Default - enabled default - sample rates: () - active 0/0
May 06, 2022 18:00:39.993 [0x8b7fe180] INFO - BASS: Device 2: bcm2835 Headphones: bcm2835 Headphones - enabled - sample rates: () - active 0/0
May 06, 2022 18:00:39.993 [0x8b7fe180] INFO - BASS: Device 3: vc4-hdmi-0: MAI PCM i2s-hifi-0 - enabled - sample rates: () - active 0/0
May 06, 2022 18:00:39.993 [0x8b7fe180] INFO - BASS: Device 4: vc4-hdmi-1: MAI PCM i2s-hifi-0 - enabled - sample rates: () - active 0/0
May 06, 2022 18:00:39.993 [0x8b7fe180] INFO - BASS: Device 5: Rate Converter Plugin Using Libav/FFmpeg Library - enabled - sample rates: () - active 0/0
May 06, 2022 18:00:39.993 [0x8b7fe180] INFO - BASS: Device 6: Rate Converter Plugin Using Samplerate Library - enabled - sample rates: () - active 0/0
May 06, 2022 18:00:39.993 [0x8b7fe180] INFO - BASS: Device 7: Rate Converter Plugin Using Speex Resampler - enabled - sample rates: () - active 0/0
May 06, 2022 18:00:39.993 [0x8b7fe180] INFO - BASS: Device 8: JACK Audio Connection Kit - enabled - sample rates: () - active 0/0
May 06, 2022 18:00:39.993 [0x8b7fe180] INFO - BASS: Device 9: Open Sound System - enabled - sample rates: () - active 0/0
May 06, 2022 18:00:39.993 [0x8b7fe180] INFO - BASS: Device 10: PulseAudio Sound Server - enabled - sample rates: () - active 0/0
May 06, 2022 18:00:39.993 [0x8b7fe180] INFO - BASS: Device 11: Plugin for channel upmix (4,6,8) - enabled - sample rates: () - active 0/0
May 06, 2022 18:00:39.993 [0x8b7fe180] INFO - BASS: Device 12: Plugin for channel downmix (stereo) with a simple spacialization - enabled - sample rates: () - active 0/0
May 06, 2022 18:00:39.993 [0x8b7fe180] DEBUG - BASS: Using plugin path '/home/pi/plexamp/treble/'.
May 06, 2022 18:00:39.994 [0x8b7fe180] DEBUG - BASS: Reloading ourselves for symbol visibility.
May 06, 2022 18:00:39.994 [0x8b7fe180] INFO - BASS: Loaded AAC plug-in version 2.4.5.11
May 06, 2022 18:00:39.994 [0x8b7fe180] INFO - BASS: Loaded ALAC plug-in version 2.4.0.3
May 06, 2022 18:00:39.994 [0x8b7fe180] INFO - BASS: Loaded FLAC plug-in version 2.4.4.5
May 06, 2022 18:00:39.994 [0x8b7fe180] INFO - BASS: Loaded OPUS plug-in version 2.4.2.1
May 06, 2022 18:00:39.995 [0x8b7fe180] INFO - BASS: Loaded APE plug-in version 2.4.2.0
May 06, 2022 18:00:39.995 [0x8b7fe180] INFO - BASS: Loaded MPC plug-in version 2.4.1.3
May 06, 2022 18:00:39.995 [0x8b7fe180] INFO - BASS: Loaded DSD plug-in version 2.4.1.2
May 06, 2022 18:00:39.995 [0x8b7fe180] INFO - BASS: Core version 2.4.16.7
May 06, 2022 18:00:39.995 [0x8b7fe180] INFO - BASS: Mixer version 2.4.11.1
May 06, 2022 18:00:39.995 [0x8b7fe180] INFO - BASS: FX version 2.4.12.1
May 06, 2022 18:00:39.995 [0x8b7fe180] INFO - BASS: Curl version is 7.83.0 (protocols: dict file http https mqtt; ssl: OpenSSL/1.1.1n; libz: 1.2.11; DNS: threaded).
May 06, 2022 18:00:39.995 [0x8b7fe180] DEBUG - BASS: Setting audio interface:  -> .
May 06, 2022 18:00:40.003 [Javascript] WARNING - DEVICE: Player connection http://192.168.1.88:40715 didn't work for Android: HTTP status -7
May 06, 2022 18:00:40.003 [Javascript] WARNING - DEVICE: Connection testing failed for Android
May 06, 2022 18:00:40.035 [Javascript] WARNING - DEVICE: The player qdw2sfsxbdpw2928a96c385y wasn't found in available resources at https://192-168-1-3.xxxxxxxxxxxxxxxxxxxxxxxxxx.plex.direct:32400.
May 06, 2022 18:00:40.037 [Javascript] WARNING - DEVICE: The player qdw2sfsxbdpw2928a96c385y wasn't found in available resources at https://xx-xxx-xx-xx.xxxxxxxxxxxxxxxxxxxxxxxxxx.plex.direct:32400.
May 06, 2022 18:00:40.037 [Javascript] WARNING - DEVICE: Connection testing failed for Chrome
May 06, 2022 18:00:40.043 [Javascript] INFO - App: Player initialized in 103ms.
May 06, 2022 18:00:40.051 [Javascript] INFO - App: Waiting for rest of stores to initialize.
May 06, 2022 18:00:40.053 [Javascript] INFO - Server Activity: Connecting based on switch.
May 06, 2022 18:00:40.054 [Javascript] INFO - Server Activity: Trying to connect to 8827705a313d5e5e28b906eab0babaad28a2f8bd.
May 06, 2022 18:00:40.056 [0xa7ea5d80] DEBUG - Networking: Create request 15: (GET https://192-168-1-3.xxxxxxxxxxxxxxxxxxxxxxxxxx.plex.direct:32400/:/eventsource/notifications?filters=timeline&X-Plex-Token=<token>).
May 06, 2022 18:00:40.069 [Javascript] INFO - Player: Initializing with state null
May 06, 2022 18:00:40.073 [Javascript] INFO - App: Stopping activity recognition.
May 06, 2022 18:00:40.078 [Javascript] INFO - Network changed: type is ethernet effectiveType is undefined -> 2
May 06, 2022 18:00:40.079 [0xa7ea5d80] INFO - BASS: Network switched to 2.
May 06, 2022 18:00:40.079 [Javascript] INFO - App: Network is connected, but type changed to 2, so doing preemptive connection testing on selected server.
May 06, 2022 18:00:40.079 [Javascript] INFO - DEVICE: Finding best connection for plex 8827705a313d5e5e28b906eab0babaad28a2f8bd.
May 06, 2022 18:00:40.080 [0xa7ea5d80] DEBUG - Networking: Create request 16: (GET https://192-168-1-3.xxxxxxxxxxxxxxxxxxxxxxxxxx.plex.direct:32400/).
May 06, 2022 18:00:40.080 [0xa7ea5d80] DEBUG - Networking: Create request 17: (GET https://xx-xxx-xx-xx.xxxxxxxxxxxxxxxxxxxxxxxxxx.plex.direct:32400/).
May 06, 2022 18:00:40.082 [Javascript] INFO - Player: Sending state changed [A]  -  (0/0) in state stopped with artwork false.
May 06, 2022 18:00:40.083 [Javascript] INFO - Player: Restoring player route of local with network state 2.
May 06, 2022 18:00:40.108 [Javascript] INFO - ViewState: Error loading from storage. Unexpected token u in JSON at position 0
May 06, 2022 18:00:40.116 [Javascript] INFO - Cloud: [RecentPlays] Loading from storage 20 items and 0 deleted.
May 06, 2022 18:00:40.118 [Javascript] INFO - Cloud: [RecentPlays] Syncing.
May 06, 2022 18:00:40.119 [0xa7ea5d80] DEBUG - Networking: Create request 18: (GET https://plex.tv/api/v2/user/settings?uuid=82694087140030a5&key=RecentPlays).
May 06, 2022 18:00:40.120 [Javascript] INFO - App: Stores initialized in 77ms.
May 06, 2022 18:00:40.121 [Javascript] INFO - App: Stores all initialized.
May 06, 2022 18:00:40.122 [Javascript] INFO - Companion: Initializing.
May 06, 2022 18:00:40.123 [Javascript] INFO - Companion: Network type is 2.
May 06, 2022 18:00:40.123 [Javascript] INFO - Companion: attempting to connect to pubsub, started undefined connected false
May 06, 2022 18:00:40.124 [0xa7ea5d80] DEBUG - Networking: Create request 19: (GET https://pubsub.plex.tv/sub/eventsource/1244998/abc9b574-896f-4bc7-86eb-bf519ea0e033?X-Plex-Token=<token>).
May 06, 2022 18:00:40.128 [Javascript] INFO - Companion: Network type is 2 and enabled is true.
May 06, 2022 18:00:40.131 [Javascript] INFO - Discovery: Refresh based on server/library switch 8827705a313d5e5e28b906eab0babaad28a2f8bd /library/sections/3.
May 06, 2022 18:00:40.133 [Javascript] INFO - Discovery: Fetching hubs for library /library/sections/3 server 8827705a313d5e5e28b906eab0babaad28a2f8bd refreshing from cloud false.
May 06, 2022 18:00:40.142 [0xa7ea5d80] DEBUG - Networking: Create request 20: (GET https://192-168-1-3.xxxxxxxxxxxxxxxxxxxxxxxxxx.plex.direct:32400/hubs/sections/3?count=4&includeExternalMetadata=1&includeMyMixes=1&includeAnniversaryReleases=1&excludeElements=Similar,Mood&includeLibraryPlaylists=1&includeStations=1&includeStationDirectories=1&excludeFields=summary&includeFields=thumbBlurHash&X-Plex-Device-Name=plexamp).
May 06, 2022 18:00:40.143 [0xa7ea5d80] DEBUG - Networking: Create request 21: (GET https://192-168-1-3.xxxxxxxxxxxxxxxxxxxxxxxxxx.plex.direct:32400/library/sections/3/all?type=10&sort=lastViewedAt:desc&group=guid&viewCount>=1&limit=4&includeFields=thumbBlurHash&X-Plex-Device-Name=plexamp).
May 06, 2022 18:00:40.150 [0x89ffb180] DEBUG - Networking: Completed request 17: (GET https://xx-xxx-xx-xx.xxxxxxxxxxxxxxxxxxxxxxxxxx.plex.direct:32400/) with code 200 (have 7712 bytes) in 69 ms.
May 06, 2022 18:00:40.154 [Javascript] INFO - Companion: Attempting to start HTTP Server on port 32500.
May 06, 2022 18:00:40.156 [0x50b3d180] DEBUG - HTTP: Serving on port 32500.
May 06, 2022 18:00:40.157 [Javascript] INFO - DEVICE: Server connection worked for plex ~ https://xx-xxx-xx-xx.xxxxxxxxxxxxxxxxxxxxxxxxxx.plex.direct:32400
May 06, 2022 18:00:40.160 [Javascript] INFO - DEVICE: Reading libraries and features from plex
May 06, 2022 18:00:40.161 [0xa7ea5d80] DEBUG - Networking: Create request 22: (GET https://xx-xxx-xx-xx.xxxxxxxxxxxxxxxxxxxxxxxxxx.plex.direct:32400/media/providers?includePreferences=1).
May 06, 2022 18:00:40.172 [Javascript] INFO - Companion: Registering device at 192.168.1.54:32500.
May 06, 2022 18:00:40.173 [0xa7ea5d80] DEBUG - Networking: Create request 23: (PUT https://plex.tv/devices/abc9b574-896f-4bc7-86eb-bf519ea0e033?Connection[][uri]=http://192.168.1.54:32500&X-Plex-Device-Name=plexamp).
May 06, 2022 18:00:40.240 [0x89ffb180] DEBUG - Networking: Completed request 16: (GET https://192-168-1-3.xxxxxxxxxxxxxxxxxxxxxxxxxx.plex.direct:32400/) with code 200 (have 7712 bytes) in 160 ms.
May 06, 2022 18:00:40.240 [0x89ffb180] DEBUG - Networking: Completed request 22: (GET https://xx-xxx-xx-xx.xxxxxxxxxxxxxxxxxxxxxxxxxx.plex.direct:32400/media/providers?includePreferences=1) with code 200 (have 36060 bytes) in 79 ms.
May 06, 2022 18:00:40.241 [Javascript] INFO - DEVICE: Server connection worked for plex ~ https://192-168-1-3.xxxxxxxxxxxxxxxxxxxxxxxxxx.plex.direct:32400
May 06, 2022 18:00:40.241 [Javascript] INFO - DEVICE: Updating with better local connection.
May 06, 2022 18:00:40.248 [Javascript] INFO - DEVICE: Found 7 libraries from plex: Home, Movies, TV Shows, Music, Baby First, Giant Bomb, Playlists
May 06, 2022 18:00:40.265 [0x89ffb180] DEBUG - Networking: Completed request 21: (GET https://192-168-1-3.xxxxxxxxxxxxxxxxxxxxxxxxxx.plex.direct:32400/library/sections/3/all?type=10&sort=lastViewedAt:desc&group=guid&viewCount>=1&limit=4&includeFields=thumbBlurHash&X-Plex-Device-Name=plexamp) with code 200 (have 5524 bytes) in 122 ms.
May 06, 2022 18:00:40.286 [0x89ffb180] DEBUG - Networking: Completed request 20: (GET https://192-168-1-3.xxxxxxxxxxxxxxxxxxxxxxxxxx.plex.direct:32400/hubs/sections/3?count=4&includeExternalMetadata=1&includeMyMixes=1&includeAnniversaryReleases=1&excludeElements=Similar,Mood&includeLibraryPlaylists=1&includeStations=1&includeStationDirectories=1&excludeFields=summary&includeFields=thumbBlurHash&X-Plex-Device-Name=plexamp) with code 200 (have 26558 bytes) in 143 ms.
May 06, 2022 18:00:40.287 [0x89ffb180] DEBUG - Networking: Completed request 2: (GET https://plex.tv/media/providers) with code 200 (have 2 bytes) in 444 ms.
May 06, 2022 18:00:40.299 [Javascript] INFO - Discovery: Setting 7 hubs from plex.
May 06, 2022 18:00:40.335 [0x89ffb180] DEBUG - Networking: Completed request 13: (GET https://plex.tv/api/v2/user/privacy.json) with code 200 (have 6766 bytes) in 461 ms.
May 06, 2022 18:00:40.336 [Javascript] INFO - METRICS: Saving latest cloud settings for metrics.
May 06, 2022 18:00:40.338 [0x89ffb180] DEBUG - Networking: Completed request 3: (GET https://plex.tv/api/resources?includeHttps=1&includeRelay=1) with code 200 (have 6351 bytes) in 495 ms.
May 06, 2022 18:00:40.338 [Javascript] INFO - METRICS: Error loading from storage. Unexpected token u in JSON at position 0
May 06, 2022 18:00:40.339 [Javascript] INFO - METRICS: Loaded 0 events from storage.
May 06, 2022 18:00:40.341 [0x89ffb180] DEBUG - Networking: Completed request 4: (GET https://sonos.plex.tv/resources) with code 403 (have 9 bytes) in 497 ms.
May 06, 2022 18:00:40.385 [Javascript] INFO - DEVICE: Fetched 11 devices from the cloud.
May 06, 2022 18:00:40.392 [Javascript] WARNING - DEVICE: Error loading cloud players from plex.tv HTTP status 403
May 06, 2022 18:00:40.398 [Javascript] INFO - DEVICE: Persisting 11 devices.
May 06, 2022 18:00:40.442 [0x89ffb180] DEBUG - Networking: Completed request 1: (GET https://plex.tv/api/users) with code 200 (have 1747 bytes) in 608 ms.
May 06, 2022 18:00:40.458 [Javascript] INFO - USER: Loaded 3 users
May 06, 2022 18:00:40.484 [0x89ffb180] DEBUG - Networking: Completed request 14: (GET https://plex.tv/users/account.json?X-Plex-Device-Name=plexamp) with code 200 (have 2100 bytes) in 604 ms.
May 06, 2022 18:00:40.521 [0x89ffb180] DEBUG - Networking: Completed request 18: (GET https://plex.tv/api/v2/user/settings?uuid=82694087140030a5&key=RecentPlays) with code 200 (have 7746 bytes) in 401 ms.
May 06, 2022 18:00:40.529 [0xa7ea5d80] DEBUG - Networking: Create request 24: (GET https://plex.tv/api/home/users).
May 06, 2022 18:00:40.530 [Javascript] INFO - Cloud: [RecentPlays] Received data, performing sync.
May 06, 2022 18:00:40.532 [Javascript] INFO - Cloud: [RecentPlays] Cloud had new data for 8827705a313d5e5e28b906eab0babaad28a2f8bd/library/metadata/396/childrenfalse
May 06, 2022 18:00:40.533 [Javascript] INFO - Discovery: There was a change to Recent Plays.
May 06, 2022 18:00:40.537 [Javascript] INFO - Cloud: [RecentPlays] Syncing complete with added: 0 deleted: 0 and dirty: 0.
May 06, 2022 18:00:40.629 [0x89ffb180] DEBUG - Networking: Completed request 23: (PUT https://plex.tv/devices/abc9b574-896f-4bc7-86eb-bf519ea0e033?Connection[][uri]=http://192.168.1.54:32500&X-Plex-Device-Name=plexamp) with code 200 (have 487 bytes) in 455 ms.
May 06, 2022 18:00:40.636 [Javascript] INFO - Companion: Advertising for GDM.
May 06, 2022 18:00:40.649 [Javascript] INFO - Companion: Listening for GDM messages.
May 06, 2022 18:00:40.649 [Javascript] INFO - Companion: Started HTTP Server on port 32500 and registered.
May 06, 2022 18:00:40.669 [0x89ffb180] DEBUG - Networking: Completed request 24: (GET https://plex.tv/api/home/users) with code 200 (have 1038 bytes) in 140 ms.
May 06, 2022 18:00:40.996 [0x537fe180] DEBUG - PQCache: Ignoring refresh as a newer one came in.
May 06, 2022 18:00:42.993 [0x89ffb180] DEBUG - Networking: Completed request 11: (GET http://192.168.1.250:32500/resources) with code -7 (have 0 bytes) in 3137 ms.
May 06, 2022 18:00:42.993 [0x89ffb180] DEBUG - Networking: Completed request 12: (GET http://192.168.1.250:32500/resources) with code -7 (have 0 bytes) in 3136 ms.
May 06, 2022 18:00:42.994 [Javascript] WARNING - DEVICE: Player connection http://192.168.1.250:32500 didn't work for pi_amp: HTTP status -7
May 06, 2022 18:00:42.994 [Javascript] WARNING - DEVICE: Connection testing failed for pi_amp
May 06, 2022 18:00:42.994 [Javascript] WARNING - DEVICE: Player connection http://192.168.1.250:32500 didn't work for plexamp: HTTP status -7
May 06, 2022 18:00:42.994 [Javascript] WARNING - DEVICE: Connection testing failed for plexamp
May 06, 2022 18:00:49.845 [Javascript] INFO - DEVICE: Finding best connection for plex 8827705a313d5e5e28b906eab0babaad28a2f8bd.
May 06, 2022 18:00:49.845 [0xa7ea5d80] DEBUG - Networking: Create request 25: (GET https://192-168-1-3.xxxxxxxxxxxxxxxxxxxxxxxxxx.plex.direct:32400/).
May 06, 2022 18:00:49.846 [0xa7ea5d80] DEBUG - Networking: Create request 26: (GET https://xx-xxx-xx-xx.xxxxxxxxxxxxxxxxxxxxxxxxxx.plex.direct:32400/).
May 06, 2022 18:00:49.938 [0x89ffb180] DEBUG - Networking: Completed request 25: (GET https://192-168-1-3.xxxxxxxxxxxxxxxxxxxxxxxxxx.plex.direct:32400/) with code 200 (have 7712 bytes) in 92 ms.
May 06, 2022 18:00:49.938 [0x89ffb180] DEBUG - Networking: Completed request 26: (GET https://xx-xxx-xx-xx.xxxxxxxxxxxxxxxxxxxxxxxxxx.plex.direct:32400/) with code 200 (have 7712 bytes) in 92 ms.
May 06, 2022 18:00:49.939 [Javascript] INFO - DEVICE: Server connection worked for plex ~ https://192-168-1-3.xxxxxxxxxxxxxxxxxxxxxxxxxx.plex.direct:32400
May 06, 2022 18:00:49.939 [Javascript] INFO - DEVICE: Reading libraries and features from plex
May 06, 2022 18:00:49.940 [0xa7ea5d80] DEBUG - Networking: Create request 27: (GET https://192-168-1-3.xxxxxxxxxxxxxxxxxxxxxxxxxx.plex.direct:32400/media/providers?includePreferences=1).
May 06, 2022 18:00:49.940 [Javascript] INFO - DEVICE: Server connection worked for plex ~ https://xx-xxx-xx-xx.xxxxxxxxxxxxxxxxxxxxxxxxxx.plex.direct:32400
May 06, 2022 18:00:50.018 [0x89ffb180] DEBUG - Networking: Completed request 27: (GET https://192-168-1-3.xxxxxxxxxxxxxxxxxxxxxxxxxx.plex.direct:32400/media/providers?includePreferences=1) with code 200 (have 36060 bytes) in 78 ms.
May 06, 2022 18:00:50.020 [Javascript] INFO - DEVICE: Found 7 libraries from plex: Home, Movies, TV Shows, Music, Baby First, Giant Bomb, Playlists
May 06, 2022 18:00:52.187 [Javascript] INFO - HTTP: Setting equalizerValues of type object to 0,0,0,0,0,0,0,0,0,0
May 06, 2022 18:00:54.765 [Javascript] INFO - DEVICE: Persisting devices because plex was dirty.
May 06, 2022 18:00:54.765 [Javascript] INFO - DEVICE: Persisting 11 devices.
May 06, 2022 18:00:54.851 [0x89ffb180] DEBUG - Networking: Completed request 5: (GET http://10.6.0.2:32500/resources) with code -28 (have 0 bytes) in 15000 ms.
May 06, 2022 18:00:54.851 [Javascript] WARNING - DEVICE: Player connection http://10.6.0.2:32500 didn't work for ALCATEL ONE TOUCH 903: HTTP status -28
May 06, 2022 18:00:54.852 [Javascript] WARNING - DEVICE: Connection testing failed for ALCATEL ONE TOUCH 903
May 06, 2022 18:00:54.852 [0x89ffb180] DEBUG - Networking: Completed request 7: (GET http://10.0.0.118:32500/resources) with code -28 (have 0 bytes) in 15000 ms.
May 06, 2022 18:00:54.853 [Javascript] WARNING - DEVICE: Player connection http://10.0.0.118:32500 didn't work for BRAVIA 4K 2015: HTTP status -28
May 06, 2022 18:00:54.853 [Javascript] WARNING - DEVICE: Connection testing failed for BRAVIA 4K 2015
May 06, 2022 18:00:54.937 [Javascript] INFO - Sync: Refreshing and completing items.
May 06, 2022 18:01:09.766 [Javascript] INFO - DEVICE: Persisting devices because ALCATEL ONE TOUCH 903 was dirty.
May 06, 2022 18:01:09.766 [Javascript] INFO - DEVICE: Persisting 11 devices.
May 06, 2022 18:01:09.940 [Javascript] INFO - Sync: Error cleaning up: ENOENT: no such file or directory, scandir '/home/pi/.local/share/Plexamp/Offline'.
May 06, 2022 18:27:41.983 [0x89ffb180] DEBUG - Networking: Completed request 15: (GET https://192-168-1-3.xxxxxxxxxxxxxxxxxxxxxxxxxx.plex.direct:32400/:/eventsource/notifications?filters=timeline&X-Plex-Token=<token>) with code -18 (have 0 bytes) in 1621926 ms.
May 06, 2022 18:27:41.986 [Javascript] WARNING - Server Activity: Connection broken to 8827705a313d5e5e28b906eab0babaad28a2f8bd, reconnecting.
May 06, 2022 18:27:55.241 [Javascript] WARNING - Server Activity: Connection broken to 8827705a313d5e5e28b906eab0babaad28a2f8bd, reconnecting.
May 06, 2022 18:28:10.242 [Javascript] INFO - Server Activity: Trying to connect to 8827705a313d5e5e28b906eab0babaad28a2f8bd.
May 06, 2022 18:28:10.242 [0xa7ea5d80] DEBUG - Networking: Create request 28: (GET https://192-168-1-3.xxxxxxxxxxxxxxxxxxxxxxxxxx.plex.direct:32400/:/eventsource/notifications?filters=timeline&X-Plex-Token=<token>).
May 06, 2022 18:28:10.280 [0x89ffb180] DEBUG - Networking: Completed request 28: (GET https://192-168-1-3.xxxxxxxxxxxxxxxxxxxxxxxxxx.plex.direct:32400/:/eventsource/notifications?filters=timeline&X-Plex-Token=<token>) with code -7 (have 0 bytes) in 37 ms.
May 06, 2022 18:28:10.281 [Javascript] WARNING - Server Activity: Connection broken to 8827705a313d5e5e28b906eab0babaad28a2f8bd, reconnecting.
May 06, 2022 18:28:25.243 [Javascript] WARNING - Server Activity: Connection broken to 8827705a313d5e5e28b906eab0babaad28a2f8bd, reconnecting.
May 06, 2022 18:28:40.244 [Javascript] INFO - Server Activity: Trying to connect to 8827705a313d5e5e28b906eab0babaad28a2f8bd.
May 06, 2022 18:28:40.245 [0xa7ea5d80] DEBUG - Networking: Create request 29: (GET https://192-168-1-3.xxxxxxxxxxxxxxxxxxxxxxxxxx.plex.direct:32400/:/eventsource/notifications?filters=timeline&X-Plex-Token=<token>).
May 06, 2022 18:28:40.248 [0x89ffb180] DEBUG - Networking: Completed request 29: (GET https://192-168-1-3.xxxxxxxxxxxxxxxxxxxxxxxxxx.plex.direct:32400/:/eventsource/notifications?filters=timeline&X-Plex-Token=<token>) with code -7 (have 0 bytes) in 2 ms.
May 06, 2022 18:28:40.249 [Javascript] WARNING - Server Activity: Connection broken to 8827705a313d5e5e28b906eab0babaad28a2f8bd, reconnecting.
May 06, 2022 18:28:55.244 [Javascript] WARNING - Server Activity: Connection broken to 8827705a313d5e5e28b906eab0babaad28a2f8bd, reconnecting.
May 06, 2022 18:29:10.245 [Javascript] INFO - Server Activity: Trying to connect to 8827705a313d5e5e28b906eab0babaad28a2f8bd.
May 06, 2022 18:29:10.246 [0xa7ea5d80] DEBUG - Networking: Create request 30: (GET https://192-168-1-3.xxxxxxxxxxxxxxxxxxxxxxxxxx.plex.direct:32400/:/eventsource/notifications?filters=timeline&X-Plex-Token=<token>).
May 06, 2022 18:29:10.413 [0x89ffb180] DEBUG - Networking: Completed request 30: (GET https://192-168-1-3.xxxxxxxxxxxxxxxxxxxxxxxxxx.plex.direct:32400/:/eventsource/notifications?filters=timeline&X-Plex-Token=<token>) with code -7 (have 0 bytes) in 166 ms.
May 06, 2022 18:29:10.414 [Javascript] WARNING - Server Activity: Connection broken to 8827705a313d5e5e28b906eab0babaad28a2f8bd, reconnecting.
May 06, 2022 18:29:25.246 [Javascript] WARNING - Server Activity: Connection broken to 8827705a313d5e5e28b906eab0babaad28a2f8bd, reconnecting.
4

that log doesn’t have any playback attempts in it.

5

Thats fancy, and makes sense. I did access the webgui and clicked play on a song. With that information, I stopped service, deleted the logs, restarted the service, logged back in, played a song, and it still is not attempting to play anything. The logs are identical. I will nuke this install and try a third time. Ill report back with success or failure. Thanks for looking at this.

6

I do not know what fixed it but the third install has worked. I did change out the memory card and I did not update Raspi OS as I did the previous two attempts. Again thank you for looking at the logs.

7

Glad to hear it’s working now.

8

I’m also having this problem running beta 3 on a Pi 4 with an up to date, fresh 64 bit Bullseye OS install. Any troubleshooting steps besides reinstall? Also, where are the full logs located?

9

Log for debugging is located in: ~/.cache/Plexamp/log/Plexamp.log,

10

Thanks, pulled the full logs. These logs were taken from a fresh start of the service, then attempting to play a single file that I confirmed works on other devices. Looks like there are some server connection errors at the end of the log, where the request is using a weird IP. The correct Plex Server IP is 192.168.1.22, and there are working requests using that IP earlier in the log.

Not sure how to troubleshoot from here, hopefully someone can help me out.

There’s also a mention of my Plex server being ‘dirty’ in the logs. I don’ think it’s related to this issue, but what does that mean exactly?

May 09, 2022 09:53:26.748 [Javascript] INFO - Starting Plexamp 4.2.2-beta.5 - linux 5.15.32-v8+
May 09, 2022 09:53:26.750 [Javascript] INFO - METRICS: Initializing.
May 09, 2022 09:53:26.753 [Javascript] INFO - USER: Refreshing users.
May 09, 2022 09:53:26.754 [Javascript] INFO - Autoupdate: Identifier desktop should check: false.
May 09, 2022 09:53:26.754 [Javascript] INFO - DEVICE: Initializing device manager.
May 09, 2022 09:53:26.760 [Javascript] INFO - DEVICE: Loaded 7 devices.
May 09, 2022 09:53:26.763 [0xb1a3a040] DEBUG - Networking: Create request 1: (GET https://plex.tv/api/users).
May 09, 2022 09:53:26.765 [Javascript] INFO - DEVICE: Initializing manager.
May 09, 2022 09:53:26.766 [Javascript] INFO - DEVICE: Fetching latest provider list from cloud.
May 09, 2022 09:53:26.768 [Javascript] INFO - DEVICE: Fetching latest list from cloud.
May 09, 2022 09:53:26.769 [Javascript] INFO - DEVICE: Fetching latest cloud player list from https://sonos.plex.tv
May 09, 2022 09:53:26.769 [Javascript] INFO - DEVICE: Starting connection test.
May 09, 2022 09:53:26.771 [0xb1a3a040] DEBUG - Networking: Create request 2: (GET https://plex.tv/media/providers).
May 09, 2022 09:53:26.780 [0xb1a3a040] DEBUG - Networking: Create request 3: (GET https://plex.tv/api/resources?includeHttps=1&includeRelay=1).
May 09, 2022 09:53:26.780 [0xb1a3a040] DEBUG - Networking: Create request 4: (GET https://sonos.plex.tv/resources).
May 09, 2022 09:53:26.780 [Javascript] INFO - DEVICE: Fast-path connection testing.
May 09, 2022 09:53:26.782 [Javascript] INFO - DEVICE: Finding best connection for Upstairs Living TV e4588abf0c29f3ef-com-plexapp-android.
May 09, 2022 09:53:26.784 [0xb1a3a040] DEBUG - Networking: Create request 5: (GET http://192.168.107.14:32500/resources).
May 09, 2022 09:53:26.784 [Javascript] INFO - DEVICE: Finding best connection for Living Room TV 9f73cc351fd29808-com-plexapp-android.
May 09, 2022 09:53:26.785 [0xb1a3a040] DEBUG - Networking: Create request 6: (GET http://192.168.107.13:32500/resources).
May 09, 2022 09:53:26.785 [Javascript] INFO - DEVICE: Finding best connection for Galaxy Z Fold3 5G 01eecdf9e7515786-com-plexapp-android.
May 09, 2022 09:53:26.785 [0xb1a3a040] DEBUG - Networking: Create request 7: (GET http://10.1.1.37:32500/resources).
May 09, 2022 09:53:26.786 [Javascript] INFO - DEVICE: Finding best connection for Android f47e27bf-8a6a-47c2-8cfe-22223b5d7bf2.
May 09, 2022 09:53:26.786 [0xb1a3a040] DEBUG - Networking: Create request 8: (GET http://192.168.1.114:42609/resources).
May 09, 2022 09:53:26.786 [Javascript] INFO - DEVICE: Finding best connection for Office 2bfa8d86-4015-4744-8071-679f437e0a40.
May 09, 2022 09:53:26.787 [0xb1a3a040] DEBUG - Networking: Create request 9: (GET http://192.168.1.50:32500/resources).
May 09, 2022 09:53:26.787 [Javascript] INFO - DEVICE: Finding best connection for rpiserver 27762551-4f25-4b25-9361-0b9548d80033.
May 09, 2022 09:53:26.787 [0xb1a3a040] DEBUG - Networking: Create request 10: (GET http://192.168.1.50:32500/resources).
May 09, 2022 09:53:26.787 [0x93fff180] DEBUG - Networking: Completed request 9: (GET http://192.168.1.50:32500/resources) with code -7 (have 0 bytes) in 0 ms.
May 09, 2022 09:53:26.788 [Javascript] INFO - DEVICE: Persisting 7 devices.
May 09, 2022 09:53:26.788 [0x93fff180] DEBUG - Networking: Completed request 10: (GET http://192.168.1.50:32500/resources) with code -7 (have 0 bytes) in 0 ms.
May 09, 2022 09:53:26.830 [Javascript] INFO - DEVICE: Initialization finished in 65ms.
May 09, 2022 09:53:26.830 [0xb1a3a040] DEBUG - Networking: Create request 11: (GET https://plex.tv/api/v2/user/privacy.json).
May 09, 2022 09:53:26.832 [Javascript] INFO - ACCOUNT: Refreshing data.
May 09, 2022 09:53:26.835 [0xb1a3a040] DEBUG - Networking: Create request 12: (GET https://plex.tv/users/account.json?X-Plex-Device-Name=rpiserver).
May 09, 2022 09:53:26.848 [Javascript] WARNING - DEVICE: Player connection http://192.168.1.50:32500 didn't work for Office: HTTP status -7
May 09, 2022 09:53:26.849 [Javascript] WARNING - DEVICE: Connection testing failed for Office
May 09, 2022 09:53:26.849 [Javascript] WARNING - DEVICE: Player connection http://192.168.1.50:32500 didn't work for rpiserver: HTTP status -7
May 09, 2022 09:53:26.849 [Javascript] WARNING - DEVICE: Connection testing failed for rpiserver
May 09, 2022 09:53:26.852 [Javascript] INFO - App: Device manager, settings and cache initialized in 99ms.
May 09, 2022 09:53:26.854 [Javascript] INFO - Sync: Loaded in 1ms.
May 09, 2022 09:53:26.854 [Javascript] INFO - App: Offline store initialized in 2ms.
May 09, 2022 09:53:26.858 [Javascript] INFO - Audio: Initializing.
May 09, 2022 09:53:26.859 [Javascript] INFO - Audio: Binding settings.
May 09, 2022 09:53:26.859 [Javascript] INFO - Audio: Setting player info.
May 09, 2022 09:53:26.860 [0xaa420180] DEBUG - BASS: Starting up.
May 09, 2022 09:53:26.860 [0xaa420180] DEBUG - BASS: Created bass audio renderer.
May 09, 2022 09:53:26.880 [0xaa420180] INFO - BASS: Device 1: Default - enabled default - sample rates: () - active 0/0
May 09, 2022 09:53:26.880 [0xaa420180] INFO - BASS: Device 2: snd_rpi_hifiberry_digi: HiFiBerry Digi+ Pro HiFi wm8804-spdif-0 - enabled - sample rates: () - active 0/0
May 09, 2022 09:53:26.880 [0xaa420180] INFO - BASS: Device 3: vc4-hdmi-1: MAI PCM i2s-hifi-0 - enabled - sample rates: () - active 0/0
May 09, 2022 09:53:26.880 [0xaa420180] INFO - BASS: Device 4: IEC958 (S/PDIF) Digital Audio Output - enabled - sample rates: () - active 0/0
May 09, 2022 09:53:26.880 [0xaa420180] DEBUG - BASS: Using plugin path '/home/Name/plexamp/treble/'.
May 09, 2022 09:53:26.880 [0xaa420180] DEBUG - BASS: Reloading ourselves for symbol visibility.
May 09, 2022 09:53:26.880 [0xaa420180] INFO - BASS: Loaded AAC plug-in version 2.4.5.11
May 09, 2022 09:53:26.880 [0xaa420180] INFO - BASS: Loaded ALAC plug-in version 2.4.0.3
May 09, 2022 09:53:26.880 [0xaa420180] INFO - BASS: Loaded FLAC plug-in version 2.4.4.5
May 09, 2022 09:53:26.881 [0xaa420180] INFO - BASS: Loaded OPUS plug-in version 2.4.2.1
May 09, 2022 09:53:26.881 [0xaa420180] INFO - BASS: Loaded APE plug-in version 2.4.2.0
May 09, 2022 09:53:26.881 [0xaa420180] INFO - BASS: Loaded MPC plug-in version 2.4.1.3
May 09, 2022 09:53:26.881 [0xaa420180] INFO - BASS: Loaded DSD plug-in version 2.4.1.2
May 09, 2022 09:53:26.881 [0xaa420180] INFO - BASS: Core version 2.4.16.7
May 09, 2022 09:53:26.881 [0xaa420180] INFO - BASS: Mixer version 2.4.11.1
May 09, 2022 09:53:26.881 [0xaa420180] INFO - BASS: FX version 2.4.12.1
May 09, 2022 09:53:26.881 [0xaa420180] INFO - BASS: Curl version is 7.83.0 (protocols: dict file http https mqtt; ssl: OpenSSL/1.1.1n; libz: 1.2.11; DNS: threaded).
May 09, 2022 09:53:26.881 [0xaa420180] DEBUG - BASS: Setting audio interface:  -> iec958.
May 09, 2022 09:53:26.881 [0xaa420180] DEBUG - BASS: Resetting device (soft: 0, initialized: 0).
May 09, 2022 09:53:26.888 [Javascript] INFO - App: Player initialized in 31ms.
May 09, 2022 09:53:26.892 [Javascript] INFO - App: Waiting for rest of stores to initialize.
May 09, 2022 09:53:26.894 [Javascript] INFO - Server Activity: Connecting based on switch.
May 09, 2022 09:53:26.895 [Javascript] INFO - Server Activity: Trying to connect to 073e131472a601d945dbb1357e059ccd55c34980.
May 09, 2022 09:53:26.896 [0xb1a3a040] DEBUG - Networking: Create request 13: (GET https://192-168-1-22.*****.plex.direct:32400/:/eventsource/notifications?filters=timeline&X-Plex-Token=<token>).
May 09, 2022 09:53:26.903 [Javascript] INFO - Player: Initializing with state null
May 09, 2022 09:53:26.905 [Javascript] INFO - App: Stopping activity recognition.
May 09, 2022 09:53:26.909 [Javascript] INFO - Network changed: type is ethernet effectiveType is undefined -> 2
May 09, 2022 09:53:26.909 [0xb1a3a040] INFO - BASS: Network switched to 2.
May 09, 2022 09:53:26.909 [Javascript] INFO - App: Network is connected, but type changed to 2, so doing preemptive connection testing on selected server.
May 09, 2022 09:53:26.910 [Javascript] INFO - DEVICE: Finding best connection for Name's Plex Server 073e131472a601d945dbb1357e059ccd55c34980.
May 09, 2022 09:53:26.910 [0xb1a3a040] DEBUG - Networking: Create request 14: (GET https://192-168-1-22.*****.plex.direct:32400/).
May 09, 2022 09:53:26.911 [0xb1a3a040] DEBUG - Networking: Create request 15: (GET https://172-19-0-1.*****.plex.direct:32400/).
May 09, 2022 09:53:26.911 [0xb1a3a040] DEBUG - Networking: Create request 16: (GET https://125-253-20-23.*****.plex.direct:32400/).
May 09, 2022 09:53:26.912 [Javascript] INFO - Player: Sending state changed [A]  -  (0/0) in state stopped with artwork false.
May 09, 2022 09:53:26.913 [Javascript] INFO - Player: Restoring player route of local with network state 2.
May 09, 2022 09:53:26.935 [Javascript] INFO - ViewState: Error loading from storage. Unexpected token u in JSON at position 0
May 09, 2022 09:53:26.944 [Javascript] INFO - Cloud: [RecentPlays] Loading from storage 20 items and 0 deleted.
May 09, 2022 09:53:26.946 [Javascript] INFO - Cloud: [RecentPlays] Syncing.
May 09, 2022 09:53:26.946 [0xb1a3a040] DEBUG - Networking: Create request 17: (GET https://plex.tv/api/v2/user/settings?uuid=1853af602ce07414&key=RecentPlays).
May 09, 2022 09:53:26.947 [Javascript] INFO - App: Stores initialized in 59ms.
May 09, 2022 09:53:26.948 [Javascript] INFO - App: Stores all initialized.
May 09, 2022 09:53:26.948 [Javascript] INFO - Companion: Initializing.
May 09, 2022 09:53:26.949 [Javascript] INFO - Companion: Network type is 2.
May 09, 2022 09:53:26.950 [Javascript] INFO - Companion: attempting to connect to pubsub, started undefined connected false
May 09, 2022 09:53:26.950 [0xb1a3a040] DEBUG - Networking: Create request 18: (GET https://pubsub.plex.tv/sub/eventsource/11765374/27762551-4f25-4b25-9361-0b9548d80033?X-Plex-Token=<token>).
May 09, 2022 09:53:26.952 [Javascript] INFO - Companion: Network type is 2 and enabled is true.
May 09, 2022 09:53:26.953 [Javascript] INFO - Discovery: Refresh based on server/library switch 073e131472a601d945dbb1357e059ccd55c34980 /library/sections/5.
May 09, 2022 09:53:26.955 [Javascript] INFO - Discovery: Fetching hubs for library /library/sections/5 server 073e131472a601d945dbb1357e059ccd55c34980 refreshing from cloud false.
May 09, 2022 09:53:26.960 [0xb1a3a040] DEBUG - Networking: Create request 19: (GET https://192-168-1-22.*****.plex.direct:32400/hubs/sections/5?count=4&includeExternalMetadata=1&includeMyMixes=1&inclu>
May 09, 2022 09:53:26.961 [0xb1a3a040] DEBUG - Networking: Create request 20: (GET https://192-168-1-22.*****.plex.direct:32400/library/sections/5/all?type=10&sort=lastViewedAt:desc&group=guid&viewCou>
May 09, 2022 09:53:26.965 [Javascript] INFO - Companion: Attempting to start HTTP Server on port 32500.
May 09, 2022 09:53:26.966 [0x4b7fe180] DEBUG - HTTP: Serving on port 32500.
May 09, 2022 09:53:26.974 [0x93fff180] DEBUG - Networking: Completed request 14: (GET https://192-168-1-22.*****.plex.direct:32400/) with code 200 (have 7612 bytes) in 63 ms.
May 09, 2022 09:53:26.974 [0x93fff180] DEBUG - Networking: Completed request 16: (GET https://125-253-20-23.*****.plex.direct:32400/) with code 200 (have 7612 bytes) in 63 ms.
May 09, 2022 09:53:26.975 [Javascript] INFO - Companion: Registering device at 192.168.1.50:32500.
May 09, 2022 09:53:26.976 [0xb1a3a040] DEBUG - Networking: Create request 21: (PUT https://plex.tv/devices/27762551-4f25-4b25-9361-0b9548d80033?Connection[][uri]=http://192.168.1.50:32500&X-Plex-Device-Name=rpiserver).
May 09, 2022 09:53:26.977 [Javascript] INFO - DEVICE: Server connection worked for Name's Plex Server ~ https://192-168-1-22.*****.plex.direct:32400
May 09, 2022 09:53:26.979 [Javascript] INFO - DEVICE: Reading libraries and features from Name's Plex Server
May 09, 2022 09:53:26.979 [0xb1a3a040] DEBUG - Networking: Create request 22: (GET https://192-168-1-22.*****.plex.direct:32400/media/providers?includePreferences=1).
May 09, 2022 09:53:26.980 [Javascript] INFO - DEVICE: Server connection worked for Name's Plex Server ~ https://125-253-20-23.*****.plex.direct:32400
May 09, 2022 09:53:26.995 [0x93fff180] DEBUG - Networking: Completed request 19: (GET https://192-168-1-22.*****.plex.direct:32400/hubs/sections/5?count=4&includeExternalMetadata=1&includeMyMixes=1&in>
May 09, 2022 09:53:27.019 [0x93fff180] DEBUG - Networking: Completed request 22: (GET https://192-168-1-22.*****.plex.direct:32400/media/providers?includePreferences=1) with code 200 (have 31626 bytes>
May 09, 2022 09:53:27.022 [Javascript] INFO - DEVICE: Found 7 libraries from Name's Plex Server: Home, Movies, TV Shows, Music, Photos, Videos, Playlists
May 09, 2022 09:53:27.143 [0x93fff180] DEBUG - Networking: Completed request 20: (GET https://192-168-1-22.*****.plex.direct:32400/library/sections/5/all?type=10&sort=lastViewedAt:desc&group=guid&view>
May 09, 2022 09:53:27.155 [Javascript] INFO - Discovery: Setting 8 hubs from Name's Plex Server.
May 09, 2022 09:53:27.479 [0x93fff180] DEBUG - Networking: Completed request 4: (GET https://sonos.plex.tv/resources) with code 403 (have 9 bytes) in 699 ms.
May 09, 2022 09:53:27.484 [Javascript] WARNING - DEVICE: Error loading cloud players from plex.tv HTTP status 403
May 09, 2022 09:53:27.601 [0x93fff180] DEBUG - Networking: Completed request 2: (GET https://plex.tv/media/providers) with code 200 (have 2 bytes) in 830 ms.
May 09, 2022 09:53:27.613 [0x93fff180] DEBUG - Networking: Completed request 1: (GET https://plex.tv/api/users) with code 200 (have 2680 bytes) in 848 ms.
May 09, 2022 09:53:27.613 [0x93fff180] DEBUG - Networking: Completed request 11: (GET https://plex.tv/api/v2/user/privacy.json) with code 200 (have 6766 bytes) in 782 ms.
May 09, 2022 09:53:27.631 [0x93fff180] DEBUG - Networking: Completed request 3: (GET https://plex.tv/api/resources?includeHttps=1&includeRelay=1) with code 200 (have 4050 bytes) in 850 ms.
May 09, 2022 09:53:27.636 [Javascript] INFO - USER: Loaded 4 users
May 09, 2022 09:53:27.636 [Javascript] INFO - METRICS: Saving latest cloud settings for metrics.
May 09, 2022 09:53:27.666 [Javascript] INFO - DEVICE: Fetched 7 devices from the cloud.
May 09, 2022 09:53:27.673 [Javascript] INFO - METRICS: Error loading from storage. Unexpected token u in JSON at position 0
May 09, 2022 09:53:27.673 [Javascript] INFO - METRICS: Loaded 0 events from storage.
May 09, 2022 09:53:27.714 [0x93fff180] DEBUG - Networking: Completed request 12: (GET https://plex.tv/users/account.json?X-Plex-Device-Name=rpiserver) with code 200 (have 2071 bytes) in 879 ms.
May 09, 2022 09:53:27.773 [0xb1a3a040] DEBUG - Networking: Create request 23: (GET https://plex.tv/api/home/users).
May 09, 2022 09:53:27.798 [0x93fff180] DEBUG - Networking: Completed request 21: (PUT https://plex.tv/devices/27762551-4f25-4b25-9361-0b9548d80033?Connection[][uri]=http://192.168.1.50:32500&X-Plex-Device-Name=rpiserver) with c>
May 09, 2022 09:53:27.802 [Javascript] INFO - Companion: Advertising for GDM.
May 09, 2022 09:53:27.807 [Javascript] INFO - Companion: Listening for GDM messages.
May 09, 2022 09:53:27.807 [Javascript] INFO - Companion: Started HTTP Server on port 32500 and registered.
May 09, 2022 09:53:27.882 [0x4bfff180] DEBUG - PQCache: Ignoring refresh as a newer one came in.
May 09, 2022 09:53:27.901 [0x93fff180] DEBUG - Networking: Completed request 17: (GET https://plex.tv/api/v2/user/settings?uuid=1853af602ce07414&key=RecentPlays) with code 200 (have 10226 bytes) in 954 ms.
May 09, 2022 09:53:27.902 [Javascript] INFO - Cloud: [RecentPlays] Received data, performing sync.
May 09, 2022 09:53:27.903 [Javascript] INFO - Cloud: [RecentPlays] Cloud had new data for 073e131472a601d945dbb1357e059ccd55c34980/library/metadata/85087false
May 09, 2022 09:53:27.904 [Javascript] INFO - Discovery: There was a change to Recent Plays.
May 09, 2022 09:53:27.908 [Javascript] INFO - Cloud: [RecentPlays] Syncing complete with added: 0 deleted: 0 and dirty: 0.
May 09, 2022 09:53:28.034 [0x93fff180] DEBUG - Networking: Completed request 23: (GET https://plex.tv/api/home/users) with code 200 (have 477 bytes) in 260 ms.
May 09, 2022 09:53:34.956 [Javascript] INFO - Companion: Resources requested by 192.168.1.136.
May 09, 2022 09:53:34.968 [Javascript] INFO - HTTP: Setting equalizerValues of type object to 0,0,0,0,0,0,0,0,0,0
May 09, 2022 09:53:36.781 [Javascript] INFO - DEVICE: Finding best connection for Name's Plex Server 073e131472a601d945dbb1357e059ccd55c34980.
May 09, 2022 09:53:36.782 [0xb1a3a040] DEBUG - Networking: Create request 24: (GET https://192-168-1-22.*****.plex.direct:32400/).
May 09, 2022 09:53:36.783 [0xb1a3a040] DEBUG - Networking: Create request 25: (GET https://172-19-0-1.*****.plex.direct:32400/).
May 09, 2022 09:53:36.783 [0xb1a3a040] DEBUG - Networking: Create request 26: (GET https://125-253-20-23.*****.plex.direct:32400/).
May 09, 2022 09:53:36.785 [0x93fff180] DEBUG - Networking: Completed request 24: (GET https://192-168-1-22.*****.plex.direct:32400/) with code 200 (have 7612 bytes) in 2 ms.
May 09, 2022 09:53:36.786 [Javascript] INFO - DEVICE: Server connection worked for Name's Plex Server ~ https://192-168-1-22.*****.plex.direct:32400
May 09, 2022 09:53:36.786 [0x93fff180] DEBUG - Networking: Completed request 26: (GET https://125-253-20-23.*****.plex.direct:32400/) with code 200 (have 7612 bytes) in 2 ms.
May 09, 2022 09:53:36.786 [Javascript] INFO - DEVICE: Reading libraries and features from Name's Plex Server
May 09, 2022 09:53:36.786 [0xb1a3a040] DEBUG - Networking: Create request 27: (GET https://192-168-1-22.*****.plex.direct:32400/media/providers?includePreferences=1).
May 09, 2022 09:53:36.787 [Javascript] INFO - DEVICE: Server connection worked for Name's Plex Server ~ https://125-253-20-23.*****.plex.direct:32400
May 09, 2022 09:53:36.813 [0x93fff180] DEBUG - Networking: Completed request 27: (GET https://192-168-1-22.*****.plex.direct:32400/media/providers?includePreferences=1) with code 200 (have 31626 bytes>
May 09, 2022 09:53:36.815 [Javascript] INFO - DEVICE: Found 7 libraries from Name's Plex Server: Home, Movies, TV Shows, Music, Photos, Videos, Playlists
May 09, 2022 09:53:41.722 [Javascript] INFO - DEVICE: Persisting devices because Name's Plex Server was dirty.
May 09, 2022 09:53:41.722 [Javascript] INFO - DEVICE: Persisting 7 devices.
May 09, 2022 09:53:41.785 [0x93fff180] DEBUG - Networking: Completed request 5: (GET http://192.168.107.14:32500/resources) with code -28 (have 0 bytes) in 15001 ms.
May 09, 2022 09:53:41.785 [0x93fff180] DEBUG - Networking: Completed request 6: (GET http://192.168.107.13:32500/resources) with code -28 (have 0 bytes) in 15000 ms.
May 09, 2022 09:53:41.785 [0x93fff180] DEBUG - Networking: Completed request 7: (GET http://10.1.1.37:32500/resources) with code -28 (have 0 bytes) in 14999 ms.
May 09, 2022 09:53:41.786 [Javascript] WARNING - DEVICE: Player connection http://192.168.107.14:32500 didn't work for Upstairs Living TV: HTTP status -28
May 09, 2022 09:53:41.787 [Javascript] WARNING - DEVICE: Connection testing failed for Upstairs Living TV
May 09, 2022 09:53:41.787 [0x93fff180] DEBUG - Networking: Completed request 8: (GET http://192.168.1.114:42609/resources) with code -28 (have 0 bytes) in 15000 ms.
May 09, 2022 09:53:41.787 [Javascript] WARNING - DEVICE: Player connection http://192.168.107.13:32500 didn't work for Living Room TV: HTTP status -28
May 09, 2022 09:53:41.787 [Javascript] WARNING - DEVICE: Connection testing failed for Living Room TV
May 09, 2022 09:53:41.788 [Javascript] WARNING - DEVICE: Player connection http://10.1.1.37:32500 didn't work for Galaxy Z Fold3 5G: HTTP status -28
May 09, 2022 09:53:41.788 [Javascript] WARNING - DEVICE: Connection testing failed for Galaxy Z Fold3 5G
May 09, 2022 09:53:41.788 [Javascript] WARNING - DEVICE: Player connection http://192.168.1.114:42609 didn't work for Android: HTTP status -28
May 09, 2022 09:53:41.788 [Javascript] WARNING - DEVICE: Connection testing failed for Android
May 09, 2022 09:53:41.856 [Javascript] INFO - Sync: Refreshing and completing items.
May 09, 2022 09:53:41.918 [0x93fff180] DEBUG - Networking: Completed request 15: (GET https://172-19-0-1.*****.plex.direct:32400/) with code -28 (have 0 bytes) in 15007 ms.
May 09, 2022 09:53:41.919 [Javascript] WARNING - DEVICE: Server connection https://172-19-0-1.*****.plex.direct:32400 didn't work for Name's Plex Server: HTTP status -28
May 09, 2022 09:53:51.783 [0x93fff180] DEBUG - Networking: Completed request 25: (GET https://172-19-0-1.*****.plex.direct:32400/) with code -28 (have 0 bytes) in 15000 ms.
May 09, 2022 09:53:51.784 [Javascript] WARNING - DEVICE: Server connection https://172-19-0-1.*****.plex.direct:32400 didn't work for Name's Plex Server: HTTP status -28
May 09, 2022 09:53:56.727 [Javascript] INFO - DEVICE: Persisting devices because Upstairs Living TV was dirty.
May 09, 2022 09:53:56.727 [Javascript] INFO - DEVICE: Persisting 7 devices.
11

there is no play attempt in there. logs possibly truncated?

12

Thanks for your reply. Just checked by performing the same sequence (restart service, attempt to play a track), but this time also reloaded the web GUI after waiting a minute or so on the spinning wheel, went into settings and changed the audio device just to get something in the log, which showed up. So they’re not being truncated. New log below:

May 09, 2022 10:50:37.115 [Javascript] INFO - Starting Plexamp 4.2.2-beta.5 - linux 5.15.32-v8+
May 09, 2022 10:50:37.123 [Javascript] INFO - METRICS: Initializing.
May 09, 2022 10:50:37.126 [Javascript] INFO - USER: Refreshing users.
May 09, 2022 10:50:37.128 [Javascript] INFO - Autoupdate: Identifier desktop should check: false.
May 09, 2022 10:50:37.128 [Javascript] INFO - DEVICE: Initializing device manager.
May 09, 2022 10:50:37.135 [Javascript] INFO - DEVICE: Loaded 7 devices.
May 09, 2022 10:50:37.145 [0xbeadf040] DEBUG - Networking: Create request 1: (GET https://plex.tv/api/users).
May 09, 2022 10:50:37.146 [Javascript] INFO - DEVICE: Initializing manager.
May 09, 2022 10:50:37.148 [Javascript] INFO - DEVICE: Fetching latest provider list from cloud.
May 09, 2022 10:50:37.149 [0xa551c180] DEBUG - Networking: Completed request 1: (GET https://plex.tv/api/users) with code -6 (have 0 bytes) in 2 ms.
May 09, 2022 10:50:37.149 [Javascript] INFO - DEVICE: Fetching latest list from cloud.
May 09, 2022 10:50:37.151 [Javascript] INFO - DEVICE: Fetching latest cloud player list from https://sonos.plex.tv
May 09, 2022 10:50:37.151 [Javascript] INFO - DEVICE: Starting connection test.
May 09, 2022 10:50:37.153 [0xbeadf040] DEBUG - Networking: Create request 2: (GET https://plex.tv/media/providers).
May 09, 2022 10:50:37.153 [0xbeadf040] DEBUG - Networking: Create request 3: (GET https://plex.tv/api/resources?includeHttps=1&includeRelay=1).
May 09, 2022 10:50:37.154 [0xbeadf040] DEBUG - Networking: Create request 4: (GET https://sonos.plex.tv/resources).
May 09, 2022 10:50:37.154 [0xa551c180] DEBUG - Networking: Completed request 2: (GET https://plex.tv/media/providers) with code -6 (have 0 bytes) in 0 ms.
May 09, 2022 10:50:37.154 [Javascript] INFO - DEVICE: Fast-path connection testing.
May 09, 2022 10:50:37.154 [0xa551c180] DEBUG - Networking: Completed request 3: (GET https://plex.tv/api/resources?includeHttps=1&includeRelay=1) with code -6 (have 0 bytes) in 1 ms.
May 09, 2022 10:50:37.155 [0xa551c180] DEBUG - Networking: Completed request 4: (GET https://sonos.plex.tv/resources) with code -6 (have 0 bytes) in 0 ms.
May 09, 2022 10:50:37.156 [Javascript] INFO - DEVICE: Finding best connection for Upstairs Living TV e4588abf0c29f3ef-com-plexapp-android.
May 09, 2022 10:50:37.158 [0xbeadf040] DEBUG - Networking: Create request 5: (GET http://192.168.107.14:32500/resources).
May 09, 2022 10:50:37.159 [0xa551c180] DEBUG - Networking: Completed request 5: (GET http://192.168.107.14:32500/resources) with code -7 (have 0 bytes) in 0 ms.
May 09, 2022 10:50:37.166 [Javascript] INFO - DEVICE: Finding best connection for Living Room TV 9f73cc351fd29808-com-plexapp-android.
May 09, 2022 10:50:37.167 [0xbeadf040] DEBUG - Networking: Create request 6: (GET http://192.168.107.13:32500/resources).
May 09, 2022 10:50:37.167 [0xa551c180] DEBUG - Networking: Completed request 6: (GET http://192.168.107.13:32500/resources) with code -7 (have 0 bytes) in 0 ms.
May 09, 2022 10:50:37.167 [Javascript] INFO - DEVICE: Finding best connection for Galaxy Z Fold3 5G 01eecdf9e7515786-com-plexapp-android.
May 09, 2022 10:50:37.168 [0xbeadf040] DEBUG - Networking: Create request 7: (GET http://10.1.1.37:32500/resources).
May 09, 2022 10:50:37.168 [0xa551c180] DEBUG - Networking: Completed request 7: (GET http://10.1.1.37:32500/resources) with code -7 (have 0 bytes) in 0 ms.
May 09, 2022 10:50:37.169 [Javascript] INFO - DEVICE: Finding best connection for Android f47e27bf-8a6a-47c2-8cfe-22223b5d7bf2.
May 09, 2022 10:50:37.169 [0xbeadf040] DEBUG - Networking: Create request 8: (GET http://192.168.1.114:42609/resources).
May 09, 2022 10:50:37.169 [0xa551c180] DEBUG - Networking: Completed request 8: (GET http://192.168.1.114:42609/resources) with code -7 (have 0 bytes) in 0 ms.
May 09, 2022 10:50:37.169 [Javascript] INFO - DEVICE: Finding best connection for Office 2bfa8d86-4015-4744-8071-679f437e0a40.
May 09, 2022 10:50:37.170 [0xbeadf040] DEBUG - Networking: Create request 9: (GET http://192.168.1.50:32500/resources).
May 09, 2022 10:50:37.170 [0xa551c180] DEBUG - Networking: Completed request 9: (GET http://192.168.1.50:32500/resources) with code -7 (have 0 bytes) in 0 ms.
May 09, 2022 10:50:37.170 [Javascript] INFO - DEVICE: Finding best connection for rpiserver 27762551-4f25-4b25-9361-0b9548d80033.
May 09, 2022 10:50:37.171 [0xbeadf040] DEBUG - Networking: Create request 10: (GET http://192.168.1.50:32500/resources).
May 09, 2022 10:50:37.171 [0xa551c180] DEBUG - Networking: Completed request 10: (GET http://192.168.1.50:32500/resources) with code -7 (have 0 bytes) in 0 ms.
May 09, 2022 10:50:37.172 [Javascript] INFO - DEVICE: Persisting 7 devices.
May 09, 2022 10:50:37.183 [Javascript] INFO - DEVICE: Initialization finished in 37ms.
May 09, 2022 10:50:37.184 [0xbeadf040] DEBUG - Networking: Create request 11: (GET https://plex.tv/api/v2/user/privacy.json).
May 09, 2022 10:50:37.185 [0xa551c180] DEBUG - Networking: Completed request 11: (GET https://plex.tv/api/v2/user/privacy.json) with code -6 (have 0 bytes) in 0 ms.
May 09, 2022 10:50:37.188 [Javascript] INFO - ACCOUNT: Refreshing data.
May 09, 2022 10:50:37.192 [0xbeadf040] DEBUG - Networking: Create request 12: (GET https://plex.tv/users/account.json?X-Plex-Device-Name=rpiserver).
May 09, 2022 10:50:37.193 [0xa551c180] DEBUG - Networking: Completed request 12: (GET https://plex.tv/users/account.json?X-Plex-Device-Name=rpiserver) with code -6 (have 0 bytes) in 0 ms.
May 09, 2022 10:50:37.207 [Javascript] WARNING - USER: Error refreshing user data:  HTTP status -6
May 09, 2022 10:50:37.207 [Javascript] INFO - USER: Loaded 4 users
May 09, 2022 10:50:37.212 [Javascript] WARNING - DEVICE: Error loading media providers from plex.tv {
  message: 'HTTP status -6',
  verb: 'get',
  response: {
    id: 2,
    status: -6,
    statusText: "Couldn't resolve host name",
    bytesWritten: 0,
    data: '',
    headers: {}
  }
}
May 09, 2022 10:50:37.213 [Javascript] WARNING - DEVICE: Error loading resources from plex.tv {
  message: 'HTTP status -6',
  verb: 'get',
  response: {
    id: 3,
    status: -6,
    statusText: "Couldn't resolve host name",
    bytesWritten: 0,
    data: '',
    headers: {}
  }
}
May 09, 2022 10:50:37.213 [Javascript] WARNING - DEVICE: Error loading cloud players from plex.tv HTTP status -6
May 09, 2022 10:50:37.214 [Javascript] WARNING - DEVICE: Error loading providers or resources, not merging.
May 09, 2022 10:50:37.214 [Javascript] WARNING - DEVICE: Player connection http://192.168.107.14:32500 didn't work for Upstairs Living TV: HTTP status -7
May 09, 2022 10:50:37.214 [Javascript] WARNING - DEVICE: Connection testing failed for Upstairs Living TV
May 09, 2022 10:50:37.214 [Javascript] WARNING - DEVICE: Player connection http://192.168.107.13:32500 didn't work for Living Room TV: HTTP status -7
May 09, 2022 10:50:37.214 [Javascript] WARNING - DEVICE: Connection testing failed for Living Room TV
May 09, 2022 10:50:37.215 [Javascript] WARNING - DEVICE: Player connection http://10.1.1.37:32500 didn't work for Galaxy Z Fold3 5G: HTTP status -7
May 09, 2022 10:50:37.215 [Javascript] WARNING - DEVICE: Connection testing failed for Galaxy Z Fold3 5G
May 09, 2022 10:50:37.215 [Javascript] WARNING - DEVICE: Player connection http://192.168.1.114:42609 didn't work for Android: HTTP status -7
May 09, 2022 10:50:37.215 [Javascript] WARNING - DEVICE: Connection testing failed for Android
May 09, 2022 10:50:37.215 [Javascript] WARNING - DEVICE: Player connection http://192.168.1.50:32500 didn't work for Office: HTTP status -7
May 09, 2022 10:50:37.215 [Javascript] WARNING - DEVICE: Connection testing failed for Office
May 09, 2022 10:50:37.215 [Javascript] WARNING - DEVICE: Player connection http://192.168.1.50:32500 didn't work for rpiserver: HTTP status -7
May 09, 2022 10:50:37.215 [Javascript] WARNING - DEVICE: Connection testing failed for rpiserver
May 09, 2022 10:50:37.216 [Javascript] WARNING - METRICS: Unable to fetch privacy settings.
May 09, 2022 10:50:37.217 [Javascript] WARNING - ACCOUNT: Error refreshing account data:  HTTP status -6
May 09, 2022 10:50:37.220 [Javascript] INFO - App: Device manager, settings and cache initialized in 93ms.
May 09, 2022 10:50:37.222 [Javascript] INFO - Sync: Loaded in 1ms.
May 09, 2022 10:50:37.222 [Javascript] INFO - App: Offline store initialized in 2ms.
May 09, 2022 10:50:37.226 [Javascript] INFO - Audio: Initializing.
May 09, 2022 10:50:37.227 [Javascript] INFO - Audio: Binding settings.
May 09, 2022 10:50:37.227 [Javascript] INFO - Audio: Setting player info.
May 09, 2022 10:50:37.228 [0xa651e180] DEBUG - BASS: Starting up.
May 09, 2022 10:50:37.228 [0xa651e180] DEBUG - BASS: Created bass audio renderer.
May 09, 2022 10:50:37.254 [0xa651e180] INFO - BASS: Device 1: Default - enabled default - sample rates: () - active 0/0
May 09, 2022 10:50:37.254 [0xa651e180] INFO - BASS: Device 2: snd_rpi_hifiberry_digi: HiFiBerry Digi+ Pro HiFi wm8804-spdif-0 - enabled - sample rates: () - active 0/0
May 09, 2022 10:50:37.254 [0xa651e180] INFO - BASS: Device 3: vc4-hdmi-1: MAI PCM i2s-hifi-0 - enabled - sample rates: () - active 0/0
May 09, 2022 10:50:37.254 [0xa651e180] INFO - BASS: Device 4: IEC958 (S/PDIF) Digital Audio Output - enabled - sample rates: () - active 0/0
May 09, 2022 10:50:37.254 [0xa651e180] DEBUG - BASS: Using plugin path '/home/chris/plexamp/treble/'.
May 09, 2022 10:50:37.254 [0xa651e180] DEBUG - BASS: Reloading ourselves for symbol visibility.
May 09, 2022 10:50:37.259 [0xa651e180] INFO - BASS: Loaded AAC plug-in version 2.4.5.11
May 09, 2022 10:50:37.263 [0xa651e180] INFO - BASS: Loaded ALAC plug-in version 2.4.0.3
May 09, 2022 10:50:37.265 [0xa651e180] INFO - BASS: Loaded FLAC plug-in version 2.4.4.5
May 09, 2022 10:50:37.268 [0xa651e180] INFO - BASS: Loaded OPUS plug-in version 2.4.2.1
May 09, 2022 10:50:37.271 [0xa651e180] INFO - BASS: Loaded APE plug-in version 2.4.2.0
May 09, 2022 10:50:37.273 [0xa651e180] INFO - BASS: Loaded MPC plug-in version 2.4.1.3
May 09, 2022 10:50:37.274 [0xa651e180] INFO - BASS: Loaded DSD plug-in version 2.4.1.2
May 09, 2022 10:50:37.274 [0xa651e180] INFO - BASS: Core version 2.4.16.7
May 09, 2022 10:50:37.274 [0xa651e180] INFO - BASS: Mixer version 2.4.11.1
May 09, 2022 10:50:37.274 [0xa651e180] INFO - BASS: FX version 2.4.12.1
May 09, 2022 10:50:37.274 [0xa651e180] INFO - BASS: Curl version is 7.83.0 (protocols: dict file http https mqtt; ssl: OpenSSL/1.1.1n; libz: 1.2.11; DNS: threaded).
May 09, 2022 10:50:37.274 [0xa651e180] DEBUG - BASS: Setting audio interface:  -> hw:1,0.
May 09, 2022 10:50:37.274 [0xa651e180] DEBUG - BASS: Resetting device (soft: 0, initialized: 0).
May 09, 2022 10:50:37.279 [Javascript] INFO - METRICS: Error loading from storage. Unexpected token u in JSON at position 0
May 09, 2022 10:50:37.279 [Javascript] INFO - METRICS: Loaded 0 events from storage.
May 09, 2022 10:50:37.287 [Javascript] INFO - App: Player initialized in 62ms.
May 09, 2022 10:50:37.292 [Javascript] INFO - App: Waiting for rest of stores to initialize.
May 09, 2022 10:50:37.293 [Javascript] INFO - Server Activity: Connecting based on switch.
May 09, 2022 10:50:37.294 [Javascript] INFO - Server Activity: Trying to connect to 073e131472a601d945dbb1357e059ccd55c34980.
May 09, 2022 10:50:37.295 [0xbeadf040] DEBUG - Networking: Create request 13: (GET https://192-168-1-22.*****.plex.direct:32400/:/eventsource/notifications?filters=timeline&X-Plex-Token>
May 09, 2022 10:50:37.295 [0xa551c180] DEBUG - Networking: Completed request 13: (GET https://192-168-1-22.*****.plex.direct:32400/:/eventsource/notifications?filters=timeline&X-Plex-To>
May 09, 2022 10:50:37.303 [Javascript] INFO - Player: Initializing with state null
May 09, 2022 10:50:37.305 [Javascript] INFO - App: Stopping activity recognition.
May 09, 2022 10:50:37.308 [Javascript] INFO - Network changed: type is ethernet effectiveType is undefined -> 2
May 09, 2022 10:50:37.309 [0xbeadf040] INFO - BASS: Network switched to 2.
May 09, 2022 10:50:37.309 [Javascript] INFO - App: Network is connected, but type changed to 2, so doing preemptive connection testing on selected server.
May 09, 2022 10:50:37.309 [Javascript] INFO - DEVICE: Finding best connection for Name's Plex Server 073e131472a601d945dbb1357e059ccd55c34980.
May 09, 2022 10:50:37.309 [0xbeadf040] DEBUG - Networking: Create request 14: (GET https://192-168-1-22.*****.plex.direct:32400/).
May 09, 2022 10:50:37.310 [0xbeadf040] DEBUG - Networking: Create request 15: (GET https://172-19-0-1.*****.plex.direct:32400/).
May 09, 2022 10:50:37.310 [0xa551c180] DEBUG - Networking: Completed request 14: (GET https://192-168-1-22.*****.plex.direct:32400/) with code -7 (have 0 bytes) in 0 ms.
May 09, 2022 10:50:37.310 [0xa551c180] DEBUG - Networking: Completed request 15: (GET https://172-19-0-1.*****.plex.direct:32400/) with code -7 (have 0 bytes) in 0 ms.
May 09, 2022 10:50:37.310 [0xbeadf040] DEBUG - Networking: Create request 16: (GET https://125-253-20-23.*****.plex.direct:32400/).
May 09, 2022 10:50:37.311 [0xa551c180] DEBUG - Networking: Completed request 16: (GET https://125-253-20-23.*****.plex.direct:32400/) with code -7 (have 0 bytes) in 0 ms.
May 09, 2022 10:50:37.311 [Javascript] INFO - Player: Sending state changed [A]  -  (0/0) in state stopped with artwork false.
May 09, 2022 10:50:37.312 [Javascript] INFO - Player: Restoring player route of local with network state 2.
May 09, 2022 10:50:37.397 [Javascript] WARNING - Server Activity: Connection broken to 073e131472a601d945dbb1357e059ccd55c34980, reconnecting.
May 09, 2022 10:50:37.397 [Javascript] WARNING - DEVICE: Server connection https://192-168-1-22.*****.plex.direct:32400 didn't work for Name's Plex Server: HTTP status -7
May 09, 2022 10:50:37.398 [Javascript] WARNING - DEVICE: Server connection https://172-19-0-1.*****.plex.direct:32400 didn't work for Name's Plex Server: HTTP status -7
May 09, 2022 10:50:37.398 [Javascript] WARNING - DEVICE: Server connection https://125-253-20-23.*****.plex.direct:32400 didn't work for Name's Plex Server: HTTP status -7
May 09, 2022 10:50:37.399 [Javascript] INFO - DEVICE: Checking Name's Plex Server for local HTTP connection.
May 09, 2022 10:50:37.400 [0xbeadf040] DEBUG - Networking: Create request 17: (GET http://192.168.1.22:32400/identity).
May 09, 2022 10:50:37.400 [0xa551c180] DEBUG - Networking: Completed request 17: (GET http://192.168.1.22:32400/identity) with code -7 (have 0 bytes) in 0 ms.
May 09, 2022 10:50:37.400 [0xbeadf040] DEBUG - Networking: Create request 18: (GET http://172.19.0.1:32400/identity).
May 09, 2022 10:50:37.401 [0xa551c180] DEBUG - Networking: Completed request 18: (GET http://172.19.0.1:32400/identity) with code -7 (have 0 bytes) in 0 ms.
May 09, 2022 10:50:37.401 [Javascript] WARNING - DEVICE: Connection testing failed for Name's Plex Server
May 09, 2022 10:50:37.405 [Javascript] INFO - ViewState: Error loading from storage. Unexpected token u in JSON at position 0
May 09, 2022 10:50:37.415 [Javascript] INFO - Cloud: [RecentPlays] Loading from storage 20 items and 0 deleted.
May 09, 2022 10:50:37.416 [Javascript] INFO - Cloud: [RecentPlays] Syncing.
May 09, 2022 10:50:37.417 [0xbeadf040] DEBUG - Networking: Create request 19: (GET https://plex.tv/api/v2/user/settings?uuid=1853af602ce07414&key=RecentPlays).
May 09, 2022 10:50:37.417 [Javascript] INFO - App: Stores initialized in 130ms.
May 09, 2022 10:50:37.418 [0xa551c180] DEBUG - Networking: Completed request 19: (GET https://plex.tv/api/v2/user/settings?uuid=1853af602ce07414&key=RecentPlays) with code -6 (have 0 bytes) in 1 ms.
May 09, 2022 10:50:37.419 [Javascript] INFO - App: Stores all initialized.
May 09, 2022 10:50:37.419 [Javascript] INFO - Companion: Initializing.
May 09, 2022 10:50:37.420 [Javascript] INFO - Companion: Network type is 2.
May 09, 2022 10:50:37.420 [Javascript] INFO - Companion: attempting to connect to pubsub, started undefined connected false
May 09, 2022 10:50:37.420 [0xbeadf040] DEBUG - Networking: Create request 20: (GET https://pubsub.plex.tv/sub/eventsource/11765374/27762551-4f25-4b25-9361-0b9548d80033?X-Plex-Token=<token>).
May 09, 2022 10:50:37.421 [0xa551c180] DEBUG - Networking: Completed request 20: (GET https://pubsub.plex.tv/sub/eventsource/11765374/27762551-4f25-4b25-9361-0b9548d80033?X-Plex-Token=<token>) with code -6 (have >
May 09, 2022 10:50:37.422 [Javascript] INFO - Companion: Network type is 2 and enabled is true.
May 09, 2022 10:50:37.424 [Javascript] INFO - Discovery: Refresh based on server/library switch 073e131472a601d945dbb1357e059ccd55c34980 /library/sections/5.
May 09, 2022 10:50:37.425 [Javascript] INFO - Discovery: Fetching hubs for library /library/sections/5 server 073e131472a601d945dbb1357e059ccd55c34980 refreshing from cloud false.
May 09, 2022 10:50:37.429 [Javascript] INFO - DEVICE: Finding best connection for Name's Plex Server 073e131472a601d945dbb1357e059ccd55c34980.
May 09, 2022 10:50:37.430 [0xbeadf040] DEBUG - Networking: Create request 21: (GET https://192-168-1-22.*****.plex.direct:32400/).
May 09, 2022 10:50:37.430 [0xbeadf040] DEBUG - Networking: Create request 22: (GET https://172-19-0-1.*****.plex.direct:32400/).
May 09, 2022 10:50:37.430 [0xa551c180] DEBUG - Networking: Completed request 21: (GET https://192-168-1-22.*****.plex.direct:32400/) with code -7 (have 0 bytes) in 0 ms.
May 09, 2022 10:50:37.430 [0xa551c180] DEBUG - Networking: Completed request 22: (GET https://172-19-0-1.*****.plex.direct:32400/) with code -7 (have 0 bytes) in 0 ms.
May 09, 2022 10:50:37.430 [0xbeadf040] DEBUG - Networking: Create request 23: (GET https://125-253-20-23.*****.plex.direct:32400/).
May 09, 2022 10:50:37.431 [0xa551c180] DEBUG - Networking: Completed request 23: (GET https://125-253-20-23.*****.plex.direct:32400/) with code -7 (have 0 bytes) in 0 ms.
May 09, 2022 10:50:37.431 [Javascript] INFO - DEVICE: Finding best connection for Name's Plex Server 073e131472a601d945dbb1357e059ccd55c34980.
May 09, 2022 10:50:37.431 [0xbeadf040] DEBUG - Networking: Create request 24: (GET https://192-168-1-22.*****.plex.direct:32400/).
May 09, 2022 10:50:37.432 [0xa551c180] DEBUG - Networking: Completed request 24: (GET https://192-168-1-22.*****.plex.direct:32400/) with code -7 (have 0 bytes) in 0 ms.
May 09, 2022 10:50:37.432 [0xbeadf040] DEBUG - Networking: Create request 25: (GET https://172-19-0-1.*****.plex.direct:32400/).
May 09, 2022 10:50:37.432 [0xa551c180] DEBUG - Networking: Completed request 25: (GET https://172-19-0-1.*****.plex.direct:32400/) with code -7 (have 0 bytes) in 0 ms.
May 09, 2022 10:50:37.432 [0xbeadf040] DEBUG - Networking: Create request 26: (GET https://125-253-20-23.*****.plex.direct:32400/).
May 09, 2022 10:50:37.432 [0xa551c180] DEBUG - Networking: Completed request 26: (GET https://125-253-20-23.*****.plex.direct:32400/) with code -7 (have 0 bytes) in 0 ms.
May 09, 2022 10:50:37.432 [Javascript] INFO - Cloud: [RecentPlays] Error getting data: HTTP status -6
May 09, 2022 10:50:37.433 [Javascript] WARNING - Cloud: [RecentPlays] No cloud data.
May 09, 2022 10:50:37.433 [Javascript] INFO - Cloud: [RecentPlays] Syncing complete with added: 0 deleted: 0 and dirty: 0.
May 09, 2022 10:50:37.433 [Javascript] INFO - PubSub: Connection broken to plex.tv, reconnecting.
May 09, 2022 10:50:37.433 [Javascript] WARNING - DEVICE: Server connection https://192-168-1-22.*****.plex.direct:32400 didn't work for Name's Plex Server: HTTP status -7
May 09, 2022 10:50:37.434 [Javascript] WARNING - DEVICE: Server connection https://172-19-0-1.*****.plex.direct:32400 didn't work for Name's Plex Server: HTTP status -7
May 09, 2022 10:50:37.434 [Javascript] WARNING - DEVICE: Server connection https://125-253-20-23.*****.plex.direct:32400 didn't work for Name's Plex Server: HTTP status -7
May 09, 2022 10:50:37.434 [Javascript] INFO - DEVICE: Checking Name's Plex Server for local HTTP connection.
May 09, 2022 10:50:37.434 [0xbeadf040] DEBUG - Networking: Create request 27: (GET http://192.168.1.22:32400/identity).
May 09, 2022 10:50:37.435 [0xa551c180] DEBUG - Networking: Completed request 27: (GET http://192.168.1.22:32400/identity) with code -7 (have 0 bytes) in 0 ms.
May 09, 2022 10:50:37.435 [0xbeadf040] DEBUG - Networking: Create request 28: (GET http://172.19.0.1:32400/identity).
May 09, 2022 10:50:37.435 [0xa551c180] DEBUG - Networking: Completed request 28: (GET http://172.19.0.1:32400/identity) with code -7 (have 0 bytes) in 0 ms.
May 09, 2022 10:50:37.435 [Javascript] WARNING - DEVICE: Server connection https://192-168-1-22.*****.plex.direct:32400 didn't work for Name's Plex Server: HTTP status -7
May 09, 2022 10:50:37.435 [Javascript] WARNING - DEVICE: Server connection https://172-19-0-1.*****.plex.direct:32400 didn't work for Name's Plex Server: HTTP status -7
May 09, 2022 10:50:37.436 [Javascript] WARNING - DEVICE: Server connection https://125-253-20-23.*****.plex.direct:32400 didn't work for Name's Plex Server: HTTP status -7
May 09, 2022 10:50:37.436 [Javascript] INFO - DEVICE: Checking Name's Plex Server for local HTTP connection.
May 09, 2022 10:50:37.436 [0xbeadf040] DEBUG - Networking: Create request 29: (GET http://192.168.1.22:32400/identity).
May 09, 2022 10:50:37.436 [0xa551c180] DEBUG - Networking: Completed request 29: (GET http://192.168.1.22:32400/identity) with code -7 (have 0 bytes) in 0 ms.
May 09, 2022 10:50:37.436 [0xbeadf040] DEBUG - Networking: Create request 30: (GET http://172.19.0.1:32400/identity).
May 09, 2022 10:50:37.437 [0xa551c180] DEBUG - Networking: Completed request 30: (GET http://172.19.0.1:32400/identity) with code -7 (have 0 bytes) in 0 ms.
May 09, 2022 10:50:37.437 [Javascript] WARNING - DEVICE: Connection testing failed for Name's Plex Server
May 09, 2022 10:50:37.437 [Javascript] WARNING - DEVICE: Connection testing failed for Name's Plex Server
May 09, 2022 10:50:37.438 [Javascript] INFO - Discovery: Error retrieving data for hubs.
May 09, 2022 10:50:37.442 [Javascript] INFO - Companion: Attempting to start HTTP Server on port 32500.
May 09, 2022 10:50:37.444 [0x85e69180] DEBUG - HTTP: Serving on port 32500.
May 09, 2022 10:50:37.453 [Javascript] INFO - Companion: Registering device at .
May 09, 2022 10:50:37.454 [0xbeadf040] DEBUG - Networking: Create request 31: (PUT https://plex.tv/devices/27762551-4f25-4b25-9361-0b9548d80033?&X-Plex-Device-Name=rpiserver).
May 09, 2022 10:50:37.455 [0xa551c180] DEBUG - Networking: Completed request 31: (PUT https://plex.tv/devices/27762551-4f25-4b25-9361-0b9548d80033?&X-Plex-Device-Name=rpiserver) with code -6 (have 0 bytes) in 0 m>
May 09, 2022 10:50:37.455 [Javascript] INFO - Companion: Failed to register device: HTTP status -6.
May 09, 2022 10:50:37.455 [Javascript] INFO - Companion: Error starting port: 32500 registered: false advertised: false.
May 09, 2022 10:50:37.456 [Javascript] INFO - Companion: Stopping (started: false).
May 09, 2022 10:50:38.275 [0x8703e180] DEBUG - PQCache: Ignoring refresh as a newer one came in.
May 09, 2022 10:51:02.203 [Javascript] INFO - DEVICE: Finding best connection for Name's Plex Server 073e131472a601d945dbb1357e059ccd55c34980.
May 09, 2022 10:51:02.203 [0xbeadf040] DEBUG - Networking: Create request 32: (GET https://192-168-1-22.*****.plex.direct:32400/).
May 09, 2022 10:51:02.204 [0xbeadf040] DEBUG - Networking: Create request 33: (GET https://172-19-0-1.*****.plex.direct:32400/).
May 09, 2022 10:51:02.205 [0xbeadf040] DEBUG - Networking: Create request 34: (GET https://125-253-20-23.*****.plex.direct:32400/).
May 09, 2022 10:51:02.300 [0xa551c180] DEBUG - Networking: Completed request 32: (GET https://192-168-1-22.*****.plex.direct:32400/) with code 200 (have 7612 bytes) in 96 ms.
May 09, 2022 10:51:02.300 [0xa551c180] DEBUG - Networking: Completed request 34: (GET https://125-253-20-23.*****.plex.direct:32400/) with code 200 (have 7612 bytes) in 94 ms.
May 09, 2022 10:51:02.301 [Javascript] INFO - DEVICE: Server connection worked for Name's Plex Server ~ https://192-168-1-22.*****.plex.direct:32400
May 09, 2022 10:51:02.302 [Javascript] INFO - DEVICE: Reading libraries and features from Name's Plex Server
May 09, 2022 10:51:02.302 [0xbeadf040] DEBUG - Networking: Create request 35: (GET https://192-168-1-22.*****.plex.direct:32400/media/providers?includePreferences=1).
May 09, 2022 10:51:02.303 [Javascript] INFO - DEVICE: Server connection worked for Name's Plex Server ~ https://125-253-20-23.*****.plex.direct:32400
May 09, 2022 10:51:02.326 [0xa551c180] DEBUG - Networking: Completed request 35: (GET https://192-168-1-22.*****.plex.direct:32400/media/providers?includePreferences=1) with code 200 (h>
May 09, 2022 10:51:02.330 [Javascript] INFO - DEVICE: Found 7 libraries from Name's Plex Server: Home, Movies, TV Shows, Music, Photos, Videos, Playlists
May 09, 2022 10:51:07.121 [Javascript] INFO - DEVICE: Persisting devices because Name's Plex Server was dirty.
May 09, 2022 10:51:07.122 [Javascript] INFO - DEVICE: Persisting 7 devices.
May 09, 2022 10:51:07.269 [Javascript] INFO - Sync: Refreshing and completing items.
May 09, 2022 10:51:07.341 [Javascript] WARNING - Server Activity: Connection broken to 073e131472a601d945dbb1357e059ccd55c34980, reconnecting.
May 09, 2022 10:51:07.467 [Javascript] INFO - PubSub: Connection broken to plex.tv, reconnecting.
May 09, 2022 10:51:17.263 [0xa551c180] DEBUG - Networking: Completed request 33: (GET https://172-19-0-1.*****.plex.direct:32400/) with code -28 (have 0 bytes) in 15058 ms.
May 09, 2022 10:51:17.264 [Javascript] WARNING - DEVICE: Server connection https://172-19-0-1.*****.plex.direct:32400 didn't work for Name's Plex Server: HTTP status -28
May 09, 2022 10:51:22.342 [Javascript] INFO - Server Activity: Trying to connect to 073e131472a601d945dbb1357e059ccd55c34980.
May 09, 2022 10:51:22.343 [0xbeadf040] DEBUG - Networking: Create request 36: (GET https://192-168-1-22.*****.plex.direct:32400/:/eventsource/notifications?filters=timeline&X-Plex-Token>
May 09, 2022 10:51:22.468 [Javascript] INFO - Companion: attempting to connect to pubsub, started true connected false
May 09, 2022 10:51:22.469 [0xbeadf040] DEBUG - Networking: Create request 37: (GET https://pubsub.plex.tv/sub/eventsource/11765374/27762551-4f25-4b25-9361-0b9548d80033?X-Plex-Token=<token>).
May 09, 2022 10:56:24.096 [Javascript] INFO - HTTP: Setting equalizerValues of type object to 0,0,0,0,0,0,0,0,0,0
May 09, 2022 10:57:59.855 [Javascript] INFO - HTTP: Setting equalizerValues of type object to 0,0,0,0,0,0,0,0,0,0
May 09, 2022 10:58:09.440 [Javascript] INFO - HTTP: Setting audioDeviceUuid of type string to iec958
May 09, 2022 10:58:09.441 [0xa5d1d180] DEBUG - BASS: Setting audio interface: hw:1,0 -> iec958.
May 09, 2022 10:58:09.441 [0xa5d1d180] DEBUG - BASS: Resetting device (soft: 0, initialized: 0).
13
  • There is some weird networking thing going on Couldn't resolve host name
  • There are zero play attempts. Possibly you don’t have the UI pointing to the right player and it’s trying to play in the browser which would always fail.
14

Ok I feel dumb, this was it. I assumed by not selecting a player in the browser UI it would play locally (ie from the output I had selected in settings), like the other Plexamp apps. The networking errors are a bit concerning still but after a quick test everything appears to be working as expected. Thanks for your help and the development time that went into this, I can finally retire my Chromecast Audio!

15

Woohoo!!!

16

This topic was automatically closed 90 days after the last reply. New replies are no longer allowed.