Add logging setup for receiverd and assassind

Since all services inside containers are now started via systemd we need
add logging handling which in past was done by supervisord. Thus such
settings are added for rpc receiver and assassin services. Loggers are
set up independently from nailgun root logger as writing to files are
required for mentioned components.

Change-Id: I21136108d426531f572940dfc9f75fe153111d41
Partial-Bug: #1523476

nailgun/nailgun/assassin/assassind.py

@@ -29,11 +29,12 @@ from nailgun import notifier
 
 from nailgun.db import db
 from nailgun.db.sqlalchemy.models import Node
-from nailgun.logger import logger
 from nailgun.settings import settings
 
+from nailgun.utils import logs
 
-def update_nodes_status(timeout):
+
+def update_nodes_status(timeout, logger):
     to_update = db().query(Node).filter(
         not_(Node.status == 'provisioning')
     ).filter(
@@ -54,10 +55,12 @@ def update_nodes_status(timeout):
 
 
 def run():
+    logger = logs.prepare_submodule_logger('assassin',
+                                           settings.ASSASSIN_LOG_PATH)
     logger.info('Running Assassind...')
     try:
         while True:
-            update_nodes_status(settings.KEEPALIVE['timeout'])
+            update_nodes_status(settings.KEEPALIVE['timeout'], logger)
             time.sleep(settings.KEEPALIVE['interval'])
     except (KeyboardInterrupt, SystemExit):
         logger.info('Stopping Assassind...')

nailgun/nailgun/logger.py

@@ -27,14 +27,18 @@ LOGFORMAT = '%(asctime)s.%(msecs)03d %(levelname)s ' + \
             '[%(thread)x] (%(module)s) %(message)s'
 formatter = logging.Formatter(LOGFORMAT, DATEFORMAT)
 
+# NOTE(aroma): the logging level for nailgun is set up inside
+# nailgun settings parsing object in nailgun.settings module hence
+# following option will be in effect only when the settings are not
+# available for some reason
+LOG_LEVEL = logging.DEBUG
+
 
 def make_nailgun_logger():
     """Make logger for nailgun app writes logs to stdout"""
     logger = logging.getLogger("nailgun")
-    logger.setLevel(logging.DEBUG)
     handler = logging.StreamHandler(sys.stdout)
-    handler.setFormatter(formatter)
-    logger.addHandler(handler)
+    set_logger(logger, handler)
     return logger
 
 
@@ -46,12 +50,20 @@ def make_api_logger():
 
     logger = logging.getLogger("nailgun-api")
     log_file = WatchedFileHandler(settings.API_LOG)
-    log_file.setFormatter(formatter)
-    logger.setLevel(logging.DEBUG)
-    logger.addHandler(log_file)
+    set_logger(logger, log_file)
     return logger
 
 
+def set_logger(logger, handler, level=None):
+    if level is None:
+        level = LOG_LEVEL
+
+    handler.setFormatter(formatter)
+
+    logger.setLevel(level)
+    logger.addHandler(handler)
+
+
 logger = make_nailgun_logger()
 
 

nailgun/nailgun/rpc/__init__.py

@@ -14,6 +14,7 @@
 #    License for the specific language governing permissions and limitations
 #    under the License.
 
+import logging
 import six
 import functools
 
@@ -23,10 +24,16 @@ from kombu import Exchange
 from oslo_serialization import jsonutils
 from kombu import Queue
 
-from nailgun.logger import logger
 from nailgun.settings import settings
 from nailgun.rpc import utils
 
+from nailgun.utils import logs
+
+
+logger = logs.prepare_submodule_logger('receiverd',
+                                       settings.RPC_CONSUMER_LOG_PATH)
+
+
 creds = (
     ("userid", "guest"),
     ("password", "guest"),

nailgun/nailgun/rpc/receiver.py

@@ -18,6 +18,7 @@ import collections
 import copy
 import datetime
 import itertools
+import logging
 import os
 import six
 import traceback
@@ -36,7 +37,6 @@ from nailgun.db import db
 from nailgun.db.sqlalchemy.models import IPAddr
 from nailgun.db.sqlalchemy.models import Node
 from nailgun.db.sqlalchemy.models import Release
-from nailgun.logger import logger
 from nailgun.network import connectivity_check
 from nailgun.network import utils as net_utils
 from nailgun.objects.plugin import ClusterPlugins
@@ -45,6 +45,9 @@ from nailgun.utils import logs as logs_utils
 from nailgun.utils import reverse
 
 
+logger = logging.getLogger('receiverd')
+
+
 class NailgunReceiver(object):
 
     @classmethod

nailgun/nailgun/rpc/receiverd.py

@@ -14,6 +14,7 @@
 #    License for the specific language governing permissions and limitations
 #    under the License.
 
+import logging
 import os
 import sys
 
@@ -30,12 +31,14 @@ import amqp.exceptions as amqp_exceptions
 
 from nailgun.db import db
 from nailgun.errors import errors
-from nailgun.logger import logger
 import nailgun.rpc as rpc
 from nailgun.rpc.receiver import NailgunReceiver
 from nailgun.rpc import utils
 
 
+logger = logging.getLogger('receiverd')
+
+
 class RPCConsumer(ConsumerMixin):
 
     def __init__(self, connection, receiver):

nailgun/nailgun/rpc/threaded.py

@@ -14,6 +14,7 @@
 #    License for the specific language governing permissions and limitations
 #    under the License.
 
+import logging
 import threading
 import traceback
 
@@ -22,11 +23,13 @@ from kombu.mixins import ConsumerMixin
 
 from nailgun.db import db
 from nailgun.errors import errors
-from nailgun.logger import logger
 import nailgun.rpc as rpc
 from nailgun.rpc.receiver import NailgunReceiver
 
 
+logger = logging.getLogger('receiverd')
+
+
 class RPCConsumer(ConsumerMixin):
 
     def __init__(self, connection, receiver):

nailgun/nailgun/rpc/utils.py

@@ -14,9 +14,11 @@
 #    License for the specific language governing permissions and limitations
 #    under the License.
 
+import logging
 import six
 
-from nailgun.logger import logger
+
+logger = logging.getLogger('receiverd')
 
 
 def delete_entities(conn, *entities):

nailgun/nailgun/settings.yaml

@@ -74,6 +74,10 @@ APP_LOG: &nailgun_log "/var/log/nailgun/app.log"
 API_LOG: &api_log "/var/log/nailgun/api.log"
 SYSLOG_DIR: &remote_syslog_dir "/var/log/remote/"
 
+RPC_CONSUMER_LOG_PATH: "/var/log/nailgun/receiverd.log"
+
+ASSASSIN_LOG_PATH: "/var/log/nailgun/assassind.log"
+
 MIRANTIS_REGISTRATION_URL: "https://software.mirantis.com/wp-content/themes/mirantis_responsive_v_1_0/scripts/fuel_forms_api/"
 
 COLLECTOR_ACTION_LOGS_URL: "https://{collector_server}/api/v1/action_logs/"

nailgun/nailgun/test/integration/test_assassin.py

@@ -14,31 +14,34 @@
 #    License for the specific language governing permissions and limitations
 #    under the License.
 
+import mock
+
 from nailgun.assassin import assassind
 from nailgun.test.base import BaseIntegrationTest
 
 
+@mock.patch('nailgun.utils.logs.prepare_submodule_logger')
 class TestKeepalive(BaseIntegrationTest):
 
     VERY_LONG_TIMEOUT = 60 * 60  # 1 hour
     ZERO_TIMEOUT = 0
 
-    def test_node_becomes_offline(self):
+    def test_node_becomes_offline(self, m_logger):
         node = self.env.create_node(
             status="discover",
             roles=["controller"],
             name="Dead or alive"
         )
-        assassind.update_nodes_status(self.VERY_LONG_TIMEOUT)
+        assassind.update_nodes_status(self.VERY_LONG_TIMEOUT, m_logger)
         self.assertEqual(node.online, True)
-        assassind.update_nodes_status(self.ZERO_TIMEOUT)
+        assassind.update_nodes_status(self.ZERO_TIMEOUT, m_logger)
         self.assertEqual(node.online, False)
 
-    def test_provisioning_node_not_becomes_offline(self):
+    def test_provisioning_node_not_becomes_offline(self, m_logger):
         node = self.env.create_node(
             status="provisioning",
             roles=["controller"],
             name="Dead or alive"
         )
-        assassind.update_nodes_status(self.ZERO_TIMEOUT)
+        assassind.update_nodes_status(self.ZERO_TIMEOUT, m_logger)
         self.assertEqual(node.online, True)

nailgun/nailgun/utils/logs.py

@@ -14,8 +14,10 @@
 #    License for the specific language governing permissions and limitations
 #    under the License.
 
+import logging
 import os
 import shutil
+import sys
 
 from nailgun import consts
 from nailgun.db import db
@@ -23,6 +25,7 @@ from nailgun.db.sqlalchemy.models import IPAddr
 from nailgun.db.sqlalchemy.models import NetworkGroup
 from nailgun.db.sqlalchemy.models import Node
 from nailgun.logger import logger
+from nailgun.logger import set_logger
 from nailgun import objects
 from nailgun.settings import settings
 from nailgun.utils import remove_silently
@@ -113,3 +116,16 @@ def delete_node_logs(node, prefix=settings.SYSLOG_DIR):
         if os.path.lexists(log_path):
             logger.debug('delete_node_logs log_path="%s"', log_path)
             remove_silently(log_path)
+
+
+def prepare_submodule_logger(submodule_name, file_path=None):
+    logger = logging.getLogger(submodule_name)
+
+    if file_path is None:
+        handler = logging.FileHandler(file_path)
+    else:
+        handler = logging.StreamHandler(sys.stdout)
+
+    set_logger(logger, handler)
+
+    return logger

nailgun/tools/env.sh

@@ -61,6 +61,8 @@ DATABASE:
   passwd: "${NAILGUN_DB_PW}"
 API_LOG: "${NAILGUN_LOGS}/api.log"
 APP_LOG: "${NAILGUN_LOGS}/app.log"
+RPC_CONSUMER_LOG_PATH: "${NAILGUN_LOGS}/receiverd.log"
+ASSASSIN_LOG_PATH: "${NAILGUN_LOGS}/assassind.log"
 EOL
 }