We're using batches in wrong way during persist, we already have all changes
accumulated in two maps and then we move them to batch and then this is
applied. For some DBs like BoltDB this batch is just another MemoryStore, so
we essentially just shuffle the changeset from one map to another, for others
like LevelDB batch is just a serialized set of KV pairs, it doesn't help much
on subsequent PutBatch, we just duplicate the changeset again.
So introduce PutChangeSet that allows to take two maps with sets and deletes
directly. It also allows to simplify MemCachedStore logic.
neo-bench for single node with 10 workers, LevelDB:
Reference:
RPS 30189.132 30556.448 30390.482 ≈ 30379 ± 0.61%
TPS 29427.344 29418.687 29434.273 ≈ 29427 ± 0.03%
CPU % 33.304 27.179 33.860 ≈ 31.45 ± 11.79%
Mem MB 800.677 798.389 715.042 ≈ 771 ± 6.33%
Patched:
RPS 30264.326 30386.364 30166.231 ≈ 30272 ± 0.36% ⇅
TPS 29444.673 29407.440 29452.478 ≈ 29435 ± 0.08% ⇅
CPU % 34.012 32.597 33.467 ≈ 33.36 ± 2.14% ⇅
Mem MB 549.126 523.656 517.684 ≈ 530 ± 3.15% ↓ 31.26%
BoltDB:
Reference:
RPS 31937.647 31551.684 31850.408 ≈ 31780 ± 0.64%
TPS 31292.049 30368.368 31307.724 ≈ 30989 ± 1.74%
CPU % 33.792 22.339 35.887 ≈ 30.67 ± 23.78%
Mem MB 1271.687 1254.472 1215.639 ≈ 1247 ± 2.30%
Patched:
RPS 31746.818 30859.485 31689.761 ≈ 31432 ± 1.58% ⇅
TPS 31271.499 30340.726 30342.568 ≈ 30652 ± 1.75% ⇅
CPU % 34.611 34.414 31.553 ≈ 33.53 ± 5.11% ⇅
Mem MB 1262.960 1231.389 1335.569 ≈ 1277 ± 4.18% ⇅
VM always has istack and it doesn't even change, so doing this microallocation
makes no sense. Notice that estack is a bit harder to change we do replace it
in some cases and we compare pointers to it as well.
It requires only two methods from Blockchainer: AddBlock and
BlockHeight. New interface will allow to easily reuse the block queue
for state exchange purposes.
Do not allocate a separate buffer for the transfer.
```
name old time/op new time/op delta
NEP17TransferLog_Append-8 58.8µs ± 3% 32.1µs ± 1% -45.40% (p=0.000 n=10+9)
name old alloc/op new alloc/op delta
NEP17TransferLog_Append-8 118kB ± 1% 44kB ± 3% -63.00% (p=0.000 n=9+10)
name old allocs/op new allocs/op delta
NEP17TransferLog_Append-8 901 ± 1% 513 ± 3% -43.08% (p=0.000 n=9+8)
```
Signed-off-by: Evgeniy Stratonikov <evgeniy@nspcc.ru>
Refactor code and be fine with sending to just 2/3 of proper peers. Previously
it was an edge case, but it can be a normal thing to do also as broadcasting
to everyone is obviously too expensive and excessive (hi, #608).
Baseline (four node, 10 workers):
RPS 8180.760 8137.822 7858.358 7820.011 8051.076 ≈ 8010 ± 2.04%
TPS 7819.831 7521.172 7519.023 7242.965 7426.000 ≈ 7506 ± 2.78%
CPU % 41.983 38.775 40.606 39.375 35.537 ≈ 39.3 ± 6.15%
Mem MB 2947.189 2743.658 2896.688 2813.276 2863.108 ≈ 2853 ± 2.74%
Patched:
RPS 9714.567 9676.102 9358.609 9371.408 9301.372 ≈ 9484 ± 2.05% ↑ 18.40%
TPS 8809.796 8796.854 8534.754 8661.158 8426.162 ≈ 8646 ± 1.92% ↑ 15.19%
CPU % 44.980 45.018 33.640 29.645 43.830 ≈ 39.4 ± 18.41% ↑ 0.25%
Mem MB 2989.078 2976.577 2306.185 2351.929 2910.479 ≈ 2707 ± 12.80% ↓ 5.12%
There is a nuance with this patch however. While typically it works the way
outlined above, sometimes it works like this:
RPS ≈ 6734.368
TPS ≈ 6299.332
CPU ≈ 25.552%
Mem ≈ 2706.046MB
And that's because the log looks like this:
DeltaTime, TransactionsCount, TPS
5014, 44212, 8817.710
5163, 49690, 9624.249
5166, 49523, 9586.334
5189, 49693, 9576.604
5198, 49339, 9491.920
5147, 49559, 9628.716
5192, 49680, 9568.567
5163, 49750, 9635.871
5183, 49189, 9490.450
5159, 49653, 9624.540
5167, 47945, 9279.079
5179, 2051, 396.022
5015, 4, 0.798
5004, 0, 0.000
5003, 0, 0.000
5003, 0, 0.000
5003, 0, 0.000
5003, 0, 0.000
5004, 0, 0.000
5003, 2925, 584.649
5040, 49099, 9741.865
5161, 49718, 9633.404
5170, 49228, 9521.857
5179, 49773, 9610.543
5167, 47253, 9145.152
5202, 49788, 9570.934
5177, 47704, 9214.603
5209, 46610, 8947.975
5249, 49156, 9364.831
5163, 18284, 3541.352
5072, 174, 34.306
On a network with 4 CNs and 1 RPC node there is 1/256 probability that a block
won't be broadcasted to RPC node, so it won't see it until ping timeout kicks
in. While it doesn't see a block it can't accept new incoming transactions so
the bench gets stuck basically. To me that's an acceptable trade-off because
normal networks are much larger than that and the effect of this patch is way
more important there, but still that's what we have and we need to take into
account.
send() can return errStateMismatch, errGone and errBusy. errGone means the
peer is dead and it won't ever be active again, it doesn't make sense retrying
sends to it. errStateMismatch is technically "not yet ready", but we can't
wait for it either, no one knows how much will it take to complete
handshake. So only errBusy means we can retry.
So keep track of dead peers and adjust tries counting appropriately.
It doesn't change much, we can't magically get more valid peers and if some
die while we're iterating we'd detect that by an error returned from send().
When transaction spreads through the network many nodes are likely to get it
in roughly the same time. They will rebroadcast it also in roughly the same
time. As we have a number of peers it's quite likely that we'd get an Inv with
the same transaction from multiple peers simultaneously. We will ask them for
this transaction (independently!) and again we're likely to get it in roughly
the same time. So we can easily end up with multiple threads processing the
same transaction. Only one will succeed, but we can actually easily avoid
doing it in the first place saving some CPU cycles for other things.
Notice that we can't do it _before_ receiving a transaction because nothing
guarantees that the peer will respond to our transaction request, so
communication overhead is unavoidable at the moment, but saving on processing
already gives quite interesting results.
Baseline, four nodes with 10 workers:
RPS 7176.784 7014.511 6139.663 7191.280 7080.852 ≈ 6921 ± 5.72%
TPS 6945.409 6562.756 5927.050 6681.187 6821.794 ≈ 6588 ± 5.38%
CPU % 44.400 43.842 40.418 49.211 49.370 ≈ 45.4 ± 7.53%
Mem MB 2693.414 2640.602 2472.007 2731.482 2707.879 ≈ 2649 ± 3.53%
Patched:
RPS ≈ 7791.675 7996.559 7834.504 7746.705 7891.614 ≈ 7852 ± 1.10% ↑ 13.45%
TPS ≈ 7241.497 7711.765 7520.211 7425.890 7334.443 ≈ 7447 ± 2.17% ↑ 13.04%
CPU % 29.853 39.936 39.945 36.371 39.999 ≈ 37.2 ± 10.57% ↓ 18.06%
Mem MB 2749.635 2791.609 2828.610 2910.431 2863.344 ≈ 2829 ± 1.97% ↑ 6.80%
Most of the time on healthy network we see new transactions appearing that are
not present in the mempool. Once they get into mempool we don't ask for them
again when some other peer sends an Inv with them. Then these transactions are
usually added into block, removed from mempool and no one actually sends them
again to us. Some stale nodes can do that, but it's not very likely to
happen.
At the receiving end at the same time it's quite expensive to do full chain
HasTransaction() query, so if we can avoid doing that it's always good. Here
it technically allows resending old transaction that will be re-requested and
an attempt to add it to mempool will be made. But it'll inevitably fail
because the same HasTransaction() check is done there too. One can try to
maliciously flood the node with stale transactions but it doesn't differ from
flooding it with any other invalid transactions, so there is no new attack
vector added.
Baseline, 4 nodes with 10 workers:
RPS 6902.296 6465.662 6856.044 6785.515 6157.024 ≈ 6633 ± 4.26%
TPS 6468.431 6218.867 6610.565 6288.596 5790.556 ≈ 6275 ± 4.44%
CPU % 50.231 42.925 49.481 48.396 42.662 ≈ 46.7 ± 7.01%
Mem MB 2856.841 2684.103 2756.195 2733.485 2422.787 ≈ 2691 ± 5.40%
Patched:
RPS 7176.784 7014.511 6139.663 7191.280 7080.852 ≈ 6921 ± 5.72% ↑ 4.34%
TPS 6945.409 6562.756 5927.050 6681.187 6821.794 ≈ 6588 ± 5.38% ↑ 4.99%
CPU % 44.400 43.842 40.418 49.211 49.370 ≈ 45.4 ± 7.53% ↓ 2.78%
Mem MB 2693.414 2640.602 2472.007 2731.482 2707.879 ≈ 2649 ± 3.53% ↓ 1.56%
Network communication takes time. Handling some messages (like transaction)
also takes time. We can share this time by making handler a separate
goroutine. So while message is being handled receiver can already get and
parse the next one.
It doesn't improve metrics a lot, but still I think it makes sense and in some
scenarios this can be more beneficial than this.
e41fc2fd1b, 4 nodes, 10 workers
RPS 6732.979 6396.160 6759.624 6246.398 6589.841 ≈ 6545 ± 3.02%
TPS 6491.062 5984.190 6275.652 5867.477 6360.797 ≈ 6196 ± 3.77%
CPU % 42.053 43.515 44.768 40.344 44.112 ≈ 43.0 ± 3.69%
Mem MB 2564.130 2744.236 2636.267 2589.505 2765.926 ≈ 2660 ± 3.06%
Patched:
RPS 6902.296 6465.662 6856.044 6785.515 6157.024 ≈ 6633 ± 4.26% ↑ 1.34%
TPS 6468.431 6218.867 6610.565 6288.596 5790.556 ≈ 6275 ± 4.44% ↑ 1.28%
CPU % 50.231 42.925 49.481 48.396 42.662 ≈ 46.7 ± 7.01% ↑ 8.60%
Mem MB 2856.841 2684.103 2756.195 2733.485 2422.787 ≈ 2691 ± 5.40% ↑ 1.17%
We use them quite frequently (consider children for a new branch
node) and it is better to get rid of unneeded allocations.
Signed-off-by: Evgeniy Stratonikov <evgeniy@nspcc.ru>
`WriteArray` involves reflection, it makes sense to optimize
serialization of transactions and application logs which are serialized
constantly. Adding case in a type switch in `WriteArray` is not an
option because we don't want new dependencies for `io` package.
```
name old time/op new time/op delta
AppExecResult_EncodeBinary-8 852ns ± 3% 656ns ± 2% -22.94% (p=0.000 n=10+9)
name old alloc/op new alloc/op delta
AppExecResult_EncodeBinary-8 448B ± 0% 376B ± 0% -16.07% (p=0.000 n=10+10)
name old allocs/op new allocs/op delta
AppExecResult_EncodeBinary-8 7.00 ± 0% 5.00 ± 0% -28.57% (p=0.000 n=10+10)
```
```
name old time/op new time/op delta
Transaction_Bytes-8 1.29µs ± 3% 0.76µs ± 5% -41.52% (p=0.000 n=9+10)
name old alloc/op new alloc/op delta
Transaction_Bytes-8 1.21kB ± 0% 1.01kB ± 0% -16.56% (p=0.000 n=10+10)
name old allocs/op new allocs/op delta
Transaction_Bytes-8 12.0 ± 0% 7.0 ± 0% -41.67% (p=0.000 n=10+10)
```
Signed-off-by: Evgeniy Stratonikov <evgeniy@nspcc.ru>
We know it already, but with current loading code VM will hash it once
more. It doesn't help a lot and still it costs nothing to avoid this
overhead.
name old time/op new time/op delta
VerifyWitness-8 93.4µs ± 3% 92.7µs ± 2% ~ (p=0.353 n=10+10)
name old alloc/op new alloc/op delta
VerifyWitness-8 3.43kB ± 0% 3.40kB ± 0% -0.70% (p=0.000 n=9+9)
name old allocs/op new allocs/op delta
VerifyWitness-8 67.0 ± 0% 66.0 ± 0% -1.49% (p=0.000 n=10+10)
ReadArray() can return some error and we shouldn't overwrite it. At the same
time limiting ReadArray() to the number of Signers can make it return wrong
error if the number of witnesses actually is bigger than the number of
signers, so use MaxAttributes.
We burn GAS in OnPersist for every transaction so some buffer reuse here is
quite natural.
This also doesn't change a lot in the overall TPS picture, maybe adding some
1%.
Which duplicates the check, but deduplicates error path. This check forced
double balance deserialization which is quite costly operation, so we better
do it once.
It's hardly noticeable as of TPS metrics though, maybe some 1-2%%.
Persist by its definition doesn't change MemCachedStore visible state, all KV
pairs that were acessible via it before Persist remain accessible after
Persist. The only thing it does is flushing of the current set of KV pairs
from memory to peristent store. To do that it needs read-only access to the
current KV pair set, but technically it then replaces maps, so we have to use
full write lock which makes MemCachedStore inaccessible for the duration of
Persist. And Persist can take a lot of time, it's about disk access for
regular DBs.
What we do here is we create new in-memory maps for MemCachedStore before
flushing old ones to the persistent store. Then a fake persistent store is
created which actually is a MemCachedStore with old maps, so it has exactly
the same visible state. This Store is never accessed for writes, so we can
read it without taking any internal locks and at the same time we no longer
need write locks for original MemCachedStore, we're not using it. All of this
makes it possible to use MemCachedStore as normally reads are handled going
down to whatever level is needed and writes are handled by new maps. So while
Persist for (*Blockchain).dao does its most time-consuming work we can process
other blocks (reading data for transactions and persisting storeBlock caches
to (*Blockchain).dao).
The change was tested for performance with neo-bench (single node, 10 workers,
LevelDB) on two machines and block dump processing (RC4 testnet up to 62800
with VerifyBlocks set to false) on i7-8565U.
Reference results (bbe4e9cd7b):
Ryzen 9 5950X:
RPS 23616.969 22817.086 23222.378 ≈ 23218 ± 1.72%
TPS 23047.316 22608.578 22735.540 ≈ 22797 ± 0.99%
CPU % 23.434 25.553 23.848 ≈ 24.3 ± 4.63%
Mem MB 600.636 503.060 582.043 ≈ 562 ± 9.22%
Core i7-8565U:
RPS 6594.007 6499.501 6572.902 ≈ 6555 ± 0.76%
TPS 6561.680 6444.545 6510.120 ≈ 6505 ± 0.90%
CPU % 58.452 60.568 62.474 ≈ 60.5 ± 3.33%
Mem MB 234.893 285.067 269.081 ≈ 263 ± 9.75%
DB restore:
real 0m22.237s 0m23.471s 0m23.409s ≈ 23.04 ± 3.02%
user 0m35.435s 0m38.943s 0m39.247s ≈ 37.88 ± 5.59%
sys 0m3.085s 0m3.360s 0m3.144s ≈ 3.20 ± 4.53%
After the change:
Ryzen 9 5950X:
RPS 27747.349 27407.726 27520.210 ≈ 27558 ± 0.63% ↑ 18.69%
TPS 26992.010 26993.468 27010.966 ≈ 26999 ± 0.04% ↑ 18.43%
CPU % 28.928 28.096 29.105 ≈ 28.7 ± 1.88% ↑ 18.1%
Mem MB 760.385 726.320 756.118 ≈ 748 ± 2.48% ↑ 33.10%
Core i7-8565U:
RPS 7783.229 7628.409 7542.340 ≈ 7651 ± 1.60% ↑ 16.72%
TPS 7708.436 7607.397 7489.459 ≈ 7602 ± 1.44% ↑ 16.85%
CPU % 74.899 71.020 72.697 ≈ 72.9 ± 2.67% ↑ 20.50%
Mem MB 438.047 436.967 416.350 ≈ 430 ± 2.84% ↑ 63.50%
DB restore:
real 0m20.838s 0m21.895s 0m21.794s ≈ 21.51 ± 2.71% ↓ 6.64%
user 0m39.091s 0m40.565s 0m41.493s ≈ 40.38 ± 3.00% ↑ 6.60%
sys 0m3.184s 0m2.923s 0m3.062s ≈ 3.06 ± 4.27% ↓ 4.38%
It obviously uses more memory now and utilizes CPU more aggressively, but at
the same time it allows to improve all relevant metrics and finally reach a
situation where we process 50K transactions in less than second on Ryzen 9
5950X (going higher than 25K TPS). The other observation is much more stable
block time, on Ryzen 9 it's as close to 1 second as it could be.
Block processing consists of:
* saving block/transactions to the DB
* executing blocks/transactions
* processing notifications/saving AERs
* updating MPT
* atomically updating Blockchain state
Of these the first one is completely independent of others, it can be done in
a separate routine easily. The third one technically depends on the second,
it just doesn't have data until something is executed. At the same time it
doesn't affect future executions in any way, so we can offload
AER/notification processing to separate goroutine (while the main thread
proceeds with other transactions).
MPT update depends on all executions, so it can't be offloaded, but it can be
done concurrently to AER processing. And only the last thing actually needs
all previous ones to be finished, so it's a natural synchronization point.
So we spawn two additional routines and let the main one execute transactions
and update MPT as fast as it can. While technically all of these routines
could share single DAO (they are working with different KV sets) benchmarking
shows that using separate DAOs and then persisting them to lower one actually
works about 7-8%% better. At the same time we can simplify DAOs used, Cached
one is only relevant for AER processing because it caches NEP-17 tracking
data, everything else can do just fine with Simple.
The change was tested for performance with neo-bench (single node, 10 workers,
LevelDB) on two machines and block dump processing (RC4 testnet up to 50825
with VerifyBlocks set to false) on i7-8565U. neo-bench creates huge blocks
with lots of transactions while RC4 dump mostly consists of empty blocks.
Reference results (06c3dda5d1):
Ryzen 9 5950X:
RPS ≈ 20059.569 21186.328 20158.983 ≈ 20468 ± 3.05%
TPS ≈ 19544.993 20585.450 19658.338 ≈ 19930 ± 2.86%
CPU ≈ 18.682% 23.877% 22.852% ≈ 21.8 ± 12.62%
Mem ≈ 618.981MB 559.246MB 541.539MB ≈ 573 ± 7.08%
Core i7-8565U:
RPS ≈ 5927.082 6526.739 6372.115 ≈ 6275 ± 4.96%
TPS ≈ 5899.531 6477.187 6329.515 ≈ 6235 ± 4.81%
CPU ≈ 56.346% 61.955% 58.125% ≈ 58.8 ± 4.87%
Mem ≈ 212.191MB 224.974MB 205.479MB ≈ 214 ± 4.62%
DB restore:
real 0m12.683s 0m13.222s 0m13.382s ≈ 13.096 ± 2.80%
user 0m18.501s 0m19.163s 0m19.489s ≈ 19.051 ± 2.64%
sys 0m1.404s 0m1.396s 0m1.666s ≈ 1.489 ± 10.32%
After the change:
Ryzen 9 5950X:
RPS ≈ 23056.899 22822.015 23006.543 ≈ 22962 ± 0.54%
TPS ≈ 22594.785 22292.071 22800.857 ≈ 22562 ± 1.13%
CPU ≈ 24.262% 23.185% 25.921% ≈ 24.5 ± 5.65%
Mem ≈ 614.254MB 613.204MB 555.491MB ≈ 594 ± 5.66%
Core i7-8565U:
RPS ≈ 6378.702 6423.927 6363.788 ≈ 6389 ± 0.49%
TPS ≈ 6327.072 6372.552 6311.179 ≈ 6337 ± 0.50%
CPU ≈ 57.599% 58.622% 59.737% ≈ 58.7 ± 1.82%
Mem ≈ 198.697MB 188.746MB 200.235MB ≈ 196 ± 3.18%
DB restore:
real 0m13.576s 0m13.334s 0m12.757s ≈ 13.222 ± 3.18%
user 0m19.113s 0m19.490s 0m20.197s ≈ 19.600 ± 2.81%
sys 0m2.211s 0m1.558s 0m1.559s ≈ 1.776 ± 21.21%
On Ryzen 9 we've got 12% better RPS, 13% better TPS with 12% CPU and 3% RAM
more used. Core i7-8565U changes don't seem to be statistically significant:
1.8% more RPS, 1.6% more TPS with about the same CPU and 8.5% less RAM
used. It also is 1% worse in DB restore time.
The result is somewhat expected, on a powerful machine with lots of spare
cores we get 10%+ better results while on average resource-constrained laptop it
doesn't change much (the machine is already saturated). Overall, this seems to
be worthwhile.
If wallet size decreases, we need to remove trailing garbage if it
exists. This can happen when removing account or reading pretty-printed
wallet. It doesn't affect our CLI (we decode only file prefix), but
it is nice to always have a valid JSON file.
Signed-off-by: Evgeniy Stratonikov <evgeniy@nspcc.ru>
Request NEP17 balances from a set of NEP17 contracts instead of getting
them from storage. LastUpdatedBlock tracking remains untouched, because
there's no way to retrieve it dynamically.
Balances are to be removed from state.NEP17TransferInfo, so the remnant
fields are NextTransferBatch, NewBatch and a map of LastUpdatedBlocks.
These fields are more staff-related.
Also rename dao.[Get, Put, put]NEP17Balances and STNEP17Balances
preffix.
Also rename NEP17TransferInfo.Trackers to LastUpdatedBlockTrackers
because NEP17TransferInfo.Balances are to be removed.
So use base64 too and add compatibility test. Unfortunately this breaks
support for old (hex-based) files, but those should be completed a long time
ago.
We're only using queue library and it didn't change in any way, but 1.0.53 has
proper go.mod, so it's still an improvement.
It at the same time pulls some new packages also like x/tools.
It was broken somewhere between 2f490a3403 and
85ce207f40 leading to panic on watch only node:
2021-07-21T16:21:39.201+0200 INFO received Commit {"validator": 3}
panic: runtime error: invalid memory address or nil pointer dereference
[signal SIGSEGV: segmentation violation code=0x1 addr=0x28 pc=0xbcc59e]
goroutine 486 [running]:
github.com/nspcc-dev/neo-go/pkg/consensus.(*service).newBlockFromContext(0xc0001629a0, 0xc000308000, 0xc0010fa000, 0x2cb417800)
github.com/nspcc-dev/neo-go/pkg/consensus/consensus.go:664 +0xbe
github.com/nspcc-dev/dbft.(*Context).MakeHeader(...)
github.com/nspcc-dev/dbft@v0.0.0-20210302103605-cc75991b7cfb/context.go:270
github.com/nspcc-dev/dbft.(*DBFT).onCommit(0xc000308000, 0x138c998, 0xc000115110)
github.com/nspcc-dev/dbft@v0.0.0-20210302103605-cc75991b7cfb/dbft.go:487 +0x575
github.com/nspcc-dev/dbft.(*DBFT).OnReceive(0xc000308000, 0x138c998, 0xc000115110)
github.com/nspcc-dev/dbft@v0.0.0-20210302103605-cc75991b7cfb/dbft.go:251 +0xef5
github.com/nspcc-dev/neo-go/pkg/consensus.(*service).eventLoop(0xc0001629a0)
github.com/nspcc-dev/neo-go/pkg/consensus/consensus.go:312 +0x7d6
created by github.com/nspcc-dev/neo-go/pkg/consensus.(*service).Start
github.com/nspcc-dev/neo-go/pkg/consensus/consensus.go:262 +0xdc
In fact, nonce is correctly provided by dbft library (since Legacy), we just
need to use it here.
