Alarm Alarm
Was so sicher ist wie das “Amen in der Kirche”, das ist, dass aktuell sicher viele Exchange Systemingenieure, Administratoren und Dienstleister in Microsoft Exchange Umgebungen eine Migration von Exchange 2000/2003 auf Exchange 2007 durchführen. Dabei gibt es derzeit eine Besonderheit, in die vielleicht schon einige gelaufen sind ohne es zu wissen.
Es kam also der Zeitpunkt, dass nach einer ausführlichen und sauberen Exchange 2007 Planung, diversen Tests mit positiven Ergebnissen, auch die ersten produktiven Postfächer mit der Exchange 2007 Management Console auf den neu installierten Exchange 2007 CCR-Cluster migriert werden konnten. Unter Verwendung des “Move Mailbox Wizards” wurde jede Nacht zeitgesteuert ein Migrationsjob eingestellt, welcher anfangs eine kleine Anzahl und später auch viele Postfächer am Stück automatisiert nach Exchange 2007 migrierte.
Wir waren begeistert wie gut die Migration voran ging, bis eines Morgens das Monitoring System meldete, dass die Anzahl der Exchange Transaktionsprotokolldateien dramatisch anstieg und die Kapazität der DB Logfile-Festplatte gegen Null ging. Im letzten Blog Beitrag habe ich bereits von der Aktion mit dem vollgelaufenen Logfile-Laufwerk berichtet.
Such den Fehler
Ein Blick in die Windows Anwendungs-Eventlogs der beiden CCR-Cluster Knoten ließ uns “rot sehen“. Da waren endlos viele der folgenden drei Fehlermeldungen vorhanden, die sich ewig wiederholten…
Application Eventlog:
Event Type: Error
Event Source: EXCDO
Event Category: General
Event ID: 8199
Date: 21.09.2007
Time: 03:35:28
User: N/A
Computer: <ClusterNodeName>
Description:
Calendaring agent failed in message save notification with error 0×800703eb on <EMailAdresse@domain.de>:
/Kalender/xxxxxyyyyyzzzzz.EML.
Application Eventlog:
Event Type: Error
Event Source: EXCDO
Event Category: General
Event ID: 8206
Date: 21.09.2007
Time: 03:35:28
User: N/A
Computer: <ClusterNodeName>
Description:
Calendaring agent failed with error code 0×80040215 while saving appointment.
Application Eventlog:
Event Type: Error
Event Source: EXCDO
Event Category: General
Event ID: 8213
Date: 21.09.2007
Time: 03:35:28
User: N/A
Computer: <ClusterNodeName>
Description:
Calendaring agent failed to update the free/busy cache during an appointment save or delete operation.
“Calendaring Agent” Fehlermeldungen also… ich erinnerte mich, dass wir unter Exchange 2000 schon einmal eine ähnliche Situation hatten… die Geschichte mit “MSExchangeFBPublish” und dem fehlenden Eintrag in der Registry. Eine kurze Suche in der Microsoft KnowledgeBase brachte mir dann auch wieder den Artikel, der damals geholfen hatte…
310440 You receive an “unable to perform the operation” error message when you save Calendar items in Exchange 2000 and Exchange 2003
Kurz die Werte in der Registry beider Clusterknoten überprüft und wir konnten ausschliessen, dass dies die Lösung war. Schade! Also weitersuchen…
Bei den sich wiederholenden Event IDs im Anwendungs-Eventlog war zu erkennen, dass es sich nicht nur um ein Postfach, sondern um mehrere, genau genommen um drei Postfächer handelte. Da bereits viele andere produktive Postfächer auf dem Exchange 2007 Server arbeiteten, konnten wir nicht lange experimentieren und so wurden die drei problematischen Mailboxen zurück nach Exchange 2000 verschoben.
Ich hatte die Vermutung, dass eventuell inkonsistente Elemente in den Postfächern waren und dass der “Move Mailbox Wizard” beim Zurückverschieben vielleicht diese Fehler erkennt, meldet und “korrigiert”, bzw. die möglichen defekten Elemente nicht mit verschiebt. Aber Pustekuchen! Auch nicht ein fehlerhaftes Element wurde beim zurück migrieren gefunden.
Immerhin war nach dem Verschieben der Postfächer jetzt aber Ruhe im Eventlog. Also als Gegenprobe das selbe Postfach wieder von Exchange 2000 Richtung 2007 zurück migrieren, in der Erwartung, dass der Fehler reproduziert werden kann.
Und wirklich… kaum liegt das eine der drei problematischen Postfächer wieder auf der 2007er Maschine – schon geht der Ärger wieder los und die “Calendaring Agent” Fehlermeldungen (EXCDO 8199, 8206 und 8213) kommen zurück. Nicht schön, aber immerhin ist eine Reproduktion möglich!
Aufgrund der besonderen Brisanz der Situation, haben wir die folgenden Schritte gemeinsam mit MS PSS (Microsoft Product Support Services) durchgeführt.
Beim Öffnen eines Microsoft Case ist es immer von Vorteil direkt einen aktuellen ExBPA-Auszug und einen MPSReport mitzuschicken und so haben wir diese auch gleich noch schnell vorab eingesammelt.
Das Microsoft Exchange Support Team hat schnell die Brisanz der Situation erkannt. Der Case wurde entsprechend hoch priorisiert und nach wenigen Stunden und dem Durchlaufen der Standardanalysen hatten wir den passenden “Escalation Engineer” im Boot.
Wir kamen jetzt in die Situation, wo ein weiteres Postfach plötzlich begann die bekannten Fehler auf dem Exchange Server zu produzieren und auch dieses Postfach musste zur Sicherheit seinen Weg zurück nach Exchange 2000 gehen. Sehr seltsam alles… Postfächer, die offensichtlich unter Exchange 2007 erst sauber funktionieren und zu irgendeinem Zeitpunkt fehlerhaft werden und dann sogar den Server selbst stören. Alle Beteiligten forschten nun parallel in unterschiedliche Richtugen…
- Ich begab mich mit meinem besten “virtuellen Freund” GOOGLE auf die Suche nach dem Unbekannten
- Unser Microsoft Engineer forderte einige unserer Exchange Transaction Logs vom kritischen Zeitpunkt, um diese anhand eines interessanten Blog Artikels von Scott Oseychik hinsichtlich der Inhalte zu analysieren
- …und ein Kollege versuchte ein leeres Postfach auf Exchange 2007 mit Daten eines der kritischen Postfächer zu befüllen, um eine weitere Reproduktion zu erzielen
In die richtige Richtung geforscht
Kaum zu glauben, aber alle drei Richtungen in die wir forschten brachten Ergebnisse und trugen ein Puzzlestück zur Findung der Ursache bei.
Meine GOOGLE-Suche ergab, dass tatsächtlich zumindest noch ein weiterer Mensch auf dieser Welt exakt das gleiche Fehlerbild wie wir hatten. Zyg Furmaniuk aus Cambridge (Massachusetts) berichtet in seinem Blog Posting vom selben Problem und er liefert uns sogar handfeste Ergebnisse von seinen Analysen.
Der Ansatz unseres Microsoft Engineers brachte als Ergebnis, dass eine ungewöhnlich hohe Anzahl an Transaktionen zu Terminen innerhalb der Logfiles zu sehen waren…
…
576 Geburtstag von J
576 ln) [Geburtstag%3B Nat
1107 IPM.Microsoft.ScheduleData.FreeBusy
1261 anrufen nicht vergessen) [Einkaufen%3B Geburtstag%3B Nat
6457 ln) [Party%3B Hans%3B Nat
6958 Geburtstag Markus
17397 IPM.Appointment.Termin
69758 IPM.Appointment.Termin
...
Die Aktion mit dem Import der Daten aus einem kritischen Postfach brachte das gleiche Ergebnis wie in Zyg Furmaniuks Blog Beitrag. Beim Import kam genau an der Stelle, bei der mehr als 1300 Objekte im Kalender waren die folgende Speicherfehlermeldung.
Für diesen Vorgang steht nicht genügend Arbeitsspeicher zur Verfügung.
Die Reproduktion des Fehlers ist denkbar einfach...
- einfach 1300 Serientermine in einem Echange 2007 Postfach erstellen
- beim Erstellen eines weiteren Serientermins kommt dann ohne Umwege die Fehlermeldung (unten)
- im Exchange Application Eventlog tauchen die EXCDO Calendaring Fehler auf
- und es ist auffällig, dass für einen Moment viele Exchange Transaktionprotokolle geschrieben werden
Aber Was ist denn nun die Ursache?
Unser Microsot Engineer stellte nun weitere Nachforschungen an.
Und tatsächlich im Code von Exchange 2007 ist offensichtlch ein Verhalten ersichtlich, das auch in der Vergangenheit schon einmal existiert hat. Bei mehr als 1300 "Recurring Appointments" (Serienterminen) hat Exchange eine feste Begrenzung im Code und übergibt Outlook einen Speicherfehler.
Das unter Exchange 2000 und 2003 bestandene Verhalten wurde bereits mit folgenden Softwareaktualisierungen bei den "alten Exchange Versionen" behoben:
- in Exchange 2000 >>> gefixt mit Update Rollup Paket Januar/Februar 2005
- in Exchange 2003 >>> gefixt mit Service Pack 1
Etwas seltsam ist das Verhalten von Exchange 2007 selbst mit migrierten Postfächern, die über 1300 Serientermine aufweisen. Erst an einem undefinierten Zeitpunkt (dies ist offensichtlich nicht zwingend der Zugriff per MAPI oder Exchanage ActiveSync auf den Kalender) merkt Exchange, dass sich zuviele Serientermine im Kalender befinden. Wenn Exchange dies aber erkannt hat, dann versucht der "Calendaring Agent" permanent das Objekt neu zu schreiben. Damit beisst sich die Ratte in den Schwanz zu Lasten der Anzahl an Exchange Transaktionen.
Problem erkannt - Gefahr gebannt?
Nun ja, zwar lässt die manuelle Reproduktion des Fehlers nicht mehr als 1300 Serientermine zu, was aber tückisch zu sein scheint ist, dass der "Exchange 2007 Move Mailbox Wizard" bei der Migration der Postfächer die Kalender mit mehr als 1300 Serienterminen erst mal anstandslos migriert.
Als Workaround bleibt uns aktuell nur das Feststellen, ob mehr als 1300 "Recurring Appointments" (Serienterminen) in einem Postfach vorliegen und dann entsprechend das Verlagern des Postfachs auf einen Exchange 2000/2003 Server.
Zur Analyse gibt es vier gute Ansätze:
1.) Prüfung eines einzelnen Postfachs direkt über Outlook selbst
Eine einfache Variante ist es, dass Postfach mit Outlook primär zu öffenen, den Kalender auszuwählen und über folgenden Weg die Ansicht des Kalenders auf "Terminserien" umzustellen:
In Outlook 2003/2007...
- Kalender auswählen
- Menü "Ansicht" auswählen
- Punkt "Aktuelle Ansicht" auswählen
- Die Ansicht "Terminserien" aktivieren
Wenn man nun "Alle Gruppen reduzieren" (Rechtsklick im rechten Fensterbereich) wählt, dann bekommt man eine Übersicht über die Anzahl der Serientemrine im Kalender
2.) Prüfung eines einzelnen Postfachs über ein separates Outlook Profil in Verbindung mit einem kleinen VBScript von Microsoft PSS
Const olFolderCalendar = 9
Counter =0
Set objOutlook = CreateObject("Outlook.Application")
Set objNamespace = objOutlook.GetNamespace("MAPI")
Set objFolder = objNamespace.GetDefaultFolder(olFolderCalendar)
Set colItems = objFolder.Items
Set colFilteredItems = colItems.Restrict("[IsRecurring] = TRUE”)
For Each objItem In colFilteredItems
Set objPattern = objItem.GetRecurrencePattern
If objPattern.PatternEndDate > Now Then
counter = counter + 1
End If
Next
Wscript.Echo “Counter steht auf ..” & counter
Das VBScript durchläuft den Kalender Ordner des aktuellen Outlook Profils und zählt die vorhandenen Serienterminen, welche am Ende in einem Internet Explorer Fenster ausgegeben werden…
3.) Prüfung aller Postfächer zentral über das VBScript “TerminCount.vbs” von Frank Carius (MS Exchange FAQ)
Frank hat uns wie immer schnell und kompetent unterstützt und eines seiner bereits bestehenden Skripte umgeschrieben, welches per CDO über alle Exchange Postfächer läuft, die Anzahl der Serientermine zählt und diese in einer XML-Datei ausgibt.
Hier gehts zum Artikel auf der “MS Exchange FAQ”:
http://www.msxfaq.de/tools/termincount.htm
So schaut das ganze während der Analyse aus…
4.) Prüfung von bereits auf Exchange 2007 migrierten Postfächern mittels PowerShell Befehl
Mit dem folgenden PowerShell Befehl kann man zwar nicht die Anzahl der Serientermine festellen, aber man kann zumindest prüfen ob Postfächer mit mehr als 1300 Terminen vorliegen, die dann z.B. weiter geprüft werden können…
Get-MailboxFolderStatistics -identity “mohmeyer” | ft folderpath,foldersize,itemsinfolder -AutoSize
Die zentrale Frage: BUG oder Feature?
Ob sich die Developer von Exchange 2007 mit dieser Grenze etwas gedacht haben, oder ob das in Exchange 2000/2003 bereits behobene Verhalten tatsächlich ein Codierungsfehler ist, der als BUG festgestellt wird, ist aktuell in Klärung. Ich werde hier im Blog zu entsprechender Zeit darüber berichten.
Mein Tipp ist, dass Microsoft in Kürze einen Hotfix dazu liefert, der sicher auch im nächsten Update Rollup Paket für Echange 20007 und vielleicht sogar auch noch im SP1 seinen Platz finden wird. Wir werden sehen.
Mein Fazit
Wer aktuell ein Exchange 2007 System aufbaut oder eine Exchange 2007 Migration durchführt, der sollte dringend prüfen, ob es Postfächer mit mehr als 1300 Serienterminen in der Umgebung gibt. Gerade wenn Mitarbeiter über Jahre mit Postfächern arbeiten, die nicht archiviert werden, oder wenn z.B. Kundendaten wie wiederkehrende Geburtstage gepflegt werden, dann besteht eine hohe Wahrscheinlichkeit, dass man in diese Problematik läuft. Die oben genannten Vorgehensweisen helfen bei der Festellung und beim umgehen des Fehlers.
Es hat sich auch einmal wieder gezeigt, wie wichtig und hilfreich ein entsprechender Supportvertrag mit Microsoft beim Betrieb einer komplexen Exchange Umgebung ist. Die Aktion hat ebenso deutlich gemacht, wie wichtig eine funktionierende Überwachung der Systeme ist und dass gerade dort im Zusammenhang mit Exchange nicht gespart werden darf.
Links zum Thema
Blogartikel von Zyg Furmaniuk aus Cambridge, der von selbem Problem berichtet
http://calendarservermigration.blogspot.com/2007/06/how-many-recurring-appointments-does-it.html
Blogartikel “Rough and Tough” guide to identifying patterns in Transaction Logs” von Scott Oseychik
http://blogs.msdn.com/scottos/archive/2007/07/12/rough-and-tough-guide-to-identifying-patterns-in-ese-transaction-log-files.aspx
Artikel zum VBScript “TerminCount.vbs” von Frank Carius
http://msxfaq.de/tools/termincount.htm
Keywords: Exchange 2007 BUG EXCDO 8199 8206 8213 Serientemrine Recurring Appointments