Skip to content
New issue

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

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

Already on GitHub? # to your account

Add logSource and taskQueue metadata on log messages #1391

Merged
merged 2 commits into from
Apr 22, 2024

Conversation

mjameswh
Copy link
Contributor

@mjameswh mjameswh commented Apr 9, 2024

What was changed

  • Add taskQueue metadata attribute on all log messages emitted inside the context of a worker. It is there to make it easier to correlate logs when there are multiple workers running in a same process while diagnosing low level issues (e.g. while running tests).

  • Add a logSource property in metadata. That property indicates where that log message was emitted from; possible values at this time are:

    • workflow: Messages emitted from workflow code (i.e. user code, through the workflow.log object);
    • activity: Messages emitted from activity code (i.e. user code, through the activity.log object);
    • worker: messages emitted by the worker itself, including workflow and activity life cycle events;
    • core: messages coming from Core SDK.

    That extra property will make it easier for users to implement fine-grained filtering of messages (eg. show DEBUG level messages for user-code, but only WARN for messages from the worker). Note that this is only about annotating log messages appropriately to make that possible. We don't plan to actually add support for that kind of filtering in the SDK itself. This can easily be implemented by users themselves in their custom runtime logger.

  • MockActivityEnvironment no longer defaults the context logger to Runtime.logger, as it is not desirable for Runtime to get instantiated only for that purpose. Instead, it defaults to sending logs to the console. MockActivityEnvironment now accept a logger option, which makes it easier to capture log messages emitted while testing an activity.

  • Fixed a Core-bridge build failure on Windows caused by Node's recent fix for CVE-2024-27980.

@mjameswh
Copy link
Contributor Author

mjameswh commented Apr 9, 2024

Ideas of names for the "subsystem" attribute:

  • streamName
  • logStreamName
  • sourceCategory
  • originContext
  • logSource
  • sourceComponent
  • loggerName

@mjameswh mjameswh changed the title [DRAFT] Add subsystem metadata on log messages [DRAFT] Add logSource and workerId metadata on log messages Apr 10, 2024
@mjameswh mjameswh changed the title [DRAFT] Add logSource and workerId metadata on log messages Add logSource and workerId metadata on log messages Apr 10, 2024
@mjameswh mjameswh changed the title Add logSource and workerId metadata on log messages Add logSource and taskQueue metadata on log messages Apr 10, 2024
@mjameswh mjameswh marked this pull request as ready for review April 10, 2024 17:57
@mjameswh mjameswh requested a review from a team as a code owner April 10, 2024 17:57

// Convert from Core's log "targets" (actually full module name, like "temporal_sdk_core::worker::workflow"),
// to the format used in our JavaScript side logger (i.e. "core/worker/workflow").
pub fn rust_package_to_js_style(input: &str) -> String {
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This seems slightly overkill to me, but you've done it so no reason to get rid of it.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

+1, just slap a core tag on every log record and be done with it.
Leave the Rust style tags verbatim so they're consistent when logging to console or being forwarded to lang.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I'd strongly prefer consistency of the TS SDK with itself than TS SDK with other SDKs. We already took the decision of converting attribute names to TS style in the past, for that reason, and I don't think we should diverge here.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

However, I wouldn't mind making TS SDK itself adopt the rust syntax for that specific purpose. Does that make sense to you?

packages/worker/src/worker-options.ts Outdated Show resolved Hide resolved
Comment on lines 86 to 94
/**
* Log Source prefix for messages emited by the Core SDK's Native Client subsystem.
*/
coreClient = 'core/client',

/**
* Log Source prefix for messages emited by the Core SDK's Worker subsystem.
*/
coreWorker = 'core/worker',
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Don't think it's worth getting into this resolution. Just emit these as core IMHO, we barely make this distinction.


// Convert from Core's log "targets" (actually full module name, like "temporal_sdk_core::worker::workflow"),
// to the format used in our JavaScript side logger (i.e. "core/worker/workflow").
pub fn rust_package_to_js_style(input: &str) -> String {
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

+1, just slap a core tag on every log record and be done with it.
Leave the Rust style tags verbatim so they're consistent when logging to console or being forwarded to lang.

Comment on lines 48 to 71
/**
* Log Source value for messages emited from an Activity Worker.
* This includes:
* - Activity Lifecycle events;
* - Activity Task processing events;
* - Activity Worker's lifecycle events.
*/
activityWorker = 'worker/activity',

/**
* Log Source value for messages emited from a Workflow Worker.
* This includes:
* - Workflow Lifecycle events;
* - Workflow Activations processing events;
* - Sink processing issues;
* - Workflow Worker's lifecycle events.
*/
workflowWorker = 'worker/workflow',

/**
* Log Source value for messages emited by the Workflow Bundling process,
* when being executed implicitly by the Workflow Worker.
*/
workflowBundler = 'worker/bundler',
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I'd just call all of this worker so users can easily filter out worker generated logs.
There are tradeoffs between the different approaches so I'm fine with keeping this as well.

@mjameswh
Copy link
Contributor Author

Flattened log sources: workflow, activity, worker, core.

@mjameswh mjameswh merged commit 1708529 into temporalio:main Apr 22, 2024
29 checks passed
@mjameswh mjameswh deleted the debug-shutdown-issue branch April 22, 2024 16:27
mjameswh added a commit to mjameswh/sdk-typescript that referenced this pull request Apr 23, 2024
@mjameswh mjameswh restored the debug-shutdown-issue branch April 23, 2024 16:17
# for free to join this conversation on GitHub. Already have an account? # to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

3 participants