EJBCA CMP TEST Using clienttoolbox

merryo
2013-12-31
2014-01-06
  • merryo
    merryo
    2013-12-31

    Hi ALL, I am trying to run clienttoolbox tool to test cmp on my ejbca installation. I am using ejbca community 4.0.16 version on ubuntu 12.

    The steps I performed were:
    Step 1: Build clienttoolbox using ant
    Step 2: using ejbca.sh file to execute CMPTEST with two parameters i.e. hostname as 127.0.0.1 and mycacert.
    (./ejbca
    .sh CMPTEST 127.0.0.1 myCAcert)

    In addtion i also did few changes in cmp.properties file as mentioned in command help and got following error.

    Fri Dec 27 17:47:54 TKT 2013 : Not possible to get algorithm.
    Fri Dec 27 17:47:54 TKT 2013 : Test in thread 0 completed but failed when the command 'org.ejbca.ui.cli.CMPTest.StressTest.GetCertificate' was executed. The time it took was 437 ms.
    Fri Dec 27 17:47:54 TKT 2013 : Not possible to get algorithm.
    Fri Dec 27 17:47:54 TKT 2013 : Test in thread 0 completed but failed when the command 'org.ejbca.ui.cli.CMPTest.StressTest.GetCertificate' was executed. The time it took was 49 ms.
    Fri Dec 27 17:47:54 TKT 2013 : Not possible to get algorithm.

    can anyone help me where i am doing wrong.

     
    • merryo
      merryo
      2014-01-02

      When i execute following command:

      ./ejbcaClientToolBox.sh CMPTEST 127.0.0.1 InterSec_TestCA.crt 1 10 CMP_ENTITY 8080 http 'null' cmp_

      i got following error in my server log.


      2014-01-02 18:39:28,235 INFO [org.ejbca.ui.web.protocol.CmpServlet] (http-0.0.0.0-8080-3) CMP message received from: 127.0.0.1.
      2014-01-02 18:39:28,238 DEBUG [org.ejbca.core.protocol.cmp.CmpMessageDispatcherSessionBean] (http-0.0.0.0-8080-3) Received CMP message with pvno=2, sender=4: CN=CMP

      Test User Nr 524694209,O=CMP Test,C=SE,E=email.address@my.com,SN=48162076480-45267, recipient=4: CN=Test CA,OU=IT Division Test,O=Test Organ,C=LL
      2014-01-02 18:39:28,238 DEBUG [org.ejbca.core.protocol.cmp.CmpMessageDispatcherSessionBean] (http-0.0.0.0-8080-3) Body is of type: 0
      2014-01-02 18:39:28,238 DEBUG [org.ejbca.core.protocol.cmp.CmpMessageDispatcherSessionBean] (http-0.0.0.0-8080-3) PKIMessage: ( header: PKIHeader: ( pvno: 2, sender:

      4: CN=CMP Test User Nr 524694209,O=CMP Test,C=SE,E=email.address@my.com,SN=48162076480-45267, recipient: 4: CN=Test CA,OU=IT Division Test,O=Test Organ,C=LL,

      messageTime: org.bouncycastle.asn1.DERGeneralizedTime@5b5bfd28, protectionAlg: org.bouncycastle.asn1.x509.AlgorithmIdentifier@54721002, senderKID:

      434d505f454e54495459, transactionID: #ae416fec12639c60f7b5e6c28eda711c, senderNonce: #9105efda25e9832d9f9273a0587f2839, , body: PKIBody: (CertReqMessages:

      (CertReqMsg: (certReq = CertRequest: (certReqId = 4, certTemplate: com.novosec.pkix.asn1.crmf.CertTemplate (issuer: CN=Test CA,OU=IT Division Test,O=Test Organ,C=LL,

      validity: com.novosec.pkix.asn1.crmf.OptionalValidity (notBefore: 20140101133927GMT+00:00, notAfter: 20140112133927GMT+00:00, hashCode: 735771fa), subject: CN=CMP Test

      User Nr 524694209,O=CMP Test,C=SE,E=email.address@my.com,SN=48162076480-45267, publicKey: org.bouncycastle.asn1.x509.SubjectPublicKeyInfo@46be4135, extensions:

      org.bouncycastle.asn1.x509.X509Extensions@9fed7e41, hashCode: 71fc0f3e), ), pop: ProofOfPossession: (NULL), regInfo :

      (com.novosec.pkix.asn1.crmf.AttributeTypeAndValue@5b4ce9e8)))), protection: #0315000EF47CF7E37416BC2460545579B551E58CA7D186, )
      2014-01-02 18:39:28,238 DEBUG [org.ejbca.core.protocol.cmp.CrmfMessageHandler] (http-0.0.0.0-8080-3) cmp.operationmode=ra
      2014-01-02 18:39:28,238 DEBUG [org.ejbca.core.protocol.cmp.CrmfMessageHandler] (http-0.0.0.0-8080-3) cmp.ra.allowcustomcertserno=false
      2014-01-02 18:39:28,238 DEBUG [org.ejbca.core.protocol.cmp.CrmfMessageHandler] (http-0.0.0.0-8080-3) cmp.ra.passwordgenparams=random
      2014-01-02 18:39:28,238 DEBUG [org.ejbca.core.protocol.cmp.CrmfMessageHandler] (http-0.0.0.0-8080-3) cmp.responseprotection=signature
      2014-01-02 18:39:28,238 DEBUG [org.ejbca.core.protocol.cmp.BaseCmpMessageHandler] (http-0.0.0.0-8080-3) Found a sender keyId: CMP_ENTITY
      2014-01-02 18:39:28,255 DEBUG [org.ejbca.core.ejb.ca.caadmin.CaSessionBean] (http-0.0.0.0-8080-3) CA not found in cache (or cache time expired), we have to get it: -1,

      AdminCA1
      2014-01-02 18:39:28,255 DEBUG [org.ejbca.core.ejb.ca.caadmin.CAData] (http-0.0.0.0-8080-3) Found CA ('AdminCA1', 972526402) in cache.
      2014-01-02 18:39:28,255 DEBUG [org.ejbca.core.model.ca.caadmin.CA] (http-0.0.0.0-8080-3) CA certificate chain is 1 levels deep.
      2014-01-02 18:39:28,256 DEBUG [org.ejbca.core.model.ca.caadmin.CA] (http-0.0.0.0-8080-3) CA-cert subjectDN: CN=AdminCA1,O=EJBCA LiveCD,C=SE
      2014-01-02 18:39:28,256 DEBUG [org.ejbca.core.model.ca.caadmin.CA] (http-0.0.0.0-8080-3) CA-cert issuerDN: CN=AdminCA1,O=EJBCA LiveCD,C=SE
      2014-01-02 18:39:28,257 DEBUG [org.ejbca.core.ejb.authorization.AuthorizationSessionBean] (http-0.0.0.0-8080-3) Checking if update neccessary
      2014-01-02 18:39:28,257 DEBUG [org.ejbca.core.model.authorization.AuthorizationProxy] (http-0.0.0.0-8080-3) Is special user: 2002
      2014-01-02 18:39:28,257 DEBUG [org.ejbca.core.protocol.cmp.BaseCmpMessageHandler] (http-0.0.0.0-8080-3) Using fixed caName when adding users in RA mode: AdminCA1

      (972526402)
      2014-01-02 18:39:28,269 DEBUG [org.ejbca.core.ejb.authorization.AuthorizationSessionBean] (http-0.0.0.0-8080-3) Checking if update neccessary
      2014-01-02 18:39:28,269 DEBUG [org.ejbca.core.model.authorization.AuthorizationProxy] (http-0.0.0.0-8080-3) Is special user: 2002
      2014-01-02 18:39:28,270 DEBUG [org.ejbca.core.ejb.authorization.AuthorizationSessionBean] (http-0.0.0.0-8080-3) Checking if update neccessary
      2014-01-02 18:39:28,270 DEBUG [org.ejbca.core.model.authorization.AuthorizationProxy] (http-0.0.0.0-8080-3) Is special user: 2002
      2014-01-02 18:39:28,270 DEBUG [org.ejbca.core.ejb.ca.caadmin.CaSessionBean] (http-0.0.0.0-8080-3) CA not found in cache (or cache time expired), we have to get it:

      972526402, null
      2014-01-02 18:39:28,271 DEBUG [org.ejbca.core.ejb.ca.caadmin.CAData] (http-0.0.0.0-8080-3) Found CA ('AdminCA1', 972526402) in cache.
      2014-01-02 18:39:28,271 DEBUG [org.ejbca.core.model.ca.caadmin.CA] (http-0.0.0.0-8080-3) CA certificate chain is 1 levels deep.
      2014-01-02 18:39:28,271 DEBUG [org.ejbca.core.model.ca.caadmin.CA] (http-0.0.0.0-8080-3) CA-cert subjectDN: CN=AdminCA1,O=EJBCA LiveCD,C=SE
      2014-01-02 18:39:28,271 DEBUG [org.ejbca.core.model.ca.caadmin.CA] (http-0.0.0.0-8080-3) CA-cert issuerDN: CN=AdminCA1,O=EJBCA LiveCD,C=SE
      2014-01-02 18:39:28,271 DEBUG [org.ejbca.core.protocol.cmp.authentication.VerifyPKIMessage] (http-0.0.0.0-8080-3) Trying to verify the message authentication by using:

      HMAC
      2014-01-02 18:39:28,271 DEBUG [org.ejbca.core.protocol.cmp.authentication.VerifyPKIMessage] (http-0.0.0.0-8080-3) Authentication module parameter: password
      2014-01-02 18:39:28,271 DEBUG [org.ejbca.core.protocol.cmp.CmpPbeVerifyer] (http-0.0.0.0-8080-3) Protection type is: 1.2.840.113533.7.66.13
      2014-01-02 18:39:28,271 DEBUG [org.ejbca.core.protocol.cmp.CmpPbeVerifyer] (http-0.0.0.0-8080-3) Iteration count is: 567
      2014-01-02 18:39:28,271 DEBUG [org.ejbca.core.protocol.cmp.CmpPbeVerifyer] (http-0.0.0.0-8080-3) Owf type is: 1.3.14.3.2.26
      2014-01-02 18:39:28,271 DEBUG [org.ejbca.core.protocol.cmp.CmpPbeVerifyer] (http-0.0.0.0-8080-3) Mac type is: 1.2.840.113549.2.7
      2014-01-02 18:39:28,271 DEBUG [org.ejbca.core.protocol.cmp.authentication.HMACAuthenticationModule] (http-0.0.0.0-8080-3) Verifying HMAC in RA mode
      2014-01-02 18:39:28,271 DEBUG [org.ejbca.core.protocol.cmp.authentication.HMACAuthenticationModule] (http-0.0.0.0-8080-3) raAuthSecret is not null
      2014-01-02 18:39:28,272 DEBUG [org.ejbca.core.protocol.cmp.CrmfRequestMessage] (http-0.0.0.0-8080-3) Request X509Name is: CN=CMP Test User Nr 524694209,O=CMP

      Test,C=SE,E=email.address@my.com,SN=48162076480-45267
      2014-01-02 18:39:28,272 DEBUG [org.ejbca.core.protocol.cmp.CrmfMessageHandler] (http-0.0.0.0-8080-3) Creating username from base dn: CN=CMP Test User Nr

      524694209,O=CMP Test,C=SE,E=email.address@my.com,SN=48162076480-45267
      2014-01-02 18:39:28,272 DEBUG [org.ejbca.core.model.ra.UsernameGenerator] (http-0.0.0.0-8080-3) Generated username: cmpCMP Test User Nr 524694209
      2014-01-02 18:39:28,272 DEBUG [org.ejbca.core.protocol.cmp.CrmfMessageHandler] (http-0.0.0.0-8080-3) Setting 12 char random user password.
      2014-01-02 18:39:28,272 DEBUG [org.ejbca.core.protocol.cmp.CrmfRequestMessage] (http-0.0.0.0-8080-3) Request altName is: rfc822name=rfc822Name@my.com,

      upn=fooupn@bar.com
      2014-01-02 18:39:28,272 DEBUG [org.ejbca.core.protocol.cmp.CrmfMessageHandler] (http-0.0.0.0-8080-3) responseProt=signature, pbeDigestAlg=1.3.14.3.2.26,

      pbeMacAlg=1.2.840.113549.2.7, keyId=CMP_ENTITY, raSecret=not null
      2014-01-02 18:39:28,272 DEBUG [org.ejbca.core.protocol.cmp.CrmfMessageHandler] (http-0.0.0.0-8080-3) Creating new request with eeProfileId '1002517071', certProfileId

      '1622813023', caId '972526402'
      2014-01-02 18:39:28,273 DEBUG [org.ejbca.core.ejb.authorization.AuthorizationSessionBean] (http-0.0.0.0-8080-3) Checking if update neccessary
      2014-01-02 18:39:28,273 DEBUG [org.ejbca.core.model.authorization.AuthorizationProxy] (http-0.0.0.0-8080-3) Is special user: 2002
      2014-01-02 18:39:28,273 DEBUG [org.ejbca.core.ejb.authorization.AuthorizationSessionBean] (http-0.0.0.0-8080-3) Checking if update neccessary
      2014-01-02 18:39:28,273 DEBUG [org.ejbca.core.model.authorization.AuthorizationProxy] (http-0.0.0.0-8080-3) Is special user: 2002
      2014-01-02 18:39:28,274 DEBUG [org.ejbca.core.ejb.authorization.AuthorizationSessionBean] (http-0.0.0.0-8080-3) Checking if update neccessary
      2014-01-02 18:39:28,274 DEBUG [org.ejbca.core.model.authorization.AuthorizationProxy] (http-0.0.0.0-8080-3) Is special user: 2002
      2014-01-02 18:39:28,275 DEBUG [org.ejbca.core.ejb.authorization.AuthorizationSessionBean] (http-0.0.0.0-8080-3) Checking if update neccessary
      2014-01-02 18:39:28,275 DEBUG [org.ejbca.core.model.authorization.AuthorizationProxy] (http-0.0.0.0-8080-3) Is special user: 2002
      2014-01-02 18:39:28,275 DEBUG [org.ejbca.core.ejb.ca.caadmin.CaSessionBean] (http-0.0.0.0-8080-3) CA not found in cache (or cache time expired), we have to get it:

      972526402, null
      2014-01-02 18:39:28,276 DEBUG [org.ejbca.core.ejb.ca.caadmin.CAData] (http-0.0.0.0-8080-3) Found CA ('AdminCA1', 972526402) in cache.
      2014-01-02 18:39:28,276 DEBUG [org.ejbca.core.model.ca.caadmin.CA] (http-0.0.0.0-8080-3) CA certificate chain is 1 levels deep.
      2014-01-02 18:39:28,276 DEBUG [org.ejbca.core.model.ca.caadmin.CA] (http-0.0.0.0-8080-3) CA-cert subjectDN: CN=AdminCA1,O=EJBCA LiveCD,C=SE
      2014-01-02 18:39:28,276 DEBUG [org.ejbca.core.model.ca.caadmin.CA] (http-0.0.0.0-8080-3) CA-cert issuerDN: CN=AdminCA1,O=EJBCA LiveCD,C=SE
      2014-01-02 18:39:28,277 DEBUG [org.ejbca.core.ejb.ra.CertificateRequestSessionBean] (http-0.0.0.0-8080-3) New User cmpCMP Test User Nr 524694209, adding userdata. New

      status of user '10'.
      2014-01-02 18:39:28,279 DEBUG [org.ejbca.core.ejb.authorization.AuthorizationSessionBean] (http-0.0.0.0-8080-3) Checking if update neccessary
      2014-01-02 18:39:28,280 DEBUG [org.ejbca.core.model.authorization.AuthorizationProxy] (http-0.0.0.0-8080-3) Is special user: 2002
      2014-01-02 18:39:28,280 DEBUG [org.ejbca.core.ejb.config.GlobalConfigurationSessionBean] (http-0.0.0.0-8080-3) Reading GlobalConfiguration
      2014-01-02 18:39:28,282 DEBUG [org.ejbca.core.ejb.authorization.AuthorizationSessionBean] (http-0.0.0.0-8080-3) Checking if update neccessary
      2014-01-02 18:39:28,282 DEBUG [org.ejbca.core.model.authorization.AuthorizationProxy] (http-0.0.0.0-8080-3) Is special user: 2002
      2014-01-02 18:39:28,282 DEBUG [org.ejbca.core.ejb.authorization.AuthorizationSessionBean] (http-0.0.0.0-8080-3) Checking if update neccessary
      2014-01-02 18:39:28,282 DEBUG [org.ejbca.core.model.authorization.AuthorizationProxy] (http-0.0.0.0-8080-3) Is special user: 2002
      2014-01-02 18:39:28,285 DEBUG [org.ejbca.core.model.ra.raadmin.EndEntityProfile] (http-0.0.0.0-8080-3) passwordStrengthEstimate=72 getMinPwdStrength=0
      2014-01-02 18:39:28,285 DEBUG [org.ejbca.core.model.ra.raadmin.EndEntityProfile] (http-0.0.0.0-8080-3) Adding new field, 101, to NUMBERARRAY.
      2014-01-02 18:39:28,285 DEBUG [org.ejbca.core.model.ra.raadmin.EndEntityProfile] (http-0.0.0.0-8080-3) Adding new field, 102, to NUMBERARRAY.
      2014-01-02 18:39:28,290 ERROR [org.ejbca.core.model.log.Log4jLogDevice] (http-0.0.0.0-8080-3) 2014-01-02 18:39:28+05:00, CAId : 972526402, RA,

      EVENT_ERROR_ADDEDENDENTITY, Administrator : RACMDLINE, User : cmpCMP Test User Nr 524694209, Certificate : No certificate involved, Comment : Userdata did not fullfill

      end entity profile CMP_ENTITY, dn 'E=email.address@my.com,CN=CMP Test User Nr 524694209,SN=48162076480-45267,O=CMP Test,C=SE: Wrong number of DNEMAIL fields in Subject

      DN..
      2014-01-02 18:39:28,298 ERROR [org.ejbca.core.protocol.cmp.CrmfMessageHandler] (http-0.0.0.0-8080-3) Error adding user 'cmpCMP Test User Nr 524694209'.
      org.ejbca.core.model.ra.raadmin.UserDoesntFullfillEndEntityProfile: Wrong number of DNEMAIL fields in Subject DN.
      at org.ejbca.core.model.ra.raadmin.EndEntityProfile.checkIfForIllegalNumberOfFields(EndEntityProfile.java:1816)
      at org.ejbca.core.model.ra.raadmin.EndEntityProfile.doesUserFullfillEndEntityProfileWithoutPassword(EndEntityProfile.java:884)
      at org.ejbca.core.model.ra.raadmin.EndEntityProfile.doesUserFullfillEndEntityProfile(EndEntityProfile.java:850)
      at org.ejbca.core.ejb.ra.UserAdminSessionBean.addUser(UserAdminSessionBean.java:279)
      at org.ejbca.core.ejb.ra.UserAdminSessionBean.addUserFromWS(UserAdminSessionBean.java:217)
      at sun.reflect.GeneratedMethodAccessor459.invoke(Unknown Source)
      at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
      at java.lang.reflect.Method.invoke(Method.java:622)
      at org.jboss.aop.joinpoint.MethodInvocation.invokeTarget(MethodInvocation.java:122)
      at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:111)
      at org.jboss.ejb3.EJBContainerInvocationWrapper.invokeNext(EJBContainerInvocationWrapper.java:69)
      at org.jboss.ejb3.interceptors.aop.InterceptorSequencer.invoke(InterceptorSequencer.java:73)
      at org.jboss.ejb3.interceptors.aop.InterceptorSequencer.aroundInvoke(InterceptorSequencer.java:59)
      at sun.reflect.GeneratedMethodAccessor432.invoke(Unknown Source)
      at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
      at java.lang.reflect.Method.invoke(Method.java:622)
      at org.jboss.aop.advice.PerJoinpointAdvice.invoke(PerJoinpointAdvice.java:174)
      at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102)
      at org.jboss.ejb3.interceptors.aop.InvocationContextInterceptor.fillMethod(InvocationContextInterceptor.java:72)
      at org.jboss.aop.advice.org.jboss.ejb3.interceptors.aop.InvocationContextInterceptor_z_fillMethod_191621102.invoke

      (InvocationContextInterceptor_z_fillMethod_191621102.java)
      at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102)
      at org.jboss.ejb3.interceptors.aop.InvocationContextInterceptor.setup(InvocationContextInterceptor.java:88)
      at org.jboss.aop.advice.org.jboss.ejb3.interceptors.aop.InvocationContextInterceptor_z_setup_191621102.invoke

      (InvocationContextInterceptor_z_setup_191621102.java)
      at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102)
      at org.jboss.ejb3.connectionmanager.CachedConnectionInterceptor.invoke(CachedConnectionInterceptor.java:62)
      at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102)
      at org.jboss.ejb3.entity.TransactionScopedEntityManagerInterceptor.invoke(TransactionScopedEntityManagerInterceptor.java:56)
      at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102)
      at org.jboss.ejb3.AllowedOperationsInterceptor.invoke(AllowedOperationsInterceptor.java:47)
      at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:102)
      at org.jboss.ejb3.tx.NullInterceptor.invoke(NullInterceptor.java:42)

       
  • Here comes the lesson in reading EJBCA error log files :-)

    UserDoesntFullfillEndEntityProfile: Wrong number of DNEMAIL fields in Subject DN.

    This means you have to edit your end entity profile and add some DNEMAIL fields to be allowed in the end entity profile.

    Cheers,
    Tomas


    PrimeKey Solutions offers commercial EJBCA and SignServer support subscriptions and training courses. Please see www.primekey.se or contact info@primekey.se for more information.
    http://www.primekey.se/Services/Support/
    http://www.primekey.se/Services/Training/

     
    • merryo
      merryo
      2014-01-03

      After adding few fields in my entity profile as server log described me now i finally got this error.

      2014-01-03 16:41:17,376 ERROR [org.ejbca.core.model.log.Log4jLogDevice] (http-0.0.0.0-8080-1) 2014-01-03 16:41:17+05:00, CAId : 972526402, RA, EVENT_ERROR_ADDEDENDENTITY, Administrator : RACMDLINE, User : cmpCMP Test User Nr -802171873, Certificate : No certificate involved, Comment : Userdata did not fullfill end entity profile CMP_ENTITY, dn 'E=email.address@my.com,CN=CMP Test User Nr -802171873,SN=97862616094-12988,O=CMP Test,C=SE: Email cannot be used in end entity profile..
      2014-01-03 16:41:17,389 ERROR [org.ejbca.core.protocol.cmp.CrmfMessageHandler] (http-0.0.0.0-8080-1) Error adding user 'cmpCMP Test User Nr -802171873'.
      org.ejbca.core.model.ra.raadmin.UserDoesntFullfillEndEntityProfile: Email cannot be used in end entity profile.

       
      Attachments
  • "UserDoesntFullfillEndEntityProfile: Email cannot be used in end entity profile"

    You have not configured your email fields correctly. You don't even have an email address field as far as I can see?

     
    • merryo
      merryo
      2014-01-06

      I configured the email and set the proper CA in CMP_Entity and the issue got resolved. Thanks