Firebase-admin无法预测的阅读时间

Question

我有一个Firebase数据库,客户端通过在node.js上运行的REST API访问,然后使用firebase-admin节点客户端从我的firebase数据库中读取.对于我的大多数端点,需要几个并发数据库读取.例如,对于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上的一些读取比几秒前完全相同的调用中的相同读取慢一秒以上(例如:第一个"项目"读取需要1174ms对78ms!).可能是什么原因造成的？我已经检查过以确保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;
        });
};

更新

这是一个为> 1s的READ调用添加的日志记录.除非我误读了这个日志输出,否则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