Merge pull request #78 from sul-dlss/honeybadger-alert-on-nonzero-scr…

…ipt-exit

send Honeybadger alert on nonzero script exit

.coveragerc

@@ -1,3 +1,6 @@
 [run]
 cov-report = term,html
 omit = tests/*
+concurrency = multiprocessing
+parallel = true
+sigterm = true

.github/workflows/deploy-prod.yml

@@ -21,6 +21,8 @@ jobs:
           AWS_ACCESS_KEY_ID: ${{ secrets.AWS_ACCESS_KEY_ID_PRODUCTION }}
           AWS_SECRET_ACCESS_KEY: ${{ secrets.AWS_SECRET_ACCESS_KEY_PRODUCTION }}
           AWS_ECR_DOCKER_REPO: ${{ secrets.AWS_ECR_DOCKER_REPO_PRODUCTION }}
+          HONEYBADGER_API_KEY: ${{ secrets.HONEYBADGER_API_KEY }}
+          DEPLOYMENT_ENV: prod
         run: |
           echo "production deploy not yet enabled"
           # uncomment this when the keys are avaialable!

.github/workflows/deploy.yml

@@ -21,11 +21,15 @@ jobs:
           AWS_ACCESS_KEY_ID: ${{ secrets.AWS_ACCESS_KEY_ID_DEVELOPMENT }}
           AWS_SECRET_ACCESS_KEY: ${{ secrets.AWS_SECRET_ACCESS_KEY_DEVELOPMENT }}
           AWS_ECR_DOCKER_REPO: ${{ secrets.AWS_ECR_DOCKER_REPO_DEVELOPMENT }}
+          HONEYBADGER_API_KEY: ${{ secrets.HONEYBADGER_API_KEY }}
+          DEPLOYMENT_ENV: qa
         run: ./deploy.sh
 
       - name: Build and push Docker image to staging
         env:
           AWS_ACCESS_KEY_ID: ${{ secrets.AWS_ACCESS_KEY_ID_STAGING }}
           AWS_SECRET_ACCESS_KEY: ${{ secrets.AWS_SECRET_ACCESS_KEY_STAGING }}
           AWS_ECR_DOCKER_REPO: ${{ secrets.AWS_ECR_DOCKER_REPO_STAGING }}
+          HONEYBADGER_API_KEY: ${{ secrets.HONEYBADGER_API_KEY }}
+          DEPLOYMENT_ENV: stage
         run: ./deploy.sh

Dockerfile

@@ -15,7 +15,9 @@ ADD ./requirements.txt requirements.txt
 RUN python3 -m pip install --upgrade pip
 RUN python3 -m pip install -r requirements.txt
 
+ADD ./error_reporting_wrapper.py error_reporting_wrapper.py
+
 ADD ./speech_to_text.py speech_to_text.py
 RUN python3 -m py_compile speech_to_text.py
 
-ENTRYPOINT ["python3", "speech_to_text.py"]
+ENTRYPOINT ["python3", "error_reporting_wrapper.py", "python3", "speech_to_text.py"]

README.md

@@ -55,6 +55,8 @@ You will want to set these in your environment:
 - AWS_ACCESS_KEY_ID: the `text_to_speech_access_key_id` value
 - AWS_SECRET_ACCESS_KEY: the `text_to_speech_secret_access_key`
 - AWS_ECR_DOCKER_REPO: the `docker_repository` value
+- DEPLOYMENT_ENV: the SDR environment being deployed to (e.g. qa, stage, prod)
+- HONEYBADGER_API_KEY: the API key for this project, to support deployment notifications (obtainable from project settings in HB web UI)
 
 Then you can run the deploy:
 
@@ -66,7 +68,7 @@ Since this project already installs the `python-dotenv` package, you can do some
 
 ```shell
 # requires you to create a .env.qa file with the QA-specific env vars values needed by deploy.sh
-dotenv --file=.env.qa run ./deploy.sh
+dotenv --file=.env.deploy.qa run ./deploy.sh
 ```
 
 ## Run

deploy.sh

@@ -6,6 +6,8 @@
 # - AWS_ACCESS_KEY_ID: the access key for the speech-to-text user
 # - AWS_SECRET_ACCESS_KEY: the secret key for the speech-to-text user
 # - AWS_ECR_DOCKER_REPO: the Elastic Compute Registry URL for the Docker repository
+# - DEPLOYMENT_ENV: the SDR environment being deployed to (e.g. qa, stage, prod)
+# - HONEYBADGER_API_KEY: the API key for this project, to support deployment notifications (obtainable from project settings in HB web UI)
 #
 # The values can be obtained by running `terraform output` in the relevant portion of
 # the Terraform configuration.
@@ -33,3 +35,9 @@ docker build -t speech-to-text --platform="linux/amd64" .
 docker tag speech-to-text $AWS_ECR_DOCKER_REPO
 
 docker push $AWS_ECR_DOCKER_REPO
+
+# Notify Honeybadger of the deployment, see https://docs.honeybadger.io/api/reporting-deployments
+# Another option would be to use the Github Action, but this allows deployment notification to work even
+# when run manually from a dev laptop (see https://github.com/marketplace/actions/honeybadger-deploy-action)
+curl --data "deploy[environment]=$DEPLOYMENT_ENV&deploy[revision]=`git rev-parse HEAD`&deploy[repository]=https://github.com/sul-dlss/speech-to-text.git&api_key=$HONEYBADGER_API_KEY" \
+            "https://api.honeybadger.io/v1/deploys"

error_reporting_wrapper.py

@@ -0,0 +1,74 @@
+#!/usr/bin/env python3
+
+import dotenv
+import logging
+import os
+import sys
+
+from honeybadger import honeybadger
+from subprocess import run, CalledProcessError
+
+
+# This must be invoked before the logger is invoked for the first time
+def configure() -> None:
+    dotenv.load_dotenv()
+
+    # TODO: HB and logging config copied from speech_to_text.py, may eventually want
+    # to centralize more and start organizing codebase as a package?
+    honeybadger.configure(
+        api_key=os.environ.get("HONEYBADGER_API_KEY", ""),
+        environment=os.environ.get("HONEYBADGER_ENV", "stage"),
+    )
+
+    logging.basicConfig(
+        level=logging.INFO,
+        format="%(asctime)s :: %(levelname)s :: %(message)s",
+        datefmt="%Y-%m-%dT%H:%M:%S%z",
+    )
+
+
+# advantages of this vs using the `honeybadger exec` subcommand
+# of the honeybadger gem/command (see https://docs.honeybadger.io/lib/ruby/gem-reference/cli/):
+# 1. a little more control over what the error reporting sends along
+# 2. more honest reporting of error code: in my testing, a script that exited with a
+#    return code of '1' was reported as having a return code of '256' by honeybadger
+#    exec (but was correctly reported by this, when compared to running the command by itself and doing `echo $?`)
+# 3. this script will bubble up the return code of the wrapped script, whereas honeybadger exec always returns 0,
+#    even when the wrapped script exits non-zero
+# 4. one or two fewer dependencies to add to the docker image (maybe ruby, depending on the base image; definitely
+#    the honeybadger gem regardless, whereas we already have the python package in our python deps)
+#
+# disadvantages of this approach: a little more code of our own to maintain
+def run_with_error_reporting(cmd_with_args: list) -> int:
+    returncode: int
+
+    try:
+        completed_process = run(cmd_with_args, check=True)
+        returncode = completed_process.returncode
+
+        logging.info(completed_process)
+    except KeyboardInterrupt:
+        logging.info(f"exiting {sys.argv[0]}")
+        sys.exit()
+    except CalledProcessError as e:
+        returncode = e.returncode
+
+        error_context = {
+            "message": str(e),
+            "cmd": e.cmd,
+            "returncode": e.returncode,
+        }
+        logging.error(error_context)
+        honeybadger.notify(e, context=error_context)
+
+    return returncode
+
+
+if __name__ == "__main__":
+    configure()
+
+    cmd_with_args = sys.argv[1:]  # argv[0] is this script's name
+    logging.info(f"command and args: {cmd_with_args}")
+
+    # bubble up the exit code from the wrapped call
+    sys.exit(run_with_error_reporting(cmd_with_args))

tests/test_error_reporting_wrapper.py

@@ -0,0 +1,59 @@
+import error_reporting_wrapper
+import pytest
+
+from subprocess import run, CalledProcessError, CompletedProcess
+
+from unittest.mock import patch
+
+
+def test_error_reporting_wrapper_exit_zero():
+    completed_process = run(["cat", "Dockerfile"], check=True)
+    assert completed_process.returncode == 0, "return code for successful command is 0"
+
+
+def test_error_reporting_wrapper_exit_nonzero():
+    completed_process = run(["cat", "foooooo"])
+    assert completed_process.returncode == 1, (
+        "return code for unsuccessful command is bubbled up through wrapper"
+    )
+
+
+@patch("error_reporting_wrapper.honeybadger")
+def test_run_with_error_reporting_on_error_honeybadger(mock_honeybadger):
+    returncode = error_reporting_wrapper.run_with_error_reporting(["cat", "foooooo"])
+
+    mock_honeybadger.notify.assert_called_once()
+    args, kwargs = mock_honeybadger.notify.call_args
+    context = kwargs["context"]
+    assert isinstance(args[0], CalledProcessError)
+    assert "returned non-zero exit status" in context["message"]
+    assert context["cmd"] == ["cat", "foooooo"]
+    assert context["returncode"] == 1
+    assert returncode == 1
+
+
+# ignore utcnow warning from within honeybadger
+@pytest.mark.filterwarnings("ignore:datetime.datetime.utcnow")
+@patch("error_reporting_wrapper.logging")
+def test_run_with_error_reporting_on_error_logging(mock_logging):
+    returncode = error_reporting_wrapper.run_with_error_reporting(["cat", "foooooo"])
+
+    mock_logging.error.assert_called_once()
+    args, kwargs = mock_logging.error.call_args
+    assert "returned non-zero exit status" in args[0]["message"]
+    assert args[0]["cmd"] == ["cat", "foooooo"]
+    assert args[0]["returncode"] == 1
+    assert returncode == 1
+
+
+@patch("error_reporting_wrapper.logging")
+@patch("error_reporting_wrapper.honeybadger")
+def test_run_with_error_reporting_on_success(mock_honeybadger, mock_logging):
+    returncode = error_reporting_wrapper.run_with_error_reporting(["cat", "Dockerfile"])
+
+    mock_honeybadger.notify.assert_not_called()
+    mock_logging.error.assert_not_called()
+    mock_logging.info.assert_called_once()
+    args = mock_logging.info.call_args.args
+    assert isinstance(args[0], CompletedProcess)
+    assert returncode == 0