DBクエリ時間のトラッキング - Bookshelf/knex

Question

APIのdbのクエリにかかる時間を監視したいと思います。 Bookshelfプラグインであるbookshelf-signalsを使って次のような関数を作成しました。 ：

bookshelf.on('fetching',() => { 
    server.app.fetching = new Date().valueOf(); 
}); 

bookshelf.on('counting',() => { 
    server.app.fetching = new Date().valueOf(); 
}); 

bookshelf.on('fetched',() => { 
    server.statsd.gauge('db_query', new Date().valueOf() - server.app.fetching); 
}); 

...フェッチ/カウントの直前と直後の時間を取得できるようにします。私は削除と同じことをしました - 削除し、保存 - 保存しました。私は理解できないと思う何

は私がフェッチとフェッチがトリガされたときに表示するためにしようとすると、基本的にはこれで終わった...フェッチとフェッチがトリガされるようになっているときです。

'fetching event A' 
'fetching event B' 
'fetching event C' 
'fetched event C' 
'fetched event B' 
'fetched event A' 

間違った値を誤って返すタイマーが発生しましたが、リード/ヒントはありますか？

Knexで 'クエリ'イベントが発生する可能性があることもわかりました。これを代替ソリューションとして使用することも考えました。私はすべてのモデルにイベントハンドラを適用したい場合は、それが実行不可能作る

knex('whatever_table').on('query',() => {///}); 

... は、私は思う：しかし、私が照会表、すなわちを指定する場合にのみ機能しているようですBookshelfに固執する必要がありますが、イベントの処理方法をどのようにすることができますか？

ありがとうございます！

Answer 1

私はちょうどknexでトランザクション期間をトレースする方法をいくつかの小さなテストコードを書いた。

https://runkit.com/embed/679qu91ylu4w

/** 
* Calculate transaction durations in knex 
* 
*/ 
require('sqlite3'); 
var knex = require("knex")({ 
    client: 'sqlite', 
    connection: ':memory:', 
    pool: { min: 1, max: 10 } 
}); 

function isTransactionStart(querySpec) { 
    return querySpec.sql === 'BEGIN;'; 
} 

function isTransactionEnd(querySpec) { 
    return querySpec.sql === 'COMMIT;' || querySpec.sql === 'ROLLBACK;'; 
} 

const transactionDurations = {}; 

knex.on('query', querySpec => { 
    console.log('On query', querySpec); 

    if (isTransactionStart(querySpec)) { 
    if (transactionDurations[querySpec.__knexUid]) { 
     console.error('New transaction started, before earlier was ended'); 
     return; 
    } 
    transactionDurations[querySpec.__knexUid] = new Date().getTime(); 
    } 

    if (isTransactionEnd(querySpec)) { 
    const startTime = transactionDurations[querySpec.__knexUid]; 
    if (!startTime) { 
     console.error('Transaction end detected, but start time not found'); 
    } 
    const endTime = new Date().getTime(); 
    transactionDurations[querySpec.__knexUid] = null; 
    console.log('TRANSACTION DURATION', endTime - startTime); 
    } 
}); 

// just as an example of other available events to show when they are called 
knex.on('query-response', (res, querySpec) => { 
    // console.log('On query response', res, querySpec); 
}); 

knex.on('query-error', (err, querySpec) => { 
    // console.log('On query error', err, querySpec); 
}); 

try { 
    a = await Promise.all([ 
     knex.transaction(trx => { 
     return trx.raw('select 1'); 
     }), 
     knex.transaction(trx => { 
     return trx.raw('select 2'); 
     }), 
     knex.transaction(trx => { 
     return trx.raw('error me'); 
     }) 
    ]); 
} catch (e) { 
    console.log('Got ERROR:', e); 
} 

アプローチの同じ王は、クエリのタイミングのためにも動作するはずです。タイマーの簿記がメモリを漏らさないようにするには、クリーンアップコードを追加する必要があります。

クエリ時間タイマーは、queryイベントで開始され、query-responseまたはquery-errorで停止する必要があります。

query - query-responseペアquerySpec.__knexQueryUidの属性を使用することができます。 - 私はHapijsで働いています

const dbEvents = (server, sdc) => { 
    knex.on('query', data => { 
    server.app[data.__knexQueryUid + ''] = new Date().valueOf(); 
    }); 

    knex.on('query-response', (data, obj, builder) => { 
    sdc.counter('db_queries_time', new Date().valueOf() - server.app[obj.__knexQueryUid + '']); 
    sdc.increment('nr_db_queries'); 
    }); 
}; 

そして、私は、サーバーを起動したとき、私は、関数を呼び出す：ミカエルLepistöに基づいて

Answer 2

は、私はこの思い付いたスニペット。

EDIT：SDCはstatsdクライアントである、私はDB時間に:)