Plexamp Headless works fine with browser url but fails connecting from clients

Plex Labs
1

I have plexamp installed per the instructions on serveral raspberry pis using justboom amplifiers (2 using Hifi berries)

One Hifi berry works fine, all of the rest have the same issue:

They work fine if you go to a chrome browser and login and play. But if you go into the ios plexamp and try and use it as a cast target (not airplay) it just hangs.

For reference, on the same device shairport-sync works fine remotely. (and yes I’ve tried it without shairport-sync on the pi and with it just disabled)

What am I doing wrong?

2

does it hang when trying to connect to the pi device from the iOS cast menu, or does it connect and then hang when trying to start playback?

1 Like
3

It hangs when trying to start playback.

It also hangs if I open chromium on the pi itself and try and playback.

Only place where it is fine is remote connection through a browser.

PS: If it matters I get the 403 error once a token is claimed.

4

based on your description i can’t think of any obvious setup issues … here are a few general / brute force things to try, if you haven’t already …

at the player/pi end, try restarting the service (sudo systemctl restart plexamp, assuming it’s set up as a system service) or even rebooting the device

at the controller end, sometimes disconnecting from the cast device, refreshing the cast device list, and reconnecting can help (in addition to closing/restarting the app)

if none of this helps, then posting Plexamp logs (probably from the Pi ?) might help the Plex devs look into it further

5

I’ve done the restart plexamp part and rebooted, no dice. I restarted my phone, no dice.

That page doesn’t list plexamp headless on linux for logging. Where are they at?

6

ah, sorry about that … headless logs are at ~/.cache/Plexamp/log

7

Here’s the logs: (I immediately played fine from the web browser fine after that)

Feb 20, 2023 09:20:48.135 [0x0d7fa140] INFO - Cache: Buffering complete as offset is now greater than 588800 (589824) and read completed: 0.
Feb 20, 2023 09:20:48.135 [0xfffff140] WARNING - Cache: READ underflowed at 589824 bytes, will go into buffering state.
Feb 20, 2023 09:20:48.135 [0xfffff140] INFO - Cache: Buffering until offset reaches 1767424 (read buffer offset: 589824, size: 1177600).
Feb 20, 2023 09:20:48.135 [0x0dffb140] INFO - BASS: Stream 347452 (channel 0x00000000) changed buffering state to 1.
Feb 20, 2023 09:20:48.180 [0x0cff9140] INFO - PQCache: Requesting play queue with 1 items ahead.
Feb 20, 2023 09:20:48.209 [0x0cff9140] INFO - Cache: HTTP response code was 200.
Feb 20, 2023 09:20:48.209 [0x0cff9140] INFO - Cache: HTTP response total size was 3149.
Feb 20, 2023 09:20:48.212 [0x0cff9140] INFO - PQCache: Parsed play queue from JSON (13949 bytes).
Feb 20, 2023 09:20:48.212 [0x0cff9140] INFO - PQCache: Parsed 5 items (2 currently active).
Feb 20, 2023 09:20:48.657 [0x0e7fc140] INFO - Cache: Asked to seek to offset 48372642 with read buffer offset at 921600.
Feb 20, 2023 09:20:48.657 [0x0e7fc140] INFO - Cache: That sucks, total cache fail on seek. Such is life.
Feb 20, 2023 09:20:48.757 [0x0d7fa140] INFO - Cache: Ending network read thread.
Feb 20, 2023 09:20:48.761 [0x0e7fc140] INFO - Cache: Buffering until offset reaches 48961442 (read buffer offset: 48372642, size: 588800).
Feb 20, 2023 09:20:48.761 [0x0d7fa140] INFO - Cache: Kicking off buffering thread at offset 48372642, disk cache has 933888 / 54382970.
Feb 20, 2023 09:20:48.761 [0x0d7fa140] INFO - Cache: We’ve been asked to buffer a disjoint region, we’ll just stream from network.
Feb 20, 2023 09:20:48.801 [0x0d7fa140] INFO - Cache: HTTP response code was 206.
Feb 20, 2023 09:20:48.801 [0x0d7fa140] INFO - Cache: HTTP response total size was 6010328.
Feb 20, 2023 09:20:48.903 [0x0e7fc140] INFO - Cache: Asked to seek to offset 48365004 with read buffer offset at 48409506.
Feb 20, 2023 09:20:48.903 [0x0e7fc140] INFO - Cache: That sucks, total cache fail on seek. Such is life.
Feb 20, 2023 09:20:48.904 [0x0d7fa140] INFO - Cache: Ending network read thread.
Feb 20, 2023 09:20:48.907 [0x0e7fc140] INFO - Cache: Buffering until offset reaches 48953804 (read buffer offset: 48365004, size: 588800).
Feb 20, 2023 09:20:48.907 [0x0d7fa140] INFO - Cache: Kicking off buffering thread at offset 48365004, disk cache has 933888 / 54382970.
Feb 20, 2023 09:20:48.907 [0x0d7fa140] INFO - Cache: We’ve been asked to buffer a disjoint region, we’ll just stream from network.
Feb 20, 2023 09:20:48.933 [0x0d7fa140] INFO - Cache: HTTP response code was 206.
Feb 20, 2023 09:20:48.934 [0x0d7fa140] INFO - Cache: HTTP response total size was 6017966.
Feb 20, 2023 09:20:48.935 [0x0e7fc140] DEBUG - BASS: Initial mixer offset 403.0 sec.
Feb 20, 2023 09:20:48.935 [0x0e7fc140] DEBUG - BASS: Setting stream gain for 347452 to -4.4 dB.
Feb 20, 2023 09:20:48.935 [0x0e7fc140] INFO - BASS: Opened stream 347452 in 1760 ms (paused: 1) with gain -4.4 dB, max 0 Kbps (picked flac, 925 Kbps, actual 940 Kbps/sec).
Feb 20, 2023 09:20:48.935 [0x0e7fc140] INFO - BASS: Created a gapless source stream for 347452 (channel: 0x80000013) with sample rate of 44100 and 2 channels (paused: 1)
Feb 20, 2023 09:20:48.935 [0x0e7fc140] INFO - BASS: Reading first bytes to ensure stream 347452 is warmed up.
Feb 20, 2023 09:20:49.036 [0x0e7fc140] DEBUG - BASS: Enabling limiter.
Feb 20, 2023 09:20:49.859 [0x0d7fa140] INFO - Cache: Buffering complete as offset is now greater than 48953804 (48954828) and read completed: 0.
Feb 20, 2023 09:20:49.859 [0x0dffb140] INFO - BASS: Stream 347452 (channel 0x80000013) changed buffering state to 0.
Feb 20, 2023 09:20:49.859 [0x0dffb140] INFO - BASS: Not touching channel state because we’re paused.
Feb 20, 2023 09:20:49.860 [Javascript] INFO - Audio: State changed from buffering to paused.
Feb 20, 2023 09:20:49.860 [Javascript] INFO - PlayQueue: Saving state {“source”:“489df7b9a696f17132f4b1e3372adae6e17541d4”,“state”:“paused”,“time”:403007,“rate”:1,“volume”:100,“playQueueID”:“6754”,“playQueueVersion”:2,“playQueueItemID”:“347452”}
Feb 20, 2023 09:20:49.871 [Javascript] INFO - Player: State transition buffering → paused for source local ID 347452.
Feb 20, 2023 09:20:49.881 [Javascript] INFO - Player: Sending state changed [A] Guns N’ Roses - Civil War (403007/462466) in state paused with artwork false.
Feb 20, 2023 09:20:51.745 [Javascript] INFO - HttpServer: [10.99.71.230] GET /player/playback/play commandID=15&type=music
Feb 20, 2023 09:20:51.747 [0x89bbc140] INFO - BASS: Resume.
Feb 20, 2023 09:20:51.747 [0x89bbc140] DEBUG - BASS: Ensuring we’re not idle.
Feb 20, 2023 09:20:51.747 [0x89bbc140] DEBUG - BASS: Resetting device (soft: 0, initialized: 1).
Feb 20, 2023 09:20:51.747 [0x89bbc140] DEBUG - BASS: Moving from decode only to real playback.
Feb 20, 2023 09:20:51.747 [0x89bbc140] DEBUG - BASS: Suspending device (sample rate: 44100, num channels: 2, soft: 0, decode only: 0, force: 1)
Feb 20, 2023 09:20:51.747 [0x89bbc140] DEBUG - BASS: Suspending 2 currently active channels.
Feb 20, 2023 09:20:51.747 [0x89bbc140] DEBUG - BASS: Tearing down audio stack.
Feb 20, 2023 09:20:51.749 [0x89bbc140] DEBUG - BASS: Resuming device (sample rate: 44100, num channels: 2, soft: 0, decode only: 0, force: 1)
Feb 20, 2023 09:20:51.749 [0x89bbc140] DEBUG - Mixer: Initializing audio pipeline with sample rate: 44100 channels:2 soft: 0.
Feb 20, 2023 09:20:51.752 [Javascript] INFO - Player: Sending state changed [A] Guns N’ Roses - Civil War (403007/462466) in state playing with artwork false.
Feb 20, 2023 09:20:51.787 [0x89bbc140] ERROR - BASS: Error initializing device -1 with sample rate 44100 and flags 00000000 (3).
Feb 20, 2023 09:20:51.787 [0x89bbc140] DEBUG - BASS: Creating a mixer with sample rate 44100 and 2 channels (decode: 0).
Feb 20, 2023 09:20:51.787 [0x89bbc140] ERROR - BASS: Error [m_mixer = BASS_Mixer_StreamCreate((DWORD)sampleRate, (DWORD)channels, flags)] - 8
Feb 20, 2023 09:20:51.787 [0x89bbc140] DEBUG - BASS: Adding back 2 streams after recreating mixer — 0x8000000d (flags: 00020000) 0x80000013 (flags: 00820000)
Feb 20, 2023 09:20:51.787 [0x89bbc140] DEBUG - BASS: We have 0 dying streams which we’re going to kill immediately.
Feb 20, 2023 09:20:51.787 [0x89bbc140] ERROR - BASS: Failed to start mixer, error 5.
Feb 20, 2023 09:20:51.787 [0x89bbc140] INFO - BASS: Resuming audio output (started: 0)
Feb 20, 2023 09:20:51.787 [0x89bbc140] ERROR - BASS: Error resuming, restarting entire system.
Feb 20, 2023 09:20:51.787 [0x89bbc140] DEBUG - BASS: Resetting device (soft: 0, initialized: 1).
Feb 20, 2023 09:20:51.787 [0x89bbc140] WARNING - BASS: Couldn’t start, so we’re not doing a soft configure.
Feb 20, 2023 09:20:51.787 [0x89bbc140] DEBUG - BASS: Suspending device (sample rate: 44100, num channels: 2, soft: 0, decode only: 0, force: 0)
Feb 20, 2023 09:20:51.787 [0x89bbc140] DEBUG - BASS: Changing mixer from 0/0 to 44100/2.
Feb 20, 2023 09:20:51.787 [0x89bbc140] DEBUG - BASS: Suspending -1 currently active channels.
Feb 20, 2023 09:20:51.787 [0x89bbc140] ERROR - BASS: Error fetching mixer channels - 5
Feb 20, 2023 09:20:51.787 [0x89bbc140] DEBUG - BASS: Tearing down audio stack.
Feb 20, 2023 09:20:51.787 [0x89bbc140] ERROR - BASS: Error [BASS_Stop()] - 8
Feb 20, 2023 09:20:51.787 [0x89bbc140] ERROR - BASS: Error [BASS_Free()] - 8
Feb 20, 2023 09:20:51.787 [0x89bbc140] DEBUG - BASS: Resuming device (sample rate: 44100, num channels: 2, soft: 0, decode only: 0, force: 0)
Feb 20, 2023 09:20:51.787 [0x89bbc140] DEBUG - Mixer: Initializing audio pipeline with sample rate: 44100 channels:2 soft: 0.
Feb 20, 2023 09:20:51.788 [0x89bbc140] ERROR - BASS: Error initializing device -1 with sample rate 44100 and flags 00000000 (3).
Feb 20, 2023 09:20:51.788 [0x89bbc140] DEBUG - BASS: Creating a mixer with sample rate 44100 and 2 channels (decode: 0).
Feb 20, 2023 09:20:51.788 [0x89bbc140] ERROR - BASS: Error [m_mixer = BASS_Mixer_StreamCreate((DWORD)sampleRate, (DWORD)channels, flags)] - 8
Feb 20, 2023 09:20:51.788 [0x89bbc140] DEBUG - BASS: We have 0 dying streams which we’re going to kill immediately.
Feb 20, 2023 09:20:51.788 [0x89bbc140] ERROR - BASS: Failed to start mixer, error 5.
Feb 20, 2023 09:20:51.788 [0x89bbc140] ERROR - BASS: Failed to start mixer, error 5.
Feb 20, 2023 09:20:51.788 [0x89bbc140] ERROR - BASS: Error resuming, restarting entire system.
Feb 20, 2023 09:20:51.788 [0x89bbc140] DEBUG - BASS: Resetting device (soft: 0, initialized: 1).
Feb 20, 2023 09:20:51.788 [0x89bbc140] WARNING - BASS: Couldn’t start, so we’re not doing a soft configure.
Feb 20, 2023 09:20:51.788 [0x89bbc140] DEBUG - BASS: Suspending device (sample rate: 44100, num channels: 2, soft: 0, decode only: 0, force: 0)
Feb 20, 2023 09:20:51.788 [0x89bbc140] DEBUG - BASS: Changing mixer from 0/0 to 44100/2.
Feb 20, 2023 09:20:51.788 [0x89bbc140] DEBUG - BASS: Suspending -1 currently active channels.
Feb 20, 2023 09:20:51.788 [0x89bbc140] ERROR - BASS: Error fetching mixer channels - 5
Feb 20, 2023 09:20:51.788 [0x89bbc140] DEBUG - BASS: Tearing down audio stack.
Feb 20, 2023 09:20:51.788 [0x89bbc140] ERROR - BASS: Error [BASS_Stop()] - 8
Feb 20, 2023 09:20:51.788 [0x89bbc140] ERROR - BASS: Error [BASS_Free()] - 8
Feb 20, 2023 09:20:51.788 [0x89bbc140] DEBUG - BASS: Resuming device (sample rate: 44100, num channels: 2, soft: 0, decode only: 0, force: 0)
Feb 20, 2023 09:20:51.788 [0x89bbc140] DEBUG - Mixer: Initializing audio pipeline with sample rate: 44100 channels:2 soft: 0.
Feb 20, 2023 09:20:51.788 [0x89bbc140] ERROR - BASS: Error initializing device -1 with sample rate 44100 and flags 00000000 (3).
Feb 20, 2023 09:20:51.788 [0x89bbc140] DEBUG - BASS: Creating a mixer with sample rate 44100 and 2 channels (decode: 0).
Feb 20, 2023 09:20:51.788 [0x89bbc140] ERROR - BASS: Error [m_mixer = BASS_Mixer_StreamCreate((DWORD)sampleRate, (DWORD)channels, flags)] - 8
Feb 20, 2023 09:20:51.788 [0x89bbc140] DEBUG - BASS: We have 0 dying streams which we’re going to kill immediately.
Feb 20, 2023 09:20:51.788 [0x89bbc140] ERROR - BASS: Failed to start mixer, error 5.
Feb 20, 2023 09:20:51.788 [0x89bbc140] ERROR - BASS: Failed to start mixer, error 5.
Feb 20, 2023 09:20:51.788 [0x89bbc140] DEBUG - BASS: Taking mixer pause flag off channel.
Feb 20, 2023 09:20:51.788 [0x89bbc140] DEBUG - BASS: Resumed in 41 ms.
Feb 20, 2023 09:20:51.791 [Javascript] INFO - Player: State transition playing → paused for source local ID 347452.
Feb 20, 2023 09:20:51.795 [Javascript] INFO - Player: Sending state changed [A] Guns N’ Roses - Civil War (403007/462466) in state paused with artwork false.
Feb 20, 2023 09:20:51.817 [Javascript] INFO - HttpServer: [10.99.71.230] GET /player/playback/setParameters volume=100&commandID=16&type=music
Feb 20, 2023 09:20:51.818 [Javascript] INFO - PlayQueue: Saving state {“source”:“489df7b9a696f17132f4b1e3372adae6e17541d4”,“state”:“paused”,“time”:403007,“rate”:1,“volume”:100,“playQueueID”:“6754”,“playQueueVersion”:2,“playQueueItemID”:“347452”}

8

thanks … please upload the full log file (devs usually request this, there should be more info on your audio device, connections, etc.)

[edit] … to save a copy of the log file, try something like a secure copy (scp) command executed from your main computer (whatever you’re using to ssh into the pi) …

scp pi_user@pi_device:/home/pi_user/.cache/Plexamp/log/Plexamp.log .

9

Plexamp.log (101.2 KB)

Note I have also tried every auto source listed under playback in the plex UX and none of them change the result.

10

from the log it doesn’t look like your audio device isn’t selected (or if you’ve selected it from the web ui, headless on the pi itself doesn’t appear to be aware of it) …

Feb 20, 2023 08:31:55.609 [0x8abbe140] DEBUG - BASS: Setting audio interface:  -> .

hopefully Plex devs can take a look and give some recommendations

11

Perhaps that’s “default”? Because that’s what it is set to right now.

12

for reference, from one of my headless devices … when i use the web ui to set it to default, it actually shows as “default” in the logs

Feb 19, 2023 10:23:14.024 [0xa5184160] DEBUG - BASS: Setting audio interface:  -> hw:2,0.
Feb 20, 2023 09:40:14.132 [0xa6186160] DEBUG - BASS: Setting audio interface: hw:2,0 -> default.
Feb 20, 2023 09:40:36.918 [0xa6186160] DEBUG - BASS: Setting audio interface: default -> hw:2,0.
13

Interesting. I’ve tried setting it multiple times but it doesn’t seem to stick.

Where is the configuration file where this stored? I would love to just set it and be done.

14

the playback settings entered from the web ui (and other info) should be automatically stored and updated here (there should be one with “audioDevice” in the name) …

~/.local/share/Plexamp/Settings

these files are not intended for manual creation/editing … if the files are not updating when you make a change from the web ui, there might be a permissions issue … this could happen, for example, if you installed Plexamp while logged in as root and then set the systemd service to run Plexamp as another user

15

That worked! Just set it, no sudo required and it started working…

2 Likes
16

good that you got it working :slight_smile: … just to confirm, were you logged in as a regular (non-root) user when you edited the settings file?

17

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