Details
-
Bug
-
Status: Open
-
Major
-
Resolution: Unresolved
-
2.0.0
-
None
Description
When we kill a topology, at the moment of topology blob-files be removed, Supervisor executor still request blob-files and get an KeyNotFoundException.
I stepped in and found the reason:
1. We do not add a guarded lock on `topologyBlobs` of AsyncLocalizer which is singleton to a supervisor node.
2. And we remove jar/code/conf blob keys in `topologyBlobs` of killed storm only in a timer task: cleanUp() method of AsyncLocalizer, the remove condition is :[no one reference the blobs] AND [ blobs removed by master OR exceeds the max configured size ], the default scheduling interval is 30 seconds.
3. When we kill a storm on a node[ which means that the slot container are empty], the AsyncLocalizer will do: releaseSlotFor, which only remove reference on the blobs [topologyBlobs keys are still there.]
4. Then the container is empty, and Slot.java will do: cleanupCurrentContainer, which will invoke AsyncLocalizer #releaseSlotFor to release the slot.
5. AsyncLocalizer have a timer task: updateBlobs to update base/user blobs every 30 seconds, which based on the AsyncLocalizer#`topologyBlobs`
6. We know that AsyncLocalizer#`topologyBlobs` overdue keys are only removed by its AsyncLocalizer#cleanUp which is also a timer task.
7. So when we kill a storm, AsyncLocalizer#updateBlobs will update based on a removed jar/code/conf blob-key and fire a exception, then retried until the configured max times to end.
Here is how i fixed it:
1. just remove the base blob keys eagerly when we do AsyncLocalizer #releaseSlotFor when there is no reference [no one used] on the blobs, and remove the overdue keys in AsyncLocalizer#`topologyBlobs`
2. Guard the AsyncLocalizer#updateBlobs and AsyncLocalizer #releaseSlotFor on the same lock.
3. When container is empty, we do not need to exec AsyncLocalizer #releaseSlotFor[because we have already deleted them].
4. I also add a new RPC api for decide if there exists a remote blob, we can use it to decide it the blob could be removed instead of use getBlobMeta and catch an confusing KeyNotFoundException [both on supervisors and master log for every base blobs].
This is the partial of Supervisor log:
2018-03-31 13:41:17.089 o.a.s.d.s.AdvancedFSOps SLOT_6700 [INFO] Deleting path /Users/danny0405/workspace/storm-2.x-test/supervisor1/apache-storm-2.0.0-SNAPSHOT/storm-local/workers/b50aa089-6584-498e-a5cc-85cba13e4cb0/pids/1115
2018-03-31 13:41:17.090 o.a.s.d.s.AdvancedFSOps SLOT_6700 [INFO] Deleting path /Users/danny0405/workspace/storm-2.x-test/supervisor1/apache-storm-2.0.0-SNAPSHOT/storm-local/workers/b50aa089-6584-498e-a5cc-85cba13e4cb0/heartbeats
2018-03-31 13:41:17.102 o.a.s.d.s.AdvancedFSOps SLOT_6700 [INFO] Deleting path /Users/danny0405/workspace/storm-2.x-test/supervisor1/apache-storm-2.0.0-SNAPSHOT/storm-local/workers/b50aa089-6584-498e-a5cc-85cba13e4cb0/pids
2018-03-31 13:41:17.102 o.a.s.d.s.AdvancedFSOps SLOT_6700 [INFO] Deleting path /Users/danny0405/workspace/storm-2.x-test/supervisor1/apache-storm-2.0.0-SNAPSHOT/storm-local/workers/b50aa089-6584-498e-a5cc-85cba13e4cb0/tmp
2018-03-31 13:41:17.102 o.a.s.d.s.AdvancedFSOps SLOT_6700 [INFO] Deleting path /Users/danny0405/workspace/storm-2.x-test/supervisor1/apache-storm-2.0.0-SNAPSHOT/storm-local/workers/b50aa089-6584-498e-a5cc-85cba13e4cb0
2018-03-31 13:41:17.103 o.a.s.d.s.Container SLOT_6700 [INFO] REMOVE worker-user b50aa089-6584-498e-a5cc-85cba13e4cb0
2018-03-31 13:41:17.103 o.a.s.d.s.AdvancedFSOps SLOT_6700 [INFO] Deleting path /Users/danny0405/workspace/storm-2.x-test/supervisor1/apache-storm-2.0.0-SNAPSHOT/storm-local/workers-users/b50aa089-6584-498e-a5cc-85cba13e4cb0
2018-03-31 13:41:17.104 o.a.s.d.s.BasicContainer SLOT_6700 [INFO] Removed Worker ID b50aa089-6584-498e-a5cc-85cba13e4cb0
2018-03-31 13:41:17.105 o.a.s.d.s.Slot SLOT_6700 [INFO] STATE KILL msInState: 25 topo:word_count_fk_11-2-1522472558 worker:null -> EMPTY msInState: 0
2018-03-31 13:41:17.105 o.a.s.d.s.Slot SLOT_6700 [INFO] SLOT 6700: Changing current assignment from LocalAssignment(topology_id:word_count_fk_11-2-1522472558, executors:[ExecutorInfo(task_start:7, task_end:7), ExecutorInfo(task_start:6, task_end:6), ExecutorInfo(task_start:5, task_end:5), ExecutorInfo(task_start:4, task_end:4), ExecutorInfo(task_start:3, task_end:3), ExecutorInfo(task_start:2, task_end:2), ExecutorInfo(task_start:1, task_end:1)], resources:WorkerResources(mem_on_heap:896.0, mem_off_heap:0.0, cpu:70.0, shared_mem_on_heap:0.0, shared_mem_off_heap:0.0, resources:
, shared_resources:{}), owner:danny0405) to null
2018-03-31 13:41:18.001 o.a.s.d.s.t.SupervisorHealthCheck timer [INFO] Running supervisor healthchecks...
2018-03-31 13:41:18.002 o.a.s.h.HealthChecker timer [INFO] The supervisor healthchecks succeeded.
2018-03-31 13:41:36.837 o.a.s.l.AsyncLocalizer AsyncLocalizer Executor - 1 [WARN] Failed to download blob LOCAL TOPO BLOB TOPO_JAR word_count_fk_11-2-1522472558 will try again in 100 ms
org.apache.storm.generated.KeyNotFoundException: null
at org.apache.storm.generated.Nimbus$getBlobMeta_result$getBlobMeta_resultStandardScheme.read(Nimbus.java:25225) ~[storm-client-2.0.0-SNAPSHOT.jar:2.0.0-SNAPSHOT]
at org.apache.storm.generated.Nimbus$getBlobMeta_result$getBlobMeta_resultStandardScheme.read(Nimbus.java:25193) ~[storm-client-2.0.0-SNAPSHOT.jar:2.0.0-SNAPSHOT]
at org.apache.storm.generated.Nimbus$getBlobMeta_result.read(Nimbus.java:25124) ~[storm-client-2.0.0-SNAPSHOT.jar:2.0.0-SNAPSHOT]
at org.apache.thrift.TServiceClient.receiveBase(TServiceClient.java:86) ~[libthrift-0.9.3.jar:0.9.3]
at org.apache.storm.generated.Nimbus$Client.recv_getBlobMeta(Nimbus.java:825) ~[storm-client-2.0.0-SNAPSHOT.jar:2.0.0-SNAPSHOT]
at org.apache.storm.generated.Nimbus$Client.getBlobMeta(Nimbus.java:812) ~[storm-client-2.0.0-SNAPSHOT.jar:2.0.0-SNAPSHOT]
at org.apache.storm.blobstore.NimbusBlobStore.getBlobMeta(NimbusBlobStore.java:318) ~[storm-client-2.0.0-SNAPSHOT.jar:2.0.0-SNAPSHOT]
at org.apache.storm.localizer.LocallyCachedTopologyBlob.getRemoteVersion(LocallyCachedTopologyBlob.java:176) ~[storm-server-2.0.0-SNAPSHOT.jar:2.0.0-SNAPSHOT]
at org.apache.storm.localizer.AsyncLocalizer.lambda$downloadOrUpdate$5(AsyncLocalizer.java:249) ~[storm-server-2.0.0-SNAPSHOT.jar:2.0.0-SNAPSHOT]
at java.util.concurrent.CompletableFuture$AsyncRun.run(CompletableFuture.java:1626) [?:1.8.0_151]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:1.8.0_151]
at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:1.8.0_151]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) [?:1.8.0_151]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) [?:1.8.0_151]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_151]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_151]
at java.lang.Thread.run(Thread.java:748) [?:1.8.0_151]
Attachments
Issue Links
- links to
