У меня есть база данных Firebase, к которой клиенты обращаются через API REST, запускается на node.js, который затем читает из моей базы данных Firebase с помощью клиента узла firebase-admin
.Для большинства моих конечных точек требуется несколько одновременных чтений из базы данных.Например, для конечной точки api/item/:itemKey
мне нужно извлечь item
из базы данных, а затем, как только она будет получена, я одновременно запрашиваю все вложенные spec
, panel
, query
иtask
объекты, связанные с найденным предметом.Это приводит к двум последовательным "волнам" вызовов базы данных: извлечению первого элемента, а затем извлечению всех ресурсов, вложенных в этот элемент.
Проблема заключается в том, что задержка при этих вызовах крайне непредсказуема.Например, вот журналы для двух последовательных вызовов к одной и той же конечной точке, выполненных в течение 5 секунд друг от друга:
// START REQUEST 1
Endpoint activated (invocation #: 18) ("GET /api/items/:itemKey")
Firebase items READ Success ("id: -LDhjV8Hkievzbh5UVfz"): 78ms
Firebase specs READ Success ("id: -LDIezNhwWX8OmoWXZO3"): 72ms
Firebase specs READ Success ("id: -LDIezNqbVuvkpr9WEf8"): 73ms
Firebase panels READ Success ("id: -LDhjV5y1mAwPmJkE4d3"): 74ms
Firebase queries READ Success ("id: -LDhjV34aJlz_XFwOp6B"): 69ms
Firebase queries READ Success ("id: -LDhjV3QO1AM9UiCVdux"): 71ms
Firebase tasks READ Success ("id: -LDhjV34aJlz_XFwOp6C"): 71ms
Firebase tasks READ Success ("id: -LDhjV3QO1AM9UiCVduy"): 72ms
Endpoint resolution ("GET /api/items/:itemKey"): 305ms
// END REQUEST 1
// START REQUEST 2
Endpoint activated (invocation #: 19) ("GET /api/items/:itemKey")
Firebase items READ Success ("id: -LDhjV8Hkievzbh5UVfz"): 1174ms
Firebase specs READ Success ("id: -LDIezNhwWX8OmoWXZO3"): 1463ms
Firebase specs READ Success ("id: -LDIezNqbVuvkpr9WEf8"): 1463ms
Firebase panels READ Success ("id: -LDhjV5y1mAwPmJkE4d3"): 1464ms
Firebase queries READ Success ("id: -LDhjV34aJlz_XFwOp6B"): 312ms
Firebase queries READ Success ("id: -LDhjV3QO1AM9UiCVdux"): 312ms
Firebase tasks READ Success ("id: -LDhjV34aJlz_XFwOp6C"): 65ms
Firebase tasks READ Success ("id: -LDhjV3QO1AM9UiCVduy"): 65ms
Endpoint resolution ("GET /api/items/:itemKey"): 3032ms
// END REQUEST 2
Как вы можете видеть, некоторые из чтений в конечной точке 2 занимают более секундымедленнее, чем идентичные чтения из того же вызова всего за несколько секунд до этого (например: первое чтение «элементов» занимает 1174 мс против 78 мс!).Что может быть причиной этого?Я проверил, чтобы убедиться, что firebase-admin
не прерывает сокетное соединение между вызовами, поэтому я не думаю, что это виновник, но в остальном у меня нет идей.
Для полноты здесьфункция, которую я использую для извлечения записей из базы данных:
// Fetch the item in the database that matches a given Firebase id
module.exports = function whenFetchedViaId(table, id, req) {
const timer = req.log ? req.log.timer() : () => {};
return req.database
.ref(`/${table}/${id}`)
.once('value')
.then((snapshot) => {
timer(`Firebase ${table} READ Success`, `id: ${id}`);
return snapshot.val();
})
.catch((error) => {
timer(`Firebase ${table} READ Failure`, `id: ${id}`);
throw error;
});
};
Обновление
Вот несколько добавленных журналов для одного из вызовов READ, который принимает> 1 с.Если я не читаю этот вывод журнала, похоже, что бэкэнд Firebase просто занимает секунду, чтобы ответить.Это правильно?
// START REQUEST
Request ("6ee776c5-2b4e-4888-b83b-ea6dddcae263"), Endpoint activated (invocation #: 4) ("GET /api/items/:itemKey")
[FIREBASE]{96328ms} p:1: Listen called for /items/-LDhjV8Hkievzbh5UVfz default
[FIREBASE]{96328ms} p:1: Listen on /items/-LDhjV8Hkievzbh5UVfz for default
[FIREBASE]{96328ms} p:1: {"r":42,"a":"q","b":{"p":"/items/-LDhjV8Hkievzbh5UVfz","h":""}}
[FIREBASE]{97842ms} p:1: handleServerMessage d {"p":"items/-LDhjV8Hkievzbh5UVfz","d":{"baseSpec":"-LDIezNhwWX8OmoWXZO3","createdAt":1527628300934,"id":"-LDhjV8Hkievzbh5UVfz","label":"Testing","panels":{"-LDhjV5y1mAwPmJkE4d3":true},"targetSpec":"-LDIezNqbVuvkpr9WEf8","x":{"-LD8Ap4ujTBp_GP5jTv9":true},"y":{"-LD89GHnTYjh99W8ltsY":true}}}
[FIREBASE]{97843ms} event: /items/-LDhjV8Hkievzbh5UVfz:value:{"baseSpec":"-LDIezNhwWX8OmoWXZO3","createdAt":1527628300934,"id":"-LDhjV8Hkievzbh5UVfz","label":"Testing","panels":{"-LDhjV5y1mAwPmJkE4d3":true},"targetSpec":"-LDIezNqbVuvkpr9WEf8","x":{"-LD8Ap4ujTBp_GP5jTv9":true},"y":{"-LD89GHnTYjh99W8ltsY":true}}
[FIREBASE]{97843ms} p:1: Unlisten called for /items/-LDhjV8Hkievzbh5UVfz default
[FIREBASE]{97843ms} p:1: Unlisten on /items/-LDhjV8Hkievzbh5UVfz for default
[FIREBASE]{97843ms} p:1: {"r":43,"a":"n","b":{"p":"/items/-LDhjV8Hkievzbh5UVfz"}}
[FIREBASE]{97844ms} p:1: from server: {"r":42,"b":{"s":"ok","d":{}}}
Request ("6ee776c5-2b4e-4888-b83b-ea6dddcae263"), Firebase items READ Success ("id: -LDhjV8Hkievzbh5UVfz"): 1516ms