[Storage] Log test method entry and exit. (Azure#23853)

* Log test method entry and exit. * pr feedback.
luishiga · Aug 31, 2021 · f3920a2 · f3920a2
1 parent 22d1324
commit f3920a2
Showing 1 changed file with 12 additions and 4 deletions.
diff --git a/...test-shared/java/com/azure/storage/common/test/shared/extensions/TestHeaderExtension.java b/...test-shared/java/com/azure/storage/common/test/shared/extensions/TestHeaderExtension.java
@@ -3,6 +3,7 @@
 
 package com.azure.storage.common.test.shared.extensions;
 
+import com.azure.core.util.logging.ClientLogger;
 import com.azure.storage.common.test.shared.TestNameProvider;
 import org.spockframework.runtime.extension.AbstractGlobalExtension;
 import org.spockframework.runtime.extension.IMethodInterceptor;
@@ -11,6 +12,8 @@
 
 public final class TestHeaderExtension extends AbstractGlobalExtension {
 
+    private static final ClientLogger LOGGER = new ClientLogger(TestHeaderExtension.class);
+
     @Override
     public void visitSpec(SpecInfo specInfo) {
         specInfo.getAllFeatures().forEach(feature ->
@@ -19,14 +22,19 @@ public void visitSpec(SpecInfo specInfo) {
 
     private static class TestHeaderIterationInterceptor implements IMethodInterceptor {
         @Override
-        public void intercept(IMethodInvocation invocation) {
+        public void intercept(IMethodInvocation invocation) throws Throwable {
             // Print out the test name to create breadcrumbs in our test logging in case anything hangs.
             String testName = TestNameProvider.getTestName(invocation.getIteration());
-            System.out.printf("========================= %s =========================%n", testName);
+            System.out.printf("%s is starting%n", testName);
+            LOGGER.info("{} is starting", testName);
+            long startTimestamp = System.currentTimeMillis();
+
             try {
                 invocation.proceed();
-            } catch (Throwable throwable) {
-                throwable.printStackTrace();
+            } finally {
+                long duration = System.currentTimeMillis() - startTimestamp;
+                System.out.printf("%s finished and took %d ms%n", testName, duration);
+                LOGGER.info("{} finished and took {} ms", testName, duration);
             }
         }
     }