X-Git-Url: https://git.sur5r.net/?a=blobdiff_plain;f=servers%2Fslapd%2Foverlays%2Faccesslog.c;h=bd61096dbbb9f8e01c5e267438b588eca0bc0c43;hb=d2d1eb786b1051047ab2c77110ddc31778359c26;hp=49d61b4e00cd3a7c5783c3b78dbc00fc8bd7849c;hpb=6a4839bd2326f17caff336d33fe8e9d7de0b9c83;p=openldap diff --git a/servers/slapd/overlays/accesslog.c b/servers/slapd/overlays/accesslog.c index 49d61b4e00..bd61096dbb 100644 --- a/servers/slapd/overlays/accesslog.c +++ b/servers/slapd/overlays/accesslog.c @@ -2,7 +2,7 @@ /* $OpenLDAP$ */ /* This work is part of OpenLDAP Software . * - * Copyright 2005 The OpenLDAP Foundation. + * Copyright 2005-2006 The OpenLDAP Foundation. * Portions copyright 2004-2005 Symas Corporation. * All rights reserved. * @@ -57,6 +57,9 @@ typedef struct log_info { int li_age; int li_cycle; struct re_s *li_task; + int li_success; + ldap_pvt_thread_mutex_t li_op_mutex; + ldap_pvt_thread_mutex_t li_log_mutex; } log_info; static ConfigDriver log_cf_gen; @@ -64,7 +67,8 @@ static ConfigDriver log_cf_gen; enum { LOG_DB = 1, LOG_OPS, - LOG_PURGE + LOG_PURGE, + LOG_SUCCESS }; static ConfigTable log_cfats[] = { @@ -82,6 +86,10 @@ static ConfigTable log_cfats[] = { log_cf_gen, "( OLcfgOvAt:4.3 NAME 'olcAccessLogPurge' " "DESC 'Log cleanup parameters' " "SYNTAX OMsDirectoryString SINGLE-VALUE )", NULL, NULL }, + { "logsuccess", NULL, 2, 2, 0, ARG_MAGIC|ARG_ON_OFF|LOG_SUCCESS, + log_cf_gen, "( OLcfgOvAt:4.4 NAME 'olcAccessLogSuccess' " + "DESC 'Log successful ops only' " + "SYNTAX OMsBoolean SINGLE-VALUE )", NULL, NULL }, { NULL } }; @@ -91,7 +99,7 @@ static ConfigOCs log_cfocs[] = { "DESC 'Access log configuration' " "SUP olcOverlayConfig " "MUST olcAccessLogDB " - "MAY ( olcAccessLogOps $ olcAccessLogPurge ) )", + "MAY ( olcAccessLogOps $ olcAccessLogPurge $ olcAccessLogSuccess ) )", Cft_Overlay, log_cfats }, { NULL } }; @@ -133,7 +141,7 @@ enum { LOG_EN__COUNT }; -static ObjectClass *log_ocs[LOG_EN__COUNT]; +static ObjectClass *log_ocs[LOG_EN__COUNT], *log_container; #define LOG_SCHEMA_ROOT "1.3.6.1.4.1.4203.666.11.5" @@ -146,10 +154,8 @@ static AttributeDescription *ad_reqDN, *ad_reqStart, *ad_reqEnd, *ad_reqType, *ad_reqNewSuperior, *ad_reqDeleteOldRDN, *ad_reqMod, *ad_reqScope, *ad_reqFilter, *ad_reqAttr, *ad_reqEntries, *ad_reqSizeLimit, *ad_reqTimeLimit, *ad_reqAttrsOnly, *ad_reqData, - *ad_reqId, *ad_reqMessage; -#if 0 -static AttributeDescription *ad_oldest; -#endif + *ad_reqId, *ad_reqMessage, *ad_reqVersion, *ad_reqDerefAliases, + *ad_reqReferral, *ad_reqOld; static struct { char *at; @@ -182,97 +188,127 @@ static struct { "EQUALITY caseIgnoreMatch " "SYNTAX OMsDirectoryString " "SINGLE-VALUE )", &ad_reqSession }, - { "( " LOG_SCHEMA_AT ".6 NAME 'reqResult' " + { "( " LOG_SCHEMA_AT ".6 NAME 'reqAuthzID' " + "DESC 'Authorization ID of requestor' " + "EQUALITY distinguishedNameMatch " + "SYNTAX OMsDN " + "SINGLE-VALUE )", &ad_reqAuthzID }, + { "( " LOG_SCHEMA_AT ".7 NAME 'reqResult' " "DESC 'Result code of request' " "EQUALITY integerMatch " + "ORDERING integerOrderingMatch " "SYNTAX OMsInteger " "SINGLE-VALUE )", &ad_reqResult }, - { "( " LOG_SCHEMA_AT ".7 NAME 'reqAuthzID' " - "DESC 'AUthorization ID of requestor' " - "EQUALITY distinguishedNameMatch " - "SYNTAX OMsDN " - "SINGLE-VALUE )", &ad_reqAuthzID }, - { "( " LOG_SCHEMA_AT ".8 NAME 'reqControls' " + { "( " LOG_SCHEMA_AT ".8 NAME 'reqMessage' " + "DESC 'Error text of request' " + "EQUALITY caseIgnoreMatch " + "SUBSTR caseIgnoreSubstringsMatch " + "SYNTAX OMsDirectoryString " + "SINGLE-VALUE )", &ad_reqMessage }, + { "( " LOG_SCHEMA_AT ".9 NAME 'reqReferral' " + "DESC 'Referrals returned for request' " + "SUP labeledURI )", &ad_reqReferral }, + { "( " LOG_SCHEMA_AT ".10 NAME 'reqControls' " "DESC 'Request controls' " "SYNTAX OMsOctetString )", &ad_reqControls }, - { "( " LOG_SCHEMA_AT ".9 NAME 'reqRespControls' " + { "( " LOG_SCHEMA_AT ".11 NAME 'reqRespControls' " "DESC 'Response controls of request' " "SYNTAX OMsOctetString )", &ad_reqRespControls }, - { "( " LOG_SCHEMA_AT ".10 NAME 'reqMethod' " + { "( " LOG_SCHEMA_AT ".12 NAME 'reqId' " + "DESC 'ID of Request to Abandon' " + "EQUALITY integerMatch " + "ORDERING integerOrderingMatch " + "SYNTAX OMsInteger " + "SINGLE-VALUE )", &ad_reqId }, + { "( " LOG_SCHEMA_AT ".13 NAME 'reqVersion' " + "DESC 'Protocol version of Bind request' " + "EQUALITY integerMatch " + "ORDERING integerOrderingMatch " + "SYNTAX OMsInteger " + "SINGLE-VALUE )", &ad_reqVersion }, + { "( " LOG_SCHEMA_AT ".14 NAME 'reqMethod' " "DESC 'Bind method of request' " "EQUALITY caseIgnoreMatch " "SYNTAX OMsDirectoryString " "SINGLE-VALUE )", &ad_reqMethod }, - { "( " LOG_SCHEMA_AT ".11 NAME 'reqAssertion' " + { "( " LOG_SCHEMA_AT ".15 NAME 'reqAssertion' " "DESC 'Compare Assertion of request' " "SYNTAX OMsDirectoryString " "SINGLE-VALUE )", &ad_reqAssertion }, - { "( " LOG_SCHEMA_AT ".12 NAME 'reqNewRDN' " + { "( " LOG_SCHEMA_AT ".16 NAME 'reqMod' " + "DESC 'Modifications of request' " + "EQUALITY octetStringMatch " + "SUBSTR octetStringSubstringsMatch " + "SYNTAX OMsOctetString )", &ad_reqMod }, + { "( " LOG_SCHEMA_AT ".17 NAME 'reqOld' " + "DESC 'Old values of entry before request completed' " + "EQUALITY octetStringMatch " + "SUBSTR octetStringSubstringsMatch " + "SYNTAX OMsOctetString )", &ad_reqOld }, + { "( " LOG_SCHEMA_AT ".18 NAME 'reqNewRDN' " "DESC 'New RDN of request' " "EQUALITY distinguishedNameMatch " "SYNTAX OMsDN " "SINGLE-VALUE )", &ad_reqNewRDN }, - { "( " LOG_SCHEMA_AT ".13 NAME 'reqNewSuperior' " + { "( " LOG_SCHEMA_AT ".19 NAME 'reqDeleteOldRDN' " + "DESC 'Delete old RDN' " + "EQUALITY booleanMatch " + "SYNTAX OMsBoolean " + "SINGLE-VALUE )", &ad_reqDeleteOldRDN }, + { "( " LOG_SCHEMA_AT ".20 NAME 'reqNewSuperior' " "DESC 'New superior DN of request' " "EQUALITY distinguishedNameMatch " "SYNTAX OMsDN " "SINGLE-VALUE )", &ad_reqNewSuperior }, - { "( " LOG_SCHEMA_AT ".14 NAME 'reqDeleteOldRDN' " - "DESC 'Delete old RDN' " - "SYNTAX OMsBoolean " - "SINGLE-VALUE )", &ad_reqDeleteOldRDN }, - { "( " LOG_SCHEMA_AT ".15 NAME 'reqMod' " - "DESC 'Modifications of request' " - "SYNTAX OMsDirectoryString " - "EQUALITY caseIgnoreMatch " - "SUBSTR caseIgnoreSubstringsMatch )", &ad_reqMod }, - { "( " LOG_SCHEMA_AT ".16 NAME 'reqScope' " + { "( " LOG_SCHEMA_AT ".21 NAME 'reqScope' " "DESC 'Scope of request' " + "EQUALITY caseIgnoreMatch " "SYNTAX OMsDirectoryString " "SINGLE-VALUE )", &ad_reqScope }, - { "( " LOG_SCHEMA_AT ".17 NAME 'reqFilter' " + { "( " LOG_SCHEMA_AT ".22 NAME 'reqDerefAliases' " + "DESC 'Disposition of Aliases in request' " + "EQUALITY caseIgnoreMatch " + "SYNTAX OMsDirectoryString " + "SINGLE-VALUE )", &ad_reqDerefAliases }, + { "( " LOG_SCHEMA_AT ".23 NAME 'reqAttrsOnly' " + "DESC 'Attributes and values of request' " + "EQUALITY booleanMatch " + "SYNTAX OMsBoolean " + "SINGLE-VALUE )", &ad_reqAttrsOnly }, + { "( " LOG_SCHEMA_AT ".24 NAME 'reqFilter' " "DESC 'Filter of request' " + "EQUALITY caseIgnoreMatch " + "SUBSTR caseIgnoreSubstringsMatch " "SYNTAX OMsDirectoryString " "SINGLE-VALUE )", &ad_reqFilter }, - { "( " LOG_SCHEMA_AT ".18 NAME 'reqAttr' " + { "( " LOG_SCHEMA_AT ".25 NAME 'reqAttr' " "DESC 'Attributes of request' " + "EQUALITY caseIgnoreMatch " "SYNTAX OMsDirectoryString )", &ad_reqAttr }, - { "( " LOG_SCHEMA_AT ".19 NAME 'reqEntries' " - "DESC 'Number of entries returned' " - "SYNTAX OMsInteger " - "SINGLE-VALUE )", &ad_reqEntries }, - { "( " LOG_SCHEMA_AT ".20 NAME 'reqSizeLimit' " + { "( " LOG_SCHEMA_AT ".26 NAME 'reqSizeLimit' " "DESC 'Size limit of request' " + "EQUALITY integerMatch " + "ORDERING integerOrderingMatch " "SYNTAX OMsInteger " "SINGLE-VALUE )", &ad_reqSizeLimit }, - { "( " LOG_SCHEMA_AT ".21 NAME 'reqTimeLimit' " + { "( " LOG_SCHEMA_AT ".27 NAME 'reqTimeLimit' " "DESC 'Time limit of request' " + "EQUALITY integerMatch " + "ORDERING integerOrderingMatch " "SYNTAX OMsInteger " "SINGLE-VALUE )", &ad_reqTimeLimit }, - { "( " LOG_SCHEMA_AT ".22 NAME 'reqAttrsOnly' " - "DESC 'Attributes and values of request' " - "SYNTAX OMsBoolean " - "SINGLE-VALUE )", &ad_reqAttrsOnly }, - { "( " LOG_SCHEMA_AT ".23 NAME 'reqData' " + { "( " LOG_SCHEMA_AT ".28 NAME 'reqEntries' " + "DESC 'Number of entries returned' " + "EQUALITY integerMatch " + "ORDERING integerOrderingMatch " + "SYNTAX OMsInteger " + "SINGLE-VALUE )", &ad_reqEntries }, + { "( " LOG_SCHEMA_AT ".29 NAME 'reqData' " "DESC 'Data of extended request' " + "EQUALITY octetStringMatch " + "SUBSTR octetStringSubstringsMatch " "SYNTAX OMsOctetString " "SINGLE-VALUE )", &ad_reqData }, - { "( " LOG_SCHEMA_AT ".24 NAME 'reqId' " - "DESC 'ID of Request to Abandon' " - "SYNTAX OMsInteger " - "SINGLE-VALUE )", &ad_reqId }, - { "( " LOG_SCHEMA_AT ".25 NAME 'reqMessage' " - "DESC 'Error text of request' " - "SYNTAX OMsDirectoryString " - "SINGLE-VALUE )", &ad_reqMessage }, -#if 0 - { "( " LOG_SCHEMA_AT ".26 NAME 'auditOldest' " - "DESC 'Oldest record in this branch' " - "EQUALITY generalizedTimeMatch " - "ORDERING generalizedTimeOrderingMatch " - "SYNTAX 1.3.6.1.4.1.1466.115.121.1.24 " - "SINGLE-VALUE )", &ad_oldest }, -#endif { NULL, NULL } }; @@ -280,24 +316,23 @@ static struct { char *ot; ObjectClass **oc; } locs[] = { -#if 0 { "( " LOG_SCHEMA_OC ".0 NAME 'auditContainer' " + "DESC 'AuditLog container' " "SUP top STRUCTURAL " - "MUST auditOldest " - "MAY cn )", &oc_container }, -#endif + "MAY ( cn $ reqStart $ reqEnd ) )", &log_container }, { "( " LOG_SCHEMA_OC ".1 NAME 'auditObject' " "DESC 'OpenLDAP request auditing' " "SUP top STRUCTURAL " "MUST ( reqStart $ reqType $ reqSession ) " "MAY ( reqDN $ reqAuthzID $ reqControls $ reqRespControls $ reqEnd $ " - "reqResult $ reqMessage ) )", &log_ocs[LOG_EN_UNBIND] }, + "reqResult $ reqMessage $ reqReferral ) )", + &log_ocs[LOG_EN_UNBIND] }, { "( " LOG_SCHEMA_OC ".2 NAME 'auditReadObject' " "DESC 'OpenLDAP read request record' " "SUP auditObject STRUCTURAL )", NULL }, { "( " LOG_SCHEMA_OC ".3 NAME 'auditWriteObject' " "DESC 'OpenLDAP write request record' " - "SUP auditObject STRUCTURAL )", &log_ocs[LOG_EN_DELETE] }, + "SUP auditObject STRUCTURAL )", NULL }, { "( " LOG_SCHEMA_OC ".4 NAME 'auditAbandon' " "DESC 'Abandon operation' " "SUP auditObject STRUCTURAL " @@ -309,27 +344,31 @@ static struct { { "( " LOG_SCHEMA_OC ".6 NAME 'auditBind' " "DESC 'Bind operation' " "SUP auditObject STRUCTURAL " - "MUST reqMethod )", &log_ocs[LOG_EN_BIND] }, + "MUST ( reqVersion $ reqMethod ) )", &log_ocs[LOG_EN_BIND] }, { "( " LOG_SCHEMA_OC ".7 NAME 'auditCompare' " "DESC 'Compare operation' " "SUP auditReadObject STRUCTURAL " "MUST reqAssertion )", &log_ocs[LOG_EN_COMPARE] }, - { "( " LOG_SCHEMA_OC ".8 NAME 'auditModify' " + { "( " LOG_SCHEMA_OC ".8 NAME 'auditDelete' " + "DESC 'Delete operation' " + "SUP auditWriteObject STRUCTURAL " + "MAY reqOld )", &log_ocs[LOG_EN_DELETE] }, + { "( " LOG_SCHEMA_OC ".9 NAME 'auditModify' " "DESC 'Modify operation' " "SUP auditWriteObject STRUCTURAL " - "MUST reqMod )", &log_ocs[LOG_EN_MODIFY] }, - { "( " LOG_SCHEMA_OC ".9 NAME 'auditModRDN' " + "MAY reqOld MUST reqMod )", &log_ocs[LOG_EN_MODIFY] }, + { "( " LOG_SCHEMA_OC ".10 NAME 'auditModRDN' " "DESC 'ModRDN operation' " "SUP auditWriteObject STRUCTURAL " "MUST ( reqNewRDN $ reqDeleteOldRDN ) " "MAY reqNewSuperior )", &log_ocs[LOG_EN_MODRDN] }, - { "( " LOG_SCHEMA_OC ".10 NAME 'auditSearch' " + { "( " LOG_SCHEMA_OC ".11 NAME 'auditSearch' " "DESC 'Search operation' " "SUP auditReadObject STRUCTURAL " - "MUST ( reqScope $ reqAttrsonly ) " + "MUST ( reqScope $ reqDerefAliases $ reqAttrsonly ) " "MAY ( reqFilter $ reqAttr $ reqEntries $ reqSizeLimit $ " "reqTimeLimit ) )", &log_ocs[LOG_EN_SEARCH] }, - { "( " LOG_SCHEMA_OC ".11 NAME 'auditExtended' " + { "( " LOG_SCHEMA_OC ".12 NAME 'auditExtended' " "DESC 'Extended operation' " "SUP auditObject STRUCTURAL " "MAY reqData )", &log_ocs[LOG_EN_EXTENDED] }, @@ -338,22 +377,26 @@ static struct { #define RDNEQ "reqStart=" -/* Our time intervals are of the form [dd+]hh:mm[:ss] - * If a field is present, it must be two digits. We assume no one - * will want to keep log records for longer than 99 days. +/* Our time intervals are of the form [ddd+]hh:mm[:ss] + * If a field is present, it must be two digits. (Except for + * days, which can be arbitrary width.) */ static int log_age_parse(char *agestr) { int t1, t2; int gotdays = 0; + char *endptr; - t1 = atoi( agestr ); + t1 = strtol( agestr, &endptr, 10 ); /* Is there a days delimiter? */ - if ( agestr[2] == '+' ) { + if ( *endptr == '+' ) { + /* 32 bit time only covers about 68 years */ + if ( t1 < 0 || t1 > 25000 ) + return -1; t1 *= 24; gotdays = 1; - } else if ( agestr[2] != ':' ) { + } else if ( *endptr != ':' ) { /* No valid delimiter found, fail */ return -1; } @@ -413,7 +456,7 @@ log_age_unparse( int age, struct berval *agebv ) ptr = agebv->bv_val; if ( dd ) - ptr += sprintf( ptr, "%02d+", dd ); + ptr += sprintf( ptr, "%d+", dd ); ptr += sprintf( ptr, "%02d:%02d", hh, mm ); if ( ss ) ptr += sprintf( ptr, ":%02d", ss ); @@ -458,8 +501,8 @@ accesslog_purge( void *ctx, void *arg ) struct log_info *li = rtask->arg; Connection conn = {0}; - char opbuf[OPERATION_BUFFER_SIZE]; - Operation *op = (Operation *)opbuf; + OperationBuffer opbuf; + Operation *op = (Operation *) &opbuf; SlapReply rs = {REP_RESULT}; slap_callback cb = { NULL, log_old_lookup, NULL, NULL }; Filter f; @@ -533,7 +576,7 @@ log_cf_gen(ConfigArgs *c) struct log_info *li = on->on_bi.bi_private; int rc = 0; slap_mask_t tmask = 0; - char agebuf[2*STRLENOF("dd+hh:mm:ss ")]; + char agebuf[2*STRLENOF("ddddd+hh:mm:ss ")]; struct berval agebv, cyclebv; switch( c->op ) { @@ -556,6 +599,12 @@ log_cf_gen(ConfigArgs *c) agebv.bv_len += cyclebv.bv_len; value_add_one( &c->rvalue_vals, &agebv ); break; + case LOG_SUCCESS: + if ( li->li_success ) + c->value_int = li->li_success; + else + rc = 1; + break; } break; case LDAP_MOD_DELETE: @@ -583,6 +632,9 @@ log_cf_gen(ConfigArgs *c) li->li_age = 0; li->li_cycle = 0; break; + case LOG_SUCCESS: + li->li_success = 0; + break; } break; default: @@ -625,41 +677,65 @@ log_cf_gen(ConfigArgs *c) } } break; + case LOG_SUCCESS: + li->li_success = c->value_int; + break; } break; } return rc; } -static Entry *accesslog_entry( Operation *op, int logop ) { +static Entry *accesslog_entry( Operation *op, int logop, + Operation *op2 ) { slap_overinst *on = (slap_overinst *)op->o_bd->bd_info; log_info *li = on->on_bi.bi_private; char rdnbuf[STRLENOF(RDNEQ)+LDAP_LUTIL_GENTIME_BUFSIZE+8]; - struct berval rdn, timestamp, bv; + char nrdnbuf[STRLENOF(RDNEQ)+LDAP_LUTIL_GENTIME_BUFSIZE+8]; + + struct berval rdn, nrdn, timestamp, ntimestamp, bv; slap_verbmasks *lo = logops+logop+EN_OFFSET; Entry *e = ch_calloc( 1, sizeof(Entry) ); strcpy( rdnbuf, RDNEQ ); rdn.bv_val = rdnbuf; + strcpy( nrdnbuf, RDNEQ ); + nrdn.bv_val = nrdnbuf; timestamp.bv_val = rdnbuf+STRLENOF(RDNEQ); timestamp.bv_len = sizeof(rdnbuf) - STRLENOF(RDNEQ); slap_timestamp( &op->o_time, ×tamp ); - if ( op->o_tincr ) { - sprintf( timestamp.bv_val + timestamp.bv_len-1, ".%06dZ", op->o_tincr ); - timestamp.bv_len += 7; - } + sprintf( timestamp.bv_val + timestamp.bv_len-1, ".%06dZ", op->o_tincr ); + timestamp.bv_len += 7; + rdn.bv_len = STRLENOF(RDNEQ)+timestamp.bv_len; + ad_reqStart->ad_type->sat_equality->smr_normalize( + SLAP_MR_VALUE_OF_ASSERTION_SYNTAX, ad_reqStart->ad_type->sat_syntax, + ad_reqStart->ad_type->sat_equality, ×tamp, &ntimestamp, + op->o_tmpmemctx ); + + strcpy( nrdn.bv_val + STRLENOF(RDNEQ), ntimestamp.bv_val ); + nrdn.bv_len = STRLENOF(RDNEQ)+ntimestamp.bv_len; build_new_dn( &e->e_name, li->li_db->be_suffix, &rdn, NULL ); - build_new_dn( &e->e_nname, li->li_db->be_nsuffix, &rdn, NULL ); + build_new_dn( &e->e_nname, li->li_db->be_nsuffix, &nrdn, NULL ); attr_merge_one( e, slap_schema.si_ad_objectClass, &log_ocs[logop]->soc_cname, NULL ); attr_merge_one( e, slap_schema.si_ad_structuralObjectClass, &log_ocs[logop]->soc_cname, NULL ); - attr_merge_one( e, ad_reqStart, ×tamp, NULL ); + attr_merge_one( e, ad_reqStart, ×tamp, &ntimestamp ); + op->o_tmpfree( ntimestamp.bv_val, op->o_tmpmemctx ); + + slap_op_time( &op2->o_time, &op2->o_tincr ); + + timestamp.bv_len = sizeof(rdnbuf) - STRLENOF(RDNEQ); + slap_timestamp( &op2->o_time, ×tamp ); + sprintf( timestamp.bv_val + timestamp.bv_len-1, ".%06dZ", op2->o_tincr ); + timestamp.bv_len += 7; + + attr_merge_normalize_one( e, ad_reqEnd, ×tamp, op->o_tmpmemctx ); /* Exops have OID appended */ if ( logop == LOG_EN_EXTENDED ) { @@ -692,9 +768,16 @@ static Entry *accesslog_entry( Operation *op, int logop ) { static struct berval scopes[] = { BER_BVC("base"), - BER_BVC("onelevel"), - BER_BVC("subtree"), - BER_BVC("subordinate") + BER_BVC("one"), + BER_BVC("sub"), + BER_BVC("subord") +}; + +static struct berval derefs[] = { + BER_BVC("never"), + BER_BVC("searching"), + BER_BVC("finding"), + BER_BVC("always") }; static struct berval simple = BER_BVC("SIMPLE"); @@ -705,16 +788,15 @@ static int accesslog_response(Operation *op, SlapReply *rs) { Attribute *a, *last_attr; Modifications *m; struct berval *b; - time_t endtime; int i; int logop; slap_verbmasks *lo; Entry *e; - char timebuf[LDAP_LUTIL_GENTIME_BUFSIZE]; + char timebuf[LDAP_LUTIL_GENTIME_BUFSIZE+8]; struct berval bv; char *ptr; BerVarray vals; - Operation op2; + Operation op2 = {0}; SlapReply rs2 = {REP_RESULT}; if ( rs->sr_type != REP_RESULT && rs->sr_type != REP_EXTENDED ) @@ -737,15 +819,15 @@ static int accesslog_response(Operation *op, SlapReply *rs) { if ( !( li->li_ops & lo->mask )) return SLAP_CB_CONTINUE; - endtime = slap_get_time(); + if ( lo->mask & LOG_OP_WRITES ) { + ldap_pvt_thread_mutex_lock( &li->li_log_mutex ); + ldap_pvt_thread_mutex_unlock( &li->li_op_mutex ); + } - e = accesslog_entry( op, logop ); + if ( li->li_success && rs->sr_err != LDAP_SUCCESS ) + goto done; - bv.bv_val = timebuf; - bv.bv_len = sizeof(timebuf); - slap_timestamp( &endtime, &bv ); - - attr_merge_one( e, ad_reqEnd, &bv, NULL ); + e = accesslog_entry( op, logop, &op2 ); attr_merge_one( e, ad_reqDN, &op->o_req_dn, &op->o_req_ndn ); @@ -844,7 +926,7 @@ static int accesslog_response(Operation *op, SlapReply *rs) { vals[i].bv_len = m->sml_desc->ad_cname.bv_len + 2; vals[i].bv_val = ch_malloc( vals[i].bv_len+1 ); ptr = lutil_strcopy( vals[i].bv_val, - a->a_desc->ad_cname.bv_val ); + m->sml_desc->ad_cname.bv_val ); *ptr++ = ':'; *ptr++ = '-'; *ptr = '\0'; @@ -883,6 +965,7 @@ static int accesslog_response(Operation *op, SlapReply *rs) { case LOG_EN_SEARCH: attr_merge_one( e, ad_reqScope, &scopes[op->ors_scope], NULL ); + attr_merge_one( e, ad_reqDerefAliases, &derefs[op->ors_deref], NULL ); attr_merge_one( e, ad_reqAttrsOnly, op->ors_attrsonly ? (struct berval *)&slap_true_bv : (struct berval *)&slap_false_bv, NULL ); @@ -907,10 +990,15 @@ static int accesslog_response(Operation *op, SlapReply *rs) { bv.bv_len = sprintf( bv.bv_val, "%d", op->ors_tlimit ); attr_merge_one( e, ad_reqTimeLimit, &bv, NULL ); - /* FIXME: slimit was zeroed by the backends */ + + bv.bv_len = sprintf( bv.bv_val, "%d", op->ors_slimit ); + attr_merge_one( e, ad_reqSizeLimit, &bv, NULL ); break; case LOG_EN_BIND: + bv.bv_val = timebuf; + bv.bv_len = sprintf( bv.bv_val, "%d", op->o_protocol ); + attr_merge_one( e, ad_reqVersion, &bv, NULL ); if ( op->orb_method == LDAP_AUTH_SIMPLE ) { attr_merge_one( e, ad_reqMethod, &simple, NULL ); } else { @@ -923,6 +1011,7 @@ static int accesslog_response(Operation *op, SlapReply *rs) { attr_merge_one( e, ad_reqMethod, &bv, NULL ); op->o_tmpfree( bv.bv_val, op->o_tmpmemctx ); } + break; case LOG_EN_EXTENDED: @@ -938,8 +1027,6 @@ static int accesslog_response(Operation *op, SlapReply *rs) { op2.o_hdr = op->o_hdr; op2.o_tag = LDAP_REQ_ADD; - op2.o_time = endtime; - op2.o_tincr = 0; op2.o_bd = li->li_db; op2.o_dn = li->li_db->be_rootdn; op2.o_ndn = li->li_db->be_rootndn; @@ -948,9 +1035,71 @@ static int accesslog_response(Operation *op, SlapReply *rs) { op2.ora_e = e; op2.o_callback = &nullsc; + if (( lo->mask & LOG_OP_WRITES ) && !BER_BVISEMPTY( &op->o_csn )) { + slap_queue_csn( &op2, &op->o_csn ); + } + op2.o_bd->be_add( &op2, &rs2 ); entry_free( e ); +done: + ldap_pvt_thread_mutex_unlock( &li->li_log_mutex ); + return SLAP_CB_CONTINUE; +} + +/* Since Bind success is sent by the frontend, it won't normally enter + * the overlay response callback. Add another callback to make sure it + * gets here. + */ +static int +accesslog_bind_resp( Operation *op, SlapReply *rs ) +{ + BackendDB *be, db; + int rc; + slap_callback *sc; + + be = op->o_bd; + db = *be; + op->o_bd = &db; + db.bd_info = op->o_callback->sc_private; + rc = accesslog_response( op, rs ); + op->o_bd = be; + sc = op->o_callback; + op->o_callback = sc->sc_next; + op->o_tmpfree( sc, op->o_tmpmemctx ); + return rc; +} + +static int +accesslog_op_bind( Operation *op, SlapReply *rs ) +{ + slap_callback *sc; + + sc = op->o_tmpcalloc( 1, sizeof(slap_callback), op->o_tmpmemctx ); + sc->sc_response = accesslog_bind_resp; + sc->sc_private = op->o_bd->bd_info; + + if ( op->o_callback ) { + sc->sc_next = op->o_callback->sc_next; + op->o_callback->sc_next = sc; + } else { + op->o_callback = sc; + } + return SLAP_CB_CONTINUE; +} + +static int +accesslog_op_mod( Operation *op, SlapReply *rs ) +{ + slap_overinst *on = (slap_overinst *)op->o_bd->bd_info; + log_info *li = on->on_bi.bi_private; + + if ( li->li_ops & LOG_OP_WRITES ) { + /* FIXME: this needs to be a recursive mutex to allow + * overlays like refint to keep working. + */ + ldap_pvt_thread_mutex_lock( &li->li_op_mutex ); + } return SLAP_CB_CONTINUE; } @@ -960,18 +1109,20 @@ static int accesslog_response(Operation *op, SlapReply *rs) { static int accesslog_unbind( Operation *op, SlapReply *rs ) { - if ( op->o_conn->c_authz_backend == op->o_bd ) { - slap_overinst *on = (slap_overinst *)op->o_bd->bd_info; + slap_overinst *on = (slap_overinst *)op->o_bd->bd_info; + if ( op->o_conn->c_authz_backend == on->on_info->oi_origdb ) { log_info *li = on->on_bi.bi_private; - Operation op2; + Operation op2 = {0}; + void *cids[SLAP_MAX_CIDS]; SlapReply rs2 = {REP_RESULT}; Entry *e; - e = accesslog_entry( op, LOG_EN_UNBIND ); + if ( !( li->li_ops & LOG_OP_UNBIND )) + return SLAP_CB_CONTINUE; + + e = accesslog_entry( op, LOG_EN_UNBIND, &op2 ); op2.o_hdr = op->o_hdr; op2.o_tag = LDAP_REQ_ADD; - op2.o_time = op->o_time; - op2.o_tincr = 0; op2.o_bd = li->li_db; op2.o_dn = li->li_db->be_rootdn; op2.o_ndn = li->li_db->be_rootndn; @@ -979,6 +1130,8 @@ accesslog_unbind( Operation *op, SlapReply *rs ) op2.o_req_ndn = e->e_nname; op2.ora_e = e; op2.o_callback = &nullsc; + op2.o_controls = cids; + memset(cids, 0, sizeof( cids )); op2.o_bd->be_add( &op2, &rs2 ); entry_free( e ); @@ -991,24 +1144,23 @@ accesslog_abandon( Operation *op, SlapReply *rs ) { slap_overinst *on = (slap_overinst *)op->o_bd->bd_info; log_info *li = on->on_bi.bi_private; - Operation op2; + Operation op2 = {0}; + void *cids[SLAP_MAX_CIDS]; SlapReply rs2 = {REP_RESULT}; Entry *e; char buf[64]; struct berval bv; - if ( !op->o_time ) + if ( !op->o_time || !( li->li_ops & LOG_OP_ABANDON )) return SLAP_CB_CONTINUE; - e = accesslog_entry( op, LOG_EN_ABANDON ); + e = accesslog_entry( op, LOG_EN_ABANDON, &op2 ); bv.bv_val = buf; bv.bv_len = sprintf( buf, "%d", op->orn_msgid ); attr_merge_one( e, ad_reqId, &bv, NULL ); op2.o_hdr = op->o_hdr; op2.o_tag = LDAP_REQ_ADD; - op2.o_time = op->o_time; - op2.o_tincr = 0; op2.o_bd = li->li_db; op2.o_dn = li->li_db->be_rootdn; op2.o_ndn = li->li_db->be_rootndn; @@ -1016,6 +1168,8 @@ accesslog_abandon( Operation *op, SlapReply *rs ) op2.o_req_ndn = e->e_nname; op2.ora_e = e; op2.o_callback = &nullsc; + op2.o_controls = cids; + memset(cids, 0, sizeof( cids )); op2.o_bd->be_add( &op2, &rs2 ); entry_free( e ); @@ -1034,6 +1188,8 @@ accesslog_db_init( log_info *li = ch_calloc(1, sizeof(log_info)); on->on_bi.bi_private = li; + ldap_pvt_thread_mutex_init( &li->li_op_mutex ); + ldap_pvt_thread_mutex_init( &li->li_log_mutex ); return 0; } @@ -1044,19 +1200,121 @@ accesslog_db_destroy( { slap_overinst *on = (slap_overinst *)be->bd_info; log_info *li = on->on_bi.bi_private; - + + ldap_pvt_thread_mutex_destroy( &li->li_log_mutex ); + ldap_pvt_thread_mutex_destroy( &li->li_op_mutex ); free( li ); return LDAP_SUCCESS; } -int accesslog_init() +static int +accesslog_db_open( + BackendDB *be +) +{ + slap_overinst *on = (slap_overinst *)be->bd_info; + log_info *li = on->on_bi.bi_private; + + Connection conn; + OperationBuffer opbuf; + Operation *op = (Operation *) &opbuf; + Entry *e; + int rc; + void *thrctx; + + if ( slapMode & SLAP_TOOL_MODE ) + return 0; + + thrctx = ldap_pvt_thread_pool_context(); + connection_fake_init( &conn, op, thrctx ); + op->o_bd = li->li_db; + op->o_dn = li->li_db->be_rootdn; + op->o_ndn = li->li_db->be_rootndn; + + rc = be_entry_get_rw( op, li->li_db->be_nsuffix, NULL, NULL, 0, &e ); + + if ( e ) { + be_entry_release_rw( op, e, 0 ); + } else { + SlapReply rs = {REP_RESULT}; + struct berval rdn, nrdn, attr; + char *ptr; + AttributeDescription *ad = NULL; + const char *text = NULL; + Entry *e_ctx; + + e = ch_calloc( 1, sizeof( Entry )); + e->e_name = *li->li_db->be_suffix; + e->e_nname = *li->li_db->be_nsuffix; + + attr_merge_one( e, slap_schema.si_ad_objectClass, + &log_container->soc_cname, NULL ); + + dnRdn( &e->e_name, &rdn ); + dnRdn( &e->e_nname, &nrdn ); + ptr = ber_bvchr( &rdn, '=' ); + + assert( ptr != NULL ); + + attr.bv_val = rdn.bv_val; + attr.bv_len = ptr - rdn.bv_val; + + slap_bv2ad( &attr, &ad, &text ); + + rdn.bv_val = ptr+1; + rdn.bv_len -= attr.bv_len + 1; + ptr = ber_bvchr( &nrdn, '=' ); + nrdn.bv_len -= ptr - nrdn.bv_val + 1; + nrdn.bv_val = ptr+1; + attr_merge_one( e, ad, &rdn, &nrdn ); + + /* Get contextCSN from main DB */ + op->o_bd = be; + op->o_bd->bd_info = on->on_info->oi_orig; + rc = be_entry_get_rw( op, be->be_nsuffix, NULL, + slap_schema.si_ad_contextCSN, 0, &e_ctx ); + + if ( e_ctx ) { + Attribute *a; + + a = attr_find( e_ctx->e_attrs, slap_schema.si_ad_contextCSN ); + if ( a ) { + attr_merge( e, slap_schema.si_ad_entryCSN, a->a_vals, NULL ); + attr_merge( e, a->a_desc, a->a_vals, NULL ); + } + be_entry_release_rw( op, e_ctx, 0 ); + } + op->o_bd->bd_info = (BackendInfo *)on; + op->o_bd = li->li_db; + + op->ora_e = e; + op->o_req_dn = e->e_name; + op->o_req_ndn = e->e_nname; + op->o_callback = &nullsc; + SLAP_DBFLAGS( op->o_bd ) |= SLAP_DBFLAG_NOLASTMOD; + rc = op->o_bd->be_add( op, &rs ); + SLAP_DBFLAGS( op->o_bd ) ^= SLAP_DBFLAG_NOLASTMOD; + attrs_free( e->e_attrs ); + ch_free( e ); + } + ldap_pvt_thread_pool_context_reset( thrctx ); + return rc; +} + +int accesslog_initialize() { int i, rc; accesslog.on_bi.bi_type = "accesslog"; accesslog.on_bi.bi_db_init = accesslog_db_init; accesslog.on_bi.bi_db_destroy = accesslog_db_destroy; + accesslog.on_bi.bi_db_open = accesslog_db_open; + accesslog.on_bi.bi_op_add = accesslog_op_mod; + accesslog.on_bi.bi_op_bind = accesslog_op_bind; + accesslog.on_bi.bi_op_delete = accesslog_op_mod; + accesslog.on_bi.bi_op_modify = accesslog_op_mod; + accesslog.on_bi.bi_op_modrdn = accesslog_op_mod; accesslog.on_bi.bi_op_unbind = accesslog_unbind; accesslog.on_bi.bi_op_abandon = accesslog_abandon; accesslog.on_response = accesslog_response; @@ -1129,8 +1387,10 @@ int accesslog_init() } #if SLAPD_OVER_ACCESSLOG == SLAPD_MOD_DYNAMIC -int init_module( int argc, char *argv[]) { - return accesslog_init(); +int +init_module( int argc, char *argv[] ) +{ + return accesslog_initialize(); } #endif