fix(metrics): prohibit overwriting stashed metrics context

2018-07-04 15:03:34 +01:00 · 2018-07-04 15:03:34 +01:00 · fafccce5ed
--- a/lib/cache.js
+++ b/lib/cache.js
@ -11,6 +11,7 @@ P.promisifyAll(Memcached.prototype)

 const NOP = () => P.resolve()
 const NULL_CACHE = {
+  addAsync: NOP,
  delAsync: NOP,
  getAsync: NOP,
  setAsync: NOP
@ -24,6 +25,21 @@ module.exports = (log, config, namespace) => {
  const CACHE_LIFETIME = config.memcached.lifetime

  return {
+    /**
+     * Add data to the cache, keyed by a string.
+     * If the key already exists,
+     * the call will fail.
+     *
+     * Fails silently if the cache is not enabled.
+     *
+     * @param {string} key
+     * @param data
+     */
+    add (key, data) {
+      return getCache()
+        .then(cache => cache.addAsync(key, data, CACHE_LIFETIME))
+    },
+
    /**
     * Delete data from the cache, keyed by a string.
     *
@ -49,7 +65,7 @@ module.exports = (log, config, namespace) => {
    },

    /**
-     * Fetch data from the cache, keyed by a string.
+     * Set data in the cache, keyed by a string.
     *
     * Fails silently if the cache is not enabled.
     *
--- a/lib/metrics/context.js
+++ b/lib/metrics/context.js
@ -44,6 +44,10 @@ module.exports = function (log, config) {
   * Stashes metrics context metadata using a key derived from a token.
   * Asynchronous, returns a promise.
   *
+   * A surprising aspect of this method's behaviour is that it silently
+   * fails if the key already is already stashed. This is so that UTM
+   * params can't be changed part-way through a flow.
+   *
   * @name stashMetricsContext
   * @this request
   * @param token    token to stash the metadata against
@ -58,10 +62,13 @@ module.exports = function (log, config) {
    metadata.service = this.payload.service || this.query.service

    return P.resolve()
-      .then(() => cache.set(getKey(token), metadata))
+      .then(() => {
+        return cache.add(getKey(token), metadata)
+          .catch(err => log.warn({ op: 'metricsContext.stash.add', err }))
+      })
      .catch(err => log.error({
        op: 'metricsContext.stash',
-        err: err,
+        err,
        hasToken: !! token,
        hasId: !! (token && token.id),
        hasUid: !! (token && token.uid)
--- a/test/local/cache.js
+++ b/test/local/cache.js
@ -43,7 +43,9 @@ describe('cache:', () => {
  it('exports the correct interface', () => {
    assert.ok(cache)
    assert.equal(typeof cache, 'object')
-    assert.equal(Object.keys(cache).length, 3)
+    assert.equal(Object.keys(cache).length, 4)
+    assert.equal(typeof cache.add, 'function')
+    assert.equal(cache.add.length, 2)
    assert.equal(typeof cache.del, 'function')
    assert.equal(cache.del.length, 1)
    assert.equal(typeof cache.get, 'function')
@ -54,11 +56,32 @@ describe('cache:', () => {

  describe('memcached resolves:', () => {
    beforeEach(() => {
+      sandbox.stub(Memcached.prototype, 'addAsync', () => P.resolve())
      sandbox.stub(Memcached.prototype, 'delAsync', () => P.resolve())
      sandbox.stub(Memcached.prototype, 'getAsync', () => P.resolve('mock get result'))
      sandbox.stub(Memcached.prototype, 'setAsync', () => P.resolve())
    })

+    describe('add:', () => {
+      beforeEach(() => {
+        return cache.add(digest, 'wibble')
+      })
+
+      it('calls memcached.addAsync correctly', () => {
+        assert.equal(Memcached.prototype.addAsync.callCount, 1)
+        const args = Memcached.prototype.addAsync.args[0]
+        assert.equal(args.length, 3)
+        assert.equal(args[0], digest)
+        assert.equal(args[1], 'wibble')
+        assert.equal(args[2], 30)
+
+        assert.equal(Memcached.prototype.delAsync.callCount, 0)
+        assert.equal(Memcached.prototype.getAsync.callCount, 0)
+        assert.equal(Memcached.prototype.setAsync.callCount, 0)
+        assert.equal(log.error.callCount, 0)
+      })
+    })
+
    describe('del:', () => {
      beforeEach(() => {
        return cache.del(digest)
@ -70,6 +93,7 @@ describe('cache:', () => {
        assert.equal(args.length, 1)
        assert.equal(args[0], digest)

+        assert.equal(Memcached.prototype.addAsync.callCount, 0)
        assert.equal(Memcached.prototype.getAsync.callCount, 0)
        assert.equal(Memcached.prototype.setAsync.callCount, 0)
        assert.equal(log.error.callCount, 0)
@ -94,6 +118,7 @@ describe('cache:', () => {
        assert.equal(args.length, 1)
        assert.equal(args[0], digest)

+        assert.equal(Memcached.prototype.addAsync.callCount, 0)
        assert.equal(Memcached.prototype.delAsync.callCount, 0)
        assert.equal(Memcached.prototype.setAsync.callCount, 0)
        assert.equal(log.error.callCount, 0)
@ -113,6 +138,7 @@ describe('cache:', () => {
        assert.equal(args[1], 'wibble')
        assert.equal(args[2], 30)

+        assert.equal(Memcached.prototype.addAsync.callCount, 0)
        assert.equal(Memcached.prototype.delAsync.callCount, 0)
        assert.equal(Memcached.prototype.getAsync.callCount, 0)
        assert.equal(log.error.callCount, 0)
@ -122,9 +148,23 @@ describe('cache:', () => {

  describe('memcached rejects:', () => {
    beforeEach(() => {
-      sandbox.stub(Memcached.prototype, 'delAsync', () => P.reject('foo'))
-      sandbox.stub(Memcached.prototype, 'getAsync', () => P.reject('bar'))
-      sandbox.stub(Memcached.prototype, 'setAsync', () => P.reject('baz'))
+      sandbox.stub(Memcached.prototype, 'addAsync', () => P.reject('foo'))
+      sandbox.stub(Memcached.prototype, 'delAsync', () => P.reject('bar'))
+      sandbox.stub(Memcached.prototype, 'getAsync', () => P.reject('baz'))
+      sandbox.stub(Memcached.prototype, 'setAsync', () => P.reject('qux'))
+    })
+
+    describe('add:', () => {
+      let error
+
+      beforeEach(() => {
+        return cache.add(digest, 'wibble')
+          .catch(e => error = e)
+      })
+
+      it('propagates the error', () => {
+        assert.equal(error, 'foo')
+      })
    })

    describe('del:', () => {
@ -136,7 +176,7 @@ describe('cache:', () => {
      })

      it('propagates the error', () => {
-        assert.equal(error, 'foo')
+        assert.equal(error, 'bar')
      })
    })

@ -149,7 +189,7 @@ describe('cache:', () => {
      })

      it('propagates the error', () => {
-        assert.equal(error, 'bar')
+        assert.equal(error, 'baz')
      })
    })

@ -162,7 +202,7 @@ describe('cache:', () => {
      })

      it('propagates the error', () => {
-        assert.equal(error, 'baz')
+        assert.equal(error, 'qux')
      })
    })
  })
@ -185,6 +225,7 @@ describe('null cache:', () => {
      uid: Buffer.alloc(32, 'cd'),
      id: 'deadbeef'
    }
+    sandbox.stub(Memcached.prototype, 'addAsync', () => P.resolve())
    sandbox.stub(Memcached.prototype, 'delAsync', () => P.resolve())
    sandbox.stub(Memcached.prototype, 'getAsync', () => P.resolve())
    sandbox.stub(Memcached.prototype, 'setAsync', () => P.resolve())
@ -192,6 +233,16 @@ describe('null cache:', () => {

  afterEach(() => sandbox.restore())

+  describe('add:', () => {
+    beforeEach(() => {
+      return cache.add(token, {})
+    })
+
+    it('did not call memcached.addAsync', () => {
+      assert.equal(Memcached.prototype.addAsync.callCount, 0)
+    })
+  })
+
  describe('del:', () => {
    beforeEach(() => {
      return cache.del(token)
--- a/test/local/metrics/context.js
+++ b/test/local/metrics/context.js
@ -34,6 +34,7 @@ describe('metricsContext', () => {
      set: P.resolve()
    }
    cache = {
+      add: sinon.spy(() => results.add),
      del: sinon.spy(() => results.del),
      get: sinon.spy(() => results.get),
      set: sinon.spy(() => results.set)
@ -85,7 +86,7 @@ describe('metricsContext', () => {
  it(
    'metricsContext.stash',
    () => {
-      results.set = P.resolve('wibble')
+      results.add = P.resolve('wibble')
      const token = {
        uid: Array(64).fill('c').join(''),
        id: 'foo'
@ -101,14 +102,42 @@ describe('metricsContext', () => {
      }, token).then(result => {
        assert.equal(result, 'wibble', 'result is correct')

-        assert.equal(cache.set.callCount, 1, 'cache.set was called once')
-        assert.equal(cache.set.args[0].length, 2, 'cache.set was passed two arguments')
-        assert.equal(cache.set.args[0][0], hashToken(token), 'first argument was correct')
-        assert.deepEqual(cache.set.args[0][1], {
+        assert.equal(cache.add.callCount, 1, 'cache.add was called once')
+        assert.equal(cache.add.args[0].length, 2, 'cache.add was passed two arguments')
+        assert.equal(cache.add.args[0][0], hashToken(token), 'first argument was correct')
+        assert.deepEqual(cache.add.args[0][1], {
          foo: 'bar',
          service: 'baz'
        }, 'second argument was correct')

+        assert.equal(cache.get.callCount, 0, 'cache.get was not called')
+        assert.equal(cache.set.callCount, 0, 'cache.set was not called')
+        assert.equal(log.warn.callCount, 0, 'log.warn was not called')
+        assert.equal(log.error.callCount, 0, 'log.error was not called')
+      })
+    }
+  )
+
+  it(
+    'metricsContext.stash with clashing data',
+    () => {
+      results.add = P.reject('wibble')
+      const token = {
+        uid: Array(64).fill('c').join(''),
+        id: 'foo'
+      }
+      return metricsContext.stash.call({
+        payload: {
+          metricsContext: {
+            foo: 'bar'
+          },
+          service: 'baz'
+        },
+        query: {}
+      }, token).then(result => {
+        assert.strictEqual(result, undefined, 'result is undefined')
+        assert.equal(cache.add.callCount, 1, 'cache.add was called once')
+        assert.equal(log.warn.callCount, 1, 'log.warn was called once')
        assert.equal(log.error.callCount, 0, 'log.error was not called')
      })
    }
@ -117,7 +146,7 @@ describe('metricsContext', () => {
  it(
    'metricsContext.stash with service query param',
    () => {
-      results.set = P.resolve('wibble')
+      results.add = P.resolve('wibble')
      const token = {
        uid: Array(64).fill('c').join(''),
        id: 'foo'
@ -132,44 +161,14 @@ describe('metricsContext', () => {
          service: 'qux'
        }
      }, token).then(result => {
-        assert.equal(cache.set.callCount, 1, 'cache.set was called once')
-        assert.equal(cache.set.args[0][1].service, 'qux', 'service property was correct')
+        assert.equal(cache.add.callCount, 1, 'cache.add was called once')
+        assert.equal(cache.add.args[0][1].service, 'qux', 'service property was correct')

        assert.equal(log.error.callCount, 0, 'log.error was not called')
      })
    }
  )

-  it(
-    'metricsContext.stash error',
-    () => {
-      results.set = P.reject('wibble')
-      return metricsContext.stash.call({
-        payload: {
-          metricsContext: {
-            foo: 'bar'
-          }
-        },
-        query: {}
-      }, {
-        uid: Array(64).fill('c').join(''),
-        id: 'foo'
-      }).then(result => {
-        assert.equal(result, undefined, 'result is undefined')
-
-        assert.equal(cache.set.callCount, 1, 'cache.set was called once')
-
-        assert.equal(log.error.callCount, 1, 'log.error was called once')
-        assert.equal(log.error.args[0].length, 1, 'log.error was passed one argument')
-        assert.equal(log.error.args[0][0].op, 'metricsContext.stash', 'argument op property was correct')
-        assert.equal(log.error.args[0][0].err, 'wibble', 'argument err property was correct')
-        assert.strictEqual(log.error.args[0][0].hasToken, true, 'hasToken property was correct')
-        assert.strictEqual(log.error.args[0][0].hasId, true, 'hasId property was correct')
-        assert.strictEqual(log.error.args[0][0].hasUid, true, 'hasUid property was correct')
-      })
-    }
-  )
-
  it(
    'metricsContext.stash with bad token',
    () => {
@ -193,7 +192,7 @@ describe('metricsContext', () => {
        assert.strictEqual(log.error.args[0][0].hasId, true, 'hasId property was correct')
        assert.strictEqual(log.error.args[0][0].hasUid, false, 'hasUid property was correct')

-        assert.equal(cache.set.callCount, 0, 'cache.set was not called')
+        assert.equal(cache.add.callCount, 0, 'cache.add was not called')
      })
    }
  )
@ -210,7 +209,7 @@ describe('metricsContext', () => {
      }).then(result => {
        assert.equal(result, undefined, 'result is undefined')

-        assert.equal(cache.set.callCount, 0, 'cache.set was not called')
+        assert.equal(cache.add.callCount, 0, 'cache.add was not called')
        assert.equal(log.error.callCount, 0, 'log.error was not called')
      })
    }