See <https://builds.apache.org/job/Mesos-Buildbot/BUILDTOOL=cmake,COMPILER=gcc,CONFIGURATION=--verbose%20--disable-libtool-wrappers,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1,OS=centos%3A7,label_exp=(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)&&(!qnode3)&&(!H23)/4596/display/redirect>
------------------------------------------ [...truncated 29.19 MB...] 3: I1214 00:19:02.332566 16054 hierarchical.cpp:344] Removed framework dcb79914-d77a-451d-bff9-381b0ae47254-0000 3: I1214 00:19:02.332813 16060 slave.cpp:909] Agent terminating 3: I1214 00:19:02.333045 16075 master.cpp:1305] Agent dcb79914-d77a-451d-bff9-381b0ae47254-S0 at slave(831)@172.17.0.7:45906 (2536c3aeddfc) disconnected 3: I1214 00:19:02.333068 16075 master.cpp:3364] Disconnecting agent dcb79914-d77a-451d-bff9-381b0ae47254-S0 at slave(831)@172.17.0.7:45906 (2536c3aeddfc) 3: I1214 00:19:02.333142 16075 master.cpp:3383] Deactivating agent dcb79914-d77a-451d-bff9-381b0ae47254-S0 at slave(831)@172.17.0.7:45906 (2536c3aeddfc) 3: I1214 00:19:02.333257 16070 hierarchical.cpp:766] Agent dcb79914-d77a-451d-bff9-381b0ae47254-S0 deactivated 3: I1214 00:19:02.340184 16058 master.cpp:1147] Master terminating 3: I1214 00:19:02.340863 16068 hierarchical.cpp:609] Removed agent dcb79914-d77a-451d-bff9-381b0ae47254-S0 3: [ OK ] ContentType/SchedulerTest.NoOffersWithAllRolesSuppressed/1 (118 ms) 3: [ RUN ] ContentType/SchedulerTest.NoOffersOnReregistrationWithAllRolesSuppressed/0 3: I1214 00:19:02.350611 16051 cluster.cpp:172] Creating default 'local' authorizer 3: I1214 00:19:02.353752 16059 master.cpp:456] Master 3c5802bd-031c-44fb-b4f2-83cfaac952d6 (2536c3aeddfc) started on 172.17.0.7:45906 3: I1214 00:19:02.353775 16059 master.cpp:458] 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/9pv1jv/credentials" --filter_gpu_resources="true" --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/9pv1jv/master" --zk_session_timeout="10secs" 3: I1214 00:19:02.354096 16059 master.cpp:507] Master only allowing authenticated frameworks to register 3: I1214 00:19:02.354104 16059 master.cpp:513] Master only allowing authenticated agents to register 3: I1214 00:19:02.354109 16059 master.cpp:519] Master only allowing authenticated HTTP frameworks to register 3: I1214 00:19:02.354113 16059 credentials.hpp:37] Loading credentials for authentication from '/tmp/9pv1jv/credentials' 3: I1214 00:19:02.354393 16059 master.cpp:563] Using default 'crammd5' authenticator 3: I1214 00:19:02.354553 16059 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly' 3: I1214 00:19:02.354732 16059 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite' 3: I1214 00:19:02.354883 16059 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler' 3: I1214 00:19:02.355000 16059 master.cpp:642] Authorization enabled 3: I1214 00:19:02.355163 16056 hierarchical.cpp:175] Initialized hierarchical allocator process 3: I1214 00:19:02.355165 16057 whitelist_watcher.cpp:77] No whitelist given 3: I1214 00:19:02.358034 16067 master.cpp:2209] Elected as the leading master! 3: I1214 00:19:02.358062 16067 master.cpp:1689] Recovering from registrar 3: I1214 00:19:02.358209 16055 registrar.cpp:347] Recovering registrar 3: I1214 00:19:02.358942 16055 registrar.cpp:391] Successfully fetched the registry (0B) in 697088ns 3: I1214 00:19:02.359074 16055 registrar.cpp:495] Applied 1 operations in 45016ns; attempting to update the registry 3: I1214 00:19:02.359774 16055 registrar.cpp:552] Successfully updated the registry in 647936ns 3: I1214 00:19:02.359923 16055 registrar.cpp:424] Successfully recovered registrar 3: I1214 00:19:02.360381 16073 master.cpp:1802] Recovered 0 agents from the registry (135B); allowing 10mins for agents to re-register 3: I1214 00:19:02.360400 16069 hierarchical.cpp:213] Skipping recovery of hierarchical allocator: nothing to recover 3: W1214 00:19:02.364912 16051 process.cpp:2756] Attempted to spawn already running process [email protected]:45906 3: I1214 00:19:02.365818 16051 containerizer.cpp:304] Using isolation { environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni } 3: W1214 00:19:02.366338 16051 backend.cpp:76] Failed to create 'aufs' backend: AufsBackend requires root privileges 3: W1214 00:19:02.366449 16051 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires root privileges 3: I1214 00:19:02.366488 16051 provisioner.cpp:299] Using default backend 'copy' 3: I1214 00:19:02.368211 16051 cluster.cpp:460] Creating default 'local' authorizer 3: I1214 00:19:02.370363 16073 slave.cpp:258] Mesos agent started on (832)@172.17.0.7:45906 3: I1214 00:19:02.370385 16073 slave.cpp:259] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://"; --appc_store_dir="/tmp/ContentType_SchedulerTest_NoOffersOnReregistrationWithAllRolesSuppressed_0_ZPozIj/store/appc" --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/ContentType_SchedulerTest_NoOffersOnReregistrationWithAllRolesSuppressed_0_ZPozIj/credential" --default_role="*" --disallow_sharing_agent_pid_namespace="false" --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/ContentType_SchedulerTest_NoOffersOnReregistrationWithAllRolesSuppressed_0_ZPozIj/store/docker" --docker_volume_checkpoint_dir="/var/run/mesos/isolators/docker/volume" --enforce_container_disk_quota="false" --executor_registration_timeout="1mins" --executor_reregistration_timeout="2secs" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/ContentType_SchedulerTest_NoOffersOnReregistrationWithAllRolesSuppressed_0_ZPozIj/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/ContentType_SchedulerTest_NoOffersOnReregistrationWithAllRolesSuppressed_0_ZPozIj/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" --reconfiguration_policy="equal" --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/ContentType_SchedulerTest_NoOffersOnReregistrationWithAllRolesSuppressed_0_ZPozIj" --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/ContentType_SchedulerTest_NoOffersOnReregistrationWithAllRolesSuppressed_0_mnUhwp" --zk_session_timeout="10secs" 3: I1214 00:19:02.370760 16073 credentials.hpp:86] Loading credential for authentication from '/tmp/ContentType_SchedulerTest_NoOffersOnReregistrationWithAllRolesSuppressed_0_ZPozIj/credential' 3: I1214 00:19:02.370951 16073 slave.cpp:291] Agent using credential for: test-principal 3: I1214 00:19:02.370968 16073 credentials.hpp:37] Loading credentials for authentication from '/tmp/ContentType_SchedulerTest_NoOffersOnReregistrationWithAllRolesSuppressed_0_ZPozIj/http_credentials' 3: I1214 00:19:02.371217 16073 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly' 3: I1214 00:19:02.371372 16073 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readwrite' 3: I1214 00:19:02.372954 16073 slave.cpp:590] Agent resources: [{"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"disk","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}] 3: I1214 00:19:02.373251 16073 slave.cpp:598] Agent attributes: [ ] 3: I1214 00:19:02.373270 16073 slave.cpp:607] Agent hostname: 2536c3aeddfc 3: I1214 00:19:02.373443 16075 task_status_update_manager.cpp:181] Pausing sending task status updates 3: I1214 00:19:02.375476 16064 state.cpp:66] Recovering state from '/tmp/ContentType_SchedulerTest_NoOffersOnReregistrationWithAllRolesSuppressed_0_mnUhwp/meta' 3: I1214 00:19:02.375792 16055 task_status_update_manager.cpp:207] Recovering task status update manager 3: I1214 00:19:02.376047 16061 containerizer.cpp:674] Recovering containerizer 3: I1214 00:19:02.377995 16071 provisioner.cpp:495] Provisioner recovery complete 3: I1214 00:19:02.378353 16075 slave.cpp:6747] Finished recovery 3: I1214 00:19:02.379110 16073 task_status_update_manager.cpp:181] Pausing sending task status updates 3: I1214 00:19:02.379109 16052 slave.cpp:1033] New master detected at [email protected]:45906 3: I1214 00:19:02.379173 16052 slave.cpp:1088] Detecting new master 3: I1214 00:19:02.386164 16053 slave.cpp:1115] Authenticating with master [email protected]:45906 3: I1214 00:19:02.386240 16053 slave.cpp:1124] Using default CRAM-MD5 authenticatee 3: I1214 00:19:02.386479 16055 authenticatee.cpp:121] Creating new client SASL connection 3: I1214 00:19:02.386807 16066 master.cpp:8928] Authenticating slave(832)@172.17.0.7:45906 3: I1214 00:19:02.386965 16054 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(1459)@172.17.0.7:45906 3: I1214 00:19:02.387230 16074 authenticator.cpp:98] Creating new server SASL connection 3: I1214 00:19:02.387446 16060 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5 3: I1214 00:19:02.387471 16060 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5' 3: I1214 00:19:02.387605 16056 authenticator.cpp:204] Received SASL authentication start 3: I1214 00:19:02.387677 16056 authenticator.cpp:326] Authentication requires more steps 3: I1214 00:19:02.387775 16069 authenticatee.cpp:259] Received SASL authentication step 3: I1214 00:19:02.387900 16063 authenticator.cpp:232] Received SASL authentication step 3: I1214 00:19:02.387936 16063 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '2536c3aeddfc' server FQDN: '2536c3aeddfc' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 3: I1214 00:19:02.387958 16063 auxprop.cpp:181] Looking up auxiliary property '*userPassword' 3: I1214 00:19:02.387992 16063 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5' 3: I1214 00:19:02.388020 16063 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '2536c3aeddfc' server FQDN: '2536c3aeddfc' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 3: I1214 00:19:02.388041 16063 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true 3: I1214 00:19:02.388051 16063 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true 3: I1214 00:19:02.388072 16063 authenticator.cpp:318] Authentication success 3: I1214 00:19:02.388164 16061 authenticatee.cpp:299] Authentication success 3: I1214 00:19:02.388244 16059 master.cpp:8958] Successfully authenticated principal 'test-principal' at slave(832)@172.17.0.7:45906 3: I1214 00:19:02.388298 16061 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(1459)@172.17.0.7:45906 3: I1214 00:19:02.388418 16062 slave.cpp:1207] Successfully authenticated with master [email protected]:45906 3: I1214 00:19:02.388595 16062 slave.cpp:1684] Will retry registration in 2.636128ms if necessary 3: I1214 00:19:02.388728 16075 master.cpp:6077] Received register agent message from slave(832)@172.17.0.7:45906 (2536c3aeddfc) 3: I1214 00:19:02.388800 16075 master.cpp:3866] Authorizing agent with principal 'test-principal' 3: I1214 00:19:02.389289 16067 master.cpp:6147] Authorized registration of agent at slave(832)@172.17.0.7:45906 (2536c3aeddfc) 3: I1214 00:19:02.389369 16067 master.cpp:6240] Registering agent at slave(832)@172.17.0.7:45906 (2536c3aeddfc) with id 3c5802bd-031c-44fb-b4f2-83cfaac952d6-S0 3: I1214 00:19:02.389847 16073 registrar.cpp:495] Applied 1 operations in 83316ns; attempting to update the registry 3: I1214 00:19:02.390519 16073 registrar.cpp:552] Successfully updated the registry in 617216ns 3: I1214 00:19:02.390717 16055 master.cpp:6288] Admitted agent 3c5802bd-031c-44fb-b4f2-83cfaac952d6-S0 at slave(832)@172.17.0.7:45906 (2536c3aeddfc) 3: I1214 00:19:02.391353 16055 master.cpp:6337] Registered agent 3c5802bd-031c-44fb-b4f2-83cfaac952d6-S0 at slave(832)@172.17.0.7:45906 (2536c3aeddfc) with cpus:2; mem:1024; disk:1024; ports:[31000-32000] 3: I1214 00:19:02.391526 16054 slave.cpp:1253] Registered with master [email protected]:45906; given agent ID 3c5802bd-031c-44fb-b4f2-83cfaac952d6-S0 3: I1214 00:19:02.391676 16057 task_status_update_manager.cpp:188] Resuming sending task status updates 3: I1214 00:19:02.391708 16074 hierarchical.cpp:574] Added agent 3c5802bd-031c-44fb-b4f2-83cfaac952d6-S0 (2536c3aeddfc) with cpus:2; mem:1024; disk:1024; ports:[31000-32000] (allocated: {}) 3: I1214 00:19:02.391858 16054 slave.cpp:1273] Checkpointing SlaveInfo to '/tmp/ContentType_SchedulerTest_NoOffersOnReregistrationWithAllRolesSuppressed_0_mnUhwp/meta/slaves/3c5802bd-031c-44fb-b4f2-83cfaac952d6-S0/slave.info' 3: I1214 00:19:02.392012 16074 hierarchical.cpp:1517] Performed allocation for 1 agents in 143218ns 3: I1214 00:19:02.392285 16054 slave.cpp:1330] Forwarding agent update {"offer_operations":{},"resource_version_uuid":"dB\/tMM\/fQiGwEQnzOZfHbw==","slave_id":{"value":"3c5802bd-031c-44fb-b4f2-83cfaac952d6-S0"},"update_oversubscribed_resources":true} 3: I1214 00:19:02.392483 16058 master.cpp:7266] Received update of agent 3c5802bd-031c-44fb-b4f2-83cfaac952d6-S0 at slave(832)@172.17.0.7:45906 (2536c3aeddfc) with total oversubscribed resources {} 3: I1214 00:19:02.392509 16051 scheduler.cpp:188] Version: 1.5.0 3: I1214 00:19:02.392724 16058 master.cpp:7364] Ignoring update on agent 3c5802bd-031c-44fb-b4f2-83cfaac952d6-S0 at slave(832)@172.17.0.7:45906 (2536c3aeddfc) as it reports no changes 3: I1214 00:19:02.392794 16061 scheduler.cpp:311] Using default 'basic' HTTP authenticatee 3: I1214 00:19:02.393211 16068 scheduler.cpp:494] New master detected at [email protected]:45906 3: I1214 00:19:02.393235 16068 scheduler.cpp:503] Waiting for 0ns before initiating a re-(connection) attempt with the master 3: I1214 00:19:02.396942 16055 scheduler.cpp:385] Connected with the master at http://172.17.0.7:45906/master/api/v1/scheduler 3: I1214 00:19:02.405841 16059 scheduler.cpp:247] Sending SUBSCRIBE call to http://172.17.0.7:45906/master/api/v1/scheduler 3: I1214 00:19:02.407191 16058 process.cpp:3503] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler' 3: I1214 00:19:02.408830 16064 http.cpp:1185] HTTP POST for /master/api/v1/scheduler from 172.17.0.7:51330 3: I1214 00:19:02.409054 16064 master.cpp:2609] Received subscription request for HTTP framework 'default' 3: I1214 00:19:02.409185 16064 master.cpp:2274] Authorizing framework principal 'test-principal' to receive offers for roles '{ * }' 3: I1214 00:19:02.409682 16073 master.cpp:2744] Subscribing framework 'default' with checkpointing disabled and capabilities [ MULTI_ROLE, RESERVATION_REFINEMENT ] 3: I1214 00:19:02.409909 16073 master.cpp:9149] Adding framework 3c5802bd-031c-44fb-b4f2-83cfaac952d6-0000 (default) with roles { } suppressed 3: I1214 00:19:02.410526 16060 hierarchical.cpp:297] Added framework 3c5802bd-031c-44fb-b4f2-83cfaac952d6-0000 3: I1214 00:19:02.411106 16054 scheduler.cpp:739] Enqueuing event SUBSCRIBED received from http://172.17.0.7:45906/master/api/v1/scheduler 3: I1214 00:19:02.411578 16054 scheduler.cpp:739] Enqueuing event HEARTBEAT received from http://172.17.0.7:45906/master/api/v1/scheduler 3: I1214 00:19:02.411872 16060 hierarchical.cpp:1517] Performed allocation for 1 agents in 1.192839ms 3: I1214 00:19:02.412310 16067 master.cpp:8758] Sending 1 offers to framework 3c5802bd-031c-44fb-b4f2-83cfaac952d6-0000 (default) 3: I1214 00:19:02.413673 16063 scheduler.cpp:739] Enqueuing event OFFERS received from http://172.17.0.7:45906/master/api/v1/scheduler 3: I1214 00:19:02.423630 16059 scheduler.cpp:468] Re-detecting master 3: I1214 00:19:02.424129 16059 scheduler.cpp:693] Ignoring event from old stale connection 3: I1214 00:19:02.424186 16059 scheduler.cpp:419] Ignoring disconnection attempt from stale connection 3: I1214 00:19:02.424214 16059 scheduler.cpp:419] Ignoring disconnection attempt from stale connection 3: I1214 00:19:02.424340 16059 scheduler.cpp:494] New master detected at [email protected]:45906 3: I1214 00:19:02.424362 16059 scheduler.cpp:503] Waiting for 0ns before initiating a re-(connection) attempt with the master 3: I1214 00:19:02.424798 16053 master.cpp:1419] Framework 3c5802bd-031c-44fb-b4f2-83cfaac952d6-0000 (default) disconnected 3: I1214 00:19:02.424819 16053 master.cpp:3327] Deactivating framework 3c5802bd-031c-44fb-b4f2-83cfaac952d6-0000 (default) 3: I1214 00:19:02.424927 16072 hierarchical.cpp:405] Deactivated framework 3c5802bd-031c-44fb-b4f2-83cfaac952d6-0000 3: W1214 00:19:02.425564 16053 master.hpp:2294] Unable to send event to framework 3c5802bd-031c-44fb-b4f2-83cfaac952d6-0000 (default): connection closed 3: I1214 00:19:02.425599 16053 master.cpp:10679] Removing offer 3c5802bd-031c-44fb-b4f2-83cfaac952d6-O0 3: I1214 00:19:02.425658 16053 master.cpp:3304] Disconnecting framework 3c5802bd-031c-44fb-b4f2-83cfaac952d6-0000 (default) 3: I1214 00:19:02.425693 16053 master.cpp:1434] Giving framework 3c5802bd-031c-44fb-b4f2-83cfaac952d6-0000 (default) 1weeks to failover 3: I1214 00:19:02.426236 16055 hierarchical.cpp:1192] 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 3c5802bd-031c-44fb-b4f2-83cfaac952d6-S0 from framework 3c5802bd-031c-44fb-b4f2-83cfaac952d6-0000 3: I1214 00:19:02.427884 16071 scheduler.cpp:385] Connected with the master at http://172.17.0.7:45906/master/api/v1/scheduler 3: I1214 00:19:02.437005 16068 scheduler.cpp:247] Sending SUBSCRIBE call to http://172.17.0.7:45906/master/api/v1/scheduler 3: I1214 00:19:02.438246 16059 process.cpp:3503] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler' 3: I1214 00:19:02.439584 16055 http.cpp:1185] HTTP POST for /master/api/v1/scheduler from 172.17.0.7:51334 3: I1214 00:19:02.439821 16055 master.cpp:2609] Received subscription request for HTTP framework 'default' 3: I1214 00:19:02.439913 16055 master.cpp:2274] Authorizing framework principal 'test-principal' to receive offers for roles '{ * }' 3: I1214 00:19:02.440397 16063 master.cpp:2744] Subscribing framework 'default' with checkpointing disabled and capabilities [ MULTI_ROLE, RESERVATION_REFINEMENT ] 3: I1214 00:19:02.440438 16063 master.cpp:7194] Updating framework 3c5802bd-031c-44fb-b4f2-83cfaac952d6-0000 (default) with roles { * } suppressed 3: I1214 00:19:02.440794 16070 hierarchical.cpp:371] Activated framework 3c5802bd-031c-44fb-b4f2-83cfaac952d6-0000 3: I1214 00:19:02.441139 16070 hierarchical.cpp:1517] Performed allocation for 1 agents in 215727ns 3: W1214 00:19:02.441360 16075 slave.cpp:3535] Ignoring info update for framework 3c5802bd-031c-44fb-b4f2-83cfaac952d6-0000 because it does not exist 3: I1214 00:19:02.441680 16052 scheduler.cpp:739] Enqueuing event SUBSCRIBED received from http://172.17.0.7:45906/master/api/v1/scheduler 3: I1214 00:19:02.442129 16052 scheduler.cpp:739] Enqueuing event HEARTBEAT received from http://172.17.0.7:45906/master/api/v1/scheduler 3: I1214 00:19:02.444586 16073 hierarchical.cpp:1517] Performed allocation for 1 agents in 222044ns 3: I1214 00:19:02.445049 16060 scheduler.cpp:739] Enqueuing event HEARTBEAT received from http://172.17.0.7:45906/master/api/v1/scheduler 3: I1214 00:19:02.445845 16059 scheduler.cpp:247] Sending REVIVE call to http://172.17.0.7:45906/master/api/v1/scheduler 3: I1214 00:19:02.446916 16066 process.cpp:3503] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler' 3: I1214 00:19:02.448091 16063 http.cpp:1185] HTTP POST for /master/api/v1/scheduler from 172.17.0.7:51332 3: I1214 00:19:02.448175 16063 master.cpp:5588] Processing REVIVE call for framework 3c5802bd-031c-44fb-b4f2-83cfaac952d6-0000 (default) 3: I1214 00:19:02.448323 16071 hierarchical.cpp:1339] Revived offers for roles { * } of framework 3c5802bd-031c-44fb-b4f2-83cfaac952d6-0000 3: I1214 00:19:02.449954 16071 hierarchical.cpp:1517] Performed allocation for 1 agents in 1.476404ms 3: I1214 00:19:02.450356 16068 master.cpp:8758] Sending 1 offers to framework 3c5802bd-031c-44fb-b4f2-83cfaac952d6-0000 (default) 3: I1214 00:19:02.451843 16061 scheduler.cpp:739] Enqueuing event OFFERS received from http://172.17.0.7:45906/master/api/v1/scheduler 3: I1214 00:19:02.458415 16051 slave.cpp:909] Agent terminating 3: I1214 00:19:02.458611 16054 master.cpp:1305] Agent 3c5802bd-031c-44fb-b4f2-83cfaac952d6-S0 at slave(832)@172.17.0.7:45906 (2536c3aeddfc) disconnected 3: I1214 00:19:02.458640 16054 master.cpp:3364] Disconnecting agent 3c5802bd-031c-44fb-b4f2-83cfaac952d6-S0 at slave(832)@172.17.0.7:45906 (2536c3aeddfc) 3: I1214 00:19:02.458711 16054 master.cpp:3383] Deactivating agent 3c5802bd-031c-44fb-b4f2-83cfaac952d6-S0 at slave(832)@172.17.0.7:45906 (2536c3aeddfc) 3: I1214 00:19:02.458839 16061 hierarchical.cpp:766] Agent 3c5802bd-031c-44fb-b4f2-83cfaac952d6-S0 deactivated 3: W1214 00:19:02.459367 16054 master.hpp:2294] Unable to send event to framework 3c5802bd-031c-44fb-b4f2-83cfaac952d6-0000 (default): connection closed 3: I1214 00:19:02.459393 16054 master.cpp:10679] Removing offer 3c5802bd-031c-44fb-b4f2-83cfaac952d6-O1 3: I1214 00:19:02.459525 16054 master.cpp:1419] Framework 3c5802bd-031c-44fb-b4f2-83cfaac952d6-0000 (default) disconnected 3: I1214 00:19:02.459542 16054 master.cpp:3327] Deactivating framework 3c5802bd-031c-44fb-b4f2-83cfaac952d6-0000 (default) 3: I1214 00:19:02.459581 16054 master.cpp:3304] Disconnecting framework 3c5802bd-031c-44fb-b4f2-83cfaac952d6-0000 (default) 3: I1214 00:19:02.459604 16054 master.cpp:1434] Giving framework 3c5802bd-031c-44fb-b4f2-83cfaac952d6-0000 (default) 0ns to failover 3: I1214 00:19:02.459960 16052 hierarchical.cpp:1192] 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 3c5802bd-031c-44fb-b4f2-83cfaac952d6-S0 from framework 3c5802bd-031c-44fb-b4f2-83cfaac952d6-0000 3: I1214 00:19:02.460068 16052 hierarchical.cpp:405] Deactivated framework 3c5802bd-031c-44fb-b4f2-83cfaac952d6-0000 3: I1214 00:19:02.460918 16066 master.cpp:8573] Framework failover timeout, removing framework 3c5802bd-031c-44fb-b4f2-83cfaac952d6-0000 (default) 3: I1214 00:19:02.460940 16066 master.cpp:9450] Removing framework 3c5802bd-031c-44fb-b4f2-83cfaac952d6-0000 (default) 3: I1214 00:19:02.461381 16074 hierarchical.cpp:344] Removed framework 3c5802bd-031c-44fb-b4f2-83cfaac952d6-0000 3: I1214 00:19:02.467726 16051 master.cpp:1147] Master terminating 3: I1214 00:19:02.468338 16061 hierarchical.cpp:609] Removed agent 3c5802bd-031c-44fb-b4f2-83cfaac952d6-S0 3: [ OK ] ContentType/SchedulerTest.NoOffersOnReregistrationWithAllRolesSuppressed/0 (124 ms) 3: [ RUN ] ContentType/SchedulerTest.NoOffersOnReregistrationWithAllRolesSuppressed/1 3: I1214 00:19:02.474798 16051 cluster.cpp:172] Creating default 'local' authorizer 3: I1214 00:19:02.477628 16056 master.cpp:456] Master 421c38ed-0eb1-4403-b143-aee16e8c1b16 (2536c3aeddfc) started on 172.17.0.7:45906 3: I1214 00:19:02.477645 16056 master.cpp:458] 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/o78mG2/credentials" --filter_gpu_resources="true" --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/o78mG2/master" --zk_session_timeout="10secs" 3: I1214 00:19:02.477916 16056 master.cpp:507] Master only allowing authenticated frameworks to register 3: I1214 00:19:02.477922 16056 master.cpp:513] Master only allowing authenticated agents to register 3: I1214 00:19:02.477926 16056 master.cpp:519] Master only allowing authenticated HTTP frameworks to register 3: I1214 00:19:02.477931 16056 credentials.hpp:37] Loading credentials for authentication from '/tmp/o78mG2/credentials' 3: I1214 00:19:02.478197 16056 master.cpp:563] Using default 'crammd5' authenticator 3: I1214 00:19:02.478348 16056 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly' 3: I1214 00:19:02.478488 16056 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite' 3: I1214 00:19:02.478606 16056 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler' 3: I1214 00:19:02.478711 16056 master.cpp:642] Authorization enabled 3: I1214 00:19:02.478874 16072 hierarchical.cpp:175] Initialized hierarchical allocator process 3: I1214 00:19:02.478896 16060 whitelist_watcher.cpp:77] No whitelist given 3: I1214 00:19:02.481688 16059 master.cpp:2209] Elected as the leading master! 3: I1214 00:19:02.481715 16059 master.cpp:1689] Recovering from registrar 3: I1214 00:19:02.481865 16058 registrar.cpp:347] Recovering registrar 3: I1214 00:19:02.482504 16058 registrar.cpp:391] Successfully fetched the registry (0B) in 604672ns 3: I1214 00:19:02.482610 16058 registrar.cpp:495] Applied 1 operations in 30127ns; attempting to update the registry 3: I1214 00:19:02.483155 16058 registrar.cpp:552] Successfully updated the registry in 498944ns 3: I1214 00:19:02.483276 16058 registrar.cpp:424] Successfully recovered registrar 3: I1214 00:19:02.483662 16063 master.cpp:1802] Recovered 0 agents from the registry (135B); allowing 10mins for agents to re-register 3: I1214 00:19:02.483698 16071 hierarchical.cpp:213] Skipping recovery of hierarchical allocator: nothing to recover 3: W1214 00:19:02.488098 16051 process.cpp:2756] Attempted to spawn already running process [email protected]:45906 3: I1214 00:19:02.488991 16051 containerizer.cpp:304] Using isolation { environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni } 3: W1214 00:19:02.489518 16051 backend.cpp:76] Failed to create 'aufs' backend: AufsBackend requires root privileges 3: W1214 00:19:02.489639 16051 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires root privileges 3: I1214 00:19:02.489670 16051 provisioner.cpp:299] Using default backend 'copy' 3: I1214 00:19:02.491422 16051 cluster.cpp:460] Creating default 'local' authorizer 3: I1214 00:19:02.493544 16060 slave.cpp:258] Mesos agent started on (833)@172.17.0.7:45906 3: I1214 00:19:02.493561 16060 slave.cpp:259] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://"; --appc_store_dir="/tmp/ContentType_SchedulerTest_NoOffersOnReregistrationWithAllRolesSuppressed_1_4hNBFR/store/appc" --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/ContentType_SchedulerTest_NoOffersOnReregistrationWithAllRolesSuppressed_1_4hNBFR/credential" --default_role="*" --disallow_sharing_agent_pid_namespace="false" --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/ContentType_SchedulerTest_NoOffersOnReregistrationWithAllRolesSuppressed_1_4hNBFR/store/docker" --docker_volume_checkpoint_dir="/var/run/mesos/isolators/docker/volume" --enforce_container_disk_quota="false" --executor_registration_timeout="1mins" --executor_reregistration_timeout="2secs" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/ContentType_SchedulerTest_NoOffersOnReregistrationWithAllRolesSuppressed_1_4hNBFR/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/ContentType_SchedulerTest_NoOffersOnReregistrationWithAllRolesSuppressed_1_4hNBFR/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" --reconfiguration_policy="equal" --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/ContentType_SchedulerTest_NoOffersOnReregistrationWithAllRolesSuppressed_1_4hNBFR" --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/ContentType_SchedulerTest_NoOffersOnReregistrationWithAllRolesSuppressed_1_dfVYaX" --zk_session_timeout="10secs" 3: I1214 00:19:02.493965 16060 credentials.hpp:86] Loading credential for authentication from '/tmp/ContentType_SchedulerTest_NoOffersOnReregistrationWithAllRolesSuppressed_1_4hNBFR/credential' 3: I1214 00:19:02.494129 16060 slave.cpp:291] Agent using credential for: test-principal 3: I1214 00:19:02.494146 16060 credentials.hpp:37] Loading credentials for authentication from '/tmp/ContentType_SchedulerTest_NoOffersOnReregistrationWithAllRolesSuppressed_1_4hNBFR/http_credentials' 3: I1214 00:19:02.494412 16060 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly' 3: I1214 00:19:02.494568 16060 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readwrite' 3: I1214 00:19:02.496074 16060 slave.cpp:590] Agent resources: [{"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"disk","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}] 3: I1214 00:19:02.496299 16060 slave.cpp:598] Agent attributes: [ ] 3: I1214 00:19:02.496311 16060 slave.cpp:607] Agent hostname: 2536c3aeddfc 3: I1214 00:19:02.496445 16059 task_status_update_manager.cpp:181] Pausing sending task status updates 3: I1214 00:19:02.498131 16070 state.cpp:66] Recovering state from '/tmp/ContentType_SchedulerTest_NoOffersOnReregistrationWithAllRolesSuppressed_1_dfVYaX/meta' 3: I1214 00:19:02.498443 16057 task_status_update_manager.cpp:207] Recovering task status update manager 3: I1214 00:19:02.498626 16064 containerizer.cpp:674] Recovering containerizer 3: I1214 00:19:02.500190 16074 provisioner.cpp:495] Provisioner recovery complete 3: I1214 00:19:02.500514 16059 slave.cpp:6747] Finished recovery 3: I1214 00:19:02.501319 16060 task_status_update_manager.cpp:181] Pausing sending task status updates 3: I1214 00:19:02.501323 16053 slave.cpp:1033] New master detected at [email protected]:45906 3: I1214 00:19:02.501405 16053 slave.cpp:1088] Detecting new master 3: I1214 00:19:02.505796 16058 slave.cpp:1115] Authenticating with master [email protected]:45906 3: I1214 00:19:02.505867 16058 slave.cpp:1124] Using default CRAM-MD5 authenticatee 3: I1214 00:19:02.506120 16075 authenticatee.cpp:121] Creating new client SASL connection 3: I1214 00:19:02.506398 16057 master.cpp:8928] Authenticating slave(833)@172.17.0.7:45906 3: I1214 00:19:02.506559 16067 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(1460)@172.17.0.7:45906 3: I1214 00:19:02.506836 16073 authenticator.cpp:98] Creating new server SASL connection 3: I1214 00:19:02.507128 16066 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5 3: I1214 00:19:02.507153 16066 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5' 3: I1214 00:19:02.507263 16072 authenticator.cpp:204] Received SASL authentication start 3: I1214 00:19:02.507313 16072 authenticator.cpp:326] Authentication requires more steps 3: I1214 00:19:02.507411 16071 authenticatee.cpp:259] Received SASL authentication step 3: I1214 00:19:02.507535 16056 authenticator.cpp:232] Received SASL authentication step 3: I1214 00:19:02.507565 16056 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '2536c3aeddfc' server FQDN: '2536c3aeddfc' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 3: I1214 00:19:02.507580 16056 auxprop.cpp:181] Looking up auxiliary property '*userPassword' 3: I1214 00:19:02.507627 16056 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5' 3: I1214 00:19:02.507648 16056 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '2536c3aeddfc' server FQDN: '2536c3aeddfc' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 3: I1214 00:19:02.507661 16056 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true 3: I1214 00:19:02.507671 16056 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true 3: I1214 00:19:02.507694 16056 authenticator.cpp:318] Authentication success 3: I1214 00:19:02.507802 16055 authenticatee.cpp:299] Authentication success 3: I1214 00:19:02.507874 16064 master.cpp:8958] Successfully authenticated principal 'test-principal' at slave(833)@172.17.0.7:45906 3: I1214 00:19:02.507913 16068 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(1460)@172.17.0.7:45906 3: I1214 00:19:02.508050 16063 slave.cpp:1207] Successfully authenticated with master [email protected]:45906 3: I1214 00:19:02.508225 16063 slave.cpp:1684] Will retry registration in 13.669677ms if necessary Process leaked file descriptors. See https://jenkins.io/redirect/troubleshooting/process-leaked-file-descriptors for more information Build step 'Execute shell' marked build as failure Not sending mail to unregistered user [email protected] Not sending mail to unregistered user [email protected]
