See <https://builds.apache.org/job/Mesos-Buildbot/BUILDTOOL=cmake,COMPILER=gcc,CONFIGURATION=--verbose%20--disable-libtool-wrappers%20--enable-libevent%20--enable-ssl,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1,OS=ubuntu%3A14.04,label_exp=(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)&&(!qnode3)&&(!H23)/4556/display/redirect?page=changes>
Changes: [bmahler] Updated the allocator to untrack allocations via a single code path. ------------------------------------------ [...truncated 6.54 MB...] 3: I1207 22:39:15.493805 20080 sched.cpp:2009] Asked to stop the driver 3: I1207 22:39:15.493999 20088 sched.cpp:1191] Stopping framework 45a73448-7083-401a-8f60-8ed9fc27a7f8-0000 3: I1207 22:39:15.494396 20080 sched.cpp:2009] Asked to stop the driver 3: I1207 22:39:15.494560 20087 sched.cpp:1191] Stopping framework 45a73448-7083-401a-8f60-8ed9fc27a7f8-0000 3: W1207 22:39:15.494843 20098 master.cpp:2343] Dropping TEARDOWN call from framework 45a73448-7083-401a-8f60-8ed9fc27a7f8-0000 at [email protected]:44557: Call is not from registered framework 3: I1207 22:39:15.495813 20093 master.cpp:1150] Master terminating 3: I1207 22:39:15.496388 20102 hierarchical.cpp:344] Removed framework 45a73448-7083-401a-8f60-8ed9fc27a7f8-0000 3: [ OK ] RateLimitingTest.SchedulerFailover (141 ms) 3: [ RUN ] RateLimitingTest.CapacityReached 3: I1207 22:39:15.505867 20080 cluster.cpp:172] Creating default 'local' authorizer 3: I1207 22:39:15.510746 20103 master.cpp:454] Master dc509d0b-50f4-4f06-82bf-70b8244ddf46 (cf5e609f41a0) started on 172.17.0.2:44557 3: I1207 22:39:15.510769 20103 master.cpp:456] 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/IYlYU4/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" --rate_limits="limits { 3: qps: 1 3: principal: "test-principal" 3: capacity: 2 3: } 3: " --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/IYlYU4/master" --zk_session_timeout="10secs" 3: I1207 22:39:15.511109 20103 master.cpp:505] Master only allowing authenticated frameworks to register 3: I1207 22:39:15.511117 20103 master.cpp:511] Master only allowing authenticated agents to register 3: I1207 22:39:15.511121 20103 master.cpp:517] Master only allowing authenticated HTTP frameworks to register 3: I1207 22:39:15.511126 20103 credentials.hpp:37] Loading credentials for authentication from '/tmp/IYlYU4/credentials' 3: I1207 22:39:15.511374 20103 master.cpp:561] Using default 'crammd5' authenticator 3: I1207 22:39:15.511508 20103 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly' 3: I1207 22:39:15.511660 20103 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite' 3: I1207 22:39:15.511782 20103 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler' 3: I1207 22:39:15.511900 20103 master.cpp:640] Authorization enabled 3: I1207 22:39:15.512022 20103 master.cpp:690] Framework rate limiting enabled 3: I1207 22:39:15.512200 20093 whitelist_watcher.cpp:77] No whitelist given 3: I1207 22:39:15.512290 20101 hierarchical.cpp:175] Initialized hierarchical allocator process 3: I1207 22:39:15.516013 20082 master.cpp:2212] Elected as the leading master! 3: I1207 22:39:15.516053 20082 master.cpp:1692] Recovering from registrar 3: I1207 22:39:15.516271 20102 registrar.cpp:347] Recovering registrar 3: I1207 22:39:15.517202 20084 registrar.cpp:391] Successfully fetched the registry (0B) in 866048ns 3: I1207 22:39:15.517366 20084 registrar.cpp:495] Applied 1 operations in 54045ns; attempting to update the registry 3: I1207 22:39:15.518324 20084 registrar.cpp:552] Successfully updated the registry in 886016ns 3: I1207 22:39:15.518530 20084 registrar.cpp:424] Successfully recovered registrar 3: I1207 22:39:15.519235 20099 master.cpp:1805] Recovered 0 agents from the registry (135B); allowing 10mins for agents to re-register 3: I1207 22:39:15.519325 20096 hierarchical.cpp:213] Skipping recovery of hierarchical allocator: nothing to recover 3: W1207 22:39:15.520524 20080 process.cpp:2756] Attempted to spawn already running process [email protected]:44557 3: I1207 22:39:15.521981 20080 sched.cpp:232] Version: 1.5.0 3: I1207 22:39:15.522704 20082 sched.cpp:336] New master detected at [email protected]:44557 3: I1207 22:39:15.522886 20082 sched.cpp:396] Authenticating with master [email protected]:44557 3: I1207 22:39:15.522912 20082 sched.cpp:403] Using default CRAM-MD5 authenticatee 3: I1207 22:39:15.523314 20089 authenticatee.cpp:121] Creating new client SASL connection 3: I1207 22:39:15.523732 20085 master.cpp:8815] Authenticating [email protected]:44557 3: I1207 22:39:15.523967 20097 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(290)@172.17.0.2:44557 3: I1207 22:39:15.524346 20088 authenticator.cpp:98] Creating new server SASL connection 3: I1207 22:39:15.524657 20102 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5 3: I1207 22:39:15.524703 20102 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5' 3: I1207 22:39:15.524850 20102 authenticator.cpp:204] Received SASL authentication start 3: I1207 22:39:15.524922 20102 authenticator.cpp:326] Authentication requires more steps 3: I1207 22:39:15.525110 20087 authenticatee.cpp:259] Received SASL authentication step 3: I1207 22:39:15.525302 20086 authenticator.cpp:232] Received SASL authentication step 3: I1207 22:39:15.525348 20086 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'cf5e609f41a0' server FQDN: 'cf5e609f41a0' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 3: I1207 22:39:15.525368 20086 auxprop.cpp:181] Looking up auxiliary property '*userPassword' 3: I1207 22:39:15.525423 20086 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5' 3: I1207 22:39:15.525460 20086 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'cf5e609f41a0' server FQDN: 'cf5e609f41a0' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 3: I1207 22:39:15.525478 20086 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true 3: I1207 22:39:15.525491 20086 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true 3: I1207 22:39:15.525517 20086 authenticator.cpp:318] Authentication success 3: I1207 22:39:15.525665 20092 authenticatee.cpp:299] Authentication success 3: I1207 22:39:15.525750 20083 master.cpp:8845] Successfully authenticated principal 'test-principal' at [email protected]:44557 3: I1207 22:39:15.525887 20092 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(290)@172.17.0.2:44557 3: I1207 22:39:15.526074 20084 sched.cpp:502] Successfully authenticated with master [email protected]:44557 3: I1207 22:39:15.526096 20084 sched.cpp:824] Sending SUBSCRIBE call to [email protected]:44557 3: I1207 22:39:15.526255 20084 sched.cpp:857] Will retry registration in 301.200844ms if necessary 3: I1207 22:39:15.526706 20096 master.cpp:2960] Received SUBSCRIBE call for framework 'default' at [email protected]:44557 3: I1207 22:39:15.526793 20096 master.cpp:2277] Authorizing framework principal 'test-principal' to receive offers for roles '{ * }' 3: I1207 22:39:15.527689 20101 master.cpp:3040] Subscribing framework default with checkpointing disabled and capabilities [ MULTI_ROLE, RESERVATION_REFINEMENT ] 3: I1207 22:39:15.527987 20101 master.cpp:9036] Adding framework dc509d0b-50f4-4f06-82bf-70b8244ddf46-0000 (default) at [email protected]:44557 with roles { } suppressed 3: I1207 22:39:15.528645 20098 sched.cpp:751] Framework registered with dc509d0b-50f4-4f06-82bf-70b8244ddf46-0000 3: I1207 22:39:15.528707 20098 sched.cpp:765] Scheduler::registered took 24596ns 3: I1207 22:39:15.528795 20103 hierarchical.cpp:297] Added framework dc509d0b-50f4-4f06-82bf-70b8244ddf46-0000 3: I1207 22:39:15.529083 20103 hierarchical.cpp:1513] Performed allocation for 0 agents in 113703ns 3: I1207 22:39:15.529902 20085 master.cpp:2960] Received SUBSCRIBE call for framework 'default' at [email protected]:44557 3: I1207 22:39:15.530006 20085 master.cpp:2277] Authorizing framework principal 'test-principal' to receive offers for roles '{ * }' 3: I1207 22:39:15.530647 20095 master.cpp:3040] Subscribing framework default with checkpointing disabled and capabilities [ MULTI_ROLE, RESERVATION_REFINEMENT ] 3: I1207 22:39:15.530694 20095 master.cpp:3050] Framework dc509d0b-50f4-4f06-82bf-70b8244ddf46-0000 (default) at [email protected]:44557 already subscribed, resending acknowledgement 3: I1207 22:39:15.530998 20102 sched.cpp:738] Ignoring framework registered message because the driver is already connected! 3: I1207 22:39:15.533684 20090 process.cpp:3503] Handling HTTP event for process 'metrics' with path: '/metrics/snapshot' 3: I1207 22:39:15.535266 20083 http.cpp:851] Authorizing principal 'ANY' to GET the endpoint '/metrics/snapshot' 3: W1207 22:39:15.554039 20082 master.cpp:1654] Dropping message mesos.scheduler.Call from [email protected]:44557(test-principal): capacity(2) exceeded 3: I1207 22:39:15.554297 20082 sched.cpp:1175] Got error 'Message mesos.scheduler.Call dropped: capacity(2) exceeded' 3: I1207 22:39:15.554324 20082 sched.cpp:2043] Asked to abort the driver 3: I1207 22:39:15.554416 20082 sched.cpp:1186] Scheduler::error took 44037ns 3: I1207 22:39:15.554492 20082 sched.cpp:1221] Aborting framework dc509d0b-50f4-4f06-82bf-70b8244ddf46-0000 3: W1207 22:39:15.554832 20089 master.cpp:1654] Dropping message mesos.internal.DeactivateFrameworkMessage from [email protected]:44557(test-principal): capacity(2) exceeded 3: I1207 22:39:15.555052 20088 sched.cpp:1171] Ignoring error message because the driver is not running! 3: I1207 22:39:15.555151 20080 sched.cpp:2009] Asked to stop the driver 3: I1207 22:39:15.557940 20083 process.cpp:3503] Handling HTTP event for process 'metrics' with path: '/metrics/snapshot' 3: I1207 22:39:15.559303 20094 http.cpp:851] Authorizing principal 'ANY' to GET the endpoint '/metrics/snapshot' 3: I1207 22:39:15.588500 20095 hierarchical.cpp:1513] Performed allocation for 0 agents in 95680ns 3: I1207 22:39:15.588666 20102 master.cpp:2960] Received SUBSCRIBE call for framework 'default' at [email protected]:44557 3: I1207 22:39:15.588760 20102 master.cpp:2277] Authorizing framework principal 'test-principal' to receive offers for roles '{ * }' 3: I1207 22:39:15.589520 20091 master.cpp:3040] Subscribing framework default with checkpointing disabled and capabilities [ MULTI_ROLE, RESERVATION_REFINEMENT ] 3: I1207 22:39:15.589565 20091 master.cpp:3050] Framework dc509d0b-50f4-4f06-82bf-70b8244ddf46-0000 (default) at [email protected]:44557 already subscribed, resending acknowledgement 3: I1207 22:39:15.590394 20093 master.cpp:2960] Received SUBSCRIBE call for framework 'default' at [email protected]:44557 3: I1207 22:39:15.590478 20093 master.cpp:2277] Authorizing framework principal 'test-principal' to receive offers for roles '{ * }' 3: I1207 22:39:15.590490 20084 hierarchical.cpp:1513] Performed allocation for 0 agents in 90209ns 3: I1207 22:39:15.591094 20092 master.cpp:3040] Subscribing framework default with checkpointing disabled and capabilities [ MULTI_ROLE, RESERVATION_REFINEMENT ] 3: I1207 22:39:15.591130 20092 master.cpp:3050] Framework dc509d0b-50f4-4f06-82bf-70b8244ddf46-0000 (default) at [email protected]:44557 already subscribed, resending acknowledgement 3: I1207 22:39:15.591956 20096 hierarchical.cpp:1513] Performed allocation for 0 agents in 104824ns 3: I1207 22:39:15.591994 20103 master.cpp:1422] Framework dc509d0b-50f4-4f06-82bf-70b8244ddf46-0000 (default) at [email protected]:44557 disconnected 3: I1207 22:39:15.592038 20103 master.cpp:3330] Deactivating framework dc509d0b-50f4-4f06-82bf-70b8244ddf46-0000 (default) at [email protected]:44557 3: I1207 22:39:15.592131 20103 master.cpp:3307] Disconnecting framework dc509d0b-50f4-4f06-82bf-70b8244ddf46-0000 (default) at [email protected]:44557 3: I1207 22:39:15.592196 20103 master.cpp:1437] Giving framework dc509d0b-50f4-4f06-82bf-70b8244ddf46-0000 (default) at [email protected]:44557 10secs to failover 3: I1207 22:39:15.592303 20096 hierarchical.cpp:405] Deactivated framework dc509d0b-50f4-4f06-82bf-70b8244ddf46-0000 3: I1207 22:39:15.594734 20089 process.cpp:3503] Handling HTTP event for process 'metrics' with path: '/metrics/snapshot' 3: I1207 22:39:15.596036 20082 http.cpp:851] Authorizing principal 'ANY' to GET the endpoint '/metrics/snapshot' 3: I1207 22:39:15.624555 20080 master.cpp:1150] Master terminating 3: I1207 22:39:15.624989 20084 hierarchical.cpp:344] Removed framework dc509d0b-50f4-4f06-82bf-70b8244ddf46-0000 3: [ OK ] RateLimitingTest.CapacityReached (130 ms) 3: [----------] 6 tests from RateLimitingTest (700 ms total) 3: 3: [----------] 5 tests from ResourceOffersTest 3: [ RUN ] ResourceOffersTest.ResourceOfferWithMultipleSlaves 3: I1207 22:39:15.636157 20080 cluster.cpp:172] Creating default 'local' authorizer 3: I1207 22:39:15.640348 20102 master.cpp:454] Master c0f714a2-d098-4158-b61a-6b5f49b3d9ec (cf5e609f41a0) started on 172.17.0.2:44557 3: I1207 22:39:15.640389 20102 master.cpp:456] 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/w2qvbT/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/w2qvbT/master" --zk_session_timeout="10secs" 3: I1207 22:39:15.640813 20102 master.cpp:505] Master only allowing authenticated frameworks to register 3: I1207 22:39:15.640823 20102 master.cpp:511] Master only allowing authenticated agents to register 3: I1207 22:39:15.640830 20102 master.cpp:517] Master only allowing authenticated HTTP frameworks to register 3: I1207 22:39:15.640836 20102 credentials.hpp:37] Loading credentials for authentication from '/tmp/w2qvbT/credentials' 3: I1207 22:39:15.641304 20102 master.cpp:561] Using default 'crammd5' authenticator 3: I1207 22:39:15.641499 20102 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly' 3: I1207 22:39:15.641715 20102 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite' 3: I1207 22:39:15.641896 20102 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler' 3: I1207 22:39:15.642048 20102 master.cpp:640] Authorization enabled 3: I1207 22:39:15.642240 20103 hierarchical.cpp:175] Initialized hierarchical allocator process 3: I1207 22:39:15.642300 20083 whitelist_watcher.cpp:77] No whitelist given 3: I1207 22:39:15.646037 20100 master.cpp:2212] Elected as the leading master! 3: I1207 22:39:15.646075 20100 master.cpp:1692] Recovering from registrar 3: I1207 22:39:15.646325 20094 registrar.cpp:347] Recovering registrar 3: I1207 22:39:15.647161 20085 registrar.cpp:391] Successfully fetched the registry (0B) in 784896ns 3: I1207 22:39:15.647358 20085 registrar.cpp:495] Applied 1 operations in 56837ns; attempting to update the registry 3: I1207 22:39:15.648280 20085 registrar.cpp:552] Successfully updated the registry in 848128ns 3: I1207 22:39:15.648494 20085 registrar.cpp:424] Successfully recovered registrar 3: I1207 22:39:15.649214 20091 master.cpp:1805] Recovered 0 agents from the registry (135B); allowing 10mins for agents to re-register 3: I1207 22:39:15.649261 20089 hierarchical.cpp:213] Skipping recovery of hierarchical allocator: nothing to recover 3: W1207 22:39:15.658169 20080 process.cpp:2756] Attempted to spawn already running process [email protected]:44557 3: I1207 22:39:15.659632 20080 containerizer.cpp:304] Using isolation { environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni } 3: W1207 22:39:15.660534 20080 backend.cpp:76] Failed to create 'aufs' backend: AufsBackend requires root privileges 3: W1207 22:39:15.660717 20080 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires root privileges 3: I1207 22:39:15.660764 20080 provisioner.cpp:299] Using default backend 'copy' 3: I1207 22:39:15.664285 20080 cluster.cpp:460] Creating default 'local' authorizer 3: I1207 22:39:15.667716 20091 slave.cpp:258] Mesos agent started on (128)@172.17.0.2:44557 3: I1207 22:39:15.667745 20091 slave.cpp:259] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://"; --appc_store_dir="/tmp/ResourceOffersTest_ResourceOfferWithMultipleSlaves_hQZJOv/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/ResourceOffersTest_ResourceOfferWithMultipleSlaves_hQZJOv/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/ResourceOffersTest_ResourceOfferWithMultipleSlaves_hQZJOv/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/ResourceOffersTest_ResourceOfferWithMultipleSlaves_hQZJOv/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/ResourceOffersTest_ResourceOfferWithMultipleSlaves_hQZJOv/http_credentials" --http_heartbeat_interval="30secs" --initialize_driver_logging="true" --isolation="posix/cpu,posix/mem" --jwt_secret_key="/tmp/ResourceOffersTest_ResourceOfferWithMultipleSlaves_hQZJOv/jwt_secret_key" --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;mem:1024" --revocable_cpu_low_priority="true" --runtime_dir="/tmp/ResourceOffersTest_ResourceOfferWithMultipleSlaves_hQZJOv" --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/ResourceOffersTest_ResourceOfferWithMultipleSlaves_k1M6uH" --zk_session_timeout="10secs" 3: I1207 22:39:15.668259 20091 credentials.hpp:86] Loading credential for authentication from '/tmp/ResourceOffersTest_ResourceOfferWithMultipleSlaves_hQZJOv/credential' 3: I1207 22:39:15.668476 20091 slave.cpp:291] Agent using credential for: test-principal 3: I1207 22:39:15.668500 20091 credentials.hpp:37] Loading credentials for authentication from '/tmp/ResourceOffersTest_ResourceOfferWithMultipleSlaves_hQZJOv/http_credentials' 3: I1207 22:39:15.668838 20091 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-executor' 3: I1207 22:39:15.668994 20091 http.cpp:1066] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-executor' 3: I1207 22:39:15.669431 20091 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly' 3: I1207 22:39:15.669703 20091 http.cpp:1066] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readonly' 3: I1207 22:39:15.670066 20091 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readwrite' 3: I1207 22:39:15.670255 20091 http.cpp:1066] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readwrite' 3: I1207 22:39:15.672240 20091 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":367489.0},"type":"SCALAR"},{"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}] 3: I1207 22:39:15.672652 20091 slave.cpp:598] Agent attributes: [ ] 3: I1207 22:39:15.672668 20091 slave.cpp:607] Agent hostname: cf5e609f41a0 3: I1207 22:39:15.672950 20101 task_status_update_manager.cpp:181] Pausing sending task status updates 3: W1207 22:39:15.674028 20080 process.cpp:2756] Attempted to spawn already running process [email protected]:44557 3: I1207 22:39:15.675200 20080 containerizer.cpp:304] Using isolation { environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni } 3: I1207 22:39:15.675704 20083 state.cpp:66] Recovering state from '/tmp/ResourceOffersTest_ResourceOfferWithMultipleSlaves_k1M6uH/meta' 3: W1207 22:39:15.675842 20080 backend.cpp:76] Failed to create 'aufs' backend: AufsBackend requires root privileges 3: W1207 22:39:15.675981 20080 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires root privileges 3: I1207 22:39:15.676015 20080 provisioner.cpp:299] Using default backend 'copy' 3: I1207 22:39:15.676220 20083 task_status_update_manager.cpp:207] Recovering task status update manager 3: I1207 22:39:15.676592 20100 containerizer.cpp:674] Recovering containerizer 3: I1207 22:39:15.678656 20080 cluster.cpp:460] Creating default 'local' authorizer 3: I1207 22:39:15.679515 20083 provisioner.cpp:495] Provisioner recovery complete 3: I1207 22:39:15.680058 20098 slave.cpp:6679] Finished recovery 3: I1207 22:39:15.681175 20088 slave.cpp:1031] New master detected at [email protected]:44557 3: I1207 22:39:15.681175 20084 task_status_update_manager.cpp:181] Pausing sending task status updates 3: I1207 22:39:15.681298 20088 slave.cpp:1086] Detecting new master 3: I1207 22:39:15.681732 20090 slave.cpp:258] Mesos agent started on (129)@172.17.0.2:44557 3: I1207 22:39:15.681756 20090 slave.cpp:259] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://"; --appc_store_dir="/tmp/ResourceOffersTest_ResourceOfferWithMultipleSlaves_wZDPq7/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/ResourceOffersTest_ResourceOfferWithMultipleSlaves_wZDPq7/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/ResourceOffersTest_ResourceOfferWithMultipleSlaves_wZDPq7/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/ResourceOffersTest_ResourceOfferWithMultipleSlaves_wZDPq7/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/ResourceOffersTest_ResourceOfferWithMultipleSlaves_wZDPq7/http_credentials" --http_heartbeat_interval="30secs" --initialize_driver_logging="true" --isolation="posix/cpu,posix/mem" --jwt_secret_key="/tmp/ResourceOffersTest_ResourceOfferWithMultipleSlaves_wZDPq7/jwt_secret_key" --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;mem:1024" --revocable_cpu_low_priority="true" --runtime_dir="/tmp/ResourceOffersTest_ResourceOfferWithMultipleSlaves_wZDPq7" --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/ResourceOffersTest_ResourceOfferWithMultipleSlaves_YvnRak" --zk_session_timeout="10secs" 3: I1207 22:39:15.682299 20090 credentials.hpp:86] Loading credential for authentication from '/tmp/ResourceOffersTest_ResourceOfferWithMultipleSlaves_wZDPq7/credential' 3: I1207 22:39:15.682603 20090 slave.cpp:291] Agent using credential for: test-principal 3: I1207 22:39:15.682636 20090 credentials.hpp:37] Loading credentials for authentication from '/tmp/ResourceOffersTest_ResourceOfferWithMultipleSlaves_wZDPq7/http_credentials' 3: I1207 22:39:15.683145 20090 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-executor' 3: I1207 22:39:15.683339 20090 http.cpp:1066] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-executor' 3: I1207 22:39:15.683655 20090 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly' 3: I1207 22:39:15.683805 20090 http.cpp:1066] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readonly' 3: I1207 22:39:15.684150 20090 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readwrite' 3: I1207 22:39:15.684305 20090 http.cpp:1066] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readwrite' 3: I1207 22:39:15.685560 20082 slave.cpp:1113] Authenticating with master [email protected]:44557 3: I1207 22:39:15.685660 20082 slave.cpp:1122] Using default CRAM-MD5 authenticatee 3: I1207 22:39:15.685989 20094 authenticatee.cpp:121] Creating new client SASL connection 3: I1207 22:39:15.685989 20090 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":367489.0},"type":"SCALAR"},{"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}] 3: I1207 22:39:15.686311 20090 slave.cpp:598] Agent attributes: [ ] 3: I1207 22:39:15.686323 20090 slave.cpp:607] Agent hostname: cf5e609f41a0 3: I1207 22:39:15.686391 20091 master.cpp:8815] Authenticating slave(128)@172.17.0.2:44557 3: I1207 22:39:15.686506 20083 task_status_update_manager.cpp:181] Pausing sending task status updates 3: I1207 22:39:15.686563 20104 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(291)@172.17.0.2:44557 3: I1207 22:39:15.686959 20093 authenticator.cpp:98] Creating new server SASL connection 3: I1207 22:39:15.687379 20084 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5 3: I1207 22:39:15.687414 20084 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5' 3: I1207 22:39:15.687593 20098 authenticator.cpp:204] Received SASL authentication start 3: I1207 22:39:15.687672 20098 authenticator.cpp:326] Authentication requires more steps 3: W1207 22:39:15.687741 20080 process.cpp:2756] Attempted to spawn already running process [email protected]:44557 3: I1207 22:39:15.687804 20098 authenticatee.cpp:259] Received SASL authentication step 3: I1207 22:39:15.687973 20098 authenticator.cpp:232] Received SASL authentication step 3: I1207 22:39:15.688006 20098 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'cf5e609f41a0' server FQDN: 'cf5e609f41a0' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 3: I1207 22:39:15.688021 20098 auxprop.cpp:181] Looking up auxiliary property '*userPassword' 3: I1207 22:39:15.688064 20098 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5' 3: I1207 22:39:15.688087 20098 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'cf5e609f41a0' server FQDN: 'cf5e609f41a0' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 3: I1207 22:39:15.688099 20098 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true 3: I1207 22:39:15.688107 20098 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true 3: I1207 22:39:15.688120 20098 authenticator.cpp:318] Authentication success 3: I1207 22:39:15.688232 20089 authenticatee.cpp:299] Authentication success 3: I1207 22:39:15.688446 20092 state.cpp:66] Recovering state from '/tmp/ResourceOffersTest_ResourceOfferWithMultipleSlaves_YvnRak/meta' 3: I1207 22:39:15.688472 20101 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(291)@172.17.0.2:44557 3: I1207 22:39:15.688520 20102 master.cpp:8845] Successfully authenticated principal 'test-principal' at slave(128)@172.17.0.2:44557 3: I1207 22:39:15.688715 20100 slave.cpp:1205] Successfully authenticated with master [email protected]:44557 3: I1207 22:39:15.688954 20080 containerizer.cpp:304] Using isolation { environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni } 3: I1207 22:39:15.688994 20082 task_status_update_manager.cpp:207] Recovering task status update manager 3: I1207 22:39:15.689033 20100 slave.cpp:1748] Will retry registration in 15.506904ms if necessary 3: I1207 22:39:15.689316 20091 containerizer.cpp:674] Recovering containerizer 3: I1207 22:39:15.689348 20094 master.cpp:6082] Received register agent message from slave(128)@172.17.0.2:44557 (cf5e609f41a0) 3: I1207 22:39:15.689534 20094 master.cpp:3869] Authorizing agent with principal 'test-principal' 3: W1207 22:39:15.689587 20080 backend.cpp:76] Failed to create 'aufs' backend: AufsBackend requires root privileges 3: W1207 22:39:15.689700 20080 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires root privileges 3: I1207 22:39:15.689733 20080 provisioner.cpp:299] Using default backend 'copy' 3: I1207 22:39:15.690266 20090 master.cpp:6158] Authorized registration of agent at slave(128)@172.17.0.2:44557 (cf5e609f41a0) 3: I1207 22:39:15.690415 20090 master.cpp:6251] Registering agent at slave(128)@172.17.0.2:44557 (cf5e609f41a0) with id c0f714a2-d098-4158-b61a-6b5f49b3d9ec-S0 3: I1207 22:39:15.691057 20101 registrar.cpp:495] Applied 1 operations in 108287ns; attempting to update the registry 3: I1207 22:39:15.691274 20083 provisioner.cpp:495] Provisioner recovery complete 3: I1207 22:39:15.691669 20101 slave.cpp:6679] Finished recovery 3: I1207 22:39:15.691807 20083 registrar.cpp:552] Successfully updated the registry in 683008ns 3: I1207 22:39:15.692095 20098 master.cpp:6300] Admitted agent c0f714a2-d098-4158-b61a-6b5f49b3d9ec-S0 at slave(128)@172.17.0.2:44557 (cf5e609f41a0) 3: I1207 22:39:15.692176 20080 cluster.cpp:460] Creating default 'local' authorizer 3: I1207 22:39:15.692739 20082 task_status_update_manager.cpp:181] Pausing sending task status updates 3: I1207 22:39:15.692723 20096 slave.cpp:1031] New master detected at [email protected]:44557 3: I1207 22:39:15.692906 20096 slave.cpp:1086] Detecting new master 3: I1207 22:39:15.693219 20098 master.cpp:6336] Registered agent c0f714a2-d098-4158-b61a-6b5f49b3d9ec-S0 at slave(128)@172.17.0.2:44557 (cf5e609f41a0) with cpus:2; mem:1024; disk:367489; ports:[31000-32000] 3: I1207 22:39:15.693296 20085 slave.cpp:1251] Registered with master [email protected]:44557; given agent ID c0f714a2-d098-4158-b61a-6b5f49b3d9ec-S0 3: I1207 22:39:15.693420 20086 task_status_update_manager.cpp:188] Resuming sending task status updates 3: I1207 22:39:15.693586 20094 hierarchical.cpp:572] Added agent c0f714a2-d098-4158-b61a-6b5f49b3d9ec-S0 (cf5e609f41a0) with cpus:2; mem:1024; disk:367489; ports:[31000-32000] (allocated: {}) 3: I1207 22:39:15.693673 20085 slave.cpp:1271] Checkpointing SlaveInfo to '/tmp/ResourceOffersTest_ResourceOfferWithMultipleSlaves_k1M6uH/meta/slaves/c0f714a2-d098-4158-b61a-6b5f49b3d9ec-S0/slave.info' 3: I1207 22:39:15.693971 20094 hierarchical.cpp:1513] Performed allocation for 1 agents in 173270ns 3: I1207 22:39:15.694167 20085 slave.cpp:1350] Forwarding total oversubscribed resources {} 3: I1207 22:39:15.694417 20083 master.cpp:7230] Received update of agent c0f714a2-d098-4158-b61a-6b5f49b3d9ec-S0 at slave(128)@172.17.0.2:44557 (cf5e609f41a0) with total oversubscribed resources {} 3: I1207 22:39:15.694635 20083 master.cpp:7273] Ignoring update on agent c0f714a2-d098-4158-b61a-6b5f49b3d9ec-S0 at slave(128)@172.17.0.2:44557 (cf5e609f41a0) as it reports no changes 3: I1207 22:39:15.695204 20101 slave.cpp:258] Mesos agent started on (130)@172.17.0.2:44557 write /dev/stdout: resource temporarily unavailable + docker rmi mesos-1512684015-8416 Error response from daemon: conflict: unable to remove repository reference "mesos-1512684015-8416" (must force) - container cf5e609f41a0 is using its referenced image 0e902f74fed4 Build step 'Execute shell' marked build as failure Not sending mail to unregistered user [email protected]
