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