[11/Jul/2012:12:23:18][http-9443-4]: AuthInfoAccess num=1
[11/Jul/2012:12:23:18][http-9443-4]: SubjectAltNameExtDefault: createExtension i=0
[11/Jul/2012:12:23:18][http-9443-4]: gname is empty, not added
[11/Jul/2012:12:23:18][http-9443-4]: count is 0
[11/Jul/2012:12:23:18][http-9443-4]: SubjectAltNameExtDefault: populate sees no extension.  get out
[11/Jul/2012:12:23:18][http-9443-4]: SubjectAltNameExtDefault: createExtension i=0
[11/Jul/2012:12:23:18][http-9443-4]: gname is empty, not added
[11/Jul/2012:12:23:18][http-9443-4]: count is 0
[11/Jul/2012:12:23:18][http-9443-4]: SubjectAltNameExtDefault: populate sees no extension.  get out
[11/Jul/2012:12:23:18][http-9443-4]: CMSServlet: curDate=Wed Jul 11 12:23:18 CEST 2012 id=caProfileReview time=30
[11/Jul/2012:12:23:37][http-9443-4]: CMSServlet:service() uri = /ca/agent/ca/profileProcess
[11/Jul/2012:12:23:37][http-9443-4]: CMSServlet::service() param name='requestNotes' value=''
[11/Jul/2012:12:23:37][http-9443-4]: CMSServlet::service() param name='keyUsageDecipherOnly' value='false'
[11/Jul/2012:12:23:37][http-9443-4]: CMSServlet::service() param name='keyUsageKeyEncipherment' value='true'
[11/Jul/2012:12:23:37][http-9443-4]: CMSServlet::service() param name='keyUsageKeyAgreement' value='false'
[11/Jul/2012:12:23:37][http-9443-4]: CMSServlet::service() param name='keyUsageDataEncipherment' value='false'
[11/Jul/2012:12:23:37][http-9443-4]: CMSServlet::service() param name='subjAltNames' value='null'
[11/Jul/2012:12:23:37][http-9443-4]: CMSServlet::service() param name='keyUsageCritical' value='true'
[11/Jul/2012:12:23:37][http-9443-4]: CMSServlet::service() param name='exKeyUsageOIDs' value='1.3.6.1.5.5.7.3.2,1.3.6.1.5.5.7.3.4'
[11/Jul/2012:12:23:37][http-9443-4]: CMSServlet::service() param name='keyUsageNonRepudiation' value='true'
[11/Jul/2012:12:23:37][http-9443-4]: CMSServlet::service() param name='notBefore' value='2012-07-11 12:22:51'
[11/Jul/2012:12:23:37][http-9443-4]: CMSServlet::service() param name='keyUsageEncipherOnly' value='false'
[11/Jul/2012:12:23:37][http-9443-4]: CMSServlet::service() param name='op' value='approve'
[11/Jul/2012:12:23:37][http-9443-4]: CMSServlet::service() param name='keyUsageDigitalSignature' value='true'
[11/Jul/2012:12:23:37][http-9443-4]: CMSServlet::service() param name='authInfoAccessGeneralNames' value='Record #0
Method:1.3.6.1.5.5.7.48.1
Location Type:URIName
Location:http://morbo.user.lan.at:9180/ca/ocsp
Enable:true

'
[11/Jul/2012:12:23:37][http-9443-4]: CMSServlet::service() param name='authInfoAccessCritical' value='false'
[11/Jul/2012:12:23:37][http-9443-4]: CMSServlet::service() param name='submit' value='submit'
[11/Jul/2012:12:23:37][http-9443-4]: CMSServlet::service() param name='signingAlg' value='SHA256withRSA'
[11/Jul/2012:12:23:37][http-9443-4]: CMSServlet::service() param name='keyUsageKeyCertSign' value='false'
[11/Jul/2012:12:23:37][http-9443-4]: CMSServlet::service() param name='subjAltNameExtCritical' value='false'
[11/Jul/2012:12:23:37][http-9443-4]: CMSServlet::service() param name='exKeyUsageCritical' value='false'
[11/Jul/2012:12:23:37][http-9443-4]: CMSServlet::service() param name='requestId' value='8'
[11/Jul/2012:12:23:37][http-9443-4]: CMSServlet::service() param name='keyUsageCrlSign' value='false'
[11/Jul/2012:12:23:37][http-9443-4]: CMSServlet::service() param name='nonce' value='4579150907973308118'
[11/Jul/2012:12:23:37][http-9443-4]: CMSServlet::service() param name='notAfter' value='2013-01-07 11:22:51'
[11/Jul/2012:12:23:37][http-9443-4]: CMSServlet::service() param name='name' value='UID=test2,E=test2@test.com,CN=test2'
[11/Jul/2012:12:23:37][http-9443-4]: CMSServlet: caProfileProcess start to service.
[11/Jul/2012:12:23:37][http-9443-4]: IP: 10.18.49.69
[11/Jul/2012:12:23:37][http-9443-4]: AuthMgrName: certUserDBAuthMgr
[11/Jul/2012:12:23:37][http-9443-4]: CMSServlet: retrieving SSL certificate
[11/Jul/2012:12:23:37][http-9443-4]: CMSServlet: certUID=CN=Klaus2 CA Administrator of Instance pki-ca,UID=admin,E=klaus.wagner@s-itsolutions.at,O=UserLan Domain
[11/Jul/2012:12:23:37][http-9443-4]: CertUserDBAuth: started
[11/Jul/2012:12:23:37][http-9443-4]: CertUserDBAuth: Retrieving client certificate
[11/Jul/2012:12:23:37][http-9443-4]: CertUserDBAuth: Got client certificate
[11/Jul/2012:12:23:37][http-9443-4]: Authentication: client certificate found
[11/Jul/2012:12:23:37][http-9443-4]: In LdapBoundConnFactory::getConn()
[11/Jul/2012:12:23:37][http-9443-4]: masterConn is connected: true
[11/Jul/2012:12:23:37][http-9443-4]: getConn: conn is connected true
[11/Jul/2012:12:23:37][http-9443-4]: getConn: mNumConns now 2
[11/Jul/2012:12:23:37][http-9443-4]: returnConn: mNumConns now 3
[11/Jul/2012:12:23:37][http-9443-4]: Authentication: mapped certificate to user
[11/Jul/2012:12:23:37][http-9443-4]: authenticated uid=admin,ou=people,dc=morbo.user.lan.at-pki-ca
[11/Jul/2012:12:23:37][http-9443-4]: CMSServlet: userid=admin
[11/Jul/2012:12:23:37][http-9443-4]: CMSServlet: in auditSubjectID
[11/Jul/2012:12:23:37][http-9443-4]: CMSServlet: auditSubjectID auditContext {locale=en_US,EN;Q=0.5, userid=admin, ipAddress=10.18.49.69, authManagerId=certUserDBAuthMgr}
[11/Jul/2012:12:23:37][http-9443-4]: CMSServlet auditSubjectID: subjectID: admin
[11/Jul/2012:12:23:37][http-9443-4]: SignedAuditEventFactory: create() message=[AuditEvent=AUTH_SUCCESS][SubjectID=admin][Outcome=Success][AuthMgr=certUserDBAuthMgr] authentication success

[11/Jul/2012:12:23:37][http-9443-4]: CMSServlet: in auditSubjectID
[11/Jul/2012:12:23:37][http-9443-4]: CMSServlet: auditSubjectID auditContext {locale=en_US,EN;Q=0.5, userid=admin, ipAddress=10.18.49.69, authManagerId=certUserDBAuthMgr}
[11/Jul/2012:12:23:37][http-9443-4]: CMSServlet auditSubjectID: subjectID: admin
[11/Jul/2012:12:23:37][http-9443-4]: CMSServlet: in auditGroupID
[11/Jul/2012:12:23:37][http-9443-4]: CMSServlet: auditGroupID auditContext {locale=en_US,EN;Q=0.5, userid=admin, ipAddress=10.18.49.69, authManagerId=certUserDBAuthMgr}
[11/Jul/2012:12:23:37][http-9443-4]: CMSServlet auditGroupID: groupID: null
[11/Jul/2012:12:23:37][http-9443-4]: checkACLS(): ACLEntry expressions= group="Certificate Manager Agents"
[11/Jul/2012:12:23:37][http-9443-4]: evaluating expressions: group="Certificate Manager Agents"
[11/Jul/2012:12:23:37][http-9443-4]: GroupAccessEvaluator: evaluate: uid=admin value="Certificate Manager Agents"
[11/Jul/2012:12:23:37][http-9443-4]: GroupAccessEvaluator: evaluate: no gid in authToken
[11/Jul/2012:12:23:37][http-9443-4]: In LdapBoundConnFactory::getConn()
[11/Jul/2012:12:23:37][http-9443-4]: masterConn is connected: true
[11/Jul/2012:12:23:37][http-9443-4]: getConn: conn is connected true
[11/Jul/2012:12:23:37][http-9443-4]: getConn: mNumConns now 2
[11/Jul/2012:12:23:37][http-9443-4]: returnConn: mNumConns now 3
[11/Jul/2012:12:23:37][http-9443-4]: UGSubsystem.isMemberOf() using new lookup code
[11/Jul/2012:12:23:37][http-9443-4]: In LdapBoundConnFactory::getConn()
[11/Jul/2012:12:23:37][http-9443-4]: masterConn is connected: true
[11/Jul/2012:12:23:37][http-9443-4]: getConn: conn is connected true
[11/Jul/2012:12:23:37][http-9443-4]: getConn: mNumConns now 2
[11/Jul/2012:12:23:37][http-9443-4]: authorization search base: cn=Certificate Manager Agents,ou=groups,dc=morbo.user.lan.at-pki-ca
[11/Jul/2012:12:23:37][http-9443-4]: authorization search filter: (uniquemember=uid=admin,ou=people,dc=morbo.user.lan.at-pki-ca)
[11/Jul/2012:12:23:37][http-9443-4]: authorization result: true
[11/Jul/2012:12:23:37][http-9443-4]: returnConn: mNumConns now 3
[11/Jul/2012:12:23:37][http-9443-4]: evaluated expression: group="Certificate Manager Agents" to be true
[11/Jul/2012:12:23:37][http-9443-4]: DirAclAuthz: authorization passed
[11/Jul/2012:12:23:37][http-9443-4]: SignedAuditEventFactory: create() message=[AuditEvent=AUTHZ_SUCCESS][SubjectID=admin][Outcome=Success][aclResource=certServer.ca.request.profile][Op=approve] authorization success

[11/Jul/2012:12:23:37][http-9443-4]: In LdapBoundConnFactory::getConn()
[11/Jul/2012:12:23:37][http-9443-4]: masterConn is connected: true
[11/Jul/2012:12:23:37][http-9443-4]: getConn: conn is connected true
[11/Jul/2012:12:23:37][http-9443-4]: getConn: mNumConns now 2
[11/Jul/2012:12:23:37][http-9443-4]: returnConn: mNumConns now 3
[11/Jul/2012:12:23:37][http-9443-4]: SignedAuditEventFactory: create() message=[AuditEvent=ROLE_ASSUME][SubjectID=admin][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/Jul/2012:12:23:37][http-9443-4]: ProfileProcessServlet:  nonceVerified=true
[11/Jul/2012:12:23:37][http-9443-4]: ProfileProcessServlet: start serving
[11/Jul/2012:12:23:37][http-9443-4]: ProfileProcessServlet: SubId=profile
[11/Jul/2012:12:23:37][http-9443-4]: ProfileProcessServlet: requestId=8
[11/Jul/2012:12:23:37][http-9443-4]: In LdapBoundConnFactory::getConn()
[11/Jul/2012:12:23:37][http-9443-4]: masterConn is connected: true
[11/Jul/2012:12:23:37][http-9443-4]: getConn: conn is connected true
[11/Jul/2012:12:23:37][http-9443-4]: getConn: mNumConns now 2
[11/Jul/2012:12:23:37][http-9443-4]: returnConn: mNumConns now 3
[11/Jul/2012:12:23:37][http-9443-4]: ProfileProcessServlet: profileId=caUserCert
[11/Jul/2012:12:23:37][http-9443-4]: SubjectNameDefault: setValue name=UID=test2,E=test2@test.com,CN=test2
[11/Jul/2012:12:23:37][http-9443-4]: parseRecords: Record0
[11/Jul/2012:12:23:37][http-9443-4]: SubjectAltNameExtDefault: createExtension i=0
[11/Jul/2012:12:23:37][http-9443-4]: gname is empty, not added
[11/Jul/2012:12:23:37][http-9443-4]: count is 0
[11/Jul/2012:12:23:37][http-9443-4]: SubjectAltNameExtDefault: populate sees no extension.  get out
[11/Jul/2012:12:23:37][http-9443-4]: SubjectAltNameExtDefault: createExtension i=0
[11/Jul/2012:12:23:37][http-9443-4]: gname is empty, not added
[11/Jul/2012:12:23:37][http-9443-4]: count is 0
[11/Jul/2012:12:23:37][http-9443-4]: SubjectAltNameExtDefault: populate sees no extension.  get out
[11/Jul/2012:12:23:37][http-9443-4]: SubjectNameConstraint: validate start
[11/Jul/2012:12:23:37][http-9443-4]: SubjectNameConstraint: validate start
[11/Jul/2012:12:23:37][http-9443-4]: SubjectNameConstraint: validate cert subject =UID=test2,E=test2@test.com,CN=test2
[11/Jul/2012:12:23:37][http-9443-4]: SubjectNameConstraint: validate() - sn500 dname = UID=test2,E=test2@test.com,CN=test2
[11/Jul/2012:12:23:37][http-9443-4]: SubjectNameConstraint: validate end
[11/Jul/2012:12:23:37][http-9443-4]: RenewGracePeriodConstraint: validate start
[11/Jul/2012:12:23:37][http-9443-4]: RenewGracePeriodConstraint: validate end
[11/Jul/2012:12:23:37][http-9443-4]: ValidityConstraint: validate start
[11/Jul/2012:12:23:37][http-9443-4]: ValidityConstraint: millisDiff=15552000000 notAfter=1357554171000 notBefore=1342002171000
[11/Jul/2012:12:23:37][http-9443-4]: ValidityConstraint: long_days: 180
[11/Jul/2012:12:23:37][http-9443-4]: ValidityConstraint: days: 180
[11/Jul/2012:12:23:37][http-9443-4]: Property policyset.userCertSet.2.constraint.params.notBeforeGracePeriod missing value
[11/Jul/2012:12:23:37][http-9443-4]: ValidityConstraint: validate end
[11/Jul/2012:12:23:37][http-9443-4]: KeyConstraint: validate start
[11/Jul/2012:12:23:37][http-9443-4]: KeyConstraint.validate: RSA key contraints passed.
[11/Jul/2012:12:23:37][http-9443-4]: KeyConstraint: validate end
[11/Jul/2012:12:23:37][http-9443-4]: KeyUsageExtConstraint: validate start
[11/Jul/2012:12:23:37][http-9443-4]: KeyUsageExtConstraint: validate end
[11/Jul/2012:12:23:37][http-9443-4]: SigningAlgConstraint: validate start
[11/Jul/2012:12:23:37][http-9443-4]: SigningAlgConstraint: validate end
[11/Jul/2012:12:23:37][http-9443-4]: CMSServlet: in auditSubjectID
[11/Jul/2012:12:23:37][http-9443-4]: CMSServlet: auditSubjectID auditContext {locale=en_US,EN;Q=0.5, userid=admin, ipAddress=10.18.49.69, authManagerId=certUserDBAuthMgr}
[11/Jul/2012:12:23:37][http-9443-4]: CMSServlet auditSubjectID: subjectID: admin
[11/Jul/2012:12:23:37][http-9443-4]: CAEnrollProfile: execute reqId=8
[11/Jul/2012:12:23:37][http-9443-4]: issueX509Cert
[11/Jul/2012:12:23:37][http-9443-4]: dnUTF8Encoding false
[11/Jul/2012:12:23:37][http-9443-4]: Repository: in getNextSerialNumber. 
[11/Jul/2012:12:23:37][http-9443-4]: Repository: getNextSerialNumber: returning retSerial 8
[11/Jul/2012:12:23:37][http-9443-4]: About to mCA.sign cert.
[11/Jul/2012:12:23:37][http-9443-4]: sign cert get algorithm
[11/Jul/2012:12:23:37][http-9443-4]: sign cert encoding cert
[11/Jul/2012:12:23:37][http-9443-4]: sign cert encoding algorithm
[11/Jul/2012:12:23:37][http-9443-4]: CA cert signing: signing cert
[11/Jul/2012:12:23:37][http-9443-4]: Getting algorithm context for SHA256withRSA RSASignatureWithSHA256Digest
[11/Jul/2012:12:23:37][http-9443-4]: Signing Certificate
[11/Jul/2012:12:23:37][http-9443-4]: storeX509Cert 8
[11/Jul/2012:12:23:37][http-9443-4]: In storeX509Cert
[11/Jul/2012:12:23:37][http-9443-4]: In LdapBoundConnFactory::getConn()
[11/Jul/2012:12:23:37][http-9443-4]: masterConn is connected: true
[11/Jul/2012:12:23:37][http-9443-4]: getConn: conn is connected true
[11/Jul/2012:12:23:37][http-9443-4]: getConn: mNumConns now 2
[11/Jul/2012:12:23:37][http-9443-4]: returnConn: mNumConns now 3
[11/Jul/2012:12:23:37][http-9443-4]: done storeX509Cert
[11/Jul/2012:12:23:37][http-9443-4]: SignedAuditEventFactory: create() message=[AuditEvent=CERT_REQUEST_PROCESSED][SubjectID=admin][Outcome=Success][ReqID=8][InfoName=certificate][InfoValue=MIIDJTCCAg2gAwIBAgIBCDANBgkqhkiG9w0BAQsFADBRMRcwFQYDVQQKEw5Vc2VyTGFuIERvbWFpbjEPMA0GA1UECxMGcGtpLWNhMSUwIwYDVQQDExxLbGF1czIgQ2VydGlmaWNhdGUgQXV0aG9yaXR5MB4XDTEyMDcxMTEwMjI1MVoXDTEzMDEwNzEwMjI1MVowRjEOMAwGA1UEAxMFdGVzdDIxHTAbBgkqhkiG9w0BCQEWDnRlc3QyQHRlc3QuY29tMRUwEwYKCZImiZPyLGQBARMFdGVzdDIwgZ8wDQYJKoZIhvcNAQEBBQADgY0AMIGJAoGBAOQMaY1DRnPY2TjAfEPIi9RKx0H1azbSxEz7OBG6Cv720mZutcll4ZYz5G6nM9Vd1il8k50josP2O70cejCwAP0y6qh+FQQh67/Cd0ww3cqQG0ziWbor6+eJfKOLpPwnZcGseGHLeZlhLbRsKScEulSOaQBbqfbI9TBHTPXAVZSNAgMBAAGjgZYwgZMwHwYDVR0jBBgwFoAUWsVRMLQFtbGyO8PazauI9xXc+14wQQYIKwYBBQUHAQEENTAzMDEGCCsGAQUFBzABhiVodHRwOi8vbW9yYm8udXNlci5sYW4uYXQ6OTE4MC9jYS9vY3NwMA4GA1UdDwEB/wQEAwIF4DAdBgNVHSUEFjAUBggrBgEFBQcDAgYIKwYBBQUHAwQwDQYJKoZIhvcNAQELBQADggEBAErAwGyKZrMvJt7UoHnMll6QIxSfa03lp9BawAXqJqxJf94fsOxz+CjpfXd1D7b2Ea/g/7/8RUf/vyoOqU/t82ouos0+/p77vN0oIq8nVVTIvRtu15RscpP3MIgtE5Juplu50h+i75b9fpWDfpHDZ+M1KWVnGWloMoIIAsumWU0b1/dJ1uQ8tmRjBGiDhyjNEfByNHY7NRrYfYObg/8ptU/e+nlC0ERNpqV+TOcSSe/ftq4sbqmWPqlSeXGxDAPjHIlOJFdhMjgbceTVS9m81K71YqhSVB4UqqaYxj76/ZcBm1nqxgpFISnYCGwI7zsa3ymXQ+iIphiXmQyuVUo/2Io=] certificate request processed

[11/Jul/2012:12:23:37][http-9443-4]: In LdapBoundConnFactory::getConn()
[11/Jul/2012:12:23:37][http-9443-4]: masterConn is connected: true
[11/Jul/2012:12:23:37][http-9443-4]: getConn: conn is connected true
[11/Jul/2012:12:23:37][http-9443-4]: getConn: mNumConns now 2
[11/Jul/2012:12:23:37][http-9443-4]: returnConn: mNumConns now 3
[11/Jul/2012:12:23:37][http-9443-4]: ARequestNotifier  notify mIsPublishingQueueEnabled=false mMaxThreads=3
[11/Jul/2012:12:23:37][Thread-34]: RunListeners:: noQueue  SingleRequest
[11/Jul/2012:12:23:37][Thread-34]: RunListeners: IRequestListener = com.netscape.cms.listeners.CertificateIssuedListener
[11/Jul/2012:12:23:37][Thread-34]: CertificateIssuedListener: accept 8
[11/Jul/2012:12:23:37][Thread-34]: RunListeners: IRequestListener = com.netscape.ca.CRLIssuingPoint$RevocationRequestListener
[11/Jul/2012:12:23:37][Thread-34]: RunListeners: IRequestListener = com.netscape.cmscore.ldap.LdapRequestListener
[11/Jul/2012:12:23:37][Thread-34]: LdapRequestListener handling publishing for enrollment request id 8
[11/Jul/2012:12:23:37][Thread-34]: Checking publishing for request 8
[11/Jul/2012:12:23:37][Thread-34]: In  PublisherProcessor::publishCert
[11/Jul/2012:12:23:37][http-9443-4]: CMSServlet: curDate=Wed Jul 11 12:23:37 CEST 2012 id=caProfileProcess time=42
[11/Jul/2012:12:23:37][Thread-34]: PublisherProcessor: in publishNow()
[11/Jul/2012:12:23:37][Thread-34]: FileBasedPublisher: publish
[11/Jul/2012:12:23:37][Thread-34]: PublisherProcessor: in publishNow()
[11/Jul/2012:12:23:37][Thread-34]: In LdapBoundConnFactory::getConn()
[11/Jul/2012:12:23:37][Thread-34]: masterConn is connected: true
[11/Jul/2012:12:23:37][Thread-34]: getConn: conn is connected true
[11/Jul/2012:12:23:37][Thread-34]: getConn: mNumConns now 2
[11/Jul/2012:12:23:37][Thread-34]: returnConn: mNumConns now 3
[11/Jul/2012:12:23:37][Thread-34]: In LdapBoundConnFactory::getConn()
[11/Jul/2012:12:23:37][Thread-34]: masterConn is connected: true
[11/Jul/2012:12:23:37][Thread-34]: getConn: conn is connected true
[11/Jul/2012:12:23:37][Thread-34]: getConn: mNumConns now 2
[11/Jul/2012:12:23:37][Thread-34]: returnConn: mNumConns now 3
[11/Jul/2012:12:23:37][Thread-34]: acceptX509: Published cert serial no 0x8
[11/Jul/2012:12:23:37][Thread-34]: RunListeners: IRequestListener = com.netscape.cms.listeners.CertificateRevokedListener
[11/Jul/2012:12:23:37][Thread-34]: RunListeners:  noQueue  SingleRequest
[11/Jul/2012:12:23:46][Timer-0]: In LdapBoundConnFactory::getConn()
[11/Jul/2012:12:23:46][Timer-0]: masterConn is connected: true
[11/Jul/2012:12:23:46][Timer-0]: getConn: conn is connected true
[11/Jul/2012:12:23:46][Timer-0]: getConn: mNumConns now 2
[11/Jul/2012:12:23:46][Timer-0]: SecurityDomainSessionTable: getSessionIds():  no sessions have been created
[11/Jul/2012:12:23:46][Timer-0]: returnConn: mNumConns now 3