add tracking for block/range lifecycle time

lib/replicator.js

@@ -54,9 +54,19 @@ class Attachable {
     this.resolved = false
     this.processing = false
     this.refs = []
+
+    this.timestamp = 0
+    this.elapsed = 0
+  }
+
+  _startTime () {
+    if (this.timestamp > 0) return
+    this.timestamp = Date.now()
   }
 
   attach (session) {
+    this._startTime()
+
     const r = {
       context: this,
       session,
@@ -1886,6 +1896,8 @@ module.exports = class Replicator {
 
     b.resolve(value)
 
+    this._onresolvedrequest(b)
+
     if (b.inflight.length > 0) { // if anything is still inflight, cancel it
       for (let i = b.inflight.length - 1; i >= 0; i--) {
         const req = b.inflight[i]
@@ -1914,6 +1926,8 @@ module.exports = class Replicator {
     if (index < this._ranges.length) this._ranges[index] = head
 
     req.resolve(true)
+
+    this._onresolvedrequest(req)
   }
 
   _clearInflightBlock (tracker, req) {
@@ -2495,6 +2509,16 @@ module.exports = class Replicator {
     }
   }
 
+  _onresolvedrequest (req) {
+    req.elapsed = Date.now() - req.timestamp
+    const sessions = this.core.monitors
+
+    for (let i = sessions.length - 1; i >= 0; i--) {
+      const s = sessions[i]
+      s.emit('resolved-request', req)
+    }
+  }
+
   _ondownload (index, byteLength, from, req) {
     const sessions = this.core.monitors
 

test/replicate.js

@@ -1941,6 +1941,32 @@ test('download event includes "elapsed" time in metadata', async function (t) {
   await b.download({ start: 0, end: a.length }).done()
 })
 
+test('resolved-request event includes elapsed time of the request', async function (t) {
+  const a = await create(t)
+  const b = await create(t, a.key)
+  const c = await create(t, a.key)
+
+  await a.append(['a', 'b', 'c', 'd'])
+  replicate(a, b, t)
+  replicate(b, c, t)
+
+  // range request
+  b.on('resolved-request', (req) => {
+    t.is(req.constructor.name, 'RangeRequest')
+    t.ok(Number.isInteger(req.timestamp))
+    t.ok(Number.isInteger(req.elapsed))
+  })
+  await b.download({ start: 0, end: a.length }).done()
+
+  // block request
+  c.on('resolved-request', (req) => {
+    t.is(req.constructor.name, 'BlockRequest')
+    t.ok(Number.isInteger(req.timestamp))
+    t.ok(Number.isInteger(req.elapsed))
+  })
+  await c.get(0)
+})
+
 async function waitForRequestBlock (core) {
   while (true) {
     const reqBlock = core.core.replicator._inflight._requests.find(req => req && req.block)