fix: Possible perf improvement and logging for team members routing logic (#17154)

* chore: increase pagination managed users endpoint (#17147)

* Add server-timings and used concurrency 2 for teamMembers matching

---------

Co-authored-by: Morgan <33722304+ThyMinimalDev@users.noreply.github.com>
This commit is contained in:
Hariom Balhara
2024-10-18 09:44:50 +00:00
committed by GitHub
co-authored by Morgan
parent e1228ca03c
commit 699e08b2ee
7 changed files with 359 additions and 142 deletions
@@ -12,17 +12,27 @@ export const enum RaqbLogicResult {
LOGIC_NOT_FOUND_SO_MATCHED = "LOGIC_NOT_FOUND_SO_MATCHED",
}
export const evaluateRaqbLogic = ({
queryValue,
queryBuilderConfig,
data,
beStrictWithEmptyLogic = false,
}: {
queryValue: JsonTree;
queryBuilderConfig: any;
data: Record<string, unknown>;
beStrictWithEmptyLogic?: boolean;
}): RaqbLogicResult => {
export const evaluateRaqbLogic = (
{
queryValue,
queryBuilderConfig,
data,
beStrictWithEmptyLogic = false,
}: {
queryValue: JsonTree;
queryBuilderConfig: any;
data: Record<string, unknown>;
beStrictWithEmptyLogic?: boolean;
},
config: {
// 2 - Error/Warning
// 1 - Info
// 0 - Debug
logLevel: 0 | 1 | 2;
} = {
logLevel: 1,
}
): RaqbLogicResult => {
const state = {
tree: QbUtils.checkTree(QbUtils.loadTree(queryValue), queryBuilderConfig),
config: queryBuilderConfig,
@@ -40,7 +50,10 @@ export const evaluateRaqbLogic = ({
// If no logic is provided, then consider it a match
return RaqbLogicResult.LOGIC_NOT_FOUND_SO_MATCHED;
}
console.log("Checking logic with data", safeStringify({ logic, data }));
if (config.logLevel >= 1) {
console.log("Checking logic with data", safeStringify({ logic, data }));
}
// eslint-disable-next-line @typescript-eslint/no-explicit-any
return !!jsonLogic.apply(logic as any, data) ? RaqbLogicResult.MATCH : RaqbLogicResult.NO_MATCH;
};
@@ -1,6 +1,7 @@
import type { BaseWidget } from "react-awesome-query-builder";
import { describe, it, expect, vi, beforeEach } from "vitest";
import logger from "@calcom/lib/logger";
import type { AttributeType } from "@calcom/prisma/enums";
import { RoutingFormFieldType } from "../../lib/FieldTypes";
@@ -31,6 +32,55 @@ function mockAttributesScenario({
);
}
function mockHugeAttributesOfTypeSingleSelect({
numAttributes,
numOptionsPerAttribute,
numTeamMembers,
numAttributesUsedPerTeamMember,
}: {
numAttributes: number;
numOptionsPerAttribute: number;
numTeamMembers: number;
numAttributesUsedPerTeamMember: number;
}) {
if (numAttributesUsedPerTeamMember > numAttributes) {
throw new Error("numAttributesUsedPerTeamMember cannot be greater than numAttributes");
}
const attributes = Array.from({ length: numAttributes }, (_, i) => ({
id: `attr${i + 1}`,
name: `Attribute ${i + 1}`,
type: "SINGLE_SELECT" as const,
slug: `attribute-${i + 1}`,
options: Array.from({ length: numOptionsPerAttribute }, (_, i) => ({
id: `opt${i + 1}`,
value: `Option ${i + 1}`,
slug: `option-${i + 1}`,
})),
}));
const assignedAttributeOptionIdForEachMember = 1;
const teamMembersWithAttributeOptionValuePerAttribute = Array.from({ length: numTeamMembers }, (_, i) => ({
userId: i + 1,
attributes: Object.fromEntries(
Array.from({ length: numAttributesUsedPerTeamMember }, (_, j) => [
attributes[j].id,
attributes[j].options[assignedAttributeOptionIdForEachMember].value,
])
),
}));
mockAttributesScenario({
attributes,
teamMembersWithAttributeOptionValuePerAttribute,
});
return {
attributes,
teamMembersWithAttributeOptionValuePerAttribute,
};
}
function buildQueryValue({
rules,
}: {
@@ -126,7 +176,7 @@ describe("findTeamMembersMatchingAttributeLogicOfRoute", () => {
});
it("should return null if route is not found", async () => {
const result = await findTeamMembersMatchingAttributeLogicOfRoute({
const { teamMembersMatchingAttributeLogic: result } = await findTeamMembersMatchingAttributeLogicOfRoute({
form: { routes: [], fields: [] },
response: {},
routeId: "non-existent-route",
@@ -137,7 +187,7 @@ describe("findTeamMembersMatchingAttributeLogicOfRoute", () => {
});
it("should return null if the route does not have an attributesQueryValue set", async () => {
const result = await findTeamMembersMatchingAttributeLogicOfRoute({
const { teamMembersMatchingAttributeLogic: result } = await findTeamMembersMatchingAttributeLogicOfRoute({
form: {
routes: [
{
@@ -183,7 +233,7 @@ describe("findTeamMembersMatchingAttributeLogicOfRoute", () => {
],
}) as AttributesQueryValue;
const result = await findTeamMembersMatchingAttributeLogicOfRoute({
const { teamMembersMatchingAttributeLogic: result } = await findTeamMembersMatchingAttributeLogicOfRoute({
form: {
routes: [
{
@@ -251,7 +301,7 @@ describe("findTeamMembersMatchingAttributeLogicOfRoute", () => {
],
}) as AttributesQueryValue;
const result = await findTeamMembersMatchingAttributeLogicOfRoute({
const { teamMembersMatchingAttributeLogic: result } = await findTeamMembersMatchingAttributeLogicOfRoute({
form: {
routes: [
buildDefaultCustomPageRoute({
@@ -286,50 +336,69 @@ describe("findTeamMembersMatchingAttributeLogicOfRoute", () => {
]);
});
describe("Error handling", () => {
it("should throw an error if the attribute type is not supported", async () => {
const Option1OfAttribute1 = { id: "opt1", value: "Option 1", slug: "option-1" };
const Attribute1 = {
id: "attr1",
name: "Attribute 1",
type: "UNSUPPORTED_ATTRIBUTE_TYPE" as unknown as AttributeType,
slug: "attribute-1",
options: [Option1OfAttribute1],
};
mockAttributesScenario({
attributes: [Attribute1],
teamMembersWithAttributeOptionValuePerAttribute: [
{
userId: 1,
attributes: { [Attribute1.id]: Option1OfAttribute1.value },
},
],
});
describe("Performance testing", () => {
describe("20 attributes, 4000 team members", async () => {
// In tests, the performance is actually really bad than real world. So, skipping this test for now
it.skip("should return matching team members with a SINGLE_SELECT attribute when 'all in' option is selected", async () => {
const { attributes } = mockHugeAttributesOfTypeSingleSelect({
numAttributes: 20,
numOptionsPerAttribute: 30,
numTeamMembers: 4000,
numAttributesUsedPerTeamMember: 10,
});
await expect(
findTeamMembersMatchingAttributeLogicOfRoute({
form: {
routes: [
buildDefaultCustomPageRoute({
id: "test-route",
attributesQueryValue: buildSelectTypeFieldQueryValue({
rules: [
{
raqbFieldId: Attribute1.id,
value: [Option1OfAttribute1.id],
operator: "select_equals",
},
],
}) as AttributesQueryValue,
}),
],
fields: [],
},
response: {},
routeId: "test-route",
teamId: 1,
})
).rejects.toThrow("Unsupported attribute type");
const attributesQueryValue = buildSelectTypeFieldQueryValue({
rules: [
{
raqbFieldId: attributes[0].id,
value: [attributes[0].options[1].id],
operator: "select_equals",
},
],
}) as AttributesQueryValue;
const { teamMembersMatchingAttributeLogic: result, timeTaken } =
await findTeamMembersMatchingAttributeLogicOfRoute(
{
form: {
routes: [
buildDefaultCustomPageRoute({
id: "test-route",
attributesQueryValue: attributesQueryValue,
}),
],
fields: [],
},
response: {},
routeId: "test-route",
teamId: 1,
},
{
concurrency: 1,
enablePerf: true,
}
);
expect(result).toEqual(
expect.arrayContaining([
{
userId: 1,
result: RaqbLogicResult.MATCH,
},
])
);
if (!timeTaken) {
throw new Error("Looks like performance testing is not enabled");
}
const totalTimeTaken = Object.values(timeTaken).reduce((sum, time) => sum ?? 0 + (time || 0), 0);
console.log("Total time taken", totalTimeTaken, {
timeTaken,
});
expect(totalTimeTaken).toBeLessThan(1000);
// All of them should match
expect(result?.length).toBe(4000);
}, 10000);
});
});
});
@@ -1,3 +1,6 @@
import type { ServerResponse } from "http";
import type { NextApiResponse } from "next";
import { entityPrismaWhereClause } from "@calcom/lib/entityPermissionUtils";
import { UserRepository } from "@calcom/lib/server/repository/user";
import type { PrismaClient } from "@calcom/prisma";
@@ -12,6 +15,7 @@ interface FindTeamMembersMatchingAttributeLogicHandlerOptions {
ctx: {
prisma: PrismaClient;
user: NonNullable<TrpcSessionUser>;
res: ServerResponse | NextApiResponse | undefined;
};
input: TFindTeamMembersMatchingAttributeLogicInputSchema;
}
@@ -21,7 +25,7 @@ export const findTeamMembersMatchingAttributeLogicHandler = async ({
input,
}: FindTeamMembersMatchingAttributeLogicHandlerOptions) => {
const { prisma, user } = ctx;
const { formId, response, routeId } = input;
const { formId, response, routeId, _enablePerf, _concurrency } = input;
const form = await prisma.app_RoutingForms_Form.findFirst({
where: {
@@ -46,18 +50,32 @@ export const findTeamMembersMatchingAttributeLogicHandler = async ({
const serializableForm = await getSerializableForm({ form });
const matchingTeamMembersWithResult = await findTeamMembersMatchingAttributeLogicOfRoute({
response,
routeId,
form: serializableForm,
teamId: form.teamId,
});
const {
teamMembersMatchingAttributeLogic: matchingTeamMembersWithResult,
timeTaken: teamMembersMatchingAttributeLogicTimeTaken,
} = await findTeamMembersMatchingAttributeLogicOfRoute(
{
response,
routeId,
form: serializableForm,
teamId: form.teamId,
},
{
enablePerf: _enablePerf,
concurrency: _concurrency,
}
);
if (!matchingTeamMembersWithResult) {
return null;
}
const matchingTeamMembersIds = matchingTeamMembersWithResult.map((member) => member.userId);
const matchingTeamMembers = await UserRepository.findByIds({ ids: matchingTeamMembersIds });
if (_enablePerf) {
ctx.res?.setHeader("Server-Timing", getServerTimingHeader(teamMembersMatchingAttributeLogicTimeTaken));
}
return matchingTeamMembers.map((user) => ({
id: user.id,
name: user.name,
@@ -65,4 +83,21 @@ export const findTeamMembersMatchingAttributeLogicHandler = async ({
}));
};
function getServerTimingHeader(timeTaken: {
gAtr: number | null;
gQryCnfg: number | null;
gMbrWtAtr: number | null;
lgcFrMbrs: number | null;
gQryVal: number | null;
}) {
const headerParts = Object.entries(timeTaken).map(([key, value]) => {
if (value !== null) {
return `${key};dur=${value}`;
}
return null;
}).filter(Boolean);
return headerParts.join(', ');
}
export default findTeamMembersMatchingAttributeLogicHandler;
@@ -4,6 +4,8 @@ export const ZFindTeamMembersMatchingAttributeLogicInputSchema = z.object({
formId: z.string(),
response: z.record(z.string(), z.any()),
routeId: z.string(),
_enablePerf: z.boolean().optional(),
_concurrency: z.number().optional(),
});
export type TFindTeamMembersMatchingAttributeLogicInputSchema = z.infer<
@@ -231,7 +231,6 @@ function getAttributesQueryValue({
return acc;
}, {} as Record<string, Attribute>);
console.log({ attributesMap });
const attributesQueryValueCompatibleForMatchingWithFormField: AttributesQueryValue = JSON.parse(
replaceFieldTemplateVariableWithOptionLabel({
queryValueString: replaceAttributeOptionIdsWithOptionLabel({
@@ -138,8 +138,8 @@ export const responseHandler = async ({ ctx, input }: ResponseHandlerOptions) =>
safeStringify({ teamMembersMatchingAttributeLogicWithResult })
);
const teamMemberIdsMatchingAttributeLogic = teamMembersMatchingAttributeLogicWithResult
? teamMembersMatchingAttributeLogicWithResult?.map((member) => member.userId)
const teamMemberIdsMatchingAttributeLogic = teamMembersMatchingAttributeLogicWithResult?.teamMembersMatchingAttributeLogic
? teamMembersMatchingAttributeLogicWithResult.teamMembersMatchingAttributeLogic.map((member) => member.userId)
: null;
await onFormSubmission(
{ ...serializableFormWithFields, userWithEmails },
+172 -73
View File
@@ -1,4 +1,6 @@
import type { App_RoutingForms_Form, User } from "@prisma/client";
import async from "async";
import os from "os";
import getWebhooks from "@calcom/features/webhooks/lib/getWebhooks";
import { sendGenericWebhookPayload } from "@calcom/features/webhooks/lib/sendPayload";
@@ -26,6 +28,24 @@ const {
const moduleLogger = logger.getSubLogger({ prefix: ["routing-forms/trpc/utils"] });
type SelectFieldWebhookResponse = string | number | string[] | { label: string; id: string | null };
type FORM_SUBMITTED_WEBHOOK_RESPONSES = Record<
string,
{
/**
* Deprecates `value` prop as it now has both the id(that doesn't change) and the label(that can change but is human friendly)
*/
response: number | string | string[] | SelectFieldWebhookResponse | SelectFieldWebhookResponse[];
/**
* @deprecated Use `response` instead
*/
value: FormResponse[keyof FormResponse]["value"];
}
>;
type TeamMemberWithAttributeOptionValuePerAttribute = Awaited<
ReturnType<typeof getTeamMembersWithAttributeOptionValuePerAttribute>
>[number];
function isOptionsField(field: Pick<SerializableField, "type" | "options">) {
return (field.type === "select" || field.type === "multiselect") && field.options;
}
@@ -77,100 +97,179 @@ function getFieldResponse({
};
}
type SelectFieldWebhookResponse = string | number | string[] | { label: string; id: string | null };
type FORM_SUBMITTED_WEBHOOK_RESPONSES = Record<
string,
{
/**
* Deprecates `value` prop as it now has both the id(that doesn't change) and the label(that can change but is human friendly)
*/
response: number | string | string[] | SelectFieldWebhookResponse | SelectFieldWebhookResponse[];
/**
* @deprecated Use `response` instead
*/
value: FormResponse[keyof FormResponse]["value"];
}
>;
/**
* Performance wrapper for async functions
*/
async function asyncPerf<ReturnValue>(fn: () => Promise<ReturnValue>): Promise<[ReturnValue, number | null]> {
const start = performance.now();
const result = await fn();
const end = performance.now();
return [result, end - start];
}
export async function findTeamMembersMatchingAttributeLogicOfRoute({
form,
response,
routeId,
teamId,
}: {
form: Pick<SerializableForm<App_RoutingForms_Form>, "routes" | "fields">;
response: FormResponse;
routeId: string;
teamId: number;
}) {
/**
* Performance wrapper for sync functions
*/
function perf<ReturnValue>(fn: () => ReturnValue): [ReturnValue, number | null] {
const start = performance.now();
const result = fn();
const end = performance.now();
return [result, end - start];
}
export async function findTeamMembersMatchingAttributeLogicOfRoute(
{
form,
response,
routeId,
teamId,
}: {
form: Pick<SerializableForm<App_RoutingForms_Form>, "routes" | "fields">;
response: FormResponse;
routeId: string;
teamId: number;
},
config: {
enablePerf?: boolean;
concurrency?: number;
} = {}
) {
const route = form.routes?.find((route) => route.id === routeId);
// Higher value of concurrency might not be performant as it might overwhelm the system. So, use a lower value as default.
const { enablePerf = false, concurrency = 2 } = config;
if (!route) {
return null;
return {
teamMembersMatchingAttributeLogic: null,
timeTaken: null,
};
}
const teamMembersMatchingAttributeLogic: {
userId: number;
result: RaqbLogicResult;
}[] = [];
if (!isRouter(route)) {
const attributesForTeam = await getAttributesForTeam({ teamId: teamId });
const attributesQueryValue = getAttributesQueryValue({
if (isRouter(route)) {
return {
teamMembersMatchingAttributeLogic: null,
timeTaken: null,
};
}
const teamMembersMatchingAttributeLogicMap = new Map<number, RaqbLogicResult>();
const [attributesForTeam, getAttributesForTeamTimeTaken] = await aPf(
async () => await getAttributesForTeam({ teamId: teamId })
);
const [attributesQueryValue, getAttributesQueryValueTimeTaken] = pf(() =>
getAttributesQueryValue({
attributesQueryValue: route.attributesQueryValue,
attributes: attributesForTeam,
response,
fields: form.fields,
getFieldResponse,
});
})
);
if (!attributesQueryValue) {
return null;
}
if (!attributesQueryValue) {
return {
teamMembersMatchingAttributeLogic: null,
timeTaken: {
gAtr: getAttributesForTeamTimeTaken,
gQryVal: getAttributesQueryValueTimeTaken,
gQryCnfg: null,
gMbrWtAtr: null,
lgcFrMbrs: null,
},
};
}
const attributesQueryBuilderConfig = getAttributesQueryBuilderConfig({
const [attributesQueryBuilderConfig, getAttributesQueryBuilderConfigTimeTaken] = pf(() =>
getAttributesQueryBuilderConfig({
form,
attributes: attributesForTeam,
attributesQueryValue,
});
})
);
moduleLogger.debug(
"Finding team members matching attribute logic",
safeStringify({
form,
response,
routeId,
teamId,
attributesQueryBuilderConfigFields: attributesQueryBuilderConfig.fields,
})
);
moduleLogger.debug(
"Finding team members matching attribute logic",
safeStringify({
form,
response,
routeId,
teamId,
attributesQueryBuilderConfigFields: attributesQueryBuilderConfig.fields,
})
);
const teamMembersWithAttributeOptionValuePerAttribute =
await getTeamMembersWithAttributeOptionValuePerAttribute({ teamId: teamId });
const [
teamMembersWithAttributeOptionValuePerAttribute,
getTeamMembersWithAttributeOptionValuePerAttributeTimeTaken,
] = await aPf(() => getTeamMembersWithAttributeOptionValuePerAttribute({ teamId: teamId }));
teamMembersWithAttributeOptionValuePerAttribute.forEach((member, index) => {
const attributesData = getAttributes({
attributesData: member.attributes,
attributesQueryValue,
});
moduleLogger.debug(
`Checking team member ${member.userId} with attributes logic`,
safeStringify({ attributes: attributesData, attributesQueryValue })
);
const result = evaluateRaqbLogic({
queryValue: attributesQueryValue,
queryBuilderConfig: attributesQueryBuilderConfig,
data: attributesData,
beStrictWithEmptyLogic: true,
});
const [_, teamMembersMatchingAttributeLogicTimeTaken] = await aPf(async () => {
return await async.mapLimit<TeamMemberWithAttributeOptionValuePerAttribute, Promise<void>>(
teamMembersWithAttributeOptionValuePerAttribute,
concurrency,
async (member: TeamMemberWithAttributeOptionValuePerAttribute) => {
const attributesData = getAttributes({
attributesData: member.attributes,
attributesQueryValue,
});
moduleLogger.debug(
`Checking team member ${member.userId} with attributes logic`,
safeStringify({ attributes: attributesData, attributesQueryValue })
);
const result = evaluateRaqbLogic(
{
queryValue: attributesQueryValue,
queryBuilderConfig: attributesQueryBuilderConfig,
data: attributesData,
beStrictWithEmptyLogic: true,
},
{
// This logic runs too many times as it is per team member and we don't want to spam the console with logs. It might also take a performance hit otherwise
logLevel: 2,
}
);
if (result === RaqbLogicResult.MATCH || result === RaqbLogicResult.LOGIC_NOT_FOUND_SO_MATCHED) {
moduleLogger.debug(`Team member ${member.userId} matches attributes logic`);
teamMembersMatchingAttributeLogic.push({ userId: member.userId, result });
} else {
moduleLogger.debug(`Team member ${member.userId} does not match attributes logic`);
if (result === RaqbLogicResult.MATCH || result === RaqbLogicResult.LOGIC_NOT_FOUND_SO_MATCHED) {
moduleLogger.debug(`Team member ${member.userId} matches attributes logic`);
teamMembersMatchingAttributeLogicMap.set(member.userId, result);
} else {
moduleLogger.debug(`Team member ${member.userId} does not match attributes logic`);
return;
}
}
});
);
});
return {
teamMembersMatchingAttributeLogic: Array.from(teamMembersMatchingAttributeLogicMap).map((item) => ({
userId: item[0],
result: item[1],
})),
timeTaken: {
gAtr: getAttributesForTeamTimeTaken,
gQryCnfg: getAttributesQueryBuilderConfigTimeTaken,
gMbrWtAtr: getTeamMembersWithAttributeOptionValuePerAttributeTimeTaken,
lgcFrMbrs: teamMembersMatchingAttributeLogicTimeTaken,
gQryVal: getAttributesQueryValueTimeTaken,
},
};
function pf<ReturnValue>(fn: () => ReturnValue): [ReturnValue, number | null] {
if (!enablePerf) {
return [fn(), null];
}
return perf(fn);
}
return teamMembersMatchingAttributeLogic;
async function aPf<ReturnValue>(fn: () => Promise<ReturnValue>): Promise<[ReturnValue, number | null]> {
if (!enablePerf) {
return [await fn(), null];
}
return asyncPerf(fn);
}
}
export async function onFormSubmission(