What happens to subsequent events in a webhook subscription batch if one fails?

rossgamble1 · 22 November 2021 11:00

We have a webhook subscription setup to send deployment step notifications to an internal endpoint (queued, started, succeeded and failed).

We have just encountered a issue where we did not receive a webhook payload for a “Deployment Succeeded” event and on further inspection of the completed tasks we cannot see a task being raised to process the subscription for the event.

However, we can see another event raised at the same time that resulted in a non-successful response (404) from our webhook endpoint. In the payload of this webhook request, we noticed it was event #1 in a batch of 2 events.

Did we not receive the second event (presumably the “Deployment Successful” event) due to the non-success return code of the first event in the batch?

charles.hague · 22 November 2021 16:05

Hi Ross,

Thank you for reaching out to us and sorry for the delay in replying.

I’ve been attempting to replicate this on my test instance but I’ve been unable to do so. I’ve tried with a single subscription monitoring multiple events and with multiple subscriptions monitoring a single event each. In all cases the subscription appears to fire regardless of a previous failure (HTTP 404).

Could you please confirm your exact subscription configuration and, if possible, provide any relevant task logs? This may help us to narrow down where the issue is.

Please let me know if you have any questions.

Best Regards,

Charles

rossgamble1 · 23 November 2021 14:41

Hi Charles, here’s some more info on our setup, we’ve been able to reproduce it using the following.

Subscription

Filters:

Event group: Deployment Events
Project: Test Project

Project

A really simple tenanted deployment project with one step in the process:

Powershell step that logs to the console

Webhook Endpoint

A simple .NET Core REST API that receives and logs the webhook payload then returns a NotFound 404 response.

Simulation #1

We wrote a small console app to call the Octopus API and start an immediate deployment using the test project to two different tenants.

Results

Octopus Task

In Octopus Tasks, we see a task for “Process Subscriptions” that “completes successfully with warnings or errors”. Here is the raw task log:

                    | == Warning: Process subscriptions ==
13:49:02   Verbose  |   Cleaning up completed Subscription tasks. Deleting 0 finished tasks...
                    | 
                    |   == Warning: Test Subscription ==
13:49:02   Info     |     Processing subscription [Test Subscription](~/app#/Spaces-1/configuration/subscriptions/Subscriptions-2)...
13:49:51   Error    |     Failed to send webhook request.
                    |     Webhook https://{webhook-endpoint-url}:443/DeploymentWebhookSubscription (Events-685965) failed, with a status of NotFound.
                    |     Octopus.Shared.ControlledFailureException: Webhook https://{webhook-endpoint-url}:443/DeploymentWebhookSubscription (Events-685965) failed, with a status of NotFound.
                    |     at Octopus.Server.Orchestration.ServerTasks.ProcessSubscriptions.EventNotifications.WebhookNotificationProcessor.SendWebhookNotifications(ILogContext logContext, ITaskContext taskContext, HttpClient httpClient, Subscription subscription, Team team, IReadOnlyCollection`1 events, DateTimeOffset lastProcessed, DateTimeOffset processingDate, ServerConfiguration serverConfiguration) in C:\BuildAgent\work\c42ca9d2b8233f1c\source\Octopus.Server\Orchestration\ServerTasks\ProcessSubscriptions\EventNotifications\WebhookNotificationProcessor.cs:line 184
                    |     Octopus.Server version 2021.1.7316 (2021.1.7316+Branch.release-2021.1.Sha.67cf4e27c2f0544fc03c1500e7b388aaf7f70b3e)
13:49:51   Info     |     Finished processing subscription.

Webhook Endpoint

In the webhook endpoint, prior to returning the NotFound 404 response, we logged the following payload (with some Subscription and Event data removed):

{
    "Timestamp": "2021-11-23T13:49:03.0382648+00:00",
    "EventType": "SubscriptionPayload",
    "Payload": {
        "ServerUri": null,
        "ServerAuditUri": null,
        "BatchProcessingDate": "2021-11-23T13:49:02.7577439+00:00",
        "Subscription": {...},
        "Event": {
            ...
            "Category": "DeploymentQueued",
            ...
        },
        "BatchId": "33ed61b7-6839-4afe-9105-af0f52874745",
        "TotalEventsInBatch": 6,
        "EventNumberInBatch": 1
    }
}

It is at this point where we see the issue. We have no further logs in the webhook endpoint for events 2-6 for that batch ID: 33ed61b7-6839-4afe-9105-af0f52874745.

Simulation #2

We modified the webhook endpoint to return an NoContent 204 result and ran the same test as above.

Results

Octopus Task

This time, the “Process Subscriptions” task reported complete success, no warnings or errors in the task log.

Webhook Endpoint

We saw all 6 events belonging to the batch logged in the API too.

is this a bug?

charles.hague · 23 November 2021 15:37

Hi Ross,

Thank you for getting back to me and for the detailed investigation.

The only difference I can see at a glance from your reproduction is the use of Tenants. It’s possible that this is a factor. I’ll attempt to reproduce using Tenants and get back to you as soon as I can.

In the meantime, please let me know if you have any questions.

Best Regards,

Charles

charles.hague · 24 November 2021 10:25

Hi Ross,

Thank you for waiting while I worked on this.

I’ve managed to reproduce this behaviour. The Tenants weren’t required in the end, but the events have to be triggered in a certain way which my earlier reproduction didn’t involve.

I’m not certain whether this is the intended behaviour or a bug so I’ve reached out to our engineering team who should be able to confirm either way. I’ll let you know as soon as I hear back from them.

Best Regards,

Charles

charles.hague · 29 November 2021 10:25

Hi Ross,

Thank you for waiting while we looked into this.

The team agree that this is a bug and so I’ve created an issue for it on GitHub. The issue is public and you can subscribe to it for updates if you would like to do so:

github.com/OctopusDeploy/Issues

Batched webhook subscriptions abort after a single failure

opened 10:23AM - 29 Nov 21 UTC

charles-hague-octopus

kind/bug state/triage team/fire-and-motion

### Team - [X] I've assigned a team label to this issue ### Severity N/A (tra…nsient issue) ### Version 2021.3 ### Latest Version Not applicable ### What happened? A batched webhook subscription task can contain multiple events. If the webhook call for one of these events fails (e.g. gets a HTTP 404) then any subsequent webhook calls in the task won't be attempted. This means that any remaining events in that batched webhook subscription task will not be sent. The system should instead attempt to send all events regardless of prior failures. ### Reproduction The key steps to reproduce the failure are as follows: * Create a subscription to a valid endpoint * Perform whatever actions are needed to create a batch (hint: create and save environments) * Observe in Tasks that all relevant events were sent in a single ‘Process Subscriptions’ task * Observe on the endpoint that multiple POSTs are received, one for each event in the batch * Change the subscription to point to an invalid endpoint * Perform whatever actions are needed to create a batch * Observe in Tasks that no events were sent in a single ‘Process Subscriptions’ task * Change the subscription to once again point to a valid endpoint * Wait for a while and confirm that no further ‘Process Subscription’ tasks run * Perform whatever actions are needed to create a batch * Observe in Tasks that only the new events were sent in a single ‘Process Subscriptions’ task * Observe on the endpoint POSTs are only received for the new events There are more detailed instructions in an internal note on the Discourse thread linked below. ### Error and Stacktrace ```shell Processing subscription Subscription Testing... November 24th 2021 09:58:02Error Failed to send webhook request. Name or service not known (doesntexist.octopus.com:443) System.Net.Http.HttpRequestException: Name or service not known (doesntexist.octopus.com:443) ---> System.Net.Sockets.SocketException (0xFFFDFFFF): Name or service not known at System.Net.Sockets.Socket.AwaitableSocketAsyncEventArgs.ThrowException(SocketError error, CancellationToken cancellationToken) at System.Net.Sockets.Socket.AwaitableSocketAsyncEventArgs.System.Threading.Tasks.Sources.IValueTaskSource.GetResult(Int16 token) at System.Net.Sockets.Socket.<ConnectAsync>g__WaitForConnectWithCancellation|283_0(AwaitableSocketAsyncEventArgs saea, ValueTask connectTask, CancellationToken cancellationToken) at System.Net.Http.HttpConnectionPool.DefaultConnectAsync(SocketsHttpConnectionContext context, CancellationToken cancellationToken) at System.Net.Http.ConnectHelper.ConnectAsync(Func`3 callback, DnsEndPoint endPoint, HttpRequestMessage requestMessage, CancellationToken cancellationToken) --- End of inner exception stack trace --- at System.Net.Http.ConnectHelper.ConnectAsync(Func`3 callback, DnsEndPoint endPoint, HttpRequestMessage requestMessage, CancellationToken cancellationToken) at System.Net.Http.HttpConnectionPool.ConnectAsync(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken) at System.Net.Http.HttpConnectionPool.CreateHttp11ConnectionAsync(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken) at System.Net.Http.HttpConnectionPool.GetHttpConnectionAsync(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken) at System.Net.Http.HttpConnectionPool.SendWithRetryAsync(HttpRequestMessage request, Boolean async, Boolean doRequestAuth, CancellationToken cancellationToken) at System.Net.Http.RedirectHandler.SendAsync(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken) at System.Net.Http.DecompressionHandler.SendAsync(HttpRequestMessage request, Boolean async, CancellationToken cancellationToken) at System.Net.Http.HttpClient.SendAsyncCore(HttpRequestMessage request, HttpCompletionOption completionOption, Boolean async, Boolean emitTelemetryStartStop, CancellationToken cancellationToken) at Octopus.Server.Orchestration.ServerTasks.ProcessSubscriptions.EventNotifications.WebhookNotificationProcessor.SendWebhookNotifications(ITaskLog taskLog, Action ensureServerTaskCancelNotRequestedByUser, HttpClient httpClient, Subscription subscription, Team team, IReadOnlyCollection`1 events, DateTimeOffset lastProcessed, DateTimeOffset processingDate, ServerConfiguration serverConfiguration) in ./source/Octopus.Server/Orchestration/ServerTasks/ProcessSubscriptions/EventNotifications/WebhookNotificationProcessor.cs:line 175 Octopus.Server version 2021.3.8275 (2021.3.8275) November 24th 2021 09:58:02Info Finished processing subscription. ``` ### More Information https://help.octopus.com/t/what-happens-to-subsequent-events-in-a-webhook-subscription-batch-if-one-fails/27412 https://octopusdeploy.slack.com/archives/CNHBHV2BX/p1637751002456700 (internal discussion) ### Workaround N/A

I hope this is helpful. Please let me know if you have any questions.

Best Regards,

Charles

rossgamble1 · 29 November 2021 10:29

Thanks Charles, I’ll watch the GitHub issue.

system · 30 December 2021 10:30

This topic was automatically closed 31 days after the last reply. New replies are no longer allowed.