Skip to content

Commit

Permalink
Entitlements optimization. Improved logging.
Browse files Browse the repository at this point in the history
  • Loading branch information
@semancik
semancik committed Oct 31, 2014
1 parent 12b444e commit f16acd5
Show file tree
Hide file tree
Showing 9 changed files with 168 additions and 44 deletions.
25 changes: 25 additions & 0 deletions infra/common/src/main/java/com/evolveum/midpoint/common/monitor/InternalMonitor.java
View file
Expand Up @@ -42,6 +42,9 @@ public class InternalMonitor {
private static long scriptCompileCount = 0;
private static long scriptExecutionCount = 0;

private static boolean traceConnectorOperation = false;
private static long connectorOperationCount = 0;

private static long shadowFetchOperationCount = 0;
private static boolean traceShadowFetchOperation = false;

Expand Down Expand Up @@ -170,7 +173,27 @@ public static void recordShadowChangeOperation() {
shadowChangeOpeartionCount++;
provisioningAllExtOperationCount++;
}

public static long getConnectorOperationCount() {
return connectorOperationCount;
}

public static void recordConnectorOperation(String name) {
connectorOperationCount++;
if (traceConnectorOperation) {
traceOperation("connector "+name, shadowFetchOperationCount);
}
}

public static boolean isTraceConnectorOperation() {
return traceShadowFetchOperation;
}

public static void setTraceConnectorOperation(boolean trace) {
LOGGER.debug("MONITOR traceConnectorOperation={}", trace);
InternalMonitor.traceConnectorOperation = trace;
}

public static long getProvisioningAllExtOperationCont() {
return provisioningAllExtOperationCount;
}
Expand All @@ -193,6 +216,8 @@ public static void reset() {
shadowFetchOperationCount = 0;
traceShadowFetchOperation = false;
shadowChangeOpeartionCount = 0;
traceConnectorOperation = false;
connectorOperationCount = 0;
}

private static void traceOperation(String opName, long counter) {
Expand Down
77 changes: 46 additions & 31 deletions .../provisioning-impl/src/main/java/com/evolveum/midpoint/provisioning/impl/ShadowCache.java
View file
Expand Up @@ -927,42 +927,50 @@ private PrismObject<ShadowType> lookupOrCreateShadowInRepository(ConnectorInstan
"Shadow object (in repo) corresponding to the resource object (on the resource) was not found. The repo shadow will be created. The resource object:\n{}",
SchemaDebugUtil.prettyPrint(resourceShadow));


PrismObject<ShadowType> conflictingShadow = shadowManager.lookupShadowBySecondaryIdentifiers(resourceShadow, objectClassDef, resourceType, parentResult);
if (conflictingShadow != null){
applyAttributesDefinition(conflictingShadow, resourceType);
conflictingShadow = completeShadow(connector, resourceShadow, conflictingShadow, resourceType, objectClassDef, parentResult);
Task task = taskManager.createTaskInstance();
ResourceOperationDescription failureDescription = shadowManager.createResourceFailureDescription(conflictingShadow, resourceType, parentResult);
changeNotificationDispatcher.notifyFailure(failureDescription, task, parentResult);
shadowManager.deleteConflictedShadowFromRepo(conflictingShadow, parentResult);
}
// TODO: make sure that the resource object has appropriate definition (use objectClass and schema)
// The resource object obviously exists on the resource, but appropriate shadow does not exist in the
// repository we need to create the shadow to align repo state to the reality (resource)

try {

repoShadow = shadowManager.createRepositoryShadow(
resourceShadow, resourceType, objectClassDef);
String oid = repositoryService.addObject(repoShadow, null,
parentResult);
repoShadow.setOid(oid);

} catch (ObjectAlreadyExistsException e) {
// This should not happen. We haven't supplied an OID so is should not conflict
LOGGER.error("Unexpected repository behavior: Object already exists: {}", e.getMessage(), e);
throw new SystemException("Unexpected repository behavior: Object already exists: "+e.getMessage(),e);
}

repoShadow = createShadowInRepository(connector, resourceShadow, objectClassDef, resourceType, parentResult);
} else {
LOGGER.trace("Found shadow object in the repository {}",
SchemaDebugUtil.prettyPrint(repoShadow));
}

return repoShadow;
}


private PrismObject<ShadowType> createShadowInRepository(ConnectorInstance connector, PrismObject<ShadowType> resourceShadow,
RefinedObjectClassDefinition objectClassDef, ResourceType resourceType, OperationResult parentResult)
throws SchemaException, ConfigurationException, ObjectNotFoundException, CommunicationException, SecurityViolationException, GenericConnectorException {

PrismObject<ShadowType> repoShadow;
PrismObject<ShadowType> conflictingShadow = shadowManager.lookupShadowBySecondaryIdentifiers(resourceShadow, objectClassDef, resourceType, parentResult);
if (conflictingShadow != null){
applyAttributesDefinition(conflictingShadow, resourceType);
conflictingShadow = completeShadow(connector, resourceShadow, conflictingShadow, resourceType, objectClassDef, parentResult);
Task task = taskManager.createTaskInstance();
ResourceOperationDescription failureDescription = shadowManager.createResourceFailureDescription(conflictingShadow, resourceType, parentResult);
changeNotificationDispatcher.notifyFailure(failureDescription, task, parentResult);
shadowManager.deleteConflictedShadowFromRepo(conflictingShadow, parentResult);
}
// TODO: make sure that the resource object has appropriate definition (use objectClass and schema)
// The resource object obviously exists on the resource, but appropriate shadow does not exist in the
// repository we need to create the shadow to align repo state to the reality (resource)

try {

repoShadow = shadowManager.createRepositoryShadow(
resourceShadow, resourceType, objectClassDef);
String oid = repositoryService.addObject(repoShadow, null,
parentResult);
repoShadow.setOid(oid);

} catch (ObjectAlreadyExistsException e) {
// This should not happen. We haven't supplied an OID so is should not conflict
LOGGER.error("Unexpected repository behavior: Object already exists: {}", e.getMessage(), e);
throw new SystemException("Unexpected repository behavior: Object already exists: "+e.getMessage(),e);
}

return repoShadow;
}

private List<ObjectFilter> getAttributeQuery(List<? extends ObjectFilter> conditions) throws SchemaException{

List<ObjectFilter> attributeFilter = new ArrayList<>();
Expand Down Expand Up @@ -1604,11 +1612,18 @@ private PrismObject<ShadowType> completeShadow(ConnectorInstance connector, Pris
RefinedAssociationDefinition rEntitlementAssociation = objectClassDefinition.findEntitlementAssociation(associationName);
RefinedObjectClassDefinition entitlementObjectClassDef = refinedSchema.getRefinedDefinition(ShadowKindType.ENTITLEMENT, rEntitlementAssociation.getIntents());

PrismObject<ShadowType> entitlementRepoShadow;
PrismObject<ShadowType> entitlementShadow = (PrismObject<ShadowType>) identifierContainer.getUserData(ResourceObjectConverter.FULL_SHADOW_KEY);
if (entitlementShadow == null) {
entitlementShadow = resouceObjectConverter.locateResourceObject(connector, resource, entitlementIdentifiers, entitlementObjectClassDef, parentResult);
entitlementRepoShadow = shadowManager.lookupShadowInRepository(identifierContainer, entitlementObjectClassDef, resource,
parentResult);
if (entitlementRepoShadow == null) {
entitlementShadow = resouceObjectConverter.locateResourceObject(connector, resource, entitlementIdentifiers, entitlementObjectClassDef, parentResult);
entitlementRepoShadow = createShadowInRepository(connector, entitlementShadow, entitlementObjectClassDef, resource, parentResult);
}
} else {
entitlementRepoShadow = lookupOrCreateShadowInRepository(connector, entitlementShadow, entitlementObjectClassDef, resource, parentResult);
}
PrismObject<ShadowType> entitlementRepoShadow = lookupOrCreateShadowInRepository(connector, entitlementShadow, entitlementObjectClassDef, resource, parentResult);
ObjectReferenceType shadowRefType = new ObjectReferenceType();
shadowRefType.setOid(entitlementRepoShadow.getOid());
shadowRefType.setType(ShadowType.COMPLEX_TYPE);
Expand Down
36 changes: 35 additions & 1 deletion ...rovisioning-impl/src/main/java/com/evolveum/midpoint/provisioning/impl/ShadowManager.java
View file
Expand Up @@ -182,7 +182,41 @@ public PrismObject<ShadowType> lookupShadowInRepository(PrismObject<ShadowType>

return results.get(0);
}


public PrismObject<ShadowType> lookupShadowInRepository(ResourceAttributeContainer identifierContainer,
RefinedObjectClassDefinition rObjClassDef, ResourceType resource, OperationResult parentResult)
throws SchemaException, ConfigurationException {

ObjectQuery query = createSearchShadowQuery(identifierContainer.getValue().getItems(), rObjClassDef, resource, prismContext,
parentResult);
if (LOGGER.isTraceEnabled()) {
LOGGER.trace("Searching for shadow using filter:\n{}",
query.debugDump());
}
// PagingType paging = new PagingType();

// TODO: check for errors
List<PrismObject<ShadowType>> results;

results = repositoryService.searchObjects(ShadowType.class, query, null, parentResult);

LOGGER.trace("lookupShadow found {} objects", results.size());

if (results.size() == 0) {
return null;
}
if (results.size() > 1) {
for (PrismObject<ShadowType> result : results) {
LOGGER.trace("Search result:\n{}", result.debugDump());
}
LOGGER.error("More than one shadows found for " + identifierContainer);
// TODO: Better error handling later
throw new IllegalStateException("More than one shadows found for " + identifierContainer);
}

return results.get(0);
}

public PrismObject<ShadowType> lookupShadowBySecondaryIdentifiers(
PrismObject<ShadowType> resourceShadow, RefinedObjectClassDefinition rObjClassDef,
ResourceType resource, OperationResult parentResult)
Expand Down
18 changes: 17 additions & 1 deletion ...l/src/main/java/com/evolveum/midpoint/provisioning/ucf/impl/ConnectorInstanceIcfImpl.java
View file
Expand Up @@ -30,16 +30,17 @@
import javax.xml.datatype.XMLGregorianCalendar;
import javax.xml.namespace.QName;

import com.evolveum.midpoint.common.monitor.InternalMonitor;
import com.evolveum.midpoint.common.refinery.RefinedObjectClassDefinition;
import com.evolveum.midpoint.common.refinery.RefinedResourceSchema;
import com.evolveum.midpoint.prism.query.ObjectPaging;
import com.evolveum.midpoint.prism.query.OrderDirection;
import com.evolveum.midpoint.schema.SchemaConstantsGenerated;
import com.evolveum.midpoint.util.DebugUtil;

import com.evolveum.midpoint.util.Holder;
import com.evolveum.midpoint.xml.ns._public.common.common_3.ResourcePagedSearchConfigurationType;
import com.evolveum.prism.xml.ns._public.query_3.OrderDirectionType;

import org.apache.commons.lang.StringUtils;
import org.apache.commons.lang.Validate;
import org.identityconnectors.common.pooling.ObjectPoolConfiguration;
Expand Down Expand Up @@ -550,6 +551,7 @@ private void retrieveResourceSchema(List<QName> generateObjectClasses, Operation

// Fetch the schema from the connector (which actually gets that
// from the resource).
InternalMonitor.recordConnectorOperation("schema");
icfSchema = icfConnectorFacade.schema();

icfResult.recordSuccess();
Expand Down Expand Up @@ -808,6 +810,7 @@ private void parseResourceSchema(org.identityconnectors.framework.common.objects

// Create capabilities from supported connector operations

InternalMonitor.recordConnectorOperation("getSupportedOperations");
Set<Class<? extends APIOperation>> supportedOperations = icfConnectorFacade.getSupportedOperations();

LOGGER.trace("Connector supported operations: {}", supportedOperations);
Expand Down Expand Up @@ -1007,6 +1010,7 @@ private ConnectorObject fetchConnectorObject(ObjectClass icfObjectClass, Uid uid
try {

// Invoke the ICF connector
InternalMonitor.recordConnectorOperation("getObject");
co = icfConnectorFacade.getObject(icfObjectClass, uid, options);

icfResult.recordSuccess();
Expand Down Expand Up @@ -1172,6 +1176,7 @@ public Collection<ResourceAttribute<?>> addObject(PrismObject<? extends ShadowTy
try {

// CALL THE ICF FRAMEWORK
InternalMonitor.recordConnectorOperation("create");
uid = icfConnectorFacade.create(objectClass, attributes, new OperationOptionsBuilder().build());

} catch (Throwable ex) {
Expand Down Expand Up @@ -1390,6 +1395,7 @@ public Set<PropertyModificationOperation> modifyObject(ObjectClassComplexTypeDef
new Object[] { objClass, uid, dumpAttributes(attributes) });
}

InternalMonitor.recordConnectorOperation("addAttributeValues");
uid = icfConnectorFacade.addAttributeValues(objClass, uid, attributes, options);

icfResult.recordSuccess();
Expand Down Expand Up @@ -1469,6 +1475,7 @@ public Set<PropertyModificationOperation> modifyObject(ObjectClassComplexTypeDef

try {
// Call ICF
InternalMonitor.recordConnectorOperation("update");
uid = icfConnectorFacade.update(objClass, uid, updateAttributes, options);

icfResult.recordSuccess();
Expand Down Expand Up @@ -1528,6 +1535,7 @@ public Set<PropertyModificationOperation> modifyObject(ObjectClassComplexTypeDef
new Object[] { objClass, uid, dumpAttributes(attributes) });
}

InternalMonitor.recordConnectorOperation("removeAttributeValues");
uid = icfConnectorFacade.removeAttributeValues(objClass, uid, attributes, options);
icfResult.recordSuccess();
}
Expand Down Expand Up @@ -1621,6 +1629,7 @@ public void deleteObject(ObjectClassComplexTypeDefinition objectClass,

try {

InternalMonitor.recordConnectorOperation("delete");
icfConnectorFacade.delete(objClass, uid, new OperationOptionsBuilder().build());

icfResult.recordSuccess();
Expand Down Expand Up @@ -1675,6 +1684,7 @@ public PrismProperty<?> fetchCurrentToken(ObjectClassComplexTypeDefinition objec

SyncToken syncToken = null;
try {
InternalMonitor.recordConnectorOperation("getLatestSyncToken");
syncToken = icfConnectorFacade.getLatestSyncToken(icfObjectClass);
icfResult.recordSuccess();
icfResult.addReturn("syncToken", syncToken==null?null:String.valueOf(syncToken.getValue()));
Expand Down Expand Up @@ -1754,6 +1764,7 @@ public boolean handle(SyncDelta delta) {
icfResult.addArbitraryObjectAsParam("syncHandler", syncHandler);

try {
InternalMonitor.recordConnectorOperation("sync");
icfConnectorFacade.sync(icfObjectClass, syncToken, syncHandler,
options);
icfResult.recordSuccess();
Expand Down Expand Up @@ -1800,6 +1811,7 @@ public void test(OperationResult parentResult) {
connectionResult.addContext("connector", connectorType);

try {
InternalMonitor.recordConnectorOperation("test");
icfConnectorFacade.test();
connectionResult.recordSuccess();
} catch (UnsupportedOperationException ex) {
Expand Down Expand Up @@ -1923,6 +1935,7 @@ public boolean handle(ConnectorObject connectorObject) {

Filter filter = convertFilterToIcf(query);

InternalMonitor.recordConnectorOperation("search");
icfConnectorFacade.search(icfObjectClass, filter, icfHandler, options);

icfResult.recordSuccess();
Expand Down Expand Up @@ -2017,6 +2030,7 @@ public boolean handle(ConnectorObject connectorObject) {
return false;
}
};
InternalMonitor.recordConnectorOperation("search");
SearchResult searchResult = icfConnectorFacade.search(icfObjectClass, filter, icfHandler, options);

if (searchResult == null || searchResult.getRemainingPagedResults() == -1) {
Expand Down Expand Up @@ -2343,8 +2357,10 @@ private Object executeScriptIcf(ExecuteProvisioningScriptOperation scriptOperati
LOGGER.trace("Running script ({})", icfOpName);

if (scriptOperation.isConnectorHost()) {
InternalMonitor.recordConnectorOperation("runScriptOnConnector");
output = icfConnectorFacade.runScriptOnConnector(scriptContext, new OperationOptionsBuilder().build());
} else if (scriptOperation.isResourceHost()) {
InternalMonitor.recordConnectorOperation("runScriptOnResource");
output = icfConnectorFacade.runScriptOnResource(scriptContext, new OperationOptionsBuilder().build());
}

Expand Down
9 changes: 9 additions & 0 deletions ...ovisioning-impl/src/test/java/com/evolveum/midpoint/provisioning/test/impl/TestDummy.java
View file
Expand Up @@ -57,6 +57,7 @@
import com.evolveum.icf.dummy.resource.DummyGroup;
import com.evolveum.icf.dummy.resource.DummyPrivilege;
import com.evolveum.icf.dummy.resource.DummySyncStyle;
import com.evolveum.midpoint.common.monitor.InternalMonitor;
import com.evolveum.midpoint.common.refinery.RefinedAttributeDefinition;
import com.evolveum.midpoint.common.refinery.RefinedObjectClassDefinition;
import com.evolveum.midpoint.common.refinery.RefinedResourceSchema;
Expand Down Expand Up @@ -195,6 +196,12 @@ protected String getDrakeRepoIcfName() {
return DRAKE_USERNAME;
}

@Override
public void initSystem(Task initTask, OperationResult initResult) throws Exception {
super.initSystem(initTask, initResult);
InternalMonitor.setTraceConnectorOperation(true);
}

@Test
public void test000Integrity() throws ObjectNotFoundException, SchemaException {
TestUtil.displayTestTile("test000Integrity");
Expand Down Expand Up @@ -3095,6 +3102,7 @@ public void test224GetFoolishPirateWill() throws Exception {
groupFools.addMember(ACCOUNT_WILL_USERNAME);

syncServiceMock.reset();
rememberConnectorOperationCount();

// WHEN
PrismObject<ShadowType> account = provisioningService.getObject(ShadowType.class, ACCOUNT_WILL_OID, null, task, result);
Expand All @@ -3105,6 +3113,7 @@ public void test224GetFoolishPirateWill() throws Exception {

display(result);
TestUtil.assertSuccess(result);
assertConnectorOperationIncrement(2);

PrismObject<ShadowType> foolsShadow = findShadowByName(new QName(RESOURCE_DUMMY_NS, OBJECTCLAS_GROUP_LOCAL_NAME), "fools", resource, result);
assertNotNull("No shadow for group fools", foolsShadow);
Expand Down

0 comments on commit f16acd5

Please sign in to comment.