Webhook subscriptions not receiving all events

[ivis-tsukioka]

I set up a subscription of webhook for FireFly to send events to our app.
But our app have received a part of event's notice from FireFly.
I think that webhook subscription is permanence.
Is it right?

I send request body(below json) for "[POST] /api/v1/namespaces/default/subscriptions" to set up a subscription of webhook.
Did I get a wrong setting?

Now, after receiving event's notice, I set up a new a subscription of webhook to continuously receive event.

request body

{
    "options": {
        "url": "http://<IP address>:8082/emit",
    	"fastack": false,
    	"readAhead":100,
    	"method": "POST",
    	"withData": false,
        "firstEvent": "oldest",
        "headers" : {
            "Authorization": "<Bearer token>"
        }
    },

    "namespace": "default",
    "name": "emitSub",

    "transport": "webhooks",
    "filter": {
        "topic": "string",
        "events": "blockchain_event_received",
        "blockchainevent": {
            "message": {},
            "transaction": {},
            "listener": "<listener_id>"
        }
    }
}

[nguyer]

Hi @ivis-tsukioka. If you have questions about how subscriptions and webhooks work, I would suggest asking in the Hyperledger Discord server in the #firefly channel https://discord.gg/nnQw2aGhX6 You will likely get a much better response there from the community.

If you suspect there is a bug in FireFly, please feel free to re-open this issue, and clearly indicate:

• The exact steps to reproduce what you saw
• The actual result
• The expected result

Thanks!

[nguyer]

After further investigation, I do think there is likely a bug here, so I'm reopening this one

[nguyer]

I did some testing on this and was able to reproduce what @ivis-tsukioka was seeing.

• I have a custom smart contract that emits 10 events when a certain function executes
• I have a subscription set up to send webhooks to a simple web server (written in Go) that will log the request and always send a 200.
• When I invoke the function I get one, or maybe two events (haven't figured out what makes the difference) and then nothing else. I see all 10 events in the FireFly Explorer, so FireFly got them.
• If I invoke the function again, I get nothing so it seems like the subscription is "stuck", but I'm pretty confident my web server should be "acking" the request with a 200 response each time.
• If I delete and recreate the subscription, up to the first two events are re-delivered and it gets "stuck" again.

[nguyer]

Attaching logs from a clean slate, reproducing this behavior, and shutting it down

geth.log
firefly_core.log
ethconnect.log

[peterbroadhurst]

In the logs, I see us go into the backend request, but never come back:

[2022-09-22T17:25:23.105Z] DEBUG ==> POST http://host.docker.internal:1234/walletReceiver breq=LiHKZU5S pid=1

While there is room for improvement in the logs in the webhooks code meaning this is really the only thing logged, there I am confident from all the other places that we use ffresty wrapper, that it would log the return from the call in DEBUG level.

[peterbroadhurst]

The lack of logging might have been a red-herring here, due to using resty in raw response mode for the webhooks code.
I've raised #1072 to improve the logging, and based on code analysis I believe I see the problem.

Not sure how long ago this was introduced, but in the case of a non-reply, non-fastack webhook, we weren't actually doing the automatic acknowledgement when the response came back

[peterbroadhurst]

As well as updating the code, I've done an extra update on the docs - particularly to clarify the behavior around redelivery of webhook events. The code generated docs for retry were missing, and the docs in the reference section for Subscription that go into the details of how Webhooks work were misleading when compared to the code.