Gerne, anbei:
EDIT: “Optionen” nachgereicht
Danke. Das sieht erstmal gut aus.
Andererseits ist an den Logs sehr eindeutig zu sehen, was passiert ist: Das Event um 18:58 hat nicht die 19-Uhr-Stunde geladen, sondern noch einmal die 18-Uhr-Stunde. Durch die dort enthalten Fixzeiten hat die Playlist alles mögliche übersprungen und ist hinter den zweiten Werbeblock der 18-Uhr-Stunde gesprungen, also in die zweite halbe Stunde der 18-Uhr-Stunde:
{"Timestamp":"2023-12-13T18:58:00.026","Message":"Führe Event PLAYLIST NACHLADEN aus","Level":"Info"}
{"Timestamp":"2023-12-13T18:58:00.118","Message":"Werbecontainer untersucht: 2, geändert: 0","Level":"Info"}
{"Timestamp":"2023-12-13T18:58:00.122","Message":"Überspringe fehlerhaftes Element \"Block 1\": ","Level":"Warning"}
{"Timestamp":"2023-12-13T18:58:00.366","Message":"Fixed time reached, jump to: 13.12.2023 18:02:59.000 - News Opener","Level":"Debug"}
{"Timestamp":"2023-12-13T18:58:00.386","Message":"Datei-Recorder: Aufnahme in Z:\\ARCHIV\\NEWS\\weltnews.mp3 wurde gestartet.","Level":"Info"}
{"Timestamp":"2023-12-13T18:58:00.469","Message":"Fixed time reached, jump to: 13.12.2023 18:38:59.000 - Block 2","Level":"Debug"}
{"Timestamp":"2023-12-13T18:58:00.470","Message":"Überspringe fehlerhaftes Element \"Block 2\": ","Level":"Warning"}
{"Timestamp":"2023-12-13T18:58:00.718","Message":"Datei-Recorder: Aufnahme in Z:\\ARCHIV\\NEWS\\regionews.mp3 wurde gestartet.","Level":"Info"}
{"Timestamp":"2023-12-13T18:58:05.367","Message":"Stop: Z:\\ON AIR\\IMPORT\\CLUBFM CHARTS\\Charts Update 25 07 2021\\George Z - Lose My Mind.mp3 (31 seconds)","Level":"Playlist"}
{"Timestamp":"2023-12-13T19:00:20.801","Message":"Start: Z:\\ON AIR\\STUDIO\\JINGLES\\Floyd Media - Club FM 2022\\06. Theme Top of the Hour\\Theme 06 TOH Basic ID Full Vocals.wav","Level":"Playlist"}
{"Timestamp":"2023-12-13T19:00:22.871","Message":"Datei-Recorder: Aufnahme in Z:\\ARCHIV\\NEWS\\weltnews.mp3 wurde gestoppt.","Level":"Info"}
{"Timestamp":"2023-12-13T19:00:22.885","Message":"Datei-Recorder: Aufnahme in Z:\\ARCHIV\\NEWS\\regionews.mp3 wurde gestoppt.","Level":"Info"}
{"Timestamp":"2023-12-13T19:00:30.288","Message":"Start: Z:\\ON AIR\\IMPORT\\CLUBFM CHARTS\\Charts Update 26 11 2023\\Oliver Heldens & Weibird - Out of Love.mp3","Level":"Playlist"}
Wenn du in die Datenbank-Playlist (oder weiter oben im Systemprotokoll) schaust, siehst du, dass Out of Love der erste Titel nach dem Werbeblock 2 in der 18-Uhr-Stunde war und dort auch schon gespielt wurde.
Dadurch war dann natürlich irgendwann Schicht im Schacht, weil eine halbe Stunde Material fehlte.
Die allesentscheidende Frage ist, warum er die falsche Stunde geladen hat. Ich vermute, dass wir es hier mit demselben Rundungsfehler zu tun haben, der in einem ähnlichen Zusammenhang auch hier schon berichtet wurde:
Der Fehler hängt mit der Art und Weise zusammen, wie Delphi (die Programmiersprache) mit Datums- und Zeitangaben rechnet. In dem Thread ist es genauer beschrieben.
Einen grundsätzlichen Bug in mAirList 7.x kann ich ausschließen, denn es hat sich an der Codestelle seit Jahren nichts mehr geändert, im Grunde ist dort alles identisch wie noch in Version 6.x.
Was sich allerdings zwischen mAirList 6 und 7 geändert hat, ist die verwendete Delphi-Version (vorher XE6, jetzt 10.4). Möglicherweise haben wir es also hier mit einem Bug in Delphi zu tun, der erst in dieser neuen Compiler-Version auftritt, weil irgendetwas an den Libraries und den Funktionen zur Zeitberechnung geändert wurde.
Ich muss da weiter nachforschen. Melde mich in Kürze, denn das ist ja schon eine kritische Angelegenheit…
5 Likes
Vielen Dank für die ausführliche Analyse und Erklärung. Das würde tatsächlich einiges erklären. Ich habe gerade mit einem Bekannten gesprochen, der auch mAirList 7 einsetzt, dort kam es kürzlich zu einem identischen Problem. Auch dort wurde in der Playlistverwaltung bei den betroffenen Stunden nichts mehr angezeigt, nach einem Neustart lief alles wieder normal.
1 Like
Noch eine Zwischenfrage: Sind irgendwelche Soundprocessing-Plugins oder sonstige “Fremd-DLLs” im Einsatz?
(Klingt abwegig, ich weiß, aber den Hintergrund erkläre ich später.)
1 Like
Nein, es sind keine Plugins o.Ä. im Einsatz. mAirList spielt hier direkt über Dante (WASAPI) aus, von da gehts weiter ins DHD. Der Soundprozessor ist extern.
Es gibt nur noch ein uraltes Script für den Auto/Assist Button (ist ne reine Layout Geschichte), hier der Code:
procedure UpdateButton;
begin
if PlaybackControl(0).GetAutomation then begin
ExecuteCommand('AUTOMATIONBUTTON TEXT AUTO');
ExecuteCommand('AUTOMATIONBUTTON FONTCOLOR #FFFFFF');
ExecuteCommand('AUTOMATIONBUTTON FONTSTYLE 1');
ExecuteCommand('AUTOMATIONBUTTON BACKGROUNDCOLOR #FF0000');
end
else begin
ExecuteCommand('AUTOMATIONBUTTON FONTCOLOR #FFFFFF');
ExecuteCommand('AUTOMATIONBUTTON TEXT Assist');
ExecuteCommand('AUTOMATIONBUTTON FONTSTYLE 1');
ExecuteCommand('AUTOMATIONBUTTON BACKGROUNDCOLOR #008000');
end;
end;
procedure OnLoad;
begin
UpdateButton;
EnableTimer(500);
end;
procedure OnAutomationOn(PlaylistIndex: integer);
begin
UpdateButton;
end;
procedure OnAutomationOff(PlaylistIndex: integer);
begin
UpdateButton;
end;
procedure OnTimer;
begin
UpdateButton;
end;
begin
end.
Sonst ist das eine reine “Stock” Installation.
Fehler gefunden!
TL;DR: Version 7.2.4 installieren
Die ganze Geschichte, etwas weiter ausgeholt und mathematisch, aber vielleicht interessiert es jemanden:
Es handelte sich tatsächlich um Rundungsfehler. Um die Ursache zu identifizieren, musste ich etwas tiefer in die Funktionsweise von Delphi eintauchen. Tatsächlich verwendet Delphi für das Runden von Zahlen die floating point unit (FPU) der CPU. Und diese lässt sich über bestimmte Befehle in verschiedene Modi schalten: kaufmännisches Runden, immer aufrunden, immer abrunden, etc.
Mein Verdacht war, dass “irgendwer” diesen Modus versehentlich umgestellt hat, und zwar auf “immer abrunden”, weswegen die Zeitberechnungen nicht mehr korrekt waren. Dazu passte die Beobachtung, dass in deinem Video nur die durch drei teilbaren Stunden (0, 3, 6, 9, 12, 15, 18, 21) noch Daten anzeigten. Delphi verwendet nämlich Brüche für die Uhrzeiten benutzt (1 Tag = 1, und 1 Stunde = 1/24), und zwar als Dezimaldarstellung. Und die durch drei teilbaren Stunden sind Achtel-Tage, und das sind die einzigen Dezimalzahlen mit einer endlichen Anzahl an Nachkommastellen (1/8 = 0.125), bei denen also nicht gerundet werden muss.
Ich hatte zuerst in Verdacht, dass das eine externe DLL wie z.B. ein Soundprocessing-Plugin hätte sein können. Durch weitere Suche im Code bin ich dann aber darauf gestoßen, dass es von einer Fremdbibliothek verursacht wird, die ich seit Version 7.x für die Anzeige von Icons etc. verwende. Diese verändert tatsächlich kurzzeitig den Rundungs-Modus, setzt ihn normalerweise auch zurück, aber unter ganz bestimmten Bedingungen kann sie es “vergessen”, wodurch der Modus dann bis zum nächsten Neustart verstellt ist, und alle folgenden Rundungs-Operationen dann möglicherweise ein falsches Ergebnis liefern.
Einen Bugreport habe ich beim dortigen Entwickler bereits hinterlassen:
Ich habe den Code aber bei mir bereits gefixt, und eine Version 7.2.4 hochgeladen, in der das Problem aus der Welt geschafft sein sollte. Übernahme in v7.3 beta folgt in Kürze.
11 Likes
Das war jetzt tatsächlich ein kritischer Fehler der Sorte “Torben schläft schlecht”, und dessen Behebung oberste Priorität hat, so dass ich im Zweifel alles stehen und liegen lasse. Zum Glück haben wir es ja noch vor dem Zubettgehen gelöst bekommen 
Gleichzeitig ein Paradebeispiel dafür, dass es Dinge gibt, auf die man als Entwickler, der sich für bestimmte Dinge zwangsläufig externer Bibliotheken bedient, nicht unbedingt direkten Einfluss hat. Wenn jemand anders beim Programmieren etwas übersehen oder vergessen hat, dann ist das zwar erstmal nicht mein Problem - es wird aber zu meinem, wenn ich den Code bei mir einbinde. Gleichzeitig ist das Debuggen von fremden Code natürlich ungleich schwieriger. Immerhin lag mir hier der Sourcecode vor, und es war nicht nur eine eingebundene DLL.
Umso wichtiger ist es, möglichst viele Informationen zu dem Fehler zu erhalten, und dass auf Nachfragen meinerseits schnell und präzise geantwortet wird. Daher einen großen Dank an @clubfm und alle Beteiligten (auch in den anderen Threads) für ihre Mithilfe!
8 Likes
Vielen Dank erstmal für die super schnelle und hervorragende Fehleranalyse und Behebung, das ist echt phänomenal. Auch vielen Dank an die Community!
Ich habe die neue Version soeben installiert und werde das Verhalten beobachten.
4 Likes
Auch von mir ein ganz großes Dankeschön für den super schnellen Support! Klasse! Neue Version wird ASAP installiert.
3 Likes
Hallo zusammen,
wie läuft die neue Version bei euch? Leider ist hier dasselbe Problem gerade eben wieder aufgetreten, hier ein kurzes Video:
Nach einem Neustart von mAirList waren die Playlisten wieder da. Muss ich die Playlisten neu rechnen lassen, oder besteht hier ggf. noch ein anderes Problem?
Mit “Problem wieder da” meinst Du das Leerlaufen einer aktiven Playliste oder “nur” das Verschwinden der Playlisten?
Leider beides - ich bin um kurz nach 20:00 Uhr zufällig ins Studio gekommen und habe gesehen, dass die Playlist gerade am Auslaufen war. Dann wollte ich die Sendestunde checken und habe gesehen, dass sie wieder nicht mehr da war.
mAirList hat offenbar auch wieder eine falsche Stunde geladen, Beispiel aus dem Log:
{"Timestamp":"2023-12-14T18:33:03.380","Message":"Start: Z:\\ON AIR\\IMPORT\\CLUBFM CHARTS\\Charts Update 19 11 2023\\Twin Scream, Franz Kolo - In Da House.mp3","Level":"Playlist"}
{"Timestamp":"2023-12-14T18:36:02.191","Message":"Stop: Z:\\ON AIR\\IMPORT\\CLUBFM CHARTS\\Charts Update 19 11 2023\\Twin Scream, Franz Kolo - In Da House.mp3 (178 seconds)","Level":"Playlist"}
{"Timestamp":"2023-12-14T20:00:47.662","Message":"Start: Z:\\ON AIR\\IMPORT\\CLUBFM CHARTS\\Charts Update 19 11 2023\\Twin Scream, Franz Kolo - In Da House.mp3","Level":"Playlist"}
{"Timestamp":"2023-12-14T20:03:46.465","Message":"Stop: Z:\\ON AIR\\IMPORT\\CLUBFM CHARTS\\Charts Update 19 11 2023\\Twin Scream, Franz Kolo - In Da House.mp3 (178 seconds)","Level":"Playlist"}
Da scheint leider noch was im Busch zu sein.
EDIT:
Hier sieht man es ggf. nochmal etwas besser, die Regionews (laufen nur um halb, zuletzt um 18:30) liefen um kurz vor 20:00 Uhr:
{"Timestamp":"2023-12-14T18:30:16.891","Message":"Datei-Recorder: Aufnahme in Z:\\ARCHIV\\NEWS\\regionews.mp3 wurde gestartet.","Level":"Info"}
{"Timestamp":"2023-12-14T18:32:55.950","Message":"Datei-Recorder: Aufnahme in Z:\\ARCHIV\\NEWS\\regionews.mp3 wurde gestoppt.","Level":"Info"}
{"Timestamp":"2023-12-14T19:58:01.197","Message":"Datei-Recorder: Aufnahme in Z:\\ARCHIV\\NEWS\\regionews.mp3 wurde gestartet.","Level":"Info"}
{"Timestamp":"2023-12-14T20:00:40.253","Message":"Datei-Recorder: Aufnahme in Z:\\ARCHIV\\NEWS\\regionews.mp3 wurde gestoppt.","Level":"Info"}
1 Like
Möglicherweise gibt es eine weitere, weniger offensichtliche Stelle im Code, die den RoundingMode verstellt.
@clubfm Ich habe dir gerade einen Link zu einer Debug-Version geschickt. Bitte installiere diese mal und lasse sie laufen. Sie überprüft 1x pro Sekunde, ob der RoundingMode noch dem erwarteten Wert (0) entspricht, und wenn nein, schreibt sie Meldungen ins Systemprotokoll (“RoundingMode: xxx”).
Bitte beobachte mal, ob diese Meldungen dort irgendwann auftauchen, und wenn ja, ob sie zeitlich mit irgendeinem speziellen Ereignis in Verbindung gebracht werden können.
Moin!
vielen Dank für die Info und die Debug Version. Ich habe sie soeben installiert und beobachte nun, wann die Meldungen auftreten. mAirList hat interessanterweise beim Start der Debug Version auch erstmal die falsche Playlist geladen, den falschen Opener gespielt, diesen abgebrochen, dann ewig viele Elemente übersprungen und dann das richtige Element aus der passenden Playlist gestartet.
1 Like
War das schon das Setup mit dem “xxx-2” im Dateinamen? Ich hatte heute morgen noch einmal eine neue Debug-Version hochgeladen, in der schon ein oder zwei Workarounds enthalten sind dahingehend, dass der RoundingMode an kritischen Stellen auf die Standardeinstellung zurückgesetzt wird.
Dennoch ist die Protokollierung sehr wichtig um herauszufinden, wann und warum er plötzlich umspringt.
1 Like
Es war noch die “debug-roundingmode-1-setup.exe”. Soll ich die 2er installieren?
Kurze Zwischeninfo: Bisher habe ich im Log noch keine Meldung zum Rounding Mode erhalten.
Ich habe jetzt sogar noch eine -3 ergänzt. Nimm die bitte mal.
Mit etwas Glück tritt der Fehler - zumindest bezogen auf das Laden von Playlists - dort nicht mehr auf.
Wohl aber noch die Protokollierung, wenn “irgendwer” den RoundingMode umgestellt hat. Denn es gibt ja noch etliche andere Stellen im Code, an denen die Round()-Funktion verwendet wird, und die sollen ja auch zuverlässig funktionieren. Also müssen wir das beobachten, auf die Meldungen warten und schauen, ob man aus dem Zeitpunkt irgendwelche Rückschlüsse über den Verursacher ziehen kann.
Leider kann dieser Verursacher “irgendwo” sein, im Zweifel in einer der von uns verwendeten DLLs, auf deren Sourcecode ich keinen Zugriff habe.
Nur mal ein Beispiel, was in Frage kommen könnte: Du spielst durchgehend nur MP3- und WAV-Dateien, irgendwo ist aber mal eine Datei in einem anderen Format (meinetwegen AAC) dabei, und deren Decoder verstellt den RoundingMode. Dann tritt das Problem erst dann auf, wenn diese eine Datei zur Ausspielung kommt.
Ein bisschen die Nadel im Heuhaufen…
Alles klar, danke! Ich habe die v3 jetzt am Laufen und werde berichten 
1 Like
… und ich finde die Bereitschaft zur Mitarbeit von @clubfm und dessen präzise Rückmeldungen vorbildlich. Könnten sich andere hierzuforen eine Scheibe (zweie?) von abschneiden.
9 Likes