57_Calendar.pm: Exchange Kalender verursacht 'HTTP Response Code 503'

[JudgeDredd]

Hallo Zusammen,

ich habe mehrere MS-Exchange Kalender in FHEM definiert.
Erstmal funktionieren die auch unauffällig. Wenn ich allerdings FHEM stoppe und (unverändert) wieder starte, erhalte ich
bei jedem Kalender Update-Zyklus im Log die Fehlermeldung:

Code Auswählen Erweitern

Calendar cal_MSE00A: retrieval failed with HTTP response code 503

Wenn ich nun beim Kalender in die DEF gehe und nur auf modify klicke ohne etwas zu ändern, rennt der Kalenderupdate wieder ohne fehler.
Aber eben wieder nur bis zum nächsten STOP/START von FHEM.

Natürlich Kann ich jederzeit mit einem wget die iCal Datei runterladen ohne Fehler.
Da scheint der Request vom Modul wohl irgendetwas anderes zu machen.

Evtl. Jemand eine Idee und kann mir helfen/erklären warum das Modul ein "503 Service Unavailable" liefert ?

Gruß,
JudgeDredd

[Dr. Boris Neubert]

Hi,

kannst Du bitte mal die Verbosity auf 5 hochdrehen und das Log nach

Code Auswählen Erweitern

set cal_MSE00A update

posten (vertrauliche Daten entfernen), wenn die Fehlersituation auftritt?

Viele Grüße
Boris

[JudgeDredd]

Hallo Boris,

vielen Dank daß Du mal ein Auge drauf werfen möchtest.
Das Debug hatte ich mir die Tage auch schonmal angesehen, aber erhellt hat es mich nicht.

Debug:

Code Auswählen Erweitern

HTTP/1.1 503 Service Unavailable
Cache-Control: no-cache, no-store
Pragma: no-cache
Content-Type: text/html; charset=utf-8
Expires: -1
Server: Microsoft-IIS/8.0
request-id: 2343e322-6700-45fe-bcf6-4ad99955029c
Set-Cookie: ClientId=LOGFRCVH0PFQSCGSEARW; expires=Mon, 26-Apr-2021 07:00:42 GMT; path=/; HttpOnly
X-CalculatedBETarget: exdag04-1.exchange.int
X-Content-Type-Options: nosniff
X-OWA-Error: Microsoft.Exchange.Data.Directory.SystemConfiguration.OverBudgetException
X-DiagInfo: EXDAG04-1
X-BEServer: EXDAG04-1
X-UA-Compatible: IE=EmulateIE7
X-AspNet-Version: 4.0.30319
Set-Cookie: X-BackEndCookie=; expires=Thu, 26-Apr-1990 07:00:42 GMT; path=/owa/calendar; secure; HttpOnly
Set-Cookie: OutlookSession=d277419c5dd1476d4daa39b9b4336407; path=/; HttpOnly
X-Powered-By: ASP.NET
X-FEServer: EXFE07
Date: Sun, 26 Apr 2020 07:00:42 GMT
Connection: close
Content-Length: 1465

Danach kommt logischerweise noch ein:

Code Auswählen Erweitern

Calendar cal_MSE00A: retrieved no or empty data

Gruß,
JudgeDredd

[Dr. Boris Neubert]

Hallo,

ich meinte, Du solltest alle Einträge des Kalenders aus dem FHEM-Log zeigen, nicht nur den Reply des Webservers.

Viele Grüße
Boris

[Otto123]

Hi,

ich denke ja der Exchange Server verweigert in dem Moment die Anmeldung bzw. es dauert zu lange bis er den Kalender zur Verfügung stellt. Ein regelmäßiges Update (Zeitraum?) verläuft immer ohne Fehler?

Die HTTP Antwort sagt (mir) ja nicht das der Client ein Problem hat, sondern das der HTTP Server Probleme hat die angeforderten Daten bereit zustellen. Wobei es sein kann, dass er Probleme mit der Anmeldung des Clients haben könnte.

Zur Fehlersuche könnte es auch helfen, das Log vom Microsoft IIS zu analysieren.

Gruß Otto

[JudgeDredd]

ich meinte, Du solltest alle Einträge des Kalenders aus dem FHEM-Log zeigen, nicht nur den Reply des Webservers.

Kein Problem, aber so viel mehr ist es leider auch nicht:

Code Auswählen Erweitern

2020.04.28 11:45:07 4: Calendar cal_MSE00A: Wakeup
2020.04.28 11:45:07 4: Calendar cal_MSE00A: Updating...
2020.04.28 11:45:07 4: Calendar cal_MSE00A: Getting data from URL <hidden>
2020.04.28 11:45:07 1: Calendar cal_MSE00A: retrieval failed with HTTP response code 503
2020.04.28 11:45:07 5: Calendar cal_MSE00A: HTTP response header:
HTTP/1.1 503 Service Unavailable
Cache-Control: no-cache, no-store
Pragma: no-cache
Content-Type: text/html; charset=utf-8
Expires: -1
Server: Microsoft-IIS/8.0
request-id: 2343e322-6700-45fe-bcf6-4ad99955029c
Set-Cookie: ClientId=LOGFRCVH0PFQSCGSEARW; expires=Wed, 28-Apr-2021 09:45:07 GMT; path=/; HttpOnly
X-CalculatedBETarget: exdag04-1.exchange.int
X-Content-Type-Options: nosniff
X-OWA-Error: Microsoft.Exchange.Data.Directory.SystemConfiguration.OverBudgetException
X-DiagInfo: EXDAG04-1
X-BEServer: EXDAG04-1
X-UA-Compatible: IE=EmulateIE7
X-AspNet-Version: 4.0.30319
Set-Cookie: X-BackEndCookie=; expires=Sat, 28-Apr-1990 09:45:07 GMT; path=/owa/calendar; secure; HttpOnly
Set-Cookie: OutlookSession=d277419c5dd1476d4daa39b9b4336407; path=/; HttpOnly
X-Powered-By: ASP.NET
X-FEServer: EXFE07
Date: Tue, 28 Apr 2020 09:45:07 GMT
Connection: close
Content-Length: 1465
2020.04.28 11:45:07 1: Calendar cal_MSE00A: retrieved no or empty data
2020.04.28 11:45:07 4: Calendar cal_MSE00A: Checking times...


Zur Fehlersuche könnte es auch helfen, das Log vom Microsoft IIS zu analysieren.

Ja, das wäre mir auch am liebsten, aber es ist ein Hosted-Exchange. Daher wird das mit den Logs nicht so einfach.

Ein regelmäßiges Update (Zeitraum?) verläuft immer ohne Fehler?

So ist der Ablauf:

• Alle Kalender  Updates laufen komplett ohne Fehler.
• Dann stoppt nachts ein maintenance Script den FHEM-Service, erledigt Dinge wie Backup, Update, etc.
• Dann wird der FHEM-Service wieder gestartet.
• Danach liefert das Kalender Update den Fehler 503
• Morgens geht dann der tolle Admin (ich  ) hin und klickt bei jedem Kalender einmal auf die DEF und auf MODIFY
• Jetzt läuft der Update Prozess wieder ohne Fehler bis zum nächsten maintenance

Zur Info:
Auch wenn ich manuell den FHEM-Service restarte, erhalte ich danach den 503.

[Otto123]

Muss es modify sein? Oder geht auch ein

Code Auswählen Erweitern

set cal_MSE00A update

[JudgeDredd]

Muss es modify sein? Oder geht auch ein

Code Auswählen Erweitern

set cal_MSE00A update

Mmmh, bei einem Adhoc untertage Test scheint es auch nach einem manuellen Update zu funktionieren.
Das würde ich aber morgen früh lieber nochmal verifizieren

[herrmannj]

mgl nicht relevant, trotzdem: ich habe vor kurzem 503 in einem anderen modul gesehen. Da war die Ursache im http-header accept und Content-Type (beim request). Vmtl war der server einfach blöd. Ohne ging es dann.

[Otto123]

Wenn es geht, dann muss es ja irgendein Zeitproblem beim Start sein - ohne eine wirklich eine Idee zu haben wo genau.

Ein würgaround wäre dann zumindest

Code Auswählen Erweitern

define FHEMinit notify global:INITIALIZED sleep 60;; set cal_MSE00A update

Ich will nicht sagen, dass der Server blöd ist, aber OWA ist zumindest speziell

[Dr. Boris Neubert]

Mmmh, bei einem Adhoc untertage Test scheint es auch nach einem manuellen Update zu funktionieren.
Das würde ich aber morgen früh lieber nochmal verifizieren

Das beruhigt mich etwas. Ich wüsste nämlich nicht, wo das Device ein Gedächtnis haben sollte, das durch Neuanlage zerstört wird.

Ich warte Deine Rückmeldung ab.

Ggf. müssen wir an den Request-Header ran, wie Joerg schreibt, wobei der ja untertägig keine Probleme zu machen scheint. Du machst doch untertägige Updates, oder?

[JudgeDredd]

Du machst doch untertägige Updates, oder?

Ja klar alle 15 Min. (900 Sek.)

Wir (oder besser ich) schaue dann mal morgen ....

[Otto123]

Ok nochmal nachgedacht:

erhalte ich
bei jedem Kalender Update-Zyklus im Log die Fehlermeldung:

Bedeutet ja: früh abgelehnt und dann für immer raus? Da bin ich mal gespannt ob ein update nach dem Neustart wirklich hilft.

@Boris Was macht er denn beim modify? update reload oder was anderes?

[Dr. Boris Neubert]

@Boris Was macht er denn beim modify? update reload oder was anderes?

Modify schmeißt das Device weg und legt es neu an. Danach läuft ein reload mit Zeitverzögerung.

Das entspricht Deinem Vorschlag von heute Mittag. Der passiert aber sowieso 10 bis 30 Sekunden nach der Initialisierung oder Neuladen der Konfiguration.

Das Modul hat kein Gedächnis.

@JudgeDredd: wenn das mit dem update nicht hinhaut: kannst Du bitte mal das Calendar-Device in eine separate Instanz von FHEM vereinzeln und sehen, ob das Problem dann auch noch auftritt?

[JudgeDredd]

Hallo,

es gibt ein paar neue Erkenntnisse.
Zum einen bleibt es dabei, das ein

Code Auswählen Erweitern

set cal_MSE00A update
ausreicht, den 503 Response-Fehler bis zum nächsten FHEM-Neustart zu beheben.

Mir ist noch eingefallen, das ich noch nicht allzu lange 3 Exchange Kalender in FHEM integriert habe. Daher bin ich mal in den Logs rückwärts gegangen und zu dem Zeitpunkt als es noch 1 Kalender war, überlebte das Update auch den FHEM-Neustart ohne Fehler.
Also erst seitdem ich mehrere (3 aktuell) verwende, tritt das Problem auf.
Ich habe den Updateintervall auch schon auf unterschiedliche Längen eingestellt, allerdings ohne Erfolg.
Kann es sein, das das Modul beim Start alle Kalender sofort abfragt ? Sollte das das Problem sein, dann wäre es aber merkwürdig, das der nächste Aufruf (der ja unterschiedlich erfolgt) auch fehl schlägt.

Gruß,
JudgeDredd