Opened 4 years ago

Closed 4 years ago

Last modified 4 years ago

#1485665 closed Bugs (invalid)

Imap error

Reported by: mosfet Owned by:
Priority: 6 Milestone: 0.2.1
Component: IMAP connection Version: 0.2-stable
Severity: normal Keywords:
Cc: monotek@…, daniel@…

Description (last modified by thomasb)

When upgrading from roundcube 0.2-beta to 0.2 stable, I cannot connect to my IMAP server anymore, I am disconnected.

Here is the log I have : 

Rouncube 0.2 stable(BROKEN): 
---------------------

dovecot: 2009-01-05 13:22:02 Info: auth(default): client in: AUTH       1       CRAM-MD5        service=IMAP    secured lip=89.192.74.52        rip=89.192.74.52
dovecot: 2009-01-05 13:22:02 Info: auth(default): client out: CONT      1       PDkwMDAxKDIyNDY0MjM4NDYuMTIzMTE1ODEyMkBzZC0xNTI1MT4=
dovecot: 2009-01-05 13:22:02 Info: auth(default): client in: CONT<hidden>
dovecot: 2009-01-05 13:22:02 Info: auth-worker(default): sql(user@mycompany.com,89.192.74.52): query: SELECT email as user, password FROM view_users WHERE email='user@mycompany.com';
dovecot: 2009-01-05 13:22:02 Info: auth-worker(default): password(user@mycompany.com,89.192.74.52): Requested CRAM-MD5 scheme, but we have only PLAIN-MD5
dovecot: 2009-01-05 13:22:02 Info: auth(default): new auth connection: pid=3544
dovecot: 2009-01-05 13:22:03 Info: auth(default): client out: FAIL      1       user=user@mycompany.com
dovecot: 2009-01-05 13:22:03 Info: imap-login: Disconnected: user=<user@mycompany.com>, method=CRAM-MD5, rip=89.192.74.52, lip=89.192.74.52, secured


Rouncube 0.2 beta (WORKING): 
---------------------
dovecot: 2009-01-05 14:03:56 Info: auth(default): client in: AUTH       1       CRAM-MD5        service=IMAP    secured lip=89.192.74.52        rip=89.192.74.52
dovecot: 2009-01-05 14:03:56 Info: auth(default): client out: CONT      1       PDkwMDAxKDIyNDY0MjM4NDYuMTIzMTE1ODEyMkBzZC0xNTI1MT4=
dovecot: 2009-01-05 14:03:56 Info: auth(default): client in: CONT<hidden>
dovecot: 2009-01-05 14:03:56 Info: auth-worker(default): sql(user@mycompany.com,89.192.74.52): query: SELECT email as user, password FROM view_users WHERE email='user@mycompany.com';
dovecot: 2009-01-05 14:03:56 Info: auth-worker(default): password(user@mycompany.com,89.192.74.52): Requested CRAM-MD5 scheme, but we have only PLAIN-MD5
dovecot: 2009-01-05 14:03:56 Info: auth(default): new auth connection: pid=3980
dovecot: 2009-01-05 14:03:57 Info: auth(default): client out: FAIL      1       user=user@mycompany.com
dovecot: 2009-01-05 14:03:57 Info: auth(default): client in: AUTH       2       PLAIN   service=IMAP    secured lip=89.192.74.52        rip=89.192.74.52        resp=<hidden>
dovecot: 2009-01-05 14:03:57 Info: auth(default): client out: OK        2       user=user@mycompany.com

I am using the following software version :
ubuntu 8.04
dovecot 1.0.10

Attachments (2)

cristal.txt​ (2.3 KB) - added by mosfet 4 years ago.
log file
plain-auth.txt​ (4.6 KB) - added by mosfet 4 years ago.
0.2 stable : log during a plain-auth

Download all attachments as: .zip

Change History (25)

Changed 4 years ago by mosfet

log file

comment:1 Changed 4 years ago by mosfet

Apache/2.2.8 (Ubuntu) DAV/2 SVN/1.5.1 mod_python/3.3.1 Python/2.5.2 PHP/5.2.4-2ubuntu5.4 with Suhosin-Patch mod_ssl/2.2.8 OpenSSL/0.9.8g mod_wsgi/2.0

comment:2 Changed 4 years ago by alec

  • Milestone changed from later to 0.2.1

Uncomment console() calls in lib/imap.inc, try to log in, then check logs/console and attach here.

comment:3 Changed 4 years ago by mosfet

With debug_level=4 in rc/config file I have the following message

IMAP Error: Authentication for user@… failed (AUTH): "a000 NO Authentication failed.
"

Warning: Cannot modify header information - headers already sent in /var/www/mycompany/rc/program/include/rcmail.php on line 951

comment:4 Changed 4 years ago by mosfet

With debug_level=4 in rc/config and console uncommented in lib/imap.inc

S: * OK Dovecot ready.

C: cp01 CAPABILITY
S: * CAPABILITY IMAP4rev1 SASL-IR SORT THREAD=REFERENCES MULTIAPPEND UNSELECT LITERAL+ IDLE CHILDREN NAMESPACE LOGIN-REFERRALS STARTTLS AUTH=PLAIN AUTH=LOGIN AUTH=DIGEST-MD5 AUTH=CRAM-MD5

S: cp01 OK Capability completed.

C: a000 AUTHENTICATE CRAM-MD5
S: + PDkwMDAxKDIyNDY0MjM4NDYuMTIzMTE1ODEyMkBzZC0xNTI1MT4=
C: Zm9yjW1lckBzbWFydG1vYmlsaS5jb21gNWE5ZTMwYWI0NzlkNWFjYTA3N2NhM2NhY2MxMmM3YmM=
S: a000 NO Authentication failed.

comment:5 Changed 4 years ago by monotek

I had the same problem.

You have to set the login mechanism to "PLAIN" in rouncube config.

comment:6 Changed 4 years ago by monotek

  • Cc monotek@… added

comment:7 Changed 4 years ago by mosfet

Thanks monotek but I dont' want my password to be sent in clear ...

comment:8 Changed 4 years ago by thomasb

  • Description modified (diff)

(better formatting)

comment:9 Changed 4 years ago by alec

As you can see in your imap logs, in 0.2-beta was PLAIN authentication used after unsuccessful CRAM-MD5 login. Now, in 0.2-stable if server is CRAM-MD5 capable, roundcube uses only that auth type. So, maybe it is imap's fault not roundcube's. Please, use my previous comment and attach more precise imap conversation logs.

comment:10 Changed 4 years ago by mosfet

[05-Jan-2009 19:00:39 +0100]: S: * OK Dovecot ready.
[05-Jan-2009 19:00:39 +0100]: C: cp01 CAPABILITY
[05-Jan-2009 19:00:39 +0100]: S: * CAPABILITY IMAP4rev1 SASL-IR SORT THREAD=REFERENCES MULTIAPPEND UNSELECT LITERAL+ IDLE CHILDREN NAMESPACE LOGIN-REFERRALS STARTTLS AUTH=PLAIN AUTH=LOGIN AUTH=DIGEST-MD5 AUTH=CRAM-MD5
[05-Jan-2009 19:00:39 +0100]: S: cp01 OK Capability completed.
[05-Jan-2009 19:00:39 +0100]: C: a000 AUTHENTICATE CRAM-MD5
[05-Jan-2009 19:00:39 +0100]: S: + PDg1NzQ4NTc2NzkyNzM4NTguMTIzMTE3ODQzOUBzZC0xNTI1MT4=
[05-Jan-2009 19:00:39 +0100]: C: Zm9ydW1lckBzbWFydG1vYmlsaS5jb20gYmFmZjgyNGNmNGM1NzBkNzQ1MzkyOWRkNGM0YmUyZmY=
[05-Jan-2009 19:00:39 +0100]: S: a000 NO Authentication failed.

comment:11 Changed 4 years ago by mosfet

Maybe I need to check my dovecot config.

comment:12 Changed 4 years ago by mosfet

I tried plain auth and it seems ok except that I stay in logging page and there is no error message.
Actually noything happens.

console.log:

[05-Jan-2009 19:29:19 +0100]: S: * OK Dovecot ready.
[05-Jan-2009 19:29:19 +0100]: C: a001 LOGIN "user@…" "user12"
[05-Jan-2009 19:29:19 +0100]: S: a001 OK Logged in.
[05-Jan-2009 19:29:19 +0100]: C: cp01 CAPABILITY
[05-Jan-2009 19:29:19 +0100]: S: * CAPABILITY IMAP4rev1 SASL-IR SORT THREAD=REFERENCES MULTIAPPEND UNSELECT LITERAL+ IDLE CHILDREN NAMESPACE LOGIN-REFERRALS
[05-Jan-2009 19:29:19 +0100]: S: cp01 OK Capability completed.
[05-Jan-2009 19:29:19 +0100]: C: ns1 NAMESPACE
[05-Jan-2009 19:29:19 +0100]: S: * NAMESPACE (("" ".")) NIL NIL
[05-Jan-2009 19:29:19 +0100]: S: ns1 OK Namespace completed.
[05-Jan-2009 19:29:19 +0100]: C: lmb LIST "" "*"
[05-Jan-2009 19:29:19 +0100]: S: * LIST (\HasNoChildren?) "." "Junk"
[05-Jan-2009 19:29:19 +0100]: S: * LIST (\HasNoChildren?) "." "Drafts"
[05-Jan-2009 19:29:19 +0100]: S: * LIST (\HasNoChildren?) "." "Sent"
[05-Jan-2009 19:29:19 +0100]: S: * LIST (\HasNoChildren?) "." "Trash"
[05-Jan-2009 19:29:19 +0100]: S: * LIST (\HasNoChildren?) "." "bug-binutils"
[05-Jan-2009 19:29:19 +0100]: S: * LIST (\HasNoChildren?) "." "gcc-help"
[05-Jan-2009 19:29:19 +0100]: S: * LIST (\HasNoChildren?) "." "INBOX"
[05-Jan-2009 19:29:19 +0100]: S: lmb OK List completed.
[05-Jan-2009 19:29:19 +0100]: C: lsb LSUB "" "*"
[05-Jan-2009 19:29:19 +0100]: S: * LSUB () "." "INBOX"
[05-Jan-2009 19:29:19 +0100]: S: * LSUB () "." "Drafts"
[05-Jan-2009 19:29:19 +0100]: S: * LSUB () "." "Sent"
[05-Jan-2009 19:29:19 +0100]: S: * LSUB () "." "Junk"
[05-Jan-2009 19:29:19 +0100]: S: * LSUB () "." "Trash"
[05-Jan-2009 19:29:19 +0100]: S: * LSUB () "." "bug-binutils"
[05-Jan-2009 19:29:19 +0100]: S: * LSUB () "." "gcc-help"
[05-Jan-2009 19:29:19 +0100]: S: lsb OK Lsub completed.
[05-Jan-2009 19:29:19 +0100]: S: * OK Dovecot ready.
[05-Jan-2009 19:29:19 +0100]: C: a001 LOGIN "user@…" "user12"
[05-Jan-2009 19:29:19 +0100]: S: a001 OK Logged in.

dovecot.info.log:

dovecot: 2009-01-05 19:29:19 Info: auth(default): client out: OK 1 user=forumer@…
dovecot: 2009-01-05 19:29:19 Info: auth-worker(default): sql(forumer@…,88.191.74.51): query: SELECT email as user, password FROM view_users WHERE email='forumer@…';
dovecot: 2009-01-05 19:29:19 Info: auth(default): master in: REQUEST 112 8392 1
dovecot: 2009-01-05 19:29:19 Info: auth(default): master out: USER 112 forumer@… uid=1002 gid=1002 home=/home/vmail/mycompany.com/forumer
dovecot: 2009-01-05 19:29:19 Info: IMAP(forumer@…): Effective uid=1002, gid=1002, home=/home/vmail/mycompany.com/forumer
dovecot: 2009-01-05 19:29:19 Info: IMAP(forumer@…): maildir: data=/home/vmail/mycompany.com/forumer
dovecot: 2009-01-05 19:29:19 Info: IMAP(forumer@…): maildir: root=/home/vmail/mycompany.com/forumer, index=/home/vmail/mycompany.com/forumer, control=, inbox=
dovecot: 2009-01-05 19:29:19 Info: imap-login: Login: user=<forumer@…>, method=PLAIN, rip=89.192.74.52, lip=89.192.74.52, secured
dovecot: 2009-01-05 19:29:19 Info: IMAP(forumer@…): Disconnected: Logged out
dovecot: 2009-01-05 19:29:19 Info: auth(default): client in: AUTH 1 PLAIN service=IMAP secured lip=89.192.74.52 rip=89.192.74.52 resp=<hidden>
dovecot: 2009-01-05 19:29:19 Info: auth(default): client out: OK 1 user=user@…
dovecot: 2009-01-05 19:29:19 Info: auth-worker(default): sql(user@…,89.192.74.52): query: SELECT email as user, password FROM view_users WHERE email='user@…';
dovecot: 2009-01-05 19:29:19 Info: auth(default): master in: REQUEST 113 8419 1
dovecot: 2009-01-05 19:29:19 Info: auth(default): master out: USER 113 user@… uid=1002 gid=1002 home=/home/vmail/mycompany.com/user
dovecot: 2009-01-05 19:29:19 Info: IMAP(user@…): Effective uid=1002, gid=1002, home=/home/vmail/mycompany.com/user
dovecot: 2009-01-05 19:29:19 Info: IMAP(user@…): maildir: data=/home/vmail/mycompany.com/user
dovecot: 2009-01-05 19:29:19 Info: IMAP(user@…): maildir: root=/home/vmail/mycompany.com/user, index=/home/vmail/mycompany.com/user, control=, inbox=
dovecot: 2009-01-05 19:29:19 Info: imap-login: Login: user=<user@…>, method=PLAIN, rip=89.192.74.52, lip=89.192.74.52, secured
dovecot: 2009-01-05 19:29:19 Info: IMAP(user@…): Disconnected: Logged out
dovecot: 2009-01-05 19:29:20 Info: auth(default): new auth connection: pid=8436
dovecot: 2009-01-05 19:29:20 Info: auth(default): new auth connection: pid=8437

Changed 4 years ago by mosfet

0.2 stable : log during a plain-auth

comment:13 Changed 4 years ago by mosfet

When using PLAIN auth and setting $rcmail_configdebug_level? = 4;
when I try to log I can se the following messages :

S: * OK Dovecot ready.
C: a001 LOGIN "user@…" "user12"
S: a001 OK Logged in.
C: I LOGOUT

so as soon as I am authentified, connection is closed.

comment:14 Changed 4 years ago by mosfet

I forgot to update DB schema I may try this.

comment:15 Changed 4 years ago by mosfet

but since I really need to be able to access my emails, if I update DB schema from a 0.2 beta to a 0.2 stable and if it still doesnt' work, will the updated schema work with beta ?

comment:16 Changed 4 years ago by dan

  • Cc daniel@… added

Question: is this two problems?

  1. problem with it failing for CRAM-M5 login with the correct password
  1. outputing 'Warning: Cannot modify header information - headers already sent in /var/www/mycompany/rc/program/include/rcmail.php on line 951' with debug level 4 for any imap login error

just confirming problem 2 exists for plain logins (and 'red' an incorrect password entered')

S: * OK You want mail? Well hurry up.
C: cp01 CAPABILITY
S: * CAPABILITY IMAP4rev1 SASL-IR SORT THREAD=REFERENCES MULTIAPPEND UNSELECT LITERAL+ IDLE CHILDREN NAMESPACE LOGIN-REFERRALS AUTH=PLAIN AUTH=LOGIN
S: cp01 OK Capability completed.
C: a001 LOGIN "daniel" "red"
S: a001 NO Authentication failed.
IMAP Error: Authentication for daniel failed (LOGIN): "a001 NO Authentication failed."

 Warning: Cannot modify header information - headers already sent in /var/www/roundcubemail-0.2-stable-cert/program/include/rcmail.php on line 951

problem 2:
./program/include/bugs.inc writes to output as a result of iil_Connect(called from include/rcube_imap.php) before the kill_session (called from index.php:104) resets the sessauth cookie.

comment:17 Changed 4 years ago by mosfet

So I have tested with another mail client and CRAM-MD5 is working fine, so I confirm there is a bug.

comment:18 Changed 4 years ago by alec

Can you provide a test account for me? Write to alec at alec.pl.

comment:19 Changed 4 years ago by mosfet

see your mails

comment:20 Changed 4 years ago by mosfet

I have reinstalled and everything works fine excexpt a display bug already reported I think

comment:21 Changed 4 years ago by alec

  • Resolution set to invalid
  • Status changed from new to closed

comment:22 Changed 4 years ago by dan

  • Priority changed from 1 - Highest to 6
  • Severity changed from blocker to normal

is it worth reopening this bug at a lower priority for the following error that was part of this?

outputing 'Warning: Cannot modify header information - headers already sent in /var/www/mycompany/rc/program/include/rcmail.php on line 951' with debug level 4 for any imap login error

This is a reasonably hard fix due to the current nesting of errors (see trace when I cc'ed myself here above)

comment:23 Changed 4 years ago by thomasb

No, this is just a side-effect when setting debug_level=4

Note: See TracTickets for help on using tickets.