You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@mesos.apache.org by "Marco Massenzio (JIRA)" <ji...@apache.org> on 2015/10/17 02:25:05 UTC
[jira] [Commented] (MESOS-2331)
MasterSlaveReconciliationTest.ReconcileRace is flaky
[ https://issues.apache.org/jira/browse/MESOS-2331?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=14961575#comment-14961575 ]
Marco Massenzio commented on MESOS-2331:
----------------------------------------
Can you please report also what OS, distro, etc. you were using for this test?
Also, why is it considered "flaky"? did it pass some times and failed others?
Not contesting that this may be flaky, but just trying to understand why it wasn't noticed before and how to repro steps.
Thanks!
> MasterSlaveReconciliationTest.ReconcileRace is flaky
> ----------------------------------------------------
>
> Key: MESOS-2331
> URL: https://issues.apache.org/jira/browse/MESOS-2331
> Project: Mesos
> Issue Type: Bug
> Components: test
> Affects Versions: 0.22.0
> Reporter: Yan Xu
> Assignee: Qian Zhang
> Labels: flaky
>
> {noformat:title=}
> [ RUN ] MasterSlaveReconciliationTest.ReconcileRace
> Using temporary directory '/tmp/MasterSlaveReconciliationTest_ReconcileRace_NE9nhV'
> I0206 19:09:44.196542 32362 leveldb.cpp:175] Opened db in 38.230192ms
> I0206 19:09:44.206826 32362 leveldb.cpp:182] Compacted db in 9.988493ms
> I0206 19:09:44.207164 32362 leveldb.cpp:197] Created db iterator in 29979ns
> I0206 19:09:44.207641 32362 leveldb.cpp:203] Seeked to beginning of db in 4478ns
> I0206 19:09:44.207929 32362 leveldb.cpp:272] Iterated through 0 keys in the db in 737ns
> I0206 19:09:44.208222 32362 replica.cpp:743] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
> I0206 19:09:44.209132 32384 recover.cpp:448] Starting replica recovery
> I0206 19:09:44.209524 32384 recover.cpp:474] Replica is in EMPTY status
> I0206 19:09:44.211094 32384 replica.cpp:640] Replica in EMPTY status received a broadcasted recover request
> I0206 19:09:44.211385 32384 recover.cpp:194] Received a recover response from a replica in EMPTY status
> I0206 19:09:44.211902 32384 recover.cpp:565] Updating replica status to STARTING
> I0206 19:09:44.236177 32381 master.cpp:344] Master 20150206-190944-16842879-36452-32362 (lucid) started on 127.0.1.1:36452
> I0206 19:09:44.236291 32381 master.cpp:390] Master only allowing authenticated frameworks to register
> I0206 19:09:44.236305 32381 master.cpp:395] Master only allowing authenticated slaves to register
> I0206 19:09:44.236327 32381 credentials.hpp:35] Loading credentials for authentication from '/tmp/MasterSlaveReconciliationTest_ReconcileRace_NE9nhV/credentials'
> I0206 19:09:44.236601 32381 master.cpp:439] Authorization enabled
> I0206 19:09:44.238539 32381 hierarchical_allocator_process.hpp:284] Initialized hierarchical allocator process
> I0206 19:09:44.238662 32381 whitelist_watcher.cpp:64] No whitelist given
> I0206 19:09:44.239364 32381 master.cpp:1350] The newly elected leader is master@127.0.1.1:36452 with id 20150206-190944-16842879-36452-32362
> I0206 19:09:44.239392 32381 master.cpp:1363] Elected as the leading master!
> I0206 19:09:44.239413 32381 master.cpp:1181] Recovering from registrar
> I0206 19:09:44.239645 32381 registrar.cpp:312] Recovering registrar
> I0206 19:09:44.241142 32384 leveldb.cpp:305] Persisting metadata (8 bytes) to leveldb took 29.029117ms
> I0206 19:09:44.241189 32384 replica.cpp:322] Persisted replica status to STARTING
> I0206 19:09:44.241478 32384 recover.cpp:474] Replica is in STARTING status
> I0206 19:09:44.243075 32384 replica.cpp:640] Replica in STARTING status received a broadcasted recover request
> I0206 19:09:44.243398 32384 recover.cpp:194] Received a recover response from a replica in STARTING status
> I0206 19:09:44.243964 32384 recover.cpp:565] Updating replica status to VOTING
> I0206 19:09:44.255692 32384 leveldb.cpp:305] Persisting metadata (8 bytes) to leveldb took 11.502759ms
> I0206 19:09:44.255765 32384 replica.cpp:322] Persisted replica status to VOTING
> I0206 19:09:44.256009 32384 recover.cpp:579] Successfully joined the Paxos group
> I0206 19:09:44.256253 32384 recover.cpp:463] Recover process terminated
> I0206 19:09:44.257669 32384 log.cpp:659] Attempting to start the writer
> I0206 19:09:44.259944 32377 replica.cpp:476] Replica received implicit promise request with proposal 1
> I0206 19:09:44.268805 32377 leveldb.cpp:305] Persisting metadata (8 bytes) to leveldb took 8.45858ms
> I0206 19:09:44.269067 32377 replica.cpp:344] Persisted promised to 1
> I0206 19:09:44.277974 32383 coordinator.cpp:229] Coordinator attemping to fill missing position
> I0206 19:09:44.279767 32383 replica.cpp:377] Replica received explicit promise request for position 0 with proposal 2
> I0206 19:09:44.288940 32383 leveldb.cpp:342] Persisting action (8 bytes) to leveldb took 9.128603ms
> I0206 19:09:44.289294 32383 replica.cpp:678] Persisted action at 0
> I0206 19:09:44.296417 32377 replica.cpp:510] Replica received write request for position 0
> I0206 19:09:44.296944 32377 leveldb.cpp:437] Reading position from leveldb took 48457ns
> I0206 19:09:44.305337 32377 leveldb.cpp:342] Persisting action (14 bytes) to leveldb took 8.141689ms
> I0206 19:09:44.305662 32377 replica.cpp:678] Persisted action at 0
> I0206 19:09:44.318168 32378 replica.cpp:657] Replica received learned notice for position 0
> I0206 19:09:44.326036 32378 leveldb.cpp:342] Persisting action (16 bytes) to leveldb took 6.910907ms
> I0206 19:09:44.326654 32378 replica.cpp:678] Persisted action at 0
> I0206 19:09:44.326942 32378 replica.cpp:663] Replica learned NOP action at position 0
> I0206 19:09:44.338552 32377 log.cpp:675] Writer started with ending position 0
> I0206 19:09:44.340262 32377 leveldb.cpp:437] Reading position from leveldb took 58420ns
> I0206 19:09:44.342963 32377 registrar.cpp:345] Successfully fetched the registry (0B) in 103.275776ms
> I0206 19:09:44.343070 32377 registrar.cpp:444] Applied 1 operations in 26702ns; attempting to update the 'registry'
> I0206 19:09:44.345824 32377 log.cpp:683] Attempting to append 118 bytes to the log
> I0206 19:09:44.346019 32377 coordinator.cpp:339] Coordinator attempting to write APPEND action at position 1
> I0206 19:09:44.347017 32382 replica.cpp:510] Replica received write request for position 1
> I0206 19:09:44.354070 32382 leveldb.cpp:342] Persisting action (135 bytes) to leveldb took 7.011319ms
> I0206 19:09:44.354118 32382 replica.cpp:678] Persisted action at 1
> I0206 19:09:44.355094 32382 replica.cpp:657] Replica received learned notice for position 1
> I0206 19:09:44.358392 32382 leveldb.cpp:342] Persisting action (137 bytes) to leveldb took 3.267785ms
> I0206 19:09:44.358621 32382 replica.cpp:678] Persisted action at 1
> I0206 19:09:44.358949 32382 replica.cpp:663] Replica learned APPEND action at position 1
> I0206 19:09:44.367099 32382 registrar.cpp:489] Successfully updated the 'registry' in 23.9488ms
> I0206 19:09:44.367259 32382 registrar.cpp:375] Successfully recovered registrar
> I0206 19:09:44.367698 32382 master.cpp:1208] Recovered 0 slaves from the Registry (82B) ; allowing 10mins for slaves to re-register
> I0206 19:09:44.367790 32382 log.cpp:702] Attempting to truncate the log to 1
> I0206 19:09:44.368067 32382 coordinator.cpp:339] Coordinator attempting to write TRUNCATE action at position 2
> I0206 19:09:44.369544 32381 replica.cpp:510] Replica received write request for position 2
> I0206 19:09:44.378540 32381 leveldb.cpp:342] Persisting action (16 bytes) to leveldb took 8.940568ms
> I0206 19:09:44.378811 32381 replica.cpp:678] Persisted action at 2
> I0206 19:09:44.387471 32377 replica.cpp:657] Replica received learned notice for position 2
> I0206 19:09:44.394693 32377 leveldb.cpp:342] Persisting action (18 bytes) to leveldb took 6.892787ms
> I0206 19:09:44.394815 32377 leveldb.cpp:400] Deleting ~1 keys from leveldb took 57353ns
> I0206 19:09:44.394840 32377 replica.cpp:678] Persisted action at 2
> I0206 19:09:44.394875 32377 replica.cpp:663] Replica learned TRUNCATE action at position 2
> I0206 19:09:44.423720 32380 slave.cpp:172] Slave started on 14)@127.0.1.1:36452
> I0206 19:09:44.426247 32380 credentials.hpp:83] Loading credential for authentication from '/tmp/MasterSlaveReconciliationTest_ReconcileRace_nT15cx/credential'
> I0206 19:09:44.426745 32380 slave.cpp:281] Slave using credential for: test-principal
> I0206 19:09:44.427234 32380 slave.cpp:299] Slave resources: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]
> I0206 19:09:44.427616 32380 slave.cpp:328] Slave hostname: lucid
> I0206 19:09:44.427829 32380 slave.cpp:329] Slave checkpoint: false
> W0206 19:09:44.428047 32380 slave.cpp:331] Disabling checkpointing is deprecated and the --checkpoint flag will be removed in a future release. Please avoid using this flag
> I0206 19:09:44.429821 32379 state.cpp:32] Recovering state from '/tmp/MasterSlaveReconciliationTest_ReconcileRace_nT15cx/meta'
> I0206 19:09:44.438045 32380 status_update_manager.cpp:196] Recovering status update manager
> I0206 19:09:44.438377 32380 slave.cpp:3526] Finished recovery
> I0206 19:09:44.439144 32380 slave.cpp:620] New master detected at master@127.0.1.1:36452
> I0206 19:09:44.439275 32380 slave.cpp:683] Authenticating with master master@127.0.1.1:36452
> I0206 19:09:44.439297 32380 slave.cpp:688] Using default CRAM-MD5 authenticatee
> I0206 19:09:44.439472 32380 slave.cpp:656] Detecting new master
> I0206 19:09:44.439589 32380 status_update_manager.cpp:170] Pausing sending status updates
> I0206 19:09:44.439757 32380 authenticatee.hpp:137] Creating new client SASL connection
> I0206 19:09:44.440255 32380 master.cpp:3786] Authenticating slave(14)@127.0.1.1:36452
> I0206 19:09:44.440287 32380 master.cpp:3797] Using default CRAM-MD5 authenticator
> I0206 19:09:44.440712 32380 authenticator.hpp:169] Creating new server SASL connection
> I0206 19:09:44.441010 32380 authenticatee.hpp:228] Received SASL authentication mechanisms: CRAM-MD5
> I0206 19:09:44.441036 32380 authenticatee.hpp:254] Attempting to authenticate with mechanism 'CRAM-MD5'
> I0206 19:09:44.441136 32380 authenticator.hpp:275] Received SASL authentication start
> I0206 19:09:44.441216 32380 authenticator.hpp:397] Authentication requires more steps
> I0206 19:09:44.441303 32380 authenticatee.hpp:274] Received SASL authentication step
> I0206 19:09:44.441395 32380 authenticator.hpp:303] Received SASL authentication step
> I0206 19:09:44.441431 32380 auxprop.cpp:98] Request to lookup properties for user: 'test-principal' realm: 'lucid' server FQDN: 'lucid' SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
> I0206 19:09:44.441442 32380 auxprop.cpp:170] Looking up auxiliary property '*userPassword'
> I0206 19:09:44.441493 32380 auxprop.cpp:170] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
> I0206 19:09:44.441526 32380 auxprop.cpp:98] Request to lookup properties for user: 'test-principal' realm: 'lucid' server FQDN: 'lucid' SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
> I0206 19:09:44.441540 32380 auxprop.cpp:120] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
> I0206 19:09:44.441546 32380 auxprop.cpp:120] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
> I0206 19:09:44.441561 32380 authenticator.hpp:389] Authentication success
> I0206 19:09:44.441668 32380 authenticatee.hpp:314] Authentication success
> I0206 19:09:44.441756 32380 master.cpp:3844] Successfully authenticated principal 'test-principal' at slave(14)@127.0.1.1:36452
> I0206 19:09:44.442070 32380 slave.cpp:754] Successfully authenticated with master master@127.0.1.1:36452
> I0206 19:09:44.442211 32380 slave.cpp:1082] Will retry registration in 19.488037ms if necessary
> I0206 19:09:44.442474 32380 master.cpp:2911] Registering slave at slave(14)@127.0.1.1:36452 (lucid) with id 20150206-190944-16842879-36452-32362-S0
> I0206 19:09:44.442922 32380 registrar.cpp:444] Applied 1 operations in 72989ns; attempting to update the 'registry'
> I0206 19:09:44.445914 32380 log.cpp:683] Attempting to append 283 bytes to the log
> I0206 19:09:44.446125 32380 coordinator.cpp:339] Coordinator attempting to write APPEND action at position 3
> I0206 19:09:44.448060 32384 replica.cpp:510] Replica received write request for position 3
> I0206 19:09:44.450963 32384 leveldb.cpp:342] Persisting action (302 bytes) to leveldb took 2.859704ms
> I0206 19:09:44.451252 32384 replica.cpp:678] Persisted action at 3
> I0206 19:09:44.452453 32382 replica.cpp:657] Replica received learned notice for position 3
> I0206 19:09:44.463752 32382 leveldb.cpp:342] Persisting action (304 bytes) to leveldb took 11.254934ms
> I0206 19:09:44.463817 32382 replica.cpp:678] Persisted action at 3
> I0206 19:09:44.463848 32382 replica.cpp:663] Replica learned APPEND action at position 3
> I0206 19:09:44.465450 32382 registrar.cpp:489] Successfully updated the 'registry' in 22.45888ms
> I0206 19:09:44.465725 32382 log.cpp:702] Attempting to truncate the log to 3
> I0206 19:09:44.466614 32379 coordinator.cpp:339] Coordinator attempting to write TRUNCATE action at position 4
> I0206 19:09:44.466958 32379 slave.cpp:1082] Will retry registration in 34.738916ms if necessary
> I0206 19:09:44.467807 32379 replica.cpp:510] Replica received write request for position 4
> I0206 19:09:44.469007 32381 slave.cpp:2595] Received ping from slave-observer(14)@127.0.1.1:36452
> I0206 19:09:44.469740 32377 hierarchical_allocator_process.hpp:450] Added slave 20150206-190944-16842879-36452-32362-S0 (lucid) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] (and cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] available)
> I0206 19:09:44.469871 32377 hierarchical_allocator_process.hpp:828] No resources available to allocate!
> I0206 19:09:44.469892 32377 hierarchical_allocator_process.hpp:753] Performed allocation for slave 20150206-190944-16842879-36452-32362-S0 in 107661ns
> I0206 19:09:44.470643 32378 slave.cpp:788] Registered with master master@127.0.1.1:36452; given slave ID 20150206-190944-16842879-36452-32362-S0
> I0206 19:09:44.473881 32383 status_update_manager.cpp:177] Resuming sending status updates
> I0206 19:09:44.476253 32379 leveldb.cpp:342] Persisting action (16 bytes) to leveldb took 8.4136ms
> I0206 19:09:44.476297 32379 replica.cpp:678] Persisted action at 4
> I0206 19:09:44.488441 32382 master.cpp:2968] Registered slave 20150206-190944-16842879-36452-32362-S0 at slave(14)@127.0.1.1:36452 (lucid) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]
> I0206 19:09:44.489220 32382 master.cpp:2887] Slave 20150206-190944-16842879-36452-32362-S0 at slave(14)@127.0.1.1:36452 (lucid) already registered, resending acknowledgement
> I0206 19:09:44.490684 32379 replica.cpp:657] Replica received learned notice for position 4
> I0206 19:09:44.491462 32362 sched.cpp:149] Version: 0.22.0
> I0206 19:09:44.494812 32378 slave.cpp:620] New master detected at master@127.0.1.1:36452
> I0206 19:09:44.494870 32378 slave.cpp:683] Authenticating with master master@127.0.1.1:36452
> I0206 19:09:44.494889 32378 slave.cpp:688] Using default CRAM-MD5 authenticatee
> I0206 19:09:44.495014 32378 slave.cpp:656] Detecting new master
> I0206 19:09:44.495160 32378 sched.cpp:246] New master detected at master@127.0.1.1:36452
> I0206 19:09:44.495232 32378 sched.cpp:302] Authenticating with master master@127.0.1.1:36452
> I0206 19:09:44.495252 32378 sched.cpp:309] Using default CRAM-MD5 authenticatee
> I0206 19:09:44.495458 32378 status_update_manager.cpp:170] Pausing sending status updates
> I0206 19:09:44.495589 32378 authenticatee.hpp:137] Creating new client SASL connection
> I0206 19:09:44.495846 32378 authenticatee.hpp:137] Creating new client SASL connection
> I0206 19:09:44.498770 32382 master.cpp:3786] Authenticating slave(14)@127.0.1.1:36452
> I0206 19:09:44.498812 32382 master.cpp:3797] Using default CRAM-MD5 authenticator
> I0206 19:09:44.499124 32382 master.cpp:3786] Authenticating scheduler-167ce2f8-8268-41f7-9c72-a4e29dc3316c@127.0.1.1:36452
> I0206 19:09:44.499151 32382 master.cpp:3797] Using default CRAM-MD5 authenticator
> I0206 19:09:44.499363 32382 slave.cpp:788] Registered with master master@127.0.1.1:36452; given slave ID 20150206-190944-16842879-36452-32362-S0
> I0206 19:09:44.499675 32382 authenticator.hpp:169] Creating new server SASL connection
> I0206 19:09:44.499925 32382 authenticator.hpp:169] Creating new server SASL connection
> I0206 19:09:44.500035 32382 status_update_manager.cpp:177] Resuming sending status updates
> I0206 19:09:44.500330 32382 authenticatee.hpp:228] Received SASL authentication mechanisms: CRAM-MD5
> I0206 19:09:44.500356 32382 authenticatee.hpp:254] Attempting to authenticate with mechanism 'CRAM-MD5'
> I0206 19:09:44.500501 32382 authenticatee.hpp:228] Received SASL authentication mechanisms: CRAM-MD5
> I0206 19:09:44.500526 32382 authenticatee.hpp:254] Attempting to authenticate with mechanism 'CRAM-MD5'
> I0206 19:09:44.500691 32382 authenticator.hpp:275] Received SASL authentication start
> I0206 19:09:44.500758 32382 authenticator.hpp:397] Authentication requires more steps
> I0206 19:09:44.500836 32382 authenticator.hpp:275] Received SASL authentication start
> I0206 19:09:44.500874 32382 authenticator.hpp:397] Authentication requires more steps
> I0206 19:09:44.500943 32382 authenticatee.hpp:274] Received SASL authentication step
> I0206 19:09:44.501026 32382 authenticatee.hpp:274] Received SASL authentication step
> I0206 19:09:44.501104 32382 authenticator.hpp:303] Received SASL authentication step
> I0206 19:09:44.501130 32382 auxprop.cpp:98] Request to lookup properties for user: 'test-principal' realm: 'lucid' server FQDN: 'lucid' SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
> I0206 19:09:44.501142 32382 auxprop.cpp:170] Looking up auxiliary property '*userPassword'
> I0206 19:09:44.501188 32382 auxprop.cpp:170] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
> I0206 19:09:44.501212 32382 auxprop.cpp:98] Request to lookup properties for user: 'test-principal' realm: 'lucid' server FQDN: 'lucid' SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
> I0206 19:09:44.501224 32382 auxprop.cpp:120] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
> I0206 19:09:44.501230 32382 auxprop.cpp:120] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
> I0206 19:09:44.501245 32382 authenticator.hpp:389] Authentication success
> I0206 19:09:44.501368 32382 authenticator.hpp:303] Received SASL authentication step
> I0206 19:09:44.501394 32382 auxprop.cpp:98] Request to lookup properties for user: 'test-principal' realm: 'lucid' server FQDN: 'lucid' SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
> I0206 19:09:44.501405 32382 auxprop.cpp:170] Looking up auxiliary property '*userPassword'
> I0206 19:09:44.501435 32382 auxprop.cpp:170] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
> I0206 19:09:44.501458 32382 auxprop.cpp:98] Request to lookup properties for user: 'test-principal' realm: 'lucid' server FQDN: 'lucid' SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
> I0206 19:09:44.501469 32382 auxprop.cpp:120] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
> I0206 19:09:44.501477 32382 auxprop.cpp:120] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
> I0206 19:09:44.501489 32382 authenticator.hpp:389] Authentication success
> I0206 19:09:44.501582 32382 authenticatee.hpp:314] Authentication success
> I0206 19:09:44.501672 32382 master.cpp:3844] Successfully authenticated principal 'test-principal' at slave(14)@127.0.1.1:36452
> I0206 19:09:44.501898 32382 master.cpp:3844] Successfully authenticated principal 'test-principal' at scheduler-167ce2f8-8268-41f7-9c72-a4e29dc3316c@127.0.1.1:36452
> I0206 19:09:44.502104 32382 authenticatee.hpp:314] Authentication success
> I0206 19:09:44.502272 32382 slave.cpp:754] Successfully authenticated with master master@127.0.1.1:36452
> I0206 19:09:44.502421 32382 sched.cpp:390] Successfully authenticated with master master@127.0.1.1:36452
> I0206 19:09:44.502447 32382 sched.cpp:513] Sending registration request to master@127.0.1.1:36452
> I0206 19:09:44.502512 32382 sched.cpp:546] Will retry registration in 1.990458655secs if necessary
> I0206 19:09:44.502679 32382 master.cpp:1568] Received registration request for framework 'default' at scheduler-167ce2f8-8268-41f7-9c72-a4e29dc3316c@127.0.1.1:36452
> I0206 19:09:44.502760 32382 master.cpp:1429] Authorizing framework principal 'test-principal' to receive offers for role '*'
> I0206 19:09:44.503207 32379 leveldb.cpp:342] Persisting action (18 bytes) to leveldb took 12.488335ms
> I0206 19:09:44.503340 32379 leveldb.cpp:400] Deleting ~2 keys from leveldb took 95587ns
> I0206 19:09:44.503365 32379 replica.cpp:678] Persisted action at 4
> I0206 19:09:44.503394 32379 replica.cpp:663] Replica learned TRUNCATE action at position 4
> I0206 19:09:44.504719 32382 master.cpp:1632] Registering framework 20150206-190944-16842879-36452-32362-0000 (default) at scheduler-167ce2f8-8268-41f7-9c72-a4e29dc3316c@127.0.1.1:36452
> I0206 19:09:44.505327 32380 hierarchical_allocator_process.hpp:318] Added framework 20150206-190944-16842879-36452-32362-0000
> I0206 19:09:44.505712 32380 hierarchical_allocator_process.hpp:735] Performed allocation for 1 slaves in 353338ns
> I0206 19:09:44.517038 32382 master.cpp:3728] Sending 1 offers to framework 20150206-190944-16842879-36452-32362-0000 (default) at scheduler-167ce2f8-8268-41f7-9c72-a4e29dc3316c@127.0.1.1:36452
> I0206 19:09:44.517523 32382 sched.cpp:440] Framework registered with 20150206-190944-16842879-36452-32362-0000
> I0206 19:09:44.517575 32382 sched.cpp:454] Scheduler::registered took 26978ns
> I0206 19:09:44.517899 32382 sched.cpp:603] Scheduler::resourceOffers took 48926ns
> I0206 19:09:45.246789 32381 hierarchical_allocator_process.hpp:828] No resources available to allocate!
> I0206 19:09:45.246841 32381 hierarchical_allocator_process.hpp:735] Performed allocation for 1 slaves in 239355ns
> I0206 19:09:46.257019 32383 hierarchical_allocator_process.hpp:828] No resources available to allocate!
> I0206 19:09:46.257325 32383 hierarchical_allocator_process.hpp:735] Performed allocation for 1 slaves in 642985ns
> I0206 19:09:47.259109 32382 hierarchical_allocator_process.hpp:828] No resources available to allocate!
> I0206 19:09:47.259160 32382 hierarchical_allocator_process.hpp:735] Performed allocation for 1 slaves in 247172ns
> I0206 19:09:48.267207 32378 hierarchical_allocator_process.hpp:828] No resources available to allocate!
> I0206 19:09:48.267590 32378 hierarchical_allocator_process.hpp:735] Performed allocation for 1 slaves in 737879ns
> I0206 19:09:49.276871 32379 hierarchical_allocator_process.hpp:828] No resources available to allocate!
> I0206 19:09:49.276924 32379 hierarchical_allocator_process.hpp:735] Performed allocation for 1 slaves in 243974ns
> I0206 19:09:50.287142 32382 hierarchical_allocator_process.hpp:828] No resources available to allocate!
> I0206 19:09:50.287504 32382 hierarchical_allocator_process.hpp:735] Performed allocation for 1 slaves in 784304ns
> I0206 19:09:51.296839 32379 hierarchical_allocator_process.hpp:828] No resources available to allocate!
> I0206 19:09:51.296893 32379 hierarchical_allocator_process.hpp:735] Performed allocation for 1 slaves in 244814ns
> I0206 19:09:52.297719 32378 hierarchical_allocator_process.hpp:828] No resources available to allocate!
> I0206 19:09:52.299626 32378 hierarchical_allocator_process.hpp:735] Performed allocation for 1 slaves in 2.277105ms
> I0206 19:09:53.306870 32384 hierarchical_allocator_process.hpp:828] No resources available to allocate!
> I0206 19:09:53.306924 32384 hierarchical_allocator_process.hpp:735] Performed allocation for 1 slaves in 262416ns
> I0206 19:09:54.317059 32382 hierarchical_allocator_process.hpp:828] No resources available to allocate!
> I0206 19:09:54.320051 32382 hierarchical_allocator_process.hpp:735] Performed allocation for 1 slaves in 3.270301ms
> I0206 19:09:55.326977 32379 hierarchical_allocator_process.hpp:828] No resources available to allocate!
> I0206 19:09:55.330344 32379 hierarchical_allocator_process.hpp:735] Performed allocation for 1 slaves in 3.569401ms
> I0206 19:09:56.339260 32381 hierarchical_allocator_process.hpp:828] No resources available to allocate!
> I0206 19:09:56.343905 32381 hierarchical_allocator_process.hpp:735] Performed allocation for 1 slaves in 5.144928ms
> I0206 19:09:57.346943 32377 hierarchical_allocator_process.hpp:828] No resources available to allocate!
> I0206 19:09:57.347012 32377 hierarchical_allocator_process.hpp:735] Performed allocation for 1 slaves in 326655ns
> I0206 19:09:58.348335 32380 hierarchical_allocator_process.hpp:828] No resources available to allocate!
> I0206 19:09:58.351338 32380 hierarchical_allocator_process.hpp:735] Performed allocation for 1 slaves in 3.622285ms
> I0206 19:09:59.356886 32383 hierarchical_allocator_process.hpp:828] No resources available to allocate!
> I0206 19:09:59.356941 32383 hierarchical_allocator_process.hpp:735] Performed allocation for 1 slaves in 271092ns
> I0206 19:09:59.477521 32381 slave.cpp:2595] Received ping from slave-observer(14)@127.0.1.1:36452
> tests/master_slave_reconciliation_tests.cpp:283: Failure
> Failed to wait 15secs for reregisterSlaveMessage
> I0206 19:09:59.510076 32377 master.cpp:872] Framework 20150206-190944-16842879-36452-32362-0000 (default) at scheduler-167ce2f8-8268-41f7-9c72-a4e29dc3316c@127.0.1.1:36452 disconnected
> I0206 19:09:59.510154 32377 master.cpp:1937] Disconnecting framework 20150206-190944-16842879-36452-32362-0000 (default) at scheduler-167ce2f8-8268-41f7-9c72-a4e29dc3316c@127.0.1.1:36452
> I0206 19:09:59.510216 32377 master.cpp:1953] Deactivating framework 20150206-190944-16842879-36452-32362-0000 (default) at scheduler-167ce2f8-8268-41f7-9c72-a4e29dc3316c@127.0.1.1:36452
> I0206 19:09:59.511065 32377 master.cpp:894] Giving framework 20150206-190944-16842879-36452-32362-0000 (default) at scheduler-167ce2f8-8268-41f7-9c72-a4e29dc3316c@127.0.1.1:36452 0ns to failover
> I0206 19:09:59.512804 32383 hierarchical_allocator_process.hpp:397] Deactivated framework 20150206-190944-16842879-36452-32362-0000
> I0206 19:09:59.512990 32383 hierarchical_allocator_process.hpp:642] Recovered cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] (total allocatable: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]) on slave 20150206-190944-16842879-36452-32362-S0 from framework 20150206-190944-16842879-36452-32362-0000
> I0206 19:09:59.513653 32382 slave.cpp:609] Re-detecting master
> I0206 19:09:59.513687 32382 slave.cpp:656] Detecting new master
> *** Aborted at 1423278599 (unix time) try "date -d @1423278599" if you are using GNU date ***
> I0206 19:09:59.514680 32380 status_update_manager.cpp:170] Pausing sending status updates
> I0206 19:09:59.516027 32379 master.cpp:781] Master terminating
> PC: @ 0x2b2b91358b79 mesos::slave::Slave::detected()
> *** SIGSEGV (@0x10) received by PID 32362 (TID 0x2b2b98dad700) from PID 16; stack trace: ***
> @ 0x2b2b9b6ff3b4 os::Linux::chained_handler()
> @ 0x2b2b9b70459a JVM_handle_linux_signal
> @ 0x2b2b8f0a98f0 (unknown)
> @ 0x2b2b91358b79 mesos::slave::Slave::detected()
> @ 0x2b2b913d31b4 std::tr1::_Mem_fn<>::operator()()
> @ 0x2b2b913cd54f _ZNSt3tr15_BindIFNS_7_Mem_fnIMN5mesos5slave5SlaveEFvRKN7process6FutureI6OptionINS2_10MasterInfoEEEEEEENS_12_PlaceholderILi1EEESA_EE6__callIIRPS4_EILi0ELi1EEEENS_9result_ofIFSF_NSN_IFNS_3_MuISH_Lb0ELb1EEESH_NS_5tupleIIDpT_EEEEE4typeENSN_IFNSO_ISA_Lb0ELb0EEESA_ST_EE4typeEEE4typeERKST_NS_12_Index_tupleIIXspT0_EEEE
> @ 0x2b2b913c3216 std::tr1::_Bind<>::operator()<>()
> @ 0x2b2b913b6a7e std::tr1::_Function_handler<>::_M_invoke()
> @ 0x7f6b9a std::tr1::function<>::operator()()
> @ 0x7e765c process::internal::vdispatcher<>()
> @ 0x80e823 _ZNSt3tr15_BindIFPFvPN7process11ProcessBaseENS_10shared_ptrINS_8functionIFvPN5mesos5slave5SlaveEEEEEEENS_12_PlaceholderILi1EEESC_EE6__callIIRS3_EILi0ELi1EEEENS_9result_ofIFSE_NSL_IFNS_3_MuISG_Lb0ELb1EEESG_NS_5tupleIIDpT_EEEEE4typeENSL_IFNSM_ISC_Lb0ELb0EEESC_SR_EE4typeEEE4typeERKSR_NS_12_Index_tupleIIXspT0_EEEE
> @ 0x803b6c std::tr1::_Bind<>::operator()<>()
> @ 0x7f6c86 std::tr1::_Function_handler<>::_M_invoke()
> @ 0x2b2b91a25714 std::tr1::function<>::operator()()
> @ 0x2b2b91a0ae4f process::ProcessBase::visit()
> @ 0x2b2b91a0f3a0 process::DispatchEvent::visit()
> @ 0x8a56f2 process::ProcessBase::serve()
> @ 0x2b2b91a06fc2 process::ProcessManager::resume()
> @ 0x2b2b919fabfc process::schedule()
> @ 0x2b2b8f0a09ca start_thread
> @ 0x2b2b94ab745d (unknown)
> make[3]: *** [check-local] Segmentation fault
> {noformat}
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)