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/10/25 01:17:03 UTC
Build failed in Jenkins:
Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Set-JAVA_HOME #1727
See <https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Set-JAVA_HOME/1727/changes>
Changes:
[vinod] Refactored slave recovery to make reading checkpointed data asynchronous.
[vinod] Added os::utime() to update access/modification times.
[vinod] Fixed slave gc to use modification time for old directories.
[vinod] Fixed slave to properly recover latest run of completed executors.
[vinod] Changed slave to do checkpointing by default.
[vinod] Fixed tests to disable checkpointing by default.
[bmahler] Require ProtobufProcess message handlers to take the sender explicitly.
[bmahler] Updated users of ProtobufProcess::from.
[bmahler] Removed logging to /tmp when --log_dir is ommitted.
------------------------------------------
[...truncated 20745 lines...]
I1024 23:17:00.103108 11102 authenticator.hpp:317] Authentication success
I1024 23:17:00.103132 11102 authenticatee.hpp:298] Authentication success
I1024 23:17:00.103163 11102 master.cpp:1742] Successfully authenticated framework at scheduler(127)@67.195.138.9:56035
I1024 23:17:00.103215 11102 sched.cpp:326] Successfully authenticated with master master@67.195.138.9:56035
W1024 23:17:00.103299 11102 master.cpp:810] Ignoring re-register framework message since not elected yet
I1024 23:17:00.103456 11104 detector.cpp:470] Master detector (slave(133)@67.195.138.9:56035) got new master pid: master@67.195.138.9:56035
I1024 23:17:00.103579 11105 detector.cpp:470] Master detector (master@67.195.138.9:56035) got new master pid: master@67.195.138.9:56035
I1024 23:17:00.103590 11106 slave.cpp:481] New master detected at master@67.195.138.9:56035
I1024 23:17:00.103634 11104 status_update_manager.cpp:158] New master detected at master@67.195.138.9:56035
I1024 23:17:00.103718 11108 master.cpp:697] Elected as master!
I1024 23:17:01.055346 11106 monitor.cpp:187] Publishing resource usage for executor 'default' of framework '201310242316-160088899-56035-11083-0000'
I1024 23:17:01.061290 11106 hierarchical_allocator_process.hpp:726] No resources available to allocate!
I1024 23:17:01.061300 11106 hierarchical_allocator_process.hpp:688] Performed allocation for 0 slaves in 20877ns
I1024 23:17:01.103495 11105 master.cpp:843] Re-registering framework 201310242316-160088899-56035-11083-0000 at scheduler(127)@67.195.138.9:56035
I1024 23:17:01.103638 11105 sched.cpp:365] Framework registered with 201310242316-160088899-56035-11083-0000
I1024 23:17:01.103660 11105 sched.cpp:379] Scheduler::registered took 9364ns
I1024 23:17:01.103744 11105 hierarchical_allocator_process.hpp:332] Added framework 201310242316-160088899-56035-11083-0000
I1024 23:17:01.103757 11105 hierarchical_allocator_process.hpp:726] No resources available to allocate!
I1024 23:17:01.103763 11105 hierarchical_allocator_process.hpp:688] Performed allocation for 0 slaves in 7488ns
I1024 23:17:01.104615 11105 master.cpp:1326] Attempting to re-register slave 201310242316-160088899-56035-11083-0 at slave(133)@67.195.138.9:56035 (vesta.apache.org)
I1024 23:17:01.104631 11105 master.cpp:2481] Adding slave 201310242316-160088899-56035-11083-0 at vesta.apache.org with cpus(*):2; mem(*):1024; disk(*):1.38501e+06; ports(*):[31000-32000]
I1024 23:17:01.104697 11107 slave.cpp:594] Re-registered with master master@67.195.138.9:56035
I1024 23:17:01.104727 11105 master.hpp:385] Adding task 0 with resources cpus(*):1; mem(*):500 on slave 201310242316-160088899-56035-11083-0 (vesta.apache.org)
I1024 23:17:01.104848 11106 slave.cpp:1289] Updating framework 201310242316-160088899-56035-11083-0000 pid to scheduler(127)@67.195.138.9:56035
I1024 23:17:01.104944 11107 hierarchical_allocator_process.hpp:445] Added slave 201310242316-160088899-56035-11083-0 (vesta.apache.org) with cpus(*):2; mem(*):1024; disk(*):1.38501e+06; ports(*):[31000-32000] (and cpus(*):1; mem(*):524; disk(*):1.38501e+06; ports(*):[31000-32000] available)
I1024 23:17:01.105006 11107 hierarchical_allocator_process.hpp:752] Offering cpus(*):1; mem(*):524; disk(*):1.38501e+06; ports(*):[31000-32000] on slave 201310242316-160088899-56035-11083-0 to framework 201310242316-160088899-56035-11083-0000
I1024 23:17:01.105121 11107 hierarchical_allocator_process.hpp:708] Performed allocation for slave 201310242316-160088899-56035-11083-0 in 144199ns
I1024 23:17:01.105203 11108 master.hpp:413] Adding offer 201310242317-160088899-56035-11083-0 with resources cpus(*):1; mem(*):524; disk(*):1.38501e+06; ports(*):[31000-32000] on slave 201310242316-160088899-56035-11083-0 (vesta.apache.org)
I1024 23:17:01.105268 11108 master.cpp:1668] Sending 1 offers to framework 201310242316-160088899-56035-11083-0000
I1024 23:17:01.105396 11105 sched.cpp:472] Scheduler::resourceOffers took 23989ns
I1024 23:17:01.105569 11105 sched.cpp:630] Stopping framework '201310242316-160088899-56035-11083-0000'
I1024 23:17:01.105592 11108 master.cpp:557] Master terminating
I1024 23:17:01.105636 11106 slave.cpp:1937] master@67.195.138.9:56035 exited
W1024 23:17:01.105650 11106 slave.cpp:1940] Master disconnected! Waiting for a new master to be elected
I1024 23:17:01.105690 11083 master.cpp:209] Shutting down master
I1024 23:17:01.105733 11083 master.hpp:403] Removing task 0 with resources cpus(*):1; mem(*):500 on slave 201310242316-160088899-56035-11083-0 (vesta.apache.org)
I1024 23:17:01.105805 11083 master.hpp:423] Removing offer 201310242317-160088899-56035-11083-0 with resources cpus(*):1; mem(*):524; disk(*):1.38501e+06; ports(*):[31000-32000] on slave 201310242316-160088899-56035-11083-0 (vesta.apache.org)
I1024 23:17:01.105924 11083 master.cpp:252] Removing slave 201310242316-160088899-56035-11083-0 (vesta.apache.org)
I1024 23:17:01.106044 11108 hierarchical_allocator_process.hpp:637] Recovered cpus(*):1; mem(*):500 (total allocatable: cpus(*):1; mem(*):500) on slave 201310242316-160088899-56035-11083-0 from framework 201310242316-160088899-56035-11083-0000
I1024 23:17:01.106724 11083 slave.cpp:388] Slave terminating
I1024 23:17:01.106745 11083 slave.cpp:1119] Asked to shut down framework 201310242316-160088899-56035-11083-0000 by @0.0.0.0:0
I1024 23:17:01.106760 11083 slave.cpp:1144] Shutting down framework 201310242316-160088899-56035-11083-0000
I1024 23:17:01.106775 11083 slave.cpp:2396] Shutting down executor 'default' of framework 201310242316-160088899-56035-11083-0000
I1024 23:17:01.106818 11103 exec.cpp:371] Executor asked to shutdown
I1024 23:17:01.106838 11103 exec.cpp:386] Executor::shutdown took 10273ns
[ OK ] AllocatorZooKeeperTest/0.FrameworkReregistersFirst (2146 ms)
[ RUN ] AllocatorZooKeeperTest/0.SlaveReregistersFirst
I1024 23:17:01.125068 11106 master.cpp:284] Master started on 67.195.138.9:56035
I1024 23:17:01.125105 11106 master.cpp:299] Master ID: 201310242317-160088899-56035-11083
I1024 23:17:01.125113 11106 master.cpp:302] Master only allowing authenticated frameworks to register!
I1024 23:17:01.125370 11102 master.cpp:85] No whitelist given. Advertising offers for all slaves
I1024 23:17:01.125437 11104 hierarchical_allocator_process.hpp:302] Initializing hierarchical allocator process with master : master@67.195.138.9:56035
I1024 23:17:01.125885 11107 slave.cpp:109] Slave started on 134)@67.195.138.9:56035
I1024 23:17:01.125994 11107 slave.cpp:209] Slave resources: cpus(*):2; mem(*):1024; disk(*):1.38501e+06; ports(*):[31000-32000]
I1024 23:17:01.126804 11105 state.cpp:33] Recovering state from '/tmp/AllocatorZooKeeperTest_0_SlaveReregistersFirst_0kPsHe/meta'
I1024 23:17:01.127010 11103 status_update_manager.cpp:180] Recovering status update manager
I1024 23:17:01.127435 11103 slave.cpp:2733] Finished recovery
I1024 23:17:01.138275 11104 detector.cpp:237] Master detector (master@67.195.138.9:56035) connected to ZooKeeper ...
I1024 23:17:01.138291 11104 detector.cpp:254] Trying to create path '/znode' in ZooKeeper
I1024 23:17:01.138629 11103 detector.cpp:237] Master detector (slave(134)@67.195.138.9:56035) connected to ZooKeeper ...
I1024 23:17:01.138643 11103 detector.cpp:254] Trying to create path '/znode' in ZooKeeper
I1024 23:17:01.138942 11109 detector.cpp:237] Master detector (scheduler(128)@67.195.138.9:56035) connected to ZooKeeper ...
I1024 23:17:01.138958 11109 detector.cpp:254] Trying to create path '/znode' in ZooKeeper
I1024 23:17:01.148151 11104 detector.cpp:284] Created ephemeral/sequence znode at '/znode/0000000004'
I1024 23:17:01.148494 11103 detector.cpp:423] Master detector (slave(134)@67.195.138.9:56035) found 1 registered masters
I1024 23:17:01.148540 11109 detector.cpp:423] Master detector (scheduler(128)@67.195.138.9:56035) found 1 registered masters
I1024 23:17:01.148699 11104 detector.cpp:423] Master detector (master@67.195.138.9:56035) found 1 registered masters
I1024 23:17:01.149195 11103 detector.cpp:470] Master detector (slave(134)@67.195.138.9:56035) got new master pid: master@67.195.138.9:56035
I1024 23:17:01.149283 11103 slave.cpp:481] New master detected at master@67.195.138.9:56035
I1024 23:17:01.149334 11104 detector.cpp:470] Master detector (master@67.195.138.9:56035) got new master pid: master@67.195.138.9:56035
W1024 23:17:01.149384 11107 master.cpp:1192] Ignoring register slave message from vesta.apache.org since not elected yet
I1024 23:17:01.149385 11106 status_update_manager.cpp:158] New master detected at master@67.195.138.9:56035
I1024 23:17:01.149425 11107 master.cpp:697] Elected as master!
I1024 23:17:01.149492 11109 detector.cpp:470] Master detector (scheduler(128)@67.195.138.9:56035) got new master pid: master@67.195.138.9:56035
I1024 23:17:01.149550 11109 sched.cpp:195] New master at master@67.195.138.9:56035
I1024 23:17:01.149561 11109 sched.cpp:281] Authenticating with master master@67.195.138.9:56035
I1024 23:17:01.149668 11104 authenticatee.hpp:124] Creating new client SASL connection
I1024 23:17:01.149734 11102 master.cpp:1702] Authenticating framework at scheduler(128)@67.195.138.9:56035
I1024 23:17:01.149847 11109 authenticator.hpp:140] Creating new server SASL connection
I1024 23:17:01.149930 11105 authenticatee.hpp:212] Received SASL authentication mechanisms: CRAM-MD5
I1024 23:17:01.149955 11105 authenticatee.hpp:238] Attempting to authenticate with mechanism 'CRAM-MD5'
I1024 23:17:01.149974 11105 authenticator.hpp:243] Received SASL authentication start
I1024 23:17:01.150017 11105 authenticator.hpp:325] Authentication requires more steps
I1024 23:17:01.150048 11105 authenticatee.hpp:258] Received SASL authentication step
I1024 23:17:01.150079 11105 authenticator.hpp:271] Received SASL authentication step
I1024 23:17:01.150097 11105 auxprop.cpp:81] Request to lookup properties for user: 'test-principal' realm: 'vesta.apache.org' server FQDN: 'vesta.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
I1024 23:17:01.150105 11105 auxprop.cpp:153] Looking up auxiliary property '*userPassword'
I1024 23:17:01.150120 11105 auxprop.cpp:153] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I1024 23:17:01.150130 11105 auxprop.cpp:81] Request to lookup properties for user: 'test-principal' realm: 'vesta.apache.org' server FQDN: 'vesta.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
I1024 23:17:01.150135 11105 auxprop.cpp:103] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I1024 23:17:01.150141 11105 auxprop.cpp:103] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I1024 23:17:01.150151 11105 authenticator.hpp:317] Authentication success
I1024 23:17:01.150168 11109 authenticatee.hpp:298] Authentication success
I1024 23:17:01.150189 11104 master.cpp:1742] Successfully authenticated framework at scheduler(128)@67.195.138.9:56035
I1024 23:17:01.150295 11103 sched.cpp:326] Successfully authenticated with master master@67.195.138.9:56035
I1024 23:17:01.150333 11109 master.cpp:755] Received registration request from scheduler(128)@67.195.138.9:56035
I1024 23:17:01.150424 11109 master.cpp:773] Registering framework 201310242317-160088899-56035-11083-0000 at scheduler(128)@67.195.138.9:56035
I1024 23:17:01.150470 11102 sched.cpp:365] Framework registered with 201310242317-160088899-56035-11083-0000
I1024 23:17:01.150485 11109 hierarchical_allocator_process.hpp:332] Added framework 201310242317-160088899-56035-11083-0000
I1024 23:17:01.150491 11102 sched.cpp:379] Scheduler::registered took 10333ns
I1024 23:17:01.150495 11109 hierarchical_allocator_process.hpp:726] No resources available to allocate!
I1024 23:17:01.150501 11109 hierarchical_allocator_process.hpp:688] Performed allocation for 0 slaves in 6998ns
I1024 23:17:02.126302 11109 hierarchical_allocator_process.hpp:726] No resources available to allocate!
I1024 23:17:02.126334 11109 hierarchical_allocator_process.hpp:688] Performed allocation for 0 slaves in 53124ns
I1024 23:17:02.150527 11102 master.cpp:1223] Attempting to register slave on vesta.apache.org at slave(134)@67.195.138.9:56035
I1024 23:17:02.150547 11102 master.cpp:2481] Adding slave 201310242317-160088899-56035-11083-0 at vesta.apache.org with cpus(*):2; mem(*):1024; disk(*):1.38501e+06; ports(*):[31000-32000]
I1024 23:17:02.150621 11106 slave.cpp:547] Registered with master master@67.195.138.9:56035; given slave ID 201310242317-160088899-56035-11083-0
I1024 23:17:02.150706 11109 hierarchical_allocator_process.hpp:445] Added slave 201310242317-160088899-56035-11083-0 (vesta.apache.org) with cpus(*):2; mem(*):1024; disk(*):1.38501e+06; ports(*):[31000-32000] (and cpus(*):2; mem(*):1024; disk(*):1.38501e+06; ports(*):[31000-32000] available)
I1024 23:17:02.150775 11109 hierarchical_allocator_process.hpp:752] Offering cpus(*):2; mem(*):1024; disk(*):1.38501e+06; ports(*):[31000-32000] on slave 201310242317-160088899-56035-11083-0 to framework 201310242317-160088899-56035-11083-0000
I1024 23:17:02.150892 11109 hierarchical_allocator_process.hpp:708] Performed allocation for slave 201310242317-160088899-56035-11083-0 in 151207ns
I1024 23:17:02.150949 11102 master.hpp:413] Adding offer 201310242317-160088899-56035-11083-0 with resources cpus(*):2; mem(*):1024; disk(*):1.38501e+06; ports(*):[31000-32000] on slave 201310242317-160088899-56035-11083-0 (vesta.apache.org)
I1024 23:17:02.150992 11102 master.cpp:1668] Sending 1 offers to framework 201310242317-160088899-56035-11083-0000
I1024 23:17:02.151259 11106 sched.cpp:472] Scheduler::resourceOffers took 172441ns
I1024 23:17:02.151352 11102 master.cpp:1994] Processing reply for offer 201310242317-160088899-56035-11083-0 on slave 201310242317-160088899-56035-11083-0 (vesta.apache.org) for framework 201310242317-160088899-56035-11083-0000
I1024 23:17:02.151455 11102 master.hpp:385] Adding task 0 with resources cpus(*):1; mem(*):500 on slave 201310242317-160088899-56035-11083-0 (vesta.apache.org)
I1024 23:17:02.151486 11102 master.cpp:2118] Launching task 0 of framework 201310242317-160088899-56035-11083-0000 with resources cpus(*):1; mem(*):500 on slave 201310242317-160088899-56035-11083-0 (vesta.apache.org)
I1024 23:17:02.151548 11106 slave.cpp:720] Got assigned task 0 for framework 201310242317-160088899-56035-11083-0000
I1024 23:17:02.151656 11102 master.hpp:423] Removing offer 201310242317-160088899-56035-11083-0 with resources cpus(*):2; mem(*):1024; disk(*):1.38501e+06; ports(*):[31000-32000] on slave 201310242317-160088899-56035-11083-0 (vesta.apache.org)
I1024 23:17:02.151725 11102 hierarchical_allocator_process.hpp:547] Framework 201310242317-160088899-56035-11083-0000 left cpus(*):1; mem(*):524; disk(*):1.38501e+06; ports(*):[31000-32000] unused on slave 201310242317-160088899-56035-11083-0
I1024 23:17:02.151739 11106 slave.cpp:831] Launching task 0 for framework 201310242317-160088899-56035-11083-0000
I1024 23:17:02.151823 11102 hierarchical_allocator_process.hpp:590] Framework 201310242317-160088899-56035-11083-0000 filtered slave 201310242317-160088899-56035-11083-0 for 5secs
I1024 23:17:02.153575 11106 slave.cpp:941] Queuing task '0' for executor default of framework '201310242317-160088899-56035-11083-0000
I1024 23:17:02.153664 11105 slave.cpp:463] Successfully attached file '/tmp/AllocatorZooKeeperTest_0_SlaveReregistersFirst_0kPsHe/slaves/201310242317-160088899-56035-11083-0/frameworks/201310242317-160088899-56035-11083-0000/executors/default/runs/ddfbc3fe-3166-4e71-af55-efd279bdb036'
I1024 23:17:02.154857 11102 exec.cpp:174] Executor started at: executor(43)@67.195.138.9:56035 with pid 11083
I1024 23:17:02.155011 11105 slave.cpp:1403] Got registration for executor 'default' of framework 201310242317-160088899-56035-11083-0000
I1024 23:17:02.155150 11105 slave.cpp:1524] Flushing queued task 0 for executor 'default' of framework 201310242317-160088899-56035-11083-0000
I1024 23:17:02.155168 11104 exec.cpp:198] Executor registered on slave 201310242317-160088899-56035-11083-0
I1024 23:17:02.156338 11104 exec.cpp:210] Executor::registered took 12534ns
I1024 23:17:02.156383 11104 exec.cpp:285] Executor asked to run task '0'
I1024 23:17:02.156420 11104 exec.cpp:294] Executor::launchTask took 21836ns
I1024 23:17:02.157516 11104 exec.cpp:505] Executor sending status update TASK_RUNNING (UUID: 21c2b660-ebf1-4a2b-83a7-def6482160eb) for task 0 of framework 201310242317-160088899-56035-11083-0000
I1024 23:17:02.157585 11104 slave.cpp:1737] Handling status update TASK_RUNNING (UUID: 21c2b660-ebf1-4a2b-83a7-def6482160eb) for task 0 of framework 201310242317-160088899-56035-11083-0000 from executor(43)@67.195.138.9:56035
I1024 23:17:02.157733 11106 status_update_manager.cpp:305] Received status update TASK_RUNNING (UUID: 21c2b660-ebf1-4a2b-83a7-def6482160eb) for task 0 of framework 201310242317-160088899-56035-11083-0000
I1024 23:17:02.157753 11106 status_update_manager.cpp:476] Creating StatusUpdate stream for task 0 of framework 201310242317-160088899-56035-11083-0000
I1024 23:17:02.157831 11106 status_update_manager.cpp:356] Forwarding status update TASK_RUNNING (UUID: 21c2b660-ebf1-4a2b-83a7-def6482160eb) for task 0 of framework 201310242317-160088899-56035-11083-0000 to master@67.195.138.9:56035
I1024 23:17:02.157966 11106 slave.cpp:1856] Status update manager successfully handled status update TASK_RUNNING (UUID: 21c2b660-ebf1-4a2b-83a7-def6482160eb) for task 0 of framework 201310242317-160088899-56035-11083-0000
I1024 23:17:02.157982 11106 slave.cpp:1862] Sending acknowledgement for status update TASK_RUNNING (UUID: 21c2b660-ebf1-4a2b-83a7-def6482160eb) for task 0 of framework 201310242317-160088899-56035-11083-0000 to executor(43)@67.195.138.9:56035
I1024 23:17:02.157969 11102 master.cpp:1425] Status update TASK_RUNNING (UUID: 21c2b660-ebf1-4a2b-83a7-def6482160eb) for task 0 of framework 201310242317-160088899-56035-11083-0000 from slave(134)@67.195.138.9:56035
I1024 23:17:02.158035 11102 exec.cpp:331] Executor received status update acknowledgement 21c2b660-ebf1-4a2b-83a7-def6482160eb for task 0 of framework 201310242317-160088899-56035-11083-0000
I1024 23:17:02.158061 11105 sched.cpp:527] Scheduler::statusUpdate took 32117ns
I1024 23:17:02.158318 11106 status_update_manager.cpp:380] Received status update acknowledgement (UUID: 21c2b660-ebf1-4a2b-83a7-def6482160eb) for task 0 of framework 201310242317-160088899-56035-11083-0000
I1024 23:17:02.158355 11083 master.cpp:557] Master terminating
I1024 23:17:02.158403 11083 master.cpp:209] Shutting down master
I1024 23:17:02.158449 11083 master.hpp:403] Removing task 0 with resources cpus(*):1; mem(*):500 on slave 201310242317-160088899-56035-11083-0 (vesta.apache.org)
I1024 23:17:02.158486 11103 slave.cpp:1937] master@67.195.138.9:56035 exited
W1024 23:17:02.158526 11103 slave.cpp:1940] Master disconnected! Waiting for a new master to be elected
I1024 23:17:02.158586 11083 master.cpp:252] Removing slave 201310242317-160088899-56035-11083-0 (vesta.apache.org)
I1024 23:17:02.158587 11103 slave.cpp:1343] Status update manager successfully handled status update acknowledgement (UUID: 21c2b660-ebf1-4a2b-83a7-def6482160eb) for task 0 of framework 201310242317-160088899-56035-11083-0000
I1024 23:17:02.158614 11106 hierarchical_allocator_process.hpp:637] Recovered cpus(*):1; mem(*):500 (total allocatable: cpus(*):2; mem(*):1024; disk(*):1.38501e+06; ports(*):[31000-32000]) on slave 201310242317-160088899-56035-11083-0 from framework 201310242317-160088899-56035-11083-0000
I1024 23:17:02.159574 11105 master.cpp:284] Master started on 67.195.138.9:56035
I1024 23:17:02.159603 11105 master.cpp:299] Master ID: 201310242317-160088899-56035-11083
I1024 23:17:02.159610 11105 master.cpp:302] Master only allowing authenticated frameworks to register!
I1024 23:17:02.159904 11102 master.cpp:85] No whitelist given. Advertising offers for all slaves
I1024 23:17:02.160027 11108 hierarchical_allocator_process.hpp:302] Initializing hierarchical allocator process with master : master@67.195.138.9:56035
I1024 23:17:02.174813 11108 detector.cpp:237] Master detector (master@67.195.138.9:56035) connected to ZooKeeper ...
I1024 23:17:02.174844 11108 detector.cpp:254] Trying to create path '/znode' in ZooKeeper
I1024 23:17:02.175034 11106 detector.cpp:423] Master detector (slave(134)@67.195.138.9:56035) found 0 registered masters
I1024 23:17:02.175051 11106 detector.cpp:444] Master detector (slave(134)@67.195.138.9:56035) couldn't find any masters
I1024 23:17:02.175055 11102 detector.cpp:423] Master detector (scheduler(128)@67.195.138.9:56035) found 0 registered masters
I1024 23:17:02.175068 11102 detector.cpp:444] Master detector (scheduler(128)@67.195.138.9:56035) couldn't find any masters
I1024 23:17:02.175086 11106 slave.cpp:515] Lost master(s) ... waiting
I1024 23:17:02.175111 11103 sched.cpp:235] No master detected, waiting for another master
I1024 23:17:02.175149 11103 sched.cpp:247] Scheduler::disconnected took 27878ns
I1024 23:17:02.185017 11108 detector.cpp:284] Created ephemeral/sequence znode at '/znode/0000000006'
I1024 23:17:02.185081 11106 detector.cpp:423] Master detector (slave(134)@67.195.138.9:56035) found 1 registered masters
I1024 23:17:02.185312 11104 detector.cpp:423] Master detector (scheduler(128)@67.195.138.9:56035) found 1 registered masters
I1024 23:17:02.185837 11108 detector.cpp:423] Master detector (master@67.195.138.9:56035) found 1 registered masters
I1024 23:17:02.186044 11106 detector.cpp:470] Master detector (slave(134)@67.195.138.9:56035) got new master pid: master@67.195.138.9:56035
I1024 23:17:02.186087 11104 detector.cpp:470] Master detector (scheduler(128)@67.195.138.9:56035) got new master pid: master@67.195.138.9:56035
I1024 23:17:02.186169 11109 sched.cpp:195] New master at master@67.195.138.9:56035
I1024 23:17:02.186190 11109 sched.cpp:281] Authenticating with master master@67.195.138.9:56035
I1024 23:17:02.186203 11106 slave.cpp:481] New master detected at master@67.195.138.9:56035
I1024 23:17:02.186247 11103 status_update_manager.cpp:158] New master detected at master@67.195.138.9:56035
I1024 23:17:02.186347 11104 authenticatee.hpp:124] Creating new client SASL connection
W1024 23:17:02.186362 11103 master.cpp:1252] Ignoring re-register slave message from vesta.apache.org since not elected yet
I1024 23:17:02.186442 11108 detector.cpp:470] Master detector (master@67.195.138.9:56035) got new master pid: master@67.195.138.9:56035
I1024 23:17:02.186513 11103 master.cpp:1702] Authenticating framework at scheduler(128)@67.195.138.9:56035
I1024 23:17:02.186643 11102 authenticator.hpp:140] Creating new server SASL connection
I1024 23:17:02.186717 11102 authenticatee.hpp:212] Received SASL authentication mechanisms: CRAM-MD5
I1024 23:17:02.186729 11102 authenticatee.hpp:238] Attempting to authenticate with mechanism 'CRAM-MD5'
I1024 23:17:02.186730 11103 master.cpp:697] Elected as master!
I1024 23:17:02.186772 11103 authenticator.hpp:243] Received SASL authentication start
I1024 23:17:02.186821 11103 authenticator.hpp:325] Authentication requires more steps
I1024 23:17:02.186856 11103 authenticatee.hpp:258] Received SASL authentication step
I1024 23:17:02.186910 11103 authenticator.hpp:271] Received SASL authentication step
I1024 23:17:02.186933 11103 auxprop.cpp:81] Request to lookup properties for user: 'test-principal' realm: 'vesta.apache.org' server FQDN: 'vesta.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
I1024 23:17:02.186940 11103 auxprop.cpp:153] Looking up auxiliary property '*userPassword'
I1024 23:17:02.186954 11103 auxprop.cpp:153] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I1024 23:17:02.186964 11103 auxprop.cpp:81] Request to lookup properties for user: 'test-principal' realm: 'vesta.apache.org' server FQDN: 'vesta.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
I1024 23:17:02.186969 11103 auxprop.cpp:103] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I1024 23:17:02.186975 11103 auxprop.cpp:103] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I1024 23:17:02.186985 11103 authenticator.hpp:317] Authentication success
I1024 23:17:02.187027 11109 authenticatee.hpp:298] Authentication success
I1024 23:17:02.187054 11102 master.cpp:1742] Successfully authenticated framework at scheduler(128)@67.195.138.9:56035
I1024 23:17:02.187122 11109 sched.cpp:326] Successfully authenticated with master master@67.195.138.9:56035
I1024 23:17:03.150861 11102 master.cpp:1326] Attempting to re-register slave 201310242317-160088899-56035-11083-0 at slave(134)@67.195.138.9:56035 (vesta.apache.org)
I1024 23:17:03.150882 11102 master.cpp:2481] Adding slave 201310242317-160088899-56035-11083-0 at vesta.apache.org with cpus(*):2; mem(*):1024; disk(*):1.38501e+06; ports(*):[31000-32000]
I1024 23:17:03.150966 11104 slave.cpp:594] Re-registered with master master@67.195.138.9:56035
I1024 23:17:03.150974 11102 master.hpp:385] Adding task 0 with resources cpus(*):1; mem(*):500 on slave 201310242317-160088899-56035-11083-0 (vesta.apache.org)
W1024 23:17:03.151000 11102 master.cpp:2576] Possibly orphaned task 0 of framework 201310242317-160088899-56035-11083-0000 running on slave 201310242317-160088899-56035-11083-0 (vesta.apache.org)
I1024 23:17:03.151237 11103 hierarchical_allocator_process.hpp:445] Added slave 201310242317-160088899-56035-11083-0 (vesta.apache.org) with cpus(*):2; mem(*):1024; disk(*):1.38501e+06; ports(*):[31000-32000] (and cpus(*):1; mem(*):524; disk(*):1.38501e+06; ports(*):[31000-32000] available)
I1024 23:17:03.151285 11103 hierarchical_allocator_process.hpp:708] Performed allocation for slave 201310242317-160088899-56035-11083-0 in 8036ns
I1024 23:17:03.156050 11105 monitor.cpp:187] Publishing resource usage for executor 'default' of framework '201310242317-160088899-56035-11083-0000'
I1024 23:17:03.160966 11105 hierarchical_allocator_process.hpp:688] Performed allocation for 1 slaves in 16564ns
I1024 23:17:03.188204 11103 master.cpp:843] Re-registering framework 201310242317-160088899-56035-11083-0000 at scheduler(128)@67.195.138.9:56035
I1024 23:17:03.188416 11107 sched.cpp:365] Framework registered with 201310242317-160088899-56035-11083-0000
I1024 23:17:03.188442 11107 sched.cpp:379] Scheduler::registered took 11022ns
I1024 23:17:03.188442 11103 slave.cpp:1289] Updating framework 201310242317-160088899-56035-11083-0000 pid to scheduler(128)@67.195.138.9:56035
I1024 23:17:03.188482 11107 hierarchical_allocator_process.hpp:332] Added framework 201310242317-160088899-56035-11083-0000
I1024 23:17:03.188527 11107 hierarchical_allocator_process.hpp:752] Offering cpus(*):1; mem(*):524; disk(*):1.38501e+06; ports(*):[31000-32000] on slave 201310242317-160088899-56035-11083-0 to framework 201310242317-160088899-56035-11083-0000
I1024 23:17:03.188644 11107 hierarchical_allocator_process.hpp:688] Performed allocation for 1 slaves in 150211ns
I1024 23:17:03.188689 11106 master.hpp:413] Adding offer 201310242317-160088899-56035-11083-0 with resources cpus(*):1; mem(*):524; disk(*):1.38501e+06; ports(*):[31000-32000] on slave 201310242317-160088899-56035-11083-0 (vesta.apache.org)
I1024 23:17:03.188732 11106 master.cpp:1668] Sending 1 offers to framework 201310242317-160088899-56035-11083-0000
I1024 23:17:03.188832 11106 sched.cpp:472] Scheduler::resourceOffers took 16179ns
I1024 23:17:03.189015 11083 master.cpp:557] Master terminating
I1024 23:17:03.189035 11083 master.cpp:209] Shutting down master
I1024 23:17:03.189076 11083 master.hpp:403] Removing task 0 with resources cpus(*):1; mem(*):500 on slave 201310242317-160088899-56035-11083-0 (vesta.apache.org)
I1024 23:17:03.189134 11083 master.hpp:423] Removing offer 201310242317-160088899-56035-11083-0 with resources cpus(*):1; mem(*):524; disk(*):1.38501e+06; ports(*):[31000-32000] on slave 201310242317-160088899-56035-11083-0 (vesta.apache.org)
I1024 23:17:03.189187 11083 master.cpp:252] Removing slave 201310242317-160088899-56035-11083-0 (vesta.apache.org)
I1024 23:17:03.189343 11106 sched.cpp:630] Stopping framework '201310242317-160088899-56035-11083-0000'
I1024 23:17:03.189451 11107 slave.cpp:1937] master@67.195.138.9:56035 exited
W1024 23:17:03.189497 11107 slave.cpp:1940] Master disconnected! Waiting for a new master to be elected
I1024 23:17:03.190590 11102 slave.cpp:388] Slave terminating
I1024 23:17:03.190618 11102 slave.cpp:1119] Asked to shut down framework 201310242317-160088899-56035-11083-0000 by @0.0.0.0:0
I1024 23:17:03.190626 11102 slave.cpp:1144] Shutting down framework 201310242317-160088899-56035-11083-0000
I1024 23:17:03.190641 11102 slave.cpp:2396] Shutting down executor 'default' of framework 201310242317-160088899-56035-11083-0000
I1024 23:17:03.190686 11104 exec.cpp:371] Executor asked to shutdown
I1024 23:17:03.190713 11104 exec.cpp:386] Executor::shutdown took 9726ns
[ OK ] AllocatorZooKeeperTest/0.SlaveReregistersFirst (2083 ms)
I1024 23:17:03.213666 11083 zookeeper_test_server.cpp:93] Shutdown ZooKeeperTestServer on port 59018
[----------] 2 tests from AllocatorZooKeeperTest/0 (4229 ms total)
[----------] Global test environment tear-down
[==========] 234 tests from 41 test cases ran. (94118 ms total)
[ PASSED ] 233 tests.
[ FAILED ] 1 test, listed below:
[ FAILED ] StatusUpdateManagerTest.DuplicateTerminalUpdateBeforeAck
1 FAILED TEST
YOU HAVE 3 DISABLED TESTS
make[3]: *** [check-local] Error 1
make[3]: Leaving directory `/home/hudson/jenkins-slave/workspace/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Set-JAVA_HOME/build/src'
make[2]: *** [check-am] Error 2
make[2]: Leaving directory `/home/hudson/jenkins-slave/workspace/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Set-JAVA_HOME/build/src'
make[1]: *** [check] Error 2
make[1]: Leaving directory `/home/hudson/jenkins-slave/workspace/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Set-JAVA_HOME/build/src'
make: *** [check-recursive] Error 1
Build step 'Execute shell' marked build as failure
Jenkins build is back to normal :
Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Set-JAVA_HOME #1728
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Set-JAVA_HOME/1728/changes>