Bug 604453 - SASL Stress and Server crash: Program quits with the assertion failure in PR_Poll

https://bugzilla.redhat.com/show_bug.cgi?id=604453
Resolves: bug 604453
Bug Description: SASL Stress and Server crash: Program quits with the assertion failure in PR_Poll
Reviewed by: nhosoi (Thanks!)
Branch: master
Fix Description: When the server pushes the SASL IO layer on to the connection
it must do so when there are no other references to the connection.  The only
way to do this without introducing more locking is to have the saslbind code
just register the intent to push SASL IO at the next available time.  This
cannot be done in the sasl bind code (or any operation code for that matter)
because connection_threadmain() will enable the connection for reading
(and polling) after reading the PDU and before calling the operation
function.  Therefore, during the operation function, the connection may be
being actively polled, so we must not access the conn c_prfd.
The best place to push the IO layer is in connection_threadmain, after the
server has notified that there is read ready on the connection, but before
we have actually attempted to read anything.  At this point,
connection_threadmain is the only thread that will be accessing the
connection, and if we push or pop the IO layer before calling the read
function, we are guaranteed to have the correct IO layer to use.
The code has been made generic enough to allow for use by the startTLS code
if the need arises.
I also added some more locking in the saslbind code, and changed the sasl IO
code to more closely resemble the way that the NSS code deals with IO
layer push/pop.
Platforms tested: RHEL5 x86_64
Flag Day: no
Doc impact: no
(cherry picked from commit c28fcadfc7812108573e40f13624e11a5a8609e5)

ldap/servers/slapd/connection.c

@@ -2181,6 +2181,14 @@ connection_threadmain()
 					g_decr_active_threadcnt();
 					return;
 				case CONN_FOUND_WORK_TO_DO:
+					/* note - don't need to lock here - connection should only
+					   be used by this thread - since c_gettingber is set to 1
+					   in connection_activity when the conn is added to the
+					   work queue, setup_pr_read_pds won't add the connection prfd
+					   to the poll list */
+					if (connection_call_io_layer_callbacks(pb->pb_conn)) {
+						LDAPDebug0Args( LDAP_DEBUG_ANY, "Error: could not add/remove IO layers from connection\n" );
+					}
 				default:
 					break;
 			}
@@ -2194,6 +2202,9 @@ connection_threadmain()
 			PR_Lock(conn->c_mutex);
 			/* Make our own pb in turbo mode */
 			connection_make_new_pb(&pb,conn);
+			if (connection_call_io_layer_callbacks(conn)) {
+				LDAPDebug0Args( LDAP_DEBUG_ANY, "Error: could not add/remove IO layers from connection\n" );
+			}
 			PR_Unlock(conn->c_mutex);
 			if (! config_check_referral_mode()) {
 			  slapi_counter_increment(ops_initiated);
@@ -2775,3 +2786,31 @@ connection_abandon_operations( Connection *c )
 		}
 	}
 }
+
+/* must be called within c->c_mutex */
+void
+connection_set_io_layer_cb( Connection *c, Conn_IO_Layer_cb push_cb, Conn_IO_Layer_cb pop_cb, void *cb_data )
+{
+	c->c_push_io_layer_cb = push_cb;
+	c->c_pop_io_layer_cb = pop_cb;
+	c->c_io_layer_cb_data = cb_data;
+}
+
+/* must be called within c->c_mutex */
+int
+connection_call_io_layer_callbacks( Connection *c )
+{
+	int rv = 0;
+	if (c->c_pop_io_layer_cb) {
+		rv = (c->c_pop_io_layer_cb)(c, c->c_io_layer_cb_data);
+		c->c_pop_io_layer_cb = NULL;
+	}
+	if (!rv && c->c_push_io_layer_cb) {
+		rv = (c->c_push_io_layer_cb)(c, c->c_io_layer_cb_data);
+		c->c_push_io_layer_cb = NULL;
+	}
+	c->c_io_layer_cb_data = NULL;
+
+	return rv;
+}
+

ldap/servers/slapd/fe.h

@@ -116,6 +116,8 @@ int connection_operations_pending( Connection *conn, Operation *op2ignore,
 void connection_done(Connection *conn);
 void connection_cleanup(Connection *conn);
 void connection_reset(Connection* conn, int ns, PRNetAddr * from, int fromLen, int is_SSL);
+void connection_set_io_layer_cb( Connection *c, Conn_IO_Layer_cb push_cb, Conn_IO_Layer_cb pop_cb, void *cb_data );
+int connection_call_io_layer_callbacks( Connection *c );
 
 /*
  * conntable.c
@@ -182,7 +184,8 @@ void configure_ns_socket( int * ns );
 /*
  * sasl_io.c
  */
-int sasl_io_enable(Connection *c);
+int sasl_io_enable(Connection *c, void *data);
+int sasl_io_cleanup(Connection *c, void *data);
 
 /*
  * sasl_map.c

ldap/servers/slapd/proto-slap.h

@@ -949,7 +949,6 @@ int slapd_ssl_init();
 int slapd_ssl_init2(PRFileDesc **fd, int startTLS);
 int slapd_security_library_is_initialized();
 int slapd_ssl_listener_is_initialized();
-int sasl_io_cleanup(Connection *c);
 int slapd_SSL_client_auth (LDAP* ld);
 
 /*

ldap/servers/slapd/sasl_io.c

@@ -481,20 +481,33 @@ sasl_io_write(PRFileDesc *fd, const void *buf, PRInt32 amount)
 }
 
 static PRStatus PR_CALLBACK
-sasl_pop_IO_layer(PRFileDesc* stack)
+sasl_pop_IO_layer(PRFileDesc* stack, int doclose)
 {
     PRFileDesc* layer = NULL;
     sasl_io_private *sp = NULL;
+    PRStatus rv = 0;
+    PRDescIdentity id = PR_TOP_IO_LAYER;
 
     /* see if stack has the sasl io layer */
-    if (!sasl_LayerID || !stack || !PR_GetIdentitiesLayer(stack, sasl_LayerID)) {
+    if (!sasl_LayerID || !stack) {
         LDAPDebug0Args( LDAP_DEBUG_CONNS,
                         "sasl_pop_IO_layer: no SASL IO layer\n" );
         return PR_SUCCESS;
     }
 
+    /* if we're not being called during PR_Close, then we just want to
+       pop the sasl io layer if it is on the stack */
+    if (!doclose) {
+        id = sasl_LayerID;
+        if (!PR_GetIdentitiesLayer(stack, id)) {
+            LDAPDebug0Args( LDAP_DEBUG_CONNS,
+                            "sasl_pop_IO_layer: no SASL IO layer\n" );
+            return PR_SUCCESS;
+        }
+    }
+
     /* remove the layer from the stack */
-    layer = PR_PopIOLayer(stack, sasl_LayerID);
+    layer = PR_PopIOLayer(stack, id);
     if (!layer) {
         LDAPDebug0Args( LDAP_DEBUG_CONNS,
                         "sasl_pop_IO_layer: error - could not pop SASL IO layer\n" );
@@ -517,23 +530,29 @@ sasl_pop_IO_layer(PRFileDesc* stack)
         layer->dtor(layer);
     }
 
-    return PR_SUCCESS;
+    if (doclose) {
+        rv = stack->methods->close(stack);
+    } else {
+        rv = PR_SUCCESS;
+    }
+
+    return rv;
 }
 
 static PRStatus PR_CALLBACK
 closeLayer(PRFileDesc* stack)
 {
+    PRStatus rv = 0;
     LDAPDebug0Args( LDAP_DEBUG_CONNS,
                     "closeLayer: closing SASL IO layer\n" );
-    if (PR_FAILURE == sasl_pop_IO_layer(stack)) {
+    rv = sasl_pop_IO_layer(stack, 1 /* do close */);
+    if (PR_SUCCESS != rv) {
         LDAPDebug0Args( LDAP_DEBUG_CONNS,
-                        "closeLayer: error closing SASL IO layer\n" );
-        return PR_FAILURE;
+                    "closeLayer: error closing SASL IO layer\n" );
+        return rv;
     }
 
-    LDAPDebug0Args( LDAP_DEBUG_CONNS,
-                    "closeLayer: calling PR_Close to close other layers\n" );
-    return PR_Close(stack);
+    return rv;
 }
 
 static PRStatus PR_CALLBACK
@@ -561,22 +580,28 @@ initialize(void)
 /*
  * Push the SASL I/O layer on top of the current NSPR I/O layer of the prfd used
  * by the connection.
+ * must be called with the connection lock (c_mutex) held or in a condition in which
+ * no other threads are accessing conn->c_prfd
  */
 int
-sasl_io_enable(Connection *c)
+sasl_io_enable(Connection *c, void *data /* UNUSED */)
 {
     PRStatus rv = PR_CallOnce(&sasl_callOnce, initialize);
     if (PR_SUCCESS == rv) {
-        PRFileDesc* layer = PR_CreateIOLayerStub(sasl_LayerID, &sasl_IoMethods);
-        sasl_io_private *sp = (sasl_io_private*) slapi_ch_calloc(1, sizeof(sasl_io_private));
+        PRFileDesc* layer = NULL;
+        sasl_io_private *sp = NULL;
 
+        if ( c->c_flags & CONN_FLAG_CLOSING ) {
+            slapi_log_error( SLAPI_LOG_FATAL, "sasl_io_enable",
+                             "Cannot enable SASL security on connection in CLOSING state\n");
+            return PR_FAILURE;
+        }
+        layer = PR_CreateIOLayerStub(sasl_LayerID, &sasl_IoMethods);
+        sp = (sasl_io_private*) slapi_ch_calloc(1, sizeof(sasl_io_private));
         sasl_io_init_buffers(sp);
         layer->secret = sp;
-
-        PR_Lock( c->c_mutex );
         sp->conn = c;
         rv = PR_PushIOLayer(c->c_prfd, PR_TOP_IO_LAYER, layer);
-        PR_Unlock( c->c_mutex );
         if (rv) {
             LDAPDebug( LDAP_DEBUG_ANY,
                        "sasl_io_enable: error enabling sasl io on connection %" NSPRIu64 " %d:%s\n", c->c_connid, rv, slapd_pr_strerror(rv) );
@@ -592,17 +617,17 @@ sasl_io_enable(Connection *c)
 /*
  * Remove the SASL I/O layer from the top of the current NSPR I/O layer of the prfd used
  * by the connection.  Must either be called within the connection lock, or be
- * called while the connection is not being referenced by another thread.
+ * called while the connection (c_prfd) is not being referenced by another thread.
  */
 int
-sasl_io_cleanup(Connection *c)
+sasl_io_cleanup(Connection *c, void *data /* UNUSED */)
 {
     int ret = 0;
 
     LDAPDebug( LDAP_DEBUG_CONNS,
                "sasl_io_cleanup for connection %" NSPRIu64 "\n", c->c_connid, 0, 0 );
 
-    ret = sasl_pop_IO_layer(c->c_prfd);
+    ret = sasl_pop_IO_layer(c->c_prfd, 0 /* do not close */);
 
     c->c_sasl_ssf = 0;
 

ldap/servers/slapd/saslbind.c

@@ -800,10 +800,12 @@ void ids_sasl_check_bind(Slapi_PBlock *pb)
     PR_ASSERT(pb);
     PR_ASSERT(pb->pb_conn);
 
+    PR_Lock(pb->pb_conn->c_mutex);
     continuing = pb->pb_conn->c_flags & CONN_FLAG_SASL_CONTINUE;
     pb->pb_conn->c_flags &= ~CONN_FLAG_SASL_CONTINUE; /* reset flag */
 
     sasl_conn = (sasl_conn_t*)pb->pb_conn->c_sasl_conn;
+    PR_Unlock(pb->pb_conn->c_mutex);
     if (sasl_conn == NULL) {
         send_ldap_result( pb, LDAP_AUTH_METHOD_NOT_SUPPORTED, NULL,
                           "sasl library unavailable", 0, NULL );
@@ -820,6 +822,7 @@ void ids_sasl_check_bind(Slapi_PBlock *pb)
      * library that CRAM-MD5 is disabled, but it gives us a
      * different error code to SASL_NOMECH.
      */
+    /* richm - this locks and unlocks pb->pb_conn */
     if (!ids_sasl_mech_supported(pb, sasl_conn, mech)) {
       rc = SASL_NOMECH;
       goto sasl_check_result;
@@ -857,30 +860,33 @@ void ids_sasl_check_bind(Slapi_PBlock *pb)
      * using the new mechanism.  We also need to do this if the
      * mechanism changed in the middle of the SASL authentication
      * process. */
+    PR_Lock(pb->pb_conn->c_mutex);
     if ((pb->pb_conn->c_flags & CONN_FLAG_SASL_COMPLETE) || continuing) {
+        Slapi_Operation *operation;
+        slapi_pblock_get( pb, SLAPI_OPERATION, &operation);
+        slapi_log_error(SLAPI_LOG_CONNS, "ids_sasl_check_bind",
+                        "cleaning up sasl IO conn=%d op=%d complete=%d continuing=%d\n",
+                        pb->pb_conn->c_connid, operation->o_opid,
+                        (pb->pb_conn->c_flags & CONN_FLAG_SASL_COMPLETE), continuing);
         /* reset flag */
         pb->pb_conn->c_flags &= ~CONN_FLAG_SASL_COMPLETE;
 
-        /* Lock the connection mutex */
-        PR_Lock(pb->pb_conn->c_mutex);
-
         /* remove any SASL I/O from the connection */
-        sasl_io_cleanup(pb->pb_conn);
+        connection_set_io_layer_cb(pb->pb_conn, NULL, sasl_io_cleanup, NULL);
 
         /* dispose of sasl_conn and create a new sasl_conn */
         sasl_dispose(&sasl_conn);
         ids_sasl_server_new(pb->pb_conn);
         sasl_conn = (sasl_conn_t*)pb->pb_conn->c_sasl_conn;
 
-        /* Unlock the connection mutex */
-        PR_Unlock(pb->pb_conn->c_mutex);
-
         if (sasl_conn == NULL) {
             send_ldap_result( pb, LDAP_AUTH_METHOD_NOT_SUPPORTED, NULL,
                           "sasl library unavailable", 0, NULL );
+            PR_Unlock(pb->pb_conn->c_mutex);
             return;
         }
     }
+    PR_Unlock(pb->pb_conn->c_mutex);
 
     rc = sasl_server_start(sasl_conn, mech, 
                            cred->bv_val, cred->bv_len, 
@@ -890,9 +896,6 @@ void ids_sasl_check_bind(Slapi_PBlock *pb)
 
     switch (rc) {
     case SASL_OK:               /* complete */
-        /* Set a flag to signify that sasl bind is complete */
-        pb->pb_conn->c_flags |= CONN_FLAG_SASL_COMPLETE;
-
         /* retrieve the authenticated username */
         if (sasl_getprop(sasl_conn, SASL_USERNAME,
                          (const void**)&username) != SASL_OK) {
@@ -922,6 +925,35 @@ void ids_sasl_check_bind(Slapi_PBlock *pb)
         }
 
         slapi_pblock_set( pb, SLAPI_BIND_TARGET, slapi_ch_strdup( dn ) );
+        /* see if we negotiated a security layer */
+        if ((sasl_getprop(sasl_conn, SASL_SSF, 
+                          (const void**)&ssfp) == SASL_OK) && (*ssfp > 0)) {
+            LDAPDebug(LDAP_DEBUG_TRACE, "sasl ssf=%u\n", (unsigned)*ssfp, 0, 0);
+        } else {
+            *ssfp = 0;
+        }
+
+        /* this is stuff we have to do inside the conn mutex */
+        PR_Lock(pb->pb_conn->c_mutex);
+        /* Set a flag to signify that sasl bind is complete */
+        pb->pb_conn->c_flags |= CONN_FLAG_SASL_COMPLETE;
+        /* note - we set this here in case there are pre-bind
+           plugins that want to know what the negotiated
+           ssf is - but this happens before we actually set
+           up the socket for SASL encryption - so one
+           consequence is that we attempt to do sasl
+           encryption on the connection after the pre-bind
+           plugin has been called, and sasl encryption fails
+           and the operation returns an error */
+        pb->pb_conn->c_sasl_ssf = (unsigned)*ssfp;
+
+        /* set the connection bind credentials */
+        PR_snprintf(authtype, sizeof(authtype), "%s%s", SLAPD_AUTH_SASL, mech);
+        bind_credentials_set_nolock(pb->pb_conn, authtype, dn, 
+                                    NULL, NULL, NULL, bind_target_entry);
+
+        PR_Unlock(pb->pb_conn->c_mutex);
+
         if (plugin_call_plugins( pb, SLAPI_PLUGIN_PRE_BIND_FN ) != 0){
             break;
         }
@@ -942,26 +974,6 @@ void ids_sasl_check_bind(Slapi_PBlock *pb)
             }
         }
 
-        /* see if we negotiated a security layer */
-        if ((sasl_getprop(sasl_conn, SASL_SSF, 
-                          (const void**)&ssfp) == SASL_OK) && (*ssfp > 0)) {
-            LDAPDebug(LDAP_DEBUG_TRACE, "sasl ssf=%u\n", (unsigned)*ssfp, 0, 0);
-
-            /* Enable SASL I/O on the connection now */
-            if (0 != sasl_io_enable(pb->pb_conn) ) {
-                send_ldap_result(pb, LDAP_OPERATIONS_ERROR, NULL,
-                                 "failed to enable sasl i/o",
-                                 0, NULL);
-            }
-	        /* Set the SSF in the connection */
-	        pb->pb_conn->c_sasl_ssf = (unsigned)*ssfp;
-        }
-
-        /* set the connection bind credentials */
-        PR_snprintf(authtype, sizeof(authtype), "%s%s", SLAPD_AUTH_SASL, mech);
-        bind_credentials_set(pb->pb_conn, authtype, dn, 
-                             NULL, NULL, NULL, bind_target_entry);
-
         /* set the auth response control if requested */
         slapi_pblock_get(pb, SLAPI_REQCONTROLS, &ctrls);
         if (slapi_control_present(ctrls, LDAP_CONTROL_AUTH_REQUEST, 
@@ -1017,11 +1029,17 @@ void ids_sasl_check_bind(Slapi_PBlock *pb)
             slapi_pblock_set(pb, SLAPI_BIND_RET_SASLCREDS, &bvr);
         }
 
+        /* see if we negotiated a security layer */
+        if (*ssfp > 0) {
+            /* Enable SASL I/O on the connection */
+            PR_Lock(pb->pb_conn->c_mutex);
+            connection_set_io_layer_cb(pb->pb_conn, sasl_io_enable, NULL, NULL);
+            PR_Unlock(pb->pb_conn->c_mutex);
+        }
+
         /* send successful result */
         send_ldap_result( pb, LDAP_SUCCESS, NULL, NULL, 0, NULL );
 
-        /* TODO: enable sasl security layer */
-
         /* remove the sasl data from the pblock */
         slapi_pblock_set(pb, SLAPI_BIND_RET_SASLCREDS, NULL);
 

ldap/servers/slapd/slap.h

@@ -1290,6 +1290,8 @@ typedef struct op {
  * represents a connection from an ldap client
  */
 
+typedef int (*Conn_IO_Layer_cb)(struct conn*, void *data);
+
 struct Conn_Private;
 typedef struct Conn_private Conn_private;
 
@@ -1345,6 +1347,11 @@ typedef struct conn {
     int             c_sort_result_code;    /* sort result put in response */
     time_t          c_timelimit;           /* time limit for this connection */
     /* PAGED_RESULTS ENDS */
+    /* IO layer push/pop */
+    Conn_IO_Layer_cb c_push_io_layer_cb; /* callback to push an IO layer on the conn->c_prfd */
+    Conn_IO_Layer_cb c_pop_io_layer_cb; /* callback to pop an IO layer off of the conn->c_prfd */
+    void             *c_io_layer_cb_data; /* callback data */
+
 } Connection;
 #define CONN_FLAG_SSL	1	/* Is this connection an SSL connection or not ? 
 							 * Used to direct I/O code when SSL is handled differently