Azuracast: Playlist Not Playing at Scheduled Time Super-Issue

[SlvrEagle23]

We've received a number of reports that playlists aren't properly playing at their scheduled times/dates. Our local tests aren't showing the same results, so I've created a single "super-issue" to track these reports, while also ensuring that everyone is using the same settings and avoiding some of the more common pitfalls that may cause these problems.

Before reporting an issue in this thread, ensure the following steps are taken:

Station Time Zone is Correct

A playlist's start date, end date, play days (Sunday thru Saturday) and play times are _all_ relative to the station's time zone. This is why we show the station's time zone on the schedule panel.

We use Linux-style "tz" timezones, which have one time zone for every geographic combination of time zone and daylight saving rule, so it isn't necessary to indicate whether Daylight Saving Time is enabled or not for a given time zone. Make sure to always select the time zone that precisely matches your intended geographic region and DST rules.

No Advanced AutoDJ Configuration Used

If your playlist has any of the "Advanced" AutoDJ configuration options (i.e. "Interrupt other songs", "Play as single track") enabled, then it will be managed by Liquidsoap's AutoDJ, not AzuraCast's AutoDJ. This should still generally adhere to the proper scheduling rules, but you will need to restart your station any time you make configuration changes, and scheduling problems in this mode are much harder for us to diagnose and fix.

Make sure all of these settings (now located in the "Advanced" tab, as of the latest AzuraCast builds) are disabled.

Testing Scheduled Playlists

For system administrators, we have recently created a new "System Debugger" page that you can access from the System Administration panel. From this page, you can manually run the AzuraCast AutoDJ's "next song" functionality with any given date/time, which will allow you to test if it's properly detecting a scheduled playlist and attempting to play from it. This page will also give you the full debug output of our AutoDJ scheduling routine, which provides quite a lot of information about how we determine which song to play next.

Before posting an issue, please make sure that the given playlist isn't being scheduled using this testing mechanism.

Given the importance of this functionality to AzuraCast, we have a number of unit tests in place that help test the basic timing functions we use, and yet we have still been largely unable to reproduce a number of the errors being reported by our users. If anyone who is experiencing these problems is able to identify the cause of the problem within our code base, we would welcome a pull request with the necessary fixes.

[yarik2720]

Running Test AutoDJ Next Song shows error

500
Call to a member function played() on null
AutoDJ.php : 354 

if i type in field Test time something, for example 1 it shows error

500
DateTimeImmutable::__construct(): Failed to parse time string (1) at position 0 (1): Unexpected character
Chronos.php : 96 

[yarik2720]

My playlist were scheduled to 20:00.
At 19:47 on System Debugger it showed that track from this playlist will be next. And it started to play on 19:48.

[SlvrEagle23]

@yarik2720 Are they scheduled to play exactly on 20:00 with the same start and end times?

[yarik2720]

@SlvrEagle23 yes

[SlvrEagle23]

Two updates:

• If you have a playlist with a start and end time that are the same time, improvements have been made to the code to prevent these from playing _before_ their scheduled play-once-a-day time.

• We've discovered the source of some playlists not playing regardless of their scheduled time: if the title or artist has the pipe "|" character, then Liquidsoap will silently ignore it. This predominantly affects playlists that contain, say, podcast episodes, as they often have titles or artists with "Foo | Bar" content. We're working around this issue currently and have a pending issue with the parent repository: savonet/liquidsoap#1151

[loics2]

I also have an issue with scheduled playlist which is included in this super-issue I think.

Here's my playlist setup :

• I have a "general" playlist, which plays when nothing's scheduled. It's a simple General rotation playlist, of weight 3
• a special playlist scheduled to play Fridays at 16h00. It has Interrupt other songs to play at scheduled time and Merge playlist to play as a single track enabled. It does not contain any | in the titles/artist names.

When I run the debugging tool, it says No valid playlists detected. Skipping AutoDJ calculations..

If I disable my "general" playlist during the special playlist's scheduled hours, nothing's happening and my radio goes offline, my special playlist is not seen. I have to disable the advanced configuration playlist and disable all my other playlist to get what I want.

OS : Ubuntu 18.04 LTS
AzuraCast : v0.9.9, #ef6393e (2020-03-22 22:40) • Docker • PHP 7.4

[SlvrEagle23]

@loics2 The "interrupt other songs" and "merge playlist" settings are both considered Advanced AutoDJ settings, which mean that Liquidsoap is in charge of playing the playlist at the proper time, not AzuraCast's AutoDJ, so our AutoDJ is correctly reporting that it has no playlists that it is in charge of playing, deferring instead to Liquidsoap for handling that playlist.

When making changes to playlists that use Advanced AutoDJ customizations, you must always restart broadcasting to rewrite the configuration and instruct Liquidsoap to use the new scheduling. We realize this is often inconvenient and confusing, which is why we continue to advise against using the Advanced AutoDJ functionality.

[sjradmin]

Hi
My playlist is simple and inline with your rules. It's scheduled based on station local time zone. Since I updated an hour ago to latest version it's not even playing on scheduled time. Previously it was playing on-time but looping at the end.

[sjradmin]

I recreated the playlist and restarted the broadcast and it plays according to schedule but still looping after the song is finished.

[sjradmin]

I think issue was that I had no other playlist for other time, I created one with no file and it solved the issue.

[sjradmin]

no still the same,

[SlvrEagle23]

@sjradmin and others experiencing this issue:

I suspect this may be a problem with how schedules are being stored in the database after being input, and the only way for me to actually tell that is to see how they're represented in your respective databases.

You can help me diagnose this issue by running this command on your host machines (for Docker installations, at least):

cd /var/azuracast
./docker.sh update-self
./docker.sh cli orm:run-dql "SELECT sch.start_time, sch.end_time, sch.start_date, sch.end_date, sch.days FROM App\Entity\StationSchedule sch"

...and then including that info alongside what you have your stations scheduled as according to your user interface.

[sjradmin]

I found this in liquidsoap log > There are currently 100 RIDs, possible request leak! Please check that you don't have a loop on empty/unavailable requests, or creating requests without destroying them. Decreasing request.grace_time can also help.

What does it mean? Do you think that its related to my problem?

[sjradmin]

and I also found this one: [clock.wallclock_main:3] Streaming loop starts, synchronized with wallclock.

[adwinter]

Hey Guys,

I might have at least a workaround for the repeating issue...

This was happening to me a lot with affiliate shows. I'd setup a playlist to play at a certain time, and it would play the show, then play it again when it ended.. I think what happens is, when it plays a track, it right away cues up the next song to play.. and because the playlist rules say that playlist should play, it cues up the next song in the playlist (or in my case it was cueing up the same track again)!

I simply added a Sweeper to the end of the playlist, so that when it plays the show, it will cue up the next song in the playlist which is my sweeper.. then by the time the sweeper plays, the time for the playlist has elapsed and it will go elsewhere for the song.

I've also found that if I have a show that runs from 8 to 9 for example... Its best to set the END TIME to well before 9... if the show plays, then the sweeper and its before 9, it may cue up the show again to play.

As an example, if I had a show that started at 8 on thursdays.... I would setup a sequential playlist with what I want to play, and add a sweeper at the end... then schedule it to start at 8, and end at say 8:45. So by the time it gets to my sweeper, it won't re-play the playlist.

Not sure this will fix your particular situation -- but it works brilliantly when my playlists were repeating. Good Luck.

[sjradmin]

Hey Guys,

I might have at least a workaround for the repeating issue...

This was happening to me a lot with affiliate shows. I'd setup a playlist to play at a certain time, and it would play the show, then play it again when it ended.. I think what happens is, when it plays a track, it right away cues up the next song to play.. and because the playlist rules say that playlist should play, it cues up the next song in the playlist (or in my case it was cueing up the same track again)!

I simply added a Sweeper to the end of the playlist, so that when it plays the show, it will cue up the next song in the playlist which is my sweeper.. then by the time the sweeper plays, the time for the playlist has elapsed and it will go elsewhere for the song.

I've also found that if I have a show that runs from 8 to 9 for example... Its best to set the END TIME to well before 9... if the show plays, then the sweeper and its before 9, it may cue up the show again to play.

As an example, if I had a show that started at 8 on thursdays.... I would setup a sequential playlist with what I want to play, and add a sweeper at the end... then schedule it to start at 8, and end at say 8:45. So by the time it gets to my sweeper, it won't re-play the playlist.

Not sure this will fix your particular situation -- but it works brilliantly when my playlists were repeating. Good Luck.

Thanks for your update, I will try that and let you know. What's the duration of your Sweeper file generally?

[sjradmin]

@sjradmin and others experiencing this issue:

I suspect this may be a problem with how schedules are being stored in the database after being input, and the only way for me to actually tell that is to see how they're represented in your respective databases.

You can help me diagnose this issue by running this command on your host machines (for Docker installations, at least):

cd /var/azuracast
./docker.sh update-self
./docker.sh cli orm:run-dql "SELECT sch.start_time, sch.end_time, sch.start_date, sch.end_date, sch.days FROM App\Entity\StationSchedule sch"

...and then including that info alongside what you have your stations scheduled as according to your user interface.

Here is the result of that command:

Starting azuracast_influxdb_1 ... done
Starting azuracast_influxdb_1 ...
Starting azuracast_stations ... done
Starting azuracast_mariadb_1 ...
Starting azuracast_mariadb_1 ... done
2020/04/20 08:53:52 Waiting for: tcp://mariadb:3306
2020/04/20 08:53:52 Waiting for: tcp://influxdb:8086
2020/04/20 08:53:52 Waiting for: tcp://redis:6379
2020/04/20 08:53:52 Connected to tcp://influxdb:8086
2020/04/20 08:53:52 Connected to tcp://redis:6379
2020/04/20 08:53:52 Connected to tcp://mariadb:3306

array(9) {
[0]=>
array(5) {
["start_time"]=>
int(200)
["end_time"]=>
int(200)
["start_date"]=>
string(0) ""
["end_date"]=>
NULL
["days"]=>
string(3) "1,5"
}
[1]=>
array(5) {
["start_time"]=>
int(1830)
["end_time"]=>
int(1830)
["start_date"]=>
NULL
["end_date"]=>
NULL
["days"]=>
string(3) "7,4"
}
[2]=>
array(5) {
["start_time"]=>
int(1830)
["end_time"]=>
int(1830)
["start_date"]=>
NULL
["end_date"]=>
NULL
["days"]=>
string(3) "7,4"
}
[3]=>
array(5) {
["start_time"]=>
int(1830)
["end_time"]=>
int(1830)
["start_date"]=>
NULL
["end_date"]=>
NULL
["days"]=>
string(3) "7,4"
}
[4]=>
array(5) {
["start_time"]=>
int(1830)
["end_time"]=>
int(1830)
["start_date"]=>
string(0) ""
["end_date"]=>
NULL
["days"]=>
string(3) "7,4"
}
[5]=>
array(5) {
["start_time"]=>
int(200)
["end_time"]=>
int(208)
["start_date"]=>
NULL
["end_date"]=>
NULL
["days"]=>
string(1) "7"
}
[6]=>
array(5) {
["start_time"]=>
int(138)
["end_time"]=>
int(140)
["start_date"]=>
NULL
["end_date"]=>
NULL
["days"]=>
string(1) "7"
}
[7]=>
array(5) {
["start_time"]=>
int(210)
["end_time"]=>
int(218)
["start_date"]=>
NULL
["end_date"]=>
NULL
["days"]=>
string(1) "7"
}
[8]=>
array(5) {
["start_time"]=>
int(220)
["end_time"]=>
int(228)
["start_date"]=>
NULL
["end_date"]=>
NULL
["days"]=>
string(1) "7"
}
}

2020/04/20 08:53:53 Command finished successfully.

[sjradmin]

Hey Guys,

I might have at least a workaround for the repeating issue...

This was happening to me a lot with affiliate shows. I'd setup a playlist to play at a certain time, and it would play the show, then play it again when it ended.. I think what happens is, when it plays a track, it right away cues up the next song to play.. and because the playlist rules say that playlist should play, it cues up the next song in the playlist (or in my case it was cueing up the same track again)!

I simply added a Sweeper to the end of the playlist, so that when it plays the show, it will cue up the next song in the playlist which is my sweeper.. then by the time the sweeper plays, the time for the playlist has elapsed and it will go elsewhere for the song.

I've also found that if I have a show that runs from 8 to 9 for example... Its best to set the END TIME to well before 9... if the show plays, then the sweeper and its before 9, it may cue up the show again to play.

As an example, if I had a show that started at 8 on thursdays.... I would setup a sequential playlist with what I want to play, and add a sweeper at the end... then schedule it to start at 8, and end at say 8:45. So by the time it gets to my sweeper, it won't re-play the playlist.

Not sure this will fix your particular situation -- but it works brilliantly when my playlists were repeating. Good Luck.

I tried that, it worked once when deleted and created a new play list,

but if I use that playlist by changing the day and time later it does not work again, It works only once!

This is really annoying issue for a simple task. Don't know why it should not be possible to schedule properly to pay a song only once :(

[SlvrEagle23]

@sjradmin As mentioned in the top of this thread, if you have any settings on a given playlist that are in the "Advanced" section (i.e. interrupt other songs, merge to play as one, etc) then Liquidsoap manages the playlist, which means any time you change it, you have to restart your station to apply the new changes.

A single playlist with a play-once (same start and end) time should be able to be updated without any issues as long as the AzuraCast AutoDJ is handling it.

[sjradmin]

@sjradmin As mentioned in the top of this thread, if you have any settings on a given playlist that are in the "Advanced" section (i.e. interrupt other songs, merge to play as one, etc) then Liquidsoap manages the playlist, which means any time you change it, you have to restart your station to apply the new changes.

A single playlist with a play-once (same start and end) time should be able to be updated without any issues as long as the AzuraCast AutoDJ is handling it.

I do not enable any option at advanced tab as you can see in my screen shot. Even restarting the station after each change in play list but still it behaves randomly. I test today it works and if another day just change the times it is looping.

[SlvrEagle23]

Update: I've tested, tweaked, re-tested, re-tweaked and worked many many hours on the AzuraCast scheduler, and on my local installation everything works absolutely fine without any issues. If anything, the recent improvements have fixed some of the smaller side issues with the schedule queue.

As I've mentioned in other threads, the entire AzuraCast AutoDJ (src/Radio/AutoDJ.php) has only ever been modified by _me_ for years now. Having one set of eyes on such a crucial component is never a good idea, but AzuraCast's so-called "complainers-to-maintainers" ratio is completely out of whack for an open-source project. We have very, very few pull requests coming in from developers to fix issues like this, so the onus has largely been on me to fix these things.

Needless to say, an endless stream of bug reports involving one feature, that I can't reproduce locally, and that I don't have enough information to be able to diagnose further...has been a huge source of stress for me.

In order to help facilitate fixing this issue, I've added a feature to the system debugger called "Build Queue" that will let you rebuild the entire upcoming songs queue with a huge amount of debug information to tell how it's making the decisions it makes during scheduling.

If you are having this issue, or if your issue has been merged into this one because it's about the scheduler, please do ALL of the following before replying:

• Make sure that, for your playlist, ALL of the "Advanced" settings (i.e. Interrupt other tracks, merge to play as one track) are turned OFF;
• Verify that your station's time zone is correct, down to the geographical region that includes your daylight saving time rules;
• Comment with how the playlist is scheduled, preferably including screenshots, and
• Include the output of the System Debugger > Build Queue command for the time when the scheduled playlist _should_ be playing.

Better yet, pull requests would be eagerly invited and accepted to improve the scheduler.

[rquara]

Hello, first of all thank you so much for the amazing code you wrote. I'm using azuracast since a couple of days but I already love it (and my listeners too!)

I'm trying to understand how to setup the scheduled playlist properly.

This is the scenario:
Today is the International Jazz Day and I built a unique schedule with music, interviews, ...
I wanted to have a unique playlist scheduled from 8am today ending 3am tomorrow morning with all the mp3 files in the right sequence.
I'm running AzuraCast • v0.10.1, #bc34f02 (2020-04-28 0:43) • Docker • PHP 7.4

1. I created a folder in "music files" called "International Jazz Day 2020".
2. In the folder I created subfolders according to the segment (0800 for the segment that I need to air at 8am, 1000 for the segment I need to air at 10am, ...).
3. In those folders I uploaded the files named in a sequential order (ie: 0800/01 - track title, 0800/02 - track title, .... , 1000/01 - track title, 1000/02 - track title).
4. I browsed to /station/1/files, selected the "International Jazz Day 2020" folder, clicked playlists, created a New Playlist called "International Jazz Day 2020" and saved.
5. Than I opened /station/1/playlists, clicked on the number of songs close to the playlist ("217 (20.2 hours)") and the tracks order was the right one.
6. I also exported the m3u of the playlist, opened it with a text editor and the order was correct.
7. I clicked on Edit Playlist, and configured it as follow. I selected SEQUENTIAL order to be sure the order was the intended one.
8. Being my first time and not knowing if it was needed I also restarted the autodj service from the /station/1/profile interface.
9. All the other playlists I have are set to priority 3, shuffle, without any other special configuration.

I configured it yesterday and today at 8am the playlist was played in a random order. The first track was the right one, but the following tracks were random tracks from the playlist.

I quickly opened mixxx and connected it to azuracast to broadcast the right sequence with a software I already know well.

I have a couple of questions:

1. is it possible to schedule the playlist to play the sequence in the right order?
2. was it the right configuration for this kind of scenario?
3. is it possible to exclude a playlist from the general autodj rotation and to play it just when scheduled?

Thanktou so much for your great work and your support!

[arulvakku]

Hi, updated Azuracast just yesterday and did as you instructed....
"Make sure that, for your playlist, ALL of the "Advanced" settings (i.e. Interrupt other tracks, merge to play as one track) are turned OFF;
Verify that your station's time zone is correct, down to the geographical region that includes your daylight saving time rules;"
But still the playlists do not play, at the right time... very frustrating since some of the playlists are time sensitive and I know some listeners wait for the particular program at the scheduled time.
Kindly check the attached screenshot. Kindly do something please....

[cmarina]

Thanks for working on this issue, if there is anything I can help with testing, am happy to spin a fresh install and give feedback!

[AmsterdamFM]

• Version: v0.10.1, #0658b68 (2020-05-06 5:59) • Docker • PHP 7.4
• No advanced features used in the scheduling
• timezone is correct

All modifications up to now were a great improvement to the reliability of the scheduling! We are only left with two small problems when it comes to scheduling. But I also think these should be easy to solve.

We have 2 different hours:

Hour type 1
x:00: News (weight 25) set to play hourly
x:02: 2 or 3 short adds (weight 25) set to play hourly
x:03: Short opening jingle (weight 25) set to play hourly
x:30: news headlines. (weight 2) set to play hourly
All silence is filled with music and jingles with (Weight 1) General rotation and not scheduled

Hour type 2
x:00: News (weight 25) set to play hourly
x:02: 2 or 3 short adds (weight 25) set to play hourly
x:03: Short opening jingle (weight 25) set to play hourly
x:04: A recorded program of about 56 minutes (weight 25) set in the schedule
the news headlines should be skipped in this type of hour.

Problem 1
On a type 2 hour a song is played after the opening jingle causing the schedule to shift forward for the duration of the song. After a few of these hours the shift is getting bigger and bigger.
Solution
I think this problem can be solved by introducing a Weight 0 priority = only play when there is absolutely nothing else to play. We only use music to fill the empty space in between.
And while we are at weights: maybe it is also an idea to introduce a weight 26 = always play. This prevents the software from skipping very important scheduled items.

Problem 2
If a type 1 hour is played after a type 2 hour the news headlines are played around the top of the hour and multiple times if headlines was not played in the preceding hours.. Probably because it could not play it in the preceding hour(s).
Solution
Our current software (Zararadio) solves this by using a _Maximum Wait_ parameter. See screenshot below. This parameter tels the software to only try to play it for the set number of minutes. Setting this to, for example, 7 minutes in our case would solve the file being incorrectly played at the top of the hour.

Hope I have explained it wel. If more information is needed I will be more than happy to provide it,

[adavenport-ops]

I have an issue that the playlists are not playing at the correct time. We will have a show that should play at 6 pm but does not queue or play. I have Created 2nd station for testing and I am unable to get a show to queue with General, Advanced settings but this has the same problem on the 2nd and now 3rd test station. This station is a single host that runs to stations. the First station that we setup does not have any of these problems it is only the second station that will not play a playlist at the scheduled time using the same settings on both stations. I hope to diagnose some of these issues by setting up a second instance and checking to see if the problem occurs only for stations past the first one setup.

Using Docker installation method
Yes

AzuraCast version
v0.10.2, #1229f2b (2020-05-07 0:05)

Host Operating System
Ubuntu 20.04 LTS

Describe the bug
Failure to play the song at the selected time

To Reproduce
Steps to reproduce the behavior:
Create a station and attach a playlist of a show.

Expected behavior
Play song at the scheduled time

Screenshots

[MrSteelMiner]

Since a few updates (there was one big LS update), my playlists are played like I want them to play, so everything is fine for me again :)

[Tragio]

@SlvrEagle23 Today I had a sequential playlist with a scheduled time of 18h with advanced settings to play only once through the playlist and to interrupt other songs.

I restarted the broadcasting a few hours earlier and it didn’t start at the scheduled time. Then I disabled all playlists and let them just the one I wanted. I had a jingle at the first, mix, and then jingle. I exported the playlist to make sure the order was good. I restarted the broadcasting and it start playing both jingles (they have a similar name) and then the mix. Then at almost the end of the mix, I enabled other playlists but they weren’t appearing in the next queue. So I needed to disable the playlist and enable the one I want and restart broadcasting.

I really love Azuracast and I’m working in some PR for frontend but this is my challenge at the time.

Our radio project is based on mixes of 1h30m and 2h but then we have shows at a specific time that needs to be interrupted.

I don’t know if I can interrupt without using the advanced tab. I also don’t know if I need to restart broadcasting in each change for advanced tab use. I don’t know where I can rebuild queue or something like that to refresh all new data.

Can you point me some direction in this? 😊

Thank you for your amazing work! 🚀

[sidney65]

Hi , i have the same problem ; I have every week some play list in sequential mode . For exemple
1 jingle
2 music
3 music
4 mic
5 music... etc...
The play list start à hour + 3 min ; jingle play but after , the autodj play ramdom music ; not music I have programed in original play .
So,only solution I have it's stream directly the show .
Hope you find the solution of this bug beacause I'm not everyday behind my computer to stream all show directly .
If you need someone else to help you ...
Thank for your work and help.

[pierluigi]

Same issue here. The scheduler seems to not work as expected. Any guidance on how to use the debugging tools would be greatly appreciated – according to the release page, as of 10.2

The system debugger page now has a "Rebuild Queue" button that will erase the current upcoming song queue and build a new one, while providing full debugging information on the screen. If you are having issues with your scheduled playlists not playing, you should use this function to help determine how the AutoDJ is running.

I have run the Rebuild Queue but the output doesn't make it clear why my scheduled playlist wasn't considered for the run.

[cpeter1207]

As a professional developer, I appreciate the level of stress a large number of unsolved bug reports can cause. I also appreciate that Azuracast has been incredibly stable for me for a number of years. I have very little experience with php, so I don't know how much I'll be able to help with the autodj script, but I'll definitely look at it.

I was unaware of the rebuild function. I'll definitely give that a try and send in the results. I'd hoped I'd be able to give it a date/time in the future, but it doesn't look like that is an option. My most complex scheduling is set up for Saturday evenings, so I'll try it during that time and see what it shows.

Fwiw, here is what I'm trying to do.

I have a large collection of radio dramas I play in a scheduled block on Saturday evenings. They're all around half an hour in length, but some are only 23 or 24 minutes, while others are 28 or 29 minutes long. Here is what I've done to accomodate that:

1. Schedule a sequential playlist from 6:30 PM to 6:54 PM because the shortest file in this playlist is 24 minutes long. I hope that scheduling it this way will cause only one track in the playlist to be played during that time.
2. Schedule a shuffled "commercial break" (they're not real commercials, just very short tracks) from 6:54 PM to 7:00 PM. I hope this will fill time for nights when shorter files get played.
3. Schedule the next sequential playlist for 7:00 PM to 7:27 PM because the shortest file in the playlist is 27 minutes long. Again, my goal is to have only one track in the playlist get scheduled during the 7:00 PM to 7:30 PM block.
4. Schedule another commercial break from 7:27 PM to 7:30 PM. Again, I hope this fills time with short tracks that allow my next playlist to begin at roughly 7:30 PM.
5. Continue the pattern for each half hour until 10:00 PM.

My timezone is America/Chicago, and I'm not using any advanced options. I understand that they give control to liquidsoap directly and all that that implies. That doesn't fit my usecase because Azuracast keeps track of where I left off in a sequential playlist, even across restarts, where liquidsoap does not. These are all serialized, so playing them in sequence is very important to me.

I've been running this schedule now for about six or seven weeks. Some weeks, it runs flawlessly. Others, I see the following behaviors.

1. The whole schedule sometimes starts quite late E.g. 6:45 PM instead of 6:30 PM. I play music most of the time, so I expect there to be some variation in start time, but not that much... At worst, I'd think it'd start at 6:35 if a five-minute track were cued at 6:29:59 PM... I've considered scheduling the first show to start at 6:25 PM to accomadate for that possible variation, but I do feel like there is a bug here.

2. Sometimes one or more of the scheduled playlists doesn't get played. The first time this happened, the whole schedule started late, so I wondered if it was skipped in an attempt to catch up. The second time I observed this, though, everything was running on time so I'm not sure what occurred there. Again, if I'm able to reproduce it, I'll send in data, but it's not consistent.

3. The last time item 2 occurred, the sequential playlist for the 8:00 PM to 8:30 PM half hour block was played a whole half hour early at 7:30 PM. This occurred after the 7:00 PM to 7:30 PM playlist had been cued twice. When I noticed this, I deleted the second entry from the upcoming song queue, so it's possible that I confused the autodj.

I think it's important to note that I have crossfading enabled. I don't see any mention of that in this issue, but it occurs to me that crossfading could throw off scheduling logic because you lose the first and last few seconds of a track. I'm not running a big station, so I can probably experiment with disabling crossfading if you think it's worth it to get that datapoint.

It's also not clear to me if, or how, playlist weights are used to make these decisions. If I scripted this with liquidsoap directly, they wouldn't be taken into account at all, but I don't know whether or not the autodj script behaves differently, so I've kept all of my scheduled playlist weights at 3.

Ultimately I think there is probably a combination of things going on here. I think there is a bug that sometimes causes scheduled events to be played much later than they should be. I have no way to prove this, but I think I've occasionally seen tracks get played that were not in the upcoming song queue. Is it possible that the queue gets thrown off if the next song script returns an error and liquidsoap inserts a track of its own?

I'm sure I've also contributed to some of this weirdness by manually manipulating the queue in an attempt to get things back on track when they start to go off the rails. It really throws things off when two tracks from a playlist consisting of half-hour tracks get played when we only expect one. I could force this by setting the start and end times of those playlists to be the same. Is there ever a point, though, where a playlist with the same start and end time will be skipped if, for some reason, it couldn't be played at or around the specified start time?

I think there are times when the schedule gets thrown off so far that something does need to get skipped. I'd hope, for example, that if one of my shows didn't start within its specified start and end times, then it wouldn't start at all. It would be helpful, though, if the autodj respected the "Only play one track at scheduled time" setting so I could clearly and unambiguously tell Azuracast that I only want one track from that playlist to be played, even if another track from the playlist could be queued again because it would start during the specified time range.

I have a number of ideas for improving the scheduling interface, and I've spent a lot of time trying to fit them into this comment, but ultimately they're beside the point. I hope this comment clearly explains what I'm trying to do. I'll follow up with more data as I'm able to recreate these rather inconsistent results.

[pierluigi]

Thanks @cpeter1207 for the detailed report. I wanted to add my anecdotal experience as it's very similar to yours, and that I _suspect_ the root cause may lie in the scheduler not taking into consideration track duration when deciding what to play next which ultimately results in schedules being thrown off.

I looked at the scheduler code but my php is a bit rusty and I'm not sure I can help.

I'd like to surface some assumptions, maybe that's useful:

1. A "scheduled" playlist should ONLY ever play at the scheduled time. Currently, this is not the case for me (e.g. I get scheduled playlists occurring outside their scheduled times)
2. A playlist with a schedule should start at the scheduled time. This is currently not the case and in my tests this is easily reproducible with e.g. a long track that gets in the way and spills over

It would be helpful to know whether or not these assumptions are correct and if they should indeed be the expected result for the scheduling behaviour.

If it helps, I would suggest the author(s) to test the scheduler with a mix of short (5m) and long (30m / 1h30) tracks (e.g. mixes) as in my experience that's when the schedule behaves erratically.

[cpeter1207]

I don’t think your assumptions are valid.

If you expect a playlist to start at a specific time, then you need to either specify that the playlist interrupt the previous playlist, an “advanced” option that has other implications, or assume that the playlist might be delayed, or even skipped entirely, if the currently playing track spills over into the next scheduled block. This really should be configurable.

I see two options:

1. Use a dynamic cue out point to simulate an interrupted playlist. If nextPlayListIsInterrupting and trackDuration > timeRemainingForPlaylist then cue_out_metadata = timeRemainingForPlaylist.

That would cause the currently running playlist to end, though abruptly, on time and allow the next, interrupting, playlist to start while keeping the autodj in control.

1. 
   
   1. Make each playlist a dynamic source, driven by a “next song” script provided by liquidsoap. For example:
   
   

playlist = request.dynamic.list(timeout=20., retry_delay=3., {azuracast_next_song(playlist_id)})

This would let you deuse liquidsoap scheduling to play a playlist while retaining the duplicate avoidance and sequence tracking that Azuracast already does well.

I need to go to work, but I haven’t decided yet which option I like better. Maybe the dynamic cue out point idea might be easier to implement within Azuracast’s current architecture.

Sent from Mailhttps://go.microsoft.com/fwlink/?LinkId=550986 for Windows 10

From: Pierluigi [e-mail]
Sent: Tuesday, June 30, 2020 3:59 AM
To: AzuraCast/[e-mail]
Cc: [e-mail]; [e-mail]
Subject: Re: [AzuraCast/AzuraCast] Playlist Not Playing at Scheduled Time Super-Issue (#2631)

Thanks @cpeter1207https://github.com/cpeter1207 for the detailed report. I wanted to add my anecdotal experience as it's very similar to yours, and that I suspect the root cause may lie in the scheduler not taking into consideration track duration when deciding what to play next which ultimately results in schedules being thrown off.

I looked at the scheduler codehttps://github.com/AzuraCast/AzuraCast/blob/master/src/Radio/AutoDJ.php#L163 but my php is a bit rusty and I'm not sure I can help.

I'd like to surface some assumptions, maybe that's useful:

1. A "scheduled" playlist should ONLY ever play at the scheduled time. Currently, this is not the case for me.
2. A playlist with a schedule should start at the scheduled time. This is currently not the case and in my tests this is easily reproducible with e.g. a long track that gets in the way and spills over.

It would be helpful to know whether or not these assumptions are correct and if they should indeed be the expected result for the scheduling behaviour.

If it helps, I would suggesting the author(s) to test the scheduler with a mix of short (5m) and long (30m / 1h30) tracks (e.g. mixes) as in my experience that's when the schedule behaves erratically.

—
You are receiving this because you were mentioned.
Reply to this email directly, view it on GitHubhttps://github.com/AzuraCast/AzuraCast/issues/2631#issuecomment-651660135, or unsubscribehttps://github.com/notifications/unsubscribe-auth/AKQZOIR332PXL2C4KVT4QITRZGSQFANCNFSM4L6Q7EDA.

[cpeter1207]

I wanted to post an update. I've cloned the AZuracast git repository and I'm looking at autodj.php. I'm able to understand parts of it, but other parts are hard to get my head around.

@SlvrEagle23 can you explain how track duration is used to decide what gets queued? More specifically, is crossfading taken into account when calculating track duration? I think track duration needs to be track duration - (crossfadeDuration / 2) to be accurate if crossfading is enabled. Does that seem correct to you?

I don't see any reference to crossfading in autodj.php, but maybe the logic for that is handled somewhere else?

I think I'm going to disable the crossfader on my station and see how that impacts the behavior I see with the scheduler unless you can tell me that you believe crossfade overlaps are taken into account.

[cpeter1207]

I have a once-per-hour playlist scheduled to play at 0 minutes after the hour. Here is an example where this didn't happen, and I think it should've...

Here are the entries from my up-coming song queue. They show that a song was queued at 1:00 PM, and the top of hour ID was queued at 1:04 PM. Why was a 4-minute song queued at 1:00 PM when the once-per-hour playlist was scheduled for 1:00 PM?

Jul 3, 2020 1:00 PM
Melanie
"Weird Al" Yankovic
Playlist: Comedy

Jul 3, 2020 1:04 PM
Radio Onionring 17
Playlist: Top of Hour ID

Jul 3, 2020 1:04 PM
Imperial Attack
The Electric Moog Orchestra
Playlist: Moog

Here is the output of the "rebuild queue" function for that time. Notice that the "top of hour" playlist wan't considered playable at this time, even though it was 1:00:19 PM when I pushed the button. It's interesting to me that the history doesn't show that "Melanie" was queued, even though it was playing by the time I pushed the button.

The history does, however, show the song that played before "Melanie", which should've ended at 1:00:02 PM according to its duration. Imo the top of hour ID should've been queued when Melanie was, and it should've played at 1:00:02 PM.

Debug
Current queue cleared.
Debug
Adding to station queue.
now
"2020-07-03 13:00:19"
station
{
"id": 1,
"name": "Radio Onion Ring"
}
Info
AzuraCast AutoDJ is calculating the next song to play...
Debug
AutoDJ recent song playback history
history
[
{
"song": "Texas - I Don't Want A Lover",
"cued_at": "2020-07-03 12:55:02",
"duration": 300,
"sent_to_autodj": true
},
{
"song": "The Simpsons - Happy Birthday, Mr. Smithers",
"cued_at": "2020-07-03 12:55:02",
"duration": 16,
"sent_to_autodj": true
},
{
"song": "Robert Lund - You've Got Hogwarts",
"cued_at": "2020-07-03 12:51:18",
"duration": 163,
"sent_to_autodj": true
},
{
"song": "Various Artists - I Love Lucy",
"cued_at": "2020-07-03 12:51:18",
"duration": 61,
"sent_to_autodj": true
},
{
"song": "Danny Birt - 02 The Answer My Friends Is Filk",
"cued_at": "2020-07-03 12:49:10",
"duration": 128,
"sent_to_autodj": true
},
{
"song": "Jerry Orbach & Angela Lansbury - Be Our Guest",
"cued_at": "2020-07-03 12:45:26",
"duration": 224,
"sent_to_autodj": true
},
{
"song": "Scooter - Jumping All Over The World",
"cued_at": "2020-07-03 12:41:35",
"duration": 230,
"sent_to_autodj": true
},
{
"song": "Seal - Kiss From A Rose",
"cued_at": "2020-07-03 12:36:48",
"duration": 288,
"sent_to_autodj": true
},
{
"song": "Weezer - No One Else",
"cued_at": "2020-07-03 12:33:10",
"duration": 185,
"sent_to_autodj": true
},
{
"song": "Radio Onionring 21",
"cued_at": "2020-07-03 12:33:10",
"duration": 33,
"sent_to_autodj": true
},
{
"song": "Perrey And Kingsley - The Unidentified Flying Object",
"cued_at": "2020-07-03 12:31:08",
"duration": 122,
"sent_to_autodj": true
},
{
"song": "Scissor Sisters - Laura",
"cued_at": "2020-07-03 12:27:58",
"duration": 190,
"sent_to_autodj": true
},
{
"song": "Brad Kane & Lea Salonga - A Whole New World",
"cued_at": "2020-07-03 12:25:16",
"duration": 162,
"sent_to_autodj": true
},
{
"song": "Lighthouse Family - High",
"cued_at": "2020-07-03 12:16:36",
"duration": 274,
"sent_to_autodj": true
},
{
"song": "Bobby Driscoll, Kathryn Beaumont, Paul Collins & Tommy Luske - You Can Fly! You Can Fly! You Can Fly!",
"cued_at": "2020-07-03 12:16:36",
"duration": 245,
"sent_to_autodj": true
}
]
station
{
"id": 1,
"name": "Radio Onion Ring"
}
Info
8 playable playlist(s) of type "default_unscheduled" found.
playlists
[
{
"id": 25,
"name": "Comedy",
"weight": 7
},
{
"id": 23,
"name": "Mainstream high",
"weight": 5
},
{
"id": 26,
"name": "Mainstream Medium",
"weight": 3
},
{
"id": 28,
"name": "Chris's Albums",
"weight": 2
},
{
"id": 27,
"name": "Mainstream Low",
"weight": 1
},
{
"id": 29,
"name": "Moog",
"weight": 1
},
{
"id": 33,
"name": "TV",
"weight": 1
},
{
"id": 34,
"name": "Kids",
"weight": 1
}
]
station
{
"id": 1,
"name": "Radio Onion Ring"
}
Info
Found track that avoids duplicate title and artist.
media_id
10108
station
{
"id": 1,
"name": "Radio Onion Ring"
}
Info
Playable track found and registered.
next_song
"StationMedia caafb806e3bbfe5fef72deb6: They Might Be Giants - Clap Your Hands (Atlanta)"
station
{
"id": 1,
"name": "Radio Onion Ring"
}
Debug
Adding to station queue.
now
"2020-07-03 13:02:17"
station
{
"id": 1,
"name": "Radio Onion Ring"
}
Info
AzuraCast AutoDJ is calculating the next song to play...
Debug
AutoDJ recent song playback history
history
[
{
"song": "They Might Be Giants - Clap Your Hands (Atlanta)",
"cued_at": "2020-07-03 13:00:19",
"duration": 118,
"sent_to_autodj": false
},
{
"song": "Texas - I Don't Want A Lover",
"cued_at": "2020-07-03 12:55:02",
"duration": 300,
"sent_to_autodj": true
},
{
"song": "The Simpsons - Happy Birthday, Mr. Smithers",
"cued_at": "2020-07-03 12:55:02",
"duration": 16,
"sent_to_autodj": true
},
{
"song": "Robert Lund - You've Got Hogwarts",
"cued_at": "2020-07-03 12:51:18",
"duration": 163,
"sent_to_autodj": true
},
{
"song": "Various Artists - I Love Lucy",
"cued_at": "2020-07-03 12:51:18",
"duration": 61,
"sent_to_autodj": true
},
{
"song": "Danny Birt - 02 The Answer My Friends Is Filk",
"cued_at": "2020-07-03 12:49:10",
"duration": 128,
"sent_to_autodj": true
},
{
"song": "Jerry Orbach & Angela Lansbury - Be Our Guest",
"cued_at": "2020-07-03 12:45:26",
"duration": 224,
"sent_to_autodj": true
},
{
"song": "Scooter - Jumping All Over The World",
"cued_at": "2020-07-03 12:41:35",
"duration": 230,
"sent_to_autodj": true
},
{
"song": "Seal - Kiss From A Rose",
"cued_at": "2020-07-03 12:36:48",
"duration": 288,
"sent_to_autodj": true
},
{
"song": "Weezer - No One Else",
"cued_at": "2020-07-03 12:33:10",
"duration": 185,
"sent_to_autodj": true
},
{
"song": "Radio Onionring 21",
"cued_at": "2020-07-03 12:33:10",
"duration": 33,
"sent_to_autodj": true
},
{
"song": "Perrey And Kingsley - The Unidentified Flying Object",
"cued_at": "2020-07-03 12:31:08",
"duration": 122,
"sent_to_autodj": true
},
{
"song": "Scissor Sisters - Laura",
"cued_at": "2020-07-03 12:27:58",
"duration": 190,
"sent_to_autodj": true
},
{
"song": "Brad Kane & Lea Salonga - A Whole New World",
"cued_at": "2020-07-03 12:25:16",
"duration": 162,
"sent_to_autodj": true
},
{
"song": "Lighthouse Family - High",
"cued_at": "2020-07-03 12:16:36",
"duration": 274,
"sent_to_autodj": true
}
]
station
{
"id": 1,
"name": "Radio Onion Ring"
}
Info
8 playable playlist(s) of type "default_unscheduled" found.
playlists
[
{
"id": 25,
"name": "Comedy",
"weight": 7
},
{
"id": 23,
"name": "Mainstream high",
"weight": 5
},
{
"id": 26,
"name": "Mainstream Medium",
"weight": 3
},
{
"id": 28,
"name": "Chris's Albums",
"weight": 2
},
{
"id": 27,
"name": "Mainstream Low",
"weight": 1
},
{
"id": 29,
"name": "Moog",
"weight": 1
},
{
"id": 33,
"name": "TV",
"weight": 1
},
{
"id": 34,
"name": "Kids",
"weight": 1
}
]
station
{
"id": 1,
"name": "Radio Onion Ring"
}
Info
Found track that avoids duplicate title and artist.
media_id
4526
station
{
"id": 1,
"name": "Radio Onion Ring"
}
Info
Playable track found and registered.
next_song
"StationMedia 1e37cbac492ef4f2bc1b5152: Voice Of The Beehive - Don't Call Me Baby"
station
{
"id": 1,
"name": "Radio Onion Ring"
}
Debug
Adding to station queue.
now
"2020-07-03 13:05:21"
station
{
"id": 1,
"name": "Radio Onion Ring"
}
Info
AzuraCast AutoDJ is calculating the next song to play...
Debug
AutoDJ recent song playback history
history
[
{
"song": "Voice Of The Beehive - Don't Call Me Baby",
"cued_at": "2020-07-03 13:02:17",
"duration": 184,
"sent_to_autodj": false
},
{
"song": "They Might Be Giants - Clap Your Hands (Atlanta)",
"cued_at": "2020-07-03 13:00:19",
"duration": 118,
"sent_to_autodj": false
},
{
"song": "Texas - I Don't Want A Lover",
"cued_at": "2020-07-03 12:55:02",
"duration": 300,
"sent_to_autodj": true
},
{
"song": "The Simpsons - Happy Birthday, Mr. Smithers",
"cued_at": "2020-07-03 12:55:02",
"duration": 16,
"sent_to_autodj": true
},
{
"song": "Robert Lund - You've Got Hogwarts",
"cued_at": "2020-07-03 12:51:18",
"duration": 163,
"sent_to_autodj": true
},
{
"song": "Various Artists - I Love Lucy",
"cued_at": "2020-07-03 12:51:18",
"duration": 61,
"sent_to_autodj": true
},
{
"song": "Danny Birt - 02 The Answer My Friends Is Filk",
"cued_at": "2020-07-03 12:49:10",
"duration": 128,
"sent_to_autodj": true
},
{
"song": "Jerry Orbach & Angela Lansbury - Be Our Guest",
"cued_at": "2020-07-03 12:45:26",
"duration": 224,
"sent_to_autodj": true
},
{
"song": "Scooter - Jumping All Over The World",
"cued_at": "2020-07-03 12:41:35",
"duration": 230,
"sent_to_autodj": true
},
{
"song": "Seal - Kiss From A Rose",
"cued_at": "2020-07-03 12:36:48",
"duration": 288,
"sent_to_autodj": true
},
{
"song": "Weezer - No One Else",
"cued_at": "2020-07-03 12:33:10",
"duration": 185,
"sent_to_autodj": true
},
{
"song": "Radio Onionring 21",
"cued_at": "2020-07-03 12:33:10",
"duration": 33,
"sent_to_autodj": true
},
{
"song": "Perrey And Kingsley - The Unidentified Flying Object",
"cued_at": "2020-07-03 12:31:08",
"duration": 122,
"sent_to_autodj": true
},
{
"song": "Scissor Sisters - Laura",
"cued_at": "2020-07-03 12:27:58",
"duration": 190,
"sent_to_autodj": true
},
{
"song": "Brad Kane & Lea Salonga - A Whole New World",
"cued_at": "2020-07-03 12:25:16",
"duration": 162,
"sent_to_autodj": true
}
]
station
{
"id": 1,
"name": "Radio Onion Ring"
}
Info
8 playable playlist(s) of type "default_unscheduled" found.
playlists
[
{
"id": 25,
"name": "Comedy",
"weight": 7
},
{
"id": 23,
"name": "Mainstream high",
"weight": 5
},
{
"id": 26,
"name": "Mainstream Medium",
"weight": 3
},
{
"id": 28,
"name": "Chris's Albums",
"weight": 2
},
{
"id": 27,
"name": "Mainstream Low",
"weight": 1
},
{
"id": 29,
"name": "Moog",
"weight": 1
},
{
"id": 33,
"name": "TV",
"weight": 1
},
{
"id": 34,
"name": "Kids",
"weight": 1
}
]
station
{
"id": 1,
"name": "Radio Onion Ring"
}
Info
Found track that avoids duplicate title and artist.
media_id
7462
station
{
"id": 1,
"name": "Radio Onion Ring"
}
Info
Playable track found and registered.
next_song
"StationMedia 7810b7ae39bad393471b0831: - Westwood One Demo Tape (Circa 1987)"
station
{
"id": 1,
"name": "Radio Onion Ring"
}

[cpeter1207]

I forgot to mention in my previous comment that I disabled crossfading for this test.

I've been trying to get a better understanding of the autodj code. It's prompted some questions for me:

Are weights considered for scheduled playlists? It appears that they might be, if I understand the code correctly.

Similarly, does the playlist type, E.g. once-per-x-minutes, matter when I also have scheduled events? I'd assumed they were mutually exclusive, but the code makes me think that if I, for example, create a once-per-30-minute playlist, and schedule it for 7:00 PM - 7:30 PM, then Azuracast might only play the track once during that 30 minute period. That is kinda cool, if that is the case, but not something I'd expected or gathered from the UI.

I'm going to try exactly that to avoid having a playlist play another track if the track that was played ends before the scheduled block ends. So far I can say that I've been listening for over half an hour, and I haven't heard my every-30-minute playlist get played, so maybe this really is how this works. If that is the case, then I suggest moving the playlist types to the "schedule" tab and clarifying how they co-exist with scheduled events.

I do believe, though, that my above comment does show that scheduled events are sometimes getting played later than they should. I don't know enough to root cause this at the moment. If anyone else does, and this gives them inspiration, I'd be glad to help test a patch.

[cpeter1207]

And here is an example of what should've happened...

Jul 3, 2020 1:25 PM
My Favorite Martian
J. Chertok
Playlist: TV

Jul 3, 2020 1:26 PM
Beat Goes On
The All Seeing I
Playlist: Mainstream high

Jul 3, 2020 1:30 PM
Radio Onionring 4
Playlist: Bottom Of Hour ID

Is it possible that rebuilding the queue reset the state such that the bottom of hour ID was scheduled at the correct time? I'm pretty sure I'll still be here at 2:00 PM, so I'll update this then to see if this holds true.

[cpeter1207]

I may have spoken too soon. It's 1:30 PM now, and "Beat Goes On" started playing at 1:29:[something]. This means the bottom of hour ID won't start for another four minutes.

I hadn't submitted this before that happened, so I was able to note that the bottom of hour ID didn't play until 1:33:30 PM, even though it was queued at 1:00 PM. It would help if the upcoming song queue displayed timestamps to the second, but it appears that the playout time lags the queue time by about three minutes on my system right now.

Note my observation about the song history in a previous comment. The song history didn't contain "Melanie", which was the song that was playing at the time the queue was rebuilt. Could that have been the issue? Is the "now" calculation off because it isn't taking into account the currently playing song?

[cpeter1207]

At 1:46:02 PM

Playing Now
Hoochie Booty
Ultimate KAOS
Playlist: Mainstream high

Playing Next
It Takes Who
the great Luke Ski

Upcoming song queue:

Jul 3, 2020 1:52 PM
It Takes Who
the great Luke Ski
Playlist: Comedy

Jul 3, 2020 1:57 PM
woman
nbw320 natural
Playlist: Comedy

Jul 3, 2020 2:00 PM
I'm So Miserable Without You (It's Just Like Having You Around)
Kip Addotta
Playlist: Comedy

Why is "I'm So Miserable" queued for 2:00 PM? Again, the top of hour ID should've been queued...

Here is a refresh of the upcoming queue after "It Takes Who" started:

Jul 3, 2020 1:57 PM
woman
nbw320 natural
Playlist: Comedy

Jul 3, 2020 2:00 PM
I'm So Miserable Without You (It's Just Like Having You Around)
Kip Addotta
Playlist: Comedy

Jul 3, 2020 2:03 PM
I'm So Excited
Pointer Sisters
Playlist: Mainstream high

Again, no top of hour ID, even though the last song was scheduled for 2:03 PM, three minutes after 2:00 PM...

And another refresh of the upcoming song queue, now showing the top of hour ID scheduled for 2:09 PM (nine minutes late):

Jul 3, 2020 2:00 PM
I'm So Miserable Without You (It's Just Like Having You Around)
Kip Addotta
Playlist: Comedy

Jul 3, 2020 2:03 PM
I'm So Excited
Pointer Sisters
Playlist: Mainstream high

Jul 3, 2020 2:09 PM
Radio Onionring 14
Playlist: Top of Hour ID

The top of hour ID did play at 2:09:18 PM, so the lag I thought was there seems to be gone now, but there also seems to be no reason the top of hour ID shouldn't have played before "I'm So Miserable".

[cpeter1207]

@SlvrEagle23

What would you like me to check next?

[pixel-paul]

I'm also getting irregularities with the playlist functionality. My use case is that I have 1-2 hour long pre-recorded shows which are scheduled each day. Here are a couple of issues I have noticed:

1. The playlist order is often not respected
2. When a change to an upcoming playlist is made, the queue is not recreated as expected. For example if a playlist is due to start at 18:00 and I have added a track to the playlist at 17:45, the 'next playing' song should be the track I have added. Sometimes it is just one of the tracks in the playlist, other times it appears in the 'upcoming song queue', but another track is played.
3. The 'upcoming song queue' often does not reflect the 'playing next' on the dashboard, particularly if the queue has been recreated.

[cpeter1207]

@SlvrEagle23
foreach ($playlists_by_type[$type] as $playlist_id => $playlist) {
/** @var Entity\StationPlaylist $playlist */
if ($playlist->shouldPlayNow($now, $cued_song_history)) {
$eligible_playlists[$playlist_id] = $playlist->getWeight();
$log_playlists[] = [
'id' => $playlist->getId(),
'name' => $playlist->getName(),
'weight' => $playlist->getWeight(),
];
}
}

        if (empty($eligible_playlists)) {
            continue;
        }

        $this->logger->info(sprintf(
            '%d playable playlist(s) of type "%s" found.',
            count($eligible_playlists),
            $type
        ), ['playlists' => $log_playlists]);

        // Shuffle playlists by weight.
        $this->weightedShuffle($eligible_playlists);

Do I understand this correctly? Playlists are first added to eligible_playlists by type, then shuffled by weight without regard to type?

Does this mean that a scheduled playlist could be delayed by an unscheduled playlist with a higher weight?

[cpeter1207]

Here is my current upcoming song queue:

Jul 3, 2020 7:56 PM
Wanted Dead Or Alive
Bon Jovi
Playlist: Mainstream high

Jul 3, 2020 8:01 PM
Radio Onionring 7
Playlist: Top of Hour ID

Jul 3, 2020 8:01 PM
I'll Have To Say I Love You...
Steve Goodie
Playlist: Comedy

At 7:59:03 PM CDT

Now Playing
Balls To The Wall
Accept
Playlist: Mainstream high
03:05 / 05:38

Playing Next
Wanted Dead Or Alive
Bon Jovi
Playlist: Mainstream high

"Balls To The Wall" was not in my up-coming song queue (I don't think), but it played before "Wanted Dead Or Alive", which was up next at the time I looked at the up-coming song queue. There could've been a good reason this got inserted, or I could've just missed it, but it does show that the up-coming song queue isn't always accurate. "Wanted Dead Or Alive
" started playing at 8:02:18 PM even though it was queued at 7:56 PM. This, of course, delayed my top of hour ID which was queued at what I think was an appropriate time.

[cpeter1207]

I noted the up-coming song queue at 7:01:47 PM CDT

Jul 4, 2020 6:26 PM
Archie Bunker Theme.Lr
For Fcc Licensed Low Power F M Radio Use Only
Playlist: Commercial Break

Jul 4, 2020 6:27 PM
Mork Mindy 01.Lr
For Fcc Licensed Low Power F M Radio Use Only
Playlist: Commercial Break

Jul 4, 2020 6:28 PM
Shock Women
For Fcc Licensed Low Power F M Radio Use Only
Playlist: Commercial Break

I then rebuilt the queue. Here is the output.

Debug
Current queue cleared.
Debug
Adding to station queue.
now
"2020-07-04 18:26:45"
station
{
"id": 1,
"name": "Radio Onion Ring"
}
Info
AzuraCast AutoDJ is calculating the next song to play...
Debug
AutoDJ recent song playback history
history
[
{
"song": "Nik Kershaw - When A Heart Beats",
"cued_at": "2020-07-04 18:22:31",
"duration": 257,
"sent_to_autodj": true
},
{
"song": "Bucks Fizz - New Beginning (Mamba Seyra)",
"cued_at": "2020-07-04 18:18:30",
"duration": 241,
"sent_to_autodj": true
},
{
"song": "Dua Lipa - Blow Your Mind (Mwah)",
"cued_at": "2020-07-04 18:15:35",
"duration": 178,
"sent_to_autodj": true
},
{
"song": "Michelle Dockrey - Mal's Song",
"cued_at": "2020-07-04 18:10:01",
"duration": 255,
"sent_to_autodj": true
},
{
"song": "TMBG--Gas - Mask",
"cued_at": "2020-07-04 18:10:01",
"duration": 83,
"sent_to_autodj": true
},
{
"song": "The Hoosiers - Worried About Ray",
"cued_at": "2020-07-04 18:07:02",
"duration": 167,
"sent_to_autodj": true
},
{
"song": "Kelly Osbourne Feat. Ozzy Osbourne - Changes",
"cued_at": "2020-07-04 18:02:54",
"duration": 249,
"sent_to_autodj": true
},
{
"song": "Go West - Faithful",
"cued_at": "2020-07-04 17:58:32",
"duration": 265,
"sent_to_autodj": true
},
{
"song": "Deep Dish - Say Hello",
"cued_at": "2020-07-04 17:55:25",
"duration": 188,
"sent_to_autodj": true
},
{
"song": "Robbie Williams - Strong",
"cued_at": "2020-07-04 17:50:50",
"duration": 278,
"sent_to_autodj": true
},
{
"song": "George Michael - Faith",
"cued_at": "2020-07-04 17:48:05",
"duration": 167,
"sent_to_autodj": true
},
{
"song": "They Might Be Giants - Meet James Ensor",
"cued_at": "2020-07-04 17:46:34",
"duration": 93,
"sent_to_autodj": true
},
{
"song": "Fatboy Slim - The Rockafeller Skank",
"cued_at": "2020-07-04 17:42:35",
"duration": 240,
"sent_to_autodj": true
},
{
"song": "Eva Cassidy - Somewhere Over The Rainbow",
"cued_at": "2020-07-04 17:37:25",
"duration": 301,
"sent_to_autodj": true
},
{
"song": "Don Henley - All She Wants To Do Is Dance",
"cued_at": "2020-07-04 17:32:57",
"duration": 269,
"sent_to_autodj": true
}
]
station
{
"id": 1,
"name": "Radio Onion Ring"
}
Info
1 playable playlist(s) of type "default_scheduled" found.
playlists
[
{
"id": 42,
"name": "Commercial Break",
"weight": 24
}
]
station
{
"id": 1,
"name": "Radio Onion Ring"
}
Info
Playable track found and registered.
next_song
"StationMedia 1b4ef8dc97b36687fa641ae4: - Jack Poet Volkswagen: Lounge Singer"
station
{
"id": 1,
"name": "Radio Onion Ring"
}
Debug
Adding to station queue.
now
"2020-07-04 18:27:32"
station
{
"id": 1,
"name": "Radio Onion Ring"
}
Info
AzuraCast AutoDJ is calculating the next song to play...
Debug
AutoDJ recent song playback history
history
[
{
"song": "Jack Poet Volkswagen: Lounge Singer",
"cued_at": "2020-07-04 18:26:45",
"duration": 47,
"sent_to_autodj": false
},
{
"song": "Nik Kershaw - When A Heart Beats",
"cued_at": "2020-07-04 18:22:31",
"duration": 257,
"sent_to_autodj": true
},
{
"song": "Bucks Fizz - New Beginning (Mamba Seyra)",
"cued_at": "2020-07-04 18:18:30",
"duration": 241,
"sent_to_autodj": true
},
{
"song": "Dua Lipa - Blow Your Mind (Mwah)",
"cued_at": "2020-07-04 18:15:35",
"duration": 178,
"sent_to_autodj": true
},
{
"song": "Michelle Dockrey - Mal's Song",
"cued_at": "2020-07-04 18:10:01",
"duration": 255,
"sent_to_autodj": true
},
{
"song": "TMBG--Gas - Mask",
"cued_at": "2020-07-04 18:10:01",
"duration": 83,
"sent_to_autodj": true
},
{
"song": "The Hoosiers - Worried About Ray",
"cued_at": "2020-07-04 18:07:02",
"duration": 167,
"sent_to_autodj": true
},
{
"song": "Kelly Osbourne Feat. Ozzy Osbourne - Changes",
"cued_at": "2020-07-04 18:02:54",
"duration": 249,
"sent_to_autodj": true
},
{
"song": "Go West - Faithful",
"cued_at": "2020-07-04 17:58:32",
"duration": 265,
"sent_to_autodj": true
},
{
"song": "Deep Dish - Say Hello",
"cued_at": "2020-07-04 17:55:25",
"duration": 188,
"sent_to_autodj": true
},
{
"song": "Robbie Williams - Strong",
"cued_at": "2020-07-04 17:50:50",
"duration": 278,
"sent_to_autodj": true
},
{
"song": "George Michael - Faith",
"cued_at": "2020-07-04 17:48:05",
"duration": 167,
"sent_to_autodj": true
},
{
"song": "They Might Be Giants - Meet James Ensor",
"cued_at": "2020-07-04 17:46:34",
"duration": 93,
"sent_to_autodj": true
},
{
"song": "Fatboy Slim - The Rockafeller Skank",
"cued_at": "2020-07-04 17:42:35",
"duration": 240,
"sent_to_autodj": true
},
{
"song": "Eva Cassidy - Somewhere Over The Rainbow",
"cued_at": "2020-07-04 17:37:25",
"duration": 301,
"sent_to_autodj": true
}
]
station
{
"id": 1,
"name": "Radio Onion Ring"
}
Info
1 playable playlist(s) of type "default_scheduled" found.
playlists
[
{
"id": 42,
"name": "Commercial Break",
"weight": 24
}
]
station
{
"id": 1,
"name": "Radio Onion Ring"
}
Info
Playable track found and registered.
next_song
"StationMedia a6f4bd53f105acb6a2e52348: - Weasel News #6"
station
{
"id": 1,
"name": "Radio Onion Ring"
}
Debug
Adding to station queue.
now
"2020-07-04 18:28:28"
station
{
"id": 1,
"name": "Radio Onion Ring"
}
Info
AzuraCast AutoDJ is calculating the next song to play...
Debug
AutoDJ recent song playback history
history
[
{
"song": "Weasel News #6",
"cued_at": "2020-07-04 18:27:32",
"duration": 56,
"sent_to_autodj": false
},
{
"song": "Jack Poet Volkswagen: Lounge Singer",
"cued_at": "2020-07-04 18:26:45",
"duration": 47,
"sent_to_autodj": false
},
{
"song": "Nik Kershaw - When A Heart Beats",
"cued_at": "2020-07-04 18:22:31",
"duration": 257,
"sent_to_autodj": true
},
{
"song": "Bucks Fizz - New Beginning (Mamba Seyra)",
"cued_at": "2020-07-04 18:18:30",
"duration": 241,
"sent_to_autodj": true
},
{
"song": "Dua Lipa - Blow Your Mind (Mwah)",
"cued_at": "2020-07-04 18:15:35",
"duration": 178,
"sent_to_autodj": true
},
{
"song": "Michelle Dockrey - Mal's Song",
"cued_at": "2020-07-04 18:10:01",
"duration": 255,
"sent_to_autodj": true
},
{
"song": "TMBG--Gas - Mask",
"cued_at": "2020-07-04 18:10:01",
"duration": 83,
"sent_to_autodj": true
},
{
"song": "The Hoosiers - Worried About Ray",
"cued_at": "2020-07-04 18:07:02",
"duration": 167,
"sent_to_autodj": true
},
{
"song": "Kelly Osbourne Feat. Ozzy Osbourne - Changes",
"cued_at": "2020-07-04 18:02:54",
"duration": 249,
"sent_to_autodj": true
},
{
"song": "Go West - Faithful",
"cued_at": "2020-07-04 17:58:32",
"duration": 265,
"sent_to_autodj": true
},
{
"song": "Deep Dish - Say Hello",
"cued_at": "2020-07-04 17:55:25",
"duration": 188,
"sent_to_autodj": true
},
{
"song": "Robbie Williams - Strong",
"cued_at": "2020-07-04 17:50:50",
"duration": 278,
"sent_to_autodj": true
},
{
"song": "George Michael - Faith",
"cued_at": "2020-07-04 17:48:05",
"duration": 167,
"sent_to_autodj": true
},
{
"song": "They Might Be Giants - Meet James Ensor",
"cued_at": "2020-07-04 17:46:34",
"duration": 93,
"sent_to_autodj": true
},
{
"song": "Fatboy Slim - The Rockafeller Skank",
"cued_at": "2020-07-04 17:42:35",
"duration": 240,
"sent_to_autodj": true
}
]
station
{
"id": 1,
"name": "Radio Onion Ring"
}
Info
1 playable playlist(s) of type "default_scheduled" found.
playlists
[
{
"id": 42,
"name": "Commercial Break",
"weight": 24
}
]
station
{
"id": 1,
"name": "Radio Onion Ring"
}
Info
Playable track found and registered.
next_song
"StationMedia 2e0335c08f5cd2ef89a3bdf7: KSCS - Clinton and Haisch on E"
station
{
"id": 1,
"name": "Radio Onion Ring"
}

[cpeter1207]

The only playlist that is "playable" is the "commercial break" playlist. However, the schedule view on the profile page shows:

Scheduled
Playlist
Hitchhiker's Guide
7:00 PM - 7:30 PM
9 minutes ago
Playlist
Dirk Gently Earth Search and SpaceForce
7:30 PM - 8:00 PM
in 21 minutes
Playlist
Scifi OTR
8:00 PM - 8:30 PM
in an hour
Playlist
Alien Worlds
8:30 PM - 9:00 PM
in an hour
Playlist
Journey Into Space
9:00 PM - 9:30 PM
in 2 hours
Playlist
Star Wars
9:30 PM - 10:00 PM
in 2 hours

Why aren't these playlists playable? I think it's because "now" is still back at 6:28 PM.

The commercial playlist mainly consists of tracks less than a minute long. Is that somehow a factor?

[cpeter1207]

And at 7:24:08 PM CDT

Jul 4, 2020 6:26 PM
Newhart 1989 02
For Fcc Licensed Low Power F M Radio Use Only
Playlist: Commercial Break

Jul 4, 2020 6:27 PM
Americas least wanted
Playlist: Commercial Break

Jul 4, 2020 6:27 PM
Jimmy Swaggert 1988
For Fcc Licensed Low Power F M Radio Use Only
Playlist: Commercial Break

[cpeter1207]

After looking at the song history in the "rebuild queue" output, I believe that there is an issue with "jingle mode" playlists. Not only is their metadata hidden from listeners, it's also hidden from the song history. I think this causes the song history to be incomplete, leading to the "now" value being "off", leading to things being mis-scheduled.

Reproduction steps:

1. Create a jingle mode playlist and schedule it for 6:20 PM to 10:00 PM.
2. Schedule non-jingle-mode playlists for 6:30 PM - 7:00 PM, 7:00 PM - 7:30 PM, 8:00 PM - 8:00 PM...etc.
3. Note that the jingle-mode playlist starts at around 6:20 PM.
4. Note that the 6:30 PM playlist never plays.
   A. Also note that the "queued on" times in the up-coming song queue seem to stay about the same, even though jingle-mode tracks leave and enter the queue.
   B. This becomes very obvious after an hour.
5. At some time later, disable "jingle mode" on the jingle mode playlist.
6. Note that things play as originally expected.

I disabled jingle mode on the "commercial break" playlist after it played for nearly an hour. When I did that, the "queued on" timestamps in the up-coming song queue view suddenly became sane again and my playlists appear to be running normally, though somewhat late...

[cpeter1207]

I believe my jingle mode issue is valid. After disabling jingle mode last night, my scheduled blocks played in the order I expected. The times were off, but that was understandable given the situation...

I still believe there is an issue, though, with scheduled events playing later than they should. I think that is independent of the jingle mode issue. Here is an example of an up-coming song queue, where a bottom of hour jingle was scheduled for 9:34 AM when it could've been scheduled for 9:32 AM.

Jul 5, 2020 9:32 AM
Sponges
The Arrogant Worms
Playlist: Comedy

Jul 5, 2020 9:34 AM
Radio Onionring 19
Playlist: Bottom Of Hour ID

Jul 5, 2020 9:34 AM
Fun Winter
ze frank
Playlist: Comedy

I believe "Radio Onionring 19" should've been queued before "Sponges".

I've been spending a lot of time reading through the code, and I'm beginning to understand it more, but I don't have a full development environment set up to test changes at this point, and I'm not yet sure I'm comfortable enough with PHP syntax. I have vacation days tomorrow and Tuesday, though. I hope to finish setting up my development environment so I can test minor changes such as adding logging in parts I don't understand. I hope that'll help me investigate this issue.

@SlvrEagle23 I've seen commits from you over the last few days, so I believe you're actively working on Azuracast right now. COuld you comment on what I've reported so far? Has that been helpful?

[cpeter1207]

I don't have a development environment set up yet, but I changed the environment setting in azuracast.env to development so I could get debug level logging.

Here is an example where I think a once-per-hour (at 0 minutes) playlist should've played, along with some Azuracast logging showing why it didn't.

Jul 6, 2020 8:55 AM
Ah, Leia
Playlist: Comedy

Jul 6, 2020 8:56 AM
I Don't Know Anybody Else
Black Box
Playlist: Mainstream high

Jul 6, 2020 9:01 AM
Dig
A Halo Called Fred
Playlist: Comedy

[2020-07-06T13:51:17.466063+00:00] AzuraCast.DEBUG: Adding to station queue. {"now":"2020-07-06 08:57:47"} {"station":{"id":1,"name":"Radio Onion Ring"}}
[2020-07-06T13:51:17.468086+00:00] AzuraCast.INFO: AzuraCast AutoDJ is calculating the next song to play... [] {"station":{"id":1,"name":"Radio Onion Ring"}}
[2020-07-06T13:51:17.497632+00:00] AzuraCast.DEBUG: AutoDJ recent song playback history {"history":[{"song":"Black Box - I Don't Know Anybody Else","cued_at":"2020-07-06 08:53:37","duration":250,"sent_to_autodj":false},{"song":"Ah, Leia","cued_at":"2020-07-06 08:51:58","duration":99,"sent_to_autodj":false},{"song":"Paul McCartney - Hope Of Deliverance","cued_at":"2020-07-06 08:51:58","duration":202,"sent_to_autodj":true},{"song":"Soul Central Feat. Kathy Brown - Strings Of Life (Stronger On My Own)","cued_at":"2020-07-06 08:48:25","duration":215,"sent_to_autodj":true},{"song":"Embrace - All You Good Good People","cued_at":"2020-07-06 08:41:59","duration":376,"sent_to_autodj":true},{"song":"Radio Onionring 20","cued_at":"2020-07-06 08:41:59","duration":15,"sent_to_autodj":true},{"song":"Bananas at Large - [Untitled Track]","cued_at":"2020-07-06 08:40:41","duration":80,"sent_to_autodj":true},{"song":"Carla Ulbrich - What If Your Butt Was Gone","cued_at":"2020-07-06 08:38:22","duration":141,"sent_to_autodj":true},{"song":"Weezer - Blowin' My Stack (Album Version)","cued_at":"2020-07-06 08:34:38","duration":224,"sent_to_autodj":true},{"song":"The Vestibules - Shakespeare","cued_at":"2020-07-06 08:30:49","duration":23,"sent_to_autodj":true},{"song":"Ilene Woods - A Dream Is A Wish Your Heart Makes","cued_at":"2020-07-06 08:26:45","duration":226,"sent_to_autodj":true},{"song":"Zero 7 - Destiny","cued_at":"2020-07-06 08:23:21","duration":227,"sent_to_autodj":true},{"song":"The Vestibules - Shakespeare","cued_at":"2020-07-06 08:22:58","duration":23,"sent_to_autodj":true},{"song":"Monty Python - Always Look On The Bright Side Of Life","cued_at":"2020-07-06 08:19:54","duration":223,"sent_to_autodj":true},{"song":"Big Daddy - Every Breath You Take","cued_at":"2020-07-06 08:19:54","duration":187,"sent_to_autodj":true}]} {"station":{"id":1,"name":"Radio Onion Ring"}}
[2020-07-06T13:51:17.498221+00:00] AzuraCast.INFO: 8 playable playlist(s) of type "default_unscheduled" found. {"playlists":[{"id":25,"name":"Comedy","weight":7},{"id":23,"name":"Mainstream high","weight":5},{"id":26,"name":"Mainstream Medium","weight":3},{"id":28,"name":"Chris's Albums","weight":2},{"id":27,"name":"Mainstream Low","weight":1},{"id":29,"name":"Moog","weight":1},{"id":33,"name":"TV","weight":1},{"id":34,"name":"Kids","weight":1}]} {"station":{"id":1,"name":"Radio Onion Ring"}}
[2020-07-06T13:51:17.561970+00:00] AzuraCast.INFO: Found track that avoids duplicate title and artist. {"media_id":7058} {"station":{"id":1,"name":"Radio Onion Ring"}}
[2020-07-06T13:51:17.618304+00:00] AzuraCast.INFO: Playable track found and registered. {"next_song":"StationMedia bf27a17e22a66ea54118f95c: A Halo Called Fred - Dig"} {"station":{"id":1,"name":"Radio Onion Ring"}}

Based on the above, the "now" value was before 09:00 AM, so the "top of hour" playlist wasn't playable when "Dig" was added to the queue.

I also notice that "Ah, Leia" and "Hope Of Deliverance" have the same queued_at time (08:51:58), which caused "now" to be calculated incorrectly.

Based on the 202 second duration of "Hope Of Deliverance", "Ah, Leia" should've had a queued_at time of 08:55:20, and "I Don't Know Anybody Else" should've had a queued_on time of 08:56:39.

Since "I Don't Know Anybody Else" had a 250 second duration, I think the "top of hour" playlist should've been queued at 08:01:49.

Based on the log, I think this chunk of code calculated "now". Comments/questions below prefixed by [CP]:

    $currentSong = $this->songHistoryRepo->getCurrent($station);

    if ($currentSong instanceof Entity\SongHistory) {
        $nowTimestamp = $currentSong->getTimestampStart() + ($currentSong->getDuration() ?? 1);

        $now = Chronos::createFromTimestamp($nowTimestamp, $stationTz);
    } else {

        $now = Chronos::now($stationTz);
    }

    // Adjust "now" time from current queue.
    $backendOptions = $station->getBackendConfig();
    $maxQueueLength = $backendOptions->getAutoDjQueueLength();

    $upcomingQueue = $this->songHistoryRepo->getUpcomingQueue($station);

    $queueLength = count($upcomingQueue);

    foreach ($upcomingQueue as $queueRow) {
        $queueRow->setTimestampCued($now->getTimestamp());
        $this->em->persist($queueRow);

        $duration = $queueRow->getDuration() ?? 1;
        $now = $now->addSeconds($duration);
    }

    $this->em->flush();

    if ($queueLength >= $maxQueueLength) {

        $this->logger->debug('AutoDJ queue is already at current max length (' . $maxQueueLength . ').');
        $this->logger->popProcessor();
        return;
    }

    // Build the remainder of the queue.
    while ($queueLength < $maxQueueLength) {

        $this->logger->debug('Adding to station queue.', [
            'now' => (string)$now,
        ]);

        $event = new BuildQueue($station, $now);
        $this->dispatcher->dispatch($event);

        $queueRow = $event->getNextSong();
        if ($queueRow instanceof Entity\SongHistory) {
            $duration = $queueRow->getDuration() ?? 1;

            $now = $now->addSeconds($duration);
        }

        $queueLength++;
    }

[cpeter1207]

I see a pattern where two consecutive songs in the recent song history end up having the same queued_at time. Here are some examples:

[2020-07-06T17:08:47.570324+00:00] AzuraCast.DEBUG: Adding to station queue. {"now":"2020-07-06 12:14:00"} {"station":{"id":1,"name":"Radio Onion Ring"}}
[2020-07-06T17:08:47.571868+00:00] AzuraCast.INFO: AzuraCast AutoDJ is calculating the next song to play... [] {"station":{"id":1,"name":"Radio Onion Ring"}}
[2020-07-06T17:08:47.605802+00:00] AzuraCast.DEBUG: AutoDJ recent song playback history {"history":[{"song":"the great Luke Ski - Jon Archer","cued_at":"2020-07-06 12:10:41","duration":199,"sent_to_autodj":false},{"song":"Dr. Demento - Demento Segment XV","cued_at":"2020-07-06 12:09:26","duration":75,"sent_to_autodj":false},{"song":"Jean-Jacques Perrey, O.C Banks, Gilbert Sigrist - Little Italy","cued_at":"2020-07-06 12:08:42","duration":128,"sent_to_autodj":true},{"song":"J. Fielding - Hogan's Heroes","cued_at":"2020-07-06 12:08:42","duration":46,"sent_to_autodj":true},{"song":"Bruce Healey - Fantasmic!","cued_at":"2020-07-06 12:05:31","duration":180,"sent_to_autodj":true},{"song":"Radio Onionring 2","cued_at":"2020-07-06 12:05:31","duration":13,"sent_to_autodj":true},{"song":"Tom Smith - Temperature of Revenge (Kahn!)","cued_at":"2020-07-06 12:02:43","duration":169,"sent_to_autodj":true},{"song":"Irene Cara - What A Feeling","cued_at":"2020-07-06 11:58:55","duration":231,"sent_to_autodj":true},{"song":"Gershon Kingsley & Maureen Forrester - Swing A La Turca","cued_at":"2020-07-06 11:55:59","duration":178,"sent_to_autodj":true},{"song":"It Bites - Calling All The Heroes","cued_at":"2020-07-06 11:51:57","duration":245,"sent_to_autodj":true},{"song":"Ilene Woods - A Dream Is A Wish Your Heart Makes","cued_at":"2020-07-06 11:48:13","duration":226,"sent_to_autodj":true},{"song":"Gershon Kingsley & Leonid Hambro - Summertime","cued_at":"2020-07-06 11:45:29","duration":165,"sent_to_autodj":true},{"song":"0320 warriors-for-hire-parody-of-we-didnt-start-the - fire","cued_at":"2020-07-06 11:42:29","duration":181,"sent_to_autodj":true},{"song":"Tim Cavanagh - Smokin' in my Mom's Womb","cued_at":"2020-07-06 11:42:25","duration":131,"sent_to_autodj":true},{"song":"Tim Cavanagh - Smokin' in my Mom's Womb","cued_at":"2020-07-06 11:40:27","duration":131,"sent_to_autodj":true}]} {"station":{"id":1,"name":"Radio Onion Ring"}}
[2020-07-06T17:08:47.606396+00:00] AzuraCast.INFO: 8 playable playlist(s) of type "default_unscheduled" found. {"playlists":[{"id":25,"name":"Comedy","weight":7},{"id":23,"name":"Mainstream high","weight":5},{"id":26,"name":"Mainstream Medium","weight":3},{"id":28,"name":"Chris's Albums","weight":2},{"id":27,"name":"Mainstream Low","weight":1},{"id":29,"name":"Moog","weight":1},{"id":33,"name":"TV","weight":1},{"id":34,"name":"Kids","weight":1}]} {"station":{"id":1,"name":"Radio Onion Ring"}}
[2020-07-06T17:08:47.609568+00:00] AzuraCast.INFO: Found track that avoids duplicate title and artist. {"media_id":11666} {"station":{"id":1,"name":"Radio Onion Ring"}}
[2020-07-06T17:08:47.618232+00:00] AzuraCast.INFO: Playable track found and registered. {"next_song":"StationMedia 3e2790b92774e157812b8d2b: David Tomlinson & Angela Lansbury - Portobello Road"} {"station":{"id":1,"name":"Radio Onion Ring"}}
[2020-07-06T17:08:47.621934+00:00] AzuraCast.DEBUG: Timer "BuildQueue" completed in 0.137 second(s). [] []

Duplicate queued_at songs are: {"song":"Jean-Jacques Perrey, O.C Banks, Gilbert Sigrist - Little Italy","cued_at":"2020-07-06 12:08:42","duration":128,"sent_to_autodj":true},{"song":"J. Fielding - Hogan's Heroes","cued_at":"2020-07-06 12:08:42","duration":46,"sent_to_autodj":true}

[2020-07-06T17:11:02.745209+00:00] AzuraCast.DEBUG: Adding to station queue. {"now":"2020-07-06 12:18:17"} {"station":{"id":1,"name":"Radio Onion Ring"}}
[2020-07-06T17:11:02.746605+00:00] AzuraCast.INFO: AzuraCast AutoDJ is calculating the next song to play... [] {"station":{"id":1,"name":"Radio Onion Ring"}}
[2020-07-06T17:11:02.767058+00:00] AzuraCast.DEBUG: AutoDJ recent song playback history {"history":[{"song":"David Tomlinson & Angela Lansbury - Portobello Road","cued_at":"2020-07-06 12:14:50","duration":207,"sent_to_autodj":false},{"song":"the great Luke Ski - Jon Archer","cued_at":"2020-07-06 12:11:31","duration":199,"sent_to_autodj":false},{"song":"Dr. Demento - Demento Segment XV","cued_at":"2020-07-06 12:11:31","duration":75,"sent_to_autodj":true},{"song":"Jean-Jacques Perrey, O.C Banks, Gilbert Sigrist - Little Italy","cued_at":"2020-07-06 12:08:42","duration":128,"sent_to_autodj":true},{"song":"J. Fielding - Hogan's Heroes","cued_at":"2020-07-06 12:08:42","duration":46,"sent_to_autodj":true},{"song":"Bruce Healey - Fantasmic!","cued_at":"2020-07-06 12:05:31","duration":180,"sent_to_autodj":true},{"song":"Radio Onionring 2","cued_at":"2020-07-06 12:05:31","duration":13,"sent_to_autodj":true},{"song":"Tom Smith - Temperature of Revenge (Kahn!)","cued_at":"2020-07-06 12:02:43","duration":169,"sent_to_autodj":true},{"song":"Irene Cara - What A Feeling","cued_at":"2020-07-06 11:58:55","duration":231,"sent_to_autodj":true},{"song":"Gershon Kingsley & Maureen Forrester - Swing A La Turca","cued_at":"2020-07-06 11:55:59","duration":178,"sent_to_autodj":true},{"song":"It Bites - Calling All The Heroes","cued_at":"2020-07-06 11:51:57","duration":245,"sent_to_autodj":true},{"song":"Ilene Woods - A Dream Is A Wish Your Heart Makes","cued_at":"2020-07-06 11:48:13","duration":226,"sent_to_autodj":true},{"song":"Gershon Kingsley & Leonid Hambro - Summertime","cued_at":"2020-07-06 11:45:29","duration":165,"sent_to_autodj":true},{"song":"0320 warriors-for-hire-parody-of-we-didnt-start-the - fire","cued_at":"2020-07-06 11:42:29","duration":181,"sent_to_autodj":true},{"song":"Tim Cavanagh - Smokin' in my Mom's Womb","cued_at":"2020-07-06 11:42:25","duration":131,"sent_to_autodj":true}]} {"station":{"id":1,"name":"Radio Onion Ring"}}
[2020-07-06T17:11:02.767802+00:00] AzuraCast.INFO: 8 playable playlist(s) of type "default_unscheduled" found. {"playlists":[{"id":25,"name":"Comedy","weight":7},{"id":23,"name":"Mainstream high","weight":5},{"id":26,"name":"Mainstream Medium","weight":3},{"id":28,"name":"Chris's Albums","weight":2},{"id":27,"name":"Mainstream Low","weight":1},{"id":29,"name":"Moog","weight":1},{"id":33,"name":"TV","weight":1},{"id":34,"name":"Kids","weight":1}]} {"station":{"id":1,"name":"Radio Onion Ring"}}
[2020-07-06T17:11:02.771682+00:00] AzuraCast.INFO: Found track that avoids duplicate title and artist. {"media_id":2241} {"station":{"id":1,"name":"Radio Onion Ring"}}
[2020-07-06T17:11:02.784144+00:00] AzuraCast.INFO: Playable track found and registered. {"next_song":"StationMedia f18ff01a2b4da38edf663d4c: Gil Trythall - Folsom Prison Blues"} {"station":{"id":1,"name":"Radio Onion Ring"}}
[2020-07-06T17:11:02.784687+00:00] AzuraCast.DEBUG: Timer "BuildQueue" completed in 0.186 second(s). [] []

Duplicate queued_at songs are: {"song":"the great Luke Ski - Jon Archer","cued_at":"2020-07-06 12:11:31","duration":199,"sent_to_autodj":false},{"song":"Dr. Demento - Demento Segment XV","cued_at":"2020-07-06 12:11:31","duration":75,"sent_to_autodj":true}

[2020-07-06T17:12:02.535807+00:00] AzuraCast.DEBUG: Adding to station queue. {"now":"2020-07-06 12:19:20"} {"station":{"id":1,"name":"Radio Onion Ring"}}
[2020-07-06T17:12:02.537236+00:00] AzuraCast.INFO: AzuraCast AutoDJ is calculating the next song to play... [] {"station":{"id":1,"name":"Radio Onion Ring"}}
[2020-07-06T17:12:02.561691+00:00] AzuraCast.DEBUG: AutoDJ recent song playback history {"history":[{"song":"Gil Trythall - Folsom Prison Blues","cued_at":"2020-07-06 12:16:11","duration":189,"sent_to_autodj":false},{"song":"David Tomlinson & Angela Lansbury - Portobello Road","cued_at":"2020-07-06 12:12:44","duration":207,"sent_to_autodj":false},{"song":"the great Luke Ski - Jon Archer","cued_at":"2020-07-06 12:12:44","duration":199,"sent_to_autodj":true},{"song":"Dr. Demento - Demento Segment XV","cued_at":"2020-07-06 12:11:31","duration":75,"sent_to_autodj":true},{"song":"Jean-Jacques Perrey, O.C Banks, Gilbert Sigrist - Little Italy","cued_at":"2020-07-06 12:08:42","duration":128,"sent_to_autodj":true},{"song":"J. Fielding - Hogan's Heroes","cued_at":"2020-07-06 12:08:42","duration":46,"sent_to_autodj":true},{"song":"Bruce Healey - Fantasmic!","cued_at":"2020-07-06 12:05:31","duration":180,"sent_to_autodj":true},{"song":"Radio Onionring 2","cued_at":"2020-07-06 12:05:31","duration":13,"sent_to_autodj":true},{"song":"Tom Smith - Temperature of Revenge (Kahn!)","cued_at":"2020-07-06 12:02:43","duration":169,"sent_to_autodj":true},{"song":"Irene Cara - What A Feeling","cued_at":"2020-07-06 11:58:55","duration":231,"sent_to_autodj":true},{"song":"Gershon Kingsley & Maureen Forrester - Swing A La Turca","cued_at":"2020-07-06 11:55:59","duration":178,"sent_to_autodj":true},{"song":"It Bites - Calling All The Heroes","cued_at":"2020-07-06 11:51:57","duration":245,"sent_to_autodj":true},{"song":"Ilene Woods - A Dream Is A Wish Your Heart Makes","cued_at":"2020-07-06 11:48:13","duration":226,"sent_to_autodj":true},{"song":"Gershon Kingsley & Leonid Hambro - Summertime","cued_at":"2020-07-06 11:45:29","duration":165,"sent_to_autodj":true},{"song":"0320 warriors-for-hire-parody-of-we-didnt-start-the - fire","cued_at":"2020-07-06 11:42:29","duration":181,"sent_to_autodj":true}]} {"station":{"id":1,"name":"Radio Onion Ring"}}
[2020-07-06T17:12:02.562246+00:00] AzuraCast.INFO: 8 playable playlist(s) of type "default_unscheduled" found. {"playlists":[{"id":25,"name":"Comedy","weight":7},{"id":23,"name":"Mainstream high","weight":5},{"id":26,"name":"Mainstream Medium","weight":3},{"id":28,"name":"Chris's Albums","weight":2},{"id":27,"name":"Mainstream Low","weight":1},{"id":29,"name":"Moog","weight":1},{"id":33,"name":"TV","weight":1},{"id":34,"name":"Kids","weight":1}]} {"station":{"id":1,"name":"Radio Onion Ring"}}
[2020-07-06T17:12:02.588920+00:00] AzuraCast.INFO: Found track that avoids duplicate title and artist. {"media_id":12441} {"station":{"id":1,"name":"Radio Onion Ring"}}
[2020-07-06T17:12:02.610628+00:00] AzuraCast.INFO: Playable track found and registered. {"next_song":"StationMedia 7a571b1a7736697d1f323d98: The Beautiful South - Bell Bottomed Tear"} {"station":{"id":1,"name":"Radio Onion Ring"}}
[2020-07-06T17:12:02.611211+00:00] AzuraCast.DEBUG: Timer "BuildQueue" completed in 0.21 second(s). [] []

Duplicate queued_at songs are: {"song":"David Tomlinson & Angela Lansbury - Portobello Road","cued_at":"2020-07-06 12:12:44","duration":207,"sent_to_autodj":false},{"song":"the great Luke Ski - Jon Archer","cued_at":"2020-07-06 12:12:44","duration":199,"sent_to_autodj":true}

[2020-07-06T17:15:32.329717+00:00] AzuraCast.DEBUG: Adding to station queue. {"now":"2020-07-06 12:23:47"} {"station":{"id":1,"name":"Radio Onion Ring"}}
[2020-07-06T17:15:32.331364+00:00] AzuraCast.INFO: AzuraCast AutoDJ is calculating the next song to play... [] {"station":{"id":1,"name":"Radio Onion Ring"}}
[2020-07-06T17:15:32.357933+00:00] AzuraCast.DEBUG: AutoDJ recent song playback history {"history":[{"song":"The Beautiful South - Bell Bottomed Tear","cued_at":"2020-07-06 12:19:12","duration":275,"sent_to_autodj":false},{"song":"Gil Trythall - Folsom Prison Blues","cued_at":"2020-07-06 12:16:03","duration":189,"sent_to_autodj":false},{"song":"David Tomlinson & Angela Lansbury - Portobello Road","cued_at":"2020-07-06 12:16:03","duration":207,"sent_to_autodj":true},{"song":"the great Luke Ski - Jon Archer","cued_at":"2020-07-06 12:12:44","duration":199,"sent_to_autodj":true},{"song":"Dr. Demento - Demento Segment XV","cued_at":"2020-07-06 12:12:40","duration":75,"sent_to_autodj":true},{"song":"Dr. Demento - Demento Segment XV","cued_at":"2020-07-06 12:11:31","duration":75,"sent_to_autodj":true},{"song":"Jean-Jacques Perrey, O.C Banks, Gilbert Sigrist - Little Italy","cued_at":"2020-07-06 12:08:42","duration":128,"sent_to_autodj":true},{"song":"J. Fielding - Hogan's Heroes","cued_at":"2020-07-06 12:08:42","duration":46,"sent_to_autodj":true},{"song":"Bruce Healey - Fantasmic!","cued_at":"2020-07-06 12:05:31","duration":180,"sent_to_autodj":true},{"song":"Radio Onionring 2","cued_at":"2020-07-06 12:05:31","duration":13,"sent_to_autodj":true},{"song":"Tom Smith - Temperature of Revenge (Kahn!)","cued_at":"2020-07-06 12:02:43","duration":169,"sent_to_autodj":true},{"song":"Irene Cara - What A Feeling","cued_at":"2020-07-06 11:58:55","duration":231,"sent_to_autodj":true},{"song":"Gershon Kingsley & Maureen Forrester - Swing A La Turca","cued_at":"2020-07-06 11:55:59","duration":178,"sent_to_autodj":true},{"song":"It Bites - Calling All The Heroes","cued_at":"2020-07-06 11:51:57","duration":245,"sent_to_autodj":true},{"song":"Ilene Woods - A Dream Is A Wish Your Heart Makes","cued_at":"2020-07-06 11:48:13","duration":226,"sent_to_autodj":true}]} {"station":{"id":1,"name":"Radio Onion Ring"}}
[2020-07-06T17:15:32.358429+00:00] AzuraCast.INFO: 8 playable playlist(s) of type "default_unscheduled" found. {"playlists":[{"id":25,"name":"Comedy","weight":7},{"id":23,"name":"Mainstream high","weight":5},{"id":26,"name":"Mainstream Medium","weight":3},{"id":28,"name":"Chris's Albums","weight":2},{"id":27,"name":"Mainstream Low","weight":1},{"id":29,"name":"Moog","weight":1},{"id":33,"name":"TV","weight":1},{"id":34,"name":"Kids","weight":1}]} {"station":{"id":1,"name":"Radio Onion Ring"}}
[2020-07-06T17:15:32.413930+00:00] AzuraCast.INFO: Found track that avoids duplicate title and artist. {"media_id":10383} {"station":{"id":1,"name":"Radio Onion Ring"}}
[2020-07-06T17:15:32.462621+00:00] AzuraCast.INFO: Playable track found and registered. {"next_song":"StationMedia f9f4940adbcb45d523f51b96: Throwing Toasters - Story Behind Chang"} {"station":{"id":1,"name":"Radio Onion Ring"}}
[2020-07-06T17:15:32.463174+00:00] AzuraCast.DEBUG: Timer "BuildQueue" completed in 0.199 second(s). [] []

Duplicate queued_at songs are: {"song":"Gil Trythall - Folsom Prison Blues","cued_at":"2020-07-06 12:16:03","duration":189,"sent_to_autodj":false},{"song":"David Tomlinson & Angela Lansbury - Portobello Road","cued_at":"2020-07-06 12:16:03","duration":207,"sent_to_autodj":true}

When this happens, $now is calculated incorrectly because it's not taking into account the duration of one of the songs in the recent history.

I strongly wonder if this occurs when a song is dequeued, but not started yet.

getCurrent queries for the currently playing song like this. Unless I miss something, sent_to_autodj is not taken into account at all. It's just assumed to be true.

public function getCurrent(Entity\Station $station): ?Entity\SongHistory
{
    return $this->em->createQuery(/** @lang DQL */ 'SELECT sh 
        FROM App\Entity\SongHistory sh
        WHERE sh.station = :station
        AND sh.timestamp_start != 0
        AND (sh.timestamp_end IS NULL OR sh.timestamp_end = 0)
        ORDER BY sh.timestamp_start DESC')
        ->setParameter('station', $station)
        ->setMaxResults(1)
        ->getOneOrNullResult();
}

But what if sent_to_autodj is true and timestamp_start is 0?

That song won't be returned by getCurrent, but it also won't be returned by getUpcomingQueue because it returns a list of songs where sent_to_autodj is false.

public function getUpcomingQueue(Entity\Station $station): array
{
return $this->getUpcomingBaseQuery($station)
->andWhere('sh.sent_to_autodj = 0')
->getQuery()
->execute();
}

I think getUpcomingBaseQuery, by itself, would return the correct results, but adding the additional andWhere('sh.sent_to_autodj = 0') clause prevents returning songs that have been dequeued, but not started. This keeps Azuracast from taking the durations of those songs into account when calculating $now. The queued_at time eventually gets updated when the song starts playing, but by then, the queuing decision has already been made for the next song and, because $now is potentially several minutes earlier than it should be, the list of eligable playlists is wrong.

protected function getUpcomingBaseQuery(Entity\Station $station): QueryBuilder
{
    return $this->em->createQueryBuilder()
        ->select('sh, sm, sp, s')
        ->from(Entity\SongHistory::class, 'sh')
        ->leftJoin('sh.media', 'sm')
        ->leftJoin('sh.song', 's')
        ->leftJoin('sh.playlist', 'sp')
        ->where('sh.station = :station')
        ->setParameter('station', $station)
        ->andWhere('sh.timestamp_cued != 0')
        ->andWhere('sh.timestamp_start = 0')
        ->orderBy('sh.timestamp_cued', 'ASC');
}

[cpeter1207]

@SlvrEagle23
I'm having trouble running docker-compose build to test what I hope will fix, or at least shed light on, the problem I'm seeing. I've tried to do this from both the stable and master branches. In both cases, the "stations" service fails to build because it can't checkout liquidsoap 1.4.3. Can you suggest a workaround for the build issue?

Also, do you want an untested patch that I hope will fix, or at least shed light on, the problem?

[cpeter1207]

@SlvrEagle23 After some changes you made recently (I just updated last night), I'm seeing some strange behavior.

When Azuracast seems to be working correctly, scheduled events may be more ontime than they used to be. However, I'm seeing long periods where the profile and upcoming song queue pages show something like this:

At 6:42:09 AM CDT

Now Playing
Stream Offline
Playing Next
The Box
Logan Whitehurst
Playlist: comedy

Upcoming song queue
Jul 10, 2020 1:01 AM
The Box
Logan Whitehurst
Playlist: comedy

Jul 10, 2020 1:03 AM
Dot Com 1999
Three Dead Trolls in a Baggie
Playlist: comedy

Jul 10, 2020 1:08 AM
Re: Vos Cerveaux
Jonathan Coulton
Playlist: comedy

Interestingly, liquidsoap is still playing songs, and the upcoming song queue is still being updated, but the times are way off.

I haven't figured out what triggers this, but I've seen this on two separate instances that I updated to the most recent commit yesterday. It eventually resolves itself, but then seems to start acting this way again later.

[cpeter1207]

app.log
liquidsoap.log

@SlvrEagle23 I'm attaching logs from an instance where the behavior I mentioned in my previous comment is occurring right now.

[cpeter1207]

spoke too soon about the scheduling behaving better. I'm still seeing the symptom I reported a few days ago. I have a development environment up and running now so I'm trying to debug it. I'm learning about PHP at the same time, though, so it's slow going...

[AmsterdamFM]

We still have this software in test as scheduling is still very unreliable. It now only plays the hourly news twice a day: around 23:00 and around 16:00

The half an hour headlines are not played but mentioned in the log file once a day:
2020/08/13 15:06:36 [decoder:3] Method "WAV" accepted "/var/azuracast/stations/amsterdamfm/media/news/headlines.wav"

I fear that scheduling can be very complex. So maybe a solution is the use of an external library ? I found this one but have no idea if this is usable in this project as I am not a programmer:

https://github.com/lavary/crunz

[SlvrEagle23]

@AmsterdamFM Unfortunately there aren't a lot of libraries that manage overlapping schedule items like we have. That library you mentioned is really for managing cron jobs, which is indeed useful for apps like ours but for different reasons.

Our scheduling tools aren't all that complex, but apparently there are issues with the scheduler anyway. If nobody else comes up with a pull request in the near future I'll probably just take another stab at refactoring it from the ground up (again).

[cpeter1207]

My main complaint was that scheduled items were occasionally being played way too late. I’ve been testing a fix for this with very good results for the past several weeks. I plan to submit a pull request containing this fix soon.

I have no idea whether it’ll fix anyone else’s issues, but it it’s been working flawlessly in my setup.

[president-2020]

My main complaint was that scheduled items were occasionally being played way too late. I’ve been testing a fix for this with very good results for the past several weeks. I plan to submit a pull request containing this fix soon. I have no idea whether it’ll fix anyone else’s issues, but it it’s been working flawlessly in my setup.

@cpeter1207: What is the fix you are using. My scheduled items do not play until way after their appointed time.

[SlvrEagle23]

Update for all interested users

I have yet again worked on revamping the AzuraCast AutoDJ scheduler and implemented some much-needed changes to both how the database structure works and how queues are delivered to the Liquidsoap AutoDJ.

If you are experiencing issues with the scheduler, please update to the latest rolling release version (the commit date in the footer should be on or after today's date, 2020-08-16) and let us know if things are improved for your installation.

After some stability testing, we will roll these same fixes out as a stable tagged version for users who are on the stable release branch.

[pixel-paul]

I've just updated to the latest release and I can report the following:

1. The 'Rebuild AutoDJ Queue' is not functioning
   [Semantical Error] line 0, col 97 near 'timestamp_cued': Error: Class App\Entity\SongHistory has no field or association named timestamp_cued QueryException.php : 65

2. When I created a new playlist, I can see it being displayed in the 'Scheduled' section (it appears twice for some reason), however when I look at the upcoming song queue, the scheduled tracks are not present.

[cpeter1207]

I upgraded this morning. It’s possible that scheduled events are occurring on time, but I want to continue monitoring before I declare that fixed.

I do, however, have several once-per-day playlists (playlists where the start time and end time are the same). Several times today, I’ve heard one loop for 15 minutes until the next scheduled event rather than playing once and falling back to general rotation playlists as they should.

[nicolas5296]

Hey. Fixed not my problem with the planning of songs in the waiting list.

Screenshot: https://prnt.sc/u1iow5

[SlvrEagle23]

@pixel-paul This error should now be fixed; thank you for the report.

@nicolas5296 We will need to debug your specific situation, possibly in our Discord or Slack chats. It's possible you have other playlists that have "Interrupt other songs" enabled which is preventing the AutoDJ from even being asked what to play next. Logs (in particular, the Liquidsoap log) will play an important part in helping diagnose this issue.

[nicolas5296]

@SlvrEagle23 Where can i get the logs? I will post it for you.

[SlvrEagle23]

@nicolas5296 Utilities on the station sidebar menu, then Log Viewer, then click Liquidsoap Log.

[pixel-paul]

Thanks for resolving the System Debugger issue. I have now run a few more tests and it seems that scheduled playlists are not being added correctly. I have deleted all playlists on the server and started form scratch with the following:

1. Daytime playlist set to play all days of the week between 06:00 and 18:00 - weight 3
2. Tuesday playlist to start at 14:00 (so in this example in 4 minutes) and end at 15:00 - weight 25

I run the 'Rebuild AutoDJ Queue' and the Tuesday playlist set to play at 14:00 does not appear, just songs from the Daytime playlist.

The dashboard displays this:

Type| Name|Time
------------ | ------------- | -----------------
Playlist | Daytime Rotation | 6:00 AM - 8:00 PM 8 hours ago
Playlist | Tuesday | 2:00 PM - 3:00 PM in 4 minutes
Playlist | Daytime Rotation | Wed, Aug 19, 2020 6:00 AM - 8:00 PM in 16 hours

But the upcoming song queue displays:

Aug 18, 2020 3:42 PM | House Fire | Playlist: Daytime Rotation |  
-- | -- | -- | --

Aug 18, 2020 5:42 PM | House Fire | Playlist: Daytime Rotation
-- | -- | --

Aug 18, 2020 7:42 PM | House Fire | Playlist: Daytime Rotation |  
-- | -- | -- | --

I believe that the expected output is that the track from the Tuesday playlist would be the next track in the queue.

[SlvrEagle23]

@pixel-paul The system seems to think the next track will be playing at 3:42pm (based on the duration and start time of the current track being played), which would put it outside the 2pm-3pm range entirely.

[pixel-paul]

OK, that is interesting, so it is working as it should. My tracks are all radio shows of between 1 to 3 hours in length, so scheduling in this manner is complex as we use Auto DJ 00:00 - 18:00 and scheduling 18:00 - 00:00 - I end up with at least 28 playlists (Sunday week 1, Sunday week 2 etc) as well as a Daytime Rotation. I've come from Centovacast, where it was possible to schedule shows and they would have increased weighting over a rotation playlist, so in my example above, the next track would have been the scheduled track in the 'Tuesday' playlist (regardless of it falling outside the time period). This means that to get the show to start at 14:00, I would just click 'Skip Song' and the 'Tuesday' playlist would have started.

Thanks!

[nicolas5296]

@SlvrEagle23 Here you will find my log from the start after the update.

2020/08/18 11:55:44 >>> LOG START 2020/08/18 11:55:44 [main:3] Liquidsoap 1.4.2 2020/08/18 11:55:44 [main:3] Using: bytes=[distributed with OCaml 4.02 or above] pcre=7.4.3 sedlex=2.2 menhirLib=20200624 dtools=0.4.2 duppy=0.8.0 cry=0.6.1 mm=0.5.0 ogg=0.5.2 vorbis=0.7.1 opus=0.1.3 mad=0.4.5 flac=0.1.5 flac.ogg=0.1.5 dynlink=[distributed with Ocaml] lame=0.3.3 fdkaac=0.3.1 ffmpeg=0.4.1 samplerate=0.1.4 taglib=0.3.3 ssl=0.5.9 camomile=1.0.2 faad=0.4.0 2020/08/18 11:55:44 [frame:3] Using 44100Hz audio, 25Hz video, 44100Hz master. 2020/08/18 11:55:44 [frame:3] Frame size must be a multiple of 1764 ticks = 1764 audio samples = 1 video samples. 2020/08/18 11:55:44 [frame:3] Targetting 'frame.duration': 0.04s = 1764 audio samples = 1764 ticks. 2020/08/18 11:55:44 [frame:3] Frames last 0.04s = 1764 audio samples = 1 video samples = 1764 ticks. 2020/08/18 11:55:44 [decoder:3] Method "FFMPEG" accepted "/usr/local/share/icecast/web/error.mp3". 2020/08/18 11:55:44 [sandbox:3] Running inside a docker container, disabling sandboxing.. 2020/08/18 11:55:44 [video.converter:3] Couldn't find preferred video converter: gavl. 2020/08/18 11:55:44 [audio.converter:3] Using samplerate converter: ffmpeg. 2020/08/18 11:55:44 [harbor:3] Adding mountpoint '/' on port 8005 2020/08/18 11:55:44 [playlist_werbetrigger:3] Loading playlist... 2020/08/18 11:55:44 [playlist_werbetrigger:3] No mime type specified, trying autodetection. 2020/08/18 11:55:44 [playlist_werbetrigger:3] Playlist treated as format application/x-mpegURL 2020/08/18 11:55:44 [playlist_werbetrigger:3] Successfully loaded a playlist of 1 tracks. 2020/08/18 11:55:44 [playlist_jingles:3] Loading playlist... 2020/08/18 11:55:44 [playlist_jingles:3] No mime type specified, trying autodetection. 2020/08/18 11:55:44 [playlist_jingles:3] Playlist treated as format application/x-mpegURL 2020/08/18 11:55:44 [playlist_jingles:3] Successfully loaded a playlist of 18 tracks. 2020/08/18 11:55:44 [playlist_nachrichten:3] Loading playlist... 2020/08/18 11:55:44 [playlist_nachrichten:3] No mime type specified, trying autodetection. 2020/08/18 11:55:44 [playlist_nachrichten:3] Playlist treated as format application/x-mpegURL 2020/08/18 11:55:44 [playlist_nachrichten:3] Successfully loaded a playlist of 1 tracks. 2020/08/18 11:55:44 [playlist_pop:3] Loading playlist... 2020/08/18 11:55:44 [decoder:3] Method "FFMPEG" accepted "/var/azuracast/stations/beatam/media/news.mp3". 2020/08/18 11:55:44 [playlist_pop:3] No mime type specified, trying autodetection. 2020/08/18 11:55:44 [playlist_pop:3] Playlist treated as format application/x-mpegURL 2020/08/18 11:55:44 [playlist_pop:3] Successfully loaded a playlist of 131 tracks. 2020/08/18 11:55:44 [playlist_deutschrap:3] Loading playlist... 2020/08/18 11:55:44 [playlist_deutschrap:3] No mime type specified, trying autodetection. 2020/08/18 11:55:44 [playlist_deutschrap:3] Playlist treated as format application/x-mpegURL 2020/08/18 11:55:44 [playlist_deutschrap:3] Successfully loaded a playlist of 38 tracks. 2020/08/18 11:55:44 [error_jingle:3] "/usr/local/share/icecast/web/error.mp3" is static, resolving once for all... 2020/08/18 11:55:44 [error_jingle:3] Prepared "/usr/local/share/icecast/web/error.mp3" (RID 0). 2020/08/18 11:55:44 [beatam_relay_1:3] Connecting mount /beatam for [email protected]... 2020/08/18 11:55:44 [decoder:3] Method "FFMPEG" accepted "/var/azuracast/stations/beatam/media/Jingles/Hookpromo/Little Mix - Selena Gomez - Lil Mosey.mp3". 2020/08/18 11:55:44 [lang:3] AzuraCast Raw Response: 2020/08/18 11:55:44 [decoder:3] Method "FFMPEG" accepted "/var/azuracast/stations/beatam/media/Werbetrigger/start_ad_break.mp3". 2020/08/18 11:55:44 [beatam_relay_1:3] Connection setup was successful. 2020/08/18 11:55:44 [clock.wallclock_main:3] Streaming loop starts, synchronized with wallclock. 2020/08/18 11:55:44 [decoder:3] Method "FFMPEG" accepted "/var/azuracast/stations/beatam/media/Musik/40. Juice Wrld & Marshmello - Come & Go.mp3". 2020/08/18 11:55:44 [decoder:3] Method "FFMPEG" accepted "/var/azuracast/stations/beatam/media/Musik/32. Miksu Macloud - XXL (feat. Summer Cem, Luciano, Jamule).mp3". 2020/08/18 11:55:44 [decoder:3] Method "FFMPEG" accepted "/var/azuracast/stations/beatam/media/Werbetrigger/start_ad_break.mp3". 2020/08/18 11:55:44 [beatam_live_fallback:3] Switch to beatam_safe_fallback. 2020/08/18 11:55:44 [beatam_safe_fallback:3] Switch to error_jingle. 2020/08/18 11:55:44 [lang:3] AzuraCast Raw Response: 2020/08/18 11:55:44 [playlist_werbetrigger:3] Prepared "/var/azuracast/stations/beatam/media/Werbetrigger/start_ad_break.mp3" (RID 8). 2020/08/18 11:55:44 [beatam_safe_fallback:3] Switch to cross_7824 with transition. 2020/08/18 11:55:44 [decoder:3] Method "FFMPEG" accepted "/var/azuracast/stations/beatam/media/Werbetrigger/start_ad_break.mp3". 2020/08/18 11:55:44 [decoder:3] Method "FFMPEG" accepted "/var/azuracast/stations/beatam/media/Werbetrigger/start_ad_break.mp3". 2020/08/18 11:55:44 [decoder:3] Method "FFMPEG" accepted "/var/azuracast/stations/beatam/media/Werbetrigger/start_ad_break.mp3". 2020/08/18 11:55:44 [decoder:3] Method "FFMPEG" accepted "/var/azuracast/stations/beatam/media/Werbetrigger/start_ad_break.mp3". 2020/08/18 11:55:44 [decoder:3] Method "FFMPEG" accepted "/var/azuracast/stations/beatam/media/Werbetrigger/start_ad_break.mp3". 2020/08/18 11:55:44 [decoder:3] Method "FFMPEG" accepted "/var/azuracast/stations/beatam/media/Werbetrigger/start_ad_break.mp3". 2020/08/18 11:55:44 [decoder:3] Method "FFMPEG" accepted "/var/azuracast/stations/beatam/media/Werbetrigger/start_ad_break.mp3". 2020/08/18 11:55:44 [decoder:3] Method "FFMPEG" accepted "/var/azuracast/stations/beatam/media/Werbetrigger/start_ad_break.mp3". 2020/08/18 11:55:44 [decoder:3] Method "FFMPEG" accepted "/var/azuracast/stations/beatam/media/Werbetrigger/start_ad_break.mp3". 2020/08/18 11:55:44 [decoder:3] Method "FFMPEG" accepted "/var/azuracast/stations/beatam/media/Werbetrigger/start_ad_break.mp3". 2020/08/18 11:55:44 [decoder:3] Method "FFMPEG" accepted "/var/azuracast/stations/beatam/media/Werbetrigger/start_ad_break.mp3". 2020/08/18 11:55:44 [beatam_requests_fallback:3] Switch to beatam_autodj_fallback. 2020/08/18 11:55:44 [beatam_autodj_fallback:3] Switch to fallback_7797. 2020/08/18 11:55:44 [fallback_7797:3] Switch to delay_7796. 2020/08/18 11:55:44 [decoder:3] Method "FFMPEG" accepted "/var/azuracast/stations/beatam/media/Werbetrigger/start_ad_break.mp3". 2020/08/18 11:55:44 [playlist_deutschrap:3] Prepared "/var/azuracast/stations/beatam/media/Musik/32. Miksu Macloud - XXL (feat. Summer Cem, Luciano, Jamule).mp3" (RID 10). 2020/08/18 11:55:44 [decoder:3] Method "FFMPEG" accepted "/var/azuracast/stations/beatam/media/Werbetrigger/start_ad_break.mp3". 2020/08/18 11:55:44 [playlist_pop:3] Prepared "/var/azuracast/stations/beatam/media/Musik/40. Juice Wrld & Marshmello - Come & Go.mp3" (RID 9). 2020/08/18 11:55:44 [playlist_jingles:3] Prepared "/var/azuracast/stations/beatam/media/Jingles/Hookpromo/Little Mix - Selena Gomez - Lil Mosey.mp3" (RID 7). 2020/08/18 11:55:44 [fallback_7797:3] Switch to rotate_7794 with forgetful transition. 2020/08/18 11:55:44 [rotate_7794:3] Switch to sequence_7793. 2020/08/18 11:55:44 [decoder:3] Method "FFMPEG" accepted "/var/azuracast/stations/beatam/media/Jingles/Hookpromo/Jax Jones - Disciples - Shawn Mendes.mp3". 2020/08/18 11:55:44 [decoder:3] Method "FFMPEG" accepted "/var/azuracast/stations/beatam/media/Werbetrigger/start_ad_break.mp3". 2020/08/18 11:55:44 [cross_7824:3] Analysis: -95.143065dB / -11.242007dB (0.94s / 0.94s) 2020/08/18 11:55:44 [crossfade:3] No transition: using default. 2020/08/18 11:55:44 [decoder:3] Method "FFMPEG" accepted "/var/azuracast/stations/beatam/media/Werbetrigger/start_ad_break.mp3". 2020/08/18 11:55:44 [decoder:3] Method "FFMPEG" accepted "/var/azuracast/stations/beatam/media/Werbetrigger/start_ad_break.mp3". 2020/08/18 11:55:44 [decoder:3] Method "FFMPEG" accepted "/var/azuracast/stations/beatam/media/Werbetrigger/start_ad_break.mp3". 2020/08/18 11:55:44 [lang:3] AzuraCast Feedback Response: 2020/08/18 11:55:44 [decoder:3] Method "FFMPEG" accepted "/var/azuracast/stations/beatam/media/Werbetrigger/start_ad_break.mp3". 2020/08/18 11:55:44 [decoder:3] Method "FFMPEG" accepted "/var/azuracast/stations/beatam/media/Werbetrigger/start_ad_break.mp3". 2020/08/18 11:55:45 [clock.wallclock_main:2] We must catchup 1.09 seconds! 2020/08/18 11:55:46 [clock.wallclock_main:2] We must catchup 1.17 seconds! 2020/08/18 11:56:21 [playlist_nachrichten:3] Prepared "/var/azuracast/stations/beatam/media/news.mp3" (RID 5). 2020/08/18 11:56:21 [rotate_7794:3] Switch to beatam_schedule_switch with forgetful transition. 2020/08/18 11:56:21 [beatam_schedule_switch:3] Switch to map_metadata_7762. 2020/08/18 11:56:21 [decoder:3] Method "FFMPEG" accepted "/var/azuracast/stations/beatam/media/news.mp3". 2020/08/18 11:56:21 [cross_7824:3] Analysis: -9.967176dB / -13.058609dB (4.49s / 4.51s) 2020/08/18 11:56:21 [crossfade:3] No transition: using default. 2020/08/18 11:56:22 [lang:3] AzuraCast Raw Response: annotate:title="Sunshine Day",artist="Bodybangers",duration="187.",song_id="4ca100ead2b81bef7a0b55a516a1721e",media_id="191",liq_amplify="0.dB",playlist_id="4":/var/azuracast/stations/beatam/media/Musik/06. Bodybangers - Sunshine Day.mp3 2020/08/18 11:56:22 [decoder:3] Method "FFMPEG" accepted "/var/azuracast/stations/beatam/media/Musik/06. Bodybangers - Sunshine Day.mp3". 2020/08/18 11:59:07 [beatam_schedule_switch:3] Switch to beatam_standard_playlists with forgetful transition. 2020/08/18 11:59:07 [beatam_next_song:3] Prepared "/var/azuracast/stations/beatam/media/Musik/06. Bodybangers - Sunshine Day.mp3" (RID 33). 2020/08/18 11:59:07 [beatam_autodj_fallback:3] Switch to beatam_cue_next_song with forgetful transition. 2020/08/18 11:59:07 [cross_7824:3] Analysis: -44.092707dB / -20.484796dB (4.52s / 4.52s) 2020/08/18 11:59:07 [crossfade:3] new >= old + margin, old <= medium and new <= high. 2020/08/18 11:59:07 [crossfade:3] Do not fade if it's already very low. 2020/08/18 11:59:07 [crossfade:3] Transition: crossed, no fade. 2020/08/18 11:59:07 [lang:3] AzuraCast Feedback Response: OK 2020/08/18 12:01:30 [lang:3] AzuraCast Raw Response: annotate:duration="41.",song_id="6c9abd56d54e63b15b9b3a8965ad1992",liq_amplify="0.dB",jingle_mode="true":/var/azuracast/stations/beatam/media/Jingles/Hookpromo/Drake - Rita Ora - Harry Styles.mp3 2020/08/18 12:01:30 [decoder:3] Method "FFMPEG" accepted "/var/azuracast/stations/beatam/media/Jingles/Hookpromo/Drake - Rita Ora - Harry Styles.mp3". 2020/08/18 12:02:10 [beatam_next_song:3] Prepared "/var/azuracast/stations/beatam/media/Jingles/Hookpromo/Drake - Rita Ora - Harry Styles.mp3" (RID 34). 2020/08/18 12:02:10 [cross_7824:3] Analysis: -88.530192dB / -11.082151dB (4.49s / 4.51s) 2020/08/18 12:02:10 [crossfade:3] No transition: using default. 2020/08/18 12:02:10 [lang:3] AzuraCast Raw Response: annotate:title="Hello",artist="Royal XTC Feat. Molti",duration="219.",song_id="590586959fbeff7ac6d54cec6eb65e41",media_id="172",liq_amplify="0.dB",playlist_id="4":/var/azuracast/stations/beatam/media/Musik/14. Royal XTC Feat. Molti - Hello.mp3 2020/08/18 12:02:10 [decoder:3] Method "FFMPEG" accepted "/var/azuracast/stations/beatam/media/Musik/14. Royal XTC Feat. Molti - Hello.mp3". 2020/08/18 12:02:10 [lang:3] AzuraCast Feedback Response: OK 2020/08/18 12:02:14 [lang:3] AzuraCast Feedback Response: OK 2020/08/18 12:02:50 [beatam_next_song:3] Prepared "/var/azuracast/stations/beatam/media/Musik/14. Royal XTC Feat. Molti - Hello.mp3" (RID 35). 2020/08/18 12:02:50 [cross_7824:3] Analysis: -28.766624dB / -24.646536dB (4.46s / 4.46s) 2020/08/18 12:02:50 [crossfade:3] new >= old + margin, old >= medium and new <= high. 2020/08/18 12:02:50 [crossfade:3] New source is significantly louder than old one. 2020/08/18 12:02:50 [crossfade:3] Transition: crossed, fade-out. 2020/08/18 12:02:50 [lang:3] AzuraCast Feedback Response: OK 2020/08/18 12:05:45 [lang:3] AzuraCast Raw Response: annotate:title="Andere Welt",artist="Capital Bra x Clueso x KC Rebell",duration="190.",song_id="3f5bd905a44ba2ac102d61fcd9a9e0bb",media_id="6",liq_amplify="0.dB",playlist_id="3":/var/azuracast/stations/beatam/media/Musik/06. Capital Bra x Clueso x KC Rebell - Andere Welt.mp3 2020/08/18 12:05:45 [decoder:3] Method "FFMPEG" accepted "/var/azuracast/stations/beatam/media/Musik/06. Capital Bra x Clueso x KC Rebell - Andere Welt.mp3". 2020/08/18 12:06:24 [beatam_next_song:3] Prepared "/var/azuracast/stations/beatam/media/Musik/06. Capital Bra x Clueso x KC Rebell - Andere Welt.mp3" (RID 1). 2020/08/18 12:06:25 [cross_7824:3] Analysis: -61.896809dB / -36.770944dB (4.45s / 4.47s) 2020/08/18 12:06:25 [crossfade:3] new >= old + margin, old <= medium and new <= high. 2020/08/18 12:06:25 [crossfade:3] Do not fade if it's already very low. 2020/08/18 12:06:25 [crossfade:3] Transition: crossed, no fade. 2020/08/18 12:06:25 [lang:3] AzuraCast Feedback Response: OK 2020/08/18 12:08:50 [lang:3] AzuraCast Raw Response: annotate:title="The Riddle Anthem",artist="Jack Holiday & Mike Candys",duration="172.",song_id="08976cb160bb47f02f8daaf36799ddd2",media_id="152",liq_amplify="0.dB",playlist_id="4":/var/azuracast/stations/beatam/media/Musik/05. Jack Holiday & Mike Candys - The Riddle Anthem.mp3 2020/08/18 12:08:50 [decoder:3] Method "FFMPEG" accepted "/var/azuracast/stations/beatam/media/Musik/05. Jack Holiday & Mike Candys - The Riddle Anthem.mp3". 2020/08/18 12:09:30 [beatam_next_song:3] Prepared "/var/azuracast/stations/beatam/media/Musik/05. Jack Holiday & Mike Candys - The Riddle Anthem.mp3" (RID 2). 2020/08/18 12:09:30 [cross_7824:3] Analysis: -55.378356dB / -17.201237dB (4.45s / 4.47s) 2020/08/18 12:09:30 [crossfade:3] new >= old + margin, old <= medium and new <= high. 2020/08/18 12:09:30 [crossfade:3] Do not fade if it's already very low. 2020/08/18 12:09:30 [crossfade:3] Transition: crossed, no fade. 2020/08/18 12:09:30 [lang:3] AzuraCast Feedback Response: OK 2020/08/18 12:11:38 [lang:3] AzuraCast Raw Response: annotate:title="ROCKSTAR (feat. Roddy Ricch)",artist="DaBaby",duration="182.",song_id="1484fea4b0ad7621381a6f0be1acc807",media_id="12",liq_amplify="0.dB",playlist_id="4":/var/azuracast/stations/beatam/media/Musik/11. DaBaby - ROCKSTAR (feat. Roddy Ricch).mp3 2020/08/18 12:11:38 [decoder:3] Method "FFMPEG" accepted "/var/azuracast/stations/beatam/media/Musik/11. DaBaby - ROCKSTAR (feat. Roddy Ricch).mp3". 2020/08/18 12:12:17 [beatam_next_song:3] Prepared "/var/azuracast/stations/beatam/media/Musik/11. DaBaby - ROCKSTAR (feat. Roddy Ricch).mp3" (RID 3). 2020/08/18 12:12:18 [cross_7824:3] Analysis: -43.489708dB / -23.948423dB (4.49s / 4.51s) 2020/08/18 12:12:18 [crossfade:3] new >= old + margin, old <= medium and new <= high. 2020/08/18 12:12:18 [crossfade:3] Do not fade if it's already very low. 2020/08/18 12:12:18 [crossfade:3] Transition: crossed, no fade. 2020/08/18 12:12:18 [lang:3] AzuraCast Feedback Response: OK 2020/08/18 12:14:35 [lang:3] AzuraCast Raw Response: annotate:title="The Woo (feat. 50 Cent & Roddy Ricch)",artist="Pop Smoke",duration="202.",song_id="fc138dea7f7dd6764f6ca34e606c7519",media_id="100",liq_amplify="0.dB",playlist_id="4":/var/azuracast/stations/beatam/media/Musik/94. Pop Smoke - The Woo (feat. 50 Cent & Roddy Ricch).mp3 2020/08/18 12:14:35 [decoder:3] Method "FFMPEG" accepted "/var/azuracast/stations/beatam/media/Musik/94. Pop Smoke - The Woo (feat. 50 Cent & Roddy Ricch).mp3". 2020/08/18 12:15:15 [beatam_next_song:3] Prepared "/var/azuracast/stations/beatam/media/Musik/94. Pop Smoke - The Woo (feat. 50 Cent & Roddy Ricch).mp3" (RID 4). 2020/08/18 12:15:15 [cross_7824:3] Analysis: -40.726660dB / -28.550185dB (4.45s / 4.47s) 2020/08/18 12:15:15 [crossfade:3] new >= old + margin, old <= medium and new <= high. 2020/08/18 12:15:15 [crossfade:3] Do not fade if it's already very low. 2020/08/18 12:15:15 [crossfade:3] Transition: crossed, no fade. 2020/08/18 12:15:15 [lang:3] AzuraCast Feedback Response: OK 2020/08/18 12:17:52 [lang:3] AzuraCast Raw Response: annotate:title="Get Up",artist="Darius & Finlay & Nicco",duration="209.",song_id="b6e11f7fe44ecd441a91e941f33bcb9a",media_id="155",liq_amplify="0.dB",playlist_id="4":/var/azuracast/stations/beatam/media/Musik/07. Darius & Finlay & Nicco - Get Up.mp3 2020/08/18 12:17:52 [decoder:3] Method "FFMPEG" accepted "/var/azuracast/stations/beatam/media/Musik/07. Darius & Finlay & Nicco - Get Up.mp3". 2020/08/18 12:18:32 [beatam_next_song:3] Prepared "/var/azuracast/stations/beatam/media/Musik/07. Darius & Finlay & Nicco - Get Up.mp3" (RID 5). 2020/08/18 12:18:32 [cross_7824:3] Analysis: -26.110454dB / -20.459188dB (4.44s / 4.44s) 2020/08/18 12:18:32 [crossfade:3] new >= old + margin, old >= medium and new <= high. 2020/08/18 12:18:32 [crossfade:3] New source is significantly louder than old one. 2020/08/18 12:18:32 [crossfade:3] Transition: crossed, fade-out. 2020/08/18 12:18:32 [lang:3] AzuraCast Feedback Response: OK 2020/08/18 12:21:17 [lang:3] AzuraCast Raw Response: annotate:title="Emotions",artist="UFO361",duration="146.",song_id="ac0b830132ad8f5a9f0a7c504985daa8",media_id="31",liq_amplify="0.dB",playlist_id="3":/var/azuracast/stations/beatam/media/Musik/15. UFO361 - Emotions.mp3 2020/08/18 12:21:17 [decoder:3] Method "FFMPEG" accepted "/var/azuracast/stations/beatam/media/Musik/15. UFO361 - Emotions.mp3". 2020/08/18 12:21:57 [beatam_next_song:3] Prepared "/var/azuracast/stations/beatam/media/Musik/15. UFO361 - Emotions.mp3" (RID 1). 2020/08/18 12:21:57 [cross_7824:3] Analysis: -63.440732dB / -17.219304dB (4.44s / 4.44s) 2020/08/18 12:21:57 [crossfade:3] new >= old + margin, old <= medium and new <= high. 2020/08/18 12:21:57 [crossfade:3] Do not fade if it's already very low. 2020/08/18 12:21:57 [crossfade:3] Transition: crossed, no fade. 2020/08/18 12:21:57 [lang:3] AzuraCast Feedback Response: OK 2020/08/18 12:23:38 [lang:3] AzuraCast Raw Response: annotate:title="Brother Louie (feat. Leony)",artist="Vize x Imanbek x Dieter Bohlen",duration="172.",song_id="3b5e7e242224dfc73d56ef63904c348f",media_id="80",liq_amplify="0.dB",playlist_id="4":/var/azuracast/stations/beatam/media/Musik/85. Vize x Imanbek x Dieter Bohlen - Brother Louie (feat. Leony).mp3 2020/08/18 12:23:38 [decoder:3] Method "FFMPEG" accepted "/var/azuracast/stations/beatam/media/Musik/85. Vize x Imanbek x Dieter Bohlen - Brother Louie (feat. Leony).mp3". 2020/08/18 12:24:18 [beatam_next_song:3] Prepared "/var/azuracast/stations/beatam/media/Musik/85. Vize x Imanbek x Dieter Bohlen - Brother Louie (feat. Leony).mp3" (RID 2). 2020/08/18 12:24:18 [cross_7824:3] Analysis: -38.048731dB / -18.958364dB (4.51s / 4.53s) 2020/08/18 12:24:18 [crossfade:3] new >= old + margin, old <= medium and new <= high. 2020/08/18 12:24:18 [crossfade:3] Do not fade if it's already very low. 2020/08/18 12:24:18 [crossfade:3] Transition: crossed, no fade. 2020/08/18 12:24:18 [lang:3] AzuraCast Feedback Response: OK 2020/08/18 12:26:26 [lang:3] AzuraCast Raw Response: annotate:title="Dance The Pain Away",artist="Benny Benassi Feat. John Legend",duration="192.",song_id="5f67fdd70d45bd4ba254028e1e8d7bea",media_id="197",liq_amplify="0.dB",playlist_id="4":/var/azuracast/stations/beatam/media/Musik/13. Benny Benassi Feat. John Legend - Dance The Pain Away.mp3 2020/08/18 12:26:26 [decoder:3] Method "FFMPEG" accepted "/var/azuracast/stations/beatam/media/Musik/13. Benny Benassi Feat. John Legend - Dance The Pain Away.mp3". 2020/08/18 12:27:06 [beatam_next_song:3] Prepared "/var/azuracast/stations/beatam/media/Musik/13. Benny Benassi Feat. John Legend - Dance The Pain Away.mp3" (RID 3). 2020/08/18 12:27:06 [cross_7824:3] Analysis: -81.839889dB / -23.774525dB (4.46s / 4.46s) 2020/08/18 12:27:06 [crossfade:3] new >= old + margin, old <= medium and new <= high. 2020/08/18 12:27:06 [crossfade:3] Do not fade if it's already very low. 2020/08/18 12:27:06 [crossfade:3] Transition: crossed, no fade. 2020/08/18 12:27:06 [lang:3] AzuraCast Feedback Response: OK 2020/08/18 12:29:34 [lang:3] AzuraCast Raw Response: annotate:title="Thank You [Not So Bad]",artist="Vize & Felix Jaehn",duration="198.",song_id="1e40ec4b28030e5bfad020196966d615",media_id="84",liq_amplify="0.dB",playlist_id="4":/var/azuracast/stations/beatam/media/Musik/84. Vize & Felix Jaehn - Thank You [Not So Bad].mp3 2020/08/18 12:29:34 [decoder:3] Method "FFMPEG" accepted "/var/azuracast/stations/beatam/media/Musik/84. Vize & Felix Jaehn - Thank You [Not So Bad].mp3". 2020/08/18 12:30:14 [beatam_next_song:3] Prepared "/var/azuracast/stations/beatam/media/Musik/84. Vize & Felix Jaehn - Thank You [Not So Bad].mp3" (RID 4). 2020/08/18 12:30:14 [cross_7824:3] Analysis: -nandB / -12.918622dB (4.47s / 4.49s) 2020/08/18 12:30:14 [crossfade:3] No transition: using default. 2020/08/18 12:30:14 [lang:3] AzuraCast Feedback Response: OK 2020/08/18 12:30:18 [lang:3] AzuraCast Feedback Response: OK 2020/08/18 12:32:52 [lang:3] AzuraCast Raw Response: annotate:title="Sie ruft",artist="Apache 207",duration="152.",song_id="bf2786983e1663148a4bbc3b546c092a",media_id="2",liq_amplify="0.dB",playlist_id="3":/var/azuracast/stations/beatam/media/Musik/01. Apache 207 - Sie ruft.mp3 2020/08/18 12:32:52 [decoder:3] Method "FFMPEG" accepted "/var/azuracast/stations/beatam/media/Musik/01. Apache 207 - Sie ruft.mp3". 2020/08/18 12:33:32 [beatam_next_song:3] Prepared "/var/azuracast/stations/beatam/media/Musik/01. Apache 207 - Sie ruft.mp3" (RID 5). 2020/08/18 12:33:32 [cross_7824:3] Analysis: -67.351187dB / -21.977917dB (4.49s / 4.51s) 2020/08/18 12:33:32 [crossfade:3] new >= old + margin, old <= medium and new <= high. 2020/08/18 12:33:32 [crossfade:3] Do not fade if it's already very low. 2020/08/18 12:33:32 [crossfade:3] Transition: crossed, no fade. 2020/08/18 12:33:32 [lang:3] AzuraCast Feedback Response: OK 2020/08/18 12:35:19 [lang:3] AzuraCast Raw Response: annotate:title="Matrix",artist="Apache 207",duration="184.",song_id="f7df2572f2d9a002dbf2568f3d793d11",media_id="42",liq_amplify="0.dB",playlist_id="3":/var/azuracast/stations/beatam/media/Musik/37. Apache 207 - Matrix.mp3 2020/08/18 12:35:19 [decoder:3] Method "FFMPEG" accepted "/var/azuracast/stations/beatam/media/Musik/37. Apache 207 - Matrix.mp3". 2020/08/18 12:35:59 [beatam_next_song:3] Prepared "/var/azuracast/stations/beatam/media/Musik/37. Apache 207 - Matrix.mp3" (RID 1). 2020/08/18 12:35:59 [cross_7824:3] Analysis: -73.518063dB / -35.043211dB (4.49s / 4.51s) 2020/08/18 12:35:59 [crossfade:3] new >= old + margin, old <= medium and new <= high. 2020/08/18 12:35:59 [crossfade:3] Do not fade if it's already very low. 2020/08/18 12:35:59 [crossfade:3] Transition: crossed, no fade. 2020/08/18 12:35:59 [lang:3] AzuraCast Feedback Response: OK 2020/08/18 12:38:18 [lang:3] AzuraCast Raw Response: annotate:title="XXL (feat. Summer Cem, Luciano, Jamule)",artist="Miksu / Macloud",duration="166.",song_id="eec5c5550f95f6065a9be941f703ec86",media_id="39",liq_amplify="0.dB",playlist_id="3":/var/azuracast/stations/beatam/media/Musik/32. Miksu Macloud - XXL (feat. Summer Cem, Luciano, Jamule).mp3 2020/08/18 12:38:18 [decoder:3] Method "FFMPEG" accepted "/var/azuracast/stations/beatam/media/Musik/32. Miksu Macloud - XXL (feat. Summer Cem, Luciano, Jamule).mp3". 2020/08/18 12:38:58 [beatam_next_song:3] Prepared "/var/azuracast/stations/beatam/media/Musik/32. Miksu Macloud - XXL (feat. Summer Cem, Luciano, Jamule).mp3" (RID 2). 2020/08/18 12:38:58 [cross_7824:3] Analysis: -68.876884dB / -19.431739dB (4.51s / 4.53s) 2020/08/18 12:38:58 [crossfade:3] new >= old + margin, old <= medium and new <= high. 2020/08/18 12:38:58 [crossfade:3] Do not fade if it's already very low. 2020/08/18 12:38:58 [crossfade:3] Transition: crossed, no fade. 2020/08/18 12:38:58 [lang:3] AzuraCast Feedback Response: OK 2020/08/18 12:41:00 [lang:3] AzuraCast Raw Response: annotate:title="Signal",artist="badmómzjay",duration="131.",song_id="1b416141b34972b9b87a4a140a3c3877",media_id="35",liq_amplify="0.dB",playlist_id="3":/var/azuracast/stations/beatam/media/Musik/24. badmómzjay - Signal.mp3 2020/08/18 12:41:00 [decoder:3] Method "FFMPEG" accepted "/var/azuracast/stations/beatam/media/Musik/24. badm\195\179mzjay - Signal.mp3". 2020/08/18 12:41:40 [beatam_next_song:3] Prepared "/var/azuracast/stations/beatam/media/Musik/24. badm\195\179mzjay - Signal.mp3" (RID 3). 2020/08/18 12:41:40 [cross_7824:3] Analysis: -20.503056dB / -19.879594dB (4.49s / 4.51s) 2020/08/18 12:41:40 [crossfade:3] No transition: using default. 2020/08/18 12:41:40 [lang:3] AzuraCast Feedback Response: OK 2020/08/18 12:41:45 [lang:3] AzuraCast Feedback Response: OK 2020/08/18 12:43:11 [lang:3] AzuraCast Raw Response: annotate:title="Canto Del Pilón",artist="Milk & Sugar Feat. Maria Marquez",duration="214.",song_id="6329e534c47650eadf01024548e2ca6e",media_id="207",liq_amplify="0.dB",playlist_id="4":/var/azuracast/stations/beatam/media/Musik/22. Milk & Sugar Feat. Maria Marquez - Canto Del Pilón.mp3 2020/08/18 12:43:11 [decoder:3] Method "FFMPEG" accepted "/var/azuracast/stations/beatam/media/Musik/22. Milk & Sugar Feat. Maria Marquez - Canto Del Pil\195\179n.mp3". 2020/08/18 12:43:51 [beatam_next_song:3] Prepared "/var/azuracast/stations/beatam/media/Musik/22. Milk & Sugar Feat. Maria Marquez - Canto Del Pil\195\179n.mp3" (RID 6). 2020/08/18 12:43:51 [cross_7824:3] Analysis: -51.568907dB / -12.634282dB (4.51s / 4.53s) 2020/08/18 12:43:51 [crossfade:3] No transition: using default. 2020/08/18 12:43:51 [lang:3] AzuraCast Feedback Response: OK 2020/08/18 12:43:56 [lang:3] AzuraCast Feedback Response: OK 2020/08/18 12:46:46 [lang:3] AzuraCast Raw Response: annotate:title="Ein Tag Am Strand",artist="Eelke Kleijn",duration="200.",song_id="d5831b29f9978a7e1dec247fdc0ce189",media_id="205",liq_amplify="0.dB",playlist_id="4":/var/azuracast/stations/beatam/media/Musik/21. Eelke Kleijn - Ein Tag Am Strand.mp3 2020/08/18 12:46:46 [decoder:3] Method "FFMPEG" accepted "/var/azuracast/stations/beatam/media/Musik/21. Eelke Kleijn - Ein Tag Am Strand.mp3". 2020/08/18 12:47:25 [beatam_next_song:3] Prepared "/var/azuracast/stations/beatam/media/Musik/21. Eelke Kleijn - Ein Tag Am Strand.mp3" (RID 4). 2020/08/18 12:47:25 [cross_7824:3] Analysis: -69.171186dB / -12.246118dB (4.51s / 4.53s) 2020/08/18 12:47:25 [crossfade:3] No transition: using default. 2020/08/18 12:47:26 [lang:3] AzuraCast Feedback Response: OK 2020/08/18 12:47:30 [lang:3] AzuraCast Feedback Response: OK 2020/08/18 12:50:05 [lang:3] AzuraCast Raw Response: annotate:title="Toosie Slide",artist="Drake",duration="247.",song_id="5dc960cb10510e26f9505d61e474a904",media_id="102",liq_amplify="0.dB",playlist_id="4":/var/azuracast/stations/beatam/media/Musik/96. Drake - Toosie Slide.mp3 2020/08/18 12:50:05 [decoder:3] Method "FFMPEG" accepted "/var/azuracast/stations/beatam/media/Musik/96. Drake - Toosie Slide.mp3". 2020/08/18 12:50:45 [beatam_next_song:3] Prepared "/var/azuracast/stations/beatam/media/Musik/96. Drake - Toosie Slide.mp3" (RID 1). 2020/08/18 12:50:45 [cross_7824:3] Analysis: -102.907972dB / -25.807369dB (4.46s / 4.46s) 2020/08/18 12:50:45 [crossfade:3] new >= old + margin, old <= medium and new <= high. 2020/08/18 12:50:45 [crossfade:3] Do not fade if it's already very low. 2020/08/18 12:50:45 [crossfade:3] Transition: crossed, no fade. 2020/08/18 12:50:45 [lang:3] AzuraCast Feedback Response: OK 2020/08/18 12:54:08 [lang:3] AzuraCast Raw Response: annotate:title="Roadrunner",artist="Bonez MC",duration="149.",song_id="d06d8430a8e7d4bc31565ea9b3a14f4e",media_id="54",liq_amplify="0.dB",playlist_id="3":/var/azuracast/stations/beatam/media/Musik/51. Bonez MC - Roadrunner.mp3 2020/08/18 12:54:08 [decoder:3] Method "FFMPEG" accepted "/var/azuracast/stations/beatam/media/Musik/51. Bonez MC - Roadrunner.mp3". 2020/08/18 12:54:48 [beatam_next_song:3] Prepared "/var/azuracast/stations/beatam/media/Musik/51. Bonez MC - Roadrunner.mp3" (RID 2). 2020/08/18 12:54:48 [cross_7824:3] Analysis: -32.813432dB / -14.223797dB (4.47s / 4.49s) 2020/08/18 12:54:48 [crossfade:3] No transition: using default. 2020/08/18 12:54:48 [lang:3] AzuraCast Feedback Response: OK 2020/08/18 12:54:52 [lang:3] AzuraCast Feedback Response: OK 2020/08/18 12:56:37 [lang:3] AzuraCast Raw Response: annotate:title="Tränen aus Kajal",artist="Céline",duration="151.",song_id="34ea773f723539aed53a3e0573d91d97",media_id="85",liq_amplify="0.dB",playlist_id="3":/var/azuracast/stations/beatam/media/Musik/93. Céline - Tränen aus Kajal.mp3 2020/08/18 12:56:37 [decoder:3] Method "FFMPEG" accepted "/var/azuracast/stations/beatam/media/Musik/93. C\195\169line - Tr\195\164nen aus Kajal.mp3". 2020/08/18 12:57:17 [beatam_next_song:3] Prepared "/var/azuracast/stations/beatam/media/Musik/93. C\195\169line - Tr\195\164nen aus Kajal.mp3" (RID 3). 2020/08/18 12:57:17 [cross_7824:3] Analysis: -69.466672dB / -50.429138dB (4.50s / 4.50s) 2020/08/18 12:57:17 [crossfade:3] new >= old + margin, old <= medium and new <= high. 2020/08/18 12:57:17 [crossfade:3] Do not fade if it's already very low. 2020/08/18 12:57:17 [crossfade:3] Transition: crossed, no fade. 2020/08/18 12:57:17 [lang:3] AzuraCast Feedback Response: OK 2020/08/18 12:59:04 [lang:3] AzuraCast Raw Response: annotate:title="Project T (Martin Garrix Remix)",artist="Dimitri Vegas & Like Mike Vs. Sander Van Doorn",duration="189.",song_id="279b8ec86c42a81099990c0e7e1ffa34",media_id="195",liq_amplify="0.dB",playlist_id="4":/var/azuracast/stations/beatam/media/Musik/10. Dimitri Vegas & Like Mike Vs. Sander Van Doorn - Project T (Martin Garrix Remix).mp3 2020/08/18 12:59:04 [decoder:3] Method "FFMPEG" accepted "/var/azuracast/stations/beatam/media/Musik/10. Dimitri Vegas & Like Mike Vs. Sander Van Doorn - Project T (Martin Garrix Remix).mp3". 2020/08/18 12:59:43 [beatam_next_song:3] Prepared "/var/azuracast/stations/beatam/media/Musik/10. Dimitri Vegas & Like Mike Vs. Sander Van Doorn - Project T (Martin Garrix Remix).mp3" (RID 5). 2020/08/18 12:59:43 [cross_7824:3] Analysis: -57.715399dB / -16.448369dB (4.50s / 4.54s) 2020/08/18 12:59:43 [crossfade:3] new >= old + margin, old <= medium and new <= high. 2020/08/18 12:59:43 [crossfade:3] Do not fade if it's already very low. 2020/08/18 12:59:43 [crossfade:3] Transition: crossed, no fade. 2020/08/18 12:59:44 [lang:3] AzuraCast Feedback Response: OK 2020/08/18 13:02:08 [lang:3] AzuraCast Raw Response: annotate:title="Say Sorry",artist="Oceana",duration="238.",song_id="8ed2158e40951a5b1325ef6816370e86",media_id="144",liq_amplify="0.dB",playlist_id="4":/var/azuracast/stations/beatam/media/Musik/14. Oceana - Say Sorry.mp3 2020/08/18 13:02:08 [decoder:3] Method "FFMPEG" accepted "/var/azuracast/stations/beatam/media/Musik/14. Oceana - Say Sorry.mp3". 2020/08/18 13:02:48 [beatam_next_song:3] Prepared "/var/azuracast/stations/beatam/media/Musik/14. Oceana - Say Sorry.mp3" (RID 4). 2020/08/18 13:02:48 [cross_7824:3] Analysis: -100.681533dB / -28.134673dB (4.47s / 4.49s) 2020/08/18 13:02:48 [crossfade:3] new >= old + margin, old <= medium and new <= high. 2020/08/18 13:02:48 [crossfade:3] Do not fade if it's already very low. 2020/08/18 13:02:48 [crossfade:3] Transition: crossed, no fade. 2020/08/18 13:02:48 [lang:3] AzuraCast Feedback Response: OK 2020/08/18 13:06:02 [lang:3] AzuraCast Raw Response: annotate:duration="41.",song_id="0f0dd8fde3c95ce770511751f152529b",liq_amplify="0.dB",jingle_mode="true":/var/azuracast/stations/beatam/media/Jingles/Hookpromo/Little Mix - Selena Gomez - Lil Mosey.mp3 2020/08/18 13:06:02 [decoder:3] Method "FFMPEG" accepted "/var/azuracast/stations/beatam/media/Jingles/Hookpromo/Little Mix - Selena Gomez - Lil Mosey.mp3". 2020/08/18 13:06:42 [beatam_next_song:3] Prepared "/var/azuracast/stations/beatam/media/Jingles/Hookpromo/Little Mix - Selena Gomez - Lil Mosey.mp3" (RID 1). 2020/08/18 13:06:42 [cross_7824:3] Analysis: -78.917432dB / -9.904572dB (4.47s / 4.49s) 2020/08/18 13:06:42 [crossfade:3] No transition: using default. 2020/08/18 13:06:42 [lang:3] AzuraCast Raw Response: annotate:title="Amanama (Money)",artist="DJ Antoine Vs. Timati",duration="290.",song_id="fcad9f78c0726a9348e49dd3d35e6a81",media_id="153",liq_amplify="0.dB",playlist_id="4":/var/azuracast/stations/beatam/media/Musik/04. DJ Antoine Vs. Timati - Amanama (Money).mp3 2020/08/18 13:06:42 [decoder:3] Method "FFMPEG" accepted "/var/azuracast/stations/beatam/media/Musik/04. DJ Antoine Vs. Timati - Amanama (Money).mp3". 2020/08/18 13:06:42 [lang:3] AzuraCast Feedback Response: OK 2020/08/18 13:06:46 [lang:3] AzuraCast Feedback Response: OK 2020/08/18 13:07:23 [beatam_next_song:3] Prepared "/var/azuracast/stations/beatam/media/Musik/04. DJ Antoine Vs. Timati - Amanama (Money).mp3" (RID 6). 2020/08/18 13:07:23 [cross_7824:3] Analysis: -9.967176dB / -17.332384dB (4.47s / 4.49s) 2020/08/18 13:07:23 [crossfade:3] No transition: using default. 2020/08/18 13:07:23 [lang:3] AzuraCast Feedback Response: OK 2020/08/18 13:07:27 [lang:3] AzuraCast Feedback Response: OK 2020/08/18 13:11:32 [lang:3] AzuraCast Raw Response: annotate:title="Come & Go",artist="Juice Wrld & Marshmello",duration="206.",song_id="1f0fb0f6e9b0969d2fa815e9bf9ea681",media_id="26",liq_amplify="0.dB",playlist_id="4":/var/azuracast/stations/beatam/media/Musik/40. Juice Wrld & Marshmello - Come & Go.mp3 2020/08/18 13:11:32 [decoder:3] Method "FFMPEG" accepted "/var/azuracast/stations/beatam/media/Musik/40. Juice Wrld & Marshmello - Come & Go.mp3". 2020/08/18 13:12:12 [beatam_next_song:3] Prepared "/var/azuracast/stations/beatam/media/Musik/40. Juice Wrld & Marshmello - Come & Go.mp3" (RID 2). 2020/08/18 13:12:12 [cross_7824:3] Analysis: -nandB / -26.017990dB (4.51s / 4.53s) 2020/08/18 13:12:12 [crossfade:3] new >= old + margin, old <= medium and new <= high. 2020/08/18 13:12:12 [crossfade:3] Do not fade if it's already very low. 2020/08/18 13:12:12 [crossfade:3] Transition: crossed, no fade. 2020/08/18 13:12:12 [lang:3] AzuraCast Feedback Response: OK 2020/08/18 13:14:53 [lang:3] AzuraCast Raw Response: annotate:title="Papaoutai",artist="Stromae",duration="233.",song_id="62a5f6f30874249a058b1c3695fad096",media_id="138",liq_amplify="0.dB",playlist_id="4":/var/azuracast/stations/beatam/media/Musik/06. Stromae - Papaoutai.mp3 2020/08/18 13:14:53 [decoder:3] Method "FFMPEG" accepted "/var/azuracast/stations/beatam/media/Musik/06. Stromae - Papaoutai.mp3". 2020/08/18 13:15:33 [beatam_next_song:3] Prepared "/var/azuracast/stations/beatam/media/Musik/06. Stromae - Papaoutai.mp3" (RID 3). 2020/08/18 13:15:33 [cross_7824:3] Analysis: -96.105654dB / -27.948821dB (4.44s / 4.48s) 2020/08/18 13:15:33 [crossfade:3] new >= old + margin, old <= medium and new <= high. 2020/08/18 13:15:33 [crossfade:3] Do not fade if it's already very low. 2020/08/18 13:15:33 [crossfade:3] Transition: crossed, no fade. 2020/08/18 13:15:33 [lang:3] AzuraCast Feedback Response: OK 2020/08/18 13:18:17 [main:3] Shutdown started! 2020/08/18 13:18:17 [main:3] Waiting for main threads to terminate... 2020/08/18 13:18:17 [beatam_relay_1:3] Closing connection... 2020/08/18 13:18:17 [lang:3] DJ Source disconnected! Current live DJ: 2020/08/18 13:18:17 [lang:3] AzuraCast Live Disconnected Response: true 2020/08/18 13:18:17 [harbor:3] Removing mountpoint '/' on port 8005 2020/08/18 13:18:17 [harbor:3] Nothing more on port 8005: closing sockets. 2020/08/18 13:18:17 [clock.wallclock_main:3] Streaming loop stopped. 2020/08/18 13:18:17 [main:3] Threads terminated. 2020/08/18 13:18:17 [threads:3] Shutting down scheduler... 2020/08/18 13:18:17 [threads:3] Scheduler shut down. 2020/08/18 13:18:17 [threads:3] Waiting for queue threads to terminate... 2020/08/18 13:18:17 [threads:3] Queues shut down 2020/08/18 13:18:17 [server:3] Closing socket. 2020/08/18 13:18:17 [main:3] Cleaning downloaded files... 2020/08/18 13:18:17 [main:3] Freeing memory...

It should play the playlist Pop, at minute 56 news and every 3 Songs Jingles. But it does not work.

[cpeter1207]

liquidsoap.log
@SlvrEagle23 thanks for working on this.

It does appear that scheduled events are more timely than before. I am, however, still experiencing the issue I reported the other day.

At 4:00 PM I have:

1. A top of hour playlist that plays every hour at 0 minutes.
2. A once-per-day playlist scheduled every day from 4:00 PM to 4:00 PM.

The top of hour playlist plays once at around 4:00 PM as expected.

The once-per-day playlist begins immediately after the top of hour playlist completes as expected.

It does not stop, however, after one track. Instead, it continues playing tracks from the once-per-day playlist until the next scheduled event, a commercial at 15 minutes past the hour...

It should play one track and then fall back to my general rotation playlists as it used too before your rework.

I'm attaching liquidsoap.log, which should show that this happened.

[cpeter1207]

@SlvrEagle23 Your update appeared to be working, asside from the affore-mentioned issue with looping once-per-day playlists, for several days.

It has now, however, gone off the rails. My up-coming song queue is 11 songs long, even though the max queue length is set to 3.

I also see no "playing next" section on my station's profile page and my once-per-hour playlists are looping for one minute every time they play.

I'm attaching a patch containing the fix I was about to propose before you pushed your rework. It had been running on my station for several weeks without any issues, and I plan to revert back to it for the moment beuntil the schedule rework is more stable.

Feel free to use my fix if you want in the meantime. Otherwise, I can try to figure out what is going wrong with your reworked code, but I have a day job so I may not be able to react as quickly as you might like.

I haven't worked with gitbhub before, so I'm also unfamiliar with how to create a pull request. I'll be glad to send this patch via a pull request, though, if you feel it's worth including.
0001-Fix-scheduled-events-playing-too-late.zip

[cpeter1207]

I'm attaching liquidsoap.log from the station that is having the issues I described in my last comment.
liquidsoap.log

[SlvrEagle23]

@cpeter1207 I have a general idea of your changes based on the patch file you submitted, though of course I wish I could review these in a pull-request format against the code as it is right now. I think the fundamental difference in what you're doing is how you're handling the now calculation.

[cpeter1207]

@SlvrEagle23 I am handling the now calculation differently, though probably not as different as you think. The main difference is that I take the crossfade duration into account.

I think the most critical part of the fix, though, is when a new song is added to the queue.

In the original code, it appeared to me that the queue was rebuilt every 15 seconds or so. This presents a problem, though, because liquidsoap seems to dequeue a song about 30 seconds before it starts playing it. If the buildQueue task runs after that happens, it calculates now from the currently playing song, which is not the song that was most recently dequeued. The impact of this is that, when you adjust the cued_at times of the songs in the queue, and add a new one, the value of $now is potentially much earlier than it should be because the duration of the dequeued, but not yet playing, song isn't taken intoaccount.

This causes scheduled events to be played late, because the value of $now is sometimes about a song's-length too early.

I think the most important part of the fix, then, is to enqueue a new song as soon as a song is dequeued, rather than the next time the buildqueue task runs. The rest is probably mostly just refactoring.

What is the process for submitting a PR for this? I assume it's to create a fork of your project, then push my fix and submit a PR from my fork?

I'll see if I can figure this out in the next day or so. I haven't taken the time to look at your rework yet, so I don't know what it would take to adapt the fix to that, but maybe my explanation of the problem is enough.

[SlvrEagle23]

@cpeter1207 Exactly, just fork the project, make your changes in the other repo, then GitHub will give you the option to submit a pull request to our repository.

If you have any questions you can also join our Slack or Discord and we can walk through it. I'm able to pick through most of your existing changes and incorporate them, but it would be more proper to follow the pull request process.

[nicolas5296]

@SlvrEagle23 Here you will find my liquidsoap.log
liquidsoap.log

AzuraCast • v0.10.3, #9811fbb (2020-06-22 4:38) • Docker • PHP 7.4

The time of the queue is still on the 12th August at 13:09. Attached you will find a screenshot.

The playlist should play music from our playlist Pop, Deutschrap, Jingle and our Adbreak. At full hour it should play the news.
Attached you will find our playlists.

How can we fix the problem?

[nicolas5296]

@SlvrEagle23 Thanks for your help. We change to your competitor Radioboss.Cloud.

[SlvrEagle23]

@nicolas5296 It is not necessary or helpful to tell us that you've switched to a competing product. You can simply say "We are no longer using AzuraCast" or something similar. I wish you the best in your radio station operations, in any case.

[pixel-paul]

The latest PR is listing tracks in the upcoming song queue in the correct order, which had been very hit and miss (https://github.com/AzuraCast/AzuraCast/pull/3144). Thanks @cpeter1207 & @SlvrEagle23!

[AmsterdamFM]

Our (around) top of the our news now plays! Only thing is it mostly skips one or two hours...

2020/09/12 22:01:21 [amsterdamfm_next_song:3] Prepared "/var/azuracast/stations/amsterdamfm/media/news/algemeen.wav" (RID 4).
2020/09/13 00:01:04 [amsterdamfm_next_song:3] Prepared "/var/azuracast/stations/amsterdamfm/media/news/algemeen.wav" (RID 4).
2020/09/13 02:05:40 [amsterdamfm_next_song:3] Prepared "/var/azuracast/stations/amsterdamfm/media/news/algemeen.wav" (RID 2).
2020/09/13 03:59:55 [amsterdamfm_next_song:3] Prepared "/var/azuracast/stations/amsterdamfm/media/news/algemeen.wav" (RID 3).
2020/09/13 05:00:51 [amsterdamfm_next_song:3] Prepared "/var/azuracast/stations/amsterdamfm/media/news/algemeen.wav" (RID 5).
2020/09/13 07:02:01 [amsterdamfm_next_song:3] Prepared "/var/azuracast/stations/amsterdamfm/media/news/algemeen.wav" (RID 3).
2020/09/13 09:00:34 [amsterdamfm_next_song:3] Prepared "/var/azuracast/stations/amsterdamfm/media/news/algemeen.wav" (RID 2).
2020/09/13 11:02:52 [amsterdamfm_next_song:3] Prepared "/var/azuracast/stations/amsterdamfm/media/news/algemeen.wav" (RID 3).
2020/09/13 13:03:45 [amsterdamfm_next_song:3] Prepared "/var/azuracast/stations/amsterdamfm/media/news/algemeen.wav" (RID 4).
2020/09/13 15:02:09 [amsterdamfm_next_song:3] Prepared "/var/azuracast/stations/amsterdamfm/media/news/algemeen.wav" (RID 2).
2020/09/13 18:02:41 [amsterdamfm_next_song:3] Prepared "/var/azuracast/stations/amsterdamfm/media/news/algemeen.wav" (RID 5).
2020/09/13 20:01:18 [amsterdamfm_next_song:3] Prepared "/var/azuracast/stations/amsterdamfm/media/news/algemeen.wav" (RID 2).
2020/09/13 22:00:11 [amsterdamfm_next_song:3] Prepared "/var/azuracast/stations/amsterdamfm/media/news/algemeen.wav" (RID 2).
2020/09/14 00:00:33 [amsterdamfm_next_song:3] Prepared "/var/azuracast/stations/amsterdamfm/media/news/algemeen.wav" (RID 5).
2020/09/14 03:00:29 [amsterdamfm_next_song:3] Prepared "/var/azuracast/stations/amsterdamfm/media/news/algemeen.wav" (RID 2).
2020/09/14 04:00:46 [amsterdamfm_next_song:3] Prepared "/var/azuracast/stations/amsterdamfm/media/news/algemeen.wav" (RID 2).
2020/09/14 06:04:06 [amsterdamfm_next_song:3] Prepared "/var/azuracast/stations/amsterdamfm/media/news/algemeen.wav" (RID 2).
2020/09/14 08:02:57 [amsterdamfm_next_song:3] Prepared "/var/azuracast/stations/amsterdamfm/media/news/algemeen.wav" (RID 4).
2020/09/14 10:08:18 [amsterdamfm_next_song:3] Prepared "/var/azuracast/stations/amsterdamfm/media/news/algemeen.wav" (RID 2).
2020/09/14 11:29:19 [amsterdamfm_next_song:3] Prepared "/var/azuracast/stations/amsterdamfm/media/news/algemeen.wav" (RID 3).
2020/09/14 14:06:05 [amsterdamfm_next_song:3] Prepared "/var/azuracast/stations/amsterdamfm/media/news/algemeen.wav" (RID 3).
2020/09/14 15:05:23 [amsterdamfm_next_song:3] Prepared "/var/azuracast/stations/amsterdamfm/media/news/algemeen.wav" (RID 0).
2020/09/14 19:18:42 [amsterdamfm_next_song:3] Prepared "/var/azuracast/stations/amsterdamfm/media/news/algemeen.wav" (RID 2).
2020/09/14 21:13:55 [amsterdamfm_next_song:3] Prepared "/var/azuracast/stations/amsterdamfm/media/news/algemeen.wav" (RID 6).
2020/09/14 23:57:59 [amsterdamfm_next_song:3] Prepared "/var/azuracast/stations/amsterdamfm/media/news/algemeen.wav" (RID 5).
2020/09/15 02:02:11 [amsterdamfm_next_song:3] Prepared "/var/azuracast/stations/amsterdamfm/media/news/algemeen.wav" (RID 2).
2020/09/15 04:03:32 [amsterdamfm_next_song:3] Prepared "/var/azuracast/stations/amsterdamfm/media/news/algemeen.wav" (RID 3).
2020/09/15 06:01:45 [amsterdamfm_next_song:3] Prepared "/var/azuracast/stations/amsterdamfm/media/news/algemeen.wav" (RID 5).
2020/09/15 08:00:38 [amsterdamfm_next_song:3] Prepared "/var/azuracast/stations/amsterdamfm/media/news/algemeen.wav" (RID 5).
2020/09/15 10:00:17 [amsterdamfm_next_song:3] Prepared "/var/azuracast/stations/amsterdamfm/media/news/algemeen.wav" (RID 3).
2020/09/15 12:01:53 [amsterdamfm_next_song:3] Prepared "/var/azuracast/stations/amsterdamfm/media/news/algemeen.wav" (RID 3).

[sidney65]

Hi , after update I've do some test with scheduled play list .

• starting time is correct for me at + or - 2 min max ; (for info , centovacast does the same offset when using play lists) .

• But ,in sequential mode, the reading order of play list is not respected ; i'v got the same bug : only first jingle or song of the play list play,the rest is ignored !

Hope you find a solution in the next release ;-)
@cpeter1207 @SlvrEagle23

have a good day

Azuracast Rolling Release #0de15ea (2020-09-15 0:14) • Docker • PHP 7.4

[AmsterdamFM]

I see this issue is closed. Only thing is that the hourly news still only plays half of the time...

Could it be a problem that fresh news is uploaded e few minutes before it is scheduled? Or is .59 confusing?

    Line 529: 2020/09/29 22:16:14 [amsterdamfm_next_song:3] Prepared "/var/azuracast/stations/amsterdamfm/media/news/algemeen.wav" (RID 0).
    Line 775: 2020/09/30 00:01:29 [amsterdamfm_next_song:3] Prepared "/var/azuracast/stations/amsterdamfm/media/news/algemeen.wav" (RID 0).
    Line 782: 2020/09/30 00:03:36 [amsterdamfm_next_song:3] Prepared "/var/azuracast/stations/amsterdamfm/media/news/algemeen.wav" (RID 2).
    Line 1046: 2020/09/30 02:00:50 [amsterdamfm_next_song:3] Prepared "/var/azuracast/stations/amsterdamfm/media/news/algemeen.wav" (RID 2).
    Line 1308: 2020/09/30 04:00:07 [amsterdamfm_next_song:3] Prepared "/var/azuracast/stations/amsterdamfm/media/news/algemeen.wav" (RID 2).
    Line 1596: 2020/09/30 06:00:09 [amsterdamfm_next_song:3] Prepared "/var/azuracast/stations/amsterdamfm/media/news/algemeen.wav" (RID 4).
    Line 1854: 2020/09/30 07:59:59 [amsterdamfm_next_song:3] Prepared "/var/azuracast/stations/amsterdamfm/media/news/algemeen.wav" (RID 5).
    Line 1997: 2020/09/30 09:01:01 [amsterdamfm_next_song:3] Prepared "/var/azuracast/stations/amsterdamfm/media/news/algemeen.wav" (RID 2).
    Line 2147: 2020/09/30 10:58:06 [amsterdamfm_next_song:3] Prepared "/var/azuracast/stations/amsterdamfm/media/news/algemeen.wav" (RID 0).
    Line 2193: 2020/09/30 12:58:08 [amsterdamfm_next_song:3] Prepared "/var/azuracast/stations/amsterdamfm/media/news/algemeen.wav" (RID 0).
    Line 2348: 2020/09/30 14:56:33 [amsterdamfm_next_song:3] Prepared "/var/azuracast/stations/amsterdamfm/media/news/algemeen.wav" (RID 2).
    Line 2503: 2020/09/30 16:59:16 [amsterdamfm_next_song:3] Prepared "/var/azuracast/stations/amsterdamfm/media/news/algemeen.wav" (RID 0).
    Line 2660: 2020/09/30 19:00:20 [amsterdamfm_next_song:3] Prepared "/var/azuracast/stations/amsterdamfm/media/news/algemeen.wav" (RID 5).
    Line 2698: 2020/09/30 20:56:36 [amsterdamfm_next_song:3] Prepared "/var/azuracast/stations/amsterdamfm/media/news/algemeen.wav" (RID 0).
    Line 2959: 2020/09/30 23:00:44 [amsterdamfm_next_song:3] Prepared "/var/azuracast/stations/amsterdamfm/media/news/algemeen.wav" (RID 0).
    Line 3196: 2020/10/01 01:00:17 [amsterdamfm_next_song:3] Prepared "/var/azuracast/stations/amsterdamfm/media/news/algemeen.wav" (RID 0).
    Line 3446: 2020/10/01 03:00:21 [amsterdamfm_next_song:3] Prepared "/var/azuracast/stations/amsterdamfm/media/news/algemeen.wav" (RID 2).
    Line 3725: 2020/10/01 05:03:27 [amsterdamfm_next_song:3] Prepared "/var/azuracast/stations/amsterdamfm/media/news/algemeen.wav" (RID 6).
    Line 3972: 2020/10/01 06:59:56 [amsterdamfm_next_song:3] Prepared "/var/azuracast/stations/amsterdamfm/media/news/algemeen.wav" (RID 2).
    Line 4236: 2020/10/01 09:02:43 [amsterdamfm_next_song:3] Prepared "/var/azuracast/stations/amsterdamfm/media/news/algemeen.wav" (RID 5).
    Line 4394: 2020/10/01 11:01:28 [amsterdamfm_next_song:3] Prepared "/var/azuracast/stations/amsterdamfm/media/news/algemeen.wav" (RID 2).
    Line 4658: 2020/10/01 13:02:49 [amsterdamfm_next_song:3] Prepared "/var/azuracast/stations/amsterdamfm/media/news/algemeen.wav" (RID 2).
    Line 5954: 2020/10/01 15:05:56 [amsterdamfm_next_song:3] Prepared "/var/azuracast/stations/amsterdamfm/media/news/algemeen.wav" (RID 2).
    Line 6093: 2020/10/01 17:04:29 [amsterdamfm_next_song:3] Prepared "/var/azuracast/stations/amsterdamfm/media/news/algemeen.wav" (RID 3).
    Line 6120: 2020/10/01 19:04:01 [amsterdamfm_next_song:3] Prepared "/var/azuracast/stations/amsterdamfm/media/news/algemeen.wav" (RID 2).
    Line 6141: 2020/10/01 20:59:45 [amsterdamfm_next_song:3] Prepared "/var/azuracast/stations/amsterdamfm/media/news/algemeen.wav" (RID 2).
    Line 6420: 2020/10/01 23:00:04 [amsterdamfm_next_song:3] Prepared "/var/azuracast/stations/amsterdamfm/media/news/algemeen.wav" (RID 3).
    Line 6696: 2020/10/02 00:57:52 [amsterdamfm_next_song:3] Prepared "/var/azuracast/stations/amsterdamfm/media/news/algemeen.wav" (RID 0).
    Line 6971: 2020/10/02 03:06:55 [amsterdamfm_next_song:3] Prepared "/var/azuracast/stations/amsterdamfm/media/news/algemeen.wav" (RID 0).
    Line 7220: 2020/10/02 05:00:59 [amsterdamfm_next_song:3] Prepared "/var/azuracast/stations/amsterdamfm/media/news/algemeen.wav" (RID 0).
    Line 7481: 2020/10/02 07:04:40 [amsterdamfm_next_song:3] Prepared "/var/azuracast/stations/amsterdamfm/media/news/algemeen.wav" (RID 3).
    Line 7747: 2020/10/02 08:59:31 [amsterdamfm_next_song:3] Prepared "/var/azuracast/stations/amsterdamfm/media/news/algemeen.wav" (RID 6).
    Line 7893: 2020/10/02 10:59:13 [amsterdamfm_next_song:3] Prepared "/var/azuracast/stations/amsterdamfm/media/news/algemeen.wav" (RID 6).
    Line 8165: 2020/10/02 12:59:53 [amsterdamfm_next_song:3] Prepared "/var/azuracast/stations/amsterdamfm/media/news/algemeen.wav" (RID 2).
    Line 8859: 2020/10/02 15:47:36 [amsterdamfm_next_song:3] Prepared "/var/azuracast/stations/amsterdamfm/media/news/algemeen.wav" (RID 2).

[SlvrEagle23]

@AmsterdamFM At this point if you have any further scheduling problems please create them as individual issues. We are no longer receiving large volumes of reports of schedule problems due to significant rewrites in our scheduler software, so we have no reason for keeping a single thread going with so many discussions in it.