perf: improve runtime performance by removing expensive verbose logging

package.json

@@ -1,6 +1,6 @@
 {
     "name": "zenstack-monorepo",
-    "version": "1.0.0-alpha.110",
+    "version": "1.0.0-alpha.111",
     "description": "",
     "scripts": {
         "build": "pnpm -r build",

packages/language/package.json

@@ -1,6 +1,6 @@
 {
     "name": "@zenstackhq/language",
-    "version": "1.0.0-alpha.110",
+    "version": "1.0.0-alpha.111",
     "displayName": "ZenStack modeling language compiler",
     "description": "ZenStack modeling language compiler",
     "homepage": "https://zenstack.dev",

packages/next/package.json

@@ -1,6 +1,6 @@
 {
     "name": "@zenstackhq/next",
-    "version": "1.0.0-alpha.110",
+    "version": "1.0.0-alpha.111",
     "displayName": "ZenStack Next.js integration",
     "description": "ZenStack Next.js integration",
     "homepage": "https://zenstack.dev",

packages/plugins/openapi/package.json

@@ -1,7 +1,7 @@
 {
   "name": "@zenstackhq/openapi",
   "displayName": "ZenStack Plugin and Runtime for OpenAPI",
-  "version": "1.0.0-alpha.110",
+  "version": "1.0.0-alpha.111",
   "description": "ZenStack plugin and runtime supporting OpenAPI",
   "main": "index.js",
   "repository": {

packages/plugins/react/package.json

@@ -1,7 +1,7 @@
 {
     "name": "@zenstackhq/react",
     "displayName": "ZenStack plugin and runtime for ReactJS",
-    "version": "1.0.0-alpha.110",
+    "version": "1.0.0-alpha.111",
     "description": "ZenStack plugin and runtime for ReactJS",
     "main": "index.js",
     "repository": {

packages/plugins/trpc/package.json

@@ -1,7 +1,7 @@
 {
     "name": "@zenstackhq/trpc",
     "displayName": "ZenStack plugin for tRPC",
-    "version": "1.0.0-alpha.110",
+    "version": "1.0.0-alpha.111",
     "description": "ZenStack plugin for tRPC",
     "main": "index.js",
     "repository": {

packages/runtime/package.json

@@ -1,7 +1,7 @@
 {
     "name": "@zenstackhq/runtime",
     "displayName": "ZenStack Runtime Library",
-    "version": "1.0.0-alpha.110",
+    "version": "1.0.0-alpha.111",
     "description": "Runtime of ZenStack for both client-side and server-side environments.",
     "repository": {
         "type": "git",

packages/runtime/src/enhancements/policy/handler.ts

@@ -5,7 +5,6 @@ import { CrudFailureReason } from '@zenstackhq/sdk';
 import { AuthUser, DbClientContract, PolicyOperationKind } from '../../types';
 import { BatchResult, PrismaProxyHandler } from '../proxy';
 import { ModelMeta, PolicyDef } from '../types';
-import { formatObject } from '../utils';
 import { Logger } from './logger';
 import { PolicyUtil } from './policy-utils';
 
@@ -224,7 +223,6 @@ export class PolicyProxyHandler<DbClient extends DbClientContract> implements Pr
         }
 
         // conduct the deletion
-        this.logger.info(`Conducting delete ${this.model}:\n${formatObject(args)}`);
         await this.modelClient.delete(args);
 
         if (!readResult) {
@@ -247,7 +245,6 @@ export class PolicyProxyHandler<DbClient extends DbClientContract> implements Pr
         await this.utils.injectAuthGuard(args, this.model, 'delete');
 
         // conduct the deletion
-        this.logger.info(`Conducting deleteMany ${this.model}:\n${formatObject(args)}`);
         return this.modelClient.deleteMany(args);
     }
 

packages/runtime/src/enhancements/policy/policy-utils.ts

@@ -1,5 +1,6 @@
 /* eslint-disable @typescript-eslint/no-explicit-any */
 
+import { createId } from '@paralleldrive/cuid2';
 import { PrismaClientKnownRequestError, PrismaClientUnknownRequestError } from '@prisma/client/runtime';
 import { AUXILIARY_FIELDS, CrudFailureReason, GUARD_FIELD_NAME, TRANSACTION_FIELD_NAME } from '@zenstackhq/sdk';
 import { camelCase } from 'change-case';
@@ -18,14 +19,15 @@ import { getVersion } from '../../version';
 import { resolveField } from '../model-meta';
 import { NestedWriteVisitor, VisitorContext } from '../nested-write-vistor';
 import { ModelMeta, PolicyDef, PolicyFunc } from '../types';
-import { enumerate, formatObject, getModelFields } from '../utils';
+import { enumerate, getModelFields } from '../utils';
 import { Logger } from './logger';
-import { createId } from '@paralleldrive/cuid2';
 
 /**
  * Access policy enforcement utilities
  */
 export class PolicyUtil {
+    // eslint-disable-next-line @typescript-eslint/ban-ts-comment
+    // @ts-ignore
     private readonly logger: Logger;
 
     constructor(
@@ -240,7 +242,9 @@ export class PolicyUtil {
         // recursively inject read guard conditions into the query args
         await this.injectNestedReadConditions(model, args);
 
-        this.logger.info(`Reading with validation for ${model}: ${formatObject(args)}`);
+        // DEBUG
+        // this.logger.info(`Reading with validation for ${model}: ${formatObject(args)}`);
+
         const result: any[] = await this.db[model].findMany(args);
 
         await Promise.all(result.map((item) => this.postProcessForRead(item, model, args, 'read')));
@@ -266,7 +270,8 @@ export class PolicyUtil {
         }
 
         if (flattened) {
-            this.logger.info(`Filter flattened: ${JSON.stringify(args)}`);
+            // DEBUG
+            // this.logger.info(`Filter flattened: ${JSON.stringify(args)}`);
         }
     }
 
@@ -352,7 +357,9 @@ export class PolicyUtil {
                 continue;
             }
 
-            this.logger.info(`Validating read of to-one relation: ${fieldInfo.type}#${formatObject(ids)}`);
+            // DEBUG
+            // this.logger.info(`Validating read of to-one relation: ${fieldInfo.type}#${formatObject(ids)}`);
+
             await this.checkPolicyForFilter(fieldInfo.type, ids, operation, this.db);
 
             // recurse
@@ -537,7 +544,8 @@ export class PolicyUtil {
                 }
 
                 const query = { where: filter, select };
-                this.logger.info(`fetching pre-update entities for ${model}: ${formatObject(query)})}`);
+                // DEBUG
+                // this.logger.info(`fetching pre-update entities for ${model}: ${formatObject(query)})}`);
 
                 const entities = await this.db[model].findMany(query);
                 entities.forEach((entity) => {
@@ -731,7 +739,8 @@ export class PolicyUtil {
         operation: PolicyOperationKind,
         db: Record<string, DbOperations>
     ) {
-        this.logger.info(`Checking policy for ${model}#${JSON.stringify(filter)} for ${operation}`);
+        // DEBUG
+        // this.logger.info(`Checking policy for ${model}#${JSON.stringify(filter)} for ${operation}`);
 
         const queryFilter = deepcopy(filter);
 
@@ -752,7 +761,8 @@ export class PolicyUtil {
             // we've got schemas, so have to fetch entities and validate them
             const entities = await db[model].findMany(guardedQuery);
             if (entities.length < count) {
-                this.logger.info(`entity ${model} failed policy check for operation ${operation}`);
+                // DEBUG
+                // this.logger.info(`entity ${model} failed policy check for operation ${operation}`);
                 throw this.deniedByPolicy(
                     model,
                     operation,
@@ -764,14 +774,16 @@ export class PolicyUtil {
             const schemaCheckErrors = entities.map((entity) => schema.safeParse(entity)).filter((r) => !r.success);
             if (schemaCheckErrors.length > 0) {
                 const error = schemaCheckErrors.map((r) => !r.success && fromZodError(r.error).message).join(', ');
-                this.logger.info(`entity ${model} failed schema check for operation ${operation}: ${error}`);
+                // DEBUG
+                // this.logger.info(`entity ${model} failed schema check for operation ${operation}: ${error}`);
                 throw this.deniedByPolicy(model, operation, `entities failed schema check: [${error}]`);
             }
         } else {
             // count entities with policy injected and see if any of them are filtered out
             const guardedCount = (await db[model].count(guardedQuery)) as number;
             if (guardedCount < count) {
-                this.logger.info(`entity ${model} failed policy check for operation ${operation}`);
+                // DEBUG
+                // this.logger.info(`entity ${model} failed policy check for operation ${operation}`);
                 throw this.deniedByPolicy(
                     model,
                     operation,
@@ -787,7 +799,8 @@ export class PolicyUtil {
         db: Record<string, DbOperations>,
         preValue: any
     ) {
-        this.logger.info(`Checking post-update policy for ${model}#${ids}, preValue: ${formatObject(preValue)}`);
+        // DEBUG
+        // this.logger.info(`Checking post-update policy for ${model}#${ids}, preValue: ${formatObject(preValue)}`);
 
         const guard = await this.getAuthGuard(model, 'postUpdate', preValue);
 
@@ -799,7 +812,8 @@ export class PolicyUtil {
 
         // see if we get fewer items with policy, if so, reject with an throw
         if (!entity) {
-            this.logger.info(`entity ${model} failed policy check for operation postUpdate`);
+            // DEBUG
+            // this.logger.info(`entity ${model} failed policy check for operation postUpdate`);
             throw this.deniedByPolicy(model, 'postUpdate');
         }
 
@@ -809,7 +823,8 @@ export class PolicyUtil {
             const schemaCheckResult = schema.safeParse(entity);
             if (!schemaCheckResult.success) {
                 const error = fromZodError(schemaCheckResult.error).message;
-                this.logger.info(`entity ${model} failed schema check for operation postUpdate: ${error}`);
+                // DEBUG
+                // this.logger.info(`entity ${model} failed schema check for operation postUpdate: ${error}`);
                 throw this.deniedByPolicy(model, 'postUpdate', `entity failed schema check: ${error}`);
             }
         }

packages/schema/package.json

@@ -3,7 +3,7 @@
     "publisher": "zenstack",
     "displayName": "ZenStack Language Tools",
     "description": "A toolkit for building secure CRUD apps with Next.js + Typescript",
-    "version": "1.0.0-alpha.110",
+    "version": "1.0.0-alpha.111",
     "author": {
         "name": "ZenStack Team"
     },

packages/sdk/package.json

@@ -1,6 +1,6 @@
 {
     "name": "@zenstackhq/sdk",
-    "version": "1.0.0-alpha.110",
+    "version": "1.0.0-alpha.111",
     "description": "ZenStack plugin development SDK",
     "main": "index.js",
     "scripts": {

packages/server/package.json

@@ -1,6 +1,6 @@
 {
     "name": "@zenstackhq/server",
-    "version": "1.0.0-alpha.110",
+    "version": "1.0.0-alpha.111",
     "displayName": "ZenStack Server-side Adapters",
     "description": "ZenStack server-side adapters",
     "homepage": "https://zenstack.dev",

packages/testtools/package.json

@@ -1,6 +1,6 @@
 {
   "name": "@zenstackhq/testtools",
-  "version": "1.0.0-alpha.110",
+  "version": "1.0.0-alpha.111",
   "description": "ZenStack Test Tools",
   "main": "index.js",
   "publishConfig": {