Hallo everybody, I think i'm getting somewhere, but i need a little bit more help.
A couple of weeks ago the caIPAserviceCert.cfg was updated to fix a subject alternative names problem with the latest chrome browser. I've put back the original file from the RPM now and imported it with "ipa cerprofile-mod caIPAserviceCert --file=caIPAserviceCert.cfg". The error has now changed: Number of certificates and requests being tracked: 1. Request ID '20170610100215': status: CA_UNREACHABLE ca-error: Server at https://freeipa.fakedomain.local/ipa/xml failed request, will retry: 4301 (RPC failed at server. Certificate operation cannot be completed: FAILURE (String index out of range: -1)). stuck: no key pair storage: type=FILE,location='/etc/pki/tls/private/vertica1.fakedomain.local.key' certificate: type=FILE,location='/etc/pki/tls/certs/vertica1.fakedomain.local.crt' CA: IPA issuer: subject: expires: unknown pre-save command: post-save command: track: yes auto-renew: yes And the relevant http error_log: [Sat Jun 10 12:02:16.201423 2017] [:error] [pid 2589] ipa: DEBUG: WSGI wsgi_dispatch.__call__: [Sat Jun 10 12:02:16.201527 2017] [:error] [pid 2589] ipa: DEBUG: KerberosWSGIExecutioner.__call__: [Sat Jun 10 12:02:16.218650 2017] [:error] [pid 2589] ipa: DEBUG: Created connection context.ldap2_140451304220432 [Sat Jun 10 12:02:16.218722 2017] [:error] [pid 2589] ipa: DEBUG: WSGI WSGIExecutioner.__call__: [Sat Jun 10 12:02:16.227438 2017] [:error] [pid 2589] ipa: DEBUG: raw: cert_request(u'<removed request for privacy reasons>', request_type=u'pkcs10', cacn=u'ipa', principal=<ipapython.kerberos.Principal object at 0x7fbd5fe6ac50>, add=True, all=False, raw =False, version=u'2.51') [Sat Jun 10 12:02:16.241057 2017] [:error] [pid 2589] ipa: DEBUG: raw: ca_is_enabled(version=u'2.213') [Sat Jun 10 12:02:16.241180 2017] [:error] [pid 2589] ipa: DEBUG: ca_is_enabled(version=u'2.213') [Sat Jun 10 12:02:16.242996 2017] [:error] [pid 2589] ipa: DEBUG: retrieving schema for SchemaCache url=ldapi://%2fvar%2frun%2fslapd-fakedomain-LOCAL.socket conn=<ldap.ldapobject.SimpleLDAPObject instance at 0x7 fbd5fe5ab90> [Sat Jun 10 12:02:16.518140 2017] [:error] [pid 2589] ipa: DEBUG: raw: ca_show(u'ipa', version=u'2.213') [Sat Jun 10 12:02:16.518322 2017] [:error] [pid 2589] ipa: DEBUG: ca_show(u'ipa', rights=False, all=False, raw=False, version=u'2.213') [Sat Jun 10 12:02:16.518504 2017] [:error] [pid 2589] ipa: DEBUG: raw: ca_is_enabled(version=u'2.213') [Sat Jun 10 12:02:16.518596 2017] [:error] [pid 2589] ipa: DEBUG: ca_is_enabled(version=u'2.213') [Sat Jun 10 12:02:16.522149 2017] [:error] [pid 2589] ipa: DEBUG: IPA: virtual verify request certificate ignore caacl [Sat Jun 10 12:02:16.526742 2017] [:error] [pid 2589] ipa: DEBUG: raw: host_show(u'vertica1.fakedomain.local', version=u'2.213') [Sat Jun 10 12:02:16.527025 2017] [:error] [pid 2589] ipa: DEBUG: host_show(u'vertica1.fakedomain.local', rights=False, all=False, raw=False, version=u'2.213', no_members=False) [Sat Jun 10 12:02:16.534007 2017] [:error] [pid 2589] ipa: DEBUG: raw: caacl_find(None, version=u'2.213', no_members=False) [Sat Jun 10 12:02:16.534195 2017] [:error] [pid 2589] ipa: DEBUG: caacl_find(None, all=False, raw=False, version=u'2.213', no_members=False, pkey_only=False) [Sat Jun 10 12:02:16.539724 2017] [:error] [pid 2589] ipa: DEBUG: raw: host_show(u'vertica1.fakedomain.local', all=True, version=u'2.213') [Sat Jun 10 12:02:16.539910 2017] [:error] [pid 2589] ipa: DEBUG: host_show(u'vertica1.fakedomain.local', rights=False, all=True, raw=False, version=u'2.213', no_members=False) [Sat Jun 10 12:02:16.556041 2017] [:error] [pid 2589] ipa: DEBUG: raw: host_show(u'vertica1.fakedomain.local', all=True, version=u'2.213') [Sat Jun 10 12:02:16.556213 2017] [:error] [pid 2589] ipa: DEBUG: host_show(u'vertica1.fakedomain.local', rights=False, all=True, raw=False, version=u'2.213', no_members=False) [Sat Jun 10 12:02:16.569401 2017] [:error] [pid 2589] ipa: DEBUG: raw: host_show(u'vertica1.fakedomain.local', version=u'2.213') [Sat Jun 10 12:02:16.569574 2017] [:error] [pid 2589] ipa: DEBUG: host_show(u'vertica1.fakedomain.local', rights=False, all=False, raw=False, version=u'2.213', no_members=False) [Sat Jun 10 12:02:16.576081 2017] [:error] [pid 2589] ipa: DEBUG: raw: caacl_find(None, version=u'2.213', no_members=False) [Sat Jun 10 12:02:16.576277 2017] [:error] [pid 2589] ipa: DEBUG: caacl_find(None, all=False, raw=False, version=u'2.213', no_members=False, pkey_only=False) [Sat Jun 10 12:02:16.579350 2017] [:error] [pid 2589] ipa: DEBUG: ra.request_certificate() [Sat Jun 10 12:02:16.580814 2017] [:error] [pid 2589] ipa: DEBUG: request POST https://freeipa.fakedomain.local:443/ca/eeca/ca/profileSubmitSSLClient [Sat Jun 10 12:02:16.580893 2017] [:error] [pid 2589] ipa: DEBUG: request body 'xml=true&profileId=caIPAserviceCert&authorityId=24c649da-1d89-40af-a1eb-72b776379eb0&cert_request=<removed for privacy reasons>%3D&cert_request_type=pkcs10' [Sat Jun 10 12:02:16.580995 2017] [:error] [pid 2589] ipa: DEBUG: NSSConnection init freeipa.fakedomain.local [Sat Jun 10 12:02:16.730493 2017] [:error] [pid 2589] ipa: DEBUG: Connecting: 192.168.0.10:0 [Sat Jun 10 12:02:16.741739 2017] [:error] [pid 2589] ipa: DEBUG: approved_usage = SSL Server intended_usage = SSL Server [Sat Jun 10 12:02:16.741828 2017] [:error] [pid 2589] ipa: DEBUG: cert valid True for "CN=freeipa.fakedomain.local,O=fakedomain.LOCAL" [Sat Jun 10 12:02:16.746383 2017] [:error] [pid 2589] ipa: DEBUG: handshake complete, peer = 192.168.0.10:443 [Sat Jun 10 12:02:16.746447 2017] [:error] [pid 2589] ipa: DEBUG: Protocol: TLS1.2 [Sat Jun 10 12:02:16.746493 2017] [:error] [pid 2589] ipa: DEBUG: Cipher: TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384 [Sat Jun 10 12:02:16.754408 2017] [:error] [pid 2589] ipa: DEBUG: approved_usage = SSL Server intended_usage = SSL Server [Sat Jun 10 12:02:16.754489 2017] [:error] [pid 2589] ipa: DEBUG: cert valid True for "CN=freeipa.fakedomain.local,O=fakedomain.LOCAL" [Sat Jun 10 12:02:16.766359 2017] [:error] [pid 2589] ipa: DEBUG: handshake complete, peer = 192.168.0.10:443 [Sat Jun 10 12:02:16.766423 2017] [:error] [pid 2589] ipa: DEBUG: Protocol: TLS1.2 [Sat Jun 10 12:02:16.766470 2017] [:error] [pid 2589] ipa: DEBUG: Cipher: TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384 [Sat Jun 10 12:02:16.860096 2017] [:error] [pid 2589] ipa: DEBUG: response status 200 [Sat Jun 10 12:02:16.860187 2017] [:error] [pid 2589] ipa: DEBUG: response headers {'date': 'Sat, 10 Jun 2017 10:02:16 GMT', 'content-length': '143', 'content-type': 'application/xml', 'server': 'Apache/2.4.6 (CentOS) mod_auth_gssapi/1.4.0 mod_nss/1.0.14 NSS/3.21 Basic ECC mod_wsgi/3.4 Python/2.7.5'} [Sat Jun 10 12:02:16.860242 2017] [:error] [pid 2589] ipa: DEBUG: response body '<?xml version="1.0" encoding="UTF-8" standalone="no"?><XMLResponse><Status>1</Status><Error>String index out of range: -1</Erro r></XMLResponse>' [Sat Jun 10 12:02:16.860672 2017] [:error] [pid 2589] ipa: DEBUG: parse_profile_submit_result_xml() xml_text: [Sat Jun 10 12:02:16.860679 2017] [:error] [pid 2589] <?xml version="1.0" encoding="UTF-8" standalone="no"?><XMLResponse><Status>1</Status><Error>String index out of range: -1</Error></XMLResponse> [Sat Jun 10 12:02:16.860687 2017] [:error] [pid 2589] parse_result: [Sat Jun 10 12:02:16.860689 2017] [:error] [pid 2589] {'error_code': 1, 'error_string': u'String index out of range: -1'} [Sat Jun 10 12:02:16.860774 2017] [:error] [pid 2589] ipa: ERROR: ra.request_certificate(): FAILURE (String index out of range: -1) [Sat Jun 10 12:02:16.915872 2017] [:error] [pid 2589] ipa: DEBUG: WSGI wsgi_execute PublicError: Traceback (most recent call last): [Sat Jun 10 12:02:16.915906 2017] [:error] [pid 2589] File "/usr/lib/python2.7/site-packages/ipaserver/rpcserver.py", line 366, in wsgi_execute [Sat Jun 10 12:02:16.915912 2017] [:error] [pid 2589] result = command(*args, **options) [Sat Jun 10 12:02:16.915914 2017] [:error] [pid 2589] File "/usr/lib/python2.7/site-packages/ipalib/frontend.py", line 449, in __call__ [Sat Jun 10 12:02:16.915916 2017] [:error] [pid 2589] return self.__do_call(*args, **options) [Sat Jun 10 12:02:16.915918 2017] [:error] [pid 2589] File "/usr/lib/python2.7/site-packages/ipalib/frontend.py", line 477, in __do_call [Sat Jun 10 12:02:16.915919 2017] [:error] [pid 2589] ret = self.run(*args, **options) [Sat Jun 10 12:02:16.915921 2017] [:error] [pid 2589] File "/usr/lib/python2.7/site-packages/ipalib/frontend.py", line 799, in run [Sat Jun 10 12:02:16.915923 2017] [:error] [pid 2589] return self.execute(*args, **options) [Sat Jun 10 12:02:16.915924 2017] [:error] [pid 2589] File "/usr/lib/python2.7/site-packages/ipaserver/plugins/cert.py", line 629, in execute [Sat Jun 10 12:02:16.915926 2017] [:error] [pid 2589] csr, profile_id, ca_id, request_type=request_type) [Sat Jun 10 12:02:16.915928 2017] [:error] [pid 2589] File "/usr/lib/python2.7/site-packages/ipaserver/plugins/dogtag.py", line 1612, in request_certificate [Sat Jun 10 12:02:16.915929 2017] [:error] [pid 2589] parse_result.get('error_string')) [Sat Jun 10 12:02:16.915931 2017] [:error] [pid 2589] File "/usr/lib/python2.7/site-packages/ipaserver/plugins/dogtag.py", line 1334, in raise_certificate_operation_error [Sat Jun 10 12:02:16.915933 2017] [:error] [pid 2589] raise errors.CertificateOperationError(error=err_msg) [Sat Jun 10 12:02:16.915934 2017] [:error] [pid 2589] CertificateOperationError: Certificate operation cannot be completed: FAILURE (String index out of range: -1) [Sat Jun 10 12:02:16.915936 2017] [:error] [pid 2589] [Sat Jun 10 12:02:16.916120 2017] [:error] [pid 2589] ipa: INFO: [xmlserver] host/vertica1.fakedomain.local@fakedomain.LOCAL: cert_request(u'<removed for privacy reasons>', principal=u'host/vertica1.fakedomain.local@fakedomain.LOCAL', add=True, version= u'2.51'): CertificateOperationError [Sat Jun 10 12:02:16.916214 2017] [:error] [pid 2589] ipa: DEBUG: response: CertificateOperationError: Certificate operation cannot be completed: FAILURE (String index out of range: -1) [Sat Jun 10 12:02:16.916801 2017] [:error] [pid 2589] ipa: DEBUG: no session id in request, generating empty session data with id=d4daa3c27378d6890f30deea15b65d7d [Sat Jun 10 12:02:16.916920 2017] [:error] [pid 2589] ipa: DEBUG: store session: session_id=d4daa3c27378d6890f30deea15b65d7d start_timestamp=2017-06-10T12:02:16 access_timestamp=2017-06-10T12:02:16 expiration _timestamp=1970-01-01T01:00:00 [Sat Jun 10 12:02:16.917574 2017] [:error] [pid 2589] ipa: DEBUG: finalize_kerberos_acquisition: xmlserver ccache_name="FILE:/var/run/httpd/ipa/clientcaches/host~vertica1.fakedomain.local@fakedomain.LOCAL-V0fnDF" s ession_id="d4daa3c27378d6890f30deea15b65d7d" [Sat Jun 10 12:02:16.917664 2017] [:error] [pid 2589] ipa: DEBUG: reading ccache data from file "/var/run/httpd/ipa/clientcaches/host~vertica1.fakedomain.local@fakedomain.LOCAL-V0fnDF" [Sat Jun 10 12:02:16.918345 2017] [:error] [pid 2589] ipa: DEBUG: set_session_expiration_time: duration_type=inactivity_timeout duration=1200 max_age=1497175035.92 expiration=1497090136.92 (2017-06-10T12:22:1 6) [Sat Jun 10 12:02:16.918427 2017] [:error] [pid 2589] ipa: DEBUG: store session: session_id=d4daa3c27378d6890f30deea15b65d7d start_timestamp=2017-06-10T12:02:16 access_timestamp=2017-06-10T12:02:16 expiration _timestamp=2017-06-10T12:22:16 [Sat Jun 10 12:02:16.919817 2017] [:error] [pid 2589] ipa: DEBUG: Destroyed connection context.ldap2_140451304220432 And the tomcat debug log: [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: according to ccMode, authorization for servlet: caProfileSubmitSSLClient is LDAP based, not XML {1}, use default authz mgr: {2}. [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: according to ccMode, authorization for servlet: caProfileSubmitSSLClient is LDAP based, not XML {1}, use default authz mgr: {2}. [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: CMSServlet:service() uri = /ca/eeca/ca/profileSubmitSSLClient [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: CMSServlet::service() param name='xml' value='true' [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: CMSServlet::service() param name='profileId' value='caIPAserviceCert' [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: CMSServlet::service() param name='authorityId' value='24c649da-1d89-40af-a1eb-72b776379eb0' [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: CMSServlet::service() param name='cert_request' value='(sensitive)' [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: CMSServlet::service() param name='cert_request_type' value='pkcs10' [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: CMSServlet: caProfileSubmitSSLClient start to service. [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: xmlOutput true [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: ProfileSubmitServlet: isRenewal false [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: according to ccMode, authorization for servlet: caProfileSubmit is LDAP based, not XML {1}, use default authz mgr: {2}. [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: ProfileSubmitServlet: profile: caIPAserviceCert [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: CAProcessor: Input Parameters: [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: CAProcessor: - isRenewal: false [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: CAProcessor: - remoteHost: 192.168.0.10 [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: CAProcessor: - cert_request_type: pkcs10 [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: CAProcessor: - profileId: caIPAserviceCert [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: CAProcessor: - cert_request: (sensitive) [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: CAProcessor: - remoteAddr: 192.168.0.10 [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: EnrollmentProcessor: isRenewal false [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: EnrollmentProcessor: profileId caIPAserviceCert [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: EnrollmentProcessor: set Inputs into profile Context [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: EnrollmentProcessor: authenticator raCertAuth found [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: CertProcessor: No authenticator credentials required [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: EnrollmentProcessor: set sslClientCertProvider [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: authenticate: authentication required. [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: CMSServlet: in auditSubjectID [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: CMSServlet: auditSubjectID auditContext {sslClientCertProvider=com.netscape.cms.servlet.profile.SSLClientCertProvider@723e403b, profileContext=com.netsca pe.cms.profile.common.ProfileContext@7b3d33dd} [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: CMSServlet auditSubjectID: subjectID: null [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: AgentCertAuthentication: start [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: authenticator instance name is raCertAuth [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: AgentCertAuthenticator: got provider [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: AgentCertAuthenticator: retrieving client certificate [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: AgentCertAuthenticator: got certificates [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: In LdapBoundConnFactory::getConn() [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: masterConn is connected: true [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: getConn: conn is connected true [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: getConn: mNumConns now 4 [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: returnConn: mNumConns now 5 [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: In LdapBoundConnFactory::getConn() [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: masterConn is connected: true [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: getConn: conn is connected true [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: getConn: mNumConns now 2 [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: returnConn: mNumConns now 3 [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: check if ipara is in group Registration Manager Agents [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: UGSubsystem.isMemberOf() using new lookup code [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: In LdapBoundConnFactory::getConn() [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: masterConn is connected: true [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: getConn: conn is connected true [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: getConn: mNumConns now 2 [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: authorization search base: cn=Registration Manager Agents,ou=groups,o=ipaca [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: authorization search filter: (uniquemember=uid=ipara,ou=people,o=ipaca) [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: authorization result: true [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: returnConn: mNumConns now 3 [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: AgentCertAuthentication: authenticated uid=ipara,ou=people,o=ipaca [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: SignedAuditEventFactory: create() message created for eventType=AUTH_SUCCESS [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: CertProcessor authToken not null [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: CAProcessor: authz using acl: [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: Start parsePKCS10(): <removed for privacy reasons> [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: EnrollProfile: parsePKCS10: signature verification enabled [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: EnrollProfile: parsePKCS10: use internal token [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: EnrollProfile: parsePKCS10 setting thread token [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: EnrollProfile: parsePKCS10 restoring thread token [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: Repository: in getNextSerialNumber. [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: In LdapBoundConnFactory::getConn() [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: masterConn is connected: true [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: getConn: conn is connected true [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: getConn: mNumConns now 4 [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: Repository: getSerialNumber() [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: returnConn: mNumConns now 5 [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: Repository: getSerialNumber serial=0 [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: Repository: in InitCache [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: Repository: Instance of Request Repository or CRLRepository. [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: Repository: minSerial:1 maxSerial: 10000000 [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: Repository: nextMinSerial: nextMaxSerial: [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: Repository: increment:10000000 lowWaterMark: 2000000 [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: RequestRepository: in getLastSerialNumberInRange: min 1 max 10000000 [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: RequestRepository: mRequestQueue com.netscape.cmscore.request.RequestQueue@50d3b8c5 [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: RequestRepository: about to call mRequestQueue.getLastRequestIdInRange [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: RequestQueue: getLastRequestId: low 1 high 10000000 [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: RequestQueue: getLastRequestId: filter (requeststate=*) fromId 10000000 [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: In LdapBoundConnFactory::getConn() [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: masterConn is connected: true [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: getConn: conn is connected true [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: getConn: mNumConns now 4 [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: In DBVirtualList filter attrs startFrom sortKey pageSize filter: (requeststate=*) attrs: null pageSize -5 startFrom 0810000000 [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: returnConn: mNumConns now 5 [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: DBVirtualList: searching for entry 0810000000 [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: DBVirtualList.getEntries() [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: DBVirtualList: entries: 6 [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: DBVirtualList: top: 64 [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: DBVirtualList: size: 70 [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: RequestQueue: getLastRequestId: size 70 [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: RequestQueue: getSizeBeforeJumpTo: 70 [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: RequestQueue: curReqId: 70 [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: RequestQueue: getLastRequestId : returning value 70 [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: Repository: mLastSerialNo: 70 [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: Repository: checkRange mLastSerialNo=71 [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: Repository: getNextSerialNumber: returning retSerial 71 [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: EnrollProfile: setDefaultCertInfo: setting issuerDN using exact CA signing cert subjectDN encoding [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: EnrollProfile: createRequest 71 [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: CertProcessor: request from RA: ipara [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: CertProcessor: profileSetid=serverCertSet [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: CertProcessor: request 71 [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: CertProcessor: populating request inputs [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: Start parsePKCS10(): <removed for privacy reasons> [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: EnrollProfile: parsePKCS10: signature verification enabled [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: EnrollProfile: parsePKCS10: use internal token [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: EnrollProfile: parsePKCS10 setting thread token [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: EnrollProfile: parsePKCS10 restoring thread token [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: Found PKCS10 extension [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: Set extensions [ObjectId: 2.5.29.17 Criticality=false SubjectAlternativeName [ [DNSName: vertica1.fakedomain.local, OtherName: (UTF8String)1.3.6.1.4.1.311.20.2.3,host/vertica1.fakedomain.local@fakedomain.LOCAL, OtherName: (Any)1.3.6.1.5.2.2,303ca00f1b0d43524f5353594e2e4c4f43414ca1293027a00302010 1a120301e1b04686f73741b1676657274696361312e63726f7373796e2e6c6f63616c]] , oid=2.5.29.37 val=48 10 6 8 43 6 1 5 5 7 3 1 , ObjectId: 2.5.29.19 Criticality=true BasicConstraints:[ CA:false PathLen: undefined ] , ObjectId: 2.5.29.14 Criticality=false SubjectKeyIdentifier [ KeyIdentifier [ 09 93 FD D2 46 C6 38 0B 20 A1 60 2C BC 65 0D FF C1 3E 78 84 ] ] ] [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: Finish parsePKCS10 - CN=vertica1.fakedomain.local [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: BasicProfile: populate() policy setid =serverCertSet [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: SubjectNameDefault: populate start java.lang.StringIndexOutOfBoundsException: String index out of range: -1 at java.lang.String.substring(String.java:1967) at com.netscape.certsrv.pattern.Pattern.substitute2(Pattern.java:132) at com.netscape.cms.profile.def.EnrollDefault.mapPattern(EnrollDefault.java:804) at com.netscape.cms.profile.def.SubjectNameDefault.populate(SubjectNameDefault.java:160) at com.netscape.cms.profile.def.EnrollDefault.populate(EnrollDefault.java:224) at com.netscape.cms.profile.common.BasicProfile.populate(BasicProfile.java:1101) at com.netscape.cms.profile.common.EnrollProfile.populate(EnrollProfile.java:1330) at com.netscape.cms.servlet.cert.CertProcessor.populateRequests(CertProcessor.java:362) at com.netscape.cms.servlet.cert.EnrollmentProcessor.processEnrollment(EnrollmentProcessor.java:181) at com.netscape.cms.servlet.cert.EnrollmentProcessor.processEnrollment(EnrollmentProcessor.java:96) at com.netscape.cms.servlet.profile.ProfileSubmitServlet.processEnrollment(ProfileSubmitServlet.java:243) at com.netscape.cms.servlet.profile.ProfileSubmitServlet.process(ProfileSubmitServlet.java:128) at com.netscape.cms.servlet.base.CMSServlet.service(CMSServlet.java:515) at javax.servlet.http.HttpServlet.service(HttpServlet.java:731) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:499) at org.apache.catalina.security.SecurityUtil$1.run(SecurityUtil.java:288) at org.apache.catalina.security.SecurityUtil$1.run(SecurityUtil.java:285) at java.security.AccessController.doPrivileged(Native Method) at javax.security.auth.Subject.doAsPrivileged(Subject.java:549) at org.apache.catalina.security.SecurityUtil.execute(SecurityUtil.java:320) at org.apache.catalina.security.SecurityUtil.doAsPrivilege(SecurityUtil.java:175) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:297) at org.apache.catalina.core.ApplicationFilterChain.access$000(ApplicationFilterChain.java:55) at org.apache.catalina.core.ApplicationFilterChain$1.run(ApplicationFilterChain.java:191) at org.apache.catalina.core.ApplicationFilterChain$1.run(ApplicationFilterChain.java:187) at java.security.AccessController.doPrivileged(Native Method) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:186) at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at org.apache.catalina.security.SecurityUtil$1.run(SecurityUtil.java:288) at org.apache.catalina.security.SecurityUtil$1.run(SecurityUtil.java:285) at java.security.AccessController.doPrivileged(Native Method) at javax.security.auth.Subject.doAsPrivileged(Subject.java:549) at org.apache.catalina.security.SecurityUtil.execute(SecurityUtil.java:320) at org.apache.catalina.security.SecurityUtil.doAsPrivilege(SecurityUtil.java:260) at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:237) at org.apache.catalina.core.ApplicationFilterChain.access$000(ApplicationFilterChain.java:55) at org.apache.catalina.core.ApplicationFilterChain$1.run(ApplicationFilterChain.java:191) at org.apache.catalina.core.ApplicationFilterChain$1.run(ApplicationFilterChain.java:187) at java.security.AccessController.doPrivileged(Native Method) at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:186) at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:220) at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:122) at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:505) at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:169) at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:103) at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:956) at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:116) at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:436) at org.apache.coyote.ajp.AjpProcessor.process(AjpProcessor.java:190) at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:625) at org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:316) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) at java.lang.Thread.run(Thread.java:748) [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: ProfileSubmitServlet: error in processing request: java.lang.StringIndexOutOfBoundsException: String index out of range: -1 [10/Jun/2017:12:02:16][ajp-bio-127.0.0.1-8009-exec-1]: CMSServlet: curDate=Sat Jun 10 12:02:16 CEST 2017 id=caProfileSubmitSSLClient time=78 Any ideas? Best regards, Jochem Kuijpers _______________________________________________ FreeIPA-users mailing list -- freeipa-users@lists.fedorahosted.org To unsubscribe send an email to freeipa-users-le...@lists.fedorahosted.org
