1/*	$NetBSD: accesslog.c,v 1.3 2021/08/14 16:15:02 christos Exp $	*/
2
3/* accesslog.c - log operations for audit/history purposes */
4/* $OpenLDAP$ */
5/* This work is part of OpenLDAP Software <http://www.openldap.org/>.
6 *
7 * Copyright 2005-2021 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 <sys/cdefs.h>
25__RCSID("$NetBSD: accesslog.c,v 1.3 2021/08/14 16:15:02 christos Exp $");
26
27#include "portable.h"
28
29#ifdef SLAPD_OVER_ACCESSLOG
30
31#include <stdio.h>
32
33#include <ac/string.h>
34#include <ac/ctype.h>
35
36#include "slap.h"
37#include "slap-config.h"
38#include "lutil.h"
39#include "ldap_rq.h"
40
41#define LOG_OP_ADD	0x001
42#define LOG_OP_DELETE	0x002
43#define	LOG_OP_MODIFY	0x004
44#define LOG_OP_MODRDN	0x008
45#define	LOG_OP_COMPARE	0x010
46#define	LOG_OP_SEARCH	0x020
47#define LOG_OP_BIND	0x040
48#define LOG_OP_UNBIND	0x080
49#define	LOG_OP_ABANDON	0x100
50#define	LOG_OP_EXTENDED	0x200
51#define LOG_OP_UNKNOWN	0x400
52
53#define	LOG_OP_WRITES	(LOG_OP_ADD|LOG_OP_DELETE|LOG_OP_MODIFY|LOG_OP_MODRDN)
54#define	LOG_OP_READS	(LOG_OP_COMPARE|LOG_OP_SEARCH)
55#define	LOG_OP_SESSION	(LOG_OP_BIND|LOG_OP_UNBIND|LOG_OP_ABANDON)
56#define LOG_OP_ALL		(LOG_OP_READS|LOG_OP_WRITES|LOG_OP_SESSION| \
57	LOG_OP_EXTENDED|LOG_OP_UNKNOWN)
58
59typedef struct log_attr {
60	struct log_attr *next;
61	AttributeDescription *attr;
62} log_attr;
63
64typedef struct log_base {
65	struct log_base *lb_next;
66	slap_mask_t lb_ops;
67	struct berval lb_base;
68	struct berval lb_line;
69} log_base;
70
71typedef struct log_info {
72	BackendDB *li_db;
73	struct berval li_db_suffix;
74	slap_mask_t li_ops;
75	int li_age;
76	int li_cycle;
77	struct re_s *li_task;
78	Filter *li_oldf;
79	Entry *li_old;
80	log_attr *li_oldattrs;
81	struct berval li_uuid;
82	int li_success;
83	log_base *li_bases;
84	BerVarray li_mincsn;
85	int *li_sids, li_numcsns;
86	ldap_pvt_thread_mutex_t li_op_rmutex;
87	ldap_pvt_thread_mutex_t li_log_mutex;
88} log_info;
89
90static ConfigDriver log_cf_gen;
91
92enum {
93	LOG_DB = 1,
94	LOG_OPS,
95	LOG_PURGE,
96	LOG_SUCCESS,
97	LOG_OLD,
98	LOG_OLDATTR,
99	LOG_BASE
100};
101
102static ConfigTable log_cfats[] = {
103	{ "logdb", "suffix", 2, 2, 0, ARG_DN|ARG_QUOTE|ARG_MAGIC|LOG_DB,
104		log_cf_gen, "( OLcfgOvAt:4.1 NAME 'olcAccessLogDB' "
105			"DESC 'Suffix of database for log content' "
106			"EQUALITY distinguishedNameMatch "
107			"SUP distinguishedName SINGLE-VALUE )", NULL, NULL },
108	{ "logops", "op|writes|reads|session|all", 2, 0, 0,
109		ARG_MAGIC|LOG_OPS,
110		log_cf_gen, "( OLcfgOvAt:4.2 NAME 'olcAccessLogOps' "
111			"DESC 'Operation types to log' "
112			"EQUALITY caseIgnoreMatch "
113			"SYNTAX OMsDirectoryString )", NULL, NULL },
114	{ "logpurge", "age> <interval", 3, 3, 0, ARG_MAGIC|LOG_PURGE,
115		log_cf_gen, "( OLcfgOvAt:4.3 NAME 'olcAccessLogPurge' "
116			"DESC 'Log cleanup parameters' "
117			"EQUALITY caseIgnoreMatch "
118			"SYNTAX OMsDirectoryString SINGLE-VALUE )", NULL, NULL },
119	{ "logsuccess", NULL, 2, 2, 0, ARG_MAGIC|ARG_ON_OFF|LOG_SUCCESS,
120		log_cf_gen, "( OLcfgOvAt:4.4 NAME 'olcAccessLogSuccess' "
121			"DESC 'Log successful ops only' "
122			"EQUALITY booleanMatch "
123			"SYNTAX OMsBoolean SINGLE-VALUE )", NULL, NULL },
124	{ "logold", "filter", 2, 2, 0, ARG_MAGIC|LOG_OLD,
125		log_cf_gen, "( OLcfgOvAt:4.5 NAME 'olcAccessLogOld' "
126			"DESC 'Log old values when modifying entries matching the filter' "
127			"EQUALITY caseExactMatch "
128			"SYNTAX OMsDirectoryString SINGLE-VALUE )", NULL, NULL },
129	{ "logoldattr", "attrs", 2, 0, 0, ARG_MAGIC|LOG_OLDATTR,
130		log_cf_gen, "( OLcfgOvAt:4.6 NAME 'olcAccessLogOldAttr' "
131			"DESC 'Log old values of these attributes even if unmodified' "
132			"EQUALITY caseIgnoreMatch "
133			"SYNTAX OMsDirectoryString )", NULL, NULL },
134	{ "logbase", "op|writes|reads|session|all< <baseDN", 3, 3, 0,
135		ARG_MAGIC|LOG_BASE,
136		log_cf_gen, "( OLcfgOvAt:4.7 NAME 'olcAccessLogBase' "
137			"DESC 'Operation types to log under a specific branch' "
138			"EQUALITY caseIgnoreMatch "
139			"SYNTAX OMsDirectoryString )", NULL, NULL },
140	{ NULL }
141};
142
143static ConfigOCs log_cfocs[] = {
144	{ "( OLcfgOvOc:4.1 "
145		"NAME 'olcAccessLogConfig' "
146		"DESC 'Access log configuration' "
147		"SUP olcOverlayConfig "
148		"MUST olcAccessLogDB "
149		"MAY ( olcAccessLogOps $ olcAccessLogPurge $ olcAccessLogSuccess $ "
150			"olcAccessLogOld $ olcAccessLogOldAttr $ olcAccessLogBase ) )",
151			Cft_Overlay, log_cfats },
152	{ NULL }
153};
154
155static slap_verbmasks logops[] = {
156	{ BER_BVC("all"),		LOG_OP_ALL },
157	{ BER_BVC("writes"),	LOG_OP_WRITES },
158	{ BER_BVC("session"),	LOG_OP_SESSION },
159	{ BER_BVC("reads"),		LOG_OP_READS },
160	{ BER_BVC("add"),		LOG_OP_ADD },
161	{ BER_BVC("delete"),	LOG_OP_DELETE },
162	{ BER_BVC("modify"),	LOG_OP_MODIFY },
163	{ BER_BVC("modrdn"),	LOG_OP_MODRDN },
164	{ BER_BVC("compare"),	LOG_OP_COMPARE },
165	{ BER_BVC("search"),	LOG_OP_SEARCH },
166	{ BER_BVC("bind"),		LOG_OP_BIND },
167	{ BER_BVC("unbind"),	LOG_OP_UNBIND },
168	{ BER_BVC("abandon"),	LOG_OP_ABANDON },
169	{ BER_BVC("extended"),	LOG_OP_EXTENDED },
170	{ BER_BVC("unknown"),	LOG_OP_UNKNOWN },
171	{ BER_BVNULL, 0 }
172};
173
174/* Start with "add" in logops */
175#define EN_OFFSET	4
176
177enum {
178	LOG_EN_ADD = 0,
179	LOG_EN_DELETE,
180	LOG_EN_MODIFY,
181	LOG_EN_MODRDN,
182	LOG_EN_COMPARE,
183	LOG_EN_SEARCH,
184	LOG_EN_BIND,
185	LOG_EN_UNBIND,
186	LOG_EN_ABANDON,
187	LOG_EN_EXTENDED,
188	LOG_EN_UNKNOWN,
189	LOG_EN__COUNT
190};
191
192static ObjectClass *log_ocs[LOG_EN__COUNT], *log_container,
193	*log_oc_read, *log_oc_write;
194
195#define LOG_SCHEMA_ROOT	"1.3.6.1.4.1.4203.666.11.5"
196
197#define LOG_SCHEMA_AT LOG_SCHEMA_ROOT ".1"
198#define LOG_SCHEMA_OC LOG_SCHEMA_ROOT ".2"
199#define LOG_SCHEMA_SYN LOG_SCHEMA_ROOT ".3"
200
201static AttributeDescription *ad_reqDN, *ad_reqStart, *ad_reqEnd, *ad_reqType,
202	*ad_reqSession, *ad_reqResult, *ad_reqAuthzID, *ad_reqControls,
203	*ad_reqRespControls, *ad_reqMethod, *ad_reqAssertion, *ad_reqNewRDN,
204	*ad_reqNewSuperior, *ad_reqDeleteOldRDN, *ad_reqMod,
205	*ad_reqScope, *ad_reqFilter, *ad_reqAttr, *ad_reqEntries,
206	*ad_reqSizeLimit, *ad_reqTimeLimit, *ad_reqAttrsOnly, *ad_reqData,
207	*ad_reqId, *ad_reqMessage, *ad_reqVersion, *ad_reqDerefAliases,
208	*ad_reqReferral, *ad_reqOld, *ad_auditContext, *ad_reqEntryUUID,
209	*ad_minCSN, *ad_reqNewDN;
210
211static int
212logSchemaControlValidate(
213	Syntax		*syntax,
214	struct berval	*val );
215
216char	*mrControl[] = {
217	"objectIdentifierFirstComponentMatch",
218	NULL
219};
220
221static struct {
222	char			*oid;
223	slap_syntax_defs_rec	syn;
224	char			**mrs;
225} lsyntaxes[] = {
226	{ LOG_SCHEMA_SYN ".1" ,
227		{ "( " LOG_SCHEMA_SYN ".1 DESC 'Control' )",
228			SLAP_SYNTAX_HIDE,
229			NULL,
230			logSchemaControlValidate,
231			NULL },
232		mrControl },
233	{ NULL }
234};
235
236static struct {
237	char *at;
238	AttributeDescription **ad;
239} lattrs[] = {
240	{ "( " LOG_SCHEMA_AT ".1 NAME 'reqDN' "
241		"DESC 'Target DN of request' "
242		"EQUALITY distinguishedNameMatch "
243		"SYNTAX OMsDN "
244		"SINGLE-VALUE )", &ad_reqDN },
245	{ "( " LOG_SCHEMA_AT ".2 NAME 'reqStart' "
246		"DESC 'Start time of request' "
247		"EQUALITY generalizedTimeMatch "
248		"ORDERING generalizedTimeOrderingMatch "
249		"SYNTAX 1.3.6.1.4.1.1466.115.121.1.24 "
250		"SINGLE-VALUE )", &ad_reqStart },
251	{ "( " LOG_SCHEMA_AT ".3 NAME 'reqEnd' "
252		"DESC 'End time of request' "
253		"EQUALITY generalizedTimeMatch "
254		"ORDERING generalizedTimeOrderingMatch "
255		"SYNTAX 1.3.6.1.4.1.1466.115.121.1.24 "
256		"SINGLE-VALUE )", &ad_reqEnd },
257	{ "( " LOG_SCHEMA_AT ".4 NAME 'reqType' "
258		"DESC 'Type of request' "
259		"EQUALITY caseIgnoreMatch "
260		"SYNTAX OMsDirectoryString "
261		"SINGLE-VALUE )", &ad_reqType },
262	{ "( " LOG_SCHEMA_AT ".5 NAME 'reqSession' "
263		"DESC 'Session ID of request' "
264		"EQUALITY caseIgnoreMatch "
265		"SYNTAX OMsDirectoryString "
266		"SINGLE-VALUE )", &ad_reqSession },
267	{ "( " LOG_SCHEMA_AT ".6 NAME 'reqAuthzID' "
268		"DESC 'Authorization ID of requestor' "
269		"EQUALITY distinguishedNameMatch "
270		"SYNTAX OMsDN "
271		"SINGLE-VALUE )", &ad_reqAuthzID },
272	{ "( " LOG_SCHEMA_AT ".7 NAME 'reqResult' "
273		"DESC 'Result code of request' "
274		"EQUALITY integerMatch "
275		"ORDERING integerOrderingMatch "
276		"SYNTAX OMsInteger "
277		"SINGLE-VALUE )", &ad_reqResult },
278	{ "( " LOG_SCHEMA_AT ".8 NAME 'reqMessage' "
279		"DESC 'Error text of request' "
280		"EQUALITY caseIgnoreMatch "
281		"SUBSTR caseIgnoreSubstringsMatch "
282		"SYNTAX OMsDirectoryString "
283		"SINGLE-VALUE )", &ad_reqMessage },
284	{ "( " LOG_SCHEMA_AT ".9 NAME 'reqReferral' "
285		"DESC 'Referrals returned for request' "
286		"SUP labeledURI )", &ad_reqReferral },
287	{ "( " LOG_SCHEMA_AT ".10 NAME 'reqControls' "
288		"DESC 'Request controls' "
289		"EQUALITY objectIdentifierFirstComponentMatch "
290		"SYNTAX " LOG_SCHEMA_SYN ".1 "
291		"X-ORDERED 'VALUES' )", &ad_reqControls },
292	{ "( " LOG_SCHEMA_AT ".11 NAME 'reqRespControls' "
293		"DESC 'Response controls of request' "
294		"EQUALITY objectIdentifierFirstComponentMatch "
295		"SYNTAX " LOG_SCHEMA_SYN ".1 "
296		"X-ORDERED 'VALUES' )", &ad_reqRespControls },
297	{ "( " LOG_SCHEMA_AT ".12 NAME 'reqId' "
298		"DESC 'ID of Request to Abandon' "
299		"EQUALITY integerMatch "
300		"ORDERING integerOrderingMatch "
301		"SYNTAX OMsInteger "
302		"SINGLE-VALUE )", &ad_reqId },
303	{ "( " LOG_SCHEMA_AT ".13 NAME 'reqVersion' "
304		"DESC 'Protocol version of Bind request' "
305		"EQUALITY integerMatch "
306		"ORDERING integerOrderingMatch "
307		"SYNTAX OMsInteger "
308		"SINGLE-VALUE )", &ad_reqVersion },
309	{ "( " LOG_SCHEMA_AT ".14 NAME 'reqMethod' "
310		"DESC 'Bind method of request' "
311		"EQUALITY caseIgnoreMatch "
312		"SYNTAX OMsDirectoryString "
313		"SINGLE-VALUE )", &ad_reqMethod },
314	{ "( " LOG_SCHEMA_AT ".15 NAME 'reqAssertion' "
315		"DESC 'Compare Assertion of request' "
316		"SYNTAX OMsDirectoryString "
317		"SINGLE-VALUE )", &ad_reqAssertion },
318	{ "( " LOG_SCHEMA_AT ".16 NAME 'reqMod' "
319		"DESC 'Modifications of request' "
320		"EQUALITY octetStringMatch "
321		"SUBSTR octetStringSubstringsMatch "
322		"SYNTAX OMsOctetString )", &ad_reqMod },
323	{ "( " LOG_SCHEMA_AT ".17 NAME 'reqOld' "
324		"DESC 'Old values of entry before request completed' "
325		"EQUALITY octetStringMatch "
326		"SUBSTR octetStringSubstringsMatch "
327		"SYNTAX OMsOctetString )", &ad_reqOld },
328	{ "( " LOG_SCHEMA_AT ".18 NAME 'reqNewRDN' "
329		"DESC 'New RDN of request' "
330		"EQUALITY distinguishedNameMatch "
331		"SYNTAX OMsDN "
332		"SINGLE-VALUE )", &ad_reqNewRDN },
333	{ "( " LOG_SCHEMA_AT ".19 NAME 'reqDeleteOldRDN' "
334		"DESC 'Delete old RDN' "
335		"EQUALITY booleanMatch "
336		"SYNTAX OMsBoolean "
337		"SINGLE-VALUE )", &ad_reqDeleteOldRDN },
338	{ "( " LOG_SCHEMA_AT ".20 NAME 'reqNewSuperior' "
339		"DESC 'New superior DN of request' "
340		"EQUALITY distinguishedNameMatch "
341		"SYNTAX OMsDN "
342		"SINGLE-VALUE )", &ad_reqNewSuperior },
343	{ "( " LOG_SCHEMA_AT ".21 NAME 'reqScope' "
344		"DESC 'Scope of request' "
345		"EQUALITY caseIgnoreMatch "
346		"SYNTAX OMsDirectoryString "
347		"SINGLE-VALUE )", &ad_reqScope },
348	{ "( " LOG_SCHEMA_AT ".22 NAME 'reqDerefAliases' "
349		"DESC 'Disposition of Aliases in request' "
350		"EQUALITY caseIgnoreMatch "
351		"SYNTAX OMsDirectoryString "
352		"SINGLE-VALUE )", &ad_reqDerefAliases },
353	{ "( " LOG_SCHEMA_AT ".23 NAME 'reqAttrsOnly' "
354		"DESC 'Attributes and values of request' "
355		"EQUALITY booleanMatch "
356		"SYNTAX OMsBoolean "
357		"SINGLE-VALUE )", &ad_reqAttrsOnly },
358	{ "( " LOG_SCHEMA_AT ".24 NAME 'reqFilter' "
359		"DESC 'Filter of request' "
360		"EQUALITY caseIgnoreMatch "
361		"SUBSTR caseIgnoreSubstringsMatch "
362		"SYNTAX OMsDirectoryString "
363		"SINGLE-VALUE )", &ad_reqFilter },
364	{ "( " LOG_SCHEMA_AT ".25 NAME 'reqAttr' "
365		"DESC 'Attributes of request' "
366		"EQUALITY caseIgnoreMatch "
367		"SYNTAX OMsDirectoryString )", &ad_reqAttr },
368	{ "( " LOG_SCHEMA_AT ".26 NAME 'reqSizeLimit' "
369		"DESC 'Size limit of request' "
370		"EQUALITY integerMatch "
371		"ORDERING integerOrderingMatch "
372		"SYNTAX OMsInteger "
373		"SINGLE-VALUE )", &ad_reqSizeLimit },
374	{ "( " LOG_SCHEMA_AT ".27 NAME 'reqTimeLimit' "
375		"DESC 'Time limit of request' "
376		"EQUALITY integerMatch "
377		"ORDERING integerOrderingMatch "
378		"SYNTAX OMsInteger "
379		"SINGLE-VALUE )", &ad_reqTimeLimit },
380	{ "( " LOG_SCHEMA_AT ".28 NAME 'reqEntries' "
381		"DESC 'Number of entries returned' "
382		"EQUALITY integerMatch "
383		"ORDERING integerOrderingMatch "
384		"SYNTAX OMsInteger "
385		"SINGLE-VALUE )", &ad_reqEntries },
386	{ "( " LOG_SCHEMA_AT ".29 NAME 'reqData' "
387		"DESC 'Data of extended request' "
388		"EQUALITY octetStringMatch "
389		"SUBSTR octetStringSubstringsMatch "
390		"SYNTAX OMsOctetString "
391		"SINGLE-VALUE )", &ad_reqData },
392
393	/*
394	 * from <draft-chu-ldap-logschema-01.txt>:
395	 *
396
397   ( LOG_SCHEMA_AT .30 NAME 'auditContext'
398   DESC 'DN of auditContainer'
399   EQUALITY distinguishedNameMatch
400   SYNTAX 1.3.6.1.4.1.1466.115.121.1.12
401   SINGLE-VALUE NO-USER-MODIFICATION USAGE directoryOperation )
402
403	 * - removed EQUALITY matchingRule
404	 * - changed directoryOperation in dSAOperation
405	 */
406	{ "( " LOG_SCHEMA_AT ".30 NAME 'auditContext' "
407		"DESC 'DN of auditContainer' "
408		"SYNTAX 1.3.6.1.4.1.1466.115.121.1.12 "
409		"SINGLE-VALUE "
410		"NO-USER-MODIFICATION "
411		"USAGE dSAOperation )", &ad_auditContext },
412
413	/*
414	 * ITS#6656
415	 */
416	{ "( " LOG_SCHEMA_AT ".31 NAME 'reqEntryUUID' "
417		"DESC 'UUID of entry' "
418		"EQUALITY UUIDMatch "
419		"ORDERING UUIDOrderingMatch "
420		"SYNTAX 1.3.6.1.1.16.1 "
421		"SINGLE-VALUE )", &ad_reqEntryUUID },
422
423	/*
424	 * ITS#8486
425	 */
426	{ "( " LOG_SCHEMA_AT ".32 NAME 'minCSN' "
427		"DESC 'CSN set that the logs are recorded from' "
428		"EQUALITY CSNMatch "
429		"ORDERING CSNOrderingMatch "
430		"SYNTAX 1.3.6.1.4.1.4203.666.11.2.1{64} "
431		"NO-USER-MODIFICATION "
432		"USAGE dSAOperation )", &ad_minCSN },
433
434	/*
435	 * ITS#9552
436	 */
437	{ "( " LOG_SCHEMA_AT ".33 NAME 'reqNewDN' "
438		"DESC 'New DN after rename' "
439		"EQUALITY distinguishedNameMatch "
440		"SYNTAX OMsDN "
441		"SINGLE-VALUE )", &ad_reqNewDN },
442	{ NULL, NULL }
443};
444
445static struct {
446	char *ot;
447	ObjectClass **oc;
448} locs[] = {
449	{ "( " LOG_SCHEMA_OC ".0 NAME 'auditContainer' "
450		"DESC 'AuditLog container' "
451		"SUP top STRUCTURAL "
452		"MAY ( cn $ reqStart $ reqEnd ) )", &log_container },
453	{ "( " LOG_SCHEMA_OC ".1 NAME 'auditObject' "
454		"DESC 'OpenLDAP request auditing' "
455		"SUP top STRUCTURAL "
456		"MUST ( reqStart $ reqType $ reqSession ) "
457		"MAY ( reqDN $ reqAuthzID $ reqControls $ reqRespControls $ reqEnd $ "
458			"reqResult $ reqMessage $ reqReferral $ reqEntryUUID ) )",
459				&log_ocs[LOG_EN_UNBIND] },
460	{ "( " LOG_SCHEMA_OC ".2 NAME 'auditReadObject' "
461		"DESC 'OpenLDAP read request record' "
462		"SUP auditObject STRUCTURAL )", &log_oc_read },
463	{ "( " LOG_SCHEMA_OC ".3 NAME 'auditWriteObject' "
464		"DESC 'OpenLDAP write request record' "
465		"SUP auditObject STRUCTURAL )", &log_oc_write },
466	{ "( " LOG_SCHEMA_OC ".4 NAME 'auditAbandon' "
467		"DESC 'Abandon operation' "
468		"SUP auditObject STRUCTURAL "
469		"MUST reqId )", &log_ocs[LOG_EN_ABANDON] },
470	{ "( " LOG_SCHEMA_OC ".5 NAME 'auditAdd' "
471		"DESC 'Add operation' "
472		"SUP auditWriteObject STRUCTURAL "
473		"MUST reqMod )", &log_ocs[LOG_EN_ADD] },
474	{ "( " LOG_SCHEMA_OC ".6 NAME 'auditBind' "
475		"DESC 'Bind operation' "
476		"SUP auditObject STRUCTURAL "
477		"MUST ( reqVersion $ reqMethod ) )", &log_ocs[LOG_EN_BIND] },
478	{ "( " LOG_SCHEMA_OC ".7 NAME 'auditCompare' "
479		"DESC 'Compare operation' "
480		"SUP auditReadObject STRUCTURAL "
481		"MUST reqAssertion )", &log_ocs[LOG_EN_COMPARE] },
482	{ "( " LOG_SCHEMA_OC ".8 NAME 'auditDelete' "
483		"DESC 'Delete operation' "
484		"SUP auditWriteObject STRUCTURAL "
485		"MAY reqOld )", &log_ocs[LOG_EN_DELETE] },
486	{ "( " LOG_SCHEMA_OC ".9 NAME 'auditModify' "
487		"DESC 'Modify operation' "
488		"SUP auditWriteObject STRUCTURAL "
489		"MAY reqOld MUST reqMod )", &log_ocs[LOG_EN_MODIFY] },
490	{ "( " LOG_SCHEMA_OC ".10 NAME 'auditModRDN' "
491		"DESC 'ModRDN operation' "
492		"SUP auditWriteObject STRUCTURAL "
493		"MUST ( reqNewRDN $ reqDeleteOldRDN ) "
494		"MAY ( reqNewSuperior $ reqMod $ reqOld $ reqNewDN ) )",
495		&log_ocs[LOG_EN_MODRDN] },
496	{ "( " LOG_SCHEMA_OC ".11 NAME 'auditSearch' "
497		"DESC 'Search operation' "
498		"SUP auditReadObject STRUCTURAL "
499		"MUST ( reqScope $ reqDerefAliases $ reqAttrsonly ) "
500		"MAY ( reqFilter $ reqAttr $ reqEntries $ reqSizeLimit $ "
501			"reqTimeLimit ) )", &log_ocs[LOG_EN_SEARCH] },
502	{ "( " LOG_SCHEMA_OC ".12 NAME 'auditExtended' "
503		"DESC 'Extended operation' "
504		"SUP auditObject STRUCTURAL "
505		"MAY reqData )", &log_ocs[LOG_EN_EXTENDED] },
506	{ NULL, NULL }
507};
508
509#define	RDNEQ	"reqStart="
510
511/* Our time intervals are of the form [ddd+]hh:mm[:ss]
512 * If a field is present, it must be two digits. (Except for
513 * days, which can be arbitrary width.)
514 */
515static int
516log_age_parse(char *agestr)
517{
518	int t1, t2;
519	int gotdays = 0;
520	char *endptr;
521
522	t1 = strtol( agestr, &endptr, 10 );
523	/* Is there a days delimiter? */
524	if ( *endptr == '+' ) {
525		/* 32 bit time only covers about 68 years */
526		if ( t1 < 0 || t1 > 25000 )
527			return -1;
528		t1 *= 24;
529		gotdays = 1;
530		agestr = endptr + 1;
531	} else {
532		if ( agestr[2] != ':' ) {
533			/* No valid delimiter found, fail */
534			return -1;
535		}
536		t1 *= 60;
537		agestr += 3;
538	}
539
540	t2 = atoi( agestr );
541	t1 += t2;
542
543	if ( agestr[2] ) {
544		/* if there's a delimiter, it can only be a colon */
545		if ( agestr[2] != ':' )
546			return -1;
547	} else {
548		/* If we're at the end of the string, and we started with days,
549		 * fail because we expected to find minutes too.
550		 */
551		return gotdays ? -1 : t1 * 60;
552	}
553
554	agestr += 3;
555	t2 = atoi( agestr );
556
557	/* last field can only be seconds */
558	if ( agestr[2] && ( agestr[2] != ':' || !gotdays ))
559		return -1;
560	t1 *= 60;
561	t1 += t2;
562
563	if ( agestr[2] ) {
564		agestr += 3;
565		if ( agestr[2] )
566			return -1;
567		t1 *= 60;
568		t1 += atoi( agestr );
569	} else if ( gotdays ) {
570		/* only got days+hh:mm */
571		t1 *= 60;
572	}
573	return t1;
574}
575
576static void
577log_age_unparse( int age, struct berval *agebv, size_t size )
578{
579	int dd, hh, mm, ss, len;
580	char *ptr;
581
582	assert( size > 0 );
583
584	ss = age % 60;
585	age /= 60;
586	mm = age % 60;
587	age /= 60;
588	hh = age % 24;
589	age /= 24;
590	dd = age;
591
592	ptr = agebv->bv_val;
593
594	if ( dd ) {
595		len = snprintf( ptr, size, "%d+", dd );
596		assert( len >= 0 && (unsigned) len < size );
597		size -= len;
598		ptr += len;
599	}
600	len = snprintf( ptr, size, "%02d:%02d", hh, mm );
601	assert( len >= 0 && (unsigned) len < size );
602	size -= len;
603	ptr += len;
604	if ( ss ) {
605		len = snprintf( ptr, size, ":%02d", ss );
606		assert( len >= 0 && (unsigned) len < size );
607		size -= len;
608		ptr += len;
609	}
610
611	agebv->bv_len = ptr - agebv->bv_val;
612}
613
614static slap_callback nullsc;
615
616#define PURGE_INCREMENT	100
617
618typedef struct purge_data {
619	struct log_info *li;
620	int slots;
621	int used;
622	int mincsn_updated;
623	BerVarray dn;
624	BerVarray ndn;
625} purge_data;
626
627static int
628log_old_lookup( Operation *op, SlapReply *rs )
629{
630	purge_data *pd = op->o_callback->sc_private;
631	struct log_info *li = pd->li;
632	Attribute *a;
633
634	if ( rs->sr_type != REP_SEARCH) return 0;
635
636	if ( slapd_shutdown ) return 0;
637
638	/* Update minCSN */
639	a = attr_find( rs->sr_entry->e_attrs,
640		slap_schema.si_ad_entryCSN );
641	if ( a ) {
642		ber_len_t len = a->a_nvals[0].bv_len;
643		int i, sid;
644
645		/* Find the correct sid */
646		sid = slap_parse_csn_sid( &a->a_nvals[0] );
647		for ( i=0; i < li->li_numcsns; i++ ) {
648			if ( sid <= li->li_sids[i] ) break;
649		}
650		if ( i >= li->li_numcsns || sid != li->li_sids[i] ) {
651			Debug( LDAP_DEBUG_ANY, "log_old_lookup: "
652					"csn=%s with sid not in minCSN set!\n",
653					a->a_nvals[0].bv_val );
654		}
655
656		/* Paranoid len check, normalized CSNs are always the same length */
657		if ( len > li->li_mincsn[i].bv_len )
658			len = li->li_mincsn[i].bv_len;
659		if ( ber_bvcmp( &li->li_mincsn[i], &a->a_nvals[0] ) < 0 ) {
660			pd->mincsn_updated = 1;
661			AC_MEMCPY( li->li_mincsn[i].bv_val, a->a_nvals[0].bv_val, len );
662		}
663	}
664	if ( pd->used >= pd->slots ) {
665		pd->slots += PURGE_INCREMENT;
666		pd->dn = ch_realloc( pd->dn, pd->slots * sizeof( struct berval ));
667		pd->ndn = ch_realloc( pd->ndn, pd->slots * sizeof( struct berval ));
668	}
669	ber_dupbv( &pd->dn[pd->used], &rs->sr_entry->e_name );
670	ber_dupbv( &pd->ndn[pd->used], &rs->sr_entry->e_nname );
671	pd->used++;
672	return 0;
673}
674
675/* Periodically search for old entries in the log database and delete them */
676static void *
677accesslog_purge( void *ctx, void *arg )
678{
679	struct re_s *rtask = arg;
680	struct log_info *li = rtask->arg;
681
682	Connection conn = {0};
683	OperationBuffer opbuf;
684	Operation *op;
685	SlapReply rs = {REP_RESULT};
686	slap_callback cb = { NULL, log_old_lookup, NULL, NULL, NULL };
687	Filter f;
688	AttributeAssertion ava = ATTRIBUTEASSERTION_INIT;
689	purge_data pd = { .li = li };
690	char timebuf[LDAP_LUTIL_GENTIME_BUFSIZE];
691	char csnbuf[LDAP_PVT_CSNSTR_BUFSIZE];
692	time_t old = slap_get_time();
693
694	connection_fake_init( &conn, &opbuf, ctx );
695	op = &opbuf.ob_op;
696
697	f.f_choice = LDAP_FILTER_LE;
698	f.f_ava = &ava;
699	f.f_next = NULL;
700
701	ava.aa_desc = ad_reqStart;
702	ava.aa_value.bv_val = timebuf;
703	ava.aa_value.bv_len = sizeof(timebuf);
704
705	old -= li->li_age;
706	slap_timestamp( &old, &ava.aa_value );
707
708	op->o_tag = LDAP_REQ_SEARCH;
709	op->o_bd = li->li_db;
710	op->o_dn = li->li_db->be_rootdn;
711	op->o_ndn = li->li_db->be_rootndn;
712	op->o_req_dn = li->li_db->be_suffix[0];
713	op->o_req_ndn = li->li_db->be_nsuffix[0];
714	op->o_callback = &cb;
715	op->ors_scope = LDAP_SCOPE_ONELEVEL;
716	op->ors_deref = LDAP_DEREF_NEVER;
717	op->ors_tlimit = SLAP_NO_LIMIT;
718	op->ors_slimit = SLAP_NO_LIMIT;
719	op->ors_filter = &f;
720	filter2bv_x( op, &f, &op->ors_filterstr );
721	op->ors_attrs = slap_anlist_no_attrs;
722	op->ors_attrsonly = 1;
723
724	cb.sc_private = &pd;
725
726	op->o_bd->be_search( op, &rs );
727	op->o_tmpfree( op->ors_filterstr.bv_val, op->o_tmpmemctx );
728
729	if ( pd.used ) {
730		int i;
731
732		op->o_callback = &nullsc;
733		op->o_dont_replicate = 1;
734		op->o_csn = slap_empty_bv;
735
736		if ( pd.mincsn_updated ) {
737			Modifications mod;
738			/* update context's minCSN to reflect oldest CSN */
739			mod.sml_numvals = li->li_numcsns;
740			mod.sml_values = li->li_mincsn;
741			mod.sml_nvalues = NULL;
742			mod.sml_desc = ad_minCSN;
743			mod.sml_op = LDAP_MOD_REPLACE;
744			mod.sml_flags = SLAP_MOD_INTERNAL;
745			mod.sml_next = NULL;
746
747			op->o_tag = LDAP_REQ_MODIFY;
748			op->orm_modlist = &mod;
749			op->orm_no_opattrs = 1;
750			op->o_req_dn = li->li_db->be_suffix[0];
751			op->o_req_ndn = li->li_db->be_nsuffix[0];
752			op->o_no_schema_check = 1;
753			op->o_managedsait = SLAP_CONTROL_NONCRITICAL;
754			if ( !slapd_shutdown ) {
755				Debug( LDAP_DEBUG_SYNC, "accesslog_purge: "
756						"updating minCSN with %d values\n",
757						li->li_numcsns );
758				op->o_bd->be_modify( op, &rs );
759			}
760		}
761
762		/* delete the expired entries */
763		op->o_tag = LDAP_REQ_DELETE;
764		for (i=0; i<pd.used; i++) {
765			op->o_req_dn = pd.dn[i];
766			op->o_req_ndn = pd.ndn[i];
767			if ( !slapd_shutdown ) {
768				rs_reinit( &rs, REP_RESULT );
769				op->o_bd->be_delete( op, &rs );
770			}
771			ch_free( pd.ndn[i].bv_val );
772			ch_free( pd.dn[i].bv_val );
773			ldap_pvt_thread_pool_pausecheck( &connection_pool );
774		}
775		ch_free( pd.ndn );
776		ch_free( pd.dn );
777	}
778
779	ldap_pvt_thread_mutex_lock( &slapd_rq.rq_mutex );
780	ldap_pvt_runqueue_stoptask( &slapd_rq, rtask );
781	ldap_pvt_thread_mutex_unlock( &slapd_rq.rq_mutex );
782
783	return NULL;
784}
785
786static int
787log_cf_gen(ConfigArgs *c)
788{
789	slap_overinst *on = (slap_overinst *)c->bi;
790	struct log_info *li = on->on_bi.bi_private;
791	int rc = 0;
792	slap_mask_t tmask = 0;
793	char agebuf[2*STRLENOF("ddddd+hh:mm:ss  ")];
794	struct berval agebv, cyclebv;
795
796	switch( c->op ) {
797	case SLAP_CONFIG_EMIT:
798		switch( c->type ) {
799		case LOG_DB:
800			if ( !BER_BVISEMPTY( &li->li_db_suffix )) {
801				value_add_one( &c->rvalue_vals, &li->li_db_suffix );
802				value_add_one( &c->rvalue_nvals, &li->li_db_suffix );
803			} else if ( li->li_db ) {
804				value_add_one( &c->rvalue_vals, li->li_db->be_suffix );
805				value_add_one( &c->rvalue_nvals, li->li_db->be_nsuffix );
806			} else {
807				snprintf( c->cr_msg, sizeof( c->cr_msg ),
808					"accesslog: \"logdb <suffix>\" must be specified" );
809				Debug( LDAP_DEBUG_ANY, "%s: %s \"%s\"\n",
810					c->log, c->cr_msg, c->value_dn.bv_val );
811				rc = 1;
812				break;
813			}
814			break;
815		case LOG_OPS:
816			rc = mask_to_verbs( logops, li->li_ops, &c->rvalue_vals );
817			break;
818		case LOG_PURGE:
819			if ( !li->li_age ) {
820				rc = 1;
821				break;
822			}
823			agebv.bv_val = agebuf;
824			log_age_unparse( li->li_age, &agebv, sizeof( agebuf ) );
825			agebv.bv_val[agebv.bv_len] = ' ';
826			agebv.bv_len++;
827			cyclebv.bv_val = agebv.bv_val + agebv.bv_len;
828			log_age_unparse( li->li_cycle, &cyclebv, sizeof( agebuf ) - agebv.bv_len );
829			agebv.bv_len += cyclebv.bv_len;
830			value_add_one( &c->rvalue_vals, &agebv );
831			break;
832		case LOG_SUCCESS:
833			if ( li->li_success )
834				c->value_int = li->li_success;
835			else
836				rc = 1;
837			break;
838		case LOG_OLD:
839			if ( li->li_oldf ) {
840				filter2bv( li->li_oldf, &agebv );
841				ber_bvarray_add( &c->rvalue_vals, &agebv );
842			}
843			else
844				rc = 1;
845			break;
846		case LOG_OLDATTR:
847			if ( li->li_oldattrs ) {
848				log_attr *la;
849
850				for ( la = li->li_oldattrs; la; la=la->next )
851					value_add_one( &c->rvalue_vals, &la->attr->ad_cname );
852			}
853			else
854				rc = 1;
855			break;
856		case LOG_BASE:
857			if ( li->li_bases ) {
858				log_base *lb;
859
860				for ( lb = li->li_bases; lb; lb=lb->lb_next )
861					value_add_one( &c->rvalue_vals, &lb->lb_line );
862			}
863			else
864				rc = 1;
865			break;
866		}
867		break;
868	case LDAP_MOD_DELETE:
869		switch( c->type ) {
870		case LOG_DB:
871			/* noop. this should always be a valid backend. */
872			break;
873		case LOG_OPS:
874			if ( c->valx < 0 ) {
875				li->li_ops = 0;
876			} else {
877				rc = verbs_to_mask( 1, &c->line, logops, &tmask );
878				if ( rc == 0 )
879					li->li_ops &= ~tmask;
880			}
881			break;
882		case LOG_PURGE:
883			if ( li->li_task ) {
884				struct re_s *re = li->li_task;
885				li->li_task = NULL;
886				ldap_pvt_thread_mutex_lock( &slapd_rq.rq_mutex );
887				if ( ldap_pvt_runqueue_isrunning( &slapd_rq, re ))
888					ldap_pvt_runqueue_stoptask( &slapd_rq, re );
889				ldap_pvt_runqueue_remove( &slapd_rq, re );
890				ldap_pvt_thread_mutex_unlock( &slapd_rq.rq_mutex );
891			}
892			li->li_age = 0;
893			li->li_cycle = 0;
894			break;
895		case LOG_SUCCESS:
896			li->li_success = 0;
897			break;
898		case LOG_OLD:
899			if ( li->li_oldf ) {
900				filter_free( li->li_oldf );
901				li->li_oldf = NULL;
902			}
903			break;
904		case LOG_OLDATTR:
905			if ( c->valx < 0 ) {
906				log_attr *la, *ln;
907
908				for ( la = li->li_oldattrs; la; la = ln ) {
909					ln = la->next;
910					ch_free( la );
911				}
912			} else {
913				log_attr *la = NULL, **lp;
914				int i;
915
916				for ( lp = &li->li_oldattrs, i=0; i < c->valx; i++ ) {
917					la = *lp;
918					lp = &la->next;
919				}
920				*lp = la->next;
921				ch_free( la );
922			}
923			break;
924		case LOG_BASE:
925			if ( c->valx < 0 ) {
926				log_base *lb, *ln;
927
928				for ( lb = li->li_bases; lb; lb = ln ) {
929					ln = lb->lb_next;
930					ch_free( lb );
931				}
932			} else {
933				log_base *lb = NULL, **lp;
934				int i;
935
936				for ( lp = &li->li_bases, i=0; i < c->valx; i++ ) {
937					lb = *lp;
938					lp = &lb->lb_next;
939				}
940				*lp = lb->lb_next;
941				ch_free( lb );
942			}
943			break;
944		}
945		break;
946	default:
947		switch( c->type ) {
948		case LOG_DB:
949			if ( CONFIG_ONLINE_ADD( c )) {
950				li->li_db = select_backend( &c->value_ndn, 0 );
951				if ( !li->li_db ) {
952					snprintf( c->cr_msg, sizeof( c->cr_msg ),
953						"<%s> no matching backend found for suffix",
954						c->argv[0] );
955					Debug( LDAP_DEBUG_ANY, "%s: %s \"%s\"\n",
956						c->log, c->cr_msg, c->value_dn.bv_val );
957					rc = 1;
958				}
959				if ( !rc && ( li->li_db->bd_self == c->be->bd_self )) {
960					snprintf( c->cr_msg, sizeof( c->cr_msg ),
961						"<%s> invalid suffix, points to itself",
962						c->argv[0] );
963					Debug( LDAP_DEBUG_ANY, "%s: %s \"%s\"\n",
964						c->log, c->cr_msg, c->value_dn.bv_val );
965					rc = 1;
966				}
967				ch_free( c->value_ndn.bv_val );
968			} else {
969				li->li_db_suffix = c->value_ndn;
970			}
971			ch_free( c->value_dn.bv_val );
972			break;
973		case LOG_OPS:
974			rc = verbs_to_mask( c->argc, c->argv, logops, &tmask );
975			if ( rc == 0 )
976				li->li_ops |= tmask;
977			break;
978		case LOG_PURGE:
979			li->li_age = log_age_parse( c->argv[1] );
980			if ( li->li_age < 1 ) {
981				rc = 1;
982			} else {
983				li->li_cycle = log_age_parse( c->argv[2] );
984				if ( li->li_cycle < 1 ) {
985					rc = 1;
986				} else if ( slapMode & SLAP_SERVER_MODE ) {
987					struct re_s *re = li->li_task;
988					if ( re )
989						re->interval.tv_sec = li->li_cycle;
990					else {
991						ldap_pvt_thread_mutex_lock( &slapd_rq.rq_mutex );
992						li->li_task = ldap_pvt_runqueue_insert( &slapd_rq,
993							li->li_cycle, accesslog_purge, li,
994							"accesslog_purge", li->li_db ?
995								li->li_db->be_suffix[0].bv_val :
996								c->be->be_suffix[0].bv_val );
997						ldap_pvt_thread_mutex_unlock( &slapd_rq.rq_mutex );
998					}
999				}
1000			}
1001			break;
1002		case LOG_SUCCESS:
1003			li->li_success = c->value_int;
1004			break;
1005		case LOG_OLD:
1006			li->li_oldf = str2filter( c->argv[1] );
1007			if ( !li->li_oldf ) {
1008				snprintf( c->cr_msg, sizeof( c->cr_msg ), "bad filter!" );
1009				rc = 1;
1010			}
1011			break;
1012		case LOG_OLDATTR: {
1013			int i;
1014			AttributeDescription *ad;
1015			const char *text;
1016
1017			for ( i=1; i< c->argc; i++ ) {
1018				ad = NULL;
1019				if ( slap_str2ad( c->argv[i], &ad, &text ) == LDAP_SUCCESS ) {
1020					log_attr *la = ch_malloc( sizeof( log_attr ));
1021					la->attr = ad;
1022					la->next = li->li_oldattrs;
1023					li->li_oldattrs = la;
1024				} else {
1025					snprintf( c->cr_msg, sizeof( c->cr_msg ), "%s <%s>: %s",
1026						c->argv[0], c->argv[i], text );
1027					Debug( LDAP_DEBUG_CONFIG|LDAP_DEBUG_NONE,
1028						"%s: %s\n", c->log, c->cr_msg );
1029					rc = ARG_BAD_CONF;
1030					break;
1031				}
1032			}
1033			}
1034			break;
1035		case LOG_BASE: {
1036			slap_mask_t m = 0;
1037			rc = verbstring_to_mask( logops, c->argv[1], '|', &m );
1038			if ( rc == 0 ) {
1039				struct berval dn, ndn;
1040				ber_str2bv( c->argv[2], 0, 0, &dn );
1041				rc = dnNormalize( 0, NULL, NULL, &dn, &ndn, NULL );
1042				if ( rc == 0 ) {
1043					log_base *lb;
1044					struct berval mbv;
1045					char *ptr;
1046					mask_to_verbstring( logops, m, '|', &mbv );
1047					lb = ch_malloc( sizeof( log_base ) + mbv.bv_len + ndn.bv_len + 3 + 1 );
1048					lb->lb_line.bv_val = (char *)(lb + 1);
1049					lb->lb_line.bv_len = mbv.bv_len + ndn.bv_len + 3;
1050					ptr = lutil_strcopy( lb->lb_line.bv_val, mbv.bv_val );
1051					*ptr++ = ' ';
1052					*ptr++ = '"';
1053					lb->lb_base.bv_val = ptr;
1054					lb->lb_base.bv_len = ndn.bv_len;
1055					ptr = lutil_strcopy( ptr, ndn.bv_val );
1056					*ptr++ = '"';
1057					lb->lb_ops = m;
1058					lb->lb_next = li->li_bases;
1059					li->li_bases = lb;
1060				} else {
1061					snprintf( c->cr_msg, sizeof( c->cr_msg ), "%s invalid DN: %s",
1062						c->argv[0], c->argv[2] );
1063					Debug( LDAP_DEBUG_CONFIG|LDAP_DEBUG_NONE,
1064						"%s: %s\n", c->log, c->cr_msg );
1065					rc = ARG_BAD_CONF;
1066				}
1067			} else {
1068				snprintf( c->cr_msg, sizeof( c->cr_msg ), "%s invalid ops: %s",
1069					c->argv[0], c->argv[1] );
1070				Debug( LDAP_DEBUG_CONFIG|LDAP_DEBUG_NONE,
1071					"%s: %s\n", c->log, c->cr_msg );
1072				rc = ARG_BAD_CONF;
1073			}
1074			}
1075			break;
1076		}
1077		break;
1078	}
1079	return rc;
1080}
1081
1082static int
1083logSchemaControlValidate(
1084	Syntax		*syntax,
1085	struct berval	*valp )
1086{
1087	struct berval	val, bv;
1088	ber_len_t		i;
1089	int		rc = LDAP_SUCCESS;
1090
1091	assert( valp != NULL );
1092
1093	val = *valp;
1094
1095	/* check minimal size */
1096	if ( val.bv_len < STRLENOF( "{*}" ) ) {
1097		return LDAP_INVALID_SYNTAX;
1098	}
1099
1100	val.bv_len--;
1101
1102	/* check SEQUENCE boundaries */
1103	if ( val.bv_val[ 0 ] != '{' /*}*/ ||
1104		val.bv_val[ val.bv_len ] != /*{*/ '}' )
1105	{
1106		return LDAP_INVALID_SYNTAX;
1107	}
1108
1109	/* extract and check OID */
1110	for ( i = 1; i < val.bv_len; i++ ) {
1111		if ( !ASCII_SPACE( val.bv_val[ i ] ) ) {
1112			break;
1113		}
1114	}
1115
1116	bv.bv_val = &val.bv_val[ i ];
1117
1118	for ( i++; i < val.bv_len; i++ ) {
1119		if ( ASCII_SPACE( val.bv_val[ i ] ) )
1120		{
1121			break;
1122		}
1123	}
1124
1125	bv.bv_len = &val.bv_val[ i ] - bv.bv_val;
1126
1127	rc = numericoidValidate( NULL, &bv );
1128	if ( rc != LDAP_SUCCESS ) {
1129		return rc;
1130	}
1131
1132	if ( i == val.bv_len ) {
1133		return LDAP_SUCCESS;
1134	}
1135
1136	if ( val.bv_val[ i ] != ' ' ) {
1137		return LDAP_INVALID_SYNTAX;
1138	}
1139
1140	for ( i++; i < val.bv_len; i++ ) {
1141		if ( !ASCII_SPACE( val.bv_val[ i ] ) ) {
1142			break;
1143		}
1144	}
1145
1146	if ( i == val.bv_len ) {
1147		return LDAP_SUCCESS;
1148	}
1149
1150	/* extract and check criticality */
1151	if ( strncasecmp( &val.bv_val[ i ], "criticality ", STRLENOF( "criticality " ) ) == 0 )
1152	{
1153		i += STRLENOF( "criticality " );
1154		for ( ; i < val.bv_len; i++ ) {
1155			if ( !ASCII_SPACE( val.bv_val[ i ] ) ) {
1156				break;
1157			}
1158		}
1159
1160		if ( i == val.bv_len ) {
1161			return LDAP_INVALID_SYNTAX;
1162		}
1163
1164		bv.bv_val = &val.bv_val[ i ];
1165
1166		for ( ; i < val.bv_len; i++ ) {
1167			if ( ASCII_SPACE( val.bv_val[ i ] ) ) {
1168				break;
1169			}
1170		}
1171
1172		bv.bv_len = &val.bv_val[ i ] - bv.bv_val;
1173
1174		if ( !bvmatch( &bv, &slap_true_bv ) && !bvmatch( &bv, &slap_false_bv ) )
1175		{
1176			return LDAP_INVALID_SYNTAX;
1177		}
1178
1179		if ( i == val.bv_len ) {
1180			return LDAP_SUCCESS;
1181		}
1182
1183		if ( val.bv_val[ i ] != ' ' ) {
1184			return LDAP_INVALID_SYNTAX;
1185		}
1186
1187		for ( i++; i < val.bv_len; i++ ) {
1188			if ( !ASCII_SPACE( val.bv_val[ i ] ) ) {
1189				break;
1190			}
1191		}
1192
1193		if ( i == val.bv_len ) {
1194			return LDAP_SUCCESS;
1195		}
1196	}
1197
1198	/* extract and check controlValue */
1199	if ( strncasecmp( &val.bv_val[ i ], "controlValue ", STRLENOF( "controlValue " ) ) == 0 )
1200	{
1201		ber_len_t valueStart, valueLen;
1202
1203		i += STRLENOF( "controlValue " );
1204		for ( ; i < val.bv_len; i++ ) {
1205			if ( !ASCII_SPACE( val.bv_val[ i ] ) ) {
1206				break;
1207			}
1208		}
1209
1210		if ( i == val.bv_len ) {
1211			return LDAP_INVALID_SYNTAX;
1212		}
1213
1214		if ( val.bv_val[ i ] != '"' ) {
1215			return LDAP_INVALID_SYNTAX;
1216		}
1217
1218		i++;
1219		valueStart = i;
1220
1221		for ( ; i < val.bv_len; i++ ) {
1222			if ( val.bv_val[ i ] == '"' ) {
1223				break;
1224			}
1225
1226			if ( !ASCII_HEX( val.bv_val[ i ] ) ) {
1227				return LDAP_INVALID_SYNTAX;
1228			}
1229		}
1230
1231		if ( val.bv_val[ i ] != '"' ) {
1232			return LDAP_INVALID_SYNTAX;
1233		}
1234
1235		valueLen = i - valueStart;
1236		if ( (valueLen/2)*2 != valueLen ) {
1237			return LDAP_INVALID_SYNTAX;
1238		}
1239
1240		for ( i++; i < val.bv_len; i++ ) {
1241			if ( !ASCII_SPACE( val.bv_val[ i ] ) ) {
1242				break;
1243			}
1244		}
1245
1246		if ( i == val.bv_len ) {
1247			return LDAP_SUCCESS;
1248		}
1249	}
1250
1251	return LDAP_INVALID_SYNTAX;
1252}
1253
1254static int
1255accesslog_ctrls(
1256	LDAPControl **ctrls,
1257	BerVarray *valsp,
1258	BerVarray *nvalsp,
1259	void *memctx )
1260{
1261	long		i, rc = 0;
1262
1263	assert( valsp != NULL );
1264	assert( ctrls != NULL );
1265
1266	*valsp = NULL;
1267	*nvalsp = NULL;
1268
1269	for ( i = 0; ctrls[ i ] != NULL; i++ ) {
1270		struct berval	idx,
1271				oid,
1272				noid,
1273				bv;
1274		char		*ptr,
1275				buf[ 32 ];
1276
1277		if ( ctrls[ i ]->ldctl_oid == NULL ) {
1278			return LDAP_PROTOCOL_ERROR;
1279		}
1280
1281		idx.bv_len = snprintf( buf, sizeof( buf ), "{%ld}", i );
1282		idx.bv_val = buf;
1283
1284		ber_str2bv( ctrls[ i ]->ldctl_oid, 0, 0, &oid );
1285		noid.bv_len = idx.bv_len + oid.bv_len;
1286		ptr = noid.bv_val = ber_memalloc_x( noid.bv_len + 1, memctx );
1287		ptr = lutil_strcopy( ptr, idx.bv_val );
1288		ptr = lutil_strcopy( ptr, oid.bv_val );
1289
1290		bv.bv_len = idx.bv_len + STRLENOF( "{}" ) + oid.bv_len;
1291
1292		if ( ctrls[ i ]->ldctl_iscritical ) {
1293			bv.bv_len += STRLENOF( " criticality TRUE" );
1294		}
1295
1296		if ( !BER_BVISNULL( &ctrls[ i ]->ldctl_value ) ) {
1297			bv.bv_len += STRLENOF( " controlValue \"\"" )
1298				+ 2 * ctrls[ i ]->ldctl_value.bv_len;
1299		}
1300
1301		ptr = bv.bv_val = ber_memalloc_x( bv.bv_len + 1, memctx );
1302		if ( ptr == NULL ) {
1303			ber_bvarray_free( *valsp );
1304			*valsp = NULL;
1305			ber_bvarray_free( *nvalsp );
1306			*nvalsp = NULL;
1307			return LDAP_OTHER;
1308		}
1309
1310		ptr = lutil_strcopy( ptr, idx.bv_val );
1311
1312		*ptr++ = '{' /*}*/ ;
1313		ptr = lutil_strcopy( ptr, oid.bv_val );
1314
1315		if ( ctrls[ i ]->ldctl_iscritical ) {
1316			ptr = lutil_strcopy( ptr, " criticality TRUE" );
1317		}
1318
1319		if ( !BER_BVISNULL( &ctrls[ i ]->ldctl_value ) ) {
1320			ber_len_t	j;
1321
1322			ptr = lutil_strcopy( ptr, " controlValue \"" );
1323			for ( j = 0; j < ctrls[ i ]->ldctl_value.bv_len; j++ ) {
1324				*ptr++ = SLAP_ESCAPE_HI(ctrls[ i ]->ldctl_value.bv_val[ j ]);
1325				*ptr++ = SLAP_ESCAPE_LO(ctrls[ i ]->ldctl_value.bv_val[ j ]);
1326			}
1327
1328			*ptr++ = '"';
1329		}
1330
1331		*ptr++ = '}';
1332		*ptr = '\0';
1333
1334		ber_bvarray_add_x( valsp, &bv, memctx );
1335		ber_bvarray_add_x( nvalsp, &noid, memctx );
1336	}
1337
1338	return rc;
1339
1340}
1341
1342static Entry *accesslog_entry( Operation *op, SlapReply *rs,
1343	log_info *li, int logop, Operation *op2 ) {
1344
1345	char rdnbuf[STRLENOF(RDNEQ)+LDAP_LUTIL_GENTIME_BUFSIZE+8];
1346	char nrdnbuf[STRLENOF(RDNEQ)+LDAP_LUTIL_GENTIME_BUFSIZE+8];
1347
1348	struct berval rdn, nrdn, timestamp, ntimestamp, bv;
1349	slap_verbmasks *lo = logops+logop+EN_OFFSET;
1350
1351	Entry *e = entry_alloc();
1352
1353	strcpy( rdnbuf, RDNEQ );
1354	rdn.bv_val = rdnbuf;
1355	strcpy( nrdnbuf, RDNEQ );
1356	nrdn.bv_val = nrdnbuf;
1357
1358	timestamp.bv_val = rdnbuf+STRLENOF(RDNEQ);
1359	timestamp.bv_len = sizeof(rdnbuf) - STRLENOF(RDNEQ);
1360	slap_timestamp( &op->o_time, &timestamp );
1361	snprintf( timestamp.bv_val + timestamp.bv_len-1, sizeof(".123456Z"), ".%06dZ", op->o_tincr );
1362	timestamp.bv_len += STRLENOF(".123456");
1363
1364	rdn.bv_len = STRLENOF(RDNEQ)+timestamp.bv_len;
1365	ad_reqStart->ad_type->sat_equality->smr_normalize(
1366		SLAP_MR_VALUE_OF_ASSERTION_SYNTAX, ad_reqStart->ad_type->sat_syntax,
1367		ad_reqStart->ad_type->sat_equality, &timestamp, &ntimestamp,
1368		op->o_tmpmemctx );
1369
1370	strcpy( nrdn.bv_val + STRLENOF(RDNEQ), ntimestamp.bv_val );
1371	nrdn.bv_len = STRLENOF(RDNEQ)+ntimestamp.bv_len;
1372	build_new_dn( &e->e_name, li->li_db->be_suffix, &rdn, NULL );
1373	build_new_dn( &e->e_nname, li->li_db->be_nsuffix, &nrdn, NULL );
1374
1375	attr_merge_one( e, slap_schema.si_ad_objectClass,
1376		&log_ocs[logop]->soc_cname, NULL );
1377	attr_merge_one( e, slap_schema.si_ad_structuralObjectClass,
1378		&log_ocs[logop]->soc_cname, NULL );
1379	attr_merge_one( e, ad_reqStart, &timestamp, &ntimestamp );
1380	op->o_tmpfree( ntimestamp.bv_val, op->o_tmpmemctx );
1381
1382	slap_op_time( &op2->o_time, &op2->o_tincr );
1383
1384	timestamp.bv_len = sizeof(rdnbuf) - STRLENOF(RDNEQ);
1385	slap_timestamp( &op2->o_time, &timestamp );
1386	snprintf( timestamp.bv_val + timestamp.bv_len-1, sizeof(".123456Z"), ".%06dZ", op2->o_tincr );
1387	timestamp.bv_len += STRLENOF(".123456");
1388
1389	attr_merge_normalize_one( e, ad_reqEnd, &timestamp, op->o_tmpmemctx );
1390
1391	/* Exops have OID appended */
1392	if ( logop == LOG_EN_EXTENDED ) {
1393		bv.bv_len = lo->word.bv_len + op->ore_reqoid.bv_len + 2;
1394		bv.bv_val = ch_malloc( bv.bv_len + 1 );
1395		AC_MEMCPY( bv.bv_val, lo->word.bv_val, lo->word.bv_len );
1396		bv.bv_val[lo->word.bv_len] = '{';
1397		AC_MEMCPY( bv.bv_val+lo->word.bv_len+1, op->ore_reqoid.bv_val,
1398			op->ore_reqoid.bv_len );
1399		bv.bv_val[bv.bv_len-1] = '}';
1400		bv.bv_val[bv.bv_len] = '\0';
1401		attr_merge_one( e, ad_reqType, &bv, NULL );
1402	} else {
1403		attr_merge_one( e, ad_reqType, &lo->word, NULL );
1404	}
1405
1406	rdn.bv_len = snprintf( rdn.bv_val, sizeof( rdnbuf ), "%lu", op->o_connid );
1407	if ( rdn.bv_len < sizeof( rdnbuf ) ) {
1408		attr_merge_one( e, ad_reqSession, &rdn, NULL );
1409	} /* else? */
1410
1411	if ( BER_BVISNULL( &op->o_dn ) ) {
1412		attr_merge_one( e, ad_reqAuthzID, (struct berval *)&slap_empty_bv,
1413			(struct berval *)&slap_empty_bv );
1414	} else {
1415		attr_merge_one( e, ad_reqAuthzID, &op->o_dn, &op->o_ndn );
1416	}
1417
1418	/* FIXME: need to add reqControls and reqRespControls */
1419	if ( op->o_ctrls ) {
1420		BerVarray	vals = NULL,
1421				nvals = NULL;
1422
1423		if ( accesslog_ctrls( op->o_ctrls, &vals, &nvals,
1424			op->o_tmpmemctx ) == LDAP_SUCCESS && vals )
1425		{
1426			attr_merge( e, ad_reqControls, vals, nvals );
1427			ber_bvarray_free_x( vals, op->o_tmpmemctx );
1428			ber_bvarray_free_x( nvals, op->o_tmpmemctx );
1429		}
1430	}
1431
1432	if ( rs->sr_ctrls ) {
1433		BerVarray	vals = NULL,
1434				nvals = NULL;
1435
1436		if ( accesslog_ctrls( rs->sr_ctrls, &vals, &nvals,
1437			op->o_tmpmemctx ) == LDAP_SUCCESS && vals )
1438		{
1439			attr_merge( e, ad_reqRespControls, vals, nvals );
1440			ber_bvarray_free_x( vals, op->o_tmpmemctx );
1441			ber_bvarray_free_x( nvals, op->o_tmpmemctx );
1442		}
1443
1444	}
1445
1446	return e;
1447}
1448
1449static struct berval scopes[] = {
1450	BER_BVC("base"),
1451	BER_BVC("one"),
1452	BER_BVC("sub"),
1453	BER_BVC("subord")
1454};
1455
1456static struct berval derefs[] = {
1457	BER_BVC("never"),
1458	BER_BVC("searching"),
1459	BER_BVC("finding"),
1460	BER_BVC("always")
1461};
1462
1463static struct berval simple = BER_BVC("SIMPLE");
1464
1465static void accesslog_val2val(AttributeDescription *ad, struct berval *val,
1466	char c_op, struct berval *dst) {
1467	char *ptr;
1468
1469	dst->bv_len = ad->ad_cname.bv_len + val->bv_len + 2;
1470	if ( c_op ) dst->bv_len++;
1471
1472	dst->bv_val = ch_malloc( dst->bv_len+1 );
1473
1474	ptr = lutil_strcopy( dst->bv_val, ad->ad_cname.bv_val );
1475	*ptr++ = ':';
1476	if ( c_op )
1477		*ptr++ = c_op;
1478	*ptr++ = ' ';
1479	AC_MEMCPY( ptr, val->bv_val, val->bv_len );
1480	dst->bv_val[dst->bv_len] = '\0';
1481}
1482
1483static int
1484accesslog_op2logop( Operation *op )
1485{
1486	switch ( op->o_tag ) {
1487	case LDAP_REQ_ADD:		return LOG_EN_ADD;
1488	case LDAP_REQ_DELETE:	return LOG_EN_DELETE;
1489	case LDAP_REQ_MODIFY:	return LOG_EN_MODIFY;
1490	case LDAP_REQ_MODRDN:	return LOG_EN_MODRDN;
1491	case LDAP_REQ_COMPARE:	return LOG_EN_COMPARE;
1492	case LDAP_REQ_SEARCH:	return LOG_EN_SEARCH;
1493	case LDAP_REQ_BIND:		return LOG_EN_BIND;
1494	case LDAP_REQ_EXTENDED:	return LOG_EN_EXTENDED;
1495	default:	/* unknown operation type */
1496		break;
1497	}	/* Unbind and Abandon never reach here */
1498	return LOG_EN_UNKNOWN;
1499}
1500
1501static int accesslog_response(Operation *op, SlapReply *rs) {
1502	slap_overinst *on = (slap_overinst *)op->o_callback->sc_private;
1503	log_info *li = on->on_bi.bi_private;
1504	Attribute *a, *last_attr;
1505	Modifications *m;
1506	struct berval *b, uuid = BER_BVNULL;
1507	int i;
1508	int logop;
1509	slap_verbmasks *lo;
1510	Entry *e = NULL, *old = NULL, *e_uuid = NULL;
1511	char timebuf[LDAP_LUTIL_GENTIME_BUFSIZE+8];
1512	struct berval bv, bv2 = BER_BVNULL;
1513	char *ptr;
1514	BerVarray vals;
1515	Operation op2 = {0};
1516	SlapReply rs2 = {REP_RESULT};
1517
1518	/* ITS#9051 Make sure we only remove the callback on a final response */
1519	if ( rs->sr_type == REP_RESULT || rs->sr_type == REP_EXTENDED ||
1520			rs->sr_type == REP_SASL ) {
1521		slap_callback *sc = op->o_callback;
1522		op->o_callback = sc->sc_next;
1523		op->o_tmpfree(sc, op->o_tmpmemctx );
1524	}
1525
1526	if ( rs->sr_type != REP_RESULT && rs->sr_type != REP_EXTENDED )
1527		return SLAP_CB_CONTINUE;
1528
1529	/* can't do anything if logDB isn't open */
1530	if ( !SLAP_DBOPEN( li->li_db ))
1531		return SLAP_CB_CONTINUE;
1532
1533	logop = accesslog_op2logop( op );
1534	lo = logops+logop+EN_OFFSET;
1535	if ( !( li->li_ops & lo->mask )) {
1536		log_base *lb;
1537
1538		i = 0;
1539		for ( lb = li->li_bases; lb; lb=lb->lb_next )
1540			if (( lb->lb_ops & lo->mask ) && dnIsSuffix( &op->o_req_ndn, &lb->lb_base )) {
1541				i = 1;
1542				break;
1543			}
1544		if ( !i )
1545			return SLAP_CB_CONTINUE;
1546	}
1547
1548	/* mutex and so were only set for write operations;
1549	 * if we got here, the operation must be logged */
1550	if ( lo->mask & LOG_OP_WRITES ) {
1551		slap_callback *cb;
1552
1553		/* These internal ops are not logged */
1554		if ( op->o_dont_replicate )
1555			return SLAP_CB_CONTINUE;
1556
1557		ldap_pvt_thread_mutex_lock( &li->li_log_mutex );
1558		old = li->li_old;
1559		uuid = li->li_uuid;
1560		li->li_old = NULL;
1561		BER_BVZERO( &li->li_uuid );
1562#ifdef RMUTEX_DEBUG
1563		Debug( LDAP_DEBUG_SYNC,
1564			"accesslog_response: unlocking rmutex for tid %x\n",
1565			op->o_tid );
1566#endif
1567		ldap_pvt_thread_mutex_unlock( &li->li_op_rmutex );
1568	}
1569
1570	/* ignore these internal reads */
1571	if (( lo->mask & LOG_OP_READS ) && op->o_do_not_cache ) {
1572		return SLAP_CB_CONTINUE;
1573	}
1574
1575	/*
1576	 * ITS#9051 Technically LDAP_REFERRAL and LDAP_SASL_BIND_IN_PROGRESS
1577	 * are not errors, but they aren't really success either
1578	 */
1579	if ( li->li_success && rs->sr_err != LDAP_SUCCESS &&
1580			rs->sr_err != LDAP_COMPARE_TRUE &&
1581			rs->sr_err != LDAP_COMPARE_FALSE )
1582		goto done;
1583
1584	e = accesslog_entry( op, rs, li, logop, &op2 );
1585
1586	if ( !BER_BVISNULL( &op->o_req_ndn ))
1587		attr_merge_one( e, ad_reqDN, &op->o_req_dn, &op->o_req_ndn );
1588
1589	if ( rs->sr_text ) {
1590		ber_str2bv( rs->sr_text, 0, 0, &bv );
1591		attr_merge_normalize_one( e, ad_reqMessage, &bv, op->o_tmpmemctx );
1592	}
1593	bv.bv_len = snprintf( timebuf, sizeof( timebuf ), "%d", rs->sr_err );
1594	if ( bv.bv_len < sizeof( timebuf ) ) {
1595		bv.bv_val = timebuf;
1596		attr_merge_one( e, ad_reqResult, &bv, NULL );
1597	}
1598
1599	last_attr = attr_find( e->e_attrs, ad_reqResult );
1600
1601	e_uuid = old;
1602	switch( logop ) {
1603	case LOG_EN_ADD:
1604	case LOG_EN_DELETE: {
1605		char c_op;
1606		Entry *e2;
1607
1608		if ( logop == LOG_EN_ADD ) {
1609			e2 = op->ora_e;
1610			e_uuid = op->ora_e;
1611			c_op = '+';
1612
1613		} else {
1614			if ( !old )
1615				break;
1616			e2 = old;
1617			c_op = 0;
1618		}
1619		/* count all the vals */
1620		i = 0;
1621		for ( a=e2->e_attrs; a; a=a->a_next ) {
1622			i += a->a_numvals;
1623		}
1624		vals = ch_malloc( (i+1) * sizeof( struct berval ));
1625		i = 0;
1626		for ( a=e2->e_attrs; a; a=a->a_next ) {
1627			if ( a->a_vals ) {
1628				for (b=a->a_vals; !BER_BVISNULL( b ); b++,i++) {
1629					accesslog_val2val( a->a_desc, b, c_op, &vals[i] );
1630				}
1631			}
1632		}
1633		vals[i].bv_val = NULL;
1634		vals[i].bv_len = 0;
1635		a = attr_alloc( logop == LOG_EN_ADD ? ad_reqMod : ad_reqOld );
1636		a->a_numvals = i;
1637		a->a_vals = vals;
1638		a->a_nvals = vals;
1639		last_attr->a_next = a;
1640		break;
1641	}
1642
1643	case LOG_EN_MODRDN:
1644	case LOG_EN_MODIFY:
1645		/* count all the mods + attributes (ITS#6545) */
1646		i = 0;
1647		for ( m = op->orm_modlist; m; m = m->sml_next ) {
1648			if ( m->sml_values ) {
1649				i += m->sml_numvals;
1650			} else if ( m->sml_op == LDAP_MOD_DELETE ||
1651				m->sml_op == SLAP_MOD_SOFTDEL ||
1652				m->sml_op == LDAP_MOD_REPLACE )
1653			{
1654				i++;
1655			}
1656			if ( m->sml_next && m->sml_desc == m->sml_next->sml_desc ) {
1657				i++;
1658			}
1659		}
1660		vals = ch_malloc( (i+1) * sizeof( struct berval ));
1661		i = 0;
1662
1663		/* init flags on old entry */
1664		if ( old ) {
1665			for ( a = old->e_attrs; a; a = a->a_next ) {
1666				log_attr *la;
1667				a->a_flags = 0;
1668
1669				/* look for attrs that are always logged */
1670				for ( la = li->li_oldattrs; la; la = la->next ) {
1671					if ( a->a_desc == la->attr ) {
1672						a->a_flags = 1;
1673					}
1674				}
1675			}
1676		}
1677
1678		for ( m = op->orm_modlist; m; m = m->sml_next ) {
1679			/* Mark this attribute as modified */
1680			if ( old ) {
1681				a = attr_find( old->e_attrs, m->sml_desc );
1682				if ( a ) {
1683					a->a_flags = 1;
1684				}
1685			}
1686
1687			/* don't log the RDN mods; they're explicitly logged later */
1688			if ( logop == LOG_EN_MODRDN &&
1689			 	( m->sml_op == SLAP_MOD_SOFTADD ||
1690				  m->sml_op == LDAP_MOD_DELETE ) )
1691			{
1692				continue;
1693			}
1694
1695			if ( m->sml_values ) {
1696				for ( b = m->sml_values; !BER_BVISNULL( b ); b++, i++ ) {
1697					char c_op;
1698
1699					switch ( m->sml_op ) {
1700					case LDAP_MOD_ADD:	/* FALLTHRU */
1701					case SLAP_MOD_SOFTADD: c_op = '+'; break;
1702					case LDAP_MOD_DELETE: /* FALLTHRU */
1703					case SLAP_MOD_SOFTDEL: c_op = '-'; break;
1704					case LDAP_MOD_REPLACE:	c_op = '='; break;
1705					case LDAP_MOD_INCREMENT:	c_op = '#'; break;
1706
1707					/* unknown op. there shouldn't be any of these. we
1708					 * don't know what to do with it, but we shouldn't just
1709					 * ignore it.
1710					 */
1711					default: c_op = '?'; break;
1712					}
1713					accesslog_val2val( m->sml_desc, b, c_op, &vals[i] );
1714				}
1715			} else if ( m->sml_op == LDAP_MOD_DELETE ||
1716				m->sml_op == SLAP_MOD_SOFTDEL ||
1717				m->sml_op == LDAP_MOD_REPLACE )
1718			{
1719				vals[i].bv_len = m->sml_desc->ad_cname.bv_len + 2;
1720				vals[i].bv_val = ch_malloc( vals[i].bv_len + 1 );
1721				ptr = lutil_strcopy( vals[i].bv_val,
1722					m->sml_desc->ad_cname.bv_val );
1723				*ptr++ = ':';
1724				if ( m->sml_op == LDAP_MOD_DELETE || m->sml_op == SLAP_MOD_SOFTDEL ) {
1725					*ptr++ = '-';
1726				} else {
1727					*ptr++ = '=';
1728				}
1729				*ptr = '\0';
1730				i++;
1731			}
1732			/* ITS#6545: when the same attribute is edited multiple times,
1733			 * record the transition */
1734			if ( m->sml_next && m->sml_desc == m->sml_next->sml_desc &&
1735					m->sml_op == m->sml_next->sml_op ) {
1736				ber_str2bv( ":", STRLENOF(":"), 1, &vals[i] );
1737				i++;
1738			}
1739		}
1740
1741		if ( i > 0 ) {
1742			BER_BVZERO( &vals[i] );
1743			a = attr_alloc( ad_reqMod );
1744			a->a_numvals = i;
1745			a->a_vals = vals;
1746			a->a_nvals = vals;
1747			last_attr->a_next = a;
1748			last_attr = a;
1749
1750		} else {
1751			ch_free( vals );
1752		}
1753
1754		if ( old ) {
1755			/* count all the vals */
1756			i = 0;
1757			for ( a = old->e_attrs; a != NULL; a = a->a_next ) {
1758				if ( a->a_vals && a->a_flags ) {
1759					i += a->a_numvals;
1760				}
1761			}
1762			if ( i ) {
1763				vals = ch_malloc( (i + 1) * sizeof( struct berval ) );
1764				i = 0;
1765				for ( a=old->e_attrs; a; a=a->a_next ) {
1766					if ( a->a_vals && a->a_flags ) {
1767						for (b=a->a_vals; !BER_BVISNULL( b ); b++,i++) {
1768							accesslog_val2val( a->a_desc, b, 0, &vals[i] );
1769						}
1770					}
1771				}
1772				vals[i].bv_val = NULL;
1773				vals[i].bv_len = 0;
1774				a = attr_alloc( ad_reqOld );
1775				a->a_numvals = i;
1776				a->a_vals = vals;
1777				a->a_nvals = vals;
1778				last_attr->a_next = a;
1779			}
1780		}
1781		if ( logop == LOG_EN_MODIFY ) {
1782			break;
1783		}
1784
1785		/* Now log the actual modRDN info */
1786		attr_merge_one( e, ad_reqNewRDN, &op->orr_newrdn, &op->orr_nnewrdn );
1787		attr_merge_one( e, ad_reqDeleteOldRDN, op->orr_deleteoldrdn ?
1788			(struct berval *)&slap_true_bv : (struct berval *)&slap_false_bv,
1789			NULL );
1790		if ( op->orr_newSup ) {
1791			attr_merge_one( e, ad_reqNewSuperior, op->orr_newSup, op->orr_nnewSup );
1792			bv2 = *op->orr_nnewSup;
1793		} else {
1794			dnParent( &op->o_req_ndn, &bv2 );
1795		}
1796		build_new_dn( &bv, &bv2, &op->orr_nnewrdn, op->o_tmpmemctx );
1797		attr_merge_one( e, ad_reqNewDN, &bv, NULL );
1798		op->o_tmpfree( bv.bv_val, op->o_tmpmemctx );
1799		break;
1800
1801	case LOG_EN_COMPARE:
1802		bv.bv_len = op->orc_ava->aa_desc->ad_cname.bv_len + 1 +
1803			op->orc_ava->aa_value.bv_len;
1804		bv.bv_val = op->o_tmpalloc( bv.bv_len+1, op->o_tmpmemctx );
1805		ptr = lutil_strcopy( bv.bv_val, op->orc_ava->aa_desc->ad_cname.bv_val );
1806		*ptr++ = '=';
1807		AC_MEMCPY( ptr, op->orc_ava->aa_value.bv_val, op->orc_ava->aa_value.bv_len );
1808		bv.bv_val[bv.bv_len] = '\0';
1809		attr_merge_one( e, ad_reqAssertion, &bv, NULL );
1810		op->o_tmpfree( bv.bv_val, op->o_tmpmemctx );
1811		break;
1812
1813	case LOG_EN_SEARCH:
1814		attr_merge_one( e, ad_reqScope, &scopes[op->ors_scope], NULL );
1815		attr_merge_one( e, ad_reqDerefAliases, &derefs[op->ors_deref], NULL );
1816		attr_merge_one( e, ad_reqAttrsOnly, op->ors_attrsonly ?
1817			(struct berval *)&slap_true_bv : (struct berval *)&slap_false_bv,
1818			NULL );
1819		if ( !BER_BVISEMPTY( &op->ors_filterstr ))
1820			attr_merge_normalize_one( e, ad_reqFilter, &op->ors_filterstr, op->o_tmpmemctx );
1821		if ( op->ors_attrs ) {
1822			int j;
1823			/* count them */
1824			for (i=0; !BER_BVISNULL(&op->ors_attrs[i].an_name );i++)
1825				;
1826			vals = op->o_tmpalloc( (i+1) * sizeof(struct berval),
1827				op->o_tmpmemctx );
1828			for (i=0, j=0; !BER_BVISNULL(&op->ors_attrs[i].an_name );i++) {
1829				if (!BER_BVISEMPTY(&op->ors_attrs[i].an_name)) {
1830					vals[j] = op->ors_attrs[i].an_name;
1831					j++;
1832				}
1833			}
1834			BER_BVZERO(&vals[j]);
1835			attr_merge_normalize( e, ad_reqAttr, vals, op->o_tmpmemctx );
1836			op->o_tmpfree( vals, op->o_tmpmemctx );
1837		}
1838		bv.bv_val = timebuf;
1839		bv.bv_len = snprintf( bv.bv_val, sizeof( timebuf ), "%d", rs->sr_nentries );
1840		if ( bv.bv_len < sizeof( timebuf ) ) {
1841			attr_merge_one( e, ad_reqEntries, &bv, NULL );
1842		} /* else? */
1843
1844		bv.bv_len = snprintf( bv.bv_val, sizeof( timebuf ), "%d", op->ors_tlimit );
1845		if ( bv.bv_len < sizeof( timebuf ) ) {
1846			attr_merge_one( e, ad_reqTimeLimit, &bv, NULL );
1847		} /* else? */
1848
1849		bv.bv_len = snprintf( bv.bv_val, sizeof( timebuf ), "%d", op->ors_slimit );
1850		if ( bv.bv_len < sizeof( timebuf ) ) {
1851			attr_merge_one( e, ad_reqSizeLimit, &bv, NULL );
1852		} /* else? */
1853		break;
1854
1855	case LOG_EN_BIND:
1856		bv.bv_val = timebuf;
1857		bv.bv_len = snprintf( bv.bv_val, sizeof( timebuf ), "%d", op->o_protocol );
1858		if ( bv.bv_len < sizeof( timebuf ) ) {
1859			attr_merge_one( e, ad_reqVersion, &bv, NULL );
1860		} /* else? */
1861		if ( op->orb_method == LDAP_AUTH_SIMPLE ) {
1862			attr_merge_normalize_one( e, ad_reqMethod, &simple, op->o_tmpmemctx );
1863		} else {
1864			bv.bv_len = STRLENOF("SASL()") + op->orb_mech.bv_len;
1865			bv.bv_val = op->o_tmpalloc( bv.bv_len + 1, op->o_tmpmemctx );
1866			ptr = lutil_strcopy( bv.bv_val, "SASL(" );
1867			ptr = lutil_strcopy( ptr, op->orb_mech.bv_val );
1868			*ptr++ = ')';
1869			*ptr = '\0';
1870			attr_merge_normalize_one( e, ad_reqMethod, &bv, op->o_tmpmemctx );
1871			op->o_tmpfree( bv.bv_val, op->o_tmpmemctx );
1872		}
1873
1874		break;
1875
1876	case LOG_EN_EXTENDED:
1877		if ( op->ore_reqdata ) {
1878			attr_merge_one( e, ad_reqData, op->ore_reqdata, NULL );
1879		}
1880		break;
1881
1882	case LOG_EN_UNKNOWN:
1883		/* we don't know its parameters, don't add any */
1884		break;
1885	}
1886
1887	if ( e_uuid || !BER_BVISNULL( &uuid ) ) {
1888		struct berval *pbv = NULL;
1889
1890		if ( !BER_BVISNULL( &uuid ) ) {
1891			pbv = &uuid;
1892
1893		} else {
1894			a = attr_find( e_uuid->e_attrs, slap_schema.si_ad_entryUUID );
1895			if ( a ) {
1896				pbv = &a->a_vals[0];
1897			}
1898		}
1899
1900		if ( pbv ) {
1901			attr_merge_normalize_one( e, ad_reqEntryUUID, pbv, op->o_tmpmemctx );
1902		}
1903
1904		if ( !BER_BVISNULL( &uuid ) ) {
1905			ber_memfree( uuid.bv_val );
1906			BER_BVZERO( &uuid );
1907		}
1908	}
1909
1910	op2.o_hdr = op->o_hdr;
1911	op2.o_tag = LDAP_REQ_ADD;
1912	op2.o_bd = li->li_db;
1913	op2.o_dn = li->li_db->be_rootdn;
1914	op2.o_ndn = li->li_db->be_rootndn;
1915	op2.o_req_dn = e->e_name;
1916	op2.o_req_ndn = e->e_nname;
1917	op2.ora_e = e;
1918	op2.o_callback = &nullsc;
1919	op2.o_csn = op->o_csn;
1920	/* contextCSN updates may still reach here */
1921	op2.o_dont_replicate = op->o_dont_replicate;
1922
1923	if (( lo->mask & LOG_OP_WRITES ) && !BER_BVISEMPTY( &op->o_csn )) {
1924		struct berval maxcsn;
1925		char cbuf[LDAP_PVT_CSNSTR_BUFSIZE];
1926		int foundit;
1927		cbuf[0] = '\0';
1928		maxcsn.bv_val = cbuf;
1929		maxcsn.bv_len = sizeof(cbuf);
1930		/* If there was a commit CSN on the main DB,
1931		 * we must propagate it to the log DB for its
1932		 * own syncprov. Otherwise, don't generate one.
1933		 */
1934		slap_get_commit_csn( op, &maxcsn, &foundit );
1935		if ( !BER_BVISEMPTY( &maxcsn ) ) {
1936			slap_queue_csn( &op2, &op->o_csn );
1937		} else {
1938			attr_merge_normalize_one( e, slap_schema.si_ad_entryCSN,
1939				&op->o_csn, op->o_tmpmemctx );
1940		}
1941	}
1942
1943	op2.o_bd->be_add( &op2, &rs2 );
1944	if ( rs2.sr_err != LDAP_SUCCESS ) {
1945		Debug( LDAP_DEBUG_SYNC, "%s accesslog_response: "
1946			"got result 0x%x adding log entry %s\n",
1947			op->o_log_prefix, rs2.sr_err, op2.o_req_dn.bv_val );
1948	}
1949	if ( e == op2.ora_e ) entry_free( e );
1950	e = NULL;
1951
1952	/* TODO: What to do about minCSN when we have an op without a CSN? */
1953	if ( !BER_BVISEMPTY( &op->o_csn ) ) {
1954		Modifications mod;
1955		int i, sid = slap_parse_csn_sid( &op->o_csn );
1956
1957		for ( i=0; i < li->li_numcsns; i++ ) {
1958			if ( sid <= li->li_sids[i] ) break;
1959		}
1960		if ( i >= li->li_numcsns || sid != li->li_sids[i] ) {
1961			/* SID not in minCSN set, add */
1962			struct berval bv[2];
1963
1964			Debug( LDAP_DEBUG_TRACE, "accesslog_response: "
1965					"adding minCSN %s\n",
1966					op->o_csn.bv_val );
1967			slap_insert_csn_sids( (struct sync_cookie *)&li->li_mincsn, i,
1968					sid, &op->o_csn );
1969
1970			op2.o_tag = LDAP_REQ_MODIFY;
1971			op2.o_req_dn = li->li_db->be_suffix[0];
1972			op2.o_req_ndn = li->li_db->be_nsuffix[0];
1973
1974			bv[0] = op->o_csn;
1975			BER_BVZERO( &bv[1] );
1976
1977			mod.sml_numvals = 1;
1978			mod.sml_values = bv;
1979			mod.sml_nvalues = bv;
1980			mod.sml_desc = ad_minCSN;
1981			mod.sml_op = LDAP_MOD_ADD;
1982			mod.sml_flags = SLAP_MOD_INTERNAL;
1983			mod.sml_next = NULL;
1984
1985			op2.orm_modlist = &mod;
1986			op2.orm_no_opattrs = 1;
1987
1988			Debug( LDAP_DEBUG_SYNC, "accesslog_response: "
1989					"adding a new csn=%s into minCSN\n",
1990					bv[0].bv_val );
1991			rs_reinit( &rs2, REP_RESULT );
1992			op2.o_bd->be_modify( &op2, &rs2 );
1993			if ( rs2.sr_err != LDAP_SUCCESS ) {
1994				Debug( LDAP_DEBUG_SYNC, "accesslog_response: "
1995						"got result 0x%x adding minCSN %s\n",
1996						rs2.sr_err, op->o_csn.bv_val );
1997			}
1998		} else if ( ber_bvcmp( &op->o_csn, &li->li_mincsn[i] ) < 0 ) {
1999			Debug( LDAP_DEBUG_ANY, "accesslog_response: "
2000					"csn=%s older than existing minCSN csn=%s for this sid\n",
2001					op->o_csn.bv_val, li->li_mincsn[i].bv_val );
2002		}
2003	}
2004
2005done:
2006	if ( lo->mask & LOG_OP_WRITES )
2007		ldap_pvt_thread_mutex_unlock( &li->li_log_mutex );
2008	if ( old ) entry_free( old );
2009	return SLAP_CB_CONTINUE;
2010}
2011
2012static int
2013accesslog_op_misc( Operation *op, SlapReply *rs )
2014{
2015	slap_callback *sc;
2016
2017	sc = op->o_tmpcalloc( 1, sizeof(slap_callback), op->o_tmpmemctx );
2018	sc->sc_response = accesslog_response;
2019	sc->sc_private = op->o_bd->bd_info;
2020
2021	if ( op->o_callback ) {
2022		sc->sc_next = op->o_callback->sc_next;
2023		op->o_callback->sc_next = sc;
2024	} else {
2025		op->o_callback = sc;
2026	}
2027	return SLAP_CB_CONTINUE;
2028}
2029
2030static int
2031accesslog_op_mod( Operation *op, SlapReply *rs )
2032{
2033	slap_overinst *on = (slap_overinst *)op->o_bd->bd_info;
2034	log_info *li = on->on_bi.bi_private;
2035	slap_verbmasks *lo;
2036	int logop;
2037	int doit = 0;
2038
2039	/* These internal ops are not logged */
2040	if ( op->o_dont_replicate )
2041		return SLAP_CB_CONTINUE;
2042
2043	/* can't do anything if logDB isn't open */
2044	if ( !SLAP_DBOPEN( li->li_db ))
2045		return SLAP_CB_CONTINUE;
2046
2047	logop = accesslog_op2logop( op );
2048	lo = logops+logop+EN_OFFSET;
2049
2050	if ( li->li_ops & lo->mask ) {
2051		doit = 1;
2052	} else {
2053		log_base *lb;
2054		for ( lb = li->li_bases; lb; lb = lb->lb_next )
2055			if (( lb->lb_ops & lo->mask ) && dnIsSuffix( &op->o_req_ndn, &lb->lb_base )) {
2056				doit = 1;
2057				break;
2058			}
2059	}
2060
2061	if ( doit ) {
2062		slap_callback *cb = op->o_tmpcalloc( 1, sizeof( slap_callback ), op->o_tmpmemctx );
2063		cb->sc_cleanup = accesslog_response;
2064		cb->sc_response = accesslog_response;
2065		cb->sc_private = on;
2066		cb->sc_next = op->o_callback;
2067		op->o_callback = cb;
2068
2069#ifdef RMUTEX_DEBUG
2070		Debug( LDAP_DEBUG_SYNC,
2071			"accesslog_op_mod: locking rmutex for tid %x\n",
2072			op->o_tid );
2073#endif
2074		ldap_pvt_thread_mutex_lock( &li->li_op_rmutex );
2075#ifdef RMUTEX_DEBUG
2076		Debug( LDAP_DEBUG_STATS,
2077			"accesslog_op_mod: locked rmutex for tid %x\n",
2078			op->o_tid );
2079#endif
2080		if ( li->li_oldf && ( op->o_tag == LDAP_REQ_DELETE ||
2081			op->o_tag == LDAP_REQ_MODIFY ||
2082			( op->o_tag == LDAP_REQ_MODRDN && li->li_oldattrs )))
2083		{
2084			int rc;
2085			Entry *e;
2086
2087			op->o_bd->bd_info = (BackendInfo *)on->on_info;
2088			rc = be_entry_get_rw( op, &op->o_req_ndn, NULL, NULL, 0, &e );
2089			if ( e ) {
2090				if ( test_filter( op, e, li->li_oldf ) == LDAP_COMPARE_TRUE )
2091					li->li_old = entry_dup( e );
2092				be_entry_release_rw( op, e, 0 );
2093			}
2094			op->o_bd->bd_info = (BackendInfo *)on;
2095
2096		} else {
2097			int rc;
2098			Entry *e;
2099
2100			op->o_bd->bd_info = (BackendInfo *)on->on_info;
2101			rc = be_entry_get_rw( op, &op->o_req_ndn, NULL, NULL, 0, &e );
2102			if ( e ) {
2103				Attribute *a = attr_find( e->e_attrs, slap_schema.si_ad_entryUUID );
2104				if ( a ) {
2105					ber_dupbv( &li->li_uuid, &a->a_vals[0] );
2106				}
2107				be_entry_release_rw( op, e, 0 );
2108			}
2109			op->o_bd->bd_info = (BackendInfo *)on;
2110		}
2111	}
2112	return SLAP_CB_CONTINUE;
2113}
2114
2115/* unbinds are broadcast to all backends; we only log it if this
2116 * backend was used for the original bind.
2117 */
2118static int
2119accesslog_unbind( Operation *op, SlapReply *rs )
2120{
2121	slap_overinst *on = (slap_overinst *)op->o_bd->bd_info;
2122	if ( op->o_conn->c_authz_backend == on->on_info->oi_origdb ) {
2123		log_info *li = on->on_bi.bi_private;
2124		Operation op2 = {0};
2125		void *cids[SLAP_MAX_CIDS];
2126		SlapReply rs2 = {REP_RESULT};
2127		Entry *e;
2128
2129		if ( !( li->li_ops & LOG_OP_UNBIND )) {
2130			log_base *lb;
2131			int i = 0;
2132
2133			for ( lb = li->li_bases; lb; lb=lb->lb_next )
2134				if (( lb->lb_ops & LOG_OP_UNBIND ) && dnIsSuffix( &op->o_ndn, &lb->lb_base )) {
2135					i = 1;
2136					break;
2137				}
2138			if ( !i )
2139				return SLAP_CB_CONTINUE;
2140		}
2141
2142		e = accesslog_entry( op, rs, li, LOG_EN_UNBIND, &op2 );
2143		op2.o_hdr = op->o_hdr;
2144		op2.o_tag = LDAP_REQ_ADD;
2145		op2.o_bd = li->li_db;
2146		op2.o_dn = li->li_db->be_rootdn;
2147		op2.o_ndn = li->li_db->be_rootndn;
2148		op2.o_req_dn = e->e_name;
2149		op2.o_req_ndn = e->e_nname;
2150		op2.ora_e = e;
2151		op2.o_callback = &nullsc;
2152		op2.o_controls = cids;
2153		memset(cids, 0, sizeof( cids ));
2154
2155		op2.o_bd->be_add( &op2, &rs2 );
2156		if ( e == op2.ora_e )
2157			entry_free( e );
2158	}
2159	return SLAP_CB_CONTINUE;
2160}
2161
2162static int
2163accesslog_abandon( Operation *op, SlapReply *rs )
2164{
2165	slap_overinst *on = (slap_overinst *)op->o_bd->bd_info;
2166	log_info *li = on->on_bi.bi_private;
2167	Operation op2 = {0};
2168	void *cids[SLAP_MAX_CIDS];
2169	SlapReply rs2 = {REP_RESULT};
2170	Entry *e;
2171	char buf[64];
2172	struct berval bv;
2173
2174	if ( !op->o_time )
2175		return SLAP_CB_CONTINUE;
2176
2177	if ( !( li->li_ops & LOG_OP_ABANDON )) {
2178		log_base *lb;
2179		int i = 0;
2180
2181		for ( lb = li->li_bases; lb; lb=lb->lb_next )
2182			if (( lb->lb_ops & LOG_OP_ABANDON ) && dnIsSuffix( &op->o_ndn, &lb->lb_base )) {
2183				i = 1;
2184				break;
2185			}
2186		if ( !i )
2187			return SLAP_CB_CONTINUE;
2188	}
2189
2190	e = accesslog_entry( op, rs, li, LOG_EN_ABANDON, &op2 );
2191	bv.bv_val = buf;
2192	bv.bv_len = snprintf( buf, sizeof( buf ), "%d", op->orn_msgid );
2193	if ( bv.bv_len < sizeof( buf ) ) {
2194		attr_merge_one( e, ad_reqId, &bv, NULL );
2195	} /* else? */
2196
2197	op2.o_hdr = op->o_hdr;
2198	op2.o_tag = LDAP_REQ_ADD;
2199	op2.o_bd = li->li_db;
2200	op2.o_dn = li->li_db->be_rootdn;
2201	op2.o_ndn = li->li_db->be_rootndn;
2202	op2.o_req_dn = e->e_name;
2203	op2.o_req_ndn = e->e_nname;
2204	op2.ora_e = e;
2205	op2.o_callback = &nullsc;
2206	op2.o_controls = cids;
2207	memset(cids, 0, sizeof( cids ));
2208
2209	op2.o_bd->be_add( &op2, &rs2 );
2210	if ( e == op2.ora_e )
2211		entry_free( e );
2212
2213	return SLAP_CB_CONTINUE;
2214}
2215
2216static int
2217accesslog_operational( Operation *op, SlapReply *rs )
2218{
2219	slap_overinst *on = (slap_overinst *)op->o_bd->bd_info;
2220	log_info *li = on->on_bi.bi_private;
2221
2222	if ( op->o_sync != SLAP_CONTROL_NONE )
2223		return SLAP_CB_CONTINUE;
2224
2225	if ( rs->sr_entry != NULL
2226		&& dn_match( &op->o_bd->be_nsuffix[0], &rs->sr_entry->e_nname ) )
2227	{
2228		Attribute	**ap;
2229
2230		for ( ap = &rs->sr_operational_attrs; *ap; ap = &(*ap)->a_next )
2231			/* just count */ ;
2232
2233		if ( SLAP_OPATTRS( rs->sr_attr_flags ) ||
2234				ad_inlist( ad_auditContext, rs->sr_attrs ) )
2235		{
2236			*ap = attr_alloc( ad_auditContext );
2237			attr_valadd( *ap,
2238				&li->li_db->be_suffix[0],
2239				&li->li_db->be_nsuffix[0], 1 );
2240		}
2241	}
2242
2243	return SLAP_CB_CONTINUE;
2244}
2245
2246static slap_overinst accesslog;
2247
2248static int
2249accesslog_db_init(
2250	BackendDB *be,
2251	ConfigReply *cr
2252)
2253{
2254	slap_overinst *on = (slap_overinst *)be->bd_info;
2255	log_info *li = ch_calloc(1, sizeof(log_info));
2256
2257	on->on_bi.bi_private = li;
2258	ldap_pvt_thread_mutex_recursive_init( &li->li_op_rmutex );
2259	ldap_pvt_thread_mutex_init( &li->li_log_mutex );
2260	return 0;
2261}
2262
2263static int
2264accesslog_db_destroy(
2265	BackendDB *be,
2266	ConfigReply *cr
2267)
2268{
2269	slap_overinst *on = (slap_overinst *)be->bd_info;
2270	log_info *li = on->on_bi.bi_private;
2271	log_attr *la;
2272
2273	if ( li->li_oldf )
2274		filter_free( li->li_oldf );
2275	for ( la=li->li_oldattrs; la; la=li->li_oldattrs ) {
2276		li->li_oldattrs = la->next;
2277		ch_free( la );
2278	}
2279	if ( li->li_sids )
2280		ch_free( li->li_sids );
2281	if ( li->li_mincsn )
2282		ber_bvarray_free( li->li_mincsn );
2283	ldap_pvt_thread_mutex_destroy( &li->li_log_mutex );
2284	ldap_pvt_thread_mutex_destroy( &li->li_op_rmutex );
2285	free( li );
2286	return LDAP_SUCCESS;
2287}
2288
2289/* Create the logdb's root entry if it's missing, load mincsn */
2290static void *
2291accesslog_db_root(
2292	void *ctx,
2293	void *arg )
2294{
2295	struct re_s *rtask = arg;
2296	slap_overinst *on = rtask->arg;
2297	log_info *li = on->on_bi.bi_private;
2298
2299	Connection conn = {0};
2300	OperationBuffer opbuf;
2301	Operation *op;
2302
2303	Entry *e;
2304	int rc;
2305
2306	connection_fake_init( &conn, &opbuf, ctx );
2307	op = &opbuf.ob_op;
2308	op->o_bd = li->li_db;
2309	op->o_dn = li->li_db->be_rootdn;
2310	op->o_ndn = li->li_db->be_rootndn;
2311	rc = be_entry_get_rw( op, li->li_db->be_nsuffix, NULL, NULL, 0, &e );
2312
2313	if ( e ) {
2314		Attribute *a = attr_find( e->e_attrs, ad_minCSN );
2315		if ( !a ) {
2316			/* TODO: find the lowest CSN we are safe to put in */
2317			a = attr_find( e->e_attrs, slap_schema.si_ad_contextCSN );
2318			if ( a ) {
2319				SlapReply rs = {REP_RESULT};
2320				Modifications mod;
2321				BackendDB db = *li->li_db;
2322
2323				op->o_bd = &db;
2324
2325				mod.sml_numvals = a->a_numvals;
2326				mod.sml_values = a->a_vals;
2327				mod.sml_nvalues = a->a_nvals;
2328				mod.sml_desc = ad_minCSN;
2329				mod.sml_op = LDAP_MOD_REPLACE;
2330				mod.sml_flags = SLAP_MOD_INTERNAL;
2331				mod.sml_next = NULL;
2332
2333				op->o_tag = LDAP_REQ_MODIFY;
2334				op->o_req_dn = e->e_name;
2335				op->o_req_ndn = e->e_nname;
2336				op->o_callback = &nullsc;
2337				SLAP_DBFLAGS( op->o_bd ) |= SLAP_DBFLAG_NOLASTMOD;
2338
2339				Debug( LDAP_DEBUG_SYNC, "accesslog_db_root: "
2340						"setting up minCSN with %d values\n",
2341						a->a_numvals );
2342
2343				op->orm_modlist = &mod;
2344				op->orm_no_opattrs = 1;
2345				rc = op->o_bd->be_modify( op, &rs );
2346			}
2347		}
2348		if ( a ) {
2349			ber_bvarray_dup_x( &li->li_mincsn, a->a_vals, NULL );
2350			li->li_numcsns = a->a_numvals;
2351			li->li_sids = slap_parse_csn_sids( li->li_mincsn, li->li_numcsns, NULL );
2352			slap_sort_csn_sids( li->li_mincsn, li->li_sids, li->li_numcsns, NULL );
2353		}
2354		be_entry_release_rw( op, e, 0 );
2355	} else {
2356		SlapReply rs = {REP_RESULT};
2357		struct berval rdn, nrdn, attr;
2358		char *ptr;
2359		AttributeDescription *ad = NULL;
2360		const char *text = NULL;
2361		Entry *e_ctx;
2362		BackendDB db;
2363
2364		e = entry_alloc();
2365		ber_dupbv( &e->e_name, li->li_db->be_suffix );
2366		ber_dupbv( &e->e_nname, li->li_db->be_nsuffix );
2367
2368		attr_merge_one( e, slap_schema.si_ad_objectClass,
2369			&log_container->soc_cname, NULL );
2370
2371		dnRdn( &e->e_name, &rdn );
2372		dnRdn( &e->e_nname, &nrdn );
2373		ptr = ber_bvchr( &rdn, '=' );
2374
2375		assert( ptr != NULL );
2376
2377		attr.bv_val = rdn.bv_val;
2378		attr.bv_len = ptr - rdn.bv_val;
2379
2380		slap_bv2ad( &attr, &ad, &text );
2381
2382		rdn.bv_val = ptr+1;
2383		rdn.bv_len -= attr.bv_len + 1;
2384		ptr = ber_bvchr( &nrdn, '=' );
2385		nrdn.bv_len -= ptr - nrdn.bv_val + 1;
2386		nrdn.bv_val = ptr+1;
2387		attr_merge_one( e, ad, &rdn, &nrdn );
2388
2389		/* Get contextCSN from main DB */
2390		op->o_bd = on->on_info->oi_origdb;
2391		rc = be_entry_get_rw( op, op->o_bd->be_nsuffix, NULL,
2392			slap_schema.si_ad_contextCSN, 0, &e_ctx );
2393
2394		if ( e_ctx ) {
2395			Attribute *a;
2396
2397			a = attr_find( e_ctx->e_attrs, slap_schema.si_ad_contextCSN );
2398			if ( a ) {
2399				/* FIXME: contextCSN could have multiple values!
2400				 * should select the one with the server's SID */
2401				attr_merge_one( e, slap_schema.si_ad_entryCSN,
2402					&a->a_vals[0], &a->a_nvals[0] );
2403				attr_merge( e, a->a_desc, a->a_vals, a->a_nvals );
2404				attr_merge( e, ad_minCSN, a->a_vals, a->a_nvals );
2405			}
2406			be_entry_release_rw( op, e_ctx, 0 );
2407		}
2408		db = *li->li_db;
2409		op->o_bd = &db;
2410
2411		op->o_tag = LDAP_REQ_ADD;
2412		op->ora_e = e;
2413		op->o_req_dn = e->e_name;
2414		op->o_req_ndn = e->e_nname;
2415		op->o_callback = &nullsc;
2416		SLAP_DBFLAGS( op->o_bd ) |= SLAP_DBFLAG_NOLASTMOD;
2417		rc = op->o_bd->be_add( op, &rs );
2418		if ( e == op->ora_e )
2419			entry_free( e );
2420	}
2421	ldap_pvt_thread_mutex_lock( &slapd_rq.rq_mutex );
2422	ldap_pvt_runqueue_stoptask( &slapd_rq, rtask );
2423	ldap_pvt_runqueue_remove( &slapd_rq, rtask );
2424	ldap_pvt_thread_mutex_unlock( &slapd_rq.rq_mutex );
2425
2426	return NULL;
2427}
2428
2429static int
2430accesslog_db_open(
2431	BackendDB *be,
2432	ConfigReply *cr
2433)
2434{
2435	slap_overinst *on = (slap_overinst *)be->bd_info;
2436	log_info *li = on->on_bi.bi_private;
2437
2438
2439	if ( !BER_BVISEMPTY( &li->li_db_suffix )) {
2440		li->li_db = select_backend( &li->li_db_suffix, 0 );
2441		ch_free( li->li_db_suffix.bv_val );
2442		BER_BVZERO( &li->li_db_suffix );
2443	}
2444	if ( li->li_db == NULL ) {
2445		Debug( LDAP_DEBUG_ANY,
2446			"accesslog: \"logdb <suffix>\" missing or invalid.\n" );
2447		return 1;
2448	}
2449	if ( li->li_db->bd_self == be->bd_self ) {
2450		Debug( LDAP_DEBUG_ANY,
2451			"accesslog: \"logdb <suffix>\" is this database, cannot log to itself.\n" );
2452		return 1;
2453	}
2454
2455	if ( slapMode & SLAP_TOOL_MODE )
2456		return 0;
2457
2458	if ( BER_BVISEMPTY( &li->li_db->be_rootndn )) {
2459		ber_dupbv( &li->li_db->be_rootdn, li->li_db->be_suffix );
2460		ber_dupbv( &li->li_db->be_rootndn, li->li_db->be_nsuffix );
2461	}
2462
2463	ldap_pvt_thread_mutex_lock( &slapd_rq.rq_mutex );
2464	ldap_pvt_runqueue_insert( &slapd_rq, 3600, accesslog_db_root, on,
2465		"accesslog_db_root", li->li_db->be_suffix[0].bv_val );
2466	ldap_pvt_thread_mutex_unlock( &slapd_rq.rq_mutex );
2467
2468	return 0;
2469}
2470
2471enum { start = 0 };
2472
2473static int
2474check_rdntime_syntax (struct berval *val,
2475	int *parts,
2476	struct berval *fraction)
2477{
2478	/*
2479	 * GeneralizedTime YYYYmmddHH[MM[SS]][(./,)d...](Z|(+/-)HH[MM])
2480	 * GeneralizedTime supports leap seconds, UTCTime does not.
2481	 */
2482	static const int ceiling[9] = { 100, 100, 12, 31, 24, 60, 60, 24, 60 };
2483	static const int mdays[2][12] = {
2484		/* non-leap years */
2485		{ 31, 28, 31, 30, 31, 30, 31, 31, 30, 31, 30, 31 },
2486		/* leap years */
2487		{ 31, 29, 31, 30, 31, 30, 31, 31, 30, 31, 30, 31 }
2488	};
2489	char *p, *e;
2490	int part, c, c1, c2, tzoffset, leapyear = 0;
2491
2492	p = val->bv_val;
2493	e = p + val->bv_len;
2494
2495	for (part = start; part < 7 && p < e; part++) {
2496		c1 = *p;
2497		if (!ASCII_DIGIT(c1)) {
2498			break;
2499		}
2500		p++;
2501		if (p == e) {
2502			return LDAP_INVALID_SYNTAX;
2503		}
2504		c = *p++;
2505		if (!ASCII_DIGIT(c)) {
2506			return LDAP_INVALID_SYNTAX;
2507		}
2508		c += c1 * 10 - '0' * 11;
2509		if ((part | 1) == 3) {
2510			--c;
2511			if (c < 0) {
2512				return LDAP_INVALID_SYNTAX;
2513			}
2514		}
2515		if (c >= ceiling[part]) {
2516			if (! (c == 60 && part == 6 && start == 0))
2517				return LDAP_INVALID_SYNTAX;
2518		}
2519		parts[part] = c;
2520	}
2521	if (part < 5 + start) {
2522		return LDAP_INVALID_SYNTAX;
2523	}
2524	for (; part < 9; part++) {
2525		parts[part] = 0;
2526	}
2527
2528	/* leapyear check for the Gregorian calendar (year>1581) */
2529	if (parts[parts[1] == 0 ? 0 : 1] % 4 == 0) {
2530		leapyear = 1;
2531	}
2532
2533	if (parts[3] >= mdays[leapyear][parts[2]]) {
2534		return LDAP_INVALID_SYNTAX;
2535	}
2536
2537	if (start == 0) {
2538		fraction->bv_val = p;
2539		fraction->bv_len = 0;
2540		if (p < e && (*p == '.' || *p == ',')) {
2541			char *end_num;
2542			while (++p < e && ASCII_DIGIT(*p)) {
2543				/* EMPTY */;
2544			}
2545			if (p - fraction->bv_val == 1) {
2546				return LDAP_INVALID_SYNTAX;
2547			}
2548
2549#if 0		/* don't truncate trailing zeros */
2550			for (end_num = p; end_num[-1] == '0'; --end_num) {
2551				/* EMPTY */;
2552			}
2553			c = end_num - fraction->bv_val;
2554#else
2555			c = p - fraction->bv_val;
2556#endif
2557			if (c != 1) fraction->bv_len = c;
2558		}
2559	}
2560
2561	if (p == e) {
2562		/* no time zone */
2563		return start == 0 ? LDAP_INVALID_SYNTAX : LDAP_SUCCESS;
2564	}
2565
2566	tzoffset = *p++;
2567	switch (tzoffset) {
2568	case 'Z':
2569		/* UTC */
2570		break;
2571	default:
2572		return LDAP_INVALID_SYNTAX;
2573	}
2574
2575	return p != e ? LDAP_INVALID_SYNTAX : LDAP_SUCCESS;
2576}
2577
2578static int
2579rdnTimestampValidate(
2580	Syntax *syntax,
2581	struct berval *in )
2582{
2583	int parts[9];
2584	struct berval fraction;
2585	return check_rdntime_syntax(in, parts, &fraction);
2586}
2587
2588static int
2589rdnTimestampNormalize(
2590	slap_mask_t usage,
2591	Syntax *syntax,
2592	MatchingRule *mr,
2593	struct berval *val,
2594	struct berval *normalized,
2595	void *ctx )
2596{
2597	int parts[9], rc;
2598	unsigned int len;
2599	struct berval fraction;
2600
2601	rc = check_rdntime_syntax(val, parts, &fraction);
2602	if (rc != LDAP_SUCCESS) {
2603		return rc;
2604	}
2605
2606	len = STRLENOF("YYYYmmddHHMMSSZ") + fraction.bv_len;
2607	normalized->bv_val = slap_sl_malloc( len + 1, ctx );
2608	if ( BER_BVISNULL( normalized ) ) {
2609		return LBER_ERROR_MEMORY;
2610	}
2611
2612	sprintf( normalized->bv_val, "%02d%02d%02d%02d%02d%02d%02d",
2613		parts[0], parts[1], parts[2] + 1, parts[3] + 1,
2614		parts[4], parts[5], parts[6] );
2615	if ( !BER_BVISEMPTY( &fraction ) ) {
2616		memcpy( normalized->bv_val + STRLENOF("YYYYmmddHHMMSSZ")-1,
2617			fraction.bv_val, fraction.bv_len );
2618		normalized->bv_val[STRLENOF("YYYYmmddHHMMSSZ")-1] = '.';
2619	}
2620	strcpy( normalized->bv_val + len-1, "Z" );
2621	normalized->bv_len = len;
2622
2623	return LDAP_SUCCESS;
2624}
2625
2626
2627int accesslog_initialize()
2628{
2629	int i, rc;
2630	Syntax *rdnTimestampSyntax;
2631	MatchingRule *rdnTimestampMatch;
2632
2633	accesslog.on_bi.bi_type = "accesslog";
2634	accesslog.on_bi.bi_db_init = accesslog_db_init;
2635	accesslog.on_bi.bi_db_destroy = accesslog_db_destroy;
2636	accesslog.on_bi.bi_db_open = accesslog_db_open;
2637
2638	accesslog.on_bi.bi_op_add = accesslog_op_mod;
2639	accesslog.on_bi.bi_op_bind = accesslog_op_misc;
2640	accesslog.on_bi.bi_op_compare = accesslog_op_misc;
2641	accesslog.on_bi.bi_op_delete = accesslog_op_mod;
2642	accesslog.on_bi.bi_op_modify = accesslog_op_mod;
2643	accesslog.on_bi.bi_op_modrdn = accesslog_op_mod;
2644	accesslog.on_bi.bi_op_search = accesslog_op_misc;
2645	accesslog.on_bi.bi_extended = accesslog_op_misc;
2646	accesslog.on_bi.bi_op_unbind = accesslog_unbind;
2647	accesslog.on_bi.bi_op_abandon = accesslog_abandon;
2648	accesslog.on_bi.bi_operational = accesslog_operational;
2649
2650	accesslog.on_bi.bi_cf_ocs = log_cfocs;
2651
2652	nullsc.sc_response = slap_null_cb;
2653
2654	rc = config_register_schema( log_cfats, log_cfocs );
2655	if ( rc ) return rc;
2656
2657	/* log schema integration */
2658	for ( i=0; lsyntaxes[i].oid; i++ ) {
2659		int code;
2660
2661		code = register_syntax( &lsyntaxes[ i ].syn );
2662		if ( code != 0 ) {
2663			Debug( LDAP_DEBUG_ANY,
2664				"accesslog_init: register_syntax failed\n" );
2665			return code;
2666		}
2667
2668		if ( lsyntaxes[i].mrs != NULL ) {
2669			code = mr_make_syntax_compat_with_mrs(
2670				lsyntaxes[i].oid, lsyntaxes[i].mrs );
2671			if ( code < 0 ) {
2672				Debug( LDAP_DEBUG_ANY,
2673					"accesslog_init: "
2674					"mr_make_syntax_compat_with_mrs "
2675					"failed\n" );
2676				return code;
2677			}
2678		}
2679	}
2680
2681	for ( i=0; lattrs[i].at; i++ ) {
2682		int code;
2683
2684		code = register_at( lattrs[i].at, lattrs[i].ad, 0 );
2685		if ( code ) {
2686			Debug( LDAP_DEBUG_ANY,
2687				"accesslog_init: register_at failed\n" );
2688			return -1;
2689		}
2690	}
2691
2692	/* Inject custom normalizer for reqStart/reqEnd */
2693	rdnTimestampMatch = ch_malloc( sizeof( MatchingRule ));
2694	rdnTimestampSyntax = ch_malloc( sizeof( Syntax ));
2695	*rdnTimestampMatch = *ad_reqStart->ad_type->sat_equality;
2696	rdnTimestampMatch->smr_normalize = rdnTimestampNormalize;
2697	*rdnTimestampSyntax = *ad_reqStart->ad_type->sat_syntax;
2698	rdnTimestampSyntax->ssyn_validate = rdnTimestampValidate;
2699	ad_reqStart->ad_type->sat_equality = rdnTimestampMatch;
2700	ad_reqStart->ad_type->sat_syntax = rdnTimestampSyntax;
2701
2702	rdnTimestampMatch = ch_malloc( sizeof( MatchingRule ));
2703	rdnTimestampSyntax = ch_malloc( sizeof( Syntax ));
2704	*rdnTimestampMatch = *ad_reqStart->ad_type->sat_equality;
2705	rdnTimestampMatch->smr_normalize = rdnTimestampNormalize;
2706	*rdnTimestampSyntax = *ad_reqStart->ad_type->sat_syntax;
2707	rdnTimestampSyntax->ssyn_validate = rdnTimestampValidate;
2708	ad_reqEnd->ad_type->sat_equality = rdnTimestampMatch;
2709	ad_reqEnd->ad_type->sat_syntax = rdnTimestampSyntax;
2710
2711	for ( i=0; locs[i].ot; i++ ) {
2712		int code;
2713
2714		code = register_oc( locs[i].ot, locs[i].oc, 0 );
2715		if ( code ) {
2716			Debug( LDAP_DEBUG_ANY,
2717				"accesslog_init: register_oc failed\n" );
2718			return -1;
2719		}
2720	}
2721
2722	return overlay_register(&accesslog);
2723}
2724
2725#if SLAPD_OVER_ACCESSLOG == SLAPD_MOD_DYNAMIC
2726int
2727init_module( int argc, char *argv[] )
2728{
2729	return accesslog_initialize();
2730}
2731#endif
2732
2733#endif /* SLAPD_OVER_ACCESSLOG */
2734