KEYCLOAK-5836 More logging around LDAP performance. Added LdapManyObjectsInitializerCommand to easily add many users and groups to the LDAP

This commit is contained in:
mposolda 2017-11-14 17:10:22 +01:00
parent 3c48ee39d9
commit c4a1764801
6 changed files with 326 additions and 4 deletions

View file

@ -92,7 +92,7 @@ public class LDAPUtils {
}
// ldapUser has filled attributes, but doesn't have filled dn.
private static void computeAndSetDn(LDAPConfig config, LDAPObject ldapUser) {
public static void computeAndSetDn(LDAPConfig config, LDAPObject ldapUser) {
String rdnLdapAttrName = config.getRdnLdapAttribute();
String rdnLdapAttrValue = ldapUser.getAttributeAsString(rdnLdapAttrName);
if (rdnLdapAttrValue == null) {

View file

@ -447,9 +447,10 @@ public class LDAPIdentityStore implements IdentityStore {
for (String objectClassValue : ldapObject.getObjectClasses()) {
objectClassAttribute.add(objectClassValue);
if (objectClassValue.equalsIgnoreCase(LDAPConstants.GROUP_OF_NAMES)
if ((objectClassValue.equalsIgnoreCase(LDAPConstants.GROUP_OF_NAMES)
|| objectClassValue.equalsIgnoreCase(LDAPConstants.GROUP_OF_ENTRIES)
|| objectClassValue.equalsIgnoreCase(LDAPConstants.GROUP_OF_UNIQUE_NAMES)) {
|| objectClassValue.equalsIgnoreCase(LDAPConstants.GROUP_OF_UNIQUE_NAMES)) &&
(entryAttributes.get(LDAPConstants.MEMBER) == null)) {
entryAttributes.put(LDAPConstants.MEMBER, LDAPConstants.EMPTY_MEMBER_ATTRIBUTE_VALUE);
}
}

View file

@ -18,6 +18,7 @@
package org.keycloak.storage.ldap.idm.store.ldap;
import org.jboss.logging.Logger;
import org.keycloak.common.util.Time;
import org.keycloak.models.LDAPConstants;
import org.keycloak.models.ModelException;
import org.keycloak.storage.ldap.LDAPConfig;
@ -65,6 +66,8 @@ public class LDAPOperationManager {
private static final Logger logger = Logger.getLogger(LDAPOperationManager.class);
private static final Logger perfLogger = Logger.getLogger(LDAPOperationManager.class, "perf");
private final LDAPConfig config;
private final Map<String, Object> connectionProperties;
@ -146,6 +149,7 @@ public class LDAPOperationManager {
public void removeEntry(final String entryDn) {
try {
execute(new LdapOperation<SearchResult>() {
@Override
public SearchResult execute(LdapContext context) throws NamingException {
if (logger.isTraceEnabled()) {
@ -154,6 +158,15 @@ public class LDAPOperationManager {
destroySubcontext(context, entryDn);
return null;
}
@Override
public String toString() {
return new StringBuilder("LdapOperation: remove\n")
.append(" dn: ").append(entryDn)
.toString();
}
});
} catch (NamingException e) {
throw new ModelException("Could not remove entry from DN [" + entryDn + "]", e);
@ -173,6 +186,7 @@ public class LDAPOperationManager {
public String renameEntry(String oldDn, String newDn, boolean fallback) {
try {
String newNonConflictingDn = execute(new LdapOperation<String>() {
@Override
public String execute(LdapContext context) throws NamingException {
String dn = newDn;
@ -201,6 +215,16 @@ public class LDAPOperationManager {
throw new ModelException("Could not rename entry from DN [" + oldDn + "] to new DN [" + newDn + "]. All fallbacks failed");
}
@Override
public String toString() {
return new StringBuilder("LdapOperation: renameEntry\n")
.append(" oldDn: ").append(oldDn).append("\n")
.append(" newDn: ").append(newDn)
.toString();
}
});
return newNonConflictingDn;
} catch (NamingException e) {
@ -236,6 +260,20 @@ public class LDAPOperationManager {
return result;
}
@Override
public String toString() {
return new StringBuilder("LdapOperation: search\n")
.append(" baseDn: ").append(baseDN).append("\n")
.append(" filter: ").append(filter).append("\n")
.append(" searchScope: ").append(searchScope).append("\n")
.append(" returningAttrs: ").append(returningAttributes).append("\n")
.append(" resultSize: ").append(result.size())
.toString();
}
});
} catch (NamingException e) {
logger.errorf(e, "Could not query server using DN [%s] and filter [%s]", baseDN, filter);
@ -249,6 +287,7 @@ public class LDAPOperationManager {
try {
return execute(new LdapOperation<List<SearchResult>>() {
@Override
public List<SearchResult> execute(LdapContext context) throws NamingException {
try {
@ -281,6 +320,20 @@ public class LDAPOperationManager {
throw new NamingException(ioe.getMessage());
}
}
@Override
public String toString() {
return new StringBuilder("LdapOperation: searchPaginated\n")
.append(" baseDn: ").append(baseDN).append("\n")
.append(" filter: ").append(filter).append("\n")
.append(" searchScope: ").append(identityQuery.getSearchScope()).append("\n")
.append(" returningAttrs: ").append(identityQuery.getReturningLdapAttributes()).append("\n")
.append(" limit: ").append(identityQuery.getLimit()).append("\n")
.append(" resultSize: ").append(result.size())
.toString();
}
});
} catch (NamingException e) {
logger.errorf(e, "Could not query server using DN [%s] and filter [%s]", baseDN, filter);
@ -308,10 +361,21 @@ public class LDAPOperationManager {
try {
Attributes attributes = execute(new LdapOperation<Attributes>() {
@Override
public Attributes execute(LdapContext context) throws NamingException {
return context.getAttributes(strObjectGUID);
}
@Override
public String toString() {
return new StringBuilder("LdapOperation: GUIDResolve\n")
.append(" strObjectGUID: ").append(strObjectGUID)
.toString();
}
});
byte[] objectGUID = (byte[]) attributes.get(LDAPConstants.OBJECT_GUID).get();
@ -340,6 +404,7 @@ public class LDAPOperationManager {
final SearchControls cons = getSearchControls(returningAttributes, this.config.getSearchScope());
return execute(new LdapOperation<SearchResult>() {
@Override
public SearchResult execute(LdapContext context) throws NamingException {
NamingEnumeration<SearchResult> search = context.search(baseDN, filter, cons);
@ -356,6 +421,18 @@ public class LDAPOperationManager {
return null;
}
@Override
public String toString() {
return new StringBuilder("LdapOperation: lookupById\n")
.append(" baseDN: ").append(baseDN).append("\n")
.append(" filter: ").append(filter).append("\n")
.append(" searchScope: ").append(cons.getSearchScope()).append("\n")
.append(" returningAttrs: ").append(returningAttributes)
.toString();
}
});
} catch (NamingException e) {
throw new ModelException("Could not query server using DN [" + baseDN + "] and filter [" + filter + "]", e);
@ -470,11 +547,23 @@ public class LDAPOperationManager {
}
execute(new LdapOperation<Void>() {
@Override
public Void execute(LdapContext context) throws NamingException {
context.modifyAttributes(dn, mods);
return null;
}
@Override
public String toString() {
return new StringBuilder("LdapOperation: modify\n")
.append(" dn: ").append(dn).append("\n")
.append(" modificationsSize: ").append(mods.length)
.toString();
}
}, decorator);
} catch (NamingException e) {
throw new ModelException("Could not modify attribute for DN [" + dn + "]", e);
@ -512,6 +601,16 @@ public class LDAPOperationManager {
return null;
}
@Override
public String toString() {
return new StringBuilder("LdapOperation: create\n")
.append(" dn: ").append(name).append("\n")
.append(" attributesSize: ").append(attributes.size())
.toString();
}
});
} catch (NamingException e) {
throw new ModelException("Error creating subcontext [" + name + "]", e);
@ -631,8 +730,13 @@ public class LDAPOperationManager {
private <R> R execute(LdapOperation<R> operation, LDAPOperationDecorator decorator) throws NamingException {
LdapContext context = null;
Long start = null;
try {
if (perfLogger.isDebugEnabled()) {
start = Time.currentTimeMillis();
}
context = createLdapContext();
if (decorator != null) {
decorator.beforeLDAPOperation(context, operation);
@ -647,6 +751,16 @@ public class LDAPOperationManager {
logger.error("Could not close Ldap context.", ne);
}
}
if (perfLogger.isDebugEnabled()) {
long took = Time.currentTimeMillis() - start;
if (took > 100) {
perfLogger.debugf("\n%s\ntook: %d ms\n", operation.toString(), took);
} else if (perfLogger.isTraceEnabled()) {
perfLogger.tracef("\n%s\ntook: %d ms\n", operation.toString(), took);
}
}
}
}

View file

@ -0,0 +1,203 @@
/*
* Copyright 2017 Red Hat, Inc. and/or its affiliates
* and other contributors as indicated by the @author tags.
*
* Licensed under the Apache License, Version 2.0 (the "License");
* you may not use this file except in compliance with the License.
* You may obtain a copy of the License at
*
* http://www.apache.org/licenses/LICENSE-2.0
*
* Unless required by applicable law or agreed to in writing, software
* distributed under the License is distributed on an "AS IS" BASIS,
* WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
* See the License for the specific language governing permissions and
* limitations under the License.
*/
package org.keycloak.testsuite.util.cli;
import java.util.ArrayList;
import java.util.Collections;
import java.util.HashMap;
import java.util.HashSet;
import java.util.List;
import java.util.Map;
import java.util.Optional;
import java.util.Set;
import org.keycloak.component.ComponentModel;
import org.keycloak.models.KeycloakSession;
import org.keycloak.models.RealmModel;
import org.keycloak.models.UserModel;
import org.keycloak.models.utils.UserModelDelegate;
import org.keycloak.storage.UserStorageProvider;
import org.keycloak.storage.ldap.LDAPStorageProvider;
import org.keycloak.storage.ldap.LDAPUtils;
import org.keycloak.storage.ldap.idm.model.LDAPDn;
import org.keycloak.storage.ldap.idm.model.LDAPObject;
import org.keycloak.storage.ldap.mappers.LDAPStorageMapper;
import org.keycloak.storage.ldap.mappers.membership.group.GroupLDAPStorageMapper;
/**
* The command requires that:
* - Realm has 1 LDAP storage provider defined
* - The LDAP provider has user-attribute-mapper named "streetMapper", which has both "User Model Attribute" and "LDAP Attribute" configured to "street"
* - The LDAP provider has group-mapper named "groupsMapper", with:
* -- "LDAP Groups DN" pointing to same DN, like this command <groups-dn> .
* -- It's supposed to use "User Roles Retrieve Strategy" - "GET_GROUPS_FROM_USER_MEMBEROF_ATTRIBUTE"
* -- It's supposed to use "Member-Of LDAP Attribute" - "street"
*
* @author <a href="mailto:mposolda@redhat.com">Marek Posolda</a>
*/
public class LdapManyObjectsInitializerCommand extends AbstractCommand {
@Override
public String getName() {
return "createLdapObjects";
}
@Override
public String printUsage() {
return super.printUsage() + " <realm-name> <groups-dn> <start-offset-users> <count-users> <start-offset-groups> <count-groups> .\nSee javadoc of class LdapManyObjectsInitializerCommand for additional details.";
}
@Override
protected void doRunCommand(KeycloakSession session) {
String realmName = getArg(0);
String groupsDn = getArg(1);
int startOffsetUsers = getIntArg(2);
int countUsers = getIntArg(3);
int batchCount = 100;
int startOffsetGroups = getIntArg(4);
int countGroups = getIntArg(5);
RealmModel realm = session.realms().getRealmByName(realmName);
List<ComponentModel> components = realm.getComponents(realm.getId(), UserStorageProvider.class.getName());
if (components.size() != 1) {
log.errorf("Expected 1 LDAP Provider, but found: %d providers", components.size());
throw new HandledException();
}
ComponentModel ldapModel = components.get(0);
// Check that street mapper exists. It's required for now, so that "street" attribute is written to the LDAP
getMapperModel(realm, ldapModel, "streetMapper");
ComponentModel groupMapperModel = getMapperModel(realm, ldapModel, "groupsMapper");
// Create users
Set<String> createdUserDNs = new HashSet<>();
BatchTaskRunner.runInBatches(startOffsetUsers, countUsers, batchCount, session.getKeycloakSessionFactory(),
(KeycloakSession kcSession, int firstIt, int countInIt) -> {
LDAPStorageProvider ldapProvider = (LDAPStorageProvider)session.getProvider(UserStorageProvider.class, ldapModel);
RealmModel appRealm = session.realms().getRealmByName(realmName);
for (int i=firstIt ; i<firstIt+countInIt ; i++) {
String username = "user-" + i;
String firstName = "John-" + i;
String lastName = "Doe-" + i;
String email = "user" + i + "@email.cz";
LDAPObject createdUser = addLDAPUser(ldapProvider, appRealm, username, firstName, lastName, email, groupsDn, startOffsetGroups, countGroups);
createdUserDNs.add(createdUser.getDn().toString());
}
log.infof("Created LDAP users from: %d to %d", firstIt, firstIt + countInIt -1);
});
// Create groups
BatchTaskRunner.runInBatches(startOffsetGroups, countGroups, batchCount, session.getKeycloakSessionFactory(),
(KeycloakSession kcSession, int firstIt, int countInIt) -> {
LDAPStorageProvider ldapProvider = (LDAPStorageProvider)session.getProvider(UserStorageProvider.class, ldapModel);
RealmModel appRealm = session.realms().getRealmByName(realmName);
GroupLDAPStorageMapper groupMapper = (GroupLDAPStorageMapper) session.getProvider(LDAPStorageMapper.class, groupMapperModel);
for (int i=firstIt ; i<firstIt+countInIt ; i++) {
String groupName = "group" + i;
Map<String, Set<String>> groupAttrs = new HashMap<>();
groupAttrs.put("member", new HashSet<>(createdUserDNs));
groupMapper.createLDAPGroup(groupName, groupAttrs);
}
log.infof("Created LDAP groups from: %d to %d", firstIt, firstIt + countInIt -1);
});
}
private ComponentModel getMapperModel(RealmModel realm, ComponentModel ldapModel, String mapperName) {
List<ComponentModel> ldapMappers = realm.getComponents(ldapModel.getId(), LDAPStorageMapper.class.getName());
Optional<ComponentModel> optional = ldapMappers.stream().filter((ComponentModel mapper) -> {
return mapper.getName().equals(mapperName);
}).findFirst();
if (!optional.isPresent()) {
log.errorf("Not present LDAP mapper called '%s'", mapperName);
throw new HandledException();
}
return optional.get();
}
private static LDAPObject addLDAPUser(LDAPStorageProvider ldapProvider, RealmModel realm, final String username,
final String firstName, final String lastName, final String email,
String groupsDN, int startOffsetGroups, int countGroups) {
// LDAPObject ldapUser = new LDAPObject();
// LDAPConfig ldapConfig = ldapProvider.getLdapIdentityStore().getConfig();
// ldapUser.setRdnAttributeName(ldapConfig.getRdnLdapAttribute());
// ldapUser.setObjectClasses(ldapConfig.getUserObjectClasses());
// LDAPUtils.computeAndSetDn(ldapConfig, ldapUser);
//
// ldapUser.setSingleAttribute("uid", )
// ldapProvider.getLdapIdentityStore().add(ldapUser);
UserModel helperUser = new UserModelDelegate(null) {
@Override
public String getUsername() {
return username;
}
@Override
public String getFirstName() {
return firstName;
}
@Override
public String getLastName() {
return lastName;
}
@Override
public String getEmail() {
return email;
}
@Override
public List<String> getAttribute(String name) {
if ("street".equals(name)) {
List<String> groupNamesList = new ArrayList<>();
for (int i=startOffsetGroups ; i<startOffsetGroups + countGroups ; i++) {
String groupName = "group" + i;
LDAPDn groupDn = LDAPDn.fromString(groupsDN);
groupDn.addFirst("cn", groupName);
groupNamesList.add(groupDn.toString());
}
return groupNamesList;
} else {
return Collections.emptyList();
}
}
};
return LDAPUtils.addUserToLDAP(ldapProvider, realm, helperUser);
}
}

View file

@ -65,7 +65,8 @@ public class TestsuiteCLI {
CacheCommands.ListCachesCommand.class,
CacheCommands.GetCacheCommand.class,
CacheCommands.CacheRealmObjectsCommand.class,
ClusterProviderTaskCommand.class
ClusterProviderTaskCommand.class,
LdapManyObjectsInitializerCommand.class
};
private final KeycloakSessionFactory sessionFactory;

View file

@ -71,6 +71,9 @@ log4j.logger.org.keycloak.models.sessions.infinispan=${keycloak.infinispan.loggi
# Enable to view queries to LDAP
# log4j.logger.org.keycloak.storage.ldap.idm.store.ldap.LDAPIdentityStore=trace
# Enable to view details about LDAP performance operations
# log4j.logger.org.keycloak.storage.ldap.idm.store.ldap.LDAPOperationManager.perf=trace
# Enable to view kerberos/spnego logging
# log4j.logger.org.keycloak.federation.kerberos=trace