You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@mesos.apache.org by "Benjamin Mahler (JIRA)" <ji...@apache.org> on 2015/02/11 01:43:13 UTC
[jira] [Updated] (MESOS-2331)
MasterSlaveReconciliationTest.ReconcileRace is flaky
[ https://issues.apache.org/jira/browse/MESOS-2331?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Benjamin Mahler updated MESOS-2331:
-----------------------------------
Labels: flaky (was: )
> 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
> 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)