Release locks between junit tests

Tdjam junits were randomly failing.  Traced it down to the fact that the
locks were being released asynchronously and thus were not always
released when the next test cases requested them.
Also simplified logging for tdjam junit tests.
Fixed the property file so it isn't overwritten by the junit tests.

Changes per review comments:
- changed "Pattern" to "pattern" in logback xml

Issue-ID: POLICY-2789
Change-Id: I325ec69cf7affa531d3c575e3a34bc0b0e1edac7
Signed-off-by: Jim Hahn <jrh3@att.com>

5 files changed, 66 insertions, 18 deletions

diff --git a/controlloop/common/controller-tdjam/src/test/java/org/onap/policy/controlloop/TdjamTest.java b/controlloop/common/controller-tdjam/src/test/java/org/onap/policy/controlloop/TdjamTest.java
index 8e286c44e..917e9adbd 100644
--- a/controlloop/common/controller-tdjam/src/test/java/org/onap/policy/controlloop/TdjamTest.java
+++ b/controlloop/common/controller-tdjam/src/test/java/org/onap/policy/controlloop/TdjamTest.java
@@ -26,7 +26,6 @@ import org.junit.After;
 import org.junit.AfterClass;
 import org.junit.Before;
 import org.junit.BeforeClass;
-import org.junit.Ignore;
 import org.junit.runner.RunWith;
 import org.onap.policy.common.utils.coder.CoderException;
 import org.onap.policy.controlloop.common.rules.test.BaseTest;
@@ -54,7 +53,6 @@ import org.onap.policy.simulators.Util;
 @RunWith(NamedRunner.class)
 @TestNames(prefixes = {"test"})
 
-@Ignore
 public class TdjamTest extends BaseTest {
     protected static final String CONTROLLER_NAME = "tdjam";
     protected static PolicyController controller;
@@ -95,7 +93,7 @@ public class TdjamTest extends BaseTest {
      */
     @Before
     public void setUp() {
-        topics = topicMaker.get();
+        init();
     }
 
     /**
@@ -103,7 +101,7 @@ public class TdjamTest extends BaseTest {
      */
     @After
     public void tearDown() {
-        topics.destroy();
+        finish();
     }
 
     protected static PolicyEngine makeEngine() {
diff --git a/controlloop/common/controller-tdjam/src/test/resources/config/tdjam-controller.properties b/controlloop/common/controller-tdjam/src/test/resources/config/tdjam-controller.properties
index 41db06c51..135fa05cd 100644
--- a/controlloop/common/controller-tdjam/src/test/resources/config/tdjam-controller.properties
+++ b/controlloop/common/controller-tdjam/src/test/resources/config/tdjam-controller.properties
@@ -23,7 +23,7 @@ controller.type=tdjam
 
 rules.groupId=NonDroolsPolicyController
 rules.artifactId=tdjam
-rules.version=1.0.0
+rules.version=1.0
 
 noop.source.topics=DCAE_TOPIC,APPC-CL,APPC-LCM-WRITE,SDNR-CL-RSP,POLICY-CL-MGT,APPC-LCM-READ
 
diff --git a/controlloop/common/controller-tdjam/src/test/resources/logback-test.xml b/controlloop/common/controller-tdjam/src/test/resources/logback-test.xml
index 656cb8136..84b02f2e7 100644
--- a/controlloop/common/controller-tdjam/src/test/resources/logback-test.xml
+++ b/controlloop/common/controller-tdjam/src/test/resources/logback-test.xml
@@ -23,16 +23,16 @@
         <!-- encoders are assigned the type
              ch.qos.logback.classic.encoder.PatternLayoutEncoder by default -->
         <encoder>
-            <pattern>%d{dd-MMM-yyyy HH:mm:ss.SSS} %-5level [%thread] %logger{36} - %msg%n</pattern>
+            <pattern>%d %level  %msg%n</pattern>
         </encoder>
     </appender>
 
     <!-- the following line doesn't seem necessary, but it is needed for some reason  -->
-    <logger name="org.onap.policy.controlloop.tdjam" level="debug" additivity="false">
+    <logger name="org.onap.policy.controlloop.tdjam" level="info" additivity="false">
         <appender-ref ref="STDOUT" />
     </logger>
 
-    <root level="debug">
+    <root level="info">
         <appender-ref ref="STDOUT" />
     </root>
 </configuration>
diff --git a/controlloop/common/rules-test/pom.xml b/controlloop/common/rules-test/pom.xml
index c36eebb21..64f823ed5 100644
--- a/controlloop/common/rules-test/pom.xml
+++ b/controlloop/common/rules-test/pom.xml
@@ -110,7 +110,7 @@
         <dependency>
             <groupId>org.powermock</groupId>
             <artifactId>powermock-api-mockito2</artifactId>
-            <scope>test</scope>
+            <scope>provided</scope>
         </dependency>
         <dependency>
             <groupId>org.onap.policy.common</groupId>
diff --git a/controlloop/common/rules-test/src/main/java/org/onap/policy/controlloop/common/rules/test/BaseTest.java b/controlloop/common/rules-test/src/main/java/org/onap/policy/controlloop/common/rules/test/BaseTest.java
index 76048f534..f5346def8 100644
--- a/controlloop/common/rules-test/src/main/java/org/onap/policy/controlloop/common/rules/test/BaseTest.java
+++ b/controlloop/common/rules-test/src/main/java/org/onap/policy/controlloop/common/rules/test/BaseTest.java
@@ -23,11 +23,14 @@ package org.onap.policy.controlloop.common.rules.test;
 import static org.junit.Assert.assertEquals;
 
 import java.util.List;
+import java.util.Map;
 import java.util.UUID;
+import java.util.concurrent.TimeUnit;
 import java.util.function.Supplier;
 import java.util.stream.Collectors;
 import lombok.AccessLevel;
 import lombok.Getter;
+import org.awaitility.Awaitility;
 import org.junit.Test;
 import org.onap.policy.appc.Request;
 import org.onap.policy.appclcm.AppcLcmDmaapWrapper;
@@ -38,8 +41,12 @@ import org.onap.policy.common.utils.coder.StandardCoderInstantAsMillis;
 import org.onap.policy.controlloop.ControlLoopNotificationType;
 import org.onap.policy.controlloop.VirtualControlLoopNotification;
 import org.onap.policy.controlloop.eventmanager.ControlLoopEventManager2;
+import org.onap.policy.drools.system.PolicyEngineConstants;
+import org.onap.policy.drools.system.internal.SimpleLockManager;
+import org.onap.policy.drools.system.internal.SimpleLockManager.SimpleLock;
 import org.onap.policy.models.tosca.authorative.concepts.ToscaPolicy;
 import org.onap.policy.sdnr.PciMessage;
+import org.powermock.reflect.Whitebox;
 
 /**
  * Superclass used for rule tests.
@@ -162,6 +169,11 @@ public abstract class BaseTest {
      */
     public void init() {
         topics = topicMaker.get();
+
+        Map<String, SimpleLock> locks = getLockMap();
+        if (locks != null) {
+            locks.clear();
+        }
     }
 
     /**
@@ -207,6 +219,8 @@ public abstract class BaseTest {
         waitForOperationSuccess();
         /* --- Transaction Completed --- */
         waitForFinalSuccess(policy, policyClMgt);
+
+        verifyUnlocked();
     }
 
     // Duplicate events
@@ -259,6 +273,8 @@ public abstract class BaseTest {
 
         long added = getCreateCount() - initCount;
         assertEquals(2, added);
+
+        verifyUnlocked();
     }
 
     // VCPE
@@ -293,8 +309,8 @@ public abstract class BaseTest {
     }
 
     /**
-      * Vdns Rainy Day with Compliant Tosca Policy.
-      */
+     * Vdns Rainy Day with Compliant Tosca Policy.
+     */
     @Test
     public void testVdnsRainyDayCompliant() {
         httpRainyDay(VDNS_TOSCA_COMPLIANT_RAINY_POLICY, VDNS_ONSET);
@@ -396,6 +412,8 @@ public abstract class BaseTest {
 
         /* --- Transaction Completed --- */
         waitForFinalSuccess(policy, policyClMgt);
+
+        verifyUnlocked();
     }
 
     /**
@@ -434,6 +452,8 @@ public abstract class BaseTest {
 
         /* --- Transaction Completed --- */
         waitForFinalSuccess(policy, policyClMgt);
+
+        verifyUnlocked();
     }
 
     /**
@@ -442,7 +462,8 @@ public abstract class BaseTest {
      * @param policyFile file containing the ToscaPolicy to be loaded
      * @param onsetFile file containing the ONSET to be injected
      * @param operation expected APPC operation request
-     * @param checkOperation flag to determine whether or not to wait for operation timeout
+     * @param checkOperation flag to determine whether or not to wait for operation
+     *        timeout
      */
     protected void appcLegacyRainyDay(String policyFile, String onsetFile, String operation) {
         policyClMgt = createNoficationTopicListener();
@@ -472,11 +493,13 @@ public abstract class BaseTest {
 
         /* --- Transaction Completed --- */
         waitForFinalFailure(policy, policyClMgt);
+
+        verifyUnlocked();
     }
 
     /**
-     * Rainy day scenario for use cases that use Legacy APPC.
-     * Expected to fail due to timeout.
+     * Rainy day scenario for use cases that use Legacy APPC. Expected to fail due to
+     * timeout.
      *
      * @param policyFile file containing the ToscaPolicy to be loaded
      * @param onsetFile file containing the ONSET to be injected
@@ -505,6 +528,8 @@ public abstract class BaseTest {
 
         /* --- Transaction Completed --- */
         waitForFinalFailure(policy, policyClMgt);
+
+        verifyUnlocked();
     }
 
     /**
@@ -542,6 +567,8 @@ public abstract class BaseTest {
 
         /* --- Transaction Completed --- */
         waitForFinalSuccess(policy, policyClMgt);
+
+        verifyUnlocked();
     }
 
     /**
@@ -568,6 +595,8 @@ public abstract class BaseTest {
 
         /* --- Transaction Completed --- */
         waitForFinalSuccess(policy, policyClMgt);
+
+        verifyUnlocked();
     }
 
     /**
@@ -593,6 +622,8 @@ public abstract class BaseTest {
 
         /* --- Transaction Completed --- */
         waitForFinalFailure(policy, policyClMgt);
+
+        verifyUnlocked();
     }
 
     protected long getCreateCount() {
@@ -658,7 +689,7 @@ public abstract class BaseTest {
      * @param fileName a path name
      * @return ToscaPolicy
      */
-    protected ToscaPolicy checkPolicy(String fileName)  {
+    protected ToscaPolicy checkPolicy(String fileName) {
         try {
             return Rules.getPolicyFromFile(fileName);
         } catch (CoderException e) {
@@ -673,16 +704,35 @@ public abstract class BaseTest {
     public static class PolicyClMgtCoder extends StandardCoder {
         public PolicyClMgtCoder() {
             super(org.onap.policy.controlloop.util.Serialization.gson,
-                  org.onap.policy.controlloop.util.Serialization.gsonPretty);
+                            org.onap.policy.controlloop.util.Serialization.gsonPretty);
         }
     }
 
     /**
      * Returns Listener from createListner based on Coder.
+     *
      * @return the Listener
      */
     protected Listener<VirtualControlLoopNotification> createNoficationTopicListener() {
-        return topics.createListener(POLICY_CL_MGT_TOPIC,
-            VirtualControlLoopNotification.class, POLICY_CL_MGT_CODER);
+        return topics.createListener(POLICY_CL_MGT_TOPIC, VirtualControlLoopNotification.class, POLICY_CL_MGT_CODER);
+    }
+
+    /**
+     * Verifies that all locks have been released, waiting a bit, if necessary.
+     */
+    private void verifyUnlocked() {
+        Map<String, SimpleLock> locks = getLockMap();
+        if (locks != null) {
+            Awaitility.await().atMost(5, TimeUnit.SECONDS).until(locks::isEmpty);
+        }
+    }
+
+    private Map<String, SimpleLock> getLockMap() {
+        Object lockMgr = Whitebox.getInternalState(PolicyEngineConstants.getManager(), "lockManager");
+        if (lockMgr instanceof SimpleLockManager) {
+            return Whitebox.getInternalState(lockMgr, "resource2lock");
+        }
+
+        return null;
     }
 }