theHacker's Blog
– It's just a glitch in the Matrix –

Synology-Kalender: Termin lässt sich nicht ändern

Seit langer Zeit benutze ich den Kalender von Synology und bin bis heute eigentlich sehr zufrieden. Bis auf die Tatsache, dass sich manchmal Termine nicht mehr nachträglich ändern lassen.

Heute gehe ich diesem Problem auf den Grund…

Mein Setup

Bevor wir richtig einsteigen, skizziere ich kurz mein Setup.

Mein Kalender befindet sich in meiner Cloud auf einer Synology-NAS. Hierzu ist auf der NAS das Calendar-Paket installiert. Das Paket stellt den Kalendar dann via CalDAV im Netzwerk bzw. Internet bereit.

Unterwegs kann ich mit meinem Android-Handy dann über die normale Kalender-App auf diesen Kalender zugreifen. Ein Kalender-Adapter ist hier noch im Spiel, aber das würde jetzt zu stark ins Detail gehen…

Zu Hause verwende ich Thunderbird mit der Lightning-Extension, um auf den Kalender zuzugreifen.

Damit habe ich alle meine Termine zentral gespeichert, sie befinden sich nicht bei Google & Co zum automatischen Analysieren für nutzer-spezifische Werbung, und ich kann von überall drauf zugreifen.

Das Problem

Kommen wir nun zum Problem. Dank der immer noch anhaltenden Corona-Panik habe ich öfters den Fall, dass ich einen Termin, der schon vor langer Zeit in den Kalender gelegt wurde, jetzt absagen muss.

Eigentlich ist das keine große Sache. Man öffnet den Termin im Thunderbird und klickt im Menü „Einstellungen / Status“ den Punkt „Abgesagt“. Danach kann man den Termin speichern und ist fertig.

Das Problem ist nun, dass – ohne eine visuelle Information – der geänderte Termin nicht gespeichert wurde. Bei einer Änderung des Status oder der Beschreibung merkt man das nicht direkt. Es fällt nur auf, wenn man den Titel oder den Zeitpunkt ändert.

Interessant ist auch, dass es nicht wirklich 100%ig reproduzierbar ist. Ich habe alle Felder schon einmal erfolgreich ändern können. An bestimmten Feldern liegt es also nicht.

Merke ich, dass eine Änderung nicht funktioniert hat, so kann ich bestätigen, dass man den Termin dann gar nicht ändern kann. Dabei ist es egal, in welchem Feld ich eine Änderung mache.

Das Problem im Detail

Die Ursache, warum die Änderung nicht greift, kann man relativ schnell ermitteln: Startet man Thunderbird über die Konsole, findet man die Information direkt. Ein anderer Weg ist im Menü „Extras / Entwickler-Werkzeuge“ die Fehlerkonsole zu öffnen. Hier bekommt man sogar noch die genaue Codestelle in der Kalender-Extension, wo der Fehler aufgetreten ist: Lightning: CalDAV: Unexpected status modifying item to (Kalendername): 405 in calDavCalendar.js:863.

Das bedeutet erstmal, dass Thunderbird, also Lightning unschuldig scheint und der Übeltäter wohl die Synology-NAS ist. – Ich bin mit einer konkreten Schuldzuweisung an dieser Stelle noch vorsichtig, da ich nicht weiß, welche Daten zwischen den beiden ausgetauscht werden. Fakt ist jedoch, dass sich die NAS weigert, den Termin im Kalender zu speichern.

Datenfluss zwischen Lightning und Synology-NAS im Detail

Um etwas tiefer in das Problem zu gucken, müssen wir nun den Traffic untersuchen, der zwischen Client und Server fließt. D. h. welche Daten werden zwischen Lightning und Synology-NAS ausgetauscht?

Kurzer Exkurs: CalDAV ist eine Erweiterung von WebDAV, welches wiederum auf HTTP basiert.

Normalerweise ist HTTP einfach zu debuggen, weil alles schön in Textform lesbar ist. Etwas schwierig ist das Debugging in diesem Fall, da nicht direkt HTTP benutzt wird, sondern HTTPS. Der Traffic zwischen Client und der NAS ist verschlüsselt und man sieht im Wireshark absolut gar nichts.

Aber auch das ist einfach gelöst, indem man für die Debugging-Session kurzfristig mit SSLKEYLOGFILE arbeitet. Damit werden die Schlüssel für sämtliche SSL-Kommunikation in eine Datei geschrieben und Wireshark kann diese lesen und den Traffic entschlüsseln.

Ich möchte an dieser Stelle auch noch kurz ergänzen, dass ich bei der Fehleranalyse in Thunderbird bewusst HTTP2 deaktiviert habe, um mir das Leben leichter zu machen. HTTP2 optimiert die Kommunikation und bündelt mehrere Requests in einem Stream. Auch machen die Binärdaten zwischendrin das Lesen schwieriger.

Der Request sieht normal aus. Wir sehen einen PUT-Request mit dem geänderten Termin.

Die Response sieht etwas komisch aus, da der Body nur eine „0“ enthält (und keinen Content-Length-Header). Ich habe auch kurz mit HTTP2 ausprobiert, da haben wir eine leere Response.

D. h. hier keine Informationen, was nun das Problem ist. Allerdings bekommen wir einen kleinen Einblick in den Synology-Kalender: X-DAViCal-Version: DAViCal/1.1.9; DB/1.2.12 zeigt uns, dass Synology hier den freien Kalender-Server DAViCal einsetzt und welche Version verwendet wird.

Auf der Suche nach der Problemlösung

Wir wissen bereits, dass der Server bei bestimmten Terminen HTTP 405 antwortet. Ich sehe hier zwei Möglichkeiten

  • Der Termin ist „kaputt“. In diesem Fall ist das Problem in der Server-Programmlogik und ich kann als Client nichts dagegen machen. Egal, welche Daten ich für den Termin schicke, die Antwort wird immer HTTP 405 bleiben.
  • Der Server akzeptiert bestimmte Daten nicht, die sich aktuell im Termin befinden. In diesem Fall kann ich den Termin „reparieren“, indem ich jene Daten entferne, die dem Server Probleme machen.

Falls die erste Möglichkeit zutrifft, hab ich keine Lösung. Die DAViCal-Version ist minimal out-of-date (aktuelle Version 1.1.9.3), aber das bringt mir nichts, solange Synology kein Update für das Calendar-Paket anbietet. Also selbst bei einem Bug in der Server-Software hab ich verloren.

Trial & Error: Manuelles Senden von Requests an den Synology-Kalender

Nur die zweite Möglichkeit bietet mir überhaupt eine Erfolgsaussicht. Hierzu werde ich nun manuell verschiedene Requests an den Server schicken und solange an den Daten rumschrauben, bis der Server den Termin akzeptiert.

Aus den Informationen von Wireshark über den Request habe ich alles, was ich brauche:

  • die URL, unter der der Termin auf dem Server abgespeichert ist
  • die Zugangsdaten (die hab ich sowieso, aber in Form eines HTTP-Authorization-Headers ist das angenehmer)
  • das ETag des Termins (siehe der If-Match-Header)

Zum Senden des Requests verwende ich curl.

Als ersten Schritt möchte ich überhaupt erstmal wissen, was auf dem Server zu diesem Termin gespeichert ist. Damit kann ich den Ist-Stand sehen.

thehacker@ares:~$ curl -k -H "Authorization: Basic XXXXXX" https://iris:5001/caldav/admin/home/ome/20200311T004651-fe7e189b%40192.168.178.20.ics
Resource Not Found.

Das ist schon mal extrem interessant. Der Server meldet 404, den Termin gibt es überhaupt nicht! Damit ist es auch logisch, dass der Server sich beschwert, wenn man ihn versucht zu ändern. Entsprechend folgern wir auch, dass die Daten des Termins irrelevant sind.

Als nächsten Schritt möchte ich die echte URL des Termins rausfinden. Der Termin existiert ja irgendwo, nur nicht da, wo ihn Thunderbird ändern möchte.

Ich lege eine Datei report.xml an und sende einen REPORT-Request:

<c:calendar-query xmlns:d="DAV:" xmlns:c="urn:ietf:params:xml:ns:caldav">
    <d:prop>
        <d:getetag />
        <c:calendar-data />
    </d:prop>
    <c:filter>
            <c:comp-filter name="VCALENDAR" />
    </c:filter>
</c:calendar-query>
thehacker@ares:~$ curl -k -X REPORT -H "Authorization: Basic XXXXXX" -d @report.xml https://iris:5001/caldav/admin/home/ > output.txt

Damit lade ich sämtliche Termine aus dem Kalender in die Datei output.txt. Diese Datei kann ich nun mit einem Text-Editor nach dem Termin durchsuchen. Ich werde auch fündig:

<response>
  <href>/caldav.php/admin/home/20200311T004651-fe7e189b%40192.168.178.20.ics</href>
  <propstat>
   <prop>
    <getetag>"a36c58a79f2b49c970c2f993c7e99670"</getetag>
    <C:calendar-data>BEGIN:VCALENDAR^M
VERSION:2.0^M
PRODID:+//IDN bitfire.at//DAVx5/3.1.1-gplay ical4j/3.0.19^M
BEGIN:VEVENT^M
UID:20200311T004651-fe7e189b@192.168.178.20^M
...
</C:calendar-data>
   </prop>
   <status>HTTP/1.1 200 OK</status>
  </propstat>
 </response>

Die URLs unterscheiden sich doch etwas. Der grundsätzliche ID-Part am Ende ist zwar identisch, aber am Anfang hat der Server noch eine .php-Endung am caldav stehen. Ausprobieren zeigt, dass es egal ist, ob man die .php-Endung anfügt oder nicht. Der Server reagiert auf beides gleichermaßen.

Interessant ist aber das /ome/ in der falschen URL. Die Kalender-Objekte erwarte ich flach im Kalender (keine Ahnung, ob CalDAV Verzeichnisstrukturen innerhalb eines Kalenders überhaupt erlaubt). Vergleicht man falsche und korrekte URL genauer, erkennt man, dass der Unterschied an beiden Stellen gleich lang ist. .php ist genauso lang wie /ome. Und /ome ist ein Teil von home.

falsche URL/caldav/admin/home/ome/20200311T004651-fe7e189b%40192.168.178.20.ics
korrekte URL/caldav.php/admin/home/20200311T004651-fe7e189b%40192.168.178.20.ics

Es sieht so aus, als ob hier eine String-Ersetzung mächtig schiefgelaufen ist. Und diese muss dann wohl in der Lightning-Extension von Thunderbird liegen!

Debugging von Lightning

Ich habe nun zwar das Problem und die Ursache, aber noch keine Lösung. Hierzu muss ich nun den Quellcode der Lightning-Extension weiter untersuchen und ermitteln, wie die URL zusammengebaut wird, die später zum Senden des PUT-Requests verwendet wird.

Debugging mit den Entwicklerwerkzeugen

Thunderbird bietet zwar einen Punkt „Add-ons debuggen“ im Menü Entwickler-Werkzeuge, der genau richtig zu sein scheint. Allerdings, wenn man dann auf „Debuggen“ klickt und der Debugger sich öffnet, muss man zur Ernüchterung feststellen, dass keine Sourcen verfügbar sind. D. h. hier kommen wir nicht weiter.

Was hingegen funktioniert, ist der Punkt „Entwickler-Werkzeugkasten“, auch im Entwickler-Werkzeuge-Menü zu finden. Hier kommt vorher eine Sicherheitsabfrage, dass Ports zum Debugging geöffnet werden. Nach Bestätigung öffnet sich der Debugger und wir sehen alle Sourcen, inklusive der Lightning-Extension. Auch das Anlegen von Haltepunkten ist hier ohne Probleme möglich.

Ich kann das Problem auf einen ungültigen Eintrag in der Cache-Struktur mItemInfoCache zurückführen, wo der falsche ome/-Pfadausdruck enthalten ist. Eine Suche nach dieser Variable findet 30 Treffer in der JavaScript-Datei. Interessant ist besonders eine Stelle (in Zeile 334), weil hier ein Aufruf an substr() gemacht wird. Ich denke, wir stehen dem Übeltäter hier von Angesicht zu Angesicht gegenüber.

Dummerweise greift ein Haltepunkt hier nicht. Ich vermute, der Code wird einmalig beim Start aufgerufen. Um mich nicht tiefer in die Materie „Wie debugge ich eine Thunderbird-Extension?“ einlesen zu müssen, greife ich auf einen altbewährten Trick zurück: printf-Debugging 🙂

printf-Debugging

Die Erweiterung ist im Thunderbird-Profil unter extensions/{e2fda1a4-762b-4020-b5ad-a41df1933103}.xpi zu finden. Das ist eine Zip-Datei, die man vorher auspacken kann. Thunderbird kann sowohl mit gezippten, als auch mit ausgepackten Erweiterungen umgehen, was die Sache für mich einfacher macht.

Beim ersten Start nach dem Auspacken hat er sich zwar beschwert und die Erweiterung nicht geladen. Ein weiterer Start hat die Situation dann normalisiert. Ich habe in die Methode fetchCachedMetaData(), wo ich den Bug vermute, eine Zeile mit cal.ERROR("Test...") reingeschrieben und, siehe da, beim Start sehe ich diese Ausgabe:

console.log: WebExtensions: Loading unpacked extension from /home/thehacker/Thunderbird-Profil/extensions/{e2fda1a4-762b-4020-b5ad-a41df1933103}
console.log: WebExtensions: Loading add-on preferences from  /home/thehacker/Thunderbird-Profil/extensions/{e2fda1a4-762b-4020-b5ad-a41df1933103}
console.log: WebExtensions: Firing profile-after-change listeners for {e2fda1a4-762b-4020-b5ad-a41df1933103}
[calBackendLoader] Using Thunderbird's builtin libical backend
console.error: Lightning: 
  TEST - diese Meldung kommt vom Debugging
console.error: Lightning: 
  TEST - diese Meldung kommt vom Debugging

Nun prüfe ich konkret die Variablen, wo ich den Fehler vermute.

In den cacheValues haben alle URLs die korrekte Form. Keine Spur von /ome/-Artefakten. Nach dem ominösen substr() sind die URLs aber wie erwartet kaputt.

Bug bestätigt! 😎

Zusammenfassung des Problems und seiner Ursache

Das Problem hier ist, dass Synology intern seine Termine mit /caldav.php/ speichert, aber nach außen hin gerne mit /caldav/ angesprochen werde möchte. Und entsprechend habe ich auch Letzteres im Thunderbird (in der Lightning-Extension) eingestellt.

Die Lightning-Extension fängt den Fall nicht ab, dass sich die URLs unterscheiden können und wendet blind eine String-Ersetzung an. Damit korrumpiert sie ihren Cache-Eintrag. Beim Ändern des Termins schlägt sie die kaputte URL aus dem Cache-Eintrag nach und bekommt vom Server dann eine Abfuhr in Form von HTTP 405.

Lösung

Ich habe lange recherchiert, ob der Bug bereits bekannt ist und bin schließlich auf Bug 605201 gestoßen, der seit knapp 10 Jahren offen ist. Hier beschweren sich Leute über das merkwürdige URL-Rewriting in Lightning, allerdings bezogen auf die Funktion addTargetCalendarItem(). Ich bin mir also nicht sicher, ob das mein Bug ist oder noch ein weiterer, der in dieselbe Kerbe schlägt.

In den Bug-Reports von Debian findet man den Bug 908249, welcher sich auf obigen Lightning-Bug bezieht, aber von den gleichen Problemen berichtet, die ich hab: Nämlich beim Ändern von Terminen, betroffen hier die Funktion doModifyItem().

Grundsätzlich sollte ein CalDAV-Client nicht an der URL manipulieren, sondern diese einfach akzeptieren. Wenn der Server sagt, der Termin wurde unter der URL who-cares abgelegt, so muss sich der Client einfach nur diese URL merken und Änderungen später wieder an dieselbe URL PUTen. Manipulation ist nicht erforderlich!

Sicher für mich ist, dass ich von Seiten der Lightning-Erweiterung nicht wirklich mit einem Fix rechne.

Selber werde ich wohl keinen Fix schreiben, da mir das zu aufwändig ist, in diesem Code weiter zu verschlimmbessern, ohne dabei noch mehr kaputt zu machen. Außerdem müsste ich idealerweise für einen korrekten Fix den kompletten Thunderbird-Buildprozess durchlaufen, da das Lightning-Extension-JavaScript, das den Bug enthält, auch nur generiert wurde aus weiterem Quellcode.

Abhilfe

Ich werde jetzt die Kalender-Einstellung im Lightning ändern und – entgegen Synologys vorgeschlagener URL – die URL mit dem .php verwenden. Damit sollten die Cache-Einträge von der Länge her wieder zusammenpassen und das Problem wäre „gelöst“ (= umgangen).

Kalender aus Lightning entfernt, Kalender mit .php in der URL wieder ergänzt und Termin geändert… funktioniert 🙂

Happy End.


Verwendest du auch eine eigene Kalender-Lösung? Welche Server- und Client-Anwendungen hast du in Verwendung?

Hat dir dieser Beitrag geholfen, so hinterlass gerne einen Kommentar.

Schreib einen Kommentar hierzu

Deine eMail-Adresse wird nicht veröffentlicht.