Detected Queue End as 20 Minutes Before the Hour

[n9xcr]

I saw this happen once last week and wrote it off as an anomaly, but it JUST happened again. Scheduler looked at the queue which was going to end at the TOTH and thought it was going to end at 20 minutes sooner. It then scheduled an additional 20 minutes of tracks which would have delayed the legal ID until 20 after the hour.

Here's an excerpt from the log that shows the end of scheduling the 8:00 hour and beginning of the 9:00 hour.

Code: [Select]

Line 29     fill Min:52:30 Max:52:30 rua 1950s & 60s
(08:47:23)  Added /Users/newuser/Music/iTunes/iTunes Media/Music/Danny Williamsw/Unknown Album/White on Whiteo.mp3
(08:50:06)  Added /Users/newuser/Music/iTunes/iTunes Media/Music/The Rolling Stones/Through the Past, Darkly (Big Hits, Vol. 2)/05 Mother's Little Helper.mp3
            6 tracks with endtime within a 1 second window of target
            Attempting track Jay and The Americans - Lets Lock The Door within a 1 second window of target.
(08:52:30)  Added /Users/newuser/Music/iTunes/iTunes Media/Music/Jay And the Americans/Unknown Album/Lets Lock The Door.mp3
Line 30     pick Jingles
(08:52:38)  Added /Users/newuser/Music/iTunes/iTunes Media/Music/x/Jingles/id2.mp3
Line 31     fill Min:60:00 Max:60:00 rua 1950s & 60s
(08:55:22)  Added /Users/newuser/Music/iTunes/iTunes Media/Music/Billy Haley & the Comets/Unknown Album/See You Later Alligator.mp3
(08:58:16)  Added /Users/newuser/Music/iTunes/iTunes Media/Music/Marvin Gaye/Unknown Album/How Sweet it Is (to Be Loved By You)T.mp3
            1 track with endtime within a 10 second window of target
            Attempting track Newbeatsb - Bread And Buttern within a 10 second window of target.
            1 track with endtime within a 12 second window of target
            Attempting track Herman's Hermitss - Silhouettes within a 12 second window of target.
(09:00:11)  Added /Users/newuser/Music/iTunes/iTunes Media/Music/Herman's Hermitss/Unknown Album/Silhouettes.mp3
7:41:19 AM  Sending to DJ
----------- Programming Segment 1950s & 60s finished at 7:41:19 AM (79 seconds) -----------

----------- Programming Segment "1950s & 60s" (Start time: 9:00 AM Length: 60 mins) started on Jan 5, 2012 at 8:40:00 AM (Auto) -----------
8:40:00 AM  Found Overlap of 1.8 in the Preference Set Default
            Queue End Time: 8:40:00 AM + Top of the Program Time: 9:00:00 AM = Total Time: -0:20:00
8:40:00 AM  Current program ends at -0:20:00 relative to start time
8:40:00 AM  Getting playlist data...
8:40:02 AM  Importing iTunes Library Tracks...
8:40:17 AM  8,237 tracks in Library, 489 tracks in 9 playlists
            Actual spots=10 Spot Distribution Ratio=2.5
Line 1      fill Min:TOTH rua 1950s & 60s
(08:42:58)  Added /Users/newuser/Music/iTunes/iTunes Media/Music/Gary Pucket And the Union Gap/Unknown Album/This Girl Is a Woman Nows.mp3
(08:45:50)  Added /Users/newuser/Music/iTunes/iTunes Media/Music/Cherh/Unknown Album/All I Really Want to Do.mp3
(08:48:40)  Added /Users/newuser/Music/iTunes/iTunes Media/Music/Claud King/Unknown Album/Wolverton Mountain.mp3
(08:50:44)  Added /Users/newuser/Music/iTunes/iTunes Media/Music/Gene Vincent/Unknown Album/Lotta Lovin'.mp3
(08:53:27)  Added /Users/newuser/Music/iTunes/iTunes Media/Music/Manfred Manne/Unknown Album/The Mighty Quinn (Quinn the Eskimo).mp3
(08:56:23)  Added /Users/newuser/Music/iTunes/iTunes Media/Music/Four Tops/Unknown Album/Bernedatte.mp3
            1 track with endtime within a 8 second window of target
            Attempting track Beach Boysh - Good Vibrations within a 8 second window of target.
            TOTH is best after this next track
(08:59:56)  Added /Users/newuser/Music/iTunes/iTunes Media/Music/Beach Boysh/Unknown Album/Good Vibrations.mp3
Line 2      time
            Added Time Announcement
Line 3      pick i Legal ID


[Jay Lichtenauer]

Versions?

Only sometimes?

The reason I ask this is because starting in version 2011.12.1, the location of where the queue end point is saved is changed and you must run at least 2011.12.1 of both DJ and Scheduler.

[n9xcr]

Yes, only sometimes. I wish I would have made a note of the last time I saw it happen. I *want* to say it was the same time of day.  Anyways...

Scheduler - 2011.12.2
DJ - Version 2011.12.1

[Jay Lichtenauer]

There are already a lot of provisions to make sure this can't happen such as retrying the file 20 times over 10 seconds if the queue end time was read as 0. Your log shows it determining the queue end point inside a second so I think The only way I can see this happening is the file system has reported the ~/Library/Preferences/Radiologik/Queue End file doesn't exist and with that it will exit right away with a zero in queue. So with that as the theory I will make a retry loop on seeing if the file exists and if it fails it should just consider queue end time to be the start time like the other provisions do.

I did a search for this error occurring on two stations over a long period of several weeks and it always reads the queue from DJ correctly. But if it this is happening to one person, it will almost certainly show for someone else.

[Jay Lichtenauer]

I've added more provisioning to this build. I can't test against a failure here so please give it a try:
http://macinmind.com/RadiologikSchedulerbeta.zip

[n9xcr]

Thanks, Jay! It is now installed and I'll keep my eye on it. It was at least a week ago when I caught it the first time. I'll dig through the logs and see if it did it any other times as well.

Chris