[ 
https://issues.apache.org/jira/browse/MESOS-2387?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
 ]

Niklas Quarfot Nielsen updated MESOS-2387:
------------------------------------------
    Fix Version/s:     (was: 0.22.1)
                   0.23.0

> SlaveTest.TaskLaunchContainerizerUpdateFails is flaky
> -----------------------------------------------------
>
>                 Key: MESOS-2387
>                 URL: https://issues.apache.org/jira/browse/MESOS-2387
>             Project: Mesos
>          Issue Type: Bug
>          Components: test
>         Environment: CentOS 7 GCC
>            Reporter: Vinod Kone
>            Assignee: Jie Yu
>             Fix For: 0.23.0
>
>
> Observed on internal CI
> {code}
> [ RUN      ] SlaveTest.TaskLaunchContainerizerUpdateFails
> Using temporary directory 
> '/tmp/SlaveTest_TaskLaunchContainerizerUpdateFails_tUjtcI'
> I0222 04:59:56.568491 21813 process.cpp:2117] Dropped / Lost event for PID: 
> slave(52)@192.168.122.68:39461
> I0222 04:59:56.595433 21791 leveldb.cpp:175] Opened db in 27.59732ms
> I0222 04:59:56.603965 21791 leveldb.cpp:182] Compacted db in 8.49192ms
> I0222 04:59:56.604019 21791 leveldb.cpp:197] Created db iterator in 19206ns
> I0222 04:59:56.604037 21791 leveldb.cpp:203] Seeked to beginning of db in 
> 1802ns
> I0222 04:59:56.604046 21791 leveldb.cpp:272] Iterated through 0 keys in the 
> db in 467ns
> I0222 04:59:56.604081 21791 replica.cpp:743] Replica recovered with log 
> positions 0 -> 0 with 1 holes and 0 unlearned
> I0222 04:59:56.607413 21809 recover.cpp:448] Starting replica recovery
> I0222 04:59:56.607687 21809 recover.cpp:474] Replica is in 4 status
> I0222 04:59:56.609011 21809 replica.cpp:640] Replica in 4 status received a 
> broadcasted recover request
> I0222 04:59:56.609262 21809 recover.cpp:194] Received a recover response from 
> a replica in 4 status
> I0222 04:59:56.609709 21809 recover.cpp:565] Updating replica status to 3
> I0222 04:59:56.610749 21811 master.cpp:347] Master 
> 20150222-045956-1148889280-39461-21791 (centos-7) started on 
> 192.168.122.68:39461
> I0222 04:59:56.610791 21811 master.cpp:393] Master only allowing 
> authenticated frameworks to register
> I0222 04:59:56.610802 21811 master.cpp:398] Master only allowing 
> authenticated slaves to register
> I0222 04:59:56.610821 21811 credentials.hpp:36] Loading credentials for 
> authentication from 
> '/tmp/SlaveTest_TaskLaunchContainerizerUpdateFails_tUjtcI/credentials'
> I0222 04:59:56.611042 21811 master.cpp:440] Authorization enabled
> I0222 04:59:56.612329 21811 hierarchical.hpp:286] Initialized hierarchical 
> allocator process
> I0222 04:59:56.612416 21811 whitelist_watcher.cpp:78] No whitelist given
> I0222 04:59:56.613005 21811 master.cpp:1354] The newly elected leader is 
> [email protected]:39461 with id 20150222-045956-1148889280-39461-21791
> I0222 04:59:56.613034 21811 master.cpp:1367] Elected as the leading master!
> I0222 04:59:56.613050 21811 master.cpp:1185] Recovering from registrar
> I0222 04:59:56.613229 21811 registrar.cpp:312] Recovering registrar
> I0222 04:59:56.622866 21809 leveldb.cpp:305] Persisting metadata (8 bytes) to 
> leveldb took 12.988429ms
> I0222 04:59:56.622913 21809 replica.cpp:322] Persisted replica status to 3
> I0222 04:59:56.623118 21809 recover.cpp:474] Replica is in 3 status
> I0222 04:59:56.624419 21809 replica.cpp:640] Replica in 3 status received a 
> broadcasted recover request
> I0222 04:59:56.624685 21809 recover.cpp:194] Received a recover response from 
> a replica in 3 status
> I0222 04:59:56.625200 21809 recover.cpp:565] Updating replica status to 1
> I0222 04:59:56.635154 21809 leveldb.cpp:305] Persisting metadata (8 bytes) to 
> leveldb took 9.799671ms
> I0222 04:59:56.635197 21809 replica.cpp:322] Persisted replica status to 1
> I0222 04:59:56.635296 21809 recover.cpp:579] Successfully joined the Paxos 
> group
> I0222 04:59:56.635426 21809 recover.cpp:463] Recover process terminated
> I0222 04:59:56.635812 21809 log.cpp:659] Attempting to start the writer
> I0222 04:59:56.637075 21809 replica.cpp:476] Replica received implicit 
> promise request with proposal 1
> I0222 04:59:56.648674 21809 leveldb.cpp:305] Persisting metadata (8 bytes) to 
> leveldb took 11.566146ms
> I0222 04:59:56.648717 21809 replica.cpp:344] Persisted promised to 1
> I0222 04:59:56.649456 21809 coordinator.cpp:229] Coordinator attemping to 
> fill missing position
> I0222 04:59:56.650800 21809 replica.cpp:377] Replica received explicit 
> promise request for position 0 with proposal 2
> I0222 04:59:56.659916 21809 leveldb.cpp:342] Persisting action (8 bytes) to 
> leveldb took 9.078258ms
> I0222 04:59:56.659981 21809 replica.cpp:678] Persisted action at 0
> I0222 04:59:56.661075 21809 replica.cpp:510] Replica received write request 
> for position 0
> I0222 04:59:56.661129 21809 leveldb.cpp:437] Reading position from leveldb 
> took 26387ns
> I0222 04:59:56.671227 21809 leveldb.cpp:342] Persisting action (14 bytes) to 
> leveldb took 10.064302ms
> I0222 04:59:56.671262 21809 replica.cpp:678] Persisted action at 0
> I0222 04:59:56.671821 21809 replica.cpp:657] Replica received learned notice 
> for position 0
> I0222 04:59:56.684200 21809 leveldb.cpp:342] Persisting action (16 bytes) to 
> leveldb took 12.346897ms
> I0222 04:59:56.684242 21809 replica.cpp:678] Persisted action at 0
> I0222 04:59:56.684262 21809 replica.cpp:663] Replica learned 1 action at 
> position 0
> I0222 04:59:56.684875 21809 log.cpp:675] Writer started with ending position 0
> I0222 04:59:56.685932 21809 leveldb.cpp:437] Reading position from leveldb 
> took 27308ns
> I0222 04:59:56.688256 21809 registrar.cpp:345] Successfully fetched the 
> registry (0B) in 74.992128ms
> I0222 04:59:56.688344 21809 registrar.cpp:444] Applied 1 operations in 
> 19566ns; attempting to update the 'registry'
> I0222 04:59:56.690690 21809 log.cpp:683] Attempting to append 129 bytes to 
> the log
> I0222 04:59:56.690848 21809 coordinator.cpp:339] Coordinator attempting to 
> write 2 action at position 1
> I0222 04:59:56.691661 21809 replica.cpp:510] Replica received write request 
> for position 1
> I0222 04:59:56.701247 21809 leveldb.cpp:342] Persisting action (148 bytes) to 
> leveldb took 9.550768ms
> I0222 04:59:56.701292 21809 replica.cpp:678] Persisted action at 1
> I0222 04:59:56.702066 21809 replica.cpp:657] Replica received learned notice 
> for position 1
> I0222 04:59:56.712136 21809 leveldb.cpp:342] Persisting action (150 bytes) to 
> leveldb took 10.041696ms
> I0222 04:59:56.712175 21809 replica.cpp:678] Persisted action at 1
> I0222 04:59:56.712198 21809 replica.cpp:663] Replica learned 2 action at 
> position 1
> I0222 04:59:56.713289 21809 registrar.cpp:489] Successfully updated the 
> 'registry' in 24.890112ms
> I0222 04:59:56.713397 21809 registrar.cpp:375] Successfully recovered 
> registrar
> I0222 04:59:56.713537 21809 log.cpp:702] Attempting to truncate the log to 1
> I0222 04:59:56.713795 21809 master.cpp:1212] Recovered 0 slaves from the 
> Registry (93B) ; allowing 10mins for slaves to re-register
> I0222 04:59:56.713871 21809 coordinator.cpp:339] Coordinator attempting to 
> write 3 action at position 2
> I0222 04:59:56.714879 21809 replica.cpp:510] Replica received write request 
> for position 2
> I0222 04:59:56.725225 21809 leveldb.cpp:342] Persisting action (16 bytes) to 
> leveldb took 10.311704ms
> I0222 04:59:56.725270 21809 replica.cpp:678] Persisted action at 2
> I0222 04:59:56.726066 21809 replica.cpp:657] Replica received learned notice 
> for position 2
> I0222 04:59:56.734110 21809 leveldb.cpp:342] Persisting action (18 bytes) to 
> leveldb took 8.012327ms
> I0222 04:59:56.734180 21809 leveldb.cpp:400] Deleting ~1 keys from leveldb 
> took 36578ns
> I0222 04:59:56.734201 21809 replica.cpp:678] Persisted action at 2
> I0222 04:59:56.734221 21809 replica.cpp:663] Replica learned 3 action at 
> position 2
> I0222 04:59:56.747556 21809 slave.cpp:173] Slave started on 
> 53)@192.168.122.68:39461
> I0222 04:59:56.747601 21809 credentials.hpp:84] Loading credential for 
> authentication from 
> '/tmp/SlaveTest_TaskLaunchContainerizerUpdateFails_qkhaJP/credential'
> I0222 04:59:56.747774 21809 slave.cpp:280] Slave using credential for: 
> test-principal
> I0222 04:59:56.748021 21809 slave.cpp:298] Slave resources: cpus(*):2; 
> mem(*):1024; disk(*):1024; ports(*):[31000-32000]
> I0222 04:59:56.748682 21809 slave.cpp:327] Slave hostname: centos-7
> I0222 04:59:56.748705 21809 slave.cpp:328] Slave checkpoint: false
> W0222 04:59:56.748714 21809 slave.cpp:330] Disabling checkpointing is 
> deprecated and the --checkpoint flag will be removed in a future release. 
> Please avoid using this flag
> I0222 04:59:56.749826 21809 state.cpp:34] Recovering state from 
> '/tmp/SlaveTest_TaskLaunchContainerizerUpdateFails_qkhaJP/meta'
> I0222 04:59:56.750191 21809 status_update_manager.cpp:196] Recovering status 
> update manager
> I0222 04:59:56.750465 21809 slave.cpp:3775] Finished recovery
> I0222 04:59:56.751260 21809 slave.cpp:623] New master detected at 
> [email protected]:39461
> I0222 04:59:56.751349 21809 slave.cpp:686] Authenticating with master 
> [email protected]:39461
> I0222 04:59:56.751369 21809 slave.cpp:691] Using default CRAM-MD5 
> authenticatee
> I0222 04:59:56.751502 21809 slave.cpp:659] Detecting new master
> I0222 04:59:56.751596 21809 status_update_manager.cpp:170] Pausing sending 
> status updates
> I0222 04:59:56.751668 21809 authenticatee.hpp:138] Creating new client SASL 
> connection
> I0222 04:59:56.752781 21809 master.cpp:3811] Authenticating 
> slave(53)@192.168.122.68:39461
> I0222 04:59:56.752820 21809 master.cpp:3822] Using default CRAM-MD5 
> authenticator
> I0222 04:59:56.753124 21809 authenticator.hpp:169] Creating new server SASL 
> connection
> I0222 04:59:56.755609 21809 authenticatee.hpp:229] Received SASL 
> authentication mechanisms: CRAM-MD5
> I0222 04:59:56.755641 21809 authenticatee.hpp:255] Attempting to authenticate 
> with mechanism 'CRAM-MD5'
> I0222 04:59:56.755708 21809 authenticator.hpp:275] Received SASL 
> authentication start
> I0222 04:59:56.755751 21809 authenticator.hpp:397] Authentication requires 
> more steps
> I0222 04:59:56.755813 21809 authenticatee.hpp:275] Received SASL 
> authentication step
> I0222 04:59:56.755887 21809 authenticator.hpp:303] Received SASL 
> authentication step
> I0222 04:59:56.755920 21809 auxprop.cpp:98] Request to lookup properties for 
> user: 'test-principal' realm: 'centos-7' server FQDN: 'centos-7' 
> SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false 
> SASL_AUXPROP_AUTHZID: false 
> I0222 04:59:56.755934 21809 auxprop.cpp:170] Looking up auxiliary property 
> '*userPassword'
> I0222 04:59:56.756005 21809 auxprop.cpp:170] Looking up auxiliary property 
> '*cmusaslsecretCRAM-MD5'
> I0222 04:59:56.756036 21809 auxprop.cpp:98] Request to lookup properties for 
> user: 'test-principal' realm: 'centos-7' server FQDN: 'centos-7' 
> SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false 
> SASL_AUXPROP_AUTHZID: true 
> I0222 04:59:56.756047 21809 auxprop.cpp:120] Skipping auxiliary property 
> '*userPassword' since SASL_AUXPROP_AUTHZID == true
> I0222 04:59:56.756054 21809 auxprop.cpp:120] Skipping auxiliary property 
> '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
> I0222 04:59:56.756068 21809 authenticator.hpp:389] Authentication success
> I0222 04:59:56.756155 21809 authenticatee.hpp:315] Authentication success
> I0222 04:59:56.756219 21809 master.cpp:3869] Successfully authenticated 
> principal 'test-principal' at slave(53)@192.168.122.68:39461
> I0222 04:59:56.756503 21809 slave.cpp:757] Successfully authenticated with 
> master [email protected]:39461
> I0222 04:59:56.756611 21809 slave.cpp:1089] Will retry registration in 
> 11.221976ms if necessary
> I0222 04:59:56.756876 21809 master.cpp:2936] Registering slave at 
> slave(53)@192.168.122.68:39461 (centos-7) with id 
> 20150222-045956-1148889280-39461-21791-S0
> I0222 04:59:56.757323 21809 registrar.cpp:444] Applied 1 operations in 
> 70787ns; attempting to update the 'registry'
> I0222 04:59:56.759790 21809 log.cpp:683] Attempting to append 299 bytes to 
> the log
> I0222 04:59:56.760000 21809 coordinator.cpp:339] Coordinator attempting to 
> write 2 action at position 3
> I0222 04:59:56.760920 21809 replica.cpp:510] Replica received write request 
> for position 3
> I0222 04:59:56.762037 21791 sched.cpp:154] Version: 0.22.0
> I0222 04:59:56.762763 21806 sched.cpp:251] New master detected at 
> [email protected]:39461
> I0222 04:59:56.762835 21806 sched.cpp:307] Authenticating with master 
> [email protected]:39461
> I0222 04:59:56.762856 21806 sched.cpp:314] Using default CRAM-MD5 
> authenticatee
> I0222 04:59:56.763082 21806 authenticatee.hpp:138] Creating new client SASL 
> connection
> I0222 04:59:56.763753 21806 master.cpp:3811] Authenticating 
> [email protected]:39461
> I0222 04:59:56.763784 21806 master.cpp:3822] Using default CRAM-MD5 
> authenticator
> I0222 04:59:56.764040 21806 authenticator.hpp:169] Creating new server SASL 
> connection
> I0222 04:59:56.764624 21806 authenticatee.hpp:229] Received SASL 
> authentication mechanisms: CRAM-MD5
> I0222 04:59:56.764653 21806 authenticatee.hpp:255] Attempting to authenticate 
> with mechanism 'CRAM-MD5'
> I0222 04:59:56.764719 21806 authenticator.hpp:275] Received SASL 
> authentication start
> I0222 04:59:56.764758 21806 authenticator.hpp:397] Authentication requires 
> more steps
> I0222 04:59:56.764819 21806 authenticatee.hpp:275] Received SASL 
> authentication step
> I0222 04:59:56.764889 21806 authenticator.hpp:303] Received SASL 
> authentication step
> I0222 04:59:56.764911 21806 auxprop.cpp:98] Request to lookup properties for 
> user: 'test-principal' realm: 'centos-7' server FQDN: 'centos-7' 
> SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false 
> SASL_AUXPROP_AUTHZID: false 
> I0222 04:59:56.764922 21806 auxprop.cpp:170] Looking up auxiliary property 
> '*userPassword'
> I0222 04:59:56.764974 21806 auxprop.cpp:170] Looking up auxiliary property 
> '*cmusaslsecretCRAM-MD5'
> I0222 04:59:56.765005 21806 auxprop.cpp:98] Request to lookup properties for 
> user: 'test-principal' realm: 'centos-7' server FQDN: 'centos-7' 
> SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false 
> SASL_AUXPROP_AUTHZID: true 
> I0222 04:59:56.765017 21806 auxprop.cpp:120] Skipping auxiliary property 
> '*userPassword' since SASL_AUXPROP_AUTHZID == true
> I0222 04:59:56.765023 21806 auxprop.cpp:120] Skipping auxiliary property 
> '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
> I0222 04:59:56.765036 21806 authenticator.hpp:389] Authentication success
> I0222 04:59:56.765120 21806 authenticatee.hpp:315] Authentication success
> I0222 04:59:56.765182 21806 master.cpp:3869] Successfully authenticated 
> principal 'test-principal' at 
> [email protected]:39461
> I0222 04:59:56.765442 21806 sched.cpp:395] Successfully authenticated with 
> master [email protected]:39461
> I0222 04:59:56.765465 21806 sched.cpp:518] Sending registration request to 
> [email protected]:39461
> I0222 04:59:56.765522 21806 sched.cpp:551] Will retry registration in 
> 1.283564292secs if necessary
> I0222 04:59:56.765637 21806 master.cpp:1572] Received registration request 
> for framework 'default' at 
> [email protected]:39461
> I0222 04:59:56.765699 21806 master.cpp:1433] Authorizing framework principal 
> 'test-principal' to receive offers for role '*'
> I0222 04:59:56.766120 21806 master.cpp:1636] Registering framework 
> 20150222-045956-1148889280-39461-21791-0000 (default) at 
> [email protected]:39461
> I0222 04:59:56.766572 21806 hierarchical.hpp:320] Added framework 
> 20150222-045956-1148889280-39461-21791-0000
> I0222 04:59:56.766598 21806 hierarchical.hpp:831] No resources available to 
> allocate!
> I0222 04:59:56.766609 21806 hierarchical.hpp:738] Performed allocation for 0 
> slaves in 15902ns
> I0222 04:59:56.766753 21806 sched.cpp:445] Framework registered with 
> 20150222-045956-1148889280-39461-21791-0000
> I0222 04:59:56.766790 21806 sched.cpp:459] Scheduler::registered took 15076ns
> I0222 04:59:56.773710 21806 slave.cpp:1089] Will retry registration in 
> 3.454005ms if necessary
> I0222 04:59:56.773900 21806 master.cpp:2924] Ignoring register slave message 
> from slave(53)@192.168.122.68:39461 (centos-7) as admission is already in 
> progress
> I0222 04:59:56.775297 21809 leveldb.cpp:342] Persisting action (318 bytes) to 
> leveldb took 14.319807ms
> I0222 04:59:56.775344 21809 replica.cpp:678] Persisted action at 3
> I0222 04:59:56.776139 21809 replica.cpp:657] Replica received learned notice 
> for position 3
> I0222 04:59:56.778630 21806 slave.cpp:1089] Will retry registration in 
> 32.764468ms if necessary
> I0222 04:59:56.778779 21806 master.cpp:2924] Ignoring register slave message 
> from slave(53)@192.168.122.68:39461 (centos-7) as admission is already in 
> progress
> I0222 04:59:56.783778 21809 leveldb.cpp:342] Persisting action (320 bytes) to 
> leveldb took 7.609533ms
> I0222 04:59:56.783828 21809 replica.cpp:678] Persisted action at 3
> I0222 04:59:56.783849 21809 replica.cpp:663] Replica learned 2 action at 
> position 3
> I0222 04:59:56.785058 21809 registrar.cpp:489] Successfully updated the 
> 'registry' in 27.669248ms
> I0222 04:59:56.785274 21809 log.cpp:702] Attempting to truncate the log to 3
> I0222 04:59:56.785815 21809 master.cpp:2993] Registered slave 
> 20150222-045956-1148889280-39461-21791-S0 at slave(53)@192.168.122.68:39461 
> (centos-7) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]
> I0222 04:59:56.785913 21809 coordinator.cpp:339] Coordinator attempting to 
> write 3 action at position 4
> I0222 04:59:56.786267 21809 hierarchical.hpp:452] Added slave 
> 20150222-045956-1148889280-39461-21791-S0 (centos-7) with cpus(*):2; 
> mem(*):1024; disk(*):1024; ports(*):[31000-32000] (and cpus(*):2; 
> mem(*):1024; disk(*):1024; ports(*):[31000-32000] available)
> I0222 04:59:56.786600 21809 hierarchical.hpp:756] Performed allocation for 
> slave 20150222-045956-1148889280-39461-21791-S0 in 292298ns
> I0222 04:59:56.786684 21809 slave.cpp:791] Registered with master 
> [email protected]:39461; given slave ID 
> 20150222-045956-1148889280-39461-21791-S0
> I0222 04:59:56.786792 21809 slave.cpp:2830] Received ping from 
> slave-observer(52)@192.168.122.68:39461
> I0222 04:59:56.787230 21809 master.cpp:3753] Sending 1 offers to framework 
> 20150222-045956-1148889280-39461-21791-0000 (default) at 
> [email protected]:39461
> I0222 04:59:56.787334 21809 status_update_manager.cpp:177] Resuming sending 
> status updates
> I0222 04:59:56.788156 21809 sched.cpp:608] Scheduler::resourceOffers took 
> 557128ns
> I0222 04:59:56.788936 21809 master.cpp:2266] Processing ACCEPT call for 
> offers: [ 20150222-045956-1148889280-39461-21791-O0 ] on slave 
> 20150222-045956-1148889280-39461-21791-S0 at slave(53)@192.168.122.68:39461 
> (centos-7) for framework 20150222-045956-1148889280-39461-21791-0000 
> (default) at 
> [email protected]:39461
> I0222 04:59:56.789000 21809 master.cpp:2110] Authorizing framework principal 
> 'test-principal' to launch task 0 as user 'jenkins'
> W0222 04:59:56.790506 21809 validation.cpp:327] Executor default for task 0 
> uses less CPUs (None) than the minimum required (0.01). Please update your 
> executor, as this will be mandatory in future releases.
> W0222 04:59:56.790546 21809 validation.cpp:339] Executor default for task 0 
> uses less memory (None) than the minimum required (32MB). Please update your 
> executor, as this will be mandatory in future releases.
> I0222 04:59:56.790808 21809 master.hpp:821] Adding task 0 with resources 
> cpus(*):1; mem(*):128 on slave 20150222-045956-1148889280-39461-21791-S0 
> (centos-7)
> I0222 04:59:56.790885 21809 master.cpp:2543] Launching task 0 of framework 
> 20150222-045956-1148889280-39461-21791-0000 (default) at 
> [email protected]:39461 with 
> resources cpus(*):1; mem(*):128 on slave 
> 20150222-045956-1148889280-39461-21791-S0 at slave(53)@192.168.122.68:39461 
> (centos-7)
> I0222 04:59:56.791201 21809 replica.cpp:510] Replica received write request 
> for position 4
> I0222 04:59:56.791610 21806 slave.cpp:1120] Got assigned task 0 for framework 
> 20150222-045956-1148889280-39461-21791-0000
> I0222 04:59:56.792140 21806 slave.cpp:1230] Launching task 0 for framework 
> 20150222-045956-1148889280-39461-21791-0000
> I0222 04:59:56.794872 21806 slave.cpp:4177] Launching executor default of 
> framework 20150222-045956-1148889280-39461-21791-0000 in work directory 
> '/tmp/SlaveTest_TaskLaunchContainerizerUpdateFails_qkhaJP/slaves/20150222-045956-1148889280-39461-21791-S0/frameworks/20150222-045956-1148889280-39461-21791-0000/executors/default/runs/753232b5-43ff-4fbf-b29a-0f76161132ab'
> I0222 04:59:56.796846 21806 exec.cpp:130] Version: 0.22.0
> I0222 04:59:56.797173 21806 slave.cpp:1377] Queuing task '0' for executor 
> default of framework '20150222-045956-1148889280-39461-21791-0000
> I0222 04:59:56.797355 21806 slave.cpp:3132] Monitoring executor 'default' of 
> framework '20150222-045956-1148889280-39461-21791-0000' in container 
> '753232b5-43ff-4fbf-b29a-0f76161132ab'
> I0222 04:59:56.797570 21806 hierarchical.hpp:645] Recovered cpus(*):1; 
> mem(*):896; disk(*):1024; ports(*):[31000-32000] (total allocatable: 
> cpus(*):1; mem(*):896; disk(*):1024; ports(*):[31000-32000]) on slave 
> 20150222-045956-1148889280-39461-21791-S0 from framework 
> 20150222-045956-1148889280-39461-21791-0000
> I0222 04:59:56.797613 21806 hierarchical.hpp:681] Framework 
> 20150222-045956-1148889280-39461-21791-0000 filtered slave 
> 20150222-045956-1148889280-39461-21791-S0 for 5secs
> I0222 04:59:56.797796 21806 exec.cpp:180] Executor started at: 
> executor(24)@192.168.122.68:39461 with pid 21791
> I0222 04:59:56.798068 21806 slave.cpp:576] Successfully attached file 
> '/tmp/SlaveTest_TaskLaunchContainerizerUpdateFails_qkhaJP/slaves/20150222-045956-1148889280-39461-21791-S0/frameworks/20150222-045956-1148889280-39461-21791-0000/executors/default/runs/753232b5-43ff-4fbf-b29a-0f76161132ab'
> I0222 04:59:56.798136 21806 slave.cpp:2140] Got registration for executor 
> 'default' of framework 20150222-045956-1148889280-39461-21791-0000 from 
> executor(24)@192.168.122.68:39461
> E0222 04:59:56.798573 21806 slave.cpp:1445] Failed to update resources for 
> container 753232b5-43ff-4fbf-b29a-0f76161132ab of executor 'default' of 
> framework 20150222-045956-1148889280-39461-21791-0000, destroying container: 
> update() failed
> I0222 04:59:56.798811 21806 slave.cpp:3190] Executor 'default' of framework 
> 20150222-045956-1148889280-39461-21791-0000 exited with status 0
> I0222 04:59:56.800436 21806 slave.cpp:2507] Handling status update TASK_LOST 
> (UUID: 45243922-bcad-4e11-9a9f-db9213111a2a) for task 0 of framework 
> 20150222-045956-1148889280-39461-21791-0000 from @0.0.0.0:0
> I0222 04:59:56.800520 21806 slave.cpp:4485] Terminating task 0
> I0222 04:59:56.801142 21806 master.cpp:3386] Executor default of framework 
> 20150222-045956-1148889280-39461-21791-0000 on slave 
> 20150222-045956-1148889280-39461-21791-S0 at slave(53)@192.168.122.68:39461 
> (centos-7) exited with status 0
> I0222 04:59:56.801211 21806 master.cpp:4712] Removing executor 'default' with 
> resources  of framework 20150222-045956-1148889280-39461-21791-0000 on slave 
> 20150222-045956-1148889280-39461-21791-S0 at slave(53)@192.168.122.68:39461 
> (centos-7)
> I0222 04:59:56.801378 21806 status_update_manager.cpp:316] Received status 
> update TASK_LOST (UUID: 45243922-bcad-4e11-9a9f-db9213111a2a) for task 0 of 
> framework 20150222-045956-1148889280-39461-21791-0000
> I0222 04:59:56.801412 21806 status_update_manager.cpp:493] Creating 
> StatusUpdate stream for task 0 of framework 
> 20150222-045956-1148889280-39461-21791-0000
> I0222 04:59:56.801574 21806 status_update_manager.cpp:370] Forwarding update 
> TASK_LOST (UUID: 45243922-bcad-4e11-9a9f-db9213111a2a) for task 0 of 
> framework 20150222-045956-1148889280-39461-21791-0000 to the slave
> I0222 04:59:56.801831 21806 slave.cpp:2750] Forwarding the update TASK_LOST 
> (UUID: 45243922-bcad-4e11-9a9f-db9213111a2a) for task 0 of framework 
> 20150222-045956-1148889280-39461-21791-0000 to [email protected]:39461
> I0222 04:59:56.802109 21805 master.cpp:3293] Status update TASK_LOST (UUID: 
> 45243922-bcad-4e11-9a9f-db9213111a2a) for task 0 of framework 
> 20150222-045956-1148889280-39461-21791-0000 from slave 
> 20150222-045956-1148889280-39461-21791-S0 at slave(53)@192.168.122.68:39461 
> (centos-7)
> I0222 04:59:56.802145 21805 master.cpp:3334] Forwarding status update 
> TASK_LOST (UUID: 45243922-bcad-4e11-9a9f-db9213111a2a) for task 0 of 
> framework 20150222-045956-1148889280-39461-21791-0000
> I0222 04:59:56.802266 21805 master.cpp:4616] Updating the latest state of 
> task 0 of framework 20150222-045956-1148889280-39461-21791-0000 to TASK_LOST
> I0222 04:59:56.802685 21805 sched.cpp:714] Scheduler::statusUpdate took 
> 40465ns
> I0222 04:59:56.802821 21805 hierarchical.hpp:645] Recovered cpus(*):1; 
> mem(*):128 (total allocatable: cpus(*):2; mem(*):1024; disk(*):1024; 
> ports(*):[31000-32000]) on slave 20150222-045956-1148889280-39461-21791-S0 
> from framework 20150222-045956-1148889280-39461-21791-0000
> I0222 04:59:56.803130 21805 master.cpp:4683] Removing task 0 with resources 
> cpus(*):1; mem(*):128 of framework 
> 20150222-045956-1148889280-39461-21791-0000 on slave 
> 20150222-045956-1148889280-39461-21791-S0 at slave(53)@192.168.122.68:39461 
> (centos-7)
> I0222 04:59:56.803268 21805 master.cpp:2780] Forwarding status update 
> acknowledgement 45243922-bcad-4e11-9a9f-db9213111a2a for task 0 of framework 
> 20150222-045956-1148889280-39461-21791-0000 (default) at 
> [email protected]:39461 to slave 
> 20150222-045956-1148889280-39461-21791-S0 at slave(53)@192.168.122.68:39461 
> (centos-7)
> I0222 04:59:56.803473 21791 sched.cpp:1585] Asked to stop the driver
> I0222 04:59:56.803547 21791 master.cpp:785] Master terminating
> I0222 04:59:56.804844 21791 process.cpp:2117] Dropped / Lost event for PID: 
> [email protected]:39461
> I0222 04:59:56.804921 21791 process.cpp:2117] Dropped / Lost event for PID: 
> [email protected]:39461
> I0222 04:59:56.805624 21812 sched.cpp:828] Stopping framework 
> '20150222-045956-1148889280-39461-21791-0000'
> I0222 04:59:56.805675 21812 process.cpp:2117] Dropped / Lost event for PID: 
> [email protected]:39461
> I0222 04:59:56.807793 21812 process.cpp:2117] Dropped / Lost event for PID: 
> log-coordinator(89)@192.168.122.68:39461
> I0222 04:59:56.809552 21806 slave.cpp:2677] Status update manager 
> successfully handled status update TASK_LOST (UUID: 
> 45243922-bcad-4e11-9a9f-db9213111a2a) for task 0 of framework 
> 20150222-045956-1148889280-39461-21791-0000
> I0222 04:59:56.809736 21806 slave.cpp:2915] [email protected]:39461 exited
> W0222 04:59:56.809759 21806 slave.cpp:2918] Master disconnected! Waiting for 
> a new master to be elected
> I0222 04:59:56.809788 21806 status_update_manager.cpp:388] Received status 
> update acknowledgement (UUID: 45243922-bcad-4e11-9a9f-db9213111a2a) for task 
> 0 of framework 20150222-045956-1148889280-39461-21791-0000
> I0222 04:59:56.809855 21806 status_update_manager.cpp:524] Cleaning up status 
> update stream for task 0 of framework 
> 20150222-045956-1148889280-39461-21791-0000
> I0222 04:59:56.810042 21806 slave.cpp:2080] Status update manager 
> successfully handled status update acknowledgement (UUID: 
> 45243922-bcad-4e11-9a9f-db9213111a2a) for task 0 of framework 
> 20150222-045956-1148889280-39461-21791-0000
> I0222 04:59:56.810088 21806 slave.cpp:4526] Completing task 0
> I0222 04:59:56.810117 21806 slave.cpp:3299] Cleaning up executor 'default' of 
> framework 20150222-045956-1148889280-39461-21791-0000
> I0222 04:59:56.810361 21806 slave.cpp:3378] Cleaning up framework 
> 20150222-045956-1148889280-39461-21791-0000
> I0222 04:59:56.810509 21806 gc.cpp:55] Scheduling 
> '/tmp/SlaveTest_TaskLaunchContainerizerUpdateFails_qkhaJP/slaves/20150222-045956-1148889280-39461-21791-S0/frameworks/20150222-045956-1148889280-39461-21791-0000/executors/default/runs/753232b5-43ff-4fbf-b29a-0f76161132ab'
>  for gc 6.99999062248889days in the future
> I0222 04:59:56.810673 21806 gc.cpp:55] Scheduling 
> '/tmp/SlaveTest_TaskLaunchContainerizerUpdateFails_qkhaJP/slaves/20150222-045956-1148889280-39461-21791-S0/frameworks/20150222-045956-1148889280-39461-21791-0000/executors/default'
>  for gc 6.99999062130963days in the future
> I0222 04:59:56.810768 21806 gc.cpp:55] Scheduling 
> '/tmp/SlaveTest_TaskLaunchContainerizerUpdateFails_qkhaJP/slaves/20150222-045956-1148889280-39461-21791-S0/frameworks/20150222-045956-1148889280-39461-21791-0000'
>  for gc 6.9999906199763days in the future
> I0222 04:59:56.810861 21806 status_update_manager.cpp:278] Closing status 
> update streams for framework 20150222-045956-1148889280-39461-21791-0000
> I0222 04:59:56.817010 21809 leveldb.cpp:342] Persisting action (16 bytes) to 
> leveldb took 25.747365ms
> I0222 04:59:56.817047 21809 replica.cpp:678] Persisted action at 4
> I0222 04:59:56.817087 21809 process.cpp:2117] Dropped / Lost event for PID: 
> (1371)@192.168.122.68:39461
> I0222 04:59:56.817679 21791 slave.cpp:505] Slave terminating
> I0222 04:59:56.818411 21791 process.cpp:2117] Dropped / Lost event for PID: 
> slave(53)@192.168.122.68:39461
> I0222 04:59:56.818869 21791 process.cpp:2117] Dropped / Lost event for PID: 
> [email protected]:39461
> tests/slave_tests.cpp:1183: Failure
> Actual function call count doesn't match EXPECT_CALL(exec, registered(_, _, 
> _, _))...
>          Expected: to be called once
>            Actual: never called - unsatisfied and active
> [  FAILED  ] SlaveTest.TaskLaunchContainerizerUpdateFails (253 ms)
> {code}



--
This message was sent by Atlassian JIRA
(v6.3.4#6332)

Reply via email to