On the importance of logging

I recently spent an inordinate amount of time trying to debug why a curl-initiated Webhook POST to AWX was being rejected with the lame message

{"detail":"A server error has occurred."}

In spite of configuring debug logging and log forwarding from AWX, I couldn’t figure out what was wrong. My assumption was the body of the post was missing something. I looked at the source code of the api view controller and still didn’t figure it out and basically gave up after an hour. Actual webhooks posted from Gitea worked (when configured in AWX as Github), but my simple curl invocation wouldn’t. (Remind me to rave about how I like Gitea and Forgejo.)

Ton then showed me how to view what’s going on in the AWX web task:

$ kubectl get pods -n awx | grep awx-web
awx-web-6b6bddcf69-75jdp                           3/3     Running

$ kubectl logs -n awx pod/awx-web-6b6bddcf69-75jdp  -c awx-web -f
...
2023-09-13 10:58:59,846 ERROR    [6e4b76bd6879443f9fbf29a65ccda3a7] django.request Internal Server Error: /api/v2/job_templates/9/github/
Traceback (most recent call last):
...
  File "/var/lib/awx/venv/awx/lib64/python3.9/site-packages/awx/api/views/webhooks.py", line 185, in get_signature
    hash_alg, signature = header_sig.split('=')
ValueError: not enough values to unpack (expected 2, got 1)
...

I quickly recognized where I’d gone wrong: I omitted the = sign between the string sha1 and the actual digest. Github now prefers SHA256 (which AWX doesn’t support here) and its header is different.

The two possible types of header for comparison:

X-Hub-Signature: sha1=05eb9e5d74e3085fce6a93fd72ec468a75dfdb8e
X-Hub-Signature-256: 6571761a59b557a1b7809ff8a687fc715daf83f23655c7a971f420ca6f40e3c2

Here’s the relevant bit from the AWX code.

I can now demonstrate how to launch a template from afar:

#!/bin/sh

export secret="dAHQB8IS3F2gecUaIHmjJCwq9O5tG3CCoUK1ItNGWg2KdraBgB" # template Webhook Key
export payload="$(jo bla=true)"

digest1="$(printf "%s" "${payload}" | openssl dgst -sha1 -hmac "${secret}" | sed -e 's/^SHA1(stdin)= //' )"
sig1="X-Hub-Signature: sha1=$digest1"
uuid=$(python3 -c "import uuid; print(uuid.uuid4())")

curl -H 'content-type: application/json' \
        -H "${sig1}" \
        -H "X-GitHub-Event: push" \
        -H "X-GitHub-Event-Type: push" \
        -H "X-GitHub-Delivery: ${uuid}" \
        -d "${payload}"  \
        https://example.com/api/v2/job_templates/9/github/

Logging, finding, and studying logs: so important!

awx and ansible :: 13 Sep 2023 :: e-mail

Jan-Piet Mens

On the importance of logging