убрал перф логирование
Tests / frontend-test (push) Successful in 1m11s

This commit is contained in:
gorbenko.pavel
2026-08-19 16:36:10 +05:00
parent 6f789f8f1c
commit 7bd540e816
4 changed files with 63 additions and 105 deletions
@@ -16,7 +16,6 @@ import { IMyRequest } from './models/IMyRequest';
import { DataTable, IDataTableColumn } from '@tnsu/ui-kit'; import { DataTable, IDataTableColumn } from '@tnsu/ui-kit';
import { REQUEST_STATUS, REQUEST_STATUS_CHOICES, IRequestType, StatusBadge } from '../../shared/approval'; import { REQUEST_STATUS, REQUEST_STATUS_CHOICES, IRequestType, StatusBadge } from '../../shared/approval';
import { onRequestsChanged } from '../../shared/requestEvents'; import { onRequestsChanged } from '../../shared/requestEvents';
import { traced } from './perfTrace';
import { useRoutedQuery } from '../../shared/usePersistedQuery'; import { useRoutedQuery } from '../../shared/usePersistedQuery';
import { IPage, pageKey, pageSignature, readPage, writePage } from './pageCache'; import { IPage, pageKey, pageSignature, readPage, writePage } from './pageCache';
import { Pager } from './Pager'; import { Pager } from './Pager';
@@ -399,7 +398,7 @@ export const RequestsTableView: React.FC<IRequestsTableViewProps> = ({
const load = async (forceRender = false): Promise<void> => { const load = async (forceRender = false): Promise<void> => {
try { try {
const fresh = await traced(`ИТОГО таблица:${view}#${page}`, fetchPage); const fresh = await fetchPage();
if (cancelled) return; if (cancelled) return;
// Перерисовываем, только если данные реально изменились — иначе при // Перерисовываем, только если данные реально изменились — иначе при
@@ -4,7 +4,6 @@ import { getLinkedTypes, hydratePendingAuthors, searchMyRequests } from './myReq
import { IMyRequest } from './models/IMyRequest'; import { IMyRequest } from './models/IMyRequest';
import { IRequestType, StatusBadge } from '../../shared/approval'; import { IRequestType, StatusBadge } from '../../shared/approval';
import { onRequestsChanged } from '../../shared/requestEvents'; import { onRequestsChanged } from '../../shared/requestEvents';
import { traced } from './perfTrace';
import { useRoutedQuery } from '../../shared/usePersistedQuery'; import { useRoutedQuery } from '../../shared/usePersistedQuery';
import { pageKey, pageSignature, readPage, writePage } from './pageCache'; import { pageKey, pageSignature, readPage, writePage } from './pageCache';
import { Pager } from './Pager'; import { Pager } from './Pager';
@@ -186,7 +185,7 @@ export const SearchView: React.FC<ISearchViewProps> = ({
const load = async (forceRender = false): Promise<void> => { const load = async (forceRender = false): Promise<void> => {
try { try {
const fresh = await traced('ИТОГО поиск', () => searchMyRequests(context, types, debouncedQuery)); const fresh = await searchMyRequests(context, types, debouncedQuery);
if (cancelled) return; if (cancelled) return;
applyKnownAuthors(fresh.rows, authors.current); applyKnownAuthors(fresh.rows, authors.current);
const prev = readPage(cacheKey); const prev = readPage(cacheKey);
@@ -16,7 +16,6 @@ import { effectiveUserEmail } from '../../shared/impersonation';
import { IMyRequest } from './models/IMyRequest'; import { IMyRequest } from './models/IMyRequest';
import { IMyRequestsTypeDebug } from './models/IMyRequestsDebug'; import { IMyRequestsTypeDebug } from './models/IMyRequestsDebug';
import { traceLinkedTypes, traceResultRows, traceSearchHits } from './searchTrace'; import { traceLinkedTypes, traceResultRows, traceSearchHits } from './searchTrace';
import { traced } from './perfTrace';
// Список данных «... — данные» → список согласования «... — согласование» // Список данных «... — данные» → список согласования «... — согласование»
// (конвенция именования; см. forms/*/provisioning.json и forms/*/approval/provisioning.json). // (конвенция именования; см. forms/*/provisioning.json и forms/*/approval/provisioning.json).
@@ -203,10 +202,8 @@ async function buildPendingIndex(
// полноценный Search, который эти вызовы как раз заменяют. // полноценный Search, который эти вызовы как раз заменяют.
const resolved = await Promise.all( const resolved = await Promise.all(
flat.map(({ type, target }) => flat.map(({ type, target }) =>
traced(`resolveApprovalSearchTarget:${type.name}#${target.listId}`, () =>
resolveApprovalSearchTarget(context, type, target) resolveApprovalSearchTarget(context, type, target)
) )
)
); );
const okEntries: IApprovalSearchTarget[] = []; const okEntries: IApprovalSearchTarget[] = [];
@@ -228,18 +225,17 @@ async function buildPendingIndex(
// поэтому идут параллельно, а не один за другим. // поэтому идут параллельно, а не один за другим.
const [hitsByTarget, recentByTarget] = await Promise.all([ const [hitsByTarget, recentByTarget] = await Promise.all([
okEntries.length > 0 okEntries.length > 0
? traced('search:approvalsAcrossAll', () => searchAcrossApprovalLists(context, okEntries, tokenEmail, statuses)) ? searchAcrossApprovalLists(context, okEntries, tokenEmail, statuses)
: Promise.resolve(new Map<string, number[]>()), : Promise.resolve(new Map<string, number[]>()),
// Довесок нужен только режиму «чья очередь сейчас»: при текстовом поиске // Довесок нужен только режиму «чья очередь сейчас»: при текстовом поиске
// важна полнота по архиву, а не мгновенная свежесть (см. scope='involved'). // важна полнота по архиву, а не мгновенная свежесть (см. scope='involved').
okEntries.length > 0 && scope === 'myTurn' okEntries.length > 0 && scope === 'myTurn'
? traced('recentRowsAcrossAll', () => fetchRecentApprovalRows(context, okEntries, tokenEmail, statuses)) ? fetchRecentApprovalRows(context, okEntries, tokenEmail, statuses)
: Promise.resolve(new Map<string, Array<Record<string, unknown>>>()), : Promise.resolve(new Map<string, Array<Record<string, unknown>>>()),
]); ]);
const parts = await Promise.all( const parts = await Promise.all(
okEntries.map((entry) => okEntries.map((entry) =>
traced(`finalizeApprovalTarget:${entry.type.name}#${entry.target.listId}`, () =>
finalizeApprovalTarget( finalizeApprovalTarget(
context, context,
entry, entry,
@@ -247,7 +243,6 @@ async function buildPendingIndex(
recentByTarget.get(targetKey(entry)) ?? [] recentByTarget.get(targetKey(entry)) ?? []
) )
) )
)
); );
const rowsByType = new Map<number, IMyRequest[]>(); const rowsByType = new Map<number, IMyRequest[]>();
@@ -343,15 +338,15 @@ export interface INavCounts {
// своим запросом — но параллельно, и ровно тем же вызовом, что наполняет саму // своим запросом — но параллельно, и ровно тем же вызовом, что наполняет саму
// вкладку: иначе счётчик и список могли бы разойтись. // вкладку: иначе счётчик и список могли бы разойтись.
export async function getNavCounts(context: WebPartContext): Promise<INavCounts> { export async function getNavCounts(context: WebPartContext): Promise<INavCounts> {
return traced('ИТОГО getNavCounts', () => getNavCountsInner(context)); return getNavCountsInner(context);
} }
async function getNavCountsInner(context: WebPartContext): Promise<INavCounts> { async function getNavCountsInner(context: WebPartContext): Promise<INavCounts> {
const types = await getLinkedTypes(context); const types = await getLinkedTypes(context);
const [turn, rework] = await Promise.all([ const [turn, rework] = await Promise.all([
traced('buildPendingIndex:myTurn', () => buildPendingIndex(context, 'myTurn', MY_TURN_STATUSES)), buildPendingIndex(context, 'myTurn', MY_TURN_STATUSES),
traced('getOwnRequestsByStatus:rework', () => getOwnRequestsByStatus(context, types, REQUEST_STATUS.returned, 1)), getOwnRequestsByStatus(context, types, REQUEST_STATUS.returned, 1),
]); ]);
return { return {
@@ -419,7 +414,7 @@ async function resolveApprovalSearchTarget(
const dataTitle = const dataTitle =
target.title ?? target.title ??
((await traced(`dataListTitle:${type.name}#${target.listId}`, () => list.select('Title')())).Title as string) ?? ((await list.select('Title')()).Title as string) ??
''; '';
if (!DATA_LIST_SUFFIX.test(dataTitle)) { if (!DATA_LIST_SUFFIX.test(dataTitle)) {
return { return {
@@ -432,9 +427,9 @@ async function resolveApprovalSearchTarget(
const approvalListTitle = `${dataTitle.replace(DATA_LIST_SUFFIX, '')} — согласование`; const approvalListTitle = `${dataTitle.replace(DATA_LIST_SUFFIX, '')} — согласование`;
const approvalList = sp.web.lists.getByTitle(approvalListTitle); const approvalList = sp.web.lists.getByTitle(approvalListTitle);
const rootFolder = (await traced(`approvalListUrl:${type.name}#${target.listId}`, () => const rootFolder = (await approvalList.select('RootFolder/ServerRelativeUrl').expand('RootFolder')()) as {
approvalList.select('RootFolder/ServerRelativeUrl').expand('RootFolder')() RootFolder?: { ServerRelativeUrl?: string };
)) as { RootFolder?: { ServerRelativeUrl?: string } }; };
const relUrl = rootFolder.RootFolder?.ServerRelativeUrl; const relUrl = rootFolder.RootFolder?.ServerRelativeUrl;
if (!relUrl) { if (!relUrl) {
return { kind: 'error', type, target, message: `Список согласования «${approvalListTitle}» не найден` }; return { kind: 'error', type, target, message: `Список согласования «${approvalListTitle}» не найден` };
@@ -583,7 +578,7 @@ async function fetchRecentApprovalRows(
// SharePoint REST — поэтому резолвим email в числовой Id (как и везде в // SharePoint REST — поэтому резолвим email в числовой Id (как и везде в
// проекте) и фильтруем по TansuSiteApproverId. // проекте) и фильтруем по TansuSiteApproverId.
const claimsLogin = tokenEmail.indexOf('|') >= 0 ? tokenEmail : `i:0#.f|membership|${tokenEmail}`; const claimsLogin = tokenEmail.indexOf('|') >= 0 ? tokenEmail : `i:0#.f|membership|${tokenEmail}`;
const approver = await traced(`ensureUser:${siteUrl}`, () => sp.web.ensureUser(claimsLogin)); const approver = await sp.web.ensureUser(claimsLogin);
const filter = `TansuSiteApproverId eq ${approver.Id} and Modified ge '${cutoffIso}'${statusFilter}`; const filter = `TansuSiteApproverId eq ${approver.Id} and Modified ge '${cutoffIso}'${statusFilter}`;
const [batchedSP, execute] = sp.batched(); const [batchedSP, execute] = sp.batched();
@@ -609,7 +604,7 @@ async function fetchRecentApprovalRows(
}) })
); );
await traced(`recentRowsBatch:${siteUrl} (партиций: ${siteEntries.length})`, execute); await execute();
await Promise.all(pending); await Promise.all(pending);
} catch (e) { } catch (e) {
console.error(`[Текущие заявки] Довесок по свежести для ${siteUrl} не сработал:`, (e as Error).message); console.error(`[Текущие заявки] Довесок по свежести для ${siteUrl} не сработал:`, (e as Error).message);
@@ -662,14 +657,12 @@ async function finalizeApprovalTarget(
// Id режем на пачки — тот же предел длины URL REST $filter, что и в // Id режем на пачки — тот же предел длины URL REST $filter, что и в
// loadByIds (см. REST_ID_FILTER_CHUNK). // loadByIds (см. REST_ID_FILTER_CHUNK).
chunk(searchHitIds, REST_ID_FILTER_CHUNK).map((idsChunk) => chunk(searchHitIds, REST_ID_FILTER_CHUNK).map((idsChunk) =>
traced(`approvalRowsRest:${type.name}#${target.listId}`, () =>
approvalList.items approvalList.items
.filter(idsChunk.map((id) => `Id eq ${id}`).join(' or ')) .filter(idsChunk.map((id) => `Id eq ${id}`).join(' or '))
.select('Id', 'TicketId', 'ApprovalStatus') .select('Id', 'TicketId', 'ApprovalStatus')
.top(idsChunk.length)() .top(idsChunk.length)()
) )
) )
)
).reduce((all, r) => all.concat(r as Array<Record<string, unknown>>), [] as Array<Record<string, unknown>>); ).reduce((all, r) => all.concat(r as Array<Record<string, unknown>>), [] as Array<Record<string, unknown>>);
// Довесок по свежести (если он был) идёт ПЕРВЫМ, а из Search берётся только // Довесок по свежести (если он был) идёт ПЕРВЫМ, а из Search берётся только
@@ -702,12 +695,10 @@ async function finalizeApprovalTarget(
// Заголовок/статус/дата заявки — отдельным запросом к списку ДАННЫХ (см. // Заголовок/статус/дата заявки — отдельным запросом к списку ДАННЫХ (см.
// комментарий у функции: через Lookup-expand это не отдаётся). // комментарий у функции: через Lookup-expand это не отдаётся).
const ticketFilter = ticketIds.map((id) => `Id eq ${id}`).join(' or '); const ticketFilter = ticketIds.map((id) => `Id eq ${id}`).join(' or ');
const ticketRows = (await traced(`ticketRowsRest:${type.name}#${target.listId}`, () => const ticketRows = (await list.items
list.items
.filter(ticketFilter) .filter(ticketFilter)
.select('Id', 'RequestUniqueCode', 'Title', 'RequestStatus', 'Created') .select('Id', 'RequestUniqueCode', 'Title', 'RequestStatus', 'Created')
.top(ticketIds.length)() .top(ticketIds.length)()) as Array<Record<string, unknown>>;
)) as Array<Record<string, unknown>>;
debug.rows = ticketRows.map((r) => ({ debug.rows = ticketRows.map((r) => ({
...toMyRequest(r, undefined, type, 'approval', target), ...toMyRequest(r, undefined, type, 'approval', target),
@@ -831,16 +822,14 @@ async function fetchAllSearchRows(
let startRow = 0; let startRow = 0;
for (;;) { for (;;) {
const results = await traced(`search:${label}#${startRow}`, () => const results = await sp.search({
sp.search({
Querytext: kql, Querytext: kql,
RowLimit: SEARCH_PAGE_SIZE, RowLimit: SEARCH_PAGE_SIZE,
StartRow: startRow, StartRow: startRow,
SelectProperties: selectProperties, SelectProperties: selectProperties,
TrimDuplicates: false, TrimDuplicates: false,
...(sortList ? { SortList: sortList } : {}), ...(sortList ? { SortList: sortList } : {}),
}) });
);
const page = results.PrimarySearchResults as Array<Record<string, unknown>>; const page = results.PrimarySearchResults as Array<Record<string, unknown>>;
rows.push(...page); rows.push(...page);
@@ -1080,13 +1069,11 @@ async function loadByIds(
await Promise.all( await Promise.all(
chunk(ids, REST_ID_FILTER_CHUNK).map(async (idsChunk) => { chunk(ids, REST_ID_FILTER_CHUNK).map(async (idsChunk) => {
const rows = (await traced(`loadByIds:${kind}:${type.name}#${target.listId}`, () => const rows = (await list.items
list.items
.filter(idsChunk.map((id) => `Id eq ${id}`).join(' or ')) .filter(idsChunk.map((id) => `Id eq ${id}`).join(' or '))
.select('Id', 'RequestUniqueCode', 'Title', 'RequestStatus', 'Created', 'Author/EMail', 'Author/Title') .select('Id', 'RequestUniqueCode', 'Title', 'RequestStatus', 'Created', 'Author/EMail', 'Author/Title')
.expand('Author') .expand('Author')
.top(idsChunk.length)() .top(idsChunk.length)()) as Array<Record<string, unknown>>;
)) as Array<Record<string, unknown>>;
rows.forEach((r) => { rows.forEach((r) => {
const author = r.Author as { EMail?: string; Title?: string } | undefined; const author = r.Author as { EMail?: string; Title?: string } | undefined;
byKey.set( byKey.set(
@@ -1205,13 +1192,13 @@ export async function getOwnRequests(
): Promise<IOwnRequestsPage> { ): Promise<IOwnRequestsPage> {
if (types.length === 0) return { rows: [], totalRows: 0 }; if (types.length === 0) return { rows: [], totalRows: 0 };
const searchPage = await traced('searchOwnRequests', () => searchOwnRequests(context, types, '', page)); const searchPage = await searchOwnRequests(context, types, '', page);
if (page !== 1) return searchPage; if (page !== 1) return searchPage;
const freshRows = ( const freshRows = (
await Promise.all( await Promise.all(
types.map((t) => traced(`getFreshOwnRowsForType:${t.name}`, () => getFreshOwnRowsForType(context, t))) types.map((t) => getFreshOwnRowsForType(context, t))
) )
).reduce((all, r) => all.concat(r), [] as IMyRequest[]); ).reduce((all, r) => all.concat(r), [] as IMyRequest[]);
@@ -1248,8 +1235,7 @@ export async function searchOwnRequests(
if (text) clauses.push(text); if (text) clauses.push(text);
const kql = clauses.join(' AND '); const kql = clauses.join(' AND ');
const results = await traced('search:searchOwnRequests', () => const results = await sp.search({
sp.search({
Querytext: kql, Querytext: kql,
RowLimit: PAGE_SIZE, RowLimit: PAGE_SIZE,
StartRow: (page - 1) * PAGE_SIZE, StartRow: (page - 1) * PAGE_SIZE,
@@ -1257,14 +1243,13 @@ export async function searchOwnRequests(
TrimDuplicates: false, TrimDuplicates: false,
// Свежие сверху (по умолчанию Search сортирует по релевантности, не по дате). // Свежие сверху (по умолчанию Search сортирует по релевантности, не по дате).
SortList: [{ Property: 'Created', Direction: 1 }], SortList: [{ Property: 'Created', Direction: 1 }],
}) });
);
const totalRows = results.TotalRows || 0; const totalRows = results.TotalRows || 0;
const entries = hitsToEntries(results, types); const entries = hitsToEntries(results, types);
const byKey = const byKey =
entries.length > 0 entries.length > 0
? await traced('loadByIds:own(searchOwnRequests)', () => loadByIds(context, entries, 'own')) ? await loadByIds(context, entries, 'own')
: new Map<string, IMyRequest>(); : new Map<string, IMyRequest>();
// Порядок задаёт релевантность поиска, а не порядок ответов REST. // Порядок задаёт релевантность поиска, а не порядок ответов REST.
const rows = entries.map((e) => byKey.get(requestKey(e.target.listId, e.id))).filter((r): r is IMyRequest => !!r); const rows = entries.map((e) => byKey.get(requestKey(e.target.listId, e.id))).filter((r): r is IMyRequest => !!r);
@@ -1299,8 +1284,7 @@ export async function getOwnRequestsByStatus(
if (text) clauses.push(text); if (text) clauses.push(text);
const kql = clauses.join(' AND '); const kql = clauses.join(' AND ');
const results = await traced('search:getOwnRequestsByStatus', () => const results = await sp.search({
sp.search({
Querytext: kql, Querytext: kql,
RowLimit: PAGE_SIZE, RowLimit: PAGE_SIZE,
StartRow: (page - 1) * PAGE_SIZE, StartRow: (page - 1) * PAGE_SIZE,
@@ -1308,14 +1292,13 @@ export async function getOwnRequestsByStatus(
TrimDuplicates: false, TrimDuplicates: false,
// Свежие сверху — как в searchOwnRequests. // Свежие сверху — как в searchOwnRequests.
SortList: [{ Property: 'Created', Direction: 1 }], SortList: [{ Property: 'Created', Direction: 1 }],
}) });
);
const totalRows = results.TotalRows || 0; const totalRows = results.TotalRows || 0;
const entries = hitsToEntries(results, types); const entries = hitsToEntries(results, types);
const byKey = const byKey =
entries.length > 0 entries.length > 0
? await traced('loadByIds:own(getOwnRequestsByStatus)', () => loadByIds(context, entries, 'own')) ? await loadByIds(context, entries, 'own')
: new Map<string, IMyRequest>(); : new Map<string, IMyRequest>();
const searchRows = entries.map((e) => byKey.get(requestKey(e.target.listId, e.id))).filter((r): r is IMyRequest => !!r); const searchRows = entries.map((e) => byKey.get(requestKey(e.target.listId, e.id))).filter((r): r is IMyRequest => !!r);
@@ -1326,9 +1309,7 @@ export async function getOwnRequestsByStatus(
// вернуть на доработку только что, индекс мог не успеть её подхватить. // вернуть на доработку только что, индекс мог не успеть её подхватить.
const freshRows = ( const freshRows = (
await Promise.all( await Promise.all(
types.map((t) => types.map((t) => getRecentlyChangedOwnRowsForType(context, t))
traced(`getRecentlyChangedOwnRowsForType:${t.name}`, () => getRecentlyChangedOwnRowsForType(context, t))
)
) )
) )
.reduce((acc, r) => acc.concat(r), [] as IMyRequest[]) .reduce((acc, r) => acc.concat(r), [] as IMyRequest[])
@@ -1,21 +0,0 @@
/**
* Замер времени отдельных этапов загрузки «Моих заявок» — что именно тормозит
* (индекс согласований, свои заявки по типу, конкретная партиция, Search),
* а не просто «страница долго грузится».
*
* ВРЕМЕННО: пишет всегда, без флага-переключателя — этот модуль и все traced()
* вокруг снимаются целиком, как только разбор текущей проблемы с
* производительностью закончится (см. myRequests.service.ts, RequestsTableView.tsx,
* SearchView.tsx).
*/
const PREFIX = '[Перф]';
/** Оборачивает async-шаг замером времени. */
export async function traced<T>(label: string, fn: () => Promise<T>): Promise<T> {
const start = performance.now();
try {
return await fn();
} finally {
console.log(`${PREFIX} ${label}: ${(performance.now() - start).toFixed(0)} мс`);
}
}