saslauthd against courier-imap server results in "Unexpected response from remote authentication server"

[Dan White]

On 28/04/10 11:14 +0300, Oguz Yilmaz wrote:
>What can be the problem ? It works on 2.1.15 and not works on 2.1.22
>and 2.1.24rc.
>Are there anybody to show a way?
>
>I have tried to compile 2.1.15 rpm in EL5 wwith no success.

Are all three versions using the same courier server?

>> * OK [CAPABILITY IMAP4rev1 UIDPLUS CHILDREN NAMESPACE
>> THREAD=ORDEREDSUBJECT THREAD=REFERENCES SORT QUOTA IDLE ACL ACL2=UNION
>> STARTTLS] Courier-IMAP ready. Copyright 1998-2005 Double Precision,
>> Inc.  See COPYING for distribution information.
>>
>> Actually saslauthd give up after imap server has sent the "OK LOGIN
>> Ok" message. It does not wait for the answer because of some error. At
>> Redhat Bugzilla, there is similar problem with Dovecot. however the
>> patch Lutz provided does not work with Courier IMAP.
>> https://bugzilla.redhat.com/show_bug.cgi?id=582540

The tcpdump and strace outputs below indicate that the initial greeting is
being fragmented into separate packets.

saslauthd appears to only grab the first packet and assumes the whole
greeting is contained in that packet. The patch from the Redhat bug report
may not be sufficient. saslauthd should be reading until a CRLF is reached,
since there may be more than two packets involved.

Please file a bug report at https://bugzilla.andrew.cmu.edu/.

>> Some Tcpdump output:
>>
>> 09:07:21.963576 IP 192.168.1.2.42412 > 12.12.12.12.143: P 1:58(57) ack
>> 47 win 46 <nop,nop,timestamp 526135 408482924>
>> q......b....."o..JGZ......<.....
>> ...7.X.lsaslauthd LOGIN "test ....
>>
>> 09:07:22.435365 IP 12.12.12.12.143 > 192.168.1.2.42412: P 47:243(196)
>> ack 1 win 33360 <nop,nop,timestamp 408483396 526134>
>> E..... at .:.I...b.........JGZ."o.....P.......
>> .X.D...6MESPACE THREAD=ORDEREDSUBJEC
>>
>> 09:07:22.435814 IP 192.168.1.2.42412 > 12.12.12.12.143: F 58:58(0) ack
>> 243 win 54 <nop,nop,timestamp 526607 408483396>
>> .......b....."o.GJGZ....63......
>> ..      ..X.D
>>
>> 09:07:22.534349 IP 12.12.12.12.143 > 192.168.1.2.42412: P 243:267(24)
>> ack 58 win 33360 <nop,nop,timestamp 408483496 526135>
>> E..L.. at .:.J...b.........JGZ."o.G...P.F.....
>> .X.....7saslauthd OK LOGIN Ok.
>>
>> 09:07:22.534479 IP 192.168.1.2.42412 > 12.12.12.12.143: R
>> 577750087:577750087(0) win 0
>> E..(.. at .@.A.......b....."o.G....P...)...
>>
>>
>> Some Strace Output:
>>
>> socket(PF_INET, SOCK_STREAM, IPPROTO_TCP) = 8
>> connect(8, {sa_family=AF_INET, sin_port=htons(143),
>> sin_addr=inet_addr("12.12.12.12")}, 16) = 0
>> rt_sigaction(SIGALRM, {0x804b6a0, [ALRM], SA_RESTART}, {0x1, [], 0}, 8) = 0
>> rt_sigaction(SIGPIPE, {0x804b6a0, [PIPE], SA_RESTART}, {0x1, [], 0}, 8) = 0
>> alarm(30)                               = 0
>> read(8, "* OK [CAPABILITY IMAP4rev1 UIDPLUS CHILDREN NA", 1000) = 46
>> alarm(0)                                = 30
>> alarm(30)                               = 0
>> writev(8, [{"saslauthd LOGIN ", 16}, {"\"test\"", 30}, {" ", 1},
>> {"\"test\"", 8}, {"\r\n", 2}], 5) = 57
>> alarm(0)                                = 30
>> alarm(30)                               = 0
>> read(8, "MESPACE THREAD=ORDEREDSUBJECT THREAD=REFERENCES SORT QUOTA
>> IDLE ACL ACL2=UNION STARTTLS] Courier-IMAP ready. Copyright 1998-2005
>> Double Precision, Inc.  See COPYING for distribution
>> information.\r\n", 1000) = 196
>> alarm(0)                                = 30
>> close(8)                                = 0
>> time(NULL)                              = 1271917242
>> stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2721, ...}) = 0
>> stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2721, ...}) = 0
>> stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2721, ...}) = 0
>> send(3, "<36>Apr 22 09:20:42 saslauthd[13399]: auth_rimap: unexpected
>> response to auth request: MESPACE THREAD=ORDEREDSUBJECT
>> THREAD=REFERENCES SORT QUOTA IDLE ACL ACL2=UNION STARTTLS]
>> Courier-IMAP ready. Copyright 1998-2005 Double Precision, Inc.  See
>> COPYING for distribution information.\0", 282, MSG_NOSIGNAL) = 282
>> time(NULL)                              = 1271917242
>> stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2721, ...}) = 0
>> stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2721, ...}) = 0
>> stat64("/etc/localtime", {st_mode=S_IFREG|0644, st_size=2721, ...}) = 0
>> send(3, "<38>Apr 22 09:20:42 saslauthd[13399]: do_auth         : auth
>> failure: [user=test] [service=smtp] [realm=] [mech=rimap]
>> [reason=[ALERT] Unexpected response from remote authentication
>> server]\0", 214, MSG_NOSIGNAL) = 214
>> write(7, "\0@", 2)                      = 2
>> write(7, "NO [ALERT] Unexpected response from remote authentication
>> server", 64) = 64
>> close(7)                                = 0
>> fcntl64(6, F_SETLKW, {type=F_WRLCK, whence=SEEK_SET, start=0, len=1}) = 0
>> accept(5,

-- 
Dan White