Merge branch 'L2SS-445-docker-logs' into 'master'

L2SS-445: Forward logs from the Docker containers to ELK

Closes L2SS-445

See merge request !159

docker-compose/archiver.yml

@@ -17,6 +17,12 @@ services:
       - MYSQL_USER=tango
       - MYSQL_PASSWORD=tango
       - TANGO_HOST=${TANGO_HOST}
+    logging:
+      driver: syslog
+      options:
+        syslog-address: udp://${HOSTNAME}:1514
+        syslog-format: rfc3164
+        tag: "{{.Name}}"
     restart: unless-stopped
 
   hdbpp-es:
@@ -36,6 +42,12 @@ services:
           wait-for-it.sh archiver-maria-db:3306 --timeout=30 --strict --
           wait-for-it.sh ${TANGO_HOST} --timeout=30 --strict --
                hdbppes-srv 01"
+      logging:
+        driver: syslog
+        options:
+          syslog-address: udp://${HOSTNAME}:1514
+          syslog-format: rfc3164
+          tag: "{{.Name}}"
       restart: unless-stopped
 
   hdbpp-cm:
@@ -55,6 +67,12 @@ services:
           wait-for-it.sh archiver-maria-db:3306 --timeout=30 --strict --
           wait-for-it.sh ${TANGO_HOST} --timeout=30 --strict --
                hdbppcm-srv 01"
+      logging:
+        driver: syslog
+        options:
+          syslog-address: udp://${HOSTNAME}:1514
+          syslog-format: rfc3164
+          tag: "{{.Name}}"
 
   dsconfig:
     image: ${DOCKER_REGISTRY_HOST}/${DOCKER_REGISTRY_USER}-tango-dsconfig:${TANGO_DSCONFIG_VERSION}
@@ -73,5 +91,11 @@ services:
       - ..:/opt/lofar/tango:rw
       - ${HOME}:/hosthome
       - ../docker/tango/tango-archiver:/tango-archiver
+    logging:
+      driver: syslog
+      options:
+        syslog-address: udp://${HOSTNAME}:1514
+        syslog-format: rfc3164
+        tag: "{{.Name}}"
     restart: unless-stopped
 

docker-compose/elk.yml

@@ -34,7 +34,8 @@ services:
       - "5601:5601" # kibana
       - "9200:9200" # elasticsearch
       - "5044:5044" # logstash beats input
-      - "1514:1514" # logstash syslog input
+      - "1514:1514/tcp" # logstash syslog input
+      - "1514:1514/udp" # logstash syslog input
       - "5959:5959" # logstash tcp json input
     depends_on:
       - elk-configure-host

docker-compose/elk/logstash/conf.d/20-parse-grafana.conf

+filter {
+  if [program] == "grafana" {
+    kv { }
+    mutate {
+      rename => {
+        "t" => "timestamp"
+        "lvl" => "level"
+        "msg" => "message"
+      }
+      uppercase => [ "level" ]
+    }
+    date {
+      match => [ "timestamp", "ISO8601" ]
+    }
+  }
+}

docker-compose/elk/logstash/conf.d/21-parse-prometheus.conf

+filter {
+  if [program] == "prometheus" {
+    kv { }
+    mutate {
+      rename => {
+        "ts" => "timestamp"
+        "msg" => "message"
+      }
+      uppercase => [ "level" ]
+    }
+    date {
+      match => [ "timestamp", "ISO8601" ]
+    }
+  }
+}

docker-compose/elk/logstash/conf.d/22-parse-tango-rest.conf

+filter {
+  if [program] == "tango-rest" {
+    grok {
+      match => {
+        "message" => "%{TIMESTAMP_ISO8601:timestamp} %{WORD:level} %{GREEDYDATA:message}"
+      }
+      "overwrite" => [ "timestamp", "level", "message" ]
+    }
+    date {
+      match => [ "timestamp", "YYYY-MM-dd HH:mm:ss,SSS" ]
+      timezone => "UTC"
+    }
+  }
+}

docker-compose/elk/logstash/conf.d/23-parse-maria-db.conf

+filter {
+  # mark all our mariadb instances
+  grok {
+    match => {
+      "program" => [ "archiver-maria-db", "tangodb" ]
+    }
+    add_tag => [ "mariadb" ]
+  }
+
+  # parse mariadb output
+  if "mariadb" in [tags] {
+    grok {
+      match => {
+        "message" => [
+          "%{TIMESTAMP_ISO8601:timestamp} .%{WORD:level}. %{GREEDYDATA:message}",
+          "%{TIMESTAMP_ISO8601:timestamp} 0 .%{WORD:level}. %{GREEDYDATA:message}"
+        ]
+      }
+      "overwrite" => [ "timestamp", "level", "message" ]
+    }
+    mutate {
+      gsub => [
+        "level", "Note", "Info"
+      ]
+      uppercase => [ "level" ]
+    }
+    date {
+      match => [ "timestamp", "YYYY-MM-dd HH:mm:ssZZ", "YYYY-MM-dd HH:mm:ss", "YYYY-MM-dd  H:mm:ss"  ]
+      timezone => "UTC"
+    }
+  }
+}

docker-compose/grafana.yml

@@ -23,4 +23,10 @@ services:
     #  - grafana-configs:/etc/grafana
     ports:
       - "3000:3000"
+    logging:
+      driver: syslog
+      options:
+        syslog-address: udp://${HOSTNAME}:1514
+        syslog-format: rfc3164
+        tag: "{{.Name}}"
     restart: unless-stopped

docker-compose/prometheus.yml

@@ -16,4 +16,10 @@ services:
       - control
     ports:
       - "9090:9090"
+    logging:
+      driver: syslog
+      options:
+        syslog-address: udp://${HOSTNAME}:1514
+        syslog-format: rfc3164
+        tag: "{{.Name}}"
     restart: unless-stopped

docker-compose/rest.yml

@@ -33,3 +33,10 @@ services:
     - /usr/bin/supervisord
     - --configuration
     - /etc/supervisor/supervisord.conf
+    logging:
+      driver: syslog
+      options:
+        syslog-address: udp://${HOSTNAME}:1514
+        syslog-format: rfc3164
+        tag: "{{.Name}}"
+    restart: unless-stopped

docker-compose/tango.yml

@@ -28,6 +28,12 @@ services:
       - tangodb:/var/lib/mysql
     ports:
       - "3306:3306"
+    logging:
+      driver: syslog
+      options:
+        syslog-address: udp://${HOSTNAME}:1514
+        syslog-format: rfc3164
+        tag: "{{.Name}}"
     restart: unless-stopped
 
   databaseds:
@@ -55,4 +61,10 @@ services:
       - "2"
       - -ORBendPoint
       - giop:tcp::10000
+    logging:
+      driver: syslog
+      options:
+        syslog-address: udp://${HOSTNAME}:1514
+        syslog-format: rfc3164
+        tag: "{{.Name}}"
     restart: unless-stopped

docs/source/developer.rst

@@ -59,3 +59,40 @@ For more information, see:
 - https://huihoo.org/ace_tao/ACE-5.2+TAO-1.2/TAO/docs/ORBEndpoint.html
 - http://omniorb.sourceforge.net/omni42/omniNames.html
 - https://sourceforge.net/p/omniorb/svn/HEAD/tree/trunk/omniORB/src/lib/omniORB/orbcore/tcp/tcpEndpoint.cc
+
+Logging
+-------------------------
+
+The ELK stack collects the logs from the containers, as well as any external processes that send theirs. It is the *Logstash* part of ELK that is responsible for this. The following interfaces are available for this purpose:
+
++-------------+------------+-------------------------------------------------------------------------------------------------------------+
+| Interface   | Port       | Note                                                                                                        |
++=============+============+=============================================================================================================+
+| Syslog      | 1514/udp   | Recommended over TCP, as the ELK stack might be down.                                                       |
++-------------+------------+-------------------------------------------------------------------------------------------------------------+
+| Syslog      | 1514/tcp   |                                                                                                             |
++-------------+------------+-------------------------------------------------------------------------------------------------------------+
+| JSON        | 5959/tcp   | From python, recommended is the `LogStash Async <https://pypi.org/project/python-logstash-async/>`_ module. |
++-------------+------------+-------------------------------------------------------------------------------------------------------------+
+| Beats       | 5044/tcp   | Use `FileBeat <https://www.elastic.co/beats/filebeat>`_ to watch logs locally, and forward them to ELK.     |
++-------------+------------+-------------------------------------------------------------------------------------------------------------+
+
+We recommend making sure the contents of your log lines are parsed correctly, especially if logs are routed to the *Syslog* input. These configurations are stored in ``docker-compose/elk/logstash/conf.d``. An example: 
+
+.. literalinclude:: ../../docker-compose/elk/logstash/conf.d/22-parse-tango-rest.conf
+
+Log from Python
+`````````````````
+
+The ``common.lofar_logging`` module provides an easy way to log to the ELK stack from a Python Tango device.
+
+Log from Docker
+`````````````````
+
+Not all Docker containers run our Python programs, and can forward the logs themselves. For those, we use the ``syslog`` log driver in Docker. Extend the ``docker compose`` files with:
+
+.. literalinclude:: ../../docker-compose/rest.yml
+   :start-at: logging:
+   :end-before: restart:
+
+Logs forwarded in this way are provided with the container name, their timestamp, and a log level guessed by Docker. It is thus wise to parse the message content further in Logstash (see above).

docs/source/interfaces/logs.rst

@@ -15,11 +15,11 @@ ELK
 To monitor the logs remotely, or to browse older logs, use the *ELK stack* that is included on the station, and served on http://localhost:5601. ELK, or ElasticSearch + Logstash + Kibana, is a popular log collection and querying system. Currently, the following logs are collected in our ELK installation:
 
 - Logs of all devices,
-- Logs of the Jupyter notebook server.
+- Logs of the Docker containers.
 
 If you browse to the ELK stack (actually, it is Kibana providing the GUI), your go-to is the *Discover* view at http://localhost:5601/app/discover. There, you can construct (and save, load) a dashboard that provides a custom view of the logs, based on the *index pattern* ``logstash-*``. There is a lot to take in, and there are excellent Kibana tutorials on the web.
 
-To get going, use for example `this dashboard <http://localhost:5601/app/discover#/?_g=(filters:!(),refreshInterval:(pause:!t,value:0),time:(from:now-60m,to:now))&_a=(columns:!(extra.lofar_id,level,message),filters:!(),index:'1e8ca200-1be0-11ec-a85f-b97e4206c18b',interval:auto,query:(language:kuery,query:''),sort:!())>`_, which shows the logs of the last hour, with some useful columns added to the default timestamp and message columns. Expand the time range if no logs appear, to look further back. You should see something like:
+To get going, use for example `this dashboard <http://localhost:5601/app/discover#/?_g=(filters:!(),refreshInterval:(pause:!t,value:0),time:(from:now-1h,to:now))&_a=(columns:!(extra.lofar_id,program,level,message),filters:!(),index:'1e8ca200-1be0-11ec-a85f-b97e4206c18b',interval:auto,query:(language:kuery,query:'extra.lofar_id.keyword%20:%20*'),sort:!())>`_, which shows the logs of the last hour, with some useful columns added to the default timestamp and message columns. Expand the time range if no logs appear, to look further back. You should see something like:
 
 .. image:: elk_last_hour.png