Parallel playback of overlay and 1st program song

You found a bug or have any issues? Please post them here!
Post Reply
User avatar
hdradio
Posts: 625
Joined: 10 Apr 2012 17:36
Location: Crete, Hellas
Parallel playback of overlay and 1st program song

Post by hdradio »

Hi
I updated last night to v3.14.10 and I faced the following problem:
PF was working fine for more than one week. I updated last night at 22:45 to v3.14.10.
I did not change anything else.

Today at 09:00 Time announce did not play and the commercial started in parallel with the first song of the new playlist.
You can imagine the OnAir result :(
I have set TimeAnnounce overlay at 09:00:00
Commercial overlay at 09:00:01
My new program starts at 09:00:00

I have set in Library Automation Options:
Reload Libs every 24 hours, starting at 01:15 and also checked reload script libraries and rescan libraries.
Looking at the debug log I see that it couldn't find the time announce file after the 01:15 daily reload.

I am sending you the debug log to check.
User avatar
hdradio
Posts: 625
Joined: 10 Apr 2012 17:36
Location: Crete, Hellas
Re: Parallel playback of overlay and 1st program song

Post by hdradio »

ok. I understand why it could not find the script.
But why the second overlay started in parallel with the first song of the new program ?
That is my main problem because it was very bad listening 2 audio files playing in parallel :(
User avatar
radio42
Site Admin
Posts: 8977
Joined: 05 Apr 2012 16:26
Location: Hamburg, Germany
Contact:
Re: Parallel playback of overlay and 1st program song

Post by radio42 »

Should now be fixed in v3.0.14.11 !
User avatar
radio42
Site Admin
Posts: 8977
Joined: 05 Apr 2012 16:26
Location: Hamburg, Germany
Contact:
Re: Parallel playback of overlay and 1st program song

Post by radio42 »

I am not sure about that yet, but I am sure it is a pure follow-up error due to the first overlay not able to run/find the script.
The case is, that at that time the 2nd overlay was already loaded and queued as a parallel overlay - but at that time it didn't know/consider, that the 1st one was failing.
However that should of course also not happen...and needs to be fixed.
User avatar
radio42
Site Admin
Posts: 8977
Joined: 05 Apr 2012 16:26
Location: Hamburg, Germany
Contact:
Re: Parallel playback of overlay and 1st program song

Post by radio42 »

Yes, that was exactly the problem!
After the reload, the 'Time Announce' script could not be found anymore by the overlays...and thus the trouble started.
Meaning, no tracks loaded for the time announce overlays etc.

So the log clearly identifies what happened (the script with the name 'Time Announce' was not found).
The real good question is why, since the reload itself was reported as successful and ok.
22/08/2014 01:14:54: AddOrReplaceScriptLib: Old 'Time Announce [Time Announce.pfs]' reloaded True.

Another puzzling thing is, that it looks like someone changed the system time as well...e.g. if you look to the log entries
22/08/2014 01:15:00: AddOrReplaceScriptLib: Old 'd1700 [d1700.pfs]' reloaded True.
22/08/2014 01:14:54: AddOrReplaceScriptLib: Old 'd2100 [d2100.pfs]' reloaded True.
22/08/2014 01:14:54: AddOrReplaceScriptLib: Old 'd2200 [d2200.pfs]' reloaded True.
As all entries are always written FiFo...it means your system time was changed and adjused by -6 seconds...
So maybe a windows update...time update? Anyhow, that shouldn't cause these problems!

I need to investigate this further what really might have happened, as it all looks impossible.
Especially, because I guess you now restarted ProppFrexx and I assume it is running fine again...?
User avatar
radio42
Site Admin
Posts: 8977
Joined: 05 Apr 2012 16:26
Location: Hamburg, Germany
Contact:
Re: Parallel playback of overlay and 1st program song

Post by radio42 »

Now I see the problem!
It was indeed related to the changing of the system time exactly while the scripts have been reloaded!!!
Do you remember our discussion about removing libs in case they are not referenced anymore during a reload?
The only reliable way to do that internally is by comparing a time stamp when they are last used vs. last reloaded.
And exactly here lies the issue!
In case the system time is changed backwards exactly while the scripts are being reload, they might incorrectly be detected as 'unused/to be deleted' - and that is what happened.
Thus the scripts could not be found anymore...

I need to correct that!

Post Reply