You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@mesos.apache.org by "Till Toenshoff (JIRA)" <ji...@apache.org> on 2018/11/20 14:18:00 UTC
[jira] [Created] (MESOS-9408)
ExamplesTest.DynamicReservationFramework is flaky.
Till Toenshoff created MESOS-9408:
-------------------------------------
Summary: ExamplesTest.DynamicReservationFramework is flaky.
Key: MESOS-9408
URL: https://issues.apache.org/jira/browse/MESOS-9408
Project: Mesos
Issue Type: Bug
Components: test
Affects Versions: 1.8.0
Environment: Centos 7
Reporter: Till Toenshoff
Just observed the following on a private CI:
{noformat}
21:43:58 [ RUN ] ExamplesTest.DynamicReservationFramework
21:43:58 Using temporary directory '/tmp/ExamplesTest_DynamicReservationFramework_ZMtmYM'
21:43:58 /home/centos/workspace/mesos/Mesos_CI-build/FLAG/CMake/label/mesos-ec2-centos-7/mesos/src/tests/dynamic_reservation_framework_test.sh: line 19: /home/centos/workspace/mesos/Mesos_CI-build/FLAG/CMake/label/mesos-ec2-centos-7/mesos/build/src/colors.sh: No such file or directory
21:43:58 /home/centos/workspace/mesos/Mesos_CI-build/FLAG/CMake/label/mesos-ec2-centos-7/mesos/src/tests/dynamic_reservation_framework_test.sh: line 20: /home/centos/workspace/mesos/Mesos_CI-build/FLAG/CMake/label/mesos-ec2-centos-7/mesos/build/src/atexit.sh: No such file or directory
21:43:58 I1119 21:43:58.839268 13958 logging.cpp:206] Logging to STDERR
21:43:58 I1119 21:43:58.843668 13958 dynamic_reservation_framework.cpp:404] Enabling authentication for the framework
21:43:58 I1119 21:43:58.853098 13958 process.cpp:1239] libprocess is initialized on 172.16.10.76:34786 with 8 worker threads
21:43:58 I1119 21:43:58.865555 13958 leveldb.cpp:174] Opened db in 6.293659ms
21:43:58 I1119 21:43:58.867594 13958 leveldb.cpp:181] Compacted db in 2.00334ms
21:43:58 I1119 21:43:58.867645 13958 leveldb.cpp:196] Created db iterator in 19149ns
21:43:58 I1119 21:43:58.867669 13958 leveldb.cpp:202] Seeked to beginning of db in 3892ns
21:43:58 I1119 21:43:58.867681 13958 leveldb.cpp:277] Iterated through 0 keys in the db in 2958ns
21:43:58 I1119 21:43:58.867907 13958 replica.cpp:795] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
21:43:58 I1119 21:43:58.871166 13958 local.cpp:291] Creating default 'local' authorizer
21:43:58 I1119 21:43:58.871464 13965 recover.cpp:437] Starting replica recovery
21:43:58 I1119 21:43:58.874862 13969 recover.cpp:468] Replica is in EMPTY status
21:43:58 I1119 21:43:58.880306 13968 replica.cpp:677] Replica in EMPTY status received a broadcasted recover request from __req_res__(1)@172.16.10.76:34786
21:43:58 I1119 21:43:58.881541 13968 recover.cpp:197] Received a recover response from a replica in EMPTY status
21:43:58 I1119 21:43:58.883182 13968 recover.cpp:564] Updating replica status to STARTING
21:43:58 I1119 21:43:58.884698 13972 leveldb.cpp:310] Persisting metadata (8 bytes) to leveldb took 1.199483ms
21:43:58 I1119 21:43:58.884734 13972 replica.cpp:322] Persisted replica status to STARTING
21:43:58 I1119 21:43:58.885232 13972 master.cpp:413] Master 0c5362db-ba85-4ddd-9c1e-c4de159c92ae (ip-172-16-10-76.ec2.internal) started on 172.16.10.76:34786
21:43:58 I1119 21:43:58.885246 13972 master.cpp:416] Flags at startup: --acls="permissive: true
21:43:58 register_frameworks {
21:43:58 principals {
21:43:58 type: ANY
21:43:58 }
21:43:58 roles {
21:43:58 type: SOME
21:43:58 values: "test"
21:43:58 }
21:43:58 }
21:43:58 " --agent_ping_timeout="15secs" --agent_reregister_timeout="10mins" --allocation_interval="1secs" --allocator="hierarchical" --authenticate_agents="false" --authenticate_frameworks="true" --authenticate_http_frameworks="false" --authenticate_http_readonly="false" --authenticate_http_readwrite="false" --authentication_v0_timeout="15secs" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/ExamplesTest_DynamicReservationFramework_ZMtmYM/credentials" --filter_gpu_resources="true" --framework_sorter="drf" --help="false" --hostname_lookup="true" --http_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" --memory_profiling="false" --min_allocatable_resources="cpus:0.01|mem:32" --port="5050" --publish_per_framework_metrics="true" --quiet="false" --recovery_agent_removal_limit="100%" --registry="replicated_log" --registry_fetch_timeout="1mins" --registry_gc_interval="15mins" --registry_max_agent_age="2weeks" --registry_max_agent_count="102400" --registry_store_timeout="20secs" --registry_strict="false" --require_agent_domain="false" --role_sorter="drf" --roles="test" --root_submissions="true" --version="false" --webui_dir="/home/centos/workspace/mesos/Mesos_CI-build/FLAG/CMake/label/mesos-ec2-centos-7/mesos/src/webui" --work_dir="/tmp/mesos-JDy6aV/master" --zk_session_timeout="10secs"
21:43:58 I1119 21:43:58.885946 13972 master.cpp:465] Master only allowing authenticated frameworks to register
21:43:58 I1119 21:43:58.885956 13972 master.cpp:473] Master allowing unauthenticated agents to register
21:43:58 I1119 21:43:58.885962 13972 master.cpp:480] Master allowing HTTP frameworks to register without authentication
21:43:58 I1119 21:43:58.885970 13972 credentials.hpp:37] Loading credentials for authentication from '/tmp/ExamplesTest_DynamicReservationFramework_ZMtmYM/credentials'
21:43:58 W1119 21:43:58.886065 13972 credentials.hpp:52] Permissions on credentials file '/tmp/ExamplesTest_DynamicReservationFramework_ZMtmYM/credentials' are too open; it is recommended that your credentials file is NOT accessible by others
21:43:58 I1119 21:43:58.886246 13972 master.cpp:521] Using default 'crammd5' authenticator
21:43:58 I1119 21:43:58.886502 13972 authenticator.cpp:520] Initializing server SASL
21:43:58 I1119 21:43:58.887771 13972 auxprop.cpp:73] Initialized in-memory auxiliary property plugin
21:43:58 I1119 21:43:58.887912 13972 master.cpp:602] Authorization enabled
21:43:58 W1119 21:43:58.887926 13972 master.cpp:665] The '--roles' flag is deprecated. This flag will be removed in the future. See the Mesos 0.27 upgrade notes for more information
21:43:58 I1119 21:43:58.890337 13969 whitelist_watcher.cpp:77] No whitelist given
21:43:58 I1119 21:43:58.891654 13970 hierarchical.cpp:175] Initialized hierarchical allocator process
21:43:58 I1119 21:43:58.892107 13967 recover.cpp:468] Replica is in STARTING status
21:43:58 I1119 21:43:58.893712 13965 replica.cpp:677] Replica in STARTING status received a broadcasted recover request from __req_res__(2)@172.16.10.76:34786
21:43:58 I1119 21:43:58.894366 13967 recover.cpp:197] Received a recover response from a replica in STARTING status
21:43:58 I1119 21:43:58.895067 13967 recover.cpp:564] Updating replica status to VOTING
21:43:58 I1119 21:43:58.896147 13958 resolver.cpp:69] Creating default secret resolver
21:43:58 I1119 21:43:58.896970 13969 leveldb.cpp:310] Persisting metadata (8 bytes) to leveldb took 1.816173ms
21:43:58 I1119 21:43:58.896997 13969 replica.cpp:322] Persisted replica status to VOTING
21:43:58 I1119 21:43:58.897207 13969 recover.cpp:578] Successfully joined the Paxos group
21:43:58 I1119 21:43:58.897903 13958 containerizer.cpp:305] Using isolation { environment_secret, filesystem/posix, network/cni, posix/mem, posix/cpu }
21:43:58 I1119 21:43:58.897929 13969 recover.cpp:447] Recover process terminated
21:43:58 I1119 21:43:58.899710 13958 provisioner.cpp:298] Using default backend 'copy'
21:43:58 I1119 21:43:58.910158 13969 slave.cpp:267] Mesos agent started on (1)@172.16.10.76:34786
21:43:58 I1119 21:43:58.910178 13969 slave.cpp:268] Flags at startup: --acls="permissive: true
21:43:58 register_frameworks {
21:43:58 principals {
21:43:58 type: ANY
21:43:58 }
21:43:58 roles {
21:43:58 type: SOME
21:43:58 values: "test"
21:43:58 }
21:43:58 }
21:43:58 " --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/mesos/store/appc" --authenticate_http_readonly="false" --authenticate_http_readwrite="false" --authenticatee="crammd5" --authentication_backoff_factor="1secs" --authentication_timeout_max="1mins" --authentication_timeout_min="5secs" --authorizer="local" --cgroups_cpu_enable_pids_and_tids_count="false" --cgroups_destroy_timeout="1mins" --cgroups_enable_cfs="false" --cgroups_hierarchy="/sys/fs/cgroup" --cgroups_limit_swap="false" --cgroups_root="mesos" --container_disk_watch_interval="15secs" --containerizers="mesos" --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/mesos/store/docker" --docker_volume_checkpoint_dir="/var/run/mesos/isolators/docker/volume" --enforce_container_disk_quota="false" --executor_registration_timeout="1mins" --executor_reregistration_timeout="2secs" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/mesos-JDy6aV/agents/0/fetch" --fetcher_cache_size="2GB" --fetcher_stall_timeout="1mins" --frameworks_home="" --gc_delay="1weeks" --gc_disk_headroom="0.1" --gc_non_executor_container_sandboxes="false" --help="false" --hostname_lookup="true" --http_command_executor="false" --http_heartbeat_interval="30secs" --initialize_driver_logging="true" --isolation="filesystem/posix,posix/cpu,posix/mem" --launcher="posix" --launcher_dir="/home/centos/workspace/mesos/Mesos_CI-build/FLAG/CMake/label/mesos-ec2-centos-7/mesos/build/src" --logbufsecs="0" --logging_level="INFO" --max_completed_executors_per_framework="150" --memory_profiling="false" --network_cni_metrics="true" --oversubscribed_resources_interval="15secs" --perf_duration="10secs" --perf_interval="1mins" --port="5051" --qos_correction_interval_min="0ns" --quiet="false" --reconfiguration_policy="equal" --recover="reconnect" --recovery_timeout="15mins" --registration_backoff_factor="1secs" --revocable_cpu_low_priority="true" --runtime_dir="/tmp/mesos-JDy6aV/agents/0/run" --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/mesos-JDy6aV/agents/0/work" --zk_session_timeout="10secs"
21:43:58 I1119 21:43:58.911094 13969 disk_profile_adaptor.cpp:80] Creating default disk profile adaptor module
21:43:58 I1119 21:43:58.911973 13958 resolver.cpp:69] Creating default secret resolver
21:43:58 I1119 21:43:58.912279 13958 containerizer.cpp:305] Using isolation { environment_secret, filesystem/posix, network/cni, posix/mem, posix/cpu }
21:43:58 I1119 21:43:58.913098 13958 provisioner.cpp:298] Using default backend 'copy'
21:43:58 I1119 21:43:58.921149 13971 slave.cpp:267] Mesos agent started on (2)@172.16.10.76:34786
21:43:58 I1119 21:43:58.921169 13971 slave.cpp:268] Flags at startup: --acls="permissive: true
21:43:58 register_frameworks {
21:43:58 principals {
21:43:58 type: ANY
21:43:58 }
21:43:58 roles {
21:43:58 type: SOME
21:43:58 values: "test"
21:43:58 }
21:43:58 }
21:43:58 " --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/mesos/store/appc" --authenticate_http_readonly="false" --authenticate_http_readwrite="false" --authenticatee="crammd5" --authentication_backoff_factor="1secs" --authentication_timeout_max="1mins" --authentication_timeout_min="5secs" --authorizer="local" --cgroups_cpu_enable_pids_and_tids_count="false" --cgroups_destroy_timeout="1mins" --cgroups_enable_cfs="false" --cgroups_hierarchy="/sys/fs/cgroup" --cgroups_limit_swap="false" --cgroups_root="mesos" --container_disk_watch_interval="15secs" --containerizers="mesos" --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/mesos/store/docker" --docker_volume_checkpoint_dir="/var/run/mesos/isolators/docker/volume" --enforce_container_disk_quota="false" --executor_registration_timeout="1mins" --executor_reregistration_timeout="2secs" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/mesos-JDy6aV/agents/1/fetch" --fetcher_cache_size="2GB" --fetcher_stall_timeout="1mins" --frameworks_home="" --gc_delay="1weeks" --gc_disk_headroom="0.1" --gc_non_executor_container_sandboxes="false" --help="false" --hostname_lookup="true" --http_command_executor="false" --http_heartbeat_interval="30secs" --initialize_driver_logging="true" --isolation="filesystem/posix,posix/cpu,posix/mem" --launcher="posix" --launcher_dir="/home/centos/workspace/mesos/Mesos_CI-build/FLAG/CMake/label/mesos-ec2-centos-7/mesos/build/src" --logbufsecs="0" --logging_level="INFO" --max_completed_executors_per_framework="150" --memory_profiling="false" --network_cni_metrics="true" --oversubscribed_resources_interval="15secs" --perf_duration="10secs" --perf_interval="1mins" --port="5051" --qos_correction_interval_min="0ns" --quiet="false" --reconfiguration_policy="equal" --recover="reconnect" --recovery_timeout="15mins" --registration_backoff_factor="1secs" --revocable_cpu_low_priority="true" --runtime_dir="/tmp/mesos-JDy6aV/agents/1/run" --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/mesos-JDy6aV/agents/1/work" --zk_session_timeout="10secs"
21:43:58 I1119 21:43:58.923465 13971 disk_profile_adaptor.cpp:80] Creating default disk profile adaptor module
21:43:58 I1119 21:43:58.925593 13966 master.cpp:2105] Elected as the leading master!
21:43:58 I1119 21:43:58.927904 13966 master.cpp:1660] Recovering from registrar
21:43:58 I1119 21:43:58.929013 13958 resolver.cpp:69] Creating default secret resolver
21:43:58 I1119 21:43:58.929797 13958 containerizer.cpp:305] Using isolation { environment_secret, filesystem/posix, network/cni, posix/mem, posix/cpu }
21:43:58 I1119 21:43:58.930805 13958 provisioner.cpp:298] Using default backend 'copy'
21:43:58 I1119 21:43:58.933077 13965 registrar.cpp:339] Recovering registrar
21:43:58 I1119 21:43:58.947762 13970 log.cpp:554] Attempting to start the writer
21:43:58 I1119 21:43:58.948777 13967 slave.cpp:267] Mesos agent started on (3)@172.16.10.76:34786
21:43:59 I1119 21:43:58.948797 13967 slave.cpp:268] Flags at startup: --acls="permissive: true
21:43:59 register_frameworks {
21:43:59 principals {
21:43:59 type: ANY
21:43:59 }
21:43:59 roles {
21:43:59 type: SOME
21:43:59 values: "test"
21:43:59 }
21:43:59 }
21:43:59 " --appc_simple_discovery_uri_prefix="http://" --appc_store_dir="/tmp/mesos/store/appc" --authenticate_http_readonly="false" --authenticate_http_readwrite="false" --authenticatee="crammd5" --authentication_backoff_factor="1secs" --authentication_timeout_max="1mins" --authentication_timeout_min="5secs" --authorizer="local" --cgroups_cpu_enable_pids_and_tids_count="false" --cgroups_destroy_timeout="1mins" --cgroups_enable_cfs="false" --cgroups_hierarchy="/sys/fs/cgroup" --cgroups_limit_swap="false" --cgroups_root="mesos" --container_disk_watch_interval="15secs" --containerizers="mesos" --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/mesos/store/docker" --docker_volume_checkpoint_dir="/var/run/mesos/isolators/docker/volume" --enforce_container_disk_quota="false" --executor_registration_timeout="1mins" --executor_reregistration_timeout="2secs" --executor_shutdown_grace_period="5secs" --fetcher_cache_dir="/tmp/mesos-JDy6aV/agents/2/fetch" --fetcher_cache_size="2GB" --fetcher_stall_timeout="1mins" --frameworks_home="" --gc_delay="1weeks" --gc_disk_headroom="0.1" --gc_non_executor_container_sandboxes="false" --help="false" --hostname_lookup="true" --http_command_executor="false" --http_heartbeat_interval="30secs" --initialize_driver_logging="true" --isolation="filesystem/posix,posix/cpu,posix/mem" --launcher="posix" --launcher_dir="/home/centos/workspace/mesos/Mesos_CI-build/FLAG/CMake/label/mesos-ec2-centos-7/mesos/build/src" --logbufsecs="0" --logging_level="INFO" --max_completed_executors_per_framework="150" --memory_profiling="false" --network_cni_metrics="true" --oversubscribed_resources_interval="15secs" --perf_duration="10secs" --perf_interval="1mins" --port="5051" --qos_correction_interval_min="0ns" --quiet="false" --reconfiguration_policy="equal" --recover="reconnect" --recovery_timeout="15mins" --registration_backoff_factor="1secs" --revocable_cpu_low_priority="true" --runtime_dir="/tmp/mesos-JDy6aV/agents/2/run" --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/mesos-JDy6aV/agents/2/work" --zk_session_timeout="10secs"
21:43:59 I1119 21:43:58.950289 13967 disk_profile_adaptor.cpp:80] Creating default disk profile adaptor module
21:43:59 W1119 21:43:58.954186 13958 sched.cpp:1937] Loaded deprecated flag 'authentication_timeout'
21:43:59 I1119 21:43:58.955873 13958 sched.cpp:232] Version: 1.8.0
21:43:59 I1119 21:43:58.913030 13969 slave.cpp:615] Agent resources: [{"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":6796.0},"type":"SCALAR"},{"name":"disk","scalar":{"value":35828.0},"type":"SCALAR"},{"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}]
21:43:59 I1119 21:43:58.957437 13969 slave.cpp:623] Agent attributes: [ ]
21:43:59 I1119 21:43:58.957470 13969 slave.cpp:632] Agent hostname: ip-172-16-10-76.ec2.internal
21:43:59 I1119 21:43:58.958123 13966 task_status_update_manager.cpp:181] Pausing sending task status updates
21:43:59 I1119 21:43:58.959180 13966 replica.cpp:497] Replica received implicit promise request from __req_res__(3)@172.16.10.76:34786 with proposal 1
21:43:59 I1119 21:43:58.951589 13967 slave.cpp:615] Agent resources: [{"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":6796.0},"type":"SCALAR"},{"name":"disk","scalar":{"value":35828.0},"type":"SCALAR"},{"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}]
21:43:59 I1119 21:43:58.960708 13967 slave.cpp:623] Agent attributes: [ ]
21:43:59 I1119 21:43:58.960721 13967 slave.cpp:632] Agent hostname: ip-172-16-10-76.ec2.internal
21:43:59 I1119 21:43:58.960731 13972 sched.cpp:336] New master detected at master@172.16.10.76:34786
21:43:59 I1119 21:43:58.960914 13972 sched.cpp:401] Authenticating with master master@172.16.10.76:34786
21:43:59 I1119 21:43:58.960935 13972 sched.cpp:408] Using default CRAM-MD5 authenticatee
21:43:59 I1119 21:43:58.961942 13972 task_status_update_manager.cpp:181] Pausing sending task status updates
21:43:59 I1119 21:43:58.962481 13968 authenticatee.cpp:97] Initializing client SASL
21:43:59 I1119 21:43:58.962617 13968 authenticatee.cpp:121] Creating new client SASL connection
21:43:59 I1119 21:43:58.963066 13968 state.cpp:66] Recovering state from '/tmp/mesos-JDy6aV/agents/2/work/meta'
21:43:59 I1119 21:43:58.963557 13965 master.cpp:1482] Dropping 'mesos.internal.AuthenticateMessage' message since not recovered yet
21:43:59 I1119 21:43:58.964624 13966 leveldb.cpp:310] Persisting metadata (8 bytes) to leveldb took 5.410404ms
21:43:59 I1119 21:43:58.964654 13966 replica.cpp:344] Persisted promised to 1
21:43:59 I1119 21:43:58.964834 13966 state.cpp:66] Recovering state from '/tmp/mesos-JDy6aV/agents/0/work/meta'
21:43:59 I1119 21:43:58.965167 13966 slave.cpp:6915] Finished recovering checkpointed state from '/tmp/mesos-JDy6aV/agents/0/work/meta', beginning agent recovery
21:43:59 I1119 21:43:58.965648 13966 task_status_update_manager.cpp:207] Recovering task status update manager
21:43:59 I1119 21:43:58.966703 13969 coordinator.cpp:238] Coordinator attempting to fill missing positions
21:43:59 I1119 21:43:58.966759 13966 containerizer.cpp:727] Recovering Mesos containers
21:43:59 I1119 21:43:58.968029 13966 containerizer.cpp:1053] Recovering isolators
21:43:59 I1119 21:43:58.968983 13967 slave.cpp:6915] Finished recovering checkpointed state from '/tmp/mesos-JDy6aV/agents/2/work/meta', beginning agent recovery
21:43:59 I1119 21:43:58.969180 13967 task_status_update_manager.cpp:207] Recovering task status update manager
21:43:59 I1119 21:43:58.969547 13967 containerizer.cpp:727] Recovering Mesos containers
21:43:59 I1119 21:43:58.969743 13965 replica.cpp:391] Replica received explicit promise request from __req_res__(4)@172.16.10.76:34786 for position 0 with proposal 2
21:43:59 I1119 21:43:58.969889 13967 containerizer.cpp:1053] Recovering isolators
21:43:59 I1119 21:43:58.971526 13972 containerizer.cpp:1092] Recovering provisioner
21:43:59 I1119 21:43:58.972260 13967 containerizer.cpp:1092] Recovering provisioner
21:43:59 I1119 21:43:58.924906 13971 slave.cpp:615] Agent resources: [{"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":6796.0},"type":"SCALAR"},{"name":"disk","scalar":{"value":35828.0},"type":"SCALAR"},{"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}]
21:43:59 I1119 21:43:58.973232 13971 slave.cpp:623] Agent attributes: [ ]
21:43:59 I1119 21:43:58.973243 13971 slave.cpp:632] Agent hostname: ip-172-16-10-76.ec2.internal
21:43:59 I1119 21:43:58.974668 13970 provisioner.cpp:494] Provisioner recovery complete
21:43:59 I1119 21:43:58.974987 13972 task_status_update_manager.cpp:181] Pausing sending task status updates
21:43:59 I1119 21:43:58.975433 13968 state.cpp:66] Recovering state from '/tmp/mesos-JDy6aV/agents/1/work/meta'
21:43:59 I1119 21:43:58.975718 13968 slave.cpp:7144] Recovering executors
21:43:59 I1119 21:43:58.975775 13965 leveldb.cpp:347] Persisting action (8 bytes) to leveldb took 5.973157ms
21:43:59 I1119 21:43:58.975811 13965 replica.cpp:712] Persisted action NOP at position 0
21:43:59 I1119 21:43:58.975927 13968 slave.cpp:7297] Finished recovery
21:43:59 I1119 21:43:58.977200 13968 slave.cpp:1260] New master detected at master@172.16.10.76:34786
21:43:59 I1119 21:43:58.977227 13968 slave.cpp:1314] No credentials provided. Attempting to register without authentication
21:43:59 I1119 21:43:58.977283 13968 slave.cpp:1325] Detecting new master
21:43:59 I1119 21:43:58.977540 13968 task_status_update_manager.cpp:181] Pausing sending task status updates
21:43:59 I1119 21:43:58.977973 13971 slave.cpp:6915] Finished recovering checkpointed state from '/tmp/mesos-JDy6aV/agents/1/work/meta', beginning agent recovery
21:43:59 I1119 21:43:58.978173 13971 task_status_update_manager.cpp:207] Recovering task status update manager
21:43:59 I1119 21:43:58.978528 13971 containerizer.cpp:727] Recovering Mesos containers
21:43:59 I1119 21:43:58.978849 13971 containerizer.cpp:1053] Recovering isolators
21:43:59 I1119 21:43:58.979971 13972 replica.cpp:541] Replica received write request for position 0 from __req_res__(5)@172.16.10.76:34786
21:43:59 I1119 21:43:58.980077 13972 leveldb.cpp:460] Reading position from leveldb took 71536ns
21:43:59 I1119 21:43:58.980315 13965 containerizer.cpp:1092] Recovering provisioner
21:43:59 I1119 21:43:58.981086 13967 provisioner.cpp:494] Provisioner recovery complete
21:43:59 I1119 21:43:58.981562 13965 provisioner.cpp:494] Provisioner recovery complete
21:43:59 I1119 21:43:58.981884 13967 slave.cpp:7144] Recovering executors
21:43:59 I1119 21:43:58.982038 13967 slave.cpp:7297] Finished recovery
21:43:59 I1119 21:43:58.982311 13965 slave.cpp:7144] Recovering executors
21:43:59 I1119 21:43:58.982487 13965 slave.cpp:7297] Finished recovery
21:43:59 I1119 21:43:58.983134 13965 slave.cpp:1260] New master detected at master@172.16.10.76:34786
21:43:59 I1119 21:43:58.983158 13965 slave.cpp:1314] No credentials provided. Attempting to register without authentication
21:43:59 I1119 21:43:58.983202 13965 slave.cpp:1325] Detecting new master
21:43:59 I1119 21:43:58.983446 13965 task_status_update_manager.cpp:181] Pausing sending task status updates
21:43:59 I1119 21:43:58.983525 13966 task_status_update_manager.cpp:181] Pausing sending task status updates
21:43:59 I1119 21:43:58.983562 13965 slave.cpp:1260] New master detected at master@172.16.10.76:34786
21:43:59 I1119 21:43:58.983590 13965 slave.cpp:1314] No credentials provided. Attempting to register without authentication
21:43:59 I1119 21:43:58.983633 13965 slave.cpp:1325] Detecting new master
21:43:59 I1119 21:43:58.984294 13972 leveldb.cpp:347] Persisting action (14 bytes) to leveldb took 4.128901ms
21:43:59 I1119 21:43:58.984329 13972 replica.cpp:712] Persisted action NOP at position 0
21:43:59 I1119 21:43:58.985469 13967 replica.cpp:695] Replica received learned notice for position 0 from log-network(1)@172.16.10.76:34786
21:43:59 I1119 21:43:58.986591 13967 leveldb.cpp:347] Persisting action (16 bytes) to leveldb took 1.093824ms
21:43:59 I1119 21:43:58.986624 13967 replica.cpp:712] Persisted action NOP at position 0
21:43:59 I1119 21:43:58.987541 13970 log.cpp:570] Writer started with ending position 0
21:43:59 I1119 21:43:58.991034 13967 leveldb.cpp:460] Reading position from leveldb took 30072ns
21:43:59 I1119 21:43:58.994820 13968 registrar.cpp:383] Successfully fetched the registry (0B) in 61.682944ms
21:43:59 I1119 21:43:58.995106 13968 registrar.cpp:487] Applied 1 operations in 124513ns; attempting to update the registry
21:43:59 I1119 21:43:58.998093 13971 log.cpp:578] Attempting to append 211 bytes to the log
21:43:59 I1119 21:43:58.998317 13965 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 1
21:43:59 I1119 21:43:58.999368 13967 replica.cpp:541] Replica received write request for position 1 from __req_res__(6)@172.16.10.76:34786
21:43:59 I1119 21:43:59.000604 13967 leveldb.cpp:347] Persisting action (230 bytes) to leveldb took 1.1731ms
21:43:59 I1119 21:43:59.000643 13967 replica.cpp:712] Persisted action APPEND at position 1
21:43:59 I1119 21:43:59.001684 13969 replica.cpp:695] Replica received learned notice for position 1 from log-network(1)@172.16.10.76:34786
21:43:59 I1119 21:43:59.002960 13969 leveldb.cpp:347] Persisting action (232 bytes) to leveldb took 1.245531ms
21:43:59 I1119 21:43:59.002992 13969 replica.cpp:712] Persisted action APPEND at position 1
21:43:59 I1119 21:43:59.004855 13965 registrar.cpp:544] Successfully updated the registry in 9.634816ms
21:43:59 I1119 21:43:59.005043 13965 registrar.cpp:416] Successfully recovered registrar
21:43:59 I1119 21:43:59.005609 13968 log.cpp:597] Attempting to truncate the log to 1
21:43:59 I1119 21:43:59.005897 13968 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 2
21:43:59 I1119 21:43:59.006147 13965 master.cpp:1774] Recovered 0 agents from the registry (172B); allowing 10mins for agents to reregister
21:43:59 I1119 21:43:59.006314 13968 hierarchical.cpp:215] Skipping recovery of hierarchical allocator: nothing to recover
21:43:59 I1119 21:43:59.007030 13965 replica.cpp:541] Replica received write request for position 2 from __req_res__(7)@172.16.10.76:34786
21:43:59 I1119 21:43:59.008175 13965 leveldb.cpp:347] Persisting action (16 bytes) to leveldb took 1.111956ms
21:43:59 I1119 21:43:59.008208 13965 replica.cpp:712] Persisted action TRUNCATE at position 2
21:43:59 I1119 21:43:59.008997 13970 replica.cpp:695] Replica received learned notice for position 2 from log-network(1)@172.16.10.76:34786
21:43:59 I1119 21:43:59.010143 13970 leveldb.cpp:347] Persisting action (18 bytes) to leveldb took 1.110339ms
21:43:59 I1119 21:43:59.010210 13970 leveldb.cpp:423] Deleting ~1 keys from leveldb took 36390ns
21:43:59 I1119 21:43:59.010231 13970 replica.cpp:712] Persisted action TRUNCATE at position 2
21:43:59 I1119 21:43:59.099745 13966 slave.cpp:1883] Will retry registration in 225.822419ms if necessary
21:43:59 I1119 21:43:59.100018 13972 master.cpp:6650] Received register agent message from slave(3)@172.16.10.76:34786 (ip-172-16-10-76.ec2.internal)
21:43:59 I1119 21:43:59.100322 13972 master.cpp:3986] Authorizing agent providing resources 'cpus:2; mem:6796; disk:35828; ports:[31000-32000]' without a principal
21:43:59 I1119 21:43:59.102182 13970 master.cpp:6717] Authorized registration of agent at slave(3)@172.16.10.76:34786 (ip-172-16-10-76.ec2.internal)
21:43:59 I1119 21:43:59.102414 13970 master.cpp:6832] Registering agent at slave(3)@172.16.10.76:34786 (ip-172-16-10-76.ec2.internal) with id 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S0
21:43:59 I1119 21:43:59.103467 13971 registrar.cpp:487] Applied 1 operations in 257018ns; attempting to update the registry
21:43:59 I1119 21:43:59.105494 13967 log.cpp:578] Attempting to append 396 bytes to the log
21:43:59 I1119 21:43:59.105619 13966 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 3
21:43:59 I1119 21:43:59.106509 13971 replica.cpp:541] Replica received write request for position 3 from __req_res__(8)@172.16.10.76:34786
21:43:59 I1119 21:43:59.107714 13971 leveldb.cpp:347] Persisting action (415 bytes) to leveldb took 1.159489ms
21:43:59 I1119 21:43:59.107748 13971 replica.cpp:712] Persisted action APPEND at position 3
21:43:59 I1119 21:43:59.108592 13965 replica.cpp:695] Replica received learned notice for position 3 from log-network(1)@172.16.10.76:34786
21:43:59 I1119 21:43:59.109714 13965 leveldb.cpp:347] Persisting action (417 bytes) to leveldb took 1.088554ms
21:43:59 I1119 21:43:59.109747 13965 replica.cpp:712] Persisted action APPEND at position 3
21:43:59 I1119 21:43:59.110780 13972 registrar.cpp:544] Successfully updated the registry in 7.22688ms
21:43:59 I1119 21:43:59.111161 13972 master.cpp:6880] Admitted agent 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S0 at slave(3)@172.16.10.76:34786 (ip-172-16-10-76.ec2.internal)
21:43:59 I1119 21:43:59.111227 13971 log.cpp:597] Attempting to truncate the log to 3
21:43:59 I1119 21:43:59.111465 13971 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 4
21:43:59 I1119 21:43:59.112509 13971 replica.cpp:541] Replica received write request for position 4 from __req_res__(9)@172.16.10.76:34786
21:43:59 I1119 21:43:59.112939 13972 master.cpp:6925] Registered agent 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S0 at slave(3)@172.16.10.76:34786 (ip-172-16-10-76.ec2.internal) with cpus:2; mem:6796; disk:35828; ports:[31000-32000]
21:43:59 I1119 21:43:59.113093 13967 slave.cpp:1485] Registered with master master@172.16.10.76:34786; given agent ID 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S0
21:43:59 I1119 21:43:59.113229 13969 task_status_update_manager.cpp:188] Resuming sending task status updates
21:43:59 I1119 21:43:59.113560 13967 slave.cpp:1505] Checkpointing SlaveInfo to '/tmp/mesos-JDy6aV/agents/2/work/meta/slaves/0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S0/slave.info'
21:43:59 I1119 21:43:59.113991 13971 leveldb.cpp:347] Persisting action (16 bytes) to leveldb took 1.446592ms
21:43:59 I1119 21:43:59.114020 13971 replica.cpp:712] Persisted action TRUNCATE at position 4
21:43:59 I1119 21:43:59.115154 13969 replica.cpp:695] Replica received learned notice for position 4 from log-network(1)@172.16.10.76:34786
21:43:59 I1119 21:43:59.116205 13968 hierarchical.cpp:603] Added agent 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S0 (ip-172-16-10-76.ec2.internal) with cpus:2; mem:6796; disk:35828; ports:[31000-32000] (allocated: {})
21:43:59 I1119 21:43:59.116775 13968 hierarchical.cpp:1566] Performed allocation for 1 agents in 256065ns
21:43:59 I1119 21:43:59.117059 13969 leveldb.cpp:347] Persisting action (18 bytes) to leveldb took 1.874896ms
21:43:59 I1119 21:43:59.117118 13969 leveldb.cpp:423] Deleting ~2 keys from leveldb took 30811ns
21:43:59 I1119 21:43:59.117135 13969 replica.cpp:712] Persisted action TRUNCATE at position 4
21:43:59 I1119 21:43:59.117700 13967 slave.cpp:1554] Forwarding agent update {"operations":{},"resource_version_uuid":{"value":"V7ugORxNQfuGTyHojcFNtA=="},"slave_id":{"value":"0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S0"},"update_oversubscribed_resources":false}
21:43:59 I1119 21:43:59.118860 13967 master.cpp:7984] Ignoring update on agent 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S0 at slave(3)@172.16.10.76:34786 (ip-172-16-10-76.ec2.internal) as it reports no changes
21:43:59 I1119 21:43:59.271581 13970 slave.cpp:1883] Will retry registration in 529.105097ms if necessary
21:43:59 I1119 21:43:59.271754 13966 master.cpp:6650] Received register agent message from slave(1)@172.16.10.76:34786 (ip-172-16-10-76.ec2.internal)
21:43:59 I1119 21:43:59.271993 13966 master.cpp:3986] Authorizing agent providing resources 'cpus:2; mem:6796; disk:35828; ports:[31000-32000]' without a principal
21:43:59 I1119 21:43:59.272825 13967 master.cpp:6717] Authorized registration of agent at slave(1)@172.16.10.76:34786 (ip-172-16-10-76.ec2.internal)
21:43:59 I1119 21:43:59.272969 13967 master.cpp:6832] Registering agent at slave(1)@172.16.10.76:34786 (ip-172-16-10-76.ec2.internal) with id 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S1
21:43:59 I1119 21:43:59.273670 13968 registrar.cpp:487] Applied 1 operations in 220824ns; attempting to update the registry
21:43:59 I1119 21:43:59.274672 13972 log.cpp:578] Attempting to append 578 bytes to the log
21:43:59 I1119 21:43:59.274788 13965 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 5
21:43:59 I1119 21:43:59.275805 13968 replica.cpp:541] Replica received write request for position 5 from __req_res__(10)@172.16.10.76:34786
21:43:59 I1119 21:43:59.277036 13968 leveldb.cpp:347] Persisting action (597 bytes) to leveldb took 1.182997ms
21:43:59 I1119 21:43:59.277070 13968 replica.cpp:712] Persisted action APPEND at position 5
21:43:59 I1119 21:43:59.277947 13967 replica.cpp:695] Replica received learned notice for position 5 from log-network(1)@172.16.10.76:34786
21:43:59 I1119 21:43:59.279114 13967 leveldb.cpp:347] Persisting action (599 bytes) to leveldb took 1.131708ms
21:43:59 I1119 21:43:59.279145 13967 replica.cpp:712] Persisted action APPEND at position 5
21:43:59 I1119 21:43:59.280218 13966 registrar.cpp:544] Successfully updated the registry in 6.475776ms
21:43:59 I1119 21:43:59.280508 13966 master.cpp:6880] Admitted agent 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S1 at slave(1)@172.16.10.76:34786 (ip-172-16-10-76.ec2.internal)
21:43:59 I1119 21:43:59.280745 13969 log.cpp:597] Attempting to truncate the log to 5
21:43:59 I1119 21:43:59.280968 13969 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 6
21:43:59 I1119 21:43:59.281277 13966 master.cpp:6925] Registered agent 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S1 at slave(1)@172.16.10.76:34786 (ip-172-16-10-76.ec2.internal) with cpus:2; mem:6796; disk:35828; ports:[31000-32000]
21:43:59 I1119 21:43:59.281572 13966 slave.cpp:1485] Registered with master master@172.16.10.76:34786; given agent ID 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S1
21:43:59 I1119 21:43:59.281805 13969 hierarchical.cpp:603] Added agent 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S1 (ip-172-16-10-76.ec2.internal) with cpus:2; mem:6796; disk:35828; ports:[31000-32000] (allocated: {})
21:43:59 I1119 21:43:59.281965 13966 slave.cpp:1505] Checkpointing SlaveInfo to '/tmp/mesos-JDy6aV/agents/0/work/meta/slaves/0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S1/slave.info'
21:43:59 I1119 21:43:59.282127 13969 hierarchical.cpp:1566] Performed allocation for 1 agents in 126981ns
21:43:59 I1119 21:43:59.282343 13969 task_status_update_manager.cpp:188] Resuming sending task status updates
21:43:59 I1119 21:43:59.283044 13966 slave.cpp:1554] Forwarding agent update {"operations":{},"resource_version_uuid":{"value":"iUAoT0c8QVWRd8H9MrWa8A=="},"slave_id":{"value":"0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S1"},"update_oversubscribed_resources":false}
21:43:59 I1119 21:43:59.283641 13966 replica.cpp:541] Replica received write request for position 6 from __req_res__(11)@172.16.10.76:34786
21:43:59 I1119 21:43:59.284157 13972 master.cpp:7984] Ignoring update on agent 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S1 at slave(1)@172.16.10.76:34786 (ip-172-16-10-76.ec2.internal) as it reports no changes
21:43:59 I1119 21:43:59.284956 13966 leveldb.cpp:347] Persisting action (16 bytes) to leveldb took 1.277598ms
21:43:59 I1119 21:43:59.284988 13966 replica.cpp:712] Persisted action TRUNCATE at position 6
21:43:59 I1119 21:43:59.285702 13966 replica.cpp:695] Replica received learned notice for position 6 from log-network(1)@172.16.10.76:34786
21:43:59 I1119 21:43:59.286990 13966 leveldb.cpp:347] Persisting action (18 bytes) to leveldb took 1.258588ms
21:43:59 I1119 21:43:59.287050 13966 leveldb.cpp:423] Deleting ~2 keys from leveldb took 30747ns
21:43:59 I1119 21:43:59.287070 13966 replica.cpp:712] Persisted action TRUNCATE at position 6
21:43:59 I1119 21:43:59.850901 13969 slave.cpp:1883] Will retry registration in 1.03719136secs if necessary
21:43:59 I1119 21:43:59.851068 13967 master.cpp:6650] Received register agent message from slave(2)@172.16.10.76:34786 (ip-172-16-10-76.ec2.internal)
21:43:59 I1119 21:43:59.851352 13967 master.cpp:3986] Authorizing agent providing resources 'cpus:2; mem:6796; disk:35828; ports:[31000-32000]' without a principal
21:43:59 I1119 21:43:59.852244 13965 master.cpp:6717] Authorized registration of agent at slave(2)@172.16.10.76:34786 (ip-172-16-10-76.ec2.internal)
21:43:59 I1119 21:43:59.852409 13965 master.cpp:6832] Registering agent at slave(2)@172.16.10.76:34786 (ip-172-16-10-76.ec2.internal) with id 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S2
21:43:59 I1119 21:43:59.853081 13970 registrar.cpp:487] Applied 1 operations in 207544ns; attempting to update the registry
21:43:59 I1119 21:43:59.854085 13968 log.cpp:578] Attempting to append 760 bytes to the log
21:43:59 I1119 21:43:59.854213 13972 coordinator.cpp:348] Coordinator attempting to write APPEND action at position 7
21:43:59 I1119 21:43:59.855171 13970 replica.cpp:541] Replica received write request for position 7 from __req_res__(12)@172.16.10.76:34786
21:43:59 I1119 21:43:59.856745 13970 leveldb.cpp:347] Persisting action (779 bytes) to leveldb took 1.524942ms
21:43:59 I1119 21:43:59.856781 13970 replica.cpp:712] Persisted action APPEND at position 7
21:43:59 I1119 21:43:59.857690 13968 replica.cpp:695] Replica received learned notice for position 7 from log-network(1)@172.16.10.76:34786
21:43:59 I1119 21:43:59.858880 13968 leveldb.cpp:347] Persisting action (781 bytes) to leveldb took 1.157635ms
21:43:59 I1119 21:43:59.858923 13968 replica.cpp:712] Persisted action APPEND at position 7
21:43:59 I1119 21:43:59.860066 13972 registrar.cpp:544] Successfully updated the registry in 6.910976ms
21:43:59 I1119 21:43:59.860325 13972 master.cpp:6880] Admitted agent 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S2 at slave(2)@172.16.10.76:34786 (ip-172-16-10-76.ec2.internal)
21:43:59 I1119 21:43:59.860738 13965 log.cpp:597] Attempting to truncate the log to 7
21:43:59 I1119 21:43:59.860965 13965 coordinator.cpp:348] Coordinator attempting to write TRUNCATE action at position 8
21:43:59 I1119 21:43:59.861083 13972 master.cpp:6925] Registered agent 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S2 at slave(2)@172.16.10.76:34786 (ip-172-16-10-76.ec2.internal) with cpus:2; mem:6796; disk:35828; ports:[31000-32000]
21:43:59 I1119 21:43:59.861307 13965 slave.cpp:1485] Registered with master master@172.16.10.76:34786; given agent ID 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S2
21:43:59 I1119 21:43:59.861585 13972 hierarchical.cpp:603] Added agent 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S2 (ip-172-16-10-76.ec2.internal) with cpus:2; mem:6796; disk:35828; ports:[31000-32000] (allocated: {})
21:43:59 I1119 21:43:59.861729 13965 slave.cpp:1505] Checkpointing SlaveInfo to '/tmp/mesos-JDy6aV/agents/1/work/meta/slaves/0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S2/slave.info'
21:43:59 I1119 21:43:59.861909 13972 hierarchical.cpp:1566] Performed allocation for 1 agents in 127945ns
21:43:59 I1119 21:43:59.862048 13972 task_status_update_manager.cpp:188] Resuming sending task status updates
21:43:59 I1119 21:43:59.862834 13965 slave.cpp:1554] Forwarding agent update {"operations":{},"resource_version_uuid":{"value":"8+gMrIU1QpKv1x/qbkNFYg=="},"slave_id":{"value":"0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S2"},"update_oversubscribed_resources":false}
21:43:59 I1119 21:43:59.863819 13965 replica.cpp:541] Replica received write request for position 8 from __req_res__(13)@172.16.10.76:34786
21:43:59 I1119 21:43:59.863893 13971 master.cpp:7984] Ignoring update on agent 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S2 at slave(2)@172.16.10.76:34786 (ip-172-16-10-76.ec2.internal) as it reports no changes
21:43:59 I1119 21:43:59.865134 13965 leveldb.cpp:347] Persisting action (16 bytes) to leveldb took 1.279431ms
21:43:59 I1119 21:43:59.865166 13965 replica.cpp:712] Persisted action TRUNCATE at position 8
21:43:59 I1119 21:43:59.866044 13968 replica.cpp:695] Replica received learned notice for position 8 from log-network(1)@172.16.10.76:34786
21:43:59 I1119 21:43:59.867327 13968 leveldb.cpp:347] Persisting action (18 bytes) to leveldb took 1.252056ms
21:43:59 I1119 21:43:59.867408 13968 leveldb.cpp:423] Deleting ~2 keys from leveldb took 47997ns
21:43:59 I1119 21:43:59.867426 13968 replica.cpp:712] Persisted action TRUNCATE at position 8
21:43:59 I1119 21:43:59.893784 13971 hierarchical.cpp:1566] Performed allocation for 3 agents in 135997ns
21:44:00 W1119 21:44:00.711314 13973 sched.cpp:446] Authentication timed out
21:44:00 I1119 21:44:00.711997 13970 sched.cpp:479] Failed to authenticate with master master@172.16.10.76:34786: Authentication discarded
21:44:00 I1119 21:44:00.712028 13970 sched.cpp:401] Authenticating with master master@172.16.10.76:34786
21:44:00 I1119 21:44:00.712038 13970 sched.cpp:408] Using default CRAM-MD5 authenticatee
21:44:00 I1119 21:44:00.712456 13969 authenticatee.cpp:121] Creating new client SASL connection
21:44:00 I1119 21:44:00.712751 13970 master.cpp:9699] Authenticating scheduler-6c8bdf5c-fd05-4490-897f-7b33c7d00630@172.16.10.76:34786
21:44:00 I1119 21:44:00.713037 13968 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(2)@172.16.10.76:34786
21:44:00 I1119 21:44:00.713711 13970 authenticator.cpp:98] Creating new server SASL connection
21:44:00 I1119 21:44:00.714020 13968 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5
21:44:00 I1119 21:44:00.714054 13968 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5'
21:44:00 I1119 21:44:00.714241 13965 authenticator.cpp:204] Received SASL authentication start
21:44:00 I1119 21:44:00.714325 13965 authenticator.cpp:326] Authentication requires more steps
21:44:00 I1119 21:44:00.714479 13969 authenticatee.cpp:259] Received SASL authentication step
21:44:00 I1119 21:44:00.714633 13971 authenticator.cpp:232] Received SASL authentication step
21:44:00 I1119 21:44:00.714674 13971 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'ip-172-16-10-76.ec2.internal' server FQDN: 'ip-172-16-10-76.ec2.internal' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
21:44:00 I1119 21:44:00.714686 13971 auxprop.cpp:181] Looking up auxiliary property '*userPassword'
21:44:00 I1119 21:44:00.714795 13971 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
21:44:00 I1119 21:44:00.714833 13971 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: 'ip-172-16-10-76.ec2.internal' server FQDN: 'ip-172-16-10-76.ec2.internal' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
21:44:00 I1119 21:44:00.714843 13971 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
21:44:00 I1119 21:44:00.714849 13971 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
21:44:00 I1119 21:44:00.714869 13971 authenticator.cpp:318] Authentication success
21:44:00 I1119 21:44:00.714978 13967 authenticatee.cpp:299] Authentication success
21:44:00 I1119 21:44:00.715487 13966 master.cpp:9731] Successfully authenticated principal 'test-principal' at scheduler-6c8bdf5c-fd05-4490-897f-7b33c7d00630@172.16.10.76:34786
21:44:00 I1119 21:44:00.715536 13967 sched.cpp:513] Successfully authenticated with master master@172.16.10.76:34786
21:44:00 I1119 21:44:00.715559 13967 sched.cpp:817] Sending SUBSCRIBE call to master@172.16.10.76:34786
21:44:00 I1119 21:44:00.715701 13966 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(2)@172.16.10.76:34786
21:44:00 I1119 21:44:00.715790 13967 sched.cpp:850] Will retry registration in 1.18103521secs if necessary
21:44:00 I1119 21:44:00.716241 13967 master.cpp:2876] Received SUBSCRIBE call for framework 'Dynamic Reservation Framework (C++)' at scheduler-6c8bdf5c-fd05-4490-897f-7b33c7d00630@172.16.10.76:34786
21:44:00 I1119 21:44:00.716498 13967 master.cpp:2177] Authorizing framework principal 'test-principal' to receive offers for roles '{ test }'
21:44:00 I1119 21:44:00.717504 13966 master.cpp:2957] Subscribing framework Dynamic Reservation Framework (C++) with checkpointing disabled and capabilities [ MULTI_ROLE, RESERVATION_REFINEMENT ]
21:44:00 I1119 21:44:00.721832 13966 master.cpp:9929] Adding framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 (Dynamic Reservation Framework (C++)) at scheduler-6c8bdf5c-fd05-4490-897f-7b33c7d00630@172.16.10.76:34786 with roles { } suppressed
21:44:00 I1119 21:44:00.722854 13966 sched.cpp:744] Framework registered with 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000
21:44:00 I1119 21:44:00.722878 13966 dynamic_reservation_framework.cpp:88] Registered!
21:44:00 I1119 21:44:00.722887 13966 sched.cpp:758] Scheduler::registered took 9421ns
21:44:00 I1119 21:44:00.724087 13972 hierarchical.cpp:304] Added framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000
21:44:00 I1119 21:44:00.727270 13972 hierarchical.cpp:1566] Performed allocation for 3 agents in 2.958494ms
21:44:00 I1119 21:44:00.728492 13969 master.cpp:9514] Sending offers [ 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-O0, 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-O1, 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-O2 ] to framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 (Dynamic Reservation Framework (C++)) at scheduler-6c8bdf5c-fd05-4490-897f-7b33c7d00630@172.16.10.76:34786
21:44:00 I1119 21:44:00.729322 13968 dynamic_reservation_framework.cpp:99] Received offer 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-O0 from agent 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S2 with [{"allocation_info":{"role":"test"},"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"allocation_info":{"role":"test"},"name":"mem","scalar":{"value":6796.0},"type":"SCALAR"},{"allocation_info":{"role":"test"},"name":"disk","scalar":{"value":35828.0},"type":"SCALAR"},{"allocation_info":{"role":"test"},"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}]
21:44:00 I1119 21:44:00.730265 13968 dynamic_reservation_framework.cpp:99] Received offer 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-O1 from agent 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S0 with [{"allocation_info":{"role":"test"},"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"allocation_info":{"role":"test"},"name":"mem","scalar":{"value":6796.0},"type":"SCALAR"},{"allocation_info":{"role":"test"},"name":"disk","scalar":{"value":35828.0},"type":"SCALAR"},{"allocation_info":{"role":"test"},"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}]
21:44:00 I1119 21:44:00.730810 13968 dynamic_reservation_framework.cpp:99] Received offer 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-O2 from agent 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S1 with [{"allocation_info":{"role":"test"},"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"allocation_info":{"role":"test"},"name":"mem","scalar":{"value":6796.0},"type":"SCALAR"},{"allocation_info":{"role":"test"},"name":"disk","scalar":{"value":35828.0},"type":"SCALAR"},{"allocation_info":{"role":"test"},"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}]
21:44:00 I1119 21:44:00.731321 13968 sched.cpp:914] Scheduler::resourceOffers took 1.995957ms
21:44:00 I1119 21:44:00.732818 13967 master.cpp:11513] Removing offer 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-O0
21:44:00 I1119 21:44:00.733186 13967 master.cpp:4511] Processing ACCEPT call for offers: [ 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-O0 ] on agent 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S2 at slave(2)@172.16.10.76:34786 (ip-172-16-10-76.ec2.internal) for framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 (Dynamic Reservation Framework (C++)) at scheduler-6c8bdf5c-fd05-4490-897f-7b33c7d00630@172.16.10.76:34786
21:44:00 I1119 21:44:00.733530 13967 master.cpp:3631] Authorizing principal 'test-principal' to reserve resources 'cpus(allocated: test)(reservations: [(DYNAMIC,test,test-principal)]):1; mem(allocated: test)(reservations: [(DYNAMIC,test,test-principal)]):128'
21:44:00 I1119 21:44:00.734997 13967 master.cpp:11513] Removing offer 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-O1
21:44:00 I1119 21:44:00.735246 13967 master.cpp:4511] Processing ACCEPT call for offers: [ 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-O1 ] on agent 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S0 at slave(3)@172.16.10.76:34786 (ip-172-16-10-76.ec2.internal) for framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 (Dynamic Reservation Framework (C++)) at scheduler-6c8bdf5c-fd05-4490-897f-7b33c7d00630@172.16.10.76:34786
21:44:00 I1119 21:44:00.735474 13967 master.cpp:3631] Authorizing principal 'test-principal' to reserve resources 'cpus(allocated: test)(reservations: [(DYNAMIC,test,test-principal)]):1; mem(allocated: test)(reservations: [(DYNAMIC,test,test-principal)]):128'
21:44:00 I1119 21:44:00.736503 13967 master.cpp:11513] Removing offer 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-O2
21:44:00 I1119 21:44:00.736752 13967 master.cpp:4511] Processing ACCEPT call for offers: [ 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-O2 ] on agent 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S1 at slave(1)@172.16.10.76:34786 (ip-172-16-10-76.ec2.internal) for framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 (Dynamic Reservation Framework (C++)) at scheduler-6c8bdf5c-fd05-4490-897f-7b33c7d00630@172.16.10.76:34786
21:44:00 I1119 21:44:00.736945 13967 master.cpp:3631] Authorizing principal 'test-principal' to reserve resources 'cpus(allocated: test)(reservations: [(DYNAMIC,test,test-principal)]):1; mem(allocated: test)(reservations: [(DYNAMIC,test,test-principal)]):128'
21:44:00 I1119 21:44:00.738126 13967 master.cpp:4879] Applying RESERVE operation for resources [{"allocation_info":{"role":"test"},"name":"cpus","reservations":[{"principal":"test-principal","role":"test","type":"DYNAMIC"}],"scalar":{"value":1.0},"type":"SCALAR"},{"allocation_info":{"role":"test"},"name":"mem","reservations":[{"principal":"test-principal","role":"test","type":"DYNAMIC"}],"scalar":{"value":128.0},"type":"SCALAR"}] from framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 (Dynamic Reservation Framework (C++)) at scheduler-6c8bdf5c-fd05-4490-897f-7b33c7d00630@172.16.10.76:34786 to agent 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S2 at slave(2)@172.16.10.76:34786 (ip-172-16-10-76.ec2.internal)
21:44:00 I1119 21:44:00.740029 13967 master.cpp:11404] Sending operation '' (uuid: 17071ace-0a85-4caa-beef-0c7ea5bec725) to agent 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S2 at slave(2)@172.16.10.76:34786 (ip-172-16-10-76.ec2.internal)
21:44:00 I1119 21:44:00.741045 13967 master.cpp:4879] Applying RESERVE operation for resources [{"allocation_info":{"role":"test"},"name":"cpus","reservations":[{"principal":"test-principal","role":"test","type":"DYNAMIC"}],"scalar":{"value":1.0},"type":"SCALAR"},{"allocation_info":{"role":"test"},"name":"mem","reservations":[{"principal":"test-principal","role":"test","type":"DYNAMIC"}],"scalar":{"value":128.0},"type":"SCALAR"}] from framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 (Dynamic Reservation Framework (C++)) at scheduler-6c8bdf5c-fd05-4490-897f-7b33c7d00630@172.16.10.76:34786 to agent 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S0 at slave(3)@172.16.10.76:34786 (ip-172-16-10-76.ec2.internal)
21:44:00 I1119 21:44:00.741647 13968 slave.cpp:4208] Updated checkpointed resources from {} to cpus(reservations: [(DYNAMIC,test,test-principal)]):1; mem(reservations: [(DYNAMIC,test,test-principal)]):128
21:44:00 I1119 21:44:00.741706 13967 master.cpp:11404] Sending operation '' (uuid: 72d66450-21e8-4b9d-b674-51c88005ad5f) to agent 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S0 at slave(3)@172.16.10.76:34786 (ip-172-16-10-76.ec2.internal)
21:44:00 I1119 21:44:00.741780 13968 slave.cpp:7996] Updating the state of operation with no ID (uuid: 17071ace-0a85-4caa-beef-0c7ea5bec725) for framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)
21:44:00 I1119 21:44:00.742496 13967 master.cpp:4879] Applying RESERVE operation for resources [{"allocation_info":{"role":"test"},"name":"cpus","reservations":[{"principal":"test-principal","role":"test","type":"DYNAMIC"}],"scalar":{"value":1.0},"type":"SCALAR"},{"allocation_info":{"role":"test"},"name":"mem","reservations":[{"principal":"test-principal","role":"test","type":"DYNAMIC"}],"scalar":{"value":128.0},"type":"SCALAR"}] from framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 (Dynamic Reservation Framework (C++)) at scheduler-6c8bdf5c-fd05-4490-897f-7b33c7d00630@172.16.10.76:34786 to agent 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S1 at slave(1)@172.16.10.76:34786 (ip-172-16-10-76.ec2.internal)
21:44:00 I1119 21:44:00.743072 13967 master.cpp:11404] Sending operation '' (uuid: 33c9675b-bf58-4f87-9a34-d08f244d297d) to agent 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S1 at slave(1)@172.16.10.76:34786 (ip-172-16-10-76.ec2.internal)
21:44:00 I1119 21:44:00.743486 13967 master.cpp:11154] Updating the state of operation '' (uuid: 17071ace-0a85-4caa-beef-0c7ea5bec725) for framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 (latest state: OPERATION_PENDING, status update state: OPERATION_FINISHED)
21:44:00 I1119 21:44:00.744043 13968 hierarchical.cpp:969] Updated allocation of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 on agent 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S2 from cpus(allocated: test):2; mem(allocated: test):6796; disk(allocated: test):35828; ports(allocated: test):[31000-32000] to cpus(allocated: test):1; mem(allocated: test):6668; disk(allocated: test):35828; ports(allocated: test):[31000-32000]; cpus(allocated: test)(reservations: [(DYNAMIC,test,test-principal)]):1; mem(allocated: test)(reservations: [(DYNAMIC,test,test-principal)]):128
21:44:00 I1119 21:44:00.744702 13967 slave.cpp:4208] Updated checkpointed resources from {} to cpus(reservations: [(DYNAMIC,test,test-principal)]):1; mem(reservations: [(DYNAMIC,test,test-principal)]):128
21:44:00 I1119 21:44:00.744792 13967 slave.cpp:7996] Updating the state of operation with no ID (uuid: 72d66450-21e8-4b9d-b674-51c88005ad5f) for framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)
21:44:00 I1119 21:44:00.744961 13968 hierarchical.cpp:1238] Recovered cpus(allocated: test):1; mem(allocated: test):6668; disk(allocated: test):35828; ports(allocated: test):[31000-32000]; cpus(allocated: test)(reservations: [(DYNAMIC,test,test-principal)]):1; mem(allocated: test)(reservations: [(DYNAMIC,test,test-principal)]):128 (total: cpus:1; mem:6668; disk:35828; ports:[31000-32000]; cpus(reservations: [(DYNAMIC,test,test-principal)]):1; mem(reservations: [(DYNAMIC,test,test-principal)]):128, allocated: {}) on agent 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S2 from framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000
21:44:00 I1119 21:44:00.745963 13967 slave.cpp:4208] Updated checkpointed resources from {} to cpus(reservations: [(DYNAMIC,test,test-principal)]):1; mem(reservations: [(DYNAMIC,test,test-principal)]):128
21:44:00 I1119 21:44:00.746052 13967 slave.cpp:7996] Updating the state of operation with no ID (uuid: 33c9675b-bf58-4f87-9a34-d08f244d297d) for framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 (latest state: OPERATION_FINISHED, status update state: OPERATION_FINISHED)
21:44:00 I1119 21:44:00.746249 13967 master.cpp:11154] Updating the state of operation '' (uuid: 72d66450-21e8-4b9d-b674-51c88005ad5f) for framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 (latest state: OPERATION_PENDING, status update state: OPERATION_FINISHED)
21:44:00 I1119 21:44:00.746455 13967 master.cpp:11154] Updating the state of operation '' (uuid: 33c9675b-bf58-4f87-9a34-d08f244d297d) for framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 (latest state: OPERATION_PENDING, status update state: OPERATION_FINISHED)
21:44:00 I1119 21:44:00.746875 13968 hierarchical.cpp:969] Updated allocation of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 on agent 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S0 from cpus(allocated: test):2; mem(allocated: test):6796; disk(allocated: test):35828; ports(allocated: test):[31000-32000] to cpus(allocated: test):1; mem(allocated: test):6668; disk(allocated: test):35828; ports(allocated: test):[31000-32000]; cpus(allocated: test)(reservations: [(DYNAMIC,test,test-principal)]):1; mem(allocated: test)(reservations: [(DYNAMIC,test,test-principal)]):128
21:44:00 I1119 21:44:00.747433 13968 hierarchical.cpp:1238] Recovered cpus(allocated: test):1; mem(allocated: test):6668; disk(allocated: test):35828; ports(allocated: test):[31000-32000]; cpus(allocated: test)(reservations: [(DYNAMIC,test,test-principal)]):1; mem(allocated: test)(reservations: [(DYNAMIC,test,test-principal)]):128 (total: cpus:1; mem:6668; disk:35828; ports:[31000-32000]; cpus(reservations: [(DYNAMIC,test,test-principal)]):1; mem(reservations: [(DYNAMIC,test,test-principal)]):128, allocated: {}) on agent 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S0 from framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000
21:44:00 I1119 21:44:00.748756 13968 hierarchical.cpp:969] Updated allocation of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 on agent 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S1 from cpus(allocated: test):2; mem(allocated: test):6796; disk(allocated: test):35828; ports(allocated: test):[31000-32000] to cpus(allocated: test):1; mem(allocated: test):6668; disk(allocated: test):35828; ports(allocated: test):[31000-32000]; cpus(allocated: test)(reservations: [(DYNAMIC,test,test-principal)]):1; mem(allocated: test)(reservations: [(DYNAMIC,test,test-principal)]):128
21:44:00 I1119 21:44:00.749321 13968 hierarchical.cpp:1238] Recovered cpus(allocated: test):1; mem(allocated: test):6668; disk(allocated: test):35828; ports(allocated: test):[31000-32000]; cpus(allocated: test)(reservations: [(DYNAMIC,test,test-principal)]):1; mem(allocated: test)(reservations: [(DYNAMIC,test,test-principal)]):128 (total: cpus:1; mem:6668; disk:35828; ports:[31000-32000]; cpus(reservations: [(DYNAMIC,test,test-principal)]):1; mem(reservations: [(DYNAMIC,test,test-principal)]):128, allocated: {}) on agent 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S1 from framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000
21:44:00 I1119 21:44:00.897213 13967 hierarchical.cpp:1566] Performed allocation for 3 agents in 2.02698ms
21:44:00 I1119 21:44:00.898555 13971 master.cpp:9514] Sending offers [ 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-O3, 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-O4, 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-O5 ] to framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 (Dynamic Reservation Framework (C++)) at scheduler-6c8bdf5c-fd05-4490-897f-7b33c7d00630@172.16.10.76:34786
21:44:00 I1119 21:44:00.899230 13972 dynamic_reservation_framework.cpp:99] Received offer 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-O3 from agent 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S0 with [{"allocation_info":{"role":"test"},"name":"cpus","scalar":{"value":1.0},"type":"SCALAR"},{"allocation_info":{"role":"test"},"name":"mem","scalar":{"value":6668.0},"type":"SCALAR"},{"allocation_info":{"role":"test"},"name":"disk","scalar":{"value":35828.0},"type":"SCALAR"},{"allocation_info":{"role":"test"},"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"},{"allocation_info":{"role":"test"},"name":"cpus","reservations":[{"principal":"test-principal","role":"test","type":"DYNAMIC"}],"scalar":{"value":1.0},"type":"SCALAR"},{"allocation_info":{"role":"test"},"name":"mem","reservations":[{"principal":"test-principal","role":"test","type":"DYNAMIC"}],"scalar":{"value":128.0},"type":"SCALAR"}]
21:44:00 I1119 21:44:00.899797 13972 dynamic_reservation_framework.cpp:170] Launching task 0 using offer 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-O3
21:44:00 I1119 21:44:00.900151 13972 dynamic_reservation_framework.cpp:99] Received offer 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-O4 from agent 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S2 with [{"allocation_info":{"role":"test"},"name":"cpus","scalar":{"value":1.0},"type":"SCALAR"},{"allocation_info":{"role":"test"},"name":"mem","scalar":{"value":6668.0},"type":"SCALAR"},{"allocation_info":{"role":"test"},"name":"disk","scalar":{"value":35828.0},"type":"SCALAR"},{"allocation_info":{"role":"test"},"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"},{"allocation_info":{"role":"test"},"name":"cpus","reservations":[{"principal":"test-principal","role":"test","type":"DYNAMIC"}],"scalar":{"value":1.0},"type":"SCALAR"},{"allocation_info":{"role":"test"},"name":"mem","reservations":[{"principal":"test-principal","role":"test","type":"DYNAMIC"}],"scalar":{"value":128.0},"type":"SCALAR"}]
21:44:00 I1119 21:44:00.900652 13972 dynamic_reservation_framework.cpp:170] Launching task 1 using offer 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-O4
21:44:00 I1119 21:44:00.900820 13972 dynamic_reservation_framework.cpp:99] Received offer 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-O5 from agent 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S1 with [{"allocation_info":{"role":"test"},"name":"cpus","scalar":{"value":1.0},"type":"SCALAR"},{"allocation_info":{"role":"test"},"name":"mem","scalar":{"value":6668.0},"type":"SCALAR"},{"allocation_info":{"role":"test"},"name":"disk","scalar":{"value":35828.0},"type":"SCALAR"},{"allocation_info":{"role":"test"},"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"},{"allocation_info":{"role":"test"},"name":"cpus","reservations":[{"principal":"test-principal","role":"test","type":"DYNAMIC"}],"scalar":{"value":1.0},"type":"SCALAR"},{"allocation_info":{"role":"test"},"name":"mem","reservations":[{"principal":"test-principal","role":"test","type":"DYNAMIC"}],"scalar":{"value":128.0},"type":"SCALAR"}]
21:44:00 I1119 21:44:00.901283 13972 dynamic_reservation_framework.cpp:170] Launching task 2 using offer 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-O5
21:44:00 I1119 21:44:00.901464 13972 sched.cpp:914] Scheduler::resourceOffers took 2.243955ms
21:44:00 I1119 21:44:00.903192 13970 master.cpp:11513] Removing offer 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-O3
21:44:00 I1119 21:44:00.903584 13970 master.cpp:4511] Processing ACCEPT call for offers: [ 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-O3 ] on agent 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S0 at slave(3)@172.16.10.76:34786 (ip-172-16-10-76.ec2.internal) for framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 (Dynamic Reservation Framework (C++)) at scheduler-6c8bdf5c-fd05-4490-897f-7b33c7d00630@172.16.10.76:34786
21:44:00 I1119 21:44:00.903693 13970 master.cpp:3563] Authorizing framework principal 'test-principal' to launch task 0
21:44:00 I1119 21:44:00.905117 13970 master.cpp:11513] Removing offer 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-O4
21:44:00 I1119 21:44:00.905447 13970 master.cpp:4511] Processing ACCEPT call for offers: [ 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-O4 ] on agent 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S2 at slave(2)@172.16.10.76:34786 (ip-172-16-10-76.ec2.internal) for framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 (Dynamic Reservation Framework (C++)) at scheduler-6c8bdf5c-fd05-4490-897f-7b33c7d00630@172.16.10.76:34786
21:44:00 I1119 21:44:00.905534 13970 master.cpp:3563] Authorizing framework principal 'test-principal' to launch task 1
21:44:00 I1119 21:44:00.906716 13970 master.cpp:11513] Removing offer 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-O5
21:44:00 I1119 21:44:00.907016 13970 master.cpp:4511] Processing ACCEPT call for offers: [ 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-O5 ] on agent 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S1 at slave(1)@172.16.10.76:34786 (ip-172-16-10-76.ec2.internal) for framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 (Dynamic Reservation Framework (C++)) at scheduler-6c8bdf5c-fd05-4490-897f-7b33c7d00630@172.16.10.76:34786
21:44:00 I1119 21:44:00.907100 13970 master.cpp:3563] Authorizing framework principal 'test-principal' to launch task 2
21:44:00 I1119 21:44:00.908869 13970 master.cpp:4088] Adding task 0 with resources cpus(allocated: test)(reservations: [(DYNAMIC,test,test-principal)]):1; mem(allocated: test)(reservations: [(DYNAMIC,test,test-principal)]):128 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 (Dynamic Reservation Framework (C++)) at scheduler-6c8bdf5c-fd05-4490-897f-7b33c7d00630@172.16.10.76:34786 on agent 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S0 at slave(3)@172.16.10.76:34786 (ip-172-16-10-76.ec2.internal)
21:44:00 I1119 21:44:00.909955 13970 master.cpp:5483] Launching task 0 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 (Dynamic Reservation Framework (C++)) at scheduler-6c8bdf5c-fd05-4490-897f-7b33c7d00630@172.16.10.76:34786 with resources [{"allocation_info":{"role":"test"},"name":"cpus","reservations":[{"principal":"test-principal","role":"test","type":"DYNAMIC"}],"scalar":{"value":1.0},"type":"SCALAR"},{"allocation_info":{"role":"test"},"name":"mem","reservations":[{"principal":"test-principal","role":"test","type":"DYNAMIC"}],"scalar":{"value":128.0},"type":"SCALAR"}] on agent 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S0 at slave(3)@172.16.10.76:34786 (ip-172-16-10-76.ec2.internal) on new executor
21:44:00 I1119 21:44:00.911324 13970 master.cpp:4088] Adding task 1 with resources cpus(allocated: test)(reservations: [(DYNAMIC,test,test-principal)]):1; mem(allocated: test)(reservations: [(DYNAMIC,test,test-principal)]):128 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 (Dynamic Reservation Framework (C++)) at scheduler-6c8bdf5c-fd05-4490-897f-7b33c7d00630@172.16.10.76:34786 on agent 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S2 at slave(2)@172.16.10.76:34786 (ip-172-16-10-76.ec2.internal)
21:44:00 I1119 21:44:00.911504 13968 slave.cpp:2020] Got assigned task '0' for framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000
21:44:00 I1119 21:44:00.911869 13970 master.cpp:5483] Launching task 1 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 (Dynamic Reservation Framework (C++)) at scheduler-6c8bdf5c-fd05-4490-897f-7b33c7d00630@172.16.10.76:34786 with resources [{"allocation_info":{"role":"test"},"name":"cpus","reservations":[{"principal":"test-principal","role":"test","type":"DYNAMIC"}],"scalar":{"value":1.0},"type":"SCALAR"},{"allocation_info":{"role":"test"},"name":"mem","reservations":[{"principal":"test-principal","role":"test","type":"DYNAMIC"}],"scalar":{"value":128.0},"type":"SCALAR"}] on agent 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S2 at slave(2)@172.16.10.76:34786 (ip-172-16-10-76.ec2.internal) on new executor
21:44:00 I1119 21:44:00.913131 13970 master.cpp:4088] Adding task 2 with resources cpus(allocated: test)(reservations: [(DYNAMIC,test,test-principal)]):1; mem(allocated: test)(reservations: [(DYNAMIC,test,test-principal)]):128 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 (Dynamic Reservation Framework (C++)) at scheduler-6c8bdf5c-fd05-4490-897f-7b33c7d00630@172.16.10.76:34786 on agent 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S1 at slave(1)@172.16.10.76:34786 (ip-172-16-10-76.ec2.internal)
21:44:00 I1119 21:44:00.913668 13970 master.cpp:5483] Launching task 2 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 (Dynamic Reservation Framework (C++)) at scheduler-6c8bdf5c-fd05-4490-897f-7b33c7d00630@172.16.10.76:34786 with resources [{"allocation_info":{"role":"test"},"name":"cpus","reservations":[{"principal":"test-principal","role":"test","type":"DYNAMIC"}],"scalar":{"value":1.0},"type":"SCALAR"},{"allocation_info":{"role":"test"},"name":"mem","reservations":[{"principal":"test-principal","role":"test","type":"DYNAMIC"}],"scalar":{"value":128.0},"type":"SCALAR"}] on agent 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S1 at slave(1)@172.16.10.76:34786 (ip-172-16-10-76.ec2.internal) on new executor
21:44:00 I1119 21:44:00.914518 13968 slave.cpp:2394] Authorizing task '0' for framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000
21:44:00 I1119 21:44:00.914589 13968 slave.cpp:8472] Authorizing framework principal 'test-principal' to launch task 0
21:44:00 I1119 21:44:00.914840 13970 hierarchical.cpp:1238] Recovered cpus(allocated: test):1; mem(allocated: test):6668; disk(allocated: test):35828; ports(allocated: test):[31000-32000] (total: cpus:1; mem:6668; disk:35828; ports:[31000-32000]; cpus(reservations: [(DYNAMIC,test,test-principal)]):1; mem(reservations: [(DYNAMIC,test,test-principal)]):128, allocated: mem(allocated: test)(reservations: [(DYNAMIC,test,test-principal)]):128; cpus(allocated: test)(reservations: [(DYNAMIC,test,test-principal)]):1) on agent 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S0 from framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000
21:44:00 I1119 21:44:00.915587 13970 hierarchical.cpp:1238] Recovered cpus(allocated: test):1; mem(allocated: test):6668; disk(allocated: test):35828; ports(allocated: test):[31000-32000] (total: cpus:1; mem:6668; disk:35828; ports:[31000-32000]; cpus(reservations: [(DYNAMIC,test,test-principal)]):1; mem(reservations: [(DYNAMIC,test,test-principal)]):128, allocated: mem(allocated: test)(reservations: [(DYNAMIC,test,test-principal)]):128; cpus(allocated: test)(reservations: [(DYNAMIC,test,test-principal)]):1) on agent 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S2 from framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000
21:44:00 I1119 21:44:00.916205 13968 slave.cpp:2020] Got assigned task '1' for framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000
21:44:00 I1119 21:44:00.916251 13970 hierarchical.cpp:1238] Recovered cpus(allocated: test):1; mem(allocated: test):6668; disk(allocated: test):35828; ports(allocated: test):[31000-32000] (total: cpus:1; mem:6668; disk:35828; ports:[31000-32000]; cpus(reservations: [(DYNAMIC,test,test-principal)]):1; mem(reservations: [(DYNAMIC,test,test-principal)]):128, allocated: mem(allocated: test)(reservations: [(DYNAMIC,test,test-principal)]):128; cpus(allocated: test)(reservations: [(DYNAMIC,test,test-principal)]):1) on agent 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S1 from framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000
21:44:00 I1119 21:44:00.917264 13970 slave.cpp:2020] Got assigned task '2' for framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000
21:44:00 I1119 21:44:00.917484 13968 slave.cpp:2394] Authorizing task '1' for framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000
21:44:00 I1119 21:44:00.917526 13968 slave.cpp:8472] Authorizing framework principal 'test-principal' to launch task 1
21:44:00 I1119 21:44:00.918474 13970 slave.cpp:2394] Authorizing task '2' for framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000
21:44:00 I1119 21:44:00.918526 13970 slave.cpp:8472] Authorizing framework principal 'test-principal' to launch task 2
21:44:00 I1119 21:44:00.921999 13970 slave.cpp:2837] Launching task '0' for framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000
21:44:00 I1119 21:44:00.922106 13970 paths.cpp:752] Creating sandbox '/tmp/mesos-JDy6aV/agents/2/work/slaves/0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S0/frameworks/0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000/executors/0/runs/2b6f1c26-ef43-46e7-b113-36f5ac1cc315' for user 'root'
21:44:00 I1119 21:44:00.922003 13969 slave.cpp:2837] Launching task '1' for framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000
21:44:00 I1119 21:44:00.922286 13969 paths.cpp:752] Creating sandbox '/tmp/mesos-JDy6aV/agents/1/work/slaves/0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S2/frameworks/0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000/executors/1/runs/461b9cfc-f631-42f4-8305-a4d4439699b4' for user 'root'
21:44:00 I1119 21:44:00.923187 13970 slave.cpp:9000] Launching executor '0' of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 with resources [{"allocation_info":{"role":"test"},"name":"cpus","scalar":{"value":0.1},"type":"SCALAR"},{"allocation_info":{"role":"test"},"name":"mem","scalar":{"value":32.0},"type":"SCALAR"}] in work directory '/tmp/mesos-JDy6aV/agents/2/work/slaves/0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S0/frameworks/0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000/executors/0/runs/2b6f1c26-ef43-46e7-b113-36f5ac1cc315'
21:44:00 I1119 21:44:00.923959 13968 slave.cpp:2837] Launching task '2' for framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000
21:44:00 I1119 21:44:00.924031 13968 paths.cpp:752] Creating sandbox '/tmp/mesos-JDy6aV/agents/0/work/slaves/0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S1/frameworks/0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000/executors/2/runs/525ae395-1c1c-48c9-9a4f-7329d9bcb759' for user 'root'
21:44:00 I1119 21:44:00.924226 13970 slave.cpp:3515] Launching container 2b6f1c26-ef43-46e7-b113-36f5ac1cc315 for executor '0' of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000
21:44:00 I1119 21:44:00.924795 13968 slave.cpp:9000] Launching executor '2' of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 with resources [{"allocation_info":{"role":"test"},"name":"cpus","scalar":{"value":0.1},"type":"SCALAR"},{"allocation_info":{"role":"test"},"name":"mem","scalar":{"value":32.0},"type":"SCALAR"}] in work directory '/tmp/mesos-JDy6aV/agents/0/work/slaves/0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S1/frameworks/0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000/executors/2/runs/525ae395-1c1c-48c9-9a4f-7329d9bcb759'
21:44:00 I1119 21:44:00.925444 13968 slave.cpp:3515] Launching container 525ae395-1c1c-48c9-9a4f-7329d9bcb759 for executor '2' of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000
21:44:00 I1119 21:44:00.925662 13970 slave.cpp:3034] Queued task '0' for executor '0' of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000
21:44:00 I1119 21:44:00.925946 13968 slave.cpp:3034] Queued task '2' for executor '2' of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000
21:44:00 I1119 21:44:00.927613 13971 slave.cpp:994] Successfully attached '/tmp/mesos-JDy6aV/agents/0/work/slaves/0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S1/frameworks/0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000/executors/2/runs/525ae395-1c1c-48c9-9a4f-7329d9bcb759' to virtual path '/tmp/mesos-JDy6aV/agents/0/work/slaves/0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S1/frameworks/0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000/executors/2/runs/latest'
21:44:00 I1119 21:44:00.927664 13971 slave.cpp:994] Successfully attached '/tmp/mesos-JDy6aV/agents/0/work/slaves/0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S1/frameworks/0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000/executors/2/runs/525ae395-1c1c-48c9-9a4f-7329d9bcb759' to virtual path '/frameworks/0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000/executors/2/runs/latest'
21:44:00 I1119 21:44:00.927739 13969 slave.cpp:9000] Launching executor '1' of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 with resources [{"allocation_info":{"role":"test"},"name":"cpus","scalar":{"value":0.1},"type":"SCALAR"},{"allocation_info":{"role":"test"},"name":"mem","scalar":{"value":32.0},"type":"SCALAR"}] in work directory '/tmp/mesos-JDy6aV/agents/1/work/slaves/0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S2/frameworks/0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000/executors/1/runs/461b9cfc-f631-42f4-8305-a4d4439699b4'
21:44:00 I1119 21:44:00.928040 13971 slave.cpp:994] Successfully attached '/tmp/mesos-JDy6aV/agents/0/work/slaves/0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S1/frameworks/0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000/executors/2/runs/525ae395-1c1c-48c9-9a4f-7329d9bcb759' to virtual path '/tmp/mesos-JDy6aV/agents/0/work/slaves/0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S1/frameworks/0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000/executors/2/runs/525ae395-1c1c-48c9-9a4f-7329d9bcb759'
21:44:00 I1119 21:44:00.928242 13971 containerizer.cpp:1288] Starting container 525ae395-1c1c-48c9-9a4f-7329d9bcb759
21:44:00 I1119 21:44:00.928421 13969 slave.cpp:3515] Launching container 461b9cfc-f631-42f4-8305-a4d4439699b4 for executor '1' of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000
21:44:00 I1119 21:44:00.928938 13969 slave.cpp:3034] Queued task '1' for executor '1' of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000
21:44:00 I1119 21:44:00.930126 13969 slave.cpp:994] Successfully attached '/tmp/mesos-JDy6aV/agents/1/work/slaves/0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S2/frameworks/0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000/executors/1/runs/461b9cfc-f631-42f4-8305-a4d4439699b4' to virtual path '/tmp/mesos-JDy6aV/agents/1/work/slaves/0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S2/frameworks/0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000/executors/1/runs/latest'
21:44:00 I1119 21:44:00.930161 13969 slave.cpp:994] Successfully attached '/tmp/mesos-JDy6aV/agents/1/work/slaves/0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S2/frameworks/0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000/executors/1/runs/461b9cfc-f631-42f4-8305-a4d4439699b4' to virtual path '/frameworks/0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000/executors/1/runs/latest'
21:44:00 I1119 21:44:00.930182 13969 slave.cpp:994] Successfully attached '/tmp/mesos-JDy6aV/agents/1/work/slaves/0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S2/frameworks/0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000/executors/1/runs/461b9cfc-f631-42f4-8305-a4d4439699b4' to virtual path '/tmp/mesos-JDy6aV/agents/1/work/slaves/0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S2/frameworks/0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000/executors/1/runs/461b9cfc-f631-42f4-8305-a4d4439699b4'
21:44:00 I1119 21:44:00.930469 13967 containerizer.cpp:1288] Starting container 461b9cfc-f631-42f4-8305-a4d4439699b4
21:44:00 I1119 21:44:00.930563 13970 slave.cpp:994] Successfully attached '/tmp/mesos-JDy6aV/agents/2/work/slaves/0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S0/frameworks/0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000/executors/0/runs/2b6f1c26-ef43-46e7-b113-36f5ac1cc315' to virtual path '/tmp/mesos-JDy6aV/agents/2/work/slaves/0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S0/frameworks/0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000/executors/0/runs/latest'
21:44:00 I1119 21:44:00.930599 13970 slave.cpp:994] Successfully attached '/tmp/mesos-JDy6aV/agents/2/work/slaves/0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S0/frameworks/0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000/executors/0/runs/2b6f1c26-ef43-46e7-b113-36f5ac1cc315' to virtual path '/frameworks/0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000/executors/0/runs/latest'
21:44:00 I1119 21:44:00.930855 13970 slave.cpp:994] Successfully attached '/tmp/mesos-JDy6aV/agents/2/work/slaves/0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S0/frameworks/0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000/executors/0/runs/2b6f1c26-ef43-46e7-b113-36f5ac1cc315' to virtual path '/tmp/mesos-JDy6aV/agents/2/work/slaves/0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S0/frameworks/0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000/executors/0/runs/2b6f1c26-ef43-46e7-b113-36f5ac1cc315'
21:44:00 I1119 21:44:00.930958 13970 containerizer.cpp:1288] Starting container 2b6f1c26-ef43-46e7-b113-36f5ac1cc315
21:44:00 I1119 21:44:00.932840 13971 containerizer.cpp:1454] Checkpointed ContainerConfig at '/tmp/mesos-JDy6aV/agents/0/run/containers/525ae395-1c1c-48c9-9a4f-7329d9bcb759/config'
21:44:00 I1119 21:44:00.932837 13970 containerizer.cpp:1454] Checkpointed ContainerConfig at '/tmp/mesos-JDy6aV/agents/2/run/containers/2b6f1c26-ef43-46e7-b113-36f5ac1cc315/config'
21:44:00 I1119 21:44:00.932885 13971 containerizer.cpp:3130] Transitioning the state of container 525ae395-1c1c-48c9-9a4f-7329d9bcb759 from PROVISIONING to PREPARING
21:44:00 I1119 21:44:00.932889 13970 containerizer.cpp:3130] Transitioning the state of container 2b6f1c26-ef43-46e7-b113-36f5ac1cc315 from PROVISIONING to PREPARING
21:44:01 I1119 21:44:00.941905 13967 containerizer.cpp:1454] Checkpointed ContainerConfig at '/tmp/mesos-JDy6aV/agents/1/run/containers/461b9cfc-f631-42f4-8305-a4d4439699b4/config'
21:44:01 I1119 21:44:00.941936 13967 containerizer.cpp:3130] Transitioning the state of container 461b9cfc-f631-42f4-8305-a4d4439699b4 from PROVISIONING to PREPARING
21:44:01 I1119 21:44:00.942562 13969 containerizer.cpp:1947] Launching 'mesos-containerizer' with flags '--help="false" --launch_info="{"command":{"arguments":["mesos-executor","--launcher_dir=/home/centos/workspace/mesos/Mesos_CI-build/FLAG/CMake/label/mesos-ec2-centos-7/mesos/build/src"],"shell":false,"value":"/home/centos/workspace/mesos/Mesos_CI-build/FLAG/CMake/label/mesos-ec2-centos-7/mesos/build/src/mesos-executor"},"environment":{"variables":[{"name":"LIBPROCESS_PORT","type":"VALUE","value":"0"},{"name":"MESOS_AGENT_ENDPOINT","type":"VALUE","value":"172.16.10.76:34786"},{"name":"MESOS_CHECKPOINT","type":"VALUE","value":"0"},{"name":"MESOS_DIRECTORY","type":"VALUE","value":"/tmp/mesos-JDy6aV/agents/2/work/slaves/0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S0/frameworks/0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000/executors/0/runs/2b6f1c26-ef43-46e7-b113-36f5ac1cc315"},{"name":"MESOS_EXECUTOR_ID","type":"VALUE","value":"0"},{"name":"MESOS_EXECUTOR_SHUTDOWN_GRACE_PERIOD","type":"VALUE","value":"5secs"},{"name":"MESOS_FRAMEWORK_ID","type":"VALUE","value":"0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000"},{"name":"MESOS_HTTP_COMMAND_EXECUTOR","type":"VALUE","value":"0"},{"name":"MESOS_SLAVE_ID","type":"VALUE","value":"0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S0"},{"name":"MESOS_SLAVE_PID","type":"VALUE","value":"slave(3)@172.16.10.76:34786"},{"name":"MESOS_SANDBOX","type":"VALUE","value":"/tmp/mesos-JDy6aV/agents/2/work/slaves/0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S0/frameworks/0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000/executors/0/runs/2b6f1c26-ef43-46e7-b113-36f5ac1cc315"}]},"task_environment":{},"user":"root","working_directory":"/tmp/mesos-JDy6aV/agents/2/work/slaves/0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S0/frameworks/0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000/executors/0/runs/2b6f1c26-ef43-46e7-b113-36f5ac1cc315"}" --pipe_read="20" --pipe_write="23" --runtime_directory="/tmp/mesos-JDy6aV/agents/2/run/containers/2b6f1c26-ef43-46e7-b113-36f5ac1cc315" --unshare_namespace_mnt="false"'
21:44:01 I1119 21:44:00.947026 13969 launcher.cpp:145] Forked child with pid '13978' for container '2b6f1c26-ef43-46e7-b113-36f5ac1cc315'
21:44:01 I1119 21:44:00.951062 13972 containerizer.cpp:1947] Launching 'mesos-containerizer' with flags '--help="false" --launch_info="{"command":{"arguments":["mesos-executor","--launcher_dir=/home/centos/workspace/mesos/Mesos_CI-build/FLAG/CMake/label/mesos-ec2-centos-7/mesos/build/src"],"shell":false,"value":"/home/centos/workspace/mesos/Mesos_CI-build/FLAG/CMake/label/mesos-ec2-centos-7/mesos/build/src/mesos-executor"},"environment":{"variables":[{"name":"LIBPROCESS_PORT","type":"VALUE","value":"0"},{"name":"MESOS_AGENT_ENDPOINT","type":"VALUE","value":"172.16.10.76:34786"},{"name":"MESOS_CHECKPOINT","type":"VALUE","value":"0"},{"name":"MESOS_DIRECTORY","type":"VALUE","value":"/tmp/mesos-JDy6aV/agents/0/work/slaves/0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S1/frameworks/0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000/executors/2/runs/525ae395-1c1c-48c9-9a4f-7329d9bcb759"},{"name":"MESOS_EXECUTOR_ID","type":"VALUE","value":"2"},{"name":"MESOS_EXECUTOR_SHUTDOWN_GRACE_PERIOD","type":"VALUE","value":"5secs"},{"name":"MESOS_FRAMEWORK_ID","type":"VALUE","value":"0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000"},{"name":"MESOS_HTTP_COMMAND_EXECUTOR","type":"VALUE","value":"0"},{"name":"MESOS_SLAVE_ID","type":"VALUE","value":"0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S1"},{"name":"MESOS_SLAVE_PID","type":"VALUE","value":"slave(1)@172.16.10.76:34786"},{"name":"MESOS_SANDBOX","type":"VALUE","value":"/tmp/mesos-JDy6aV/agents/0/work/slaves/0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S1/frameworks/0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000/executors/2/runs/525ae395-1c1c-48c9-9a4f-7329d9bcb759"}]},"task_environment":{},"user":"root","working_directory":"/tmp/mesos-JDy6aV/agents/0/work/slaves/0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S1/frameworks/0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000/executors/2/runs/525ae395-1c1c-48c9-9a4f-7329d9bcb759"}" --pipe_read="24" --pipe_write="25" --runtime_directory="/tmp/mesos-JDy6aV/agents/0/run/containers/525ae395-1c1c-48c9-9a4f-7329d9bcb759" --unshare_namespace_mnt="false"'
21:44:01 I1119 21:44:00.952868 13972 launcher.cpp:145] Forked child with pid '13979' for container '525ae395-1c1c-48c9-9a4f-7329d9bcb759'
21:44:01 I1119 21:44:00.954741 13972 containerizer.cpp:3130] Transitioning the state of container 525ae395-1c1c-48c9-9a4f-7329d9bcb759 from PREPARING to ISOLATING
21:44:01 I1119 21:44:00.960245 13965 containerizer.cpp:1947] Launching 'mesos-containerizer' with flags '--help="false" --launch_info="{"command":{"arguments":["mesos-executor","--launcher_dir=/home/centos/workspace/mesos/Mesos_CI-build/FLAG/CMake/label/mesos-ec2-centos-7/mesos/build/src"],"shell":false,"value":"/home/centos/workspace/mesos/Mesos_CI-build/FLAG/CMake/label/mesos-ec2-centos-7/mesos/build/src/mesos-executor"},"environment":{"variables":[{"name":"LIBPROCESS_PORT","type":"VALUE","value":"0"},{"name":"MESOS_AGENT_ENDPOINT","type":"VALUE","value":"172.16.10.76:34786"},{"name":"MESOS_CHECKPOINT","type":"VALUE","value":"0"},{"name":"MESOS_DIRECTORY","type":"VALUE","value":"/tmp/mesos-JDy6aV/agents/1/work/slaves/0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S2/frameworks/0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000/executors/1/runs/461b9cfc-f631-42f4-8305-a4d4439699b4"},{"name":"MESOS_EXECUTOR_ID","type":"VALUE","value":"1"},{"name":"MESOS_EXECUTOR_SHUTDOWN_GRACE_PERIOD","type":"VALUE","value":"5secs"},{"name":"MESOS_FRAMEWORK_ID","type":"VALUE","value":"0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000"},{"name":"MESOS_HTTP_COMMAND_EXECUTOR","type":"VALUE","value":"0"},{"name":"MESOS_SLAVE_ID","type":"VALUE","value":"0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S2"},{"name":"MESOS_SLAVE_PID","type":"VALUE","value":"slave(2)@172.16.10.76:34786"},{"name":"MESOS_SANDBOX","type":"VALUE","value":"/tmp/mesos-JDy6aV/agents/1/work/slaves/0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S2/frameworks/0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000/executors/1/runs/461b9cfc-f631-42f4-8305-a4d4439699b4"}]},"task_environment":{},"user":"root","working_directory":"/tmp/mesos-JDy6aV/agents/1/work/slaves/0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S2/frameworks/0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000/executors/1/runs/461b9cfc-f631-42f4-8305-a4d4439699b4"}" --pipe_read="26" --pipe_write="27" --runtime_directory="/tmp/mesos-JDy6aV/agents/1/run/containers/461b9cfc-f631-42f4-8305-a4d4439699b4" --unshare_namespace_mnt="false"'
21:44:01 I1119 21:44:00.962139 13965 launcher.cpp:145] Forked child with pid '13980' for container '461b9cfc-f631-42f4-8305-a4d4439699b4'
21:44:01 I1119 21:44:00.963304 13969 containerizer.cpp:3130] Transitioning the state of container 2b6f1c26-ef43-46e7-b113-36f5ac1cc315 from PREPARING to ISOLATING
21:44:01 I1119 21:44:00.963320 13965 containerizer.cpp:3130] Transitioning the state of container 461b9cfc-f631-42f4-8305-a4d4439699b4 from PREPARING to ISOLATING
21:44:01 I1119 21:44:00.966850 13966 containerizer.cpp:3130] Transitioning the state of container 525ae395-1c1c-48c9-9a4f-7329d9bcb759 from ISOLATING to FETCHING
21:44:01 I1119 21:44:00.969605 13965 fetcher.cpp:369] Starting to fetch URIs for container: 525ae395-1c1c-48c9-9a4f-7329d9bcb759, directory: /tmp/mesos-JDy6aV/agents/0/work/slaves/0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S1/frameworks/0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000/executors/2/runs/525ae395-1c1c-48c9-9a4f-7329d9bcb759
21:44:01 I1119 21:44:00.970595 13969 containerizer.cpp:3130] Transitioning the state of container 2b6f1c26-ef43-46e7-b113-36f5ac1cc315 from ISOLATING to FETCHING
21:44:01 I1119 21:44:00.971704 13969 fetcher.cpp:369] Starting to fetch URIs for container: 2b6f1c26-ef43-46e7-b113-36f5ac1cc315, directory: /tmp/mesos-JDy6aV/agents/2/work/slaves/0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S0/frameworks/0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000/executors/0/runs/2b6f1c26-ef43-46e7-b113-36f5ac1cc315
21:44:01 I1119 21:44:00.974714 13969 containerizer.cpp:3130] Transitioning the state of container 461b9cfc-f631-42f4-8305-a4d4439699b4 from ISOLATING to FETCHING
21:44:01 I1119 21:44:00.975037 13969 containerizer.cpp:3130] Transitioning the state of container 2b6f1c26-ef43-46e7-b113-36f5ac1cc315 from FETCHING to RUNNING
21:44:01 I1119 21:44:00.975906 13969 fetcher.cpp:369] Starting to fetch URIs for container: 461b9cfc-f631-42f4-8305-a4d4439699b4, directory: /tmp/mesos-JDy6aV/agents/1/work/slaves/0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S2/frameworks/0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000/executors/1/runs/461b9cfc-f631-42f4-8305-a4d4439699b4
21:44:01 I1119 21:44:00.977767 13965 containerizer.cpp:3130] Transitioning the state of container 461b9cfc-f631-42f4-8305-a4d4439699b4 from FETCHING to RUNNING
21:44:01 I1119 21:44:00.978091 13969 containerizer.cpp:3130] Transitioning the state of container 525ae395-1c1c-48c9-9a4f-7329d9bcb759 from FETCHING to RUNNING
21:44:01 I1119 21:44:01.328681 13981 exec.cpp:162] Version: 1.8.0
21:44:01 I1119 21:44:01.349761 13970 slave.cpp:4809] Got registration for executor '1' of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 from executor(1)@172.16.10.76:36350
21:44:01 I1119 21:44:01.355062 13969 slave.cpp:3247] Sending queued task '1' to executor '1' of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 at executor(1)@172.16.10.76:36350
21:44:01 I1119 21:44:01.364338 13989 exec.cpp:236] Executor registered on agent 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S2
21:44:01 I1119 21:44:01.368993 13989 executor.cpp:184] Received SUBSCRIBED event
21:44:01 I1119 21:44:01.369977 13989 executor.cpp:188] Subscribed executor on ip-172-16-10-76.ec2.internal
21:44:01 I1119 21:44:01.370147 13989 executor.cpp:184] Received LAUNCH event
21:44:01 I1119 21:44:01.370663 13989 executor.cpp:687] Starting task 1
21:44:01 I1119 21:44:01.385877 13967 slave.cpp:5275] Handling status update TASK_STARTING (Status UUID: 928d26af-437a-4cf6-b9c8-b44171f32b94) for task 1 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 from executor(1)@172.16.10.76:36350
21:44:01 I1119 21:44:01.393554 13967 task_status_update_manager.cpp:328] Received task status update TASK_STARTING (Status UUID: 928d26af-437a-4cf6-b9c8-b44171f32b94) for task 1 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000
21:44:01 I1119 21:44:01.393622 13967 task_status_update_manager.cpp:507] Creating StatusUpdate stream for task 1 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000
21:44:01 I1119 21:44:01.394486 13967 task_status_update_manager.cpp:383] Forwarding task status update TASK_STARTING (Status UUID: 928d26af-437a-4cf6-b9c8-b44171f32b94) for task 1 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 to the agent
21:44:01 I1119 21:44:01.395072 13967 slave.cpp:5767] Forwarding the update TASK_STARTING (Status UUID: 928d26af-437a-4cf6-b9c8-b44171f32b94) for task 1 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 to master@172.16.10.76:34786
21:44:01 I1119 21:44:01.395397 13967 slave.cpp:5660] Task status update manager successfully handled status update TASK_STARTING (Status UUID: 928d26af-437a-4cf6-b9c8-b44171f32b94) for task 1 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000
21:44:01 I1119 21:44:01.395467 13967 slave.cpp:5676] Sending acknowledgement for status update TASK_STARTING (Status UUID: 928d26af-437a-4cf6-b9c8-b44171f32b94) for task 1 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 to executor(1)@172.16.10.76:36350
21:44:01 I1119 21:44:01.395658 13966 master.cpp:8420] Status update TASK_STARTING (Status UUID: 928d26af-437a-4cf6-b9c8-b44171f32b94) for task 1 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 from agent 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S2 at slave(2)@172.16.10.76:34786 (ip-172-16-10-76.ec2.internal)
21:44:01 I1119 21:44:01.395720 13966 master.cpp:8477] Forwarding status update TASK_STARTING (Status UUID: 928d26af-437a-4cf6-b9c8-b44171f32b94) for task 1 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000
21:44:01 I1119 21:44:01.396008 13966 master.cpp:10978] Updating the state of task 1 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 (latest state: TASK_STARTING, status update state: TASK_STARTING)
21:44:01 I1119 21:44:01.396322 13966 dynamic_reservation_framework.cpp:231] Task 1 is in state TASK_STARTING
21:44:01 I1119 21:44:01.396347 13966 sched.cpp:1022] Scheduler::statusUpdate took 25747ns
21:44:01 I1119 21:44:01.396726 13966 master.cpp:6286] Processing ACKNOWLEDGE call for status 928d26af-437a-4cf6-b9c8-b44171f32b94 for task 1 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 (Dynamic Reservation Framework (C++)) at scheduler-6c8bdf5c-fd05-4490-897f-7b33c7d00630@172.16.10.76:34786 on agent 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S2
21:44:01 I1119 21:44:01.397348 13966 task_status_update_manager.cpp:401] Received task status update acknowledgement (UUID: 928d26af-437a-4cf6-b9c8-b44171f32b94) for task 1 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000
21:44:01 I1119 21:44:01.397902 13969 slave.cpp:4511] Task status update manager successfully handled status update acknowledgement (UUID: 928d26af-437a-4cf6-b9c8-b44171f32b94) for task 1 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000
21:44:01 I1119 21:44:01.416920 13989 executor.cpp:502] Running '/home/centos/workspace/mesos/Mesos_CI-build/FLAG/CMake/label/mesos-ec2-centos-7/mesos/build/src/mesos-containerizer launch <POSSIBLY-SENSITIVE-DATA>'
21:44:01 I1119 21:44:01.420053 13989 executor.cpp:702] Forked command at 13993
21:44:01 I1119 21:44:01.426112 13966 slave.cpp:5275] Handling status update TASK_RUNNING (Status UUID: 3e04893b-ff3e-427c-be53-6acb27f2680b) for task 1 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 from executor(1)@172.16.10.76:36350
21:44:01 I1119 21:44:01.429504 13966 task_status_update_manager.cpp:328] Received task status update TASK_RUNNING (Status UUID: 3e04893b-ff3e-427c-be53-6acb27f2680b) for task 1 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000
21:44:01 I1119 21:44:01.429656 13966 task_status_update_manager.cpp:383] Forwarding task status update TASK_RUNNING (Status UUID: 3e04893b-ff3e-427c-be53-6acb27f2680b) for task 1 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 to the agent
21:44:01 I1119 21:44:01.430030 13966 slave.cpp:5767] Forwarding the update TASK_RUNNING (Status UUID: 3e04893b-ff3e-427c-be53-6acb27f2680b) for task 1 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 to master@172.16.10.76:34786
21:44:01 I1119 21:44:01.430202 13966 slave.cpp:5660] Task status update manager successfully handled status update TASK_RUNNING (Status UUID: 3e04893b-ff3e-427c-be53-6acb27f2680b) for task 1 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000
21:44:01 I1119 21:44:01.430246 13966 slave.cpp:5676] Sending acknowledgement for status update TASK_RUNNING (Status UUID: 3e04893b-ff3e-427c-be53-6acb27f2680b) for task 1 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 to executor(1)@172.16.10.76:36350
21:44:01 I1119 21:44:01.430613 13970 master.cpp:8420] Status update TASK_RUNNING (Status UUID: 3e04893b-ff3e-427c-be53-6acb27f2680b) for task 1 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 from agent 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S2 at slave(2)@172.16.10.76:34786 (ip-172-16-10-76.ec2.internal)
21:44:01 I1119 21:44:01.430667 13970 master.cpp:8477] Forwarding status update TASK_RUNNING (Status UUID: 3e04893b-ff3e-427c-be53-6acb27f2680b) for task 1 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000
21:44:01 I1119 21:44:01.430879 13970 master.cpp:10978] Updating the state of task 1 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 (latest state: TASK_RUNNING, status update state: TASK_RUNNING)
21:44:01 I1119 21:44:01.431118 13970 dynamic_reservation_framework.cpp:231] Task 1 is in state TASK_RUNNING
21:44:01 I1119 21:44:01.431136 13970 sched.cpp:1022] Scheduler::statusUpdate took 20883ns
21:44:01 I1119 21:44:01.431407 13970 master.cpp:6286] Processing ACKNOWLEDGE call for status 3e04893b-ff3e-427c-be53-6acb27f2680b for task 1 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 (Dynamic Reservation Framework (C++)) at scheduler-6c8bdf5c-fd05-4490-897f-7b33c7d00630@172.16.10.76:34786 on agent 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S2
21:44:01 I1119 21:44:01.432313 13966 task_status_update_manager.cpp:401] Received task status update acknowledgement (UUID: 3e04893b-ff3e-427c-be53-6acb27f2680b) for task 1 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000
21:44:01 I1119 21:44:01.432696 13966 slave.cpp:4511] Task status update manager successfully handled status update acknowledgement (UUID: 3e04893b-ff3e-427c-be53-6acb27f2680b) for task 1 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000
21:44:01 I1119 21:44:01.459226 13983 exec.cpp:162] Version: 1.8.0
21:44:01 I1119 21:44:01.481746 13968 slave.cpp:4809] Got registration for executor '0' of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 from executor(1)@172.16.10.76:38687
21:44:01 I1119 21:44:01.487349 13968 slave.cpp:3247] Sending queued task '0' to executor '0' of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 at executor(1)@172.16.10.76:38687
21:44:01 I1119 21:44:01.494725 13994 exec.cpp:236] Executor registered on agent 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S0
21:44:01 I1119 21:44:01.499750 13994 executor.cpp:184] Received SUBSCRIBED event
21:44:01 I1119 21:44:01.500708 13994 executor.cpp:188] Subscribed executor on ip-172-16-10-76.ec2.internal
21:44:01 I1119 21:44:01.500881 13994 executor.cpp:184] Received LAUNCH event
21:44:01 I1119 21:44:01.501405 13994 executor.cpp:687] Starting task 0
21:44:01 I1119 21:44:01.506439 14003 exec.cpp:162] Version: 1.8.0
21:44:01 I1119 21:44:01.514806 13972 slave.cpp:5275] Handling status update TASK_STARTING (Status UUID: a5fb4148-d5e7-4f44-97c7-4638e0aa0dcb) for task 0 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 from executor(1)@172.16.10.76:38687
21:44:01 I1119 21:44:01.518007 13965 task_status_update_manager.cpp:328] Received task status update TASK_STARTING (Status UUID: a5fb4148-d5e7-4f44-97c7-4638e0aa0dcb) for task 0 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000
21:44:01 I1119 21:44:01.518056 13965 task_status_update_manager.cpp:507] Creating StatusUpdate stream for task 0 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000
21:44:01 I1119 21:44:01.518626 13965 task_status_update_manager.cpp:383] Forwarding task status update TASK_STARTING (Status UUID: a5fb4148-d5e7-4f44-97c7-4638e0aa0dcb) for task 0 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 to the agent
21:44:01 I1119 21:44:01.519031 13965 slave.cpp:5767] Forwarding the update TASK_STARTING (Status UUID: a5fb4148-d5e7-4f44-97c7-4638e0aa0dcb) for task 0 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 to master@172.16.10.76:34786
21:44:01 I1119 21:44:01.519222 13965 slave.cpp:5660] Task status update manager successfully handled status update TASK_STARTING (Status UUID: a5fb4148-d5e7-4f44-97c7-4638e0aa0dcb) for task 0 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000
21:44:01 I1119 21:44:01.519274 13965 slave.cpp:5676] Sending acknowledgement for status update TASK_STARTING (Status UUID: a5fb4148-d5e7-4f44-97c7-4638e0aa0dcb) for task 0 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 to executor(1)@172.16.10.76:38687
21:44:01 I1119 21:44:01.520117 13965 master.cpp:8420] Status update TASK_STARTING (Status UUID: a5fb4148-d5e7-4f44-97c7-4638e0aa0dcb) for task 0 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 from agent 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S0 at slave(3)@172.16.10.76:34786 (ip-172-16-10-76.ec2.internal)
21:44:01 I1119 21:44:01.520171 13965 master.cpp:8477] Forwarding status update TASK_STARTING (Status UUID: a5fb4148-d5e7-4f44-97c7-4638e0aa0dcb) for task 0 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000
21:44:01 I1119 21:44:01.520411 13965 master.cpp:10978] Updating the state of task 0 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 (latest state: TASK_STARTING, status update state: TASK_STARTING)
21:44:01 I1119 21:44:01.520640 13965 dynamic_reservation_framework.cpp:231] Task 0 is in state TASK_STARTING
21:44:01 I1119 21:44:01.520658 13965 sched.cpp:1022] Scheduler::statusUpdate took 19631ns
21:44:01 I1119 21:44:01.520918 13965 master.cpp:6286] Processing ACKNOWLEDGE call for status a5fb4148-d5e7-4f44-97c7-4638e0aa0dcb for task 0 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 (Dynamic Reservation Framework (C++)) at scheduler-6c8bdf5c-fd05-4490-897f-7b33c7d00630@172.16.10.76:34786 on agent 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S0
21:44:01 I1119 21:44:01.521247 13965 task_status_update_manager.cpp:401] Received task status update acknowledgement (UUID: a5fb4148-d5e7-4f44-97c7-4638e0aa0dcb) for task 0 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000
21:44:01 I1119 21:44:01.525005 13969 slave.cpp:4809] Got registration for executor '2' of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 from executor(1)@172.16.10.76:35159
21:44:01 I1119 21:44:01.528702 13969 slave.cpp:3247] Sending queued task '2' to executor '2' of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 at executor(1)@172.16.10.76:35159
21:44:01 I1119 21:44:01.536106 13965 slave.cpp:4511] Task status update manager successfully handled status update acknowledgement (UUID: a5fb4148-d5e7-4f44-97c7-4638e0aa0dcb) for task 0 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000
21:44:01 I1119 21:44:01.539146 13994 executor.cpp:502] Running '/home/centos/workspace/mesos/Mesos_CI-build/FLAG/CMake/label/mesos-ec2-centos-7/mesos/build/src/mesos-containerizer launch <POSSIBLY-SENSITIVE-DATA>'
21:44:01 I1119 21:44:01.541213 14008 exec.cpp:236] Executor registered on agent 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S1
21:44:01 I1119 21:44:01.542239 13994 executor.cpp:702] Forked command at 14012
21:44:01 I1119 21:44:01.546123 13970 slave.cpp:5275] Handling status update TASK_RUNNING (Status UUID: 863e4a38-23a1-478a-ad46-8e8e552f6d07) for task 0 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 from executor(1)@172.16.10.76:38687
21:44:01 I1119 21:44:01.548782 13971 task_status_update_manager.cpp:328] Received task status update TASK_RUNNING (Status UUID: 863e4a38-23a1-478a-ad46-8e8e552f6d07) for task 0 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000
21:44:01 I1119 21:44:01.548943 13971 task_status_update_manager.cpp:383] Forwarding task status update TASK_RUNNING (Status UUID: 863e4a38-23a1-478a-ad46-8e8e552f6d07) for task 0 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 to the agent
21:44:01 I1119 21:44:01.549357 13971 slave.cpp:5767] Forwarding the update TASK_RUNNING (Status UUID: 863e4a38-23a1-478a-ad46-8e8e552f6d07) for task 0 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 to master@172.16.10.76:34786
21:44:01 I1119 21:44:01.549568 13971 slave.cpp:5660] Task status update manager successfully handled status update TASK_RUNNING (Status UUID: 863e4a38-23a1-478a-ad46-8e8e552f6d07) for task 0 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000
21:44:01 I1119 21:44:01.549616 13971 slave.cpp:5676] Sending acknowledgement for status update TASK_RUNNING (Status UUID: 863e4a38-23a1-478a-ad46-8e8e552f6d07) for task 0 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 to executor(1)@172.16.10.76:38687
21:44:01 I1119 21:44:01.549746 13972 master.cpp:8420] Status update TASK_RUNNING (Status UUID: 863e4a38-23a1-478a-ad46-8e8e552f6d07) for task 0 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 from agent 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S0 at slave(3)@172.16.10.76:34786 (ip-172-16-10-76.ec2.internal)
21:44:01 I1119 21:44:01.549801 13972 master.cpp:8477] Forwarding status update TASK_RUNNING (Status UUID: 863e4a38-23a1-478a-ad46-8e8e552f6d07) for task 0 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000
21:44:01 I1119 21:44:01.550035 13972 master.cpp:10978] Updating the state of task 0 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 (latest state: TASK_RUNNING, status update state: TASK_RUNNING)
21:44:01 I1119 21:44:01.550290 13972 dynamic_reservation_framework.cpp:231] Task 0 is in state TASK_RUNNING
21:44:01 I1119 21:44:01.550309 13972 sched.cpp:1022] Scheduler::statusUpdate took 21260ns
21:44:01 I1119 21:44:01.550607 13972 master.cpp:6286] Processing ACKNOWLEDGE call for status 863e4a38-23a1-478a-ad46-8e8e552f6d07 for task 0 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 (Dynamic Reservation Framework (C++)) at scheduler-6c8bdf5c-fd05-4490-897f-7b33c7d00630@172.16.10.76:34786 on agent 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S0
21:44:01 I1119 21:44:01.550941 13972 task_status_update_manager.cpp:401] Received task status update acknowledgement (UUID: 863e4a38-23a1-478a-ad46-8e8e552f6d07) for task 0 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000
21:44:01 I1119 21:44:01.551353 13972 slave.cpp:4511] Task status update manager successfully handled status update acknowledgement (UUID: 863e4a38-23a1-478a-ad46-8e8e552f6d07) for task 0 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000
21:44:01 I1119 21:44:01.553335 14008 executor.cpp:184] Received SUBSCRIBED event
21:44:01 I1119 21:44:01.554332 14008 executor.cpp:188] Subscribed executor on ip-172-16-10-76.ec2.internal
21:44:01 I1119 21:44:01.555662 14008 executor.cpp:184] Received LAUNCH event
21:44:01 I1119 21:44:01.556164 14008 executor.cpp:687] Starting task 2
21:44:01 I1119 21:44:01.571473 14008 executor.cpp:502] Running '/home/centos/workspace/mesos/Mesos_CI-build/FLAG/CMake/label/mesos-ec2-centos-7/mesos/build/src/mesos-containerizer launch <POSSIBLY-SENSITIVE-DATA>'
21:44:01 I1119 21:44:01.574616 14008 executor.cpp:702] Forked command at 14013
21:44:01 I1119 21:44:01.584978 13972 slave.cpp:5275] Handling status update TASK_STARTING (Status UUID: f1764db4-9c5f-4dc4-8d7d-0bde0eb711ee) for task 2 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 from executor(1)@172.16.10.76:35159
21:44:01 I1119 21:44:01.588280 13967 task_status_update_manager.cpp:328] Received task status update TASK_STARTING (Status UUID: f1764db4-9c5f-4dc4-8d7d-0bde0eb711ee) for task 2 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000
21:44:01 I1119 21:44:01.588330 13967 task_status_update_manager.cpp:507] Creating StatusUpdate stream for task 2 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000
21:44:01 I1119 21:44:01.588917 13967 task_status_update_manager.cpp:383] Forwarding task status update TASK_STARTING (Status UUID: f1764db4-9c5f-4dc4-8d7d-0bde0eb711ee) for task 2 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 to the agent
21:44:01 I1119 21:44:01.589409 13967 slave.cpp:5275] Handling status update TASK_RUNNING (Status UUID: 3ce2314d-2d06-4d5c-9a0f-8cdc828c8771) for task 2 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 from executor(1)@172.16.10.76:35159
21:44:01 I1119 21:44:01.589658 13967 slave.cpp:5767] Forwarding the update TASK_STARTING (Status UUID: f1764db4-9c5f-4dc4-8d7d-0bde0eb711ee) for task 2 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 to master@172.16.10.76:34786
21:44:01 I1119 21:44:01.589846 13967 slave.cpp:5660] Task status update manager successfully handled status update TASK_STARTING (Status UUID: f1764db4-9c5f-4dc4-8d7d-0bde0eb711ee) for task 2 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000
21:44:01 I1119 21:44:01.589900 13967 slave.cpp:5676] Sending acknowledgement for status update TASK_STARTING (Status UUID: f1764db4-9c5f-4dc4-8d7d-0bde0eb711ee) for task 2 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 to executor(1)@172.16.10.76:35159
21:44:01 I1119 21:44:01.590602 13966 master.cpp:8420] Status update TASK_STARTING (Status UUID: f1764db4-9c5f-4dc4-8d7d-0bde0eb711ee) for task 2 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 from agent 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S1 at slave(1)@172.16.10.76:34786 (ip-172-16-10-76.ec2.internal)
21:44:01 I1119 21:44:01.590662 13966 master.cpp:8477] Forwarding status update TASK_STARTING (Status UUID: f1764db4-9c5f-4dc4-8d7d-0bde0eb711ee) for task 2 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000
21:44:01 I1119 21:44:01.590900 13966 master.cpp:10978] Updating the state of task 2 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 (latest state: TASK_STARTING, status update state: TASK_STARTING)
21:44:01 I1119 21:44:01.591673 13968 dynamic_reservation_framework.cpp:231] Task 2 is in state TASK_STARTING
21:44:01 I1119 21:44:01.591696 13968 sched.cpp:1022] Scheduler::statusUpdate took 25337ns
21:44:01 I1119 21:44:01.591992 13968 master.cpp:6286] Processing ACKNOWLEDGE call for status f1764db4-9c5f-4dc4-8d7d-0bde0eb711ee for task 2 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 (Dynamic Reservation Framework (C++)) at scheduler-6c8bdf5c-fd05-4490-897f-7b33c7d00630@172.16.10.76:34786 on agent 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S1
21:44:01 I1119 21:44:01.592878 13967 task_status_update_manager.cpp:328] Received task status update TASK_RUNNING (Status UUID: 3ce2314d-2d06-4d5c-9a0f-8cdc828c8771) for task 2 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000
21:44:01 I1119 21:44:01.593217 13967 task_status_update_manager.cpp:401] Received task status update acknowledgement (UUID: f1764db4-9c5f-4dc4-8d7d-0bde0eb711ee) for task 2 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000
21:44:01 I1119 21:44:01.593363 13967 task_status_update_manager.cpp:383] Forwarding task status update TASK_RUNNING (Status UUID: 3ce2314d-2d06-4d5c-9a0f-8cdc828c8771) for task 2 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 to the agent
21:44:01 I1119 21:44:01.593780 13967 slave.cpp:5660] Task status update manager successfully handled status update TASK_RUNNING (Status UUID: 3ce2314d-2d06-4d5c-9a0f-8cdc828c8771) for task 2 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000
21:44:01 I1119 21:44:01.593834 13967 slave.cpp:5676] Sending acknowledgement for status update TASK_RUNNING (Status UUID: 3ce2314d-2d06-4d5c-9a0f-8cdc828c8771) for task 2 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 to executor(1)@172.16.10.76:35159
21:44:01 I1119 21:44:01.594612 13967 slave.cpp:5767] Forwarding the update TASK_RUNNING (Status UUID: 3ce2314d-2d06-4d5c-9a0f-8cdc828c8771) for task 2 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 to master@172.16.10.76:34786
21:44:01 I1119 21:44:01.594799 13967 slave.cpp:4511] Task status update manager successfully handled status update acknowledgement (UUID: f1764db4-9c5f-4dc4-8d7d-0bde0eb711ee) for task 2 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000
21:44:01 I1119 21:44:01.595032 13967 master.cpp:8420] Status update TASK_RUNNING (Status UUID: 3ce2314d-2d06-4d5c-9a0f-8cdc828c8771) for task 2 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 from agent 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S1 at slave(1)@172.16.10.76:34786 (ip-172-16-10-76.ec2.internal)
21:44:01 I1119 21:44:01.595084 13967 master.cpp:8477] Forwarding status update TASK_RUNNING (Status UUID: 3ce2314d-2d06-4d5c-9a0f-8cdc828c8771) for task 2 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000
21:44:01 I1119 21:44:01.595302 13967 master.cpp:10978] Updating the state of task 2 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 (latest state: TASK_RUNNING, status update state: TASK_RUNNING)
21:44:01 I1119 21:44:01.595571 13967 dynamic_reservation_framework.cpp:231] Task 2 is in state TASK_RUNNING
21:44:01 I1119 21:44:01.595589 13967 sched.cpp:1022] Scheduler::statusUpdate took 20908ns
21:44:01 I1119 21:44:01.595845 13967 master.cpp:6286] Processing ACKNOWLEDGE call for status 3ce2314d-2d06-4d5c-9a0f-8cdc828c8771 for task 2 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 (Dynamic Reservation Framework (C++)) at scheduler-6c8bdf5c-fd05-4490-897f-7b33c7d00630@172.16.10.76:34786 on agent 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S1
21:44:01 I1119 21:44:01.596182 13967 task_status_update_manager.cpp:401] Received task status update acknowledgement (UUID: 3ce2314d-2d06-4d5c-9a0f-8cdc828c8771) for task 2 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000
21:44:01 I1119 21:44:01.607698 13967 slave.cpp:4511] Task status update manager successfully handled status update acknowledgement (UUID: 3ce2314d-2d06-4d5c-9a0f-8cdc828c8771) for task 2 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000
21:44:01 hello
21:44:01 hello
21:44:01 hello
21:44:01 I1119 21:44:01.814025 14010 executor.cpp:1003] Command exited with status 0 (pid: 14013)
21:44:01 I1119 21:44:01.817373 13972 slave.cpp:5275] Handling status update TASK_FINISHED (Status UUID: 918be1ed-c157-48a6-b3a4-74813d89a54c) for task 2 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 from executor(1)@172.16.10.76:35159
21:44:01 I1119 21:44:01.822005 13969 task_status_update_manager.cpp:328] Received task status update TASK_FINISHED (Status UUID: 918be1ed-c157-48a6-b3a4-74813d89a54c) for task 2 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000
21:44:01 I1119 21:44:01.822171 13969 task_status_update_manager.cpp:383] Forwarding task status update TASK_FINISHED (Status UUID: 918be1ed-c157-48a6-b3a4-74813d89a54c) for task 2 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 to the agent
21:44:01 I1119 21:44:01.822476 13968 slave.cpp:5767] Forwarding the update TASK_FINISHED (Status UUID: 918be1ed-c157-48a6-b3a4-74813d89a54c) for task 2 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 to master@172.16.10.76:34786
21:44:01 I1119 21:44:01.822685 13968 slave.cpp:5660] Task status update manager successfully handled status update TASK_FINISHED (Status UUID: 918be1ed-c157-48a6-b3a4-74813d89a54c) for task 2 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000
21:44:01 I1119 21:44:01.822738 13968 slave.cpp:5676] Sending acknowledgement for status update TASK_FINISHED (Status UUID: 918be1ed-c157-48a6-b3a4-74813d89a54c) for task 2 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 to executor(1)@172.16.10.76:35159
21:44:01 I1119 21:44:01.822836 13971 master.cpp:8420] Status update TASK_FINISHED (Status UUID: 918be1ed-c157-48a6-b3a4-74813d89a54c) for task 2 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 from agent 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S1 at slave(1)@172.16.10.76:34786 (ip-172-16-10-76.ec2.internal)
21:44:01 I1119 21:44:01.822893 13971 master.cpp:8477] Forwarding status update TASK_FINISHED (Status UUID: 918be1ed-c157-48a6-b3a4-74813d89a54c) for task 2 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000
21:44:01 I1119 21:44:01.823163 13971 master.cpp:10978] Updating the state of task 2 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 (latest state: TASK_FINISHED, status update state: TASK_FINISHED)
21:44:01 I1119 21:44:01.823715 13968 dynamic_reservation_framework.cpp:228] Task 2 is finished at agent 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S1
21:44:01 I1119 21:44:01.823731 13968 sched.cpp:1022] Scheduler::statusUpdate took 28389ns
21:44:01 I1119 21:44:01.824014 13968 master.cpp:6286] Processing ACKNOWLEDGE call for status 918be1ed-c157-48a6-b3a4-74813d89a54c for task 2 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 (Dynamic Reservation Framework (C++)) at scheduler-6c8bdf5c-fd05-4490-897f-7b33c7d00630@172.16.10.76:34786 on agent 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S1
21:44:01 I1119 21:44:01.824151 13968 master.cpp:11076] Removing task 2 with resources cpus(allocated: test)(reservations: [(DYNAMIC,test,test-principal)]):1; mem(allocated: test)(reservations: [(DYNAMIC,test,test-principal)]):128 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 on agent 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S1 at slave(1)@172.16.10.76:34786 (ip-172-16-10-76.ec2.internal)
21:44:01 I1119 21:44:01.824263 13971 hierarchical.cpp:1238] Recovered cpus(allocated: test)(reservations: [(DYNAMIC,test,test-principal)]):1; mem(allocated: test)(reservations: [(DYNAMIC,test,test-principal)]):128 (total: cpus:1; mem:6668; disk:35828; ports:[31000-32000]; cpus(reservations: [(DYNAMIC,test,test-principal)]):1; mem(reservations: [(DYNAMIC,test,test-principal)]):128, allocated: {}) on agent 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S1 from framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000
21:44:01 I1119 21:44:01.825076 13968 task_status_update_manager.cpp:401] Received task status update acknowledgement (UUID: 918be1ed-c157-48a6-b3a4-74813d89a54c) for task 2 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000
21:44:01 I1119 21:44:01.825197 13968 task_status_update_manager.cpp:538] Cleaning up status update stream for task 2 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000
21:44:01 I1119 21:44:01.825875 13968 slave.cpp:4511] Task status update manager successfully handled status update acknowledgement (UUID: 918be1ed-c157-48a6-b3a4-74813d89a54c) for task 2 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000
21:44:01 I1119 21:44:01.825927 13968 slave.cpp:9657] Completing task 2
21:44:01 I1119 21:44:01.845880 13984 executor.cpp:1003] Command exited with status 0 (pid: 13993)
21:44:01 I1119 21:44:01.848634 13971 slave.cpp:5275] Handling status update TASK_FINISHED (Status UUID: da8bd324-6a7c-458c-8dac-8558a7c3e4a1) for task 1 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 from executor(1)@172.16.10.76:36350
21:44:01 I1119 21:44:01.852344 13965 task_status_update_manager.cpp:328] Received task status update TASK_FINISHED (Status UUID: da8bd324-6a7c-458c-8dac-8558a7c3e4a1) for task 1 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000
21:44:01 I1119 21:44:01.852501 13965 task_status_update_manager.cpp:383] Forwarding task status update TASK_FINISHED (Status UUID: da8bd324-6a7c-458c-8dac-8558a7c3e4a1) for task 1 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 to the agent
21:44:01 I1119 21:44:01.852710 13971 slave.cpp:5767] Forwarding the update TASK_FINISHED (Status UUID: da8bd324-6a7c-458c-8dac-8558a7c3e4a1) for task 1 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 to master@172.16.10.76:34786
21:44:01 I1119 21:44:01.852880 13971 slave.cpp:5660] Task status update manager successfully handled status update TASK_FINISHED (Status UUID: da8bd324-6a7c-458c-8dac-8558a7c3e4a1) for task 1 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000
21:44:01 I1119 21:44:01.852926 13971 slave.cpp:5676] Sending acknowledgement for status update TASK_FINISHED (Status UUID: da8bd324-6a7c-458c-8dac-8558a7c3e4a1) for task 1 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 to executor(1)@172.16.10.76:36350
21:44:01 I1119 21:44:01.853014 13965 master.cpp:8420] Status update TASK_FINISHED (Status UUID: da8bd324-6a7c-458c-8dac-8558a7c3e4a1) for task 1 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 from agent 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S2 at slave(2)@172.16.10.76:34786 (ip-172-16-10-76.ec2.internal)
21:44:01 I1119 21:44:01.853063 13965 master.cpp:8477] Forwarding status update TASK_FINISHED (Status UUID: da8bd324-6a7c-458c-8dac-8558a7c3e4a1) for task 1 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000
21:44:01 I1119 21:44:01.853289 13965 master.cpp:10978] Updating the state of task 1 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 (latest state: TASK_FINISHED, status update state: TASK_FINISHED)
21:44:01 I1119 21:44:01.853904 13971 dynamic_reservation_framework.cpp:228] Task 1 is finished at agent 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S2
21:44:01 I1119 21:44:01.853920 13971 sched.cpp:1022] Scheduler::statusUpdate took 23710ns
21:44:01 I1119 21:44:01.854183 13971 master.cpp:6286] Processing ACKNOWLEDGE call for status da8bd324-6a7c-458c-8dac-8558a7c3e4a1 for task 1 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 (Dynamic Reservation Framework (C++)) at scheduler-6c8bdf5c-fd05-4490-897f-7b33c7d00630@172.16.10.76:34786 on agent 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S2
21:44:01 I1119 21:44:01.854251 13965 hierarchical.cpp:1238] Recovered cpus(allocated: test)(reservations: [(DYNAMIC,test,test-principal)]):1; mem(allocated: test)(reservations: [(DYNAMIC,test,test-principal)]):128 (total: cpus:1; mem:6668; disk:35828; ports:[31000-32000]; cpus(reservations: [(DYNAMIC,test,test-principal)]):1; mem(reservations: [(DYNAMIC,test,test-principal)]):128, allocated: {}) on agent 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S2 from framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000
21:44:01 I1119 21:44:01.854320 13971 master.cpp:11076] Removing task 1 with resources cpus(allocated: test)(reservations: [(DYNAMIC,test,test-principal)]):1; mem(allocated: test)(reservations: [(DYNAMIC,test,test-principal)]):128 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 on agent 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S2 at slave(2)@172.16.10.76:34786 (ip-172-16-10-76.ec2.internal)
21:44:01 I1119 21:44:01.854871 13971 task_status_update_manager.cpp:401] Received task status update acknowledgement (UUID: da8bd324-6a7c-458c-8dac-8558a7c3e4a1) for task 1 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000
21:44:01 I1119 21:44:01.854988 13971 task_status_update_manager.cpp:538] Cleaning up status update stream for task 1 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000
21:44:01 I1119 21:44:01.855532 13971 slave.cpp:4511] Task status update manager successfully handled status update acknowledgement (UUID: da8bd324-6a7c-458c-8dac-8558a7c3e4a1) for task 1 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000
21:44:01 I1119 21:44:01.855581 13971 slave.cpp:9657] Completing task 1
21:44:01 I1119 21:44:01.890357 13995 executor.cpp:1003] Command exited with status 0 (pid: 14012)
21:44:01 I1119 21:44:01.894318 13971 slave.cpp:5275] Handling status update TASK_FINISHED (Status UUID: dab5eb35-d3ab-45fd-ba25-7ec4a438d043) for task 0 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 from executor(1)@172.16.10.76:38687
21:44:01 I1119 21:44:01.898308 13972 task_status_update_manager.cpp:328] Received task status update TASK_FINISHED (Status UUID: dab5eb35-d3ab-45fd-ba25-7ec4a438d043) for task 0 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000
21:44:01 I1119 21:44:01.898474 13972 task_status_update_manager.cpp:383] Forwarding task status update TASK_FINISHED (Status UUID: dab5eb35-d3ab-45fd-ba25-7ec4a438d043) for task 0 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 to the agent
21:44:01 I1119 21:44:01.898864 13972 slave.cpp:5767] Forwarding the update TASK_FINISHED (Status UUID: dab5eb35-d3ab-45fd-ba25-7ec4a438d043) for task 0 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 to master@172.16.10.76:34786
21:44:01 I1119 21:44:01.899053 13972 slave.cpp:5660] Task status update manager successfully handled status update TASK_FINISHED (Status UUID: dab5eb35-d3ab-45fd-ba25-7ec4a438d043) for task 0 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000
21:44:01 I1119 21:44:01.899102 13972 slave.cpp:5676] Sending acknowledgement for status update TASK_FINISHED (Status UUID: dab5eb35-d3ab-45fd-ba25-7ec4a438d043) for task 0 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 to executor(1)@172.16.10.76:38687
21:44:01 I1119 21:44:01.900029 13972 master.cpp:8420] Status update TASK_FINISHED (Status UUID: dab5eb35-d3ab-45fd-ba25-7ec4a438d043) for task 0 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 from agent 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S0 at slave(3)@172.16.10.76:34786 (ip-172-16-10-76.ec2.internal)
21:44:01 I1119 21:44:01.900084 13972 master.cpp:8477] Forwarding status update TASK_FINISHED (Status UUID: dab5eb35-d3ab-45fd-ba25-7ec4a438d043) for task 0 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000
21:44:01 I1119 21:44:01.900323 13972 master.cpp:10978] Updating the state of task 0 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 (latest state: TASK_FINISHED, status update state: TASK_FINISHED)
21:44:01 I1119 21:44:01.900967 13972 dynamic_reservation_framework.cpp:228] Task 0 is finished at agent 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S0
21:44:01 I1119 21:44:01.900984 13972 sched.cpp:1022] Scheduler::statusUpdate took 24143ns
21:44:01 I1119 21:44:01.901262 13972 master.cpp:6286] Processing ACKNOWLEDGE call for status dab5eb35-d3ab-45fd-ba25-7ec4a438d043 for task 0 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 (Dynamic Reservation Framework (C++)) at scheduler-6c8bdf5c-fd05-4490-897f-7b33c7d00630@172.16.10.76:34786 on agent 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S0
21:44:01 I1119 21:44:01.901417 13972 master.cpp:11076] Removing task 0 with resources cpus(allocated: test)(reservations: [(DYNAMIC,test,test-principal)]):1; mem(allocated: test)(reservations: [(DYNAMIC,test,test-principal)]):128 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 on agent 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S0 at slave(3)@172.16.10.76:34786 (ip-172-16-10-76.ec2.internal)
21:44:01 I1119 21:44:01.901948 13972 task_status_update_manager.cpp:401] Received task status update acknowledgement (UUID: dab5eb35-d3ab-45fd-ba25-7ec4a438d043) for task 0 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000
21:44:01 I1119 21:44:01.902040 13968 hierarchical.cpp:1566] Performed allocation for 3 agents in 3.04807ms
21:44:01 I1119 21:44:01.902061 13972 task_status_update_manager.cpp:538] Cleaning up status update stream for task 0 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000
21:44:01 I1119 21:44:01.902865 13968 hierarchical.cpp:1238] Recovered cpus(allocated: test)(reservations: [(DYNAMIC,test,test-principal)]):1; mem(allocated: test)(reservations: [(DYNAMIC,test,test-principal)]):128 (total: cpus:1; mem:6668; disk:35828; ports:[31000-32000]; cpus(reservations: [(DYNAMIC,test,test-principal)]):1; mem(reservations: [(DYNAMIC,test,test-principal)]):128, allocated: disk(allocated: test):35828; ports(allocated: test):[31000-32000]; cpus(allocated: test):1; mem(allocated: test):6668) on agent 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S0 from framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000
21:44:01 I1119 21:44:01.904876 13972 slave.cpp:4511] Task status update manager successfully handled status update acknowledgement (UUID: dab5eb35-d3ab-45fd-ba25-7ec4a438d043) for task 0 of framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000
21:44:01 I1119 21:44:01.904929 13972 slave.cpp:9657] Completing task 0
21:44:01 I1119 21:44:01.905475 13968 master.cpp:9514] Sending offers [ 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-O6, 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-O7, 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-O8 ] to framework 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-0000 (Dynamic Reservation Framework (C++)) at scheduler-6c8bdf5c-fd05-4490-897f-7b33c7d00630@172.16.10.76:34786
21:44:01 I1119 21:44:01.906069 13966 dynamic_reservation_framework.cpp:99] Received offer 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-O6 from agent 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S1 with [{"allocation_info":{"role":"test"},"name":"cpus","scalar":{"value":1.0},"type":"SCALAR"},{"allocation_info":{"role":"test"},"name":"mem","scalar":{"value":6668.0},"type":"SCALAR"},{"allocation_info":{"role":"test"},"name":"disk","scalar":{"value":35828.0},"type":"SCALAR"},{"allocation_info":{"role":"test"},"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"},{"allocation_info":{"role":"test"},"name":"cpus","reservations":[{"principal":"test-principal","role":"test","type":"DYNAMIC"}],"scalar":{"value":1.0},"type":"SCALAR"},{"allocation_info":{"role":"test"},"name":"mem","reservations":[{"principal":"test-principal","role":"test","type":"DYNAMIC"}],"scalar":{"value":128.0},"type":"SCALAR"}]
21:44:01 I1119 21:44:01.906554 13966 dynamic_reservation_framework.cpp:170] Launching task 3 using offer 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-O6
21:44:01 I1119 21:44:01.906750 13966 dynamic_reservation_framework.cpp:99] Received offer 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-O7 from agent 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S2 with [{"allocation_info":{"role":"test"},"name":"cpus","scalar":{"value":1.0},"type":"SCALAR"},{"allocation_info":{"role":"test"},"name":"mem","scalar":{"value":6668.0},"type":"SCALAR"},{"allocation_info":{"role":"test"},"name":"disk","scalar":{"value":35828.0},"type":"SCALAR"},{"allocation_info":{"role":"test"},"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"},{"allocation_info":{"role":"test"},"name":"cpus","reservations":[{"principal":"test-principal","role":"test","type":"DYNAMIC"}],"scalar":{"value":1.0},"type":"SCALAR"},{"allocation_info":{"role":"test"},"name":"mem","reservations":[{"principal":"test-principal","role":"test","type":"DYNAMIC"}],"scalar":{"value":128.0},"type":"SCALAR"}]
21:44:01 I1119 21:44:01.907142 13966 dynamic_reservation_framework.cpp:170] Launching task 4 using offer 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-O7
21:44:01 I1119 21:44:01.907335 13966 dynamic_reservation_framework.cpp:99] Received offer 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-O8 from agent 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S0 with [{"allocation_info":{"role":"test"},"name":"cpus","scalar":{"value":1.0},"type":"SCALAR"},{"allocation_info":{"role":"test"},"name":"mem","scalar":{"value":6668.0},"type":"SCALAR"},{"allocation_info":{"role":"test"},"name":"disk","scalar":{"value":35828.0},"type":"SCALAR"},{"allocation_info":{"role":"test"},"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}]
21:44:01 F1119 21:44:01.907629 13966 dynamic_reservation_framework.cpp:153] Check failed: reserved.contains(taskResources) Reserved {} does not contain taskResources cpus(allocated: test)(reservations: [(DYNAMIC,test,test-principal)]):1; mem(allocated: test)(reservations: [(DYNAMIC,test,test-principal)]):128 states { 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S1: 3, 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S0: 2, 0c5362db-ba85-4ddd-9c1e-c4de159c92ae-S2: 3 }
21:44:01 *** Check failure stack trace: ***
21:44:01 @ 0x7f3d7e97556d google::LogMessage::Fail()
21:44:01 @ 0x7f3d7e9772ed google::LogMessage::SendToLog()
21:44:01 @ 0x7f3d7e975153 google::LogMessage::Flush()
21:44:01 @ 0x7f3d7e977d8e google::LogMessageFatal::~LogMessageFatal()
21:44:01 @ 0x46ee38 DynamicReservationScheduler::resourceOffers()
21:44:01 @ 0x7f3d8aaab7dc mesos::internal::SchedulerProcess::resourceOffers()
21:44:01 @ 0x7f3d8aabd2a6 _ZN15ProtobufProcessIN5mesos8internal16SchedulerProcessEE8handlerNINS1_21ResourceOffersMessageEJRKN6google8protobuf16RepeatedPtrFieldINS0_5OfferEEERKNS8_ISsEEEJRKSt6vectorIS9_SaIS9_EERKSG_ISsSaISsEEEEEvPS2_MS2_FvRKN7process4UPIDEDpT1_EST_RKSsDpMT_KFT0_vE
21:44:01 @ 0x7f3d8aad9a9f _ZNSt5_BindIFPFvPN5mesos8internal16SchedulerProcessEMS2_FvRKN7process4UPIDERKSt6vectorINS0_5OfferESaIS9_EERKS8_ISsSaISsEEES7_RKSsMNS1_21ResourceOffersMessageEKFRKN6google8protobuf16RepeatedPtrFieldIS9_EEvEMSM_KFRKNSP_ISsEEvEES3_SJ_St12_PlaceholderILi1EES12_ILi2EESU_SZ_EE6__callIvJS7_SL_EJLm0ELm1ELm2ELm3ELm4ELm5EEEET_OSt5tupleIJDpT0_EESt12_Index_tupleIJXspT1_EEE
21:44:02 @ 0x7f3d8aad58ff _ZNSt5_BindIFPFvPN5mesos8internal16SchedulerProcessEMS2_FvRKN7process4UPIDERKSt6vectorINS0_5OfferESaIS9_EERKS8_ISsSaISsEEES7_RKSsMNS1_21ResourceOffersMessageEKFRKN6google8protobuf16RepeatedPtrFieldIS9_EEvEMSM_KFRKNSP_ISsEEvEES3_SJ_St12_PlaceholderILi1EES12_ILi2EESU_SZ_EEclIJS7_SL_EvEET0_DpOT_
21:44:02 @ 0x7f3d8aacf0c2 std::_Function_handler<>::_M_invoke()
21:44:02 @ 0x7f3d8987a409 std::function<>::operator()()
21:44:02 @ 0x7f3d8aadd98a ProtobufProcess<>::consume()
21:44:02 @ 0x7f3d8a4fe2e4 _ZNO7process12MessageEvent7consumeEPNS_13EventConsumerE
21:44:02 @ 0x7f3d893c5680 process::ProcessBase::serve()
21:44:02 @ 0x7f3d800c46f6 process::ProcessManager::resume()
21:44:02 @ 0x7f3d800c0aca _ZZN7process14ProcessManager12init_threadsEvENKUlvE_clEv
21:44:02 @ 0x7f3d800e80d4 _ZNSt12_Bind_simpleIFZN7process14ProcessManager12init_threadsEvEUlvE_vEE9_M_invokeIJEEEvSt12_Index_tupleIJXspT_EEE
21:44:02 @ 0x7f3d800e7208 _ZNSt12_Bind_simpleIFZN7process14ProcessManager12init_threadsEvEUlvE_vEEclEv
21:44:02 @ 0x7f3d800e6130 _ZNSt6thread5_ImplISt12_Bind_simpleIFZN7process14ProcessManager12init_threadsEvEUlvE_vEEE6_M_runEv
21:44:02 @ 0x7f3d7ba6d590 execute_native_thread_routine
21:44:02 @ 0x7f3d7e4ece25 start_thread
21:44:02 @ 0x7f3d7a15fbad __clone
21:44:02 /home/centos/workspace/mesos/Mesos_CI-build/FLAG/CMake/label/mesos-ec2-centos-7/mesos/src/tests/script.cpp:86: Failure
21:44:02 Failed
21:44:02 dynamic_reservation_framework_test.sh terminated with signal Aborted
21:44:02 [ FAILED ] ExamplesTest.DynamicReservationFramework (3349 ms)
{noformat}
--
This message was sent by Atlassian JIRA
(v7.6.3#76005)