You are viewing a plain text version of this content. The canonical link for it is here.
Posted to builds@mesos.apache.org by Apache Jenkins Server <je...@builds.apache.org> on 2017/03/15 01:00:48 UTC

Build failed in Jenkins: Mesos-Buildbot » autotools,gcc,--verbose,GLOG_v=1 MESOS_VERBOSE=1,centos:7,(docker||Hadoop)&&(!ubuntu-us1)&&(!ubuntu-eu2) #3372

See <https://builds.apache.org/job/Mesos-Buildbot/BUILDTOOL=autotools,COMPILER=gcc,CONFIGURATION=--verbose,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1,OS=centos%3A7,label_exp=(docker%7C%7CHadoop)&&(!ubuntu-us1)&&(!ubuntu-eu2)/3372/display/redirect?page=changes>

Changes:

[xujyan] Check task user before allowing a task to be launched on the agent.

[xujyan] Test to ensure non-authorized users cannot launch tasks on agents.

[xujyan] Fixed a duplicate `AuthorizeRunTaskOnAgent` due to merge error.

------------------------------------------
[...truncated 3.04 MB...]
I0315 01:00:27.740391 31642 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
I0315 01:00:27.740507 31641 authenticator.cpp:204] Received SASL authentication start
I0315 01:00:27.740569 31641 authenticator.cpp:326] Authentication requires more steps
I0315 01:00:27.740674 31642 authenticatee.cpp:259] Received SASL authentication step
I0315 01:00:27.740609 31655 slave.cpp:545] Agent resources: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]
I0315 01:00:27.740732 31655 slave.cpp:553] Agent attributes: [  ]
I0315 01:00:27.740751 31655 slave.cpp:558] Agent hostname: 5b7065a6b902
I0315 01:00:27.740798 31642 authenticator.cpp:232] Received SASL authentication step
I0315 01:00:27.740836 31642 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '5b7065a6b902' server FQDN: '5b7065a6b902' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 
I0315 01:00:27.740860 31642 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
I0315 01:00:27.740916 31642 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0315 01:00:27.740965 31642 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '5b7065a6b902' server FQDN: '5b7065a6b902' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 
I0315 01:00:27.740983 31642 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I0315 01:00:27.740990 31642 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0315 01:00:27.741008 31642 authenticator.cpp:318] Authentication success
I0315 01:00:27.741098 31652 authenticatee.cpp:299] Authentication success
I0315 01:00:27.741194 31650 master.cpp:7282] Successfully authenticated principal 'test-principal' at scheduler-fd8b68d4-7e58-41d1-966d-f8882e26a7ef@172.17.0.3:34409
I0315 01:00:27.741454 31647 sched.cpp:513] Successfully authenticated with master master@172.17.0.3:34409
I0315 01:00:27.741480 31647 sched.cpp:836] Sending SUBSCRIBE call to master@172.17.0.3:34409
I0315 01:00:27.741498 31633 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(34)@172.17.0.3:34409
I0315 01:00:27.741593 31647 sched.cpp:869] Will retry registration in 673.934967ms if necessary
I0315 01:00:27.741838 31644 master.cpp:2817] Received SUBSCRIBE call for framework 'default' at scheduler-fd8b68d4-7e58-41d1-966d-f8882e26a7ef@172.17.0.3:34409
I0315 01:00:27.741921 31644 master.cpp:2201] Authorizing framework principal 'test-principal' to receive offers for roles '{ * }'
I0315 01:00:27.742368 31654 master.cpp:2894] Subscribing framework default with checkpointing disabled and capabilities [  ]
I0315 01:00:27.742985 31654 state.cpp:62] Recovering state from '/tmp/HTTPCommandExecutorTest_TerminateWithACK_afoUZl/meta'
I0315 01:00:27.743084 31636 status_update_manager.cpp:177] Pausing sending status updates
I0315 01:00:27.743118 31635 sched.cpp:759] Framework registered with 47ac227f-5c40-4f74-becb-fe5af6ac8363-0000
I0315 01:00:27.743177 31635 sched.cpp:773] Scheduler::registered took 28949ns
I0315 01:00:27.743252 31645 hierarchical.cpp:271] Added framework 47ac227f-5c40-4f74-becb-fe5af6ac8363-0000
I0315 01:00:27.743405 31645 hierarchical.cpp:1854] No allocations performed
I0315 01:00:27.743453 31645 hierarchical.cpp:1944] No inverse offers to send out!
I0315 01:00:27.743520 31645 hierarchical.cpp:1438] Performed allocation for 0 agents in 165296ns
I0315 01:00:27.743896 31643 status_update_manager.cpp:203] Recovering status update manager
I0315 01:00:27.744083 31633 containerizer.cpp:608] Recovering containerizer
I0315 01:00:27.745878 31656 provisioner.cpp:410] Provisioner recovery complete
I0315 01:00:27.746224 31645 slave.cpp:5753] Finished recovery
I0315 01:00:27.746721 31645 slave.cpp:5935] Querying resource estimator for oversubscribable resources
I0315 01:00:27.746960 31645 slave.cpp:936] New master detected at master@172.17.0.3:34409
I0315 01:00:27.746969 31637 status_update_manager.cpp:177] Pausing sending status updates
I0315 01:00:27.747102 31645 slave.cpp:971] Detecting new master
I0315 01:00:27.750422 31645 slave.cpp:998] Authenticating with master master@172.17.0.3:34409
I0315 01:00:27.750517 31645 slave.cpp:1009] Using default CRAM-MD5 authenticatee
I0315 01:00:27.750852 31645 authenticatee.cpp:121] Creating new client SASL connection
I0315 01:00:27.751199 31650 master.cpp:7252] Authenticating (13)@172.17.0.3:34409
I0315 01:00:27.751368 31645 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(35)@172.17.0.3:34409
I0315 01:00:27.751610 31636 authenticator.cpp:98] Creating new server SASL connection
I0315 01:00:27.751888 31651 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
I0315 01:00:27.751922 31651 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
I0315 01:00:27.752027 31650 authenticator.cpp:204] Received SASL authentication start
I0315 01:00:27.752089 31650 authenticator.cpp:326] Authentication requires more steps
I0315 01:00:27.752220 31649 authenticatee.cpp:259] Received SASL authentication step
I0315 01:00:27.752349 31651 authenticator.cpp:232] Received SASL authentication step
I0315 01:00:27.752388 31651 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '5b7065a6b902' server FQDN: '5b7065a6b902' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 
I0315 01:00:27.752405 31651 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
I0315 01:00:27.752444 31651 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
I0315 01:00:27.752460 31651 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '5b7065a6b902' server FQDN: '5b7065a6b902' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 
I0315 01:00:27.752468 31651 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
I0315 01:00:27.752475 31651 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I0315 01:00:27.752488 31651 authenticator.cpp:318] Authentication success
I0315 01:00:27.752568 31649 authenticatee.cpp:299] Authentication success
I0315 01:00:27.752630 31651 master.cpp:7282] Successfully authenticated principal 'test-principal' at (13)@172.17.0.3:34409
I0315 01:00:27.752668 31649 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(35)@172.17.0.3:34409
I0315 01:00:27.753057 31651 slave.cpp:1093] Successfully authenticated with master master@172.17.0.3:34409
I0315 01:00:27.753265 31651 slave.cpp:1521] Will retry registration in 10.597529ms if necessary
I0315 01:00:27.753492 31636 master.cpp:5437] Registering agent at (13)@172.17.0.3:34409 (5b7065a6b902) with id 47ac227f-5c40-4f74-becb-fe5af6ac8363-S0
I0315 01:00:27.753968 31643 registrar.cpp:463] Applied 1 operations in 73567ns; attempting to update the registry
I0315 01:00:27.755733 31643 registrar.cpp:508] Successfully updated the registry in 1.690112ms
I0315 01:00:27.756484 31641 slave.cpp:4536] Received ping from slave-observer(9)@172.17.0.3:34409
I0315 01:00:27.756651 31637 master.cpp:5511] Registered agent 47ac227f-5c40-4f74-becb-fe5af6ac8363-S0 at (13)@172.17.0.3:34409 (5b7065a6b902) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]
I0315 01:00:27.756861 31637 slave.cpp:1139] Registered with master master@172.17.0.3:34409; given agent ID 47ac227f-5c40-4f74-becb-fe5af6ac8363-S0
I0315 01:00:27.756886 31637 fetcher.cpp:94] Clearing fetcher cache
I0315 01:00:27.757081 31641 hierarchical.cpp:527] Added agent 47ac227f-5c40-4f74-becb-fe5af6ac8363-S0 (5b7065a6b902) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] (allocated: {})
I0315 01:00:27.757339 31637 slave.cpp:1167] Checkpointing SlaveInfo to '/tmp/HTTPCommandExecutorTest_TerminateWithACK_afoUZl/meta/slaves/47ac227f-5c40-4f74-becb-fe5af6ac8363-S0/slave.info'
I0315 01:00:27.757740 31637 status_update_manager.cpp:184] Resuming sending status updates
I0315 01:00:27.758961 31641 hierarchical.cpp:1944] No inverse offers to send out!
I0315 01:00:27.759043 31641 hierarchical.cpp:1438] Performed allocation for 1 agents in 1.81414ms
I0315 01:00:27.759449 31637 master.cpp:7081] Sending 1 offers to framework 47ac227f-5c40-4f74-becb-fe5af6ac8363-0000 (default) at scheduler-fd8b68d4-7e58-41d1-966d-f8882e26a7ef@172.17.0.3:34409
I0315 01:00:27.760067 31635 sched.cpp:933] Scheduler::resourceOffers took 167469ns
I0315 01:00:27.762023 31653 master.cpp:3839] Processing ACCEPT call for offers: [ 47ac227f-5c40-4f74-becb-fe5af6ac8363-O0 ] on agent 47ac227f-5c40-4f74-becb-fe5af6ac8363-S0 at (13)@172.17.0.3:34409 (5b7065a6b902) for framework 47ac227f-5c40-4f74-becb-fe5af6ac8363-0000 (default) at scheduler-fd8b68d4-7e58-41d1-966d-f8882e26a7ef@172.17.0.3:34409
I0315 01:00:27.762135 31653 master.cpp:3415] Authorizing framework principal 'test-principal' to launch task 22ea580c-4530-4b2f-8761-cecd3bfe562e
I0315 01:00:27.764308 31653 master.cpp:9097] Adding task 22ea580c-4530-4b2f-8761-cecd3bfe562e with resources cpus(*)(allocated: *):2; mem(*)(allocated: *):1024; disk(*)(allocated: *):1024; ports(*)(allocated: *):[31000-32000] on agent 47ac227f-5c40-4f74-becb-fe5af6ac8363-S0 at (13)@172.17.0.3:34409 (5b7065a6b902)
I0315 01:00:27.764652 31653 master.cpp:4489] Launching task 22ea580c-4530-4b2f-8761-cecd3bfe562e of framework 47ac227f-5c40-4f74-becb-fe5af6ac8363-0000 (default) at scheduler-fd8b68d4-7e58-41d1-966d-f8882e26a7ef@172.17.0.3:34409 with resources cpus(*)(allocated: *):2; mem(*)(allocated: *):1024; disk(*)(allocated: *):1024; ports(*)(allocated: *):[31000-32000] on agent 47ac227f-5c40-4f74-becb-fe5af6ac8363-S0 at (13)@172.17.0.3:34409 (5b7065a6b902)
I0315 01:00:27.765573 31654 slave.cpp:1631] Got assigned task '22ea580c-4530-4b2f-8761-cecd3bfe562e' for framework 47ac227f-5c40-4f74-becb-fe5af6ac8363-0000
I0315 01:00:27.766599 31654 slave.cpp:1912] Authorizing task '22ea580c-4530-4b2f-8761-cecd3bfe562e' for framework 47ac227f-5c40-4f74-becb-fe5af6ac8363-0000
I0315 01:00:27.767678 31654 slave.cpp:2099] Launching task '22ea580c-4530-4b2f-8761-cecd3bfe562e' for framework 47ac227f-5c40-4f74-becb-fe5af6ac8363-0000
I0315 01:00:27.768465 31653 hierarchical.cpp:844] Updated allocation of framework 47ac227f-5c40-4f74-becb-fe5af6ac8363-0000 on agent 47ac227f-5c40-4f74-becb-fe5af6ac8363-S0 from cpus(*)(allocated: *):2; mem(*)(allocated: *):1024; disk(*)(allocated: *):1024; ports(*)(allocated: *):[31000-32000] to cpus(*)(allocated: *):2; mem(*)(allocated: *):1024; disk(*)(allocated: *):1024; ports(*)(allocated: *):[31000-32000]
I0315 01:00:27.768540 31654 paths.cpp:547] Trying to chown '/tmp/HTTPCommandExecutorTest_TerminateWithACK_afoUZl/slaves/47ac227f-5c40-4f74-becb-fe5af6ac8363-S0/frameworks/47ac227f-5c40-4f74-becb-fe5af6ac8363-0000/executors/22ea580c-4530-4b2f-8761-cecd3bfe562e/runs/4e2a9d41-71eb-4b86-8f30-f5a7504cc39b' to user 'mesos'
I0315 01:00:27.768844 31654 slave.cpp:6719] Launching executor '22ea580c-4530-4b2f-8761-cecd3bfe562e' of framework 47ac227f-5c40-4f74-becb-fe5af6ac8363-0000 with resources cpus(*)(allocated: *):0.1; mem(*)(allocated: *):32 in work directory '/tmp/HTTPCommandExecutorTest_TerminateWithACK_afoUZl/slaves/47ac227f-5c40-4f74-becb-fe5af6ac8363-S0/frameworks/47ac227f-5c40-4f74-becb-fe5af6ac8363-0000/executors/22ea580c-4530-4b2f-8761-cecd3bfe562e/runs/4e2a9d41-71eb-4b86-8f30-f5a7504cc39b'
I0315 01:00:27.769498 31655 containerizer.cpp:1001] Starting container 4e2a9d41-71eb-4b86-8f30-f5a7504cc39b for executor '22ea580c-4530-4b2f-8761-cecd3bfe562e' of framework 47ac227f-5c40-4f74-becb-fe5af6ac8363-0000
I0315 01:00:27.769613 31654 slave.cpp:2313] Queued task '22ea580c-4530-4b2f-8761-cecd3bfe562e' for executor '22ea580c-4530-4b2f-8761-cecd3bfe562e' of framework 47ac227f-5c40-4f74-becb-fe5af6ac8363-0000
I0315 01:00:27.769683 31654 slave.cpp:889] Successfully attached file '/tmp/HTTPCommandExecutorTest_TerminateWithACK_afoUZl/slaves/47ac227f-5c40-4f74-becb-fe5af6ac8363-S0/frameworks/47ac227f-5c40-4f74-becb-fe5af6ac8363-0000/executors/22ea580c-4530-4b2f-8761-cecd3bfe562e/runs/4e2a9d41-71eb-4b86-8f30-f5a7504cc39b'
I0315 01:00:27.779422 31633 containerizer.cpp:1499] Launching 'mesos-containerizer' with flags '--help="false" --launch_info="{"command":{"arguments":["mesos-executor","--launcher_dir=\/mesos\/mesos-1.3.0\/_build\/src"],"shell":false,"value":"\/mesos\/mesos-1.3.0\/_build\/src\/mesos-executor"},"environment":{"variables":[{"name":"LIBPROCESS_PORT","type":"VALUE","value":"0"},{"name":"MESOS_AGENT_ENDPOINT","type":"VALUE","value":"172.17.0.3:34409"},{"name":"MESOS_CHECKPOINT","type":"VALUE","value":"0"},{"name":"MESOS_DIRECTORY","type":"VALUE","value":"\/tmp\/HTTPCommandExecutorTest_TerminateWithACK_afoUZl\/slaves\/47ac227f-5c40-4f74-becb-fe5af6ac8363-S0\/frameworks\/47ac227f-5c40-4f74-becb-fe5af6ac8363-0000\/executors\/22ea580c-4530-4b2f-8761-cecd3bfe562e\/runs\/4e2a9d41-71eb-4b86-8f30-f5a7504cc39b"},{"name":"MESOS_EXECUTOR_ID","type":"VALUE","value":"22ea580c-4530-4b2f-8761-cecd3bfe562e"},{"name":"MESOS_EXECUTOR_SHUTDOWN_GRACE_PERIOD","type":"VALUE","value":"5secs"},{"name":"MESOS_FRAMEWORK_ID","type":"VALUE","value":"47ac227f-5c40-4f74-becb-fe5af6ac8363-0000"},{"name":"MESOS_HTTP_COMMAND_EXECUTOR","type":"VALUE","value":"1"},{"name":"MESOS_SLAVE_ID","type":"VALUE","value":"47ac227f-5c40-4f74-becb-fe5af6ac8363-S0"},{"name":"MESOS_SLAVE_PID","type":"VALUE","value":"(13)@172.17.0.3:34409"},{"name":"MESOS_SANDBOX","type":"VALUE","value":"\/tmp\/HTTPCommandExecutorTest_TerminateWithACK_afoUZl\/slaves\/47ac227f-5c40-4f74-becb-fe5af6ac8363-S0\/frameworks\/47ac227f-5c40-4f74-becb-fe5af6ac8363-0000\/executors\/22ea580c-4530-4b2f-8761-cecd3bfe562e\/runs\/4e2a9d41-71eb-4b86-8f30-f5a7504cc39b"}]},"user":"mesos","working_directory":"\/tmp\/HTTPCommandExecutorTest_TerminateWithACK_afoUZl\/slaves\/47ac227f-5c40-4f74-becb-fe5af6ac8363-S0\/frameworks\/47ac227f-5c40-4f74-becb-fe5af6ac8363-0000\/executors\/22ea580c-4530-4b2f-8761-cecd3bfe562e\/runs\/4e2a9d41-71eb-4b86-8f30-f5a7504cc39b"}" --pipe_read="6" --pipe_write="7" --runtime_directory="/tmp/HTTPCommandExecutorTest_TerminateWithACK_cxPfi7/containers/4e2a9d41-71eb-4b86-8f30-f5a7504cc39b" --unshare_namespace_mnt="false"'
I0315 01:00:27.782599 31633 launcher.cpp:135] Forked child with pid '31669' for container '4e2a9d41-71eb-4b86-8f30-f5a7504cc39b'
I0315 01:00:27.792897 31633 fetcher.cpp:353] Starting to fetch URIs for container: 4e2a9d41-71eb-4b86-8f30-f5a7504cc39b, directory: /tmp/HTTPCommandExecutorTest_TerminateWithACK_afoUZl/slaves/47ac227f-5c40-4f74-becb-fe5af6ac8363-S0/frameworks/47ac227f-5c40-4f74-becb-fe5af6ac8363-0000/executors/22ea580c-4530-4b2f-8761-cecd3bfe562e/runs/4e2a9d41-71eb-4b86-8f30-f5a7504cc39b
I0315 01:00:28.726302 31634 hierarchical.cpp:1854] No allocations performed
I0315 01:00:28.726392 31634 hierarchical.cpp:1944] No inverse offers to send out!
I0315 01:00:28.726457 31634 hierarchical.cpp:1438] Performed allocation for 1 agents in 364273ns
I0315 01:00:29.727972 31655 hierarchical.cpp:1854] No allocations performed
I0315 01:00:29.728055 31655 hierarchical.cpp:1944] No inverse offers to send out!
I0315 01:00:29.728116 31655 hierarchical.cpp:1438] Performed allocation for 1 agents in 376168ns
I0315 01:00:30.728917 31638 hierarchical.cpp:1854] No allocations performed
I0315 01:00:30.729018 31638 hierarchical.cpp:1944] No inverse offers to send out!
I0315 01:00:30.729076 31638 hierarchical.cpp:1438] Performed allocation for 1 agents in 353984ns
I0315 01:00:31.730000 31647 hierarchical.cpp:1854] No allocations performed
I0315 01:00:31.730087 31647 hierarchical.cpp:1944] No inverse offers to send out!
I0315 01:00:31.730170 31647 hierarchical.cpp:1438] Performed allocation for 1 agents in 340465ns
I0315 01:00:32.730903 31633 hierarchical.cpp:1854] No allocations performed
I0315 01:00:32.731006 31633 hierarchical.cpp:1944] No inverse offers to send out!
I0315 01:00:32.731071 31633 hierarchical.cpp:1438] Performed allocation for 1 agents in 348297ns
I0315 01:00:33.731657 31634 hierarchical.cpp:1854] No allocations performed
I0315 01:00:33.731739 31634 hierarchical.cpp:1944] No inverse offers to send out!
I0315 01:00:33.731803 31634 hierarchical.cpp:1438] Performed allocation for 1 agents in 300439ns
I0315 01:00:34.733499 31639 hierarchical.cpp:1854] No allocations performed
I0315 01:00:34.733587 31639 hierarchical.cpp:1944] No inverse offers to send out!
I0315 01:00:34.733655 31639 hierarchical.cpp:1438] Performed allocation for 1 agents in 325510ns
I0315 01:00:35.735347 31643 hierarchical.cpp:1854] No allocations performed
I0315 01:00:35.735426 31643 hierarchical.cpp:1944] No inverse offers to send out!
I0315 01:00:35.735491 31643 hierarchical.cpp:1438] Performed allocation for 1 agents in 310104ns
I0315 01:00:36.736214 31634 hierarchical.cpp:1854] No allocations performed
I0315 01:00:36.736296 31634 hierarchical.cpp:1944] No inverse offers to send out!
I0315 01:00:36.736361 31634 hierarchical.cpp:1438] Performed allocation for 1 agents in 308486ns
I0315 01:00:37.737452 31641 hierarchical.cpp:1854] No allocations performed
I0315 01:00:37.737531 31641 hierarchical.cpp:1944] No inverse offers to send out!
I0315 01:00:37.737598 31641 hierarchical.cpp:1438] Performed allocation for 1 agents in 323808ns
I0315 01:00:38.738646 31647 hierarchical.cpp:1854] No allocations performed
I0315 01:00:38.738724 31647 hierarchical.cpp:1944] No inverse offers to send out!
I0315 01:00:38.738786 31647 hierarchical.cpp:1438] Performed allocation for 1 agents in 300290ns
I0315 01:00:39.740034 31648 hierarchical.cpp:1854] No allocations performed
I0315 01:00:39.740141 31648 hierarchical.cpp:1944] No inverse offers to send out!
I0315 01:00:39.740231 31648 hierarchical.cpp:1438] Performed allocation for 1 agents in 392896ns
I0315 01:00:40.747072 31642 hierarchical.cpp:1854] No allocations performed
I0315 01:00:40.747473 31642 hierarchical.cpp:1944] No inverse offers to send out!
I0315 01:00:40.747731 31642 hierarchical.cpp:1438] Performed allocation for 1 agents in 4.768531ms
I0315 01:00:41.748679 31649 hierarchical.cpp:1854] No allocations performed
I0315 01:00:41.748770 31649 hierarchical.cpp:1944] No inverse offers to send out!
I0315 01:00:41.748834 31649 hierarchical.cpp:1438] Performed allocation for 1 agents in 386629ns
I0315 01:00:42.750859 31634 hierarchical.cpp:1854] No allocations performed
I0315 01:00:42.751158 31634 hierarchical.cpp:1944] No inverse offers to send out!
I0315 01:00:42.751341 31634 hierarchical.cpp:1438] Performed allocation for 1 agents in 986831ns
I0315 01:00:42.758191 31634 slave.cpp:4536] Received ping from slave-observer(9)@172.17.0.3:34409
../../src/tests/command_executor_tests.cpp:402: Failure
Failed to wait 15secs for statusRunning
I0315 01:00:42.766816 31636 master.cpp:1434] Framework 47ac227f-5c40-4f74-becb-fe5af6ac8363-0000 (default) at scheduler-fd8b68d4-7e58-41d1-966d-f8882e26a7ef@172.17.0.3:34409 disconnected
I0315 01:00:42.767123 31636 master.cpp:3148] Deactivating framework 47ac227f-5c40-4f74-becb-fe5af6ac8363-0000 (default) at scheduler-fd8b68d4-7e58-41d1-966d-f8882e26a7ef@172.17.0.3:34409
I0315 01:00:42.767297 31636 master.cpp:3125] Disconnecting framework 47ac227f-5c40-4f74-becb-fe5af6ac8363-0000 (default) at scheduler-fd8b68d4-7e58-41d1-966d-f8882e26a7ef@172.17.0.3:34409
I0315 01:00:42.767432 31636 master.cpp:1449] Giving framework 47ac227f-5c40-4f74-becb-fe5af6ac8363-0000 (default) at scheduler-fd8b68d4-7e58-41d1-966d-f8882e26a7ef@172.17.0.3:34409 0ns to failover
../../src/tests/command_executor_tests.cpp:391: Failure
Actual function call count doesn't match EXPECT_CALL(sched, statusUpdate(_, _))...
         Expected: to be called twice
           Actual: never called - unsatisfied and active
I0315 01:00:42.768435 31649 hierarchical.cpp:376] Deactivated framework 47ac227f-5c40-4f74-becb-fe5af6ac8363-0000
I0315 01:00:42.769788 31637 master.cpp:6921] Framework failover timeout, removing framework 47ac227f-5c40-4f74-becb-fe5af6ac8363-0000 (default) at scheduler-fd8b68d4-7e58-41d1-966d-f8882e26a7ef@172.17.0.3:34409
I0315 01:00:42.769908 31637 master.cpp:7777] Removing framework 47ac227f-5c40-4f74-becb-fe5af6ac8363-0000 (default) at scheduler-fd8b68d4-7e58-41d1-966d-f8882e26a7ef@172.17.0.3:34409
I0315 01:00:42.770433 31637 master.cpp:8345] Updating the state of task 22ea580c-4530-4b2f-8761-cecd3bfe562e of framework 47ac227f-5c40-4f74-becb-fe5af6ac8363-0000 (latest state: TASK_KILLED, status update state: TASK_KILLED)
../../src/tests/command_executor_tests.cpp:396: Failure
Actual function call count doesn't match EXPECT_CALL(slave, executorTerminated(_, _, _))...
         Expected: to be called once
           Actual: never called - unsatisfied and active
I0315 01:00:42.771291 31654 slave.cpp:2853] Asked to shut down framework 47ac227f-5c40-4f74-becb-fe5af6ac8363-0000 by master@172.17.0.3:34409
F0315 01:00:42.771564 31654 slave.cpp:2912] Framework 47ac227f-5c40-4f74-becb-fe5af6ac8363-0000 is in unexpected state UNKNOWN
*** Check failure stack trace: ***
I0315 01:00:42.774034 31637 master.cpp:8439] Removing task 22ea580c-4530-4b2f-8761-cecd3bfe562e with resources cpus(*)(allocated: *):2; mem(*)(allocated: *):1024; disk(*)(allocated: *):1024; ports(*)(allocated: *):[31000-32000] of framework 47ac227f-5c40-4f74-becb-fe5af6ac8363-0000 on agent 47ac227f-5c40-4f74-becb-fe5af6ac8363-S0 at (13)@172.17.0.3:34409 (5b7065a6b902)
I0315 01:00:42.777034 31637 hierarchical.cpp:1108] Recovered cpus(*)(allocated: *):2; mem(*)(allocated: *):1024; disk(*)(allocated: *):1024; ports(*)(allocated: *):[31000-32000] (total: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000], allocated: {}) on agent 47ac227f-5c40-4f74-becb-fe5af6ac8363-S0 from framework 47ac227f-5c40-4f74-becb-fe5af6ac8363-0000
I0315 01:00:42.789026 31637 hierarchical.cpp:323] Removed framework 47ac227f-5c40-4f74-becb-fe5af6ac8363-0000
    @     0x7f5248879d88  google::LogMessage::Fail()
I0315 01:00:42.811238 31648 master.cpp:1156] Master terminating
I0315 01:00:42.822901 31648 hierarchical.cpp:560] Removed agent 47ac227f-5c40-4f74-becb-fe5af6ac8363-S0
    @     0x7f5248879ce7  google::LogMessage::SendToLog()
[  FAILED  ] HTTPCommandExecutorTest.TerminateWithACK (15111 ms)
[ RUN      ] HTTPCommandExecutorTest.ExplicitAcknowledgements
I0315 01:00:42.840243 31614 cluster.cpp:160] Creating default 'local' authorizer
    @     0x7f52488796f8  google::LogMessage::Flush()
I0315 01:00:42.855372 31653 master.cpp:437] Master 6b1145e6-ba02-4b9a-ad40-7afa93ec0489 (5b7065a6b902) started on 172.17.0.3:34409
I0315 01:00:42.856057 31653 master.cpp:439] Flags at startup: --acls="" --agent_ping_timeout="15secs" --agent_reregister_timeout="10mins" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate_agents="true" --authenticate_frameworks="true" --authenticate_http_frameworks="true" --authenticate_http_readonly="true" --authenticate_http_readwrite="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/inxrXK/credentials" --framework_sorter="drf" --help="false" --hostname_lookup="true" --http_authenticators="basic" --http_framework_authenticators="basic" --initialize_driver_logging="true" --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO" --max_agent_ping_timeouts="5" --max_completed_frameworks="50" --max_completed_tasks_per_framework="1000" --max_unreachable_tasks_per_framework="1000" --quiet="false" --recovery_agent_removal_limit="100%" --registry="in_memory" --registry_fetch_timeout="1mins" --registry_gc_interval="15mins" --registry_max_agent_age="2weeks" --registry_max_agent_count="102400" --registry_store_timeout="100secs" --registry_strict="false" --root_submissions="true" --user_sorter="drf" --version="false" --webui_dir="/mesos/mesos-1.3.0/_inst/share/mesos/webui" --work_dir="/tmp/inxrXK/master" --zk_session_timeout="10secs"
I0315 01:00:42.858619 31653 master.cpp:489] Master only allowing authenticated frameworks to register
I0315 01:00:42.858810 31653 master.cpp:503] Master only allowing authenticated agents to register
I0315 01:00:42.858932 31653 master.cpp:516] Master only allowing authenticated HTTP frameworks to register
I0315 01:00:42.859203 31653 credentials.hpp:37] Loading credentials for authentication from '/tmp/inxrXK/credentials'
I0315 01:00:42.860618 31653 master.cpp:561] Using default 'crammd5' authenticator
    @     0x7f524887c42c  google::LogMessageFatal::~LogMessageFatal()
I0315 01:00:42.861668 31653 http.cpp:964] Using default 'basic' HTTP authenticator for realm 'mesos-master-readonly'
I0315 01:00:42.862069 31653 http.cpp:964] Using default 'basic' HTTP authenticator for realm 'mesos-master-readwrite'
I0315 01:00:42.862300 31653 http.cpp:964] Using default 'basic' HTTP authenticator for realm 'mesos-master-scheduler'
I0315 01:00:42.862543 31653 master.cpp:641] Authorization enabled
I0315 01:00:42.863287 31640 whitelist_watcher.cpp:77] No whitelist given
I0315 01:00:42.863581 31633 hierarchical.cpp:159] Initialized hierarchical allocator process
I0315 01:00:42.876993 31645 master.cpp:2165] Elected as the leading master!
I0315 01:00:42.877580 31645 master.cpp:1704] Recovering from registrar
I0315 01:00:42.878118 31649 registrar.cpp:331] Recovering registrar
I0315 01:00:42.880645 31649 registrar.cpp:364] Successfully fetched the registry (0B) in 1600us
I0315 01:00:42.880905 31649 registrar.cpp:463] Applied 1 operations in 30032ns; attempting to update the registry
I0315 01:00:42.883332 31649 registrar.cpp:508] Successfully updated the registry in 2.278912ms
I0315 01:00:42.883672 31649 registrar.cpp:394] Successfully recovered registrar
I0315 01:00:42.884938 31636 master.cpp:1803] Recovered 0 agents from the registry (129B); allowing 10mins for agents to re-register
I0315 01:00:42.885004 31645 hierarchical.cpp:186] Skipping recovery of hierarchical allocator: nothing to recover
    @     0x7f5247902ec8  mesos::internal::slave::Slave::shutdownFramework()
    @     0x7f52479524ac  ProtobufProcess<>::handler1<>()
    @     0x7f52479b86f0  _ZNSt5_BindIFPFvPN5mesos8internal5slave5SlaveEMS3_FvRKN7process4UPIDERKNS0_11FrameworkIDEEMNS1_24ShutdownFrameworkMessageEKFSB_vES8_RKSsES4_SD_SG_St12_PlaceholderILi1EESL_ILi2EEEE6__callIvJS8_SI_EJLm0ELm1ELm2ELm3ELm4EEEET_OSt5tupleIJDpT0_EESt12_Index_tupleIJXspT1_EEE
    @     0x7f52479a4fbf  _ZNSt5_BindIFPFvPN5mesos8internal5slave5SlaveEMS3_FvRKN7process4UPIDERKNS0_11FrameworkIDEEMNS1_24ShutdownFrameworkMessageEKFSB_vES8_RKSsES4_SD_SG_St12_PlaceholderILi1EESL_ILi2EEEEclIJS8_SI_EvEET0_DpOT_
    @     0x7f524798ea27  std::_Function_handler<>::_M_invoke()
    @     0x559fd3a3186d  std::function<>::operator()()
    @     0x559fd3d5dc1b  ProtobufProcess<>::visit()
    @     0x7f524749dd30  process::MessageEvent::visit()
    @     0x559fd325bf00  process::ProcessBase::serve()
    @     0x7f524879a8e5  process::ProcessManager::resume()
    @     0x7f5248797090  _ZZN7process14ProcessManager12init_threadsEvENKUt_clEv
    @     0x7f52487a9310  _ZNSt12_Bind_simpleIFZN7process14ProcessManager12init_threadsEvEUt_vEE9_M_invokeIIEEEvSt12_Index_tupleIIXspT_EEE
    @     0x7f52487a9254  _ZNSt12_Bind_simpleIFZN7process14ProcessManager12init_threadsEvEUt_vEEclEv
    @     0x7f52487a91de  _ZNSt6thread5_ImplISt12_Bind_simpleIFZN7process14ProcessManager12init_threadsEvEUt_vEEE6_M_runEv
    @     0x7f5242333230  (unknown)
    @     0x7f524299adc5  start_thread
    @     0x7f5241a9c73d  __clone
make[4]: *** [check-local] Aborted (core dumped)
make[4]: Leaving directory `/mesos/mesos-1.3.0/_build/src'
make[3]: *** [check-am] Error 2
make[3]: Leaving directory `/mesos/mesos-1.3.0/_build/src'
make[2]: *** [check] Error 2
make[2]: Leaving directory `/mesos/mesos-1.3.0/_build/src'
make[1]: *** [check-recursive] Error 1
make[1]: Leaving directory `/mesos/mesos-1.3.0/_build'
make: *** [distcheck] Error 1
+ docker rmi mesos-1489537250-25789
Untagged: mesos-1489537250-25789:latest
Deleted: sha256:08e20ead0f390ce3576fee9534ae4c65981b34c45753c7e0955ee18ced2077fd
Deleted: sha256:859b6ceddfb6e28a366672971dd17246bfa0263a37c029ce065335ca6db70685
Deleted: sha256:a0d5876b0bfd3774612a1a561301bf8b3a1474a4888a570fc2a20a7d7d3156cf
Deleted: sha256:6a10a7f79e433e72db3d735d6e5f1c29bc70957a9f1dd3f9b10e7dfa85700897
Deleted: sha256:ac5e53a4ed0a44999ec69f25a3cd0817566f84d8a7dcd538da4755b1ecbd89b6
Deleted: sha256:4160a3cd5b22c967363fe5b69eaeed56d144a16766f5c7fadc93a4b327b2281b
Deleted: sha256:425cdc764aa6e9510031da7309c9c5deeea1d6b6a837bff8add2734ce7c9ba32
Deleted: sha256:3f12db32f7d4018f06977bff6a03e3039c50713b56920a994d7fd1da4877baf3
Deleted: sha256:d3d28e6d9ee268e6ea56c14a287bdb3a0f260cfd73c3f8cdb4c03cae5452dc68
Deleted: sha256:22e89fc7a7ed114cbdbe48ed12cb8efcea4081412beb55f61b3be5587753b959
Deleted: sha256:069c9d0a0cfbabf8bf582e58daf6df8a1a94abd89521bb8abb6ae801b26fed50
Deleted: sha256:942a8105f0cc1b8dc62087406bf43df15c85cd8415b5f8e8adb1ea3fb08a45ee
Deleted: sha256:c52f862744f7099af72013d4305734c8bbac8adbe9a7bee3a387f20e89fe0439
Deleted: sha256:3a30a412722c17c26e4cc1956f64e8838ac9d0aab21cae47311026dcf542bc37
Deleted: sha256:7ea70b5958b4bea238bd4f4b7befd549620e5af253fbc15cfe63e35cd9586651
Deleted: sha256:3ef6a0c0225b7dfe517b36e0df12e58b6e7e169885ff5bd96a8a0fc058db23f3
Deleted: sha256:b52923053f2cb0e94e935728f298a2b3edcdd6a6c84187e1a04bfd22ade91390
Deleted: sha256:a794eb991c0501b6736794bf01a8b3d88374d46984a5a6ecf1efee5e2edacaf4
Deleted: sha256:e81cd1739abb71f5806b8fa101c6a1e27dcfec50fa28a263b6f7c6876daff6bf
Deleted: sha256:7eaecae107ef8369f1957417c6a22edccb01a169912413319e836136c8924399
Deleted: sha256:4fc9f7617e126c54631444c3cb85005e68316197e1cad4479261854b8a93b6be
Deleted: sha256:4338440ff889d4e7721f960ac62632bfcd45315577b44d901f7585adb1506816
Deleted: sha256:3c62103e991db9791f065b5a7aa84869c2b90dd1a0aaa9ed45bfb90a44886174
Deleted: sha256:c33dd32316eb257118d57976cf3bf39d2e5bc86432440e9b91170043d2a90e6d
Deleted: sha256:add6b1c437c5c41af29bd6311de30a1cae01dcc914dbb9d7fdc36d3a2a324e5b
Build step 'Execute shell' marked build as failure

Jenkins build is back to normal : Mesos-Buildbot » autotools,gcc,--verbose,GLOG_v=1 MESOS_VERBOSE=1,centos:7,(docker||Hadoop)&&(!ubuntu-us1)&&(!ubuntu-eu2) #3373

Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos-Buildbot/BUILDTOOL=autotools,COMPILER=gcc,CONFIGURATION=--verbose,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1,OS=centos%3A7,label_exp=(docker%7C%7CHadoop)&&(!ubuntu-us1)&&(!ubuntu-eu2)/3373/display/redirect?page=changes>