iExecBlockchainComputing / iexec-result-proxy

The iExec Result Proxy is an authenticated IPFS gateway for storing results of tasks computed on iExec.
Apache License 2.0
2 stars 7 forks source link

Duplicate db entry causes the result upload to fail #21

Open zguesmi opened 3 years ago

zguesmi commented 3 years ago

In integration tests, the worker fails with this error when it tries to push the result:

2021-08-31 10:24:45.313 ERROR 1 --- [         task-8] c.i.worker.executor.TaskManagerService   : Failed to upload result [chainTaskId:'0x534080c0504c69b799c3b2f8be7bc7aee69c69d9a6945072f76c07e472e46b80', cause:'RESULT_LINK_MISSING']

This exception appears in the result proxy logs:

2021-08-31 10:24:39.216  INFO 1 --- [io-13200-exec-6] c.i.resultproxy.proxy.ProxyController    : Result uploaded successfully [chainTaskId:0x534080c0504c69b799c3b2f8be7bc7aee69c69d9a6945072f76c07e472e46b80, uploadRequester:0x1a69b2eb604db8eba185df03ea4f5288dcbbd248, resultLink:/ipfs/QmQZqGJoSWWgjNs5gNAbNPs8D5qviMXqrqgKNZ8fg23ZU6]
2021-08-31 10:24:39.272 ERROR 1 --- [io-13200-exec-8] o.a.c.c.C.[.[.[/].[dispatcherServlet]    : Servlet.service() for servlet [dispatcherServlet] in context with path [] threw exception [Request processing failed; nested exception is org.springframework.dao.IncorrectResultSizeDataAccessException: Query { "$java" : Query: { "taskId" : "0x534080c0504c69b799c3b2f8be7bc7aee69c69d9a6945072f76c07e472e46b80"}, Fields: {}, Sort: {} } returned non unique result.] with root cause

org.springframework.dao.IncorrectResultSizeDataAccessException: Query { "$java" : Query: { "taskId" : "0x534080c0504c69b799c3b2f8be7bc7aee69c69d9a6945072f76c07e472e46b80"}, Fields: {}, Sort: {} } returned non unique result.
    at org.springframework.data.mongodb.core.ExecutableFindOperationSupport$ExecutableFindSupport.oneValue(ExecutableFindOperationSupport.java:134) ~[spring-data-mongodb-2.2.5.RELEASE.jar!/:2.2.5.RELEASE]
    at org.springframework.data.mongodb.repository.query.AbstractMongoQuery.lambda$getExecution$4(AbstractMongoQuery.java:153) ~[spring-data-mongodb-2.2.5.RELEASE.jar!/:2.2.5.RELEASE]
    at org.springframework.data.mongodb.repository.query.AbstractMongoQuery.doExecute(AbstractMongoQuery.java:126) ~[spring-data-mongodb-2.2.5.RELEASE.jar!/:2.2.5.RELEASE]
    at org.springframework.data.mongodb.repository.query.AbstractMongoQuery.execute(AbstractMongoQuery.java:101) ~[spring-data-mongodb-2.2.5.RELEASE.jar!/:2.2.5.RELEASE]
    at org.springframework.data.repository.core.support.RepositoryFactorySupport$QueryExecutorMethodInterceptor.doInvoke(RepositoryFactorySupport.java:618) ~[spring-data-commons-2.2.5.RELEASE.jar!/:2.2.5.RELEASE]
    at org.springframework.data.repository.core.support.RepositoryFactorySupport$QueryExecutorMethodInterceptor.invoke(RepositoryFactorySupport.java:605) ~[spring-data-commons-2.2.5.RELEASE.jar!/:2.2.5.RELEASE]
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) ~[spring-aop-5.2.4.RELEASE.jar!/:5.2.4.RELEASE]
    at org.springframework.data.projection.DefaultMethodInvokingMethodInterceptor.invoke(DefaultMethodInvokingMethodInterceptor.java:80) ~[spring-data-commons-2.2.5.RELEASE.jar!/:2.2.5.RELEASE]
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) ~[spring-aop-5.2.4.RELEASE.jar!/:5.2.4.RELEASE]
    at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:95) ~[spring-aop-5.2.4.RELEASE.jar!/:5.2.4.RELEASE]
    at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186) ~[spring-aop-5.2.4.RELEASE.jar!/:5.2.4.RELEASE]
    at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:212) ~[spring-aop-5.2.4.RELEASE.jar!/:5.2.4.RELEASE]
    at com.sun.proxy.$Proxy98.findByTaskId(Unknown Source) ~[na:na]
    at com.iexec.resultproxy.ipfs.task.IpfsNameService.getIpfsHashForTask(IpfsNameService.java:34) ~[classes!/:na]
    at com.iexec.resultproxy.proxy.ProxyController.getIpfsHashForTask(ProxyController.java:176) ~[classes!/:na]
    at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:na]

How to fix:

Add @Unique to the field taskId of the model IpfsName here.

jeremyjams commented 3 years ago

@zguesmi Your log implies we have a 2-uploaders race condition here: https://github.com/iExecBlockchainComputing/iexec-result-proxy/blob/f878d5e278d4b006344ead37dc11b64c970ca931/src/main/java/com/iexec/resultproxy/proxy/ProxyService.java#L57

zguesmi commented 3 years ago

It might be yes, it should be correctly handled. That might also mean we have fixes to add to the scheduler.

mcornaton commented 3 years ago

This issue seems to arise when two or more workers try to upload their result for the same task before the result proxy is fully initialized. All the requests are put in a queue and then executed simultaneously. E.g:

2021-09-28 12:02:03.309  INFO 1 --- [io-13200-exec-3] o.s.web.servlet.DispatcherServlet        : Completed initialization in 5 ms
2021-09-28 12:02:03.478  INFO 1 --- [io-13200-exec-2] org.mongodb.driver.connection            : Opened connection [connectionId{localValue:3, serverValue:6}] to result-proxy-mongo:13202
2021-09-28 12:02:03.478  INFO 1 --- [io-13200-exec-4] org.mongodb.driver.connection            : Opened connection [connectionId{localValue:2, serverValue:5}] to result-proxy-mongo:13202
2021-09-28 12:02:03.723  INFO 1 --- [io-13200-exec-5] c.i.resultproxy.proxy.ProxyController    : Result uploaded successfully [chainTaskId:0x71d953138e0293b77eeae25b5114cbcc5df53ef9d99c3a153fcd9fe615668883, uploadRequester:0x2ab2674aa374fe6415d11f0a8fcbd8027fc1e6a9, resultLink:/ipfs/QmPbZfnkdoxt4CEmRS2jq7ms8LF9GQuSgBm5NNBsBXNbnh]
2021-09-28 12:02:03.723  INFO 1 --- [io-13200-exec-6] c.i.resultproxy.proxy.ProxyController    : Result uploaded successfully [chainTaskId:0x71d953138e0293b77eeae25b5114cbcc5df53ef9d99c3a153fcd9fe615668883, uploadRequester:0x1a69b2eb604db8eba185df03ea4f5288dcbbd248, resultLink:/ipfs/QmbHadrtdZ5cz9bJTaVRLUnKAWm9442sC1vE1Pg8xMtRAV]
2021-09-28 12:02:03.757 ERROR 1 --- [io-13200-exec-8] o.a.c.c.C.[.[.[/].[dispatcherServlet]    : Servlet.service() for servlet [dispatcherServlet] in context with path [] threw exception [Request processing failed; nested exception is org.springframework.dao.IncorrectResultSizeDataAccessException: Query { "$java" : Query: { "taskId" : "0x71d953138e0293b77eeae25b5114cbcc5df53ef9d99c3a153fcd9fe615668883"}, Fields: {}, Sort: {} } returned non unique result.] with root cause

There's probably something to fix here to make it more robust but the scenario where 2 workers try to upload their result for the same task should not happen.