Can't get plexamp headless to play anything

Plex Labs
1

Hi

I have my PAH on a Pi, directly connected to a stereo using the built in headphone jack (Pi4b)

if I use

mpg321 file.mp3

if works fine. Sounds normal.

I have a seperate issue with PAH not being able to find my media, but if I cast from my phone, then some sound comes out - sort of. It sounds like it’s really faint and crackly. (I thought it was around 1/4 speed, but appears not now)

A sample of it here: https://fastchicken.co.nz/content/media/2022/10/plexampheadless.mp3

which is ment to be about 5:55 into the first track of this: Falling into Focus (Live 2020) | Bob Moses

Any ideas? Any idea how to get more debug info so I can workout WTF is going on?

I’ve also attached some of the logs.

Oct 17, 2022 11:34:47.325 [Javascript] INFO - AutoPlay: Kicking off computation with 0 items in play queue. true
Oct 17, 2022 11:34:47.325 [Javascript] INFO - PLAYER: Issuing play for music from server 24fxxxxxxef073219451535912f7e23861e9
Oct 17, 2022 11:34:47.327 [Javascript] DEBUG - PlayQueue: Processing STOP
Oct 17, 2022 11:34:47.327 [Javascript] INFO - PlayQueue: Stop.
Oct 17, 2022 11:34:47.328 [0x6f7ef0e0] INFO - BASS: Stop.
Oct 17, 2022 11:34:47.328 [0x6f7ef0e0] INFO - PQCache: Clearing.
Oct 17, 2022 11:34:47.328 [0x6f7ef0e0] DEBUG - BASS: Stopped in 0 ms.
Oct 17, 2022 11:34:47.328 [Javascript] DEBUG - PlayQueue: Processing send timelines in state stopped time -1000.
Oct 17, 2022 11:34:47.330 [Javascript] INFO - PlayQueue: Processing play media.
Oct 17, 2022 11:34:47.382 [Javascript] INFO - PlayQueue: Loaded play queue from 24f9f9f0a2728ef073219451535912f7e23861e9/11441.
Oct 17, 2022 11:34:47.382 [Javascript] INFO - PlayQueue: Saving to storage.
Oct 17, 2022 11:34:47.383 [Javascript] INFO - PlayQueue: Processing PQ 24f9f9f0a2xxx51535912f7e23861e9 11441 with 13 items (full: true, play after: false), selected 81445 at offset 0.
Oct 17, 2022 11:34:47.384 [Javascript] INFO - PlayQueue: Looked at all the tracks and consecutive: true.
Oct 17, 2022 11:34:47.384 [Javascript] INFO - Audio: Effective repeat mode is: undefined from mode: undefined play queue length: 13
Oct 17, 2022 11:34:47.384 [Javascript] DEBUG - PlayQueue: Audio queue:
Oct 17, 2022 11:34:47.385 [Javascript] DEBUG - PlayQueue: Play queue: 81445,81446
Oct 17, 2022 11:34:47.385 [Javascript] DEBUG - PlayQueue: Adding both current and next track.
Oct 17, 2022 11:34:47.385 [0x6ffff0e0] INFO - BASS: Stop.
Oct 17, 2022 11:34:47.385 [0x6ffff0e0] INFO - PQCache: Clearing.
Oct 17, 2022 11:34:47.385 [0x6ffff0e0] DEBUG - BASS: Stopped in 0 ms.
Oct 17, 2022 11:34:47.386 [Javascript] DEBUG - PlayQueue: Using first offset of 357000.
Oct 17, 2022 11:34:47.386 [Javascript] DEBUG - PlayQueue: Adding track 81445 to audio player, gapless true gain -10.36 looping false.
Oct 17, 2022 11:34:47.388 [0x6f7ef0e0] INFO - PQCache: Set item 81445 active to 1, 1 active remaining.
Oct 17, 2022 11:34:47.388 [0x6f7ef0e0] INFO - BASS: Queueing stream (1 total, 1 handles) with identifier 81445, gain -10.4 dB, overlap duration 0 ms, start offset 357000 ms (paused: 0).
Oct 17, 2022 11:34:47.388 [0x6f7ef0e0] DEBUG - BASS: Resetting device (soft: 1, initialized: 1).
Oct 17, 2022 11:34:47.388 [0x6f7ef0e0] INFO - Media: Found an item to direct play with bitrate under 0 (it was 187 kbps).
Oct 17, 2022 11:34:47.388 [0x6f7ef0e0] WARNING - BASS: Couldn't start, so we're not doing a soft configure.
Oct 17, 2022 11:34:47.388 [0x6f7ef0e0] DEBUG - BASS: Resuming device (sample rate: 44100, num channels: 2, soft: 0, decode only: 0, force: 0)
Oct 17, 2022 11:34:47.388 [0x6f7ef0e0] DEBUG - Mixer: Initializing audio pipeline with sample rate: 44100 channels:2 soft: 0.
Oct 17, 2022 11:34:47.414 [0x6f7ef0e0] INFO - BASS: Device -1 opened and sample rate is 44100 (preferred was 44100, best was 44100, range is 0 - 0), latency is 45ms (period: 30ms).
Oct 17, 2022 11:34:47.414 [0x6f7ef0e0] DEBUG - BASS: Creating a mixer with sample rate 44100 and 2 channels (decode: 0).
Oct 17, 2022 11:34:47.414 [0x6f7ef0e0] DEBUG - BASS: Sliding volume to 75.0 over 0 ms.
Oct 17, 2022 11:34:47.414 [0x6f7ef0e0] DEBUG - BASS: Adding back 1 streams after recreating mixer — 0x8000000c (flags: 00020000)
Oct 17, 2022 11:34:47.414 [0x6f7ef0e0] DEBUG - BASS: We have 0 dying streams which we're going to kill immediately.
Oct 17, 2022 11:34:47.414 [0x6f7ef0e0] INFO - BASS: Resuming audio output (started: 2)
Oct 17, 2022 11:34:47.414 [0x6f7ef0e0] DEBUG - BASS: Sliding volume to 75.0 over 0 ms.
Oct 17, 2022 11:34:47.414 [0x07fff0e0] INFO - BASS: Opening stream 81445.
Oct 17, 2022 11:34:47.415 [0x07fff0e0] DEBUG - Cache: Considering cached file (partial: 0, playing immediately: 1) with bitrate 187 kbps, looking for bitrate 187 kbps (too low: 0, disallowed partial: 0).
Oct 17, 2022 11:34:47.415 [0x07fff0e0] INFO - Cache: Opened cache file with 10158723 bytes (of 10158723 total) at '/home/ubuntu/Library/Caches/Media/bbc1defeb07d069c45e5c0e998729fab97a3779b399c76d9f522425e02478f23'.
Oct 17, 2022 11:34:47.415 [0x07fff0e0] INFO - Cache: Using RAM buffer of 8192 KB for item with container mp4 bitrate of 23 KB/sec.
Oct 17, 2022 11:34:47.415 [Javascript] DEBUG - PlayQueue: Adding track 81446 to audio player, gapless true gain -10.36 looping false.
Oct 17, 2022 11:34:47.436 [0x07fff0e0] DEBUG - Cache: Fully cached, not going into buffering state.
Oct 17, 2022 11:34:47.437 [0x07fff0e0] INFO - PQCache: Set item 81445 active to 0, 0 active remaining.
Oct 17, 2022 11:34:47.437 [0x07fff0e0] INFO - BASS: Stream 81445 completed caching.
Oct 17, 2022 11:34:47.437 [0x07fff0e0] INFO - PQCache: Set item 81445 active to 0, 0 active remaining.
Oct 17, 2022 11:34:47.437 [0x84aff0e0] INFO - PQCache: Set item 81446 active to 1, 1 active remaining.
Oct 17, 2022 11:34:47.437 [0x84aff0e0] INFO - BASS: Queueing stream (2 total, 2 handles) with identifier 81446, gain -10.4 dB, overlap duration 0 ms, start offset 0 ms (paused: 1).
Oct 17, 2022 11:34:47.437 [0x12fdf0e0] INFO - BASS: Pre-caching next stream 81446
Oct 17, 2022 11:34:47.437 [0x11fbf0e0] INFO - BASS: Opening stream 81446.
Oct 17, 2022 11:34:47.437 [0x11fbf0e0] INFO - Media: Found an item to direct play with bitrate under 0 (it was 183 kbps).
Oct 17, 2022 11:34:47.437 [0x11fbf0e0] DEBUG - Cache: Considering cached file (partial: 0, playing immediately: 1) with bitrate 183 kbps, looking for bitrate 183 kbps (too low: 0, disallowed partial: 0).
Oct 17, 2022 11:34:47.437 [0x11fbf0e0] INFO - Cache: Opened cache file with 9120619 bytes (of 9120619 total) at '/home/ubuntu/Library/Caches/Media/bd1da5c722d4231eaa246d7a586d20be2c0a401ba3312e8fe8a69060e3c05087'.
Oct 17, 2022 11:34:47.437 [0x11fbf0e0] INFO - Cache: Using RAM buffer of 8192 KB for item with container mp4 bitrate of 22 KB/sec.
Oct 17, 2022 11:34:47.443 [Javascript] DEBUG - PlayQueue: Final AudioQueue: 81445,81446.
Oct 17, 2022 11:34:47.443 [0x07fff0e0] INFO - Cache: Media was fully cached, just reading from disk.
Oct 17, 2022 11:34:47.443 [0x07fff0e0] DEBUG - BASS: Initial mixer offset 357.0 sec.
Oct 17, 2022 11:34:47.443 [Javascript] INFO - Audio: Setting play queue to 24f9f9f0axxxx5912f7e23861e9 /playQueues/11441
Oct 17, 2022 11:34:47.443 [0x07fff0e0] DEBUG - BASS: Setting stream gain for 81445 to -6.4 dB.
Oct 17, 2022 11:34:47.443 [0x07fff0e0] INFO - BASS: Opened stream 81445 in 6 ms (paused: 0) with gain -6.4 dB, max 0 Kbps (picked aac, 187 Kbps, actual 187 Kbps/sec).
Oct 17, 2022 11:34:47.443 [0x07fff0e0] INFO - BASS: Created a gapless source stream for 81445 (channel: 0x8000004d) with sample rate of 44100 and 2 channels (paused: 0)
Oct 17, 2022 11:34:47.443 [0x07fff0e0] DEBUG - BASS: Enabling limiter.
Oct 17, 2022 11:34:47.458 [0x11fbf0e0] DEBUG - Cache: Fully cached, not going into buffering state.
Oct 17, 2022 11:34:47.458 [0x11fbf0e0] DEBUG - Cache: Setting transfer speed limit for stream bd1da5c722d4231eaa246d7a586d20be2c0a401ba3312e8fe8a69060e3c05087 to 5 Mbps.
Oct 17, 2022 11:34:47.458 [0x11fbf0e0] INFO - PQCache: Set item 81446 active to 0, 0 active remaining.
Oct 17, 2022 11:34:47.458 [0x11fbf0e0] INFO - BASS: Stream 81446 completed caching.
Oct 17, 2022 11:34:47.458 [0x11fbf0e0] INFO - PQCache: Set item 81446 active to 0, 0 active remaining.
Oct 17, 2022 11:34:47.458 [0x8c8ab020] INFO - PQCache: Setting play queue to 24f9f9f0xxx912f7e23861e9/playQueues/11441
Oct 17, 2022 11:34:47.459 [Javascript] INFO - PlayQueue: Processed play media with success true
Oct 17, 2022 11:34:47.460 [Javascript] INFO - Audio: State changed from stopped to playing.
Oct 17, 2022 11:34:47.461 [Javascript] INFO - Audio: Queue identifier changed from undefined to 81445
Oct 17, 2022 11:34:47.461 [Javascript] INFO - PlayQueue: Saving state {"source":"24f9f9fxxxx51535912f7e23861e9","state":"playing","time":357000,"rate":1,"volume":75,"playQueueID":"11441","playQueueVersion":6,"playQueueItemID":"81445"}
Oct 17, 2022 11:34:47.463 [0x04dbd0e0] DEBUG - BASS: Gapless 0x8000004d sprang to life as 81445
Oct 17, 2022 11:34:47.464 [0x127cf0e0] DEBUG - BASS: Setting start offsets to be 0.0 sec (mixer) and 357.0 sec (stream).
Oct 17, 2022 11:34:47.464 [0x127cf0e0] DEBUG - BASS: Stream 81445 sprang to life at mixer time 0.0 sec stream position 357.0 sec.
Oct 17, 2022 11:34:47.464 [0x127cf0e0] DEBUG - BASS: STREAM TIMES
Oct 17, 2022 11:34:47.464 [0x127cf0e0] DEBUG - BASS:  - Stream 81445 (channel 0x8000004d) start: 0.0 end -1.0 (offset 357.0).
Oct 17, 2022 11:34:47.464 [0x127cf0e0] DEBUG - BASS:  - Stream 81446 (channel 0x00000000) start: -1.0 end -1.0 (offset 0.0).
Oct 17, 2022 11:34:47.466 [0x11fbf0e0] INFO - Cache: Media was fully cached, just reading from disk.
Oct 17, 2022 11:34:47.466 [0x11fbf0e0] DEBUG - BASS: Initial mixer offset 0.0 sec.
Oct 17, 2022 11:34:47.466 [0x11fbf0e0] DEBUG - BASS: Setting stream gain for 81446 to -6.4 dB.
Oct 17, 2022 11:34:47.466 [0x11fbf0e0] INFO - BASS: Opened stream 81446 in 7 ms (paused: 1) with gain -6.4 dB, max 0 Kbps (picked aac, 183 Kbps, actual 182 Kbps/sec).
Oct 17, 2022 11:34:47.466 [0x11fbf0e0] INFO - BASS: Created a gapless source stream for 81446 (channel: 0x80000056) with sample rate of 44100 and 2 channels (paused: 1)
Oct 17, 2022 11:34:47.466 [0x11fbf0e0] DEBUG - BASS: Enabling limiter.
Oct 17, 2022 11:34:47.466 [0x11fbf0e0] INFO - BASS: We're gaplessly connecting the two streams.
Oct 17, 2022 11:34:47.467 [Javascript] DEBUG - PlayQueue: Processing audio queue update with current track 81445.
Oct 17, 2022 11:34:47.468 [Javascript] DEBUG - PlayQueue: Processing send timelines in state playing time 357000.
Oct 17, 2022 11:34:47.468 [Javascript] INFO - ViewState: Progress 83% (357000 ms) on item 24f9f9f0a2728ef073219451535912f7e23861e9/43022.
Oct 17, 2022 11:34:47.468 [Javascript] INFO - ViewState: Trying to send directly.
Oct 17, 2022 11:34:47.469 [Javascript] INFO - METRICS: Starting new track.

Any ideas?

2

Yes. Upload the full logs.

3

Logs attached.

Plexamp.log (67.2 KB)

I:

  • Killed Plexamp
  • deleted the log file
  • started plex amp
  • cast to it from my phone
  • waited a bit (20 seconds or so). I could hear the sound, but distorted
  • paused
  • disconnected
  • copied off the log files.

Should be a clear run of it

I’m on a rPi4b running ubuntu 22.04 arm64 if that makes a difference.

thanks!

4

I had more of a hunt around the settings, and I found that I’d not set anything under Playback → Audio Output

Set that to the BCM, and I have perfect sound!

image
image1645×304 18.9 KB

(there was nothing - not even default - selected before)

5

OK, glad to hear you got it working!

6

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