[gelöst] Horde Fehler bei gpg-unterschriebenen Emails

[scientific]

Bin jetzt mal auf der Dovecot-Mailingliste gelandet.

So wie es ausschaut, dürfte es doch ein Horde-Problem sein... Horde aktiviert nach einem Timeout das QRESYNC nicht mehr.
Die Frage ist, wieso es zu einem Timeout kommt...

lg scientific

[slu]

So wie es ausschaut, dürfte es doch ein Horde-Problem sein...

Hört sich spannend an, mach doch mal bei Horde ein Ticket auf und füge die IMAP Logdatei hinzu.

[scientific]

Ich möchte zuerst die Analyse meiner Logfiles (horde + dovecot) von den dovecot-Mailinglistlern durch haben, bevor ich die Pferde bei Horde aufscheuche...

Es gibt ja ein Ticket aus dem Jahr 2015 (die imapproxy-Geschichte), welches genau dieses Thema (nur nicht bei virtual-folder) behandelt. Damals war die Aussage bei Horde, dass Dovecot ziemlich sicher einen Fehler mache.
Deshalb möchte ich das auf der Dovecotliste zuerst abgeklärt haben, ob tatsächlich ein Reenablen von QRESYNC bei Horde nach einem Timeout die Ursache ist (bin ziemlich sicher, dass das auch das Ticket von Damals betreffen würde.)
Auf der Dovecot-Mailingliste sind die Antworten auch ziemlich fix da gewesen. Ich nehm an, das geht so flott weiter.

lg scientific

[scientific]

Andere Frage...
wo liegt eigentlich das mit PEAR installierte Zeugs?
Hab zwar nur Grundkenntnisse in php... aber vielleicht finde ich ja einen entscheidenden Hinweis, wo ein reenablen von QRESYNC nach einem Timeout gemacht werden kann...

Ich frag mich aber schon seit heut morgen, warum dieses Timeout überhaupt auftritt, und warum es nur bei bestimmten Emails auftritt...

lg scientific

[scientific]

Das ist dieses Timeout:

Code: Alles auswählen

S: )
S: 6 OK Fetch completed (0.004 + 0.000 + 0.003 secs).
>> Command 6 took 0,0038 seconds.
C: 7 UID FETCH 43462 (BINARY.PEEK[1])
>> ERROR: read/timeout error.
>> ERROR: Server closed the connection.
>> Connection to: imap://aldebaran.local/
>> Server connection took 0,002 seconds.
S: * OK [CAPABILITY IMAP4rev1 LITERAL+ SASL-IR LOGIN-REFERRALS ID ENABLE IDLE XDOVECOT STARTTLS AUTH=PLAIN AUTH=LOGIN AUTH=CRAM-MD5 AUTH=DIGEST-MD5] Dovecot ready.
C: 8 [AUTHENTICATE response (username: jakob)]
S: + PDUyMjg4MDg2MTc3NjY3NTEuMTUxMDc1NTYxMEBhbGRlYmFyYW4+
C: amFrb2IgNmMzY2YyZDEwODg1MTY1NDE1OGE0NDIwMGEzMjE2NmQ=
S: 8 OK [CAPABILITY IMAP4rev1 LITERAL+ SASL-IR LOGIN-REFERRALS ID ENABLE IDLE SORT SORT=DISPLAY THREAD=REFERENCES THREAD=REFS THREAD=ORDEREDSUBJECT MULTIAPPEND URL-PARTIAL CATENATE UNSELECT CHILDREN NAMESPACE UIDPLUS LIST-EXTENDED I18NLEVEL=1 CONDSTORE QRESYNC ESEARCH ESORT SEARCHRES WITHIN CONTEXT=SEARCH LIST-STATUS BINARY MOVE XDOVECOT SPECIAL-USE QUOTA ACL RIGHTS=texk] Logged in
>> Command 8 took 0,0143 seconds.
C: 9 SELECT Virtual$Alle (QRESYNC (1510698551 957 43365:43366,43368:43390,43392:43402,43404:43443,43445:43449,43451,43453:43454,43456:43486,43525,43544,43651,47819,49811:49812,49815:49826,56239:56243,73576:73586,75035:75039,75048,75071,77704,77865:77872))
S: 9 BAD Error in IMAP command SELECT: QRESYNC not enabled (0.000 + 0.000 secs).
>> Command 9 took 0,0003 seconds.
>> CACHE: Retrieved messages (HICenv,HICdg [Virtual$Alle; 43462])

Möglicherweise aber kommt das Timeout weil der Server die Verbindung unterbricht wegen dem:

Code: Alles auswählen

Nov 15 15:20:10 aldebaran dovecot[8794]: imap(jakob): Debug: Mailbox INBOX$Sent: Opened mail UID=2364 because: header stream
Nov 15 15:20:10 aldebaran dovecot[8794]: imap(jakob): Debug: Mailbox INBOX$Sent: Opened mail UID=2364 because: header stream
Nov 15 15:20:10 aldebaran dovecot[8794]: imap(jakob): Debug: Mailbox INBOX$Sent: Opened mail UID=2364 because: access
Nov 15 15:20:10 aldebaran dovecot[8794]: imap(jakob): Debug: Mailbox INBOX$Sent: Opened mail UID=2364 because: mail stream
Nov 15 15:20:10 aldebaran dovecot[8794]: imap(jakob): Panic: file index-mail-binary.c: line 586 (index_mail_get_binary_stream): assertion failed: (mail->data.stream != NULL)
Nov 15 15:20:10 aldebaran dovecot[8794]: imap(jakob): Error: Raw backtrace: /usr/lib/dovecot/libdovecot.so.0(+0x95272) [0x7f898649f272] -> /usr/lib/dovecot/libdovecot.so.0(+0x9536d) [0x7f898649f36d] -> /usr//lib/dovecot/libdovecot.so.0(i_fatal+0) [0x7f8986435951] -> /usr/lib/dovecot/libdovecot-storage.so.0(index_mail_get_binary_stream+0x238) [0x7f89867d4de8] -> /usr/lib/dovecot/libdovecot-storage.so.0(mail_get_binary_stream+0x60) [0x7f8986761fa0] -> /usr/lib/dovecot/libdovecot-storage.so.0(imap_msgpart_open+0x139) [0x7f89868150f9] -> dovecot/imap [jakob 192.168.0.14 UID FETCH](+0x1ebbc) [0x561e4bf69bbc] -> doveco[...]ETCH](+0x19a4c) [0x561e4bf64a4c] -> dovecot/imap [jakob 192.168.0.14 UID FETCH](client_handle_input+0x1b5) [0x561e4bf64e55] -> dovecot/imap [jakob 192.168.0.14 UID FETCH][...](client_input+0x86
Nov 15 15:20:10 aldebaran dovecot[8794]: imap(jakob): Fatal: master: service(imap): child 11915 killed with signal 6 (core dumps disabled)
Nov 15 15:20:10 aldebaran dovecot[8794]: imap-login: Login: user=<jakob>, method=CRAM-MD5, rip=192.168.0.14, lip=172.17.0.1, mpid=11950, secured, session=</92CMwZe7rrAqAAO>
Nov 15 15:20:10 aldebaran dovecot[8794]: imap(jakob): Debug: Loading modules from directory: /usr/lib/dovecot/modules

Also dovecot beendet sich, weil ein Fehler auftritt.

Momentan sieht es für mich so aus, als ob beide Seiten Fehler machen. Horde reagiert falsch auf den Abbruch der Verbindung, und Dovecot hat das Problem mit index-mail-binary.c, dass irgendwo ein Datenstrom nicht korrekt ist und deshalb ein Prozess mit einem Fehler beendet wird.

Wenn ich die Meldung

Code: Alles auswählen

assertion failed: (mail->data.stream != NULL)

richtig interpretiere, dann erwartet die Zeile 586 in index-mail-binary.c, dass der Datenstrom aus dem erwünschten Email ungleich null ist. Der gelieferte Datenstrom (also das Email) das geöffnet wird, ist aber leer. Daher wird der Fehler erzeugt.
Für mich passt das schon irgendwie rein, da die Mailbox ja nur eine virtuelle ist, und das Email irgendwo anders liegt. Ich vermute, je länger ich darüber nachdenke und stöbere, dass ein Zeiger im Virtual-Plugin womöglich falsch ist/verwendet wird.

Aber es ist wirklich seltsam.
Wenn ich die IMAP-Befehle direkt im gdb abarbeite, kann ich sie problemlos nacheinander ausführen.
Warum kommt der Fehler, wenn Horde das macht?

Die Befehle aus dem Log sind:
2 ENABLE QRESYNC
3 SELECT Virtual$Alle
4 NAMESPACE
5 UID FETCH 43543 (ENVELOPE)
6 UID FETCH 43543 (BODYSTRUCTURE),
7 UID FETCH 43543 (BODY[HEADER])
8 UID FETCH 43543 (BINARY.PEEK[1]) <--- hier tritt bei horde der Fehler auf, manuell aber ok!


Muss mir direkt mal den Source-Code von dovecot runterladen. Aber leider kann ich kein C Programmieren...

Und damit es festgehalten ist:
Ich hab jetzt einen Bericht gefunden, der ein äußerst ähnliches Problem beschreibt. Gelöst wurde es mit dem Upgrade auf eine neuere dovecot-Version (2.2.17 von 2.2.13)
Es scheint also doch ein Problem in Dovecot zu sein. Ich vermute, dass das im Code des virtual-Plugins noch nicht gefixt ist.
https://lists.horde.org/archives/horde/ ... 56281.html (Im Thread weiterschauen. Die Fehlermeldungen sind die selben)
Dürfte mit dem im Zusammenhang stehen:
https://tools.ietf.org/html/rfc3516

lg scientific

[scientific]

Gute/Schlechte Nachrichten.
Auf der dovecot-Mailingliste bin ich soweit gekommen, dass mir mitgeteilt wurde, dass es sich in der Tat offenbar um einen Bug in Dovecot handelt!

Immer wieder schön, zur Weiterenwicklung von FOSS beitragen zu können!
Vor allem dovecot, der auf - WIMRE - auf 50-60% aller Mailserver weltweit läuft.

lg scientific

[scientific]

Das ging ja fix...

Hier ist der Patch https://github.com/dovecot/core/commit/ ... 2ef5870c8d

Nur... Wie wende ich das jetzt unter Debian an?

Git clonen und selber kompillieren?
Und wenns funktioniert einen Debian-Bugreport verfassen und auf einen Backport für stretch hoffen?

[scientific]

Also!

Zuerst die Build-Dependencies geholt:

Code: Alles auswählen

sudo apt-get build-dep dovecot-core

Ich hab mir mit

Code: Alles auswählen

apt-get source dovecot-core

die aktuellen Sourcen von dovecot-2.2.27 rungerheladen.
Die werden nach

dovecot-2.2.27

im aktuellen Verzeichnis entpackt.
In dieses Verzeichnis rein, nach src und dann hab ich mal ganz "hot" einen Fix angewendet... ich hab die Datei aus dem Github-Commit gesucht:

Code: Alles auswählen

https://github.com/dovecot/core/commit/489af46c6c1ee32fe6a6ff96a8281f2ef5870c8d?diff=unified

Und die Ergänzungen/Änderungen an den entsprechenden Stellen eingefügt.

Dann mit

Code: Alles auswählen

debuild -b -uc -us

das Paket neu gebaut.

Es entstehen eine ganze menge neuer Pakete im Verzeichnis darüber.
Hab dann entsprechend der bereits installierten die entsprechenden mit dpkg -i <Paketname> installiert.
Dovecot neu gestartet... und siehe da, ich kann in Horde die zuvor nicht funkionierenden Emails öffnen.

Hab einen Bugreport an Debian und das paket dovecot-core gemacht, den Link zum Github-Commit beigefügt und gebeten, dies auch in Stable oder den Backports einzufügen.

Ganz sicher falsch ist, dass ich die Versionsnummer in Control nicht angepasst habe... Und Patches fügt man auch anders ein. Hatte aber jetzt keine Zeit, mir das genauer anzusehen. Mach in demnächst und werde ein ordentliches Paket dazu bauen.

lg scientific

[slu]

Sehr schön das Du den Fehler gefunden hast, vielen Dank für das Berichten und melden.

[weshalb]

Auch einen Dank von mir scientific, werde ich mal bei Gelegenheit ausprobieren.

[scientific]

Der Dank gilt vor allem den dovecot-Entwicklern. Die waren wirklich flott und super!