[
https://issues.apache.org/jira/browse/MESOS-2831?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16706050#comment-16706050
]
Till Toenshoff commented on MESOS-2831:
---------------------------------------
The test is still flaky, symptoms however are much different from the above -
observed on Centos 6 (internal CI):
{noformat}
17:03:37 [ RUN ] FetcherCacheTest.SimpleEviction
17:03:37 I1201 17:03:36.468372 27052 cluster.cpp:173] Creating default 'local'
authorizer
17:03:37 I1201 17:03:36.469640 27073 master.cpp:414] Master
851721f2-f8da-4afb-8248-1c66dcf55e4b (ip-172-16-10-14.ec2.internal) started on
172.16.10.14:43373
17:03:37 I1201 17:03:36.469662 27073 master.cpp:417] 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/twhCtT/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" --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/twhCtT/master" --zk_session_timeout="10secs"
17:03:37 I1201 17:03:36.469805 27073 master.cpp:466] Master only allowing
authenticated frameworks to register
17:03:37 I1201 17:03:36.469813 27073 master.cpp:472] Master only allowing
authenticated agents to register
17:03:37 I1201 17:03:36.469820 27073 master.cpp:478] Master only allowing
authenticated HTTP frameworks to register
17:03:37 I1201 17:03:36.469826 27073 credentials.hpp:37] Loading credentials
for authentication from '/tmp/twhCtT/credentials'
17:03:37 I1201 17:03:36.469919 27073 master.cpp:522] Using default 'crammd5'
authenticator
17:03:37 I1201 17:03:36.469966 27073 http.cpp:1017] Creating default 'basic'
HTTP authenticator for realm 'mesos-master-readonly'
17:03:37 I1201 17:03:36.470006 27073 http.cpp:1017] Creating default 'basic'
HTTP authenticator for realm 'mesos-master-readwrite'
17:03:37 I1201 17:03:36.470032 27073 http.cpp:1017] Creating default 'basic'
HTTP authenticator for realm 'mesos-master-scheduler'
17:03:37 I1201 17:03:36.470072 27073 master.cpp:603] Authorization enabled
17:03:37 I1201 17:03:36.470346 27075 whitelist_watcher.cpp:77] No whitelist
given
17:03:37 I1201 17:03:36.470376 27078 hierarchical.cpp:175] Initialized
hierarchical allocator process
17:03:37 I1201 17:03:36.470836 27073 master.cpp:2089] Elected as the leading
master!
17:03:37 I1201 17:03:36.470852 27073 master.cpp:1644] Recovering from registrar
17:03:37 I1201 17:03:36.470891 27073 registrar.cpp:339] Recovering registrar
17:03:37 I1201 17:03:36.471021 27073 registrar.cpp:383] Successfully fetched
the registry (0B) in 116992ns
17:03:37 I1201 17:03:36.471228 27073 registrar.cpp:487] Applied 1 operations in
180707ns; attempting to update the registry
17:03:37 I1201 17:03:36.471421 27073 registrar.cpp:544] Successfully updated
the registry in 163072ns
17:03:37 I1201 17:03:36.471449 27073 registrar.cpp:416] Successfully recovered
registrar
17:03:37 I1201 17:03:36.471534 27073 master.cpp:1758] Recovered 0 agents from
the registry (171B); allowing 10mins for agents to reregister
17:03:37 I1201 17:03:36.471563 27076 hierarchical.cpp:215] Skipping recovery of
hierarchical allocator: nothing to recover
17:03:37 W1201 17:03:36.471896 27052 process.cpp:2829] Attempted to spawn
already running process [email protected]:43373
17:03:37 I1201 17:03:36.472522 27052 containerizer.cpp:305] Using isolation {
environment_secret, posix/cpu, posix/mem, filesystem/posix, network/cni }
17:03:37 I1201 17:03:36.474298 27052 linux_launcher.cpp:144] Using
/cgroup/freezer as the freezer hierarchy for the Linux launcher
17:03:37 I1201 17:03:36.474673 27052 provisioner.cpp:298] Using default backend
'copy'
17:03:37 W1201 17:03:36.476142 27052 process.cpp:2829] Attempted to spawn
already running process [email protected]:43373
17:03:37 I1201 17:03:36.476346 27052 cluster.cpp:485] Creating default 'local'
authorizer
17:03:37 I1201 17:03:36.476867 27076 slave.cpp:268] Mesos agent started on
(81)@172.16.10.14:43373
17:03:37 I1201 17:03:36.476881 27076 slave.cpp:269] Flags at startup: --acls=""
--appc_simple_discovery_uri_prefix="http://";
--appc_store_dir="/tmp/FetcherCacheTest_SimpleEviction_LTCh0J/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/FetcherCacheTest_SimpleEviction_LTCh0J/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/FetcherCacheTest_SimpleEviction_LTCh0J/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/FetcherCacheTest_SimpleEviction_LTCh0J/fetch"
--fetcher_cache_size="60B" --fetcher_stall_timeout="1mins"
--frameworks_home="/tmp/FetcherCacheTest_SimpleEviction_LTCh0J/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/FetcherCacheTest_SimpleEviction_LTCh0J/http_credentials"
--http_heartbeat_interval="30secs" --initialize_driver_logging="true"
--isolation="posix/cpu,posix/mem"
--jwt_secret_key="/tmp/FetcherCacheTest_SimpleEviction_LTCh0J/jwt_secret_key"
--launcher="linux"
--launcher_dir="/home/centos/workspace/mesos/Mesos_CI-build/FLAG/SSL/label/mesos-ec2-centos-6/mesos/build/src"
--logbufsecs="0" --logging_level="INFO"
--max_completed_executors_per_framework="150" --memory_profiling="false"
--network_cni_metrics="true" --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:1000;mem:1000" --revocable_cpu_low_priority="true"
--runtime_dir="/tmp/FetcherCacheTest_SimpleEviction_LTCh0J"
--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/FetcherCacheTest_SimpleEviction_ZVKWJj"
--zk_session_timeout="10secs"
17:03:37 I1201 17:03:36.477095 27076 credentials.hpp:86] Loading credential for
authentication from '/tmp/FetcherCacheTest_SimpleEviction_LTCh0J/credential'
17:03:37 I1201 17:03:36.477144 27076 slave.cpp:301] Agent using credential for:
test-principal
17:03:37 I1201 17:03:36.477151 27076 credentials.hpp:37] Loading credentials
for authentication from
'/tmp/FetcherCacheTest_SimpleEviction_LTCh0J/http_credentials'
17:03:37 I1201 17:03:36.477207 27076 http.cpp:1017] Creating default 'basic'
HTTP authenticator for realm 'mesos-agent-executor'
17:03:37 I1201 17:03:36.477238 27076 http.cpp:1038] Creating default 'jwt' HTTP
authenticator for realm 'mesos-agent-executor'
17:03:37 I1201 17:03:36.477286 27076 http.cpp:1017] Creating default 'basic'
HTTP authenticator for realm 'mesos-agent-readonly'
17:03:37 I1201 17:03:36.477308 27076 http.cpp:1038] Creating default 'jwt' HTTP
authenticator for realm 'mesos-agent-readonly'
17:03:37 I1201 17:03:36.477346 27076 http.cpp:1017] Creating default 'basic'
HTTP authenticator for realm 'mesos-agent-readwrite'
17:03:37 I1201 17:03:36.477368 27076 http.cpp:1038] Creating default 'jwt' HTTP
authenticator for realm 'mesos-agent-readwrite'
17:03:37 I1201 17:03:36.477437 27076 disk_profile_adaptor.cpp:80] Creating
default disk profile adaptor module
17:03:37 I1201 17:03:36.477936 27076 slave.cpp:616] Agent resources:
[{"name":"cpus","scalar":{"value":1000.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":1000.0},"type":"SCALAR"},{"name":"disk","scalar":{"value":35068.0},"type":"SCALAR"},{"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}]
17:03:37 I1201 17:03:36.477993 27076 slave.cpp:624] Agent attributes: [ ]
17:03:37 I1201 17:03:36.478001 27076 slave.cpp:633] Agent hostname:
ip-172-16-10-14.ec2.internal
17:03:37 I1201 17:03:36.478102 27078 task_status_update_manager.cpp:181]
Pausing sending task status updates
17:03:37 I1201 17:03:36.478327 27076 state.cpp:66] Recovering state from
'/tmp/FetcherCacheTest_SimpleEviction_ZVKWJj/meta'
17:03:37 I1201 17:03:36.478379 27076 slave.cpp:6914] Finished recovering
checkpointed state from '/tmp/FetcherCacheTest_SimpleEviction_ZVKWJj/meta',
beginning agent recovery
17:03:37 I1201 17:03:36.478418 27076 task_status_update_manager.cpp:207]
Recovering task status update manager
17:03:37 I1201 17:03:36.478499 27076 containerizer.cpp:727] Recovering Mesos
containers
17:03:37 I1201 17:03:36.478552 27076 linux_launcher.cpp:286] Recovering Linux
launcher
17:03:37 I1201 17:03:36.478667 27076 containerizer.cpp:1053] Recovering
isolators
17:03:37 I1201 17:03:36.478826 27076 containerizer.cpp:1092] Recovering
provisioner
17:03:37 I1201 17:03:36.478943 27076 provisioner.cpp:494] Provisioner recovery
complete
17:03:37 I1201 17:03:36.479118 27079 composing.cpp:339] Finished recovering all
containerizers
17:03:37 I1201 17:03:36.479218 27072 slave.cpp:7143] Recovering executors
17:03:37 I1201 17:03:36.479243 27072 slave.cpp:7296] Finished recovery
17:03:37 I1201 17:03:36.479589 27078 task_status_update_manager.cpp:181]
Pausing sending task status updates
17:03:37 I1201 17:03:36.479589 27075 slave.cpp:1259] New master detected at
[email protected]:43373
17:03:37 I1201 17:03:36.479631 27075 slave.cpp:1324] Detecting new master
17:03:37 I1201 17:03:36.484871 27076 slave.cpp:1351] Authenticating with master
[email protected]:43373
17:03:37 I1201 17:03:36.484899 27076 slave.cpp:1360] Using default CRAM-MD5
authenticatee
17:03:37 I1201 17:03:36.484973 27076 authenticatee.cpp:121] Creating new client
SASL connection
17:03:37 I1201 17:03:36.485075 27076 master.cpp:9649] Authenticating
slave(81)@172.16.10.14:43373
17:03:37 I1201 17:03:36.485121 27076 authenticator.cpp:414] Starting
authentication session for crammd5-authenticatee(186)@172.16.10.14:43373
17:03:37 I1201 17:03:36.485177 27076 authenticator.cpp:98] Creating new server
SASL connection
17:03:37 I1201 17:03:36.485234 27075 authenticatee.cpp:213] Received SASL
authentication mechanisms: CRAM-MD5
17:03:37 I1201 17:03:36.485246 27075 authenticatee.cpp:239] Attempting to
authenticate with mechanism 'CRAM-MD5'
17:03:37 I1201 17:03:36.485285 27076 authenticator.cpp:204] Received SASL
authentication start
17:03:37 I1201 17:03:36.485327 27076 authenticator.cpp:326] Authentication
requires more steps
17:03:37 I1201 17:03:36.485360 27076 authenticatee.cpp:259] Received SASL
authentication step
17:03:37 I1201 17:03:36.485399 27076 authenticator.cpp:232] Received SASL
authentication step
17:03:37 I1201 17:03:36.485415 27076 auxprop.cpp:109] Request to lookup
properties for user: 'test-principal' realm: 'ip-172-16-10-14' server FQDN:
'ip-172-16-10-14' SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
17:03:37 I1201 17:03:36.485424 27076 auxprop.cpp:181] Looking up auxiliary
property '*userPassword'
17:03:37 I1201 17:03:36.485435 27076 auxprop.cpp:181] Looking up auxiliary
property '*cmusaslsecretCRAM-MD5'
17:03:37 I1201 17:03:36.485445 27076 auxprop.cpp:109] Request to lookup
properties for user: 'test-principal' realm: 'ip-172-16-10-14' server FQDN:
'ip-172-16-10-14' SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
17:03:37 I1201 17:03:36.485452 27076 auxprop.cpp:131] Skipping auxiliary
property '*userPassword' since SASL_AUXPROP_AUTHZID == true
17:03:37 I1201 17:03:36.485458 27076 auxprop.cpp:131] Skipping auxiliary
property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
17:03:37 I1201 17:03:36.485471 27076 authenticator.cpp:318] Authentication
success
17:03:37 I1201 17:03:36.485497 27079 authenticatee.cpp:299] Authentication
success
17:03:37 I1201 17:03:36.488126 27079 slave.cpp:1451] Successfully authenticated
with master [email protected]:43373
17:03:37 I1201 17:03:36.488164 27074 master.cpp:9681] Successfully
authenticated principal 'test-principal' at slave(81)@172.16.10.14:43373
17:03:37 I1201 17:03:36.488211 27076 authenticator.cpp:432] Authentication
session cleanup for crammd5-authenticatee(186)@172.16.10.14:43373
17:03:37 I1201 17:03:36.488479 27078 master.cpp:6600] Received register agent
message from slave(81)@172.16.10.14:43373 (ip-172-16-10-14.ec2.internal)
17:03:37 I1201 17:03:36.488549 27078 master.cpp:3930] Authorizing agent
providing resources 'cpus:1000; mem:1000; disk:35068; ports:[31000-32000]' with
principal 'test-principal'
17:03:37 I1201 17:03:36.488633 27079 slave.cpp:1882] Will retry registration in
5.721782ms if necessary
17:03:37 I1201 17:03:36.489310 27074 master.cpp:6667] Authorized registration
of agent at slave(81)@172.16.10.14:43373 (ip-172-16-10-14.ec2.internal)
17:03:37 I1201 17:03:36.489352 27074 master.cpp:6782] Registering agent at
slave(81)@172.16.10.14:43373 (ip-172-16-10-14.ec2.internal) with id
851721f2-f8da-4afb-8248-1c66dcf55e4b-S0
17:03:37 I1201 17:03:36.489476 27074 registrar.cpp:487] Applied 1 operations in
40208ns; attempting to update the registry
17:03:37 I1201 17:03:36.489609 27074 registrar.cpp:544] Successfully updated
the registry in 114176ns
17:03:37 I1201 17:03:36.489722 27073 master.cpp:6830] Admitted agent
851721f2-f8da-4afb-8248-1c66dcf55e4b-S0 at slave(81)@172.16.10.14:43373
(ip-172-16-10-14.ec2.internal)
17:03:37 I1201 17:03:36.489835 27073 master.cpp:6875] Registered agent
851721f2-f8da-4afb-8248-1c66dcf55e4b-S0 at slave(81)@172.16.10.14:43373
(ip-172-16-10-14.ec2.internal) with cpus:1000; mem:1000; disk:35068;
ports:[31000-32000]
17:03:37 I1201 17:03:36.489886 27072 hierarchical.cpp:603] Added agent
851721f2-f8da-4afb-8248-1c66dcf55e4b-S0 (ip-172-16-10-14.ec2.internal) with
cpus:1000; mem:1000; disk:35068; ports:[31000-32000] (allocated: {})
17:03:37 I1201 17:03:36.489948 27073 slave.cpp:1484] Registered with master
[email protected]:43373; given agent ID
851721f2-f8da-4afb-8248-1c66dcf55e4b-S0
17:03:37 I1201 17:03:36.489982 27075 task_status_update_manager.cpp:188]
Resuming sending task status updates
17:03:37 I1201 17:03:36.490088 27072 hierarchical.cpp:1566] Performed
allocation for 1 agents in 13835ns
17:03:37 I1201 17:03:36.490159 27073 slave.cpp:1504] Checkpointing SlaveInfo to
'/tmp/FetcherCacheTest_SimpleEviction_ZVKWJj/meta/slaves/851721f2-f8da-4afb-8248-1c66dcf55e4b-S0/slave.info'
17:03:37 I1201 17:03:36.490435 27073 slave.cpp:1553] Forwarding agent update
{"operations":{},"resource_version_uuid":{"value":"dr0P4gGHTEK7+hB8014xTQ=="},"slave_id":{"value":"851721f2-f8da-4afb-8248-1c66dcf55e4b-S0"},"update_oversubscribed_resources":false}
17:03:37 I1201 17:03:36.490615 27073 master.cpp:7934] Ignoring update on agent
851721f2-f8da-4afb-8248-1c66dcf55e4b-S0 at slave(81)@172.16.10.14:43373
(ip-172-16-10-14.ec2.internal) as it reports no changes
17:03:37 I1201 17:03:36.491401 27052 sched.cpp:232] Version: 1.8.0
17:03:37 I1201 17:03:36.491606 27075 sched.cpp:336] New master detected at
[email protected]:43373
17:03:37 I1201 17:03:36.491642 27075 sched.cpp:401] Authenticating with master
[email protected]:43373
17:03:37 I1201 17:03:36.491652 27075 sched.cpp:408] Using default CRAM-MD5
authenticatee
17:03:37 I1201 17:03:36.491739 27075 authenticatee.cpp:121] Creating new client
SASL connection
17:03:37 I1201 17:03:36.491814 27075 master.cpp:9649] Authenticating
[email protected]:43373
17:03:37 I1201 17:03:36.491855 27075 authenticator.cpp:414] Starting
authentication session for crammd5-authenticatee(187)@172.16.10.14:43373
17:03:37 I1201 17:03:36.491904 27075 authenticator.cpp:98] Creating new server
SASL connection
17:03:37 I1201 17:03:36.491957 27075 authenticatee.cpp:213] Received SASL
authentication mechanisms: CRAM-MD5
17:03:37 I1201 17:03:36.491969 27075 authenticatee.cpp:239] Attempting to
authenticate with mechanism 'CRAM-MD5'
17:03:37 I1201 17:03:36.491994 27075 authenticator.cpp:204] Received SASL
authentication start
17:03:37 I1201 17:03:36.492027 27075 authenticator.cpp:326] Authentication
requires more steps
17:03:37 I1201 17:03:36.492070 27075 authenticatee.cpp:259] Received SASL
authentication step
17:03:37 I1201 17:03:36.492105 27075 authenticator.cpp:232] Received SASL
authentication step
17:03:37 I1201 17:03:36.492120 27075 auxprop.cpp:109] Request to lookup
properties for user: 'test-principal' realm: 'ip-172-16-10-14' server FQDN:
'ip-172-16-10-14' SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
17:03:37 I1201 17:03:36.492127 27075 auxprop.cpp:181] Looking up auxiliary
property '*userPassword'
17:03:37 I1201 17:03:36.492137 27075 auxprop.cpp:181] Looking up auxiliary
property '*cmusaslsecretCRAM-MD5'
17:03:37 I1201 17:03:36.492146 27075 auxprop.cpp:109] Request to lookup
properties for user: 'test-principal' realm: 'ip-172-16-10-14' server FQDN:
'ip-172-16-10-14' SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
17:03:37 I1201 17:03:36.492153 27075 auxprop.cpp:131] Skipping auxiliary
property '*userPassword' since SASL_AUXPROP_AUTHZID == true
17:03:37 I1201 17:03:36.492159 27075 auxprop.cpp:131] Skipping auxiliary
property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
17:03:37 I1201 17:03:36.492172 27075 authenticator.cpp:318] Authentication
success
17:03:37 I1201 17:03:36.492203 27075 authenticatee.cpp:299] Authentication
success
17:03:37 I1201 17:03:36.492236 27075 master.cpp:9681] Successfully
authenticated principal 'test-principal' at
[email protected]:43373
17:03:37 I1201 17:03:36.492259 27075 authenticator.cpp:432] Authentication
session cleanup for crammd5-authenticatee(187)@172.16.10.14:43373
17:03:37 I1201 17:03:36.492311 27075 sched.cpp:513] Successfully authenticated
with master [email protected]:43373
17:03:37 I1201 17:03:36.492321 27075 sched.cpp:817] Sending SUBSCRIBE call to
[email protected]:43373
17:03:37 I1201 17:03:36.492353 27075 sched.cpp:850] Will retry registration in
807.834975ms if necessary
17:03:37 I1201 17:03:36.492434 27075 master.cpp:2860] Received SUBSCRIBE call
for framework 'default' at
[email protected]:43373
17:03:37 W1201 17:03:36.492455 27075 master.cpp:2868] Setting 'principal' in
FrameworkInfo to 'test-principal' because the framework authenticated with that
principal but did not set it in FrameworkInfo
17:03:37 I1201 17:03:36.492470 27075 master.cpp:2161] Authorizing framework
principal 'test-principal' to receive offers for roles '{ * }'
17:03:37 I1201 17:03:36.492547 27075 master.cpp:2941] Subscribing framework
default with checkpointing enabled and capabilities [ ]
17:03:37 I1201 17:03:36.493037 27075 master.cpp:9879] Adding framework
851721f2-f8da-4afb-8248-1c66dcf55e4b-0000 (default) at
[email protected]:43373 with roles {
} suppressed
17:03:37 I1201 17:03:36.493253 27074 sched.cpp:744] Framework registered with
851721f2-f8da-4afb-8248-1c66dcf55e4b-0000
17:03:37 I1201 17:03:36.493288 27074 sched.cpp:758] Scheduler::registered took
11324ns
17:03:37 I1201 17:03:36.493468 27075 hierarchical.cpp:304] Added framework
851721f2-f8da-4afb-8248-1c66dcf55e4b-0000
17:03:37 I1201 17:03:36.493628 27075 hierarchical.cpp:1566] Performed
allocation for 1 agents in 114984ns
17:03:37 I1201 17:03:36.493801 27075 master.cpp:9464] Sending offers [
851721f2-f8da-4afb-8248-1c66dcf55e4b-O0 ] to framework
851721f2-f8da-4afb-8248-1c66dcf55e4b-0000 (default) at
[email protected]:43373
17:03:37 I1201 17:03:36.494027 27075 sched.cpp:914] Scheduler::resourceOffers
took 17454ns
17:03:38 I1201 17:03:37.471371 27073 hierarchical.cpp:1566] Performed
allocation for 1 agents in 45500ns
17:03:39 I1201 17:03:38.472393 27074 hierarchical.cpp:1566] Performed
allocation for 1 agents in 44442ns
17:03:40 I1201 17:03:39.473476 27079 hierarchical.cpp:1566] Performed
allocation for 1 agents in 44121ns
17:03:41 I1201 17:03:40.473913 27072 hierarchical.cpp:1566] Performed
allocation for 1 agents in 42439ns
17:03:42 I1201 17:03:41.474455 27077 hierarchical.cpp:1566] Performed
allocation for 1 agents in 43706ns
17:03:43 I1201 17:03:42.475361 27073 hierarchical.cpp:1566] Performed
allocation for 1 agents in 44375ns
17:03:44 I1201 17:03:43.475981 27074 hierarchical.cpp:1566] Performed
allocation for 1 agents in 44258ns
17:03:45 I1201 17:03:44.476438 27076 hierarchical.cpp:1566] Performed
allocation for 1 agents in 43860ns
17:03:46 I1201 17:03:45.476824 27078 hierarchical.cpp:1566] Performed
allocation for 1 agents in 43903ns
17:03:47 I1201 17:03:46.477864 27073 hierarchical.cpp:1566] Performed
allocation for 1 agents in 45218ns
17:03:48 I1201 17:03:47.478896 27077 hierarchical.cpp:1566] Performed
allocation for 1 agents in 43071ns
17:03:49 I1201 17:03:48.479848 27072 hierarchical.cpp:1566] Performed
allocation for 1 agents in 44045ns
17:03:50 I1201 17:03:49.481199 27075 hierarchical.cpp:1566] Performed
allocation for 1 agents in 43578ns
17:03:51 I1201 17:03:50.482036 27073 hierarchical.cpp:1566] Performed
allocation for 1 agents in 44314ns
17:03:52 I1201 17:03:51.483171 27077 hierarchical.cpp:1566] Performed
allocation for 1 agents in 43829ns
17:03:52 ../../src/tests/fetcher_cache_tests.cpp:1467: Failure
17:03:52 task: Failed to wait for resource offers: discarded
17:03:52 Begin listing sandboxes
17:03:52 End sandboxes
17:03:52 I1201 17:03:51.494846 27052 sched.cpp:2008] Asked to stop the driver
17:03:52 I1201 17:03:51.494887 27077 sched.cpp:1184] Stopping framework
851721f2-f8da-4afb-8248-1c66dcf55e4b-0000
17:03:52 I1201 17:03:51.494997 27079 master.cpp:10181] Processing TEARDOWN call
for framework 851721f2-f8da-4afb-8248-1c66dcf55e4b-0000 (default) at
[email protected]:43373
17:03:52 I1201 17:03:51.495028 27079 master.cpp:10193] Removing framework
851721f2-f8da-4afb-8248-1c66dcf55e4b-0000 (default) at
[email protected]:43373
17:03:52 I1201 17:03:51.495040 27079 master.cpp:3236] Deactivating framework
851721f2-f8da-4afb-8248-1c66dcf55e4b-0000 (default) at
[email protected]:43373
17:03:52 I1201 17:03:51.495111 27072 hierarchical.cpp:418] Deactivated
framework 851721f2-f8da-4afb-8248-1c66dcf55e4b-0000
17:03:52 I1201 17:03:51.495266 27074 hierarchical.cpp:1238] Recovered
cpus(allocated: *):1000; mem(allocated: *):1000; disk(allocated: *):35068;
ports(allocated: *):[31000-32000] (total: cpus:1000; mem:1000; disk:35068;
ports:[31000-32000], allocated: {}) on agent
851721f2-f8da-4afb-8248-1c66dcf55e4b-S0 from framework
851721f2-f8da-4afb-8248-1c66dcf55e4b-0000
17:03:52 I1201 17:03:51.495348 27079 master.cpp:11463] Removing offer
851721f2-f8da-4afb-8248-1c66dcf55e4b-O0
17:03:52 I1201 17:03:51.495450 27079 slave.cpp:3901] Asked to shut down
framework 851721f2-f8da-4afb-8248-1c66dcf55e4b-0000 by [email protected]:43373
17:03:52 I1201 17:03:51.495465 27079 slave.cpp:3916] Cannot shut down unknown
framework 851721f2-f8da-4afb-8248-1c66dcf55e4b-0000
17:03:52 I1201 17:03:51.495546 27079 hierarchical.cpp:357] Removed framework
851721f2-f8da-4afb-8248-1c66dcf55e4b-0000
17:03:52 I1201 17:03:51.495776 27077 master.cpp:1117] Master terminating
17:03:52 I1201 17:03:51.495856 27074 hierarchical.cpp:643] Removed agent
851721f2-f8da-4afb-8248-1c66dcf55e4b-S0
17:03:52 I1201 17:03:51.495944 27077 slave.cpp:5898] Got exited event for
[email protected]:43373
17:03:52 W1201 17:03:51.495956 27077 slave.cpp:5903] Master disconnected!
Waiting for a new master to be elected
17:03:52 I1201 17:03:51.504190 27052 slave.cpp:914] Agent terminating
17:03:52 [ FAILED ] FetcherCacheTest.SimpleEviction (15053 ms){noformat}
> FetcherCacheTest.SimpleEviction is flaky
> ----------------------------------------
>
> Key: MESOS-2831
> URL: https://issues.apache.org/jira/browse/MESOS-2831
> Project: Mesos
> Issue Type: Bug
> Components: fetcher
> Affects Versions: 0.23.0, 1.8.0
> Reporter: Vinod Kone
> Priority: Major
> Labels: containerizer, flaky-test, mesosphere
>
> Saw this when reviewbot was testing an unrelated review
> https://reviews.apache.org/r/35119/
> {code}
> [ RUN ] FetcherCacheTest.SimpleEviction
> GMOCK WARNING:
> Uninteresting mock function call - returning directly.
> Function call: resourceOffers(0x5365320, @0x2b7bef9f1b20 { 128-byte
> object <B0-C0 36-E6 7B-2B 00-00 00-00 00-00 00-00 00-00 20-75 00-18 7C-2B
> 00-00 C0-75 00-18 7C-2B 00-00 60-76 00-18 7C-2B 00-00 00-77 00-18 7C-2B 00-00
> 40-3A 00-18 7C-2B 00-00 04-00 00-00 04-00 00-00 04-00 00-00 7C-2B 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 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 00-00 0F-00
> 00-00> })
> Stack trace:
> F0607 21:19:23.181392 4246 fetcher_cache_tests.cpp:354] CHECK_READY(offers):
> is PENDING Failed to wait for resource offers
> *** Check failure stack trace: ***
> @ 0x2b7be56c5972 google::LogMessage::Fail()
> @ 0x2b7be56c58be google::LogMessage::SendToLog()
> @ 0x2b7be56c52c0 google::LogMessage::Flush()
> @ 0x2b7be56c81d4 google::LogMessageFatal::~LogMessageFatal()
> @ 0x97d182 _CheckFatal::~_CheckFatal()
> @ 0xb58a28
> mesos::internal::tests::FetcherCacheTest::launchTask()
> @ 0xb65b50
> mesos::internal::tests::FetcherCacheTest_SimpleEviction_Test::TestBody()
> @ 0x11923b7
> testing::internal::HandleSehExceptionsInMethodIfSupported<>()
> @ 0x118d5b4
> testing::internal::HandleExceptionsInMethodIfSupported<>()
> @ 0x1175975 testing::Test::Run()
> @ 0x1176098 testing::TestInfo::Run()
> @ 0x1176620 testing::TestCase::Run()
> @ 0x117b2ea testing::internal::UnitTestImpl::RunAllTests()
> @ 0x1193229
> testing::internal::HandleSehExceptionsInMethodIfSupported<>()
> @ 0x118e2a5
> testing::internal::HandleExceptionsInMethodIfSupported<>()
> @ 0x117a1f6 testing::UnitTest::Run()
> @ 0xcc832b main
> @ 0x2b7be7d46ec5 (unknown)
> @ 0x872379 (unknown)
> {code}
--
This message was sent by Atlassian JIRA
(v7.6.3#76005)
