Better capture the timing of a postgres query.

.gitignore

@@ -1,3 +1,4 @@
+package-lock.json
 dist/
 node_modules/
 npm-debug.log

.vscode/settings.json

@@ -13,5 +13,6 @@
         "src/**/*.js.map": true
     }
 ,
-"typescript.tsdk": "./node_modules/typescript/lib"
+"typescript.tsdk": "./node_modules/typescript/lib",
+"debug.node.autoAttach": "on"
 }

package.json

@@ -1,6 +1,6 @@
 {
   "name": "tinypg",
-  "version": "4.0.0",
+  "version": "4.1.0",
   "description": "Easy way to call sql files using postgres.",
   "main": "dist/index.js",
   "typings": "dist/index.d.ts",
@@ -10,7 +10,7 @@
     "clean": "rimraf './dist/' './src/**/*.js' './src/**/*.map'",
     "prepublish": "npm run build",
     "test": "npm run build-test && NODE_ENV=test ./node_modules/mocha/bin/mocha 'src/test/**/*.js' --full-trace -t 15000 $MOCHA_FLAGS --require source-map-support/register --reporter spec",
-    "test-debugging": "npm run build-test && NODE_ENV=test ./node_modules/mocha/bin/mocha 'src/test/**/*.js' --debug-brk=5858 --no-timeouts --colors --full-trace $MOCHA_FLAGS --require source-map-support/register --reporter spec"
+    "test-debugging": "npm run build-test && NODE_ENV=test ./node_modules/mocha/bin/mocha 'src/test/**/*.js' --inspect-brk --no-timeouts --colors --full-trace $MOCHA_FLAGS --require source-map-support/register --reporter spec"
   },
   "repository": {
     "type": "git",

src/test/select.ts

@@ -2,6 +2,7 @@ import * as H from './helper'
 import { TinyPg } from '../'
 import * as E from '../errors'
 import { expect } from 'chai'
+import * as T from '../types'
 
 describe('Tiny', () => {
    let tiny: TinyPg
@@ -63,22 +64,30 @@ describe('Tiny', () => {
       })
 
       it('should emit events', () => {
-         let onQueryData: any
-         let onResultData: any
+         let onQueryData: T.QueryBeginContext
+         let onResultData: T.QueryCompleteContext
+         let onSubmitData: T.QuerySubmitContext
 
          tiny.events.on('query', (e: any) => {
             onQueryData = e
          })
 
+         tiny.events.on('submit', (e: any) => {
+            onSubmitData = e
+         })
+
          tiny.events.on('result', (e: any) => {
             onResultData = e
          })
 
          return tiny.sql('a.select').then(res => {
             expect(onQueryData).not.to.be.null
+            expect(onSubmitData).not.to.be.null
             expect(onResultData).not.to.be.null
 
             expect(onQueryData.name).to.equal('a_select')
+            expect(onSubmitData.submit).to.be.least(onQueryData.start)
+            expect(onSubmitData.wait_duration).to.be.least(0)
             expect(onResultData.duration).to.be.least(0)
 
             tiny.events.removeAllListeners()

src/tiny.ts

@@ -217,6 +217,8 @@ export class TinyPg {
          params,
       }
 
+      let submit_context: T.QuerySubmitContext = null
+
       // Work around node-postgres swallowing queries after a connection error
       // https://github.com/brianc/node-postgres/issues/718
       const connection_failed_promise = new Promise<any>((resolve, reject) => {
@@ -250,13 +252,27 @@ export class TinyPg {
                return _.get(params, m.name)
             })
 
-            const result = db_call.config.prepared
-               ? await client.query({
+            const query: Pg.Submittable & { callback: (err: Error, result: Pg.QueryResult) => void } = db_call.config.prepared
+               ? (<any>Pg.Query)({
                     name: db_call.prepared_name,
                     text: db_call.config.parameterized_query,
                     values,
                  })
-               : await client.query(db_call.config.parameterized_query, values)
+               : (<any>Pg.Query)(db_call.config.parameterized_query, values)
+
+            const original_submit = query.submit
+
+            query.submit = (connection: any) => {
+               const submitted_at = Date.now()
+               submit_context = { ...begin_context, submit: submitted_at, wait_duration: submitted_at - begin_context.start }
+               this.events.emit('submit', submit_context)
+               original_submit.call(query, connection)
+            }
+
+            const result = await new Promise<Pg.QueryResult>((resolve, reject) => {
+               query.callback = (err, res) => (err ? reject(err) : resolve(res))
+               client.query(query)
+            })
 
             log('execute result', db_call.config.name)
 
@@ -275,8 +291,28 @@ export class TinyPg {
 
       const createCompleteContext = (error: any, data: T.Result<T>): T.QueryCompleteContext => {
          const end_at = Date.now()
-
-         return { ...begin_context, end: end_at, duration: end_at - start_at, error: error, data: data }
+         const query_duration = end_at - start_at
+
+         const timings = _.isNil(submit_context)
+            ? {
+                 submit: null,
+                 wait_duration: query_duration,
+                 active_duration: 0,
+              }
+            : {
+                 submit: submit_context.submit,
+                 wait_duration: submit_context.wait_duration,
+                 active_duration: end_at - submit_context.submit,
+              }
+
+         return {
+            ...begin_context,
+            ...timings,
+            end: end_at,
+            duration: query_duration,
+            error: error,
+            data: data,
+         }
       }
 
       try {

src/types.ts

@@ -38,9 +38,15 @@ export interface QueryBeginContext {
    params: TinyPgParams
 }
 
-export interface QueryCompleteContext extends QueryBeginContext {
+export interface QuerySubmitContext extends QueryBeginContext {
+   wait_duration: number
+   submit: number
+}
+
+export interface QueryCompleteContext extends QuerySubmitContext {
    end: number
    duration: number
+   active_duration: number
    data: Result<any> | null
    error: Error | null
 }
@@ -83,7 +89,9 @@ export interface TinyPgEvents extends EventEmitter {
 
    on(event: 'result', listener: (x: QueryCompleteContext) => void): this
 
-   emit(event: 'query' | 'result', ...args: any[]): boolean
+   on(event: 'submit', listener: (x: QuerySubmitContext) => void): this
+
+   emit(event: 'query' | 'submit' | 'result', ...args: any[]): boolean
 }
 
 declare module 'pg' {