You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@mesos.apache.org by "Jie Yu (JIRA)" <ji...@apache.org> on 2015/02/23 21:55:11 UTC
[jira] [Updated] (MESOS-2387)
SlaveTest.TaskLaunchContainerizerUpdateFails is flaky
[ https://issues.apache.org/jira/browse/MESOS-2387?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Jie Yu updated MESOS-2387:
--------------------------
Sprint: Twitter Mesos Q1 Sprint 3
Story Points: 1
> 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
>
> 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 master@192.168.122.68: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 master@192.168.122.68:39461
> I0222 04:59:56.751349 21809 slave.cpp:686] Authenticating with master master@192.168.122.68: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 master@192.168.122.68: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 master@192.168.122.68:39461
> I0222 04:59:56.762835 21806 sched.cpp:307] Authenticating with master master@192.168.122.68: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 scheduler-d9c22c4e-8dec-42a6-a350-a98472642891@192.168.122.68: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 scheduler-d9c22c4e-8dec-42a6-a350-a98472642891@192.168.122.68:39461
> I0222 04:59:56.765442 21806 sched.cpp:395] Successfully authenticated with master master@192.168.122.68:39461
> I0222 04:59:56.765465 21806 sched.cpp:518] Sending registration request to master@192.168.122.68: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 scheduler-d9c22c4e-8dec-42a6-a350-a98472642891@192.168.122.68: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 scheduler-d9c22c4e-8dec-42a6-a350-a98472642891@192.168.122.68: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 master@192.168.122.68: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 scheduler-d9c22c4e-8dec-42a6-a350-a98472642891@192.168.122.68: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 scheduler-d9c22c4e-8dec-42a6-a350-a98472642891@192.168.122.68: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 scheduler-d9c22c4e-8dec-42a6-a350-a98472642891@192.168.122.68: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 master@192.168.122.68: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 scheduler-d9c22c4e-8dec-42a6-a350-a98472642891@192.168.122.68: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: master@192.168.122.68:39461
> I0222 04:59:56.804921 21791 process.cpp:2117] Dropped / Lost event for PID: master@192.168.122.68: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: master@192.168.122.68: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] master@192.168.122.68: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: scheduler-d9c22c4e-8dec-42a6-a350-a98472642891@192.168.122.68: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)