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)