Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

OCSP installation failure, possibly due to index issue #4919

Open
PsOverflow opened this issue Dec 24, 2024 · 0 comments
Open

OCSP installation failure, possibly due to index issue #4919

PsOverflow opened this issue Dec 24, 2024 · 0 comments

Comments

@PsOverflow
Copy link
Contributor

Issue: OCSP installation is failing with an error: PKIException: LDAP error (1): Operations error

Affected version:
OS: Fedora-41
Build: @pki/master
pki-11.6.0-0.2.alpha2.20241223220239UTC.80a0b94e.fc41.src.rpm
389-ds-base-3.1.1-3.fc41.x86_64

Steps to reproduce:

  1. Install DS
  2. Install CA using interactive based installation
  3. Install OCSP using interactive based installation:
...
FINE: LdapBoundConnection: Connecting to pki1.example.com:389 with basic auth as cn=Directory Manager
FINE: PKISocketFactory: Creating socket for pki1.example.com:389
FINE: LdapBoundConnFactory.makeMinimum: ends: total connections: 1
FINE: LdapBoundConnFactory.makeMinimum: ends: number of connections: 1
FINE: LdapBoundConnFactory: number of connections: 0
FINE: LdapBoundConnFactory (UGSubsystem).getConn:  final values. Total: 1, pool: 0
FINE: LdapBoundConnFactory (UGSubsystem).returnConn: initial values. Total: 1, pool: 0
FINE: LdapBoundConnFactory (UGSubsystem).returnConn:  final values. Total: 0, pool: 0
FINE: Destroying LdapBoundConnFactory(UGSubsystem)
com.netscape.certsrv.base.PKIException: LDAP error (1): Operations error
	at com.netscape.certsrv.ldap.LDAPExceptionConverter.toPKIException(LDAPExceptionConverter.java:66)
	at com.netscape.cmscore.usrgrp.UGSubsystem.modifyGroup(UGSubsystem.java:1802)
	at org.dogtagpki.server.cli.SubsystemGroupMemberAddCLI.execute(SubsystemGroupMemberAddCLI.java:77)
	at org.dogtagpki.cli.CommandCLI.execute(CommandCLI.java:58)
	at org.dogtagpki.cli.CLI.execute(CLI.java:353)
	at org.dogtagpki.cli.CLI.execute(CLI.java:353)
	at org.dogtagpki.cli.CLI.execute(CLI.java:353)
	at org.dogtagpki.cli.CLI.execute(CLI.java:353)
	at org.dogtagpki.server.cli.PKIServerCLI.execute(PKIServerCLI.java:93)
	at org.dogtagpki.server.cli.PKIServerCLI.main(PKIServerCLI.java:123)
Caused by: netscape.ldap.LDAPException: Operations error (1)
	at netscape.ldap.LDAPConnection.checkMsg(LDAPConnection.java:4933)
	at netscape.ldap.LDAPConnection.modify(LDAPConnection.java:3201)
	at netscape.ldap.LDAPConnection.modify(LDAPConnection.java:3139)
	at netscape.ldap.LDAPConnection.modify(LDAPConnection.java:3149)
	at netscape.ldap.LDAPConnection.modify(LDAPConnection.java:3114)
	at com.netscape.cmscore.usrgrp.UGSubsystem.modifyGroup(UGSubsystem.java:1799)
	... 8 more
ERROR: CalledProcessError: Command '['/usr/sbin/runuser', '-u', 'pkiuser', '--', '/usr/lib/jvm/jre-21-openjdk/bin/java', '-classpath', '/usr/share/tomcat/bin/tomcat-juli.jar:/usr/share/java/tomcat-servlet-api.jar:/usr/share/pki/tks/webapps/tks/WEB-INF/lib/*:/var/lib/pki/pki-tomcat/common/lib/*:/usr/share/pki/lib/*', '-Djavax.sql.DataSource.Factory=org.apache.commons.dbcp.BasicDataSourceFactory', '-Dcatalina.base=/var/lib/pki/pki-tomcat', '-Dcatalina.home=/usr/share/tomcat', '-Djava.endorsed.dirs=', '-Djava.io.tmpdir=/var/lib/pki/pki-tomcat/temp', '-Djava.util.logging.config.file=/var/lib/pki/pki-tomcat/conf/logging.properties', '-Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager', '-Dcom.redhat.fips=false', 'org.dogtagpki.server.cli.PKIServerCLI', 'tks-group-member-add', '--debug', 'Administrators', 'tksadmin']' returned non-zero exit status 255.
  File "/usr/lib/python3.13/site-packages/pki/server/pkispawn.py", line 594, in main
    deployer.spawn()
    ~~~~~~~~~~~~~~^^
  File "/usr/lib/python3.13/site-packages/pki/server/deployment/__init__.py", line 5887, in spawn
    scriptlet.spawn(self)
    ~~~~~~~~~~~~~~~^^^^^^
  File "/usr/lib/python3.13/site-packages/pki/server/deployment/scriptlets/configuration.py", line 160, in spawn
    deployer.setup_admin_user(subsystem, admin_cert)
    ~~~~~~~~~~~~~~~~~~~~~~~~~^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.13/site-packages/pki/server/deployment/__init__.py", line 4191, in setup_admin_user
    subsystem.add_group_member(group, uid)
    ~~~~~~~~~~~~~~~~~~~~~~~~~~^^^^^^^^^^^^
  File "/usr/lib/python3.13/site-packages/pki/server/subsystem.py", line 1877, in add_group_member
    self.run(cmd, as_current_user=as_current_user)
    ~~~~~~~~^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.13/site-packages/pki/server/subsystem.py", line 2259, in run
    return subprocess.run(
           ~~~~~~~~~~~~~~^
        cmd,
        ^^^^
    ...<2 lines>...
        stderr=stderr,
        ^^^^^^^^^^^^^^
        check=True)
        ^^^^^^^^^^^
  File "/usr/lib64/python3.13/subprocess.py", line 577, in run
    raise CalledProcessError(retcode, process.args,
                             output=stdout, stderr=stderr)


Installation failed: Command failed: /usr/sbin/runuser -u pkiuser -- /usr/lib/jvm/jre-21-openjdk/bin/java -classpath /usr/share/tomcat/bin/tomcat-juli.jar:/usr/share/java/tomcat-servlet-api.jar:/usr/share/pki/tks/webapps/tks/WEB-INF/lib/*:/var/lib/pki/pki-tomcat/common/lib/*:/usr/share/pki/lib/* -Djavax.sql.DataSource.Factory=org.apache.commons.dbcp.BasicDataSourceFactory -Dcatalina.base=/var/lib/pki/pki-tomcat -Dcatalina.home=/usr/share/tomcat -Djava.endorsed.dirs= -Djava.io.tmpdir=/var/lib/pki/pki-tomcat/temp -Djava.util.logging.config.file=/var/lib/pki/pki-tomcat/conf/logging.properties -Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager -Dcom.redhat.fips=false org.dogtagpki.server.cli.PKIServerCLI tks-group-member-add --debug Administrators tksadmin

DS error log:

    [24/Dec/2024:04:10:18.088031241 -0500] - INFO - dbmdb_import_all_done - Backend pki-tomcat-CA is now online.
    [24/Dec/2024:04:10:18.089395802 -0500] - INFO - dbmdb_task_finish - pki-tomcat-CA: Finished indexing task 'cn=index1160589769,cn=index,cn=tasks,cn=config'. Exit code is 0
    [24/Dec/2024:04:13:05.392585010 -0500] - INFO - ldbm_instance_config_cachememsize_set - force a minimal value 512000
    [24/Dec/2024:04:13:05.411948965 -0500] - ERR - attrcrypt_cipher_init - No symmetric key found for cipher AES in backend pki-tomcat-OCSP, attempting to create one...
    [24/Dec/2024:04:13:05.416417771 -0500] - INFO - attrcrypt_cipher_init - Key for cipher AES successfully generated and stored
    [24/Dec/2024:04:13:05.417005492 -0500] - ERR - attrcrypt_cipher_init - No symmetric key found for cipher 3DES in backend pki-tomcat-OCSP, attempting to create one...
    [24/Dec/2024:04:13:05.421101674 -0500] - INFO - attrcrypt_cipher_init - Key for cipher 3DES successfully generated and stored
    [24/Dec/2024:04:13:06.720212374 -0500] - NOTICE - dse_modify - A plugin has been enabled or disabled, but nsslapd-dynamic-plugins is off. A server restart is required to change this plugin state.
    [24/Dec/2024:04:13:14.285665250 -0500] - NOTICE - dse_modify - A plugin has been enabled or disabled, but nsslapd-dynamic-plugins is off. A server restart is required to change this plugin state.
    [24/Dec/2024:04:13:31.925962032 -0500] - WARN - dbmdb_open_dbi_from_filename - Attempt to open to open dbi pki-tomcat-OCSP/description while txn is already pending. Usually that means that the index must be reindex. Root cause is likely that last import of reindex failed or that the index was created but not yet reindexed).
    [24/Dec/2024:04:13:31.927291978 -0500] - WARN - slapi_log_backtrace - 	[0]	/usr/lib64/dirsrv/libslapd.so.0(+0x5cc78) [0x7f7049c5cc78]
    [24/Dec/2024:04:13:31.928195392 -0500] - WARN - slapi_log_backtrace - 	[1]	/usr/lib64/dirsrv/plugins/libback-ldbm.so(dbmdb_open_dbi_from_filename+0x35a) [0x7f7045830d3a]
    [24/Dec/2024:04:13:31.928806344 -0500] - WARN - slapi_log_backtrace - 	[2]	/usr/lib64/dirsrv/plugins/libback-ldbm.so(dbmdb_get_db+0xbc) [0x7f7045834b3c]
    [24/Dec/2024:04:13:31.929356805 -0500] - WARN - slapi_log_backtrace - 	[3]	/usr/lib64/dirsrv/plugins/libback-ldbm.so(dblayer_get_index_file+0xa8) [0x7f70457b8008]
    [24/Dec/2024:04:13:31.929917571 -0500] - WARN - slapi_log_backtrace - 	[4]	/usr/lib64/dirsrv/plugins/libback-ldbm.so(index_addordel_values_ext_sv+0x17c) [0x7f70457ca42c]
    [24/Dec/2024:04:13:31.930388648 -0500] - WARN - slapi_log_backtrace - 	[5]	/usr/lib64/dirsrv/plugins/libback-ldbm.so(index_addordel_values_sv+0x18) [0x7f70457cb198]
    [24/Dec/2024:04:13:31.930808880 -0500] - WARN - slapi_log_backtrace - 	[6]	/usr/lib64/dirsrv/plugins/libback-ldbm.so(index_add_mods+0x680) [0x7f70457cbe40]
    [24/Dec/2024:04:13:31.931187104 -0500] - WARN - slapi_log_backtrace - 	[7]	/usr/lib64/dirsrv/plugins/libback-ldbm.so(ldbm_back_modify+0x852) [0x7f70457ea622]
    [24/Dec/2024:04:13:31.931528032 -0500] - WARN - slapi_log_backtrace - 	[8]	/usr/lib64/dirsrv/libslapd.so.0(+0x67360) [0x7f7049c67360]
    [24/Dec/2024:04:13:31.931868143 -0500] - WARN - slapi_log_backtrace - 	[9]	/usr/lib64/dirsrv/libslapd.so.0(do_modify+0x99e) [0x7f7049c6910e]
    [24/Dec/2024:04:13:31.932257115 -0500] - WARN - slapi_log_backtrace - 	[10]	/usr/sbin/ns-slapd(+0xe8bb) [0x55bd737a08bb]
    [24/Dec/2024:04:13:31.932619774 -0500] - WARN - slapi_log_backtrace - 	[11]	/lib64/libnspr4.so(+0x233b7) [0x7f704a3203b7]
    [24/Dec/2024:04:13:31.933037389 -0500] - WARN - slapi_log_backtrace - 	[12]	/lib64/libc.so.6(+0x70cd7) [0x7f7049a7ccd7]
    [24/Dec/2024:04:13:31.933411266 -0500] - WARN - slapi_log_backtrace - 	[13]	/lib64/libc.so.6(+0xf4c8c) [0x7f7049b00c8c]
    [24/Dec/2024:04:13:31.933764098 -0500] - ERR - index_addordel_values_ext_sv - index_read NULL (could not open index attr description)
    [24/Dec/2024:04:13:31.934164943 -0500] - ERR - index_addordel_values_ext_sv - database index operation failed BAD 1210, err=-30798 Unexpected dbimpl error code
    [24/Dec/2024:04:13:31.934588643 -0500] - ERR - index_add_mods - database index operation failed BAD 1041, err=-30798 Unexpected dbimpl error code
    [24/Dec/2024:04:13:31.934969501 -0500] - ERR - index_add_mods - database index operation failed BAD 1040, err=-30798 Unexpected dbimpl error code
    [24/Dec/2024:04:13:31.935370745 -0500] - ERR - ldbm_back_modify - index_add_mods failed, err=-30798 Unexpected dbimpl error code

Additional:
CA and KRA installations are working fine and deployed on same DS instance but OCSP, TKS installation are failing with ^^ errors.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

1 participant