Hi, On Wed, Sep 22, 2021 at 3:18 AM Kathy Zhu via FreeIPA-users <freeipa-users@lists.fedorahosted.org> wrote: > > Hi list, > > > one of my ipa server (dirsrv) hang this morning. "ipactl status" no output > and did not return. With nsslapd-errorlog-level being set to 16384, however, > very few log entries. I rebooted the server to recover. But after reboot, ipa > hang again then I have to reboot it. I collected following before 2nd reboot: > > > Check where the process got stuck: > > > [root@ipa5 ~]# cat /proc/$PID/stack > > [<ffffffffb0a63465>] poll_schedule_timeout+0x55/0xc0 > > [<ffffffffb0a64bfd>] do_sys_poll+0x48d/0x590 > > [<ffffffffb0a64e04>] SyS_poll+0x74/0x110 > > [<ffffffffb0f92ed2>] system_call_fastpath+0x25/0x2a > > [<ffffffffffffffff>] 0xffffffffffffffff > > [root@ipa5 ~]# > > > check if there is any lock in place: > > > [root@ipa5 ~]# gdb -ex 'set confirm off' -ex 'set pagination off' -ex 'thread > apply all bt full' -ex 'quit' /usr/sbin/ns-slapd $PID |& grep '^#0.*lock' > > #0 0x00007f132465f39e in pthread_rwlock_wrlock () at /lib64/libpthread.so.0 > > #0 0x00007f132465f184 in pthread_rwlock_rdlock () at /lib64/libpthread.so.0 > > #0 0x00007f132465f184 in pthread_rwlock_rdlock () at /lib64/libpthread.so.0 > > #0 0x00007f132465f184 in pthread_rwlock_rdlock () at /lib64/libpthread.so.0 > > #0 0x00007f132465f184 in pthread_rwlock_rdlock () at /lib64/libpthread.so.0 > > #0 0x00007f132465f184 in pthread_rwlock_rdlock () at /lib64/libpthread.so.0 > > #0 0x00007f132465f184 in pthread_rwlock_rdlock () at /lib64/libpthread.so.0 > > #0 0x00007f132465f184 in pthread_rwlock_rdlock () at /lib64/libpthread.so.0 > > #0 0x00007f132465f184 in pthread_rwlock_rdlock () at /lib64/libpthread.so.0 > > #0 0x00007f132465f184 in pthread_rwlock_rdlock () at /lib64/libpthread.so.0 > > #0 0x00007f132465f184 in pthread_rwlock_rdlock () at /lib64/libpthread.so.0 > > #0 0x00007f132465f184 in pthread_rwlock_rdlock () at /lib64/libpthread.so.0 > > #0 0x00007f132465f184 in pthread_rwlock_rdlock () at /lib64/libpthread.so.0 > > #0 0x00007f132465f184 in pthread_rwlock_rdlock () at /lib64/libpthread.so.0 > > #0 0x00007f132465f184 in pthread_rwlock_rdlock () at /lib64/libpthread.so.0 > > #0 0x00007f132465f39e in pthread_rwlock_wrlock () at /lib64/libpthread.so.0 > > [root@ipa5 ~]# > > > The software versions: > > > Centos 7-8.2003.0 SELinux enabled > > 389-ds-base-1.3.10.2-12.el7_9.x86_64 > > 389-ds-base-libs-1.3.10.2-12.el7_9.x86_64 > > slapi-nis-0.56.5-3.el7_9.x86_64 > > > I attached related messages and dirsrv errors log. Does anyone know how to > fix it? > > > Many thanks! > > > Kathy. > > > > > In the messages (11:37 was 1st reboot and 14:32 was second reboot): > > > [root@ipa5 log]# grep ERR messages > > Sep 20 09:06:17 ipa5 ns-slapd: [20/Sep/2021:09:06:17.767149314 -0700] - ERR - > NSMMReplicationPlugin - bind_and_check_pwp - agmt="cn=meToipa6.example.com" > (ipa6:389) - Replication bind with GSSAPI auth failed: LDAP error -1 (Can't > contact LDAP server) () > > Sep 21 11:37:24 ipa5 ns-slapd: [21/Sep/2021:11:37:24.603324539 -0700] - ERR - > schema-compat-plugin - scheduled schema-compat-plugin tree scan in about 5 > seconds after the server startup! > > Sep 21 11:37:25 ipa5 ns-slapd: [21/Sep/2021:11:37:25.630440119 -0700] - ERR - > set_krb5_creds - Could not get initial credentials for principal > [ldap/ipa5.example....@example.com] in keytab [FILE:/etc/dirsrv/ds.keytab]: > -1765328228 (Cannot contact any KDC for requested realm) > > Sep 21 11:37:25 ipa5 ns-slapd: [21/Sep/2021:11:37:25.676602753 -0700] - ERR - > schema-compat-plugin - schema-compat-plugin tree scan will start in about 5 > seconds! > > Sep 21 11:37:25 ipa5 ns-slapd: [21/Sep/2021:11:37:25.714060760 -0700] - ERR - > set_krb5_creds - Could not get initial credentials for principal > [ldap/ipa5.example....@example.com] in keytab [FILE:/etc/dirsrv/ds.keytab]: > -1765328228 (Cannot contact any KDC for requested realm) > > Sep 21 11:37:25 ipa5 ns-slapd: [21/Sep/2021:11:37:25.796587660 -0700] - ERR - > set_krb5_creds - Could not get initial credentials for principal > [ldap/ipa5.example....@example.com] in keytab [FILE:/etc/dirsrv/ds.keytab]: > -1765328228 (Cannot contact any KDC for requested realm) > > Sep 21 11:37:25 ipa5 ns-slapd: [21/Sep/2021:11:37:25.879136209 -0700] - ERR - > set_krb5_creds - Could not get initial credentials for principal > [ldap/ipa5.example....@example.com] in keytab [FILE:/etc/dirsrv/ds.keytab]: > -1765328228 (Cannot contact any KDC for requested realm) > > Sep 21 11:37:31 ipa5 ns-slapd: [21/Sep/2021:11:37:31.829134731 -0700] - ERR - > schema-compat-plugin - warning: no entries set up under cn=computers, > cn=compat,dc=example,dc=com > > Sep 21 11:37:31 ipa5 ns-slapd: [21/Sep/2021:11:37:31.833560101 -0700] - ERR - > schema-compat-plugin - Finished plugin initialization. > > Sep 21 14:32:13 ipa5 ns-slapd: [21/Sep/2021:14:32:13.105730037 -0700] - ERR - > schema-compat-plugin - scheduled schema-compat-plugin tree scan in about 5 > seconds after the server startup! > > Sep 21 14:32:14 ipa5 ns-slapd: [21/Sep/2021:14:32:14.107014580 -0700] - ERR - > set_krb5_creds - Could not get initial credentials for principal > [ldap/ipa5.example....@example.com] in keytab [FILE:/etc/dirsrv/ds.keytab]: > -1765328228 (Cannot contact any KDC for requested realm) > > Sep 21 14:32:14 ipa5 ns-slapd: [21/Sep/2021:14:32:14.153908801 -0700] - ERR - > schema-compat-plugin - schema-compat-plugin tree scan will start in about 5 > seconds! > > Sep 21 14:32:14 ipa5 ns-slapd: [21/Sep/2021:14:32:14.191647629 -0700] - ERR - > set_krb5_creds - Could not get initial credentials for principal > [ldap/ipa5.example....@example.com] in keytab [FILE:/etc/dirsrv/ds.keytab]: > -1765328228 (Cannot contact any KDC for requested realm) > > Sep 21 14:32:14 ipa5 ns-slapd: [21/Sep/2021:14:32:14.273919809 -0700] - ERR - > set_krb5_creds - Could not get initial credentials for principal > [ldap/ipa5.example....@example.com] in keytab [FILE:/etc/dirsrv/ds.keytab]: > -1765328228 (Cannot contact any KDC for requested realm) > > Sep 21 14:32:20 ipa5 ns-slapd: [21/Sep/2021:14:32:20.293525463 -0700] - ERR - > schema-compat-plugin - warning: no entries set up under cn=computers, > cn=compat,dc=example,dc=com > > Sep 21 14:32:20 ipa5 ns-slapd: [21/Sep/2021:14:32:20.293736655 -0700] - ERR - > schema-compat-plugin - Finished plugin initialization. > > [root@ipa5 log]# > > > errors log (11:37 was 1st reboot and 14:32 was second reboot): > > > [root@ipa5 slapd-EXAMPLE-COM]# cat errors > > 389-Directory/1.3.10.2 B2021.160.169 > > ipa5.example.com:636 (/etc/dirsrv/slapd-EXAMPLE-COM) > > > [20/Sep/2021:09:06:17.768066990 -0700] - ERR - NSMMReplicationPlugin - > bind_and_check_pwp - agmt="cn=meToipa6.example.com" (ipa6:389) - Replication > bind with GSSAPI auth failed: LDAP error -1 (Can't contact LDAP server) () > > [20/Sep/2021:09:06:20.348325236 -0700] - INFO - NSMMReplicationPlugin - > bind_and_check_pwp - agmt="cn=meToipa6.example.com" (ipa6:389): Replication > bind with GSSAPI auth resumed > > [20/Sep/2021:09:08:24.400342570 -0700] - WARN - NSMMReplicationPlugin - > replica_generate_next_csn - opcsn=6148fb190008002a0000 <= > basecsn=6148fb19ae5800040000, adjusted opcsn=6148fb19ae5a002a0000 > > [20/Sep/2021:09:09:14.372623984 -0700] - WARN - NSMMReplicationPlugin - > replica_generate_next_csn - opcsn=6148fb4b0007002a0000 <= > basecsn=6148fb4bafac00040000, adjusted opcsn=6148fb4bafae002a0000 > > [20/Sep/2021:11:51:58.900633352 -0700] - WARN - NSMMReplicationPlugin - > replica_generate_next_csn - opcsn=6149216f0004002a0000 <= > basecsn=6149216f718a00040000, adjusted opcsn=6149216f718c002a0000 > > [21/Sep/2021:11:26:59.139128524 -0700] - INFO - op_thread_cleanup - slapd > shutting down - signaling operation threads - op stack size 0 max work q size > 316 max work q stack size 12 > > [21/Sep/2021:11:26:59.140129110 -0700] - INFO - slapd_daemon - slapd shutting > down - waiting for 24 threads to terminate > > [21/Sep/2021:11:30:08.927140039 -0700] - WARN - NSMMReplicationPlugin - > acquire_replica - agmt="cn=meToipa6.example.com" (ipa6:389): Unable to > receive the response for a startReplication extended operation to consumer > (Timed out). Will retry later. > > [21/Sep/2021:11:37:22.087091069 -0700] - INFO - slapd_extract_cert - CA CERT > NAME: EXAMPLE.COM IPA CA > > [21/Sep/2021:11:37:22.107553462 -0700] - WARN - Security Initialization - SSL > alert: Sending pin request to SVRCore. You may need to run > systemd-tty-ask-password-agent to provide the password. > > [21/Sep/2021:11:37:22.108208619 -0700] - INFO - slapd_extract_cert - SERVER > CERT NAME: Server-Cert > > [21/Sep/2021:11:37:22.121340459 -0700] - INFO - Security Initialization - SSL > info: Enabling default cipher set. > > [21/Sep/2021:11:37:22.131009941 -0700] - INFO - Security Initialization - SSL > info: Configured NSS Ciphers > > [21/Sep/2021:11:37:22.141010955 -0700] - INFO - Security Initialization - SSL > info: TLS_AES_128_GCM_SHA256: enabled > > [21/Sep/2021:11:37:22.143647711 -0700] - INFO - Security Initialization - SSL > info: TLS_CHACHA20_POLY1305_SHA256: enabled > > [21/Sep/2021:11:37:22.143881989 -0700] - INFO - Security Initialization - SSL > info: TLS_AES_256_GCM_SHA384: enabled > > [21/Sep/2021:11:37:22.144109322 -0700] - INFO - Security Initialization - SSL > info: TLS_ECDHE_ECDSA_WITH_AES_256_GCM_SHA384: enabled > > [21/Sep/2021:11:37:22.144325392 -0700] - INFO - Security Initialization - SSL > info: TLS_ECDHE_ECDSA_WITH_AES_256_CBC_SHA: enabled > > [21/Sep/2021:11:37:22.144620475 -0700] - INFO - Security Initialization - SSL > info: TLS_ECDHE_ECDSA_WITH_AES_128_GCM_SHA256: enabled > > [21/Sep/2021:11:37:22.144823798 -0700] - INFO - Security Initialization - SSL > info: TLS_ECDHE_ECDSA_WITH_CHACHA20_POLY1305_SHA256: enabled > > [21/Sep/2021:11:37:22.145040176 -0700] - INFO - Security Initialization - SSL > info: TLS_ECDHE_ECDSA_WITH_AES_128_CBC_SHA: enabled > > [21/Sep/2021:11:37:22.145248453 -0700] - INFO - Security Initialization - SSL > info: TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384: enabled > > [21/Sep/2021:11:37:22.145449371 -0700] - INFO - Security Initialization - SSL > info: TLS_ECDHE_RSA_WITH_AES_256_CBC_SHA: enabled > > [21/Sep/2021:11:37:22.145647646 -0700] - INFO - Security Initialization - SSL > info: TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256: enabled > > [21/Sep/2021:11:37:22.145844189 -0700] - INFO - Security Initialization - SSL > info: TLS_ECDHE_RSA_WITH_CHACHA20_POLY1305_SHA256: enabled > > [21/Sep/2021:11:37:22.146054551 -0700] - INFO - Security Initialization - SSL > info: TLS_ECDHE_RSA_WITH_AES_128_CBC_SHA: enabled > > [21/Sep/2021:11:37:22.146251412 -0700] - INFO - Security Initialization - SSL > info: TLS_DHE_RSA_WITH_AES_256_GCM_SHA384: enabled > > [21/Sep/2021:11:37:22.146449693 -0700] - INFO - Security Initialization - SSL > info: TLS_DHE_RSA_WITH_AES_256_CBC_SHA: enabled > > [21/Sep/2021:11:37:22.146735864 -0700] - INFO - Security Initialization - SSL > info: TLS_DHE_DSS_WITH_AES_256_CBC_SHA: enabled > > [21/Sep/2021:11:37:22.146936445 -0700] - INFO - Security Initialization - SSL > info: TLS_DHE_RSA_WITH_AES_256_CBC_SHA256: enabled > > [21/Sep/2021:11:37:22.147149142 -0700] - INFO - Security Initialization - SSL > info: TLS_DHE_RSA_WITH_AES_128_GCM_SHA256: enabled > > [21/Sep/2021:11:37:22.147348187 -0700] - INFO - Security Initialization - SSL > info: TLS_DHE_RSA_WITH_CHACHA20_POLY1305_SHA256: enabled > > [21/Sep/2021:11:37:22.147543861 -0700] - INFO - Security Initialization - SSL > info: TLS_DHE_RSA_WITH_AES_128_CBC_SHA: enabled > > [21/Sep/2021:11:37:22.147740471 -0700] - INFO - Security Initialization - SSL > info: TLS_DHE_DSS_WITH_AES_128_CBC_SHA: enabled > > [21/Sep/2021:11:37:22.147945320 -0700] - INFO - Security Initialization - SSL > info: TLS_DHE_RSA_WITH_AES_128_CBC_SHA256: enabled > > [21/Sep/2021:11:37:22.148203907 -0700] - INFO - Security Initialization - SSL > info: TLS_RSA_WITH_AES_256_GCM_SHA384: enabled > > [21/Sep/2021:11:37:22.148408650 -0700] - INFO - Security Initialization - SSL > info: TLS_RSA_WITH_AES_256_CBC_SHA: enabled > > [21/Sep/2021:11:37:22.148608462 -0700] - INFO - Security Initialization - SSL > info: TLS_RSA_WITH_AES_256_CBC_SHA256: enabled > > [21/Sep/2021:11:37:22.148856140 -0700] - INFO - Security Initialization - SSL > info: TLS_RSA_WITH_AES_128_GCM_SHA256: enabled > > [21/Sep/2021:11:37:22.149070747 -0700] - INFO - Security Initialization - SSL > info: TLS_RSA_WITH_AES_128_CBC_SHA: enabled > > [21/Sep/2021:11:37:22.149270007 -0700] - INFO - Security Initialization - SSL > info: TLS_RSA_WITH_AES_128_CBC_SHA256: enabled > > [21/Sep/2021:11:37:22.152892336 -0700] - INFO - Security Initialization - > slapd_ssl_init2 - Configured SSL version range: min: TLS1.0, max: TLS1.2 > > [21/Sep/2021:11:37:22.153485284 -0700] - INFO - main - 389-Directory/1.3.10.2 > B2021.160.169 starting up > > [21/Sep/2021:11:37:22.153702300 -0700] - INFO - main - Setting the maximum > file descriptor limit to: 16384 > > [21/Sep/2021:11:37:24.381088447 -0700] - INFO - > ldbm_instance_config_cachememsize_set - force a minimal value 512000 > > [21/Sep/2021:11:37:24.383729177 -0700] - WARN - default_mr_indexer_create - > Plugin [caseIgnoreIA5Match] does not handle caseExactIA5Match > > [21/Sep/2021:11:37:24.385755952 -0700] - INFO - > ldbm_instance_config_cachememsize_set - force a minimal value 512000 > > [21/Sep/2021:11:37:24.389648132 -0700] - INFO - > ldbm_instance_config_cachememsize_set - force a minimal value 512000 > > [21/Sep/2021:11:37:24.393387733 -0700] - NOTICE - ldbm_back_start - found > 8008992k physical memory > > [21/Sep/2021:11:37:24.393534680 -0700] - NOTICE - ldbm_back_start - found > 7254208k available > > [21/Sep/2021:11:37:24.393666179 -0700] - NOTICE - ldbm_back_start - cache > autosizing: db cache: 200224k > > [21/Sep/2021:11:37:24.393811926 -0700] - NOTICE - ldbm_back_start - cache > autosizing: userRoot entry cache (3 total): 196608k > > [21/Sep/2021:11:37:24.394413949 -0700] - NOTICE - ldbm_back_start - cache > autosizing: userRoot dn cache (3 total): 65536k > > [21/Sep/2021:11:37:24.395241483 -0700] - NOTICE - ldbm_back_start - cache > autosizing: ipaca entry cache (3 total): 196608k > > [21/Sep/2021:11:37:24.395762334 -0700] - NOTICE - ldbm_back_start - cache > autosizing: ipaca dn cache (3 total): 65536k > > [21/Sep/2021:11:37:24.396437365 -0700] - NOTICE - ldbm_back_start - cache > autosizing: changelog entry cache (3 total): 196608k > > [21/Sep/2021:11:37:24.396931574 -0700] - NOTICE - ldbm_back_start - cache > autosizing: changelog dn cache (3 total): 65536k > > [21/Sep/2021:11:37:24.399397009 -0700] - NOTICE - ldbm_back_start - total > cache size: 969330524 B; > > [21/Sep/2021:11:37:24.402519856 -0700] - NOTICE - dblayer_start - Detected > Disorderly Shutdown last time Directory Server was running, recovering > database. > > [21/Sep/2021:11:37:24.603333323 -0700] - ERR - schema-compat-plugin - > scheduled schema-compat-plugin tree scan in about 5 seconds after the server > startup! > > [21/Sep/2021:11:37:24.619972344 -0700] - WARN - NSACLPlugin - acl_parse - The > ACL target cn=groups,cn=compat,dc=example,dc=com does not exist > > [21/Sep/2021:11:37:24.620216729 -0700] - WARN - NSACLPlugin - acl_parse - The > ACL target cn=computers,cn=compat,dc=example,dc=com does not exist > > [21/Sep/2021:11:37:24.620395665 -0700] - WARN - NSACLPlugin - acl_parse - The > ACL target cn=ng,cn=compat,dc=example,dc=com does not exist > > [21/Sep/2021:11:37:24.620631777 -0700] - WARN - NSACLPlugin - acl_parse - The > ACL target ou=sudoers,dc=example,dc=com does not exist > > [21/Sep/2021:11:37:24.620809457 -0700] - WARN - NSACLPlugin - acl_parse - The > ACL target cn=users,cn=compat,dc=example,dc=com does not exist > > [21/Sep/2021:11:37:24.621006476 -0700] - WARN - NSACLPlugin - acl_parse - The > ACL target cn=vaults,cn=kra,dc=example,dc=com does not exist > > [21/Sep/2021:11:37:24.621182026 -0700] - WARN - NSACLPlugin - acl_parse - The > ACL target cn=vaults,cn=kra,dc=example,dc=com does not exist > > [21/Sep/2021:11:37:24.621361114 -0700] - WARN - NSACLPlugin - acl_parse - The > ACL target cn=vaults,cn=kra,dc=example,dc=com does not exist > > [21/Sep/2021:11:37:24.621543112 -0700] - WARN - NSACLPlugin - acl_parse - The > ACL target cn=vaults,cn=kra,dc=example,dc=com does not exist > > [21/Sep/2021:11:37:24.621719758 -0700] - WARN - NSACLPlugin - acl_parse - The > ACL target cn=vaults,cn=kra,dc=example,dc=com does not exist > > [21/Sep/2021:11:37:24.621912694 -0700] - WARN - NSACLPlugin - acl_parse - The > ACL target cn=vaults,cn=kra,dc=example,dc=com does not exist > > [21/Sep/2021:11:37:24.622087172 -0700] - WARN - NSACLPlugin - acl_parse - The > ACL target cn=vaults,cn=kra,dc=example,dc=com does not exist > > [21/Sep/2021:11:37:24.622263736 -0700] - WARN - NSACLPlugin - acl_parse - The > ACL target cn=vaults,cn=kra,dc=example,dc=com does not exist > > [21/Sep/2021:11:37:24.622439497 -0700] - WARN - NSACLPlugin - acl_parse - The > ACL target cn=vaults,cn=kra,dc=example,dc=com does not exist > > [21/Sep/2021:11:37:24.622616843 -0700] - WARN - NSACLPlugin - acl_parse - The > ACL target cn=vaults,cn=kra,dc=example,dc=com does not exist > > [21/Sep/2021:11:37:24.622793368 -0700] - WARN - NSACLPlugin - acl_parse - The > ACL target cn=vaults,cn=kra,dc=example,dc=com does not exist > > [21/Sep/2021:11:37:24.663383897 -0700] - WARN - NSACLPlugin - acl_parse - The > ACL target cn=casigningcert > cert-pki-ca,cn=ca_renewal,cn=ipa,cn=etc,dc=example,dc=com does not exist > > [21/Sep/2021:11:37:24.663575439 -0700] - WARN - NSACLPlugin - acl_parse - The > ACL target cn=casigningcert > cert-pki-ca,cn=ca_renewal,cn=ipa,cn=etc,dc=example,dc=com does not exist > > [21/Sep/2021:11:37:24.727752819 -0700] - WARN - NSACLPlugin - acl_parse - The > ACL target cn=automember rebuild membership,cn=tasks,cn=config does not exist > > [21/Sep/2021:11:37:24.754864655 -0700] - NOTICE - NSMMReplicationPlugin - > changelog program - _cl5ConstructRUV - Rebuilding the replication changelog > RUV, this may take several minutes... > > [21/Sep/2021:11:37:24.757027555 -0700] - NOTICE - NSMMReplicationPlugin - > changelog program - _cl5ConstructRUV - Rebuilding replication changelog RUV > complete. Result 0 (Success) > > [21/Sep/2021:11:37:24.757181126 -0700] - NOTICE - NSMMReplicationPlugin - > changelog program - _cl5ConstructRUV - Rebuilding the replication changelog > RUV, this may take several minutes... > > [21/Sep/2021:11:37:24.759270661 -0700] - NOTICE - NSMMReplicationPlugin - > changelog program - _cl5ConstructRUV - Rebuilding replication changelog RUV > complete. Result 0 (Success) > > [21/Sep/2021:11:37:24.959483078 -0700] - NOTICE - NSMMReplicationPlugin - > changelog program - _cl5ConstructRUV - Rebuilding the replication changelog > RUV, this may take several minutes... > > [21/Sep/2021:11:37:25.287387667 -0700] - NOTICE - NSMMReplicationPlugin - > changelog program - _cl5ConstructRUV - Rebuilding replication changelog RUV > complete. Result 0 (Success) > > [21/Sep/2021:11:37:25.287687713 -0700] - NOTICE - NSMMReplicationPlugin - > changelog program - _cl5ConstructRUV - Rebuilding the replication changelog > RUV, this may take several minutes... > > [21/Sep/2021:11:37:25.626948414 -0700] - NOTICE - NSMMReplicationPlugin - > changelog program - _cl5ConstructRUV - Rebuilding replication changelog RUV > complete. Result 0 (Success) > > [21/Sep/2021:11:37:25.628156874 -0700] - WARN - NSMMReplicationPlugin - > replica_check_for_data_reload - Disorderly shutdown for replica o=ipaca. > Check if DB RUV needs to be updated > > [21/Sep/2021:11:37:25.628441700 -0700] - WARN - NSMMReplicationPlugin - > replica_check_for_data_reload - Disorderly shutdown for replica > dc=example,dc=com. Check if DB RUV needs to be updated > > [21/Sep/2021:11:37:25.628593983 -0700] - NOTICE - NSMMReplicationPlugin - > Force update of database RUV (from CL RUV) -> 614a6468b12c002a0000 > > [21/Sep/2021:11:37:25.628741783 -0700] - NOTICE - NSMMReplicationPlugin - > Force update of database RUV (from CL RUV) -> 614a6465b119001c0000 > > [21/Sep/2021:11:37:25.630449068 -0700] - ERR - set_krb5_creds - Could not get > initial credentials for principal [ldap/ipa5.example....@example.com] in > keytab [FILE:/etc/dirsrv/ds.keytab]: -1765328228 (Cannot contact any KDC for > requested realm) > > [21/Sep/2021:11:37:25.637993198 -0700] - INFO - slapd_daemon - slapd started. > Listening on All Interfaces port 389 for LDAP requests > > [21/Sep/2021:11:37:25.638150651 -0700] - INFO - slapd_daemon - Listening on > All Interfaces port 636 for LDAPS requests > > [21/Sep/2021:11:37:25.638294957 -0700] - INFO - slapd_daemon - Listening on > /var/run/slapd-EXAMPLE-COM.socket for LDAPI requests > > [21/Sep/2021:11:37:25.676737896 -0700] - ERR - schema-compat-plugin - > schema-compat-plugin tree scan will start in about 5 seconds! > > [21/Sep/2021:11:37:25.714069163 -0700] - ERR - set_krb5_creds - Could not get > initial credentials for principal [ldap/ipa5.example....@example.com] in > keytab [FILE:/etc/dirsrv/ds.keytab]: -1765328228 (Cannot contact any KDC for > requested realm) > > [21/Sep/2021:11:37:25.796599172 -0700] - ERR - set_krb5_creds - Could not get > initial credentials for principal [ldap/ipa5.example....@example.com] in > keytab [FILE:/etc/dirsrv/ds.keytab]: -1765328228 (Cannot contact any KDC for > requested realm) > > [21/Sep/2021:11:37:25.879148077 -0700] - ERR - set_krb5_creds - Could not get > initial credentials for principal [ldap/ipa5.example....@example.com] in > keytab [FILE:/etc/dirsrv/ds.keytab]: -1765328228 (Cannot contact any KDC for > requested realm) > > [21/Sep/2021:11:37:29.469422032 -0700] - INFO - csngen_new_csn - Detected > large jump in CSN time. Delta: 3195237 (current time: 1632249449 vs > previous time: 1629054212) > > [21/Sep/2021:11:37:31.829146877 -0700] - ERR - schema-compat-plugin - > warning: no entries set up under cn=computers, cn=compat,dc=example,dc=com > > [21/Sep/2021:11:37:31.833570449 -0700] - ERR - schema-compat-plugin - > Finished plugin initialization. > > [21/Sep/2021:14:21:48.128729268 -0700] - INFO - op_thread_cleanup - slapd > shutting down - signaling operation threads - op stack size 0 max work q size > 1237 max work q stack size 5 > > [21/Sep/2021:14:21:48.130690397 -0700] - INFO - slapd_daemon - slapd shutting > down - waiting for 24 threads to terminate > > [21/Sep/2021:14:32:10.605597874 -0700] - INFO - slapd_extract_cert - CA CERT > NAME: EXAMPLE.COM IPA CA > > [21/Sep/2021:14:32:10.606686976 -0700] - WARN - Security Initialization - SSL > alert: Sending pin request to SVRCore. You may need to run > systemd-tty-ask-password-agent to provide the password. > > [21/Sep/2021:14:32:10.607191737 -0700] - INFO - slapd_extract_cert - SERVER > CERT NAME: Server-Cert > > [21/Sep/2021:14:32:10.610492924 -0700] - INFO - Security Initialization - SSL > info: Enabling default cipher set. > > [21/Sep/2021:14:32:10.610702247 -0700] - INFO - Security Initialization - SSL > info: Configured NSS Ciphers > > [21/Sep/2021:14:32:10.610883434 -0700] - INFO - Security Initialization - SSL > info: TLS_AES_128_GCM_SHA256: enabled > > [21/Sep/2021:14:32:10.611082442 -0700] - INFO - Security Initialization - SSL > info: TLS_CHACHA20_POLY1305_SHA256: enabled > > [21/Sep/2021:14:32:10.611262035 -0700] - INFO - Security Initialization - SSL > info: TLS_AES_256_GCM_SHA384: enabled > > [21/Sep/2021:14:32:10.611464581 -0700] - INFO - Security Initialization - SSL > info: TLS_ECDHE_ECDSA_WITH_AES_256_GCM_SHA384: enabled > > [21/Sep/2021:14:32:10.611640568 -0700] - INFO - Security Initialization - SSL > info: TLS_ECDHE_ECDSA_WITH_AES_256_CBC_SHA: enabled > > [21/Sep/2021:14:32:10.611817444 -0700] - INFO - Security Initialization - SSL > info: TLS_ECDHE_ECDSA_WITH_AES_128_GCM_SHA256: enabled > > [21/Sep/2021:14:32:10.612010226 -0700] - INFO - Security Initialization - SSL > info: TLS_ECDHE_ECDSA_WITH_CHACHA20_POLY1305_SHA256: enabled > > [21/Sep/2021:14:32:10.612186942 -0700] - INFO - Security Initialization - SSL > info: TLS_ECDHE_ECDSA_WITH_AES_128_CBC_SHA: enabled > > [21/Sep/2021:14:32:10.612359300 -0700] - INFO - Security Initialization - SSL > info: TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384: enabled > > [21/Sep/2021:14:32:10.612534043 -0700] - INFO - Security Initialization - SSL > info: TLS_ECDHE_RSA_WITH_AES_256_CBC_SHA: enabled > > [21/Sep/2021:14:32:10.612707265 -0700] - INFO - Security Initialization - SSL > info: TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256: enabled > > [21/Sep/2021:14:32:10.612890259 -0700] - INFO - Security Initialization - SSL > info: TLS_ECDHE_RSA_WITH_CHACHA20_POLY1305_SHA256: enabled > > [21/Sep/2021:14:32:10.613072932 -0700] - INFO - Security Initialization - SSL > info: TLS_ECDHE_RSA_WITH_AES_128_CBC_SHA: enabled > > [21/Sep/2021:14:32:10.613252512 -0700] - INFO - Security Initialization - SSL > info: TLS_DHE_RSA_WITH_AES_256_GCM_SHA384: enabled > > [21/Sep/2021:14:32:10.613428106 -0700] - INFO - Security Initialization - SSL > info: TLS_DHE_RSA_WITH_AES_256_CBC_SHA: enabled > > [21/Sep/2021:14:32:10.613607982 -0700] - INFO - Security Initialization - SSL > info: TLS_DHE_DSS_WITH_AES_256_CBC_SHA: enabled > > [21/Sep/2021:14:32:10.613783773 -0700] - INFO - Security Initialization - SSL > info: TLS_DHE_RSA_WITH_AES_256_CBC_SHA256: enabled > > [21/Sep/2021:14:32:10.613963528 -0700] - INFO - Security Initialization - SSL > info: TLS_DHE_RSA_WITH_AES_128_GCM_SHA256: enabled > > [21/Sep/2021:14:32:10.614139566 -0700] - INFO - Security Initialization - SSL > info: TLS_DHE_RSA_WITH_CHACHA20_POLY1305_SHA256: enabled > > [21/Sep/2021:14:32:10.614313931 -0700] - INFO - Security Initialization - SSL > info: TLS_DHE_RSA_WITH_AES_128_CBC_SHA: enabled > > [21/Sep/2021:14:32:10.614485765 -0700] - INFO - Security Initialization - SSL > info: TLS_DHE_DSS_WITH_AES_128_CBC_SHA: enabled > > [21/Sep/2021:14:32:10.614667815 -0700] - INFO - Security Initialization - SSL > info: TLS_DHE_RSA_WITH_AES_128_CBC_SHA256: enabled > > [21/Sep/2021:14:32:10.614843058 -0700] - INFO - Security Initialization - SSL > info: TLS_RSA_WITH_AES_256_GCM_SHA384: enabled > > [21/Sep/2021:14:32:10.615033164 -0700] - INFO - Security Initialization - SSL > info: TLS_RSA_WITH_AES_256_CBC_SHA: enabled > > [21/Sep/2021:14:32:10.615208640 -0700] - INFO - Security Initialization - SSL > info: TLS_RSA_WITH_AES_256_CBC_SHA256: enabled > > [21/Sep/2021:14:32:10.615384704 -0700] - INFO - Security Initialization - SSL > info: TLS_RSA_WITH_AES_128_GCM_SHA256: enabled > > [21/Sep/2021:14:32:10.615558123 -0700] - INFO - Security Initialization - SSL > info: TLS_RSA_WITH_AES_128_CBC_SHA: enabled > > [21/Sep/2021:14:32:10.615747508 -0700] - INFO - Security Initialization - SSL > info: TLS_RSA_WITH_AES_128_CBC_SHA256: enabled > > [21/Sep/2021:14:32:10.619176886 -0700] - INFO - Security Initialization - > slapd_ssl_init2 - Configured SSL version range: min: TLS1.0, max: TLS1.2 > > [21/Sep/2021:14:32:10.619596992 -0700] - INFO - main - 389-Directory/1.3.10.2 > B2021.160.169 starting up > > [21/Sep/2021:14:32:10.619786789 -0700] - INFO - main - Setting the maximum > file descriptor limit to: 16384 > > [21/Sep/2021:14:32:12.863761900 -0700] - INFO - > ldbm_instance_config_cachememsize_set - force a minimal value 512000 > > [21/Sep/2021:14:32:12.866303167 -0700] - WARN - default_mr_indexer_create - > Plugin [caseIgnoreIA5Match] does not handle caseExactIA5Match > > [21/Sep/2021:14:32:12.868327459 -0700] - INFO - > ldbm_instance_config_cachememsize_set - force a minimal value 512000 > > [21/Sep/2021:14:32:12.872018894 -0700] - INFO - > ldbm_instance_config_cachememsize_set - force a minimal value 512000 > > [21/Sep/2021:14:32:12.875942159 -0700] - NOTICE - ldbm_back_start - found > 8008992k physical memory > > [21/Sep/2021:14:32:12.876118261 -0700] - NOTICE - ldbm_back_start - found > 7273264k available > > [21/Sep/2021:14:32:12.876251543 -0700] - NOTICE - ldbm_back_start - cache > autosizing: db cache: 200224k > > [21/Sep/2021:14:32:12.876401888 -0700] - NOTICE - ldbm_back_start - cache > autosizing: userRoot entry cache (3 total): 196608k > > [21/Sep/2021:14:32:12.877015107 -0700] - NOTICE - ldbm_back_start - cache > autosizing: userRoot dn cache (3 total): 65536k > > [21/Sep/2021:14:32:12.879111165 -0700] - NOTICE - ldbm_back_start - cache > autosizing: ipaca entry cache (3 total): 196608k > > [21/Sep/2021:14:32:12.879699133 -0700] - NOTICE - ldbm_back_start - cache > autosizing: ipaca dn cache (3 total): 65536k > > [21/Sep/2021:14:32:12.880810497 -0700] - NOTICE - ldbm_back_start - cache > autosizing: changelog entry cache (3 total): 196608k > > [21/Sep/2021:14:32:12.881400177 -0700] - NOTICE - ldbm_back_start - cache > autosizing: changelog dn cache (3 total): 65536k > > [21/Sep/2021:14:32:12.883113645 -0700] - NOTICE - ldbm_back_start - total > cache size: 969330524 B; > > [21/Sep/2021:14:32:12.886703828 -0700] - NOTICE - dblayer_start - Detected > Disorderly Shutdown last time Directory Server was running, recovering > database. > > [21/Sep/2021:14:32:13.105739416 -0700] - ERR - schema-compat-plugin - > scheduled schema-compat-plugin tree scan in about 5 seconds after the server > startup! > > [21/Sep/2021:14:32:13.122672646 -0700] - WARN - NSACLPlugin - acl_parse - The > ACL target cn=groups,cn=compat,dc=example,dc=com does not exist > > [21/Sep/2021:14:32:13.122865415 -0700] - WARN - NSACLPlugin - acl_parse - The > ACL target cn=computers,cn=compat,dc=example,dc=com does not exist > > [21/Sep/2021:14:32:13.123066536 -0700] - WARN - NSACLPlugin - acl_parse - The > ACL target cn=ng,cn=compat,dc=example,dc=com does not exist > > [21/Sep/2021:14:32:13.123271167 -0700] - WARN - NSACLPlugin - acl_parse - The > ACL target ou=sudoers,dc=example,dc=com does not exist > > [21/Sep/2021:14:32:13.123441717 -0700] - WARN - NSACLPlugin - acl_parse - The > ACL target cn=users,cn=compat,dc=example,dc=com does not exist > > [21/Sep/2021:14:32:13.123629053 -0700] - WARN - NSACLPlugin - acl_parse - The > ACL target cn=vaults,cn=kra,dc=example,dc=com does not exist > > [21/Sep/2021:14:32:13.123800535 -0700] - WARN - NSACLPlugin - acl_parse - The > ACL target cn=vaults,cn=kra,dc=example,dc=com does not exist > > [21/Sep/2021:14:32:13.123971584 -0700] - WARN - NSACLPlugin - acl_parse - The > ACL target cn=vaults,cn=kra,dc=example,dc=com does not exist > > [21/Sep/2021:14:32:13.124143620 -0700] - WARN - NSACLPlugin - acl_parse - The > ACL target cn=vaults,cn=kra,dc=example,dc=com does not exist > > [21/Sep/2021:14:32:13.124311857 -0700] - WARN - NSACLPlugin - acl_parse - The > ACL target cn=vaults,cn=kra,dc=example,dc=com does not exist > > [21/Sep/2021:14:32:13.124489965 -0700] - WARN - NSACLPlugin - acl_parse - The > ACL target cn=vaults,cn=kra,dc=example,dc=com does not exist > > [21/Sep/2021:14:32:13.124665189 -0700] - WARN - NSACLPlugin - acl_parse - The > ACL target cn=vaults,cn=kra,dc=example,dc=com does not exist > > [21/Sep/2021:14:32:13.124836908 -0700] - WARN - NSACLPlugin - acl_parse - The > ACL target cn=vaults,cn=kra,dc=example,dc=com does not exist > > [21/Sep/2021:14:32:13.125004506 -0700] - WARN - NSACLPlugin - acl_parse - The > ACL target cn=vaults,cn=kra,dc=example,dc=com does not exist > > [21/Sep/2021:14:32:13.125172452 -0700] - WARN - NSACLPlugin - acl_parse - The > ACL target cn=vaults,cn=kra,dc=example,dc=com does not exist > > [21/Sep/2021:14:32:13.125341330 -0700] - WARN - NSACLPlugin - acl_parse - The > ACL target cn=vaults,cn=kra,dc=example,dc=com does not exist > > [21/Sep/2021:14:32:13.167392303 -0700] - WARN - NSACLPlugin - acl_parse - The > ACL target cn=casigningcert > cert-pki-ca,cn=ca_renewal,cn=ipa,cn=etc,dc=example,dc=com does not exist > > [21/Sep/2021:14:32:13.167585840 -0700] - WARN - NSACLPlugin - acl_parse - The > ACL target cn=casigningcert > cert-pki-ca,cn=ca_renewal,cn=ipa,cn=etc,dc=example,dc=com does not exist > > [21/Sep/2021:14:32:13.231724926 -0700] - WARN - NSACLPlugin - acl_parse - The > ACL target cn=automember rebuild membership,cn=tasks,cn=config does not exist > > [21/Sep/2021:14:32:13.256786460 -0700] - NOTICE - NSMMReplicationPlugin - > changelog program - _cl5ConstructRUV - Rebuilding the replication changelog > RUV, this may take several minutes... > > [21/Sep/2021:14:32:13.258790153 -0700] - NOTICE - NSMMReplicationPlugin - > changelog program - _cl5ConstructRUV - Rebuilding replication changelog RUV > complete. Result 0 (Success) > > [21/Sep/2021:14:32:13.258932037 -0700] - NOTICE - NSMMReplicationPlugin - > changelog program - _cl5ConstructRUV - Rebuilding the replication changelog > RUV, this may take several minutes... > > [21/Sep/2021:14:32:13.260869035 -0700] - NOTICE - NSMMReplicationPlugin - > changelog program - _cl5ConstructRUV - Rebuilding replication changelog RUV > complete. Result 0 (Success) > > [21/Sep/2021:14:32:13.453340945 -0700] - NOTICE - NSMMReplicationPlugin - > changelog program - _cl5ConstructRUV - Rebuilding the replication changelog > RUV, this may take several minutes... > > [21/Sep/2021:14:32:13.778192948 -0700] - NOTICE - NSMMReplicationPlugin - > changelog program - _cl5ConstructRUV - Rebuilding replication changelog RUV > complete. Result 0 (Success) > > [21/Sep/2021:14:32:13.778399400 -0700] - NOTICE - NSMMReplicationPlugin - > changelog program - _cl5ConstructRUV - Rebuilding the replication changelog > RUV, this may take several minutes... > > [21/Sep/2021:14:32:14.104152139 -0700] - NOTICE - NSMMReplicationPlugin - > changelog program - _cl5ConstructRUV - Rebuilding replication changelog RUV > complete. Result 0 (Success) > > [21/Sep/2021:14:32:14.105222428 -0700] - WARN - NSMMReplicationPlugin - > replica_check_for_data_reload - Disorderly shutdown for replica o=ipaca. > Check if DB RUV needs to be updated > > [21/Sep/2021:14:32:14.105487767 -0700] - WARN - NSMMReplicationPlugin - > replica_check_for_data_reload - Disorderly shutdown for replica > dc=example,dc=com. Check if DB RUV needs to be updated > > [21/Sep/2021:14:32:14.105629420 -0700] - NOTICE - NSMMReplicationPlugin - > Force update of database RUV (from CL RUV) -> 614a70200002002a0000 > > [21/Sep/2021:14:32:14.105754006 -0700] - NOTICE - NSMMReplicationPlugin - > Force update of database RUV (from CL RUV) -> 614a701f001100040000 > > [21/Sep/2021:14:32:14.107024420 -0700] - ERR - set_krb5_creds - Could not get > initial credentials for principal [ldap/ipa5.example....@example.com] in > keytab [FILE:/etc/dirsrv/ds.keytab]: -1765328228 (Cannot contact any KDC for > requested realm) > > [21/Sep/2021:14:32:14.115281150 -0700] - INFO - slapd_daemon - slapd started. > Listening on All Interfaces port 389 for LDAP requests > > [21/Sep/2021:14:32:14.115431268 -0700] - INFO - slapd_daemon - Listening on > All Interfaces port 636 for LDAPS requests > > [21/Sep/2021:14:32:14.115563063 -0700] - INFO - slapd_daemon - Listening on > /var/run/slapd-EXAMPLE-COM.socket for LDAPI requests > > [21/Sep/2021:14:32:14.153916575 -0700] - ERR - schema-compat-plugin - > schema-compat-plugin tree scan will start in about 5 seconds! > > [21/Sep/2021:14:32:14.191656955 -0700] - ERR - set_krb5_creds - Could not get > initial credentials for principal [ldap/ipa5.example....@example.com] in > keytab [FILE:/etc/dirsrv/ds.keytab]: -1765328228 (Cannot contact any KDC for > requested realm) > > [21/Sep/2021:14:32:14.273925417 -0700] - ERR - set_krb5_creds - Could not get > initial credentials for principal [ldap/ipa5.example....@example.com] in > keytab [FILE:/etc/dirsrv/ds.keytab]: -1765328228 (Cannot contact any KDC for > requested realm) > > [21/Sep/2021:14:32:17.628480282 -0700] - INFO - csngen_new_csn - Detected > large jump in CSN time. Delta: 3205725 (current time: 1632259937 vs > previous time: 1629054212)
That's a fairly large jump: $ date -d @1629054212 Sun Aug 15 09:03:32 PM CEST 2021 $ date -d @1632259937 Tue Sep 21 11:32:17 PM CEST 2021 Which version of IPA and dirserv is this and in which environment (which hypervisor) is it running? Is chrony active on all IPA hosts? If you have control of the virtualization stack, can you check that all virt hosts have NTP (or chrony) configured and that they're not overcommitted? This smells like https://bugzilla.redhat.com/show_bug.cgi?id=1807537 but it's not ; that bz took care of the cases where time functions returned an error, not when the time jump was too large. Best regards François > [21/Sep/2021:14:32:20.293538970 -0700] - ERR - schema-compat-plugin - > warning: no entries set up under cn=computers, cn=compat,dc=example,dc=com > > [21/Sep/2021:14:32:20.293740865 -0700] - ERR - schema-compat-plugin - > Finished plugin initialization. > > [root@ipa5 slapd-EXAMPLE-COM]# > > > > _______________________________________________ > FreeIPA-users mailing list -- freeipa-users@lists.fedorahosted.org > To unsubscribe send an email to freeipa-users-le...@lists.fedorahosted.org > Fedora Code of Conduct: > https://docs.fedoraproject.org/en-US/project/code-of-conduct/ > List Guidelines: https://fedoraproject.org/wiki/Mailing_list_guidelines > List Archives: > https://lists.fedorahosted.org/archives/list/freeipa-users@lists.fedorahosted.org > Do not reply to spam on the list, report it: > https://pagure.io/fedora-infrastructure _______________________________________________ FreeIPA-users mailing list -- freeipa-users@lists.fedorahosted.org To unsubscribe send an email to freeipa-users-le...@lists.fedorahosted.org Fedora Code of Conduct: https://docs.fedoraproject.org/en-US/project/code-of-conduct/ List Guidelines: https://fedoraproject.org/wiki/Mailing_list_guidelines List Archives: https://lists.fedorahosted.org/archives/list/freeipa-users@lists.fedorahosted.org Do not reply to spam on the list, report it: https://pagure.io/fedora-infrastructure
