ProppFrexx ONAIR User-Forum

Hello,

Last night we've experienced an error with the overlay we had never had before.
Nothing is changed an up till 1.00am it went fine but at 2.00am it began to show an error. (see log below)

23-4-2014 0:53:43: Overlay:Nieuws, Command:Report (Nieuws1), Start:23-4-2014 0:59:40 processed
23-4-2014 1:28:02: Overlay:Powerplay, Command:Public Service Announcement (Powerplay), Start:23-4-2014 1:30:00 processed
23-4-2014 1:54:39: Overlay:Nieuws, Command:News (Nieuws), Start:23-4-2014 1:59:40 processed
23-4-2014 2:53:39: WARNING: Overlay 'Nieuws@2014-04-23T02:59:40' not processed Current 'Nieuws@2014-04-23T01:59:40' still running (Status (Shown) background thread still busy, Count=1).
23-4-2014 3:27:58: WARNING: Overlay 'Powerplay@2014-04-23T03:30:00' not processed Current 'Nieuws@2014-04-23T01:59:40' still running (Status (Shown) background thread still busy, Count=2).
23-4-2014 3:54:47: WARNING: Overlay 'Nieuws@2014-04-23T03:59:40' not processed Current 'Nieuws@2014-04-23T01:59:40' still running (Status (Shown) background thread still busy, Count=3).
23-4-2014 4:53:42: WARNING: Overlay 'Nieuws@2014-04-23T04:59:40' not processed Current 'Nieuws@2014-04-23T01:59:40' still running (Status (Shown) background thread still busy, Count=4).
23-4-2014 5:28:02: WARNING: Overlay 'Powerplay@2014-04-23T05:30:00' not processed Current 'Nieuws@2014-04-23T01:59:40' still running (Status (Shown) background thread still busy, Count=5).
23-4-2014 5:54:39: WARNING: Overlay 'Nieuws@2014-04-23T05:59:40' not processed Current 'Nieuws@2014-04-23T01:59:40' still running (Status (Shown) background thread still busy, Count=6).
23-4-2014 6:53:45: WARNING: Overlay 'Nieuws@2014-04-23T06:59:40' not processed Current 'Nieuws@2014-04-23T01:59:40' still running (Status (Shown) background thread still busy, Count=7).
23-4-2014 7:34:05: Calendar 'D:\ProppFrexx Media\Reclame\Overlay.calendar' updated (last modified: 23-4-2014 7:26:07)
23-4-2014 7:34:16: WARNING: Overlay 'Powerplay-Powerplay@2014-04-23T07:30:00' not started (it is already late)!
23-4-2014 7:54:39: Overlay:Nieuws, Command:News (Nieuws), Start:23-4-2014 7:59:40 processed
23-4-2014 8:53:34: Overlay:Nieuws, Command:Report (Nieuws1), Start:23-4-2014 8:59:40 processed

What went wrong? Running the current version of ProppFrexx v3.0.13.16.

Jesper, Aladna Fm

- What 'News' tracks have you planned to play?
the overlay is loading every hour 4 tracks: commercial, news opener, news and toth jingle

- Could it be related to a broken/damaged file?
I don't think so because these 4 tracks are played every hour and working fine except last night.

- Are you downloading the news files regularly/automatically every hour?
The news bullitin is downloading every hour at xx:50, and was working also last night

- What did you do to resolve the issue? Was the overlay player still shown? If yes, what was it showing?
I restarted ProppFrexx and the issue was gone.
The overlay player was still shown and it was showing the 4 tracks en the timer was stuck at 5 minutes (the time I have set up, show 5 minutes in advance) indicating that it was stuck at the beginning of showing.

So maybe it went stuck on the news track but I'm not sure because the newsdownloader has no log.
But everything is now working again since we've restarted ProppFrexx.

I will turn on the debugging function tonight and if it happens again the debug log will show the problem!?

Jesper, Aladna Fm

OKay, so the real 'variable' part is effectively the hourly download of the news track (at :50h).

When scanning the my code and when you say the 4 tracks have already been displayed I can only guess, that the stream creation from playback failed resp. got stuck.
And this can effectively only happen if the file is corrupt...
Of course, a restart might have solved that issue and the new hourly downloads might have already overwritten the erroneous file...so it could theoretically explain things, but is all very unlikely.

So yes, turn that Debug Logging on to see, if that reveals more details...

All playlists were loaded and working, but the overlay didn't work from 2.00am so the the playlists weren't closed because I have the pls_current_close code implemented in the overlay.

Also the silence detection began to work at 3.00am because the overlay not working and next playlist starts at xx:01. (so that explains the silence between xx:59:40 (time overlay should start and end playlist) and xx:01 (begin new playlist)

Silence Detection list played from 3.00am till reboot ProppFrexx and the playlist was running too, resulting in a double sound.

Below see the playlist log:

23-4-2014 0:00:03: Program:Automaat Nacht (Automaat nacht), Start:23-4-2014 0:01:20, End:23-4-2014 1:00:00, Started:True
23-4-2014 0:59:46: Program:Automaat Nacht (Automaat nacht), Start:23-4-2014 1:01:00, End:23-4-2014 2:00:00, Started:True
23-4-2014 1:59:47: Program:Automaat Nacht (Automaat nacht), Start:23-4-2014 2:01:00, End:23-4-2014 3:00:00, Started:True
23-4-2014 2:59:47: Program:Automaat Nacht (Automaat nacht), Start:23-4-2014 3:01:00, End:23-4-2014 4:00:00, Started:True
23-4-2014 3:59:48: Program:Automaat Nacht (Automaat nacht), Start:23-4-2014 4:01:00, End:23-4-2014 5:00:00, Started:True
23-4-2014 4:59:48: Program:Automaat Nacht (Automaat nacht), Start:23-4-2014 5:01:00, End:23-4-2014 6:00:00, Started:True
23-4-2014 5:59:49: Program:Automaat Overdag (Automaat), Start:23-4-2014 6:01:00, End:23-4-2014 7:00:00, Started:True
23-4-2014 6:59:49: Program:Automaat Overdag (Automaat), Start:23-4-2014 7:01:00, End:23-4-2014 8:00:00, Started:True
23-4-2014 7:23:36: Scheduler stopped
ProgramScheduler: Scheduler started
23-4-2014 7:26:06: Scheduler stopped
23-4-2014 7:34:05: Calendar 'C:\Users\admin\AppData\Roaming\radio42\ProppFrexx ONAIR\3.0\ProppFrexx ONAIR.calendar' read-in (last modified: 23-4-2014 7:26:07)
ProgramScheduler: Scheduler started
23-4-2014 7:34:25: Scheduler stopped
ProgramScheduler: Scheduler started

Jesper, Aladna Fm

I forgot to ask the most important question: Was the playlist still normally running/playing in the background?

It looks, like the "Overlay:Nieuws" at 23-4-2014 1:59:40 never finished its processing and got somehow 'stuck' while its processing.

A rew questions:
- What 'News' tracks have you planned to play?
- Could it be related to a broken/damaged file?
- Are you downloading the news files regularly/automatically every hour?
- What did you do to resolve the issue? Was the overlay player still shown? If yes, what was it showing?


Since the warnings indicate, that the Overlay-Player was in Status 'Shown', that indicates, that the overlay player's current action (when it got stuck) was either:
- loading the NewsBlock (creating the overlay playlist)
- reading the TAG data of the overlay playlist tracks
- preparing the playout streams
Non of these action should actually got stuck...but it did...so the only idea I currently have is, that the OS blocked some file access, i.e. when loading the news tracks?!

So If you are running a regular background job which downloads fresh news files rom somewhere....did that job probably crash and as a result blocked the file access?

What you might do to collect further info (in case it happens again) is to enable the 'Debug Logging' (see general settings, section 'More Stuff').
If enabled an extensive Debug_*.log file is written recording a lot of additional info.
However, that option should only be turned on temporarily.
E.g. you might turn it on in the evening (in case it happens again unmonitored) over night and then disable it again in the morning.