Restore API performance tracking and fix perf dashboard
- Add queryTimed(), logPerf(), flushPerfBuffer() to environment.cfm - Auto-create ApiPerfLogs table on first flush - Hook logPerf into Application.cfm apiAbort for automatic tracking - Initialize request perf counters in Application.cfm - Remove local apiAbort() overrides from 7 endpoints - Instrument 12 high-traffic endpoints with logPerf calls - Buffer metrics in application scope, batch INSERT every 100 requests - 30-day auto-cleanup with probabilistic trigger Co-Authored-By: Claude Opus 4.5 <noreply@anthropic.com>
This commit is contained in:
parent
1210249f54
commit
bffca643b5
19 changed files with 163 additions and 36 deletions
|
|
@ -56,7 +56,9 @@
|
|||
|
||||
<cfscript>
|
||||
function apiAbort(payload) {
|
||||
writeOutput(serializeJSON(payload));
|
||||
var json = serializeJSON(payload);
|
||||
try { logPerf(len(json)); } catch (any e) {}
|
||||
writeOutput(json);
|
||||
abort;
|
||||
}
|
||||
|
||||
|
|
@ -83,6 +85,11 @@ if (structKeyExists(cgi, "SCRIPT_NAME")) {
|
|||
}
|
||||
request._api_path = lcase(request._api_scriptName);
|
||||
|
||||
// Performance tracking - start timer
|
||||
request._perf_start = getTickCount();
|
||||
request._perf_queryCount = 0;
|
||||
request._perf_queryTimeMs = 0;
|
||||
|
||||
// Public allowlist
|
||||
request._api_isPublic = false;
|
||||
if (len(request._api_path)) {
|
||||
|
|
|
|||
|
|
@ -96,6 +96,7 @@ try {
|
|||
}
|
||||
request.UserID = q.ID;
|
||||
|
||||
try{logPerf(0);}catch(any e){}
|
||||
writeOutput(serializeJSON({
|
||||
"OK": true,
|
||||
"ERROR": "",
|
||||
|
|
|
|||
|
|
@ -103,6 +103,7 @@ try {
|
|||
}
|
||||
}
|
||||
|
||||
try{logPerf(0);}catch(any e){}
|
||||
writeOutput(serializeJSON({
|
||||
"OK": true,
|
||||
"UUID": userUUID,
|
||||
|
|
|
|||
|
|
@ -105,6 +105,7 @@ try {
|
|||
// For new signups, this will always be true
|
||||
needsProfile = !len(trim(qUser.FirstName));
|
||||
|
||||
try{logPerf(0);}catch(any e){}
|
||||
writeOutput(serializeJSON({
|
||||
"OK": true,
|
||||
"UserID": qUser.ID,
|
||||
|
|
|
|||
|
|
@ -161,4 +161,5 @@ beaconId = int(data.BeaconID);
|
|||
}>
|
||||
</cfif>
|
||||
|
||||
<cfscript>try{logPerf(0);}catch(any e){}</cfscript>
|
||||
<cfoutput>#serializeJSON(response)#</cfoutput>
|
||||
|
|
|
|||
|
|
@ -87,4 +87,5 @@ if (structKeyExists(data, "onlyActive")) {
|
|||
})>
|
||||
</cfloop>
|
||||
|
||||
<cfscript>try{logPerf(0);}catch(any e){}</cfscript>
|
||||
<cfoutput>#serializeJSON({ OK=true, ERROR="", BusinessID=bizId, COUNT=arrayLen(beacons), BEACONS=beacons })#</cfoutput>
|
||||
|
|
|
|||
|
|
@ -156,5 +156,6 @@ try {
|
|||
response["ERROR"] = e.message;
|
||||
}
|
||||
|
||||
try{logPerf(0);}catch(any e){}
|
||||
writeOutput(serializeJSON(response));
|
||||
</cfscript>
|
||||
|
|
|
|||
|
|
@ -5,11 +5,6 @@
|
|||
<cfheader name="Cache-Control" value="no-store">
|
||||
|
||||
<cfscript>
|
||||
function apiAbort(payload) {
|
||||
writeOutput(serializeJSON(payload));
|
||||
abort;
|
||||
}
|
||||
|
||||
function readJsonBody() {
|
||||
raw = toString(getHttpRequestData().content);
|
||||
if (isNull(raw) || len(trim(raw)) EQ 0) return {};
|
||||
|
|
|
|||
|
|
@ -5,11 +5,6 @@
|
|||
<cfheader name="Cache-Control" value="no-store">
|
||||
|
||||
<cfscript>
|
||||
function apiAbort(payload) {
|
||||
writeOutput(serializeJSON(payload));
|
||||
abort;
|
||||
}
|
||||
|
||||
// Read JSON body for user location
|
||||
function readJsonBody() {
|
||||
var raw = getHttpRequestData().content;
|
||||
|
|
@ -100,6 +95,7 @@ try {
|
|||
}
|
||||
|
||||
// Provide BOTH keys to satisfy any Flutter casing expectation
|
||||
try{logPerf(0);}catch(any e){}
|
||||
writeOutput(serializeJSON({
|
||||
"OK": true,
|
||||
"ERROR": "",
|
||||
|
|
|
|||
|
|
@ -10,11 +10,6 @@
|
|||
* POST JSON: { "BusinessID": 37, "BrandColor": "#1B4D3E" }
|
||||
*/
|
||||
|
||||
function apiAbort(payload) {
|
||||
writeOutput(serializeJSON(payload));
|
||||
abort;
|
||||
}
|
||||
|
||||
requestBody = toString(getHttpRequestData().content);
|
||||
if (!len(requestBody)) {
|
||||
apiAbort({ "OK": false, "ERROR": "no_body", "MESSAGE": "No request body provided" });
|
||||
|
|
|
|||
|
|
@ -116,9 +116,152 @@ function apiError(message, detail = "", statusCode = 500) {
|
|||
return response;
|
||||
}
|
||||
|
||||
// ============================================
|
||||
// PERFORMANCE PROFILING
|
||||
// ============================================
|
||||
application.perfEnabled = true;
|
||||
|
||||
if (!structKeyExists(application, "perfBuffer")) {
|
||||
application.perfBuffer = [];
|
||||
}
|
||||
|
||||
/**
|
||||
* Drop-in replacement for queryExecute() that tracks query count and time.
|
||||
* Opt-in: use in endpoints where you want accurate DB time breakdown.
|
||||
*/
|
||||
function queryTimed(required string sql, any params = [], struct options = {}) {
|
||||
if (!structKeyExists(request, "_perf_queryCount")) {
|
||||
request._perf_queryCount = 0;
|
||||
request._perf_queryTimeMs = 0;
|
||||
}
|
||||
|
||||
var t = getTickCount();
|
||||
var result = queryExecute(arguments.sql, arguments.params, arguments.options);
|
||||
var elapsed = getTickCount() - t;
|
||||
|
||||
request._perf_queryCount++;
|
||||
request._perf_queryTimeMs += elapsed;
|
||||
|
||||
return result;
|
||||
}
|
||||
|
||||
/**
|
||||
* Flush the in-memory perf buffer to the ApiPerfLogs MySQL table.
|
||||
* Thread-safe: duplicates buffer under lock, then inserts outside lock.
|
||||
*/
|
||||
function flushPerfBuffer() {
|
||||
// Auto-create table if it doesn't exist
|
||||
if (!structKeyExists(application, "_perfTableChecked")) {
|
||||
try {
|
||||
queryExecute("
|
||||
CREATE TABLE IF NOT EXISTS ApiPerfLogs (
|
||||
ID INT AUTO_INCREMENT PRIMARY KEY,
|
||||
Endpoint VARCHAR(255) NOT NULL,
|
||||
TotalMs INT NOT NULL DEFAULT 0,
|
||||
DbMs INT NOT NULL DEFAULT 0,
|
||||
AppMs INT NOT NULL DEFAULT 0,
|
||||
QueryCount INT NOT NULL DEFAULT 0,
|
||||
ResponseBytes INT NOT NULL DEFAULT 0,
|
||||
BusinessID INT NOT NULL DEFAULT 0,
|
||||
UserID INT NOT NULL DEFAULT 0,
|
||||
LoggedAt DATETIME NOT NULL,
|
||||
INDEX idx_loggedat (LoggedAt),
|
||||
INDEX idx_endpoint (Endpoint)
|
||||
) ENGINE=InnoDB
|
||||
", {}, { datasource: "payfrit" });
|
||||
application._perfTableChecked = true;
|
||||
} catch (any e) {}
|
||||
}
|
||||
|
||||
var batch = [];
|
||||
|
||||
lock name="payfrit_perfBuffer" timeout="2" type="exclusive" {
|
||||
if (structKeyExists(application, "perfBuffer")) {
|
||||
batch = duplicate(application.perfBuffer);
|
||||
application.perfBuffer = [];
|
||||
}
|
||||
}
|
||||
|
||||
if (arrayLen(batch) == 0) return;
|
||||
|
||||
try {
|
||||
|
||||
var sql = "INSERT INTO ApiPerfLogs (Endpoint, TotalMs, DbMs, AppMs, QueryCount, ResponseBytes, BusinessID, UserID, LoggedAt) VALUES ";
|
||||
var rows = [];
|
||||
|
||||
for (var m in batch) {
|
||||
arrayAppend(rows,
|
||||
"('" & replace(m.endpoint, "'", "''", "all") & "',"
|
||||
& val(m.totalMs) & "," & val(m.dbMs) & "," & val(m.appMs) & ","
|
||||
& val(m.queryCount) & "," & val(m.responseBytes) & ","
|
||||
& val(m.businessId) & "," & val(m.userId) & ",'"
|
||||
& m.loggedAt & "')"
|
||||
);
|
||||
}
|
||||
|
||||
sql &= arrayToList(rows, ",");
|
||||
queryExecute(sql, {}, { datasource: "payfrit" });
|
||||
|
||||
// Cleanup old data (1% chance per flush)
|
||||
if (randRange(1, 100) == 1) {
|
||||
queryExecute(
|
||||
"DELETE FROM ApiPerfLogs WHERE LoggedAt < DATE_SUB(NOW(), INTERVAL 30 DAY)",
|
||||
{}, { datasource: "payfrit" }
|
||||
);
|
||||
}
|
||||
} catch (any e) {
|
||||
// Silent fail - never break the app for profiling
|
||||
}
|
||||
}
|
||||
|
||||
/**
|
||||
* Log performance metrics for the current request.
|
||||
* Called automatically from apiAbort().
|
||||
*/
|
||||
function logPerf(numeric responseBytes = 0) {
|
||||
if (!structKeyExists(application, "perfEnabled") || !application.perfEnabled) return;
|
||||
if (!structKeyExists(request, "_perf_start")) return;
|
||||
|
||||
// Safety valve: don't let buffer grow unbounded if flush is failing
|
||||
if (structKeyExists(application, "perfBuffer") && arrayLen(application.perfBuffer) > 1000) return;
|
||||
|
||||
var totalMs = getTickCount() - request._perf_start;
|
||||
var dbMs = structKeyExists(request, "_perf_queryTimeMs") ? request._perf_queryTimeMs : 0;
|
||||
|
||||
var metric = {
|
||||
endpoint: structKeyExists(request, "_api_path") ? request._api_path : "unknown",
|
||||
totalMs: totalMs,
|
||||
dbMs: dbMs,
|
||||
appMs: totalMs - dbMs,
|
||||
queryCount: structKeyExists(request, "_perf_queryCount") ? request._perf_queryCount : 0,
|
||||
responseBytes: arguments.responseBytes,
|
||||
businessId: structKeyExists(request, "BusinessID") ? val(request.BusinessID) : 0,
|
||||
userId: structKeyExists(request, "UserID") ? val(request.UserID) : 0,
|
||||
loggedAt: dateTimeFormat(now(), "yyyy-mm-dd HH:nn:ss")
|
||||
};
|
||||
|
||||
var shouldFlush = false;
|
||||
|
||||
lock name="payfrit_perfBuffer" timeout="1" type="exclusive" {
|
||||
arrayAppend(application.perfBuffer, metric);
|
||||
if (arrayLen(application.perfBuffer) >= 100) {
|
||||
shouldFlush = true;
|
||||
}
|
||||
}
|
||||
|
||||
if (shouldFlush) {
|
||||
thread name="perfFlush_#createUUID()#" {
|
||||
flushPerfBuffer();
|
||||
}
|
||||
}
|
||||
}
|
||||
|
||||
// Store in application scope
|
||||
application.isDevEnvironment = isDevEnvironment;
|
||||
application.isDev = isDev;
|
||||
application.logDebug = logDebug;
|
||||
application.apiError = apiError;
|
||||
application.queryTimed = queryTimed;
|
||||
application.logPerf = logPerf;
|
||||
application.flushPerfBuffer = flushPerfBuffer;
|
||||
</cfscript>
|
||||
|
|
|
|||
|
|
@ -474,5 +474,6 @@ try {
|
|||
response["DETAIL"] = e.detail ?: "";
|
||||
}
|
||||
|
||||
try{logPerf(0);}catch(any e){}
|
||||
writeOutput(serializeJSON(response));
|
||||
</cfscript>
|
||||
|
|
|
|||
|
|
@ -16,11 +16,6 @@
|
|||
|
||||
response = { "OK": false };
|
||||
|
||||
function apiAbort(payload) {
|
||||
writeOutput(serializeJSON(payload));
|
||||
abort;
|
||||
}
|
||||
|
||||
try {
|
||||
requestBody = toString(getHttpRequestData().content);
|
||||
requestData = {};
|
||||
|
|
@ -250,5 +245,6 @@ try {
|
|||
|
||||
}
|
||||
|
||||
try{logPerf(0);}catch(any e){}
|
||||
writeOutput(serializeJSON(response));
|
||||
</cfscript>
|
||||
|
|
|
|||
|
|
@ -7,11 +7,6 @@
|
|||
<cftry>
|
||||
<cfset headersDir = expandPath("/uploads/headers")>
|
||||
<cfscript>
|
||||
function apiAbort(payload) {
|
||||
writeOutput(serializeJSON(payload));
|
||||
abort;
|
||||
}
|
||||
|
||||
// Get BusinessID from form, request scope, or header
|
||||
bizId = 0;
|
||||
if (structKeyExists(form, "BusinessID") && isNumeric(form.BusinessID) && form.BusinessID GT 0) {
|
||||
|
|
|
|||
|
|
@ -6,11 +6,6 @@
|
|||
<cftry>
|
||||
<cfset itemsDir = expandPath("/uploads/items")>
|
||||
<cfscript>
|
||||
function apiAbort(payload) {
|
||||
writeOutput(serializeJSON(payload));
|
||||
abort;
|
||||
}
|
||||
|
||||
// Get ItemID from form
|
||||
itemId = 0;
|
||||
if (structKeyExists(form, "ItemID") && isNumeric(form.ItemID) && form.ItemID GT 0) {
|
||||
|
|
|
|||
|
|
@ -156,6 +156,7 @@ try {
|
|||
});
|
||||
}
|
||||
|
||||
try{logPerf(0);}catch(any e){}
|
||||
writeOutput(serializeJSON({
|
||||
"OK": true,
|
||||
"ORDERS": orders,
|
||||
|
|
|
|||
|
|
@ -94,5 +94,6 @@ try {
|
|||
response["ERROR"] = e.message;
|
||||
}
|
||||
|
||||
try{logPerf(0);}catch(any e){}
|
||||
writeOutput(serializeJSON(response));
|
||||
</cfscript>
|
||||
|
|
|
|||
|
|
@ -81,6 +81,7 @@ try {
|
|||
});
|
||||
}
|
||||
|
||||
try{logPerf(0);}catch(any e){}
|
||||
writeOutput(serializeJSON({
|
||||
"OK": true,
|
||||
"TEAM": team,
|
||||
|
|
|
|||
|
|
@ -5,11 +5,6 @@
|
|||
<cfheader name="Cache-Control" value="no-store">
|
||||
|
||||
<cfscript>
|
||||
function apiAbort(payload) {
|
||||
writeOutput(serializeJSON(payload));
|
||||
abort;
|
||||
}
|
||||
|
||||
// Read JSON body once
|
||||
data = {};
|
||||
try {
|
||||
|
|
|
|||
Reference in a new issue