TransferProcessManagerImpl error while running the instance

[kss682]

I have set up a basic EDC using the SeedVault and certs.

plugins {
    `java-library`
    id("application")
    alias(libs.plugins.shadow)
}

dependencies {
    implementation(libs.edc.control.api.configuration)
    implementation(libs.edc.control.plane.api.client)
    implementation(libs.edc.control.plane.api)
    implementation(libs.edc.control.plane.core)
    implementation(libs.edc.control.plane.sql)

    implementation(libs.edc.dsp)
    implementation(libs.edc.configuration.filesystem)
    implementation(libs.edc.iam.mock)
	implementation(libs.edc.sql.apache.commons)
	implementation(libs.postgresql)
	implementation(libs.edc.transaction.local)
	implementation(libs.edc.transaction.datasource.spi)

    implementation(libs.edc.management.api)
    implementation(libs.edc.transfer.data.plane.signaling)
    implementation(libs.edc.transfer.pull.http.receiver)
    implementation(libs.edc.validator.data.address.http.data)
    
    implementation(libs.edc.edr.cache.api)
    implementation(libs.edc.edr.store.core)
    implementation(libs.edc.edr.store.receiver)

    implementation(libs.edc.data.plane.selector.api)
    implementation(libs.edc.data.plane.selector.core)
    
    implementation(libs.edc.data.plane.self.registration)
    implementation(libs.edc.data.plane.control.api)
    implementation(libs.edc.data.plane.public.api)
    implementation(libs.edc.data.plane.core)
    implementation(libs.edc.data.plane.http)
}

application {
    mainClass.set("org.eclipse.edc.boot.system.runtime.BaseRuntime")
}

var distTar = tasks.getByName("distTar")
var distZip = tasks.getByName("distZip")

tasks.withType<com.github.jengelman.gradle.plugins.shadow.tasks.ShadowJar> {
    mergeServiceFiles()
    archiveFileName.set("connector.jar")
    dependsOn(distTar, distZip)
}

Using the above config I spin up 2 instance, one provider and consumer with the following configurations:

edc.participant.id=provider
edc.dsp.callback.address=http://localhost:19194/protocol
web.http.port=19191
web.http.path=/api
web.http.management.port=19193
web.http.management.path=/management
web.http.protocol.port=19194
web.http.protocol.path=/protocol
edc.transfer.proxy.token.signer.privatekey.alias=private-key
edc.transfer.proxy.token.verifier.publickey.alias=public-key
web.http.public.port=19291
web.http.public.path=/public
web.http.control.port=19192
web.http.control.path=/control
edc.dataplane.api.public.baseurl=http://localhost:19291/public

edc.datasource.default.user=a
edc.datasource.default.password=
edc.datasource.default.url=jdbc:postgresql://localhost:5433/provider

Similar config for consumer as well with the ports changed.
I'm able to create asset, policy and contract and negotiate it but unable to complete the transfer process.
Looking into the logs, the data plane of the provider shows the following error:

SEVERE 2024-07-10T16:32:13.626474236 StateMachineManager [TransferProcessManagerImpl] error caught
org.eclipse.edc.spi.EdcException: Cannot invoke "Object.hashCode()" because "key" is null
	at org.eclipse.edc.transaction.local.LocalTransactionContext.execute(LocalTransactionContext.java:81)

Meanwhile the consumer service runs fine. Is this because transferprocess is not initiated on consumer that the error is not seen.
Is the cert in the repo still correct ?
This is how I run it.

java -Dedc.keystore=resources/certs/cert.pfx -Dedc.keystore.password=123456 -Dedc.fs.config=resources/config/provider.properties -jar app/build/libs/connector.jar

[ndr-brt]

please attach the transfer request payload and maybe the complete stacktrace. which state reaches the transfer on the consumer side? and on the provider one?

[kss682]

First I complete till contract negotiation to get the contract id, using which I initiate the transfer process request.

curl --location 'http://localhost:29193/management/v3/transferprocesses' \
--header 'Content-Type: application/json' \
--data-raw '{
  "@context": {
    "@vocab": "https://w3id.org/edc/v0.0.1/ns/"
  },
  "@type": "TransferRequestDto",
  "connectorId": "provider",
  "counterPartyAddress": "http://localhost:19194/protocol",
  "contractId": "89298d61-6bb1-46ee-89e3-1124e7873cda",
  "assetId": "assetId",
  "protocol": "dataspace-protocol-http",
  "transferType": "HttpData-PULL"
}'

Output

{
    "@type": "IdResponse",
    "@id": "b5ef5961-eb30-4eb3-bd72-530a1c978ab9",
    "createdAt": 1720699678899,
    "@context": {
        "@vocab": "https://w3id.org/edc/v0.0.1/ns/",
        "edc": "https://w3id.org/edc/v0.0.1/ns/",
        "odrl": "http://www.w3.org/ns/odrl/2/"
    }
}

But the logs show error as follows

DEBUG 2024-07-11T14:07:59.936840927 DSP: Incoming TransferRequestMessage for class org.eclipse.edc.connector.controlplane.transfer.spi.types.TransferProcess process
DEBUG 2024-07-11T14:07:59.964873107 TransferProcess d08b12bf-b3bb-4ffb-b9a9-3baf181f7cb4 is now in state INITIAL
DEBUG 2024-07-11T14:08:00.279310571 [TransferProcessManagerImpl] TransferProcess d08b12bf-b3bb-4ffb-b9a9-3baf181f7cb4 is now in state PROVISIONING
DEBUG 2024-07-11T14:08:00.283926139 TransferProcess: ID d08b12bf-b3bb-4ffb-b9a9-3baf181f7cb4. Provisioning
DEBUG 2024-07-11T14:08:00.288776878 [TransferProcessManagerImpl] TransferProcess d08b12bf-b3bb-4ffb-b9a9-3baf181f7cb4 is now in state PROVISIONED
DEBUG 2024-07-11T14:08:00.293532313 [TransferProcessManagerImpl] TransferProcess d08b12bf-b3bb-4ffb-b9a9-3baf181f7cb4 is now in state STARTING
DEBUG 2024-07-11T14:08:00.297195828 TransferProcess: ID d08b12bf-b3bb-4ffb-b9a9-3baf181f7cb4. Initiate data flow
DEBUG 2024-07-11T14:08:00.299127809 Resolving secret private-key
DEBUG 2024-07-11T14:08:00.299356546 [PrivateKeyResolution] Public key not found, fallback to config. Error: Private key with ID 'private-key' not found in Vault
WARNING 2024-07-11T14:08:00.29952697 Cannot resolve private key: Private key with ID 'private-key' not found in Config
WARNING 2024-07-11T14:08:00.299702548 Error obtaining EDR DataAddress: PrivateKey cannot be resolved.
SEVERE 2024-07-11T14:08:00.299847598 TransferProcess: ID d08b12bf-b3bb-4ffb-b9a9-3baf181f7cb4. Fatal error while Initiate data flow. Error details: PrivateKey cannot be resolved.
WARNING 2024-07-11T14:08:00.299871729 PrivateKey cannot be resolved.
DEBUG 2024-07-11T14:08:00.302027469 [TransferProcessManagerImpl] TransferProcess d08b12bf-b3bb-4ffb-b9a9-3baf181f7cb4 is now in state TERMINATING
DEBUG 2024-07-11T14:08:00.304652124 TransferProcess: ID d08b12bf-b3bb-4ffb-b9a9-3baf181f7cb4. Terminate data flow
SEVERE 2024-07-11T14:08:00.304942813 StateMachineManager [TransferProcessManagerImpl] error caught
org.eclipse.edc.spi.EdcException
	at org.eclipse.edc.transaction.local.LocalTransactionContext.execute(LocalTransactionContext.java:81)
	at org.eclipse.edc.connector.dataplane.selector.service.EmbeddedDataPlaneSelectorService.findById(EmbeddedDataPlaneSelectorService.java:103)
	at org.eclipse.edc.connector.controlplane.transfer.dataplane.flow.DataPlaneSignalingFlowController.getClientForDataplane(DataPlaneSignalingFlowController.java:152)
	at org.eclipse.edc.connector.controlplane.transfer.dataplane.flow.DataPlaneSignalingFlowController.terminate(DataPlaneSignalingFlowController.java:128)
	at org.eclipse.edc.connector.controlplane.transfer.flow.DataFlowManagerImpl.lambda$terminate$1(DataFlowManagerImpl.java:75)
	at java.base/java.util.Optional.map(Optional.java:260)
	at org.eclipse.edc.connector.controlplane.transfer.flow.DataFlowManagerImpl.chooseControllerAndApply(DataFlowManagerImpl.java:99)
	at org.eclipse.edc.connector.controlplane.transfer.flow.DataFlowManagerImpl.terminate(DataFlowManagerImpl.java:75)
	at org.eclipse.edc.connector.controlplane.transfer.process.TransferProcessManagerImpl.terminateDataFlow(TransferProcessManagerImpl.java:473)
	at org.eclipse.edc.connector.controlplane.transfer.process.TransferProcessManagerImpl.lambda$processTerminating$31(TransferProcessManagerImpl.java:418)
	at org.eclipse.edc.statemachine.retry.StatusResultRetryProcess.process(StatusResultRetryProcess.java:48)
	at org.eclipse.edc.statemachine.retry.RetryProcess.execute(RetryProcess.java:71)
	at org.eclipse.edc.connector.controlplane.transfer.process.TransferProcessManagerImpl.processTerminating(TransferProcessManagerImpl.java:423)
	at org.eclipse.edc.spi.telemetry.Telemetry.lambda$contextPropagationMiddleware$0(Telemetry.java:73)
	at org.eclipse.edc.statemachine.ProcessorImpl.lambda$process$1(ProcessorImpl.java:55)
	at java.base/java.util.stream.ReferencePipeline$3$1.accept(ReferencePipeline.java:197)
	at java.base/java.util.ArrayList$ArrayListSpliterator.forEachRemaining(ArrayList.java:1708)
	at java.base/java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:509)
	at java.base/java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:499)
	at java.base/java.util.stream.ReduceOps$ReduceOp.evaluateSequential(ReduceOps.java:921)
	at java.base/java.util.stream.ReduceOps$5.evaluateSequential(ReduceOps.java:258)
	at java.base/java.util.stream.ReduceOps$5.evaluateSequential(ReduceOps.java:248)
	at java.base/java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:234)
	at java.base/java.util.stream.ReferencePipeline.count(ReferencePipeline.java:709)
	at org.eclipse.edc.statemachine.ProcessorImpl.process(ProcessorImpl.java:62)
	at java.base/java.util.stream.ReferencePipeline$5$1.accept(ReferencePipeline.java:231)
	at java.base/java.util.ArrayList$ArrayListSpliterator.forEachRemaining(ArrayList.java:1708)
	at java.base/java.util.stream.AbstractPipeline.copyInto(AbstractPipeline.java:509)
	at java.base/java.util.stream.AbstractPipeline.wrapAndCopyInto(AbstractPipeline.java:499)
	at java.base/java.util.stream.ReduceOps$ReduceOp.evaluateSequential(ReduceOps.java:921)
	at java.base/java.util.stream.AbstractPipeline.evaluate(AbstractPipeline.java:234)
	at java.base/java.util.stream.LongPipeline.reduce(LongPipeline.java:498)
	at java.base/java.util.stream.LongPipeline.sum(LongPipeline.java:456)
	at org.eclipse.edc.statemachine.StateMachineManager.performLogic(StateMachineManager.java:110)
	at org.eclipse.edc.statemachine.StateMachineManager.lambda$loop$2(StateMachineManager.java:101)
	at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:572)
	at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:317)
	at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304)
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1144)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:642)
	at java.base/java.lang.Thread.run(Thread.java:1583)
Caused by: java.lang.NullPointerException

After this querying for the transfer state from consumer side

[ndr-brt]

the solution is here:

DEBUG 2024-07-11T14:08:00.299356546 [PrivateKeyResolution] Public key not found, fallback to config. Error: Private key with ID 'private-key' not found in Vault
WARNING 2024-07-11T14:08:00.29952697 Cannot resolve private key: Private key with ID 'private-key' not found in Config
WARNING 2024-07-11T14:08:00.299702548 Error obtaining EDR DataAddress: PrivateKey cannot be resolved.
SEVERE 2024-07-11T14:08:00.299847598 TransferProcess: ID d08b12bf-b3bb-4ffb-b9a9-3baf181f7cb4. Fatal error while Initiate data flow. Error details: PrivateKey cannot be resolved.
WARNING 2024-07-11T14:08:00.299871729 PrivateKey cannot be resolved.

the provider data plane is not able to get the private key to sign the EDR token. please ensure that the SeedVaultExtension is loaded correctly at startup

[kss682]

I don't see any other error related to public key except this warning

INFO 2024-07-11T15:36:14.821326566 Initialized org.eclipse.edc.connector.core.SecurityDefaultServicesExtension
WARNING 2024-07-11T15:36:14.825254147 There were missing service registrations in extension class org.eclipse.edc.connector.core.LocalPublicKeyDefaultExtension: org.eclipse.edc.keys.spi.LocalPublicKeyService
INFO 2024-07-11T15:36:14.82532808 Initialized org.eclipse.edc.connector.core.LocalPublicKeyDefaultExtension

Do you think this could be an issue ?

[ndr-brt]

if your project is a fork of a sample, I suggest to look at what you changed compared with the working sample

[kss682]

These are the only changes
kss682@ba2c3b5

[ndr-brt]

please verify that the seed extension is loaded properly. If not, you could add the private key by yourself into the Vault (or, as a fallback, it could be stored in the config)

[kss682]

It is working when I run it inside the Samples repository, but it doesn't work when I bring the transfer modules outside and run it as separate service. It looks like a configuration issue on my side. Thanks for the support !