Recording Logs - 🌲 Sonamu

Learn how to record data during test execution using Naite.t().

Naite.t() Overview

Simple API

Two parametersIntuitive usage

Automatic Tracking

Automatic callstack collectionCall path identification

Any Type

All values allowedFlexible logging

Test-Only

NODE_ENV checkNo production impact

What is Naite.t()?

Naite.t() is a function that records data at specific points during test execution. It takes a unique key as the first argument and the value to record as the second argument.

import { Naite } from "sonamu";

// Basic usage
Naite.t("user:create", { userId: 123, username: "john" });

Data recorded this way:

Can be queried at any time during test execution with Naite.get()
Transmitted in real-time to VSCode Extension
Stored with callstack and time information

Basic Usage

Simple Logging

The most basic usage is recording function inputs and outputs.

test("user creation flow", async () => {
  const userModel = new UserModel();

  // Record input data
  const input = {
    username: "john",
    email: "john@example.com",
  };
  Naite.t("user:create:input", input);

  // Create user
  const { user } = await userModel.create(input);

  // Record output data
  Naite.t("user:create:output", {
    userId: user.id,
    username: user.username,
  });
});

test("post update", async () => {
  const postModel = new PostModel();

  Naite.t("post:update:before", {
    id: 1,
    title: "Old Title",
  });

  await postModel.update(1, { title: "New Title" });

  Naite.t("post:update:after", {
    id: 1,
    title: "New Title",
  });
});

Input/Output Pattern: Using :input/:output or :before/:after patterns helps clearly track data transformation processes.

Step-by-Step Logging

Track the flow of complex processes by logging step by step.

test("full order processing flow", async () => {
  const orderId = 123;

  // Step 1: Order validation
  Naite.t("order:validate:start", { orderId });
  await validateOrder(orderId);
  Naite.t("order:validate:done", { valid: true });

  // Step 2: Inventory check
  Naite.t("order:inventory:check", { orderId });
  const available = await checkInventory(orderId);
  Naite.t("order:inventory:result", { available });

  // Step 3: Payment processing
  Naite.t("order:payment:start", { orderId });
  await processPayment(orderId);
  Naite.t("order:payment:done", { transactionId: "tx_123" });

  // Step 4: Start shipping
  Naite.t("order:shipping:start", { orderId });
  await startShipping(orderId);
  Naite.t("order:shipping:done", { trackingNumber: "TRK_001" });
});

Benefits:

Clearly identify which step failed
Measure time spent at each step
Filter specific steps with wildcard patterns (order:payment:*)

start/done Pattern: Recording the start and completion of each operation with :start/:done makes it easier to calculate elapsed time or verify completion status later.

Understanding Internal Behavior

1. Environment Check

Naite.t() first checks the execution environment.

t(name: string, value: any) {
  // Immediately return if not in test environment
  if (process.env.NODE_ENV !== "test") {
    return;
  }
  // ...
}

Reasons:

Safe even if Naite.t() exists in production code
Test-only feature
No runtime overhead

You don’t need to remove Naite.t() calls before production deployment. It’s automatically controlled by environment variables.

2. Context Check

Naite uses Sonamu’s Context system.

try {
  const context = Sonamu.getContext();
  const store = context?.naiteStore;

  if (!store) {
    return; // Ignore if no Context
  }
  // ...
} catch {
  // No Context situation
}

Role of Context:

Provides independent naiteStore for each test
Ensures test isolation
Maintains Context in async operations with AsyncLocalStorage

Context Creation Process

// bootstrap.ts
function getMockContext(): Context {
  return {
    ip: "127.0.0.1",
    session: {},
    user: null,
    naiteStore: Naite.createStore(), // Create new Map
    // ...
  };
}

// New Context for each test() execution
export const test = async (title, fn, options) => {
  return vitestTest(title, options, async (context) => {
    await runWithMockContext(async () => {
      // Naite.t() can be called here
      await fn(context);
    });
  });
};

3. Callstack Collection

Automatically collects the callstack at the time of Naite.t() call.

// Callstack collection
const stack = extractCallStack();

function extractCallStack(): StackFrame[] {
  const stack = new Error().stack;

  // Exclude "Error", "extractCallStack", "Naite.t"
  const frames = stack.split("\n")
    .slice(3)
    .map(parseStackFrame)
    .filter(frame => frame !== null);

  // Stop when runWithContext is found
  const contextIndex = frames.findIndex(
    f => f.functionName?.includes("runWithContext")
  );

  return contextIndex >= 0
    ? frames.slice(0, contextIndex + 1)
    : frames;
}

Collected Information:

Function name (createUser)
File path (/Users/.../user.model.ts)
Line number (123)

Callstack Example

async function createUser() {
  Naite.t("user:create", { username: "john" });
}

test("create user", async () => {
  await createUser();
});

// Collected callstack:
// [
//   {
//     functionName: "createUser",
//     filePath: "/Users/.../user.model.ts",
//     lineNumber: 15
//   },
//   {
//     functionName: "test",
//     filePath: "/Users/.../user.model.test.ts",
//     lineNumber: 42
//   },
//   {
//     functionName: "runWithMockContext",
//     filePath: "/Users/.../bootstrap.ts",
//     lineNumber: 58
//   }
// ]

4. Trace Creation and Storage

Creates a NaiteTrace object with collected information and stores it in the Store.

const trace: NaiteTrace = {
  key: name,
  data: value,
  stack: stack,
  at: new Date(),
};

// Add to Store (always managed as array)
const existing = store.get(name) ?? [];
store.set(name, [...existing, trace]);

Reason for Array Management:

Same key can be called multiple times
Track in chronological order
Support for loop operation logging

Single Call
Multiple Calls

Naite.t("user:create", { userId: 1 });

// Store:
// "user:create" => [{ key, data: { userId: 1 }, ... }]

Naite.t("user:create", { userId: 1 });
Naite.t("user:create", { userId: 2 });
Naite.t("user:create", { userId: 3 });

// Store:
// "user:create" => [
//   { key, data: { userId: 1 }, ... },
//   { key, data: { userId: 2 }, ... },
//   { key, data: { userId: 3 }, ... }
// ]

Key Naming Strategy

Hierarchical Structure

Separating hierarchies with colons (:) makes it easy to query later with wildcard patterns.

Correct Way
Wrong Way

// ✅ Hierarchical structure
Naite.t("user:create", { /* ... */ });
Naite.t("user:update", { /* ... */ });
Naite.t("user:delete", { /* ... */ });

Naite.t("syncer:renderTemplate", { /* ... */ });
Naite.t("syncer:writeFile", { /* ... */ });

// Easy query with wildcards
Naite.get("user:*").result();         // All user related
Naite.get("syncer:*").result();       // All syncer related
Naite.get("*:create").result();       // All create operations

// ❌ Flat structure
Naite.t("userCreate", { /* ... */ });
Naite.t("userUpdate", { /* ... */ });
Naite.t("syncerRender", { /* ... */ });

// Can't use wildcards
// "user*" won't match

Recommended Patterns

module:function

The most basic pattern.

Naite.t("user:create", { /* ... */ });
Naite.t("post:update", { /* ... */ });
Naite.t("syncer:render", { /* ... */ });

module:function:action

Use when more detailed tracking is needed.

Naite.t("user:create:input", { /* ... */ });
Naite.t("user:create:validation", { /* ... */ });
Naite.t("user:create:db", { /* ... */ });
Naite.t("user:create:done", { /* ... */ });

module:function:action:detail

Use for very complex flows.

Naite.t("order:payment:card:charge:start", { /* ... */ });
Naite.t("order:payment:card:charge:done", { /* ... */ });
Naite.t("order:payment:bank:transfer:start", { /* ... */ });
Naite.t("order:payment:bank:transfer:done", { /* ... */ });

Too deep hierarchies (5+ levels) actually reduce readability. In most cases, 3 levels are sufficient.

Practical Patterns

1. Conditional Tracking

Clearly track business logic branches.

async function processPayment(order: Order) {
  Naite.t("payment:start", {
    orderId: order.id,
    method: order.payment_method
  });

  if (order.payment_method === "card") {
    Naite.t("payment:card:selected", { cardNumber: "****1234" });
    await chargeCard(order);
    Naite.t("payment:card:success", { transactionId: "tx_123" });
  } else if (order.payment_method === "bank") {
    Naite.t("payment:bank:selected", { bankCode: "001" });
    await transferBank(order);
    Naite.t("payment:bank:success", { transferId: "tf_456" });
  }

  Naite.t("payment:done", { orderId: order.id });
}

test("card payment", async () => {
  const order = { id: 1, payment_method: "card" };
  await processPayment(order);

  // Verify card payment path was executed
  const cardLogs = Naite.get("payment:card:*").result();
  expect(cardLogs.length).toBeGreaterThan(0);

  // Bank transfer was not executed
  const bankLogs = Naite.get("payment:bank:*").result();
  expect(bankLogs).toHaveLength(0);
});

Usage:

A/B testing path verification
Permission branch verification
Error handling path tracking

2. Error Tracking

Record detailed information when errors occur.

async function createUser(data: UserCreateInput) {
  Naite.t("user:create:input", data);

  try {
    // Validation
    await validateUser(data);
    Naite.t("user:create:validation:pass", {});

    // DB save
    const user = await db.insert("users").values(data);
    Naite.t("user:create:success", { userId: user.id });

    return user;
  } catch (error) {
    // Record error details
    Naite.t("user:create:error", {
      errorType: error.constructor.name,
      errorMessage: error.message,
      errorCode: error.code,
      inputData: data,
      stack: error.stack,
    });
    throw error;
  }
}

test("invalid input handling", async () => {
  try {
    await createUser({ username: "" }); // Empty value
    throw new Error("Should have failed");
  } catch (error) {
    // Check error log
    const errorLog = Naite.get("user:create:error").first();

    expect(errorLog).toBeDefined();
    expect(errorLog.errorType).toBe("ValidationError");
    expect(errorLog.errorMessage).toContain("username");

    // Verify validation was not passed
    const validationPass = Naite.get("user:create:validation:pass").result();
    expect(validationPass).toHaveLength(0);
  }
});

Error Tracking Pattern: Calling Naite.t() in the catch block allows you to capture all context at the time of error. Combined with callstack storage, debugging becomes much easier.

3. Performance Measurement

Record time information to identify bottlenecks.

test("data processing performance", async () => {
  Naite.t("process:start", { timestamp: Date.now() });

  // Step 1: Data fetch
  Naite.t("process:fetch:start", { timestamp: Date.now() });
  const data = await fetchLargeData();
  Naite.t("process:fetch:done", {
    timestamp: Date.now(),
    dataSize: data.length
  });

  // Step 2: Data processing
  Naite.t("process:transform:start", { timestamp: Date.now() });
  const processed = await transformData(data);
  Naite.t("process:transform:done", {
    timestamp: Date.now(),
    processedCount: processed.length
  });

  // Step 3: DB save
  Naite.t("process:save:start", { timestamp: Date.now() });
  await saveToDatabase(processed);
  Naite.t("process:save:done", { timestamp: Date.now() });

  Naite.t("process:end", { timestamp: Date.now() });

  // Calculate time for each step
  const logs = Naite.get("process:*").result();
  const start = logs.find(l => l.timestamp).timestamp;
  const fetchDone = logs.find(l => l.timestamp && l.dataSize).timestamp;
  const transformDone = logs.find(l => l.timestamp && l.processedCount).timestamp;
  const saveDone = logs[logs.length - 2].timestamp;

  console.log(`Fetch: ${fetchDone - start}ms`);
  console.log(`Transform: ${transformDone - fetchDone}ms`);
  console.log(`Save: ${saveDone - transformDone}ms`);
});

4. Loop Operation Tracking

For loops or batch operations, record only summary information.

Bad Example
Good Example
Conditional Logging

// ❌ Logging inside loop
for (let i = 0; i < 10000; i++) {
  Naite.t("loop:iteration", { i, value: data[i] });
  // Creates 10,000 traces!
}

// ✅ Only summary information
Naite.t("loop:start", {
  count: 10000,
  timestamp: Date.now()
});

for (let i = 0; i < 10000; i++) {
  // No logging
  processItem(data[i]);
}

Naite.t("loop:done", {
  count: 10000,
  duration: Date.now() - startTime,
  successCount: results.filter(r => r.success).length
});

// ✅ Only when there's a problem
for (let i = 0; i < 10000; i++) {
  const result = processItem(data[i]);

  if (!result.success) {
    Naite.t("loop:error", {
      index: i,
      error: result.error
    });
  }
}

Value Types and Serialization

Any Type Allowed

Naite.t() accepts any type, allowing all JavaScript values to be recorded.

// ✅ All types possible
Naite.t("key", "string");
Naite.t("key", 123);
Naite.t("key", true);
Naite.t("key", { nested: { object: true } });
Naite.t("key", [1, 2, 3]);
Naite.t("key", new Date());
Naite.t("key", null);
Naite.t("key", undefined);

Design Reasons:

Ease of use prioritized over TypeScript type safety
No interruption from type errors while writing tests
Same philosophy as expect()

Serialization Warning

JSON serialization is required to transmit to VSCode Extension. Non-serializable values will show a warning.

Recommended
Warning

// ✅ Serializable
Naite.t("key", { data: "value" });
Naite.t("key", [1, 2, 3]);
Naite.t("key", "string");
Naite.t("key", 123);
Naite.t("key", true);

// ⚠️ Non-serializable (warning displayed)
Naite.t("key", functionValue);      // Function
Naite.t("key", symbolValue);        // Symbol
Naite.t("key", circularRef);        // Circular reference
Naite.t("key", new WeakMap());      // WeakMap

Serialization Warning Message

╔════════════════════════════════════════════════════════════════╗
║  [Naite] Non-serializable value detected!                      ║
╠════════════════════════════════════════════════════════════════╣
║  Key: user:create                                               ║
║  Reason: Cannot serialize function                              ║
║  Location: /Users/.../user.model.test.ts                        ║
║  Line: 15                                                       ║
╠════════════════════════════════════════════════════════════════╣
║  Naite.t() accepts any type of value. However, values will     ║
║  be serialized to JSON when exported via Naite.getAllTraces(). ║
╚════════════════════════════════════════════════════════════════╝

Tests run normally even with warnings. However, you won’t be able to see those values in VSCode Extension.

Performance Considerations

1. Test Environment Only

if (process.env.NODE_ENV !== "test") {
  return; // Immediate return, no cost
}

Even if Naite.t() exists in production code, there’s no performance impact.

2. Avoid Excessive Logging

Calling Naite.t() inside loops creates thousands of traces, causing:

Increased memory usage
Slower test speed
Slower VSCode Extension

Recommendations:

Record only loop start/end
Record only when problems occur
Use summary information

3. Conditional Logging

Enable detailed logging only when debugging is needed.

const DEBUG = process.env.DEBUG_NAITE === "true";

function processItem(item: any) {
  if (DEBUG) {
    Naite.t("process:detail", item);
  }

  // Processing logic
}

// Usage:
// DEBUG_NAITE=true pnpm test

Best Practices

Use Clear Keys

// ✅ Correct way
Naite.t("user:create:input", { username: "john" });
Naite.t("user:create:validation", { valid: true });
Naite.t("user:create:db", { query: "INSERT..." });

// ❌ Wrong way
Naite.t("data1", { username: "john" });
Naite.t("data2", { valid: true });
Naite.t("data3", { query: "INSERT..." });

Consistent Structure

// ✅ Correct way: Consistent hierarchy
Naite.t("user:create", { /* ... */ });
Naite.t("user:update", { /* ... */ });
Naite.t("user:delete", { /* ... */ });

Naite.t("post:create", { /* ... */ });
Naite.t("post:update", { /* ... */ });
Naite.t("post:delete", { /* ... */ });

Minimal Information

// ✅ Correct way: Only necessary information
Naite.t("user:create", {
  userId: user.id,
  username: user.username,
});

// ❌ Wrong way: Including unnecessary information
Naite.t("user:create", {
  ...user,              // All fields
  ...request,           // Entire Request
  ...context,           // Entire Context
});

Log at Meaningful Locations

// ✅ Correct way: At important branch points
async function processUser(user: User) {
  Naite.t("user:process:start", { userId: user.id });

  if (user.isAdmin) {
    Naite.t("user:process:admin", { userId: user.id });
    await processAdmin(user);
  } else {
    Naite.t("user:process:regular", { userId: user.id });
    await processRegular(user);
  }

  Naite.t("user:process:done", { userId: user.id });
}

Cautions

Cautions when using Naite.t():

Test-only: Only works when NODE_ENV === "test".
Context required: Sonamu.getContext() must exist. Only use within bootstrap’s runWithMockContext().
Serializable values recommended: Serializable values are recommended for VSCode Extension transmission.
No excessive logging: Calling inside loops degrades performance.
Key convention: The module:function:action format is recommended.

Next Steps

Querying Logs

Learn how to query recorded logs with Naite.get().

Naite Viewer

Learn how to visualize logs with VSCode Extension.

Debugging Tests

Learn how to find bugs with callstack tracking.

What is Naite?

Return to Naite overview.

​Naite.t() Overview

Simple API

Automatic Tracking

Any Type

Test-Only

​What is Naite.t()?

​Basic Usage

​Simple Logging

​Step-by-Step Logging

​Understanding Internal Behavior

​1. Environment Check

​2. Context Check

​3. Callstack Collection

​4. Trace Creation and Storage

​Key Naming Strategy

​Hierarchical Structure

​Recommended Patterns

​Practical Patterns

​1. Conditional Tracking

​2. Error Tracking

​3. Performance Measurement

​4. Loop Operation Tracking

​Value Types and Serialization

​Any Type Allowed

​Serialization Warning

​Performance Considerations

​1. Test Environment Only

​2. Avoid Excessive Logging

​3. Conditional Logging

​Best Practices

​Cautions

​Next Steps

Querying Logs

Naite Viewer

Debugging Tests

What is Naite?

Naite.t() Overview

What is Naite.t()?

Basic Usage

Simple Logging

Step-by-Step Logging

Understanding Internal Behavior

1. Environment Check

2. Context Check

3. Callstack Collection

4. Trace Creation and Storage

Key Naming Strategy

Hierarchical Structure

Recommended Patterns

Practical Patterns

1. Conditional Tracking

2. Error Tracking

3. Performance Measurement

4. Loop Operation Tracking

Value Types and Serialization

Any Type Allowed

Serialization Warning

Performance Considerations

1. Test Environment Only

2. Avoid Excessive Logging

3. Conditional Logging

Best Practices

Cautions

Next Steps