feat(calltree): show where a slow callers search spent its time

- The panel's engine label was a prediction; it now shows what the
  response actually used and how long it took, with the breakdown on
  hover: index call, file resolution with file count, rg scan, raw hit
  count, and the server's build stamp
- A slow corporate machine cannot be reproduced remotely, so one click
  there becomes the measurement: a large index number points at the
  process-spawn path (EDR scans each attempt; the transport probing is
  known to cost seconds), a large resolve number at storage, a scan
  number at the rg fallback, and the build stamp settles whether the
  fix being tested is even running
- The binary now knows its own commit via the VCS info go build embeds,
  shown at startup and in the response header; two rounds of "still
  slow" reports have already turned out to be a stale binary

Author: Taka-S-dev

README.md

@@ -105,7 +105,7 @@ static 変数・関数呼び出しはテキストパターンに基づくヒュ
 - `callers` / `callees` タブで方向を切り替え（タブを戻っても展開状態を保持）
 - ノードをクリックして実装箇所へジャンプ（プロトタイプ宣言ではなく定義本体を優先）。`▶` で再帰的に展開
 - Esc で検索欄をクリア（もう一度 Esc でパネルを閉じる）
-- GNU Global が利用可能な場合、Callers は `global -xr` による構文解析ベースの参照検索を使用（ripgrep より誤検知が少ない）。使用中エンジンをパネル内に表示
+- GNU Global が利用可能な場合、Callers は `global -xr` による構文解析ベースの参照検索を使用（ripgrep より誤検知が少ない）。検索のたびに、実際に使ったエンジンと所要時間をパネルに表示し、ホバーで内訳（索引の呼び出し / ファイル解決 / rg 走査・読んだファイル数・サーバのビルド版）が見える——遅い環境で「どこが遅いか」をその場で切り分けるための計測
 - 関数ポインタのテーブルで登録される関数（メソッドテーブル・ops 構造体）は、登録行が「ファイル名:行」のノードで出ます。囲む関数が無い参照は以前は捨てて ripgrep の全木走査へ降格していましたが、登録箇所こそが「誰が呼ぶのか」への答えなので、索引の結果をそのまま返します（実測: openssl の `ssl3_read_bytes` で 1.85 秒 → 0.05 秒）
 
 #### ジャンプマップ

api/handlers_analysis.go

@@ -731,6 +731,7 @@ func (h *Handler) handleCallers(w http.ResponseWriter, r *http.Request) {
 	} else if !filepath.IsAbs(dir) {
 		dir = filepath.Join(hroot, dir)
 	}
+	timing := &search.RefTiming{}
 	hits, engine, truncated, err := search.FindRefSites(r.Context(), search.RefQuery{
 		Word:        word,
 		Root:        hroot,
@@ -740,7 +741,8 @@ func (h *Handler) handleCallers(w http.ResponseWriter, r *http.Request) {
 		NoIndex:     q.Get("gtags") == "0",
 		// 呼び出し元は「これで全部か」を見る一覧なので上限は高く取り、
 		// 触れたときは X-Truncated で伝える
-		Limit: 1000,
+		Limit:  1000,
+		Timing: timing,
 	})
 	if err != nil {
 		jsonErr(w, err.Error(), http.StatusInternalServerError)
@@ -752,6 +754,12 @@ func (h *Handler) handleCallers(w http.ResponseWriter, r *http.Request) {
 	// 呼び出し元が上限で切られたかを伝える。黙って切ると「これで全部」と誤解される。
 	// gtags は全件返すので、打ち切りが起きるのは rg 経路だけ。
 	w.Header().Set("X-Engine", engine)
+	// どこで時間を使ったかを応答に載せる。遅い環境（EDR 入りの社用機・
+	// ネットワークドライブ）は手元で再現できないので、現地の1クリックが
+	// そのまま計測になる形にしておく。
+	w.Header().Set("X-Timing", fmt.Sprintf("index=%dms resolve=%dms scan=%dms raw=%d files=%d",
+		timing.IndexMS, timing.ResolveMS, timing.ScanMS, timing.RawHits, timing.FilesRead))
+	w.Header().Set("X-Build", headerSafe(BuildStamp()))
 	if truncated {
 		w.Header().Set("X-Truncated", "true")
 	}

api/version.go

@@ -0,0 +1,44 @@
+package api
+
+import (
+	"runtime/debug"
+	"sync"
+)
+
+var (
+	buildOnce  sync.Once
+	buildStamp string
+)
+
+// BuildStamp はこのバイナリのコミットとビルド時刻。「動いているのは直した版か」
+// が現地で分からないと、修正済みの症状を古いバイナリで再報告する往復が起きる
+// （実際に2回起きた）。go build が埋める VCS 情報なので、ソース側の更新は不要。
+func BuildStamp() string {
+	buildOnce.Do(func() {
+		buildStamp = "unknown"
+		bi, ok := debug.ReadBuildInfo()
+		if !ok {
+			return
+		}
+		rev, at, dirty := "", "", ""
+		for _, s := range bi.Settings {
+			switch s.Key {
+			case "vcs.revision":
+				rev = s.Value
+				if len(rev) > 9 {
+					rev = rev[:9]
+				}
+			case "vcs.time":
+				at = s.Value
+			case "vcs.modified":
+				if s.Value == "true" {
+					dirty = "+dirty"
+				}
+			}
+		}
+		if rev != "" {
+			buildStamp = rev + dirty + " " + at
+		}
+	})
+	return buildStamp
+}

main.go

@@ -14,6 +14,7 @@ import (
 	"strings"
 	"time"
 
+	"grepnavi/api"
 	"grepnavi/desktop"
 	"grepnavi/proc"
 )
@@ -125,7 +126,7 @@ func main() {
 
 	srv := newServer(absRoot, rootExplicit, *graphFile, graphExplicit, addr, *debug, *mcp, *tray)
 
-	slog.Info("grepnavi started", "root", absRoot, "graph", *graphFile)
+	slog.Info("grepnavi started", "root", absRoot, "graph", *graphFile, "build", api.BuildStamp())
 	if *mcp {
 		slog.Warn("--mcp enabled: non-browser (Origin-less) API access is allowed")
 	}

search/refsites.go

@@ -6,6 +6,7 @@ import (
 	"regexp"
 	"strconv"
 	"strings"
+	"time"
 )
 
 // RefQuery は「word はどこで使われているか」の問い合わせ。
@@ -32,6 +33,19 @@ type RefQuery struct {
 	AssignOnly bool
 	// NoIndex は索引を使わず ripgrep だけで引く（利用者が明示的に指定したとき）。
 	NoIndex bool
+	// Timing を渡すと、どの段階に時間を使ったかを書き込む。遅い環境
+	// （EDR 入りの社用機・ネットワークドライブ等）は手元で再現できないので、
+	// 現地の1クリックで原因を切り分けられる数字を応答に載せるためにある。
+	Timing *RefTiming
+}
+
+// RefTiming は参照検索1回の内訳。
+type RefTiming struct {
+	IndexMS   int64 // global の呼び出し（初回はプロセス起動経路の検出込み）
+	ResolveMS int64 // ファイルを読んで囲む関数を解決した時間
+	ScanMS    int64 // ripgrep 降格時の全木走査
+	RawHits   int   // 索引が返した生ヒット数
+	FilesRead int   // 解決で開いたファイル数
 }
 
 // FindRefSites は索引で引き、答えられなければ ripgrep に落ちる。
@@ -44,7 +58,12 @@ func FindRefSites(ctx context.Context, q RefQuery) ([]CallSite, string, bool, er
 		q.Scope = q.Root
 	}
 	if !q.NoIndex && GtagsAvailable(q.Root) {
+		t0 := time.Now()
 		hits, err := gtagsRawRefs(ctx, q.Word, q.Root)
+		if q.Timing != nil {
+			q.Timing.IndexMS = time.Since(t0).Milliseconds()
+			q.Timing.RawHits = len(hits)
+		}
 		if err == nil && len(hits) > 0 {
 			// 絞り込みと上限は解決の前に掛ける。解決はヒットのあるファイルを
 			// 読む処理なので、後ろに置くと索引が返した全件ぶん働いてしまう。
@@ -67,17 +86,25 @@ func FindRefSites(ctx context.Context, q RefQuery) ([]CallSite, string, bool, er
 				hits, cut = hits[:budget], true
 			}
 			var sites []CallSite
+			t1 := time.Now()
 			if q.CallersOnly {
 				// 解決（ファイル読み + 関数範囲の走査）が一覧の主コスト。
 				// 全ヒットを解決してから上限で切ると、上限の 20 倍を先に
 				// 払うことになる（実測: linux の kfree で 3.9s、畳みながら
 				// 止めれば参照一覧と同等まで落ちる）。
 				var full bool
-				sites, full = resolveCallerSites(hits, q.Word, q.Limit)
+				var files int
+				sites, full, files = resolveCallerSites(hits, q.Word, q.Limit)
 				cut = cut || full
+				if q.Timing != nil {
+					q.Timing.FilesRead = files
+				}
 			} else {
 				sites = ResolveRefSites(hits, q.Word)
 			}
+			if q.Timing != nil {
+				q.Timing.ResolveMS = time.Since(t1).Milliseconds()
+			}
 			MarkIndirectCalls(sites, q.Word)
 			MarkAssignments(sites, q.Word)
 
@@ -95,12 +122,19 @@ func FindRefSites(ctx context.Context, q RefQuery) ([]CallSite, string, bool, er
 	// 呼び出し元の形に整えると 0 件」は降格しない — 索引の参照は全量なので、
 	// rg の再走査が足せるのは索引対象外ファイルの分だけで、実測ではそこに
 	// 生成 HTML の誤パースが混ざった。0 件は「呼び出し元なし」という答え。
+	t2 := time.Now()
 	if q.CallersOnly {
 		sites, truncated, err := FindCallers(ctx, q.Word, q.Scope, q.Glob)
+		if q.Timing != nil {
+			q.Timing.ScanMS = time.Since(t2).Milliseconds()
+		}
 		return sites, "rg", truncated, err
 	}
 	sites, truncated, err := rgRefSites(ctx, q.Word, q.Scope, q.Glob, q.Limit,
 		parseRefFilter(q.Filter), q.AssignOnly)
+	if q.Timing != nil {
+		q.Timing.ScanMS = time.Since(t2).Milliseconds()
+	}
 	return sites, "rg", truncated, err
 }
 
@@ -178,15 +212,17 @@ func callerKey(s *CallSite, word string, reDecl *regexp.Regexp) (string, bool) {
 // そろった時点で止める。第2戻り値は「生ヒットを使い切る前に止めた」。
 // 解決はファイル読み + コメント除去 + 関数範囲の走査で、一覧の主コストなので、
 // 使わない解決はやらない。
-func resolveCallerSites(hits []DefHit, word string, limit int) ([]CallSite, bool) {
+// 第3戻り値は開いたファイル数（遅い環境の切り分け用: 解決が遅いのか、
+// ファイルが多いのか、1ファイルが重いのかを分ける材料になる）。
+func resolveCallerSites(hits []DefHit, word string, limit int) ([]CallSite, bool, int) {
 	reDecl := callerDeclPattern(word)
 	code := codeOnlyCache{}
 	seen := map[string]bool{}
 	var out []CallSite
 	for i, h := range hits {
 		if len(out) >= limit {
 			_ = hits[i] // まだ残っている = 打ち切り
-			return out, true
+			return out, true, len(code)
 		}
 		lines, err := CachedLines(h.File)
 		if err != nil {
@@ -206,7 +242,7 @@ func resolveCallerSites(hits []DefHit, word string, limit int) ([]CallSite, bool
 		seen[key] = true
 		out = append(out, s)
 	}
-	return out, false
+	return out, false, len(code)
 }
 
 // refTerm は絞り込み条件1つぶん。

static/addons/call-tree/addon.js

@@ -149,6 +149,45 @@ document.addEventListener('DOMContentLoaded', () => {
   });
 });
 
+// 応答の実測をラベルへ。予測（gtagsAvailable）だけだと、rg へ降格した・
+// 索引呼び出しに何秒かかった、が現地で見えず「遅い」以上の報告ができない。
+// EDR 入りの社用機やネットワークドライブは手元で再現できないので、
+// 1クリックがそのまま計測になるようにしておく。
+// 生の内訳（index=..ms resolve=..ms）を読ませるのではなく、比較と判定は
+// こちらでやって日本語の一文にする。数字はその下に残す（報告用）。
+function ctTimingVerdict(eng, totalMs, t) {
+  const ms = (k) => parseInt((t.match(new RegExp(k + '=([0-9]+)')) || [])[1] || '0', 10);
+  const index = ms('index'), resolve = ms('resolve'), scan = ms('scan'), files = ms('files');
+  if (totalMs < 1500) return 'この検索は遅くありません';
+  if (eng !== 'gtags') {
+    return 'この語は索引で答えられず、rg でツリー全体を走査しました (' + scan + 'ms)。' +
+      '毎回こうなるなら、索引が無い・古い・プロジェクトルート直下に無い、のどれかです';
+  }
+  if (index > 1000 && index >= resolve * 2) {
+    return '時間の大半は global の呼び出しです (' + index + 'ms)。プロセス起動が遅い環境' +
+      '（ウイルス対策/EDR がプロセスを検査している）の典型です。2回目も遅いままか見てください';
+  }
+  if (resolve > 1000) {
+    return '時間の大半はファイル読みです (' + resolve + 'ms / ' + files + ' ファイル)。' +
+      '遅いディスクかネットワークドライブ上のプロジェクトが典型です';
+  }
+  return 'サーバ側はどの段階も速いのに合計が遅い場合、通信か描画側です';
+}
+
+function ctShowTiming(res, totalMs) {
+  const label = document.getElementById('ct-engine-label');
+  if (!label || !res) return;
+  const eng = res.headers.get('X-Engine');
+  if (!eng) return;
+  const name = eng === 'gtags' ? 'GNU Global' : 'ripgrep';
+  const sec = (totalMs / 1000).toFixed(totalMs >= 9500 ? 0 : 1);
+  label.textContent = `${name} · ${sec}s`;
+  const t = res.headers.get('X-Timing') || '';
+  label.title = ctTimingVerdict(eng, totalMs, t) +
+    String.fromCharCode(10) + String.fromCharCode(10) + t +
+    String.fromCharCode(10) + 'build: ' + (res.headers.get('X-Build') || '?');
+}
+
 function updateCtEngineLabel(mode) {
   const label = document.getElementById('ct-engine-label');
   if (!label) return;
@@ -234,7 +273,9 @@ async function ctSearch() {
       // 見る一覧なので、別のパネルの設定で黙って件数が減るほうが危ない
       const params = new URLSearchParams({ word });
       if (!useGtags) params.set('gtags', '0');
+      const t0 = performance.now();
       const res = await fetch('/api/callers?' + params, { signal });
+      ctShowTiming(res, performance.now() - t0);
       if (!res.ok) { body.innerHTML = '<div class="ct-empty">エラー</div>'; return; }
       const hits = await res.json();
 
@@ -512,7 +553,9 @@ async function ctToggle(node, el) {
   if (_ctMode === 'callers') {
     const params = new URLSearchParams({ word: node.func });
     if (typeof gtagsAvailable === 'function' && !gtagsAvailable()) params.set('gtags', '0');
+    const t0 = performance.now();
     const res = await fetch('/api/callers?' + params).catch(() => null);
+    ctShowTiming(res, performance.now() - t0);
     if (res && res.ok) {
       const hits = await res.json();
       node.truncated = res.headers.get('X-Truncated') === 'true';