[
https://issues.apache.org/jira/browse/MESOS-9664?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16958877#comment-16958877
]
Andrei Sekretenko commented on MESOS-9664:
------------------------------------------
Observed a similar failure in internal CI,
{noformat}
[ RUN ] UpgradeTest.RefineResourceOnOldAgent
I1023 19:44:37.580667 21878 cluster.cpp:177] Creating default 'local' authorizer
I1023 19:44:37.581563 21879 master.cpp:440] Master
518ae562-76f1-47ed-8f1d-ba0ec7d63321 (localhost) started on 127.0.0.1:45481
I1023 19:44:37.582000 21879 master.cpp:443] Flags at startup: --acls=""
--agent_ping_timeout="15secs" --agent_reregister_timeout="10mins"
--allocation_interval="1secs" --allocator="hierarchical"
--authenticate_agents="true" --authenticate_frameworks="true"
--authenticate_http_frameworks="true" --authenticate_http_readonly="true"
--authenticate_http_readwrite="true" --authentication_v0_timeout="15secs"
--authenticators="crammd5" --authorizers="local"
--credentials="/tmp/vl9OmD/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/vl9OmD/master" --zk_session_timeout="10secs"
W1023 19:44:37.582558 21879 master.cpp:446]
**************************************************
Master bound to loopback interface! Cannot communicate with remote schedulers
or agents. You might want to set '--ip' flag to a routable IP address.
**************************************************
I1023 19:44:37.582979 21879 master.cpp:492] Master only allowing authenticated
frameworks to register
I1023 19:44:37.583384 21879 master.cpp:498] Master only allowing authenticated
agents to register
I1023 19:44:37.583793 21879 master.cpp:504] Master only allowing authenticated
HTTP frameworks to register
I1023 19:44:37.584199 21879 credentials.hpp:37] Loading credentials for
authentication from '/tmp/vl9OmD/credentials'
I1023 19:44:37.584667 21879 master.cpp:548] Using default 'crammd5'
authenticator
I1023 19:44:37.585119 21879 http.cpp:975] Creating default 'basic' HTTP
authenticator for realm 'mesos-master-readonly'
I1023 19:44:37.585587 21879 http.cpp:975] Creating default 'basic' HTTP
authenticator for realm 'mesos-master-readwrite'
I1023 19:44:37.586028 21879 http.cpp:975] Creating default 'basic' HTTP
authenticator for realm 'mesos-master-scheduler'
I1023 19:44:37.586475 21879 master.cpp:629] Authorization enabled
I1023 19:44:37.586985 21884 hierarchical.cpp:567] Initialized hierarchical
allocator process
I1023 19:44:37.587249 21881 whitelist_watcher.cpp:77] No whitelist given
I1023 19:44:37.588035 21879 master.cpp:2169] Elected as the leading master!
I1023 19:44:37.588485 21879 master.cpp:1665] Recovering from registrar
I1023 19:44:37.588963 21885 registrar.cpp:339] Recovering registrar
I1023 19:44:37.589098 21885 registrar.cpp:383] Successfully fetched the
registry (0B) in 0ns
I1023 19:44:37.589125 21885 registrar.cpp:487] Applied 1 operations in 6092ns;
attempting to update the registry
I1023 19:44:37.589236 21885 registrar.cpp:544] Successfully updated the
registry in 0ns
I1023 19:44:37.589264 21885 registrar.cpp:416] Successfully recovered registrar
I1023 19:44:37.589336 21885 master.cpp:1818] Recovered 0 agents from the
registry (136B); allowing 10mins for agents to reregister
I1023 19:44:37.589368 21885 hierarchical.cpp:606] Skipping recovery of
hierarchical allocator: nothing to recover
W1023 19:44:37.590909 21878 process.cpp:2877] Attempted to spawn already
running process files@127.0.0.1:45481
I1023 19:44:37.591393 21878 containerizer.cpp:318] Using isolation {
environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni }
I1023 19:44:37.593200 21878 linux_launcher.cpp:144] Using
/sys/fs/cgroup/freezer as the freezer hierarchy for the Linux launcher
I1023 19:44:37.593719 21878 provisioner.cpp:294] Using default backend 'overlay'
I1023 19:44:37.594841 21878 cluster.cpp:524] Creating default 'local' authorizer
I1023 19:44:37.595507 21880 slave.cpp:267] Mesos agent started on
(752)@127.0.0.1:45481
I1023 19:44:37.595523 21886 hierarchical.cpp:1843] Performed allocation for 0
agents in 5853ns
I1023 19:44:37.595525 21880 slave.cpp:268] Flags at startup: --acls=""
--appc_simple_discovery_uri_prefix="http://";
--appc_store_dir="/tmp/vl9OmD/4mnSBl/store/appc"
--authenticate_http_executors="true" --authenticate_http_readonly="true"
--authenticate_http_readwrite="true" --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/vl9OmD/4mnSBl/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/vl9OmD/4mnSBl/store/docker"
--docker_volume_checkpoint_dir="/var/run/mesos/isolators/docker/volume"
--docker_volume_chown="false" --enforce_container_disk_quota="false"
--executor_registration_timeout="1mins"
--executor_reregistration_timeout="2secs"
--executor_shutdown_grace_period="5secs"
--fetcher_cache_dir="/tmp/vl9OmD/4mnSBl/fetch" --fetcher_cache_size="2GB"
--fetcher_stall_timeout="1mins"
--frameworks_home="/tmp/vl9OmD/4mnSBl/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/vl9OmD/4mnSBl/http_credentials"
--http_heartbeat_interval="30secs" --initialize_driver_logging="true"
--isolation="posix/cpu,posix/mem"
--jwt_secret_key="/tmp/vl9OmD/4mnSBl/jwt_secret_key" --launcher="linux"
--launcher_dir="/home/admin/workspace/mesos/Mesos_CI-build/FLAG/SSL/label/mesos-ec2-debian-9/mesos/build/src"
--logbufsecs="0" --logging_level="INFO"
--max_completed_executors_per_framework="150" --memory_profiling="false"
--network_cni_metrics="true" --network_cni_root_dir_persist="false"
--oversubscribed_resources_interval="15secs" --perf_duration="10secs"
--perf_interval="1mins" --port="5051" --qos_correction_interval_min="0ns"
--quiet="false" --reconfiguration_policy="equal" --recover="reconnect"
--recovery_timeout="15mins" --registration_backoff_factor="10ms"
--resources="cpus:1;mem:512;disk(role1):1024"
--revocable_cpu_low_priority="true"
--runtime_dir="/tmp/UpgradeTest_RefineResourceOnOldAgent_XBKbcM"
--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/UpgradeTest_RefineResourceOnOldAgent_9PcvMc"
--zk_session_timeout="10secs"
W1023 19:44:37.595721 21880 slave.cpp:271]
**************************************************
Agent bound to loopback interface! Cannot communicate with remote master(s).
You might want to set '--ip' flag to a routable IP address.
**************************************************
I1023 19:44:37.595731 21880 credentials.hpp:86] Loading credential for
authentication from '/tmp/vl9OmD/4mnSBl/credential'
I1023 19:44:37.595777 21880 slave.cpp:300] Agent using credential for:
test-principal
I1023 19:44:37.595788 21880 credentials.hpp:37] Loading credentials for
authentication from '/tmp/vl9OmD/4mnSBl/http_credentials'
I1023 19:44:37.595852 21880 http.cpp:975] Creating default 'basic' HTTP
authenticator for realm 'mesos-agent-executor'
I1023 19:44:37.595886 21880 http.cpp:996] Creating default 'jwt' HTTP
authenticator for realm 'mesos-agent-executor'
I1023 19:44:37.595930 21880 http.cpp:975] Creating default 'basic' HTTP
authenticator for realm 'mesos-agent-readonly'
I1023 19:44:37.595952 21880 http.cpp:996] Creating default 'jwt' HTTP
authenticator for realm 'mesos-agent-readonly'
I1023 19:44:37.595979 21880 http.cpp:975] Creating default 'basic' HTTP
authenticator for realm 'mesos-agent-readwrite'
I1023 19:44:37.595996 21880 http.cpp:996] Creating default 'jwt' HTTP
authenticator for realm 'mesos-agent-readwrite'
I1023 19:44:37.596053 21880 disk_profile_adaptor.cpp:78] Creating default disk
profile adaptor module
I1023 19:44:37.596251 21880 slave.cpp:615] Agent resources:
[{"name":"cpus","scalar":{"value":1.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":512.0},"type":"SCALAR"},{"name":"disk","reservations":[{"role":"role1","type":"STATIC"}],"scalar":{"value":1024.0},"type":"SCALAR"},{"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}]
I1023 19:44:37.596323 21880 slave.cpp:623] Agent attributes: [ ]
I1023 19:44:37.596330 21880 slave.cpp:632] Agent hostname: localhost
I1023 19:44:37.596578 21880 task_status_update_manager.cpp:181] Pausing sending
task status updates
I1023 19:44:37.596601 21880 status_update_manager_process.hpp:379] Pausing
operation status update manager
I1023 19:44:37.596745 21880 state.cpp:67] Recovering state from
'/tmp/UpgradeTest_RefineResourceOnOldAgent_9PcvMc/meta'
I1023 19:44:37.596796 21880 slave.cpp:7492] Finished recovering checkpointed
state from '/tmp/UpgradeTest_RefineResourceOnOldAgent_9PcvMc/meta', beginning
agent recovery
I1023 19:44:37.596859 21880 task_status_update_manager.cpp:207] Recovering task
status update manager
I1023 19:44:37.596935 21880 containerizer.cpp:821] Recovering Mesos containers
I1023 19:44:37.596988 21880 linux_launcher.cpp:286] Recovering Linux launcher
I1023 19:44:37.597116 21880 containerizer.cpp:1161] Recovering isolators
I1023 19:44:37.597363 21880 containerizer.cpp:1200] Recovering provisioner
I1023 19:44:37.597470 21880 provisioner.cpp:518] Provisioner recovery complete
I1023 19:44:37.597620 21880 composing.cpp:339] Finished recovering all
containerizers
I1023 19:44:37.597681 21880 slave.cpp:7974] Recovering executors
I1023 19:44:37.597707 21880 slave.cpp:8127] Finished recovery
I1023 19:44:37.598007 21880 slave.cpp:1351] New master detected at
master@127.0.0.1:45481
I1023 19:44:37.598057 21883 task_status_update_manager.cpp:181] Pausing sending
task status updates
I1023 19:44:37.598073 21883 status_update_manager_process.hpp:379] Pausing
operation status update manager
I1023 19:44:37.598127 21880 slave.cpp:1416] Detecting new master
I1023 19:44:37.598173 21880 slave.cpp:1443] Authenticating with master
master@127.0.0.1:45481
I1023 19:44:37.598189 21880 slave.cpp:1452] Using default CRAM-MD5 authenticatee
I1023 19:44:37.598299 21882 authenticatee.cpp:121] Creating new client SASL
connection
I1023 19:44:37.598387 21882 master.cpp:10594] Authenticating
slave(752)@127.0.0.1:45481
I1023 19:44:37.598425 21882 authenticator.cpp:414] Starting authentication
session for crammd5-authenticatee(1447)@127.0.0.1:45481
I1023 19:44:37.598471 21882 authenticator.cpp:98] Creating new server SASL
connection
I1023 19:44:37.598563 21882 authenticatee.cpp:213] Received SASL authentication
mechanisms: CRAM-MD5
I1023 19:44:37.598577 21882 authenticatee.cpp:239] Attempting to authenticate
with mechanism 'CRAM-MD5'
I1023 19:44:37.598608 21882 authenticator.cpp:204] Received SASL authentication
start
I1023 19:44:37.598632 21882 authenticator.cpp:326] Authentication requires more
steps
I1023 19:44:37.598662 21882 authenticatee.cpp:259] Received SASL authentication
step
I1023 19:44:37.598698 21882 authenticator.cpp:232] Received SASL authentication
step
I1023 19:44:37.598711 21882 auxprop.cpp:109] Request to lookup properties for
user: 'test-principal' realm: 'ip-172-16-10-241' server FQDN:
'ip-172-16-10-241' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
I1023 19:44:37.598719 21882 auxprop.cpp:181] Looking up auxiliary property
'*userPassword'
I1023 19:44:37.598728 21882 auxprop.cpp:181] Looking up auxiliary property
'*cmusaslsecretCRAM-MD5'
I1023 19:44:37.598737 21882 auxprop.cpp:109] Request to lookup properties for
user: 'test-principal' realm: 'ip-172-16-10-241' server FQDN:
'ip-172-16-10-241' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
I1023 19:44:37.598742 21882 auxprop.cpp:131] Skipping auxiliary property
'*userPassword' since SASL_AUXPROP_AUTHZID == true
I1023 19:44:37.598748 21882 auxprop.cpp:131] Skipping auxiliary property
'*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I1023 19:44:37.598759 21882 authenticator.cpp:318] Authentication success
I1023 19:44:37.598794 21882 authenticatee.cpp:299] Authentication success
I1023 19:44:37.598814 21882 master.cpp:10626] Successfully authenticated
principal 'test-principal' at slave(752)@127.0.0.1:45481
I1023 19:44:37.598834 21882 authenticator.cpp:432] Authentication session
cleanup for crammd5-authenticatee(1447)@127.0.0.1:45481
I1023 19:44:37.602619 21880 slave.cpp:1543] Successfully authenticated with
master master@127.0.0.1:45481
I1023 19:44:37.602864 21880 slave.cpp:1993] Will retry registration in
3.728839ms if necessary
I1023 19:44:37.603018 21879 slave.cpp:1993] Will retry registration in
19.88139ms if necessary
I1023 19:44:37.603073 21879 master.cpp:7083] Received register agent message
from slave(752)@127.0.0.1:45481 (localhost)
I1023 19:44:37.603133 21879 master.cpp:4189] Authorizing agent providing
resources 'cpus:1; mem:512; disk(reservations: [(STATIC,role1)]):1024;
ports:[31000-32000]' with principal 'test-principal'
I1023 19:44:37.603185 21879 master.cpp:3811] Authorizing principal
'test-principal' to reserve resources 'cpus:1; mem:512; disk(reservations:
[(STATIC,role1)]):1024; ports:[31000-32000]'
I1023 19:44:37.603370 21879 master.cpp:7150] Authorized registration of agent
at slave(752)@127.0.0.1:45481 (localhost)
I1023 19:44:37.603399 21879 master.cpp:7262] Registering agent at
slave(752)@127.0.0.1:45481 (localhost) with id
518ae562-76f1-47ed-8f1d-ba0ec7d63321-S0
I1023 19:44:37.603497 21879 registrar.cpp:487] Applied 1 operations in 33954ns;
attempting to update the registry
I1023 19:44:37.603600 21879 registrar.cpp:544] Successfully updated the
registry in 0ns
I1023 19:44:37.603646 21879 master.cpp:7310] Admitted agent
518ae562-76f1-47ed-8f1d-ba0ec7d63321-S0 at slave(752)@127.0.0.1:45481
(localhost)
I1023 19:44:37.603749 21879 master.cpp:7355] Registered agent
518ae562-76f1-47ed-8f1d-ba0ec7d63321-S0 at slave(752)@127.0.0.1:45481
(localhost) with cpus:1; mem:512; disk(reservations: [(STATIC,role1)]):1024;
ports:[31000-32000]
I1023 19:44:37.603874 21879 hierarchical.cpp:955] Added agent
518ae562-76f1-47ed-8f1d-ba0ec7d63321-S0 (localhost) with cpus:1; mem:512;
disk(reservations: [(STATIC,role1)]):1024; ports:[31000-32000] (offered or
allocated: {})
I1023 19:44:37.603933 21879 hierarchical.cpp:1843] Performed allocation for 1
agents in 12604ns
I1023 19:44:37.603982 21879 slave.cpp:1576] Registered with master
master@127.0.0.1:45481; given agent ID 518ae562-76f1-47ed-8f1d-ba0ec7d63321-S0
I1023 19:44:37.604141 21879 slave.cpp:1611] Checkpointing SlaveInfo to
'/tmp/UpgradeTest_RefineResourceOnOldAgent_9PcvMc/meta/slaves/518ae562-76f1-47ed-8f1d-ba0ec7d63321-S0/slave.info'
I1023 19:44:37.604405 21879 slave.cpp:1663] Forwarding agent update
{"operations":{},"resource_providers":{},"resource_version_uuid":{"value":"eQgMdDLpT/CBW9PvHJIqpw=="},"slave_id":{"value":"518ae562-76f1-47ed-8f1d-ba0ec7d63321-S0"},"update_oversubscribed_resources":false}
I1023 19:44:37.604508 21879 task_status_update_manager.cpp:188] Resuming
sending task status updates
I1023 19:44:37.604529 21879 status_update_manager_process.hpp:385] Resuming
operation status update manager
I1023 19:44:37.604858 21884 master.cpp:8474] Ignoring update on agent
518ae562-76f1-47ed-8f1d-ba0ec7d63321-S0 at slave(752)@127.0.0.1:45481
(localhost) as it reports no changes
I1023 19:44:37.618376 21886 master.cpp:7083] Received register agent message
from slave(752)@127.0.0.1:45481 (localhost)
I1023 19:44:37.618458 21886 master.cpp:4189] Authorizing agent providing
resources 'cpus:1; mem:512; disk(reservations: [(STATIC,role1)]):1024;
ports:[31000-32000]' with principal 'test-principal'
I1023 19:44:37.618515 21886 master.cpp:3811] Authorizing principal
'test-principal' to reserve resources 'cpus:1; mem:512; disk(reservations:
[(STATIC,role1)]):1024; ports:[31000-32000]'
I1023 19:44:37.618733 21886 master.cpp:7150] Authorized registration of agent
at slave(752)@127.0.0.1:45481 (localhost)
I1023 19:44:37.618759 21886 master.cpp:7241] Agent
518ae562-76f1-47ed-8f1d-ba0ec7d63321-S0 at slave(752)@127.0.0.1:45481
(localhost) already registered, resending acknowledgement
W1023 19:44:37.618805 21886 slave.cpp:1645] Already registered with master
master@127.0.0.1:45481
I1023 19:44:37.618832 21886 slave.cpp:1663] Forwarding agent update
{"operations":{},"resource_providers":{},"resource_version_uuid":{"value":"eQgMdDLpT/CBW9PvHJIqpw=="},"slave_id":{"value":"518ae562-76f1-47ed-8f1d-ba0ec7d63321-S0"},"update_oversubscribed_resources":false}
I1023 19:44:37.618937 21886 master.cpp:8474] Ignoring update on agent
518ae562-76f1-47ed-8f1d-ba0ec7d63321-S0 at slave(752)@127.0.0.1:45481
(localhost) as it reports no changes
W1023 19:44:37.619212 21878 sched.cpp:1849]
**************************************************
Scheduler driver bound to loopback interface! Cannot communicate with remote
master(s). You might want to set 'LIBPROCESS_IP' environment variable to use a
routable IP address.
**************************************************
W1023 19:44:37.619249 21878 process.cpp:2877] Attempted to spawn already
running process version@127.0.0.1:45481
I1023 19:44:37.619644 21878 sched.cpp:239] Version: 1.10.0
I1023 19:44:37.619735 21881 sched.cpp:343] New master detected at
master@127.0.0.1:45481
I1023 19:44:37.619763 21881 sched.cpp:408] Authenticating with master
master@127.0.0.1:45481
I1023 19:44:37.619771 21881 sched.cpp:415] Using default CRAM-MD5 authenticatee
I1023 19:44:37.619844 21881 authenticatee.cpp:121] Creating new client SASL
connection
I1023 19:44:37.619937 21881 master.cpp:10594] Authenticating
scheduler-2e279a9b-04a2-4551-bcb1-fe72790bf487@127.0.0.1:45481
I1023 19:44:37.619967 21881 authenticator.cpp:414] Starting authentication
session for crammd5-authenticatee(1448)@127.0.0.1:45481
I1023 19:44:37.620012 21881 authenticator.cpp:98] Creating new server SASL
connection
I1023 19:44:37.620074 21881 authenticatee.cpp:213] Received SASL authentication
mechanisms: CRAM-MD5
I1023 19:44:37.620084 21881 authenticatee.cpp:239] Attempting to authenticate
with mechanism 'CRAM-MD5'
I1023 19:44:37.620103 21881 authenticator.cpp:204] Received SASL authentication
start
I1023 19:44:37.620126 21881 authenticator.cpp:326] Authentication requires more
steps
I1023 19:44:37.620146 21881 authenticatee.cpp:259] Received SASL authentication
step
I1023 19:44:37.620172 21881 authenticator.cpp:232] Received SASL authentication
step
I1023 19:44:37.620184 21881 auxprop.cpp:109] Request to lookup properties for
user: 'test-principal' realm: 'ip-172-16-10-241' server FQDN:
'ip-172-16-10-241' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
I1023 19:44:37.620190 21881 auxprop.cpp:181] Looking up auxiliary property
'*userPassword'
I1023 19:44:37.620198 21881 auxprop.cpp:181] Looking up auxiliary property
'*cmusaslsecretCRAM-MD5'
I1023 19:44:37.620205 21881 auxprop.cpp:109] Request to lookup properties for
user: 'test-principal' realm: 'ip-172-16-10-241' server FQDN:
'ip-172-16-10-241' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
I1023 19:44:37.620211 21881 auxprop.cpp:131] Skipping auxiliary property
'*userPassword' since SASL_AUXPROP_AUTHZID == true
I1023 19:44:37.620216 21881 auxprop.cpp:131] Skipping auxiliary property
'*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
I1023 19:44:37.620226 21881 authenticator.cpp:318] Authentication success
I1023 19:44:37.620252 21881 authenticatee.cpp:299] Authentication success
I1023 19:44:37.620281 21881 master.cpp:10626] Successfully authenticated
principal 'test-principal' at
scheduler-2e279a9b-04a2-4551-bcb1-fe72790bf487@127.0.0.1:45481
I1023 19:44:37.620298 21881 authenticator.cpp:432] Authentication session
cleanup for crammd5-authenticatee(1448)@127.0.0.1:45481
I1023 19:44:37.620343 21881 sched.cpp:520] Successfully authenticated with
master master@127.0.0.1:45481
I1023 19:44:37.620350 21881 sched.cpp:835] Sending SUBSCRIBE call to
master@127.0.0.1:45481
I1023 19:44:37.620380 21881 sched.cpp:870] Will retry registration in
1.367222533secs if necessary
I1023 19:44:37.620456 21881 master.cpp:2909] Received SUBSCRIBE call for
framework 'default' at
scheduler-2e279a9b-04a2-4551-bcb1-fe72790bf487@127.0.0.1:45481
I1023 19:44:37.620470 21881 master.cpp:2241] Authorizing framework principal
'test-principal' to receive offers for roles '{ role1/xyz }'
I1023 19:44:37.620540 21881 master.cpp:2996] Subscribing framework default with
checkpointing disabled and capabilities [ MULTI_ROLE, RESERVATION_REFINEMENT ]
I1023 19:44:37.620820 21881 master.cpp:10824] Adding framework
518ae562-76f1-47ed-8f1d-ba0ec7d63321-0000 (default) at
scheduler-2e279a9b-04a2-4551-bcb1-fe72790bf487@127.0.0.1:45481 with roles { }
suppressed
I1023 19:44:37.621371 21881 hierarchical.cpp:700] Added framework
518ae562-76f1-47ed-8f1d-ba0ec7d63321-0000
I1023 19:44:37.621497 21881 hierarchical.cpp:1843] Performed allocation for 1
agents in 96442ns
I1023 19:44:37.621539 21881 sched.cpp:751] Framework registered with
518ae562-76f1-47ed-8f1d-ba0ec7d63321-0000
I1023 19:44:37.621557 21881 sched.cpp:770] Scheduler::registered took 9287ns
I1023 19:44:37.621675 21881 master.cpp:10409] Sending offers [
518ae562-76f1-47ed-8f1d-ba0ec7d63321-O0 ] to framework
518ae562-76f1-47ed-8f1d-ba0ec7d63321-0000 (default) at
scheduler-2e279a9b-04a2-4551-bcb1-fe72790bf487@127.0.0.1:45481
I1023 19:44:37.621790 21881 sched.cpp:934] Scheduler::resourceOffers took
17186ns
I1023 19:44:37.622261 21883 master.cpp:4719] Processing ACCEPT call for offers:
[ 518ae562-76f1-47ed-8f1d-ba0ec7d63321-O0 ] on agent
518ae562-76f1-47ed-8f1d-ba0ec7d63321-S0 at slave(752)@127.0.0.1:45481
(localhost) for framework 518ae562-76f1-47ed-8f1d-ba0ec7d63321-0000 (default)
at scheduler-2e279a9b-04a2-4551-bcb1-fe72790bf487@127.0.0.1:45481
I1023 19:44:37.622313 21883 master.cpp:3811] Authorizing principal
'test-principal' to reserve resources 'disk(allocated: role1/xyz)(reservations:
[(STATIC,role1),(DYNAMIC,role1/xyz,test-principal)]):1024'
I1023 19:44:37.622547 21883 master.cpp:12706] Removing offer
518ae562-76f1-47ed-8f1d-ba0ec7d63321-O0
I1023 19:44:37.622620 21883 master.cpp:5109] Applying RESERVE operation for
resources
[{"allocation_info":{"role":"role1/xyz"},"name":"disk","reservations":[{"role":"role1","type":"STATIC"},{"principal":"test-principal","role":"role1/xyz","type":"DYNAMIC"}],"scalar":{"value":1024.0},"type":"SCALAR"}]
from framework 518ae562-76f1-47ed-8f1d-ba0ec7d63321-0000 (default) at
scheduler-2e279a9b-04a2-4551-bcb1-fe72790bf487@127.0.0.1:45481 to agent
518ae562-76f1-47ed-8f1d-ba0ec7d63321-S0 at slave(752)@127.0.0.1:45481
(localhost)
I1023 19:44:37.622733 21883 master.cpp:12571] Sending operation '' (uuid:
679157e6-50bd-45e0-8db2-14ce62d3ff9c) to agent
518ae562-76f1-47ed-8f1d-ba0ec7d63321-S0 at slave(752)@127.0.0.1:45481
(localhost)
I1023 19:44:37.622860 21883 slave.cpp:4352] Ignoring new checkpointed resources
and operations identical to the current version
I1023 19:44:37.622915 21883 slave.cpp:8936] Updating the state of operation
with no ID (uuid: 679157e6-50bd-45e0-8db2-14ce62d3ff9c) for framework
518ae562-76f1-47ed-8f1d-ba0ec7d63321-0000 (latest state: OPERATION_FINISHED,
status update state: OPERATION_FINISHED)
I1023 19:44:37.623311 21883 slave.cpp:4440] Updated checkpointed resources from
{} to disk(reservations:
[(STATIC,role1),(DYNAMIC,role1/xyz,test-principal)]):1024
I1023 19:44:37.623359 21883 slave.cpp:4464] Updated checkpointed operations
from [ ] to [ 679157e6-50bd-45e0-8db2-14ce62d3ff9c (RESERVE for framework
518ae562-76f1-47ed-8f1d-ba0ec7d63321-0000, latest state: OPERATION_FINISHED) ]
I1023 19:44:37.623631 21883 hierarchical.cpp:1302] Updated allocation of
framework 518ae562-76f1-47ed-8f1d-ba0ec7d63321-0000 on agent
518ae562-76f1-47ed-8f1d-ba0ec7d63321-S0 from disk(allocated:
role1/xyz)(reservations: [(STATIC,role1)]):1024; ports(allocated:
role1/xyz):[31000-32000]; cpus(allocated: role1/xyz):1; mem(allocated:
role1/xyz):512 to mem(allocated: role1/xyz):512; ports(allocated:
role1/xyz):[31000-32000]; cpus(allocated: role1/xyz):1; disk(allocated:
role1/xyz)(reservations:
[(STATIC,role1),(DYNAMIC,role1/xyz,test-principal)]):1024
I1023 19:44:37.623672 21883 hierarchical.cpp:1767] Allocation paused
I1023 19:44:37.623703 21883 hierarchical.cpp:1566] Recovered disk(allocated:
role1/xyz)(reservations:
[(STATIC,role1),(DYNAMIC,role1/xyz,test-principal)]):1024 (total: cpus:1;
mem:512; ports:[31000-32000]; disk(reservations:
[(STATIC,role1),(DYNAMIC,role1/xyz,test-principal)]):1024, offered or
allocated: mem(allocated: role1/xyz):512; ports(allocated:
role1/xyz):[31000-32000]; cpus(allocated: role1/xyz):1) on agent
518ae562-76f1-47ed-8f1d-ba0ec7d63321-S0 from framework
518ae562-76f1-47ed-8f1d-ba0ec7d63321-0000
I1023 19:44:37.623788 21883 hierarchical.cpp:1566] Recovered mem(allocated:
role1/xyz):512; ports(allocated: role1/xyz):[31000-32000]; cpus(allocated:
role1/xyz):1 (total: cpus:1; mem:512; ports:[31000-32000]; disk(reservations:
[(STATIC,role1),(DYNAMIC,role1/xyz,test-principal)]):1024, offered or
allocated: {}) on agent 518ae562-76f1-47ed-8f1d-ba0ec7d63321-S0 from framework
518ae562-76f1-47ed-8f1d-ba0ec7d63321-0000
I1023 19:44:37.623869 21883 hierarchical.cpp:1777] Allocation resumed
I1023 19:44:37.623883 21883 status_update_manager_process.hpp:152] Received
operation status update OPERATION_FINISHED (Status UUID:
2dbf83be-5a08-45db-a28e-ea3de58266ec) for operation UUID
679157e6-50bd-45e0-8db2-14ce62d3ff9c of framework
'518ae562-76f1-47ed-8f1d-ba0ec7d63321-0000' on agent
518ae562-76f1-47ed-8f1d-ba0ec7d63321-S0
I1023 19:44:37.623903 21883 status_update_manager_process.hpp:414] Creating
operation status update stream 679157e6-50bd-45e0-8db2-14ce62d3ff9c
checkpoint=true
I1023 19:44:37.624024 21883 status_update_manager_process.hpp:929]
Checkpointing UPDATE for operation status update OPERATION_FINISHED (Status
UUID: 2dbf83be-5a08-45db-a28e-ea3de58266ec) for operation UUID
679157e6-50bd-45e0-8db2-14ce62d3ff9c of framework
'518ae562-76f1-47ed-8f1d-ba0ec7d63321-0000' on agent
518ae562-76f1-47ed-8f1d-ba0ec7d63321-S0
I1023 19:44:37.629184 21883 status_update_manager_process.hpp:528] Forwarding
operation status update OPERATION_FINISHED (Status UUID:
2dbf83be-5a08-45db-a28e-ea3de58266ec) for operation UUID
679157e6-50bd-45e0-8db2-14ce62d3ff9c of framework
'518ae562-76f1-47ed-8f1d-ba0ec7d63321-0000' on agent
518ae562-76f1-47ed-8f1d-ba0ec7d63321-S0
I1023 19:44:37.629253 21883 slave.cpp:8936] Updating the state of operation
with no ID (uuid: 679157e6-50bd-45e0-8db2-14ce62d3ff9c) for framework
518ae562-76f1-47ed-8f1d-ba0ec7d63321-0000 (latest state: OPERATION_FINISHED,
status update state: OPERATION_FINISHED)
I1023 19:44:37.629268 21883 slave.cpp:6327] Forwarding status update of
operation with no ID (operation_uuid: 679157e6-50bd-45e0-8db2-14ce62d3ff9c) for
framework 518ae562-76f1-47ed-8f1d-ba0ec7d63321-0000
I1023 19:44:37.629317 21883 master.cpp:12223] Updating the state of operation
'' (uuid: 679157e6-50bd-45e0-8db2-14ce62d3ff9c) for framework
518ae562-76f1-47ed-8f1d-ba0ec7d63321-0000 (latest state: OPERATION_PENDING,
status update state: OPERATION_FINISHED)
I1023 19:44:37.629408 21883 status_update_manager_process.hpp:252] Received
operation status update acknowledgement (UUID:
2dbf83be-5a08-45db-a28e-ea3de58266ec) for stream
679157e6-50bd-45e0-8db2-14ce62d3ff9c
I1023 19:44:37.629423 21883 status_update_manager_process.hpp:929]
Checkpointing ACK for operation status update OPERATION_FINISHED (Status UUID:
2dbf83be-5a08-45db-a28e-ea3de58266ec) for operation UUID
679157e6-50bd-45e0-8db2-14ce62d3ff9c of framework
'518ae562-76f1-47ed-8f1d-ba0ec7d63321-0000' on agent
518ae562-76f1-47ed-8f1d-ba0ec7d63321-S0
I1023 19:44:37.633864 21883 status_update_manager_process.hpp:490] Cleaning up
operation status update stream 679157e6-50bd-45e0-8db2-14ce62d3ff9c
I1023 19:44:37.634150 21883 slave.cpp:4464] Updated checkpointed operations
from [ 679157e6-50bd-45e0-8db2-14ce62d3ff9c (RESERVE for framework
518ae562-76f1-47ed-8f1d-ba0ec7d63321-0000, latest state: OPERATION_FINISHED) ]
to [ ]
I1023 19:44:37.634776 21884 master.cpp:10409] Sending offers [
518ae562-76f1-47ed-8f1d-ba0ec7d63321-O1 ] to framework
518ae562-76f1-47ed-8f1d-ba0ec7d63321-0000 (default) at
scheduler-2e279a9b-04a2-4551-bcb1-fe72790bf487@127.0.0.1:45481
I1023 19:44:37.634903 21884 sched.cpp:934] Scheduler::resourceOffers took
17442ns
I1023 19:44:37.635087 21879 hierarchical.cpp:1843] Performed allocation for 1
agents in 493804ns
../../src/tests/upgrade_tests.cpp:905: Failure
Value of: Resources(offer.resources()).contains(
allocatedResources(baseReservation, frameworkInfo.roles(0)))
Actual: false
Expected: true
I1023 19:44:37.635694 21886 master.cpp:4719] Processing ACCEPT call for offers:
[ 518ae562-76f1-47ed-8f1d-ba0ec7d63321-O1 ] on agent
518ae562-76f1-47ed-8f1d-ba0ec7d63321-S0 at slave(752)@127.0.0.1:45481
(localhost) for framework 518ae562-76f1-47ed-8f1d-ba0ec7d63321-0000 (default)
at scheduler-2e279a9b-04a2-4551-bcb1-fe72790bf487@127.0.0.1:45481
I1023 19:44:37.635744 21886 master.cpp:3811] Authorizing principal
'test-principal' to reserve resources 'disk(allocated: role1/xyz)(reservations:
[(STATIC,role1),(DYNAMIC,role1/xyz,test-principal)]):1024'
I1023 19:44:37.635797 21886 master.cpp:3743] Authorizing framework principal
'test-principal' to launch task 35cad4d2-e213-4009-a1d7-7cb29dbb5eb0
I1023 19:44:37.636052 21886 master.cpp:12706] Removing offer
518ae562-76f1-47ed-8f1d-ba0ec7d63321-O1
W1023 19:44:37.636126 21886 master.cpp:2320] Dropping RESERVE operation from
framework 518ae562-76f1-47ed-8f1d-ba0ec7d63321-0000 (default) at
scheduler-2e279a9b-04a2-4551-bcb1-fe72790bf487@127.0.0.1:45481:
ports(allocated: role1/xyz):[31000-32000]; disk(allocated:
role1/xyz)(reservations:
[(STATIC,role1),(DYNAMIC,role1/xyz,test-principal)]):1024; cpus(allocated:
role1/xyz):1; mem(allocated: role1/xyz):512 does not contain disk(allocated:
role1/xyz)(reservations: [(STATIC,role1)]):1024
I1023 19:44:37.636297 21886 master.cpp:4287] Adding task
35cad4d2-e213-4009-a1d7-7cb29dbb5eb0 with resources disk(allocated:
role1/xyz)(reservations:
[(STATIC,role1),(DYNAMIC,role1/xyz,test-principal)]):1024 of framework
518ae562-76f1-47ed-8f1d-ba0ec7d63321-0000 (default) at
scheduler-2e279a9b-04a2-4551-bcb1-fe72790bf487@127.0.0.1:45481 on agent
518ae562-76f1-47ed-8f1d-ba0ec7d63321-S0 at slave(752)@127.0.0.1:45481
(localhost)
I1023 19:44:37.636371 21886 master.cpp:5714] Launching task
35cad4d2-e213-4009-a1d7-7cb29dbb5eb0 of framework
518ae562-76f1-47ed-8f1d-ba0ec7d63321-0000 (default) at
scheduler-2e279a9b-04a2-4551-bcb1-fe72790bf487@127.0.0.1:45481 with resources
[{"allocation_info":{"role":"role1/xyz"},"name":"disk","reservations":[{"role":"role1","type":"STATIC"},{"principal":"test-principal","role":"role1/xyz","type":"DYNAMIC"}],"scalar":{"value":1024.0},"type":"SCALAR"}]
on agent 518ae562-76f1-47ed-8f1d-ba0ec7d63321-S0 at slave(752)@127.0.0.1:45481
(localhost) on new executor
../../3rdparty/libprocess/include/process/gmock.hpp:667: Failure
Mock function called more times than expected - returning default value.
Function call: filter(@0x55db746d5ae8 slave(752)@127.0.0.1:45481,
@0x7f7aec0a5fd0 344-byte object <E0-83 6A-2B 7B-7F 00-00 30-E0 09-EC 7A-7F
00-00 1D-00 00-00 00-00 00-00 1D-00 00-00 00-00 00-00 05-0A 00-00 00-00 00-00
00-ED 28-73 DB-55 00-00 F0-EC 28-73 DB-55 00-00 02-00 00-00 7F-00 00-01 ...
04-00 00-00 00-00 00-00 00-00 00-00 00-00 00-00 80-F6 5B-74 DB-55 00-00 70-F6
5B-74 DB-55 00-00 50-C9 09-EC 7A-7F 00-00 7E-01 00-00 00-00 00-00 7E-01 00-00
00-00 00-00 60-01 00-00 00-00 00-00>)
Returns: false
Expected: to be never called
Actual: called once - over-saturated and active
I1023 19:44:37.636747 21886 slave.cpp:2130] Got assigned task
'35cad4d2-e213-4009-a1d7-7cb29dbb5eb0' for framework
518ae562-76f1-47ed-8f1d-ba0ec7d63321-0000
I1023 19:44:37.636992 21886 slave.cpp:2504] Authorizing task
'35cad4d2-e213-4009-a1d7-7cb29dbb5eb0' for framework
518ae562-76f1-47ed-8f1d-ba0ec7d63321-0000
I1023 19:44:37.637014 21886 slave.cpp:9466] Authorizing framework principal
'test-principal' to launch task 35cad4d2-e213-4009-a1d7-7cb29dbb5eb0
I1023 19:44:37.637152 21886 hierarchical.cpp:1767] Allocation paused
I1023 19:44:37.637197 21886 hierarchical.cpp:1566] Recovered ports(allocated:
role1/xyz):[31000-32000]; mem(allocated: role1/xyz):512; cpus(allocated:
role1/xyz):1 (total: cpus:1; mem:512; ports:[31000-32000]; disk(reservations:
[(STATIC,role1),(DYNAMIC,role1/xyz,test-principal)]):1024, offered or
allocated: disk(allocated: role1/xyz)(reservations:
[(STATIC,role1),(DYNAMIC,role1/xyz,test-principal)]):1024) on agent
518ae562-76f1-47ed-8f1d-ba0ec7d63321-S0 from framework
518ae562-76f1-47ed-8f1d-ba0ec7d63321-0000
I1023 19:44:37.637303 21886 hierarchical.cpp:1777] Allocation resumed
I1023 19:44:37.637574 21886 slave.cpp:2977] Launching task
'35cad4d2-e213-4009-a1d7-7cb29dbb5eb0' for framework
518ae562-76f1-47ed-8f1d-ba0ec7d63321-0000
I1023 19:44:37.637614 21886 paths.cpp:817] Creating sandbox
'/tmp/UpgradeTest_RefineResourceOnOldAgent_9PcvMc/slaves/518ae562-76f1-47ed-8f1d-ba0ec7d63321-S0/frameworks/518ae562-76f1-47ed-8f1d-ba0ec7d63321-0000/executors/35cad4d2-e213-4009-a1d7-7cb29dbb5eb0/runs/e27e900e-a896-4f04-a490-5634ea67456e'
for user 'root'
I1023 19:44:37.637971 21886 slave.cpp:10004] Launching executor
'35cad4d2-e213-4009-a1d7-7cb29dbb5eb0' of framework
518ae562-76f1-47ed-8f1d-ba0ec7d63321-0000 with resources
[{"allocation_info":{"role":"role1/xyz"},"name":"cpus","scalar":{"value":0.1},"type":"SCALAR"},{"allocation_info":{"role":"role1/xyz"},"name":"mem","scalar":{"value":32.0},"type":"SCALAR"}]
in work directory
'/tmp/UpgradeTest_RefineResourceOnOldAgent_9PcvMc/slaves/518ae562-76f1-47ed-8f1d-ba0ec7d63321-S0/frameworks/518ae562-76f1-47ed-8f1d-ba0ec7d63321-0000/executors/35cad4d2-e213-4009-a1d7-7cb29dbb5eb0/runs/e27e900e-a896-4f04-a490-5634ea67456e'
I1023 19:44:37.638149 21886 slave.cpp:3209] Queued task
'35cad4d2-e213-4009-a1d7-7cb29dbb5eb0' for executor
'35cad4d2-e213-4009-a1d7-7cb29dbb5eb0' of framework
518ae562-76f1-47ed-8f1d-ba0ec7d63321-0000
I1023 19:44:37.638365 21886 slave.cpp:3657] Launching container
e27e900e-a896-4f04-a490-5634ea67456e for executor
'35cad4d2-e213-4009-a1d7-7cb29dbb5eb0' of framework
518ae562-76f1-47ed-8f1d-ba0ec7d63321-0000
I1023 19:44:37.638630 21884 slave.cpp:1084] Successfully attached
'/tmp/UpgradeTest_RefineResourceOnOldAgent_9PcvMc/slaves/518ae562-76f1-47ed-8f1d-ba0ec7d63321-S0/frameworks/518ae562-76f1-47ed-8f1d-ba0ec7d63321-0000/executors/35cad4d2-e213-4009-a1d7-7cb29dbb5eb0/runs/e27e900e-a896-4f04-a490-5634ea67456e'
to virtual path
'/tmp/UpgradeTest_RefineResourceOnOldAgent_9PcvMc/slaves/518ae562-76f1-47ed-8f1d-ba0ec7d63321-S0/frameworks/518ae562-76f1-47ed-8f1d-ba0ec7d63321-0000/executors/35cad4d2-e213-4009-a1d7-7cb29dbb5eb0/runs/latest'
I1023 19:44:37.638650 21884 slave.cpp:1084] Successfully attached
'/tmp/UpgradeTest_RefineResourceOnOldAgent_9PcvMc/slaves/518ae562-76f1-47ed-8f1d-ba0ec7d63321-S0/frameworks/518ae562-76f1-47ed-8f1d-ba0ec7d63321-0000/executors/35cad4d2-e213-4009-a1d7-7cb29dbb5eb0/runs/e27e900e-a896-4f04-a490-5634ea67456e'
to virtual path
'/frameworks/518ae562-76f1-47ed-8f1d-ba0ec7d63321-0000/executors/35cad4d2-e213-4009-a1d7-7cb29dbb5eb0/runs/latest'
I1023 19:44:37.638677 21884 containerizer.cpp:1396] Starting container
e27e900e-a896-4f04-a490-5634ea67456e
I1023 19:44:37.638816 21884 containerizer.cpp:3318] Transitioning the state of
container e27e900e-a896-4f04-a490-5634ea67456e from STARTING to PROVISIONING
after 0ns
I1023 19:44:37.639053 21884 containerizer.cpp:1574] Checkpointed
ContainerConfig at
'/tmp/UpgradeTest_RefineResourceOnOldAgent_XBKbcM/containers/e27e900e-a896-4f04-a490-5634ea67456e/config'
I1023 19:44:37.639068 21884 containerizer.cpp:3318] Transitioning the state of
container e27e900e-a896-4f04-a490-5634ea67456e from PROVISIONING to PREPARING
after 0ns
I1023 19:44:37.640235 21884 containerizer.cpp:2100] Launching
'mesos-containerizer' with flags '--help="false"
--launch_info="{"command":{"arguments":["mesos-executor","--launcher_dir=/home/admin/workspace/mesos/Mesos_CI-build/FLAG/SSL/label/mesos-ec2-debian-9/mesos/build/src"],"shell":false,"value":"/proc/self/fd/28"},"environment":{"variables":[{"name":"LIBPROCESS_PORT","type":"VALUE","value":"0"},{"name":"MESOS_AGENT_ENDPOINT","type":"VALUE","value":"127.0.0.1:45481"},{"name":"MESOS_CHECKPOINT","type":"VALUE","value":"0"},{"name":"MESOS_DIRECTORY","type":"VALUE","value":"/tmp/UpgradeTest_RefineResourceOnOldAgent_9PcvMc/slaves/518ae562-76f1-47ed-8f1d-ba0ec7d63321-S0/frameworks/518ae562-76f1-47ed-8f1d-ba0ec7d63321-0000/executors/35cad4d2-e213-4009-a1d7-7cb29dbb5eb0/runs/e27e900e-a896-4f04-a490-5634ea67456e"},{"name":"MESOS_EXECUTOR_AUTHENTICATION_TOKEN","type":"VALUE","value":"eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJjaWQiOiJlMjdlOTAwZS1hODk2LTRmMDQtYTQ5MC01NjM0ZWE2NzQ1NmUiLCJlaWQiOiIzNWNhZDRkMi1lMjEzLTQwMDktYTFkNy03Y2IyOWRiYjVlYjAiLCJmaWQiOiI1MThhZTU2Mi03NmYxLTQ3ZWQtOGYxZC1iYTBlYzdkNjMzMjEtMDAwMCJ9.Rz6V8BCYfiHDpYbXICxPDu_793OGGQv3ekr2nIKVt7E"},{"name":"MESOS_EXECUTOR_ID","type":"VALUE","value":"35cad4d2-e213-4009-a1d7-7cb29dbb5eb0"},{"name":"MESOS_EXECUTOR_SHUTDOWN_GRACE_PERIOD","type":"VALUE","value":"5secs"},{"name":"MESOS_FRAMEWORK_ID","type":"VALUE","value":"518ae562-76f1-47ed-8f1d-ba0ec7d63321-0000"},{"name":"MESOS_HTTP_COMMAND_EXECUTOR","type":"VALUE","value":"0"},{"name":"MESOS_SLAVE_ID","type":"VALUE","value":"518ae562-76f1-47ed-8f1d-ba0ec7d63321-S0"},{"name":"MESOS_SLAVE_PID","type":"VALUE","value":"slave(752)@127.0.0.1:45481"},{"name":"MESOS_SANDBOX","type":"VALUE","value":"/tmp/UpgradeTest_RefineResourceOnOldAgent_9PcvMc/slaves/518ae562-76f1-47ed-8f1d-ba0ec7d63321-S0/frameworks/518ae562-76f1-47ed-8f1d-ba0ec7d63321-0000/executors/35cad4d2-e213-4009-a1d7-7cb29dbb5eb0/runs/e27e900e-a896-4f04-a490-5634ea67456e"}]},"task_environment":{},"user":"root","working_directory":"/tmp/UpgradeTest_RefineResourceOnOldAgent_9PcvMc/slaves/518ae562-76f1-47ed-8f1d-ba0ec7d63321-S0/frameworks/518ae562-76f1-47ed-8f1d-ba0ec7d63321-0000/executors/35cad4d2-e213-4009-a1d7-7cb29dbb5eb0/runs/e27e900e-a896-4f04-a490-5634ea67456e"}"
--pipe_read="34" --pipe_write="44"
--runtime_directory="/tmp/UpgradeTest_RefineResourceOnOldAgent_XBKbcM/containers/e27e900e-a896-4f04-a490-5634ea67456e"
--unshare_namespace_mnt="false"'
I1023 19:44:37.640413 21882 linux_launcher.cpp:492] Launching container
e27e900e-a896-4f04-a490-5634ea67456e and cloning with namespaces
I1023 19:44:37.645475 21886 slave.cpp:1084] Successfully attached
'/tmp/UpgradeTest_RefineResourceOnOldAgent_9PcvMc/slaves/518ae562-76f1-47ed-8f1d-ba0ec7d63321-S0/frameworks/518ae562-76f1-47ed-8f1d-ba0ec7d63321-0000/executors/35cad4d2-e213-4009-a1d7-7cb29dbb5eb0/runs/e27e900e-a896-4f04-a490-5634ea67456e'
to virtual path
'/tmp/UpgradeTest_RefineResourceOnOldAgent_9PcvMc/slaves/518ae562-76f1-47ed-8f1d-ba0ec7d63321-S0/frameworks/518ae562-76f1-47ed-8f1d-ba0ec7d63321-0000/executors/35cad4d2-e213-4009-a1d7-7cb29dbb5eb0/runs/e27e900e-a896-4f04-a490-5634ea67456e'
I1023 19:44:37.654846 21884 containerizer.cpp:3318] Transitioning the state of
container e27e900e-a896-4f04-a490-5634ea67456e from PREPARING to ISOLATING
after 0ns
I1023 19:44:37.655356 21884 containerizer.cpp:3318] Transitioning the state of
container e27e900e-a896-4f04-a490-5634ea67456e from ISOLATING to FETCHING after
0ns
I1023 19:44:37.655406 21884 fetcher.cpp:369] Starting to fetch URIs for
container: e27e900e-a896-4f04-a490-5634ea67456e, directory:
/tmp/UpgradeTest_RefineResourceOnOldAgent_9PcvMc/slaves/518ae562-76f1-47ed-8f1d-ba0ec7d63321-S0/frameworks/518ae562-76f1-47ed-8f1d-ba0ec7d63321-0000/executors/35cad4d2-e213-4009-a1d7-7cb29dbb5eb0/runs/e27e900e-a896-4f04-a490-5634ea67456e
I1023 19:44:37.655629 21884 containerizer.cpp:3318] Transitioning the state of
container e27e900e-a896-4f04-a490-5634ea67456e from FETCHING to RUNNING after
0ns
I1023 19:44:37.770642 28971 exec.cpp:164] Version: 1.10.0
I1023 19:44:37.772238 21884 slave.cpp:5256] Got registration for executor
'35cad4d2-e213-4009-a1d7-7cb29dbb5eb0' of framework
518ae562-76f1-47ed-8f1d-ba0ec7d63321-0000 from executor(1)@127.0.0.1:45463
I1023 19:44:37.773126 21880 slave.cpp:3427] Sending queued task
'35cad4d2-e213-4009-a1d7-7cb29dbb5eb0' to executor
'35cad4d2-e213-4009-a1d7-7cb29dbb5eb0' of framework
518ae562-76f1-47ed-8f1d-ba0ec7d63321-0000 at executor(1)@127.0.0.1:45463
I1023 19:44:37.773730 28977 exec.cpp:237] Executor registered on agent
518ae562-76f1-47ed-8f1d-ba0ec7d63321-S0
I1023 19:44:37.774801 28972 executor.cpp:190] Received SUBSCRIBED event
I1023 19:44:37.775010 28972 executor.cpp:194] Subscribed executor on localhost
I1023 19:44:37.775069 28972 executor.cpp:190] Received LAUNCH event
I1023 19:44:37.775727 28972 executor.cpp:722] Starting task
35cad4d2-e213-4009-a1d7-7cb29dbb5eb0
I1023 19:44:37.776891 21882 slave.cpp:5737] Handling status update
TASK_STARTING (Status UUID: 1d5b8a1f-b800-4e2b-84fc-0190a21f64a1) for task
35cad4d2-e213-4009-a1d7-7cb29dbb5eb0 of framework
518ae562-76f1-47ed-8f1d-ba0ec7d63321-0000 from executor(1)@127.0.0.1:45463
I1023 19:44:37.777493 21879 task_status_update_manager.cpp:328] Received task
status update TASK_STARTING (Status UUID: 1d5b8a1f-b800-4e2b-84fc-0190a21f64a1)
for task 35cad4d2-e213-4009-a1d7-7cb29dbb5eb0 of framework
518ae562-76f1-47ed-8f1d-ba0ec7d63321-0000
I1023 19:44:37.777519 21879 task_status_update_manager.cpp:507] Creating
StatusUpdate stream for task 35cad4d2-e213-4009-a1d7-7cb29dbb5eb0 of framework
518ae562-76f1-47ed-8f1d-ba0ec7d63321-0000
I1023 19:44:37.777700 21879 task_status_update_manager.cpp:383] Forwarding task
status update TASK_STARTING (Status UUID: 1d5b8a1f-b800-4e2b-84fc-0190a21f64a1)
for task 35cad4d2-e213-4009-a1d7-7cb29dbb5eb0 of framework
518ae562-76f1-47ed-8f1d-ba0ec7d63321-0000 to the agent
I1023 19:44:37.777782 21883 slave.cpp:6277] Forwarding the update TASK_STARTING
(Status UUID: 1d5b8a1f-b800-4e2b-84fc-0190a21f64a1) for task
35cad4d2-e213-4009-a1d7-7cb29dbb5eb0 of framework
518ae562-76f1-47ed-8f1d-ba0ec7d63321-0000 to master@127.0.0.1:45481
I1023 19:44:37.777890 21883 slave.cpp:6161] Task status update manager
successfully handled status update TASK_STARTING (Status UUID:
1d5b8a1f-b800-4e2b-84fc-0190a21f64a1) for task
35cad4d2-e213-4009-a1d7-7cb29dbb5eb0 of framework
518ae562-76f1-47ed-8f1d-ba0ec7d63321-0000
I1023 19:44:37.777920 21883 slave.cpp:6188] Sending acknowledgement for status
update TASK_STARTING (Status UUID: 1d5b8a1f-b800-4e2b-84fc-0190a21f64a1) for
task 35cad4d2-e213-4009-a1d7-7cb29dbb5eb0 of framework
518ae562-76f1-47ed-8f1d-ba0ec7d63321-0000 to executor(1)@127.0.0.1:45463
I1023 19:44:37.778064 21883 master.cpp:8956] Status update TASK_STARTING
(Status UUID: 1d5b8a1f-b800-4e2b-84fc-0190a21f64a1) for task
35cad4d2-e213-4009-a1d7-7cb29dbb5eb0 of framework
518ae562-76f1-47ed-8f1d-ba0ec7d63321-0000 from agent
518ae562-76f1-47ed-8f1d-ba0ec7d63321-S0 at slave(752)@127.0.0.1:45481
(localhost)
I1023 19:44:37.778086 21883 master.cpp:9013] Forwarding status update
TASK_STARTING (Status UUID: 1d5b8a1f-b800-4e2b-84fc-0190a21f64a1) for task
35cad4d2-e213-4009-a1d7-7cb29dbb5eb0 of framework
518ae562-76f1-47ed-8f1d-ba0ec7d63321-0000
I1023 19:44:37.778189 21883 master.cpp:12023] Updating the state of task
35cad4d2-e213-4009-a1d7-7cb29dbb5eb0 of framework
518ae562-76f1-47ed-8f1d-ba0ec7d63321-0000 (latest state: TASK_STARTING, status
update state: TASK_STARTING)
I1023 19:44:37.778296 21883 sched.cpp:1042] Scheduler::statusUpdate took 29657ns
I1023 19:44:37.778393 21883 master.cpp:6690] Processing ACKNOWLEDGE call for
status 1d5b8a1f-b800-4e2b-84fc-0190a21f64a1 for task
35cad4d2-e213-4009-a1d7-7cb29dbb5eb0 of framework
518ae562-76f1-47ed-8f1d-ba0ec7d63321-0000 (default) at
scheduler-2e279a9b-04a2-4551-bcb1-fe72790bf487@127.0.0.1:45481 on agent
518ae562-76f1-47ed-8f1d-ba0ec7d63321-S0
I1023 19:44:37.778482 21883 task_status_update_manager.cpp:401] Received task
status update acknowledgement (UUID: 1d5b8a1f-b800-4e2b-84fc-0190a21f64a1) for
task 35cad4d2-e213-4009-a1d7-7cb29dbb5eb0 of framework
518ae562-76f1-47ed-8f1d-ba0ec7d63321-0000
I1023 19:44:37.778703 21881 slave.cpp:4866] Task status update manager
successfully handled status update acknowledgement (UUID:
1d5b8a1f-b800-4e2b-84fc-0190a21f64a1) for task
35cad4d2-e213-4009-a1d7-7cb29dbb5eb0 of framework
518ae562-76f1-47ed-8f1d-ba0ec7d63321-0000
I1023 19:44:37.782461 28972 executor.cpp:740] Forked command at 28981
I1023 19:44:37.783438 21881 slave.cpp:5737] Handling status update TASK_RUNNING
(Status UUID: 29823f5e-c37a-4ed2-bcd3-6a482179d6ec) for task
35cad4d2-e213-4009-a1d7-7cb29dbb5eb0 of framework
518ae562-76f1-47ed-8f1d-ba0ec7d63321-0000 from executor(1)@127.0.0.1:45463
I1023 19:44:37.783879 21881 task_status_update_manager.cpp:328] Received task
status update TASK_RUNNING (Status UUID: 29823f5e-c37a-4ed2-bcd3-6a482179d6ec)
for task 35cad4d2-e213-4009-a1d7-7cb29dbb5eb0 of framework
518ae562-76f1-47ed-8f1d-ba0ec7d63321-0000
I1023 19:44:37.783918 21881 task_status_update_manager.cpp:383] Forwarding task
status update TASK_RUNNING (Status UUID: 29823f5e-c37a-4ed2-bcd3-6a482179d6ec)
for task 35cad4d2-e213-4009-a1d7-7cb29dbb5eb0 of framework
518ae562-76f1-47ed-8f1d-ba0ec7d63321-0000 to the agent
I1023 19:44:37.783975 21881 slave.cpp:6277] Forwarding the update TASK_RUNNING
(Status UUID: 29823f5e-c37a-4ed2-bcd3-6a482179d6ec) for task
35cad4d2-e213-4009-a1d7-7cb29dbb5eb0 of framework
518ae562-76f1-47ed-8f1d-ba0ec7d63321-0000 to master@127.0.0.1:45481
I1023 19:44:37.784035 21881 slave.cpp:6161] Task status update manager
successfully handled status update TASK_RUNNING (Status UUID:
29823f5e-c37a-4ed2-bcd3-6a482179d6ec) for task
35cad4d2-e213-4009-a1d7-7cb29dbb5eb0 of framework
518ae562-76f1-47ed-8f1d-ba0ec7d63321-0000
I1023 19:44:37.784059 21881 slave.cpp:6188] Sending acknowledgement for status
update TASK_RUNNING (Status UUID: 29823f5e-c37a-4ed2-bcd3-6a482179d6ec) for
task 35cad4d2-e213-4009-a1d7-7cb29dbb5eb0 of framework
518ae562-76f1-47ed-8f1d-ba0ec7d63321-0000 to executor(1)@127.0.0.1:45463
I1023 19:44:37.784188 21881 master.cpp:8956] Status update TASK_RUNNING (Status
UUID: 29823f5e-c37a-4ed2-bcd3-6a482179d6ec) for task
35cad4d2-e213-4009-a1d7-7cb29dbb5eb0 of framework
518ae562-76f1-47ed-8f1d-ba0ec7d63321-0000 from agent
518ae562-76f1-47ed-8f1d-ba0ec7d63321-S0 at slave(752)@127.0.0.1:45481
(localhost)
I1023 19:44:37.784209 21881 master.cpp:9013] Forwarding status update
TASK_RUNNING (Status UUID: 29823f5e-c37a-4ed2-bcd3-6a482179d6ec) for task
35cad4d2-e213-4009-a1d7-7cb29dbb5eb0 of framework
518ae562-76f1-47ed-8f1d-ba0ec7d63321-0000
I1023 19:44:37.784260 21881 master.cpp:12023] Updating the state of task
35cad4d2-e213-4009-a1d7-7cb29dbb5eb0 of framework
518ae562-76f1-47ed-8f1d-ba0ec7d63321-0000 (latest state: TASK_RUNNING, status
update state: TASK_RUNNING)
../../src/tests/upgrade_tests.cpp:911: Failure
Mock function called more times than expected - returning directly.
Function call: statusUpdate(0x7ffddd25d2f0, @0x7f7b1cf19420 136-byte object
<50-82 6F-2B 7B-7F 00-00 00-00 00-00 00-00 00-00 BC-A8 00-00 00-00 00-00 C0-A0
6B-71 DB-55 00-00 C0-A0 6B-71 DB-55 00-00 20-04 10-08 7B-7F 00-00 A0-FA 0E-08
7B-7F 00-00 00-B3 04-08 7B-7F 00-00 ... 00-00 00-00 00-00 00-00 E0-AA 0F-08
7B-7F 00-00 00-00 00-00 00-00 00-00 00-00 00-00 00-00 00-00 00-00 00-00 00-00
00-00 22-16 72-69 2B-6C D7-41 00-00 00-00 02-00 00-00 00-00 00-00 01-00 00-00>)
Expected: to be called once
Actual: called twice - over-saturated and active
I1023 19:44:37.784425 21881 sched.cpp:1042] Scheduler::statusUpdate took
102239ns
I1023 19:44:37.784487 21881 master.cpp:6690] Processing ACKNOWLEDGE call for
status 29823f5e-c37a-4ed2-bcd3-6a482179d6ec for task
35cad4d2-e213-4009-a1d7-7cb29dbb5eb0 of framework
518ae562-76f1-47ed-8f1d-ba0ec7d63321-0000 (default) at
scheduler-2e279a9b-04a2-4551-bcb1-fe72790bf487@127.0.0.1:45481 on agent
518ae562-76f1-47ed-8f1d-ba0ec7d63321-S0
I1023 19:44:37.784549 21881 task_status_update_manager.cpp:401] Received task
status update acknowledgement (UUID: 29823f5e-c37a-4ed2-bcd3-6a482179d6ec) for
task 35cad4d2-e213-4009-a1d7-7cb29dbb5eb0 of framework
518ae562-76f1-47ed-8f1d-ba0ec7d63321-0000
I1023 19:44:37.784596 21881 slave.cpp:4866] Task status update manager
successfully handled status update acknowledgement (UUID:
29823f5e-c37a-4ed2-bcd3-6a482179d6ec) for task
35cad4d2-e213-4009-a1d7-7cb29dbb5eb0 of framework
518ae562-76f1-47ed-8f1d-ba0ec7d63321-0000
../../src/tests/upgrade_tests.cpp:927: Failure
Expected: TASK_ERROR
To be equal to: status->state()
Which is: TASK_STARTING
I1023 19:44:37.788347 21886 hierarchical.cpp:1843] Performed allocation for 1
agents in 159746ns
I1023 19:44:37.788492 21886 master.cpp:10409] Sending offers [
518ae562-76f1-47ed-8f1d-ba0ec7d63321-O2 ] to framework
518ae562-76f1-47ed-8f1d-ba0ec7d63321-0000 (default) at
scheduler-2e279a9b-04a2-4551-bcb1-fe72790bf487@127.0.0.1:45481
I1023 19:44:37.788652 21886 sched.cpp:934] Scheduler::resourceOffers took
28849ns
../../src/tests/upgrade_tests.cpp:937: Failure
Value of: Resources(offer.resources()).contains(
allocatedResources(baseReservation, frameworkInfo.roles(0)))
Actual: false
Expected: true
I1023 19:44:37.788893 21878 sched.cpp:2166] Asked to stop the driver
I1023 19:44:37.789048 21885 sched.cpp:1204] Stopping framework
518ae562-76f1-47ed-8f1d-ba0ec7d63321-0000
I1023 19:44:37.789165 21885 master.cpp:11185] Processing TEARDOWN call for
framework 518ae562-76f1-47ed-8f1d-ba0ec7d63321-0000 (default) at
scheduler-2e279a9b-04a2-4551-bcb1-fe72790bf487@127.0.0.1:45481
I1023 19:44:37.789188 21885 master.cpp:11197] Removing framework
518ae562-76f1-47ed-8f1d-ba0ec7d63321-0000 (default) at
scheduler-2e279a9b-04a2-4551-bcb1-fe72790bf487@127.0.0.1:45481
I1023 19:44:37.789202 21885 master.cpp:3356] Deactivating framework
518ae562-76f1-47ed-8f1d-ba0ec7d63321-0000 (default) at
scheduler-2e279a9b-04a2-4551-bcb1-fe72790bf487@127.0.0.1:45481
I1023 19:44:37.789273 21885 master.cpp:12706] Removing offer
518ae562-76f1-47ed-8f1d-ba0ec7d63321-O2
I1023 19:44:37.789320 21885 master.cpp:12023] Updating the state of task
35cad4d2-e213-4009-a1d7-7cb29dbb5eb0 of framework
518ae562-76f1-47ed-8f1d-ba0ec7d63321-0000 (latest state: TASK_KILLED, status
update state: TASK_KILLED)
I1023 19:44:37.789408 21885 master.cpp:12123] Removing task
35cad4d2-e213-4009-a1d7-7cb29dbb5eb0 with resources disk(allocated:
role1/xyz)(reservations:
[(STATIC,role1),(DYNAMIC,role1/xyz,test-principal)]):1024 of framework
518ae562-76f1-47ed-8f1d-ba0ec7d63321-0000 on agent
518ae562-76f1-47ed-8f1d-ba0ec7d63321-S0 at slave(752)@127.0.0.1:45481
(localhost)
I1023 19:44:37.789573 21885 hierarchical.cpp:813] Deactivated framework
518ae562-76f1-47ed-8f1d-ba0ec7d63321-0000
I1023 19:44:37.789638 21885 hierarchical.cpp:1566] Recovered ports(allocated:
role1/xyz):[31000-32000]; cpus(allocated: role1/xyz):1; mem(allocated:
role1/xyz):512 (total: cpus:1; mem:512; ports:[31000-32000]; disk(reservations:
[(STATIC,role1),(DYNAMIC,role1/xyz,test-principal)]):1024, offered or
allocated: disk(allocated: role1/xyz)(reservations:
[(STATIC,role1),(DYNAMIC,role1/xyz,test-principal)]):1024) on agent
518ae562-76f1-47ed-8f1d-ba0ec7d63321-S0 from framework
518ae562-76f1-47ed-8f1d-ba0ec7d63321-0000
I1023 19:44:37.789777 21885 hierarchical.cpp:1566] Recovered disk(allocated:
role1/xyz)(reservations:
[(STATIC,role1),(DYNAMIC,role1/xyz,test-principal)]):1024 (total: cpus:1;
mem:512; ports:[31000-32000]; disk(reservations:
[(STATIC,role1),(DYNAMIC,role1/xyz,test-principal)]):1024, offered or
allocated: {}) on agent 518ae562-76f1-47ed-8f1d-ba0ec7d63321-S0 from framework
518ae562-76f1-47ed-8f1d-ba0ec7d63321-0000
I1023 19:44:37.789844 21885 hierarchical.cpp:1767] Allocation paused
I1023 19:44:37.789889 21885 hierarchical.cpp:757] Removed framework
518ae562-76f1-47ed-8f1d-ba0ec7d63321-0000
I1023 19:44:37.789904 21885 hierarchical.cpp:1777] Allocation resumed
I1023 19:44:37.789932 21885 slave.cpp:4062] Asked to shut down framework
518ae562-76f1-47ed-8f1d-ba0ec7d63321-0000 by master@127.0.0.1:45481
I1023 19:44:37.789944 21885 slave.cpp:4087] Shutting down framework
518ae562-76f1-47ed-8f1d-ba0ec7d63321-0000
I1023 19:44:37.789954 21885 slave.cpp:7223] Shutting down executor
'35cad4d2-e213-4009-a1d7-7cb29dbb5eb0' of framework
518ae562-76f1-47ed-8f1d-ba0ec7d63321-0000 at executor(1)@127.0.0.1:45463
I1023 19:44:37.790359 28976 exec.cpp:459] Executor asked to shutdown
I1023 19:44:37.790583 28976 executor.cpp:190] Received SHUTDOWN event
I1023 19:44:37.790598 28976 executor.cpp:843] Shutting down
I1023 19:44:37.790608 28976 executor.cpp:956] Sending SIGTERM to process tree
at pid 28981
I1023 19:44:37.790838 21878 slave.cpp:924] Agent terminating
I1023 19:44:37.790858 21878 slave.cpp:4062] Asked to shut down framework
518ae562-76f1-47ed-8f1d-ba0ec7d63321-0000 by @0.0.0.0:0
W1023 19:44:37.790868 21878 slave.cpp:4083] Ignoring shutdown framework
518ae562-76f1-47ed-8f1d-ba0ec7d63321-0000 because it is terminating
I1023 19:44:37.794880 21882 master.cpp:1296] Agent
518ae562-76f1-47ed-8f1d-ba0ec7d63321-S0 at slave(752)@127.0.0.1:45481
(localhost) disconnected
I1023 19:44:37.794910 21882 master.cpp:3391] Disconnecting agent
518ae562-76f1-47ed-8f1d-ba0ec7d63321-S0 at slave(752)@127.0.0.1:45481
(localhost)
I1023 19:44:37.794931 21882 master.cpp:3410] Deactivating agent
518ae562-76f1-47ed-8f1d-ba0ec7d63321-S0 at slave(752)@127.0.0.1:45481
(localhost)
I1023 19:44:37.795045 21882 hierarchical.cpp:1146] Agent
518ae562-76f1-47ed-8f1d-ba0ec7d63321-S0 deactivated
I1023 19:44:37.795238 21882 containerizer.cpp:2620] Destroying container
e27e900e-a896-4f04-a490-5634ea67456e in RUNNING state
I1023 19:44:37.795253 21882 containerizer.cpp:3318] Transitioning the state of
container e27e900e-a896-4f04-a490-5634ea67456e from RUNNING to DESTROYING after
1.215155968secs
I1023 19:44:37.795349 21882 linux_launcher.cpp:576] Asked to destroy container
e27e900e-a896-4f04-a490-5634ea67456e
I1023 19:44:37.795387 21882 linux_launcher.cpp:618] Destroying cgroup
'/sys/fs/cgroup/freezer/mesos/e27e900e-a896-4f04-a490-5634ea67456e'
I1023 19:44:37.795608 21882 cgroups.cpp:2854] Freezing cgroup
/sys/fs/cgroup/freezer/mesos/e27e900e-a896-4f04-a490-5634ea67456e
I1023 19:44:37.896860 21879 cgroups.cpp:1242] Successfully froze cgroup
/sys/fs/cgroup/freezer/mesos/e27e900e-a896-4f04-a490-5634ea67456e after
101.227008ms
I1023 19:44:37.897127 21879 cgroups.cpp:2872] Thawing cgroup
/sys/fs/cgroup/freezer/mesos/e27e900e-a896-4f04-a490-5634ea67456e
I1023 19:44:37.897284 21879 cgroups.cpp:1271] Successfully thawed cgroup
/sys/fs/cgroup/freezer/mesos/e27e900e-a896-4f04-a490-5634ea67456e after 125952ns
I1023 19:44:37.997125 21884 containerizer.cpp:3156] Container
e27e900e-a896-4f04-a490-5634ea67456e has exited
I1023 19:44:37.997931 21885 provisioner.cpp:652] Ignoring destroy request for
unknown container e27e900e-a896-4f04-a490-5634ea67456e
I1023 19:44:38.007932 21878 master.cpp:1137] Master terminating
I1023 19:44:38.013327 21885 hierarchical.cpp:1122] Removed all filters for
agent 518ae562-76f1-47ed-8f1d-ba0ec7d63321-S0
I1023 19:44:38.013352 21885 hierarchical.cpp:998] Removed agent
518ae562-76f1-47ed-8f1d-ba0ec7d63321-S0
[ FAILED ] UpgradeTest.RefineResourceOnOldAgent (451 ms)
{noformat}
Note the first failure in the test:
{noformat}
I1023 19:44:37.634903 21884 sched.cpp:934] Scheduler::resourceOffers took
17442ns
I1023 19:44:37.635087 21879 hierarchical.cpp:1843] Performed allocation for 1
agents in 493804ns
../../src/tests/upgrade_tests.cpp:905: Failure
Value of: Resources(offer.resources()).contains(
allocatedResources(baseReservation, frameworkInfo.roles(0)))
Actual: false
Expected: true
{noformat}
> UpgradeTest.RefineResourceOnOldAgent is flaky
> ---------------------------------------------
>
> Key: MESOS-9664
> URL: https://issues.apache.org/jira/browse/MESOS-9664
> Project: Mesos
> Issue Type: Bug
> Affects Versions: 1.8.0
> Reporter: Greg Mann
> Priority: Major
> Labels: flaky, flaky-test, foundations, mesosphere
> Attachments: UpgradeTest.RefineResourceOnOldAgent.failure.txt
>
>
> This failure was observed in internal CI on Ubuntu 14.04, an SSL-enabled
> build. Verbose log attached.
--
This message was sent by Atlassian Jira
(v8.3.4#803005)
