See <https://builds.apache.org/job/Mesos-Buildbot/BUILDTOOL=cmake,COMPILER=clang,CONFIGURATION=--verbose%20--enable-libevent%20--enable-ssl,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1,OS=ubuntu%3A14.04,label_exp=(docker%7C%7CHadoop)&&(!ubuntu-us1)&&(!ubuntu-eu2)/3561/display/redirect?page=changes>
Changes: [yujie.jay] Fixed an ordering issue in 1.2.1 CHANGELOG. [yujie.jay] Added MESOS-5172 to 1.2.1 CHANGELOG. [yujie.jay] Fixed an ordering issue in 1.1.2 CHANGELOG. [yujie.jay] Added MESOS-5172 to 1.1.2 CHANGELOG. ------------------------------------------ [...truncated 18.00 MB...] I0426 04:06:15.762091 26006 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite' I0426 04:06:15.762176 26006 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler' I0426 04:06:15.762217 26006 master.cpp:642] Authorization enabled I0426 04:06:15.762364 26007 hierarchical.cpp:159] Initialized hierarchical allocator process I0426 04:06:15.762413 26007 whitelist_watcher.cpp:77] No whitelist given I0426 04:06:15.763134 26008 master.cpp:2163] Elected as the leading master! I0426 04:06:15.763149 26008 master.cpp:1702] Recovering from registrar I0426 04:06:15.763197 26007 registrar.cpp:345] Recovering registrar I0426 04:06:15.763427 25998 registrar.cpp:389] Successfully fetched the registry (0B) in 147968ns I0426 04:06:15.763469 25998 registrar.cpp:493] Applied 1 operations in 11559ns; attempting to update the registry I0426 04:06:15.763654 26002 registrar.cpp:550] Successfully updated the registry in 163840ns I0426 04:06:15.763695 26002 registrar.cpp:422] Successfully recovered registrar I0426 04:06:15.763862 26008 master.cpp:1801] Recovered 0 agents from the registry (129B); allowing 10mins for agents to re-register I0426 04:06:15.763911 26000 hierarchical.cpp:186] Skipping recovery of hierarchical allocator: nothing to recover I0426 04:06:15.766216 26011 slave.cpp:225] Mesos agent started on @172.17.0.2:37535 I0426 04:06:15.766366 25996 scheduler.cpp:184] Version: 1.3.0 I0426 04:06:15.766577 26000 scheduler.cpp:470] New master detected at [email protected]:37535 I0426 04:06:15.766595 26000 scheduler.cpp:479] Waiting for 0ns before initiating a re-(connection) attempt with the master I0426 04:06:15.766237 26011 slave.cpp:226] Flags at startup: --acls="permissive: true " --appc_simple_discovery_uri_prefix="http://"; --appc_store_dir="/tmp/mesos/store/appc" --authenticate_http_executors="true" --authenticate_http_readonly="true" --authenticate_http_readwrite="true" --authenticatee="crammd5" --authentication_backoff_factor="1secs" --authorizer="local" --cgroups_cpu_enable_pids_and_tids_count="false" --cgroups_enable_cfs="false" --cgroups_hierarchy="/sys/fs/cgroup" --cgroups_limit_swap="false" --cgroups_root="mesos" --container_disk_watch_interval="15secs" --containerizers="mesos" --credential="/tmp/ExecutorAuthorizationTest_FailedSubscribe_mCCO75/credential" --default_role="*" --disk_watch_interval="1mins" --docker="docker" --docker_kill_orphans="true" --docker_registry="https://registry-1.docker.io"; --docker_remove_delay="6hrs" --docker_socket="/var/run/docker.sock" --docker_stop_timeout="0ns" --docker_store_dir="/tmp/mesos/store/docker" --docker_volume_checkpoint_dir="/var/run/mesos/isolators/docker/volume" --enforce_container_disk_quota="false" --executor_registration_timeout="1mins" --executor_secret_key="/tmp/ExecutorAuthorizationTest_FailedSubscribe_mCCO75/executor_secret_key" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/ExecutorAuthorizationTest_FailedSubscribe_mCCO75/fetch" --fetcher_cache_size="2GB" --frameworks_home="" --gc_delay="1weeks" --gc_disk_headroom="0.1" --hadoop_home="" --help="false" --hostname_lookup="true" --http_command_executor="false" --http_credentials="/tmp/ExecutorAuthorizationTest_FailedSubscribe_mCCO75/http_credentials" --http_heartbeat_interval="30secs" --initialize_driver_logging="true" --isolation="posix/cpu,posix/mem" --launcher="posix" --launcher_dir="/mesos/build/src" --logbufsecs="0" --logging_level="INFO" --max_completed_executors_per_framework="150" --oversubscribed_resources_interval="15secs" --perf_duration="10secs" --perf_interval="1mins" --port="5051" --qos_correction_interval_min="0ns" --quiet="false" --recover="reconnect" --recovery_timeout="15mins" --registration_backoff_factor="10ms" --resources="cpus:2;gpus:0;mem:1024;disk:1024;ports:[31000-32000]" --revocable_cpu_low_priority="true" --runtime_dir="/tmp/ExecutorAuthorizationTest_FailedSubscribe_mCCO75" --sandbox_directory="/mnt/mesos/sandbox" --strict="true" --switch_user="true" --systemd_enable_support="true" --systemd_runtime_directory="/run/systemd/system" --version="false" --work_dir="/tmp/ExecutorAuthorizationTest_FailedSubscribe_i1zmxe" I0426 04:06:15.766649 26011 credentials.hpp:86] Loading credential for authentication from '/tmp/ExecutorAuthorizationTest_FailedSubscribe_mCCO75/credential' I0426 04:06:15.766851 26011 slave.cpp:258] Agent using credential for: test-principal I0426 04:06:15.766959 26011 credentials.hpp:37] Loading credentials for authentication from '/tmp/ExecutorAuthorizationTest_FailedSubscribe_mCCO75/http_credentials' I0426 04:06:15.767208 26011 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-executor' I0426 04:06:15.767248 26011 http.cpp:996] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-executor' I0426 04:06:15.767436 25998 scheduler.cpp:361] Connected with the master at http://172.17.0.2:37535/master/api/v1/scheduler I0426 04:06:15.767469 26011 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly' I0426 04:06:15.767601 26011 http.cpp:996] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readonly' I0426 04:06:15.767907 26011 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readwrite' I0426 04:06:15.767948 26011 http.cpp:996] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readwrite' I0426 04:06:15.767979 26004 scheduler.cpp:243] Sending SUBSCRIBE call to http://172.17.0.2:37535/master/api/v1/scheduler I0426 04:06:15.768477 26011 slave.cpp:525] Agent resources: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] I0426 04:06:15.768515 26011 slave.cpp:533] Agent attributes: [ ] I0426 04:06:15.768522 26011 slave.cpp:538] Agent hostname: 93a06a1a94c4 I0426 04:06:15.768501 26002 process.cpp:3722] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler' I0426 04:06:15.768585 26007 status_update_manager.cpp:177] Pausing sending status updates I0426 04:06:15.768892 26004 state.cpp:62] Recovering state from '/tmp/ExecutorAuthorizationTest_FailedSubscribe_i1zmxe/meta' I0426 04:06:15.769531 26002 status_update_manager.cpp:203] Recovering status update manager I0426 04:06:15.769656 26002 slave.cpp:5963] Finished recovery I0426 04:06:15.770112 26002 slave.cpp:6145] Querying resource estimator for oversubscribable resources I0426 04:06:15.770248 26002 slave.cpp:918] New master detected at [email protected]:37535 I0426 04:06:15.770287 26002 slave.cpp:953] Detecting new master I0426 04:06:15.770328 26002 status_update_manager.cpp:177] Pausing sending status updates I0426 04:06:15.780958 26011 http.cpp:1115] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:33245 I0426 04:06:15.781136 26011 master.cpp:2515] Received subscription request for HTTP framework 'default' I0426 04:06:15.781175 26011 master.cpp:2199] Authorizing framework principal 'test-principal' to receive offers for roles '{ * }' I0426 04:06:15.781232 26004 slave.cpp:980] Authenticating with master [email protected]:37535 I0426 04:06:15.781276 26004 slave.cpp:991] Using default CRAM-MD5 authenticatee I0426 04:06:15.781380 26011 authenticatee.cpp:121] Creating new client SASL connection I0426 04:06:15.781467 26004 master.cpp:2630] Subscribing framework 'default' with checkpointing disabled and capabilities [ ] I0426 04:06:15.781675 26011 hierarchical.cpp:271] Added framework 4779542b-dc31-43a4-9a0d-1a93a421753a-0000 I0426 04:06:15.781723 26011 hierarchical.cpp:1862] No allocations performed I0426 04:06:15.781733 26011 hierarchical.cpp:1952] No inverse offers to send out! I0426 04:06:15.781744 26011 hierarchical.cpp:1446] Performed allocation for 0 agents in 37340ns I0426 04:06:15.781780 25999 master.hpp:2167] Sending heartbeat to 4779542b-dc31-43a4-9a0d-1a93a421753a-0000 I0426 04:06:15.781795 26004 master.cpp:7257] Authenticating (562)@172.17.0.2:37535 I0426 04:06:15.781834 25999 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(1014)@172.17.0.2:37535 I0426 04:06:15.781987 25998 authenticator.cpp:98] Creating new server SASL connection I0426 04:06:15.782176 25998 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5 I0426 04:06:15.782219 25998 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5' I0426 04:06:15.782331 26001 authenticator.cpp:204] Received SASL authentication start I0426 04:06:15.782416 26001 authenticator.cpp:326] Authentication requires more steps I0426 04:06:15.782477 26001 authenticatee.cpp:259] Received SASL authentication step I0426 04:06:15.782594 26009 authenticator.cpp:232] Received SASL authentication step I0426 04:06:15.782594 26000 scheduler.cpp:676] Enqueuing event SUBSCRIBED received from http://172.17.0.2:37535/master/api/v1/scheduler I0426 04:06:15.782627 26009 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '93a06a1a94c4' server FQDN: '93a06a1a94c4' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false I0426 04:06:15.782637 26009 auxprop.cpp:181] Looking up auxiliary property '*userPassword' I0426 04:06:15.782654 26009 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5' I0426 04:06:15.782665 26009 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '93a06a1a94c4' server FQDN: '93a06a1a94c4' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true I0426 04:06:15.782673 26009 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true I0426 04:06:15.782680 26009 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true I0426 04:06:15.782694 26009 authenticator.cpp:318] Authentication success I0426 04:06:15.782811 26012 master.cpp:7287] Successfully authenticated principal 'test-principal' at (562)@172.17.0.2:37535 I0426 04:06:15.782876 26012 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(1014)@172.17.0.2:37535 I0426 04:06:15.782888 26009 scheduler.cpp:676] Enqueuing event HEARTBEAT received from http://172.17.0.2:37535/master/api/v1/scheduler I0426 04:06:15.783192 26000 authenticatee.cpp:299] Authentication success I0426 04:06:15.783298 26000 slave.cpp:1075] Successfully authenticated with master [email protected]:37535 I0426 04:06:15.783392 26000 slave.cpp:1503] Will retry registration in 3.387433ms if necessary I0426 04:06:15.783445 26002 master.cpp:5447] Registering agent at (562)@172.17.0.2:37535 (93a06a1a94c4) with id 4779542b-dc31-43a4-9a0d-1a93a421753a-S0 I0426 04:06:15.783622 26002 registrar.cpp:493] Applied 1 operations in 29613ns; attempting to update the registry I0426 04:06:15.783807 26002 registrar.cpp:550] Successfully updated the registry in 158976ns I0426 04:06:15.784020 26002 master.cpp:5521] Registered agent 4779542b-dc31-43a4-9a0d-1a93a421753a-S0 at (562)@172.17.0.2:37535 (93a06a1a94c4) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] I0426 04:06:15.784165 26002 hierarchical.cpp:527] Added agent 4779542b-dc31-43a4-9a0d-1a93a421753a-S0 (93a06a1a94c4) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] (allocated: {}) I0426 04:06:15.784423 26002 hierarchical.cpp:1952] No inverse offers to send out! I0426 04:06:15.784442 26002 hierarchical.cpp:1446] Performed allocation for 1 agents in 225454ns I0426 04:06:15.784481 26002 slave.cpp:1121] Registered with master [email protected]:37535; given agent ID 4779542b-dc31-43a4-9a0d-1a93a421753a-S0 I0426 04:06:15.784498 26002 fetcher.cpp:94] Clearing fetcher cache I0426 04:06:15.784790 26002 slave.cpp:1149] Checkpointing SlaveInfo to '/tmp/ExecutorAuthorizationTest_FailedSubscribe_i1zmxe/meta/slaves/4779542b-dc31-43a4-9a0d-1a93a421753a-S0/slave.info' I0426 04:06:15.785079 26002 slave.cpp:4745] Received ping from slave-observer(490)@172.17.0.2:37535 I0426 04:06:15.785254 26002 master.cpp:7087] Sending 1 offers to framework 4779542b-dc31-43a4-9a0d-1a93a421753a-0000 (default) I0426 04:06:15.785441 26002 status_update_manager.cpp:184] Resuming sending status updates I0426 04:06:15.785953 26008 scheduler.cpp:676] Enqueuing event OFFERS received from http://172.17.0.2:37535/master/api/v1/scheduler I0426 04:06:15.786793 26008 scheduler.cpp:243] Sending ACCEPT call to http://172.17.0.2:37535/master/api/v1/scheduler I0426 04:06:15.790604 25997 process.cpp:3722] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler' I0426 04:06:15.791149 26004 http.cpp:1115] HTTP POST for /master/api/v1/scheduler from 172.17.0.2:33246 I0426 04:06:15.791638 26004 master.cpp:3853] Processing ACCEPT call for offers: [ 4779542b-dc31-43a4-9a0d-1a93a421753a-O0 ] on agent 4779542b-dc31-43a4-9a0d-1a93a421753a-S0 at (562)@172.17.0.2:37535 (93a06a1a94c4) for framework 4779542b-dc31-43a4-9a0d-1a93a421753a-0000 (default) I0426 04:06:15.791697 26004 master.cpp:3429] Authorizing framework principal 'test-principal' to launch task 3c0a14de-0728-48c3-ad90-3850c709cc1d I0426 04:06:15.793156 26008 master.cpp:9102] Adding task 3c0a14de-0728-48c3-ad90-3850c709cc1d with resources cpus(*)(allocated: *):0.1; mem(*)(allocated: *):32; disk(*)(allocated: *):32 on agent 4779542b-dc31-43a4-9a0d-1a93a421753a-S0 at (562)@172.17.0.2:37535 (93a06a1a94c4) I0426 04:06:15.793304 26008 master.cpp:4708] Launching task group { 3c0a14de-0728-48c3-ad90-3850c709cc1d } of framework 4779542b-dc31-43a4-9a0d-1a93a421753a-0000 (default) with resources cpus(*)(allocated: *):0.1; mem(*)(allocated: *):32; disk(*)(allocated: *):32 on agent 4779542b-dc31-43a4-9a0d-1a93a421753a-S0 at (562)@172.17.0.2:37535 (93a06a1a94c4) I0426 04:06:15.793764 26011 slave.cpp:1613] Got assigned task group containing tasks [ 3c0a14de-0728-48c3-ad90-3850c709cc1d ] for framework 4779542b-dc31-43a4-9a0d-1a93a421753a-0000 I0426 04:06:15.794003 26008 hierarchical.cpp:1116] Recovered cpus(*)(allocated: *):1.8; mem(*)(allocated: *):960; disk(*)(allocated: *):960; ports(*)(allocated: *):[31000-32000] (total: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000], allocated: cpus(*)(allocated: *):0.2; mem(*)(allocated: *):64; disk(*)(allocated: *):64) on agent 4779542b-dc31-43a4-9a0d-1a93a421753a-S0 from framework 4779542b-dc31-43a4-9a0d-1a93a421753a-0000 I0426 04:06:15.794052 26008 hierarchical.cpp:1153] Framework 4779542b-dc31-43a4-9a0d-1a93a421753a-0000 filtered agent 4779542b-dc31-43a4-9a0d-1a93a421753a-S0 for 5secs I0426 04:06:15.794214 26011 slave.cpp:1894] Authorizing task group containing tasks [ 3c0a14de-0728-48c3-ad90-3850c709cc1d ] for framework 4779542b-dc31-43a4-9a0d-1a93a421753a-0000 I0426 04:06:15.794250 26011 slave.cpp:6582] Authorizing framework principal 'test-principal' to launch task 3c0a14de-0728-48c3-ad90-3850c709cc1d I0426 04:06:15.794777 26011 slave.cpp:2081] Launching task group containing tasks [ 3c0a14de-0728-48c3-ad90-3850c709cc1d ] for framework 4779542b-dc31-43a4-9a0d-1a93a421753a-0000 I0426 04:06:15.795473 26011 paths.cpp:556] Trying to chown '/tmp/ExecutorAuthorizationTest_FailedSubscribe_i1zmxe/slaves/4779542b-dc31-43a4-9a0d-1a93a421753a-S0/frameworks/4779542b-dc31-43a4-9a0d-1a93a421753a-0000/executors/default/runs/af96a2dc-d6b4-4f14-9e67-2fd58e24ea8d' to user 'mesos' I0426 04:06:15.795742 26011 slave.cpp:6926] Launching executor 'default' of framework 4779542b-dc31-43a4-9a0d-1a93a421753a-0000 with resources cpus(*)(allocated: *):0.1; mem(*)(allocated: *):32; disk(*)(allocated: *):32 in work directory '/tmp/ExecutorAuthorizationTest_FailedSubscribe_i1zmxe/slaves/4779542b-dc31-43a4-9a0d-1a93a421753a-S0/frameworks/4779542b-dc31-43a4-9a0d-1a93a421753a-0000/executors/default/runs/af96a2dc-d6b4-4f14-9e67-2fd58e24ea8d' I0426 04:06:15.795910 26011 slave.cpp:2310] Queued task group containing tasks [ 3c0a14de-0728-48c3-ad90-3850c709cc1d ] for executor 'default' of framework 4779542b-dc31-43a4-9a0d-1a93a421753a-0000 I0426 04:06:15.796990 26008 slave.cpp:871] Successfully attached file '/tmp/ExecutorAuthorizationTest_FailedSubscribe_i1zmxe/slaves/4779542b-dc31-43a4-9a0d-1a93a421753a-S0/frameworks/4779542b-dc31-43a4-9a0d-1a93a421753a-0000/executors/default/runs/af96a2dc-d6b4-4f14-9e67-2fd58e24ea8d' I0426 04:06:15.797613 26011 executor.cpp:192] Version: 1.3.0 I0426 04:06:15.798446 26002 executor.cpp:410] Connected with the agent I0426 04:06:15.798985 26010 executor.cpp:307] Sending SUBSCRIBE call to http://172.17.0.2:37535/(562)/api/v1/executor I0426 04:06:15.799708 25999 process.cpp:3722] Handling HTTP event for process '(562)' with path: '/(562)/api/v1/executor' I0426 04:06:15.800498 25999 http.cpp:1115] HTTP POST for /(562)/api/v1/executor from 172.17.0.2:33247 I0426 04:06:15.801069 26002 executor.cpp:723] Enqueuing locally injected event ERROR GMOCK WARNING: Uninteresting mock function call - returning directly. Function call: error(0x2abdd40449e0, @0x2abdb801b290 32-byte object <C0-0B 46-9A BD-2A 00-00 00-00 00-00 00-00 00-00 01-00 00-00 00-00 00-00 70-68 00-B8 BD-2A 00-00>) Stack trace: I0426 04:06:16.763469 26010 hierarchical.cpp:2106] Filtered offer with cpus(*):1.8; mem(*):960; disk(*):960; ports(*):[31000-32000] on agent 4779542b-dc31-43a4-9a0d-1a93a421753a-S0 for role * of framework 4779542b-dc31-43a4-9a0d-1a93a421753a-0000 I0426 04:06:16.763526 26010 hierarchical.cpp:1862] No allocations performed I0426 04:06:16.763538 26010 hierarchical.cpp:1952] No inverse offers to send out! I0426 04:06:16.763552 26010 hierarchical.cpp:1446] Performed allocation for 1 agents in 204516ns I0426 04:06:17.764171 26004 hierarchical.cpp:2106] Filtered offer with cpus(*):1.8; mem(*):960; disk(*):960; ports(*):[31000-32000] on agent 4779542b-dc31-43a4-9a0d-1a93a421753a-S0 for role * of framework 4779542b-dc31-43a4-9a0d-1a93a421753a-0000 I0426 04:06:17.764227 26004 hierarchical.cpp:1862] No allocations performed I0426 04:06:17.764240 26004 hierarchical.cpp:1952] No inverse offers to send out! I0426 04:06:17.764253 26004 hierarchical.cpp:1446] Performed allocation for 1 agents in 236122ns I0426 04:06:18.765559 26012 hierarchical.cpp:2106] Filtered offer with cpus(*):1.8; mem(*):960; disk(*):960; ports(*):[31000-32000] on agent 4779542b-dc31-43a4-9a0d-1a93a421753a-S0 for role * of framework 4779542b-dc31-43a4-9a0d-1a93a421753a-0000 I0426 04:06:18.765620 26012 hierarchical.cpp:1862] No allocations performed I0426 04:06:18.765632 26012 hierarchical.cpp:1952] No inverse offers to send out! I0426 04:06:18.765646 26012 hierarchical.cpp:1446] Performed allocation for 1 agents in 194513ns I0426 04:06:19.769064 26012 hierarchical.cpp:2106] Filtered offer with cpus(*):1.8; mem(*):960; disk(*):960; ports(*):[31000-32000] on agent 4779542b-dc31-43a4-9a0d-1a93a421753a-S0 for role * of framework 4779542b-dc31-43a4-9a0d-1a93a421753a-0000 I0426 04:06:19.769124 26012 hierarchical.cpp:1862] No allocations performed I0426 04:06:19.769136 26012 hierarchical.cpp:1952] No inverse offers to send out! I0426 04:06:19.769150 26012 hierarchical.cpp:1446] Performed allocation for 1 agents in 194587ns I0426 04:06:20.771225 26003 hierarchical.cpp:2106] Filtered offer with cpus(*):1.8; mem(*):960; disk(*):960; ports(*):[31000-32000] on agent 4779542b-dc31-43a4-9a0d-1a93a421753a-S0 for role * of framework 4779542b-dc31-43a4-9a0d-1a93a421753a-0000 I0426 04:06:20.771286 26003 hierarchical.cpp:1862] No allocations performed I0426 04:06:20.771301 26003 hierarchical.cpp:1952] No inverse offers to send out! I0426 04:06:20.771314 26003 hierarchical.cpp:1446] Performed allocation for 1 agents in 212741ns I0426 04:06:21.772572 26010 hierarchical.cpp:1952] No inverse offers to send out! I0426 04:06:21.772614 26010 hierarchical.cpp:1446] Performed allocation for 1 agents in 260937ns I0426 04:06:21.772810 26010 master.cpp:7087] Sending 1 offers to framework 4779542b-dc31-43a4-9a0d-1a93a421753a-0000 (default) I0426 04:06:21.773937 26007 scheduler.cpp:676] Enqueuing event OFFERS received from http://172.17.0.2:37535/master/api/v1/scheduler I0426 04:06:22.776525 26000 hierarchical.cpp:1862] No allocations performed I0426 04:06:22.776563 26000 hierarchical.cpp:1952] No inverse offers to send out! I0426 04:06:22.776578 26000 hierarchical.cpp:1446] Performed allocation for 1 agents in 101358ns I0426 04:06:23.779902 26008 hierarchical.cpp:1862] No allocations performed I0426 04:06:23.779937 26008 hierarchical.cpp:1952] No inverse offers to send out! I0426 04:06:23.779948 26008 hierarchical.cpp:1446] Performed allocation for 1 agents in 96396ns I0426 04:06:24.781158 25997 hierarchical.cpp:1862] No allocations performed I0426 04:06:24.781189 25997 hierarchical.cpp:1952] No inverse offers to send out! I0426 04:06:24.781201 25997 hierarchical.cpp:1446] Performed allocation for 1 agents in 110981ns I0426 04:06:25.784158 26004 hierarchical.cpp:1862] No allocations performed I0426 04:06:25.784189 26004 hierarchical.cpp:1952] No inverse offers to send out! I0426 04:06:25.784202 26004 hierarchical.cpp:1446] Performed allocation for 1 agents in 97312ns I0426 04:06:26.787794 26008 hierarchical.cpp:1862] No allocations performed I0426 04:06:26.787833 26008 hierarchical.cpp:1952] No inverse offers to send out! I0426 04:06:26.787850 26008 hierarchical.cpp:1446] Performed allocation for 1 agents in 104623ns I0426 04:06:27.792022 26001 hierarchical.cpp:1862] No allocations performed I0426 04:06:27.792059 26001 hierarchical.cpp:1952] No inverse offers to send out! I0426 04:06:27.792073 26001 hierarchical.cpp:1446] Performed allocation for 1 agents in 116639ns I0426 04:06:28.796178 26010 hierarchical.cpp:1862] No allocations performed I0426 04:06:28.796211 26010 hierarchical.cpp:1952] No inverse offers to send out! I0426 04:06:28.796222 26010 hierarchical.cpp:1446] Performed allocation for 1 agents in 109224ns I0426 04:06:29.799729 25998 hierarchical.cpp:1862] No allocations performed I0426 04:06:29.799767 25998 hierarchical.cpp:1952] No inverse offers to send out! I0426 04:06:29.799782 25998 hierarchical.cpp:1446] Performed allocation for 1 agents in 117511ns I0426 04:06:30.782210 26005 master.hpp:2167] Sending heartbeat to 4779542b-dc31-43a4-9a0d-1a93a421753a-0000 I0426 04:06:30.782663 26007 scheduler.cpp:676] Enqueuing event HEARTBEAT received from http://172.17.0.2:37535/master/api/v1/scheduler I0426 04:06:30.785182 26009 slave.cpp:4745] Received ping from slave-observer(490)@172.17.0.2:37535 I0426 04:06:30.803978 26007 hierarchical.cpp:1862] No allocations performed I0426 04:06:30.804029 26007 hierarchical.cpp:1952] No inverse offers to send out! I0426 04:06:30.804478 26007 hierarchical.cpp:1446] Performed allocation for 1 agents in 617293ns /mesos/src/tests/slave_authorization_tests.cpp:743: Failure Failed to wait 15secs for error I0426 04:06:30.814179 26011 master.cpp:1432] Framework 4779542b-dc31-43a4-9a0d-1a93a421753a-0000 (default) disconnected I0426 04:06:30.814476 26011 master.cpp:3162] Deactivating framework 4779542b-dc31-43a4-9a0d-1a93a421753a-0000 (default) W0426 04:06:30.814796 26011 master.hpp:2328] Unable to send event to framework 4779542b-dc31-43a4-9a0d-1a93a421753a-0000 (default): connection closed I0426 04:06:30.815074 26001 hierarchical.cpp:376] Deactivated framework 4779542b-dc31-43a4-9a0d-1a93a421753a-0000 I0426 04:06:30.816205 26001 hierarchical.cpp:1116] Recovered cpus(*)(allocated: *):1.8; mem(*)(allocated: *):960; disk(*)(allocated: *):960; ports(*)(allocated: *):[31000-32000] (total: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000], allocated: cpus(*)(allocated: *):0.2; mem(*)(allocated: *):64; disk(*)(allocated: *):64) on agent 4779542b-dc31-43a4-9a0d-1a93a421753a-S0 from framework 4779542b-dc31-43a4-9a0d-1a93a421753a-0000 I0426 04:06:30.816731 26011 master.cpp:3139] Disconnecting framework 4779542b-dc31-43a4-9a0d-1a93a421753a-0000 (default) I0426 04:06:30.817150 26011 master.cpp:1447] Giving framework 4779542b-dc31-43a4-9a0d-1a93a421753a-0000 (default) 0ns to failover I0426 04:06:30.818812 26000 master.cpp:6928] Framework failover timeout, removing framework 4779542b-dc31-43a4-9a0d-1a93a421753a-0000 (default) I0426 04:06:30.818852 26000 master.cpp:7782] Removing framework 4779542b-dc31-43a4-9a0d-1a93a421753a-0000 (default) I0426 04:06:30.819046 26000 master.cpp:8350] Updating the state of task 3c0a14de-0728-48c3-ad90-3850c709cc1d of framework 4779542b-dc31-43a4-9a0d-1a93a421753a-0000 (latest state: TASK_KILLED, status update state: TASK_KILLED) I0426 04:06:30.819427 26000 master.cpp:8444] Removing task 3c0a14de-0728-48c3-ad90-3850c709cc1d with resources cpus(*)(allocated: *):0.1; mem(*)(allocated: *):32; disk(*)(allocated: *):32 of framework 4779542b-dc31-43a4-9a0d-1a93a421753a-0000 on agent 4779542b-dc31-43a4-9a0d-1a93a421753a-S0 at (562)@172.17.0.2:37535 (93a06a1a94c4) I0426 04:06:30.819430 26001 hierarchical.cpp:1116] Recovered cpus(*)(allocated: *):0.1; mem(*)(allocated: *):32; disk(*)(allocated: *):32 (total: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000], allocated: cpus(*)(allocated: *):0.1; mem(*)(allocated: *):32; disk(*)(allocated: *):32) on agent 4779542b-dc31-43a4-9a0d-1a93a421753a-S0 from framework 4779542b-dc31-43a4-9a0d-1a93a421753a-0000 I0426 04:06:30.819599 26000 master.cpp:8473] Removing executor 'default' with resources cpus(*)(allocated: *):0.1; mem(*)(allocated: *):32; disk(*)(allocated: *):32 of framework 4779542b-dc31-43a4-9a0d-1a93a421753a-0000 on agent 4779542b-dc31-43a4-9a0d-1a93a421753a-S0 at (562)@172.17.0.2:37535 (93a06a1a94c4) /mesos/src/tests/slave_authorization_tests.cpp:740: Failure Actual function call count doesn't match EXPECT_CALL(*executor, error(_, _))... Expected: to be called once Actual: never called - unsatisfied and active mesos-tests: /mesos/3rdparty/libprocess/include/process/dispatch.hpp:229: auto process::dispatch(const PID<mesos::internal::slave::Slave> &, void (mesos::internal::slave::Slave::*)(const process::Future<Option<mesos::MasterInfo> > &), process::Future<Option<mesos::MasterInfo> >)::(anonymous class)::operator()(process::ProcessBase *) const: Assertion `t != nullptr' failed. I*** Aborted at 1493179590 (unix time) try "date -d @1493179590" if you are using GNU date *** 0426 04:06:30.820302 26002 hierarchical.cpp:1116] Recovered cpus(*)(allocated: *):0.1; mem(*)(allocated: *):32; disk(*)(allocated: *):32 (total: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000], allocated: {}) on agent 4779542b-dc31-43a4-9a0d-1a93a421753a-S0 from framework 4779542b-dc31-43a4-9a0d-1a93a421753a-0000 I0426 04:06:30.820543 26002 hierarchical.cpp:323] Removed framework 4779542b-dc31-43a4-9a0d-1a93a421753a-0000 PC: @ 0x2abd9cdfec37 (unknown) *** SIGABRT (@0x3e80000658c) received by PID 25996 (TID 0x2abda4593700) from PID 25996; stack trace: *** @ 0x2abd9c39a330 (unknown) @ 0x2abd9cdfec37 (unknown) @ 0x2abd9ce02028 (unknown) @ 0x2abd9cdf7bf6 (unknown) @ 0x2abd9cdf7ca2 (unknown) I0426 04:06:30.823978 25996 master.cpp:1157] Master terminating I0426 04:06:30.824339 26002 hierarchical.cpp:560] Removed agent 4779542b-dc31-43a4-9a0d-1a93a421753a-S0 [ FAILED ] ExecutorAuthorizationTest.FailedSubscribe (15067 ms) [ RUN ] ExecutorAuthorizationTest.FailedApiCalls I0426 04:06:30.828591 25996 cluster.cpp:162] Creating default 'local' authorizer I0426 04:06:30.829638 26011 master.cpp:438] Master 6fc275b9-58c7-4237-84f9-55573c08c064 (93a06a1a94c4) started on 172.17.0.2:37535 I0426 04:06:30.829679 26011 master.cpp:440] 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/I1tSpk/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" --port="5050" --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="/usr/local/share/mesos/webui" --work_dir="/tmp/I1tSpk/master" --zk_session_timeout="10secs" I0426 04:06:30.829829 26011 master.cpp:490] Master only allowing authenticated frameworks to register I0426 04:06:30.829839 26011 master.cpp:504] Master only allowing authenticated agents to register I0426 04:06:30.829848 26011 master.cpp:517] Master only allowing authenticated HTTP frameworks to register I0426 04:06:30.829856 26011 credentials.hpp:37] Loading credentials for authentication from '/tmp/I1tSpk/credentials' I0426 04:06:30.829980 26011 master.cpp:562] Using default 'crammd5' authenticator I0426 04:06:30.830034 26011 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly' I0426 04:06:30.830111 26011 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite' I0426 04:06:30.830159 26011 http.cpp:975] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler' I0426 04:06:30.830206 26011 master.cpp:642] Authorization enabled I0426 04:06:30.830389 26008 whitelist_watcher.cpp:77] No whitelist given I0426 04:06:30.830555 26006 hierarchical.cpp:159] Initialized hierarchical allocator process I0426 04:06:30.831250 25999 master.cpp:2163] Elected as the leading master! I0426 04:06:30.831266 25999 master.cpp:1702] Recovering from registrar I0426 04:06:30.831390 25998 registrar.cpp:345] Recovering registrar I0426 04:06:30.831689 25998 registrar.cpp:389] Successfully fetched the registry (0B) in 279040ns I0426 04:06:30.831728 25998 registrar.cpp:493] Applied 1 operations in 17224ns; attempting to update the registry I0426 04:06:30.831957 25998 registrar.cpp:550] Successfully updated the registry in 204032ns I0426 04:06:30.832005 25998 registrar.cpp:422] Successfully recovered registrar I0426 04:06:30.832268 26005 master.cpp:1801] Recovered 0 agents from the registry (129B); allowing 10mins for agents to re-register I0426 04:06:30.832306 25999 hierarchical.cpp:186] Skipping recovery of hierarchical allocator: nothing to recover @ 0x2abd97853347 _ZNSt17_Function_handlerIFvPN7process11ProcessBaseEEZNS0_8dispatchIN5mesos8internal5slave5SlaveERKNS0_6FutureI6OptionINS5_10MasterInfoEEEESD_EEvRKNS0_3PIDIT_EEMSH_FvT0_ET1_EUlS2_E_E9_M_invokeERKSt9_Any_dataS2_ @ 0x2abd990fa0e7 process::ProcessManager::resume() @ 0x2abd9910f29f std::thread::_Impl<>::_M_run() @ 0x2abd9c659a60 (unknown) @ 0x2abd9c392184 start_thread @ 0x2abd9cec5bed (unknown) make[3]: *** [CMakeFiles/check] Aborted make[3]: Leaving directory `/mesos/build' make[2]: *** [CMakeFiles/check.dir/all] Error 2 make[2]: Leaving directory `/mesos/build' make[1]: *** [CMakeFiles/check.dir/rule] Error 2 make[1]: Leaving directory `/mesos/build' make: *** [check] Error 2 + docker rmi mesos-1493177170-31249 Untagged: mesos-1493177170-31249:latest Deleted: sha256:385b7e99b7912a41d84eca9b932a29ff741d9db993f17f934162d50c427714a5 Build step 'Execute shell' marked build as failure Not sending mail to unregistered user [email protected]
