Provider-HTTP-Push: Transferprocess completes but callback request fails

[Julian-Marco]

Bug Report

When my Provider-EDC uses an HTTP-Push, the transfer does complete in the kind of sense that the file gets transferred succesfully, but for whatever reason the Provider-EDC tries to inform itself about the completion of the transfer, which seems to fail since the callback address used for this could not be found. At the same time, the Consumer-EDC doesn't even show a Complete message. Instead, it only shows that the transferprocess has started and then never mentions anything again about it.

Consumer-EDC: (<PROVIDER-HOST> represents the address of the Provider-EDC)

DEBUG 2023-11-10T12:31:42.911661039 [TransferProcessManagerImpl] TransferProcess 9254411e-5e64-46bf-b1f3-5f313991362a is now in state INITIAL
DEBUG 2023-11-10T12:31:42.913282158 Process 9254411e-5e64-46bf-b1f3-5f313991362a is now INITIAL
DEBUG 2023-11-10T12:31:42.916961092 Transfer Process created 9254411e-5e64-46bf-b1f3-5f313991362a
DEBUG 2023-11-10T12:31:42.948720783 [TransferProcessManagerImpl] TransferProcess 9254411e-5e64-46bf-b1f3-5f313991362a is now in state PROVISIONING
DEBUG 2023-11-10T12:31:42.959172004 TransferProcess: ID 9254411e-5e64-46bf-b1f3-5f313991362a. Provisioning
DEBUG 2023-11-10T12:31:42.972737804 [TransferProcessManagerImpl] TransferProcess 9254411e-5e64-46bf-b1f3-5f313991362a is now in state PROVISIONED
DEBUG 2023-11-10T12:31:42.988325171 [TransferProcessManagerImpl] TransferProcess 9254411e-5e64-46bf-b1f3-5f313991362a is now in state REQUESTING
DEBUG 2023-11-10T12:31:42.998597462 TransferProcess: ID 9254411e-5e64-46bf-b1f3-5f313991362a. Send TransferRequestMessage to http://<AZURE-HOST>:8282/protocol
DEBUG 2023-11-10T12:31:43.067094791 TransferProcess: ID 9254411e-5e64-46bf-b1f3-5f313991362a. Send TransferRequestMessage to http://<AZURE-HOST>:8282/protocol
DEBUG 2023-11-10T12:31:43.074430496 [TransferProcessManagerImpl] TransferProcess 9254411e-5e64-46bf-b1f3-5f313991362a is now in state REQUESTED
DEBUG 2023-11-10T12:31:43.716170965 DSP: Incoming TransferStartMessage for class org.eclipse.edc.connector.transfer.spi.types.TransferProcess process: 9254411e-5e64-46bf-b1f3-5f313991362a
DEBUG 2023-11-10T12:31:43.730461527 TransferProcess 9254411e-5e64-46bf-b1f3-5f313991362a is now in state STARTED

Provider-EDC: (<CONSUMER-HOST> represents the address of the Consumer-EDC)

DEBUG 2023-11-10T12:31:43.529575729 DSP: Incoming TransferRequestMessage for class org.eclipse.edc.connector.transfer.spi.types.TransferProcess process
DEBUG 2023-11-10T12:31:43.538102259 TransferProcess c4cc0767-4031-4ce4-9868-e210eea52582 is now in state INITIAL
DEBUG 2023-11-10T12:31:44.169073581 [TransferProcessManagerImpl] TransferProcess c4cc0767-4031-4ce4-9868-e210eea52582 is now in state PROVISIONING
DEBUG 2023-11-10T12:31:44.170069885 TransferProcess: ID c4cc0767-4031-4ce4-9868-e210eea52582. Provisioning
DEBUG 2023-11-10T12:31:44.173096095 [TransferProcessManagerImpl] TransferProcess c4cc0767-4031-4ce4-9868-e210eea52582 is now in state PROVISIONED
DEBUG 2023-11-10T12:31:44.173879398 [TransferProcessManagerImpl] TransferProcess c4cc0767-4031-4ce4-9868-e210eea52582 is now in state STARTING
DEBUG 2023-11-10T12:31:44.174702501 TransferProcess: ID c4cc0767-4031-4ce4-9868-e210eea52582. Initiate data flow
DEBUG 2023-11-10T12:31:44.181202824 [DataPlaneManagerImpl] DataFlow c4cc0767-4031-4ce4-9868-e210eea52582 is now in state RECEIVED
DEBUG 2023-11-10T12:31:44.182661729 TransferProcess: ID c4cc0767-4031-4ce4-9868-e210eea52582. Send TransferStartMessage to <CONSUMER-HOST>:8282/protocol
DEBUG 2023-11-10T12:31:44.267099626 TransferProcess: ID c4cc0767-4031-4ce4-9868-e210eea52582. Send TransferStartMessage to <CONSUMER-HOST>:8282/protocol
DEBUG 2023-11-10T12:31:44.267514328 [TransferProcessManagerImpl] TransferProcess c4cc0767-4031-4ce4-9868-e210eea52582 is now in state STARTED
INFO 2023-11-10T12:31:45.050022983 ExecutionManager: Run pre-execution task
INFO 2023-11-10T12:31:45.050109483 ExecutionManager: Run execution
WARNING 2023-11-10T12:31:45.050152784 No WorkItems found, aborting execution
INFO 2023-11-10T12:31:45.050205284 ExecutionManager: Run post-execution task
DEBUG 2023-11-10T12:31:45.168055599 DataFlow: ID c4cc0767-4031-4ce4-9868-e210eea52582. start data flow
DEBUG 2023-11-10T12:31:45.352418048 Transferring from AzureStorage to HttpData.
DEBUG 2023-11-10T12:31:46.38664479 [DataPlaneManagerImpl] DataFlow c4cc0767-4031-4ce4-9868-e210eea52582 is now in state COMPLETED

Then, the Provider keeps trying to send a request to a callback address that doesn't seem to exist:

SEVERE 2023-11-10T12:32:02.265747884 Failed to send callback request
org.eclipse.edc.spi.http.EdcHttpClientException: Server response to Request{method=POST, url=http://<PROVIDER-HOST>:8183/control/transferprocess/c4cc0767-4031-4ce4-9868-e210eea52582/complete} was not one of [200, 204] but was 404: <html>

Looks like the address gets created here but the Provider-EDC doesn't seem to recognize it. Might this be an issue with how I initialize the DataPlane?

{
 "@context": {
   "edc": "https://w3id.org/edc/v0.0.1/ns/"
  },
   "edctype": "dataspaceconnector:dataplaneinstance",
   "id": "http-provider-dataplane",
   "url": "http://<PROVIDER-HOST>:8183/control/transfer",
   "allowedSourceTypes": [ "HttpData", "AzureStorage" ],
   "allowedDestTypes": [ "HttpProxy", "HttpData" ],
   "properties": {
     "publicApiUrl": "http://<PROVIDER-HOST>:8185/public/"
   }
 }

Maybe the endpoint in the url needs to be /transferprocess instead of /transfer or something like that?

[wolf4ood]

Hi @Julian-Marco the URL callback is automatically derived for simple cases, if you have a particular setup you should configure the URL of the control api, check here

[Julian-Marco]

Thank you, didn't know that, interesting. The provider is running on an AKS and uses an AzureStorage as a DataSource. I suppose you mean this value here?

edc.control.endpoint=<control-api-endpoint>

Can this be chosen completely arbitrary?

Edit:

... assuming that this is my current configuration for the other two values:

      web.http.control.port    = 8183
      web.http.control.path    = /control

[wolf4ood]

You also have to include control-plane-api module in order to expose the api under the control context

[Julian-Marco]

Guess I was simply missing the control-plane-api here, I only used control-plane-core and control-plane-api-client. The dataplane definition from above works fine then, even without explicitly setting a value for edc.control.endpoint.

Works like a charm now, thank you! :)

[wolf4ood]

Cool, closing this then :)