Hi François,

I noticed that the previous time 1629054212 in the following two log entries are the same! I wonder if there is a fixed time instead of a wrong clock?

Thanks!

Kathy.

[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:14:32:17.628480282 -0700] - INFO - csngen_new_csn - Detected large jump in CSN time. Delta: 3205725 (current time: 1632259937 vs previous time: 1629054212)

On Wed, Sep 22, 2021 at 11:32 AM Kathy Zhu wrote:

Hi François,

It is confirmed that the VM host is configured with NTP. Now I need to dig into the reason for the time gap. Thank you so much for pointing it out.

Thanks.

Kathy.

On Wed, Sep 22, 2021 at 8:27 AM Kathy Zhu wrote:

Hi François,

The IPA server is a VMware virtual host. I have NTP configured on all IPA servers and monitor NTP service as well. I do not manage the VMware infra myself, I will check my coworker and get back to you.

The software versions:

Centos 7-8.2003.0 SELinux enabled

ipa-server.x86_64 4.6.8-5.el7.centos.6

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

Thanks!

Kathy.

On Tue, Sep 21, 2021 at 11:53 PM François Cami <fcami@redhat.com> wrote:

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.com@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.com@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.com@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.com@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.com@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.com@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.com@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.com@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.com@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.com@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.com@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.com@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.com@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.com@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-leave@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