[
https://issues.apache.org/jira/browse/MESOS-2858?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=14960668#comment-14960668
]
Bernd Mathiske edited comment on MESOS-2858 at 10/16/15 1:21 PM:
-----------------------------------------------------------------
Puzzling. When accessing the files via a terminal, they exist and can be read.
But when the fetcher tries to access them programmatically running as root, the
operation is not permitted.
The "access" that fails merely checks whether the downloaded archive is
executable (and expects to find it non-executable). We could skip this check
and the test would succeed. It is not essential to Mesos' operations at all.
However, I'd still like to know what is going on here.
was (Author: bernd-mesos):
Puzzling. When accessing the files via a terminal, they exist and can be read.
But when the fetcher tries to access them programmatically running as root, the
operation is not permitted.
> FetcherCacheHttpTest.HttpMixed is flaky.
> ----------------------------------------
>
> Key: MESOS-2858
> URL: https://issues.apache.org/jira/browse/MESOS-2858
> Project: Mesos
> Issue Type: Bug
> Components: fetcher, test
> Reporter: Benjamin Mahler
> Assignee: Bernd Mathiske
> Labels: flaky-test, mesosphere
>
> From jenkins:
> {noformat}
> [ RUN ] FetcherCacheHttpTest.HttpMixed
> Using temporary directory '/tmp/FetcherCacheHttpTest_HttpMixed_qfpOOC'
> I0611 00:40:28.208909 26042 leveldb.cpp:176] Opened db in 3.831173ms
> I0611 00:40:28.209951 26042 leveldb.cpp:183] Compacted db in 997319ns
> I0611 00:40:28.210011 26042 leveldb.cpp:198] Created db iterator in 23917ns
> I0611 00:40:28.210032 26042 leveldb.cpp:204] Seeked to beginning of db in
> 2112ns
> I0611 00:40:28.210043 26042 leveldb.cpp:273] Iterated through 0 keys in the
> db in 392ns
> I0611 00:40:28.210095 26042 replica.cpp:744] Replica recovered with log
> positions 0 -> 0 with 1 holes and 0 unlearned
> I0611 00:40:28.210741 26067 recover.cpp:449] Starting replica recovery
> I0611 00:40:28.211144 26067 recover.cpp:475] Replica is in EMPTY status
> I0611 00:40:28.212210 26074 replica.cpp:641] Replica in EMPTY status received
> a broadcasted recover request
> I0611 00:40:28.212728 26071 recover.cpp:195] Received a recover response from
> a replica in EMPTY status
> I0611 00:40:28.213260 26069 recover.cpp:566] Updating replica status to
> STARTING
> I0611 00:40:28.214066 26073 leveldb.cpp:306] Persisting metadata (8 bytes) to
> leveldb took 590673ns
> I0611 00:40:28.214095 26073 replica.cpp:323] Persisted replica status to
> STARTING
> I0611 00:40:28.214350 26073 recover.cpp:475] Replica is in STARTING status
> I0611 00:40:28.214774 26061 master.cpp:363] Master
> 20150611-004028-1946161580-33349-26042 (658ddc752264) started on
> 172.17.0.116:33349
> I0611 00:40:28.214800 26061 master.cpp:365] Flags at startup: --acls=""
> --allocation_interval="1secs" --allocator="HierarchicalDRF"
> --authenticate="true" --authenticate_slaves="true" --authenticators="crammd5"
> --credentials="/tmp/FetcherCacheHttpTest_HttpMixed_qfpOOC/credentials"
> --framework_sorter="drf" --help="false" --initialize_driver_logging="true"
> --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO"
> --quiet="false" --recovery_slave_removal_limit="100%"
> --registry="replicated_log" --registry_fetch_timeout="1mins"
> --registry_store_timeout="25secs" --registry_strict="true"
> --root_submissions="true" --slave_reregister_timeout="10mins"
> --user_sorter="drf" --version="false"
> --webui_dir="/mesos/mesos-0.23.0/_inst/share/mesos/webui"
> --work_dir="/tmp/FetcherCacheHttpTest_HttpMixed_qfpOOC/master"
> --zk_session_timeout="10secs"
> I0611 00:40:28.215342 26061 master.cpp:410] Master only allowing
> authenticated frameworks to register
> I0611 00:40:28.215361 26061 master.cpp:415] Master only allowing
> authenticated slaves to register
> I0611 00:40:28.215397 26061 credentials.hpp:37] Loading credentials for
> authentication from '/tmp/FetcherCacheHttpTest_HttpMixed_qfpOOC/credentials'
> I0611 00:40:28.215589 26064 replica.cpp:641] Replica in STARTING status
> received a broadcasted recover request
> I0611 00:40:28.215770 26061 master.cpp:454] Using default 'crammd5'
> authenticator
> I0611 00:40:28.215934 26061 master.cpp:491] Authorization enabled
> I0611 00:40:28.215932 26062 recover.cpp:195] Received a recover response from
> a replica in STARTING status
> I0611 00:40:28.216256 26070 whitelist_watcher.cpp:79] No whitelist given
> I0611 00:40:28.216310 26066 hierarchical.hpp:309] Initialized hierarchical
> allocator process
> I0611 00:40:28.216352 26067 recover.cpp:566] Updating replica status to VOTING
> I0611 00:40:28.216909 26070 leveldb.cpp:306] Persisting metadata (8 bytes) to
> leveldb took 374189ns
> I0611 00:40:28.216931 26070 replica.cpp:323] Persisted replica status to
> VOTING
> I0611 00:40:28.217052 26075 recover.cpp:580] Successfully joined the Paxos
> group
> I0611 00:40:28.217355 26063 master.cpp:1476] The newly elected leader is
> [email protected]:33349 with id 20150611-004028-1946161580-33349-26042
> I0611 00:40:28.217512 26063 master.cpp:1489] Elected as the leading master!
> I0611 00:40:28.217540 26063 master.cpp:1259] Recovering from registrar
> I0611 00:40:28.217753 26070 registrar.cpp:313] Recovering registrar
> I0611 00:40:28.217396 26075 recover.cpp:464] Recover process terminated
> I0611 00:40:28.218341 26065 log.cpp:661] Attempting to start the writer
> I0611 00:40:28.219391 26067 replica.cpp:477] Replica received implicit
> promise request with proposal 1
> I0611 00:40:28.219696 26067 leveldb.cpp:306] Persisting metadata (8 bytes) to
> leveldb took 276905ns
> I0611 00:40:28.219720 26067 replica.cpp:345] Persisted promised to 1
> I0611 00:40:28.220255 26064 coordinator.cpp:230] Coordinator attemping to
> fill missing position
> I0611 00:40:28.221247 26073 replica.cpp:378] Replica received explicit
> promise request for position 0 with proposal 2
> I0611 00:40:28.221545 26073 leveldb.cpp:343] Persisting action (8 bytes) to
> leveldb took 265847ns
> I0611 00:40:28.221567 26073 replica.cpp:679] Persisted action at 0
> I0611 00:40:28.222412 26073 replica.cpp:511] Replica received write request
> for position 0
> I0611 00:40:28.222458 26073 leveldb.cpp:438] Reading position from leveldb
> took 23520ns
> I0611 00:40:28.222777 26073 leveldb.cpp:343] Persisting action (14 bytes) to
> leveldb took 280968ns
> I0611 00:40:28.222800 26073 replica.cpp:679] Persisted action at 0
> I0611 00:40:28.223316 26073 replica.cpp:658] Replica received learned notice
> for position 0
> I0611 00:40:28.223616 26073 leveldb.cpp:343] Persisting action (16 bytes) to
> leveldb took 276737ns
> I0611 00:40:28.223637 26073 replica.cpp:679] Persisted action at 0
> I0611 00:40:28.223654 26073 replica.cpp:664] Replica learned NOP action at
> position 0
> I0611 00:40:28.224063 26063 log.cpp:677] Writer started with ending position 0
> I0611 00:40:28.225039 26076 leveldb.cpp:438] Reading position from leveldb
> took 29011ns
> I0611 00:40:28.227192 26062 registrar.cpp:346] Successfully fetched the
> registry (0B) in 9.399808ms
> I0611 00:40:28.227277 26062 registrar.cpp:445] Applied 1 operations in
> 20073ns; attempting to update the 'registry'
> I0611 00:40:28.229274 26063 log.cpp:685] Attempting to append 131 bytes to
> the log
> I0611 00:40:28.229415 26066 coordinator.cpp:340] Coordinator attempting to
> write APPEND action at position 1
> I0611 00:40:28.230022 26069 replica.cpp:511] Replica received write request
> for position 1
> I0611 00:40:28.230345 26069 leveldb.cpp:343] Persisting action (150 bytes) to
> leveldb took 292219ns
> I0611 00:40:28.230368 26069 replica.cpp:679] Persisted action at 1
> I0611 00:40:28.230881 26073 replica.cpp:658] Replica received learned notice
> for position 1
> I0611 00:40:28.231205 26073 leveldb.cpp:343] Persisting action (152 bytes) to
> leveldb took 299315ns
> I0611 00:40:28.231230 26073 replica.cpp:679] Persisted action at 1
> I0611 00:40:28.231256 26073 replica.cpp:664] Replica learned APPEND action at
> position 1
> I0611 00:40:28.232048 26061 registrar.cpp:490] Successfully updated the
> 'registry' in 4.71808ms
> I0611 00:40:28.232169 26061 registrar.cpp:376] Successfully recovered
> registrar
> I0611 00:40:28.232230 26075 log.cpp:704] Attempting to truncate the log to 1
> I0611 00:40:28.232393 26069 coordinator.cpp:340] Coordinator attempting to
> write TRUNCATE action at position 2
> I0611 00:40:28.232430 26071 master.cpp:1286] Recovered 0 slaves from the
> Registry (95B) ; allowing 10mins for slaves to re-register
> I0611 00:40:28.233050 26065 replica.cpp:511] Replica received write request
> for position 2
> I0611 00:40:28.233394 26065 leveldb.cpp:343] Persisting action (16 bytes) to
> leveldb took 315334ns
> I0611 00:40:28.233415 26065 replica.cpp:679] Persisted action at 2
> I0611 00:40:28.233902 26069 replica.cpp:658] Replica received learned notice
> for position 2
> I0611 00:40:28.234197 26069 leveldb.cpp:343] Persisting action (18 bytes) to
> leveldb took 268125ns
> I0611 00:40:28.234242 26069 leveldb.cpp:401] Deleting ~1 keys from leveldb
> took 23549ns
> I0611 00:40:28.234268 26069 replica.cpp:679] Persisted action at 2
> I0611 00:40:28.234295 26069 replica.cpp:664] Replica learned TRUNCATE action
> at position 2
> I0611 00:40:28.246417 26042 containerizer.cpp:111] Using isolation:
> posix/cpu,posix/mem
> I0611 00:40:28.251890 26076 slave.cpp:188] Slave started on
> 47)@172.17.0.116:33349
> I0611 00:40:28.252024 26076 slave.cpp:189] Flags at startup:
> --authenticatee="crammd5" --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/FetcherCacheHttpTest_HttpMixed_kwsjNe/credential"
> --default_role="*" --disk_watch_interval="1mins" --docker="docker"
> --docker_kill_orphans="true" --docker_remove_delay="6hrs"
> --docker_sandbox_directory="/mnt/mesos/sandbox"
> --docker_socket="/var/run/docker.sock" --docker_stop_timeout="0ns"
> --enforce_container_disk_quota="false"
> --executor_registration_timeout="1mins"
> --executor_shutdown_grace_period="5secs"
> --fetcher_cache_dir="/tmp/FetcherCacheHttpTest_HttpMixed_kwsjNe/fetch"
> --fetcher_cache_size="2GB" --frameworks_home="" --gc_delay="1weeks"
> --gc_disk_headroom="0.1" --hadoop_home="" --help="true"
> --initialize_driver_logging="true" --isolation="posix/cpu,posix/mem"
> --launcher_dir="/mesos/mesos-0.23.0/_build/src" --logbufsecs="0"
> --logging_level="INFO" --oversubscribed_resources_interval="15secs"
> --perf_duration="10secs" --perf_interval="1mins" --quiet="false"
> --recover="reconnect" --recovery_timeout="15mins"
> --registration_backoff_factor="10ms" --resource_monitoring_interval="1secs"
> --resources="cpus(*):1000; mem(*):1000" --revocable_cpu_low_priority="true"
> --strict="true" --switch_user="true" --version="false"
> --work_dir="/tmp/FetcherCacheHttpTest_HttpMixed_kwsjNe"
> I0611 00:40:28.252583 26076 credentials.hpp:85] Loading credential for
> authentication from '/tmp/FetcherCacheHttpTest_HttpMixed_kwsjNe/credential'
> I0611 00:40:28.252779 26076 slave.cpp:319] Slave using credential for:
> test-principal
> I0611 00:40:28.253324 26076 slave.cpp:352] Slave resources: cpus(*):1000;
> mem(*):1000; disk(*):3.70122e+06; ports(*):[31000-32000]
> I0611 00:40:28.253428 26076 slave.cpp:382] Slave hostname: 658ddc752264
> I0611 00:40:28.253445 26076 slave.cpp:387] Slave checkpoint: true
> I0611 00:40:28.254259 26064 state.cpp:35] Recovering state from
> '/tmp/FetcherCacheHttpTest_HttpMixed_kwsjNe/meta'
> I0611 00:40:28.254647 26068 status_update_manager.cpp:201] Recovering status
> update manager
> I0611 00:40:28.254853 26069 containerizer.cpp:312] Recovering containerizer
> I0611 00:40:28.255537 26076 slave.cpp:3955] Finished recovery
> I0611 00:40:28.256093 26076 slave.cpp:4109] Querying resource estimator for
> oversubscribable resources
> I0611 00:40:28.256330 26076 slave.cpp:678] New master detected at
> [email protected]:33349
> I0611 00:40:28.256335 26063 status_update_manager.cpp:175] Pausing sending
> status updates
> I0611 00:40:28.256434 26076 slave.cpp:741] Authenticating with master
> [email protected]:33349
> I0611 00:40:28.256456 26076 slave.cpp:746] Using default CRAM-MD5
> authenticatee
> I0611 00:40:28.256599 26076 slave.cpp:714] Detecting new master
> I0611 00:40:28.256702 26062 authenticatee.hpp:139] Creating new client SASL
> connection
> I0611 00:40:28.256769 26076 slave.cpp:4130] Received oversubscribable
> resources from the resource estimator
> I0611 00:40:28.256804 26076 slave.cpp:4134] No master detected. Re-querying
> resource estimator after 15secs
> I0611 00:40:28.257128 26074 master.cpp:4192] Authenticating
> slave(47)@172.17.0.116:33349
> I0611 00:40:28.257244 26061 authenticator.cpp:406] Starting authentication
> session for crammd5_authenticatee(140)@172.17.0.116:33349
> I0611 00:40:28.257448 26063 authenticator.cpp:92] Creating new server SASL
> connection
> I0611 00:40:28.257630 26064 authenticatee.hpp:230] Received SASL
> authentication mechanisms: CRAM-MD5
> I0611 00:40:28.257660 26064 authenticatee.hpp:256] Attempting to authenticate
> with mechanism 'CRAM-MD5'
> I0611 00:40:28.257786 26069 authenticator.cpp:197] Received SASL
> authentication start
> I0611 00:40:28.257855 26069 authenticator.cpp:319] Authentication requires
> more steps
> I0611 00:40:28.257948 26064 authenticatee.hpp:276] Received SASL
> authentication step
> I0611 00:40:28.258060 26064 authenticator.cpp:225] Received SASL
> authentication step
> I0611 00:40:28.258106 26064 auxprop.cpp:101] Request to lookup properties for
> user: 'test-principal' realm: '658ddc752264' server FQDN: '658ddc752264'
> SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
> SASL_AUXPROP_AUTHZID: false
> I0611 00:40:28.258123 26064 auxprop.cpp:173] Looking up auxiliary property
> '*userPassword'
> I0611 00:40:28.258173 26064 auxprop.cpp:173] Looking up auxiliary property
> '*cmusaslsecretCRAM-MD5'
> I0611 00:40:28.258203 26064 auxprop.cpp:101] Request to lookup properties for
> user: 'test-principal' realm: '658ddc752264' server FQDN: '658ddc752264'
> SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
> SASL_AUXPROP_AUTHZID: true
> I0611 00:40:28.258215 26064 auxprop.cpp:123] Skipping auxiliary property
> '*userPassword' since SASL_AUXPROP_AUTHZID == true
> I0611 00:40:28.258224 26064 auxprop.cpp:123] Skipping auxiliary property
> '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
> I0611 00:40:28.258242 26064 authenticator.cpp:311] Authentication success
> I0611 00:40:28.258389 26069 authenticatee.hpp:316] Authentication success
> I0611 00:40:28.258401 26065 master.cpp:4222] Successfully authenticated
> principal 'test-principal' at slave(47)@172.17.0.116:33349
> I0611 00:40:28.258450 26072 authenticator.cpp:424] Authentication session
> cleanup for crammd5_authenticatee(140)@172.17.0.116:33349
> I0611 00:40:28.258625 26068 slave.cpp:812] Successfully authenticated with
> master [email protected]:33349
> I0611 00:40:28.258744 26068 slave.cpp:1146] Will retry registration in
> 14.347946ms if necessary
> I0611 00:40:28.258904 26069 master.cpp:3168] Registering slave at
> slave(47)@172.17.0.116:33349 (658ddc752264) with id
> 20150611-004028-1946161580-33349-26042-S0
> I0611 00:40:28.259302 26065 registrar.cpp:445] Applied 1 operations in
> 65373ns; attempting to update the 'registry'
> I0611 00:40:28.262166 26067 log.cpp:685] Attempting to append 305 bytes to
> the log
> I0611 00:40:28.262317 26068 coordinator.cpp:340] Coordinator attempting to
> write APPEND action at position 3
> I0611 00:40:28.263157 26070 replica.cpp:511] Replica received write request
> for position 3
> I0611 00:40:28.263372 26070 leveldb.cpp:343] Persisting action (324 bytes) to
> leveldb took 175524ns
> I0611 00:40:28.263404 26070 replica.cpp:679] Persisted action at 3
> I0611 00:40:28.264120 26064 replica.cpp:658] Replica received learned notice
> for position 3
> I0611 00:40:28.264689 26064 leveldb.cpp:343] Persisting action (326 bytes) to
> leveldb took 536529ns
> I0611 00:40:28.264717 26064 replica.cpp:679] Persisted action at 3
> I0611 00:40:28.264740 26064 replica.cpp:664] Replica learned APPEND action at
> position 3
> I0611 00:40:28.265750 26071 registrar.cpp:490] Successfully updated the
> 'registry' in 6.358784ms
> I0611 00:40:28.266057 26066 log.cpp:704] Attempting to truncate the log to 3
> I0611 00:40:28.266203 26073 coordinator.cpp:340] Coordinator attempting to
> write TRUNCATE action at position 4
> I0611 00:40:28.266695 26061 slave.cpp:2895] Received ping from
> slave-observer(46)@172.17.0.116:33349
> I0611 00:40:28.267076 26072 replica.cpp:511] Replica received write request
> for position 4
> I0611 00:40:28.267200 26065 master.cpp:3225] Registered slave
> 20150611-004028-1946161580-33349-26042-S0 at slave(47)@172.17.0.116:33349
> (658ddc752264) with cpus(*):1000; mem(*):1000; disk(*):3.70122e+06;
> ports(*):[31000-32000]
> I0611 00:40:28.267371 26070 slave.cpp:846] Registered with master
> [email protected]:33349; given slave ID
> 20150611-004028-1946161580-33349-26042-S0
> I0611 00:40:28.267406 26070 fetcher.cpp:77] Clearing fetcher cache
> I0611 00:40:28.267385 26069 hierarchical.hpp:496] Added slave
> 20150611-004028-1946161580-33349-26042-S0 (658ddc752264) with cpus(*):1000;
> mem(*):1000; disk(*):3.70122e+06; ports(*):[31000-32000] (and cpus(*):1000;
> mem(*):1000; disk(*):3.70122e+06; ports(*):[31000-32000] available)
> I0611 00:40:28.267596 26069 hierarchical.hpp:933] No resources available to
> allocate!
> I0611 00:40:28.267608 26072 leveldb.cpp:343] Persisting action (16 bytes) to
> leveldb took 493557ns
> I0611 00:40:28.267624 26069 hierarchical.hpp:852] Performed allocation for
> slave 20150611-004028-1946161580-33349-26042-S0 in 185107ns
> I0611 00:40:28.267640 26072 replica.cpp:679] Persisted action at 4
> I0611 00:40:28.267599 26066 status_update_manager.cpp:182] Resuming sending
> status updates
> I0611 00:40:28.267889 26070 slave.cpp:869] Checkpointing SlaveInfo to
> '/tmp/FetcherCacheHttpTest_HttpMixed_kwsjNe/meta/slaves/20150611-004028-1946161580-33349-26042-S0/slave.info'
> I0611 00:40:28.268245 26072 replica.cpp:658] Replica received learned notice
> for position 4
> I0611 00:40:28.268631 26072 leveldb.cpp:343] Persisting action (18 bytes) to
> leveldb took 358080ns
> I0611 00:40:28.268684 26072 leveldb.cpp:401] Deleting ~2 keys from leveldb
> took 29788ns
> I0611 00:40:28.268698 26072 replica.cpp:679] Persisted action at 4
> I0611 00:40:28.268718 26072 replica.cpp:664] Replica learned TRUNCATE action
> at position 4
> I0611 00:40:28.269922 26042 sched.cpp:157] Version: 0.23.0
> I0611 00:40:28.270370 26076 sched.cpp:254] New master detected at
> [email protected]:33349
> I0611 00:40:28.270438 26076 sched.cpp:310] Authenticating with master
> [email protected]:33349
> I0611 00:40:28.270457 26076 sched.cpp:317] Using default CRAM-MD5
> authenticatee
> I0611 00:40:28.270597 26066 authenticatee.hpp:139] Creating new client SASL
> connection
> I0611 00:40:28.270895 26074 master.cpp:4192] Authenticating
> [email protected]:33349
> I0611 00:40:28.270992 26068 authenticator.cpp:406] Starting authentication
> session for crammd5_authenticatee(141)@172.17.0.116:33349
> I0611 00:40:28.271212 26065 authenticator.cpp:92] Creating new server SASL
> connection
> I0611 00:40:28.271389 26076 authenticatee.hpp:230] Received SASL
> authentication mechanisms: CRAM-MD5
> I0611 00:40:28.271427 26076 authenticatee.hpp:256] Attempting to authenticate
> with mechanism 'CRAM-MD5'
> I0611 00:40:28.271509 26068 authenticator.cpp:197] Received SASL
> authentication start
> I0611 00:40:28.271554 26068 authenticator.cpp:319] Authentication requires
> more steps
> I0611 00:40:28.271628 26070 authenticatee.hpp:276] Received SASL
> authentication step
> I0611 00:40:28.271734 26073 authenticator.cpp:225] Received SASL
> authentication step
> I0611 00:40:28.271761 26073 auxprop.cpp:101] Request to lookup properties for
> user: 'test-principal' realm: '658ddc752264' server FQDN: '658ddc752264'
> SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
> SASL_AUXPROP_AUTHZID: false
> I0611 00:40:28.271770 26073 auxprop.cpp:173] Looking up auxiliary property
> '*userPassword'
> I0611 00:40:28.271803 26073 auxprop.cpp:173] Looking up auxiliary property
> '*cmusaslsecretCRAM-MD5'
> I0611 00:40:28.271848 26073 auxprop.cpp:101] Request to lookup properties for
> user: 'test-principal' realm: '658ddc752264' server FQDN: '658ddc752264'
> SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
> SASL_AUXPROP_AUTHZID: true
> I0611 00:40:28.271862 26073 auxprop.cpp:123] Skipping auxiliary property
> '*userPassword' since SASL_AUXPROP_AUTHZID == true
> I0611 00:40:28.271867 26073 auxprop.cpp:123] Skipping auxiliary property
> '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
> I0611 00:40:28.271879 26073 authenticator.cpp:311] Authentication success
> I0611 00:40:28.271949 26070 authenticatee.hpp:316] Authentication success
> I0611 00:40:28.271985 26068 master.cpp:4222] Successfully authenticated
> principal 'test-principal' at
> [email protected]:33349
> I0611 00:40:28.272043 26070 authenticator.cpp:424] Authentication session
> cleanup for crammd5_authenticatee(141)@172.17.0.116:33349
> I0611 00:40:28.272197 26073 sched.cpp:398] Successfully authenticated with
> master [email protected]:33349
> I0611 00:40:28.272222 26073 sched.cpp:521] Sending registration request to
> [email protected]:33349
> I0611 00:40:28.272280 26073 sched.cpp:554] Will retry registration in
> 983.889094ms if necessary
> I0611 00:40:28.272351 26072 master.cpp:1716] Received registration request
> for framework 'default' at
> [email protected]:33349
> W0611 00:40:28.272406 26072 master.cpp:1539] Framework at
> [email protected]:33349
> (authenticated as 'test-principal') does not specify principal in its
> FrameworkInfo
> I0611 00:40:28.272425 26072 master.cpp:1555] Authorizing framework principal
> '' to receive offers for role '*'
> I0611 00:40:28.272718 26067 master.cpp:1783] Registering framework
> 20150611-004028-1946161580-33349-26042-0000 (default) at
> [email protected]:33349 with
> checkpointing enabled and capabilities [ ]
> I0611 00:40:28.273047 26063 hierarchical.hpp:354] Added framework
> 20150611-004028-1946161580-33349-26042-0000
> I0611 00:40:28.273154 26070 sched.cpp:448] Framework registered with
> 20150611-004028-1946161580-33349-26042-0000
> I0611 00:40:28.273200 26070 sched.cpp:462] Scheduler::registered took 22736ns
> I0611 00:40:28.273486 26063 hierarchical.hpp:834] Performed allocation for 1
> slaves in 415024ns
> I0611 00:40:28.273775 26067 master.cpp:4111] Sending 1 offers to framework
> 20150611-004028-1946161580-33349-26042-0000 (default) at
> [email protected]:33349
> I0611 00:40:28.274096 26061 sched.cpp:611] Scheduler::resourceOffers took
> 58588ns
> I0611 00:40:28.276064 26064 master.cpp:2424] Processing ACCEPT call for
> offers: [ 20150611-004028-1946161580-33349-26042-O0 ] on slave
> 20150611-004028-1946161580-33349-26042-S0 at slave(47)@172.17.0.116:33349
> (658ddc752264) for framework 20150611-004028-1946161580-33349-26042-0000
> (default) at [email protected]:33349
> I0611 00:40:28.276109 26064 master.cpp:2268] Authorizing framework principal
> '' to launch task 0 as user 'mesos'
> I0611 00:40:28.276221 26064 master.cpp:2268] Authorizing framework principal
> '' to launch task 1 as user 'mesos'
> I0611 00:40:28.276329 26064 master.cpp:2268] Authorizing framework principal
> '' to launch task 2 as user 'mesos'
> I0611 00:40:28.277539 26070 master.hpp:159] Adding task 0 with resources
> cpus(*):1; mem(*):1 on slave 20150611-004028-1946161580-33349-26042-S0
> (658ddc752264)
> I0611 00:40:28.277657 26070 master.cpp:2751] Launching task 0 of framework
> 20150611-004028-1946161580-33349-26042-0000 (default) at
> [email protected]:33349 with
> resources cpus(*):1; mem(*):1 on slave
> 20150611-004028-1946161580-33349-26042-S0 at slave(47)@172.17.0.116:33349
> (658ddc752264)
> I0611 00:40:28.277953 26063 slave.cpp:1186] Got assigned task 0 for framework
> 20150611-004028-1946161580-33349-26042-0000
> I0611 00:40:28.278112 26063 slave.cpp:4439] Checkpointing FrameworkInfo to
> '/tmp/FetcherCacheHttpTest_HttpMixed_kwsjNe/meta/slaves/20150611-004028-1946161580-33349-26042-S0/frameworks/20150611-004028-1946161580-33349-26042-0000/framework.info'
> I0611 00:40:28.278301 26070 master.hpp:159] Adding task 1 with resources
> cpus(*):1; mem(*):1 on slave 20150611-004028-1946161580-33349-26042-S0
> (658ddc752264)
> I0611 00:40:28.278399 26070 master.cpp:2751] Launching task 1 of framework
> 20150611-004028-1946161580-33349-26042-0000 (default) at
> [email protected]:33349 with
> resources cpus(*):1; mem(*):1 on slave
> 20150611-004028-1946161580-33349-26042-S0 at slave(47)@172.17.0.116:33349
> (658ddc752264)
> I0611 00:40:28.278478 26063 slave.cpp:4446] Checkpointing framework pid
> '[email protected]:33349' to
> '/tmp/FetcherCacheHttpTest_HttpMixed_kwsjNe/meta/slaves/20150611-004028-1946161580-33349-26042-S0/frameworks/20150611-004028-1946161580-33349-26042-0000/framework.pid'
> I0611 00:40:28.278982 26070 master.hpp:159] Adding task 2 with resources
> cpus(*):1; mem(*):1 on slave 20150611-004028-1946161580-33349-26042-S0
> (658ddc752264)
> I0611 00:40:28.279062 26070 master.cpp:2751] Launching task 2 of framework
> 20150611-004028-1946161580-33349-26042-0000 (default) at
> [email protected]:33349 with
> resources cpus(*):1; mem(*):1 on slave
> 20150611-004028-1946161580-33349-26042-S0 at slave(47)@172.17.0.116:33349
> (658ddc752264)
> I0611 00:40:28.279366 26063 slave.cpp:1186] Got assigned task 1 for framework
> 20150611-004028-1946161580-33349-26042-0000
> I0611 00:40:28.279496 26065 hierarchical.hpp:741] Recovered cpus(*):997;
> mem(*):997; disk(*):3.70122e+06; ports(*):[31000-32000] (total allocatable:
> cpus(*):997; mem(*):997; disk(*):3.70122e+06; ports(*):[31000-32000]) on
> slave 20150611-004028-1946161580-33349-26042-S0 from framework
> 20150611-004028-1946161580-33349-26042-0000
> I0611 00:40:28.279634 26065 hierarchical.hpp:777] Framework
> 20150611-004028-1946161580-33349-26042-0000 filtered slave
> 20150611-004028-1946161580-33349-26042-S0 for 5secs
> I0611 00:40:28.280042 26063 slave.cpp:1186] Got assigned task 2 for framework
> 20150611-004028-1946161580-33349-26042-0000
> I0611 00:40:28.280503 26063 slave.cpp:1300] Launching task 0 for framework
> 20150611-004028-1946161580-33349-26042-0000
> I0611 00:40:28.287946 26063 slave.cpp:4875] Checkpointing ExecutorInfo to
> '/tmp/FetcherCacheHttpTest_HttpMixed_kwsjNe/meta/slaves/20150611-004028-1946161580-33349-26042-S0/frameworks/20150611-004028-1946161580-33349-26042-0000/executors/0/executor.info'
> I0611 00:40:28.288858 26063 slave.cpp:4512] Launching executor 0 of framework
> 20150611-004028-1946161580-33349-26042-0000 with resources cpus(*):0.1;
> mem(*):32 in work directory
> '/tmp/FetcherCacheHttpTest_HttpMixed_kwsjNe/slaves/20150611-004028-1946161580-33349-26042-S0/frameworks/20150611-004028-1946161580-33349-26042-0000/executors/0/runs/7bde6e5f-f6a9-4631-973b-3dbe57deae6d'
> I0611 00:40:28.289345 26072 containerizer.cpp:530] Starting container
> '7bde6e5f-f6a9-4631-973b-3dbe57deae6d' for executor '0' of framework
> '20150611-004028-1946161580-33349-26042-0000'
> I0611 00:40:28.289517 26063 slave.cpp:4898] Checkpointing TaskInfo to
> '/tmp/FetcherCacheHttpTest_HttpMixed_kwsjNe/meta/slaves/20150611-004028-1946161580-33349-26042-S0/frameworks/20150611-004028-1946161580-33349-26042-0000/executors/0/runs/7bde6e5f-f6a9-4631-973b-3dbe57deae6d/tasks/0/task.info'
> I0611 00:40:28.290138 26063 slave.cpp:1446] Queuing task '0' for executor 0
> of framework '20150611-004028-1946161580-33349-26042-0000
> I0611 00:40:28.290283 26063 slave.cpp:1300] Launching task 1 for framework
> 20150611-004028-1946161580-33349-26042-0000
> I0611 00:40:28.292667 26072 launcher.cpp:131] Forked child with pid '30601'
> for container '7bde6e5f-f6a9-4631-973b-3dbe57deae6d'
> I0611 00:40:28.292867 26072 containerizer.cpp:766] Checkpointing executor's
> forked pid 30601 to
> '/tmp/FetcherCacheHttpTest_HttpMixed_kwsjNe/meta/slaves/20150611-004028-1946161580-33349-26042-S0/frameworks/20150611-004028-1946161580-33349-26042-0000/executors/0/runs/7bde6e5f-f6a9-4631-973b-3dbe57deae6d/pids/forked.pid'
> I0611 00:40:28.295876 26065 fetcher.cpp:299] Starting to fetch URIs for
> container: 7bde6e5f-f6a9-4631-973b-3dbe57deae6d, directory:
> /tmp/FetcherCacheHttpTest_HttpMixed_kwsjNe/slaves/20150611-004028-1946161580-33349-26042-S0/frameworks/20150611-004028-1946161580-33349-26042-0000/executors/0/runs/7bde6e5f-f6a9-4631-973b-3dbe57deae6d
> I0611 00:40:28.298319 26063 slave.cpp:4875] Checkpointing ExecutorInfo to
> '/tmp/FetcherCacheHttpTest_HttpMixed_kwsjNe/meta/slaves/20150611-004028-1946161580-33349-26042-S0/frameworks/20150611-004028-1946161580-33349-26042-0000/executors/1/executor.info'
> I0611 00:40:28.299039 26063 slave.cpp:4512] Launching executor 1 of framework
> 20150611-004028-1946161580-33349-26042-0000 with resources cpus(*):0.1;
> mem(*):32 in work directory
> '/tmp/FetcherCacheHttpTest_HttpMixed_kwsjNe/slaves/20150611-004028-1946161580-33349-26042-S0/frameworks/20150611-004028-1946161580-33349-26042-0000/executors/1/runs/fe2dae2c-3efc-49e2-98a9-c6ffd689e1ef'
> I0611 00:40:28.299458 26073 containerizer.cpp:530] Starting container
> 'fe2dae2c-3efc-49e2-98a9-c6ffd689e1ef' for executor '1' of framework
> '20150611-004028-1946161580-33349-26042-0000'
> I0611 00:40:28.299595 26063 slave.cpp:4898] Checkpointing TaskInfo to
> '/tmp/FetcherCacheHttpTest_HttpMixed_kwsjNe/meta/slaves/20150611-004028-1946161580-33349-26042-S0/frameworks/20150611-004028-1946161580-33349-26042-0000/executors/1/runs/fe2dae2c-3efc-49e2-98a9-c6ffd689e1ef/tasks/1/task.info'
> I0611 00:40:28.300205 26063 slave.cpp:1446] Queuing task '1' for executor 1
> of framework '20150611-004028-1946161580-33349-26042-0000
> I0611 00:40:28.300290 26065 fetcher.cpp:873] Created cache entry
> 'mesos@http://172.17.0.116:33349/(1407)/mesos-fetcher-test-archive.tgz' with
> file: c1-mesos-fetc_rchive.tgz
> I0611 00:40:28.300354 26063 slave.cpp:1300] Launching task 2 for framework
> 20150611-004028-1946161580-33349-26042-0000
> I0611 00:40:28.301391 26064 fetcher.cpp:248] Fetching size for URI:
> http://172.17.0.116:33349/(1407)/mesos-fetcher-test-archive.tgz
> I0611 00:40:28.305124 26072 launcher.cpp:131] Forked child with pid '30612'
> for container 'fe2dae2c-3efc-49e2-98a9-c6ffd689e1ef'
> I0611 00:40:28.305352 26072 containerizer.cpp:766] Checkpointing executor's
> forked pid 30612 to
> '/tmp/FetcherCacheHttpTest_HttpMixed_kwsjNe/meta/slaves/20150611-004028-1946161580-33349-26042-S0/frameworks/20150611-004028-1946161580-33349-26042-0000/executors/1/runs/fe2dae2c-3efc-49e2-98a9-c6ffd689e1ef/pids/forked.pid'
> I0611 00:40:28.307904 26073 fetcher.cpp:299] Starting to fetch URIs for
> container: fe2dae2c-3efc-49e2-98a9-c6ffd689e1ef, directory:
> /tmp/FetcherCacheHttpTest_HttpMixed_kwsjNe/slaves/20150611-004028-1946161580-33349-26042-S0/frameworks/20150611-004028-1946161580-33349-26042-0000/executors/1/runs/fe2dae2c-3efc-49e2-98a9-c6ffd689e1ef
> I0611 00:40:28.309226 26063 slave.cpp:4875] Checkpointing ExecutorInfo to
> '/tmp/FetcherCacheHttpTest_HttpMixed_kwsjNe/meta/slaves/20150611-004028-1946161580-33349-26042-S0/frameworks/20150611-004028-1946161580-33349-26042-0000/executors/2/executor.info'
> I0611 00:40:28.310174 26063 slave.cpp:4512] Launching executor 2 of framework
> 20150611-004028-1946161580-33349-26042-0000 with resources cpus(*):0.1;
> mem(*):32 in work directory
> '/tmp/FetcherCacheHttpTest_HttpMixed_kwsjNe/slaves/20150611-004028-1946161580-33349-26042-S0/frameworks/20150611-004028-1946161580-33349-26042-0000/executors/2/runs/09e97509-9ee7-4c22-b6ae-7017b778e120'
> I0611 00:40:28.310665 26076 containerizer.cpp:530] Starting container
> '09e97509-9ee7-4c22-b6ae-7017b778e120' for executor '2' of framework
> '20150611-004028-1946161580-33349-26042-0000'
> I0611 00:40:28.310803 26063 slave.cpp:4898] Checkpointing TaskInfo to
> '/tmp/FetcherCacheHttpTest_HttpMixed_kwsjNe/meta/slaves/20150611-004028-1946161580-33349-26042-S0/frameworks/20150611-004028-1946161580-33349-26042-0000/executors/2/runs/09e97509-9ee7-4c22-b6ae-7017b778e120/tasks/2/task.info'
> I0611 00:40:28.311332 26063 slave.cpp:1446] Queuing task '2' for executor 2
> of framework '20150611-004028-1946161580-33349-26042-0000
> I0611 00:40:28.311569 26063 slave.cpp:631] Successfully attached file
> '/tmp/FetcherCacheHttpTest_HttpMixed_kwsjNe/slaves/20150611-004028-1946161580-33349-26042-S0/frameworks/20150611-004028-1946161580-33349-26042-0000/executors/0/runs/7bde6e5f-f6a9-4631-973b-3dbe57deae6d'
> I0611 00:40:28.311640 26063 slave.cpp:631] Successfully attached file
> '/tmp/FetcherCacheHttpTest_HttpMixed_kwsjNe/slaves/20150611-004028-1946161580-33349-26042-S0/frameworks/20150611-004028-1946161580-33349-26042-0000/executors/1/runs/fe2dae2c-3efc-49e2-98a9-c6ffd689e1ef'
> I0611 00:40:28.311704 26063 slave.cpp:631] Successfully attached file
> '/tmp/FetcherCacheHttpTest_HttpMixed_kwsjNe/slaves/20150611-004028-1946161580-33349-26042-S0/frameworks/20150611-004028-1946161580-33349-26042-0000/executors/2/runs/09e97509-9ee7-4c22-b6ae-7017b778e120'
> I0611 00:40:28.313941 26076 launcher.cpp:131] Forked child with pid '30631'
> for container '09e97509-9ee7-4c22-b6ae-7017b778e120'
> I0611 00:40:28.314162 26076 containerizer.cpp:766] Checkpointing executor's
> forked pid 30631 to
> '/tmp/FetcherCacheHttpTest_HttpMixed_kwsjNe/meta/slaves/20150611-004028-1946161580-33349-26042-S0/frameworks/20150611-004028-1946161580-33349-26042-0000/executors/2/runs/09e97509-9ee7-4c22-b6ae-7017b778e120/pids/forked.pid'
> I0611 00:40:28.317991 26073 fetcher.cpp:299] Starting to fetch URIs for
> container: 09e97509-9ee7-4c22-b6ae-7017b778e120, directory:
> /tmp/FetcherCacheHttpTest_HttpMixed_kwsjNe/slaves/20150611-004028-1946161580-33349-26042-S0/frameworks/20150611-004028-1946161580-33349-26042-0000/executors/2/runs/09e97509-9ee7-4c22-b6ae-7017b778e120
> I0611 00:40:28.325078 26069 process.cpp:2751] Handling HTTP event for process
> '(1407)' with path: '/(1407)/mesos-fetcher-test-archive.tgz'
> I0611 00:40:28.325812 26070 process.cpp:1082] Sending file at
> '/tmp/FetcherCacheHttpTest_HttpMixed_kwsjNe/mesos-fetcher-test-assets/mesos-fetcher-test-archive.tgz'
> with length 145
> HTTP/1.1 200 OK
> Date: Thu, 11 Jun 2015 00:40:28 GMT
> Content-Length: 145
> I0611 00:40:28.331157 26073 fetcher.cpp:756] Fetching URIs using command
> '/mesos/mesos-0.23.0/_build/src/mesos-fetcher'
> I0611 00:40:28.333117 26073 fetcher.cpp:663] Claiming fetcher cache space
> for: mesos@http://172.17.0.116:33349/(1407)/mesos-fetcher-test-archive.tgz
> I0611 00:40:28.333161 26073 fetcher.cpp:1086] Claimed cache space: 145B, now
> using: 145B
> I0611 00:40:28.339479 26064 fetcher.cpp:756] Fetching URIs using command
> '/mesos/mesos-0.23.0/_build/src/mesos-fetcher'
> I0611 00:40:28.391845 26068 process.cpp:2751] Handling HTTP event for process
> '(1407)' with path: '/(1407)/mesos-fetcher-test-archive.tgz'
> I0611 00:40:28.392280 26071 process.cpp:1082] Sending file at
> '/tmp/FetcherCacheHttpTest_HttpMixed_kwsjNe/mesos-fetcher-test-assets/mesos-fetcher-test-archive.tgz'
> with length 145
> I0611 00:40:28.394189 26070 process.cpp:2751] Handling HTTP event for process
> '(1407)' with path: '/(1407)/mesos-fetcher-test-archive.tgz'
> I0611 00:40:28.394484 26074 process.cpp:1082] Sending file at
> '/tmp/FetcherCacheHttpTest_HttpMixed_kwsjNe/mesos-fetcher-test-assets/mesos-fetcher-test-archive.tgz'
> with length 145
> I0611 00:40:28.399312 26066 process.cpp:2751] Handling HTTP event for process
> '(1407)' with path: '/(1407)/mesos-fetcher-test-cmd'
> I0611 00:40:28.399658 26068 process.cpp:1082] Sending file at
> '/tmp/FetcherCacheHttpTest_HttpMixed_kwsjNe/mesos-fetcher-test-assets/mesos-fetcher-test-cmd'
> with length 30
> E0611 00:40:28.491381 26062 fetcher.cpp:515] Failed to run mesos-fetcher:
> Failed to fetch all URIs for container 'fe2dae2c-3efc-49e2-98a9-c6ffd689e1ef'
> with exit status: 256
> I0611 00:40:28.491879 26062 fetcher.cpp:1098] Released cache space: 0B, now
> using: 145B
> E0611 00:40:28.491886 26065 slave.cpp:3154] Container
> 'fe2dae2c-3efc-49e2-98a9-c6ffd689e1ef' for executor '1' of framework
> '20150611-004028-1946161580-33349-26042-0000' failed to start: Failed to
> fetch all URIs for container 'fe2dae2c-3efc-49e2-98a9-c6ffd689e1ef' with exit
> status: 256
> I0611 00:40:28.492027 26068 containerizer.cpp:997] Destroying container
> 'fe2dae2c-3efc-49e2-98a9-c6ffd689e1ef'
> I0611 00:40:28.492053 26068 containerizer.cpp:1026] Waiting for the isolators
> to complete for container 'fe2dae2c-3efc-49e2-98a9-c6ffd689e1ef'
> I0611 00:40:28.499197 26067 fetcher.cpp:756] Fetching URIs using command
> '/mesos/mesos-0.23.0/_build/src/mesos-fetcher'
> I0611 00:40:28.499322 26062 slave.cpp:3211] Monitoring executor '0' of
> framework '20150611-004028-1946161580-33349-26042-0000' in container
> '7bde6e5f-f6a9-4631-973b-3dbe57deae6d'
> WARNING: Logging before InitGoogleLogging() is written to STDERR
> I0611 00:40:28.558794 30697 process.cpp:926] libprocess is initialized on
> 172.17.0.116:46512 for 16 cpus
> I0611 00:40:28.559777 30697 logging.cpp:177] Logging to STDERR
> I0611 00:40:28.562319 30697 exec.cpp:132] Version: 0.23.0
> I0611 00:40:28.572161 30732 exec.cpp:182] Executor started at:
> executor(1)@172.17.0.116:46512 with pid 30697
> I0611 00:40:28.574589 26071 slave.cpp:2198] Got registration for executor '0'
> of framework 20150611-004028-1946161580-33349-26042-0000 from
> executor(1)@172.17.0.116:46512
> I0611 00:40:28.574707 26071 slave.cpp:2284] Checkpointing executor pid
> 'executor(1)@172.17.0.116:46512' to
> '/tmp/FetcherCacheHttpTest_HttpMixed_kwsjNe/meta/slaves/20150611-004028-1946161580-33349-26042-S0/frameworks/20150611-004028-1946161580-33349-26042-0000/executors/0/runs/7bde6e5f-f6a9-4631-973b-3dbe57deae6d/pids/libprocess.pid'
> I0611 00:40:28.576479 26074 slave.cpp:1598] Sending queued task '0' to
> executor '0' of framework 20150611-004028-1946161580-33349-26042-0000
> I0611 00:40:28.576915 30727 exec.cpp:206] Executor registered on slave
> 20150611-004028-1946161580-33349-26042-S0
> I0611 00:40:28.578711 30727 exec.cpp:218] Executor::registered took 242627ns
> Registered executor on 658ddc752264
> I0611 00:40:28.579038 30727 exec.cpp:293] Executor asked to run task '0'
> Starting task 0
> I0611 00:40:28.579160 30727 exec.cpp:302] Executor::launchTask took 95102ns
> Forked command at 30743
> sh -c './mesos-fetcher-test-cmd 0'
> I0611 00:40:28.582968 30730 exec.cpp:507] Executor sending status update
> TASK_RUNNING (UUID: 9e94363e-e0e1-4bd2-aa92-cf290a2530b1) for task 0 of
> framework 20150611-004028-1946161580-33349-26042-0000
> I0611 00:40:28.583927 26071 slave.cpp:2564] Handling status update
> TASK_RUNNING (UUID: 9e94363e-e0e1-4bd2-aa92-cf290a2530b1) for task 0 of
> framework 20150611-004028-1946161580-33349-26042-0000 from
> executor(1)@172.17.0.116:46512
> I0611 00:40:28.584228 26072 status_update_manager.cpp:321] Received status
> update TASK_RUNNING (UUID: 9e94363e-e0e1-4bd2-aa92-cf290a2530b1) for task 0
> of framework 20150611-004028-1946161580-33349-26042-0000
> I0611 00:40:28.584264 26072 status_update_manager.cpp:498] Creating
> StatusUpdate stream for task 0 of framework
> 20150611-004028-1946161580-33349-26042-0000
> I0611 00:40:28.584704 26072 status_update_manager.cpp:821] Checkpointing
> UPDATE for status update TASK_RUNNING (UUID:
> 9e94363e-e0e1-4bd2-aa92-cf290a2530b1) for task 0 of framework
> 20150611-004028-1946161580-33349-26042-0000
> I0611 00:40:28.586175 26072 status_update_manager.cpp:375] Forwarding update
> TASK_RUNNING (UUID: 9e94363e-e0e1-4bd2-aa92-cf290a2530b1) for task 0 of
> framework 20150611-004028-1946161580-33349-26042-0000 to the slave
> I0611 00:40:28.586480 26072 slave.cpp:2819] Forwarding the update
> TASK_RUNNING (UUID: 9e94363e-e0e1-4bd2-aa92-cf290a2530b1) for task 0 of
> framework 20150611-004028-1946161580-33349-26042-0000 to
> [email protected]:33349
> I0611 00:40:28.586612 26072 slave.cpp:2746] Status update manager
> successfully handled status update TASK_RUNNING (UUID:
> 9e94363e-e0e1-4bd2-aa92-cf290a2530b1) for task 0 of framework
> 20150611-004028-1946161580-33349-26042-0000
> I0611 00:40:28.586645 26072 slave.cpp:2752] Sending acknowledgement for
> status update TASK_RUNNING (UUID: 9e94363e-e0e1-4bd2-aa92-cf290a2530b1) for
> task 0 of framework 20150611-004028-1946161580-33349-26042-0000 to
> executor(1)@172.17.0.116:46512
> I0611 00:40:28.587002 26076 master.cpp:3585] Status update TASK_RUNNING
> (UUID: 9e94363e-e0e1-4bd2-aa92-cf290a2530b1) for task 0 of framework
> 20150611-004028-1946161580-33349-26042-0000 from slave
> 20150611-004028-1946161580-33349-26042-S0 at slave(47)@172.17.0.116:33349
> (658ddc752264)
> I0611 00:40:28.587038 26076 master.cpp:3624] Forwarding status update
> TASK_RUNNING (UUID: 9e94363e-e0e1-4bd2-aa92-cf290a2530b1) for task 0 of
> framework 20150611-004028-1946161580-33349-26042-0000
> I0611 00:40:28.587162 26076 master.cpp:4978] Updating the latest state of
> task 0 of framework 20150611-004028-1946161580-33349-26042-0000 to
> TASK_RUNNING
> I0611 00:40:28.587364 26061 sched.cpp:717] Scheduler::statusUpdate took
> 119729ns
> I0611 00:40:28.587575 26062 master.cpp:3015] Forwarding status update
> acknowledgement 9e94363e-e0e1-4bd2-aa92-cf290a2530b1 for task 0 of framework
> 20150611-004028-1946161580-33349-26042-0000 (default) at
> [email protected]:33349 to slave
> 20150611-004028-1946161580-33349-26042-S0 at slave(47)@172.17.0.116:33349
> (658ddc752264)
> I0611 00:40:28.587920 26068 status_update_manager.cpp:393] Received status
> update acknowledgement (UUID: 9e94363e-e0e1-4bd2-aa92-cf290a2530b1) for task
> 0 of framework 20150611-004028-1946161580-33349-26042-0000
> I0611 00:40:28.587990 30725 exec.cpp:339] Executor received status update
> acknowledgement 9e94363e-e0e1-4bd2-aa92-cf290a2530b1 for task 0 of framework
> 20150611-004028-1946161580-33349-26042-0000
> I0611 00:40:28.588034 26068 status_update_manager.cpp:821] Checkpointing ACK
> for status update TASK_RUNNING (UUID: 9e94363e-e0e1-4bd2-aa92-cf290a2530b1)
> for task 0 of framework 20150611-004028-1946161580-33349-26042-0000
> I0611 00:40:28.588912 26076 slave.cpp:2138] Status update manager
> successfully handled status update acknowledgement (UUID:
> 9e94363e-e0e1-4bd2-aa92-cf290a2530b1) for task 0 of framework
> 20150611-004028-1946161580-33349-26042-0000
> I0611 00:40:28.592269 26068 containerizer.cpp:1184] Executor for container
> 'fe2dae2c-3efc-49e2-98a9-c6ffd689e1ef' has exited
> E0611 00:40:28.593114 26073 fetcher.cpp:515] Failed to run mesos-fetcher:
> Failed to fetch all URIs for container '09e97509-9ee7-4c22-b6ae-7017b778e120'
> with exit status: 256
> Failed to synchronize with slave (it's probably exited)
> E0611 00:40:28.593425 26063 slave.cpp:3154] Container
> '09e97509-9ee7-4c22-b6ae-7017b778e120' for executor '2' of framework
> '20150611-004028-1946161580-33349-26042-0000' failed to start: Failed to
> fetch all URIs for container '09e97509-9ee7-4c22-b6ae-7017b778e120' with exit
> status: 256
> I0611 00:40:28.593508 26072 containerizer.cpp:997] Destroying container
> '09e97509-9ee7-4c22-b6ae-7017b778e120'
> I0611 00:40:28.593530 26063 slave.cpp:3268] Executor '1' of framework
> 20150611-004028-1946161580-33349-26042-0000 terminated with signal Killed
> I0611 00:40:28.593530 26072 containerizer.cpp:1026] Waiting for the isolators
> to complete for container '09e97509-9ee7-4c22-b6ae-7017b778e120'
> E0611 00:40:28.593739 26069 slave.cpp:3515] Failed to unmonitor container for
> executor 1 of framework 20150611-004028-1946161580-33349-26042-0000: Not
> monitored
> I0611 00:40:28.595237 26063 slave.cpp:2564] Handling status update
> TASK_FAILED (UUID: c4066d51-abab-43a2-bf20-f28063ed0153) for task 1 of
> framework 20150611-004028-1946161580-33349-26042-0000 from @0.0.0.0:0
> I0611 00:40:28.595484 26063 slave.cpp:4813] Terminating task 1
> I0611 00:40:28.595937 26077 process.cpp:552] Decode failure: Connection reset
> by peer
> W0611 00:40:28.597589 26072 containerizer.cpp:881] Ignoring update for
> unknown container: fe2dae2c-3efc-49e2-98a9-c6ffd689e1ef
> I0611 00:40:28.597913 26067 status_update_manager.cpp:321] Received status
> update TASK_FAILED (UUID: c4066d51-abab-43a2-bf20-f28063ed0153) for task 1 of
> framework 20150611-004028-1946161580-33349-26042-0000
> I0611 00:40:28.597955 26067 status_update_manager.cpp:498] Creating
> StatusUpdate stream for task 1 of framework
> 20150611-004028-1946161580-33349-26042-0000
> I0611 00:40:28.598310 26067 status_update_manager.cpp:821] Checkpointing
> UPDATE for status update TASK_FAILED (UUID:
> c4066d51-abab-43a2-bf20-f28063ed0153) for task 1 of framework
> 20150611-004028-1946161580-33349-26042-0000
> I0611 00:40:28.599653 26067 status_update_manager.cpp:375] Forwarding update
> TASK_FAILED (UUID: c4066d51-abab-43a2-bf20-f28063ed0153) for task 1 of
> framework 20150611-004028-1946161580-33349-26042-0000 to the slave
> I0611 00:40:28.599859 26065 slave.cpp:2819] Forwarding the update TASK_FAILED
> (UUID: c4066d51-abab-43a2-bf20-f28063ed0153) for task 1 of framework
> 20150611-004028-1946161580-33349-26042-0000 to [email protected]:33349
> I0611 00:40:28.600031 26065 slave.cpp:2746] Status update manager
> successfully handled status update TASK_FAILED (UUID:
> c4066d51-abab-43a2-bf20-f28063ed0153) for task 1 of framework
> 20150611-004028-1946161580-33349-26042-0000
> I0611 00:40:28.600142 26064 master.cpp:3585] Status update TASK_FAILED (UUID:
> c4066d51-abab-43a2-bf20-f28063ed0153) for task 1 of framework
> 20150611-004028-1946161580-33349-26042-0000 from slave
> 20150611-004028-1946161580-33349-26042-S0 at slave(47)@172.17.0.116:33349
> (658ddc752264)
> I0611 00:40:28.600179 26064 master.cpp:3624] Forwarding status update
> TASK_FAILED (UUID: c4066d51-abab-43a2-bf20-f28063ed0153) for task 1 of
> framework 20150611-004028-1946161580-33349-26042-0000
> I0611 00:40:28.600316 26064 master.cpp:4978] Updating the latest state of
> task 1 of framework 20150611-004028-1946161580-33349-26042-0000 to TASK_FAILED
> I0611 00:40:28.600571 26069 sched.cpp:717] Scheduler::statusUpdate took
> 97941ns
> I0611 00:40:28.600594 26061 hierarchical.hpp:741] Recovered cpus(*):1;
> mem(*):1 (total allocatable: cpus(*):998; mem(*):998; disk(*):3.70122e+06;
> ports(*):[31000-32000]) on slave 20150611-004028-1946161580-33349-26042-S0
> from framework 20150611-004028-1946161580-33349-26042-0000
> I0611 00:40:28.600893 26064 master.cpp:5046] Removing task 1 with resources
> cpus(*):1; mem(*):1 of framework 20150611-004028-1946161580-33349-26042-0000
> on slave 20150611-004028-1946161580-33349-26042-S0 at
> slave(47)@172.17.0.116:33349 (658ddc752264)
> I0611 00:40:28.601007 26064 master.cpp:3015] Forwarding status update
> acknowledgement c4066d51-abab-43a2-bf20-f28063ed0153 for task 1 of framework
> 20150611-004028-1946161580-33349-26042-0000 (default) at
> [email protected]:33349 to slave
> 20150611-004028-1946161580-33349-26042-S0 at slave(47)@172.17.0.116:33349
> (658ddc752264)
> I0611 00:40:28.601276 26066 status_update_manager.cpp:393] Received status
> update acknowledgement (UUID: c4066d51-abab-43a2-bf20-f28063ed0153) for task
> 1 of framework 20150611-004028-1946161580-33349-26042-0000
> I0611 00:40:28.601361 26066 status_update_manager.cpp:821] Checkpointing ACK
> for status update TASK_FAILED (UUID: c4066d51-abab-43a2-bf20-f28063ed0153)
> for task 1 of framework 20150611-004028-1946161580-33349-26042-0000
> I0611 00:40:28.602502 26066 status_update_manager.cpp:529] Cleaning up status
> update stream for task 1 of framework
> 20150611-004028-1946161580-33349-26042-0000
> I0611 00:40:28.602725 26071 slave.cpp:2138] Status update manager
> successfully handled status update acknowledgement (UUID:
> c4066d51-abab-43a2-bf20-f28063ed0153) for task 1 of framework
> 20150611-004028-1946161580-33349-26042-0000
> I0611 00:40:28.602778 26071 slave.cpp:4854] Completing task 1
> I0611 00:40:28.602901 26071 slave.cpp:3378] Cleaning up executor '1' of
> framework 20150611-004028-1946161580-33349-26042-0000
> I0611 00:40:28.603219 26062 gc.cpp:56] Scheduling
> '/tmp/FetcherCacheHttpTest_HttpMixed_kwsjNe/slaves/20150611-004028-1946161580-33349-26042-S0/frameworks/20150611-004028-1946161580-33349-26042-0000/executors/1/runs/fe2dae2c-3efc-49e2-98a9-c6ffd689e1ef'
> for gc 6.99999301946963days in the future
> I0611 00:40:28.603381 26062 gc.cpp:56] Scheduling
> '/tmp/FetcherCacheHttpTest_HttpMixed_kwsjNe/slaves/20150611-004028-1946161580-33349-26042-S0/frameworks/20150611-004028-1946161580-33349-26042-0000/executors/1'
> for gc 6.99999301806518days in the future
> I0611 00:40:28.603464 26062 gc.cpp:56] Scheduling
> '/tmp/FetcherCacheHttpTest_HttpMixed_kwsjNe/meta/slaves/20150611-004028-1946161580-33349-26042-S0/frameworks/20150611-004028-1946161580-33349-26042-0000/executors/1/runs/fe2dae2c-3efc-49e2-98a9-c6ffd689e1ef'
> for gc 6.99999301674667days in the future
> I0611 00:40:28.603598 26062 gc.cpp:56] Scheduling
> '/tmp/FetcherCacheHttpTest_HttpMixed_kwsjNe/meta/slaves/20150611-004028-1946161580-33349-26042-S0/frameworks/20150611-004028-1946161580-33349-26042-0000/executors/1'
> for gc 6.99999301563556days in the future
> Command exited with status 0 (pid: 30743)
> I0611 00:40:28.684661 30736 exec.cpp:507] Executor sending status update
> TASK_FINISHED (UUID: e4609c35-53c8-42ee-b945-54bddad51ab6) for task 0 of
> framework 20150611-004028-1946161580-33349-26042-0000
> I0611 00:40:28.685423 26066 slave.cpp:2564] Handling status update
> TASK_FINISHED (UUID: e4609c35-53c8-42ee-b945-54bddad51ab6) for task 0 of
> framework 20150611-004028-1946161580-33349-26042-0000 from
> executor(1)@172.17.0.116:46512
> I0611 00:40:28.685531 26066 slave.cpp:4813] Terminating task 0
> I0611 00:40:28.686537 26067 status_update_manager.cpp:321] Received status
> update TASK_FINISHED (UUID: e4609c35-53c8-42ee-b945-54bddad51ab6) for task 0
> of framework 20150611-004028-1946161580-33349-26042-0000
> I0611 00:40:28.686595 26067 status_update_manager.cpp:821] Checkpointing
> UPDATE for status update TASK_FINISHED (UUID:
> e4609c35-53c8-42ee-b945-54bddad51ab6) for task 0 of framework
> 20150611-004028-1946161580-33349-26042-0000
> I0611 00:40:28.687923 26067 status_update_manager.cpp:375] Forwarding update
> TASK_FINISHED (UUID: e4609c35-53c8-42ee-b945-54bddad51ab6) for task 0 of
> framework 20150611-004028-1946161580-33349-26042-0000 to the slave
> I0611 00:40:28.688122 26073 slave.cpp:2819] Forwarding the update
> TASK_FINISHED (UUID: e4609c35-53c8-42ee-b945-54bddad51ab6) for task 0 of
> framework 20150611-004028-1946161580-33349-26042-0000 to
> [email protected]:33349
> I0611 00:40:28.688282 26073 slave.cpp:2746] Status update manager
> successfully handled status update TASK_FINISHED (UUID:
> e4609c35-53c8-42ee-b945-54bddad51ab6) for task 0 of framework
> 20150611-004028-1946161580-33349-26042-0000
> I0611 00:40:28.688315 26073 slave.cpp:2752] Sending acknowledgement for
> status update TASK_FINISHED (UUID: e4609c35-53c8-42ee-b945-54bddad51ab6) for
> task 0 of framework 20150611-004028-1946161580-33349-26042-0000 to
> executor(1)@172.17.0.116:46512
> I0611 00:40:28.688357 26066 master.cpp:3585] Status update TASK_FINISHED
> (UUID: e4609c35-53c8-42ee-b945-54bddad51ab6) for task 0 of framework
> 20150611-004028-1946161580-33349-26042-0000 from slave
> 20150611-004028-1946161580-33349-26042-S0 at slave(47)@172.17.0.116:33349
> (658ddc752264)
> I0611 00:40:28.688396 26066 master.cpp:3624] Forwarding status update
> TASK_FINISHED (UUID: e4609c35-53c8-42ee-b945-54bddad51ab6) for task 0 of
> framework 20150611-004028-1946161580-33349-26042-0000
> I0611 00:40:28.688534 26066 master.cpp:4978] Updating the latest state of
> task 0 of framework 20150611-004028-1946161580-33349-26042-0000 to
> TASK_FINISHED
> I0611 00:40:28.688725 26069 sched.cpp:717] Scheduler::statusUpdate took
> 102799ns
> I0611 00:40:28.688778 26065 hierarchical.hpp:741] Recovered cpus(*):1;
> mem(*):1 (total allocatable: cpus(*):999; mem(*):999; disk(*):3.70122e+06;
> ports(*):[31000-32000]) on slave 20150611-004028-1946161580-33349-26042-S0
> from framework 20150611-004028-1946161580-33349-26042-0000
> I0611 00:40:28.689079 26072 master.cpp:5046] Removing task 0 with resources
> cpus(*):1; mem(*):1 of framework 20150611-004028-1946161580-33349-26042-0000
> on slave 20150611-004028-1946161580-33349-26042-S0 at
> slave(47)@172.17.0.116:33349 (658ddc752264)
> I0611 00:40:28.689205 26072 master.cpp:3015] Forwarding status update
> acknowledgement e4609c35-53c8-42ee-b945-54bddad51ab6 for task 0 of framework
> 20150611-004028-1946161580-33349-26042-0000 (default) at
> [email protected]:33349 to slave
> 20150611-004028-1946161580-33349-26042-S0 at slave(47)@172.17.0.116:33349
> (658ddc752264)
> I0611 00:40:28.689443 26061 status_update_manager.cpp:393] Received status
> update acknowledgement (UUID: e4609c35-53c8-42ee-b945-54bddad51ab6) for task
> 0 of framework 20150611-004028-1946161580-33349-26042-0000
> I0611 00:40:28.689479 30728 exec.cpp:339] Executor received status update
> acknowledgement e4609c35-53c8-42ee-b945-54bddad51ab6 for task 0 of framework
> 20150611-004028-1946161580-33349-26042-0000
> I0611 00:40:28.689602 26061 status_update_manager.cpp:821] Checkpointing ACK
> for status update TASK_FINISHED (UUID: e4609c35-53c8-42ee-b945-54bddad51ab6)
> for task 0 of framework 20150611-004028-1946161580-33349-26042-0000
> I0611 00:40:28.690604 26061 status_update_manager.cpp:529] Cleaning up status
> update stream for task 0 of framework
> 20150611-004028-1946161580-33349-26042-0000
> I0611 00:40:28.690866 26067 slave.cpp:2138] Status update manager
> successfully handled status update acknowledgement (UUID:
> e4609c35-53c8-42ee-b945-54bddad51ab6) for task 0 of framework
> 20150611-004028-1946161580-33349-26042-0000
> I0611 00:40:28.690961 26067 slave.cpp:4854] Completing task 0
> I0611 00:40:28.693780 26066 containerizer.cpp:1184] Executor for container
> '09e97509-9ee7-4c22-b6ae-7017b778e120' has exited
> I0611 00:40:28.694926 26066 slave.cpp:3268] Executor '2' of framework
> 20150611-004028-1946161580-33349-26042-0000 exited with status 1
> E0611 00:40:28.695080 26072 slave.cpp:3515] Failed to unmonitor container for
> executor 2 of framework 20150611-004028-1946161580-33349-26042-0000: Not
> monitored
> I0611 00:40:28.696722 26066 slave.cpp:2564] Handling status update
> TASK_FAILED (UUID: 82f23559-b612-44ef-bc14-2c42368ba13d) for task 2 of
> framework 20150611-004028-1946161580-33349-26042-0000 from @0.0.0.0:0
> I0611 00:40:28.696780 26066 slave.cpp:4813] Terminating task 2
> W0611 00:40:28.697016 26076 containerizer.cpp:881] Ignoring update for
> unknown container: 09e97509-9ee7-4c22-b6ae-7017b778e120
> I0611 00:40:28.697342 26076 status_update_manager.cpp:321] Received status
> update TASK_FAILED (UUID: 82f23559-b612-44ef-bc14-2c42368ba13d) for task 2 of
> framework 20150611-004028-1946161580-33349-26042-0000
> I0611 00:40:28.697381 26076 status_update_manager.cpp:498] Creating
> StatusUpdate stream for task 2 of framework
> 20150611-004028-1946161580-33349-26042-0000
> I0611 00:40:28.697770 26076 status_update_manager.cpp:821] Checkpointing
> UPDATE for status update TASK_FAILED (UUID:
> 82f23559-b612-44ef-bc14-2c42368ba13d) for task 2 of framework
> 20150611-004028-1946161580-33349-26042-0000
> I0611 00:40:28.699062 26076 status_update_manager.cpp:375] Forwarding update
> TASK_FAILED (UUID: 82f23559-b612-44ef-bc14-2c42368ba13d) for task 2 of
> framework 20150611-004028-1946161580-33349-26042-0000 to the slave
> I0611 00:40:28.699250 26074 slave.cpp:2819] Forwarding the update TASK_FAILED
> (UUID: 82f23559-b612-44ef-bc14-2c42368ba13d) for task 2 of framework
> 20150611-004028-1946161580-33349-26042-0000 to [email protected]:33349
> I0611 00:40:28.699416 26074 slave.cpp:2746] Status update manager
> successfully handled status update TASK_FAILED (UUID:
> 82f23559-b612-44ef-bc14-2c42368ba13d) for task 2 of framework
> 20150611-004028-1946161580-33349-26042-0000
> I0611 00:40:28.699529 26061 master.cpp:3585] Status update TASK_FAILED (UUID:
> 82f23559-b612-44ef-bc14-2c42368ba13d) for task 2 of framework
> 20150611-004028-1946161580-33349-26042-0000 from slave
> 20150611-004028-1946161580-33349-26042-S0 at slave(47)@172.17.0.116:33349
> (658ddc752264)
> I0611 00:40:28.699561 26061 master.cpp:3624] Forwarding status update
> TASK_FAILED (UUID: 82f23559-b612-44ef-bc14-2c42368ba13d) for task 2 of
> framework 20150611-004028-1946161580-33349-26042-0000
> I0611 00:40:28.699686 26061 master.cpp:4978] Updating the latest state of
> task 2 of framework 20150611-004028-1946161580-33349-26042-0000 to TASK_FAILED
> I0611 00:40:28.699928 26070 sched.cpp:717] Scheduler::statusUpdate took
> 111157ns
> I0611 00:40:28.699976 26067 hierarchical.hpp:741] Recovered cpus(*):1;
> mem(*):1 (total allocatable: cpus(*):1000; mem(*):1000; disk(*):3.70122e+06;
> ports(*):[31000-32000]) on slave 20150611-004028-1946161580-33349-26042-S0
> from framework 20150611-004028-1946161580-33349-26042-0000
> I0611 00:40:28.700158 26065 master.cpp:5046] Removing task 2 with resources
> cpus(*):1; mem(*):1 of framework 20150611-004028-1946161580-33349-26042-0000
> on slave 20150611-004028-1946161580-33349-26042-S0 at
> slave(47)@172.17.0.116:33349 (658ddc752264)
> I0611 00:40:28.700294 26065 master.cpp:3015] Forwarding status update
> acknowledgement 82f23559-b612-44ef-bc14-2c42368ba13d for task 2 of framework
> 20150611-004028-1946161580-33349-26042-0000 (default) at
> [email protected]:33349 to slave
> 20150611-004028-1946161580-33349-26042-S0 at slave(47)@172.17.0.116:33349
> (658ddc752264)
> I0611 00:40:28.700510 26065 status_update_manager.cpp:393] Received status
> update acknowledgement (UUID: 82f23559-b612-44ef-bc14-2c42368ba13d) for task
> 2 of framework 20150611-004028-1946161580-33349-26042-0000
> I0611 00:40:28.700615 26065 status_update_manager.cpp:821] Checkpointing ACK
> for status update TASK_FAILED (UUID: 82f23559-b612-44ef-bc14-2c42368ba13d)
> for task 2 of framework 20150611-004028-1946161580-33349-26042-0000
> I0611 00:40:28.701634 26065 status_update_manager.cpp:529] Cleaning up status
> update stream for task 2 of framework
> 20150611-004028-1946161580-33349-26042-0000
> I0611 00:40:28.701866 26061 slave.cpp:2138] Status update manager
> successfully handled status update acknowledgement (UUID:
> 82f23559-b612-44ef-bc14-2c42368ba13d) for task 2 of framework
> 20150611-004028-1946161580-33349-26042-0000
> I0611 00:40:28.701918 26061 slave.cpp:4854] Completing task 2
> I0611 00:40:28.701962 26061 slave.cpp:3378] Cleaning up executor '2' of
> framework 20150611-004028-1946161580-33349-26042-0000
> I0611 00:40:28.702255 26062 gc.cpp:56] Scheduling
> '/tmp/FetcherCacheHttpTest_HttpMixed_kwsjNe/slaves/20150611-004028-1946161580-33349-26042-S0/frameworks/20150611-004028-1946161580-33349-26042-0000/executors/2/runs/09e97509-9ee7-4c22-b6ae-7017b778e120'
> for gc 6.9999918729037days in the future
> I0611 00:40:28.702478 26062 gc.cpp:56] Scheduling
> '/tmp/FetcherCacheHttpTest_HttpMixed_kwsjNe/slaves/20150611-004028-1946161580-33349-26042-S0/frameworks/20150611-004028-1946161580-33349-26042-0000/executors/2'
> for gc 6.99999187138963days in the future
> I0611 00:40:28.702582 26062 gc.cpp:56] Scheduling
> '/tmp/FetcherCacheHttpTest_HttpMixed_kwsjNe/meta/slaves/20150611-004028-1946161580-33349-26042-S0/frameworks/20150611-004028-1946161580-33349-26042-0000/executors/2/runs/09e97509-9ee7-4c22-b6ae-7017b778e120'
> for gc 6.99999187020741days in the future
> I0611 00:40:28.702733 26062 gc.cpp:56] Scheduling
> '/tmp/FetcherCacheHttpTest_HttpMixed_kwsjNe/meta/slaves/20150611-004028-1946161580-33349-26042-S0/frameworks/20150611-004028-1946161580-33349-26042-0000/executors/2'
> for gc 6.99999186917926days in the future
> I0611 00:40:29.217691 26069 hierarchical.hpp:834] Performed allocation for 1
> slaves in 559962ns
> I0611 00:40:29.218114 26064 master.cpp:4111] Sending 1 offers to framework
> 20150611-004028-1946161580-33349-26042-0000 (default) at
> [email protected]:33349
> I0611 00:40:29.218622 26069 sched.cpp:611] Scheduler::resourceOffers took
> 113704ns
> I0611 00:40:29.219339 26070 master.cpp:2424] Processing ACCEPT call for
> offers: [ 20150611-004028-1946161580-33349-26042-O1 ] on slave
> 20150611-004028-1946161580-33349-26042-S0 at slave(47)@172.17.0.116:33349
> (658ddc752264) for framework 20150611-004028-1946161580-33349-26042-0000
> (default) at [email protected]:33349
> I0611 00:40:29.219998 26066 hierarchical.hpp:741] Recovered cpus(*):1000;
> mem(*):1000; disk(*):3.70122e+06; ports(*):[31000-32000] (total allocatable:
> cpus(*):1000; mem(*):1000; disk(*):3.70122e+06; ports(*):[31000-32000]) on
> slave 20150611-004028-1946161580-33349-26042-S0 from framework
> 20150611-004028-1946161580-33349-26042-0000
> I0611 00:40:29.220055 26066 hierarchical.hpp:777] Framework
> 20150611-004028-1946161580-33349-26042-0000 filtered slave
> 20150611-004028-1946161580-33349-26042-S0 for 5secs
> I0611 00:40:29.700505 26075 containerizer.cpp:1184] Executor for container
> '7bde6e5f-f6a9-4631-973b-3dbe57deae6d' has exited
> I0611 00:40:29.700566 26075 containerizer.cpp:997] Destroying container
> '7bde6e5f-f6a9-4631-973b-3dbe57deae6d'
> I0611 00:40:29.703644 26065 slave.cpp:3268] Executor '0' of framework
> 20150611-004028-1946161580-33349-26042-0000 exited with status 0
> I0611 00:40:29.703851 26065 slave.cpp:3378] Cleaning up executor '0' of
> framework 20150611-004028-1946161580-33349-26042-0000
> I0611 00:40:29.704249 26066 gc.cpp:56] Scheduling
> '/tmp/FetcherCacheHttpTest_HttpMixed_kwsjNe/slaves/20150611-004028-1946161580-33349-26042-S0/frameworks/20150611-004028-1946161580-33349-26042-0000/executors/0/runs/7bde6e5f-f6a9-4631-973b-3dbe57deae6d'
> for gc 6.99999184983704days in the future
> I0611 00:40:29.704416 26075 gc.cpp:56] Scheduling
> '/tmp/FetcherCacheHttpTest_HttpMixed_kwsjNe/slaves/20150611-004028-1946161580-33349-26042-S0/frameworks/20150611-004028-1946161580-33349-26042-0000/executors/0'
> for gc 6.99999184786963days in the future
> I0611 00:40:29.704507 26075 gc.cpp:56] Scheduling
> '/tmp/FetcherCacheHttpTest_HttpMixed_kwsjNe/meta/slaves/20150611-004028-1946161580-33349-26042-S0/frameworks/20150611-004028-1946161580-33349-26042-0000/executors/0/runs/7bde6e5f-f6a9-4631-973b-3dbe57deae6d'
> for gc 6.99999184659852days in the future
> I0611 00:40:29.704608 26065 slave.cpp:3465] Cleaning up framework
> 20150611-004028-1946161580-33349-26042-0000
> I0611 00:40:29.704639 26075 gc.cpp:56] Scheduling
> '/tmp/FetcherCacheHttpTest_HttpMixed_kwsjNe/meta/slaves/20150611-004028-1946161580-33349-26042-S0/frameworks/20150611-004028-1946161580-33349-26042-0000/executors/0'
> for gc 6.99999184553185days in the future
> I0611 00:40:29.704718 26062 status_update_manager.cpp:283] Closing status
> update streams for framework 20150611-004028-1946161580-33349-26042-0000
> I0611 00:40:29.704789 26062 gc.cpp:56] Scheduling
> '/tmp/FetcherCacheHttpTest_HttpMixed_kwsjNe/slaves/20150611-004028-1946161580-33349-26042-S0/frameworks/20150611-004028-1946161580-33349-26042-0000'
> for gc 6.99999184344889days in the future
> I0611 00:40:29.704926 26062 gc.cpp:56] Scheduling
> '/tmp/FetcherCacheHttpTest_HttpMixed_kwsjNe/meta/slaves/20150611-004028-1946161580-33349-26042-S0/frameworks/20150611-004028-1946161580-33349-26042-0000'
> for gc 6.99999184208296days in the future
> I0611 00:40:30.219069 26070 hierarchical.hpp:997] Filtered cpus(*):1000;
> mem(*):1000; disk(*):3.70122e+06; ports(*):[31000-32000] on slave
> 20150611-004028-1946161580-33349-26042-S0 for framework
> 20150611-004028-1946161580-33349-26042-0000
> I0611 00:40:30.219151 26070 hierarchical.hpp:933] No resources available to
> allocate!
> I0611 00:40:30.219171 26070 hierarchical.hpp:834] Performed allocation for 1
> slaves in 599271ns
> I0611 00:40:31.220145 26076 hierarchical.hpp:997] Filtered cpus(*):1000;
> mem(*):1000; disk(*):3.70122e+06; ports(*):[31000-32000] on slave
> 20150611-004028-1946161580-33349-26042-S0 for framework
> 20150611-004028-1946161580-33349-26042-0000
> I0611 00:40:31.220199 26076 hierarchical.hpp:933] No resources available to
> allocate!
> I0611 00:40:31.220218 26076 hierarchical.hpp:834] Performed allocation for 1
> slaves in 361554ns
> I0611 00:40:32.220938 26072 hierarchical.hpp:997] Filtered cpus(*):1000;
> mem(*):1000; disk(*):3.70122e+06; ports(*):[31000-32000] on slave
> 20150611-004028-1946161580-33349-26042-S0 for framework
> 20150611-004028-1946161580-33349-26042-0000
> I0611 00:40:32.220989 26072 hierarchical.hpp:933] No resources available to
> allocate!
> I0611 00:40:32.221007 26072 hierarchical.hpp:834] Performed allocation for 1
> slaves in 354664ns
> I0611 00:40:33.221792 26068 hierarchical.hpp:997] Filtered cpus(*):1000;
> mem(*):1000; disk(*):3.70122e+06; ports(*):[31000-32000] on slave
> 20150611-004028-1946161580-33349-26042-S0 for framework
> 20150611-004028-1946161580-33349-26042-0000
> I0611 00:40:33.221897 26068 hierarchical.hpp:933] No resources available to
> allocate!
> I0611 00:40:33.221930 26068 hierarchical.hpp:834] Performed allocation for 1
> slaves in 444354ns
> I0611 00:40:34.223534 26073 hierarchical.hpp:834] Performed allocation for 1
> slaves in 511375ns
> I0611 00:40:34.224037 26075 master.cpp:4111] Sending 1 offers to framework
> 20150611-004028-1946161580-33349-26042-0000 (default) at
> [email protected]:33349
> I0611 00:40:34.224625 26075 sched.cpp:611] Scheduler::resourceOffers took
> 133787ns
> I0611 00:40:34.225481 26075 master.cpp:2424] Processing ACCEPT call for
> offers: [ 20150611-004028-1946161580-33349-26042-O2 ] on slave
> 20150611-004028-1946161580-33349-26042-S0 at slave(47)@172.17.0.116:33349
> (658ddc752264) for framework 20150611-004028-1946161580-33349-26042-0000
> (default) at [email protected]:33349
> I0611 00:40:34.226282 26075 hierarchical.hpp:741] Recovered cpus(*):1000;
> mem(*):1000; disk(*):3.70122e+06; ports(*):[31000-32000] (total allocatable:
> cpus(*):1000; mem(*):1000; disk(*):3.70122e+06; ports(*):[31000-32000]) on
> slave 20150611-004028-1946161580-33349-26042-S0 from framework
> 20150611-004028-1946161580-33349-26042-0000
> I0611 00:40:34.226343 26075 hierarchical.hpp:777] Framework
> 20150611-004028-1946161580-33349-26042-0000 filtered slave
> 20150611-004028-1946161580-33349-26042-S0 for 5secs
> I0611 00:40:35.224714 26064 hierarchical.hpp:997] Filtered cpus(*):1000;
> mem(*):1000; disk(*):3.70122e+06; ports(*):[31000-32000] on slave
> 20150611-004028-1946161580-33349-26042-S0 for framework
> 20150611-004028-1946161580-33349-26042-0000
> I0611 00:40:35.224768 26064 hierarchical.hpp:933] No resources available to
> allocate!
> I0611 00:40:35.224787 26064 hierarchical.hpp:834] Performed allocation for 1
> slaves in 353370ns
> I0611 00:40:36.225898 26062 hierarchical.hpp:997] Filtered cpus(*):1000;
> mem(*):1000; disk(*):3.70122e+06; ports(*):[31000-32000] on slave
> 20150611-004028-1946161580-33349-26042-S0 for framework
> 20150611-004028-1946161580-33349-26042-0000
> I0611 00:40:36.225947 26062 hierarchical.hpp:933] No resources available to
> allocate!
> I0611 00:40:36.225965 26062 hierarchical.hpp:834] Performed allocation for 1
> slaves in 366492ns
> I0611 00:40:37.227095 26070 hierarchical.hpp:997] Filtered cpus(*):1000;
> mem(*):1000; disk(*):3.70122e+06; ports(*):[31000-32000] on slave
> 20150611-004028-1946161580-33349-26042-S0 for framework
> 20150611-004028-1946161580-33349-26042-0000
> I0611 00:40:37.227152 26070 hierarchical.hpp:933] No resources available to
> allocate!
> I0611 00:40:37.227170 26070 hierarchical.hpp:834] Performed allocation for 1
> slaves in 371931ns
> I0611 00:40:38.228006 26065 hierarchical.hpp:997] Filtered cpus(*):1000;
> mem(*):1000; disk(*):3.70122e+06; ports(*):[31000-32000] on slave
> 20150611-004028-1946161580-33349-26042-S0 for framework
> 20150611-004028-1946161580-33349-26042-0000
> I0611 00:40:38.228065 26065 hierarchical.hpp:933] No resources available to
> allocate!
> I0611 00:40:38.228096 26065 hierarchical.hpp:834] Performed allocation for 1
> slaves in 417441ns
> I0611 00:40:39.229778 26071 hierarchical.hpp:834] Performed allocation for 1
> slaves in 499278ns
> I0611 00:40:39.230177 26074 master.cpp:4111] Sending 1 offers to framework
> 20150611-004028-1946161580-33349-26042-0000 (default) at
> [email protected]:33349
> I0611 00:40:39.230624 26068 sched.cpp:611] Scheduler::resourceOffers took
> 99803ns
> I0611 00:40:39.231348 26076 master.cpp:2424] Processing ACCEPT call for
> offers: [ 20150611-004028-1946161580-33349-26042-O3 ] on slave
> 20150611-004028-1946161580-33349-26042-S0 at slave(47)@172.17.0.116:33349
> (658ddc752264) for framework 20150611-004028-1946161580-33349-26042-0000
> (default) at [email protected]:33349
> I0611 00:40:39.232098 26068 hierarchical.hpp:741] Recovered cpus(*):1000;
> mem(*):1000; disk(*):3.70122e+06; ports(*):[31000-32000] (total allocatable:
> cpus(*):1000; mem(*):1000; disk(*):3.70122e+06; ports(*):[31000-32000]) on
> slave 20150611-004028-1946161580-33349-26042-S0 from framework
> 20150611-004028-1946161580-33349-26042-0000
> I0611 00:40:39.232158 26068 hierarchical.hpp:777] Framework
> 20150611-004028-1946161580-33349-26042-0000 filtered slave
> 20150611-004028-1946161580-33349-26042-S0 for 5secs
> I0611 00:40:40.231142 26074 hierarchical.hpp:997] Filtered cpus(*):1000;
> mem(*):1000; disk(*):3.70122e+06; ports(*):[31000-32000] on slave
> 20150611-004028-1946161580-33349-26042-S0 for framework
> 20150611-004028-1946161580-33349-26042-0000
> I0611 00:40:40.231194 26074 hierarchical.hpp:933] No resources available to
> allocate!
> I0611 00:40:40.231211 26074 hierarchical.hpp:834] Performed allocation for 1
> slaves in 340014ns
> I0611 00:40:41.231977 26066 hierarchical.hpp:997] Filtered cpus(*):1000;
> mem(*):1000; disk(*):3.70122e+06; ports(*):[31000-32000] on slave
> 20150611-004028-1946161580-33349-26042-S0 for framework
> 20150611-004028-1946161580-33349-26042-0000
> I0611 00:40:41.232029 26066 hierarchical.hpp:933] No resources available to
> allocate!
> I0611 00:40:41.232048 26066 hierarchical.hpp:834] Performed allocation for 1
> slaves in 411628ns
> I0611 00:40:42.233392 26071 hierarchical.hpp:997] Filtered cpus(*):1000;
> mem(*):1000; disk(*):3.70122e+06; ports(*):[31000-32000] on slave
> 20150611-004028-1946161580-33349-26042-S0 for framework
> 20150611-004028-1946161580-33349-26042-0000
> I0611 00:40:42.233444 26071 hierarchical.hpp:933] No resources available to
> allocate!
> I0611 00:40:42.233463 26071 hierarchical.hpp:834] Performed allocation for 1
> slaves in 358516ns
> I0611 00:40:43.234984 26076 hierarchical.hpp:997] Filtered cpus(*):1000;
> mem(*):1000; disk(*):3.70122e+06; ports(*):[31000-32000] on slave
> 20150611-004028-1946161580-33349-26042-S0 for framework
> 20150611-004028-1946161580-33349-26042-0000
> I0611 00:40:43.235039 26076 hierarchical.hpp:933] No resources available to
> allocate!
> I0611 00:40:43.235070 26076 hierarchical.hpp:834] Performed allocation for 1
> slaves in 398273ns
> I0611 00:40:43.257271 26070 slave.cpp:4109] Querying resource estimator for
> oversubscribable resources
> I0611 00:40:43.257582 26062 slave.cpp:4130] Received oversubscribable
> resources from the resource estimator
> I0611 00:40:43.267734 26069 slave.cpp:2895] Received ping from
> slave-observer(46)@172.17.0.116:33349
> ../../src/tests/fetcher_cache_tests.cpp:1004: Failure
> Failed to wait 15secs for awaitFinished(tasks)
> I0611 00:40:43.329689 26042 sched.cpp:1591] Asked to stop the driver
> I0611 00:40:43.330145 26073 sched.cpp:831] Stopping framework
> '20150611-004028-1946161580-33349-26042-0000'
> I0611 00:40:43.330777 26074 master.cpp:2054] Asked to unregister framework
> 20150611-004028-1946161580-33349-26042-0000
> I0611 00:40:43.330893 26074 master.cpp:4532] Removing framework
> 20150611-004028-1946161580-33349-26042-0000 (default) at
> [email protected]:33349
> I0611 00:40:43.331203 26063 hierarchical.hpp:437] Deactivated framework
> 20150611-004028-1946161580-33349-26042-0000
> I0611 00:40:43.331290 26065 slave.cpp:1811] Asked to shut down framework
> 20150611-004028-1946161580-33349-26042-0000 by [email protected]:33349
> W0611 00:40:43.331336 26065 slave.cpp:1826] Cannot shut down unknown
> framework 20150611-004028-1946161580-33349-26042-0000
> I0611 00:40:43.331665 26071 hierarchical.hpp:391] Removed framework
> 20150611-004028-1946161580-33349-26042-0000
> I0611 00:40:43.332484 26067 master.cpp:839] Master terminating
> I0611 00:40:43.332773 26074 hierarchical.hpp:527] Removed slave
> 20150611-004028-1946161580-33349-26042-S0
> I0611 00:40:43.333277 26063 slave.cpp:2980] [email protected]:33349 exited
> W0611 00:40:43.333305 26063 slave.cpp:2983] Master disconnected! Waiting for
> a new master to be elected
> I0611 00:40:43.338379 26067 slave.cpp:560] Slave terminating
> [ FAILED ] FetcherCacheHttpTest.HttpMixed (15148 ms)
> {noformat}
> [~bernd-mesos] couldn't find a ticket, sorry if this is a duplicate!
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
