improve logging

lib/DboBuilder/TableHandler/TableHandler.ts

@@ -3,7 +3,7 @@ import { AnyObject, asName, DeleteParams, FieldFilter, InsertParams, Select, Upd
 import { DB } from "../../Prostgles";
 import { SyncRule, TableRule } from "../../PublishParser/PublishParser";
 import TableConfigurator from "../../TableConfig/TableConfig";
-import { DboBuilder, Filter, LocalParams, parseError, TableHandlers } from "../DboBuilder";
+import { DboBuilder, Filter, getErrorAsObject, LocalParams, parseError, TableHandlers } from "../DboBuilder";
 import type { TableSchema } from "../DboBuilderTypes";
 import { parseUpdateRules } from "../parseUpdateRules";
 import { COMPUTED_FIELDS, FUNCTIONS } from "../QueryBuilder/Functions";
@@ -99,9 +99,8 @@ export class TableHandler extends ViewHandler {
 
   /* External request. Cannot sync from server */
   async sync(filter: Filter, params: { select?: FieldFilter }, param3_unused: undefined, table_rules: TableRule, localParams: LocalParams) {
-
+    const start = Date.now();
     try {
-      await this._log({ command: "sync", localParams, data: { filter, params } });
 
       if (!localParams) throw "Sync not allowed within the server code";
       const { socket } = localParams;
@@ -145,7 +144,7 @@ export class TableHandler extends ViewHandler {
       });
 
       /* Step 1: parse command and params */
-      return this.find(filter, { select, limit: 0 }, undefined, table_rules, localParams)
+      const result = await this.find(filter, { select, limit: 0 }, undefined, table_rules, localParams)
         .then(async _isValid => {
 
           const { filterFields, forcedFilter } = table_rules?.select || {};
@@ -163,8 +162,10 @@ export class TableHandler extends ViewHandler {
             params: { select }
           }).then(channelName => ({ channelName, id_fields, synced_field }));
         });
-
+      await this._log({ command: "sync", localParams, data: { filter, params }, duration: Date.now() - start });
+      return result;
     } catch (e) {
+      await this._log({ command: "sync", localParams, data: { filter, params }, duration: Date.now() - start, error: getErrorAsObject(e) });
       if (localParams && localParams.testRule) throw e;
       throw parseError(e, `dbo.${this.name}.sync()`);
     }

lib/DboBuilder/TableHandler/delete.ts

@@ -1,14 +1,14 @@
 import pgPromise from "pg-promise";
 import { AnyObject, DeleteParams, FieldFilter } from "prostgles-types";
-import { Filter, LocalParams, parseError, withUserRLS } from "../DboBuilder";
+import { Filter, LocalParams, getErrorAsObject, parseError, withUserRLS } from "../DboBuilder";
 import { DeleteRule, TableRule } from "../../PublishParser/PublishParser";
 import { runQueryReturnType } from "../ViewHandler/find";
 import { TableHandler } from "./TableHandler";
 import { onDeleteFromFileTable } from "./onDeleteFromFileTable";
 
 export async function _delete(this: TableHandler, filter?: Filter, params?: DeleteParams, param3_unused?: undefined, tableRules?: TableRule, localParams?: LocalParams): Promise<any> {
+  const start = Date.now();
   try {
-    await this._log({ command: "delete", localParams, data: { filter, params } });
     const { returning } = params || {};
     filter = filter || {};
     this.checkFilter(filter);
@@ -86,24 +86,29 @@ export async function _delete(this: TableHandler, filter?: Filter, params?: Dele
      * Delete file
      */
     if (this.is_media) {
-      return onDeleteFromFileTable.bind(this)({ 
+      const result = await onDeleteFromFileTable.bind(this)({ 
         localParams, 
         queryType, 
         returningQuery: returnQuery? returnQuery : undefined,
         filterOpts,
       });
+      await this._log({ command: "delete", localParams, data: { filter, params }, duration: Date.now() - start });
+      return result;
     }
 
-    return runQueryReturnType({ 
+    const result = await runQueryReturnType({ 
       queryWithoutRLS,
       queryWithRLS,
       newQuery: undefined, 
       returnType: params?.returnType, 
       handler: this, 
       localParams
     });
+    await this._log({ command: "delete", localParams, data: { filter, params }, duration: Date.now() - start });
+    return result;
 
   } catch (e) {
+    await this._log({ command: "delete", localParams, data: { filter, params }, duration: Date.now() - start, error: getErrorAsObject(e) });
     if (localParams && localParams.testRule) throw e;
     throw parseError(e, `dbo.${this.name}.delete(${JSON.stringify(filter || {}, null, 2)}, ${JSON.stringify(params || {}, null, 2)})`);
   }

lib/DboBuilder/TableHandler/insert.ts

@@ -1,18 +1,17 @@
 import { AnyObject, InsertParams, asName, isObject } from "prostgles-types";
-import { LocalParams, parseError, withUserRLS } from "../DboBuilder";
 import { TableRule, ValidateRowBasic } from "../../PublishParser/PublishParser";
+import { LocalParams, getErrorAsObject, parseError, withUserRLS } from "../DboBuilder";
 import { insertNestedRecords } from "../insertNestedRecords";
-import { insertTest } from "./insertTest";
+import { prepareNewData } from "./DataValidator";
 import { TableHandler } from "./TableHandler";
+import { insertTest } from "./insertTest";
 import { runInsertUpdateQuery } from "./runInsertUpdateQuery";
-import { prepareNewData } from "./DataValidator";
-import { DBOFullyTyped } from "../../DBSchemaBuilder";
 
 export async function insert(this: TableHandler, rowOrRows: AnyObject | AnyObject[] = {}, insertParams?: InsertParams, param3_unused?: undefined, tableRules?: TableRule, localParams?: LocalParams): Promise<any | any[] | boolean> {
 
   const ACTION = "insert";
+  const start = Date.now();
   try {
-    await this._log({ command: "insert", localParams, data: { rowOrRows, param2: insertParams } });
 
     const { fixIssues = false } = insertParams || {};
     const { returnQuery = false, nestedInsert } = localParams || {};
@@ -129,7 +128,7 @@ export async function insert(this: TableHandler, rowOrRows: AnyObject | AnyObjec
       console.log(this.tx?.t.ctx?.start, "insert in " + this.name, data);
     }
 
-    return await runInsertUpdateQuery({
+    const result = await runInsertUpdateQuery({
       rule, 
       localParams, 
       queryWithoutUserRLS, 
@@ -141,8 +140,10 @@ export async function insert(this: TableHandler, rowOrRows: AnyObject | AnyObjec
       type: "insert",
       isMultiInsert,
     });
-
+    await this._log({ command: "insert", localParams, data: { rowOrRows, param2: insertParams }, duration: Date.now() - start });
+    return result;
   } catch (e) {
+    await this._log({ command: "insert", localParams, data: { rowOrRows, param2: insertParams }, duration: Date.now() - start, error: getErrorAsObject(e) });
     if (localParams?.testRule) throw e;
     throw parseError(e, `dbo.${this.name}.${ACTION}()`)
   }

lib/DboBuilder/TableHandler/update.ts

@@ -1,6 +1,6 @@
 import { AnyObject, UpdateParams } from "prostgles-types";
 import { TableRule } from "../../PublishParser/PublishParser";
-import { Filter, LocalParams, parseError, withUserRLS } from "../DboBuilder";
+import { Filter, LocalParams, getErrorAsObject, parseError, withUserRLS } from "../DboBuilder";
 import { getInsertTableRules, getReferenceColumnInserts } from "../insertNestedRecords";
 import { runInsertUpdateQuery } from "./runInsertUpdateQuery";
 import { TableHandler } from "./TableHandler";
@@ -9,8 +9,8 @@ import { prepareNewData } from "./DataValidator";
 
 export async function update(this: TableHandler, filter: Filter, _newData: AnyObject, params?: UpdateParams, tableRules?: TableRule, localParams?: LocalParams): Promise<AnyObject | void> {
   const ACTION = "update";
+  const start = Date.now();
   try {
-    await this._log({ command: "update", localParams, data: { filter, _newData, params } });
     /** postValidate */
     const finalDBtx = this.getFinalDBtx(localParams);
     const wrapInTx = () => this.dboBuilder.getTX(_dbtx => _dbtx[this.name]?.[ACTION]?.(filter, _newData, params, tableRules, localParams))
@@ -105,7 +105,7 @@ export async function update(this: TableHandler, filter: Filter, _newData: AnyOb
 
     if (returnQuery) return query as unknown as void;
 
-    return runInsertUpdateQuery({
+    const result = await runInsertUpdateQuery({
       tableHandler: this,
       data: undefined,
       fields,
@@ -117,8 +117,10 @@ export async function update(this: TableHandler, filter: Filter, _newData: AnyOb
       type: "update",
       nestedInsertsResultsObj
     });
-
+    await this._log({ command: "update", localParams, data: { filter, _newData, params }, duration: Date.now() - start });
+    return result;
   } catch (e) {
+    await this._log({ command: "update", localParams, data: { filter, _newData, params }, duration: Date.now() - start, error: getErrorAsObject(e) });
     if (localParams && localParams.testRule) throw e;
     throw parseError(e, `dbo.${this.name}.${ACTION}(${JSON.stringify(filter || {}, null, 2)}, ${Array.isArray(_newData)? "[{...}]": "{...}"}, ${JSON.stringify(params || {}, null, 2)})`)
   }

lib/DboBuilder/TableHandler/updateBatch.ts

@@ -1,12 +1,12 @@
 import { AnyObject, UpdateParams } from "prostgles-types";
-import { Filter, LocalParams, getClientErrorFromPGError, parseError, withUserRLS } from "../DboBuilder";
+import { Filter, LocalParams, getClientErrorFromPGError, getErrorAsObject, parseError, withUserRLS } from "../DboBuilder";
 import { TableRule } from "../../PublishParser/PublishParser";
 import { TableHandler } from "./TableHandler";
 
 
 export async function updateBatch(this: TableHandler, updates: [Filter, AnyObject][], params?: UpdateParams, tableRules?: TableRule, localParams?: LocalParams): Promise<any> {
+  const start = Date.now();
   try {
-    await this._log({ command: "updateBatch", localParams, data: { data: updates, params } });
     const { checkFilter, postValidate } = tableRules?.update ?? {};
     if(checkFilter || postValidate){
       throw `updateBatch not allowed for tables with checkFilter or postValidate rules`
@@ -31,12 +31,19 @@ export async function updateBatch(this: TableHandler, updates: [Filter, AnyObjec
 
     const t = localParams?.tx?.t ?? this.tx?.t;
     if(t){
-      return t.none(queries.join(";\n"))
+      const result = await t.none(queries.join(";\n"));
+      await this._log({ command: "updateBatch", localParams, data: { data: updates, params }, duration: Date.now() - start });
+      return result;
     }
-    return this.db.tx(t => {
-      return t.none(queries.join(";\n"));
-    }).catch(err => getClientErrorFromPGError(err, { type: "tableMethod", localParams, view: this, allowedKeys: []}));
+    const result = await this.db.tx(t => {
+        return t.none(queries.join(";\n"));
+      })
+      .catch(err => getClientErrorFromPGError(err, { type: "tableMethod", localParams, view: this, allowedKeys: []}));
+
+    await this._log({ command: "updateBatch", localParams, data: { data: updates, params }, duration: Date.now() - start });
+    return result;
   } catch (e) {
+    await this._log({ command: "updateBatch", localParams, data: { data: updates, params }, duration: Date.now() - start, error: getErrorAsObject(e) });
     if (localParams && localParams.testRule) throw e;
     throw parseError(e, `dbo.${this.name}.update()`);
   }

lib/DboBuilder/TableHandler/upsert.ts

@@ -2,11 +2,11 @@ import { AnyObject, UpdateParams } from "prostgles-types";
 import { TableHandler } from "./TableHandler";
 import { Filter, LocalParams } from "../DboBuilderTypes";
 import { TableRule } from "../../PublishParser/publishTypesAndUtils";
-import { parseError } from "../dboBuilderUtils";
+import { getErrorAsObject, parseError } from "../dboBuilderUtils";
 
 export const upsert = async function(this: TableHandler, filter: Filter, newData: AnyObject, params?: UpdateParams, table_rules?: TableRule, localParams?: LocalParams): Promise<any> {
+  const start = Date.now();
   try {
-    await this._log({ command: "upsert", localParams, data: { filter, newData, params } });
     const _upsert = async function (tblH: TableHandler) {
       return tblH.find(filter, { select: "", limit: 1 }, undefined, table_rules, localParams)
         .then(exists => {
@@ -22,10 +22,13 @@ export const upsert = async function(this: TableHandler, filter: Filter, newData
     if (!this.tx) {
       return this.dboBuilder.getTX(dbTX => _upsert(dbTX[this.name] as TableHandler))
     } else {
-      return _upsert(this);
+      const result = await _upsert(this);
+      await this._log({ command: "upsert", localParams, data: { filter, newData, params }, duration: Date.now() - start });
+      return result;
     }
 
   } catch (e) {
+    await this._log({ command: "upsert", localParams, data: { filter, newData, params }, duration: Date.now() - start, error: getErrorAsObject(e) });
     if (localParams && localParams.testRule) throw e;
     throw parseError(e, `dbo.${this.name}.upsert()`);
   }

lib/DboBuilder/ViewHandler/ViewHandler.ts

@@ -85,8 +85,8 @@ export class ViewHandler {
     });
   } 
 
-  _log = ({ command, data, localParams }: Pick<TableEvent, "command" | "data" | "localParams">) => {
-    return this.dboBuilder.prostgles.opts.onLog?.({ type: "table", tableName: this.name, command, data, localParams })
+  _log = ({ command, data, localParams, duration, error }: Pick<TableEvent, "command" | "data" | "localParams"> & { duration: number; error?: any; }) => {
+    return this.dboBuilder.prostgles.opts.onLog?.({ type: "table", tableName: this.name, command, data, localParams, duration, error });
   }
 
   getRowHashSelect(allowedFields: FieldFilter, alias?: string, tableAlias?: string): string {
@@ -271,12 +271,14 @@ export class ViewHandler {
   async findOne(filter?: Filter, selectParams?: SelectParams, _param3_unused?: undefined, table_rules?: TableRule, localParams?: LocalParams): Promise<any> {
 
     try {
-      await this._log({ command: "find", localParams, data: { filter, selectParams } });
       const { limit, ...params } = selectParams ?? {};
       if (limit) {
         throw "limit not allowed in findOne()";
       }
-      return this.find(filter, { ...params, limit: 1, returnType: "row" }, undefined, table_rules, localParams);
+      const start = Date.now();
+      const result = await this.find(filter, { ...params, limit: 1, returnType: "row" }, undefined, table_rules, localParams);
+      await this._log({ command: "find", localParams, data: { filter, selectParams }, duration: Date.now() - start });
+      return result;
     } catch (e) {
       if (localParams && localParams.testRule) throw e;
       throw parseError(e, `Issue with dbo.${this.name}.findOne()`);

lib/DboBuilder/ViewHandler/count.ts

@@ -1,15 +1,15 @@
 import { SelectParams } from "prostgles-types";
-import { parseError, withUserRLS } from "../dboBuilderUtils";
+import { getErrorAsObject, parseError, withUserRLS } from "../dboBuilderUtils";
 import { ViewHandler } from "./ViewHandler";
 import { Filter, LocalParams } from "../DboBuilder";
 import { TableRule } from "../../PublishParser/publishTypesAndUtils";
 
 export async function count(this: ViewHandler, _filter?: Filter, selectParams?: SelectParams, _param3_unused?: undefined, table_rules?: TableRule, localParams?: LocalParams): Promise<number> {
   const filter = _filter || {};
   const { limit: _limit, ...selectParamsWithoutLimit } = selectParams ?? {};
+  const start = Date.now();
   try {
-    await this._log({ command: "count", localParams, data: { filter } });
-    return await this.find(filter, { select: selectParamsWithoutLimit?.select ?? "", limit: 0 }, undefined, table_rules, localParams)
+    const result = await this.find(filter, { select: selectParamsWithoutLimit?.select ?? "", limit: 0 }, undefined, table_rules, localParams)
       .then(async _allowed => {
         const findQuery = await this.find(
           filter, 
@@ -28,7 +28,11 @@ export async function count(this: ViewHandler, _filter?: Filter, selectParams?:
         const handler = this.tx?.t ?? this.db;
         return handler.one(query).then(({ count }) => +count);
       });
+
+    await this._log({ command: "count", localParams, data: { filter }, duration: Date.now() - start });
+    return result;
   } catch (e) {
+    await this._log({ command: "count", localParams, data: { filter }, duration: Date.now() - start, error: getErrorAsObject(e) });
     if (localParams && localParams.testRule) throw e;
     throw parseError(e, `dbo.${this.name}.count()`)
   }

lib/DboBuilder/ViewHandler/find.ts

@@ -1,6 +1,6 @@
 
 import { SelectParams, isObject } from "prostgles-types";
-import { Filter, LocalParams, getClientErrorFromPGError, parseError, withUserRLS } from "../DboBuilder";
+import { Filter, LocalParams, getClientErrorFromPGError, getErrorAsObject, parseError, withUserRLS } from "../DboBuilder";
 import { canRunSQL } from "../runSQL";
 import { TableRule } from "../../PublishParser/PublishParser";
 import { getNewQuery } from "../QueryBuilder/getNewQuery";
@@ -10,8 +10,9 @@ import { ViewHandler } from "./ViewHandler";
 import { NewQuery } from "../QueryBuilder/QueryBuilder";
 
 export const find = async function(this: ViewHandler, filter?: Filter, selectParams?: SelectParams, _?: undefined, tableRules?: TableRule, localParams?: LocalParams): Promise<any[]> {
+  const start = Date.now();
+  const command = selectParams?.limit === 1 && selectParams?.returnType === "row"? "findOne" : "find";
   try {
-    await this._log({ command: "find", localParams, data: { filter, selectParams } });
     filter = filter || {};
     const allowedReturnTypes = Object.keys({ 
       row: 1, statement: 1, value: 1, values: 1, 
@@ -92,7 +93,7 @@ export const find = async function(this: ViewHandler, filter?: Filter, selectPar
       return ((localParams?.returnQuery === "noRLS"? queryWithoutRLS : queryWithRLS) as unknown as any[]);
     }
 
-    return runQueryReturnType({ 
+    const result = await runQueryReturnType({ 
       queryWithoutRLS, 
       queryWithRLS, 
       returnType, 
@@ -101,7 +102,10 @@ export const find = async function(this: ViewHandler, filter?: Filter, selectPar
       newQuery,
     });
 
+    await this._log({ command, localParams, data: { filter, selectParams }, duration: Date.now() - start });
+    return result;
   } catch (e) {
+    this._log({ command, localParams, data: { filter, selectParams }, duration: Date.now() - start, error: getErrorAsObject(e) });
     if (localParams && localParams.testRule) throw e;
     throw parseError(e, `dbo.${this.name}.find()`);
   }

lib/DboBuilder/ViewHandler/getInfo.ts

@@ -1,17 +1,20 @@
-import { 
-  TableInfo as TInfo, pickKeys,
- } from "prostgles-types/dist";
-import { LocalParams } from "../DboBuilder";
+import {
+  TableInfo as TInfo
+} from "prostgles-types/dist";
 import { TableRule } from "../../PublishParser/PublishParser";
+import { LocalParams } from "../DboBuilder";
 import { ViewHandler } from "./ViewHandler";
 
 export async function getInfo(this: ViewHandler, lang?: string, param2?: any, param3?: any, tableRules?: TableRule, localParams?: LocalParams): Promise<TInfo> {
-  await this._log({ command: "getInfo", localParams, data: { lang } });
   const p = this.getValidatedRules(tableRules, localParams);
-  if (!p.getInfo) throw "Not allowed";
+  if (!p.getInfo) {
+    await this._log({ command: "getInfo", localParams, data: { lang }, duration: 0, error: "Not allowed" });
+    throw "Not allowed";
+  }
 
   const fileTableName = this.dboBuilder.prostgles?.opts?.fileTable?.tableName;
 
+  await this._log({ command: "getInfo", localParams, data: { lang }, duration: 0 });
   return {
     oid: this.tableOrViewInfo.oid,
     comment: this.tableOrViewInfo.comment,