dsdb: Log the transaction duraton.
[nivanova/samba-autobuild/.git] / python / samba / tests / audit_log_dsdb.py
1 # Tests for SamDb password change audit logging.
2 # Copyright (C) Andrew Bartlett <abartlet@samba.org> 2018
3 #
4 # This program is free software; you can redistribute it and/or modify
5 # it under the terms of the GNU General Public License as published by
6 # the Free Software Foundation; either version 3 of the License, or
7 # (at your option) any later version.
8 #
9 # This program is distributed in the hope that it will be useful,
10 # but WITHOUT ANY WARRANTY; without even the implied warranty of
11 # MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
12 # GNU General Public License for more details.
13 #
14 # You should have received a copy of the GNU General Public License
15 # along with this program.  If not, see <http://www.gnu.org/licenses/>.
16 #
17
18 from __future__ import print_function
19 """Tests for the SamDb logging of password changes.
20 """
21
22 import samba.tests
23 from samba.dcerpc.messaging import MSG_DSDB_LOG, DSDB_EVENT_NAME
24 from ldb import ERR_NO_SUCH_OBJECT
25 from samba.samdb import SamDB
26 from samba.auth import system_session
27 import os
28 import time
29 from samba.tests.audit_log_base import AuditLogTestBase
30 from samba.tests import delete_force
31 from samba.net import Net
32 import samba
33 from samba.dcerpc import security, lsa
34
35 USER_NAME = "auditlogtestuser"
36 USER_PASS = samba.generate_random_password(32, 32)
37
38
39 class AuditLogDsdbTests(AuditLogTestBase):
40
41     def setUp(self):
42         self.message_type = MSG_DSDB_LOG
43         self.event_type   = DSDB_EVENT_NAME
44         super(AuditLogDsdbTests, self).setUp()
45
46         self.remoteAddress = os.environ["CLIENT_IP"]
47         self.server_ip = os.environ["SERVER_IP"]
48
49         host = "ldap://%s" % os.environ["SERVER"]
50         self.ldb = SamDB(url=host,
51                          session_info=system_session(),
52                          credentials=self.get_credentials(),
53                          lp=self.get_loadparm())
54         self.server = os.environ["SERVER"]
55
56         # Gets back the basedn
57         self.base_dn = self.ldb.domain_dn()
58
59         # Get the old "dSHeuristics" if it was set
60         dsheuristics = self.ldb.get_dsheuristics()
61
62         # Set the "dSHeuristics" to activate the correct "userPassword"
63         # behaviour
64         self.ldb.set_dsheuristics("000000001")
65
66         # Reset the "dSHeuristics" as they were before
67         self.addCleanup(self.ldb.set_dsheuristics, dsheuristics)
68
69         # Get the old "minPwdAge"
70         minPwdAge = self.ldb.get_minPwdAge()
71
72         # Set it temporarily to "0"
73         self.ldb.set_minPwdAge("0")
74         self.base_dn = self.ldb.domain_dn()
75
76         # Reset the "minPwdAge" as it was before
77         self.addCleanup(self.ldb.set_minPwdAge, minPwdAge)
78
79         # (Re)adds the test user USER_NAME with password USER_PASS
80         delete_force(self.ldb, "cn=" + USER_NAME + ",cn=users," + self.base_dn)
81         self.ldb.add({
82             "dn": "cn=" + USER_NAME + ",cn=users," + self.base_dn,
83             "objectclass": "user",
84             "sAMAccountName": USER_NAME,
85             "userPassword": USER_PASS
86         })
87
88     #
89     # Discard the messages from the setup code
90     #
91     def discardSetupMessages(self, dn):
92         self.waitForMessages(2, dn=dn)
93         self.discardMessages()
94
95     def tearDown(self):
96         self.discardMessages()
97         super(AuditLogDsdbTests, self).tearDown()
98
99     def haveExpectedTxn(self, expected):
100         if self.context["txnMessage"] is not None:
101             txn = self.context["txnMessage"]["dsdbTransaction"]
102             if txn["transactionId"] == expected:
103                 return True
104         return False
105
106     def waitForTransaction(self, expected, connection=None):
107         """Wait for a transaction message to arrive
108         The connection is passed through to keep the connection alive
109         until all the logging messages have been received.
110         """
111
112         self.connection = connection
113
114         start_time = time.time()
115         while not self.haveExpectedTxn(expected):
116             self.msg_ctx.loop_once(0.1)
117             if time.time() - start_time > 1:
118                 self.connection = None
119                 return ""
120
121         self.connection = None
122         return self.context["txnMessage"]
123
124     def test_net_change_password(self):
125
126         dn = "CN=" + USER_NAME + ",CN=Users," + self.base_dn
127         self.discardSetupMessages(dn)
128
129         creds = self.insta_creds(template=self.get_credentials())
130
131         lp = self.get_loadparm()
132         net = Net(creds, lp, server=self.server)
133         password = "newPassword!!42"
134
135         net.change_password(newpassword=password.encode('utf-8'),
136                             username=USER_NAME,
137                             oldpassword=USER_PASS)
138
139         messages = self.waitForMessages(1, net, dn=dn)
140         print("Received %d messages" % len(messages))
141         self.assertEquals(1,
142                           len(messages),
143                           "Did not receive the expected number of messages")
144
145         audit = messages[0]["dsdbChange"]
146         self.assertEquals("Modify", audit["operation"])
147         self.assertFalse(audit["performedAsSystem"])
148         self.assertTrue(dn.lower(), audit["dn"].lower())
149         self.assertRegexpMatches(audit["remoteAddress"],
150                                  self.remoteAddress)
151         session_id = self.get_session()
152         self.assertEquals(session_id, audit["sessionId"])
153         service_description = self.get_service_description()
154         self.assertEquals(service_description, "DCE/RPC")
155         self.assertTrue(self.is_guid(audit["transactionId"]))
156
157         attributes = audit["attributes"]
158         self.assertEquals(1, len(attributes))
159         actions = attributes["clearTextPassword"]["actions"]
160         self.assertEquals(1, len(actions))
161         self.assertTrue(actions[0]["redacted"])
162         self.assertEquals("replace", actions[0]["action"])
163
164     def test_net_set_password(self):
165
166         dn = "CN=" + USER_NAME + ",CN=Users," + self.base_dn
167         self.discardSetupMessages(dn)
168
169         creds = self.insta_creds(template=self.get_credentials())
170
171         lp = self.get_loadparm()
172         net = Net(creds, lp, server=self.server)
173         password = "newPassword!!42"
174         domain = lp.get("workgroup")
175
176         net.set_password(newpassword=password.encode('utf-8'),
177                          account_name=USER_NAME,
178                          domain_name=domain)
179         messages = self.waitForMessages(1, net, dn=dn)
180         print("Received %d messages" % len(messages))
181         self.assertEquals(1,
182                           len(messages),
183                           "Did not receive the expected number of messages")
184         audit = messages[0]["dsdbChange"]
185         self.assertEquals("Modify", audit["operation"])
186         self.assertFalse(audit["performedAsSystem"])
187         self.assertEquals(dn, audit["dn"])
188         self.assertRegexpMatches(audit["remoteAddress"],
189                                  self.remoteAddress)
190         session_id = self.get_session()
191         self.assertEquals(session_id, audit["sessionId"])
192         service_description = self.get_service_description()
193         self.assertEquals(service_description, "DCE/RPC")
194         self.assertTrue(self.is_guid(audit["transactionId"]))
195
196         attributes = audit["attributes"]
197         self.assertEquals(1, len(attributes))
198         actions = attributes["clearTextPassword"]["actions"]
199         self.assertEquals(1, len(actions))
200         self.assertTrue(actions[0]["redacted"])
201         self.assertEquals("replace", actions[0]["action"])
202
203     def test_ldap_change_password(self):
204
205         dn = "cn=" + USER_NAME + ",cn=users," + self.base_dn
206         self.discardSetupMessages(dn)
207
208         new_password = samba.generate_random_password(32, 32)
209         dn = "cn=" + USER_NAME + ",cn=users," + self.base_dn
210         self.ldb.modify_ldif(
211             "dn: " + dn + "\n" +
212             "changetype: modify\n" +
213             "delete: userPassword\n" +
214             "userPassword: " + USER_PASS + "\n" +
215             "add: userPassword\n" +
216             "userPassword: " + new_password + "\n")
217
218         messages = self.waitForMessages(1)
219         print("Received %d messages" % len(messages))
220         self.assertEquals(1,
221                           len(messages),
222                           "Did not receive the expected number of messages")
223
224         audit = messages[0]["dsdbChange"]
225         self.assertEquals("Modify", audit["operation"])
226         self.assertFalse(audit["performedAsSystem"])
227         self.assertEquals(dn, audit["dn"])
228         self.assertRegexpMatches(audit["remoteAddress"],
229                                  self.remoteAddress)
230         self.assertTrue(self.is_guid(audit["sessionId"]))
231         session_id = self.get_session()
232         self.assertEquals(session_id, audit["sessionId"])
233         service_description = self.get_service_description()
234         self.assertEquals(service_description, "LDAP")
235
236         attributes = audit["attributes"]
237         self.assertEquals(1, len(attributes))
238         actions = attributes["userPassword"]["actions"]
239         self.assertEquals(2, len(actions))
240         self.assertTrue(actions[0]["redacted"])
241         self.assertEquals("delete", actions[0]["action"])
242         self.assertTrue(actions[1]["redacted"])
243         self.assertEquals("add", actions[1]["action"])
244
245     def test_ldap_replace_password(self):
246
247         dn = "cn=" + USER_NAME + ",cn=users," + self.base_dn
248         self.discardSetupMessages(dn)
249
250         new_password = samba.generate_random_password(32, 32)
251         self.ldb.modify_ldif(
252             "dn: " + dn + "\n" +
253             "changetype: modify\n" +
254             "replace: userPassword\n" +
255             "userPassword: " + new_password + "\n")
256
257         messages = self.waitForMessages(1, dn=dn)
258         print("Received %d messages" % len(messages))
259         self.assertEquals(1,
260                           len(messages),
261                           "Did not receive the expected number of messages")
262
263         audit = messages[0]["dsdbChange"]
264         self.assertEquals("Modify", audit["operation"])
265         self.assertFalse(audit["performedAsSystem"])
266         self.assertTrue(dn.lower(), audit["dn"].lower())
267         self.assertRegexpMatches(audit["remoteAddress"],
268                                  self.remoteAddress)
269         self.assertTrue(self.is_guid(audit["sessionId"]))
270         session_id = self.get_session()
271         self.assertEquals(session_id, audit["sessionId"])
272         service_description = self.get_service_description()
273         self.assertEquals(service_description, "LDAP")
274         self.assertTrue(self.is_guid(audit["transactionId"]))
275
276         attributes = audit["attributes"]
277         self.assertEquals(1, len(attributes))
278         actions = attributes["userPassword"]["actions"]
279         self.assertEquals(1, len(actions))
280         self.assertTrue(actions[0]["redacted"])
281         self.assertEquals("replace", actions[0]["action"])
282
283     def test_ldap_add_user(self):
284
285         # The setup code adds a user, so we check for the dsdb events
286         # generated by it.
287         dn = "cn=" + USER_NAME + ",cn=users," + self.base_dn
288         messages = self.waitForMessages(2, dn=dn)
289         print("Received %d messages" % len(messages))
290         self.assertEquals(2,
291                           len(messages),
292                           "Did not receive the expected number of messages")
293
294         audit = messages[1]["dsdbChange"]
295         self.assertEquals("Add", audit["operation"])
296         self.assertFalse(audit["performedAsSystem"])
297         self.assertEquals(dn, audit["dn"])
298         self.assertRegexpMatches(audit["remoteAddress"],
299                                  self.remoteAddress)
300         session_id = self.get_session()
301         self.assertEquals(session_id, audit["sessionId"])
302         service_description = self.get_service_description()
303         self.assertEquals(service_description, "LDAP")
304         self.assertTrue(self.is_guid(audit["sessionId"]))
305         self.assertTrue(self.is_guid(audit["transactionId"]))
306
307         attributes = audit["attributes"]
308         self.assertEquals(3, len(attributes))
309
310         actions = attributes["objectclass"]["actions"]
311         self.assertEquals(1, len(actions))
312         self.assertEquals("add", actions[0]["action"])
313         self.assertEquals(1, len(actions[0]["values"]))
314         self.assertEquals("user", actions[0]["values"][0]["value"])
315
316         actions = attributes["sAMAccountName"]["actions"]
317         self.assertEquals(1, len(actions))
318         self.assertEquals("add", actions[0]["action"])
319         self.assertEquals(1, len(actions[0]["values"]))
320         self.assertEquals(USER_NAME, actions[0]["values"][0]["value"])
321
322         actions = attributes["userPassword"]["actions"]
323         self.assertEquals(1, len(actions))
324         self.assertEquals("add", actions[0]["action"])
325         self.assertTrue(actions[0]["redacted"])
326
327     def test_samdb_delete_user(self):
328
329         dn = "cn=" + USER_NAME + ",cn=users," + self.base_dn
330         self.discardSetupMessages(dn)
331
332         self.ldb.deleteuser(USER_NAME)
333
334         messages = self.waitForMessages(1, dn=dn)
335         print("Received %d messages" % len(messages))
336         self.assertEquals(1,
337                           len(messages),
338                           "Did not receive the expected number of messages")
339
340         audit = messages[0]["dsdbChange"]
341         self.assertEquals("Delete", audit["operation"])
342         self.assertFalse(audit["performedAsSystem"])
343         self.assertTrue(dn.lower(), audit["dn"].lower())
344         self.assertRegexpMatches(audit["remoteAddress"],
345                                  self.remoteAddress)
346         self.assertTrue(self.is_guid(audit["sessionId"]))
347         self.assertEquals(0, audit["statusCode"])
348         self.assertEquals("Success", audit["status"])
349         session_id = self.get_session()
350         self.assertEquals(session_id, audit["sessionId"])
351         service_description = self.get_service_description()
352         self.assertEquals(service_description, "LDAP")
353
354         transactionId = audit["transactionId"]
355         message = self.waitForTransaction(transactionId)
356         audit = message["dsdbTransaction"]
357         self.assertEquals("commit", audit["action"])
358         self.assertTrue(self.is_guid(audit["transactionId"]))
359         self.assertTrue(audit["duration"] > 0)
360
361     def test_samdb_delete_non_existent_dn(self):
362
363         DOES_NOT_EXIST = "doesNotExist"
364         dn = "cn=" + USER_NAME + ",cn=users," + self.base_dn
365         self.discardSetupMessages(dn)
366
367         dn = "cn=" + DOES_NOT_EXIST + ",cn=users," + self.base_dn
368         try:
369             self.ldb.delete(dn)
370             self.fail("Exception not thrown")
371         except Exception:
372             pass
373
374         messages = self.waitForMessages(1)
375         print("Received %d messages" % len(messages))
376         self.assertEquals(1,
377                           len(messages),
378                           "Did not receive the expected number of messages")
379
380         audit = messages[0]["dsdbChange"]
381         self.assertEquals("Delete", audit["operation"])
382         self.assertFalse(audit["performedAsSystem"])
383         self.assertTrue(dn.lower(), audit["dn"].lower())
384         self.assertRegexpMatches(audit["remoteAddress"],
385                                  self.remoteAddress)
386         self.assertEquals(ERR_NO_SUCH_OBJECT, audit["statusCode"])
387         self.assertEquals("No such object", audit["status"])
388         self.assertTrue(self.is_guid(audit["sessionId"]))
389         session_id = self.get_session()
390         self.assertEquals(session_id, audit["sessionId"])
391         service_description = self.get_service_description()
392         self.assertEquals(service_description, "LDAP")
393
394         transactionId = audit["transactionId"]
395         message = self.waitForTransaction(transactionId)
396         audit = message["dsdbTransaction"]
397         self.assertEquals("rollback", audit["action"])
398         self.assertTrue(self.is_guid(audit["transactionId"]))
399         self.assertTrue(audit["duration"] > 0)
400
401     def test_create_and_delete_secret_over_lsa(self):
402
403         dn = "cn=Test Secret,CN=System," + self.base_dn
404         self.discardSetupMessages(dn)
405
406         creds = self.insta_creds(template=self.get_credentials())
407         lsa_conn = lsa.lsarpc(
408             "ncacn_np:%s" % self.server,
409             self.get_loadparm(),
410             creds)
411         lsa_handle = lsa_conn.OpenPolicy2(
412             system_name="\\",
413             attr=lsa.ObjectAttribute(),
414             access_mask=security.SEC_FLAG_MAXIMUM_ALLOWED)
415         secret_name = lsa.String()
416         secret_name.string = "G$Test"
417         lsa_conn.CreateSecret(
418             handle=lsa_handle,
419             name=secret_name,
420             access_mask=security.SEC_FLAG_MAXIMUM_ALLOWED)
421
422         messages = self.waitForMessages(1, dn=dn)
423         print("Received %d messages" % len(messages))
424         self.assertEquals(1,
425                           len(messages),
426                           "Did not receive the expected number of messages")
427
428         audit = messages[0]["dsdbChange"]
429         self.assertEquals("Add", audit["operation"])
430         self.assertTrue(audit["performedAsSystem"])
431         self.assertTrue(dn.lower(), audit["dn"].lower())
432         self.assertRegexpMatches(audit["remoteAddress"],
433                                  self.remoteAddress)
434         self.assertTrue(self.is_guid(audit["sessionId"]))
435         session_id = self.get_session()
436         self.assertEquals(session_id, audit["sessionId"])
437         service_description = self.get_service_description()
438         self.assertEquals(service_description, "DCE/RPC")
439         attributes = audit["attributes"]
440         self.assertEquals(2, len(attributes))
441
442         object_class = attributes["objectClass"]
443         self.assertEquals(1, len(object_class["actions"]))
444         action = object_class["actions"][0]
445         self.assertEquals("add", action["action"])
446         values = action["values"]
447         self.assertEquals(1, len(values))
448         self.assertEquals("secret", values[0]["value"])
449
450         cn = attributes["cn"]
451         self.assertEquals(1, len(cn["actions"]))
452         action = cn["actions"][0]
453         self.assertEquals("add", action["action"])
454         values = action["values"]
455         self.assertEquals(1, len(values))
456         self.assertEquals("Test Secret", values[0]["value"])
457
458         #
459         # Now delete the secret.
460         self.discardMessages()
461         h = lsa_conn.OpenSecret(
462             handle=lsa_handle,
463             name=secret_name,
464             access_mask=security.SEC_FLAG_MAXIMUM_ALLOWED)
465
466         lsa_conn.DeleteObject(h)
467         messages = self.waitForMessages(1, dn=dn)
468         print("Received %d messages" % len(messages))
469         self.assertEquals(1,
470                           len(messages),
471                           "Did not receive the expected number of messages")
472
473         dn = "cn=Test Secret,CN=System," + self.base_dn
474         audit = messages[0]["dsdbChange"]
475         self.assertEquals("Delete", audit["operation"])
476         self.assertTrue(audit["performedAsSystem"])
477         self.assertTrue(dn.lower(), audit["dn"].lower())
478         self.assertRegexpMatches(audit["remoteAddress"],
479                                  self.remoteAddress)
480         self.assertTrue(self.is_guid(audit["sessionId"]))
481         session_id = self.get_session()
482         self.assertEquals(session_id, audit["sessionId"])
483         service_description = self.get_service_description()
484         self.assertEquals(service_description, "DCE/RPC")
485
486     def test_modify(self):
487
488         dn = "cn=" + USER_NAME + ",cn=users," + self.base_dn
489         self.discardSetupMessages(dn)
490
491         #
492         # Add an attribute value
493         #
494         self.ldb.modify_ldif(
495             "dn: " + dn + "\n" +
496             "changetype: modify\n" +
497             "add: carLicense\n" +
498             "carLicense: license-01\n")
499
500         messages = self.waitForMessages(1, dn=dn)
501         print("Received %d messages" % len(messages))
502         self.assertEquals(1,
503                           len(messages),
504                           "Did not receive the expected number of messages")
505
506         audit = messages[0]["dsdbChange"]
507         self.assertEquals("Modify", audit["operation"])
508         self.assertFalse(audit["performedAsSystem"])
509         self.assertEquals(dn, audit["dn"])
510         self.assertRegexpMatches(audit["remoteAddress"],
511                                  self.remoteAddress)
512         self.assertTrue(self.is_guid(audit["sessionId"]))
513         session_id = self.get_session()
514         self.assertEquals(session_id, audit["sessionId"])
515         service_description = self.get_service_description()
516         self.assertEquals(service_description, "LDAP")
517
518         attributes = audit["attributes"]
519         self.assertEquals(1, len(attributes))
520         actions = attributes["carLicense"]["actions"]
521         self.assertEquals(1, len(actions))
522         self.assertEquals("add", actions[0]["action"])
523         values = actions[0]["values"]
524         self.assertEquals(1, len(values))
525         self.assertEquals("license-01", values[0]["value"])
526
527         #
528         # Add an another value to the attribute
529         #
530         self.discardMessages()
531         self.ldb.modify_ldif(
532             "dn: " + dn + "\n" +
533             "changetype: modify\n" +
534             "add: carLicense\n" +
535             "carLicense: license-02\n")
536
537         messages = self.waitForMessages(1, dn=dn)
538         print("Received %d messages" % len(messages))
539         self.assertEquals(1,
540                           len(messages),
541                           "Did not receive the expected number of messages")
542         attributes = messages[0]["dsdbChange"]["attributes"]
543         self.assertEquals(1, len(attributes))
544         actions = attributes["carLicense"]["actions"]
545         self.assertEquals(1, len(actions))
546         self.assertEquals("add", actions[0]["action"])
547         values = actions[0]["values"]
548         self.assertEquals(1, len(values))
549         self.assertEquals("license-02", values[0]["value"])
550
551         #
552         # Add an another two values to the attribute
553         #
554         self.discardMessages()
555         self.ldb.modify_ldif(
556             "dn: " + dn + "\n" +
557             "changetype: modify\n" +
558             "add: carLicense\n" +
559             "carLicense: license-03\n" +
560             "carLicense: license-04\n")
561
562         messages = self.waitForMessages(1, dn=dn)
563         print("Received %d messages" % len(messages))
564         self.assertEquals(1,
565                           len(messages),
566                           "Did not receive the expected number of messages")
567         attributes = messages[0]["dsdbChange"]["attributes"]
568         self.assertEquals(1, len(attributes))
569         actions = attributes["carLicense"]["actions"]
570         self.assertEquals(1, len(actions))
571         self.assertEquals("add", actions[0]["action"])
572         values = actions[0]["values"]
573         self.assertEquals(2, len(values))
574         self.assertEquals("license-03", values[0]["value"])
575         self.assertEquals("license-04", values[1]["value"])
576
577         #
578         # delete two values to the attribute
579         #
580         self.discardMessages()
581         self.ldb.modify_ldif(
582             "dn: " + dn + "\n" +
583             "changetype: delete\n" +
584             "delete: carLicense\n" +
585             "carLicense: license-03\n" +
586             "carLicense: license-04\n")
587
588         messages = self.waitForMessages(1, dn=dn)
589         print("Received %d messages" % len(messages))
590         self.assertEquals(1,
591                           len(messages),
592                           "Did not receive the expected number of messages")
593         attributes = messages[0]["dsdbChange"]["attributes"]
594         self.assertEquals(1, len(attributes))
595         actions = attributes["carLicense"]["actions"]
596         self.assertEquals(1, len(actions))
597         self.assertEquals("delete", actions[0]["action"])
598         values = actions[0]["values"]
599         self.assertEquals(2, len(values))
600         self.assertEquals("license-03", values[0]["value"])
601         self.assertEquals("license-04", values[1]["value"])
602
603         #
604         # replace two values to the attribute
605         #
606         self.discardMessages()
607         self.ldb.modify_ldif(
608             "dn: " + dn + "\n" +
609             "changetype: delete\n" +
610             "replace: carLicense\n" +
611             "carLicense: license-05\n" +
612             "carLicense: license-06\n")
613
614         messages = self.waitForMessages(1, dn=dn)
615         print("Received %d messages" % len(messages))
616         self.assertEquals(1,
617                           len(messages),
618                           "Did not receive the expected number of messages")
619         attributes = messages[0]["dsdbChange"]["attributes"]
620         self.assertEquals(1, len(attributes))
621         actions = attributes["carLicense"]["actions"]
622         self.assertEquals(1, len(actions))
623         self.assertEquals("replace", actions[0]["action"])
624         values = actions[0]["values"]
625         self.assertEquals(2, len(values))
626         self.assertEquals("license-05", values[0]["value"])
627         self.assertEquals("license-06", values[1]["value"])