Issue 3061 - RFE - Add password policy debug log level

Description:

Added new logging level (1048576) for password policy debugging where the
failure message, entry dn, and pwd policy is recorded (it's either
the global policy or the DN of the local policy).

relates: #3061

Reviewed by: firstyear & spichugi(Thanks!!)

dirsrvtests/create_test.py

@@ -1,13 +1,17 @@
 #!/usr/bin/python3
 #
 # --- BEGIN COPYRIGHT BLOCK ---
-# Copyright (C) 2020 Red Hat, Inc.
+# Copyright (C) 2022 Red Hat, Inc.
 # All rights reserved.
 #
 # License: GPL (version 3 or any later version).
 # See LICENSE for details.
 # --- END COPYRIGHT BLOCK ---
+#
+# PYTHON_ARGCOMPLETE_OK
 
+import argparse, argcomplete
+import argcomplete
 import optparse
 import os
 import re
@@ -23,27 +27,27 @@
 """
 
 
-def displayUsage():
+def display_usage():
     """Display the usage"""
 
-    print ('\nUsage:\ncreate_ticket.py -t|--ticket <ticket number> ' +
-           '-s|--suite <suite name> ' +
-           '[ i|--instances <number of standalone instances> ' +
-           '[ -m|--suppliers <number of suppliers> -h|--hubs <number of hubs> ' +
-           '-c|--consumers <number of consumers> ] -o|--outputfile ]\n')
-    print ('If only "-t" is provided then a single standalone instance is ' +
-           'created. Or you can create a test suite script using ' +
-           '"-s|--suite" instead of using "-t|--ticket". The "-i" option ' +
-           'can add multiple standalone instances (maximum 99). However, you' +
-           ' can not mix "-i" with the replication options (-m, -h , -c).  ' +
-           'There is a maximum of 99 suppliers, 99 hubs, and 99 consumers.')
+    print('\nUsage:\ncreate_ticket.py -t|--ticket <ticket number> ' +
+          '-s|--suite <suite name> ' +
+          '[ i|--instances <number of standalone instances> ' +
+          '[ -m|--suppliers <number of suppliers> -h|--hubs <number of hubs> ' +
+          '-c|--consumers <number of consumers> ] -o|--outputfile ]\n')
+    print('If only "-t" is provided then a single standalone instance is ' +
+          'created. Or you can create a test suite script using ' +
+          '"-s|--suite" instead of using "-t|--ticket". The "-i" option ' +
+          'can add multiple standalone instances (maximum 99). However, you' +
+          ' can not mix "-i" with the replication options (-m, -h , -c).  ' +
+          'There is a maximum of 99 suppliers, 99 hubs, and 99 consumers.')
     print('If "-s|--suite" option was chosen, then no topology would be added ' +
           'to the test script. You can find predefined fixtures in the lib389/topologies.py ' +
           'and use them or write a new one if you have a special case.')
     exit(1)
 
 
-def writeFinalizer():
+def write_finalizer():
     """Write the finalizer function - delete/stop each instance"""
 
     def writeInstanceOp(action):
@@ -119,7 +123,6 @@ def check_id_uniqueness(id_value):
     """
 
     tests_dir = os.path.join(os.getcwd(), 'tests')
-
     for root, dirs, files in os.walk(tests_dir):
         for name in files:
             if name.endswith('.py'):
@@ -131,74 +134,83 @@ def check_id_uniqueness(id_value):
     return True
 
 
+def display_uuid():
+    tc_uuid = '0'
+    while not check_id_uniqueness(tc_uuid): tc_uuid = uuid.uuid4()
+    print(str(tc_uuid))
+    exit(0)
+
+
 desc = 'Script to generate an initial lib389 test script.  ' + \
        'This generates the topology, test, final, and run-isolated functions.'
 
 if len(sys.argv) > 0:
-    parser = optparse.OptionParser(description=desc, add_help_option=False)
-
-    # Script options
-    parser.add_option('-t', '--ticket', dest='ticket', default=None)
-    parser.add_option('-s', '--suite', dest='suite', default=None)
-    parser.add_option('-i', '--instances', dest='inst', default='0')
-    parser.add_option('-m', '--suppliers', dest='suppliers', default='0')
-    parser.add_option('-h', '--hubs', dest='hubs', default='0')
-    parser.add_option('-c', '--consumers', dest='consumers', default='0')
-    parser.add_option('-o', '--outputfile', dest='filename', default=None)
-
-    # Validate the options
-    try:
-        (args, opts) = parser.parse_args()
-    except:
-        displayUsage()
+    parser = argparse.ArgumentParser()
+    parser.add_argument('-t', '--ticket', default=None,
+                        help="The name of the ticket/issue to include in the script name: 'ticket_<TEXT INPUT>_test.py'")
+    parser.add_argument('-s', '--suite', default=None, help="Name for the test: '<TEXT INPUT>_test.py'")
+    parser.add_argument('-i', '--instances', default='0', help="Number of instances needed in the test")
+    parser.add_argument('-m', '--suppliers', default='0',
+                        help="Number of replication suppliers needed in the test")
+    parser.add_argument('-b', '--hubs', default='0', help="Number of replication hubs needed in the test")
+    parser.add_argument('-c', '--consumers', default='0',
+                        help="Number of replication consumers needed in the test")
+    parser.add_argument('-o', '--filename', default=None, help="Custom test script file name")
+    parser.add_argument('-u', '--uuid', action='store_true',
+                        help="Display a test case uuid to used for new test functions in script")
+    argcomplete.autocomplete(parser)
+    args = parser.parse_args()
+
+    if args.uuid:
+        display_uuid()
 
     if args.ticket is None and args.suite is None:
         print('Missing required ticket number/suite name')
-        displayUsage()
+        display_usage()
 
     if args.ticket and args.suite:
         print('You must choose either "-t|--ticket" or "-s|--suite", ' +
               'but not both.')
-        displayUsage()
+        display_usage()
 
     if int(args.suppliers) == 0:
         if int(args.hubs) > 0 or int(args.consumers) > 0:
             print('You must use "-m|--suppliers" if you want to have hubs ' +
                   'and/or consumers')
-            displayUsage()
+            display_usage()
 
     if not args.suppliers.isdigit() or \
-           int(args.suppliers) > 99 or \
-           int(args.suppliers) < 0:
+        int(args.suppliers) > 99 or \
+            int(args.suppliers) < 0:
         print('Invalid value for "--suppliers", it must be a number and it can' +
               ' not be greater than 99')
-        displayUsage()
+        display_usage()
 
     if not args.hubs.isdigit() or int(args.hubs) > 99 or int(args.hubs) < 0:
         print('Invalid value for "--hubs", it must be a number and it can ' +
               'not be greater than 99')
-        displayUsage()
+        display_usage()
 
     if not args.consumers.isdigit() or \
-           int(args.consumers) > 99 or \
-           int(args.consumers) < 0:
+        int(args.consumers) > 99 or \
+            int(args.consumers) < 0:
         print('Invalid value for "--consumers", it must be a number and it ' +
               'can not be greater than 99')
-        displayUsage()
+        display_usage()
 
     if args.inst:
         if not args.inst.isdigit() or \
-               int(args.inst) > 99 or \
-               int(args.inst) < 0:
+            int(args.inst) > 99 or \
+            int(args.inst) < 0:
             print('Invalid value for "--instances", it must be a number ' +
                   'greater than 0 and not greater than 99')
-            displayUsage()
+            display_usage()
         if int(args.inst) > 0:
             if int(args.suppliers) > 0 or \
                             int(args.hubs) > 0 or \
                             int(args.consumers) > 0:
                 print('You can not mix "--instances" with replication.')
-                displayUsage()
+                display_usage()
 
     # Extract usable values
     ticket = args.ticket
@@ -273,7 +285,7 @@ def check_id_uniqueness(id_value):
         TEST.write('    # replicas = Replicas(topology.ms["supplier1"])\n')
         TEST.write('    # replicas.test(DEFAULT_SUFFIX, topology.cs["consumer1"])\n')
 
-        writeFinalizer()
+        write_finalizer()
         TEST.write('    return topology\n\n')
 
     tc_id = '0'

dirsrvtests/tests/suites/password/pwdPolicy_logging_test.py

@@ -0,0 +1,152 @@
+import ldap
+import logging
+import pytest
+import os
+import time
+from lib389._constants import DEFAULT_SUFFIX, PASSWORD
+from lib389.topologies import topology_st as topo
+from lib389.pwpolicy import PwPolicyManager
+from lib389.idm.organizationalunit import OrganizationalUnits
+from lib389.idm.user import UserAccount, UserAccounts, TEST_USER_PROPERTIES
+from lib389.idm.domain import Domain
+
+log = logging.getLogger(__name__)
+
+LOCAL_RDN = 'ou=People'
+GLOBAL_RDN = 'ou=Global'
+LOCAL_BIND_DN ="uid=local_user,ou=people," + DEFAULT_SUFFIX
+GLOBAL_BIND_DN ="uid=global_user,ou=global," + DEFAULT_SUFFIX
+
+
+def create_entries(inst):
+    # Create local user
+    users = UserAccounts(inst, DEFAULT_SUFFIX, rdn=LOCAL_RDN)
+    user_props = TEST_USER_PROPERTIES.copy()
+    user_props.update({'uid': 'local_user', 'cn': 'local_user', 'userpassword': PASSWORD})
+    users.create(properties=user_props)
+
+    # Create new OU
+    ou_global = OrganizationalUnits(inst, DEFAULT_SUFFIX).create(properties={'ou': 'Global'})
+
+    # Create global user
+    users = UserAccounts(inst, DEFAULT_SUFFIX, rdn=GLOBAL_RDN)
+    user_props = TEST_USER_PROPERTIES.copy()
+    user_props.update({'uid': 'global_user', 'cn': 'global_user', 'userpassword': PASSWORD})
+    users.create(properties=user_props)
+
+    # Add aci
+    aci = '(targetattr="*")(version 3.0; acl "pwp test"; allow (all) userdn="ldap:///self";)'
+    suffix = Domain(inst, DEFAULT_SUFFIX)
+    suffix.add('aci', aci)
+
+
+def create_policies(inst):
+    # Configure subtree policy
+    pwp = PwPolicyManager(inst)
+    subtree_policy_props = {
+        'passwordCheckSyntax': 'on',
+        'passwordMinLength': '6',
+        'passwordChange': 'on',
+        'passwordLockout': 'on',
+        'passwordMaxFailure': '2',
+    }
+    pwp.create_subtree_policy(f'{LOCAL_RDN},{DEFAULT_SUFFIX}', subtree_policy_props)
+
+    # Configure global policy
+    inst.config.replace('nsslapd-pwpolicy-local', 'on')
+    inst.config.replace('passwordCheckSyntax', 'on')
+    inst.config.replace('passwordMinLength', '8')
+    inst.config.replace('passwordChange', 'on')
+    inst.config.replace('passwordLockout', 'on')
+    inst.config.replace('passwordMaxFailure', '5')
+    time.sleep(1)
+
+
+def test_debug_logging(topo):
+    """Enable password policy logging
+
+    :id: cc152c65-94e0-4716-a77c-abdd2deec00d
+    :setup: Standalone Instance
+    :steps:
+        1. Set password policy logging level
+        2. Add database entries
+        3. Configure local and global policies
+        4. Test syntax checking on local policy
+        5. Test syntax checking on global policy
+        6. Test account lockout on local policy
+        7. Test account lockout on global policy
+
+    :expectedresults:
+        1. Success
+        2. Success
+        3. Success
+        4. Success
+        5. Success
+        6. Success
+        7. Success
+    """
+
+    inst = topo.standalone
+
+    # Enable password policy debug logging
+    inst.config.replace('nsslapd-errorlog-level', '1048576')
+
+    # Create entries and password policies
+    create_entries(inst)
+    create_policies(inst)
+
+    # Setup bind connections
+
+    local_conn = UserAccounts(inst, DEFAULT_SUFFIX, rdn=LOCAL_RDN).get('local_user').bind(PASSWORD)
+    local_user = UserAccount(local_conn, LOCAL_BIND_DN)
+    global_conn = UserAccounts(inst, DEFAULT_SUFFIX, rdn=GLOBAL_RDN).get('global_user').bind(PASSWORD)
+    global_user = UserAccount(global_conn, GLOBAL_BIND_DN)
+
+    # Test syntax checking on local policy
+    passwd_val = "passw"  # len 5 which is less than configured 6
+    with pytest.raises(ldap.CONSTRAINT_VIOLATION):
+        local_user.replace('userpassword', passwd_val)
+    time.sleep(1)
+
+    err_msg = "PWDPOLICY_DEBUG - invalid password syntax - password must be at least 6 characters long: Entry " + \
+              "\\(uid=local_user,ou=people,dc=example,dc=com\\) Policy \\(cn="
+    assert inst.searchErrorsLog(err_msg)
+
+    # Test syntax checking on global policy
+    passwd_val = "passwod"  # len 7 which is less than configured 8
+    with pytest.raises(ldap.CONSTRAINT_VIOLATION):
+        global_user.replace('userpassword', passwd_val)
+    time.sleep(1)
+
+    err_msg = "PWDPOLICY_DEBUG - invalid password syntax - password must be at least 8 characters long: Entry " + \
+              "\\(uid=global_user,ou=global,dc=example,dc=com\\) Policy \\(Global\\)"
+    assert inst.searchErrorsLog(err_msg)
+
+    # Test account lock is logging for local policy
+    for i in range(2):
+        with pytest.raises(ldap.INVALID_CREDENTIALS):
+            local_user.bind("bad")
+    with pytest.raises(ldap.CONSTRAINT_VIOLATION):
+        local_user.bind("bad")
+
+    err_msg = "PWDPOLICY_DEBUG - Account is locked: Entry " + \
+              "\\(uid=local_user,ou=people,dc=example,dc=com\\) Policy \\(cn="
+    assert inst.searchErrorsLog(err_msg)
+
+    # Test account lock is logging for global policy
+    for i in range(5):
+        with pytest.raises(ldap.INVALID_CREDENTIALS):
+            global_user.bind("bad")
+    with pytest.raises(ldap.CONSTRAINT_VIOLATION):
+        global_user.bind("bad")
+
+    err_msg = "PWDPOLICY_DEBUG - Account is locked: Entry " + \
+              "\\(uid=global_user,ou=global,dc=example,dc=com\\) Policy \\(Global\\)"
+    assert inst.searchErrorsLog(err_msg)
+
+
+if __name__ == '__main__':
+    # Run isolated
+    # -s for DEBUG mode
+    CURRENT_FILE = os.path.realpath(__file__)
+    pytest.main(["-s", CURRENT_FILE])

ldap/servers/slapd/log.c

@@ -71,7 +71,7 @@ static int slapi_log_map[] = {
     LDAP_DEBUG_TIMING,     /* SLAPI_LOG_TIMING */
     LDAP_DEBUG_BACKLDBM,   /* SLAPI_LOG_BACKLDBM */
     LDAP_DEBUG_ACLSUMMARY, /* SLAPI_LOG_ACLSUMMARY */
-    LDAP_DEBUG_NUNCSTANS,  /* SLAPI_LOG_NUNCSTANS */
+    LDAP_DEBUG_PWDPOLICY,  /* SLAPI_LOG_PWDPOLICY */
     LDAP_DEBUG_EMERG,      /* SLAPI_LOG_EMERG */
     LDAP_DEBUG_ALERT,      /* SLAPI_LOG_ALERT */
     LDAP_DEBUG_CRIT,       /* SLAPI_LOG_CRIT */

ldap/servers/slapd/modify.c

@@ -1249,6 +1249,10 @@ op_shared_allow_pw_change(Slapi_PBlock *pb, LDAPMod *mod, char **old_pw, Slapi_M
             if (pwresponse_req == 1) {
                 slapi_pwpolicy_make_response_control(pb, -1, -1, LDAP_PWPOLICY_PWDMODNOTALLOWED);
             }
+            slapi_log_err(SLAPI_LOG_PWDPOLICY, PWDPOLICY_DEBUG,
+                          "user is not allowed to change password.  Entry (%s) Policy (%s)\n",
+                          slapi_sdn_get_dn(&sdn),
+                          pwpolicy->pw_local_dn ? pwpolicy->pw_local_dn : "Global");
             send_ldap_result(pb, LDAP_UNWILLING_TO_PERFORM, NULL,
                              "user is not allowed to change password", 0, NULL);
 

ldap/servers/slapd/proto-slap.h

@@ -801,7 +801,7 @@ int lock_fclose(FILE *fp, FILE *lfp);
 #define LDAP_DEBUG_TIMING     0x00020000  /*    131072 */
 #define LDAP_DEBUG_ACLSUMMARY 0x00040000  /*    262144 */
 #define LDAP_DEBUG_BACKLDBM   0x00080000  /*    524288 */
-#define LDAP_DEBUG_NUNCSTANS  0x00100000  /*   1048576 */
+#define LDAP_DEBUG_PWDPOLICY  0x00100000  /*   1048576 */
 #define LDAP_DEBUG_EMERG      0x00200000  /*   2097152 */
 #define LDAP_DEBUG_ALERT      0x00400000  /*   4194304 */
 #define LDAP_DEBUG_CRIT       0x00800000  /*   8388608 */