Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

HttpClient: log request and response #3913

Merged
merged 2 commits into from
Apr 15, 2022
Merged

HttpClient: log request and response #3913

merged 2 commits into from
Apr 15, 2022

Conversation

twoeths
Copy link
Contributor

@twoeths twoeths commented Apr 12, 2022

Motivation

Similar to the node side, we want to debug when we request and get response from validator side

Description

part of #3911

@github-actions
Copy link
Contributor

github-actions bot commented Apr 12, 2022 •
edited
Loading

Performance Report

✔️ no performance regression detected

Full benchmark results
Benchmark suite Current: 381312a Previous: bb7ca8d Ratio
BeaconState.hashTreeRoot - No change 422.00 ns/op 548.00 ns/op 0.77
BeaconState.hashTreeRoot - 1 full validator 55.810 us/op 54.724 us/op 1.02
BeaconState.hashTreeRoot - 32 full validator 536.73 us/op 557.84 us/op 0.96
BeaconState.hashTreeRoot - 512 full validator 5.9979 ms/op 5.9171 ms/op 1.01
BeaconState.hashTreeRoot - 1 validator.effectiveBalance 67.759 us/op 69.432 us/op 0.98
BeaconState.hashTreeRoot - 32 validator.effectiveBalance 947.75 us/op 939.99 us/op 1.01
BeaconState.hashTreeRoot - 512 validator.effectiveBalance 12.774 ms/op 12.813 ms/op 1.00
BeaconState.hashTreeRoot - 1 balances 46.620 us/op 52.808 us/op 0.88
BeaconState.hashTreeRoot - 32 balances 412.14 us/op 469.92 us/op 0.88
BeaconState.hashTreeRoot - 512 balances 4.0582 ms/op 4.5384 ms/op 0.89
BeaconState.hashTreeRoot - 250000 balances 101.73 ms/op 98.624 ms/op 1.03
processSlot - 1 slots 9.5000 us/op 9.5070 us/op 1.00
processSlot - 32 slots 1.5472 ms/op 1.5971 ms/op 0.97
getCommitteeAssignments - req 1 vs - 250000 vc 5.2609 ms/op 5.2541 ms/op 1.00
getCommitteeAssignments - req 100 vs - 250000 vc 7.3399 ms/op 7.2724 ms/op 1.01
getCommitteeAssignments - req 1000 vs - 250000 vc 7.8685 ms/op 7.7400 ms/op 1.02
computeProposers - vc 250000 14.912 ms/op 17.321 ms/op 0.86
computeEpochShuffling - vc 250000 149.99 ms/op 158.57 ms/op 0.95
getNextSyncCommittee - vc 250000 277.71 ms/op 286.99 ms/op 0.97
altair processAttestation - 250000 vs - 7PWei normalcase 3.4593 ms/op 4.1630 ms/op 0.83
altair processAttestation - 250000 vs - 7PWei worstcase 5.1825 ms/op 5.4843 ms/op 0.94
altair processAttestation - setStatus - 1/6 committees join 189.05 us/op 191.85 us/op 0.99
altair processAttestation - setStatus - 1/3 committees join 369.48 us/op 331.07 us/op 1.12
altair processAttestation - setStatus - 1/2 committees join 514.85 us/op 519.15 us/op 0.99
altair processAttestation - setStatus - 2/3 committees join 593.01 us/op 668.84 us/op 0.89
altair processAttestation - setStatus - 4/5 committees join 799.02 us/op 925.95 us/op 0.86
altair processAttestation - setStatus - 100% committees join 1.0867 ms/op 1.1029 ms/op 0.99
altair processBlock - 250000 vs - 7PWei normalcase 26.020 ms/op 25.580 ms/op 1.02
altair processBlock - 250000 vs - 7PWei normalcase hashState 30.990 ms/op 35.559 ms/op 0.87
altair processBlock - 250000 vs - 7PWei worstcase 74.719 ms/op 68.805 ms/op 1.09
altair processBlock - 250000 vs - 7PWei worstcase hashState 93.247 ms/op 107.68 ms/op 0.87
altair processEth1Data - 250000 vs - 7PWei normalcase 700.40 us/op 663.52 us/op 1.06
altair processEpoch - mainnet_e81889 533.35 ms/op 474.81 ms/op 1.12
mainnet_e81889 - altair beforeProcessEpoch 121.36 ms/op 154.86 ms/op 0.78
mainnet_e81889 - altair processJustificationAndFinalization 39.043 us/op 29.571 us/op 1.32
mainnet_e81889 - altair processInactivityUpdates 10.581 ms/op 10.190 ms/op 1.04
mainnet_e81889 - altair processRewardsAndPenalties 121.47 ms/op 127.96 ms/op 0.95
mainnet_e81889 - altair processRegistryUpdates 6.0790 us/op 6.3880 us/op 0.95
mainnet_e81889 - altair processSlashings 1.6210 us/op 1.8360 us/op 0.88
mainnet_e81889 - altair processEth1DataReset 1.7250 us/op 2.0530 us/op 0.84
mainnet_e81889 - altair processEffectiveBalanceUpdates 6.6464 ms/op 6.8075 ms/op 0.98
mainnet_e81889 - altair processSlashingsReset 8.0020 us/op 9.4840 us/op 0.84
mainnet_e81889 - altair processRandaoMixesReset 9.5890 us/op 10.472 us/op 0.92
mainnet_e81889 - altair processHistoricalRootsUpdate 2.1440 us/op 2.8060 us/op 0.76
mainnet_e81889 - altair processParticipationFlagUpdates 4.6360 us/op 5.1330 us/op 0.90
mainnet_e81889 - altair processSyncCommitteeUpdates 929.00 ns/op 1.5760 us/op 0.59
mainnet_e81889 - altair afterProcessEpoch 176.28 ms/op 186.23 ms/op 0.95
altair processInactivityUpdates - 250000 normalcase 31.940 ms/op 31.507 ms/op 1.01
altair processInactivityUpdates - 250000 worstcase 26.499 ms/op 26.611 ms/op 1.00
altair processRewardsAndPenalties - 250000 normalcase 122.85 ms/op 76.212 ms/op 1.61
altair processRewardsAndPenalties - 250000 worstcase 74.210 ms/op 103.14 ms/op 0.72
altair processSyncCommitteeUpdates - 250000 277.29 ms/op 292.82 ms/op 0.95
Tree 40 250000 create 630.82 ms/op 613.03 ms/op 1.03
Tree 40 250000 get(125000) 282.78 ns/op 289.76 ns/op 0.98
Tree 40 250000 set(125000) 2.0883 us/op 1.9968 us/op 1.05
Tree 40 250000 toArray() 31.202 ms/op 31.017 ms/op 1.01
Tree 40 250000 iterate all - toArray() + loop 31.306 ms/op 30.701 ms/op 1.02
Tree 40 250000 iterate all - get(i) 108.71 ms/op 108.88 ms/op 1.00
MutableVector 250000 create 13.728 ms/op 14.108 ms/op 0.97
MutableVector 250000 get(125000) 12.937 ns/op 13.063 ns/op 0.99
MutableVector 250000 set(125000) 542.48 ns/op 518.58 ns/op 1.05
MutableVector 250000 toArray() 5.4324 ms/op 6.1947 ms/op 0.88
MutableVector 250000 iterate all - toArray() + loop 6.0380 ms/op 6.2763 ms/op 0.96
MutableVector 250000 iterate all - get(i) 3.4405 ms/op 3.2800 ms/op 1.05
Array 250000 create 4.7252 ms/op 5.6135 ms/op 0.84
Array 250000 clone - spread 2.1229 ms/op 2.4696 ms/op 0.86
Array 250000 get(125000) 1.0010 ns/op 1.1320 ns/op 0.88
Array 250000 set(125000) 0.99400 ns/op 1.1120 ns/op 0.89
Array 250000 iterate all - loop 148.03 us/op 167.84 us/op 0.88
effectiveBalanceIncrements clone Uint8Array 300000 71.745 us/op 69.059 us/op 1.04
effectiveBalanceIncrements clone MutableVector 300000 465.00 ns/op 768.00 ns/op 0.61
effectiveBalanceIncrements rw all Uint8Array 300000 266.20 us/op 301.96 us/op 0.88
effectiveBalanceIncrements rw all MutableVector 300000 137.87 ms/op 177.73 ms/op 0.78
aggregationBits - 2048 els - zipIndexesInBitList 23.022 us/op 28.567 us/op 0.81
regular array get 100000 times 59.458 us/op 67.439 us/op 0.88
wrappedArray get 100000 times 59.470 us/op 67.429 us/op 0.88
arrayWithProxy get 100000 times 32.177 ms/op 31.854 ms/op 1.01
ssz.Root.equals 387.00 ns/op 486.00 ns/op 0.80
byteArrayEquals 359.00 ns/op 466.00 ns/op 0.77
phase0 processBlock - 250000 vs - 7PWei normalcase 3.2709 ms/op 3.5364 ms/op 0.92
phase0 processBlock - 250000 vs - 7PWei worstcase 38.955 ms/op 45.343 ms/op 0.86
phase0 afterProcessEpoch - 250000 vs - 7PWei 164.28 ms/op 174.04 ms/op 0.94
phase0 beforeProcessEpoch - 250000 vs - 7PWei 77.899 ms/op 70.813 ms/op 1.10
phase0 processEpoch - mainnet_e58758 503.86 ms/op 562.79 ms/op 0.90
mainnet_e58758 - phase0 beforeProcessEpoch 205.52 ms/op 245.66 ms/op 0.84
mainnet_e58758 - phase0 processJustificationAndFinalization 35.141 us/op 28.047 us/op 1.25
mainnet_e58758 - phase0 processRewardsAndPenalties 66.760 ms/op 123.04 ms/op 0.54
mainnet_e58758 - phase0 processRegistryUpdates 17.199 us/op 18.711 us/op 0.92
mainnet_e58758 - phase0 processSlashings 2.0670 us/op 1.9670 us/op 1.05
mainnet_e58758 - phase0 processEth1DataReset 1.9930 us/op 1.7930 us/op 1.11
mainnet_e58758 - phase0 processEffectiveBalanceUpdates 5.3262 ms/op 5.6361 ms/op 0.95
mainnet_e58758 - phase0 processSlashingsReset 7.6330 us/op 6.4070 us/op 1.19
mainnet_e58758 - phase0 processRandaoMixesReset 10.287 us/op 9.7340 us/op 1.06
mainnet_e58758 - phase0 processHistoricalRootsUpdate 1.3770 us/op 2.2690 us/op 0.61
mainnet_e58758 - phase0 processParticipationRecordUpdates 9.5900 us/op 11.479 us/op 0.84
mainnet_e58758 - phase0 afterProcessEpoch 142.50 ms/op 155.17 ms/op 0.92
phase0 processEffectiveBalanceUpdates - 250000 normalcase 5.7897 ms/op 6.4688 ms/op 0.90
phase0 processEffectiveBalanceUpdates - 250000 worstcase 0.5 6.1775 ms/op 6.8776 ms/op 0.90
phase0 processRegistryUpdates - 250000 normalcase 14.237 us/op 14.336 us/op 0.99
phase0 processRegistryUpdates - 250000 badcase_full_deposits 576.11 us/op 490.37 us/op 1.17
phase0 processRegistryUpdates - 250000 worstcase 0.5 228.98 ms/op 211.87 ms/op 1.08
phase0 getAttestationDeltas - 250000 normalcase 14.054 ms/op 14.825 ms/op 0.95
phase0 getAttestationDeltas - 250000 worstcase 14.087 ms/op 14.581 ms/op 0.97
phase0 processSlashings - 250000 worstcase 5.6532 ms/op 5.6495 ms/op 1.00
shuffle list - 16384 els 10.628 ms/op 10.642 ms/op 1.00
shuffle list - 250000 els 154.57 ms/op 153.38 ms/op 1.01
getEffectiveBalanceIncrementsZeroInactive - 250000 vs - 7PWei 363.72 us/op 356.54 us/op 1.02
pass gossip attestations to forkchoice per slot 3.3543 ms/op 3.4176 ms/op 0.98
computeDeltas 3.4440 ms/op 3.3106 ms/op 1.04
computeProposerBoostScoreFromBalances 503.16 us/op 503.07 us/op 1.00
getPubkeys - index2pubkey - req 1000 vs - 250000 vc 2.3006 ms/op 1.7903 ms/op 1.29
getPubkeys - validatorsArr - req 1000 vs - 250000 vc 80.473 us/op 79.583 us/op 1.01
BLS verify - blst-native 1.8561 ms/op 1.8583 ms/op 1.00
BLS verifyMultipleSignatures 3 - blst-native 3.7995 ms/op 3.8046 ms/op 1.00
BLS verifyMultipleSignatures 8 - blst-native 8.1843 ms/op 8.1871 ms/op 1.00
BLS verifyMultipleSignatures 32 - blst-native 29.658 ms/op 29.685 ms/op 1.00
BLS aggregatePubkeys 32 - blst-native 39.600 us/op 39.959 us/op 0.99
BLS aggregatePubkeys 128 - blst-native 155.06 us/op 153.56 us/op 1.01
getAttestationsForBlock 55.936 ms/op 58.008 ms/op 0.96
CheckpointStateCache - add get delete 10.128 us/op 10.455 us/op 0.97
validate gossip signedAggregateAndProof - struct 4.2509 ms/op 4.2553 ms/op 1.00
validate gossip attestation - struct 2.0252 ms/op 2.0308 ms/op 1.00
pickEth1Vote - no votes 2.2068 ms/op 2.2768 ms/op 0.97
pickEth1Vote - max votes 17.609 ms/op 18.828 ms/op 0.94
pickEth1Vote - Eth1Data hashTreeRoot value x2048 11.595 ms/op 11.651 ms/op 1.00
pickEth1Vote - Eth1Data hashTreeRoot tree x2048 19.248 ms/op 21.058 ms/op 0.91
pickEth1Vote - Eth1Data fastSerialize value x2048 1.4555 ms/op 1.8450 ms/op 0.79
pickEth1Vote - Eth1Data fastSerialize tree x2048 11.178 ms/op 12.220 ms/op 0.91
bytes32 toHexString 840.00 ns/op 916.00 ns/op 0.92
bytes32 Buffer.toString(hex) 616.00 ns/op 681.00 ns/op 0.90
bytes32 Buffer.toString(hex) from Uint8Array 826.00 ns/op 868.00 ns/op 0.95
bytes32 Buffer.toString(hex) + 0x 613.00 ns/op 704.00 ns/op 0.87
Object access 1 prop 0.28900 ns/op 0.32600 ns/op 0.89
Map access 1 prop 0.26300 ns/op 0.29600 ns/op 0.89
Object get x1000 15.552 ns/op 17.512 ns/op 0.89
Map get x1000 0.86100 ns/op 1.0770 ns/op 0.80
Object set x1000 91.823 ns/op 101.42 ns/op 0.91
Map set x1000 54.099 ns/op 62.244 ns/op 0.87
Return object 10000 times 0.33190 ns/op 0.36990 ns/op 0.90
Throw Error 10000 times 5.1673 us/op 5.8920 us/op 0.88
enrSubnets - fastDeserialize 64 bits 778.00 ns/op 909.00 ns/op 0.86
enrSubnets - ssz BitVector 64 bits 509.00 ns/op 578.00 ns/op 0.88
enrSubnets - fastDeserialize 4 bits 329.00 ns/op 405.00 ns/op 0.81
enrSubnets - ssz BitVector 4 bits 496.00 ns/op 598.00 ns/op 0.83
RateTracker 1000000 limit, 1 obj count per request 154.98 ns/op 179.37 ns/op 0.86
RateTracker 1000000 limit, 2 obj count per request 115.87 ns/op 132.66 ns/op 0.87
RateTracker 1000000 limit, 4 obj count per request 95.956 ns/op 114.88 ns/op 0.84
RateTracker 1000000 limit, 8 obj count per request 85.776 ns/op 99.809 ns/op 0.86
RateTracker with prune 3.4250 us/op 3.6280 us/op 0.94
array of 16000 items push then shift 2.7259 us/op 3.1545 us/op 0.86
LinkedList of 16000 items push then shift 14.803 ns/op 15.767 ns/op 0.94
array of 16000 items push then pop 200.42 ns/op 197.45 ns/op 1.02
LinkedList of 16000 items push then pop 15.853 ns/op 16.001 ns/op 0.99
array of 24000 items push then shift 4.5518 us/op 4.5615 us/op 1.00
LinkedList of 24000 items push then shift 19.687 ns/op 18.003 ns/op 1.09
array of 24000 items push then pop 176.64 ns/op 186.93 ns/op 0.94
LinkedList of 24000 items push then pop 17.567 ns/op 17.510 ns/op 1.00

by benchmarkbot/action

@codecov
Copy link

codecov bot commented Apr 12, 2022 •
edited
Loading

Codecov Report

Merging #3913 (e4e6cb2) into master (053f76a) will decrease coverage by 0.00%.
The diff coverage is n/a.

@@            Coverage Diff             @@
##           master    #3913      +/-   ##
==========================================
- Coverage   36.32%   36.31%   -0.01%     
==========================================
  Files         324      324              
  Lines        9059     9064       +5     
  Branches     1453     1456       +3     
==========================================
+ Hits         3291     3292       +1     
- Misses       5597     5598       +1     
- Partials      171      174       +3

@dapplion
Copy link
Contributor

Warning! This is a breaking change to the API of lodestar-api. If we are gonna do the breaking change let's review the interface and ensure it doesn't change in the short - medium term again

@dapplion dapplion added the meta-breaking-change Introduces breaking changes to DB, Validator, Beacon Node, or CLI interfaces. Handle with care! label Apr 12, 2022
@twoeths twoeths marked this pull request as ready for review April 12, 2022 10:51
@twoeths
Copy link
Contributor Author

twoeths commented Apr 12, 2022 •
edited by g11tech
Loading

Warning! This is a breaking change to the API of lodestar-api. If we are gonna do the breaking change let's review the interface and ensure it doesn't change in the short - medium term again

This follows our convention constructor(options, modules), and modules could be extended in the future.

@dapplion do you know any apps use our api interface except for lodestar?

@g11tech
Copy link
Contributor

g11tech commented Apr 12, 2022

Warning! This is a breaking change to the API of lodestar-api. If we are gonna do the breaking change let's review the interface and ensure it doesn't change in the short - medium term again

This follows our convention constructor(options, modules), and modules could be extended in the future.

@dapplion do you know any apps use our api interface except for lodestar?

the light client demo, but i guess its easily updated 👍

wemeetagain
wemeetagain previously approved these changes Apr 12, 2022
View reviewed changes
Copy link
Member

@wemeetagain wemeetagain left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

LGTM

I think the breaking change is fine, aligns with the 'style' of our other code and makes it easier to add more modules to the client if we need.

@dapplion
Copy link
Contributor

dapplion commented Apr 13, 2022 •
edited
Loading

LGTM

I think the breaking change is fine, aligns with the 'style' of our other code and makes it easier to add more modules to the client if we need.

👍 sounds good to me.

Can we wait for #3914 ? the http client will have access the routeId and makes for nicer logging that dumping the full url.

@twoeths twoeths requested a review from a team as a code owner April 14, 2022 03:27
@twoeths twoeths merged commit 8898b2a into master Apr 15, 2022
@twoeths twoeths deleted the tuyen/log-http-client branch April 15, 2022 01:19
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Reviewers

@dapplion dapplion dapplion approved these changes

@wemeetagain wemeetagain wemeetagain left review comments

@g11tech g11tech Awaiting requested review from g11tech

@philknows philknows Awaiting requested review from philknows

Assignees
No one assigned
Labels
meta-breaking-change Introduces breaking changes to DB, Validator, Beacon Node, or CLI interfaces. Handle with care!
Projects
None yet
Milestone
No milestone
Development

Successfully merging this pull request may close these issues.
4 participants
@twoeths @dapplion @g11tech @wemeetagain