[Samba] net ads and wbinfo are painfully slow -- but they work

[Chris Stankevitz]

On Wed, Feb 1, 2017 at 8:19 AM, Rowland Penny via samba
<samba at lists.samba.org> wrote:
> There is definitely something strange going on here, if I flush
> the winbind cache, then ask for a users info with getent, I get this:

I suspect now that the problem is not getent/nsswitch/pam and that it
is either winbindd/krb5/AD.

I launched winbindd in debug99/foreground/no_cache mode.  I waited
about 10 seconds, then issued "wbinfo -u".

wbinfo -u took 4 minutes to complete.  It completed and displayed the
correct/valid list of users.

During the several minutes it took to display the users, winbindd was
logging lots activity.  The activity was interrupted by long waits.
These long waits of course summed to be the ~4 minutes it took for
"wbinfo -u" to return.

The debug log is probably too large for this list.  I snipped out of
the debug output A) the lines that preceeded long waits and B) the
lines that look like error messages.  Please let me know if anything
stands out as a configuration problem.

The windows domain is just a couple days old and contains only a
handful of users.

Please keep in mind that the wbinfo -u is working and returns correct
results.  It is just outrageously slow.

Thank you again,

Chris

=== A. log entries tha preceeded long waits ===

Opening connection to LDAP server '192.168.1.4:389', timeout 15 seconds

Starting GENSEC submechanism gse_krb5

list_users MYDOMAIN
     wbint_QueryUserList: struct wbint_QueryUserList
        in: struct wbint_QueryUserList

Opening connection to LDAP server '192.168.1.4:389', timeout 15 seconds

Starting GENSEC submechanism gse_krb5

Opening connection to LDAP server '192.168.1.4:389', timeout 15 seconds

Starting GENSEC submechanism gse_krb5

Starting GENSEC submechanism gse_krb5

Opening connection to LDAP server '192.168.1.4:389', timeout 15 seconds

Starting GENSEC submechanism gse_krb5

Opening connection to LDAP server '192.168.1.4:389', timeout 15 seconds

Starting GENSEC submechanism gse_krb5

Starting GENSEC submechanism gse_krb5

Starting GENSEC submechanism gse_krb5

Starting GENSEC submechanism gse_krb5

Already reaped child 89263 died


=== B. log entries that look like error messages ===

1. A complaint about addrchange_context_create

addrchange_context_create failed: NT_STATUS_NOT_SUPPORTED


2. A complaint about broken pipe after starting gse_krb5.  This
happened multiple times.

Starting GENSEC submechanism gse_krb5
Client request timed out, shutting down sock 23, pid 89266
final write to client failed: Broken pipe


3. A complainted about gss_acquire_creds.  This happened multiple times.

gss_acquire_creds failed for GSS_C_NO_NAME with [ No credentials were
supplied, or the credentials w
ere unavailable or inaccessible.: unknown mech-code 0 for mech 1 2 840
113554 1 2 2] -the caller may
 retry after a kinit.
Failed to start GENSEC client mech gse_krb5: NT_STATUS_INTERNAL_ERROR
Failed to setup SPNEGO negTokenInit request: NT_STATUS_INTERNAL_ERROR
ads_sasl_spnego_gensec_bind(KRB5) failed with: An internal error
occurred., calling kinit