search

kenellorando / cadence

All-in-one web radio suite with browser UI, music search, request, artwork, and real-time stream information.
https://cadenceradio.com
60 stars 16 forks source link

Frontend Disconnected from server and/or not playing audio #262

Closed willcl-ark closed 6 months ago

willcl-ark commented 6 months ago

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

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

Backend logs meanwhile look something like this:

Details ```log 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 * Redis version found by RedisSearch : 7.2.4 - oss redis | 8:M 08 May 2024 00:21:45.463 * RediSearch version 2.8.13 (Git=2.8-c1535c6) redis | 8:M 08 May 2024 00:21:45.463 * Low level api version 1 initialized successfully redis | 8:M 08 May 2024 00:21:45.463 * 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 * Initialized thread pools! redis | 8:M 08 May 2024 00:21:45.464 * 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 * RedisTimeSeries version 11012, git_sha=81d5ef59cdaba059a0eb9705c3c4b0127949f388 redis | 8:M 08 May 2024 00:21:45.754 * Redis version found by RedisTimeSeries : 7.2.4 - oss redis | 8:M 08 May 2024 00:21:45.754 * loaded default CHUNK_SIZE_BYTES policy: 4096 redis | 8:M 08 May 2024 00:21:45.754 * loaded server DUPLICATE_POLICY: block redis | 8:M 08 May 2024 00:21:45.754 * Setting default series ENCODING to: compressed redis | 8:M 08 May 2024 00:21:45.754 * 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 * Created new data type 'ReJSON-RL' redis | 8:M 08 May 2024 00:21:45.755 * version: 20610 git sha: unknown branch: unknown redis | 8:M 08 May 2024 00:21:45.755 * Exported RedisJSON_V1 API redis | 8:M 08 May 2024 00:21:45.755 * Exported RedisJSON_V2 API redis | 8:M 08 May 2024 00:21:45.755 * Exported RedisJSON_V3 API redis | 8:M 08 May 2024 00:21:45.755 * Exported RedisJSON_V4 API redis | 8:M 08 May 2024 00:21:45.755 * Exported RedisJSON_V5 API redis | 8:M 08 May 2024 00:21:45.755 * 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 * Acquired RedisJSON_V5 API redis | 8:M 08 May 2024 00:21:45.755 * 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 * Created new data type 'GearsType' redis | 8:M 08 May 2024 00:21:45.756 * Detected redis oss redis | 8:M 08 May 2024 00:21:45.756 # could not initialize RedisAI_InitError redis | redis | 8:M 08 May 2024 00:21:45.756 * Failed loading RedisAI API. redis | 8:M 08 May 2024 00:21:45.756 * 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 * 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 commented 6 months ago

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 commented 6 months ago

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 commented 6 months ago

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