search

Fraunhofer-AISEC / ids-clearing-house-service

This is an implementation of the IDS Clearing House
Apache License 2.0
0 stars 11 forks source link

Error during the connection between a DSC and the CH ("HTTP(S) request failed, retry request with exclusive lock...") #18

Closed boxer-code closed 2 years ago

boxer-code commented 2 years ago

Hi, I'm trying to connect the clearing-house to an existing ids-structure containing a Dataspace Connector. But during the connection between these components the DSC receive an invalid ids message and the trusted-connector of the ch throws an exception and the warning "HTTP(S) request failed, retry request with exclusive lock..." after retrieving the DAT from DAPS. The other components (DSC, Broker) don't have problems to receive a DAT and the omejdn server doesn't show an error. Could there be a missing part of the setup that causes that especially the trusted-connector throws an dat exception? I attach the logs of the DSC, trusted-connector and the clearing-house-api underneath. These are the obtained logs of the DSC: 

2022-04-19T15:08:02,348 [https-jsse-nio-8080-exec-1] INFO - Using cached DAPS DAT. [expiration=(2022-04-19T16:07:40.000+0000)]

2022-04-19T15:08:02,405 [https-jsse-nio-8080-exec-1] DEBUG - Built request message. [header=({\n  "@context" : {\n    "ids" : "https://w3id.org/idsa/core/",\n    "idsc" : "https://w3id.org/idsa/code/"\n  },\n  "@type" : "ids:RequestMessage",\n  "@id" : "https://w3id.org/idsa/autogen/requestMessage/6662442a-155f-43e9-b3f3-554c6cc6c497",\n  "ids:modelVersion" : "4.2.7",\n  "ids:issued" : {\n    "@value" : "2022-04-19T15:08:02.369Z",\n    "@type" : "http://www.w3.org/2001/XMLSchema#dateTimeStamp"\n  },\n  "ids:issuerConnector" : {\n    "@id" : "https://w3id.org/idsa/autogen/baseConnector/7b934432-a85e-41c5-9f65-669219dde4ea"\n  },\n  "ids:recipientConnector" : [ {\n    "@id" : "https://consumer-core:9999/process/ec0e0578-3247-40f5-abd9-a8ba19b06e0a"\n  } ],\n  "ids:senderAgent" : {\n    "@id" : "https://w3id.org/idsa/autogen/baseConnector/7b934432-a85e-41c5-9f65-669219dde4ea"\n  },\n  "ids:securityToken" : {\n    "@type" : "ids:DynamicAttributeToken",\n    "@id" : "https://w3id.org/idsa/autogen/dynamicAttributeToken/6a6cc86e-bc1e-474b-a52a-8306dabeedc1",\n    "ids:tokenValue" : "eyJ0eXAiOiJKV1QiLCJraWQiOiJkZWZhdWx0IiwiYWxnIjoiUlMyNTYifQ.eyJzY29wZXMiOlsiaWRzYzpJRFNfQ09OTkVDVE9SX0FUVFJJQlVURVNfQUxMIl0sImF1ZCI6Imlkc2M6SURTX0NPTk5FQ1RPUlNfQUxMIiwiaXNzIjoiaHR0cDovL29tZWpkbjo0NTY3IiwibmJmIjoxNjUwMzgwODYwLCJpYXQiOjE2NTAzODA4NjAsImp0aSI6Ik56RXhOemMyT1RnME9UTTBNRE0yTVRRME9BPT0iLCJleHAiOjE2NTAzODQ0NjAsInNlY3VyaXR5UHJvZmlsZSI6Imlkc2M6QkFTRV9TRUNVUklUWV9QUk9GSUxFIiwicmVmZXJyaW5nQ29ubmVjdG9yIjoiaHR0cDovL3Rlc3RiZWQxLmRlbW8iLCJAdHlwZSI6ImlkczpEYXRQYXlsb2FkIiwiQGNvbnRleHQiOiJodHRwczovL3czaWQub3JnL2lkc2EvY29udGV4dHMvY29udGV4dC5qc29ubGQiLCJ0cmFuc3BvcnRDZXJ0c1NoYTI1NiI6ImM2OGQ5ZTZiYTNmMTc5OWJjYmU1YmVjOWQ3ZDk4YjE1YjBlZjJmMjkyYzgwZjZiY2E5OTQxNzhhYTk1YWUxMGQiLCJzdWIiOiI2NjowNzpFRDpFNTo4MDpFNDoyOTo2RDoxRTpERDpGNzo0MzpDQTowRTpFQjozODozMjpDODozQTo0MzprZXlpZDowNzpGQzo5NToxNzpDNDo5NTpCOTpFNDpBRDowOTo1RjowNzoxRTpEMjoyMDo3NToyRDo4OTo2Njo4NSJ9.ZxBm60TQyfcuqATRIJ78Oaq-K5K7qkxsbgegMgLEMuk7RLfYUq6VK1g2MeSIPsw7i76Vus-e6nU2ipqypHKeOG1H0FYjSiJFM06eiHgXPl2I3icea9BWx-3QD_O6HllwAtxSDR0ekG2hWeYIvX1efiYOruzTB1lYSRAsRNdomJReBUBA6Itoh_Q4FHBniMRwJlz6zJz8qctj1IgaHNL3pMz8chGzRxP4fWr9l7WovZnm38lxUbCC00gFPCZ-4MZyvRHhGJqH76-ZxEy9jvR5xLIdOWm_9Fty6XXW4asBWN8Etw2A8LSsm2ASDHAnBUHMDctsbKJ1Eg8vwcrITxAbcg",\n    "ids:tokenFormat" : {\n      "@id" : "https://w3id.org/idsa/code/JWT"\n    }\n  }\n}), payload=({"owners":["66:07:ED:E5:80:E4:29:6D:1E:DD:F7:43:CA:0E:EB:38:32:C8:3A:43:keyid:07:FC:95:17:C4:95:B9:E4:AD:09:5F:07:1E:D2:20:75:2D:89:66:85","4B:4A:0E:81:99:6A:19:B9:3A:04:37:B6:7C:86:83:17:19:5A:6E:68:keyid:07:FC:95:17:C4:95:B9:E4:AD:09:5F:07:1E:D2:20:75:2D:89:66:85"]})]

2022-04-19T15:08:02,412 [https-jsse-nio-8080-exec-1] INFO - Sending request to https://consumer-core:9999/process/ec0e0578-3247-40f5-abd9-a8ba19b06e0a ...

2022-04-19T15:08:05,520 [https-jsse-nio-8080-exec-1] WARN - Received response but response-code not in 200-299. [code=(IMSMEW0046), response-code=(500)]

2022-04-19T15:08:05,522 [https-jsse-nio-8080-exec-1] DEBUG - Received invalid ids message. [exception=(String could not be parsed, could not find a boundary!)]

de.fraunhofer.ids.messaging.protocol.multipart.parser.MultipartParseException: String could not be parsed, could not find a boundary!

at de.fraunhofer.ids.messaging.protocol.multipart.parser.MultipartParser.<init>(MultipartParser.java:60) ~[messaging-6.1.0.jar:?]

at de.fraunhofer.ids.messaging.protocol.multipart.parser.MultipartParser.stringToMultipart(MultipartParser.java:87) ~[messaging-6.1.0.jar:?]

at de.fraunhofer.ids.messaging.protocol.http.IdsHttpService.checkDatFromResponse(IdsHttpService.java:107) ~[messaging-6.1.0.jar:?]

at de.fraunhofer.ids.messaging.protocol.http.IdsHttpService.sendAndCheckDat(IdsHttpService.java:509) ~[messaging-6.1.0.jar:?]

at io.dataspaceconnector.service.message.builder.type.base.AbstractMessageService.send(AbstractMessageService.java:126) ~[classes/:7.1.0]

at io.dataspaceconnector.common.ids.message.ClearingHouseService.createProcessAtClearingHouse(ClearingHouseService.java:137) ~[classes/:7.1.0]

at io.dataspaceconnector.service.usagecontrol.PolicyExecutionService.sendAgreement(PolicyExecutionService.java:87) ~[classes/:7.1.0]

at io.dataspaceconnector.service.message.handler.event.AgreementEventHandler.handleAgreementEvent(AgreementEventHandler.java:46) ~[classes/:7.1.0]

at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:?]

at jdk.internal.reflect.NativeMethodAccessorImpl.invoke(Unknown Source) ~[?:?]

at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source) ~[?:?]

at java.lang.reflect.Method.invoke(Unknown Source) ~[?:?]

at org.springframework.context.event.ApplicationListenerMethodAdapter.doInvoke(ApplicationListenerMethodAdapter.java:344) ~[spring-context-5.3.18.jar:5.3.18]

at org.springframework.context.event.ApplicationListenerMethodAdapter.processEvent(ApplicationListenerMethodAdapter.java:229) ~[spring-context-5.3.18.jar:5.3.18]

at org.springframework.context.event.ApplicationListenerMethodAdapter.onApplicationEvent(ApplicationListenerMethodAdapter.java:166) ~[spring-context-5.3.18.jar:5.3.18]

at org.springframework.context.event.SimpleApplicationEventMulticaster.doInvokeListener(SimpleApplicationEventMulticaster.java:176) ~[spring-context-5.3.18.jar:5.3.18]

at org.springframework.context.event.SimpleApplicationEventMulticaster.invokeListener(SimpleApplicationEventMulticaster.java:169) ~[spring-context-5.3.18.jar:5.3.18]

at org.springframework.context.event.SimpleApplicationEventMulticaster.multicastEvent(SimpleApplicationEventMulticaster.java:143) ~[spring-context-5.3.18.jar:5.3.18]

at org.springframework.context.support.AbstractApplicationContext.publishEvent(AbstractApplicationContext.java:421) ~[spring-context-5.3.18.jar:5.3.18]

at org.springframework.context.support.AbstractApplicationContext.publishEvent(AbstractApplicationContext.java:391) ~[spring-context-5.3.18.jar:5.3.18]

at io.dataspaceconnector.service.message.handler.processor.AgreementComparisonProcessor.processInternal(AgreementComparisonProcessor.java:110) ~[classes/:7.1.0]

at io.dataspaceconnector.service.message.handler.processor.base.IdsProcessor.process(IdsProcessor.java:50) ~[classes/:7.1.0]

at org.apache.camel.support.processor.DelegateSyncProcessor.process(DelegateSyncProcessor.java:65) ~[camel-support-3.16.0.jar:3.16.0]

at org.apache.camel.processor.errorhandler.RedeliveryErrorHandler$RedeliveryTask.doRun(RedeliveryErrorHandler.java:812) ~[camel-core-processor-3.16.0.jar:3.16.0]

at org.apache.camel.processor.errorhandler.RedeliveryErrorHandler$RedeliveryTask.run(RedeliveryErrorHandler.java:720) ~[camel-core-processor-3.16.0.jar:3.16.0]

at org.apache.camel.impl.engine.DefaultReactiveExecutor$Worker.executeFromQueue(DefaultReactiveExecutor.java:224) ~[camel-base-engine-3.16.0.jar:3.16.0]

at org.apache.camel.impl.engine.DefaultReactiveExecutor.executeFromQueue(DefaultReactiveExecutor.java:82) ~[camel-base-engine-3.16.0.jar:3.16.0]

at org.apache.camel.impl.engine.DefaultAsyncProcessorAwaitManager.await(DefaultAsyncProcessorAwaitManager.java:96) ~[camel-base-engine-3.16.0.jar:3.16.0]

at org.apache.camel.impl.engine.DefaultAsyncProcessorAwaitManager.process(DefaultAsyncProcessorAwaitManager.java:85) ~[camel-base-engine-3.16.0.jar:3.16.0]

at org.apache.camel.processor.errorhandler.RedeliveryErrorHandler.process(RedeliveryErrorHandler.java:201) ~[camel-core-processor-3.16.0.jar:3.16.0]

at org.apache.camel.impl.engine.CamelInternalProcessor.process(CamelInternalProcessor.java:371) ~[camel-base-engine-3.16.0.jar:3.16.0]

at org.apache.camel.processor.Pipeline$PipelineTask.run(Pipeline.java:109) ~[camel-core-processor-3.16.0.jar:3.16.0]

at org.apache.camel.impl.engine.DefaultReactiveExecutor$Worker.executeFromQueue(DefaultReactiveExecutor.java:224) ~[camel-base-engine-3.16.0.jar:3.16.0]

at org.apache.camel.impl.engine.DefaultReactiveExecutor.executeFromQueue(DefaultReactiveExecutor.java:82) ~[camel-base-engine-3.16.0.jar:3.16.0]

at org.apache.camel.impl.engine.DefaultAsyncProcessorAwaitManager.await(DefaultAsyncProcessorAwaitManager.java:96) ~[camel-base-engine-3.16.0.jar:3.16.0]

at org.apache.camel.impl.engine.DefaultAsyncProcessorAwaitManager.process(DefaultAsyncProcessorAwaitManager.java:85) ~[camel-base-engine-3.16.0.jar:3.16.0]

at org.apache.camel.spring.spi.TransactionErrorHandler.processByErrorHandler(TransactionErrorHandler.java:244) ~[camel-spring-3.16.0.jar:3.16.0]

at org.apache.camel.spring.spi.TransactionErrorHandler.process(TransactionErrorHandler.java:119) ~[camel-spring-3.16.0.jar:3.16.0]

at org.apache.camel.spring.spi.TransactionErrorHandler.process(TransactionErrorHandler.java:132) ~[camel-spring-3.16.0.jar:3.16.0]

at org.apache.camel.processor.errorhandler.RedeliveryErrorHandler$RedeliveryTask.doRun(RedeliveryErrorHandler.java:812) ~[camel-core-processor-3.16.0.jar:3.16.0]

at org.apache.camel.processor.errorhandler.RedeliveryErrorHandler$RedeliveryTask.run(RedeliveryErrorHandler.java:720) ~[camel-core-processor-3.16.0.jar:3.16.0]

at org.apache.camel.impl.engine.DefaultReactiveExecutor$Worker.executeFromQueue(DefaultReactiveExecutor.java:224) ~[camel-base-engine-3.16.0.jar:3.16.0]

at org.apache.camel.impl.engine.DefaultReactiveExecutor.executeFromQueue(DefaultReactiveExecutor.java:82) ~[camel-base-engine-3.16.0.jar:3.16.0]

at org.apache.camel.impl.engine.DefaultAsyncProcessorAwaitManager.await(DefaultAsyncProcessorAwaitManager.java:96) ~[camel-base-engine-3.16.0.jar:3.16.0]

at org.apache.camel.impl.engine.DefaultAsyncProcessorAwaitManager.process(DefaultAsyncProcessorAwaitManager.java:85) ~[camel-base-engine-3.16.0.jar:3.16.0]

at org.apache.camel.spring.spi.TransactionErrorHandler.processByErrorHandler(TransactionErrorHandler.java:244) ~[camel-spring-3.16.0.jar:3.16.0]

at org.apache.camel.spring.spi.TransactionErrorHandler$1.doInTransactionWithoutResult(TransactionErrorHandler.java:207) ~[camel-spring-3.16.0.jar:3.16.0]

at org.springframework.transaction.support.TransactionCallbackWithoutResult.doInTransaction(TransactionCallbackWithoutResult.java:36) ~[spring-tx-5.3.18.jar:5.3.18]

at org.springframework.transaction.support.TransactionTemplate.execute(TransactionTemplate.java:140) ~[spring-tx-5.3.18.jar:5.3.18]

at org.apache.camel.spring.spi.TransactionErrorHandler.doInTransactionTemplate(TransactionErrorHandler.java:200) ~[camel-spring-3.16.0.jar:3.16.0]

at org.apache.camel.spring.spi.TransactionErrorHandler.processInTransaction(TransactionErrorHandler.java:155) ~[camel-spring-3.16.0.jar:3.16.0]

at org.apache.camel.spring.spi.TransactionErrorHandler.process(TransactionErrorHandler.java:123) ~[camel-spring-3.16.0.jar:3.16.0]

at org.apache.camel.spring.spi.TransactionErrorHandler.process(TransactionErrorHandler.java:132) ~[camel-spring-3.16.0.jar:3.16.0]

at org.apache.camel.impl.engine.CamelInternalProcessor.process(CamelInternalProcessor.java:399) ~[camel-base-engine-3.16.0.jar:3.16.0]

at org.apache.camel.processor.Pipeline$PipelineTask.run(Pipeline.java:109) ~[camel-core-processor-3.16.0.jar:3.16.0]

at org.apache.camel.impl.engine.DefaultReactiveExecutor$Worker.schedule(DefaultReactiveExecutor.java:193) ~[camel-base-engine-3.16.0.jar:3.16.0]

at org.apache.camel.impl.engine.DefaultReactiveExecutor.scheduleMain(DefaultReactiveExecutor.java:64) ~[camel-base-engine-3.16.0.jar:3.16.0]

at org.apache.camel.processor.Pipeline.process(Pipeline.java:184) ~[camel-core-processor-3.16.0.jar:3.16.0]

at org.apache.camel.impl.engine.CamelInternalProcessor.process(CamelInternalProcessor.java:399) ~[camel-base-engine-3.16.0.jar:3.16.0]

at org.apache.camel.component.direct.DirectProducer.process(DirectProducer.java:96) ~[camel-direct-3.16.0.jar:3.16.0]

at org.apache.camel.impl.engine.SharedCamelInternalProcessor.process(SharedCamelInternalProcessor.java:214) ~[camel-base-engine-3.16.0.jar:3.16.0]

at org.apache.camel.impl.engine.SharedCamelInternalProcessor$1.process(SharedCamelInternalProcessor.java:111) ~[camel-base-engine-3.16.0.jar:3.16.0]

at org.apache.camel.impl.engine.DefaultAsyncProcessorAwaitManager.process(DefaultAsyncProcessorAwaitManager.java:83) ~[camel-base-engine-3.16.0.jar:3.16.0]

at org.apache.camel.impl.engine.SharedCamelInternalProcessor.process(SharedCamelInternalProcessor.java:108) ~[camel-base-engine-3.16.0.jar:3.16.0]

at org.apache.camel.support.cache.DefaultProducerCache.send(DefaultProducerCache.java:199) ~[camel-support-3.16.0.jar:3.16.0]

at org.apache.camel.impl.engine.DefaultProducerTemplate.send(DefaultProducerTemplate.java:176) ~[camel-base-engine-3.16.0.jar:3.16.0]

at org.apache.camel.impl.engine.DefaultProducerTemplate.send(DefaultProducerTemplate.java:148) ~[camel-base-engine-3.16.0.jar:3.16.0]

at org.apache.camel.impl.engine.DefaultProducerTemplate.send(DefaultProducerTemplate.java:131) ~[camel-base-engine-3.16.0.jar:3.16.0]

at io.dataspaceconnector.service.message.handler.type.base.AbstractMessageHandler.handleMessage(AbstractMessageHandler.java:79) ~[classes/:7.1.0]

at de.fraunhofer.ids.messaging.dispatcher.MessageDispatcher.process(MessageDispatcher.java:218) ~[messaging-6.1.0.jar:?]

at de.fraunhofer.ids.messaging.endpoint.MessageController.handleIDSMessage(MessageController.java:164) ~[messaging-6.1.0.jar:?]

at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:?]

at jdk.internal.reflect.NativeMethodAccessorImpl.invoke(Unknown Source) ~[?:?]

at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source) ~[?:?]

at java.lang.reflect.Method.invoke(Unknown Source) ~[?:?]

at org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:205) ~[spring-web-5.3.18.jar:5.3.18]

at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:150) ~[spring-web-5.3.18.jar:5.3.18]

at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:117) ~[spring-webmvc-5.3.18.jar:5.3.18]

at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:895) ~[spring-webmvc-5.3.18.jar:5.3.18]

at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:808) ~[spring-webmvc-5.3.18.jar:5.3.18]

at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:87) ~[spring-webmvc-5.3.18.jar:5.3.18]

at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:1067) ~[spring-webmvc-5.3.18.jar:5.3.18]

at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:963) ~[spring-webmvc-5.3.18.jar:5.3.18]

at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:1006) ~[spring-webmvc-5.3.18.jar:5.3.18]

at org.springframework.web.servlet.FrameworkServlet.doPost(FrameworkServlet.java:909) ~[spring-webmvc-5.3.18.jar:5.3.18]

at javax.servlet.http.HttpServlet.service(HttpServlet.java:681) ~[tomcat-embed-core-9.0.60.jar:4.0.FR]

at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:883) ~[spring-webmvc-5.3.18.jar:5.3.18]

at javax.servlet.http.HttpServlet.service(HttpServlet.java:764) ~[tomcat-embed-core-9.0.60.jar:4.0.FR]

at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:227) ~[tomcat-embed-core-9.0.60.jar:9.0.60]

at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162) ~[tomcat-embed-core-9.0.60.jar:9.0.60]

at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:53) ~[tomcat-embed-websocket-9.0.60.jar:9.0.60]

at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:189) ~[tomcat-embed-core-9.0.60.jar:9.0.60]

at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162) ~[tomcat-embed-core-9.0.60.jar:9.0.60]

at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:327) ~[spring-security-web-5.6.2.jar:5.6.2]

at org.springframework.security.web.access.intercept.FilterSecurityInterceptor.invoke(FilterSecurityInterceptor.java:115) ~[spring-security-web-5.6.2.jar:5.6.2]

at org.springframework.security.web.access.intercept.FilterSecurityInterceptor.doFilter(FilterSecurityInterceptor.java:81) ~[spring-security-web-5.6.2.jar:5.6.2]

at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:336) ~[spring-security-web-5.6.2.jar:5.6.2]

at org.springframework.security.web.access.ExceptionTranslationFilter.doFilter(ExceptionTranslationFilter.java:122) ~[spring-security-web-5.6.2.jar:5.6.2]

at org.springframework.security.web.access.ExceptionTranslationFilter.doFilter(ExceptionTranslationFilter.java:116) ~[spring-security-web-5.6.2.jar:5.6.2]

at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:336) ~[spring-security-web-5.6.2.jar:5.6.2]

at org.springframework.security.web.session.SessionManagementFilter.doFilter(SessionManagementFilter.java:126) ~[spring-security-web-5.6.2.jar:5.6.2]

at org.springframework.security.web.session.SessionManagementFilter.doFilter(SessionManagementFilter.java:81) ~[spring-security-web-5.6.2.jar:5.6.2]

at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:336) ~[spring-security-web-5.6.2.jar:5.6.2]

at org.springframework.security.web.authentication.AnonymousAuthenticationFilter.doFilter(AnonymousAuthenticationFilter.java:109) ~[spring-security-web-5.6.2.jar:5.6.2]

at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:336) ~[spring-security-web-5.6.2.jar:5.6.2]

at org.springframework.security.web.servletapi.SecurityContextHolderAwareRequestFilter.doFilter(SecurityContextHolderAwareRequestFilter.java:149) ~[spring-security-web-5.6.2.jar:5.6.2]

at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:336) ~[spring-security-web-5.6.2.jar:5.6.2]

at org.springframework.security.web.savedrequest.RequestCacheAwareFilter.doFilter(RequestCacheAwareFilter.java:63) ~[spring-security-web-5.6.2.jar:5.6.2]

at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:336) ~[spring-security-web-5.6.2.jar:5.6.2]

at org.springframework.security.web.authentication.www.BasicAuthenticationFilter.doFilterInternal(BasicAuthenticationFilter.java:150) ~[spring-security-web-5.6.2.jar:5.6.2]

at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:117) ~[spring-web-5.3.18.jar:5.3.18]

at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:336) ~[spring-security-web-5.6.2.jar:5.6.2]

at org.springframework.security.web.authentication.logout.LogoutFilter.doFilter(LogoutFilter.java:103) ~[spring-security-web-5.6.2.jar:5.6.2]

at org.springframework.security.web.authentication.logout.LogoutFilter.doFilter(LogoutFilter.java:89) ~[spring-security-web-5.6.2.jar:5.6.2]

at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:336) ~[spring-security-web-5.6.2.jar:5.6.2]

at org.springframework.security.web.header.HeaderWriterFilter.doHeadersAfter(HeaderWriterFilter.java:90) ~[spring-security-web-5.6.2.jar:5.6.2]

at org.springframework.security.web.header.HeaderWriterFilter.doFilterInternal(HeaderWriterFilter.java:75) ~[spring-security-web-5.6.2.jar:5.6.2]

at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:117) ~[spring-web-5.3.18.jar:5.3.18]

at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:336) ~[spring-security-web-5.6.2.jar:5.6.2]

at org.springframework.security.web.context.SecurityContextPersistenceFilter.doFilter(SecurityContextPersistenceFilter.java:110) ~[spring-security-web-5.6.2.jar:5.6.2]

at org.springframework.security.web.context.SecurityContextPersistenceFilter.doFilter(SecurityContextPersistenceFilter.java:80) ~[spring-security-web-5.6.2.jar:5.6.2]

at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:336) ~[spring-security-web-5.6.2.jar:5.6.2]

at org.springframework.security.web.context.request.async.WebAsyncManagerIntegrationFilter.doFilterInternal(WebAsyncManagerIntegrationFilter.java:55) ~[spring-security-web-5.6.2.jar:5.6.2]

at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:117) ~[spring-web-5.3.18.jar:5.3.18]

at org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:336) ~[spring-security-web-5.6.2.jar:5.6.2]

at org.springframework.security.web.FilterChainProxy.doFilterInternal(FilterChainProxy.java:211) ~[spring-security-web-5.6.2.jar:5.6.2]

at org.springframework.security.web.FilterChainProxy.doFilter(FilterChainProxy.java:183) ~[spring-security-web-5.6.2.jar:5.6.2]

at org.springframework.web.filter.DelegatingFilterProxy.invokeDelegate(DelegatingFilterProxy.java:354) ~[spring-web-5.3.18.jar:5.3.18]

at org.springframework.web.filter.DelegatingFilterProxy.doFilter(DelegatingFilterProxy.java:267) ~[spring-web-5.3.18.jar:5.3.18]

at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:189) ~[tomcat-embed-core-9.0.60.jar:9.0.60]

at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162) ~[tomcat-embed-core-9.0.60.jar:9.0.60]

at org.springframework.web.filter.RequestContextFilter.doFilterInternal(RequestContextFilter.java:100) ~[spring-web-5.3.18.jar:5.3.18]

at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:117) ~[spring-web-5.3.18.jar:5.3.18]

at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:189) ~[tomcat-embed-core-9.0.60.jar:9.0.60]

at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162) ~[tomcat-embed-core-9.0.60.jar:9.0.60]

at org.springframework.web.filter.FormContentFilter.doFilterInternal(FormContentFilter.java:93) ~[spring-web-5.3.18.jar:5.3.18]

at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:117) ~[spring-web-5.3.18.jar:5.3.18]

at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:189) ~[tomcat-embed-core-9.0.60.jar:9.0.60]

at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162) ~[tomcat-embed-core-9.0.60.jar:9.0.60]

at org.springframework.boot.actuate.metrics.web.servlet.WebMvcMetricsFilter.doFilterInternal(WebMvcMetricsFilter.java:96) ~[spring-boot-actuator-2.6.6.jar:2.6.6]

at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:117) ~[spring-web-5.3.18.jar:5.3.18]

at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:189) ~[tomcat-embed-core-9.0.60.jar:9.0.60]

at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162) ~[tomcat-embed-core-9.0.60.jar:9.0.60]

at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:201) ~[spring-web-5.3.18.jar:5.3.18]

at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:117) ~[spring-web-5.3.18.jar:5.3.18]

at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:189) ~[tomcat-embed-core-9.0.60.jar:9.0.60]

at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162) ~[tomcat-embed-core-9.0.60.jar:9.0.60]

at io.opentracing.contrib.web.servlet.filter.TracingFilter.doFilter(TracingFilter.java:189) ~[opentracing-web-servlet-filter-0.4.0.jar:?]

at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:189) ~[tomcat-embed-core-9.0.60.jar:9.0.60]

at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:162) ~[tomcat-embed-core-9.0.60.jar:9.0.60]

at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:197) ~[tomcat-embed-core-9.0.60.jar:9.0.60]

at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:97) ~[tomcat-embed-core-9.0.60.jar:9.0.60]

at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:541) ~[tomcat-embed-core-9.0.60.jar:9.0.60]

at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:135) ~[tomcat-embed-core-9.0.60.jar:9.0.60]

at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:92) ~[tomcat-embed-core-9.0.60.jar:9.0.60]

at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:78) ~[tomcat-embed-core-9.0.60.jar:9.0.60]

at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:360) ~[tomcat-embed-core-9.0.60.jar:9.0.60]

at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:399) ~[tomcat-embed-core-9.0.60.jar:9.0.60]

at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:65) ~[tomcat-embed-core-9.0.60.jar:9.0.60]

at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:889) ~[tomcat-embed-core-9.0.60.jar:9.0.60]

at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1743) ~[tomcat-embed-core-9.0.60.jar:9.0.60]

at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49) ~[tomcat-embed-core-9.0.60.jar:9.0.60]

at org.apache.tomcat.util.threads.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1191) ~[tomcat-embed-core-9.0.60.jar:9.0.60]

at org.apache.tomcat.util.threads.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:659) ~[tomcat-embed-core-9.0.60.jar:9.0.60]

at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) ~[tomcat-embed-core-9.0.60.jar:9.0.60]

at java.lang.Thread.run(Unknown Source) ~[?:?]

2022-04-19T15:08:05,547 [https-jsse-nio-8080-exec-1] WARN - Failed to send contract agreement to clearing house. [exception=(Received invalid ids message.)]

2022-04-19T15:08:05,547 [https-jsse-nio-8080-exec-1] INFO - Using cached DAPS DAT. [expiration=(2022-04-19T16:07:40.000+0000)]

2022-04-19T15:08:05,690 [https-jsse-nio-8080-exec-1] INFO - Sending response with status OK (200).

These are the obtained logs of the trusted connector: 

worker-1] o.a.c.impl.engine.AbstractCamelContext   : Apache Camel 3.14.0 (camel-2) started in 4s739ms (build:14ms init:1s856ms start:2s869ms)
2022-04-19 15:08:02.863 DEBUG 1 --- [tp1275711101-34] d.f.a.i.d.PolicyDecisionPoint            : Query for uncached label transformation: once(setof(S, action_service('From[rest://post:/process/%7Bpid%7D?consumerComponentName=jetty&routeId=CH_CREATE_PID]', S), SC); SC = []),
collect_creates_labels(SC, ACraw), set_of(ACraw, Adds),
collect_removes_labels(SC, RCraw), set_of(RCraw, Removes).
2022-04-19 15:08:03.193 DEBUG 1 --- [tp1275711101-34] d.f.a.i.d.lucon.LuconEngine              : Prolog library loaded de.fhg.aisec.ids.dataflowcontrol.lucon.LuconLibrary
2022-04-19 15:08:03.245 DEBUG 1 --- [tp1275711101-34] d.f.a.i.d.PolicyDecisionPoint            : Transformation: de.fhg.aisec.ids.api.policy.TransformationDecision@d9a67ac
2022-04-19 15:08:03.259 DEBUG 1 --- [tp1275711101-34] d.f.a.i.d.PolicyDecisionPoint            : Query for uncached label transformation: once(setof(S, action_service('To[direct:multipart]', S), SC); SC = []),
collect_creates_labels(SC, ACraw), set_of(ACraw, Adds),
collect_removes_labels(SC, RCraw), set_of(RCraw, Removes).
2022-04-19 15:08:03.277 DEBUG 1 --- [tp1275711101-34] d.f.a.i.d.PolicyDecisionPoint            : Transformation: de.fhg.aisec.ids.api.policy.TransformationDecision@622b348a
2022-04-19 15:08:03.319 DEBUG 1 --- [tp1275711101-34] d.f.a.i.c.m.MultiPartStringParser        : Found header:
{
  "@context" : {
    "ids" : "https://w3id.org/idsa/core/",
    "idsc" : "https://w3id.org/idsa/code/"
  },
  "@type" : "ids:RequestMessage",
  "@id" : "https://w3id.org/idsa/autogen/requestMessage/6662442a-155f-43e9-b3f3-554c6cc6c497",
  "ids:modelVersion" : "4.2.7",
  "ids:issued" : {
    "@value" : "2022-04-19T15:08:02.369Z",
    "@type" : "http://www.w3.org/2001/XMLSchema#dateTimeStamp"
  },
  "ids:issuerConnector" : {
    "@id" : "https://w3id.org/idsa/autogen/baseConnector/7b934432-a85e-41c5-9f65-669219dde4ea"
  },
  "ids:recipientConnector" : [ {
    "@id" : "https://consumer-core:9999/process/ec0e0578-3247-40f5-abd9-a8ba19b06e0a"
  } ],
  "ids:senderAgent" : {
    "@id" : "https://w3id.org/idsa/autogen/baseConnector/7b934432-a85e-41c5-9f65-669219dde4ea"
  },
  "ids:securityToken" : {
    "@type" : "ids:DynamicAttributeToken",
    "@id" : "https://w3id.org/idsa/autogen/dynamicAttributeToken/6a6cc86e-bc1e-474b-a52a-8306dabeedc1",
    "ids:tokenValue" : "eyJ0eXAiOiJKV1QiLCJraWQiOiJkZWZhdWx0IiwiYWxnIjoiUlMyNTYifQ.eyJzY29wZXMiOlsiaWRzYzpJRFNfQ09OTkVDVE9SX0FUVFJJQlVURVNfQUxMIl0sImF1ZCI6Imlkc2M6SURTX0NPTk5FQ1RPUlNfQUxMIiwiaXNzIjoiaHR0cDovL29tZWpkbjo0NTY3IiwibmJmIjoxNjUwMzgwODYwLCJpYXQiOjE2NTAzODA4NjAsImp0aSI6Ik56RXhOemMyT1RnME9UTTBNRE0yTVRRME9BPT0iLCJleHAiOjE2NTAzODQ0NjAsInNlY3VyaXR5UHJvZmlsZSI6Imlkc2M6QkFTRV9TRUNVUklUWV9QUk9GSUxFIiwicmVmZXJyaW5nQ29ubmVjdG9yIjoiaHR0cDovL3Rlc3RiZWQxLmRlbW8iLCJAdHlwZSI6ImlkczpEYXRQYXlsb2FkIiwiQGNvbnRleHQiOiJodHRwczovL3czaWQub3JnL2lkc2EvY29udGV4dHMvY29udGV4dC5qc29ubGQiLCJ0cmFuc3BvcnRDZXJ0c1NoYTI1NiI6ImM2OGQ5ZTZiYTNmMTc5OWJjYmU1YmVjOWQ3ZDk4YjE1YjBlZjJmMjkyYzgwZjZiY2E5OTQxNzhhYTk1YWUxMGQiLCJzdWIiOiI2NjowNzpFRDpFNTo4MDpFNDoyOTo2RDoxRTpERDpGNzo0MzpDQTowRTpFQjozODozMjpDODozQTo0MzprZXlpZDowNzpGQzo5NToxNzpDNDo5NTpCOTpFNDpBRDowOTo1RjowNzoxRTpEMjoyMDo3NToyRDo4OTo2Njo4NSJ9.ZxBm60TQyfcuqATRIJ78Oaq-K5K7qkxsbgegMgLEMuk7RLfYUq6VK1g2MeSIPsw7i76Vus-e6nU2ipqypHKeOG1H0FYjSiJFM06eiHgXPl2I3icea9BWx-3QD_O6HllwAtxSDR0ekG2hWeYIvX1efiYOruzTB1lYSRAsRNdomJReBUBA6Itoh_Q4FHBniMRwJlz6zJz8qctj1IgaHNL3pMz8chGzRxP4fWr9l7WovZnm38lxUbCC00gFPCZ-4MZyvRHhGJqH76-ZxEy9jvR5xLIdOWm_9Fty6XXW4asBWN8Etw2A8LSsm2ASDHAnBUHMDctsbKJ1Eg8vwcrITxAbcg",
    "ids:tokenFormat" : {
      "@id" : "https://w3id.org/idsa/code/JWT"
    }
  }
}
2022-04-19 15:08:03.319 DEBUG 1 --- [tp1275711101-34] d.f.a.i.c.m.MultiPartStringParser        : Found body with Content-Type "application/json; charset=utf-8"
2022-04-19 15:08:03.324 DEBUG 1 --- [tp1275711101-34] d.f.a.i.d.PolicyDecisionPoint            : Query for uncached label transformation: once(setof(S, action_service('process[ref:MultipartInputProcessor]', S), SC); SC = []),
collect_creates_labels(SC, ACraw), set_of(ACraw, Adds),
collect_removes_labels(SC, RCraw), set_of(RCraw, Removes).
2022-04-19 15:08:03.337 DEBUG 1 --- [tp1275711101-34] d.f.a.i.d.PolicyDecisionPoint            : Transformation: de.fhg.aisec.ids.api.policy.TransformationDecision@4a48d23a
2022-04-19 15:08:04.676 DEBUG 1 --- [tp1275711101-34] c.ClearingHouseInfomodelParsingProcessor : Using Charset from Content-Type header: utf-8
2022-04-19 15:08:04.782 DEBUG 1 --- [tp1275711101-34] d.f.a.i.d.PolicyDecisionPoint            : Query for uncached label transformation: once(setof(S, action_service('process[ref:InfoModelParsingProcessor]', S), SC); SC = []),
collect_creates_labels(SC, ACraw), set_of(ACraw, Adds),
collect_removes_labels(SC, RCraw), set_of(RCraw, Removes).
2022-04-19 15:08:04.791 DEBUG 1 --- [tp1275711101-34] d.f.a.i.d.PolicyDecisionPoint            : Transformation: de.fhg.aisec.ids.api.policy.TransformationDecision@560804af
2022-04-19 15:08:04.797 DEBUG 1 --- [tp1275711101-34] d.f.a.i.d.PolicyDecisionPoint            : Query for uncached label transformation: once(setof(S, action_service('process[ref:TokenValidationProcessor]', S), SC); SC = []),
collect_creates_labels(SC, ACraw), set_of(ACraw, Adds),
collect_removes_labels(SC, RCraw), set_of(RCraw, Removes).
2022-04-19 15:08:04.806 DEBUG 1 --- [tp1275711101-34] d.f.a.i.d.PolicyDecisionPoint            : Transformation: de.fhg.aisec.ids.api.policy.TransformationDecision@6b87122
2022-04-19 15:08:04.846 DEBUG 1 --- [tp1275711101-34] d.f.a.i.d.PolicyDecisionPoint            : Query for uncached label transformation: once(setof(S, action_service('To[http://clearing-house-api:8000/?bridgeEndpoint=true&throwExceptionOnFailure=false]', S), SC); SC = []),
collect_creates_labels(SC, ACraw), set_of(ACraw, Adds),
collect_removes_labels(SC, RCraw), set_of(RCraw, Removes).
2022-04-19 15:08:04.859 DEBUG 1 --- [tp1275711101-34] d.f.a.i.d.PolicyDecisionPoint            : Transformation: de.fhg.aisec.ids.api.policy.TransformationDecision@6cfc90a4
2022-04-19 15:08:04.893 DEBUG 1 --- [tp1275711101-34] d.f.a.i.i.d.d.a.AisecDapsDriver          : AKI: CB:8C:C7:B6:85:79:A8:23:A6:CB:15:AB:17:50:2F:E6:65:43:5D:E8:
2022-04-19 15:08:04.893 DEBUG 1 --- [tp1275711101-34] d.f.a.i.i.d.d.a.AisecDapsDriver          : SKI: A5:0C:A5:F0:84:D9:90:BB:BC:D9:57:3A:04:C8:7F:93:ED:97:A2:52:
2022-04-19 15:08:05.025  INFO 1 --- [tp1275711101-34] d.f.a.i.i.d.d.a.AisecDapsDriver          : Retrieving Dynamic Attribute Token from DAPS ...
2022-04-19 15:08:05.026 DEBUG 1 --- [tp1275711101-34] d.f.a.i.i.d.d.a.AisecDapsDriver          : ConnectorUUID: A5:0C:A5:F0:84:D9:90:BB:BC:D9:57:3A:04:C8:7F:93:ED:97:A2:52:keyid:CB:8C:C7:B6:85:79:A8:23:A6:CB:15:AB:17:50:2F:E6:65:43:5D:E8
2022-04-19 15:08:05.348  WARN 1 --- [tp1275711101-34] d.f.a.i.i.d.d.a.AisecDapsDriver          : HTTP(S) request failed, retry request with exclusive lock...
2022-04-19 15:08:05.355 DEBUG 1 --- [tp1275711101-34] d.f.a.i.d.PolicyDecisionPoint            : Query for uncached label transformation: once(setof(S, action_service('process[ref:CHOutputProcessor]', S), SC); SC = []),
collect_creates_labels(SC, ACraw), set_of(ACraw, Adds),
collect_removes_labels(SC, RCraw), set_of(RCraw, Removes).
2022-04-19 15:08:05.367 DEBUG 1 --- [tp1275711101-34] d.f.a.i.d.PolicyDecisionPoint            : Transformation: de.fhg.aisec.ids.api.policy.TransformationDecision@1ba72e3e
2022-04-19 15:08:05.373 DEBUG 1 --- [tp1275711101-34] d.f.a.i.d.PolicyDecisionPoint            : Query for uncached label transformation: once(setof(S, action_service('Transform[simple{${exception.message}}]', S), SC); SC = []),
collect_creates_labels(SC, ACraw), set_of(ACraw, Adds),
collect_removes_labels(SC, RCraw), set_of(RCraw, Removes).
2022-04-19 15:08:05.384 DEBUG 1 --- [tp1275711101-34] d.f.a.i.d.PolicyDecisionPoint            : Transformation: de.fhg.aisec.ids.api.policy.TransformationDecision@453c7dd3
2022-04-19 15:08:05.423  INFO 1 --- [tp1275711101-34] CH_MULTIPART_ROUTE                       : ### Handle class de.fhg.aisec.ids.idscp2.idscp_core.error.DatException ###
2022-04-19 15:08:05.424 DEBUG 1 --- [tp1275711101-34] d.f.a.i.d.PolicyDecisionPoint            : Query for uncached label transformation: once(setof(S, action_service('Log[### Handle ${exception.class} ###]', S), SC); SC = []),
collect_creates_labels(SC, ACraw), set_of(ACraw, Adds),
collect_removes_labels(SC, RCraw), set_of(RCraw, Removes).
2022-04-19 15:08:05.436 DEBUG 1 --- [tp1275711101-34] d.f.a.i.d.PolicyDecisionPoint            : Transformation: de.fhg.aisec.ids.api.policy.TransformationDecision@71ad0362
2022-04-19 15:08:05.441 DEBUG 1 --- [tp1275711101-34] d.f.a.i.d.PolicyDecisionPoint            : Query for uncached label transformation: once(setof(S, action_service('RemoveHeader[idsMultipartHeader]', S), SC); SC = []),
collect_creates_labels(SC, ACraw), set_of(ACraw, Adds),
collect_removes_labels(SC, RCraw), set_of(RCraw, Removes).
2022-04-19 15:08:05.450 DEBUG 1 --- [tp1275711101-34] d.f.a.i.d.PolicyDecisionPoint            : Transformation: de.fhg.aisec.ids.api.policy.TransformationDecision@273cb565
2022-04-19 15:08:05.454 DEBUG 1 --- [tp1275711101-34] d.f.a.i.d.PolicyDecisionPoint            : Query for uncached label transformation: once(setof(S, action_service('RemoveHeader[pid]', S), SC); SC = []),
collect_creates_labels(SC, ACraw), set_of(ACraw, Adds),
collect_removes_labels(SC, RCraw), set_of(RCraw, Removes).
2022-04-19 15:08:05.462 DEBUG 1 --- [tp1275711101-34] d.f.a.i.d.PolicyDecisionPoint            : Transformation: de.fhg.aisec.ids.api.policy.TransformationDecision@3fd852a2
2022-04-19 15:08:05.473 DEBUG 1 --- [tp1275711101-34] d.f.a.i.d.PolicyDecisionPoint            : Query for uncached label transformation: once(setof(S, action_service('Choice[[When[simple{${exception.class} == ''java.lang.SecurityException'' || ${exception.class} == ''java.lang.IllegalArgumentException''} -> [SetHeader[CamelHttpResponseCode, simple{401}]]], When[simple{${exception.class} == ''java.io.IOException''} -> [SetHeader[CamelHttpResponseCode, simple{400}]]]] Otherwise[[SetHeader[CamelHttpResponseCode, simple{500}], Transform[constant{Internal Server Error}]]]]', S), SC); SC = []),
collect_creates_labels(SC, ACraw), set_of(ACraw, Adds),
collect_removes_labels(SC, RCraw), set_of(RCraw, Removes).
2022-04-19 15:08:05.483 DEBUG 1 --- [tp1275711101-34] d.f.a.i.d.PolicyDecisionPoint            : Transformation: de.fhg.aisec.ids.api.policy.TransformationDecision@18ebb514
2022-04-19 15:08:05.487 DEBUG 1 --- [tp1275711101-34] d.f.a.i.d.PolicyDecisionPoint            : Query for uncached label transformation: once(setof(S, action_service('SetHeader[CamelHttpResponseCode, simple{500}]', S), SC); SC = []),
collect_creates_labels(SC, ACraw), set_of(ACraw, Adds),
collect_removes_labels(SC, RCraw), set_of(RCraw, Removes).
2022-04-19 15:08:05.494 DEBUG 1 --- [tp1275711101-34] d.f.a.i.d.PolicyDecisionPoint            : Transformation: de.fhg.aisec.ids.api.policy.TransformationDecision@6fe1398e

These are the obtained logs of the clearing-house-api: 

[2022-04-19][15:07:13][ch_lib::db][DEBUG] clear_db: false found. Preparing to clear database...
[2022-04-19][15:07:13][ch_lib::db][DEBUG] Using database url: '"mongodb://clearing-house-mongo:27017"'
[2022-04-19][15:07:13][os_info::imp::lsb_release][DEBUG] lsb_release command failed with Os { code: 2, kind: NotFound, message: "No such file or directory" }
[2022-04-19][15:07:13][ch_lib::db][DEBUG] Check if database is empty...
[2022-04-19][15:07:13][ch_lib::db][DEBUG] ... found collections: [
    "transactions",
    "processes",
]
[2022-04-19][15:07:13][ch_lib::db][DEBUG] ... database initialized.
[2022-04-19][15:07:13][core_lib::api::client][DEBUG] Configuring Daps Api Client...
[2022-04-19][15:07:13][core_lib::api::client][DEBUG] ...found api url: http://omejdn:4567
[2022-04-19][15:07:13][core_lib::api::client::daps_api][DEBUG] Parsing certificate certs/cert.der ...
[2022-04-19][15:07:13][core_lib::api::client::daps_api][DEBUG] ... adding certificate as root certificate
[2022-04-19][15:07:13][core_lib::api::client][DEBUG] Configuring Document Api Client...
[2022-04-19][15:07:13][core_lib::api::client][DEBUG] ...found api url: http://document-api:8001
[2022-04-19][15:07:13][core_lib::api::client][DEBUG] Configuring Keyring Api Client...
[2022-04-19][15:07:13][core_lib::api::client][DEBUG] ...found api url: http://keyring-api:8002
[2022-04-19][15:07:13][rocket::launch][WARN] 🔧 Configured for release.
[2022-04-19][15:07:13][rocket::launch_][WARN] address: 0.0.0.0
[2022-04-19][15:07:13][rocket::launch_][WARN] port: 8000
[2022-04-19][15:07:13][rocket::launch_][WARN] workers: 8
[2022-04-19][15:07:13][rocket::launch_][WARN] ident: Rocket
[2022-04-19][15:07:13][rocket::launch_][WARN] keep-alive: 5s
[2022-04-19][15:07:13][rocket::launch_][WARN] limits: bytes = 8KiB, data-form = 2MiB, file = 1MiB, form = 32KiB, forms = 32KiB, json = 5MiB, msgpack = 1MiB, string = 8KiB
[2022-04-19][15:07:13][rocket::launch_][WARN] tls: disabled
[2022-04-19][15:07:13][rocket::launch_][WARN] temp dir: /tmp
[2022-04-19][15:07:13][rocket::launch_][WARN] log level: normal
[2022-04-19][15:07:13][rocket::launch_][WARN] cli colors: true
[2022-04-19][15:07:13][rocket::launch_][WARN] shutdown: ctrlc = true, force = true, signals = [SIGTERM], grace = 2s, mercy = 3s
[2022-04-19][15:07:13][rocket::launch][WARN] 🛰  Routes:
[2022-04-19][15:07:13][rocket::launch_][WARN] (get_public_sign_key) GET /.well-known/jwks.json application/json
[2022-04-19][15:07:13][rocket::launch_][WARN] (create_process) POST /process/<pid> application/json
[2022-04-19][15:07:13][rocket::launch_][WARN] (unauth) POST /process/<_pid> [50] application/json
[2022-04-19][15:07:13][rocket::launch_][WARN] (log) POST /messages/log/<pid> application/json
[2022-04-19][15:07:13][rocket::launch_][WARN] (unauth) POST /messages/log/<_pid> [50] application/json
[2022-04-19][15:07:13][rocket::launch_][WARN] (query_pid) POST /messages/query/<pid>?<page>&<size>&<sort> application/json
[2022-04-19][15:07:13][rocket::launch_][WARN] (unauth) POST /messages/query/<_pid> [50] application/json
[2022-04-19][15:07:13][rocket::launch_][WARN] (query_id) POST /messages/query/<pid>/<id> application/json
[2022-04-19][15:07:13][rocket::launch_][WARN] (unauth_id) POST /messages/query/<_pid>/<_id> [50] application/json
[2022-04-19][15:07:13][rocket::launch][WARN] 📡 Fairings:
[2022-04-19][15:07:13][rocket::launch_][WARN] Configuring Daps Api Client (ignite)
[2022-04-19][15:07:13][rocket::launch_][WARN] Mounting Clearing House API (ignite)
[2022-04-19][15:07:13][rocket::launch_][WARN] Configuring Document Api Client (ignite)
[2022-04-19][15:07:13][rocket::launch_][WARN] Configuring Process Database (ignite)
[2022-04-19][15:07:13][rocket::launch_][WARN] Configuring Keyring Api Client (ignite)
[2022-04-19][15:07:13][rocket::launch_][WARN] Shield (liftoff, response, singleton)
[2022-04-19][15:07:13][rocket::launch_][WARN] Adding Signing Key (ignite)
[2022-04-19][15:07:13][rocket::shield::shield][INFO] 🛡️ Shield:
[2022-04-19][15:07:13][_][INFO] Permissions-Policy: interest-cohort=()
[2022-04-19][15:07:13][_][INFO] X-Frame-Options: SAMEORIGIN
[2022-04-19][15:07:13][_][INFO] X-Content-Type-Options: nosniff
[2022-04-19][15:07:13][rocket::launch][WARN] 🚀 Rocket has launched from http://0.0.0.0:8000
[2022-04-19][15:08:04][rocket::server][INFO] POST /process/ec0e0578-3247-40f5-abd9-a8ba19b06e0a application/json:
[2022-04-19][15:08:04][_][INFO] Matched: (create_process) POST /process/<pid> application/json
[2022-04-19][15:08:04][core_lib::api::auth][DEBUG] ...no jwks cached
[2022-04-19][15:08:04][core_lib::api::client::daps_api][DEBUG] trying to get JWKSet from url: http://omejdn:4567/.well-known/jwks.json
[2022-04-19][15:08:04][hyper::client::connect::dns][DEBUG] resolving host="omejdn"
[2022-04-19][15:08:04][hyper::client::connect::http][DEBUG] connecting to 172.18.0.2:4567
[2022-04-19][15:08:04][tokio_reactor][DEBUG] adding I/O source: 0
[2022-04-19][15:08:04][tokio_reactor::registration][DEBUG] scheduling Write for: 0
[2022-04-19][15:08:04][hyper::client::connect::http][DEBUG] connected to Some(172.18.0.2:4567)
[2022-04-19][15:08:04][tokio_reactor::registration][DEBUG] scheduling Read for: 0
[2022-04-19][15:08:04][tokio_reactor::registration][DEBUG] scheduling Read for: 0
[2022-04-19][15:08:04][hyper::proto::h1::io][DEBUG] flushed 122 bytes
[2022-04-19][15:08:04][hyper::proto::h1::io][DEBUG] read 652 bytes
[2022-04-19][15:08:04][hyper::proto::h1::io][DEBUG] parsed 6 headers
[2022-04-19][15:08:04][hyper::proto::h1::conn][DEBUG] incoming body is content-length (400 bytes)
[2022-04-19][15:08:04][hyper::proto::h1::conn][DEBUG] incoming body completed
[2022-04-19][15:08:04][tokio_reactor::registration][DEBUG] scheduling Read for: 0
[2022-04-19][15:08:04][tokio_reactor::registration][DEBUG] scheduling Read for: 0
[2022-04-19][15:08:04][tokio_reactor::registration][DEBUG] scheduling Read for: 0
[2022-04-19][15:08:04][hyper::client::pool][DEBUG] pooling idle connection for "http://omejdn:4567"
[2022-04-19][15:08:04][reqwest::async_impl::response][DEBUG] Response: '200 OK' for http://omejdn:4567/.well-known/jwks.json
[2022-04-19][15:08:04][tokio_reactor::registration][DEBUG] scheduling Read for: 0
[2022-04-19][15:08:04][tokio_reactor::registration][DEBUG] scheduling Read for: 0
[2022-04-19][15:08:04][core_lib::api::auth][DEBUG] ...got jwks from daps
[2022-04-19][15:08:04][core_lib::api::auth][DEBUG] ...valid token!
[2022-04-19][15:08:04][core_lib::api::auth][DEBUG] ...updating jwks cache...
[2022-04-19][15:08:04][ch_lib::db][DEBUG] Trying to get process with id ec0e0578-3247-40f5-abd9-a8ba19b06e0a...
[2022-04-19][15:08:04][ch_lib::db][DEBUG] ... found it.
[2022-04-19][15:08:04][clearing_house_api::clearing_house_api][DEBUG] OwnerList: '"{\"owners\":[\"66:07:ED:E5:80:E4:29:6D:1E:DD:F7:43:CA:0E:EB:38:32:C8:3A:43:keyid:07:FC:95:17:C4:95:B9:E4:AD:09:5F:07:1E:D2:20:75:2D:89:66:85\",\"4B:4A:0E:81:99:6A:19:B9:3A:04:37:B6:7C:86:83:17:19:5A:6E:68:keyid:07:FC:95:17:C4:95:B9:E4:AD:09:5F:07:1E:D2:20:75:2D:89:66:85\"]}"'
[2022-04-19][15:08:04][clearing_house_api::clearing_house_api][INFO] Requested pid 'ec0e0578-3247-40f5-abd9-a8ba19b06e0a' will have 2 owners
[2022-04-19][15:08:04][clearing_house_api::clearing_house_api][INFO] Requested pid 'ec0e0578-3247-40f5-abd9-a8ba19b06e0a' does not exist. Creating...
[2022-04-19][15:08:04][ch_lib::db][DEBUG] Storing process with pid "ec0e0578-3247-40f5-abd9-a8ba19b06e0a"...
[2022-04-19][15:08:04][ch_lib::db][DEBUG] ...added new process: ObjectId("625ed054390618c6998bbf85")
[2022-04-19][15:08:04][_][INFO] Outcome: Success
[2022-04-19][15:08:04][_][INFO] Response succeeded.
[2022-04-19][15:09:04][hyper::proto::h1::io][DEBUG] read 0 bytes
[2022-04-19][15:09:04][tokio_reactor][DEBUG] dropping I/O source: 0
tmberthold commented 2 years ago

Short summary from DSC side:

DSC complains about an Internal Server Error received as response WARN - Received response but response-code not in 200-299. [code=(IMSMEW0046), response-code=(500)] after sending a request to INFO - Sending request to https://consumer-core:9999/process/ec0e0578-3247-40f5-abd9-a8ba19b06e0a ...

kragall commented 2 years ago

What happens on the Clearing House side is this:

  1. The request gets internally transformed and forwarded to the clearing-house-api
  2. You can see in the logs that the request is successfully handled by the clearing-house-api
  3. The result is then handled in the TC and enveloped into a proper IDS message, which requires the TC to get a DAPS token. This is where things go south. The TC is not able to get the token from the DAPS.

In the past there have been issues because people did not configure their own instances of the DAPS as anticipated by the trusted connector team. Getting the token is handled by AisecDapsDriver.kt of a library of the TC. The past issued had to do with an anticipated versioning in the token-url.

Newer versions of the DAPS and Trusted Connector might fix this issue. With Release v0.7.7 you can (and are required to) use the new version (6.3.0) of Trusted Connector. So please try if the issue persists with the new versions.

boxer-code commented 2 years ago

I've tried using the new release of the ch and the new version of the tc but the error still looks very similiar. I don't get any logs or error messages about what specific problem causes the exception, even though there are some log messages obtained from the AisecDapsDriver.kt connected to the datsexception. Do you have any ideas on how I could get more information about the origin of the error? The obtained logs are: 


  .   ____          _            __ _ _
 /\\ / ___'_ __ _ _(_)_ __  __ _ \ \ \ \
( ( )\___ | '_ | '_| | '_ \/ _` | \ \ \ \
 \\/  ___)| |_)| | | | | || (_| |  ) ) ) )
  '  |____| .__|_| |_|_| |_\__, | / / / /
 =========|_|==============|___/=/_/_/_/
 :: Spring Boot ::                (v2.6.6)

2022-05-05 18:42:39.907  INFO 1 --- [           main] d.f.a.ids.TrustedConnector$Companion     : Starting TrustedConnector.Companion using Java 17.0.2 on 793855e7f411 with PID 1 (/root/jars/ids-connector-6.3.0-plain.jar started by root in /root)
2022-05-05 18:42:39.910 DEBUG 1 --- [           main] d.f.a.ids.TrustedConnector$Companion     : Running with Spring Boot v2.6.6, Spring v5.3.18
2022-05-05 18:42:39.911  INFO 1 --- [           main] d.f.a.ids.TrustedConnector$Companion     : No active profile set, falling back to 1 default profile: "default"
2022-05-05 18:42:42.125  INFO 1 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat initialized with port(s): 8080 (http)
2022-05-05 18:42:42.139  INFO 1 --- [           main] o.apache.catalina.core.StandardService   : Starting service [Tomcat]
2022-05-05 18:42:42.140  INFO 1 --- [           main] org.apache.catalina.core.StandardEngine  : Starting Servlet engine: [Apache Tomcat/9.0.60]
2022-05-05 18:42:42.379  INFO 1 --- [           main] o.a.c.c.C.[Tomcat].[localhost].[/]       : Initializing Spring embedded WebApplicationContext
2022-05-05 18:42:42.379  INFO 1 --- [           main] w.s.c.ServletWebServerApplicationContext : Root WebApplicationContext: initialization completed in 2351 ms
2022-05-05 18:42:42.402  INFO 1 --- [           main] de.fhg.aisec.ids.webconsole.WebConsole   : Registering WebConsole classes
2022-05-05 18:42:42.582 DEBUG 1 --- [           main] d.f.a.ids.settings.SettingsComponent     : Open Settings Database /root/etc/settings.mapdb...
2022-05-05 18:42:43.031  INFO 1 --- [           main] d.f.a.ids.settings.SettingsComponent     : Migrating settings database from version 1 to version 4...
2022-05-05 18:42:43.038  INFO 1 --- [           main] d.f.a.ids.settings.SettingsComponent     : Migration successful
2022-05-05 18:42:43.039  INFO 1 --- [           main] d.f.a.ids.settings.SettingsComponent     : Migrating settings database from version 2 to version 4...
2022-05-05 18:42:43.044  INFO 1 --- [           main] d.f.a.ids.settings.SettingsComponent     : Migration successful
2022-05-05 18:42:43.045  INFO 1 --- [           main] d.f.a.ids.settings.SettingsComponent     : Migrating settings database from version 3 to version 4...
2022-05-05 18:42:43.050  INFO 1 --- [           main] d.f.a.ids.settings.SettingsComponent     : Migration successful
2022-05-05 18:42:43.403  INFO 1 --- [           main] d.f.a.ids.cm.ContainerManagerService     : Default container management is de.fhg.aisec.ids.cm.impl.docker.DockerCM@2965dd88
2022-05-05 18:42:43.446  INFO 1 --- [           main] d.f.a.i.d.PolicyDecisionPoint            : Loading Lucon policy from deploy/allow-all-flows.pl
2022-05-05 18:42:44.354 DEBUG 1 --- [           main] d.f.a.i.d.lucon.LuconEngine              : Prolog library loaded de.fhg.aisec.ids.dataflowcontrol.lucon.LuconLibrary
2022-05-05 18:42:44.357 DEBUG 1 --- [           main] d.f.a.i.d.lucon.LuconEngine              : Loading theory:
%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%
%   Prolog representation of a data flow policy
%   
%   Source: default
%
%   Do not edit this file, it has been generated automatically
%   by XText/Xtend.
%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%%
%
% Only required for SWI-Prolog
% Allow the following predicates to be scattered around the prolog file.
% Otherwise Prolog will issue a warning if they are not stated in subsequent lines.
%:- discontiguous service/1.
%:- discontiguous has_endpoint/2.
%:- discontiguous creates_label/2.
%:- discontiguous removes_label/2.
%:- discontiguous rule/1.
%:- discontiguous rule_priority/2.
%:- discontiguous receives_label/1.
%:- discontiguous has_decision/2.
%:- discontiguous has_target/2.
%:- discontiguous has_capability/2.
%:- discontiguous has_property/3.
%:- discontiguous requires_prerequisites/2.
%:- discontiguous has_alternativedecision/2.
%:- discontiguous has_obligation/2.

%%%%%%%%% Basic Blocking Rule %%%%%%%%%%
rule(dropAll).
rule_priority(dropAll,0).
has_decision(dropAll,drop).
receives_label(dropAll).
has_target(dropAll,serviceAll).

%%%%%%%%%% Catch All Service %%%%%%%%%%%
service(serviceAll).
has_endpoint(serviceAll,'.*').

%%%%%%%%%%%%%%%% Rules %%%%%%%%%%%%%%%%%
% Allow everything
rule(allowAll).
rule_priority(allowAll, 1).
has_target(allowAll, serviceAll).
receives_label(allowAll).
has_decision(allowAll, allow).
2022-05-05 18:42:44.911  INFO 1 --- [           main] o.s.b.a.w.s.WelcomePageHandlerMapping    : Adding welcome page: class path resource [static/index.html]
2022-05-05 18:42:45.184  INFO 1 --- [           main] o.a.c.m.DefaultConfigurationConfigurer   : Adding custom InterceptStrategy with id: idsCamelInterceptor and implementation: de.fhg.aisec.ids.dataflowcontrol.CamelInterceptor@5862dda4
2022-05-05 18:42:45.473  INFO 1 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat started on port(s): 8080 (http) with context path ''
2022-05-05 18:42:45.530  INFO 1 --- [           main] o.a.c.management.JmxManagementStrategy   : JMX is enabled
2022-05-05 18:42:45.566  INFO 1 --- [           main] o.a.c.impl.engine.AbstractCamelContext   : Apache Camel 3.16.0 (camel-1) is starting
2022-05-05 18:42:45.746  INFO 1 --- [           main] o.a.c.impl.engine.AbstractCamelContext   : Routes startup (total:0 started:0)
2022-05-05 18:42:45.746  INFO 1 --- [           main] o.a.c.impl.engine.AbstractCamelContext   : Apache Camel 3.16.0 (camel-1) started in 318ms (build:57ms init:81ms start:180ms)
2022-05-05 18:42:45.754  INFO 1 --- [           main] d.f.a.ids.TrustedConnector$Companion     : Started TrustedConnector.Companion in 6.434 seconds (JVM running for 7.336)
2022-05-05 18:42:45.759  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Information model 4.1.0 loaded
2022-05-05 18:42:45.761  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: appApi
2022-05-05 18:42:45.761  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: applicationAvailability
2022-05-05 18:42:45.761  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: applicationController
2022-05-05 18:42:45.762  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: applicationTaskExecutor
2022-05-05 18:42:45.762  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: awsVaultConfiguration
2022-05-05 18:42:45.762  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: basicErrorController
2022-05-05 18:42:45.762  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: beanNameHandlerMapping
2022-05-05 18:42:45.762  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: beanNameViewResolver
2022-05-05 18:42:45.762  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: camel.cloud-org.apache.camel.spring.boot.cloud.CamelCloudConfigurationProperties
2022-05-05 18:42:45.763  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: camel.component-org.apache.camel.spring.boot.ComponentConfigurationProperties
2022-05-05 18:42:45.763  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: camel.component.bean-org.apache.camel.component.bean.springboot.BeanComponentConfiguration
2022-05-05 18:42:45.763  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: camel.component.browse-org.apache.camel.component.browse.springboot.BrowseComponentConfiguration
2022-05-05 18:42:45.763  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: camel.component.class-org.apache.camel.component.beanclass.springboot.ClassComponentConfiguration
2022-05-05 18:42:45.764  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: camel.component.controlbus-org.apache.camel.component.controlbus.springboot.ControlBusComponentConfiguration
2022-05-05 18:42:45.764  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: camel.component.dataformat-org.apache.camel.component.dataformat.springboot.DataFormatComponentConfiguration
2022-05-05 18:42:45.764  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: camel.component.dataset-org.apache.camel.component.dataset.springboot.DataSetComponentConfiguration
2022-05-05 18:42:45.764  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: camel.component.dataset-test-org.apache.camel.component.dataset.springboot.DataSetTestComponentConfiguration
2022-05-05 18:42:45.764  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: camel.component.direct-org.apache.camel.component.direct.springboot.DirectComponentConfiguration
2022-05-05 18:42:45.764  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: camel.component.direct-vm-org.apache.camel.component.directvm.springboot.DirectVmComponentConfiguration
2022-05-05 18:42:45.764  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: camel.component.file-org.apache.camel.component.file.springboot.FileComponentConfiguration
2022-05-05 18:42:45.765  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: camel.component.http-org.apache.camel.component.http.springboot.HttpComponentConfiguration
2022-05-05 18:42:45.765  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: camel.component.language-org.apache.camel.component.language.springboot.LanguageComponentConfiguration
2022-05-05 18:42:45.765  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: camel.component.log-org.apache.camel.component.log.springboot.LogComponentConfiguration
2022-05-05 18:42:45.765  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: camel.component.mock-org.apache.camel.component.mock.springboot.MockComponentConfiguration
2022-05-05 18:42:45.765  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: camel.component.properties-org.apache.camel.spring.boot.properties.PropertiesComponentConfiguration
2022-05-05 18:42:45.765  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: camel.component.ref-org.apache.camel.component.ref.springboot.RefComponentConfiguration
2022-05-05 18:42:45.766  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: camel.component.rest-api-org.apache.camel.component.rest.springboot.RestApiComponentConfiguration
2022-05-05 18:42:45.766  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: camel.component.rest-org.apache.camel.component.rest.springboot.RestComponentConfiguration
2022-05-05 18:42:45.766  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: camel.component.saga-org.apache.camel.component.saga.springboot.SagaComponentConfiguration
2022-05-05 18:42:45.766  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: camel.component.scheduler-org.apache.camel.component.scheduler.springboot.SchedulerComponentConfiguration
2022-05-05 18:42:45.766  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: camel.component.seda-org.apache.camel.component.seda.springboot.SedaComponentConfiguration
2022-05-05 18:42:45.767  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: camel.component.stub-org.apache.camel.component.stub.springboot.StubComponentConfiguration
2022-05-05 18:42:45.767  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: camel.component.timer-org.apache.camel.component.timer.springboot.TimerComponentConfiguration
2022-05-05 18:42:45.767  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: camel.component.validator-org.apache.camel.component.validator.springboot.ValidatorComponentConfiguration
2022-05-05 18:42:45.767  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: camel.component.vm-org.apache.camel.component.vm.springboot.VmComponentConfiguration
2022-05-05 18:42:45.767  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: camel.component.xslt-org.apache.camel.component.xslt.springboot.XsltComponentConfiguration
2022-05-05 18:42:45.767  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: camel.language-org.apache.camel.spring.boot.LanguageConfigurationProperties
2022-05-05 18:42:45.767  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: camel.language.bean-org.apache.camel.language.bean.springboot.BeanLanguageConfiguration
2022-05-05 18:42:45.767  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: camel.language.constant-org.apache.camel.language.constant.springboot.ConstantLanguageConfiguration
2022-05-05 18:42:45.767  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: camel.language.csimple-org.apache.camel.language.csimple.springboot.CSimpleLanguageConfiguration
2022-05-05 18:42:45.767  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: camel.language.exchange-property-org.apache.camel.language.property.springboot.ExchangePropertyLanguageConfiguration
2022-05-05 18:42:45.768  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: camel.language.file-org.apache.camel.language.simple.springboot.FileLanguageConfiguration
2022-05-05 18:42:45.768  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: camel.language.header-org.apache.camel.language.header.springboot.HeaderLanguageConfiguration
2022-05-05 18:42:45.768  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: camel.language.ref-org.apache.camel.language.ref.springboot.RefLanguageConfiguration
2022-05-05 18:42:45.768  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: camel.language.simple-org.apache.camel.language.simple.springboot.SimpleLanguageConfiguration
2022-05-05 18:42:45.768  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: camel.language.tokenize-org.apache.camel.language.tokenizer.springboot.TokenizeLanguageConfiguration
2022-05-05 18:42:45.768  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: camel.language.xpath-org.apache.camel.language.xpath.springboot.XPathLanguageConfiguration
2022-05-05 18:42:45.768  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: camel.language.xtokenize-org.apache.camel.language.xtokenizer.springboot.XMLTokenizeLanguageConfiguration
2022-05-05 18:42:45.768  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: camel.rest-org.apache.camel.model.rest.springboot.RestConfigurationDefinitionProperties
2022-05-05 18:42:45.768  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: camel.routetemplate-org.apache.camel.spring.boot.routetemplate.CamelRouteTemplateConfigurationProperties
2022-05-05 18:42:45.768  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: camel.springboot-org.apache.camel.spring.boot.CamelConfigurationProperties
2022-05-05 18:42:45.768  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: camel.threadpool-org.apache.camel.spring.boot.threadpool.CamelThreadPoolConfigurationProperties
2022-05-05 18:42:45.769  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: camel.vault.aws-org.apache.camel.spring.boot.vault.AwsVaultConfigurationProperties
2022-05-05 18:42:45.769  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: camel.vault.gcp-org.apache.camel.spring.boot.vault.GcpVaultConfigurationProperties
2022-05-05 18:42:45.769  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: camelBeanPostProcessor
2022-05-05 18:42:45.769  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: camelContext
2022-05-05 18:42:45.769  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: camelEndpoint
2022-05-05 18:42:45.769  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: certApi
2022-05-05 18:42:45.769  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: characterEncodingFilter
2022-05-05 18:42:45.769  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: configApi
2022-05-05 18:42:45.769  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: configureBeanComponent
2022-05-05 18:42:45.769  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: configureBeanLanguage
2022-05-05 18:42:45.769  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: configureBrowseComponent
2022-05-05 18:42:45.769  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: configureCSimpleLanguage
2022-05-05 18:42:45.769  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: configureClassComponent
2022-05-05 18:42:45.769  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: configureConstantLanguage
2022-05-05 18:42:45.770  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: configureControlBusComponent
2022-05-05 18:42:45.770  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: configureDataFormatComponent
2022-05-05 18:42:45.770  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: configureDataSetComponent
2022-05-05 18:42:45.770  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: configureDataSetTestComponent
2022-05-05 18:42:45.770  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: configureDirectComponent
2022-05-05 18:42:45.770  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: configureDirectVmComponent
2022-05-05 18:42:45.770  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: configureExchangePropertyLanguage
2022-05-05 18:42:45.770  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: configureFileComponent
2022-05-05 18:42:45.770  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: configureFileLanguage
2022-05-05 18:42:45.770  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: configureHeaderLanguage
2022-05-05 18:42:45.770  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: configureHttpComponent
2022-05-05 18:42:45.770  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: configureIdscp2
2022-05-05 18:42:45.770  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: configureLanguageComponent
2022-05-05 18:42:45.770  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: configureLogComponent
2022-05-05 18:42:45.771  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: configureMockComponent
2022-05-05 18:42:45.771  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: configureRefComponent
2022-05-05 18:42:45.771  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: configureRefLanguage
2022-05-05 18:42:45.771  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: configureRestApiComponent
2022-05-05 18:42:45.771  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: configureRestComponent
2022-05-05 18:42:45.771  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: configureSagaComponent
2022-05-05 18:42:45.771  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: configureSchedulerComponent
2022-05-05 18:42:45.771  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: configureSedaComponent
2022-05-05 18:42:45.771  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: configureSimpleLanguage
2022-05-05 18:42:45.771  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: configureStubComponent
2022-05-05 18:42:45.771  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: configureTimerComponent
2022-05-05 18:42:45.771  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: configureTokenizeLanguage
2022-05-05 18:42:45.771  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: configureValidatorComponent
2022-05-05 18:42:45.771  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: configureVmComponent
2022-05-05 18:42:45.772  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: configureXMLTokenizeLanguage
2022-05-05 18:42:45.772  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: configureXPathLanguage
2022-05-05 18:42:45.772  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: configureXsltComponent
2022-05-05 18:42:45.772  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: connectionAPI
2022-05-05 18:42:45.772  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: connectorConfiguration
2022-05-05 18:42:45.772  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: consumerTemplate
2022-05-05 18:42:45.772  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: conventionErrorViewResolver
2022-05-05 18:42:45.772  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: defaultServletHandlerMapping
2022-05-05 18:42:45.772  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: defaultValidator
2022-05-05 18:42:45.772  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: defaultViewResolver
2022-05-05 18:42:45.772  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: dispatcherServlet
2022-05-05 18:42:45.772  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: dispatcherServletRegistration
2022-05-05 18:42:45.772  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: error
2022-05-05 18:42:45.773  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: errorAttributes
2022-05-05 18:42:45.773  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: errorPageCustomizer
2022-05-05 18:42:45.773  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: errorPageRegistrarBeanPostProcessor
2022-05-05 18:42:45.773  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: flashMapManager
2022-05-05 18:42:45.773  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: fluentProducerTemplate
2022-05-05 18:42:45.773  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: forceAutoProxyCreatorToUseClassProxying
2022-05-05 18:42:45.773  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: formContentFilter
2022-05-05 18:42:45.773  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: gcpVaultConfiguration
2022-05-05 18:42:45.773  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: handlerExceptionResolver
2022-05-05 18:42:45.774  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: handlerFunctionAdapter
2022-05-05 18:42:45.774  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: httpRequestHandlerAdapter
2022-05-05 18:42:45.774  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: idsCamelInterceptor
2022-05-05 18:42:45.774  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: idsContainerManager
2022-05-05 18:42:45.774  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: idsDataflowControl
2022-05-05 18:42:45.774  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: idsMultipartComponent
2022-05-05 18:42:45.774  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: idscp2UsageControlComponent
2022-05-05 18:42:45.774  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: infoModelService
2022-05-05 18:42:45.775  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: jacksonObjectMapper
2022-05-05 18:42:45.775  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: jacksonObjectMapperBuilder
2022-05-05 18:42:45.775  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: jerseyApplicationPath
2022-05-05 18:42:45.775  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: jerseyServletRegistration
2022-05-05 18:42:45.775  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: jettyWebServerFactoryCustomizer
2022-05-05 18:42:45.775  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: jsonComponentModule
2022-05-05 18:42:45.775  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: lifecycleProcessor
2022-05-05 18:42:45.775  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: listBeans
2022-05-05 18:42:45.775  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: listContainers
2022-05-05 18:42:45.776  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: localeCharsetMappingsCustomizer
2022-05-05 18:42:45.776  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: localeResolver
2022-05-05 18:42:45.776  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: management.endpoint.camelroutes-org.apache.camel.spring.boot.actuate.endpoint.CamelRoutesEndpointProperties
2022-05-05 18:42:45.776  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: mappingJackson2HttpMessageConverter
2022-05-05 18:42:45.777  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: messageConverters
2022-05-05 18:42:45.777  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: methodValidationPostProcessor
2022-05-05 18:42:45.777  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: metricAPI
2022-05-05 18:42:45.777  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: multipartConfigElement
2022-05-05 18:42:45.777  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: multipartResolver
2022-05-05 18:42:45.777  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: mvcContentNegotiationManager
2022-05-05 18:42:45.777  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: mvcConversionService
2022-05-05 18:42:45.777  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: mvcHandlerMappingIntrospector
2022-05-05 18:42:45.777  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: mvcPathMatcher
2022-05-05 18:42:45.777  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: mvcPatternParser
2022-05-05 18:42:45.778  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: mvcResourceUrlProvider
2022-05-05 18:42:45.778  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: mvcUriComponentsContributor
2022-05-05 18:42:45.778  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: mvcUrlPathHelper
2022-05-05 18:42:45.778  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: mvcValidator
2022-05-05 18:42:45.778  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: mvcViewResolver
2022-05-05 18:42:45.778  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.apache.camel.component.bean.springboot.BeanComponentAutoConfiguration
2022-05-05 18:42:45.778  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.apache.camel.component.beanclass.springboot.ClassComponentAutoConfiguration
2022-05-05 18:42:45.778  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.apache.camel.component.browse.springboot.BrowseComponentAutoConfiguration
2022-05-05 18:42:45.778  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.apache.camel.component.controlbus.springboot.ControlBusComponentAutoConfiguration
2022-05-05 18:42:45.779  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.apache.camel.component.dataformat.springboot.DataFormatComponentAutoConfiguration
2022-05-05 18:42:45.780  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.apache.camel.component.dataset.springboot.DataSetComponentAutoConfiguration
2022-05-05 18:42:45.780  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.apache.camel.component.dataset.springboot.DataSetComponentConverter
2022-05-05 18:42:45.780  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.apache.camel.component.dataset.springboot.DataSetTestComponentAutoConfiguration
2022-05-05 18:42:45.780  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.apache.camel.component.dataset.springboot.DataSetTestComponentConverter
2022-05-05 18:42:45.780  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.apache.camel.component.direct.springboot.DirectComponentAutoConfiguration
2022-05-05 18:42:45.780  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.apache.camel.component.directvm.springboot.DirectVmComponentAutoConfiguration
2022-05-05 18:42:45.780  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.apache.camel.component.directvm.springboot.DirectVmComponentConverter
2022-05-05 18:42:45.781  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.apache.camel.component.file.springboot.FileComponentAutoConfiguration
2022-05-05 18:42:45.781  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.apache.camel.component.http.springboot.HttpComponentAutoConfiguration
2022-05-05 18:42:45.781  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.apache.camel.component.http.springboot.HttpComponentConverter
2022-05-05 18:42:45.781  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.apache.camel.component.language.springboot.LanguageComponentAutoConfiguration
2022-05-05 18:42:45.781  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.apache.camel.component.log.springboot.LogComponentAutoConfiguration
2022-05-05 18:42:45.781  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.apache.camel.component.log.springboot.LogComponentConverter
2022-05-05 18:42:45.781  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.apache.camel.component.mock.springboot.MockComponentAutoConfiguration
2022-05-05 18:42:45.782  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.apache.camel.component.mock.springboot.MockComponentConverter
2022-05-05 18:42:45.782  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.apache.camel.component.ref.springboot.RefComponentAutoConfiguration
2022-05-05 18:42:45.782  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.apache.camel.component.rest.springboot.RestApiComponentAutoConfiguration
2022-05-05 18:42:45.782  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.apache.camel.component.rest.springboot.RestComponentAutoConfiguration
2022-05-05 18:42:45.782  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.apache.camel.component.saga.springboot.SagaComponentAutoConfiguration
2022-05-05 18:42:45.783  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.apache.camel.component.scheduler.springboot.SchedulerComponentAutoConfiguration
2022-05-05 18:42:45.783  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.apache.camel.component.seda.springboot.SedaComponentAutoConfiguration
2022-05-05 18:42:45.783  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.apache.camel.component.seda.springboot.SedaComponentConverter
2022-05-05 18:42:45.783  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.apache.camel.component.stub.springboot.StubComponentAutoConfiguration
2022-05-05 18:42:45.783  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.apache.camel.component.stub.springboot.StubComponentConverter
2022-05-05 18:42:45.783  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.apache.camel.component.timer.springboot.TimerComponentAutoConfiguration
2022-05-05 18:42:45.783  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.apache.camel.component.validator.springboot.ValidatorComponentAutoConfiguration
2022-05-05 18:42:45.784  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.apache.camel.component.validator.springboot.ValidatorComponentConverter
2022-05-05 18:42:45.784  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.apache.camel.component.vm.springboot.VmComponentAutoConfiguration
2022-05-05 18:42:45.784  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.apache.camel.component.vm.springboot.VmComponentConverter
2022-05-05 18:42:45.784  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.apache.camel.component.xslt.springboot.XsltComponentAutoConfiguration
2022-05-05 18:42:45.784  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.apache.camel.component.xslt.springboot.XsltComponentConverter
2022-05-05 18:42:45.784  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.apache.camel.language.bean.springboot.BeanLanguageAutoConfiguration
2022-05-05 18:42:45.784  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.apache.camel.language.constant.springboot.ConstantLanguageAutoConfiguration
2022-05-05 18:42:45.784  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.apache.camel.language.csimple.springboot.CSimpleLanguageAutoConfiguration
2022-05-05 18:42:45.784  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.apache.camel.language.header.springboot.HeaderLanguageAutoConfiguration
2022-05-05 18:42:45.785  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.apache.camel.language.property.springboot.ExchangePropertyLanguageAutoConfiguration
2022-05-05 18:42:45.785  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.apache.camel.language.ref.springboot.RefLanguageAutoConfiguration
2022-05-05 18:42:45.785  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.apache.camel.language.simple.springboot.FileLanguageAutoConfiguration
2022-05-05 18:42:45.785  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.apache.camel.language.simple.springboot.SimpleLanguageAutoConfiguration
2022-05-05 18:42:45.785  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.apache.camel.language.tokenizer.springboot.TokenizeLanguageAutoConfiguration
2022-05-05 18:42:45.785  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.apache.camel.language.xpath.springboot.XPathLanguageAutoConfiguration
2022-05-05 18:42:45.785  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.apache.camel.language.xtokenizer.springboot.XMLTokenizeLanguageAutoConfiguration
2022-05-05 18:42:45.785  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.apache.camel.model.rest.springboot.RestConfigurationDefinitionAutoConfiguration
2022-05-05 18:42:45.785  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.apache.camel.spring.boot.CamelAutoConfiguration
2022-05-05 18:42:45.785  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.apache.camel.spring.boot.TypeConversionConfiguration
2022-05-05 18:42:45.786  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.apache.camel.spring.boot.actuate.endpoint.CamelRouteControllerEndpointAutoConfiguration
2022-05-05 18:42:45.786  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.apache.camel.spring.boot.actuate.endpoint.CamelRoutesEndpointAutoConfiguration
2022-05-05 18:42:45.786  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.apache.camel.spring.boot.cloud.CamelCloudAutoConfiguration
2022-05-05 18:42:45.786  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.apache.camel.spring.boot.cloud.CamelCloudServiceCallConfigurationAutoConfiguration
2022-05-05 18:42:45.786  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.apache.camel.spring.boot.cloud.CamelCloudServiceChooserAutoConfiguration
2022-05-05 18:42:45.786  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.apache.camel.spring.boot.cloud.CamelCloudServiceDiscoveryAutoConfiguration
2022-05-05 18:42:45.786  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.apache.camel.spring.boot.cloud.CamelCloudServiceFilterAutoConfiguration
2022-05-05 18:42:45.786  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.apache.camel.spring.boot.properties.PropertiesComponentAutoConfiguration
2022-05-05 18:42:45.786  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.apache.camel.spring.boot.routetemplate.CamelRouteTemplateAutoConfiguration
2022-05-05 18:42:45.786  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.apache.camel.spring.boot.threadpool.CamelThreadPoolAutoConfiguration
2022-05-05 18:42:45.786  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.apache.camel.spring.boot.vault.AwsVaultAutoConfiguration
2022-05-05 18:42:45.786  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.apache.camel.spring.boot.vault.GcpVaultAutoConfiguration
2022-05-05 18:42:45.786  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.springframework.aop.config.internalAutoProxyCreator
2022-05-05 18:42:45.786  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.springframework.boot.autoconfigure.AutoConfigurationPackages
2022-05-05 18:42:45.786  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.springframework.boot.autoconfigure.aop.AopAutoConfiguration
2022-05-05 18:42:45.786  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.springframework.boot.autoconfigure.aop.AopAutoConfiguration$ClassProxyingConfiguration
2022-05-05 18:42:45.786  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.springframework.boot.autoconfigure.availability.ApplicationAvailabilityAutoConfiguration
2022-05-05 18:42:45.786  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.springframework.boot.autoconfigure.context.ConfigurationPropertiesAutoConfiguration
2022-05-05 18:42:45.786  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.springframework.boot.autoconfigure.context.LifecycleAutoConfiguration
2022-05-05 18:42:45.786  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.springframework.boot.autoconfigure.context.PropertyPlaceholderAutoConfiguration
2022-05-05 18:42:45.787  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.springframework.boot.autoconfigure.dao.PersistenceExceptionTranslationAutoConfiguration
2022-05-05 18:42:45.787  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.springframework.boot.autoconfigure.http.HttpMessageConvertersAutoConfiguration
2022-05-05 18:42:45.787  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.springframework.boot.autoconfigure.http.HttpMessageConvertersAutoConfiguration$StringHttpMessageConverterConfiguration
2022-05-05 18:42:45.787  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.springframework.boot.autoconfigure.http.JacksonHttpMessageConvertersConfiguration
2022-05-05 18:42:45.787  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.springframework.boot.autoconfigure.http.JacksonHttpMessageConvertersConfiguration$MappingJackson2HttpMessageConverterConfiguration
2022-05-05 18:42:45.787  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.springframework.boot.autoconfigure.info.ProjectInfoAutoConfiguration
2022-05-05 18:42:45.788  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.springframework.boot.autoconfigure.internalCachingMetadataReaderFactory
2022-05-05 18:42:45.788  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.springframework.boot.autoconfigure.jackson.JacksonAutoConfiguration
2022-05-05 18:42:45.788  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.springframework.boot.autoconfigure.jackson.JacksonAutoConfiguration$Jackson2ObjectMapperBuilderCustomizerConfiguration
2022-05-05 18:42:45.788  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.springframework.boot.autoconfigure.jackson.JacksonAutoConfiguration$JacksonObjectMapperBuilderConfiguration
2022-05-05 18:42:45.789  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.springframework.boot.autoconfigure.jackson.JacksonAutoConfiguration$JacksonObjectMapperConfiguration
2022-05-05 18:42:45.789  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.springframework.boot.autoconfigure.jackson.JacksonAutoConfiguration$ParameterNamesModuleConfiguration
2022-05-05 18:42:45.789  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.springframework.boot.autoconfigure.jersey.JerseyAutoConfiguration
2022-05-05 18:42:45.789  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.springframework.boot.autoconfigure.jersey.JerseyAutoConfiguration$JacksonResourceConfigCustomizer
2022-05-05 18:42:45.789  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.springframework.boot.autoconfigure.jersey.JerseyAutoConfiguration$JacksonResourceConfigCustomizer$JaxbObjectMapperCustomizer
2022-05-05 18:42:45.789  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.springframework.boot.autoconfigure.sql.init.SqlInitializationAutoConfiguration
2022-05-05 18:42:45.789  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.springframework.boot.autoconfigure.task.TaskExecutionAutoConfiguration
2022-05-05 18:42:45.789  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.springframework.boot.autoconfigure.task.TaskSchedulingAutoConfiguration
2022-05-05 18:42:45.789  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.springframework.boot.autoconfigure.transaction.TransactionAutoConfiguration
2022-05-05 18:42:45.789  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.springframework.boot.autoconfigure.validation.ValidationAutoConfiguration
2022-05-05 18:42:45.789  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.springframework.boot.autoconfigure.web.client.RestTemplateAutoConfiguration
2022-05-05 18:42:45.789  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.springframework.boot.autoconfigure.web.embedded.EmbeddedWebServerFactoryCustomizerAutoConfiguration
2022-05-05 18:42:45.789  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.springframework.boot.autoconfigure.web.embedded.EmbeddedWebServerFactoryCustomizerAutoConfiguration$JettyWebServerFactoryCustomizerConfiguration
2022-05-05 18:42:45.789  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.springframework.boot.autoconfigure.web.embedded.EmbeddedWebServerFactoryCustomizerAutoConfiguration$TomcatWebServerFactoryCustomizerConfiguration
2022-05-05 18:42:45.789  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.springframework.boot.autoconfigure.web.servlet.DispatcherServletAutoConfiguration
2022-05-05 18:42:45.789  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.springframework.boot.autoconfigure.web.servlet.DispatcherServletAutoConfiguration$DispatcherServletConfiguration
2022-05-05 18:42:45.789  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.springframework.boot.autoconfigure.web.servlet.DispatcherServletAutoConfiguration$DispatcherServletRegistrationConfiguration
2022-05-05 18:42:45.789  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.springframework.boot.autoconfigure.web.servlet.HttpEncodingAutoConfiguration
2022-05-05 18:42:45.790  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.springframework.boot.autoconfigure.web.servlet.MultipartAutoConfiguration
2022-05-05 18:42:45.790  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.springframework.boot.autoconfigure.web.servlet.ServletWebServerFactoryAutoConfiguration
2022-05-05 18:42:45.790  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.springframework.boot.autoconfigure.web.servlet.ServletWebServerFactoryConfiguration$EmbeddedTomcat
2022-05-05 18:42:45.790  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.springframework.boot.autoconfigure.web.servlet.WebMvcAutoConfiguration
2022-05-05 18:42:45.790  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.springframework.boot.autoconfigure.web.servlet.WebMvcAutoConfiguration$EnableWebMvcConfiguration
2022-05-05 18:42:45.790  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.springframework.boot.autoconfigure.web.servlet.WebMvcAutoConfiguration$WebMvcAutoConfigurationAdapter
2022-05-05 18:42:45.790  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.springframework.boot.autoconfigure.web.servlet.error.ErrorMvcAutoConfiguration
2022-05-05 18:42:45.790  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.springframework.boot.autoconfigure.web.servlet.error.ErrorMvcAutoConfiguration$DefaultErrorViewResolverConfiguration
2022-05-05 18:42:45.790  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.springframework.boot.autoconfigure.web.servlet.error.ErrorMvcAutoConfiguration$WhitelabelErrorViewConfiguration
2022-05-05 18:42:45.790  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.springframework.boot.autoconfigure.websocket.servlet.WebSocketServletAutoConfiguration
2022-05-05 18:42:45.790  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.springframework.boot.autoconfigure.websocket.servlet.WebSocketServletAutoConfiguration$JettyWebSocketConfiguration
2022-05-05 18:42:45.790  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.springframework.boot.autoconfigure.websocket.servlet.WebSocketServletAutoConfiguration$TomcatWebSocketConfiguration
2022-05-05 18:42:45.790  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.springframework.boot.context.internalConfigurationPropertiesBinder
2022-05-05 18:42:45.790  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.springframework.boot.context.internalConfigurationPropertiesBinderFactory
2022-05-05 18:42:45.790  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.springframework.boot.context.properties.BoundConfigurationProperties
2022-05-05 18:42:45.790  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.springframework.boot.context.properties.ConfigurationPropertiesBindingPostProcessor
2022-05-05 18:42:45.790  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.springframework.boot.context.properties.EnableConfigurationPropertiesRegistrar.methodValidationExcludeFilter
2022-05-05 18:42:45.790  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.springframework.boot.sql.init.dependency.DatabaseInitializationDependencyConfigurer$DependsOnDatabaseInitializationPostProcessor
2022-05-05 18:42:45.790  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.springframework.context.annotation.internalAutowiredAnnotationProcessor
2022-05-05 18:42:45.791  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.springframework.context.annotation.internalCommonAnnotationProcessor
2022-05-05 18:42:45.791  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.springframework.context.annotation.internalConfigurationAnnotationProcessor
2022-05-05 18:42:45.791  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.springframework.context.event.internalEventListenerFactory
2022-05-05 18:42:45.791  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: org.springframework.context.event.internalEventListenerProcessor
2022-05-05 18:42:45.791  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: parameterNamesModule
2022-05-05 18:42:45.791  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: persistenceExceptionTranslationPostProcessor
2022-05-05 18:42:45.791  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: platformTransactionManagerCustomizers
2022-05-05 18:42:45.791  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: policyApi
2022-05-05 18:42:45.791  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: preserveErrorControllerTargetClassPostProcessor
2022-05-05 18:42:45.791  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: producerTemplate
2022-05-05 18:42:45.791  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: properties
2022-05-05 18:42:45.791  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: propertiesParser
2022-05-05 18:42:45.791  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: propertySourcesPlaceholderConfigurer
2022-05-05 18:42:45.791  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: requestContextFilter
2022-05-05 18:42:45.791  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: requestMappingHandlerAdapter
2022-05-05 18:42:45.791  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: requestMappingHandlerMapping
2022-05-05 18:42:45.791  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: resourceConfigCustomizer
2022-05-05 18:42:45.791  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: resourceHandlerMapping
2022-05-05 18:42:45.791  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: rest-configuration
2022-05-05 18:42:45.791  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: restTemplateBuilder
2022-05-05 18:42:45.791  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: restTemplateBuilderConfigurer
2022-05-05 18:42:45.791  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: routeApi
2022-05-05 18:42:45.791  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: routeControllerEndpoint
2022-05-05 18:42:45.791  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: routeManagerService
2022-05-05 18:42:45.791  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: routeTemplate
2022-05-05 18:42:45.792  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: routerFunctionMapping
2022-05-05 18:42:45.792  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: routesCollector
2022-05-05 18:42:45.792  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: routesCollectorListener
2022-05-05 18:42:45.792  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: scheduledBeanLazyInitializationExcludeFilter
2022-05-05 18:42:45.792  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: server-org.springframework.boot.autoconfigure.web.ServerProperties
2022-05-05 18:42:45.792  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: service-call-configuration
2022-05-05 18:42:45.792  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: service-discovery
2022-05-05 18:42:45.792  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: service-filter
2022-05-05 18:42:45.792  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: servletWebServerFactoryCustomizer
2022-05-05 18:42:45.792  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: settingsApi
2022-05-05 18:42:45.792  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: settingsComponent
2022-05-05 18:42:45.792  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: showCamelInfo
2022-05-05 18:42:45.792  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: showConnectorProfile
2022-05-05 18:42:45.792  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: simpleControllerHandlerAdapter
2022-05-05 18:42:45.792  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: spring.info-org.springframework.boot.autoconfigure.info.ProjectInfoProperties
2022-05-05 18:42:45.792  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: spring.jackson-org.springframework.boot.autoconfigure.jackson.JacksonProperties
2022-05-05 18:42:45.792  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: spring.jersey-org.springframework.boot.autoconfigure.jersey.JerseyProperties
2022-05-05 18:42:45.792  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: spring.lifecycle-org.springframework.boot.autoconfigure.context.LifecycleProperties
2022-05-05 18:42:45.793  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: spring.mvc-org.springframework.boot.autoconfigure.web.servlet.WebMvcProperties
2022-05-05 18:42:45.793  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: spring.servlet.multipart-org.springframework.boot.autoconfigure.web.servlet.MultipartProperties
2022-05-05 18:42:45.793  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: spring.sql.init-org.springframework.boot.autoconfigure.sql.init.SqlInitializationProperties
2022-05-05 18:42:45.793  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: spring.task.execution-org.springframework.boot.autoconfigure.task.TaskExecutionProperties
2022-05-05 18:42:45.793  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: spring.task.scheduling-org.springframework.boot.autoconfigure.task.TaskSchedulingProperties
2022-05-05 18:42:45.793  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: spring.transaction-org.springframework.boot.autoconfigure.transaction.TransactionProperties
2022-05-05 18:42:45.793  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: spring.web-org.springframework.boot.autoconfigure.web.WebProperties
2022-05-05 18:42:45.793  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: springTypeConverter
2022-05-05 18:42:45.793  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: standardJacksonObjectMapperBuilderCustomizer
2022-05-05 18:42:45.793  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: static-service-discovery
2022-05-05 18:42:45.793  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: stringHttpMessageConverter
2022-05-05 18:42:45.793  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: taskExecutorBuilder
2022-05-05 18:42:45.793  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: taskSchedulerBuilder
2022-05-05 18:42:45.793  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: themeResolver
2022-05-05 18:42:45.793  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: threadPool
2022-05-05 18:42:45.793  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: tomcatServletWebServerFactory
2022-05-05 18:42:45.793  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: tomcatServletWebServerFactoryCustomizer
2022-05-05 18:42:45.793  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: tomcatWebServerFactoryCustomizer
2022-05-05 18:42:45.793  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: trustedConnector
2022-05-05 18:42:45.793  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: typeConverter
2022-05-05 18:42:45.794  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: userApi
2022-05-05 18:42:45.794  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: viewControllerHandlerMapping
2022-05-05 18:42:45.794  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: viewNameTranslator
2022-05-05 18:42:45.794  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: viewResolver
2022-05-05 18:42:45.794  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: webConsole
2022-05-05 18:42:45.794  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: webServerFactoryCustomizerBeanPostProcessor
2022-05-05 18:42:45.794  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: websocketServletWebServerCustomizer
2022-05-05 18:42:45.794  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: welcomePageHandlerMapping
2022-05-05 18:42:45.794  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Loaded bean: xmlDeployWatcher
2022-05-05 18:42:46.744 DEBUG 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Container: clearing-house-api
2022-05-05 18:42:46.744 DEBUG 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Container: document-api
2022-05-05 18:42:46.744 DEBUG 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Container: keyring-api
2022-05-05 18:42:46.744 DEBUG 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Container: document-mongo
2022-05-05 18:42:46.744 DEBUG 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Container: clearing-house-mongo
2022-05-05 18:42:46.744 DEBUG 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Container: consumer-core
2022-05-05 18:42:46.745 DEBUG 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Container: keyring-mongo
2022-05-05 18:42:46.745 DEBUG 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Container: broker-fuseki
2022-05-05 18:42:46.745 DEBUG 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Container: broker-reverseproxy
2022-05-05 18:42:46.745 DEBUG 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Container: broker-core
2022-05-05 18:42:46.745 DEBUG 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Container: connectorb
2022-05-05 18:42:46.745 DEBUG 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Container: connectora
2022-05-05 18:42:46.745 DEBUG 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Container: omejdn
2022-05-05 18:42:46.747  WARN 1 --- [           main] d.f.a.i.i.InfoModelService               : Settings or ConnectorProfile not available, or no connector entity names provided
2022-05-05 18:42:46.747  WARN 1 --- [           main] d.f.a.i.i.InfoModelService               : Connector couldn't be built: Maintainer URL is required!
2022-05-05 18:42:46.747  INFO 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : No connector profile stored yet.
2022-05-05 18:42:46.748 DEBUG 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Component: camel-bean
2022-05-05 18:42:46.749 DEBUG 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Component: camel-class
2022-05-05 18:42:46.749 DEBUG 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Component: camel-browse
2022-05-05 18:42:46.749 DEBUG 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Component: camel-controlbus
2022-05-05 18:42:46.749 DEBUG 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Component: camel-dataformat
2022-05-05 18:42:46.749 DEBUG 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Component: camel-dataset
2022-05-05 18:42:46.749 DEBUG 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Component: camel-dataset-test
2022-05-05 18:42:46.749 DEBUG 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Component: camel-direct
2022-05-05 18:42:46.749 DEBUG 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Component: camel-direct-vm
2022-05-05 18:42:46.749 DEBUG 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Component: camel-file
2022-05-05 18:42:46.749 DEBUG 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Component: camel-http
2022-05-05 18:42:46.749 DEBUG 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Component: camel-language
2022-05-05 18:42:46.749 DEBUG 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Component: camel-log
2022-05-05 18:42:46.749 DEBUG 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Component: camel-mock
2022-05-05 18:42:46.749 DEBUG 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Component: camel-ref
2022-05-05 18:42:46.749 DEBUG 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Component: camel-rest-api
2022-05-05 18:42:46.749 DEBUG 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Component: camel-rest
2022-05-05 18:42:46.749 DEBUG 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Component: camel-saga
2022-05-05 18:42:46.749 DEBUG 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Component: camel-scheduler
2022-05-05 18:42:46.749 DEBUG 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Component: camel-seda
2022-05-05 18:42:46.749 DEBUG 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Component: camel-stub
2022-05-05 18:42:46.749 DEBUG 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Component: camel-timer
2022-05-05 18:42:46.750 DEBUG 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Component: camel-validator
2022-05-05 18:42:46.750 DEBUG 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Component: camel-vm
2022-05-05 18:42:46.750 DEBUG 1 --- [           main] de.fhg.aisec.ids.TrustedConnector        : Component: camel-xslt
2022-05-05 18:42:46.752  INFO 1 --- [           main] de.fhg.aisec.ids.rm.XmlDeployWatcher     : XML file deploy/clearing-house-routes.xml detected, creating XmlApplicationContext...
2022-05-05 18:42:48.783  INFO 1 --- [onPool-worker-1] .a.c.c.x.AbstractCamelContextFactoryBean : Using custom TypeConverterRegistry: org.apache.camel.impl.converter.DefaultTypeConverter@222bfa2a
2022-05-05 18:42:48.794  INFO 1 --- [onPool-worker-1] .a.c.c.x.AbstractCamelContextFactoryBean : Using custom InterceptStrategy with id: idsCamelInterceptor and implementation: de.fhg.aisec.ids.dataflowcontrol.CamelInterceptor@5862dda4
2022-05-05 18:42:48.842  INFO 1 --- [onPool-worker-1] o.a.c.management.JmxManagementStrategy   : JMX is enabled
2022-05-05 18:42:49.042 DEBUG 1 --- [onPool-worker-1] d.f.a.i.i.i.r.RaProverDriverRegistry     : Register 'Dummy' driver to RA prover registry
2022-05-05 18:42:49.043 DEBUG 1 --- [onPool-worker-1] d.f.a.i.i.i.r.RaProverDriverRegistry     : Register 'Dummy2' driver to RA prover registry
2022-05-05 18:42:49.045 DEBUG 1 --- [onPool-worker-1] d.f.a.i.i.i.r.RaVerifierDriverRegistry   : Register 'Dummy' driver to RA verifier registry
2022-05-05 18:42:49.047 DEBUG 1 --- [onPool-worker-1] d.f.a.i.i.i.r.RaVerifierDriverRegistry   : Register 'Dummy2' driver to RA verifier registry
2022-05-05 18:42:49.193  INFO 1 --- [onPool-worker-1] o.a.c.impl.engine.AbstractCamelContext   : Apache Camel 3.16.0 (camel-2) is starting
2022-05-05 18:42:49.297 DEBUG 1 --- [onPool-worker-1] d.f.a.i.c.i.server.Idscp2ServerEndpoint  : Starting IDSCP2 server endpoint idscp2server://0.0.0.0:29292?copyHeadersRegex=%28ch-ids-%5Ba-z%5D*%7CContent-Type%29&sslContextParameters=%23ChSslContext&useIdsMessages=true
2022-05-05 18:42:49.300  INFO 1 --- [onPool-worker-1] de.fhg.aisec.ids.TrustedConnector        : Found DAPS_URL env var, DAPS URL is overridden with http://omejdn:4567
2022-05-05 18:42:49.387 DEBUG 1 --- [onPool-worker-1] d.f.a.i.i.d.d.a.AisecDapsDriver          : AKI: CB:8C:C7:B6:85:79:A8:23:A6:CB:15:AB:17:50:2F:E6:65:43:5D:E8:
2022-05-05 18:42:49.387 DEBUG 1 --- [onPool-worker-1] d.f.a.i.i.d.d.a.AisecDapsDriver          : SKI: A5:0C:A5:F0:84:D9:90:BB:BC:D9:57:3A:04:C8:7F:93:ED:97:A2:52:
2022-05-05 18:42:49.540  INFO 1 --- [onPool-worker-1] d.f.a.i.i.i.a.i.Idscp2ServerFactory      : Starting new IDSCP2 server
2022-05-05 18:42:49.668  INFO 1 --- [onPool-worker-1] org.eclipse.jetty.util.log               : Logging initialized @11250ms to org.eclipse.jetty.util.log.Slf4jLog
2022-05-05 18:42:49.682  INFO 1 --- [onPool-worker-1] o.a.c.support.jsse.SSLContextParameters  : Available providers: SUN version 17.
2022-05-05 18:42:49.836  INFO 1 --- [onPool-worker-1] o.a.c.c.jetty9.JettyHttpComponent9       : Connector on port: 9999 is using includeCipherSuites: [] excludeCipherSuites: [^.*_(MD5|SHA|SHA1)$, ^TLS_RSA_.*$, ^SSL_.*$, ^.*_NULL_.*$, ^.*_anon_.*$] includeProtocols: [] excludeProtocols: [SSL, SSLv2, SSLv2Hello, SSLv3]
2022-05-05 18:42:49.856  INFO 1 --- [onPool-worker-1] org.eclipse.jetty.server.Server          : jetty-9.4.45.v20220203; built: 2022-02-03T09:14:34.105Z; git: 4a0c91c0be53805e3fcffdcdcc9587d5301863db; jvm 17.0.2+8-Debian-1deb11u1
2022-05-05 18:42:49.884  INFO 1 --- [onPool-worker-1] o.e.jetty.server.handler.ContextHandler  : Started o.e.j.s.ServletContextHandler@42ec9b04{/,null,AVAILABLE}
2022-05-05 18:42:49.899  INFO 1 --- [onPool-worker-1] o.e.jetty.server.AbstractConnector       : Started ServerConnector@443536ec{ssl, (ssl, http/1.1)}{0.0.0.0:9999}
2022-05-05 18:42:49.899  INFO 1 --- [onPool-worker-1] org.eclipse.jetty.server.Server          : Started @11482ms
2022-05-05 18:42:49.904  INFO 1 --- [onPool-worker-1] o.a.c.impl.engine.AbstractCamelContext   : Routes startup (total:6 started:6)
2022-05-05 18:42:49.904  INFO 1 --- [onPool-worker-1] o.a.c.impl.engine.AbstractCamelContext   :     Started CH_MULTIPART_ROUTE (direct://multipart)
2022-05-05 18:42:49.904  INFO 1 --- [onPool-worker-1] o.a.c.impl.engine.AbstractCamelContext   :     Started CH_IDSCP2_ROUTE (idscp2server://0.0.0.0:29292)
2022-05-05 18:42:49.904  INFO 1 --- [onPool-worker-1] o.a.c.impl.engine.AbstractCamelContext   :     Started CH_QUERY_PID (rest://post:/messages/query/%7Bpid%7D)
2022-05-05 18:42:49.904  INFO 1 --- [onPool-worker-1] o.a.c.impl.engine.AbstractCamelContext   :     Started CH_QUERY_PID_ID (rest://post:/messages/query/%7Bpid%7D/%7Bid%7D)
2022-05-05 18:42:49.904  INFO 1 --- [onPool-worker-1] o.a.c.impl.engine.AbstractCamelContext   :     Started CH_LOG_PID (rest://post:/messages/log/%7Bpid%7D)
2022-05-05 18:42:49.904  INFO 1 --- [onPool-worker-1] o.a.c.impl.engine.AbstractCamelContext   :     Started CH_CREATE_PID (rest://post:/process/%7Bpid%7D)
2022-05-05 18:42:49.904  INFO 1 --- [onPool-worker-1] o.a.c.impl.engine.AbstractCamelContext   : Apache Camel 3.16.0 (camel-2) started in 1s68ms (build:3ms init:355ms start:710ms)
2022-05-05 18:43:10.693 DEBUG 1 --- [tp1681821293-46] d.f.a.i.d.PolicyDecisionPoint            : Query for uncached label transformation: once(setof(S, action_service('From[rest://post:/process/%7Bpid%7D?consumerComponentName=jetty&routeId=CH_CREATE_PID]', S), SC); SC = []),
collect_creates_labels(SC, ACraw), set_of(ACraw, Adds),
collect_removes_labels(SC, RCraw), set_of(RCraw, Removes).
2022-05-05 18:43:10.820 DEBUG 1 --- [tp1681821293-46] d.f.a.i.d.lucon.LuconEngine              : Prolog library loaded de.fhg.aisec.ids.dataflowcontrol.lucon.LuconLibrary
2022-05-05 18:43:10.852 DEBUG 1 --- [tp1681821293-46] d.f.a.i.d.PolicyDecisionPoint            : Transformation: de.fhg.aisec.ids.api.policy.TransformationDecision@23b9b22
2022-05-05 18:43:10.861 DEBUG 1 --- [tp1681821293-46] d.f.a.i.d.PolicyDecisionPoint            : Query for uncached label transformation: once(setof(S, action_service('To[direct:multipart]', S), SC); SC = []),
collect_creates_labels(SC, ACraw), set_of(ACraw, Adds),
collect_removes_labels(SC, RCraw), set_of(RCraw, Removes).
2022-05-05 18:43:10.872 DEBUG 1 --- [tp1681821293-46] d.f.a.i.d.PolicyDecisionPoint            : Transformation: de.fhg.aisec.ids.api.policy.TransformationDecision@6f82addd
2022-05-05 18:43:10.895 DEBUG 1 --- [tp1681821293-46] d.f.a.i.c.m.MultiPartStringParser        : Found header:
{
  "@context" : {
    "ids" : "https://w3id.org/idsa/core/",
    "idsc" : "https://w3id.org/idsa/code/"
  },
  "@type" : "ids:RequestMessage",
  "@id" : "https://w3id.org/idsa/autogen/requestMessage/5f687072-dd77-4988-8dac-9e354ce18992",
  "ids:modelVersion" : "4.2.7",
  "ids:issued" : {
    "@value" : "2022-05-05T18:43:10.540Z",
    "@type" : "http://www.w3.org/2001/XMLSchema#dateTimeStamp"
  },
  "ids:issuerConnector" : {
    "@id" : "https://connector_A"
  },
  "ids:recipientConnector" : [ {
    "@id" : "https://consumer-core:9999/process/a2ae1b68-115d-497f-a396-c150b158efef"
  } ],
  "ids:senderAgent" : {
    "@id" : "https://connector_A"
  },
  "ids:securityToken" : {
    "@type" : "ids:DynamicAttributeToken",
    "@id" : "https://w3id.org/idsa/autogen/dynamicAttributeToken/9363f53c-79d5-4cc7-902d-3c0bfb6c89f6",
    "ids:tokenValue" : "eyJ0eXAiOiJKV1QiLCJraWQiOiJkZWZhdWx0IiwiYWxnIjoiUlMyNTYifQ.eyJzY29wZXMiOlsiaWRzYzpJRFNfQ09OTkVDVE9SX0FUVFJJQlVURVNfQUxMIl0sImF1ZCI6Imlkc2M6SURTX0NPTk5FQ1RPUlNfQUxMIiwiaXNzIjoiaHR0cDovL29tZWpkbjo0NTY3IiwibmJmIjoxNjUxNzczMzY0LCJpYXQiOjE2NTE3NzMzNjQsImp0aSI6Ik16TXpOVFkxTVRFek1ETTNPVEU1TXpVMU9RPT0iLCJleHAiOjE2NTE3NzY5NjQsInNlY3VyaXR5UHJvZmlsZSI6Imlkc2M6QkFTRV9TRUNVUklUWV9QUk9GSUxFIiwicmVmZXJyaW5nQ29ubmVjdG9yIjoiaHR0cDovL3Rlc3RiZWQxLmRlbW8iLCJAdHlwZSI6ImlkczpEYXRQYXlsb2FkIiwiQGNvbnRleHQiOiJodHRwczovL3czaWQub3JnL2lkc2EvY29udGV4dHMvY29udGV4dC5qc29ubGQiLCJ0cmFuc3BvcnRDZXJ0c1NoYTI1NiI6ImM2OGQ5ZTZiYTNmMTc5OWJjYmU1YmVjOWQ3ZDk4YjE1YjBlZjJmMjkyYzgwZjZiY2E5OTQxNzhhYTk1YWUxMGQiLCJzdWIiOiI2NjowNzpFRDpFNTo4MDpFNDoyOTo2RDoxRTpERDpGNzo0MzpDQTowRTpFQjozODozMjpDODozQTo0MzprZXlpZDowNzpGQzo5NToxNzpDNDo5NTpCOTpFNDpBRDowOTo1RjowNzoxRTpEMjoyMDo3NToyRDo4OTo2Njo4NSJ9.I5BB_2eJ-Pnc1sktdwUgkdwBikM1KIp-DN0a_fK_ciBNArAacRzK3ZY7M7KuFC1gOnqLTtbHQShkfpJaXAkRxI1cBRLv5d8hDQV_KQjIj7cft9JNj74XJo1uCDIgKlSwmkUDSGH3JhzpVTPQ8MUD04R7r-BIfqm1WbL9S5jztOIMwSh_h5sxKRvFyOr89xuc0jsZDyHInAjK6z_wJwMGGaNTtmMIPbAPnlzTA9vTq0CoYzQFYYjza8DXIM4qExkWPT_MYVadUHSrMSVNXr6s33W-tQat6ONtrgb8_bkT2LRi4qAfyBpp8DnTcypBTR9BKln1QNCOJiz5QehQaISl5Q",
    "ids:tokenFormat" : {
      "@id" : "https://w3id.org/idsa/code/JWT"
    }
  }
}
2022-05-05 18:43:10.895 DEBUG 1 --- [tp1681821293-46] d.f.a.i.c.m.MultiPartStringParser        : Found body with Content-Type "null"
2022-05-05 18:43:10.896 DEBUG 1 --- [tp1681821293-46] d.f.a.i.d.PolicyDecisionPoint            : Query for uncached label transformation: once(setof(S, action_service('process[ref:MultipartInputProcessor]', S), SC); SC = []),
collect_creates_labels(SC, ACraw), set_of(ACraw, Adds),
collect_removes_labels(SC, RCraw), set_of(RCraw, Removes).
2022-05-05 18:43:10.905 DEBUG 1 --- [tp1681821293-46] d.f.a.i.d.PolicyDecisionPoint            : Transformation: de.fhg.aisec.ids.api.policy.TransformationDecision@6b62137f
2022-05-05 18:43:11.619  WARN 1 --- [tp1681821293-46] c.ClearingHouseInfomodelParsingProcessor : Expected application/json, got application/octet-stream
2022-05-05 18:43:11.625 DEBUG 1 --- [tp1681821293-46] d.f.a.i.d.PolicyDecisionPoint            : Query for uncached label transformation: once(setof(S, action_service('process[ref:InfoModelParsingProcessor]', S), SC); SC = []),
collect_creates_labels(SC, ACraw), set_of(ACraw, Adds),
collect_removes_labels(SC, RCraw), set_of(RCraw, Removes).
2022-05-05 18:43:11.630 DEBUG 1 --- [tp1681821293-46] d.f.a.i.d.PolicyDecisionPoint            : Transformation: de.fhg.aisec.ids.api.policy.TransformationDecision@27ec09c2
2022-05-05 18:43:11.633 DEBUG 1 --- [tp1681821293-46] d.f.a.i.d.PolicyDecisionPoint            : Query for uncached label transformation: once(setof(S, action_service('Transform[simple{${exception.message}}]', S), SC); SC = []),
collect_creates_labels(SC, ACraw), set_of(ACraw, Adds),
collect_removes_labels(SC, RCraw), set_of(RCraw, Removes).
2022-05-05 18:43:11.637 DEBUG 1 --- [tp1681821293-46] d.f.a.i.d.PolicyDecisionPoint            : Transformation: de.fhg.aisec.ids.api.policy.TransformationDecision@1a3c2490
2022-05-05 18:43:11.655  INFO 1 --- [tp1681821293-46] CH_MULTIPART_ROUTE                       : ### Handle class java.lang.IllegalArgumentException ###
2022-05-05 18:43:11.656 DEBUG 1 --- [tp1681821293-46] d.f.a.i.d.PolicyDecisionPoint            : Query for uncached label transformation: once(setof(S, action_service('Log[### Handle ${exception.class} ###]', S), SC); SC = []),
collect_creates_labels(SC, ACraw), set_of(ACraw, Adds),
collect_removes_labels(SC, RCraw), set_of(RCraw, Removes).
2022-05-05 18:43:11.664 DEBUG 1 --- [tp1681821293-46] d.f.a.i.d.PolicyDecisionPoint            : Transformation: de.fhg.aisec.ids.api.policy.TransformationDecision@3cb8e661
2022-05-05 18:43:11.667 DEBUG 1 --- [tp1681821293-46] d.f.a.i.d.PolicyDecisionPoint            : Query for uncached label transformation: once(setof(S, action_service('RemoveHeader[idsMultipartHeader]', S), SC); SC = []),
collect_creates_labels(SC, ACraw), set_of(ACraw, Adds),
collect_removes_labels(SC, RCraw), set_of(RCraw, Removes).
2022-05-05 18:43:11.673 DEBUG 1 --- [tp1681821293-46] d.f.a.i.d.PolicyDecisionPoint            : Transformation: de.fhg.aisec.ids.api.policy.TransformationDecision@111a8f10
2022-05-05 18:43:11.676 DEBUG 1 --- [tp1681821293-46] d.f.a.i.d.PolicyDecisionPoint            : Query for uncached label transformation: once(setof(S, action_service('RemoveHeader[pid]', S), SC); SC = []),
collect_creates_labels(SC, ACraw), set_of(ACraw, Adds),
collect_removes_labels(SC, RCraw), set_of(RCraw, Removes).
2022-05-05 18:43:11.683 DEBUG 1 --- [tp1681821293-46] d.f.a.i.d.PolicyDecisionPoint            : Transformation: de.fhg.aisec.ids.api.policy.TransformationDecision@39ed1b3a
2022-05-05 18:43:11.689 DEBUG 1 --- [tp1681821293-46] d.f.a.i.d.PolicyDecisionPoint            : Query for uncached label transformation: once(setof(S, action_service('Choice[[When[simple{${exception.class} == ''java.lang.SecurityException'' || ${exception.class} == ''java.lang.IllegalArgumentException''} -> [SetHeader[CamelHttpResponseCode, simple{401}]]], When[simple{${exception.class} == ''java.io.IOException''} -> [SetHeader[CamelHttpResponseCode, simple{400}]]]] Otherwise[[SetHeader[CamelHttpResponseCode, simple{500}], Transform[constant{Internal Server Error}]]]]', S), SC); SC = []),
collect_creates_labels(SC, ACraw), set_of(ACraw, Adds),
collect_removes_labels(SC, RCraw), set_of(RCraw, Removes).
2022-05-05 18:43:11.697 DEBUG 1 --- [tp1681821293-46] d.f.a.i.d.PolicyDecisionPoint            : Transformation: de.fhg.aisec.ids.api.policy.TransformationDecision@4cb468f2
2022-05-05 18:43:13.106 DEBUG 1 --- [tp1681821293-45] d.f.a.i.d.PolicyDecisionPoint            : Query for uncached label transformation: once(setof(S, action_service('From[rest://post:/messages/log/%7Bpid%7D?consumerComponentName=jetty&routeId=CH_LOG_PID]', S), SC); SC = []),
collect_creates_labels(SC, ACraw), set_of(ACraw, Adds),
collect_removes_labels(SC, RCraw), set_of(RCraw, Removes).
2022-05-05 18:43:13.201 DEBUG 1 --- [tp1681821293-45] d.f.a.i.d.lucon.LuconEngine              : Prolog library loaded de.fhg.aisec.ids.dataflowcontrol.lucon.LuconLibrary
2022-05-05 18:43:13.208 DEBUG 1 --- [tp1681821293-45] d.f.a.i.d.PolicyDecisionPoint            : Transformation: de.fhg.aisec.ids.api.policy.TransformationDecision@29d5545c
2022-05-05 18:43:13.214 DEBUG 1 --- [tp1681821293-45] d.f.a.i.c.m.MultiPartStringParser        : Found header:
{
  "@context" : {
    "ids" : "https://w3id.org/idsa/core/",
    "idsc" : "https://w3id.org/idsa/code/"
  },
  "@type" : "ids:LogMessage",
  "@id" : "https://w3id.org/idsa/autogen/logMessage/107d5262-ef56-4539-8fc5-26195729ef34",
  "ids:modelVersion" : "4.2.7",
  "ids:issued" : {
    "@value" : "2022-05-05T18:43:13.097Z",
    "@type" : "http://www.w3.org/2001/XMLSchema#dateTimeStamp"
  },
  "ids:issuerConnector" : {
    "@id" : "https://connector_A"
  },
  "ids:recipientConnector" : [ {
    "@id" : "https://consumer-core:9999/messages/log/a2ae1b68-115d-497f-a396-c150b158efef"
  } ],
  "ids:senderAgent" : {
    "@id" : "https://connector_A"
  },
  "ids:securityToken" : {
    "@type" : "ids:DynamicAttributeToken",
    "@id" : "https://w3id.org/idsa/autogen/dynamicAttributeToken/40f79fc1-1703-461c-8ac2-c7cc5a71f897",
    "ids:tokenValue" : "eyJ0eXAiOiJKV1QiLCJraWQiOiJkZWZhdWx0IiwiYWxnIjoiUlMyNTYifQ.eyJzY29wZXMiOlsiaWRzYzpJRFNfQ09OTkVDVE9SX0FUVFJJQlVURVNfQUxMIl0sImF1ZCI6Imlkc2M6SURTX0NPTk5FQ1RPUlNfQUxMIiwiaXNzIjoiaHR0cDovL29tZWpkbjo0NTY3IiwibmJmIjoxNjUxNzczMzY0LCJpYXQiOjE2NTE3NzMzNjQsImp0aSI6Ik16TXpOVFkxTVRFek1ETTNPVEU1TXpVMU9RPT0iLCJleHAiOjE2NTE3NzY5NjQsInNlY3VyaXR5UHJvZmlsZSI6Imlkc2M6QkFTRV9TRUNVUklUWV9QUk9GSUxFIiwicmVmZXJyaW5nQ29ubmVjdG9yIjoiaHR0cDovL3Rlc3RiZWQxLmRlbW8iLCJAdHlwZSI6ImlkczpEYXRQYXlsb2FkIiwiQGNvbnRleHQiOiJodHRwczovL3czaWQub3JnL2lkc2EvY29udGV4dHMvY29udGV4dC5qc29ubGQiLCJ0cmFuc3BvcnRDZXJ0c1NoYTI1NiI6ImM2OGQ5ZTZiYTNmMTc5OWJjYmU1YmVjOWQ3ZDk4YjE1YjBlZjJmMjkyYzgwZjZiY2E5OTQxNzhhYTk1YWUxMGQiLCJzdWIiOiI2NjowNzpFRDpFNTo4MDpFNDoyOTo2RDoxRTpERDpGNzo0MzpDQTowRTpFQjozODozMjpDODozQTo0MzprZXlpZDowNzpGQzo5NToxNzpDNDo5NTpCOTpFNDpBRDowOTo1RjowNzoxRTpEMjoyMDo3NToyRDo4OTo2Njo4NSJ9.I5BB_2eJ-Pnc1sktdwUgkdwBikM1KIp-DN0a_fK_ciBNArAacRzK3ZY7M7KuFC1gOnqLTtbHQShkfpJaXAkRxI1cBRLv5d8hDQV_KQjIj7cft9JNj74XJo1uCDIgKlSwmkUDSGH3JhzpVTPQ8MUD04R7r-BIfqm1WbL9S5jztOIMwSh_h5sxKRvFyOr89xuc0jsZDyHInAjK6z_wJwMGGaNTtmMIPbAPnlzTA9vTq0CoYzQFYYjza8DXIM4qExkWPT_MYVadUHSrMSVNXr6s33W-tQat6ONtrgb8_bkT2LRi4qAfyBpp8DnTcypBTR9BKln1QNCOJiz5QehQaISl5Q",
    "ids:tokenFormat" : {
      "@id" : "https://w3id.org/idsa/code/JWT"
    }
  }
}
2022-05-05 18:43:13.214 DEBUG 1 --- [tp1681821293-45] d.f.a.i.c.m.MultiPartStringParser        : Found body with Content-Type "null"
2022-05-05 18:43:13.309 DEBUG 1 --- [tp1681821293-45] d.f.a.i.d.PolicyDecisionPoint            : Query for uncached label transformation: once(setof(S, action_service('process[ref:TokenValidationProcessor]', S), SC); SC = []),
collect_creates_labels(SC, ACraw), set_of(ACraw, Adds),
collect_removes_labels(SC, RCraw), set_of(RCraw, Removes).
2022-05-05 18:43:13.315 DEBUG 1 --- [tp1681821293-45] d.f.a.i.d.PolicyDecisionPoint            : Transformation: de.fhg.aisec.ids.api.policy.TransformationDecision@76d92ba3
2022-05-05 18:43:13.564 DEBUG 1 --- [tp1681821293-45] d.f.a.i.d.PolicyDecisionPoint            : Query for uncached label transformation: once(setof(S, action_service('To[http://clearing-house-api:8000/?bridgeEndpoint=true&throwExceptionOnFailure=false]', S), SC); SC = []),
collect_creates_labels(SC, ACraw), set_of(ACraw, Adds),
collect_removes_labels(SC, RCraw), set_of(RCraw, Removes).
2022-05-05 18:43:13.570 DEBUG 1 --- [tp1681821293-45] d.f.a.i.d.PolicyDecisionPoint            : Transformation: de.fhg.aisec.ids.api.policy.TransformationDecision@6e4245b5
2022-05-05 18:43:13.590 DEBUG 1 --- [tp1681821293-45] d.f.a.i.i.d.d.a.AisecDapsDriver          : AKI: CB:8C:C7:B6:85:79:A8:23:A6:CB:15:AB:17:50:2F:E6:65:43:5D:E8:
2022-05-05 18:43:13.590 DEBUG 1 --- [tp1681821293-45] d.f.a.i.i.d.d.a.AisecDapsDriver          : SKI: A5:0C:A5:F0:84:D9:90:BB:BC:D9:57:3A:04:C8:7F:93:ED:97:A2:52:
2022-05-05 18:43:13.677  INFO 1 --- [tp1681821293-45] d.f.a.i.i.d.d.a.AisecDapsDriver          : Retrieving Dynamic Attribute Token from DAPS ...
2022-05-05 18:43:13.677 DEBUG 1 --- [tp1681821293-45] d.f.a.i.i.d.d.a.AisecDapsDriver          : ConnectorUUID: A5:0C:A5:F0:84:D9:90:BB:BC:D9:57:3A:04:C8:7F:93:ED:97:A2:52:keyid:CB:8C:C7:B6:85:79:A8:23:A6:CB:15:AB:17:50:2F:E6:65:43:5D:E8
2022-05-05 18:43:13.979 DEBUG 1 --- [tp1681821293-45] d.f.a.i.d.PolicyDecisionPoint            : Query for uncached label transformation: once(setof(S, action_service('process[ref:CHOutputProcessor]', S), SC); SC = []),
collect_creates_labels(SC, ACraw), set_of(ACraw, Adds),
collect_removes_labels(SC, RCraw), set_of(RCraw, Removes).
2022-05-05 18:43:13.983 DEBUG 1 --- [tp1681821293-45] d.f.a.i.d.PolicyDecisionPoint            : Transformation: de.fhg.aisec.ids.api.policy.TransformationDecision@1495429
2022-05-05 18:43:13.988  INFO 1 --- [tp1681821293-45] CH_MULTIPART_ROUTE                       : ### Handle class de.fhg.aisec.ids.idscp2.idscp_core.error.DatException ###
2022-05-05 18:43:13.996 DEBUG 1 --- [tp1681821293-45] d.f.a.i.d.PolicyDecisionPoint            : Query for uncached label transformation: once(setof(S, action_service('SetHeader[CamelHttpResponseCode, simple{500}]', S), SC); SC = []),
collect_creates_labels(SC, ACraw), set_of(ACraw, Adds),
collect_removes_labels(SC, RCraw), set_of(RCraw, Removes).
2022-05-05 18:43:13.999 DEBUG 1 --- [tp1681821293-45] d.f.a.i.d.PolicyDecisionPoint            : Transformation: de.fhg.aisec.ids.api.policy.TransformationDecision@37fa1edb
2022-05-05 18:43:16.797 DEBUG 1 --- [tp1681821293-46] d.f.a.i.c.m.MultiPartStringParser        : Found header:
{
  "@context" : {
    "ids" : "https://w3id.org/idsa/core/",
    "idsc" : "https://w3id.org/idsa/code/"
  },
  "@type" : "ids:LogMessage",
  "@id" : "https://w3id.org/idsa/autogen/logMessage/d7dc87f6-e4c6-4e8c-846c-407eb8bac3b4",
  "ids:modelVersion" : "4.2.7",
  "ids:issued" : {
    "@value" : "2022-05-05T18:43:16.786Z",
    "@type" : "http://www.w3.org/2001/XMLSchema#dateTimeStamp"
  },
  "ids:issuerConnector" : {
    "@id" : "https://connector_A"
  },
  "ids:recipientConnector" : [ {
    "@id" : "https://consumer-core:9999/messages/log/a2ae1b68-115d-497f-a396-c150b158efef"
  } ],
  "ids:senderAgent" : {
    "@id" : "https://connector_A"
  },
  "ids:securityToken" : {
    "@type" : "ids:DynamicAttributeToken",
    "@id" : "https://w3id.org/idsa/autogen/dynamicAttributeToken/a9805f11-d3ce-4a69-98e2-42a4f7325caa",
    "ids:tokenValue" : "eyJ0eXAiOiJKV1QiLCJraWQiOiJkZWZhdWx0IiwiYWxnIjoiUlMyNTYifQ.eyJzY29wZXMiOlsiaWRzYzpJRFNfQ09OTkVDVE9SX0FUVFJJQlVURVNfQUxMIl0sImF1ZCI6Imlkc2M6SURTX0NPTk5FQ1RPUlNfQUxMIiwiaXNzIjoiaHR0cDovL29tZWpkbjo0NTY3IiwibmJmIjoxNjUxNzczMzY0LCJpYXQiOjE2NTE3NzMzNjQsImp0aSI6Ik16TXpOVFkxTVRFek1ETTNPVEU1TXpVMU9RPT0iLCJleHAiOjE2NTE3NzY5NjQsInNlY3VyaXR5UHJvZmlsZSI6Imlkc2M6QkFTRV9TRUNVUklUWV9QUk9GSUxFIiwicmVmZXJyaW5nQ29ubmVjdG9yIjoiaHR0cDovL3Rlc3RiZWQxLmRlbW8iLCJAdHlwZSI6ImlkczpEYXRQYXlsb2FkIiwiQGNvbnRleHQiOiJodHRwczovL3czaWQub3JnL2lkc2EvY29udGV4dHMvY29udGV4dC5qc29ubGQiLCJ0cmFuc3BvcnRDZXJ0c1NoYTI1NiI6ImM2OGQ5ZTZiYTNmMTc5OWJjYmU1YmVjOWQ3ZDk4YjE1YjBlZjJmMjkyYzgwZjZiY2E5OTQxNzhhYTk1YWUxMGQiLCJzdWIiOiI2NjowNzpFRDpFNTo4MDpFNDoyOTo2RDoxRTpERDpGNzo0MzpDQTowRTpFQjozODozMjpDODozQTo0MzprZXlpZDowNzpGQzo5NToxNzpDNDo5NTpCOTpFNDpBRDowOTo1RjowNzoxRTpEMjoyMDo3NToyRDo4OTo2Njo4NSJ9.I5BB_2eJ-Pnc1sktdwUgkdwBikM1KIp-DN0a_fK_ciBNArAacRzK3ZY7M7KuFC1gOnqLTtbHQShkfpJaXAkRxI1cBRLv5d8hDQV_KQjIj7cft9JNj74XJo1uCDIgKlSwmkUDSGH3JhzpVTPQ8MUD04R7r-BIfqm1WbL9S5jztOIMwSh_h5sxKRvFyOr89xuc0jsZDyHInAjK6z_wJwMGGaNTtmMIPbAPnlzTA9vTq0CoYzQFYYjza8DXIM4qExkWPT_MYVadUHSrMSVNXr6s33W-tQat6ONtrgb8_bkT2LRi4qAfyBpp8DnTcypBTR9BKln1QNCOJiz5QehQaISl5Q",
    "ids:tokenFormat" : {
      "@id" : "https://w3id.org/idsa/code/JWT"
    }
  }
}
2022-05-05 18:43:16.797 DEBUG 1 --- [tp1681821293-46] d.f.a.i.c.m.MultiPartStringParser        : Found body with Content-Type "null"
2022-05-05 18:43:16.879 DEBUG 1 --- [tp1681821293-46] d.f.a.i.i.d.d.a.AisecDapsDriver          : AKI: CB:8C:C7:B6:85:79:A8:23:A6:CB:15:AB:17:50:2F:E6:65:43:5D:E8:
2022-05-05 18:43:16.879 DEBUG 1 --- [tp1681821293-46] d.f.a.i.i.d.d.a.AisecDapsDriver          : SKI: A5:0C:A5:F0:84:D9:90:BB:BC:D9:57:3A:04:C8:7F:93:ED:97:A2:52:
2022-05-05 18:43:16.946  INFO 1 --- [tp1681821293-46] d.f.a.i.i.d.d.a.AisecDapsDriver          : Retrieving Dynamic Attribute Token from DAPS ...
2022-05-05 18:43:16.946 DEBUG 1 --- [tp1681821293-46] d.f.a.i.i.d.d.a.AisecDapsDriver          : ConnectorUUID: A5:0C:A5:F0:84:D9:90:BB:BC:D9:57:3A:04:C8:7F:93:ED:97:A2:52:keyid:CB:8C:C7:B6:85:79:A8:23:A6:CB:15:AB:17:50:2F:E6:65:43:5D:E8
2022-05-05 18:43:16.957  INFO 1 --- [tp1681821293-46] CH_MULTIPART_ROUTE                       : ### Handle class de.fhg.aisec.ids.idscp2.idscp_core.error.DatException ###
kragall commented 2 years ago

You can log the stack trace and more information about the error with these two lines in the routes:

<log message="### Handle ${exception} ###"/>
<log message="### With Trace ${exception.stacktrace} ###"/>

If you are using an unchanged version of clearing-house-routes.xml, you could e.g. add those lines after the <otherwise> in line 72. After the change you need to restart the Trusted Connector and trigger the route

boxer-code commented 2 years ago

Thanks! I've added those lines into the clearing-house-routes.xml but the stacktrace isn't very helpful either. It only gives me the information that the error is caught by the else part of the try and catch block of the AisecDapsDriver.kt. It doesn't contain any information about the origin of the error. Do you have any idea what else I could be missing? These are the obtained logs of the error and the stacktrace:

2022-05-11 12:51:01.115 DEBUG 1 --- [qtp213578674-46] d.f.a.i.c.m.MultiPartStringParser        : Found body with Content-Type "application/ld+json; charset=utf-8"

2022-05-11 12:51:01.153 DEBUG 1 --- [qtp213578674-46] c.ClearingHouseInfomodelParsingProcessor : Using Charset from Content-Type header: utf-8

2022-05-11 12:51:01.254 DEBUG 1 --- [qtp213578674-46] d.f.a.i.i.d.d.a.AisecDapsDriver          : AKI: CB:8C:C7:B6:85:79:A8:23:A6:CB:15:AB:17:50:2F:E6:65:43:5D:E8:

2022-05-11 12:51:01.255 DEBUG 1 --- [qtp213578674-46] d.f.a.i.i.d.d.a.AisecDapsDriver          : SKI: A5:0C:A5:F0:84:D9:90:BB:BC:D9:57:3A:04:C8:7F:93:ED:97:A2:52:

2022-05-11 12:51:01.393  INFO 1 --- [qtp213578674-46] d.f.a.i.i.d.d.a.AisecDapsDriver          : Retrieving Dynamic Attribute Token from DAPS ...

2022-05-11 12:51:01.393 DEBUG 1 --- [qtp213578674-46] d.f.a.i.i.d.d.a.AisecDapsDriver          : ConnectorUUID: A5:0C:A5:F0:84:D9:90:BB:BC:D9:57:3A:04:C8:7F:93:ED:97:A2:52:keyid:CB:8C:C7:B6:85:79:A8:23:A6:CB:15:AB:17:50:2F:E6:65:43:5D:E8

2022-05-11 12:51:01.416  INFO 1 --- [qtp213578674-46] CH_MULTIPART_ROUTE                       : ### Handle class de.fhg.aisec.ids.idscp2.idscp_core.error.DatException ###

2022-05-11 12:51:01.438  INFO 1 --- [qtp213578674-46] CH_MULTIPART_ROUTE                       : ### Handle de.fhg.aisec.ids.idscp2.idscp_core.error.DatException: Error whilst retrieving DAT ###

2022-05-11 12:51:01.443  INFO 1 --- [qtp213578674-46] CH_MULTIPART_ROUTE                       : ### With Trace de.fhg.aisec.ids.idscp2.idscp_core.error.DatException: Error whilst retrieving DAT

at de.fhg.aisec.ids.idscp2.default_drivers.daps.aisec_daps.AisecDapsDriver.getToken(AisecDapsDriver.kt:342)

at de.fhg.aisec.ids.clearinghouse.ClearingHouseOutputProcessor$Companion.processClearingHouseOutput(ClearingHouseOutputProcessor.kt:65)

at de.fhg.aisec.ids.clearinghouse.ClearingHouseOutputProcessor.process(ClearingHouseOutputProcessor.kt:40)

at org.apache.camel.support.processor.DelegateSyncProcessor.process(DelegateSyncProcessor.java:65)

at org.apache.camel.support.processor.DelegateAsyncProcessor.process(DelegateAsyncProcessor.java:104)

at de.fhg.aisec.ids.dataflowcontrol.PolicyEnforcementPoint.process(PolicyEnforcementPoint.kt:201)

at org.apache.camel.support.processor.DelegateAsyncProcessor.process(DelegateAsyncProcessor.java:104)

at org.apache.camel.processor.errorhandler.RedeliveryErrorHandler$RedeliveryTask.doRun(RedeliveryErrorHandler.java:812)

at org.apache.camel.processor.errorhandler.RedeliveryErrorHandler$RedeliveryTask.run(RedeliveryErrorHandler.java:720)

at org.apache.camel.impl.engine.DefaultReactiveExecutor$Worker.schedule(DefaultReactiveExecutor.java:193)

at org.apache.camel.impl.engine.DefaultReactiveExecutor.scheduleMain(DefaultReactiveExecutor.java:64)

at org.apache.camel.processor.Pipeline.process(Pipeline.java:184)

at org.apache.camel.impl.engine.CamelInternalProcessor.process(CamelInternalProcessor.java:399)

at org.apache.camel.component.jetty.CamelContinuationServlet.doService(CamelContinuationServlet.java:245)

at org.apache.camel.http.common.CamelServlet.service(CamelServlet.java:130)

at javax.servlet.http.HttpServlet.service(HttpServlet.java:584)

at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:799)

at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:550)

at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:233)

at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1440)

at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:188)

at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:501)

at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:186)

at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1355)

at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)

at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127)

at org.eclipse.jetty.server.Server.handle(Server.java:516)

at org.eclipse.jetty.server.HttpChannel.lambda$handle$1(HttpChannel.java:487)

at org.eclipse.jetty.server.HttpChannel.dispatch(HttpChannel.java:732)

at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:479)

at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:277)

at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:311)

at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:105)

at org.eclipse.jetty.io.ssl.SslConnection$DecryptedEndPoint.onFillable(SslConnection.java:555)

at org.eclipse.jetty.io.ssl.SslConnection.onFillable(SslConnection.java:410)

at org.eclipse.jetty.io.ssl.SslConnection$2.succeeded(SslConnection.java:164)

at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:105)

at org.eclipse.jetty.io.ChannelEndPoint$1.run(ChannelEndPoint.java:104)

at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:338)

at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:315)

at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:173)

at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:131)

at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:409)

at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:883)

at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:1034)

at java.base/java.lang.Thread.run(Thread.java:833)

Caused by: java.net.ConnectException

at java.net.http/jdk.internal.net.http.common.Utils.toConnectException(Utils.java:1047)

at java.net.http/jdk.internal.net.http.PlainHttpConnection.connectAsync(PlainHttpConnection.java:198)

at java.net.http/jdk.internal.net.http.PlainHttpConnection.checkRetryConnect(PlainHttpConnection.java:230)

at java.net.http/jdk.internal.net.http.PlainHttpConnection.lambda$connectAsync$1(PlainHttpConnection.java:206)

at java.base/java.util.concurrent.CompletableFuture.uniHandle(CompletableFuture.java:934)

at java.base/java.util.concurrent.CompletableFuture$UniHandle.tryFire(CompletableFuture.java:911)

at java.base/java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:510)

at java.base/java.util.concurrent.CompletableFuture$AsyncSupply.run(CompletableFuture.java:1773)

at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)

at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)

... 1 more

Caused by: java.nio.channels.ClosedChannelException

at java.base/sun.nio.ch.SocketChannelImpl.ensureOpen(SocketChannelImpl.java:195)

at java.base/sun.nio.ch.SocketChannelImpl.beginConnect(SocketChannelImpl.java:760)

at java.base/sun.nio.ch.SocketChannelImpl.connect(SocketChannelImpl.java:848)

at java.net.http/jdk.internal.net.http.PlainHttpConnection.lambda$connectAsync$0(PlainHttpConnection.java:183)

at java.base/java.security.AccessController.doPrivileged(AccessController.java:569)

at java.net.http/jdk.internal.net.http.PlainHttpConnection.connectAsync(PlainHttpConnection.java:185)

... 9 more

 ###

​
kragall commented 2 years ago

Could you try adding this line? <log message="### With Cause ${exception.cause.stacktrace} ###"/>

boxer-code commented 2 years ago

After adding the line I'm getting a new exception due to the attempt to get the stacktrace with cause. It seems like the cause is null. These are the obtained logs:

2022-05-15 15:15:02.710  INFO 1 --- [qtp929881100-46] CH_MULTIPART_ROUTE                       : ### Handle class de.fhg.aisec.ids.idscp2.idscp_core.error.DatException ###

2022-05-15 15:15:02.725  INFO 1 --- [qtp929881100-46] CH_MULTIPART_ROUTE                       : ### Handle de.fhg.aisec.ids.idscp2.idscp_core.error.DatException: Error whilst retrieving DAT ###

2022-05-15 15:15:02.728  INFO 1 --- [qtp929881100-46] CH_MULTIPART_ROUTE                       : ### With Trace de.fhg.aisec.ids.idscp2.idscp_core.error.DatException: Error whilst retrieving DAT

at de.fhg.aisec.ids.idscp2.default_drivers.daps.aisec_daps.AisecDapsDriver.getToken(AisecDapsDriver.kt:342)

at de.fhg.aisec.ids.clearinghouse.ClearingHouseOutputProcessor$Companion.processClearingHouseOutput(ClearingHouseOutputProcessor.kt:65)

at de.fhg.aisec.ids.clearinghouse.ClearingHouseOutputProcessor.process(ClearingHouseOutputProcessor.kt:40)

at org.apache.camel.support.processor.DelegateSyncProcessor.process(DelegateSyncProcessor.java:65)

at org.apache.camel.support.processor.DelegateAsyncProcessor.process(DelegateAsyncProcessor.java:104)

at de.fhg.aisec.ids.dataflowcontrol.PolicyEnforcementPoint.process(PolicyEnforcementPoint.kt:201)

at org.apache.camel.support.processor.DelegateAsyncProcessor.process(DelegateAsyncProcessor.java:104)

at org.apache.camel.processor.errorhandler.RedeliveryErrorHandler$RedeliveryTask.doRun(RedeliveryErrorHandler.java:812)

at org.apache.camel.processor.errorhandler.RedeliveryErrorHandler$RedeliveryTask.run(RedeliveryErrorHandler.java:720)

at org.apache.camel.impl.engine.DefaultReactiveExecutor$Worker.schedule(DefaultReactiveExecutor.java:193)

at org.apache.camel.impl.engine.DefaultReactiveExecutor.scheduleMain(DefaultReactiveExecutor.java:64)

at org.apache.camel.processor.Pipeline.process(Pipeline.java:184)

at org.apache.camel.impl.engine.CamelInternalProcessor.process(CamelInternalProcessor.java:399)

at org.apache.camel.component.jetty.CamelContinuationServlet.doService(CamelContinuationServlet.java:245)

at org.apache.camel.http.common.CamelServlet.service(CamelServlet.java:130)

at javax.servlet.http.HttpServlet.service(HttpServlet.java:584)

at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:799)

at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:550)

at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:233)

at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1440)

at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:188)

at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:501)

at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:186)

at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1355)

at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)

at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127)

at org.eclipse.jetty.server.Server.handle(Server.java:516)

at org.eclipse.jetty.server.HttpChannel.lambda$handle$1(HttpChannel.java:487)

at org.eclipse.jetty.server.HttpChannel.dispatch(HttpChannel.java:732)

at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:479)

at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:277)

at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:311)

at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:105)

at org.eclipse.jetty.io.ssl.SslConnection$DecryptedEndPoint.onFillable(SslConnection.java:555)

at org.eclipse.jetty.io.ssl.SslConnection.onFillable(SslConnection.java:410)

at org.eclipse.jetty.io.ssl.SslConnection$2.succeeded(SslConnection.java:164)

at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:105)

at org.eclipse.jetty.io.ChannelEndPoint$1.run(ChannelEndPoint.java:104)

at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:338)

at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:315)

at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:173)

at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:131)

at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:409)

at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:883)

at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:1034)

at java.base/java.lang.Thread.run(Thread.java:833)

Caused by: java.net.ConnectException

at java.net.http/jdk.internal.net.http.common.Utils.toConnectException(Utils.java:1047)

at java.net.http/jdk.internal.net.http.PlainHttpConnection.connectAsync(PlainHttpConnection.java:198)

at java.net.http/jdk.internal.net.http.PlainHttpConnection.checkRetryConnect(PlainHttpConnection.java:230)

at java.net.http/jdk.internal.net.http.PlainHttpConnection.lambda$connectAsync$1(PlainHttpConnection.java:206)

at java.base/java.util.concurrent.CompletableFuture.uniHandle(CompletableFuture.java:934)

at java.base/java.util.concurrent.CompletableFuture$UniHandle.tryFire(CompletableFuture.java:911)

at java.base/java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:510)

at java.base/java.util.concurrent.CompletableFuture$AsyncSupply.run(CompletableFuture.java:1773)

at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)

at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)

... 1 more

Caused by: java.nio.channels.ClosedChannelException

at java.base/sun.nio.ch.SocketChannelImpl.ensureOpen(SocketChannelImpl.java:195)

at java.base/sun.nio.ch.SocketChannelImpl.beginConnect(SocketChannelImpl.java:760)

at java.base/sun.nio.ch.SocketChannelImpl.connect(SocketChannelImpl.java:848)

at java.net.http/jdk.internal.net.http.PlainHttpConnection.lambda$connectAsync$0(PlainHttpConnection.java:183)

at java.base/java.security.AccessController.doPrivileged(AccessController.java:569)

at java.net.http/jdk.internal.net.http.PlainHttpConnection.connectAsync(PlainHttpConnection.java:185)

... 9 more

 ###

2022-05-15 15:15:02.731 ERROR 1 --- [qtp929881100-46] o.a.c.p.FatalFallbackErrorHandler        : Exception occurred while trying to handle previously thrown exception on exchangeId: D5BA342F6DB190F-0000000000000004 using: [null]. The previous and the new exception will be logged in the following.

2022-05-15 15:15:02.733 ERROR 1 --- [qtp929881100-46] o.a.c.p.FatalFallbackErrorHandler        : \--> Previous exception on exchangeId: D5BA342F6DB190F-0000000000000004

de.fhg.aisec.ids.idscp2.idscp_core.error.DatException: Error whilst retrieving DAT

at de.fhg.aisec.ids.idscp2.default_drivers.daps.aisec_daps.AisecDapsDriver.getToken(AisecDapsDriver.kt:342) ~[idscp2-0.10.3.jar:na]

at de.fhg.aisec.ids.clearinghouse.ClearingHouseOutputProcessor$Companion.processClearingHouseOutput(ClearingHouseOutputProcessor.kt:65) ~[clearing-house-processors.jar:na]

at de.fhg.aisec.ids.clearinghouse.ClearingHouseOutputProcessor.process(ClearingHouseOutputProcessor.kt:40) ~[clearing-house-processors.jar:na]

at org.apache.camel.support.processor.DelegateSyncProcessor.process(DelegateSyncProcessor.java:65) ~[camel-support-3.16.0.jar:3.16.0]

at org.apache.camel.support.processor.DelegateAsyncProcessor.process(DelegateAsyncProcessor.java:104) ~[camel-support-3.16.0.jar:3.16.0]

at de.fhg.aisec.ids.dataflowcontrol.PolicyEnforcementPoint.process(PolicyEnforcementPoint.kt:201) ~[ids-dataflow-control-6.3.0.jar:na]

at org.apache.camel.support.processor.DelegateAsyncProcessor.process(DelegateAsyncProcessor.java:104) ~[camel-support-3.16.0.jar:3.16.0]

at org.apache.camel.processor.errorhandler.RedeliveryErrorHandler$RedeliveryTask.doRun(RedeliveryErrorHandler.java:812) ~[camel-core-processor-3.16.0.jar:3.16.0]

at org.apache.camel.processor.errorhandler.RedeliveryErrorHandler$RedeliveryTask.run(RedeliveryErrorHandler.java:720) ~[camel-core-processor-3.16.0.jar:3.16.0]

at org.apache.camel.impl.engine.DefaultReactiveExecutor$Worker.schedule(DefaultReactiveExecutor.java:193) ~[camel-base-engine-3.16.0.jar:3.16.0]

at org.apache.camel.impl.engine.DefaultReactiveExecutor.scheduleMain(DefaultReactiveExecutor.java:64) ~[camel-base-engine-3.16.0.jar:3.16.0]

at org.apache.camel.processor.Pipeline.process(Pipeline.java:184) ~[camel-core-processor-3.16.0.jar:3.16.0]

at org.apache.camel.impl.engine.CamelInternalProcessor.process(CamelInternalProcessor.java:399) ~[camel-base-engine-3.16.0.jar:3.16.0]

at org.apache.camel.component.jetty.CamelContinuationServlet.doService(CamelContinuationServlet.java:245) ~[camel-jetty-common-3.16.0.jar:3.16.0]

at org.apache.camel.http.common.CamelServlet.service(CamelServlet.java:130) ~[camel-http-common-3.16.0.jar:3.16.0]

at javax.servlet.http.HttpServlet.service(HttpServlet.java:584) ~[jakarta.servlet-api-4.0.4.jar:4.0.4]

at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:799) ~[jetty-servlet-9.4.45.v20220203.jar:9.4.45.v20220203]

at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:550) ~[jetty-servlet-9.4.45.v20220203.jar:9.4.45.v20220203]

at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:233) ~[jetty-server-9.4.45.v20220203.jar:9.4.45.v20220203]

at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1440) ~[jetty-server-9.4.45.v20220203.jar:9.4.45.v20220203]

at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:188) ~[jetty-server-9.4.45.v20220203.jar:9.4.45.v20220203]

at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:501) ~[jetty-servlet-9.4.45.v20220203.jar:9.4.45.v20220203]

at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:186) ~[jetty-server-9.4.45.v20220203.jar:9.4.45.v20220203]

at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1355) ~[jetty-server-9.4.45.v20220203.jar:9.4.45.v20220203]

at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141) ~[jetty-server-9.4.45.v20220203.jar:9.4.45.v20220203]

at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127) ~[jetty-server-9.4.45.v20220203.jar:9.4.45.v20220203]

at org.eclipse.jetty.server.Server.handle(Server.java:516) ~[jetty-server-9.4.45.v20220203.jar:9.4.45.v20220203]

at org.eclipse.jetty.server.HttpChannel.lambda$handle$1(HttpChannel.java:487) ~[jetty-server-9.4.45.v20220203.jar:9.4.45.v20220203]

at org.eclipse.jetty.server.HttpChannel.dispatch(HttpChannel.java:732) ~[jetty-server-9.4.45.v20220203.jar:9.4.45.v20220203]

at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:479) ~[jetty-server-9.4.45.v20220203.jar:9.4.45.v20220203]

at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:277) ~[jetty-server-9.4.45.v20220203.jar:9.4.45.v20220203]

at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:311) ~[jetty-io-9.4.45.v20220203.jar:9.4.45.v20220203]

at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:105) ~[jetty-io-9.4.45.v20220203.jar:9.4.45.v20220203]

at org.eclipse.jetty.io.ssl.SslConnection$DecryptedEndPoint.onFillable(SslConnection.java:555) ~[jetty-io-9.4.45.v20220203.jar:9.4.45.v20220203]

at org.eclipse.jetty.io.ssl.SslConnection.onFillable(SslConnection.java:410) ~[jetty-io-9.4.45.v20220203.jar:9.4.45.v20220203]

at org.eclipse.jetty.io.ssl.SslConnection$2.succeeded(SslConnection.java:164) ~[jetty-io-9.4.45.v20220203.jar:9.4.45.v20220203]

at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:105) ~[jetty-io-9.4.45.v20220203.jar:9.4.45.v20220203]

at org.eclipse.jetty.io.ChannelEndPoint$1.run(ChannelEndPoint.java:104) ~[jetty-io-9.4.45.v20220203.jar:9.4.45.v20220203]

at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:338) ~[jetty-util-9.4.45.v20220203.jar:9.4.45.v20220203]

at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:315) ~[jetty-util-9.4.45.v20220203.jar:9.4.45.v20220203]

at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:173) ~[jetty-util-9.4.45.v20220203.jar:9.4.45.v20220203]

at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:131) ~[jetty-util-9.4.45.v20220203.jar:9.4.45.v20220203]

at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:409) ~[jetty-util-9.4.45.v20220203.jar:9.4.45.v20220203]

at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:883) ~[jetty-util-9.4.45.v20220203.jar:9.4.45.v20220203]

at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:1034) ~[jetty-util-9.4.45.v20220203.jar:9.4.45.v20220203]

at java.base/java.lang.Thread.run(Thread.java:833) ~[na:na]

Caused by: java.net.ConnectException: null

at java.net.http/jdk.internal.net.http.common.Utils.toConnectException(Utils.java:1047) ~[java.net.http:na]

at java.net.http/jdk.internal.net.http.PlainHttpConnection.connectAsync(PlainHttpConnection.java:198) ~[java.net.http:na]

at java.net.http/jdk.internal.net.http.PlainHttpConnection.checkRetryConnect(PlainHttpConnection.java:230) ~[java.net.http:na]

at java.net.http/jdk.internal.net.http.PlainHttpConnection.lambda$connectAsync$1(PlainHttpConnection.java:206) ~[java.net.http:na]

at java.base/java.util.concurrent.CompletableFuture.uniHandle(CompletableFuture.java:934) ~[na:na]

at java.base/java.util.concurrent.CompletableFuture$UniHandle.tryFire(CompletableFuture.java:911) ~[na:na]

at java.base/java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:510) ~[na:na]

at java.base/java.util.concurrent.CompletableFuture$AsyncSupply.run(CompletableFuture.java:1773) ~[na:na]

at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) ~[na:na]

at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) ~[na:na]

... 1 common frames omitted

Caused by: java.nio.channels.ClosedChannelException: null

at java.base/sun.nio.ch.SocketChannelImpl.ensureOpen(SocketChannelImpl.java:195) ~[na:na]

at java.base/sun.nio.ch.SocketChannelImpl.beginConnect(SocketChannelImpl.java:760) ~[na:na]

at java.base/sun.nio.ch.SocketChannelImpl.connect(SocketChannelImpl.java:848) ~[na:na]

at java.net.http/jdk.internal.net.http.PlainHttpConnection.lambda$connectAsync$0(PlainHttpConnection.java:183) ~[java.net.http:na]

at java.base/java.security.AccessController.doPrivileged(AccessController.java:569) ~[na:na]

at java.net.http/jdk.internal.net.http.PlainHttpConnection.connectAsync(PlainHttpConnection.java:185) ~[java.net.http:na]

... 9 common frames omitted

2022-05-15 15:15:02.737 ERROR 1 --- [qtp929881100-46] o.a.c.p.FatalFallbackErrorHandler        : \--> New exception on exchangeId: D5BA342F6DB190F-0000000000000004

org.apache.camel.language.bean.RuntimeBeanExpressionException: Failed to invoke method: stacktrace on null due to: org.apache.camel.component.bean.MethodNotFoundException: Method with name: stacktrace not found on bean: java.net.ConnectException of type: java.net.ConnectException on the exchange: Exchange[D5BA342F6DB190F-0000000000000004]

at org.apache.camel.language.bean.BeanExpression.invokeOgnlMethod(BeanExpression.java:453) ~[camel-bean-3.16.0.jar:3.16.0]

at org.apache.camel.language.bean.BeanExpression.evaluate(BeanExpression.java:199) ~[camel-bean-3.16.0.jar:3.16.0]

at org.apache.camel.language.bean.BeanExpression.evaluate(BeanExpression.java:214) ~[camel-bean-3.16.0.jar:3.16.0]

at org.apache.camel.language.simple.SimpleExpressionBuilder$31.evaluate(SimpleExpressionBuilder.java:912) ~[camel-core-languages-3.16.0.jar:3.16.0]

at org.apache.camel.support.ExpressionAdapter.evaluate(ExpressionAdapter.java:45) ~[camel-support-3.16.0.jar:3.16.0]

at org.apache.camel.support.builder.ExpressionBuilder$51.evaluate(ExpressionBuilder.java:1560) ~[camel-support-3.16.0.jar:3.16.0]

at org.apache.camel.support.ExpressionAdapter.evaluate(ExpressionAdapter.java:45) ~[camel-support-3.16.0.jar:3.16.0]

at org.apache.camel.processor.LogProcessor.process(LogProcessor.java:71) ~[camel-core-processor-3.16.0.jar:3.16.0]

at org.apache.camel.support.processor.DelegateAsyncProcessor.process(DelegateAsyncProcessor.java:104) ~[camel-support-3.16.0.jar:3.16.0]

at de.fhg.aisec.ids.dataflowcontrol.PolicyEnforcementPoint.process(PolicyEnforcementPoint.kt:201) ~[ids-dataflow-control-6.3.0.jar:na]

at org.apache.camel.support.processor.DelegateAsyncProcessor.process(DelegateAsyncProcessor.java:104) ~[camel-support-3.16.0.jar:3.16.0]

at org.apache.camel.impl.engine.CamelInternalProcessor.process(CamelInternalProcessor.java:399) ~[camel-base-engine-3.16.0.jar:3.16.0]

at org.apache.camel.processor.Pipeline$PipelineTask.run(Pipeline.java:109) ~[camel-core-processor-3.16.0.jar:3.16.0]

at org.apache.camel.impl.engine.DefaultReactiveExecutor$Worker.schedule(DefaultReactiveExecutor.java:193) ~[camel-base-engine-3.16.0.jar:3.16.0]

at org.apache.camel.impl.engine.DefaultReactiveExecutor.scheduleMain(DefaultReactiveExecutor.java:64) ~[camel-base-engine-3.16.0.jar:3.16.0]

at org.apache.camel.processor.Pipeline.process(Pipeline.java:184) ~[camel-core-processor-3.16.0.jar:3.16.0]

at org.apache.camel.impl.engine.CamelInternalProcessor.process(CamelInternalProcessor.java:399) ~[camel-base-engine-3.16.0.jar:3.16.0]

at org.apache.camel.component.jetty.CamelContinuationServlet.doService(CamelContinuationServlet.java:245) ~[camel-jetty-common-3.16.0.jar:3.16.0]

at org.apache.camel.http.common.CamelServlet.service(CamelServlet.java:130) ~[camel-http-common-3.16.0.jar:3.16.0]

at javax.servlet.http.HttpServlet.service(HttpServlet.java:584) ~[jakarta.servlet-api-4.0.4.jar:4.0.4]

at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:799) ~[jetty-servlet-9.4.45.v20220203.jar:9.4.45.v20220203]

at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:550) ~[jetty-servlet-9.4.45.v20220203.jar:9.4.45.v20220203]

at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:233) ~[jetty-server-9.4.45.v20220203.jar:9.4.45.v20220203]

at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1440) ~[jetty-server-9.4.45.v20220203.jar:9.4.45.v20220203]

at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:188) ~[jetty-server-9.4.45.v20220203.jar:9.4.45.v20220203]

at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:501) ~[jetty-servlet-9.4.45.v20220203.jar:9.4.45.v20220203]

at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:186) ~[jetty-server-9.4.45.v20220203.jar:9.4.45.v20220203]

at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1355) ~[jetty-server-9.4.45.v20220203.jar:9.4.45.v20220203]

at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141) ~[jetty-server-9.4.45.v20220203.jar:9.4.45.v20220203]

at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127) ~[jetty-server-9.4.45.v20220203.jar:9.4.45.v20220203]

at org.eclipse.jetty.server.Server.handle(Server.java:516) ~[jetty-server-9.4.45.v20220203.jar:9.4.45.v20220203]

at org.eclipse.jetty.server.HttpChannel.lambda$handle$1(HttpChannel.java:487) ~[jetty-server-9.4.45.v20220203.jar:9.4.45.v20220203]

at org.eclipse.jetty.server.HttpChannel.dispatch(HttpChannel.java:732) ~[jetty-server-9.4.45.v20220203.jar:9.4.45.v20220203]

at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:479) ~[jetty-server-9.4.45.v20220203.jar:9.4.45.v20220203]

at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:277) ~[jetty-server-9.4.45.v20220203.jar:9.4.45.v20220203]

at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:311) ~[jetty-io-9.4.45.v20220203.jar:9.4.45.v20220203]

at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:105) ~[jetty-io-9.4.45.v20220203.jar:9.4.45.v20220203]

at org.eclipse.jetty.io.ssl.SslConnection$DecryptedEndPoint.onFillable(SslConnection.java:555) ~[jetty-io-9.4.45.v20220203.jar:9.4.45.v20220203]

at org.eclipse.jetty.io.ssl.SslConnection.onFillable(SslConnection.java:410) ~[jetty-io-9.4.45.v20220203.jar:9.4.45.v20220203]

at org.eclipse.jetty.io.ssl.SslConnection$2.succeeded(SslConnection.java:164) ~[jetty-io-9.4.45.v20220203.jar:9.4.45.v20220203]

at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:105) ~[jetty-io-9.4.45.v20220203.jar:9.4.45.v20220203]

at org.eclipse.jetty.io.ChannelEndPoint$1.run(ChannelEndPoint.java:104) ~[jetty-io-9.4.45.v20220203.jar:9.4.45.v20220203]

at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:338) ~[jetty-util-9.4.45.v20220203.jar:9.4.45.v20220203]

at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:315) ~[jetty-util-9.4.45.v20220203.jar:9.4.45.v20220203]

at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:173) ~[jetty-util-9.4.45.v20220203.jar:9.4.45.v20220203]

at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:131) ~[jetty-util-9.4.45.v20220203.jar:9.4.45.v20220203]

at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:409) ~[jetty-util-9.4.45.v20220203.jar:9.4.45.v20220203]

at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:883) ~[jetty-util-9.4.45.v20220203.jar:9.4.45.v20220203]

at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:1034) ~[jetty-util-9.4.45.v20220203.jar:9.4.45.v20220203]

at java.base/java.lang.Thread.run(Thread.java:833) ~[na:na]

Caused by: org.apache.camel.component.bean.MethodNotFoundException: Method with name: stacktrace not found on bean: java.net.ConnectException of type: java.net.ConnectException on the exchange: Exchange[D5BA342F6DB190F-0000000000000004]

at org.apache.camel.component.bean.BeanInfo.createInvocation(BeanInfo.java:263) ~[camel-bean-3.16.0.jar:3.16.0]

at org.apache.camel.component.bean.AbstractBeanProcessor.process(AbstractBeanProcessor.java:126) ~[camel-bean-3.16.0.jar:3.16.0]

at org.apache.camel.impl.engine.DefaultAsyncProcessorAwaitManager.process(DefaultAsyncProcessorAwaitManager.java:83) ~[camel-base-engine-3.16.0.jar:3.16.0]

at org.apache.camel.support.AsyncProcessorSupport.process(AsyncProcessorSupport.java:41) ~[camel-support-3.16.0.jar:3.16.0]

at org.apache.camel.language.bean.BeanExpression.invokeBean(BeanExpression.java:347) ~[camel-bean-3.16.0.jar:3.16.0]

at org.apache.camel.language.bean.BeanExpression.invokeOgnlMethod(BeanExpression.java:449) ~[camel-bean-3.16.0.jar:3.16.0]

... 49 common frames omitted
boxer-code commented 2 years ago

If I change the TC_DAPS_URL to the default url of the Fraunhofer Institut, I'm getting errors as well. Do you think they could hint towards a common error? The obtained logs are:

2022-05-15 18:50:29.662 DEBUG 1 --- [qtp553961412-47] d.f.a.i.c.m.MultiPartStringParser        : Found header:

{

  "@context" : {

    "ids" : "https://w3id.org/idsa/core/",

    "idsc" : "https://w3id.org/idsa/code/"

  },

  "@type" : "ids:LogMessage",

  "@id" : "https://w3id.org/idsa/autogen/logMessage/70961ba1-9ef8-48e8-942c-6d6e4d6d5cf3",

  "ids:modelVersion" : "4.2.7",

  "ids:issued" : {

    "@value" : "2022-05-15T18:50:29.625Z",

    "@type" : "http://www.w3.org/2001/XMLSchema#dateTimeStamp"

  },

  "ids:issuerConnector" : {

    "@id" : "https://w3id.org/idsa/autogen/baseConnector/7b934432-a85e-41c5-9f65-669219dde4ea"

  },

  "ids:recipientConnector" : [ {

    "@id" : "https://consumer-core:9999/messages/log/4f840e7e-b798-4231-95ee-cfb24a723323"

  } ],

  "ids:senderAgent" : {

    "@id" : "https://w3id.org/idsa/autogen/baseConnector/7b934432-a85e-41c5-9f65-669219dde4ea"

  },

  "ids:securityToken" : {

    "@type" : "ids:DynamicAttributeToken",

    "@id" : "https://w3id.org/idsa/autogen/dynamicAttributeToken/fc56cef2-18d8-491e-9409-ef082eecccbf",

    "ids:tokenValue" : "eyJ0eXAiOiJKV1QiLCJraWQiOiJkZWZhdWx0IiwiYWxnIjoiUlMyNTYifQ.eyJzY29wZXMiOlsiaWRzYzpJRFNfQ09OTkVDVE9SX0FUVFJJQlVURVNfQUxMIl0sImF1ZCI6Imlkc2M6SURTX0NPTk5FQ1RPUlNfQUxMIiwiaXNzIjoiaHR0cDovL29tZWpkbjo0NTY3IiwibmJmIjoxNjUyNjQwNDYwLCJpYXQiOjE2NTI2NDA0NjAsImp0aSI6Ik1UUXpNemMxTXpNMU5qWXdPVFk0TlRVNE9EZz0iLCJleHAiOjE2NTI2NDQwNjAsInNlY3VyaXR5UHJvZmlsZSI6Imlkc2M6QkFTRV9TRUNVUklUWV9QUk9GSUxFIiwicmVmZXJyaW5nQ29ubmVjdG9yIjoiaHR0cDovL3Rlc3RiZWQxLmRlbW8iLCJAdHlwZSI6ImlkczpEYXRQYXlsb2FkIiwiQGNvbnRleHQiOiJodHRwczovL3czaWQub3JnL2lkc2EvY29udGV4dHMvY29udGV4dC5qc29ubGQiLCJ0cmFuc3BvcnRDZXJ0c1NoYTI1NiI6ImM2OGQ5ZTZiYTNmMTc5OWJjYmU1YmVjOWQ3ZDk4YjE1YjBlZjJmMjkyYzgwZjZiY2E5OTQxNzhhYTk1YWUxMGQiLCJzdWIiOiI2NjowNzpFRDpFNTo4MDpFNDoyOTo2RDoxRTpERDpGNzo0MzpDQTowRTpFQjozODozMjpDODozQTo0MzprZXlpZDowNzpGQzo5NToxNzpDNDo5NTpCOTpFNDpBRDowOTo1RjowNzoxRTpEMjoyMDo3NToyRDo4OTo2Njo4NSJ9.wUlZVnvqW76yC5WZA5CH9_QjgL7b_4dA-ukTGG63t23l1Rs9S2_DW0Y3IjPS8hdrUxgFItx5Sc9ZoSGILuawbwWrO_nX7DSxwExFz8NtMID9KEfgXVMh4ghdP50rND2WuFE4dENvfOn_qRkcMLZL0qnsil0JF6AgDP8Y5bpDTHKFDgPoln-DezP4rSZj-khnUuTiXaUgx-EVMoCE0tYhcd-4h1zf80NExTue4nPcsNGWFPjhTWy9pnzj9-HZ_NRuYIbVYg3Yv-MO9RfLLEBzuvTo1WR1CCVSBiZo9q9LXm-6DuN6BB5c1BZ5Pi9seblsobn9f5g9Xqr_j3x84xkvmQ",

    "ids:tokenFormat" : {

      "@id" : "https://w3id.org/idsa/code/JWT"

    }

  }

}

2022-05-15 18:50:29.662 DEBUG 1 --- [qtp553961412-47] d.f.a.i.c.m.MultiPartStringParser        : Found body with Content-Type "application/ld+json; charset=utf-8"

2022-05-15 18:50:29.713 DEBUG 1 --- [qtp553961412-47] c.ClearingHouseInfomodelParsingProcessor : Using Charset from Content-Type header: utf-8

2022-05-15 18:50:29.811 DEBUG 1 --- [qtp553961412-47] d.f.a.i.i.d.d.a.AisecDapsDriver          : AKI: CB:8C:C7:B6:85:79:A8:23:A6:CB:15:AB:17:50:2F:E6:65:43:5D:E8:

2022-05-15 18:50:29.812 DEBUG 1 --- [qtp553961412-47] d.f.a.i.i.d.d.a.AisecDapsDriver          : SKI: A5:0C:A5:F0:84:D9:90:BB:BC:D9:57:3A:04:C8:7F:93:ED:97:A2:52:

2022-05-15 18:50:29.921  INFO 1 --- [qtp553961412-47] d.f.a.i.i.d.d.a.AisecDapsDriver          : Retrieving Dynamic Attribute Token from DAPS ...

2022-05-15 18:50:29.921 DEBUG 1 --- [qtp553961412-47] d.f.a.i.i.d.d.a.AisecDapsDriver          : ConnectorUUID: A5:0C:A5:F0:84:D9:90:BB:BC:D9:57:3A:04:C8:7F:93:ED:97:A2:52:keyid:CB:8C:C7:B6:85:79:A8:23:A6:CB:15:AB:17:50:2F:E6:65:43:5D:E8

2022-05-15 18:50:30.209 DEBUG 1 --- [qtp553961412-47] d.f.a.i.i.d.d.a.AisecDapsDriver          : Acquired DAT from https://daps.aisec.fraunhofer.de/v2/token

2022-05-15 18:50:30.209 DEBUG 1 --- [qtp553961412-47] d.f.a.i.i.d.d.a.AisecDapsDriver          : Received DAT from DAPS: eyJ0eXAiOiJhdCtqd3QiLCJraWQiOiJUQ1VGZUNOYXphbEtIZzlLenJ6TElBelJXVE1ERFdTYTdMY005WndITXlvIiwiYWxnIjoiUlMyNTYifQ.eyJhdWQiOiJpZHNjOklEU19DT05ORUNUT1JTX0FMTCIsImlzcyI6Imh0dHBzOi8vZGFwcy5haXNlYy5mcmF1bmhvZmVyLmRlIiwic3ViIjoiQTU6MEM6QTU6RjA6ODQ6RDk6OTA6QkI6QkM6RDk6NTc6M0E6MDQ6Qzg6N0Y6OTM6RUQ6OTc6QTI6NTI6a2V5aWQ6Q0I6OEM6Qzc6QjY6ODU6Nzk6QTg6MjM6QTY6Q0I6MTU6QUI6MTc6NTA6MkY6RTY6NjU6NDM6NUQ6RTgiLCJuYmYiOjE2NTI2NDA2MzAsImlhdCI6MTY1MjY0MDYzMCwianRpIjoiTnpFMU1ETTVNalV6Tmprek1qTTBNRFkwTUE9PSIsImV4cCI6MTY1MjY0NDIzMCwiY2xpZW50X2lkIjoiQTU6MEM6QTU6RjA6ODQ6RDk6OTA6QkI6QkM6RDk6NTc6M0E6MDQ6Qzg6N0Y6OTM6RUQ6OTc6QTI6NTI6a2V5aWQ6Q0I6OEM6Qzc6QjY6ODU6Nzk6QTg6MjM6QTY6Q0I6MTU6QUI6MTc6NTA6MkY6RTY6NjU6NDM6NUQ6RTgiLCJzZWN1cml0eVByb2ZpbGUiOiJpZHNjOlRSVVNUX1NFQ1VSSVRZX1BST0ZJTEUiLCJyZWZlcnJpbmdDb25uZWN0b3IiOiJodHRwOi8vY29uc3VtZXItY29yZS5kZW1vIiwiQHR5cGUiOiJpZHM6RGF0UGF5bG9hZCIsIkBjb250ZXh0IjoiaHR0cHM6Ly93M2lkLm9yZy9pZHNhL2NvbnRleHRzL2NvbnRleHQuanNvbmxkIiwidHJhbnNwb3J0Q2VydHNTaGEyNTYiOiJjMTVlNjU1ODA4OGRiZmVmMjE1YTQzZDI1MDdiYmQxMjRmNDRmYjhmYWNkNTYxYzE0NTYxYTJjMWE2NjlkMGUwIiwic2NvcGVzIjpbImlkc2M6SURTX0NPTk5FQ1RPUl9BVFRSSUJVVEVTX0FMTCJdfQ.BuMPMFL2BFYxJo07Eoe5kNBf6hNjEPSDNMf-dnHujJORzZ4akf3a751xPK-1aLHWuiTGGrsHTS4Zq0HnC8ACNKqyW12L7WOfIDYqXhOGd9NIwvgj4b0CJQGNJUvIF9BH-fIbxFJgWZ3hGvETNtB_bc3yb_P1jVDYofXonwllf0d0WEKmMwvY_AtD7WWnePB9RuijimGaH9VhqBnnAQrjp51qCyRxQRUPo-mb12GFXiuOtYqkYiSTwO5C4Cj1nGnxflK30EYAWhZzmklQBLCEHtGA9yj3SRkTO2dhSUW214NDj8qTQHUo1j2iLCtZ67GNWZIVnqQ3slbz2CsU-1-7PA

2022-05-15 18:50:30.209 DEBUG 1 --- [qtp553961412-47] d.f.a.i.i.d.d.a.AisecDapsDriver          : Verifying dynamic attribute token...

2022-05-15 18:50:30.216 DEBUG 1 --- [qtp553961412-47] d.f.a.i.i.d.d.a.AisecDapsDriver          : DAT is valid for 3600 seconds

2022-05-15 18:50:30.218 ERROR 1 --- [qtp553961412-47] d.f.a.ids.clearinghouse.Configuration    : Configuration invalid: Missing TC_CH_ISSUER_CONNECTOR

2022-05-15 18:50:30.219 ERROR 1 --- [qtp553961412-47] d.f.a.ids.clearinghouse.Configuration    : Configuration invalid: Missing TC_CH_AGENT

2022-05-15 18:50:30.226  WARN 1 --- [qtp553961412-47] d.f.a.i.c.MultipartOutputProcessor       : Status Code: 401 with Payload: Token not valid!
kragall commented 2 years ago

With the default_url set to the Fraunhofer DAPS there are two things that I can see in the logs:

  1. Your TC is missing the environment variables TC_CH_ISSUER_CONNECTORand TC_CH_AGENT. Both are mandatory and if not set will result in an error later on.
  2. You changed the DAPS url of the TC, but didn't change the DAPS url in the Rocket.toml files of the APIs. They currently also check if the jwt token is valid, i.e. TC and APIs use different DAPS to validate your token.
boxer-code commented 2 years ago

Thanks! Could you give me an example how I need to configure the missing variables? I didn't find an example in the Information Model.

kragall commented 2 years ago

I'm not aware of a standardization when it comes to what those variables should contain. The only thing I can tell you is that the serializer of the information model only accepts URIs as values of these variables. So currently, any URI that identifies your Clearing House should work

boxer-code commented 2 years ago

Ok thanks! That solved this error. I've changed back to my own omejdn server and now I'm getting the error message that the trusted connector tries to connect to http://omejdn/.well-known/oauth-authorization-server and gets an 404. I think that my server only can handle http://omejdn/auth/jwks.json. Do you know how to fix this? These are the obtained logs of the omejdn-server:

2022/05/18 14:58:56 [error] 37#37: *51 open() "/etc/nginx/html/.well-known/oauth-authorization-server" failed (2: No such file or directory), client: 172.18.0.5, server: omejdn, request: "GET /.well-known/oauth-authorization-server HTTP/1.1", host: "omejdn"

And the obtained logs of the trusted connector:

2022-05-18 15:04:39.440 DEBUG 1 --- [tp1065096518-46] d.f.a.i.i.d.d.a.AisecDapsDriver          : ConnectorUUID: A5:0C:A5:F0:84:D9:90:BB:BC:D9:57:3A:04:C8:7F:93:ED:97:A2:52:keyid:CB:8C:C7:B6:85:79:A8:23:A6:CB:15:AB:17:50:2F:E6:65:43:5D:E8

2022-05-18 15:04:39.456 ERROR 1 --- [tp1065096518-46] o.a.c.p.e.DefaultErrorHandler            : Failed delivery for (MessageId: F42B3723A07FAF5-0000000000000002 on ExchangeId: F42B3723A07FAF5-0000000000000002). Exhausted after delivery attempt: 1 caught: de.fhg.aisec.ids.idscp2.idscp_core.error.DatException: Error whilst retrieving DAT

Message History (source location and message history is disabled)

---------------------------------------------------------------------------------------------------------------------------------------

Source                                   ID                             Processor                                          Elapsed (ms)

                                         CH_LOG_PID/CH_LOG_PID          from[jetty:https://0.0.0.0:9999/messages/log/%7Bpi          221

...

                                         CH_MULTIPART_ROUTE/process4    ref:CHOutputProcessor                                         0

Stacktrace

---------------------------------------------------------------------------------------------------------------------------------------

de.fhg.aisec.ids.idscp2.idscp_core.error.DatException: Error whilst retrieving DAT

at de.fhg.aisec.ids.idscp2.default_drivers.daps.aisec_daps.AisecDapsDriver.getToken(AisecDapsDriver.kt:342) ~[idscp2-0.10.3.jar:na]

at de.fhg.aisec.ids.clearinghouse.ClearingHouseOutputProcessor$Companion.processClearingHouseOutput(ClearingHouseOutputProcessor.kt:65) ~[clearing-house-processors.jar:na]

at de.fhg.aisec.ids.clearinghouse.ClearingHouseOutputProcessor.process(ClearingHouseOutputProcessor.kt:40) ~[clearing-house-processors.jar:na]

at org.apache.camel.support.processor.DelegateSyncProcessor.process(DelegateSyncProcessor.java:65) ~[camel-support-3.16.0.jar:3.16.0]

at org.apache.camel.support.processor.DelegateAsyncProcessor.process(DelegateAsyncProcessor.java:104) ~[camel-support-3.16.0.jar:3.16.0]

at de.fhg.aisec.ids.dataflowcontrol.PolicyEnforcementPoint.process(PolicyEnforcementPoint.kt:201) ~[ids-dataflow-control-6.3.0.jar:na]

at org.apache.camel.support.processor.DelegateAsyncProcessor.process(DelegateAsyncProcessor.java:104) ~[camel-support-3.16.0.jar:3.16.0]

at org.apache.camel.processor.errorhandler.RedeliveryErrorHandler$RedeliveryTask.doRun(RedeliveryErrorHandler.java:812) ~[camel-core-processor-3.16.0.jar:3.16.0]

at org.apache.camel.processor.errorhandler.RedeliveryErrorHandler$RedeliveryTask.run(RedeliveryErrorHandler.java:720) ~[camel-core-processor-3.16.0.jar:3.16.0]

at org.apache.camel.impl.engine.DefaultReactiveExecutor$Worker.schedule(DefaultReactiveExecutor.java:193) ~[camel-base-engine-3.16.0.jar:3.16.0]

at org.apache.camel.impl.engine.DefaultReactiveExecutor.scheduleMain(DefaultReactiveExecutor.java:64) ~[camel-base-engine-3.16.0.jar:3.16.0]

at org.apache.camel.processor.Pipeline.process(Pipeline.java:184) ~[camel-core-processor-3.16.0.jar:3.16.0]

at org.apache.camel.impl.engine.CamelInternalProcessor.process(CamelInternalProcessor.java:399) ~[camel-base-engine-3.16.0.jar:3.16.0]

at org.apache.camel.component.jetty.CamelContinuationServlet.doService(CamelContinuationServlet.java:245) ~[camel-jetty-common-3.16.0.jar:3.16.0]

at org.apache.camel.http.common.CamelServlet.service(CamelServlet.java:130) ~[camel-http-common-3.16.0.jar:3.16.0]

at javax.servlet.http.HttpServlet.service(HttpServlet.java:584) ~[jakarta.servlet-api-4.0.4.jar:4.0.4]

at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:799) ~[jetty-servlet-9.4.45.v20220203.jar:9.4.45.v20220203]

at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:550) ~[jetty-servlet-9.4.45.v20220203.jar:9.4.45.v20220203]

at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:233) ~[jetty-server-9.4.45.v20220203.jar:9.4.45.v20220203]

at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1440) ~[jetty-server-9.4.45.v20220203.jar:9.4.45.v20220203]

at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:188) ~[jetty-server-9.4.45.v20220203.jar:9.4.45.v20220203]

at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:501) ~[jetty-servlet-9.4.45.v20220203.jar:9.4.45.v20220203]

at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:186) ~[jetty-server-9.4.45.v20220203.jar:9.4.45.v20220203]

at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1355) ~[jetty-server-9.4.45.v20220203.jar:9.4.45.v20220203]

at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141) ~[jetty-server-9.4.45.v20220203.jar:9.4.45.v20220203]

at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127) ~[jetty-server-9.4.45.v20220203.jar:9.4.45.v20220203]

at org.eclipse.jetty.server.Server.handle(Server.java:516) ~[jetty-server-9.4.45.v20220203.jar:9.4.45.v20220203]

at org.eclipse.jetty.server.HttpChannel.lambda$handle$1(HttpChannel.java:487) ~[jetty-server-9.4.45.v20220203.jar:9.4.45.v20220203]

at org.eclipse.jetty.server.HttpChannel.dispatch(HttpChannel.java:732) ~[jetty-server-9.4.45.v20220203.jar:9.4.45.v20220203]

at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:479) ~[jetty-server-9.4.45.v20220203.jar:9.4.45.v20220203]

at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:277) ~[jetty-server-9.4.45.v20220203.jar:9.4.45.v20220203]

at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:311) ~[jetty-io-9.4.45.v20220203.jar:9.4.45.v20220203]

at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:105) ~[jetty-io-9.4.45.v20220203.jar:9.4.45.v20220203]

at org.eclipse.jetty.io.ssl.SslConnection$DecryptedEndPoint.onFillable(SslConnection.java:555) ~[jetty-io-9.4.45.v20220203.jar:9.4.45.v20220203]

at org.eclipse.jetty.io.ssl.SslConnection.onFillable(SslConnection.java:410) ~[jetty-io-9.4.45.v20220203.jar:9.4.45.v20220203]

at org.eclipse.jetty.io.ssl.SslConnection$2.succeeded(SslConnection.java:164) ~[jetty-io-9.4.45.v20220203.jar:9.4.45.v20220203]

at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:105) ~[jetty-io-9.4.45.v20220203.jar:9.4.45.v20220203]

at org.eclipse.jetty.io.ChannelEndPoint$1.run(ChannelEndPoint.java:104) ~[jetty-io-9.4.45.v20220203.jar:9.4.45.v20220203]

at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:338) ~[jetty-util-9.4.45.v20220203.jar:9.4.45.v20220203]

at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:315) ~[jetty-util-9.4.45.v20220203.jar:9.4.45.v20220203]

at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:173) ~[jetty-util-9.4.45.v20220203.jar:9.4.45.v20220203]

at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:131) ~[jetty-util-9.4.45.v20220203.jar:9.4.45.v20220203]

at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:409) ~[jetty-util-9.4.45.v20220203.jar:9.4.45.v20220203]

at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:883) ~[jetty-util-9.4.45.v20220203.jar:9.4.45.v20220203]

at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:1034) ~[jetty-util-9.4.45.v20220203.jar:9.4.45.v20220203]

at java.base/java.lang.Thread.run(Thread.java:833) ~[na:na]

Caused by: io.ktor.client.plugins.ClientRequestException: Client request(GET http://omejdn/.well-known/oauth-authorization-server) invalid: 404 Not Found. Text: "<html>

<head><title>404 Not Found</title></head>

<body>

<center><h1>404 Not Found</h1></center>

<hr><center>nginx/1.21.6</center>

</body>

</html>

"

at io.ktor.client.plugins.DefaultResponseValidationKt$addDefaultResponseValidation$1$1.invokeSuspend(DefaultResponseValidation.kt:47) ~[ktor-client-core-jvm-2.0.0-beta-1.jar:2.0.0-beta-1]

at io.ktor.client.plugins.DefaultResponseValidationKt$addDefaultResponseValidation$1$1.invoke(DefaultResponseValidation.kt) ~[ktor-client-core-jvm-2.0.0-beta-1.jar:2.0.0-beta-1]

at io.ktor.client.plugins.DefaultResponseValidationKt$addDefaultResponseValidation$1$1.invoke(DefaultResponseValidation.kt) ~[ktor-client-core-jvm-2.0.0-beta-1.jar:2.0.0-beta-1]

at io.ktor.client.plugins.HttpCallValidator.validateResponse(HttpCallValidator.kt:40) ~[ktor-client-core-jvm-2.0.0-beta-1.jar:2.0.0-beta-1]

at io.ktor.client.plugins.HttpCallValidator.access$validateResponse(HttpCallValidator.kt:33) ~[ktor-client-core-jvm-2.0.0-beta-1.jar:2.0.0-beta-1]

at io.ktor.client.plugins.HttpCallValidator$Companion$install$3.invokeSuspend(HttpCallValidator.kt:122) ~[ktor-client-core-jvm-2.0.0-beta-1.jar:2.0.0-beta-1]

at kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(ContinuationImpl.kt:33) ~[kotlin-stdlib-1.6.20.jar:1.6.20-release-275(1.6.20)]

at io.ktor.util.pipeline.SuspendFunctionGun.resumeRootWith(SuspendFunctionGun.kt:142) ~[ktor-utils-jvm-2.0.0-beta-1.jar:2.0.0-beta-1]

at io.ktor.util.pipeline.SuspendFunctionGun.loop(SuspendFunctionGun.kt:116) ~[ktor-utils-jvm-2.0.0-beta-1.jar:2.0.0-beta-1]

at io.ktor.util.pipeline.SuspendFunctionGun.access$loop(SuspendFunctionGun.kt:14) ~[ktor-utils-jvm-2.0.0-beta-1.jar:2.0.0-beta-1]

at io.ktor.util.pipeline.SuspendFunctionGun$continuation$1.resumeWith(SuspendFunctionGun.kt:62) ~[ktor-utils-jvm-2.0.0-beta-1.jar:2.0.0-beta-1]

at kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(ContinuationImpl.kt:46) ~[kotlin-stdlib-1.6.20.jar:1.6.20-release-275(1.6.20)]

at kotlinx.coroutines.DispatchedTask.run(DispatchedTask.kt:106) ~[kotlinx-coroutines-core-jvm-1.5.2.jar:na]

at kotlinx.coroutines.EventLoopImplBase.processNextEvent(EventLoop.common.kt:274) ~[kotlinx-coroutines-core-jvm-1.5.2.jar:na]

at kotlinx.coroutines.BlockingCoroutine.joinBlocking(Builders.kt:85) ~[kotlinx-coroutines-core-jvm-1.5.2.jar:na]

at kotlinx.coroutines.BuildersKt__BuildersKt.runBlocking(Builders.kt:59) ~[kotlinx-coroutines-core-jvm-1.5.2.jar:na]

at kotlinx.coroutines.BuildersKt.runBlocking(Unknown Source) ~[kotlinx-coroutines-core-jvm-1.5.2.jar:na]

at kotlinx.coroutines.BuildersKt__BuildersKt.runBlocking$default(Builders.kt:38) ~[kotlinx-coroutines-core-jvm-1.5.2.jar:na]

at kotlinx.coroutines.BuildersKt.runBlocking$default(Unknown Source) ~[kotlinx-coroutines-core-jvm-1.5.2.jar:na]

at de.fhg.aisec.ids.idscp2.default_drivers.daps.aisec_daps.AisecDapsDriver.getDapsMeta(AisecDapsDriver.kt:208) ~[idscp2-0.10.3.jar:na]

at de.fhg.aisec.ids.idscp2.default_drivers.daps.aisec_daps.AisecDapsDriver.getToken(AisecDapsDriver.kt:287) ~[idscp2-0.10.3.jar:na]

... 45 common frames omitted
bellebaum commented 2 years ago

Hi Are you using the latest version of Omejdn? If so, which address did you configure in the trusted connector?

boxer-code commented 2 years ago

Hi it seems to be fixed. I'm not sure about what caused the error but I'm using the latest version of the IDS-Testbed (https://github.com/International-Data-Spaces-Association/IDS-testbed). There is Omejdn version 1.6.0 with a nginx container used. The address configured is the url of the nginx container. I've changed a few things on the nginx side and now it seems to be working. Thanks for all the help!

AnaCarolinaChaves commented 2 years ago

Were you using the test bed DAPS when the error was happening? I'm using the IDS-Testbed and the error is being thrown.

boxer-code commented 2 years ago

Hi, yes I was using the IDS-Testbed Setup and had to change the configuration of the nginx container. I've added the following two lines in line 27/28 of the unchanged nginx.conf of the testbed DAPS: rewrite /.well-known/oauth-authorization-server ${OMEJDN_PATH}/.well-known/oauth-authorization-server last; rewrite /.well-known/oauth-authorization-server /.well-known/oauth-authorization-server last; This fixed the error in my configuration.

AnaCarolinaChaves commented 2 years ago

Thank you for the quick answer. I was already using the first line. However, adding the second did not solve the error.

boxer-code commented 2 years ago

Do you get the exact same error? Could you post the logs of the DAPS and the trusted-connector of the ch?

AnaCarolinaChaves commented 2 years ago

I'm having one of the older errors. It says that the DAT could not be retrieved because there was an error.

The request arrives at the DAPS, since I have two GETS on the proxy from the IP. The line on the logs is:

IP - - [20/Jun/2022:17:00:48 +0000] "GET /.well-known/jwks.json HTTP/1.1" 200 469 "-" "reqwest/0.9.24" "-"
IP - - [20/Jun/2022:17:00:48 +0000] "GET /.well-known/jwks.json HTTP/1.1" 200 469 "-" "reqwest/0.9.24" "-"

And the logs from the trusted connector of the CH say:

...
2022-06-20 15:23:13.596  INFO 1 --- [           main] de.fhg.aisec.ids.rm.XmlDeployWatcher     : XML file deploy/clearing-house-routes.xml detected, creating XmlApplicationContext...
2022-06-20 15:23:15.418  INFO 1 --- [       Thread-1] .a.c.c.x.AbstractCamelContextFactoryBean : Using custom TypeConverterRegistry: org.apache.camel.impl.converter.DefaultTypeConverter@57c17066
2022-06-20 15:23:15.427  INFO 1 --- [       Thread-1] .a.c.c.x.AbstractCamelContextFactoryBean : Using custom InterceptStrategy with id: idsCamelInterceptor and implementation: de.fhg.aisec.ids.dataflowcontrol.CamelInterceptor@74c23525
2022-06-20 15:23:15.474  INFO 1 --- [       Thread-1] o.a.c.management.JmxManagementStrategy   : JMX is enabled
2022-06-20 15:23:15.718 DEBUG 1 --- [       Thread-1] d.f.a.i.i.i.r.RaProverDriverRegistry     : Register 'Dummy' driver to RA prover registry
2022-06-20 15:23:15.719 DEBUG 1 --- [       Thread-1] d.f.a.i.i.i.r.RaProverDriverRegistry     : Register 'Dummy2' driver to RA prover registry
2022-06-20 15:23:15.720 DEBUG 1 --- [       Thread-1] d.f.a.i.i.i.r.RaVerifierDriverRegistry   : Register 'Dummy' driver to RA verifier registry
2022-06-20 15:23:15.721 DEBUG 1 --- [       Thread-1] d.f.a.i.i.i.r.RaVerifierDriverRegistry   : Register 'Dummy2' driver to RA verifier registry
2022-06-20 15:23:15.825  INFO 1 --- [       Thread-1] o.a.c.impl.engine.AbstractCamelContext   : Apache Camel 3.16.0 (camel-2) is starting
2022-06-20 15:23:16.036 DEBUG 1 --- [       Thread-1] d.f.a.i.c.i.server.Idscp2ServerEndpoint  : Starting IDSCP2 server endpoint idscp2server://0.0.0.0:29292?copyHeadersRegex=%28ch-ids-%5Ba-z%5D*%7CContent-Type%29&sslContextParameters=%23ChSslContext&useIdsMessages=true
2022-06-20 15:23:16.045  INFO 1 --- [       Thread-1] de.fhg.aisec.ids.TrustedConnector        : Found DAPS_URL env var, DAPS URL is overridden with http://vcese19.inesctec.pt:4567
2022-06-20 15:23:16.278 DEBUG 1 --- [       Thread-1] d.f.a.i.i.d.d.a.AisecDapsDriver          : AKI: C4:10:D7:AB:4B:F0:81:45:96:06:97:AD:2A:01:47:D0:C5:F0:45:AC:
2022-06-20 15:23:16.280 DEBUG 1 --- [       Thread-1] d.f.a.i.i.d.d.a.AisecDapsDriver          : SKI: C4:10:D7:AB:4B:F0:81:45:96:06:97:AD:2A:01:47:D0:C5:F0:45:AC:
2022-06-20 15:23:16.614  INFO 1 --- [       Thread-1] d.f.a.i.i.i.a.i.Idscp2ServerFactory      : Starting new IDSCP2 server
2022-06-20 15:23:16.910  INFO 1 --- [       Thread-1] org.eclipse.jetty.util.log               : Logging initialized @18740ms to org.eclipse.jetty.util.log.Slf4jLog
2022-06-20 15:23:16.925  INFO 1 --- [       Thread-1] o.a.c.support.jsse.SSLContextParameters  : Available providers: SUN version 17.
2022-06-20 15:23:17.099  INFO 1 --- [       Thread-1] o.a.c.c.jetty9.JettyHttpComponent9       : Connector on port: 9999 is using includeCipherSuites: [] excludeCipherSuites: [^.*_(MD5|SHA|SHA1)$, ^TLS_RSA_.*$, ^SSL_.*$, ^.*_NULL_.*$, ^.*_anon_.*$] includeProtocols: [] excludeProtocols: [SSL, SSLv2, SSLv2Hello, SSLv3]
2022-06-20 15:23:17.130  INFO 1 --- [       Thread-1] org.eclipse.jetty.server.Server          : jetty-9.4.45.v20220203; built: 2022-02-03T09:14:34.105Z; git: 4a0c91c0be53805e3fcffdcdcc9587d5301863db; jvm 17.0.2+8-Debian-1deb11u1
2022-06-20 15:23:17.201  INFO 1 --- [       Thread-1] o.e.jetty.server.handler.ContextHandler  : Started o.e.j.s.ServletContextHandler@2ab2b989{/,null,AVAILABLE}
2022-06-20 15:23:17.220  INFO 1 --- [       Thread-1] o.e.jetty.server.AbstractConnector       : Started ServerConnector@60e174d4{ssl, (ssl, http/1.1)}{0.0.0.0:9999}
2022-06-20 15:23:17.221  INFO 1 --- [       Thread-1] org.eclipse.jetty.server.Server          : Started @19052ms
2022-06-20 15:23:17.226  INFO 1 --- [       Thread-1] o.a.c.impl.engine.AbstractCamelContext   : Routes startup (total:6 started:6)
2022-06-20 15:23:17.227  INFO 1 --- [       Thread-1] o.a.c.impl.engine.AbstractCamelContext   :     Started CH_MULTIPART_ROUTE (direct://multipart)
2022-06-20 15:23:17.227  INFO 1 --- [       Thread-1] o.a.c.impl.engine.AbstractCamelContext   :     Started CH_IDSCP2_ROUTE (idscp2server://0.0.0.0:29292)
2022-06-20 15:23:17.228  INFO 1 --- [       Thread-1] o.a.c.impl.engine.AbstractCamelContext   :     Started CH_QUERY_PID (rest://post:/messages/query/%7Bpid%7D)
2022-06-20 15:23:17.229  INFO 1 --- [       Thread-1] o.a.c.impl.engine.AbstractCamelContext   :     Started CH_QUERY_PID_ID (rest://post:/messages/query/%7Bpid%7D/%7Bid%7D)
2022-06-20 15:23:17.229  INFO 1 --- [       Thread-1] o.a.c.impl.engine.AbstractCamelContext   :     Started CH_LOG_PID (rest://post:/messages/log/%7Bpid%7D)
2022-06-20 15:23:17.229  INFO 1 --- [       Thread-1] o.a.c.impl.engine.AbstractCamelContext   :     Started CH_CREATE_PID (rest://post:/process/%7Bpid%7D)
2022-06-20 15:23:17.230  INFO 1 --- [       Thread-1] o.a.c.impl.engine.AbstractCamelContext   : Apache Camel 3.16.0 (camel-2) started in 1s769ms (build:5ms init:360ms start:1s404ms)
2022-06-20 15:26:37.316 DEBUG 1 --- [qtp643001118-39] d.f.a.i.d.PolicyDecisionPoint            : Query for uncached label transformation: once(setof(S, action_service('From[rest://post:/process/%7Bpid%7D?consumerComponentName=jetty&routeId=CH_CREATE_PID]', S), SC); SC = []),
collect_creates_labels(SC, ACraw), set_of(ACraw, Adds),
collect_removes_labels(SC, RCraw), set_of(RCraw, Removes).
2022-06-20 15:26:37.569 DEBUG 1 --- [qtp643001118-39] d.f.a.i.d.lucon.LuconEngine              : Prolog library loaded de.fhg.aisec.ids.dataflowcontrol.lucon.LuconLibrary
2022-06-20 15:26:37.655 DEBUG 1 --- [qtp643001118-39] d.f.a.i.d.PolicyDecisionPoint            : Transformation: de.fhg.aisec.ids.api.policy.TransformationDecision@844c8cd
2022-06-20 15:26:37.698 DEBUG 1 --- [qtp643001118-39] d.f.a.i.d.PolicyDecisionPoint            : Query for uncached label transformation: once(setof(S, action_service('To[direct:multipart]', S), SC); SC = []),
collect_creates_labels(SC, ACraw), set_of(ACraw, Adds),
collect_removes_labels(SC, RCraw), set_of(RCraw, Removes).
2022-06-20 15:26:37.734 DEBUG 1 --- [qtp643001118-39] d.f.a.i.d.PolicyDecisionPoint            : Transformation: de.fhg.aisec.ids.api.policy.TransformationDecision@7fa942cb
2022-06-20 15:26:37.835 DEBUG 1 --- [qtp643001118-39] d.f.a.i.c.m.MultiPartStringParser        : Found header:
{
  "@context" : {
    "ids" : "https://w3id.org/idsa/core/",
    "idsc" : "https://w3id.org/idsa/code/"
  },
  "@type" : "ids:RequestMessage",
  "@id" : "https://w3id.org/idsa/autogen/requestMessage/50358895-c12b-485f-9570-dcc050c18998",
  "ids:modelVersion" : "4.2.7",
  "ids:issued" : {
    "@value" : "2022-06-20T15:26:36.825Z",
    "@type" : "http://www.w3.org/2001/XMLSchema#dateTimeStamp"
  },
  "ids:issuerConnector" : {
    "@id" : "https://vcese12.inesctec.pt:8080/stvgodigital/subcontracted-01"
  },
  "ids:recipientConnector" : [ {
    "@id" : "https://vcese19.inesctec.pt:8443/process/2d94d01c-15f1-4795-8041-4abb95436ad3"
  } ],
  "ids:senderAgent" : {
    "@id" : "https://vcese12.inesctec.pt:8080/stvgodigital/subcontracted-01"
  },
  "ids:securityToken" : {
    "@type" : "ids:DynamicAttributeToken",
    "@id" : "https://w3id.org/idsa/autogen/dynamicAttributeToken/ce1f34cd-49f7-4065-afa6-acaae3d3fd8f",
    "ids:tokenValue" : "eyJ0eXAiOiJhdCtqd3QiLCJraWQiOiI2MGJlZmYxYWQ2NjJlMzhmZDg5OTY2MzkyODZlM2MyNGUyYjM2NmU1MmY4N2Q4ODI1MWI4NTQwOTZlZjc4YzM5IiwiYWxnIjoiUlMyNTYifQ.eyJzY29wZSI6Imlkc2M6SURTX0NPTk5FQ1RPUl9BVFRSSUJVVEVTX0FMTCIsImF1ZCI6WyJpZHNjOklEU19DT05ORUNUT1JTX0FMTCJdLCJpc3MiOiJodHRwOi8vdmNlc2UxOS5pbmVzY3RlYy5wdDo0NTY3L2F1dGgiLCJzdWIiOiJENjpDNjpBMDpCMzo4QTpGODo4QzowNDpCMjo2OTo1MDo2QjozRDo1MDo4RjozQTo2MjpGNzo0MDpFMTprZXlpZDpENjpDNjpBMDpCMzo4QTpGODo4QzowNDpCMjo2OTo1MDo2QjozRDo1MDo4RjozQTo2MjpGNzo0MDpFMSIsIm5iZiI6MTY1NTczODc4MSwiaWF0IjoxNjU1NzM4NzgxLCJqdGkiOiIwZjhjMjg0MC04ZWMyLTRjMmMtODJmMC0yNzc3YzQ1NGE3ZDIiLCJleHAiOjE2NTU3NDIzODEsImNsaWVudF9pZCI6IkQ2OkM2OkEwOkIzOjhBOkY4OjhDOjA0OkIyOjY5OjUwOjZCOjNEOjUwOjhGOjNBOjYyOkY3OjQwOkUxOmtleWlkOkQ2OkM2OkEwOkIzOjhBOkY4OjhDOjA0OkIyOjY5OjUwOjZCOjNEOjUwOjhGOjNBOjYyOkY3OjQwOkUxIiwic2VjdXJpdHlQcm9maWxlIjoiaWRzYzpCQVNFX1NFQ1VSSVRZX1BST0ZJTEUiLCJyZWZlcnJpbmdDb25uZWN0b3IiOiJodHRwOi8vdmNlc2UxMi5kZW1vIiwiQHR5cGUiOiJpZHM6RGF0UGF5bG9hZCIsIkBjb250ZXh0IjoiaHR0cHM6Ly93M2lkLm9yZy9pZHNhL2NvbnRleHRzL2NvbnRleHQuanNvbmxkIiwidHJhbnNwb3J0Q2VydHNTaGEyNTYiOiI5M2ZkODAxZjY1YTdkYzQwNDY4ZWU5NzdhNWExMmRmMjcxYjhhNWZjOGQxYjExNzY5M2UyMWJhZmEwZWIxOWVlIn0.VzS_2li1rB8uD8ZUViylYnQhgWGNQ7-qW1htQLCic7CAldoQA26UOVdPRctE1Di_HUT8jYVB0miAJ8E8d2S8o5fAjA_AxTRQU-_yIjcPepS_M1jeleEm-e5b1-oxyxCfZ49Rhe_qLymBJYzJTNtm2_8FATtSXF02Sv4jwYP9Dg7hr56InO_VD_tuKEVTkjk_DuZGIWYbOuB9emKOX-LkjUMxWlBpxYQQeQ5rVOlriRpSjWdtMymacjhXg8gbjHgCQ92Qc3QxuZRnhgwKg_MgLyZ5WnitSD8OLh2N3AGm2uaOpKTvskMLqfC4PxAb6-XLWIfdJ7nM-jCVRoehVCK53g",
    "ids:tokenFormat" : {
      "@id" : "https://w3id.org/idsa/code/JWT"
    }
  }
}
2022-06-20 15:26:37.835 DEBUG 1 --- [qtp643001118-39] d.f.a.i.c.m.MultiPartStringParser        : Found body with Content-Type "application/json; charset=utf-8"
2022-06-20 15:26:37.839 DEBUG 1 --- [qtp643001118-39] d.f.a.i.d.PolicyDecisionPoint            : Query for uncached label transformation: once(setof(S, action_service('process[ref:MultipartInputProcessor]', S), SC); SC = []),
collect_creates_labels(SC, ACraw), set_of(ACraw, Adds),
collect_removes_labels(SC, RCraw), set_of(RCraw, Removes).
2022-06-20 15:26:37.859 DEBUG 1 --- [qtp643001118-39] d.f.a.i.d.PolicyDecisionPoint            : Transformation: de.fhg.aisec.ids.api.policy.TransformationDecision@4fdb09ac
2022-06-20 15:26:38.562 DEBUG 1 --- [qtp643001118-39] c.ClearingHouseInfomodelParsingProcessor : Using Charset from Content-Type header: utf-8
2022-06-20 15:26:38.620 DEBUG 1 --- [qtp643001118-39] d.f.a.i.d.PolicyDecisionPoint            : Query for uncached label transformation: once(setof(S, action_service('process[ref:InfoModelParsingProcessor]', S), SC); SC = []),
collect_creates_labels(SC, ACraw), set_of(ACraw, Adds),
collect_removes_labels(SC, RCraw), set_of(RCraw, Removes).
2022-06-20 15:26:38.630 DEBUG 1 --- [qtp643001118-39] d.f.a.i.d.PolicyDecisionPoint            : Transformation: de.fhg.aisec.ids.api.policy.TransformationDecision@19b7ee63
2022-06-20 15:26:38.633 DEBUG 1 --- [qtp643001118-39] d.f.a.i.d.PolicyDecisionPoint            : Query for uncached label transformation: once(setof(S, action_service('process[ref:TokenValidationProcessor]', S), SC); SC = []),
collect_creates_labels(SC, ACraw), set_of(ACraw, Adds),
collect_removes_labels(SC, RCraw), set_of(RCraw, Removes).
2022-06-20 15:26:38.642 DEBUG 1 --- [qtp643001118-39] d.f.a.i.d.PolicyDecisionPoint            : Transformation: de.fhg.aisec.ids.api.policy.TransformationDecision@d25777b
2022-06-20 15:26:38.687 DEBUG 1 --- [qtp643001118-39] d.f.a.i.d.PolicyDecisionPoint            : Query for uncached label transformation: once(setof(S, action_service('To[http://logging-service:8000/?bridgeEndpoint=true&throwExceptionOnFailure=false]', S), SC); SC = []),
collect_creates_labels(SC, ACraw), set_of(ACraw, Adds),
collect_removes_labels(SC, RCraw), set_of(RCraw, Removes).
2022-06-20 15:26:38.695 DEBUG 1 --- [qtp643001118-39] d.f.a.i.d.PolicyDecisionPoint            : Transformation: de.fhg.aisec.ids.api.policy.TransformationDecision@325cb629
2022-06-20 15:26:38.716 DEBUG 1 --- [qtp643001118-39] d.f.a.i.i.d.d.a.AisecDapsDriver          : AKI: C4:10:D7:AB:4B:F0:81:45:96:06:97:AD:2A:01:47:D0:C5:F0:45:AC:
2022-06-20 15:26:38.716 DEBUG 1 --- [qtp643001118-39] d.f.a.i.i.d.d.a.AisecDapsDriver          : SKI: C4:10:D7:AB:4B:F0:81:45:96:06:97:AD:2A:01:47:D0:C5:F0:45:AC:
2022-06-20 15:26:38.790  INFO 1 --- [qtp643001118-39] d.f.a.i.i.d.d.a.AisecDapsDriver          : Retrieving Dynamic Attribute Token from DAPS ...
2022-06-20 15:26:38.791 DEBUG 1 --- [qtp643001118-39] d.f.a.i.i.d.d.a.AisecDapsDriver          : ConnectorUUID: C4:10:D7:AB:4B:F0:81:45:96:06:97:AD:2A:01:47:D0:C5:F0:45:AC:keyid:C4:10:D7:AB:4B:F0:81:45:96:06:97:AD:2A:01:47:D0:C5:F0:45:AC
2022-06-20 15:26:39.230 DEBUG 1 --- [qtp643001118-39] d.f.a.i.d.PolicyDecisionPoint            : Query for uncached label transformation: once(setof(S, action_service('process[ref:CHOutputProcessor]', S), SC); SC = []),
collect_creates_labels(SC, ACraw), set_of(ACraw, Adds),
collect_removes_labels(SC, RCraw), set_of(RCraw, Removes).
2022-06-20 15:26:39.245 DEBUG 1 --- [qtp643001118-39] d.f.a.i.d.PolicyDecisionPoint            : Transformation: de.fhg.aisec.ids.api.policy.TransformationDecision@23ee0a98
2022-06-20 15:26:39.252 DEBUG 1 --- [qtp643001118-39] d.f.a.i.d.PolicyDecisionPoint            : Query for uncached label transformation: once(setof(S, action_service('Transform[simple{${exception.message}}]', S), SC); SC = []),
collect_creates_labels(SC, ACraw), set_of(ACraw, Adds),
collect_removes_labels(SC, RCraw), set_of(RCraw, Removes).
2022-06-20 15:26:39.265 DEBUG 1 --- [qtp643001118-39] d.f.a.i.d.PolicyDecisionPoint            : Transformation: de.fhg.aisec.ids.api.policy.TransformationDecision@1f15c4f6
2022-06-20 15:26:39.304  INFO 1 --- [qtp643001118-39] CH_MULTIPART_ROUTE                       : ### Handle class de.fhg.aisec.ids.idscp2.idscp_core.error.DatException ###
2022-06-20 15:26:39.306 DEBUG 1 --- [qtp643001118-39] d.f.a.i.d.PolicyDecisionPoint            : Query for uncached label transformation: once(setof(S, action_service('Log[### Handle ${exception.class} ###]', S), SC); SC = []),
collect_creates_labels(SC, ACraw), set_of(ACraw, Adds),
collect_removes_labels(SC, RCraw), set_of(RCraw, Removes).
2022-06-20 15:26:39.319 DEBUG 1 --- [qtp643001118-39] d.f.a.i.d.PolicyDecisionPoint            : Transformation: de.fhg.aisec.ids.api.policy.TransformationDecision@27f52351
2022-06-20 15:26:39.324 DEBUG 1 --- [qtp643001118-39] d.f.a.i.d.PolicyDecisionPoint            : Query for uncached label transformation: once(setof(S, action_service('RemoveHeader[idsMultipartHeader]', S), SC); SC = []),
collect_creates_labels(SC, ACraw), set_of(ACraw, Adds),
collect_removes_labels(SC, RCraw), set_of(RCraw, Removes).
2022-06-20 15:26:39.337 DEBUG 1 --- [qtp643001118-39] d.f.a.i.d.PolicyDecisionPoint            : Transformation: de.fhg.aisec.ids.api.policy.TransformationDecision@5260c222
2022-06-20 15:26:39.343 DEBUG 1 --- [qtp643001118-39] d.f.a.i.d.PolicyDecisionPoint            : Query for uncached label transformation: once(setof(S, action_service('RemoveHeader[pid]', S), SC); SC = []),
collect_creates_labels(SC, ACraw), set_of(ACraw, Adds),
collect_removes_labels(SC, RCraw), set_of(RCraw, Removes).
2022-06-20 15:26:39.352 DEBUG 1 --- [qtp643001118-39] d.f.a.i.d.PolicyDecisionPoint            : Transformation: de.fhg.aisec.ids.api.policy.TransformationDecision@679adab9
2022-06-20 15:26:39.360 DEBUG 1 --- [qtp643001118-39] d.f.a.i.d.PolicyDecisionPoint            : Query for uncached label transformation: once(setof(S, action_service('Choice[[When[simple{${exception.class} == ''java.lang.SecurityException'' || ${exception.class} == ''java.lang.IllegalArgumentException''} -> [SetHeader[CamelHttpResponseCode, simple{401}]]], When[simple{${exception.class} == ''java.io.IOException''} -> [SetHeader[CamelHttpResponseCode, simple{400}]]]] Otherwise[[Log[### Handle ${exception} ###], Log[### With Trace ${exception.stacktrace} ###], Log[### With Cause ${exception.cause.stacktrace} ###], SetHeader[CamelHttpResponseCode, simple{500}], Transform[constant{Internal Server Error}]]]]', S), SC); SC = []),
collect_creates_labels(SC, ACraw), set_of(ACraw, Adds),
collect_removes_labels(SC, RCraw), set_of(RCraw, Removes).
2022-06-20 15:26:39.369 DEBUG 1 --- [qtp643001118-39] d.f.a.i.d.PolicyDecisionPoint            : Transformation: de.fhg.aisec.ids.api.policy.TransformationDecision@162565b9
2022-06-20 15:26:39.376  INFO 1 --- [qtp643001118-39] CH_MULTIPART_ROUTE                       : ### Handle de.fhg.aisec.ids.idscp2.idscp_core.error.DatException: Error whilst retrieving DAT ###
2022-06-20 15:26:39.377 DEBUG 1 --- [qtp643001118-39] d.f.a.i.d.PolicyDecisionPoint            : Query for uncached label transformation: once(setof(S, action_service('Log[### Handle ${exception} ###]', S), SC); SC = []),
collect_creates_labels(SC, ACraw), set_of(ACraw, Adds),
collect_removes_labels(SC, RCraw), set_of(RCraw, Removes).
2022-06-20 15:26:39.388 DEBUG 1 --- [qtp643001118-39] d.f.a.i.d.PolicyDecisionPoint            : Transformation: de.fhg.aisec.ids.api.policy.TransformationDecision@13c2d64
2022-06-20 15:26:39.393  INFO 1 --- [qtp643001118-39] CH_MULTIPART_ROUTE                       : ### With Trace de.fhg.aisec.ids.idscp2.idscp_core.error.DatException: Error whilst retrieving DAT
        at de.fhg.aisec.ids.idscp2.default_drivers.daps.aisec_daps.AisecDapsDriver.getToken(AisecDapsDriver.kt:342)
        at de.fhg.aisec.ids.clearinghouse.ClearingHouseOutputProcessor$Companion.processClearingHouseOutput(ClearingHouseOutputProcessor.kt:65)
        at de.fhg.aisec.ids.clearinghouse.ClearingHouseOutputProcessor.process(ClearingHouseOutputProcessor.kt:40)
        at org.apache.camel.support.processor.DelegateSyncProcessor.process(DelegateSyncProcessor.java:65)
        at org.apache.camel.support.processor.DelegateAsyncProcessor.process(DelegateAsyncProcessor.java:104)
        at de.fhg.aisec.ids.dataflowcontrol.PolicyEnforcementPoint.process(PolicyEnforcementPoint.kt:201)
        at org.apache.camel.support.processor.DelegateAsyncProcessor.process(DelegateAsyncProcessor.java:104)
        at org.apache.camel.processor.errorhandler.RedeliveryErrorHandler$RedeliveryTask.doRun(RedeliveryErrorHandler.java:812)
        at org.apache.camel.processor.errorhandler.RedeliveryErrorHandler$RedeliveryTask.run(RedeliveryErrorHandler.java:720)
        at org.apache.camel.impl.engine.DefaultReactiveExecutor$Worker.schedule(DefaultReactiveExecutor.java:193)
        at org.apache.camel.impl.engine.DefaultReactiveExecutor.scheduleMain(DefaultReactiveExecutor.java:64)
        at org.apache.camel.processor.Pipeline.process(Pipeline.java:184)
        at org.apache.camel.impl.engine.CamelInternalProcessor.process(CamelInternalProcessor.java:399)
        at org.apache.camel.component.jetty.CamelContinuationServlet.doService(CamelContinuationServlet.java:245)
        at org.apache.camel.http.common.CamelServlet.service(CamelServlet.java:130)
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:584)
        at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:799)
        at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:550)
        at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:233)
        at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1440)
        at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:188)
        at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:501)
        at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:186)
        at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1355)
        at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
        at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127)
        at org.eclipse.jetty.server.Server.handle(Server.java:516)
        at org.eclipse.jetty.server.HttpChannel.lambda$handle$1(HttpChannel.java:487)
        at org.eclipse.jetty.server.HttpChannel.dispatch(HttpChannel.java:732)
        at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:479)
        at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:277)
        at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:311)
        at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:105)
        at org.eclipse.jetty.io.ssl.SslConnection$DecryptedEndPoint.onFillable(SslConnection.java:555)
        at org.eclipse.jetty.io.ssl.SslConnection.onFillable(SslConnection.java:410)
        at org.eclipse.jetty.io.ssl.SslConnection$2.succeeded(SslConnection.java:164)
        at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:105)
        at org.eclipse.jetty.io.ChannelEndPoint$1.run(ChannelEndPoint.java:104)
        at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:338)
        at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:315)
        at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:173)
        at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:131)
        at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:409)
        at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:883)
        at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:1034)
        at java.base/java.lang.Thread.run(Thread.java:833)
Caused by: java.net.ConnectException
        at java.net.http/jdk.internal.net.http.common.Utils.toConnectException(Utils.java:1047)
        at java.net.http/jdk.internal.net.http.PlainHttpConnection.connectAsync(PlainHttpConnection.java:198)
        at java.net.http/jdk.internal.net.http.PlainHttpConnection.checkRetryConnect(PlainHttpConnection.java:230)
        at java.net.http/jdk.internal.net.http.PlainHttpConnection.lambda$connectAsync$1(PlainHttpConnection.java:206)
        at java.base/java.util.concurrent.CompletableFuture.uniHandle(CompletableFuture.java:934)
        at java.base/java.util.concurrent.CompletableFuture$UniHandle.tryFire(CompletableFuture.java:911)
        at java.base/java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:510)
        at java.base/java.util.concurrent.CompletableFuture$AsyncSupply.run(CompletableFuture.java:1773)
        at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136)
        at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635)
        ... 1 more
Caused by: java.nio.channels.ClosedChannelException
        at java.base/sun.nio.ch.SocketChannelImpl.ensureOpen(SocketChannelImpl.java:195)
        at java.base/sun.nio.ch.SocketChannelImpl.beginConnect(SocketChannelImpl.java:760)
        at java.base/sun.nio.ch.SocketChannelImpl.connect(SocketChannelImpl.java:848)
        at java.net.http/jdk.internal.net.http.PlainHttpConnection.lambda$connectAsync$0(PlainHttpConnection.java:183)
        at java.base/java.security.AccessController.doPrivileged(AccessController.java:569)
        at java.net.http/jdk.internal.net.http.PlainHttpConnection.connectAsync(PlainHttpConnection.java:185)
        ... 9 more
 ###
boxer-code commented 2 years ago

Do you use docker compose to start your ch? I forgot to configure the TC_CH_ISSUER_CONNECTOR and the TC_CH_AGENT env variables at first. That could cause an error too. The trusted-connector part of my IDS-testbed+Clearing-House docker compose looks like this:

consumer-core:
    container_name: "consumer-core"
    image: fraunhoferaisec/trusted-connector-core:6.3.0
    tty: true
    stdin_open: true
    volumes:
        - ./Clearing-house/trusted-connector/allow-all-flows.pl:/root/deploy/allow-all-flows.pl
        - ./Clearing-house/trusted-connector/consumer-keystore.p12:/root/etc/keystore.p12
        - ./Clearing-house/trusted-connector/truststore.p12:/root/etc/truststore.p12
        - ./Clearing-house/trusted-connector/clearing-house-processors-0.8.0.jar:/root/jars/clearing-house-processors.jar
        - ./Clearing-house/trusted-connector/routes/clearing-house-routes.xml:/root/deploy/clearing-house-routes.xml
        - //var/run/docker.sock://var/run/docker.sock
    environment:
      TC_CH_ISSUER_CONNECTOR: "https://w3id.org/idsa/core/issuerConnector"
      TC_CH_AGENT: "https://w3id.org/idsa/core/Agent"
      TC_DAPS_URL: "http://omejdn"
    ports:
        - "8443:8443"
        - "9999:9999"
AnaCarolinaChaves commented 2 years ago

I already had configured them. My trusted connector is similar to yours.

boxer-code commented 2 years ago

And all of your container are in the same docker network?

AnaCarolinaChaves commented 2 years ago

No. I have the Clearing House and the DAPS on the same virtual machine, but I use different docker-composes. My variable is TC_DAPS_URL: http://vcese19:4567

boxer-code commented 2 years ago

Different docker-composes shouldn't be a problem if they are in the same network. Had you change anything else of the DAPS container except the address? Maybe theres a certificate problem that causes trouble?

AnaCarolinaChaves commented 2 years ago

The DAPS works with the Metadata Broker and with the DSC.

boxer-code commented 2 years ago

Have you added the certificate of the DAPS server at the truststore of the TC?

AnaCarolinaChaves commented 2 years ago

Yes, I did.

boxer-code commented 2 years ago

I've tried changing the DAPS Url to the default fraunhofer daps server and got at least an appropriate error message. That would be a try to get more information about misconfigured settings. Otherwise I have a fork of the IDS-testbed repo where I pushed my configuration of the testbed + ch. It should be public. Maybe you can recognize any basic difference?

AnaCarolinaChaves commented 2 years ago

Before using the local DAPS I was using the Fraunhofer and was working. I'll search for your configuration. Thank you.

AnaCarolinaChaves commented 2 years ago

I changed to the Fraunhofer DAPS and the logs say Status Code: 401 with Payload: Token not valid!

I think this error is because the DSC is still using my local DAPS.