Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

chore: expose logging to actors #1602

Closed
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
86 changes: 86 additions & 0 deletions docs/src/content/docs/logging.mdx
Original file line number Diff line number Diff line change
@@ -0,0 +1,86 @@
# Logging

Actors provide a built-in way to log complex data to the console.

When dealing with lots of data, `console.log` often doesn't cut it. Using `this.log` allows you to log complex data using structured logging.

<Note>Using the actor logging API is completely optional.</Note>

## Log levels

There are 5 log levels:

| Level | Call | Description |
| -------- | -------------------------------------- | ---------------------------------------------------------------- |
| Critical | `this.log.critical(message, ...args);` | Severe errors that prevent core functionality |
| Error | `this.log.error(message, ...args);` | Errors that affect functionality but allow continued operation |
| Warning | `this.log.warn(message, ...args);` | Potentially harmful situations that should be addressed |
| Info | `this.log.info(message, ...args);` | General information about significant events & state changes |
| Debug | `this.log.debug(message, ...args);` | Detailed debugging information, usually used only in development |

## Structured logging

The built-in logging API (using `this.log`) provides structured logging to let you log key-value
pairs instead of raw strings. Structures logs are readable by both machines &
humans to make them easier to parse & search.

Passing an object to a log will print as structured data. For example:

```typescript
this.log.info('increment', { connection: rpc.connection.id, count });
// Prints: level=INFO msg=increment connection=123 count=456
```

The first parameter in each log method is the message. The rest of the arguments are used for structured logging.

## `this.log` vs `console.log` logging

`this.log` makes it easier to manage complex logs, while `console.log` can
become unmaintainable at scale.

Consider this example:

<CodeGroup>

```typescript {{ "title": "structured_logging.ts" }}
export default class Counter extends Actor<State> {
increment(rpc: Rpc<Counter>, count: number): number {
// Prints: level=INFO msg=increment connection=123 count=456
this.log.info('increment', { connection: rpc.connection.id, count });

this.state.count += count;
return this.state.count;
}

// ...etc...
}
```

```typescript {{ "title": "unstructured_logging.ts" }}
export default class Counter extends Actor<State> {
increment(rpc: Rpc<Counter>, count: number): number {
// Prints: Increment for connection 123 with count 456
console.log(`Increment for connection ${rpc.connection.id} with count ${count}`);

this.state.count += count;
return this.state.count;
}

// ...etc...
}
```

</CodeGroup>

If you need to search through a lot of logs, it's easier to read the structured logs. To find increments for a single connection, you can search `connection=123`.

Additionally, structured logs can be parsed and queried at scale using tools like Elasticsearch, Loki, or Datadog. For example, you can parse the log `level=INFO msg=increment connection=123 count=456` in to the JSON object `{"level":"INFO","msg":"increment","connection":123,"count":456}` and then query it as you would any other structured data.

## Configuring logging

The Rivet logging API is powered by the [@std/log](https://jsr.io/@std/log) package.

By default, logs are printed in [logfmt](https://brandur.org/logfmt) format for
a balance between machine & human readability. To configure the logging format
yourself, you can call the [`setup`](https://jsr.io/@std/log/doc/~/setup)
function in `_onStart`.
5 changes: 5 additions & 0 deletions docs/src/sitemap/mod.ts
Original file line number Diff line number Diff line change
Expand Up @@ -137,6 +137,11 @@ export const sitemap = [
title: 'Fault Tolerance',
href: '/docs/fault-tolerance',
icon: 'heart-pulse'
},
{
title: 'Logging',
href: '/docs/logging',
icon: 'list-ul'
}
// { title: 'DDoS & Botting Mitigation', href: '/docs', icon: 'shield-halved' },
]
Expand Down
13 changes: 9 additions & 4 deletions examples/counter/counter.ts
Original file line number Diff line number Diff line change
Expand Up @@ -13,29 +13,34 @@ interface ConnParams {
mod: number;
}

export default class Counter extends Actor<State, ConnParams | undefined, ConnState> {
export default class Counter extends Actor<
State,
ConnParams | undefined,
ConnState
> {
override _onInitialize(): State {
return { count: 0 };
}

override _onBeforeConnect(opts: OnBeforeConnectOpts<ConnParams>): ConnState {
console.log("parameters", opts.parameters);
this.log.info("parameters", { params: opts.parameters });
return { mod: opts.parameters?.mod ?? 1 };
}

override _onStateChange(newState: State): void | Promise<void> {
this._broadcast("broadcastCount", newState.count);

for (const conn of this.connections.values()) {
console.log("checking mod", conn.id, conn.state);
console.log("state", conn.state);
this.log.info("checking mod", { id: conn.id, state: conn.state });
this.log.info("state", { state: conn.state });
if (newState.count % conn.state.mod === 0) {
conn.send("directCount", newState.count);
}
}
}

increment(_rpc: Rpc<Counter>, count: number): number {
this.log.info("increment", { count });
this.state.count += count;
return this.state.count;
}
Expand Down
3 changes: 2 additions & 1 deletion sdks/actors/common/src/log.ts
Original file line number Diff line number Diff line change
Expand Up @@ -2,7 +2,7 @@ import * as log from "@std/log";
//import { getEnv as crossGetEnv } from "@cross/env";
import { LOGGER_NAME as CLIENT } from "../../client/src/log.ts";
import { LOGGER_NAME as MANAGER } from "../../manager/src/log.ts";
import { LOGGER_NAME as RUNTIME } from "../../runtime/src/log.ts";
import { LOGGER_NAME as RUNTIME, INSTANCE_LOGGER_NAME as INSTANCE } from "../../runtime/src/log.ts";
import { type LogEntry, stringify, castToLogValue } from "./logfmt.ts";

export function getLogger(name: string): log.Logger {
Expand All @@ -28,6 +28,7 @@ export function setupLogging() {
[CLIENT]: loggerConfig,
[MANAGER]: loggerConfig,
[RUNTIME]: loggerConfig,
[INSTANCE]: loggerConfig,
},
});
}
Expand Down
7 changes: 6 additions & 1 deletion sdks/actors/runtime/src/actor.ts
Original file line number Diff line number Diff line change
Expand Up @@ -13,8 +13,9 @@ import type * as wsToServer from "../../protocol/src/ws/to_server.ts";
import { type ActorConfig, mergeActorConfig } from "./config.ts";
import { Connection } from "./connection.ts";
import { Rpc } from "./rpc.ts";
import { logger } from "./log.ts";
import { instanceLogger, logger } from "./log.ts";
import { setupLogging } from "../../common/src/log.ts";
import type { Logger } from "@std/log/get-logger";

const KEYS = {
SCHEDULE: {
Expand Down Expand Up @@ -101,6 +102,10 @@ export abstract class Actor<
this.#config = mergeActorConfig(config);
}

protected get log(): Logger {
return instanceLogger();
}

protected get connections(): Set<Connection<this>> {
return this.#connections;
}
Expand Down
8 changes: 8 additions & 0 deletions sdks/actors/runtime/src/log.ts
Original file line number Diff line number Diff line change
@@ -1,7 +1,15 @@
import { getLogger } from "../../common/src/log.ts";

/** Logger for this library. */
export const LOGGER_NAME = "actors";

/** Logger used for logs from the actor instance itself. */
export const INSTANCE_LOGGER_NAME = "actors-instance";

export function logger() {
return getLogger(LOGGER_NAME);
}

export function instanceLogger() {
return getLogger(INSTANCE_LOGGER_NAME);
}