[
https://issues.apache.org/jira/browse/MESOS-2007?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15139472#comment-15139472
]
Kevin Klues commented on MESOS-2007:
------------------------------------
I propose we mark this ticket closed for the following reasons. If you feel
this is in error, please reopen it with specific details and a way to reproduce
the bug. Thanks!
1) Unfortunately, we don't have archives of the Jenkins builds before April
2015, so I don't have any easy way of seeing the exact last time this error
occurred. However, we do know it has not cropped up on the Jenkins builds since
at least December 2015:
http://www.mail-archive.com/search?q=AllocatorTest&l=builds%40mesos.apache.org
2) As suggested in a related ticket (MESOS-2017), I reset my Mesos tree to:
{noformat}
commit 5d5b65e5722a21868315d80eb05428b11b4d87d0
Author: Adam B <[email protected]>
Date: Mon Oct 13 21:33:11 2014 -0700
Enabled whitespace/semicolon rule for cpplint.
{noformat}
and ran the following command, trying to trigger both the flaky test error, as
well as the "RAW: Pure virtual method called" error.
GTEST_FILTER="DRFAllocatorTest.DRFAllocatorProcess:ReconciliationTest.TaskStateMismatch:AllocatorTest/0.SlaveReregistersFirst"
run-one-until-failure src/mesos-tests --verbose
I ran this test continuously overnight on 2 different setups without error:
– My native Mac OS X setup
– A docker container based on the support/docker_build.sh script in newer
Mesoses.
I set up the docker with the following configuration:
COMPILER=clang, CONFIGURATION=--verbose, ENVIRONMENT=GLOG_v=1, MESOS_VERBOSE=1,
OS=ubuntu:14.04, label_exp=docker||Hadoop/1638/changes
3) Recently a new ticket with a similar error has cropped up with a similar
"RAW: Pure virtual method called" error (MESOS-4604), but we have diagnosed
this problem already and it is unrelated to the errors seen in this test
(details are in the ticket itself).
> AllocatorTest/0.SlaveReregistersFirst is flaky
> ----------------------------------------------
>
> Key: MESOS-2007
> URL: https://issues.apache.org/jira/browse/MESOS-2007
> Project: Mesos
> Issue Type: Bug
> Components: test
> Affects Versions: 0.21.0
> Environment: https://builds.apache.org/computer/ubuntu-1/systemInfo
> Reporter: Yan Xu
> Assignee: Kevin Klues
> Labels: flaky
>
> {noformat:title=}
> [ RUN ] AllocatorTest/0.SlaveReregistersFirst
> Using temporary directory '/tmp/AllocatorTest_0_SlaveReregistersFirst_YPe61d'
> I1028 23:48:22.360447 31190 leveldb.cpp:176] Opened db in 2.192575ms
> I1028 23:48:22.361253 31190 leveldb.cpp:183] Compacted db in 760753ns
> I1028 23:48:22.361320 31190 leveldb.cpp:198] Created db iterator in 22188ns
> I1028 23:48:22.361340 31190 leveldb.cpp:204] Seeked to beginning of db in
> 1950ns
> I1028 23:48:22.361351 31190 leveldb.cpp:273] Iterated through 0 keys in the
> db in 345ns
> I1028 23:48:22.361403 31190 replica.cpp:741] Replica recovered with log
> positions 0 -> 0 with 1 holes and 0 unlearned
> I1028 23:48:22.362185 31217 recover.cpp:437] Starting replica recovery
> I1028 23:48:22.362764 31219 recover.cpp:463] Replica is in EMPTY status
> I1028 23:48:22.363955 31210 replica.cpp:638] Replica in EMPTY status received
> a broadcasted recover request
> I1028 23:48:22.364320 31217 recover.cpp:188] Received a recover response from
> a replica in EMPTY status
> I1028 23:48:22.364820 31211 recover.cpp:554] Updating replica status to
> STARTING
> I1028 23:48:22.365365 31215 leveldb.cpp:306] Persisting metadata (8 bytes) to
> leveldb took 418991ns
> I1028 23:48:22.365391 31215 replica.cpp:320] Persisted replica status to
> STARTING
> I1028 23:48:22.365617 31217 recover.cpp:463] Replica is in STARTING status
> I1028 23:48:22.366328 31206 master.cpp:312] Master
> 20141028-234822-3193029443-50043-31190 (pietas.apache.org) started on
> 67.195.81.190:50043
> I1028 23:48:22.366377 31206 master.cpp:358] Master only allowing
> authenticated frameworks to register
> I1028 23:48:22.366391 31206 master.cpp:363] Master only allowing
> authenticated slaves to register
> I1028 23:48:22.366402 31206 credentials.hpp:36] Loading credentials for
> authentication from
> '/tmp/AllocatorTest_0_SlaveReregistersFirst_YPe61d/credentials'
> I1028 23:48:22.366708 31206 master.cpp:392] Authorization enabled
> I1028 23:48:22.366886 31209 replica.cpp:638] Replica in STARTING status
> received a broadcasted recover request
> I1028 23:48:22.367311 31208 master.cpp:120] No whitelist given. Advertising
> offers for all slaves
> I1028 23:48:22.367312 31207 recover.cpp:188] Received a recover response from
> a replica in STARTING status
> I1028 23:48:22.367686 31211 hierarchical_allocator_process.hpp:299]
> Initializing hierarchical allocator process with master :
> [email protected]:50043
> I1028 23:48:22.367863 31212 recover.cpp:554] Updating replica status to VOTING
> I1028 23:48:22.368477 31218 leveldb.cpp:306] Persisting metadata (8 bytes) to
> leveldb took 375527ns
> I1028 23:48:22.368505 31218 replica.cpp:320] Persisted replica status to
> VOTING
> I1028 23:48:22.368517 31204 master.cpp:1242] The newly elected leader is
> [email protected]:50043 with id 20141028-234822-3193029443-50043-31190
> I1028 23:48:22.368549 31204 master.cpp:1255] Elected as the leading master!
> I1028 23:48:22.368567 31204 master.cpp:1073] Recovering from registrar
> I1028 23:48:22.368621 31215 recover.cpp:568] Successfully joined the Paxos
> group
> I1028 23:48:22.368716 31219 registrar.cpp:313] Recovering registrar
> I1028 23:48:22.369000 31215 recover.cpp:452] Recover process terminated
> I1028 23:48:22.369523 31208 log.cpp:656] Attempting to start the writer
> I1028 23:48:22.370909 31205 replica.cpp:474] Replica received implicit
> promise request with proposal 1
> I1028 23:48:22.371266 31205 leveldb.cpp:306] Persisting metadata (8 bytes) to
> leveldb took 325016ns
> I1028 23:48:22.371290 31205 replica.cpp:342] Persisted promised to 1
> I1028 23:48:22.371979 31218 coordinator.cpp:230] Coordinator attemping to
> fill missing position
> I1028 23:48:22.373378 31210 replica.cpp:375] Replica received explicit
> promise request for position 0 with proposal 2
> I1028 23:48:22.373746 31210 leveldb.cpp:343] Persisting action (8 bytes) to
> leveldb took 329018ns
> I1028 23:48:22.373772 31210 replica.cpp:676] Persisted action at 0
> I1028 23:48:22.374897 31214 replica.cpp:508] Replica received write request
> for position 0
> I1028 23:48:22.374951 31214 leveldb.cpp:438] Reading position from leveldb
> took 26002ns
> I1028 23:48:22.375272 31214 leveldb.cpp:343] Persisting action (14 bytes) to
> leveldb took 289094ns
> I1028 23:48:22.375298 31214 replica.cpp:676] Persisted action at 0
> I1028 23:48:22.375886 31204 replica.cpp:655] Replica received learned notice
> for position 0
> I1028 23:48:22.376258 31204 leveldb.cpp:343] Persisting action (16 bytes) to
> leveldb took 346650ns
> I1028 23:48:22.376277 31204 replica.cpp:676] Persisted action at 0
> I1028 23:48:22.376298 31204 replica.cpp:661] Replica learned NOP action at
> position 0
> I1028 23:48:22.376843 31215 log.cpp:672] Writer started with ending position 0
> I1028 23:48:22.378056 31205 leveldb.cpp:438] Reading position from leveldb
> took 28265ns
> I1028 23:48:22.380323 31217 registrar.cpp:346] Successfully fetched the
> registry (0B) in 11.55584ms
> I1028 23:48:22.380466 31217 registrar.cpp:445] Applied 1 operations in
> 50632ns; attempting to update the 'registry'
> I1028 23:48:22.382472 31217 log.cpp:680] Attempting to append 139 bytes to
> the log
> I1028 23:48:22.382715 31210 coordinator.cpp:340] Coordinator attempting to
> write APPEND action at position 1
> I1028 23:48:22.383463 31210 replica.cpp:508] Replica received write request
> for position 1
> I1028 23:48:22.383857 31210 leveldb.cpp:343] Persisting action (158 bytes) to
> leveldb took 363758ns
> I1028 23:48:22.383875 31210 replica.cpp:676] Persisted action at 1
> I1028 23:48:22.384397 31218 replica.cpp:655] Replica received learned notice
> for position 1
> I1028 23:48:22.384840 31218 leveldb.cpp:343] Persisting action (160 bytes) to
> leveldb took 420161ns
> I1028 23:48:22.384862 31218 replica.cpp:676] Persisted action at 1
> I1028 23:48:22.384882 31218 replica.cpp:661] Replica learned APPEND action at
> position 1
> I1028 23:48:22.385684 31211 registrar.cpp:490] Successfully updated the
> 'registry' in 5.158144ms
> I1028 23:48:22.385818 31211 registrar.cpp:376] Successfully recovered
> registrar
> I1028 23:48:22.385912 31214 log.cpp:699] Attempting to truncate the log to 1
> I1028 23:48:22.386101 31218 coordinator.cpp:340] Coordinator attempting to
> write TRUNCATE action at position 2
> I1028 23:48:22.386124 31211 master.cpp:1100] Recovered 0 slaves from the
> Registry (101B) ; allowing 10mins for slaves to re-register
> I1028 23:48:22.387398 31209 replica.cpp:508] Replica received write request
> for position 2
> I1028 23:48:22.387758 31209 leveldb.cpp:343] Persisting action (16 bytes) to
> leveldb took 334969ns
> I1028 23:48:22.387776 31209 replica.cpp:676] Persisted action at 2
> I1028 23:48:22.388272 31204 replica.cpp:655] Replica received learned notice
> for position 2
> I1028 23:48:22.388453 31204 leveldb.cpp:343] Persisting action (18 bytes) to
> leveldb took 159390ns
> I1028 23:48:22.388501 31204 leveldb.cpp:401] Deleting ~1 keys from leveldb
> took 30409ns
> I1028 23:48:22.388516 31204 replica.cpp:676] Persisted action at 2
> I1028 23:48:22.388531 31204 replica.cpp:661] Replica learned TRUNCATE action
> at position 2
> I1028 23:48:22.400737 31207 slave.cpp:169] Slave started on
> 34)@67.195.81.190:50043
> I1028 23:48:22.400786 31207 credentials.hpp:84] Loading credential for
> authentication from
> '/tmp/AllocatorTest_0_SlaveReregistersFirst_QPPV21/credential'
> I1028 23:48:22.400996 31207 slave.cpp:276] Slave using credential for:
> test-principal
> I1028 23:48:22.401304 31207 slave.cpp:289] Slave resources: cpus(*):2;
> mem(*):1024; disk(*):3.70122e+06; ports(*):[31000-32000]
> I1028 23:48:22.401413 31207 slave.cpp:318] Slave hostname: pietas.apache.org
> I1028 23:48:22.401520 31207 slave.cpp:319] Slave checkpoint: false
> W1028 23:48:22.401535 31207 slave.cpp:321] Disabling checkpointing is
> deprecated and the --checkpoint flag will be removed in a future release.
> Please avoid using this flag
> I1028 23:48:22.402349 31207 state.cpp:33] Recovering state from
> '/tmp/AllocatorTest_0_SlaveReregistersFirst_QPPV21/meta'
> I1028 23:48:22.402678 31207 status_update_manager.cpp:197] Recovering status
> update manager
> I1028 23:48:22.403048 31211 slave.cpp:3456] Finished recovery
> I1028 23:48:22.403815 31215 slave.cpp:602] New master detected at
> [email protected]:50043
> I1028 23:48:22.403852 31215 slave.cpp:665] Authenticating with master
> [email protected]:50043
> I1028 23:48:22.403875 31206 status_update_manager.cpp:171] Pausing sending
> status updates
> I1028 23:48:22.403961 31215 slave.cpp:638] Detecting new master
> I1028 23:48:22.404016 31211 authenticatee.hpp:133] Creating new client SASL
> connection
> I1028 23:48:22.404230 31204 master.cpp:3853] Authenticating
> slave(34)@67.195.81.190:50043
> I1028 23:48:22.404464 31205 authenticator.hpp:161] Creating new server SASL
> connection
> I1028 23:48:22.404613 31211 authenticatee.hpp:224] Received SASL
> authentication mechanisms: CRAM-MD5
> I1028 23:48:22.404649 31211 authenticatee.hpp:250] Attempting to authenticate
> with mechanism 'CRAM-MD5'
> I1028 23:48:22.404734 31211 authenticator.hpp:267] Received SASL
> authentication start
> I1028 23:48:22.404783 31211 authenticator.hpp:389] Authentication requires
> more steps
> I1028 23:48:22.404898 31215 authenticatee.hpp:270] Received SASL
> authentication step
> I1028 23:48:22.404999 31215 authenticator.hpp:295] Received SASL
> authentication step
> I1028 23:48:22.405030 31215 auxprop.cpp:81] Request to lookup properties for
> user: 'test-principal' realm: 'pietas.apache.org' server FQDN:
> 'pietas.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
> SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
> I1028 23:48:22.405047 31215 auxprop.cpp:153] Looking up auxiliary property
> '*userPassword'
> I1028 23:48:22.405086 31215 auxprop.cpp:153] Looking up auxiliary property
> '*cmusaslsecretCRAM-MD5'
> I1028 23:48:22.405109 31215 auxprop.cpp:81] Request to lookup properties for
> user: 'test-principal' realm: 'pietas.apache.org' server FQDN:
> 'pietas.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
> SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
> I1028 23:48:22.405122 31215 auxprop.cpp:103] Skipping auxiliary property
> '*userPassword' since SASL_AUXPROP_AUTHZID == true
> I1028 23:48:22.405129 31215 auxprop.cpp:103] Skipping auxiliary property
> '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
> I1028 23:48:22.405146 31215 authenticator.hpp:381] Authentication success
> I1028 23:48:22.405243 31213 authenticatee.hpp:310] Authentication success
> I1028 23:48:22.405253 31214 master.cpp:3893] Successfully authenticated
> principal 'test-principal' at slave(34)@67.195.81.190:50043
> I1028 23:48:22.405505 31213 slave.cpp:722] Successfully authenticated with
> master [email protected]:50043
> I1028 23:48:22.405619 31213 slave.cpp:1050] Will retry registration in
> 17.050994ms if necessary
> I1028 23:48:22.405819 31215 master.cpp:3032] Registering slave at
> slave(34)@67.195.81.190:50043 (pietas.apache.org) with id
> 20141028-234822-3193029443-50043-31190-S0
> I1028 23:48:22.406262 31216 registrar.cpp:445] Applied 1 operations in
> 52647ns; attempting to update the 'registry'
> I1028 23:48:22.406697 31190 sched.cpp:137] Version: 0.21.0
> I1028 23:48:22.407083 31211 sched.cpp:233] New master detected at
> [email protected]:50043
> I1028 23:48:22.407114 31211 sched.cpp:283] Authenticating with master
> [email protected]:50043
> I1028 23:48:22.407290 31214 authenticatee.hpp:133] Creating new client SASL
> connection
> I1028 23:48:22.407424 31214 master.cpp:3853] Authenticating
> [email protected]:50043
> I1028 23:48:22.407659 31207 authenticator.hpp:161] Creating new server SASL
> connection
> I1028 23:48:22.407757 31207 authenticatee.hpp:224] Received SASL
> authentication mechanisms: CRAM-MD5
> I1028 23:48:22.407774 31207 authenticatee.hpp:250] Attempting to authenticate
> with mechanism 'CRAM-MD5'
> I1028 23:48:22.407830 31207 authenticator.hpp:267] Received SASL
> authentication start
> I1028 23:48:22.407868 31207 authenticator.hpp:389] Authentication requires
> more steps
> I1028 23:48:22.407927 31207 authenticatee.hpp:270] Received SASL
> authentication step
> I1028 23:48:22.408015 31212 authenticator.hpp:295] Received SASL
> authentication step
> I1028 23:48:22.408037 31212 auxprop.cpp:81] Request to lookup properties for
> user: 'test-principal' realm: 'pietas.apache.org' server FQDN:
> 'pietas.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
> SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
> I1028 23:48:22.408046 31212 auxprop.cpp:153] Looking up auxiliary property
> '*userPassword'
> I1028 23:48:22.408072 31212 auxprop.cpp:153] Looking up auxiliary property
> '*cmusaslsecretCRAM-MD5'
> I1028 23:48:22.408092 31212 auxprop.cpp:81] Request to lookup properties for
> user: 'test-principal' realm: 'pietas.apache.org' server FQDN:
> 'pietas.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
> SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
> I1028 23:48:22.408100 31212 auxprop.cpp:103] Skipping auxiliary property
> '*userPassword' since SASL_AUXPROP_AUTHZID == true
> I1028 23:48:22.408105 31212 auxprop.cpp:103] Skipping auxiliary property
> '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
> I1028 23:48:22.408116 31212 authenticator.hpp:381] Authentication success
> I1028 23:48:22.408192 31210 authenticatee.hpp:310] Authentication success
> I1028 23:48:22.408210 31217 master.cpp:3893] Successfully authenticated
> principal 'test-principal' at
> [email protected]:50043
> I1028 23:48:22.408419 31210 sched.cpp:357] Successfully authenticated with
> master [email protected]:50043
> I1028 23:48:22.408460 31210 sched.cpp:476] Sending registration request to
> [email protected]:50043
> I1028 23:48:22.408568 31217 master.cpp:1362] Received registration request
> for framework 'default' at
> [email protected]:50043
> I1028 23:48:22.408617 31217 master.cpp:1321] Authorizing framework principal
> 'test-principal' to receive offers for role '*'
> I1028 23:48:22.408937 31214 master.cpp:1426] Registering framework
> 20141028-234822-3193029443-50043-31190-0000 (default) at
> [email protected]:50043
> I1028 23:48:22.409265 31213 sched.cpp:407] Framework registered with
> 20141028-234822-3193029443-50043-31190-0000
> I1028 23:48:22.409267 31212 hierarchical_allocator_process.hpp:329] Added
> framework 20141028-234822-3193029443-50043-31190-0000
> I1028 23:48:22.409312 31212 hierarchical_allocator_process.hpp:697] No
> resources available to allocate!
> I1028 23:48:22.409324 31215 log.cpp:680] Attempting to append 316 bytes to
> the log
> I1028 23:48:22.409333 31213 sched.cpp:421] Scheduler::registered took 38591ns
> I1028 23:48:22.409327 31212 hierarchical_allocator_process.hpp:659] Performed
> allocation for 0 slaves in 24107ns
> I1028 23:48:22.409518 31205 coordinator.cpp:340] Coordinator attempting to
> write APPEND action at position 3
> I1028 23:48:22.410127 31206 replica.cpp:508] Replica received write request
> for position 3
> I1028 23:48:22.410706 31206 leveldb.cpp:343] Persisting action (335 bytes) to
> leveldb took 554098ns
> I1028 23:48:22.410725 31206 replica.cpp:676] Persisted action at 3
> I1028 23:48:22.411151 31217 replica.cpp:655] Replica received learned notice
> for position 3
> I1028 23:48:22.411499 31217 leveldb.cpp:343] Persisting action (337 bytes) to
> leveldb took 326572ns
> I1028 23:48:22.411519 31217 replica.cpp:676] Persisted action at 3
> I1028 23:48:22.411533 31217 replica.cpp:661] Replica learned APPEND action at
> position 3
> I1028 23:48:22.412292 31219 registrar.cpp:490] Successfully updated the
> 'registry' in 5.972992ms
> I1028 23:48:22.412518 31218 log.cpp:699] Attempting to truncate the log to 3
> I1028 23:48:22.412621 31213 coordinator.cpp:340] Coordinator attempting to
> write TRUNCATE action at position 4
> I1028 23:48:22.412734 31219 slave.cpp:2522] Received ping from
> slave-observer(38)@67.195.81.190:50043
> I1028 23:48:22.412787 31206 master.cpp:3086] Registered slave
> 20141028-234822-3193029443-50043-31190-S0 at slave(34)@67.195.81.190:50043
> (pietas.apache.org) with cpus(*):2; mem(*):1024; disk(*):3.70122e+06;
> ports(*):[31000-32000]
> I1028 23:48:22.412858 31219 slave.cpp:756] Registered with master
> [email protected]:50043; given slave ID
> 20141028-234822-3193029443-50043-31190-S0
> I1028 23:48:22.412994 31210 status_update_manager.cpp:178] Resuming sending
> status updates
> I1028 23:48:22.413014 31211 hierarchical_allocator_process.hpp:442] Added
> slave 20141028-234822-3193029443-50043-31190-S0 (pietas.apache.org) with
> cpus(*):2; mem(*):1024; disk(*):3.70122e+06; ports(*):[31000-32000] (and
> cpus(*):2; mem(*):1024; disk(*):3.70122e+06; ports(*):[31000-32000] available)
> I1028 23:48:22.413159 31211 hierarchical_allocator_process.hpp:734] Offering
> cpus(*):2; mem(*):1024; disk(*):3.70122e+06; ports(*):[31000-32000] on slave
> 20141028-234822-3193029443-50043-31190-S0 to framework
> 20141028-234822-3193029443-50043-31190-0000
> I1028 23:48:22.413290 31208 replica.cpp:508] Replica received write request
> for position 4
> I1028 23:48:22.413421 31211 hierarchical_allocator_process.hpp:679] Performed
> allocation for slave 20141028-234822-3193029443-50043-31190-S0 in 346658ns
> I1028 23:48:22.413650 31208 leveldb.cpp:343] Persisting action (16 bytes) to
> leveldb took 336067ns
> I1028 23:48:22.413668 31208 replica.cpp:676] Persisted action at 4
> I1028 23:48:22.413797 31216 master.cpp:3795] Sending 1 offers to framework
> 20141028-234822-3193029443-50043-31190-0000 (default) at
> [email protected]:50043
> I1028 23:48:22.414077 31212 replica.cpp:655] Replica received learned notice
> for position 4
> I1028 23:48:22.414356 31212 leveldb.cpp:343] Persisting action (18 bytes) to
> leveldb took 260401ns
> I1028 23:48:22.414403 31212 leveldb.cpp:401] Deleting ~2 keys from leveldb
> took 28541ns
> I1028 23:48:22.414417 31212 replica.cpp:676] Persisted action at 4
> I1028 23:48:22.414446 31212 replica.cpp:661] Replica learned TRUNCATE action
> at position 4
> I1028 23:48:22.414422 31207 sched.cpp:544] Scheduler::resourceOffers took
> 310278ns
> I1028 23:48:22.415086 31214 master.cpp:2321] Processing reply for offers: [
> 20141028-234822-3193029443-50043-31190-O0 ] on slave
> 20141028-234822-3193029443-50043-31190-S0 at slave(34)@67.195.81.190:50043
> (pietas.apache.org) for framework 20141028-234822-3193029443-50043-31190-0000
> (default) at
> [email protected]:50043
> W1028 23:48:22.415163 31214 master.cpp:1969] 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.
> W1028 23:48:22.415186 31214 master.cpp:1980] 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.
> I1028 23:48:22.415256 31214 master.cpp:2417] Authorizing framework principal
> 'test-principal' to launch task 0 as user 'jenkins'
> I1028 23:48:22.416033 31219 master.hpp:877] Adding task 0 with resources
> cpus(*):1; mem(*):500 on slave 20141028-234822-3193029443-50043-31190-S0
> (pietas.apache.org)
> I1028 23:48:22.416084 31219 master.cpp:2480] Launching task 0 of framework
> 20141028-234822-3193029443-50043-31190-0000 (default) at
> [email protected]:50043 with
> resources cpus(*):1; mem(*):500 on slave
> 20141028-234822-3193029443-50043-31190-S0 at slave(34)@67.195.81.190:50043
> (pietas.apache.org)
> I1028 23:48:22.416317 31214 slave.cpp:1081] Got assigned task 0 for framework
> 20141028-234822-3193029443-50043-31190-0000
> I1028 23:48:22.416679 31215 hierarchical_allocator_process.hpp:563] Recovered
> cpus(*):1; mem(*):524; disk(*):3.70122e+06; ports(*):[31000-32000] (total
> allocatable: cpus(*):1; mem(*):524; disk(*):3.70122e+06;
> ports(*):[31000-32000]) on slave 20141028-234822-3193029443-50043-31190-S0
> from framework 20141028-234822-3193029443-50043-31190-0000
> I1028 23:48:22.416721 31215 hierarchical_allocator_process.hpp:599] Framework
> 20141028-234822-3193029443-50043-31190-0000 filtered slave
> 20141028-234822-3193029443-50043-31190-S0 for 5secs
> I1028 23:48:22.416724 31214 slave.cpp:1191] Launching task 0 for framework
> 20141028-234822-3193029443-50043-31190-0000
> I1028 23:48:22.418534 31214 slave.cpp:3871] Launching executor default of
> framework 20141028-234822-3193029443-50043-31190-0000 in work directory
> '/tmp/AllocatorTest_0_SlaveReregistersFirst_QPPV21/slaves/20141028-234822-3193029443-50043-31190-S0/frameworks/20141028-234822-3193029443-50043-31190-0000/executors/default/runs/d593f433-3c16-4678-8f76-4038fe2841c4'
> I1028 23:48:22.420557 31214 exec.cpp:132] Version: 0.21.0
> I1028 23:48:22.420755 31213 exec.cpp:182] Executor started at:
> executor(22)@67.195.81.190:50043 with pid 31190
> I1028 23:48:22.420903 31214 slave.cpp:1317] Queuing task '0' for executor
> default of framework '20141028-234822-3193029443-50043-31190-0000
> I1028 23:48:22.420997 31214 slave.cpp:555] Successfully attached file
> '/tmp/AllocatorTest_0_SlaveReregistersFirst_QPPV21/slaves/20141028-234822-3193029443-50043-31190-S0/frameworks/20141028-234822-3193029443-50043-31190-0000/executors/default/runs/d593f433-3c16-4678-8f76-4038fe2841c4'
> I1028 23:48:22.421058 31214 slave.cpp:1849] Got registration for executor
> 'default' of framework 20141028-234822-3193029443-50043-31190-0000 from
> executor(22)@67.195.81.190:50043
> I1028 23:48:22.421295 31214 slave.cpp:1968] Flushing queued task 0 for
> executor 'default' of framework 20141028-234822-3193029443-50043-31190-0000
> I1028 23:48:22.421391 31205 exec.cpp:206] Executor registered on slave
> 20141028-234822-3193029443-50043-31190-S0
> I1028 23:48:22.421495 31214 slave.cpp:2802] Monitoring executor 'default' of
> framework '20141028-234822-3193029443-50043-31190-0000' in container
> 'd593f433-3c16-4678-8f76-4038fe2841c4'
> I1028 23:48:22.422873 31205 exec.cpp:218] Executor::registered took 19148ns
> I1028 23:48:22.422991 31205 exec.cpp:293] Executor asked to run task '0'
> I1028 23:48:22.423085 31205 exec.cpp:302] Executor::launchTask took 76519ns
> I1028 23:48:22.424541 31205 exec.cpp:525] Executor sending status update
> TASK_RUNNING (UUID: 10174aa0-0e5a-4f9d-a530-dee64e93f222) for task 0 of
> framework 20141028-234822-3193029443-50043-31190-0000
> I1028 23:48:22.424724 31205 slave.cpp:2202] Handling status update
> TASK_RUNNING (UUID: 10174aa0-0e5a-4f9d-a530-dee64e93f222) for task 0 of
> framework 20141028-234822-3193029443-50043-31190-0000 from
> executor(22)@67.195.81.190:50043
> I1028 23:48:22.424932 31213 status_update_manager.cpp:317] Received status
> update TASK_RUNNING (UUID: 10174aa0-0e5a-4f9d-a530-dee64e93f222) for task 0
> of framework 20141028-234822-3193029443-50043-31190-0000
> I1028 23:48:22.424963 31213 status_update_manager.cpp:494] Creating
> StatusUpdate stream for task 0 of framework
> 20141028-234822-3193029443-50043-31190-0000
> I1028 23:48:22.425122 31213 status_update_manager.cpp:371] Forwarding update
> TASK_RUNNING (UUID: 10174aa0-0e5a-4f9d-a530-dee64e93f222) for task 0 of
> framework 20141028-234822-3193029443-50043-31190-0000 to the slave
> I1028 23:48:22.425257 31205 slave.cpp:2442] Forwarding the update
> TASK_RUNNING (UUID: 10174aa0-0e5a-4f9d-a530-dee64e93f222) for task 0 of
> framework 20141028-234822-3193029443-50043-31190-0000 to
> [email protected]:50043
> I1028 23:48:22.425398 31205 slave.cpp:2369] Status update manager
> successfully handled status update TASK_RUNNING (UUID:
> 10174aa0-0e5a-4f9d-a530-dee64e93f222) for task 0 of framework
> 20141028-234822-3193029443-50043-31190-0000
> I1028 23:48:22.425420 31205 slave.cpp:2375] Sending acknowledgement for
> status update TASK_RUNNING (UUID: 10174aa0-0e5a-4f9d-a530-dee64e93f222) for
> task 0 of framework 20141028-234822-3193029443-50043-31190-0000 to
> executor(22)@67.195.81.190:50043
> I1028 23:48:22.425583 31212 master.cpp:3410] Forwarding status update
> TASK_RUNNING (UUID: 10174aa0-0e5a-4f9d-a530-dee64e93f222) for task 0 of
> framework 20141028-234822-3193029443-50043-31190-0000
> I1028 23:48:22.425621 31206 exec.cpp:339] Executor received status update
> acknowledgement 10174aa0-0e5a-4f9d-a530-dee64e93f222 for task 0 of framework
> 20141028-234822-3193029443-50043-31190-0000
> I1028 23:48:22.425786 31212 master.cpp:3382] Status update TASK_RUNNING
> (UUID: 10174aa0-0e5a-4f9d-a530-dee64e93f222) for task 0 of framework
> 20141028-234822-3193029443-50043-31190-0000 from slave
> 20141028-234822-3193029443-50043-31190-S0 at slave(34)@67.195.81.190:50043
> (pietas.apache.org)
> I1028 23:48:22.425832 31212 master.cpp:4617] Updating the latest state of
> task 0 of framework 20141028-234822-3193029443-50043-31190-0000 to
> TASK_RUNNING
> I1028 23:48:22.425885 31208 sched.cpp:635] Scheduler::statusUpdate took
> 49727ns
> I1028 23:48:22.426082 31208 master.cpp:2882] Forwarding status update
> acknowledgement 10174aa0-0e5a-4f9d-a530-dee64e93f222 for task 0 of framework
> 20141028-234822-3193029443-50043-31190-0000 (default) at
> [email protected]:50043 to slave
> 20141028-234822-3193029443-50043-31190-S0 at slave(34)@67.195.81.190:50043
> (pietas.apache.org)
> I1028 23:48:22.426360 31206 status_update_manager.cpp:389] Received status
> update acknowledgement (UUID: 10174aa0-0e5a-4f9d-a530-dee64e93f222) for task
> 0 of framework 20141028-234822-3193029443-50043-31190-0000
> I1028 23:48:22.426623 31206 slave.cpp:1789] Status update manager
> successfully handled status update acknowledgement (UUID:
> 10174aa0-0e5a-4f9d-a530-dee64e93f222) for task 0 of framework
> 20141028-234822-3193029443-50043-31190-0000
> I1028 23:48:22.426893 31210 master.cpp:677] Master terminating
> W1028 23:48:22.427028 31210 master.cpp:4662] Removing task 0 with resources
> cpus(*):1; mem(*):500 of framework
> 20141028-234822-3193029443-50043-31190-0000 on slave
> 20141028-234822-3193029443-50043-31190-S0 at slave(34)@67.195.81.190:50043
> (pietas.apache.org) in non-terminal state TASK_RUNNING
> I1028 23:48:22.427397 31209 hierarchical_allocator_process.hpp:563] Recovered
> cpus(*):1; mem(*):500 (total allocatable: cpus(*):2; mem(*):1024;
> disk(*):3.70122e+06; ports(*):[31000-32000]) on slave
> 20141028-234822-3193029443-50043-31190-S0 from framework
> 20141028-234822-3193029443-50043-31190-0000
> I1028 23:48:22.427512 31210 master.cpp:4705] Removing executor 'default' with
> resources of framework 20141028-234822-3193029443-50043-31190-0000 on slave
> 20141028-234822-3193029443-50043-31190-S0 at slave(34)@67.195.81.190:50043
> (pietas.apache.org)
> I1028 23:48:22.428129 31206 slave.cpp:2607] [email protected]:50043 exited
> W1028 23:48:22.428153 31206 slave.cpp:2610] Master disconnected! Waiting for
> a new master to be elected
> I1028 23:48:22.434645 31190 leveldb.cpp:176] Opened db in 2.551453ms
> I1028 23:48:22.437157 31190 leveldb.cpp:183] Compacted db in 2.484612ms
> I1028 23:48:22.437203 31190 leveldb.cpp:198] Created db iterator in 19171ns
> I1028 23:48:22.437235 31190 leveldb.cpp:204] Seeked to beginning of db in
> 18300ns
> I1028 23:48:22.437306 31190 leveldb.cpp:273] Iterated through 3 keys in the
> db in 59465ns
> I1028 23:48:22.437347 31190 replica.cpp:741] Replica recovered with log
> positions 3 -> 4 with 0 holes and 0 unlearned
> I1028 23:48:22.437827 31216 recover.cpp:437] Starting replica recovery
> I1028 23:48:22.438127 31216 recover.cpp:463] Replica is in VOTING status
> I1028 23:48:22.438443 31216 recover.cpp:452] Recover process terminated
> I1028 23:48:22.439877 31212 master.cpp:312] Master
> 20141028-234822-3193029443-50043-31190 (pietas.apache.org) started on
> 67.195.81.190:50043
> I1028 23:48:22.439916 31212 master.cpp:358] Master only allowing
> authenticated frameworks to register
> I1028 23:48:22.439931 31212 master.cpp:363] Master only allowing
> authenticated slaves to register
> I1028 23:48:22.439946 31212 credentials.hpp:36] Loading credentials for
> authentication from
> '/tmp/AllocatorTest_0_SlaveReregistersFirst_YPe61d/credentials'
> I1028 23:48:22.440142 31212 master.cpp:392] Authorization enabled
> I1028 23:48:22.440439 31218 master.cpp:120] No whitelist given. Advertising
> offers for all slaves
> I1028 23:48:22.440901 31213 hierarchical_allocator_process.hpp:299]
> Initializing hierarchical allocator process with master :
> [email protected]:50043
> I1028 23:48:22.441395 31206 master.cpp:1242] The newly elected leader is
> [email protected]:50043 with id 20141028-234822-3193029443-50043-31190
> I1028 23:48:22.441421 31206 master.cpp:1255] Elected as the leading master!
> I1028 23:48:22.441457 31206 master.cpp:1073] Recovering from registrar
> I1028 23:48:22.441623 31205 registrar.cpp:313] Recovering registrar
> I1028 23:48:22.442172 31219 log.cpp:656] Attempting to start the writer
> I1028 23:48:22.443235 31219 replica.cpp:474] Replica received implicit
> promise request with proposal 2
> I1028 23:48:22.443685 31219 leveldb.cpp:306] Persisting metadata (8 bytes) to
> leveldb took 427888ns
> I1028 23:48:22.443703 31219 replica.cpp:342] Persisted promised to 2
> I1028 23:48:22.444371 31213 coordinator.cpp:230] Coordinator attemping to
> fill missing position
> I1028 23:48:22.444687 31209 log.cpp:672] Writer started with ending position 4
> I1028 23:48:22.445754 31215 leveldb.cpp:438] Reading position from leveldb
> took 47909ns
> I1028 23:48:22.445826 31215 leveldb.cpp:438] Reading position from leveldb
> took 30611ns
> I1028 23:48:22.446941 31218 registrar.cpp:346] Successfully fetched the
> registry (277B) in 5.213184ms
> I1028 23:48:22.447118 31218 registrar.cpp:445] Applied 1 operations in
> 42362ns; attempting to update the 'registry'
> I1028 23:48:22.449329 31204 log.cpp:680] Attempting to append 316 bytes to
> the log
> I1028 23:48:22.449477 31218 coordinator.cpp:340] Coordinator attempting to
> write APPEND action at position 5
> I1028 23:48:22.450187 31215 replica.cpp:508] Replica received write request
> for position 5
> I1028 23:48:22.450767 31215 leveldb.cpp:343] Persisting action (335 bytes) to
> leveldb took 554400ns
> I1028 23:48:22.450788 31215 replica.cpp:676] Persisted action at 5
> I1028 23:48:22.451561 31215 replica.cpp:655] Replica received learned notice
> for position 5
> I1028 23:48:22.451979 31215 leveldb.cpp:343] Persisting action (337 bytes) to
> leveldb took 397219ns
> I1028 23:48:22.452000 31215 replica.cpp:676] Persisted action at 5
> I1028 23:48:22.452020 31215 replica.cpp:661] Replica learned APPEND action at
> position 5
> I1028 23:48:22.452993 31213 registrar.cpp:490] Successfully updated the
> 'registry' in 5.816832ms
> I1028 23:48:22.453136 31213 registrar.cpp:376] Successfully recovered
> registrar
> I1028 23:48:22.453238 31208 log.cpp:699] Attempting to truncate the log to 5
> I1028 23:48:22.453384 31214 coordinator.cpp:340] Coordinator attempting to
> write TRUNCATE action at position 6
> I1028 23:48:22.453518 31215 master.cpp:1100] Recovered 1 slaves from the
> Registry (277B) ; allowing 10mins for slaves to re-register
> I1028 23:48:22.454116 31207 replica.cpp:508] Replica received write request
> for position 6
> I1028 23:48:22.454570 31207 leveldb.cpp:343] Persisting action (16 bytes) to
> leveldb took 427424ns
> I1028 23:48:22.454589 31207 replica.cpp:676] Persisted action at 6
> I1028 23:48:22.455095 31219 replica.cpp:655] Replica received learned notice
> for position 6
> I1028 23:48:22.455399 31219 leveldb.cpp:343] Persisting action (18 bytes) to
> leveldb took 282466ns
> I1028 23:48:22.455462 31219 leveldb.cpp:401] Deleting ~2 keys from leveldb
> took 43939ns
> I1028 23:48:22.455478 31219 replica.cpp:676] Persisted action at 6
> I1028 23:48:22.455494 31219 replica.cpp:661] Replica learned TRUNCATE action
> at position 6
> I1028 23:48:22.465553 31213 status_update_manager.cpp:171] Pausing sending
> status updates
> I1028 23:48:22.465566 31216 slave.cpp:602] New master detected at
> [email protected]:50043
> I1028 23:48:22.465612 31216 slave.cpp:665] Authenticating with master
> [email protected]:50043
> I1028 23:48:23.441506 31206 hierarchical_allocator_process.hpp:697] No
> resources available to allocate!
> I1028 23:48:27.441004 31214 master.cpp:120] No whitelist given. Advertising
> offers for all slaves
> I1028 23:48:30.101379 31206 hierarchical_allocator_process.hpp:659] Performed
> allocation for 0 slaves in 6.659877806secs
> I1028 23:48:30.101568 31216 slave.cpp:638] Detecting new master
> I1028 23:48:30.101632 31214 authenticatee.hpp:133] Creating new client SASL
> connection
> I1028 23:48:30.102021 31218 master.cpp:3853] Authenticating
> slave(34)@67.195.81.190:50043
> I1028 23:48:30.102329 31212 authenticator.hpp:161] Creating new server SASL
> connection
> I1028 23:48:30.102505 31216 authenticatee.hpp:224] Received SASL
> authentication mechanisms: CRAM-MD5
> I1028 23:48:30.102545 31216 authenticatee.hpp:250] Attempting to authenticate
> with mechanism 'CRAM-MD5'
> I1028 23:48:30.102638 31216 authenticator.hpp:267] Received SASL
> authentication start
> I1028 23:48:30.102709 31216 authenticator.hpp:389] Authentication requires
> more steps
> I1028 23:48:30.102812 31216 authenticatee.hpp:270] Received SASL
> authentication step
> I1028 23:48:30.102957 31204 authenticator.hpp:295] Received SASL
> authentication step
> I1028 23:48:30.102982 31204 auxprop.cpp:81] Request to lookup properties for
> user: 'test-principal' realm: 'pietas.apache.org' server FQDN:
> 'pietas.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
> SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
> I1028 23:48:30.102993 31204 auxprop.cpp:153] Looking up auxiliary property
> '*userPassword'
> I1028 23:48:30.103032 31204 auxprop.cpp:153] Looking up auxiliary property
> '*cmusaslsecretCRAM-MD5'
> I1028 23:48:30.103049 31204 auxprop.cpp:81] Request to lookup properties for
> user: 'test-principal' realm: 'pietas.apache.org' server FQDN:
> 'pietas.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
> SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
> I1028 23:48:30.103056 31204 auxprop.cpp:103] Skipping auxiliary property
> '*userPassword' since SASL_AUXPROP_AUTHZID == true
> I1028 23:48:30.103061 31204 auxprop.cpp:103] Skipping auxiliary property
> '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
> I1028 23:48:30.103073 31204 authenticator.hpp:381] Authentication success
> I1028 23:48:30.103149 31209 authenticatee.hpp:310] Authentication success
> I1028 23:48:30.103153 31204 master.cpp:3893] Successfully authenticated
> principal 'test-principal' at slave(34)@67.195.81.190:50043
> I1028 23:48:30.103371 31209 slave.cpp:722] Successfully authenticated with
> master [email protected]:50043
> I1028 23:48:30.103773 31209 slave.cpp:1050] Will retry registration in
> 12.861518ms if necessary
> I1028 23:48:30.104068 31219 master.cpp:3210] Re-registering slave
> 20141028-234822-3193029443-50043-31190-S0 at slave(34)@67.195.81.190:50043
> (pietas.apache.org)
> I1028 23:48:30.104760 31216 registrar.cpp:445] Applied 1 operations in
> 71655ns; attempting to update the 'registry'
> I1028 23:48:30.107877 31205 log.cpp:680] Attempting to append 316 bytes to
> the log
> I1028 23:48:30.108070 31219 coordinator.cpp:340] Coordinator attempting to
> write APPEND action at position 7
> I1028 23:48:30.109110 31211 replica.cpp:508] Replica received write request
> for position 7
> I1028 23:48:30.109434 31211 leveldb.cpp:343] Persisting action (335 bytes) to
> leveldb took 281545ns
> I1028 23:48:30.109484 31211 replica.cpp:676] Persisted action at 7
> I1028 23:48:30.110124 31219 replica.cpp:655] Replica received learned notice
> for position 7
> I1028 23:48:30.110903 31219 leveldb.cpp:343] Persisting action (337 bytes) to
> leveldb took 750414ns
> I1028 23:48:30.110927 31219 replica.cpp:676] Persisted action at 7
> I1028 23:48:30.110950 31219 replica.cpp:661] Replica learned APPEND action at
> position 7
> I1028 23:48:30.112160 31205 registrar.cpp:490] Successfully updated the
> 'registry' in 7.33824ms
> I1028 23:48:30.112529 31217 log.cpp:699] Attempting to truncate the log to 7
> I1028 23:48:30.112714 31207 coordinator.cpp:340] Coordinator attempting to
> write TRUNCATE action at position 8
> I1028 23:48:30.112870 31210 master.hpp:877] Adding task 0 with resources
> cpus(*):1; mem(*):500 on slave 20141028-234822-3193029443-50043-31190-S0
> (pietas.apache.org)
> W1028 23:48:30.113136 31210 master.cpp:4394] Possibly orphaned task 0 of
> framework 20141028-234822-3193029443-50043-31190-0000 running on slave
> 20141028-234822-3193029443-50043-31190-S0 at slave(34)@67.195.81.190:50043
> (pietas.apache.org)
> I1028 23:48:30.113198 31219 slave.cpp:2522] Received ping from
> slave-observer(39)@67.195.81.190:50043
> I1028 23:48:30.113340 31210 master.cpp:3278] Re-registered slave
> 20141028-234822-3193029443-50043-31190-S0 at slave(34)@67.195.81.190:50043
> (pietas.apache.org) with cpus(*):2; mem(*):1024; disk(*):3.70122e+06;
> ports(*):[31000-32000]
> I1028 23:48:30.113499 31219 slave.cpp:824] Re-registered with master
> [email protected]:50043
> I1028 23:48:30.113636 31219 replica.cpp:508] Replica received write request
> for position 8
> I1028 23:48:30.113652 31210 status_update_manager.cpp:178] Resuming sending
> status updates
> I1028 23:48:30.113759 31212 hierarchical_allocator_process.hpp:442] Added
> slave 20141028-234822-3193029443-50043-31190-S0 (pietas.apache.org) with
> cpus(*):2; mem(*):1024; disk(*):3.70122e+06; ports(*):[31000-32000] (and
> cpus(*):1; mem(*):524; disk(*):3.70122e+06; ports(*):[31000-32000] available)
> I1028 23:48:30.113904 31212 hierarchical_allocator_process.hpp:679] Performed
> allocation for slave 20141028-234822-3193029443-50043-31190-S0 in 74698ns
> I1028 23:48:30.114116 31219 leveldb.cpp:343] Persisting action (16 bytes) to
> leveldb took 452165ns
> I1028 23:48:30.114142 31219 replica.cpp:676] Persisted action at 8
> I1028 23:48:30.114786 31213 replica.cpp:655] Replica received learned notice
> for position 8
> I1028 23:48:30.115337 31213 leveldb.cpp:343] Persisting action (18 bytes) to
> leveldb took 525187ns
> I1028 23:48:30.115399 31213 leveldb.cpp:401] Deleting ~2 keys from leveldb
> took 37689ns
> I1028 23:48:30.115418 31213 replica.cpp:676] Persisted action at 8
> I1028 23:48:30.115484 31213 replica.cpp:661] Replica learned TRUNCATE action
> at position 8
> I1028 23:48:30.116603 31212 sched.cpp:227] Scheduler::disconnected took
> 16969ns
> I1028 23:48:30.116624 31212 sched.cpp:233] New master detected at
> [email protected]:50043
> I1028 23:48:30.116657 31212 sched.cpp:283] Authenticating with master
> [email protected]:50043
> I1028 23:48:30.116870 31205 authenticatee.hpp:133] Creating new client SASL
> connection
> I1028 23:48:30.117084 31207 master.cpp:3853] Authenticating
> [email protected]:50043
> I1028 23:48:30.117279 31212 authenticator.hpp:161] Creating new server SASL
> connection
> I1028 23:48:30.117410 31210 authenticatee.hpp:224] Received SASL
> authentication mechanisms: CRAM-MD5
> I1028 23:48:30.117507 31210 authenticatee.hpp:250] Attempting to authenticate
> with mechanism 'CRAM-MD5'
> I1028 23:48:30.117604 31214 authenticator.hpp:267] Received SASL
> authentication start
> I1028 23:48:30.117652 31214 authenticator.hpp:389] Authentication requires
> more steps
> I1028 23:48:30.117738 31210 authenticatee.hpp:270] Received SASL
> authentication step
> I1028 23:48:30.117905 31208 authenticator.hpp:295] Received SASL
> authentication step
> I1028 23:48:30.117935 31208 auxprop.cpp:81] Request to lookup properties for
> user: 'test-principal' realm: 'pietas.apache.org' server FQDN:
> 'pietas.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
> SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
> I1028 23:48:30.117947 31208 auxprop.cpp:153] Looking up auxiliary property
> '*userPassword'
> I1028 23:48:30.117979 31208 auxprop.cpp:153] Looking up auxiliary property
> '*cmusaslsecretCRAM-MD5'
> I1028 23:48:30.118001 31208 auxprop.cpp:81] Request to lookup properties for
> user: 'test-principal' realm: 'pietas.apache.org' server FQDN:
> 'pietas.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false
> SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
> I../../src/tests/allocator_tests.cpp:2405: Failure
> 1028 23:48:30.118013 31208 auxprop.cpp:103] Skipping auxiliary property
> '*userPassword' since SASL_AUXPROP_AUTHZID == true
> Failed to wait 10secs for resourceOffers2
> I1028 23:48:31.101976 31212 hierarchical_allocator_process.hpp:659] Performed
> allocation for 1 slaves in 124354ns
> I1028 23:48:58.775811 31208 auxprop.cpp:103] Skipping auxiliary property
> '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
> W1028 23:48:35.117725 31214 sched.cpp:378] Authentication timed out
> W1028 23:48:35.117784 31219 master.cpp:3911] Authentication timed out
> I1028 23:48:45.114322 31213 slave.cpp:2522] Received ping from
> slave-observer(39)@67.195.81.190:50043
> I1028 23:48:35.102212 31206 master.cpp:120] No whitelist given. Advertising
> offers for all slaves
> I1028 23:48:58.775874 31208 authenticator.hpp:381] Authentication success
> I1028 23:48:58.776267 31214 sched.cpp:338] Failed to authenticate with master
> [email protected]:50043: Authentication discarded
> ../../src/tests/allocator_tests.cpp:2396: Failure
> Actual function call count doesn't match EXPECT_CALL(allocator2,
> frameworkAdded(_, _, _))...
> Expected: to be called once
> Actual: never called - unsatisfied and active
> I1028 23:48:58.776526 31204 master.cpp:3893] Successfully authenticated
> principal 'test-principal' at
> [email protected]:50043
> I1028 23:48:58.776626 31214 sched.cpp:283] Authenticating with master
> [email protected]:50043
> I1028 23:48:58.776928 31204 authenticatee.hpp:133] Creating new client SASL
> connection
> I1028 23:48:58.777194 31210 master.cpp:3853] Authenticating
> [email protected]:50043
> W1028 23:48:58.777528 31210 master.cpp:3888] Failed to authenticate
> [email protected]:50043: Failed to
> communicate with authenticatee
> ../../src/tests/allocator_tests.cpp:2399: Failure
> Actual function call count doesn't match EXPECT_CALL(sched,
> resourceOffers(&driver, _))...
> Expected: to be called once
> Actual: never called - unsatisfied and active
> ../../src/tests/allocator_tests.cpp:2394: Failure
> Actual function call count doesn't match EXPECT_CALL(sched,
> registered(&driver, _, _))...
> Expected: to be called once
> Actual: never called - unsatisfied and active
> I1028 23:48:58.778053 31205 slave.cpp:591] Re-detecting master
> I1028 23:48:58.778084 31205 slave.cpp:638] Detecting new master
> I1028 23:48:58.778115 31207 status_update_manager.cpp:171] Pausing sending
> status updates
> F1028 23:48:58.778115 31205 logging.cpp:57] RAW: Pure virtual method called
> I1028 23:48:58.778724 31210 master.cpp:677] Master terminating
> W1028 23:48:58.778919 31210 master.cpp:4662] Removing task 0 with resources
> cpus(*):1; mem(*):500 of framework
> 20141028-234822-3193029443-50043-31190-0000 on slave
> 20141028-234822-3193029443-50043-31190-S0 at slave(34)@67.195.81.190:50043
> (pietas.apache.org) in non-terminal state TASK_RUNNING
> *** Aborted at 1414540138 (unix time) try "date -d @1414540138" if you are
> using GNU date ***
> PC: @ 0x91bc86 process::PID<>::PID()
> *** SIGSEGV (@0x0) received by PID 31190 (TID 0x2b20a6d95700) from PID 0;
> stack trace: ***
> @ 0x2b20a41ff340 (unknown)
> @ 0x2b20a1f2a188 google::LogMessage::Fail()
> @ 0x2b20a1f2f87c google::RawLog__()
> @ 0x91bc86 process::PID<>::PID()
> @ 0x91bf24 process::Process<>::self()
> @ 0x2b20a15d5c06 __cxa_pure_virtual
> @ 0x2b20a1877752 mesos::internal::slave::Slave::detected()
> @ 0x2b20a1671f24 process::dispatch<>()
> @ 0x2b20a18b35f9
> _ZZN7process8dispatchIN5mesos8internal5slave5SlaveERKNS_6FutureI6OptionINS1_10MasterInfoEEEES9_EEvRKNS_3PIDIT_EEMSD_FvT0_ET1_ENKUlPNS_11ProcessBaseEE_clESM_
> @ 0x2b20a1663217
> mesos::internal::master::allocator::Allocator::resourcesRecovered()
> @ 0x2b20a1650d01 mesos::internal::master::Master::removeTask()
> @ 0x2b20a162fb41 mesos::internal::master::Master::finalize()
> @ 0x2b20a1eb69a1 process::ProcessBase::visit()
> @ 0x2b20a1ec0464 process::TerminateEvent::visit()
> @ 0x8e0812 process::ProcessBase::serve()
> @ 0x2b20a18da89e
> _ZNSt17_Function_handlerIFvPN7process11ProcessBaseEEZNS0_8dispatchIN5mesos8internal5slave5SlaveERKNS0_6FutureI6OptionINS5_10MasterInfoEEEESD_EEvRKNS0_3PIDIT_EEMSH_FvT0_ET1_EUlS2_E_E9_M_invokeERKSt9_Any_dataS2_
> @ 0x2b20a1eb1ca0 process::ProcessManager::resume()
> @ 0x2b20a1ea8365 process::schedule()
> @ 0x2b20a41f7182 start_thread
> @ 0x2b20a4507fbd (unknown)
> make[3]: *** [check-local] Segmentation fault
> {noformat}
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
