mesos-issues mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Vinod Kone (JIRA)" <j...@apache.org>
Subject [jira] [Created] (MESOS-2387) SlaveTest.TaskLaunchContainerizerUpdateFails is flaky
Date Mon, 23 Feb 2015 20:23:11 GMT
Vinod Kone created MESOS-2387:
---------------------------------

             Summary: 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)

Mime
View raw message