publishBlockV2: latency streaming body from vc to bn due to big payload

[twoeths]

Describe the bug

When vc and bn stay on different machine, publishBlockV2 may take a long time - normally it takes <0.5s but could be up to >3s randomly. This is the log of 5 longest requests

5636:Dec-21 07:38:50.098[rest]            debug: Req req-4a1 127.0.0.1 publishBlockV2
5637:Dec-21 07:38:50.098[rest]            debug: preParsing req-4a1 127.0.0.1 publishBlockV2
5638:Dec-21 07:38:53.669[rest]            debug: preValidation req-4a1 127.0.0.1 publishBlockV2
5639:Dec-21 07:38:53.669[rest]            debug: Exec req-4a1 127.0.0.1 publishBlockV2
5640:Dec-21 07:38:53.693[rest]            debug: Res req-4a1 publishBlockV2 - 200

4751:Dec-21 07:03:25.830[rest]            debug: Req req-36v 127.0.0.1 publishBlockV2
4752:Dec-21 07:03:25.830[rest]            debug: preParsing req-36v 127.0.0.1 publishBlockV2
4753:Dec-21 07:03:28.829[rest]            debug: preValidation req-36v 127.0.0.1 publishBlockV2
4754:Dec-21 07:03:28.829[rest]            debug: Exec req-36v 127.0.0.1 publishBlockV2
4755:Dec-21 07:03:28.858[rest]            debug: Res req-36v publishBlockV2 - 200

5001:Dec-21 07:13:26.321[rest]            debug: Req req-3i1 127.0.0.1 publishBlockV2
5002:Dec-21 07:13:26.321[rest]            debug: preParsing req-3i1 127.0.0.1 publishBlockV2
5003:Dec-21 07:13:29.285[rest]            debug: preValidation req-3i1 127.0.0.1 publishBlockV2
5004:Dec-21 07:13:29.285[rest]            debug: Exec req-3i1 127.0.0.1 publishBlockV2
5005:Dec-21 07:13:29.334[rest]            debug: Res req-3i1 publishBlockV2 - 200

5681:Dec-21 07:40:38.286[rest]            debug: Req req-4c1 127.0.0.1 publishBlockV2
5682:Dec-21 07:40:38.286[rest]            debug: preParsing req-4c1 127.0.0.1 publishBlockV2
5683:Dec-21 07:40:41.188[rest]            debug: preValidation req-4c1 127.0.0.1 publishBlockV2
5684:Dec-21 07:40:41.189[rest]            debug: Exec req-4c1 127.0.0.1 publishBlockV2
5685:Dec-21 07:40:41.224[rest]            debug: Res req-4c1 publishBlockV2 - 200

4601:Dec-21 06:57:26.223[rest]            debug: Req req-306 127.0.0.1 publishBlockV2
4602:Dec-21 06:57:26.223[rest]            debug: preParsing req-306 127.0.0.1 publishBlockV2
4603:Dec-21 06:57:29.083[rest]            debug: preValidation req-306 127.0.0.1 publishBlockV2
4604:Dec-21 06:57:29.083[rest]            debug: Exec req-306 127.0.0.1 publishBlockV2
4605:Dec-21 06:57:29.142[rest]            debug: Res req-306 publishBlockV2 - 200

in the worse case it could cause missed or orphaned blocks

Expected behavior

Looking at the log we can see that it always take time after "preParsing" and before "preValidation" hook, likely happens at this phase https://github.com/fastify/fastify/blob/bc8743a2f225c92ad68cf2ad11bcd6930249fb69/lib/handleRequest.js#L41

This does 2 things: wait for body stream from vc to bn and JSON.parse

I guess JSON.parse() is not an issue because it only happen randomly when vc stay on a different machine than bn, so could be a network thing. I think we can reduce the bandwidth of this api by either:

• only return BlindedBeaconBlock to vc cc @g11tech
• or ssz api cc @wemeetagain @nflaig

Steps to reproduce

Run bn and vc in 2 diferent 2 hosts with this branch: tuyen/produce_block_interop_key which use interop key to produce and publish block at every slot (but bn does not spread block to the network)

Additional context

No response

Operating system

Linux

Lodestar version or commit hash

v1.12.0

[nflaig]

I guess JSON.parse() is not an issue because it only happen randomly when vc stay on a different machine than bn

Are you sure about that? Based on preParsing docs you can modify the request payload stream in that hook which means it should be already streamed, or at least that's what I would expect.

[twoeths]

Are you sure about that? Based on preParsing docs you can modify the request payload stream in that hook which means it should be already streamed, or at least that's what I would expect.

@nflaig yes, based on the log and the way it's implemented in the code I linked in the issue. I'm not sure about the example, but modifying the request payload stream doesn't mean the whole payload is flushed from vc to bn

[twoeths]

rebased against #6227 I love how lightweight it is to go with localBlinded @g11tech

vs the whole payload like yesterday's test

[g11tech]

rebased against #6227 I love how lightweight it is to go with localBlinded @g11tech

wow didn't imagine the diff would be so huge