Line data Source code
1 : /*
2 : ldb database library
3 :
4 : Copyright (C) Andrew Bartlett <abartlet@samba.org> 2018
5 :
6 : This program is free software; you can redistribute it and/or modify
7 : it under the terms of the GNU General Public License as published by
8 : the Free Software Foundation; either version 3 of the License, or
9 : (at your option) any later version.
10 :
11 : This program is distributed in the hope that it will be useful,
12 : but WITHOUT ANY WARRANTY; without even the implied warranty of
13 : MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
14 : GNU General Public License for more details.
15 :
16 : You should have received a copy of the GNU General Public License
17 : along with this program. If not, see <http://www.gnu.org/licenses/>.
18 : */
19 :
20 : /*
21 : * Provide an audit log of changes made to the database and at a
22 : * higher level details of any password changes and resets.
23 : *
24 : */
25 :
26 : #include "includes.h"
27 : #include "ldb_module.h"
28 : #include "lib/audit_logging/audit_logging.h"
29 :
30 : #include "dsdb/samdb/samdb.h"
31 : #include "dsdb/samdb/ldb_modules/util.h"
32 : #include "dsdb/samdb/ldb_modules/audit_util_proto.h"
33 : #include "libcli/security/dom_sid.h"
34 : #include "auth/common_auth.h"
35 : #include "param/param.h"
36 : #include "librpc/gen_ndr/windows_event_ids.h"
37 :
38 : #define OPERATION_JSON_TYPE "dsdbChange"
39 : #define OPERATION_HR_TAG "DSDB Change"
40 : #define OPERATION_MAJOR 1
41 : #define OPERATION_MINOR 0
42 : #define OPERATION_LOG_LVL 5
43 :
44 : #define PASSWORD_JSON_TYPE "passwordChange"
45 : #define PASSWORD_HR_TAG "Password Change"
46 : #define PASSWORD_MAJOR 1
47 : #define PASSWORD_MINOR 1
48 : #define PASSWORD_LOG_LVL 5
49 :
50 : #define TRANSACTION_JSON_TYPE "dsdbTransaction"
51 : #define TRANSACTION_HR_TAG "DSDB Transaction"
52 : #define TRANSACTION_MAJOR 1
53 : #define TRANSACTION_MINOR 0
54 : #define TRANSACTION_LOG_FAILURE_LVL 5
55 : #define TRANSACTION_LOG_COMPLETION_LVL 10
56 :
57 : #define REPLICATION_JSON_TYPE "replicatedUpdate"
58 : #define REPLICATION_HR_TAG "Replicated Update"
59 : #define REPLICATION_MAJOR 1
60 : #define REPLICATION_MINOR 0
61 : #define REPLICATION_LOG_LVL 5
62 : /*
63 : * Attribute values are truncated in the logs if they are longer than
64 : * MAX_LENGTH
65 : */
66 : #define MAX_LENGTH 1024
67 :
68 : #define min(a, b) (((a)>(b))?(b):(a))
69 :
70 : /*
71 : * Private data for the module, stored in the ldb_module private data
72 : */
73 : struct audit_private {
74 : /*
75 : * Should details of database operations be sent over the
76 : * messaging bus.
77 : */
78 : bool send_samdb_events;
79 : /*
80 : * Should details of password changes and resets be sent over
81 : * the messaging bus.
82 : */
83 : bool send_password_events;
84 : /*
85 : * The messaging context to send the messages over. Will only
86 : * be set if send_samdb_events or send_password_events are
87 : * true.
88 : */
89 : struct imessaging_context *msg_ctx;
90 : /*
91 : * Unique transaction id for the current transaction
92 : */
93 : struct GUID transaction_guid;
94 : /*
95 : * Transaction start time, used to calculate the transaction
96 : * duration.
97 : */
98 : struct timeval transaction_start;
99 : };
100 :
101 : /*
102 : * @brief Has the password changed.
103 : *
104 : * Does the message contain a change to one of the password attributes? The
105 : * password attributes are defined in DSDB_PASSWORD_ATTRIBUTES
106 : *
107 : * @return true if the message contains a password attribute
108 : *
109 : */
110 847150 : static bool has_password_changed(const struct ldb_message *message)
111 : {
112 : unsigned int i;
113 847150 : if (message == NULL) {
114 76576 : return false;
115 : }
116 5848332 : for (i=0;i<message->num_elements;i++) {
117 5184875 : if (dsdb_audit_is_password_attribute(
118 5184875 : message->elements[i].name)) {
119 13937 : return true;
120 : }
121 : }
122 663676 : return false;
123 : }
124 :
125 : /*
126 : * @brief get the password change windows event id
127 : *
128 : * Get the Windows Event Id for the action being performed on the user password.
129 : *
130 : * This routine assumes that the request contains password attributes and that the
131 : * password ACL checks have been performed by acl.c
132 : *
133 : * @param request the ldb_request to inspect
134 : * @param reply the ldb_reply, will contain the password controls
135 : *
136 : * @return The windows event code.
137 : */
138 7998 : static enum event_id_type get_password_windows_event_id(
139 : const struct ldb_request *request,
140 : const struct ldb_reply *reply)
141 : {
142 7998 : if(request->operation == LDB_ADD) {
143 1250 : return EVT_ID_PASSWORD_RESET;
144 : } else {
145 6736 : struct ldb_control *pav_ctrl = NULL;
146 6736 : struct dsdb_control_password_acl_validation *pav = NULL;
147 :
148 6736 : pav_ctrl = ldb_reply_get_control(
149 : discard_const(reply),
150 : DSDB_CONTROL_PASSWORD_ACL_VALIDATION_OID);
151 6736 : if (pav_ctrl == NULL) {
152 846 : return EVT_ID_PASSWORD_RESET;
153 : }
154 :
155 5834 : pav = talloc_get_type_abort(
156 : pav_ctrl->data,
157 : struct dsdb_control_password_acl_validation);
158 :
159 5834 : if (pav->pwd_reset) {
160 4964 : return EVT_ID_PASSWORD_RESET;
161 : } else {
162 798 : return EVT_ID_PASSWORD_CHANGE;
163 : }
164 : }
165 : }
166 : /*
167 : * @brief Is the request a password "Change" or a "Reset"
168 : *
169 : * Get a description of the action being performed on the user password. This
170 : * routine assumes that the request contains password attributes and that the
171 : * password ACL checks have been performed by acl.c
172 : *
173 : * @param request the ldb_request to inspect
174 : * @param reply the ldb_reply, will contain the password controls
175 : *
176 : * @return "Change" if the password is being changed.
177 : * "Reset" if the password is being reset.
178 : */
179 8004 : static const char *get_password_action(
180 : const struct ldb_request *request,
181 : const struct ldb_reply *reply)
182 : {
183 8004 : if(request->operation == LDB_ADD) {
184 1250 : return "Reset";
185 : } else {
186 6740 : struct ldb_control *pav_ctrl = NULL;
187 6740 : struct dsdb_control_password_acl_validation *pav = NULL;
188 :
189 6740 : pav_ctrl = ldb_reply_get_control(
190 : discard_const(reply),
191 : DSDB_CONTROL_PASSWORD_ACL_VALIDATION_OID);
192 6740 : if (pav_ctrl == NULL) {
193 846 : return "Reset";
194 : }
195 :
196 5836 : pav = talloc_get_type_abort(
197 : pav_ctrl->data,
198 : struct dsdb_control_password_acl_validation);
199 :
200 5836 : if (pav->pwd_reset) {
201 4964 : return "Reset";
202 : } else {
203 798 : return "Change";
204 : }
205 : }
206 : }
207 :
208 : /*
209 : * @brief generate a JSON object detailing an ldb operation.
210 : *
211 : * Generate a JSON object detailing an ldb operation.
212 : *
213 : * @param module the ldb module
214 : * @param request the request
215 : * @param reply the result of the operation.
216 : *
217 : * @return the generated JSON object, should be freed with json_free.
218 : *
219 : *
220 : */
221 294349 : static struct json_object operation_json(
222 : struct ldb_module *module,
223 : const struct ldb_request *request,
224 : const struct ldb_reply *reply)
225 : {
226 294349 : struct ldb_context *ldb = NULL;
227 294349 : const struct dom_sid *sid = NULL;
228 294349 : bool as_system = false;
229 294349 : struct json_object wrapper = json_empty_object;
230 294349 : struct json_object audit = json_empty_object;
231 294349 : const struct tsocket_address *remote = NULL;
232 294349 : const char *dn = NULL;
233 294349 : const char* operation = NULL;
234 294349 : const struct GUID *unique_session_token = NULL;
235 294349 : const struct ldb_message *message = NULL;
236 233655 : struct audit_private *audit_private
237 294349 : = talloc_get_type_abort(ldb_module_get_private(module),
238 : struct audit_private);
239 294349 : int rc = 0;
240 :
241 294349 : ldb = ldb_module_get_ctx(module);
242 :
243 294349 : remote = dsdb_audit_get_remote_address(ldb);
244 294349 : if (remote != NULL && dsdb_audit_is_system_session(module)) {
245 2942 : as_system = true;
246 2942 : sid = dsdb_audit_get_actual_sid(ldb);
247 2942 : unique_session_token =
248 119 : dsdb_audit_get_actual_unique_session_token(ldb);
249 : } else {
250 291407 : sid = dsdb_audit_get_user_sid(module);
251 230832 : unique_session_token =
252 60575 : dsdb_audit_get_unique_session_token(module);
253 : }
254 294349 : dn = dsdb_audit_get_primary_dn(request);
255 294349 : operation = dsdb_audit_get_operation_name(request);
256 :
257 294349 : audit = json_new_object();
258 294349 : if (json_is_invalid(&audit)) {
259 0 : goto failure;
260 : }
261 294348 : rc = json_add_version(&audit, OPERATION_MAJOR, OPERATION_MINOR);
262 294348 : if (rc != 0) {
263 0 : goto failure;
264 : }
265 294347 : rc = json_add_int(&audit, "statusCode", reply->error);
266 294347 : if (rc != 0) {
267 0 : goto failure;
268 : }
269 294347 : rc = json_add_string(&audit, "status", ldb_strerror(reply->error));
270 294347 : if (rc != 0) {
271 0 : goto failure;
272 : }
273 294347 : rc = json_add_string(&audit, "operation", operation);
274 294347 : if (rc != 0) {
275 0 : goto failure;
276 : }
277 294347 : rc = json_add_address(&audit, "remoteAddress", remote);
278 294347 : if (rc != 0) {
279 0 : goto failure;
280 : }
281 294347 : rc = json_add_bool(&audit, "performedAsSystem", as_system);
282 294347 : if (rc != 0) {
283 0 : goto failure;
284 : }
285 294347 : rc = json_add_sid(&audit, "userSid", sid);
286 294347 : if (rc != 0) {
287 0 : goto failure;
288 : }
289 294347 : rc = json_add_string(&audit, "dn", dn);
290 294347 : if (rc != 0) {
291 0 : goto failure;
292 : }
293 294347 : rc = json_add_guid(
294 294347 : &audit, "transactionId", &audit_private->transaction_guid);
295 294347 : if (rc != 0) {
296 0 : goto failure;
297 : }
298 294347 : rc = json_add_guid(&audit, "sessionId", unique_session_token);
299 294347 : if (rc != 0) {
300 0 : goto failure;
301 : }
302 :
303 294347 : message = dsdb_audit_get_message(request);
304 294347 : if (message != NULL) {
305 207686 : struct json_object attributes =
306 262546 : dsdb_audit_attributes_json(
307 54860 : request->operation,
308 : message);
309 262546 : if (json_is_invalid(&attributes)) {
310 0 : goto failure;
311 : }
312 262546 : rc = json_add_object(&audit, "attributes", &attributes);
313 262546 : if (rc != 0) {
314 0 : goto failure;
315 : }
316 : }
317 :
318 294347 : wrapper = json_new_object();
319 294347 : if (json_is_invalid(&wrapper)) {
320 0 : goto failure;
321 : }
322 294346 : rc = json_add_timestamp(&wrapper);
323 294346 : if (rc != 0) {
324 0 : goto failure;
325 : }
326 294345 : rc = json_add_string(&wrapper, "type", OPERATION_JSON_TYPE);
327 294345 : if (rc != 0) {
328 0 : goto failure;
329 : }
330 294345 : rc = json_add_object(&wrapper, OPERATION_JSON_TYPE, &audit);
331 294345 : if (rc != 0) {
332 0 : goto failure;
333 : }
334 294345 : return wrapper;
335 :
336 4 : failure:
337 : /*
338 : * On a failure audit will not have been added to wrapper so it
339 : * needs to free it to avoid a leak.
340 : *
341 : * wrapper is freed to invalidate it as it will have only been
342 : * partially constructed and may be inconsistent.
343 : *
344 : * All the json manipulation routines handle a freed object correctly
345 : */
346 4 : json_free(&audit);
347 4 : json_free(&wrapper);
348 4 : DBG_ERR("Unable to create ldb operation JSON audit message\n");
349 4 : return wrapper;
350 : }
351 :
352 : /*
353 : * @brief generate a JSON object detailing a replicated update.
354 : *
355 : * Generate a JSON object detailing a replicated update
356 : *
357 : * @param module the ldb module
358 : * @param request the request
359 : * @paran reply the result of the operation
360 : *
361 : * @return the generated JSON object, should be freed with json_free.
362 : * NULL if there was an error generating the message.
363 : *
364 : */
365 7 : static struct json_object replicated_update_json(
366 : struct ldb_module *module,
367 : const struct ldb_request *request,
368 : const struct ldb_reply *reply)
369 : {
370 7 : struct json_object wrapper = json_empty_object;
371 7 : struct json_object audit = json_empty_object;
372 7 : struct audit_private *audit_private
373 7 : = talloc_get_type_abort(ldb_module_get_private(module),
374 : struct audit_private);
375 7 : struct dsdb_extended_replicated_objects *ro = talloc_get_type(
376 : request->op.extended.data,
377 : struct dsdb_extended_replicated_objects);
378 7 : const char *partition_dn = NULL;
379 7 : const char *error = NULL;
380 7 : int rc = 0;
381 :
382 7 : partition_dn = ldb_dn_get_linearized(ro->partition_dn);
383 7 : error = get_friendly_werror_msg(ro->error);
384 :
385 7 : audit = json_new_object();
386 7 : if (json_is_invalid(&audit)) {
387 0 : goto failure;
388 : }
389 6 : rc = json_add_version(&audit, REPLICATION_MAJOR, REPLICATION_MINOR);
390 6 : if (rc != 0) {
391 0 : goto failure;
392 : }
393 5 : rc = json_add_int(&audit, "statusCode", reply->error);
394 5 : if (rc != 0) {
395 0 : goto failure;
396 : }
397 5 : rc = json_add_string(&audit, "status", ldb_strerror(reply->error));
398 5 : if (rc != 0) {
399 0 : goto failure;
400 : }
401 5 : rc = json_add_guid(
402 5 : &audit, "transactionId", &audit_private->transaction_guid);
403 5 : if (rc != 0) {
404 0 : goto failure;
405 : }
406 5 : rc = json_add_int(&audit, "objectCount", ro->num_objects);
407 5 : if (rc != 0) {
408 0 : goto failure;
409 : }
410 5 : rc = json_add_int(&audit, "linkCount", ro->linked_attributes_count);
411 5 : if (rc != 0) {
412 0 : goto failure;
413 : }
414 5 : rc = json_add_string(&audit, "partitionDN", partition_dn);
415 5 : if (rc != 0) {
416 0 : goto failure;
417 : }
418 5 : rc = json_add_string(&audit, "error", error);
419 5 : if (rc != 0) {
420 0 : goto failure;
421 : }
422 5 : rc = json_add_int(&audit, "errorCode", W_ERROR_V(ro->error));
423 5 : if (rc != 0) {
424 0 : goto failure;
425 : }
426 5 : rc = json_add_guid(
427 5 : &audit, "sourceDsa", &ro->source_dsa->source_dsa_obj_guid);
428 5 : if (rc != 0) {
429 0 : goto failure;
430 : }
431 5 : rc = json_add_guid(
432 5 : &audit, "invocationId", &ro->source_dsa->source_dsa_invocation_id);
433 5 : if (rc != 0) {
434 0 : goto failure;
435 : }
436 :
437 5 : wrapper = json_new_object();
438 5 : if (json_is_invalid(&wrapper)) {
439 0 : goto failure;
440 : }
441 4 : rc = json_add_timestamp(&wrapper);
442 4 : if (rc != 0) {
443 0 : goto failure;
444 : }
445 3 : rc = json_add_string(&wrapper, "type", REPLICATION_JSON_TYPE);
446 3 : if (rc != 0) {
447 0 : goto failure;
448 : }
449 3 : rc = json_add_object(&wrapper, REPLICATION_JSON_TYPE, &audit);
450 3 : if (rc != 0) {
451 0 : goto failure;
452 : }
453 3 : return wrapper;
454 4 : failure:
455 : /*
456 : * On a failure audit will not have been added to wrapper so it
457 : * needs to be freed it to avoid a leak.
458 : *
459 : * wrapper is freed to invalidate it as it will have only been
460 : * partially constructed and may be inconsistent.
461 : *
462 : * All the json manipulation routines handle a freed object correctly
463 : */
464 4 : json_free(&audit);
465 4 : json_free(&wrapper);
466 4 : DBG_ERR("Unable to create replicated update JSON audit message\n");
467 4 : return wrapper;
468 : }
469 :
470 : /*
471 : * @brief generate a JSON object detailing a password change.
472 : *
473 : * Generate a JSON object detailing a password change.
474 : *
475 : * @param module the ldb module
476 : * @param request the request
477 : * @param reply the result/response
478 : * @param status the status code returned for the underlying ldb operation.
479 : *
480 : * @return the generated JSON object.
481 : *
482 : */
483 7998 : static struct json_object password_change_json(
484 : struct ldb_module *module,
485 : const struct ldb_request *request,
486 : const struct ldb_reply *reply)
487 : {
488 7998 : struct ldb_context *ldb = NULL;
489 7998 : const struct dom_sid *sid = NULL;
490 7998 : const char *dn = NULL;
491 7998 : struct json_object wrapper = json_empty_object;
492 7998 : struct json_object audit = json_empty_object;
493 7998 : const struct tsocket_address *remote = NULL;
494 7998 : const char* action = NULL;
495 7998 : const struct GUID *unique_session_token = NULL;
496 5960 : struct audit_private *audit_private
497 7998 : = talloc_get_type_abort(ldb_module_get_private(module),
498 : struct audit_private);
499 7998 : int rc = 0;
500 : enum event_id_type event_id;
501 :
502 7998 : ldb = ldb_module_get_ctx(module);
503 :
504 7998 : remote = dsdb_audit_get_remote_address(ldb);
505 7998 : sid = dsdb_audit_get_user_sid(module);
506 7998 : dn = dsdb_audit_get_primary_dn(request);
507 7998 : action = get_password_action(request, reply);
508 7998 : unique_session_token = dsdb_audit_get_unique_session_token(module);
509 7998 : event_id = get_password_windows_event_id(request, reply);
510 :
511 7998 : audit = json_new_object();
512 7998 : if (json_is_invalid(&audit)) {
513 0 : goto failure;
514 : }
515 7997 : rc = json_add_version(&audit, PASSWORD_MAJOR, PASSWORD_MINOR);
516 7997 : if (rc != 0) {
517 0 : goto failure;
518 : }
519 7996 : rc = json_add_int(&audit, "eventId", event_id);
520 7996 : if (rc != 0) {
521 0 : goto failure;
522 : }
523 7996 : rc = json_add_int(&audit, "statusCode", reply->error);
524 7996 : if (rc != 0) {
525 0 : goto failure;
526 : }
527 7996 : rc = json_add_string(&audit, "status", ldb_strerror(reply->error));
528 7996 : if (rc != 0) {
529 0 : goto failure;
530 : }
531 7996 : rc = json_add_address(&audit, "remoteAddress", remote);
532 7996 : if (rc != 0) {
533 0 : goto failure;
534 : }
535 7996 : rc = json_add_sid(&audit, "userSid", sid);
536 7996 : if (rc != 0) {
537 0 : goto failure;
538 : }
539 7996 : rc = json_add_string(&audit, "dn", dn);
540 7996 : if (rc != 0) {
541 0 : goto failure;
542 : }
543 7996 : rc = json_add_string(&audit, "action", action);
544 7996 : if (rc != 0) {
545 0 : goto failure;
546 : }
547 7996 : rc = json_add_guid(
548 7996 : &audit, "transactionId", &audit_private->transaction_guid);
549 7996 : if (rc != 0) {
550 0 : goto failure;
551 : }
552 7996 : rc = json_add_guid(&audit, "sessionId", unique_session_token);
553 7996 : if (rc != 0) {
554 0 : goto failure;
555 : }
556 :
557 7996 : wrapper = json_new_object();
558 7996 : if (json_is_invalid(&wrapper)) {
559 0 : goto failure;
560 : }
561 7995 : rc = json_add_timestamp(&wrapper);
562 7995 : if (rc != 0) {
563 0 : goto failure;
564 : }
565 7994 : rc = json_add_string(&wrapper, "type", PASSWORD_JSON_TYPE);
566 7994 : if (rc != 0) {
567 0 : goto failure;
568 : }
569 7994 : rc = json_add_object(&wrapper, PASSWORD_JSON_TYPE, &audit);
570 7994 : if (rc != 0) {
571 0 : goto failure;
572 : }
573 :
574 7994 : return wrapper;
575 4 : failure:
576 : /*
577 : * On a failure audit will not have been added to wrapper so it
578 : * needs to free it to avoid a leak.
579 : *
580 : * wrapper is freed to invalidate it as it will have only been
581 : * partially constructed and may be inconsistent.
582 : *
583 : * All the json manipulation routines handle a freed object correctly
584 : */
585 4 : json_free(&wrapper);
586 4 : json_free(&audit);
587 4 : DBG_ERR("Unable to create password change JSON audit message\n");
588 4 : return wrapper;
589 : }
590 :
591 :
592 : /*
593 : * @brief create a JSON object containing details of a transaction event.
594 : *
595 : * Create a JSON object detailing a transaction transaction life cycle events,
596 : * i.e. begin, commit, roll back
597 : *
598 : * @param action a one word description of the event/action
599 : * @param transaction_id the GUID identifying the current transaction.
600 : * @param status the status code returned by the operation
601 : * @param duration the duration of the operation.
602 : *
603 : * @return a JSON object detailing the event
604 : */
605 115079 : static struct json_object transaction_json(
606 : const char *action,
607 : struct GUID *transaction_id,
608 : const int64_t duration)
609 : {
610 115079 : struct json_object wrapper = json_empty_object;
611 115079 : struct json_object audit = json_empty_object;
612 115079 : int rc = 0;
613 :
614 115079 : audit = json_new_object();
615 115079 : if (json_is_invalid(&audit)) {
616 0 : goto failure;
617 : }
618 :
619 115078 : rc = json_add_version(&audit, TRANSACTION_MAJOR, TRANSACTION_MINOR);
620 115078 : if (rc != 0) {
621 0 : goto failure;
622 : }
623 115077 : rc = json_add_string(&audit, "action", action);
624 115077 : if (rc != 0) {
625 0 : goto failure;
626 : }
627 115077 : rc = json_add_guid(&audit, "transactionId", transaction_id);
628 115077 : if (rc != 0) {
629 0 : goto failure;
630 : }
631 115077 : rc = json_add_int(&audit, "duration", duration);
632 115077 : if (rc != 0) {
633 0 : goto failure;
634 : }
635 :
636 115077 : wrapper = json_new_object();
637 115077 : if (json_is_invalid(&wrapper)) {
638 0 : goto failure;
639 : }
640 115076 : rc = json_add_timestamp(&wrapper);
641 115076 : if (rc != 0) {
642 0 : goto failure;
643 : }
644 115075 : rc = json_add_string(&wrapper, "type", TRANSACTION_JSON_TYPE);
645 115075 : if (rc != 0) {
646 0 : goto failure;
647 : }
648 115075 : rc = json_add_object(&wrapper, TRANSACTION_JSON_TYPE, &audit);
649 115075 : if (rc != 0) {
650 0 : goto failure;
651 : }
652 :
653 115075 : return wrapper;
654 4 : failure:
655 : /*
656 : * On a failure audit will not have been added to wrapper so it
657 : * needs to free it to avoid a leak.
658 : *
659 : * wrapper is freed to invalidate it as it will have only been
660 : * partially constructed and may be inconsistent.
661 : *
662 : * All the json manipulation routines handle a freed object correctly
663 : */
664 4 : json_free(&wrapper);
665 4 : json_free(&audit);
666 4 : DBG_ERR("Unable to create transaction JSON audit message\n");
667 4 : return wrapper;
668 : }
669 :
670 :
671 : /*
672 : * @brief generate a JSON object detailing a commit failure.
673 : *
674 : * Generate a JSON object containing details of a commit failure.
675 : *
676 : * @param action the commit action, "commit" or "prepare"
677 : * @param status the status code returned by commit
678 : * @param reason any extra failure information/reason available
679 : * @param transaction_id the GUID identifying the current transaction.
680 : */
681 6 : static struct json_object commit_failure_json(
682 : const char *action,
683 : const int64_t duration,
684 : int status,
685 : const char *reason,
686 : struct GUID *transaction_id)
687 : {
688 6 : struct json_object wrapper = json_empty_object;
689 6 : struct json_object audit = json_empty_object;
690 6 : int rc = 0;
691 :
692 6 : audit = json_new_object();
693 6 : if (json_is_invalid(&audit)) {
694 0 : goto failure;
695 : }
696 5 : rc = json_add_version(&audit, TRANSACTION_MAJOR, TRANSACTION_MINOR);
697 5 : if (rc != 0) {
698 0 : goto failure;
699 : }
700 4 : rc = json_add_string(&audit, "action", action);
701 4 : if (rc != 0) {
702 0 : goto failure;
703 : }
704 4 : rc = json_add_guid(&audit, "transactionId", transaction_id);
705 4 : if (rc != 0) {
706 0 : goto failure;
707 : }
708 4 : rc = json_add_int(&audit, "duration", duration);
709 4 : if (rc != 0) {
710 0 : goto failure;
711 : }
712 4 : rc = json_add_int(&audit, "statusCode", status);
713 4 : if (rc != 0) {
714 0 : goto failure;
715 : }
716 4 : rc = json_add_string(&audit, "status", ldb_strerror(status));
717 4 : if (rc != 0) {
718 0 : goto failure;
719 : }
720 4 : rc = json_add_string(&audit, "reason", reason);
721 4 : if (rc != 0) {
722 0 : goto failure;
723 : }
724 :
725 4 : wrapper = json_new_object();
726 4 : if (json_is_invalid(&wrapper)) {
727 0 : goto failure;
728 : }
729 3 : rc = json_add_timestamp(&wrapper);
730 3 : if (rc != 0) {
731 0 : goto failure;
732 : }
733 2 : rc = json_add_string(&wrapper, "type", TRANSACTION_JSON_TYPE);
734 2 : if (rc != 0) {
735 0 : goto failure;
736 : }
737 2 : rc = json_add_object(&wrapper, TRANSACTION_JSON_TYPE, &audit);
738 2 : if (rc != 0) {
739 0 : goto failure;
740 : }
741 :
742 2 : return wrapper;
743 4 : failure:
744 : /*
745 : * On a failure audit will not have been added to wrapper so it
746 : * needs to free it to avoid a leak.
747 : *
748 : * wrapper is freed to invalidate it as it will have only been
749 : * partially constructed and may be inconsistent.
750 : *
751 : * All the json manipulation routines handle a freed object correctly
752 : */
753 4 : json_free(&audit);
754 4 : json_free(&wrapper);
755 4 : DBG_ERR("Unable to create commit failure JSON audit message\n");
756 4 : return wrapper;
757 : }
758 :
759 : /*
760 : * @brief Print a human readable log line for a password change event.
761 : *
762 : * Generate a human readable log line detailing a password change.
763 : *
764 : * @param mem_ctx The talloc context that will own the generated log line.
765 : * @param module the ldb module
766 : * @param request the request
767 : * @param reply the result/response
768 : * @param status the status code returned for the underlying ldb operation.
769 : *
770 : * @return the generated log line.
771 : */
772 2 : static char *password_change_human_readable(
773 : TALLOC_CTX *mem_ctx,
774 : struct ldb_module *module,
775 : const struct ldb_request *request,
776 : const struct ldb_reply *reply)
777 : {
778 2 : struct ldb_context *ldb = NULL;
779 2 : const char *remote_host = NULL;
780 2 : const struct dom_sid *sid = NULL;
781 : struct dom_sid_buf user_sid;
782 2 : const char *timestamp = NULL;
783 2 : char *log_entry = NULL;
784 2 : const char *action = NULL;
785 2 : const char *dn = NULL;
786 :
787 2 : TALLOC_CTX *ctx = talloc_new(NULL);
788 :
789 2 : ldb = ldb_module_get_ctx(module);
790 :
791 2 : remote_host = dsdb_audit_get_remote_host(ldb, ctx);
792 2 : sid = dsdb_audit_get_user_sid(module);
793 2 : timestamp = audit_get_timestamp(ctx);
794 2 : action = get_password_action(request, reply);
795 2 : dn = dsdb_audit_get_primary_dn(request);
796 :
797 2 : log_entry = talloc_asprintf(
798 : mem_ctx,
799 : "[%s] at [%s] status [%s] "
800 : "remote host [%s] SID [%s] DN [%s]",
801 : action,
802 : timestamp,
803 0 : ldb_strerror(reply->error),
804 : remote_host,
805 : dom_sid_str_buf(sid, &user_sid),
806 : dn);
807 2 : TALLOC_FREE(ctx);
808 2 : return log_entry;
809 : }
810 : /*
811 : * @brief Generate a human readable string, detailing attributes in a message
812 : *
813 : * For modify operations each attribute is prefixed with the action.
814 : * Normal values are enclosed in []
815 : * Base64 values are enclosed in {}
816 : * Truncated values are indicated by three trailing dots "..."
817 : *
818 : * @param ldb The ldb_context
819 : * @param buffer The attributes will be appended to the buffer.
820 : * assumed to have been allocated via talloc.
821 : * @param operation The operation type
822 : * @param message the message to process
823 : *
824 : */
825 10 : static char *log_attributes(
826 : struct ldb_context *ldb,
827 : char *buffer,
828 : enum ldb_request_type operation,
829 : const struct ldb_message *message)
830 : {
831 : size_t i, j;
832 20 : for (i=0;i<message->num_elements;i++) {
833 10 : if (i > 0) {
834 1 : buffer = talloc_asprintf_append_buffer(buffer, " ");
835 : }
836 :
837 10 : if (message->elements[i].name == NULL) {
838 0 : ldb_debug(
839 : ldb,
840 : LDB_DEBUG_ERROR,
841 : "Error: Invalid element name (NULL) at "
842 : "position %zu", i);
843 0 : return NULL;
844 : }
845 :
846 10 : if (operation == LDB_MODIFY) {
847 4 : const char *action =NULL;
848 4 : action = dsdb_audit_get_modification_action(
849 0 : message->elements[i].flags);
850 4 : buffer = talloc_asprintf_append_buffer(
851 : buffer,
852 : "%s: %s ",
853 : action,
854 4 : message->elements[i].name);
855 : } else {
856 6 : buffer = talloc_asprintf_append_buffer(
857 : buffer,
858 : "%s ",
859 0 : message->elements[i].name);
860 : }
861 :
862 10 : if (dsdb_audit_redact_attribute(message->elements[i].name)) {
863 : /*
864 : * Do not log the value of any secret or password
865 : * attributes
866 : */
867 2 : buffer = talloc_asprintf_append_buffer(
868 : buffer,
869 : "[REDACTED SECRET ATTRIBUTE]");
870 2 : continue;
871 : }
872 :
873 9 : for (j=0;j<message->elements[i].num_values;j++) {
874 : struct ldb_val v;
875 9 : bool use_b64_encode = false;
876 : size_t length;
877 9 : if (j > 0) {
878 1 : buffer = talloc_asprintf_append_buffer(
879 : buffer,
880 : " ");
881 : }
882 :
883 9 : v = message->elements[i].values[j];
884 9 : length = min(MAX_LENGTH, v.length);
885 9 : use_b64_encode = ldb_should_b64_encode(ldb, &v);
886 9 : if (use_b64_encode) {
887 2 : const char *encoded = ldb_base64_encode(
888 : buffer,
889 1 : (char *)v.data,
890 : length);
891 1 : buffer = talloc_asprintf_append_buffer(
892 : buffer,
893 : "{%s%s}",
894 : encoded,
895 1 : (v.length > MAX_LENGTH ? "..." : ""));
896 : } else {
897 16 : buffer = talloc_asprintf_append_buffer(
898 : buffer,
899 : "[%*.*s%s]",
900 : (int)length,
901 : (int)length,
902 8 : (char *)v.data,
903 8 : (v.length > MAX_LENGTH ? "..." : ""));
904 : }
905 : }
906 : }
907 0 : return buffer;
908 : }
909 :
910 : /*
911 : * @brief generate a human readable log entry detailing an ldb operation.
912 : *
913 : * Generate a human readable log entry detailing an ldb operation.
914 : *
915 : * @param mem_ctx The talloc context owning the returned string.
916 : * @param module the ldb module
917 : * @param request the request
918 : * @param reply the result of the operation
919 : *
920 : * @return the log entry.
921 : *
922 : */
923 3 : static char *operation_human_readable(
924 : TALLOC_CTX *mem_ctx,
925 : struct ldb_module *module,
926 : const struct ldb_request *request,
927 : const struct ldb_reply *reply)
928 : {
929 3 : struct ldb_context *ldb = NULL;
930 3 : const char *remote_host = NULL;
931 3 : const struct tsocket_address *remote = NULL;
932 3 : const struct dom_sid *sid = NULL;
933 : struct dom_sid_buf user_sid;
934 3 : const char *timestamp = NULL;
935 3 : const char *op_name = NULL;
936 3 : char *log_entry = NULL;
937 3 : const char *dn = NULL;
938 3 : const char *new_dn = NULL;
939 3 : const struct ldb_message *message = NULL;
940 :
941 3 : TALLOC_CTX *ctx = talloc_new(NULL);
942 :
943 3 : ldb = ldb_module_get_ctx(module);
944 :
945 3 : remote_host = dsdb_audit_get_remote_host(ldb, ctx);
946 3 : remote = dsdb_audit_get_remote_address(ldb);
947 3 : if (remote != NULL && dsdb_audit_is_system_session(module)) {
948 1 : sid = dsdb_audit_get_actual_sid(ldb);
949 : } else {
950 2 : sid = dsdb_audit_get_user_sid(module);
951 : }
952 3 : timestamp = audit_get_timestamp(ctx);
953 3 : op_name = dsdb_audit_get_operation_name(request);
954 3 : dn = dsdb_audit_get_primary_dn(request);
955 3 : new_dn = dsdb_audit_get_secondary_dn(request);
956 :
957 3 : message = dsdb_audit_get_message(request);
958 :
959 3 : log_entry = talloc_asprintf(
960 : mem_ctx,
961 : "[%s] at [%s] status [%s] "
962 : "remote host [%s] SID [%s] DN [%s]",
963 : op_name,
964 : timestamp,
965 0 : ldb_strerror(reply->error),
966 : remote_host,
967 : dom_sid_str_buf(sid, &user_sid),
968 : dn);
969 3 : if (new_dn != NULL) {
970 0 : log_entry = talloc_asprintf_append_buffer(
971 : log_entry,
972 : " New DN [%s]",
973 : new_dn);
974 : }
975 3 : if (message != NULL) {
976 2 : log_entry = talloc_asprintf_append_buffer(log_entry,
977 : " attributes [");
978 2 : log_entry = log_attributes(ldb,
979 : log_entry,
980 0 : request->operation,
981 : message);
982 2 : log_entry = talloc_asprintf_append_buffer(log_entry, "]");
983 : }
984 3 : TALLOC_FREE(ctx);
985 3 : return log_entry;
986 : }
987 :
988 : /*
989 : * @brief generate a human readable log entry detailing a replicated update
990 : * operation.
991 : *
992 : * Generate a human readable log entry detailing a replicated update operation
993 : *
994 : * @param mem_ctx The talloc context owning the returned string.
995 : * @param module the ldb module
996 : * @param request the request
997 : * @param reply the result of the operation.
998 : *
999 : * @return the log entry.
1000 : *
1001 : */
1002 2 : static char *replicated_update_human_readable(
1003 : TALLOC_CTX *mem_ctx,
1004 : struct ldb_module *module,
1005 : const struct ldb_request *request,
1006 : const struct ldb_reply *reply)
1007 : {
1008 2 : struct dsdb_extended_replicated_objects *ro = talloc_get_type(
1009 : request->op.extended.data,
1010 : struct dsdb_extended_replicated_objects);
1011 2 : const char *partition_dn = NULL;
1012 2 : const char *error = NULL;
1013 2 : char *log_entry = NULL;
1014 2 : char *timestamp = NULL;
1015 : struct GUID_txt_buf object_buf;
1016 2 : const char *object = NULL;
1017 : struct GUID_txt_buf invocation_buf;
1018 2 : const char *invocation = NULL;
1019 :
1020 :
1021 2 : TALLOC_CTX *ctx = talloc_new(NULL);
1022 :
1023 2 : timestamp = audit_get_timestamp(ctx);
1024 2 : error = get_friendly_werror_msg(ro->error);
1025 2 : partition_dn = ldb_dn_get_linearized(ro->partition_dn);
1026 2 : object = GUID_buf_string(
1027 2 : &ro->source_dsa->source_dsa_obj_guid,
1028 : &object_buf);
1029 2 : invocation = GUID_buf_string(
1030 2 : &ro->source_dsa->source_dsa_invocation_id,
1031 : &invocation_buf);
1032 :
1033 :
1034 2 : log_entry = talloc_asprintf(
1035 : mem_ctx,
1036 : "at [%s] status [%s] error [%s] partition [%s] objects [%d] "
1037 : "links [%d] object [%s] invocation [%s]",
1038 : timestamp,
1039 0 : ldb_strerror(reply->error),
1040 : error,
1041 : partition_dn,
1042 : ro->num_objects,
1043 : ro->linked_attributes_count,
1044 : object,
1045 : invocation);
1046 :
1047 2 : TALLOC_FREE(ctx);
1048 2 : return log_entry;
1049 : }
1050 : /*
1051 : * @brief create a human readable log entry detailing a transaction event.
1052 : *
1053 : * Create a human readable log entry detailing a transaction event.
1054 : * i.e. begin, commit, roll back
1055 : *
1056 : * @param mem_ctx The talloc context owning the returned string.
1057 : * @param action a one word description of the event/action
1058 : * @param duration the duration of the transaction.
1059 : *
1060 : * @return the log entry
1061 : */
1062 1 : static char *transaction_human_readable(
1063 : TALLOC_CTX *mem_ctx,
1064 : const char* action,
1065 : const int64_t duration)
1066 : {
1067 1 : const char *timestamp = NULL;
1068 1 : char *log_entry = NULL;
1069 :
1070 1 : TALLOC_CTX *ctx = talloc_new(NULL);
1071 :
1072 1 : timestamp = audit_get_timestamp(ctx);
1073 :
1074 1 : log_entry = talloc_asprintf(
1075 : mem_ctx,
1076 : "[%s] at [%s] duration [%"PRIi64"]",
1077 : action,
1078 : timestamp,
1079 : duration);
1080 :
1081 1 : TALLOC_FREE(ctx);
1082 1 : return log_entry;
1083 : }
1084 :
1085 : /*
1086 : * @brief generate a human readable log entry detailing a commit failure.
1087 : *
1088 : * Generate generate a human readable log entry detailing a commit failure.
1089 : *
1090 : * @param mem_ctx The talloc context owning the returned string.
1091 : * @param action the commit action, "prepare" or "commit"
1092 : * @param status the status code returned by commit
1093 : * @param reason any extra failure information/reason available
1094 : *
1095 : * @return the log entry
1096 : */
1097 1 : static char *commit_failure_human_readable(
1098 : TALLOC_CTX *mem_ctx,
1099 : const char *action,
1100 : const int64_t duration,
1101 : int status,
1102 : const char *reason)
1103 : {
1104 1 : const char *timestamp = NULL;
1105 1 : char *log_entry = NULL;
1106 :
1107 1 : TALLOC_CTX *ctx = talloc_new(NULL);
1108 :
1109 1 : timestamp = audit_get_timestamp(ctx);
1110 :
1111 1 : log_entry = talloc_asprintf(
1112 : mem_ctx,
1113 : "[%s] at [%s] duration [%"PRIi64"] status [%d] reason [%s]",
1114 : action,
1115 : timestamp,
1116 : duration,
1117 : status,
1118 : reason);
1119 :
1120 1 : TALLOC_FREE(ctx);
1121 1 : return log_entry;
1122 : }
1123 :
1124 : /*
1125 : * @brief log details of a standard ldb operation.
1126 : *
1127 : * Log the details of an ldb operation in JSON and or human readable format
1128 : * and send over the message bus.
1129 : *
1130 : * @param module the ldb_module
1131 : * @param request the operation request.
1132 : * @param reply the operation result.
1133 : * @param the status code returned for the operation.
1134 : *
1135 : */
1136 847139 : static void log_standard_operation(
1137 : struct ldb_module *module,
1138 : const struct ldb_request *request,
1139 : const struct ldb_reply *reply)
1140 : {
1141 :
1142 847139 : const struct ldb_message *message = dsdb_audit_get_message(request);
1143 847139 : bool password_changed = has_password_changed(message);
1144 679149 : struct audit_private *audit_private =
1145 847139 : talloc_get_type_abort(ldb_module_get_private(module),
1146 : struct audit_private);
1147 :
1148 847139 : TALLOC_CTX *ctx = talloc_new(NULL);
1149 :
1150 847139 : if (CHECK_DEBUGLVLC(DBGC_DSDB_AUDIT, OPERATION_LOG_LVL)) {
1151 0 : char *entry = NULL;
1152 0 : entry = operation_human_readable(
1153 : ctx,
1154 : module,
1155 : request,
1156 : reply);
1157 0 : audit_log_human_text(
1158 : OPERATION_HR_TAG,
1159 : entry,
1160 : DBGC_DSDB_AUDIT,
1161 : OPERATION_LOG_LVL);
1162 0 : TALLOC_FREE(entry);
1163 : }
1164 847139 : if (CHECK_DEBUGLVLC(DBGC_DSDB_PWD_AUDIT, PASSWORD_LOG_LVL)) {
1165 0 : if (password_changed) {
1166 0 : char *entry = NULL;
1167 0 : entry = password_change_human_readable(
1168 : ctx,
1169 : module,
1170 : request,
1171 : reply);
1172 0 : audit_log_human_text(
1173 : PASSWORD_HR_TAG,
1174 : entry,
1175 : DBGC_DSDB_PWD_AUDIT,
1176 : PASSWORD_LOG_LVL);
1177 0 : TALLOC_FREE(entry);
1178 : }
1179 : }
1180 1526288 : if (CHECK_DEBUGLVLC(DBGC_DSDB_AUDIT_JSON, OPERATION_LOG_LVL) ||
1181 847139 : (audit_private->msg_ctx
1182 294341 : && audit_private->send_samdb_events)) {
1183 : struct json_object json;
1184 294341 : json = operation_json(module, request, reply);
1185 294341 : audit_log_json(
1186 : &json,
1187 : DBGC_DSDB_AUDIT_JSON,
1188 : OPERATION_LOG_LVL);
1189 294341 : if (audit_private->msg_ctx
1190 294341 : && audit_private->send_samdb_events) {
1191 294341 : audit_message_send(
1192 : audit_private->msg_ctx,
1193 : DSDB_EVENT_NAME,
1194 : MSG_DSDB_LOG,
1195 : &json);
1196 : }
1197 294341 : json_free(&json);
1198 : }
1199 1526288 : if (CHECK_DEBUGLVLC(DBGC_DSDB_PWD_AUDIT_JSON, PASSWORD_LOG_LVL) ||
1200 847139 : (audit_private->msg_ctx
1201 294341 : && audit_private->send_password_events)) {
1202 294341 : if (password_changed) {
1203 : struct json_object json;
1204 7991 : json = password_change_json(module, request, reply);
1205 7991 : audit_log_json(
1206 : &json,
1207 : DBGC_DSDB_PWD_AUDIT_JSON,
1208 : PASSWORD_LOG_LVL);
1209 7991 : if (audit_private->send_password_events) {
1210 7991 : audit_message_send(
1211 : audit_private->msg_ctx,
1212 : DSDB_PWD_EVENT_NAME,
1213 : MSG_DSDB_PWD_LOG,
1214 : &json);
1215 : }
1216 7991 : json_free(&json);
1217 : }
1218 : }
1219 847139 : TALLOC_FREE(ctx);
1220 847139 : }
1221 :
1222 : /*
1223 : * @brief log details of a replicated update.
1224 : *
1225 : * Log the details of a replicated update in JSON and or human readable
1226 : * format and send over the message bus.
1227 : *
1228 : * @param module the ldb_module
1229 : * @param request the operation request
1230 : * @param reply the result of the operation.
1231 : *
1232 : */
1233 0 : static void log_replicated_operation(
1234 : struct ldb_module *module,
1235 : const struct ldb_request *request,
1236 : const struct ldb_reply *reply)
1237 : {
1238 :
1239 0 : struct audit_private *audit_private =
1240 0 : talloc_get_type_abort(ldb_module_get_private(module),
1241 : struct audit_private);
1242 :
1243 0 : TALLOC_CTX *ctx = talloc_new(NULL);
1244 :
1245 0 : if (CHECK_DEBUGLVLC(DBGC_DSDB_AUDIT, REPLICATION_LOG_LVL)) {
1246 0 : char *entry = NULL;
1247 0 : entry = replicated_update_human_readable(
1248 : ctx,
1249 : module,
1250 : request,
1251 : reply);
1252 0 : audit_log_human_text(
1253 : REPLICATION_HR_TAG,
1254 : entry,
1255 : DBGC_DSDB_AUDIT,
1256 : REPLICATION_LOG_LVL);
1257 0 : TALLOC_FREE(entry);
1258 : }
1259 0 : if (CHECK_DEBUGLVLC(DBGC_DSDB_AUDIT_JSON, REPLICATION_LOG_LVL) ||
1260 0 : (audit_private->msg_ctx && audit_private->send_samdb_events)) {
1261 : struct json_object json;
1262 0 : json = replicated_update_json(module, request, reply);
1263 0 : audit_log_json(
1264 : &json,
1265 : DBGC_DSDB_AUDIT_JSON,
1266 : REPLICATION_LOG_LVL);
1267 0 : if (audit_private->send_samdb_events) {
1268 0 : audit_message_send(
1269 : audit_private->msg_ctx,
1270 : DSDB_EVENT_NAME,
1271 : MSG_DSDB_LOG,
1272 : &json);
1273 : }
1274 0 : json_free(&json);
1275 : }
1276 0 : TALLOC_FREE(ctx);
1277 0 : }
1278 :
1279 : /*
1280 : * @brief log details of an ldb operation.
1281 : *
1282 : * Log the details of an ldb operation in JSON and or human readable format
1283 : * and send over the message bus.
1284 : *
1285 : * @param module the ldb_module
1286 : * @param request the operation request
1287 : * @part reply the result of the operation
1288 : *
1289 : */
1290 851109 : static void log_operation(
1291 : struct ldb_module *module,
1292 : const struct ldb_request *request,
1293 : const struct ldb_reply *reply)
1294 : {
1295 :
1296 851109 : if (request->operation == LDB_EXTENDED) {
1297 3970 : if (strcmp(
1298 69 : request->op.extended.oid,
1299 : DSDB_EXTENDED_REPLICATED_OBJECTS_OID) != 0) {
1300 :
1301 0 : log_replicated_operation(module, request, reply);
1302 : }
1303 : } else {
1304 847139 : log_standard_operation(module, request, reply);
1305 : }
1306 851109 : }
1307 :
1308 : /*
1309 : * @brief log details of a transaction event.
1310 : *
1311 : * Log the details of a transaction event in JSON and or human readable format
1312 : * and send over the message bus.
1313 : *
1314 : * @param module the ldb_module
1315 : * @param action the transaction event i.e. begin, commit, roll back.
1316 : * @param log_level the logging level
1317 : *
1318 : */
1319 258847 : static void log_transaction(
1320 : struct ldb_module *module,
1321 : const char *action,
1322 : int log_level)
1323 : {
1324 :
1325 195438 : struct audit_private *audit_private =
1326 258847 : talloc_get_type_abort(ldb_module_get_private(module),
1327 : struct audit_private);
1328 258847 : const struct timeval now = timeval_current();
1329 258847 : const int64_t duration = usec_time_diff(&now, &audit_private->transaction_start);
1330 :
1331 258847 : TALLOC_CTX *ctx = talloc_new(NULL);
1332 :
1333 258847 : if (CHECK_DEBUGLVLC(DBGC_DSDB_TXN_AUDIT, log_level)) {
1334 0 : char* entry = NULL;
1335 0 : entry = transaction_human_readable(ctx, action, duration);
1336 0 : audit_log_human_text(
1337 : TRANSACTION_HR_TAG,
1338 : entry,
1339 : DBGC_DSDB_TXN_AUDIT,
1340 : log_level);
1341 0 : TALLOC_FREE(entry);
1342 : }
1343 454285 : if (CHECK_DEBUGLVLC(DBGC_DSDB_TXN_AUDIT_JSON, log_level) ||
1344 354780 : (audit_private->msg_ctx && audit_private->send_samdb_events)) {
1345 : struct json_object json;
1346 115073 : json = transaction_json(
1347 : action,
1348 : &audit_private->transaction_guid,
1349 : duration);
1350 115073 : audit_log_json(
1351 : &json,
1352 : DBGC_DSDB_TXN_AUDIT_JSON,
1353 : log_level);
1354 115073 : if (audit_private->send_samdb_events) {
1355 115073 : audit_message_send(
1356 : audit_private->msg_ctx,
1357 : DSDB_EVENT_NAME,
1358 : MSG_DSDB_LOG,
1359 : &json);
1360 : }
1361 115073 : json_free(&json);
1362 : }
1363 258847 : TALLOC_FREE(ctx);
1364 258847 : }
1365 :
1366 : /*
1367 : * @brief log details of a commit failure.
1368 : *
1369 : * Log the details of a commit failure in JSON and or human readable
1370 : * format and send over the message bus.
1371 : *
1372 : * @param module the ldb_module
1373 : * @param action the commit action "prepare" or "commit"
1374 : * @param status the ldb status code returned by prepare commit.
1375 : *
1376 : */
1377 0 : static void log_commit_failure(
1378 : struct ldb_module *module,
1379 : const char *action,
1380 : int status)
1381 : {
1382 :
1383 0 : struct audit_private *audit_private =
1384 0 : talloc_get_type_abort(ldb_module_get_private(module),
1385 : struct audit_private);
1386 0 : const char* reason = dsdb_audit_get_ldb_error_string(module, status);
1387 0 : const int log_level = TRANSACTION_LOG_FAILURE_LVL;
1388 0 : const struct timeval now = timeval_current();
1389 0 : const int64_t duration = usec_time_diff(&now,
1390 0 : &audit_private->transaction_start);
1391 :
1392 0 : TALLOC_CTX *ctx = talloc_new(NULL);
1393 :
1394 0 : if (CHECK_DEBUGLVLC(DBGC_DSDB_TXN_AUDIT, log_level)) {
1395 :
1396 0 : char* entry = NULL;
1397 0 : entry = commit_failure_human_readable(
1398 : ctx,
1399 : action,
1400 : duration,
1401 : status,
1402 : reason);
1403 0 : audit_log_human_text(
1404 : TRANSACTION_HR_TAG,
1405 : entry,
1406 : DBGC_DSDB_TXN_AUDIT,
1407 : TRANSACTION_LOG_FAILURE_LVL);
1408 0 : TALLOC_FREE(entry);
1409 : }
1410 0 : if (CHECK_DEBUGLVLC(DBGC_DSDB_TXN_AUDIT_JSON, log_level) ||
1411 0 : (audit_private->msg_ctx
1412 0 : && audit_private->send_samdb_events)) {
1413 : struct json_object json;
1414 0 : json = commit_failure_json(
1415 : action,
1416 : duration,
1417 : status,
1418 : reason,
1419 : &audit_private->transaction_guid);
1420 0 : audit_log_json(
1421 : &json,
1422 : DBGC_DSDB_TXN_AUDIT_JSON,
1423 : log_level);
1424 0 : if (audit_private->send_samdb_events) {
1425 0 : audit_message_send(audit_private->msg_ctx,
1426 : DSDB_EVENT_NAME,
1427 : MSG_DSDB_LOG,
1428 : &json);
1429 : }
1430 0 : json_free(&json);
1431 : }
1432 0 : TALLOC_FREE(ctx);
1433 0 : }
1434 :
1435 : /*
1436 : * Context needed by audit_callback
1437 : */
1438 : struct audit_callback_context {
1439 : struct ldb_request *request;
1440 : struct ldb_module *module;
1441 : };
1442 :
1443 : /*
1444 : * @brief call back function for the ldb_operations.
1445 : *
1446 : * As the LDB operations are async, and we wish to examine the results of
1447 : * the operations, a callback needs to be registered to process the results
1448 : * of the LDB operations.
1449 : *
1450 : * @param req the ldb request
1451 : * @param res the result of the operation
1452 : *
1453 : * @return the LDB_STATUS
1454 : */
1455 851143 : static int audit_callback(struct ldb_request *req, struct ldb_reply *ares)
1456 : {
1457 851143 : struct audit_callback_context *ac = NULL;
1458 :
1459 851143 : ac = talloc_get_type(
1460 : req->context,
1461 : struct audit_callback_context);
1462 :
1463 851143 : if (!ares) {
1464 0 : return ldb_module_done(
1465 : ac->request,
1466 : NULL,
1467 : NULL,
1468 : LDB_ERR_OPERATIONS_ERROR);
1469 : }
1470 :
1471 : /* pass on to the callback */
1472 851143 : switch (ares->type) {
1473 0 : case LDB_REPLY_ENTRY:
1474 0 : return ldb_module_send_entry(
1475 : ac->request,
1476 : ares->message,
1477 : ares->controls);
1478 :
1479 34 : case LDB_REPLY_REFERRAL:
1480 34 : return ldb_module_send_referral(
1481 : ac->request,
1482 : ares->referral);
1483 :
1484 851109 : case LDB_REPLY_DONE:
1485 : /*
1486 : * Log the operation once DONE
1487 : */
1488 851109 : log_operation(ac->module, ac->request, ares);
1489 851109 : return ldb_module_done(
1490 : ac->request,
1491 : ares->controls,
1492 : ares->response,
1493 : ares->error);
1494 :
1495 0 : default:
1496 : /* Can't happen */
1497 0 : return LDB_ERR_OPERATIONS_ERROR;
1498 : }
1499 : }
1500 :
1501 : /*
1502 : * @brief Add the current transaction identifier to the request.
1503 : *
1504 : * Add the current transaction identifier in the module private data,
1505 : * to the request as a control.
1506 : *
1507 : * @param module
1508 : * @param req the request.
1509 : *
1510 : * @return an LDB_STATUS code, LDB_SUCCESS if successful.
1511 : */
1512 850362 : static int add_transaction_id(
1513 : struct ldb_module *module,
1514 : struct ldb_request *req)
1515 : {
1516 682411 : struct audit_private *audit_private =
1517 850362 : talloc_get_type_abort(ldb_module_get_private(module),
1518 : struct audit_private);
1519 : struct dsdb_control_transaction_identifier *transaction_id;
1520 : int ret;
1521 :
1522 850362 : transaction_id = talloc_zero(
1523 : req,
1524 : struct dsdb_control_transaction_identifier);
1525 850362 : if (transaction_id == NULL) {
1526 0 : struct ldb_context *ldb = ldb_module_get_ctx(module);
1527 0 : return ldb_oom(ldb);
1528 : }
1529 850362 : transaction_id->transaction_guid = audit_private->transaction_guid;
1530 850362 : ret = ldb_request_add_control(req,
1531 : DSDB_CONTROL_TRANSACTION_IDENTIFIER_OID,
1532 : false,
1533 : transaction_id);
1534 850362 : return ret;
1535 :
1536 : }
1537 :
1538 : /*
1539 : * @brief log details of an add operation.
1540 : *
1541 : * Log the details of an add operation.
1542 : *
1543 : * @param module the ldb_module
1544 : * @param req the ldb_request
1545 : *
1546 : * @return ldb status code
1547 : */
1548 490202 : static int log_add(
1549 : struct ldb_module *module,
1550 : struct ldb_request *req)
1551 : {
1552 490202 : struct audit_callback_context *context = NULL;
1553 490202 : struct ldb_request *new_req = NULL;
1554 490202 : struct ldb_context *ldb = NULL;
1555 : int ret;
1556 :
1557 490202 : ldb = ldb_module_get_ctx(module);
1558 490202 : context = talloc_zero(req, struct audit_callback_context);
1559 :
1560 490202 : if (context == NULL) {
1561 0 : return ldb_oom(ldb);
1562 : }
1563 490202 : context->request = req;
1564 490202 : context->module = module;
1565 : /*
1566 : * We want to log the return code status, so we need to register
1567 : * a callback function to get the actual result.
1568 : * We need to take a new copy so that we don't alter the callers copy
1569 : */
1570 490202 : ret = ldb_build_add_req(
1571 : &new_req,
1572 : ldb,
1573 : req,
1574 : req->op.add.message,
1575 : req->controls,
1576 : context,
1577 : audit_callback,
1578 : req);
1579 490202 : if (ret != LDB_SUCCESS) {
1580 0 : return ret;
1581 : }
1582 490202 : ret = add_transaction_id(module, new_req);
1583 490202 : if (ret != LDB_SUCCESS) {
1584 0 : return ret;
1585 : }
1586 490202 : return ldb_next_request(module, new_req);
1587 : }
1588 :
1589 : /*
1590 : * @brief log details of an delete operation.
1591 : *
1592 : * Log the details of an delete operation.
1593 : *
1594 : * @param module the ldb_module
1595 : * @param req the ldb_request
1596 : *
1597 : * @return ldb status code
1598 : */
1599 76702 : static int log_delete(
1600 : struct ldb_module *module,
1601 : struct ldb_request *req)
1602 : {
1603 76702 : struct audit_callback_context *context = NULL;
1604 76702 : struct ldb_request *new_req = NULL;
1605 76702 : struct ldb_context *ldb = NULL;
1606 : int ret;
1607 :
1608 76702 : ldb = ldb_module_get_ctx(module);
1609 76702 : context = talloc_zero(req, struct audit_callback_context);
1610 :
1611 76702 : if (context == NULL) {
1612 0 : return ldb_oom(ldb);
1613 : }
1614 76702 : context->request = req;
1615 76702 : context->module = module;
1616 : /*
1617 : * We want to log the return code status, so we need to register
1618 : * a callback function to get the actual result.
1619 : * We need to take a new copy so that we don't alter the callers copy
1620 : */
1621 76702 : ret = ldb_build_del_req(&new_req,
1622 : ldb,
1623 : req,
1624 : req->op.del.dn,
1625 : req->controls,
1626 : context,
1627 : audit_callback,
1628 : req);
1629 76702 : if (ret != LDB_SUCCESS) {
1630 0 : return ret;
1631 : }
1632 76702 : ret = add_transaction_id(module, new_req);
1633 76702 : if (ret != LDB_SUCCESS) {
1634 0 : return ret;
1635 : }
1636 76702 : return ldb_next_request(module, new_req);
1637 : }
1638 :
1639 : /*
1640 : * @brief log details of a modify operation.
1641 : *
1642 : * Log the details of a modify operation.
1643 : *
1644 : * @param module the ldb_module
1645 : * @param req the ldb_request
1646 : *
1647 : * @return ldb status code
1648 : */
1649 279487 : static int log_modify(
1650 : struct ldb_module *module,
1651 : struct ldb_request *req)
1652 : {
1653 279487 : struct audit_callback_context *context = NULL;
1654 279487 : struct ldb_request *new_req = NULL;
1655 279487 : struct ldb_context *ldb = NULL;
1656 : int ret;
1657 :
1658 279487 : ldb = ldb_module_get_ctx(module);
1659 279487 : context = talloc_zero(req, struct audit_callback_context);
1660 :
1661 279487 : if (context == NULL) {
1662 0 : return ldb_oom(ldb);
1663 : }
1664 279487 : context->request = req;
1665 279487 : context->module = module;
1666 : /*
1667 : * We want to log the return code status, so we need to register
1668 : * a callback function to get the actual result.
1669 : * We need to take a new copy so that we don't alter the callers copy
1670 : */
1671 279487 : ret = ldb_build_mod_req(
1672 : & new_req,
1673 : ldb,
1674 : req,
1675 : req->op.mod.message,
1676 : req->controls,
1677 : context,
1678 : audit_callback,
1679 : req);
1680 279487 : if (ret != LDB_SUCCESS) {
1681 0 : return ret;
1682 : }
1683 279487 : ret = add_transaction_id(module, new_req);
1684 279487 : if (ret != LDB_SUCCESS) {
1685 0 : return ret;
1686 : }
1687 279487 : return ldb_next_request(module, new_req);
1688 : }
1689 :
1690 : /*
1691 : * @brief process a transaction start.
1692 : *
1693 : * process a transaction start, as we don't currently log transaction starts
1694 : * just generate the new transaction_id.
1695 : *
1696 : * @param module the ldb_module
1697 : * @param req the ldb_request
1698 : *
1699 : * @return ldb status code
1700 : */
1701 258849 : static int log_start_transaction(struct ldb_module *module)
1702 : {
1703 195440 : struct audit_private *audit_private =
1704 258849 : talloc_get_type_abort(ldb_module_get_private(module),
1705 : struct audit_private);
1706 :
1707 : /*
1708 : * We do not log transaction begins
1709 : * however we do generate a new transaction_id and record the start
1710 : * time so that we can log the transaction duration.
1711 : *
1712 : */
1713 258849 : audit_private->transaction_guid = GUID_random();
1714 258849 : audit_private->transaction_start = timeval_current();
1715 258849 : return ldb_next_start_trans(module);
1716 : }
1717 :
1718 : /*
1719 : * @brief log details of a prepare commit.
1720 : *
1721 : * Log the details of a prepare commit, currently only details of
1722 : * failures are logged.
1723 : *
1724 : * @param module the ldb_module
1725 : * @param req the ldb_request
1726 : *
1727 : * @return ldb status code
1728 : */
1729 231527 : static int log_prepare_commit(struct ldb_module *module)
1730 : {
1731 :
1732 231527 : int ret = ldb_next_prepare_commit(module);
1733 231527 : if (ret != LDB_SUCCESS) {
1734 : /*
1735 : * We currently only log prepare commit failures
1736 : */
1737 0 : log_commit_failure(module, "prepare", ret);
1738 : }
1739 231527 : return ret;
1740 : }
1741 :
1742 : /*
1743 : * @brief process a transaction end aka commit.
1744 : *
1745 : * process a transaction end, as we don't currently log transaction ends
1746 : * just clear transaction_id.
1747 : *
1748 : * @param module the ldb_module
1749 : * @param req the ldb_request
1750 : *
1751 : * @return ldb status code
1752 : */
1753 231525 : static int log_end_transaction(struct ldb_module *module)
1754 : {
1755 178490 : struct audit_private *audit_private =
1756 231525 : talloc_get_type_abort(ldb_module_get_private(module),
1757 : struct audit_private);
1758 231525 : int ret = 0;
1759 :
1760 :
1761 231525 : ret = ldb_next_end_trans(module);
1762 231525 : if (ret == LDB_SUCCESS) {
1763 231525 : log_transaction(
1764 : module,
1765 : "commit",
1766 : TRANSACTION_LOG_COMPLETION_LVL);
1767 : } else {
1768 0 : log_commit_failure(module, "commit", ret);
1769 : }
1770 : /*
1771 : * Clear the transaction id inserted by log_start_transaction
1772 : */
1773 231525 : audit_private->transaction_guid = GUID_zero();
1774 231525 : return ret;
1775 : }
1776 :
1777 : /*
1778 : * @brief log details of a transaction delete aka roll back.
1779 : *
1780 : * Log details of a transaction roll back.
1781 : *
1782 : * @param module the ldb_module
1783 : * @param req the ldb_request
1784 : *
1785 : * @return ldb status code
1786 : */
1787 27322 : static int log_del_transaction(struct ldb_module *module)
1788 : {
1789 16948 : struct audit_private *audit_private =
1790 27322 : talloc_get_type_abort(ldb_module_get_private(module),
1791 : struct audit_private);
1792 :
1793 27322 : log_transaction(module, "rollback", TRANSACTION_LOG_FAILURE_LVL);
1794 27322 : audit_private->transaction_guid = GUID_zero();
1795 27322 : return ldb_next_del_trans(module);
1796 : }
1797 :
1798 : /*
1799 : * @brief log details of an extended operation.
1800 : *
1801 : * Log the details of an extended operation.
1802 : *
1803 : * @param module the ldb_module
1804 : * @param req the ldb_request
1805 : *
1806 : * @return ldb status code
1807 : */
1808 1442118 : static int log_extended(
1809 : struct ldb_module *module,
1810 : struct ldb_request *req)
1811 : {
1812 1442118 : struct audit_callback_context *context = NULL;
1813 1442118 : struct ldb_request *new_req = NULL;
1814 1442118 : struct ldb_context *ldb = NULL;
1815 : int ret;
1816 :
1817 : /*
1818 : * Currently we only log replication extended operations
1819 : */
1820 1442118 : if (strcmp(
1821 : req->op.extended.oid,
1822 : DSDB_EXTENDED_REPLICATED_OBJECTS_OID) != 0) {
1823 :
1824 1438148 : return ldb_next_request(module, req);
1825 : }
1826 3970 : ldb = ldb_module_get_ctx(module);
1827 3970 : context = talloc_zero(req, struct audit_callback_context);
1828 :
1829 3970 : if (context == NULL) {
1830 0 : return ldb_oom(ldb);
1831 : }
1832 3970 : context->request = req;
1833 3970 : context->module = module;
1834 : /*
1835 : * We want to log the return code status, so we need to register
1836 : * a callback function to get the actual result.
1837 : * We need to take a new copy so that we don't alter the callers copy
1838 : */
1839 3970 : ret = ldb_build_extended_req(
1840 : &new_req,
1841 : ldb,
1842 : req,
1843 : req->op.extended.oid,
1844 : req->op.extended.data,
1845 : req->controls,
1846 : context,
1847 : audit_callback,
1848 : req);
1849 3970 : if (ret != LDB_SUCCESS) {
1850 0 : return ret;
1851 : }
1852 3970 : ret = add_transaction_id(module, new_req);
1853 3970 : if (ret != LDB_SUCCESS) {
1854 0 : return ret;
1855 : }
1856 3970 : return ldb_next_request(module, new_req);
1857 : }
1858 :
1859 : /*
1860 : * @brief module initialisation
1861 : */
1862 132453 : static int log_init(struct ldb_module *module)
1863 : {
1864 :
1865 132453 : struct ldb_context *ldb = ldb_module_get_ctx(module);
1866 132453 : struct audit_private *audit_private = NULL;
1867 92424 : struct loadparm_context *lp_ctx
1868 132453 : = talloc_get_type_abort(ldb_get_opaque(ldb, "loadparm"),
1869 : struct loadparm_context);
1870 132453 : struct tevent_context *ev = ldb_get_event_context(ldb);
1871 132453 : bool sdb_events = false;
1872 132453 : bool pwd_events = false;
1873 :
1874 132453 : audit_private = talloc_zero(module, struct audit_private);
1875 132453 : if (audit_private == NULL) {
1876 0 : return ldb_module_oom(module);
1877 : }
1878 :
1879 132453 : if (lp_ctx != NULL) {
1880 132453 : sdb_events = lpcfg_dsdb_event_notification(lp_ctx);
1881 132453 : pwd_events = lpcfg_dsdb_password_event_notification(lp_ctx);
1882 : }
1883 132453 : if (sdb_events || pwd_events) {
1884 81617 : audit_private->send_samdb_events = sdb_events;
1885 81617 : audit_private->send_password_events = pwd_events;
1886 : audit_private->msg_ctx
1887 81617 : = imessaging_client_init(audit_private,
1888 : lp_ctx,
1889 : ev);
1890 : }
1891 :
1892 132453 : ldb_module_set_private(module, audit_private);
1893 132453 : return ldb_next_init(module);
1894 : }
1895 :
1896 : static const struct ldb_module_ops ldb_audit_log_module_ops = {
1897 : .name = "audit_log",
1898 : .init_context = log_init,
1899 : .add = log_add,
1900 : .modify = log_modify,
1901 : .del = log_delete,
1902 : .start_transaction = log_start_transaction,
1903 : .prepare_commit = log_prepare_commit,
1904 : .end_transaction = log_end_transaction,
1905 : .del_transaction = log_del_transaction,
1906 : .extended = log_extended,
1907 : };
1908 :
1909 5536 : int ldb_audit_log_module_init(const char *version)
1910 : {
1911 5536 : LDB_MODULE_CHECK_VERSION(version);
1912 5536 : return ldb_register_module(&ldb_audit_log_module_ops);
1913 : }
|
