LBRYCommunity/lbcd
1
0
Fork 0
Code Issues 17 Pull requests 4 Projects Releases 28 Packages Wiki Activity

Reduce claimtrie temp allocs. #51

Open
moodyjon wants to merge 4 commits from moodyjon/claimtrie_temp_allocs into master
pull from: moodyjon/claimtrie_temp_allocs
merge into: LBRYCommunity:master
Conversation 9 Commits 4 Files changed 15 +147 -49
moodyjon commented 2022-06-07 00:04:01 +02:00 (Migrated from github.com)
Copy link

Unbundled from PR https://github.com/lbryio/lbcd/pull/43

See that for usage/testing.

Based on work by @BrannonKing in mem_pressure_try_2 and reduce_memory_pressure.

The commits 8482890759 and 787098e2a2 are newly added to claw back costs from node cache and node.Clone().

Unbundled from PR https://github.com/lbryio/lbcd/pull/43 See that for usage/testing. Based on work by @BrannonKing in mem_pressure_try_2 and reduce_memory_pressure. The commits 84828907593e597856f977af18649637bd5b8c6c and 787098e2a2f4692c7c3e6eab1a1ba25d00a54ae0 are newly added to claw back costs from node cache and node.Clone().
roylee17 (Migrated from github.com) reviewed 2022-06-07 00:04:01 +02:00
coveralls commented 2022-06-07 00:08:50 +02:00 (Migrated from github.com)
Copy link

Pull Request Test Coverage Report for Build 2450737946

  • 71 of 112 (63.39%) changed or added relevant lines in 9 files are covered.
  • 15 unchanged lines in 5 files lost coverage.
  • Overall coverage increased (+0.002%) to 51.818%
Changes Missing Coverage Covered Lines Changed/Added Lines %
claimtrie/node/hashfork_manager.go 0 1 0.0%
claimtrie/node/normalizing_manager.go 0 1 0.0%
blockchain/claimtrie.go 0 4 0.0%
rpcclaimtrie.go 0 4 0.0%
claimtrie/node/node.go 45 51 88.24%
claimtrie/node/noderepo/pebble.go 11 17 64.71%
claimtrie/node/cache.go 3 12 25.0%
claimtrie/node/manager.go 9 19 47.37%
Files with Coverage Reduction New Missed Lines %
claimtrie/node/cache.go 1 62.16%
claimtrie/node/noderepo/pebble.go 1 68.75%
integration/rpctest/blockgen.go 2 83.78%
btcec/signature.go 3 92.82%
peer/peer.go 8 76.31%
Totals Coverage Status
Change from base Build 2450492318: 0.002%
Covered Lines: 22490
Relevant Lines: 43402
💛 - Coveralls
## Pull Request Test Coverage Report for [Build 2450737946](https://coveralls.io/builds/49777005) * **71** of **112** **(63.39%)** changed or added relevant lines in **9** files are covered. * **15** unchanged lines in **5** files lost coverage. * Overall coverage increased (+**0.002%**) to **51.818%** --- | Changes Missing Coverage | Covered Lines | Changed/Added Lines | % | | :-----|--------------|--------|---: | | [claimtrie/node/hashfork_manager.go](https://coveralls.io/builds/49777005/source?filename=claimtrie%2Fnode%2Fhashfork_manager.go#L18) | 0 | 1 | 0.0% | [claimtrie/node/normalizing_manager.go](https://coveralls.io/builds/49777005/source?filename=claimtrie%2Fnode%2Fnormalizing_manager.go#L75) | 0 | 1 | 0.0% | [blockchain/claimtrie.go](https://coveralls.io/builds/49777005/source?filename=blockchain%2Fclaimtrie.go#L38) | 0 | 4 | 0.0% | [rpcclaimtrie.go](https://coveralls.io/builds/49777005/source?filename=rpcclaimtrie.go#L109) | 0 | 4 | 0.0% | [claimtrie/node/node.go](https://coveralls.io/builds/49777005/source?filename=claimtrie%2Fnode%2Fnode.go#L41) | 45 | 51 | 88.24% | [claimtrie/node/noderepo/pebble.go](https://coveralls.io/builds/49777005/source?filename=claimtrie%2Fnode%2Fnoderepo%2Fpebble.go#L119) | 11 | 17 | 64.71% | [claimtrie/node/cache.go](https://coveralls.io/builds/49777005/source?filename=claimtrie%2Fnode%2Fcache.go#L35) | 3 | 12 | 25.0% | [claimtrie/node/manager.go](https://coveralls.io/builds/49777005/source?filename=claimtrie%2Fnode%2Fmanager.go#L68) | 9 | 19 | 47.37% <!-- | **Total:** | **71** | **112** | **63.39%** | --> | Files with Coverage Reduction | New Missed Lines | % | | :-----|--------------|--: | | [claimtrie/node/cache.go](https://coveralls.io/builds/49777005/source?filename=claimtrie%2Fnode%2Fcache.go#L50) | 1 | 62.16% | | [claimtrie/node/noderepo/pebble.go](https://coveralls.io/builds/49777005/source?filename=claimtrie%2Fnode%2Fnoderepo%2Fpebble.go#L147) | 1 | 68.75% | | [integration/rpctest/blockgen.go](https://coveralls.io/builds/49777005/source?filename=integration%2Frpctest%2Fblockgen.go#L52) | 2 | 83.78% | | [btcec/signature.go](https://coveralls.io/builds/49777005/source?filename=btcec%2Fsignature.go#L405) | 3 | 92.82% | | [peer/peer.go](https://coveralls.io/builds/49777005/source?filename=peer%2Fpeer.go#L1534) | 8 | 76.31% | <!-- | **Total:** | **15** | | --> | Totals | [![Coverage Status](https://coveralls.io/builds/49777005/badge)](https://coveralls.io/builds/49777005) | | :-- | --: | | Change from base [Build 2450492318](https://coveralls.io/builds/49775589): | 0.002% | | Covered Lines: | 22490 | | Relevant Lines: | 43402 | --- ##### 💛 - [Coveralls](https://coveralls.io)
roylee17 commented 2022-06-09 07:52:54 +02:00 (Migrated from github.com)
Copy link

The tuning doesn't work out, both sync time and startup time got worse.

Sync time

Before (pr46):

2022-06-06 06:37:12.838 [INF] MAIN: Version 0.0.0-local.0+15191b7ede02f4c052a2a61c55c8ef7a95d8e134
2022-06-06 20:31:12.230 [INF] SYNC: Processed 63 blocks in the last 10s (10282 transactions, height 1163018, 2022-05-20 23:52:46 +0000 UTC)

After:

2022-06-07 19:39:26.514 [INF] MAIN: Version 0.0.0-local.0+787098e2a2f4692c7c3e6eab1a1ba25d00a54ae0
2022-06-08 13:58:51.657 [INF] SYNC: Processed 70 blocks in the last 10.22s (9345 transactions, height 1163069, 2022-05-21 02:04:36 +0000 UTC)

(Re)startup time

Before (pr46):

2022-06-06 20:47:34.503 [INF] MAIN: Version 0.0.0-local.0+c4e7528a6a87e37d631925ad19e8a78675609fa0
2022-06-06 20:51:05.282 [INF] CHAN: Loading block index...

After:

2022-06-09 05:40:36.626 [INF] MAIN: Version 0.0.0-local.0+787098e2a2f4692c7c3e6eab1a1ba25d00a54ae0
2022-06-09 05:50:55.352 [INF] CHAN: Loading block index...
The tuning doesn't work out, both sync time and startup time got worse. ### Sync time Before (pr46): ``` 2022-06-06 06:37:12.838 [INF] MAIN: Version 0.0.0-local.0+15191b7ede02f4c052a2a61c55c8ef7a95d8e134 2022-06-06 20:31:12.230 [INF] SYNC: Processed 63 blocks in the last 10s (10282 transactions, height 1163018, 2022-05-20 23:52:46 +0000 UTC) ``` After: ``` 2022-06-07 19:39:26.514 [INF] MAIN: Version 0.0.0-local.0+787098e2a2f4692c7c3e6eab1a1ba25d00a54ae0 2022-06-08 13:58:51.657 [INF] SYNC: Processed 70 blocks in the last 10.22s (9345 transactions, height 1163069, 2022-05-21 02:04:36 +0000 UTC) ``` ### (Re)startup time Before (pr46): ``` 2022-06-06 20:47:34.503 [INF] MAIN: Version 0.0.0-local.0+c4e7528a6a87e37d631925ad19e8a78675609fa0 2022-06-06 20:51:05.282 [INF] CHAN: Loading block index... ``` After: ``` 2022-06-09 05:40:36.626 [INF] MAIN: Version 0.0.0-local.0+787098e2a2f4692c7c3e6eab1a1ba25d00a54ae0 2022-06-09 05:50:55.352 [INF] CHAN: Loading block index... ```
moodyjon commented 2022-06-09 19:24:20 +02:00 (Migrated from github.com)
Copy link

Wow. 10 minutes for claimtrie build. :-( Something's not right.... That's so bad that it makes me suspect that there was some extra load on the machine at some point.

Can you rerun it with profile collection? Just the restart case at first to see whether 10min is reproducible.

./lbcd --memprofile=./after.mem --cpuprofile=./after.cpu

When I run it on an 8core arm64 Mac mini, it continues to be about 3 min (before) and 2.2min (after) for claimtrie build.

Before:

swdev1@Mac-mini lbcd % ./lbcd --memprofile=./before7.mem --cpuprofile=./before7.cpu
2022-06-09 12:59:18.282 [INF] MAIN: Version 0.0.0-local.0+3772b1ef1d7625b6f71f107e00d47f89136e5071-dirty
2022-06-09 12:59:18.283 [INF] MAIN: Loading block database from '/Users/swdev1/Library/Application Support/Lbcd/data/mainnet/blocks_ffldb'
2022-06-09 12:59:18.577 [INF] MAIN: Block database loaded
2022-06-09 12:59:21.579 [INF] SRVR: Can't discover UPnP-enabled device: write udp4 0.0.0.0:55040->239.255.255.250:1900: i/o timeout
2022-06-09 12:59:21.586 [INF] INDX: Transaction index is enabled
2022-06-09 12:59:21.586 [INF] INDX: Committed filter index is enabled
2022-06-09 12:59:22.063 [INF] LBRY: Normalizing strings via Go. Casefold and NFD table versions: 11.0.0 (from ICU 63.2)
2022-06-09 12:59:22.064 [INF] LBRY: Building the entire claim trie in RAM...
2022-06-09 12:59:26.136 [INF] LBRY: Spending claim but missing existing claim with TXO bd183d94dc0b2c38d500838f4ab7c93b643123f46e87214d3e37f5e9e0d4baf5:0, Name: 1791l-trumpcnn, ID: 6a28cbbe64c3c54113770705c928e80a138ddae9
2022-06-09 12:59:58.719 [INF] MAIN: RAM: using 1.3 GB with 2.7 available, DISK: using 122.3 GB with 786.7 available
2022-06-09 13:00:27.944 [INF] LBRY: Spending claim but missing existing claim with TXO 546a1b99218f5935d6d11d6a5632ba199b24d6dbb6c07e75bea1089eee23987d:0, Name: ggminingpool-xzc, ID: 0b9e8ea179d6f68d3b37ab0e636af6ab1b93b52e
2022-06-09 13:00:27.949 [INF] LBRY: Spending claim but missing existing claim with TXO 5dff52209029a63547f8805c3e92fce87e3744a15f6539a12011fe0c421ca132:0, Name: ggminingpoolxzc, ID: 3fa8d7113bd4873e79ec02019bea3c7840f0deee
2022-06-09 13:00:38.821 [INF] MAIN: RAM: using 2.1 GB with 2.7 available, DISK: using 122.3 GB with 786.7 available
2022-06-09 13:01:09.422 [INF] LBRY: Spending claim but missing existing claim with TXO 022a25b42e0327d6bf7a741cd3bae34404453549635d916e5b05eb15edb05019:1, Name: redbullfourthphase, ID: f054e085e8d38c0a0e63a472b033e42d437a4014
2022-06-09 13:01:18.640 [INF] MAIN: RAM: using 2.8 GB with 2.7 available, DISK: using 122.3 GB with 785.7 available
2022-06-09 13:01:33.753 [INF] LBRY: Spending claim but missing existing claim with TXO d549351f731019573d921f5db8e2844449edf3011073b3e5f4ce9b0d9aee5490:1, Name: timcast-sweden-day1, ID: 247895d4b9389b74038ea5a4fd807cafc97ede53
2022-06-09 13:01:37.968 [INF] LBRY: Spending claim but missing existing claim with TXO 36a719a156a1df178531f3c712b8b37f8e7cc3b36eea532df961229d936272a1:0, Name: two, ID: bb6168c9a56286999c7c938c7b8c5afb221d38d0
2022-06-09 13:01:58.644 [INF] MAIN: RAM: using 3.0 GB with 2.7 available, DISK: using 122.3 GB with 785.7 available
2022-06-09 13:02:17.393 [INF] CHAN: Loading block index...
2022-06-09 13:02:31.779 [INF] CHAN: Chain state (height 1173692, hash 4554e96707dd2a5af693e838909198b054c93341143bd6483de95cbf81c3a0cd, totaltx 80332019, work 44494961111535296297409)

After:

swdev1@Mac-mini lbcd % ./lbcd --memprofile=./after7.mem --cpuprofile=./after7.cpu  
2022-06-09 13:09:19.742 [INF] MAIN: Version 0.0.0-local.0+787098e2a2f4692c7c3e6eab1a1ba25d00a54ae0-dirty
2022-06-09 13:09:19.743 [INF] MAIN: Loading block database from '/Users/swdev1/Library/Application Support/Lbcd/data/mainnet/blocks_ffldb'
2022-06-09 13:09:19.995 [INF] MAIN: Block database loaded
2022-06-09 13:09:22.997 [INF] SRVR: Can't discover UPnP-enabled device: write udp4 0.0.0.0:54877->239.255.255.250:1900: i/o timeout
2022-06-09 13:09:23.005 [INF] INDX: Transaction index is enabled
2022-06-09 13:09:23.007 [INF] INDX: Committed filter index is enabled
2022-06-09 13:09:23.548 [INF] LBRY: Normalizing strings via Go. Casefold and NFD table versions: 11.0.0 (from ICU 63.2)
2022-06-09 13:09:23.548 [INF] LBRY: Building the entire claim trie in RAM...
2022-06-09 13:09:26.987 [INF] LBRY: Spending claim but missing existing claim with TXO bd183d94dc0b2c38d500838f4ab7c93b643123f46e87214d3e37f5e9e0d4baf5:0, Name: 1791l-trumpcnn, ID: 6a28cbbe64c3c54113770705c928e80a138ddae9
2022-06-09 13:10:00.234 [INF] MAIN: RAM: using 1.4 GB with 2.7 available, DISK: using 122.3 GB with 786.8 available
2022-06-09 13:10:16.859 [INF] LBRY: Spending claim but missing existing claim with TXO 5dff52209029a63547f8805c3e92fce87e3744a15f6539a12011fe0c421ca132:0, Name: ggminingpoolxzc, ID: 3fa8d7113bd4873e79ec02019bea3c7840f0deee
2022-06-09 13:10:16.859 [INF] LBRY: Spending claim but missing existing claim with TXO 546a1b99218f5935d6d11d6a5632ba199b24d6dbb6c07e75bea1089eee23987d:0, Name: ggminingpool-xzc, ID: 0b9e8ea179d6f68d3b37ab0e636af6ab1b93b52e
2022-06-09 13:10:40.122 [INF] MAIN: RAM: using 2.4 GB with 2.7 available, DISK: using 122.3 GB with 786.8 available
2022-06-09 13:10:48.349 [INF] LBRY: Spending claim but missing existing claim with TXO 022a25b42e0327d6bf7a741cd3bae34404453549635d916e5b05eb15edb05019:1, Name: redbullfourthphase, ID: f054e085e8d38c0a0e63a472b033e42d437a4014
2022-06-09 13:11:01.676 [INF] LBRY: Spending claim but missing existing claim with TXO d549351f731019573d921f5db8e2844449edf3011073b3e5f4ce9b0d9aee5490:1, Name: timcast-sweden-day1, ID: 247895d4b9389b74038ea5a4fd807cafc97ede53
2022-06-09 13:11:04.191 [INF] LBRY: Spending claim but missing existing claim with TXO 36a719a156a1df178531f3c712b8b37f8e7cc3b36eea532df961229d936272a1:0, Name: two, ID: bb6168c9a56286999c7c938c7b8c5afb221d38d0
2022-06-09 13:11:20.361 [INF] MAIN: RAM: using 3.0 GB with 2.7 available, DISK: using 122.3 GB with 785.7 available
2022-06-09 13:11:33.715 [INF] CHAN: Loading block index...
2022-06-09 13:11:45.898 [INF] CHAN: Chain state (height 1173695, hash 2bda7b7cd69805029b02cf66dc34e92418843b00310bc90c38b12d36f5bb8d6a, totaltx 80332222, work 44495327569169772684103)
Wow. 10 minutes for claimtrie build. :-( Something's not right.... That's so bad that it makes me suspect that there was some extra load on the machine at some point. Can you rerun it with profile collection? Just the restart case at first to see whether 10min is reproducible. ./lbcd --memprofile=./after.mem --cpuprofile=./after.cpu When I run it on an 8core arm64 Mac mini, it continues to be about 3 min (before) and 2.2min (after) for claimtrie build. Before: ``` swdev1@Mac-mini lbcd % ./lbcd --memprofile=./before7.mem --cpuprofile=./before7.cpu 2022-06-09 12:59:18.282 [INF] MAIN: Version 0.0.0-local.0+3772b1ef1d7625b6f71f107e00d47f89136e5071-dirty 2022-06-09 12:59:18.283 [INF] MAIN: Loading block database from '/Users/swdev1/Library/Application Support/Lbcd/data/mainnet/blocks_ffldb' 2022-06-09 12:59:18.577 [INF] MAIN: Block database loaded 2022-06-09 12:59:21.579 [INF] SRVR: Can't discover UPnP-enabled device: write udp4 0.0.0.0:55040->239.255.255.250:1900: i/o timeout 2022-06-09 12:59:21.586 [INF] INDX: Transaction index is enabled 2022-06-09 12:59:21.586 [INF] INDX: Committed filter index is enabled 2022-06-09 12:59:22.063 [INF] LBRY: Normalizing strings via Go. Casefold and NFD table versions: 11.0.0 (from ICU 63.2) 2022-06-09 12:59:22.064 [INF] LBRY: Building the entire claim trie in RAM... 2022-06-09 12:59:26.136 [INF] LBRY: Spending claim but missing existing claim with TXO bd183d94dc0b2c38d500838f4ab7c93b643123f46e87214d3e37f5e9e0d4baf5:0, Name: 1791l-trumpcnn, ID: 6a28cbbe64c3c54113770705c928e80a138ddae9 2022-06-09 12:59:58.719 [INF] MAIN: RAM: using 1.3 GB with 2.7 available, DISK: using 122.3 GB with 786.7 available 2022-06-09 13:00:27.944 [INF] LBRY: Spending claim but missing existing claim with TXO 546a1b99218f5935d6d11d6a5632ba199b24d6dbb6c07e75bea1089eee23987d:0, Name: ggminingpool-xzc, ID: 0b9e8ea179d6f68d3b37ab0e636af6ab1b93b52e 2022-06-09 13:00:27.949 [INF] LBRY: Spending claim but missing existing claim with TXO 5dff52209029a63547f8805c3e92fce87e3744a15f6539a12011fe0c421ca132:0, Name: ggminingpoolxzc, ID: 3fa8d7113bd4873e79ec02019bea3c7840f0deee 2022-06-09 13:00:38.821 [INF] MAIN: RAM: using 2.1 GB with 2.7 available, DISK: using 122.3 GB with 786.7 available 2022-06-09 13:01:09.422 [INF] LBRY: Spending claim but missing existing claim with TXO 022a25b42e0327d6bf7a741cd3bae34404453549635d916e5b05eb15edb05019:1, Name: redbullfourthphase, ID: f054e085e8d38c0a0e63a472b033e42d437a4014 2022-06-09 13:01:18.640 [INF] MAIN: RAM: using 2.8 GB with 2.7 available, DISK: using 122.3 GB with 785.7 available 2022-06-09 13:01:33.753 [INF] LBRY: Spending claim but missing existing claim with TXO d549351f731019573d921f5db8e2844449edf3011073b3e5f4ce9b0d9aee5490:1, Name: timcast-sweden-day1, ID: 247895d4b9389b74038ea5a4fd807cafc97ede53 2022-06-09 13:01:37.968 [INF] LBRY: Spending claim but missing existing claim with TXO 36a719a156a1df178531f3c712b8b37f8e7cc3b36eea532df961229d936272a1:0, Name: two, ID: bb6168c9a56286999c7c938c7b8c5afb221d38d0 2022-06-09 13:01:58.644 [INF] MAIN: RAM: using 3.0 GB with 2.7 available, DISK: using 122.3 GB with 785.7 available 2022-06-09 13:02:17.393 [INF] CHAN: Loading block index... 2022-06-09 13:02:31.779 [INF] CHAN: Chain state (height 1173692, hash 4554e96707dd2a5af693e838909198b054c93341143bd6483de95cbf81c3a0cd, totaltx 80332019, work 44494961111535296297409) ``` After: ``` swdev1@Mac-mini lbcd % ./lbcd --memprofile=./after7.mem --cpuprofile=./after7.cpu 2022-06-09 13:09:19.742 [INF] MAIN: Version 0.0.0-local.0+787098e2a2f4692c7c3e6eab1a1ba25d00a54ae0-dirty 2022-06-09 13:09:19.743 [INF] MAIN: Loading block database from '/Users/swdev1/Library/Application Support/Lbcd/data/mainnet/blocks_ffldb' 2022-06-09 13:09:19.995 [INF] MAIN: Block database loaded 2022-06-09 13:09:22.997 [INF] SRVR: Can't discover UPnP-enabled device: write udp4 0.0.0.0:54877->239.255.255.250:1900: i/o timeout 2022-06-09 13:09:23.005 [INF] INDX: Transaction index is enabled 2022-06-09 13:09:23.007 [INF] INDX: Committed filter index is enabled 2022-06-09 13:09:23.548 [INF] LBRY: Normalizing strings via Go. Casefold and NFD table versions: 11.0.0 (from ICU 63.2) 2022-06-09 13:09:23.548 [INF] LBRY: Building the entire claim trie in RAM... 2022-06-09 13:09:26.987 [INF] LBRY: Spending claim but missing existing claim with TXO bd183d94dc0b2c38d500838f4ab7c93b643123f46e87214d3e37f5e9e0d4baf5:0, Name: 1791l-trumpcnn, ID: 6a28cbbe64c3c54113770705c928e80a138ddae9 2022-06-09 13:10:00.234 [INF] MAIN: RAM: using 1.4 GB with 2.7 available, DISK: using 122.3 GB with 786.8 available 2022-06-09 13:10:16.859 [INF] LBRY: Spending claim but missing existing claim with TXO 5dff52209029a63547f8805c3e92fce87e3744a15f6539a12011fe0c421ca132:0, Name: ggminingpoolxzc, ID: 3fa8d7113bd4873e79ec02019bea3c7840f0deee 2022-06-09 13:10:16.859 [INF] LBRY: Spending claim but missing existing claim with TXO 546a1b99218f5935d6d11d6a5632ba199b24d6dbb6c07e75bea1089eee23987d:0, Name: ggminingpool-xzc, ID: 0b9e8ea179d6f68d3b37ab0e636af6ab1b93b52e 2022-06-09 13:10:40.122 [INF] MAIN: RAM: using 2.4 GB with 2.7 available, DISK: using 122.3 GB with 786.8 available 2022-06-09 13:10:48.349 [INF] LBRY: Spending claim but missing existing claim with TXO 022a25b42e0327d6bf7a741cd3bae34404453549635d916e5b05eb15edb05019:1, Name: redbullfourthphase, ID: f054e085e8d38c0a0e63a472b033e42d437a4014 2022-06-09 13:11:01.676 [INF] LBRY: Spending claim but missing existing claim with TXO d549351f731019573d921f5db8e2844449edf3011073b3e5f4ce9b0d9aee5490:1, Name: timcast-sweden-day1, ID: 247895d4b9389b74038ea5a4fd807cafc97ede53 2022-06-09 13:11:04.191 [INF] LBRY: Spending claim but missing existing claim with TXO 36a719a156a1df178531f3c712b8b37f8e7cc3b36eea532df961229d936272a1:0, Name: two, ID: bb6168c9a56286999c7c938c7b8c5afb221d38d0 2022-06-09 13:11:20.361 [INF] MAIN: RAM: using 3.0 GB with 2.7 available, DISK: using 122.3 GB with 785.7 available 2022-06-09 13:11:33.715 [INF] CHAN: Loading block index... 2022-06-09 13:11:45.898 [INF] CHAN: Chain state (height 1173695, hash 2bda7b7cd69805029b02cf66dc34e92418843b00310bc90c38b12d36f5bb8d6a, totaltx 80332222, work 44495327569169772684103) ```
roylee17 commented 2022-06-09 23:13:03 +02:00 (Migrated from github.com)
Copy link

Hm.. a re-run does perform closer to what it was. But no significant changes though.

2022-06-09 18:30:16.146 [INF] MAIN: Version 0.0.0-local.0+787098e2a2f4692c7c3e6eab1a1ba25d00a54ae0
2022-06-09 18:34:43.958 [INF] CHAN: Loading block index...

Attach the profiled data.

after.zip

Does it show improvements on the sync time in your environment?

Hm.. a re-run does perform closer to what it was. But no significant changes though. ``` 2022-06-09 18:30:16.146 [INF] MAIN: Version 0.0.0-local.0+787098e2a2f4692c7c3e6eab1a1ba25d00a54ae0 2022-06-09 18:34:43.958 [INF] CHAN: Loading block index... ``` Attach the profiled data. [after.zip](https://github.com/lbryio/lbcd/files/8873973/after.zip) Does it show improvements on the sync time in your environment?
moodyjon commented 2022-06-10 13:47:05 +02:00 (Migrated from github.com)
Copy link

Yes, it's showing claimtrie build time improvement (2min after, 3min before), but not overall sync time AFAICT. It takes me many days to sync from a remote node.

Here is my run:
after2.zip

I tried to get a comparable one with 317s wall clock runtime. CPU profiles are very different. Yours shows a lot more CPU time consumed in GC, makeNameHashNext func1 and func2. The descendants of sstable Reader.readBlock() are very different. Some stuff like Sha256 does not even show up in mine under the default pprof options.

My hardware specs (16GB RAM 2TB SSD variant):
https://en.wikipedia.org/wiki/Mac_Mini#Technical_specifications_5

My guess is you've reached some hardware limitation (RAM throughput/latency?), so demonstrating improvement becomes impossible. Just like I can't see any improvement in overall sync time because fetching blocks from a remote node is the limiting factor.

I assume you are syncing blocks over LAN. What is your test hardware? SSD? CPUs? RAM type? What about isolation from other load? Is this a virtual machine?

Yes, it's showing claimtrie build time improvement (2min after, 3min before), but not overall sync time AFAICT. It takes me many days to sync from a remote node. Here is my run: [after2.zip](https://github.com/lbryio/lbcd/files/8878112/after2.zip) I tried to get a comparable one with 317s wall clock runtime. CPU profiles are very different. Yours shows a lot more CPU time consumed in GC, makeNameHashNext func1 and func2. The descendants of sstable Reader.readBlock() are very different. Some stuff like Sha256 does not even show up in mine under the default pprof options. My hardware specs (16GB RAM 2TB SSD variant): https://en.wikipedia.org/wiki/Mac_Mini#Technical_specifications_5 My guess is you've reached some hardware limitation (RAM throughput/latency?), so demonstrating improvement becomes impossible. Just like I can't see any improvement in overall sync time because fetching blocks from a remote node is the limiting factor. I assume you are syncing blocks over LAN. What is your test hardware? SSD? CPUs? RAM type? What about isolation from other load? Is this a virtual machine?
moodyjon commented 2022-06-10 17:28:20 +02:00 (Migrated from github.com)
Copy link

Regarding sha256 performance discrepancy:
https://github.com/golang/go/tree/master/src/crypto/sha256

The performance you get depends on availability of special CPU instructions.

go tool pprof --svg --show_from sha256 XXX.cpu

Mine (arm64):
profile006

Yours (???):
profile007

Regarding sha256 performance discrepancy: https://github.com/golang/go/tree/master/src/crypto/sha256 The performance you get depends on availability of special CPU instructions. go tool pprof --svg --show_from sha256 XXX.cpu Mine (arm64): ![profile006](https://user-images.githubusercontent.com/103143855/173100211-f94ac195-9eb0-485b-9a75-1cd8ae939e84.svg) Yours (???): ![profile007](https://user-images.githubusercontent.com/103143855/173100237-09828b01-fd0f-4bda-9108-bf544e9d9b8e.svg)
moodyjon commented 2022-06-10 18:04:24 +02:00 (Migrated from github.com)
Copy link

Focusing on GC scanobject:

go tool pprof --svg --show_from scanobject XXX.cpu

Mine (arm64):
profile008

Yours (???):
profile009

I don't see anything obviously architecture-specific. But yours is registering a lot more time spent. The mem allocs report is ~28GB for yours and 26GB for mine, so GC should be triggering about the same number of times.

Focusing on GC scanobject: go tool pprof --svg --show_from scanobject XXX.cpu Mine (arm64): ![profile008](https://user-images.githubusercontent.com/103143855/173102458-1f71326d-e357-419e-8d2b-81c17702afad.svg) Yours (???): ![profile009](https://user-images.githubusercontent.com/103143855/173102485-cb9c357b-e02f-43bd-9f15-2569b958485f.svg) I don't see anything obviously architecture-specific. But yours is registering a lot more time spent. The mem allocs report is ~28GB for yours and 26GB for mine, so GC should be triggering about the same number of times.
kauffj commented 2022-06-13 21:31:38 +02:00 (Migrated from github.com)
Copy link

Thanks for your contributions @moodyjon!

Can you send me an email at jeremy@lbry.com? You're welcome to stay anonymous if that's your preference.

Thanks for your contributions @moodyjon! Can you send me an email at jeremy@lbry.com? You're welcome to stay anonymous if that's your preference.
moodyjon commented 2022-07-28 03:53:50 +02:00 (Migrated from github.com)
Copy link

Demote to draft status as this is a sensitive code area. There is an outstanding bug being investigated at this time:

https://github.com/lbryio/lbcd/issues/71

Demote to draft status as this is a sensitive code area. There is an outstanding bug being investigated at this time: https://github.com/lbryio/lbcd/issues/71
This pull request has changes conflicting with the target branch.
  • claimtrie/node/cache.go
  • claimtrie/node/manager.go
View command line instructions

Checkout

From your project repository, check out a new branch and test the changes.
git fetch -u origin moodyjon/claimtrie_temp_allocs:moodyjon/claimtrie_temp_allocs
git checkout moodyjon/claimtrie_temp_allocs

Merge

Merge the changes and update on Forgejo.

Warning: The "Autodetect manual merge" setting is not enabled for this repository, you will have to mark this pull request as manually merged afterwards.

git checkout master
git merge --no-ff moodyjon/claimtrie_temp_allocs
git checkout moodyjon/claimtrie_temp_allocs
git rebase master
git checkout master
git merge --ff-only moodyjon/claimtrie_temp_allocs
git checkout moodyjon/claimtrie_temp_allocs
git rebase master
git checkout master
git merge --no-ff moodyjon/claimtrie_temp_allocs
git checkout master
git merge --squash moodyjon/claimtrie_temp_allocs
git checkout master
git merge --ff-only moodyjon/claimtrie_temp_allocs
git checkout master
git merge moodyjon/claimtrie_temp_allocs
git push origin master
Sign in to join this conversation.
Reviewers
No reviewers
roylee17
Labels
Clear labels   
ci

   
claimtrie

   
consider soon

Discuss this issue at the next planning meeting, then remove this label

  
Epic

   
good first issue

Good for newcomers

  
hacktoberfest

Welcome to Hacktoberfest

  
help wanted

Extra attention is needed

  
mempool

   
mining

Mining (including pool) related issues

  
peer

p2p network

  
priority: blocker

Issue is blocking release, do ASAP

  
priority: high

Work needs to be moved into sprint ASAP

  
priority: low

Work should be done but can stay in the backlog for now

  
priority: medium

Work needs to be done within 2-3 sprints

  
rpc

RPC related issues

  
runtime

   
test

   
type: bug

Existing functionality is wrong or broken

  
type: discussion

A conversation. No specific changes requested

  
type: improvement

Existing (or partially existing) functionality needs to be changed

  
type: new feature

New functionality that does not exist yet

  
type: refactor

Minimal user-visible changes, but significant internal work

  
type: task

Either work that's not related to the code, or a small chore that does not fit into other categories

  
ux

User experience

  
wallet
No labels
ci
claimtrie
consider soon
Epic
good first issue
hacktoberfest
help wanted
mempool
mining
peer
priority: blocker
priority: high
priority: low
priority: medium
rpc
runtime
test
type: bug
type: discussion
type: improvement
type: new feature
type: refactor
type: task
ux
wallet
Milestone
Clear milestone
No items
No milestone
Projects
Clear projects
No items
No project
Assignees
Clear assignees
No assignees
1 participant
Notifications
Due date
The due date is invalid or out of range. Please use the format "yyyy-mm-dd".

No due date set.

Dependencies

No dependencies set.

Reference: LBRYCommunity/lbcd#51
No description provided.
Delete branch "moodyjon/claimtrie_temp_allocs"

Deleting a branch is permanent. Although the deleted branch may continue to exist for a short time before it actually gets removed, it CANNOT be undone in most cases. Continue?