Add session context to logs and fix the failing tests in CircleCI

config.py

@@ -43,6 +43,7 @@
 
 DATASET_DIR = "/opt/moses-service/data"
 
+
 def setup_logging(default_path='logging.yml', default_level=logging.INFO):
     """Setup logging configuration
     """
@@ -55,3 +56,15 @@ def setup_logging(default_path='logging.yml', default_level=logging.INFO):
         logging.config.dictConfig(config)
     else:
         logging.basicConfig(level=default_level)
+
+
+def get_logger(session_id=None):
+    if session_id is None:
+        return logging.getLogger("mozi_snet")
+
+    extra = {"session": session_id}
+
+    logger = logging.getLogger("mozi_snet")
+    logger = logging.LoggerAdapter(logger, extra)
+
+    return logger

crossval/model_evaluator.py

@@ -6,19 +6,19 @@
 import pandas as pd
 import subprocess
 import logging
-import os
 from mlxtend.evaluate import scoring, mcnemar, mcnemar_table
 import tempfile
+from config import get_logger
 
 
 class ModelEvaluator:
     """
     This is class evaluates programs that are output by MOSES and scores them against test and training data
     """
 
-    def __init__(self, target_feature):
+    def __init__(self, target_feature, session_id):
         self.target_feature = target_feature
-        self.logger = logging.getLogger("mozi_snet")
+        self.logger = get_logger(session_id)
 
     def run_eval(self, models, input_file):
         """

crossval/moses_cross_val.py

@@ -1,18 +1,18 @@
 __author__ = 'Abdulrahman Semrie<[email protected]>'
 
-from models.objmodel import EnsembleModel
 import os
-from crossval.moses_runner import MosesRunner
-from sklearn.model_selection import StratifiedShuffleSplit
-import pandas as pd
 import random
-import logging
-from crossval.model_evaluator import ModelEvaluator
-import math
-from utils.feature_count import combo_parser, ComboTreeTransform
-from scipy import stats
 import tempfile
 
+import pandas as pd
+from scipy import stats
+from sklearn.model_selection import StratifiedShuffleSplit
+
+from crossval.model_evaluator import ModelEvaluator
+from crossval.moses_runner import MosesRunner
+from models.objmodel import EnsembleModel
+from utils.feature_count import combo_parser, ComboTreeTransform
+from config import get_logger
 
 class CrossValidation:
     """
@@ -30,7 +30,7 @@ def __init__(self, session, db, filter_type, value, cwd):
         self.db = db
         self.filter = filter_type
         self.filter_value = value
-        self.logger = logging.getLogger("mozi_snet")
+        self.logger = get_logger(session.mnemonic)
         self.fold_files = []
         self._set_dir()
 
@@ -67,7 +67,7 @@ def run_folds(self):
 
             fold_fname = f"fold_{i}.csv"
             self.fold_files.append(fold_fname)
-            self.logger.info(f"Got {len(fold_models)} for fold_{i}")
+            self.logger.info(f"Got {len(fold_models)} models for fold_{i}")
             # CrossValidation.merge_fold_files(fold_fname, files)
             self.logger.info("Evaluating fold: %d" % i)
             scored_models = self.score_fold(fold_models, train_file, test_file)
@@ -111,7 +111,7 @@ def run_seeds(self, seeds, i, file):
             output_file = tempfile.NamedTemporaryFile(mode="w+")
             moses_options = " ".join([self.session.moses_options, "--random-seed " + str(seed)])
 
-            moses_runner = MosesRunner(file, output_file.name, moses_options)
+            moses_runner = MosesRunner(file, output_file.name, moses_options, self.session.mnemonic)
             returncode, stdout, stderr = moses_runner.run_moses()
 
             if returncode != 0:
@@ -142,7 +142,7 @@ def score_fold(self, models, train_file, test_file):
         :param test_file: The file containing the test set
         :return:
         """
-        model_evaluator = ModelEvaluator(self.session.target_feature)
+        model_evaluator = ModelEvaluator(self.session.target_feature, self.session.mnemonic)
 
         test_matrix = model_evaluator.run_eval(models, test_file)
         train_matrix = model_evaluator.run_eval(models, train_file)
@@ -196,7 +196,7 @@ def majority_vote(self):
         their individual scores and the combined score
         """
         data = {"model": [], "recall": [], "precision": [], "accuracy": [], "f1_score": [], "p_value": []}
-        model_eval = ModelEvaluator(self.session.target_feature)
+        model_eval = ModelEvaluator(self.session.target_feature, self.session.id)
         filtered_models = []
         for _, v in self.result_models.items():
             res = self.filter.cut_off(v, self.filter_value)

crossval/moses_runner.py

@@ -1,19 +1,18 @@
 __author__ = 'Abdulrahman Semrie<[email protected]>'
 
-from models.objmodel import MosesModel
-import subprocess
 import logging
 import re
-import tempfile
-import fileinput
+import subprocess
+from config import get_logger
+from models.objmodel import MosesModel
 
 
 class MosesRunner:
     """
     A class that handles running of the MOSES binary program
     """
 
-    def __init__(self, input_file, output_file, moses_opts):
+    def __init__(self, input_file, output_file, moses_opts, session_id):
         """
         :param input_file: The input file to run MOSES on
         :param output_file: The file to write MOSES program outputs to
@@ -24,7 +23,7 @@ def __init__(self, input_file, output_file, moses_opts):
         self.moses_options = moses_opts
         if not "W1" in moses_opts: moses_opts += ' -W1'
         self.output_regex = re.compile(r"(-?\d+) (.+) \[(.+)\]")
-        self.logger = logging.getLogger("mozi_snet")
+        self.logger = get_logger(session_id)
 
     def run_moses(self):
         """
@@ -65,5 +64,4 @@ def format_combo(self, combo_file):
                     complexity = match.group(3).split(",")[2].split("=")[1]
                     models.append(MosesModel(model, complexity))
 
-        self.logger.info(f"Num of combo models {len(models)}")
         return models

logging.yml

@@ -2,9 +2,9 @@ version: 1
 disable_existing_loggers: False
 formatters:
     simple:
-        format: "%(asctime)s - %(name)s - %(levelname)s - %(message)s"
+        format: "%(asctime)s - %(levelname)s - %(session)s - %(message)s"
     print:
-        format: "%(levelname)s - %(message)s"
+        format: "%(asctime)s - %(levelname)s - %(session)s - %(message)s"
 
 handlers:
     console_1:

task/task_runner.py

@@ -14,6 +14,7 @@
 from crossval.moses_cross_val import CrossValidation
 from models.dbmodels import Session
 from crossval.filters import loader
+from config import get_logger
 
 celery = Celery('mozi_snet', broker=CELERY_OPTS["CELERY_BROKER_URL"])
 celery.conf.update(CELERY_OPTS)
@@ -77,12 +78,11 @@ def start_analysis(**kwargs):
     :return:
     """
     db = pymongo.MongoClient(MONGODB_URI)[DB_NAME]
-    logger = logging.getLogger("mozi_snet")
 
     swd, file_path = write_dataset(kwargs["dataset"], kwargs["mnemonic"])
     session = Session(kwargs["id"], kwargs["moses_options"], kwargs["crossval_options"],
                       file_path, kwargs["mnemonic"], kwargs["target_feature"])
-
+    logger = get_logger(session.mnemonic)
     session.save(db)
 
     session.status = 1

tests/test_model_evaluator.py

@@ -20,14 +20,14 @@ def setUp(self):
         self.input_file = os.path.join(TEST_DATA_DIR, "bin_truncated.csv")
 
     def test_run_eval_happy_path(self):
-        model_eval = ModelEvaluator("case")
+        model_eval = ModelEvaluator("case", "abcdre")
 
         matrix = model_eval.run_eval(self.test_combo, self.input_file)
 
         self.assertEqual(matrix.shape[0], 3)
 
     def test_score_models(self):
-        model_eval = ModelEvaluator("case")
+        model_eval = ModelEvaluator("case", "abcdre")
         matrix = model_eval.run_eval(self.test_combo, self.input_file)
 
         scored_matrix = model_eval.score_models(matrix, self.input_file)

tests/test_moses_cross_val.py

@@ -21,7 +21,8 @@ def setUp(self):
         session_id = str(uuid.uuid4())
         self.session = Session(session_id, moses_options, crossval_options, dataset, "abcd")
 
-        self.train_file, self.test_file = os.path.join(TEST_DATA_DIR, "train_file"), os.path.join(TEST_DATA_DIR, "test_file")
+        self.train_file, self.test_file = os.path.join(TEST_DATA_DIR, "train_file"), os.path.join(TEST_DATA_DIR,
+                                                                                                  "test_file")
         self.test_matrix = [[1, 1, 1, 1, 1, 1, 1, 0, 0, 0, 0, 1, 0, 1, 1, 0, 0, 1, 0, 1, 1, 0, 1, 0, 1, 1, 1, 1, 0, 1],
                             [1, 1, 1, 1, 1, 1, 1, 0, 0, 0, 0, 1, 0, 1, 1, 0, 0, 1, 0, 1, 1, 0, 1, 1, 1, 1, 1, 1, 0, 1],
                             [0, 1, 0, 0, 1, 1, 0, 0, 0, 0, 0, 1, 0, 1, 1, 0, 0, 0, 0, 0, 0, 0, 1, 1, 1, 1, 0, 0, 0, 1],

tests/test_moses_runner.py

@@ -26,20 +26,20 @@ def tearDown(self):
             os.remove(opencog_log)
 
     def test_run_moses_happy_path(self):
-        moses_runner = MosesRunner(self.input_file, self.output_file, self.moses_opts)
+        moses_runner = MosesRunner(self.input_file, self.output_file, self.moses_opts, "abcdre")
 
         self.assertEqual(moses_runner.run_moses()[0], 0)  # successfully ran moses
 
     def test_run_moses_error_path(self):
         tweaked_options = self.moses_opts + "-xyz"  # this is done to make moses deliberately fail
-        moses_runner = MosesRunner(self.input_file, self.output_file, tweaked_options)
+        moses_runner = MosesRunner(self.input_file, self.output_file, tweaked_options, "abcdre")
 
         self.assertNotEqual(moses_runner.run_moses()[0], 0)
 
         self.assertNotEqual("", moses_runner.run_moses()[2])  # make sure there is an error output
 
     def test_format_combo(self):
-        moses_runner = MosesRunner(self.input_file, self.output_file, self.moses_opts)
+        moses_runner = MosesRunner(self.input_file, self.output_file, self.moses_opts, "abcdre")
         moses_runner.run_moses()
         test_combo_file = os.path.join(TEST_DATA_DIR, self.output_file)
 

tests/test_start_analysis.py

@@ -19,7 +19,7 @@ def setUpClass(cls):
         with open(dataset, "rb") as fp:
             content = fp.read()
 
-        cls.dataset = base64.b64encode(content)
+        cls.dataset = base64.b64encode(content).decode("utf-8")
         cls.session_id = str(uuid.uuid4())
         cls.cwd = os.path.join(TEST_DATA_DIR, f"session_{cls.session_id}")