Datahub 6.6 - PKIX path validation failed: java.security.cert.CertPathValidatorException: validity check failed.

[bharathyelugula]

Hello Everyone, I am facing an issue with datahub 6.6. Is this familier to you ?

Datahub is not recognizing Hybris system(which is running on https://localhost:9002/datahubadapter)

I am using Datahub 6.6 and Hybris commerce suite version 5.7 (is it possible to connet 5.7 to 6.6 datahub ?) all my custom enhancements are build across datahub 6.6.

I have tried both http and https (with required certs from the datahub war) tomcats but the issue is same, it is not recognizing the target system due to PKIX path validation... Please find the below log...

---

2018-08-29 01:20:00,280 [INFO] [c.h.d.f.r.r.TxtFileImportResource] Received POST request /data-feeds-elx/{feedName}/items/{type} with args [DEFAULT_FEED,RawProduct,E:\datahub\REX_MASTER_PARTS_10.txt] 2018-08-29 01:20:00,290 [INFO] [c.h.d.f.r.r.TxtFileImportResource] dummy Received request to import file data for type RawProduct into data feed DEFAULT_FEED 2018-08-29 01:20:00,290 [INFO] [c.h.d.f.f.i.DefaultTxtImportFacade] Develoment under process - Bharath 2018-08-29 01:20:00,309 [INFO] [c.h.d.f.f.i.DefaultTxtImportFacade] custom Importing 3 raw fragments of type RawProduct into data feed DEFAULT_FEED 2018-08-29 01:20:00,339 [INFO] [c.h.d.s.f.DataFeedActor] Loading 3 items to 'DEFAULT_FEED' data feed 2018-08-29 01:20:00,340 [DEBUG] [c.h.d.p.i.GlobalPoolStrategy] Searching for global pool for feed 0 - DEFAULT_FEED 2018-08-29 01:20:00,385 [DEBUG] [c.h.d.p.i.DefaultProcessMonitor] Registered DataLoad #1: 1 processes running 2018-08-29 01:20:00,387 [INFO] [c.h.d.s.i.AsynchronousEventPublicationService] Firing data hub event : DataLoadingStartedEvent{actionId=1, feedId=0, poolId=0, itemCount=3} 2018-08-29 01:20:00,435 [DEBUG] [c.h.d.p.i.DefaultProcessMonitor] Unregistered DataLoad #1, 0 processes running 2018-08-29 01:20:00,437 [INFO] [c.h.d.f.r.r.TxtFileImportResource] result iscom.hybris.datahub.dto.item.ResultData@4132207d 2018-08-29 01:20:00,438 [INFO] [c.h.d.s.i.AsynchronousEventPublicationService] Firing data hub event : DataLoadingCompletedEvent{actionId=1, feedId=0, poolId=0, itemCount=3, status='COMPLETE'} 2018-08-29 01:20:00,717 [INFO] [c.h.d.s.e.AutoComposeEventListener] Pool GLOBAL(0) registered for composition 2018-08-29 01:20:00,717 [DEBUG] [c.h.d.s.c.i.CallbackTriggerTimerImpl] Callback registered for trigger callback: com.hybris.datahub.sapcoreconfiguration.event.AutoComposeEventListener@293cd25d 2018-08-29 01:20:00,718 [DEBUG] [c.h.d.s.c.i.CallbackTriggerTimerImpl] Current callbacks: [com.hybris.datahub.sapcoreconfiguration.event.AutoComposeEventListener@293cd25d] 2018-08-29 01:20:00,719 [DEBUG] [c.h.d.s.c.i.CallbackTriggerTimerImpl] Start trigger thread 2018-08-29 01:20:00,722 [DEBUG] [c.h.d.s.c.i.CallbackTriggerTimerImpl] Trigger Thread created with sleep time: 10000 2018-08-29 01:20:00,723 [DEBUG] [c.h.d.s.c.i.CallbackTriggerTimerImpl] Trigger Thread starts notifying callbacks [com.hybris.datahub.sapcoreconfiguration.event.AutoComposeEventListener@293cd25d] in 10000 msec 2018-08-29 01:20:10,724 [DEBUG] [c.h.d.s.c.i.CallbackTriggerTimerImpl] Trigger Thread starts notifying callbacks 2018-08-29 01:20:10,725 [DEBUG] [c.h.d.s.c.i.CallbackTriggerTimerImpl] Call trigger for 1 callbacks 2018-08-29 01:20:10,728 [DEBUG] [c.h.d.s.c.i.CallbackTriggerTimerImpl] Call trigger for callback: com.hybris.datahub.sapcoreconfiguration.event.AutoComposeEventListener@293cd25d 2018-08-29 01:20:10,731 [INFO] [c.h.d.s.e.AutoComposeEventListener] Initiate composition for pool: GLOBAL 2018-08-29 01:20:10,733 [DEBUG] [c.h.d.s.c.i.CallbackTriggerTimerImpl] Callback unregistered for trigger callback: com.hybris.datahub.sapcoreconfiguration.event.AutoComposeEventListener@293cd25d 2018-08-29 01:20:10,733 [DEBUG] [c.h.d.s.c.i.CallbackTriggerTimerImpl] Current callbacks: [] 2018-08-29 01:20:10,733 [INFO] [c.h.d.s.i.AsynchronousEventPublicationService] Firing data hub event : InitiateCompositionEvent{poolId=0} 2018-08-29 01:20:10,738 [DEBUG] [c.h.d.s.c.i.CallbackTriggerTimerImpl] Disable trigger callback: com.hybris.datahub.sapcoreconfiguration.event.AutoComposeEventListener@293cd25d 2018-08-29 01:20:10,741 [DEBUG] [c.h.d.s.c.i.CallbackTriggerTimerImpl] Disable Trigger Thread 2018-08-29 01:20:10,742 [DEBUG] [c.h.d.s.c.i.CallbackTriggerTimerImpl] Trigger Thread disabled and finished 2018-08-29 01:20:10,811 [INFO] [c.h.d.s.i.AsynchronousEventPublicationService] Firing data hub event : PerformCompositionEvent{actionId=1, poolId=0} 2018-08-29 01:20:10,861 [DEBUG] [c.h.d.p.i.DefaultProcessMonitor] Registered Composition #1: 1 processes running 2018-08-29 01:20:10,863 [INFO] [c.h.d.s.i.AsynchronousEventPublicationService] Firing data hub event : CompositionStartedEvent{actionId=1, poolId=0} 2018-08-29 01:20:11,010 [INFO] [c.h.d.s.i.DefaultRawTypeComposerService] 0 items found for composition of type RawHybrisDiscount 2018-08-29 01:20:11,046 [INFO] [c.h.d.s.i.DefaultRawTypeComposerService] 3 items found for composition of type RawProduct 2018-08-29 01:20:11,415 [INFO] [c.h.d.s.i.DefaultRawTypeComposerService] 0 items found for composition of type RawProduct 2018-08-29 01:20:11,417 [INFO] [c.h.d.s.i.DefaultRawTypeComposerService] 0 items found for composition of type RawHybrisDeliveryModeMapping 2018-08-29 01:20:11,419 [INFO] [c.h.d.s.i.DefaultRawTypeComposerService] 0 items found for composition of type RawSAPBaseStoreConfigurationMapping 2018-08-29 01:20:11,421 [INFO] [c.h.d.s.i.DefaultRawTypeComposerService] 0 items found for composition of type RawPricingSalesAreaMapping 2018-08-29 01:20:11,422 [INFO] [c.h.d.s.i.DefaultRawTypeComposerService] 0 items found for composition of type RawSAPLogicalSystem 2018-08-29 01:20:11,424 [INFO] [c.h.d.s.i.DefaultRawTypeComposerService] 0 items found for composition of type RawSAPBaseStoreConfiguration 2018-08-29 01:20:11,426 [INFO] [c.h.d.s.i.DefaultRawTypeComposerService] 0 items found for composition of type RawBonusBuySite 2018-08-29 01:20:11,428 [INFO] [c.h.d.s.i.DefaultRawTypeComposerService] 0 items found for composition of type RawSAPHTTPDestination 2018-08-29 01:20:11,433 [INFO] [c.h.d.s.i.DefaultRawTypeComposerService] 0 items found for composition of type RawHybrisUnit 2018-08-29 01:20:11,435 [INFO] [c.h.d.s.i.DefaultRawTypeComposerService] 0 items found for composition of type RawSAPGlobalConfiguration 2018-08-29 01:20:11,438 [INFO] [c.h.d.s.i.DefaultRawTypeComposerService] 0 items found for composition of type RawHybrisProductSalesAreaToCatalogMapping 2018-08-29 01:20:11,439 [DEBUG] [c.h.d.s.c.i.AkkaEnabledCompositionActionHandler] Entering handleCompositionSuccess 2018-08-29 01:20:11,457 [DEBUG] [c.h.d.p.i.DefaultProcessMonitor] Unregistered Composition #1, 0 processes running 2018-08-29 01:20:11,458 [INFO] [c.h.d.s.i.AsynchronousEventPublicationService] Firing data hub event : CompositionCompletedEvent{actionId=1, poolId=0, status=SUCCESS, compositionResult=CompositionResult{status=SUCCESS, canonicalItemCount=3, processedRawItemCount=3, ignoredRawItemCount=0, successCount=3, archivedCount=0, deleteArchivedCount=0, errorCount=0, deletedCount=0, items=[]}} 2018-08-29 01:20:11,463 [DEBUG] [c.h.d.c.i.DefaultAutoCompositionDecisionStrategy] Querying for Raw Items in pool GLOBAL remaining in PENDING state. 2018-08-29 01:20:11,530 [DEBUG] [c.h.d.c.e.AutoPublishCompositionEventListener] Attempting to auto publish for CompositionCompletedEvent{actionId=1, poolId=0, status=SUCCESS, compositionResult=CompositionResult{status=SUCCESS, canonicalItemCount=3, processedRawItemCount=3, ignoredRawItemCount=0, successCount=3, archivedCount=0, deleteArchivedCount=0, errorCount=0, deletedCount=0, items=[]}}. 2018-08-29 01:20:11,532 [DEBUG] [c.h.d.c.j.AbstractJdbcDataHubEventListener] Handling CompositionCompletedEvent{actionId=1, poolId=0, status=SUCCESS, compositionResult=CompositionResult{status=SUCCESS, canonicalItemCount=3, processedRawItemCount=3, ignoredRawItemCount=0, successCount=3, archivedCount=0, deleteArchivedCount=0, errorCount=0, deletedCount=0, items=[]}} 2018-08-29 01:20:11,555 [INFO] [c.h.d.c.j.AbstractJdbcCleanupService] RawItem cleanup: [DELETE FROM RawItem WHERE id IN (:ids)]: 3 records were deleted 2018-08-29 01:20:11,557 [INFO] [c.h.d.s.e.AutoPublishEventListener] Pool GLOBAL(0) registered for publishing to target systems: [HybrisCore] 2018-08-29 01:20:11,558 [DEBUG] [c.h.d.s.c.i.CallbackTriggerTimerImpl] Callback registered for trigger callback: com.hybris.datahub.sapcoreconfiguration.event.AutoPublishEventListener@7e7b50af 2018-08-29 01:20:11,559 [DEBUG] [c.h.d.s.c.i.CallbackTriggerTimerImpl] Current callbacks: [com.hybris.datahub.sapcoreconfiguration.event.AutoPublishEventListener@7e7b50af] 2018-08-29 01:20:11,559 [DEBUG] [c.h.d.s.c.i.CallbackTriggerTimerImpl] Start trigger thread 2018-08-29 01:20:11,559 [DEBUG] [c.h.d.s.c.i.CallbackTriggerTimerImpl] Trigger Thread created with sleep time: 10000 2018-08-29 01:20:11,560 [DEBUG] [c.h.d.s.c.i.CallbackTriggerTimerImpl] Trigger Thread starts notifying callbacks [com.hybris.datahub.sapcoreconfiguration.event.AutoPublishEventListener@7e7b50af] in 10000 msec 2018-08-29 01:20:21,561 [DEBUG] [c.h.d.s.c.i.CallbackTriggerTimerImpl] Trigger Thread starts notifying callbacks 2018-08-29 01:20:21,562 [DEBUG] [c.h.d.s.c.i.CallbackTriggerTimerImpl] Call trigger for 1 callbacks 2018-08-29 01:20:21,565 [DEBUG] [c.h.d.s.c.i.CallbackTriggerTimerImpl] Call trigger for callback: com.hybris.datahub.sapcoreconfiguration.event.AutoPublishEventListener@7e7b50af 2018-08-29 01:20:21,568 [INFO] [c.h.d.s.e.AutoPublishEventListener] Initiate publication for pool: GLOBAL -> to target systems: [HybrisCore] 2018-08-29 01:20:21,569 [DEBUG] [c.h.d.s.c.i.CallbackTriggerTimerImpl] Callback unregistered for trigger callback: com.hybris.datahub.sapcoreconfiguration.event.AutoPublishEventListener@7e7b50af 2018-08-29 01:20:21,570 [DEBUG] [c.h.d.s.c.i.CallbackTriggerTimerImpl] Current callbacks: [] 2018-08-29 01:20:21,570 [INFO] [c.h.d.s.i.AsynchronousEventPublicationService] Firing data hub event : InitiatePublicationEvent{poolId=0 ,targetSystemNames=[HybrisCore]} 2018-08-29 01:20:21,572 [DEBUG] [c.h.d.s.c.i.CallbackTriggerTimerImpl] Disable trigger callback: com.hybris.datahub.sapcoreconfiguration.event.AutoPublishEventListener@7e7b50af 2018-08-29 01:20:21,578 [DEBUG] [c.h.d.s.c.i.CallbackTriggerTimerImpl] Disable Trigger Thread 2018-08-29 01:20:21,580 [DEBUG] [c.h.d.s.c.i.CallbackTriggerTimerImpl] Trigger Thread disabled and finished 2018-08-29 01:20:21,703 [INFO] [c.h.d.s.i.AsynchronousEventPublicationService] Firing data hub event : PerformPublicationEvent{actionId=1, poolId=0, systemUrl='https://localhost:8443/datahub-webapp/v1', targetPublicationIds=[1]} 2018-08-29 01:20:21,709 [DEBUG] [c.h.d.p.i.DefaultProcessMonitor] Registered Publication #1: 1 processes running 2018-08-29 01:20:21,710 [INFO] [c.h.d.s.i.AsynchronousEventPublicationService] Firing data hub event : PublicationStartedEvent{actionId=1, poolId=0} 2018-08-29 01:20:21,735 [DEBUG] [c.h.d.s.i.DefaultPublicationActionService] Pinging target system HybrisCore at https://localhost:9002/datahubadapter/ for target system publication id 1 and pool GLOBAL. 2018-08-29 01:20:21,860 [WARN] [c.h.d.p.TargetSystemAvailabilityRetryListener] The target system HybrisCore at https://localhost:9002/datahubadapter/ is unavailable for target system publication id 1 and pool GLOBAL: javax.net.ssl.SSLHandshakeException: sun.security.validator.ValidatorException: PKIX path validation failed: java.security.cert.CertPathValidatorException: validity check failed. The connection will be retried in 0 seconds for attempt 1. 2018-08-29 01:20:22,378 [WARN] [c.h.d.p.TargetSystemAvailabilityRetryListener] The target system HybrisCore at https://localhost:9002/datahubadapter/ is unavailable for target system publication id 1 and pool GLOBAL: javax.net.ssl.SSLHandshakeException: sun.security.validator.ValidatorException: PKIX path validation failed: java.security.cert.CertPathValidatorException: validity check failed. The connection will be retried in 1 seconds for attempt 2. 2018-08-29 01:20:23,405 [WARN] [c.h.d.p.TargetSystemAvailabilityRetryListener] The target system HybrisCore at https://localhost:9002/datahubadapter/ is unavailable for target system publication id 1 and pool GLOBAL: javax.net.ssl.SSLHandshakeException: sun.security.validator.ValidatorException: PKIX path validation failed: java.security.cert.CertPathValidatorException: validity check failed. The connection will be retried in 2 seconds for attempt 3. 2018-08-29 01:20:25,424 [WARN] [c.h.d.p.TargetSystemAvailabilityRetryListener] The target system HybrisCore at https://localhost:9002/datahubadapter/ is unavailable for target system publication id 1 and pool GLOBAL: javax.net.ssl.SSLHandshakeException: sun.security.validator.ValidatorException: PKIX path validation failed: java.security.cert.CertPathValidatorException: validity check failed. The connection will be retried in 4 seconds for attempt 4. 2018-08-29 01:20:29,439 [WARN] [c.h.d.p.TargetSystemAvailabilityRetryListener] The target system HybrisCore at https://localhost:9002/datahubadapter/ is unavailable for target system publication id 1 and pool GLOBAL: javax.net.ssl.SSLHandshakeException: sun.security.validator.ValidatorException: PKIX path validation failed: java.security.cert.CertPathValidatorException: validity check failed. The connection will be retried in 8 seconds for attempt 5. 2018-08-29 01:20:37,457 [WARN] [c.h.d.p.TargetSystemAvailabilityRetryListener] The target system HybrisCore at https://localhost:9002/datahubadapter/ is unavailable for target system publication id 1 and pool GLOBAL: javax.net.ssl.SSLHandshakeException: sun.security.validator.ValidatorException: PKIX path validation failed: java.security.cert.CertPathValidatorException: validity check failed. The connection will be retried in 16 seconds for attempt 6. 2018-08-29 01:20:53,480 [WARN] [c.h.d.p.TargetSystemAvailabilityRetryListener] The target system HybrisCore at https://localhost:9002/datahubadapter/ is unavailable for target system publication id 1 and pool GLOBAL: javax.net.ssl.SSLHandshakeException: sun.security.validator.ValidatorException: PKIX path validation failed: java.security.cert.CertPathValidatorException: validity check failed. The connection will be retried in 32 seconds for attempt 7. 2018-08-29 01:21:25,486 [WARN] [c.h.d.p.TargetSystemAvailabilityRetryListener] The target system HybrisCore at https://localhost:9002/datahubadapter/ is unavailable for target system publication id 1 and pool GLOBAL: javax.net.ssl.SSLHandshakeException: sun.security.validator.ValidatorException: PKIX path validation failed: java.security.cert.CertPathValidatorException: validity check failed. The connection will be retried in 64 seconds for attempt 8. 2018-08-29 01:22:29,507 [WARN] [c.h.d.p.TargetSystemAvailabilityRetryListener] The target system HybrisCore at https://localhost:9002/datahubadapter/ is unavailable for target system publication id 1 and pool GLOBAL: javax.net.ssl.SSLHandshakeException: sun.security.validator.ValidatorException: PKIX path validation failed: java.security.cert.CertPathValidatorException: validity check failed. The connection will be retried in 128 seconds for attempt 9. 2018-08-29 01:28:58,228 [WARN] [c.h.d.p.TargetSystemAvailabilityRetryListener] The target system HybrisCore at https://localhost:9002/datahubadapter/ is unavailable for target system publication id 1 and pool GLOBAL: javax.net.ssl.SSLHandshakeException: sun.security.validator.ValidatorException: PKIX path validation failed: java.security.cert.CertPathValidatorException: validity check failed. The connection will be retried in 256 seconds for attempt 10. 2018-08-29 01:33:14,242 [WARN] [c.h.d.p.TargetSystemAvailabilityRetryListener] The target system HybrisCore at https://localhost:9002/datahubadapter/ is unavailable for target system publication id 1 and pool GLOBAL: javax.net.ssl.SSLHandshakeException: sun.security.validator.ValidatorException: PKIX path validation failed: java.security.cert.CertPathValidatorException: validity check failed. The connection will be retried in 256 seconds for attempt 11.

[mpern]

looks like the datahub tries to verify the https certificate of commerce, and fails to do so.

can't you connect to commerce using plain http?

[bharathyelugula]

Thx for your response... Same issue with http as well... attached log. link text

[former_member631673]

Hi,

could you resolve the issue? I am facing the exact same issue right now.

Everything is working fine but the target publication from datahub to hybris is failing due to the SSLHandshake Exception.

There is no difference in either using the https mode or not via the properties - the error is the same with both versions.

Regards

[former_member593346]

Hi Bharath,

There is SSLHandshakeException exception in the log file. could you please add below properties in the datahub and hybris local.properties files and try.

Hybris's Local.properties

datahubadapter.security.https.enabled=false

Datahub's local.properties

datahub.security.https.enabled=false

Thanks,

[Former Member]

Hi Bharath,

Can you please share your daathub local.properties file.

From the error I can see that datahub is trying to use https://localhost:9002/datahubadapter/ as the target system.

Could you please remove the / from

targetsystem.hybriscore.url= https://localhost:9002/datahubadapter/ and use

targetsystem.hybriscore.url=https://localhost:9002/datahubadapter

thanks,

[Former Member]

Hi Bahrath, Do you have your SSL certificates installed or up to date?

https://wiki.hybris.com/display/cloudss/Step+3+-+Data+Hub+Standalone+Server

//Giles

[bharathyelugula]

Hi Giles, Thanks for your response. Yes I did verify all the certificates (using java keystore tool). did check for the datahub.jks and keystore.jks validity as well... What all certificates should i be considering for checking the validate (or up to date) ?

Regards, Bharath