T5610 Add logging (#216)

* add log.ini

* add frontend log config and switchboard web logging

* update k8s key fetch url; fix kubectl install in devcontainer

* bump pyngrok to 6.0.0; update poetry.lock

.devcontainer/Dockerfile

@@ -18,11 +18,14 @@ ARG USER_UID=1000
 ARG USER_GID=$USER_UID
 COPY library-scripts/*.sh /tmp/library-scripts/
 RUN apt-get update \
-    && /bin/bash /tmp/library-scripts/common-debian.sh "${INSTALL_ZSH}" "${USERNAME}" "${USER_UID}" "${USER_GID}" "${UPGRADE_PACKAGES}" "true" "true" \
-    # Use Docker script from script library to set things up
-    && /bin/bash /tmp/library-scripts/docker-debian.sh "${ENABLE_NONROOT_DOCKER}" "/var/run/docker-host.sock" "/var/run/docker.sock" "${USERNAME}" \
-    # Clean up
-    && apt-get autoremove -y && apt-get clean -y && rm -rf /var/lib/apt/lists/* /tmp/library-scripts/
+    && /bin/bash /tmp/library-scripts/common-debian.sh "${INSTALL_ZSH}" "${USERNAME}" "${USER_UID}" "${USER_GID}" "${UPGRADE_PACKAGES}" "true" "true"
+# Use Docker script from script library to set things up
+RUN /bin/bash /tmp/library-scripts/docker-debian.sh "${ENABLE_NONROOT_DOCKER}" "/var/run/docker-host.sock" "/var/run/docker.sock" "${USERNAME}"
+# install all the things that didn't work in that workflow
+# keep separate so the other steps cache if adding sth breaks here
+RUN /bin/bash /tmp/library-scripts/custom-installs.sh
+# Clean up
+RUN apt-get autoremove -y && apt-get clean -y && rm -rf /var/lib/apt/lists/* /tmp/library-scripts/
 
 # Setting the ENTRYPOINT to docker-init.sh will configure non-root access
 # to the Docker socket. The script will also execute CMD as needed.

.devcontainer/devcontainer.json

@@ -42,7 +42,7 @@
 		],
 
         // Use 'postCreateCommand' to run commands after the container is created.
-        "postCreateCommand": "python -m pip install poetry && poetry install -E 'twisted web' && poetry run pre-commit install",
+        "postCreateCommand": "python -m pip install poetry && poetry install -E 'twisted web' && poetry run pre-commit install && git config --global --add safe.directory /workspace",
 
         // Comment out connect as root instead. More info: https://aka.ms/vscode-remote/containers/non-root.
         "remoteUser": "vscode",

.devcontainer/library-scripts/common-debian.sh

@@ -164,42 +164,6 @@ if [ "${UPGRADE_PACKAGES}" = "true" ]; then
     apt-get autoremove -y
 fi
 
-# Install terraform and packer
-apt-get update
-apt-get install -y gnupg software-properties-common curl
-curl -fsSL https://apt.releases.hashicorp.com/gpg | sudo apt-key add -
-curl -fsSL https://apt.releases.hashicorp.com/gpg | sudo apt-key add -
-apt-add-repository "deb [arch=amd64] https://apt.releases.hashicorp.com $(lsb_release -cs) main"
-apt-add-repository "deb [arch=amd64] https://apt.releases.hashicorp.com $(lsb_release -cs) main"
-
-apt-get update
-apt-get install terraform
-apt-get install packer
-
-curl -Lo ./terraform-docs.tar.gz https://github.com/terraform-docs/terraform-docs/releases/download/v0.16.0/terraform-docs-v0.16.0-$(uname)-amd64.tar.gz
-tar -xzf terraform-docs.tar.gz
-chmod +x terraform-docs
-mv terraform-docs /usr/local/terraform-docs
-
-# Install mysql (default repos are broken for buster)
-wget https://dev.mysql.com/get/mysql-apt-config_0.8.22-1_all.deb
-DEBIAN_FRONTEND=noninteractive dpkg -i mysql-apt-config_0.8.22-1_all.deb
-apt update
-DEBIAN_FRONTEND=noninteractive apt-get install -y mysql-client
-
-apt install -y wireguard-tools
-
-# curl -sSL https://install.python-poetry.org | POETRY_HOME=/home/vscode/.local python -
-# /home/vscode/.local/bin/poetry config virtualenvs.in-project true
-
-# wget https://golang.org/dl/go1.18.2.linux-amd64.tar.gz
-# tar -C /usr/local -xzf go1.18.2.linux-amd64.tar.gz
-# /usr/local/go/bin/go install github.com/aquasecurity/tfsec/cmd/tfsec@latest
-curl -fsSLo /usr/share/keyrings/kubernetes-archive-keyring.gpg https://packages.cloud.google.com/apt/doc/apt-key.gpg
-echo "deb [signed-by=/usr/share/keyrings/kubernetes-archive-keyring.gpg] https://apt.kubernetes.io/ kubernetes-xenial main" | sudo tee /etc/apt/sources.list.d/kubernetes.list
-apt-get update -y
-apt-get install -y kubectl
-
 # Ensure at least the en_US.UTF-8 UTF-8 locale is available.
 # Common need for both applications and things like the agnoster ZSH theme.
 if [ "${LOCALE_ALREADY_SET}" != "true" ] && ! grep -o -E '^\s*en_US.UTF-8\s+UTF-8' /etc/locale.gen > /dev/null; then

.devcontainer/library-scripts/custom-installs.sh

@@ -0,0 +1,37 @@
+# Install terraform and packer
+apt-get update
+apt-get install -y gnupg software-properties-common curl
+curl -fsSL https://apt.releases.hashicorp.com/gpg | sudo apt-key add -
+curl -fsSL https://apt.releases.hashicorp.com/gpg | sudo apt-key add -
+apt-add-repository "deb [arch=amd64] https://apt.releases.hashicorp.com $(lsb_release -cs) main"
+apt-add-repository "deb [arch=amd64] https://apt.releases.hashicorp.com $(lsb_release -cs) main"
+
+apt-get update
+apt-get install terraform
+apt-get install packer
+
+curl -Lo ./terraform-docs.tar.gz https://github.com/terraform-docs/terraform-docs/releases/download/v0.16.0/terraform-docs-v0.16.0-$(uname)-amd64.tar.gz
+tar -xzf terraform-docs.tar.gz
+chmod +x terraform-docs
+mv terraform-docs /usr/local/terraform-docs
+
+# Install mysql (default repos are broken for buster)
+wget https://dev.mysql.com/get/mysql-apt-config_0.8.22-1_all.deb
+DEBIAN_FRONTEND=noninteractive dpkg -i mysql-apt-config_0.8.22-1_all.deb
+apt update
+DEBIAN_FRONTEND=noninteractive apt-get install -y mysql-client
+
+apt install -y wireguard-tools
+
+# curl -sSL https://install.python-poetry.org | POETRY_HOME=/home/vscode/.local python -
+# /home/vscode/.local/bin/poetry config virtualenvs.in-project true
+
+# wget https://golang.org/dl/go1.18.2.linux-amd64.tar.gz
+# tar -C /usr/local -xzf go1.18.2.linux-amd64.tar.gz
+# /usr/local/go/bin/go install github.com/aquasecurity/tfsec/cmd/tfsec@latest
+
+sudo curl -fsSLo /usr/share/keyrings/kubernetes-archive-keyring.gpg  https://dl.k8s.io/apt/doc/apt-key.gpg
+sudo install -o root -g root -m 644 /usr/share/keyrings/kubernetes-archive-keyring.gpg /etc/apt/trusted.gpg.d/
+sudo echo "deb [signed-by=/etc/apt/trusted.gpg.d/kubernetes-archive-keyring.gpg] https://apt.kubernetes.io kubernetes-xenial main" | sudo tee /etc/apt/sources.list.d/kubernetes.list
+sudo apt-get update -y
+sudo apt-get install -y kubectl

.github/workflows/test.yml

@@ -4,7 +4,7 @@ on:
   push:
     branches:
       - "T4627_py3_main"
-      - "T5610_misc_fixes"
+      - "T5610_log_ini"
 
 jobs:
   tests:
@@ -72,7 +72,7 @@ jobs:
           poetry config virtualenvs.in-project true
           sudo apt-get update -y
           sudo apt-get install -y apt-transport-https ca-certificates curl
-          sudo curl -fsSLo /usr/share/keyrings/kubernetes-archive-keyring.gpg https://packages.cloud.google.com/apt/doc/apt-key.gpg
+          sudo curl -fsSLo /usr/share/keyrings/kubernetes-archive-keyring.gpg https://dl.k8s.io/apt/doc/apt-key.gpg
           echo "deb [signed-by=/usr/share/keyrings/kubernetes-archive-keyring.gpg] https://apt.kubernetes.io/ kubernetes-xenial main" | sudo tee /etc/apt/sources.list.d/kubernetes.list
           sudo apt-get update -y
           sudo apt-get install -y kubectl

.gitignore

@@ -1,7 +1,7 @@
 *.pyc
 *.swp
 tokensvenv/*
-*.log
+*.log*
 *.pid
 .vscode
 .DS_Store

canarytokens/loghandlers.py

@@ -0,0 +1,112 @@
+from twisted.logger import eventAsJSON, ILogObserver, Logger, LogLevel
+from twisted.web.iweb import IBodyProducer
+from twisted.web.client import Agent
+from twisted.web.http_headers import Headers
+from twisted.internet import defer, reactor
+from twisted.internet.defer import succeed
+from zope.interface import implementer
+
+import os
+import json
+
+
+log = Logger()
+
+
+# The below value comes up whenever a mailgun API requested is attempted
+# And the intended recipient of the mail is an incorrectly entered/obviously wrong
+# email address. eg `asd@x.xa`
+text_for_failed_email_address_entered = "A mailgun error occurred: <class 'requests.exceptions.HTTPError'> - 400 Client Error: BAD REQUEST for url: https://api.mailgun.net/v3/canarytokens.org/messages"
+
+
+@implementer(IBodyProducer)
+class BytesProducer:
+    def __init__(self, body):
+        self.body = body
+        self.length = len(body)
+
+    def startProducing(self, consumer):
+        consumer.write(self.body)
+        return succeed(None)
+
+    def pauseProducing(self):
+        pass
+
+    def stopProducing(self):
+        pass
+
+
+@implementer(ILogObserver)
+class errorsToWebhookLogObserver(object):
+    """
+    Log observer that sends errors out to a Slack endpoint.
+    """
+
+    def __init__(self, formatEvent):
+        """
+        @param formatEvent: A callable that formats an event.
+        @type formatEvent: L{callable} that takes an C{event} argument and
+            returns a formatted event as L{unicode}.
+        """
+        self.formatEvent = formatEvent
+
+    def __call__(self, event):
+        """
+        Check if log_level Error or higher, if so post to webhook
+
+        @param event: An event.
+        @type event: L{dict}
+        """
+        if (
+            event["log_level"] == LogLevel.error
+            or event["log_level"] == LogLevel.critical
+        ):
+            if event["log_namespace"] == "log_legacy":
+                # A log from the legacy logger has been called, therefore use a different key to get the log message
+                postdata = {"text": event["log_text"]}
+            else:
+                postdata = {"text": event["log_format"]}
+            if (
+                postdata["text"] == "Unhandled error in Deferred:"
+                or postdata["text"] == text_for_failed_email_address_entered
+            ):
+                # filters out non useful spam of messages seen before with these exact contents
+                return
+            _ = httpRequest(postdata)
+
+
+def httpRequest(postdata):
+    agent = Agent(reactor)
+    headers = {b"Content-Type": [b"application/x-www-form-urlencoded"]}
+    data_str = json.dumps(postdata)
+    body = BytesProducer(data_str.encode())
+    url = os.getenv("ERROR_LOG_WEBHOOK").encode()
+    d = agent.request(b"POST", url, Headers(headers), body)
+
+    def handle_response(response):
+        if response.code == 200:
+            d = defer.succeed("")
+        else:
+            log.warn("Failed to post to webhook")
+            d = None
+        return d
+
+    d.addCallback(handle_response)
+    return d
+
+
+def webhookLogObserver(recordSeparator="\x1e"):
+    """
+    Create a L{errorsToWebhookLogObserver} that emits error and critical
+    loglines' text to a specified webhook URL by doing a HTTP POST.
+
+    @param recordSeparator: The record separator to use.
+    @type recordSeparator: L{unicode}
+
+    @return: A log observer that POST critical and Error logs to a webhook.
+    @rtype: L{errorsToWebhookLogObserver}
+
+    """
+    return errorsToWebhookLogObserver(
+        lambda event: "{0}{1}\n".format(recordSeparator, eventAsJSON(event))
+    )

canarytokens/settings.py

@@ -47,6 +47,9 @@ class SwitchboardSettings(BaseSettings):
     SENTRY_ENVIRONMENT: Literal["prod", "staging", "dev", "ci", "local"] = "local"
     SENTRY_ENABLE: bool = True
 
+    SWITCHBOARD_LOG_SIZE: Optional[int] = 500000000
+    SWITCHBOARD_LOG_COUNT: Optional[int] = 20
+
     TOKEN_RETURN: Literal["gif", "fortune"] = "gif"
 
     class Config:

frontend/log.ini

@@ -0,0 +1,27 @@
+[loggers]
+keys=root
+
+[handlers]
+keys=fileHandler,stdoutHandler
+
+[formatters]
+keys=defaultFormatter
+
+[logger_root]
+level=INFO
+handlers=fileHandler,stdoutHandler
+
+[handler_fileHandler]
+class=FileHandler
+; level=INFO
+formatter=defaultFormatter
+args=(os.getenv("LOG_FILE","frontend.log"), 'a')
+
+[handler_stdoutHandler]
+class=StreamHandler
+; level=INFO
+formatter=defaultFormatter
+args=(sys.stdout,)
+
+[formatter_defaultFormatter]
+format=%(asctime)s - %(name)s - %(levelname)s - %(message)s

makefile

@@ -6,7 +6,7 @@ switchboard:
 
 .PHONY: frontend
 frontend:
-	cd frontend; poetry run uvicorn app:app --reload
+	cd frontend; poetry run uvicorn app:app --reload --log-config log.ini
 
 .PHONY: testv3
 testv3: