improve logging

diff --git a/servers/slapd/back-sql/add.c b/servers/slapd/back-sql/add.c
index f09cdcd4d3726c69f75e1f6ccf115c02b2a66003..a938b1697815a30348b39a53f429294ddcc45dd4 100644 (file)
--- a/servers/slapd/back-sql/add.c
+++ b/servers/slapd/back-sql/add.c
@@ -518,7 +518,7 @@ backsql_add( Operation *op, SlapReply *rs )
        int                     prc;
        struct berval           realdn, realpdn;
 
-       Debug( LDAP_DEBUG_TRACE, "==>backsql_add(): adding entry \"%s\"\n",
+       Debug( LDAP_DEBUG_TRACE, "==>backsql_add(\"%s\")\n",
                        op->oq_add.rs_e->e_name.bv_val, 0, 0 );
 
        /* check schema */
@@ -529,9 +529,9 @@ backsql_add( Operation *op, SlapReply *rs )
                                NULL,
                                &rs->sr_text, textbuf, sizeof( textbuf ) );
                if ( rs->sr_err != LDAP_SUCCESS ) {
-                       Debug( LDAP_DEBUG_TRACE, "   backsql_add(): "
+                       Debug( LDAP_DEBUG_TRACE, "   backsql_add(\"%s\"): "
                                "entry failed schema check -- aborting\n",
-                               0, 0, 0 );
+                               op->oq_add.rs_e->e_name.bv_val, 0, 0 );
                        goto done;
                }
        }
@@ -550,27 +550,33 @@ backsql_add( Operation *op, SlapReply *rs )
        oc = backsql_name2oc( bi, &at->a_vals[0] );
 
        if ( oc == NULL ) {
-               Debug( LDAP_DEBUG_TRACE, "   backsql_add(): "
-                       "cannot determine objectclass of entry -- aborting\n",
-                       0, 0, 0 );
+               Debug( LDAP_DEBUG_TRACE, "   backsql_add(\"%s\"): "
+                       "cannot map structuralObjectClass \"%s\" -- aborting\n",
+                       op->oq_add.rs_e->e_name.bv_val,
+                       at->a_vals[0].bv_val, 0 );
                rs->sr_err = LDAP_UNWILLING_TO_PERFORM;
                rs->sr_text = "operation not permitted within namingContext";
                goto done;
        }
 
        if ( oc->bom_create_proc == NULL ) {
-               Debug( LDAP_DEBUG_TRACE, "   backsql_add(): "
-                       "create procedure is not defined for this objectclass "
-                       "- aborting\n", 0, 0, 0 );
+               Debug( LDAP_DEBUG_TRACE, "   backsql_add(\"%s\"): "
+                       "create procedure is not defined "
+                       "for structuralObjectClass \"%s\" - aborting\n",
+                       op->oq_add.rs_e->e_name.bv_val,
+                       at->a_vals[0].bv_val, 0 );
                rs->sr_err = LDAP_UNWILLING_TO_PERFORM;
                rs->sr_text = "operation not permitted within namingContext";
                goto done;
 
        } else if ( BACKSQL_CREATE_NEEDS_SELECT( bi )
                        && oc->bom_create_keyval == NULL ) {
-               Debug( LDAP_DEBUG_TRACE, "   backsql_add(): "
+               Debug( LDAP_DEBUG_TRACE, "   backsql_add(\"%s\"): "
                        "create procedure needs select procedure, "
-                       "but none is defined - aborting\n", 0, 0, 0 );
+                       "but none is defined for structuralObjectClass \"%s\" "
+                       "- aborting\n",
+                       op->oq_add.rs_e->e_name.bv_val,
+                       at->a_vals[0].bv_val, 0 );
                rs->sr_err = LDAP_UNWILLING_TO_PERFORM;
                rs->sr_text = "operation not permitted within namingContext";
                goto done;
@@ -578,9 +584,9 @@ backsql_add( Operation *op, SlapReply *rs )
 
        rs->sr_err = backsql_get_db_conn( op, &dbh );
        if ( rs->sr_err != LDAP_SUCCESS ) {
-               Debug( LDAP_DEBUG_TRACE, "   backsql_add(): "
+               Debug( LDAP_DEBUG_TRACE, "   backsql_add(\"%s\"): "
                        "could not get connection handle - exiting\n", 
-                       0, 0, 0 );
+                       op->oq_add.rs_e->e_name.bv_val, 0, 0 );
                rs->sr_text = ( rs->sr_err == LDAP_OTHER )
                        ?  "SQL-backend error" : NULL;
                goto done;
@@ -591,9 +597,10 @@ backsql_add( Operation *op, SlapReply *rs )
         */
        realdn = op->oq_add.rs_e->e_name;
        if ( backsql_api_dn2odbc( op, rs, &realdn ) ) {
-               Debug( LDAP_DEBUG_TRACE, "backsql_search(): "
-                       "backsql_api_dn2odbc failed\n", 
-                       0, 0, 0 );
+               Debug( LDAP_DEBUG_TRACE, "   backsql_add(\"%s\"): "
+                       "backsql_api_dn2odbc(\"%s\") failed\n", 
+                       op->oq_add.rs_e->e_name.bv_val,
+                       op->oq_add.rs_e->e_name.bv_val, 0 );
                rs->sr_err = LDAP_OTHER;
                rs->sr_text = "SQL-backend error";
                goto done;
@@ -601,8 +608,8 @@ backsql_add( Operation *op, SlapReply *rs )
 
        rs->sr_err = backsql_dn2id( bi, NULL, dbh, &realdn );
        if ( rs->sr_err == LDAP_SUCCESS ) {
-               Debug( LDAP_DEBUG_TRACE, "   backsql_add(): "
-                       "entry \"%s\" exists\n",
+               Debug( LDAP_DEBUG_TRACE, "   backsql_add(\"%s\"): "
+                       "entry exists\n",
                        op->oq_add.rs_e->e_name.bv_val, 0, 0 );
                rs->sr_err = LDAP_ALREADY_EXISTS;
                goto done;
@@ -614,9 +621,9 @@ backsql_add( Operation *op, SlapReply *rs )
        dnParent( &op->oq_add.rs_e->e_name, &pdn );
        realpdn = pdn;
        if ( backsql_api_dn2odbc( op, rs, &realpdn ) ) {
-               Debug( LDAP_DEBUG_TRACE, "backsql_search(): "
-                       "backsql_api_dn2odbc failed\n", 
-                       0, 0, 0 );
+               Debug( LDAP_DEBUG_TRACE, "   backsql_add(\"%s\"): "
+                       "backsql_api_dn2odbc(\"%s\") failed\n", 
+                       op->oq_add.rs_e->e_name.bv_val, pdn.bv_val, 0 );
                rs->sr_err = LDAP_OTHER;
                rs->sr_text = "SQL-backend error";
                goto done;
@@ -624,9 +631,9 @@ backsql_add( Operation *op, SlapReply *rs )
 
        rs->sr_err = backsql_dn2id( bi, &parent_id, dbh, &realpdn );
        if ( rs->sr_err != LDAP_SUCCESS ) {
-               Debug( LDAP_DEBUG_TRACE, "   backsql_add(): "
+               Debug( LDAP_DEBUG_TRACE, "   backsql_add(\"%s\"): "
                        "could not lookup parent entry for new record \"%s\"\n",
-                       pdn.bv_val, 0, 0 );
+                       op->oq_add.rs_e->e_name.bv_val, pdn.bv_val, 0 );
 
                if ( rs->sr_err != LDAP_NO_SUCH_OBJECT ) {
                        goto done;
@@ -651,9 +658,10 @@ backsql_add( Operation *op, SlapReply *rs )
                         */
                        realpdn = pdn;
                        if ( backsql_api_dn2odbc( op, rs, &realpdn ) ) {
-                               Debug( LDAP_DEBUG_TRACE, "backsql_add(): "
+                               Debug( LDAP_DEBUG_TRACE,
+                                       "   backsql_add(\"%s\"): "
                                        "backsql_api_dn2odbc failed\n", 
-                                       0, 0, 0 );
+                                       op->oq_add.rs_e->e_name.bv_val, 0, 0 );
                                rs->sr_err = LDAP_OTHER;
                                rs->sr_text = "SQL-backend error";
                                goto done;
@@ -707,12 +715,13 @@ backsql_add( Operation *op, SlapReply *rs )
                                SQL_INTEGER, 0, 0, &new_keyval, 0, 0 );
        }
 
-       Debug( LDAP_DEBUG_TRACE, "   backsql_add(): executing \"%s\"\n",
-               oc->bom_create_proc, 0, 0 );
+       Debug( LDAP_DEBUG_TRACE, "   backsql_add(\"%s\"): executing \"%s\"\n",
+               op->oq_add.rs_e->e_name.bv_val, oc->bom_create_proc, 0 );
        rc = SQLExecDirect( sth, oc->bom_create_proc, SQL_NTS );
        if ( rc != SQL_SUCCESS ) {
-               Debug( LDAP_DEBUG_TRACE, "   backsql_add(): "
-                       "create_proc execution failed\n", 0, 0, 0 );
+               Debug( LDAP_DEBUG_TRACE, "   backsql_add(\"%s\"): "
+                       "create_proc execution failed\n",
+                       op->oq_add.rs_e->e_name.bv_val, 0, 0 );
                backsql_PrintErrors( bi->db_env, dbh, sth, rc);
                SQLFreeStmt( sth, SQL_DROP );
                rs->sr_err = LDAP_OTHER;
@@ -754,9 +763,9 @@ backsql_add( Operation *op, SlapReply *rs )
                 */
                rc = SQLNumResultCols( sth, &ncols );
                if ( rc != SQL_SUCCESS ) {
-                       Debug( LDAP_DEBUG_TRACE, "   backsql_add(): "
+                       Debug( LDAP_DEBUG_TRACE, "   backsql_add(\"%s\"): "
                                "create_proc result evaluation failed\n",
-                               0, 0, 0 );
+                               op->oq_add.rs_e->e_name.bv_val, 0, 0 );
                        backsql_PrintErrors( bi->db_env, dbh, sth, rc);
                        SQLFreeStmt( sth, SQL_DROP );
                        rs->sr_err = LDAP_OTHER;
@@ -764,9 +773,9 @@ backsql_add( Operation *op, SlapReply *rs )
                        goto done;
 
                } else if ( ncols != 1 ) {
-                       Debug( LDAP_DEBUG_TRACE, "   backsql_add(): "
+                       Debug( LDAP_DEBUG_TRACE, "   backsql_add(\"%s\"): "
                                "create_proc result is bogus (ncols=%d)\n",
-                               ncols, 0, 0 );
+                               op->oq_add.rs_e->e_name.bv_val, ncols, 0 );
                        backsql_PrintErrors( bi->db_env, dbh, sth, rc);
                        SQLFreeStmt( sth, SQL_DROP );
                        rs->sr_err = LDAP_OTHER;
@@ -800,9 +809,9 @@ backsql_add( Operation *op, SlapReply *rs )
                rc = SQLFetch( sth );
 
                if ( value_len <= 0 ) {
-                       Debug( LDAP_DEBUG_TRACE, "   backsql_add(): "
+                       Debug( LDAP_DEBUG_TRACE, "   backsql_add(\"%s\"): "
                                "create_proc result is empty?\n",
-                               0, 0, 0 );
+                               op->oq_add.rs_e->e_name.bv_val, 0, 0 );
                        backsql_PrintErrors( bi->db_env, dbh, sth, rc);
                        SQLFreeStmt( sth, SQL_DROP );
                        rs->sr_err = LDAP_OTHER;
@@ -817,8 +826,9 @@ backsql_add( Operation *op, SlapReply *rs )
        SQLFreeStmt( sth, SQL_DROP );
 #endif /* BACKSQL_REALLOC_STMT */
 
-       Debug( LDAP_DEBUG_TRACE, "   backsql_add(): "
-               "create_proc returned keyval=%ld\n", new_keyval, 0, 0 );
+       Debug( LDAP_DEBUG_TRACE, "   backsql_add(\"%s\"): "
+               "create_proc returned keyval=%ld\n",
+               op->oq_add.rs_e->e_name.bv_val, new_keyval, 0 );
 
        for ( at = op->oq_add.rs_e->e_attrs; at != NULL; at = at->a_next ) {
                SQLUSMALLINT    currpos;
@@ -841,11 +851,12 @@ backsql_add( Operation *op, SlapReply *rs )
                at_rec = backsql_ad2at( oc, at->a_desc ); 
   
                if ( at_rec == NULL ) {
-                       Debug( LDAP_DEBUG_TRACE, "   backsql_add(): "
+                       Debug( LDAP_DEBUG_TRACE, "   backsql_add(\"%s\"): "
                                "attribute \"%s\" is not registered "
                                "in objectclass \"%s\"\n",
+                               op->oq_add.rs_e->e_name.bv_val,
                                at->a_desc->ad_cname.bv_val,
-                               BACKSQL_OC_NAME( oc ), 0 );
+                               BACKSQL_OC_NAME( oc ) );
 
                        if ( BACKSQL_FAIL_IF_NO_MAPPING( bi ) ) {
                                rs->sr_err = LDAP_UNWILLING_TO_PERFORM;
@@ -858,10 +869,13 @@ backsql_add( Operation *op, SlapReply *rs )
                }
                
                if ( at_rec->bam_add_proc == NULL ) {
-                       Debug( LDAP_DEBUG_TRACE, "   backsql_add(): "
+                       Debug( LDAP_DEBUG_TRACE, "   backsql_add(\"%s\"): "
                                "add procedure is not defined "
-                               "for attribute \"%s\"\n",
-                               at->a_desc->ad_cname.bv_val, 0, 0 );
+                               "for attribute \"%s\" "
+                               "of structuralObjectClass \"%s\"\n",
+                               op->oq_add.rs_e->e_name.bv_val,
+                               at->a_desc->ad_cname.bv_val,
+                               BACKSQL_OC_NAME( oc ) );
 
                        if ( BACKSQL_FAIL_IF_NO_MAPPING( bi ) ) {
                                rs->sr_err = LDAP_UNWILLING_TO_PERFORM;
@@ -906,6 +920,7 @@ backsql_add( Operation *op, SlapReply *rs )
                for ( i = 0, at_val = &at->a_vals[ i ];
                                at_val->bv_val != NULL;
                                i++, at_val = &at->a_vals[ i ] ) {
+                       char logbuf[] = "val[18446744073709551615UL], id=18446744073709551615UL";
 
                        /*
                         * Do not deal with the objectClass that is used
@@ -924,14 +939,14 @@ backsql_add( Operation *op, SlapReply *rs )
 
                        backsql_BindParamStr( sth, currpos,
                                        at_val->bv_val, at_val->bv_len + 1 );
-#ifdef SECURITY_PARANOID
-                       Debug( LDAP_DEBUG_TRACE, "   backsql_add(): "
-                               "executing \"%s\", id=%ld\n", 
-                               at_rec->bam_add_proc, new_keyval, 0 );
-#else
-                       Debug( LDAP_DEBUG_TRACE, "   backsql_add(): "
-                               "executing \"%s\" for val[%d], id=%ld\n", 
-                               at_rec->bam_add_proc, i, new_keyval );
+
+#ifdef LDAP_DEBUG
+                       snprintf( logbuf, sizeof( logbuf ), "val[%d], id=%ld",
+                                       i, new_keyval );
+                       Debug( LDAP_DEBUG_TRACE, "   backsql_add(\"%s\"): "
+                               "executing \"%s\" %s\n", 
+                               op->oq_add.rs_e->e_name.bv_val,
+                               at_rec->bam_add_proc, logbuf );
 #endif
 #ifndef BACKSQL_REALLOC_STMT
                        rc = SQLExecDirect( sth, at_rec->bam_add_proc, SQL_NTS );
@@ -939,9 +954,10 @@ backsql_add( Operation *op, SlapReply *rs )
                        rc = SQLExecute( sth );
 #endif /* BACKSQL_REALLOC_STMT */
                        if ( rc != SQL_SUCCESS ) {
-                               Debug( LDAP_DEBUG_TRACE, "   backsql_add(): "
+                               Debug( LDAP_DEBUG_TRACE,
+                                       "   backsql_add(\"%s\"): "
                                        "add_proc execution failed\n", 
-                                       0, 0, 0 );
+                                       op->oq_add.rs_e->e_name.bv_val, 0, 0 );
                                backsql_PrintErrors( bi->db_env, dbh, sth, rc );
 
                                if ( BACKSQL_FAIL_IF_NO_MAPPING( bi ) ) {
@@ -998,8 +1014,9 @@ backsql_add( Operation *op, SlapReply *rs )
        rc = SQLExecute( sth );
 #endif /* BACKSQL_REALLOC_STMT */
        if ( rc != SQL_SUCCESS ) {
-               Debug( LDAP_DEBUG_TRACE, "   backsql_add(): "
-                       "could not insert ldap_entries record\n", 0, 0, 0 );
+               Debug( LDAP_DEBUG_TRACE, "   backsql_add(\"%s\"): "
+                       "could not insert ldap_entries record\n",
+                       op->oq_add.rs_e->e_name.bv_val, 0, 0 );
                backsql_PrintErrors( bi->db_env, dbh, sth, rc );
                
                /*
@@ -1043,9 +1060,9 @@ done:;
                backsql_free_entryID( &parent_id, 0 );
        }
 
-       Debug( LDAP_DEBUG_TRACE, "<==backsql_add(): %d%s%s\n",
+       Debug( LDAP_DEBUG_TRACE, "<==backsql_add(\"%s\"): %d \"%s\"\n",
+                       op->oq_add.rs_e->e_name.bv_val,
                        rs->sr_err,
-                       rs->sr_text ? ": " : "",
                        rs->sr_text ? rs->sr_text : "" );
 
        return ( ( rs->sr_err == LDAP_SUCCESS ) ? op->o_noop : 1 );