Is this logged "error" message a real error?

[talcher]

Hi the EJBCA team,

could you help me read properly the logged message when a CRL is retrieved from a "Service".
Here is my Service configuration:

Those are the logged messages when a new CRL appears in the /tmp/crl directory:

INFO [org.ejbca.core.ejb.services.ServiceSessionBean] (EJB default - 1) Timer was triggered. Trying to run service with ID 426930987.
INFO [org.ejbca.core.ejb.services.ServiceSessionBean] (EJB default - 1) Attempting to run service: crl_reader
INFO [org.cesecore.certificates.crl.CrlStoreSessionBean] (EJB default - 1) Error retrieving CRL for issuer 'CN=test' with CRL number 66.
INFO [org.cesecore.audit.impl.log4j.Log4jDevice] (EJB default - 1) timestamp;ACCESS_CONTROL;SUCCESS;ACCESSCONTROL;CORE;ServiceSession;;;;resource0=/ca/1571137120
INFO [org.cesecore.audit.impl.log4j.Log4jDevice] (EJB default - 1) timestamp;CRL_STORED;SUCCESS;CRL;CORE;ServiceSession;1571137120;;;msg=Stored CRL with CRLNumber=66, fingerprint=a02675e91c8e6683900bcf22211fd1a4e5ce4f21, issuerDN 'CN=test'.
INFO [org.cesecore.certificates.crl.CrlStoreSessionBean] (EJB default - 1) Error retrieving CRL for issuer 'CN=test2' with CRL number 53.
INFO [org.cesecore.audit.impl.log4j.Log4jDevice] (EJB default - 1) timestamp;ACCESS_CONTROL;SUCCESS;ACCESSCONTROL;CORE;ServiceSession;;;;resource0=/ca/-558845960
INFO [org.cesecore.audit.impl.log4j.Log4jDevice] (EJB default - 1) timestamp;CRL_STORED;SUCCESS;CRL;CORE;ServiceSession;-558845960;;;msg=Stored CRL with CRLNumber=53, fingerprint=245b1e0eeb98fed3774aabdae284fb8b4a393521, issuerDN 'CN=test2'.
INFO [org.ejbca.core.ejb.services.ServiceSessionBean] (EJB default - 1) Service crl_reader executed with the following result: Success.CertificateCrlReader ran: 2 CRLs were imported.

Why is "Error retrieving CRL" written, while the logging level is INFO and the content of the messages seems successful?

When I import a CRL through the Webadmin > "CA Structure & CRLs " > "Import external CRL" button, the logged messages do not contain "error":

INFO [org.ejbca.core.ejb.crl.ImportCrlSessionBean] (default task-6) CA: CN=test2
INFO [org.cesecore.certificates.crl.CrlStoreSessionBean] (default task-6) Retrieved CRL from issuer 'CN=test2', with CRL number 53.
INFO [org.ejbca.core.ejb.crl.ImportCrlSessionBean] (default task-6) Found 0 new entires in full CRL number 54 issued by 'CN=test2' compared to previous.
INFO [org.cesecore.audit.impl.log4j.Log4jDevice] (default task-6) timestamp;ACCESS_CONTROL;SUCCESS;ACCESSCONTROL;CORE;CN=admin;;;;resource0=/ca/-558845960
INFO [org.cesecore.audit.impl.log4j.Log4jDevice] (default task-6) timestamp;CRL_STORED;SUCCESS;CRL;CORE;CN=admin;-558845960;;;msg=Stored CRL with CRLNumber=54, fingerprint=a75b4ae82636cae2e1ad94c47c5fc4df46f4b411, issuerDN 'CN=test2'.

Thank you for your help!

talcher

[primetomas]

This looks normal. It comes from this test:
https://github.com/Keyfactor/ejbca-ce/blob/main/modules/plugins/src/org/ejbca/core/model/services/workers/CertificateCrlReader.java#L373

It simply checks that the CRL doesn't already exist in the database before it tries to store it.

[talcher]

Thank you for your answer, Tomas.

I gave it a try copying in /tmp/crl an old CRL, already in the database. The Error message did not come up. It only said: `Retrieved CRL from issuer 'CN=test2', with CRL number 52.

I was only misled by this Error wording, considering the absence of the CRL in the database more as the expected situation than an error. My bad!

[primetomas]

Yeah, luckily Info really meant info here :-).