Merge pull request #96 from EGA-archive/logging-vector

Fixing the Logging mechanism

Dockerfile

@@ -1,7 +1,7 @@
 ##########################
 ## Build env
 ##########################
-FROM python:3.6-alpine3.10 as BUILD
+FROM python:3.8-alpine3.11 as BUILD
 
 RUN apk add git postgresql-dev gcc musl-dev libffi-dev make gnupg
 
@@ -17,7 +17,7 @@ RUN pip install /root/LocalEGA
 ##########################
 ## Final image
 ##########################
-FROM python:3.6-alpine3.10
+FROM python:3.8-alpine3.11
 
 LABEL maintainer "EGA System Developers"
 LABEL org.label-schema.schema-version="1.0"
@@ -32,8 +32,7 @@ ARG LEGA_GID=1000
 RUN addgroup -g ${LEGA_GID} lega && \
     adduser -D -G lega -u ${LEGA_UID} lega
 
-COPY --from=BUILD usr/local/lib/python3.6/ usr/local/lib/python3.6/
-
+COPY --from=BUILD usr/local/lib/python3.8/ usr/local/lib/python3.8/
 COPY --from=BUILD /usr/local/bin/ega-* /usr/local/bin/
 
 RUN mkdir -p /ega/archive && \

deploy/Makefile

@@ -35,7 +35,8 @@ preflight-check:
 # For the moment, we simply do sleep 20, because we need
 # the rabbitmq shovel to CentralEGA (the federated queue can be late, it doesn't hurt)
 
-
+logs:
+	@docker logs -f logs
 
 ####################################################
 ## Base Image

deploy/README.md

@@ -44,7 +44,14 @@ The following images are pulled from Docker Hub, when starting LocalEGA (only th
 * [`egarchive/lega-mq`](https://github.com/EGA-archive/LocalEGA-mq) (based on `rabbitmq:3.6.14-management`)
 * [`egarchive/lega-db`](https://github.com/EGA-archive/LocalEGA-db) (based on `postgres:11.2`)
 * [`egarchive/lega-inbox`](https://github.com/EGA-archive/LocalEGA-inbox) (based on OpenSSH version 7.8p1 and CentOS7)
-* `python:3.6-alpine3.10` 
+* `python:3.8-alpine3.11` 
+
+
+> Important notice: The user inside the container is called `lega`,
+> and its ID is by default 1000. When (re)building the image, the
+> above target `make image` will make the ID match the current user
+> calling the command. This is important to allow injected files to be
+> readable by the `lega` user inside the containers.
 
 ----
 

deploy/bootstrap/requirements.txt

@@ -1,5 +1,5 @@
 PyYaml
-pika==1.0.1
+pika==1.1.0
 bcrypt
 ruamel.yaml
 docopt

deploy/bootstrap/run/lega/services.py

@@ -142,7 +142,7 @@ def main(cega_conf, conf, args):
 
         'ingest': {
             'environment': [
-                'LEGA_LOG=debug',
+                'LEGA_LOG=centralized',
             ] + ([
                 'S3_ACCESS_KEY='+conf.get('s3','access_key'),
                 'S3_SECRET_KEY='+conf.get('s3','secret_key'),
@@ -170,7 +170,7 @@ def main(cega_conf, conf, args):
 
         'verify': {
             'environment': [
-                'LEGA_LOG=debug',
+                'LEGA_LOG=centralized',
             ] + ([
                 'S3_ACCESS_KEY='+conf.get('s3','access_key'),
                 'S3_SECRET_KEY='+conf.get('s3','secret_key'),
@@ -198,13 +198,12 @@ def main(cega_conf, conf, args):
 
         'finalize': {
             'environment': [
-                'LEGA_LOG=debug'
+                'LEGA_LOG=centralized'
             ],
             'hostname': f'finalize{HOSTNAME_DOMAIN}',
             'image': 'egarchive/lega-base:latest',
             'container_name': f'finalize{HOSTNAME_DOMAIN}',
             'volumes': [
-                '../../lega:/home/lega/.local/lib/python3.6/site-packages/lega',  # under dev
                 './finalize.ini:/etc/ega/conf.ini:ro',
                 './lega-entrypoint.sh:/usr/local/bin/lega-entrypoint.sh',
                 './certs/finalize.cert.pem:/etc/ega/ssl.cert',
@@ -218,8 +217,26 @@ def main(cega_conf, conf, args):
             'user': 'lega',
             'entrypoint': ["lega-entrypoint.sh"],
             'command': ["ega-finalize"],
-            # 'entrypoint': ["/bin/sleep", "1000000000000"]
+        },
+
+        # Collect logs to a central location.
+        # Vector.dev, logstash, or a custom code can receive them
+        'logs': {
+            'hostname': f'logs{HOSTNAME_DOMAIN}',
+            'image': 'python:3.8-alpine3.11',
+            'container_name': f'logs{HOSTNAME_DOMAIN}',
+            'volumes': [
+                '../bootstrap/udplogs.py:/logserver.py',
+            ],
+            'networks': [
+                'internal',
+                # 'private-db',
+                # 'private-vault',
+                # 'external',
+            ],
+            'entrypoint': ['python', '/logserver.py']
         }
+
     }
 
     if with_s3:
@@ -253,27 +270,27 @@ def main(cega_conf, conf, args):
                   'target': 'db.connection',
                   'uid': 'lega',
                   'gid': 'lega',
-                  'mode': 0o400,
+                  'mode': '0400', # octal
                 },
                 { 'source': 'mq.connection',
                   'target': 'mq.connection',
                   'uid': 'lega',
                   'gid': 'lega',
-                  'mode': 0o400,
+                  'mode': '0400', # octal
                 }]
             # S3 access and secret keys are in insecure env vars
 
-        lega['services']['verify']['secrets'].append({ 'source': 'master.key',
-                                                       'target': 'master.key',
+        lega['services']['verify']['secrets'].append({ 'source': 'master.key.passphrase',
+                                                       'target': 'master.key.passphrase',
                                                        'uid': 'lega',
                                                        'gid': 'lega',
-                                                       'mode': 0o400,
+                                                       'mode': '0400', # octal
         })
 
         lega['secrets'] = {
             'db.connection': { 'file': './secrets/db.connection'         },
             'mq.connection': { 'file': './secrets/mq.connection'         },
-            'master.key'   : { 'file': './secrets/master.key.passphrase' },
+            'master.key.passphrase' : { 'file': './secrets/master.key.passphrase' },
         }
 
         # create the files 

deploy/bootstrap/run/lega/verify.py

@@ -33,7 +33,7 @@ def main(conf, args):
         'master_key': 'c4gh_file',
     }
 
-    master_key = ('secret:///run/secrets/master.key'
+    master_key = ('secret:///run/secrets/master.key.passphrase'
                   if with_docker_secrets else
                   conf.get('master_key','passphrase', raw=True))
 

deploy/bootstrap/udplogs.py

@@ -0,0 +1,13 @@
+import socketserver
+
+class LogHandler(socketserver.BaseRequestHandler):
+
+    def handle(self):
+        client = self.client_address[0]
+        data = self.request[0].strip()
+        print(client,"|",data.decode(errors='ignore'))
+
+if __name__ == "__main__":
+    print('Starting a UDP listener on port 9000')
+    with socketserver.UDPServer(("0.0.0.0", 9000), LogHandler) as server:
+        server.serve_forever()

deploy/bootstrap/vector.toml

@@ -0,0 +1,10 @@
+[sources.lega]
+type = "socket"
+mode = "udp"
+address = "0.0.0.0:9000"
+
+[sinks.out]
+inputs   = ["lega"]
+type     = "console"
+#encoding = "json"
+target   = "stdout"

lega/__init__.py

@@ -11,8 +11,8 @@
 
 # This updates the logging class from all loggers used in this package.
 # The new logging class injects a correlation id to the log record.
-from .conf.logging import LEGALogger
 import logging
+from .conf.logging import LEGALogger
 logging.setLoggerClass(LEGALogger)
 
 # Send warnings using the package warnings to the logging system
@@ -21,4 +21,3 @@
 import warnings
 logging.captureWarnings(True)
 warnings.simplefilter("default")  # do not ignore Deprecation Warnings
-

lega/conf/__init__.py

@@ -1,6 +1,6 @@
 """Configuration Module provides a dictionary-like with configuration settings.
 
-It also loads the logging settings when ``setup`` is called.
+It also sets up the logging.
 
 * The ``LEGA_LOG`` environment variable is used to configure where the logs go.
   Without it, there is no logging capabilities.
@@ -12,7 +12,6 @@
   The files must be either in ``INI`` format or in ``YAML`` format, in
   which case, it must end in ``.yaml`` or ``.yml``.
 """
-
 from . import logging as lega_logging
 import logging
 logging.setLoggerClass(lega_logging.LEGALogger)
@@ -26,12 +25,27 @@
 from pathlib import Path
 import yaml
 
-from ..utils import get_from_file, get_from_env
-
 LOG_FILE = os.getenv('LEGA_LOG', None)
 CONF_FILE = os.getenv('LEGA_CONF', '/etc/ega/conf.ini')
 LOG = logging.getLogger(__name__)
 
+def get_from_file(filepath, mode='rb', remove_after=False):
+    """Return file content.
+
+    Raises ValueError if it errors.
+    """
+    try:
+        with open(filepath, mode) as s:
+            return s.read()
+    except: # Crash if not found, or permission denied
+        raise ValueError(f'Error loading {filepath}')
+    finally:
+        if remove_after:
+            try:
+                os.remove(filepath)
+            except: # Crash if not found, or permission denied
+                LOG.warning('Could not remove %s', filepath)
+
 def convert_sensitive(value):
     """Fetch a sensitive value from different sources.
 
@@ -65,7 +79,10 @@ def convert_sensitive(value):
             " Use secret:// instead",
             DeprecationWarning, stacklevel=4
         )
-        return get_from_env(envvar)
+        envvalue = os.getenv(envvar, None)
+        if envvalue is None:
+            raise ValueError(f'Environment variable {envvar} not found')
+        return envvalue
 
     if value.startswith('file://'):
         path=value[7:]
@@ -113,7 +130,11 @@ def __init__(self):
         try:
             self.load_log(LOG_FILE)
         except Exception as e:
-            print(f'No logging supplied: {e}', file=sys.stderr)
+            # import traceback
+            # traceback.print_stack()
+            print(f'No logging supplied: {e!r}', file=sys.stderr)
+            if e.__cause__:
+                print('Cause: {e.__cause__!r}', file=sys.stderr)
 
     def __repr__(self):
         """Show the configuration files."""

lega/conf/__main__.py

@@ -8,7 +8,6 @@
 
 def main(print_values=False):
     """Run the main routine, for loading configuration."""
-    CONF.setup()
 
     print(repr(CONF))
 

lega/conf/loggers/centralized.yaml

@@ -0,0 +1,41 @@
+version: 1
+root:
+  level: NOTSET
+  handlers: [noHandler]
+
+loggers:
+  lega:
+    level: DEBUG
+    handlers: [udp, console]
+    propagate: True
+    qualname: lega
+  py.warnings:
+    level: DEBUG
+    handlers: [console]
+
+
+handlers:
+  noHandler:
+    class: logging.NullHandler
+    level: NOTSET
+  console:
+    class: logging.StreamHandler
+    formatter: simple
+    stream: ext://sys.stderr
+  udp:
+    class: lega.utils.logging.UDPHandler
+    formatter: json
+    host: logs
+    port: 9000
+    level: INFO
+
+formatters:
+  simple:
+    format: '[{correlation_id}][{name:^10}][{levelname:^6}] (L{lineno}) {message}'
+    style: '{'
+    datefmt: '%Y-%m-%d %H:%M:%S'
+  json:
+    (): lega.utils.logging.JSONFormatter
+    fmt: '(correlation_id) (asctime) (name) (levelname) (lineno) (funcName) (message)'
+    validate: False
+    datefmt: '%Y-%m-%d %H:%M:%S'

lega/conf/loggers/console.yaml

@@ -28,13 +28,15 @@ handlers:
     stream: ext://sys.stdout
 
 formatters:
-  json:
-    (): lega.conf.logging.JSONFormatter
-    format: '(asctime) (name) (process) (processName) (levelname) (lineno) (funcName) (message)'
   lega:
     format: '[{asctime:<20}][{name}][{process:d} {processName:>15}][{levelname}] (L:{lineno}) {funcName}: {message}'
     style: '{'
     datefmt: '%Y-%m-%d %H:%M:%S'
   simple:
     format: '[{name:^10}][{levelname:^6}] (L{lineno}) {message}'
     style: '{'
+  json:
+    (): lega.utils.logging.JSONFormatter
+    fmt: '(correlation_id) (asctime) (name) (process) (processName) (levelname) (lineno) (funcName) (message)'
+    validate: False
+    datefmt: '%Y-%m-%d %H:%M:%S'