iExecBlockchainComputing/iexec-core

Handle NPE

Closed this issue · 4 comments

This happened on Goerli network (Goerli is having some strange behaviour in the moment exp: chain reorg....)

https://github.com/iExecBlockchainComputing/iexec-core/blob/master/src/main/java/com/iexec/core/chain/IexecHubService.java#L111
https://github.com/iExecBlockchainComputing/iexec-core/blob/master/src/main/java/com/iexec/core/chain/IexecHubService.java#L146

2020-02-10 10:24:44.021  INFO 1 --- [pool-2-thread-8] com.iexec.core.chain.DealWatcherService  : Received deal [dealId:0xaca33026833319b46ba870a797c2e3cea5ba9dd76a9e64f55bf6f15cfaec0779, block:2153338]
2020-02-10 10:24:44.433  INFO 1 --- [pool-2-thread-8] com.iexec.core.task.TaskService          : Add new task [chainDealId:0xaca33026833319b46ba870a797c2e3cea5ba9dd76a9e64f55bf6f15cfaec0779, taskIndex:0, imageName:registry.hub.docker.com/iexechub/vanityeth:1.1.1, commandLine:python3 /app/app.py, trust:1]
2020-02-10 10:24:44.762  INFO 1 --- [ol-812-thread-1] com.iexec.core.chain.IexecHubService     : Requested  initialize [chainDealId:0xaca33026833319b46ba870a797c2e3cea5ba9dd76a9e64f55bf6f15cfaec0779, taskIndex:0, waitingTxCount:0]
java.util.concurrent.ExecutionException: java.lang.NullPointerException
	at java.base/java.util.concurrent.CompletableFuture.reportGet(Unknown Source)
	at java.base/java.util.concurrent.CompletableFuture.get(Unknown Source)
	at com.iexec.core.chain.IexecHubService.initialize(IexecHubService.java:111)
	at com.iexec.core.task.TaskService.received2Initialized(TaskService.java:184)
	at com.iexec.core.task.TaskService.tryUpgradeTaskStatus(TaskService.java:114)
	at com.iexec.core.task.TaskExecutorEngine.lambda$updateTask$0(TaskExecutorEngine.java:37)
	at java.base/java.util.concurrent.CompletableFuture$AsyncSupply.run(Unknown Source)
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
	at java.base/java.lang.Thread.run(Unknown Source)
Caused by: java.lang.NullPointerException
	at com.iexec.core.chain.IexecHubService.sendInitializeTransaction(IexecHubService.java:146)
	at com.iexec.core.chain.IexecHubService.lambda$initialize$1(IexecHubService.java:111)

Update: this happens with every initialize tx on Goerli even though the explorer displays that the task is initialized.

The same thing happened with the finalize transaction

2020-02-10 13:26:45.622  INFO 1 --- [ol-915-thread-1] com.iexec.core.chain.IexecHubService     : Finalizable onchain [chainTaskId:0xa0812890123a904d48145ba1efe554c199f632a070baeb56bf0b9dc307cc2100]
2020-02-10 13:26:45.700  INFO 1 --- [ol-915-thread-1] com.iexec.core.task.TaskService          : UpdateTaskStatus suceeded [chainTaskId:0xa0812890123a904d48145ba1efe554c199f632a070baeb56bf0b9dc307cc2100, currentStatus:RESULT_UPLOADED, newStatus:FINALIZING]
2020-02-10 13:26:45.701  INFO 1 --- [ol-915-thread-1] com.iexec.core.chain.IexecHubService     : Requested  finalize [chainTaskId:0xa0812890123a904d48145ba1efe554c199f632a070baeb56bf0b9dc307cc2100, waitingTxCount:0]
java.util.concurrent.ExecutionException: java.lang.NullPointerException
	at java.base/java.util.concurrent.CompletableFuture.reportGet(Unknown Source)
	at java.base/java.util.concurrent.CompletableFuture.get(Unknown Source)
	at com.iexec.core.chain.IexecHubService.finalizeTask(IexecHubService.java:187)
	at com.iexec.core.task.TaskService.resultUploaded2Finalizing(TaskService.java:489)
	at com.iexec.core.task.TaskService.resultUploading2Uploaded(TaskService.java:405)
	at com.iexec.core.task.TaskService.tryUpgradeTaskStatus(TaskService.java:139)
	at com.iexec.core.task.TaskExecutorEngine.lambda$updateTask$0(TaskExecutorEngine.java:37)
	at java.base/java.util.concurrent.CompletableFuture$AsyncSupply.run(Unknown Source)
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
	at java.base/java.lang.Thread.run(Unknown Source)
Caused by: java.lang.NullPointerException
	at com.iexec.core.chain.IexecHubService.sendFinalizeTransaction(IexecHubService.java:222)
	at com.iexec.core.chain.IexecHubService.lambda$finalizeTask$2(IexecHubService.java:187)
	... 4 more
2020-02-10 13:27:24.911  INFO 1 --- [ol-915-thread-1] com.iexec.core.task.TaskService          : UpdateTaskStatus suceeded [chainTaskId:0xa0812890123a904d48145ba1efe554c199f632a070baeb56bf0b9dc307cc2100, currentStatus:FINALIZING, newStatus:FINALIZED]
2020-02-10 13:27:24.913  INFO 1 --- [ol-915-thread-1] com.iexec.core.task.TaskService          : UpdateTaskStatus suceeded [chainTaskId:0xa0812890123a904d48145ba1efe554c199f632a070baeb56bf0b9dc307cc2100, currentStatus:FINALIZED, newStatus:COMPLETED]
2020-02-10 13:27:24.913  INFO 1 --- [ol-915-thread-1] c.i.core.task.listener.TaskListeners     : Received TaskCompletedEvent [chainTaskId:0xa0812890123a904d48145ba1efe554c199f632a070baeb56bf0b9dc307cc2100] 
2020-02-10 13:27:24.914  INFO 1 --- [ol-915-thread-1] c.iexec.core.pubsub.NotificationService  : Sent TaskNotification [chainTaskId:0xa0812890123a904d48145ba1efe554c199f632a070baeb56bf0b9dc307cc2100, type:PLEASE_COMPLETE, workers:[]]

Update: this is due to Goerli's frequent reorg problem.

This is already fixed in #353.

Before the fix:

(!initializeEvent.log.getType().equals(PENDING_RECEIPT_STATUS)

(!finalizeEvent.log.getType().equals(PENDING_RECEIPT_STATUS)

After the fix:
if (txEvent.log.getType() == null || txEvent.log.getType().equals(PENDING_RECEIPT_STATUS)) {