diff --git a/.github/workflows/docker-dist-tests.yml b/.github/workflows/docker-dist-tests.yml index f6bb163c..4afe6dcf 100644 --- a/.github/workflows/docker-dist-tests.yml +++ b/.github/workflows/docker-dist-tests.yml @@ -52,7 +52,7 @@ jobs: uses: ./.github/workflows/docker-reusable.yml needs: get-contracts-hash with: - nimflags: '-d:disableMarchNative -d:codex_enable_api_debug_peers=true -d:codex_enable_proof_failures=true -d:codex_enable_log_counter=true -d:verify_circuit=true' + nimflags: '-d:disableMarchNative -d:codex_enable_api_debug_peers=true -d:codex_enable_proof_failures=true -d:codex_enable_log_counter=true -d:verify_circuit=true -d:codex_enable_repostore_timinglogs=true' nat_ip_auto: true tag_latest: ${{ github.ref_name == github.event.repository.default_branch || startsWith(github.ref, 'refs/tags/') }} tag_suffix: dist-tests diff --git a/codex/stores/repostore/store.nim b/codex/stores/repostore/store.nim index 16813a16..4cdca8d7 100644 --- a/codex/stores/repostore/store.nim +++ b/codex/stores/repostore/store.nim @@ -29,6 +29,16 @@ import ../../logutils import ../../merkletree import ../../utils +const codex_enable_repostore_timinglogs* {.booldefine.} = false + +when codex_enable_repostore_timinglogs: + import std/monotimes + import ../../utils/statsummary + + let + getBlockSummary = declareStatSummary("getBlock") + putBlockSummary = declareStatSummary("putBlock") + export blocktype, cid logScope: @@ -70,6 +80,9 @@ method getBlock*( trace "Error getting key from provider", err = err.msg return failure(err) + when codex_enable_repostore_timinglogs: + let startTime = getMonoTime().ticks + without data =? await self.repoDs.get(key), err: if not (err of DatastoreKeyNotFound): trace "Error getting block from datastore", err = err.msg, key @@ -77,7 +90,13 @@ method getBlock*( return failure(newException(BlockNotFoundError, err.msg)) - trace "Got block for cid", cid + when codex_enable_repostore_timinglogs: + let durationUs = (getMonoTime().ticks - startTime) div 1000 + trace "Got block for cid", cid, durationUs + getBlockSummary.observe(durationUs) + else: + trace "Got block for cid", cid + return Block.new(cid, data, verify = true) method getBlockAndProof*( @@ -188,6 +207,9 @@ method putBlock*( let expiry = self.clock.now() + (ttl |? self.blockTtl).seconds + when codex_enable_repostore_timinglogs: + let startTime = getMonoTime().ticks + without res =? await self.storeBlock(blk, expiry), err: return failure(err) @@ -207,6 +229,11 @@ method putBlock*( else: trace "Block already exists" + when codex_enable_repostore_timinglogs: + let durationUs = (getMonoTime().ticks - startTime) div 1000 + trace "putBlock", durationUs + putBlockSummary.observe(durationUs) + return success() proc delBlockInternal( diff --git a/codex/utils/statsummary.nim b/codex/utils/statsummary.nim new file mode 100644 index 00000000..21fc22e1 --- /dev/null +++ b/codex/utils/statsummary.nim @@ -0,0 +1,44 @@ +import pkg/metrics + +when defined(metrics): + type StatSummary* = ref object of Collector + hasValues: bool + min: float64 + max: float64 + ravg: float64 + + method collect(st: StatSummary, output: MetricHandler) = + if not st.hasValues: + return + + let timestamp = st.now() + output(name = st.name & "_min", value = st.min, timestamp = timestamp) + output(name = st.name & "_max", value = st.max, timestamp = timestamp) + output(name = st.name & "_ravg", value = st.ravg, timestamp = timestamp) + +proc declareStatSummary*(name: string, help: string = ""): StatSummary = + when defined(metrics): + result = StatSummary.newCollector(name, help) + result.hasValues = false + else: + return IgnoredCollector + +proc observeStatSummary(st: StatSummary, value: float64) = + if st.hasValues: + if value < st.min: + st.min = value + if value > st.max: + st.max = value + st.ravg = (st.ravg + value) / float64(2) + else: + st.hasValues = true + st.min = value + st.max = value + st.ravg = value + +template observe*( + statSummary: StatSummary | type IgnoredCollector, amount: int64 | float64 = 1 +) = + when defined(metrics) and statSummary is not IgnoredCollector: + {.gcsafe.}: + observeStatSummary(statSummary, amount.float64)