Skip to content

feat!: rank every timed operation, not just methods, and give each fact one shape #108

Description

@lukecotter

Problem

isMethodNode keeps a node when its type is CODE_UNIT_STARTED or METHOD_ENTRY, or its
subCategory is Method. Measured against what the parser actually produces, that is wrong in
both directions.

Wrongly counted as methods:

  • EXECUTION_STARTED — the whole transaction frame.
  • ENTERING_MANAGED_PKG — a namespace marker.

Both inflate totalMethods in all three tools.

Wrongly excluded — every one of these is a timed node with duration.self:

subCategory Events
SOQL SOQL_EXECUTE_BEGIN (query text, rows, aggregations), SOSL_EXECUTE_BEGIN, QUERY_MORE_BEGIN
DML DML_BEGIN (operation, object, rows)
Flow FLOW_START_INTERVIEW, FLOW_ELEMENT, FLOW_BULK_ELEMENT, event service pub/sub
Workflow WF_RULE_EVAL, WF_FORMULA, WF_APPROVAL, WF_EMAIL_ALERT, duplicate detection
System Method SYSTEM_METHOD_ENTRY, SYSTEM_CONSTRUCTOR_ENTRY, NBA nodes

Self time excludes children, so a query that takes eight seconds adds nothing to its parent's self
time — and the query is never a row of its own. A transaction dominated by one slow query, flow or
DML returns a slowestMethods table of near-zero rows and a low topMethodsSelfPercentage, with
no clue where the time went. The field name hides the hole: nobody looks for DML in a list called
slowestMethods.

find_performance_bottlenecks has three further defects:

  • governorLimitWarnings is emitted whatever analysisType asks for, so analysisType: "methods"
    still returns limit warnings.
  • The same fact has two shapes: databaseBottlenecks.soqlQueries is {used, limit, percentage},
    while governorLimitWarnings.<x> dumps the raw parser object with no percentage. Which shape the
    caller gets depends on which limit tripped, which breaks the one-key-set rule TOON tables need.
  • cpuBottlenecks.warning: "High CPU usage - consider optimizing algorithms" is prose the caller
    cannot act on, beside the percentage that already said it.

And in analyze_apex_log_performance, minDuration filters on total duration while the
ranking is by self duration, so a 500 ms wrapper with 1 ms of its own passes minDuration: 100
and then ranks last. The description does not say which axis it filters.

Design

One module flattens the log once into operations, and every tool is a view over that list.
extractMethods today is the only view, with its filter welded in.

type OperationKind =
  | "codeUnit" | "method" | "systemMethod"
  | "soql" | "sosl" | "dml" | "flow" | "workflow";

kind is not the Salesforce debug log category — subCategory is a timeline grouping, and soql
and dml both come from the database category. Carry both, so an absence is readable: soql 0
beside database NONE means "not logged", and beside database FINEST means "no queries ran".

Governor counts and observed counts stay separate facts, because they disagree when the log is
truncated, and the disagreement is the signal. The parser already detects truncation
(MAXIMUM DEBUG LOG SIZE REACHED) but leaves it in a logIssues string; promote it to a
first-class truncated field so a caller knows not to trust the observed counts.

Every name and every string, swept

The same fact has a different name in each tool. Settled column is what all four adopt.

The fact Summary Analyze Bottlenecks Execute Settles as
duration, with children totalExecutionTime totalExecutionTime, duration totalDuration durationMs durationTotalMs
duration, without children selfDuration durationSelfMs
SOQL count totalSOQLQueries soqlCount soqlCount
DML count totalDMLOperations dmlCount dmlCount
query rows totalSOQLRows soqlRows soqlRowCount
DML rows totalDMLRows dmlRows dmlRowCount
file size size fileSizeBytes fileSizeBytes
a limit's usage {name, used, limit} {used, limit, percentage} and a raw parser dump {limit, used, max, usedPercentage}
a percentage selfPercentage, topMethodsSelfPercentage cpuUsagePercentage, percentage always <fact>Percentage
success success succeeded

totalMethods is worse than a clash: all three analysis tools use the name, but the bottleneck tool
computes it from extractMethods(apexLog, 0) and the summary from countMethods, so two responses
about one log can disagree. It goes, in favour of operationCount per timeByKind row.

Inputs: topMethodslimit, minDurationminSelfMs, analysisType deleted. logFilePath,
namespace, apex, targetOrg, outputDir and debugLevel are unchanged.

Prose that states what the caller can derive

String Carries a fact the numbers do not? Action
note: "No bottlenecks or governor limit warnings found." no, once atRisk: [] is always present delete
warning: "High CPU usage - consider optimizing algorithms" no — the percentage is beside it delete
tip: the .gitignore advice only "this directory did not exist until now" replace with outputDirCreated: true
recommendations[] no delete — see below
logIssues[].summary yes, parser-only keep

Every branch of getRecommendation reads one column of a row already in the response, compares it to
a constant we invented, and emits a sentence. An agent that can read soqlRowCount: 4200 writes that
advice unaided, and writes it better, because it reads every column at once where the rule fires on
the first match only — and once SOQL rows carry the query text it can name the missing filter, which
we never could. The ranking already draws the attention: row 1 is "look here first". Deleting the
field also removes five thresholds we would have to defend.

New responses

apexlog_get_summary
  fileSizeBytes, durationTotalMs, truncated, parsingErrorCount,
  namespaces[], debugLevels[]{category, level},
  governorLimits[]{limit, used, max},
  timeByKind[]{kind, logCategory, level, operationCount, durationSelfMs, selfPercentage},
  logIssues[]?{type, summary}

apexlog_list_slow_operations
  in:  logFilePath, kind?, namespace?, minSelfMs?, limit?, groupBy?
  out: durationTotalMs, returnedSelfPercentage,
       operations[]{kind, name, namespace, lineNumber, callCount,
                    durationTotalMs, durationSelfMs, selfPercentage,
                    soqlCount, dmlCount, soslCount, rowCount, thrownCount}

apexlog_list_limit_risks
  in:  logFilePath, threshold?   (default 80)
  out: threshold, atRisk[]{limit, used, max, usedPercentage}
  • SOQL rows carry the query text. No tool exposes it today.
  • groupBy: "name" aggregates repeats, which is what finds a query inside a loop — the most common
    Apex fault, and undetectable with this server as it stands.
  • minSelfMs filters on the axis it ranks by.
  • threshold and an always-present atRisk list replace note: an empty list says "nothing at risk"
    where an empty object could not be told from a tool that broke. threshold is reported even when
    the caller set it, because without it an empty list cannot be read.
  • analysisType goes: with the namespace breakdown dropped there is nothing left to select
    between, so a parameter leaves the definition and a decision leaves the agent.
  • methodsByNamespace goes: groupBy: "namespace" answers it on demand.

Work

  • New src/tools/operations.ts; retire isMethodNode and extractMethods.
  • Rewrite the three responses, and their jest suites.
  • Re-record goldens, reset TOKEN_BUDGET, DEFINITION_BUDGET and SELECTION_KEYWORDS, and
    regenerate both README token tables.

Breaking. Every analysis response changes shape.

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Projects

    No projects

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions