See <https://builds.apache.org/job/Mesos-Ubuntu-distcheck/220/changes>
Changes: [yujie.jay] Fixed a bug in port mapping metrics. ------------------------------------------ [...truncated 60223 lines...] I0718 01:27:51.216940 1336 auxprop.cpp:103] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true I0718 01:27:51.216944 1336 auxprop.cpp:103] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true I0718 01:27:51.216955 1336 authenticator.hpp:376] Authentication success I0718 01:27:51.216976 1336 authenticatee.hpp:305] Authentication success I0718 01:27:51.216995 1336 master.cpp:3552] Successfully authenticated principal 'test-principal' at slave(196)@67.195.138.9:49254 I0718 01:27:51.217051 1336 slave.cpp:733] Successfully authenticated with master [email protected]:49254 I0718 01:27:51.217088 1336 slave.cpp:971] Will retry registration in 13.993153ms if necessary I0718 01:27:51.217149 1336 master.cpp:2789] Registering slave at slave(196)@67.195.138.9:49254 (vesta.apache.org) with id 20140718-012751-160088899-49254-1284-0 I0718 01:27:51.217274 1340 registrar.cpp:422] Attempting to update the 'registry' I0718 01:27:51.218101 1284 sched.cpp:139] Version: 0.20.0 I0718 01:27:51.218333 1332 sched.cpp:235] New master detected at [email protected]:49254 I0718 01:27:51.218349 1332 sched.cpp:285] Authenticating with master [email protected]:49254 I0718 01:27:51.218436 1337 authenticatee.hpp:128] Creating new client SASL connection I0718 01:27:51.218552 1333 master.cpp:3512] Authenticating [email protected]:49254 I0718 01:27:51.218622 1337 authenticator.hpp:156] Creating new server SASL connection I0718 01:27:51.218685 1337 authenticatee.hpp:219] Received SASL authentication mechanisms: CRAM-MD5 I0718 01:27:51.218705 1337 authenticatee.hpp:245] Attempting to authenticate with mechanism 'CRAM-MD5' I0718 01:27:51.218739 1337 authenticator.hpp:262] Received SASL authentication start I0718 01:27:51.218786 1337 authenticator.hpp:384] Authentication requires more steps I0718 01:27:51.218816 1337 authenticatee.hpp:265] Received SASL authentication step I0718 01:27:51.218864 1337 authenticator.hpp:290] Received SASL authentication step I0718 01:27:51.218884 1337 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 I0718 01:27:51.218891 1337 auxprop.cpp:153] Looking up auxiliary property '*userPassword' I0718 01:27:51.218902 1337 auxprop.cpp:153] Looking up auxiliary property '*cmusaslsecretCRAM-MD5' I0718 01:27:51.218911 1337 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 I0718 01:27:51.218917 1337 auxprop.cpp:103] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true I0718 01:27:51.218921 1337 auxprop.cpp:103] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true I0718 01:27:51.218932 1337 authenticator.hpp:376] Authentication success I0718 01:27:51.218991 1337 master.cpp:3552] Successfully authenticated principal 'test-principal' at [email protected]:49254 I0718 01:27:51.218993 1334 authenticatee.hpp:305] Authentication success I0718 01:27:51.219136 1337 sched.cpp:359] Successfully authenticated with master [email protected]:49254 I0718 01:27:51.219148 1337 sched.cpp:478] Sending registration request to [email protected]:49254 I0718 01:27:51.219210 1336 master.cpp:1247] Received registration request from [email protected]:49254 I0718 01:27:51.219233 1336 master.cpp:1207] Authorizing framework principal 'test-principal' to receive offers for role '*' I0718 01:27:51.219362 1332 master.cpp:1306] Registering framework 20140718-012751-160088899-49254-1284-0000 at [email protected]:49254 I0718 01:27:51.219430 1339 sched.cpp:409] Framework registered with 20140718-012751-160088899-49254-1284-0000 I0718 01:27:51.219456 1339 sched.cpp:423] Scheduler::registered took 8889ns I0718 01:27:51.219496 1332 hierarchical_allocator_process.hpp:331] Added framework 20140718-012751-160088899-49254-1284-0000 I0718 01:27:51.219518 1332 hierarchical_allocator_process.hpp:724] No resources available to allocate! I0718 01:27:51.219529 1332 hierarchical_allocator_process.hpp:686] Performed allocation for 0 slaves in 11217ns I0718 01:27:51.219562 1336 log.cpp:680] Attempting to append 325 bytes to the log I0718 01:27:51.219660 1340 coordinator.cpp:340] Coordinator attempting to write APPEND action at position 3 I0718 01:27:51.219955 1337 replica.cpp:508] Replica received write request for position 3 I0718 01:27:51.221379 1337 leveldb.cpp:343] Persisting action (344 bytes) to leveldb took 1.406378ms I0718 01:27:51.221393 1337 replica.cpp:676] Persisted action at 3 I0718 01:27:51.221655 1332 replica.cpp:655] Replica received learned notice for position 3 I0718 01:27:51.225364 1332 leveldb.cpp:343] Persisting action (346 bytes) to leveldb took 3.685523ms I0718 01:27:51.225384 1332 replica.cpp:676] Persisted action at 3 I0718 01:27:51.225405 1332 replica.cpp:661] Replica learned APPEND action at position 3 I0718 01:27:51.225800 1336 registrar.cpp:479] Successfully updated 'registry' I0718 01:27:51.225966 1334 master.cpp:2829] Registered slave 20140718-012751-160088899-49254-1284-0 at slave(196)@67.195.138.9:49254 (vesta.apache.org) I0718 01:27:51.225972 1332 log.cpp:699] Attempting to truncate the log to 3 I0718 01:27:51.225993 1334 master.cpp:3980] Adding slave 20140718-012751-160088899-49254-1284-0 at slave(196)@67.195.138.9:49254 (vesta.apache.org) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] I0718 01:27:51.226038 1336 coordinator.cpp:340] Coordinator attempting to write TRUNCATE action at position 4 I0718 01:27:51.226073 1332 slave.cpp:767] Registered with master [email protected]:49254; given slave ID 20140718-012751-160088899-49254-1284-0 I0718 01:27:51.226176 1337 hierarchical_allocator_process.hpp:444] Added slave 20140718-012751-160088899-49254-1284-0 (vesta.apache.org) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] (and cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] available) I0718 01:27:51.226227 1332 slave.cpp:780] Checkpointing SlaveInfo to '/tmp/MesosContainerizerSlaveRecoveryTest_ResourceStatistics_EIUpwL/meta/slaves/20140718-012751-160088899-49254-1284-0/slave.info' I0718 01:27:51.226245 1337 hierarchical_allocator_process.hpp:750] Offering cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20140718-012751-160088899-49254-1284-0 to framework 20140718-012751-160088899-49254-1284-0000 I0718 01:27:51.226287 1336 replica.cpp:508] Replica received write request for position 4 I0718 01:27:51.226322 1332 slave.cpp:2324] Received ping from slave-observer(169)@67.195.138.9:49254 I0718 01:27:51.226377 1337 hierarchical_allocator_process.hpp:706] Performed allocation for slave 20140718-012751-160088899-49254-1284-0 in 157230ns I0718 01:27:51.226456 1340 master.hpp:800] Adding offer 20140718-012751-160088899-49254-1284-0 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20140718-012751-160088899-49254-1284-0 (vesta.apache.org) I0718 01:27:51.226519 1340 master.cpp:3459] Sending 1 offers to framework 20140718-012751-160088899-49254-1284-0000 I0718 01:27:51.226655 1339 sched.cpp:546] Scheduler::resourceOffers took 25048ns I0718 01:27:51.228036 1337 master.hpp:810] Removing offer 20140718-012751-160088899-49254-1284-0 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20140718-012751-160088899-49254-1284-0 (vesta.apache.org) I0718 01:27:51.228096 1337 master.cpp:2133] Processing reply for offers: [ 20140718-012751-160088899-49254-1284-0 ] on slave 20140718-012751-160088899-49254-1284-0 at slave(196)@67.195.138.9:49254 (vesta.apache.org) for framework 20140718-012751-160088899-49254-1284-0000 I0718 01:27:51.228135 1337 master.cpp:2219] Authorizing framework principal 'test-principal' to launch task fc4664a4-eb11-4bef-a6db-ca4da79de574 as user 'jenkins' I0718 01:27:51.228479 1332 master.hpp:772] Adding task fc4664a4-eb11-4bef-a6db-ca4da79de574 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20140718-012751-160088899-49254-1284-0 (vesta.apache.org) I0718 01:27:51.228523 1332 master.cpp:2285] Launching task fc4664a4-eb11-4bef-a6db-ca4da79de574 of framework 20140718-012751-160088899-49254-1284-0000 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20140718-012751-160088899-49254-1284-0 at slave(196)@67.195.138.9:49254 (vesta.apache.org) I0718 01:27:51.228621 1340 slave.cpp:1002] Got assigned task fc4664a4-eb11-4bef-a6db-ca4da79de574 for framework 20140718-012751-160088899-49254-1284-0000 I0718 01:27:51.228725 1340 slave.cpp:3399] Checkpointing FrameworkInfo to '/tmp/MesosContainerizerSlaveRecoveryTest_ResourceStatistics_EIUpwL/meta/slaves/20140718-012751-160088899-49254-1284-0/frameworks/20140718-012751-160088899-49254-1284-0000/framework.info' I0718 01:27:51.229193 1340 slave.cpp:3406] Checkpointing framework pid '[email protected]:49254' to '/tmp/MesosContainerizerSlaveRecoveryTest_ResourceStatistics_EIUpwL/meta/slaves/20140718-012751-160088899-49254-1284-0/frameworks/20140718-012751-160088899-49254-1284-0000/framework.pid' I0718 01:27:51.229347 1336 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 3.04375ms I0718 01:27:51.229362 1336 replica.cpp:676] Persisted action at 4 I0718 01:27:51.229485 1340 slave.cpp:1112] Launching task fc4664a4-eb11-4bef-a6db-ca4da79de574 for framework 20140718-012751-160088899-49254-1284-0000 I0718 01:27:51.229614 1338 replica.cpp:655] Replica received learned notice for position 4 I0718 01:27:51.230804 1340 slave.cpp:3721] Checkpointing ExecutorInfo to '/tmp/MesosContainerizerSlaveRecoveryTest_ResourceStatistics_EIUpwL/meta/slaves/20140718-012751-160088899-49254-1284-0/frameworks/20140718-012751-160088899-49254-1284-0000/executors/fc4664a4-eb11-4bef-a6db-ca4da79de574/executor.info' I0718 01:27:51.231566 1340 slave.cpp:3836] Checkpointing TaskInfo to '/tmp/MesosContainerizerSlaveRecoveryTest_ResourceStatistics_EIUpwL/meta/slaves/20140718-012751-160088899-49254-1284-0/frameworks/20140718-012751-160088899-49254-1284-0000/executors/fc4664a4-eb11-4bef-a6db-ca4da79de574/runs/515c6331-d459-4175-988a-9793e5fdeefa/tasks/fc4664a4-eb11-4bef-a6db-ca4da79de574/task.info' I0718 01:27:51.231576 1337 containerizer.cpp:427] Starting container '515c6331-d459-4175-988a-9793e5fdeefa' for executor 'fc4664a4-eb11-4bef-a6db-ca4da79de574' of framework '20140718-012751-160088899-49254-1284-0000' I0718 01:27:51.231717 1340 slave.cpp:1222] Queuing task 'fc4664a4-eb11-4bef-a6db-ca4da79de574' for executor fc4664a4-eb11-4bef-a6db-ca4da79de574 of framework '20140718-012751-160088899-49254-1284-0000 I0718 01:27:51.231884 1340 slave.cpp:561] Successfully attached file '/tmp/MesosContainerizerSlaveRecoveryTest_ResourceStatistics_EIUpwL/slaves/20140718-012751-160088899-49254-1284-0/frameworks/20140718-012751-160088899-49254-1284-0000/executors/fc4664a4-eb11-4bef-a6db-ca4da79de574/runs/515c6331-d459-4175-988a-9793e5fdeefa' I0718 01:27:51.234931 1338 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 5.231451ms I0718 01:27:51.235292 1337 launcher.cpp:137] Forked child with pid '8667' for container '515c6331-d459-4175-988a-9793e5fdeefa' I0718 01:27:51.235321 1338 leveldb.cpp:401] Deleting ~2 keys from leveldb took 132585ns I0718 01:27:51.235442 1337 containerizer.cpp:705] Checkpointing executor's forked pid 8667 to '/tmp/MesosContainerizerSlaveRecoveryTest_ResourceStatistics_EIUpwL/meta/slaves/20140718-012751-160088899-49254-1284-0/frameworks/20140718-012751-160088899-49254-1284-0000/executors/fc4664a4-eb11-4bef-a6db-ca4da79de574/runs/515c6331-d459-4175-988a-9793e5fdeefa/pids/forked.pid' I0718 01:27:51.235477 1338 replica.cpp:676] Persisted action at 4 I0718 01:27:51.235594 1338 replica.cpp:661] Replica learned TRUNCATE action at position 4 I0718 01:27:51.236394 1337 containerizer.cpp:537] Fetching URIs for container '515c6331-d459-4175-988a-9793e5fdeefa' using command '/home/hudson/jenkins-slave/workspace/Mesos-Ubuntu-distcheck/build/mesos-0.20.0/_build/src/mesos-fetcher' I0718 01:27:51.950124 1334 slave.cpp:2469] Monitoring executor 'fc4664a4-eb11-4bef-a6db-ca4da79de574' of framework '20140718-012751-160088899-49254-1284-0000' in container '515c6331-d459-4175-988a-9793e5fdeefa' WARNING: Logging before InitGoogleLogging() is written to STDERR I0718 01:27:51.980073 8703 process.cpp:1671] libprocess is initialized on 67.195.138.9:56591 for 8 cpus I0718 01:27:51.981204 8703 exec.cpp:131] Version: 0.20.0 I0718 01:27:51.982527 8723 exec.cpp:181] Executor started at: executor(1)@67.195.138.9:56591 with pid 8703 I0718 01:27:51.983140 1334 slave.cpp:1733] Got registration for executor 'fc4664a4-eb11-4bef-a6db-ca4da79de574' of framework 20140718-012751-160088899-49254-1284-0000 I0718 01:27:51.983213 1334 slave.cpp:1818] Checkpointing executor pid 'executor(1)@67.195.138.9:56591' to '/tmp/MesosContainerizerSlaveRecoveryTest_ResourceStatistics_EIUpwL/meta/slaves/20140718-012751-160088899-49254-1284-0/frameworks/20140718-012751-160088899-49254-1284-0000/executors/fc4664a4-eb11-4bef-a6db-ca4da79de574/runs/515c6331-d459-4175-988a-9793e5fdeefa/pids/libprocess.pid' I0718 01:27:51.986217 1334 slave.cpp:1852] Flushing queued task fc4664a4-eb11-4bef-a6db-ca4da79de574 for executor 'fc4664a4-eb11-4bef-a6db-ca4da79de574' of framework 20140718-012751-160088899-49254-1284-0000 I0718 01:27:51.986374 1334 slave.cpp:484] Slave terminating I0718 01:27:51.986397 1341 process.cpp:1098] Socket closed while receiving I0718 01:27:51.986498 1334 master.cpp:766] Slave 20140718-012751-160088899-49254-1284-0 at slave(196)@67.195.138.9:49254 (vesta.apache.org) disconnected I0718 01:27:51.986522 1334 master.cpp:1608] Disconnecting slave 20140718-012751-160088899-49254-1284-0 I0718 01:27:51.986547 8721 exec.cpp:205] Executor registered on slave 20140718-012751-160088899-49254-1284-0 I0718 01:27:51.986588 1334 hierarchical_allocator_process.hpp:483] Slave 20140718-012751-160088899-49254-1284-0 deactivated I0718 01:27:51.987049 8725 process.cpp:1037] Socket closed while receiving I0718 01:27:51.988296 1284 containerizer.cpp:124] Using isolation: posix/cpu,posix/mem Registered executor on vesta.apache.org I0718 01:27:51.990020 8721 exec.cpp:217] Executor::registered took 2.523571ms I0718 01:27:51.990185 8721 exec.cpp:292] Executor asked to run task 'fc4664a4-eb11-4bef-a6db-ca4da79de574' I0718 01:27:51.990262 8721 exec.cpp:301] Executor::launchTask took 67267ns Starting task fc4664a4-eb11-4bef-a6db-ca4da79de574 I0718 01:27:51.990835 1332 slave.cpp:168] Slave started on 197)@67.195.138.9:49254 I0718 01:27:51.990864 1332 credentials.hpp:84] Loading credential for authentication from '/tmp/MesosContainerizerSlaveRecoveryTest_ResourceStatistics_EIUpwL/credential' sh -c 'sleep 1000' Forked command at 8726 I0718 01:27:51.990962 1332 slave.cpp:266] Slave using credential for: test-principal I0718 01:27:51.991106 1332 slave.cpp:279] Slave resources: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] I0718 01:27:51.991181 1332 slave.cpp:324] Slave hostname: vesta.apache.org I0718 01:27:51.991190 1332 slave.cpp:325] Slave checkpoint: true I0718 01:27:51.991845 1333 state.cpp:33] Recovering state from '/tmp/MesosContainerizerSlaveRecoveryTest_ResourceStatistics_EIUpwL/meta' I0718 01:27:51.992213 8720 exec.cpp:524] Executor sending status update TASK_RUNNING (UUID: 5ad7146a-b317-4d95-bf84-38fb850c42fa) for task fc4664a4-eb11-4bef-a6db-ca4da79de574 of framework 20140718-012751-160088899-49254-1284-0000 W0718 01:27:51.992375 1333 state.cpp:558] Failed to find status updates file '/tmp/MesosContainerizerSlaveRecoveryTest_ResourceStatistics_EIUpwL/meta/slaves/20140718-012751-160088899-49254-1284-0/frameworks/20140718-012751-160088899-49254-1284-0000/executors/fc4664a4-eb11-4bef-a6db-ca4da79de574/runs/515c6331-d459-4175-988a-9793e5fdeefa/tasks/fc4664a4-eb11-4bef-a6db-ca4da79de574/task.updates' I0718 01:27:51.993095 1332 slave.cpp:3195] Recovering framework 20140718-012751-160088899-49254-1284-0000 I0718 01:27:51.993120 1332 slave.cpp:3571] Recovering executor 'fc4664a4-eb11-4bef-a6db-ca4da79de574' of framework 20140718-012751-160088899-49254-1284-0000 I0718 01:27:51.993476 1334 status_update_manager.cpp:193] Recovering status update manager I0718 01:27:51.993510 1334 status_update_manager.cpp:201] Recovering executor 'fc4664a4-eb11-4bef-a6db-ca4da79de574' of framework 20140718-012751-160088899-49254-1284-0000 W0718 01:27:51.993557 1334 status_update_manager.cpp:240] No updates found for task fc4664a4-eb11-4bef-a6db-ca4da79de574 of framework 20140718-012751-160088899-49254-1284-0000 I0718 01:27:51.993716 1332 slave.cpp:561] Successfully attached file '/tmp/MesosContainerizerSlaveRecoveryTest_ResourceStatistics_EIUpwL/slaves/20140718-012751-160088899-49254-1284-0/frameworks/20140718-012751-160088899-49254-1284-0000/executors/fc4664a4-eb11-4bef-a6db-ca4da79de574/runs/515c6331-d459-4175-988a-9793e5fdeefa' I0718 01:27:51.994216 1337 containerizer.cpp:287] Recovering containerizer I0718 01:27:51.994242 1337 containerizer.cpp:329] Recovering container '515c6331-d459-4175-988a-9793e5fdeefa' for executor 'fc4664a4-eb11-4bef-a6db-ca4da79de574' of framework 20140718-012751-160088899-49254-1284-0000 I0718 01:27:51.995184 1338 slave.cpp:3068] Sending reconnect request to executor fc4664a4-eb11-4bef-a6db-ca4da79de574 of framework 20140718-012751-160088899-49254-1284-0000 at executor(1)@67.195.138.9:56591 I0718 01:27:51.995331 1341 process.cpp:1098] Socket closed while receiving I0718 01:27:51.995436 8721 exec.cpp:251] Received reconnect request from slave 20140718-012751-160088899-49254-1284-0 I0718 01:27:51.995448 8725 process.cpp:1037] Socket closed while receiving I0718 01:27:51.995782 1332 slave.cpp:1912] Re-registering executor fc4664a4-eb11-4bef-a6db-ca4da79de574 of framework 20140718-012751-160088899-49254-1284-0000 I0718 01:27:51.995908 1332 slave.cpp:2087] Handling status update TASK_RUNNING (UUID: 5ad7146a-b317-4d95-bf84-38fb850c42fa) for task fc4664a4-eb11-4bef-a6db-ca4da79de574 of framework 20140718-012751-160088899-49254-1284-0000 from executor(1)@67.195.138.9:56591 I0718 01:27:51.995990 1341 process.cpp:1098] Socket closed while receiving I0718 01:27:51.996021 8725 process.cpp:1037] Socket closed while receiving I0718 01:27:51.996037 8724 exec.cpp:228] Executor re-registered on slave 20140718-012751-160088899-49254-1284-0 I0718 01:27:51.996141 1340 status_update_manager.cpp:320] Received status update TASK_RUNNING (UUID: 5ad7146a-b317-4d95-bf84-38fb850c42fa) for task fc4664a4-eb11-4bef-a6db-ca4da79de574 of framework 20140718-012751-160088899-49254-1284-0000 I0718 01:27:51.996162 1340 status_update_manager.cpp:499] Creating StatusUpdate stream for task fc4664a4-eb11-4bef-a6db-ca4da79de574 of framework 20140718-012751-160088899-49254-1284-0000 I0718 01:27:51.996398 1340 status_update_manager.hpp:342] Checkpointing UPDATE for status update TASK_RUNNING (UUID: 5ad7146a-b317-4d95-bf84-38fb850c42fa) for task fc4664a4-eb11-4bef-a6db-ca4da79de574 of framework 20140718-012751-160088899-49254-1284-0000 Re-registered executor on vesta.apache.org I0718 01:27:51.996937 8724 exec.cpp:240] Executor::reregistered took 39020ns I0718 01:27:52.015056 1333 containerizer.cpp:903] Destroying container '515c6331-d459-4175-988a-9793e5fdeefa' W0718 01:27:52.065505 1340 status_update_manager.cpp:381] Not forwarding status update TASK_RUNNING (UUID: 5ad7146a-b317-4d95-bf84-38fb850c42fa) for task fc4664a4-eb11-4bef-a6db-ca4da79de574 of framework 20140718-012751-160088899-49254-1284-0000 because no master is elected yet I0718 01:27:52.065645 1336 slave.cpp:2245] Status update manager successfully handled status update TASK_RUNNING (UUID: 5ad7146a-b317-4d95-bf84-38fb850c42fa) for task fc4664a4-eb11-4bef-a6db-ca4da79de574 of framework 20140718-012751-160088899-49254-1284-0000 I0718 01:27:52.065677 1336 slave.cpp:2251] Sending acknowledgement for status update TASK_RUNNING (UUID: 5ad7146a-b317-4d95-bf84-38fb850c42fa) for task fc4664a4-eb11-4bef-a6db-ca4da79de574 of framework 20140718-012751-160088899-49254-1284-0000 to executor(1)@67.195.138.9:56591 I0718 01:27:52.065896 1341 process.cpp:1098] Socket closed while receiving I0718 01:27:52.074810 1341 process.cpp:1037] Socket closed while receiving I0718 01:27:52.135118 1336 hierarchical_allocator_process.hpp:686] Performed allocation for 1 slaves in 63743ns 2014-07-18 01:27:52,358:1284(0x2b6f8d5cd700):ZOO_ERROR@handle_socket_error_msg@1697: Socket [127.0.0.1:47246] zk retcode=-4, errno=111(Connection refused): server refused to accept the client I0718 01:27:52.950551 1333 containerizer.cpp:1019] Executor for container '515c6331-d459-4175-988a-9793e5fdeefa' has exited I0718 01:27:52.951163 1332 slave.cpp:2527] Executor 'fc4664a4-eb11-4bef-a6db-ca4da79de574' of framework 20140718-012751-160088899-49254-1284-0000 terminated with signal Killed I0718 01:27:52.951421 1338 sched.cpp:747] Stopping framework '20140718-012751-160088899-49254-1284-0000' I0718 01:27:52.951484 1284 master.cpp:625] Master terminating I0718 01:27:52.951612 1284 master.hpp:790] Removing task fc4664a4-eb11-4bef-a6db-ca4da79de574 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20140718-012751-160088899-49254-1284-0 (vesta.apache.org) W0718 01:27:52.951695 1284 master.cpp:4266] Removing task fc4664a4-eb11-4bef-a6db-ca4da79de574 of framework 20140718-012751-160088899-49254-1284-0000 and slave 20140718-012751-160088899-49254-1284-0 in non-terminal state TASK_STAGING I0718 01:27:52.951838 1338 hierarchical_allocator_process.hpp:635] Recovered cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] (total allocatable: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]) on slave 20140718-012751-160088899-49254-1284-0 from framework 20140718-012751-160088899-49254-1284-0000 I0718 01:27:52.952800 1332 slave.cpp:2087] Handling status update TASK_FAILED (UUID: d4d8cbf5-809e-4453-87cf-6dfd8f0500f7) for task fc4664a4-eb11-4bef-a6db-ca4da79de574 of framework 20140718-012751-160088899-49254-1284-0000 from @0.0.0.0:0 I0718 01:27:52.952843 1332 slave.cpp:3769] Terminating task fc4664a4-eb11-4bef-a6db-ca4da79de574 W0718 01:27:52.953040 1336 containerizer.cpp:809] Ignoring update for unknown container: 515c6331-d459-4175-988a-9793e5fdeefa I0718 01:27:52.953275 1334 status_update_manager.cpp:320] Received status update TASK_FAILED (UUID: d4d8cbf5-809e-4453-87cf-6dfd8f0500f7) for task fc4664a4-eb11-4bef-a6db-ca4da79de574 of framework 20140718-012751-160088899-49254-1284-0000 I0718 01:27:52.953317 1334 status_update_manager.hpp:342] Checkpointing UPDATE for status update TASK_FAILED (UUID: d4d8cbf5-809e-4453-87cf-6dfd8f0500f7) for task fc4664a4-eb11-4bef-a6db-ca4da79de574 of framework 20140718-012751-160088899-49254-1284-0000 I0718 01:27:52.955446 1284 slave.cpp:484] Slave terminating [ OK ] MesosContainerizerSlaveRecoveryTest.ResourceStatistics (2078 ms) [----------] 1 test from MesosContainerizerSlaveRecoveryTest (2078 ms total) [----------] 3 tests from FsTest [ RUN ] FsTest.FileSystemTableRead [ OK ] FsTest.FileSystemTableRead (0 ms) [ RUN ] FsTest.MountTableRead [ OK ] FsTest.MountTableRead (0 ms) [ RUN ] FsTest.MountTableHasOption [ OK ] FsTest.MountTableHasOption (1 ms) [----------] 3 tests from FsTest (1 ms total) [----------] 3 tests from SASL [ RUN ] SASL.failed1 I0718 01:27:53.023330 1336 authenticatee.hpp:128] Creating new client SASL connection I0718 01:27:53.023598 1340 authenticator.hpp:156] Creating new server SASL connection I0718 01:27:53.023675 1336 authenticatee.hpp:219] Received SASL authentication mechanisms: CRAM-MD5 I0718 01:27:53.023694 1336 authenticatee.hpp:245] Attempting to authenticate with mechanism 'CRAM-MD5' I0718 01:27:53.023720 1336 authenticator.hpp:262] Received SASL authentication start I0718 01:27:53.023772 1336 authenticator.hpp:384] Authentication requires more steps I0718 01:27:53.023800 1336 authenticatee.hpp:265] Received SASL authentication step I0718 01:27:53.023833 1336 authenticator.hpp:290] Received SASL authentication step I0718 01:27:53.023852 1336 auxprop.cpp:81] Request to lookup properties for user: 'benh' realm: 'vesta.apache.org' server FQDN: 'vesta.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false I0718 01:27:53.023864 1336 auxprop.cpp:153] Looking up auxiliary property '*userPassword' I0718 01:27:53.023875 1336 auxprop.cpp:153] Looking up auxiliary property '*cmusaslsecretCRAM-MD5' I0718 01:27:53.023885 1336 auxprop.cpp:81] Request to lookup properties for user: 'benh' realm: 'vesta.apache.org' server FQDN: 'vesta.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true I0718 01:27:53.023890 1336 auxprop.cpp:103] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true I0718 01:27:53.023895 1336 auxprop.cpp:103] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true W0718 01:27:53.023911 1336 authenticator.hpp:390] Authentication failure: authentication failure [ OK ] SASL.failed1 (1 ms) [ RUN ] SASL.failed2 I0718 01:27:53.024349 1336 authenticatee.hpp:128] Creating new client SASL connection I0718 01:27:53.024554 1336 authenticator.hpp:156] Creating new server SASL connection I0718 01:27:53.024755 1337 authenticatee.hpp:219] Received SASL authentication mechanisms: CRAM-MD5 I0718 01:27:53.024770 1337 authenticatee.hpp:245] Attempting to authenticate with mechanism 'CRAM-MD5' I0718 01:27:53.024798 1337 authenticator.hpp:262] Received SASL authentication start I0718 01:27:53.024826 1337 authenticator.hpp:384] Authentication requires more steps I0718 01:27:53.024853 1337 authenticatee.hpp:265] Received SASL authentication step I0718 01:27:53.024893 1337 authenticator.hpp:290] Received SASL authentication step I0718 01:27:53.024907 1337 auxprop.cpp:81] Request to lookup properties for user: 'benh' realm: 'vesta.apache.org' server FQDN: 'vesta.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false I0718 01:27:53.024914 1337 auxprop.cpp:153] Looking up auxiliary property '*userPassword' I0718 01:27:53.024920 1337 auxprop.cpp:153] Looking up auxiliary property '*cmusaslsecretCRAM-MD5' I0718 01:27:53.024926 1337 auxprop.cpp:81] Request to lookup properties for user: 'benh' realm: 'vesta.apache.org' server FQDN: 'vesta.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true I0718 01:27:53.024932 1337 auxprop.cpp:103] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true I0718 01:27:53.024937 1337 auxprop.cpp:103] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true W0718 01:27:53.024943 1337 authenticator.hpp:390] Authentication failure: user not found [ OK ] SASL.failed2 (1 ms) [ RUN ] SASL.success I0718 01:27:53.025563 1339 authenticatee.hpp:128] Creating new client SASL connection I0718 01:27:53.025775 1336 authenticator.hpp:156] Creating new server SASL connection I0718 01:27:53.025868 1336 authenticatee.hpp:219] Received SASL authentication mechanisms: CRAM-MD5 I0718 01:27:53.025883 1336 authenticatee.hpp:245] Attempting to authenticate with mechanism 'CRAM-MD5' I0718 01:27:53.025914 1336 authenticator.hpp:262] Received SASL authentication start I0718 01:27:53.025966 1336 authenticator.hpp:384] Authentication requires more steps I0718 01:27:53.026000 1336 authenticatee.hpp:265] Received SASL authentication step I0718 01:27:53.026064 1334 authenticator.hpp:290] Received SASL authentication step I0718 01:27:53.026098 1334 auxprop.cpp:81] Request to lookup properties for user: 'benh' realm: 'vesta.apache.org' server FQDN: 'vesta.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false I0718 01:27:53.026109 1334 auxprop.cpp:153] Looking up auxiliary property '*userPassword' I0718 01:27:53.026120 1334 auxprop.cpp:153] Looking up auxiliary property '*cmusaslsecretCRAM-MD5' I0718 01:27:53.026130 1334 auxprop.cpp:81] Request to lookup properties for user: 'benh' realm: 'vesta.apache.org' server FQDN: 'vesta.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true I0718 01:27:53.026137 1334 auxprop.cpp:103] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true I0718 01:27:53.026141 1334 auxprop.cpp:103] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true I0718 01:27:53.026154 1334 authenticator.hpp:376] Authentication success I0718 01:27:53.026185 1334 authenticatee.hpp:305] Authentication success [ OK ] SASL.success (1 ms) [----------] 3 tests from SASL (3 ms total) [----------] Global test environment tear-down [==========] 391 tests from 64 test cases ran. (359306 ms total) [ PASSED ] 390 tests. [ FAILED ] 1 test, listed below: [ FAILED ] ExamplesTest.JavaFramework 1 FAILED TEST YOU HAVE 3 DISABLED TESTS make[4]: *** [check-local] Error 1 make[4]: Leaving directory `/home/hudson/jenkins-slave/workspace/Mesos-Ubuntu-distcheck/build/mesos-0.20.0/_build/src' make[3]: *** [check-am] Error 2 make[3]: Leaving directory `/home/hudson/jenkins-slave/workspace/Mesos-Ubuntu-distcheck/build/mesos-0.20.0/_build/src' make[2]: *** [check] Error 2 make[2]: Leaving directory `/home/hudson/jenkins-slave/workspace/Mesos-Ubuntu-distcheck/build/mesos-0.20.0/_build/src' make[1]: *** [check-recursive] Error 1 make[1]: Leaving directory `/home/hudson/jenkins-slave/workspace/Mesos-Ubuntu-distcheck/build/mesos-0.20.0/_build' make: *** [distcheck] Error 1 Build step 'Execute shell' marked build as failure
