Cannot get a running installation of Libretime with functional Webstreams

[boydbadten]

Libretime Developers!!

First of all, we really appreciate you guys! Thanks so much for Libretime! Our little non-profit used Airtime for many years and our radio station is an important offering to our community.

Airtime began to get really flakey for us around 2019 and thank goodness we found Libretime! We converted over to Libretime around 2020 and it has been more dependable than Airtime ever was.

Now we must move from the hosting provider we were using which has been running Libretime version fd1449674—and has been running flawlessly since December of 2020. I know how to restore a saved DB and get the settings right to migrate so I thought it would be no big deal.

To my dismay, I have not been able to get a fully functional version of Libretime installed on either my development system or on a Digital Ocean instance for the past two weeks. The main problem with Libretime alpha10 is that Webstreams do not work—instead they either don’t start at all or else they play for about 8 minutes and then quit.

Our radio station depends heavily on webstreams since we mix in one or more live programs (from Butt>>Icecast) as well as static content every day. I see a lot of github commits lately and so I’ve installed a lot of new builds lately in case this gets fixed any day. But I’m so desperate that I would be fine with installing an old version of Libretime—which works—but I’ve totally struck out.

What I have tried – all on clean, updated Bionic Ubuntu:

1. Installed latest Libretime from git—Icecast fails to link up to Libretime regardless of settings in either—can’t stream with icecast with either default connection or with custom settings
2. Installed git checkout of 3.0.0-alpha.10—install completes and functions, except Webstreams broken (explained above)
3. (Older version might work OK?) – Tried to install older versions from git, 7,8x, 9x—install scripts error out and fail due to missing dependencies or wrong pathnames, etc….cannot complete install scripts
4. (Older version might work OK?) - Install older version from older .debs----all fail to complete install script due to earlier mentioned missing dependencies, wrong pathnames, etc……except alpha6.2 install script does complete on Xenial—but most of the Libretime daemons fail (really fail and cannot be fixed by me)
5. Installed from git with “git checkout 9f1e41e6fa8656d2aa2dc74d2ed07026bef38593”—under the premise that it fixes the icecast-libretime connection plus the webstream problem (found this as a discord post by a user)----install script completed and libretime runs—except webstreams broken (as above)
6. From Libretime github issue on old-moldy liquidsoap 1.1.1 creating problems with webstreams due to one or more changes elsewhere (Problem: We want to upgrade to Liquidsoap >=1.3.x · Issue #192 · libretime/libretime · GitHub) I used an otherwise functional Libretime-alpha-10 install and attempted to fix the liquidsoap problems by upgrading from liquidsoap 1.1.1 to various newer versions by:
   a. Hairmare’s solution found near the beginning of the page----could not complete procedure (no surprise—it’s 5 years old….)
   b. Using Opam to upgrade to liquidsoap 1.3.7 (or other versions) after removing liquidsoap 1.1.1—Opam refused to pin install to 1.3.7 and would only install the latest liquidsoap 2.0.3—which Libretime daemon could not work with despite my best efforts.
   c. Install liquidsoap 1.3.7 (tried others as well) from source—many, many tries and .configure or make always failed due to package version or other inscrutable errors.

So….I’m in a situation where I already moved our Libretime installation to a new hosting environment and it’s running on Libretime alpha-10 because I missed catching the webstream fail issue in my testing. And I’m in hot water with listeners and others I report to—because I cannot make Libretime play webstreams—they just get 2 hours of silence.

Help me. Is there anything I’ve missed as far as getting Libretime to function fully—with webstreams?

My goal is to never pester developers with trite questions without giving it a really good effort myself to solve things. But I’m out of bullets and I’m about 2 weeks and 60+ hours in now trying to get a working version of Libretime going.

Thanks again. I just made a donation to Libretime out of gratitude for the use of Libretime we’ve had in the past.

[Darren3770]

I am just running a test now, i have managed to get 2 30min http streams to run fully, back to back. Tomorrow i will try a 2hr stream. and then install a fresh copy of Libretime on a digital ocean droplet, make the same changes, if it works i will tell you how to do it. Very simple fix that i stumbled on, whilst looking at Liquidsoap and icecast. Ive currently got it running on digital ocean with Ubuntu 18.04.
I will let you know the out come.

Darren

[boydbadten]

Thanks Darren—I’m very curious to see what you found.

I know from reading that jooola has fashioned a comprehensive solution to the Webstreams challenge that will be rolled into alpha-11 release. I’m trying to figure out what I’m going to do with my broken production server now—wait for alpha-11 release or pull an old snapshot out of EC2 and fire up a mothballed version just to get the Webstreams going again. It would be sweet to know roughly when alpha-11 will be out for that reason. But I know the developers are working their behinds off and will release it when it’s really ready.

As you can see I’ve tried a lot of things—so I’m super curious as to what you discovered.

Boyd

[Darren3770]

Hi, I am at a loss, this morning i got libretime to run a webstream for over 2hrs. I try again later and back to only 6mins. I adjusted Icecast, I found something online concerning Icecast and liquidsoap, it recommended turning the burst off and changing sources from 2 to 10. I did that and it worked. But as i said, a few hours later it doesn’t want to know, and now it won’t play https streams at all.
I’m going to use Libretime as a front end, and pay for something to use as a back end that enables scheduling webstreams. I have been looking at RadioJar, they do a Cheapish set up for £20 which is roughly 20eur. I have been using RadioBoss, but that isn’t good for backend.
I will have another go tomorrow, I will let you know.

Darren

[boydbadten]

For what it’s worth, I’ve used Airtime/Libretime 24/7 for almost 7 years and I think it’s a fantastic app. Nothing comes close as far as radio goes. During that time I’ve never had to deal with something like this webstream snafu for any substantial length of time—it just works. Our most recent Libretime server ran flawlessly for over 2 years and was rebooted perhaps a couple of times.

Our Libretime devs are doing their best coping with OS and component package version changes introducing mayhem and friction into their brew as well as adding new, cool features. From what I’ve gathered of reading about the error logs and core issues here, I somewhat doubt that those variables in icecast.xml that you mention would provide a perfect fix. I think the problem is in how liquidsoap is reacting to various situations–such as what comes before/after the webstream in the programming, if anything, and how the timing of that detection is treated by liquidsoap’s other rules. I might not be perfectly accurate in this description. But I know they will have this fixed soon.

I would love to know when Libretime 3.0.0-Alpha-11 will be pushed out. I know that the webstream problem will be solved in that release. Hang in there.

[Darren3770]

I am definitely sticking with it. Unfortunately i am not very computer savvy when it comes to linux. I only have a small Internet radio station, that I enjoy doing. For now , I will run libretime with RadioJar, Libretime can do the music , prerecorded shows and live shows and RadioJar the Webstreams.
I agree that everyone has done an amazing job with developing Libretime, I am very impressed and really appreciate the hard work they have done. I wish i was as good as they are. Hopefully Alpha 11 will be ready to try soon.

Darren

[Darren3770]

Hi Boyd, I have just downloaded the latest version,
chore: bump actions/checkout from 2 to 3 by dependabot[bot] · Pull Request #1668 · libretime/libretime · GitHub onto a Digital Ocean droplet with Ubuntu 20.04,
I did all the Ubuntu updates before downloading, then updated again after the download, then did the install. I created a show put a song before a webstream and after. So far the webstream is playing, 20 mins and counting. To start with the stream cut out after afew seconds when the first song was playing, I suspect an Icecast issue as the stream counter read 11mins and it took ages to buffer and start. But when the webstream started it streamed ok, but running with a 40s delay. I have noticed that it will only stream on default settings, I haven’t changed anything like passwords or anything yet, i am just seeing how the webstream goes. I hope this helps and if you can work the delay out please let me know.

Darren

[boydbadten]

Thanks Darren—yes they are definitely working on this.

I’m curious though, any time I have attempted to install Libretime on Ubuntu 20.04 it refuses and says it’s only good for 18.04. Did you have to do anything to get around that or have you ever seen that version check blow you out of the install script?

What am I missing?

[Darren3770]

Yes I have had that, I ran all the ubuntu updates , downloaded Libretime then redid the updates. I read that some cloud suppliers run broken O/S, so its good too do updates. Is your Libretime working ok, I could get webstreams to run but not any music files. the files played but the stream only played for about 8seconds of each file and took ages for the Icecast player to Load. Im going to try a download on 18.04 to see if that solves it. Unfortunately, I haven’t got a clue on linux so can’t get error logs or stuff like that up, I am not sure what commands to put infront of the stuff in the troubleshooting page.

Darren

[boydbadten]

I do have a Digital Ocean droplet running Ubuntu 18.04 and Libretime 3.0.0.0-Alpha-10 and it runs correctly all except the webstreams. I installed it about 2 weeks ago.

But most of the work I do testing is on one of several KVM virtual machines which have snapshots that let me roll back or forward to positions which comprise a totally clean OS state. That means they are installed by me from ISO and updated to be “latest” periodically.

I did manage to install Libretime on Ubuntu 20.04 recently but it was not stable. As soon as I started streaming it would spawn an endless number of python-playout threads—each one consuming about 2% cpu resources. After about a minute the cpu is saturated and cannot continue.

[Darren3770]

Sounds like whats happening on the version I have on 20.04. I just tried installing on 18.04 from the new commit i sent you and It says problem with Liquidsoap. I think I will have to wait for Alpha11, as I said, I haven’t a clue when it comes to Linux, so don’t know where to start. Hats off to all of you that understands it, I can’t get my head around it. I have a working version, but without the webstream, so I will use that in conjuction with Radiojar so I can get the streams on that. I will get the best of both worlds and it means i have always got a fallback. I only have a small station that i am trying to build up, before Covid I was a truck driver, but I got Covid at Xmas 2020 and haven’t been able to work since. So the radio keeps me going.
If you know of any idiot guides , please let me know.

Cheers
Darren

[Darren3770]

Hi Boyd, I hope you are well, I was wondering if you had found a solution for the webstream problem. I see that Alpha11 is due for release next week, so fingers crossed. I know everyone is working hard to solve the issue, which I really appreciate, and I know everyone else feels the same.
I also have seen your post about SSL , so i might pic your brains next week.

cheers

Darren

[boydbadten]

I’m waiting for Alpha11 to come out. Looking forward to finishing migration of our server to a new host.

Did you try the ssl for Icecast method? It works if you just follow it and do all the steps.

If you had any difficulties I’m curious to hear about them.

[boydbadten]

I now have Libretime Alpha12 running on Ubuntu 20.04 and it is working much better for me than Alpha10 did. Webstreams seem to behave now—that was the major issue for me on Alpha10. And it seems as though Alpha12 works better (for me) in Ubuntu 20.04 than 18.04. I would rather use 20.04 at this point anyway—it has a newer Liquidsoap, Icecast, Postgresql, etc…somewhat more futureproof.

[rtl3]

Hi BoydBedten,

I’m trying to install a new instance on Ubuntu 20.04 also, and i get a lot of thread, and therefore my stream is not working. Seems like your faced the same situation before, have found you any solution ?
I’m installing the lastest Alpha12 from tar file.

[esbobkov]

I have Alpha 12 on Ubuntu 20.04
Sometimes (2 - 3 times per week) server have countless playout processes and going to Out Of Memory error. Server has 2Gb RAM

How to fix it?

[joola]

Please share the logs when asking for help.

Jo

[boydbadten]

I don’t have any idea why this is happening to you—the cpu being overloaded with playout threads. This happened to me some months ago (predictably) with Alpha10 and Ubuntu 20.04. But since they released Alpha12 I have never experienced this.

Are you very certain that you’re running a clean install of Alpha12? Or was it an upgrade?

I would try installing from git repository just to be sure. It should not matter of course. But I always pull from the git repository and the multiple instances of Libretime Alpha12 that I have running now all run perfectly.

[rtl3]

Thanks for your answer, it was a clean install. I tried it several time with always the same result (but from the same tar file). I finally downgrade the server to 18, and made it work, because I couldn’t find any solution to this error.
Thanks for your reply anyway !

[esbobkov]

Now i have Alpha 13 with same problem
playout

2022-08-10 17:58:48.424 | INFO     | libretime_playout.pypofetch:main:520 - Queue timeout. Fetching schedule manually
2022-08-10 17:58:48.842 | INFO     | libretime_playout.pypofetch:main:499 - Loop #27
2022-08-10 17:58:48.844 | INFO     | libretime_playout.pypoliqqueue:main:56 - New schedule received
2022-08-10 17:58:48.844 | INFO     | libretime_playout.pypoliqqueue:main:37 - waiting 34.155469s until next scheduled item
2022-08-10 17:59:23.003 | INFO     | libretime_playout.pypoliqqueue:main:37 - waiting 36.996815s until next scheduled item
2022-08-10 18:00:00.003 | INFO     | libretime_playout.pypoliqqueue:main:37 - waiting 3553.996144s until next scheduled item
2022-08-10 18:05:28.842 | INFO     | libretime_playout.pypofetch:main:520 - Queue timeout. Fetching schedule manually
2022-08-10 18:05:29.690 | ERROR    | libretime_playout.pypofetch:sanity_check_media_item:397 - end - start length: %s
2022-08-10 18:05:29.690 | ERROR    | libretime_playout.pypofetch:sanity_check_media_item:398 - cue_out - cue_in length: %s
2022-08-10 18:05:29.691 | ERROR    | libretime_playout.pypofetch:sanity_check_media_item:399 - Two lengths are not equal!!!
2022-08-10 18:05:29.692 | INFO     | libretime_playout.pypofile:copy_file:56 - copying from None to local cache /var/lib/libretime/playout/scheduler/126.mp3
2022-08-10 18:05:29.692 | INFO     | libretime_playout.pypofile:copy_file:59 - {'type': <EventKind.FILE: 'file'>, 'independent_event': False, 'row_id': 96032, 'start': datetime.datetime(2022, 8, 10, 19, 0), 'end': datetime.datetime(2022, 8, 10, 21, 35, 49), 'uri': None, 'id': 126, 'show_name': 'Anabiosis', 'fade_in': 500.0, 'fade_out': 10000.0, 'cue_in': 20.2879, 'cue_out': 9370.13, 'metadata': {'track_title': 'isolatedmix 102 - Charlie May', 'artist_name': 'Charlie May', 'mime': 'audio/mp3'}, 'replay_gain': '-2.16', 'filesize': 377341708, 'file_ext': '.mp3', 'dst': '/var/lib/libretime/playout/scheduler/126.mp3', 'file_ready': False}
2022-08-10 18:05:29.715 | INFO     | libretime_playout.pypoliqqueue:main:56 - New schedule received
2022-08-10 18:05:29.717 | INFO     | libretime_playout.pypoliqqueue:main:37 - waiting 3224.282673s until next scheduled item
2022-08-10 18:05:29.828 | INFO     | libretime_playout.pypofetch:cache_cleanup:444 - File '/var/lib/libretime/playout/scheduler/7.mp3' removed
2022-08-10 18:05:29.828 | INFO     | libretime_playout.pypofetch:main:499 - Loop #28
2022-08-10 18:05:44.568 | INFO     | libretime_playout.pypofile:copy_file:56 - copying from None to local cache /var/lib/libretime/playout/scheduler/127.mp3
2022-08-10 18:05:44.569 | INFO     | libretime_playout.pypofile:copy_file:59 - {'type': <EventKind.FILE: 'file'>, 'independent_event': False, 'row_id': 96033, 'start': datetime.datetime(2022, 8, 10, 21, 35, 49), 'end': datetime.datetime(2022, 8, 10, 22, 38, 59), 'uri': None, 'id': 127, 'show_name': 'Anabiosis', 'fade_in': 500.0, 'fade_out': 10000.0, 'cue_in': 3.69927, 'cue_out': 3793.72, 'metadata': {'track_title': 'isolatedmix 104 - Optic Echo', 'artist_name': 'Optic Echo', 'mime': 'audio/mp3'}, 'replay_gain': '-7.22', 'filesize': 153511765, 'file_ext': '.mp3', 'dst': '/var/lib/libretime/playout/scheduler/127.mp3', 'file_ready': False}
2022-08-10 18:05:51.486 | INFO     | libretime_playout.pypofile:copy_file:56 - copying from None to local cache /var/lib/libretime/playout/scheduler/130.mp3
2022-08-10 18:05:51.487 | INFO     | libretime_playout.pypofile:copy_file:59 - {'type': <EventKind.FILE: 'file'>, 'independent_event': False, 'row_id': 96034, 'start': datetime.datetime(2022, 8, 10, 22, 38, 59), 'end': datetime.datetime(2022, 8, 10, 23, 33, 16), 'uri': None, 'id': 130, 'show_name': 'Anabiosis', 'fade_in': 500.0, 'fade_out': 10000.0, 'cue_in': 1.30462, 'cue_out': 3257.81, 'metadata': {'track_title': 'isolatedmix 106 - Secede', 'artist_name': 'Secede', 'mime': 'audio/mp3'}, 'replay_gain': '-6.11', 'filesize': 126158536, 'file_ext': '.mp3', 'dst': '/var/lib/libretime/playout/scheduler/130.mp3', 'file_ready': False}
2022-08-10 18:05:56.874 | INFO     | libretime_playout.pypofile:copy_file:56 - copying from None to local cache /var/lib/libretime/playout/scheduler/129.mp3
2022-08-10 18:05:56.874 | INFO     | libretime_playout.pypofile:copy_file:59 - {'type': <EventKind.FILE: 'file'>, 'independent_event': False, 'row_id': 96035, 'start': datetime.datetime(2022, 8, 10, 23, 33, 16), 'end': datetime.datetime(2022, 8, 11, 0, 35, 50), 'uri': None, 'id': 129, 'show_name': 'Anabiosis', 'fade_in': 500.0, 'fade_out': 10000.0, 'cue_in': 7.81649, 'cue_out': 3762.26, 'metadata': {'track_title': 'isolatedmix 105 - SaffronKeira', 'artist_name': 'SaffronKeira', 'mime': 'audio/mp3'}, 'replay_gain': '-4.25', 'filesize': 152187778, 'file_ext': '.mp3', 'dst': '/var/lib/libretime/playout/scheduler/129.mp3', 'file_ready': False}
2022-08-10 18:06:03.700 | INFO     | libretime_playout.pypofile:copy_file:56 - copying from None to local cache /var/lib/libretime/playout/scheduler/125.mp3
2022-08-10 18:06:03.701 | INFO     | libretime_playout.pypofile:copy_file:59 - {'type': <EventKind.FILE: 'file'>, 'independent_event': False, 'row_id': 96036, 'start': datetime.datetime(2022, 8, 11, 0, 35, 50), 'end': datetime.datetime(2022, 8, 11, 4, 10), 'uri': None, 'id': 125, 'show_name': 'Anabiosis', 'fade_in': 500.0, 'fade_out': 10000.0, 'cue_in': 0.0, 'cue_out': 12849.5, 'metadata': {'track_title': 'isolatedmix 100 - Tom Middleton', 'artist_name': 'Tom Middleton', 'mime': 'audio/mp3'}, 'replay_gain': '-5.52', 'filesize': 515097619, 'file_ext': '.mp3', 'dst': '/var/lib/libretime/playout/scheduler/125.mp3', 'file_ready': False}
2022-08-10 18:06:29.037 | INFO     | libretime_playout.main:cli:132 - ###########################################
2022-08-10 18:06:29.037 | INFO     | libretime_playout.main:cli:133 - #             *** pypo  ***               #
2022-08-10 18:06:29.037 | INFO     | libretime_playout.main:cli:134 - #   Liquidsoap Scheduled Playout System   #
2022-08-10 18:06:29.038 | INFO     | libretime_playout.main:cli:135 - ###########################################
2022-08-10 18:06:29.038 | INFO     | libretime_playout.main:cli:140 - Timezone: ('UTC', 'UTC')
2022-08-10 18:06:29.038 | INFO     | libretime_playout.main:cli:141 - UTC time: 2022-08-10 18:06:29.038451
2022-08-10 18:06:31.560 | INFO     | libretime_playout.main:liquidsoap_startup_test:112 - Liquidsoap version string found 1.4.2
2022-08-10 18:06:31.561 | INFO     | libretime_playout.pypomessagehandler:init_rabbit_mq:38 - Initializing RabbitMQ stuff
2022-08-10 18:06:31.575 | INFO     | libretime_playout.pypofetch:__init__:65 - PypoFetch: init complete
2022-08-10 18:06:31.583 | INFO     | libretime_playout.pypoliqqueue:main:34 - waiting indefinitely for schedule
2022-08-10 18:06:31.589 | INFO     | libretime_playout.recorder:__init__:188 - RecorderFetch: init complete
2022-08-10 18:06:31.610 | INFO     | libretime_playout.recorder:run:333 - Started...
2022-08-10 18:06:31.666 | INFO     | libretime_playout.recorder:process_recorder_schedule:220 - Parsing recording show schedules...
2022-08-10 18:06:31.667 | INFO     | libretime_playout.recorder:run:340 - Bootstrap recorder schedule received: %s
2022-08-10 18:06:31.667 | INFO     | libretime_playout.recorder:run:345 - Bootstrap complete: got initial copy of the schedule
2022-08-10 18:06:31.758 | INFO     | libretime_playout.telnetliquidsoap:telnet_send:270 - streams.live_dj_stop

2022-08-10 18:06:31.759 | INFO     | libretime_playout.telnetliquidsoap:telnet_send:270 - streams.master_dj_stop

2022-08-10 18:06:31.759 | INFO     | libretime_playout.telnetliquidsoap:telnet_send:270 - streams.scheduled_play_start

2022-08-10 18:06:31.759 | INFO     | libretime_playout.telnetliquidsoap:telnet_send:270 - b'vars.stream_metadata_type 0\n'
2022-08-10 18:06:31.760 | INFO     | libretime_playout.telnetliquidsoap:telnet_send:270 - b'vars.station_name Ripple in Space\n'
2022-08-10 18:06:31.760 | INFO     | libretime_playout.telnetliquidsoap:telnet_send:270 - b'vars.default_dj_fade 0.000\n'
2022-08-10 18:06:32.931 | ERROR    | libretime_playout.pypofetch:sanity_check_media_item:397 - end - start length: %s
2022-08-10 18:06:32.931 | ERROR    | libretime_playout.pypofetch:sanity_check_media_item:398 - cue_out - cue_in length: %s
2022-08-10 18:06:32.932 | ERROR    | libretime_playout.pypofetch:sanity_check_media_item:399 - Two lengths are not equal!!!
2022-08-10 18:06:32.933 | INFO     | libretime_playout.pypoliquidsoap:verify_correct_present_media:178 - Need to add items to Liquidsoap *now*: {96030}
2022-08-10 18:06:32.934 | INFO     | libretime_playout.pypofile:copy_file:56 - copying from None to local cache /var/lib/libretime/playout/scheduler/125.mp3
2022-08-10 18:06:32.934 | INFO     | libretime_playout.pypofile:copy_file:59 - {'type': <EventKind.FILE: 'file'>, 'independent_event': False, 'row_id': 96036, 'start': datetime.datetime(2022, 8, 11, 0, 35, 50), 'end': datetime.datetime(2022, 8, 11, 4, 10), 'uri': None, 'id': 125, 'show_name': 'Anabiosis', 'fade_in': 500.0, 'fade_out': 10000.0, 'cue_in': 0.0, 'cue_out': 12849.5, 'metadata': {'track_title': 'isolatedmix 100 - Tom Middleton', 'artist_name': 'Tom Middleton', 'mime': 'audio/mp3'}, 'replay_gain': '-5.52', 'filesize': 515097619, 'file_ext': '.mp3', 'dst': '/var/lib/libretime/playout/scheduler/125.mp3', 'file_ready': False}
2022-08-10 18:06:32.937 | INFO     | libretime_playout.pypofetch:main:495 - Bootstrap schedule received: %s
2022-08-10 18:06:32.937 | INFO     | libretime_playout.pypofetch:main:499 - Loop #1
2022-08-10 18:06:33.160 | INFO     | libretime_playout.pypopush:main:69 - heartbeat
2022-08-10 18:06:33.161 | INFO     | libretime_playout.pypoliqqueue:main:56 - New schedule received
2022-08-10 18:06:33.161 | INFO     | libretime_playout.pypoliqqueue:main:37 - waiting 3160.838088s until next scheduled item
2022-08-10 18:06:59.353 | INFO     | libretime_playout.main:cli:132 - ###########################################
2022-08-10 18:06:59.353 | INFO     | libretime_playout.main:cli:133 - #             *** pypo  ***               #
2022-08-10 18:06:59.354 | INFO     | libretime_playout.main:cli:134 - #   Liquidsoap Scheduled Playout System   #
2022-08-10 18:06:59.354 | INFO     | libretime_playout.main:cli:135 - ###########################################
2022-08-10 18:06:59.354 | INFO     | libretime_playout.main:cli:140 - Timezone: ('UTC', 'UTC')
2022-08-10 18:06:59.354 | INFO     | libretime_playout.main:cli:141 - UTC time: 2022-08-10 18:06:59.354666
2022-08-10 18:07:01.371 | INFO     | libretime_playout.main:liquidsoap_startup_test:112 - Liquidsoap version string found 1.4.2
2022-08-10 18:07:01.372 | INFO     | libretime_playout.pypomessagehandler:init_rabbit_mq:38 - Initializing RabbitMQ stuff
2022-08-10 18:07:01.393 | INFO     | libretime_playout.pypofetch:__init__:65 - PypoFetch: init complete
2022-08-10 18:07:01.400 | INFO     | libretime_playout.pypoliqqueue:main:34 - waiting indefinitely for schedule
2022-08-10 18:07:01.406 | INFO     | libretime_playout.recorder:__init__:188 - RecorderFetch: init complete
2022-08-10 18:07:01.436 | INFO     | libretime_playout.recorder:run:333 - Started...
2022-08-10 18:07:01.476 | INFO     | libretime_playout.recorder:process_recorder_schedule:220 - Parsing recording show schedules...
2022-08-10 18:07:01.477 | INFO     | libretime_playout.recorder:run:340 - Bootstrap recorder schedule received: %s
2022-08-10 18:07:01.477 | INFO     | libretime_playout.recorder:run:345 - Bootstrap complete: got initial copy of the schedule
2022-08-10 18:07:01.540 | INFO     | libretime_playout.telnetliquidsoap:telnet_send:270 - streams.live_dj_stop

2022-08-10 18:07:01.542 | INFO     | libretime_playout.telnetliquidsoap:telnet_send:270 - streams.master_dj_stop

2022-08-10 18:07:01.543 | INFO     | libretime_playout.telnetliquidsoap:telnet_send:270 - streams.scheduled_play_start

2022-08-10 18:07:01.545 | INFO     | libretime_playout.telnetliquidsoap:telnet_send:270 - b'vars.stream_metadata_type 0\n'
2022-08-10 18:07:01.545 | INFO     | libretime_playout.telnetliquidsoap:telnet_send:270 - b'vars.station_name Ripple in Space\n'
2022-08-10 18:07:01.546 | INFO     | libretime_playout.telnetliquidsoap:telnet_send:270 - b'vars.default_dj_fade 0.000\n'
2022-08-10 18:07:02.721 | ERROR    | libretime_playout.pypofetch:sanity_check_media_item:397 - end - start length: %s
2022-08-10 18:07:02.722 | ERROR    | libretime_playout.pypofetch:sanity_check_media_item:398 - cue_out - cue_in length: %s
2022-08-10 18:07:02.722 | ERROR    | libretime_playout.pypofetch:sanity_check_media_item:399 - Two lengths are not equal!!!
2022-08-10 18:07:02.723 | INFO     | libretime_playout.pypoliquidsoap:verify_correct_present_media:178 - Need to add items to Liquidsoap *now*: {96030}
2022-08-10 18:07:02.725 | INFO     | libretime_playout.pypofetch:main:495 - Bootstrap schedule received: %s
2022-08-10 18:07:02.725 | INFO     | libretime_playout.pypofetch:main:499 - Loop #1
2022-08-10 18:07:02.725 | INFO     | libretime_playout.pypofile:copy_file:56 - copying from None to local cache /var/lib/libretime/playout/scheduler/125.mp3
2022-08-10 18:07:02.726 | INFO     | libretime_playout.pypofile:copy_file:59 - {'type': <EventKind.FILE: 'file'>, 'independent_event': False, 'row_id': 96036, 'start': datetime.datetime(2022, 8, 11, 0, 35, 50), 'end': datetime.datetime(2022, 8, 11, 4, 10), 'uri': None, 'id': 125, 'show_name': 'Anabiosis', 'fade_in': 500.0, 'fade_out': 10000.0, 'cue_in': 0.0, 'cue_out': 12849.5, 'metadata': {'track_title': 'isolatedmix 100 - Tom Middleton', 'artist_name': 'Tom Middleton', 'mime': 'audio/mp3'}, 'replay_gain': '-5.52', 'filesize': 515097619, 'file_ext': '.mp3', 'dst': '/var/lib/libretime/playout/scheduler/125.mp3', 'file_ready': False}
2022-08-10 18:07:03.044 | INFO     | libretime_playout.pypopush:main:69 - heartbeat
2022-08-10 18:07:03.045 | INFO     | libretime_playout.pypoliqqueue:main:56 - New schedule received
2022-08-10 18:07:03.045 | INFO     | libretime_playout.pypoliqqueue:main:37 - waiting 3130.954061s until next scheduled item
2022-08-10 18:07:25.611 | INFO     | libretime_playout.main:cli:132 - ###########################################
2022-08-10 18:07:25.612 | INFO     | libretime_playout.main:cli:133 - #             *** pypo  ***               #
2022-08-10 18:07:25.612 | INFO     | libretime_playout.main:cli:134 - #   Liquidsoap Scheduled Playout System   #
2022-08-10 18:07:25.612 | INFO     | libretime_playout.main:cli:135 - ###########################################
2022-08-10 18:07:25.612 | INFO     | libretime_playout.main:cli:140 - Timezone: ('UTC', 'UTC')
2022-08-10 18:07:25.612 | INFO     | libretime_playout.main:cli:141 - UTC time: 2022-08-10 18:07:25.612956
2022-08-10 18:07:27.409 | INFO     | libretime_playout.main:liquidsoap_startup_test:112 - Liquidsoap version string found 1.4.2
2022-08-10 18:07:27.410 | INFO     | libretime_playout.pypomessagehandler:init_rabbit_mq:38 - Initializing RabbitMQ stuff
2022-08-10 18:07:27.428 | INFO     | libretime_playout.pypofetch:__init__:65 - PypoFetch: init complete
2022-08-10 18:07:27.435 | INFO     | libretime_playout.pypoliqqueue:main:34 - waiting indefinitely for schedule
2022-08-10 18:07:27.440 | INFO     | libretime_playout.recorder:__init__:188 - RecorderFetch: init complete
2022-08-10 18:07:27.463 | INFO     | libretime_playout.recorder:run:333 - Started...
2022-08-10 18:07:27.532 | INFO     | libretime_playout.recorder:process_recorder_schedule:220 - Parsing recording show schedules...
2022-08-10 18:07:27.533 | INFO     | libretime_playout.recorder:run:340 - Bootstrap recorder schedule received: %s
2022-08-10 18:07:27.533 | INFO     | libretime_playout.recorder:run:345 - Bootstrap complete: got initial copy of the schedule
2022-08-10 18:07:27.560 | INFO     | libretime_playout.telnetliquidsoap:telnet_send:270 - streams.live_dj_stop

2022-08-10 18:07:27.560 | INFO     | libretime_playout.telnetliquidsoap:telnet_send:270 - streams.master_dj_stop

2022-08-10 18:07:27.561 | INFO     | libretime_playout.telnetliquidsoap:telnet_send:270 - streams.scheduled_play_start

2022-08-10 18:07:27.561 | INFO     | libretime_playout.telnetliquidsoap:telnet_send:270 - b'vars.stream_metadata_type 0\n'
2022-08-10 18:07:27.562 | INFO     | libretime_playout.telnetliquidsoap:telnet_send:270 - b'vars.station_name Ripple in Space\n'
2022-08-10 18:07:27.562 | INFO     | libretime_playout.telnetliquidsoap:telnet_send:270 - b'vars.default_dj_fade 0.000\n'
2022-08-10 18:07:28.587 | ERROR    | libretime_playout.pypofetch:sanity_check_media_item:397 - end - start length: %s
2022-08-10 18:07:28.587 | ERROR    | libretime_playout.pypofetch:sanity_check_media_item:398 - cue_out - cue_in length: %s
2022-08-10 18:07:28.588 | ERROR    | libretime_playout.pypofetch:sanity_check_media_item:399 - Two lengths are not equal!!!
2022-08-10 18:07:28.589 | INFO     | libretime_playout.pypoliquidsoap:verify_correct_present_media:178 - Need to add items to Liquidsoap *now*: {96030}
2022-08-10 18:07:28.590 | INFO     | libretime_playout.pypofetch:main:495 - Bootstrap schedule received: %s
2022-08-10 18:07:28.590 | INFO     | libretime_playout.pypofetch:main:499 - Loop #1
2022-08-10 18:07:28.590 | INFO     | libretime_playout.pypofile:copy_file:56 - copying from None to local cache /var/lib/libretime/playout/scheduler/125.mp3
2022-08-10 18:07:28.591 | INFO     | libretime_playout.pypofile:copy_file:59 - {'type': <EventKind.FILE: 'file'>, 'independent_event': False, 'row_id': 96036, 'start': datetime.datetime(2022, 8, 11, 0, 35, 50), 'end': datetime.datetime(2022, 8, 11, 4, 10), 'uri': None, 'id': 125, 'show_name': 'Anabiosis', 'fade_in': 500.0, 'fade_out': 10000.0, 'cue_in': 0.0, 'cue_out': 12849.5, 'metadata': {'track_title': 'isolatedmix 100 - Tom Middleton', 'artist_name': 'Tom Middleton', 'mime': 'audio/mp3'}, 'replay_gain': '-5.52', 'filesize': 515097619, 'file_ext': '.mp3', 'dst': '/var/lib/libretime/playout/scheduler/125.mp3', 'file_ready': False}
2022-08-10 18:07:28.840 | INFO     | libretime_playout.pypopush:main:69 - heartbeat
2022-08-10 18:07:28.840 | INFO     | libretime_playout.pypoliqqueue:main:56 - New schedule received
2022-08-10 18:07:28.841 | INFO     | libretime_playout.pypoliqqueue:main:37 - waiting 3105.158957s until next scheduled item

liquidsoap

2022/08/10 17:58:48 [server:3] Client 127.0.0.1 disconnected.
2022/08/10 17:59:23 [server:3] New client: 127.0.0.1.
2022/08/10 17:59:23 [lang:3] vars.show_name
2022/08/10 17:59:23 [server:3] Client 127.0.0.1 disconnected.
2022/08/10 17:59:24 [cue_cut_9659:3] Cueing out...
2022/08/10 17:59:24 [cross_9665:3] Analysis: -18.722513dB / -nandB (0.00s / 0.00s)
2022/08/10 17:59:24 [crossfade:3] No transition: using default.
2022/08/10 17:59:24 [schedule_noise_switch:3] Switch to map_metadata_9743 with forgetful transition.
2022/08/10 17:59:24 [lang:3] transition called...
2022/08/10 17:59:24 [decoder:3] Method "FFMPEG" accepted "/var/lib/libretime/playout/scheduler/48.mp3".
2022/08/10 17:59:24 [dummy(dot)2:3] Source failed (no more tracks) stopping output...
2022/08/10 17:59:24 [dummy(dot)4:3] Source failed (no more tracks) stopping output...
2022/08/10 17:59:25 [s4:3] Prepared "/var/lib/libretime/playout/scheduler/48.mp3" (RID 0).
2022/08/10 17:59:25 [schedule_noise_switch:3] Switch to map_metadata_9732 with transition.
2022/08/10 17:59:25 [lang:3] transition called...
2022/08/10 17:59:25 [switch_9730:3] Switch to insert_metadata_9715.
2022/08/10 17:59:25 [lang:3] timeout --signal=KILL 45 libretime-playout-notify media '96028' &
2022/08/10 17:59:25 [lang:3] Using stream_format 0
2022/08/10 17:59:25 [lang:3] Using stream_format 0
2022/08/10 17:59:25 [lang:3] Using stream_format 0
2022-08-10 17:59:27.210 | INFO     | libretime_playout.notify.main:media:47 - Sending currently playing media id '96028'
2022/08/10 18:00:00 [server:3] New client: 127.0.0.1.
2022/08/10 18:00:00 [lang:3] vars.show_name
2022/08/10 18:00:00 [server:3] Client 127.0.0.1 disconnected.
2022/08/10 18:00:01 [cue_cut_9659:3] Cueing out...
2022/08/10 18:00:01 [cross_9665:3] Analysis: -15.036624dB / -nandB (0.00s / 0.00s)
2022/08/10 18:00:01 [crossfade:3] No transition: using default.
2022/08/10 18:00:01 [schedule_noise_switch:3] Switch to map_metadata_9743 with forgetful transition.
2022/08/10 18:00:01 [lang:3] transition called...
2022/08/10 18:00:01 [decoder:3] Method "FFMPEG" accepted "/var/lib/libretime/playout/scheduler/15.mp3".
2022/08/10 18:00:01 [dummy(dot)2:3] Source failed (no more tracks) stopping output...
2022/08/10 18:00:01 [dummy(dot)4:3] Source failed (no more tracks) stopping output...
2022/08/10 18:00:01 [s4:3] Prepared "/var/lib/libretime/playout/scheduler/15.mp3" (RID 2).
2022/08/10 18:00:01 [switch_9730:3] Switch to insert_metadata_9715.
2022/08/10 18:00:01 [lang:3] timeout --signal=KILL 45 libretime-playout-notify media '96030' &
2022/08/10 18:00:01 [lang:3] Using stream_format 0
2022/08/10 18:00:01 [lang:3] Using stream_format 0
2022/08/10 18:00:01 [schedule_noise_switch:3] Switch to map_metadata_9732 with transition.
2022/08/10 18:00:01 [lang:3] transition called...
2022/08/10 18:00:01 [lang:3] Using stream_format 0
2022-08-10 18:00:02.092 | INFO     | libretime_playout.notify.main:media:47 - Sending currently playing media id '96030'
2022/08/10 18:05:29 [server:3] New client: 127.0.0.1.
2022/08/10 18:05:29 [lang:3] dynamic_source.get_id
2022/08/10 18:05:29 [server:3] Client 127.0.0.1 disconnected.
2022/08/10 18:06:21 [clock.wallclock_main:2] We must catchup 1.02 seconds!
2022/08/10 18:06:31 [server:3] New client: 127.0.0.1.
2022/08/10 18:06:31 [server:3] Client 127.0.0.1 disconnected.
2022/08/10 18:06:31 [server:3] New client: 127.0.0.1.
2022/08/10 18:06:31 [lang:3] queues.s8_skip
2022/08/10 18:06:31 [lang:3] queues.s8_skip
2022/08/10 18:06:31 [lang:3] queues.s8_skip
2022/08/10 18:06:31 [lang:3] queues.s8_skip
2022/08/10 18:06:31 [lang:3] queues.s8_skip
2022/08/10 18:06:31 [cue_cut_9659:3] End of track before cue-out point.
2022/08/10 18:06:31 [cross_9665:3] Analysis: -18.229567dB / -nandB (0.00s / 0.00s)
2022/08/10 18:06:31 [crossfade:3] No transition: using default.
2022/08/10 18:06:31 [schedule_noise_switch:3] Switch to map_metadata_9743 with forgetful transition.
2022/08/10 18:06:31 [lang:3] transition called...
2022/08/10 18:06:31 [server:3] Client 127.0.0.1 disconnected.
2022/08/10 18:06:31 [server:3] New client: 127.0.0.1.
2022/08/10 18:06:31 [lang:3] streams.live_dj_stop
2022/08/10 18:06:31 [lang:3] streams.master_dj_stop
2022/08/10 18:06:31 [lang:3] streams.scheduled_play_start
2022/08/10 18:06:31 [lang:3] vars.stream_metadata_type
2022/08/10 18:06:31 [lang:3] vars.station_name
2022/08/10 18:06:31 [lang:3] vars.default_dj_fade
2022/08/10 18:06:31 [server:3] Client 127.0.0.1 disconnected.
2022/08/10 18:06:31 [server:3] New client: 127.0.0.1.
2022/08/10 18:06:31 [lang:3] queues.s8_skip
2022/08/10 18:06:31 [lang:3] queues.s8_skip
2022/08/10 18:06:31 [lang:3] queues.s8_skip
2022/08/10 18:06:31 [lang:3] queues.s8_skip
2022/08/10 18:06:31 [lang:3] queues.s8_skip
2022/08/10 18:06:31 [server:3] Client 127.0.0.1 disconnected.
2022/08/10 18:06:31 [dummy(dot)4:3] Source failed (no more tracks) stopping output...
2022/08/10 18:06:31 [dummy(dot)2:3] Source failed (no more tracks) stopping output...
2022/08/10 18:06:33 [server:3] New client: 127.0.0.1.
2022/08/10 18:06:33 [lang:3] vars.show_name
2022/08/10 18:06:33 [server:3] Client 127.0.0.1 disconnected.
2022/08/10 18:06:33 [server:3] New client: 127.0.0.1.
2022/08/10 18:06:33 [lang:3] dynamic_source.get_id
2022/08/10 18:06:33 [server:3] Client 127.0.0.1 disconnected.
2022/08/10 18:06:33 [decoder:3] Method "FFMPEG" accepted "/var/lib/libretime/playout/scheduler/15.mp3".
2022/08/10 18:06:33 [s4:3] Prepared "/var/lib/libretime/playout/scheduler/15.mp3" (RID 3).
2022/08/10 18:06:33 [schedule_noise_switch:3] Switch to map_metadata_9732 with transition.
2022/08/10 18:06:33 [lang:3] transition called...
2022/08/10 18:06:33 [cue_cut_9659:3] Cueing in...
2022/08/10 18:06:34 [lang:3] timeout --signal=KILL 45 libretime-playout-notify media '96030' &
2022/08/10 18:06:34 [switch_9730:3] Switch to insert_metadata_9715.
2022/08/10 18:06:34 [lang:3] Using stream_format 0
2022/08/10 18:06:34 [lang:3] Using stream_format 0
2022/08/10 18:06:34 [lang:3] Using stream_format 0
2022/08/10 18:06:34 [switch_10601:3] Switch to fade(dot)final.
2022-08-10 18:06:34.505 | INFO     | libretime_playout.notify.main:media:47 - Sending currently playing media id '96030'
2022/08/10 18:07:01 [server:3] New client: 127.0.0.1.
2022/08/10 18:07:01 [server:3] Client 127.0.0.1 disconnected.
2022/08/10 18:07:01 [server:3] New client: 127.0.0.1.
2022/08/10 18:07:01 [lang:3] queues.s8_skip
2022/08/10 18:07:01 [lang:3] queues.s8_skip
2022/08/10 18:07:01 [lang:3] queues.s8_skip
2022/08/10 18:07:01 [lang:3] queues.s8_skip
2022/08/10 18:07:01 [lang:3] queues.s8_skip
2022/08/10 18:07:01 [server:3] Client 127.0.0.1 disconnected.
2022/08/10 18:07:01 [cue_cut_9659:3] End of track before cue-out point.
2022/08/10 18:07:01 [cross_9665:3] Analysis: -18.384544dB / -nandB (0.00s / 0.00s)
2022/08/10 18:07:01 [crossfade:3] No transition: using default.
2022/08/10 18:07:01 [schedule_noise_switch:3] Switch to map_metadata_9743 with forgetful transition.
2022/08/10 18:07:01 [lang:3] transition called...
2022/08/10 18:07:01 [server:3] New client: 127.0.0.1.
2022/08/10 18:07:01 [lang:3] streams.live_dj_stop
2022/08/10 18:07:01 [lang:3] streams.master_dj_stop
2022/08/10 18:07:01 [lang:3] streams.scheduled_play_start
2022/08/10 18:07:01 [lang:3] vars.stream_metadata_type
2022/08/10 18:07:01 [lang:3] vars.station_name
2022/08/10 18:07:01 [lang:3] vars.default_dj_fade
2022/08/10 18:07:01 [server:3] Client 127.0.0.1 disconnected.
2022/08/10 18:07:01 [server:3] New client: 127.0.0.1.
2022/08/10 18:07:01 [lang:3] queues.s8_skip
2022/08/10 18:07:01 [lang:3] queues.s8_skip
2022/08/10 18:07:01 [lang:3] queues.s8_skip
2022/08/10 18:07:01 [lang:3] queues.s8_skip
2022/08/10 18:07:01 [lang:3] queues.s8_skip
2022/08/10 18:07:01 [server:3] Client 127.0.0.1 disconnected.
2022/08/10 18:07:01 [dummy(dot)4:3] Source failed (no more tracks) stopping output...
2022/08/10 18:07:01 [dummy(dot)2:3] Source failed (no more tracks) stopping output...
2022/08/10 18:07:02 [server:3] New client: 127.0.0.1.
2022/08/10 18:07:03 [decoder:3] Method "FFMPEG" accepted "/var/lib/libretime/playout/scheduler/15.mp3".
2022/08/10 18:07:03 [lang:3] vars.show_name
2022/08/10 18:07:03 [server:3] Client 127.0.0.1 disconnected.
2022/08/10 18:07:03 [server:3] New client: 127.0.0.1.
2022/08/10 18:07:03 [lang:3] dynamic_source.get_id
2022/08/10 18:07:03 [server:3] Client 127.0.0.1 disconnected.
2022/08/10 18:07:03 [s4:3] Prepared "/var/lib/libretime/playout/scheduler/15.mp3" (RID 4).
2022/08/10 18:07:03 [schedule_noise_switch:3] Switch to map_metadata_9732 with transition.
2022/08/10 18:07:03 [lang:3] transition called...
2022/08/10 18:07:03 [cue_cut_9659:3] Cueing in...
2022/08/10 18:07:03 [lang:3] timeout --signal=KILL 45 libretime-playout-notify media '96030' &
2022/08/10 18:07:03 [switch_9730:3] Switch to insert_metadata_9715.
2022/08/10 18:07:03 [lang:3] Using stream_format 0
2022/08/10 18:07:03 [lang:3] Using stream_format 0
2022/08/10 18:07:03 [lang:3] Using stream_format 0
2022/08/10 18:07:03 [switch_10745:3] Switch to fade(dot)final.
2022-08-10 18:07:04.310 | INFO     | libretime_playout.notify.main:media:47 - Sending currently playing media id '96030'
2022/08/10 18:07:27 [server:3] New client: 127.0.0.1.
2022/08/10 18:07:27 [server:3] Client 127.0.0.1 disconnected.
2022/08/10 18:07:27 [server:3] New client: 127.0.0.1.
2022/08/10 18:07:27 [lang:3] queues.s8_skip
2022/08/10 18:07:27 [lang:3] queues.s8_skip
2022/08/10 18:07:27 [lang:3] queues.s8_skip
2022/08/10 18:07:27 [lang:3] queues.s8_skip
2022/08/10 18:07:27 [lang:3] queues.s8_skip
2022/08/10 18:07:27 [server:3] Client 127.0.0.1 disconnected.
2022/08/10 18:07:27 [cue_cut_9659:3] End of track before cue-out point.
2022/08/10 18:07:27 [cross_9665:3] Analysis: -17.704416dB / -nandB (0.00s / 0.00s)
2022/08/10 18:07:27 [crossfade:3] No transition: using default.
2022/08/10 18:07:27 [schedule_noise_switch:3] Switch to map_metadata_9743 with forgetful transition.
2022/08/10 18:07:27 [lang:3] transition called...
2022/08/10 18:07:27 [server:3] New client: 127.0.0.1.
2022/08/10 18:07:27 [lang:3] streams.live_dj_stop
2022/08/10 18:07:27 [lang:3] streams.master_dj_stop
2022/08/10 18:07:27 [lang:3] streams.scheduled_play_start
2022/08/10 18:07:27 [lang:3] vars.stream_metadata_type
2022/08/10 18:07:27 [lang:3] vars.station_name
2022/08/10 18:07:27 [lang:3] vars.default_dj_fade
2022/08/10 18:07:27 [server:3] Client 127.0.0.1 disconnected.
2022/08/10 18:07:27 [server:3] New client: 127.0.0.1.
2022/08/10 18:07:27 [lang:3] queues.s8_skip
2022/08/10 18:07:27 [lang:3] queues.s8_skip
2022/08/10 18:07:27 [lang:3] queues.s8_skip
2022/08/10 18:07:27 [lang:3] queues.s8_skip
2022/08/10 18:07:27 [lang:3] queues.s8_skip
2022/08/10 18:07:27 [server:3] Client 127.0.0.1 disconnected.
2022/08/10 18:07:27 [dummy(dot)2:3] Source failed (no more tracks) stopping output...
2022/08/10 18:07:27 [dummy(dot)4:3] Source failed (no more tracks) stopping output...
2022/08/10 18:07:28 [server:3] New client: 127.0.0.1.
2022/08/10 18:07:28 [decoder:3] Method "FFMPEG" accepted "/var/lib/libretime/playout/scheduler/15.mp3".
2022/08/10 18:07:28 [lang:3] vars.show_name
2022/08/10 18:07:28 [server:3] Client 127.0.0.1 disconnected.
2022/08/10 18:07:28 [server:3] New client: 127.0.0.1.
2022/08/10 18:07:28 [lang:3] dynamic_source.get_id
2022/08/10 18:07:28 [server:3] Client 127.0.0.1 disconnected.
2022/08/10 18:07:29 [s4:3] Prepared "/var/lib/libretime/playout/scheduler/15.mp3" (RID 5).
2022/08/10 18:07:29 [schedule_noise_switch:3] Switch to map_metadata_9732 with transition.
2022/08/10 18:07:29 [lang:3] transition called...
2022/08/10 18:07:29 [cue_cut_9659:3] Cueing in...
2022/08/10 18:07:29 [lang:3] timeout --signal=KILL 45 libretime-playout-notify media '96030' &
2022/08/10 18:07:29 [switch_9730:3] Switch to insert_metadata_9715.
2022/08/10 18:07:29 [lang:3] Using stream_format 0
2022/08/10 18:07:29 [lang:3] Using stream_format 0
2022/08/10 18:07:29 [lang:3] Using stream_format 0
2022/08/10 18:07:29 [switch_10889:3] Switch to fade(dot)final.
2022-08-10 18:07:30.117 | INFO     | libretime_playout.notify.main:media:47 - Sending currently playing media id '96030'