You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@mesos.apache.org by "Adam B (JIRA)" <ji...@apache.org> on 2014/05/06 21:15:16 UTC
[jira] [Commented] (MESOS-1310) Queuing up slave (re-)registration
during authentication causes reply() to fail
[ https://issues.apache.org/jira/browse/MESOS-1310?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13991009#comment-13991009 ]
Adam B commented on MESOS-1310:
-------------------------------
Duly noted. I'll look into this today/tomorrow.
> Queuing up slave (re-)registration during authentication causes reply() to fail
> -------------------------------------------------------------------------------
>
> Key: MESOS-1310
> URL: https://issues.apache.org/jira/browse/MESOS-1310
> Project: Mesos
> Issue Type: Bug
> Affects Versions: 0.19.0
> Reporter: Vinod Kone
> Assignee: Adam B
> Priority: Critical
> Fix For: 0.19.0
>
>
> When slave authentication is enabled, a (re-)registration could be queued if authentication is in progress. This causes registerSlave/reregisterSlave methods to be enqueued via a defer.
> This means when registerSlave/reregisterSlave is eventually executed the 'from' field of the base ProtobufProcess might not be set. But the these methods call 'reply()' which expects 'from' to be set crashing the master.
> Fix: Instead of calling reply(), do an explicit 'send(from, message)' where 'from' is the argument passed to the function.
> Example flaky test
> {code}
> [ RUN ] FaultToleranceTest.ReconcileLostTasks
> I0506 00:00:37.996906 30661 leveldb.cpp:174] Opened db in 1.867592ms
> I0506 00:00:37.998474 30661 leveldb.cpp:181] Compacted db in 861564ns
> I0506 00:00:37.998494 30661 leveldb.cpp:196] Created db iterator in 8506ns
> I0506 00:00:37.998502 30661 leveldb.cpp:202] Seeked to beginning of db in 4323ns
> I0506 00:00:37.998509 30661 leveldb.cpp:271] Iterated through 0 keys in the db in 3865ns
> I0506 00:00:37.998524 30661 replica.cpp:741] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned
> I0506 00:00:37.999277 30683 recover.cpp:425] Starting replica recovery
> I0506 00:00:37.999354 30683 recover.cpp:451] Replica is in EMPTY status
> I0506 00:00:37.999789 30683 replica.cpp:638] Replica in EMPTY status received a broadcasted recover request
> I0506 00:00:37.999850 30683 recover.cpp:188] Received a recover response from a replica in EMPTY status
> I0506 00:00:37.999953 30683 recover.cpp:542] Updating replica status to STARTING
> I0506 00:00:38.000051 30683 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 47190ns
> I0506 00:00:38.000064 30683 replica.cpp:320] Persisted replica status to STARTING
> I0506 00:00:38.000118 30683 recover.cpp:451] Replica is in STARTING status
> I0506 00:00:38.000393 30683 replica.cpp:638] Replica in STARTING status received a broadcasted recover request
> I0506 00:00:38.000448 30683 recover.cpp:188] Received a recover response from a replica in STARTING status
> I0506 00:00:38.000540 30683 recover.cpp:542] Updating replica status to VOTING
> I0506 00:00:38.000601 30683 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 23411ns
> I0506 00:00:38.000613 30683 replica.cpp:320] Persisted replica status to VOTING
> I0506 00:00:38.000643 30683 recover.cpp:556] Successfully joined the Paxos group
> I0506 00:00:38.000687 30683 recover.cpp:440] Recover process terminated
> I0506 00:00:38.003407 30685 master.cpp:267] Master 20140506-000038-2256185536-45784-30661 (fedora-19) started on 192.168.122.134:45784
> I0506 00:00:38.003443 30685 master.cpp:304] Master only allowing authenticated frameworks to register
> I0506 00:00:38.003449 30685 master.cpp:309] Master only allowing authenticated slaves to register
> I0506 00:00:38.003455 30685 credentials.hpp:35] Loading credentials for authentication
> W0506 00:00:38.003515 30685 credentials.hpp:48] Failed to stat credentials file 'file:///tmp/FaultToleranceTest_ReconcileLostTasks_XNdyPU/credentials': No such file or directory
> I0506 00:00:38.003880 30685 hierarchical_allocator_process.hpp:301] Initializing hierarchical allocator process with master : master@192.168.122.134:45784
> I0506 00:00:38.003916 30685 master.cpp:104] No whitelist given. Advertising offers for all slaves
> I0506 00:00:38.004066 30685 master.cpp:921] The newly elected leader is master@192.168.122.134:45784 with id 20140506-000038-2256185536-45784-30661
> I0506 00:00:38.004081 30685 master.cpp:931] Elected as the leading master!
> I0506 00:00:38.004086 30685 master.cpp:752] Recovering from registrar
> I0506 00:00:38.004133 30685 registrar.cpp:313] Recovering registrar
> I0506 00:00:38.004382 30685 log.cpp:656] Attempting to start the writer
> I0506 00:00:38.004660 30685 replica.cpp:474] Replica received implicit promise request with proposal 1
> I0506 00:00:38.004694 30685 leveldb.cpp:304] Persisting metadata (8 bytes) to leveldb took 24302ns
> I0506 00:00:38.004704 30685 replica.cpp:342] Persisted promised to 1
> I0506 00:00:38.004850 30685 coordinator.cpp:230] Coordinator attemping to fill missing position
> I0506 00:00:38.005123 30685 replica.cpp:375] Replica received explicit promise request for position 0 with proposal 2
> I0506 00:00:38.005707 30685 leveldb.cpp:341] Persisting action (8 bytes) to leveldb took 548301ns
> I0506 00:00:38.005723 30685 replica.cpp:676] Persisted action at 0
> I0506 00:00:38.005955 30685 replica.cpp:508] Replica received write request for position 0
> I0506 00:00:38.005983 30685 leveldb.cpp:436] Reading position from leveldb took 18774ns
> I0506 00:00:38.006010 30685 leveldb.cpp:341] Persisting action (14 bytes) to leveldb took 17914ns
> I0506 00:00:38.006018 30685 replica.cpp:676] Persisted action at 0
> I0506 00:00:38.006134 30685 replica.cpp:655] Replica received learned notice for position 0
> I0506 00:00:38.006193 30685 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 23998ns
> I0506 00:00:38.006206 30685 replica.cpp:676] Persisted action at 0
> I0506 00:00:38.006211 30685 replica.cpp:661] Replica learned NOP action at position 0
> I0506 00:00:38.006381 30685 log.cpp:672] Writer started with ending position 0
> I0506 00:00:38.006594 30685 leveldb.cpp:436] Reading position from leveldb took 19599ns
> I0506 00:00:38.013350 30680 registrar.cpp:346] Successfully fetched the registry (0B)
> I0506 00:00:38.013383 30680 registrar.cpp:422] Attempting to update the 'registry'
> I0506 00:00:38.015118 30685 log.cpp:680] Attempting to append 131 bytes to the log
> I0506 00:00:38.016417 30685 coordinator.cpp:340] Coordinator attempting to write APPEND action at position 1
> I0506 00:00:38.017129 30685 replica.cpp:508] Replica received write request for position 1
> I0506 00:00:38.017204 30685 leveldb.cpp:341] Persisting action (150 bytes) to leveldb took 38285ns
> I0506 00:00:38.017217 30685 replica.cpp:676] Persisted action at 1
> I0506 00:00:38.017370 30685 replica.cpp:655] Replica received learned notice for position 1
> I0506 00:00:38.017401 30685 leveldb.cpp:341] Persisting action (152 bytes) to leveldb took 22383ns
> I0506 00:00:38.017411 30685 replica.cpp:676] Persisted action at 1
> I0506 00:00:38.017418 30685 replica.cpp:661] Replica learned APPEND action at position 1
> I0506 00:00:38.021289 30682 registrar.cpp:479] Successfully updated 'registry'
> I0506 00:00:38.021328 30682 registrar.cpp:372] Successfully recovered registrar
> I0506 00:00:38.021389 30682 master.cpp:779] Recovered 0 slaves from the Registry (95B) ; allowing 10mins for slaves to re-register
> I0506 00:00:38.023375 30680 log.cpp:699] Attempting to truncate the log to 1
> I0506 00:00:38.023776 30686 coordinator.cpp:340] Coordinator attempting to write TRUNCATE action at position 2
> I0506 00:00:38.024025 30686 replica.cpp:508] Replica received write request for position 2
> I0506 00:00:38.024063 30686 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 28844ns
> I0506 00:00:38.024075 30686 replica.cpp:676] Persisted action at 2
> I0506 00:00:38.024327 30681 replica.cpp:655] Replica received learned notice for position 2
> I0506 00:00:38.024359 30681 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 22694ns
> I0506 00:00:38.024375 30681 leveldb.cpp:399] Deleting ~1 keys from leveldb took 10826ns
> I0506 00:00:38.024384 30681 replica.cpp:676] Persisted action at 2
> I0506 00:00:38.024391 30681 replica.cpp:661] Replica learned TRUNCATE action at position 2
> I0506 00:00:38.026319 30661 mesos_containerizer.cpp:122] Using isolation: posix/cpu,posix/mem
> I0506 00:00:38.027962 30680 slave.cpp:140] Slave started on 143)@192.168.122.134:45784
> I0506 00:00:38.027987 30680 credentials.hpp:35] Loading credentials for authentication
> W0506 00:00:38.028131 30680 credentials.hpp:48] Failed to stat credentials file 'file:///tmp/FaultToleranceTest_ReconcileLostTasks_S5cKrh/credential': No such file or directory
> I0506 00:00:38.028201 30680 slave.cpp:230] Slave using credential for: test-principal
> I0506 00:00:38.028282 30680 slave.cpp:243] Slave resources: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]
> I0506 00:00:38.028599 30680 slave.cpp:271] Slave hostname: fedora-19
> I0506 00:00:38.028610 30680 slave.cpp:272] Slave checkpoint: false
> I0506 00:00:38.030406 30681 state.cpp:33] Recovering state from '/tmp/FaultToleranceTest_ReconcileLostTasks_S5cKrh/meta'
> I0506 00:00:38.033030 30686 status_update_manager.cpp:193] Recovering status update manager
> I0506 00:00:38.033130 30683 mesos_containerizer.cpp:279] Recovering containerizer
> I0506 00:00:38.033810 30680 slave.cpp:2945] Finished recovery
> I0506 00:00:38.034116 30680 slave.cpp:526] New master detected at master@192.168.122.134:45784
> I0506 00:00:38.035115 30683 status_update_manager.cpp:167] New master detected at master@192.168.122.134:45784
> I0506 00:00:38.035684 30680 slave.cpp:586] Authenticating with master master@192.168.122.134:45784
> I0506 00:00:38.036331 30683 authenticatee.hpp:128] Creating new client SASL connection
> I0506 00:00:38.036705 30683 master.cpp:2798] Authenticating slave(143)@192.168.122.134:45784
> I0506 00:00:38.036876 30683 authenticator.hpp:148] Creating new server SASL connection
> I0506 00:00:38.037279 30683 authenticatee.hpp:219] Received SASL authentication mechanisms: CRAM-MD5
> I0506 00:00:38.037303 30683 authenticatee.hpp:245] Attempting to authenticate with mechanism 'CRAM-MD5'
> I0506 00:00:38.037327 30683 authenticator.hpp:254] Received SASL authentication start
> I0506 00:00:38.037364 30683 authenticator.hpp:342] Authentication requires more steps
> I0506 00:00:38.037389 30683 authenticatee.hpp:265] Received SASL authentication step
> I0506 00:00:38.037421 30683 authenticator.hpp:282] Received SASL authentication step
> I0506 00:00:38.037437 30683 auxprop.cpp:81] Request to lookup properties for user: 'test-principal' realm: 'fedora-19' server FQDN: 'fedora-19' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
> I0506 00:00:38.037446 30683 auxprop.cpp:153] Looking up auxiliary property '*userPassword'
> I0506 00:00:38.037457 30683 auxprop.cpp:153] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
> I0506 00:00:38.037467 30683 auxprop.cpp:81] Request to lookup properties for user: 'test-principal' realm: 'fedora-19' server FQDN: 'fedora-19' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
> I0506 00:00:38.037472 30683 auxprop.cpp:103] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
> I0506 00:00:38.037477 30683 auxprop.cpp:103] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
> I0506 00:00:38.037487 30683 authenticator.hpp:334] Authentication success
> I0506 00:00:38.037513 30683 authenticatee.hpp:305] Authentication success
> I0506 00:00:38.037528 30683 master.cpp:2838] Successfully authenticated slave(143)@192.168.122.134:45784
> I0506 00:00:38.037966 30680 slave.cpp:559] Detecting new master
> I0506 00:00:38.038729 30680 slave.cpp:643] Successfully authenticated with master master@192.168.122.134:45784
> I0506 00:00:38.038772 30680 slave.cpp:872] Will retry registration in 6.326818904secs if necessary
> I0506 00:00:38.038833 30680 master.cpp:2134] Registering slave at slave(143)@192.168.122.134:45784 (fedora-19) with id 20140506-000038-2256185536-45784-30661-0
> I0506 00:00:38.038921 30680 registrar.cpp:422] Attempting to update the 'registry'
> I0506 00:00:38.042039 30683 log.cpp:680] Attempting to append 312 bytes to the log
> I0506 00:00:38.042093 30683 coordinator.cpp:340] Coordinator attempting to write APPEND action at position 3
> I0506 00:00:38.042331 30686 replica.cpp:508] Replica received write request for position 3
> I0506 00:00:38.042383 30686 leveldb.cpp:341] Persisting action (331 bytes) to leveldb took 40155ns
> I0506 00:00:38.042395 30686 replica.cpp:676] Persisted action at 3
> I0506 00:00:38.042597 30683 replica.cpp:655] Replica received learned notice for position 3
> I0506 00:00:38.042629 30683 leveldb.cpp:341] Persisting action (333 bytes) to leveldb took 23754ns
> I0506 00:00:38.042640 30683 replica.cpp:676] Persisted action at 3
> I0506 00:00:38.042647 30683 replica.cpp:661] Replica learned APPEND action at position 3
> I0506 00:00:38.042809 30683 log.cpp:699] Attempting to truncate the log to 3
> I0506 00:00:38.042843 30683 coordinator.cpp:340] Coordinator attempting to write TRUNCATE action at position 4
> I0506 00:00:38.042984 30683 replica.cpp:508] Replica received write request for position 4
> I0506 00:00:38.043015 30683 leveldb.cpp:341] Persisting action (16 bytes) to leveldb took 21501ns
> I0506 00:00:38.043025 30683 replica.cpp:676] Persisted action at 4
> I0506 00:00:38.043196 30686 replica.cpp:655] Replica received learned notice for position 4
> I0506 00:00:38.043228 30686 leveldb.cpp:341] Persisting action (18 bytes) to leveldb took 21966ns
> I0506 00:00:38.043246 30686 leveldb.cpp:399] Deleting ~2 keys from leveldb took 13546ns
> I0506 00:00:38.043256 30686 replica.cpp:676] Persisted action at 4
> I0506 00:00:38.043262 30686 replica.cpp:661] Replica learned TRUNCATE action at position 4
> I0506 00:00:38.048326 30680 registrar.cpp:479] Successfully updated 'registry'
> I0506 00:00:38.048410 30680 master.cpp:2174] Registered slave 20140506-000038-2256185536-45784-30661-0 at slave(143)@192.168.122.134:45784 (fedora-19)
> I0506 00:00:38.048426 30680 master.cpp:3283] Adding slave 20140506-000038-2256185536-45784-30661-0 at slave(143)@192.168.122.134:45784 (fedora-19) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]
> I0506 00:00:38.048517 30680 slave.cpp:676] Registered with master master@192.168.122.134:45784; given slave ID 20140506-000038-2256185536-45784-30661-0
> I0506 00:00:38.048575 30680 hierarchical_allocator_process.hpp:444] Added slave 20140506-000038-2256185536-45784-30661-0 (fedora-19) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] (and cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] available)
> I0506 00:00:38.048612 30680 hierarchical_allocator_process.hpp:707] Performed allocation for slave 20140506-000038-2256185536-45784-30661-0 in 15797ns
> I0506 00:00:38.049540 30661 sched.cpp:121] Version: 0.19.0
> I0506 00:00:38.050317 30680 sched.cpp:217] New master detected at master@192.168.122.134:45784
> I0506 00:00:38.050340 30680 sched.cpp:268] Authenticating with master master@192.168.122.134:45784
> I0506 00:00:38.050978 30679 authenticatee.hpp:128] Creating new client SASL connection
> I0506 00:00:38.051373 30679 master.cpp:2798] Authenticating scheduler(124)@192.168.122.134:45784
> I0506 00:00:38.051473 30679 authenticator.hpp:148] Creating new server SASL connection
> I0506 00:00:38.052317 30679 authenticatee.hpp:219] Received SASL authentication mechanisms: CRAM-MD5
> I0506 00:00:38.052341 30679 authenticatee.hpp:245] Attempting to authenticate with mechanism 'CRAM-MD5'
> I0506 00:00:38.052364 30679 authenticator.hpp:254] Received SASL authentication start
> I0506 00:00:38.052398 30679 authenticator.hpp:342] Authentication requires more steps
> I0506 00:00:38.052423 30679 authenticatee.hpp:265] Received SASL authentication step
> I0506 00:00:38.052455 30679 authenticator.hpp:282] Received SASL authentication step
> I0506 00:00:38.052470 30679 auxprop.cpp:81] Request to lookup properties for user: 'test-principal' realm: 'fedora-19' server FQDN: 'fedora-19' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
> I0506 00:00:38.052479 30679 auxprop.cpp:153] Looking up auxiliary property '*userPassword'
> I0506 00:00:38.052489 30679 auxprop.cpp:153] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
> I0506 00:00:38.052497 30679 auxprop.cpp:81] Request to lookup properties for user: 'test-principal' realm: 'fedora-19' server FQDN: 'fedora-19' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
> I0506 00:00:38.052503 30679 auxprop.cpp:103] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
> I0506 00:00:38.052508 30679 auxprop.cpp:103] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
> I0506 00:00:38.052520 30679 authenticator.hpp:334] Authentication success
> I0506 00:00:38.052543 30679 authenticatee.hpp:305] Authentication success
> I0506 00:00:38.052561 30679 master.cpp:2838] Successfully authenticated scheduler(124)@192.168.122.134:45784
> I0506 00:00:38.053640 30680 sched.cpp:342] Successfully authenticated with master master@192.168.122.134:45784
> I0506 00:00:38.053660 30680 sched.cpp:461] Sending registration request to master@192.168.122.134:45784
> I0506 00:00:38.053717 30680 master.cpp:980] Received registration request from scheduler(124)@192.168.122.134:45784
> I0506 00:00:38.053741 30680 master.cpp:998] Registering framework 20140506-000038-2256185536-45784-30661-0000 at scheduler(124)@192.168.122.134:45784
> I0506 00:00:38.053791 30680 sched.cpp:392] Framework registered with 20140506-000038-2256185536-45784-30661-0000
> I0506 00:00:38.053812 30680 sched.cpp:406] Scheduler::registered took 14043ns
> I0506 00:00:38.053840 30680 hierarchical_allocator_process.hpp:331] Added framework 20140506-000038-2256185536-45784-30661-0000
> I0506 00:00:38.053872 30680 hierarchical_allocator_process.hpp:751] Offering cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20140506-000038-2256185536-45784-30661-0 to framework 20140506-000038-2256185536-45784-30661-0000
> I0506 00:00:38.053954 30680 hierarchical_allocator_process.hpp:687] Performed allocation for 1 slaves in 110496ns
> I0506 00:00:38.053999 30680 master.hpp:612] Adding offer 20140506-000038-2256185536-45784-30661-0 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20140506-000038-2256185536-45784-30661-0 (fedora-19)
> I0506 00:00:38.054035 30680 master.cpp:2747] Sending 1 offers to framework 20140506-000038-2256185536-45784-30661-0000
> I0506 00:00:38.054118 30680 sched.cpp:529] Scheduler::resourceOffers took 23160ns
> I0506 00:00:38.055182 30680 master.hpp:622] Removing offer 20140506-000038-2256185536-45784-30661-0 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20140506-000038-2256185536-45784-30661-0 (fedora-19)
> I0506 00:00:38.056296 30680 master.cpp:1812] Processing reply for offers: [ 20140506-000038-2256185536-45784-30661-0 ] on slave 20140506-000038-2256185536-45784-30661-0 at slave(143)@192.168.122.134:45784 (fedora-19) for framework 20140506-000038-2256185536-45784-30661-0000
> I0506 00:00:38.056910 30680 master.hpp:584] Adding task 1 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20140506-000038-2256185536-45784-30661-0 (fedora-19)
> I0506 00:00:38.056957 30680 master.cpp:2922] Launching task 1 of framework 20140506-000038-2256185536-45784-30661-0000 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20140506-000038-2256185536-45784-30661-0 at slave(143)@192.168.122.134:45784 (fedora-19)
> I0506 00:00:38.058881 30686 slave.cpp:526] New master detected at master@192.168.122.134:45784
> I0506 00:00:38.058910 30686 slave.cpp:586] Authenticating with master master@192.168.122.134:45784
> I0506 00:00:38.058951 30686 slave.cpp:559] Detecting new master
> I0506 00:00:38.058990 30686 status_update_manager.cpp:167] New master detected at master@192.168.122.134:45784
> I0506 00:00:38.059016 30686 authenticatee.hpp:128] Creating new client SASL connection
> I0506 00:00:38.060091 30680 master.cpp:1262] Disconnecting slave 20140506-000038-2256185536-45784-30661-0
> I0506 00:00:38.061342 30682 hierarchical_allocator_process.hpp:483] Slave 20140506-000038-2256185536-45784-30661-0 disconnected
> I0506 00:00:38.061863 30680 master.cpp:2798] Authenticating slave(143)@192.168.122.134:45784
> I0506 00:00:38.062556 30684 authenticator.hpp:148] Creating new server SASL connection
> I0506 00:00:38.062885 30684 authenticatee.hpp:219] Received SASL authentication mechanisms: CRAM-MD5
> I0506 00:00:38.062907 30684 authenticatee.hpp:245] Attempting to authenticate with mechanism 'CRAM-MD5'
> I0506 00:00:38.062932 30684 authenticator.hpp:254] Received SASL authentication start
> I0506 00:00:38.062964 30684 authenticator.hpp:342] Authentication requires more steps
> I0506 00:00:38.062989 30684 authenticatee.hpp:265] Received SASL authentication step
> I0506 00:00:38.063022 30684 authenticator.hpp:282] Received SASL authentication step
> I0506 00:00:38.063040 30684 auxprop.cpp:81] Request to lookup properties for user: 'test-principal' realm: 'fedora-19' server FQDN: 'fedora-19' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false
> I0506 00:00:38.063047 30684 auxprop.cpp:153] Looking up auxiliary property '*userPassword'
> I0506 00:00:38.063057 30684 auxprop.cpp:153] Looking up auxiliary property '*cmusaslsecretCRAM-MD5'
> I0506 00:00:38.063066 30684 auxprop.cpp:81] Request to lookup properties for user: 'test-principal' realm: 'fedora-19' server FQDN: 'fedora-19' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true
> I0506 00:00:38.063072 30684 auxprop.cpp:103] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true
> I0506 00:00:38.063077 30684 auxprop.cpp:103] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
> I0506 00:00:38.063087 30684 authenticator.hpp:334] Authentication success
> I0506 00:00:38.063108 30684 authenticatee.hpp:305] Authentication success
> I0506 00:00:38.063210 30684 slave.cpp:643] Successfully authenticated with master master@192.168.122.134:45784
> I0506 00:00:38.063256 30684 slave.cpp:872] Will retry registration in 8.318284332secs if necessary
> I0506 00:00:38.064519 30680 master.cpp:2192] Queuing up re-registration request from slave(143)@192.168.122.134:45784 because authentication is still in progress
> I0506 00:00:38.064581 30680 master.cpp:2838] Successfully authenticated slave(143)@192.168.122.134:45784
> W0506 00:00:38.068217 30680 master.cpp:2248] Slave at slave(143)@192.168.122.134:45784 (fedora-19) is being allowed to re-register with an already in use id (20140506-000038-2256185536-45784-30661-0)
> F0506 00:00:38.068243 30680 protobuf.hpp:110] Check failed: from Attempting to reply without a sender
> *** Check failure stack trace: ***
> @ 0x7f9fc0e87076 google::LogMessage::SendToLog()
> @ 0x7f9fc0e874de google::LogMessage::Flush()
> @ 0x7f9fc0e8ab79 google::LogMessageFatal::~LogMessageFatal()
> @ 0x7f9fc08772d5 ProtobufProcess<>::reply()
> @ 0x7f9fc0857596 mesos::internal::master::Master::reregisterSlave()
> @ 0x7f9fc088e942 _ZNSt17_Function_handlerIFvPN7process11ProcessBaseEEZNS0_8dispatchIN5mesos8internal6master6MasterERKNS0_4UPIDERKNS5_7SlaveIDERKNS5_9SlaveInfoERKSt6vectorINS5_12ExecutorInfoESaISJ_EERKSI_INS6_4TaskESaISO_EERKSI_INS6_17Archive_FrameworkESaIST_EES9_SC_SF_SL_SQ_SV_EEvRKNS0_3PIDIT_EEMSZ_FvT0_T1_T2_T3_T4_T5_ET6_T7_T8_T9_T10_T11_EUlS2_E_E9_M_invokeERKSt9_Any_dataS2_
> @ 0x7f9fc0d8ad6c process::ProcessManager::resume()
> @ 0x7f9fc0d8a8bf process::schedule()
> @ 0x3284c07c53 (unknown)
> @ 0x32844f5dbd (unknown)
> {code}
--
This message was sent by Atlassian JIRA
(v6.2#6252)