Adjust "Response" and "State" when Queue enabled

[sahaqaa]

Hello, we've previously used version "2.0.1", now we are upgrading to "2.2.0". Full current config:

server:
  protected: true
  user: <%= $webhook_username %>
  password: <%= $webhook_password %>
  port: 8088
  tls:
    enabled: false
    certificate: ""
    key: ""
  queue:
    enabled: true
    max_concurrent_jobs: 1
    max_history_items: 20
r10k:
  config_path: /etc/puppetlabs/r10k/r10k.yaml
  default_branch: production
  allow_uppercase: true
  verbose: false

When testing we've seen next output in logs of Bitbucket server:

{"Id":"ca058a06-6e4d-11ee-9b22-02b1b244607d","Name":"testing_webhook_upgrade","CommandType":"env","AddedAt":"2023-10-19T07:04:47.596187402Z","StartedAt":"0001-01-01T00:00:00Z","FinishedAt":"0001-01-01T00:00:00Z","Command":["r10k","deploy","environment","testing_webhook_upgrade","--config=/etc/puppetlabs/r10k/r10k.yaml","--generate-types","--modules"],"Response":null,"State":"added"}

and in logs of systemd service:

$ systemctl status puppet-webhook.service 
● puppet-webhook.service - Puppet Deployment API Server
     Loaded: loaded (/etc/systemd/system/puppet-webhook.service; enabled; vendor preset: enabled)
     Active: active (running) since Thu 2023-10-19 06:55:13 UTC; 10min ago
       Docs: https://github.com/voxpupuli/webhook-go
   Main PID: 3182338 (webhook-go)
      Tasks: 5 (limit: 9399)
     Memory: 10.4M
     CGroup: /system.slice/puppet-webhook.service
             └─3182338 /opt/bitbucket-webhook/webhook-go server --config /opt/bitbucket-webhook/webhook.yml

Oct 19 06:55:13 puppet7 systemd[1]: Started Puppet Deployment API Server.
Oct 19 06:55:13 puppet7 webhook-go[3182338]: time="2023-10-19T06:55:13Z" level=info msg="start queue with 1 jobs"
Oct 19 06:55:13 puppet7 webhook-go[3182338]: time="2023-10-19T06:55:13Z" level=info msg="Worker is waiting for jobs"
Oct 19 07:01:54 puppet7 webhook-go[3182338]: [GIN] 2023/10/19 - 07:01:54 | 202 |    2.015361ms | 104.192.140.245 | POST     "/api/v1/r10k/environment"
Oct 19 07:01:54 puppet7 webhook-go[3182338]: time="2023-10-19T07:01:54Z" level=info msg="Worker picked Job 62ce1f3e-6e4d-11ee-9b22-02b1b244607d"
Oct 19 07:04:47 puppet7 webhook-go[3182338]: [GIN] 2023/10/19 - 07:04:47 | 202 |     419.796µs | 104.192.140.246 | POST     "/api/v1/r10k/environment"
Oct 19 07:04:47 puppet7 webhook-go[3182338]: time="2023-10-19T07:04:47Z" level=info msg="Worker picked Job ca058a06-6e4d-11ee-9b22-02b1b244607d"

What seems to be not right:

1. Response to Bitbucket
   Currently

"Response":null,"State":"added"

I believe in case webhook-go was able to process/deploy without errors - it may be better to send different "Response" and different "State".

When i change "verbose: true" response in Bitbucket server logs:

{"Id":"72b78852-6e52-11ee-8cdb-02b1b244607d","Name":"testing_webhook_upgrade","CommandType":"env","AddedAt":"2023-10-19T07:38:08.607012195Z","StartedAt":"0001-01-01T00:00:00Z","FinishedAt":"0001-01-01T00:00:00Z","Command":["r10k","deploy","environment","testing_webhook_upgrade","--config=/etc/puppetlabs/r10k/r10k.yaml","--verbose","--generate-types","--modules"],"Response":null,"State":"added"}

It would be better if, for example, "State" could be "applied" and "Response" could contain something like "Environment testing_webhook_upgrade is now at 80ba8d60a3545076534ef551f959a8c551c259f0"

2. Output into Systemd service logs

With " verbose: false" and with "verbose: true" output is the same:

$ systemctl status puppet-webhook.service 
● puppet-webhook.service - Puppet Deployment API Server
     Loaded: loaded (/etc/systemd/system/puppet-webhook.service; enabled; vendor preset: enabled)
     Active: active (running) since Thu 2023-10-19 07:37:27 UTC; 49s ago
...............................
Oct 19 07:37:27 puppet7 systemd[1]: Started Puppet Deployment API Server.
Oct 19 07:37:27 puppet7 webhook-go[3185508]: time="2023-10-19T07:37:27Z" level=info msg="start queue with 1 jobs"
Oct 19 07:37:27 puppet7 webhook-go[3185508]: time="2023-10-19T07:37:27Z" level=info msg="Worker is waiting for jobs"
Oct 19 07:38:08 puppet7 webhook-go[3185508]: [GIN] 2023/10/19 - 07:38:08 | 202 |    1.402347ms | 104.192.140.246 | POST     "/api/v1/r10k/environment"
Oct 19 07:38:08 puppet7 webhook-go[3185508]: time="2023-10-19T07:38:08Z" level=info msg="Worker picked Job 72b78852-6e52-11ee-8cdb-02b1b244607d"

I.e. i can see that first webhook-go sends response to Bitbucket server and only after that Worker picking up "job", but in logs there are no indications if Job succeded or not.

It would be good if in case when webhook-go was able to apply/deploy code -> there would be second entry with clear indication that code was applied/deployed successfully

[dhollinger]

@sahaqaa I will look into this. The issues I do see with this request at first glance are:

1. Changing the State to "applied" when it's added to the queue is not an accurate representation of the State.
2. I can't speak to BitBucket server, but GitLab and GitHub only allow a single response to a webhook call and that response has to come within 10 seconds. I imagine there's a similar requirement for Bitbucket.

As for the Response field, I will look into what's going on there. It should at least send a response stating what happened with the request. But a full tracking of state would require a separate service to report to.