Announcement

Collapse
No announcement yet.

Probleme mit dovecot sieve server

Collapse
X
 
  • Filter
  • Time
  • Show
Clear All
new posts

  • Probleme mit dovecot sieve server

    Hallo,

    1/4 Tag für die Installation von OX, und dann 1 Tag weil das sieve nicht so will..

    Ich übersehe was...

    Aber von Anfang an:

    Debian lenny syetm moit postfix und dovecot.
    Virtuelle Benutzer in Postfix wie in diesem Howto http://workaround.org/articles/ispmail-etch/ angegeben.

    Sasl und tls noch kurzgeschlossen da Clients im lokalen Netz sich nicht Authentifizieren müssen.
    Funktioniert auch alles:
    • mail empfangen
    • email per imap ansehen (mit mutt und imap URL)
    • eMail verschicken


    Dann OX 6.6 0-2 per aptitude installiert.

    GUI läuft, Mail ist da, kann verschickt werden, alles prima...
    Aber beim Login dauert es eine Weile und dann kommt eine Fehlermeldung "Error in low level connection to sieve server", die im Log so aussieht:

    Code:
    INFO: com.openexchange.pooling:name=DB Pool 4 registered 
    15.08.2008 16:32:15 com.openexchange.sessiond.impl.SessionHandler addSession
    INFO: Session created. ID: b2053a85d456ed16f89867aa24b6f359, Context:  1, User: 5
    15.08.2008 16:32:49 com.openexchange.mailfilter.ajax.AJAXServlet doGet
    SCHWERWIEGEND: MAIL_FILTER-0014 Category=8 Message=Error in low level connection to sieve server exceptionID=-948274205-4
    MAIL_FILTER-0014 Category=8 Message=Error in low level connection to sieve server exceptionID=-948274205-4
            at com.openexchange.mailfilter.ajax.actions.MailfilterAction.actionConfig(MailfilterAction.java:165)
            at com.openexchange.mailfilter.ajax.actions.MailfilterAction.actionConfig(MailfilterAction.java:98)
            at com.openexchange.mailfilter.ajax.actions.AbstractAction.action(AbstractAction.java:79)
            at com.openexchange.mailfilter.ajax.AJAXServlet.doGet(AJAXServlet.java:192)
            at javax.servlet.http.HttpServlet.service(HttpServlet.java:596)
            at javax.servlet.http.HttpServlet.service(HttpServlet.java:689)
            at com.openexchange.ajp13.AJPv13Request.response(AJPv13Request.java:120)
            at com.openexchange.ajp13.AJPv13RequestHandler.createResponse(AJPv13RequestHandler.java:466)
            at com.openexchange.ajp13.AJPv13Connection.createResponse(AJPv13Connection.java:197)
            at com.openexchange.ajp13.AJPv13Listener.run(AJPv13Listener.java:259)
            at java.lang.Thread.run(Thread.java:595)
    Caused by: java.net.SocketTimeoutException: Read timed out
            at java.net.SocketInputStream.socketRead0(Native Method)
            at java.net.SocketInputStream.read(SocketInputStream.java:129)
            at sun.nio.cs.StreamDecoder$CharsetSD.readBytes(StreamDecoder.java:411)
            at sun.nio.cs.StreamDecoder$CharsetSD.implRead(StreamDecoder.java:453)
            at sun.nio.cs.StreamDecoder.read(StreamDecoder.java:183)
            at java.io.InputStreamReader.read(InputStreamReader.java:167)
            at java.io.BufferedReader.fill(BufferedReader.java:136)
            at java.io.BufferedReader.readLine(BufferedReader.java:299)
            at java.io.BufferedReader.readLine(BufferedReader.java:362)
            at com.openexchange.jsieve.SieveHandler.getServerWelcome(SieveHandler.java:500)
            at com.openexchange.jsieve.SieveHandler.initializeConnection(SieveHandler.java:246)
            at com.openexchange.mailfilter.ajax.actions.MailfilterAction.actionConfig(MailfilterAction.java:158)
            ... 10 more
    15.08.2008 16:50:39 com.openexchange.authentication.database.osgi.Activator start
    INFO: starting bundle: com.openexchange.authentication.database
    GUI, auch für email, ist aber trotzdem benutzbar.

    dovecot ist soweit anscheinend richtig, weil per telnet geht's soweit:
    Der Buchstabensalat beim AUTH ist das md5 vom IMAP Login, wie im OX admin angegeben und das OX (und IMAP) Kennwort.
    Code:
    # telnet localhost 2000
    Trying 127.0.0.1...
    Connected to viggo.ampersand.loc.
    Escape character is '^]'.
    "IMPLEMENTATION" "dovecot"
    "SASL" "PLAIN LOGIN"
    "SIEVE" "fileinto reject envelope vacation imapflags notify subaddress relational comparator-i;ascii-numeric regex"
    "STARTTLS"
    OK "Dovecot ready."
    AUTHENTICATE "PLAIN" "YW5kcmVhc0BlbnRpdHkzOC5kZQBhbmRyZWFzQGVudGl0eTM4LmRlAG5peCNuaXg="
    OK "Logged in."
    PUTSCRIPT "hutsefluts" {6+}
    keep;
    OK "Putscript completed."
    PUTSCRIPT "hutsefluts" {6+}
    keep;
    OK "Putscript completed."
    LISTSCRIPTS
    "hutsefluts"
    OK "Listscripts completed."
    GETSCRIPT "hutsefluts"
    {6}
    keep;
    OK "Getscript completed."
    logout
    OK "Logout completed."
    Connection closed by foreign host.
    die mailfilter.properties sieht so aus:
    Code:
    SIEVE_LOGIN_TYPE=global
    SIEVE_CREDSRC=imapLogin
    SIEVE_SERVER=localhost
    SIEVE_PORT=2000
    SCRIPT_NAME=Open-Xchange
    der IMAP Login funzt, weil eMail ist ja in der GUI sichtbar.

    Also was übersehe ich da...?

  • #2
    Originally posted by WegDamit View Post

    [...]

    Code:
    [...]
    
    Caused by: java.net.SocketTimeoutException: Read timed out
            at java.net.SocketInputStream.socketRead0(Native Method)
            at java.net.SocketInputStream.read(SocketInputStream.java:129)
            at sun.nio.cs.StreamDecoder$CharsetSD.readBytes(StreamDecoder.java:411)
            at sun.nio.cs.StreamDecoder$CharsetSD.implRead(StreamDecoder.java:453)
            at sun.nio.cs.StreamDecoder.read(StreamDecoder.java:183)
            at java.io.InputStreamReader.read(InputStreamReader.java:167)
            at java.io.BufferedReader.fill(BufferedReader.java:136)
            at java.io.BufferedReader.readLine(BufferedReader.java:299)
            at java.io.BufferedReader.readLine(BufferedReader.java:362)
            at com.openexchange.jsieve.SieveHandler.getServerWelcome(SieveHandler.java:500)
            at com.openexchange.jsieve.SieveHandler.initializeConnection(SieveHandler.java:246)
            at com.openexchange.mailfilter.ajax.actions.MailfilterAction.actionConfig(MailfilterAction.java:158)
            ... 10 more
    15.08.2008 16:50:39 com.openexchange.authentication.database.osgi.Activator start
    INFO: starting bundle: com.openexchange.authentication.database
    GUI, auch für email, ist aber trotzdem benutzbar.

    dovecot ist soweit anscheinend richtig, weil per telnet geht's soweit:
    Der Buchstabensalat beim AUTH ist das md5 vom IMAP Login, wie im OX admin angegeben und das OX (und IMAP) Kennwort.
    Code:
    # telnet localhost 2000
    Trying 127.0.0.1...
    Connected to viggo.ampersand.loc.
    Escape character is '^]'.
    "IMPLEMENTATION" "dovecot"
    "SASL" "PLAIN LOGIN"
    "SIEVE" "fileinto reject envelope vacation imapflags notify subaddress relational comparator-i;ascii-numeric regex"
    "STARTTLS"
    OK "Dovecot ready."
    AUTHENTICATE "PLAIN" "YW5kcmVhc0BlbnRpdHkzOC5kZQBhbmRyZWFzQGVudGl0eTM4LmRlAG5peCNuaXg="
    OK "Logged in."
    PUTSCRIPT "hutsefluts" {6+}
    keep;
    OK "Putscript completed."
    PUTSCRIPT "hutsefluts" {6+}
    keep;
    OK "Putscript completed."
    LISTSCRIPTS
    "hutsefluts"
    OK "Listscripts completed."
    GETSCRIPT "hutsefluts"
    {6}
    keep;
    OK "Getscript completed."
    logout
    OK "Logout completed."
    Connection closed by foreign host.
    die mailfilter.properties sieht so aus:
    Code:
    SIEVE_LOGIN_TYPE=global
    SIEVE_CREDSRC=imapLogin
    SIEVE_SERVER=localhost
    SIEVE_PORT=2000
    SCRIPT_NAME=Open-Xchange
    der IMAP Login funzt, weil eMail ist ja in der GUI sichtbar.

    Also was übersehe ich da...?
    Your mailfilter.properties file is correct.
    The login string is not md5, but base64 encoded:

    Code:
    echo YW5kcmVhc0BlbnRpdHkzOC5kZQBhbmRyZWFzQGVudGl0eTM4LmRlAG5peCNuaXg= | mimencode -u
    andreas@entity38.d
    NOTE: if that's your real password and the server is reachable from the outside, you should change your password now.

    But now to the problem:

    I see a read timeout in the logs, so it looks like a communication problem between our sievehandler and the dovecot sieve daemon.
    As we never tested with dovecot before, that could happen. Currently only cyrus sieve has been tested.

    To further debug that issue, could you please make a tcpdump of the communication and post it here? That might at least give us a hint where's the problem.

    Comment


    • #3
      Thanks for the quick reply.

      Password is not a problem, it's all in an testing environment (and a realy simple on for testing only, i#m to lazy for long ones if i have to type them often...)
      But thanks for the warning...

      here a tcpdump starting from login until the apperance of the error messag in GUI
      Code:
      # tcpdump -vvv port 2000 -i lo
      tcpdump: listening on lo, link-type EN10MB (Ethernet), capture size 96 bytes
      18:45:48.876231 IP (tos 0x0, ttl  64, id 58539, offset 0, flags [DF], proto: TCP (6), length: 60) viggo.ampersand.loc.41404 > viggo.ampersand.loc.sieve: S, cksum 0x5212 (correct), 4193029233:4193029233(0) win 32792 <mss 16396,sackOK,timestamp 2763352282 0,nop,wscale 7>
      18:45:48.876288 IP (tos 0x0, ttl  64, id 0, offset 0, flags [DF], proto: TCP (6), length: 60) viggo.ampersand.loc.sieve > viggo.ampersand.loc.41404: S, cksum 0x5d00 (correct), 4193971597:4193971597(0) ack 4193029234 win 32768 <mss 16396,sackOK,timestamp 2763352282 2763352282,nop,wscale 7>
      18:45:48.876326 IP (tos 0x0, ttl  64, id 58540, offset 0, flags [DF], proto: TCP (6), length: 52) viggo.ampersand.loc.41404 > viggo.ampersand.loc.sieve: ., cksum 0x4524 (correct), 1:1(0) ack 1 win 257 <nop,nop,timestamp 2763352282 2763352282>
      18:45:48.876665 IP (tos 0x0, ttl  64, id 34133, offset 0, flags [DF], proto: TCP (6), length: 252) viggo.ampersand.loc.sieve > viggo.ampersand.loc.41404: P 1:201(200) ack 1 win 256 <nop,nop,timestamp 2763352283 2763352282>
      18:45:48.876709 IP (tos 0x0, ttl  64, id 58541, offset 0, flags [DF], proto: TCP (6), length: 52) viggo.ampersand.loc.41404 > viggo.ampersand.loc.sieve: ., cksum 0x4452 (correct), 1:1(0) ack 201 win 265 <nop,nop,timestamp 2763352283 2763352283>
      18:46:18.880390 IP (tos 0x0, ttl  64, id 58542, offset 0, flags [DF], proto: TCP (6), length: 60) viggo.ampersand.loc.41404 > viggo.ampersand.loc.sieve: P, cksum 0xfe30 (incorrect (-> 0x30f9), 1:9(8) ack 201 win 265 <nop,nop,timestamp 2763359783 2763352283>
      18:46:18.880453 IP (tos 0x0, ttl  64, id 34134, offset 0, flags [DF], proto: TCP (6), length: 52) viggo.ampersand.loc.sieve > viggo.ampersand.loc.41404: ., cksum 0x09bb (correct), 201:201(0) ack 9 win 256 <nop,nop,timestamp 2763359783 2763359783>
      18:46:18.880552 IP (tos 0x0, ttl  64, id 58543, offset 0, flags [DF], proto: TCP (6), length: 52) viggo.ampersand.loc.41404 > viggo.ampersand.loc.sieve: F, cksum 0x09b1 (correct), 9:9(0) ack 201 win 265 <nop,nop,timestamp 2763359783 2763359783>
      18:46:18.880851 IP (tos 0x0, ttl  64, id 34135, offset 0, flags [DF], proto: TCP (6), length: 76) viggo.ampersand.loc.sieve > viggo.ampersand.loc.41404: FP, cksum 0xfe40 (incorrect (-> 0x6a96), 201:225(24) ack 10 win 256 <nop,nop,timestamp 2763359783 2763359783>
      18:46:18.880955 IP (tos 0x0, ttl  64, id 0, offset 0, flags [DF], proto: TCP (6), length: 40) viggo.ampersand.loc.41404 > viggo.ampersand.loc.sieve: R, cksum 0x81e9 (correct), 4193029243:4193029243(0) win 0
      i can't read much out of this...

      and my dovecot log gave me:
      Code:
      008-08-15 18:45:46 Info: imap-login: Login: user=<andreas@entity38.de>, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, secured
      2008-08-15 18:45:46 Info: IMAP(andreas@entity38.de): Effective uid=116, gid=116
      2008-08-15 18:45:46 Info: IMAP(andreas@entity38.de): maildir: data=/var/vmail/entity38.de/andreas/Maildir
      2008-08-15 18:45:46 Info: IMAP(andreas@entity38.de): maildir: root=/var/vmail/entity38.de/andreas/Maildir, index=/var/vmail/entity38.de/andreas/Maildir, control=, inbox=
      2008-08-15 18:45:48 Info: IMAP(andreas@entity38.de): Disconnected: Logged out
      2008-08-15 18:45:48 Info: IMAP(andreas@entity38.de): Effective uid=116, gid=116
      2008-08-15 18:45:48 Info: IMAP(andreas@entity38.de): maildir: data=/var/vmail/entity38.de/andreas/Maildir
      2008-08-15 18:45:48 Info: IMAP(andreas@entity38.de): maildir: root=/var/vmail/entity38.de/andreas/Maildir, index=/var/vmail/entity38.de/andreas/Maildir, control=, inbox=
      2008-08-15 18:45:48 Info: imap-login: Login: user=<andreas@entity38.de>, method=PLAIN, rip=127.0.0.1, lip=127.0.0.1, secured
      2008-08-15 18:45:56 Info: IMAP(andreas@entity38.de): Disconnected: Logged out
      2008-08-15 18:46:18 Info: managesieve-login: Aborted login (logout command): rip=127.0.0.1, lip=127.0.0.1, secured
      and there is a ten sec delay roght bevor the disconnect message...

      Hope that help's...

      Comment


      • #4
        A dump of the network communication can be made by either using wireshark (ethereal) and its Follow TCP Stream feature or using tcpdump and capturing the complete packages of the communication.

        tcpdump -n -i lo -s 0 -w dump.out src or dst port 2000

        -s 0 == snaplen 0

        tcpdump(1):
        [...]
        Setting snaplen to 0 means use the required length to catch whole packets.
        [...]

        Comment


        • #5
          *headslap* Aua.

          Ok.
          Anbei der dump in einem ZIP...

          sieht nach einem richtigen login aus, dannkommt ein logout und ... fertig.

          Sieht für mich eigentlich ganz gut aus..?
          Attached Files

          Comment


          • #6
            Originally posted by WegDamit View Post
            *headslap* Aua.

            Ok.
            Anbei der dump in einem ZIP...

            sieht nach einem richtigen login aus, dannkommt ein logout und ... fertig.

            Sieht für mich eigentlich ganz gut aus..?
            Yes, the dump doesn't seem to match the error message, no idea.
            Last chance is to enable server debugging in /opt/open-xchange/etc/groupware/file-logging.properties.

            Set the topmost

            .level=INFO

            to

            .level=ALL

            and restart the server and login again and post the complete log /var/log/open-xchange/open-xchange.log.0

            Comment


            • #7
              attached is a log of a restart und one login until the sieve errror messgae appeared in the frontend.

              There is a problem with the RMI on port 9999 mentioned (around line 40).
              (whoch i reconfigured to be on a real interface )
              and the know MAIL_FILTER-0014 messag at line 1629.

              But nothing i can identify as a probalbly error in between...
              Attached Files

              Comment


              • #8
                Well, I've no idea why the com.openexchange.jsieve.SieveHandler.getServerWelc ome() method fails with a read timeout... :-(
                Looks like that's something which can only be debugged when running a local dovecot instance.

                Comment


                • #9
                  Ok.
                  i have a local dovecot installation.

                  But no expierince in OX src or debugging...

                  Any hints....?

                  I will see what i can find out, but...

                  Comment


                  • #10
                    Originally posted by WegDamit View Post
                    Ok.
                    i have a local dovecot installation.

                    But no expierince in OX src or debugging...

                    Any hints....?

                    I will see what i can find out, but...
                    The current implementation is only tested against cyrus-sieve daemon.
                    It should work with other implementations as well, but it seems like it does not with dovecot.

                    It would not hurt to report a bug: http://bugs.open-xchange.com/cgi-bin/bugzilla/index.cgi

                    Comment


                    • #11
                      Good news

                      The bug has been fixed.

                      The fixed code should be in cvs tomorrow and within the nightly snapshot build at http://download.opensuse.org/reposit.../OX:/snapshot/ and will be part with the next official RC.

                      Comment


                      • #12
                        is this fix now in the debian packages (6.6.0-6606)?
                        becous I get the same Error

                        Comment


                        • #13
                          Just to "close" this Thread:

                          Originally posted by Carsten Hoeger View Post
                          The bug has been fixed.

                          The fixed code should be in cvs tomorrow and within the nightly snapshot build at http://download.opensuse.org/reposit.../OX:/snapshot/ and will be part with the next official RC.
                          It is. My debian (lenny) works with sieve now.

                          Thanks for your help.

                          Comment

                          Working...
                          X