sqlite: add statement duration payload property

Author: araujogui

src/node_sqlite.cc

@@ -1027,15 +1027,15 @@ bool DatabaseSync::Open() {
   diagnostics_channel::Channel* ch =
       diagnostics_channel::Channel::Get(env(), "sqlite.db.query");
   if (ch != nullptr && ch->HasSubscribers()) {
-    sqlite3_trace_v2(connection_, SQLITE_TRACE_STMT, TraceCallback, this);
+    sqlite3_trace_v2(connection_, SQLITE_TRACE_PROFILE, TraceCallback, this);
   }
 
   return true;
 }
 
 void DatabaseSync::EnableTracing() {
   if (!IsOpen()) return;
-  sqlite3_trace_v2(connection_, SQLITE_TRACE_STMT, TraceCallback, this);
+  sqlite3_trace_v2(connection_, SQLITE_TRACE_PROFILE, TraceCallback, this);
 }
 
 void DatabaseSync::DisableTracing() {
@@ -2591,7 +2591,7 @@ int DatabaseSync::TraceCallback(unsigned int type,
                                 void* user_data,
                                 void* p,
                                 void* x) {
-  if (type != SQLITE_TRACE_STMT) {
+  if (type != SQLITE_TRACE_PROFILE) {
     return 0;
   }
 
@@ -2625,6 +2625,10 @@ int DatabaseSync::TraceCallback(unsigned int type,
     }
   }
 
+  // x points to the estimated statement run time in nanoseconds. A double is
+  // sufficient since 2^53 ns (~104 days) exceeds any realistic query duration.
+  sqlite3_int64 duration_ns = *static_cast<sqlite3_int64*>(x);
+
   Local<Object> payload = Object::New(isolate);
   if (payload
           ->Set(context,
@@ -2635,6 +2639,11 @@ int DatabaseSync::TraceCallback(unsigned int type,
           ->Set(context,
                 FIXED_ONE_BYTE_STRING(isolate, "database"),
                 db->object())
+          .IsNothing() ||
+      payload
+          ->Set(context,
+                FIXED_ONE_BYTE_STRING(isolate, "duration"),
+                Number::New(isolate, static_cast<double>(duration_ns)))
           .IsNothing()) {
     return 0;
   }

test/parallel/test-sqlite-trace.js

@@ -147,9 +147,7 @@ suite('sqlite.db.query diagnostics channel', () => {
     const calls = [];
     const db1 = new DatabaseSync(':memory:');
     const db2 = new DatabaseSync(':memory:');
-    t.after(() => {
-      db1.close(); db2.close();
-    });
+    t.after(() => { db1.close(); db2.close(); });
 
     const handler = (msg) => calls.push(msg);
     dc.subscribe('sqlite.db.query', handler);
@@ -163,4 +161,34 @@ suite('sqlite.db.query diagnostics channel', () => {
     assert.strictEqual(calls[1].database, db2);
     assert.notStrictEqual(calls[0].database, calls[1].database);
   });
+
+  it('duration is a number', (t) => {
+    const calls = [];
+    const db = new DatabaseSync(':memory:');
+    t.after(() => db.close());
+
+    const handler = (msg) => calls.push(msg);
+    dc.subscribe('sqlite.db.query', handler);
+    t.after(() => dc.unsubscribe('sqlite.db.query', handler));
+
+    db.exec('CREATE TABLE t (x INTEGER)');
+
+    assert.strictEqual(calls.length, 1);
+    assert.strictEqual(typeof calls[0].duration, 'number');
+  });
+
+  it('duration is non-negative', (t) => {
+    const calls = [];
+    const db = new DatabaseSync(':memory:');
+    t.after(() => db.close());
+
+    const handler = (msg) => calls.push(msg);
+    dc.subscribe('sqlite.db.query', handler);
+    t.after(() => dc.unsubscribe('sqlite.db.query', handler));
+
+    db.exec('CREATE TABLE t (x INTEGER)');
+
+    assert.strictEqual(calls.length, 1);
+    assert.ok(calls[0].duration >= 0);
+  });
 });