[ 
https://issues.apache.org/jira/browse/MESOS-830?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=14681032#comment-14681032
 ] 

Greg Mann commented on MESOS-830:
---------------------------------

It seems that this is occurring because the JVM will happily continue execution 
after {{driver.stop()}} at the end of {{TestFramework.java}}, regardless of 
whether or not the MesosSchedulerDriver and associated objects have finished 
their teardown. This can mean that {{System.exit(status)}} is called while the 
driver still has logging to do, leading to an attempt to destroy a locked mutex 
or an attempt to lock a destroyed mutex.

Since Java doesn't like to provide explicit garbage collection facilities, it's 
not easy to ensure that the native routines have completed before calling 
{{System.exit(status)}} without resorting to a hack like calling the 
MesosSchedulerDriver's {{finalize()}} method explicitly. Incidentally, using 
that {{finalize()}} hack does fix this bug on my machine. Ideally, we would 
inspect the status of the driver and its associated tasks via the Java API and 
wait until their teardown is complete to exit.

> ExamplesTest.JavaFramework is flaky
> -----------------------------------
>
>                 Key: MESOS-830
>                 URL: https://issues.apache.org/jira/browse/MESOS-830
>             Project: Mesos
>          Issue Type: Bug
>          Components: test
>            Reporter: Vinod Kone
>            Assignee: Greg Mann
>              Labels: flaky, mesosphere
>
> Identify the cause of the following test failure:
> [ RUN      ] ExamplesTest.JavaFramework
> Using temporary directory '/tmp/ExamplesTest_JavaFramework_wSc7u8'
> Enabling authentication for the framework
> I1120 15:13:39.820032 1681264640 master.cpp:285] Master started on 
> 172.25.133.171:52576
> I1120 15:13:39.820180 1681264640 master.cpp:299] Master ID: 
> 201311201513-2877626796-52576-3234
> I1120 15:13:39.820194 1681264640 master.cpp:302] Master only allowing 
> authenticated frameworks to register!
> I1120 15:13:39.821197 1679654912 slave.cpp:112] Slave started on 
> 1)@172.25.133.171:52576
> I1120 15:13:39.821795 1679654912 slave.cpp:212] Slave resources: cpus(*):4; 
> mem(*):7168; disk(*):481998; ports(*):[31000-32000]
> I1120 15:13:39.822855 1682337792 slave.cpp:112] Slave started on 
> 2)@172.25.133.171:52576
> I1120 15:13:39.823652 1682337792 slave.cpp:212] Slave resources: cpus(*):4; 
> mem(*):7168; disk(*):481998; ports(*):[31000-32000]
> I1120 15:13:39.825330 1679118336 master.cpp:744] The newly elected leader is 
> [email protected]:52576
> I1120 15:13:39.825445 1679118336 master.cpp:748] Elected as the leading 
> master!
> I1120 15:13:39.825907 1681264640 state.cpp:33] Recovering state from 
> '/tmp/ExamplesTest_JavaFramework_wSc7u8/0/meta'
> I1120 15:13:39.826127 1681264640 status_update_manager.cpp:180] Recovering 
> status update manager
> I1120 15:13:39.826331 1681801216 process_isolator.cpp:317] Recovering isolator
> I1120 15:13:39.826738 1682874368 slave.cpp:2743] Finished recovery
> I1120 15:13:39.827747 1682337792 state.cpp:33] Recovering state from 
> '/tmp/ExamplesTest_JavaFramework_wSc7u8/1/meta'
> I1120 15:13:39.827945 1680191488 slave.cpp:112] Slave started on 
> 3)@172.25.133.171:52576
> I1120 15:13:39.828415 1682337792 status_update_manager.cpp:180] Recovering 
> status update manager
> I1120 15:13:39.828608 1680728064 sched.cpp:260] Authenticating with master 
> [email protected]:52576
> I1120 15:13:39.828606 1680191488 slave.cpp:212] Slave resources: cpus(*):4; 
> mem(*):7168; disk(*):481998; ports(*):[31000-32000]
> I1120 15:13:39.828680 1682874368 slave.cpp:497] New master detected at 
> [email protected]:52576
> I1120 15:13:39.828765 1682337792 process_isolator.cpp:317] Recovering isolator
> I1120 15:13:39.829828 1680728064 sched.cpp:229] Detecting new master
> I1120 15:13:39.830288 1679654912 authenticatee.hpp:100] Initializing client 
> SASL
> I1120 15:13:39.831635 1680191488 state.cpp:33] Recovering state from 
> '/tmp/ExamplesTest_JavaFramework_wSc7u8/2/meta'
> I1120 15:13:39.831991 1679118336 status_update_manager.cpp:158] New master 
> detected at [email protected]:52576
> I1120 15:13:39.832042 1682874368 slave.cpp:524] Detecting new master
> I1120 15:13:39.832314 1682337792 slave.cpp:2743] Finished recovery
> I1120 15:13:39.832309 1681264640 master.cpp:1266] Attempting to register 
> slave on vkone.local at slave(1)@172.25.133.171:52576
> I1120 15:13:39.832929 1680728064 status_update_manager.cpp:180] Recovering 
> status update manager
> I1120 15:13:39.833371 1681801216 slave.cpp:497] New master detected at 
> [email protected]:52576
> I1120 15:13:39.833273 1681264640 master.cpp:2513] Adding slave 
> 201311201513-2877626796-52576-3234-0 at vkone.local with cpus(*):4; 
> mem(*):7168; disk(*):481998; ports(*):[31000-32000]
> I1120 15:13:39.833595 1680728064 process_isolator.cpp:317] Recovering isolator
> I1120 15:13:39.833859 1681801216 slave.cpp:524] Detecting new master
> I1120 15:13:39.833861 1682874368 status_update_manager.cpp:158] New master 
> detected at [email protected]:52576
> I1120 15:13:39.834092 1680191488 slave.cpp:542] Registered with master 
> [email protected]:52576; given slave ID 
> 201311201513-2877626796-52576-3234-0
> I1120 15:13:39.834486 1681264640 master.cpp:1266] Attempting to register 
> slave on vkone.local at slave(2)@172.25.133.171:52576
> I1120 15:13:39.834549 1681264640 master.cpp:2513] Adding slave 
> 201311201513-2877626796-52576-3234-1 at vkone.local with cpus(*):4; 
> mem(*):7168; disk(*):481998; ports(*):[31000-32000]
> I1120 15:13:39.834750 1680191488 slave.cpp:555] Checkpointing SlaveInfo to 
> '/tmp/ExamplesTest_JavaFramework_wSc7u8/0/meta/slaves/201311201513-2877626796-52576-3234-0/slave.info'
> I1120 15:13:39.834875 1682874368 hierarchical_allocator_process.hpp:445] 
> Added slave 201311201513-2877626796-52576-3234-0 (vkone.local) with 
> cpus(*):4; mem(*):7168; disk(*):481998; ports(*):[31000-32000] (and 
> cpus(*):4; mem(*):7168; disk(*):481998; ports(*):[31000-32000] available)
> I1120 15:13:39.835155 1680728064 slave.cpp:542] Registered with master 
> [email protected]:52576; given slave ID 
> 201311201513-2877626796-52576-3234-1
> I1120 15:13:39.835458 1679118336 slave.cpp:2743] Finished recovery
> I1120 15:13:39.835739 1680728064 slave.cpp:555] Checkpointing SlaveInfo to 
> '/tmp/ExamplesTest_JavaFramework_wSc7u8/1/meta/slaves/201311201513-2877626796-52576-3234-1/slave.info'
> I1120 15:13:39.835922 1682874368 hierarchical_allocator_process.hpp:445] 
> Added slave 201311201513-2877626796-52576-3234-1 (vkone.local) with 
> cpus(*):4; mem(*):7168; disk(*):481998; ports(*):[31000-32000] (and 
> cpus(*):4; mem(*):7168; disk(*):481998; ports(*):[31000-32000] available)
> I1120 15:13:39.836120 1681264640 slave.cpp:497] New master detected at 
> [email protected]:52576
> I1120 15:13:39.836340 1679118336 status_update_manager.cpp:158] New master 
> detected at [email protected]:52576
> I1120 15:13:39.836436 1681264640 slave.cpp:524] Detecting new master
> I1120 15:13:39.836629 1682874368 master.cpp:1266] Attempting to register 
> slave on vkone.local at slave(3)@172.25.133.171:52576
> I1120 15:13:39.836653 1682874368 master.cpp:2513] Adding slave 
> 201311201513-2877626796-52576-3234-2 at vkone.local with cpus(*):4; 
> mem(*):7168; disk(*):481998; ports(*):[31000-32000]
> I1120 15:13:39.836804 1680728064 slave.cpp:542] Registered with master 
> [email protected]:52576; given slave ID 
> 201311201513-2877626796-52576-3234-2
> I1120 15:13:39.837190 1680728064 slave.cpp:555] Checkpointing SlaveInfo to 
> '/tmp/ExamplesTest_JavaFramework_wSc7u8/2/meta/slaves/201311201513-2877626796-52576-3234-2/slave.info'
> I1120 15:13:39.837569 1682874368 hierarchical_allocator_process.hpp:445] 
> Added slave 201311201513-2877626796-52576-3234-2 (vkone.local) with 
> cpus(*):4; mem(*):7168; disk(*):481998; ports(*):[31000-32000] (and 
> cpus(*):4; mem(*):7168; disk(*):481998; ports(*):[31000-32000] available)
> I1120 15:13:39.852011 1679654912 authenticatee.hpp:124] Creating new client 
> SASL connection
> I1120 15:13:39.852219 1680191488 master.cpp:1734] Authenticating framework at 
> scheduler(1)@172.25.133.171:52576
> I1120 15:13:39.852577 1682337792 authenticator.hpp:83] Initializing server 
> SASL
> I1120 15:13:39.856160 1682337792 authenticator.hpp:140] Creating new server 
> SASL connection
> I1120 15:13:39.856334 1681264640 authenticatee.hpp:212] Received SASL 
> authentication mechanisms: CRAM-MD5
> I1120 15:13:39.856360 1681264640 authenticatee.hpp:238] Attempting to 
> authenticate with mechanism 'CRAM-MD5'
> I1120 15:13:39.856421 1681264640 authenticator.hpp:243] Received SASL 
> authentication start
> I1120 15:13:39.856487 1681264640 authenticator.hpp:325] Authentication 
> requires more steps
> I1120 15:13:39.856531 1681264640 authenticatee.hpp:258] Received SASL 
> authentication step
> I1120 15:13:39.856576 1681264640 authenticator.hpp:271] Received SASL 
> authentication step
> I1120 15:13:39.856643 1681264640 authenticator.hpp:317] Authentication success
> I1120 15:13:39.856724 1681264640 authenticatee.hpp:298] Authentication success
> I1120 15:13:39.856768 1681264640 master.cpp:1774] Successfully authenticated 
> framework at scheduler(1)@172.25.133.171:52576
> I1120 15:13:39.857028 1681264640 sched.cpp:334] Successfully authenticated 
> with master [email protected]:52576
> I1120 15:13:39.857139 1681264640 master.cpp:798] Received registration 
> request from scheduler(1)@172.25.133.171:52576
> I1120 15:13:39.857306 1681264640 master.cpp:816] Registering framework 
> 201311201513-2877626796-52576-3234-0000 at scheduler(1)@172.25.133.171:52576
> I1120 15:13:39.862296 1680191488 hierarchical_allocator_process.hpp:332] 
> Added framework 201311201513-2877626796-52576-3234-0000
> I1120 15:13:39.863867 1680191488 master.cpp:1700] Sending 3 offers to 
> framework 201311201513-2877626796-52576-3234-0000
> Registered! ID = 201311201513-2877626796-52576-3234-0000
> Launching task 0
> Launching task 1
> Launching task 2
> I1120 15:13:39.905390 1680191488 master.cpp:2026] Processing reply for offer 
> 201311201513-2877626796-52576-3234-0 on slave 
> 201311201513-2877626796-52576-3234-1 (vkone.local) for framework 
> 201311201513-2877626796-52576-3234-0000
> I1120 15:13:39.905825 1680191488 master.hpp:400] Adding task 0 with resources 
> cpus(*):1; mem(*):128 on slave 201311201513-2877626796-52576-3234-1 
> (vkone.local)
> I1120 15:13:39.905886 1680191488 master.cpp:2150] Launching task 0 of 
> framework 201311201513-2877626796-52576-3234-0000 with resources cpus(*):1; 
> mem(*):128 on slave 201311201513-2877626796-52576-3234-1 (vkone.local)
> I1120 15:13:39.906422 1680191488 master.cpp:2026] Processing reply for offer 
> 201311201513-2877626796-52576-3234-1 on slave 
> 201311201513-2877626796-52576-3234-2 (vkone.local) for framework 
> 201311201513-2877626796-52576-3234-0000
> I1120 15:13:39.906664 1680191488 master.hpp:400] Adding task 1 with resources 
> cpus(*):1; mem(*):128 on slave 201311201513-2877626796-52576-3234-2 
> (vkone.local)
> I1120 15:13:39.906721 1680191488 master.cpp:2150] Launching task 1 of 
> framework 201311201513-2877626796-52576-3234-0000 with resources cpus(*):1; 
> mem(*):128 on slave 201311201513-2877626796-52576-3234-2 (vkone.local)
> I1120 15:13:39.907171 1680191488 master.cpp:2026] Processing reply for offer 
> 201311201513-2877626796-52576-3234-2 on slave 
> 201311201513-2877626796-52576-3234-0 (vkone.local) for framework 
> 201311201513-2877626796-52576-3234-0000
> I1120 15:13:39.907419 1680191488 master.hpp:400] Adding task 2 with resources 
> cpus(*):1; mem(*):128 on slave 201311201513-2877626796-52576-3234-0 
> (vkone.local)
> I1120 15:13:39.907480 1680191488 master.cpp:2150] Launching task 2 of 
> framework 201311201513-2877626796-52576-3234-0000 with resources cpus(*):1; 
> mem(*):128 on slave 201311201513-2877626796-52576-3234-0 (vkone.local)
> I1120 15:13:39.907938 1680191488 slave.cpp:722] Got assigned task 0 for 
> framework 201311201513-2877626796-52576-3234-0000
> I1120 15:13:39.908473 1680191488 slave.cpp:833] Launching task 0 for 
> framework 201311201513-2877626796-52576-3234-0000
> I1120 15:13:39.914427 1682874368 slave.cpp:722] Got assigned task 1 for 
> framework 201311201513-2877626796-52576-3234-0000
> I1120 15:13:39.914594 1680728064 slave.cpp:722] Got assigned task 2 for 
> framework 201311201513-2877626796-52576-3234-0000
> I1120 15:13:39.914844 1681801216 hierarchical_allocator_process.hpp:590] 
> Framework 201311201513-2877626796-52576-3234-0000 filtered slave 
> 201311201513-2877626796-52576-3234-1 for 1secs
> I1120 15:13:39.915292 1682874368 slave.cpp:833] Launching task 1 for 
> framework 201311201513-2877626796-52576-3234-0000
> I1120 15:13:39.915424 1681801216 hierarchical_allocator_process.hpp:590] 
> Framework 201311201513-2877626796-52576-3234-0000 filtered slave 
> 201311201513-2877626796-52576-3234-2 for 1secs
> I1120 15:13:39.915685 1681801216 hierarchical_allocator_process.hpp:590] 
> Framework 201311201513-2877626796-52576-3234-0000 filtered slave 
> 201311201513-2877626796-52576-3234-0 for 1secs
> I1120 15:13:39.915828 1680728064 slave.cpp:833] Launching task 2 for 
> framework 201311201513-2877626796-52576-3234-0000
> I1120 15:13:39.917840 1680191488 slave.cpp:943] Queuing task '0' for executor 
> default of framework '201311201513-2877626796-52576-3234-0000
> I1120 15:13:39.917935 1679118336 process_isolator.cpp:100] Launching default 
> (/Users/vinod/workspace/apache/mesos/build/src/examples/java/test-executor) 
> in 
> /tmp/ExamplesTest_JavaFramework_wSc7u8/1/slaves/201311201513-2877626796-52576-3234-1/frameworks/201311201513-2877626796-52576-3234-0000/executors/default/runs/375b31a9-7093-4db1-964d-e6b425b1e4b4
>  with resources ' for framework 201311201513-2877626796-52576-3234-0000
> I1120 15:13:39.922019 1679118336 process_isolator.cpp:163] Forked executor at 
> 3268
> I1120 15:13:39.922703 1679118336 slave.cpp:2073] Monitoring executor default 
> of framework 201311201513-2877626796-52576-3234-0000 forked at pid 3268
> I1120 15:13:39.929134 1682874368 slave.cpp:943] Queuing task '1' for executor 
> default of framework '201311201513-2877626796-52576-3234-0000
> I1120 15:13:39.929323 1682874368 process_isolator.cpp:100] Launching default 
> (/Users/vinod/workspace/apache/mesos/build/src/examples/java/test-executor) 
> in 
> /tmp/ExamplesTest_JavaFramework_wSc7u8/2/slaves/201311201513-2877626796-52576-3234-2/frameworks/201311201513-2877626796-52576-3234-0000/executors/default/runs/2bd0e75d-a2b9-4ae6-be08-9782612309a5
>  with resources ' for framework 201311201513-2877626796-52576-3234-0000
> I1120 15:13:39.931243 1682874368 process_isolator.cpp:163] Forked executor at 
> 3269
> I1120 15:13:39.931612 1681801216 slave.cpp:2073] Monitoring executor default 
> of framework 201311201513-2877626796-52576-3234-0000 forked at pid 3269
> E1120 15:13:39.931836 1681801216 slave.cpp:2099] Failed to watch executor 
> default of framework 201311201513-2877626796-52576-3234-0000: Already watched
> I1120 15:13:39.936460 1680728064 slave.cpp:943] Queuing task '2' for executor 
> default of framework '201311201513-2877626796-52576-3234-0000
> I1120 15:13:39.936619 1681801216 process_isolator.cpp:100] Launching default 
> (/Users/vinod/workspace/apache/mesos/build/src/examples/java/test-executor) 
> in 
> /tmp/ExamplesTest_JavaFramework_wSc7u8/0/slaves/201311201513-2877626796-52576-3234-0/frameworks/201311201513-2877626796-52576-3234-0000/executors/default/runs/16d600da-da86-4614-91cb-58a7b27ab534
>  with resources ' for framework 201311201513-2877626796-52576-3234-0000
> I1120 15:13:39.941299 1681801216 process_isolator.cpp:163] Forked executor at 
> 3270
> I1120 15:13:39.942179 1681801216 slave.cpp:2073] Monitoring executor default 
> of framework 201311201513-2877626796-52576-3234-0000 forked at pid 3270
> E1120 15:13:39.942395 1681801216 slave.cpp:2099] Failed to watch executor 
> default of framework 201311201513-2877626796-52576-3234-0000: Already watched
> Fetching resources into 
> '/tmp/ExamplesTest_JavaFramework_wSc7u8/2/slaves/201311201513-2877626796-52576-3234-2/frameworks/201311201513-2877626796-52576-3234-0000/executors/default/runs/2bd0e75d-a2b9-4ae6-be08-9782612309a5'
> Fetching resources into 
> '/tmp/ExamplesTest_JavaFramework_wSc7u8/1/slaves/201311201513-2877626796-52576-3234-1/frameworks/201311201513-2877626796-52576-3234-0000/executors/default/runs/375b31a9-7093-4db1-964d-e6b425b1e4b4'
> Fetching resources into 
> '/tmp/ExamplesTest_JavaFramework_wSc7u8/0/slaves/201311201513-2877626796-52576-3234-0/frameworks/201311201513-2877626796-52576-3234-0000/executors/default/runs/16d600da-da86-4614-91cb-58a7b27ab534'
> I1120 15:13:40.372573 1681801216 slave.cpp:1406] Got registration for 
> executor 'default' of framework 201311201513-2877626796-52576-3234-0000
> I1120 15:13:40.373258 1681801216 slave.cpp:1527] Flushing queued task 1 for 
> executor 'default' of framework 201311201513-2877626796-52576-3234-0000
> I1120 15:13:40.388317 1681801216 slave.cpp:1406] Got registration for 
> executor 'default' of framework 201311201513-2877626796-52576-3234-0000
> I1120 15:13:40.388983 1681801216 slave.cpp:1527] Flushing queued task 0 for 
> executor 'default' of framework 201311201513-2877626796-52576-3234-0000
> I1120 15:13:40.398084 1679654912 slave.cpp:1406] Got registration for 
> executor 'default' of framework 201311201513-2877626796-52576-3234-0000
> I1120 15:13:40.399344 1679654912 slave.cpp:1527] Flushing queued task 2 for 
> executor 'default' of framework 201311201513-2877626796-52576-3234-0000
> Registered executor on vkone.local
> I1120 15:13:40.491843 1679654912 slave.cpp:1740] Handling status update 
> TASK_RUNNING (UUID: f04b1852-3669-444a-906f-3675f784c14f) for task 1 of 
> framework 201311201513-2877626796-52576-3234-0000 from 
> executor(1)@172.25.133.171:52577
> I1120 15:13:40.492202 1679654912 status_update_manager.cpp:305] Received 
> status update TASK_RUNNING (UUID: f04b1852-3669-444a-906f-3675f784c14f) for 
> task 1 of framework 201311201513-2877626796-52576-3234-0000
> I1120 15:13:40.492424 1679654912 status_update_manager.cpp:356] Forwarding 
> status update TASK_RUNNING (UUID: f04b1852-3669-444a-906f-3675f784c14f) for 
> task 1 of framework 201311201513-2877626796-52576-3234-0000 to 
> [email protected]:52576
> Registered executor on vkone.local
> I1120 15:13:40.492671 1682337792 master.cpp:1452] Status update TASK_RUNNING 
> (UUID: f04b1852-3669-444a-906f-3675f784c14f) for task 1 of framework 
> 201311201513-2877626796-52576-3234-0000 from slave(3)@172.25.133.171:52576
> I1120 15:13:40.492735 1682337792 slave.cpp:1865] Sending acknowledgement for 
> status update TASK_RUNNING (UUID: f04b1852-3669-444a-906f-3675f784c14f) for 
> task 1 of framework 201311201513-2877626796-52576-3234-0000 to 
> executor(1)@172.25.133.171:52577
> Status update: task 1 is in state TASK_RUNNING
> I1120 15:13:40.502235 1679654912 status_update_manager.cpp:380] Received 
> status update acknowledgement (UUID: f04b1852-3669-444a-906f-3675f784c14f) 
> for task 1 of framework 201311201513-2877626796-52576-3234-0000
> Registered executor on vkone.local
> I1120 15:13:40.531292 1679654912 slave.cpp:1740] Handling status update 
> TASK_RUNNING (UUID: c19b6a5a-19ce-4613-8a5a-08fe807ff27c) for task 2 of 
> framework 201311201513-2877626796-52576-3234-0000 from 
> executor(1)@172.25.133.171:52579
> I1120 15:13:40.532091 1680728064 status_update_manager.cpp:305] Received 
> status update TASK_RUNNING (UUID: c19b6a5a-19ce-4613-8a5a-08fe807ff27c) for 
> task 2 of framework 201311201513-2877626796-52576-3234-0000
> I1120 15:13:40.532305 1680728064 status_update_manager.cpp:356] Forwarding 
> status update TASK_RUNNING (UUID: c19b6a5a-19ce-4613-8a5a-08fe807ff27c) for 
> task 2 of framework 201311201513-2877626796-52576-3234-0000 to 
> [email protected]:52576
> I1120 15:13:40.532776 1682874368 slave.cpp:1865] Sending acknowledgement for 
> status update TASK_RUNNING (UUID: c19b6a5a-19ce-4613-8a5a-08fe807ff27c) for 
> task 2 of framework 201311201513-2877626796-52576-3234-0000 to 
> executor(1)@172.25.133.171:52579
> I1120 15:13:40.532951 1681801216 master.cpp:1452] Status update TASK_RUNNING 
> (UUID: c19b6a5a-19ce-4613-8a5a-08fe807ff27c) for task 2 of framework 
> 201311201513-2877626796-52576-3234-0000 from slave(1)@172.25.133.171:52576
> Status update: task 2 is in state TASK_RUNNING
> I1120 15:13:40.538895 1682874368 status_update_manager.cpp:380] Received 
> status update acknowledgement (UUID: c19b6a5a-19ce-4613-8a5a-08fe807ff27c) 
> for task 2 of framework 201311201513-2877626796-52576-3234-0000
> I1120 15:13:40.541267 1682874368 slave.cpp:1740] Handling status update 
> TASK_RUNNING (UUID: c218b0c3-d77c-4901-8570-391c330ba117) for task 0 of 
> framework 201311201513-2877626796-52576-3234-0000 from 
> executor(1)@172.25.133.171:52578
> I1120 15:13:40.541555 1682874368 status_update_manager.cpp:305] Received 
> status update TASK_RUNNING (UUID: c218b0c3-d77c-4901-8570-391c330ba117) for 
> task 0 of framework 201311201513-2877626796-52576-3234-0000
> I1120 15:13:40.541725 1682874368 status_update_manager.cpp:356] Forwarding 
> status update TASK_RUNNING (UUID: c218b0c3-d77c-4901-8570-391c330ba117) for 
> task 0 of framework 201311201513-2877626796-52576-3234-0000 to 
> [email protected]:52576
> I1120 15:13:40.542196 1682874368 master.cpp:1452] Status update TASK_RUNNING 
> (UUID: c218b0c3-d77c-4901-8570-391c330ba117) for task 0 of framework 
> 201311201513-2877626796-52576-3234-0000 from slave(2)@172.25.133.171:52576
> I1120 15:13:40.542251 1682874368 slave.cpp:1865] Sending acknowledgement for 
> status update TASK_RUNNING (UUID: c218b0c3-d77c-4901-8570-391c330ba117) for 
> task 0 of framework 201311201513-2877626796-52576-3234-0000 to 
> executor(1)@172.25.133.171:52578
> Status update: task 0 is in state TASK_RUNNING
> I1120 15:13:40.545537 1682874368 status_update_manager.cpp:380] Received 
> status update acknowledgement (UUID: c218b0c3-d77c-4901-8570-391c330ba117) 
> for task 0 of framework 201311201513-2877626796-52576-3234-0000
> Running task value: "1"
> I1120 15:13:40.764219 1682337792 slave.cpp:1740] Handling status update 
> TASK_FINISHED (UUID: 4a163594-146a-46f7-bd43-f906e76ad84c) for task 1 of 
> framework 201311201513-2877626796-52576-3234-0000 from 
> executor(1)@172.25.133.171:52577
> I1120 15:13:40.764629 1682337792 status_update_manager.cpp:305] Received 
> status update TASK_FINISHED (UUID: 4a163594-146a-46f7-bd43-f906e76ad84c) for 
> task 1 of framework 201311201513-2877626796-52576-3234-0000
> I1120 15:13:40.764698 1682337792 status_update_manager.cpp:356] Forwarding 
> status update TASK_FINISHED (UUID: 4a163594-146a-46f7-bd43-f906e76ad84c) for 
> task 1 of framework 201311201513-2877626796-52576-3234-0000 to 
> [email protected]:52576
> I1120 15:13:40.765043 1682337792 master.cpp:1452] Status update TASK_FINISHED 
> (UUID: 4a163594-146a-46f7-bd43-f906e76ad84c) for task 1 of framework 
> 201311201513-2877626796-52576-3234-0000 from slave(3)@172.25.133.171:52576
> I1120 15:13:40.765192 1682337792 master.hpp:418] Removing task 1 with 
> resources cpus(*):1; mem(*):128 on slave 2Status update: task 1 is in state 
> TASK_FINISHED
> Finished tasks: 1
> 01311201513-2877626796-52576-3234-2 (vkone.local)
> I1120 15:13:40.765363 1679118336 slave.cpp:1865] Sending acknowledgement for 
> status update TASK_FINISHED (UUID: 4a163594-146a-46f7-bd43-f906e76ad84c) for 
> task 1 of framework 201311201513-2877626796-52576-3234-0000 to 
> executor(1)@172.25.133.171:52577
> I1120 15:13:40.772738 1682337792 hierarchical_allocator_process.hpp:637] 
> Recovered cpus(*):1; mem(*):128 (total allocatable: cpus(*):4; mem(*):7168; 
> disk(*):481998; ports(*):[31000-32000]) on slave 
> 201311201513-2877626796-52576-3234-2 from framework 
> 201311201513-2877626796-52576-3234-0000
> I1120 15:13:40.773190 1679118336 status_update_manager.cpp:380] Received 
> status update acknowledgement (UUID: 4a163594-146a-46f7-bd43-f906e76ad84c) 
> for task 1 of framework 201311201513-2877626796-52576-3234-0000
> Running task value: "0"
> Running task value: "2"
> I1120 15:13:40.790068 1679118336 slave.cpp:1740] Handling status update 
> TASK_FINISHED (UUID: 13265a94-50f1-4bc4-b2e2-9f60a1bb4086) for task 0 of 
> framework 201311201513-2877626796-52576-3234-0000 from 
> executor(1)@172.25.133.171:52578
> I1120 15:13:40.790411 1680728064 status_update_manager.cpp:305] Received 
> status update TASK_FINISHED (UUID: 13265a94-50f1-4bc4-b2e2-9f60a1bb4086) for 
> task 0 of framework 201311201513-2877626796-52576-3234-0000
> I1120 15:13:40.790493 1680728064 status_update_manager.cpp:356] Forwarding 
> status update TASK_FINISHED (UUID: 13265a94-50f1-4bc4-b2e2-9f60a1bb4086) for 
> task 0 of framework 201311201513-2877626796-52576-3234-0000 to 
> [email protected]:52576
> I1120 15:13:40.790674 1679118336 master.cpp:1452] Status update TASK_FINISHED 
> (UUID: 13265a94-50f1-4bc4-b2e2-9f60a1bb4086) for task 0 of framework 
> 201311201513-2877626796-52576-3234-0000 from slave(2)@172.25.133.171:52576
> I1120 15:13:40.790798 1679118336 master.hpp:418] Removing task 0 with 
> resources cpus(*):1; mem(*):128 on slave 201311201513-2877626796-52576-3234-1 
> (vkone.local)
> I1120 15:13:40.790928 1679118336 slave.cpp:1865] Sending acknowledgement for 
> status update TASK_FINISHED (UUID: 13265a94-50f1-4bc4-b2e2-9f60a1bb4086) for 
> task 0 of framework 201311201513-2877626796-52576-3234-0000 to 
> executor(1)@172.25.133.171:52578
> Status update: task 0 is in state TASK_FINISHED
> Finished tasks: 2
> I1120 15:13:40.791225 1680191488 hierarchical_allocator_process.hpp:637] 
> Recovered cpus(*):1; mem(*):128 (total allocatable: cpus(*):4; mem(*):7168; 
> disk(*):481998; ports(*):[31000-32000]) on slave 
> 201311201513-2877626796-52576-3234-1 from framework 
> 201311201513-2877626796-52576-3234-0000
> I1120 15:13:40.794234 1679118336 status_update_manager.cpp:380] Received 
> status update acknowledgement (UUID: 13265a94-50f1-4bc4-b2e2-9f60a1bb4086) 
> for task 0 of framework 201311201513-2877626796-52576-3234-0000
> I1120 15:13:40.795830 1681801216 slave.cpp:1740] Handling status update 
> TASK_FINISHED (UUID: f6f28e88-5ea6-4519-ba92-65ead6236fff) for task 2 of 
> framework 201311201513-2877626796-52576-3234-0000 from 
> executor(1)@172.25.133.171:52579
> I1120 15:13:40.796111 1679118336 status_update_manager.cpp:305] Received 
> status update TASK_FINISHED (UUID: f6f28e88-5ea6-4519-ba92-65ead6236fff) for 
> task 2 of framework 201311201513-2877626796-52576-3234-0000
> I1120 15:13:40.796182 1679118336 status_update_manager.cpp:356] Forwarding 
> status update TASK_FINISHED (UUID: f6f28e88-5ea6-4519-ba92-65ead6236fff) for 
> task 2 of framework 201311201513-2877626796-52576-3234-0000 to 
> [email protected]:52576
> I1120 15:13:40.796352 1680728064 master.cpp:1452] Status update TASK_FINISHED 
> (UUID: f6f28e88-5ea6-4519-ba92-65ead6236fff) for task 2 of framework 
> 201311201513-2877626796-52576-3234-0000 from slave(1)@172.25.133.171:52576
> I1120 15:13:40.796398 1679118336 slave.cpp:1865] Sending acknowledgement for 
> status update TASK_FINISHED (UUID: f6f28e88-5ea6-4519-ba92-65ead6236fff) for 
> task 2 of framework 201311201513-2877626796-52576-3234-0000 to 
> executor(1)@172.25.133.171:52579
> I1120 15:13:40.796466 1680728064 master.hpp:418] Removing task 2 with 
> resources cpus(*):1; mem(*):128 on slave 201311201513-2877626796-52576-3234-0 
> (vkone.local)
> I1120 15:13:40.796707 1679118336 hierarchical_allocator_process.hpp:637] 
> Recovered cpus(*):1; mem(*):128 (total allocatable: cpus(*):4; mem(*):7168; 
> disk(*):481998; ports(*):[31000-32000]) on slave 
> 201311201513-2877626796-52576-3234-0 from framework 
> 201311201513-2877626796-52576-3234-0000
> Status update: task 2 is in state TASK_FINISHED
> Finished tasks: 3
> I1120 15:13:40.797384 1680728064 status_update_manager.cpp:380] Received 
> status update acknowledgement (UUID: f6f28e88-5ea6-4519-ba92-65ead6236fff) 
> for task 2 of framework 201311201513-2877626796-52576-3234-0000
> I1120 15:13:40.824383 1681801216 master.cpp:1700] Sending 3 offers to 
> framework 201311201513-2877626796-52576-3234-0000
> Launching task 3
> Launching task 4
> I1120 15:13:40.826971 1679118336 master.cpp:2026] Processing reply for offer 
> 201311201513-2877626796-52576-3234-3 on slave 
> 201311201513-2877626796-52576-3234-1 (vkone.local) for framework 
> 201311201513-2877626796-52576-3234-0000
> I1120 15:13:40.827268 1679118336 master.hpp:400] Adding task 3 with resources 
> cpus(*):1; mem(*):128 on slave 201311201513-2877626796-52576-3234-1 
> (vkone.local)
> I1120 15:13:40.827348 1679118336 master.cpp:2150] Launching task 3 of 
> framework 201311201513-2877626796-52576-3234-0000 with resources cpus(*):1; 
> mem(*):128 on slave 201311201513-2877626796-52576-3234-1 (vkone.local)
> I1120 15:13:40.827487 1680728064 slave.cpp:722] Got assigned task 3 for 
> framework 201311201513-2877626796-52576-3234-0000
> I1120 15:13:40.827857 1680728064 slave.cpp:833] Launching task 3 for 
> framework 201311201513-2877626796-52576-3234-0000
> I1120 15:13:40.827913 1679118336 master.cpp:2026] Processing reply for offer 
> 201311201513-2877626796-52576-3234-4 on slave 
> 201311201513-2877626796-52576-3234-2 (vkone.local) for framework 
> 201311201513-2877626796-52576-3234-0000
> I1120 15:13:40.827986 1680728064 slave.cpp:968] Sending task '3' to executor 
> 'default' of framework 201311201513-2877626796-52576-3234-0000
> I1120 15:13:40.828126 1679118336 master.hpp:400] Adding task 4 with resources 
> cpus(*):1; mem(*):128 on slave 201311201513-2877626796-52576-3234-2 
> (vkone.local)
> I1120 15:13:40.828187 1679118336 master.cpp:2150] Launching task 4 of 
> framework 201311201513-2877626796-52576-3234-0000 with resources cpus(*):1; 
> mem(*):128 on slave 201311201513-2877626796-52576-3234-2 (vkone.local)
> I1120 15:13:40.828632 1679118336 master.cpp:2026] Processing reply for offer 
> 201311201513-2877626796-52576-3234-5 on slave 
> 201311201513-2877626796-52576-3234-0 (vkone.local) for framework 
> 201311201513-2877626796-52576-3234-0000
> I1120 15:13:40.828655 1680728064 hierarchical_allocator_process.hpp:590] 
> Framework 201311201513-2877626796-52576-3234-0000 filtered slave 
> 201311201513-2877626796-52576-3234-1 for 1secs
> I1120 15:13:40.829005 1679118336 slave.cpp:722] Got assigned task 4 for 
> framework 201311201513-2877626796-52576-3234-0000
> I1120 15:13:40.829027 1680728064 hierarchical_allocator_process.hpp:590] 
> Framework 201311201513-2877626796-52576-3234-0000 filtered slave 
> 201311201513-2877626796-52576-3234-2 for 1secs
> I1120 15:13:40.829260 1679118336 slave.cpp:833] Launching task 4 for 
> framework 201311201513-2877626796-52576-3234-0000
> I1120 15:13:40.829273 1680728064 hierarchical_allocator_process.hpp:590] 
> Framework 201311201513-2877626796-52576-3234-0000 filtered slave 
> 201311201513-2877626796-52576-3234-0 for 1secs
> I1120 15:13:40.829390 1679118336 slave.cpp:968] Sending task '4' to executor 
> 'default' of framework 201311201513-2877626796-52576-3234-0000
> Running task value: "3"
> Running task value: "4"
> I1120 15:13:40.839279 1682337792 slave.cpp:1740] Handling status update 
> TASK_RUNNING (UUID: a8d02ae6-3138-441c-a004-465d879b1277) for task 3 of 
> framework 201311201513-2877626796-52576-3234-0000 from 
> executor(1)@172.25.133.171:52578
> I1120 15:13:40.839534 1679118336 status_update_manager.cpp:305] Received 
> status update TASK_RUNNING (UUID: a8d02ae6-3138-441c-a004-465d879b1277) for 
> task 3 of framework 201311201513-2877626796-52576-3234-0000
> I1120 15:13:40.839705 1679118336 status_update_manager.cpp:356] Forwarding 
> status update TASK_RUNNING (UUID: a8d02ae6-3138-441c-a004-465d879b1277) for 
> task 3 of framework 201311201513-2877626796-52576-3234-0000 to 
> [email protected]:52576
> I1120 15:13:40.839944 1682337792 master.cpp:1452] Status update TASK_RUNNING 
> (UUID: a8d02ae6-3138-441c-a004-465d879b1277) for task 3 of framework 
> 201311201513-2877626796-52576-3234-0000 from slave(2)@172.25.133.171:52576
> Status update: task 3 is in state TASK_RUNNING
> I1120 15:13:40.839947 1679118336 slave.cpp:1865] Sending acknowledgement for 
> status update TASK_RUNNING (UUID: a8d02ae6-3138-441c-a004-465d879b1277) for 
> task 3 of framework 201311201513-2877626796-52576-3234-0000 to 
> executor(1)@172.25.133.171:52578
> I1120 15:13:40.856334 1679118336 slave.cpp:1740] Handling status update 
> TASK_FINISHED (UUID: 3fc45cb8-fd7f-4bed-a21d-76f234af6b36) for task 3 of 
> framework 201311201513-2877626796-52576-3234-0000 from 
> executor(1)@172.25.133.171:52578
> I1120 15:13:40.856650 1679118336 status_update_manager.cpp:380] Received 
> status update acknowledgement (UUID: a8d02ae6-3138-441c-a004-465d879b1277) 
> for task 3 of framework 201311201513-2877626796-52576-3234-0000
> I1120 15:13:40.856818 1679118336 status_update_manager.cpp:305] Received 
> status update TASK_FINISHED (UUID: 3fc45cb8-fd7f-4bed-a21d-76f234af6b36) for 
> task 3 of framework 201311201513-2877626796-52576-3234-0000
> I1120 15:13:40.856875 1679118336 status_update_manager.cpp:356] Forwarding 
> status update TASK_FINISHED (UUID: 3fc45cb8-fd7f-4bed-a21d-76f234af6b36) for 
> task 3 of framework 201311201513-2877626796-52576-3234-0000 to 
> [email protected]:52576
> I1120 15:13:40.857105 1679118336 slave.cpp:1740] Handling status update 
> TASK_RUNNING (UUID: 4f97c8df-1cc0-4eeb-8469-9d72df09ec73) for task 4 of 
> framework 201311201513-2877626796-52576-3234-0000 from 
> executor(1)@172.25.133.171:52577
> I1120 15:13:40.857369 1679118336 slave.cpp:1865] Sending acknowledgement for 
> status update TASK_FINISHED (UUID: 3fc45cb8-fd7f-4bed-a21d-76f234af6b36) for 
> task 3 of framework 201311201513-2877626796-52576-3234-0000 to 
> executor(1)@172.25.133.171:52578
> I1120 15:13:40.857498 1680728064 status_update_manager.cpp:305] Received 
> status update TASK_RUNNING (UUID: 4f97c8df-1cc0-4eeb-8469-9d72df09ec73) for 
> task 4 of framework 201311201513-2877626796-52576-3234-0000
> I1120 15:13:40.857518 1682337792 master.cpp:1452] Status update TASK_FINISHED 
> (UUID: 3fc45cb8-fd7f-4bed-a21d-76f234af6b36) for task 3 of framework 
> 201311201513-2877626796-52576-3234-0000 from slave(2)@172.25.133.171:52576
> I1120 15:13:40.857635 1680728064 status_update_manager.cpp:356] Forwarding 
> status update TASK_RUNNING (UUID: 4f97c8df-1cc0-4eeb-8469-9d72df09ec73) for 
> task 4 of framework 201311201513-2877626796-52576-3234-0000 to 
> [email protected]:52576
> I1120 15:13:40.857630 1682337792 master.hpp:418] Removing task 3 with 
> resources cpus(*):1; mem(*):128 on slave 201311201513-2877626796-52576-3234-1 
> (vkone.local)
> I1120 15:13:40.857843 1682337792 master.cpp:1452] Status update TASK_RUNNING 
> (UUID: 4f97c8df-1cc0-4eeb-8469-9d72df09ec73) for task 4 of framework 
> 201311201513-2877626796-52576-3234-0000 from slave(3)@172.25.133.171:52576
> I1120 15:13:40.858043 1680728064 hierarchical_allocator_process.hpp:637] 
> Recovered cpus(*):1; mem(*):128 (total allocatable: cpus(*):4; mem(*):7168; 
> disk(*):481998; ports(*):[31000-32000]) on slave 
> 201311201513-2877626796-52576-3234-1 from framework 
> 201311201513-2877626796-52576-3234-0000
> I1120 15:13:40.858098 1680728064 slave.cpp:1865] Sending acknowledgement for 
> status update TASK_RUNNING (UUID: 4f97c8df-1cc0-4eeb-8469-9d72df09ec73) for 
> task 4 of framework 201311201513-2877626796-52576-3234-0000 to 
> executor(1)@172.25.133.171:52577
> Status update: task 3 is in state TASK_FINISHED
> Finished tasks: 4
> Status update: task 4 is in state TASK_RUNNING
> I1120 15:13:40.858896 1682337792 status_update_manager.cpp:380] Received 
> status update acknowledgement (UUID: 3fc45cb8-fd7f-4bed-a21d-76f234af6b36) 
> for task 3 of framework 201311201513-2877626796-52576-3234-0000
> I1120 15:13:40.858957 1680728064 status_update_manager.cpp:380] Received 
> status update acknowledgement (UUID: 4f97c8df-1cc0-4eeb-8469-9d72df09ec73) 
> for task 4 of framework 201311201513-2877626796-52576-3234-0000
> I1120 15:13:40.859905 1679654912 slave.cpp:1740] Handling status update 
> TASK_FINISHED (UUID: 876d7ddc-5d58-48df-a590-d82cf39d4978) for task 4 of 
> framework 201311201513-2877626796-52576-3234-0000 from 
> executor(1)@172.25.133.171:52577
> I1120 15:13:40.860174 1680728064 status_update_manager.cpp:305] Received 
> status update TASK_FINISHED (UUID: 876d7ddc-5d58-48df-a590-d82cf39d4978) for 
> task 4 of framework 201311201513-2877626796-52576-3234-0000
> I1120 15:13:40.860245 1680728064 status_update_manager.cpp:356] Forwarding 
> status update TASK_FINISHED (UUID: 876d7ddc-5d58-48df-a590-d82cf39d4978) for 
> task 4 of framework 201311201513-2877626796-52576-3234-0000 to 
> [email protected]:52576
> I1120 15:13:40.860437 1679654912 master.cpp:1452] Status update TASK_FINISHED 
> (UUID: 876d7ddc-5d58-48df-a590-d82cf39d4978) for task 4 of framework 
> 201311201513-2877626796-52576-3234-0000 from slave(3)@172.25.133.171:52576
> I1120 15:13:40.860486 1680728064 slave.cpp:1865] Sending acknowledgement for 
> status update TASK_FINISHED (UUID: 876d7ddc-5d58-48df-a590-d82cf39d4978) for 
> task 4 of framework 201311201513-2877626796-52576-3234-0000 to 
> executor(1)@172.25.133.171:52577
> I1120 15:13:40.860550 1679654912 master.hpp:418] Removing task 4 with 
> resources cpus(*):1; mem(Status update: task 4 is in state TASK_FINISHED
> Finished tasks: 5
> *):128 on slave 201311201513-2877626796-52576-3234-2 (vkone.local)
> I1120 15:13:40.863689 1679654912 master.cpp:996] Asked to unregister 
> framework 201311201513-2877626796-52576-3234-0000
> I1120 15:13:40.863750 1679654912 master.cpp:2385] Removing framework 
> 201311201513-2877626796-52576-3234-0000
> ../../src/tests/script.cpp:81: Failure
> Failed
> java_framework_test.sh terminated with signal 'Abort trap: 6'
> [  FAILED  ] ExamplesTest.JavaFramework (2688 ms)
> [----------] 1 test from ExamplesTest (2688 ms total)
> [----------] Global test environment tear-down
> [==========] 1 test from 1 test case ran. (2692 ms total)
> [  PASSED  ] 0 tests.
> [  FAILED  ] 1 test, listed below:
> [  FAILED  ] ExamplesTest.JavaFramework



--
This message was sent by Atlassian JIRA
(v6.3.4#6332)

Reply via email to