[
https://issues.apache.org/jira/browse/MESOS-9928?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Benno Evers reassigned MESOS-9928:
----------------------------------
Assignee: Benno Evers
> OperationReconciliationTest.FrameworkReconciliationRaceWithUpdateSlaveMessage
> is severely flaky
> -----------------------------------------------------------------------------------------------
>
> Key: MESOS-9928
> URL: https://issues.apache.org/jira/browse/MESOS-9928
> Project: Mesos
> Issue Type: Bug
> Affects Versions: 1.9.0
> Reporter: Andrei Sekretenko
> Assignee: Benno Evers
> Priority: Major
> Labels: flaky, flaky-test, foundations
>
> Flakes are frequently observed in the internal CI.
> Example:
> {code}
> [ RUN ]
> ContentType/OperationReconciliationTest.FrameworkReconciliationRaceWithUpdateSlaveMessage/1
> I0806 20:00:24.128456 29945 cluster.cpp:177] Creating default 'local'
> authorizer
> I0806 20:00:24.132164 21364 master.cpp:440] Master
> 7bbcb55d-ce3b-40e6-a605-62ed7d843832 (ip-172-16-10-6.ec2.internal) started on
> 172.16.10.6:36902
> I0806 20:00:24.132181 21364 master.cpp:443] Flags at startup: --acls=""
> --agent_ping_timeout="15secs" --agent_reregister_timeout="10mins"
> --allocation_interval="1secs" --allocator="hierarchical"
> --authenticate_agents="true" --authenticate_frameworks="true"
> --authenticate_http_frameworks="true" --authenticate_http_readonly="true"
> --authenticate_http_readwrite="true" --authentication_v0_timeout="15secs"
> --authenticators="crammd5" --authorizers="local"
> --credentials="/tmp/MpmzC4/credentials" --filter_gpu_resources="true"
> --framework_sorter="drf" --help="false" --hostname_lookup="true"
> --http_authenticators="basic" --http_framework_authenticators="basic"
> --initialize_driver_logging="true" --log_auto_initialize="true"
> --logbufsecs="0" --logging_level="INFO" --max_agent_ping_timeouts="5"
> --max_completed_frameworks="50" --max_completed_tasks_per_framework="1000"
> --max_operator_event_stream_subscribers="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="in_memory"
> --registry_fetch_timeout="1mins" --registry_gc_interval="15mins"
> --registry_max_agent_age="2weeks" --registry_max_agent_count="102400"
> --registry_store_timeout="100secs" --registry_strict="false"
> --require_agent_domain="false" --role_sorter="drf" --root_submissions="true"
> --version="false" --webui_dir="/usr/local/share/mesos/webui"
> --work_dir="/tmp/MpmzC4/master" --zk_session_timeout="10secs"
> I0806 20:00:24.132485 21364 master.cpp:492] Master only allowing
> authenticated frameworks to register
> I0806 20:00:24.132494 21364 master.cpp:498] Master only allowing
> authenticated agents to register
> I0806 20:00:24.132500 21364 master.cpp:504] Master only allowing
> authenticated HTTP frameworks to register
> I0806 20:00:24.132506 21364 credentials.hpp:37] Loading credentials for
> authentication from '/tmp/MpmzC4/credentials'
> I0806 20:00:24.132709 21364 master.cpp:548] Using default 'crammd5'
> authenticator
> I0806 20:00:24.132845 21364 http.cpp:975] Creating default 'basic' HTTP
> authenticator for realm 'mesos-master-readonly'
> I0806 20:00:24.132975 21364 http.cpp:975] Creating default 'basic' HTTP
> authenticator for realm 'mesos-master-readwrite'
> I0806 20:00:24.133085 21364 http.cpp:975] Creating default 'basic' HTTP
> authenticator for realm 'mesos-master-scheduler'
> I0806 20:00:24.133188 21364 master.cpp:629] Authorization enabled
> I0806 20:00:24.135308 21363 whitelist_watcher.cpp:77] No whitelist given
> I0806 20:00:24.139948 21364 master.cpp:2168] Elected as the leading master!
> I0806 20:00:24.139968 21364 master.cpp:1664] Recovering from registrar
> I0806 20:00:24.140195 21364 registrar.cpp:339] Recovering registrar
> I0806 20:00:24.141042 21364 registrar.cpp:383] Successfully fetched the
> registry (0B) in 0ns
> I0806 20:00:24.141141 21364 registrar.cpp:487] Applied 1 operations in
> 25620ns; attempting to update the registry
> I0806 20:00:24.141793 21364 registrar.cpp:544] Successfully updated the
> registry in 0ns
> I0806 20:00:24.141894 21364 registrar.cpp:416] Successfully recovered
> registrar
> I0806 20:00:24.142277 21364 master.cpp:1817] Recovered 0 agents from the
> registry (175B); allowing 10mins for agents to reregister
> I0806 20:00:24.142611 21366 hierarchical.cpp:241] Initialized hierarchical
> allocator process
> I0806 20:00:24.142735 21366 hierarchical.cpp:280] Skipping recovery of
> hierarchical allocator: nothing to recover
> W0806 20:00:24.147953 29945 process.cpp:2877] Attempted to spawn already
> running process files@172.16.10.6:36902
> I0806 20:00:24.149081 29945 containerizer.cpp:318] Using isolation {
> environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni }
> I0806 20:00:24.153627 29945 linux_launcher.cpp:144] Using
> /sys/fs/cgroup/freezer as the freezer hierarchy for the Linux launcher
> I0806 20:00:24.154449 29945 provisioner.cpp:300] Using default backend 'copy'
> I0806 20:00:24.158208 29945 cluster.cpp:518] Creating default 'local'
> authorizer
> I0806 20:00:24.160681 21368 slave.cpp:267] Mesos agent started on
> (1277)@172.16.10.6:36902
> I0806 20:00:24.160698 21368 slave.cpp:268] Flags at startup: --acls=""
> --appc_simple_discovery_uri_prefix="http://";
> --appc_store_dir="/tmp/MpmzC4/mGaOxR/store/appc"
> --authenticate_http_readonly="true" --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" --credential="/tmp/MpmzC4/mGaOxR/credential"
> --default_role="*" --disallow_sharing_agent_ipc_namespace="false"
> --disallow_sharing_agent_pid_namespace="false" --disk_watch_interval="1mins"
> --docker="docker" --docker_ignore_runtime="false"
> --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/MpmzC4/mGaOxR/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/MpmzC4/mGaOxR/fetch" --fetcher_cache_size="2GB"
> --fetcher_stall_timeout="1mins"
> --frameworks_home="/tmp/MpmzC4/mGaOxR/frameworks" --gc_delay="1weeks"
> --gc_disk_headroom="0.1" --gc_non_executor_container_sandboxes="false"
> --help="false" --hostname_lookup="true" --http_command_executor="false"
> --http_credentials="/tmp/MpmzC4/mGaOxR/http_credentials"
> --http_heartbeat_interval="30secs" --initialize_driver_logging="true"
> --isolation="posix/cpu,posix/mem" --launcher="linux"
> --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" --network_cni_root_dir_persist="false"
> --oversubscribed_resources_interval="15secs" --perf_duration="10secs"
> --perf_interval="1mins" --port="5051" --qos_correction_interval_min="0ns"
> --quiet="false" --reconfiguration_policy="equal" --recover="reconnect"
> --recovery_timeout="15mins" --registration_backoff_factor="10ms"
> --resources="cpus:2;gpus:0;mem:1024;disk:1024;ports:[31000-32000]"
> --revocable_cpu_low_priority="true"
> --runtime_dir="/tmp/ContentType_OperationReconciliationTest_FrameworkReconciliationRaceWithUpdateSlaveMessage_1_rFyIeB"
> --sandbox_directory="/mnt/mesos/sandbox" --strict="true"
> --switch_user="true" --systemd_enable_support="true"
> --systemd_runtime_directory="/run/systemd/system" --version="false"
> --work_dir="/tmp/ContentType_OperationReconciliationTest_FrameworkReconciliationRaceWithUpdateSlaveMessage_1_C1BDVk"
> --zk_session_timeout="10secs"
> I0806 20:00:24.161079 21368 credentials.hpp:86] Loading credential for
> authentication from '/tmp/MpmzC4/mGaOxR/credential'
> I0806 20:00:24.161200 21368 slave.cpp:300] Agent using credential for:
> test-principal
> I0806 20:00:24.161213 21368 credentials.hpp:37] Loading credentials for
> authentication from '/tmp/MpmzC4/mGaOxR/http_credentials'
> I0806 20:00:24.161360 21368 http.cpp:975] Creating default 'basic' HTTP
> authenticator for realm 'mesos-agent-readonly'
> I0806 20:00:24.161633 21368 disk_profile_adaptor.cpp:78] Creating default
> disk profile adaptor module
> I0806 20:00:24.163035 21368 slave.cpp:615] Agent resources:
> [{"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"disk","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}]
> I0806 20:00:24.163216 21368 slave.cpp:623] Agent attributes: [ ]
> I0806 20:00:24.163226 21368 slave.cpp:632] Agent hostname:
> ip-172-16-10-6.ec2.internal
> I0806 20:00:24.164947 21368 task_status_update_manager.cpp:181] Pausing
> sending task status updates
> I0806 20:00:24.164978 21368 status_update_manager_process.hpp:379] Pausing
> operation status update manager
> I0806 20:00:24.166102 21368 state.cpp:67] Recovering state from
> '/tmp/ContentType_OperationReconciliationTest_FrameworkReconciliationRaceWithUpdateSlaveMessage_1_C1BDVk/meta'
> I0806 20:00:24.166347 21368 slave.cpp:7444] Finished recovering checkpointed
> state from
> '/tmp/ContentType_OperationReconciliationTest_FrameworkReconciliationRaceWithUpdateSlaveMessage_1_C1BDVk/meta',
> beginning agent recovery
> I0806 20:00:24.166906 21368 task_status_update_manager.cpp:207] Recovering
> task status update manager
> I0806 20:00:24.167408 21368 containerizer.cpp:821] Recovering Mesos containers
> I0806 20:00:24.167639 21368 linux_launcher.cpp:286] Recovering Linux launcher
> I0806 20:00:24.168066 21368 containerizer.cpp:1147] Recovering isolators
> I0806 20:00:24.169267 21368 containerizer.cpp:1186] Recovering provisioner
> I0806 20:00:24.169919 21368 provisioner.cpp:500] Provisioner recovery complete
> I0806 20:00:24.171048 21368 composing.cpp:339] Finished recovering all
> containerizers
> I0806 20:00:24.171375 21368 slave.cpp:7908] Recovering executors
> I0806 20:00:24.171452 21368 slave.cpp:8061] Finished recovery
> I0806 20:00:24.172451 21368 slave.cpp:1351] New master detected at
> master@172.16.10.6:36902
> I0806 20:00:24.172538 21368 slave.cpp:1416] Detecting new master
> I0806 20:00:24.172674 21368 task_status_update_manager.cpp:181] Pausing
> sending task status updates
> I0806 20:00:24.172704 21368 status_update_manager_process.hpp:379] Pausing
> operation status update manager
> I0806 20:00:24.173789 21368 slave.cpp:1443] Authenticating with master
> master@172.16.10.6:36902
> I0806 20:00:24.173863 21368 slave.cpp:1452] Using default CRAM-MD5
> authenticatee
> I0806 20:00:24.174245 21368 authenticatee.cpp:121] Creating new client SASL
> connection
> I0806 20:00:24.174455 21368 master.cpp:10578] Authenticating
> slave(1277)@172.16.10.6:36902
> I0806 20:00:24.174621 21368 authenticator.cpp:414] Starting authentication
> session for crammd5-authenticatee(2162)@172.16.10.6:36902
> I0806 20:00:24.174991 21368 authenticator.cpp:98] Creating new server SASL
> connection
> I0806 20:00:24.175177 21368 authenticatee.cpp:213] Received SASL
> authentication mechanisms: CRAM-MD5
> I0806 20:00:24.175195 21368 authenticatee.cpp:239] Attempting to authenticate
> with mechanism 'CRAM-MD5'
> I0806 20:00:24.175279 21368 authenticator.cpp:204] Received SASL
> authentication start
> I0806 20:00:24.175318 21368 authenticator.cpp:326] Authentication requires
> more steps
> I0806 20:00:24.175391 21368 authenticatee.cpp:259] Received SASL
> authentication step
> I0806 20:00:24.175469 21368 authenticator.cpp:232] Received SASL
> authentication step
> I0806 20:00:24.175490 21368 auxprop.cpp:109] Request to lookup properties for
> user: 'test-principal' realm: 'ip-172-16-10-6.ec2.internal' server FQDN:
> 'ip-172-16-10-6.ec2.internal' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
> SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
> I0806 20:00:24.175500 21368 auxprop.cpp:181] Looking up auxiliary property
> '*userPassword'
> I0806 20:00:24.175530 21368 auxprop.cpp:181] Looking up auxiliary property
> '*cmusaslsecretCRAM-MD5'
> I0806 20:00:24.175544 21368 auxprop.cpp:109] Request to lookup properties for
> user: 'test-principal' realm: 'ip-172-16-10-6.ec2.internal' server FQDN:
> 'ip-172-16-10-6.ec2.internal' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
> SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
> I0806 20:00:24.175550 21368 auxprop.cpp:131] Skipping auxiliary property
> '*userPassword' since SASL_AUXPROP_AUTHZID == true
> I0806 20:00:24.175557 21368 auxprop.cpp:131] Skipping auxiliary property
> '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
> I0806 20:00:24.175570 21368 authenticator.cpp:318] Authentication success
> I0806 20:00:24.175745 21368 authenticatee.cpp:299] Authentication success
> I0806 20:00:24.175917 21368 master.cpp:10610] Successfully authenticated
> principal 'test-principal' at slave(1277)@172.16.10.6:36902
> I0806 20:00:24.175993 21368 authenticator.cpp:432] Authentication session
> cleanup for crammd5-authenticatee(2162)@172.16.10.6:36902
> I0806 20:00:24.176301 21368 slave.cpp:1543] Successfully authenticated with
> master master@172.16.10.6:36902
> I0806 20:00:24.176601 21368 slave.cpp:1993] Will retry registration in
> 8.320422ms if necessary
> I0806 20:00:24.176966 21368 master.cpp:7086] Received register agent message
> from slave(1277)@172.16.10.6:36902 (ip-172-16-10-6.ec2.internal)
> I0806 20:00:24.177207 21368 master.cpp:4202] Authorizing agent providing
> resources 'cpus:2; mem:1024; disk:1024; ports:[31000-32000]' with principal
> 'test-principal'
> I0806 20:00:24.178033 21368 master.cpp:7153] Authorized registration of agent
> at slave(1277)@172.16.10.6:36902 (ip-172-16-10-6.ec2.internal)
> I0806 20:00:24.178100 21368 master.cpp:7265] Registering agent at
> slave(1277)@172.16.10.6:36902 (ip-172-16-10-6.ec2.internal) with id
> 7bbcb55d-ce3b-40e6-a605-62ed7d843832-S0
> I0806 20:00:24.178675 21368 registrar.cpp:487] Applied 1 operations in
> 200693ns; attempting to update the registry
> I0806 20:00:24.179406 21368 registrar.cpp:544] Successfully updated the
> registry in 0ns
> I0806 20:00:24.179685 21368 master.cpp:7313] Admitted agent
> 7bbcb55d-ce3b-40e6-a605-62ed7d843832-S0 at slave(1277)@172.16.10.6:36902
> (ip-172-16-10-6.ec2.internal)
> I0806 20:00:24.180236 21368 master.cpp:7358] Registered agent
> 7bbcb55d-ce3b-40e6-a605-62ed7d843832-S0 at slave(1277)@172.16.10.6:36902
> (ip-172-16-10-6.ec2.internal) with cpus:2; mem:1024; disk:1024;
> ports:[31000-32000]
> I0806 20:00:24.180523 21368 hierarchical.cpp:617] Added agent
> 7bbcb55d-ce3b-40e6-a605-62ed7d843832-S0 (ip-172-16-10-6.ec2.internal) with
> cpus:2; mem:1024; disk:1024; ports:[31000-32000] (allocated: {})
> I0806 20:00:24.180778 21368 hierarchical.cpp:1508] Performed allocation for 1
> agents in 100435ns
> I0806 20:00:24.180869 21368 slave.cpp:1576] Registered with master
> master@172.16.10.6:36902; given agent ID
> 7bbcb55d-ce3b-40e6-a605-62ed7d843832-S0
> I0806 20:00:24.181309 21368 slave.cpp:1611] Checkpointing SlaveInfo to
> '/tmp/ContentType_OperationReconciliationTest_FrameworkReconciliationRaceWithUpdateSlaveMessage_1_C1BDVk/meta/slaves/7bbcb55d-ce3b-40e6-a605-62ed7d843832-S0/slave.info'
> I0806 20:00:24.182250 21368 slave.cpp:1663] Forwarding agent update
> {"operations":{},"resource_providers":{},"resource_version_uuid":{"value":"/JaO7ln0ROi+NZkPMvYECw=="},"slave_id":{"value":"7bbcb55d-ce3b-40e6-a605-62ed7d843832-S0"},"update_oversubscribed_resources":false}
> I0806 20:00:24.182448 21368 task_status_update_manager.cpp:188] Resuming
> sending task status updates
> I0806 20:00:24.182512 21368 status_update_manager_process.hpp:385] Resuming
> operation status update manager
> I0806 20:00:24.184386 21363 master.cpp:8457] Ignoring update on agent
> 7bbcb55d-ce3b-40e6-a605-62ed7d843832-S0 at slave(1277)@172.16.10.6:36902
> (ip-172-16-10-6.ec2.internal) as it reports no changes
> I0806 20:00:24.202025 21368 http_connection.hpp:227] New endpoint detected at
> http://172.16.10.6:36902/slave(1277)/api/v1/resource_provider
> I0806 20:00:24.204447 21366 http_connection.hpp:283] Connected with the
> remote endpoint at
> http://172.16.10.6:36902/slave(1277)/api/v1/resource_provider
> I0806 20:00:24.205152 21367 http_connection.hpp:131] Sending 1 call to
> http://172.16.10.6:36902/slave(1277)/api/v1/resource_provider
> I0806 20:00:24.206167 21367 process.cpp:3671] Handling HTTP event for process
> 'slave(1277)' with path: '/slave(1277)/api/v1/resource_provider'
> I0806 20:00:24.207383 21365 http.cpp:1115] HTTP POST for
> /slave(1277)/api/v1/resource_provider from 172.16.10.6:48886
> I0806 20:00:24.207850 21365 manager.cpp:807] Subscribing resource provider
> {"name":"test","type":"org.apache.mesos.rp.test"}
> I0806 20:00:24.210747 21361 slave.cpp:8417] Handling resource provider
> message 'SUBSCRIBE:
> {"id":{"value":"08838aad-7f0b-495d-8b72-dd2c2678d320"},"name":"test","type":"org.apache.mesos.rp.test"}'
> I0806 20:00:24.212172 21362 http_connection.hpp:131] Sending 3 call to
> http://172.16.10.6:36902/slave(1277)/api/v1/resource_provider
> I0806 20:00:24.213117 21364 process.cpp:3671] Handling HTTP event for process
> 'slave(1277)' with path: '/slave(1277)/api/v1/resource_provider'
> I0806 20:00:24.214156 21363 http.cpp:1115] HTTP POST for
> /slave(1277)/api/v1/resource_provider from 172.16.10.6:48884
> I0806 20:00:24.214596 21363 manager.cpp:1039] Received UPDATE_STATE call with
> resources
> '[{"disk":{"source":{"type":"RAW"}},"name":"disk","provider_id":{"value":"08838aad-7f0b-495d-8b72-dd2c2678d320"},"scalar":{"value":200.0},"type":"SCALAR"}]'
> and 0 operations from resource provider 08838aad-7f0b-495d-8b72-dd2c2678d320
> I0806 20:00:24.214985 21363 slave.cpp:8417] Handling resource provider
> message 'UPDATE_STATE: 08838aad-7f0b-495d-8b72-dd2c2678d320 disk[RAW]:200'
> I0806 20:00:24.215077 21363 slave.cpp:8537] Forwarding new total resources
> cpus:2; mem:1024; disk:1024; ports:[31000-32000]; disk[RAW]:200
> I0806 20:00:24.217061 29945 scheduler.cpp:189] Version: 1.9.0
> I0806 20:00:24.217216 21363 hierarchical.cpp:753] Grew agent
> 7bbcb55d-ce3b-40e6-a605-62ed7d843832-S0 by disk[RAW]:200 (total), { } (used)
> I0806 20:00:24.217445 21363 hierarchical.cpp:710] Agent
> 7bbcb55d-ce3b-40e6-a605-62ed7d843832-S0 (ip-172-16-10-6.ec2.internal) updated
> with total resources cpus:2; mem:1024; disk:1024; ports:[31000-32000];
> disk[RAW]:200
> I0806 20:00:24.217761 21363 scheduler.cpp:342] Using default 'basic' HTTP
> authenticatee
> I0806 20:00:24.218135 21363 scheduler.cpp:525] New master detected at
> master@172.16.10.6:36902
> I0806 20:00:24.218155 21363 scheduler.cpp:534] Waiting for 0ns before
> initiating a re-(connection) attempt with the master
> I0806 20:00:24.222335 21365 scheduler.cpp:416] Connected with the master at
> http://172.16.10.6:36902/master/api/v1/scheduler
> I0806 20:00:24.223047 21365 scheduler.cpp:246] Adding authentication headers
> to SUBSCRIBE call to http://172.16.10.6:36902/master/api/v1/scheduler
> I0806 20:00:24.223444 21364 scheduler.cpp:600] Sending SUBSCRIBE call to
> http://172.16.10.6:36902/master/api/v1/scheduler
> I0806 20:00:24.224323 21363 process.cpp:3671] Handling HTTP event for process
> 'master' with path: '/master/api/v1/scheduler'
> I0806 20:00:24.225673 21365 http.cpp:1115] HTTP POST for
> /master/api/v1/scheduler from 172.16.10.6:48890
> I0806 20:00:24.225988 21365 master.cpp:2668] Received subscription request
> for HTTP framework 'default'
> I0806 20:00:24.226054 21365 master.cpp:2240] Authorizing framework principal
> 'test-principal' to receive offers for roles '{ default-role }'
> I0806 20:00:24.227097 21365 master.cpp:2740] Subscribing framework 'default'
> with checkpointing disabled and capabilities [ MULTI_ROLE,
> RESERVATION_REFINEMENT ]
> I0806 20:00:24.229744 21365 master.cpp:10808] Adding framework
> 7bbcb55d-ce3b-40e6-a605-62ed7d843832-0000 (default) with roles { } suppressed
> I0806 20:00:24.230711 21367 hierarchical.cpp:368] Added framework
> 7bbcb55d-ce3b-40e6-a605-62ed7d843832-0000
> I0806 20:00:24.231781 21367 hierarchical.cpp:1508] Performed allocation for 1
> agents in 939160ns
> I0806 20:00:24.232277 21367 master.cpp:10393] Sending offers [
> 7bbcb55d-ce3b-40e6-a605-62ed7d843832-O0 ] to framework
> 7bbcb55d-ce3b-40e6-a605-62ed7d843832-0000 (default)
> I0806 20:00:24.233058 21362 scheduler.cpp:847] Enqueuing event SUBSCRIBED
> received from http://172.16.10.6:36902/master/api/v1/scheduler
> I0806 20:00:24.233510 21362 scheduler.cpp:847] Enqueuing event HEARTBEAT
> received from http://172.16.10.6:36902/master/api/v1/scheduler
> I0806 20:00:24.235025 21366 scheduler.cpp:847] Enqueuing event OFFERS
> received from http://172.16.10.6:36902/master/api/v1/scheduler
> I0806 20:00:24.242210 21363 scheduler.cpp:246] Adding authentication headers
> to ACCEPT call to http://172.16.10.6:36902/master/api/v1/scheduler
> I0806 20:00:24.242585 21363 scheduler.cpp:600] Sending ACCEPT call to
> http://172.16.10.6:36902/master/api/v1/scheduler
> I0806 20:00:24.243816 21368 process.cpp:3671] Handling HTTP event for process
> 'master' with path: '/master/api/v1/scheduler'
> I0806 20:00:24.244995 21364 http.cpp:1115] HTTP POST for
> /master/api/v1/scheduler from 172.16.10.6:48888
> I0806 20:00:24.245823 21364 master.cpp:12685] Removing offer
> 7bbcb55d-ce3b-40e6-a605-62ed7d843832-O0
> I0806 20:00:24.246209 21364 master.cpp:4739] Processing ACCEPT call for
> offers: [ 7bbcb55d-ce3b-40e6-a605-62ed7d843832-O0 ] on agent
> 7bbcb55d-ce3b-40e6-a605-62ed7d843832-S0 at slave(1277)@172.16.10.6:36902
> (ip-172-16-10-6.ec2.internal) for framework
> 7bbcb55d-ce3b-40e6-a605-62ed7d843832-0000 (default)
> I0806 20:00:24.246385 21364 master.cpp:3824] Authorizing principal
> 'test-principal' to reserve resources 'disk(allocated:
> default-role)(reservations: [(DYNAMIC,default-role,test-principal)])[RAW]:200'
> I0806 20:00:24.248404 21364 master.cpp:5108] Applying RESERVE operation for
> resources
> [{"allocation_info":{"role":"default-role"},"disk":{"source":{"type":"RAW"}},"name":"disk","provider_id":{"value":"08838aad-7f0b-495d-8b72-dd2c2678d320"},"reservations":[{"principal":"test-principal","role":"default-role","type":"DYNAMIC"}],"scalar":{"value":200.0},"type":"SCALAR"}]
> from framework 7bbcb55d-ce3b-40e6-a605-62ed7d843832-0000 (default) to agent
> 7bbcb55d-ce3b-40e6-a605-62ed7d843832-S0 at slave(1277)@172.16.10.6:36902
> (ip-172-16-10-6.ec2.internal)
> I0806 20:00:24.248947 21364 master.cpp:12576] Sending operation 'operation'
> (uuid: aea1e1d0-f192-4940-8afb-1d435a4d144b) to agent
> 7bbcb55d-ce3b-40e6-a605-62ed7d843832-S0 at slave(1277)@172.16.10.6:36902
> (ip-172-16-10-6.ec2.internal)
> I0806 20:00:24.249485 21362 slave.cpp:4346] Ignoring new checkpointed
> resources and operations identical to the current version
> I0806 20:00:24.251276 21364 hierarchical.cpp:956] Updated allocation of
> framework 7bbcb55d-ce3b-40e6-a605-62ed7d843832-0000 on agent
> 7bbcb55d-ce3b-40e6-a605-62ed7d843832-S0 from cpus(allocated: default-role):2;
> mem(allocated: default-role):1024; disk(allocated: default-role):1024;
> disk(allocated: default-role)[RAW]:200; ports(allocated:
> default-role):[31000-32000] to cpus(allocated: default-role):2;
> mem(allocated: default-role):1024; disk(allocated: default-role):1024;
> ports(allocated: default-role):[31000-32000]; disk(allocated:
> default-role)(reservations: [(DYNAMIC,default-role,test-principal)])[RAW]:200
> I0806 20:00:24.251394 21364 hierarchical.cpp:1432] Allocation paused
> I0806 20:00:24.251924 21364 hierarchical.cpp:1218] Recovered disk(allocated:
> default-role)(reservations: [(DYNAMIC,default-role,test-principal)])[RAW]:200
> (total: cpus:2; mem:1024; disk:1024; ports:[31000-32000]; disk(reservations:
> [(DYNAMIC,default-role,test-principal)])[RAW]:200, allocated: cpus(allocated:
> default-role):2; mem(allocated: default-role):1024; disk(allocated:
> default-role):1024; ports(allocated: default-role):[31000-32000]) on agent
> 7bbcb55d-ce3b-40e6-a605-62ed7d843832-S0 from framework
> 7bbcb55d-ce3b-40e6-a605-62ed7d843832-0000
> I0806 20:00:24.252714 21368 http_connection.hpp:131] Sending 2 call to
> http://172.16.10.6:36902/slave(1277)/api/v1/resource_provider
> I0806 20:00:24.253152 21364 hierarchical.cpp:1218] Recovered cpus(allocated:
> default-role):2; mem(allocated: default-role):1024; disk(allocated:
> default-role):1024; ports(allocated: default-role):[31000-32000] (total:
> cpus:2; mem:1024; disk:1024; ports:[31000-32000]; disk(reservations:
> [(DYNAMIC,default-role,test-principal)])[RAW]:200, allocated: {}) on agent
> 7bbcb55d-ce3b-40e6-a605-62ed7d843832-S0 from framework
> 7bbcb55d-ce3b-40e6-a605-62ed7d843832-0000
> I0806 20:00:24.253226 21364 hierarchical.cpp:1264] Framework
> 7bbcb55d-ce3b-40e6-a605-62ed7d843832-0000 filtered agent
> 7bbcb55d-ce3b-40e6-a605-62ed7d843832-S0 for 5secs
> I0806 20:00:24.253456 21364 hierarchical.cpp:1442] Allocation resumed
> I0806 20:00:24.254040 21361 process.cpp:3671] Handling HTTP event for process
> 'slave(1277)' with path: '/slave(1277)/api/v1/resource_provider'
> I0806 20:00:24.293757 21363 http.cpp:1115] HTTP POST for
> /slave(1277)/api/v1/resource_provider from 172.16.10.6:48884
> I0806 20:00:24.294436 21364 slave.cpp:8417] Handling resource provider
> message 'UPDATE_OPERATION_STATUS: (uuid:
> aea1e1d0-f192-4940-8afb-1d435a4d144b) for framework
> 7bbcb55d-ce3b-40e6-a605-62ed7d843832-0000 (latest state: OPERATION_FINISHED,
> status update state: OPERATION_FINISHED)'
> I0806 20:00:24.294539 21364 slave.cpp:8870] Updating the state of operation
> 'operation' (uuid: aea1e1d0-f192-4940-8afb-1d435a4d144b) for framework
> 7bbcb55d-ce3b-40e6-a605-62ed7d843832-0000 (latest state: OPERATION_FINISHED,
> status update state: OPERATION_FINISHED)
> I0806 20:00:24.294571 21364 slave.cpp:8624] Forwarding status update of
> operation 'operation' (operation_uuid: aea1e1d0-f192-4940-8afb-1d435a4d144b)
> for framework 7bbcb55d-ce3b-40e6-a605-62ed7d843832-0000
> I0806 20:00:24.294821 21364 master.cpp:12232] Updating the state of operation
> 'operation' (uuid: aea1e1d0-f192-4940-8afb-1d435a4d144b) for framework
> 7bbcb55d-ce3b-40e6-a605-62ed7d843832-0000 (latest state: OPERATION_PENDING,
> status update state: OPERATION_FINISHED)
> I0806 20:00:24.294898 21364 master.cpp:9168] Forwarding operation status
> update OPERATION_FINISHED (Status UUID: INVALID UUID) for operation UUID
> aea1e1d0-f192-4940-8afb-1d435a4d144b (framework-supplied ID 'operation') of
> framework '7bbcb55d-ce3b-40e6-a605-62ed7d843832-0000' on agent
> 7bbcb55d-ce3b-40e6-a605-62ed7d843832-S0
> I0806 20:00:24.296190 21362 scheduler.cpp:847] Enqueuing event
> UPDATE_OPERATION_STATUS received from
> http://172.16.10.6:36902/master/api/v1/scheduler
> I0806 20:00:24.304412 29945 master.cpp:1135] Master terminating
> I0806 20:00:24.305038 21366 hierarchical.cpp:775] Removed all filters for
> agent 7bbcb55d-ce3b-40e6-a605-62ed7d843832-S0
> I0806 20:00:24.305061 21366 hierarchical.cpp:650] Removed agent
> 7bbcb55d-ce3b-40e6-a605-62ed7d843832-S0
> I0806 20:00:24.310272 21363 slave.cpp:6409] Got exited event for
> master@172.16.10.6:36902
> W0806 20:00:24.310297 21363 slave.cpp:6414] Master disconnected! Waiting for
> a new master to be elected
> E0806 20:00:24.310421 21363 scheduler.cpp:820] End-Of-File received from
> master. The master closed the event stream
> I0806 20:00:24.310497 21364 hierarchical.cpp:417] Removed framework
> 7bbcb55d-ce3b-40e6-a605-62ed7d843832-0000
> I0806 20:00:24.311053 21363 scheduler.cpp:499] Re-detecting master
> I0806 20:00:24.311995 21363 scheduler.cpp:450] Ignoring disconnection attempt
> from stale connection
> I0806 20:00:24.312081 21363 scheduler.cpp:525] New master detected at
> master@172.16.10.6:36902
> I0806 20:00:24.312100 21363 scheduler.cpp:534] Waiting for 0ns before
> initiating a re-(connection) attempt with the master
> I0806 20:00:24.312278 21363 scheduler.cpp:450] Ignoring disconnection attempt
> from stale connection
> I0806 20:00:24.313170 29945 cluster.cpp:177] Creating default 'local'
> authorizer
> I0806 20:00:24.319995 21366 scheduler.cpp:416] Connected with the master at
> http://172.16.10.6:36902/master/api/v1/scheduler
> I0806 20:00:24.327302 21362 master.cpp:440] Master
> aef84e86-60f9-4d30-93f8-98210598b3a3 (ip-172-16-10-6.ec2.internal) started on
> 172.16.10.6:36902
> I0806 20:00:24.327320 21362 master.cpp:443] Flags at startup: --acls=""
> --agent_ping_timeout="15secs" --agent_reregister_timeout="10mins"
> --allocation_interval="1secs" --allocator="hierarchical"
> --authenticate_agents="true" --authenticate_frameworks="true"
> --authenticate_http_frameworks="true" --authenticate_http_readonly="true"
> --authenticate_http_readwrite="true" --authentication_v0_timeout="15secs"
> --authenticators="crammd5" --authorizers="local"
> --credentials="/tmp/MpmzC4/credentials" --filter_gpu_resources="true"
> --framework_sorter="drf" --help="false" --hostname_lookup="true"
> --http_authenticators="basic" --http_framework_authenticators="basic"
> --initialize_driver_logging="true" --log_auto_initialize="true"
> --logbufsecs="0" --logging_level="INFO" --max_agent_ping_timeouts="5"
> --max_completed_frameworks="50" --max_completed_tasks_per_framework="1000"
> --max_operator_event_stream_subscribers="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="in_memory"
> --registry_fetch_timeout="1mins" --registry_gc_interval="15mins"
> --registry_max_agent_age="2weeks" --registry_max_agent_count="102400"
> --registry_store_timeout="100secs" --registry_strict="false"
> --require_agent_domain="false" --role_sorter="drf" --root_submissions="true"
> --version="false" --webui_dir="/usr/local/share/mesos/webui"
> --work_dir="/tmp/MpmzC4/master" --zk_session_timeout="10secs"
> I0806 20:00:24.327594 21362 master.cpp:492] Master only allowing
> authenticated frameworks to register
> I0806 20:00:24.327603 21362 master.cpp:498] Master only allowing
> authenticated agents to register
> I0806 20:00:24.327608 21362 master.cpp:504] Master only allowing
> authenticated HTTP frameworks to register
> I0806 20:00:24.327615 21362 credentials.hpp:37] Loading credentials for
> authentication from '/tmp/MpmzC4/credentials'
> I0806 20:00:24.327802 21362 master.cpp:548] Using default 'crammd5'
> authenticator
> I0806 20:00:24.327941 21362 http.cpp:975] Creating default 'basic' HTTP
> authenticator for realm 'mesos-master-readonly'
> I0806 20:00:24.328074 21362 http.cpp:975] Creating default 'basic' HTTP
> authenticator for realm 'mesos-master-readwrite'
> I0806 20:00:24.328189 21362 http.cpp:975] Creating default 'basic' HTTP
> authenticator for realm 'mesos-master-scheduler'
> I0806 20:00:24.328295 21362 master.cpp:629] Authorization enabled
> I0806 20:00:24.330752 21362 hierarchical.cpp:241] Initialized hierarchical
> allocator process
> I0806 20:00:24.330838 21362 whitelist_watcher.cpp:77] No whitelist given
> I0806 20:00:24.332286 21362 master.cpp:2168] Elected as the leading master!
> I0806 20:00:24.332306 21362 master.cpp:1664] Recovering from registrar
> I0806 20:00:24.332532 21362 registrar.cpp:339] Recovering registrar
> I0806 20:00:24.333374 21362 registrar.cpp:383] Successfully fetched the
> registry (0B) in 0ns
> I0806 20:00:24.333463 21362 registrar.cpp:487] Applied 1 operations in
> 27198ns; attempting to update the registry
> I0806 20:00:24.334455 21362 registrar.cpp:544] Successfully updated the
> registry in 0ns
> I0806 20:00:24.334558 21362 registrar.cpp:416] Successfully recovered
> registrar
> I0806 20:00:24.335054 21362 master.cpp:1817] Recovered 0 agents from the
> registry (175B); allowing 10mins for agents to reregister
> I0806 20:00:24.335175 21362 hierarchical.cpp:280] Skipping recovery of
> hierarchical allocator: nothing to recover
> I0806 20:00:24.336079 21361 slave.cpp:1351] New master detected at
> master@172.16.10.6:36902
> I0806 20:00:24.336210 21361 slave.cpp:1416] Detecting new master
> I0806 20:00:24.336489 21361 scheduler.cpp:525] New master detected at
> master@172.16.10.6:36902
> I0806 20:00:24.336508 21361 scheduler.cpp:534] Waiting for 0ns before
> initiating a re-(connection) attempt with the master
> I0806 20:00:24.336859 21361 task_status_update_manager.cpp:181] Pausing
> sending task status updates
> I0806 20:00:24.336889 21361 status_update_manager_process.hpp:379] Pausing
> operation status update manager
> I0806 20:00:24.337605 21361 scheduler.cpp:450] Ignoring disconnection attempt
> from stale connection
> I0806 20:00:24.337633 21361 scheduler.cpp:450] Ignoring disconnection attempt
> from stale connection
> I0806 20:00:24.343678 21363 slave.cpp:1443] Authenticating with master
> master@172.16.10.6:36902
> I0806 20:00:24.343744 21363 slave.cpp:1452] Using default CRAM-MD5
> authenticatee
> I0806 20:00:24.344133 21363 authenticatee.cpp:121] Creating new client SASL
> connection
> I0806 20:00:24.344328 21363 master.cpp:10578] Authenticating
> slave(1277)@172.16.10.6:36902
> I0806 20:00:24.344491 21363 authenticator.cpp:414] Starting authentication
> session for crammd5-authenticatee(2163)@172.16.10.6:36902
> I0806 20:00:24.344847 21363 authenticator.cpp:98] Creating new server SASL
> connection
> I0806 20:00:24.345027 21363 authenticatee.cpp:213] Received SASL
> authentication mechanisms: CRAM-MD5
> I0806 20:00:24.345046 21363 authenticatee.cpp:239] Attempting to authenticate
> with mechanism 'CRAM-MD5'
> I0806 20:00:24.345126 21363 authenticator.cpp:204] Received SASL
> authentication start
> I0806 20:00:24.345166 21363 authenticator.cpp:326] Authentication requires
> more steps
> I0806 20:00:24.345238 21363 authenticatee.cpp:259] Received SASL
> authentication step
> I0806 20:00:24.345316 21363 authenticator.cpp:232] Received SASL
> authentication step
> I0806 20:00:24.345336 21363 auxprop.cpp:109] Request to lookup properties for
> user: 'test-principal' realm: 'ip-172-16-10-6.ec2.internal' server FQDN:
> 'ip-172-16-10-6.ec2.internal' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
> SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
> I0806 20:00:24.345346 21363 auxprop.cpp:181] Looking up auxiliary property
> '*userPassword'
> I0806 20:00:24.345373 21363 auxprop.cpp:181] Looking up auxiliary property
> '*cmusaslsecretCRAM-MD5'
> I0806 20:00:24.345386 21363 auxprop.cpp:109] Request to lookup properties for
> user: 'test-principal' realm: 'ip-172-16-10-6.ec2.internal' server FQDN:
> 'ip-172-16-10-6.ec2.internal' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
> SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
> I0806 20:00:24.345393 21363 auxprop.cpp:131] Skipping auxiliary property
> '*userPassword' since SASL_AUXPROP_AUTHZID == true
> I0806 20:00:24.345400 21363 auxprop.cpp:131] Skipping auxiliary property
> '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
> I0806 20:00:24.345413 21363 authenticator.cpp:318] Authentication success
> I0806 20:00:24.345561 21363 authenticatee.cpp:299] Authentication success
> I0806 20:00:24.345755 21363 master.cpp:10610] Successfully authenticated
> principal 'test-principal' at slave(1277)@172.16.10.6:36902
> I0806 20:00:24.345831 21363 authenticator.cpp:432] Authentication session
> cleanup for crammd5-authenticatee(2163)@172.16.10.6:36902
> I0806 20:00:24.346129 21363 slave.cpp:1543] Successfully authenticated with
> master master@172.16.10.6:36902
> I0806 20:00:24.346573 21363 slave.cpp:1993] Will retry registration in
> 1.163754ms if necessary
> I0806 20:00:24.346999 21363 master.cpp:7437] Received reregister agent
> message from agent 7bbcb55d-ce3b-40e6-a605-62ed7d843832-S0 at
> slave(1277)@172.16.10.6:36902 (ip-172-16-10-6.ec2.internal)
> I0806 20:00:24.347373 21363 master.cpp:4202] Authorizing agent providing
> resources 'cpus:2; mem:1024; disk:1024; ports:[31000-32000]' with principal
> 'test-principal'
> I0806 20:00:24.348167 21363 master.cpp:7529] Authorized re-registration of
> agent 7bbcb55d-ce3b-40e6-a605-62ed7d843832-S0 at
> slave(1277)@172.16.10.6:36902 (ip-172-16-10-6.ec2.internal)
> I0806 20:00:24.348232 21363 master.cpp:7701] Consulting registry about agent
> 7bbcb55d-ce3b-40e6-a605-62ed7d843832-S0 at
> slave(1277)@172.16.10.6:36902(ip-172-16-10-6.ec2.internal)
> W0806 20:00:24.348624 21363 registry_operations.cpp:200] Allowing UNKNOWN
> agent to reregister: hostname: "ip-172-16-10-6.ec2.internal"
> resources {
> name: "cpus"
> type: SCALAR
> scalar {
> value: 2
> }
> }
> resources {
> name: "mem"
> type: SCALAR
> scalar {
> value: 1024
> }
> }
> resources {
> name: "disk"
> type: SCALAR
> scalar {
> value: 1024
> }
> }
> resources {
> name: "ports"
> type: RANGES
> ranges {
> range {
> begin: 31000
> end: 32000
> }
> }
> }
> id {
> value: "7bbcb55d-ce3b-40e6-a605-62ed7d843832-S0"
> }
> checkpoint: true
> port: 36902
> I0806 20:00:24.348960 21363 registrar.cpp:487] Applied 1 operations in
> 376537ns; attempting to update the registry
> I0806 20:00:24.349635 21363 registrar.cpp:544] Successfully updated the
> registry in 0ns
> I0806 20:00:24.349889 21363 master.cpp:7757] Re-admitted agent
> 7bbcb55d-ce3b-40e6-a605-62ed7d843832-S0 at slave(1277)@172.16.10.6:36902
> (ip-172-16-10-6.ec2.internal)
> I0806 20:00:24.350466 21363 master.cpp:7954] Re-registered agent
> 7bbcb55d-ce3b-40e6-a605-62ed7d843832-S0 at slave(1277)@172.16.10.6:36902
> (ip-172-16-10-6.ec2.internal) with cpus:2; mem:1024; disk:1024;
> ports:[31000-32000]
> I0806 20:00:24.350785 21363 hierarchical.cpp:617] Added agent
> 7bbcb55d-ce3b-40e6-a605-62ed7d843832-S0 (ip-172-16-10-6.ec2.internal) with
> cpus:2; mem:1024; disk:1024; ports:[31000-32000] (allocated: {})
> I0806 20:00:24.351011 21363 hierarchical.cpp:1508] Performed allocation for 1
> agents in 91911ns
> I0806 20:00:24.351110 21363 slave.cpp:1700] Re-registered with master
> master@172.16.10.6:36902
> I0806 20:00:24.352250 21363 slave.cpp:1746] Forwarding agent update
> {"operations":{},"resource_providers":{"providers":[{"info":{"id":{"value":"08838aad-7f0b-495d-8b72-dd2c2678d320"},"name":"test","type":"org.apache.mesos.rp.test"},"operations":{"operations":[{"framework_id":{"value":"7bbcb55d-ce3b-40e6-a605-62ed7d843832-0000"},"info":{"id":{"value":"operation"},"reserve":{"resources":[{"allocation_info":{"role":"default-role"},"disk":{"source":{"type":"RAW"}},"name":"disk","provider_id":{"value":"08838aad-7f0b-495d-8b72-dd2c2678d320"},"reservations":[{"principal":"test-principal","role":"default-role","type":"DYNAMIC"}],"scalar":{"value":200.0},"type":"SCALAR"}]},"type":"RESERVE"},"latest_status":{"operation_id":{"value":"operation"},"resource_provider_id":{"value":"08838aad-7f0b-495d-8b72-dd2c2678d320"},"slave_id":{"value":"7bbcb55d-ce3b-40e6-a605-62ed7d843832-S0"},"state":"OPERATION_FINISHED","uuid":{"value":"ZGU4OWU0MjItZDUzMC00MDg4LTk0MzktZjZmZjgxMWVjZjJj"}},"slave_id":{"value":"7bbcb55d-ce3b-40e6-a605-62ed7d843832-S0"},"statuses":[{"operation_id":{"value":"operation"},"resource_provider_id":{"value":"08838aad-7f0b-495d-8b72-dd2c2678d320"},"slave_id":{"value":"7bbcb55d-ce3b-40e6-a605-62ed7d843832-S0"},"state":"OPERATION_FINISHED","uuid":{"value":"ZGU4OWU0MjItZDUzMC00MDg4LTk0MzktZjZmZjgxMWVjZjJj"}}],"uuid":{"value":"rqHh0PGSSUCK+x1DWk0USw=="}}]},"resource_version_uuid":{"value":"KfJNkTTGQNaEY5QhGULSQA=="},"total_resources":[{"disk":{"source":{"type":"RAW"}},"name":"disk","provider_id":{"value":"08838aad-7f0b-495d-8b72-dd2c2678d320"},"reservations":[{"principal":"test-principal","role":"default-role","type":"DYNAMIC"}],"scalar":{"value":200.0},"type":"SCALAR"}]}]},"resource_version_uuid":{"value":"/JaO7ln0ROi+NZkPMvYECw=="},"slave_id":{"value":"7bbcb55d-ce3b-40e6-a605-62ed7d843832-S0"},"update_oversubscribed_resources":false}
> I0806 20:00:24.352717 21363 task_status_update_manager.cpp:188] Resuming
> sending task status updates
> I0806 20:00:24.352749 21363 status_update_manager_process.hpp:385] Resuming
> operation status update manager
> I0806 20:00:24.353631 21365 scheduler.cpp:246] Adding authentication headers
> to SUBSCRIBE call to http://172.16.10.6:36902/master/api/v1/scheduler
> W0806 20:00:24.354037 21365 scheduler.cpp:568] Dropping SUBSCRIBE: Scheduler
> is in state CONNECTING
> I0806 20:00:24.355710 21364 scheduler.cpp:416] Connected with the master at
> http://172.16.10.6:36902/master/api/v1/scheduler
> /home/centos/workspace/mesos/Mesos_CI-build/FLAG/CMake/label/mesos-ec2-centos-7/mesos/src/tests/operation_reconciliation_tests.cpp:1871:
> Failure
> Failed to wait 15secs for resubscribed
> /home/centos/workspace/mesos/Mesos_CI-build/FLAG/CMake/label/mesos-ec2-centos-7/mesos/src/tests/operation_reconciliation_tests.cpp:1864:
> Failure
> Actual function call count doesn't match EXPECT_CALL(*scheduler,
> subscribed(_, _))...
> Expected: to be called once
> Actual: never called - unsatisfied and active
> I0806 20:00:39.360781 29945 slave.cpp:924] Agent terminating
> I0806 20:00:39.361528 29945 manager.cpp:163] Terminating resource provider
> 08838aad-7f0b-495d-8b72-dd2c2678d320
> I0806 20:00:39.363170 21361 master.cpp:1295] Agent
> 7bbcb55d-ce3b-40e6-a605-62ed7d843832-S0 at slave(1277)@172.16.10.6:36902
> (ip-172-16-10-6.ec2.internal) disconnected
> I0806 20:00:39.363198 21361 master.cpp:3397] Disconnecting agent
> 7bbcb55d-ce3b-40e6-a605-62ed7d843832-S0 at slave(1277)@172.16.10.6:36902
> (ip-172-16-10-6.ec2.internal)
> I0806 20:00:39.363250 21361 master.cpp:3416] Deactivating agent
> 7bbcb55d-ce3b-40e6-a605-62ed7d843832-S0 at slave(1277)@172.16.10.6:36902
> (ip-172-16-10-6.ec2.internal)
> I0806 20:00:39.363620 21361 hierarchical.cpp:799] Agent
> 7bbcb55d-ce3b-40e6-a605-62ed7d843832-S0 deactivated
> I0806 20:00:39.367709 21363 hierarchical.cpp:1508] Performed allocation for 1
> agents in 130458ns
> I0806 20:00:39.375468 29945 master.cpp:1135] Master terminating
> I0806 20:00:39.375960 21367 hierarchical.cpp:775] Removed all filters for
> agent 7bbcb55d-ce3b-40e6-a605-62ed7d843832-S0
> I0806 20:00:39.375977 21367 hierarchical.cpp:650] Removed agent
> 7bbcb55d-ce3b-40e6-a605-62ed7d843832-S0
> [ FAILED ]
> ContentType/OperationReconciliationTest.FrameworkReconciliationRaceWithUpdateSlaveMessage/1,
> where GetParam() = application/json (15253 ms)
> {code}
--
This message was sent by Atlassian JIRA
(v7.6.14#76016)
