From 0d7a2bf417c6ea5cc5c6c3568593a0fbe7d7903e Mon Sep 17 00:00:00 2001 From: Yiming Date: Sun, 30 Apr 2023 23:41:07 -0700 Subject: [PATCH] perf: improve runtime performance by removing expensive verbose logging (#371) --- package.json | 2 +- packages/language/package.json | 2 +- packages/next/package.json | 2 +- packages/plugins/openapi/package.json | 2 +- packages/plugins/react/package.json | 2 +- packages/plugins/trpc/package.json | 2 +- packages/runtime/package.json | 2 +- .../src/enhancements/policy/handler.ts | 3 -- .../src/enhancements/policy/policy-utils.ts | 41 +++++++++++++------ packages/schema/package.json | 2 +- packages/sdk/package.json | 2 +- packages/server/package.json | 2 +- packages/testtools/package.json | 2 +- tests/integration/test-run/package-lock.json | 4 +- 14 files changed, 41 insertions(+), 29 deletions(-) diff --git a/package.json b/package.json index 72d7adf33..18f28bd3e 100644 --- a/package.json +++ b/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", diff --git a/packages/language/package.json b/packages/language/package.json index 2c5de4905..08437ad08 100644 --- a/packages/language/package.json +++ b/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", diff --git a/packages/next/package.json b/packages/next/package.json index e3225992d..ff5f2d7c0 100644 --- a/packages/next/package.json +++ b/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", diff --git a/packages/plugins/openapi/package.json b/packages/plugins/openapi/package.json index 9e0ef8659..a266fd8ee 100644 --- a/packages/plugins/openapi/package.json +++ b/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": { diff --git a/packages/plugins/react/package.json b/packages/plugins/react/package.json index 93a4c9f33..77f31cd6c 100644 --- a/packages/plugins/react/package.json +++ b/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": { diff --git a/packages/plugins/trpc/package.json b/packages/plugins/trpc/package.json index f128fe747..8470a62bb 100644 --- a/packages/plugins/trpc/package.json +++ b/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": { diff --git a/packages/runtime/package.json b/packages/runtime/package.json index ba7b67a8b..5846f1ce7 100644 --- a/packages/runtime/package.json +++ b/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", diff --git a/packages/runtime/src/enhancements/policy/handler.ts b/packages/runtime/src/enhancements/policy/handler.ts index 9c5ac16b4..b55b3ec0f 100644 --- a/packages/runtime/src/enhancements/policy/handler.ts +++ b/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 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 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); } diff --git a/packages/runtime/src/enhancements/policy/policy-utils.ts b/packages/runtime/src/enhancements/policy/policy-utils.ts index e279d1044..4f244bef5 100644 --- a/packages/runtime/src/enhancements/policy/policy-utils.ts +++ b/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 ) { - 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, 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}`); } } diff --git a/packages/schema/package.json b/packages/schema/package.json index a4851c2dd..e9e37bfb9 100644 --- a/packages/schema/package.json +++ b/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" }, diff --git a/packages/sdk/package.json b/packages/sdk/package.json index c62a6a23b..4e9d0f9b0 100644 --- a/packages/sdk/package.json +++ b/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": { diff --git a/packages/server/package.json b/packages/server/package.json index 6d9c26644..396838550 100644 --- a/packages/server/package.json +++ b/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", diff --git a/packages/testtools/package.json b/packages/testtools/package.json index 0f5d2e79c..eb07ba3ac 100644 --- a/packages/testtools/package.json +++ b/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": { diff --git a/tests/integration/test-run/package-lock.json b/tests/integration/test-run/package-lock.json index fdcff6665..f6310c5f8 100644 --- a/tests/integration/test-run/package-lock.json +++ b/tests/integration/test-run/package-lock.json @@ -126,7 +126,7 @@ }, "../../../packages/runtime/dist": { "name": "@zenstackhq/runtime", - "version": "1.0.0-alpha.110", + "version": "1.0.0-alpha.111", "license": "MIT", "dependencies": { "@paralleldrive/cuid2": "^2.2.0", @@ -158,7 +158,7 @@ }, "../../../packages/schema/dist": { "name": "zenstack", - "version": "1.0.0-alpha.110", + "version": "1.0.0-alpha.111", "hasInstallScript": true, "license": "MIT", "dependencies": {