[jira] [Commented] (MESOS-830) ExamplesTest.JavaFramework is flaky

2015-08-14 Thread Greg Mann (JIRA)

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

Greg Mann commented on MESOS-830:
-

Created a new ticket for the more general issue of the lack of synchronization 
between the JVM and native shutdown routines: MESOS-3264

> 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 
> master@172.25.133.171: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 
> master@172.25.133.171: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 
> master@172.25.133.171: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 master@172.25.133.171: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 
> master@172.25.133.171: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 master@172.25.133.171:52576
> I1120 15:13:39.834092 1680191488 slave.cpp:542] Registered with master 
> master@172.25.133.171: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/20131

[jira] [Commented] (MESOS-830) ExamplesTest.JavaFramework is flaky

2015-08-12 Thread Greg Mann (JIRA)

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

Greg Mann commented on MESOS-830:
-

There does not seem to be a good way to ensure completion of SchedulerDriver 
teardown before exiting the program, so I've settled for the not-so-good 
alternative of inserting a brief sleep before {{System.exit()}} is called. 
Review is here: https://reviews.apache.org/r/37415/

With the sleep, I can run the test several hundred times with no failures. This 
bug is also a bit dependent upon JDK installation: in OSX, it would fail nearly 
every time with the JVM 1.8 installed via {{brew cask install java}}, while it 
would fail only infrequently with the Oracle v7 or v8 JDK installed.

> 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 
> master@172.25.133.171: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 
> master@172.25.133.171: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 
> master@172.25.133.171: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 master@172.25.133.171: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 
> master@172.25.133.171: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 master@172.25.133.171:52576
> I1120 15:13:39.834092 1680191488 slave.cpp:542] Registered with master 
> master@172.25.133.171:52576; given slave ID 
> 201311201513-2877626796-52576-3234-0
> I1120

[jira] [Commented] (MESOS-830) ExamplesTest.JavaFramework is flaky

2015-08-10 Thread Greg Mann (JIRA)

[ 
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 
> master@172.25.133.171: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 
> master@172.25.133.171: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 
> master@172.25.133.171: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 master@172.25.133.171: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 
> master@172.25.133.171: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
> I

[jira] [Commented] (MESOS-830) ExamplesTest.JavaFramework is flaky

2015-08-06 Thread Greg Mann (JIRA)

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

Greg Mann commented on MESOS-830:
-

Excellent, thanks for the tip [~tillt]. I did the same, and indeed I see one of 
two things: either glog is attempting to lock a mutex that has already been 
destroyed, or it is attempting to destroy a mutex that is currently locked. 
Placing some print statements, I can see a process with a certain pid running 
the destructor of the file-scope mutex {{log_mutex}} from 
{{glog-0.3.3/src/logging.cc}}, then the same process with the same pid 
attempting to lock it. Strange.

> 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 
> master@172.25.133.171: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 
> master@172.25.133.171: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 
> master@172.25.133.171: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 master@172.25.133.171: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 
> master@172.25.133.171: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 master@172.25.133.171:52576
> I1120 15:13:39.834092 1680191488 slave.cpp:542] Registered with master 
> master@172.25.133.171: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.

[jira] [Commented] (MESOS-830) ExamplesTest.JavaFramework is flaky

2015-08-05 Thread Till Toenshoff (JIRA)

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

Till Toenshoff commented on MESOS-830:
--

[~greggomann] I added some debug code into that macro which told me that 
pthread_rwlock_wrlock returned 22 (Invalid Argument) and from that I assumed 
that the mutex in question had gotten killed already.

> 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 
> master@172.25.133.171: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 
> master@172.25.133.171: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 
> master@172.25.133.171: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 master@172.25.133.171: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 
> master@172.25.133.171: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 master@172.25.133.171:52576
> I1120 15:13:39.834092 1680191488 slave.cpp:542] Registered with master 
> master@172.25.133.171: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] Checkpoint

[jira] [Commented] (MESOS-830) ExamplesTest.JavaFramework is flaky

2015-08-05 Thread Niklas Quarfot Nielsen (JIRA)

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

Niklas Quarfot Nielsen commented on MESOS-830:
--

[~jvanremoortere] Would you mind shepherd this? :)

> 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 
> master@172.25.133.171: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 
> master@172.25.133.171: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 
> master@172.25.133.171: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 master@172.25.133.171: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 
> master@172.25.133.171: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 master@172.25.133.171:52576
> I1120 15:13:39.834092 1680191488 slave.cpp:542] Registered with master 
> master@172.25.133.171: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

[jira] [Commented] (MESOS-830) ExamplesTest.JavaFramework is flaky

2015-08-04 Thread Greg Mann (JIRA)

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

Greg Mann commented on MESOS-830:
-

It seems this issue is due to a race condition as the logs are flushing at the 
conclusion of this test framework. If I fork off a process during 
MesosSchedulerDriver::start() and use it to attach a debugger to the driver 
process, I see the following at the SIGABRT:

{noformat}
(lldb) th li
Process 25383 stopped
  thread #1: tid = 0x2e8f96, 0x7fff86ac84de 
libsystem_kernel.dylib`mach_msg_trap + 10, queue = 'com.apple.main-thread'
  thread #2: tid = 0x2e8fb9, 0x7fff86acd48a 
libsystem_kernel.dylib`__semwait_signal + 10
  thread #3: tid = 0x2e8fba, 0x7fff86ace232 libsystem_kernel.dylib`kevent64 
+ 10, queue = 'com.apple.libdispatch-manager'
  thread #4: tid = 0x2e8fbb, 0x7fff86acd136 
libsystem_kernel.dylib`__psynch_cvwait + 10
  thread #5: tid = 0x2e8fbc, 0x7fff86acd136 
libsystem_kernel.dylib`__psynch_cvwait + 10
  thread #6: tid = 0x2e8fbd, 0x7fff86acd136 
libsystem_kernel.dylib`__psynch_cvwait + 10
  thread #7: tid = 0x2e8fbe, 0x7fff86acd136 
libsystem_kernel.dylib`__psynch_cvwait + 10
  thread #8: tid = 0x2e8fbf, 0x7fff86acd136 
libsystem_kernel.dylib`__psynch_cvwait + 10
  thread #9: tid = 0x2e8fc0, 0x7fff86acd136 
libsystem_kernel.dylib`__psynch_cvwait + 10
  thread #10: tid = 0x2e8fc1, 0x7fff86acd136 
libsystem_kernel.dylib`__psynch_cvwait + 10
  thread #11: tid = 0x2e8fc2, 0x7fff86acd136 
libsystem_kernel.dylib`__psynch_cvwait + 10
  thread #12: tid = 0x2e8fc3, 0x7fff86acd136 
libsystem_kernel.dylib`__psynch_cvwait + 10
  thread #13: tid = 0x2e8fc4, 0x7fff8d8c4d62 
libsystem_malloc.dylib`tiny_free_list_add_ptr + 108
  thread #14: tid = 0x2e8fc5, 0x7fff86acd136 
libsystem_kernel.dylib`__psynch_cvwait + 10, name = 'Java: Reference Handler'
  thread #15: tid = 0x2e8fc6, 0x7fff86acd136 
libsystem_kernel.dylib`__psynch_cvwait + 10, name = 'Java: Finalizer'
  thread #18: tid = 0x2e8fcb, 0x7fff86acd136 
libsystem_kernel.dylib`__psynch_cvwait + 10, name = 'Java: Signal Dispatcher'
  thread #19: tid = 0x2e8fcc, 0x7fff86acd136 
libsystem_kernel.dylib`__psynch_cvwait + 10, name = 'Java: C2 CompilerThread0'
  thread #20: tid = 0x2e8fcd, 0x7fff86acd136 
libsystem_kernel.dylib`__psynch_cvwait + 10, name = 'Java: C2 CompilerThread1'
  thread #21: tid = 0x2e8fce, 0x7fff86acd136 
libsystem_kernel.dylib`__psynch_cvwait + 10, name = 'Java: C2 CompilerThread2'
  thread #22: tid = 0x2e8fcf, 0x7fff86acd136 
libsystem_kernel.dylib`__psynch_cvwait + 10, name = 'Java: C1 CompilerThread3'
  thread #23: tid = 0x2e8fd0, 0x7fff86acd136 
libsystem_kernel.dylib`__psynch_cvwait + 10, name = 'Java: Service Thread'
  thread #25: tid = 0x2e8fd2, 0x7fff86acd136 
libsystem_kernel.dylib`__psynch_cvwait + 10
  thread #26: tid = 0x2e8fd3, 0x7fff86acd136 
libsystem_kernel.dylib`__psynch_cvwait + 10
  thread #27: tid = 0x2e8fd4, 0x7fff86acd136 
libsystem_kernel.dylib`__psynch_cvwait + 10
  thread #28: tid = 0x2e8fd5, 0x7fff86acd136 
libsystem_kernel.dylib`__psynch_cvwait + 10
  thread #29: tid = 0x2e8fd6, 0x7fff86acd136 
libsystem_kernel.dylib`__psynch_cvwait + 10
  thread #30: tid = 0x2e8fd7, 0x7fff86acd136 
libsystem_kernel.dylib`__psynch_cvwait + 10
* thread #31: tid = 0x2e8fd8, 0x7fff86acd286 
libsystem_kernel.dylib`__pthread_kill + 10, stop reason = signal SIGABRT
  thread #32: tid = 0x2e8fd9, 0x7fff86acd136 
libsystem_kernel.dylib`__psynch_cvwait + 10
  thread #33: tid = 0x2e8fda, 0x0001274f9fb0 
libmesos-0.24.0.dylib`std::__1::atomic_flag* 
synchronized_get_pointer(t=0x7ff1) at 
synchronized.hpp:88
  thread #34: tid = 0x2e8fdb, 0x7fff86acd136 
libsystem_kernel.dylib`__psynch_cvwait + 10
(lldb) th b
* thread #31: tid = 0x2e8fd8, 0x7fff86acd286 
libsystem_kernel.dylib`__pthread_kill + 10, stop reason = signal SIGABRT
frame #0: 0x7fff86acd286 libsystem_kernel.dylib`__pthread_kill + 10
frame #1: 0x7fff87e8842f libsystem_pthread.dylib`pthread_kill + 90
  * frame #2: 0x7fff8c237b53 libsystem_c.dylib`abort + 129
frame #3: 0x000129216010 
libmesos-0.24.0.dylib`glog_internal_namespace_::Mutex::Lock(this=0x0001298b4c38)
 + 64 at mutex.h:248
frame #4: 0x000129215fc3 
libmesos-0.24.0.dylib`glog_internal_namespace_::MutexLock::MutexLock(this=0x00012d945cc8,
 mu=0x0001298b4c38) + 35 at mutex.h:288
frame #5: 0x00012921285d 
libmesos-0.24.0.dylib`glog_internal_namespace_::MutexLock::MutexLock(this=0x00012d945cc8,
 mu=0x0001298b4c38) + 29 at mutex.h:288
frame #6: 0x000129202f17 
libmesos-0.24.0.dylib`google::LogMessage::Flush(this=0x00012d945e40) + 279 
at logging.cc:1280
frame #7: 0x000129202db8 
libmesos-0.24.0.dylib`google::LogMessage::~LogMessage(this=0x00012d945e40) 
+ 24 at loggin

[jira] [Commented] (MESOS-830) ExamplesTest.JavaFramework is flaky

2015-07-24 Thread Greg Mann (JIRA)

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

Greg Mann commented on MESOS-830:
-

Also worth noting that if I instead install Java 8 via Oracle's official 
installer, running this test fails and I get a prompt to install the JRE ver. 6

> 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
>  Labels: flaky
>
> [ 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 
> master@172.25.133.171: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 
> master@172.25.133.171: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 
> master@172.25.133.171: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 master@172.25.133.171: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 
> master@172.25.133.171: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 master@172.25.133.171:52576
> I1120 15:13:39.834092 1680191488 slave.cpp:542] Registered with master 
> master@172.25.133.171: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 h

[jira] [Commented] (MESOS-830) ExamplesTest.JavaFramework is flaky

2015-07-24 Thread Greg Mann (JIRA)

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

Greg Mann commented on MESOS-830:
-

I'm currently seeing this issue on OSX, with Java 8 installed via {{brew cask 
install java}}:
{noformat}
GLOG_v=2 ./bin/mesos-tests.sh --gtest_filter="ExamplesTest.JavaFramework" 
--verbose --gtest_break_on_failure
...
[ RUN  ] ExamplesTest.JavaFramework
Using temporary directory '/tmp/ExamplesTest_JavaFramework_GeoV8A'
Enabling authentication for the framework
WARNING: Logging before InitGoogleLogging() is written to STDERR
I0724 13:36:12.288672 180789248 process.cpp:2367] Spawned process 
__gc__@10.0.79.73:59658
I0724 13:36:12.288795 180789248 process.cpp:2367] Spawned process 
help@10.0.79.73:59658
I0724 13:36:12.288879 180789248 process.cpp:2367] Spawned process 
logging@10.0.79.73:59658
I0724 13:36:12.288673 784003072 process.cpp:2377] Resuming 
__gc__@10.0.79.73:59658 at 2015-07-24 20:36:12.288710144+00:00
I0724 13:36:12.288861 786149376 process.cpp:2377] Resuming 
logging@10.0.79.73:59658 at 2015-07-24 20:36:12.20128+00:00
I0724 13:36:12.288808 782393344 process.cpp:2377] Resuming 
help@10.0.79.73:59658 at 2015-07-24 20:36:12.288839936+00:00
I0724 13:36:12.288959 180789248 process.cpp:2367] Spawned process 
profiler@10.0.79.73:59658
I0724 13:36:12.288980 785076224 process.cpp:2377] Resuming 
profiler@10.0.79.73:59658 at 2015-07-24 20:36:12.28836+00:00
I0724 13:36:12.289037 786149376 process.cpp:2377] Resuming 
system@10.0.79.73:59658 at 2015-07-24 20:36:12.289053952+00:00
I0724 13:36:12.289039 782929920 process.cpp:2377] Resuming 
help@10.0.79.73:59658 at 2015-07-24 20:36:12.289055232+00:00
I0724 13:36:12.289058 180789248 process.cpp:2367] Spawned process 
system@10.0.79.73:59658
I0724 13:36:12.289150 786149376 process.cpp:2367] Spawned process 
__limiter__(1)@10.0.79.73:59658
I0724 13:36:12.289172 785076224 process.cpp:2377] Resuming 
__limiter__(1)@10.0.79.73:59658 at 2015-07-24 20:36:12.289180928+00:00
I0724 13:36:12.289196 785076224 process.cpp:2377] Resuming 
metrics@10.0.79.73:59658 at 2015-07-24 20:36:12.289200128+00:00
I0724 13:36:12.289233 786149376 process.cpp:2367] Spawned process 
metrics@10.0.79.73:59658
I0724 13:36:12.289284 784003072 process.cpp:2377] Resuming 
help@10.0.79.73:59658 at 2015-07-24 20:36:12.289297152+00:00
I0724 13:36:12.289331 782929920 process.cpp:2377] Resuming 
metrics@10.0.79.73:59658 at 2015-07-24 20:36:12.289338112+00:00
I0724 13:36:12.289417 786149376 process.cpp:2377] Resuming 
help@10.0.79.73:59658 at 2015-07-24 20:36:12.289427968+00:00
I0724 13:36:12.289448 784539648 process.cpp:2377] Resuming 
__processes__@10.0.79.73:59658 at 2015-07-24 20:36:12.289460992+00:00
I0724 13:36:12.289479 180789248 process.cpp:2367] Spawned process 
__processes__@10.0.79.73:59658
I0724 13:36:12.289499 180789248 process.cpp:987] libprocess is initialized on 
10.0.79.73:59658 for 8 cpus
I0724 13:36:12.289517 180789248 logging.cpp:177] Logging to STDERR
I0724 13:36:12.289515 786149376 process.cpp:2377] Resuming 
help@10.0.79.73:59658 at 2015-07-24 20:36:12.289522944+00:00
I0724 13:36:12.289801 782393344 process.cpp:2377] Resuming 
metrics@10.0.79.73:59658 at 2015-07-24 20:36:12.289825792+00:00
I0724 13:36:12.289835 785612800 process.cpp:2377] Resuming 
hierarchical-allocator(1)@10.0.79.73:59658 at 2015-07-24 
20:36:12.289848064+00:00
I0724 13:36:12.289876 180789248 process.cpp:2367] Spawned process 
hierarchical-allocator(1)@10.0.79.73:59658
I0724 13:36:12.289964 180789248 process.cpp:2367] Spawned process 
files@10.0.79.73:59658
I0724 13:36:12.289970 783466496 process.cpp:2377] Resuming 
files@10.0.79.73:59658 at 2015-07-24 20:36:12.289984000+00:00
I0724 13:36:12.290007 785076224 process.cpp:2377] Resuming 
help@10.0.79.73:59658 at 2015-07-24 20:36:12.290021888+00:00
I0724 13:36:12.296522 180789248 leveldb.cpp:176] Opened db in 3397us
...
I0724 13:36:17.713187 785612800 pid.cpp:96] Attempting to parse 
'slave(2)@10.0.79.73:59658' into a PID
Finished tasks: 1I0724 13:36:17.713224 784539648 slave.cpp:2273] Status update 
manager successfully handled status update acknowledgement (UUID: 
582d2414-be68-4b03-b496-cebc9378b05a) for task 3 of framework 
20150724-133612-1229914122-59658-23348-
I0724 13:36:17.713215 784003072 process.cpp:2377] Resuming 
(14)@10.0.79.73:59658 at 2015-07-24 20:36:17.713229824+00:00

I0724 13:36:17.713225 785612800 master.cpp:3790] Status update TASK_FINISHED 
(UUID: c5c8ee27-ac6b-4fa6-ad9d-a3397fae5598) for task 3 of framework 
20150724-133612-1229914122-59658-23348- from slave 
20150724-133612-1229914122-59658-23348-S0 at slave(2)@10.0.79.73:59658 
(10.0.79.73)
I0724 13:36:17.713268 784003072 status_update_manager.cpp:394] Received status 
update acknowledgement (UUID: 4795edfd-4df3-44fd-b204-5fe833d35d86) for task 2 
of framework 20150724-133612-1229914122-59658-23348-
I0724 13:36:17.713280 785

[jira] [Commented] (MESOS-830) ExamplesTest.JavaFramework is flaky

2015-04-09 Thread Cody Maloney (JIRA)

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

Cody Maloney commented on MESOS-830:


Still failing (Although frequency seems to have increased) on our OSX Buildbot.

> 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
>  Labels: flaky
>
> [ 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 
> master@172.25.133.171: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 
> master@172.25.133.171: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 
> master@172.25.133.171: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 master@172.25.133.171: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 
> master@172.25.133.171: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 master@172.25.133.171:52576
> I1120 15:13:39.834092 1680191488 slave.cpp:542] Registered with master 
> master@172.25.133.171: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-2

[jira] [Commented] (MESOS-830) ExamplesTest.JavaFramework is flaky

2015-01-30 Thread Cody Maloney (JIRA)

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

Cody Maloney commented on MESOS-830:


Recent failure: https://reviews.apache.org/r/30442/

> 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
>  Labels: flaky
>
> [ 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 
> master@172.25.133.171: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 
> master@172.25.133.171: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 
> master@172.25.133.171: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 master@172.25.133.171: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 
> master@172.25.133.171: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 master@172.25.133.171:52576
> I1120 15:13:39.834092 1680191488 slave.cpp:542] Registered with master 
> master@172.25.133.171: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 (vkon

[jira] [Commented] (MESOS-830) ExamplesTest.JavaFramework is flaky

2014-11-04 Thread Till Toenshoff (JIRA)

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

Till Toenshoff commented on MESOS-830:
--

I also see this one failing a lot on OSX. 

Just ran a gtest_repeat=20 and got 19 failures, 1 pass.

{noformat}
[ RUN  ] ExamplesTest.JavaFramework
Using temporary directory '/tmp/ExamplesTest_JavaFramework_DCnIxN'
Enabling authentication for the framework
I1104 22:21:37.416721 112590848 leveldb.cpp:176] Opened db in 2428us
I1104 22:21:37.417207 112590848 leveldb.cpp:183] Compacted db in 454us
I1104 22:21:37.417244 112590848 leveldb.cpp:198] Created db iterator in 15us
I1104 22:21:37.417258 112590848 leveldb.cpp:204] Seeked to beginning of db in 
7us
I1104 22:21:37.417268 112590848 leveldb.cpp:273] Iterated through 0 keys in the 
db in 8us
I1104 22:21:37.417317 112590848 replica.cpp:741] Replica recovered with log 
positions 0 -> 0 with 1 holes and 0 unlearned
I1104 22:21:37.417966 503451648 recover.cpp:437] Starting replica recovery
I1104 22:21:37.418251 503451648 recover.cpp:463] Replica is in EMPTY status
I1104 22:21:37.419044 502378496 replica.cpp:638] Replica in EMPTY status 
received a broadcasted recover request
I1104 22:21:37.419242 506134528 recover.cpp:188] Received a recover response 
from a replica in EMPTY status
I1104 22:21:37.419445 504524800 recover.cpp:554] Updating replica status to 
STARTING
I1104 22:21:37.419777 505597952 leveldb.cpp:306] Persisting metadata (8 bytes) 
to leveldb took 231us
I1104 22:21:37.419802 505597952 replica.cpp:320] Persisted replica status to 
STARTING
I1104 22:21:37.419909 503988224 recover.cpp:463] Replica is in STARTING status
I1104 22:21:37.420393 502378496 replica.cpp:638] Replica in STARTING status 
received a broadcasted recover request
I1104 22:21:37.420555 503988224 recover.cpp:188] Received a recover response 
from a replica in STARTING status
I1104 22:21:37.420811 502915072 recover.cpp:554] Updating replica status to 
VOTING
I1104 22:21:37.421128 505597952 leveldb.cpp:306] Persisting metadata (8 bytes) 
to leveldb took 193us
I1104 22:21:37.421161 505597952 replica.cpp:320] Persisted replica status to 
VOTING
I1104 22:21:37.421190 504524800 recover.cpp:568] Successfully joined the Paxos 
group
I1104 22:21:37.421301 504524800 recover.cpp:452] Recover process terminated
I1104 22:21:37.425765 502378496 master.cpp:318] Master 
20141104-222137-347252928-55703-8935 (lobomacpro2.fritz.box) started on 
192.168.178.20:55703
I1104 22:21:37.425830 502378496 master.cpp:364] Master only allowing 
authenticated frameworks to register
I1104 22:21:37.425843 502378496 master.cpp:371] Master allowing unauthenticated 
slaves to register
I1104 22:21:37.425854 502378496 credentials.hpp:36] Loading credentials for 
authentication from '/tmp/ExamplesTest_JavaFramework_DCnIxN/credentials'
W1104 22:21:37.425889 502378496 credentials.hpp:51] Permissions on credentials 
file '/tmp/ExamplesTest_JavaFramework_DCnIxN/credentials' are too open. It is 
recommended that your credentials file is NOT accessible by others.
I1104 22:21:37.425921 502378496 master.cpp:408] Authorization enabled
I1104 22:21:37.426417 112590848 containerizer.cpp:100] Using isolation: 
posix/cpu,posix/mem
I1104 22:21:37.427026 504524800 slave.cpp:169] Slave started on 
1)@192.168.178.20:55703
I1104 22:21:37.427248 504524800 slave.cpp:289] Slave resources: cpus(*):2; 
mem(*):10240; disk(*):470808; ports(*):[31000-32000]
I1104 22:21:37.427533 112590848 containerizer.cpp:100] Using isolation: 
posix/cpu,posix/mem
I1104 22:21:37.428071 503988224 slave.cpp:169] Slave started on 
2)@192.168.178.20:55703
I1104 22:21:37.428176 502378496 master.cpp:1258] The newly elected leader is 
master@192.168.178.20:55703 with id 20141104-222137-347252928-55703-8935
I1104 22:21:37.428205 502378496 master.cpp:1271] Elected as the leading master!
I1104 22:21:37.428220 502378496 master.cpp:1089] Recovering from registrar
I1104 22:21:37.428267 503988224 slave.cpp:289] Slave resources: cpus(*):2; 
mem(*):10240; disk(*):470808; ports(*):[31000-32000]
I1104 22:21:37.428318 502915072 registrar.cpp:313] Recovering registrar
I1104 22:21:37.428598 505061376 log.cpp:656] Attempting to start the writer
I1104 22:21:37.428805 112590848 containerizer.cpp:100] Using isolation: 
posix/cpu,posix/mem
I1104 22:21:37.428889 503988224 slave.cpp:318] Slave hostname: 
lobomacpro2.fritz.box
I1104 22:21:37.428892 504524800 slave.cpp:318] Slave hostname: 
lobomacpro2.fritz.box
I1104 22:21:37.428917 503988224 slave.cpp:319] Slave checkpoint: true
I1104 22:21:37.428927 504524800 slave.cpp:319] Slave checkpoint: true
I1104 22:21:37.429457 506134528 state.cpp:33] Recovering state from 
'/var/folders/_t/rdp354gx7j5fjww270kbk6_rgn/T/mesos-XX.3EkfQ7TT/1/meta'
I1104 22:21:37.429478 505061376 state.cpp:33] Recovering state from 
'/var/folders/_t/rdp354gx7j5fjww270kbk6_rgn/T/mesos-XX.3EkfQ7TT/0/meta'

[jira] [Commented] (MESOS-830) ExamplesTest.JavaFramework is flaky

2014-10-15 Thread Alexander Rukletsov (JIRA)

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

Alexander Rukletsov commented on MESOS-830:
---

[ RUN  ] ExamplesTest.JavaFramework
Using temporary directory '/tmp/ExamplesTest_JavaFramework_qJnXgB'
Enabling authentication for the framework
I1015 16:30:22.277333 280764416 leveldb.cpp:176] Opened db in 2162us
I1015 16:30:22.277742 280764416 leveldb.cpp:183] Compacted db in 391us
I1015 16:30:22.277783 280764416 leveldb.cpp:198] Created db iterator in 15us
I1015 16:30:22.277808 280764416 leveldb.cpp:204] Seeked to beginning of db in 
17us
I1015 16:30:22.277823 280764416 leveldb.cpp:273] Iterated through 0 keys in the 
db in 12us
I1015 16:30:22.277849 280764416 replica.cpp:741] Replica recovered with log 
positions 0 -> 0 with 1 holes and 0 unlearned
I1015 16:30:22.278256 793427968 recover.cpp:425] Starting replica recovery
I1015 16:30:22.278350 793427968 recover.cpp:451] Replica is in EMPTY status
I1015 16:30:22.278827 791818240 replica.cpp:638] Replica in EMPTY status 
received a broadcasted recover request
I1015 16:30:22.278897 793427968 recover.cpp:188] Received a recover response 
from a replica in EMPTY status
I1015 16:30:22.279062 793964544 recover.cpp:542] Updating replica status to 
STARTING
I1015 16:30:22.279276 792354816 master.cpp:312] Master 
20141015-163022-26053898-61054-26738 (10.141.141.1) started on 
10.141.141.1:61054
I1015 16:30:22.279325 792354816 master.cpp:358] Master only allowing 
authenticated frameworks to register
I1015 16:30:22.279333 792354816 master.cpp:365] Master allowing unauthenticated 
slaves to register
I1015 16:30:22.279341 792354816 credentials.hpp:36] Loading credentials for 
authentication from '/tmp/ExamplesTest_JavaFramework_qJnXgB/credentials'
I1015 16:30:22.279333 791281664 leveldb.cpp:306] Persisting metadata (8 bytes) 
to leveldb took 214us
I1015 16:30:22.279356 791281664 replica.cpp:320] Persisted replica status to 
STARTING
W1015 16:30:22.279388 792354816 credentials.hpp:51] Permissions on credentials 
file '/tmp/ExamplesTest_JavaFramework_qJnXgB/credentials' are too open. It is 
recommended that your credentials file is NOT accessible by others.
I1015 16:30:22.279394 793964544 recover.cpp:451] Replica is in STARTING status
I1015 16:30:22.279422 792354816 master.cpp:392] Authorization enabled
I1015 16:30:22.279675 280764416 containerizer.cpp:89] Using isolation: 
posix/cpu,posix/mem
I1015 16:30:22.279726 793427968 replica.cpp:638] Replica in STARTING status 
received a broadcasted recover request
I1015 16:30:22.279810 790208512 recover.cpp:188] Received a recover response 
from a replica in STARTING status
I1015 16:30:22.279940 793964544 recover.cpp:542] Updating replica status to 
VOTING
I1015 16:30:22.280112 791281664 leveldb.cpp:306] Persisting metadata (8 bytes) 
to leveldb took 115us
I1015 16:30:22.280133 791281664 replica.cpp:320] Persisted replica status to 
VOTING
I1015 16:30:22.280145 793964544 slave.cpp:169] Slave started on 
1)@10.141.141.1:61054
I1015 16:30:22.280171 793427968 recover.cpp:556] Successfully joined the Paxos 
group
I1015 16:30:22.280227 793427968 recover.cpp:440] Recover process terminated
I1015 16:30:22.280302 793964544 slave.cpp:289] Slave resources: cpus(*):2; 
mem(*):10240; disk(*):470842; ports(*):[31000-32000]
I1015 16:30:22.280405 792354816 master.cpp:1242] The newly elected leader is 
master@10.141.141.1:61054 with id 20141015-163022-26053898-61054-26738
I1015 16:30:22.280423 792354816 master.cpp:1255] Elected as the leading master!
I1015 16:30:22.280434 792354816 master.cpp:1073] Recovering from registrar
I1015 16:30:22.280478 790208512 registrar.cpp:313] Recovering registrar
I1015 16:30:22.280477 280764416 containerizer.cpp:89] Using isolation: 
posix/cpu,posix/mem
I1015 16:30:22.280521 793964544 slave.cpp:318] Slave hostname: 10.141.141.1
I1015 16:30:22.280529 793964544 slave.cpp:319] Slave checkpoint: true
I1015 16:30:22.280633 793427968 log.cpp:656] Attempting to start the writer
I1015 16:30:22.280802 792354816 slave.cpp:169] Slave started on 
2)@10.141.141.1:61054
I1015 16:30:22.280841 792891392 state.cpp:33] Recovering state from 
'/var/folders/h3/8j18s1cx2bn78ms99d3lz4jhgn/T/mesos-XX.TWviyPgj/0/meta'
I1015 16:30:22.280932 792354816 slave.cpp:289] Slave resources: cpus(*):2; 
mem(*):10240; disk(*):470842; ports(*):[31000-32000]
I1015 16:30:22.280943 791818240 status_update_manager.cpp:193] Recovering 
status update manager
I1015 16:30:22.281029 790208512 containerizer.cpp:252] Recovering containerizer
I1015 16:30:22.281132 791818240 replica.cpp:474] Replica received implicit 
promise request with proposal 1
I1015 16:30:22.281138 792354816 slave.cpp:318] Slave hostname: 10.141.141.1
I1015 16:30:22.281148 280764416 containerizer.cpp:89] Using isolation: 
posix/cpu,posix/mem
I1015 16:30:22.281158 792354816 slave.cpp:319] Slave checkpoint: true
I101