Re: [Pki-users] Dogtag TPS wizard - java.lang.NullPointerException on last button

Hi, I tried a second time. Here is the log of the ca and from the tps. I skipped pki-kra and pki-tks because there are no log entries after the startup and no errors on startup. Ath the ca thre is the line: [11/Nov/2010:16:25:52][http-9544-Processor21]: RegisterUser: exception thrown: java.lang.NullPointerException Wher does this come from? best regards, Fabian pki-subca/debug: <next button pressed> [11/Nov/2010:16:25:46][http-9545-Processor24]: CMSServlet:service() uri = /ca/admin/ca/getDomainXML [11/Nov/2010:16:25:46][http-9545-Processor24]: CMSServlet: caGetDomainXML start to service. [11/Nov/2010:16:25:46][http-9545-Processor24]: GetDomainXML: processing... [11/Nov/2010:16:25:46][http-9545-Processor24]: LdapBoundConnFactory: init [11/Nov/2010:16:25:46][http-9545-Processor24]: LdapBoundConnFactory:doCloning true [11/Nov/2010:16:25:46][http-9545-Processor24]: LdapAuthInfo: init() [11/Nov/2010:16:25:46][http-9545-Processor24]: LdapAuthInfo: init begins [11/Nov/2010:16:25:46][http-9545-Processor24]: LdapAuthInfo: init: prompt is Internal LDAP Database [11/Nov/2010:16:25:46][http-9545-Processor24]: LdapAuthInfo: init: try getting from memory cache [11/Nov/2010:16:25:46][http-9545-Processor24]: LdapAuthInfo: init: got password from memory [11/Nov/2010:16:25:46][http-9545-Processor24]: LdapAuthInfo: init: password found for prompt. [11/Nov/2010:16:25:46][http-9545-Processor24]: LdapAuthInfo: password ok: store in memory cache [11/Nov/2010:16:25:46][http-9545-Processor24]: LdapAuthInfo: init ends [11/Nov/2010:16:25:46][http-9545-Processor24]: init: before makeConnection errorIfDown is false [11/Nov/2010:16:25:46][http-9545-Processor24]: makeConnection: errorIfDown false [11/Nov/2010:16:25:46][http-9545-Processor24]: Established LDAP connection using basic authentication to host localhost port 389 as cn=Directory Manager [11/Nov/2010:16:25:46][http-9545-Processor24]: initializing with mininum 3 and maximum 15 connections to host localhost port 389, secure connection, false, authentication type 1 [11/Nov/2010:16:25:46][http-9545-Processor24]: increasing minimum connections by 3 [11/Nov/2010:16:25:46][http-9545-Processor24]: new total available connections 3 [11/Nov/2010:16:25:46][http-9545-Processor24]: new number of connections 3 [11/Nov/2010:16:25:46][http-9545-Processor24]: getConn: mNumConns now 2 [11/Nov/2010:16:25:46][http-9545-Processor24]: Releasing ldap connection [11/Nov/2010:16:25:46][http-9545-Processor24]: returnConn: mNumConns now 3 [11/Nov/2010:16:25:46][http-9545-Processor24]: CMSServlet: curDate=Thu Nov 11 16:25:46 CET 2010 id=caGetDomainXML time=546 [11/Nov/2010:16:25:50][http-9544-Processor21]: CMSServlet:service() uri = /ca/admin/ca/registerUser [11/Nov/2010:16:25:50][http-9544-Processor21]: CMSServlet::service() param name='certificate' value='' [11/Nov/2010:16:25:50][http-9544-Processor21]: CMSServlet::service() param name='name' value='Token Processing Subsystem' [11/Nov/2010:16:25:50][http-9544-Processor21]: CMSServlet::service() param name='auth_hostname' value='pki-server1' [11/Nov/2010:16:25:50][http-9544-Processor21]: CMSServlet::service() param name='uid' value='TPS-pki-server1-7889' [11/Nov/2010:16:25:50][http-9544-Processor21]: CMSServlet::service() param name='auth_port' value='9544' [11/Nov/2010:16:25:50][http-9544-Processor21]: CMSServlet::service() param name='xmlOutput' value='true' [11/Nov/2010:16:25:50][http-9544-Processor21]: CMSServlet::service() param name='sessionID' value='326321180524051384' [11/Nov/2010:16:25:50][http-9544-Processor21]: CMSServlet: caRegisterUser start to service. [11/Nov/2010:16:25:50][http-9544-Processor21]: UpdateUpdater: processing... [11/Nov/2010:16:25:50][http-9544-Processor21]: IP: 192.168.253.35 [11/Nov/2010:16:25:50][http-9544-Processor21]: AuthMgrName: TokenAuth [11/Nov/2010:16:25:50][http-9544-Processor21]: CMSServlet: no client certificate found [11/Nov/2010:16:25:50][http-9544-Processor21]: TokenAuthentication: start [11/Nov/2010:16:25:50][http-9544-Processor21]: TokenAuthentication: content=sessionID=326321180524051384&hostname=192.168.253.35 [11/Nov/2010:16:25:50][http-9544-Processor24]: CMSServlet:service() uri = /ca/ee/ca/tokenAuthenticate [11/Nov/2010:16:25:50][http-9544-Processor24]: CMSServlet::service() param name='hostname' value='192.168.253.35' [11/Nov/2010:16:25:50][http-9544-Processor24]: CMSServlet::service() param name='sessionID' value='326321180524051384' [11/Nov/2010:16:25:50][http-9544-Processor24]: CMSServlet: caTokenAuthenticate start to service. [11/Nov/2010:16:25:50][http-9544-Processor24]: TokenAuthentication: sessionId=326321180524051384 [11/Nov/2010:16:25:50][http-9544-Processor24]: TokenAuthentication: givenHost=192.168.253.35 [11/Nov/2010:16:25:50][http-9544-Processor24]: TokenAuthentication: checking session in the session table [11/Nov/2010:16:25:50][http-9544-Processor24]: CMSEngine: getPasswordStore(): password store initialized before. [11/Nov/2010:16:25:50][http-9544-Processor24]: CMSEngine: getPasswordStore(): password store initialized. [11/Nov/2010:16:25:51][http-9544-Processor24]: TokenAuthentication: found session [11/Nov/2010:16:25:51][http-9544-Processor24]: CMSEngine: getPasswordStore(): password store initialized before. [11/Nov/2010:16:25:51][http-9544-Processor24]: CMSEngine: getPasswordStore(): password store initialized. [11/Nov/2010:16:25:51][http-9544-Processor24]: TokenAuthentication: hostname and givenHost matched [11/Nov/2010:16:25:51][http-9544-Processor24]: CMSEngine: getPasswordStore(): password store initialized before. [11/Nov/2010:16:25:51][http-9544-Processor24]: CMSEngine: getPasswordStore(): password store initialized. [11/Nov/2010:16:25:51][http-9544-Processor24]: CMSEngine: getPasswordStore(): password store initialized before. [11/Nov/2010:16:25:51][http-9544-Processor24]: CMSEngine: getPasswordStore(): password store initialized. [11/Nov/2010:16:25:52][http-9544-Processor24]: TokenAuthenticate successfully authenticate [11/Nov/2010:16:25:52][http-9544-Processor24]: CMSServlet: curDate=Thu Nov 11 16:25:52 CET 2010 id=caTokenAuthenticate time=1292 [11/Nov/2010:16:25:52][http-9544-Processor21]: TokenAuthentication: status=0 [11/Nov/2010:16:25:52][http-9544-Processor21]: SessionContext.USER_ID admin SessionContext.GROUP_ID Enterprise TPS Administrators [11/Nov/2010:16:25:52][http-9544-Processor21]: TokenAuthentication: authenticated uid=admin, gid=Enterprise TPS Administrators [11/Nov/2010:16:25:52][http-9544-Processor21]: CMSServlet: userid=null [11/Nov/2010:16:25:52][http-9544-Processor21]: CMSServlet: in auditSubjectID [11/Nov/2010:16:25:52][http-9544-Processor21]: CMSServlet: auditSubjectID auditContext {locale=de_DE, groupid=Enterprise TPS Administrators, userid=admin, ipAddress=192.168.253.35, authManagerId=TokenAuth} [11/Nov/2010:16:25:52][http-9544-Processor21]: CMSServlet auditSubjectID: subjectID: admin [11/Nov/2010:16:25:52][http-9544-Processor21]: SignedAuditEventFactory: create() message=[AuditEvent=AUTH_SUCCESS][SubjectID=admin][Outcome=Success][AuthMgr=TokenAuth] authentication success [11/Nov/2010:16:25:52][http-9544-Processor21]: RegisterUser authentication successful. [11/Nov/2010:16:25:52][http-9544-Processor21]: CMSServlet: in auditSubjectID [11/Nov/2010:16:25:52][http-9544-Processor21]: CMSServlet: auditSubjectID auditContext {locale=de_DE, groupid=Enterprise TPS Administrators, userid=admin, ipAddress=192.168.253.35, authManagerId=TokenAuth} [11/Nov/2010:16:25:52][http-9544-Processor21]: CMSServlet auditSubjectID: subjectID: admin [11/Nov/2010:16:25:52][http-9544-Processor21]: CMSServlet: in auditGroupID [11/Nov/2010:16:25:52][http-9544-Processor21]: CMSServlet: auditGroupID auditContext {locale=de_DE, groupid=Enterprise TPS Administrators, userid=admin, ipAddress=192.168.253.35, authManagerId=TokenAuth} [11/Nov/2010:16:25:52][http-9544-Processor21]: CMSServlet auditGroupID: groupID: Enterprise TPS Administrators [11/Nov/2010:16:25:52][http-9544-Processor21]: checkACLS(): ACLEntry expressions= group="Enterprise CA Administrators" || group="Enterprise KRA Administrators" || group="Enterprise RA Administrators" || group="Enterprise OCSP Administrators" || group="Enterprise TKS Administrators" || group="Enterprise TPS Administrators" [11/Nov/2010:16:25:52][http-9544-Processor21]: evaluating expressions: group="Enterprise CA Administrators" || group="Enterprise KRA Administrators" || group="Enterprise RA Administrators" || group="Enterprise OCSP Administrators" || group="Enterprise TKS Administrators" || group="Enterprise TPS Administrators" [11/Nov/2010:16:25:52][http-9544-Processor21]: GroupAccessEvaluator: evaluate: uid=admin value="Enterprise CA Administrators" [11/Nov/2010:16:25:52][http-9544-Processor21]: GroupAccessEvaluator: evaluate: authToken gid=Enterprise TPS Administrators [11/Nov/2010:16:25:52][http-9544-Processor21]: evaluated expression: group="Enterprise CA Administrators" to be false [11/Nov/2010:16:25:52][http-9544-Processor21]: GroupAccessEvaluator: evaluate: uid=admin value="Enterprise KRA Administrators" [11/Nov/2010:16:25:52][http-9544-Processor21]: GroupAccessEvaluator: evaluate: authToken gid=Enterprise TPS Administrators [11/Nov/2010:16:25:52][http-9544-Processor21]: evaluated expression: group="Enterprise KRA Administrators" to be false [11/Nov/2010:16:25:52][http-9544-Processor21]: GroupAccessEvaluator: evaluate: uid=admin value="Enterprise RA Administrators" [11/Nov/2010:16:25:52][http-9544-Processor21]: GroupAccessEvaluator: evaluate: authToken gid=Enterprise TPS Administrators [11/Nov/2010:16:25:52][http-9544-Processor21]: evaluated expression: group="Enterprise RA Administrators" to be false [11/Nov/2010:16:25:52][http-9544-Processor21]: GroupAccessEvaluator: evaluate: uid=admin value="Enterprise OCSP Administrators" [11/Nov/2010:16:25:52][http-9544-Processor21]: GroupAccessEvaluator: evaluate: authToken gid=Enterprise TPS Administrators [11/Nov/2010:16:25:52][http-9544-Processor21]: evaluated expression: group="Enterprise OCSP Administrators" to be false [11/Nov/2010:16:25:52][http-9544-Processor21]: GroupAccessEvaluator: evaluate: uid=admin value="Enterprise TKS Administrators" [11/Nov/2010:16:25:52][http-9544-Processor21]: GroupAccessEvaluator: evaluate: authToken gid=Enterprise TPS Administrators [11/Nov/2010:16:25:52][http-9544-Processor21]: evaluated expression: group="Enterprise TKS Administrators" to be false [11/Nov/2010:16:25:52][http-9544-Processor21]: GroupAccessEvaluator: evaluate: uid=admin value="Enterprise TPS Administrators" [11/Nov/2010:16:25:52][http-9544-Processor21]: GroupAccessEvaluator: evaluate: authToken gid=Enterprise TPS Administrators [11/Nov/2010:16:25:52][http-9544-Processor21]: evaluated expression: group="Enterprise TPS Administrators" to be true [11/Nov/2010:16:25:52][http-9544-Processor21]: DirAclAuthz: authorization passed [11/Nov/2010:16:25:52][http-9544-Processor21]: SignedAuditEventFactory: create() message=[AuditEvent=AUTHZ_SUCCESS][SubjectID=admin][Outcome=Success][aclResource=certServer.ca.registerUser][Op=modify] authorization success [11/Nov/2010:16:25:52][http-9544-Processor21]: getConn: mNumConns now 2 [11/Nov/2010:16:25:52][http-9544-Processor21]: returnConn: mNumConns now 3 [11/Nov/2010:16:25:52][http-9544-Processor21]: SignedAuditEventFactory: create() message=[AuditEvent=ROLE_ASSUME][SubjectID=Enterprise TPS Administrators][Outcome=Success][Role=Certificate Manager Agents, Administrators, Security Domain Administrators, Enterprise CA Administrators, Enterprise KRA Administrators, Enterprise OCSP Administrators, Enterprise TKS Administrators, Enterprise RA Administrators, Enterprise TPS Administrators] assume privileged role [11/Nov/2010:16:25:52][http-9544-Processor21]: RegisterUser authorization successful. [11/Nov/2010:16:25:52][http-9544-Processor21]: RegisterUser got uid=TPS-pki-server1-7889 [11/Nov/2010:16:25:52][http-9544-Processor21]: RegisterUser got name=Token Processing Subsystem [11/Nov/2010:16:25:52][http-9544-Processor21]: RegisterUser got certsString= [11/Nov/2010:16:25:52][http-9544-Processor21]: RegisterUser: exception thrown: java.lang.NullPointerException [11/Nov/2010:16:25:52][http-9544-Processor21]: RegisterUser NOT found user by cert [11/Nov/2010:16:25:52][http-9544-Processor21]: getConn: mNumConns now 2 [11/Nov/2010:16:25:52][http-9544-Processor21]: returnConn: mNumConns now 3 [11/Nov/2010:16:25:52][http-9544-Processor21]: RegisterUser found user by uid TPS-pki-server1-7889 [11/Nov/2010:16:25:52][http-9544-Processor21]: RegisterUser error java.lang.NullPointerException [11/Nov/2010:16:25:52][http-9544-Processor21]: CMSServlet: curDate=Thu Nov 11 16:25:52 CET 2010 id=caRegisterUser time=1685 pki-tps/debug: Thu Nov 11 16:25:48 CET 2010 - DonePanel: display Thu Nov 11 16:25:48 CET 2010 - DonePanel: register_tps at https://pki-server1:9544 Thu Nov 11 16:25:48 CET 2010 - DonePanel: subsystem CA uri=/ca/admin/ca/registerUser Thu Nov 11 16:25:48 CET 2010 - DonePanel: Connecting to Security Domain Thu Nov 11 16:25:48 CET 2010 - DonePanel: Security Domain Info https://pki-server1:9544 Thu Nov 11 16:25:49 CET 2010 - ReqCertInfo: update got token name = NSS Certificate DB Thu Nov 11 16:25:50 CET 2010 - DonePanel: Connecting Thu Nov 11 16:25:52 CET 2010 - req = HTTP/1.1 200 OK Server: Apache-Coyote/1.1 Content-Type: application/xml Content-Length: 126 Date: Thu, 11 Nov 2010 15:25:52 GMT Connection: close <?xml version="1.0" encoding="UTF-8"?><XMLResponse><Status>1</Status><Error>Error: Certificate malformed</Error></XMLResponse> Subject: CN=pki-server1,OU=pki-subca,O=ST Test SubCA 1 Domain Issuer : CN=Certificate Authority,OU=pki-subca,O=ST Test SubCA 1 Domain bulk cipher RC4, 128 secret key bits, 128 key bits, status: 1 Thu Nov 11 16:25:53 CET 2010 - DonePanel: result <XMLResponse><Status>1</Status><Error>Error: Certificate malformed</Error></XMLResponse> Thu Nov 11 16:25:53 CET 2010 - DonePanel: register_tps at https://pki-server1:13443 Thu Nov 11 16:25:53 CET 2010 - DonePanel: subsystem TKS uri=/tks/admin/tks/registerUser Thu Nov 11 16:25:54 CET 2010 - ReqCertInfo: update got token name = NSS Certificate DB Thu Nov 11 16:25:54 CET 2010 - DonePanel: Connecting Thu Nov 11 16:25:55 CET 2010 - req = Thu Nov 11 16:25:55 CET 2010 - DonePanel: result Thu Nov 11 16:25:55 CET 2010 - DonePanel: KRA available Thu Nov 11 16:25:55 CET 2010 - DonePanel: register_tps at https://pki-server1:10443 Thu Nov 11 16:25:55 CET 2010 - DonePanel: subsystem KRA uri=/kra/admin/kra/registerUser Thu Nov 11 16:25:56 CET 2010 - DonePanel: Connecting to Security Domain Thu Nov 11 16:25:56 CET 2010 - DonePanel: Security Domain Info https://pki-server1:10443 Thu Nov 11 16:25:56 CET 2010 - ReqCertInfo: update got token name = NSS Certificate DB Thu Nov 11 16:25:56 CET 2010 - DonePanel: Connecting Thu Nov 11 16:25:58 CET 2010 - req = Thu Nov 11 16:25:58 CET 2010 - DonePanel: result Thu Nov 11 16:25:58 CET 2010 - DonePanel: Connecting to KRA pki-tps/error_log: [Thu Nov 11 16:25:41 2010] [info] Initial (No.1) HTTPS request received for child 59 (server 192 .168.253.35:7890) sh: host:https://pki-server1:9543/-: No such file or directory GET /ca/admin/ca/getDomainXML HTTP/1.0 port: 9545 addr='pki-server1' family='2' -- SSL3: Server Certificate Validated. PR_Write wrote 42 bytes from bigBuf bytes: [GET /ca/admin/ca/getDomainXML HTTP/1.0 ] do_writes shutting down send socket do_writes exiting with (failure = 0) connection 1 read 2541 bytes (2541 total). these bytes read: connection 1 read 2541 bytes total. ----------------------------- [Thu Nov 11 16:25:48 2010] -e: Use of uninitialized value $status in string eq at /var/lib/pki-tps/lib/perl/PKI/TPS/DonePanel.pm line 289. certutil: Could not find cert: subsystemCert cert-pki-tps0 : File not found.