The place where B1 (SLAPD_DISCONNECT_BAD_BER_TAG) is set and returned is in the function connection_read_operation. It calls connection_read_ldap_data and if 0 is returned, it considers the connection is already closed and it cleans up the resource and return CONN_DONE.
1684 int connection_read_operation(Connection *conn, Operation *op, ber_tag_t *tag, int *remaining_data)
1685 {
[...]
1734 /* We make a non-blocking read call */
1735 ret = connection_read_ldap_data(conn,&err);
1736 if (ret <= 0) {
1737 if (0 == ret) {
1738 /* Connection is closed */
1739 PR_Lock( conn->c_mutex );
1740 disconnect_server_nomutex( conn, conn->c_connid, -1, SLAPD_DISCONNECT_BAD_BER_TAG, 0 );
1741 conn->c_gettingber = 0;
1742 PR_Unlock( conn->c_mutex );
1743 signal_listner();
1744 return CONN_DONE;
1745 }
In connection_read_ldap_data, sasl_reciv_connection is called for the SASL auth case. In the function, if nothing is in the decrypted buffer (line 260 in the following snippet), it reads from the socket to fill in the encrypted_buffer. And if "sasl_io_finished_packet(sp)" is true, it thinks it read the enough size of encrypted data and decrypt it in the decrypted_buffer. But, if "sasl_io_finished_packet(sp)" is false, it does not do any further job, and since bytes_to_return is still 0, it returns 0. That is, if the sasl request is not read by one call of sasl_io_read_packet, it looks to me that the server misinterprets it with B1 and closes the connection.
249 sasl_recv_connection(Connection *c, char *buffer, size_t count,PRInt32 *err)
250 {
251 int ret = 0;
252 size_t bytes_in_buffer = 0;
253 sasl_io_private *sp = c->c_sasl_io_private;
254
255 *err = 0;
256 LDAPDebug( LDAP_DEBUG_CONNS,
257 "sasl_recv_connection for connection %d\n", c->c_connid, 0, 0 );
258 /* Do we have decrypted data buffered from 'before' ? */
259 bytes_in_buffer = sp->decrypted_buffer_count - sp->decrypted_buffer_offset;
260 if (0 == bytes_in_buffer) {
261 /* If there wasn't buffered decrypted data, we need to get some. .. */
277 /* Are we there yet ? */
278 if (sasl_io_finished_packet(sp)) {
279 const char *output_buffer = NULL;
[...]
301 }
302 /* Finally, return data from the buffer to the caller */
303 {
304 size_t bytes_to_return = sp->decrypted_buffer_count - sp->decrypted_buffer_offset;
This is sasl_io_finished_packet call:
183 static int
184 sasl_io_finished_packet(sasl_io_private *sp)
185 {
186 return (sp->encrypted_buffer_count && (sp->encrypted_buffer_offset == sp->encrypted_buffer_count) );
187 }
188
I haven't successfully reproduced it yet, so it may not be the exact cause of the original problem, but I think we should support this particular case... Here's my proposal. If it looks reasonable, I'm opening a bug for this problem.
Index: sasl_io.c
===================================================================
RCS file: /cvs/dirsec/ldapserver/ldap/servers/slapd/sasl_io.c,v
retrieving revision 1.10
diff -t -w -U4 -r1.10 sasl_io.c
--- sasl_io.c 10 Nov 2006 23:45:40 -0000 1.10
+++ sasl_io.c 24 Apr 2007 01:34:08 -0000
@@ -269,14 +269,16 @@
}
/* We now have the packet length
* we now must read more data off the wire until we have the complete packet
*/
+ do {
ret = sasl_io_read_packet(c,err);
if (0 == ret || -1 == ret) {
return ret;
}
- /* Are we there yet ? */
- if (sasl_io_finished_packet(sp)) {
+ } while (!sasl_io_finished_packet(sp));
+ /* We are there. */
+ {
const char *output_buffer = NULL;
unsigned int output_length = 0;
LDAPDebug( LDAP_DEBUG_CONNS,
"sasl_recv_connection finished reading packet for connection %d\n", c->c_connid, 0, 0 );