耗时日志不准的根本原因是未覆盖所有请求终点，必须将开始时间存入context并在HTTPErrorHandler中读取计算，才能100%捕获包括404、panic恢复、自定义错误处理在内的全部请求生命周期。

直接在中间件里用 time.Since() 算耗时并打日志，会漏掉 404、panic 恢复后、自定义错误处理器接管的请求 —— 这类请求根本不会走到你写的日志中间件末端。

为什么中间件里的耗时日志总是不准

看似简单：中间件开头 start := time.Now()，结尾 duration := time.Since(start)，再 log.Printf() —— 但真实请求生命周期比这复杂得多。

• 路由未匹配（比如访问 /nonexistent）时，中间件链根本不会执行，HTTPErrorHandler 才是兜底入口
• handler panic 后被 echo.MiddlewareFunc(recover) 捕获，但你的日志中间件早已退出，无法记录这次失败耗时
• 如果你设置了自定义 e.HTTPErrorHandler（例如统一返回 JSON 错误），它才是请求真正结束的位置，而中间件此时已不可达

必须把开始时间存进 c，并在 HTTPErrorHandler 中读取

只有 HTTPErrorHandler 能 100% 覆盖所有请求终点。要让它能拿到耗时，就得提前把开始时间塞进 c 上下文，并确保它不被后续中间件覆盖或丢弃。

Skill Weave Chains — 技能链路由引擎

开箱即用的技能链路由引擎。13 条预定义链覆盖搜索、开发、审查、MLOps、法律、创意等场景，三层路由架构（触发词→SAD反馈→DAG编排），recall@10=96.97%。配置驱动（chains.yaml），零代码扩展。pip install skill-weave-chains 一键安装。

下载

• 注册一个前置中间件，在 next(c) 前调用 c.Set("startTime", time.Now())
• 重写 e.HTTPErrorHandler，先从 c.Get("startTime") 取值，再调用原始 handler（避免破坏 panic 恢复逻辑）
• 示例片段：

  e.Use(func(next echo.Handler) echo.Handler {
      return echo.HandlerFunc(func(c echo.Context) error {
          c.Set("startTime", time.Now())
          return next.ServeHTTP(c)
      })
  })
  
  oldHandler := e.HTTPErrorHandler
  e.HTTPErrorHandler = func(err error, c echo.Context) {
      if start, ok := c.Get("startTime").(time.Time); ok {
          dur := time.Since(start)
          log.Printf("method=%s path=%s status=%d dur=%.3fms",
              c.Request().Method,
              normalizePath(c), // 见下节
              c.Response().Status,
              dur.Seconds()*1000,
          )
      }
      oldHandler(err, c)
  }

路径归一化是避免 Prometheus label 爆炸的关键

直接用 c.Request().URL.Path 打日志或上报指标，会导致 /user/123、/user/456 被当成不同路径，label 组合爆炸 —— Prometheus 查询变慢、内存飙升、甚至 OOM。

• 必须对 path 做正则归一化：把数字、UUID、ID 类动态段替换为占位符，例如 /user/:id、/order/:oid/status
• 禁用任何带查询参数、Header、RemoteAddr 的字段作为日志维度；只保留 method、归一化 path、status
• 简单归一化函数示例（用 echo.Route 更可靠，但需确保路由已注册）：

  func normalizePath(c echo.Context) string {
      r := c.Route()
      if r != nil {
          return r.Path
      }
      // fallback：手动正则（慎用）
      re := regexp.MustCompile(`/\d+`)
      return re.ReplaceAllString(c.Request().URL.Path, "/:id")
  }

真正难的不是写中间件，而是理解 Echo 请求生命周期里哪些钩子能 100% 覆盖所有出口 —— HTTPErrorHandler 是唯一答案，其余都是幻觉。归一化路径也常被跳过，等 Prometheus 报警了才回头改，那时 label 已经污染指标存储数天了。