Merge pull request #32 from UCSD-E4E/31-logging

Added invocation logging

e4e_data_management/cli.py

@@ -2,6 +2,10 @@
 '''
 import argparse
 import datetime as dt
+import logging
+import logging.handlers
+import sys
+import time
 from dataclasses import dataclass
 from glob import glob
 from pathlib import Path
@@ -28,6 +32,9 @@ class DataMangerCLI:
     """Data Manager Command Line Interface
     """
     def __init__(self):
+        self.__configure_logging()
+        self._log = logging.getLogger('e4edm.cli')
+        self._log.debug('Invoking version %s from %s', __version__, __file__)
         self.app = DataManager.load()
         commands = [
             'init_dataset',
@@ -85,6 +92,26 @@ def __init__(self):
         self.parser.add_argument('--version', action='version', version=f'e4edm {__version__}')
         self.parser.set_defaults(func=self.parser.print_help)
 
+    def __configure_logging(self) -> None:
+        log_dir = Path(DataManager.dirs.user_log_dir).resolve()
+        log_dir.mkdir(parents=True, exist_ok=True)
+        log_dest = log_dir.joinpath('e4edm.log')
+
+        root_logger = logging.getLogger()
+        root_logger.setLevel(logging.DEBUG)
+
+        log_file_handler = logging.handlers.RotatingFileHandler(log_dest,
+                                                                maxBytes=5*1024*1024,
+                                                                backupCount=5)
+        log_file_handler.setLevel(logging.DEBUG)
+
+        root_formatter = logging.Formatter(('%(asctime)s.%(msecs)03d - %(name)s - %(levelname)s - '
+                                           '%(message)s'),
+                                           datefmt="%Y-%m-%d %H:%M:%S")
+        log_file_handler.setFormatter(root_formatter)
+        root_logger.addHandler(log_file_handler)
+
+        logging.Formatter.converter = time.gmtime
 
     def configure_parameters(self, parameter: str, value: Optional[str]) -> None:
         """Configures or prints the specified parameter
@@ -195,6 +222,7 @@ def status_cmd(self):
     def main(self):
         """Main function
         """
+        self._log.info("Invoked with %s", ' '.join(sys.argv))
         args = self.parser.parse_args()
         arg_dict = vars(args)
 

e4e_data_management/core.py

@@ -3,12 +3,14 @@
 from __future__ import annotations
 
 import datetime as dt
+import fnmatch
+import logging
 import pickle
 import re
 from pathlib import Path
 from shutil import copy2
 from typing import Dict, Iterable, List, Optional
-import fnmatch
+
 import appdirs
 
 from e4e_data_management.data import Dataset, Mission
@@ -26,7 +28,7 @@ class DataManager:
         appauthor='Engineers for Exploration'
     )
     def __init__(self, *, app_config_dir: Optional[Path] = None):
-        # self.__log = logging.getLogger('DataManager')
+        self.__log = logging.getLogger('e4edm')
         self.config_path = Path(app_config_dir)
         self.active_dataset: Optional[Dataset] = None
         self.active_mission: Optional[Mission] = None
@@ -38,6 +40,7 @@ def __init__(self, *, app_config_dir: Optional[Path] = None):
     def upgrade(self):
         """Upgrades self to current version
         """
+        self.__log.warning('Upgrading to version 2 from version %d', self.version)
         if self.version < 2:
             self.dataset_dir = Path(self.dirs.user_data_dir)
         self.version = 2
@@ -71,6 +74,7 @@ def load(cls, *, config_dir: Optional[Path] = None) -> DataManager:
     def save(self) -> None:
         """Saves the app into the specified config dir
         """
+        self.__log.debug('Saving')
         config_file = self.config_path.joinpath(self.__CONFIG_NAME)
         if not config_file.exists():
             config_file.parent.mkdir(parents=True, exist_ok=True)

e4e_data_management/data.py

@@ -4,6 +4,7 @@
 
 import datetime as dt
 import json
+import logging
 import pickle
 from dataclasses import dataclass
 from hashlib import sha256
@@ -176,6 +177,7 @@ class Mission:
     """
     __MANIFEST_NAME = 'manifest.json'
     def __init__(self, path: Path, mission_metadata: Metadata) -> None:
+        self.__log = logging.getLogger(f'e4edm.mission {mission_metadata.mission}')
         self.path = path.resolve()
         self.metadata = mission_metadata
         self.committed_files: List[Path] = []
@@ -237,25 +239,35 @@ def stage(self, paths: Iterable[Path], destination: Optional[Path] = None):
             destination = Path('.')
         dst = self.path.joinpath(destination)
         for path in paths:
-            if path.is_file():
+            origin_path = path.resolve()
+            if origin_path.is_file():
+                file_hash = Manifest.compute_file_hash(origin_path.resolve())
+                target_path = dst.joinpath(path.name).resolve()
                 self.staged_files.add(
                     StagedFile(
-                    origin_path=path.resolve(),
-                    target_path=dst.joinpath(path.name).resolve(),
-                    hash=Manifest.compute_file_hash(path.resolve())
+                    origin_path=origin_path,
+                    target_path=target_path,
+                    hash=file_hash
                     )
                 )
-            elif path.is_dir():
-                for file in path.rglob('*'):
+                self.__log.info('Staging %s (%s) to %s', origin_path.as_posix(), file_hash,
+                                target_path.as_posix())
+            elif origin_path.is_dir():
+                for file in origin_path.rglob('*'):
                     if file.is_dir():
                         continue
+                    origin_file = file.resolve()
+                    target_path = dst.joinpath(origin_file.relative_to(origin_path)).resolve()
+                    file_hash = Manifest.compute_file_hash(origin_file)
                     self.staged_files.add(
                         StagedFile(
-                        origin_path=file.resolve(),
-                        target_path=dst.joinpath(file.relative_to(path)).resolve(),
-                        hash=Manifest.compute_file_hash(file.resolve())
+                        origin_path=origin_file,
+                        target_path=target_path,
+                        hash=file_hash
                         )
                     )
+                    self.__log.info('Staging %s (%s) to %s', origin_file.as_posix(), file_hash,
+                                target_path.as_posix())
             else:
                 raise RuntimeWarning('Not a normal file')
 
@@ -281,6 +293,9 @@ def commit(self) -> List[Path]:
             if Manifest.compute_file_hash(staged_file.target_path) != staged_file.hash:
                 raise RuntimeError(f'Failed to copy {staged_file.origin_path.as_posix()}')
             committed_files.append(staged_file.target_path)
+            self.__log.info('Copied %s to %s',
+                            staged_file.origin_path.as_posix(),
+                            staged_file.target_path.as_posix())
         self.manifest.update(committed_files)
         self.committed_files.extend([file.relative_to(self.path) for file in committed_files])
         self.staged_files = set()
@@ -296,6 +311,7 @@ class Dataset:
     VERSION = 1
 
     def __init__(self, root: Path, day_0: dt.date):
+        self.__log = logging.getLogger('e4edm.dataset')
         self.root = root.resolve()
         self.day_0: dt.date = day_0
         self.last_country: Optional[str] = None
@@ -452,6 +468,8 @@ def stage(self, paths: Iterable[Path]):
             paths (Iterable[Path]): Paths to stage
         """
         self.staged_files.extend(paths)
+        for path in paths:
+            self.__log.info('Staged %s', path.as_posix())
 
     def commit(self) -> List[Path]:
         """Commits staged files to the mission
@@ -485,6 +503,7 @@ def commit(self) -> List[Path]:
                 dest.parent.mkdir(parents=True, exist_ok=True)
                 copy2(src=src, dst=dest)
                 new_files.append(dest)
+                self.__log.info('Copied %s to %s', src.as_posix(), dest.as_posix())
             if not self.manifest.validate(manifest=original_manifest, files=new_files):
                 raise RuntimeError(f'Failed to copy {path.as_posix()}')
             self.manifest.update(new_files)