Add logger to python code

Change-Id: I526059b2a18685dbb978c0776cc728bbbd90e9cd
Issue-ID: CCSDK-1164
Signed-off-by: Alexis de Talhouët <adetalhouet89@gmail.com>

6 files changed, 101 insertions, 59 deletions

diff --git a/ms/command-executor/src/main/docker/Dockerfile b/ms/command-executor/src/main/docker/Dockerfile
index 1137de168..50f592dd6 100644
--- a/ms/command-executor/src/main/docker/Dockerfile
+++ b/ms/command-executor/src/main/docker/Dockerfile
@@ -8,13 +8,14 @@ RUN pip install virtualenv
 COPY start.sh /opt/app/onap/start.sh
 RUN chmod u+x /opt/app/onap/start.sh
 
+RUN mkdir -p /opt/app/onap/logs/ && touch /opt/app/onap/logs/application.log
+
 COPY @project.build.finalName@-@assembly.id@.tar.gz /source.tar.gz
 RUN tar -xzf /source.tar.gz -C /tmp \
  && cp -rf /tmp/@project.build.finalName@/opt / \
  && rm -rf /source.tar.gz \
  && rm -rf /tmp/@project.build.finalName@
 
-
 VOLUME /opt/app/onap/blueprints/deploy/
 
 ENTRYPOINT /opt/app/onap/start.sh
\ No newline at end of file
diff --git a/ms/command-executor/src/main/docker/start.sh b/ms/command-executor/src/main/docker/start.sh
index 0dbd7e8f3..659038418 100755
--- a/ms/command-executor/src/main/docker/start.sh
+++ b/ms/command-executor/src/main/docker/start.sh
@@ -29,4 +29,4 @@ then
 fi
 
 cd /opt/app/onap/python/
-python command_executor_server.py ${APP_PORT} ${BASIC_AUTH}
\ No newline at end of file
+python server.py ${APP_PORT} ${BASIC_AUTH}
\ No newline at end of file
diff --git a/ms/command-executor/src/main/python/command_executor_handler.py b/ms/command-executor/src/main/python/command_executor_handler.py
index 3027859b3..4ae575b0f 100644
--- a/ms/command-executor/src/main/python/command_executor_handler.py
+++ b/ms/command-executor/src/main/python/command_executor_handler.py
@@ -13,7 +13,7 @@
 # See the License for the specific language governing permissions and
 # limitations under the License.
 #
-
+import logging
 import os
 import subprocess
 import virtualenv
@@ -27,6 +27,7 @@ import utils
 class CommandExecutorHandler:
 
     def __init__(self, request):
+        self.logger = logging.getLogger(self.__class__.__name__)
         self.blueprint_id = utils.get_blueprint_id(request)
         self.venv_home = '/opt/app/onap/blueprints/deploy/' + self.blueprint_id
 
@@ -49,7 +50,7 @@ class CommandExecutorHandler:
         try:
             results.append(os.popen(request.command).read())
         except Exception as e:
-            print("{} - Failed to execute command. Error: {}".format(self.blueprint_id, e))
+            self.logger.info("{} - Failed to execute command. Error: {}".format(self.blueprint_id, e))
             results.append(e)
             return False
 
@@ -57,10 +58,11 @@ class CommandExecutorHandler:
         return True
 
     def install(self, package, results):
-        print("{} - Install package({}) in Python Virtual Environment".format(self.blueprint_id, package))
+        self.logger.info("{} - Install package({}) in Python Virtual Environment".format(self.blueprint_id, package))
         command = ["pip", "install", package]
 
         env = dict(os.environ)
+        # fixme - parameterize
         # env['https_proxy'] = "https://fastweb.int.bell.ca:8083"
 
         try:
@@ -71,30 +73,33 @@ class CommandExecutorHandler:
             return False
 
     def create_venv(self):
-        print("{} - Create Python Virtual Environment".format(self.blueprint_id))
+        self.logger.info("{} - Create Python Virtual Environment".format(self.blueprint_id))
         try:
             bin_dir = self.venv_home + "/bin"
             # venv doesn't populate the activate_this.py script, hence we use from virtualenv
             venv.create(self.venv_home, with_pip=True, system_site_packages=True)
             virtualenv.writefile(os.path.join(bin_dir, "activate_this.py"), virtualenv.ACTIVATE_THIS)
         except Exception as err:
-            print("{} - Failed to provision Python Virtual Environment. Error: {}".format(self.blueprint_id, err))
+            self.logger.info(
+                "{} - Failed to provision Python Virtual Environment. Error: {}".format(self.blueprint_id, err))
 
     def activate_venv(self):
-        print("{} - Activate Python Virtual Environment".format(self.blueprint_id))
+        self.logger.info("{} - Activate Python Virtual Environment".format(self.blueprint_id))
 
         path = "%s/bin/activate_this.py" % self.venv_home
         try:
             exec (open(path).read(), {'__file__': path})
             return True
         except Exception as err:
-            print("{} - Failed to activate Python Virtual Environment. Error: {}".format(self.blueprint_id, err))
+            self.logger.info(
+                "{} - Failed to activate Python Virtual Environment. Error: {}".format(self.blueprint_id, err))
             return False
 
     def deactivate_venv(self):
-        print("{} - Deactivate Python Virtual Environment".format(self.blueprint_id))
+        self.logger.info("{} - Deactivate Python Virtual Environment".format(self.blueprint_id))
         command = ["deactivate"]
         try:
             subprocess.run(command, check=True)
         except Exception as err:
-            print("{} - Failed to deactivate Python Virtual Environment. Error: {}".format(self.blueprint_id, err))
+            self.logger.info(
+                "{} - Failed to deactivate Python Virtual Environment. Error: {}".format(self.blueprint_id, err))
diff --git a/ms/command-executor/src/main/python/command_executor_server.py b/ms/command-executor/src/main/python/command_executor_server.py
index b62f15011..3596a0ec5 100644
--- a/ms/command-executor/src/main/python/command_executor_server.py
+++ b/ms/command-executor/src/main/python/command_executor_server.py
@@ -15,16 +15,10 @@
 # See the License for the specific language governing permissions and
 # limitations under the License.
 #
-from builtins import KeyboardInterrupt
-from concurrent import futures
-import time
-import sys
-
-import grpc
+import logging
 
 import proto.CommandExecutor_pb2_grpc as CommandExecutor_pb2_grpc
 
-from request_header_validator_interceptor import RequestHeaderValidatorInterceptor
 from command_executor_handler import CommandExecutorHandler
 import utils
 
@@ -33,59 +27,31 @@ _ONE_DAY_IN_SECONDS = 60 * 60 * 24
 
 class CommandExecutorServer(CommandExecutor_pb2_grpc.CommandExecutorServiceServicer):
 
+    def __init__(self):
+        self.logger = logging.getLogger(self.__class__.__name__)
+
     def prepareEnv(self, request, context):
         blueprint_id = utils.get_blueprint_id(request)
-        print("{} - Received prepareEnv request".format(blueprint_id))
-        print (request)
+        self.logger.info("{} - Received prepareEnv request".format(blueprint_id))
+        self.logger.info(request)
 
         results = []
         handler = CommandExecutorHandler(request)
         if not handler.prepare_env(request, results):
-            print("{} - Failed to prepare python environment. {}".format(blueprint_id, results))
+            self.logger.info("{} - Failed to prepare python environment. {}".format(blueprint_id, results))
             return utils.build_response(request, results, False)
-        print("{} - Package installation logs {}".format(blueprint_id, results))
+        self.logger.info("{} - Package installation logs {}".format(blueprint_id, results))
         return utils.build_response(request, results)
 
     def executeCommand(self, request, context):
         blueprint_id = utils.get_blueprint_id(request)
-        print("{} - Received executeCommand request".format(blueprint_id))
-        print(request)
+        self.logger.info("{} - Received executeCommand request".format(blueprint_id))
+        self.logger.info(request)
 
         results = []
         handler = CommandExecutorHandler(request)
         if not handler.execute_command(request, results):
-            print("{} - Failed to executeCommand. {}".format(blueprint_id, results))
+            self.logger.info("{} - Failed to executeCommand. {}".format(blueprint_id, results))
             return utils.build_response(request, results, False)
-        print("{} - Execute command logs: {}".format(blueprint_id, results))
+        self.logger.info("{} - Execute command logs: {}".format(blueprint_id, results))
         return utils.build_response(request, results)
-
-
-def serve():
-    port = sys.argv[1]
-    basic_auth = sys.argv[2] + ' ' + sys.argv[3]
-
-    header_validator = RequestHeaderValidatorInterceptor(
-        'authorization', basic_auth, grpc.StatusCode.UNAUTHENTICATED,
-        'Access denied!')
-
-    server = grpc.server(
-        futures.ThreadPoolExecutor(max_workers=10),
-        interceptors=(header_validator,))
-
-    CommandExecutor_pb2_grpc.add_CommandExecutorServiceServicer_to_server(
-        CommandExecutorServer(), server)
-
-    server.add_insecure_port('[::]:' + port)
-    server.start()
-
-    print("Command Executor Server started on %s" % port)
-
-    try:
-        while True:
-            time.sleep(_ONE_DAY_IN_SECONDS)
-    except KeyboardInterrupt:
-        server.stop(0)
-
-
-if __name__ == '__main__':
-    serve()
diff --git a/ms/command-executor/src/main/python/server.py b/ms/command-executor/src/main/python/server.py
new file mode 100644
index 000000000..de620474b
--- /dev/null
+++ b/ms/command-executor/src/main/python/server.py
@@ -0,0 +1,72 @@
+#!/usr/bin/python
+
+#
+# Copyright (C) 2019 Bell Canada.
+#
+# 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.
+#
+from builtins import KeyboardInterrupt
+from concurrent import futures
+import logging
+import time
+import sys
+
+import grpc
+
+import proto.CommandExecutor_pb2_grpc as CommandExecutor_pb2_grpc
+
+from request_header_validator_interceptor import RequestHeaderValidatorInterceptor
+from command_executor_server import CommandExecutorServer
+
+logger = logging.getLogger("Server")
+
+_ONE_DAY_IN_SECONDS = 60 * 60 * 24
+
+
+def serve():
+    port = sys.argv[1]
+    basic_auth = sys.argv[2] + ' ' + sys.argv[3]
+
+    header_validator = RequestHeaderValidatorInterceptor(
+        'authorization', basic_auth, grpc.StatusCode.UNAUTHENTICATED,
+        'Access denied!')
+
+    server = grpc.server(
+        futures.ThreadPoolExecutor(max_workers=10),
+        interceptors=(header_validator,))
+
+    CommandExecutor_pb2_grpc.add_CommandExecutorServiceServicer_to_server(
+        CommandExecutorServer(), server)
+
+    server.add_insecure_port('[::]:' + port)
+    server.start()
+
+    logger.info("Command Executor Server started on %s" % port)
+
+    try:
+        while True:
+            time.sleep(_ONE_DAY_IN_SECONDS)
+    except KeyboardInterrupt:
+        server.stop(0)
+
+
+if __name__ == '__main__':
+    logging_formater = '%(asctime)s - %(name)s - %(threadName)s - %(levelname)s - %(message)s'
+    logging.basicConfig(filename='/opt/app/onap/logs/application.log', level=logging.DEBUG,
+                        format=logging_formater)
+    console = logging.StreamHandler()
+    console.setLevel(logging.INFO)
+    formatter = logging.Formatter(logging_formater)
+    console.setFormatter(formatter)
+    logging.getLogger('').addHandler(console)
+    serve()
diff --git a/ms/command-executor/src/main/python/utils.py b/ms/command-executor/src/main/python/utils.py
index b0013b996..6260997f3 100644
--- a/ms/command-executor/src/main/python/utils.py
+++ b/ms/command-executor/src/main/python/utils.py
@@ -13,8 +13,6 @@
 # See the License for the specific language governing permissions and
 # limitations under the License.
 #
-from builtins import map, bytes
-
 from google.protobuf.timestamp_pb2 import Timestamp
 
 import proto.CommandExecutor_pb2 as CommandExecutor_pb2