[
https://issues.apache.org/jira/browse/KUDU-3217?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17241736#comment-17241736
]
Alexey Serbin commented on KUDU-3217:
-------------------------------------
A few more references on the fix for the related issue in SSSD:
* Bug report in RedHat bugzilla:
https://bugzilla.redhat.com/show_bug.cgi?id=1461462
* Corresponding published errata:
https://access.redhat.com/errata/RHEA-2018:0929
* SSSD 1.16 release notes (the fix is in 1.16 release):
https://sssd.io/docs/users/relnotes/notes_1_16_0.html
> Limit the amount of time spent by SASL method run by WrapSaslCall
> -----------------------------------------------------------------
>
> Key: KUDU-3217
> URL: https://issues.apache.org/jira/browse/KUDU-3217
> Project: Kudu
> Issue Type: Improvement
> Components: master, security, tserver
> Reporter: Alexey Serbin
> Priority: Major
>
> There were reports on connection negotiation issues in a secure Kudu cluster:
> Kudu clients (e.g., {{kudu cluster ksck}} tool) would fail to establish a
> connection to a tablet server or master. The issue happened rather rarely,
> but in a busy cluster that was a major nuisance because the target server
> (master or tablet server) would not accept any new connections for a very
> long time, and usually the solution was to restart the process.
> The stack traces collected from the diagnostic files pointed to a situation
> where one negotiation thread acquired the mutex in {{WrapSaslCall()}} in read
> mode and stuck for a long time (at least a few minutes), while the Kerberos
> creds renewal thread was waiting on the lock to be acquired in write mode.
> Consequently, all other connection negotiation threads were blocked on the
> same mutex after that since the mutex is of
> {{RWMutex::Priority::PREFER_WRITING}} priority.
> The stacks of the related threads looked like the following:
> {noformat}
> tids=[380992]
> 0x7f060e1e45e0 <unknown>
> 0x7f060c4afa3d __GI___poll
> 0x7f0605813ffa <unknown>
> 0x7f06058147b5 <unknown>
> 0x7f0605814b07 sss_pac_make_request
> 0x7f0605813dab <unknown>
> 0x7f060df31deb <unknown>
> 0x7f060df53661 <unknown>
> 0x7f060df5407a krb5_rd_req_decoded
> 0x7f060d3d190c <unknown>
> 0x7f060d3d2dea <unknown>
> 0x7f060d3d2f49 <unknown>
> 0x7f060d3c0606 gss_accept_sec_context
> 0x7f060765c04c <unknown>
> 0x7f060d610b9b sasl_server_step
> 0x7f060d611109 sasl_server_start
> tids=[170406,168067,167927,170163,168917,169251]
> 0x7f060e1e45e0 <unknown>
> 0x7f060e1e0092 __GI___pthread_rwlock_rdlock
> 0x1d09883 kudu::rpc::WrapSaslCall()
> 0x1d0bd21 kudu::rpc::ServerNegotiation::InitSaslServer()
> 0x1d112f7 kudu::rpc::ServerNegotiation::AuthenticateBySasl()
> 0x1d13096 kudu::rpc::ServerNegotiation::Negotiate()
> 0x1d2420c kudu::rpc::Negotiation::RunNegotiation()
> 0x1cfa905 kudu::internal::Invoker<>::Run()
> 0x1e9234f kudu::ThreadPool::DispatchThread()
> 0x1e88014 kudu::Thread::SuperviseThread()
> 0x7f060e1dce25 start_thread
> 0x7f060c4ba34d __clone
> tids=[380520]
> 0x7f060e1e45e0 <unknown>
> 0x7f060e1e02ac __GI___pthread_rwlock_wrlock
> 0x1d3b737 kudu::security::(anonymous namespace)::RenewThread()
> 0x1e88014 kudu::Thread::SuperviseThread()
> 0x7f060e1dce25 start_thread
> 0x7f060c4ba34d __clone
> {noformat}
> Thread {{80992}} is the thread that acquired the mutex in read mode and stuck
> in a SASL call (the latter went through SSSD). Thread {{380520}} is the
> Kerberos creds renewal thread, trying to lock the mutex in write mode. The
> rest are connection negotiation threads trying to acquire the lock in read
> mode.
> Further investigation revealed an [issue in
> SSSD|https://github.com/SSSD/sssd/issues/4544], where the stack of the stuck
> thread looks exactly the same as the stack of {{80992}} (modulo the latter
> didn't have debug symbols to show information on every function in the stack):
> {noformat}
> #0 0x00007f29342dcdfd in poll () from /lib64/libc.so.6
> #1 0x00007f2901e722ba in sss_cli_make_request_nochecks () from
> /usr/lib64/krb5/plugins/authdata/sssd_pac_plugin.so
> #2 0x00007f2901e72a75 in sss_cli_check_socket () from
> /usr/lib64/krb5/plugins/authdata/sssd_pac_plugin.so
> #3 0x00007f2901e72e07 in sss_pac_make_request () from
> /usr/lib64/krb5/plugins/authdata/sssd_pac_plugin.so
> #4 0x00007f2901e71feb in sssdpac_verify () from
> /usr/lib64/krb5/plugins/authdata/sssd_pac_plugin.so
> #5 0x00007f29364ea3d3 in krb5int_authdata_verify () from /lib64/libkrb5.so.3
> #6 0x00007f293650b621 in rd_req_decoded_opt () from /lib64/libkrb5.so.3
> #7 0x00007f293650c03a in krb5_rd_req_decoded () from /lib64/libkrb5.so.3
> #8 0x00007f292d592b3f in kg_accept_krb5 () from /lib64/libgssapi_krb5.so.2
> #9 0x00007f292d5941fa in krb5_gss_accept_sec_context_ext () from
> /lib64/libgssapi_krb5.so.2
> #10 0x00007f292d594359 in krb5_gss_accept_sec_context () from
> /lib64/libgssapi_krb5.so.2
> #11 0x00007f292d5816d6 in gss_accept_sec_context () from
> /lib64/libgssapi_krb5.so.2
> #12 0x00007f292d7c3edc in gssapi_server_mech_step () from
> /usr/lib64/sasl2/libgssapiv2.so
> #13 0x00007f29349e5b9b in sasl_server_step () from /lib64/libsasl2.so.3
> #14 0x00007f29349e6109 in sasl_server_start () from /lib64/libsasl2.so.3
> {noformat}
> With that, given that there might be many other bugs in that path and a
> remote KDC might be very slow to respond if overloaded in a larger cluster,
> it would be great to limit the amount of time spent by the SASL call run by
> {{WrapSaslCall()}}, so if it's over the limit, the code would return
> {{Status::TimedOut()}} or {{Status::ServiceUnavailable()}} status.
> Also, it doesn't seem like a very good idea to lock a mutex and issue a SASL
> call since the latter is often turns to be a call to remote KDC.
--
This message was sent by Atlassian Jira
(v8.3.4#803005)
