xref: /netbsd-src/external/bsd/openldap/dist/servers/slapd/overlays/accesslog.c (revision c2f76ff004a2cb67efe5b12d97bd3ef7fe89e18d)
1 /*	$NetBSD: accesslog.c,v 1.1.1.3 2010/12/12 15:23:32 adam Exp $	*/
2 
3 /* accesslog.c - log operations for audit/history purposes */
4 /* OpenLDAP: pkg/ldap/servers/slapd/overlays/accesslog.c,v 1.37.2.30 2010/04/19 20:37:53 quanah Exp */
5 /* This work is part of OpenLDAP Software <http://www.openldap.org/>.
6  *
7  * Copyright 2005-2010 The OpenLDAP Foundation.
8  * Portions copyright 2004-2005 Symas Corporation.
9  * All rights reserved.
10  *
11  * Redistribution and use in source and binary forms, with or without
12  * modification, are permitted only as authorized by the OpenLDAP
13  * Public License.
14  *
15  * A copy of this license is available in the file LICENSE in the
16  * top-level directory of the distribution or, alternatively, at
17  * <http://www.OpenLDAP.org/license.html>.
18  */
19 /* ACKNOWLEDGEMENTS:
20  * This work was initially developed by Howard Chu for inclusion in
21  * OpenLDAP Software.
22  */
23 
24 #include "portable.h"
25 
26 #ifdef SLAPD_OVER_ACCESSLOG
27 
28 #include <stdio.h>
29 
30 #include <ac/string.h>
31 #include <ac/ctype.h>
32 
33 #include "slap.h"
34 #include "config.h"
35 #include "lutil.h"
36 #include "ldap_rq.h"
37 
38 #define LOG_OP_ADD	0x001
39 #define LOG_OP_DELETE	0x002
40 #define	LOG_OP_MODIFY	0x004
41 #define LOG_OP_MODRDN	0x008
42 #define	LOG_OP_COMPARE	0x010
43 #define	LOG_OP_SEARCH	0x020
44 #define LOG_OP_BIND	0x040
45 #define LOG_OP_UNBIND	0x080
46 #define	LOG_OP_ABANDON	0x100
47 #define	LOG_OP_EXTENDED	0x200
48 #define LOG_OP_UNKNOWN	0x400
49 
50 #define	LOG_OP_WRITES	(LOG_OP_ADD|LOG_OP_DELETE|LOG_OP_MODIFY|LOG_OP_MODRDN)
51 #define	LOG_OP_READS	(LOG_OP_COMPARE|LOG_OP_SEARCH)
52 #define	LOG_OP_SESSION	(LOG_OP_BIND|LOG_OP_UNBIND|LOG_OP_ABANDON)
53 #define LOG_OP_ALL		(LOG_OP_READS|LOG_OP_WRITES|LOG_OP_SESSION| \
54 	LOG_OP_EXTENDED|LOG_OP_UNKNOWN)
55 
56 typedef struct log_attr {
57 	struct log_attr *next;
58 	AttributeDescription *attr;
59 } log_attr;
60 
61 typedef struct log_info {
62 	BackendDB *li_db;
63 	struct berval li_db_suffix;
64 	slap_mask_t li_ops;
65 	int li_age;
66 	int li_cycle;
67 	struct re_s *li_task;
68 	Filter *li_oldf;
69 	Entry *li_old;
70 	log_attr *li_oldattrs;
71 	int li_success;
72 	ldap_pvt_thread_rmutex_t li_op_rmutex;
73 	ldap_pvt_thread_mutex_t li_log_mutex;
74 } log_info;
75 
76 static ConfigDriver log_cf_gen;
77 
78 enum {
79 	LOG_DB = 1,
80 	LOG_OPS,
81 	LOG_PURGE,
82 	LOG_SUCCESS,
83 	LOG_OLD,
84 	LOG_OLDATTR
85 };
86 
87 static ConfigTable log_cfats[] = {
88 	{ "logdb", "suffix", 2, 2, 0, ARG_DN|ARG_MAGIC|LOG_DB,
89 		log_cf_gen, "( OLcfgOvAt:4.1 NAME 'olcAccessLogDB' "
90 			"DESC 'Suffix of database for log content' "
91 			"SUP distinguishedName SINGLE-VALUE )", NULL, NULL },
92 	{ "logops", "op|writes|reads|session|all", 2, 0, 0,
93 		ARG_MAGIC|LOG_OPS,
94 		log_cf_gen, "( OLcfgOvAt:4.2 NAME 'olcAccessLogOps' "
95 			"DESC 'Operation types to log' "
96 			"EQUALITY caseIgnoreMatch "
97 			"SYNTAX OMsDirectoryString )", NULL, NULL },
98 	{ "logpurge", "age> <interval", 3, 3, 0, ARG_MAGIC|LOG_PURGE,
99 		log_cf_gen, "( OLcfgOvAt:4.3 NAME 'olcAccessLogPurge' "
100 			"DESC 'Log cleanup parameters' "
101 			"SYNTAX OMsDirectoryString SINGLE-VALUE )", NULL, NULL },
102 	{ "logsuccess", NULL, 2, 2, 0, ARG_MAGIC|ARG_ON_OFF|LOG_SUCCESS,
103 		log_cf_gen, "( OLcfgOvAt:4.4 NAME 'olcAccessLogSuccess' "
104 			"DESC 'Log successful ops only' "
105 			"SYNTAX OMsBoolean SINGLE-VALUE )", NULL, NULL },
106 	{ "logold", "filter", 2, 2, 0, ARG_MAGIC|LOG_OLD,
107 		log_cf_gen, "( OLcfgOvAt:4.5 NAME 'olcAccessLogOld' "
108 			"DESC 'Log old values when modifying entries matching the filter' "
109 			"SYNTAX OMsDirectoryString SINGLE-VALUE )", NULL, NULL },
110 	{ "logoldattr", "attrs", 2, 0, 0, ARG_MAGIC|LOG_OLDATTR,
111 		log_cf_gen, "( OLcfgOvAt:4.6 NAME 'olcAccessLogOldAttr' "
112 			"DESC 'Log old values of these attributes even if unmodified' "
113 			"EQUALITY caseIgnoreMatch "
114 			"SYNTAX OMsDirectoryString )", NULL, NULL },
115 	{ NULL }
116 };
117 
118 static ConfigOCs log_cfocs[] = {
119 	{ "( OLcfgOvOc:4.1 "
120 		"NAME 'olcAccessLogConfig' "
121 		"DESC 'Access log configuration' "
122 		"SUP olcOverlayConfig "
123 		"MUST olcAccessLogDB "
124 		"MAY ( olcAccessLogOps $ olcAccessLogPurge $ olcAccessLogSuccess $ "
125 			"olcAccessLogOld $ olcAccessLogOldAttr ) )",
126 			Cft_Overlay, log_cfats },
127 	{ NULL }
128 };
129 
130 static slap_verbmasks logops[] = {
131 	{ BER_BVC("all"),		LOG_OP_ALL },
132 	{ BER_BVC("writes"),	LOG_OP_WRITES },
133 	{ BER_BVC("session"),	LOG_OP_SESSION },
134 	{ BER_BVC("reads"),		LOG_OP_READS },
135 	{ BER_BVC("add"),		LOG_OP_ADD },
136 	{ BER_BVC("delete"),	LOG_OP_DELETE },
137 	{ BER_BVC("modify"),	LOG_OP_MODIFY },
138 	{ BER_BVC("modrdn"),	LOG_OP_MODRDN },
139 	{ BER_BVC("compare"),	LOG_OP_COMPARE },
140 	{ BER_BVC("search"),	LOG_OP_SEARCH },
141 	{ BER_BVC("bind"),		LOG_OP_BIND },
142 	{ BER_BVC("unbind"),	LOG_OP_UNBIND },
143 	{ BER_BVC("abandon"),	LOG_OP_ABANDON },
144 	{ BER_BVC("extended"),	LOG_OP_EXTENDED },
145 	{ BER_BVC("unknown"),	LOG_OP_UNKNOWN },
146 	{ BER_BVNULL, 0 }
147 };
148 
149 /* Start with "add" in logops */
150 #define EN_OFFSET	4
151 
152 enum {
153 	LOG_EN_ADD = 0,
154 	LOG_EN_DELETE,
155 	LOG_EN_MODIFY,
156 	LOG_EN_MODRDN,
157 	LOG_EN_COMPARE,
158 	LOG_EN_SEARCH,
159 	LOG_EN_BIND,
160 	LOG_EN_UNBIND,
161 	LOG_EN_ABANDON,
162 	LOG_EN_EXTENDED,
163 	LOG_EN_UNKNOWN,
164 	LOG_EN__COUNT
165 };
166 
167 static ObjectClass *log_ocs[LOG_EN__COUNT], *log_container,
168 	*log_oc_read, *log_oc_write;
169 
170 #define LOG_SCHEMA_ROOT	"1.3.6.1.4.1.4203.666.11.5"
171 
172 #define LOG_SCHEMA_AT LOG_SCHEMA_ROOT ".1"
173 #define LOG_SCHEMA_OC LOG_SCHEMA_ROOT ".2"
174 #define LOG_SCHEMA_SYN LOG_SCHEMA_ROOT ".3"
175 
176 static AttributeDescription *ad_reqDN, *ad_reqStart, *ad_reqEnd, *ad_reqType,
177 	*ad_reqSession, *ad_reqResult, *ad_reqAuthzID, *ad_reqControls,
178 	*ad_reqRespControls, *ad_reqMethod, *ad_reqAssertion, *ad_reqNewRDN,
179 	*ad_reqNewSuperior, *ad_reqDeleteOldRDN, *ad_reqMod,
180 	*ad_reqScope, *ad_reqFilter, *ad_reqAttr, *ad_reqEntries,
181 	*ad_reqSizeLimit, *ad_reqTimeLimit, *ad_reqAttrsOnly, *ad_reqData,
182 	*ad_reqId, *ad_reqMessage, *ad_reqVersion, *ad_reqDerefAliases,
183 	*ad_reqReferral, *ad_reqOld, *ad_auditContext;
184 
185 static int
186 logSchemaControlValidate(
187 	Syntax		*syntax,
188 	struct berval	*val );
189 
190 char	*mrControl[] = {
191 	"objectIdentifierFirstComponentMatch",
192 	NULL
193 };
194 
195 static struct {
196 	char			*oid;
197 	slap_syntax_defs_rec	syn;
198 	char			**mrs;
199 } lsyntaxes[] = {
200 	{ LOG_SCHEMA_SYN ".1" ,
201 		{ "( " LOG_SCHEMA_SYN ".1 DESC 'Control' )",
202 			SLAP_SYNTAX_HIDE,
203 			NULL,
204 			logSchemaControlValidate,
205 			NULL },
206 		mrControl },
207 	{ NULL }
208 };
209 
210 static struct {
211 	char *at;
212 	AttributeDescription **ad;
213 } lattrs[] = {
214 	{ "( " LOG_SCHEMA_AT ".1 NAME 'reqDN' "
215 		"DESC 'Target DN of request' "
216 		"EQUALITY distinguishedNameMatch "
217 		"SYNTAX OMsDN "
218 		"SINGLE-VALUE )", &ad_reqDN },
219 	{ "( " LOG_SCHEMA_AT ".2 NAME 'reqStart' "
220 		"DESC 'Start time of request' "
221 		"EQUALITY generalizedTimeMatch "
222 		"ORDERING generalizedTimeOrderingMatch "
223 		"SYNTAX 1.3.6.1.4.1.1466.115.121.1.24 "
224 		"SINGLE-VALUE )", &ad_reqStart },
225 	{ "( " LOG_SCHEMA_AT ".3 NAME 'reqEnd' "
226 		"DESC 'End time of request' "
227 		"EQUALITY generalizedTimeMatch "
228 		"ORDERING generalizedTimeOrderingMatch "
229 		"SYNTAX 1.3.6.1.4.1.1466.115.121.1.24 "
230 		"SINGLE-VALUE )", &ad_reqEnd },
231 	{ "( " LOG_SCHEMA_AT ".4 NAME 'reqType' "
232 		"DESC 'Type of request' "
233 		"EQUALITY caseIgnoreMatch "
234 		"SYNTAX OMsDirectoryString "
235 		"SINGLE-VALUE )", &ad_reqType },
236 	{ "( " LOG_SCHEMA_AT ".5 NAME 'reqSession' "
237 		"DESC 'Session ID of request' "
238 		"EQUALITY caseIgnoreMatch "
239 		"SYNTAX OMsDirectoryString "
240 		"SINGLE-VALUE )", &ad_reqSession },
241 	{ "( " LOG_SCHEMA_AT ".6 NAME 'reqAuthzID' "
242 		"DESC 'Authorization ID of requestor' "
243 		"EQUALITY distinguishedNameMatch "
244 		"SYNTAX OMsDN "
245 		"SINGLE-VALUE )", &ad_reqAuthzID },
246 	{ "( " LOG_SCHEMA_AT ".7 NAME 'reqResult' "
247 		"DESC 'Result code of request' "
248 		"EQUALITY integerMatch "
249 		"ORDERING integerOrderingMatch "
250 		"SYNTAX OMsInteger "
251 		"SINGLE-VALUE )", &ad_reqResult },
252 	{ "( " LOG_SCHEMA_AT ".8 NAME 'reqMessage' "
253 		"DESC 'Error text of request' "
254 		"EQUALITY caseIgnoreMatch "
255 		"SUBSTR caseIgnoreSubstringsMatch "
256 		"SYNTAX OMsDirectoryString "
257 		"SINGLE-VALUE )", &ad_reqMessage },
258 	{ "( " LOG_SCHEMA_AT ".9 NAME 'reqReferral' "
259 		"DESC 'Referrals returned for request' "
260 		"SUP labeledURI )", &ad_reqReferral },
261 	{ "( " LOG_SCHEMA_AT ".10 NAME 'reqControls' "
262 		"DESC 'Request controls' "
263 		"EQUALITY objectIdentifierFirstComponentMatch "
264 		"SYNTAX " LOG_SCHEMA_SYN ".1 "
265 		"X-ORDERED 'VALUES' )", &ad_reqControls },
266 	{ "( " LOG_SCHEMA_AT ".11 NAME 'reqRespControls' "
267 		"DESC 'Response controls of request' "
268 		"EQUALITY objectIdentifierFirstComponentMatch "
269 		"SYNTAX " LOG_SCHEMA_SYN ".1 "
270 		"X-ORDERED 'VALUES' )", &ad_reqRespControls },
271 	{ "( " LOG_SCHEMA_AT ".12 NAME 'reqId' "
272 		"DESC 'ID of Request to Abandon' "
273 		"EQUALITY integerMatch "
274 		"ORDERING integerOrderingMatch "
275 		"SYNTAX OMsInteger "
276 		"SINGLE-VALUE )", &ad_reqId },
277 	{ "( " LOG_SCHEMA_AT ".13 NAME 'reqVersion' "
278 		"DESC 'Protocol version of Bind request' "
279 		"EQUALITY integerMatch "
280 		"ORDERING integerOrderingMatch "
281 		"SYNTAX OMsInteger "
282 		"SINGLE-VALUE )", &ad_reqVersion },
283 	{ "( " LOG_SCHEMA_AT ".14 NAME 'reqMethod' "
284 		"DESC 'Bind method of request' "
285 		"EQUALITY caseIgnoreMatch "
286 		"SYNTAX OMsDirectoryString "
287 		"SINGLE-VALUE )", &ad_reqMethod },
288 	{ "( " LOG_SCHEMA_AT ".15 NAME 'reqAssertion' "
289 		"DESC 'Compare Assertion of request' "
290 		"SYNTAX OMsDirectoryString "
291 		"SINGLE-VALUE )", &ad_reqAssertion },
292 	{ "( " LOG_SCHEMA_AT ".16 NAME 'reqMod' "
293 		"DESC 'Modifications of request' "
294 		"EQUALITY octetStringMatch "
295 		"SUBSTR octetStringSubstringsMatch "
296 		"SYNTAX OMsOctetString )", &ad_reqMod },
297 	{ "( " LOG_SCHEMA_AT ".17 NAME 'reqOld' "
298 		"DESC 'Old values of entry before request completed' "
299 		"EQUALITY octetStringMatch "
300 		"SUBSTR octetStringSubstringsMatch "
301 		"SYNTAX OMsOctetString )", &ad_reqOld },
302 	{ "( " LOG_SCHEMA_AT ".18 NAME 'reqNewRDN' "
303 		"DESC 'New RDN of request' "
304 		"EQUALITY distinguishedNameMatch "
305 		"SYNTAX OMsDN "
306 		"SINGLE-VALUE )", &ad_reqNewRDN },
307 	{ "( " LOG_SCHEMA_AT ".19 NAME 'reqDeleteOldRDN' "
308 		"DESC 'Delete old RDN' "
309 		"EQUALITY booleanMatch "
310 		"SYNTAX OMsBoolean "
311 		"SINGLE-VALUE )", &ad_reqDeleteOldRDN },
312 	{ "( " LOG_SCHEMA_AT ".20 NAME 'reqNewSuperior' "
313 		"DESC 'New superior DN of request' "
314 		"EQUALITY distinguishedNameMatch "
315 		"SYNTAX OMsDN "
316 		"SINGLE-VALUE )", &ad_reqNewSuperior },
317 	{ "( " LOG_SCHEMA_AT ".21 NAME 'reqScope' "
318 		"DESC 'Scope of request' "
319 		"EQUALITY caseIgnoreMatch "
320 		"SYNTAX OMsDirectoryString "
321 		"SINGLE-VALUE )", &ad_reqScope },
322 	{ "( " LOG_SCHEMA_AT ".22 NAME 'reqDerefAliases' "
323 		"DESC 'Disposition of Aliases in request' "
324 		"EQUALITY caseIgnoreMatch "
325 		"SYNTAX OMsDirectoryString "
326 		"SINGLE-VALUE )", &ad_reqDerefAliases },
327 	{ "( " LOG_SCHEMA_AT ".23 NAME 'reqAttrsOnly' "
328 		"DESC 'Attributes and values of request' "
329 		"EQUALITY booleanMatch "
330 		"SYNTAX OMsBoolean "
331 		"SINGLE-VALUE )", &ad_reqAttrsOnly },
332 	{ "( " LOG_SCHEMA_AT ".24 NAME 'reqFilter' "
333 		"DESC 'Filter of request' "
334 		"EQUALITY caseIgnoreMatch "
335 		"SUBSTR caseIgnoreSubstringsMatch "
336 		"SYNTAX OMsDirectoryString "
337 		"SINGLE-VALUE )", &ad_reqFilter },
338 	{ "( " LOG_SCHEMA_AT ".25 NAME 'reqAttr' "
339 		"DESC 'Attributes of request' "
340 		"EQUALITY caseIgnoreMatch "
341 		"SYNTAX OMsDirectoryString )", &ad_reqAttr },
342 	{ "( " LOG_SCHEMA_AT ".26 NAME 'reqSizeLimit' "
343 		"DESC 'Size limit of request' "
344 		"EQUALITY integerMatch "
345 		"ORDERING integerOrderingMatch "
346 		"SYNTAX OMsInteger "
347 		"SINGLE-VALUE )", &ad_reqSizeLimit },
348 	{ "( " LOG_SCHEMA_AT ".27 NAME 'reqTimeLimit' "
349 		"DESC 'Time limit of request' "
350 		"EQUALITY integerMatch "
351 		"ORDERING integerOrderingMatch "
352 		"SYNTAX OMsInteger "
353 		"SINGLE-VALUE )", &ad_reqTimeLimit },
354 	{ "( " LOG_SCHEMA_AT ".28 NAME 'reqEntries' "
355 		"DESC 'Number of entries returned' "
356 		"EQUALITY integerMatch "
357 		"ORDERING integerOrderingMatch "
358 		"SYNTAX OMsInteger "
359 		"SINGLE-VALUE )", &ad_reqEntries },
360 	{ "( " LOG_SCHEMA_AT ".29 NAME 'reqData' "
361 		"DESC 'Data of extended request' "
362 		"EQUALITY octetStringMatch "
363 		"SUBSTR octetStringSubstringsMatch "
364 		"SYNTAX OMsOctetString "
365 		"SINGLE-VALUE )", &ad_reqData },
366 
367 	/*
368 	 * from <draft-chu-ldap-logschema-01.txt>:
369 	 *
370 
371    ( LOG_SCHEMA_AT .30 NAME 'auditContext'
372    DESC 'DN of auditContainer'
373    EQUALITY distinguishedNameMatch
374    SYNTAX 1.3.6.1.4.1.1466.115.121.1.12
375    SINGLE-VALUE NO-USER-MODIFICATION USAGE directoryOperation )
376 
377 	 * - removed EQUALITY matchingRule
378 	 * - changed directoryOperation in dSAOperation
379 	 */
380 	{ "( " LOG_SCHEMA_AT ".30 NAME 'auditContext' "
381 		"DESC 'DN of auditContainer' "
382 		"SYNTAX 1.3.6.1.4.1.1466.115.121.1.12 "
383 		"SINGLE-VALUE "
384 		"NO-USER-MODIFICATION "
385 		"USAGE dSAOperation )", &ad_auditContext },
386 	{ NULL, NULL }
387 };
388 
389 static struct {
390 	char *ot;
391 	ObjectClass **oc;
392 } locs[] = {
393 	{ "( " LOG_SCHEMA_OC ".0 NAME 'auditContainer' "
394 		"DESC 'AuditLog container' "
395 		"SUP top STRUCTURAL "
396 		"MAY ( cn $ reqStart $ reqEnd ) )", &log_container },
397 	{ "( " LOG_SCHEMA_OC ".1 NAME 'auditObject' "
398 		"DESC 'OpenLDAP request auditing' "
399 		"SUP top STRUCTURAL "
400 		"MUST ( reqStart $ reqType $ reqSession ) "
401 		"MAY ( reqDN $ reqAuthzID $ reqControls $ reqRespControls $ reqEnd $ "
402 			"reqResult $ reqMessage $ reqReferral ) )",
403 				&log_ocs[LOG_EN_UNBIND] },
404 	{ "( " LOG_SCHEMA_OC ".2 NAME 'auditReadObject' "
405 		"DESC 'OpenLDAP read request record' "
406 		"SUP auditObject STRUCTURAL )", &log_oc_read },
407 	{ "( " LOG_SCHEMA_OC ".3 NAME 'auditWriteObject' "
408 		"DESC 'OpenLDAP write request record' "
409 		"SUP auditObject STRUCTURAL )", &log_oc_write },
410 	{ "( " LOG_SCHEMA_OC ".4 NAME 'auditAbandon' "
411 		"DESC 'Abandon operation' "
412 		"SUP auditObject STRUCTURAL "
413 		"MUST reqId )", &log_ocs[LOG_EN_ABANDON] },
414 	{ "( " LOG_SCHEMA_OC ".5 NAME 'auditAdd' "
415 		"DESC 'Add operation' "
416 		"SUP auditWriteObject STRUCTURAL "
417 		"MUST reqMod )", &log_ocs[LOG_EN_ADD] },
418 	{ "( " LOG_SCHEMA_OC ".6 NAME 'auditBind' "
419 		"DESC 'Bind operation' "
420 		"SUP auditObject STRUCTURAL "
421 		"MUST ( reqVersion $ reqMethod ) )", &log_ocs[LOG_EN_BIND] },
422 	{ "( " LOG_SCHEMA_OC ".7 NAME 'auditCompare' "
423 		"DESC 'Compare operation' "
424 		"SUP auditReadObject STRUCTURAL "
425 		"MUST reqAssertion )", &log_ocs[LOG_EN_COMPARE] },
426 	{ "( " LOG_SCHEMA_OC ".8 NAME 'auditDelete' "
427 		"DESC 'Delete operation' "
428 		"SUP auditWriteObject STRUCTURAL "
429 		"MAY reqOld )", &log_ocs[LOG_EN_DELETE] },
430 	{ "( " LOG_SCHEMA_OC ".9 NAME 'auditModify' "
431 		"DESC 'Modify operation' "
432 		"SUP auditWriteObject STRUCTURAL "
433 		"MAY reqOld MUST reqMod )", &log_ocs[LOG_EN_MODIFY] },
434 	{ "( " LOG_SCHEMA_OC ".10 NAME 'auditModRDN' "
435 		"DESC 'ModRDN operation' "
436 		"SUP auditWriteObject STRUCTURAL "
437 		"MUST ( reqNewRDN $ reqDeleteOldRDN ) "
438 		"MAY ( reqNewSuperior $ reqMod $ reqOld ) )", &log_ocs[LOG_EN_MODRDN] },
439 	{ "( " LOG_SCHEMA_OC ".11 NAME 'auditSearch' "
440 		"DESC 'Search operation' "
441 		"SUP auditReadObject STRUCTURAL "
442 		"MUST ( reqScope $ reqDerefAliases $ reqAttrsonly ) "
443 		"MAY ( reqFilter $ reqAttr $ reqEntries $ reqSizeLimit $ "
444 			"reqTimeLimit ) )", &log_ocs[LOG_EN_SEARCH] },
445 	{ "( " LOG_SCHEMA_OC ".12 NAME 'auditExtended' "
446 		"DESC 'Extended operation' "
447 		"SUP auditObject STRUCTURAL "
448 		"MAY reqData )", &log_ocs[LOG_EN_EXTENDED] },
449 	{ NULL, NULL }
450 };
451 
452 #define	RDNEQ	"reqStart="
453 
454 /* Our time intervals are of the form [ddd+]hh:mm[:ss]
455  * If a field is present, it must be two digits. (Except for
456  * days, which can be arbitrary width.)
457  */
458 static int
459 log_age_parse(char *agestr)
460 {
461 	int t1, t2;
462 	int gotdays = 0;
463 	char *endptr;
464 
465 	t1 = strtol( agestr, &endptr, 10 );
466 	/* Is there a days delimiter? */
467 	if ( *endptr == '+' ) {
468 		/* 32 bit time only covers about 68 years */
469 		if ( t1 < 0 || t1 > 25000 )
470 			return -1;
471 		t1 *= 24;
472 		gotdays = 1;
473 		agestr = endptr + 1;
474 	} else {
475 		if ( agestr[2] != ':' ) {
476 			/* No valid delimiter found, fail */
477 			return -1;
478 		}
479 		t1 *= 60;
480 		agestr += 3;
481 	}
482 
483 	t2 = atoi( agestr );
484 	t1 += t2;
485 
486 	if ( agestr[2] ) {
487 		/* if there's a delimiter, it can only be a colon */
488 		if ( agestr[2] != ':' )
489 			return -1;
490 	} else {
491 		/* If we're at the end of the string, and we started with days,
492 		 * fail because we expected to find minutes too.
493 		 */
494 		return gotdays ? -1 : t1 * 60;
495 	}
496 
497 	agestr += 3;
498 	t2 = atoi( agestr );
499 
500 	/* last field can only be seconds */
501 	if ( agestr[2] && ( agestr[2] != ':' || !gotdays ))
502 		return -1;
503 	t1 *= 60;
504 	t1 += t2;
505 
506 	if ( agestr[2] ) {
507 		agestr += 3;
508 		if ( agestr[2] )
509 			return -1;
510 		t1 *= 60;
511 		t1 += atoi( agestr );
512 	} else if ( gotdays ) {
513 		/* only got days+hh:mm */
514 		t1 *= 60;
515 	}
516 	return t1;
517 }
518 
519 static void
520 log_age_unparse( int age, struct berval *agebv, size_t size )
521 {
522 	int dd, hh, mm, ss, len;
523 	char *ptr;
524 
525 	assert( size > 0 );
526 
527 	ss = age % 60;
528 	age /= 60;
529 	mm = age % 60;
530 	age /= 60;
531 	hh = age % 24;
532 	age /= 24;
533 	dd = age;
534 
535 	ptr = agebv->bv_val;
536 
537 	if ( dd ) {
538 		len = snprintf( ptr, size, "%d+", dd );
539 		assert( len >= 0 && (unsigned) len < size );
540 		size -= len;
541 		ptr += len;
542 	}
543 	len = snprintf( ptr, size, "%02d:%02d", hh, mm );
544 	assert( len >= 0 && (unsigned) len < size );
545 	size -= len;
546 	ptr += len;
547 	if ( ss ) {
548 		len = snprintf( ptr, size, ":%02d", ss );
549 		assert( len >= 0 && (unsigned) len < size );
550 		size -= len;
551 		ptr += len;
552 	}
553 
554 	agebv->bv_len = ptr - agebv->bv_val;
555 }
556 
557 static slap_callback nullsc = { NULL, NULL, NULL, NULL };
558 
559 #define PURGE_INCREMENT	100
560 
561 typedef struct purge_data {
562 	int slots;
563 	int used;
564 	BerVarray dn;
565 	BerVarray ndn;
566 	struct berval csn;	/* an arbitrary old CSN */
567 } purge_data;
568 
569 static int
570 log_old_lookup( Operation *op, SlapReply *rs )
571 {
572 	purge_data *pd = op->o_callback->sc_private;
573 	Attribute *a;
574 
575 	if ( rs->sr_type != REP_SEARCH) return 0;
576 
577 	if ( slapd_shutdown ) return 0;
578 
579 	/* Remember max CSN: should always be the last entry
580 	 * seen, since log entries are ordered chronologically...
581 	 */
582 	a = attr_find( rs->sr_entry->e_attrs,
583 		slap_schema.si_ad_entryCSN );
584 	if ( a ) {
585 		ber_len_t len = a->a_nvals[0].bv_len;
586 		/* Paranoid len check, normalized CSNs are always the same length */
587 		if ( len > LDAP_PVT_CSNSTR_BUFSIZE )
588 			len = LDAP_PVT_CSNSTR_BUFSIZE;
589 		if ( memcmp( a->a_nvals[0].bv_val, pd->csn.bv_val, len ) > 0 ) {
590 			AC_MEMCPY( pd->csn.bv_val, a->a_nvals[0].bv_val, len );
591 			pd->csn.bv_len = len;
592 		}
593 	}
594 	if ( pd->used >= pd->slots ) {
595 		pd->slots += PURGE_INCREMENT;
596 		pd->dn = ch_realloc( pd->dn, pd->slots * sizeof( struct berval ));
597 		pd->ndn = ch_realloc( pd->ndn, pd->slots * sizeof( struct berval ));
598 	}
599 	ber_dupbv( &pd->dn[pd->used], &rs->sr_entry->e_name );
600 	ber_dupbv( &pd->ndn[pd->used], &rs->sr_entry->e_nname );
601 	pd->used++;
602 	return 0;
603 }
604 
605 /* Periodically search for old entries in the log database and delete them */
606 static void *
607 accesslog_purge( void *ctx, void *arg )
608 {
609 	struct re_s *rtask = arg;
610 	struct log_info *li = rtask->arg;
611 
612 	Connection conn = {0};
613 	OperationBuffer opbuf;
614 	Operation *op;
615 	SlapReply rs = {REP_RESULT};
616 	slap_callback cb = { NULL, log_old_lookup, NULL, NULL };
617 	Filter f;
618 	AttributeAssertion ava = ATTRIBUTEASSERTION_INIT;
619 	purge_data pd = {0};
620 	char timebuf[LDAP_LUTIL_GENTIME_BUFSIZE];
621 	char csnbuf[LDAP_PVT_CSNSTR_BUFSIZE];
622 	time_t old = slap_get_time();
623 
624 	connection_fake_init( &conn, &opbuf, ctx );
625 	op = &opbuf.ob_op;
626 
627 	f.f_choice = LDAP_FILTER_LE;
628 	f.f_ava = &ava;
629 	f.f_next = NULL;
630 
631 	ava.aa_desc = ad_reqStart;
632 	ava.aa_value.bv_val = timebuf;
633 	ava.aa_value.bv_len = sizeof(timebuf);
634 
635 	old -= li->li_age;
636 	slap_timestamp( &old, &ava.aa_value );
637 
638 	op->o_tag = LDAP_REQ_SEARCH;
639 	op->o_bd = li->li_db;
640 	op->o_dn = li->li_db->be_rootdn;
641 	op->o_ndn = li->li_db->be_rootndn;
642 	op->o_req_dn = li->li_db->be_suffix[0];
643 	op->o_req_ndn = li->li_db->be_nsuffix[0];
644 	op->o_callback = &cb;
645 	op->ors_scope = LDAP_SCOPE_ONELEVEL;
646 	op->ors_deref = LDAP_DEREF_NEVER;
647 	op->ors_tlimit = SLAP_NO_LIMIT;
648 	op->ors_slimit = SLAP_NO_LIMIT;
649 	op->ors_filter = &f;
650 	filter2bv_x( op, &f, &op->ors_filterstr );
651 	op->ors_attrs = slap_anlist_no_attrs;
652 	op->ors_attrsonly = 1;
653 
654 	pd.csn.bv_len = sizeof( csnbuf );
655 	pd.csn.bv_val = csnbuf;
656 	csnbuf[0] = '\0';
657 	cb.sc_private = &pd;
658 
659 	op->o_bd->be_search( op, &rs );
660 	op->o_tmpfree( op->ors_filterstr.bv_val, op->o_tmpmemctx );
661 
662 	if ( pd.used ) {
663 		int i;
664 
665 		/* delete the expired entries */
666 		op->o_tag = LDAP_REQ_DELETE;
667 		op->o_callback = &nullsc;
668 		op->o_csn = pd.csn;
669 		op->o_dont_replicate = 1;
670 
671 		for (i=0; i<pd.used; i++) {
672 			op->o_req_dn = pd.dn[i];
673 			op->o_req_ndn = pd.ndn[i];
674 			if ( !slapd_shutdown )
675 				op->o_bd->be_delete( op, &rs );
676 			ch_free( pd.ndn[i].bv_val );
677 			ch_free( pd.dn[i].bv_val );
678 		}
679 		ch_free( pd.ndn );
680 		ch_free( pd.dn );
681 
682 		{
683 			Modifications mod;
684 			struct berval bv[2];
685 			/* update context's entryCSN to reflect oldest CSN */
686 			mod.sml_numvals = 1;
687 			mod.sml_values = bv;
688 			bv[0] = pd.csn;
689 			BER_BVZERO(&bv[1]);
690 			mod.sml_nvalues = NULL;
691 			mod.sml_desc = slap_schema.si_ad_entryCSN;
692 			mod.sml_op = LDAP_MOD_REPLACE;
693 			mod.sml_flags = SLAP_MOD_INTERNAL;
694 			mod.sml_next = NULL;
695 
696 			op->o_tag = LDAP_REQ_MODIFY;
697 			op->orm_modlist = &mod;
698 			op->orm_no_opattrs = 1;
699 			op->o_req_dn = li->li_db->be_suffix[0];
700 			op->o_req_ndn = li->li_db->be_nsuffix[0];
701 			op->o_no_schema_check = 1;
702 			op->o_managedsait = SLAP_CONTROL_NONCRITICAL;
703 			op->o_bd->be_modify( op, &rs );
704 			if ( mod.sml_next ) {
705 				slap_mods_free( mod.sml_next, 1 );
706 			}
707 		}
708 	}
709 
710 	ldap_pvt_thread_mutex_lock( &slapd_rq.rq_mutex );
711 	ldap_pvt_runqueue_stoptask( &slapd_rq, rtask );
712 	ldap_pvt_thread_mutex_unlock( &slapd_rq.rq_mutex );
713 
714 	return NULL;
715 }
716 
717 static int
718 log_cf_gen(ConfigArgs *c)
719 {
720 	slap_overinst *on = (slap_overinst *)c->bi;
721 	struct log_info *li = on->on_bi.bi_private;
722 	int rc = 0;
723 	slap_mask_t tmask = 0;
724 	char agebuf[2*STRLENOF("ddddd+hh:mm:ss  ")];
725 	struct berval agebv, cyclebv;
726 
727 	switch( c->op ) {
728 	case SLAP_CONFIG_EMIT:
729 		switch( c->type ) {
730 		case LOG_DB:
731 			if ( !BER_BVISEMPTY( &li->li_db_suffix )) {
732 				value_add_one( &c->rvalue_vals, &li->li_db_suffix );
733 				value_add_one( &c->rvalue_nvals, &li->li_db_suffix );
734 			} else if ( li->li_db ) {
735 				value_add_one( &c->rvalue_vals, li->li_db->be_suffix );
736 				value_add_one( &c->rvalue_nvals, li->li_db->be_nsuffix );
737 			} else {
738 				snprintf( c->cr_msg, sizeof( c->cr_msg ),
739 					"accesslog: \"logdb <suffix>\" must be specified" );
740 				Debug( LDAP_DEBUG_ANY, "%s: %s \"%s\"\n",
741 					c->log, c->cr_msg, c->value_dn.bv_val );
742 				rc = 1;
743 				break;
744 			}
745 			break;
746 		case LOG_OPS:
747 			rc = mask_to_verbs( logops, li->li_ops, &c->rvalue_vals );
748 			break;
749 		case LOG_PURGE:
750 			if ( !li->li_age ) {
751 				rc = 1;
752 				break;
753 			}
754 			agebv.bv_val = agebuf;
755 			log_age_unparse( li->li_age, &agebv, sizeof( agebuf ) );
756 			agebv.bv_val[agebv.bv_len] = ' ';
757 			agebv.bv_len++;
758 			cyclebv.bv_val = agebv.bv_val + agebv.bv_len;
759 			log_age_unparse( li->li_cycle, &cyclebv, sizeof( agebuf ) - agebv.bv_len );
760 			agebv.bv_len += cyclebv.bv_len;
761 			value_add_one( &c->rvalue_vals, &agebv );
762 			break;
763 		case LOG_SUCCESS:
764 			if ( li->li_success )
765 				c->value_int = li->li_success;
766 			else
767 				rc = 1;
768 			break;
769 		case LOG_OLD:
770 			if ( li->li_oldf ) {
771 				filter2bv( li->li_oldf, &agebv );
772 				ber_bvarray_add( &c->rvalue_vals, &agebv );
773 			}
774 			else
775 				rc = 1;
776 			break;
777 		case LOG_OLDATTR:
778 			if ( li->li_oldattrs ) {
779 				log_attr *la;
780 
781 				for ( la = li->li_oldattrs; la; la=la->next )
782 					value_add_one( &c->rvalue_vals, &la->attr->ad_cname );
783 			}
784 			else
785 				rc = 1;
786 			break;
787 		}
788 		break;
789 	case LDAP_MOD_DELETE:
790 		switch( c->type ) {
791 		case LOG_DB:
792 			/* noop. this should always be a valid backend. */
793 			break;
794 		case LOG_OPS:
795 			if ( c->valx < 0 ) {
796 				li->li_ops = 0;
797 			} else {
798 				rc = verbs_to_mask( 1, &c->line, logops, &tmask );
799 				if ( rc == 0 )
800 					li->li_ops &= ~tmask;
801 			}
802 			break;
803 		case LOG_PURGE:
804 			if ( li->li_task ) {
805 				struct re_s *re = li->li_task;
806 				li->li_task = NULL;
807 				ldap_pvt_thread_mutex_lock( &slapd_rq.rq_mutex );
808 				if ( ldap_pvt_runqueue_isrunning( &slapd_rq, re ))
809 					ldap_pvt_runqueue_stoptask( &slapd_rq, re );
810 				ldap_pvt_runqueue_remove( &slapd_rq, re );
811 				ldap_pvt_thread_mutex_unlock( &slapd_rq.rq_mutex );
812 			}
813 			li->li_age = 0;
814 			li->li_cycle = 0;
815 			break;
816 		case LOG_SUCCESS:
817 			li->li_success = 0;
818 			break;
819 		case LOG_OLD:
820 			if ( li->li_oldf ) {
821 				filter_free( li->li_oldf );
822 				li->li_oldf = NULL;
823 			}
824 			break;
825 		case LOG_OLDATTR:
826 			if ( c->valx < 0 ) {
827 				log_attr *la, *ln;
828 
829 				for ( la = li->li_oldattrs; la; la = ln ) {
830 					ln = la->next;
831 					ch_free( la );
832 				}
833 			} else {
834 				log_attr *la = NULL, **lp;
835 				int i;
836 
837 				for ( lp = &li->li_oldattrs, i=0; i < c->valx; i++ ) {
838 					la = *lp;
839 					lp = &la->next;
840 				}
841 				*lp = la->next;
842 				ch_free( la );
843 			}
844 			break;
845 		}
846 		break;
847 	default:
848 		switch( c->type ) {
849 		case LOG_DB:
850 			if ( CONFIG_ONLINE_ADD( c )) {
851 				li->li_db = select_backend( &c->value_ndn, 0 );
852 				if ( !li->li_db ) {
853 					snprintf( c->cr_msg, sizeof( c->cr_msg ),
854 						"<%s> no matching backend found for suffix",
855 						c->argv[0] );
856 					Debug( LDAP_DEBUG_ANY, "%s: %s \"%s\"\n",
857 						c->log, c->cr_msg, c->value_dn.bv_val );
858 					rc = 1;
859 				}
860 				ch_free( c->value_ndn.bv_val );
861 			} else {
862 				li->li_db_suffix = c->value_ndn;
863 			}
864 			ch_free( c->value_dn.bv_val );
865 			break;
866 		case LOG_OPS:
867 			rc = verbs_to_mask( c->argc, c->argv, logops, &tmask );
868 			if ( rc == 0 )
869 				li->li_ops |= tmask;
870 			break;
871 		case LOG_PURGE:
872 			li->li_age = log_age_parse( c->argv[1] );
873 			if ( li->li_age < 1 ) {
874 				rc = 1;
875 			} else {
876 				li->li_cycle = log_age_parse( c->argv[2] );
877 				if ( li->li_cycle < 1 ) {
878 					rc = 1;
879 				} else if ( slapMode & SLAP_SERVER_MODE ) {
880 					struct re_s *re = li->li_task;
881 					if ( re )
882 						re->interval.tv_sec = li->li_cycle;
883 					else {
884 						ldap_pvt_thread_mutex_lock( &slapd_rq.rq_mutex );
885 						li->li_task = ldap_pvt_runqueue_insert( &slapd_rq,
886 							li->li_cycle, accesslog_purge, li,
887 							"accesslog_purge", li->li_db ?
888 								li->li_db->be_suffix[0].bv_val :
889 								c->be->be_suffix[0].bv_val );
890 						ldap_pvt_thread_mutex_unlock( &slapd_rq.rq_mutex );
891 					}
892 				}
893 			}
894 			break;
895 		case LOG_SUCCESS:
896 			li->li_success = c->value_int;
897 			break;
898 		case LOG_OLD:
899 			li->li_oldf = str2filter( c->argv[1] );
900 			if ( !li->li_oldf ) {
901 				snprintf( c->cr_msg, sizeof( c->cr_msg ), "bad filter!" );
902 				rc = 1;
903 			}
904 			break;
905 		case LOG_OLDATTR: {
906 			int i;
907 			AttributeDescription *ad;
908 			const char *text;
909 
910 			for ( i=1; i< c->argc; i++ ) {
911 				ad = NULL;
912 				if ( slap_str2ad( c->argv[i], &ad, &text ) == LDAP_SUCCESS ) {
913 					log_attr *la = ch_malloc( sizeof( log_attr ));
914 					la->attr = ad;
915 					la->next = li->li_oldattrs;
916 					li->li_oldattrs = la;
917 				} else {
918 					snprintf( c->cr_msg, sizeof( c->cr_msg ), "%s <%s>: %s",
919 						c->argv[0], c->argv[i], text );
920 					Debug( LDAP_DEBUG_CONFIG|LDAP_DEBUG_NONE,
921 						"%s: %s\n", c->log, c->cr_msg, 0 );
922 					rc = ARG_BAD_CONF;
923 					break;
924 				}
925 			}
926 			}
927 			break;
928 		}
929 		break;
930 	}
931 	return rc;
932 }
933 
934 static int
935 logSchemaControlValidate(
936 	Syntax		*syntax,
937 	struct berval	*valp )
938 {
939 	struct berval	val, bv;
940 	ber_len_t		i;
941 	int		rc = LDAP_SUCCESS;
942 
943 	assert( valp != NULL );
944 
945 	val = *valp;
946 
947 	/* check minimal size */
948 	if ( val.bv_len < STRLENOF( "{*}" ) ) {
949 		return LDAP_INVALID_SYNTAX;
950 	}
951 
952 	val.bv_len--;
953 
954 	/* check SEQUENCE boundaries */
955 	if ( val.bv_val[ 0 ] != '{' /*}*/ ||
956 		val.bv_val[ val.bv_len ] != /*{*/ '}' )
957 	{
958 		return LDAP_INVALID_SYNTAX;
959 	}
960 
961 	/* extract and check OID */
962 	for ( i = 1; i < val.bv_len; i++ ) {
963 		if ( !ASCII_SPACE( val.bv_val[ i ] ) ) {
964 			break;
965 		}
966 	}
967 
968 	bv.bv_val = &val.bv_val[ i ];
969 
970 	for ( i++; i < val.bv_len; i++ ) {
971 		if ( ASCII_SPACE( val.bv_val[ i ] ) )
972 		{
973 			break;
974 		}
975 	}
976 
977 	bv.bv_len = &val.bv_val[ i ] - bv.bv_val;
978 
979 	rc = numericoidValidate( NULL, &bv );
980 	if ( rc != LDAP_SUCCESS ) {
981 		return rc;
982 	}
983 
984 	if ( i == val.bv_len ) {
985 		return LDAP_SUCCESS;
986 	}
987 
988 	if ( val.bv_val[ i ] != ' ' ) {
989 		return LDAP_INVALID_SYNTAX;
990 	}
991 
992 	for ( i++; i < val.bv_len; i++ ) {
993 		if ( !ASCII_SPACE( val.bv_val[ i ] ) ) {
994 			break;
995 		}
996 	}
997 
998 	if ( i == val.bv_len ) {
999 		return LDAP_SUCCESS;
1000 	}
1001 
1002 	/* extract and check criticality */
1003 	if ( strncasecmp( &val.bv_val[ i ], "criticality ", STRLENOF( "criticality " ) ) == 0 )
1004 	{
1005 		i += STRLENOF( "criticality " );
1006 		for ( ; i < val.bv_len; i++ ) {
1007 			if ( !ASCII_SPACE( val.bv_val[ i ] ) ) {
1008 				break;
1009 			}
1010 		}
1011 
1012 		if ( i == val.bv_len ) {
1013 			return LDAP_INVALID_SYNTAX;
1014 		}
1015 
1016 		bv.bv_val = &val.bv_val[ i ];
1017 
1018 		for ( ; i < val.bv_len; i++ ) {
1019 			if ( ASCII_SPACE( val.bv_val[ i ] ) ) {
1020 				break;
1021 			}
1022 		}
1023 
1024 		bv.bv_len = &val.bv_val[ i ] - bv.bv_val;
1025 
1026 		if ( !bvmatch( &bv, &slap_true_bv ) && !bvmatch( &bv, &slap_false_bv ) )
1027 		{
1028 			return LDAP_INVALID_SYNTAX;
1029 		}
1030 
1031 		if ( i == val.bv_len ) {
1032 			return LDAP_SUCCESS;
1033 		}
1034 
1035 		if ( val.bv_val[ i ] != ' ' ) {
1036 			return LDAP_INVALID_SYNTAX;
1037 		}
1038 
1039 		for ( i++; i < val.bv_len; i++ ) {
1040 			if ( !ASCII_SPACE( val.bv_val[ i ] ) ) {
1041 				break;
1042 			}
1043 		}
1044 
1045 		if ( i == val.bv_len ) {
1046 			return LDAP_SUCCESS;
1047 		}
1048 	}
1049 
1050 	/* extract and check controlValue */
1051 	if ( strncasecmp( &val.bv_val[ i ], "controlValue ", STRLENOF( "controlValue " ) ) == 0 )
1052 	{
1053 		i += STRLENOF( "controlValue " );
1054 		for ( ; i < val.bv_len; i++ ) {
1055 			if ( !ASCII_SPACE( val.bv_val[ i ] ) ) {
1056 				break;
1057 			}
1058 		}
1059 
1060 		if ( i == val.bv_len ) {
1061 			return LDAP_INVALID_SYNTAX;
1062 		}
1063 
1064 		if ( val.bv_val[ i ] != '"' ) {
1065 			return LDAP_INVALID_SYNTAX;
1066 		}
1067 
1068 		for ( ; i < val.bv_len; i++ ) {
1069 			if ( val.bv_val[ i ] == '"' ) {
1070 				break;
1071 			}
1072 
1073 			if ( !ASCII_HEX( val.bv_val[ i ] ) ) {
1074 				return LDAP_INVALID_SYNTAX;
1075 			}
1076 		}
1077 
1078 		if ( val.bv_val[ i ] != '"' ) {
1079 			return LDAP_INVALID_SYNTAX;
1080 		}
1081 
1082 		for ( ; i < val.bv_len; i++ ) {
1083 			if ( !ASCII_SPACE( val.bv_val[ i ] ) ) {
1084 				break;
1085 			}
1086 		}
1087 
1088 		if ( i == val.bv_len ) {
1089 			return LDAP_SUCCESS;
1090 		}
1091 	}
1092 
1093 	return LDAP_INVALID_SYNTAX;
1094 }
1095 
1096 static int
1097 accesslog_ctrls(
1098 	LDAPControl **ctrls,
1099 	BerVarray *valsp,
1100 	BerVarray *nvalsp,
1101 	void *memctx )
1102 {
1103 	long		i, rc = 0;
1104 
1105 	assert( valsp != NULL );
1106 	assert( ctrls != NULL );
1107 
1108 	*valsp = NULL;
1109 	*nvalsp = NULL;
1110 
1111 	for ( i = 0; ctrls[ i ] != NULL; i++ ) {
1112 		struct berval	idx,
1113 				oid,
1114 				noid,
1115 				bv;
1116 		char		*ptr,
1117 				buf[ 32 ];
1118 
1119 		if ( ctrls[ i ]->ldctl_oid == NULL ) {
1120 			return LDAP_PROTOCOL_ERROR;
1121 		}
1122 
1123 		idx.bv_len = snprintf( buf, sizeof( buf ), "{%ld}", i );
1124 		idx.bv_val = buf;
1125 
1126 		ber_str2bv( ctrls[ i ]->ldctl_oid, 0, 0, &oid );
1127 		noid.bv_len = idx.bv_len + oid.bv_len;
1128 		ptr = noid.bv_val = ber_memalloc_x( noid.bv_len + 1, memctx );
1129 		ptr = lutil_strcopy( ptr, idx.bv_val );
1130 		ptr = lutil_strcopy( ptr, oid.bv_val );
1131 
1132 		bv.bv_len = idx.bv_len + STRLENOF( "{}" ) + oid.bv_len;
1133 
1134 		if ( ctrls[ i ]->ldctl_iscritical ) {
1135 			bv.bv_len += STRLENOF( " criticality TRUE" );
1136 		}
1137 
1138 		if ( !BER_BVISNULL( &ctrls[ i ]->ldctl_value ) ) {
1139 			bv.bv_len += STRLENOF( " controlValue \"\"" )
1140 				+ 2 * ctrls[ i ]->ldctl_value.bv_len;
1141 		}
1142 
1143 		ptr = bv.bv_val = ber_memalloc_x( bv.bv_len + 1, memctx );
1144 		if ( ptr == NULL ) {
1145 			ber_bvarray_free( *valsp );
1146 			*valsp = NULL;
1147 			ber_bvarray_free( *nvalsp );
1148 			*nvalsp = NULL;
1149 			return LDAP_OTHER;
1150 		}
1151 
1152 		ptr = lutil_strcopy( ptr, idx.bv_val );
1153 
1154 		*ptr++ = '{' /*}*/ ;
1155 		ptr = lutil_strcopy( ptr, oid.bv_val );
1156 
1157 		if ( ctrls[ i ]->ldctl_iscritical ) {
1158 			ptr = lutil_strcopy( ptr, " criticality TRUE" );
1159 		}
1160 
1161 		if ( !BER_BVISNULL( &ctrls[ i ]->ldctl_value ) ) {
1162 			ber_len_t	j;
1163 
1164 			ptr = lutil_strcopy( ptr, " controlValue \"" );
1165 			for ( j = 0; j < ctrls[ i ]->ldctl_value.bv_len; j++ )
1166 			{
1167 				unsigned char	o;
1168 
1169 				o = ( ( ctrls[ i ]->ldctl_value.bv_val[ j ] >> 4 ) & 0xF );
1170 				if ( o < 10 ) {
1171 					*ptr++ = '0' + o;
1172 
1173 				} else {
1174 					*ptr++ = 'A' + o;
1175 				}
1176 
1177 				o = ( ctrls[ i ]->ldctl_value.bv_val[ j ] & 0xF );
1178 				if ( o < 10 ) {
1179 					*ptr++ = '0' + o;
1180 
1181 				} else {
1182 					*ptr++ = 'A' + o;
1183 				}
1184 			}
1185 
1186 			*ptr++ = '"';
1187 		}
1188 
1189 		*ptr++ = '}';
1190 		*ptr = '\0';
1191 
1192 		ber_bvarray_add_x( valsp, &bv, memctx );
1193 		ber_bvarray_add_x( nvalsp, &noid, memctx );
1194 	}
1195 
1196 	return rc;
1197 
1198 }
1199 
1200 static Entry *accesslog_entry( Operation *op, SlapReply *rs, int logop,
1201 	Operation *op2 ) {
1202 	slap_overinst *on = (slap_overinst *)op->o_bd->bd_info;
1203 	log_info *li = on->on_bi.bi_private;
1204 
1205 	char rdnbuf[STRLENOF(RDNEQ)+LDAP_LUTIL_GENTIME_BUFSIZE+8];
1206 	char nrdnbuf[STRLENOF(RDNEQ)+LDAP_LUTIL_GENTIME_BUFSIZE+8];
1207 
1208 	struct berval rdn, nrdn, timestamp, ntimestamp, bv;
1209 	slap_verbmasks *lo = logops+logop+EN_OFFSET;
1210 
1211 	Entry *e = entry_alloc();
1212 
1213 	strcpy( rdnbuf, RDNEQ );
1214 	rdn.bv_val = rdnbuf;
1215 	strcpy( nrdnbuf, RDNEQ );
1216 	nrdn.bv_val = nrdnbuf;
1217 
1218 	timestamp.bv_val = rdnbuf+STRLENOF(RDNEQ);
1219 	timestamp.bv_len = sizeof(rdnbuf) - STRLENOF(RDNEQ);
1220 	slap_timestamp( &op->o_time, &timestamp );
1221 	snprintf( timestamp.bv_val + timestamp.bv_len-1, sizeof(".123456Z"), ".%06dZ", op->o_tincr );
1222 	timestamp.bv_len += STRLENOF(".123456");
1223 
1224 	rdn.bv_len = STRLENOF(RDNEQ)+timestamp.bv_len;
1225 	ad_reqStart->ad_type->sat_equality->smr_normalize(
1226 		SLAP_MR_VALUE_OF_ASSERTION_SYNTAX, ad_reqStart->ad_type->sat_syntax,
1227 		ad_reqStart->ad_type->sat_equality, &timestamp, &ntimestamp,
1228 		op->o_tmpmemctx );
1229 
1230 	strcpy( nrdn.bv_val + STRLENOF(RDNEQ), ntimestamp.bv_val );
1231 	nrdn.bv_len = STRLENOF(RDNEQ)+ntimestamp.bv_len;
1232 	build_new_dn( &e->e_name, li->li_db->be_suffix, &rdn, NULL );
1233 	build_new_dn( &e->e_nname, li->li_db->be_nsuffix, &nrdn, NULL );
1234 
1235 	attr_merge_one( e, slap_schema.si_ad_objectClass,
1236 		&log_ocs[logop]->soc_cname, NULL );
1237 	attr_merge_one( e, slap_schema.si_ad_structuralObjectClass,
1238 		&log_ocs[logop]->soc_cname, NULL );
1239 	attr_merge_one( e, ad_reqStart, &timestamp, &ntimestamp );
1240 	op->o_tmpfree( ntimestamp.bv_val, op->o_tmpmemctx );
1241 
1242 	slap_op_time( &op2->o_time, &op2->o_tincr );
1243 
1244 	timestamp.bv_len = sizeof(rdnbuf) - STRLENOF(RDNEQ);
1245 	slap_timestamp( &op2->o_time, &timestamp );
1246 	snprintf( timestamp.bv_val + timestamp.bv_len-1, sizeof(".123456Z"), ".%06dZ", op2->o_tincr );
1247 	timestamp.bv_len += STRLENOF(".123456");
1248 
1249 	attr_merge_normalize_one( e, ad_reqEnd, &timestamp, op->o_tmpmemctx );
1250 
1251 	/* Exops have OID appended */
1252 	if ( logop == LOG_EN_EXTENDED ) {
1253 		bv.bv_len = lo->word.bv_len + op->ore_reqoid.bv_len + 2;
1254 		bv.bv_val = ch_malloc( bv.bv_len + 1 );
1255 		AC_MEMCPY( bv.bv_val, lo->word.bv_val, lo->word.bv_len );
1256 		bv.bv_val[lo->word.bv_len] = '{';
1257 		AC_MEMCPY( bv.bv_val+lo->word.bv_len+1, op->ore_reqoid.bv_val,
1258 			op->ore_reqoid.bv_len );
1259 		bv.bv_val[bv.bv_len-1] = '}';
1260 		bv.bv_val[bv.bv_len] = '\0';
1261 		attr_merge_one( e, ad_reqType, &bv, NULL );
1262 	} else {
1263 		attr_merge_one( e, ad_reqType, &lo->word, NULL );
1264 	}
1265 
1266 	rdn.bv_len = snprintf( rdn.bv_val, sizeof( rdnbuf ), "%lu", op->o_connid );
1267 	if ( rdn.bv_len < sizeof( rdnbuf ) ) {
1268 		attr_merge_one( e, ad_reqSession, &rdn, NULL );
1269 	} /* else? */
1270 
1271 	if ( BER_BVISNULL( &op->o_dn ) ) {
1272 		attr_merge_one( e, ad_reqAuthzID, (struct berval *)&slap_empty_bv,
1273 			(struct berval *)&slap_empty_bv );
1274 	} else {
1275 		attr_merge_one( e, ad_reqAuthzID, &op->o_dn, &op->o_ndn );
1276 	}
1277 
1278 	/* FIXME: need to add reqControls and reqRespControls */
1279 	if ( op->o_ctrls ) {
1280 		BerVarray	vals = NULL,
1281 				nvals = NULL;
1282 
1283 		if ( accesslog_ctrls( op->o_ctrls, &vals, &nvals,
1284 			op->o_tmpmemctx ) == LDAP_SUCCESS && vals )
1285 		{
1286 			attr_merge( e, ad_reqControls, vals, nvals );
1287 			ber_bvarray_free_x( vals, op->o_tmpmemctx );
1288 			ber_bvarray_free_x( nvals, op->o_tmpmemctx );
1289 		}
1290 	}
1291 
1292 	if ( rs->sr_ctrls ) {
1293 		BerVarray	vals = NULL,
1294 				nvals = NULL;
1295 
1296 		if ( accesslog_ctrls( rs->sr_ctrls, &vals, &nvals,
1297 			op->o_tmpmemctx ) == LDAP_SUCCESS && vals )
1298 		{
1299 			attr_merge( e, ad_reqRespControls, vals, nvals );
1300 			ber_bvarray_free_x( vals, op->o_tmpmemctx );
1301 			ber_bvarray_free_x( nvals, op->o_tmpmemctx );
1302 		}
1303 
1304 	}
1305 
1306 	return e;
1307 }
1308 
1309 static struct berval scopes[] = {
1310 	BER_BVC("base"),
1311 	BER_BVC("one"),
1312 	BER_BVC("sub"),
1313 	BER_BVC("subord")
1314 };
1315 
1316 static struct berval derefs[] = {
1317 	BER_BVC("never"),
1318 	BER_BVC("searching"),
1319 	BER_BVC("finding"),
1320 	BER_BVC("always")
1321 };
1322 
1323 static struct berval simple = BER_BVC("SIMPLE");
1324 
1325 static void accesslog_val2val(AttributeDescription *ad, struct berval *val,
1326 	char c_op, struct berval *dst) {
1327 	char *ptr;
1328 
1329 	dst->bv_len = ad->ad_cname.bv_len + val->bv_len + 2;
1330 	if ( c_op ) dst->bv_len++;
1331 
1332 	dst->bv_val = ch_malloc( dst->bv_len+1 );
1333 
1334 	ptr = lutil_strcopy( dst->bv_val, ad->ad_cname.bv_val );
1335 	*ptr++ = ':';
1336 	if ( c_op )
1337 		*ptr++ = c_op;
1338 	*ptr++ = ' ';
1339 	AC_MEMCPY( ptr, val->bv_val, val->bv_len );
1340 	dst->bv_val[dst->bv_len] = '\0';
1341 }
1342 
1343 static int accesslog_response(Operation *op, SlapReply *rs) {
1344 	slap_overinst *on = (slap_overinst *)op->o_bd->bd_info;
1345 	log_info *li = on->on_bi.bi_private;
1346 	Attribute *a, *last_attr;
1347 	Modifications *m;
1348 	struct berval *b;
1349 	int i;
1350 	int logop;
1351 	slap_verbmasks *lo;
1352 	Entry *e = NULL, *old = NULL;
1353 	char timebuf[LDAP_LUTIL_GENTIME_BUFSIZE+8];
1354 	struct berval bv;
1355 	char *ptr;
1356 	BerVarray vals;
1357 	Operation op2 = {0};
1358 	SlapReply rs2 = {REP_RESULT};
1359 
1360 	if ( rs->sr_type != REP_RESULT && rs->sr_type != REP_EXTENDED )
1361 		return SLAP_CB_CONTINUE;
1362 
1363 	switch ( op->o_tag ) {
1364 	case LDAP_REQ_ADD:		logop = LOG_EN_ADD; break;
1365 	case LDAP_REQ_DELETE:	logop = LOG_EN_DELETE; break;
1366 	case LDAP_REQ_MODIFY:	logop = LOG_EN_MODIFY; break;
1367 	case LDAP_REQ_MODRDN:	logop = LOG_EN_MODRDN; break;
1368 	case LDAP_REQ_COMPARE:	logop = LOG_EN_COMPARE; break;
1369 	case LDAP_REQ_SEARCH:	logop = LOG_EN_SEARCH; break;
1370 	case LDAP_REQ_BIND:		logop = LOG_EN_BIND; break;
1371 	case LDAP_REQ_EXTENDED:	logop = LOG_EN_EXTENDED; break;
1372 	default:	/* unknown operation type */
1373 		logop = LOG_EN_UNKNOWN; break;
1374 	}	/* Unbind and Abandon never reach here */
1375 
1376 	lo = logops+logop+EN_OFFSET;
1377 	if ( !( li->li_ops & lo->mask ))
1378 		return SLAP_CB_CONTINUE;
1379 
1380 	if ( lo->mask & LOG_OP_WRITES ) {
1381 		slap_callback *cb;
1382 		ldap_pvt_thread_mutex_lock( &li->li_log_mutex );
1383 		old = li->li_old;
1384 		li->li_old = NULL;
1385 		/* Disarm mod_cleanup */
1386 		for ( cb = op->o_callback; cb; cb = cb->sc_next ) {
1387 			if ( cb->sc_private == (void *)on ) {
1388 				cb->sc_private = NULL;
1389 				break;
1390 			}
1391 		}
1392 		ldap_pvt_thread_rmutex_unlock( &li->li_op_rmutex, op->o_tid );
1393 	}
1394 
1395 	if ( li->li_success && rs->sr_err != LDAP_SUCCESS )
1396 		goto done;
1397 
1398 	e = accesslog_entry( op, rs, logop, &op2 );
1399 
1400 	attr_merge_one( e, ad_reqDN, &op->o_req_dn, &op->o_req_ndn );
1401 
1402 	if ( rs->sr_text ) {
1403 		ber_str2bv( rs->sr_text, 0, 0, &bv );
1404 		attr_merge_one( e, ad_reqMessage, &bv, NULL );
1405 	}
1406 	bv.bv_len = snprintf( timebuf, sizeof( timebuf ), "%d", rs->sr_err );
1407 	if ( bv.bv_len < sizeof( timebuf ) ) {
1408 		bv.bv_val = timebuf;
1409 		attr_merge_one( e, ad_reqResult, &bv, NULL );
1410 	}
1411 
1412 	last_attr = attr_find( e->e_attrs, ad_reqResult );
1413 
1414 	switch( logop ) {
1415 	case LOG_EN_ADD:
1416 	case LOG_EN_DELETE: {
1417 		char c_op;
1418 		Entry *e2;
1419 
1420 		if ( logop == LOG_EN_ADD ) {
1421 			e2 = op->ora_e;
1422 			c_op = '+';
1423 		} else {
1424 			if ( !old )
1425 				break;
1426 			e2 = old;
1427 			c_op = 0;
1428 		}
1429 		/* count all the vals */
1430 		i = 0;
1431 		for ( a=e2->e_attrs; a; a=a->a_next ) {
1432 			i += a->a_numvals;
1433 		}
1434 		vals = ch_malloc( (i+1) * sizeof( struct berval ));
1435 		i = 0;
1436 		for ( a=e2->e_attrs; a; a=a->a_next ) {
1437 			if ( a->a_vals ) {
1438 				for (b=a->a_vals; !BER_BVISNULL( b ); b++,i++) {
1439 					accesslog_val2val( a->a_desc, b, c_op, &vals[i] );
1440 				}
1441 			}
1442 		}
1443 		vals[i].bv_val = NULL;
1444 		vals[i].bv_len = 0;
1445 		a = attr_alloc( logop == LOG_EN_ADD ? ad_reqMod : ad_reqOld );
1446 		a->a_numvals = i;
1447 		a->a_vals = vals;
1448 		a->a_nvals = vals;
1449 		last_attr->a_next = a;
1450 		break;
1451 	}
1452 
1453 	case LOG_EN_MODRDN:
1454 	case LOG_EN_MODIFY:
1455 		/* count all the mods */
1456 		i = 0;
1457 		for ( m = op->orm_modlist; m; m = m->sml_next ) {
1458 			if ( m->sml_values ) {
1459 				i += m->sml_numvals;
1460 			} else if ( m->sml_op == LDAP_MOD_DELETE ||
1461 				m->sml_op == LDAP_MOD_REPLACE )
1462 			{
1463 				i++;
1464 			}
1465 		}
1466 		vals = ch_malloc( (i+1) * sizeof( struct berval ));
1467 		i = 0;
1468 
1469 		/* init flags on old entry */
1470 		if ( old ) {
1471 			for ( a = old->e_attrs; a; a = a->a_next ) {
1472 				log_attr *la;
1473 				a->a_flags = 0;
1474 
1475 				/* look for attrs that are always logged */
1476 				for ( la = li->li_oldattrs; la; la = la->next ) {
1477 					if ( a->a_desc == la->attr ) {
1478 						a->a_flags = 1;
1479 					}
1480 				}
1481 			}
1482 		}
1483 
1484 		for ( m = op->orm_modlist; m; m = m->sml_next ) {
1485 			/* Mark this attribute as modified */
1486 			if ( old ) {
1487 				a = attr_find( old->e_attrs, m->sml_desc );
1488 				if ( a ) {
1489 					a->a_flags = 1;
1490 				}
1491 			}
1492 
1493 			/* don't log the RDN mods; they're explicitly logged later */
1494 			if ( logop == LOG_EN_MODRDN &&
1495 			 	( m->sml_op == SLAP_MOD_SOFTADD ||
1496 				  m->sml_op == LDAP_MOD_DELETE ) )
1497 			{
1498 				continue;
1499 			}
1500 
1501 			if ( m->sml_values ) {
1502 				for ( b = m->sml_values; !BER_BVISNULL( b ); b++, i++ ) {
1503 					char c_op;
1504 
1505 					switch ( m->sml_op ) {
1506 					case LDAP_MOD_ADD: c_op = '+'; break;
1507 					case LDAP_MOD_DELETE:	c_op = '-'; break;
1508 					case LDAP_MOD_REPLACE:	c_op = '='; break;
1509 					case LDAP_MOD_INCREMENT:	c_op = '#'; break;
1510 
1511 					/* unknown op. there shouldn't be any of these. we
1512 					 * don't know what to do with it, but we shouldn't just
1513 					 * ignore it.
1514 					 */
1515 					default: c_op = '?'; break;
1516 					}
1517 					accesslog_val2val( m->sml_desc, b, c_op, &vals[i] );
1518 				}
1519 			} else if ( m->sml_op == LDAP_MOD_DELETE ||
1520 				m->sml_op == LDAP_MOD_REPLACE )
1521 			{
1522 				vals[i].bv_len = m->sml_desc->ad_cname.bv_len + 2;
1523 				vals[i].bv_val = ch_malloc( vals[i].bv_len + 1 );
1524 				ptr = lutil_strcopy( vals[i].bv_val,
1525 					m->sml_desc->ad_cname.bv_val );
1526 				*ptr++ = ':';
1527 				if ( m->sml_op == LDAP_MOD_DELETE ) {
1528 					*ptr++ = '-';
1529 				} else {
1530 					*ptr++ = '=';
1531 				}
1532 				*ptr = '\0';
1533 				i++;
1534 			}
1535 		}
1536 
1537 		if ( i > 0 ) {
1538 			BER_BVZERO( &vals[i] );
1539 			a = attr_alloc( ad_reqMod );
1540 			a->a_numvals = i;
1541 			a->a_vals = vals;
1542 			a->a_nvals = vals;
1543 			last_attr->a_next = a;
1544 			last_attr = a;
1545 
1546 		} else {
1547 			ch_free( vals );
1548 		}
1549 
1550 		if ( old ) {
1551 			/* count all the vals */
1552 			i = 0;
1553 			for ( a = old->e_attrs; a != NULL; a = a->a_next ) {
1554 				if ( a->a_vals && a->a_flags ) {
1555 					i += a->a_numvals;
1556 				}
1557 			}
1558 			if ( i ) {
1559 				vals = ch_malloc( (i + 1) * sizeof( struct berval ) );
1560 				i = 0;
1561 				for ( a=old->e_attrs; a; a=a->a_next ) {
1562 					if ( a->a_vals && a->a_flags ) {
1563 						for (b=a->a_vals; !BER_BVISNULL( b ); b++,i++) {
1564 							accesslog_val2val( a->a_desc, b, 0, &vals[i] );
1565 						}
1566 					}
1567 				}
1568 				vals[i].bv_val = NULL;
1569 				vals[i].bv_len = 0;
1570 				a = attr_alloc( ad_reqOld );
1571 				a->a_numvals = i;
1572 				a->a_vals = vals;
1573 				a->a_nvals = vals;
1574 				last_attr->a_next = a;
1575 			}
1576 		}
1577 		if ( logop == LOG_EN_MODIFY ) {
1578 			break;
1579 		}
1580 
1581 		/* Now log the actual modRDN info */
1582 		attr_merge_one( e, ad_reqNewRDN, &op->orr_newrdn, &op->orr_nnewrdn );
1583 		attr_merge_one( e, ad_reqDeleteOldRDN, op->orr_deleteoldrdn ?
1584 			(struct berval *)&slap_true_bv : (struct berval *)&slap_false_bv,
1585 			NULL );
1586 		if ( op->orr_newSup ) {
1587 			attr_merge_one( e, ad_reqNewSuperior, op->orr_newSup, op->orr_nnewSup );
1588 		}
1589 		break;
1590 
1591 	case LOG_EN_COMPARE:
1592 		bv.bv_len = op->orc_ava->aa_desc->ad_cname.bv_len + 1 +
1593 			op->orc_ava->aa_value.bv_len;
1594 		bv.bv_val = op->o_tmpalloc( bv.bv_len+1, op->o_tmpmemctx );
1595 		ptr = lutil_strcopy( bv.bv_val, op->orc_ava->aa_desc->ad_cname.bv_val );
1596 		*ptr++ = '=';
1597 		AC_MEMCPY( ptr, op->orc_ava->aa_value.bv_val, op->orc_ava->aa_value.bv_len );
1598 		bv.bv_val[bv.bv_len] = '\0';
1599 		attr_merge_one( e, ad_reqAssertion, &bv, NULL );
1600 		op->o_tmpfree( bv.bv_val, op->o_tmpmemctx );
1601 		break;
1602 
1603 	case LOG_EN_SEARCH:
1604 		attr_merge_one( e, ad_reqScope, &scopes[op->ors_scope], NULL );
1605 		attr_merge_one( e, ad_reqDerefAliases, &derefs[op->ors_deref], NULL );
1606 		attr_merge_one( e, ad_reqAttrsOnly, op->ors_attrsonly ?
1607 			(struct berval *)&slap_true_bv : (struct berval *)&slap_false_bv,
1608 			NULL );
1609 		if ( !BER_BVISEMPTY( &op->ors_filterstr ))
1610 			attr_merge_one( e, ad_reqFilter, &op->ors_filterstr, NULL );
1611 		if ( op->ors_attrs ) {
1612 			/* count them */
1613 			for (i=0; !BER_BVISNULL(&op->ors_attrs[i].an_name );i++)
1614 				;
1615 			vals = op->o_tmpalloc( (i+1) * sizeof(struct berval),
1616 				op->o_tmpmemctx );
1617 			for (i=0; !BER_BVISNULL(&op->ors_attrs[i].an_name );i++)
1618 				vals[i] = op->ors_attrs[i].an_name;
1619 			vals[i].bv_val = NULL;
1620 			vals[i].bv_len = 0;
1621 			attr_merge( e, ad_reqAttr, vals, NULL );
1622 			op->o_tmpfree( vals, op->o_tmpmemctx );
1623 		}
1624 		bv.bv_val = timebuf;
1625 		bv.bv_len = snprintf( bv.bv_val, sizeof( timebuf ), "%d", rs->sr_nentries );
1626 		if ( bv.bv_len < sizeof( timebuf ) ) {
1627 			attr_merge_one( e, ad_reqEntries, &bv, NULL );
1628 		} /* else? */
1629 
1630 		bv.bv_len = snprintf( bv.bv_val, sizeof( timebuf ), "%d", op->ors_tlimit );
1631 		if ( bv.bv_len < sizeof( timebuf ) ) {
1632 			attr_merge_one( e, ad_reqTimeLimit, &bv, NULL );
1633 		} /* else? */
1634 
1635 		bv.bv_len = snprintf( bv.bv_val, sizeof( timebuf ), "%d", op->ors_slimit );
1636 		if ( bv.bv_len < sizeof( timebuf ) ) {
1637 			attr_merge_one( e, ad_reqSizeLimit, &bv, NULL );
1638 		} /* else? */
1639 		break;
1640 
1641 	case LOG_EN_BIND:
1642 		bv.bv_val = timebuf;
1643 		bv.bv_len = snprintf( bv.bv_val, sizeof( timebuf ), "%d", op->o_protocol );
1644 		if ( bv.bv_len < sizeof( timebuf ) ) {
1645 			attr_merge_one( e, ad_reqVersion, &bv, NULL );
1646 		} /* else? */
1647 		if ( op->orb_method == LDAP_AUTH_SIMPLE ) {
1648 			attr_merge_one( e, ad_reqMethod, &simple, NULL );
1649 		} else {
1650 			bv.bv_len = STRLENOF("SASL()") + op->orb_mech.bv_len;
1651 			bv.bv_val = op->o_tmpalloc( bv.bv_len + 1, op->o_tmpmemctx );
1652 			ptr = lutil_strcopy( bv.bv_val, "SASL(" );
1653 			ptr = lutil_strcopy( ptr, op->orb_mech.bv_val );
1654 			*ptr++ = ')';
1655 			*ptr = '\0';
1656 			attr_merge_one( e, ad_reqMethod, &bv, NULL );
1657 			op->o_tmpfree( bv.bv_val, op->o_tmpmemctx );
1658 		}
1659 
1660 		break;
1661 
1662 	case LOG_EN_EXTENDED:
1663 		if ( op->ore_reqdata ) {
1664 			attr_merge_one( e, ad_reqData, op->ore_reqdata, NULL );
1665 		}
1666 		break;
1667 
1668 	case LOG_EN_UNKNOWN:
1669 		/* we don't know its parameters, don't add any */
1670 		break;
1671 	}
1672 
1673 	op2.o_hdr = op->o_hdr;
1674 	op2.o_tag = LDAP_REQ_ADD;
1675 	op2.o_bd = li->li_db;
1676 	op2.o_dn = li->li_db->be_rootdn;
1677 	op2.o_ndn = li->li_db->be_rootndn;
1678 	op2.o_req_dn = e->e_name;
1679 	op2.o_req_ndn = e->e_nname;
1680 	op2.ora_e = e;
1681 	op2.o_callback = &nullsc;
1682 
1683 	if (( lo->mask & LOG_OP_WRITES ) && !BER_BVISEMPTY( &op->o_csn )) {
1684 		slap_queue_csn( &op2, &op->o_csn );
1685 	}
1686 
1687 	op2.o_bd->be_add( &op2, &rs2 );
1688 	if ( e == op2.ora_e ) entry_free( e );
1689 	e = NULL;
1690 
1691 done:
1692 	if ( lo->mask & LOG_OP_WRITES )
1693 		ldap_pvt_thread_mutex_unlock( &li->li_log_mutex );
1694 	if ( old ) entry_free( old );
1695 	return SLAP_CB_CONTINUE;
1696 }
1697 
1698 /* Since Bind success is sent by the frontend, it won't normally enter
1699  * the overlay response callback. Add another callback to make sure it
1700  * gets here.
1701  */
1702 static int
1703 accesslog_bind_resp( Operation *op, SlapReply *rs )
1704 {
1705 	BackendDB *be, db;
1706 	int rc;
1707 	slap_callback *sc;
1708 
1709 	be = op->o_bd;
1710 	db = *be;
1711 	op->o_bd = &db;
1712 	db.bd_info = op->o_callback->sc_private;
1713 	rc = accesslog_response( op, rs );
1714 	op->o_bd = be;
1715 	sc = op->o_callback;
1716 	op->o_callback = sc->sc_next;
1717 	op->o_tmpfree( sc, op->o_tmpmemctx );
1718 	return rc;
1719 }
1720 
1721 static int
1722 accesslog_op_bind( Operation *op, SlapReply *rs )
1723 {
1724 	slap_callback *sc;
1725 
1726 	sc = op->o_tmpcalloc( 1, sizeof(slap_callback), op->o_tmpmemctx );
1727 	sc->sc_response = accesslog_bind_resp;
1728 	sc->sc_private = op->o_bd->bd_info;
1729 
1730 	if ( op->o_callback ) {
1731 		sc->sc_next = op->o_callback->sc_next;
1732 		op->o_callback->sc_next = sc;
1733 	} else {
1734 		op->o_callback = sc;
1735 	}
1736 	return SLAP_CB_CONTINUE;
1737 }
1738 
1739 static int
1740 accesslog_mod_cleanup( Operation *op, SlapReply *rs )
1741 {
1742 	slap_callback *sc = op->o_callback;
1743 	slap_overinst *on = sc->sc_private;
1744 	op->o_callback = sc->sc_next;
1745 
1746 	op->o_tmpfree( sc, op->o_tmpmemctx );
1747 
1748 	if ( on ) {
1749 		BackendInfo *bi = op->o_bd->bd_info;
1750 		op->o_bd->bd_info = (BackendInfo *)on;
1751 		accesslog_response( op, rs );
1752 		op->o_bd->bd_info = bi;
1753 	}
1754 	return 0;
1755 }
1756 
1757 static int
1758 accesslog_op_mod( Operation *op, SlapReply *rs )
1759 {
1760 	slap_overinst *on = (slap_overinst *)op->o_bd->bd_info;
1761 	log_info *li = on->on_bi.bi_private;
1762 
1763 	if ( li->li_ops & LOG_OP_WRITES ) {
1764 		slap_callback *cb = op->o_tmpalloc( sizeof( slap_callback ), op->o_tmpmemctx ), *cb2;
1765 		cb->sc_cleanup = accesslog_mod_cleanup;
1766 		cb->sc_response = NULL;
1767 		cb->sc_private = on;
1768 		cb->sc_next = NULL;
1769 		for ( cb2 = op->o_callback; cb2->sc_next; cb2 = cb2->sc_next );
1770 		cb2->sc_next = cb;
1771 
1772 		ldap_pvt_thread_rmutex_lock( &li->li_op_rmutex, op->o_tid );
1773 		if ( li->li_oldf && ( op->o_tag == LDAP_REQ_DELETE ||
1774 			op->o_tag == LDAP_REQ_MODIFY ||
1775 			( op->o_tag == LDAP_REQ_MODRDN && li->li_oldattrs ))) {
1776 			int rc;
1777 			Entry *e;
1778 
1779 			op->o_bd->bd_info = (BackendInfo *)on->on_info;
1780 			rc = be_entry_get_rw( op, &op->o_req_ndn, NULL, NULL, 0, &e );
1781 			if ( e ) {
1782 				if ( test_filter( op, e, li->li_oldf ) == LDAP_COMPARE_TRUE )
1783 					li->li_old = entry_dup( e );
1784 				be_entry_release_rw( op, e, 0 );
1785 			}
1786 			op->o_bd->bd_info = (BackendInfo *)on;
1787 		}
1788 	}
1789 	return SLAP_CB_CONTINUE;
1790 }
1791 
1792 /* unbinds are broadcast to all backends; we only log it if this
1793  * backend was used for the original bind.
1794  */
1795 static int
1796 accesslog_unbind( Operation *op, SlapReply *rs )
1797 {
1798 	slap_overinst *on = (slap_overinst *)op->o_bd->bd_info;
1799 	if ( op->o_conn->c_authz_backend == on->on_info->oi_origdb ) {
1800 		log_info *li = on->on_bi.bi_private;
1801 		Operation op2 = {0};
1802 		void *cids[SLAP_MAX_CIDS];
1803 		SlapReply rs2 = {REP_RESULT};
1804 		Entry *e;
1805 
1806 		if ( !( li->li_ops & LOG_OP_UNBIND ))
1807 			return SLAP_CB_CONTINUE;
1808 
1809 		e = accesslog_entry( op, rs, LOG_EN_UNBIND, &op2 );
1810 		op2.o_hdr = op->o_hdr;
1811 		op2.o_tag = LDAP_REQ_ADD;
1812 		op2.o_bd = li->li_db;
1813 		op2.o_dn = li->li_db->be_rootdn;
1814 		op2.o_ndn = li->li_db->be_rootndn;
1815 		op2.o_req_dn = e->e_name;
1816 		op2.o_req_ndn = e->e_nname;
1817 		op2.ora_e = e;
1818 		op2.o_callback = &nullsc;
1819 		op2.o_controls = cids;
1820 		memset(cids, 0, sizeof( cids ));
1821 
1822 		op2.o_bd->be_add( &op2, &rs2 );
1823 		if ( e == op2.ora_e )
1824 			entry_free( e );
1825 	}
1826 	return SLAP_CB_CONTINUE;
1827 }
1828 
1829 static int
1830 accesslog_abandon( Operation *op, SlapReply *rs )
1831 {
1832 	slap_overinst *on = (slap_overinst *)op->o_bd->bd_info;
1833 	log_info *li = on->on_bi.bi_private;
1834 	Operation op2 = {0};
1835 	void *cids[SLAP_MAX_CIDS];
1836 	SlapReply rs2 = {REP_RESULT};
1837 	Entry *e;
1838 	char buf[64];
1839 	struct berval bv;
1840 
1841 	if ( !op->o_time || !( li->li_ops & LOG_OP_ABANDON ))
1842 		return SLAP_CB_CONTINUE;
1843 
1844 	e = accesslog_entry( op, rs, LOG_EN_ABANDON, &op2 );
1845 	bv.bv_val = buf;
1846 	bv.bv_len = snprintf( buf, sizeof( buf ), "%d", op->orn_msgid );
1847 	if ( bv.bv_len < sizeof( buf ) ) {
1848 		attr_merge_one( e, ad_reqId, &bv, NULL );
1849 	} /* else? */
1850 
1851 	op2.o_hdr = op->o_hdr;
1852 	op2.o_tag = LDAP_REQ_ADD;
1853 	op2.o_bd = li->li_db;
1854 	op2.o_dn = li->li_db->be_rootdn;
1855 	op2.o_ndn = li->li_db->be_rootndn;
1856 	op2.o_req_dn = e->e_name;
1857 	op2.o_req_ndn = e->e_nname;
1858 	op2.ora_e = e;
1859 	op2.o_callback = &nullsc;
1860 	op2.o_controls = cids;
1861 	memset(cids, 0, sizeof( cids ));
1862 
1863 	op2.o_bd->be_add( &op2, &rs2 );
1864 	if ( e == op2.ora_e )
1865 		entry_free( e );
1866 
1867 	return SLAP_CB_CONTINUE;
1868 }
1869 
1870 static int
1871 accesslog_operational( Operation *op, SlapReply *rs )
1872 {
1873 	slap_overinst *on = (slap_overinst *)op->o_bd->bd_info;
1874 	log_info *li = on->on_bi.bi_private;
1875 
1876 	if ( op->o_sync != SLAP_CONTROL_NONE )
1877 		return SLAP_CB_CONTINUE;
1878 
1879 	if ( rs->sr_entry != NULL
1880 		&& dn_match( &op->o_bd->be_nsuffix[0], &rs->sr_entry->e_nname ) )
1881 	{
1882 		Attribute	**ap;
1883 
1884 		for ( ap = &rs->sr_operational_attrs; *ap; ap = &(*ap)->a_next )
1885 			/* just count */ ;
1886 
1887 		if ( SLAP_OPATTRS( rs->sr_attr_flags ) ||
1888 				ad_inlist( ad_auditContext, rs->sr_attrs ) )
1889 		{
1890 			*ap = attr_alloc( ad_auditContext );
1891 			attr_valadd( *ap,
1892 				&li->li_db->be_suffix[0],
1893 				&li->li_db->be_nsuffix[0], 1 );
1894 		}
1895 	}
1896 
1897 	return SLAP_CB_CONTINUE;
1898 }
1899 
1900 static slap_overinst accesslog;
1901 
1902 static int
1903 accesslog_db_init(
1904 	BackendDB *be,
1905 	ConfigReply *cr
1906 )
1907 {
1908 	slap_overinst *on = (slap_overinst *)be->bd_info;
1909 	log_info *li = ch_calloc(1, sizeof(log_info));
1910 
1911 	on->on_bi.bi_private = li;
1912 	ldap_pvt_thread_rmutex_init( &li->li_op_rmutex );
1913 	ldap_pvt_thread_mutex_init( &li->li_log_mutex );
1914 	return 0;
1915 }
1916 
1917 static int
1918 accesslog_db_destroy(
1919 	BackendDB *be,
1920 	ConfigReply *cr
1921 )
1922 {
1923 	slap_overinst *on = (slap_overinst *)be->bd_info;
1924 	log_info *li = on->on_bi.bi_private;
1925 	log_attr *la;
1926 
1927 	if ( li->li_oldf )
1928 		filter_free( li->li_oldf );
1929 	for ( la=li->li_oldattrs; la; la=li->li_oldattrs ) {
1930 		li->li_oldattrs = la->next;
1931 		ch_free( la );
1932 	}
1933 	ldap_pvt_thread_mutex_destroy( &li->li_log_mutex );
1934 	ldap_pvt_thread_rmutex_destroy( &li->li_op_rmutex );
1935 	free( li );
1936 	return LDAP_SUCCESS;
1937 }
1938 
1939 /* Create the logdb's root entry if it's missing */
1940 static void *
1941 accesslog_db_root(
1942 	void *ctx,
1943 	void *arg )
1944 {
1945 	struct re_s *rtask = arg;
1946 	slap_overinst *on = rtask->arg;
1947 	log_info *li = on->on_bi.bi_private;
1948 
1949 	Connection conn = {0};
1950 	OperationBuffer opbuf;
1951 	Operation *op;
1952 
1953 	Entry *e;
1954 	int rc;
1955 
1956 	connection_fake_init( &conn, &opbuf, ctx );
1957 	op = &opbuf.ob_op;
1958 	op->o_bd = li->li_db;
1959 	op->o_dn = li->li_db->be_rootdn;
1960 	op->o_ndn = li->li_db->be_rootndn;
1961 	rc = be_entry_get_rw( op, li->li_db->be_nsuffix, NULL, NULL, 0, &e );
1962 
1963 	if ( e ) {
1964 		be_entry_release_rw( op, e, 0 );
1965 
1966 	} else {
1967 		SlapReply rs = {REP_RESULT};
1968 		struct berval rdn, nrdn, attr;
1969 		char *ptr;
1970 		AttributeDescription *ad = NULL;
1971 		const char *text = NULL;
1972 		Entry *e_ctx;
1973 
1974 		e = entry_alloc();
1975 		ber_dupbv( &e->e_name, li->li_db->be_suffix );
1976 		ber_dupbv( &e->e_nname, li->li_db->be_nsuffix );
1977 
1978 		attr_merge_one( e, slap_schema.si_ad_objectClass,
1979 			&log_container->soc_cname, NULL );
1980 
1981 		dnRdn( &e->e_name, &rdn );
1982 		dnRdn( &e->e_nname, &nrdn );
1983 		ptr = ber_bvchr( &rdn, '=' );
1984 
1985 		assert( ptr != NULL );
1986 
1987 		attr.bv_val = rdn.bv_val;
1988 		attr.bv_len = ptr - rdn.bv_val;
1989 
1990 		slap_bv2ad( &attr, &ad, &text );
1991 
1992 		rdn.bv_val = ptr+1;
1993 		rdn.bv_len -= attr.bv_len + 1;
1994 		ptr = ber_bvchr( &nrdn, '=' );
1995 		nrdn.bv_len -= ptr - nrdn.bv_val + 1;
1996 		nrdn.bv_val = ptr+1;
1997 		attr_merge_one( e, ad, &rdn, &nrdn );
1998 
1999 		/* Get contextCSN from main DB */
2000 		op->o_bd = on->on_info->oi_origdb;
2001 		rc = be_entry_get_rw( op, op->o_bd->be_nsuffix, NULL,
2002 			slap_schema.si_ad_contextCSN, 0, &e_ctx );
2003 
2004 		if ( e_ctx ) {
2005 			Attribute *a;
2006 
2007 			a = attr_find( e_ctx->e_attrs, slap_schema.si_ad_contextCSN );
2008 			if ( a ) {
2009 				/* FIXME: contextCSN could have multiple values!
2010 				 * should select the one with the server's SID */
2011 				attr_merge_one( e, slap_schema.si_ad_entryCSN,
2012 					&a->a_vals[0], &a->a_nvals[0] );
2013 				attr_merge( e, a->a_desc, a->a_vals, a->a_nvals );
2014 			}
2015 			be_entry_release_rw( op, e_ctx, 0 );
2016 		}
2017 		op->o_bd = li->li_db;
2018 
2019 		op->ora_e = e;
2020 		op->o_req_dn = e->e_name;
2021 		op->o_req_ndn = e->e_nname;
2022 		op->o_callback = &nullsc;
2023 		SLAP_DBFLAGS( op->o_bd ) |= SLAP_DBFLAG_NOLASTMOD;
2024 		rc = op->o_bd->be_add( op, &rs );
2025 		SLAP_DBFLAGS( op->o_bd ) ^= SLAP_DBFLAG_NOLASTMOD;
2026 		if ( e == op->ora_e )
2027 			entry_free( e );
2028 	}
2029 	ldap_pvt_thread_mutex_lock( &slapd_rq.rq_mutex );
2030 	ldap_pvt_runqueue_stoptask( &slapd_rq, rtask );
2031 	ldap_pvt_runqueue_remove( &slapd_rq, rtask );
2032 	ldap_pvt_thread_mutex_unlock( &slapd_rq.rq_mutex );
2033 
2034 	return NULL;
2035 }
2036 
2037 static int
2038 accesslog_db_open(
2039 	BackendDB *be,
2040 	ConfigReply *cr
2041 )
2042 {
2043 	slap_overinst *on = (slap_overinst *)be->bd_info;
2044 	log_info *li = on->on_bi.bi_private;
2045 
2046 
2047 	if ( !BER_BVISEMPTY( &li->li_db_suffix )) {
2048 		li->li_db = select_backend( &li->li_db_suffix, 0 );
2049 		ch_free( li->li_db_suffix.bv_val );
2050 		BER_BVZERO( &li->li_db_suffix );
2051 	}
2052 	if ( li->li_db == NULL ) {
2053 		Debug( LDAP_DEBUG_ANY,
2054 			"accesslog: \"logdb <suffix>\" missing or invalid.\n",
2055 			0, 0, 0 );
2056 		return 1;
2057 	}
2058 
2059 	if ( slapMode & SLAP_TOOL_MODE )
2060 		return 0;
2061 
2062 	if ( BER_BVISEMPTY( &li->li_db->be_rootndn )) {
2063 		ber_dupbv( &li->li_db->be_rootdn, li->li_db->be_suffix );
2064 		ber_dupbv( &li->li_db->be_rootndn, li->li_db->be_nsuffix );
2065 	}
2066 
2067 	ldap_pvt_thread_mutex_lock( &slapd_rq.rq_mutex );
2068 	ldap_pvt_runqueue_insert( &slapd_rq, 3600, accesslog_db_root, on,
2069 		"accesslog_db_root", li->li_db->be_suffix[0].bv_val );
2070 	ldap_pvt_thread_mutex_unlock( &slapd_rq.rq_mutex );
2071 
2072 	return 0;
2073 }
2074 
2075 int accesslog_initialize()
2076 {
2077 	int i, rc;
2078 
2079 	accesslog.on_bi.bi_type = "accesslog";
2080 	accesslog.on_bi.bi_db_init = accesslog_db_init;
2081 	accesslog.on_bi.bi_db_destroy = accesslog_db_destroy;
2082 	accesslog.on_bi.bi_db_open = accesslog_db_open;
2083 
2084 	accesslog.on_bi.bi_op_add = accesslog_op_mod;
2085 	accesslog.on_bi.bi_op_bind = accesslog_op_bind;
2086 	accesslog.on_bi.bi_op_delete = accesslog_op_mod;
2087 	accesslog.on_bi.bi_op_modify = accesslog_op_mod;
2088 	accesslog.on_bi.bi_op_modrdn = accesslog_op_mod;
2089 	accesslog.on_bi.bi_op_unbind = accesslog_unbind;
2090 	accesslog.on_bi.bi_op_abandon = accesslog_abandon;
2091 	accesslog.on_bi.bi_operational = accesslog_operational;
2092 	accesslog.on_response = accesslog_response;
2093 
2094 	accesslog.on_bi.bi_cf_ocs = log_cfocs;
2095 
2096 	nullsc.sc_response = slap_null_cb;
2097 
2098 	rc = config_register_schema( log_cfats, log_cfocs );
2099 	if ( rc ) return rc;
2100 
2101 	/* log schema integration */
2102 	for ( i=0; lsyntaxes[i].oid; i++ ) {
2103 		int code;
2104 
2105 		code = register_syntax( &lsyntaxes[ i ].syn );
2106 		if ( code != 0 ) {
2107 			Debug( LDAP_DEBUG_ANY,
2108 				"accesslog_init: register_syntax failed\n",
2109 				0, 0, 0 );
2110 			return code;
2111 		}
2112 
2113 		if ( lsyntaxes[i].mrs != NULL ) {
2114 			code = mr_make_syntax_compat_with_mrs(
2115 				lsyntaxes[i].oid, lsyntaxes[i].mrs );
2116 			if ( code < 0 ) {
2117 				Debug( LDAP_DEBUG_ANY,
2118 					"accesslog_init: "
2119 					"mr_make_syntax_compat_with_mrs "
2120 					"failed\n",
2121 					0, 0, 0 );
2122 				return code;
2123 			}
2124 		}
2125 	}
2126 
2127 	for ( i=0; lattrs[i].at; i++ ) {
2128 		int code;
2129 
2130 		code = register_at( lattrs[i].at, lattrs[i].ad, 0 );
2131 		if ( code ) {
2132 			Debug( LDAP_DEBUG_ANY,
2133 				"accesslog_init: register_at failed\n",
2134 				0, 0, 0 );
2135 			return -1;
2136 		}
2137 #ifndef LDAP_DEVEL
2138 		(*lattrs[i].ad)->ad_type->sat_flags |= SLAP_AT_HIDE;
2139 #endif
2140 	}
2141 
2142 	for ( i=0; locs[i].ot; i++ ) {
2143 		int code;
2144 
2145 		code = register_oc( locs[i].ot, locs[i].oc, 0 );
2146 		if ( code ) {
2147 			Debug( LDAP_DEBUG_ANY,
2148 				"accesslog_init: register_oc failed\n",
2149 				0, 0, 0 );
2150 			return -1;
2151 		}
2152 #ifndef LDAP_DEVEL
2153 		(*locs[i].oc)->soc_flags |= SLAP_OC_HIDE;
2154 #endif
2155 	}
2156 
2157 	return overlay_register(&accesslog);
2158 }
2159 
2160 #if SLAPD_OVER_ACCESSLOG == SLAPD_MOD_DYNAMIC
2161 int
2162 init_module( int argc, char *argv[] )
2163 {
2164 	return accesslog_initialize();
2165 }
2166 #endif
2167 
2168 #endif /* SLAPD_OVER_ACCESSLOG */
2169