X-Git-Url: https://git.sur5r.net/?a=blobdiff_plain;ds=sidebyside;f=servers%2Fslapd%2Fconnection.c;h=439c6fdd1c0210776692d9e015e5479f0d27ef48;hb=b09727567d047cb79c8da8545cca9c8355822185;hp=9ba74d49a002d54e073494901ede3f291fa77475;hpb=466ff113e184deb33849e7e1a708384c4aececa3;p=openldap diff --git a/servers/slapd/connection.c b/servers/slapd/connection.c index 9ba74d49a0..439c6fdd1c 100644 --- a/servers/slapd/connection.c +++ b/servers/slapd/connection.c @@ -73,8 +73,13 @@ int connections_init(void) assert( connections == NULL ); if( connections != NULL) { +#ifdef NEW_LOGGING + LDAP_LOG(( "connection", LDAP_LEVEL_INFO, + "connections_init: already initialized.\n" )); +#else Debug( LDAP_DEBUG_ANY, "connections_init: already initialized.\n", 0, 0, 0 ); +#endif return -1; } @@ -84,9 +89,15 @@ int connections_init(void) connections = (Connection *) calloc( dtblsize, sizeof(Connection) ); if( connections == NULL ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "connection", LDAP_LEVEL_ERR, + "connections_init: allocation (%d * %ld) of connection array failed\n", + dtblsize, (long) sizeof(Connection) )); +#else Debug( LDAP_DEBUG_ANY, "connections_init: allocation (%d*%ld) of connection array failed\n", dtblsize, (long) sizeof(Connection), 0 ); +#endif return -1; } @@ -111,8 +122,13 @@ int connections_destroy(void) /* should check return of every call */ if( connections == NULL) { +#ifdef NEW_LOGGING + LDAP_LOG(( "connection", LDAP_LEVEL_INFO, + "connections_destroy: nothing to destroy.\n")); +#else Debug( LDAP_DEBUG_ANY, "connections_destroy: nothing to destroy.\n", 0, 0, 0 ); +#endif return -1; } @@ -169,7 +185,7 @@ int connections_timeout_idle(time_t now) int connindex; Connection* c; - for( c = connection_first( &connindex ); + for( c = connection_first( &connindex ); c != NULL; c = connection_next( c, &connindex ) ) { @@ -191,9 +207,14 @@ static Connection* connection_get( ber_socket_t s ) Connection *c; +#ifdef NEW_LOGGING + LDAP_LOG(( "connection", LDAP_LEVEL_ENTRY, + "connection_get: socket %ld\n", (long)s )); +#else Debug( LDAP_DEBUG_ARGS, "connection_get(%ld)\n", (long) s, 0, 0 ); +#endif assert( connections != NULL ); @@ -251,17 +272,27 @@ static Connection* connection_get( ber_socket_t s ) assert( c->c_conn_state == SLAP_C_INVALID ); assert( sd == AC_SOCKET_INVALID ); +#ifdef NEW_LOGGING + LDAP_LOG(( "connection", LDAP_LEVEL_ARGS, + "connection_get: connection %d not used\n", s )); +#else Debug( LDAP_DEBUG_TRACE, "connection_get(%d): connection not used\n", s, 0, 0 ); +#endif ldap_pvt_thread_mutex_unlock( &c->c_mutex ); return NULL; } +#ifdef NEW_LOGGING + LDAP_LOG(( "connection", LDAP_LEVEL_RESULTS, + "connection_get: get for %d got connid %ld\n",s, c->c_connid )); +#else Debug( LDAP_DEBUG_TRACE, "connection_get(%d): got connid=%ld\n", s, c->c_connid, 0 ); +#endif c->c_n_get++; @@ -269,7 +300,7 @@ static Connection* connection_get( ber_socket_t s ) assert( c->c_conn_state != SLAP_C_INVALID ); assert( sd != AC_SOCKET_INVALID ); - c->c_activitytime = slap_get_time(); + c->c_activitytime = slap_get_time(); } return c; @@ -304,9 +335,14 @@ long connection_init( #endif if( s == AC_SOCKET_INVALID ) { - Debug( LDAP_DEBUG_ANY, - "connection_init(%ld): invalid.\n", - (long) s, 0, 0 ); +#ifdef NEW_LOGGING + LDAP_LOG(( "connection", LDAP_LEVEL_INFO, + "connection_init: init of socket %ld invalid.\n", (long)s )); +#else + Debug( LDAP_DEBUG_ANY, + "connection_init(%ld): invalid.\n", + (long) s, 0, 0 ); +#endif return -1; } @@ -326,69 +362,81 @@ long connection_init( c = NULL; - for( i=0; i < dtblsize; i++) { - ber_socket_t sd; + for( i=0; i < dtblsize; i++) { + ber_socket_t sd; - if( connections[i].c_struct_state == SLAP_C_UNINITIALIZED ) { - assert( connections[i].c_sb == 0 ); - c = &connections[i]; - break; - } + if( connections[i].c_struct_state == SLAP_C_UNINITIALIZED ) { + assert( connections[i].c_sb == 0 ); + c = &connections[i]; + break; + } sd = AC_SOCKET_INVALID; if (connections[i].c_sb != NULL) - ber_sockbuf_ctrl( connections[i].c_sb, LBER_SB_OPT_GET_FD, &sd ); + ber_sockbuf_ctrl( connections[i].c_sb, LBER_SB_OPT_GET_FD, &sd ); - if( connections[i].c_struct_state == SLAP_C_UNUSED ) { - assert( sd == AC_SOCKET_INVALID ); - c = &connections[i]; - break; - } - - assert( connections[i].c_struct_state == SLAP_C_USED ); - assert( connections[i].c_conn_state != SLAP_C_INVALID ); - assert( sd != AC_SOCKET_INVALID ); - } - - if( c == NULL ) { - Debug( LDAP_DEBUG_ANY, + if( connections[i].c_struct_state == SLAP_C_UNUSED ) { + assert( sd == AC_SOCKET_INVALID ); + c = &connections[i]; + break; + } + + assert( connections[i].c_struct_state == SLAP_C_USED ); + assert( connections[i].c_conn_state != SLAP_C_INVALID ); + assert( sd != AC_SOCKET_INVALID ); + } + + if( c == NULL ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "connection", LDAP_LEVEL_INFO, + "connection_init: skt %d connection table full (%d/%d)\n", + s, i, dtblsize )); +#else + Debug( LDAP_DEBUG_ANY, "connection_init(%d): connection table full (%d/%d)\n", s, i, dtblsize); - ldap_pvt_thread_mutex_unlock( &connections_mutex ); - return -1; - } +#endif + ldap_pvt_thread_mutex_unlock( &connections_mutex ); + return -1; + } } #endif assert( c != NULL ); - if( c->c_struct_state == SLAP_C_UNINITIALIZED ) { + if( c->c_struct_state == SLAP_C_UNINITIALIZED ) { c->c_authmech = NULL; - c->c_dn = NULL; - c->c_cdn = NULL; + c->c_dn = NULL; + c->c_cdn = NULL; c->c_listener_url = NULL; c->c_peer_domain = NULL; - c->c_peer_name = NULL; - c->c_sock_name = NULL; + c->c_peer_name = NULL; + c->c_sock_name = NULL; - c->c_ops = NULL; - c->c_pending_ops = NULL; + c->c_ops = NULL; + c->c_pending_ops = NULL; c->c_sasl_bind_mech = NULL; c->c_sasl_context = NULL; c->c_sasl_extra = NULL; - c->c_sb = ber_sockbuf_alloc( ); + c->c_sb = ber_sockbuf_alloc( ); + + { + ber_len_t max = sockbuf_max_incoming; + ber_sockbuf_ctrl( c->c_sb, LBER_SB_OPT_SET_MAX_INCOMING, &max ); + } + c->c_currentber = NULL; - /* should check status of thread calls */ - ldap_pvt_thread_mutex_init( &c->c_mutex ); - ldap_pvt_thread_mutex_init( &c->c_write_mutex ); - ldap_pvt_thread_cond_init( &c->c_write_cv ); + /* should check status of thread calls */ + ldap_pvt_thread_mutex_init( &c->c_mutex ); + ldap_pvt_thread_mutex_init( &c->c_write_mutex ); + ldap_pvt_thread_cond_init( &c->c_write_cv ); - c->c_struct_state = SLAP_C_UNUSED; - } + c->c_struct_state = SLAP_C_UNUSED; + } ldap_pvt_thread_mutex_lock( &c->c_mutex ); @@ -443,9 +491,15 @@ long connection_init( if( ber_sockbuf_ctrl( c->c_sb, LBER_SB_OPT_SET_NONBLOCK, c /* non-NULL */ ) < 0 ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "connection", LDAP_LEVEL_INFO, + "connection_init: conn %d set nonblocking failed\n", + c->c_connid )); +#else Debug( LDAP_DEBUG_ANY, "connection_init(%d, %s): set nonblocking failed\n", s, c->c_peer_name, 0 ); +#endif } id = c->c_connid = conn_nextid++; @@ -482,14 +536,19 @@ void connection2anonymous( Connection *c ) assert( connections != NULL ); assert( c != NULL ); + { + ber_len_t max = sockbuf_max_incoming; + ber_sockbuf_ctrl( c->c_sb, LBER_SB_OPT_SET_MAX_INCOMING, &max ); + } + if(c->c_authmech != NULL ) { free(c->c_authmech); c->c_authmech = NULL; } if(c->c_dn != NULL) { - free(c->c_dn); - c->c_dn = NULL; + free(c->c_dn); + c->c_dn = NULL; } if(c->c_cdn != NULL) { @@ -576,9 +635,15 @@ connection_destroy( Connection *c ) c->c_connid, sd, 0, 0, 0 ); } - ber_sockbuf_free( c->c_sb ); + ber_sockbuf_free( c->c_sb ); + c->c_sb = ber_sockbuf_alloc( ); + { + ber_len_t max = sockbuf_max_incoming; + ber_sockbuf_ctrl( c->c_sb, LBER_SB_OPT_SET_MAX_INCOMING, &max ); + } + c->c_conn_state = SLAP_C_INVALID; c->c_struct_state = SLAP_C_UNUSED; } @@ -632,10 +697,15 @@ void connection_closing( Connection *c ) ber_socket_t sd; ber_sockbuf_ctrl( c->c_sb, LBER_SB_OPT_GET_FD, &sd ); +#ifdef NEW_LOGGING + LDAP_LOG(( "connection", LDAP_LEVEL_DETAIL1, + "connection_closing: conn %d readying socket %d for close.\n", + c->c_connid, sd )); +#else Debug( LDAP_DEBUG_TRACE, "connection_closing: readying conn=%ld sd=%d for close\n", c->c_connid, sd, 0 ); - +#endif /* update state to closing */ c->c_conn_state = SLAP_C_CLOSING; @@ -664,16 +734,26 @@ static void connection_close( Connection *c ) ber_sockbuf_ctrl( c->c_sb, LBER_SB_OPT_GET_FD, &sd ); if( c->c_ops != NULL ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "connection", LDAP_LEVEL_DETAIL1, + "connection_close: conn %d deferring sd %d\n", + c->c_connid, sd )); +#else Debug( LDAP_DEBUG_TRACE, "connection_close: deferring conn=%ld sd=%d\n", c->c_connid, sd, 0 ); - +#endif return; } +#ifdef NEW_LOGGING + LDAP_LOG(( "connection", LDAP_LEVEL_RESULTS, + "connection_close: conn %d sd %d\n", + c->c_connid, sd )); +#else Debug( LDAP_DEBUG_TRACE, "connection_close: conn=%ld sd=%d\n", c->c_connid, sd, 0 ); - +#endif connection_destroy( c ); } @@ -772,9 +852,15 @@ connection_operation( void *arg_v ) ldap_pvt_thread_mutex_unlock( &num_ops_mutex ); if( conn->c_sasl_bind_in_progress && tag != LDAP_REQ_BIND ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "connection", LDAP_LEVEL_ERR, + "connection_operation: conn %d SASL bind in progress (tag=%ld).\n", + conn->c_connid, (long)tag )); +#else Debug( LDAP_DEBUG_ANY, "connection_operation: " "error: SASL bind in progress (tag=%ld).\n", (long) tag, 0, 0 ); +#endif send_ldap_result( conn, arg->co_op, rc = LDAP_OPERATIONS_ERROR, NULL, "SASL bind in progress", NULL, NULL ); @@ -823,8 +909,14 @@ connection_operation( void *arg_v ) break; default: +#ifdef NEW_LOGGING + LDAP_LOG(( "connection", LDAP_LEVEL_INFO, + "connection_operation: conn %d unknown LDAP request 0x%lx\n", + conn->c_connid, tag )); +#else Debug( LDAP_DEBUG_ANY, "unknown LDAP request 0x%lx\n", tag, 0, 0 ); +#endif arg->co_op->o_tag = LBER_ERROR; send_ldap_disconnect( conn, arg->co_op, LDAP_PROTOCOL_ERROR, "unknown LDAP request" ); @@ -886,10 +978,15 @@ int connection_read(ber_socket_t s) c = connection_get( s ); if( c == NULL ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "connection", LDAP_LEVEL_INFO, + "connection_read: sock %ld no connection\n", + (long)s )); +#else Debug( LDAP_DEBUG_ANY, "connection_read(%ld): no connection!\n", (long) s, 0, 0 ); - +#endif slapd_remove(s, 0); ldap_pvt_thread_mutex_unlock( &connections_mutex ); @@ -899,18 +996,28 @@ int connection_read(ber_socket_t s) c->c_n_read++; if( c->c_conn_state == SLAP_C_CLOSING ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "connection", LDAP_LEVEL_INFO, + "connection_read: conn %d connection closing, ignoring input\n", + c->c_connid)); +#else Debug( LDAP_DEBUG_TRACE, "connection_read(%d): closing, ignoring input for id=%ld\n", s, c->c_connid, 0 ); - +#endif connection_return( c ); ldap_pvt_thread_mutex_unlock( &connections_mutex ); return 0; } +#ifdef NEW_LOGGING + LDAP_LOG(( "connection", LDAP_LEVEL_DETAIL1, + "connection_read: conn %d checking for input.\n", c->c_connid )); +#else Debug( LDAP_DEBUG_TRACE, "connection_read(%d): checking for input on id=%ld\n", s, c->c_connid, 0 ); +#endif #ifdef HAVE_TLS if ( c->c_is_tls && c->c_needs_tls_accept ) { @@ -919,11 +1026,16 @@ int connection_read(ber_socket_t s) struct timeval tv; fd_set rfd; +#ifdef NEW_LOGGING + LDAP_LOG(( "connection", LDAP_LEVEL_ERR, + "connection_read: conn %d TLS accept error, error %d\n", + c->c_connid, rc )); +#else Debug( LDAP_DEBUG_TRACE, "connection_read(%d): TLS accept error " "error=%d id=%ld, closing\n", s, rc, c->c_connid ); - +#endif c->c_needs_tls_accept = 0; /* connections_mutex and c_mutex are locked */ connection_closing( c ); @@ -952,7 +1064,7 @@ int connection_read(ber_socket_t s) c->c_needs_tls_accept = 0; /* we need to let SASL know */ - ssl = (void *)ldap_pvt_tls_sb_handle( c->c_sb ); + ssl = (void *)ldap_pvt_tls_sb_ctx( c->c_sb ); c->c_tls_ssf = (slap_ssf_t) ldap_pvt_tls_get_strength( ssl ); if( c->c_tls_ssf > c->c_ssf ) { @@ -975,11 +1087,16 @@ int connection_read(ber_socket_t s) rc = ldap_pvt_sasl_install( c->c_sb, c->c_sasl_context ); if( rc != LDAP_SUCCESS ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "connection", LDAP_LEVEL_ERR, + "connection_read: conn %d SASL install error %d, closing\n", + c->c_connid, rc )); +#else Debug( LDAP_DEBUG_TRACE, "connection_read(%d): SASL install error " "error=%d id=%ld, closing\n", s, rc, c->c_connid ); - +#endif /* connections_mutex and c_mutex are locked */ connection_closing( c ); connection_close( c ); @@ -1003,10 +1120,15 @@ int connection_read(ber_socket_t s) } if( rc < 0 ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "connection", LDAP_LEVEL_ERR, + "connection_read: conn %d input error %d, closing.\n", + c->c_connid, rc )); +#else Debug( LDAP_DEBUG_TRACE, "connection_read(%d): input error=%d id=%ld, closing.\n", s, rc, c->c_connid ); - +#endif /* connections_mutex and c_mutex are locked */ connection_closing( c ); connection_close( c ); @@ -1041,7 +1163,12 @@ connection_input( if ( conn->c_currentber == NULL && (conn->c_currentber = ber_alloc()) == NULL ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "connection", LDAP_LEVEL_ERR, + "connection_input: conn %d ber_alloc failed.\n", conn->c_connid )); +#else Debug( LDAP_DEBUG_ANY, "ber_alloc failed\n", 0, 0, 0 ); +#endif return -1; } @@ -1054,10 +1181,15 @@ connection_input( ber_sockbuf_ctrl( conn->c_sb, LBER_SB_OPT_GET_FD, &sd ); +#ifdef NEW_LOGGING + LDAP_LOG(( "connection", LDAP_LEVEL_ERR, + "connection_input: conn %d ber_get_next failed, errno %d (%s).\n", + conn->c_connid, err, sock_errstr(err) )); +#else Debug( LDAP_DEBUG_TRACE, "ber_get_next on fd %d failed errno=%d (%s)\n", sd, err, sock_errstr(err) ); - +#endif if ( err != EWOULDBLOCK && err != EAGAIN ) { /* log, close and send error */ ber_free( conn->c_currentber, 1 ); @@ -1073,16 +1205,28 @@ connection_input( if ( (tag = ber_get_int( ber, &msgid )) != LDAP_TAG_MSGID ) { /* log, close and send error */ +#ifdef NEW_LOGGING + LDAP_LOG(( "connection", LDAP_LEVEL_ERR, + "connection_input: conn %d ber_get_int returns 0x%lx.\n", + conn->c_connid, tag )); +#else Debug( LDAP_DEBUG_ANY, "ber_get_int returns 0x%lx\n", tag, 0, 0 ); +#endif ber_free( ber, 1 ); return -1; } if ( (tag = ber_peek_tag( ber, &len )) == LBER_ERROR ) { /* log, close and send error */ +#ifdef NEW_LOGGING + LDAP_LOG(( "connection", LDAP_LEVEL_ERR, + "connection_input: conn %d ber_peek_tag returns 0x%lx.\n", + conn->c_connid, tag )); +#else Debug( LDAP_DEBUG_ANY, "ber_peek_tag returns 0x%lx\n", tag, 0, 0 ); +#endif ber_free( ber, 1 ); return -1; @@ -1098,7 +1242,13 @@ connection_input( if ( conn->c_conn_state == SLAP_C_BINDING || conn->c_conn_state == SLAP_C_CLOSING ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "connection", LDAP_LEVEL_INFO, + "connection_input: conn %d deferring operation\n", + conn->c_connid )); +#else Debug( LDAP_DEBUG_ANY, "deferring operation\n", 0, 0, 0 ); +#endif conn->c_n_ops_pending++; slap_op_add( &conn->c_pending_ops, op ); @@ -1132,9 +1282,15 @@ connection_resched( Connection *conn ) rc = ldap_pvt_thread_mutex_trylock( &connections_mutex ); if( rc ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "connection", LDAP_LEVEL_DETAIL1, + "connection_resched: conn %d reaquiring locks.\n", + conn->c_connid )); +#else Debug( LDAP_DEBUG_TRACE, "connection_resched: reaquiring locks conn=%ld sd=%d\n", conn->c_connid, sd, 0 ); +#endif /* * reaquire locks in the right order... * this may allow another thread to close this connection, @@ -1146,15 +1302,25 @@ connection_resched( Connection *conn ) } if( conn->c_conn_state != SLAP_C_CLOSING ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "connection", LDAP_LEVEL_INFO, + "connection_resched: conn %d closed by other thread.\n", + conn->c_connid )); +#else Debug( LDAP_DEBUG_TRACE, "connection_resched: " "closed by other thread conn=%ld sd=%d\n", conn->c_connid, sd, 0 ); - +#endif } else { +#ifdef NEW_LOGGING + LDAP_LOG(( "connection", LDAP_LEVEL_DETAIL1, + "connection_resched: conn %d attempting closing.\n", + conn->c_connid )); +#else Debug( LDAP_DEBUG_TRACE, "connection_resched: " "attempting closing conn=%ld sd=%d\n", conn->c_connid, sd, 0 ); - +#endif connection_close( conn ); } @@ -1218,8 +1384,14 @@ static int connection_op_activate( Connection *conn, Operation *op ) connection_operation, (void *) arg ); if ( status != 0 ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "connection", LDAP_LEVEL_ERR, + "connection_op_activate: conn %d thread pool submit failed.\n", + conn->c_connid )); +#else Debug( LDAP_DEBUG_ANY, "ldap_pvt_thread_pool_submit failed (%d)\n", status, 0, 0 ); +#endif /* should move op to pending list */ } @@ -1238,9 +1410,14 @@ int connection_write(ber_socket_t s) slapd_clr_write( s, 0); if( c == NULL ) { +#ifdef NEW_LOGGING + LDAP_LOG(( "connection", LDAP_LEVEL_ERR, + "connection_write: sock %ld no connection!\n",(long)s)); +#else Debug( LDAP_DEBUG_ANY, "connection_write(%ld): no connection!\n", (long) s, 0, 0 ); +#endif slapd_remove(s, 0); ldap_pvt_thread_mutex_unlock( &connections_mutex ); return -1; @@ -1248,10 +1425,15 @@ int connection_write(ber_socket_t s) c->c_n_write++; +#ifdef NEW_LOGGING + LDAP_LOG(( "connection", LDAP_LEVEL_DETAIL1, + "connection_write conn %d waking output.\n", + c->c_connid )); +#else Debug( LDAP_DEBUG_TRACE, "connection_write(%d): waking output for id=%ld\n", s, c->c_connid, 0 ); - +#endif ldap_pvt_thread_cond_signal( &c->c_write_cv ); if ( ber_sockbuf_ctrl( c->c_sb, LBER_SB_OPT_NEEDS_READ, NULL ) )