Homepage | Products | OX Knowledge Base | Support | Try Now | Contact | Company
OX Logo
Page 1 of 2 12 LastLast
Results 1 to 10 of 12
  1. #1
    TomL Guest

    Default Error from admin GUI

    When I click on any user in the admin GUI other than the oxadmin user, I get the following:

    Code:
    Error code: Error occured in: com.openexchange.admin.rmi.extensions.OXUserMailfilterExtension! Errortext: com.openexchange.admin.rmi.exceptions.OXSieveHandlerInvalidCredentialsException: Authentication failed (SVL-0001,465066230-55)
    and everything's disabled: can't change anything. Not sure what to check here... everything else works. Sieve is working:

    Code:
    root@elise:/etc# telnet localhost 2000
    Trying 127.0.0.1...
    Connected to localhost.
    Escape character is '^]'.
    "IMPLEMENTATION" "Cyrus timsieved v2.2.13"
    "SASL" "LOGIN PLAIN"
    "SIEVE" "fileinto reject envelope vacation imapflags notify subaddress relational comparator-i;ascii-numeric regex"
    "STARTTLS"
    OK
    I can send mail, receive mail as multiple users, can't seem to break anything else.

  2. #2
    Join Date
    Feb 2007
    Location
    Germany
    Posts
    3,695

    Default

    Hi,

    did you sniff the traffic on port 2000 when accessing the user configuration? I guess wrong credentials are used caused by a missing "admin: oxadmin" entry at the cyrus configuration.

    Greetings

  3. #3
    TomL Guest

    Default packet capture

    I have "admins: oxadmin" in /etc/imapd.conf, so that's not it. I can log in to the IMAP server as oxadmin.

    Here's a wireshark/libpcap packet capture of port 2000 traffic when I click on a user in the admin gui.

    It seems there is something else -- I can't view mail as "oxadmin", I get

    Code:
    Error code: No IMAP Account exists for user Open-Xchange Administrator(2) in context 1 (MSG-0096, 465066230-78)
    Apparently I need to create an account in Cyrus for oxadmin... I'll see if I can find any documentation on that. It's not included in the install doc on the wiki that I can see.
    Attached Files Attached Files
    Last edited by TomL; 02-26-2008 at 11:03 PM.

  4. #4
    Gertjan Guest

    Default

    Are you sure /etc/pam.d/sieve looks the same as /etc/pam.d/imap?

  5. #5
    TomL Guest

    Default Yep.

    They weren't but they are identical now, but still the same problem (new packet capture still looks the same).

    I've got cyradm working but it doesn't seem to be able to help. imtest says that oxadmin can authenticate.

    Code:
    root@elise:/var/log/open-xchange# imtest -a oxadmin
    WARNING: no hostname supplied, assuming localhost
    
    S: * OK elise Cyrus IMAP4 v2.2.13 server ready
    C: C01 CAPABILITY
    S: * CAPABILITY IMAP4 IMAP4rev1 ACL QUOTA LITERAL+ MAILBOX-REFERRALS NAMESPACE UIDPLUS ID NO_ATOMIC_RENAME UNSELECT CHILDREN MULTIAPPEND BINARY SORT THREAD=ORDEREDSUBJECT THREAD=REFERENCES ANNOTATEMORE IDLE STARTTLS
    S: C01 OK Completed
    Please enter your password:
    C: L01 LOGIN oxadmin {12}
    S: + go ahead
    C: <omitted>
    S: L01 OK User logged in
    Authenticated.
    Security strength factor: 0
    I get this in /var/log/messages with every click on a user in the admin GUI:

    Code:
    Feb 26 15:38:33 elise imap[18768]: login: localhost [127.0.0.1] oxadmin plaintext User logged in
    and this in /var/log/debug:

    Code:
    Feb 26 15:42:44 elise imap[18942]: accepted connection
    Feb 26 15:42:44 elise master[18949]: about to exec /usr/cyrus/bin/timsieved
    Feb 26 15:42:44 elise sieve[18949]: executed
    Feb 26 15:42:44 elise sieve[18949]: accepted connection

    I'm also getting the following in /var/log/open-xchange/open-xchange-admin.log.0 with every click on a user in the admin GUI:


    Code:
    Feb 26, 2008 11:17:53 PM com.openexchange.admin.rmi.impl.OXUserMailfilterImpl getData
    SEVERE: Authentication failed
    com.openexchange.admin.rmi.exceptions.OXSieveHandlerInvalidCredentialsException:
     Authentication failed
            at com.openexchange.admin.rmi.impl.SieveHandler.initializeConnection(Sie
    veHandler.java:256)
            at com.openexchange.admin.rmi.impl.OXUserMailfilterImpl.getDataimpl(OXUs
    erMailfilterImpl.java:706)
            at com.openexchange.admin.rmi.impl.OXUserMailfilterImpl.getData(OXUserMa
    ilfilterImpl.java:242)
            at com.openexchange.admin.rmi.impl.OXUser.getData(OXUser.java:850)
            at com.openexchange.admin.rmi.impl.OXUser.getData(OXUser.java:728)
            at sun.reflect.GeneratedMethodAccessor107.invoke(Unknown Source)
            at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAcces
    sorImpl.java:25)
            at java.lang.reflect.Method.invoke(Method.java:597)
            at sun.rmi.server.UnicastServerRef.dispatch(UnicastServerRef.java:305)
            at sun.rmi.transport.Transport$1.run(Transport.java:159)
            at java.security.AccessController.doPrivileged(Native Method)
            at sun.rmi.transport.Transport.serviceCall(Transport.java:155)
            at sun.rmi.transport.tcp.TCPTransport.handleMessages(TCPTransport.java:5
    35)
            at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run0(TCPTranspor
    t.java:790)
            at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run(TCPTransport
    .java:649)
            at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExec
    utor.java:885)
            at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor
    .java:907)
            at java.lang.Thread.run(Thread.java:619)
    Last edited by TomL; 02-27-2008 at 01:18 AM.

  6. #6
    TomL Guest

    Default timsieved broken?

    It would seem that timesieved won't authenticate anyone, not just oxadmin.

    Code:
    root@elise:/var/log# sivtest -m plain -a toml
    WARNING: no hostname supplied, assuming localhost
    
    S: "IMPLEMENTATION" "Cyrus timsieved v2.2.13"
    S: "SASL" "LOGIN PLAIN"
    S: "SIEVE" "fileinto reject envelope vacation imapflags notify subaddress relational comparator-i;ascii-numeric regex"
    S: "STARTTLS"
    S: OK
    Please enter your password:
    C: AUTHENTICATE "PLAIN" {20+}
    AHRvbWwAN2gwcnVwXg==
    S: NO "Authentication Error"
    Authentication failed. generic failure
    Security strength factor: 0
    C: LOGOUT
    Connection closed.
    sivtest -m plain -a oxadmin looks identical. Interestingly, without the "-m plain", sivtest tries AUTHENTICATE "LOGIN" and never prompts for a password at all, and emits an error about base64 decoding:

    Code:
    root@elise:/var/log# sivtest -a toml
    WARNING: no hostname supplied, assuming localhost
    
    S: "IMPLEMENTATION" "Cyrus timsieved v2.2.13"
    S: "SASL" "LOGIN PLAIN"
    S: "SIEVE" "fileinto reject envelope vacation imapflags notify subaddress relational comparator-i;ascii-numeric regex"
    S: "STARTTLS"
    S: OK
    C: AUTHENTICATE "LOGIN"
    S: {12}
    S: VXNlcm5hbWU6
    base64 decoding error
    Authentication failed. generic failure
    Security strength factor: 0
    C: LOGOUT
    Connection closed.

  7. #7
    TomL Guest

    Default Update

    I updated cyrus-imapd to the latest test version, 2.3.11 and that solved the base64 decode problem when sivtest tries LOGIN authentication. However, it still doesn't authenticate any user, with either LOGIN or PLAIN.

    What, other than /etc/pam.d/* files, would cause imapd to authenticate and timsieved to not authenticate? My /etc/pam.d/imap and /etc/pam.d/sieve are identical.

    It would be nice if I could get pam_mysql and timsieved to log some debug output....

  8. #8
    TomL Guest

    Default Now we're getting somewhere...

    I got pam_mysql to log some debug output. It still doesn't tell me why the pam setup isn't working for sieve, though. Below is output to /var/log/secure when I click on a user in the admin GUI. What's really funky is that when I look at the same debug output from an imap login, they are exactly identical, except for the time and process id.

    Code:
    Feb 27 09:33:45 elise saslauthd[3021]: pam_mysql - option verbose is set to "1"
    Feb 27 09:33:45 elise saslauthd[3021]: pam_mysql - pam_mysql_close_db() called.
    Feb 27 09:33:45 elise saslauthd[3021]: pam_mysql - pam_sm_authenticate() called.
    Feb 27 09:33:45 elise saslauthd[3021]: pam_mysql - pam_mysql_open_db() called.
    Feb 27 09:33:45 elise saslauthd[3021]: pam_mysql - pam_mysql_open_db() returning 0.
    Feb 27 09:33:45 elise saslauthd[3021]: pam_mysql - pam_mysql_check_passwd() called.
    Feb 27 09:33:45 elise saslauthd[3021]: pam_mysql - pam_mysql_format_string() called
    Feb 27 09:33:45 elise saslauthd[3021]: pam_mysql - pam_mysql_quick_escape() called.
    Feb 27 09:33:45 elise saslauthd[3021]: pam_mysql - SELECT user.userPassword FROM login2user LEFT JOIN user ON login2user.id=user.id AND login2user.cid=user.cid WHERE login2user.uid = 'oxadmin' AND (user.cid=1)
    Feb 27 09:33:45 elise saslauthd[3021]: pam_mysql - pam_mysql_check_passwd() returning 6.
    Feb 27 09:33:45 elise saslauthd[3021]: pam_mysql - pam_mysql_sql_log() called.
    Feb 27 09:33:45 elise saslauthd[3021]: pam_mysql - pam_mysql_sql_log() returning 0.
    Feb 27 09:33:45 elise saslauthd[3021]: pam_mysql - pam_mysql_converse() called.
    Feb 27 09:33:45 elise saslauthd[3021]: pam_mysql - pam_mysql_open_db() called.
    Feb 27 09:33:45 elise saslauthd[3021]: pam_mysql - pam_mysql_check_passwd() called.
    Feb 27 09:33:45 elise saslauthd[3021]: pam_mysql - pam_mysql_format_string() called
    Feb 27 09:33:45 elise saslauthd[3021]: pam_mysql - pam_mysql_quick_escape() called.
    Feb 27 09:33:45 elise saslauthd[3021]: pam_mysql - SELECT user.userPassword FROM login2user LEFT JOIN user ON login2user.id=user.id AND login2user.cid=user.cid WHERE login2user.uid = 'oxadmin' AND (user.cid=1)
    Feb 27 09:33:45 elise saslauthd[3021]: pam_mysql - pam_mysql_check_passwd() returning 0.
    Feb 27 09:33:45 elise saslauthd[3021]: pam_mysql - pam_mysql_sql_log() called.
    Feb 27 09:33:45 elise saslauthd[3021]: pam_mysql - pam_mysql_sql_log() returning 0.
    Feb 27 09:33:45 elise saslauthd[3021]: pam_mysql - pam_sm_authenticate() returning 0.
    Feb 27 09:33:45 elise saslauthd[3021]: pam_mysql - option host is set to "localhost"
    Feb 27 09:33:45 elise saslauthd[3021]: pam_mysql - option user is set to "openexchange"
    Feb 27 09:33:45 elise saslauthd[3021]: pam_mysql - option passwd is set to "xxxxxxxxxxxxx"
    Feb 27 09:33:45 elise saslauthd[3021]: pam_mysql - option db is set to "open-xchange-db"
    Feb 27 09:33:45 elise saslauthd[3021]: pam_mysql - option table is set to "login2user LEFT JOIN user ON login2user.id=user.id AND login2user.cid=user.cid"
    Feb 27 09:33:45 elise saslauthd[3021]: pam_mysql - option where is set to "user.cid=1"
    Feb 27 09:33:45 elise saslauthd[3021]: pam_mysql - option usercolumn is set to "login2user.uid"
    Feb 27 09:33:45 elise saslauthd[3021]: pam_mysql - option passwdcolumn is set to "user.userPassword"
    Feb 27 09:33:45 elise saslauthd[3021]: pam_mysql - option crypt is set to "1"
    Feb 27 09:33:45 elise saslauthd[3021]: pam_mysql - option verbose is set to "1"
    Feb 27 09:33:45 elise saslauthd[3021]: pam_mysql - pam_mysql_close_db() called.
    Feb 27 09:33:45 elise saslauthd[3021]: pam_mysql - pam_sm_acct_mgmt() called.
    Feb 27 09:33:45 elise saslauthd[3021]: pam_mysql - pam_mysql_open_db() called.
    Feb 27 09:33:45 elise saslauthd[3021]: pam_mysql - pam_mysql_open_db() returning 0.
    Feb 27 09:33:45 elise saslauthd[3021]: pam_mysql - pam_mysql_query_user_stat() called.
    Feb 27 09:33:45 elise saslauthd[3021]: pam_mysql - pam_mysql_format_string() called
    Feb 27 09:33:45 elise saslauthd[3021]: pam_mysql - pam_mysql_quick_escape() called.
    Feb 27 09:33:45 elise saslauthd[3021]: pam_mysql - SELECT 0, user.userPassword FROM login2user LEFT JOIN user ON login2user.id=user.id AND login2user.cid=user.cid WHERE login2user.uid = 'oxadmin' AND (user.cid=1)
    Feb 27 09:33:45 elise saslauthd[3021]: pam_mysql - pam_mysql_query_user_stat() returning 0.
    Feb 27 09:33:45 elise saslauthd[3021]: pam_mysql - pam_mysql_sql_log() called.
    Feb 27 09:33:45 elise saslauthd[3021]: pam_mysql - pam_mysql_sql_log() returning 0.
    Feb 27 09:33:45 elise saslauthd[3021]: pam_mysql - pam_sm_acct_mgmt() returning 0.
    Feb 27 09:33:45 elise saslauthd[3021]: pam_mysql - pam_mysql_release_ctx() called.
    Feb 27 09:33:45 elise saslauthd[3021]: pam_mysql - pam_mysql_destroy_ctx() called.
    Feb 27 09:33:45 elise saslauthd[3021]: pam_mysql - pam_mysql_close_db() called.
    Last edited by TomL; 02-27-2008 at 07:30 PM.

  9. #9
    TomL Guest

    Default pam_sm_authenticate

    The important bit seems to be the return value of pam_sm_authenticate. When the authentication succeeds it returns a value of 0. I ran imtest and typed the wrong password on purpose just to see what it would log for a failure -- in that case, pam_sm_authenticate returns 7, and there's far fewer lines logged.

    What I don't understand is, when sieve fails to authenticate, pam_sm_authenticate is returning 0! I can only surmise that the pam interface in sieve is different from the pam interface in imapd, to the point where its broken -- at least with respect to the version pam_mysql I have running (0.7RC1).

    What version of pam_mysql is everyone using, and where did you get it? And what version of timsieved? And what version of pam itself? What about sasl?

    My versions: pam 0.99.8.1, pam_mysql 0.7RC1, timsieved 2.3.11 (from cyrus-imapd 2.3.11), cyrus-sasl 2.1.22
    Last edited by TomL; 02-27-2008 at 08:11 PM.

  10. #10
    TomL Guest

    Default saslauthd debug

    saslauthd is seeing the "OK" from pam_mysql, but timsieved still fails to authenticate. This is what I get from saslauthd debug output when I click a user in the admin GUI:

    Code:
    saslauthd[20342] :rel_accept_lock : released accept lock
    saslauthd[20346] :get_accept_lock : acquired accept lock
    saslauthd[20342] :do_auth         : auth success: [user=oxadmin] [service=imap] [realm=] [mech=pam]
    saslauthd[20342] :do_request      : response: OK
    saslauthd[20346] :rel_accept_lock : released accept lock
    saslauthd[20342] :get_accept_lock : acquired accept lock
    saslauthd[20346] :do_auth         : auth success: [user=oxadmin] [service=sieve] [realm=] [mech=pam]
    saslauthd[20346] :do_request      : response: OK
    And this is what happens when I run imtest and type a bad password on purpose:

    Code:
    saslauthd[20342] :rel_accept_lock : released accept lock
    saslauthd[20343] :get_accept_lock : acquired accept lock
    saslauthd[20342] :do_auth         : auth failure: [user=toml] [service=imap] [realm=] [mech=pam] [reason=PAM auth error]
    And yet in both cases, I get "authentication failed".

Bookmarks

Posting Permissions

  • You may not post new threads
  • You may not post replies
  • You may not post attachments
  • You may not edit your posts
  •