Webhook: gogs payload validation failed

Created on 20 May 2020 · 18Comments · Source: adnanh/webhook

I'm trying to use the webhook with Gogs (Go Git Server) and the payload validation is failing:

May 19 19:25:29 nixie docker-compose[3608844]: puppet_g10k | [webhook] 2020/05/19 23:25:29 [c84770] incoming HTTP GET request from 172.22.0.1:52448
May 19 19:25:29 nixie docker-compose[3608844]: puppet_g10k | [webhook] 2020/05/19 23:25:29 [c84770] gogs got matched
May 19 19:25:29 nixie docker-compose[3608844]: puppet_g10k | [webhook] 2020/05/19 23:25:29 [c84770] error parsing JSON payload EOF
May 19 19:25:29 nixie docker-compose[3608844]: puppet_g10k | [webhook] 2020/05/19 23:25:29 [c84770] error evaluating hook: invalid payload signatures [76cda40505e58837211ee37fe7e8c819e31f33a1221a686fbebbe5829002ea01]
May 19 19:25:29 nixie docker-compose[3608844]: puppet_g10k | > [c84770] GET /hooks/gogs
May 19 19:25:29 nixie docker-compose[3608844]: puppet_g10k | > [c84770] Accept-Encoding: gzip
May 19 19:25:29 nixie docker-compose[3608844]: puppet_g10k | > [c84770] Content-Type: application/json
May 19 19:25:29 nixie docker-compose[3608844]: puppet_g10k | > [c84770] Referer: http://nixie.home.honig.net:18140//hooks/gogs
May 19 19:25:29 nixie docker-compose[3608844]: puppet_g10k | > [c84770] User-Agent: GogsServer
May 19 19:25:29 nixie docker-compose[3608844]: puppet_g10k | > [c84770] X-Github-Delivery: f45348ae-7fdf-4697-8230-45b07e55e056
May 19 19:25:29 nixie docker-compose[3608844]: puppet_g10k | > [c84770] X-Github-Event: push
May 19 19:25:29 nixie docker-compose[3608844]: puppet_g10k | > [c84770] X-Gogs-Delivery: f45348ae-7fdf-4697-8230-45b07e55e056
May 19 19:25:29 nixie docker-compose[3608844]: puppet_g10k | > [c84770] X-Gogs-Event: push
May 19 19:25:29 nixie docker-compose[3608844]: puppet_g10k | > [c84770] X-Gogs-Signature: 76cda40505e58837211ee37fe7e8c819e31f33a1221a686fbebbe5829002ea01
May 19 19:25:29 nixie docker-compose[3608844]: puppet_g10k | > [c84770] id:
May 19 19:25:29 nixie docker-compose[3608844]: puppet_g10k | < [c84770] Internal Server Error
May 19 19:25:29 nixie docker-compose[3608844]: puppet_g10k | < [c84770] Error occurred while evaluating hook rules.
May 19 19:25:29 nixie docker-compose[3608844]: puppet_g10k |
May 19 19:25:29 nixie docker-compose[3608844]: puppet_g10k | [webhook] 2020/05/19 23:25:29 [c84770] 500 | 43 B | 133.025µs | nixie.home.honig.net:18140 | GET /hooks/gogs

I'm using a version of https://github.com/camptocamp/docker-g10k-webhook where I've upgraded to 2.7.0 and swapped -verbose for -debug to try to debug this.

Now the funny thing is that I have python flask implementation of a hook that verifies the signatures that has been working with Gogs webhooks for a long time.

The template file looks to be derrived from the example in the git repo:

- id: gogs
  execute-command: /push-to-g10k.sh
  command-working-directory: /
  pass-arguments-to-command:
  - source: payload
    name: ref
  - source: payload
    name: repository.ssh_url
  trigger-rule:
    and:
      - match:
          type: payload-hash-sha256
          secret: "{{ getenv "HOOK_SECRET" | js }}"
          parameter:
            source: header
            name: X-Gogs-Signature

I've verified that HOOK_SECRET in the environment is correct. I even replaced
``` secret: "{{ getenv "HOOK_SECRET" | js }}"

with

            secret: FRED

(which is the secret I'm using so that I can share stuff here).

Any tips to help debug this?

Gogs gives me the following information about the hook call:

Request URL: http://nixie.home.honig.net:18140//hooks/gogs
Request method: POST
Content-Type: application/json
X-Github-Delivery: 9a37cb8c-151c-4801-9f38-f722e93c85fa
X-Github-Event: push
X-Gogs-Delivery: 9a37cb8c-151c-4801-9f38-f722e93c85fa
X-Gogs-Event: push
X-Gogs-Signature: 76cda40505e58837211ee37fe7e8c819e31f33a1221a686fbebbe5829002ea01

{
"ref": "refs/heads/production",
"before": "0d63846da1e52542b34ec1cd7f63598a42e4a9fe",
"after": "0d63846da1e52542b34ec1cd7f63598a42e4a9fe",
"compare_url": "",
"commits": [
{
"id": "0d63846da1e52542b34ec1cd7f63598a42e4a9fe",
"message": "fixup! Fix trim_ssd errors with FUSE% variablesn",
"url": "https://git.home.honig.net/Sysadmin/puppet/commit/0d63846da1e52542b34ec1cd7f63598a42e4a9fe",
"author": {
"name": "Jeffrey C Honig",
"email": "[email protected]",
"username": "jch"
},
"committer": {
"name": "Jeffrey C Honig",
"email": "[email protected]",
"username": "jch"
},
"added": null,
"removed": null,
"modified": [
"site/profile/files/bin/trim_ssd"
],
"timestamp": "0001-01-01T00:00:00Z"
}
],
"repository": {
"id": 10,
"owner": {
"id": 3,
"username": "Sysadmin",
"login": "Sysadmin",
"full_name": "Sysadmin repos",
"email": "",
"avatar_url": "https://git.home.honig.net/avatars/3"
},
"name": "puppet",
"full_name": "Sysadmin/puppet",
"description": "Server puppet configs",
"private": true,
"fork": false,
"parent": null,
"empty": false,
"mirror": false,
"size": 23244800,
"html_url": "https://git.home.honig.net/Sysadmin/puppet",
"ssh_url": "[email protected]:Sysadmin/puppet.git",
"clone_url": "https://git.home.honig.net/Sysadmin/puppet.git",
"website": "",
"stars_count": 0,
"forks_count": 0,
"watchers_count": 2,
"open_issues_count": 0,
"default_branch": "production",
"created_at": "2017-04-22T23:31:30Z",
"updated_at": "2020-05-19T13:02:51Z"
},
"pusher": {
"id": 1,
"username": "jch",
"login": "jch",
"full_name": "Jeffrey Honig",
"email": "[email protected]",
"avatar_url": "https://secure.gravatar.com/avatar/b25e2ae1f07ec30647f346df81d2d841"
},
"sender": {
"id": 1,
"username": "jch",
"login": "jch",
"full_name": "Jeffrey Honig",
"email": "[email protected]",
"avatar_url": "https://secure.gravatar.com/avatar/b25e2ae1f07ec30647f346df81d2d841"
}
}
```

Any other suggestions for debugging this?

Thanks.

Jeff

question

Source

jchonig

Most helpful comment

Could you also try one more thing before doing that, fix the request url so that it's hooks/gogs instead of /hooks/gogs in the gogs?

D'oh! That was it!

Here's some debugging that I added:

diff --git a/webhook.go b/webhook.go
index 3af8ab4..840bd4d 100644
--- a/webhook.go
+++ b/webhook.go
@@ -246,6 +246,9 @@ func hookHandler(w http.ResponseWriter, r *http.Request) {
        if err != nil {
            log.Printf("[%s] error reading the request body. %+v\n", rid, err)
        }
+//     fmt.Printf("BODY: %d %d '%s'\n", len(body), len(string(body)), string(body))
+       fmt.Printf("REQUEST: %#v\n", r)
+       fmt.Printf("REQUEST: %#v\n", r.Body)

        // parse headers
        headers := valuesToMap(r.Header)

Which shows:

REQUEST: &http.Request{Method:"GET", URL:(*url.URL)(0xc00012a200), Proto:"HTTP/1.1", ProtoMajor:1, ProtoMinor:1, Header:http.Header{"Accept-Encoding":[]string{"gzip"}, "Content-Type":[]string{"application/json"}, "Referer":[]string{"http://nixie.home.honig.net:18140//hooks/gogs"}, "User-Agent":[]string{"GogsServer"}, "X-Github-Delivery":[]string{"9a37cb8c-151c-4801-9f38-f722e93c85fa"}, "X-Github-Event":[]string{"push"}, "X-Gogs-Delivery":[]string{"9a37cb8c-151c-4801-9f38-f722e93c85fa"}, "X-Gogs-Event":[]string{"push"}, "X-Gogs-Signature":[]string{"76cda40505e58837211ee37fe7e8c819e31f33a1221a686fbebbe5829002ea01"}}, Body:http.noBody{}, GetBody:(func() (io.ReadCloser, error))(nil), ContentLength:0, TransferEncoding:[]string(nil), Close:false, Host:"nixie.home.honig.net:18140", Form:url.Values(nil), PostForm:url.Values(nil), MultipartForm:(*multipart.Form)(nil), Trailer:http.Header(nil), RemoteAddr:"172.19.0.2:42716", RequestURI:"/hooks/gogs", TLS:(*tls.ConnectionState)(nil), Cancel:(<-chan struct {})(nil), Response:(*http.Response)(nil), ctx:(*context.valueCtx)(0xc0000f8360)}
REQUEST: http.noBody{}

Might I suggest checking for an empty body. And also bailing if the json.Decode() fails?

Thanks for your help finding my typo!

jchonig on 21 May 2020

👍2

All 18 comments

Payload signature validation is failing. Can you test it with 2.6.11?

moorereason on 20 May 2020

Same failure:

[webhook] 2020/05/20 14:29:27 version 2.6.11 starting
[webhook] 2020/05/20 14:29:27 setting up os signal watcher
[webhook] 2020/05/20 14:29:27 attempting to load hooks from /etc/webhook/g10k.yaml.tmpl
[webhook] 2020/05/20 14:29:27 os signal watcher ready
[webhook] 2020/05/20 14:29:27 found 4 hook(s) in file
[webhook] 2020/05/20 14:29:27   loaded: github
[webhook] 2020/05/20 14:29:27   loaded: gogs
[webhook] 2020/05/20 14:29:27   loaded: gitlab
[webhook] 2020/05/20 14:29:27   loaded: payload
[webhook] 2020/05/20 14:29:27 serving hooks on http://0.0.0.0:9000/hooks/{id}
[webhook] 2020/05/20 14:29:38 301 | 57.593µs | nixie.home.honig.net:18140 | POST //hooks/gogs
[webhook] 2020/05/20 14:29:38 [41f1fb] incoming HTTP request from 192.168.0.1:44810
[webhook] 2020/05/20 14:29:38 [41f1fb] gogs got matched
[webhook] 2020/05/20 14:29:38 500 | 302.084µs | nixie.home.honig.net:18140 | GET /hooks/gogs
[webhook] 2020/05/20 14:29:38 [41f1fb] error parsing JSON payload EOF
[webhook] 2020/05/20 14:29:38 [41f1fb] error evaluating hook: invalid payload signature 76cda40505e58837211ee37fe7e8c819e31f33a1221a686fbebbe5829002ea01
[webhook] 2020/05/20 14:31:57 301 | 11.945µs | nixie.home.honig.net:18140 | POST //hooks/gogs

I've validated that the other webhook listener I wrote receives the exact same payload and signature. For reference, the code I have that validates the hook successfully:

def verify_signature(request):
    """ Verify the signature if provided """

    # Validate signature if required
    if 'GOGS_SECRET' in WEBHOOK.config:
        gogs_secret = WEBHOOK.config['GOGS_SECRET'].encode('utf-8')
        if gogs_secret:
            signature = request.headers.get('X-Gogs-Signature')
            if not signature:
                logging.error("Request has no signature")
                return False

            valid_signature = hmac.HMAC(gogs_secret,
                                        request.data,
                                        digestmod=hashlib.sha256).hexdigest()
            if not hmac.compare_digest(signature, valid_signature):
                logging.error("Signature %s expected %s", signature, valid_signature)
                return False

    return True

jchonig on 20 May 2020

I added a test case for this, and it works as expected. Hmm.

One thing that's throwing me off is the error parsing JSON payload EOF message you're seeing. For some reason, webhook is failing to parse the payload even though it appears to be valid JSON. I'm not seeing that message in my testing.

So, what are we missing?

moorereason on 20 May 2020

Can you run nc -l -v -p WEBHOOK_PORT instead of webhook, trigger the hook and post the raw output of the request that you get. (nc is the netcat)

adnanh on 20 May 2020

This part totally looks out of place:

May 19 19:25:29 nixie docker-compose[3608844]: puppet_g10k | > [c84770] id:

adnanh on 20 May 2020

Note, no NL at EOF. Secret for these tests is "FRED".

```
root@nixie:/vol/services/puppetserver# nc -l -v -p 18140
Listening on 0.0.0.0 18140
Connection received on 172.20.0.2 43474
POST //hooks/gogs HTTP/1.1
Host: nixie.home.honig.net:18140
User-Agent: GogsServer
Content-Length: 2191
Content-Type: application/json
X-Github-Delivery: 06674621-f8dc-4e18-9126-607ffae1d3ed
X-Github-Event: push
X-Gogs-Delivery: 06674621-f8dc-4e18-9126-607ffae1d3ed
X-Gogs-Event: push
X-Gogs-Signature: 76cda40505e58837211ee37fe7e8c819e31f33a1221a686fbebbe5829002ea01
Accept-Encoding: gzip

jchonig on 20 May 2020

This part totally looks out of place:
May 19 19:25:29 nixie docker-compose[3608844]: puppet_g10k | > [c84770] id:

That was 2.7.0 with -debug flag.

jchonig on 20 May 2020

This part totally looks out of place:
May 19 19:25:29 nixie docker-compose[3608844]: puppet_g10k | > [c84770] id:

That looks like a bug in the debug logger. Doesn't look to be related to this issue. I'll fix it separately.

moorereason on 21 May 2020

@jchonig, are you sure that nc sample is correct? It looks like the same body as before but the header has a new signature.

moorereason on 21 May 2020

@jchonig, are you sure that nc sample is correct? It looks like the same body as before but the header has a new signature.

I updated the comment above with the correct output. I'd changed the password to compare it to the hook that worked and didn't do all the steps to switch it back. Or screwe up the copy and paste. Sorry about that.

jchonig on 21 May 2020

Hmm, I managed to reproduce the error parsing JSON payload unexpected EOF message by specifying Content-Length header value to something less or more than the actual payload size. Could it be an encoding issue? Weird locale?

adnanh on 21 May 2020

That would certainly explain it.

I updated my working python web hook as listed above and added:

            logging.warning("Content-Length: %s data length %d",
                            request.headers.get('Content-Length'),
                            len(request.data))

I get:

May 21 07:29:07 mittens r10kd[4640]: Content-Length: 2176 data length 2176

So it appears that Gogs is sending the correct data.

Note there is another commit in the tree. If I resent the older notification we are sending above, I get the correct length of 2191:

May 21 07:33:55 mittens r10kd[4640]: Content-Length: 2191 data length 2191

jchonig on 21 May 2020

Perhaps we should try to rule out the environment first, could you try launching a webhook instance on your host, outside of docker, and see if the signature is still being miscalculated?

Unfortunately(?) my local setup calculates the correct signature for this scenario, so my guess would be that either there is something that gogs is sending that is being lost in the copy/paste, or the environment in which webhook is running is making it misbehave.

adnanh on 21 May 2020

Using the version in the Ubuntu 20.04 repos:

jch@nixie[535]:docker-g10k-webhook$ webhook --hooks ./g10k.yaml.tmpl -template -verbose --port 18140
[webhook] 2020/05/21 08:57:57 version 2.6.9 starting
[webhook] 2020/05/21 08:57:57 setting up os signal watcher
[webhook] 2020/05/21 08:57:57 attempting to load hooks from ./g10k.yaml.tmpl
[webhook] 2020/05/21 08:57:57 os signal watcher ready
[webhook] 2020/05/21 08:57:57 found 4 hook(s) in file
[webhook] 2020/05/21 08:57:57   loaded: github
[webhook] 2020/05/21 08:57:57   loaded: gogs
[webhook] 2020/05/21 08:57:57   loaded: gitlab
[webhook] 2020/05/21 08:57:57   loaded: payload
[webhook] 2020/05/21 08:57:57 serving hooks on http://0.0.0.0:18140/hooks/{id}
[webhook] 2020/05/21 08:58:12 Started POST //hooks/gogs
[webhook] 2020/05/21 08:58:12 Completed 301 Moved Permanently in 59.25µs
[webhook] 2020/05/21 08:58:12 Started GET /hooks/gogs
[webhook] 2020/05/21 08:58:12 [98d411] incoming HTTP request from 172.19.0.2:41840
[webhook] 2020/05/21 08:58:12 [98d411] gogs got matched
[webhook] 2020/05/21 08:58:12 [98d411] error parsing JSON payload EOF
[webhook] 2020/05/21 08:58:12 [98d411] error evaluating hook: invalid payload signature 76cda40505e58837211ee37fe7e8c819e31f33a1221a686fbebbe5829002ea01
[webhook] 2020/05/21 08:58:12 Completed 500 Internal Server Error in 148.516µs

Let me see if I can build from master and add some debugging.

jchonig on 21 May 2020

Could you also try one more thing before doing that, fix the request url so that it's hooks/gogs instead of /hooks/gogs in the gogs?

adnanh on 21 May 2020

I'm starting to wonder if gogs webhook sending logic can handle redirects properly :/

adnanh on 21 May 2020

Could you also try one more thing before doing that, fix the request url so that it's hooks/gogs instead of /hooks/gogs in the gogs?

D'oh! That was it!

Here's some debugging that I added:

diff --git a/webhook.go b/webhook.go
index 3af8ab4..840bd4d 100644
--- a/webhook.go
+++ b/webhook.go
@@ -246,6 +246,9 @@ func hookHandler(w http.ResponseWriter, r *http.Request) {
        if err != nil {
            log.Printf("[%s] error reading the request body. %+v\n", rid, err)
        }
+//     fmt.Printf("BODY: %d %d '%s'\n", len(body), len(string(body)), string(body))
+       fmt.Printf("REQUEST: %#v\n", r)
+       fmt.Printf("REQUEST: %#v\n", r.Body)

        // parse headers
        headers := valuesToMap(r.Header)

Which shows:

REQUEST: &http.Request{Method:"GET", URL:(*url.URL)(0xc00012a200), Proto:"HTTP/1.1", ProtoMajor:1, ProtoMinor:1, Header:http.Header{"Accept-Encoding":[]string{"gzip"}, "Content-Type":[]string{"application/json"}, "Referer":[]string{"http://nixie.home.honig.net:18140//hooks/gogs"}, "User-Agent":[]string{"GogsServer"}, "X-Github-Delivery":[]string{"9a37cb8c-151c-4801-9f38-f722e93c85fa"}, "X-Github-Event":[]string{"push"}, "X-Gogs-Delivery":[]string{"9a37cb8c-151c-4801-9f38-f722e93c85fa"}, "X-Gogs-Event":[]string{"push"}, "X-Gogs-Signature":[]string{"76cda40505e58837211ee37fe7e8c819e31f33a1221a686fbebbe5829002ea01"}}, Body:http.noBody{}, GetBody:(func() (io.ReadCloser, error))(nil), ContentLength:0, TransferEncoding:[]string(nil), Close:false, Host:"nixie.home.honig.net:18140", Form:url.Values(nil), PostForm:url.Values(nil), MultipartForm:(*multipart.Form)(nil), Trailer:http.Header(nil), RemoteAddr:"172.19.0.2:42716", RequestURI:"/hooks/gogs", TLS:(*tls.ConnectionState)(nil), Cancel:(<-chan struct {})(nil), Response:(*http.Response)(nil), ctx:(*context.valueCtx)(0xc0000f8360)}
REQUEST: http.noBody{}

Might I suggest checking for an empty body. And also bailing if the json.Decode() fails?

Thanks for your help finding my typo!

jchonig on 21 May 2020

👍2

Dang it. I just noticed that your original post has the debug output and the body isn't printed. Duh! I should have caught that.

Might I suggest checking for an empty body. And also bailing if the json.Decode() fails?

Well, empty bodies are acceptable in some scenarios. And a failed JSON decode may be acceptable, too, since we attempt to decode it even if you're not referencing it in the trigger rules.

I think more applicable to your issue would have been a warning that you requested a signature validation on an empty body. That may be easy to add.

It would require more work (I think) but be even more helpful to add warnings if you use any payload references when an empty body is sent.

Braindump:
I don't have time to flesh this out right now, but wanted to leave a note (at least for myself). Maybe we add a Hook property such as RequireBody bool that we set to true if we find any payload references in the hook definition. We can bail early in the request processing if we get an empty body.

moorereason on 21 May 2020

Was this page helpful?

0 / 5 - 0 ratings