[ 
https://issues.apache.org/jira/browse/STORM-3104?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
 ]

Zhengdai Hu updated STORM-3104:
-------------------------------
    Description: 
In Slot.java, there is a comparison in 
{code:java}
handleWaitingForBlobUpdate()
{code}
 between dynamic state's current assignment and new assignment, which 
accidentally route back state machine just transitioned from 
WAIT_FOR_BLOB_LOCALIZATION back to WAIT_FOR_BLOB_LOCALIZATION, because the 
current assignment in this case is highly likely to be null (I'm not sure if 
it's guaranteed). This causes delay for a worker to start/restart.

The symptom is able to be reproduced by launching an empty supervisor and 
submit any topology. Here's the log sample:

{code:sh}
2018-06-13 16:57:10.254 o.a.s.d.s.Slot SLOT_6700 [INFO] STATE EMPTY msInState: 
6024 -> EMPTY msInState: 6024
2018-06-13 16:57:10.255 o.a.s.d.s.Slot SLOT_6700 [DEBUG] STATE EMPTY
2018-06-13 16:57:10.257 o.a.s.d.s.Slot SLOT_6700 [DEBUG] Transition from EMPTY 
to WAITING_FOR_BLOB_LOCALIZATION
2018-06-13 16:57:10.257 o.a.s.d.s.Slot SLOT_6700 [INFO] STATE EMPTY msInState: 
6027 -> WAITING_FOR_BLOB_LOCALIZATION msInState: 0
2018-06-13 16:57:10.258 o.a.s.d.s.Slot SLOT_6700 [DEBUG] STATE 
WAITING_FOR_BLOB_LOCALIZATION
2018-06-13 16:57:10.258 o.a.s.d.s.Slot SLOT_6700 [DEBUG] pendingChangingBlobs 
are []
2018-06-13 16:57:11.259 o.a.s.d.s.Slot SLOT_6700 [INFO] STATE 
WAITING_FOR_BLOB_LOCALIZATION msInState: 1003 -> WAITING_FOR_BLOB_LOCALIZATION 
msInState: 1003
2018-06-13 16:57:11.260 o.a.s.d.s.Slot SLOT_6700 [DEBUG] STATE 
WAITING_FOR_BLOB_LOCALIZATION
2018-06-13 16:57:11.260 o.a.s.d.s.Slot SLOT_6700 [DEBUG] found changing blobs 
[BLOB CHANGING LOCAL TOPO BLOB TOPO_CONF test-1-1528927024 
LocalAssignment(topology_id:test-1-1528927024, 
executors:[ExecutorInfo(task_start:10, task_end:10), 
ExecutorInfo(task_start:16, task_end:16), ExecutorInfo(task_start:4, 
task_end:4), ExecutorInfo(task_start:7, task_end:7), ExecutorInfo(task_start:1, 
task_end:1), ExecutorInfo(task_start:13, task_end:13)], 
resources:WorkerResources(mem_on_heap:768.0, mem_off_heap:0.0, cpu:60.0, 
shared_mem_on_heap:0.0, shared_mem_off_heap:0.0, 
resources:{offheap.memory.mb=0.0, onheap.memory.mb=768.0, 
cpu.pcore.percent=60.0}, shared_resources:{}), owner:zhu02), BLOB CHANGING 
LOCAL TOPO BLOB TOPO_CODE test-1-1528927024 
LocalAssignment(topology_id:test-1-1528927024, 
executors:[ExecutorInfo(task_start:10, task_end:10), 
ExecutorInfo(task_start:16, task_end:16), ExecutorInfo(task_start:4, 
task_end:4), ExecutorInfo(task_start:7, task_end:7), ExecutorInfo(task_start:1, 
task_end:1), ExecutorInfo(task_start:13, task_end:13)], 
resources:WorkerResources(mem_on_heap:768.0, mem_off_heap:0.0, cpu:60.0, 
shared_mem_on_heap:0.0, shared_mem_off_heap:0.0, 
resources:{offheap.memory.mb=0.0, onheap.memory.mb=768.0, 
cpu.pcore.percent=60.0}, shared_resources:{}), owner:zhu02)] moving them to 
pending...
2018-06-13 16:57:12.262 o.a.s.d.s.Slot SLOT_6700 [INFO] STATE 
WAITING_FOR_BLOB_LOCALIZATION msInState: 2005 -> WAITING_FOR_BLOB_LOCALIZATION 
msInState: 2005
2018-06-13 16:57:12.263 o.a.s.d.s.Slot SLOT_6700 [DEBUG] STATE 
WAITING_FOR_BLOB_LOCALIZATION
2018-06-13 16:57:12.263 o.a.s.d.s.Slot SLOT_6700 [DEBUG] found changing blobs 
[BLOB CHANGING LOCAL TOPO BLOB TOPO_JAR test-1-1528927024 
LocalAssignment(topology_id:test-1-1528927024, 
executors:[ExecutorInfo(task_start:10, task_end:10), 
ExecutorInfo(task_start:16, task_end:16), ExecutorInfo(task_start:4, 
task_end:4), ExecutorInfo(task_start:7, task_end:7), ExecutorInfo(task_start:1, 
task_end:1), ExecutorInfo(task_start:13, task_end:13)], 
resources:WorkerResources(mem_on_heap:768.0, mem_off_heap:0.0, cpu:60.0, 
shared_mem_on_heap:0.0, shared_mem_off_heap:0.0, 
resources:{offheap.memory.mb=0.0, onheap.memory.mb=768.0, 
cpu.pcore.percent=60.0}, shared_resources:{}), owner:zhu02)] moving them to 
pending...
2018-06-13 16:57:12.274 o.a.s.d.s.Slot SLOT_6700 [DEBUG] pendingLocalization 
LocalAssignment(topology_id:test-1-1528927024, 
executors:[ExecutorInfo(task_start:10, task_end:10), 
ExecutorInfo(task_start:16, task_end:16), ExecutorInfo(task_start:4, 
task_end:4), ExecutorInfo(task_start:7, task_end:7), ExecutorInfo(task_start:1, 
task_end:1), ExecutorInfo(task_start:13, task_end:13)], 
resources:WorkerResources(mem_on_heap:768.0, mem_off_heap:0.0, cpu:60.0, 
shared_mem_on_heap:0.0, shared_mem_off_heap:0.0, 
resources:{offheap.memory.mb=0.0, onheap.memory.mb=768.0, 
cpu.pcore.percent=60.0}, shared_resources:{}), owner:zhu02) == current null ? 
false
2018-06-13 16:57:12.274 o.a.s.d.s.Slot SLOT_6700 [INFO] There are pending 
changes, waiting for them to finish before launching container...
2018-06-13 16:57:12.275 o.a.s.d.s.Slot SLOT_6700 [DEBUG] Transition from 
WAITING_FOR_BLOB_LOCALIZATION to WAITING_FOR_BLOB_UPDATE
2018-06-13 16:57:12.275 o.a.s.d.s.Slot SLOT_6700 [INFO] STATE 
WAITING_FOR_BLOB_LOCALIZATION msInState: 2018 -> WAITING_FOR_BLOB_UPDATE 
msInState: 1
2018-06-13 16:57:12.275 o.a.s.d.s.Slot SLOT_6700 [DEBUG] STATE 
WAITING_FOR_BLOB_UPDATE
2018-06-13 16:57:12.275 o.a.s.d.s.Slot SLOT_6700 [DEBUG] pendingLocalization: 
null, new: LocalAssignment(topology_id:test-1-1528927024, 
executors:[ExecutorInfo(task_start:10, task_end:10), 
ExecutorInfo(task_start:16, task_end:16), ExecutorInfo(task_start:4, 
task_end:4), ExecutorInfo(task_start:7, task_end:7), ExecutorInfo(task_start:1, 
task_end:1), ExecutorInfo(task_start:13, task_end:13)], 
resources:WorkerResources(mem_on_heap:768.0, mem_off_heap:0.0, cpu:60.0, 
shared_mem_on_heap:0.0, shared_mem_off_heap:0.0, 
resources:{offheap.memory.mb=0.0, onheap.memory.mb=768.0, 
cpu.pcore.percent=60.0}, shared_resources:{}), owner:zhu02), current: null, 
pdchanging: LocalAssignment(topology_id:test-1-1528927024, 
executors:[ExecutorInfo(task_start:10, task_end:10), 
ExecutorInfo(task_start:16, task_end:16), ExecutorInfo(task_start:4, 
task_end:4), ExecutorInfo(task_start:7, task_end:7), ExecutorInfo(task_start:1, 
task_end:1), ExecutorInfo(task_start:13, task_end:13)], 
resources:WorkerResources(mem_on_heap:768.0, mem_off_heap:0.0, cpu:60.0, 
shared_mem_on_heap:0.0, shared_mem_off_heap:0.0, 
resources:{offheap.memory.mb=0.0, onheap.memory.mb=768.0, 
cpu.pcore.percent=60.0}, shared_resources:{}), owner:zhu02)
2018-06-13 16:57:12.276 o.a.s.d.s.Slot SLOT_6700 [INFO] SLOT 6700: Assignment 
Changed from null to LocalAssignment(topology_id:test-1-1528927024, 
executors:[ExecutorInfo(task_start:10, task_end:10), 
ExecutorInfo(task_start:16, task_end:16), ExecutorInfo(task_start:4, 
task_end:4), ExecutorInfo(task_start:7, task_end:7), ExecutorInfo(task_start:1, 
task_end:1), ExecutorInfo(task_start:13, task_end:13)], 
resources:WorkerResources(mem_on_heap:768.0, mem_off_heap:0.0, cpu:60.0, 
shared_mem_on_heap:0.0, shared_mem_off_heap:0.0, 
resources:{offheap.memory.mb=0.0, onheap.memory.mb=768.0, 
cpu.pcore.percent=60.0}, shared_resources:{}), owner:zhu02)
2018-06-13 16:57:12.278 o.a.s.d.s.Slot SLOT_6700 [DEBUG] Transition from 
WAITING_FOR_BLOB_UPDATE to WAITING_FOR_BLOB_LOCALIZATION
2018-06-13 16:57:12.278 o.a.s.d.s.Slot SLOT_6700 [INFO] STATE 
WAITING_FOR_BLOB_UPDATE msInState: 4 -> WAITING_FOR_BLOB_LOCALIZATION 
msInState: 0
2018-06-13 16:57:12.279 o.a.s.d.s.Slot SLOT_6700 [DEBUG] STATE 
WAITING_FOR_BLOB_LOCALIZATION
2018-06-13 16:57:12.279 o.a.s.d.s.Slot SLOT_6700 [DEBUG] pendingChangingBlobs 
are []
2018-06-13 16:57:12.279 o.a.s.d.s.Slot SLOT_6700 [DEBUG] pendingLocalization 
LocalAssignment(topology_id:test-1-1528927024, 
executors:[ExecutorInfo(task_start:10, task_end:10), 
ExecutorInfo(task_start:16, task_end:16), ExecutorInfo(task_start:4, 
task_end:4), ExecutorInfo(task_start:7, task_end:7), ExecutorInfo(task_start:1, 
task_end:1), ExecutorInfo(task_start:13, task_end:13)], 
resources:WorkerResources(mem_on_heap:768.0, mem_off_heap:0.0, cpu:60.0, 
shared_mem_on_heap:0.0, shared_mem_off_heap:0.0, 
resources:{offheap.memory.mb=0.0, onheap.memory.mb=768.0, 
cpu.pcore.percent=60.0}, shared_resources:{}), owner:zhu02) == current null ? 
false
2018-06-13 16:57:12.280 o.a.s.d.s.Slot SLOT_6700 [DEBUG] launch container for 
the first time
2018-06-13 16:57:12.284 o.a.s.d.s.BasicContainer SLOT_6700 [INFO] Created 
Worker ID 4155b2bb-ebd1-431d-907f-d8a4ff1e1da4

{code}

I would like to know if this is actually the desired behavior of the state 
machine, or I can help fix the bug. The implementation would be to redesign the 
if statement.

  was:
In Slot.java, there is a comparison in 
{code:java}
handleWaitingForBlobUpdate()
{code}
 between dynamic state's current assignment and new assignment, which 
accidentally route back state machine just transitioned from 
WAIT_FOR_BLOB_LOCALIZATION back to WAIT_FOR_BLOB_LOCALIZATION. This is because 
the current assignment in this case is highly likely to be null (I'm not sure 
if it's guaranteed) and causes delay for a worker to start/restart.

The symptom is able to be reproduced by launching an empty supervisor and 
submit any topology. Here's the log sample:

{code:sh}
2018-06-13 16:57:10.254 o.a.s.d.s.Slot SLOT_6700 [INFO] STATE EMPTY msInState: 
6024 -> EMPTY msInState: 6024
2018-06-13 16:57:10.255 o.a.s.d.s.Slot SLOT_6700 [DEBUG] STATE EMPTY
2018-06-13 16:57:10.257 o.a.s.d.s.Slot SLOT_6700 [DEBUG] Transition from EMPTY 
to WAITING_FOR_BLOB_LOCALIZATION
2018-06-13 16:57:10.257 o.a.s.d.s.Slot SLOT_6700 [INFO] STATE EMPTY msInState: 
6027 -> WAITING_FOR_BLOB_LOCALIZATION msInState: 0
2018-06-13 16:57:10.258 o.a.s.d.s.Slot SLOT_6700 [DEBUG] STATE 
WAITING_FOR_BLOB_LOCALIZATION
2018-06-13 16:57:10.258 o.a.s.d.s.Slot SLOT_6700 [DEBUG] pendingChangingBlobs 
are []
2018-06-13 16:57:11.259 o.a.s.d.s.Slot SLOT_6700 [INFO] STATE 
WAITING_FOR_BLOB_LOCALIZATION msInState: 1003 -> WAITING_FOR_BLOB_LOCALIZATION 
msInState: 1003
2018-06-13 16:57:11.260 o.a.s.d.s.Slot SLOT_6700 [DEBUG] STATE 
WAITING_FOR_BLOB_LOCALIZATION
2018-06-13 16:57:11.260 o.a.s.d.s.Slot SLOT_6700 [DEBUG] found changing blobs 
[BLOB CHANGING LOCAL TOPO BLOB TOPO_CONF test-1-1528927024 
LocalAssignment(topology_id:test-1-1528927024, 
executors:[ExecutorInfo(task_start:10, task_end:10), 
ExecutorInfo(task_start:16, task_end:16), ExecutorInfo(task_start:4, 
task_end:4), ExecutorInfo(task_start:7, task_end:7), ExecutorInfo(task_start:1, 
task_end:1), ExecutorInfo(task_start:13, task_end:13)], 
resources:WorkerResources(mem_on_heap:768.0, mem_off_heap:0.0, cpu:60.0, 
shared_mem_on_heap:0.0, shared_mem_off_heap:0.0, 
resources:{offheap.memory.mb=0.0, onheap.memory.mb=768.0, 
cpu.pcore.percent=60.0}, shared_resources:{}), owner:zhu02), BLOB CHANGING 
LOCAL TOPO BLOB TOPO_CODE test-1-1528927024 
LocalAssignment(topology_id:test-1-1528927024, 
executors:[ExecutorInfo(task_start:10, task_end:10), 
ExecutorInfo(task_start:16, task_end:16), ExecutorInfo(task_start:4, 
task_end:4), ExecutorInfo(task_start:7, task_end:7), ExecutorInfo(task_start:1, 
task_end:1), ExecutorInfo(task_start:13, task_end:13)], 
resources:WorkerResources(mem_on_heap:768.0, mem_off_heap:0.0, cpu:60.0, 
shared_mem_on_heap:0.0, shared_mem_off_heap:0.0, 
resources:{offheap.memory.mb=0.0, onheap.memory.mb=768.0, 
cpu.pcore.percent=60.0}, shared_resources:{}), owner:zhu02)] moving them to 
pending...
2018-06-13 16:57:12.262 o.a.s.d.s.Slot SLOT_6700 [INFO] STATE 
WAITING_FOR_BLOB_LOCALIZATION msInState: 2005 -> WAITING_FOR_BLOB_LOCALIZATION 
msInState: 2005
2018-06-13 16:57:12.263 o.a.s.d.s.Slot SLOT_6700 [DEBUG] STATE 
WAITING_FOR_BLOB_LOCALIZATION
2018-06-13 16:57:12.263 o.a.s.d.s.Slot SLOT_6700 [DEBUG] found changing blobs 
[BLOB CHANGING LOCAL TOPO BLOB TOPO_JAR test-1-1528927024 
LocalAssignment(topology_id:test-1-1528927024, 
executors:[ExecutorInfo(task_start:10, task_end:10), 
ExecutorInfo(task_start:16, task_end:16), ExecutorInfo(task_start:4, 
task_end:4), ExecutorInfo(task_start:7, task_end:7), ExecutorInfo(task_start:1, 
task_end:1), ExecutorInfo(task_start:13, task_end:13)], 
resources:WorkerResources(mem_on_heap:768.0, mem_off_heap:0.0, cpu:60.0, 
shared_mem_on_heap:0.0, shared_mem_off_heap:0.0, 
resources:{offheap.memory.mb=0.0, onheap.memory.mb=768.0, 
cpu.pcore.percent=60.0}, shared_resources:{}), owner:zhu02)] moving them to 
pending...
2018-06-13 16:57:12.274 o.a.s.d.s.Slot SLOT_6700 [DEBUG] pendingLocalization 
LocalAssignment(topology_id:test-1-1528927024, 
executors:[ExecutorInfo(task_start:10, task_end:10), 
ExecutorInfo(task_start:16, task_end:16), ExecutorInfo(task_start:4, 
task_end:4), ExecutorInfo(task_start:7, task_end:7), ExecutorInfo(task_start:1, 
task_end:1), ExecutorInfo(task_start:13, task_end:13)], 
resources:WorkerResources(mem_on_heap:768.0, mem_off_heap:0.0, cpu:60.0, 
shared_mem_on_heap:0.0, shared_mem_off_heap:0.0, 
resources:{offheap.memory.mb=0.0, onheap.memory.mb=768.0, 
cpu.pcore.percent=60.0}, shared_resources:{}), owner:zhu02) == current null ? 
false
2018-06-13 16:57:12.274 o.a.s.d.s.Slot SLOT_6700 [INFO] There are pending 
changes, waiting for them to finish before launching container...
2018-06-13 16:57:12.275 o.a.s.d.s.Slot SLOT_6700 [DEBUG] Transition from 
WAITING_FOR_BLOB_LOCALIZATION to WAITING_FOR_BLOB_UPDATE
2018-06-13 16:57:12.275 o.a.s.d.s.Slot SLOT_6700 [INFO] STATE 
WAITING_FOR_BLOB_LOCALIZATION msInState: 2018 -> WAITING_FOR_BLOB_UPDATE 
msInState: 1
2018-06-13 16:57:12.275 o.a.s.d.s.Slot SLOT_6700 [DEBUG] STATE 
WAITING_FOR_BLOB_UPDATE
2018-06-13 16:57:12.275 o.a.s.d.s.Slot SLOT_6700 [DEBUG] pendingLocalization: 
null, new: LocalAssignment(topology_id:test-1-1528927024, 
executors:[ExecutorInfo(task_start:10, task_end:10), 
ExecutorInfo(task_start:16, task_end:16), ExecutorInfo(task_start:4, 
task_end:4), ExecutorInfo(task_start:7, task_end:7), ExecutorInfo(task_start:1, 
task_end:1), ExecutorInfo(task_start:13, task_end:13)], 
resources:WorkerResources(mem_on_heap:768.0, mem_off_heap:0.0, cpu:60.0, 
shared_mem_on_heap:0.0, shared_mem_off_heap:0.0, 
resources:{offheap.memory.mb=0.0, onheap.memory.mb=768.0, 
cpu.pcore.percent=60.0}, shared_resources:{}), owner:zhu02), current: null, 
pdchanging: LocalAssignment(topology_id:test-1-1528927024, 
executors:[ExecutorInfo(task_start:10, task_end:10), 
ExecutorInfo(task_start:16, task_end:16), ExecutorInfo(task_start:4, 
task_end:4), ExecutorInfo(task_start:7, task_end:7), ExecutorInfo(task_start:1, 
task_end:1), ExecutorInfo(task_start:13, task_end:13)], 
resources:WorkerResources(mem_on_heap:768.0, mem_off_heap:0.0, cpu:60.0, 
shared_mem_on_heap:0.0, shared_mem_off_heap:0.0, 
resources:{offheap.memory.mb=0.0, onheap.memory.mb=768.0, 
cpu.pcore.percent=60.0}, shared_resources:{}), owner:zhu02)
2018-06-13 16:57:12.276 o.a.s.d.s.Slot SLOT_6700 [INFO] SLOT 6700: Assignment 
Changed from null to LocalAssignment(topology_id:test-1-1528927024, 
executors:[ExecutorInfo(task_start:10, task_end:10), 
ExecutorInfo(task_start:16, task_end:16), ExecutorInfo(task_start:4, 
task_end:4), ExecutorInfo(task_start:7, task_end:7), ExecutorInfo(task_start:1, 
task_end:1), ExecutorInfo(task_start:13, task_end:13)], 
resources:WorkerResources(mem_on_heap:768.0, mem_off_heap:0.0, cpu:60.0, 
shared_mem_on_heap:0.0, shared_mem_off_heap:0.0, 
resources:{offheap.memory.mb=0.0, onheap.memory.mb=768.0, 
cpu.pcore.percent=60.0}, shared_resources:{}), owner:zhu02)
2018-06-13 16:57:12.278 o.a.s.d.s.Slot SLOT_6700 [DEBUG] Transition from 
WAITING_FOR_BLOB_UPDATE to WAITING_FOR_BLOB_LOCALIZATION
2018-06-13 16:57:12.278 o.a.s.d.s.Slot SLOT_6700 [INFO] STATE 
WAITING_FOR_BLOB_UPDATE msInState: 4 -> WAITING_FOR_BLOB_LOCALIZATION 
msInState: 0
2018-06-13 16:57:12.279 o.a.s.d.s.Slot SLOT_6700 [DEBUG] STATE 
WAITING_FOR_BLOB_LOCALIZATION
2018-06-13 16:57:12.279 o.a.s.d.s.Slot SLOT_6700 [DEBUG] pendingChangingBlobs 
are []
2018-06-13 16:57:12.279 o.a.s.d.s.Slot SLOT_6700 [DEBUG] pendingLocalization 
LocalAssignment(topology_id:test-1-1528927024, 
executors:[ExecutorInfo(task_start:10, task_end:10), 
ExecutorInfo(task_start:16, task_end:16), ExecutorInfo(task_start:4, 
task_end:4), ExecutorInfo(task_start:7, task_end:7), ExecutorInfo(task_start:1, 
task_end:1), ExecutorInfo(task_start:13, task_end:13)], 
resources:WorkerResources(mem_on_heap:768.0, mem_off_heap:0.0, cpu:60.0, 
shared_mem_on_heap:0.0, shared_mem_off_heap:0.0, 
resources:{offheap.memory.mb=0.0, onheap.memory.mb=768.0, 
cpu.pcore.percent=60.0}, shared_resources:{}), owner:zhu02) == current null ? 
false
2018-06-13 16:57:12.280 o.a.s.d.s.Slot SLOT_6700 [DEBUG] launch container for 
the first time
2018-06-13 16:57:12.284 o.a.s.d.s.BasicContainer SLOT_6700 [INFO] Created 
Worker ID 4155b2bb-ebd1-431d-907f-d8a4ff1e1da4

{code}

I would like to know if this is actually the desired behavior of the state 
machine, or I can help fix the bug. The implementation would be to redesign the 
if statement.


> Delayed worker launch due to accidental transitioning in state machine
> ----------------------------------------------------------------------
>
>                 Key: STORM-3104
>                 URL: https://issues.apache.org/jira/browse/STORM-3104
>             Project: Apache Storm
>          Issue Type: Bug
>          Components: storm-server
>    Affects Versions: 2.0.0
>            Reporter: Zhengdai Hu
>            Priority: Critical
>             Fix For: 2.0.0
>
>
> In Slot.java, there is a comparison in 
> {code:java}
> handleWaitingForBlobUpdate()
> {code}
>  between dynamic state's current assignment and new assignment, which 
> accidentally route back state machine just transitioned from 
> WAIT_FOR_BLOB_LOCALIZATION back to WAIT_FOR_BLOB_LOCALIZATION, because the 
> current assignment in this case is highly likely to be null (I'm not sure if 
> it's guaranteed). This causes delay for a worker to start/restart.
> The symptom is able to be reproduced by launching an empty supervisor and 
> submit any topology. Here's the log sample:
> {code:sh}
> 2018-06-13 16:57:10.254 o.a.s.d.s.Slot SLOT_6700 [INFO] STATE EMPTY 
> msInState: 6024 -> EMPTY msInState: 6024
> 2018-06-13 16:57:10.255 o.a.s.d.s.Slot SLOT_6700 [DEBUG] STATE EMPTY
> 2018-06-13 16:57:10.257 o.a.s.d.s.Slot SLOT_6700 [DEBUG] Transition from 
> EMPTY to WAITING_FOR_BLOB_LOCALIZATION
> 2018-06-13 16:57:10.257 o.a.s.d.s.Slot SLOT_6700 [INFO] STATE EMPTY 
> msInState: 6027 -> WAITING_FOR_BLOB_LOCALIZATION msInState: 0
> 2018-06-13 16:57:10.258 o.a.s.d.s.Slot SLOT_6700 [DEBUG] STATE 
> WAITING_FOR_BLOB_LOCALIZATION
> 2018-06-13 16:57:10.258 o.a.s.d.s.Slot SLOT_6700 [DEBUG] pendingChangingBlobs 
> are []
> 2018-06-13 16:57:11.259 o.a.s.d.s.Slot SLOT_6700 [INFO] STATE 
> WAITING_FOR_BLOB_LOCALIZATION msInState: 1003 -> 
> WAITING_FOR_BLOB_LOCALIZATION msInState: 1003
> 2018-06-13 16:57:11.260 o.a.s.d.s.Slot SLOT_6700 [DEBUG] STATE 
> WAITING_FOR_BLOB_LOCALIZATION
> 2018-06-13 16:57:11.260 o.a.s.d.s.Slot SLOT_6700 [DEBUG] found changing blobs 
> [BLOB CHANGING LOCAL TOPO BLOB TOPO_CONF test-1-1528927024 
> LocalAssignment(topology_id:test-1-1528927024, 
> executors:[ExecutorInfo(task_start:10, task_end:10), 
> ExecutorInfo(task_start:16, task_end:16), ExecutorInfo(task_start:4, 
> task_end:4), ExecutorInfo(task_start:7, task_end:7), 
> ExecutorInfo(task_start:1, task_end:1), ExecutorInfo(task_start:13, 
> task_end:13)], resources:WorkerResources(mem_on_heap:768.0, mem_off_heap:0.0, 
> cpu:60.0, shared_mem_on_heap:0.0, shared_mem_off_heap:0.0, 
> resources:{offheap.memory.mb=0.0, onheap.memory.mb=768.0, 
> cpu.pcore.percent=60.0}, shared_resources:{}), owner:zhu02), BLOB CHANGING 
> LOCAL TOPO BLOB TOPO_CODE test-1-1528927024 
> LocalAssignment(topology_id:test-1-1528927024, 
> executors:[ExecutorInfo(task_start:10, task_end:10), 
> ExecutorInfo(task_start:16, task_end:16), ExecutorInfo(task_start:4, 
> task_end:4), ExecutorInfo(task_start:7, task_end:7), 
> ExecutorInfo(task_start:1, task_end:1), ExecutorInfo(task_start:13, 
> task_end:13)], resources:WorkerResources(mem_on_heap:768.0, mem_off_heap:0.0, 
> cpu:60.0, shared_mem_on_heap:0.0, shared_mem_off_heap:0.0, 
> resources:{offheap.memory.mb=0.0, onheap.memory.mb=768.0, 
> cpu.pcore.percent=60.0}, shared_resources:{}), owner:zhu02)] moving them to 
> pending...
> 2018-06-13 16:57:12.262 o.a.s.d.s.Slot SLOT_6700 [INFO] STATE 
> WAITING_FOR_BLOB_LOCALIZATION msInState: 2005 -> 
> WAITING_FOR_BLOB_LOCALIZATION msInState: 2005
> 2018-06-13 16:57:12.263 o.a.s.d.s.Slot SLOT_6700 [DEBUG] STATE 
> WAITING_FOR_BLOB_LOCALIZATION
> 2018-06-13 16:57:12.263 o.a.s.d.s.Slot SLOT_6700 [DEBUG] found changing blobs 
> [BLOB CHANGING LOCAL TOPO BLOB TOPO_JAR test-1-1528927024 
> LocalAssignment(topology_id:test-1-1528927024, 
> executors:[ExecutorInfo(task_start:10, task_end:10), 
> ExecutorInfo(task_start:16, task_end:16), ExecutorInfo(task_start:4, 
> task_end:4), ExecutorInfo(task_start:7, task_end:7), 
> ExecutorInfo(task_start:1, task_end:1), ExecutorInfo(task_start:13, 
> task_end:13)], resources:WorkerResources(mem_on_heap:768.0, mem_off_heap:0.0, 
> cpu:60.0, shared_mem_on_heap:0.0, shared_mem_off_heap:0.0, 
> resources:{offheap.memory.mb=0.0, onheap.memory.mb=768.0, 
> cpu.pcore.percent=60.0}, shared_resources:{}), owner:zhu02)] moving them to 
> pending...
> 2018-06-13 16:57:12.274 o.a.s.d.s.Slot SLOT_6700 [DEBUG] pendingLocalization 
> LocalAssignment(topology_id:test-1-1528927024, 
> executors:[ExecutorInfo(task_start:10, task_end:10), 
> ExecutorInfo(task_start:16, task_end:16), ExecutorInfo(task_start:4, 
> task_end:4), ExecutorInfo(task_start:7, task_end:7), 
> ExecutorInfo(task_start:1, task_end:1), ExecutorInfo(task_start:13, 
> task_end:13)], resources:WorkerResources(mem_on_heap:768.0, mem_off_heap:0.0, 
> cpu:60.0, shared_mem_on_heap:0.0, shared_mem_off_heap:0.0, 
> resources:{offheap.memory.mb=0.0, onheap.memory.mb=768.0, 
> cpu.pcore.percent=60.0}, shared_resources:{}), owner:zhu02) == current null ? 
> false
> 2018-06-13 16:57:12.274 o.a.s.d.s.Slot SLOT_6700 [INFO] There are pending 
> changes, waiting for them to finish before launching container...
> 2018-06-13 16:57:12.275 o.a.s.d.s.Slot SLOT_6700 [DEBUG] Transition from 
> WAITING_FOR_BLOB_LOCALIZATION to WAITING_FOR_BLOB_UPDATE
> 2018-06-13 16:57:12.275 o.a.s.d.s.Slot SLOT_6700 [INFO] STATE 
> WAITING_FOR_BLOB_LOCALIZATION msInState: 2018 -> WAITING_FOR_BLOB_UPDATE 
> msInState: 1
> 2018-06-13 16:57:12.275 o.a.s.d.s.Slot SLOT_6700 [DEBUG] STATE 
> WAITING_FOR_BLOB_UPDATE
> 2018-06-13 16:57:12.275 o.a.s.d.s.Slot SLOT_6700 [DEBUG] pendingLocalization: 
> null, new: LocalAssignment(topology_id:test-1-1528927024, 
> executors:[ExecutorInfo(task_start:10, task_end:10), 
> ExecutorInfo(task_start:16, task_end:16), ExecutorInfo(task_start:4, 
> task_end:4), ExecutorInfo(task_start:7, task_end:7), 
> ExecutorInfo(task_start:1, task_end:1), ExecutorInfo(task_start:13, 
> task_end:13)], resources:WorkerResources(mem_on_heap:768.0, mem_off_heap:0.0, 
> cpu:60.0, shared_mem_on_heap:0.0, shared_mem_off_heap:0.0, 
> resources:{offheap.memory.mb=0.0, onheap.memory.mb=768.0, 
> cpu.pcore.percent=60.0}, shared_resources:{}), owner:zhu02), current: null, 
> pdchanging: LocalAssignment(topology_id:test-1-1528927024, 
> executors:[ExecutorInfo(task_start:10, task_end:10), 
> ExecutorInfo(task_start:16, task_end:16), ExecutorInfo(task_start:4, 
> task_end:4), ExecutorInfo(task_start:7, task_end:7), 
> ExecutorInfo(task_start:1, task_end:1), ExecutorInfo(task_start:13, 
> task_end:13)], resources:WorkerResources(mem_on_heap:768.0, mem_off_heap:0.0, 
> cpu:60.0, shared_mem_on_heap:0.0, shared_mem_off_heap:0.0, 
> resources:{offheap.memory.mb=0.0, onheap.memory.mb=768.0, 
> cpu.pcore.percent=60.0}, shared_resources:{}), owner:zhu02)
> 2018-06-13 16:57:12.276 o.a.s.d.s.Slot SLOT_6700 [INFO] SLOT 6700: Assignment 
> Changed from null to LocalAssignment(topology_id:test-1-1528927024, 
> executors:[ExecutorInfo(task_start:10, task_end:10), 
> ExecutorInfo(task_start:16, task_end:16), ExecutorInfo(task_start:4, 
> task_end:4), ExecutorInfo(task_start:7, task_end:7), 
> ExecutorInfo(task_start:1, task_end:1), ExecutorInfo(task_start:13, 
> task_end:13)], resources:WorkerResources(mem_on_heap:768.0, mem_off_heap:0.0, 
> cpu:60.0, shared_mem_on_heap:0.0, shared_mem_off_heap:0.0, 
> resources:{offheap.memory.mb=0.0, onheap.memory.mb=768.0, 
> cpu.pcore.percent=60.0}, shared_resources:{}), owner:zhu02)
> 2018-06-13 16:57:12.278 o.a.s.d.s.Slot SLOT_6700 [DEBUG] Transition from 
> WAITING_FOR_BLOB_UPDATE to WAITING_FOR_BLOB_LOCALIZATION
> 2018-06-13 16:57:12.278 o.a.s.d.s.Slot SLOT_6700 [INFO] STATE 
> WAITING_FOR_BLOB_UPDATE msInState: 4 -> WAITING_FOR_BLOB_LOCALIZATION 
> msInState: 0
> 2018-06-13 16:57:12.279 o.a.s.d.s.Slot SLOT_6700 [DEBUG] STATE 
> WAITING_FOR_BLOB_LOCALIZATION
> 2018-06-13 16:57:12.279 o.a.s.d.s.Slot SLOT_6700 [DEBUG] pendingChangingBlobs 
> are []
> 2018-06-13 16:57:12.279 o.a.s.d.s.Slot SLOT_6700 [DEBUG] pendingLocalization 
> LocalAssignment(topology_id:test-1-1528927024, 
> executors:[ExecutorInfo(task_start:10, task_end:10), 
> ExecutorInfo(task_start:16, task_end:16), ExecutorInfo(task_start:4, 
> task_end:4), ExecutorInfo(task_start:7, task_end:7), 
> ExecutorInfo(task_start:1, task_end:1), ExecutorInfo(task_start:13, 
> task_end:13)], resources:WorkerResources(mem_on_heap:768.0, mem_off_heap:0.0, 
> cpu:60.0, shared_mem_on_heap:0.0, shared_mem_off_heap:0.0, 
> resources:{offheap.memory.mb=0.0, onheap.memory.mb=768.0, 
> cpu.pcore.percent=60.0}, shared_resources:{}), owner:zhu02) == current null ? 
> false
> 2018-06-13 16:57:12.280 o.a.s.d.s.Slot SLOT_6700 [DEBUG] launch container for 
> the first time
> 2018-06-13 16:57:12.284 o.a.s.d.s.BasicContainer SLOT_6700 [INFO] Created 
> Worker ID 4155b2bb-ebd1-431d-907f-d8a4ff1e1da4
> {code}
> I would like to know if this is actually the desired behavior of the state 
> machine, or I can help fix the bug. The implementation would be to redesign 
> the if statement.



--
This message was sent by Atlassian JIRA
(v7.6.3#76005)

Reply via email to