You are viewing a plain text version of this content. The canonical link for it is here.
Posted to builds@mesos.apache.org by Apache Jenkins Server <je...@builds.apache.org> on 2017/11/16 21:01:38 UTC
Build failed in Jenkins: Mesos-Buildbot » cmake,clang,--verbose --disable-libtool-wrappers --enable-libevent --enable-ssl,GLOG_v=1 MESOS_VERBOSE=1,ubuntu:14.04,(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)&&(!qnode3)&&(!H23) #4468
See <https://builds.apache.org/job/Mesos-Buildbot/BUILDTOOL=cmake,COMPILER=clang,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)/4468/display/redirect?page=changes>
Changes:
[Kapil Arya] Removed WIP from 1.4.1 changelog.
[Kapil Arya] Update website for 1.4.1 relsease.
------------------------------------------
[...truncated 25.46 MB...]
3: I1116 21:01:33.158370 18306 containerizer.cpp:2818] Transitioning the state of container 30af0834-22c2-4a55-bbc4-fe0783f4642e.a9057b21-3e4f-4683-8d68-3520fa4a65c2.e0a0b495-42d3-4ce4-9d3f-c54b7d1e8071 from FETCHING to RUNNING
3: I1116 21:01:33.164489 18311 process.cpp:3925] Handling HTTP event for process 'slave(667)' with path: '/slave(667)/api/v1'
3: I1116 21:01:33.165262 18298 process.cpp:3925] Handling HTTP event for process 'slave(667)' with path: '/slave(667)/api/v1'
3: I1116 21:01:33.166113 18305 process.cpp:3925] Handling HTTP event for process 'slave(667)' with path: '/slave(667)/api/v1'
3: I1116 21:01:33.167974 18310 http.cpp:1185] HTTP POST for /slave(667)/api/v1 from 172.17.0.4:56302
3: I1116 21:01:33.168373 18310 http.cpp:1185] HTTP POST for /slave(667)/api/v1 from 172.17.0.4:56304
3: I1116 21:01:33.168671 18310 http.cpp:1185] HTTP POST for /slave(667)/api/v1 from 172.17.0.4:56306
3: I1116 21:01:33.169168 18310 http.cpp:2617] Processing WAIT_CONTAINER call for container '30af0834-22c2-4a55-bbc4-fe0783f4642e.a9057b21-3e4f-4683-8d68-3520fa4a65c2'
3: I1116 21:01:33.169559 18310 http.cpp:2617] Processing WAIT_CONTAINER call for container '30af0834-22c2-4a55-bbc4-fe0783f4642e.a9057b21-3e4f-4683-8d68-3520fa4a65c2.e0a0b495-42d3-4ce4-9d3f-c54b7d1e8071'
3: I1116 21:01:33.169852 18310 http.cpp:2781] Processing KILL_CONTAINER call for container '30af0834-22c2-4a55-bbc4-fe0783f4642e.a9057b21-3e4f-4683-8d68-3520fa4a65c2.e0a0b495-42d3-4ce4-9d3f-c54b7d1e8071'
3: I1116 21:01:33.206629 18297 containerizer.cpp:2705] Container 30af0834-22c2-4a55-bbc4-fe0783f4642e.a9057b21-3e4f-4683-8d68-3520fa4a65c2.e0a0b495-42d3-4ce4-9d3f-c54b7d1e8071 has exited
3: I1116 21:01:33.206686 18297 containerizer.cpp:2254] Destroying container 30af0834-22c2-4a55-bbc4-fe0783f4642e.a9057b21-3e4f-4683-8d68-3520fa4a65c2.e0a0b495-42d3-4ce4-9d3f-c54b7d1e8071 in RUNNING state
3: I1116 21:01:33.206701 18297 containerizer.cpp:2818] Transitioning the state of container 30af0834-22c2-4a55-bbc4-fe0783f4642e.a9057b21-3e4f-4683-8d68-3520fa4a65c2.e0a0b495-42d3-4ce4-9d3f-c54b7d1e8071 from RUNNING to DESTROYING
3: I1116 21:01:33.207015 18297 launcher.cpp:156] Asked to destroy container 30af0834-22c2-4a55-bbc4-fe0783f4642e.a9057b21-3e4f-4683-8d68-3520fa4a65c2.e0a0b495-42d3-4ce4-9d3f-c54b7d1e8071
3: I1116 21:01:33.210564 18309 provisioner.cpp:490] Ignoring destroy request for unknown container 30af0834-22c2-4a55-bbc4-fe0783f4642e.a9057b21-3e4f-4683-8d68-3520fa4a65c2.e0a0b495-42d3-4ce4-9d3f-c54b7d1e8071
3: I1116 21:01:33.210813 18296 containerizer.cpp:2543] Checkpointing termination state to nested container's runtime directory '/tmp/ParentChildContainerTypeAndContentType_AgentContainerAPITest_TwoLevelNestedContainerLaunch_6_k5G5kP/containers/30af0834-22c2-4a55-bbc4-fe0783f4642e/containers/a9057b21-3e4f-4683-8d68-3520fa4a65c2/containers/e0a0b495-42d3-4ce4-9d3f-c54b7d1e8071/termination'
3: I1116 21:01:33.216012 18304 process.cpp:3925] Handling HTTP event for process 'slave(667)' with path: '/slave(667)/api/v1'
3: I1116 21:01:33.217830 18298 http.cpp:1185] HTTP POST for /slave(667)/api/v1 from 172.17.0.4:56308
3: I1116 21:01:33.218489 18298 http.cpp:2781] Processing KILL_CONTAINER call for container '30af0834-22c2-4a55-bbc4-fe0783f4642e.a9057b21-3e4f-4683-8d68-3520fa4a65c2'
3: I1116 21:01:33.307938 18304 containerizer.cpp:2705] Container 30af0834-22c2-4a55-bbc4-fe0783f4642e.a9057b21-3e4f-4683-8d68-3520fa4a65c2 has exited
3: I1116 21:01:33.308007 18304 containerizer.cpp:2254] Destroying container 30af0834-22c2-4a55-bbc4-fe0783f4642e.a9057b21-3e4f-4683-8d68-3520fa4a65c2 in RUNNING state
3: I1116 21:01:33.308030 18304 containerizer.cpp:2818] Transitioning the state of container 30af0834-22c2-4a55-bbc4-fe0783f4642e.a9057b21-3e4f-4683-8d68-3520fa4a65c2 from RUNNING to DESTROYING
3: I1116 21:01:33.308322 18304 launcher.cpp:156] Asked to destroy container 30af0834-22c2-4a55-bbc4-fe0783f4642e.a9057b21-3e4f-4683-8d68-3520fa4a65c2
3: I1116 21:01:33.313282 18314 provisioner.cpp:490] Ignoring destroy request for unknown container 30af0834-22c2-4a55-bbc4-fe0783f4642e.a9057b21-3e4f-4683-8d68-3520fa4a65c2
3: I1116 21:01:33.313442 18314 containerizer.cpp:2543] Checkpointing termination state to nested container's runtime directory '/tmp/ParentChildContainerTypeAndContentType_AgentContainerAPITest_TwoLevelNestedContainerLaunch_6_k5G5kP/containers/30af0834-22c2-4a55-bbc4-fe0783f4642e/containers/a9057b21-3e4f-4683-8d68-3520fa4a65c2/termination'
3: I1116 21:01:33.317034 18308 containerizer.cpp:2254] Destroying container 30af0834-22c2-4a55-bbc4-fe0783f4642e in RUNNING state
3: I1116 21:01:33.317059 18308 containerizer.cpp:2818] Transitioning the state of container 30af0834-22c2-4a55-bbc4-fe0783f4642e from RUNNING to DESTROYING
3: I1116 21:01:33.317229 18308 launcher.cpp:156] Asked to destroy container 30af0834-22c2-4a55-bbc4-fe0783f4642e
3: I1116 21:01:33.334429 18313 slave.cpp:5130] Got exited event for executor(1)@172.17.0.4:40721
3: I1116 21:01:33.411957 18293 containerizer.cpp:2705] Container 30af0834-22c2-4a55-bbc4-fe0783f4642e has exited
3: I1116 21:01:33.415360 18298 provisioner.cpp:490] Ignoring destroy request for unknown container 30af0834-22c2-4a55-bbc4-fe0783f4642e
3: I1116 21:01:33.417297 18303 slave.cpp:5539] Executor 'affb31ef-fdbd-4656-a42e-160658a90402' of framework f95b612b-5ff4-41f0-8009-9d693a660f85-0000 terminated with signal Killed
3: I1116 21:01:33.417592 18303 slave.cpp:4517] Handling status update TASK_FAILED (UUID: d7bad3c0-7aad-44e6-b0b9-ffd65a536fe3) for task affb31ef-fdbd-4656-a42e-160658a90402 of framework f95b612b-5ff4-41f0-8009-9d693a660f85-0000 from @0.0.0.0:0
3: W1116 21:01:33.418994 18308 containerizer.cpp:2063] Ignoring update for unknown container 30af0834-22c2-4a55-bbc4-fe0783f4642e
3: I1116 21:01:33.419035 18310 slave.cpp:883] Agent terminating
3: I1116 21:01:33.419507 18292 master.cpp:1309] Agent f95b612b-5ff4-41f0-8009-9d693a660f85-S0 at slave(667)@172.17.0.4:41828 (dbd9964db352) disconnected
3: I1116 21:01:33.419569 18292 master.cpp:3368] Disconnecting agent f95b612b-5ff4-41f0-8009-9d693a660f85-S0 at slave(667)@172.17.0.4:41828 (dbd9964db352)
3: I1116 21:01:33.419689 18292 master.cpp:3387] Deactivating agent f95b612b-5ff4-41f0-8009-9d693a660f85-S0 at slave(667)@172.17.0.4:41828 (dbd9964db352)
3: I1116 21:01:33.419920 18311 hierarchical.cpp:690] Agent f95b612b-5ff4-41f0-8009-9d693a660f85-S0 deactivated
3: I1116 21:01:33.430433 18290 master.cpp:1151] Master terminating
3: W1116 21:01:33.430639 18290 master.cpp:9582] Removing task affb31ef-fdbd-4656-a42e-160658a90402 with resources [{"allocation_info":{"role":"*"},"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"disk","scalar":{"value":1024.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}] of framework f95b612b-5ff4-41f0-8009-9d693a660f85-0000 on agent f95b612b-5ff4-41f0-8009-9d693a660f85-S0 at slave(667)@172.17.0.4:41828 (dbd9964db352) in non-removable state TASK_RUNNING
3: I1116 21:01:33.431741 18295 hierarchical.cpp:626] Removed agent f95b612b-5ff4-41f0-8009-9d693a660f85-S0
3: I1116 21:01:33.433791 18295 hierarchical.cpp:355] Removed framework f95b612b-5ff4-41f0-8009-9d693a660f85-0000
3: I1116 21:01:33.438745 18290 sched.cpp:2009] Asked to stop the driver
3: I1116 21:01:33.438987 18298 sched.cpp:1191] Stopping framework f95b612b-5ff4-41f0-8009-9d693a660f85-0000
3: [ OK ] ParentChildContainerTypeAndContentType/AgentContainerAPITest.TwoLevelNestedContainerLaunch/6 (718 ms)
3: [ RUN ] ParentChildContainerTypeAndContentType/AgentContainerAPITest.TwoLevelNestedContainerLaunch/8
3: I1116 21:01:33.448720 18290 cluster.cpp:162] Creating default 'local' authorizer
3: I1116 21:01:33.452847 18305 master.cpp:448] Master 6d2c86f1-9276-4e52-adb7-96d3ea164ced (dbd9964db352) started on 172.17.0.4:41828
3: I1116 21:01:33.452898 18305 master.cpp:450] 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/pD1QqV/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/pD1QqV/master" --zk_session_timeout="10secs"
3: I1116 21:01:33.453421 18305 master.cpp:499] Master only allowing authenticated frameworks to register
3: I1116 21:01:33.453433 18305 master.cpp:505] Master only allowing authenticated agents to register
3: I1116 21:01:33.453440 18305 master.cpp:511] Master only allowing authenticated HTTP frameworks to register
3: I1116 21:01:33.453449 18305 credentials.hpp:37] Loading credentials for authentication from '/tmp/pD1QqV/credentials'
3: I1116 21:01:33.453979 18305 master.cpp:555] Using default 'crammd5' authenticator
3: I1116 21:01:33.454241 18305 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly'
3: I1116 21:01:33.454533 18305 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite'
3: I1116 21:01:33.454761 18305 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler'
3: I1116 21:01:33.455019 18305 master.cpp:634] Authorization enabled
3: I1116 21:01:33.455324 18310 hierarchical.cpp:171] Initialized hierarchical allocator process
3: I1116 21:01:33.455360 18309 whitelist_watcher.cpp:77] No whitelist given
3: I1116 21:01:33.459506 18296 master.cpp:2213] Elected as the leading master!
3: I1116 21:01:33.459547 18296 master.cpp:1693] Recovering from registrar
3: I1116 21:01:33.459764 18311 registrar.cpp:347] Recovering registrar
3: I1116 21:01:33.460511 18311 registrar.cpp:391] Successfully fetched the registry (0B) in 697088ns
3: I1116 21:01:33.460662 18311 registrar.cpp:495] Applied 1 operations in 54722ns; attempting to update the registry
3: I1116 21:01:33.461335 18311 registrar.cpp:552] Successfully updated the registry in 599040ns
3: I1116 21:01:33.461480 18311 registrar.cpp:424] Successfully recovered registrar
3: I1116 21:01:33.461964 18304 master.cpp:1806] Recovered 0 agents from the registry (129B); allowing 10mins for agents to re-register
3: I1116 21:01:33.462034 18314 hierarchical.cpp:209] Skipping recovery of hierarchical allocator: nothing to recover
3: W1116 21:01:33.468334 18290 process.cpp:3178] Attempted to spawn already running process files@172.17.0.4:41828
3: I1116 21:01:33.469480 18290 containerizer.cpp:301] Using isolation { environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni }
3: W1116 21:01:33.470157 18290 backend.cpp:76] Failed to create 'aufs' backend: AufsBackend requires root privileges
3: W1116 21:01:33.470309 18290 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires root privileges
3: I1116 21:01:33.470350 18290 provisioner.cpp:255] Using default backend 'copy'
3: I1116 21:01:33.472775 18290 cluster.cpp:448] Creating default 'local' authorizer
3: I1116 21:01:33.475280 18309 slave.cpp:262] Mesos agent started on (668)@172.17.0.4:41828
3: I1116 21:01:33.475316 18309 slave.cpp:263] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/ParentChildContainerTypeAndContentType_AgentContainerAPITest_TwoLevelNestedContainerLaunch_8_H5oQEr/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/ParentChildContainerTypeAndContentType_AgentContainerAPITest_TwoLevelNestedContainerLaunch_8_H5oQEr/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/ParentChildContainerTypeAndContentType_AgentContainerAPITest_TwoLevelNestedContainerLaunch_8_H5oQEr/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_secret_key="/tmp/ParentChildContainerTypeAndContentType_AgentContainerAPITest_TwoLevelNestedContainerLaunch_8_H5oQEr/executor_secret_key" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/ParentChildContainerTypeAndContentType_AgentContainerAPITest_TwoLevelNestedContainerLaunch_8_H5oQEr/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/ParentChildContainerTypeAndContentType_AgentContainerAPITest_TwoLevelNestedContainerLaunch_8_H5oQEr/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/ParentChildContainerTypeAndContentType_AgentContainerAPITest_TwoLevelNestedContainerLaunch_8_H5oQEr" --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/ParentChildContainerTypeAndContentType_AgentContainerAPITest_TwoLevelNestedContainerLaunch_8_dd3Pxb" --zk_session_timeout="10secs"
3: I1116 21:01:33.475759 18309 credentials.hpp:86] Loading credential for authentication from '/tmp/ParentChildContainerTypeAndContentType_AgentContainerAPITest_TwoLevelNestedContainerLaunch_8_H5oQEr/credential'
3: I1116 21:01:33.475926 18309 slave.cpp:295] Agent using credential for: test-principal
3: I1116 21:01:33.475945 18309 credentials.hpp:37] Loading credentials for authentication from '/tmp/ParentChildContainerTypeAndContentType_AgentContainerAPITest_TwoLevelNestedContainerLaunch_8_H5oQEr/http_credentials'
3: I1116 21:01:33.476260 18309 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-executor'
3: I1116 21:01:33.476439 18309 http.cpp:1066] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-executor'
3: I1116 21:01:33.476734 18309 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
3: I1116 21:01:33.476881 18309 http.cpp:1066] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readonly'
3: I1116 21:01:33.477152 18309 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readwrite'
3: I1116 21:01:33.477247 18309 http.cpp:1066] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readwrite'
3: I1116 21:01:33.479627 18309 slave.cpp:593] 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: I1116 21:01:33.480006 18309 slave.cpp:601] Agent attributes: [ ]
3: I1116 21:01:33.480024 18309 slave.cpp:610] Agent hostname: dbd9964db352
3: I1116 21:01:33.480278 18298 status_update_manager.cpp:177] Pausing sending status updates
3: I1116 21:01:33.482396 18297 state.cpp:64] Recovering state from '/tmp/ParentChildContainerTypeAndContentType_AgentContainerAPITest_TwoLevelNestedContainerLaunch_8_dd3Pxb/meta'
3: I1116 21:01:33.482882 18292 status_update_manager.cpp:203] Recovering status update manager
3: I1116 21:01:33.483285 18305 containerizer.cpp:662] Recovering containerizer
3: I1116 21:01:33.485337 18303 provisioner.cpp:416] Provisioner recovery complete
3: I1116 21:01:33.485718 18298 slave.cpp:6441] Finished recovery
3: I1116 21:01:33.486793 18314 status_update_manager.cpp:177] Pausing sending status updates
3: I1116 21:01:33.486790 18298 slave.cpp:1007] New master detected at master@172.17.0.4:41828
3: I1116 21:01:33.486949 18298 slave.cpp:1042] Detecting new master
3: I1116 21:01:33.491264 18297 slave.cpp:1069] Authenticating with master master@172.17.0.4:41828
3: I1116 21:01:33.491367 18297 slave.cpp:1078] Using default CRAM-MD5 authenticatee
3: I1116 21:01:33.491760 18310 authenticatee.cpp:121] Creating new client SASL connection
3: I1116 21:01:33.492378 18300 master.cpp:8285] Authenticating slave(668)@172.17.0.4:41828
3: I1116 21:01:33.492569 18292 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(1299)@172.17.0.4:41828
3: I1116 21:01:33.493005 18308 authenticator.cpp:98] Creating new server SASL connection
3: I1116 21:01:33.493386 18313 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
3: I1116 21:01:33.493439 18313 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
3: I1116 21:01:33.493624 18313 authenticator.cpp:204] Received SASL authentication start
3: I1116 21:01:33.493721 18313 authenticator.cpp:326] Authentication requires more steps
3: I1116 21:01:33.493914 18313 authenticatee.cpp:259] Received SASL authentication step
3: I1116 21:01:33.494161 18293 authenticator.cpp:232] Received SASL authentication step
3: I1116 21:01:33.494217 18293 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'dbd9964db352' server FQDN: 'dbd9964db352' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
3: I1116 21:01:33.494237 18293 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
3: I1116 21:01:33.494292 18293 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
3: I1116 21:01:33.494319 18293 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'dbd9964db352' server FQDN: 'dbd9964db352' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
3: I1116 21:01:33.494330 18293 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
3: I1116 21:01:33.494338 18293 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
3: I1116 21:01:33.494359 18293 authenticator.cpp:318] Authentication success
3: I1116 21:01:33.494534 18296 authenticatee.cpp:299] Authentication success
3: I1116 21:01:33.494653 18305 master.cpp:8315] Successfully authenticated principal 'test-principal' at slave(668)@172.17.0.4:41828
3: I1116 21:01:33.494704 18293 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(1299)@172.17.0.4:41828
3: I1116 21:01:33.495097 18299 slave.cpp:1161] Successfully authenticated with master master@172.17.0.4:41828
3: I1116 21:01:33.495515 18299 slave.cpp:1682] Will retry registration in 198028ns if necessary
3: I1116 21:01:33.495810 18303 master.cpp:6032] Received register agent message from slave(668)@172.17.0.4:41828 (dbd9964db352)
3: I1116 21:01:33.495864 18303 master.cpp:3870] Authorizing agent with principal 'test-principal'
3: I1116 21:01:33.496340 18311 master.cpp:6092] Authorized registration of agent at slave(668)@172.17.0.4:41828 (dbd9964db352)
3: I1116 21:01:33.496526 18311 master.cpp:6185] Registering agent at slave(668)@172.17.0.4:41828 (dbd9964db352) with id 6d2c86f1-9276-4e52-adb7-96d3ea164ced-S0
3: I1116 21:01:33.496973 18291 registrar.cpp:495] Applied 1 operations in 94086ns; attempting to update the registry
3: I1116 21:01:33.497583 18291 registrar.cpp:552] Successfully updated the registry in 534016ns
3: I1116 21:01:33.497896 18297 master.cpp:6232] Admitted agent 6d2c86f1-9276-4e52-adb7-96d3ea164ced-S0 at slave(668)@172.17.0.4:41828 (dbd9964db352)
3: I1116 21:01:33.498786 18297 master.cpp:6263] Registered agent 6d2c86f1-9276-4e52-adb7-96d3ea164ced-S0 at slave(668)@172.17.0.4:41828 (dbd9964db352) with [{"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: I1116 21:01:33.499269 18300 slave.cpp:1207] Registered with master master@172.17.0.4:41828; given agent ID 6d2c86f1-9276-4e52-adb7-96d3ea164ced-S0
3: I1116 21:01:33.499294 18310 hierarchical.cpp:593] Added agent 6d2c86f1-9276-4e52-adb7-96d3ea164ced-S0 (dbd9964db352) with cpus:2; mem:1024; disk:1024; ports:[31000-32000] (allocated: {})
3: I1116 21:01:33.499500 18313 status_update_manager.cpp:184] Resuming sending status updates
3: I1116 21:01:33.499711 18300 slave.cpp:1227] Checkpointing SlaveInfo to '/tmp/ParentChildContainerTypeAndContentType_AgentContainerAPITest_TwoLevelNestedContainerLaunch_8_dd3Pxb/meta/slaves/6d2c86f1-9276-4e52-adb7-96d3ea164ced-S0/slave.info'
3: I1116 21:01:33.499769 18310 hierarchical.cpp:1450] Performed allocation for 1 agents in 212856ns
3: I1116 21:01:33.500253 18300 slave.cpp:1295] Forwarding total oversubscribed resources {}
3: I1116 21:01:33.500576 18305 master.cpp:7064] Received update of agent 6d2c86f1-9276-4e52-adb7-96d3ea164ced-S0 at slave(668)@172.17.0.4:41828 (dbd9964db352) with total oversubscribed resources {}
3: I1116 21:01:33.501008 18305 master.cpp:7082] Ignoring update on agent 6d2c86f1-9276-4e52-adb7-96d3ea164ced-S0 at slave(668)@172.17.0.4:41828 (dbd9964db352) as it reports no changes
3: I1116 21:01:33.502924 18299 process.cpp:3925] Handling HTTP event for process 'slave(668)' with path: '/slave(668)/api/v1'
3: I1116 21:01:33.505039 18292 http.cpp:1185] HTTP POST for /slave(668)/api/v1 from 172.17.0.4:56310
3: I1116 21:01:33.506258 18292 http.cpp:2395] Processing LAUNCH_CONTAINER call for container '1a4cbd31-7a02-4663-9c53-f363e9910dc7'
3: I1116 21:01:33.507547 18302 containerizer.cpp:1149] Starting container 1a4cbd31-7a02-4663-9c53-f363e9910dc7
3: I1116 21:01:33.508239 18302 containerizer.cpp:2818] Transitioning the state of container 1a4cbd31-7a02-4663-9c53-f363e9910dc7 from PROVISIONING to PREPARING
3: I1116 21:01:33.512398 18301 containerizer.cpp:1768] Launching 'mesos-containerizer' with flags '--help="false" --launch_info="{"command":{"shell":true,"value":"sleep 1000"},"environment":{"variables":[{"name":"MESOS_SANDBOX","type":"VALUE","value":"\/tmp\/ParentChildContainerTypeAndContentType_AgentContainerAPITest_TwoLevelNestedContainerLaunch_8_dd3Pxb\/containers\/1a4cbd31-7a02-4663-9c53-f363e9910dc7"}]},"task_environment":{},"working_directory":"\/tmp\/ParentChildContainerTypeAndContentType_AgentContainerAPITest_TwoLevelNestedContainerLaunch_8_dd3Pxb\/containers\/1a4cbd31-7a02-4663-9c53-f363e9910dc7"}" --pipe_read="14" --pipe_write="15" --runtime_directory="/tmp/ParentChildContainerTypeAndContentType_AgentContainerAPITest_TwoLevelNestedContainerLaunch_8_H5oQEr/containers/1a4cbd31-7a02-4663-9c53-f363e9910dc7" --unshare_namespace_mnt="false"'
3: I1116 21:01:33.515650 18301 launcher.cpp:140] Forked child with pid '25770' for container '1a4cbd31-7a02-4663-9c53-f363e9910dc7'
3: I1116 21:01:33.516919 18301 containerizer.cpp:2818] Transitioning the state of container 1a4cbd31-7a02-4663-9c53-f363e9910dc7 from PREPARING to ISOLATING
3: I1116 21:01:33.519606 18291 containerizer.cpp:2818] Transitioning the state of container 1a4cbd31-7a02-4663-9c53-f363e9910dc7 from ISOLATING to FETCHING
3: I1116 21:01:33.519907 18298 fetcher.cpp:379] Starting to fetch URIs for container: 1a4cbd31-7a02-4663-9c53-f363e9910dc7, directory: /tmp/ParentChildContainerTypeAndContentType_AgentContainerAPITest_TwoLevelNestedContainerLaunch_8_dd3Pxb/containers/1a4cbd31-7a02-4663-9c53-f363e9910dc7
3: I1116 21:01:33.520768 18292 containerizer.cpp:2818] Transitioning the state of container 1a4cbd31-7a02-4663-9c53-f363e9910dc7 from FETCHING to RUNNING
3: I1116 21:01:33.526309 18293 process.cpp:3925] Handling HTTP event for process 'slave(668)' with path: '/slave(668)/api/v1'
3: I1116 21:01:33.528126 18291 http.cpp:1185] HTTP POST for /slave(668)/api/v1 from 172.17.0.4:56312
3: I1116 21:01:33.528883 18291 http.cpp:2362] Processing LAUNCH_NESTED_CONTAINER call for container '1a4cbd31-7a02-4663-9c53-f363e9910dc7.dd1fa0d8-3c0a-4dbc-a0ca-931cb25c37ec'
3: I1116 21:01:33.529824 18292 containerizer.cpp:1149] Starting container 1a4cbd31-7a02-4663-9c53-f363e9910dc7.dd1fa0d8-3c0a-4dbc-a0ca-931cb25c37ec
3: I1116 21:01:33.530247 18292 containerizer.cpp:2818] Transitioning the state of container 1a4cbd31-7a02-4663-9c53-f363e9910dc7.dd1fa0d8-3c0a-4dbc-a0ca-931cb25c37ec from PROVISIONING to PREPARING
3: I1116 21:01:33.533231 18302 containerizer.cpp:1768] Launching 'mesos-containerizer' with flags '--help="false" --launch_info="{"command":{"shell":true,"value":"sleep 100"},"environment":{"variables":[{"name":"MESOS_SANDBOX","type":"VALUE","value":"\/tmp\/ParentChildContainerTypeAndContentType_AgentContainerAPITest_TwoLevelNestedContainerLaunch_8_dd3Pxb\/containers\/1a4cbd31-7a02-4663-9c53-f363e9910dc7\/containers\/dd1fa0d8-3c0a-4dbc-a0ca-931cb25c37ec"}]},"task_environment":{},"working_directory":"\/tmp\/ParentChildContainerTypeAndContentType_AgentContainerAPITest_TwoLevelNestedContainerLaunch_8_dd3Pxb\/containers\/1a4cbd31-7a02-4663-9c53-f363e9910dc7\/containers\/dd1fa0d8-3c0a-4dbc-a0ca-931cb25c37ec"}" --pipe_read="14" --pipe_write="15" --runtime_directory="/tmp/ParentChildContainerTypeAndContentType_AgentContainerAPITest_TwoLevelNestedContainerLaunch_8_H5oQEr/containers/1a4cbd31-7a02-4663-9c53-f363e9910dc7/containers/dd1fa0d8-3c0a-4dbc-a0ca-931cb25c37ec" --unshare_namespace_mnt="false"'
3: I1116 21:01:33.536296 18302 launcher.cpp:140] Forked child with pid '25771' for container '1a4cbd31-7a02-4663-9c53-f363e9910dc7.dd1fa0d8-3c0a-4dbc-a0ca-931cb25c37ec'
3: I1116 21:01:33.537742 18302 containerizer.cpp:2818] Transitioning the state of container 1a4cbd31-7a02-4663-9c53-f363e9910dc7.dd1fa0d8-3c0a-4dbc-a0ca-931cb25c37ec from PREPARING to ISOLATING
3: I1116 21:01:33.538915 18302 containerizer.cpp:2818] Transitioning the state of container 1a4cbd31-7a02-4663-9c53-f363e9910dc7.dd1fa0d8-3c0a-4dbc-a0ca-931cb25c37ec from ISOLATING to FETCHING
3: I1116 21:01:33.539182 18293 fetcher.cpp:379] Starting to fetch URIs for container: 1a4cbd31-7a02-4663-9c53-f363e9910dc7.dd1fa0d8-3c0a-4dbc-a0ca-931cb25c37ec, directory: /tmp/ParentChildContainerTypeAndContentType_AgentContainerAPITest_TwoLevelNestedContainerLaunch_8_dd3Pxb/containers/1a4cbd31-7a02-4663-9c53-f363e9910dc7/containers/dd1fa0d8-3c0a-4dbc-a0ca-931cb25c37ec
3: I1116 21:01:33.539918 18314 containerizer.cpp:2818] Transitioning the state of container 1a4cbd31-7a02-4663-9c53-f363e9910dc7.dd1fa0d8-3c0a-4dbc-a0ca-931cb25c37ec from FETCHING to RUNNING
3: I1116 21:01:33.544836 18296 process.cpp:3925] Handling HTTP event for process 'slave(668)' with path: '/slave(668)/api/v1'
3: I1116 21:01:33.546644 18302 http.cpp:1185] HTTP POST for /slave(668)/api/v1 from 172.17.0.4:56314
3: I1116 21:01:33.547461 18302 http.cpp:2362] Processing LAUNCH_NESTED_CONTAINER call for container '1a4cbd31-7a02-4663-9c53-f363e9910dc7.dd1fa0d8-3c0a-4dbc-a0ca-931cb25c37ec.b10214e7-f8e5-47a4-a0d6-7dd7b72e3a0b'
3: I1116 21:01:33.548393 18314 containerizer.cpp:1149] Starting container 1a4cbd31-7a02-4663-9c53-f363e9910dc7.dd1fa0d8-3c0a-4dbc-a0ca-931cb25c37ec.b10214e7-f8e5-47a4-a0d6-7dd7b72e3a0b
3: I1116 21:01:33.548810 18314 containerizer.cpp:2818] Transitioning the state of container 1a4cbd31-7a02-4663-9c53-f363e9910dc7.dd1fa0d8-3c0a-4dbc-a0ca-931cb25c37ec.b10214e7-f8e5-47a4-a0d6-7dd7b72e3a0b from PROVISIONING to PREPARING
3: I1116 21:01:33.551276 18303 containerizer.cpp:1768] Launching 'mesos-containerizer' with flags '--help="false" --launch_info="{"command":{"shell":true,"value":"sleep 100"},"environment":{"variables":[{"name":"MESOS_SANDBOX","type":"VALUE","value":"\/tmp\/ParentChildContainerTypeAndContentType_AgentContainerAPITest_TwoLevelNestedContainerLaunch_8_dd3Pxb\/containers\/1a4cbd31-7a02-4663-9c53-f363e9910dc7\/containers\/dd1fa0d8-3c0a-4dbc-a0ca-931cb25c37ec\/containers\/b10214e7-f8e5-47a4-a0d6-7dd7b72e3a0b"}]},"task_environment":{},"working_directory":"\/tmp\/ParentChildContainerTypeAndContentType_AgentContainerAPITest_TwoLevelNestedContainerLaunch_8_dd3Pxb\/containers\/1a4cbd31-7a02-4663-9c53-f363e9910dc7\/containers\/dd1fa0d8-3c0a-4dbc-a0ca-931cb25c37ec\/containers\/b10214e7-f8e5-47a4-a0d6-7dd7b72e3a0b"}" --pipe_read="14" --pipe_write="15" --runtime_directory="/tmp/ParentChildContainerTypeAndContentType_AgentContainerAPITest_TwoLevelNestedContainerLaunch_8_H5oQEr/containers/1a4cbd31-7a02-4663-9c53-f363e9910dc7/containers/dd1fa0d8-3c0a-4dbc-a0ca-931cb25c37ec/containers/b10214e7-f8e5-47a4-a0d6-7dd7b72e3a0b" --unshare_namespace_mnt="false"'
3: I1116 21:01:33.553864 18303 launcher.cpp:140] Forked child with pid '25772' for container '1a4cbd31-7a02-4663-9c53-f363e9910dc7.dd1fa0d8-3c0a-4dbc-a0ca-931cb25c37ec.b10214e7-f8e5-47a4-a0d6-7dd7b72e3a0b'
3: I1116 21:01:33.555089 18303 containerizer.cpp:2818] Transitioning the state of container 1a4cbd31-7a02-4663-9c53-f363e9910dc7.dd1fa0d8-3c0a-4dbc-a0ca-931cb25c37ec.b10214e7-f8e5-47a4-a0d6-7dd7b72e3a0b from PREPARING to ISOLATING
3: I1116 21:01:33.556084 18303 containerizer.cpp:2818] Transitioning the state of container 1a4cbd31-7a02-4663-9c53-f363e9910dc7.dd1fa0d8-3c0a-4dbc-a0ca-931cb25c37ec.b10214e7-f8e5-47a4-a0d6-7dd7b72e3a0b from ISOLATING to FETCHING
3: I1116 21:01:33.556305 18312 fetcher.cpp:379] Starting to fetch URIs for container: 1a4cbd31-7a02-4663-9c53-f363e9910dc7.dd1fa0d8-3c0a-4dbc-a0ca-931cb25c37ec.b10214e7-f8e5-47a4-a0d6-7dd7b72e3a0b, directory: /tmp/ParentChildContainerTypeAndContentType_AgentContainerAPITest_TwoLevelNestedContainerLaunch_8_dd3Pxb/containers/1a4cbd31-7a02-4663-9c53-f363e9910dc7/containers/dd1fa0d8-3c0a-4dbc-a0ca-931cb25c37ec/containers/b10214e7-f8e5-47a4-a0d6-7dd7b72e3a0b
3: I1116 21:01:33.557214 18310 containerizer.cpp:2818] Transitioning the state of container 1a4cbd31-7a02-4663-9c53-f363e9910dc7.dd1fa0d8-3c0a-4dbc-a0ca-931cb25c37ec.b10214e7-f8e5-47a4-a0d6-7dd7b72e3a0b from FETCHING to RUNNING
3: I1116 21:01:33.563406 18295 process.cpp:3925] Handling HTTP event for process 'slave(668)' with path: '/slave(668)/api/v1'
3: I1116 21:01:33.564685 18300 process.cpp:3925] Handling HTTP event for process 'slave(668)' with path: '/slave(668)/api/v1'
3: I1116 21:01:33.565222 18305 process.cpp:3925] Handling HTTP event for process 'slave(668)' with path: '/slave(668)/api/v1'
3: I1116 21:01:33.566138 18314 http.cpp:1185] HTTP POST for /slave(668)/api/v1 from 172.17.0.4:56318
3: I1116 21:01:33.566774 18314 http.cpp:2589] Processing WAIT_NESTED_CONTAINER call for container '1a4cbd31-7a02-4663-9c53-f363e9910dc7.dd1fa0d8-3c0a-4dbc-a0ca-931cb25c37ec.b10214e7-f8e5-47a4-a0d6-7dd7b72e3a0b'
3: I1116 21:01:33.567229 18314 http.cpp:1185] HTTP POST for /slave(668)/api/v1 from 172.17.0.4:56316
3: I1116 21:01:33.567687 18314 http.cpp:1185] HTTP POST for /slave(668)/api/v1 from 172.17.0.4:56320
3: I1116 21:01:33.568074 18314 http.cpp:2589] Processing WAIT_NESTED_CONTAINER call for container '1a4cbd31-7a02-4663-9c53-f363e9910dc7.dd1fa0d8-3c0a-4dbc-a0ca-931cb25c37ec'
3: I1116 21:01:33.568436 18314 http.cpp:2747] Processing KILL_NESTED_CONTAINER call for container '1a4cbd31-7a02-4663-9c53-f363e9910dc7.dd1fa0d8-3c0a-4dbc-a0ca-931cb25c37ec.b10214e7-f8e5-47a4-a0d6-7dd7b72e3a0b'
3: I1116 21:01:33.618894 18299 containerizer.cpp:2705] Container 1a4cbd31-7a02-4663-9c53-f363e9910dc7.dd1fa0d8-3c0a-4dbc-a0ca-931cb25c37ec.b10214e7-f8e5-47a4-a0d6-7dd7b72e3a0b has exited
3: I1116 21:01:33.618952 18299 containerizer.cpp:2254] Destroying container 1a4cbd31-7a02-4663-9c53-f363e9910dc7.dd1fa0d8-3c0a-4dbc-a0ca-931cb25c37ec.b10214e7-f8e5-47a4-a0d6-7dd7b72e3a0b in RUNNING state
3: I1116 21:01:33.618969 18299 containerizer.cpp:2818] Transitioning the state of container 1a4cbd31-7a02-4663-9c53-f363e9910dc7.dd1fa0d8-3c0a-4dbc-a0ca-931cb25c37ec.b10214e7-f8e5-47a4-a0d6-7dd7b72e3a0b from RUNNING to DESTROYING
3: I1116 21:01:33.619333 18299 launcher.cpp:156] Asked to destroy container 1a4cbd31-7a02-4663-9c53-f363e9910dc7.dd1fa0d8-3c0a-4dbc-a0ca-931cb25c37ec.b10214e7-f8e5-47a4-a0d6-7dd7b72e3a0b
3: I1116 21:01:33.622534 18303 provisioner.cpp:490] Ignoring destroy request for unknown container 1a4cbd31-7a02-4663-9c53-f363e9910dc7.dd1fa0d8-3c0a-4dbc-a0ca-931cb25c37ec.b10214e7-f8e5-47a4-a0d6-7dd7b72e3a0b
3: I1116 21:01:33.622733 18303 containerizer.cpp:2543] Checkpointing termination state to nested container's runtime directory '/tmp/ParentChildContainerTypeAndContentType_AgentContainerAPITest_TwoLevelNestedContainerLaunch_8_H5oQEr/containers/1a4cbd31-7a02-4663-9c53-f363e9910dc7/containers/dd1fa0d8-3c0a-4dbc-a0ca-931cb25c37ec/containers/b10214e7-f8e5-47a4-a0d6-7dd7b72e3a0b/termination'
3: I1116 21:01:33.627254 18291 process.cpp:3925] Handling HTTP event for process 'slave(668)' with path: '/slave(668)/api/v1'
3: I1116 21:01:33.628803 18312 http.cpp:1185] HTTP POST for /slave(668)/api/v1 from 172.17.0.4:56322
3: I1116 21:01:33.629276 18312 http.cpp:2747] Processing KILL_NESTED_CONTAINER call for container '1a4cbd31-7a02-4663-9c53-f363e9910dc7.dd1fa0d8-3c0a-4dbc-a0ca-931cb25c37ec'
3: I1116 21:01:33.719775 18298 containerizer.cpp:2705] Container 1a4cbd31-7a02-4663-9c53-f363e9910dc7.dd1fa0d8-3c0a-4dbc-a0ca-931cb25c37ec has exited
3: I1116 21:01:33.719841 18298 containerizer.cpp:2254] Destroying container 1a4cbd31-7a02-4663-9c53-f363e9910dc7.dd1fa0d8-3c0a-4dbc-a0ca-931cb25c37ec in RUNNING state
3: I1116 21:01:33.719872 18298 containerizer.cpp:2818] Transitioning the state of container 1a4cbd31-7a02-4663-9c53-f363e9910dc7.dd1fa0d8-3c0a-4dbc-a0ca-931cb25c37ec from RUNNING to DESTROYING
3: I1116 21:01:33.720309 18298 launcher.cpp:156] Asked to destroy container 1a4cbd31-7a02-4663-9c53-f363e9910dc7.dd1fa0d8-3c0a-4dbc-a0ca-931cb25c37ec
3: I1116 21:01:33.725504 18310 provisioner.cpp:490] Ignoring destroy request for unknown container 1a4cbd31-7a02-4663-9c53-f363e9910dc7.dd1fa0d8-3c0a-4dbc-a0ca-931cb25c37ec
3: I1116 21:01:33.725777 18310 containerizer.cpp:2543] Checkpointing termination state to nested container's runtime directory '/tmp/ParentChildContainerTypeAndContentType_AgentContainerAPITest_TwoLevelNestedContainerLaunch_8_H5oQEr/containers/1a4cbd31-7a02-4663-9c53-f363e9910dc7/containers/dd1fa0d8-3c0a-4dbc-a0ca-931cb25c37ec/termination'
3: I1116 21:01:33.730548 18302 containerizer.cpp:2254] Destroying container 1a4cbd31-7a02-4663-9c53-f363e9910dc7 in RUNNING state
3: I1116 21:01:33.730592 18302 containerizer.cpp:2818] Transitioning the state of container 1a4cbd31-7a02-4663-9c53-f363e9910dc7 from RUNNING to DESTROYING
3: I1116 21:01:33.730859 18302 launcher.cpp:156] Asked to destroy container 1a4cbd31-7a02-4663-9c53-f363e9910dc7
3: I1116 21:01:33.825037 18309 containerizer.cpp:2705] Container 1a4cbd31-7a02-4663-9c53-f363e9910dc7 has exited
3: I1116 21:01:33.827780 18295 provisioner.cpp:490] Ignoring destroy request for unknown container 1a4cbd31-7a02-4663-9c53-f363e9910dc7
3: I1116 21:01:33.830601 18299 slave.cpp:883] Agent terminating
3: I1116 21:01:33.831018 18306 master.cpp:1309] Agent 6d2c86f1-9276-4e52-adb7-96d3ea164ced-S0 at slave(668)@172.17.0.4:41828 (dbd9964db352) disconnected
3: I1116 21:01:33.831074 18306 master.cpp:3368] Disconnecting agent 6d2c86f1-9276-4e52-adb7-96d3ea164ced-S0 at slave(668)@172.17.0.4:41828 (dbd9964db352)
3: I1116 21:01:33.831243 18306 master.cpp:3387] Deactivating agent 6d2c86f1-9276-4e52-adb7-96d3ea164ced-S0 at slave(668)@172.17.0.4:41828 (dbd9964db352)
3: I1116 21:01:33.831434 18305 hierarchical.cpp:690] Agent 6d2c86f1-9276-4e52-adb7-96d3ea164ced-S0 deactivated
3: I1116 21:01:33.841567 18290 master.cpp:1151] Master terminating
3: I1116 21:01:33.842838 18312 hierarchical.cpp:626] Removed agent 6d2c86f1-9276-4e52-adb7-96d3ea164ced-S0
3: [ OK ] ParentChildContainerTypeAndContentType/AgentContainerAPITest.TwoLevelNestedContainerLaunch/8 (402 ms)
3: [ RUN ] ParentChildContainerTypeAndContentType/AgentContainerAPITest.TwoLevelNestedContainerLaunch/10
3: I1116 21:01:33.853464 18290 cluster.cpp:162] Creating default 'local' authorizer
3: I1116 21:01:33.857887 18312 master.cpp:448] Master a1a296be-d4fc-46b3-b3b0-236d86684287 (dbd9964db352) started on 172.17.0.4:41828
3: I1116 21:01:33.857939 18312 master.cpp:450] 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/SSyFaC/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/SSyFaC/master" --zk_session_timeout="10secs"
3: I1116 21:01:33.858464 18312 master.cpp:499] Master only allowing authenticated frameworks to register
3: I1116 21:01:33.858479 18312 master.cpp:505] Master only allowing authenticated agents to register
3: I1116 21:01:33.858490 18312 master.cpp:511] Master only allowing authenticated HTTP frameworks to register
3: I1116 21:01:33.858502 18312 credentials.hpp:37] Loading credentials for authentication from '/tmp/SSyFaC/credentials'
3: I1116 21:01:33.859005 18312 master.cpp:555] Using default 'crammd5' authenticator
3: I1116 21:01:33.859316 18312 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly'
3: I1116 21:01:33.859560 18312 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite'
3: I1116 21:01:33.859752 18312 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler'
3: I1116 21:01:33.859961 18312 master.cpp:634] Authorization enabled
3: I1116 21:01:33.860232 18295 hierarchical.cpp:171] Initialized hierarchical allocator process
3: I1116 21:01:33.860290 18305 whitelist_watcher.cpp:77] No whitelist given
3: I1116 21:01:33.864960 18299 master.cpp:2213] Elected as the leading master!
3: I1116 21:01:33.864998 18299 master.cpp:1693] Recovering from registrar
3: I1116 21:01:33.865236 18301 registrar.cpp:347] Recovering registrar
3: I1116 21:01:33.866083 18301 registrar.cpp:391] Successfully fetched the registry (0B) in 797184ns
3: I1116 21:01:33.866267 18301 registrar.cpp:495] Applied 1 operations in 65717ns; attempting to update the registry
3: I1116 21:01:33.867103 18301 registrar.cpp:552] Successfully updated the registry in 747008ns
3: I1116 21:01:33.867326 18301 registrar.cpp:424] Successfully recovered registrar
3: I1116 21:01:33.867993 18308 master.cpp:1806] Recovered 0 agents from the registry (129B); allowing 10mins for agents to re-register
3: I1116 21:01:33.868132 18303 hierarchical.cpp:209] Skipping recovery of hierarchical allocator: nothing to recover
3: W1116 21:01:33.875102 18290 process.cpp:3178] Attempted to spawn already running process files@172.17.0.4:41828
3: I1116 21:01:33.876412 18290 containerizer.cpp:301] Using isolation { environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni }
3: W1116 21:01:33.877182 18290 backend.cpp:76] Failed to create 'aufs' backend: AufsBackend requires root privileges
3: W1116 21:01:33.877355 18290 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires root privileges
3: I1116 21:01:33.877399 18290 provisioner.cpp:255] Using default backend 'copy'
3: I1116 21:01:33.879922 18290 cluster.cpp:448] Creating default 'local' authorizer
3: I1116 21:01:33.882761 18303 slave.cpp:262] Mesos agent started on (669)@172.17.0.4:41828
3: I1116 21:01:33.882805 18303 slave.cpp:263] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/ParentChildContainerTypeAndContentType_AgentContainerAPITest_TwoLevelNestedContainerLaunch_10_olMHla/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/ParentChildContainerTypeAndContentType_AgentContainerAPITest_TwoLevelNestedContainerLaunch_10_olMHla/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/ParentChildContainerTypeAndContentType_AgentContainerAPITest_TwoLevelNestedContainerLaunch_10_olMHla/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_secret_key="/tmp/ParentChildContainerTypeAndContentType_AgentContainerAPITest_TwoLevelNestedContainerLaunch_10_olMHla/executor_secret_key" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/ParentChildContainerTypeAndContentType_AgentContainerAPITest_TwoLevelNestedContainerLaunch_10_olMHla/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/ParentChildContainerTypeAndContentType_AgentContainerAPITest_TwoLevelNestedContainerLaunch_10_olMHla/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/ParentChildContainerTypeAndContentType_AgentContainerAPITest_TwoLevelNestedContainerLaunch_10_olMHla" --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/ParentChildContainerTypeAndContentType_AgentContainerAPITest_TwoLevelNestedContainerLaunch_10_gC0agT" --zk_session_timeout="10secs"
3: I1116 21:01:33.883386 18303 credentials.hpp:86] Loading credential for authentication from '/tmp/ParentChildContainerTypeAndContentType_AgentContainerAPITest_TwoLevelNestedContainerLaunch_10_olMHla/credential'
3: I1116 21:01:33.883666 18303 slave.cpp:295] Agent using credential for: test-principal
3: I1116 21:01:33.883697 18303 credentials.hpp:37] Loading credentials for authentication from '/tmp/ParentChildContainerTypeAndContentType_AgentContainerAPITest_TwoLevelNestedContainerLaunch_10_olMHla/http_credentials'
3: I1116 21:01:33.884140 18303 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-executor'
3: I1116 21:01:33.884336 18303 http.cpp:1066] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-executor'
3: I1116 21:01:33.884680 18303 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
write /dev/stdout: resource temporarily unavailable
Build step 'Execute shell' marked build as failure
Jenkins build is back to normal : Mesos-Buildbot » cmake,clang,--verbose --disable-libtool-wrappers --enable-libevent --enable-ssl,GLOG_v=1 MESOS_VERBOSE=1,ubuntu:14.04,(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)&&(!qnode3)&&(!H23) #4471
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos-Buildbot/BUILDTOOL=cmake,COMPILER=clang,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)/4471/display/redirect?page=changes>
Build failed in Jenkins: Mesos-Buildbot » cmake,clang,--verbose --disable-libtool-wrappers --enable-libevent --enable-ssl,GLOG_v=1 MESOS_VERBOSE=1,ubuntu:14.04,(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)&&(!qnode3)&&(!H23) #4470
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos-Buildbot/BUILDTOOL=cmake,COMPILER=clang,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)/4470/display/redirect?page=changes>
Changes:
[Kapil Arya] Use annotated tags in vote.sh and release.sh.
------------------------------------------
[...truncated 5.23 MB...]
3: I1118 00:53:22.440713 18315 state.cpp:64] Recovering state from '/tmp/MasterMaintenanceTest_InverseOffersFilters_9Uw10Q/meta'
3: I1118 00:53:22.440994 18315 status_update_manager.cpp:203] Recovering status update manager
3: I1118 00:53:22.441282 18297 slave.cpp:6441] Finished recovery
3: I1118 00:53:22.442013 18304 status_update_manager.cpp:177] Pausing sending status updates
3: I1118 00:53:22.442051 18303 slave.cpp:1007] New master detected at master@172.17.0.4:45533
3: I1118 00:53:22.442114 18303 slave.cpp:1042] Detecting new master
3: I1118 00:53:22.448230 18294 slave.cpp:1069] Authenticating with master master@172.17.0.4:45533
3: I1118 00:53:22.448359 18294 slave.cpp:1078] Using default CRAM-MD5 authenticatee
3: I1118 00:53:22.448689 18305 authenticatee.cpp:121] Creating new client SASL connection
3: I1118 00:53:22.449086 18306 master.cpp:8285] Authenticating slave(96)@172.17.0.4:45533
3: I1118 00:53:22.449218 18292 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(201)@172.17.0.4:45533
3: I1118 00:53:22.449522 18309 authenticator.cpp:98] Creating new server SASL connection
3: I1118 00:53:22.449791 18311 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
3: I1118 00:53:22.449821 18311 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
3: I1118 00:53:22.449926 18310 authenticator.cpp:204] Received SASL authentication start
3: I1118 00:53:22.449976 18310 authenticator.cpp:326] Authentication requires more steps
3: I1118 00:53:22.450078 18300 authenticatee.cpp:259] Received SASL authentication step
3: I1118 00:53:22.450242 18302 authenticator.cpp:232] Received SASL authentication step
3: I1118 00:53:22.450280 18302 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '1fb2fbcd726c' server FQDN: '1fb2fbcd726c' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
3: I1118 00:53:22.450292 18302 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
3: I1118 00:53:22.450332 18302 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
3: I1118 00:53:22.450350 18302 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '1fb2fbcd726c' server FQDN: '1fb2fbcd726c' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
3: I1118 00:53:22.450356 18302 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
3: I1118 00:53:22.450359 18302 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
3: I1118 00:53:22.450374 18302 authenticator.cpp:318] Authentication success
3: I1118 00:53:22.450460 18296 authenticatee.cpp:299] Authentication success
3: I1118 00:53:22.450517 18301 master.cpp:8315] Successfully authenticated principal 'test-principal' at slave(96)@172.17.0.4:45533
3: I1118 00:53:22.450575 18296 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(201)@172.17.0.4:45533
3: I1118 00:53:22.451334 18299 slave.cpp:1161] Successfully authenticated with master master@172.17.0.4:45533
3: I1118 00:53:22.451699 18299 slave.cpp:1682] Will retry registration in 3.391235ms if necessary
3: I1118 00:53:22.451912 18297 master.cpp:6032] Received register agent message from slave(96)@172.17.0.4:45533 (maintenance-host-2)
3: I1118 00:53:22.451948 18297 master.cpp:3870] Authorizing agent with principal 'test-principal'
3: I1118 00:53:22.452486 18308 master.cpp:6092] Authorized registration of agent at slave(96)@172.17.0.4:45533 (maintenance-host-2)
3: I1118 00:53:22.452612 18308 master.cpp:6185] Registering agent at slave(96)@172.17.0.4:45533 (maintenance-host-2) with id 8545d424-bd1d-4c98-b88e-00a5c2d5e027-S1
3: I1118 00:53:22.453042 18304 registrar.cpp:495] Applied 1 operations in 111373ns; attempting to update the registry
3: I1118 00:53:22.453755 18304 registrar.cpp:552] Successfully updated the registry in 631040ns
3: I1118 00:53:22.453966 18305 master.cpp:6232] Admitted agent 8545d424-bd1d-4c98-b88e-00a5c2d5e027-S1 at slave(96)@172.17.0.4:45533 (maintenance-host-2)
3: I1118 00:53:22.454608 18305 master.cpp:6263] Registered agent 8545d424-bd1d-4c98-b88e-00a5c2d5e027-S1 at slave(96)@172.17.0.4:45533 (maintenance-host-2) with [{"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: I1118 00:53:22.454881 18309 hierarchical.cpp:593] Added agent 8545d424-bd1d-4c98-b88e-00a5c2d5e027-S1 (maintenance-host-2) with cpus:2; mem:1024; disk:1024; ports:[31000-32000] (allocated: {})
3: I1118 00:53:22.454893 18292 slave.cpp:1207] Registered with master master@172.17.0.4:45533; given agent ID 8545d424-bd1d-4c98-b88e-00a5c2d5e027-S1
3: I1118 00:53:22.455171 18314 status_update_manager.cpp:184] Resuming sending status updates
3: I1118 00:53:22.455185 18309 hierarchical.cpp:1450] Performed allocation for 1 agents in 159529ns
3: I1118 00:53:22.455798 18292 slave.cpp:1227] Checkpointing SlaveInfo to '/tmp/MasterMaintenanceTest_InverseOffersFilters_9Uw10Q/meta/slaves/8545d424-bd1d-4c98-b88e-00a5c2d5e027-S1/slave.info'
3: I1118 00:53:22.456653 18292 slave.cpp:1295] Forwarding total oversubscribed resources {}
3: I1118 00:53:22.456918 18312 master.cpp:7064] Received update of agent 8545d424-bd1d-4c98-b88e-00a5c2d5e027-S1 at slave(96)@172.17.0.4:45533 (maintenance-host-2) with total oversubscribed resources {}
3: I1118 00:53:22.457155 18312 master.cpp:7082] Ignoring update on agent 8545d424-bd1d-4c98-b88e-00a5c2d5e027-S1 at slave(96)@172.17.0.4:45533 (maintenance-host-2) as it reports no changes
3: I1118 00:53:22.457505 18297 process.cpp:3932] Handling HTTP event for process 'master' with path: '/master/maintenance/schedule'
3: I1118 00:53:22.458744 18306 http.cpp:1185] HTTP POST for /master/maintenance/schedule from 172.17.0.4:53402
3: I1118 00:53:22.459933 18310 registrar.cpp:495] Applied 1 operations in 224384ns; attempting to update the registry
3: I1118 00:53:22.460610 18310 registrar.cpp:552] Successfully updated the registry in 620032ns
3: I1118 00:53:22.460924 18309 master.cpp:7164] Updating unavailability of agent 8545d424-bd1d-4c98-b88e-00a5c2d5e027-S0 at slave(95)@172.17.0.4:45533 (maintenance-host), starting at 2503.29154010438weeks
3: I1118 00:53:22.461072 18309 master.cpp:7164] Updating unavailability of agent 8545d424-bd1d-4c98-b88e-00a5c2d5e027-S1 at slave(96)@172.17.0.4:45533 (maintenance-host-2), starting at 2503.29154010438weeks
3: I1118 00:53:22.461426 18313 hierarchical.cpp:1450] Performed allocation for 2 agents in 186500ns
3: I1118 00:53:22.463011 18291 scheduler.cpp:190] Version: 1.5.0
3: I1118 00:53:22.463335 18295 scheduler.cpp:313] Using default 'basic' HTTP authenticatee
3: I1118 00:53:22.463805 18306 scheduler.cpp:496] New master detected at master@172.17.0.4:45533
3: I1118 00:53:22.463827 18306 scheduler.cpp:505] Waiting for 0ns before initiating a re-(connection) attempt with the master
3: I1118 00:53:22.465781 18310 scheduler.cpp:387] Connected with the master at http://172.17.0.4:45533/master/api/v1/scheduler
3: I1118 00:53:22.466902 18297 scheduler.cpp:249] Sending SUBSCRIBE call to http://172.17.0.4:45533/master/api/v1/scheduler
3: I1118 00:53:22.467979 18298 process.cpp:3932] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
3: I1118 00:53:22.469326 18301 http.cpp:1185] HTTP POST for /master/api/v1/scheduler from 172.17.0.4:53404
3: I1118 00:53:22.469611 18301 master.cpp:2613] Received subscription request for HTTP framework 'default'
3: I1118 00:53:22.469662 18301 master.cpp:2278] Authorizing framework principal 'test-principal' to receive offers for roles '{ * }'
3: I1118 00:53:22.470147 18313 master.cpp:2748] Subscribing framework 'default' with checkpointing disabled and capabilities [ RESERVATION_REFINEMENT ]
3: I1118 00:53:22.471009 18312 hierarchical.cpp:303] Added framework 8545d424-bd1d-4c98-b88e-00a5c2d5e027-0000
3: I1118 00:53:22.471510 18294 scheduler.cpp:741] Enqueuing event SUBSCRIBED received from http://172.17.0.4:45533/master/api/v1/scheduler
3: I1118 00:53:22.471967 18294 scheduler.cpp:741] Enqueuing event HEARTBEAT received from http://172.17.0.4:45533/master/api/v1/scheduler
3: I1118 00:53:22.474146 18312 hierarchical.cpp:1450] Performed allocation for 2 agents in 2.918857ms
3: I1118 00:53:22.474707 18309 master.cpp:8115] Sending 2 offers to framework 8545d424-bd1d-4c98-b88e-00a5c2d5e027-0000 (default)
3: I1118 00:53:22.475703 18309 master.cpp:8204] Sending 2 inverse offers to framework 8545d424-bd1d-4c98-b88e-00a5c2d5e027-0000 (default)
3: I1118 00:53:22.476944 18292 scheduler.cpp:741] Enqueuing event OFFERS received from http://172.17.0.4:45533/master/api/v1/scheduler
3: I1118 00:53:22.477991 18292 scheduler.cpp:741] Enqueuing event INVERSE_OFFERS received from http://172.17.0.4:45533/master/api/v1/scheduler
3: I1118 00:53:22.479291 18305 hierarchical.cpp:1450] Performed allocation for 2 agents in 396076ns
3: I1118 00:53:22.480792 18302 scheduler.cpp:249] Sending ACCEPT call to http://172.17.0.4:45533/master/api/v1/scheduler
3: I1118 00:53:22.481259 18302 scheduler.cpp:249] Sending ACCEPT call to http://172.17.0.4:45533/master/api/v1/scheduler
3: I1118 00:53:22.482427 18309 process.cpp:3932] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
3: I1118 00:53:22.483706 18310 process.cpp:3932] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
3: I1118 00:53:22.484227 18292 http.cpp:1185] HTTP POST for /master/api/v1/scheduler from 172.17.0.4:53406
3: I1118 00:53:22.486071 18292 master.cpp:10024] Removing offer 8545d424-bd1d-4c98-b88e-00a5c2d5e027-O0
3: I1118 00:53:22.486326 18292 master.cpp:4228] Processing ACCEPT call for offers: [ 8545d424-bd1d-4c98-b88e-00a5c2d5e027-O0 ] on agent 8545d424-bd1d-4c98-b88e-00a5c2d5e027-S0 at slave(95)@172.17.0.4:45533 (maintenance-host) for framework 8545d424-bd1d-4c98-b88e-00a5c2d5e027-0000 (default)
3: I1118 00:53:22.486490 18292 master.cpp:3597] Authorizing framework principal 'test-principal' to launch task 3e97fc6e-7bc4-4125-a41c-8596e3c8e71a
3: W1118 00:53:22.489950 18292 validation.cpp:1391] Executor 'executor-1' for task '3e97fc6e-7bc4-4125-a41c-8596e3c8e71a' uses less CPUs (None) than the minimum required (0.01). Please update your executor, as this will be mandatory in future releases.
3: W1118 00:53:22.490003 18292 validation.cpp:1403] Executor 'executor-1' for task '3e97fc6e-7bc4-4125-a41c-8596e3c8e71a' uses less memory (None) than the minimum required (32MB). Please update your executor, as this will be mandatory in future releases.
3: I1118 00:53:22.490900 18292 master.cpp:10770] Adding task 3e97fc6e-7bc4-4125-a41c-8596e3c8e71a with resources [{"allocation_info":{"role":"*"},"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"disk","scalar":{"value":1024.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}] on agent 8545d424-bd1d-4c98-b88e-00a5c2d5e027-S0 at slave(95)@172.17.0.4:45533 (maintenance-host)
3: I1118 00:53:22.491871 18292 master.cpp:4976] Launching task 3e97fc6e-7bc4-4125-a41c-8596e3c8e71a of framework 8545d424-bd1d-4c98-b88e-00a5c2d5e027-0000 (default) with resources [{"allocation_info":{"role":"*"},"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"disk","scalar":{"value":1024.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}] on agent 8545d424-bd1d-4c98-b88e-00a5c2d5e027-S0 at slave(95)@172.17.0.4:45533 (maintenance-host)
3: I1118 00:53:22.492856 18305 slave.cpp:1803] Got assigned task '3e97fc6e-7bc4-4125-a41c-8596e3c8e71a' for framework 8545d424-bd1d-4c98-b88e-00a5c2d5e027-0000
3: I1118 00:53:22.492911 18301 http.cpp:1185] HTTP POST for /master/api/v1/scheduler from 172.17.0.4:53406
3: I1118 00:53:22.493563 18305 slave.cpp:2071] Authorizing task '3e97fc6e-7bc4-4125-a41c-8596e3c8e71a' for framework 8545d424-bd1d-4c98-b88e-00a5c2d5e027-0000
3: I1118 00:53:22.493633 18305 slave.cpp:7262] Authorizing framework principal 'test-principal' to launch task 3e97fc6e-7bc4-4125-a41c-8596e3c8e71a
3: I1118 00:53:22.494068 18301 master.cpp:10024] Removing offer 8545d424-bd1d-4c98-b88e-00a5c2d5e027-O1
3: I1118 00:53:22.494263 18301 master.cpp:4228] Processing ACCEPT call for offers: [ 8545d424-bd1d-4c98-b88e-00a5c2d5e027-O1 ] on agent 8545d424-bd1d-4c98-b88e-00a5c2d5e027-S1 at slave(96)@172.17.0.4:45533 (maintenance-host-2) for framework 8545d424-bd1d-4c98-b88e-00a5c2d5e027-0000 (default)
3: I1118 00:53:22.494372 18301 master.cpp:3597] Authorizing framework principal 'test-principal' to launch task b55899ae-818d-4fc1-abce-cb700fc4ef30
3: I1118 00:53:22.494505 18300 slave.cpp:2239] Launching task '3e97fc6e-7bc4-4125-a41c-8596e3c8e71a' for framework 8545d424-bd1d-4c98-b88e-00a5c2d5e027-0000
3: I1118 00:53:22.495110 18300 paths.cpp:621] Trying to chown '/tmp/MasterMaintenanceTest_InverseOffersFilters_q2aSG0/slaves/8545d424-bd1d-4c98-b88e-00a5c2d5e027-S0/frameworks/8545d424-bd1d-4c98-b88e-00a5c2d5e027-0000/executors/executor-1/runs/03bb2264-caa4-4213-b7bb-2247cc8eb9cb' to user 'mesos'
3: I1118 00:53:22.495393 18300 slave.cpp:7736] Launching executor 'executor-1' of framework 8545d424-bd1d-4c98-b88e-00a5c2d5e027-0000 with resources [] in work directory '/tmp/MasterMaintenanceTest_InverseOffersFilters_q2aSG0/slaves/8545d424-bd1d-4c98-b88e-00a5c2d5e027-S0/frameworks/8545d424-bd1d-4c98-b88e-00a5c2d5e027-0000/executors/executor-1/runs/03bb2264-caa4-4213-b7bb-2247cc8eb9cb'
3: I1118 00:53:22.496359 18300 slave.cpp:2467] Queued task '3e97fc6e-7bc4-4125-a41c-8596e3c8e71a' for executor 'executor-1' of framework 8545d424-bd1d-4c98-b88e-00a5c2d5e027-0000
3: I1118 00:53:22.496456 18300 slave.cpp:958] Successfully attached '/tmp/MasterMaintenanceTest_InverseOffersFilters_q2aSG0/slaves/8545d424-bd1d-4c98-b88e-00a5c2d5e027-S0/frameworks/8545d424-bd1d-4c98-b88e-00a5c2d5e027-0000/executors/executor-1/runs/03bb2264-caa4-4213-b7bb-2247cc8eb9cb' to virtual path '/tmp/MasterMaintenanceTest_InverseOffersFilters_q2aSG0/slaves/8545d424-bd1d-4c98-b88e-00a5c2d5e027-S0/frameworks/8545d424-bd1d-4c98-b88e-00a5c2d5e027-0000/executors/executor-1/runs/latest'
3: I1118 00:53:22.496500 18300 slave.cpp:958] Successfully attached '/tmp/MasterMaintenanceTest_InverseOffersFilters_q2aSG0/slaves/8545d424-bd1d-4c98-b88e-00a5c2d5e027-S0/frameworks/8545d424-bd1d-4c98-b88e-00a5c2d5e027-0000/executors/executor-1/runs/03bb2264-caa4-4213-b7bb-2247cc8eb9cb' to virtual path '/frameworks/8545d424-bd1d-4c98-b88e-00a5c2d5e027-0000/executors/executor-1/runs/latest'
3: I1118 00:53:22.496541 18300 slave.cpp:958] Successfully attached '/tmp/MasterMaintenanceTest_InverseOffersFilters_q2aSG0/slaves/8545d424-bd1d-4c98-b88e-00a5c2d5e027-S0/frameworks/8545d424-bd1d-4c98-b88e-00a5c2d5e027-0000/executors/executor-1/runs/03bb2264-caa4-4213-b7bb-2247cc8eb9cb' to virtual path '/tmp/MasterMaintenanceTest_InverseOffersFilters_q2aSG0/slaves/8545d424-bd1d-4c98-b88e-00a5c2d5e027-S0/frameworks/8545d424-bd1d-4c98-b88e-00a5c2d5e027-0000/executors/executor-1/runs/03bb2264-caa4-4213-b7bb-2247cc8eb9cb'
3: I1118 00:53:22.496826 18300 slave.cpp:2930] Launching container 03bb2264-caa4-4213-b7bb-2247cc8eb9cb for executor 'executor-1' of framework 8545d424-bd1d-4c98-b88e-00a5c2d5e027-0000
3: W1118 00:53:22.496894 18301 validation.cpp:1391] Executor 'executor-2' for task 'b55899ae-818d-4fc1-abce-cb700fc4ef30' uses less CPUs (None) than the minimum required (0.01). Please update your executor, as this will be mandatory in future releases.
3: W1118 00:53:22.496924 18301 validation.cpp:1403] Executor 'executor-2' for task 'b55899ae-818d-4fc1-abce-cb700fc4ef30' uses less memory (None) than the minimum required (32MB). Please update your executor, as this will be mandatory in future releases.
3: I1118 00:53:22.497483 18301 master.cpp:10770] Adding task b55899ae-818d-4fc1-abce-cb700fc4ef30 with resources [{"allocation_info":{"role":"*"},"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"disk","scalar":{"value":1024.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}] on agent 8545d424-bd1d-4c98-b88e-00a5c2d5e027-S1 at slave(96)@172.17.0.4:45533 (maintenance-host-2)
3: I1118 00:53:22.498086 18301 master.cpp:4976] Launching task b55899ae-818d-4fc1-abce-cb700fc4ef30 of framework 8545d424-bd1d-4c98-b88e-00a5c2d5e027-0000 (default) with resources [{"allocation_info":{"role":"*"},"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"disk","scalar":{"value":1024.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}] on agent 8545d424-bd1d-4c98-b88e-00a5c2d5e027-S1 at slave(96)@172.17.0.4:45533 (maintenance-host-2)
3: I1118 00:53:22.498915 18299 slave.cpp:1803] Got assigned task 'b55899ae-818d-4fc1-abce-cb700fc4ef30' for framework 8545d424-bd1d-4c98-b88e-00a5c2d5e027-0000
3: W1118 00:53:22.499274 18298 process.cpp:3185] Attempted to spawn already running process version@172.17.0.4:45533
3: I1118 00:53:22.499470 18298 exec.cpp:162] Version: 1.5.0
3: I1118 00:53:22.499620 18299 slave.cpp:2071] Authorizing task 'b55899ae-818d-4fc1-abce-cb700fc4ef30' for framework 8545d424-bd1d-4c98-b88e-00a5c2d5e027-0000
3: I1118 00:53:22.499712 18299 slave.cpp:7262] Authorizing framework principal 'test-principal' to launch task b55899ae-818d-4fc1-abce-cb700fc4ef30
3: I1118 00:53:22.499737 18304 exec.cpp:212] Executor started at: executor(28)@172.17.0.4:45533 with pid 18291
3: I1118 00:53:22.500051 18304 slave.cpp:4063] Got registration for executor 'executor-1' of framework 8545d424-bd1d-4c98-b88e-00a5c2d5e027-0000 from executor(28)@172.17.0.4:45533
3: I1118 00:53:22.500572 18292 exec.cpp:237] Executor registered on agent 8545d424-bd1d-4c98-b88e-00a5c2d5e027-S0
3: I1118 00:53:22.500628 18292 exec.cpp:249] Executor::registered took 42170ns
3: I1118 00:53:22.500722 18312 slave.cpp:2239] Launching task 'b55899ae-818d-4fc1-abce-cb700fc4ef30' for framework 8545d424-bd1d-4c98-b88e-00a5c2d5e027-0000
3: I1118 00:53:22.501319 18309 slave.cpp:2669] Sending queued task '3e97fc6e-7bc4-4125-a41c-8596e3c8e71a' to executor 'executor-1' of framework 8545d424-bd1d-4c98-b88e-00a5c2d5e027-0000 at executor(28)@172.17.0.4:45533
3: I1118 00:53:22.501334 18312 paths.cpp:621] Trying to chown '/tmp/MasterMaintenanceTest_InverseOffersFilters_9Uw10Q/slaves/8545d424-bd1d-4c98-b88e-00a5c2d5e027-S1/frameworks/8545d424-bd1d-4c98-b88e-00a5c2d5e027-0000/executors/executor-2/runs/bb34f439-2c70-4f9e-b27f-132dc096333d' to user 'mesos'
3: I1118 00:53:22.501598 18312 slave.cpp:7736] Launching executor 'executor-2' of framework 8545d424-bd1d-4c98-b88e-00a5c2d5e027-0000 with resources [] in work directory '/tmp/MasterMaintenanceTest_InverseOffersFilters_9Uw10Q/slaves/8545d424-bd1d-4c98-b88e-00a5c2d5e027-S1/frameworks/8545d424-bd1d-4c98-b88e-00a5c2d5e027-0000/executors/executor-2/runs/bb34f439-2c70-4f9e-b27f-132dc096333d'
3: I1118 00:53:22.501863 18314 exec.cpp:331] Executor asked to run task '3e97fc6e-7bc4-4125-a41c-8596e3c8e71a'
3: I1118 00:53:22.501966 18314 exec.cpp:340] Executor::launchTask took 89672ns
3: I1118 00:53:22.502070 18314 exec.cpp:571] Executor sending status update TASK_RUNNING (UUID: 2431691f-1040-438c-96b0-efd00ae28c1b) for task 3e97fc6e-7bc4-4125-a41c-8596e3c8e71a of framework 8545d424-bd1d-4c98-b88e-00a5c2d5e027-0000
3: I1118 00:53:22.502372 18313 slave.cpp:4517] Handling status update TASK_RUNNING (UUID: 2431691f-1040-438c-96b0-efd00ae28c1b) for task 3e97fc6e-7bc4-4125-a41c-8596e3c8e71a of framework 8545d424-bd1d-4c98-b88e-00a5c2d5e027-0000 from executor(28)@172.17.0.4:45533
3: I1118 00:53:22.502539 18312 slave.cpp:2467] Queued task 'b55899ae-818d-4fc1-abce-cb700fc4ef30' for executor 'executor-2' of framework 8545d424-bd1d-4c98-b88e-00a5c2d5e027-0000
3: I1118 00:53:22.502634 18312 slave.cpp:958] Successfully attached '/tmp/MasterMaintenanceTest_InverseOffersFilters_9Uw10Q/slaves/8545d424-bd1d-4c98-b88e-00a5c2d5e027-S1/frameworks/8545d424-bd1d-4c98-b88e-00a5c2d5e027-0000/executors/executor-2/runs/bb34f439-2c70-4f9e-b27f-132dc096333d' to virtual path '/tmp/MasterMaintenanceTest_InverseOffersFilters_9Uw10Q/slaves/8545d424-bd1d-4c98-b88e-00a5c2d5e027-S1/frameworks/8545d424-bd1d-4c98-b88e-00a5c2d5e027-0000/executors/executor-2/runs/latest'
3: I1118 00:53:22.502677 18312 slave.cpp:958] Successfully attached '/tmp/MasterMaintenanceTest_InverseOffersFilters_9Uw10Q/slaves/8545d424-bd1d-4c98-b88e-00a5c2d5e027-S1/frameworks/8545d424-bd1d-4c98-b88e-00a5c2d5e027-0000/executors/executor-2/runs/bb34f439-2c70-4f9e-b27f-132dc096333d' to virtual path '/frameworks/8545d424-bd1d-4c98-b88e-00a5c2d5e027-0000/executors/executor-2/runs/latest'
3: I1118 00:53:22.502717 18312 slave.cpp:958] Successfully attached '/tmp/MasterMaintenanceTest_InverseOffersFilters_9Uw10Q/slaves/8545d424-bd1d-4c98-b88e-00a5c2d5e027-S1/frameworks/8545d424-bd1d-4c98-b88e-00a5c2d5e027-0000/executors/executor-2/runs/bb34f439-2c70-4f9e-b27f-132dc096333d' to virtual path '/tmp/MasterMaintenanceTest_InverseOffersFilters_9Uw10Q/slaves/8545d424-bd1d-4c98-b88e-00a5c2d5e027-S1/frameworks/8545d424-bd1d-4c98-b88e-00a5c2d5e027-0000/executors/executor-2/runs/bb34f439-2c70-4f9e-b27f-132dc096333d'
3: I1118 00:53:22.502964 18310 status_update_manager.cpp:323] Received status update TASK_RUNNING (UUID: 2431691f-1040-438c-96b0-efd00ae28c1b) for task 3e97fc6e-7bc4-4125-a41c-8596e3c8e71a of framework 8545d424-bd1d-4c98-b88e-00a5c2d5e027-0000
3: I1118 00:53:22.503002 18310 status_update_manager.cpp:500] Creating StatusUpdate stream for task 3e97fc6e-7bc4-4125-a41c-8596e3c8e71a of framework 8545d424-bd1d-4c98-b88e-00a5c2d5e027-0000
3: I1118 00:53:22.503115 18312 slave.cpp:2930] Launching container bb34f439-2c70-4f9e-b27f-132dc096333d for executor 'executor-2' of framework 8545d424-bd1d-4c98-b88e-00a5c2d5e027-0000
3: I1118 00:53:22.503548 18310 status_update_manager.cpp:377] Forwarding update TASK_RUNNING (UUID: 2431691f-1040-438c-96b0-efd00ae28c1b) for task 3e97fc6e-7bc4-4125-a41c-8596e3c8e71a of framework 8545d424-bd1d-4c98-b88e-00a5c2d5e027-0000 to the agent
3: I1118 00:53:22.503794 18307 slave.cpp:4998] Forwarding the update TASK_RUNNING (UUID: 2431691f-1040-438c-96b0-efd00ae28c1b) for task 3e97fc6e-7bc4-4125-a41c-8596e3c8e71a of framework 8545d424-bd1d-4c98-b88e-00a5c2d5e027-0000 to master@172.17.0.4:45533
3: I1118 00:53:22.504045 18307 slave.cpp:4892] Status update manager successfully handled status update TASK_RUNNING (UUID: 2431691f-1040-438c-96b0-efd00ae28c1b) for task 3e97fc6e-7bc4-4125-a41c-8596e3c8e71a of framework 8545d424-bd1d-4c98-b88e-00a5c2d5e027-0000
3: I1118 00:53:22.504096 18307 slave.cpp:4908] Sending acknowledgement for status update TASK_RUNNING (UUID: 2431691f-1040-438c-96b0-efd00ae28c1b) for task 3e97fc6e-7bc4-4125-a41c-8596e3c8e71a of framework 8545d424-bd1d-4c98-b88e-00a5c2d5e027-0000 to executor(28)@172.17.0.4:45533
3: I1118 00:53:22.504290 18308 exec.cpp:388] Executor received status update acknowledgement 2431691f-1040-438c-96b0-efd00ae28c1b for task 3e97fc6e-7bc4-4125-a41c-8596e3c8e71a of framework 8545d424-bd1d-4c98-b88e-00a5c2d5e027-0000
3: I1118 00:53:22.504305 18303 master.cpp:7247] Status update TASK_RUNNING (UUID: 2431691f-1040-438c-96b0-efd00ae28c1b) for task 3e97fc6e-7bc4-4125-a41c-8596e3c8e71a of framework 8545d424-bd1d-4c98-b88e-00a5c2d5e027-0000 from agent 8545d424-bd1d-4c98-b88e-00a5c2d5e027-S0 at slave(95)@172.17.0.4:45533 (maintenance-host)
3: I1118 00:53:22.504376 18303 master.cpp:7309] Forwarding status update TASK_RUNNING (UUID: 2431691f-1040-438c-96b0-efd00ae28c1b) for task 3e97fc6e-7bc4-4125-a41c-8596e3c8e71a of framework 8545d424-bd1d-4c98-b88e-00a5c2d5e027-0000
3: I1118 00:53:22.504853 18303 master.cpp:9502] Updating the state of task 3e97fc6e-7bc4-4125-a41c-8596e3c8e71a of framework 8545d424-bd1d-4c98-b88e-00a5c2d5e027-0000 (latest state: TASK_RUNNING, status update state: TASK_RUNNING)
3: *** Aborted at 1510966402 (unix time) try "date -d @1510966402" if you are using GNU date ***
3: PC: @ 0x2b7ae11b882d (unknown)
3: W1118 00:53:22.506050 18312 process.cpp:3185] Attempted to spawn already running process version@172.17.0.4:45533
3: I1118 00:53:22.506053 18299 scheduler.cpp:741] Enqueuing event UPDATE received from http://172.17.0.4:45533/master/api/v1/scheduler
3: I1118 00:53:22.506285 18312 exec.cpp:162] Version: 1.5.0
3: I1118 00:53:22.506587 18304 exec.cpp:212] Executor started at: executor(29)@172.17.0.4:45533 with pid 18291
3: I1118 00:53:22.506805 18304 slave.cpp:4063] Got registration for executor 'executor-2' of framework 8545d424-bd1d-4c98-b88e-00a5c2d5e027-0000 from executor(29)@172.17.0.4:45533
3: I1118 00:53:22.507248 18302 exec.cpp:237] Executor registered on agent 8545d424-bd1d-4c98-b88e-00a5c2d5e027-S1
3: I1118 00:53:22.507297 18302 exec.cpp:249] Executor::registered took 33749ns
3: I1118 00:53:22.507838 18304 slave.cpp:2669] Sending queued task 'b55899ae-818d-4fc1-abce-cb700fc4ef30' to executor 'executor-2' of framework 8545d424-bd1d-4c98-b88e-00a5c2d5e027-0000 at executor(29)@172.17.0.4:45533
3: I1118 00:53:22.508199 18315 exec.cpp:331] Executor asked to run task 'b55899ae-818d-4fc1-abce-cb700fc4ef30'
3: I1118 00:53:22.508286 18315 exec.cpp:340] Executor::launchTask took 76003ns
3: I1118 00:53:22.508368 18315 exec.cpp:571] Executor sending status update TASK_RUNNING (UUID: 52e2250c-a69b-45f1-94aa-28ad0a3bc0c8) for task b55899ae-818d-4fc1-abce-cb700fc4ef30 of framework 8545d424-bd1d-4c98-b88e-00a5c2d5e027-0000
3: I1118 00:53:22.508708 18314 slave.cpp:4517] Handling status update TASK_RUNNING (UUID: 52e2250c-a69b-45f1-94aa-28ad0a3bc0c8) for task b55899ae-818d-4fc1-abce-cb700fc4ef30 of framework 8545d424-bd1d-4c98-b88e-00a5c2d5e027-0000 from executor(29)@172.17.0.4:45533
3: I1118 00:53:22.509420 18296 status_update_manager.cpp:323] Received status update TASK_RUNNING (UUID: 52e2250c-a69b-45f1-94aa-28ad0a3bc0c8) for task b55899ae-818d-4fc1-abce-cb700fc4ef30 of framework 8545d424-bd1d-4c98-b88e-00a5c2d5e027-0000
3: I1118 00:53:22.509467 18296 status_update_manager.cpp:500] Creating StatusUpdate stream for task b55899ae-818d-4fc1-abce-cb700fc4ef30 of framework 8545d424-bd1d-4c98-b88e-00a5c2d5e027-0000
3: I1118 00:53:22.510020 18296 status_update_manager.cpp:377] Forwarding update TASK_RUNNING (UUID: 52e2250c-a69b-45f1-94aa-28ad0a3bc0c8) for task b55899ae-818d-4fc1-abce-cb700fc4ef30 of framework 8545d424-bd1d-4c98-b88e-00a5c2d5e027-0000 to the agent
3: I1118 00:53:22.510220 18310 slave.cpp:4998] Forwarding the update TASK_RUNNING (UUID: 52e2250c-a69b-45f1-94aa-28ad0a3bc0c8) for task b55899ae-818d-4fc1-abce-cb700fc4ef30 of framework 8545d424-bd1d-4c98-b88e-00a5c2d5e027-0000 to master@172.17.0.4:45533
3: I1118 00:53:22.510447 18310 slave.cpp:4892] Status update manager successfully handled status update TASK_RUNNING (UUID: 52e2250c-a69b-45f1-94aa-28ad0a3bc0c8) for task b55899ae-818d-4fc1-abce-cb700fc4ef30 of framework 8545d424-bd1d-4c98-b88e-00a5c2d5e027-0000
3: I1118 00:53:22.510499 18310 slave.cpp:4908] Sending acknowledgement for status update TASK_RUNNING (UUID: 52e2250c-a69b-45f1-94aa-28ad0a3bc0c8) for task b55899ae-818d-4fc1-abce-cb700fc4ef30 of framework 8545d424-bd1d-4c98-b88e-00a5c2d5e027-0000 to executor(29)@172.17.0.4:45533
3: I1118 00:53:22.510665 18308 exec.cpp:388] Executor received status update acknowledgement 52e2250c-a69b-45f1-94aa-28ad0a3bc0c8 for task b55899ae-818d-4fc1-abce-cb700fc4ef30 of framework 8545d424-bd1d-4c98-b88e-00a5c2d5e027-0000
3: I1118 00:53:22.510658 18307 master.cpp:7247] Status update TASK_RUNNING (UUID: 52e2250c-a69b-45f1-94aa-28ad0a3bc0c8) for task b55899ae-818d-4fc1-abce-cb700fc4ef30 of framework 8545d424-bd1d-4c98-b88e-00a5c2d5e027-0000 from agent 8545d424-bd1d-4c98-b88e-00a5c2d5e027-S1 at slave(96)@172.17.0.4:45533 (maintenance-host-2)
3: I1118 00:53:22.510730 18307 master.cpp:7309] Forwarding status update TASK_RUNNING (UUID: 52e2250c-a69b-45f1-94aa-28ad0a3bc0c8) for task b55899ae-818d-4fc1-abce-cb700fc4ef30 of framework 8545d424-bd1d-4c98-b88e-00a5c2d5e027-0000
3: I1118 00:53:22.511173 18307 master.cpp:9502] Updating the state of task b55899ae-818d-4fc1-abce-cb700fc4ef30 of framework 8545d424-bd1d-4c98-b88e-00a5c2d5e027-0000 (latest state: TASK_RUNNING, status update state: TASK_RUNNING)
3: I1118 00:53:22.513242 18300 scheduler.cpp:249] Sending ACKNOWLEDGE call to http://172.17.0.4:45533/master/api/v1/scheduler
3: I1118 00:53:22.515055 18299 process.cpp:3932] Handling HTTP event for process 'master' with path: '/master/api/v1/scheduler'
3: *** SIGSEGV (@0xf0) received by PID 18291 (TID 0x2b7ae9830700) from PID 240; stack trace: ***
3: @ 0x2b7adcd96330 (unknown)
3: @ 0x2b7ae11b882d (unknown)
3: @ 0x2b7ae11ae6f1 (unknown)
3: @ 0x2b7ae1205c9e (unknown)
3: I1118 00:53:22.552978 18309 http.cpp:1185] HTTP POST for /master/api/v1/scheduler from 172.17.0.4:53406
3: I1118 00:53:22.553330 18309 master.cpp:5791] Processing ACKNOWLEDGE call 2431691f-1040-438c-96b0-efd00ae28c1b for task 3e97fc6e-7bc4-4125-a41c-8596e3c8e71a of framework 8545d424-bd1d-4c98-b88e-00a5c2d5e027-0000 (default) on agent 8545d424-bd1d-4c98-b88e-00a5c2d5e027-S0
3: I1118 00:53:22.553743 18314 status_update_manager.cpp:395] Received status update acknowledgement (UUID: 2431691f-1040-438c-96b0-efd00ae28c1b) for task 3e97fc6e-7bc4-4125-a41c-8596e3c8e71a of framework 8545d424-bd1d-4c98-b88e-00a5c2d5e027-0000
3: I1118 00:53:22.554121 18313 slave.cpp:3801] Status update manager successfully handled status update acknowledgement (UUID: 2431691f-1040-438c-96b0-efd00ae28c1b) for task 3e97fc6e-7bc4-4125-a41c-8596e3c8e71a of framework 8545d424-bd1d-4c98-b88e-00a5c2d5e027-0000
3: @ 0xabbee5 os::strerror()
3: @ 0xabbe41 ErrnoError::ErrnoError()
3: @ 0xabbe04 ErrnoError::ErrnoError()
3: @ 0x2b7adbfd3a47 process::io::internal::read()::$_3::operator()()
3: @ 0x2b7adbfd2ba6 process::internal::Loop<>::start()
3: @ 0x2b7adbfb063d process::loop<>()
3: @ 0x2b7adbfb0553 process::io::internal::read()
3: @ 0x2b7adbfb0bdc process::io::read()
3: @ 0x2b7adc05230e process::network::internal::PollSocketImpl::recv()
3: @ 0x2b7adc1a5a29 process::network::internal::SocketImpl::recv()
3: @ 0x2b7adbf6fb2e process::network::internal::Socket<>::recv()
3: @ 0x2b7adbf6f97b process::http::internal::ConnectionProcess::read()
3: @ 0x2b7adbf70bdc process::http::internal::ConnectionProcess::_read()
3: @ 0x2b7adbf74ba0 _ZZN7process8dispatchINS_4http8internal17ConnectionProcessERKNS_6FutureISsEES7_EEvRKNS_3PIDIT_EEMS9_FvT0_EOT1_ENKUlRS5_PNS_11ProcessBaseEE_clESI_SK_
3: @ 0x2b7adbf74a25 _ZNSt5_BindIFZN7process8dispatchINS0_4http8internal17ConnectionProcessERKNS0_6FutureISsEES8_EEvRKNS0_3PIDIT_EEMSA_FvT0_EOT1_EUlRS6_PNS0_11ProcessBaseEE_S6_St12_PlaceholderILi1EEEE6__callIvJOSL_EJLm0ELm1EEEESA_OSt5tupleIJDpT0_EESt12_Index_tupleIJXspT1_EEE
3: @ 0x2b7adbf74986 _ZNSt5_BindIFZN7process8dispatchINS0_4http8internal17ConnectionProcessERKNS0_6FutureISsEES8_EEvRKNS0_3PIDIT_EEMSA_FvT0_EOT1_EUlRS6_PNS0_11ProcessBaseEE_S6_St12_PlaceholderILi1EEEEclIJSL_EvEESE_DpOT_
3: @ 0x2b7adbf7462f _ZNSt17_Function_handlerIFvPN7process11ProcessBaseEESt5_BindIFZNS0_8dispatchINS0_4http8internal17ConnectionProcessERKNS0_6FutureISsEESC_EEvRKNS0_3PIDIT_EEMSE_FvT0_EOT1_EUlRSA_S2_E_SA_St12_PlaceholderILi1EEEEE9_M_invokeERKSt9_Any_dataS2_
3: @ 0x2b7adc0b4134 std::function<>::operator()()
3: @ 0x2b7adc095fd4 process::ProcessBase::visit()
3: @ 0x2b7adc14c44e process::DispatchEvent::visit()
3: @ 0xb074a1 process::ProcessBase::serve()
3: @ 0x2b7adc093772 process::ProcessManager::resume()
3: @ 0x2b7adc0a3801 process::ProcessManager::init_threads()::$_9::operator()()
3: @ 0x2b7adc0a3745 _ZNSt12_Bind_simpleIFZN7process14ProcessManager12init_threadsEvE3$_9vEE9_M_invokeIJEEEvSt12_Index_tupleIJXspT_EEE
3: @ 0x2b7adc0a3715 std::_Bind_simple<>::operator()()
3: @ 0x2b7adc0a36ec std::thread::_Impl<>::_M_run()
3: @ 0x2b7ae0a0ea60 (unknown)
3: @ 0x2b7adcd8e184 start_thread
3/3 Test #3: MesosTests .......................***Exception: SegFault 69.41 sec
67% tests passed, 1 tests failed out of 3
Total Test time (real) = 109.60 sec
The following tests FAILED:
3 - MesosTests (SEGFAULT)
Errors while running CTest
make[3]: *** [CMakeFiles/check] Error 8
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-1510964846-8027
Untagged: mesos-1510964846-8027:latest
Deleted: sha256:f5eddd2c05830b9f34fee624bf0d52b3927931700aec92c2584c7d79b3bb64d2
Deleted: sha256:436861642f0d995f5d5e2ff9281e0d32d4c1d03c7f33a212669bc7caf4cab3a1
Deleted: sha256:85adae9da19e434699a7c966bc3e39ecb270e5ec0b4c2a8169e74c8b370a933a
Deleted: sha256:c57adc5b2bf22bf91dafaba2ec912dea0f70aa00bfd9994e70601de6f36b4a48
Deleted: sha256:b4ed032d2c76cbf877bb945acafc5a6d0348a65f96deeafdb376891deb313203
Deleted: sha256:8c9ed8ed41719d4040856f9a96aeddfb4635ebaf08761bd6346d39eba5d068da
Deleted: sha256:47e57f05332e03c5d2a0f3737ac7082333ca69e00f3e9725bdd98812376f3e1f
Deleted: sha256:03b1893124108eaea525c8cfd2a45e8a5d6bf6865edfa9f39a57db8b7bfe5002
Deleted: sha256:1986be2fa9089ca90deb95363a860bf48e56b33eb3e5a7740fcb3181fb6225bf
Deleted: sha256:f9fcdbe03df138c1e0f9c7cf9ccc35fcd61d0c6743be6893c015c2d420bb8b89
Deleted: sha256:c586bdbfd406b7cd8c9df8136af472c892af60c04d50fcfe7acfe5e46ed23b0c
Deleted: sha256:b1c31b069894e43a022df6a260f447b5dca4ed547e6d59ff92339d5250c77285
Deleted: sha256:3c58d151b17c6c3214534a04b2e5eed18a5ef39b33927ce8ef0de0993ce8d7dc
Deleted: sha256:6fe2cae57940c69c024375d3f074d974af56d6c2459385680282a6dd0862a599
Deleted: sha256:2fae0b312a3d48d47eb87d57ee17a4d64143e6d4c6b8bb831217bb89c9100cdb
Deleted: sha256:7769b94b72e504ea5ab4196b3f1b78b7f88635ea6ae4a13f94cdbeedf47da7ab
Deleted: sha256:9befdcbb90077bc3e201be672d05eeda1353072ecf152027bf91eadb667368e1
Deleted: sha256:2aa1b5ffafe06986743aca5332e65d281d7968c327abc2b68b2f72594097b0d9
Deleted: sha256:4fdb69e23b6a39f1a61e03bc21185c4fb7bb5eac79d7d8a35c8ea6adff509f8e
Deleted: sha256:1b5250c549c0f0832e15fe9ce0152cddb44e239c40fce02fcf454356b22e462f
Deleted: sha256:168145ce6f1f92f2853a20de37dcd566d21f2ba74f0fc019e2dd41732380c1e1
Deleted: sha256:d6de0c5d26ae982d0c6d3076abe6e7eb96db56f0675283d0edf905aa836ad0e9
Deleted: sha256:e13f432c232966578e1413327b43c390a12b343b477b4169edc8a6d9797d6cb9
Deleted: sha256:1cd87731e41bd718c29ec87c72563908934694ca9ed65b84d50773970c929f61
Deleted: sha256:3ba217826c4ecbf536448b3e70dfb193dc4b3e582b52847529d7d3298815ba86
Deleted: sha256:5c9b2fef43a1b577765dfab68d416b3ec6b49cd2a60c3af2ea071bcbd3f29b21
Deleted: sha256:c22959bcf27489850437fac864cedc453b89c894bf53a582d15df6ec59b9df97
Deleted: sha256:5bdfca3511d761218859c4a4c50eefbc532c8ef88073290365c98de6eedf95b5
Deleted: sha256:9e727500194182b1a3b12329aa6627674d024f6000c7b5bb23fc27f622745a00
Deleted: sha256:e3534acf4f2b11d57f311505da265831a9536aed59e7922ab433a1b7eb354ded
Build step 'Execute shell' marked build as failure
Not sending mail to unregistered user xujyan@apple.com
Build failed in Jenkins: Mesos-Buildbot » cmake,clang,--verbose --disable-libtool-wrappers --enable-libevent --enable-ssl,GLOG_v=1 MESOS_VERBOSE=1,ubuntu:14.04,(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)&&(!qnode3)&&(!H23) #4469
Posted by Apache Jenkins Server <je...@builds.apache.org>.
See <https://builds.apache.org/job/Mesos-Buildbot/BUILDTOOL=cmake,COMPILER=clang,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)/4469/display/redirect?page=changes>
Changes:
[xujyan] Downgraded the logging level of socket shutdown failures.
------------------------------------------
[...truncated 3.93 MB...]
3: I1117 19:44:42.324316 18301 gc.cpp:90] Scheduling '/tmp/GarbageCollectorIntegrationTest_ExitedExecutor_NiYrdE/slaves/0a0c937e-b503-42d7-849f-dc69b51335d9-S0/frameworks/0a0c937e-b503-42d7-849f-dc69b51335d9-0000/executors/default' for gc 6.99999632762667days in the future
3: I1117 19:44:42.324421 18301 gc.cpp:90] Scheduling '/tmp/GarbageCollectorIntegrationTest_ExitedExecutor_NiYrdE/slaves/0a0c937e-b503-42d7-849f-dc69b51335d9-S0/frameworks/0a0c937e-b503-42d7-849f-dc69b51335d9-0000' for gc 6.99999632762667days in the future
3: I1117 19:44:42.325963 18311 slave.cpp:5966] Framework 0a0c937e-b503-42d7-849f-dc69b51335d9-0000 seems to have exited. Ignoring registration timeout for executor 'default'
3: I1117 19:44:42.326037 18295 gc.cpp:208] Deleting /tmp/GarbageCollectorIntegrationTest_ExitedExecutor_NiYrdE/slaves/0a0c937e-b503-42d7-849f-dc69b51335d9-S0/frameworks/0a0c937e-b503-42d7-849f-dc69b51335d9-0000/executors/default/runs/d93ea47a-48c0-47ec-8ac4-a11225f663ee
3: I1117 19:44:42.326081 18302 master.cpp:1881] Skipping periodic registry garbage collection: no agents qualify for removal
3: I1117 19:44:42.326279 18311 slave.cpp:6058] Current disk usage 19.86%. Max allowed age: 4.909499922442871days
3: I1117 19:44:42.326313 18295 gc.cpp:218] Deleted '/tmp/GarbageCollectorIntegrationTest_ExitedExecutor_NiYrdE/slaves/0a0c937e-b503-42d7-849f-dc69b51335d9-S0/frameworks/0a0c937e-b503-42d7-849f-dc69b51335d9-0000/executors/default/runs/d93ea47a-48c0-47ec-8ac4-a11225f663ee'
3: I1117 19:44:42.326438 18295 gc.cpp:208] Deleting /tmp/GarbageCollectorIntegrationTest_ExitedExecutor_NiYrdE/slaves/0a0c937e-b503-42d7-849f-dc69b51335d9-S0/frameworks/0a0c937e-b503-42d7-849f-dc69b51335d9-0000/executors/default
3: I1117 19:44:42.326443 18305 gc.cpp:263] Pruning directories with remaining removal time 0ns
3: I1117 19:44:42.326588 18305 gc.cpp:183] Skipping deletion of '/tmp/GarbageCollectorIntegrationTest_ExitedExecutor_NiYrdE/slaves/0a0c937e-b503-42d7-849f-dc69b51335d9-S0/frameworks/0a0c937e-b503-42d7-849f-dc69b51335d9-0000/executors/default/runs/d93ea47a-48c0-47ec-8ac4-a11225f663ee' as it is already in progress
3: I1117 19:44:42.326614 18305 gc.cpp:183] Skipping deletion of '/tmp/GarbageCollectorIntegrationTest_ExitedExecutor_NiYrdE/slaves/0a0c937e-b503-42d7-849f-dc69b51335d9-S0/frameworks/0a0c937e-b503-42d7-849f-dc69b51335d9-0000/executors/default' as it is already in progress
3: I1117 19:44:42.326627 18305 gc.cpp:183] Skipping deletion of '/tmp/GarbageCollectorIntegrationTest_ExitedExecutor_NiYrdE/slaves/0a0c937e-b503-42d7-849f-dc69b51335d9-S0/frameworks/0a0c937e-b503-42d7-849f-dc69b51335d9-0000' as it is already in progress
3: I1117 19:44:42.326756 18295 gc.cpp:218] Deleted '/tmp/GarbageCollectorIntegrationTest_ExitedExecutor_NiYrdE/slaves/0a0c937e-b503-42d7-849f-dc69b51335d9-S0/frameworks/0a0c937e-b503-42d7-849f-dc69b51335d9-0000/executors/default'
3: I1117 19:44:42.326850 18295 gc.cpp:208] Deleting /tmp/GarbageCollectorIntegrationTest_ExitedExecutor_NiYrdE/slaves/0a0c937e-b503-42d7-849f-dc69b51335d9-S0/frameworks/0a0c937e-b503-42d7-849f-dc69b51335d9-0000
3: I1117 19:44:42.327111 18295 gc.cpp:218] Deleted '/tmp/GarbageCollectorIntegrationTest_ExitedExecutor_NiYrdE/slaves/0a0c937e-b503-42d7-849f-dc69b51335d9-S0/frameworks/0a0c937e-b503-42d7-849f-dc69b51335d9-0000'
3: I1117 19:44:42.327409 18293 hierarchical.cpp:1450] Performed allocation for 1 agents in 1.330671ms
3: I1117 19:44:42.328150 18312 master.cpp:8115] Sending 1 offers to framework 0a0c937e-b503-42d7-849f-dc69b51335d9-0000 (default) at scheduler-1a556d16-16c7-492f-aac1-260c7e6d24de@172.17.0.2:33183
3: I1117 19:44:42.328673 18291 sched.cpp:921] Scheduler::resourceOffers took 30133ns
3: I1117 19:44:42.331784 18304 process.cpp:3932] Handling HTTP event for process 'files' with path: '/files/browse'
3: I1117 19:44:42.333365 18292 http.cpp:1185] HTTP GET for /files/browse?path=%2Ftmp%2FGarbageCollectorIntegrationTest_ExitedExecutor_NiYrdE%2Fslaves%2F0a0c937e-b503-42d7-849f-dc69b51335d9-S0%2Fframeworks%2F0a0c937e-b503-42d7-849f-dc69b51335d9-0000%2Fexecutors%2Fdefault from 172.17.0.2:33998
3: I1117 19:44:42.341603 18299 process.cpp:3932] Handling HTTP event for process 'files' with path: '/files/browse'
3: I1117 19:44:42.342913 18298 http.cpp:1185] HTTP GET for /files/browse?path=%2Ftmp%2FGarbageCollectorIntegrationTest_ExitedExecutor_NiYrdE%2Fslaves%2F0a0c937e-b503-42d7-849f-dc69b51335d9-S0%2Fframeworks%2F0a0c937e-b503-42d7-849f-dc69b51335d9-0000%2Fexecutors%2Fdefault%2Fruns%2Flatest from 172.17.0.2:34000
3: I1117 19:44:42.350323 18290 sched.cpp:2009] Asked to stop the driver
3: I1117 19:44:42.350463 18313 sched.cpp:1191] Stopping framework 0a0c937e-b503-42d7-849f-dc69b51335d9-0000
3: I1117 19:44:42.350960 18304 master.cpp:8792] Processing TEARDOWN call for framework 0a0c937e-b503-42d7-849f-dc69b51335d9-0000 (default) at scheduler-1a556d16-16c7-492f-aac1-260c7e6d24de@172.17.0.2:33183
3: I1117 19:44:42.351013 18304 master.cpp:8804] Removing framework 0a0c937e-b503-42d7-849f-dc69b51335d9-0000 (default) at scheduler-1a556d16-16c7-492f-aac1-260c7e6d24de@172.17.0.2:33183
3: I1117 19:44:42.351042 18304 master.cpp:3331] Deactivating framework 0a0c937e-b503-42d7-849f-dc69b51335d9-0000 (default) at scheduler-1a556d16-16c7-492f-aac1-260c7e6d24de@172.17.0.2:33183
3: I1117 19:44:42.351258 18292 hierarchical.cpp:412] Deactivated framework 0a0c937e-b503-42d7-849f-dc69b51335d9-0000
3: I1117 19:44:42.352150 18304 master.cpp:10024] Removing offer 0a0c937e-b503-42d7-849f-dc69b51335d9-O1
3: I1117 19:44:42.352406 18313 slave.cpp:3267] Asked to shut down framework 0a0c937e-b503-42d7-849f-dc69b51335d9-0000 by master@172.17.0.2:33183
3: I1117 19:44:42.352443 18313 slave.cpp:3282] Cannot shut down unknown framework 0a0c937e-b503-42d7-849f-dc69b51335d9-0000
3: I1117 19:44:42.352696 18303 hierarchical.cpp:1125] 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 0a0c937e-b503-42d7-849f-dc69b51335d9-S0 from framework 0a0c937e-b503-42d7-849f-dc69b51335d9-0000
3: I1117 19:44:42.352788 18293 slave.cpp:883] Agent terminating
3: I1117 19:44:42.352970 18311 master.cpp:1309] Agent 0a0c937e-b503-42d7-849f-dc69b51335d9-S0 at slave(63)@172.17.0.2:33183 (ed775a6760c9) disconnected
3: I1117 19:44:42.353001 18311 master.cpp:3368] Disconnecting agent 0a0c937e-b503-42d7-849f-dc69b51335d9-S0 at slave(63)@172.17.0.2:33183 (ed775a6760c9)
3: I1117 19:44:42.353066 18311 master.cpp:3387] Deactivating agent 0a0c937e-b503-42d7-849f-dc69b51335d9-S0 at slave(63)@172.17.0.2:33183 (ed775a6760c9)
3: I1117 19:44:42.353158 18303 hierarchical.cpp:355] Removed framework 0a0c937e-b503-42d7-849f-dc69b51335d9-0000
3: I1117 19:44:42.353229 18303 hierarchical.cpp:690] Agent 0a0c937e-b503-42d7-849f-dc69b51335d9-S0 deactivated
3: I1117 19:44:42.357669 18290 master.cpp:1151] Master terminating
3: I1117 19:44:42.359021 18305 hierarchical.cpp:626] Removed agent 0a0c937e-b503-42d7-849f-dc69b51335d9-S0
3: [ OK ] GarbageCollectorIntegrationTest.ExitedExecutor (133 ms)
3: [ RUN ] GarbageCollectorIntegrationTest.DiskUsage
3: I1117 19:44:42.367640 18290 cluster.cpp:162] Creating default 'local' authorizer
3: I1117 19:44:42.371377 18301 master.cpp:448] Master 6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3 (ed775a6760c9) started on 172.17.0.2:33183
3: I1117 19:44:42.371448 18301 master.cpp:450] 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/NO5Jjj/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/NO5Jjj/master" --zk_session_timeout="10secs"
3: I1117 19:44:42.372038 18301 master.cpp:499] Master only allowing authenticated frameworks to register
3: I1117 19:44:42.372051 18301 master.cpp:505] Master only allowing authenticated agents to register
3: I1117 19:44:42.372059 18301 master.cpp:511] Master only allowing authenticated HTTP frameworks to register
3: I1117 19:44:42.372069 18301 credentials.hpp:37] Loading credentials for authentication from '/tmp/NO5Jjj/credentials'
3: I1117 19:44:42.372552 18301 master.cpp:555] Using default 'crammd5' authenticator
3: I1117 19:44:42.372815 18301 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly'
3: I1117 19:44:42.373070 18301 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite'
3: I1117 19:44:42.373255 18301 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler'
3: I1117 19:44:42.373478 18301 master.cpp:634] Authorization enabled
3: I1117 19:44:42.373739 18296 hierarchical.cpp:171] Initialized hierarchical allocator process
3: I1117 19:44:42.373766 18295 whitelist_watcher.cpp:77] No whitelist given
3: I1117 19:44:42.379053 18293 master.cpp:2213] Elected as the leading master!
3: I1117 19:44:42.379097 18293 master.cpp:1693] Recovering from registrar
3: I1117 19:44:42.379325 18306 registrar.cpp:347] Recovering registrar
3: I1117 19:44:42.380815 18309 registrar.cpp:391] Successfully fetched the registry (0B) in 1.415168ms
3: I1117 19:44:42.381080 18309 registrar.cpp:495] Applied 1 operations in 93561ns; attempting to update the registry
3: I1117 19:44:42.382089 18309 registrar.cpp:552] Successfully updated the registry in 894976ns
3: I1117 19:44:42.382282 18309 registrar.cpp:424] Successfully recovered registrar
3: I1117 19:44:42.382781 18300 master.cpp:1806] Recovered 0 agents from the registry (129B); allowing 10mins for agents to re-register
3: I1117 19:44:42.382809 18295 hierarchical.cpp:209] Skipping recovery of hierarchical allocator: nothing to recover
3: W1117 19:44:42.389235 18290 process.cpp:3185] Attempted to spawn already running process files@172.17.0.2:33183
3: I1117 19:44:42.389633 18290 cluster.cpp:448] Creating default 'local' authorizer
3: I1117 19:44:42.392227 18310 slave.cpp:262] Mesos agent started on (64)@172.17.0.2:33183
3: I1117 19:44:42.392289 18310 slave.cpp:263] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/GarbageCollectorIntegrationTest_DiskUsage_v4ubj9/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/GarbageCollectorIntegrationTest_DiskUsage_v4ubj9/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/GarbageCollectorIntegrationTest_DiskUsage_v4ubj9/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_secret_key="/tmp/GarbageCollectorIntegrationTest_DiskUsage_v4ubj9/executor_secret_key" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/GarbageCollectorIntegrationTest_DiskUsage_v4ubj9/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/GarbageCollectorIntegrationTest_DiskUsage_v4ubj9/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/GarbageCollectorIntegrationTest_DiskUsage_v4ubj9" --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/GarbageCollectorIntegrationTest_DiskUsage_Ix1rjJ" --zk_session_timeout="10secs"
3: I1117 19:44:42.393242 18310 credentials.hpp:86] Loading credential for authentication from '/tmp/GarbageCollectorIntegrationTest_DiskUsage_v4ubj9/credential'
3: I1117 19:44:42.393618 18310 slave.cpp:295] Agent using credential for: test-principal
3: I1117 19:44:42.393656 18310 credentials.hpp:37] Loading credentials for authentication from '/tmp/GarbageCollectorIntegrationTest_DiskUsage_v4ubj9/http_credentials'
3: I1117 19:44:42.394209 18310 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-executor'
3: I1117 19:44:42.394454 18310 http.cpp:1066] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-executor'
3: I1117 19:44:42.394841 18310 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly'
3: I1117 19:44:42.395015 18310 http.cpp:1066] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readonly'
3: I1117 19:44:42.395325 18310 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readwrite'
3: I1117 19:44:42.395481 18310 http.cpp:1066] Creating default 'jwt' HTTP authenticator for realm 'mesos-agent-readwrite'
3: I1117 19:44:42.398730 18310 slave.cpp:593] 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: I1117 19:44:42.399175 18310 slave.cpp:601] Agent attributes: [ ]
3: I1117 19:44:42.399202 18310 slave.cpp:610] Agent hostname: ed775a6760c9
3: I1117 19:44:42.399408 18308 status_update_manager.cpp:177] Pausing sending status updates
3: I1117 19:44:42.402468 18312 state.cpp:64] Recovering state from '/tmp/GarbageCollectorIntegrationTest_DiskUsage_Ix1rjJ/meta'
3: I1117 19:44:42.402832 18312 status_update_manager.cpp:203] Recovering status update manager
3: I1117 19:44:42.403270 18292 slave.cpp:6441] Finished recovery
3: I1117 19:44:42.404253 18307 status_update_manager.cpp:177] Pausing sending status updates
3: I1117 19:44:42.404304 18292 slave.cpp:1007] New master detected at master@172.17.0.2:33183
3: I1117 19:44:42.404467 18292 slave.cpp:1042] Detecting new master
3: I1117 19:44:42.410651 18299 slave.cpp:1069] Authenticating with master master@172.17.0.2:33183
3: I1117 19:44:42.410727 18299 slave.cpp:1078] Using default CRAM-MD5 authenticatee
3: I1117 19:44:42.410985 18297 authenticatee.cpp:121] Creating new client SASL connection
3: I1117 19:44:42.411407 18313 master.cpp:8285] Authenticating slave(64)@172.17.0.2:33183
3: I1117 19:44:42.411578 18301 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(146)@172.17.0.2:33183
3: I1117 19:44:42.412060 18308 authenticator.cpp:98] Creating new server SASL connection
3: I1117 19:44:42.412443 18304 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
3: I1117 19:44:42.412473 18304 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
3: I1117 19:44:42.412608 18293 authenticator.cpp:204] Received SASL authentication start
3: I1117 19:44:42.412672 18293 authenticator.cpp:326] Authentication requires more steps
3: I1117 19:44:42.412778 18293 authenticatee.cpp:259] Received SASL authentication step
3: I1117 19:44:42.412957 18306 authenticator.cpp:232] Received SASL authentication step
3: I1117 19:44:42.413017 18306 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'ed775a6760c9' server FQDN: 'ed775a6760c9' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
3: I1117 19:44:42.413049 18306 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
3: I1117 19:44:42.413126 18306 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
3: I1117 19:44:42.413177 18306 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'ed775a6760c9' server FQDN: 'ed775a6760c9' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
3: I1117 19:44:42.413203 18306 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
3: I1117 19:44:42.413223 18306 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
3: I1117 19:44:42.413260 18306 authenticator.cpp:318] Authentication success
3: I1117 19:44:42.413481 18298 authenticatee.cpp:299] Authentication success
3: I1117 19:44:42.413624 18302 master.cpp:8315] Successfully authenticated principal 'test-principal' at slave(64)@172.17.0.2:33183
3: I1117 19:44:42.414011 18311 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(146)@172.17.0.2:33183
3: I1117 19:44:42.414058 18310 slave.cpp:1161] Successfully authenticated with master master@172.17.0.2:33183
3: I1117 19:44:42.414618 18310 slave.cpp:1682] Will retry registration in 17.131645ms if necessary
3: I1117 19:44:42.415033 18309 master.cpp:6032] Received register agent message from slave(64)@172.17.0.2:33183 (ed775a6760c9)
3: I1117 19:44:42.415096 18309 master.cpp:3870] Authorizing agent with principal 'test-principal'
3: I1117 19:44:42.415843 18294 master.cpp:6092] Authorized registration of agent at slave(64)@172.17.0.2:33183 (ed775a6760c9)
3: I1117 19:44:42.416043 18294 master.cpp:6185] Registering agent at slave(64)@172.17.0.2:33183 (ed775a6760c9) with id 6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-S0
3: I1117 19:44:42.416623 18296 registrar.cpp:495] Applied 1 operations in 140284ns; attempting to update the registry
3: I1117 19:44:42.417647 18296 registrar.cpp:552] Successfully updated the registry in 911872ns
3: I1117 19:44:42.418017 18313 master.cpp:6232] Admitted agent 6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-S0 at slave(64)@172.17.0.2:33183 (ed775a6760c9)
3: I1117 19:44:42.419312 18313 master.cpp:6263] Registered agent 6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-S0 at slave(64)@172.17.0.2:33183 (ed775a6760c9) with [{"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: I1117 19:44:42.419674 18308 slave.cpp:1207] Registered with master master@172.17.0.2:33183; given agent ID 6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-S0
3: I1117 19:44:42.419865 18302 status_update_manager.cpp:184] Resuming sending status updates
3: I1117 19:44:42.419919 18304 hierarchical.cpp:593] Added agent 6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-S0 (ed775a6760c9) with cpus:2; mem:1024; disk:1024; ports:[31000-32000] (allocated: {})
3: I1117 19:44:42.420418 18304 hierarchical.cpp:1450] Performed allocation for 1 agents in 254868ns
3: I1117 19:44:42.420543 18308 slave.cpp:1227] Checkpointing SlaveInfo to '/tmp/GarbageCollectorIntegrationTest_DiskUsage_Ix1rjJ/meta/slaves/6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-S0/slave.info'
3: W1117 19:44:42.421103 18290 process.cpp:3185] Attempted to spawn already running process version@172.17.0.2:33183
3: I1117 19:44:42.421296 18308 slave.cpp:1295] Forwarding total oversubscribed resources {}
3: I1117 19:44:42.421744 18312 master.cpp:7064] Received update of agent 6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-S0 at slave(64)@172.17.0.2:33183 (ed775a6760c9) with total oversubscribed resources {}
3: I1117 19:44:42.422194 18312 master.cpp:7082] Ignoring update on agent 6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-S0 at slave(64)@172.17.0.2:33183 (ed775a6760c9) as it reports no changes
3: I1117 19:44:42.423605 18290 sched.cpp:232] Version: 1.5.0
3: I1117 19:44:42.424561 18292 sched.cpp:336] New master detected at master@172.17.0.2:33183
3: I1117 19:44:42.424691 18292 sched.cpp:396] Authenticating with master master@172.17.0.2:33183
3: I1117 19:44:42.424715 18292 sched.cpp:403] Using default CRAM-MD5 authenticatee
3: I1117 19:44:42.425077 18307 authenticatee.cpp:121] Creating new client SASL connection
3: I1117 19:44:42.425544 18299 master.cpp:8285] Authenticating scheduler-61f76c1c-ca30-4c2a-b1aa-72aacf0d19c0@172.17.0.2:33183
3: I1117 19:44:42.425680 18297 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(147)@172.17.0.2:33183
3: I1117 19:44:42.425961 18296 authenticator.cpp:98] Creating new server SASL connection
3: I1117 19:44:42.426285 18301 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
3: I1117 19:44:42.426342 18301 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
3: I1117 19:44:42.426532 18291 authenticator.cpp:204] Received SASL authentication start
3: I1117 19:44:42.426643 18291 authenticator.cpp:326] Authentication requires more steps
3: I1117 19:44:42.426868 18313 authenticatee.cpp:259] Received SASL authentication step
3: I1117 19:44:42.427088 18305 authenticator.cpp:232] Received SASL authentication step
3: I1117 19:44:42.427147 18305 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'ed775a6760c9' server FQDN: 'ed775a6760c9' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
3: I1117 19:44:42.427179 18305 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
3: I1117 19:44:42.427253 18305 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
3: I1117 19:44:42.427307 18305 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'ed775a6760c9' server FQDN: 'ed775a6760c9' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
3: I1117 19:44:42.427337 18305 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
3: I1117 19:44:42.427353 18305 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
3: I1117 19:44:42.427384 18305 authenticator.cpp:318] Authentication success
3: I1117 19:44:42.427649 18293 master.cpp:8315] Successfully authenticated principal 'test-principal' at scheduler-61f76c1c-ca30-4c2a-b1aa-72aacf0d19c0@172.17.0.2:33183
3: I1117 19:44:42.427698 18302 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(147)@172.17.0.2:33183
3: I1117 19:44:42.427724 18313 authenticatee.cpp:299] Authentication success
3: I1117 19:44:42.428136 18293 sched.cpp:502] Successfully authenticated with master master@172.17.0.2:33183
3: I1117 19:44:42.428175 18293 sched.cpp:824] Sending SUBSCRIBE call to master@172.17.0.2:33183
3: I1117 19:44:42.428390 18293 sched.cpp:857] Will retry registration in 1.118481905secs if necessary
3: I1117 19:44:42.428692 18312 master.cpp:2961] Received SUBSCRIBE call for framework 'default' at scheduler-61f76c1c-ca30-4c2a-b1aa-72aacf0d19c0@172.17.0.2:33183
3: I1117 19:44:42.428731 18312 master.cpp:2278] Authorizing framework principal 'test-principal' to receive offers for roles '{ * }'
3: I1117 19:44:42.429538 18311 master.cpp:3041] Subscribing framework default with checkpointing disabled and capabilities [ RESERVATION_REFINEMENT ]
3: I1117 19:44:42.430573 18310 sched.cpp:751] Framework registered with 6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-0000
3: I1117 19:44:42.430725 18310 sched.cpp:765] Scheduler::registered took 120257ns
3: I1117 19:44:42.430817 18309 hierarchical.cpp:303] Added framework 6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-0000
3: I1117 19:44:42.432708 18309 hierarchical.cpp:1450] Performed allocation for 1 agents in 1.645254ms
3: I1117 19:44:42.433480 18291 master.cpp:8115] Sending 1 offers to framework 6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-0000 (default) at scheduler-61f76c1c-ca30-4c2a-b1aa-72aacf0d19c0@172.17.0.2:33183
3: I1117 19:44:42.435371 18305 sched.cpp:921] Scheduler::resourceOffers took 1.272652ms
3: I1117 19:44:42.437239 18303 master.cpp:10024] Removing offer 6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-O0
3: I1117 19:44:42.437516 18303 master.cpp:4228] Processing ACCEPT call for offers: [ 6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-O0 ] on agent 6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-S0 at slave(64)@172.17.0.2:33183 (ed775a6760c9) for framework 6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-0000 (default) at scheduler-61f76c1c-ca30-4c2a-b1aa-72aacf0d19c0@172.17.0.2:33183
3: I1117 19:44:42.437690 18303 master.cpp:3597] Authorizing framework principal 'test-principal' to launch task 0
3: W1117 19:44:42.440263 18302 validation.cpp:1391] Executor 'default' for task '0' uses less CPUs (None) than the minimum required (0.01). Please update your executor, as this will be mandatory in future releases.
3: W1117 19:44:42.440316 18302 validation.cpp:1403] Executor 'default' for task '0' uses less memory (None) than the minimum required (32MB). Please update your executor, as this will be mandatory in future releases.
3: I1117 19:44:42.440935 18302 master.cpp:10770] Adding task 0 with resources [{"allocation_info":{"role":"*"},"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"}] on agent 6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-S0 at slave(64)@172.17.0.2:33183 (ed775a6760c9)
3: I1117 19:44:42.441613 18302 master.cpp:4976] Launching task 0 of framework 6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-0000 (default) at scheduler-61f76c1c-ca30-4c2a-b1aa-72aacf0d19c0@172.17.0.2:33183 with resources [{"allocation_info":{"role":"*"},"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"}] on agent 6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-S0 at slave(64)@172.17.0.2:33183 (ed775a6760c9)
3: I1117 19:44:42.442507 18308 slave.cpp:1803] Got assigned task '0' for framework 6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-0000
3: I1117 19:44:42.443538 18308 slave.cpp:2071] Authorizing task '0' for framework 6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-0000
3: I1117 19:44:42.443640 18308 slave.cpp:7262] Authorizing framework principal 'test-principal' to launch task 0
3: I1117 19:44:42.443931 18293 hierarchical.cpp:1125] Recovered ports(allocated: *):[31000-32000]; disk(allocated: *):1024 (total: cpus:2; mem:1024; disk:1024; ports:[31000-32000], allocated: cpus(allocated: *):2; mem(allocated: *):1024) on agent 6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-S0 from framework 6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-0000
3: I1117 19:44:42.444085 18293 hierarchical.cpp:1171] Framework 6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-0000 filtered agent 6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-S0 for 5secs
3: I1117 19:44:42.444896 18311 slave.cpp:2239] Launching task '0' for framework 6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-0000
3: I1117 19:44:42.445885 18311 paths.cpp:621] Trying to chown '/tmp/GarbageCollectorIntegrationTest_DiskUsage_Ix1rjJ/slaves/6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-S0/frameworks/6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-0000/executors/default/runs/7bc1e39b-cbdf-43ae-b2b6-735d30a7d7c3' to user 'mesos'
3: I1117 19:44:42.446295 18311 slave.cpp:7736] Launching executor 'default' of framework 6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-0000 with resources [] in work directory '/tmp/GarbageCollectorIntegrationTest_DiskUsage_Ix1rjJ/slaves/6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-S0/frameworks/6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-0000/executors/default/runs/7bc1e39b-cbdf-43ae-b2b6-735d30a7d7c3'
3: I1117 19:44:42.447585 18311 slave.cpp:2467] Queued task '0' for executor 'default' of framework 6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-0000
3: I1117 19:44:42.447739 18311 slave.cpp:958] Successfully attached '/tmp/GarbageCollectorIntegrationTest_DiskUsage_Ix1rjJ/slaves/6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-S0/frameworks/6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-0000/executors/default/runs/7bc1e39b-cbdf-43ae-b2b6-735d30a7d7c3' to virtual path '/tmp/GarbageCollectorIntegrationTest_DiskUsage_Ix1rjJ/slaves/6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-S0/frameworks/6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-0000/executors/default/runs/latest'
3: I1117 19:44:42.447824 18311 slave.cpp:958] Successfully attached '/tmp/GarbageCollectorIntegrationTest_DiskUsage_Ix1rjJ/slaves/6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-S0/frameworks/6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-0000/executors/default/runs/7bc1e39b-cbdf-43ae-b2b6-735d30a7d7c3' to virtual path '/frameworks/6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-0000/executors/default/runs/latest'
3: I1117 19:44:42.448232 18311 slave.cpp:2930] Launching container 7bc1e39b-cbdf-43ae-b2b6-735d30a7d7c3 for executor 'default' of framework 6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-0000
3: I1117 19:44:42.448658 18311 slave.cpp:958] Successfully attached '/tmp/GarbageCollectorIntegrationTest_DiskUsage_Ix1rjJ/slaves/6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-S0/frameworks/6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-0000/executors/default/runs/7bc1e39b-cbdf-43ae-b2b6-735d30a7d7c3' to virtual path '/tmp/GarbageCollectorIntegrationTest_DiskUsage_Ix1rjJ/slaves/6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-S0/frameworks/6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-0000/executors/default/runs/7bc1e39b-cbdf-43ae-b2b6-735d30a7d7c3'
3: W1117 19:44:42.454800 18292 process.cpp:3185] Attempted to spawn already running process version@172.17.0.2:33183
3: I1117 19:44:42.455214 18292 exec.cpp:162] Version: 1.5.0
3: I1117 19:44:42.455775 18300 exec.cpp:212] Executor started at: executor(15)@172.17.0.2:33183 with pid 18290
3: I1117 19:44:42.455977 18307 slave.cpp:4063] Got registration for executor 'default' of framework 6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-0000 from executor(15)@172.17.0.2:33183
3: I1117 19:44:42.456380 18297 exec.cpp:237] Executor registered on agent 6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-S0
3: I1117 19:44:42.456431 18297 exec.cpp:249] Executor::registered took 34773ns
3: I1117 19:44:42.456923 18307 slave.cpp:2669] Sending queued task '0' to executor 'default' of framework 6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-0000 at executor(15)@172.17.0.2:33183
3: I1117 19:44:42.457252 18307 exec.cpp:331] Executor asked to run task '0'
3: I1117 19:44:42.457382 18307 exec.cpp:340] Executor::launchTask took 120317ns
3: I1117 19:44:42.457499 18307 exec.cpp:571] Executor sending status update TASK_RUNNING (UUID: dc885a5e-5f06-4fde-aa3d-fb28212aaf4e) for task 0 of framework 6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-0000
3: I1117 19:44:42.457855 18291 slave.cpp:4517] Handling status update TASK_RUNNING (UUID: dc885a5e-5f06-4fde-aa3d-fb28212aaf4e) for task 0 of framework 6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-0000 from executor(15)@172.17.0.2:33183
3: I1117 19:44:42.458745 18313 status_update_manager.cpp:323] Received status update TASK_RUNNING (UUID: dc885a5e-5f06-4fde-aa3d-fb28212aaf4e) for task 0 of framework 6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-0000
3: I1117 19:44:42.458793 18313 status_update_manager.cpp:500] Creating StatusUpdate stream for task 0 of framework 6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-0000
3: I1117 19:44:42.459374 18313 status_update_manager.cpp:377] Forwarding update TASK_RUNNING (UUID: dc885a5e-5f06-4fde-aa3d-fb28212aaf4e) for task 0 of framework 6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-0000 to the agent
3: I1117 19:44:42.459599 18303 slave.cpp:4998] Forwarding the update TASK_RUNNING (UUID: dc885a5e-5f06-4fde-aa3d-fb28212aaf4e) for task 0 of framework 6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-0000 to master@172.17.0.2:33183
3: I1117 19:44:42.459852 18303 slave.cpp:4892] Status update manager successfully handled status update TASK_RUNNING (UUID: dc885a5e-5f06-4fde-aa3d-fb28212aaf4e) for task 0 of framework 6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-0000
3: I1117 19:44:42.459913 18303 slave.cpp:4908] Sending acknowledgement for status update TASK_RUNNING (UUID: dc885a5e-5f06-4fde-aa3d-fb28212aaf4e) for task 0 of framework 6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-0000 to executor(15)@172.17.0.2:33183
3: I1117 19:44:42.460008 18306 master.cpp:7247] Status update TASK_RUNNING (UUID: dc885a5e-5f06-4fde-aa3d-fb28212aaf4e) for task 0 of framework 6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-0000 from agent 6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-S0 at slave(64)@172.17.0.2:33183 (ed775a6760c9)
3: I1117 19:44:42.460062 18306 master.cpp:7309] Forwarding status update TASK_RUNNING (UUID: dc885a5e-5f06-4fde-aa3d-fb28212aaf4e) for task 0 of framework 6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-0000
3: I1117 19:44:42.460144 18304 exec.cpp:388] Executor received status update acknowledgement dc885a5e-5f06-4fde-aa3d-fb28212aaf4e for task 0 of framework 6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-0000
3: I1117 19:44:42.460263 18306 master.cpp:9502] Updating the state of task 0 of framework 6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-0000 (latest state: TASK_RUNNING, status update state: TASK_RUNNING)
3: I1117 19:44:42.460572 18302 sched.cpp:1029] Scheduler::statusUpdate took 120778ns
3: I1117 19:44:42.461055 18295 master.cpp:5791] Processing ACKNOWLEDGE call dc885a5e-5f06-4fde-aa3d-fb28212aaf4e for task 0 of framework 6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-0000 (default) at scheduler-61f76c1c-ca30-4c2a-b1aa-72aacf0d19c0@172.17.0.2:33183 on agent 6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-S0
3: I1117 19:44:42.461593 18311 status_update_manager.cpp:395] Received status update acknowledgement (UUID: dc885a5e-5f06-4fde-aa3d-fb28212aaf4e) for task 0 of framework 6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-0000
3: I1117 19:44:42.461838 18296 slave.cpp:5130] Got exited event for executor(15)@172.17.0.2:33183
3: I1117 19:44:42.461971 18297 slave.cpp:3801] Status update manager successfully handled status update acknowledgement (UUID: dc885a5e-5f06-4fde-aa3d-fb28212aaf4e) for task 0 of framework 6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-0000
3: I1117 19:44:42.462170 18301 slave.cpp:5539] Executor 'default' of framework 6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-0000 exited with status 0
3: I1117 19:44:42.462361 18301 slave.cpp:4517] Handling status update TASK_FAILED (UUID: 279c414c-901e-4efa-a0d4-88c48fdbee08) for task 0 of framework 6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-0000 from @0.0.0.0:0
3: I1117 19:44:42.463136 18307 master.cpp:7459] Executor 'default' of framework 6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-0000 on agent 6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-S0 at slave(64)@172.17.0.2:33183 (ed775a6760c9): exited with status 0
3: I1117 19:44:42.463229 18307 master.cpp:9625] Removing executor 'default' with resources [] of framework 6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-0000 on agent 6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-S0 at slave(64)@172.17.0.2:33183 (ed775a6760c9)
3: I1117 19:44:42.463778 18298 sched.cpp:1131] Executor default on agent 6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-S0 exited with status 0
3: I1117 19:44:42.463773 18313 status_update_manager.cpp:323] Received status update TASK_FAILED (UUID: 279c414c-901e-4efa-a0d4-88c48fdbee08) for task 0 of framework 6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-0000
3: I1117 19:44:42.463840 18298 sched.cpp:1142] Scheduler::executorLost took 37780ns
3: I1117 19:44:42.463930 18313 status_update_manager.cpp:377] Forwarding update TASK_FAILED (UUID: 279c414c-901e-4efa-a0d4-88c48fdbee08) for task 0 of framework 6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-0000 to the agent
3: I1117 19:44:42.464188 18303 slave.cpp:4998] Forwarding the update TASK_FAILED (UUID: 279c414c-901e-4efa-a0d4-88c48fdbee08) for task 0 of framework 6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-0000 to master@172.17.0.2:33183
3: I1117 19:44:42.464462 18303 slave.cpp:4892] Status update manager successfully handled status update TASK_FAILED (UUID: 279c414c-901e-4efa-a0d4-88c48fdbee08) for task 0 of framework 6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-0000
3: I1117 19:44:42.464601 18306 master.cpp:7247] Status update TASK_FAILED (UUID: 279c414c-901e-4efa-a0d4-88c48fdbee08) for task 0 of framework 6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-0000 from agent 6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-S0 at slave(64)@172.17.0.2:33183 (ed775a6760c9)
3: I1117 19:44:42.464666 18306 master.cpp:7309] Forwarding status update TASK_FAILED (UUID: 279c414c-901e-4efa-a0d4-88c48fdbee08) for task 0 of framework 6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-0000
3: I1117 19:44:42.464915 18306 master.cpp:9502] Updating the state of task 0 of framework 6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-0000 (latest state: TASK_FAILED, status update state: TASK_FAILED)
3: I1117 19:44:42.465421 18308 sched.cpp:1029] Scheduler::statusUpdate took 42103ns
3: I1117 19:44:42.465813 18314 master.cpp:5791] Processing ACKNOWLEDGE call 279c414c-901e-4efa-a0d4-88c48fdbee08 for task 0 of framework 6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-0000 (default) at scheduler-61f76c1c-ca30-4c2a-b1aa-72aacf0d19c0@172.17.0.2:33183 on agent 6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-S0
3: I1117 19:44:42.465893 18314 master.cpp:9596] Removing task 0 with resources [{"allocation_info":{"role":"*"},"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"}] of framework 6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-0000 on agent 6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-S0 at slave(64)@172.17.0.2:33183 (ed775a6760c9)
3: I1117 19:44:42.466228 18302 hierarchical.cpp:1125] Recovered cpus(allocated: *):2; mem(allocated: *):1024 (total: cpus:2; mem:1024; disk:1024; ports:[31000-32000], allocated: {}) on agent 6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-S0 from framework 6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-0000
3: I1117 19:44:42.466637 18293 status_update_manager.cpp:395] Received status update acknowledgement (UUID: 279c414c-901e-4efa-a0d4-88c48fdbee08) for task 0 of framework 6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-0000
3: I1117 19:44:42.466784 18293 status_update_manager.cpp:531] Cleaning up status update stream for task 0 of framework 6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-0000
3: I1117 19:44:42.467274 18295 slave.cpp:3801] Status update manager successfully handled status update acknowledgement (UUID: 279c414c-901e-4efa-a0d4-88c48fdbee08) for task 0 of framework 6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-0000
3: I1117 19:44:42.467332 18295 slave.cpp:8341] Completing task 0
3: I1117 19:44:42.467373 18295 slave.cpp:5643] Cleaning up executor 'default' of framework 6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-0000 at executor(15)@172.17.0.2:33183
3: I1117 19:44:42.467696 18294 gc.cpp:90] Scheduling '/tmp/GarbageCollectorIntegrationTest_DiskUsage_Ix1rjJ/slaves/6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-S0/frameworks/6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-0000/executors/default/runs/7bc1e39b-cbdf-43ae-b2b6-735d30a7d7c3' for gc 6.99999466334519days in the future
3: I1117 19:44:42.467912 18295 slave.cpp:5750] Cleaning up framework 6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-0000
3: I1117 19:44:42.467934 18294 gc.cpp:90] Scheduling '/tmp/GarbageCollectorIntegrationTest_DiskUsage_Ix1rjJ/slaves/6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-S0/frameworks/6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-0000/executors/default' for gc 6.99999466334519days in the future
3: I1117 19:44:42.468080 18299 status_update_manager.cpp:285] Closing status update streams for framework 6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-0000
3: I1117 19:44:42.468201 18300 gc.cpp:90] Scheduling '/tmp/GarbageCollectorIntegrationTest_DiskUsage_Ix1rjJ/slaves/6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-S0/frameworks/6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-0000' for gc 6.99999466334519days in the future
3: I1117 19:44:42.468513 18296 slave.cpp:6058] Current disk usage 90.00%. Max allowed age: 0ns
3: I1117 19:44:42.468686 18311 gc.cpp:263] Pruning directories with remaining removal time 6.99998308927111days
3: I1117 19:44:42.468942 18310 gc.cpp:208] Deleting /tmp/GarbageCollectorIntegrationTest_DiskUsage_Ix1rjJ/slaves/6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-S0/frameworks/6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-0000/executors/default/runs/7bc1e39b-cbdf-43ae-b2b6-735d30a7d7c3
3: I1117 19:44:42.469287 18310 gc.cpp:218] Deleted '/tmp/GarbageCollectorIntegrationTest_DiskUsage_Ix1rjJ/slaves/6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-S0/frameworks/6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-0000/executors/default/runs/7bc1e39b-cbdf-43ae-b2b6-735d30a7d7c3'
3: I1117 19:44:42.469466 18310 gc.cpp:208] Deleting /tmp/GarbageCollectorIntegrationTest_DiskUsage_Ix1rjJ/slaves/6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-S0/frameworks/6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-0000/executors/default
3: I1117 19:44:42.469920 18310 gc.cpp:218] Deleted '/tmp/GarbageCollectorIntegrationTest_DiskUsage_Ix1rjJ/slaves/6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-S0/frameworks/6f4e53e9-a46b-4f5c-8eb1-2c008dc6c3f3-0000/executors/default'
write /dev/stdout: resource temporarily unavailable
+ docker rmi mesos-1510945799-6468
Error response from daemon: conflict: unable to remove repository reference "mesos-1510945799-6468" (must force) - container ed775a6760c9 is using its referenced image 9691d1a484a3
Build step 'Execute shell' marked build as failure
Not sending mail to unregistered user xujyan@apple.com