DataConnector Delay

[Mr. Christopher Bland]

HI All,

I am experiencing a weird delay between 3 and 6 seconds when using DataConnector shown below.  My DataConnector is pretty much the same as Shibboleth Wiki "Generate eduPersonAffiliation based on recursive group membership in Active Directory” example on Generate eduPersonAffiliation based on recursive group membership in Active Directory<https://wiki.shibboleth.net/confluence/display/SHIB2/ResolverScriptAttributeDefinitionExamples#ResolverScriptAttributeDefinitionExamples-GenerateeduPersonAffiliationbasedonrecursivegroupmembershipinActiveDirectory>.  I am running IDP v2.4 (planning to upgrade soon)  I’ve tried cranking up logging but am not seeing the issue.  Has anyone else had an issue like this?


<resolver:DataConnector id="ADgroupLDAP" xsi:type="dc:LDAPDirectory"
        ldapURL="ldaps://adserver_1:3269 ldaps://adserver_2:3269 ldaps://adserver_3:3269 ldaps://adserver_4:3269 ldaps://adserver_5:3269 ldaps://adserver_6:3269"
        baseDN=“AD_BASE_DN"
        principal=“PRINCIPAL"
        principalCredential=“PASSWORD"
maxResultSize="1000"
mergeResults="true"
searchTimeLimit="PT30.000S"
connectionStrategy="RANDOM"
>

<resolver:Dependency ref="scripted_distinguishedName" />
<dc:FilterTemplate>
<![CDATA[
(member:1.2.840.113556.1.4.1941:=${scripted_distinguishedName.get(0)})
]]>
</dc:FilterTemplate>
<dc:ReturnAttributes>distinguishedName</dc:ReturnAttributes>
</resolver:DataConnector>


2016-12-27 00:00:02.383 - DEBUG [edu.vt.middleware.ldap.ssl.DefaultHostnameVerifier:210] - verifyDNS found hostname match: adserver_6
2016-12-27 00:00:02.436 - DEBUG [edu.vt.middleware.ldap.Ldap:193] - Search with the following parameters:
2016-12-27 00:00:02.437 - DEBUG [edu.vt.middleware.ldap.Ldap:194] -   dn = AD_BASE_DN
2016-12-27 00:00:02.437 - DEBUG [edu.vt.middleware.ldap.Ldap:195] -   filter = (member:1.2.840.113556.1.4.1941:=USER_DN)
2016-12-27 00:00:02.437 - DEBUG [edu.vt.middleware.ldap.Ldap:196] -   filterArgs = []
2016-12-27 00:00:02.437 - DEBUG [edu.vt.middleware.ldap.Ldap:197] -   searchControls = javax.naming.directory.SearchControls at 12a0b94
2016-12-27 00:00:02.438 - DEBUG [edu.vt.middleware.ldap.Ldap:198] -   handler = [edu.vt.middleware.ldap.handler.FqdnSearchResultHandler at 144f65b, edu.vt.middleware.ldap.handler.EntryDnSearchResultHandler at 8a0a75, edu.vt.middleware.ldap.handler.MergeSearchResultHandler at b4bbea, edu.vt.middleware.ldap.handler.BinarySearchResultHandler at 19d3974]
2016-12-27 00:00:06.922 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.dataConnector.LdapDataConnector:414] - LDAP data connector ADgroupLDAP - Found the following attribute: entryDN[CN=Desktop-



2016-12-28 00:03:54.382 - DEBUG [edu.vt.middleware.ldap.ssl.DefaultHostnameVerifier:210] - verifyDNS found hostname match: adserver_5
2016-12-28 00:03:54.440 - DEBUG [edu.vt.middleware.ldap.Ldap:193] - Search with the following parameters:
2016-12-28 00:03:54.440 - DEBUG [edu.vt.middleware.ldap.Ldap:194] -   dn = AD_BASE_DN
2016-12-28 00:03:54.440 - DEBUG [edu.vt.middleware.ldap.Ldap:195] -   filter = (member:1.2.840.113556.1.4.1941:=USER_DN)
2016-12-28 00:03:54.441 - DEBUG [edu.vt.middleware.ldap.Ldap:196] -   filterArgs = []
2016-12-28 00:03:54.441 - DEBUG [edu.vt.middleware.ldap.Ldap:197] -   searchControls = javax.naming.directory.SearchControls at 1a5793
2016-12-28 00:03:54.441 - DEBUG [edu.vt.middleware.ldap.Ldap:198] -   handler = [edu.vt.middleware.ldap.handler.FqdnSearchResultHandler at 144f65b, edu.vt.middleware.ldap.handler.EntryDnSearchResultHandler at 8a0a75, edu.vt.middleware.ldap.handler.MergeSearchResultHandler at b4bbea, edu.vt.middleware.ldap.handler.BinarySearchResultHandler at 19d3974]
2016-12-28 00:03:59.432 - INFO [Shibboleth-Access:73] - 20161228T050359Z|174.1.116.121|idp.fdu.edu:443<http://idp.fdu.edu:443>|/profile/SAML2/Redirect/SSO|


2016-12-28 00:06:44.514 - DEBUG [edu.vt.middleware.ldap.ssl.DefaultHostnameVerifier:210] - verifyDNS found hostname match: adserver_3
2016-12-28 00:06:44.576 - DEBUG [edu.vt.middleware.ldap.Ldap:193] - Search with the following parameters:
2016-12-28 00:06:44.576 - DEBUG [edu.vt.middleware.ldap.Ldap:194] -   dn = AD_BASE_DN
2016-12-28 00:06:44.577 - DEBUG [edu.vt.middleware.ldap.Ldap:195] -   filter = (member:1.2.840.113556.1.4.1941:=USER_DN)
2016-12-28 00:06:44.577 - DEBUG [edu.vt.middleware.ldap.Ldap:196] -   filterArgs = []
2016-12-28 00:06:44.577 - DEBUG [edu.vt.middleware.ldap.Ldap:197] -   searchControls = javax.naming.directory.SearchControls at f5e8c1
2016-12-28 00:06:44.577 - DEBUG [edu.vt.middleware.ldap.Ldap:198] -   handler = [edu.vt.middleware.ldap.handler.FqdnSearchResultHandler at 144f65b, edu.vt.middleware.ldap.handler.EntryDnSearchResultHandler at 8a0a75, edu.vt.middleware.ldap.handler.MergeSearchResultHandler at b4bbea, edu.vt.middleware.ldap.handler.BinarySearchResultHandler at 19d3974]
2016-12-28 00:06:49.484 - DEBUG [edu.internet2.middleware.shibboleth.common.attribute.resolver.provider.dataConnector.LdapDataConnector:414] -



Thank you in advance,

-Chris

-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://shibboleth.net/pipermail/users/attachments/20161229/191d8ba1/attachment-0001.html>