You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@mesos.apache.org by Apache Jenkins Server <je...@builds.apache.org> on 2013/04/13 05:43:57 UTC
Build failed in Jenkins:
Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME #302
See <https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/302/changes>
Changes:
[bmahler] Fixed the command executor to setsid on the command, and issue
killtree() to clean up.
Review: https://reviews.apache.org/r/10440
[bmahler] Added isolation module tests for resource usage.
Review: https://reviews.apache.org/r/9797
[bmahler] Better cgroups resource monitoring error handling.
Review: https://reviews.apache.org/r/9796
[bmahler] Added child process monitoring to process based isolation module.
Review: https://reviews.apache.org/r/9795
[bmahler] Added proc::children for linux.
Review: https://reviews.apache.org/r/9794
------------------------------------------
[...truncated 15466 lines...]
I0413 03:43:54.753515 14285 detector.cpp:531] Master detector (master@67.195.138.60:43866) got new master pid: master@67.195.138.60:43866
I0413 03:43:54.753723 14282 sched.cpp:182] New master at master@67.195.138.60:43866
I0413 03:43:54.754180 14286 slave.cpp:453] New master detected at master@67.195.138.60:43866
I0413 03:43:54.754680 14285 master.cpp:603] Elected as master!
I0413 03:43:54.755678 14280 status_update_manager.cpp:132] New master detected at master@67.195.138.60:43866
I0413 03:43:54.756098 14285 master.cpp:681] Re-registering framework 201304130343-1015726915-43866-14090-0000 at scheduler(74)@67.195.138.60:43866
I0413 03:43:54.759197 14283 sched.cpp:217] Framework registered with 201304130343-1015726915-43866-14090-0000
I0413 03:43:54.759289 14284 hierarchical_allocator_process.hpp:268] Added framework 201304130343-1015726915-43866-14090-0000
I0413 03:43:54.767462 14284 hierarchical_allocator_process.hpp:668] No resources available to allocate!
I0413 03:43:54.767917 14284 hierarchical_allocator_process.hpp:599] Performed allocation for 0 slaves in 457.24us
I0413 03:43:54.786214 14279 hierarchical_allocator_process.hpp:660] Found available resources: cpus=1; mem=524; ports=[31000-32000]; disk=1024 on slave 201304130343-1015726915-43866-14090-0
I0413 03:43:54.786304 14279 hierarchical_allocator_process.hpp:756] Filtered cpus=1; mem=524; ports=[31000-32000]; disk=1024 on slave 201304130343-1015726915-43866-14090-0 for framework 201304130343-1015726915-43866-14090-0000
I0413 03:43:54.807374 14279 hierarchical_allocator_process.hpp:599] Performed allocation for 1 slaves in 21.18ms
I0413 03:43:55.290869 14284 master.cpp:1029] Attempting to re-register slave 201304130343-1015726915-43866-14090-0 at slave(82)@67.195.138.60:43866 (janus.apache.org)
I0413 03:43:55.329746 14284 master.cpp:1224] Master now considering a slave at janus.apache.org:43866 as active
I0413 03:43:55.330188 14284 master.cpp:1862] Adding slave 201304130343-1015726915-43866-14090-0 at janus.apache.org with cpus=2; mem=1024; ports=[31000-32000]; disk=1024
I0413 03:43:55.330729 14285 slave.cpp:520] Re-registered with master
I0413 03:43:55.330729 14284 master.hpp:289] Adding task with resources cpus=1; mem=500 on slave 201304130343-1015726915-43866-14090-0
I0413 03:43:55.331684 14284 slave.cpp:956] Updating framework 201304130343-1015726915-43866-14090-0000 pid to scheduler(74)@67.195.138.60:43866
I0413 03:43:55.331763 14285 hierarchical_allocator_process.hpp:395] Added slave 201304130343-1015726915-43866-14090-0 (janus.apache.org) with cpus=2; mem=1024; ports=[31000-32000]; disk=1024 (and cpus=1; mem=524; ports=[31000-32000]; disk=1024 available)
I0413 03:43:55.332557 14285 hierarchical_allocator_process.hpp:660] Found available resources: cpus=1; mem=524; ports=[31000-32000]; disk=1024 on slave 201304130343-1015726915-43866-14090-0
I0413 03:43:55.333031 14285 hierarchical_allocator_process.hpp:686] Offering cpus=1; mem=524; ports=[31000-32000]; disk=1024 on slave 201304130343-1015726915-43866-14090-0 to framework 201304130343-1015726915-43866-14090-0000
I0413 03:43:55.333606 14285 hierarchical_allocator_process.hpp:619] Performed allocation for slave 201304130343-1015726915-43866-14090-0 in 1.04ms
I0413 03:43:55.333639 14279 master.hpp:309] Adding offer with resources cpus=1; mem=524; ports=[31000-32000]; disk=1024 on slave 201304130343-1015726915-43866-14090-0
I0413 03:43:55.334467 14279 master.cpp:1327] Sending 1 offers to framework 201304130343-1015726915-43866-14090-0000
I0413 03:43:55.335010 14282 sched.cpp:282] Received 1 offers
I0413 03:43:55.335803 14280 sched.cpp:422] Stopping framework '201304130343-1015726915-43866-14090-0000'
I0413 03:43:55.363181 14285 master.cpp:774] Asked to unregister framework 201304130343-1015726915-43866-14090-0000
I0413 03:43:55.363632 14279 slave.cpp:889] Asked to shut down framework 201304130343-1015726915-43866-14090-0000 by master@67.195.138.60:43866
I0413 03:43:55.364146 14279 slave.cpp:894] Shutting down framework 201304130343-1015726915-43866-14090-0000
I0413 03:43:55.363682 14281 hierarchical_allocator_process.hpp:359] Deactivated framework 201304130343-1015726915-43866-14090-0000
I0413 03:43:55.363641 14285 master.hpp:300] Removing task with resources cpus=1; mem=500 on slave 201304130343-1015726915-43866-14090-0
I0413 03:43:55.407805 14279 slave.cpp:1681] Shutting down executor 'default' of framework 201304130343-1015726915-43866-14090-0000
I0413 03:43:55.419177 14285 master.hpp:318] Removing offer with resources cpus=1; mem=524; ports=[31000-32000]; disk=1024 on slave 201304130343-1015726915-43866-14090-0
I0413 03:43:55.419250 14284 hierarchical_allocator_process.hpp:544] Recovered cpus=1; mem=500 (total allocatable: cpus=1; mem=500; ports=[]; disk=0) on slave 201304130343-1015726915-43866-14090-0 from framework 201304130343-1015726915-43866-14090-0000
I0413 03:43:55.431138 14286 exec.cpp:321] Executor asked to shutdown
I0413 03:43:55.431155 14279 status_update_manager.cpp:233] Closing status update streams for framework 201304130343-1015726915-43866-14090-0000
I0413 03:43:55.439350 14281 slave.cpp:386] Slave terminating
I0413 03:43:55.452872 14281 slave.cpp:889] Asked to shut down framework 201304130343-1015726915-43866-14090-0000 by @0.0.0.0:0
I0413 03:43:55.453397 14281 slave.cpp:894] Shutting down framework 201304130343-1015726915-43866-14090-0000
I0413 03:43:55.453961 14281 slave.cpp:1681] Shutting down executor 'default' of framework 201304130343-1015726915-43866-14090-0000
I0413 03:43:55.452334 14279 status_update_manager.cpp:434] Cleaning up status update stream for task 0 of framework 201304130343-1015726915-43866-14090-0000
I0413 03:43:55.455425 14279 status_update_manager.cpp:233] Closing status update streams for framework 201304130343-1015726915-43866-14090-0000
I0413 03:43:55.454681 14282 master.cpp:537] Slave 201304130343-1015726915-43866-14090-0(janus.apache.org) disconnected
I0413 03:43:55.507040 14282 master.cpp:542] Removing disconnected slave 201304130343-1015726915-43866-14090-0(janus.apache.org) because it is not checkpointing!
I0413 03:43:55.451287 14284 hierarchical_allocator_process.hpp:544] Recovered cpus=1; mem=524; ports=[31000-32000]; disk=1024 (total allocatable: cpus=2; mem=1024; ports=[31000-32000]; disk=1024) on slave 201304130343-1015726915-43866-14090-0 from framework 201304130343-1015726915-43866-14090-0000
I0413 03:43:55.512676 14090 master.cpp:477] Master terminating
I0413 03:43:55.523597 14090 master.cpp:283] Shutting down master
I0413 03:43:55.524268 14090 master.cpp:283] Shutting down master
I0413 03:43:55.555112 14090 master.hpp:300] Removing task with resources cpus=1; mem=500 on slave 201304130343-1015726915-43866-14090-0
I0413 03:43:55.555135 14286 hierarchical_allocator_process.hpp:359] Deactivated framework 201304130343-1015726915-43866-14090-0000
I0413 03:43:55.556171 14286 hierarchical_allocator_process.hpp:544] Recovered cpus=1; mem=500 (total allocatable: cpus=2; mem=1024; ports=[31000-32000]; disk=1024) on slave 201304130343-1015726915-43866-14090-0 from framework 201304130343-1015726915-43866-14090-0000
I0413 03:43:55.556673 14286 hierarchical_allocator_process.hpp:312] Removed framework 201304130343-1015726915-43866-14090-0000
I0413 03:43:55.557142 14090 zookeeper_test_server.cpp:195] Shutdown ZooKeeperTestServer on port 45972
I0413 03:43:55.557152 14286 hierarchical_allocator_process.hpp:423] Removed slave 201304130343-1015726915-43866-14090-0
[ OK ] AllocatorZooKeeperTest/0.FrameworkReregistersFirst (1814 ms)
[ RUN ] AllocatorZooKeeperTest/0.SlaveReregistersFirst
I0413 03:43:55.559051 14090 jvm.cpp:34] looking up method <init>(Ljava/lang/String;)V
I0413 03:43:55.559109 14090 jvm.cpp:34] looking up method <init>(I)V
I0413 03:43:55.559484 14090 jvm.cpp:34] looking up method <init>(Ljava/net/InetSocketAddress;)V
I0413 03:43:55.559948 14090 jvm.cpp:34] looking up method startup(Lorg/apache/zookeeper/server/ZooKeeperServer;)V
I0413 03:43:55.560416 14090 jvm.cpp:34] looking up method isAlive()Z
I0413 03:43:55.560889 14090 jvm.cpp:34] looking up method shutdown()V
I0413 03:43:55.563791 14090 jvm.cpp:34] looking up method <init>(Ljava/io/File;Ljava/io/File;)V
I0413 03:43:55.564339 14090 jvm.cpp:34] looking up method <init>()V
I0413 03:43:55.564518 14090 jvm.cpp:34] looking up method <init>(Lorg/apache/zookeeper/server/persistence/FileTxnSnapLog;Lorg/apache/zookeeper/server/ZooKeeperServer$DataTreeBuilder;)V
I0413 03:43:55.565075 14090 jvm.cpp:34] looking up method getClientPort()I
I0413 03:43:55.565593 14090 jvm.cpp:34] looking up method closeSession(J)V
I0413 03:43:55.567770 14090 zookeeper_test_server.cpp:212] Started ZooKeeperTestServer on port 56697
I0413 03:43:55.567970 14280 master.cpp:309] Master started on 67.195.138.60:43866
I0413 03:43:55.568179 14280 master.cpp:324] Master ID: 201304130343-1015726915-43866-14090
W0413 03:43:55.569541 14282 master.cpp:81] No whitelist given. Advertising offers for all slaves
I0413 03:43:55.569545 14284 hierarchical_allocator_process.hpp:236] Initializing hierarchical allocator process with master : master@67.195.138.60:43866
I0413 03:43:55.568408 14279 slave.cpp:203] Slave started on 83)@67.195.138.60:43866
I0413 03:43:55.584365 14279 slave.cpp:204] Slave resources: cpus=2; mem=1024; ports=[31000-32000]; disk=1024
I0413 03:43:55.632521 14286 detector.cpp:283] Master detector (master@67.195.138.60:43866) connected to ZooKeeper ...
I0413 03:43:55.672487 14283 slave.cpp:377] Finished recovery
I0413 03:43:55.672554 14280 detector.cpp:283] Master detector (slave(83)@67.195.138.60:43866) connected to ZooKeeper ...
I0413 03:43:55.673038 14281 detector.cpp:283] Master detector (scheduler(75)@67.195.138.60:43866) connected to ZooKeeper ...
I0413 03:43:55.695670 14281 detector.cpp:300] Trying to create path '/znode' in ZooKeeper
I0413 03:43:55.695094 14280 detector.cpp:300] Trying to create path '/znode' in ZooKeeper
I0413 03:43:55.679105 14286 detector.cpp:300] Trying to create path '/znode' in ZooKeeper
I0413 03:43:55.766578 14281 detector.cpp:485] Master detector (scheduler(75)@67.195.138.60:43866) found 0 registered masters
I0413 03:43:55.766595 14280 detector.cpp:485] Master detector (slave(83)@67.195.138.60:43866) found 0 registered masters
I0413 03:43:55.766628 14281 detector.cpp:506] Master detector (scheduler(75)@67.195.138.60:43866) couldn't find any masters
I0413 03:43:55.805379 14286 detector.cpp:330] Created ephemeral/sequence znode at '/znode/0000000000'
I0413 03:43:55.811058 14280 detector.cpp:506] Master detector (slave(83)@67.195.138.60:43866) couldn't find any masters
I0413 03:43:55.819715 14285 sched.cpp:193] No master detected, waiting for another master
I0413 03:43:55.820173 14281 detector.cpp:485] Master detector (scheduler(75)@67.195.138.60:43866) found 1 registered masters
I0413 03:43:55.827546 14286 detector.cpp:485] Master detector (master@67.195.138.60:43866) found 1 registered masters
I0413 03:43:55.835255 14279 slave.cpp:479] Lost master(s) ... waiting
I0413 03:43:55.835785 14280 detector.cpp:485] Master detector (slave(83)@67.195.138.60:43866) found 1 registered masters
I0413 03:43:55.839942 14281 detector.cpp:531] Master detector (scheduler(75)@67.195.138.60:43866) got new master pid: master@67.195.138.60:43866
I0413 03:43:55.840409 14286 detector.cpp:531] Master detector (master@67.195.138.60:43866) got new master pid: master@67.195.138.60:43866
I0413 03:43:55.842829 14286 master.cpp:603] Elected as master!
I0413 03:43:55.842430 14285 sched.cpp:182] New master at master@67.195.138.60:43866
I0413 03:43:55.842399 14280 detector.cpp:531] Master detector (slave(83)@67.195.138.60:43866) got new master pid: master@67.195.138.60:43866
I0413 03:43:55.843904 14281 master.cpp:646] Registering framework 201304130343-1015726915-43866-14090-0000 at scheduler(75)@67.195.138.60:43866
I0413 03:43:55.844288 14280 slave.cpp:453] New master detected at master@67.195.138.60:43866
I0413 03:43:55.844789 14285 sched.cpp:217] Framework registered with 201304130343-1015726915-43866-14090-0000
I0413 03:43:55.844815 14283 hierarchical_allocator_process.hpp:268] Added framework 201304130343-1015726915-43866-14090-0000
I0413 03:43:55.846220 14283 hierarchical_allocator_process.hpp:668] No resources available to allocate!
I0413 03:43:55.846716 14283 hierarchical_allocator_process.hpp:599] Performed allocation for 0 slaves in 470.34us
I0413 03:43:55.845322 14284 status_update_manager.cpp:132] New master detected at master@67.195.138.60:43866
I0413 03:43:55.845382 14279 master.cpp:968] Attempting to register slave on janus.apache.org at slave(83)@67.195.138.60:43866
I0413 03:43:55.856400 14279 master.cpp:1224] Master now considering a slave at janus.apache.org:43866 as active
I0413 03:43:55.856961 14279 master.cpp:1862] Adding slave 201304130343-1015726915-43866-14090-0 at janus.apache.org with cpus=2; mem=1024; ports=[31000-32000]; disk=1024
I0413 03:43:55.857586 14281 slave.cpp:487] Registered with master; given slave ID 201304130343-1015726915-43866-14090-0
I0413 03:43:55.857720 14283 hierarchical_allocator_process.hpp:395] Added slave 201304130343-1015726915-43866-14090-0 (janus.apache.org) with cpus=2; mem=1024; ports=[31000-32000]; disk=1024 (and cpus=2; mem=1024; ports=[31000-32000]; disk=1024 available)
I0413 03:43:55.867064 14283 hierarchical_allocator_process.hpp:660] Found available resources: cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201304130343-1015726915-43866-14090-0
I0413 03:43:55.876487 14283 hierarchical_allocator_process.hpp:686] Offering cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201304130343-1015726915-43866-14090-0 to framework 201304130343-1015726915-43866-14090-0000
I0413 03:43:55.883152 14283 hierarchical_allocator_process.hpp:619] Performed allocation for slave 201304130343-1015726915-43866-14090-0 in 16.11ms
I0413 03:43:55.883203 14281 master.hpp:309] Adding offer with resources cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201304130343-1015726915-43866-14090-0
I0413 03:43:55.903097 14281 master.cpp:1327] Sending 1 offers to framework 201304130343-1015726915-43866-14090-0000
I0413 03:43:55.911085 14280 sched.cpp:282] Received 1 offers
I0413 03:43:55.927302 14285 master.cpp:1534] Processing reply for offer 201304130343-1015726915-43866-14090-0 on slave 201304130343-1015726915-43866-14090-0 (janus.apache.org) for framework 201304130343-1015726915-43866-14090-0000
I0413 03:43:55.943145 14285 master.hpp:289] Adding task with resources cpus=1; mem=500 on slave 201304130343-1015726915-43866-14090-0
I0413 03:43:55.963089 14285 master.cpp:1651] Launching task 0 of framework 201304130343-1015726915-43866-14090-0000 with resources cpus=1; mem=500 on slave 201304130343-1015726915-43866-14090-0 (janus.apache.org)
I0413 03:43:55.995117 14280 slave.cpp:587] Got assigned task 0 for framework 201304130343-1015726915-43866-14090-0000
I0413 03:43:55.996983 14280 paths.hpp:302] Created executor directory '/tmp/AllocatorZooKeeperTest_0_SlaveReregistersFirst_eYdL7u/slaves/201304130343-1015726915-43866-14090-0/frameworks/201304130343-1015726915-43866-14090-0000/executors/default/runs/c6101b3e-05cd-4ea6-861e-7e37f6da0ba0'
I0413 03:43:55.995198 14279 hierarchical_allocator_process.hpp:471] Framework 201304130343-1015726915-43866-14090-0000 left cpus=1; mem=524; ports=[31000-32000]; disk=1024 unused on slave 201304130343-1015726915-43866-14090-0
I0413 03:43:55.997467 14279 hierarchical_allocator_process.hpp:497] Framework 201304130343-1015726915-43866-14090-0000 filtered slave 201304130343-1015726915-43866-14090-0 for 5.00secs
I0413 03:43:55.997263 14281 exec.cpp:170] Executor started at: executor(27)@67.195.138.60:43866 with pid 14090
I0413 03:43:55.997269 14282 slave.cpp:436] Successfully attached file '/tmp/AllocatorZooKeeperTest_0_SlaveReregistersFirst_eYdL7u/slaves/201304130343-1015726915-43866-14090-0/frameworks/201304130343-1015726915-43866-14090-0000/executors/default/runs/c6101b3e-05cd-4ea6-861e-7e37f6da0ba0'
I0413 03:43:55.995182 14285 master.hpp:318] Removing offer with resources cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201304130343-1015726915-43866-14090-0
I0413 03:43:55.999106 14282 slave.cpp:1046] Got registration for executor 'default' of framework 201304130343-1015726915-43866-14090-0000
I0413 03:43:56.000192 14282 slave.cpp:1121] Flushing queued tasks for framework 201304130343-1015726915-43866-14090-0000
I0413 03:43:56.000218 14283 exec.cpp:194] Executor registered on slave 201304130343-1015726915-43866-14090-0
I0413 03:43:56.001173 14283 exec.cpp:258] Executor asked to run task '0'
I0413 03:43:56.001677 14283 exec.cpp:382] Executor sending status update for task 0 in state TASK_RUNNING
I0413 03:43:56.003312 14283 slave.cpp:1232] Handling status update TASK_RUNNING from task 0 of framework 201304130343-1015726915-43866-14090-0000
I0413 03:43:56.003346 14283 slave.cpp:1280] Forwarding status update TASK_RUNNING from task 0 of framework 201304130343-1015726915-43866-14090-0000 to the status update manager
I0413 03:43:56.003798 14283 status_update_manager.cpp:254] Received status update TASK_RUNNING from task 0 of framework 201304130343-1015726915-43866-14090-0000
I0413 03:43:56.004904 14283 status_update_manager.cpp:403] Creating StatusUpdate stream for task 0 of framework 201304130343-1015726915-43866-14090-0000
I0413 03:43:56.005323 14283 status_update_manager.hpp:314] Handling UPDATE for status update TASK_RUNNING from task 0 of framework 201304130343-1015726915-43866-14090-0000
I0413 03:43:56.007518 14283 status_update_manager.cpp:289] Forwarding status update TASK_RUNNING from task 0 of framework 201304130343-1015726915-43866-14090-0000 to the master at master@67.195.138.60:43866
I0413 03:43:56.008474 14284 master.cpp:1086] Status update from (796)@67.195.138.60:43866: task 0 of framework 201304130343-1015726915-43866-14090-0000 is now in state TASK_RUNNING
I0413 03:43:56.008482 14280 slave.cpp:1342] Sending ACK for status update TASK_RUNNING from task 0 of framework 201304130343-1015726915-43866-14090-0000 to executor executor(27)@67.195.138.60:43866
I0413 03:43:56.008882 14283 sched.cpp:327] Received status update TASK_RUNNING from task 0 of framework 201304130343-1015726915-43866-14090-0000 from slave(83)@67.195.138.60:43866
I0413 03:43:56.009348 14284 exec.cpp:289] Executor received ACK for status update of task 0 of framework 201304130343-1015726915-43866-14090-0000
I0413 03:43:56.009892 14283 sched.cpp:360] Sending ACK for status update TASK_RUNNING from task 0 of framework 201304130343-1015726915-43866-14090-0000 to slave(83)@67.195.138.60:43866
I0413 03:43:56.010159 14090 master.cpp:477] Master terminating
I0413 03:43:56.010925 14283 slave.cpp:979] Got acknowledgement of status update for task 0 of framework 201304130343-1015726915-43866-14090-0000
I0413 03:43:56.011988 14283 slave.cpp:1392] Process exited: @0.0.0.0:0
I0413 03:43:56.012018 14279 status_update_manager.cpp:314] Received status update acknowledgement for task 0 of framework 201304130343-1015726915-43866-14090-0000
I0413 03:43:56.012253 14285 master.cpp:309] Master started on 67.195.138.60:43866
I0413 03:43:56.073743 14285 master.cpp:324] Master ID: 201304130343-1015726915-43866-14090
I0413 03:43:56.074148 14281 detector.cpp:485] Master detector (slave(83)@67.195.138.60:43866) found 0 registered masters
W0413 03:43:56.012467 14283 slave.cpp:1395] WARNING! Master disconnected! Waiting for a new master to be elected.
I0413 03:43:56.073962 14286 detector.cpp:283] Master detector (master@67.195.138.60:43866) connected to ZooKeeper ...
I0413 03:43:56.076017 14286 detector.cpp:300] Trying to create path '/znode' in ZooKeeper
I0413 03:43:56.074306 14282 detector.cpp:485] Master detector (scheduler(75)@67.195.138.60:43866) found 0 registered masters
W0413 03:43:56.074336 14280 master.cpp:81] No whitelist given. Advertising offers for all slaves
I0413 03:43:56.074450 14284 hierarchical_allocator_process.hpp:236] Initializing hierarchical allocator process with master : master@67.195.138.60:43866
I0413 03:43:56.074640 14281 detector.cpp:506] Master detector (slave(83)@67.195.138.60:43866) couldn't find any masters
I0413 03:43:56.071900 14279 status_update_manager.hpp:314] Handling ACK for status update TASK_RUNNING from task 0 of framework 201304130343-1015726915-43866-14090-0000
I0413 03:43:56.168957 14286 detector.cpp:330] Created ephemeral/sequence znode at '/znode/0000000002'
I0413 03:43:56.168992 14282 detector.cpp:506] Master detector (scheduler(75)@67.195.138.60:43866) couldn't find any masters
I0413 03:43:56.303058 14285 slave.cpp:479] Lost master(s) ... waiting
I0413 03:43:56.303627 14281 detector.cpp:485] Master detector (slave(83)@67.195.138.60:43866) found 1 registered masters
I0413 03:43:56.380162 14280 sched.cpp:193] No master detected, waiting for another master
I0413 03:43:56.380460 14286 detector.cpp:485] Master detector (master@67.195.138.60:43866) found 1 registered masters
I0413 03:43:56.380565 14285 slave.cpp:1016] Status update manager successfully handled status update acknowledgement for task 0 of framework 201304130343-1015726915-43866-14090-0000
I0413 03:43:56.380724 14282 detector.cpp:485] Master detector (scheduler(75)@67.195.138.60:43866) found 1 registered masters
I0413 03:43:56.381572 14281 detector.cpp:531] Master detector (slave(83)@67.195.138.60:43866) got new master pid: master@67.195.138.60:43866
I0413 03:43:56.382460 14286 detector.cpp:531] Master detector (master@67.195.138.60:43866) got new master pid: master@67.195.138.60:43866
I0413 03:43:56.475528 14282 detector.cpp:531] Master detector (scheduler(75)@67.195.138.60:43866) got new master pid: master@67.195.138.60:43866
I0413 03:43:56.495154 14279 slave.cpp:453] New master detected at master@67.195.138.60:43866
I0413 03:43:56.498584 14286 master.cpp:603] Elected as master!
I0413 03:43:56.499037 14282 sched.cpp:182] New master at master@67.195.138.60:43866
I0413 03:43:56.516162 14279 status_update_manager.cpp:132] New master detected at master@67.195.138.60:43866
I0413 03:43:56.519122 14286 master.cpp:1029] Attempting to re-register slave 201304130343-1015726915-43866-14090-0 at slave(83)@67.195.138.60:43866 (janus.apache.org)
I0413 03:43:56.520470 14286 master.cpp:1224] Master now considering a slave at janus.apache.org:43866 as active
I0413 03:43:56.520946 14286 master.cpp:1862] Adding slave 201304130343-1015726915-43866-14090-0 at janus.apache.org with cpus=2; mem=1024; ports=[31000-32000]; disk=1024
I0413 03:43:56.521461 14281 slave.cpp:520] Re-registered with master
I0413 03:43:56.521517 14286 master.hpp:289] Adding task with resources cpus=1; mem=500 on slave 201304130343-1015726915-43866-14090-0
W0413 03:43:56.522400 14286 master.cpp:1948] Possibly orphaned task 0 of framework 201304130343-1015726915-43866-14090-0000 running on slave 201304130343-1015726915-43866-14090-0 (janus.apache.org)
I0413 03:43:56.523190 14281 hierarchical_allocator_process.hpp:395] Added slave 201304130343-1015726915-43866-14090-0 (janus.apache.org) with cpus=2; mem=1024; ports=[31000-32000]; disk=1024 (and cpus=1; mem=524; ports=[31000-32000]; disk=1024 available)
I0413 03:43:56.523788 14281 hierarchical_allocator_process.hpp:632] No users to allocate resources!
I0413 03:43:56.524260 14281 hierarchical_allocator_process.hpp:619] Performed allocation for slave 201304130343-1015726915-43866-14090-0 in 471.83us
I0413 03:43:56.585477 14285 hierarchical_allocator_process.hpp:660] Found available resources: cpus=1; mem=524; ports=[31000-32000]; disk=1024 on slave 201304130343-1015726915-43866-14090-0
I0413 03:43:56.585589 14285 hierarchical_allocator_process.hpp:756] Filtered cpus=1; mem=524; ports=[31000-32000]; disk=1024 on slave 201304130343-1015726915-43866-14090-0 for framework 201304130343-1015726915-43866-14090-0000
I0413 03:43:56.666113 14285 hierarchical_allocator_process.hpp:599] Performed allocation for 1 slaves in 80.66ms
I0413 03:43:56.844866 14286 master.cpp:681] Re-registering framework 201304130343-1015726915-43866-14090-0000 at scheduler(75)@67.195.138.60:43866
I0413 03:43:56.845178 14281 sched.cpp:217] Framework registered with 201304130343-1015726915-43866-14090-0000
I0413 03:43:56.845243 14286 slave.cpp:956] Updating framework 201304130343-1015726915-43866-14090-0000 pid to scheduler(75)@67.195.138.60:43866
I0413 03:43:56.845332 14284 hierarchical_allocator_process.hpp:268] Added framework 201304130343-1015726915-43866-14090-0000
I0413 03:43:56.852169 14284 hierarchical_allocator_process.hpp:660] Found available resources: cpus=1; mem=524; ports=[31000-32000]; disk=1024 on slave 201304130343-1015726915-43866-14090-0
I0413 03:43:56.852705 14284 hierarchical_allocator_process.hpp:686] Offering cpus=1; mem=524; ports=[31000-32000]; disk=1024 on slave 201304130343-1015726915-43866-14090-0 to framework 201304130343-1015726915-43866-14090-0000
I0413 03:43:56.853343 14284 hierarchical_allocator_process.hpp:599] Performed allocation for 1 slaves in 1.21ms
I0413 03:43:56.853432 14283 master.hpp:309] Adding offer with resources cpus=1; mem=524; ports=[31000-32000]; disk=1024 on slave 201304130343-1015726915-43866-14090-0
I0413 03:43:56.855125 14283 master.cpp:1327] Sending 1 offers to framework 201304130343-1015726915-43866-14090-0000
I0413 03:43:56.855859 14283 sched.cpp:282] Received 1 offers
I0413 03:43:56.857270 14280 sched.cpp:422] Stopping framework '201304130343-1015726915-43866-14090-0000'
I0413 03:43:56.857411 14281 master.cpp:774] Asked to unregister framework 201304130343-1015726915-43866-14090-0000
I0413 03:43:56.857987 14281 master.hpp:300] Removing task with resources cpus=1; mem=500 on slave 201304130343-1015726915-43866-14090-0
I0413 03:43:56.858060 14285 slave.cpp:889] Asked to shut down framework 201304130343-1015726915-43866-14090-0000 by master@67.195.138.60:43866
I0413 03:43:56.858084 14284 hierarchical_allocator_process.hpp:359] Deactivated framework 201304130343-1015726915-43866-14090-0000
I0413 03:43:56.858494 14281 master.hpp:318] Removing offer with resources cpus=1; mem=524; ports=[31000-32000]; disk=1024 on slave 201304130343-1015726915-43866-14090-0
I0413 03:43:56.955142 14285 slave.cpp:894] Shutting down framework 201304130343-1015726915-43866-14090-0000
I0413 03:43:56.956504 14285 slave.cpp:1681] Shutting down executor 'default' of framework 201304130343-1015726915-43866-14090-0000
I0413 03:43:56.957008 14286 exec.cpp:321] Executor asked to shutdown
I0413 03:43:56.957023 14285 slave.cpp:386] Slave terminating
I0413 03:43:56.957949 14285 slave.cpp:889] Asked to shut down framework 201304130343-1015726915-43866-14090-0000 by @0.0.0.0:0
I0413 03:43:56.958423 14285 slave.cpp:894] Shutting down framework 201304130343-1015726915-43866-14090-0000
I0413 03:43:56.958894 14285 slave.cpp:1681] Shutting down executor 'default' of framework 201304130343-1015726915-43866-14090-0000
I0413 03:43:56.955617 14284 hierarchical_allocator_process.hpp:544] Recovered cpus=1; mem=500 (total allocatable: cpus=1; mem=500; ports=[]; disk=0) on slave 201304130343-1015726915-43866-14090-0 from framework 201304130343-1015726915-43866-14090-0000
I0413 03:43:56.959982 14284 hierarchical_allocator_process.hpp:544] Recovered cpus=1; mem=524; ports=[31000-32000]; disk=1024 (total allocatable: cpus=2; mem=1024; ports=[31000-32000]; disk=1024) on slave 201304130343-1015726915-43866-14090-0 from framework 201304130343-1015726915-43866-14090-0000
I0413 03:43:56.959467 14279 master.cpp:537] Slave 201304130343-1015726915-43866-14090-0(janus.apache.org) disconnected
I0413 03:43:56.957042 14281 status_update_manager.cpp:233] Closing status update streams for framework 201304130343-1015726915-43866-14090-0000
I0413 03:43:57.079107 14279 master.cpp:542] Removing disconnected slave 201304130343-1015726915-43866-14090-0(janus.apache.org) because it is not checkpointing!
I0413 03:43:57.136837 14281 status_update_manager.cpp:434] Cleaning up status update stream for task 0 of framework 201304130343-1015726915-43866-14090-0000
I0413 03:43:57.137419 14090 master.cpp:477] Master terminating
I0413 03:43:57.239202 14281 status_update_manager.cpp:233] Closing status update streams for framework 201304130343-1015726915-43866-14090-0000
I0413 03:43:57.240082 14090 master.cpp:283] Shutting down master
I0413 03:43:57.241713 14090 master.cpp:283] Shutting down master
I0413 03:43:57.258272 14281 hierarchical_allocator_process.hpp:660] Found available resources: cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201304130343-1015726915-43866-14090-0
I0413 03:43:57.283614 14281 hierarchical_allocator_process.hpp:599] Performed allocation for 1 slaves in 25.37ms
I0413 03:43:57.283203 14090 master.hpp:300] Removing task with resources cpus=1; mem=500 on slave 201304130343-1015726915-43866-14090-0
I0413 03:43:57.283187 14284 hierarchical_allocator_process.hpp:359] Deactivated framework 201304130343-1015726915-43866-14090-0000
I0413 03:43:57.321043 14090 zookeeper_test_server.cpp:195] Shutdown ZooKeeperTestServer on port 56697
I0413 03:43:57.331166 14284 hierarchical_allocator_process.hpp:544] Recovered cpus=1; mem=500 (total allocatable: cpus=2; mem=1024; ports=[31000-32000]; disk=1024) on slave 201304130343-1015726915-43866-14090-0 from framework 201304130343-1015726915-43866-14090-0000
I0413 03:43:57.332315 14284 hierarchical_allocator_process.hpp:312] Removed framework 201304130343-1015726915-43866-14090-0000
[ OK ] AllocatorZooKeeperTest/0.SlaveReregistersFirst (1775 ms)
[----------] 2 tests from AllocatorZooKeeperTest/0 (3589 ms total)
[----------] Global test environment tear-down
[==========] 190 tests from 39 test cases ran. (120325 ms total)
[ PASSED ] 187 tests.
[ FAILED ] 3 tests, listed below:
[ FAILED ] FaultToleranceTest.SchedulerFailover
[ FAILED ] CoordinatorTest.MultipleAppendsNotLearnedFill
[ FAILED ] CoordinatorTest.TruncateNotLearnedFill
3 FAILED TESTS
YOU HAVE 1 DISABLED TEST
FAIL: mesos-tests
==================
1 of 1 test failed
==================
make[3]: *** [check-TESTS] Error 1
make[3]: Leaving directory `<https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/ws/src'>
make[2]: *** [check-am] Error 2
make[2]: Leaving directory `<https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/ws/src'>
make[1]: *** [check] Error 2
make[1]: Leaving directory `<https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/ws/src'>
make: *** [check-recursive] Error 1
Build step 'Execute shell' marked build as failure
Jenkins build is back to normal :
Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME #306
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/306/changes>
Build failed in Jenkins:
Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME #305
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/305/changes>
Changes:
[bmahler] Fixed tests to use new Clock::advance() and Clock::update() functions
that take a Duration.
From: Jiang Yan Xu <ya...@jxu.me>
Review: https://reviews.apache.org/r/10442
[bmahler] Changed Clock::advance() and Clock::update() to use Duration.
From: Jiang Yan Xu <ya...@jxu.me>
Review: https://reviews.apache.org/r/10421
[bmahler] Implemented Duration arithmetic operators +, -, +=, -=.
From: Jiang Yan Xu <ya...@jxu.me>
Review: https://reviews.apache.org/r/10422
------------------------------------------
[...truncated 15867 lines...]
I0416 15:07:51.474792 8632 detector.cpp:531] Master detector (master@67.195.138.60:58457) got new master pid: master@67.195.138.60:58457
W0416 15:07:51.474803 8633 master.cpp:668] Ignoring re-register framework message since not elected yet
I0416 15:07:51.476721 8633 master.cpp:603] Elected as master!
I0416 15:07:52.326354 8630 hierarchical_allocator_process.hpp:660] Found available resources: cpus=1; mem=524; ports=[31000-32000]; disk=1024 on slave 201304161507-1015726915-58457-8569-0
I0416 15:07:52.326458 8630 hierarchical_allocator_process.hpp:756] Filtered cpus=1; mem=524; ports=[31000-32000]; disk=1024 on slave 201304161507-1015726915-58457-8569-0 for framework 201304161507-1015726915-58457-8569-0000
I0416 15:07:52.329959 8630 hierarchical_allocator_process.hpp:599] Performed allocation for 1 slaves in 3.626482000000000ms
I0416 15:07:52.425475 8626 hierarchical_allocator_process.hpp:632] No users to allocate resources!
I0416 15:07:52.425515 8626 hierarchical_allocator_process.hpp:599] Performed allocation for 0 slaves in 44.947000000000003us
I0416 15:07:52.475683 8631 master.cpp:681] Re-registering framework 201304161507-1015726915-58457-8569-0000 at scheduler(74)@67.195.138.60:58457
I0416 15:07:52.475926 8632 sched.cpp:217] Framework registered with 201304161507-1015726915-58457-8569-0000
I0416 15:07:52.476019 8630 hierarchical_allocator_process.hpp:268] Added framework 201304161507-1015726915-58457-8569-0000
I0416 15:07:52.498662 8630 hierarchical_allocator_process.hpp:668] No resources available to allocate!
I0416 15:07:52.499115 8630 hierarchical_allocator_process.hpp:599] Performed allocation for 0 slaves in 453.276000000000010us
I0416 15:07:53.331588 8626 hierarchical_allocator_process.hpp:660] Found available resources: cpus=1; mem=524; ports=[31000-32000]; disk=1024 on slave 201304161507-1015726915-58457-8569-0
I0416 15:07:53.331725 8626 hierarchical_allocator_process.hpp:756] Filtered cpus=1; mem=524; ports=[31000-32000]; disk=1024 on slave 201304161507-1015726915-58457-8569-0 for framework 201304161507-1015726915-58457-8569-0000
I0416 15:07:53.332020 8626 hierarchical_allocator_process.hpp:599] Performed allocation for 1 slaves in 492.640000000000043us
I0416 15:07:53.385776 8627 master.cpp:1029] Attempting to re-register slave 201304161507-1015726915-58457-8569-0 at slave(82)@67.195.138.60:58457 (janus.apache.org)
I0416 15:07:53.385890 8627 master.cpp:1224] Master now considering a slave at janus.apache.org:58457 as active
I0416 15:07:53.386237 8627 master.cpp:1862] Adding slave 201304161507-1015726915-58457-8569-0 at janus.apache.org with cpus=2; mem=1024; ports=[31000-32000]; disk=1024
I0416 15:07:53.386718 8634 slave.cpp:520] Re-registered with master
I0416 15:07:53.386849 8627 master.hpp:289] Adding task with resources cpus=1; mem=500 on slave 201304161507-1015726915-58457-8569-0
I0416 15:07:53.387732 8628 slave.cpp:956] Updating framework 201304161507-1015726915-58457-8569-0000 pid to scheduler(74)@67.195.138.60:58457
I0416 15:07:53.387830 8633 hierarchical_allocator_process.hpp:395] Added slave 201304161507-1015726915-58457-8569-0 (janus.apache.org) with cpus=2; mem=1024; ports=[31000-32000]; disk=1024 (and cpus=1; mem=524; ports=[31000-32000]; disk=1024 available)
I0416 15:07:53.388581 8633 hierarchical_allocator_process.hpp:660] Found available resources: cpus=1; mem=524; ports=[31000-32000]; disk=1024 on slave 201304161507-1015726915-58457-8569-0
I0416 15:07:53.389065 8633 hierarchical_allocator_process.hpp:686] Offering cpus=1; mem=524; ports=[31000-32000]; disk=1024 on slave 201304161507-1015726915-58457-8569-0 to framework 201304161507-1015726915-58457-8569-0000
I0416 15:07:53.389628 8633 hierarchical_allocator_process.hpp:619] Performed allocation for slave 201304161507-1015726915-58457-8569-0 in 1.064704000000000ms
I0416 15:07:53.389703 8630 master.hpp:309] Adding offer with resources cpus=1; mem=524; ports=[31000-32000]; disk=1024 on slave 201304161507-1015726915-58457-8569-0
I0416 15:07:53.390550 8630 master.cpp:1327] Sending 1 offers to framework 201304161507-1015726915-58457-8569-0000
I0416 15:07:53.391055 8634 sched.cpp:282] Received 1 offers
I0416 15:07:53.391790 8626 sched.cpp:422] Stopping framework '201304161507-1015726915-58457-8569-0000'
I0416 15:07:53.391973 8631 master.cpp:774] Asked to unregister framework 201304161507-1015726915-58457-8569-0000
I0416 15:07:53.392457 8632 slave.cpp:889] Asked to shut down framework 201304161507-1015726915-58457-8569-0000 by master@67.195.138.60:58457
I0416 15:07:53.392886 8632 slave.cpp:894] Shutting down framework 201304161507-1015726915-58457-8569-0000
I0416 15:07:53.393343 8632 slave.cpp:1681] Shutting down executor 'default' of framework 201304161507-1015726915-58457-8569-0000
I0416 15:07:53.392468 8634 hierarchical_allocator_process.hpp:359] Deactivated framework 201304161507-1015726915-58457-8569-0000
I0416 15:07:53.392478 8631 master.hpp:300] Removing task with resources cpus=1; mem=500 on slave 201304161507-1015726915-58457-8569-0
I0416 15:07:53.395613 8626 exec.cpp:321] Executor asked to shutdown
I0416 15:07:53.395618 8632 status_update_manager.cpp:233] Closing status update streams for framework 201304161507-1015726915-58457-8569-0000
I0416 15:07:53.397485 8632 status_update_manager.cpp:434] Cleaning up status update stream for task 0 of framework 201304161507-1015726915-58457-8569-0000
I0416 15:07:53.396677 8627 hierarchical_allocator_process.hpp:544] Recovered cpus=1; mem=500 (total allocatable: cpus=1; mem=500; ports=[]; disk=0) on slave 201304161507-1015726915-58457-8569-0 from framework 201304161507-1015726915-58457-8569-0000
I0416 15:07:53.398533 8627 hierarchical_allocator_process.hpp:544] Recovered cpus=1; mem=524; ports=[31000-32000]; disk=1024 (total allocatable: cpus=2; mem=1024; ports=[31000-32000]; disk=1024) on slave 201304161507-1015726915-58457-8569-0 from framework 201304161507-1015726915-58457-8569-0000
I0416 15:07:53.396597 8631 master.hpp:318] Removing offer with resources cpus=1; mem=524; ports=[31000-32000]; disk=1024 on slave 201304161507-1015726915-58457-8569-0
I0416 15:07:53.399580 8569 slave.cpp:386] Slave terminating
I0416 15:07:53.399878 8569 slave.cpp:889] Asked to shut down framework 201304161507-1015726915-58457-8569-0000 by @0.0.0.0:0
I0416 15:07:53.400377 8569 slave.cpp:894] Shutting down framework 201304161507-1015726915-58457-8569-0000
I0416 15:07:53.400848 8569 slave.cpp:1681] Shutting down executor 'default' of framework 201304161507-1015726915-58457-8569-0000
I0416 15:07:53.401351 8628 status_update_manager.cpp:233] Closing status update streams for framework 201304161507-1015726915-58457-8569-0000
I0416 15:07:53.401372 8630 master.cpp:537] Slave 201304161507-1015726915-58457-8569-0(janus.apache.org) disconnected
I0416 15:07:53.402274 8630 master.cpp:542] Removing disconnected slave 201304161507-1015726915-58457-8569-0(janus.apache.org) because it is not checkpointing!
I0416 15:07:53.402865 8628 master.cpp:477] Master terminating
I0416 15:07:53.403647 8569 master.cpp:283] Shutting down master
I0416 15:07:53.404203 8569 master.cpp:283] Shutting down master
I0416 15:07:53.404289 8630 hierarchical_allocator_process.hpp:359] Deactivated framework 201304161507-1015726915-58457-8569-0000
I0416 15:07:53.404289 8569 master.hpp:300] Removing task with resources cpus=1; mem=500 on slave 201304161507-1015726915-58457-8569-0
I0416 15:07:53.406000 8633 hierarchical_allocator_process.hpp:544] Recovered cpus=1; mem=500 (total allocatable: cpus=2; mem=1024; ports=[31000-32000]; disk=1024) on slave 201304161507-1015726915-58457-8569-0 from framework 201304161507-1015726915-58457-8569-0000
I0416 15:07:53.406471 8633 hierarchical_allocator_process.hpp:312] Removed framework 201304161507-1015726915-58457-8569-0000
I0416 15:07:53.406905 8633 hierarchical_allocator_process.hpp:423] Removed slave 201304161507-1015726915-58457-8569-0
I0416 15:07:53.414137 8569 zookeeper_test_server.cpp:195] Shutdown ZooKeeperTestServer on port 36066
[ OK ] AllocatorZooKeeperTest/0.FrameworkReregistersFirst (3127 ms)
[ RUN ] AllocatorZooKeeperTest/0.SlaveReregistersFirst
I0416 15:07:53.439216 8569 jvm.cpp:34] looking up method <init>(Ljava/lang/String;)V
I0416 15:07:53.439287 8569 jvm.cpp:34] looking up method <init>(I)V
I0416 15:07:53.439780 8569 jvm.cpp:34] looking up method <init>(Ljava/net/InetSocketAddress;)V
I0416 15:07:53.440268 8569 jvm.cpp:34] looking up method startup(Lorg/apache/zookeeper/server/ZooKeeperServer;)V
I0416 15:07:53.440795 8569 jvm.cpp:34] looking up method isAlive()Z
I0416 15:07:53.441355 8569 jvm.cpp:34] looking up method shutdown()V
I0416 15:07:53.444331 8569 jvm.cpp:34] looking up method <init>(Ljava/io/File;Ljava/io/File;)V
I0416 15:07:53.444963 8569 jvm.cpp:34] looking up method <init>()V
I0416 15:07:53.445045 8569 jvm.cpp:34] looking up method <init>(Lorg/apache/zookeeper/server/persistence/FileTxnSnapLog;Lorg/apache/zookeeper/server/ZooKeeperServer$DataTreeBuilder;)V
I0416 15:07:53.445504 8569 jvm.cpp:34] looking up method getClientPort()I
I0416 15:07:53.445834 8569 jvm.cpp:34] looking up method closeSession(J)V
I0416 15:07:53.448143 8569 zookeeper_test_server.cpp:212] Started ZooKeeperTestServer on port 41684
I0416 15:07:53.448415 8630 master.cpp:309] Master started on 67.195.138.60:58457
I0416 15:07:53.448886 8631 slave.cpp:203] Slave started on 83)@67.195.138.60:58457
I0416 15:07:53.449059 8630 master.cpp:324] Master ID: 201304161507-1015726915-58457-8569
I0416 15:07:53.449498 8631 slave.cpp:204] Slave resources: cpus=2; mem=1024; ports=[31000-32000]; disk=1024
W0416 15:07:53.450187 8634 master.cpp:81] No whitelist given. Advertising offers for all slaves
I0416 15:07:53.450212 8628 hierarchical_allocator_process.hpp:236] Initializing hierarchical allocator process with master : master@67.195.138.60:58457
I0416 15:07:53.451098 8631 slave.cpp:377] Finished recovery
I0416 15:07:53.504499 8632 detector.cpp:283] Master detector (master@67.195.138.60:58457) connected to ZooKeeper ...
I0416 15:07:53.504546 8632 detector.cpp:300] Trying to create path '/znode' in ZooKeeper
I0416 15:07:53.504884 8627 detector.cpp:283] Master detector (slave(83)@67.195.138.60:58457) connected to ZooKeeper ...
I0416 15:07:53.529904 8627 detector.cpp:300] Trying to create path '/znode' in ZooKeeper
I0416 15:07:53.529961 8630 detector.cpp:283] Master detector (scheduler(75)@67.195.138.60:58457) connected to ZooKeeper ...
I0416 15:07:53.545517 8630 detector.cpp:300] Trying to create path '/znode' in ZooKeeper
I0416 15:07:53.578740 8632 detector.cpp:330] Created ephemeral/sequence znode at '/znode/0000000000'
I0416 15:07:53.579087 8627 detector.cpp:485] Master detector (slave(83)@67.195.138.60:58457) found 1 registered masters
I0416 15:07:53.596590 8632 detector.cpp:485] Master detector (master@67.195.138.60:58457) found 1 registered masters
I0416 15:07:53.596887 8627 detector.cpp:531] Master detector (slave(83)@67.195.138.60:58457) got new master pid: master@67.195.138.60:58457
I0416 15:07:53.597054 8627 slave.cpp:453] New master detected at master@67.195.138.60:58457
I0416 15:07:53.597208 8630 detector.cpp:485] Master detector (scheduler(75)@67.195.138.60:58457) found 1 registered masters
I0416 15:07:53.597357 8632 detector.cpp:531] Master detector (master@67.195.138.60:58457) got new master pid: master@67.195.138.60:58457
I0416 15:07:53.598471 8630 detector.cpp:531] Master detector (scheduler(75)@67.195.138.60:58457) got new master pid: master@67.195.138.60:58457
W0416 15:07:53.597642 8626 master.cpp:949] Ignoring register slave message from janus.apache.org since not elected yet
I0416 15:07:53.597527 8631 status_update_manager.cpp:132] New master detected at master@67.195.138.60:58457
I0416 15:07:53.599015 8630 sched.cpp:182] New master at master@67.195.138.60:58457
I0416 15:07:53.599555 8626 master.cpp:603] Elected as master!
I0416 15:07:53.601411 8626 master.cpp:646] Registering framework 201304161507-1015726915-58457-8569-0000 at scheduler(75)@67.195.138.60:58457
I0416 15:07:53.601829 8634 sched.cpp:217] Framework registered with 201304161507-1015726915-58457-8569-0000
I0416 15:07:53.601856 8632 hierarchical_allocator_process.hpp:268] Added framework 201304161507-1015726915-58457-8569-0000
I0416 15:07:53.602799 8632 hierarchical_allocator_process.hpp:668] No resources available to allocate!
I0416 15:07:53.603272 8632 hierarchical_allocator_process.hpp:599] Performed allocation for 0 slaves in 473.867000000000075us
I0416 15:07:54.493096 8626 hierarchical_allocator_process.hpp:668] No resources available to allocate!
I0416 15:07:54.556881 8626 hierarchical_allocator_process.hpp:599] Performed allocation for 0 slaves in 63.801762999999994ms
I0416 15:07:54.598289 8630 master.cpp:968] Attempting to register slave on janus.apache.org at slave(83)@67.195.138.60:58457
I0416 15:07:54.598331 8630 master.cpp:1224] Master now considering a slave at janus.apache.org:58457 as active
I0416 15:07:54.598705 8630 master.cpp:1862] Adding slave 201304161507-1015726915-58457-8569-0 at janus.apache.org with cpus=2; mem=1024; ports=[31000-32000]; disk=1024
I0416 15:07:54.599174 8634 slave.cpp:487] Registered with master; given slave ID 201304161507-1015726915-58457-8569-0
I0416 15:07:54.599292 8626 hierarchical_allocator_process.hpp:395] Added slave 201304161507-1015726915-58457-8569-0 (janus.apache.org) with cpus=2; mem=1024; ports=[31000-32000]; disk=1024 (and cpus=2; mem=1024; ports=[31000-32000]; disk=1024 available)
I0416 15:07:54.600106 8626 hierarchical_allocator_process.hpp:660] Found available resources: cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201304161507-1015726915-58457-8569-0
I0416 15:07:54.600568 8626 hierarchical_allocator_process.hpp:686] Offering cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201304161507-1015726915-58457-8569-0 to framework 201304161507-1015726915-58457-8569-0000
I0416 15:07:54.601125 8626 hierarchical_allocator_process.hpp:619] Performed allocation for slave 201304161507-1015726915-58457-8569-0 in 1.036736000000000ms
I0416 15:07:54.601227 8634 master.hpp:309] Adding offer with resources cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201304161507-1015726915-58457-8569-0
I0416 15:07:54.602030 8634 master.cpp:1327] Sending 1 offers to framework 201304161507-1015726915-58457-8569-0000
I0416 15:07:54.602526 8630 sched.cpp:282] Received 1 offers
I0416 15:07:54.603209 8630 master.cpp:1534] Processing reply for offer 201304161507-1015726915-58457-8569-0 on slave 201304161507-1015726915-58457-8569-0 (janus.apache.org) for framework 201304161507-1015726915-58457-8569-0000
I0416 15:07:54.603525 8630 master.hpp:289] Adding task with resources cpus=1; mem=500 on slave 201304161507-1015726915-58457-8569-0
I0416 15:07:54.603934 8630 master.cpp:1651] Launching task 0 of framework 201304161507-1015726915-58457-8569-0000 with resources cpus=1; mem=500 on slave 201304161507-1015726915-58457-8569-0 (janus.apache.org)
I0416 15:07:54.604450 8634 slave.cpp:587] Got assigned task 0 for framework 201304161507-1015726915-58457-8569-0000
I0416 15:07:54.604521 8633 hierarchical_allocator_process.hpp:471] Framework 201304161507-1015726915-58457-8569-0000 left cpus=1; mem=524; ports=[31000-32000]; disk=1024 unused on slave 201304161507-1015726915-58457-8569-0
I0416 15:07:54.605483 8633 hierarchical_allocator_process.hpp:497] Framework 201304161507-1015726915-58457-8569-0000 filtered slave 201304161507-1015726915-58457-8569-0 for 5.000000000000000secs
I0416 15:07:54.604522 8630 master.hpp:318] Removing offer with resources cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201304161507-1015726915-58457-8569-0
I0416 15:07:54.606739 8634 paths.hpp:302] Created executor directory '/tmp/AllocatorZooKeeperTest_0_SlaveReregistersFirst_bOONm3/slaves/201304161507-1015726915-58457-8569-0/frameworks/201304161507-1015726915-58457-8569-0000/executors/default/runs/13ce3317-af22-44b9-b3eb-68266ff4930a'
I0416 15:07:54.607063 8626 slave.cpp:436] Successfully attached file '/tmp/AllocatorZooKeeperTest_0_SlaveReregistersFirst_bOONm3/slaves/201304161507-1015726915-58457-8569-0/frameworks/201304161507-1015726915-58457-8569-0000/executors/default/runs/13ce3317-af22-44b9-b3eb-68266ff4930a'
I0416 15:07:54.607121 8630 exec.cpp:170] Executor started at: executor(27)@67.195.138.60:58457 with pid 8569
I0416 15:07:54.608551 8630 slave.cpp:1046] Got registration for executor 'default' of framework 201304161507-1015726915-58457-8569-0000
I0416 15:07:54.609037 8630 slave.cpp:1121] Flushing queued tasks for framework 201304161507-1015726915-58457-8569-0000
I0416 15:07:54.609086 8627 exec.cpp:194] Executor registered on slave 201304161507-1015726915-58457-8569-0
I0416 15:07:54.609988 8627 exec.cpp:258] Executor asked to run task '0'
I0416 15:07:54.610456 8627 exec.cpp:382] Executor sending status update for task 0 in state TASK_RUNNING
I0416 15:07:54.612329 8627 slave.cpp:1232] Handling status update TASK_RUNNING from task 0 of framework 201304161507-1015726915-58457-8569-0000
I0416 15:07:54.612370 8627 slave.cpp:1280] Forwarding status update TASK_RUNNING from task 0 of framework 201304161507-1015726915-58457-8569-0000 to the status update manager
I0416 15:07:54.612833 8627 status_update_manager.cpp:254] Received status update TASK_RUNNING from task 0 of framework 201304161507-1015726915-58457-8569-0000
I0416 15:07:54.613230 8627 status_update_manager.cpp:403] Creating StatusUpdate stream for task 0 of framework 201304161507-1015726915-58457-8569-0000
I0416 15:07:54.613716 8627 status_update_manager.hpp:314] Handling UPDATE for status update TASK_RUNNING from task 0 of framework 201304161507-1015726915-58457-8569-0000
I0416 15:07:54.614192 8627 status_update_manager.cpp:289] Forwarding status update TASK_RUNNING from task 0 of framework 201304161507-1015726915-58457-8569-0000 to the master at master@67.195.138.60:58457
I0416 15:07:54.614784 8634 master.cpp:1086] Status update from (824)@67.195.138.60:58457: task 0 of framework 201304161507-1015726915-58457-8569-0000 is now in state TASK_RUNNING
I0416 15:07:54.614799 8631 slave.cpp:1342] Sending ACK for status update TASK_RUNNING from task 0 of framework 201304161507-1015726915-58457-8569-0000 to executor executor(27)@67.195.138.60:58457
I0416 15:07:54.615677 8631 exec.cpp:289] Executor received ACK for status update of task 0 of framework 201304161507-1015726915-58457-8569-0000
I0416 15:07:54.615207 8634 sched.cpp:327] Received status update TASK_RUNNING from task 0 of framework 201304161507-1015726915-58457-8569-0000 from slave(83)@67.195.138.60:58457
I0416 15:07:54.616652 8634 sched.cpp:360] Sending ACK for status update TASK_RUNNING from task 0 of framework 201304161507-1015726915-58457-8569-0000 to slave(83)@67.195.138.60:58457
I0416 15:07:54.616945 8569 master.cpp:477] Master terminating
I0416 15:07:54.617157 8634 slave.cpp:979] Got acknowledgement of status update for task 0 of framework 201304161507-1015726915-58457-8569-0000
I0416 15:07:54.618315 8634 slave.cpp:1392] Process exited: @0.0.0.0:0
I0416 15:07:54.618450 8631 status_update_manager.cpp:314] Received status update acknowledgement for task 0 of framework 201304161507-1015726915-58457-8569-0000
I0416 15:07:54.618650 8632 master.cpp:309] Master started on 67.195.138.60:58457
W0416 15:07:54.619140 8634 slave.cpp:1395] WARNING! Master disconnected! Waiting for a new master to be elected.
I0416 15:07:54.646049 8631 status_update_manager.hpp:314] Handling ACK for status update TASK_RUNNING from task 0 of framework 201304161507-1015726915-58457-8569-0000
I0416 15:07:54.646566 8632 master.cpp:324] Master ID: 201304161507-1015726915-58457-8569
I0416 15:07:54.670086 8631 slave.cpp:1016] Status update manager successfully handled status update acknowledgement for task 0 of framework 201304161507-1015726915-58457-8569-0000
I0416 15:07:54.670256 8626 detector.cpp:283] Master detector (master@67.195.138.60:58457) connected to ZooKeeper ...
I0416 15:07:54.670588 8627 detector.cpp:485] Master detector (scheduler(75)@67.195.138.60:58457) found 0 registered masters
W0416 15:07:54.670784 8630 master.cpp:81] No whitelist given. Advertising offers for all slaves
I0416 15:07:54.670817 8633 hierarchical_allocator_process.hpp:236] Initializing hierarchical allocator process with master : master@67.195.138.60:58457
I0416 15:07:54.670845 8628 detector.cpp:485] Master detector (slave(83)@67.195.138.60:58457) found 0 registered masters
I0416 15:07:54.671452 8626 detector.cpp:300] Trying to create path '/znode' in ZooKeeper
I0416 15:07:54.671926 8627 detector.cpp:506] Master detector (scheduler(75)@67.195.138.60:58457) couldn't find any masters
I0416 15:07:54.674792 8627 sched.cpp:193] No master detected, waiting for another master
I0416 15:07:54.673813 8628 detector.cpp:506] Master detector (slave(83)@67.195.138.60:58457) couldn't find any masters
I0416 15:07:54.676183 8634 slave.cpp:479] Lost master(s) ... waiting
I0416 15:07:54.720202 8626 detector.cpp:330] Created ephemeral/sequence znode at '/znode/0000000002'
I0416 15:07:54.720566 8630 detector.cpp:485] Master detector (scheduler(75)@67.195.138.60:58457) found 1 registered masters
I0416 15:07:54.720790 8628 detector.cpp:485] Master detector (slave(83)@67.195.138.60:58457) found 1 registered masters
I0416 15:07:54.721143 8626 detector.cpp:485] Master detector (master@67.195.138.60:58457) found 1 registered masters
I0416 15:07:54.721251 8630 detector.cpp:531] Master detector (scheduler(75)@67.195.138.60:58457) got new master pid: master@67.195.138.60:58457
I0416 15:07:54.722090 8630 sched.cpp:182] New master at master@67.195.138.60:58457
I0416 15:07:54.721616 8628 detector.cpp:531] Master detector (slave(83)@67.195.138.60:58457) got new master pid: master@67.195.138.60:58457
I0416 15:07:54.722962 8628 slave.cpp:453] New master detected at master@67.195.138.60:58457
I0416 15:07:54.722151 8626 detector.cpp:531] Master detector (master@67.195.138.60:58457) got new master pid: master@67.195.138.60:58457
I0416 15:07:54.723546 8628 status_update_manager.cpp:132] New master detected at master@67.195.138.60:58457
W0416 15:07:54.723645 8630 master.cpp:996] Ignoring re-register slave message from janus.apache.org since not elected yet
I0416 15:07:54.724928 8630 master.cpp:603] Elected as master!
I0416 15:07:55.558383 8633 hierarchical_allocator_process.hpp:660] Found available resources: cpus=1; mem=524; ports=[31000-32000]; disk=1024 on slave 201304161507-1015726915-58457-8569-0
I0416 15:07:55.581393 8633 hierarchical_allocator_process.hpp:756] Filtered cpus=1; mem=524; ports=[31000-32000]; disk=1024 on slave 201304161507-1015726915-58457-8569-0 for framework 201304161507-1015726915-58457-8569-0000
I0416 15:07:55.581715 8633 hierarchical_allocator_process.hpp:599] Performed allocation for 1 slaves in 23.355994000000003ms
I0416 15:07:55.598505 8630 master.cpp:1029] Attempting to re-register slave 201304161507-1015726915-58457-8569-0 at slave(83)@67.195.138.60:58457 (janus.apache.org)
I0416 15:07:55.598539 8630 master.cpp:1224] Master now considering a slave at janus.apache.org:58457 as active
I0416 15:07:55.598896 8630 master.cpp:1862] Adding slave 201304161507-1015726915-58457-8569-0 at janus.apache.org with cpus=2; mem=1024; ports=[31000-32000]; disk=1024
I0416 15:07:55.599387 8632 slave.cpp:520] Re-registered with master
I0416 15:07:55.599398 8630 master.hpp:289] Adding task with resources cpus=1; mem=500 on slave 201304161507-1015726915-58457-8569-0
W0416 15:07:55.600390 8630 master.cpp:1948] Possibly orphaned task 0 of framework 201304161507-1015726915-58457-8569-0000 running on slave 201304161507-1015726915-58457-8569-0 (janus.apache.org)
I0416 15:07:55.601148 8633 hierarchical_allocator_process.hpp:395] Added slave 201304161507-1015726915-58457-8569-0 (janus.apache.org) with cpus=2; mem=1024; ports=[31000-32000]; disk=1024 (and cpus=1; mem=524; ports=[31000-32000]; disk=1024 available)
I0416 15:07:55.601892 8633 hierarchical_allocator_process.hpp:632] No users to allocate resources!
I0416 15:07:55.602424 8633 hierarchical_allocator_process.hpp:619] Performed allocation for slave 201304161507-1015726915-58457-8569-0 in 532.544000000000096us
I0416 15:07:55.673511 8632 hierarchical_allocator_process.hpp:632] No users to allocate resources!
I0416 15:07:55.673557 8632 hierarchical_allocator_process.hpp:599] Performed allocation for 1 slaves in 51.991000000000007us
I0416 15:07:55.722609 8627 master.cpp:681] Re-registering framework 201304161507-1015726915-58457-8569-0000 at scheduler(75)@67.195.138.60:58457
I0416 15:07:55.722877 8630 sched.cpp:217] Framework registered with 201304161507-1015726915-58457-8569-0000
I0416 15:07:55.722988 8631 hierarchical_allocator_process.hpp:268] Added framework 201304161507-1015726915-58457-8569-0000
I0416 15:07:55.723441 8631 hierarchical_allocator_process.hpp:660] Found available resources: cpus=1; mem=524; ports=[31000-32000]; disk=1024 on slave 201304161507-1015726915-58457-8569-0
I0416 15:07:55.723916 8631 hierarchical_allocator_process.hpp:686] Offering cpus=1; mem=524; ports=[31000-32000]; disk=1024 on slave 201304161507-1015726915-58457-8569-0 to framework 201304161507-1015726915-58457-8569-0000
I0416 15:07:55.724479 8631 hierarchical_allocator_process.hpp:599] Performed allocation for 1 slaves in 1.048925000000000ms
I0416 15:07:55.722913 8627 slave.cpp:956] Updating framework 201304161507-1015726915-58457-8569-0000 pid to scheduler(75)@67.195.138.60:58457
I0416 15:07:55.724570 8630 master.hpp:309] Adding offer with resources cpus=1; mem=524; ports=[31000-32000]; disk=1024 on slave 201304161507-1015726915-58457-8569-0
I0416 15:07:55.725857 8630 master.cpp:1327] Sending 1 offers to framework 201304161507-1015726915-58457-8569-0000
I0416 15:07:55.726373 8628 sched.cpp:282] Received 1 offers
I0416 15:07:55.727169 8633 sched.cpp:422] Stopping framework '201304161507-1015726915-58457-8569-0000'
I0416 15:07:55.727344 8626 master.cpp:774] Asked to unregister framework 201304161507-1015726915-58457-8569-0000
I0416 15:07:55.727821 8626 master.hpp:300] Removing task with resources cpus=1; mem=500 on slave 201304161507-1015726915-58457-8569-0
I0416 15:07:55.728428 8626 master.hpp:318] Removing offer with resources cpus=1; mem=524; ports=[31000-32000]; disk=1024 on slave 201304161507-1015726915-58457-8569-0
I0416 15:07:55.727923 8634 hierarchical_allocator_process.hpp:359] Deactivated framework 201304161507-1015726915-58457-8569-0000
I0416 15:07:55.727903 8627 slave.cpp:889] Asked to shut down framework 201304161507-1015726915-58457-8569-0000 by master@67.195.138.60:58457
I0416 15:07:55.745939 8627 slave.cpp:894] Shutting down framework 201304161507-1015726915-58457-8569-0000
I0416 15:07:55.746413 8627 slave.cpp:1681] Shutting down executor 'default' of framework 201304161507-1015726915-58457-8569-0000
I0416 15:07:55.746912 8627 slave.cpp:386] Slave terminating
I0416 15:07:55.747387 8627 slave.cpp:889] Asked to shut down framework 201304161507-1015726915-58457-8569-0000 by @0.0.0.0:0
I0416 15:07:55.747863 8627 slave.cpp:894] Shutting down framework 201304161507-1015726915-58457-8569-0000
I0416 15:07:55.748339 8627 slave.cpp:1681] Shutting down executor 'default' of framework 201304161507-1015726915-58457-8569-0000
I0416 15:07:55.745550 8634 hierarchical_allocator_process.hpp:544] Recovered cpus=1; mem=500 (total allocatable: cpus=1; mem=500; ports=[]; disk=0) on slave 201304161507-1015726915-58457-8569-0 from framework 201304161507-1015726915-58457-8569-0000
I0416 15:07:55.749387 8634 hierarchical_allocator_process.hpp:544] Recovered cpus=1; mem=524; ports=[31000-32000]; disk=1024 (total allocatable: cpus=2; mem=1024; ports=[31000-32000]; disk=1024) on slave 201304161507-1015726915-58457-8569-0 from framework 201304161507-1015726915-58457-8569-0000
I0416 15:07:55.746976 8626 status_update_manager.cpp:233] Closing status update streams for framework 201304161507-1015726915-58457-8569-0000
I0416 15:07:55.750255 8626 status_update_manager.cpp:434] Cleaning up status update stream for task 0 of framework 201304161507-1015726915-58457-8569-0000
I0416 15:07:55.750736 8626 status_update_manager.cpp:233] Closing status update streams for framework 201304161507-1015726915-58457-8569-0000
I0416 15:07:55.748853 8631 master.cpp:537] Slave 201304161507-1015726915-58457-8569-0(janus.apache.org) disconnected
I0416 15:07:55.752130 8631 master.cpp:542] Removing disconnected slave 201304161507-1015726915-58457-8569-0(janus.apache.org) because it is not checkpointing!
I0416 15:07:55.746965 8633 exec.cpp:321] Executor asked to shutdown
I0416 15:07:55.770635 8569 master.cpp:477] Master terminating
I0416 15:07:55.774967 8569 master.cpp:283] Shutting down master
I0416 15:07:55.778825 8569 master.cpp:283] Shutting down master
I0416 15:07:55.778923 8626 hierarchical_allocator_process.hpp:359] Deactivated framework 201304161507-1015726915-58457-8569-0000
I0416 15:07:55.778944 8569 master.hpp:300] Removing task with resources cpus=1; mem=500 on slave 201304161507-1015726915-58457-8569-0
I0416 15:07:55.796077 8633 hierarchical_allocator_process.hpp:544] Recovered cpus=1; mem=500 (total allocatable: cpus=2; mem=1024; ports=[31000-32000]; disk=1024) on slave 201304161507-1015726915-58457-8569-0 from framework 201304161507-1015726915-58457-8569-0000
I0416 15:07:55.796474 8633 hierarchical_allocator_process.hpp:312] Removed framework 201304161507-1015726915-58457-8569-0000
I0416 15:07:55.796918 8633 hierarchical_allocator_process.hpp:423] Removed slave 201304161507-1015726915-58457-8569-0
I0416 15:07:55.797358 8569 zookeeper_test_server.cpp:195] Shutdown ZooKeeperTestServer on port 41684
[ OK ] AllocatorZooKeeperTest/0.SlaveReregistersFirst (2383 ms)
[----------] 2 tests from AllocatorZooKeeperTest/0 (5510 ms total)
[----------] Global test environment tear-down
[==========] 190 tests from 39 test cases ran. (98534 ms total)
[ PASSED ] 189 tests.
[ FAILED ] 1 test, listed below:
[ FAILED ] FaultToleranceTest.SchedulerFailover
1 FAILED TEST
YOU HAVE 1 DISABLED TEST
FAIL: mesos-tests
==================
1 of 1 test failed
==================
make[3]: *** [check-TESTS] Error 1
make[3]: Leaving directory `<https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/ws/src'>
make[2]: *** [check-am] Error 2
make[2]: Leaving directory `<https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/ws/src'>
make[1]: *** [check] Error 2
make[1]: Leaving directory `<https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/ws/src'>
make: *** [check-recursive] Error 1
Build step 'Execute shell' marked build as failure
Build failed in Jenkins:
Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME #304
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/304/changes>
Changes:
[bmahler] Updated the Resource Monitor tests to use dispatch expectations.
Review: https://reviews.apache.org/r/10485
------------------------------------------
[...truncated 15652 lines...]
I0416 02:11:57.696905 21138 detector.cpp:330] Created ephemeral/sequence znode at '/znode/0000000002'
I0416 02:11:57.697299 21142 detector.cpp:485] Master detector (slave(82)@67.195.138.60:42719) found 1 registered masters
I0416 02:11:57.697497 21141 detector.cpp:485] Master detector (scheduler(74)@67.195.138.60:42719) found 1 registered masters
I0416 02:11:57.722810 21138 detector.cpp:485] Master detector (master@67.195.138.60:42719) found 1 registered masters
I0416 02:11:57.723637 21142 detector.cpp:531] Master detector (slave(82)@67.195.138.60:42719) got new master pid: master@67.195.138.60:42719
I0416 02:11:57.745682 21141 detector.cpp:531] Master detector (scheduler(74)@67.195.138.60:42719) got new master pid: master@67.195.138.60:42719
I0416 02:11:57.745919 21142 slave.cpp:453] New master detected at master@67.195.138.60:42719
I0416 02:11:57.746191 21138 detector.cpp:531] Master detector (master@67.195.138.60:42719) got new master pid: master@67.195.138.60:42719
I0416 02:11:57.746773 21141 sched.cpp:182] New master at master@67.195.138.60:42719
I0416 02:11:57.771847 21139 status_update_manager.cpp:132] New master detected at master@67.195.138.60:42719
I0416 02:11:57.772326 21138 master.cpp:603] Elected as master!
I0416 02:11:57.795343 21138 master.cpp:681] Re-registering framework 201304160211-1015726915-42719-21090-0000 at scheduler(74)@67.195.138.60:42719
I0416 02:11:57.796284 21143 sched.cpp:217] Framework registered with 201304160211-1015726915-42719-21090-0000
I0416 02:11:57.796362 21138 hierarchical_allocator_process.hpp:268] Added framework 201304160211-1015726915-42719-21090-0000
I0416 02:11:57.822163 21138 hierarchical_allocator_process.hpp:668] No resources available to allocate!
I0416 02:11:57.822684 21138 hierarchical_allocator_process.hpp:599] Performed allocation for 0 slaves in 522.74us
I0416 02:11:58.287884 21141 hierarchical_allocator_process.hpp:660] Found available resources: cpus=1; mem=524; ports=[31000-32000]; disk=1024 on slave 201304160211-1015726915-42719-21090-0
I0416 02:11:58.288024 21141 hierarchical_allocator_process.hpp:756] Filtered cpus=1; mem=524; ports=[31000-32000]; disk=1024 on slave 201304160211-1015726915-42719-21090-0 for framework 201304160211-1015726915-42719-21090-0000
I0416 02:11:58.299015 21141 hierarchical_allocator_process.hpp:599] Performed allocation for 1 slaves in 11.19ms
I0416 02:11:58.376142 21139 master.cpp:1029] Attempting to re-register slave 201304160211-1015726915-42719-21090-0 at slave(82)@67.195.138.60:42719 (janus.apache.org)
I0416 02:11:58.376232 21139 master.cpp:1224] Master now considering a slave at janus.apache.org:42719 as active
I0416 02:11:58.377939 21139 master.cpp:1862] Adding slave 201304160211-1015726915-42719-21090-0 at janus.apache.org with cpus=2; mem=1024; ports=[31000-32000]; disk=1024
I0416 02:11:58.396493 21142 slave.cpp:520] Re-registered with master
I0416 02:11:58.396567 21139 master.hpp:289] Adding task with resources cpus=1; mem=500 on slave 201304160211-1015726915-42719-21090-0
I0416 02:11:58.410270 21139 slave.cpp:956] Updating framework 201304160211-1015726915-42719-21090-0000 pid to scheduler(74)@67.195.138.60:42719
I0416 02:11:58.410352 21142 hierarchical_allocator_process.hpp:395] Added slave 201304160211-1015726915-42719-21090-0 (janus.apache.org) with cpus=2; mem=1024; ports=[31000-32000]; disk=1024 (and cpus=1; mem=524; ports=[31000-32000]; disk=1024 available)
I0416 02:11:58.430600 21142 hierarchical_allocator_process.hpp:660] Found available resources: cpus=1; mem=524; ports=[31000-32000]; disk=1024 on slave 201304160211-1015726915-42719-21090-0
I0416 02:11:58.443539 21142 hierarchical_allocator_process.hpp:686] Offering cpus=1; mem=524; ports=[31000-32000]; disk=1024 on slave 201304160211-1015726915-42719-21090-0 to framework 201304160211-1015726915-42719-21090-0000
I0416 02:11:58.444380 21142 hierarchical_allocator_process.hpp:619] Performed allocation for slave 201304160211-1015726915-42719-21090-0 in 13.79ms
I0416 02:11:58.444502 21145 master.hpp:309] Adding offer with resources cpus=1; mem=524; ports=[31000-32000]; disk=1024 on slave 201304160211-1015726915-42719-21090-0
I0416 02:11:58.463601 21145 master.cpp:1327] Sending 1 offers to framework 201304160211-1015726915-42719-21090-0000
I0416 02:11:58.464501 21138 sched.cpp:282] Received 1 offers
I0416 02:11:58.477341 21143 sched.cpp:422] Stopping framework '201304160211-1015726915-42719-21090-0000'
I0416 02:11:58.477442 21141 master.cpp:774] Asked to unregister framework 201304160211-1015726915-42719-21090-0000
I0416 02:11:58.478222 21144 hierarchical_allocator_process.hpp:359] Deactivated framework 201304160211-1015726915-42719-21090-0000
I0416 02:11:58.478229 21139 slave.cpp:889] Asked to shut down framework 201304160211-1015726915-42719-21090-0000 by master@67.195.138.60:42719
I0416 02:11:58.508712 21139 slave.cpp:894] Shutting down framework 201304160211-1015726915-42719-21090-0000
I0416 02:11:58.478243 21141 master.hpp:300] Removing task with resources cpus=1; mem=500 on slave 201304160211-1015726915-42719-21090-0
I0416 02:11:58.530246 21141 master.hpp:318] Removing offer with resources cpus=1; mem=524; ports=[31000-32000]; disk=1024 on slave 201304160211-1015726915-42719-21090-0
I0416 02:11:58.529743 21139 slave.cpp:1681] Shutting down executor 'default' of framework 201304160211-1015726915-42719-21090-0000
I0416 02:11:58.530300 21144 hierarchical_allocator_process.hpp:544] Recovered cpus=1; mem=500 (total allocatable: cpus=1; mem=500; ports=[]; disk=0) on slave 201304160211-1015726915-42719-21090-0 from framework 201304160211-1015726915-42719-21090-0000
I0416 02:11:58.531559 21145 exec.cpp:321] Executor asked to shutdown
I0416 02:11:58.531579 21139 slave.cpp:386] Slave terminating
I0416 02:11:58.531596 21140 status_update_manager.cpp:233] Closing status update streams for framework 201304160211-1015726915-42719-21090-0000
I0416 02:11:58.543561 21144 hierarchical_allocator_process.hpp:544] Recovered cpus=1; mem=524; ports=[31000-32000]; disk=1024 (total allocatable: cpus=2; mem=1024; ports=[31000-32000]; disk=1024) on slave 201304160211-1015726915-42719-21090-0 from framework 201304160211-1015726915-42719-21090-0000
I0416 02:11:58.544710 21139 slave.cpp:889] Asked to shut down framework 201304160211-1015726915-42719-21090-0000 by @0.0.0.0:0
I0416 02:11:58.563062 21140 status_update_manager.cpp:434] Cleaning up status update stream for task 0 of framework 201304160211-1015726915-42719-21090-0000
I0416 02:11:58.564359 21139 slave.cpp:894] Shutting down framework 201304160211-1015726915-42719-21090-0000
I0416 02:11:58.577132 21139 slave.cpp:1681] Shutting down executor 'default' of framework 201304160211-1015726915-42719-21090-0000
I0416 02:11:58.577710 21142 status_update_manager.cpp:233] Closing status update streams for framework 201304160211-1015726915-42719-21090-0000
I0416 02:11:58.577743 21139 master.cpp:537] Slave 201304160211-1015726915-42719-21090-0(janus.apache.org) disconnected
I0416 02:11:58.594277 21141 hierarchical_allocator_process.hpp:660] Found available resources: cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201304160211-1015726915-42719-21090-0
I0416 02:11:58.596355 21139 master.cpp:542] Removing disconnected slave 201304160211-1015726915-42719-21090-0(janus.apache.org) because it is not checkpointing!
I0416 02:11:58.608671 21141 hierarchical_allocator_process.hpp:599] Performed allocation for 1 slaves in 14.42ms
I0416 02:11:58.629847 21090 master.cpp:477] Master terminating
I0416 02:11:58.630944 21090 master.cpp:283] Shutting down master
I0416 02:11:58.635185 21090 master.cpp:283] Shutting down master
I0416 02:11:58.635288 21138 hierarchical_allocator_process.hpp:359] Deactivated framework 201304160211-1015726915-42719-21090-0000
I0416 02:11:58.635294 21090 master.hpp:300] Removing task with resources cpus=1; mem=500 on slave 201304160211-1015726915-42719-21090-0
I0416 02:11:58.663161 21143 hierarchical_allocator_process.hpp:544] Recovered cpus=1; mem=500 (total allocatable: cpus=2; mem=1024; ports=[31000-32000]; disk=1024) on slave 201304160211-1015726915-42719-21090-0 from framework 201304160211-1015726915-42719-21090-0000
I0416 02:11:58.663532 21143 hierarchical_allocator_process.hpp:312] Removed framework 201304160211-1015726915-42719-21090-0000
I0416 02:11:58.664309 21090 zookeeper_test_server.cpp:195] Shutdown ZooKeeperTestServer on port 46971
I0416 02:11:58.664341 21143 hierarchical_allocator_process.hpp:423] Removed slave 201304160211-1015726915-42719-21090-0
[ OK ] AllocatorZooKeeperTest/0.FrameworkReregistersFirst (1542 ms)
[ RUN ] AllocatorZooKeeperTest/0.SlaveReregistersFirst
I0416 02:11:58.678334 21090 jvm.cpp:34] looking up method <init>(Ljava/lang/String;)V
I0416 02:11:58.678458 21090 jvm.cpp:34] looking up method <init>(I)V
I0416 02:11:58.678930 21090 jvm.cpp:34] looking up method <init>(Ljava/net/InetSocketAddress;)V
I0416 02:11:58.696377 21090 jvm.cpp:34] looking up method startup(Lorg/apache/zookeeper/server/ZooKeeperServer;)V
I0416 02:11:58.697044 21090 jvm.cpp:34] looking up method isAlive()Z
I0416 02:11:58.697329 21090 jvm.cpp:34] looking up method shutdown()V
I0416 02:11:58.699945 21090 jvm.cpp:34] looking up method <init>(Ljava/io/File;Ljava/io/File;)V
I0416 02:11:58.700423 21090 jvm.cpp:34] looking up method <init>()V
I0416 02:11:58.719435 21090 jvm.cpp:34] looking up method <init>(Lorg/apache/zookeeper/server/persistence/FileTxnSnapLog;Lorg/apache/zookeeper/server/ZooKeeperServer$DataTreeBuilder;)V
I0416 02:11:58.720150 21090 jvm.cpp:34] looking up method getClientPort()I
I0416 02:11:58.720505 21090 jvm.cpp:34] looking up method closeSession(J)V
I0416 02:11:58.723328 21090 zookeeper_test_server.cpp:212] Started ZooKeeperTestServer on port 45647
I0416 02:11:58.723583 21142 master.cpp:309] Master started on 67.195.138.60:42719
I0416 02:11:58.746695 21142 master.cpp:324] Master ID: 201304160211-1015726915-42719-21090
I0416 02:11:58.723959 21143 slave.cpp:203] Slave started on 83)@67.195.138.60:42719
I0416 02:11:58.748605 21143 slave.cpp:204] Slave resources: cpus=2; mem=1024; ports=[31000-32000]; disk=1024
I0416 02:11:58.748756 21141 hierarchical_allocator_process.hpp:236] Initializing hierarchical allocator process with master : master@67.195.138.60:42719
W0416 02:11:58.748813 21144 master.cpp:81] No whitelist given. Advertising offers for all slaves
I0416 02:11:58.800019 21138 detector.cpp:283] Master detector (master@67.195.138.60:42719) connected to ZooKeeper ...
I0416 02:11:58.851594 21138 detector.cpp:300] Trying to create path '/znode' in ZooKeeper
I0416 02:11:58.800346 21140 detector.cpp:283] Master detector (slave(83)@67.195.138.60:42719) connected to ZooKeeper ...
I0416 02:11:58.841883 21141 detector.cpp:283] Master detector (scheduler(75)@67.195.138.60:42719) connected to ZooKeeper ...
I0416 02:11:58.861981 21141 detector.cpp:300] Trying to create path '/znode' in ZooKeeper
I0416 02:11:58.861450 21140 detector.cpp:300] Trying to create path '/znode' in ZooKeeper
I0416 02:11:58.800086 21145 slave.cpp:377] Finished recovery
I0416 02:11:58.971228 21138 detector.cpp:330] Created ephemeral/sequence znode at '/znode/0000000000'
I0416 02:11:58.971596 21141 detector.cpp:485] Master detector (scheduler(75)@67.195.138.60:42719) found 1 registered masters
I0416 02:11:58.971798 21138 detector.cpp:485] Master detector (master@67.195.138.60:42719) found 1 registered masters
I0416 02:11:58.971956 21140 detector.cpp:485] Master detector (slave(83)@67.195.138.60:42719) found 1 registered masters
I0416 02:11:58.985503 21141 detector.cpp:531] Master detector (scheduler(75)@67.195.138.60:42719) got new master pid: master@67.195.138.60:42719
I0416 02:11:58.991778 21138 detector.cpp:531] Master detector (master@67.195.138.60:42719) got new master pid: master@67.195.138.60:42719
I0416 02:11:58.992382 21140 detector.cpp:531] Master detector (slave(83)@67.195.138.60:42719) got new master pid: master@67.195.138.60:42719
I0416 02:11:59.012938 21141 sched.cpp:182] New master at master@67.195.138.60:42719
I0416 02:11:59.013372 21138 master.cpp:603] Elected as master!
I0416 02:11:59.014210 21140 slave.cpp:453] New master detected at master@67.195.138.60:42719
I0416 02:11:59.027415 21138 master.cpp:646] Registering framework 201304160211-1015726915-42719-21090-0000 at scheduler(75)@67.195.138.60:42719
I0416 02:11:59.046293 21140 status_update_manager.cpp:132] New master detected at master@67.195.138.60:42719
I0416 02:11:59.047049 21138 master.cpp:968] Attempting to register slave on janus.apache.org at slave(83)@67.195.138.60:42719
I0416 02:11:59.047056 21139 hierarchical_allocator_process.hpp:268] Added framework 201304160211-1015726915-42719-21090-0000
I0416 02:11:59.047088 21142 sched.cpp:217] Framework registered with 201304160211-1015726915-42719-21090-0000
I0416 02:11:59.060704 21138 master.cpp:1224] Master now considering a slave at janus.apache.org:42719 as active
I0416 02:11:59.080083 21139 hierarchical_allocator_process.hpp:668] No resources available to allocate!
I0416 02:11:59.101558 21138 master.cpp:1862] Adding slave 201304160211-1015726915-42719-21090-0 at janus.apache.org with cpus=2; mem=1024; ports=[31000-32000]; disk=1024
I0416 02:11:59.102313 21139 hierarchical_allocator_process.hpp:599] Performed allocation for 0 slaves in 22.23ms
I0416 02:11:59.127712 21143 slave.cpp:487] Registered with master; given slave ID 201304160211-1015726915-42719-21090-0
I0416 02:11:59.128432 21139 hierarchical_allocator_process.hpp:395] Added slave 201304160211-1015726915-42719-21090-0 (janus.apache.org) with cpus=2; mem=1024; ports=[31000-32000]; disk=1024 (and cpus=2; mem=1024; ports=[31000-32000]; disk=1024 available)
I0416 02:11:59.143640 21139 hierarchical_allocator_process.hpp:660] Found available resources: cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201304160211-1015726915-42719-21090-0
I0416 02:11:59.144480 21139 hierarchical_allocator_process.hpp:686] Offering cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201304160211-1015726915-42719-21090-0 to framework 201304160211-1015726915-42719-21090-0000
I0416 02:11:59.163589 21139 hierarchical_allocator_process.hpp:619] Performed allocation for slave 201304160211-1015726915-42719-21090-0 in 19.96ms
I0416 02:11:59.163655 21143 master.hpp:309] Adding offer with resources cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201304160211-1015726915-42719-21090-0
I0416 02:11:59.184835 21143 master.cpp:1327] Sending 1 offers to framework 201304160211-1015726915-42719-21090-0000
I0416 02:11:59.185693 21143 sched.cpp:282] Received 1 offers
I0416 02:11:59.211113 21143 master.cpp:1534] Processing reply for offer 201304160211-1015726915-42719-21090-0 on slave 201304160211-1015726915-42719-21090-0 (janus.apache.org) for framework 201304160211-1015726915-42719-21090-0000
I0416 02:11:59.211748 21143 master.hpp:289] Adding task with resources cpus=1; mem=500 on slave 201304160211-1015726915-42719-21090-0
I0416 02:11:59.226450 21143 master.cpp:1651] Launching task 0 of framework 201304160211-1015726915-42719-21090-0000 with resources cpus=1; mem=500 on slave 201304160211-1015726915-42719-21090-0 (janus.apache.org)
I0416 02:11:59.227011 21141 slave.cpp:587] Got assigned task 0 for framework 201304160211-1015726915-42719-21090-0000
I0416 02:11:59.227056 21143 master.hpp:318] Removing offer with resources cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201304160211-1015726915-42719-21090-0
I0416 02:11:59.227087 21144 hierarchical_allocator_process.hpp:471] Framework 201304160211-1015726915-42719-21090-0000 left cpus=1; mem=524; ports=[31000-32000]; disk=1024 unused on slave 201304160211-1015726915-42719-21090-0
I0416 02:11:59.229250 21141 paths.hpp:302] Created executor directory '/tmp/AllocatorZooKeeperTest_0_SlaveReregistersFirst_pWp8QJ/slaves/201304160211-1015726915-42719-21090-0/frameworks/201304160211-1015726915-42719-21090-0000/executors/default/runs/39ad9277-42ff-4d1f-ba51-01e32616859b'
I0416 02:11:59.247297 21144 hierarchical_allocator_process.hpp:497] Framework 201304160211-1015726915-42719-21090-0000 filtered slave 201304160211-1015726915-42719-21090-0 for 5.00secs
I0416 02:11:59.248296 21138 slave.cpp:436] Successfully attached file '/tmp/AllocatorZooKeeperTest_0_SlaveReregistersFirst_pWp8QJ/slaves/201304160211-1015726915-42719-21090-0/frameworks/201304160211-1015726915-42719-21090-0000/executors/default/runs/39ad9277-42ff-4d1f-ba51-01e32616859b'
I0416 02:11:59.248368 21140 exec.cpp:170] Executor started at: executor(27)@67.195.138.60:42719 with pid 21090
I0416 02:11:59.269418 21140 slave.cpp:1046] Got registration for executor 'default' of framework 201304160211-1015726915-42719-21090-0000
I0416 02:11:59.294253 21140 slave.cpp:1121] Flushing queued tasks for framework 201304160211-1015726915-42719-21090-0000
I0416 02:11:59.294311 21145 exec.cpp:194] Executor registered on slave 201304160211-1015726915-42719-21090-0
I0416 02:11:59.295975 21145 exec.cpp:258] Executor asked to run task '0'
I0416 02:11:59.318085 21145 exec.cpp:382] Executor sending status update for task 0 in state TASK_RUNNING
I0416 02:11:59.319820 21145 slave.cpp:1232] Handling status update TASK_RUNNING from task 0 of framework 201304160211-1015726915-42719-21090-0000
I0416 02:11:59.319856 21145 slave.cpp:1280] Forwarding status update TASK_RUNNING from task 0 of framework 201304160211-1015726915-42719-21090-0000 to the status update manager
I0416 02:11:59.344202 21145 status_update_manager.cpp:254] Received status update TASK_RUNNING from task 0 of framework 201304160211-1015726915-42719-21090-0000
I0416 02:11:59.344626 21145 status_update_manager.cpp:403] Creating StatusUpdate stream for task 0 of framework 201304160211-1015726915-42719-21090-0000
I0416 02:11:59.345458 21145 status_update_manager.hpp:314] Handling UPDATE for status update TASK_RUNNING from task 0 of framework 201304160211-1015726915-42719-21090-0000
I0416 02:11:59.368046 21145 status_update_manager.cpp:289] Forwarding status update TASK_RUNNING from task 0 of framework 201304160211-1015726915-42719-21090-0000 to the master at master@67.195.138.60:42719
I0416 02:11:59.368553 21139 master.cpp:1086] Status update from (806)@67.195.138.60:42719: task 0 of framework 201304160211-1015726915-42719-21090-0000 is now in state TASK_RUNNING
I0416 02:11:59.368557 21145 slave.cpp:1342] Sending ACK for status update TASK_RUNNING from task 0 of framework 201304160211-1015726915-42719-21090-0000 to executor executor(27)@67.195.138.60:42719
I0416 02:11:59.369057 21143 sched.cpp:327] Received status update TASK_RUNNING from task 0 of framework 201304160211-1015726915-42719-21090-0000 from slave(83)@67.195.138.60:42719
I0416 02:11:59.369879 21139 exec.cpp:289] Executor received ACK for status update of task 0 of framework 201304160211-1015726915-42719-21090-0000
I0416 02:11:59.394145 21143 sched.cpp:360] Sending ACK for status update TASK_RUNNING from task 0 of framework 201304160211-1015726915-42719-21090-0000 to slave(83)@67.195.138.60:42719
I0416 02:11:59.394479 21090 master.cpp:477] Master terminating
I0416 02:11:59.395469 21143 slave.cpp:979] Got acknowledgement of status update for task 0 of framework 201304160211-1015726915-42719-21090-0000
I0416 02:11:59.418561 21140 status_update_manager.cpp:314] Received status update acknowledgement for task 0 of framework 201304160211-1015726915-42719-21090-0000
I0416 02:11:59.419051 21140 status_update_manager.hpp:314] Handling ACK for status update TASK_RUNNING from task 0 of framework 201304160211-1015726915-42719-21090-0000
I0416 02:11:59.418958 21141 master.cpp:309] Master started on 67.195.138.60:42719
I0416 02:11:59.418670 21143 slave.cpp:1392] Process exited: @0.0.0.0:0
W0416 02:11:59.469073 21143 slave.cpp:1395] WARNING! Master disconnected! Waiting for a new master to be elected.
I0416 02:11:59.475599 21143 slave.cpp:1016] Status update manager successfully handled status update acknowledgement for task 0 of framework 201304160211-1015726915-42719-21090-0000
I0416 02:11:59.475467 21139 detector.cpp:283] Master detector (master@67.195.138.60:42719) connected to ZooKeeper ...
I0416 02:11:59.505424 21139 detector.cpp:300] Trying to create path '/znode' in ZooKeeper
I0416 02:11:59.475775 21140 detector.cpp:485] Master detector (scheduler(75)@67.195.138.60:42719) found 0 registered masters
I0416 02:11:59.506724 21140 detector.cpp:506] Master detector (scheduler(75)@67.195.138.60:42719) couldn't find any masters
I0416 02:11:59.444576 21141 master.cpp:324] Master ID: 201304160211-1015726915-42719-21090
I0416 02:11:59.475940 21142 detector.cpp:485] Master detector (slave(83)@67.195.138.60:42719) found 0 registered masters
I0416 02:11:59.585031 21142 detector.cpp:506] Master detector (slave(83)@67.195.138.60:42719) couldn't find any masters
W0416 02:11:59.555675 21145 master.cpp:81] No whitelist given. Advertising offers for all slaves
I0416 02:11:59.555789 21144 hierarchical_allocator_process.hpp:236] Initializing hierarchical allocator process with master : master@67.195.138.60:42719
I0416 02:11:59.544050 21140 sched.cpp:193] No master detected, waiting for another master
I0416 02:11:59.606917 21139 detector.cpp:330] Created ephemeral/sequence znode at '/znode/0000000002'
I0416 02:11:59.607213 21143 detector.cpp:485] Master detector (scheduler(75)@67.195.138.60:42719) found 1 registered masters
I0416 02:11:59.607306 21138 slave.cpp:479] Lost master(s) ... waiting
I0416 02:11:59.607776 21142 detector.cpp:485] Master detector (slave(83)@67.195.138.60:42719) found 1 registered masters
I0416 02:11:59.632551 21139 detector.cpp:485] Master detector (master@67.195.138.60:42719) found 1 registered masters
I0416 02:11:59.632820 21143 detector.cpp:531] Master detector (scheduler(75)@67.195.138.60:42719) got new master pid: master@67.195.138.60:42719
I0416 02:11:59.634143 21142 detector.cpp:531] Master detector (slave(83)@67.195.138.60:42719) got new master pid: master@67.195.138.60:42719
I0416 02:11:59.669620 21143 sched.cpp:182] New master at master@67.195.138.60:42719
I0416 02:11:59.669713 21139 detector.cpp:531] Master detector (master@67.195.138.60:42719) got new master pid: master@67.195.138.60:42719
I0416 02:11:59.701262 21139 master.cpp:603] Elected as master!
I0416 02:11:59.670162 21142 slave.cpp:453] New master detected at master@67.195.138.60:42719
I0416 02:11:59.702277 21140 status_update_manager.cpp:132] New master detected at master@67.195.138.60:42719
I0416 02:11:59.702415 21145 master.cpp:1029] Attempting to re-register slave 201304160211-1015726915-42719-21090-0 at slave(83)@67.195.138.60:42719 (janus.apache.org)
I0416 02:11:59.705492 21145 master.cpp:1224] Master now considering a slave at janus.apache.org:42719 as active
I0416 02:11:59.735702 21145 master.cpp:1862] Adding slave 201304160211-1015726915-42719-21090-0 at janus.apache.org with cpus=2; mem=1024; ports=[31000-32000]; disk=1024
I0416 02:11:59.756533 21144 slave.cpp:520] Re-registered with master
I0416 02:11:59.756542 21145 master.hpp:289] Adding task with resources cpus=1; mem=500 on slave 201304160211-1015726915-42719-21090-0
W0416 02:11:59.779944 21145 master.cpp:1948] Possibly orphaned task 0 of framework 201304160211-1015726915-42719-21090-0000 running on slave 201304160211-1015726915-42719-21090-0 (janus.apache.org)
I0416 02:11:59.781358 21141 hierarchical_allocator_process.hpp:395] Added slave 201304160211-1015726915-42719-21090-0 (janus.apache.org) with cpus=2; mem=1024; ports=[31000-32000]; disk=1024 (and cpus=1; mem=524; ports=[31000-32000]; disk=1024 available)
I0416 02:11:59.800801 21142 hierarchical_allocator_process.hpp:660] Found available resources: cpus=1; mem=524; ports=[31000-32000]; disk=1024 on slave 201304160211-1015726915-42719-21090-0
I0416 02:11:59.809659 21141 hierarchical_allocator_process.hpp:632] No users to allocate resources!
I0416 02:11:59.835578 21141 hierarchical_allocator_process.hpp:619] Performed allocation for slave 201304160211-1015726915-42719-21090-0 in 25.92ms
I0416 02:11:59.810417 21142 hierarchical_allocator_process.hpp:756] Filtered cpus=1; mem=524; ports=[31000-32000]; disk=1024 on slave 201304160211-1015726915-42719-21090-0 for framework 201304160211-1015726915-42719-21090-0000
I0416 02:11:59.836935 21142 hierarchical_allocator_process.hpp:599] Performed allocation for 1 slaves in 36.15ms
I0416 02:12:00.027128 21143 master.cpp:681] Re-registering framework 201304160211-1015726915-42719-21090-0000 at scheduler(75)@67.195.138.60:42719
I0416 02:12:00.027395 21145 sched.cpp:217] Framework registered with 201304160211-1015726915-42719-21090-0000
I0416 02:12:00.027426 21143 slave.cpp:956] Updating framework 201304160211-1015726915-42719-21090-0000 pid to scheduler(75)@67.195.138.60:42719
I0416 02:12:00.027503 21142 hierarchical_allocator_process.hpp:268] Added framework 201304160211-1015726915-42719-21090-0000
I0416 02:12:00.046862 21142 hierarchical_allocator_process.hpp:660] Found available resources: cpus=1; mem=524; ports=[31000-32000]; disk=1024 on slave 201304160211-1015726915-42719-21090-0
I0416 02:12:00.067761 21142 hierarchical_allocator_process.hpp:686] Offering cpus=1; mem=524; ports=[31000-32000]; disk=1024 on slave 201304160211-1015726915-42719-21090-0 to framework 201304160211-1015726915-42719-21090-0000
I0416 02:12:00.068231 21142 hierarchical_allocator_process.hpp:599] Performed allocation for 1 slaves in 21.39ms
I0416 02:12:00.068310 21144 master.hpp:309] Adding offer with resources cpus=1; mem=524; ports=[31000-32000]; disk=1024 on slave 201304160211-1015726915-42719-21090-0
I0416 02:12:00.088613 21144 master.cpp:1327] Sending 1 offers to framework 201304160211-1015726915-42719-21090-0000
I0416 02:12:00.089087 21144 sched.cpp:282] Received 1 offers
I0416 02:12:00.089896 21144 sched.cpp:422] Stopping framework '201304160211-1015726915-42719-21090-0000'
I0416 02:12:00.090052 21140 master.cpp:774] Asked to unregister framework 201304160211-1015726915-42719-21090-0000
I0416 02:12:00.090570 21138 hierarchical_allocator_process.hpp:359] Deactivated framework 201304160211-1015726915-42719-21090-0000
I0416 02:12:00.090623 21143 slave.cpp:889] Asked to shut down framework 201304160211-1015726915-42719-21090-0000 by master@67.195.138.60:42719
I0416 02:12:00.090651 21140 master.hpp:300] Removing task with resources cpus=1; mem=500 on slave 201304160211-1015726915-42719-21090-0
I0416 02:12:00.135432 21143 slave.cpp:894] Shutting down framework 201304160211-1015726915-42719-21090-0000
I0416 02:12:00.151489 21143 slave.cpp:1681] Shutting down executor 'default' of framework 201304160211-1015726915-42719-21090-0000
I0416 02:12:00.152191 21139 exec.cpp:321] Executor asked to shutdown
I0416 02:12:00.151142 21140 master.hpp:318] Removing offer with resources cpus=1; mem=524; ports=[31000-32000]; disk=1024 on slave 201304160211-1015726915-42719-21090-0
I0416 02:12:00.151212 21141 hierarchical_allocator_process.hpp:544] Recovered cpus=1; mem=500 (total allocatable: cpus=1; mem=500; ports=[]; disk=0) on slave 201304160211-1015726915-42719-21090-0 from framework 201304160211-1015726915-42719-21090-0000
I0416 02:12:00.172327 21141 hierarchical_allocator_process.hpp:544] Recovered cpus=1; mem=524; ports=[31000-32000]; disk=1024 (total allocatable: cpus=2; mem=1024; ports=[31000-32000]; disk=1024) on slave 201304160211-1015726915-42719-21090-0 from framework 201304160211-1015726915-42719-21090-0000
I0416 02:12:00.171849 21140 slave.cpp:386] Slave terminating
I0416 02:12:00.193105 21140 slave.cpp:889] Asked to shut down framework 201304160211-1015726915-42719-21090-0000 by @0.0.0.0:0
I0416 02:12:00.193580 21140 slave.cpp:894] Shutting down framework 201304160211-1015726915-42719-21090-0000
I0416 02:12:00.194056 21140 slave.cpp:1681] Shutting down executor 'default' of framework 201304160211-1015726915-42719-21090-0000
I0416 02:12:00.194598 21140 master.cpp:537] Slave 201304160211-1015726915-42719-21090-0(janus.apache.org) disconnected
I0416 02:12:00.195036 21140 master.cpp:542] Removing disconnected slave 201304160211-1015726915-42719-21090-0(janus.apache.org) because it is not checkpointing!
I0416 02:12:00.152217 21143 status_update_manager.cpp:233] Closing status update streams for framework 201304160211-1015726915-42719-21090-0000
I0416 02:12:00.195746 21090 master.cpp:477] Master terminating
I0416 02:12:00.196439 21143 status_update_manager.cpp:434] Cleaning up status update stream for task 0 of framework 201304160211-1015726915-42719-21090-0000
I0416 02:12:00.227531 21090 master.cpp:283] Shutting down master
I0416 02:12:00.238435 21143 status_update_manager.cpp:233] Closing status update streams for framework 201304160211-1015726915-42719-21090-0000
I0416 02:12:00.284580 21090 master.cpp:283] Shutting down master
I0416 02:12:00.284840 21138 hierarchical_allocator_process.hpp:359] Deactivated framework 201304160211-1015726915-42719-21090-0000
I0416 02:12:00.284857 21090 master.hpp:300] Removing task with resources cpus=1; mem=500 on slave 201304160211-1015726915-42719-21090-0
I0416 02:12:00.285866 21139 hierarchical_allocator_process.hpp:544] Recovered cpus=1; mem=500 (total allocatable: cpus=2; mem=1024; ports=[31000-32000]; disk=1024) on slave 201304160211-1015726915-42719-21090-0 from framework 201304160211-1015726915-42719-21090-0000
I0416 02:12:00.286828 21139 hierarchical_allocator_process.hpp:312] Removed framework 201304160211-1015726915-42719-21090-0000
I0416 02:12:00.287201 21139 hierarchical_allocator_process.hpp:423] Removed slave 201304160211-1015726915-42719-21090-0
I0416 02:12:00.287050 21090 zookeeper_test_server.cpp:195] Shutdown ZooKeeperTestServer on port 45647
[ OK ] AllocatorZooKeeperTest/0.SlaveReregistersFirst (1611 ms)
[----------] 2 tests from AllocatorZooKeeperTest/0 (3153 ms total)
[----------] Global test environment tear-down
[==========] 190 tests from 39 test cases ran. (119136 ms total)
[ PASSED ] 188 tests.
[ FAILED ] 2 tests, listed below:
[ FAILED ] FaultToleranceTest.SchedulerFailover
[ FAILED ] CoordinatorTest.TruncateNotLearnedFill
2 FAILED TESTS
YOU HAVE 1 DISABLED TEST
FAIL: mesos-tests
==================
1 of 1 test failed
==================
make[3]: *** [check-TESTS] Error 1
make[3]: Leaving directory `<https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/ws/src'>
make[2]: *** [check-am] Error 2
make[2]: Leaving directory `<https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/ws/src'>
make[1]: *** [check] Error 2
make[1]: Leaving directory `<https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/ws/src'>
make: *** [check-recursive] Error 1
Build step 'Execute shell' marked build as failure
Re: Build failed in Jenkins: Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME
#303
Posted by Benjamin Hindman <be...@eecs.berkeley.edu>.
The fix for this is at https://reviews.apache.org/r/10462.
On Sun, Apr 14, 2013 at 8:52 PM, Apache Jenkins Server <
jenkins@builds.apache.org> wrote:
> See <
> https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/303/changes
> >
>
> Changes:
>
> [bmahler] Replaced sleep() and usleep() calls with os::sleep().
>
> From: Jiang Yan Xu <ya...@jxu.me>
> Review: https://reviews.apache.org/r/10443
>
> [bmahler] Replaced usleep() calls in libprocess with os::sleep().
>
> From: Jiang Yan Xu <ya...@jxu.me>
> Review: https://reviews.apache.org/r/10241
>
> [bmahler] Changed os::sleep() to take a Duration instead of a double.
>
> From: Jiang Yan Xu <ya...@jxu.me>
> Review: https://reviews.apache.org/r/10231
>
> ------------------------------------------
> [...truncated 15692 lines...]
> I0415 03:52:14.867821 28013 detector.cpp:531] Master detector (slave(82)@
> 67.195.138.60:60471) got new master pid: master@67.195.138.60:60471
> I0415 03:52:14.869232 28013 slave.cpp:453] New master detected at
> master@67.195.138.60:60471
> W0415 03:52:14.868774 28018 master.cpp:668] Ignoring re-register framework
> message since not elected yet
> I0415 03:52:14.868716 28011 detector.cpp:531] Master detector (
> master@67.195.138.60:60471) got new master pid:
> master@67.195.138.60:60471
> I0415 03:52:14.869796 28013 status_update_manager.cpp:132] New master
> detected at master@67.195.138.60:60471
> I0415 03:52:14.870738 28011 master.cpp:603] Elected as master!
> I0415 03:52:15.710227 28016 hierarchical_allocator_process.hpp:660] Found
> available resources: cpus=1; mem=524; ports=[31000-32000]; disk=1024 on
> slave 201304150352-1015726915-60471-27966-0
> I0415 03:52:15.750718 28016 hierarchical_allocator_process.hpp:756]
> Filtered cpus=1; mem=524; ports=[31000-32000]; disk=1024 on slave
> 201304150352-1015726915-60471-27966-0 for framework
> 201304150352-1015726915-60471-27966-0000
> I0415 03:52:15.751005 28016 hierarchical_allocator_process.hpp:599]
> Performed allocation for 1 slaves in 40.82ms
> I0415 03:52:15.778457 28015 master.cpp:681] Re-registering framework
> 201304150352-1015726915-60471-27966-0000 at scheduler(74)@
> 67.195.138.60:60471
> I0415 03:52:15.778777 28017 sched.cpp:217] Framework registered with
> 201304150352-1015726915-60471-27966-0000
> I0415 03:52:15.778832 28015 hierarchical_allocator_process.hpp:268] Added
> framework 201304150352-1015726915-60471-27966-0000
> I0415 03:52:15.779409 28015 hierarchical_allocator_process.hpp:668] No
> resources available to allocate!
> I0415 03:52:15.779876 28015 hierarchical_allocator_process.hpp:599]
> Performed allocation for 0 slaves in 468.78us
> I0415 03:52:15.825428 28017 hierarchical_allocator_process.hpp:668] No
> resources available to allocate!
> I0415 03:52:15.825634 28017 hierarchical_allocator_process.hpp:599]
> Performed allocation for 0 slaves in 232.74us
> I0415 03:52:15.870821 28017 master.cpp:1029] Attempting to re-register
> slave 201304150352-1015726915-60471-27966-0 at slave(82)@
> 67.195.138.60:60471 (janus.apache.org)
> I0415 03:52:15.870980 28017 master.cpp:1224] Master now considering a
> slave at janus.apache.org:60471 as active
> I0415 03:52:15.871337 28017 master.cpp:1862] Adding slave
> 201304150352-1015726915-60471-27966-0 at janus.apache.org with cpus=2;
> mem=1024; ports=[31000-32000]; disk=1024
> I0415 03:52:15.871814 28013 slave.cpp:520] Re-registered with master
> I0415 03:52:15.871881 28017 master.hpp:289] Adding task with resources
> cpus=1; mem=500 on slave 201304150352-1015726915-60471-27966-0
> I0415 03:52:15.872872 28012 slave.cpp:956] Updating framework
> 201304150352-1015726915-60471-27966-0000 pid to scheduler(74)@
> 67.195.138.60:60471
> I0415 03:52:15.872985 28015 hierarchical_allocator_process.hpp:395] Added
> slave 201304150352-1015726915-60471-27966-0 (janus.apache.org) with
> cpus=2; mem=1024; ports=[31000-32000]; disk=1024 (and cpus=1; mem=524;
> ports=[31000-32000]; disk=1024 available)
> I0415 03:52:15.873723 28015 hierarchical_allocator_process.hpp:660] Found
> available resources: cpus=1; mem=524; ports=[31000-32000]; disk=1024 on
> slave 201304150352-1015726915-60471-27966-0
> I0415 03:52:15.874207 28015 hierarchical_allocator_process.hpp:686]
> Offering cpus=1; mem=524; ports=[31000-32000]; disk=1024 on slave
> 201304150352-1015726915-60471-27966-0 to framework
> 201304150352-1015726915-60471-27966-0000
> I0415 03:52:15.874761 28015 hierarchical_allocator_process.hpp:619]
> Performed allocation for slave 201304150352-1015726915-60471-27966-0 in
> 1.05ms
> I0415 03:52:15.874876 28011 master.hpp:309] Adding offer with resources
> cpus=1; mem=524; ports=[31000-32000]; disk=1024 on slave
> 201304150352-1015726915-60471-27966-0
> I0415 03:52:15.875663 28011 master.cpp:1327] Sending 1 offers to framework
> 201304150352-1015726915-60471-27966-0000
> I0415 03:52:15.876142 28014 sched.cpp:282] Received 1 offers
> I0415 03:52:15.877135 28018 sched.cpp:422] Stopping framework
> '201304150352-1015726915-60471-27966-0000'
> I0415 03:52:15.877218 28011 master.cpp:774] Asked to unregister framework
> 201304150352-1015726915-60471-27966-0000
> I0415 03:52:15.877617 28018 slave.cpp:889] Asked to shut down framework
> 201304150352-1015726915-60471-27966-0000 by master@67.195.138.60:60471
> I0415 03:52:15.877672 28017 hierarchical_allocator_process.hpp:359]
> Deactivated framework 201304150352-1015726915-60471-27966-0000
> I0415 03:52:15.877657 28011 master.hpp:300] Removing task with resources
> cpus=1; mem=500 on slave 201304150352-1015726915-60471-27966-0
> I0415 03:52:15.877977 28018 slave.cpp:894] Shutting down framework
> 201304150352-1015726915-60471-27966-0000
> I0415 03:52:15.885417 28017 hierarchical_allocator_process.hpp:544]
> Recovered cpus=1; mem=500 (total allocatable: cpus=1; mem=500; ports=[];
> disk=0) on slave 201304150352-1015726915-60471-27966-0 from framework
> 201304150352-1015726915-60471-27966-0000
> I0415 03:52:15.885397 28011 master.hpp:318] Removing offer with resources
> cpus=1; mem=524; ports=[31000-32000]; disk=1024 on slave
> 201304150352-1015726915-60471-27966-0
> I0415 03:52:15.885673 28018 slave.cpp:1681] Shutting down executor
> 'default' of framework 201304150352-1015726915-60471-27966-0000
> I0415 03:52:15.886265 28017 hierarchical_allocator_process.hpp:544]
> Recovered cpus=1; mem=524; ports=[31000-32000]; disk=1024 (total
> allocatable: cpus=2; mem=1024; ports=[31000-32000]; disk=1024) on slave
> 201304150352-1015726915-60471-27966-0 from framework
> 201304150352-1015726915-60471-27966-0000
> I0415 03:52:15.887142 28014 exec.cpp:321] Executor asked to shutdown
> I0415 03:52:15.887159 28018 slave.cpp:386] Slave terminating
> I0415 03:52:15.887166 28016 status_update_manager.cpp:233] Closing status
> update streams for framework 201304150352-1015726915-60471-27966-0000
> I0415 03:52:15.889034 28016 status_update_manager.cpp:434] Cleaning up
> status update stream for task 0 of framework
> 201304150352-1015726915-60471-27966-0000
> I0415 03:52:15.888540 28018 slave.cpp:889] Asked to shut down framework
> 201304150352-1015726915-60471-27966-0000 by @0.0.0.0:0
> I0415 03:52:15.889957 28018 slave.cpp:894] Shutting down framework
> 201304150352-1015726915-60471-27966-0000
> I0415 03:52:15.890426 28018 slave.cpp:1681] Shutting down executor
> 'default' of framework 201304150352-1015726915-60471-27966-0000
> I0415 03:52:15.890962 28013 status_update_manager.cpp:233] Closing status
> update streams for framework 201304150352-1015726915-60471-27966-0000
> I0415 03:52:15.891006 28015 master.cpp:537] Slave
> 201304150352-1015726915-60471-27966-0(janus.apache.org) disconnected
> I0415 03:52:15.891890 28015 master.cpp:542] Removing disconnected slave
> 201304150352-1015726915-60471-27966-0(janus.apache.org) because it is not
> checkpointing!
> I0415 03:52:15.892469 28017 master.cpp:477] Master terminating
> I0415 03:52:15.893165 27966 master.cpp:283] Shutting down master
> I0415 03:52:15.893846 27966 master.cpp:283] Shutting down master
> I0415 03:52:15.893923 28013 hierarchical_allocator_process.hpp:359]
> Deactivated framework 201304150352-1015726915-60471-27966-0000
> I0415 03:52:15.893959 27966 master.hpp:300] Removing task with resources
> cpus=1; mem=500 on slave 201304150352-1015726915-60471-27966-0
> I0415 03:52:15.896077 28016 hierarchical_allocator_process.hpp:544]
> Recovered cpus=1; mem=500 (total allocatable: cpus=2; mem=1024;
> ports=[31000-32000]; disk=1024) on slave
> 201304150352-1015726915-60471-27966-0 from framework
> 201304150352-1015726915-60471-27966-0000
> I0415 03:52:15.896258 28016 hierarchical_allocator_process.hpp:312]
> Removed framework 201304150352-1015726915-60471-27966-0000
> I0415 03:52:15.896742 28016 hierarchical_allocator_process.hpp:423]
> Removed slave 201304150352-1015726915-60471-27966-0
> I0415 03:52:15.905767 27966 zookeeper_test_server.cpp:195] Shutdown
> ZooKeeperTestServer on port 47833
> [ OK ] AllocatorZooKeeperTest/0.FrameworkReregistersFirst (2242 ms)
> [ RUN ] AllocatorZooKeeperTest/0.SlaveReregistersFirst
> I0415 03:52:15.907378 27966 jvm.cpp:34] looking up method
> <init>(Ljava/lang/String;)V
> I0415 03:52:15.907512 27966 jvm.cpp:34] looking up method <init>(I)V
> I0415 03:52:15.907819 27966 jvm.cpp:34] looking up method
> <init>(Ljava/net/InetSocketAddress;)V
> I0415 03:52:15.908318 27966 jvm.cpp:34] looking up method
> startup(Lorg/apache/zookeeper/server/ZooKeeperServer;)V
> I0415 03:52:15.908787 27966 jvm.cpp:34] looking up method isAlive()Z
> I0415 03:52:15.909245 27966 jvm.cpp:34] looking up method shutdown()V
> I0415 03:52:15.912058 27966 jvm.cpp:34] looking up method
> <init>(Ljava/io/File;Ljava/io/File;)V
> I0415 03:52:15.912618 27966 jvm.cpp:34] looking up method <init>()V
> I0415 03:52:15.912720 27966 jvm.cpp:34] looking up method
> <init>(Lorg/apache/zookeeper/server/persistence/FileTxnSnapLog;Lorg/apache/zookeeper/server/ZooKeeperServer$DataTreeBuilder;)V
> I0415 03:52:15.913173 27966 jvm.cpp:34] looking up method getClientPort()I
> I0415 03:52:15.913513 27966 jvm.cpp:34] looking up method closeSession(J)V
> I0415 03:52:15.915868 27966 zookeeper_test_server.cpp:212] Started
> ZooKeeperTestServer on port 53584
> I0415 03:52:15.916173 28011 master.cpp:309] Master started on
> 67.195.138.60:60471
> I0415 03:52:15.916242 28011 master.cpp:324] Master ID:
> 201304150352-1015726915-60471-27966
> I0415 03:52:15.916827 28014 hierarchical_allocator_process.hpp:236]
> Initializing hierarchical allocator process with master :
> master@67.195.138.60:60471
> W0415 03:52:15.916849 28017 master.cpp:81] No whitelist given. Advertising
> offers for all slaves
> I0415 03:52:15.916645 28013 slave.cpp:203] Slave started on 83)@
> 67.195.138.60:60471
> I0415 03:52:15.918356 28013 slave.cpp:204] Slave resources: cpus=2;
> mem=1024; ports=[31000-32000]; disk=1024
> I0415 03:52:15.920147 28012 slave.cpp:377] Finished recovery
> I0415 03:52:15.974617 28017 detector.cpp:283] Master detector (
> master@67.195.138.60:60471) connected to ZooKeeper ...
> I0415 03:52:15.974661 28017 detector.cpp:300] Trying to create path
> '/znode' in ZooKeeper
> I0415 03:52:15.975020 28014 detector.cpp:283] Master detector (slave(83)@
> 67.195.138.60:60471) connected to ZooKeeper ...
> I0415 03:52:15.975471 28014 detector.cpp:300] Trying to create path
> '/znode' in ZooKeeper
> I0415 03:52:15.986569 28011 detector.cpp:283] Master detector
> (scheduler(75)@67.195.138.60:60471) connected to ZooKeeper ...
> I0415 03:52:15.986613 28011 detector.cpp:300] Trying to create path
> '/znode' in ZooKeeper
> I0415 03:52:16.031102 28014 detector.cpp:485] Master detector (slave(83)@
> 67.195.138.60:60471) found 0 registered masters
> I0415 03:52:16.031152 28014 detector.cpp:506] Master detector (slave(83)@
> 67.195.138.60:60471) couldn't find any masters
> I0415 03:52:16.031517 28014 slave.cpp:479] Lost master(s) ... waiting
> I0415 03:52:16.053187 28017 detector.cpp:330] Created ephemeral/sequence
> znode at '/znode/0000000000'
> I0415 03:52:16.053555 28011 detector.cpp:485] Master detector
> (scheduler(75)@67.195.138.60:60471) found 1 registered masters
> I0415 03:52:16.053598 28018 detector.cpp:485] Master detector (slave(83)@
> 67.195.138.60:60471) found 1 registered masters
> I0415 03:52:16.053761 28017 detector.cpp:485] Master detector (
> master@67.195.138.60:60471) found 1 registered masters
> I0415 03:52:16.056705 28011 detector.cpp:531] Master detector
> (scheduler(75)@67.195.138.60:60471) got new master pid:
> master@67.195.138.60:60471
> I0415 03:52:16.057068 28018 detector.cpp:531] Master detector (slave(83)@
> 67.195.138.60:60471) got new master pid: master@67.195.138.60:60471
> I0415 03:52:16.057497 28017 detector.cpp:531] Master detector (
> master@67.195.138.60:60471) got new master pid:
> master@67.195.138.60:60471
> I0415 03:52:16.057570 28011 sched.cpp:182] New master at
> master@67.195.138.60:60471
> I0415 03:52:16.058527 28018 slave.cpp:453] New master detected at
> master@67.195.138.60:60471
> I0415 03:52:16.058948 28017 master.cpp:603] Elected as master!
> I0415 03:52:16.059919 28013 status_update_manager.cpp:132] New master
> detected at master@67.195.138.60:60471
> I0415 03:52:16.060400 28017 master.cpp:646] Registering framework
> 201304150352-1015726915-60471-27966-0000 at scheduler(75)@
> 67.195.138.60:60471
> I0415 03:52:16.061298 28014 sched.cpp:217] Framework registered with
> 201304150352-1015726915-60471-27966-0000
> I0415 03:52:16.061336 28012 hierarchical_allocator_process.hpp:268] Added
> framework 201304150352-1015726915-60471-27966-0000
> I0415 03:52:16.062196 28012 hierarchical_allocator_process.hpp:668] No
> resources available to allocate!
> I0415 03:52:16.062657 28012 hierarchical_allocator_process.hpp:599]
> Performed allocation for 0 slaves in 463.10us
> I0415 03:52:16.061337 28017 master.cpp:968] Attempting to register slave
> on janus.apache.org at slave(83)@67.195.138.60:60471
> I0415 03:52:16.063691 28017 master.cpp:1224] Master now considering a
> slave at janus.apache.org:60471 as active
> I0415 03:52:16.064242 28017 master.cpp:1862] Adding slave
> 201304150352-1015726915-60471-27966-0 at janus.apache.org with cpus=2;
> mem=1024; ports=[31000-32000]; disk=1024
> I0415 03:52:16.064872 28015 slave.cpp:487] Registered with master; given
> slave ID 201304150352-1015726915-60471-27966-0
> I0415 03:52:16.064906 28017 hierarchical_allocator_process.hpp:395] Added
> slave 201304150352-1015726915-60471-27966-0 (janus.apache.org) with
> cpus=2; mem=1024; ports=[31000-32000]; disk=1024 (and cpus=2; mem=1024;
> ports=[31000-32000]; disk=1024 available)
> I0415 03:52:16.066014 28017 hierarchical_allocator_process.hpp:660] Found
> available resources: cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on
> slave 201304150352-1015726915-60471-27966-0
> I0415 03:52:16.066556 28017 hierarchical_allocator_process.hpp:686]
> Offering cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave
> 201304150352-1015726915-60471-27966-0 to framework
> 201304150352-1015726915-60471-27966-0000
> I0415 03:52:16.067203 28017 hierarchical_allocator_process.hpp:619]
> Performed allocation for slave 201304150352-1015726915-60471-27966-0 in
> 1.20ms
> I0415 03:52:16.067248 28015 master.hpp:309] Adding offer with resources
> cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave
> 201304150352-1015726915-60471-27966-0
> I0415 03:52:16.068080 28015 master.cpp:1327] Sending 1 offers to framework
> 201304150352-1015726915-60471-27966-0000
> I0415 03:52:16.068614 28013 sched.cpp:282] Received 1 offers
> I0415 03:52:16.069325 28011 master.cpp:1534] Processing reply for offer
> 201304150352-1015726915-60471-27966-0 on slave
> 201304150352-1015726915-60471-27966-0 (janus.apache.org) for framework
> 201304150352-1015726915-60471-27966-0000
> I0415 03:52:16.069624 28011 master.hpp:289] Adding task with resources
> cpus=1; mem=500 on slave 201304150352-1015726915-60471-27966-0
> I0415 03:52:16.070015 28011 master.cpp:1651] Launching task 0 of framework
> 201304150352-1015726915-60471-27966-0000 with resources cpus=1; mem=500 on
> slave 201304150352-1015726915-60471-27966-0 (janus.apache.org)
> I0415 03:52:16.070535 28015 slave.cpp:587] Got assigned task 0 for
> framework 201304150352-1015726915-60471-27966-0000
> I0415 03:52:16.072350 28015 paths.hpp:302] Created executor directory
> '/tmp/AllocatorZooKeeperTest_0_SlaveReregistersFirst_Ern3zU/slaves/201304150352-1015726915-60471-27966-0/frameworks/201304150352-1015726915-60471-27966-0000/executors/default/runs/707fea91-d760-4884-a29d-bf387467c868'
> I0415 03:52:16.070592 28018 hierarchical_allocator_process.hpp:471]
> Framework 201304150352-1015726915-60471-27966-0000 left cpus=1; mem=524;
> ports=[31000-32000]; disk=1024 unused on slave
> 201304150352-1015726915-60471-27966-0
> I0415 03:52:16.072819 28018 hierarchical_allocator_process.hpp:497]
> Framework 201304150352-1015726915-60471-27966-0000 filtered slave
> 201304150352-1015726915-60471-27966-0 for 5.00secs
> I0415 03:52:16.072558 28017 slave.cpp:436] Successfully attached file
> '/tmp/AllocatorZooKeeperTest_0_SlaveReregistersFirst_Ern3zU/slaves/201304150352-1015726915-60471-27966-0/frameworks/201304150352-1015726915-60471-27966-0000/executors/default/runs/707fea91-d760-4884-a29d-bf387467c868'
> I0415 03:52:16.072614 28015 exec.cpp:170] Executor started at:
> executor(27)@67.195.138.60:60471 with pid 27966
> I0415 03:52:16.070593 28011 master.hpp:318] Removing offer with resources
> cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave
> 201304150352-1015726915-60471-27966-0
> I0415 03:52:16.107143 28015 slave.cpp:1046] Got registration for executor
> 'default' of framework 201304150352-1015726915-60471-27966-0000
> I0415 03:52:16.108271 28015 slave.cpp:1121] Flushing queued tasks for
> framework 201304150352-1015726915-60471-27966-0000
> I0415 03:52:16.108311 28016 exec.cpp:194] Executor registered on slave
> 201304150352-1015726915-60471-27966-0
> I0415 03:52:16.109413 28016 exec.cpp:258] Executor asked to run task '0'
> I0415 03:52:16.110012 28016 exec.cpp:382] Executor sending status update
> for task 0 in state TASK_RUNNING
> I0415 03:52:16.111738 28016 slave.cpp:1232] Handling status update
> TASK_RUNNING from task 0 of framework
> 201304150352-1015726915-60471-27966-0000
> I0415 03:52:16.111771 28016 slave.cpp:1280] Forwarding status update
> TASK_RUNNING from task 0 of framework
> 201304150352-1015726915-60471-27966-0000 to the status update manager
> I0415 03:52:16.112221 28016 status_update_manager.cpp:254] Received status
> update TASK_RUNNING from task 0 of framework
> 201304150352-1015726915-60471-27966-0000
> I0415 03:52:16.112695 28016 status_update_manager.cpp:403] Creating
> StatusUpdate stream for task 0 of framework
> 201304150352-1015726915-60471-27966-0000
> I0415 03:52:16.113306 28016 status_update_manager.hpp:314] Handling UPDATE
> for status update TASK_RUNNING from task 0 of framework
> 201304150352-1015726915-60471-27966-0000
> I0415 03:52:16.115521 28016 status_update_manager.cpp:289] Forwarding
> status update TASK_RUNNING from task 0 of framework
> 201304150352-1015726915-60471-27966-0000 to the master at
> master@67.195.138.60:60471
> I0415 03:52:16.116060 28012 master.cpp:1086] Status update from (824)@
> 67.195.138.60:60471: task 0 of framework
> 201304150352-1015726915-60471-27966-0000 is now in state TASK_RUNNING
> I0415 03:52:16.116063 28017 slave.cpp:1342] Sending ACK for status update
> TASK_RUNNING from task 0 of framework
> 201304150352-1015726915-60471-27966-0000 to executor executor(27)@
> 67.195.138.60:60471
> I0415 03:52:16.117076 28017 exec.cpp:289] Executor received ACK for status
> update of task 0 of framework 201304150352-1015726915-60471-27966-0000
> I0415 03:52:16.116580 28012 sched.cpp:327] Received status update
> TASK_RUNNING from task 0 of framework
> 201304150352-1015726915-60471-27966-0000 from slave(83)@
> 67.195.138.60:60471
> I0415 03:52:16.118093 28012 sched.cpp:360] Sending ACK for status update
> TASK_RUNNING from task 0 of framework
> 201304150352-1015726915-60471-27966-0000 to slave(83)@67.195.138.60:60471
> I0415 03:52:16.118615 28012 slave.cpp:979] Got acknowledgement of status
> update for task 0 of framework 201304150352-1015726915-60471-27966-0000
> I0415 03:52:16.118305 27966 master.cpp:477] Master terminating
> I0415 03:52:16.119169 28012 status_update_manager.cpp:314] Received status
> update acknowledgement for task 0 of framework
> 201304150352-1015726915-60471-27966-0000
> I0415 03:52:16.119724 28013 slave.cpp:1392] Process exited: @0.0.0.0:0
> W0415 03:52:16.186488 28013 slave.cpp:1395] WARNING! Master disconnected!
> Waiting for a new master to be elected.
> I0415 03:52:16.120364 28012 status_update_manager.hpp:314] Handling ACK
> for status update TASK_RUNNING from task 0 of framework
> 201304150352-1015726915-60471-27966-0000
> I0415 03:52:16.120265 28016 master.cpp:309] Master started on
> 67.195.138.60:60471
> I0415 03:52:16.186831 28011 detector.cpp:283] Master detector (
> master@67.195.138.60:60471) connected to ZooKeeper ...
> I0415 03:52:16.187080 28017 detector.cpp:485] Master detector
> (scheduler(75)@67.195.138.60:60471) found 0 registered masters
> I0415 03:52:16.187259 28015 detector.cpp:485] Master detector (slave(83)@
> 67.195.138.60:60471) found 0 registered masters
> I0415 03:52:16.196260 28012 slave.cpp:1016] Status update manager
> successfully handled status update acknowledgement for task 0 of framework
> 201304150352-1015726915-60471-27966-0000
> I0415 03:52:16.196817 28016 master.cpp:324] Master ID:
> 201304150352-1015726915-60471-27966
> I0415 03:52:16.205389 28011 detector.cpp:300] Trying to create path
> '/znode' in ZooKeeper
> I0415 03:52:16.215061 28017 detector.cpp:506] Master detector
> (scheduler(75)@67.195.138.60:60471) couldn't find any masters
> I0415 03:52:16.215571 28015 detector.cpp:506] Master detector (slave(83)@
> 67.195.138.60:60471) couldn't find any masters
> W0415 03:52:16.216775 28013 master.cpp:81] No whitelist given. Advertising
> offers for all slaves
> I0415 03:52:16.216907 28018 hierarchical_allocator_process.hpp:236]
> Initializing hierarchical allocator process with master :
> master@67.195.138.60:60471
> I0415 03:52:16.217649 28017 sched.cpp:193] No master detected, waiting for
> another master
> I0415 03:52:16.218143 28015 slave.cpp:479] Lost master(s) ... waiting
> I0415 03:52:16.290632 28011 detector.cpp:330] Created ephemeral/sequence
> znode at '/znode/0000000002'
> I0415 03:52:16.291086 28012 detector.cpp:485] Master detector
> (scheduler(75)@67.195.138.60:60471) found 1 registered masters
> I0415 03:52:16.291277 28015 detector.cpp:485] Master detector (slave(83)@
> 67.195.138.60:60471) found 1 registered masters
> I0415 03:52:16.291388 28011 detector.cpp:485] Master detector (
> master@67.195.138.60:60471) found 1 registered masters
> I0415 03:52:16.291739 28012 detector.cpp:531] Master detector
> (scheduler(75)@67.195.138.60:60471) got new master pid:
> master@67.195.138.60:60471
> I0415 03:52:16.292052 28015 detector.cpp:531] Master detector (slave(83)@
> 67.195.138.60:60471) got new master pid: master@67.195.138.60:60471
> I0415 03:52:16.293006 28015 slave.cpp:453] New master detected at
> master@67.195.138.60:60471
> I0415 03:52:16.292529 28012 sched.cpp:182] New master at
> master@67.195.138.60:60471
> I0415 03:52:16.292438 28011 detector.cpp:531] Master detector (
> master@67.195.138.60:60471) got new master pid:
> master@67.195.138.60:60471
> I0415 03:52:16.293545 28017 status_update_manager.cpp:132] New master
> detected at master@67.195.138.60:60471
> W0415 03:52:16.293617 28014 master.cpp:996] Ignoring re-register slave
> message from janus.apache.org since not elected yet
> I0415 03:52:16.295465 28014 master.cpp:603] Elected as master!
> I0415 03:52:16.917891 28013 hierarchical_allocator_process.hpp:660] Found
> available resources: cpus=1; mem=524; ports=[31000-32000]; disk=1024 on
> slave 201304150352-1015726915-60471-27966-0
> I0415 03:52:16.949961 28013 hierarchical_allocator_process.hpp:756]
> Filtered cpus=1; mem=524; ports=[31000-32000]; disk=1024 on slave
> 201304150352-1015726915-60471-27966-0 for framework
> 201304150352-1015726915-60471-27966-0000
> I0415 03:52:16.950294 28013 hierarchical_allocator_process.hpp:599]
> Performed allocation for 1 slaves in 32.45ms
> I0415 03:52:17.060214 28011 master.cpp:1029] Attempting to re-register
> slave 201304150352-1015726915-60471-27966-0 at slave(83)@
> 67.195.138.60:60471 (janus.apache.org)
> I0415 03:52:17.060259 28011 master.cpp:1224] Master now considering a
> slave at janus.apache.org:60471 as active
> I0415 03:52:17.060606 28011 master.cpp:1862] Adding slave
> 201304150352-1015726915-60471-27966-0 at janus.apache.org with cpus=2;
> mem=1024; ports=[31000-32000]; disk=1024
> I0415 03:52:17.061087 28017 slave.cpp:520] Re-registered with master
> I0415 03:52:17.061118 28011 master.hpp:289] Adding task with resources
> cpus=1; mem=500 on slave 201304150352-1015726915-60471-27966-0
> W0415 03:52:17.061993 28011 master.cpp:1948] Possibly orphaned task 0 of
> framework 201304150352-1015726915-60471-27966-0000 running on slave
> 201304150352-1015726915-60471-27966-0 (janus.apache.org)
> I0415 03:52:17.062723 28011 hierarchical_allocator_process.hpp:395] Added
> slave 201304150352-1015726915-60471-27966-0 (janus.apache.org) with
> cpus=2; mem=1024; ports=[31000-32000]; disk=1024 (and cpus=1; mem=524;
> ports=[31000-32000]; disk=1024 available)
> I0415 03:52:17.063420 28011 hierarchical_allocator_process.hpp:632] No
> users to allocate resources!
> I0415 03:52:17.063848 28011 hierarchical_allocator_process.hpp:619]
> Performed allocation for slave 201304150352-1015726915-60471-27966-0 in
> 428.89us
> I0415 03:52:17.241173 28013 hierarchical_allocator_process.hpp:632] No
> users to allocate resources!
> I0415 03:52:17.241243 28013 hierarchical_allocator_process.hpp:599]
> Performed allocation for 1 slaves in 73.92us
> I0415 03:52:17.294363 28016 master.cpp:681] Re-registering framework
> 201304150352-1015726915-60471-27966-0000 at scheduler(75)@
> 67.195.138.60:60471
> I0415 03:52:17.294672 28016 slave.cpp:956] Updating framework
> 201304150352-1015726915-60471-27966-0000 pid to scheduler(75)@
> 67.195.138.60:60471
> I0415 03:52:17.294653 28012 sched.cpp:217] Framework registered with
> 201304150352-1015726915-60471-27966-0000
> I0415 03:52:17.294734 28011 hierarchical_allocator_process.hpp:268] Added
> framework 201304150352-1015726915-60471-27966-0000
> I0415 03:52:17.344810 28011 hierarchical_allocator_process.hpp:660] Found
> available resources: cpus=1; mem=524; ports=[31000-32000]; disk=1024 on
> slave 201304150352-1015726915-60471-27966-0
> I0415 03:52:17.345317 28011 hierarchical_allocator_process.hpp:686]
> Offering cpus=1; mem=524; ports=[31000-32000]; disk=1024 on slave
> 201304150352-1015726915-60471-27966-0 to framework
> 201304150352-1015726915-60471-27966-0000
> I0415 03:52:17.345898 28011 hierarchical_allocator_process.hpp:599]
> Performed allocation for 1 slaves in 1.10ms
> I0415 03:52:17.345988 28018 master.hpp:309] Adding offer with resources
> cpus=1; mem=524; ports=[31000-32000]; disk=1024 on slave
> 201304150352-1015726915-60471-27966-0
> I0415 03:52:17.346806 28018 master.cpp:1327] Sending 1 offers to framework
> 201304150352-1015726915-60471-27966-0000
> I0415 03:52:17.347316 28017 sched.cpp:282] Received 1 offers
> I0415 03:52:17.348103 28012 sched.cpp:422] Stopping framework
> '201304150352-1015726915-60471-27966-0000'
> I0415 03:52:17.348254 28015 master.cpp:774] Asked to unregister framework
> 201304150352-1015726915-60471-27966-0000
> I0415 03:52:17.348747 28017 slave.cpp:889] Asked to shut down framework
> 201304150352-1015726915-60471-27966-0000 by master@67.195.138.60:60471
> I0415 03:52:17.349159 28017 slave.cpp:894] Shutting down framework
> 201304150352-1015726915-60471-27966-0000
> I0415 03:52:17.349648 28017 slave.cpp:1681] Shutting down executor
> 'default' of framework 201304150352-1015726915-60471-27966-0000
> I0415 03:52:17.350154 28013 exec.cpp:321] Executor asked to shutdown
> I0415 03:52:17.348780 28018 hierarchical_allocator_process.hpp:359]
> Deactivated framework 201304150352-1015726915-60471-27966-0000
> I0415 03:52:17.350172 28017 status_update_manager.cpp:233] Closing status
> update streams for framework 201304150352-1015726915-60471-27966-0000
> I0415 03:52:17.351585 28017 status_update_manager.cpp:434] Cleaning up
> status update stream for task 0 of framework
> 201304150352-1015726915-60471-27966-0000
> I0415 03:52:17.348753 28015 master.hpp:300] Removing task with resources
> cpus=1; mem=500 on slave 201304150352-1015726915-60471-27966-0
> I0415 03:52:17.352645 28015 master.hpp:318] Removing offer with resources
> cpus=1; mem=524; ports=[31000-32000]; disk=1024 on slave
> 201304150352-1015726915-60471-27966-0
> I0415 03:52:17.352738 28014 hierarchical_allocator_process.hpp:544]
> Recovered cpus=1; mem=500 (total allocatable: cpus=1; mem=500; ports=[];
> disk=0) on slave 201304150352-1015726915-60471-27966-0 from framework
> 201304150352-1015726915-60471-27966-0000
> I0415 03:52:17.354449 28018 slave.cpp:386] Slave terminating
> I0415 03:52:17.355085 28018 slave.cpp:889] Asked to shut down framework
> 201304150352-1015726915-60471-27966-0000 by @0.0.0.0:0
> I0415 03:52:17.355623 28018 slave.cpp:894] Shutting down framework
> 201304150352-1015726915-60471-27966-0000
> I0415 03:52:17.354775 28014 hierarchical_allocator_process.hpp:544]
> Recovered cpus=1; mem=524; ports=[31000-32000]; disk=1024 (total
> allocatable: cpus=2; mem=1024; ports=[31000-32000]; disk=1024) on slave
> 201304150352-1015726915-60471-27966-0 from framework
> 201304150352-1015726915-60471-27966-0000
> I0415 03:52:17.356153 28018 slave.cpp:1681] Shutting down executor
> 'default' of framework 201304150352-1015726915-60471-27966-0000
> I0415 03:52:17.357228 28015 status_update_manager.cpp:233] Closing status
> update streams for framework 201304150352-1015726915-60471-27966-0000
> I0415 03:52:17.357238 28018 master.cpp:537] Slave
> 201304150352-1015726915-60471-27966-0(janus.apache.org) disconnected
> I0415 03:52:17.358275 28018 master.cpp:542] Removing disconnected slave
> 201304150352-1015726915-60471-27966-0(janus.apache.org) because it is not
> checkpointing!
> I0415 03:52:17.358933 27966 master.cpp:477] Master terminating
> I0415 03:52:17.359760 27966 master.cpp:283] Shutting down master
> I0415 03:52:17.381469 27966 master.cpp:283] Shutting down master
> I0415 03:52:17.381543 27966 master.hpp:300] Removing task with resources
> cpus=1; mem=500 on slave 201304150352-1015726915-60471-27966-0
> I0415 03:52:17.381575 28011 hierarchical_allocator_process.hpp:359]
> Deactivated framework 201304150352-1015726915-60471-27966-0000
> I0415 03:52:17.382721 28011 hierarchical_allocator_process.hpp:544]
> Recovered cpus=1; mem=500 (total allocatable: cpus=2; mem=1024;
> ports=[31000-32000]; disk=1024) on slave
> 201304150352-1015726915-60471-27966-0 from framework
> 201304150352-1015726915-60471-27966-0000
> I0415 03:52:17.383054 28011 hierarchical_allocator_process.hpp:312]
> Removed framework 201304150352-1015726915-60471-27966-0000
> I0415 03:52:17.383503 28011 hierarchical_allocator_process.hpp:423]
> Removed slave 201304150352-1015726915-60471-27966-0
> I0415 03:52:17.394901 27966 zookeeper_test_server.cpp:195] Shutdown
> ZooKeeperTestServer on port 53584
> [ OK ] AllocatorZooKeeperTest/0.SlaveReregistersFirst (1489 ms)
> [----------] 2 tests from AllocatorZooKeeperTest/0 (3731 ms total)
>
> [----------] Global test environment tear-down
> [==========] 190 tests from 39 test cases ran. (95876 ms total)
> [ PASSED ] 189 tests.
> [ FAILED ] 1 test, listed below:
> [ FAILED ] FaultToleranceTest.SchedulerFailover
>
> 1 FAILED TEST
> YOU HAVE 1 DISABLED TEST
>
> FAIL: mesos-tests
> ==================
> 1 of 1 test failed
> ==================
> make[3]: *** [check-TESTS] Error 1
> make[3]: Leaving directory `<
> https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/ws/src
> '>
> make[2]: *** [check-am] Error 2
> make[2]: Leaving directory `<
> https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/ws/src
> '>
> make[1]: *** [check] Error 2
> make[1]: Leaving directory `<
> https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/ws/src
> '>
> make: *** [check-recursive] Error 1
> Build step 'Execute shell' marked build as failure
>
Build failed in Jenkins:
Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME #303
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/303/changes>
Changes:
[bmahler] Replaced sleep() and usleep() calls with os::sleep().
From: Jiang Yan Xu <ya...@jxu.me>
Review: https://reviews.apache.org/r/10443
[bmahler] Replaced usleep() calls in libprocess with os::sleep().
From: Jiang Yan Xu <ya...@jxu.me>
Review: https://reviews.apache.org/r/10241
[bmahler] Changed os::sleep() to take a Duration instead of a double.
From: Jiang Yan Xu <ya...@jxu.me>
Review: https://reviews.apache.org/r/10231
------------------------------------------
[...truncated 15692 lines...]
I0415 03:52:14.867821 28013 detector.cpp:531] Master detector (slave(82)@67.195.138.60:60471) got new master pid: master@67.195.138.60:60471
I0415 03:52:14.869232 28013 slave.cpp:453] New master detected at master@67.195.138.60:60471
W0415 03:52:14.868774 28018 master.cpp:668] Ignoring re-register framework message since not elected yet
I0415 03:52:14.868716 28011 detector.cpp:531] Master detector (master@67.195.138.60:60471) got new master pid: master@67.195.138.60:60471
I0415 03:52:14.869796 28013 status_update_manager.cpp:132] New master detected at master@67.195.138.60:60471
I0415 03:52:14.870738 28011 master.cpp:603] Elected as master!
I0415 03:52:15.710227 28016 hierarchical_allocator_process.hpp:660] Found available resources: cpus=1; mem=524; ports=[31000-32000]; disk=1024 on slave 201304150352-1015726915-60471-27966-0
I0415 03:52:15.750718 28016 hierarchical_allocator_process.hpp:756] Filtered cpus=1; mem=524; ports=[31000-32000]; disk=1024 on slave 201304150352-1015726915-60471-27966-0 for framework 201304150352-1015726915-60471-27966-0000
I0415 03:52:15.751005 28016 hierarchical_allocator_process.hpp:599] Performed allocation for 1 slaves in 40.82ms
I0415 03:52:15.778457 28015 master.cpp:681] Re-registering framework 201304150352-1015726915-60471-27966-0000 at scheduler(74)@67.195.138.60:60471
I0415 03:52:15.778777 28017 sched.cpp:217] Framework registered with 201304150352-1015726915-60471-27966-0000
I0415 03:52:15.778832 28015 hierarchical_allocator_process.hpp:268] Added framework 201304150352-1015726915-60471-27966-0000
I0415 03:52:15.779409 28015 hierarchical_allocator_process.hpp:668] No resources available to allocate!
I0415 03:52:15.779876 28015 hierarchical_allocator_process.hpp:599] Performed allocation for 0 slaves in 468.78us
I0415 03:52:15.825428 28017 hierarchical_allocator_process.hpp:668] No resources available to allocate!
I0415 03:52:15.825634 28017 hierarchical_allocator_process.hpp:599] Performed allocation for 0 slaves in 232.74us
I0415 03:52:15.870821 28017 master.cpp:1029] Attempting to re-register slave 201304150352-1015726915-60471-27966-0 at slave(82)@67.195.138.60:60471 (janus.apache.org)
I0415 03:52:15.870980 28017 master.cpp:1224] Master now considering a slave at janus.apache.org:60471 as active
I0415 03:52:15.871337 28017 master.cpp:1862] Adding slave 201304150352-1015726915-60471-27966-0 at janus.apache.org with cpus=2; mem=1024; ports=[31000-32000]; disk=1024
I0415 03:52:15.871814 28013 slave.cpp:520] Re-registered with master
I0415 03:52:15.871881 28017 master.hpp:289] Adding task with resources cpus=1; mem=500 on slave 201304150352-1015726915-60471-27966-0
I0415 03:52:15.872872 28012 slave.cpp:956] Updating framework 201304150352-1015726915-60471-27966-0000 pid to scheduler(74)@67.195.138.60:60471
I0415 03:52:15.872985 28015 hierarchical_allocator_process.hpp:395] Added slave 201304150352-1015726915-60471-27966-0 (janus.apache.org) with cpus=2; mem=1024; ports=[31000-32000]; disk=1024 (and cpus=1; mem=524; ports=[31000-32000]; disk=1024 available)
I0415 03:52:15.873723 28015 hierarchical_allocator_process.hpp:660] Found available resources: cpus=1; mem=524; ports=[31000-32000]; disk=1024 on slave 201304150352-1015726915-60471-27966-0
I0415 03:52:15.874207 28015 hierarchical_allocator_process.hpp:686] Offering cpus=1; mem=524; ports=[31000-32000]; disk=1024 on slave 201304150352-1015726915-60471-27966-0 to framework 201304150352-1015726915-60471-27966-0000
I0415 03:52:15.874761 28015 hierarchical_allocator_process.hpp:619] Performed allocation for slave 201304150352-1015726915-60471-27966-0 in 1.05ms
I0415 03:52:15.874876 28011 master.hpp:309] Adding offer with resources cpus=1; mem=524; ports=[31000-32000]; disk=1024 on slave 201304150352-1015726915-60471-27966-0
I0415 03:52:15.875663 28011 master.cpp:1327] Sending 1 offers to framework 201304150352-1015726915-60471-27966-0000
I0415 03:52:15.876142 28014 sched.cpp:282] Received 1 offers
I0415 03:52:15.877135 28018 sched.cpp:422] Stopping framework '201304150352-1015726915-60471-27966-0000'
I0415 03:52:15.877218 28011 master.cpp:774] Asked to unregister framework 201304150352-1015726915-60471-27966-0000
I0415 03:52:15.877617 28018 slave.cpp:889] Asked to shut down framework 201304150352-1015726915-60471-27966-0000 by master@67.195.138.60:60471
I0415 03:52:15.877672 28017 hierarchical_allocator_process.hpp:359] Deactivated framework 201304150352-1015726915-60471-27966-0000
I0415 03:52:15.877657 28011 master.hpp:300] Removing task with resources cpus=1; mem=500 on slave 201304150352-1015726915-60471-27966-0
I0415 03:52:15.877977 28018 slave.cpp:894] Shutting down framework 201304150352-1015726915-60471-27966-0000
I0415 03:52:15.885417 28017 hierarchical_allocator_process.hpp:544] Recovered cpus=1; mem=500 (total allocatable: cpus=1; mem=500; ports=[]; disk=0) on slave 201304150352-1015726915-60471-27966-0 from framework 201304150352-1015726915-60471-27966-0000
I0415 03:52:15.885397 28011 master.hpp:318] Removing offer with resources cpus=1; mem=524; ports=[31000-32000]; disk=1024 on slave 201304150352-1015726915-60471-27966-0
I0415 03:52:15.885673 28018 slave.cpp:1681] Shutting down executor 'default' of framework 201304150352-1015726915-60471-27966-0000
I0415 03:52:15.886265 28017 hierarchical_allocator_process.hpp:544] Recovered cpus=1; mem=524; ports=[31000-32000]; disk=1024 (total allocatable: cpus=2; mem=1024; ports=[31000-32000]; disk=1024) on slave 201304150352-1015726915-60471-27966-0 from framework 201304150352-1015726915-60471-27966-0000
I0415 03:52:15.887142 28014 exec.cpp:321] Executor asked to shutdown
I0415 03:52:15.887159 28018 slave.cpp:386] Slave terminating
I0415 03:52:15.887166 28016 status_update_manager.cpp:233] Closing status update streams for framework 201304150352-1015726915-60471-27966-0000
I0415 03:52:15.889034 28016 status_update_manager.cpp:434] Cleaning up status update stream for task 0 of framework 201304150352-1015726915-60471-27966-0000
I0415 03:52:15.888540 28018 slave.cpp:889] Asked to shut down framework 201304150352-1015726915-60471-27966-0000 by @0.0.0.0:0
I0415 03:52:15.889957 28018 slave.cpp:894] Shutting down framework 201304150352-1015726915-60471-27966-0000
I0415 03:52:15.890426 28018 slave.cpp:1681] Shutting down executor 'default' of framework 201304150352-1015726915-60471-27966-0000
I0415 03:52:15.890962 28013 status_update_manager.cpp:233] Closing status update streams for framework 201304150352-1015726915-60471-27966-0000
I0415 03:52:15.891006 28015 master.cpp:537] Slave 201304150352-1015726915-60471-27966-0(janus.apache.org) disconnected
I0415 03:52:15.891890 28015 master.cpp:542] Removing disconnected slave 201304150352-1015726915-60471-27966-0(janus.apache.org) because it is not checkpointing!
I0415 03:52:15.892469 28017 master.cpp:477] Master terminating
I0415 03:52:15.893165 27966 master.cpp:283] Shutting down master
I0415 03:52:15.893846 27966 master.cpp:283] Shutting down master
I0415 03:52:15.893923 28013 hierarchical_allocator_process.hpp:359] Deactivated framework 201304150352-1015726915-60471-27966-0000
I0415 03:52:15.893959 27966 master.hpp:300] Removing task with resources cpus=1; mem=500 on slave 201304150352-1015726915-60471-27966-0
I0415 03:52:15.896077 28016 hierarchical_allocator_process.hpp:544] Recovered cpus=1; mem=500 (total allocatable: cpus=2; mem=1024; ports=[31000-32000]; disk=1024) on slave 201304150352-1015726915-60471-27966-0 from framework 201304150352-1015726915-60471-27966-0000
I0415 03:52:15.896258 28016 hierarchical_allocator_process.hpp:312] Removed framework 201304150352-1015726915-60471-27966-0000
I0415 03:52:15.896742 28016 hierarchical_allocator_process.hpp:423] Removed slave 201304150352-1015726915-60471-27966-0
I0415 03:52:15.905767 27966 zookeeper_test_server.cpp:195] Shutdown ZooKeeperTestServer on port 47833
[ OK ] AllocatorZooKeeperTest/0.FrameworkReregistersFirst (2242 ms)
[ RUN ] AllocatorZooKeeperTest/0.SlaveReregistersFirst
I0415 03:52:15.907378 27966 jvm.cpp:34] looking up method <init>(Ljava/lang/String;)V
I0415 03:52:15.907512 27966 jvm.cpp:34] looking up method <init>(I)V
I0415 03:52:15.907819 27966 jvm.cpp:34] looking up method <init>(Ljava/net/InetSocketAddress;)V
I0415 03:52:15.908318 27966 jvm.cpp:34] looking up method startup(Lorg/apache/zookeeper/server/ZooKeeperServer;)V
I0415 03:52:15.908787 27966 jvm.cpp:34] looking up method isAlive()Z
I0415 03:52:15.909245 27966 jvm.cpp:34] looking up method shutdown()V
I0415 03:52:15.912058 27966 jvm.cpp:34] looking up method <init>(Ljava/io/File;Ljava/io/File;)V
I0415 03:52:15.912618 27966 jvm.cpp:34] looking up method <init>()V
I0415 03:52:15.912720 27966 jvm.cpp:34] looking up method <init>(Lorg/apache/zookeeper/server/persistence/FileTxnSnapLog;Lorg/apache/zookeeper/server/ZooKeeperServer$DataTreeBuilder;)V
I0415 03:52:15.913173 27966 jvm.cpp:34] looking up method getClientPort()I
I0415 03:52:15.913513 27966 jvm.cpp:34] looking up method closeSession(J)V
I0415 03:52:15.915868 27966 zookeeper_test_server.cpp:212] Started ZooKeeperTestServer on port 53584
I0415 03:52:15.916173 28011 master.cpp:309] Master started on 67.195.138.60:60471
I0415 03:52:15.916242 28011 master.cpp:324] Master ID: 201304150352-1015726915-60471-27966
I0415 03:52:15.916827 28014 hierarchical_allocator_process.hpp:236] Initializing hierarchical allocator process with master : master@67.195.138.60:60471
W0415 03:52:15.916849 28017 master.cpp:81] No whitelist given. Advertising offers for all slaves
I0415 03:52:15.916645 28013 slave.cpp:203] Slave started on 83)@67.195.138.60:60471
I0415 03:52:15.918356 28013 slave.cpp:204] Slave resources: cpus=2; mem=1024; ports=[31000-32000]; disk=1024
I0415 03:52:15.920147 28012 slave.cpp:377] Finished recovery
I0415 03:52:15.974617 28017 detector.cpp:283] Master detector (master@67.195.138.60:60471) connected to ZooKeeper ...
I0415 03:52:15.974661 28017 detector.cpp:300] Trying to create path '/znode' in ZooKeeper
I0415 03:52:15.975020 28014 detector.cpp:283] Master detector (slave(83)@67.195.138.60:60471) connected to ZooKeeper ...
I0415 03:52:15.975471 28014 detector.cpp:300] Trying to create path '/znode' in ZooKeeper
I0415 03:52:15.986569 28011 detector.cpp:283] Master detector (scheduler(75)@67.195.138.60:60471) connected to ZooKeeper ...
I0415 03:52:15.986613 28011 detector.cpp:300] Trying to create path '/znode' in ZooKeeper
I0415 03:52:16.031102 28014 detector.cpp:485] Master detector (slave(83)@67.195.138.60:60471) found 0 registered masters
I0415 03:52:16.031152 28014 detector.cpp:506] Master detector (slave(83)@67.195.138.60:60471) couldn't find any masters
I0415 03:52:16.031517 28014 slave.cpp:479] Lost master(s) ... waiting
I0415 03:52:16.053187 28017 detector.cpp:330] Created ephemeral/sequence znode at '/znode/0000000000'
I0415 03:52:16.053555 28011 detector.cpp:485] Master detector (scheduler(75)@67.195.138.60:60471) found 1 registered masters
I0415 03:52:16.053598 28018 detector.cpp:485] Master detector (slave(83)@67.195.138.60:60471) found 1 registered masters
I0415 03:52:16.053761 28017 detector.cpp:485] Master detector (master@67.195.138.60:60471) found 1 registered masters
I0415 03:52:16.056705 28011 detector.cpp:531] Master detector (scheduler(75)@67.195.138.60:60471) got new master pid: master@67.195.138.60:60471
I0415 03:52:16.057068 28018 detector.cpp:531] Master detector (slave(83)@67.195.138.60:60471) got new master pid: master@67.195.138.60:60471
I0415 03:52:16.057497 28017 detector.cpp:531] Master detector (master@67.195.138.60:60471) got new master pid: master@67.195.138.60:60471
I0415 03:52:16.057570 28011 sched.cpp:182] New master at master@67.195.138.60:60471
I0415 03:52:16.058527 28018 slave.cpp:453] New master detected at master@67.195.138.60:60471
I0415 03:52:16.058948 28017 master.cpp:603] Elected as master!
I0415 03:52:16.059919 28013 status_update_manager.cpp:132] New master detected at master@67.195.138.60:60471
I0415 03:52:16.060400 28017 master.cpp:646] Registering framework 201304150352-1015726915-60471-27966-0000 at scheduler(75)@67.195.138.60:60471
I0415 03:52:16.061298 28014 sched.cpp:217] Framework registered with 201304150352-1015726915-60471-27966-0000
I0415 03:52:16.061336 28012 hierarchical_allocator_process.hpp:268] Added framework 201304150352-1015726915-60471-27966-0000
I0415 03:52:16.062196 28012 hierarchical_allocator_process.hpp:668] No resources available to allocate!
I0415 03:52:16.062657 28012 hierarchical_allocator_process.hpp:599] Performed allocation for 0 slaves in 463.10us
I0415 03:52:16.061337 28017 master.cpp:968] Attempting to register slave on janus.apache.org at slave(83)@67.195.138.60:60471
I0415 03:52:16.063691 28017 master.cpp:1224] Master now considering a slave at janus.apache.org:60471 as active
I0415 03:52:16.064242 28017 master.cpp:1862] Adding slave 201304150352-1015726915-60471-27966-0 at janus.apache.org with cpus=2; mem=1024; ports=[31000-32000]; disk=1024
I0415 03:52:16.064872 28015 slave.cpp:487] Registered with master; given slave ID 201304150352-1015726915-60471-27966-0
I0415 03:52:16.064906 28017 hierarchical_allocator_process.hpp:395] Added slave 201304150352-1015726915-60471-27966-0 (janus.apache.org) with cpus=2; mem=1024; ports=[31000-32000]; disk=1024 (and cpus=2; mem=1024; ports=[31000-32000]; disk=1024 available)
I0415 03:52:16.066014 28017 hierarchical_allocator_process.hpp:660] Found available resources: cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201304150352-1015726915-60471-27966-0
I0415 03:52:16.066556 28017 hierarchical_allocator_process.hpp:686] Offering cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201304150352-1015726915-60471-27966-0 to framework 201304150352-1015726915-60471-27966-0000
I0415 03:52:16.067203 28017 hierarchical_allocator_process.hpp:619] Performed allocation for slave 201304150352-1015726915-60471-27966-0 in 1.20ms
I0415 03:52:16.067248 28015 master.hpp:309] Adding offer with resources cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201304150352-1015726915-60471-27966-0
I0415 03:52:16.068080 28015 master.cpp:1327] Sending 1 offers to framework 201304150352-1015726915-60471-27966-0000
I0415 03:52:16.068614 28013 sched.cpp:282] Received 1 offers
I0415 03:52:16.069325 28011 master.cpp:1534] Processing reply for offer 201304150352-1015726915-60471-27966-0 on slave 201304150352-1015726915-60471-27966-0 (janus.apache.org) for framework 201304150352-1015726915-60471-27966-0000
I0415 03:52:16.069624 28011 master.hpp:289] Adding task with resources cpus=1; mem=500 on slave 201304150352-1015726915-60471-27966-0
I0415 03:52:16.070015 28011 master.cpp:1651] Launching task 0 of framework 201304150352-1015726915-60471-27966-0000 with resources cpus=1; mem=500 on slave 201304150352-1015726915-60471-27966-0 (janus.apache.org)
I0415 03:52:16.070535 28015 slave.cpp:587] Got assigned task 0 for framework 201304150352-1015726915-60471-27966-0000
I0415 03:52:16.072350 28015 paths.hpp:302] Created executor directory '/tmp/AllocatorZooKeeperTest_0_SlaveReregistersFirst_Ern3zU/slaves/201304150352-1015726915-60471-27966-0/frameworks/201304150352-1015726915-60471-27966-0000/executors/default/runs/707fea91-d760-4884-a29d-bf387467c868'
I0415 03:52:16.070592 28018 hierarchical_allocator_process.hpp:471] Framework 201304150352-1015726915-60471-27966-0000 left cpus=1; mem=524; ports=[31000-32000]; disk=1024 unused on slave 201304150352-1015726915-60471-27966-0
I0415 03:52:16.072819 28018 hierarchical_allocator_process.hpp:497] Framework 201304150352-1015726915-60471-27966-0000 filtered slave 201304150352-1015726915-60471-27966-0 for 5.00secs
I0415 03:52:16.072558 28017 slave.cpp:436] Successfully attached file '/tmp/AllocatorZooKeeperTest_0_SlaveReregistersFirst_Ern3zU/slaves/201304150352-1015726915-60471-27966-0/frameworks/201304150352-1015726915-60471-27966-0000/executors/default/runs/707fea91-d760-4884-a29d-bf387467c868'
I0415 03:52:16.072614 28015 exec.cpp:170] Executor started at: executor(27)@67.195.138.60:60471 with pid 27966
I0415 03:52:16.070593 28011 master.hpp:318] Removing offer with resources cpus=2; mem=1024; ports=[31000-32000]; disk=1024 on slave 201304150352-1015726915-60471-27966-0
I0415 03:52:16.107143 28015 slave.cpp:1046] Got registration for executor 'default' of framework 201304150352-1015726915-60471-27966-0000
I0415 03:52:16.108271 28015 slave.cpp:1121] Flushing queued tasks for framework 201304150352-1015726915-60471-27966-0000
I0415 03:52:16.108311 28016 exec.cpp:194] Executor registered on slave 201304150352-1015726915-60471-27966-0
I0415 03:52:16.109413 28016 exec.cpp:258] Executor asked to run task '0'
I0415 03:52:16.110012 28016 exec.cpp:382] Executor sending status update for task 0 in state TASK_RUNNING
I0415 03:52:16.111738 28016 slave.cpp:1232] Handling status update TASK_RUNNING from task 0 of framework 201304150352-1015726915-60471-27966-0000
I0415 03:52:16.111771 28016 slave.cpp:1280] Forwarding status update TASK_RUNNING from task 0 of framework 201304150352-1015726915-60471-27966-0000 to the status update manager
I0415 03:52:16.112221 28016 status_update_manager.cpp:254] Received status update TASK_RUNNING from task 0 of framework 201304150352-1015726915-60471-27966-0000
I0415 03:52:16.112695 28016 status_update_manager.cpp:403] Creating StatusUpdate stream for task 0 of framework 201304150352-1015726915-60471-27966-0000
I0415 03:52:16.113306 28016 status_update_manager.hpp:314] Handling UPDATE for status update TASK_RUNNING from task 0 of framework 201304150352-1015726915-60471-27966-0000
I0415 03:52:16.115521 28016 status_update_manager.cpp:289] Forwarding status update TASK_RUNNING from task 0 of framework 201304150352-1015726915-60471-27966-0000 to the master at master@67.195.138.60:60471
I0415 03:52:16.116060 28012 master.cpp:1086] Status update from (824)@67.195.138.60:60471: task 0 of framework 201304150352-1015726915-60471-27966-0000 is now in state TASK_RUNNING
I0415 03:52:16.116063 28017 slave.cpp:1342] Sending ACK for status update TASK_RUNNING from task 0 of framework 201304150352-1015726915-60471-27966-0000 to executor executor(27)@67.195.138.60:60471
I0415 03:52:16.117076 28017 exec.cpp:289] Executor received ACK for status update of task 0 of framework 201304150352-1015726915-60471-27966-0000
I0415 03:52:16.116580 28012 sched.cpp:327] Received status update TASK_RUNNING from task 0 of framework 201304150352-1015726915-60471-27966-0000 from slave(83)@67.195.138.60:60471
I0415 03:52:16.118093 28012 sched.cpp:360] Sending ACK for status update TASK_RUNNING from task 0 of framework 201304150352-1015726915-60471-27966-0000 to slave(83)@67.195.138.60:60471
I0415 03:52:16.118615 28012 slave.cpp:979] Got acknowledgement of status update for task 0 of framework 201304150352-1015726915-60471-27966-0000
I0415 03:52:16.118305 27966 master.cpp:477] Master terminating
I0415 03:52:16.119169 28012 status_update_manager.cpp:314] Received status update acknowledgement for task 0 of framework 201304150352-1015726915-60471-27966-0000
I0415 03:52:16.119724 28013 slave.cpp:1392] Process exited: @0.0.0.0:0
W0415 03:52:16.186488 28013 slave.cpp:1395] WARNING! Master disconnected! Waiting for a new master to be elected.
I0415 03:52:16.120364 28012 status_update_manager.hpp:314] Handling ACK for status update TASK_RUNNING from task 0 of framework 201304150352-1015726915-60471-27966-0000
I0415 03:52:16.120265 28016 master.cpp:309] Master started on 67.195.138.60:60471
I0415 03:52:16.186831 28011 detector.cpp:283] Master detector (master@67.195.138.60:60471) connected to ZooKeeper ...
I0415 03:52:16.187080 28017 detector.cpp:485] Master detector (scheduler(75)@67.195.138.60:60471) found 0 registered masters
I0415 03:52:16.187259 28015 detector.cpp:485] Master detector (slave(83)@67.195.138.60:60471) found 0 registered masters
I0415 03:52:16.196260 28012 slave.cpp:1016] Status update manager successfully handled status update acknowledgement for task 0 of framework 201304150352-1015726915-60471-27966-0000
I0415 03:52:16.196817 28016 master.cpp:324] Master ID: 201304150352-1015726915-60471-27966
I0415 03:52:16.205389 28011 detector.cpp:300] Trying to create path '/znode' in ZooKeeper
I0415 03:52:16.215061 28017 detector.cpp:506] Master detector (scheduler(75)@67.195.138.60:60471) couldn't find any masters
I0415 03:52:16.215571 28015 detector.cpp:506] Master detector (slave(83)@67.195.138.60:60471) couldn't find any masters
W0415 03:52:16.216775 28013 master.cpp:81] No whitelist given. Advertising offers for all slaves
I0415 03:52:16.216907 28018 hierarchical_allocator_process.hpp:236] Initializing hierarchical allocator process with master : master@67.195.138.60:60471
I0415 03:52:16.217649 28017 sched.cpp:193] No master detected, waiting for another master
I0415 03:52:16.218143 28015 slave.cpp:479] Lost master(s) ... waiting
I0415 03:52:16.290632 28011 detector.cpp:330] Created ephemeral/sequence znode at '/znode/0000000002'
I0415 03:52:16.291086 28012 detector.cpp:485] Master detector (scheduler(75)@67.195.138.60:60471) found 1 registered masters
I0415 03:52:16.291277 28015 detector.cpp:485] Master detector (slave(83)@67.195.138.60:60471) found 1 registered masters
I0415 03:52:16.291388 28011 detector.cpp:485] Master detector (master@67.195.138.60:60471) found 1 registered masters
I0415 03:52:16.291739 28012 detector.cpp:531] Master detector (scheduler(75)@67.195.138.60:60471) got new master pid: master@67.195.138.60:60471
I0415 03:52:16.292052 28015 detector.cpp:531] Master detector (slave(83)@67.195.138.60:60471) got new master pid: master@67.195.138.60:60471
I0415 03:52:16.293006 28015 slave.cpp:453] New master detected at master@67.195.138.60:60471
I0415 03:52:16.292529 28012 sched.cpp:182] New master at master@67.195.138.60:60471
I0415 03:52:16.292438 28011 detector.cpp:531] Master detector (master@67.195.138.60:60471) got new master pid: master@67.195.138.60:60471
I0415 03:52:16.293545 28017 status_update_manager.cpp:132] New master detected at master@67.195.138.60:60471
W0415 03:52:16.293617 28014 master.cpp:996] Ignoring re-register slave message from janus.apache.org since not elected yet
I0415 03:52:16.295465 28014 master.cpp:603] Elected as master!
I0415 03:52:16.917891 28013 hierarchical_allocator_process.hpp:660] Found available resources: cpus=1; mem=524; ports=[31000-32000]; disk=1024 on slave 201304150352-1015726915-60471-27966-0
I0415 03:52:16.949961 28013 hierarchical_allocator_process.hpp:756] Filtered cpus=1; mem=524; ports=[31000-32000]; disk=1024 on slave 201304150352-1015726915-60471-27966-0 for framework 201304150352-1015726915-60471-27966-0000
I0415 03:52:16.950294 28013 hierarchical_allocator_process.hpp:599] Performed allocation for 1 slaves in 32.45ms
I0415 03:52:17.060214 28011 master.cpp:1029] Attempting to re-register slave 201304150352-1015726915-60471-27966-0 at slave(83)@67.195.138.60:60471 (janus.apache.org)
I0415 03:52:17.060259 28011 master.cpp:1224] Master now considering a slave at janus.apache.org:60471 as active
I0415 03:52:17.060606 28011 master.cpp:1862] Adding slave 201304150352-1015726915-60471-27966-0 at janus.apache.org with cpus=2; mem=1024; ports=[31000-32000]; disk=1024
I0415 03:52:17.061087 28017 slave.cpp:520] Re-registered with master
I0415 03:52:17.061118 28011 master.hpp:289] Adding task with resources cpus=1; mem=500 on slave 201304150352-1015726915-60471-27966-0
W0415 03:52:17.061993 28011 master.cpp:1948] Possibly orphaned task 0 of framework 201304150352-1015726915-60471-27966-0000 running on slave 201304150352-1015726915-60471-27966-0 (janus.apache.org)
I0415 03:52:17.062723 28011 hierarchical_allocator_process.hpp:395] Added slave 201304150352-1015726915-60471-27966-0 (janus.apache.org) with cpus=2; mem=1024; ports=[31000-32000]; disk=1024 (and cpus=1; mem=524; ports=[31000-32000]; disk=1024 available)
I0415 03:52:17.063420 28011 hierarchical_allocator_process.hpp:632] No users to allocate resources!
I0415 03:52:17.063848 28011 hierarchical_allocator_process.hpp:619] Performed allocation for slave 201304150352-1015726915-60471-27966-0 in 428.89us
I0415 03:52:17.241173 28013 hierarchical_allocator_process.hpp:632] No users to allocate resources!
I0415 03:52:17.241243 28013 hierarchical_allocator_process.hpp:599] Performed allocation for 1 slaves in 73.92us
I0415 03:52:17.294363 28016 master.cpp:681] Re-registering framework 201304150352-1015726915-60471-27966-0000 at scheduler(75)@67.195.138.60:60471
I0415 03:52:17.294672 28016 slave.cpp:956] Updating framework 201304150352-1015726915-60471-27966-0000 pid to scheduler(75)@67.195.138.60:60471
I0415 03:52:17.294653 28012 sched.cpp:217] Framework registered with 201304150352-1015726915-60471-27966-0000
I0415 03:52:17.294734 28011 hierarchical_allocator_process.hpp:268] Added framework 201304150352-1015726915-60471-27966-0000
I0415 03:52:17.344810 28011 hierarchical_allocator_process.hpp:660] Found available resources: cpus=1; mem=524; ports=[31000-32000]; disk=1024 on slave 201304150352-1015726915-60471-27966-0
I0415 03:52:17.345317 28011 hierarchical_allocator_process.hpp:686] Offering cpus=1; mem=524; ports=[31000-32000]; disk=1024 on slave 201304150352-1015726915-60471-27966-0 to framework 201304150352-1015726915-60471-27966-0000
I0415 03:52:17.345898 28011 hierarchical_allocator_process.hpp:599] Performed allocation for 1 slaves in 1.10ms
I0415 03:52:17.345988 28018 master.hpp:309] Adding offer with resources cpus=1; mem=524; ports=[31000-32000]; disk=1024 on slave 201304150352-1015726915-60471-27966-0
I0415 03:52:17.346806 28018 master.cpp:1327] Sending 1 offers to framework 201304150352-1015726915-60471-27966-0000
I0415 03:52:17.347316 28017 sched.cpp:282] Received 1 offers
I0415 03:52:17.348103 28012 sched.cpp:422] Stopping framework '201304150352-1015726915-60471-27966-0000'
I0415 03:52:17.348254 28015 master.cpp:774] Asked to unregister framework 201304150352-1015726915-60471-27966-0000
I0415 03:52:17.348747 28017 slave.cpp:889] Asked to shut down framework 201304150352-1015726915-60471-27966-0000 by master@67.195.138.60:60471
I0415 03:52:17.349159 28017 slave.cpp:894] Shutting down framework 201304150352-1015726915-60471-27966-0000
I0415 03:52:17.349648 28017 slave.cpp:1681] Shutting down executor 'default' of framework 201304150352-1015726915-60471-27966-0000
I0415 03:52:17.350154 28013 exec.cpp:321] Executor asked to shutdown
I0415 03:52:17.348780 28018 hierarchical_allocator_process.hpp:359] Deactivated framework 201304150352-1015726915-60471-27966-0000
I0415 03:52:17.350172 28017 status_update_manager.cpp:233] Closing status update streams for framework 201304150352-1015726915-60471-27966-0000
I0415 03:52:17.351585 28017 status_update_manager.cpp:434] Cleaning up status update stream for task 0 of framework 201304150352-1015726915-60471-27966-0000
I0415 03:52:17.348753 28015 master.hpp:300] Removing task with resources cpus=1; mem=500 on slave 201304150352-1015726915-60471-27966-0
I0415 03:52:17.352645 28015 master.hpp:318] Removing offer with resources cpus=1; mem=524; ports=[31000-32000]; disk=1024 on slave 201304150352-1015726915-60471-27966-0
I0415 03:52:17.352738 28014 hierarchical_allocator_process.hpp:544] Recovered cpus=1; mem=500 (total allocatable: cpus=1; mem=500; ports=[]; disk=0) on slave 201304150352-1015726915-60471-27966-0 from framework 201304150352-1015726915-60471-27966-0000
I0415 03:52:17.354449 28018 slave.cpp:386] Slave terminating
I0415 03:52:17.355085 28018 slave.cpp:889] Asked to shut down framework 201304150352-1015726915-60471-27966-0000 by @0.0.0.0:0
I0415 03:52:17.355623 28018 slave.cpp:894] Shutting down framework 201304150352-1015726915-60471-27966-0000
I0415 03:52:17.354775 28014 hierarchical_allocator_process.hpp:544] Recovered cpus=1; mem=524; ports=[31000-32000]; disk=1024 (total allocatable: cpus=2; mem=1024; ports=[31000-32000]; disk=1024) on slave 201304150352-1015726915-60471-27966-0 from framework 201304150352-1015726915-60471-27966-0000
I0415 03:52:17.356153 28018 slave.cpp:1681] Shutting down executor 'default' of framework 201304150352-1015726915-60471-27966-0000
I0415 03:52:17.357228 28015 status_update_manager.cpp:233] Closing status update streams for framework 201304150352-1015726915-60471-27966-0000
I0415 03:52:17.357238 28018 master.cpp:537] Slave 201304150352-1015726915-60471-27966-0(janus.apache.org) disconnected
I0415 03:52:17.358275 28018 master.cpp:542] Removing disconnected slave 201304150352-1015726915-60471-27966-0(janus.apache.org) because it is not checkpointing!
I0415 03:52:17.358933 27966 master.cpp:477] Master terminating
I0415 03:52:17.359760 27966 master.cpp:283] Shutting down master
I0415 03:52:17.381469 27966 master.cpp:283] Shutting down master
I0415 03:52:17.381543 27966 master.hpp:300] Removing task with resources cpus=1; mem=500 on slave 201304150352-1015726915-60471-27966-0
I0415 03:52:17.381575 28011 hierarchical_allocator_process.hpp:359] Deactivated framework 201304150352-1015726915-60471-27966-0000
I0415 03:52:17.382721 28011 hierarchical_allocator_process.hpp:544] Recovered cpus=1; mem=500 (total allocatable: cpus=2; mem=1024; ports=[31000-32000]; disk=1024) on slave 201304150352-1015726915-60471-27966-0 from framework 201304150352-1015726915-60471-27966-0000
I0415 03:52:17.383054 28011 hierarchical_allocator_process.hpp:312] Removed framework 201304150352-1015726915-60471-27966-0000
I0415 03:52:17.383503 28011 hierarchical_allocator_process.hpp:423] Removed slave 201304150352-1015726915-60471-27966-0
I0415 03:52:17.394901 27966 zookeeper_test_server.cpp:195] Shutdown ZooKeeperTestServer on port 53584
[ OK ] AllocatorZooKeeperTest/0.SlaveReregistersFirst (1489 ms)
[----------] 2 tests from AllocatorZooKeeperTest/0 (3731 ms total)
[----------] Global test environment tear-down
[==========] 190 tests from 39 test cases ran. (95876 ms total)
[ PASSED ] 189 tests.
[ FAILED ] 1 test, listed below:
[ FAILED ] FaultToleranceTest.SchedulerFailover
1 FAILED TEST
YOU HAVE 1 DISABLED TEST
FAIL: mesos-tests
==================
1 of 1 test failed
==================
make[3]: *** [check-TESTS] Error 1
make[3]: Leaving directory `<https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/ws/src'>
make[2]: *** [check-am] Error 2
make[2]: Leaving directory `<https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/ws/src'>
make[1]: *** [check] Error 2
make[1]: Leaving directory `<https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/ws/src'>
make: *** [check-recursive] Error 1
Build step 'Execute shell' marked build as failure