Configuration.executorService is not respected by TLValidationJob

[cbxp]

It creates its own ExecutorService and threads, but it should use the one provided by Configuration class.

[rsarendus]

The ExecutorService configurable via Configuration#setThreadExecutor(ExecutorService) is meant for signature validation only.

It wouldn't be advisable to use the same ExecutorService for both signature validation and TSL loading, because TSL loading can be triggered by signature validation (if TSL has expired and needs a refresh), blocking the signature validation process until TSL has been updated. If then the ExecutorService's thread pool has already been saturated, having each of its thread blocked and waiting for TSL to get updated, then this will result in a deadlock.

We are looking into possibilities to make ExecutorService separately configurable for each of these use-cases in the future.

[angryziber]

Please at least provide thread factories for all executors and give the threads proper names, so that it would be clear where the threads come from.

As a side note, calling tsl.refresh() blocks the calling thread, even if the actual refresh happens in another thread.

[rsarendus]

As a side note, calling tsl.refresh() blocks the calling thread, even if the actual refresh happens in another thread.

The blocking happens in the underlying DSS library level, so in order to add a fire-and-forget implementation of tsl.refresh(), the Digidoc4j layer would need to use an additional thread.

Generally, blocking is preferrable for TSL updates, because in case the TSL has expired, a TSL refresh could be triggered by any signature creation or validation event that accesses the TSL. So, the event that triggered the update (as well as any other signature creation or validation events that are running in parallel and use the same TSL) must block until the internal state of TSL has been properly updated and synchronized.

[cbxp]

tsl.refresh() blocks the current thread, but does all the work in a bunch of random threads that it gets from somewhere of it's internal pool. All threads consume resources (especially, for stacks) - and it is not possible for the app developer to control these.

Questions:

• if the refresh() blocks anyway, why does it use so many threads internally?
• Configuration#setThreadExecutor(ExecutorService) is meant for signature validation only - how the developers supposed to know/guess that?
• How to control the other internal thread pools that the library uses? E.g. to limit their number and give them proper names?
• It seems if TSL loading (or something else?) fails, then the library can remain in an invalid state, unable to build containers with signatures anymore - how to understand that this happened and what to do to reset it's state?

E.g. we got that this morning, restart of the server fixed the issue :-(

(Signature ID: id-c30ed397d743c511721777383407ac0d) - OCSP request failed. Please check GitHub Wiki for more information: https://github.com/open-eid/digidoc4j/wiki/Questions-&-Answers#if-ocsp-request-has-failed
at org.digidoc4j.impl.asic.AsicSignatureFinalizer.validateOcspResponse(AsicSignatureFinalizer.java:168)
at org.digidoc4j.impl.asic.AsicSignatureFinalizer.createSignature(AsicSignatureFinalizer.java:111)
at org.digidoc4j.impl.asic.AsicSignatureFinalizer.finalizeSignature(AsicSignatureFinalizer.java:87)
at org.digidoc4j.DataToSign.finalize(DataToSign.java:93)

The logs preceding the OCSP error (note that the signature was provided by the PROD Smart-ID service, so the cert is definitely valid):

Apr 26 09:32:06 82460828 [6729-739] INFO CommonCertificateVerifier - + New CommonCertificateVerifier created.
Apr 26 09:32:06 82460828 [6729-739] INFO Configuration - Source by country <EE> not found, using default TSP source
Apr 26 09:32:06 [Fatal Error] :1:1: Content is not allowed in prolog.
Apr 26 09:32:06 82460832 [6729-739] INFO XAdESLevelBaselineT - ====> Extending: IN MEMORY DOCUMENT
Apr 26 09:32:06 82460834 [6729-739] INFO CommonCertificateVerifier - + New CommonCertificateVerifier created.
Apr 26 09:32:06 82460840 [6729-739] INFO XAdESCertificateSource - +XAdESCertificateSource
Apr 26 09:32:06 82461008 [6729-739] INFO OnlineTSPSource - TSP Status: Operation Okay
Apr 26 09:32:06 82461008 [6729-739] INFO OnlineTSPSource - TSP SID : SN 9341197341178141782522153967405961574, Issuer C=EE,O=AS Sertifitseerimiskeskus,CN=EE Certification Centre Root CA,E=pki@sk.ee
Apr 26 09:32:06 82461015 [6729-739] INFO XAdESCertificateSource - +XAdESCertificateSource
Apr 26 09:32:06 82461024 [6729-739] INFO AIACertificateSource - Retrieving C-27B3CDA7A21ED109CE56A0A0D99512CED563645BD8C0515171957B6C90B0C21A certificate's issuer using AIA.
Apr 26 09:32:07 82461091 [6729-739] WARN CertificateReorderer - Issuer not found for certificate C-187BDA4F75689E5708B0B2288D8EA6E0D6C07EB8E7BD2C92859378349384BDD9
Apr 26 09:32:07 82461092 [6729-739] WARN SignatureValidationContext - External revocation check is skipped for untrusted certificate : C-27B3CDA7A21ED109CE56A0A0D99512CED563645BD8C0515171957B6C90B0C21A
Apr 26 09:32:07 82461092 [6729-739] WARN SignatureValidationContext - No revocation found for the certificate C-27B3CDA7A21ED109CE56A0A0D99512CED563645BD8C0515171957B6C90B0C21A
Apr 26 09:32:07 82461092 [6729-739] INFO AIACertificateSource - Retrieving C-187BDA4F75689E5708B0B2288D8EA6E0D6C07EB8E7BD2C92859378349384BDD9 certificate's issuer using AIA.
Apr 26 09:32:07 82461160 [6729-739] WARN SignatureValidationContext - External revocation check is skipped for untrusted certificate : C-187BDA4F75689E5708B0B2288D8EA6E0D6C07EB8E7BD2C92859378349384BDD9
Apr 26 09:32:07 82461160 [6729-739] WARN SignatureValidationContext - No revocation found for the certificate C-187BDA4F75689E5708B0B2288D8EA6E0D6C07EB8E7BD2C92859378349384BDD9
Apr 26 09:32:07 82461161 [6729-739] WARN SignatureValidationContext - External revocation check is skipped for untrusted certificate : C-E73F1F19A4459A6067A45E84DB585D6C1DF8F12A739D733F5B28996546F1875A
Apr 26 09:32:07 82461161 [6729-739] WARN SignatureValidationContext - No revocation found for the certificate C-E73F1F19A4459A6067A45E84DB585D6C1DF8F12A739D733F5B28996546F1875A
Apr 26 09:32:07 82461161 [6729-739] WARN LogHandler - Revocation data is missing for one or more POE(s). [POE 'C-27B3CDA7A21ED109CE56A0A0D99512CED563645BD8C0515171957B6C90B0C21A' not covered by a valid revocation data (nextUpdate : null)]
Apr 26 09:32:07 82461161 [6729-739] WARN LogHandler - Fresh revocation data is missing for one or more certificate(s). [Revocation data is skipped for untrusted certificate chain for the token : 'C-27B3CDA7A21ED109CE56A0A0D99512CED563645BD8C0515171957B6C90B0C21A', Revocation data is skipped for untrusted certificate chain for the token : 'C-187BDA4F75689E5708B0B2288D8EA6E0D6C07EB8E7BD2C92859378349384BDD9']
Apr 26 09:32:07 82461169 [6729-739] INFO CommonCertificateVerifier - + New CommonCertificateVerifier created.
Apr 26 09:32:07 82461173 [6729-739] INFO CommonCertificateVerifier - + New CommonCertificateVerifier created.
Apr 26 09:32:07 82461202 [6729-739] INFO XAdESCertificateSource - +XAdESCertificateSource
Apr 26 09:32:07 82461248 [6729-739] ERROR AsicSignatureFinalizer - Signature does not contain OCSP response
Apr 26 09:32:07 82461254 [6729-739] ERROR ErrorHandler - Unhandled exception
Apr 26 09:32:07 (Signature ID: id-c30ed397d743c511721777383407ac0d) - OCSP request failed. Please check GitHub Wiki for more information: https://github.com/open-eid/digidoc4j/wiki/Questions-&-Answers#if-ocsp-request-has-failed
Apr 26 09:32:07 	at org.digidoc4j.impl.asic.AsicSignatureFinalizer.validateOcspResponse(AsicSignatureFinalizer.java:168)
Apr 26 09:32:07 	at org.digidoc4j.impl.asic.AsicSignatureFinalizer.createSignature(AsicSignatureFinalizer.java:111)
Apr 26 09:32:07 	at org.digidoc4j.impl.asic.AsicSignatureFinalizer.finalizeSignature(AsicSignatureFinalizer.java:87)
Apr 26 09:32:07 	at org.digidoc4j.DataToSign.finalize(DataToSign.java:93)

The main difference with working flow after the restart is this line:

WARN SignatureValidationContext - External revocation check is skipped for untrusted certificate : C-27B3CDA7A21ED109CE56A0A0D99512CED563645BD8C0515171957B6C90B0C21A

Which probably means that SK-issued certificate is "untrusted"

Even before that we found the following in the logs:

INFO RetryExec - I/O exception (java.net.SocketException) caught when processing request to {s}->https://ec.europa.eu:443: Network unreachable

Update: we submitted a separate CRITICAL issue about the TSL loading failure: #109