5a3be3af33b76d69d1fc98ee76b9a37f96e96fc7
max
  Wed Aug 26 00:36:52 2026 -0700
Add opt-in per-phase request timing to the new hgBlat and hgSession pages, shown in a dialog with &measureTiming=1. refs #38157

New reusable perfTimer collector (lib/perfTimer.c) records labeled wall-clock intervals via clock1000() and emits them as JSON; hgBlat and hgSession attach a timing array to their payload when the existing measureTiming cart/CGI var is set. A shared gbShowTimingDialog helper in utils.js renders the server phases plus a client render-time row in a house-style modal, which opens automatically when measureTiming is on. Confirms the position band/locus annotation loop dominates hgSession, and run-BLAT plus locus lookups dominate hgBlat.

diff --git src/hg/hgBlat/hgBlat.c src/hg/hgBlat/hgBlat.c
index 591e2aae91b..e1a8620644d 100644
--- src/hg/hgBlat/hgBlat.c
+++ src/hg/hgBlat/hgBlat.c
@@ -34,33 +34,36 @@
 #include "errCatch.h"
 #include "portable.h"
 #include "portable.h"
 #include "dystring.h"
 #include "chromInfo.h"
 #include "net.h"
 #include "fuzzyFind.h"
 #include "chromAlias.h"
 #include "subText.h"
 #include "jsHelper.h"
 #include "obscure.h"
 #include "jsonWrite.h"
 #include "bigBed.h"
 #include "bigPsl.h"
 #include "blatShare.h"
+#include "perfTimer.h"
 
 struct cart *cart;	/* The user's ui state. */
 struct hash *oldVars = NULL;
+struct perfTimer *hgBlatTiming = NULL;	/* Non-NULL when &measureTiming is set; times the request
+					 * and is emitted as hgBlatData.timing for the JS dialog. */
 boolean orgChange = FALSE;
 boolean dbChange = FALSE;
 boolean allGenomes = FALSE;
 boolean allResults = FALSE;
 boolean autoRearr = FALSE;
 static long enteredMainTime = 0;
 
 
 boolean autoBigPsl = FALSE;  // DEFAULT VALUE change to TRUE in future
 
 /* for earlyBotCheck() function at the beginning of main() */
 #define delayFraction   0.5    /* standard penalty is 1.0 for most CGIs */
                                 /* this one is 0.5 */
 static boolean issueBotWarning = FALSE;
 
@@ -779,35 +782,40 @@
                 int n = chopByChar(dupe, '|', words, ArraySize(words));
                 int i;
                 for (i = 0; i < n; ++i)
                     jsonWriteString(jw, NULL, words[i]);
                 freeMem(dupe);
                 jsonWriteListEnd(jw);
                 }
             }
         sqlFreeResult(&sr);
         }
     jsonWriteObjectEnd(jw);
     freeMem(inTabUrl);
     freeMem(newTabUrl);
     }
 jsonWriteListEnd(jw);    // hits
+/* When &measureTiming is set, hand the per-phase timings to hgBlat.js (it shows them in a
+ * dialog).  This step covers building the results JSON, including the per-hit locusName lookups. */
+perfTimerStep(hgBlatTiming, "assemble results JSON + locus lookups");
+perfTimerJson(hgBlatTiming, jw, "timing");
 jsonWriteObjectEnd(jw);  // root
 
 printf("<div id='blatResults' class='gbApp'></div>\n");
 jsInlineF("var hgBlatData = %s;\n", jw->dy->string);
 jsonWriteFree(&jw);
+perfTimerFree(&hgBlatTiming);
 }
 
 static void printBlatBannerStyle()
 /* Emit the .blatBanner rule for the classic, C-rendered pages.  Those don't load hgBlat.js, which
  * is where the new pages get this class from, so define the same thing here; keep the values in
  * sync with the .blatBanner rule in hgBlat.js.  Only the first call emits anything, so a page may
  * carry more than one banner without repeating the stylesheet. */
 {
 static boolean styleDone = FALSE;
 if (styleDone)
     return;
 styleDone = TRUE;
 printf("<style>"
        ".blatBanner{background:#fbf3e2;border:1px solid #d9bd82;padding:10px 14px;margin:12px 0 20px;"
        "font-size:14px;color:#1e2833}"
@@ -2071,30 +2079,32 @@
             serve->stepSize = atoi(buf+strlen("stepSize "));
 	    }
 	if (startsWith("minMatch ", buf))
 	    {
             serve->minMatch = atoi(buf+strlen("minMatch "));
 	    }
         }
     }
 gfEndRequest(conn);
 return(ret); 
 }
 
 void blatSeq(char *userSeq, char *organism, char *database, int dbCount)
 /* Blat sequence user pasted in. */
 {
+if (isNotEmpty(cartOptionalString(cart, "measureTiming")))
+    hgBlatTiming = perfTimerNew();   /* times the request; emitted as hgBlatData.timing */
 FILE *f;
 struct dnaSeq *seqList = NULL, *seq;
 struct tempName pslTn, faTn;
 int maxSingleSize, maxTotalSize, maxSeqCount;
 char *genome, *db;
 char *type = cgiString("type");
 char *seqLetters = cloneString(userSeq);
 struct serverTable *serve;
 struct gfConnection *conn = NULL;
 int oneSize, totalSize = 0, seqCount = 0;
 boolean isTx = FALSE;
 boolean isTxTx = FALSE;
 boolean txTxBoth = FALSE;
 struct gfOutput *gvo;
 boolean qIsProt = FALSE;
@@ -2291,30 +2301,32 @@
     minMatchShown = findMinMatch(genomeSize, qType == gftProt);
     #endif
     if (allResults)
 	minMatchShown = 0;
 
     conn = gfConnect(serve->host, serve->port, trackHubDatabaseToGenome(serve->db), serve->genomeDataDir);
 
     // read tileSize stepSize minMatch from server status
     findGenomeParams(conn, serve);
 
     int minLucky = (serve->minMatch * serve->stepSize + (serve->tileSize - serve->stepSize)) * xlat;
 
     minSuggested = max(minMatchShown,minLucky);
     }
 
+perfTimerStep(hgBlatTiming, "prepare query");
+
 int seqNumber = 0;
 /* Loop through each sequence. */
 for (seq = seqList; seq != NULL; seq = seq->next)
     {
     printf(" "); fflush(stdout);  /* prevent apache cgi timeout by outputting something */
     oneSize = realSeqSize(seq, !isTx);
     // Impose half the usual bot delay per sequence
     
     if (dbCount == 0 && issueBotWarning)
         {
         char *ip = getenv("REMOTE_ADDR");
         botDelayMessage(ip, botDelayMillis);
         }
 
     if (++seqCount > maxSeqCount)
@@ -2399,30 +2411,31 @@
 	    gfAlignStrand(conn, serve->nibDir, seq, FALSE, minMatchShown, tFileCache, gvo);
 	    }
 	reverseComplement(seq->dna, seq->size);
 	if (allGenomes)
 	    queryServer(serve->host, serve->port, db, seq, "query", xType, FALSE, FALSE, TRUE, seqNumber,
                         serve->genomeDataDir);
 	else
 	    {
 	    gfAlignStrand(conn, serve->nibDir, seq, TRUE, minMatchShown, tFileCache, gvo);
 	    }
 	}
     gfOutputQuery(gvo, f);
     ++seqNumber;
     }
 carefulClose(&f);
+perfTimerStep(hgBlatTiming, "run BLAT");
 
 if (!allGenomes)
     {
     /* Remember the trash result files so the Table view's "Old BLAT result page" link can
      * re-render the classic hyperlink view from them within this session without re-running BLAT
      * (see doOldPageReopen).  These are just short paths; the query sequence is not stored. */
     cartSetString(cart, "blatPslFile", pslTn.forCgi);
     cartSetString(cart, "blatFaFile", faTn.forCgi);
     /* Remember the db/organism the search actually ran against, so a later blatReopen renders with
      * the right assembly even if the cart's current db has since drifted (e.g. the user searched a
      * different assembly in between).  The trash PSLs carry this assembly's chrom names. */
     cartSetString(cart, "blatDb", serve->db);
     cartSetString(cart, "blatOrganism", organism);
     showAliPlaces(pslTn.forCgi, faTn.forCgi, NULL, serve->db, qType, tType,
               organism, feelingLucky);