/api/ids/description endpoint returns 500

[achreffaidi]

Describe the bug

We have two connectors both running on version 7.1.0 and configured with DAPS:

• PROD connector
• E2E connector

When we try to send /api/ids/description [POST] request from the PROD connector to the E2E connector we get this error:

Message handling or processing failed.

For recipient URL we tried both : {connector_url} and {connector_url}/api/ids/data

Screenshots & Logs

The sender connector shows this error in the logs:

2022-05-06T14:15:50,054 [https-jsse-nio-8080-exec-4] WARN - Could not parse JWT! Treat JWT as having expired.
--
2022-05-06T14:15:50,358 [https-jsse-nio-8080-exec-4] INFO - Successfully received DAT from DAPS.
2022-05-06T14:15:50,366 [https-jsse-nio-8080-exec-4] WARN - Could not parse JWT! Treat JWT as having expired.
2022-05-06T14:15:50,498 [https-jsse-nio-8080-exec-4] INFO - Successfully received DAT from DAPS.
2022-05-06T14:15:50,509 [https-jsse-nio-8080-exec-4] INFO - Sending request to https://dsc-e2e.bmwgroup.com/api/ids/data ...
2022-05-06T14:15:50,617 [https-jsse-nio-8080-exec-4] ERROR - Received response but response-code not in 200-299! Response-code: 400!
2022-05-06T14:15:50,618 [https-jsse-nio-8080-exec-4] WARN - Message handling or processing failed. [exception=(Unexpected code Response{protocol=h2, code=400, message=, url=https://dsc-e2e.bmwgroup.com/api/ids/data} With Body: --GGBUUzdFcA7sNpzvQUrW9I_zbegzE8lqVNJ\r\nContent-Disposition: form-data; name="header"\r\nContent-Type: text/plain;charset=UTF-8\r\nContent-Length: 960\r\n\r\n{\n  "@type" : "ids:RejectionMessage",\n  "@id" : "https://w3id.org/idsa/autogen/rejectionMessage/534bf67d-9b01-4818-91ab-7131179cd43d",\n  "ids:modelVersion" : "4.2.0",\n  "ids:issued" : {\n    "@value" : "2022-05-06T14:15:50.608Z",\n    "@type" : "http://www.w3.org/2001/XMLSchema#dateTimeStamp"\n  },\n  "ids:correlationMessage" : {\n    "@id" : "https://INVALID"\n  },\n  "ids:issuerConnector" : {\n    "@id" : "https://dsc-e2e.bmwgroup.com"\n  },\n  "ids:recipientConnector" : [ ],\n  "ids:senderAgent" : {\n    "@id" : "https://dsc-e2e.bmwgroup.com"\n  },\n  "ids:recipientAgent" : [ ],\n  "ids:securityToken" : {\n    "@type" : "ids:DynamicAttributeToken",\n    "@id" : "https://w3id.org/idsa/autogen/dynamicAttributeToken/58d9d924-115e-4dc3-9aff-e0605f82c5f5",\n    "ids:tokenValue" : "rejected!",\n    "ids:tokenFormat" : {\n      "@id" : "https://w3id.org/idsa/code/JWT"\n    }\n  },\n  "ids:rejectionReason" : {\n    "@id" : "https://w3id.org/idsa/code/MALFORMED_MESSAGE"\n  }\n}\r\n--GGBUUzdFcA7sNpzvQUrW9I_zbegzE8lqVNJ\r\nContent-Disposition: form-data; name="payload"\r\nContent-Type: text/plain;charset=UTF-8\r\nContent-Length: 33\r\n\r\nCould not parse incoming message!\r\n--GGBUUzdFcA7sNpzvQUrW9I_zbegzE8lqVNJ--\r\n)]
java.io.IOException: Unexpected code Response{protocol=h2, code=400, message=, url=https://dsc-e2e.bmwgroup.com/api/ids/data} With Body: --GGBUUzdFcA7sNpzvQUrW9I_zbegzE8lqVNJ
Content-Disposition: form-data; name="header"
Content-Type: text/plain;charset=UTF-8
Content-Length: 960
 
{
"@type" : "ids:RejectionMessage",
"@id" : "https://w3id.org/idsa/autogen/rejectionMessage/534bf67d-9b01-4818-91ab-7131179cd43d",
"ids:modelVersion" : "4.2.0",
"ids:issued" : {
"@value" : "2022-05-06T14:15:50.608Z",
"@type" : "http://www.w3.org/2001/XMLSchema#dateTimeStamp"
},
"ids:correlationMessage" : {
"@id" : "https://INVALID"
},
"ids:issuerConnector" : {
"@id" : "https://dsc-e2e.bmwgroup.com"
},
"ids:recipientConnector" : [ ],
"ids:senderAgent" : {
"@id" : "https://dsc-e2e.bmwgroup.com"
},
"ids:recipientAgent" : [ ],
"ids:securityToken" : {
"@type" : "ids:DynamicAttributeToken",
"@id" : "https://w3id.org/idsa/autogen/dynamicAttributeToken/58d9d924-115e-4dc3-9aff-e0605f82c5f5",
"ids:tokenValue" : "rejected!",
"ids:tokenFormat" : {
"@id" : "https://w3id.org/idsa/code/JWT"
}
},
"ids:rejectionReason" : {
"@id" : "https://w3id.org/idsa/code/MALFORMED_MESSAGE"
}
}
--GGBUUzdFcA7sNpzvQUrW9I_zbegzE8lqVNJ
Content-Disposition: form-data; name="payload"
Content-Type: text/plain;charset=UTF-8
Content-Length: 33
 
Could not parse incoming message!
--GGBUUzdFcA7sNpzvQUrW9I_zbegzE8lqVNJ--

And for the recipient connector we got this log:

2022-05-06T14:15:50,596 [https-jsse-nio-8080-exec-12] INFO - Received incoming message.
--
2022-05-06T14:15:50,601 [https-jsse-nio-8080-exec-12] INFO - Executed query: PREFIX ids: <https://w3id.org/idsa/core/>\nSELECT ?securityToken ?authorizationToken ?correlationMessage (GROUP_CONCAT(?recipientConnector;separator="\|\|") AS ?recipientConnectors)  ?issuerConnector ?senderAgent ?modelVersion ?requestedElement ?issued ?contentVersion ?transferContract (GROUP_CONCAT(?recipientAgent;separator="\|\|") AS ?recipientAgents)  {  <https://w3id.org/idsa/autogen/descriptionRequestMessage/7b632284-3a9a-405c-9910-3fcdb99f6145> a ids:DescriptionRequestMessage.  <https://w3id.org/idsa/autogen/descriptionRequestMessage/7b632284-3a9a-405c-9910-3fcdb99f6145> ids:securityToken ?securityToken . OPTIONAL { <https://w3id.org/idsa/autogen/descriptionRequestMessage/7b632284-3a9a-405c-9910-3fcdb99f6145> ids:authorizationToken ?authorizationToken .}  OPTIONAL { <https://w3id.org/idsa/autogen/descriptionRequestMessage/7b632284-3a9a-405c-9910-3fcdb99f6145> ids:correlationMessage ?correlationMessage .}  OPTIONAL { <https://w3id.org/idsa/autogen/descriptionRequestMessage/7b632284-3a9a-405c-9910-3fcdb99f6145> ids:recipientConnector ?recipientConnector .}  <https://w3id.org/idsa/autogen/descriptionRequestMessage/7b632284-3a9a-405c-9910-3fcdb99f6145> ids:issuerConnector ?issuerConnector . <https://w3id.org/idsa/autogen/descriptionRequestMessage/7b632284-3a9a-405c-9910-3fcdb99f6145> ids:senderAgent ?senderAgent . <https://w3id.org/idsa/autogen/descriptionRequestMessage/7b632284-3a9a-405c-9910-3fcdb99f6145> ids:modelVersion ?modelVersion . OPTIONAL { <https://w3id.org/idsa/autogen/descriptionRequestMessage/7b632284-3a9a-405c-9910-3fcdb99f6145> ids:requestedElement ?requestedElement .}  <https://w3id.org/idsa/autogen/descriptionRequestMessage/7b632284-3a9a-405c-9910-3fcdb99f6145> ids:issued ?issued . OPTIONAL { <https://w3id.org/idsa/autogen/descriptionRequestMessage/7b632284-3a9a-405c-9910-3fcdb99f6145> ids:contentVersion ?contentVersion .}  OPTIONAL { <https://w3id.org/idsa/autogen/descriptionRequestMessage/7b632284-3a9a-405c-9910-3fcdb99f6145> ids:transferContract ?transferContract .}  OPTIONAL { <https://w3id.org/idsa/autogen/descriptionRequestMessage/7b632284-3a9a-405c-9910-3fcdb99f6145> ids:recipientAgent ?recipientAgent .}  } GROUP BY ?securityToken ?authorizationToken ?correlationMessage ?issuerConnector ?senderAgent ?modelVersion ?requestedElement ?issued ?contentVersion ?transferContract
2022-05-06T14:15:50,601 [https-jsse-nio-8080-exec-12] WARN - Incoming message could not be parsed, sending response BAD_REQUEST with RejectionReason.MALFORMED_MESSAGE! The following mandatory field(s) of DescriptionRequestMessage are not filled or invalid: ids:securityToken, ids:issuerConnector, ids:senderAgent, ids:modelVersion, ids:issued. Note that the value of "@id" fields MUST be a valid URI (e.g. emails preceded by "mailto:"). Mandatory fields are: securityToken, issuerConnector, senderAgent, modelVersion, issued

[tmberthold]

For a first debugging step, could you please add the application property daps.enable.log.jwt=true or set it via env-variables.

Successfully received DAT from DAPS. is then extended by an output of the DAT received from the DAPS.

[achreffaidi]

I just did, add that attribute to the sender connector:

Now the error code is 502 Received invalid ids message.

Logs from the sender:

2022-05-06T15:05:18,397 [https-jsse-nio-8080-exec-8] INFO - Successfully received DAT from DAPS.
--
2022-05-06T15:05:18,451 [https-jsse-nio-8080-exec-8] INFO - Sending request to https://dsc.bmwgroup.com/api/ids/data ...
2022-05-06T15:05:18,595 [https-jsse-nio-8080-exec-8] INFO - Successfully received response to request.
2022-05-06T15:05:18,607 [https-jsse-nio-8080-exec-8] INFO - Initializing SHACL shapes.
2022-05-06T15:05:18,607 [https-jsse-nio-8080-exec-8] INFO - Loading SHACL shapes from resources. You can optionally download the latest shapes from GitHub.
2022-05-06T15:05:20,228 [https-jsse-nio-8080-exec-8] INFO - Loading ontology from resources
2022-05-06T15:05:20,288 [https-jsse-nio-8080-exec-8] INFO - Initialization of SHACL shapes complete.
2022-05-06T15:05:20,307 [https-jsse-nio-8080-exec-8] INFO - Successfully passed SHACL-Validation.
2022-05-06T15:05:20,330 [https-jsse-nio-8080-exec-8] INFO - Executed query: PREFIX ids: <https://w3id.org/idsa/core/>\nSELECT ?securityToken ?authorizationToken ?correlationMessage (GROUP_CONCAT(?recipientConnector;separator="\|\|") AS ?recipientConnectors)  ?issuerConnector ?senderAgent ?modelVersion ?issued ?rejectionReason ?contentVersion ?transferContract (GROUP_CONCAT(?recipientAgent;separator="\|\|") AS ?recipientAgents)  {  <https://w3id.org/idsa/autogen/rejectionMessage/61d52960-c67d-47f4-8ebe-63c92c38e06e> a ids:RejectionMessage.  <https://w3id.org/idsa/autogen/rejectionMessage/61d52960-c67d-47f4-8ebe-63c92c38e06e> ids:securityToken ?securityToken . OPTIONAL { <https://w3id.org/idsa/autogen/rejectionMessage/61d52960-c67d-47f4-8ebe-63c92c38e06e> ids:authorizationToken ?authorizationToken .}  <https://w3id.org/idsa/autogen/rejectionMessage/61d52960-c67d-47f4-8ebe-63c92c38e06e> ids:correlationMessage ?correlationMessage . OPTIONAL { <https://w3id.org/idsa/autogen/rejectionMessage/61d52960-c67d-47f4-8ebe-63c92c38e06e> ids:recipientConnector ?recipientConnector .}  <https://w3id.org/idsa/autogen/rejectionMessage/61d52960-c67d-47f4-8ebe-63c92c38e06e> ids:issuerConnector ?issuerConnector . <https://w3id.org/idsa/autogen/rejectionMessage/61d52960-c67d-47f4-8ebe-63c92c38e06e> ids:senderAgent ?senderAgent . <https://w3id.org/idsa/autogen/rejectionMessage/61d52960-c67d-47f4-8ebe-63c92c38e06e> ids:modelVersion ?modelVersion . <https://w3id.org/idsa/autogen/rejectionMessage/61d52960-c67d-47f4-8ebe-63c92c38e06e> ids:issued ?issued . OPTIONAL { <https://w3id.org/idsa/autogen/rejectionMessage/61d52960-c67d-47f4-8ebe-63c92c38e06e> ids:rejectionReason ?rejectionReason .}  OPTIONAL { <https://w3id.org/idsa/autogen/rejectionMessage/61d52960-c67d-47f4-8ebe-63c92c38e06e> ids:contentVersion ?contentVersion .}  OPTIONAL { <https://w3id.org/idsa/autogen/rejectionMessage/61d52960-c67d-47f4-8ebe-63c92c38e06e> ids:transferContract ?transferContract .}  OPTIONAL { <https://w3id.org/idsa/autogen/rejectionMessage/61d52960-c67d-47f4-8ebe-63c92c38e06e> ids:recipientAgent ?recipientAgent .}  } GROUP BY ?securityToken ?authorizationToken ?correlationMessage ?issuerConnector ?senderAgent ?modelVersion ?issued ?rejectionReason ?contentVersion ?transferContract

Recipient log:

2022-05-06T15:11:48,420 [scheduling-1] INFO - Scanning agreements...
--
2022-05-06T15:11:49,292 [https-jsse-nio-8080-exec-25] INFO - Received incoming message.

[achreffaidi]

Hey @tmberthold, Any updates on the reported issue?

[tmberthold]

Purely from the logs I can't see any problem, because they are all info logs.

With the current DSC-main version we have added a new feature, two new settings, with which you can output the incoming and outgoing ids-messages of DSCs in the logs, if enabled via properties.

As of current main (not released as stable version):

messaging.log.incoming=true
messaging.log.outgoing=true

1. RejectionMessage because unsupported infomodel version When I look at what the connector is responding to me on send requests, it responds with a rejectionMessage because of incompatible infomodel-message-versions. Please check the connector configuration, if the model version of the incoming message is in the list of inbound modelversions.

2. RejectionMessage because DAT could not be parsed When I downgrade my outbound model version to the ones supported by said connector, thus bypassing 1. with a workaround, the connector replies that it cannot parse the DAT of the incoming message. Here please check the settings, whether everything is correct in connection with the DAPS setup, perhaps the connector can not fetch the public key or something similar from the DAPS.

[achreffaidi]

The two connectors we have has the following info-model config:

  ids:inboundModelVersion" : [ "4.2.0", "4.1.2", "4.0.0", "4.1.0" ]
  ids:outboundModelVersion" : "4.2.0"

DAPS is working perfectly for other endpoints, so probably the error isn't coming from there.

I'll try to set up the logging parameter you mentioned in one of our connectors and see if there's useful logs.