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 2015/03/18 19:06:41 UTC
Build failed in Jenkins:
Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui
#2827
See <https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/2827/changes>
Changes:
[idownes] Disable MountInfoTableRead test.
------------------------------------------
[...truncated 75582 lines...]
I0318 18:06:26.286846 24789 slave.cpp:283] Slave using credential for: test-principal
I0318 18:06:26.287199 24789 slave.cpp:301] Slave resources: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]
I0318 18:06:26.287336 24789 slave.cpp:330] Slave hostname: pietas.apache.org
I0318 18:06:26.287367 24789 slave.cpp:331] Slave checkpoint: false
W0318 18:06:26.287384 24789 slave.cpp:333] Disabling checkpointing is deprecated and the --checkpoint flag will be removed in a future release. Please avoid using this flag
I0318 18:06:26.287451 27903 exec.cpp:86] Committing suicide by killing the process group
I0318 18:06:26.287796 24762 scheduler.cpp:149] Version: 0.23.0
I0318 18:06:26.288240 24788 state.cpp:35] Recovering state from '/tmp/SchedulerTest_TaskRunning_G2awIG/meta'
I0318 18:06:26.288525 24786 status_update_manager.cpp:197] Recovering status update manager
I0318 18:06:26.288858 24783 slave.cpp:3763] Finished recovery
I0318 18:06:26.289276 27916 exec.cpp:86] Committing suicide by killing the process group
I0318 18:06:26.289443 24779 slave.cpp:612] New master detected at master@67.195.81.190:54255
I0318 18:06:26.289500 24782 status_update_manager.cpp:171] Pausing sending status updates
I0318 18:06:26.289564 24779 slave.cpp:675] Authenticating with master master@67.195.81.190:54255
I0318 18:06:26.289589 24779 slave.cpp:680] Using default CRAM-MD5 authenticatee
I0318 18:06:26.289738 24779 slave.cpp:648] Detecting new master
I0318 18:06:26.289762 24788 authenticatee.hpp:139] Creating new client SASL connection
I0318 18:06:26.289985 24788 master.cpp:3815] Authenticating slave(233)@67.195.81.190:54255
I0318 18:06:26.290019 24788 master.cpp:3826] Using default CRAM-MD5 authenticator
I0318 18:06:26.290220 24779 authenticator.hpp:170] Creating new server SASL connection
I0318 18:06:26.290390 24779 authenticatee.hpp:230] Received SASL authentication mechanisms: CRAM-MD5
I0318 18:06:26.290447 24779 authenticatee.hpp:256] Attempting to authenticate with mechanism 'CRAM-MD5'
I0318 18:06:26.290596 24778 authenticator.hpp:276] Received SASL authentication start
I0318 18:06:26.290612 24789 scheduler.cpp:420] New master detected at master@67.195.81.190:54255
I0318 18:06:26.290643 24789 scheduler.cpp:469] Authenticating with master master@67.195.81.190:54255
I0318 18:06:26.290662 24778 authenticator.hpp:398] Authentication requires more steps
I0318 18:06:26.290766 24778 authenticatee.hpp:276] Received SASL authentication step
I0318 18:06:26.290894 24783 authenticatee.hpp:139] Creating new client SASL connection
I0318 18:06:26.290930 24790 authenticator.hpp:304] Received SASL authentication step
I0318 18:06:26.290962 24790 auxprop.cpp:99] Request to lookup properties for user: 'test-principal' realm: 'pietas.apache.org' server FQDN: 'pietas.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
I0318 18:06:26.290973 24790 auxprop.cpp:171] Looking up auxiliary property '*userPassword'
I0318 18:06:26.291013 24790 auxprop.cpp:171] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0318 18:06:26.291059 24790 auxprop.cpp:99] Request to lookup properties for user: 'test-principal' realm: 'pietas.apache.org' server FQDN: 'pietas.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
I0318 18:06:26.291079 24790 auxprop.cpp:121] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I0318 18:06:26.291088 24790 auxprop.cpp:121] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0318 18:06:26.291105 24790 authenticator.hpp:390] Authentication success
I0318 18:06:26.291165 27932 exec.cpp:86] Committing suicide by killing the process group
I0318 18:06:26.291260 24788 authenticatee.hpp:316] Authentication success
I0318 18:06:26.291425 24786 master.cpp:3815] Authenticating scheduler(1)@67.195.81.190:54255
I0318 18:06:26.291453 24786 master.cpp:3826] Using default CRAM-MD5 authenticator
I0318 18:06:26.291625 24784 authenticator.hpp:170] Creating new server SASL connection
I0318 18:06:26.291673 24786 master.cpp:3873] Successfully authenticated principal 'test-principal' at slave(233)@67.195.81.190:54255
I0318 18:06:26.291863 24790 authenticatee.hpp:230] Received SASL authentication mechanisms: CRAM-MD5
I0318 18:06:26.291872 24788 slave.cpp:746] Successfully authenticated with master master@67.195.81.190:54255
I0318 18:06:26.291905 24790 authenticatee.hpp:256] Attempting to authenticate with mechanism 'CRAM-MD5'
I0318 18:06:26.292006 24790 authenticator.hpp:276] Received SASL authentication start
I0318 18:06:26.292052 24788 slave.cpp:1078] Will retry registration in 8.532941ms if necessary
I0318 18:06:26.292076 24790 authenticator.hpp:398] Authentication requires more steps
I0318 18:06:26.292175 24790 authenticatee.hpp:276] Received SASL authentication step
I0318 18:06:26.292228 24783 master.cpp:2945] Registering slave at slave(233)@67.195.81.190:54255 (pietas.apache.org) with id 20150318-180626-3193029443-54255-24762-S0
I0318 18:06:26.292300 24788 authenticator.hpp:304] Received SASL authentication step
I0318 18:06:26.292346 24788 auxprop.cpp:99] Request to lookup properties for user: 'test-principal' realm: 'pietas.apache.org' server FQDN: 'pietas.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
I0318 18:06:26.292361 24788 auxprop.cpp:171] Looking up auxiliary property '*userPassword'
I0318 18:06:26.292412 24788 auxprop.cpp:171] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0318 18:06:26.292455 24788 auxprop.cpp:99] Request to lookup properties for user: 'test-principal' realm: 'pietas.apache.org' server FQDN: 'pietas.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
I0318 18:06:26.292493 24788 auxprop.cpp:121] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I0318 18:06:26.292510 24788 auxprop.cpp:121] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0318 18:06:26.292546 24788 authenticator.hpp:390] Authentication success
I0318 18:06:26.292634 24790 authenticatee.hpp:316] Authentication success
I0318 18:06:26.292688 24776 master.cpp:3873] Successfully authenticated principal 'test-principal' at scheduler(1)@67.195.81.190:54255
I0318 18:06:26.292733 24786 registrar.cpp:445] Applied 1 operations in 74231ns; attempting to update the 'registry'
I0318 18:06:26.292958 24788 scheduler.cpp:540] Successfully authenticated with master master@67.195.81.190:54255
I0318 18:06:26.293848 24788 master.cpp:1592] Received registration request for framework 'default' at scheduler(1)@67.195.81.190:54255
I0318 18:06:26.293905 24788 master.cpp:1453] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0318 18:06:26.294193 24787 master.cpp:1656] Registering framework 20150318-180626-3193029443-54255-24762-0000 (default) at scheduler(1)@67.195.81.190:54255
I0318 18:06:26.294451 24777 hierarchical.hpp:321] Added framework 20150318-180626-3193029443-54255-24762-0000
I0318 18:06:26.294482 24777 hierarchical.hpp:834] No resources available to allocate!
I0318 18:06:26.294498 24777 hierarchical.hpp:741] Performed allocation for 0 slaves in 24226ns
I0318 18:06:26.294636 24785 scheduler.cpp:589] Enqueuing event 1 from master@67.195.81.190:54255
I0318 18:06:26.295176 24782 log.cpp:684] Attempting to append 316 bytes to the log
I0318 18:06:26.295276 24785 coordinator.cpp:340] Coordinator attempting to write APPEND action at position 3
I0318 18:06:26.296066 24784 replica.cpp:511] Replica received write request for position 3
I0318 18:06:26.296696 24784 leveldb.cpp:343] Persisting action (335 bytes) to leveldb took 589256ns
I0318 18:06:26.296722 24784 replica.cpp:679] Persisted action at 3
I0318 18:06:26.297416 24779 replica.cpp:658] Replica received learned notice for position 3
I0318 18:06:26.297910 24779 leveldb.cpp:343] Persisting action (337 bytes) to leveldb took 467893ns
I0318 18:06:26.297935 24779 replica.cpp:679] Persisted action at 3
I0318 18:06:26.297955 24779 replica.cpp:664] Replica learned APPEND action at position 3
I0318 18:06:26.298934 24779 registrar.cpp:490] Successfully updated the 'registry' in 6.136832ms
I0318 18:06:26.299233 24783 log.cpp:703] Attempting to truncate the log to 3
I0318 18:06:26.299345 24778 coordinator.cpp:340] Coordinator attempting to write TRUNCATE action at position 4
I0318 18:06:26.299620 24783 slave.cpp:2799] Received ping from slave-observer(211)@67.195.81.190:54255
I0318 18:06:26.299715 24787 master.cpp:3002] Registered slave 20150318-180626-3193029443-54255-24762-S0 at slave(233)@67.195.81.190:54255 (pietas.apache.org) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]
I0318 18:06:26.299808 24783 slave.cpp:780] Registered with master master@67.195.81.190:54255; given slave ID 20150318-180626-3193029443-54255-24762-S0
I0318 18:06:26.299908 24777 status_update_manager.cpp:178] Resuming sending status updates
I0318 18:06:26.299918 24785 hierarchical.hpp:455] Added slave 20150318-180626-3193029443-54255-24762-S0 (pietas.apache.org) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] (and cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] available)
I0318 18:06:26.300099 24779 replica.cpp:511] Replica received write request for position 4
I0318 18:06:26.300390 24785 hierarchical.hpp:759] Performed allocation for slave 20150318-180626-3193029443-54255-24762-S0 in 417895ns
I0318 18:06:26.300668 24790 master.cpp:3757] Sending 1 offers to framework 20150318-180626-3193029443-54255-24762-0000 (default) at scheduler(1)@67.195.81.190:54255
I0318 18:06:26.300686 24779 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 557921ns
I0318 18:06:26.300712 24779 replica.cpp:679] Persisted action at 4
I0318 18:06:26.301029 24790 scheduler.cpp:589] Enqueuing event 3 from master@67.195.81.190:54255
I0318 18:06:26.301658 24784 replica.cpp:658] Replica received learned notice for position 4
I0318 18:06:26.302245 24784 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 556039ns
I0318 18:06:26.302325 24784 leveldb.cpp:401] Deleting ~2 keys from leveldb took 49114ns
I0318 18:06:26.302350 24784 replica.cpp:679] Persisted action at 4
I0318 18:06:26.302373 24784 replica.cpp:664] Replica learned TRUNCATE action at position 4
I0318 18:06:26.303541 24782 master.cpp:2285] Processing ACCEPT call for offers: [ 20150318-180626-3193029443-54255-24762-O0 ] on slave 20150318-180626-3193029443-54255-24762-S0 at slave(233)@67.195.81.190:54255 (pietas.apache.org) for framework 20150318-180626-3193029443-54255-24762-0000 (default) at scheduler(1)@67.195.81.190:54255
I0318 18:06:26.303591 24782 master.cpp:2130] Authorizing framework principal 'test-principal' to launch task 1 as user 'jenkins'
W0318 18:06:26.305060 24779 validation.cpp:326] Executor default for task 1 uses less CPUs (None) than the minimum required (0.01). Please update your executor, as this will be mandatory in future releases.
W0318 18:06:26.305107 24779 validation.cpp:338] Executor default for task 1 uses less memory (None) than the minimum required (32MB). Please update your executor, as this will be mandatory in future releases.
I0318 18:06:26.305526 24779 master.hpp:802] Adding task 1 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20150318-180626-3193029443-54255-24762-S0 (pietas.apache.org)
I0318 18:06:26.305675 24779 master.cpp:2557] Launching task 1 of framework 20150318-180626-3193029443-54255-24762-0000 (default) at scheduler(1)@67.195.81.190:54255 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20150318-180626-3193029443-54255-24762-S0 at slave(233)@67.195.81.190:54255 (pietas.apache.org)
I0318 18:06:26.306042 24777 slave.cpp:1109] Got assigned task 1 for framework 20150318-180626-3193029443-54255-24762-0000
I0318 18:06:26.306612 24777 slave.cpp:1219] Launching task 1 for framework 20150318-180626-3193029443-54255-24762-0000
I0318 18:06:26.309324 24777 slave.cpp:4151] Launching executor default of framework 20150318-180626-3193029443-54255-24762-0000 in work directory '/tmp/SchedulerTest_TaskRunning_G2awIG/slaves/20150318-180626-3193029443-54255-24762-S0/frameworks/20150318-180626-3193029443-54255-24762-0000/executors/default/runs/58ba70d8-fc8b-4975-accb-76e28cd0e636'
I0318 18:06:26.312172 24777 exec.cpp:132] Version: 0.23.0
I0318 18:06:26.312402 24783 exec.cpp:182] Executor started at: executor(80)@67.195.81.190:54255 with pid 24762
I0318 18:06:26.312553 24777 slave.cpp:1365] Queuing task '1' for executor default of framework '20150318-180626-3193029443-54255-24762-0000
I0318 18:06:26.312685 24777 slave.cpp:565] Successfully attached file '/tmp/SchedulerTest_TaskRunning_G2awIG/slaves/20150318-180626-3193029443-54255-24762-S0/frameworks/20150318-180626-3193029443-54255-24762-0000/executors/default/runs/58ba70d8-fc8b-4975-accb-76e28cd0e636'
I0318 18:06:26.312832 24777 slave.cpp:3101] Monitoring executor 'default' of framework '20150318-180626-3193029443-54255-24762-0000' in container '58ba70d8-fc8b-4975-accb-76e28cd0e636'
I0318 18:06:26.313056 24777 slave.cpp:2117] Got registration for executor 'default' of framework 20150318-180626-3193029443-54255-24762-0000 from executor(80)@67.195.81.190:54255
I0318 18:06:26.313335 24780 exec.cpp:206] Executor registered on slave 20150318-180626-3193029443-54255-24762-S0
I0318 18:06:26.313741 24777 slave.cpp:1517] Sending queued task '1' to executor 'default' of framework 20150318-180626-3193029443-54255-24762-0000
I0318 18:06:26.315560 24780 exec.cpp:218] Executor::registered took 28419ns
I0318 18:06:26.315754 24780 exec.cpp:293] Executor asked to run task '1'
I0318 18:06:26.315865 24780 exec.cpp:302] Executor::launchTask took 59728ns
I0318 18:06:26.317347 24780 exec.cpp:525] Executor sending status update TASK_RUNNING (UUID: 4776bc98-1fce-425e-b6ce-9cc7d3287344) for task 1 of framework 20150318-180626-3193029443-54255-24762-0000
I0318 18:06:26.317512 24780 slave.cpp:2484] Handling status update TASK_RUNNING (UUID: 4776bc98-1fce-425e-b6ce-9cc7d3287344) for task 1 of framework 20150318-180626-3193029443-54255-24762-0000 from executor(80)@67.195.81.190:54255
I0318 18:06:26.317843 24779 status_update_manager.cpp:317] Received status update TASK_RUNNING (UUID: 4776bc98-1fce-425e-b6ce-9cc7d3287344) for task 1 of framework 20150318-180626-3193029443-54255-24762-0000
I0318 18:06:26.317888 24779 status_update_manager.cpp:494] Creating StatusUpdate stream for task 1 of framework 20150318-180626-3193029443-54255-24762-0000
I0318 18:06:26.318106 24779 status_update_manager.cpp:371] Forwarding update TASK_RUNNING (UUID: 4776bc98-1fce-425e-b6ce-9cc7d3287344) for task 1 of framework 20150318-180626-3193029443-54255-24762-0000 to the slave
I0318 18:06:26.318357 24781 slave.cpp:2723] Forwarding the update TASK_RUNNING (UUID: 4776bc98-1fce-425e-b6ce-9cc7d3287344) for task 1 of framework 20150318-180626-3193029443-54255-24762-0000 to master@67.195.81.190:54255
I0318 18:06:26.318513 24781 slave.cpp:2650] Status update manager successfully handled status update TASK_RUNNING (UUID: 4776bc98-1fce-425e-b6ce-9cc7d3287344) for task 1 of framework 20150318-180626-3193029443-54255-24762-0000
I0318 18:06:26.318545 24781 slave.cpp:2656] Sending acknowledgement for status update TASK_RUNNING (UUID: 4776bc98-1fce-425e-b6ce-9cc7d3287344) for task 1 of framework 20150318-180626-3193029443-54255-24762-0000 to executor(80)@67.195.81.190:54255
I0318 18:06:26.318629 24777 master.cpp:3299] Status update TASK_RUNNING (UUID: 4776bc98-1fce-425e-b6ce-9cc7d3287344) for task 1 of framework 20150318-180626-3193029443-54255-24762-0000 from slave 20150318-180626-3193029443-54255-24762-S0 at slave(233)@67.195.81.190:54255 (pietas.apache.org)
I0318 18:06:26.318699 24777 master.cpp:3338] Forwarding status update TASK_RUNNING (UUID: 4776bc98-1fce-425e-b6ce-9cc7d3287344) for task 1 of framework 20150318-180626-3193029443-54255-24762-0000
I0318 18:06:26.318713 24785 exec.cpp:339] Executor received status update acknowledgement 4776bc98-1fce-425e-b6ce-9cc7d3287344 for task 1 of framework 20150318-180626-3193029443-54255-24762-0000
I0318 18:06:26.318863 24777 master.cpp:4617] Updating the latest state of task 1 of framework 20150318-180626-3193029443-54255-24762-0000 to TASK_RUNNING
I0318 18:06:26.318955 24785 scheduler.cpp:589] Enqueuing event 5 from master@67.195.81.190:54255
I0318 18:06:26.320056 24762 master.cpp:752] Master terminating
I0318 18:06:26.320292 24786 hierarchical.hpp:486] Removed slave 20150318-180626-3193029443-54255-24762-S0
W0318 18:06:26.320264 24762 master.cpp:4668] Removing task 1 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] of framework 20150318-180626-3193029443-54255-24762-0000 on slave 20150318-180626-3193029443-54255-24762-S0 at slave(233)@67.195.81.190:54255 (pietas.apache.org) in non-terminal state TASK_RUNNING
I0318 18:06:26.320888 24762 master.cpp:4711] Removing executor 'default' with resources of framework 20150318-180626-3193029443-54255-24762-0000 on slave 20150318-180626-3193029443-54255-24762-S0 at slave(233)@67.195.81.190:54255 (pietas.apache.org)
I0318 18:06:26.321517 24782 hierarchical.hpp:354] Removed framework 20150318-180626-3193029443-54255-24762-0000
I0318 18:06:26.321810 24785 slave.cpp:2884] master@67.195.81.190:54255 exited
W0318 18:06:26.321843 24785 slave.cpp:2887] Master disconnected! Waiting for a new master to be elected
I0318 18:06:26.323400 24762 process.cpp:2067] Dropped / Lost event for PID: master@67.195.81.190:54255
I0318 18:06:26.323501 24762 process.cpp:2067] Dropped / Lost event for PID: master@67.195.81.190:54255
I0318 18:06:26.326028 24776 slave.cpp:3159] Executor 'default' of framework 20150318-180626-3193029443-54255-24762-0000 exited with status 0
I0318 18:06:26.327759 24776 slave.cpp:2484] Handling status update TASK_LOST (UUID: 6360b509-0134-41dc-9f58-0d38b364ac13) for task 1 of framework 20150318-180626-3193029443-54255-24762-0000 from @0.0.0.0:0
I0318 18:06:26.327837 24776 slave.cpp:4459] Terminating task 1
I0318 18:06:26.328037 24776 process.cpp:2067] Dropped / Lost event for PID: master@67.195.81.190:54255
I0318 18:06:26.328071 24776 slave.cpp:494] Slave terminating
I0318 18:06:26.328122 24776 slave.cpp:1730] Asked to shut down framework 20150318-180626-3193029443-54255-24762-0000 by @0.0.0.0:0
I0318 18:06:26.328143 24776 slave.cpp:1755] Shutting down framework 20150318-180626-3193029443-54255-24762-0000
I0318 18:06:26.328184 24776 slave.cpp:3268] Cleaning up executor 'default' of framework 20150318-180626-3193029443-54255-24762-0000
I0318 18:06:26.328310 24785 gc.cpp:56] Scheduling '/tmp/SchedulerTest_TaskRunning_G2awIG/slaves/20150318-180626-3193029443-54255-24762-S0/frameworks/20150318-180626-3193029443-54255-24762-0000/executors/default/runs/58ba70d8-fc8b-4975-accb-76e28cd0e636' for gc 6.99999620081185days in the future
I0318 18:06:26.328413 24776 slave.cpp:3347] Cleaning up framework 20150318-180626-3193029443-54255-24762-0000
I0318 18:06:26.328429 24785 gc.cpp:56] Scheduling '/tmp/SchedulerTest_TaskRunning_G2awIG/slaves/20150318-180626-3193029443-54255-24762-S0/frameworks/20150318-180626-3193029443-54255-24762-0000/executors/default' for gc 6.99999619968889days in the future
I0318 18:06:26.328492 24778 status_update_manager.cpp:279] Closing status update streams for framework 20150318-180626-3193029443-54255-24762-0000
I0318 18:06:26.328527 24785 gc.cpp:56] Scheduling '/tmp/SchedulerTest_TaskRunning_G2awIG/slaves/20150318-180626-3193029443-54255-24762-S0/frameworks/20150318-180626-3193029443-54255-24762-0000' for gc 6.99999619816days in the future
I0318 18:06:26.328574 24778 status_update_manager.cpp:525] Cleaning up status update stream for task 1 of framework 20150318-180626-3193029443-54255-24762-0000
I0318 18:06:26.329710 24762 process.cpp:2067] Dropped / Lost event for PID: slave(233)@67.195.81.190:54255
[ OK ] SchedulerTest.TaskRunning (93 ms)
[----------] 1 test from SchedulerTest (93 ms total)
[----------] 23 tests from ModuleTest
[ RUN ] ModuleTest.ParameterWithoutValue
Using temporary directory '/tmp/ModuleTest_ParameterWithoutValue_y2ezpn'
[ OK ] ModuleTest.ParameterWithoutValue (1 ms)
[ RUN ] ModuleTest.ExampleModuleLoadTest
Using temporary directory '/tmp/ModuleTest_ExampleModuleLoadTest_6dKGOI'
[ OK ] ModuleTest.ExampleModuleLoadTest (1 ms)
[ RUN ] ModuleTest.EmptyModuleName
Using temporary directory '/tmp/ModuleTest_EmptyModuleName_mHITd4'
[ OK ] ModuleTest.EmptyModuleName (0 ms)
[ RUN ] ModuleTest.DifferentApiVersion
Using temporary directory '/tmp/ModuleTest_DifferentApiVersion_8qybDp'
[ OK ] ModuleTest.DifferentApiVersion (1 ms)
[ RUN ] ModuleTest.NonModuleLibrary
Using temporary directory '/tmp/ModuleTest_NonModuleLibrary_QFnz2K'
[ OK ] ModuleTest.NonModuleLibrary (0 ms)
[ RUN ] ModuleTest.ExampleModuleUnloadTest
Using temporary directory '/tmp/ModuleTest_ExampleModuleUnloadTest_SpT2r6'
[ OK ] ModuleTest.ExampleModuleUnloadTest (1 ms)
[ RUN ] ModuleTest.UnknownModuleTest
Using temporary directory '/tmp/ModuleTest_UnknownModuleTest_uYrBRr'
[ OK ] ModuleTest.UnknownModuleTest (0 ms)
[ RUN ] ModuleTest.UnknownLibraryTest
Using temporary directory '/tmp/ModuleTest_UnknownLibraryTest_KHLehN'
[ OK ] ModuleTest.UnknownLibraryTest (1 ms)
[ RUN ] ModuleTest.InvalidModuleKind
Using temporary directory '/tmp/ModuleTest_InvalidModuleKind_YgcYG8'
[ OK ] ModuleTest.InvalidModuleKind (0 ms)
[ RUN ] ModuleTest.ParameterWithInvalidKey
Using temporary directory '/tmp/ModuleTest_ParameterWithInvalidKey_yHQL6t'
[ OK ] ModuleTest.ParameterWithInvalidKey (1 ms)
[ RUN ] ModuleTest.ParameterWithInvalidValue
Using temporary directory '/tmp/ModuleTest_ParameterWithInvalidValue_G1tEwP'
[ OK ] ModuleTest.ParameterWithInvalidValue (0 ms)
[ RUN ] ModuleTest.DuplicateModule
Using temporary directory '/tmp/ModuleTest_DuplicateModule_Km5CWa'
[ OK ] ModuleTest.DuplicateModule (1 ms)
[ RUN ] ModuleTest.ParameterWithoutKey
Using temporary directory '/tmp/ModuleTest_ParameterWithoutKey_CGCGmw'
[ OK ] ModuleTest.ParameterWithoutKey (0 ms)
[ RUN ] ModuleTest.OlderModuleLibrary
Using temporary directory '/tmp/ModuleTest_OlderModuleLibrary_ShePMR'
[ OK ] ModuleTest.OlderModuleLibrary (1 ms)
[ RUN ] ModuleTest.EmptyLibraryFilename
Using temporary directory '/tmp/ModuleTest_EmptyLibraryFilename_Uio2cd'
[ OK ] ModuleTest.EmptyLibraryFilename (0 ms)
[ RUN ] ModuleTest.UnknownModuleInstantiationTest
Using temporary directory '/tmp/ModuleTest_UnknownModuleInstantiationTest_eobkDy'
[ OK ] ModuleTest.UnknownModuleInstantiationTest (1 ms)
[ RUN ] ModuleTest.ModuleKindMismatch
Using temporary directory '/tmp/ModuleTest_ModuleKindMismatch_AK2F3T'
[ OK ] ModuleTest.ModuleKindMismatch (0 ms)
[ RUN ] ModuleTest.NewerModuleLibrary
Using temporary directory '/tmp/ModuleTest_NewerModuleLibrary_EDA6tf'
[ OK ] ModuleTest.NewerModuleLibrary (1 ms)
[ RUN ] ModuleTest.ValidParameters
Using temporary directory '/tmp/ModuleTest_ValidParameters_6NSBUA'
[ OK ] ModuleTest.ValidParameters (0 ms)
[ RUN ] ModuleTest.AuthorInfoTest
Using temporary directory '/tmp/ModuleTest_AuthorInfoTest_UvWblW'
[ OK ] ModuleTest.AuthorInfoTest (0 ms)
[ RUN ] ModuleTest.LibraryNameWithoutExtension
Using temporary directory '/tmp/ModuleTest_LibraryNameWithoutExtension_oXdQLh'
[ OK ] ModuleTest.LibraryNameWithoutExtension (1 ms)
[ RUN ] ModuleTest.JsonParseTest
Using temporary directory '/tmp/ModuleTest_JsonParseTest_wRgzcD'
[ OK ] ModuleTest.JsonParseTest (1 ms)
[ RUN ] ModuleTest.LibraryNameWithExtension
Using temporary directory '/tmp/ModuleTest_LibraryNameWithExtension_kxzuDY'
[ OK ] ModuleTest.LibraryNameWithExtension (1 ms)
[----------] 23 tests from ModuleTest (13 ms total)
[----------] Global test environment tear-down
[==========] 505 tests from 78 test cases ran. (157999 ms total)
[ PASSED ] 504 tests.
[ FAILED ] 1 test, listed below:
[ FAILED ] MesosContainerizerDestroyTest.LauncherDestroyFailure
1 FAILED TEST
YOU HAVE 9 DISABLED TESTS
make[3]: *** [check-local] Error 1
make[3]: Leaving directory `<https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/ws/build/src'>
make[2]: *** [check-am] Error 2
make[2]: Leaving directory `<https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/ws/build/src'>
make[1]: *** [check] Error 2
make[1]: Leaving directory `<https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/ws/build/src'>
make: *** [check-recursive] Error 1
Test finished
Exit status: 2
Build step 'Execute shell' marked build as failure
Recording test results
Jenkins build is back to normal :
Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui
#2829
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/2829/changes>
Build failed in Jenkins:
Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui
#2828
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/2828/changes>
Changes:
[yujie.jay] Factored out sum function for Resources.
[yujie.jay] Added operator+= and operator+ for hashmap<SlaveID, Resources>.
------------------------------------------
[...truncated 75992 lines...]
[----------] 1 test from ZooKeeper
[ RUN ] ZooKeeper.URL
[ OK ] ZooKeeper.URL (0 ms)
[----------] 1 test from ZooKeeper (0 ms total)
[----------] 3 tests from HookTest
[ RUN ] HookTest.VerifyMasterLaunchTaskHook
Using temporary directory '/tmp/HookTest_VerifyMasterLaunchTaskHook_Y9yn3G'
I0319 23:56:32.688122 18582 leveldb.cpp:176] Opened db in 108.107259ms
I0319 23:56:32.746817 18582 leveldb.cpp:183] Compacted db in 58.615756ms
I0319 23:56:32.746924 18582 leveldb.cpp:198] Created db iterator in 27322ns
I0319 23:56:32.746944 18582 leveldb.cpp:204] Seeked to beginning of db in 3560ns
I0319 23:56:32.746955 18582 leveldb.cpp:273] Iterated through 0 keys in the db in 263ns
I0319 23:56:32.747006 18582 replica.cpp:744] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
I0319 23:56:32.747824 18620 recover.cpp:449] Starting replica recovery
I0319 23:56:32.748056 18620 recover.cpp:475] Replica is in EMPTY status
I0319 23:56:32.749167 18611 replica.cpp:641] Replica in EMPTY status received a broadcasted recover request
I0319 23:56:32.749402 18614 recover.cpp:195] Received a recover response from a replica in EMPTY status
I0319 23:56:32.749831 18618 recover.cpp:566] Updating replica status to STARTING
I0319 23:56:32.749951 18612 master.cpp:358] Master 20150319-235632-3176252227-48061-18582 (proserpina.apache.org) started on 67.195.81.189:48061
I0319 23:56:32.750000 18612 master.cpp:404] Master only allowing authenticated frameworks to register
I0319 23:56:32.750011 18612 master.cpp:409] Master only allowing authenticated slaves to register
I0319 23:56:32.750033 18612 credentials.hpp:37] Loading credentials for authentication from '/tmp/HookTest_VerifyMasterLaunchTaskHook_Y9yn3G/credentials'
I0319 23:56:32.750311 18612 master.cpp:451] Authorization enabled
I0319 23:56:32.750860 18616 whitelist_watcher.cpp:79] No whitelist given
I0319 23:56:32.751029 18611 hierarchical.hpp:287] Initialized hierarchical allocator process
I0319 23:56:32.752022 18611 master.cpp:1374] The newly elected leader is master@67.195.81.189:48061 with id 20150319-235632-3176252227-48061-18582
I0319 23:56:32.752048 18611 master.cpp:1387] Elected as the leading master!
I0319 23:56:32.752064 18611 master.cpp:1165] Recovering from registrar
I0319 23:56:32.752339 18620 registrar.cpp:313] Recovering registrar
I0319 23:56:32.788537 18613 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 38.158899ms
I0319 23:56:32.788617 18613 replica.cpp:323] Persisted replica status to STARTING
I0319 23:56:32.789693 18613 recover.cpp:475] Replica is in STARTING status
I0319 23:56:32.791786 18625 replica.cpp:641] Replica in STARTING status received a broadcasted recover request
I0319 23:56:32.792600 18613 recover.cpp:195] Received a recover response from a replica in STARTING status
I0319 23:56:32.793501 18613 recover.cpp:566] Updating replica status to VOTING
I0319 23:56:32.855921 18611 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 61.996666ms
I0319 23:56:32.855990 18611 replica.cpp:323] Persisted replica status to VOTING
I0319 23:56:32.856220 18622 recover.cpp:580] Successfully joined the Paxos group
I0319 23:56:32.856451 18622 recover.cpp:464] Recover process terminated
I0319 23:56:32.857142 18619 log.cpp:660] Attempting to start the writer
I0319 23:56:32.858432 18624 replica.cpp:477] Replica received implicit promise request with proposal 1
I0319 23:56:32.890548 18624 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 32.061642ms
I0319 23:56:32.890627 18624 replica.cpp:345] Persisted promised to 1
I0319 23:56:32.891376 18615 coordinator.cpp:230] Coordinator attemping to fill missing position
I0319 23:56:32.892595 18620 replica.cpp:378] Replica received explicit promise request for position 0 with proposal 2
I0319 23:56:32.939208 18620 leveldb.cpp:343] Persisting action (8 bytes) to leveldb took 46.561226ms
I0319 23:56:32.939291 18620 replica.cpp:679] Persisted action at 0
I0319 23:56:32.940659 18617 replica.cpp:511] Replica received write request for position 0
I0319 23:56:32.940749 18617 leveldb.cpp:438] Reading position from leveldb took 58103ns
I0319 23:56:32.961671 18627 process.cpp:2067] Dropped / Lost event for PID: __waiter__(1458)@67.195.81.189:48061
I0319 23:56:33.022475 18617 leveldb.cpp:343] Persisting action (14 bytes) to leveldb took 81.658835ms
I0319 23:56:33.022586 18617 replica.cpp:679] Persisted action at 0
I0319 23:56:33.023588 18618 replica.cpp:658] Replica received learned notice for position 0
I0319 23:56:33.063735 18618 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 40.082197ms
I0319 23:56:33.063814 18618 replica.cpp:679] Persisted action at 0
I0319 23:56:33.063846 18618 replica.cpp:664] Replica learned NOP action at position 0
I0319 23:56:33.064609 18617 log.cpp:676] Writer started with ending position 0
I0319 23:56:33.065906 18625 leveldb.cpp:438] Reading position from leveldb took 46866ns
I0319 23:56:33.068755 18614 registrar.cpp:346] Successfully fetched the registry (0B) in 316.37504ms
I0319 23:56:33.068864 18614 registrar.cpp:445] Applied 1 operations in 26429ns; attempting to update the 'registry'
I0319 23:56:33.071493 18611 log.cpp:684] Attempting to append 143 bytes to the log
I0319 23:56:33.071605 18618 coordinator.cpp:340] Coordinator attempting to write APPEND action at position 1
I0319 23:56:33.072252 18625 replica.cpp:511] Replica received write request for position 1
I0319 23:56:33.099802 18627 process.cpp:2067] Dropped / Lost event for PID: hierarchical-allocator(262)@67.195.81.189:48061
I0319 23:56:33.105772 18625 leveldb.cpp:343] Persisting action (162 bytes) to leveldb took 33.481181ms
I0319 23:56:33.105828 18625 replica.cpp:679] Persisted action at 1
I0319 23:56:33.107218 18621 replica.cpp:658] Replica received learned notice for position 1
I0319 23:56:33.131132 18621 leveldb.cpp:343] Persisting action (164 bytes) to leveldb took 23.86755ms
I0319 23:56:33.131206 18621 replica.cpp:679] Persisted action at 1
I0319 23:56:33.131237 18621 replica.cpp:664] Replica learned APPEND action at position 1
I0319 23:56:33.132818 18612 registrar.cpp:490] Successfully updated the 'registry' in 63.872256ms
I0319 23:56:33.132936 18612 registrar.cpp:376] Successfully recovered registrar
I0319 23:56:33.132972 18611 log.cpp:703] Attempting to truncate the log to 1
I0319 23:56:33.133177 18611 coordinator.cpp:340] Coordinator attempting to write TRUNCATE action at position 2
I0319 23:56:33.133229 18612 master.cpp:1192] Recovered 0 slaves from the Registry (105B) ; allowing 10mins for slaves to re-register
I0319 23:56:33.134135 18612 replica.cpp:511] Replica received write request for position 2
I0319 23:56:33.156566 18612 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 22.373665ms
I0319 23:56:33.156653 18612 replica.cpp:679] Persisted action at 2
I0319 23:56:33.158303 18625 replica.cpp:658] Replica received learned notice for position 2
I0319 23:56:33.181902 18625 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 23.546806ms
I0319 23:56:33.182039 18625 leveldb.cpp:401] Deleting ~1 keys from leveldb took 60490ns
I0319 23:56:33.182070 18625 replica.cpp:679] Persisted action at 2
I0319 23:56:33.182102 18625 replica.cpp:664] Replica learned TRUNCATE action at position 2
I0319 23:56:33.191092 18611 slave.cpp:176] Slave started on @67.195.81.189:48061
I0319 23:56:33.191146 18611 credentials.hpp:85] Loading credential for authentication from '/tmp/HookTest_VerifyMasterLaunchTaskHook_8b6lzz/credential'
I0319 23:56:33.191300 18611 slave.cpp:283] Slave using credential for: test-principal
I0319 23:56:33.191511 18611 slave.cpp:301] Slave resources: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]
I0319 23:56:33.191601 18611 slave.cpp:330] Slave hostname: proserpina.apache.org
I0319 23:56:33.191613 18611 slave.cpp:331] Slave checkpoint: false
W0319 23:56:33.191619 18611 slave.cpp:333] Disabling checkpointing is deprecated and the --checkpoint flag will be removed in a future release. Please avoid using this flag
I0319 23:56:33.192592 18611 state.cpp:35] Recovering state from '/tmp/HookTest_VerifyMasterLaunchTaskHook_8b6lzz/meta'
I0319 23:56:33.192865 18611 status_update_manager.cpp:197] Recovering status update manager
I0319 23:56:33.193202 18616 slave.cpp:3763] Finished recovery
I0319 23:56:33.193886 18611 status_update_manager.cpp:171] Pausing sending status updates
I0319 23:56:33.193900 18625 slave.cpp:612] New master detected at master@67.195.81.189:48061
I0319 23:56:33.194006 18625 slave.cpp:675] Authenticating with master master@67.195.81.189:48061
I0319 23:56:33.194036 18625 slave.cpp:680] Using default CRAM-MD5 authenticatee
I0319 23:56:33.194170 18625 slave.cpp:648] Detecting new master
I0319 23:56:33.194349 18620 authenticatee.hpp:139] Creating new client SASL connection
I0319 23:56:33.194566 18625 master.cpp:3815] Authenticating (5406)@67.195.81.189:48061
I0319 23:56:33.194604 18625 master.cpp:3826] Using default CRAM-MD5 authenticator
I0319 23:56:33.194908 18618 authenticator.hpp:170] Creating new server SASL connection
I0319 23:56:33.195057 18625 authenticatee.hpp:230] Received SASL authentication mechanisms: CRAM-MD5
I0319 23:56:33.195086 18625 authenticatee.hpp:256] Attempting to authenticate with mechanism 'CRAM-MD5'
I0319 23:56:33.195160 18625 authenticator.hpp:276] Received SASL authentication start
I0319 23:56:33.195207 18625 authenticator.hpp:398] Authentication requires more steps
I0319 23:56:33.195273 18625 authenticatee.hpp:276] Received SASL authentication step
I0319 23:56:33.195410 18618 authenticator.hpp:304] Received SASL authentication step
I0319 23:56:33.195446 18618 auxprop.cpp:99] Request to lookup properties for user: 'test-principal' realm: 'proserpina.apache.org' server FQDN: 'proserpina.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
I0319 23:56:33.195461 18618 auxprop.cpp:171] Looking up auxiliary property '*userPassword'
I0319 23:56:33.195510 18618 auxprop.cpp:171] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0319 23:56:33.195541 18618 auxprop.cpp:99] Request to lookup properties for user: 'test-principal' realm: 'proserpina.apache.org' server FQDN: 'proserpina.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
I0319 23:56:33.195554 18618 auxprop.cpp:121] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I0319 23:56:33.195564 18618 auxprop.cpp:121] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0319 23:56:33.195585 18618 authenticator.hpp:390] Authentication success
I0319 23:56:33.195665 18625 authenticatee.hpp:316] Authentication success
I0319 23:56:33.195729 18612 master.cpp:3873] Successfully authenticated principal 'test-principal' at (5406)@67.195.81.189:48061
I0319 23:56:33.196149 18626 slave.cpp:746] Successfully authenticated with master master@67.195.81.189:48061
I0319 23:56:33.196303 18626 slave.cpp:1078] Will retry registration in 17.225993ms if necessary
I0319 23:56:33.196652 18626 master.cpp:2945] Registering slave at (5406)@67.195.81.189:48061 (proserpina.apache.org) with id 20150319-235632-3176252227-48061-18582-S0
I0319 23:56:33.197410 18611 registrar.cpp:445] Applied 1 operations in 75737ns; attempting to update the 'registry'
I0319 23:56:33.200342 18611 log.cpp:684] Attempting to append 324 bytes to the log
I0319 23:56:33.200589 18626 coordinator.cpp:340] Coordinator attempting to write APPEND action at position 3
I0319 23:56:33.201804 18626 replica.cpp:511] Replica received write request for position 3
I0319 23:56:33.205606 18582 sched.cpp:157] Version: 0.23.0
I0319 23:56:33.206243 18618 sched.cpp:254] New master detected at master@67.195.81.189:48061
I0319 23:56:33.206357 18618 sched.cpp:310] Authenticating with master master@67.195.81.189:48061
I0319 23:56:33.206379 18618 sched.cpp:317] Using default CRAM-MD5 authenticatee
I0319 23:56:33.206648 18618 authenticatee.hpp:139] Creating new client SASL connection
I0319 23:56:33.207020 18618 master.cpp:3815] Authenticating scheduler-c1b4faee-5d85-4884-8000-7ebf49022394@67.195.81.189:48061
I0319 23:56:33.207054 18618 master.cpp:3826] Using default CRAM-MD5 authenticator
I0319 23:56:33.207372 18618 authenticator.hpp:170] Creating new server SASL connection
I0319 23:56:33.207514 18618 authenticatee.hpp:230] Received SASL authentication mechanisms: CRAM-MD5
I0319 23:56:33.207538 18618 authenticatee.hpp:256] Attempting to authenticate with mechanism 'CRAM-MD5'
I0319 23:56:33.207614 18618 authenticator.hpp:276] Received SASL authentication start
I0319 23:56:33.207661 18618 authenticator.hpp:398] Authentication requires more steps
I0319 23:56:33.207821 18618 authenticatee.hpp:276] Received SASL authentication step
I0319 23:56:33.207924 18618 authenticator.hpp:304] Received SASL authentication step
I0319 23:56:33.207952 18618 auxprop.cpp:99] Request to lookup properties for user: 'test-principal' realm: 'proserpina.apache.org' server FQDN: 'proserpina.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
I0319 23:56:33.207965 18618 auxprop.cpp:171] Looking up auxiliary property '*userPassword'
I0319 23:56:33.208014 18618 auxprop.cpp:171] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0319 23:56:33.208041 18618 auxprop.cpp:99] Request to lookup properties for user: 'test-principal' realm: 'proserpina.apache.org' server FQDN: 'proserpina.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
I0319 23:56:33.208055 18618 auxprop.cpp:121] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I0319 23:56:33.208065 18618 auxprop.cpp:121] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0319 23:56:33.208082 18618 authenticator.hpp:390] Authentication success
I0319 23:56:33.208268 18618 authenticatee.hpp:316] Authentication success
I0319 23:56:33.208343 18618 master.cpp:3873] Successfully authenticated principal 'test-principal' at scheduler-c1b4faee-5d85-4884-8000-7ebf49022394@67.195.81.189:48061
I0319 23:56:33.208816 18617 sched.cpp:398] Successfully authenticated with master master@67.195.81.189:48061
I0319 23:56:33.208844 18617 sched.cpp:521] Sending registration request to master@67.195.81.189:48061
I0319 23:56:33.208900 18617 sched.cpp:554] Will retry registration in 60.244493ms if necessary
I0319 23:56:33.209218 18618 master.cpp:1592] Received registration request for framework 'default' at scheduler-c1b4faee-5d85-4884-8000-7ebf49022394@67.195.81.189:48061
I0319 23:56:33.209301 18618 master.cpp:1453] Authorizing framework principal 'test-principal' to receive offers for role '*'
I0319 23:56:33.209763 18624 master.cpp:1656] Registering framework 20150319-235632-3176252227-48061-18582-0000 (default) at scheduler-c1b4faee-5d85-4884-8000-7ebf49022394@67.195.81.189:48061
I0319 23:56:33.210150 18613 hierarchical.hpp:321] Added framework 20150319-235632-3176252227-48061-18582-0000
I0319 23:56:33.210177 18613 hierarchical.hpp:818] No resources available to allocate!
I0319 23:56:33.210191 18613 hierarchical.hpp:725] Performed allocation for 0 slaves in 20439ns
I0319 23:56:33.210268 18613 sched.cpp:448] Framework registered with 20150319-235632-3176252227-48061-18582-0000
I0319 23:56:33.210307 18613 sched.cpp:462] Scheduler::registered took 20633ns
I0319 23:56:33.215451 18624 slave.cpp:1078] Will retry registration in 24.042428ms if necessary
I0319 23:56:33.215615 18620 master.cpp:2933] Ignoring register slave message from (5406)@67.195.81.189:48061 (proserpina.apache.org) as admission is already in progress
I0319 23:56:33.240170 18615 slave.cpp:1078] Will retry registration in 42.808242ms if necessary
I0319 23:56:33.240316 18614 master.cpp:2933] Ignoring register slave message from (5406)@67.195.81.189:48061 (proserpina.apache.org) as admission is already in progress
I0319 23:56:33.241935 18626 leveldb.cpp:343] Persisting action (343 bytes) to leveldb took 40.0908ms
I0319 23:56:33.241977 18626 replica.cpp:679] Persisted action at 3
I0319 23:56:33.242988 18624 replica.cpp:658] Replica received learned notice for position 3
I0319 23:56:33.283838 18613 slave.cpp:1078] Will retry registration in 138.461912ms if necessary
I0319 23:56:33.284006 18616 master.cpp:2933] Ignoring register slave message from (5406)@67.195.81.189:48061 (proserpina.apache.org) as admission is already in progress
I0319 23:56:33.300742 18624 leveldb.cpp:343] Persisting action (345 bytes) to leveldb took 57.684777ms
I0319 23:56:33.300815 18624 replica.cpp:679] Persisted action at 3
I0319 23:56:33.300848 18624 replica.cpp:664] Replica learned APPEND action at position 3
I0319 23:56:33.302220 18611 registrar.cpp:490] Successfully updated the 'registry' in 104.72704ms
I0319 23:56:33.302520 18619 log.cpp:703] Attempting to truncate the log to 3
I0319 23:56:33.302634 18611 coordinator.cpp:340] Coordinator attempting to write TRUNCATE action at position 4
I0319 23:56:33.303021 18611 slave.cpp:2799] Received ping from slave-observer(203)@67.195.81.189:48061
I0319 23:56:33.303180 18611 slave.cpp:780] Registered with master master@67.195.81.189:48061; given slave ID 20150319-235632-3176252227-48061-18582-S0
I0319 23:56:33.303134 18618 master.cpp:3002] Registered slave 20150319-235632-3176252227-48061-18582-S0 at (5406)@67.195.81.189:48061 (proserpina.apache.org) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]
I0319 23:56:33.303289 18626 status_update_manager.cpp:178] Resuming sending status updates
I0319 23:56:33.303349 18624 hierarchical.hpp:439] Added slave 20150319-235632-3176252227-48061-18582-S0 (proserpina.apache.org) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] (and cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] available)
I0319 23:56:33.303577 18611 replica.cpp:511] Replica received write request for position 4
I0319 23:56:33.303864 18624 hierarchical.hpp:743] Performed allocation for slave 20150319-235632-3176252227-48061-18582-S0 in 441159ns
I0319 23:56:33.304106 18618 master.cpp:3757] Sending 1 offers to framework 20150319-235632-3176252227-48061-18582-0000 (default) at scheduler-c1b4faee-5d85-4884-8000-7ebf49022394@67.195.81.189:48061
I0319 23:56:33.304497 18625 sched.cpp:611] Scheduler::resourceOffers took 75701ns
I0319 23:56:33.305966 18624 master.cpp:2285] Processing ACCEPT call for offers: [ 20150319-235632-3176252227-48061-18582-O0 ] on slave 20150319-235632-3176252227-48061-18582-S0 at (5406)@67.195.81.189:48061 (proserpina.apache.org) for framework 20150319-235632-3176252227-48061-18582-0000 (default) at scheduler-c1b4faee-5d85-4884-8000-7ebf49022394@67.195.81.189:48061
I0319 23:56:33.306017 18624 master.cpp:2130] Authorizing framework principal 'test-principal' to launch task 1 as user 'jenkins'
I0319 23:56:33.307518 18614 master.hpp:802] Adding task 1 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20150319-235632-3176252227-48061-18582-S0 (proserpina.apache.org)
I0319 23:56:33.307677 18614 master.cpp:2557] Launching task 1 of framework 20150319-235632-3176252227-48061-18582-0000 (default) at scheduler-c1b4faee-5d85-4884-8000-7ebf49022394@67.195.81.189:48061 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20150319-235632-3176252227-48061-18582-S0 at (5406)@67.195.81.189:48061 (proserpina.apache.org)
I0319 23:56:33.307845 18614 test_hook_module.cpp:45] Executing 'masterLaunchTaskLabelDecorator' hook
I0319 23:56:33.308418 18582 sched.cpp:1589] Asked to stop the driver
I0319 23:56:33.308517 18622 sched.cpp:831] Stopping framework '20150319-235632-3176252227-48061-18582-0000'
I0319 23:56:33.308727 18618 master.cpp:1916] Asked to unregister framework 20150319-235632-3176252227-48061-18582-0000
I0319 23:56:33.308765 18618 master.cpp:4185] Removing framework 20150319-235632-3176252227-48061-18582-0000 (default) at scheduler-c1b4faee-5d85-4884-8000-7ebf49022394@67.195.81.189:48061
I0319 23:56:33.308751 18614 slave.cpp:494] Slave terminating
I0319 23:56:33.308889 18625 hierarchical.hpp:400] Deactivated framework 20150319-235632-3176252227-48061-18582-0000
I0319 23:56:33.309011 18618 process.cpp:2067] Dropped / Lost event for PID: (5406)@67.195.81.189:48061
I0319 23:56:33.311152 18618 master.cpp:4617] Updating the latest state of task 1 of framework 20150319-235632-3176252227-48061-18582-0000 to TASK_KILLED
I0319 23:56:33.311553 18623 hierarchical.hpp:632] Recovered cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] (total allocatable: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]) on slave 20150319-235632-3176252227-48061-18582-S0 from framework 20150319-235632-3176252227-48061-18582-0000
I0319 23:56:33.311693 18618 master.cpp:4682] Removing task 1 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] of framework 20150319-235632-3176252227-48061-18582-0000 on slave 20150319-235632-3176252227-48061-18582-S0 at (5406)@67.195.81.189:48061 (proserpina.apache.org)
I0319 23:56:33.312185 18618 master.cpp:752] Master terminating
I0319 23:56:33.312273 18616 hierarchical.hpp:354] Removed framework 20150319-235632-3176252227-48061-18582-0000
I0319 23:56:33.312378 18616 hierarchical.hpp:470] Removed slave 20150319-235632-3176252227-48061-18582-S0
I0319 23:56:33.314257 18582 process.cpp:2067] Dropped / Lost event for PID: master@67.195.81.189:48061
I0319 23:56:33.314366 18582 process.cpp:2067] Dropped / Lost event for PID: master@67.195.81.189:48061
I0319 23:56:33.314950 18619 process.cpp:2067] Dropped / Lost event for PID: log-coordinator(303)@67.195.81.189:48061
I0319 23:56:33.334215 18611 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 30.56383ms
I0319 23:56:33.334357 18611 replica.cpp:679] Persisted action at 4
I0319 23:56:33.334434 18611 process.cpp:2067] Dropped / Lost event for PID: (5410)@67.195.81.189:48061
I0319 23:56:33.335268 18582 process.cpp:2067] Dropped / Lost event for PID: scheduler-c1b4faee-5d85-4884-8000-7ebf49022394@67.195.81.189:48061
I0319 23:56:33.336596 18582 process.cpp:2067] Dropped / Lost event for PID: (5406)@67.195.81.189:48061
[ OK ] HookTest.VerifyMasterLaunchTaskHook (759 ms)
[ RUN ] HookTest.VerifySlaveExecutorEnvironmentDecorator
Using temporary directory '/tmp/HookTest_VerifySlaveExecutorEnvironmentDecorator_cPPg0k'
I0319 23:56:33.338142 18582 containerizer.cpp:113] Using isolation: posix/cpu,posix/mem
I0319 23:56:33.338605 18623 containerizer.cpp:469] Starting container 'test_container' for executor 'executor' of framework ''
I0319 23:56:33.339643 18623 test_hook_module.cpp:61] Executing 'slaveExecutorEnvironmentDecorator' hook
I0319 23:56:33.341132 18623 launcher.cpp:130] Forked child with pid '31406' for container 'test_container'
I0319 23:56:33.422914 18627 process.cpp:2067] Dropped / Lost event for PID: (5406)@67.195.81.189:48061
I0319 23:56:33.490775 18619 containerizer.cpp:1159] Executor for container 'test_container' has exited
I0319 23:56:33.490834 18619 containerizer.cpp:950] Destroying container 'test_container'
[ OK ] HookTest.VerifySlaveExecutorEnvironmentDecorator (179 ms)
[ RUN ] HookTest.HookLoading
Using temporary directory '/tmp/HookTest_HookLoading_cRUJh7'
[ OK ] HookTest.HookLoading (0 ms)
[----------] 3 tests from HookTest (938 ms total)
[----------] Global test environment tear-down
I0319 23:56:33.705442 18627 process.cpp:2067] Dropped / Lost event for PID: scheduler-38c79962-83d1-48fc-a056-8a8d30334e02@67.195.81.189:48061
I0319 23:56:33.706673 18627 process.cpp:2067] Dropped / Lost event for PID: master@67.195.81.189:48061
I0319 23:56:33.752070 18627 process.cpp:2067] Dropped / Lost event for PID: hierarchical-allocator(263)@67.195.81.189:48061
I0319 23:56:33.806890 18627 process.cpp:2067] Dropped / Lost event for PID: slave(230)@67.195.81.189:48061
[==========] 505 tests from 78 test cases ran. (394241 ms total)
[ PASSED ] 504 tests.
[ FAILED ] 1 test, listed below:
[ FAILED ] ExamplesTest.LowLevelSchedulerLibprocess
1 FAILED TEST
YOU HAVE 9 DISABLED TESTS
make[3]: *** [check-local] Error 1
make[3]: Leaving directory `<https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/ws/build/src'>
make[2]: *** [check-am] Error 2
make[2]: Leaving directory `<https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/ws/build/src'>
make[1]: *** [check] Error 2
make[1]: Leaving directory `<https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/ws/build/src'>
make: *** [check-recursive] Error 1
Test finished
Exit status: 2
Build step 'Execute shell' marked build as failure
Recording test results