Till Toenshoff created MESOS-8541:
-------------------------------------
Summary:
MasterTestPrePostReservationRefinement.StateEndpointPendingTasks is flaky.
Key: MESOS-8541
URL: https://issues.apache.org/jira/browse/MESOS-8541
Project: Mesos
Issue Type: Bug
Environment: Ubuntu 16.04, CMake
Reporter: Till Toenshoff
The following was observed
{noformat}
23:03:26 [ RUN ]
bool/MasterTestPrePostReservationRefinement.StateEndpointPendingTasks/0
23:03:26 I0202 23:03:26.725302 6733 master.cpp:458] Master
d107b5f2-a7b1-43e4-bc3e-c5d6a782f949 (ip-172-16-10-161.ec2.internal) started on
172.16.10.161:40613
23:03:26 I0202 23:03:26.725329 6733 master.cpp:460] Flags at startup:
--acls="" --agent_ping_timeout="15secs" --agent_reregister_timeout="10mins"
--allocation_interval="1000secs" --allocator="HierarchicalDRF"
--authenticate_agents="true" --authenticate_frameworks="true"
--authenticate_http_frameworks="true" --authenticate_http_readonly="true"
--authenticate_http_readwrite="true" --authenticators="crammd5"
--authorizers="local" --credentials="/tmp/NEpZ1C/credentials"
--filter_gpu_resources="true" --framework_sorter="drf" --help="false"
--hostname_lookup="true" --http_authenticators="basic"
--http_framework_authenticators="basic" --initialize_driver_logging="true"
--log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO"
--max_agent_ping_timeouts="5" --max_completed_frameworks="50"
--max_completed_tasks_per_framework="1000"
--max_unreachable_tasks_per_framework="1000" --port="5050" --quiet="false"
--recovery_agent_removal_limit="100%" --registry="in_memory"
--registry_fetch_timeout="1mins" --registry_gc_interval="15mins"
--registry_max_agent_age="2weeks" --registry_max_agent_count="102400"
--registry_store_timeout="100secs" --registry_strict="false"
--require_agent_domain="false" --root_submissions="true" --user_sorter="drf"
--version="false" --webui_dir="/usr/local/share/mesos/webui"
--work_dir="/tmp/NEpZ1C/master" --zk_session_timeout="10secs"
23:03:26 I0202 23:03:26.725617 6733 master.cpp:509] Master only allowing
authenticated frameworks to register
23:03:26 I0202 23:03:26.725630 6733 master.cpp:515] Master only allowing
authenticated agents to register
23:03:26 I0202 23:03:26.725636 6733 master.cpp:521] Master only allowing
authenticated HTTP frameworks to register
23:03:26 I0202 23:03:26.725643 6733 credentials.hpp:37] Loading credentials
for authentication from '/tmp/NEpZ1C/credentials'
23:03:26 I0202 23:03:26.725884 6733 master.cpp:565] Using default 'crammd5'
authenticator
23:03:26 I0202 23:03:26.726058 6733 http.cpp:1045] Creating default 'basic'
HTTP authenticator for realm 'mesos-master-readonly'
23:03:26 I0202 23:03:26.726233 6733 http.cpp:1045] Creating default 'basic'
HTTP authenticator for realm 'mesos-master-readwrite'
23:03:26 I0202 23:03:26.726392 6733 http.cpp:1045] Creating default 'basic'
HTTP authenticator for realm 'mesos-master-scheduler'
23:03:26 I0202 23:03:26.726521 6733 master.cpp:644] Authorization enabled
23:03:26 I0202 23:03:26.726989 6734 hierarchical.cpp:175] Initialized
hierarchical allocator process
23:03:26 I0202 23:03:26.727095 6732 whitelist_watcher.cpp:77] No whitelist
given
23:03:26 I0202 23:03:26.730202 6730 master.cpp:2133] Elected as the leading
master!
23:03:26 I0202 23:03:26.730232 6730 master.cpp:1692] Recovering from registrar
23:03:26 I0202 23:03:26.730422 6731 registrar.cpp:347] Recovering registrar
23:03:26 I0202 23:03:26.731240 6731 registrar.cpp:391] Successfully fetched
the registry (0B) in 619776ns
23:03:26 I0202 23:03:26.731371 6731 registrar.cpp:495] Applied 1 operations
in 49150ns; attempting to update the registry
23:03:26 I0202 23:03:26.731995 6731 registrar.cpp:552] Successfully updated
the registry in 578048ns
23:03:26 I0202 23:03:26.732132 6731 registrar.cpp:424] Successfully recovered
registrar
23:03:26 I0202 23:03:26.732560 6729 master.cpp:1806] Recovered 0 agents from
the registry (176B); allowing 10mins for agents to re-register
23:03:26 I0202 23:03:26.732638 6734 hierarchical.cpp:213] Skipping recovery
of hierarchical allocator: nothing to recover
23:03:26 W0202 23:03:26.736220 26266 process.cpp:2795] Attempted to spawn
already running process files@172.16.10.161:40613
23:03:26 I0202 23:03:26.737097 26266 containerizer.cpp:304] Using isolation {
environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni }
23:03:26 I0202 23:03:26.742087 26266 linux_launcher.cpp:146] Using
/sys/fs/cgroup/freezer as the freezer hierarchy for the Linux launcher
23:03:26 I0202 23:03:26.743149 26266 provisioner.cpp:299] Using default
backend 'overlay'
23:03:26 I0202 23:03:26.745007 26266 cluster.cpp:460] Creating default 'local'
authorizer
23:03:26 W0202 23:03:26.747300 26266 process.cpp:2795] Attempted to spawn
already running process version@172.16.10.161:40613
23:03:26 I0202 23:03:26.747448 6732 slave.cpp:262] Mesos agent started on
(1103)@172.16.10.161:40613
23:03:26 I0202 23:03:26.747563 6732 slave.cpp:263] Flags at startup:
--acls="" --appc_simple_discovery_uri_prefix="http://";
--appc_store_dir="/tmp/bool_MasterTestPrePostReservationRefinement_StateEndpointPendingTasks_0_JIHxj9/store/appc"
--authenticate_http_readonly="true" --authenticate_http_readwrite="false"
--authenticatee="crammd5" --authentication_backoff_factor="1secs"
--authorizer="local" --cgroups_cpu_enable_pids_and_tids_count="false"
--cgroups_enable_cfs="false" --cgroups_hierarchy="/sys/fs/cgroup"
--cgroups_limit_swap="false" --cgroups_root="mesos"
--container_disk_watch_interval="15secs" --containerizers="mesos"
--credential="/tmp/bool_MasterTestPrePostReservationRefinement_StateEndpointPendingTasks_0_JIHxj9/credential"
--default_role="*" --disallow_sharing_agent_pid_namespace="false"
--disk_watch_interval="1mins" --docker="docker" --docker_kill_orphans="true"
--docker_registry="https://registry-1.docker.io"; --docker_remove_delay="6hrs"
--docker_socket="/var/run/docker.sock" --docker_stop_timeout="0ns"
--docker_store_dir="/tmp/bool_MasterTestPrePostReservationRefinement_StateEndpointPendingTasks_0_JIHxj9/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/bool_MasterTestPrePostReservationRefinement_StateEndpointPendingTasks_0_JIHxj9/fetch"
--fetcher_cache_size="2GB" --frameworks_home="" --gc_delay="1weeks"
--gc_disk_headroom="0.1" --hadoop_home="" --help="false"
--hostname_lookup="true" --http_command_executor="false"
--http_credentials="/tmp/bool_MasterTestPrePostReservationRefinement_StateEndpointPendingTasks_0_JIHxj9/http_credentials"
--http_heartbeat_interval="30secs" --initialize_driver_logging="true"
--isolation="posix/cpu,posix/mem" --launcher="linux"
--launcher_dir="/home/ubuntu/workspace/mesos/Mesos_CI-build/FLAG/CMake/label/mesos-ec2-ubuntu-16.04/mesos/build/src"
--logbufsecs="0" --logging_level="INFO"
--max_completed_executors_per_framework="150"
--oversubscribed_resources_interval="15secs" --perf_duration="10secs"
--perf_interval="1mins" --port="5051" --qos_correction_interval_min="0ns"
--quiet="false" --reconfiguration_policy="equal" --recover="reconnect"
--recovery_timeout="15mins" --registration_backoff_factor="10ms"
--resources="cpus:2;gpus:0;mem:1024;disk:1024;ports:[31000-32000]"
--revocable_cpu_low_priority="true"
--runtime_dir="/tmp/bool_MasterTestPrePostReservationRefinement_StateEndpointPendingTasks_0_JIHxj9"
--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/bool_MasterTestPrePostReservationRefinement_StateEndpointPendingTasks_0_ZHkLaT"
--zk_session_timeout="10secs"
23:03:26 I0202 23:03:26.748066 6732 credentials.hpp:86] Loading credential
for authentication from
'/tmp/bool_MasterTestPrePostReservationRefinement_StateEndpointPendingTasks_0_JIHxj9/credential'
23:03:26 I0202 23:03:26.748420 6732 slave.cpp:295] Agent using credential
for: test-principal
23:03:26 I0202 23:03:26.748610 6732 credentials.hpp:37] Loading credentials
for authentication from
'/tmp/bool_MasterTestPrePostReservationRefinement_StateEndpointPendingTasks_0_JIHxj9/http_credentials'
23:03:26 I0202 23:03:26.748677 26266 sched.cpp:232] Version: 1.6.0
23:03:26 I0202 23:03:26.748957 6732 http.cpp:1045] Creating default 'basic'
HTTP authenticator for realm 'mesos-agent-readonly'
23:03:26 I0202 23:03:26.750955 6733 sched.cpp:336] New master detected at
master@172.16.10.161:40613
23:03:26 I0202 23:03:26.751215 6733 sched.cpp:396] Authenticating with master
master@172.16.10.161:40613
23:03:26 I0202 23:03:26.751368 6733 sched.cpp:403] Using default CRAM-MD5
authenticatee
23:03:26 I0202 23:03:26.750792 6732 slave.cpp:612] 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"}]
23:03:26 I0202 23:03:26.751910 6732 slave.cpp:620] Agent attributes: [ ]
23:03:26 I0202 23:03:26.751926 6732 slave.cpp:629] Agent hostname:
ip-172-16-10-161.ec2.internal
23:03:26 I0202 23:03:26.752007 6733 authenticatee.cpp:121] Creating new
client SASL connection
23:03:26 I0202 23:03:26.752274 6735 task_status_update_manager.cpp:181]
Pausing sending task status updates
23:03:26 I0202 23:03:26.752578 6729 master.cpp:8978] Authenticating
scheduler-6d45fb68-942a-4729-8a9b-1f8526ba598f@172.16.10.161:40613
23:03:26 I0202 23:03:26.752714 6734 authenticator.cpp:414] Starting
authentication session for crammd5-authenticatee(1854)@172.16.10.161:40613
23:03:26 I0202 23:03:26.753255 6734 authenticator.cpp:98] Creating new server
SASL connection
23:03:26 I0202 23:03:26.753751 6733 authenticatee.cpp:213] Received SASL
authentication mechanisms: CRAM-MD5
23:03:26 I0202 23:03:26.753917 6733 authenticatee.cpp:239] Attempting to
authenticate with mechanism 'CRAM-MD5'
23:03:26 I0202 23:03:26.754232 6734 authenticator.cpp:204] Received SASL
authentication start
23:03:26 I0202 23:03:26.754465 6734 authenticator.cpp:326] Authentication
requires more steps
23:03:26 I0202 23:03:26.754699 6734 authenticatee.cpp:259] Received SASL
authentication step
23:03:26 I0202 23:03:26.754964 6729 authenticator.cpp:232] Received SASL
authentication step
23:03:26 I0202 23:03:26.755002 6729 auxprop.cpp:109] Request to lookup
properties for user: 'test-principal' realm: 'ip-172-16-10-161.ec2.internal'
server FQDN: 'ip-172-16-10-161.ec2.internal' SASL_AUXPROP_VERIFY_AGAINST_HASH:
false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
23:03:26 I0202 23:03:26.755023 6729 auxprop.cpp:181] Looking up auxiliary
property '*userPassword'
23:03:26 I0202 23:03:26.755067 6729 auxprop.cpp:181] Looking up auxiliary
property '*cmusaslsecretCRAM-MD5'
23:03:26 I0202 23:03:26.755110 6729 auxprop.cpp:109] Request to lookup
properties for user: 'test-principal' realm: 'ip-172-16-10-161.ec2.internal'
server FQDN: 'ip-172-16-10-161.ec2.internal' SASL_AUXPROP_VERIFY_AGAINST_HASH:
false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
23:03:26 I0202 23:03:26.755127 6729 auxprop.cpp:131] Skipping auxiliary
property '*userPassword' since SASL_AUXPROP_AUTHZID == true
23:03:26 I0202 23:03:26.755134 6729 auxprop.cpp:131] Skipping auxiliary
property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
23:03:26 I0202 23:03:26.755148 6729 authenticator.cpp:318] Authentication
success
23:03:26 I0202 23:03:26.755328 6733 authenticatee.cpp:299] Authentication
success
23:03:26 I0202 23:03:26.755383 6729 master.cpp:9008] Successfully
authenticated principal 'test-principal' at
scheduler-6d45fb68-942a-4729-8a9b-1f8526ba598f@172.16.10.161:40613
23:03:26 I0202 23:03:26.755455 6735 authenticator.cpp:432] Authentication
session cleanup for crammd5-authenticatee(1854)@172.16.10.161:40613
23:03:26 I0202 23:03:26.755877 6733 sched.cpp:502] Successfully authenticated
with master master@172.16.10.161:40613
23:03:26 I0202 23:03:26.755899 6733 sched.cpp:824] Sending SUBSCRIBE call to
master@172.16.10.161:40613
23:03:26 I0202 23:03:26.756026 6733 sched.cpp:857] Will retry registration in
1.799480061secs if necessary
23:03:26 I0202 23:03:26.756294 6734 master.cpp:2869] Received SUBSCRIBE call
for framework 'default' at
scheduler-6d45fb68-942a-4729-8a9b-1f8526ba598f@172.16.10.161:40613
23:03:26 I0202 23:03:26.756516 6734 master.cpp:2198] Authorizing framework
principal 'test-principal' to receive offers for roles '{ default-role }'
23:03:26 I0202 23:03:26.756880 6734 master.cpp:2949] Subscribing framework
default with checkpointing disabled and capabilities [ MULTI_ROLE,
RESERVATION_REFINEMENT ]
23:03:26 I0202 23:03:26.757212 6734 master.cpp:9199] Adding framework
d107b5f2-a7b1-43e4-bc3e-c5d6a782f949-0000 (default) at
scheduler-6d45fb68-942a-4729-8a9b-1f8526ba598f@172.16.10.161:40613 with roles {
} suppressed
23:03:26 I0202 23:03:26.757549 6735 state.cpp:66] Recovering state from
'/tmp/bool_MasterTestPrePostReservationRefinement_StateEndpointPendingTasks_0_ZHkLaT/meta'
23:03:26 I0202 23:03:26.757979 6733 task_status_update_manager.cpp:207]
Recovering task status update manager
23:03:26 I0202 23:03:26.758175 6733 containerizer.cpp:674] Recovering
containerizer
23:03:26 I0202 23:03:26.758695 6732 hierarchical.cpp:297] Added framework
d107b5f2-a7b1-43e4-bc3e-c5d6a782f949-0000
23:03:26 I0202 23:03:26.758908 6732 hierarchical.cpp:1517] Performed
allocation for 0 agents in 62754ns
23:03:26 I0202 23:03:26.760069 6734 sched.cpp:751] Framework registered with
d107b5f2-a7b1-43e4-bc3e-c5d6a782f949-0000
23:03:26 I0202 23:03:26.760370 6734 sched.cpp:765] Scheduler::registered took
24678ns
23:03:26 I0202 23:03:26.760864 6732 provisioner.cpp:495] Provisioner recovery
complete
23:03:26 I0202 23:03:26.761168 6734 slave.cpp:6824] Finished recovery
23:03:26 I0202 23:03:26.761876 6730 task_status_update_manager.cpp:181]
Pausing sending task status updates
23:03:26 I0202 23:03:26.761879 6734 slave.cpp:1146] New master detected at
master@172.16.10.161:40613
23:03:26 I0202 23:03:26.762114 6734 slave.cpp:1201] Detecting new master
23:03:26 I0202 23:03:26.769500 6729 slave.cpp:1228] Authenticating with
master master@172.16.10.161:40613
23:03:26 I0202 23:03:26.769574 6729 slave.cpp:1237] Using default CRAM-MD5
authenticatee
23:03:26 I0202 23:03:26.769814 6732 authenticatee.cpp:121] Creating new
client SASL connection
23:03:26 I0202 23:03:26.770305 6731 master.cpp:8978] Authenticating
slave(1103)@172.16.10.161:40613
23:03:26 I0202 23:03:26.770478 6735 authenticator.cpp:414] Starting
authentication session for crammd5-authenticatee(1855)@172.16.10.161:40613
23:03:26 I0202 23:03:26.770710 6733 authenticator.cpp:98] Creating new server
SASL connection
23:03:26 I0202 23:03:26.771149 6730 authenticatee.cpp:213] Received SASL
authentication mechanisms: CRAM-MD5
23:03:26 I0202 23:03:26.771179 6730 authenticatee.cpp:239] Attempting to
authenticate with mechanism 'CRAM-MD5'
23:03:26 I0202 23:03:26.771276 6730 authenticator.cpp:204] Received SASL
authentication start
23:03:26 I0202 23:03:26.771319 6730 authenticator.cpp:326] Authentication
requires more steps
23:03:26 I0202 23:03:26.771414 6730 authenticatee.cpp:259] Received SASL
authentication step
23:03:26 I0202 23:03:26.771519 6730 authenticator.cpp:232] Received SASL
authentication step
23:03:26 I0202 23:03:26.771548 6730 auxprop.cpp:109] Request to lookup
properties for user: 'test-principal' realm: 'ip-172-16-10-161.ec2.internal'
server FQDN: 'ip-172-16-10-161.ec2.internal' SASL_AUXPROP_VERIFY_AGAINST_HASH:
false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
23:03:26 I0202 23:03:26.771559 6730 auxprop.cpp:181] Looking up auxiliary
property '*userPassword'
23:03:26 I0202 23:03:26.771589 6730 auxprop.cpp:181] Looking up auxiliary
property '*cmusaslsecretCRAM-MD5'
23:03:26 I0202 23:03:26.771616 6730 auxprop.cpp:109] Request to lookup
properties for user: 'test-principal' realm: 'ip-172-16-10-161.ec2.internal'
server FQDN: 'ip-172-16-10-161.ec2.internal' SASL_AUXPROP_VERIFY_AGAINST_HASH:
false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
23:03:26 I0202 23:03:26.771626 6730 auxprop.cpp:131] Skipping auxiliary
property '*userPassword' since SASL_AUXPROP_AUTHZID == true
23:03:26 I0202 23:03:26.771633 6730 auxprop.cpp:131] Skipping auxiliary
property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
23:03:26 I0202 23:03:26.771646 6730 authenticator.cpp:318] Authentication
success
23:03:26 I0202 23:03:26.771785 6732 authenticatee.cpp:299] Authentication
success
23:03:26 I0202 23:03:26.771821 6730 master.cpp:9008] Successfully
authenticated principal 'test-principal' at slave(1103)@172.16.10.161:40613
23:03:26 I0202 23:03:26.771872 6735 authenticator.cpp:432] Authentication
session cleanup for crammd5-authenticatee(1855)@172.16.10.161:40613
23:03:26 I0202 23:03:26.772351 6733 slave.cpp:1320] Successfully
authenticated with master master@172.16.10.161:40613
23:03:26 I0202 23:03:26.772650 6733 slave.cpp:1766] Will retry registration
in 2.501104ms if necessary
23:03:26 I0202 23:03:26.772873 6731 master.cpp:6013] Received register agent
message from slave(1103)@172.16.10.161:40613 (ip-172-16-10-161.ec2.internal)
23:03:26 I0202 23:03:26.773100 6731 master.cpp:3793] Authorizing agent
providing resources 'cpus:2; mem:1024; disk:1024; ports:[31000-32000]' with
principal 'test-principal'
23:03:26 I0202 23:03:26.773591 6736 master.cpp:6084] Authorized registration
of agent at slave(1103)@172.16.10.161:40613 (ip-172-16-10-161.ec2.internal)
23:03:26 I0202 23:03:26.773699 6736 master.cpp:6195] Registering agent at
slave(1103)@172.16.10.161:40613 (ip-172-16-10-161.ec2.internal) with id
d107b5f2-a7b1-43e4-bc3e-c5d6a782f949-S0
23:03:26 I0202 23:03:26.774212 6735 registrar.cpp:495] Applied 1 operations
in 144531ns; attempting to update the registry
23:03:26 I0202 23:03:26.774802 6735 registrar.cpp:552] Successfully updated
the registry in 536064ns
23:03:26 I0202 23:03:26.774993 6734 master.cpp:6243] Admitted agent
d107b5f2-a7b1-43e4-bc3e-c5d6a782f949-S0 at slave(1103)@172.16.10.161:40613
(ip-172-16-10-161.ec2.internal)
23:03:26 I0202 23:03:26.775849 6729 hierarchical.cpp:574] Added agent
d107b5f2-a7b1-43e4-bc3e-c5d6a782f949-S0 (ip-172-16-10-161.ec2.internal) with
cpus:2; mem:1024; disk:1024; ports:[31000-32000] (allocated: {})
23:03:26 I0202 23:03:26.776824 6729 hierarchical.cpp:1517] Performed
allocation for 1 agents in 805552ns
23:03:26 I0202 23:03:26.777098 6729 slave.cpp:1766] Will retry registration
in 31.277744ms if necessary
23:03:26 I0202 23:03:26.777317 6734 master.cpp:6292] Registered agent
d107b5f2-a7b1-43e4-bc3e-c5d6a782f949-S0 at slave(1103)@172.16.10.161:40613
(ip-172-16-10-161.ec2.internal) with cpus:2; mem:1024; disk:1024;
ports:[31000-32000]
23:03:26 I0202 23:03:26.777429 6735 slave.cpp:1367] Registered with master
master@172.16.10.161:40613; given agent ID
d107b5f2-a7b1-43e4-bc3e-c5d6a782f949-S0
23:03:26 I0202 23:03:26.777777 6735 slave.cpp:1387] Checkpointing SlaveInfo
to
'/tmp/bool_MasterTestPrePostReservationRefinement_StateEndpointPendingTasks_0_ZHkLaT/meta/slaves/d107b5f2-a7b1-43e4-bc3e-c5d6a782f949-S0/slave.info'
23:03:26 I0202 23:03:26.777977 6734 master.cpp:8808] Sending 1 offers to
framework d107b5f2-a7b1-43e4-bc3e-c5d6a782f949-0000 (default) at
scheduler-6d45fb68-942a-4729-8a9b-1f8526ba598f@172.16.10.161:40613
23:03:26 I0202 23:03:26.778116 6730 task_status_update_manager.cpp:188]
Resuming sending task status updates
23:03:26 I0202 23:03:26.778604 6730 sched.cpp:921] Scheduler::resourceOffers
took 119195ns
23:03:26 I0202 23:03:26.778867 6734 master.cpp:6013] Received register agent
message from slave(1103)@172.16.10.161:40613 (ip-172-16-10-161.ec2.internal)
23:03:26 I0202 23:03:26.778611 6735 slave.cpp:1434] Forwarding agent update
{"operations":{},"resource_version_uuid":{"value":"wYfv18OwTQi56nm7gH0ong=="},"slave_id":{"value":"d107b5f2-a7b1-43e4-bc3e-c5d6a782f949-S0"},"update_oversubscribed_resources":true}
23:03:26 I0202 23:03:26.779146 6734 master.cpp:3793] Authorizing agent
providing resources 'cpus:2; mem:1024; disk:1024; ports:[31000-32000]' with
principal 'test-principal'
23:03:26 I0202 23:03:26.781471 6734 master.cpp:7235] Received update of agent
d107b5f2-a7b1-43e4-bc3e-c5d6a782f949-S0 at slave(1103)@172.16.10.161:40613
(ip-172-16-10-161.ec2.internal) with total oversubscribed resources {}
23:03:26 I0202 23:03:26.781878 6734 master.cpp:7329] Ignoring update on agent
d107b5f2-a7b1-43e4-bc3e-c5d6a782f949-S0 at slave(1103)@172.16.10.161:40613
(ip-172-16-10-161.ec2.internal) as it reports no changes
23:03:26 I0202 23:03:26.784138 6734 master.cpp:10716] Removing offer
d107b5f2-a7b1-43e4-bc3e-c5d6a782f949-O0
23:03:26 I0202 23:03:26.784728 6734 master.cpp:4220] Processing ACCEPT call
for offers: [ d107b5f2-a7b1-43e4-bc3e-c5d6a782f949-O0 ] on agent
d107b5f2-a7b1-43e4-bc3e-c5d6a782f949-S0 at slave(1103)@172.16.10.161:40613
(ip-172-16-10-161.ec2.internal) for framework
d107b5f2-a7b1-43e4-bc3e-c5d6a782f949-0000 (default) at
scheduler-6d45fb68-942a-4729-8a9b-1f8526ba598f@172.16.10.161:40613
23:03:26 I0202 23:03:26.784871 6734 master.cpp:3505] Authorizing framework
principal 'test-principal' to launch task 1
23:03:26
/home/ubuntu/workspace/mesos/Mesos_CI-build/FLAG/CMake/label/mesos-ec2-ubuntu-16.04/mesos/src/tests/master_tests.cpp:9273:
Failure
23:03:26 Mock function called more times than expected - returning default
value.
23:03:26 Function call: authorized(@0x7fd48fe511c0 48-byte object <F8-FF
F3-9C D4-7F 00-00 00-00 00-00 00-00 00-00 07-00 00-00 00-00 00-00 E0-79 05-6C
D4-7F 00-00 00-63 02-6C D4-7F 00-00 02-00 00-00 D4-7F 00-00>)
23:03:26 Returns: Abandoned
23:03:26 Expected: to be called once
23:03:26 Actual: called twice - over-saturated and active
23:03:26 I0202 23:03:26.785715 6734 process.cpp:3554] Handling HTTP event for
process 'master' with path: '/master/state'
23:03:26 I0202 23:03:26.787667 6733 http.cpp:1185] HTTP GET for /master/state
from 172.16.10.161:34134
23:03:26 I0202 23:03:26.793382 26266 sched.cpp:2009] Asked to stop the driver
23:03:26 I0202 23:03:26.793581 6734 sched.cpp:1191] Stopping framework
d107b5f2-a7b1-43e4-bc3e-c5d6a782f949-0000
23:03:26 I0202 23:03:26.794227 6730 master.cpp:9488] Processing TEARDOWN call
for framework d107b5f2-a7b1-43e4-bc3e-c5d6a782f949-0000 (default) at
scheduler-6d45fb68-942a-4729-8a9b-1f8526ba598f@172.16.10.161:40613
23:03:26 I0202 23:03:26.794417 6730 master.cpp:9500] Removing framework
d107b5f2-a7b1-43e4-bc3e-c5d6a782f949-0000 (default) at
scheduler-6d45fb68-942a-4729-8a9b-1f8526ba598f@172.16.10.161:40613
23:03:26 I0202 23:03:26.794451 6730 master.cpp:3239] Deactivating framework
d107b5f2-a7b1-43e4-bc3e-c5d6a782f949-0000 (default) at
scheduler-6d45fb68-942a-4729-8a9b-1f8526ba598f@172.16.10.161:40613
23:03:26 I0202 23:03:26.794642 6735 hierarchical.cpp:405] Deactivated
framework d107b5f2-a7b1-43e4-bc3e-c5d6a782f949-0000
23:03:26 I0202 23:03:26.794895 6735 slave.cpp:3454] Asked to shut down
framework d107b5f2-a7b1-43e4-bc3e-c5d6a782f949-0000 by
master@172.16.10.161:40613
23:03:26 I0202 23:03:26.795086 6735 slave.cpp:3469] Cannot shut down unknown
framework d107b5f2-a7b1-43e4-bc3e-c5d6a782f949-0000
23:03:26 I0202 23:03:26.795987 6730 hierarchical.cpp:344] Removed framework
d107b5f2-a7b1-43e4-bc3e-c5d6a782f949-0000
23:03:26 I0202 23:03:26.798878 26266 slave.cpp:931] Agent terminating
23:03:26 I0202 23:03:26.799244 6731 master.cpp:1307] Agent
d107b5f2-a7b1-43e4-bc3e-c5d6a782f949-S0 at slave(1103)@172.16.10.161:40613
(ip-172-16-10-161.ec2.internal) disconnected
23:03:26 I0202 23:03:26.799278 6731 master.cpp:3276] Disconnecting agent
d107b5f2-a7b1-43e4-bc3e-c5d6a782f949-S0 at slave(1103)@172.16.10.161:40613
(ip-172-16-10-161.ec2.internal)
23:03:26 I0202 23:03:26.799329 6731 master.cpp:3295] Deactivating agent
d107b5f2-a7b1-43e4-bc3e-c5d6a782f949-S0 at slave(1103)@172.16.10.161:40613
(ip-172-16-10-161.ec2.internal)
23:03:26 I0202 23:03:26.799549 6731 hierarchical.cpp:766] Agent
d107b5f2-a7b1-43e4-bc3e-c5d6a782f949-S0 deactivated
23:03:26 I0202 23:03:26.807224 26266 master.cpp:1149] Master terminating
23:03:26 I0202 23:03:26.808149 6736 hierarchical.cpp:609] Removed agent
d107b5f2-a7b1-43e4-bc3e-c5d6a782f949-S0
23:03:26 [ FAILED ]
bool/MasterTestPrePostReservationRefinement.StateEndpointPendingTasks/0, where
GetParam() = true (90 ms)
{noformat}
--
This message was sent by Atlassian JIRA
(v7.6.3#76005)
