Add reducer name to database log records

[gefjon]

Description of Changes

Extends log records with a new field, function, which stores the name of the reducer being executed when the log was produced. I have chosen to name this field function rather than reducer because we will soon be adding procedures, which are not reducers but will also be valid values for this field.

While making this change, I noticed inconsistent values for injected logs. Previously, we injected logs in three places, with different values for the record fields:

1. SystemLogger (used when publishing and updating) set filename: Some("spacetimedb") and target: None.
2. log_reducer_error (used for reducer error returns) set filename: None and target: Some(reducer), with reducer being the name of the reducer.
3. ModuleHost::inject_logs (used for calls to nonexistent reducers and calls with ill-typed arguments) set filename: Some("external") and target: None.

With this change, I have decided that injected logs universally have filename: Some("__spacetimedb__") and target: Some("__spacetimedb__"). I have chosen the double-underscore convention for reserved names to avoid confusion should a user name a source file or reducer spacetimedb. I am not terribly attached to using spacetimedb here, and would be happy to change to some other string, like internal or system.

I have further decided that log_reducer_error and inject_logs both have access to a sensible non-None value for function and so should set it to the name of the reducer. The target field is not used for this. Note that in cases where a client attempts to call a non-existent reducer, the function field of the log record will be set to that client-supplied non-existent reducer name.

API and ABI breaking changes

Changes our log record format. This is at least backwards-compatible (as in, newer consumers can read older logs) because the new field is optional. I am unsure if it is forwards-compatible (as in, older consumers reading newer logs) because I don't know if serde_json will ignore unknown fields or will error.

Expected complexity level and risk

1

Testing

• Manually ran quickstart-chat (modified to log messages and name changes) and saw sensible output.

[gefjon]

Output from spacetime logs:

$ spacetime logs -s local quickstart-chat
    Finished `release` profile [optimized] target(s) in 0.15s
    Finished `release` profile [optimized] target(s) in 0.14s
     Running `/home/phoebe/clockworklabs/SpacetimeDB/target/x86_64-unknown-linux-gnu/release/spacetimedb-cli logs -s local quickstart-chat`
2025-09-23T14:40:18.218267Z  INFO: __spacetimedb__ __spacetimedb__: Creating table `message`
2025-09-23T14:40:18.218327Z  INFO: __spacetimedb__ __spacetimedb__: Creating table `user`
2025-09-23T14:40:18.218479Z  INFO: __spacetimedb__ __spacetimedb__: Invoking `init` reducer
2025-09-23T14:40:18.218567Z  INFO: __spacetimedb__ __spacetimedb__: Database initialized
2025-09-23T14:40:31.077171Z  INFO: set_name modules/quickstart-chat/src/lib.rs:30: User c2004cbe351992901ea1f3ecd09a36d318bd5289f4eb17c7fad36c025fd0eba2 sets name to phoebe
2025-09-23T14:40:44.593588Z  INFO: send_message modules/quickstart-chat/src/lib.rs:55: User c2004cbe351992901ea1f3ecd09a36d318bd5289f4eb17c7fad36c025fd0eba2: Hey!
2025-09-23T14:55:33.213621Z  INFO: send_message modules/quickstart-chat/src/lib.rs:55: User c2004cbe351992901ea1f3ecd09a36d318bd5289f4eb17c7fad36c025fd0eba2: Hey!

Note that set_name and send_message are reducer names. __spacetimedb__ __spacetimedb__ are the function and target fields of the record with sentinels for injected messages by SystemLogger. I have been unable to use the CLI to trigger a message from log_reducer_error or inject_logs because we do more aggressive checks in the HTTP call path than the WS call path, and I'm too lazy to build a custom SDK-ful client with intentionally incorrect bindings to test this patch.

The raw JSON records are:

{"level":"Info","ts":1758638418218267,"target":"__spacetimedb__","filename":"__spacetimedb__","function":"__spacetimedb__","message":"Creating table `message`"}
{"level":"Info","ts":1758638418218327,"target":"__spacetimedb__","filename":"__spacetimedb__","function":"__spacetimedb__","message":"Creating table `user`"}
{"level":"Info","ts":1758638418218479,"target":"__spacetimedb__","filename":"__spacetimedb__","function":"__spacetimedb__","message":"Invoking `init` reducer"}
{"level":"Info","ts":1758638418218567,"target":"__spacetimedb__","filename":"__spacetimedb__","function":"__spacetimedb__","message":"Database initialized"}
{"level":"Info","ts":1758638431077171,"target":"quickstart_chat_module","filename":"modules/quickstart-chat/src/lib.rs","line_number":30,"function":"set_name","message":"User c2004cbe351992901ea1f3ecd09a36d318bd5289f4eb17c7fad36c025fd0eba2 sets name to phoebe"}
{"level":"Info","ts":1758638444593588,"target":"quickstart_chat_module","filename":"modules/quickstart-chat/src/lib.rs","line_number":55,"function":"send_message","message":"User c2004cbe351992901ea1f3ecd09a36d318bd5289f4eb17c7fad36c025fd0eba2: Hey!"}
{"level":"Info","ts":1758639333213621,"target":"quickstart_chat_module","filename":"modules/quickstart-chat/src/lib.rs","line_number":55,"function":"send_message","message":"User c2004cbe351992901ea1f3ecd09a36d318bd5289f4eb17c7fad36c025fd0eba2: Hey!"}

[cloutiertyler]

2025-09-23T14:40:18.218267Z INFO: spacetimedb spacetimedb: Creating table message
2025-09-23T14:40:31.077171Z INFO: set_name modules/quickstart-chat/src/lib.rs:30: User c2004cbe351992901ea1f3ecd09a36d318bd5289f4eb17c7fad36c025fd0eba2 sets name to phoebe

NIT: I would reverse the order of function and target since the function is within the target.

NIT: Is it possible to just not print anything instead of __spacetimedb__ __spacetimedb__:, or is that not possible?

[gefjon]

NIT: I would reverse the order of function and target since the function is within the target.

Happy to reverse these; the order I chose was arbitrary.

I don't think it's necessarily true that the function is within the target module, strictly speaking, though. What function is executing is a dynamic property, whereas the target is a static property. It is possible to get two logs with the same target, filename and line number but different functions, and/or with a function where the defining form for the listed reducer is defined somewhere entirely unrelated to the target, filename and line number.

But again, happy to reverse these, I don't care about the order.

NIT: Is it possible to just not print anything instead of __spacetimedb__ __spacetimedb__:, or is that not possible?

Sure, that's easy. Two different ways we could do this:

1. Decide that putting the sentinel in the log records is not useful, and leave these fields None for injected messages.
2. In the CLI, recognize the sentinels and strip them out.

Do you have a preference?

[cloutiertyler]

WRT point 1: Ah I see, yeah then I'd just leave it as is.

WRT point 2: Well I suppose they logically don't have a target (that the user created) nor a function (that the user created). A sentinel makes a little more sense for a target kinda? I slightly favor option 2, but I don't have a strong opinion.

[gefjon]

WRT point 1: Ah I see, yeah then I'd just leave it as is.

WRT point 2: Well I suppose they logically don't have a target (that the user created) nor a function (that the user created). A sentinel makes a little more sense for a target kinda? I slightly favor option 2, but I don't have a strong opinion.

Done.

[JulienLavocat]

WRT point 1: Ah I see, yeah then I'd just leave it as is.

WRT point 2: Well I suppose they logically don't have a target (that the user created) nor a function (that the user created). A sentinel makes a little more sense for a target kinda? I slightly favor option 2, but I don't have a strong opinion.

For the record, I filter these sentinel values in the log explorer of my dashboard:
https://github.com/JulienLavocat/SpacetimeDB-Admin/blob/main/src/app/pages/logs/logs.component.ts#L80

[gefjon]

Log output now looks like:

spacetime logs -s local quickstart-chat
   Compiling spacetimedb-cli v1.4.0 (/home/phoebe/clockworklabs/SpacetimeDB/crates/cli)
    Finished `release` profile [optimized] target(s) in 9.53s
    Finished `release` profile [optimized] target(s) in 0.14s
     Running `/home/phoebe/clockworklabs/SpacetimeDB/target/x86_64-unknown-linux-gnu/release/spacetimedb-cli logs -s local quickstart-chat`
2025-09-23T14:40:18.218267Z  INFO: Creating table `message`
2025-09-23T14:40:18.218327Z  INFO: Creating table `user`
2025-09-23T14:40:18.218479Z  INFO: Invoking `init` reducer
2025-09-23T14:40:18.218567Z  INFO: Database initialized
2025-09-23T14:40:31.077171Z  INFO: set_name modules/quickstart-chat/src/lib.rs:30: User c2004cbe351992901ea1f3ecd09a36d318bd5289f4eb17c7fad36c025fd0eba2 sets name to phoebe
2025-09-23T14:40:44.593588Z  INFO: send_message modules/quickstart-chat/src/lib.rs:55: User c2004cbe351992901ea1f3ecd09a36d318bd5289f4eb17c7fad36c025fd0eba2: Hey!
2025-09-23T14:55:33.213621Z  INFO: send_message modules/quickstart-chat/src/lib.rs:55: User c2004cbe351992901ea1f3ecd09a36d318bd5289f4eb17c7fad36c025fd0eba2: Hey!

Raw JSON is unchanged.

[JulienLavocat]

I can't comment on SpacetimeDB internals but otherwise LGTM

[gefjon]

WRT point 1: Ah I see, yeah then I'd just leave it as is.
WRT point 2: Well I suppose they logically don't have a target (that the user created) nor a function (that the user created). A sentinel makes a little more sense for a target kinda? I slightly favor option 2, but I don't have a strong opinion.

For the record, I filter these sentinel values in the log explorer of my dashboard: https://github.com/JulienLavocat/SpacetimeDB-Admin/blob/main/src/app/pages/logs/logs.component.ts#L80

You'll have to switch this to filter on "__spacetimedb__", but otherwise this should still work.

[cloutiertyler]

LGTM