[
https://issues.apache.org/jira/browse/MESOS-2858?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Bernd Mathiske resolved MESOS-2858.
-----------------------------------
Resolution: Fixed
https://reviews.apache.org/r/35438/
> 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
> master@172.17.0.116: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
> master@172.17.0.116: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
> master@172.17.0.116: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 master@172.17.0.116: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
> master@172.17.0.116: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
> master@172.17.0.116:33349
> I0611 00:40:28.270438 26076 sched.cpp:310] Authenticating with master
> master@172.17.0.116: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
> scheduler-e5bc28c2-aed6-461a-bb5e-77ec57032e75@172.17.0.116: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
> scheduler-e5bc28c2-aed6-461a-bb5e-77ec57032e75@172.17.0.116: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 master@172.17.0.116:33349
> I0611 00:40:28.272222 26073 sched.cpp:521] Sending registration request to
> master@172.17.0.116: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
> scheduler-e5bc28c2-aed6-461a-bb5e-77ec57032e75@172.17.0.116:33349
> W0611 00:40:28.272406 26072 master.cpp:1539] Framework at
> scheduler-e5bc28c2-aed6-461a-bb5e-77ec57032e75@172.17.0.116: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
> scheduler-e5bc28c2-aed6-461a-bb5e-77ec57032e75@172.17.0.116: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
> scheduler-e5bc28c2-aed6-461a-bb5e-77ec57032e75@172.17.0.116: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 scheduler-e5bc28c2-aed6-461a-bb5e-77ec57032e75@172.17.0.116: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
> scheduler-e5bc28c2-aed6-461a-bb5e-77ec57032e75@172.17.0.116: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
> scheduler-e5bc28c2-aed6-461a-bb5e-77ec57032e75@172.17.0.116: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
> 'scheduler-e5bc28c2-aed6-461a-bb5e-77ec57032e75@172.17.0.116: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
> scheduler-e5bc28c2-aed6-461a-bb5e-77ec57032e75@172.17.0.116: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
> master@172.17.0.116: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
> scheduler-e5bc28c2-aed6-461a-bb5e-77ec57032e75@172.17.0.116: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 master@172.17.0.116: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
> scheduler-e5bc28c2-aed6-461a-bb5e-77ec57032e75@172.17.0.116: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
> master@172.17.0.116: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
> scheduler-e5bc28c2-aed6-461a-bb5e-77ec57032e75@172.17.0.116: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 master@172.17.0.116: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
> scheduler-e5bc28c2-aed6-461a-bb5e-77ec57032e75@172.17.0.116: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
> scheduler-e5bc28c2-aed6-461a-bb5e-77ec57032e75@172.17.0.116: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 scheduler-e5bc28c2-aed6-461a-bb5e-77ec57032e75@172.17.0.116: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
> scheduler-e5bc28c2-aed6-461a-bb5e-77ec57032e75@172.17.0.116: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 scheduler-e5bc28c2-aed6-461a-bb5e-77ec57032e75@172.17.0.116: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
> scheduler-e5bc28c2-aed6-461a-bb5e-77ec57032e75@172.17.0.116: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 scheduler-e5bc28c2-aed6-461a-bb5e-77ec57032e75@172.17.0.116: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
> scheduler-e5bc28c2-aed6-461a-bb5e-77ec57032e75@172.17.0.116: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 master@172.17.0.116: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] master@172.17.0.116: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)
