Frontend Disconnected from server and/or not playing audio

[willcl-ark]

Hi, first of all, thanks for this interesting stack!

I do have a few issues though, (probably all related):

• Frontend shows incorrect number of songs in database (85 shown, many blank, vs 66 in directory)
• Frontend shows "Disconnected from server." and does not allow playing of the station

Backend logs meanwhile look something like this:

Details

root@dsb27088 ~/s/cadence (master)# docker compose up
WARN[0000] /root/src/cadence/docker-compose.yml: `version` is obsolete
[+] Running 6/0
 ✔ Container postgres    Created                                                                                                   0.0s
 ✔ Container redis       Created                                                                                                   0.0s
 ✔ Container icecast2    Created                                                                                                   0.0s
 ✔ Container liquidsoap  Created                                                                                                   0.0s
 ✔ Container cadence     Created                                                                                                   0.0s
 ✔ Container nginx       Created                                                                                                   0.0s
Attaching to cadence, icecast2, liquidsoap, nginx, postgres, redis
postgres    |
postgres    | PostgreSQL Database directory appears to contain a database; Skipping initialization
postgres    |
postgres    | 2024-05-08 00:21:44.403 UTC [1] LOG:  starting PostgreSQL 15.6 on x86_64-pc-linux-musl, compiled by gcc (Alpine 13.2.1_git20231014) 13.2.1 20231014, 64-bit
postgres    | 2024-05-08 00:21:44.403 UTC [1] LOG:  listening on IPv4 address "0.0.0.0", port 5432
postgres    | 2024-05-08 00:21:44.403 UTC [1] LOG:  listening on IPv6 address "::", port 5432
postgres    | 2024-05-08 00:21:44.748 UTC [1] LOG:  listening on Unix socket "/var/run/postgresql/.s.PGSQL.5432"
postgres    | 2024-05-08 00:21:44.856 UTC [24] LOG:  database system was shut down at 2024-05-08 00:19:54 UTC
postgres    | 2024-05-08 00:21:45.006 UTC [1] LOG:  database system is ready to accept connections
redis       | 8:C 08 May 2024 00:21:45.271 # WARNING Memory overcommit must be enabled! Without it, a background save or replication may fail under low memory condition. Being disabled, it can also cause failures without low memory condition, see https://github.com/jemalloc/jemalloc/issues/1328. To fix this issue add 'vm.overcommit_memory = 1' to /etc/sysctl.conf and then reboot or run the command 'sysctl vm.overcommit_memory=1' for this to take effect.
redis       | 8:C 08 May 2024 00:21:45.271 * oO0OoO0OoO0Oo Redis is starting oO0OoO0OoO0Oo
redis       | 8:C 08 May 2024 00:21:45.271 * Redis version=7.2.4, bits=64, commit=00000000, modified=0, pid=8, just started
redis       | 8:C 08 May 2024 00:21:45.271 * Configuration loaded
redis       | 8:M 08 May 2024 00:21:45.271 * monotonic clock: POSIX clock_gettime
redis       | 8:M 08 May 2024 00:21:45.301 * Running mode=standalone, port=6379.
redis       | 8:M 08 May 2024 00:21:45.301 * Module 'RedisCompat' loaded from /opt/redis-stack/lib/rediscompat.so
redis       | 8:M 08 May 2024 00:21:45.463 * <search> Redis version found by RedisSearch : 7.2.4 - oss
redis       | 8:M 08 May 2024 00:21:45.463 * <search> RediSearch version 2.8.13 (Git=2.8-c1535c6)
redis       | 8:M 08 May 2024 00:21:45.463 * <search> Low level api version 1 initialized successfully
redis       | 8:M 08 May 2024 00:21:45.463 * <search> concurrent writes: OFF, gc: ON, prefix min length: 2, prefix max expansions: 200, query timeout (ms): 500, timeout policy: return, cursor read size: 1000, cursor max idle (ms): 300000, max doctable size: 1000000, max number of search results:  10000, search pool size: 20, index pool size: 8,
redis       | 8:M 08 May 2024 00:21:45.464 * <search> Initialized thread pools!
redis       | 8:M 08 May 2024 00:21:45.464 * <search> Enabled role change notification
redis       | 8:M 08 May 2024 00:21:45.464 * Module 'search' loaded from /opt/redis-stack/lib/redisearch.so
icecast2    | [2024-05-08  00:21:45] WARN CONFIG/_parse_root Warning, serving of static files has been disabled in the config, this will also affect files used by the web interface (stylesheets, images).
icecast2    | [2024-05-08  00:21:45] WARN fserve/fserve_recheck_mime_types Cannot open mime types file /etc/mime.types
redis       | 8:M 08 May 2024 00:21:45.754 * <timeseries> RedisTimeSeries version 11012, git_sha=81d5ef59cdaba059a0eb9705c3c4b0127949f388
redis       | 8:M 08 May 2024 00:21:45.754 * <timeseries> Redis version found by RedisTimeSeries : 7.2.4 - oss
redis       | 8:M 08 May 2024 00:21:45.754 * <timeseries> loaded default CHUNK_SIZE_BYTES policy: 4096
redis       | 8:M 08 May 2024 00:21:45.754 * <timeseries> loaded server DUPLICATE_POLICY: block
redis       | 8:M 08 May 2024 00:21:45.754 * <timeseries> Setting default series ENCODING to: compressed
redis       | 8:M 08 May 2024 00:21:45.754 * <timeseries> Detected redis oss
redis       | 8:M 08 May 2024 00:21:45.754 * Module 'timeseries' loaded from /opt/redis-stack/lib/redistimeseries.so
redis       | 8:M 08 May 2024 00:21:45.755 * <ReJSON> Created new data type 'ReJSON-RL'
redis       | 8:M 08 May 2024 00:21:45.755 * <ReJSON> version: 20610 git sha: unknown branch: unknown
redis       | 8:M 08 May 2024 00:21:45.755 * <ReJSON> Exported RedisJSON_V1 API
redis       | 8:M 08 May 2024 00:21:45.755 * <ReJSON> Exported RedisJSON_V2 API
redis       | 8:M 08 May 2024 00:21:45.755 * <ReJSON> Exported RedisJSON_V3 API
redis       | 8:M 08 May 2024 00:21:45.755 * <ReJSON> Exported RedisJSON_V4 API
redis       | 8:M 08 May 2024 00:21:45.755 * <ReJSON> Exported RedisJSON_V5 API
redis       | 8:M 08 May 2024 00:21:45.755 * <ReJSON> Enabled diskless replication
redis       | 8:M 08 May 2024 00:21:45.755 * Module 'ReJSON' loaded from /opt/redis-stack/lib/rejson.so
redis       | 8:M 08 May 2024 00:21:45.755 * <search> Acquired RedisJSON_V5 API
redis       | 8:M 08 May 2024 00:21:45.755 * <bf> RedisBloom version 2.6.12 (Git=unknown)
redis       | 8:M 08 May 2024 00:21:45.755 * Module 'bf' loaded from /opt/redis-stack/lib/redisbloom.so
redis       | 8:M 08 May 2024 00:21:45.756 * <redisgears_2> Created new data type 'GearsType'
redis       | 8:M 08 May 2024 00:21:45.756 * <redisgears_2> Detected redis oss
redis       | 8:M 08 May 2024 00:21:45.756 # <redisgears_2> could not initialize RedisAI_InitError
redis       |
redis       | 8:M 08 May 2024 00:21:45.756 * <redisgears_2> Failed loading RedisAI API.
redis       | 8:M 08 May 2024 00:21:45.756 * <redisgears_2> RedisGears v2.0.20, sha='9b737886bf825fe29ddc2f8da81f73cbe0b4e858', build_type='release', built_for='Linux-ubuntu22.04.x86_64', redis_version:'7.2.4', enterprise:'false'.
redis       | 8:M 08 May 2024 00:21:45.757 * <redisgears_2> Registered backend: js.
redis       | 8:M 08 May 2024 00:21:45.757 * Module 'redisgears_2' loaded from /opt/redis-stack/lib/redisgears.so
redis       | 8:M 08 May 2024 00:21:45.758 * Server initialized
redis       | 8:M 08 May 2024 00:21:45.758 * Ready to accept connections tcp
liquidsoap  | 2024/05/08 00:21:48 >>> LOG START
liquidsoap  | 2024/05/08 00:21:47 [main:3] Liquidsoap 1.4.3
liquidsoap  | 2024/05/08 00:21:47 [main:3] Using: bytes=[distributed with OCaml 4.02 or above] pcre=[unspecified] sedlex=2.2 menhirLib=20201216 dtools=0.4.2 duppy=0.8.0 cry=0.6.5 mm=0.5.0 xmlplaylist=0.1.5 lastfm=0.3.2 ogg=0.5.2 vorbis=0.7.1 opus=0.1.3 speex=0.2.1 mad=0.4.6 flac=0.1.7 flac.ogg=0.1.7 dynlink=[distributed with Ocaml] lame=0.3.4 shine=0.2.1 gstreamer=0.3.0 frei0r=0.1.1 theora=0.3.1 gavl=0.1.6 ffmpeg=0.4.3 bjack=0.1.5 alsa=0.3.0 ao=0.2.1 samplerate=0.1.4 taglib=0.3.6 ssl=0.5.9 magic=0.7.3 camomile=[unspecified] inotify=2.3 yojson=[unspecified] faad=0.4.0 soundtouch=0.1.8 portaudio=0.2.1 pulseaudio=0.1.3 ladspa=0.1.5 sdl=0.9.1 camlimages=4.2.6 lo=0.1.2 gd=1.0a5
liquidsoap  | 2024/05/08 00:21:47 [gstreamer.loader:3] Loaded GStreamer 1.18.4 0
liquidsoap  | 2024/05/08 00:21:47 [dynamic.loader:3] Could not find dynamic module for fdkaac encoder.
liquidsoap  | 2024/05/08 00:21:48 [frame:3] Using 44100Hz audio, 25Hz video, 44100Hz master.
liquidsoap  | 2024/05/08 00:21:48 [frame:3] Frame size must be a multiple of 1764 ticks = 1764 audio samples = 1 video samples.
liquidsoap  | 2024/05/08 00:21:48 [frame:3] Targetting 'frame.duration': 0.04s = 1764 audio samples = 1764 ticks.
liquidsoap  | 2024/05/08 00:21:48 [frame:3] Frames last 0.04s = 1764 audio samples = 1 video samples = 1764 ticks.
liquidsoap  | 2024/05/08 00:21:48 [sandbox:3] Running inside a docker container, disabling sandboxing..
liquidsoap  | 2024/05/08 00:21:48 [video.converter:3] Using preferred video converter: gavl.
liquidsoap  | 2024/05/08 00:21:48 [audio.converter:3] Using samplerate converter: ffmpeg.
liquidsoap  | 2024/05/08 00:21:48 [mp3:3] Loading playlist...
liquidsoap  | 2024/05/08 00:21:48 [mp3:3] Playlist is a directory.
liquidsoap  | 2024/05/08 00:21:48 [mp3:3] Successfully loaded a playlist of 65 tracks.
liquidsoap  | 2024/05/08 00:21:48 [fish-radio:3] Connecting mount fish-radio for source@icecast2...
liquidsoap  | 2024/05/08 00:21:48 [decoder:3] Method "FFMPEG" accepted "/home/davidblaine/radio/mp3/RA.906_Azu_Tiwaline.mp3".
liquidsoap  | 2024/05/08 00:21:48 [decoder:3] Method "FFMPEG" accepted "/home/davidblaine/radio/mp3/Cxemcast_091_Oleg_Patselya.mp3".
liquidsoap  | 2024/05/08 00:21:48 [fish-radio:3] Connection setup was successful.
liquidsoap  | 2024/05/08 00:21:48 [clock.wallclock_main:3] Streaming loop starts, synchronized with wallclock.
liquidsoap  | 2024/05/08 00:21:48 [fallback_9371:3] Switch to fallback_9368.
liquidsoap  | 2024/05/08 00:21:48 [fallback_9368:3] Switch to mksafe.
liquidsoap  | 2024/05/08 00:21:48 [mksafe:3] Switch to safe_blank.
liquidsoap  | 2024/05/08 00:21:48 [mp3:3] Prepared "/home/davidblaine/radio/mp3/RA.906_Azu_Tiwaline.mp3" (RID 1).
liquidsoap  | 2024/05/08 00:21:48 [mksafe:3] Switch to mp3 with transition.
liquidsoap  | 2024/05/08 00:21:48 [ffmpeg:3] [mp3float @ 0x7f41b80a6500] Could not update timestamps for skipped samples.
nginx       | /docker-entrypoint.sh: /docker-entrypoint.d/ is not empty, will attempt to perform configuration
nginx       | /docker-entrypoint.sh: Looking for shell scripts in /docker-entrypoint.d/
nginx       | /docker-entrypoint.sh: Launching /docker-entrypoint.d/10-listen-on-ipv6-by-default.sh
nginx       | 10-listen-on-ipv6-by-default.sh: info: IPv6 listen already enabled
nginx       | /docker-entrypoint.sh: Sourcing /docker-entrypoint.d/15-local-resolvers.envsh
nginx       | /docker-entrypoint.sh: Launching /docker-entrypoint.d/20-envsubst-on-templates.sh
nginx       | /docker-entrypoint.sh: Launching /docker-entrypoint.d/30-tune-worker-processes.sh
nginx       | /docker-entrypoint.sh: Configuration complete; ready for start up
postgres    | 2024-05-08 00:21:53.145 UTC [28] ERROR:  extension "fuzzystrmatch" already exists
postgres    | 2024-05-08 00:21:53.145 UTC [28] STATEMENT:  CREATE EXTENSION fuzzystrmatch
postgres    | 2024-05-08 00:21:53.155 UTC [22] LOG:  checkpoint starting: immediate force wait
postgres    | 2024-05-08 00:21:53.401 UTC [22] LOG:  checkpoint complete: wrote 5 buffers (0.0%); 0 WAL file(s) added, 0 removed, 0 recycled; write=0.071 s, sync=0.058 s, total=0.247 s; sync files=4, longest=0.039 s, average=0.015 s; distance=1 kB, estimate=1 kB
cadence     | 2024/05/08 00:21:54 INFO Database population completed. func=postgresPopulate
cadence     | 2024/05/08 00:21:54 INFO Starting Cadence on port <:8080>. func=main
cadence     | 2024/05/08 00:22:07 WARN The currently playing song could not be found in the database. The database may not be populated. func=NowPlayingMetadata
cadence     | 2024/05/08 00:22:07 WARN The currently playing song could not be found in the database. The database may not be populated. func=NowPlayingAlbumArt
cadence     | 2024/05/08 00:22:30 INFO IP <100.89.20.73> is rate limited. func=rateLimitArt
cadence     | 2024/05/08 00:22:30 WARN The currently playing song could not be found in the database. The database may not be populated. func=NowPlayingMetadata
cadence     | 2024/05/08 00:22:30 WARN The currently playing song could not be found in the database. The database may not be populated. func=NowPlayingAlbumArt
cadence     | 2024/05/08 00:22:32 WARN The currently playing song could not be found in the database. The database may not be populated. func=NowPlayingMetadata
cadence     | 2024/05/08 00:22:32 INFO IP <100.89.20.73> is rate limited. func=rateLimitArt
cadence     | 2024/05/08 00:22:32 WARN The currently playing song could not be found in the database. The database may not be populated. func=NowPlayingAlbumArt
cadence     | 2024/05/08 00:22:35 INFO IP <100.89.20.73> is rate limited. func=rateLimitArt
cadence     | 2024/05/08 00:22:35 WARN The currently playing song could not be found in the database. The database may not be populated. func=NowPlayingMetadata
cadence     | 2024/05/08 00:22:35 WARN The currently playing song could not be found in the database. The database may not be populated. func=NowPlayingAlbumArt
cadence     | 2024/05/08 00:22:39 INFO Request-by-ID by client 100.89.20.73:48286. func=Request
liquidsoap  | 2024/05/08 00:22:39 [server:3] New client: 172.22.0.5.
liquidsoap  | 2024/05/08 00:22:39 [decoder:3] Method "FFMPEG" accepted "/home/davidblaine/radio/mp3/AceMo_for_Thank_You_for_Sweating_Side_A.mp3".
cadence     | 2024/05/08 00:22:39 INFO Message from audio source server: 3
cadence     |  func=liquidsoapRequest
liquidsoap  | 2024/05/08 00:22:39 [server:3] Client 172.22.0.5 disconnected.
cadence     | 2024/05/08 00:25:26 WARN The currently playing song could not be found in the database. The database may not be populated. func=NowPlayingAlbumArt
cadence     | 2024/05/08 00:25:26 WARN The currently playing song could not be found in the database. The database may not be populated. func=NowPlayingMetadata
cadence     | 2024/05/08 00:25:32 WARN The currently playing song could not be found in the database. The database may not be populated. func=NowPlayingMetadata
cadence     | 2024/05/08 00:25:32 INFO IP <172.21.0.1> is rate limited. func=rateLimitArt
cadence     | 2024/05/08 00:25:32 WARN The currently playing song could not be found in the database. The database may not be populated. func=NowPlayingAlbumArt
cadence     | 2024/05/08 00:25:33 INFO IP <172.21.0.1> is rate limited. func=rateLimitArt
cadence     | 2024/05/08 00:25:33 WARN The currently playing song could not be found in the database. The database may not be populated. func=NowPlayingMetadata
cadence     | 2024/05/08 00:25:33 WARN The currently playing song could not be found in the database. The database may not be populated. func=NowPlayingAlbumArt
cadence     | 2024/05/08 00:25:36 INFO IP <172.21.0.1> is rate limited. func=rateLimitArt
cadence     | 2024/05/08 00:25:36 WARN The currently playing song could not be found in the database. The database may not be populated. func=NowPlayingMetadata
cadence     | 2024/05/08 00:25:36 WARN The currently playing song could not be found in the database. The database may not be populated. func=NowPlayingAlbumArt
cadence     | 2024/05/08 00:25:38 INFO IP <172.21.0.1> is rate limited. func=rateLimitArt
cadence     | 2024/05/08 00:25:38 WARN The currently playing song could not be found in the database. The database may not be populated. func=NowPlayingMetadata
cadence     | 2024/05/08 00:25:38 WARN The currently playing song could not be found in the database. The database may not be populated. func=NowPlayingAlbumArt
postgres    | 2024-05-08 00:26:53.499 UTC [22] LOG:  checkpoint starting: time

The songs do include some youtube rips, however I sanitised filenames (no spaces) and largely populated ID3 tags, though some are certainly missing Artist names.

I have also tried just putting a single (properly tagged) MP3 in the source directory, however whilst this give a correct db on the frontend, there is no volume when played?

The stream is available/working in both cases via the direct icecast mount on port 80, so it seems icecast and liquidsoap are both working properly, only the frontend seems to not be working.

[kenellorando]

Hi @willcl-ark! First thanks for your interest in my repo. I will do my best to provide some help.

Your first issue with the extra songs (85 vs apparent 66) appearing in the database makes me think of two possibilities. Also, them appearing blank seems incidental, and would make sense if the files are not populated by both title and artist metadata.

1. You might have nested sub-directories with additional files. When Cadence starts up, it searches recursively based on your provided target.
2. This one is more of a reach, but you also might have entered a situation where you tried to start up Cadence once but failed, partially populating the database in the process. Normally, Cadence will drop the entire database and completely refresh it at startup, but it's possible it might have skipped this. A strong signal of this is if you see duplicate entries in your database. If this is the case, I suggest restarting the stack with docker compose down (verifying the postgres component is removed) then docker compose up.

Your second issue diagnosis about the disconnect between the frontend and radio services seems to be correct to me. A couple more possibilities I can think of:

1. By pure coincidence, you might have tried to pull a container at the same time I was pushing an updated container, which unfortunately turned out to be broken. I was just working on it about an hour ago. The breakage seems to be in line with what you described-- broken frontend operation but working direct-connect radio services. I re-pushed a new working latest version. So it's possible you might just need to update containers:

   docker compose down
   docker compose pull
   docker compose up
   

2. If updating containers does not fix the issue, I might need more information about your installation. Did you use the install.sh script? If so, the value you populate for Stream address is what will exactly be copied to the frontend. I'm going to gloss over some of the details here, but that value is passed around until it is ultimately set by Cadence into the audio source that connects the frontend to Icecast. I would start by verifying that this is correct, rerunning ./install.sh if necessary.

Let's start with these for now. Let me know if any problems are alleviated, I will follow up. Thanks!

[willcl-ark]

Thanks so much for the detailed (and fast!) reply. It didn't exactly solve my issue, but was enough to get me thinking correctly so that I was able to myself :)

My issue was that I am already running Caddy on the base metal, so needed to disable nginx, and modify the ports being used from 80 and 8080 to 81 and 8081. Then make sure those changes were also matching in docker-compose.yml. Now that I've managed that, and set the DNS records the right way around, I have it all working!

The phantom db entries seemed to sort themselves out too, which is a nice bonus.

Now I just need to fix my tags, and I'm away :)

Thanks again

[kenellorando]

Happy to assist, or at least put you on the right track! Enjoy your station!