基于自定义Babel插件与Loki实现CircleCI构建过程的深度性能剖析


我们团队的 monorepo 仓库,前端部分由超过四十个基于 Chakra UI 的 React 包构成。最近两个月,CircleCI 上的合并前检查(包括 lint、test 和 build)时间从可接受的15分钟悄然增长到了令人难以忍受的45分钟。流水线的日志输出成了一片混沌的文本海洋,npm run build 命令后面跟着几万行无从下手的输出。所有人都凭直觉猜测是 Babel 的转译过程拖慢了速度,但没有人能拿出证据。究竟是哪个 Babel 插件在“作恶”?是哪个 package 里的文件结构特别复杂?还是某个特定的 Chakra UI 组件用法触发了低效的转换路径?在真实项目中,这种“不知道为什么慢”的状态是技术债的温床。

传统的 console.time 调试方式在 CI 环境中几乎无效。它会产生大量杂乱的输出,淹没在已有日志中,且无法聚合分析。我们需要一种系统性的方法,将构建过程本身视为一个需要被观测的服务。这意味着,我们需要为构建过程引入结构化的、可查询的遥测数据。

初步的构想是,如果我们能精确测量 Babel 在处理每个文件时,其内部每个插件所花费的时间,并将这些数据以结构化日志的形式发送到一个中央日志系统,问题便迎刃而解。

技术选型决策很快就清晰了:

  1. 数据采集:自定义 Babel 插件。这是唯一能深入 Babel 内核,以非侵入性方式包裹(wrap)其他插件执行逻辑,并精确测量其耗时的手段。我们可以捕获到文件路径、插件别名、访问的 AST 节点类型以及精确到微秒的执行时间。
  2. 数据存储与查询:Grafana Loki。对于这种高容量、低基数、半结构化的日志数据,Loki 是最经济高效的选择。它只索引元数据(我们称之为标签,如 job_id, package_name, plugin_name),而不是日志全文,存储成本远低于 Elasticsearch。其查询语言 LogQL 也足够强大,可以对指标进行聚合与分析。
  3. 执行环境与数据上报:CircleCI。这是我们现有的 CI/CD 平台。我们需要设计一个健壮的机制,在 CircleCI 的 job 执行完毕后,将本地生成的性能日志文件可靠地推送至 Loki 服务。

Chakra UI 在这个场景中并非主动选择,而是“问题”的来源。它作为一个拥有大量组件、高度依赖主题上下文、并广泛使用 CSS-in-JS 方案(如 Emotion)的库,其代码在 Babel 转译过程中会触发大量插件的复杂操作,是检验我们这套观测体系有效性的绝佳样本。

步骤一:构建性能埋点Babel插件

核心思路不是编写一个新的代码转换插件,而是创建一个“元插件”,它的唯一职责是修改 Babel 的内部行为,以便测量其他插件的性能。具体来说,它会遍历 babel.config.js 中的所有插件,并用我们自己的计时逻辑去包裹它们原始的 visitor 对象。

这是 babel-plugin-build-profiler 的核心实现:

// babel-plugin-build-profiler.js

const fs = require('fs');
const path = require('path');

// 使用一个简单、高效的日志收集器,避免在主线程中进行频繁的IO操作
const logEntries = [];
let outputFilePath = path.join(process.cwd(), 'build-metrics.log');
let isProfilerEnabled = process.env.ENABLE_BUILD_PROFILER === 'true';

// 在进程退出时,将所有收集到的日志一次性写入文件
process.on('exit', () => {
  if (isProfilerEnabled && logEntries.length > 0) {
    try {
      fs.writeFileSync(outputFilePath, logEntries.join('\n'));
    } catch (err) {
      console.error('Failed to write build profiler logs:', err);
    }
  }
});

/**
 * 用计时逻辑包装原始的 visitor 函数
 * @param {Function} originalVisitor - 原始的 visitor 函数
 * @param {string} pluginAlias - 插件的别名
 * @param {string} visitorKey - visitor 的键名 (e.g., 'Program', 'JSXElement')
 * @returns {Function} - 被包装后的函数
 */
function wrapVisitor(originalVisitor, pluginAlias, visitorKey) {
  return function(...args) {
    const startTime = process.hrtime.bigint();
    // 执行原始的 visitor 逻辑
    originalVisitor.apply(this, args);
    const endTime = process.hrtime.bigint();
    const durationMs = Number(endTime - startTime) / 1e6;

    const state = args[0].hub.file.opts;
    const filePath = state.filename || 'unknown';

    // 仅记录耗时超过阈值的操作,避免日志泛滥。在生产中这是一个重要的优化。
    if (durationMs > 0.1) { // 阈值可以配置
      const logData = {
        ts: new Date().toISOString(),
        level: 'info',
        message: 'Babel Plugin Execution',
        // 关键的遥测数据
        duration_ms: durationMs,
        // 用于 Loki 索引的标签
        labels: {
          job_name: process.env.CIRCLE_JOB || 'local',
          build_num: process.env.CIRCLE_BUILD_NUM || 'local',
          package_name: path.relative(process.cwd(), filePath).split('/')[0],
          plugin_name: pluginAlias,
          visitor_key: visitorKey,
          file_path: filePath,
        }
      };
      logEntries.push(JSON.stringify(logData));
    }
  };
}

/**
 * 主插件逻辑
 * @param {import('@babel/core')} babel
 * @returns {import('@babel/core').PluginObj}
 */
module.exports = function(babel) {
  // 如果环境变量未设置,则插件不执行任何操作
  if (!isProfilerEnabled) {
    return {
      name: 'babel-plugin-build-profiler',
      visitor: {}, // 返回一个空的 visitor
    };
  }

  return {
    name: 'babel-plugin-build-profiler',
    // pre 在所有插件的 visitor 运行之前执行
    pre(state) {
      // 从 Babel 配置中获取所有已配置的插件
      const allPlugins = state.opts.plugins || [];

      for (const plugin of allPlugins) {
        // plugin.key 是插件的唯一标识
        if (!plugin.key || plugin.key === 'babel-plugin-build-profiler') {
          continue;
        }

        // plugin.visitor 是插件的核心逻辑所在
        const originalVisitor = plugin.visitor;
        if (!originalVisitor) {
          continue;
        }

        const newVisitor = {};
        // 遍历原始 visitor 的所有属性 (e.g., 'Program', 'FunctionDeclaration')
        for (const visitorKey in originalVisitor) {
          const visitorFn = originalVisitor[visitorKey];
          // 函数形式:{ Program(path, state) { ... } }
          if (typeof visitorFn === 'function') {
            newVisitor[visitorKey] = wrapVisitor(visitorFn, plugin.key, visitorKey);
          }

          // 对象形式:{ Identifier: { enter(path, state) { ... }, exit(...) } }
          else if (typeof visitorFn === 'object' && visitorFn !== null) {
            newVisitor[visitorKey] = {};
            if (typeof visitorFn.enter === 'function') {
              newVisitor[visitorKey].enter = wrapVisitor(visitorFn.enter, plugin.key, `${visitorKey}:enter`);
            }
            if (typeof visitorFn.exit === 'function') {
              newVisitor[visitorKey].exit = wrapVisitor(visitorFn.exit, plugin.key, `${visitorKey}:exit`);
            }
          }
        }
        // 用我们包装后的 visitor 替换掉原始的 visitor
        plugin.visitor = newVisitor;
      }
    },
    // visitor 字段必须存在,即使为空
    visitor: {},
  };
};

这个插件的设计有几个关键考量:

  1. 非侵入性:它通过 Babel 的 pre 钩子动态地修改了其他插件的配置,而不是要求我们去手动修改每一个插件的源代码。
  2. 性能开销process.hrtime.bigint() 是 Node.js 中用于高精度时间测量的标准方法,其开销极低。日志被缓存在内存中,通过 process.on('exit') 钩子一次性写入文件,最大限度地减少了对构建过程本身的 IO 干扰。
  3. 可控性:通过 ENABLE_BUILD_PROFILER 环境变量,我们可以轻松地在本地开发和 CI 环境中切换是否启用性能剖析,避免对日常开发造成影响。
  4. 数据格式:输出的是标准的 JSON Lines 格式,每一行都是一个独立的 JSON 对象,这对于 Loki 或任何日志处理系统都非常友好。JSON 内部我们特地设计了一个 labels 字段,这与 Loki 的数据模型完美契合。

步骤二:在项目中集成分析插件

首先,将这个插件文件保存在项目根目录的 scripts/babel/ 目录下。然后,我们需要修改 babel.config.js,让它在 CI 环境中被应用。一个常见的错误是直接将它加到 plugins 数组的末尾,但为了能测量到所有其他插件,它必须位于数组的最前面。

// babel.config.js

const isProfilerEnabled = process.env.ENABLE_BUILD_PROFILER === 'true';

const plugins = [
  // 基础插件
  '@babel/plugin-proposal-class-properties',
  '@babel/plugin-transform-runtime',
  // Emotion 是 Chakra UI 的底层依赖,这个插件在编译时做了很多工作
  '@emotion/babel-plugin', 
  // ... 其他十几个插件
];

if (isProfilerEnabled) {
  // 必须将分析插件放在最前面,以便它的 pre() 钩子能访问到后续所有插件
  plugins.unshift('./scripts/babel/babel-plugin-build-profiler.js');
}

module.exports = {
  presets: [
    '@babel/preset-env',
    ['@babel/preset-react', { runtime: 'automatic' }],
    '@babel/preset-typescript',
  ],
  plugins: plugins,
};

步骤三:从 CircleCI 上报日志到 Loki

现在,当我们在 CircleCI 中运行构建时,会在工作目录下生成一个 build-metrics.log 文件。下一步是把它发送到 Loki。在 CircleCI 的容器化环境中,安装一个完整的日志代理(如 Promtail)显得过于笨重。一个更务实的做法是使用一个简单的 shell 脚本,结合 curl 命令来完成。

#!/bin/bash
# scripts/ci/ship-loki-logs.sh

set -e # 如果任何命令失败,则立即退出

LOKI_URL="${LOKI_HOST}/loki/api/v1/push"
LOG_FILE="build-metrics.log"
BATCH_SIZE=500 # 每次请求发送的日志条数

if [ ! -f "$LOG_FILE" ]; then
  echo "Log file not found: $LOG_FILE. Skipping."
  exit 0
fi

# 从日志文件中提取标签,并构造 Loki API 需要的 payload
# 我们的日志格式是 { ..., "labels": { "key": "value" } }
jq -c '. | { "stream": .labels, "values": [ [ (now*1e9 | tostring), (. | tojson) ] ] }' "$LOG_FILE" | \
split -l "$BATCH_SIZE" - --filter="
  # --filter 允许我们对每个分割后的文件块执行一个命令
  # 这里我们用 curl 发送数据
  # -H 使用了 CircleCI 的环境变量来安全地传递认证信息
  # --fail 会在 HTTP 状态码 >= 400 时让 curl 失败,触发 set -e
  # --silent-on-error 避免在失败时打印 HTML 错误页面
  # || true 确保即使 Loki 推送失败,也不会导致整个 CI job 失败
  curl -s -f -u \"${LOKI_USER}:${LOKI_API_KEY}\" \
       -H \"Content-Type: application/json\" \
       --data-binary @- \"${LOKI_URL}\" || echo 'Loki push failed for a batch, continuing build.'
"

echo "Finished shipping build metrics to Loki."

这个脚本的精妙之处在于:

  1. 鲁棒性set -e 保证了脚本的健壮性。|| echo '...' 确保了即使 Loki 服务暂时不可用,日志上报的失败也不会中断整个 CI 流水线,这是在生产环境中至关重要的。
  2. 效率:它使用 jq 来将我们的日志格式转换成 Loki API 需要的格式,并利用 split--filter 组合实现了高效的批处理,避免了成千上万次的 curl 调用。
  3. 安全性:Loki 的认证信息通过 CircleCI 的上下文或项目环境变量(LOKI_USER, LOKI_API_KEY)注入,而不是硬编码在脚本里。

接下来,更新 CircleCI 的配置文件 .circleci/config.yml

# .circleci/config.yml

version: 2.1

jobs:
  build_and_test:
    docker:
      - image: cimg/node:16.18
    steps:
      - checkout
      - run:
          name: Install Dependencies
          command: npm install
      - run:
          name: Build Packages
          # 关键:在这里设置环境变量以启用我们的分析插件
          command: |
            export ENABLE_BUILD_PROFILER=true
            npm run build --workspaces --if-present
      - run:
          name: Ship Build Metrics to Loki
          # 仅在构建成功后执行
          command: ./scripts/ci/ship-loki-logs.sh
          when: on_success

workflows:
  main:
    jobs:
      - build_and_test:
          context:
            - org-secrets # 包含 LOKI_USER 和 LOKI_API_KEY

为了更清晰地展示整个流程,我们可以用 Mermaid 图来描述:

sequenceDiagram
    participant C as CircleCI Job
    participant B as Babel Build
    participant P as Profiler Plugin
    participant S as Shell Script
    participant L as Loki API

    C->>B: Executes `npm run build` with ENABLE_BUILD_PROFILER=true
    B->>P: Babel invokes plugins on each file
    loop For each plugin visitor
        P->>P: Records start time
        P->>B: Calls original visitor
        B-->>P: Original visitor finishes
        P->>P: Records end time, calculates duration
        P->>P: Appends JSON log to in-memory array
    end
    B-->>C: Build process finishes
    Note right of P: On process exit, flushes logs to build-metrics.log
    C->>S: Executes ship-loki-logs.sh
    S->>S: Reads and batches logs from build-metrics.log
    S->>L: POST /loki/api/v1/push with log batch
    L-->>S: 204 No Content (Success)
    S-->>C: Script finishes

步骤四:在 Loki 中挖掘性能瓶颈

当 CircleCI 作业运行几次后,Loki 中就积累了足够的数据。现在,我们可以通过 Grafana 的 Explore 界面,使用 LogQL 来回答我们最初提出的问题。

查询一:找出在特定构建中最耗时的 Babel 插件

这个查询将一个构建任务 (build_num="12345") 中所有日志条目的 duration_ms 相加,并按插件名称 (plugin_name) 分组。

sum by (plugin_name) (
  sum_over_time(
    {build_num="12345"} | json | unwrap duration_ms [1h]
  )
)

sum_over_time 将时间序列数据聚合,json 解析器解析日志行,unwrap 则将 JSON 字段 duration_ms 提取为一个指标。结果可能会让你大吃一惊,发现 @emotion/babel-plugin 占据了总构建时间的 60%。

查询二:定位转译最慢的前 10 个文件

topk(10,
  sum by (file_path) (
    sum_over_time(
      {build_num="12345"} | json | unwrap duration_ms [1h]
    )
  )
)

这个查询帮助我们识别出那些“坏苹果”文件。我们曾发现一个包含巨大 switch 语句和复杂 JSX 结构的老旧主题配置文件,其转译时间是其他文件的 50 倍以上。

查询三:比较某个插件在不同包中的性能表现

有时候,一个插件本身没有问题,但它在处理某些特定代码模式时会变得异常缓慢。这个查询可以帮助我们发现这种现象。

avg by (package_name) (
  sum_over_time(
    {plugin_name="@emotion/babel-plugin", job_name="build_and_test"} | json | unwrap duration_ms [24h]
  )
)

通过这个查询,我们定位到 @our-company/legacy-components 这个包在使用 Emotion 插件时,平均耗时是其他包的三倍。深入调查发现,该包内大量使用了嵌套的对象形式的样式定义,导致了 Emotion 插件的深度递归和性能下降。

有了这些数据,我们的优化工作从盲目的猜测变成了精确的外科手术。我们针对最慢的文件和最耗时的插件用法进行了重构。例如,将那个巨大的主题文件拆分,并将 legacy-components 中的样式定义扁平化。仅仅两周的定向优化,就将平均构建时间从45分钟缩短到了20分钟以内。

这个体系的建立,其价值远不止于一次性的性能优化。它为我们的前端构建流程提供了一套持久的可观测性系统。现在,任何导致构建时间显著增加的合并请求,都会在数据中留下清晰的印记,使得性能回归问题无所遁形。

局限性与未来展望

这套方案并非没有缺点。首先,我们的性能分析插件本身会带来一定的开销,根据我们的测量,大约在 5% 到 8% 之间。这是一个可以接受的权衡,尤其是在 CI 环境中。其次,它目前只覆盖了 Babel 的转译阶段,而一个完整的前端构建过程还包括 TypeScript 类型检查、Webpack/Vite 的模块打包、terser 的代码压缩等多个环节。

未来的迭代方向很明确。可以将类似的思想应用于 Webpack,通过编写一个自定义的 loader-runner 或者使用 tapable 钩子来收集每个 loader 的执行数据。更进一步,可以整合 TypeScript 的 --generateTrace 标志输出的性能追踪文件,将类型检查的耗时也纳入我们的观测范围。最终的目标是构建一个覆盖前端构建全链路的、统一的性能遥测平台,让每一次代码提交对构建性能的影响都清晰可见。


  目录