From b2354bc2ec4af5eaa8e8ee42435c4037be2b9262 Mon Sep 17 00:00:00 2001 From: John Casey Date: Mon, 15 Apr 2019 16:07:37 -0500 Subject: [PATCH 1/2] Add MDC entries to mark progress in content promotion --- .../indy/promote/data/PromotionManager.java | 23 +++++ .../validate/PromoteValidationsManager.java | 9 +- .../validate/PromotionValidationTools.java | 90 +++++++++++++------ .../promote/validate/PromotionValidator.java | 5 ++ 4 files changed, 97 insertions(+), 30 deletions(-) diff --git a/addons/promote/common/src/main/java/org/commonjava/indy/promote/data/PromotionManager.java b/addons/promote/common/src/main/java/org/commonjava/indy/promote/data/PromotionManager.java index 77f24ddd20..fcab53e552 100644 --- a/addons/promote/common/src/main/java/org/commonjava/indy/promote/data/PromotionManager.java +++ b/addons/promote/common/src/main/java/org/commonjava/indy/promote/data/PromotionManager.java @@ -57,6 +57,7 @@ import org.commonjava.maven.galley.spi.nfc.NotFoundCache; import org.slf4j.Logger; import org.slf4j.LoggerFactory; +import org.slf4j.MDC; import javax.enterprise.context.ApplicationScoped; import javax.enterprise.event.Event; @@ -94,6 +95,18 @@ public class PromotionManager { + private static final String PROMOTION_TYPE = "promotion-type"; + + private static final String PATH_PROMOTION = "path"; + + private static final String GROUP_PROMOTION = "group"; + + private static final String PROMOTION_SOURCE = "promotion-source"; + + private static final String PROMOTION_TARGET = "promotion-target"; + + private static final String PROMOTION_CONTENT_PATH = "promotion-content-path"; + private final Logger logger = LoggerFactory.getLogger( getClass() ); @Inject @@ -170,6 +183,10 @@ public PromotionManager( PromotionValidator validator, final ContentManager cont public GroupPromoteResult promoteToGroup( GroupPromoteRequest request, String user, String baseUrl ) throws PromotionException, IndyWorkflowException { + MDC.put( PROMOTION_TYPE, GROUP_PROMOTION ); + MDC.put( PROMOTION_SOURCE, request.getSource().toString() ); + MDC.put( PROMOTION_TARGET, request.getTargetKey().toString() ); + if ( !storeManager.hasArtifactStore( request.getSource() ) ) { String error = String.format( "Cannot promote from missing source: %s", request.getSource() ); @@ -466,6 +483,10 @@ private Future submitGroupPromoteRequest( final GroupPromote public PathsPromoteResult promotePaths( final PathsPromoteRequest request, final String baseUrl ) throws PromotionException, IndyWorkflowException { + MDC.put( PROMOTION_TYPE, PATH_PROMOTION ); + MDC.put( PROMOTION_SOURCE, request.getSource().toString() ); + MDC.put( PROMOTION_TARGET, request.getTargetKey().toString() ); + Future future = submitPathsPromoteRequest( request, baseUrl ); if ( request.isAsync() ) { @@ -1013,6 +1034,8 @@ private Callable newPathsPromoteTransfer( final Transfer tra final PathsPromoteRequest request ) { return () -> { + MDC.put( PROMOTION_CONTENT_PATH, transfer.getPath() ); + PathTransferResult result = new PathTransferResult( transfer.getPath() ); final String path = transfer.getPath(); diff --git a/addons/promote/common/src/main/java/org/commonjava/indy/promote/validate/PromoteValidationsManager.java b/addons/promote/common/src/main/java/org/commonjava/indy/promote/validate/PromoteValidationsManager.java index 6700f6dcfe..8f0e3312d3 100644 --- a/addons/promote/common/src/main/java/org/commonjava/indy/promote/validate/PromoteValidationsManager.java +++ b/addons/promote/common/src/main/java/org/commonjava/indy/promote/validate/PromoteValidationsManager.java @@ -212,6 +212,7 @@ public ValidationRuleSet getRuleSetMatching( StoreKey storeKey ) { if ( ruleSets == null ) { + logger.debug( "No rule sets to match against. No validations will be executed for: {}", storeKey ); return null; } @@ -220,13 +221,15 @@ public ValidationRuleSet getRuleSetMatching( StoreKey storeKey ) String.format( "%s:%s", storeKey.getType().singularEndpointName(), storeKey.getName() ) ); - for ( ValidationRuleSet set : ruleSets.values() ) + for ( Map.Entry entry : ruleSets.entrySet() ) { for ( String keyStr : keyStrings ) { - if ( set.matchesKey( keyStr ) ) + logger.debug( "Checking for rule-set match. Key='{}', rule-set: '{}'", keyStr, entry.getKey() ); + if ( entry.getValue().matchesKey( keyStr ) ) { - return set; + logger.debug( "Rule set '{}' matches key: '{}'", entry.getKey(), keyStr ); + return entry.getValue(); } } } diff --git a/addons/promote/common/src/main/java/org/commonjava/indy/promote/validate/PromotionValidationTools.java b/addons/promote/common/src/main/java/org/commonjava/indy/promote/validate/PromotionValidationTools.java index 72bed0f5da..b58d9999df 100644 --- a/addons/promote/common/src/main/java/org/commonjava/indy/promote/validate/PromotionValidationTools.java +++ b/addons/promote/common/src/main/java/org/commonjava/indy/promote/validate/PromotionValidationTools.java @@ -17,6 +17,7 @@ import groovy.lang.Closure; import org.commonjava.cdi.util.weft.ExecutorConfig; +import org.commonjava.cdi.util.weft.ThreadContext; import org.commonjava.cdi.util.weft.WeftManaged; import org.commonjava.indy.IndyWorkflowException; import org.commonjava.indy.content.ContentDigester; @@ -54,6 +55,7 @@ import org.commonjava.maven.galley.transport.htcli.model.HttpExchangeMetadata; import org.slf4j.Logger; import org.slf4j.LoggerFactory; +import org.slf4j.MDC; import javax.inject.Inject; import java.net.URI; @@ -68,6 +70,7 @@ import java.util.concurrent.CountDownLatch; import java.util.concurrent.Executor; import java.util.concurrent.TimeUnit; +import java.util.concurrent.atomic.AtomicInteger; import java.util.stream.Collectors; import java.util.stream.Stream; @@ -89,6 +92,10 @@ public class PromotionValidationTools private static final int DEFAULT_RULE_PARALLEL_WAIT_TIME_MINS = 30; + private static final String ITERATION_DEPTH = "promotion-validation-parallel-depth"; + + private static final String ITERATION_ITEM = "promotion-validation-parallel-item"; + @Inject private ContentManager contentManager; @@ -595,20 +602,34 @@ public void paralleledInBatch( Map map, Closure closure ) private void runParallelInBatchAndWait( Collection> batches, Closure closure, Logger logger ) { - final CountDownLatch latch = new CountDownLatch( batches.size() ); - batches.forEach( batch -> ruleParallelExecutor.execute( () -> { - try - { - logger.trace( "The paralleled exe on batch {}", batch ); - batch.forEach( e -> closure.call( e ) ); - } - finally - { - latch.countDown(); - } - } ) ); + ThreadContext ctx = ThreadContext.getContext( true ); + AtomicInteger depth = (AtomicInteger) ctx.computeIfAbsent( ITERATION_DEPTH, k -> new AtomicInteger( -1 ) ); + depth.incrementAndGet(); - waitForCompletion( latch ); + try + { + final CountDownLatch latch = new CountDownLatch( batches.size() ); + batches.forEach( batch -> ruleParallelExecutor.execute( () -> { + try + { + logger.trace( "The paralleled exe on batch {}", batch ); + batch.forEach( e -> { + MDC.put( ITERATION_ITEM, String.valueOf( e ) ); + closure.call( e ); + } ); + } + finally + { + latch.countDown(); + } + } ) ); + + waitForCompletion( latch ); + } + finally + { + depth.decrementAndGet(); + } } private Collection> batch( Collection collection, int batchSize ) @@ -636,21 +657,36 @@ private Collection> batch( Collection collection, int batch private void runParallelAndWait( Collection runCollection, Closure closure, Logger logger ) { - Set todo = new HashSet<>( runCollection ); - final CountDownLatch latch = new CountDownLatch( todo.size() ); - todo.forEach( e -> ruleParallelExecutor.execute( () -> { - try - { - logger.trace( "The paralleled exe on element {}", e ); - closure.call( e ); - } - finally - { - latch.countDown(); - } - } ) ); + ThreadContext ctx = ThreadContext.getContext( true ); + AtomicInteger depth = (AtomicInteger) ctx.computeIfAbsent( ITERATION_DEPTH, k -> new AtomicInteger( -1 ) ); + depth.incrementAndGet(); + + try + { + Set todo = new HashSet<>( runCollection ); + final CountDownLatch latch = new CountDownLatch( todo.size() ); + todo.forEach( e -> ruleParallelExecutor.execute( () -> { + MDC.put( ITERATION_ITEM, String.valueOf( e ) ); + MDC.put( ITERATION_DEPTH, String.valueOf( depth.get() ) ); + + try + { + logger.trace( "The paralleled exe on element {}", e ); + closure.call( e ); + } + finally + { + latch.countDown(); + } + } ) ); + + waitForCompletion( latch ); + } + finally + { + depth.decrementAndGet(); + } - waitForCompletion( latch ); } private void waitForCompletion( CountDownLatch latch ) diff --git a/addons/promote/common/src/main/java/org/commonjava/indy/promote/validate/PromotionValidator.java b/addons/promote/common/src/main/java/org/commonjava/indy/promote/validate/PromotionValidator.java index 1e46925023..c303657e12 100644 --- a/addons/promote/common/src/main/java/org/commonjava/indy/promote/validate/PromotionValidator.java +++ b/addons/promote/common/src/main/java/org/commonjava/indy/promote/validate/PromotionValidator.java @@ -43,6 +43,7 @@ import org.commonjava.maven.galley.model.Transfer; import org.slf4j.Logger; import org.slf4j.LoggerFactory; +import org.slf4j.MDC; import javax.inject.Inject; import java.io.File; @@ -67,6 +68,8 @@ public class PromotionValidator { private static final String PROMOTE_REPO_PREFIX = "Promote_"; + private static final String PROMOTION_VALIDATION_RULE = "promotion-validation-rule"; + @Inject private PromoteValidationsManager validationsManager; @@ -157,6 +160,8 @@ public ValidationRequest validate( PromoteRequest request, ValidationResult resu for ( String ruleRef : ruleNames ) { svc.submit( () -> { + MDC.put( PROMOTION_VALIDATION_RULE, ruleRef ); + Exception err = null; try { From 62aca5d8ffc3031aa52fe4580c749393318329f0 Mon Sep 17 00:00:00 2001 From: John Casey Date: Tue, 16 Apr 2019 14:27:59 -0500 Subject: [PATCH 2/2] fix iteration depth MDC injection clear validation tool iteration MDC items,and give a warning when iteration depth is > 0 --- .../validate/PromotionValidationTools.java | 25 ++++++++++++++++--- 1 file changed, 22 insertions(+), 3 deletions(-) diff --git a/addons/promote/common/src/main/java/org/commonjava/indy/promote/validate/PromotionValidationTools.java b/addons/promote/common/src/main/java/org/commonjava/indy/promote/validate/PromotionValidationTools.java index b58d9999df..e661a7cac3 100644 --- a/addons/promote/common/src/main/java/org/commonjava/indy/promote/validate/PromotionValidationTools.java +++ b/addons/promote/common/src/main/java/org/commonjava/indy/promote/validate/PromotionValidationTools.java @@ -604,7 +604,11 @@ private void runParallelInBatchAndWait( Collection> batches, C { ThreadContext ctx = ThreadContext.getContext( true ); AtomicInteger depth = (AtomicInteger) ctx.computeIfAbsent( ITERATION_DEPTH, k -> new AtomicInteger( -1 ) ); - depth.incrementAndGet(); + int nextDepth = depth.incrementAndGet(); + if ( nextDepth > 0 ) + { + logger.warn( "Nested parallel iteration detected in promotion validation rule!!" ); + } try { @@ -615,7 +619,16 @@ private void runParallelInBatchAndWait( Collection> batches, C logger.trace( "The paralleled exe on batch {}", batch ); batch.forEach( e -> { MDC.put( ITERATION_ITEM, String.valueOf( e ) ); - closure.call( e ); + MDC.put( ITERATION_DEPTH, String.valueOf( depth.get() ) ); + try + { + closure.call( e ); + } + finally + { + MDC.remove( ITERATION_ITEM ); + MDC.remove( ITERATION_DEPTH ); + } } ); } finally @@ -659,7 +672,11 @@ private void runParallelAndWait( Collection runCollection, Closure closur { ThreadContext ctx = ThreadContext.getContext( true ); AtomicInteger depth = (AtomicInteger) ctx.computeIfAbsent( ITERATION_DEPTH, k -> new AtomicInteger( -1 ) ); - depth.incrementAndGet(); + int nextDepth = depth.incrementAndGet(); + if ( nextDepth > 0 ) + { + logger.warn( "Nested parallel iteration detected in promotion validation rule!!" ); + } try { @@ -677,6 +694,8 @@ private void runParallelAndWait( Collection runCollection, Closure closur finally { latch.countDown(); + MDC.remove( ITERATION_ITEM ); + MDC.remove( ITERATION_DEPTH ); } } ) );