From 4ae3037fc405da861ef7041fe902a61f752e8b84 Mon Sep 17 00:00:00 2001
From: pkupczyk <pkupczyk>
Date: Tue, 27 Aug 2013 10:09:38 +0000
Subject: [PATCH] SP-824 / BIS-518 : Logs - improve logging of service calls

SVN: 29679
---
 .../cisd/common/utilities/TestResources.java  | 45 +++++++++++
 .../common/controlfile/ControlFileReader.java | 70 +++++++++++++++++
 .../spring/IInvocationLoggerContext.java      |  8 +-
 .../openbis/common/spring/LogInterceptor.java | 25 +++++-
 .../controlfile/ControlFileReaderTest.java    | 77 +++++++++++++++++++
 .../generic/shared/AbstractServerLogger.java  | 34 +++++---
 .../systemtest/server/CommonServerTest.java   | 26 ++-----
 7 files changed, 250 insertions(+), 35 deletions(-)
 create mode 100644 common/sourceTest/java/ch/systemsx/cisd/common/utilities/TestResources.java
 create mode 100644 openbis-common/source/java/ch/systemsx/cisd/openbis/common/controlfile/ControlFileReader.java
 create mode 100644 openbis-common/sourceTest/java/ch/systemsx/cisd/openbis/common/controlfile/ControlFileReaderTest.java

diff --git a/common/sourceTest/java/ch/systemsx/cisd/common/utilities/TestResources.java b/common/sourceTest/java/ch/systemsx/cisd/common/utilities/TestResources.java
new file mode 100644
index 00000000000..f17db7c0bbc
--- /dev/null
+++ b/common/sourceTest/java/ch/systemsx/cisd/common/utilities/TestResources.java
@@ -0,0 +1,45 @@
+/*
+ * Copyright 2013 ETH Zuerich, CISD
+ *
+ * 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 ch.systemsx.cisd.common.utilities;
+
+import java.io.File;
+
+/**
+ * @author pkupczyk
+ */
+public class TestResources
+{
+
+    private Class<?> testClass;
+
+    public TestResources(Class<?> testClass)
+    {
+        this.testClass = testClass;
+    }
+
+    public File getResourcesDirectory()
+    {
+        return new File("sourceTest/java/"
+                + testClass.getName().replace(".", "/") + "Resources" + "/");
+    }
+
+    public File getResourceFile(String fileName)
+    {
+        return new File(getResourcesDirectory(), fileName);
+    }
+
+}
diff --git a/openbis-common/source/java/ch/systemsx/cisd/openbis/common/controlfile/ControlFileReader.java b/openbis-common/source/java/ch/systemsx/cisd/openbis/common/controlfile/ControlFileReader.java
new file mode 100644
index 00000000000..b0b1cc71dab
--- /dev/null
+++ b/openbis-common/source/java/ch/systemsx/cisd/openbis/common/controlfile/ControlFileReader.java
@@ -0,0 +1,70 @@
+/*
+ * Copyright 2013 ETH Zuerich, CISD
+ *
+ * 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 ch.systemsx.cisd.openbis.common.controlfile;
+
+import java.io.File;
+
+import ch.systemsx.cisd.common.filesystem.control.DelayingDecorator;
+import ch.systemsx.cisd.common.filesystem.control.FileSystemBasedEventProvider;
+import ch.systemsx.cisd.common.filesystem.control.IValueFilter;
+import ch.systemsx.cisd.common.filesystem.control.ParameterMap;
+
+/**
+ * @author pkupczyk
+ */
+public class ControlFileReader
+{
+
+    private static final String CONTROL_FILE_DIRECTORY = ".control";
+
+    private static final long CONTROL_FILE_MAX_DELAY = 10 * 1000L;
+
+    private static final String LOG_SERVICE_CALL_START = "log-service-call-start";
+
+    private static final String ON = "on";
+
+    private static final String OFF = "off";
+
+    private ParameterMap parameterMap;
+
+    public ControlFileReader()
+    {
+        this(new File(CONTROL_FILE_DIRECTORY), CONTROL_FILE_MAX_DELAY);
+    }
+
+    public ControlFileReader(File controlFileDirectory, long controlFileMaxDelay)
+    {
+        parameterMap =
+                new ParameterMap(new DelayingDecorator(controlFileMaxDelay, new FileSystemBasedEventProvider(controlFileDirectory)));
+        parameterMap.addParameter(LOG_SERVICE_CALL_START, OFF, new IValueFilter()
+            {
+
+                @Override
+                public boolean isValid(String value)
+                {
+                    return ON.equalsIgnoreCase(value) || OFF.equalsIgnoreCase(value);
+                }
+            });
+    }
+
+    public boolean isLogServiceCallStartEnabled()
+    {
+        String value = parameterMap.get(LOG_SERVICE_CALL_START);
+        return ON.equalsIgnoreCase(value);
+    }
+
+}
diff --git a/openbis-common/source/java/ch/systemsx/cisd/openbis/common/spring/IInvocationLoggerContext.java b/openbis-common/source/java/ch/systemsx/cisd/openbis/common/spring/IInvocationLoggerContext.java
index 0a49b85d7c0..9ef9796e404 100644
--- a/openbis-common/source/java/ch/systemsx/cisd/openbis/common/spring/IInvocationLoggerContext.java
+++ b/openbis-common/source/java/ch/systemsx/cisd/openbis/common/spring/IInvocationLoggerContext.java
@@ -17,15 +17,15 @@
 package ch.systemsx.cisd.openbis.common.spring;
 
 /**
- * 
- *
  * @author Franz-Josef Elmer
  */
 public interface IInvocationLoggerContext
 {
     public String tryToGetSessionToken();
-    
+
+    public boolean invocationFinished();
+
     public boolean invocationWasSuccessful();
-    
+
     public long getElapsedTime();
 }
diff --git a/openbis-common/source/java/ch/systemsx/cisd/openbis/common/spring/LogInterceptor.java b/openbis-common/source/java/ch/systemsx/cisd/openbis/common/spring/LogInterceptor.java
index 7dac23abfbf..86be8f0fd01 100644
--- a/openbis-common/source/java/ch/systemsx/cisd/openbis/common/spring/LogInterceptor.java
+++ b/openbis-common/source/java/ch/systemsx/cisd/openbis/common/spring/LogInterceptor.java
@@ -27,6 +27,7 @@ import org.apache.log4j.Logger;
 import ch.systemsx.cisd.common.logging.LogCategory;
 import ch.systemsx.cisd.common.logging.LogFactory;
 import ch.systemsx.cisd.common.reflection.MethodUtils;
+import ch.systemsx.cisd.openbis.common.controlfile.ControlFileReader;
 
 /**
  * Interceptor for objects which provide their own logger.
@@ -39,6 +40,8 @@ public final class LogInterceptor implements MethodInterceptor, Serializable
     {
         private final String sessionToken;
 
+        boolean invocationFinished;
+
         boolean invocationSuccessful;
 
         long elapsedTime;
@@ -54,6 +57,12 @@ public final class LogInterceptor implements MethodInterceptor, Serializable
             return sessionToken;
         }
 
+        @Override
+        public boolean invocationFinished()
+        {
+            return invocationFinished;
+        }
+
         @Override
         public boolean invocationWasSuccessful()
         {
@@ -70,6 +79,13 @@ public final class LogInterceptor implements MethodInterceptor, Serializable
 
     private static final long serialVersionUID = 1L;
 
+    private ControlFileReader controlFileReader;
+
+    public LogInterceptor()
+    {
+        controlFileReader = new ControlFileReader();
+    }
+
     //
     // MethodInterceptor
     //
@@ -90,12 +106,19 @@ public final class LogInterceptor implements MethodInterceptor, Serializable
         InvocationLoggerContext invocationLoggerContext =
                 new InvocationLoggerContext(sessionTokenOrNull);
         final Object logger = loggerFactory.createLogger(invocationLoggerContext);
+        final Method method = invocation.getMethod();
 
         StopWatch timer = new StopWatch();
 
         try
         {
             timer.start();
+
+            if (controlFileReader.isLogServiceCallStartEnabled())
+            {
+                method.invoke(logger, arguments);
+            }
+
             final Object result = invocation.proceed();
             invocationLoggerContext.invocationSuccessful = true;
             return result;
@@ -106,8 +129,8 @@ public final class LogInterceptor implements MethodInterceptor, Serializable
         } finally
         {
             timer.stop();
+            invocationLoggerContext.invocationFinished = true;
             invocationLoggerContext.elapsedTime = timer.getTime();
-            final Method method = invocation.getMethod();
             try
             {
                 method.invoke(logger, arguments);
diff --git a/openbis-common/sourceTest/java/ch/systemsx/cisd/openbis/common/controlfile/ControlFileReaderTest.java b/openbis-common/sourceTest/java/ch/systemsx/cisd/openbis/common/controlfile/ControlFileReaderTest.java
new file mode 100644
index 00000000000..256d8ff23e4
--- /dev/null
+++ b/openbis-common/sourceTest/java/ch/systemsx/cisd/openbis/common/controlfile/ControlFileReaderTest.java
@@ -0,0 +1,77 @@
+/*
+ * Copyright 2013 ETH Zuerich, CISD
+ *
+ * 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 ch.systemsx.cisd.openbis.common.controlfile;
+
+import java.io.File;
+import java.io.IOException;
+
+import org.testng.Assert;
+import org.testng.annotations.AfterTest;
+import org.testng.annotations.BeforeMethod;
+import org.testng.annotations.Test;
+
+import ch.systemsx.cisd.common.filesystem.FileUtilities;
+import ch.systemsx.cisd.common.utilities.TestResources;
+
+/**
+ * @author pkupczyk
+ */
+public class ControlFileReaderTest
+{
+
+    @BeforeMethod
+    public void beforeMethod()
+    {
+        deleteControlFileDirectory();
+        getControlFileDirectory().mkdirs();
+    }
+
+    @AfterTest
+    public void afterTest()
+    {
+        deleteControlFileDirectory();
+    }
+
+    @Test
+    public void test() throws IOException
+    {
+        ControlFileReader reader = new ControlFileReader(getControlFileDirectory(), -1);
+        Assert.assertFalse(reader.isLogServiceCallStartEnabled());
+
+        new File(getControlFileDirectory(), "log-service-call-start-on").createNewFile();
+        Assert.assertTrue(reader.isLogServiceCallStartEnabled());
+
+        new File(getControlFileDirectory(), "log-service-call-start-off").createNewFile();
+        Assert.assertFalse(reader.isLogServiceCallStartEnabled());
+    }
+
+    private File getControlFileDirectory()
+    {
+        TestResources resources = new TestResources(getClass());
+        return resources.getResourcesDirectory();
+    }
+
+    private void deleteControlFileDirectory()
+    {
+        File directory = getControlFileDirectory();
+        if (directory.exists())
+        {
+            FileUtilities.deleteRecursively(directory);
+        }
+    }
+
+}
diff --git a/openbis/source/java/ch/systemsx/cisd/openbis/generic/shared/AbstractServerLogger.java b/openbis/source/java/ch/systemsx/cisd/openbis/generic/shared/AbstractServerLogger.java
index b8f77d729ea..f04520d1431 100644
--- a/openbis/source/java/ch/systemsx/cisd/openbis/generic/shared/AbstractServerLogger.java
+++ b/openbis/source/java/ch/systemsx/cisd/openbis/generic/shared/AbstractServerLogger.java
@@ -197,15 +197,29 @@ public abstract class AbstractServerLogger implements IServer
             }
         }
         final String message = String.format(parameterDisplayFormat, parameters);
-        final String invocationStatusMessage = getInvocationStatusMessage();
-        final String elapsedTimeMessage = getElapsedTimeMessage();
-        // We put on purpose 2 spaces between the command and the message derived from the
-        // parameters.
-        logger.log(
-                level,
-                tryToCreatePrefixSecondTime(sessionToken)
-                        + String.format(": (%s) %s  %s%s", elapsedTimeMessage, commandName,
-                                message, invocationStatusMessage));
+
+        if (context.invocationFinished())
+        {
+            final String invocationStatusMessage = getInvocationStatusMessage();
+            final String elapsedTimeMessage = getElapsedTimeMessage();
+
+            // We put on purpose 2 spaces between the command and the message derived from the
+            // parameters.
+            logger.log(
+                    level,
+                    tryToCreatePrefixSecondTime(sessionToken)
+                            + String.format(": (%s) %s  %s%s", elapsedTimeMessage, commandName,
+                                    message, invocationStatusMessage));
+        } else
+        {
+            // We put on purpose 2 spaces between the command and the message derived from the
+            // parameters.
+            logger.log(
+                    level,
+                    tryToCreatePrefixSecondTime(sessionToken)
+                            + String.format(": (START) %s  %s", commandName,
+                                    message));
+        }
     }
 
     private String getInvocationStatusMessage()
@@ -348,7 +362,7 @@ public abstract class AbstractServerLogger implements IServer
     public void setSessionUser(String sessionToken, String userID)
     {
         logMessage(authLog, Level.INFO, sessionToken, "set_session_user", "USER(%s)", new Object[]
-            { userID });
+        { userID });
     }
 
     public int unarchiveDatasets(String sessionToken, List<String> datasetCodes)
diff --git a/openbis/sourceTest/java/ch/systemsx/cisd/openbis/systemtest/server/CommonServerTest.java b/openbis/sourceTest/java/ch/systemsx/cisd/openbis/systemtest/server/CommonServerTest.java
index 0eb5a87c075..23c0e0e8489 100644
--- a/openbis/sourceTest/java/ch/systemsx/cisd/openbis/systemtest/server/CommonServerTest.java
+++ b/openbis/sourceTest/java/ch/systemsx/cisd/openbis/systemtest/server/CommonServerTest.java
@@ -16,17 +16,14 @@
 
 package ch.systemsx.cisd.openbis.systemtest.server;
 
-import java.io.File;
-import java.io.FileInputStream;
-import java.io.IOException;
-
 import junit.framework.Assert;
 
-import org.apache.commons.io.IOUtils;
 import org.testng.annotations.AfterMethod;
 import org.testng.annotations.BeforeMethod;
 import org.testng.annotations.Test;
 
+import ch.systemsx.cisd.common.filesystem.FileUtilities;
+import ch.systemsx.cisd.common.utilities.TestResources;
 import ch.systemsx.cisd.openbis.generic.shared.basic.dto.EntityKind;
 import ch.systemsx.cisd.openbis.generic.shared.basic.dto.EntityValidationEvaluationInfo;
 import ch.systemsx.cisd.openbis.generic.shared.basic.dto.PluginType;
@@ -172,9 +169,10 @@ public class CommonServerTest extends SystemTestCase
 
     private void testAdaptorCommon(EntityKind entityKind, String entityIdentifier, String scriptName)
     {
-        String script =
-                getResourceAsString("common_adaptor_test.py") + "\n"
-                        + getResourceAsString(scriptName);
+        TestResources resources = new TestResources(getClass());
+        String commonScript = FileUtilities.loadToString(resources.getResourceFile("common_adaptor_test.py"));
+        String specificScript = FileUtilities.loadToString(resources.getResourceFile(scriptName));
+        String script = commonScript + "\n" + specificScript;
 
         EntityValidationEvaluationInfo info =
                 new EntityValidationEvaluationInfo(entityKind, entityIdentifier, false,
@@ -184,16 +182,4 @@ public class CommonServerTest extends SystemTestCase
         Assert.assertEquals("Validation OK", result);
     }
 
-    private String getResourceAsString(String fileName)
-    {
-        try
-        {
-            return IOUtils.toString(new FileInputStream(new File("sourceTest/java/"
-                    + getClass().getName().replace(".", "/") + "Resources" + "/" + fileName)));
-        } catch (IOException ex)
-        {
-            throw new RuntimeException(ex);
-        }
-    }
-
 }
\ No newline at end of file
-- 
GitLab