feat(obs): make observability.access_log turn the access log off

config.example.yaml

@@ -173,6 +173,10 @@ admin:
 observability:
   service_name: "aisix"
   log_level: "info"
+  # One access-log line ("proxy request completed") per request, written at
+  # `info`, so the effective log filter (`RUST_LOG` when set, else `log_level`)
+  # must allow `info` for it to appear. false turns the access log off whatever
+  # the filter; every other log line is unaffected.
   access_log: true
   metrics:
     # Complete label lists per metric. Omitted metrics retain their defaults.

config.managed.yaml

@@ -169,6 +169,10 @@ admin:
 observability:
   service_name: "aisix"
   log_level: "info"
+  # One access-log line ("proxy request completed") per request, written at
+  # `info`, so the effective log filter (`RUST_LOG` when set, else `log_level`)
+  # must allow `info` for it to appear. false turns the access log off whatever
+  # the filter; every other log line is unaffected.
   access_log: true
   metrics:
     # Complete label lists per metric. Omitted metrics retain their defaults.

crates/aisix-core/src/config.rs

@@ -1188,6 +1188,8 @@ pub struct ObservabilityConfig {
     pub service_name: String,
     #[serde(default = "ObservabilityConfig::default_log_level")]
     pub log_level: String,
+    /// Write one access-log line per request. Off, no access-log line is
+    /// written whatever the log level; every other log line is unaffected.
     #[serde(default = "ObservabilityConfig::default_access_log")]
     pub access_log: bool,
     pub metrics: MetricsConfig,

crates/aisix-obs/src/access_log.rs

@@ -87,8 +87,19 @@
 //!   last byte out. On a non-streamed request the two coincide; on a
 //!   streamed one they differ by the whole length of the stream.
 
+use std::sync::atomic::{AtomicBool, Ordering};
 use std::time::Duration;
 
+/// `observability.access_log`, installed once by [`crate::init_tracing`].
+/// Checked where every access-log line is written rather than expressed
+/// as a filter directive, so no `RUST_LOG` spelling can bring the lines
+/// back and no other event is affected.
+static ENABLED: AtomicBool = AtomicBool::new(true);
+
+pub(crate) fn set_enabled(enabled: bool) {
+    ENABLED.store(enabled, Ordering::Relaxed);
+}
+
 /// Canonical access-log fields, passed to [`log_access`].
 ///
 /// Constructed at the point a request's outcome becomes known — which is not
@@ -291,15 +302,17 @@ pub struct McpAccessLog<'a> {
 }
 
 impl AccessLog<'_> {
-    /// Emit a single `tracing::info!` event carrying every field. The
-    /// subscriber's configured format (text or JSON) determines the
-    /// wire shape — operators choose via `cfg.observability.log_level`
-    /// and (later) a JSON/text knob.
+    /// Emit a single `tracing::info!` event carrying every field, unless
+    /// `observability.access_log` is off. When on, the line is filtered by
+    /// the log level like any other `info` event.
     pub fn emit(&self) {
         self.emit_with(None);
     }
 
     fn emit_with(&self, semantic: Option<&SemanticAccessLog>) {
+        if !ENABLED.load(Ordering::Relaxed) {
+            return;
+        }
         let mcp = self.mcp.as_ref();
         tracing::info!(
             method = self.method,

crates/aisix-obs/src/lib.rs

@@ -135,6 +135,7 @@ pub fn init_tracing(cfg: &ObservabilityConfig) -> Result<(), ObsError> {
         return Err(ObsError::AlreadyInitialised);
     }
     let _ = LOG_WRITER.set(writer);
+    access_log::set_enabled(cfg.access_log);
 
     tracing::info!(
         service = %cfg.service_name,

tests/e2e/src/cases/access-log-switch-e2e.test.ts

@@ -0,0 +1,176 @@
+import { createHash } from "node:crypto";
+import { afterAll, beforeAll, describe, expect, test } from "vitest";
+import {
+  EtcdClient,
+  ProxyClient,
+  SeedClient,
+  spawnApp,
+  startOpenAiUpstream,
+  waitConfigPropagation,
+  waitForLogLine,
+  type OpenAiUpstream,
+  type SpawnedApp,
+} from "../harness/index.js";
+
+// E2E: `observability.access_log` is the switch for the access log.
+// Off, a gateway logging at `info` writes no access-log line for any
+// request — buffered, streamed, or refused before a handler — while its
+// other `info` lines, including the ones those same requests produce,
+// still appear. Left at its default, the same requests each write one.
+
+const ACCESS_LINE = "proxy request completed";
+const CALLER_PLAINTEXT = "sk-access-log-switch-caller";
+const CALLER_KEY_HASH = createHash("sha256").update(CALLER_PLAINTEXT).digest("hex");
+const MODEL = "access-log-switch-e2e";
+const STREAM_MODEL = "access-log-switch-stream-e2e";
+
+const CHAT_COMPLETION = {
+  id: "chatcmpl-access-log-switch",
+  object: "chat.completion",
+  model: "gpt-4o-mini",
+  choices: [{ index: 0, message: { role: "assistant", content: "hi" }, finish_reason: "stop" }],
+  usage: { prompt_tokens: 3, completion_tokens: 1, total_tokens: 4 },
+};
+const STREAM_EVENTS = [
+  JSON.stringify({
+    id: "chatcmpl-access-log-switch",
+    object: "chat.completion.chunk",
+    model: "gpt-4o-mini",
+    choices: [{ index: 0, delta: { content: "hi" }, finish_reason: null }],
+  }),
+  JSON.stringify({
+    id: "chatcmpl-access-log-switch",
+    object: "chat.completion.chunk",
+    model: "gpt-4o-mini",
+    choices: [{ index: 0, delta: {}, finish_reason: "stop" }],
+    usage: { prompt_tokens: 3, completion_tokens: 1, total_tokens: 4 },
+  }),
+  "[DONE]",
+];
+
+interface Sent {
+  buffered: string;
+  streamed: string;
+  refused: string;
+}
+
+async function chat(app: SpawnedApp, body: string): Promise<{ status: number; requestId: string }> {
+  const res = await fetch(`${app.proxyUrl}/v1/chat/completions`, {
+    method: "POST",
+    headers: { authorization: `Bearer ${CALLER_PLAINTEXT}`, "content-type": "application/json" },
+    body,
+  });
+  await res.text();
+  return { status: res.status, requestId: res.headers.get("x-aisix-request-id") ?? "" };
+}
+
+/** Drive one request of each kind and return their request ids. */
+async function drive(app: SpawnedApp): Promise<Sent> {
+  const messages = [{ role: "user", content: "hello" }];
+  const buffered = await chat(app, JSON.stringify({ model: MODEL, messages }));
+  expect(buffered.status).toBe(200);
+  const streamed = await chat(app, JSON.stringify({ model: STREAM_MODEL, stream: true, messages }));
+  expect(streamed.status).toBe(200);
+  // Refused before dispatch: its line is written by a different path.
+  const refused = await chat(app, "{not json");
+  expect(refused.status).toBe(400);
+  for (const id of [buffered.requestId, streamed.requestId, refused.requestId]) {
+    expect(id, "every response carries x-aisix-request-id").toBeTruthy();
+  }
+  return { buffered: buffered.requestId, streamed: streamed.requestId, refused: refused.requestId };
+}
+
+describe("observability.access_log switches the access log", () => {
+  const upstreams: OpenAiUpstream[] = [];
+  let off: SpawnedApp | undefined;
+  let on: SpawnedApp | undefined;
+  let etcdReachable = false;
+
+  beforeAll(async () => {
+    const etcd = new EtcdClient();
+    etcdReachable = await etcd.ping();
+    if (!etcdReachable) return;
+
+    const buffered = await startOpenAiUpstream({ nonStreamBody: CHAT_COMPLETION });
+    const streamed = await startOpenAiUpstream({ streamEvents: STREAM_EVENTS });
+    upstreams.push(buffered, streamed);
+    off = await spawnApp({ logLevel: "info", accessLog: false });
+    on = await spawnApp({ logLevel: "info" });
+
+    for (const app of [off, on]) {
+      const seed = new SeedClient(etcd, app.etcdPrefix);
+      for (const [name, upstream] of [
+        [MODEL, buffered],
+        [STREAM_MODEL, streamed],
+      ] as const) {
+        const pk = await seed.createProviderKey({
+          display_name: `${name}-pk`,
+          secret: "sk-mock",
+          api_base: `${upstream.baseUrl}/v1`,
+        });
+        await seed.createModel({
+          display_name: name,
+          provider: "openai",
+          model_name: "gpt-4o-mini",
+          provider_key_id: pk.id,
+        });
+      }
+      await seed.createApiKey({ key_hash: CALLER_KEY_HASH, allowed_models: [MODEL, STREAM_MODEL] });
+      const probe = new ProxyClient(app.proxyUrl, CALLER_PLAINTEXT);
+      await waitConfigPropagation(async () => (await probe.listModels()).status === 200);
+    }
+  });
+
+  afterAll(async () => {
+    await off?.exit();
+    await on?.exit();
+    for (const u of upstreams) await u.close();
+  });
+
+  test("access_log: false writes no access-log line, and every other line still appears", async (ctx) => {
+    if (!etcdReachable || !off) {
+      ctx.skip();
+      return;
+    }
+    const sent = await drive(off);
+
+    // Stopping the gateway is the barrier: it drains its log queue before
+    // exiting, so every line these requests could have written is ahead of
+    // the shutdown line.
+    await off.stop();
+    await waitForLogLine(off, (l) => l.includes("aisix shut down cleanly"), "the shutdown line");
+    const lines = off.output().split("\n");
+
+    expect(lines.filter((l) => l.includes(ACCESS_LINE))).toEqual([]);
+    // Application `info` lines are unaffected — the boot line, and the
+    // per-attempt lines the same requests wrote.
+    expect(lines.some((l) => l.includes("tracing initialised"))).toBe(true);
+    for (const id of [sent.buffered, sent.streamed]) {
+      expect(
+        lines.some((l) => l.includes("provider call completed") && l.includes(`request_id="${id}"`)),
+        `the provider-call line for ${id}`,
+      ).toBe(true);
+    }
+  });
+
+  test("by default each request writes its access-log line", async (ctx) => {
+    if (!etcdReachable || !on) {
+      ctx.skip();
+      return;
+    }
+    const sent = await drive(on);
+    const app = on;
+    for (const [id, status] of [
+      [sent.buffered, 200],
+      [sent.streamed, 200],
+      [sent.refused, 400],
+    ] as const) {
+      const line = await waitForLogLine(
+        app,
+        (l) => l.includes(ACCESS_LINE) && l.includes(`request_id="${id}"`),
+        `the access-log line for ${id}`,
+      );
+      expect(line).toContain(`status=${status}`);
+    }
+  });
+});

tests/e2e/src/cases/body-edges-e2e.test.ts

@@ -242,10 +242,6 @@ describe("body edges e2e: multi-turn, oversize body, empty messages", () => {
     // emitted BY the handlers. That left an operator with nothing to
     // look at: a caller reporting a 413 the gateway had no record of is
     // indistinguishable from the request never arriving.
-    //
-    // (`observability.access_log` in the harness config is the reserved
-    // field nothing reads today — the access log is gated by the log
-    // level alone, which is why this suite raises it to `info`.)
     const filler = "x".repeat(10 * 1024 * 1024 + 512 * 1024);
     const res = await fetch(`${app.proxyUrl}/v1/chat/completions`, {
       method: "POST",

tests/e2e/src/cases/listener-tls-e2e.test.ts

@@ -91,7 +91,6 @@ describe("listener TLS (#473)", () => {
       observability: {
         service_name: "aisix-e2e-tls",
         log_level: "warn",
-        access_log: false,
         // Explicit free port so concurrent test files never collide on
         // the default 0.0.0.0:9090 metrics listener.
         metrics: {

tests/e2e/src/cases/status-config-e2e.test.ts

@@ -567,7 +567,6 @@ async function spawnPointedAtDeadEtcd(): Promise<MinimalApp> {
     observability: {
       service_name: "aisix-status-nl",
       log_level: "warn",
-      access_log: false,
       metrics: {
         prometheus: { enabled: true, path: "/metrics", addr: `127.0.0.1:${metricsPort}` },
         // Retired blocks, kept here on purpose: they were placeholders no

tests/e2e/src/harness/app.ts

@@ -115,6 +115,11 @@ export interface AppOverrides {
    * debugging with `RUST_LOG=error` can't turn a test's subject off.
    */
   logLevel?: string;
+  /**
+   * `observability.access_log`. Defaults to `true`, the binary's own
+   * default; only a spec whose subject is the switch turns it off.
+   */
+  accessLog?: boolean;
   /**
    * `observability.metrics.client_type_rules` (AISIX-Cloud#1045): operator
    * UA→client_type regex rules, tried before the built-in allowlist.
@@ -434,7 +439,7 @@ async function spawnAppOnce(overrides: AppOverrides = {}): Promise<SpawnedApp> {
     observability: {
       service_name: "aisix-e2e",
       log_level: overrides.logLevel ?? "warn",
-      access_log: false,
+      access_log: overrides.accessLog ?? true,
       metrics: {
         prometheus: {
           enabled: prometheusEnabled,