mesos-issues mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Gilbert Song (JIRA)" <j...@apache.org>
Subject [jira] [Created] (MESOS-9371) `FetcherCacheTest.RemoveLRUCacheEntries` is flaky.
Date Wed, 07 Nov 2018 21:31:00 GMT
Gilbert Song created MESOS-9371:
-----------------------------------

             Summary: `FetcherCacheTest.RemoveLRUCacheEntries` is flaky.
                 Key: MESOS-9371
                 URL: https://issues.apache.org/jira/browse/MESOS-9371
             Project: Mesos
          Issue Type: Bug
            Reporter: Gilbert Song


{noformat}
[ RUN      ] FetcherCacheTest.RemoveLRUCacheEntries
I1107 13:20:28.161957 39728 cluster.cpp:172] Creating default 'local' authorizer
I1107 13:20:28.165024 39777 master.cpp:457] Master f7977f54-bb98-445f-9610-ede08bf34093 (core-dev)
started on 10.0.49.2:41973
I1107 13:20:28.165122 39777 master.cpp:459] 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/ds9Byj/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" --min_allocatable_resources="cpus:0.01|mem:32"
--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" --role_sorter="drf" --root_submissions="true" --version="false"
--webui_dir="/usr/local/share/mesos/webui" --work_dir="/tmp/ds9Byj/master" --zk_session_timeout="10secs"
I1107 13:20:28.169046 39777 master.cpp:508] Master only allowing authenticated frameworks
to register
I1107 13:20:28.169070 39777 master.cpp:514] Master only allowing authenticated agents to register
I1107 13:20:28.169093 39777 master.cpp:520] Master only allowing authenticated HTTP frameworks
to register
I1107 13:20:28.169121 39777 credentials.hpp:37] Loading credentials for authentication from
'/tmp/ds9Byj/credentials'
I1107 13:20:28.169910 39777 master.cpp:564] Using default 'crammd5' authenticator
I1107 13:20:28.170156 39777 authenticator.cpp:520] Initializing server SASL
I1107 13:20:28.171118 39777 http.cpp:1045] Creating default 'basic' HTTP authenticator for
realm 'mesos-master-readonly'
I1107 13:20:28.171545 39777 http.cpp:1045] Creating default 'basic' HTTP authenticator for
realm 'mesos-master-readwrite'
I1107 13:20:28.171684 39777 http.cpp:1045] Creating default 'basic' HTTP authenticator for
realm 'mesos-master-scheduler'
I1107 13:20:28.171854 39777 master.cpp:643] Authorization enabled
I1107 13:20:28.185091 39744 master.cpp:2247] Elected as the leading master!
I1107 13:20:28.185139 39744 master.cpp:1727] Recovering from registrar
I1107 13:20:28.188170 39752 registrar.cpp:391] Successfully fetched the registry (0B) in 2.571008ms
I1107 13:20:28.188540 39752 registrar.cpp:495] Applied 1 operations in 122344ns; attempting
to update the registry
I1107 13:20:28.191902 39752 registrar.cpp:552] Successfully updated the registry in 3.163904ms
I1107 13:20:28.192203 39752 registrar.cpp:424] Successfully recovered registrar
I1107 13:20:28.193151 39756 master.cpp:1840] Recovered 0 agents from the registry (123B);
allowing 10mins for agents to re-register
I1107 13:20:28.194456 39728 containerizer.cpp:304] Using isolation { environment_secret, posix/cpu,
posix/mem, filesystem/posix, network/cni }
W1107 13:20:28.195065 39728 backend.cpp:76] Failed to create 'overlay' backend: OverlayBackend
requires root privileges
W1107 13:20:28.195108 39728 backend.cpp:76] Failed to create 'bind' backend: BindBackend requires
root privileges
I1107 13:20:28.195156 39728 provisioner.cpp:299] Using default backend 'copy'
W1107 13:20:28.198040 39728 process.cpp:2745] Attempted to spawn already running process files@10.0.49.2:41973
I1107 13:20:28.198199 39728 cluster.cpp:460] Creating default 'local' authorizer
I1107 13:20:28.199762 39789 slave.cpp:261] Mesos agent started on (1)@10.0.49.2:41973
I1107 13:20:28.199816 39789 slave.cpp:262] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://"
--appc_store_dir="/tmp/FetcherCacheTest_RemoveLRUCacheEntries_bzpwJi/store/appc" --authenticate_http_readonly="true"
--authenticate_http_readwrite="false" --authenticatee="crammd5" --authentication_backoff_factor="1secs"
--authentication_timeout_max="1mins" --authentication_timeout_min="5secs" --authorizer="local"
--cgroups_cpu_enable_pids_and_tids_count="false" --cgroups_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_RemoveLRUCacheEntries_bzpwJi/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_RemoveLRUCacheEntries_bzpwJi/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_RemoveLRUCacheEntries_bzpwJi/fetch"
--fetcher_cache_size="60B" --fetcher_stall_timeout="1mins" --frameworks_home="" --gc_delay="1weeks"
--gc_disk_headroom="0.1" --hadoop_home="" --help="false" --hostname_lookup="true" --http_command_executor="false"
--http_credentials="/tmp/FetcherCacheTest_RemoveLRUCacheEntries_bzpwJi/http_credentials" --http_heartbeat_interval="30secs"
--initialize_driver_logging="true" --isolation="posix/cpu,posix/mem" --launcher="posix" --launcher_dir="/home/gilbert/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:1000;mem:1000" --revocable_cpu_low_priority="true"
--runtime_dir="/tmp/FetcherCacheTest_RemoveLRUCacheEntries_bzpwJi" --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_RemoveLRUCacheEntries_aJU38i" --zk_session_timeout="10secs"
I1107 13:20:28.200455 39789 credentials.hpp:86] Loading credential for authentication from
'/tmp/FetcherCacheTest_RemoveLRUCacheEntries_bzpwJi/credential'
I1107 13:20:28.200681 39789 slave.cpp:294] Agent using credential for: test-principal
I1107 13:20:28.200724 39789 credentials.hpp:37] Loading credentials for authentication from
'/tmp/FetcherCacheTest_RemoveLRUCacheEntries_bzpwJi/http_credentials'
I1107 13:20:28.200971 39789 http.cpp:1045] Creating default 'basic' HTTP authenticator for
realm 'mesos-agent-readonly'
I1107 13:20:28.202383 39789 slave.cpp:611] Agent resources: [{"name":"cpus","scalar":{"value":1000.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":1000.0},"type":"SCALAR"},{"name":"disk","scalar":{"value":46053.0},"type":"SCALAR"},{"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}]
I1107 13:20:28.202714 39789 slave.cpp:619] Agent attributes: [  ]
I1107 13:20:28.202750 39789 slave.cpp:628] Agent hostname: core-dev
I1107 13:20:28.203182 39743 task_status_update_manager.cpp:181] Pausing sending task status
updates
I1107 13:20:28.206714 39755 state.cpp:66] Recovering state from '/tmp/FetcherCacheTest_RemoveLRUCacheEntries_aJU38i/meta'
I1107 13:20:28.207412 39750 task_status_update_manager.cpp:207] Recovering task status update
manager
I1107 13:20:28.207798 39757 containerizer.cpp:674] Recovering containerizer
I1107 13:20:28.211381 39766 provisioner.cpp:495] Provisioner recovery complete
I1107 13:20:28.212124 39771 slave.cpp:7330] Finished recovery
I1107 13:20:28.213066 39772 task_status_update_manager.cpp:181] Pausing sending task status
updates
I1107 13:20:28.213106 39771 slave.cpp:1262] New master detected at master@10.0.49.2:41973
I1107 13:20:28.213232 39771 slave.cpp:1327] Detecting new master
I1107 13:20:28.218950 39778 slave.cpp:1354] Authenticating with master master@10.0.49.2:41973
I1107 13:20:28.219066 39778 slave.cpp:1363] Using default CRAM-MD5 authenticatee
I1107 13:20:28.219641 39775 authenticatee.cpp:97] Initializing client SASL
I1107 13:20:28.219825 39775 authenticatee.cpp:121] Creating new client SASL connection
I1107 13:20:28.220322 39780 master.cpp:9059] Authenticating slave(1)@10.0.49.2:41973
I1107 13:20:28.221060 39782 authenticator.cpp:98] Creating new server SASL connection
I1107 13:20:28.221434 39783 authenticatee.cpp:213] Received SASL authentication mechanisms:
CRAM-MD5
I1107 13:20:28.221490 39783 authenticatee.cpp:239] Attempting to authenticate with mechanism
'CRAM-MD5'
I1107 13:20:28.221662 39787 authenticator.cpp:204] Received SASL authentication start
I1107 13:20:28.221809 39787 authenticator.cpp:326] Authentication requires more steps
I1107 13:20:28.221963 39787 authenticatee.cpp:259] Received SASL authentication step
I1107 13:20:28.222141 39747 authenticator.cpp:232] Received SASL authentication step
I1107 13:20:28.222296 39747 authenticator.cpp:318] Authentication success
I1107 13:20:28.222481 39777 authenticatee.cpp:299] Authentication success
I1107 13:20:28.222745 39785 master.cpp:9091] Successfully authenticated principal 'test-principal'
at slave(1)@10.0.49.2:41973
I1107 13:20:28.222930 39784 slave.cpp:1454] Successfully authenticated with master master@10.0.49.2:41973
I1107 13:20:28.223770 39746 master.cpp:6146] Received register agent message from slave(1)@10.0.49.2:41973
(core-dev)
I1107 13:20:28.223964 39746 master.cpp:3911] Authorizing agent with principal 'test-principal'
I1107 13:20:28.225159 39753 master.cpp:6315] Registering agent at slave(1)@10.0.49.2:41973
(core-dev) with id f7977f54-bb98-445f-9610-ede08bf34093-S0
I1107 13:20:28.226071 39751 registrar.cpp:495] Applied 1 operations in 234510ns; attempting
to update the registry
I1107 13:20:28.228108 39751 registrar.cpp:552] Successfully updated the registry in 1.930752ms
I1107 13:20:28.229776 39761 master.cpp:6412] Registered agent f7977f54-bb98-445f-9610-ede08bf34093-S0
at slave(1)@10.0.49.2:41973 (core-dev) with cpus:1000; mem:1000; disk:46053; ports:[31000-32000]
I1107 13:20:28.230113 39762 slave.cpp:1486] Registered with master master@10.0.49.2:41973;
given agent ID f7977f54-bb98-445f-9610-ede08bf34093-S0
I1107 13:20:28.230247 39756 task_status_update_manager.cpp:188] Resuming sending task status
updates
I1107 13:20:28.230576 39760 hierarchical.cpp:576] Added agent f7977f54-bb98-445f-9610-ede08bf34093-S0
(core-dev) with cpus:1000; mem:1000; disk:46053; ports:[31000-32000] (allocated: {})
I1107 13:20:28.231068 39728 sched.cpp:232] Version: 1.5.2
I1107 13:20:28.231282 39762 slave.cpp:1553] Forwarding agent update {"operations":{},"resource_version_uuid":{"value":"R\/u701ANQpKRXrXDq+uQog=="},"slave_id":{"value":"f7977f54-bb98-445f-9610-ede08bf34093-S0"},"update_oversubscribed_resources":true}
I1107 13:20:28.231889 39774 master.cpp:7339] Received update of agent f7977f54-bb98-445f-9610-ede08bf34093-S0
at slave(1)@10.0.49.2:41973 (core-dev) with total oversubscribed resources {}
I1107 13:20:28.232173 39776 sched.cpp:336] New master detected at master@10.0.49.2:41973
I1107 13:20:28.232216 39774 master.cpp:7433] Ignoring update on agent f7977f54-bb98-445f-9610-ede08bf34093-S0
at slave(1)@10.0.49.2:41973 (core-dev) as it reports no changes
I1107 13:20:28.232291 39776 sched.cpp:401] Authenticating with master master@10.0.49.2:41973
I1107 13:20:28.232326 39776 sched.cpp:408] Using default CRAM-MD5 authenticatee
I1107 13:20:28.232530 39771 authenticatee.cpp:121] Creating new client SASL connection
I1107 13:20:28.232861 39778 master.cpp:9059] Authenticating scheduler-1733bec2-b206-47a9-a8b4-6bb319d8eb92@10.0.49.2:41973
I1107 13:20:28.233188 39780 authenticator.cpp:98] Creating new server SASL connection
I1107 13:20:28.233477 39786 authenticatee.cpp:213] Received SASL authentication mechanisms:
CRAM-MD5
I1107 13:20:28.233522 39786 authenticatee.cpp:239] Attempting to authenticate with mechanism
'CRAM-MD5'
I1107 13:20:28.233618 39786 authenticator.cpp:204] Received SASL authentication start
I1107 13:20:28.233675 39786 authenticator.cpp:326] Authentication requires more steps
I1107 13:20:28.233758 39786 authenticatee.cpp:259] Received SASL authentication step
I1107 13:20:28.233881 39788 authenticator.cpp:232] Received SASL authentication step
I1107 13:20:28.233960 39788 authenticator.cpp:318] Authentication success
I1107 13:20:28.234045 39787 authenticatee.cpp:299] Authentication success
I1107 13:20:28.234163 39745 master.cpp:9091] Successfully authenticated principal 'test-principal'
at scheduler-1733bec2-b206-47a9-a8b4-6bb319d8eb92@10.0.49.2:41973
I1107 13:20:28.234391 39747 sched.cpp:514] Successfully authenticated with master master@10.0.49.2:41973
I1107 13:20:28.234825 39784 master.cpp:3002] Received SUBSCRIBE call for framework 'default'
at scheduler-1733bec2-b206-47a9-a8b4-6bb319d8eb92@10.0.49.2:41973
W1107 13:20:28.234877 39784 master.cpp:3010] Setting 'principal' in FrameworkInfo to 'test-principal'
because the framework authenticated with that principal but did not set it in FrameworkInfo
I1107 13:20:28.234912 39784 master.cpp:2319] Authorizing framework principal 'test-principal'
to receive offers for roles '{ * }'
I1107 13:20:28.235620 39749 master.cpp:3082] Subscribing framework default with checkpointing
enabled and capabilities [  ]
I1107 13:20:28.236039 39749 master.cpp:9289] Adding framework f7977f54-bb98-445f-9610-ede08bf34093-0000
(default) at scheduler-1733bec2-b206-47a9-a8b4-6bb319d8eb92@10.0.49.2:41973 with roles { 
} suppressed
I1107 13:20:28.236717 39749 sched.cpp:746] Framework registered with f7977f54-bb98-445f-9610-ede08bf34093-0000
I1107 13:20:28.237150 39753 hierarchical.cpp:299] Added framework f7977f54-bb98-445f-9610-ede08bf34093-0000
I1107 13:20:28.239576 39755 master.cpp:8893] Sending 1 offers to framework f7977f54-bb98-445f-9610-ede08bf34093-0000
(default) at scheduler-1733bec2-b206-47a9-a8b4-6bb319d8eb92@10.0.49.2:41973
I1107 13:20:28.242939 39756 master.cpp:10830] Removing offer f7977f54-bb98-445f-9610-ede08bf34093-O0
I1107 13:20:28.243361 39756 master.cpp:4330] Processing ACCEPT call for offers: [ f7977f54-bb98-445f-9610-ede08bf34093-O0
] on agent f7977f54-bb98-445f-9610-ede08bf34093-S0 at slave(1)@10.0.49.2:41973 (core-dev)
for framework f7977f54-bb98-445f-9610-ede08bf34093-0000 (default) at scheduler-1733bec2-b206-47a9-a8b4-6bb319d8eb92@10.0.49.2:41973
I1107 13:20:28.243461 39756 master.cpp:3638] Authorizing framework principal 'test-principal'
to launch task 0
I1107 13:20:28.245926 39760 master.cpp:11588] Adding task 0 with resources cpus(allocated:
*):1; mem(allocated: *):1 on agent f7977f54-bb98-445f-9610-ede08bf34093-S0 at slave(1)@10.0.49.2:41973
(core-dev)
I1107 13:20:28.246232 39760 master.cpp:5090] Launching task 0 of framework f7977f54-bb98-445f-9610-ede08bf34093-0000
(default) at scheduler-1733bec2-b206-47a9-a8b4-6bb319d8eb92@10.0.49.2:41973 with resources
[{"allocation_info":{"role":"*"},"name":"cpus","scalar":{"value":1.0},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"mem","scalar":{"value":1.0},"type":"SCALAR"}]
on agent f7977f54-bb98-445f-9610-ede08bf34093-S0 at slave(1)@10.0.49.2:41973 (core-dev) on
 new executor
I1107 13:20:28.247491 39770 slave.cpp:2021] Got assigned task '0' for framework f7977f54-bb98-445f-9610-ede08bf34093-0000
I1107 13:20:28.250591 39770 slave.cpp:2395] Authorizing task '0' for framework f7977f54-bb98-445f-9610-ede08bf34093-0000
I1107 13:20:28.250668 39770 slave.cpp:8447] Authorizing framework principal 'test-principal'
to launch task 0
I1107 13:20:28.252602 39776 slave.cpp:2869] Launching task '0' for framework f7977f54-bb98-445f-9610-ede08bf34093-0000
I1107 13:20:28.254923 39776 paths.cpp:756] Trying to chown '/tmp/FetcherCacheTest_RemoveLRUCacheEntries_aJU38i/slaves/f7977f54-bb98-445f-9610-ede08bf34093-S0/frameworks/f7977f54-bb98-445f-9610-ede08bf34093-0000/executors/0/runs/b0c1d94a-5bfe-443d-b284-be33a81924e7'
to user 'gilbert'
I1107 13:20:28.256227 39776 slave.cpp:8938] Launching executor '0' of framework f7977f54-bb98-445f-9610-ede08bf34093-0000
with resources [{"allocation_info":{"role":"*"},"name":"cpus","scalar":{"value":0.1},"type":"SCALAR"},{"allocation_info":{"role":"*"},"name":"mem","scalar":{"value":32.0},"type":"SCALAR"}]
in work directory '/tmp/FetcherCacheTest_RemoveLRUCacheEntries_aJU38i/slaves/f7977f54-bb98-445f-9610-ede08bf34093-S0/frameworks/f7977f54-bb98-445f-9610-ede08bf34093-0000/executors/0/runs/b0c1d94a-5bfe-443d-b284-be33a81924e7'
I1107 13:20:28.257133 39776 slave.cpp:3565] Launching container b0c1d94a-5bfe-443d-b284-be33a81924e7
for executor '0' of framework f7977f54-bb98-445f-9610-ede08bf34093-0000
I1107 13:20:28.258895 39776 slave.cpp:3085] Queued task '0' for executor '0' of framework
f7977f54-bb98-445f-9610-ede08bf34093-0000
I1107 13:20:28.259526 39775 containerizer.cpp:1209] Starting container b0c1d94a-5bfe-443d-b284-be33a81924e7
I1107 13:20:28.262679 39775 containerizer.cpp:2993] Transitioning the state of container b0c1d94a-5bfe-443d-b284-be33a81924e7
from PROVISIONING to PREPARING
I1107 13:20:28.272727 39743 launcher.cpp:151] Forked child with pid '39804' for container
'b0c1d94a-5bfe-443d-b284-be33a81924e7'
I1107 13:20:28.273000 39743 containerizer.cpp:1965] Checkpointing container's forked pid 39804
to '/tmp/FetcherCacheTest_RemoveLRUCacheEntries_aJU38i/meta/slaves/f7977f54-bb98-445f-9610-ede08bf34093-S0/frameworks/f7977f54-bb98-445f-9610-ede08bf34093-0000/executors/0/runs/b0c1d94a-5bfe-443d-b284-be33a81924e7/pids/forked.pid'
I1107 13:20:28.274046 39743 containerizer.cpp:2993] Transitioning the state of container b0c1d94a-5bfe-443d-b284-be33a81924e7
from PREPARING to ISOLATING
I1107 13:20:28.275709 39743 containerizer.cpp:2993] Transitioning the state of container b0c1d94a-5bfe-443d-b284-be33a81924e7
from ISOLATING to FETCHING
W1107 13:20:28.416662 39773 fetcher.cpp:912] Begin fetcher log (stderr in sandbox) for container
b0c1d94a-5bfe-443d-b284-be33a81924e7 from running command: /home/gilbert/mesos/build/src/mesos-fetcher
I1107 13:20:28.373706 39811 fetcher.cpp:560] Fetcher Info: {"cache_directory":"\/tmp\/FetcherCacheTest_RemoveLRUCacheEntries_bzpwJi\/fetch\/gilbert","items":[{"action":"DOWNLOAD_AND_CACHE","cache_filename":"c1-cmd0","uri":{"cache":true,"executable":true,"extract":true,"value":"\/tmp\/FetcherCacheTest_RemoveLRUCacheEntries_aJU38i\/mesos-fetcher-test-assets\/cmd0"}}],"sandbox_directory":"\/tmp\/FetcherCacheTest_RemoveLRUCacheEntries_aJU38i\/slaves\/f7977f54-bb98-445f-9610-ede08bf34093-S0\/frameworks\/f7977f54-bb98-445f-9610-ede08bf34093-0000\/executors\/0\/runs\/b0c1d94a-5bfe-443d-b284-be33a81924e7","stall_timeout":{"nanoseconds":60000000000},"user":"gilbert"}
I1107 13:20:28.384097 39811 fetcher.cpp:457] Fetching URI '/tmp/FetcherCacheTest_RemoveLRUCacheEntries_aJU38i/mesos-fetcher-test-assets/cmd0'
I1107 13:20:28.384130 39811 fetcher.cpp:431] Downloading into cache
I1107 13:20:28.384142 39811 fetcher.cpp:227] Fetching URI '/tmp/FetcherCacheTest_RemoveLRUCacheEntries_aJU38i/mesos-fetcher-test-assets/cmd0'
I1107 13:20:28.386828 39811 fetcher.cpp:351] Fetching from cache
I1107 13:20:28.389147 39811 fetcher.cpp:617] Fetched '/tmp/FetcherCacheTest_RemoveLRUCacheEntries_aJU38i/mesos-fetcher-test-assets/cmd0'
to '/tmp/FetcherCacheTest_RemoveLRUCacheEntries_aJU38i/slaves/f7977f54-bb98-445f-9610-ede08bf34093-S0/frameworks/f7977f54-bb98-445f-9610-ede08bf34093-0000/executors/0/runs/b0c1d94a-5bfe-443d-b284-be33a81924e7/cmd0'
I1107 13:20:28.389169 39811 fetcher.cpp:622] Successfully fetched all URIs into '/tmp/FetcherCacheTest_RemoveLRUCacheEntries_aJU38i/slaves/f7977f54-bb98-445f-9610-ede08bf34093-S0/frameworks/f7977f54-bb98-445f-9610-ede08bf34093-0000/executors/0/runs/b0c1d94a-5bfe-443d-b284-be33a81924e7'

End fetcher log for container b0c1d94a-5bfe-443d-b284-be33a81924e7
E1107 13:20:28.416877 39773 fetcher.cpp:571] Failed to run mesos-fetcher: No status available
from mesos-fetcher
Failed to synchronize with agent (it's probably exited)
E1107 13:20:28.417824 39762 slave.cpp:6204] Container 'b0c1d94a-5bfe-443d-b284-be33a81924e7'
for executor '0' of framework f7977f54-bb98-445f-9610-ede08bf34093-0000 failed to start: No
status available from mesos-fetcher
I1107 13:20:28.418114 39769 containerizer.cpp:2375] Destroying container b0c1d94a-5bfe-443d-b284-be33a81924e7
in FETCHING state
I1107 13:20:28.418174 39769 containerizer.cpp:2993] Transitioning the state of container b0c1d94a-5bfe-443d-b284-be33a81924e7
from FETCHING to DESTROYING
I1107 13:20:28.419108 39769 launcher.cpp:167] Asked to destroy container b0c1d94a-5bfe-443d-b284-be33a81924e7
I1107 13:20:28.517963 39779 containerizer.cpp:2832] Container b0c1d94a-5bfe-443d-b284-be33a81924e7
has exited
I1107 13:20:28.522321 39758 slave.cpp:6333] Executor '0' of framework f7977f54-bb98-445f-9610-ede08bf34093-0000
exited with status 1
I1107 13:20:28.524320 39758 slave.cpp:5311] Handling status update TASK_FAILED (Status UUID:
7e2d6619-93b2-45de-8508-f945ad86de2a) for task 0 of framework f7977f54-bb98-445f-9610-ede08bf34093-0000
from @0.0.0.0:0
W1107 13:20:28.525140 39755 containerizer.cpp:2177] Ignoring update for unknown container
b0c1d94a-5bfe-443d-b284-be33a81924e7
I1107 13:20:28.525960 39750 task_status_update_manager.cpp:328] Received task status update
TASK_FAILED (Status UUID: 7e2d6619-93b2-45de-8508-f945ad86de2a) for task 0 of framework f7977f54-bb98-445f-9610-ede08bf34093-0000
I1107 13:20:28.526929 39750 task_status_update_manager.cpp:842] Checkpointing UPDATE for task
status update TASK_FAILED (Status UUID: 7e2d6619-93b2-45de-8508-f945ad86de2a) for task 0 of
framework f7977f54-bb98-445f-9610-ede08bf34093-0000
I1107 13:20:28.527523 39757 slave.cpp:5803] Forwarding the update TASK_FAILED (Status UUID:
7e2d6619-93b2-45de-8508-f945ad86de2a) for task 0 of framework f7977f54-bb98-445f-9610-ede08bf34093-0000
to master@10.0.49.2:41973
I1107 13:20:28.527943 39750 master.cpp:7985] Status update TASK_FAILED (Status UUID: 7e2d6619-93b2-45de-8508-f945ad86de2a)
for task 0 of framework f7977f54-bb98-445f-9610-ede08bf34093-0000 from agent f7977f54-bb98-445f-9610-ede08bf34093-S0
at slave(1)@10.0.49.2:41973 (core-dev)
I1107 13:20:28.528023 39750 master.cpp:8041] Forwarding status update TASK_FAILED (Status
UUID: 7e2d6619-93b2-45de-8508-f945ad86de2a) for task 0 of framework f7977f54-bb98-445f-9610-ede08bf34093-0000
I1107 13:20:28.528257 39750 master.cpp:10313] Updating the state of task 0 of framework f7977f54-bb98-445f-9610-ede08bf34093-0000
(latest state: TASK_FAILED, status update state: TASK_FAILED)
I1107 13:20:28.529274 39750 master.cpp:5914] Processing ACKNOWLEDGE call 7e2d6619-93b2-45de-8508-f945ad86de2a
for task 0 of framework f7977f54-bb98-445f-9610-ede08bf34093-0000 (default) at scheduler-1733bec2-b206-47a9-a8b4-6bb319d8eb92@10.0.49.2:41973
on agent f7977f54-bb98-445f-9610-ede08bf34093-S0
I1107 13:20:28.529394 39750 master.cpp:10417] Removing task 0 with resources cpus(allocated:
*):1; mem(allocated: *):1 of framework f7977f54-bb98-445f-9610-ede08bf34093-0000 on agent
f7977f54-bb98-445f-9610-ede08bf34093-S0 at slave(1)@10.0.49.2:41973 (core-dev)
I1107 13:20:28.530251 39763 task_status_update_manager.cpp:401] Received task status update
acknowledgement (UUID: 7e2d6619-93b2-45de-8508-f945ad86de2a) for task 0 of framework f7977f54-bb98-445f-9610-ede08bf34093-0000
I1107 13:20:28.530354 39763 task_status_update_manager.cpp:842] Checkpointing ACK for task
status update TASK_FAILED (Status UUID: 7e2d6619-93b2-45de-8508-f945ad86de2a) for task 0 of
framework f7977f54-bb98-445f-9610-ede08bf34093-0000
I1107 13:20:28.531067 39756 slave.cpp:6431] Cleaning up executor '0' of framework f7977f54-bb98-445f-9610-ede08bf34093-0000
I1107 13:20:28.531690 39767 gc.cpp:95] Scheduling '/tmp/FetcherCacheTest_RemoveLRUCacheEntries_aJU38i/slaves/f7977f54-bb98-445f-9610-ede08bf34093-S0/frameworks/f7977f54-bb98-445f-9610-ede08bf34093-0000/executors/0/runs/b0c1d94a-5bfe-443d-b284-be33a81924e7'
for gc 6.99999384877333days in the future
I1107 13:20:28.531982 39767 gc.cpp:95] Scheduling '/tmp/FetcherCacheTest_RemoveLRUCacheEntries_aJU38i/slaves/f7977f54-bb98-445f-9610-ede08bf34093-S0/frameworks/f7977f54-bb98-445f-9610-ede08bf34093-0000/executors/0'
for gc 6.99999384428444days in the future
I1107 13:20:28.532151 39756 slave.cpp:6560] Cleaning up framework f7977f54-bb98-445f-9610-ede08bf34093-0000
I1107 13:20:28.532166 39767 gc.cpp:95] Scheduling '/tmp/FetcherCacheTest_RemoveLRUCacheEntries_aJU38i/meta/slaves/f7977f54-bb98-445f-9610-ede08bf34093-S0/frameworks/f7977f54-bb98-445f-9610-ede08bf34093-0000/executors/0/runs/b0c1d94a-5bfe-443d-b284-be33a81924e7'
for gc 6.99999384350815days in the future
I1107 13:20:28.532282 39767 gc.cpp:95] Scheduling '/tmp/FetcherCacheTest_RemoveLRUCacheEntries_aJU38i/meta/slaves/f7977f54-bb98-445f-9610-ede08bf34093-S0/frameworks/f7977f54-bb98-445f-9610-ede08bf34093-0000/executors/0'
for gc 6.99999384303407days in the future
I1107 13:20:28.532343 39760 task_status_update_manager.cpp:289] Closing task status update
streams for framework f7977f54-bb98-445f-9610-ede08bf34093-0000
I1107 13:20:28.532397 39767 gc.cpp:95] Scheduling '/tmp/FetcherCacheTest_RemoveLRUCacheEntries_aJU38i/slaves/f7977f54-bb98-445f-9610-ede08bf34093-S0/frameworks/f7977f54-bb98-445f-9610-ede08bf34093-0000'
for gc 6.99999383965333days in the future
I1107 13:20:28.532516 39767 gc.cpp:95] Scheduling '/tmp/FetcherCacheTest_RemoveLRUCacheEntries_aJU38i/meta/slaves/f7977f54-bb98-445f-9610-ede08bf34093-S0/frameworks/f7977f54-bb98-445f-9610-ede08bf34093-0000'
for gc 6.99999383915556days in the future
I1107 13:20:29.175374 39771 master.cpp:8893] Sending 1 offers to framework f7977f54-bb98-445f-9610-ede08bf34093-0000
(default) at scheduler-1733bec2-b206-47a9-a8b4-6bb319d8eb92@10.0.49.2:41973
I1107 13:20:29.176127 39781 master.cpp:5555] Processing DECLINE call for offers: [ f7977f54-bb98-445f-9610-ede08bf34093-O1
] for framework f7977f54-bb98-445f-9610-ede08bf34093-0000 (default) at scheduler-1733bec2-b206-47a9-a8b4-6bb319d8eb92@10.0.49.2:41973
I1107 13:20:29.176542 39781 master.cpp:10830] Removing offer f7977f54-bb98-445f-9610-ede08bf34093-O1
I1107 13:20:34.184898 39754 master.cpp:8893] Sending 1 offers to framework f7977f54-bb98-445f-9610-ede08bf34093-0000
(default) at scheduler-1733bec2-b206-47a9-a8b4-6bb319d8eb92@10.0.49.2:41973
I1107 13:20:34.185727 39788 master.cpp:5555] Processing DECLINE call for offers: [ f7977f54-bb98-445f-9610-ede08bf34093-O2
] for framework f7977f54-bb98-445f-9610-ede08bf34093-0000 (default) at scheduler-1733bec2-b206-47a9-a8b4-6bb319d8eb92@10.0.49.2:41973
I1107 13:20:34.186174 39788 master.cpp:10830] Removing offer f7977f54-bb98-445f-9610-ede08bf34093-O2
I1107 13:20:39.191220 39758 master.cpp:8893] Sending 1 offers to framework f7977f54-bb98-445f-9610-ede08bf34093-0000
(default) at scheduler-1733bec2-b206-47a9-a8b4-6bb319d8eb92@10.0.49.2:41973
I1107 13:20:39.191926 39758 master.cpp:5555] Processing DECLINE call for offers: [ f7977f54-bb98-445f-9610-ede08bf34093-O3
] for framework f7977f54-bb98-445f-9610-ede08bf34093-0000 (default) at scheduler-1733bec2-b206-47a9-a8b4-6bb319d8eb92@10.0.49.2:41973
I1107 13:20:39.192348 39758 master.cpp:10830] Removing offer f7977f54-bb98-445f-9610-ede08bf34093-O3
../../src/tests/fetcher_cache_tests.cpp:1677: Failure
Failed to wait 15secs for awaitFinished(task.get())
Begin listing sandboxes
Begin listing sandbox `/tmp/FetcherCacheTest_RemoveLRUCacheEntries_aJU38i/slaves/f7977f54-bb98-445f-9610-ede08bf34093-S0/frameworks/f7977f54-bb98-445f-9610-ede08bf34093-0000/executors/0/runs/latest`:
Begin file contents of `stdout`:

End file
Begin file contents of `stderr`:
I1107 13:20:28.373706 39811 fetcher.cpp:560] Fetcher Info: {"cache_directory":"\/tmp\/FetcherCacheTest_RemoveLRUCacheEntries_bzpwJi\/fetch\/gilbert","items":[{"action":"DOWNLOAD_AND_CACHE","cache_filename":"c1-cmd0","uri":{"cache":true,"executable":true,"extract":true,"value":"\/tmp\/FetcherCacheTest_RemoveLRUCacheEntries_aJU38i\/mesos-fetcher-test-assets\/cmd0"}}],"sandbox_directory":"\/tmp\/FetcherCacheTest_RemoveLRUCacheEntries_aJU38i\/slaves\/f7977f54-bb98-445f-9610-ede08bf34093-S0\/frameworks\/f7977f54-bb98-445f-9610-ede08bf34093-0000\/executors\/0\/runs\/b0c1d94a-5bfe-443d-b284-be33a81924e7","stall_timeout":{"nanoseconds":60000000000},"user":"gilbert"}
I1107 13:20:28.384097 39811 fetcher.cpp:457] Fetching URI '/tmp/FetcherCacheTest_RemoveLRUCacheEntries_aJU38i/mesos-fetcher-test-assets/cmd0'
I1107 13:20:28.384130 39811 fetcher.cpp:431] Downloading into cache
I1107 13:20:28.384142 39811 fetcher.cpp:227] Fetching URI '/tmp/FetcherCacheTest_RemoveLRUCacheEntries_aJU38i/mesos-fetcher-test-assets/cmd0'
I1107 13:20:28.386828 39811 fetcher.cpp:351] Fetching from cache
I1107 13:20:28.389147 39811 fetcher.cpp:617] Fetched '/tmp/FetcherCacheTest_RemoveLRUCacheEntries_aJU38i/mesos-fetcher-test-assets/cmd0'
to '/tmp/FetcherCacheTest_RemoveLRUCacheEntries_aJU38i/slaves/f7977f54-bb98-445f-9610-ede08bf34093-S0/frameworks/f7977f54-bb98-445f-9610-ede08bf34093-0000/executors/0/runs/b0c1d94a-5bfe-443d-b284-be33a81924e7/cmd0'
I1107 13:20:28.389169 39811 fetcher.cpp:622] Successfully fetched all URIs into '/tmp/FetcherCacheTest_RemoveLRUCacheEntries_aJU38i/slaves/f7977f54-bb98-445f-9610-ede08bf34093-S0/frameworks/f7977f54-bb98-445f-9610-ede08bf34093-0000/executors/0/runs/b0c1d94a-5bfe-443d-b284-be33a81924e7'

End file
Begin file contents of `cmd0`:
touch mesos-fetcher-test-cmd$1
End file
End sandbox
End sandboxes
I1107 13:20:43.242727 39728 sched.cpp:2004] Asked to stop the driver
I1107 13:20:43.242909 39766 sched.cpp:1186] Stopping framework f7977f54-bb98-445f-9610-ede08bf34093-0000
I1107 13:20:43.243196 39760 master.cpp:9578] Processing TEARDOWN call for framework f7977f54-bb98-445f-9610-ede08bf34093-0000
(default) at scheduler-1733bec2-b206-47a9-a8b4-6bb319d8eb92@10.0.49.2:41973
I1107 13:20:43.243263 39760 master.cpp:9590] Removing framework f7977f54-bb98-445f-9610-ede08bf34093-0000
(default) at scheduler-1733bec2-b206-47a9-a8b4-6bb319d8eb92@10.0.49.2:41973
I1107 13:20:43.243294 39760 master.cpp:3372] Deactivating framework f7977f54-bb98-445f-9610-ede08bf34093-0000
(default) at scheduler-1733bec2-b206-47a9-a8b4-6bb319d8eb92@10.0.49.2:41973
I1107 13:20:43.243441 39762 hierarchical.cpp:407] Deactivated framework f7977f54-bb98-445f-9610-ede08bf34093-0000
I1107 13:20:43.244105 39760 master.cpp:1185] Master terminating
I1107 13:20:43.244341 39778 hierarchical.cpp:346] Removed framework f7977f54-bb98-445f-9610-ede08bf34093-0000
I1107 13:20:43.244846 39778 hierarchical.cpp:612] Removed agent f7977f54-bb98-445f-9610-ede08bf34093-S0
I1107 13:20:43.244846 39760 slave.cpp:5935] Got exited event for master@10.0.49.2:41973
W1107 13:20:43.244915 39760 slave.cpp:5940] Master disconnected! Waiting for a new master
to be elected
I1107 13:20:43.248229 39755 slave.cpp:921] Agent terminating
[  FAILED  ] FetcherCacheTest.RemoveLRUCacheEntries (15107 ms)
[----------] 1 test from FetcherCacheTest (15109 ms total)

[----------] Global test environment tear-down
[==========] 1 test from 1 test case ran. (15138 ms total)
[  PASSED  ] 0 tests.
[  FAILED  ] 1 test, listed below:
[  FAILED  ] FetcherCacheTest.RemoveLRUCacheEntries

 1 FAILED TEST
I1107 13:20:43.287750 39790 process.cpp:874] Failed to accept socket: future discarded
{noformat}



--
This message was sent by Atlassian JIRA
(v7.6.3#76005)

Mime
View raw message