mesos-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Benjamin Mahler <benjamin.mah...@gmail.com>
Subject Re: Build failed in Jenkins: Mesos-Ubuntu-distcheck #71
Date Fri, 02 May 2014 17:15:26 GMT
Should we disable this test until there's a fix for MESOS-1264?

(Sorry, I initially thought this was a new flaky test).


On Fri, May 2, 2014 at 10:13 AM, Benjamin Mahler
<benjamin.mahler@gmail.com>wrote:

> +adam, vinod
>
> Looks like this is re-authentication causing the master to call
> disconnect(Slave*) leading to TASK_LOST (MESOS-1264), can you guys take a
> look?
>
>
> On Thu, May 1, 2014 at 11:51 PM, Apache Jenkins Server <
> jenkins@builds.apache.org> wrote:
>
>> See <https://builds.apache.org/job/Mesos-Ubuntu-distcheck/71/changes>
>>
>> Changes:
>>
>> [vinod] Temporarily disabled ExternalContainerizerTest.Launch due to
>>
>> [bmahler] Add 'value' and 'units' methods to Duration subclasses.
>>
>> [bmahler] Used Duration subclasses to allow Timer users to specify units.
>>
>> [bmahler] Added template parameter to Timer.
>>
>> [niklas] Temporarily disabled
>> SlaveRecoveryTest.RestartBeforeContainerizerLaunch due to MESOS-1273.
>>
>> [vinod] Improved log messages in master.
>>
>> [yujie.jay] Ignored the log write request to a position if it has already
>> been
>>
>> ------------------------------------------
>> [...truncated 9344 lines...]
>> I0502 06:06:39.558637 21634 slave.cpp:2554] Cleaning up framework
>> 20140502-060639-143311683-52864-21608-0000
>> I0502 06:06:39.558696 21634 slave.cpp:414] Slave terminating
>> I0502 06:06:39.558749 21634 gc.cpp:56] Scheduling
>> '/tmp/FaultToleranceTest_IgnoreKillTaskFromUnregisteredFramework_BQTNoh/slaves/20140502-060639-143311683-52864-21608-0/frameworks/20140502-060639-143311683-52864-21608-0000/executors/default/runs/7f8f1bcc-b368-4436-a8c6-cac83589e12a'
>> for gc 6.99999353491852days in the future
>> [       OK ] FaultToleranceTest.IgnoreKillTaskFromUnregisteredFramework
>> (64 ms)
>> [ RUN      ] FaultToleranceTest.ReconcileIncompleteTasks
>> I0502 06:06:39.561995 21608 leveldb.cpp:174] Opened db in 2.240191ms
>> I0502 06:06:39.562350 21608 leveldb.cpp:181] Compacted db in 336286ns
>> I0502 06:06:39.562371 21608 leveldb.cpp:196] Created db iterator in 3426ns
>> I0502 06:06:39.562377 21608 leveldb.cpp:202] Seeked to beginning of db in
>> 673ns
>> I0502 06:06:39.562383 21608 leveldb.cpp:271] Iterated through 0 keys in
>> the db in 295ns
>> I0502 06:06:39.562396 21608 replica.cpp:741] Replica recovered with log
>> positions 0 -> 0 with 1 holes and 0 unlearned
>> I0502 06:06:39.562556 21634 recover.cpp:425] Starting replica recovery
>> I0502 06:06:39.562891 21630 recover.cpp:451] Replica is in EMPTY status
>> I0502 06:06:39.563066 21632 master.cpp:266] Master
>> 20140502-060639-143311683-52864-21608 (minerva.apache.org) started on
>> 67.195.138.8:52864
>> I0502 06:06:39.563086 21632 master.cpp:303] Master only allowing
>> authenticated frameworks to register
>> I0502 06:06:39.563092 21632 master.cpp:308] Master only allowing
>> authenticated slaves to register
>> I0502 06:06:39.563097 21632 credentials.hpp:35] Loading credentials for
>> authentication
>> W0502 06:06:39.563133 21632 credentials.hpp:48] Failed to stat
>> credentials file
>> 'file:///tmp/FaultToleranceTest_ReconcileIncompleteTasks_1niY7k/credentials':
>> No such file or directory
>> I0502 06:06:39.563380 21633 master.cpp:104] No whitelist given.
>> Advertising offers for all slaves
>> I0502 06:06:39.563474 21628 hierarchical_allocator_process.hpp:302]
>> Initializing hierarchical allocator process with master :
>> master@67.195.138.8:52864
>> I0502 06:06:39.564005 21632 master.cpp:919] The newly elected leader is
>> master@67.195.138.8:52864 with id 20140502-060639-143311683-52864-21608
>> I0502 06:06:39.564018 21632 master.cpp:929] Elected as the leading master!
>> I0502 06:06:39.564026 21632 master.cpp:750] Recovering from registrar
>> I0502 06:06:39.564064 21630 replica.cpp:638] Replica in EMPTY status
>> received a broadcasted recover request
>> I0502 06:06:39.564090 21632 registrar.cpp:275] Recovering registrar
>> I0502 06:06:39.564218 21631 recover.cpp:188] Received a recover response
>> from a replica in EMPTY status
>> I0502 06:06:39.564431 21629 recover.cpp:542] Updating replica status to
>> STARTING
>> I0502 06:06:39.565256 21631 leveldb.cpp:304] Persisting metadata (8
>> bytes) to leveldb took 719407ns
>> I0502 06:06:39.565273 21631 replica.cpp:320] Persisted replica status to
>> STARTING
>> I0502 06:06:39.565371 21634 recover.cpp:451] Replica is in STARTING status
>> I0502 06:06:39.565817 21632 replica.cpp:638] Replica in STARTING status
>> received a broadcasted recover request
>> I0502 06:06:39.565918 21630 recover.cpp:188] Received a recover response
>> from a replica in STARTING status
>> I0502 06:06:39.566041 21632 recover.cpp:542] Updating replica status to
>> VOTING
>> I0502 06:06:39.566215 21628 leveldb.cpp:304] Persisting metadata (8
>> bytes) to leveldb took 119341ns
>> I0502 06:06:39.566228 21628 replica.cpp:320] Persisted replica status to
>> VOTING
>> I0502 06:06:39.566288 21632 recover.cpp:556] Successfully joined the
>> Paxos group
>> I0502 06:06:39.566368 21632 recover.cpp:440] Recover process terminated
>> I0502 06:06:39.566618 21629 log.cpp:656] Attempting to start the writer
>> I0502 06:06:39.567194 21627 replica.cpp:474] Replica received implicit
>> promise request with proposal 1
>> I0502 06:06:39.567347 21627 leveldb.cpp:304] Persisting metadata (8
>> bytes) to leveldb took 134819ns
>> I0502 06:06:39.567360 21627 replica.cpp:342] Persisted promised to 1
>> I0502 06:06:39.567697 21631 coordinator.cpp:229] Coordinator attemping to
>> fill missing position
>> I0502 06:06:39.568219 21631 replica.cpp:375] Replica received explicit
>> promise request for position 0 with proposal 2
>> I0502 06:06:39.568356 21631 leveldb.cpp:341] Persisting action (8 bytes)
>> to leveldb took 110514ns
>> I0502 06:06:39.568369 21631 replica.cpp:676] Persisted action at 0
>> I0502 06:06:39.568887 21634 replica.cpp:508] Replica received write
>> request for position 0
>> I0502 06:06:39.568912 21634 leveldb.cpp:436] Reading position from
>> leveldb took 10327ns
>> I0502 06:06:39.569063 21634 leveldb.cpp:341] Persisting action (14 bytes)
>> to leveldb took 139170ns
>> I0502 06:06:39.569077 21634 replica.cpp:676] Persisted action at 0
>> I0502 06:06:39.569313 21630 replica.cpp:655] Replica received learned
>> notice for position 0
>> I0502 06:06:39.569470 21630 leveldb.cpp:341] Persisting action (16 bytes)
>> to leveldb took 142830ns
>> I0502 06:06:39.569483 21630 replica.cpp:676] Persisted action at 0
>> I0502 06:06:39.569493 21630 replica.cpp:661] Replica learned NOP action
>> at position 0
>> I0502 06:06:39.569710 21628 log.cpp:672] Writer started with ending
>> position 0
>> I0502 06:06:39.570241 21634 leveldb.cpp:436] Reading position from
>> leveldb took 6812ns
>> I0502 06:06:39.571600 21628 registrar.cpp:306] Successfully recovered
>> registrar
>> I0502 06:06:39.571631 21628 registrar.cpp:377] Attempting to update the
>> 'registry'
>> I0502 06:06:39.573010 21631 log.cpp:680] Attempting to append 137 bytes
>> to the log
>> I0502 06:06:39.573118 21632 coordinator.cpp:339] Coordinator attempting
>> to write APPEND action at position 1
>> I0502 06:06:39.573508 21633 replica.cpp:508] Replica received write
>> request for position 1
>> I0502 06:06:39.573667 21633 leveldb.cpp:341] Persisting action (156
>> bytes) to leveldb took 133454ns
>> I0502 06:06:39.573680 21633 replica.cpp:676] Persisted action at 1
>> I0502 06:06:39.573936 21633 replica.cpp:655] Replica received learned
>> notice for position 1
>> I0502 06:06:39.574091 21633 leveldb.cpp:341] Persisting action (158
>> bytes) to leveldb took 105922ns
>> I0502 06:06:39.574105 21633 replica.cpp:676] Persisted action at 1
>> I0502 06:06:39.574115 21633 replica.cpp:661] Replica learned APPEND
>> action at position 1
>> I0502 06:06:39.574446 21629 registrar.cpp:423] Successfully updated
>> 'registry'
>> I0502 06:06:39.574636 21629 log.cpp:699] Attempting to truncate the log
>> to 1
>> I0502 06:06:39.574692 21628 master.cpp:777] Recovered 0 slaves from the
>> Registry (99B) ; allowing 10mins for slaves to re-register
>> I0502 06:06:39.574759 21630 coordinator.cpp:339] Coordinator attempting
>> to write TRUNCATE action at position 2
>> I0502 06:06:39.574959 21630 replica.cpp:508] Replica received write
>> request for position 2
>> I0502 06:06:39.575103 21630 leveldb.cpp:341] Persisting action (16 bytes)
>> to leveldb took 132049ns
>> I0502 06:06:39.575115 21630 replica.cpp:676] Persisted action at 2
>> I0502 06:06:39.575255 21630 replica.cpp:655] Replica received learned
>> notice for position 2
>> I0502 06:06:39.575340 21630 leveldb.cpp:341] Persisting action (18 bytes)
>> to leveldb took 73110ns
>> I0502 06:06:39.575363 21630 leveldb.cpp:399] Deleting ~1 keys from
>> leveldb took 11413ns
>> I0502 06:06:39.575372 21630 replica.cpp:676] Persisted action at 2
>> I0502 06:06:39.575379 21630 replica.cpp:661] Replica learned TRUNCATE
>> action at position 2
>> I0502 06:06:39.588472 21629 slave.cpp:140] Slave started on 10)@
>> 67.195.138.8:52864
>> I0502 06:06:39.588489 21629 credentials.hpp:35] Loading credentials for
>> authentication
>> W0502 06:06:39.588584 21629 credentials.hpp:48] Failed to stat
>> credentials file
>> 'file:///tmp/FaultToleranceTest_ReconcileIncompleteTasks_Cc9VTo/credential':
>> No such file or directory
>> I0502 06:06:39.588605 21629 slave.cpp:231] Slave using credential for:
>> test-principal
>> I0502 06:06:39.588724 21629 slave.cpp:244] Slave resources: cpus(*):2;
>> mem(*):1024; disk(*):1024; ports(*):[31000-32000]
>> I0502 06:06:39.588784 21629 slave.cpp:272] Slave hostname:
>> minerva.apache.org
>> I0502 06:06:39.588793 21629 slave.cpp:273] Slave checkpoint: false
>> I0502 06:06:39.589261 21628 state.cpp:33] Recovering state from
>> '/tmp/FaultToleranceTest_ReconcileIncompleteTasks_Cc9VTo/meta'
>> I0502 06:06:39.589412 21630 status_update_manager.cpp:193] Recovering
>> status update manager
>> I0502 06:06:39.589576 21627 slave.cpp:2943] Finished recovery
>> I0502 06:06:39.589823 21631 slave.cpp:525] New master detected at
>> master@67.195.138.8:52864
>> I0502 06:06:39.589853 21631 slave.cpp:585] Authenticating with master
>> master@67.195.138.8:52864
>> I0502 06:06:39.589871 21627 status_update_manager.cpp:167] New master
>> detected at master@67.195.138.8:52864
>> I0502 06:06:39.589897 21631 slave.cpp:558] Detecting new master
>> I0502 06:06:39.589911 21627 authenticatee.hpp:128] Creating new client
>> SASL connection
>> I0502 06:06:39.590051 21631 master.cpp:2788] Authenticating slave(10)@
>> 67.195.138.8:52864
>> I0502 06:06:39.590129 21627 authenticator.hpp:148] Creating new server
>> SASL connection
>> I0502 06:06:39.590230 21627 authenticatee.hpp:219] Received SASL
>> authentication mechanisms: CRAM-MD5
>> I0502 06:06:39.590253 21627 authenticatee.hpp:245] Attempting to
>> authenticate with mechanism 'CRAM-MD5'
>> I0502 06:06:39.590286 21627 authenticator.hpp:254] Received SASL
>> authentication start
>> I0502 06:06:39.590347 21608 sched.cpp:121] Version: 0.19.0
>> I0502 06:06:39.590351 21627 authenticator.hpp:342] Authentication
>> requires more steps
>> I0502 06:06:39.590435 21628 authenticatee.hpp:265] Received SASL
>> authentication step
>> I0502 06:06:39.590517 21633 sched.cpp:217] New master detected at
>> master@67.195.138.8:52864
>> I0502 06:06:39.590543 21633 sched.cpp:268] Authenticating with master
>> master@67.195.138.8:52864
>> I0502 06:06:39.590550 21632 authenticator.hpp:282] Received SASL
>> authentication step
>> I0502 06:06:39.590576 21632 auxprop.cpp:81] Request to lookup properties
>> for user: 'test-principal' realm: 'minerva.apache.org' server FQDN: '
>> minerva.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
>> SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
>> I0502 06:06:39.590585 21632 auxprop.cpp:153] Looking up auxiliary
>> property '*userPassword'
>> I0502 06:06:39.590596 21632 auxprop.cpp:153] Looking up auxiliary
>> property '*cmusaslsecretCRAM-MD5'
>> I0502 06:06:39.590606 21632 auxprop.cpp:81] Request to lookup properties
>> for user: 'test-principal' realm: 'minerva.apache.org' server FQDN: '
>> minerva.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
>> SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
>> I0502 06:06:39.590615 21632 auxprop.cpp:103] Skipping auxiliary property
>> '*userPassword' since SASL_AUXPROP_AUTHZID == true
>> I0502 06:06:39.590616 21630 authenticatee.hpp:128] Creating new client
>> SASL connection
>> I0502 06:06:39.590620 21632 auxprop.cpp:103] Skipping auxiliary property
>> '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
>> I0502 06:06:39.590662 21632 authenticator.hpp:334] Authentication success
>> I0502 06:06:39.590729 21627 master.cpp:2828] Successfully authenticated
>> slave(10)@67.195.138.8:52864
>> I0502 06:06:39.590801 21629 authenticatee.hpp:305] Authentication success
>> I0502 06:06:39.590811 21627 master.cpp:2788] Authenticating scheduler(11)@
>> 67.195.138.8:52864
>> I0502 06:06:39.590896 21633 authenticator.hpp:148] Creating new server
>> SASL connection
>> I0502 06:06:39.590893 21629 slave.cpp:642] Successfully authenticated
>> with master master@67.195.138.8:52864
>> I0502 06:06:39.590962 21629 slave.cpp:871] Will retry registration in
>> 7.697427362secs if necessary
>> I0502 06:06:39.591027 21628 authenticatee.hpp:219] Received SASL
>> authentication mechanisms: CRAM-MD5
>> I0502 06:06:39.591035 21631 master.cpp:2124] Registering slave at
>> slave(10)@67.195.138.8:52864 (minerva.apache.org) with id
>> I0502 06:06:39.591053 21628 authenticatee.hpp:245] Attempting to
>> authenticate with mechanism 'CRAM-MD5'
>> I0502 06:06:39.591094 21628 authenticator.hpp:254] Received SASL
>> authentication start
>> I0502 06:06:39.591171 21628 authenticator.hpp:342] Authentication
>> requires more steps
>> I0502 06:06:39.591188 21632 registrar.cpp:377] Attempting to update the
>> 'registry'
>> I0502 06:06:39.591212 21628 authenticatee.hpp:265] Received SASL
>> authentication step
>> I0502 06:06:39.591270 21628 authenticator.hpp:282] Received SASL
>> authentication step
>> I0502 06:06:39.591300 21628 auxprop.cpp:81] Request to lookup properties
>> for user: 'test-principal' realm: 'minerva.apache.org' server FQDN: '
>> minerva.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
>> SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
>> I0502 06:06:39.591310 21628 auxprop.cpp:153] Looking up auxiliary
>> property '*userPassword'
>> I0502 06:06:39.591322 21628 auxprop.cpp:153] Looking up auxiliary
>> property '*cmusaslsecretCRAM-MD5'
>> I0502 06:06:39.591331 21628 auxprop.cpp:81] Request to lookup properties
>> for user: 'test-principal' realm: 'minerva.apache.org' server FQDN: '
>> minerva.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
>> SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
>> I0502 06:06:39.591339 21628 auxprop.cpp:103] Skipping auxiliary property
>> '*userPassword' since SASL_AUXPROP_AUTHZID == true
>> I0502 06:06:39.591344 21628 auxprop.cpp:103] Skipping auxiliary property
>> '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
>> I0502 06:06:39.591356 21628 authenticator.hpp:334] Authentication success
>> I0502 06:06:39.591403 21629 authenticatee.hpp:305] Authentication success
>> I0502 06:06:39.591421 21628 master.cpp:2828] Successfully authenticated
>> scheduler(11)@67.195.138.8:52864
>> I0502 06:06:39.591521 21629 sched.cpp:342] Successfully authenticated
>> with master master@67.195.138.8:52864
>> I0502 06:06:39.591541 21629 sched.cpp:461] Sending registration request
>> to master@67.195.138.8:52864
>> I0502 06:06:39.591599 21628 master.cpp:978] Received registration request
>> from scheduler(11)@67.195.138.8:52864
>> I0502 06:06:39.591645 21628 master.cpp:996] Registering framework
>> 20140502-060639-143311683-52864-21608-0000 at scheduler(11)@
>> 67.195.138.8:52864
>> I0502 06:06:39.591732 21631 sched.cpp:392] Framework registered with
>> 20140502-060639-143311683-52864-21608-0000
>> I0502 06:06:39.591755 21628 hierarchical_allocator_process.hpp:332] Added
>> framework 20140502-060639-143311683-52864-21608-0000
>> I0502 06:06:39.591761 21631 sched.cpp:406] Scheduler::registered took
>> 10321ns
>> I0502 06:06:39.591766 21628 hierarchical_allocator_process.hpp:726] No
>> resources available to allocate!
>> I0502 06:06:39.591776 21628 hierarchical_allocator_process.hpp:688]
>> Performed allocation for 0 slaves in 9584ns
>> I0502 06:06:39.592458 21632 log.cpp:680] Attempting to append 333 bytes
>> to the log
>> I0502 06:06:39.592532 21631 coordinator.cpp:339] Coordinator attempting
>> to write APPEND action at position 3
>> I0502 06:06:39.592767 21628 replica.cpp:508] Replica received write
>> request for position 3
>> I0502 06:06:39.592962 21628 leveldb.cpp:341] Persisting action (352
>> bytes) to leveldb took 176771ns
>> I0502 06:06:39.592975 21628 replica.cpp:676] Persisted action at 3
>> I0502 06:06:39.593230 21634 replica.cpp:655] Replica received learned
>> notice for position 3
>> I0502 06:06:39.593384 21634 leveldb.cpp:341] Persisting action (354
>> bytes) to leveldb took 129668ns
>> I0502 06:06:39.593400 21634 replica.cpp:676] Persisted action at 3
>> I0502 06:06:39.593410 21634 replica.cpp:661] Replica learned APPEND
>> action at position 3
>> I0502 06:06:39.593914 21628 registrar.cpp:423] Successfully updated
>> 'registry'
>> I0502 06:06:39.594022 21628 log.cpp:699] Attempting to truncate the log
>> to 3
>> I0502 06:06:39.594079 21628 master.cpp:2164] Registered slave
>> 20140502-060639-143311683-52864-21608-0 at slave(10)@67.195.138.8:52864 (
>> minerva.apache.org)
>> I0502 06:06:39.594094 21628 master.cpp:3273] Adding slave
>> 20140502-060639-143311683-52864-21608-0 at slave(10)@67.195.138.8:52864 (
>> minerva.apache.org) with cpus(*):2; mem(*):1024; disk(*):1024;
>> ports(*):[31000-32000]
>> I0502 06:06:39.594210 21628 coordinator.cpp:339] Coordinator attempting
>> to write TRUNCATE action at position 4
>> I0502 06:06:39.594290 21628 slave.cpp:675] Registered with master
>> master@67.195.138.8:52864; given slave ID
>> 20140502-060639-143311683-52864-21608-0
>> I0502 06:06:39.594367 21628 hierarchical_allocator_process.hpp:445] Added
>> slave 20140502-060639-143311683-52864-21608-0 (minerva.apache.org) with
>> cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] (and
>> cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] available)
>> I0502 06:06:39.594434 21628 hierarchical_allocator_process.hpp:752]
>> Offering cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on
>> slave 20140502-060639-143311683-52864-21608-0 to framework
>> 20140502-060639-143311683-52864-21608-0000
>> I0502 06:06:39.594548 21628 hierarchical_allocator_process.hpp:708]
>> Performed allocation for slave 20140502-060639-143311683-52864-21608-0 in
>> 138437ns
>> I0502 06:06:39.594674 21628 master.hpp:586] Adding offer
>> 20140502-060639-143311683-52864-21608-0 with resources cpus(*):2;
>> mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave
>> 20140502-060639-143311683-52864-21608-0 (minerva.apache.org)
>> I0502 06:06:39.594739 21628 master.cpp:2737] Sending 1 offers to
>> framework 20140502-060639-143311683-52864-21608-0000
>> I0502 06:06:39.594935 21632 sched.cpp:529] Scheduler::resourceOffers took
>> 36114ns
>> I0502 06:06:39.595026 21633 replica.cpp:508] Replica received write
>> request for position 4
>> I0502 06:06:39.595144 21633 leveldb.cpp:341] Persisting action (16 bytes)
>> to leveldb took 100698ns
>> I0502 06:06:39.595167 21633 replica.cpp:676] Persisted action at 4
>> I0502 06:06:39.595443 21630 replica.cpp:655] Replica received learned
>> notice for position 4
>> I0502 06:06:39.595535 21630 leveldb.cpp:341] Persisting action (18 bytes)
>> to leveldb took 75305ns
>> I0502 06:06:39.595562 21630 leveldb.cpp:399] Deleting ~2 keys from
>> leveldb took 12985ns
>> I0502 06:06:39.595573 21630 replica.cpp:676] Persisted action at 4
>> I0502 06:06:39.595582 21630 replica.cpp:661] Replica learned TRUNCATE
>> action at position 4
>> I0502 06:06:39.595607 21628 master.hpp:596] Removing offer
>> 20140502-060639-143311683-52864-21608-0 with resources cpus(*):2;
>> mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave
>> 20140502-060639-143311683-52864-21608-0 (minerva.apache.org)
>> I0502 06:06:39.595669 21628 master.cpp:1802] Processing reply for offers:
>> [ 20140502-060639-143311683-52864-21608-0 ] on slave
>> 20140502-060639-143311683-52864-21608-0 at slave(10)@67.195.138.8:52864 (
>> minerva.apache.org) for framework
>> 20140502-060639-143311683-52864-21608-0000
>> I0502 06:06:39.595903 21628 master.hpp:558] Adding task 1 with resources
>> cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave
>> 20140502-060639-143311683-52864-21608-0 (minerva.apache.org)
>> I0502 06:06:39.595954 21628 master.cpp:2912] Launching task 1 of
>> framework 20140502-060639-143311683-52864-21608-0000 with resources
>> cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave
>> 20140502-060639-143311683-52864-21608-0 at slave(10)@67.195.138.8:52864 (
>> minerva.apache.org)
>> I0502 06:06:39.596096 21627 slave.cpp:905] Got assigned task 1 for
>> framework 20140502-060639-143311683-52864-21608-0000
>> I0502 06:06:39.596284 21627 slave.cpp:1015] Launching task 1 for
>> framework 20140502-060639-143311683-52864-21608-0000
>> I0502 06:06:39.598829 21627 exec.cpp:131] Version: 0.19.0
>> I0502 06:06:39.598899 21632 exec.cpp:181] Executor started at:
>> executor(5)@67.195.138.8:52864 with pid 21608
>> I0502 06:06:39.598984 21627 slave.cpp:1125] Queuing task '1' for executor
>> default of framework '20140502-060639-143311683-52864-21608-0000
>> I0502 06:06:39.599036 21627 slave.cpp:486] Successfully attached file
>> '/tmp/FaultToleranceTest_ReconcileIncompleteTasks_Cc9VTo/slaves/20140502-060639-143311683-52864-21608-0/frameworks/20140502-060639-143311683-52864-21608-0000/executors/default/runs/7aa3fa54-cae3-454d-af6b-e8ea86391a59'
>> I0502 06:06:39.599066 21627 slave.cpp:2282] Monitoring executor 'default'
>> of framework '20140502-060639-143311683-52864-21608-0000' in container
>> '7aa3fa54-cae3-454d-af6b-e8ea86391a59'
>> I0502 06:06:39.599149 21627 slave.cpp:1598] Got registration for executor
>> 'default' of framework 20140502-060639-143311683-52864-21608-0000
>> I0502 06:06:39.599297 21627 slave.cpp:1717] Flushing queued task 1 for
>> executor 'default' of framework 20140502-060639-143311683-52864-21608-0000
>> I0502 06:06:39.599372 21631 exec.cpp:205] Executor registered on slave
>> 20140502-060639-143311683-52864-21608-0
>> I0502 06:06:39.600342 21631 exec.cpp:217] Executor::registered took 9837ns
>> I0502 06:06:39.600396 21631 exec.cpp:292] Executor asked to run task '1'
>> I0502 06:06:39.600438 21631 exec.cpp:301] Executor::launchTask took
>> 31390ns
>> I0502 06:06:39.601402 21631 exec.cpp:524] Executor sending status update
>> TASK_FINISHED (UUID: a796dadd-9194-418d-8fe4-6fb0a1e38f29) for task 1 of
>> framework 20140502-060639-143311683-52864-21608-0000
>> I0502 06:06:39.601474 21631 slave.cpp:1953] Handling status update
>> TASK_FINISHED (UUID: a796dadd-9194-418d-8fe4-6fb0a1e38f29) for task 1 of
>> framework 20140502-060639-143311683-52864-21608-0000 from executor(5)@
>> 67.195.138.8:52864
>> I0502 06:06:39.601505 21631 slave.cpp:3444] Terminating task 1
>> I0502 06:06:39.601635 21632 status_update_manager.cpp:320] Received
>> status update TASK_FINISHED (UUID: a796dadd-9194-418d-8fe4-6fb0a1e38f29)
>> for task 1 of framework 20140502-060639-143311683-52864-21608-0000
>> I0502 06:06:39.601660 21632 status_update_manager.cpp:499] Creating
>> StatusUpdate stream for task 1 of framework
>> 20140502-060639-143311683-52864-21608-0000
>> I0502 06:06:39.601737 21632 status_update_manager.cpp:373] Forwarding
>> status update TASK_FINISHED (UUID: a796dadd-9194-418d-8fe4-6fb0a1e38f29)
>> for task 1 of framework 20140502-060639-143311683-52864-21608-0000 to
>> master@67.195.138.8:52864
>> I0502 06:06:39.601901 21628 slave.cpp:2070] Status update manager
>> successfully handled status update TASK_FINISHED (UUID:
>> a796dadd-9194-418d-8fe4-6fb0a1e38f29) for task 1 of framework
>> 20140502-060639-143311683-52864-21608-0000
>> I0502 06:06:39.601919 21628 slave.cpp:2076] Sending acknowledgement for
>> status update TASK_FINISHED (UUID: a796dadd-9194-418d-8fe4-6fb0a1e38f29)
>> for task 1 of framework 20140502-060639-143311683-52864-21608-0000 to
>> executor(5)@67.195.138.8:52864
>> I0502 06:06:39.602010 21634 exec.cpp:338] Executor received status update
>> acknowledgement a796dadd-9194-418d-8fe4-6fb0a1e38f29 for task 1 of
>> framework 20140502-060639-143311683-52864-21608-0000
>> I0502 06:06:39.606542 21632 slave.cpp:525] New master detected at
>> master@67.195.138.8:52864
>> I0502 06:06:39.606576 21632 slave.cpp:585] Authenticating with master
>> master@67.195.138.8:52864
>> I0502 06:06:39.606642 21631 status_update_manager.cpp:167] New master
>> detected at master@67.195.138.8:52864
>> I0502 06:06:39.606678 21633 authenticatee.hpp:128] Creating new client
>> SASL connection
>> I0502 06:06:39.606667 21632 slave.cpp:558] Detecting new master
>> W0502 06:06:39.606688 21631 status_update_manager.cpp:181] Resending
>> status update TASK_FINISHED (UUID: a796dadd-9194-418d-8fe4-6fb0a1e38f29)
>> for task 1 of framework 20140502-060639-143311683-52864-21608-0000
>> I0502 06:06:39.606719 21631 status_update_manager.cpp:373] Forwarding
>> status update TASK_FINISHED (UUID: a796dadd-9194-418d-8fe4-6fb0a1e38f29)
>> for task 1 of framework 20140502-060639-143311683-52864-21608-0000 to
>> master@67.195.138.8:52864
>> I0502 06:06:39.606796 21632 master.cpp:1260] Disconnecting slave
>> 20140502-060639-143311683-52864-21608-0
>> I0502 06:06:39.606843 21632 master.cpp:1280] Removing non-checkpointing
>> framework 20140502-060639-143311683-52864-21608-0000 from disconnected
>> slave 20140502-060639-143311683-52864-21608-0 at slave(10)@
>> 67.195.138.8:52864 (minerva.apache.org)
>> I0502 06:06:39.606866 21633 hierarchical_allocator_process.hpp:484] Slave
>> 20140502-060639-143311683-52864-21608-0 disconnected
>> I0502 06:06:39.606866 21632 master.cpp:3226] Removing framework
>> 20140502-060639-143311683-52864-21608-0000 from slave
>> 20140502-060639-143311683-52864-21608-0 at slave(10)@67.195.138.8:52864 (
>> minerva.apache.org)
>> I0502 06:06:39.607900 21632 master.cpp:2440] Status update TASK_LOST
>> (UUID: 2a53f35a-c441-4891-a01a-bf58fcbcaf61) for task 1 of framework
>> 20140502-060639-143311683-52864-21608-0000 from slave
>> 20140502-060639-143311683-52864-21608-0 at slave(10)@67.195.138.8:52864 (
>> minerva.apache.org)
>> I0502 06:06:39.607970 21629 sched.cpp:620] Scheduler::statusUpdate took
>> 14519ns
>> I0502 06:06:39.607969 21632 master.hpp:576] Removing task 1 with
>> resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on
>> slave 20140502-060639-143311683-52864-21608-0 (minerva.apache.org)
>> I0502 06:06:39.608113 21632 master.cpp:2788] Authenticating slave(10)@
>> 67.195.138.8:52864
>> I0502 06:06:39.608181 21627 hierarchical_allocator_process.hpp:637]
>> Recovered cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]
>> (total allocatable: cpus(*):2; mem(*):1024; disk(*):1024;
>> ports(*):[31000-32000]) on slave 20140502-060639-143311683-52864-21608-0
>> from framework 20140502-060639-143311683-52864-21608-0000
>> I0502 06:06:39.608211 21630 authenticator.hpp:148] Creating new server
>> SASL connection
>> W0502 06:06:39.608288 21632 master.cpp:2434] Could not lookup task for
>> status update TASK_FINISHED (UUID: a796dadd-9194-418d-8fe4-6fb0a1e38f29)
>> for task 1 of framework 20140502-060639-143311683-52864-21608-0000 from
>> slave 20140502-060639-143311683-52864-21608-0 at slave(10)@
>> 67.195.138.8:52864 (minerva.apache.org)
>> I0502 06:06:39.608330 21633 sched.cpp:620] Scheduler::statusUpdate took
>> 6917ns
>> I0502 06:06:39.608332 21630 authenticatee.hpp:219] Received SASL
>> authentication mechanisms: CRAM-MD5
>> I0502 06:06:39.608366 21630 authenticatee.hpp:245] Attempting to
>> authenticate with mechanism 'CRAM-MD5'
>> I0502 06:06:39.608397 21630 authenticator.hpp:254] Received SASL
>> authentication start
>> I0502 06:06:39.608440 21630 authenticator.hpp:342] Authentication
>> requires more steps
>> I0502 06:06:39.608471 21632 status_update_manager.cpp:398] Received
>> status update acknowledgement (UUID: a796dadd-9194-418d-8fe4-6fb0a1e38f29)
>> for task 1 of framework 20140502-060639-143311683-52864-21608-0000
>> I0502 06:06:39.608494 21631 authenticatee.hpp:265] Received SASL
>> authentication step
>> I0502 06:06:39.608505 21632 status_update_manager.cpp:530] Cleaning up
>> status update stream for task 1 of framework
>> 20140502-060639-143311683-52864-21608-0000
>> I0502 06:06:39.608547 21631 authenticator.hpp:282] Received SASL
>> authentication step
>> I0502 06:06:39.608577 21631 auxprop.cpp:81] Request to lookup properties
>> for user: 'test-principal' realm: 'minerva.apache.org' server FQDN: '
>> minerva.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
>> SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
>> I0502 06:06:39.608587 21631 auxprop.cpp:153] Looking up auxiliary
>> property '*userPassword'
>> I0502 06:06:39.608588 21634 slave.cpp:1538] Status update manager
>> successfully handled status update acknowledgement (UUID:
>> a796dadd-9194-418d-8fe4-6fb0a1e38f29) for task 1 of framework
>> 20140502-060639-143311683-52864-21608-0000
>> I0502 06:06:39.608599 21631 auxprop.cpp:153] Looking up auxiliary
>> property '*cmusaslsecretCRAM-MD5'
>> I0502 06:06:39.608603 21634 slave.cpp:3468] Completing task 1
>> I0502 06:06:39.608610 21631 auxprop.cpp:81] Request to lookup properties
>> for user: 'test-principal' realm: 'minerva.apache.org' server FQDN: '
>> minerva.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
>> SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
>> I0502 06:06:39.608621 21631 auxprop.cpp:103] Skipping auxiliary property
>> '*userPassword' since SASL_AUXPROP_AUTHZID == true
>> I0502 06:06:39.608633 21631 auxprop.cpp:103] Skipping auxiliary property
>> '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
>> I0502 06:06:39.608644 21631 authenticator.hpp:334] Authentication success
>> I0502 06:06:39.608707 21629 master.cpp:2828] Successfully authenticated
>> slave(10)@67.195.138.8:52864
>> I0502 06:06:39.608734 21632 authenticatee.hpp:305] Authentication success
>> I0502 06:06:39.608839 21627 slave.cpp:642] Successfully authenticated
>> with master master@67.195.138.8:52864
>> I0502 06:06:39.608906 21627 slave.cpp:871] Will retry registration in
>> 9.584457319secs if necessary
>> W0502 06:06:39.608942 21634 master.cpp:2238] Slave at slave(10)@
>> 67.195.138.8:52864 (minerva.apache.org) is being allowed to re-register
>> with an already in use id (20140502-060639-143311683-52864-21608-0)
>> I0502 06:06:39.609022 21627 slave.cpp:725] Re-registered with master
>> master@67.195.138.8:52864
>> I0502 06:06:39.609079 21628 hierarchical_allocator_process.hpp:498] Slave
>> 20140502-060639-143311683-52864-21608-0 reconnected
>> ../../src/tests/fault_tolerance_tests.cpp:2084: Failure
>> Value of: status.get().state()
>>   Actual: TASK_LOST
>> Expected: TASK_FINISHED
>> I0502 06:06:42.722064 22444 exec.cpp:85] Committing suicide by killing
>> the process group
>> Build timed out (after 120 minutes). Marking the build as failed.
>> Build was aborted
>>
>
>

Mime
  • Unnamed multipart/alternative (inline, None, 0 bytes)
View raw message