From b581a3e2bb452145ac633f3b028d9265e7e84ca8 Mon Sep 17 00:00:00 2001 From: Miguel Jimenez Esun Date: Sun, 18 Mar 2018 06:41:39 -0700 Subject: [PATCH] Add logging into cache class Reviewed By: rafeca Differential Revision: D7307863 fbshipit-source-id: 0365c5598cd8e56580ebab953dfdcf2d27a59276 --- packages/metro-cache/package.json | 1 + packages/metro-cache/src/Cache.js | 57 +++++++++-- .../metro-cache/src/__tests__/Cache.test.js | 95 +++++++++++++++++-- packages/metro-core/src/Logger/Logger.js | 1 + 4 files changed, 138 insertions(+), 16 deletions(-) diff --git a/packages/metro-cache/package.json b/packages/metro-cache/package.json index 5b0b8c38..753adfed 100644 --- a/packages/metro-cache/package.json +++ b/packages/metro-cache/package.json @@ -13,6 +13,7 @@ }, "dependencies": { "jest-serializer": "^22.4.0", + "metro-core": "^0.30.1", "mkdirp": "^0.5.1" } } diff --git a/packages/metro-cache/src/Cache.js b/packages/metro-cache/src/Cache.js index 21c29b96..c134cf67 100644 --- a/packages/metro-cache/src/Cache.js +++ b/packages/metro-cache/src/Cache.js @@ -10,8 +10,17 @@ 'use strict'; +const {Logger} = require('metro-core'); + import type {CacheStore} from 'metro-cache'; +/** + * Main cache class. Receives an array of cache instances, and sequentially + * traverses them to return a previously stored value. It also ensures setting + * the value in all instances. + * + * All get/set operations are logged via Metro's logger. + */ class Cache { _stores: $ReadOnlyArray>; @@ -27,16 +36,40 @@ class Cache { const length = stores.length; for (let i = 0; i < length; i++) { - let value = stores[i].get(key); + const store = stores[i]; + const name = store.constructor.name + '::' + key.toString('hex'); + let value = null; - if (value instanceof Promise) { - value = await value; - } + const logStart = Logger.log( + Logger.createActionStartEntry({ + action_name: 'Cache get', + log_entry_label: name, + }), + ); - if (value != null) { - this._hits.set(key, stores[i]); + try { + const valueOrPromise = store.get(key); - return value; + if (valueOrPromise && typeof valueOrPromise.then === 'function') { + value = await valueOrPromise; + } else { + value = valueOrPromise; + } + } finally { + Logger.log(Logger.createActionEndEntry(logStart)); + + Logger.log( + Logger.createEntry({ + action_name: 'Cache ' + (value == null ? 'miss' : 'hit'), + log_entry_label: name, + }), + ); + + if (value != null) { + this._hits.set(key, store); + + return value; + } } } @@ -50,6 +83,16 @@ class Cache { const promises = []; for (let i = 0; i < length && stores[i] !== stop; i++) { + const store = stores[i]; + const name = store.constructor.name + '::' + key.toString('hex'); + + Logger.log( + Logger.createEntry({ + action_name: 'Cache set', + log_entry_label: name, + }), + ); + promises.push(stores[i].set(key, value)); } diff --git a/packages/metro-cache/src/__tests__/Cache.test.js b/packages/metro-cache/src/__tests__/Cache.test.js index 72dff463..c512d72f 100644 --- a/packages/metro-cache/src/__tests__/Cache.test.js +++ b/packages/metro-cache/src/__tests__/Cache.test.js @@ -11,18 +11,38 @@ 'use strict'; -const Cache = require('../Cache'); - describe('Cache', () => { - function createStore(i) { - return { + let Cache; + let Logger; + let log; + + function createStore(name = '') { + // eslint-disable-next-line no-eval + const TempClass = eval(`(class ${name} {})`); + + return Object.assign(new TempClass(), { get: jest.fn().mockImplementation(() => null), set: jest.fn(), - }; + }); } + beforeEach(() => { + Logger = require('metro-core').Logger; + Cache = require('../Cache'); + + Logger.on('log', item => { + log.push({ + a: item.action_name, + l: item.log_entry_label, + p: item.action_phase, + }); + }); + + log = []; + }); + afterEach(() => { - jest.restoreAllMocks(); + jest.resetModules().restoreAllMocks(); }); it('returns null when no result is found', async () => { @@ -39,9 +59,9 @@ describe('Cache', () => { }); it('sequentially searches up until it finds a valid result', async () => { - const store1 = createStore(1); - const store2 = createStore(2); - const store3 = createStore(3); + const store1 = createStore(); + const store2 = createStore(); + const store3 = createStore(); const cache = new Cache([store1, store2, store3]); // Only cache 2 can return results. @@ -137,4 +157,61 @@ describe('Cache', () => { expect(error).toBeInstanceOf(TypeError); }); + + it('logs the right messages when getting without errors', async () => { + const store1 = createStore('Local'); + const store2 = createStore('Network'); + const cache = new Cache([store1, store2]); + + store1.get.mockImplementation(() => null); + store2.get.mockImplementation(() => 'le potato'); + + await cache.get(Buffer.from('foo')); + + expect(log).toEqual([ + {a: 'Cache get', l: 'Cache get', p: 'start'}, + {a: 'Cache get', l: 'Cache get', p: 'end'}, + {a: 'Cache miss', l: 'Local::666f6f', p: undefined}, + {a: 'Cache get', l: 'Cache get', p: 'start'}, + {a: 'Cache get', l: 'Cache get', p: 'end'}, + {a: 'Cache hit', l: 'Network::666f6f', p: undefined}, + ]); + }); + + it('logs the right messages when getting with errors', async () => { + const store1 = createStore('Local'); + const store2 = createStore('Network'); + const cache = new Cache([store1, store2]); + + store1.get.mockImplementation(() => null); + store2.get.mockImplementation(() => Promise.reject(new TypeError('bar'))); + + try { + await cache.get(Buffer.from('foo')); + } catch (err) { + // Do nothing, we care about the logs. + } + + expect(log).toEqual([ + {a: 'Cache get', l: 'Cache get', p: 'start'}, + {a: 'Cache get', l: 'Cache get', p: 'end'}, + {a: 'Cache miss', l: 'Local::666f6f', p: undefined}, + {a: 'Cache get', l: 'Cache get', p: 'start'}, + {a: 'Cache get', l: 'Cache get', p: 'end'}, + {a: 'Cache miss', l: 'Network::666f6f', p: undefined}, + ]); + }); + + it('logs the right messages when setting', async () => { + const store1 = createStore('Local'); + const store2 = createStore('Network'); + const cache = new Cache([store1, store2]); + + await cache.set(Buffer.from('foo')); + + expect(log).toEqual([ + {a: 'Cache set', l: 'Local::666f6f', p: undefined}, + {a: 'Cache set', l: 'Network::666f6f', p: undefined}, + ]); + }); }); diff --git a/packages/metro-core/src/Logger/Logger.js b/packages/metro-core/src/Logger/Logger.js index 643492f9..7a6f667d 100644 --- a/packages/metro-core/src/Logger/Logger.js +++ b/packages/metro-core/src/Logger/Logger.js @@ -18,6 +18,7 @@ const VERSION = require('../../package.json').version; type ActionLogEntryData = { action_name: string, + log_entry_label?: string, }; type ActionStartLogEntry = {