Andrei Sekretenko created MESOS-9922:
----------------------------------------
Summary: MasterQuotaTest.RescindOffersEnforcingLimits is flaky
Key: MESOS-9922
URL: https://issues.apache.org/jira/browse/MESOS-9922
Project: Mesos
Issue Type: Bug
Reporter: Andrei Sekretenko
Assignee: Meng Zhu
Showed up on ASF CI:
https://builds.apache.org/view/M-R/view/Mesos/job/Mesos-Buildbot/6657/BUILDTOOL=cmake,COMPILER=clang,CONFIGURATION=--verbose%20--disable-libtool-wrappers%20--enable-parallel-test-execution=no,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1%20MESOS_TEST_AWAIT_TIMEOUT=60secs,OS=centos:7,label_exp=(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)&&(!ubuntu-4)&&(!H21)&&(!H23)&&(!H26)&&(!H27)/consoleFull
{code}
3: [ RUN ] MasterQuotaTest.RescindOffersEnforcingLimits
3: I0802 09:57:05.017333 15861 cluster.cpp:177] Creating default 'local'
authorizer
3: I0802 09:57:05.029503 15877 master.cpp:440] Master
9dd926f8-c8be-42ad-a1c7-ef0d88a99199 (148706d6d9ee) started on 172.17.0.2:41613
3: I0802 09:57:05.029911 15877 master.cpp:443] Flags at startup: --acls=""
--agent_ping_timeout="15secs" --agent_reregister_timeout="10mins"
--allocation_interval="50ms" --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/450qM2/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/450qM2/master" --zk_session_timeout="10secs"
3: I0802 09:57:05.030527 15877 master.cpp:492] Master only allowing
authenticated frameworks to register
3: I0802 09:57:05.030567 15877 master.cpp:498] Master only allowing
authenticated agents to register
3: I0802 09:57:05.030601 15877 master.cpp:504] Master only allowing
authenticated HTTP frameworks to register
3: I0802 09:57:05.030634 15877 credentials.hpp:37] Loading credentials for
authentication from '/tmp/450qM2/credentials'
3: I0802 09:57:05.031009 15877 master.cpp:548] Using default 'crammd5'
authenticator
3: I0802 09:57:05.031306 15877 http.cpp:975] Creating default 'basic' HTTP
authenticator for realm 'mesos-master-readonly'
3: I0802 09:57:05.031747 15877 http.cpp:975] Creating default 'basic' HTTP
authenticator for realm 'mesos-master-readwrite'
3: I0802 09:57:05.032049 15877 http.cpp:975] Creating default 'basic' HTTP
authenticator for realm 'mesos-master-scheduler'
3: I0802 09:57:05.032627 15877 master.cpp:629] Authorization enabled
3: I0802 09:57:05.033092 15880 hierarchical.cpp:241] Initialized hierarchical
allocator process
3: I0802 09:57:05.033552 15892 whitelist_watcher.cpp:77] No whitelist given
3: I0802 09:57:05.052621 15877 master.cpp:2168] Elected as the leading master!
3: I0802 09:57:05.052700 15877 master.cpp:1664] Recovering from registrar
3: I0802 09:57:05.052943 15873 registrar.cpp:339] Recovering registrar
3: I0802 09:57:05.054116 15873 registrar.cpp:383] Successfully fetched the
registry (0B) in 1.131008ms
3: I0802 09:57:05.054304 15873 registrar.cpp:487] Applied 1 operations in
73189ns; attempting to update the registry
3: I0802 09:57:05.055423 15873 registrar.cpp:544] Successfully updated the
registry in 1.02912ms
3: I0802 09:57:05.055572 15873 registrar.cpp:416] Successfully recovered
registrar
3: I0802 09:57:05.057384 15876 hierarchical.cpp:280] Skipping recovery of
hierarchical allocator: nothing to recover
3: I0802 09:57:05.057569 15877 master.cpp:1817] Recovered 0 agents from the
registry (143B); allowing 10mins for agents to reregister
3: W0802 09:57:05.074198 15861 process.cpp:2877] Attempted to spawn already
running process files@172.17.0.2:41613
3: I0802 09:57:05.086482 15880 hierarchical.cpp:1508] Performed allocation for
0 agents in 119003ns
3: I0802 09:57:05.089071 15861 containerizer.cpp:318] Using isolation {
environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni }
3: W0802 09:57:05.090075 15861 backend.cpp:76] Failed to create 'overlay'
backend: OverlayBackend requires root privileges
3: W0802 09:57:05.090544 15861 backend.cpp:76] Failed to create 'aufs' backend:
AufsBackend requires root privileges
3: W0802 09:57:05.090595 15861 backend.cpp:76] Failed to create 'bind' backend:
BindBackend requires root privileges
3: I0802 09:57:05.090658 15861 provisioner.cpp:300] Using default backend 'copy'
3: I0802 09:57:05.093798 15861 cluster.cpp:518] Creating default 'local'
authorizer
3: I0802 09:57:05.099562 15882 slave.cpp:267] Mesos agent started on
(17)@172.17.0.2:41613
3: I0802 09:57:05.099623 15882 slave.cpp:268] Flags at startup: --acls=""
--appc_simple_discovery_uri_prefix="http://";
--appc_store_dir="/tmp/450qM2/jqdwI0/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/450qM2/jqdwI0/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/450qM2/jqdwI0/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/450qM2/jqdwI0/fetch" --fetcher_cache_size="2GB"
--fetcher_stall_timeout="1mins"
--frameworks_home="/tmp/450qM2/jqdwI0/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/450qM2/jqdwI0/http_credentials"
--http_heartbeat_interval="30secs" --initialize_driver_logging="true"
--isolation="posix/cpu,posix/mem" --launcher="posix"
--launcher_dir="/tmp/SRC/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:1;mem:1024" --revocable_cpu_low_priority="true"
--runtime_dir="/tmp/MasterQuotaTest_RescindOffersEnforcingLimits_Nys8o1"
--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/MasterQuotaTest_RescindOffersEnforcingLimits_XCzL51"
--zk_session_timeout="10secs"
3: I0802 09:57:05.100447 15882 credentials.hpp:86] Loading credential for
authentication from '/tmp/450qM2/jqdwI0/credential'
3: I0802 09:57:05.100728 15882 slave.cpp:300] Agent using credential for:
test-principal
3: I0802 09:57:05.100751 15882 credentials.hpp:37] Loading credentials for
authentication from '/tmp/450qM2/jqdwI0/http_credentials'
3: I0802 09:57:05.101040 15882 http.cpp:975] Creating default 'basic' HTTP
authenticator for realm 'mesos-agent-readonly'
3: I0802 09:57:05.101528 15882 disk_profile_adaptor.cpp:78] Creating default
disk profile adaptor module
3: I0802 09:57:05.102972 15882 slave.cpp:615] Agent resources:
[{"name":"cpus","scalar":{"value":1.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"disk","scalar":{"value":3749337.0},"type":"SCALAR"},{"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}]
3: I0802 09:57:05.103250 15882 slave.cpp:623] Agent attributes: [ ]
3: I0802 09:57:05.103266 15882 slave.cpp:632] Agent hostname: 148706d6d9ee
3: I0802 09:57:05.104347 15886 task_status_update_manager.cpp:181] Pausing
sending task status updates
3: I0802 09:57:05.104373 15878 status_update_manager_process.hpp:379] Pausing
operation status update manager
3: I0802 09:57:05.107336 15877 state.cpp:67] Recovering state from
'/tmp/MasterQuotaTest_RescindOffersEnforcingLimits_XCzL51/meta'
3: I0802 09:57:05.120726 15882 slave.cpp:7444] Finished recovering checkpointed
state from '/tmp/MasterQuotaTest_RescindOffersEnforcingLimits_XCzL51/meta',
beginning agent recovery
3: I0802 09:57:05.121412 15892 task_status_update_manager.cpp:207] Recovering
task status update manager
3: I0802 09:57:05.122179 15882 containerizer.cpp:821] Recovering Mesos
containers
3: I0802 09:57:05.122614 15882 containerizer.cpp:1147] Recovering isolators
3: I0802 09:57:05.126801 15882 containerizer.cpp:1186] Recovering provisioner
3: I0802 09:57:05.127704 15876 provisioner.cpp:500] Provisioner recovery
complete
3: I0802 09:57:05.140862 15882 hierarchical.cpp:1508] Performed allocation for
0 agents in 107533ns
3: I0802 09:57:05.141611 15878 composing.cpp:339] Finished recovering all
containerizers
3: I0802 09:57:05.142130 15878 slave.cpp:7908] Recovering executors
3: I0802 09:57:05.142243 15878 slave.cpp:8061] Finished recovery
3: I0802 09:57:05.143589 15888 task_status_update_manager.cpp:181] Pausing
sending task status updates
3: I0802 09:57:05.143630 15886 status_update_manager_process.hpp:379] Pausing
operation status update manager
3: I0802 09:57:05.143709 15892 slave.cpp:1351] New master detected at
master@172.17.0.2:41613
3: I0802 09:57:05.143868 15892 slave.cpp:1416] Detecting new master
3: W0802 09:57:05.144331 15861 process.cpp:2877] Attempted to spawn already
running process version@172.17.0.2:41613
3: I0802 09:57:05.146203 15861 sched.cpp:239] Version: 1.9.0
3: I0802 09:57:05.147024 15887 sched.cpp:343] New master detected at
master@172.17.0.2:41613
3: I0802 09:57:05.147194 15887 sched.cpp:408] Authenticating with master
master@172.17.0.2:41613
3: I0802 09:57:05.147215 15887 sched.cpp:415] Using default CRAM-MD5
authenticatee
3: I0802 09:57:05.147907 15890 authenticatee.cpp:121] Creating new client SASL
connection
3: I0802 09:57:05.148314 15874 master.cpp:10578] Authenticating
scheduler-e08ce575-9286-4e6e-9572-c83259dad792@172.17.0.2:41613
3: I0802 09:57:05.148574 15874 authenticator.cpp:414] Starting authentication
session for crammd5-authenticatee(41)@172.17.0.2:41613
3: I0802 09:57:05.149073 15874 authenticator.cpp:98] Creating new server SASL
connection
3: I0802 09:57:05.149623 15874 authenticatee.cpp:213] Received SASL
authentication mechanisms: CRAM-MD5
3: I0802 09:57:05.149660 15874 authenticatee.cpp:239] Attempting to
authenticate with mechanism 'CRAM-MD5'
3: I0802 09:57:05.149797 15874 authenticator.cpp:204] Received SASL
authentication start
3: I0802 09:57:05.149865 15874 authenticator.cpp:326] Authentication requires
more steps
3: I0802 09:57:05.150003 15874 authenticatee.cpp:259] Received SASL
authentication step
3: I0802 09:57:05.150120 15874 authenticator.cpp:232] Received SASL
authentication step
3: I0802 09:57:05.150152 15874 auxprop.cpp:109] Request to lookup properties
for user: 'test-principal' realm: '148706d6d9ee' server FQDN: '148706d6d9ee'
SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
SASL_AUXPROP_AUTHZID: false
3: I0802 09:57:05.150167 15874 auxprop.cpp:181] Looking up auxiliary property
'*userPassword'
3: I0802 09:57:05.150226 15874 auxprop.cpp:181] Looking up auxiliary property
'*cmusaslsecretCRAM-MD5'
3: I0802 09:57:05.150254 15874 auxprop.cpp:109] Request to lookup properties
for user: 'test-principal' realm: '148706d6d9ee' server FQDN: '148706d6d9ee'
SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
SASL_AUXPROP_AUTHZID: true
3: I0802 09:57:05.150266 15874 auxprop.cpp:131] Skipping auxiliary property
'*userPassword' since SASL_AUXPROP_AUTHZID == true
3: I0802 09:57:05.150275 15874 auxprop.cpp:131] Skipping auxiliary property
'*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
3: I0802 09:57:05.150293 15874 authenticator.cpp:318] Authentication success
3: I0802 09:57:05.150494 15875 authenticatee.cpp:299] Authentication success
3: I0802 09:57:05.150573 15874 master.cpp:10610] Successfully authenticated
principal 'test-principal' at
scheduler-e08ce575-9286-4e6e-9572-c83259dad792@172.17.0.2:41613
3: I0802 09:57:05.150702 15874 authenticator.cpp:432] Authentication session
cleanup for crammd5-authenticatee(41)@172.17.0.2:41613
3: I0802 09:57:05.150995 15875 sched.cpp:520] Successfully authenticated with
master master@172.17.0.2:41613
3: I0802 09:57:05.151018 15875 sched.cpp:835] Sending SUBSCRIBE call to
master@172.17.0.2:41613
3: I0802 09:57:05.151211 15875 sched.cpp:870] Will retry registration in
24.561819ms if necessary
3: I0802 09:57:05.151538 15875 master.cpp:2908] Received SUBSCRIBE call for
framework 'default' at
scheduler-e08ce575-9286-4e6e-9572-c83259dad792@172.17.0.2:41613
3: I0802 09:57:05.151566 15875 master.cpp:2240] Authorizing framework principal
'test-principal' to receive offers for roles '{ role1 }'
3: I0802 09:57:05.152302 15891 master.cpp:2995] Subscribing framework default
with checkpointing disabled and capabilities [ MULTI_ROLE,
RESERVATION_REFINEMENT ]
3: I0802 09:57:05.152519 15887 slave.cpp:1443] Authenticating with master
master@172.17.0.2:41613
3: I0802 09:57:05.152618 15887 slave.cpp:1452] Using default CRAM-MD5
authenticatee
3: I0802 09:57:05.153172 15887 authenticatee.cpp:121] Creating new client SASL
connection
3: I0802 09:57:05.157215 15891 master.cpp:10808] Adding framework
9dd926f8-c8be-42ad-a1c7-ef0d88a99199-0000 (default) at
scheduler-e08ce575-9286-4e6e-9572-c83259dad792@172.17.0.2:41613 with roles { }
suppressed
3: I0802 09:57:05.160701 15888 hierarchical.cpp:368] Added framework
9dd926f8-c8be-42ad-a1c7-ef0d88a99199-0000
3: I0802 09:57:05.161007 15888 hierarchical.cpp:1508] Performed allocation for
0 agents in 131361ns
3: I0802 09:57:05.161232 15888 sched.cpp:751] Framework registered with
9dd926f8-c8be-42ad-a1c7-ef0d88a99199-0000
3: I0802 09:57:05.161291 15888 sched.cpp:770] Scheduler::registered took 43881ns
3: I0802 09:57:05.161705 15891 master.cpp:10578] Authenticating
slave(17)@172.17.0.2:41613
3: I0802 09:57:05.161986 15891 authenticator.cpp:414] Starting authentication
session for crammd5-authenticatee(42)@172.17.0.2:41613
3: I0802 09:57:05.162549 15891 authenticator.cpp:98] Creating new server SASL
connection
3: I0802 09:57:05.162926 15891 authenticatee.cpp:213] Received SASL
authentication mechanisms: CRAM-MD5
3: I0802 09:57:05.162976 15891 authenticatee.cpp:239] Attempting to
authenticate with mechanism 'CRAM-MD5'
3: I0802 09:57:05.163103 15891 authenticator.cpp:204] Received SASL
authentication start
3: I0802 09:57:05.163193 15891 authenticator.cpp:326] Authentication requires
more steps
3: I0802 09:57:05.163318 15891 authenticatee.cpp:259] Received SASL
authentication step
3: I0802 09:57:05.163466 15881 authenticator.cpp:232] Received SASL
authentication step
3: I0802 09:57:05.163518 15881 auxprop.cpp:109] Request to lookup properties
for user: 'test-principal' realm: '148706d6d9ee' server FQDN: '148706d6d9ee'
SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
SASL_AUXPROP_AUTHZID: false
3: I0802 09:57:05.168320 15881 auxprop.cpp:181] Looking up auxiliary property
'*userPassword'
3: I0802 09:57:05.168431 15881 auxprop.cpp:181] Looking up auxiliary property
'*cmusaslsecretCRAM-MD5'
3: I0802 09:57:05.168474 15881 auxprop.cpp:109] Request to lookup properties
for user: 'test-principal' realm: '148706d6d9ee' server FQDN: '148706d6d9ee'
SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
SASL_AUXPROP_AUTHZID: true
3: I0802 09:57:05.168493 15881 auxprop.cpp:131] Skipping auxiliary property
'*userPassword' since SASL_AUXPROP_AUTHZID == true
3: I0802 09:57:05.168503 15881 auxprop.cpp:131] Skipping auxiliary property
'*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
3: I0802 09:57:05.168534 15881 authenticator.cpp:318] Authentication success
3: I0802 09:57:05.168964 15881 authenticatee.cpp:299] Authentication success
3: I0802 09:57:05.169320 15881 master.cpp:10610] Successfully authenticated
principal 'test-principal' at slave(17)@172.17.0.2:41613
3: I0802 09:57:05.169478 15881 authenticator.cpp:432] Authentication session
cleanup for crammd5-authenticatee(42)@172.17.0.2:41613
3: I0802 09:57:05.170004 15881 slave.cpp:1543] Successfully authenticated with
master master@172.17.0.2:41613
3: I0802 09:57:05.170763 15881 slave.cpp:1993] Will retry registration in
4.399581ms if necessary
3: I0802 09:57:05.171401 15881 master.cpp:7086] Received register agent message
from slave(17)@172.17.0.2:41613 (148706d6d9ee)
3: I0802 09:57:05.171723 15881 master.cpp:4202] Authorizing agent providing
resources 'cpus:1; mem:1024; disk:3749337; ports:[31000-32000]' with principal
'test-principal'
3: I0802 09:57:05.177142 15878 slave.cpp:1993] Will retry registration in
37.129856ms if necessary
3: I0802 09:57:05.178035 15878 master.cpp:7079] Ignoring register agent message
from slave(17)@172.17.0.2:41613 (148706d6d9ee) as registration is already in
progress
3: I0802 09:57:05.178143 15878 master.cpp:7153] Authorized registration of
agent at slave(17)@172.17.0.2:41613 (148706d6d9ee)
3: I0802 09:57:05.178246 15878 master.cpp:7265] Registering agent at
slave(17)@172.17.0.2:41613 (148706d6d9ee) with id
9dd926f8-c8be-42ad-a1c7-ef0d88a99199-S0
3: I0802 09:57:05.179272 15888 registrar.cpp:487] Applied 1 operations in
362994ns; attempting to update the registry
3: I0802 09:57:05.180107 15888 registrar.cpp:544] Successfully updated the
registry in 748032ns
3: I0802 09:57:05.184391 15879 master.cpp:7313] Admitted agent
9dd926f8-c8be-42ad-a1c7-ef0d88a99199-S0 at slave(17)@172.17.0.2:41613
(148706d6d9ee)
3: I0802 09:57:05.185465 15879 master.cpp:7358] Registered agent
9dd926f8-c8be-42ad-a1c7-ef0d88a99199-S0 at slave(17)@172.17.0.2:41613
(148706d6d9ee) with cpus:1; mem:1024; disk:3749337; ports:[31000-32000]
3: I0802 09:57:05.186156 15879 hierarchical.cpp:617] Added agent
9dd926f8-c8be-42ad-a1c7-ef0d88a99199-S0 (148706d6d9ee) with cpus:1; mem:1024;
disk:3749337; ports:[31000-32000] (allocated: {})
3: I0802 09:57:05.187729 15879 hierarchical.cpp:1508] Performed allocation for
1 agents in 1.368422ms
3: I0802 09:57:05.187886 15879 slave.cpp:1576] Registered with master
master@172.17.0.2:41613; given agent ID 9dd926f8-c8be-42ad-a1c7-ef0d88a99199-S0
3: I0802 09:57:05.192725 15876 task_status_update_manager.cpp:188] Resuming
sending task status updates
3: I0802 09:57:05.192859 15879 slave.cpp:1611] Checkpointing SlaveInfo to
'/tmp/MasterQuotaTest_RescindOffersEnforcingLimits_XCzL51/meta/slaves/9dd926f8-c8be-42ad-a1c7-ef0d88a99199-S0/slave.info'
3: I0802 09:57:05.193363 15871 master.cpp:10393] Sending offers [
9dd926f8-c8be-42ad-a1c7-ef0d88a99199-O0 ] to framework
9dd926f8-c8be-42ad-a1c7-ef0d88a99199-0000 (default) at
scheduler-e08ce575-9286-4e6e-9572-c83259dad792@172.17.0.2:41613
3: I0802 09:57:05.193572 15873 status_update_manager_process.hpp:385] Resuming
operation status update manager
3: I0802 09:57:05.194280 15873 sched.cpp:934] Scheduler::resourceOffers took
116258ns
3: I0802 09:57:05.194945 15873 hierarchical.cpp:1508] Performed allocation for
1 agents in 375907ns
3: I0802 09:57:05.195372 15879 slave.cpp:1663] Forwarding agent update
{"operations":{},"resource_providers":{},"resource_version_uuid":{"value":"Chjy8C/USQqbsT32vnA1uw=="},"slave_id":{"value":"9dd926f8-c8be-42ad-a1c7-ef0d88a99199-S0"},"update_oversubscribed_resources":false}
3: I0802 09:57:05.196919 15893 master.cpp:8457] Ignoring update on agent
9dd926f8-c8be-42ad-a1c7-ef0d88a99199-S0 at slave(17)@172.17.0.2:41613
(148706d6d9ee) as it reports no changes
3: W0802 09:57:05.205972 15861 process.cpp:2877] Attempted to spawn already
running process files@172.17.0.2:41613
3: I0802 09:57:05.207845 15861 containerizer.cpp:318] Using isolation {
environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni }
3: W0802 09:57:05.222391 15861 backend.cpp:76] Failed to create 'overlay'
backend: OverlayBackend requires root privileges
3: W0802 09:57:05.222438 15861 backend.cpp:76] Failed to create 'aufs' backend:
AufsBackend requires root privileges
3: W0802 09:57:05.222460 15861 backend.cpp:76] Failed to create 'bind' backend:
BindBackend requires root privileges
3: I0802 09:57:05.222501 15861 provisioner.cpp:300] Using default backend 'copy'
3: I0802 09:57:05.238737 15861 cluster.cpp:518] Creating default 'local'
authorizer
3: I0802 09:57:05.249315 15876 hierarchical.cpp:1508] Performed allocation for
1 agents in 408138ns
3: I0802 09:57:05.276511 15872 slave.cpp:267] Mesos agent started on
(18)@172.17.0.2:41613
3: I0802 09:57:05.276571 15872 slave.cpp:268] Flags at startup: --acls=""
--appc_simple_discovery_uri_prefix="http://";
--appc_store_dir="/tmp/450qM2/TDawGY/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/450qM2/TDawGY/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/450qM2/TDawGY/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/450qM2/TDawGY/fetch" --fetcher_cache_size="2GB"
--fetcher_stall_timeout="1mins"
--frameworks_home="/tmp/450qM2/TDawGY/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/450qM2/TDawGY/http_credentials"
--http_heartbeat_interval="30secs" --initialize_driver_logging="true"
--isolation="posix/cpu,posix/mem" --launcher="posix"
--launcher_dir="/tmp/SRC/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:1;mem:1024" --revocable_cpu_low_priority="true"
--runtime_dir="/tmp/MasterQuotaTest_RescindOffersEnforcingLimits_TODS3Y"
--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/MasterQuotaTest_RescindOffersEnforcingLimits_w13frZ"
--zk_session_timeout="10secs"
3: I0802 09:57:05.277412 15872 credentials.hpp:86] Loading credential for
authentication from '/tmp/450qM2/TDawGY/credential'
3: I0802 09:57:05.277693 15872 slave.cpp:300] Agent using credential for:
test-principal
3: I0802 09:57:05.277715 15872 credentials.hpp:37] Loading credentials for
authentication from '/tmp/450qM2/TDawGY/http_credentials'
3: I0802 09:57:05.277998 15872 http.cpp:975] Creating default 'basic' HTTP
authenticator for realm 'mesos-agent-readonly'
3: I0802 09:57:05.278468 15872 disk_profile_adaptor.cpp:78] Creating default
disk profile adaptor module
3: I0802 09:57:05.279918 15872 slave.cpp:615] Agent resources:
[{"name":"cpus","scalar":{"value":1.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"disk","scalar":{"value":3749337.0},"type":"SCALAR"},{"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}]
3: I0802 09:57:05.280186 15872 slave.cpp:623] Agent attributes: [ ]
3: I0802 09:57:05.280205 15872 slave.cpp:632] Agent hostname: 148706d6d9ee
3: I0802 09:57:05.283205 15872 task_status_update_manager.cpp:181] Pausing
sending task status updates
3: I0802 09:57:05.283267 15872 status_update_manager_process.hpp:379] Pausing
operation status update manager
3: I0802 09:57:05.288424 15872 state.cpp:67] Recovering state from
'/tmp/MasterQuotaTest_RescindOffersEnforcingLimits_w13frZ/meta'
3: I0802 09:57:05.289094 15872 slave.cpp:7444] Finished recovering checkpointed
state from '/tmp/MasterQuotaTest_RescindOffersEnforcingLimits_w13frZ/meta',
beginning agent recovery
3: I0802 09:57:05.289788 15875 task_status_update_manager.cpp:207] Recovering
task status update manager
3: I0802 09:57:05.290593 15872 containerizer.cpp:821] Recovering Mesos
containers
3: I0802 09:57:05.290952 15872 containerizer.cpp:1147] Recovering isolators
3: I0802 09:57:05.292505 15885 containerizer.cpp:1186] Recovering provisioner
3: I0802 09:57:05.293473 15885 provisioner.cpp:500] Provisioner recovery
complete
3: I0802 09:57:05.294914 15885 composing.cpp:339] Finished recovering all
containerizers
3: I0802 09:57:05.295361 15885 slave.cpp:7908] Recovering executors
3: I0802 09:57:05.295472 15885 slave.cpp:8061] Finished recovery
3: W0802 09:57:05.297149 15861 process.cpp:2877] Attempted to spawn already
running process version@172.17.0.2:41613
3: I0802 09:57:05.297420 15885 slave.cpp:1351] New master detected at
master@172.17.0.2:41613
3: I0802 09:57:05.297458 15880 task_status_update_manager.cpp:181] Pausing
sending task status updates
3: I0802 09:57:05.297533 15885 slave.cpp:1416] Detecting new master
3: I0802 09:57:05.297538 15880 status_update_manager_process.hpp:379] Pausing
operation status update manager
3: I0802 09:57:05.305006 15887 hierarchical.cpp:1508] Performed allocation for
1 agents in 317611ns
3: I0802 09:57:05.305449 15861 sched.cpp:239] Version: 1.9.0
3: I0802 09:57:05.306335 15882 sched.cpp:343] New master detected at
master@172.17.0.2:41613
3: I0802 09:57:05.306438 15882 sched.cpp:408] Authenticating with master
master@172.17.0.2:41613
3: I0802 09:57:05.306457 15882 sched.cpp:415] Using default CRAM-MD5
authenticatee
3: I0802 09:57:05.307082 15882 authenticatee.cpp:121] Creating new client SASL
connection
3: I0802 09:57:05.307696 15882 master.cpp:10578] Authenticating
scheduler-76d82e9d-f02c-4174-894e-be6b1a164320@172.17.0.2:41613
3: I0802 09:57:05.307929 15882 authenticator.cpp:414] Starting authentication
session for crammd5-authenticatee(43)@172.17.0.2:41613
3: I0802 09:57:05.308429 15876 slave.cpp:1443] Authenticating with master
master@172.17.0.2:41613
3: I0802 09:57:05.308714 15882 authenticator.cpp:98] Creating new server SASL
connection
3: I0802 09:57:05.309056 15882 authenticatee.cpp:213] Received SASL
authentication mechanisms: CRAM-MD5
3: I0802 09:57:05.309088 15882 authenticatee.cpp:239] Attempting to
authenticate with mechanism 'CRAM-MD5'
3: I0802 09:57:05.309224 15882 authenticator.cpp:204] Received SASL
authentication start
3: I0802 09:57:05.309303 15882 authenticator.cpp:326] Authentication requires
more steps
3: I0802 09:57:05.309432 15882 authenticatee.cpp:259] Received SASL
authentication step
3: I0802 09:57:05.309566 15882 authenticator.cpp:232] Received SASL
authentication step
3: I0802 09:57:05.309602 15882 auxprop.cpp:109] Request to lookup properties
for user: 'test-principal' realm: '148706d6d9ee' server FQDN: '148706d6d9ee'
SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
SASL_AUXPROP_AUTHZID: false
3: I0802 09:57:05.309623 15882 auxprop.cpp:181] Looking up auxiliary property
'*userPassword'
3: I0802 09:57:05.309686 15882 auxprop.cpp:181] Looking up auxiliary property
'*cmusaslsecretCRAM-MD5'
3: I0802 09:57:05.309722 15882 auxprop.cpp:109] Request to lookup properties
for user: 'test-principal' realm: '148706d6d9ee' server FQDN: '148706d6d9ee'
SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
SASL_AUXPROP_AUTHZID: true
3: I0802 09:57:05.309739 15882 auxprop.cpp:131] Skipping auxiliary property
'*userPassword' since SASL_AUXPROP_AUTHZID == true
3: I0802 09:57:05.309751 15882 auxprop.cpp:131] Skipping auxiliary property
'*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
3: I0802 09:57:05.309772 15882 authenticator.cpp:318] Authentication success
3: I0802 09:57:05.310050 15882 authenticatee.cpp:299] Authentication success
3: I0802 09:57:05.310207 15870 master.cpp:10610] Successfully authenticated
principal 'test-principal' at
scheduler-76d82e9d-f02c-4174-894e-be6b1a164320@172.17.0.2:41613
3: I0802 09:57:05.310354 15870 authenticator.cpp:432] Authentication session
cleanup for crammd5-authenticatee(43)@172.17.0.2:41613
3: I0802 09:57:05.310809 15876 slave.cpp:1452] Using default CRAM-MD5
authenticatee
3: I0802 09:57:05.311417 15876 authenticatee.cpp:121] Creating new client SASL
connection
3: I0802 09:57:05.311868 15876 master.cpp:10578] Authenticating
slave(18)@172.17.0.2:41613
3: I0802 09:57:05.312104 15876 authenticator.cpp:414] Starting authentication
session for crammd5-authenticatee(44)@172.17.0.2:41613
3: I0802 09:57:05.316658 15876 authenticator.cpp:98] Creating new server SASL
connection
3: I0802 09:57:05.317152 15876 authenticatee.cpp:213] Received SASL
authentication mechanisms: CRAM-MD5
3: I0802 09:57:05.317185 15876 authenticatee.cpp:239] Attempting to
authenticate with mechanism 'CRAM-MD5'
3: I0802 09:57:05.317333 15876 authenticator.cpp:204] Received SASL
authentication start
3: I0802 09:57:05.317412 15876 authenticator.cpp:326] Authentication requires
more steps
3: I0802 09:57:05.317543 15876 authenticatee.cpp:259] Received SASL
authentication step
3: I0802 09:57:05.317685 15876 authenticator.cpp:232] Received SASL
authentication step
3: I0802 09:57:05.317723 15876 auxprop.cpp:109] Request to lookup properties
for user: 'test-principal' realm: '148706d6d9ee' server FQDN: '148706d6d9ee'
SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
SASL_AUXPROP_AUTHZID: false
3: I0802 09:57:05.317742 15876 auxprop.cpp:181] Looking up auxiliary property
'*userPassword'
3: I0802 09:57:05.317811 15876 auxprop.cpp:181] Looking up auxiliary property
'*cmusaslsecretCRAM-MD5'
3: I0802 09:57:05.317848 15876 auxprop.cpp:109] Request to lookup properties
for user: 'test-principal' realm: '148706d6d9ee' server FQDN: '148706d6d9ee'
SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
SASL_AUXPROP_AUTHZID: true
3: I0802 09:57:05.317867 15876 auxprop.cpp:131] Skipping auxiliary property
'*userPassword' since SASL_AUXPROP_AUTHZID == true
3: I0802 09:57:05.317879 15876 auxprop.cpp:131] Skipping auxiliary property
'*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
3: I0802 09:57:05.317901 15876 authenticator.cpp:318] Authentication success
3: I0802 09:57:05.318174 15876 authenticatee.cpp:299] Authentication success
3: I0802 09:57:05.318508 15876 master.cpp:10610] Successfully authenticated
principal 'test-principal' at slave(18)@172.17.0.2:41613
3: I0802 09:57:05.318650 15876 authenticator.cpp:432] Authentication session
cleanup for crammd5-authenticatee(44)@172.17.0.2:41613
3: I0802 09:57:05.319175 15876 slave.cpp:1543] Successfully authenticated with
master master@172.17.0.2:41613
3: I0802 09:57:05.320288 15873 master.cpp:7086] Received register agent message
from slave(18)@172.17.0.2:41613 (148706d6d9ee)
3: I0802 09:57:05.320581 15873 master.cpp:4202] Authorizing agent providing
resources 'cpus:1; mem:1024; disk:3749337; ports:[31000-32000]' with principal
'test-principal'
3: I0802 09:57:05.321904 15889 master.cpp:7153] Authorized registration of
agent at slave(18)@172.17.0.2:41613 (148706d6d9ee)
3: I0802 09:57:05.322043 15889 master.cpp:7265] Registering agent at
slave(18)@172.17.0.2:41613 (148706d6d9ee) with id
9dd926f8-c8be-42ad-a1c7-ef0d88a99199-S1
3: I0802 09:57:05.322157 15876 slave.cpp:1993] Will retry registration in
13.968289ms if necessary
3: I0802 09:57:05.322919 15873 sched.cpp:520] Successfully authenticated with
master master@172.17.0.2:41613
3: I0802 09:57:05.322943 15873 sched.cpp:835] Sending SUBSCRIBE call to
master@172.17.0.2:41613
3: I0802 09:57:05.322984 15889 registrar.cpp:487] Applied 1 operations in
419808ns; attempting to update the registry
3: I0802 09:57:05.323137 15873 sched.cpp:870] Will retry registration in
1.840847468secs if necessary
3: I0802 09:57:05.323462 15873 master.cpp:2908] Received SUBSCRIBE call for
framework 'default' at
scheduler-76d82e9d-f02c-4174-894e-be6b1a164320@172.17.0.2:41613
3: I0802 09:57:05.323485 15873 master.cpp:2240] Authorizing framework principal
'test-principal' to receive offers for roles '{ role1/child }'
3: I0802 09:57:05.324035 15889 registrar.cpp:544] Successfully updated the
registry in 973056ns
3: I0802 09:57:05.328315 15873 master.cpp:7313] Admitted agent
9dd926f8-c8be-42ad-a1c7-ef0d88a99199-S1 at slave(18)@172.17.0.2:41613
(148706d6d9ee)
3: I0802 09:57:05.329753 15875 hierarchical.cpp:617] Added agent
9dd926f8-c8be-42ad-a1c7-ef0d88a99199-S1 (148706d6d9ee) with cpus:1; mem:1024;
disk:3749337; ports:[31000-32000] (allocated: {})
3: I0802 09:57:05.331312 15875 hierarchical.cpp:1508] Performed allocation for
1 agents in 1.343027ms
3: I0802 09:57:05.331818 15884 slave.cpp:1576] Registered with master
master@172.17.0.2:41613; given agent ID 9dd926f8-c8be-42ad-a1c7-ef0d88a99199-S1
3: I0802 09:57:05.332558 15884 slave.cpp:1611] Checkpointing SlaveInfo to
'/tmp/MasterQuotaTest_RescindOffersEnforcingLimits_w13frZ/meta/slaves/9dd926f8-c8be-42ad-a1c7-ef0d88a99199-S1/slave.info'
3: I0802 09:57:05.334188 15884 slave.cpp:1663] Forwarding agent update
{"operations":{},"resource_providers":{},"resource_version_uuid":{"value":"S/Rp1HolSa65hmTUbrhp9Q=="},"slave_id":{"value":"9dd926f8-c8be-42ad-a1c7-ef0d88a99199-S1"},"update_oversubscribed_resources":false}
3: I0802 09:57:05.334450 15884 task_status_update_manager.cpp:188] Resuming
sending task status updates
3: I0802 09:57:05.334573 15884 status_update_manager_process.hpp:385] Resuming
operation status update manager
3: I0802 09:57:05.336449 15873 master.cpp:7358] Registered agent
9dd926f8-c8be-42ad-a1c7-ef0d88a99199-S1 at slave(18)@172.17.0.2:41613
(148706d6d9ee) with cpus:1; mem:1024; disk:3749337; ports:[31000-32000]
3: I0802 09:57:05.336958 15873 master.cpp:2995] Subscribing framework default
with checkpointing disabled and capabilities [ MULTI_ROLE,
RESERVATION_REFINEMENT ]
3: I0802 09:57:05.349050 15873 master.cpp:10808] Adding framework
9dd926f8-c8be-42ad-a1c7-ef0d88a99199-0001 (default) at
scheduler-76d82e9d-f02c-4174-894e-be6b1a164320@172.17.0.2:41613 with roles { }
suppressed
3: I0802 09:57:05.351337 15873 master.cpp:10393] Sending offers [
9dd926f8-c8be-42ad-a1c7-ef0d88a99199-O1 ] to framework
9dd926f8-c8be-42ad-a1c7-ef0d88a99199-0000 (default) at
scheduler-e08ce575-9286-4e6e-9572-c83259dad792@172.17.0.2:41613
3: I0802 09:57:05.352591 15873 master.cpp:8457] Ignoring update on agent
9dd926f8-c8be-42ad-a1c7-ef0d88a99199-S1 at slave(18)@172.17.0.2:41613
(148706d6d9ee) as it reports no changes
3: I0802 09:57:05.353605 15881 hierarchical.cpp:368] Added framework
9dd926f8-c8be-42ad-a1c7-ef0d88a99199-0001
3: I0802 09:57:05.355470 15873 sched.cpp:934] Scheduler::resourceOffers took
47676ns
3: I0802 09:57:05.355579 15881 hierarchical.cpp:1508] Performed allocation for
2 agents in 577092ns
3: I0802 09:57:05.356719 15892 hierarchical.cpp:1508] Performed allocation for
2 agents in 446921ns
3: I0802 09:57:05.354157 15883 sched.cpp:751] Framework registered with
9dd926f8-c8be-42ad-a1c7-ef0d88a99199-0001
3: I0802 09:57:05.360374 15883 sched.cpp:770] Scheduler::registered took 75574ns
3: I0802 09:57:05.409284 15875 hierarchical.cpp:1508] Performed allocation for
2 agents in 493987ns
3: I0802 09:57:05.465063 15870 hierarchical.cpp:1508] Performed allocation for
2 agents in 508165ns
...........
3: I0802 09:58:05.034294 15880 hierarchical.cpp:1508] Performed allocation for
2 agents in 557279ns
3: I0802 09:58:05.086269 15876 hierarchical.cpp:1508] Performed allocation for
2 agents in 561517ns
3: I0802 09:58:05.104465 15886 slave.cpp:7359] Current disk usage 16.47%. Max
allowed age: 5.146766280423298days
3: I0802 09:58:05.138171 15890 hierarchical.cpp:1508] Performed allocation for
2 agents in 517343ns
3: I0802 09:58:05.190285 15888 hierarchical.cpp:1508] Performed allocation for
2 agents in 564397ns
3: I0802 09:58:05.241955 15889 hierarchical.cpp:1508] Performed allocation for
2 agents in 569996ns
3: I0802 09:58:05.282167 15884 slave.cpp:7359] Current disk usage 16.47%. Max
allowed age: 5.146765275367859days
3: I0802 09:58:05.293754 15873 hierarchical.cpp:1508] Performed allocation for
2 agents in 521450ns
3: /tmp/SRC/src/tests/master_quota_tests.cpp:2111: Failure
3: Failed to wait 1mins for offers2
3: I0802 09:58:05.308029 15870 master.cpp:1410] Framework
9dd926f8-c8be-42ad-a1c7-ef0d88a99199-0001 (default) at
scheduler-76d82e9d-f02c-4174-894e-be6b1a164320@172.17.0.2:41613 disconnected
3: I0802 09:58:05.308115 15870 master.cpp:3360] Deactivating framework
9dd926f8-c8be-42ad-a1c7-ef0d88a99199-0001 (default) at
scheduler-76d82e9d-f02c-4174-894e-be6b1a164320@172.17.0.2:41613
3: /tmp/SRC/src/tests/master_quota_tests.cpp:2106: Failure
3: Actual function call count doesn't match EXPECT_CALL(sched2,
offerRescinded(&framework2, _))...
3: Expected: to be called once
3: Actual: never called - unsatisfied and active
3: /tmp/SRC/src/tests/master_quota_tests.cpp:2101: Failure
3: Actual function call count doesn't match EXPECT_CALL(sched2,
resourceOffers(&framework2, _))...
3: Expected: to be called at least once
3: Actual: never called - unsatisfied and active
3: I0802 09:58:05.308616 15870 master.cpp:3337] Disconnecting framework
9dd926f8-c8be-42ad-a1c7-ef0d88a99199-0001 (default) at
scheduler-76d82e9d-f02c-4174-894e-be6b1a164320@172.17.0.2:41613
3: I0802 09:58:05.308703 15870 master.cpp:1425] Giving framework
9dd926f8-c8be-42ad-a1c7-ef0d88a99199-0001 (default) at
scheduler-76d82e9d-f02c-4174-894e-be6b1a164320@172.17.0.2:41613 0ns to failover
3: I0802 09:58:05.308718 15882 hierarchical.cpp:475] Deactivated framework
9dd926f8-c8be-42ad-a1c7-ef0d88a99199-0001
3: I0802 09:58:05.309415 15890 slave.cpp:924] Agent terminating
3: I0802 09:58:05.310885 15890 master.cpp:1295] Agent
9dd926f8-c8be-42ad-a1c7-ef0d88a99199-S1 at slave(18)@172.17.0.2:41613
(148706d6d9ee) disconnected
3: I0802 09:58:05.310933 15890 master.cpp:3397] Disconnecting agent
9dd926f8-c8be-42ad-a1c7-ef0d88a99199-S1 at slave(18)@172.17.0.2:41613
(148706d6d9ee)
3: I0802 09:58:05.311017 15890 master.cpp:3416] Deactivating agent
9dd926f8-c8be-42ad-a1c7-ef0d88a99199-S1 at slave(18)@172.17.0.2:41613
(148706d6d9ee)
3: I0802 09:58:05.311187 15871 hierarchical.cpp:799] Agent
9dd926f8-c8be-42ad-a1c7-ef0d88a99199-S1 deactivated
3: I0802 09:58:05.312307 15890 master.cpp:12685] Removing offer
9dd926f8-c8be-42ad-a1c7-ef0d88a99199-O1
3: I0802 09:58:05.312551 15885 sched.cpp:960] Rescinded offer
9dd926f8-c8be-42ad-a1c7-ef0d88a99199-O1
3: I0802 09:58:05.312649 15885 sched.cpp:971] Scheduler::offerRescinded took
42088ns
3: I0802 09:58:05.313125 15870 master.cpp:10185] Framework failover timeout,
removing framework 9dd926f8-c8be-42ad-a1c7-ef0d88a99199-0001 (default) at
scheduler-76d82e9d-f02c-4174-894e-be6b1a164320@172.17.0.2:41613
3: I0802 09:58:05.313181 15870 master.cpp:11184] Removing framework
9dd926f8-c8be-42ad-a1c7-ef0d88a99199-0001 (default) at
scheduler-76d82e9d-f02c-4174-894e-be6b1a164320@172.17.0.2:41613
3: I0802 09:58:05.313244 15879 hierarchical.cpp:1218] Recovered cpus(allocated:
role1):1; mem(allocated: role1):1024; disk(allocated: role1):3749337;
ports(allocated: role1):[31000-32000] (total: cpus:1; mem:1024; disk:3749337;
ports:[31000-32000], allocated: {}) on agent
9dd926f8-c8be-42ad-a1c7-ef0d88a99199-S1 from framework
9dd926f8-c8be-42ad-a1c7-ef0d88a99199-0000
3: I0802 09:58:05.313500 15880 slave.cpp:4056] Asked to shut down framework
9dd926f8-c8be-42ad-a1c7-ef0d88a99199-0001 by master@172.17.0.2:41613
3: I0802 09:58:05.313560 15880 slave.cpp:4071] Cannot shut down unknown
framework 9dd926f8-c8be-42ad-a1c7-ef0d88a99199-0001
3: I0802 09:58:05.314222 15870 hierarchical.cpp:1432] Allocation paused
3: I0802 09:58:05.315065 15870 hierarchical.cpp:417] Removed framework
9dd926f8-c8be-42ad-a1c7-ef0d88a99199-0001
3: I0802 09:58:05.315119 15870 hierarchical.cpp:1442] Allocation resumed
3: I0802 09:58:05.345412 15874 hierarchical.cpp:1508] Performed allocation for
2 agents in 515090ns
3: I0802 09:58:05.386776 15887 master.cpp:1410] Framework
9dd926f8-c8be-42ad-a1c7-ef0d88a99199-0000 (default) at
scheduler-e08ce575-9286-4e6e-9572-c83259dad792@172.17.0.2:41613 disconnected
3: I0802 09:58:05.386883 15887 master.cpp:3360] Deactivating framework
9dd926f8-c8be-42ad-a1c7-ef0d88a99199-0000 (default) at
scheduler-e08ce575-9286-4e6e-9572-c83259dad792@172.17.0.2:41613
3: I0802 09:58:05.387162 15874 hierarchical.cpp:475] Deactivated framework
9dd926f8-c8be-42ad-a1c7-ef0d88a99199-0000
3: I0802 09:58:05.387805 15861 slave.cpp:924] Agent terminating
3: I0802 09:58:05.387997 15887 master.cpp:12685] Removing offer
9dd926f8-c8be-42ad-a1c7-ef0d88a99199-O0
3: I0802 09:58:05.388083 15887 master.cpp:3337] Disconnecting framework
9dd926f8-c8be-42ad-a1c7-ef0d88a99199-0000 (default) at
scheduler-e08ce575-9286-4e6e-9572-c83259dad792@172.17.0.2:41613
3: I0802 09:58:05.388149 15887 master.cpp:1425] Giving framework
9dd926f8-c8be-42ad-a1c7-ef0d88a99199-0000 (default) at
scheduler-e08ce575-9286-4e6e-9572-c83259dad792@172.17.0.2:41613 0ns to failover
3: I0802 09:58:05.389353 15893 hierarchical.cpp:1218] Recovered cpus(allocated:
role1):1; mem(allocated: role1):1024; disk(allocated: role1):3749337;
ports(allocated: role1):[31000-32000] (total: cpus:1; mem:1024; disk:3749337;
ports:[31000-32000], allocated: {}) on agent
9dd926f8-c8be-42ad-a1c7-ef0d88a99199-S0 from framework
9dd926f8-c8be-42ad-a1c7-ef0d88a99199-0000
3: I0802 09:58:05.392590 15877 master.cpp:10185] Framework failover timeout,
removing framework 9dd926f8-c8be-42ad-a1c7-ef0d88a99199-0000 (default) at
scheduler-e08ce575-9286-4e6e-9572-c83259dad792@172.17.0.2:41613
3: I0802 09:58:05.392665 15877 master.cpp:11184] Removing framework
9dd926f8-c8be-42ad-a1c7-ef0d88a99199-0000 (default) at
scheduler-e08ce575-9286-4e6e-9572-c83259dad792@172.17.0.2:41613
3: I0802 09:58:05.397346 15881 hierarchical.cpp:1508] Performed allocation for
2 agents in 495689ns
3: I0802 09:58:05.405243 15890 hierarchical.cpp:1432] Allocation paused
3: I0802 09:58:05.405948 15890 hierarchical.cpp:417] Removed framework
9dd926f8-c8be-42ad-a1c7-ef0d88a99199-0000
3: I0802 09:58:05.406090 15890 hierarchical.cpp:1442] Allocation resumed
3: I0802 09:58:05.406883 15884 master.cpp:1295] Agent
9dd926f8-c8be-42ad-a1c7-ef0d88a99199-S0 at slave(17)@172.17.0.2:41613
(148706d6d9ee) disconnected
3: I0802 09:58:05.406925 15884 master.cpp:3397] Disconnecting agent
9dd926f8-c8be-42ad-a1c7-ef0d88a99199-S0 at slave(17)@172.17.0.2:41613
(148706d6d9ee)
3: I0802 09:58:05.407009 15884 master.cpp:3416] Deactivating agent
9dd926f8-c8be-42ad-a1c7-ef0d88a99199-S0 at slave(17)@172.17.0.2:41613
(148706d6d9ee)
3: I0802 09:58:05.407382 15871 hierarchical.cpp:799] Agent
9dd926f8-c8be-42ad-a1c7-ef0d88a99199-S0 deactivated
3: I0802 09:58:05.449240 15884 hierarchical.cpp:1508] Performed allocation for
2 agents in 264454ns
3: I0802 09:58:05.486388 15861 master.cpp:1135] Master terminating
3: I0802 09:58:05.487401 15877 hierarchical.cpp:775] Removed all filters for
agent 9dd926f8-c8be-42ad-a1c7-ef0d88a99199-S1
3: I0802 09:58:05.487440 15877 hierarchical.cpp:650] Removed agent
9dd926f8-c8be-42ad-a1c7-ef0d88a99199-S1
3: I0802 09:58:05.487804 15877 hierarchical.cpp:775] Removed all filters for
agent 9dd926f8-c8be-42ad-a1c7-ef0d88a99199-S0
3: I0802 09:58:05.487824 15877 hierarchical.cpp:650] Removed agent
9dd926f8-c8be-42ad-a1c7-ef0d88a99199-S0
3: I0802 09:58:05.500919 15888 hierarchical.cpp:1508] Performed allocation for
0 agents in 143260ns
3: [ FAILED ] MasterQuotaTest.RescindOffersEnforcingLimits (60493 ms)
{code}
If I understand correctly, the offer with resources on a second slave went to
the fiirst framework, because the allocator wasn't aware about the second
framework when the second slave was added.
--
This message was sent by Atlassian JIRA
(v7.6.14#76016)
