We've discussed the desire to unify logging across core/lang.

Right now, core uses https://github.com/tokio-rs/tracing to simultaneously perform traditional logging functions, while also generating OpenTelemetry traces.

When we consider unifying these concerns across the language barrier, we really want to do two things:

1. Have consistent "traditional" logging output - IE: What you'd see in the console / a log file.
2. Pass tracing context across the language barrier

For 1, one option (possibly better option described below) is to expose a log function from core which takes a level parameter, a span parameter, a message parameter, and optionally a series of key/value pairs to be logged (all logging is structured). Then, lang side has to translate it's logging interface to the core logging interface in whatever way feels most natural/idiomatic and pass logging through to core. The core implementation of that function then constructs an https://tracing-rs.netlify.app/tracing/struct.event corresponding to the passed in parameters.

If there's something more automatic we could do here I'm all ears but nothing comes to mind.

For 2, is seems best for poll_workflow_task and poll_activity_task to return a Span as defined here https://github.com/open-telemetry/opentelemetry-proto/blob/main/opentelemetry/proto/trace/v1/trace.proto#L57 by OpenTelemetry. Then, lang can convert that into the Span type that the tracing library it has chosen to use uses, and proceed from there to pass it around and create new child spans, etc. It would then pass it / such spans back into the logging interface described above as the span parameter.

While writing the above, I realized there probably is a more elegant option here. The core side can provide an OpenTelemetry "Collector" https://opentelemetry.io/docs/concepts/data-collection/ which the lang side will need to provide an implementation for. Then, ideally, lang simply uses it's opentelem library, registering the custom collector which is core. On the core side, the collector is just a pass through to tokio tracing. Lang would be expected to disable all output, relying on core to collect the logs/traces and output them as console/file/tracing etc. This is more work up front, and possibly per-lang, but also feels substantially less hacky. Unfortunately, I think the spans from 2 still need to be passed into lang so that what it's doing can be associated with certain workflow/activity tasks.

What was changed

An activity context that tries to be as close to the go sdk as possible. Implementation added in sdk/src/activity_context.rs. sdk/src/lib.rs was also modified to support the new context for each activity worker function.

1. Closes https://github.com/temporalio/sdk-core/issues/301

2. How was this tested:

• Ran Unit Tests
• Ran Integration tests
• Sanity Tested with External Project on Docker-compose temporal environment

3. Any docs updates needed? Not that I know of. Would be happy to contribute with some direction.

This PR seeks to iteratively flesh out the design for any interface changes needed to support sticky task queues.

Checklist:

• [x] Add configuration option to enable or disable sticky mode, with a cache size limit
• [x] Add some way (a new method) to evict specific workflows, or entire cache.
• [x] Decide on if we should change to using run ids rather than task tokens as the primary identifier returned by polls and provided in activations
  • [x] If so, make that change
• [x] Add unit tests for multiple worker scenarios

See original discussion here: https://github.com/temporalio/sdk-core/pull/89

We need to test and determine best course of action when a new PA interrupts a poll. Ideally it should cancel the request, but there are many potential weird corner cases here like what to do if things race and we somehow get a new task back but don't acknowledge it.

Expected Behavior

Server sends legacy query and activity resolution at the same time and workflow should be able to send response to query and next command.

Actual Behavior

This one is a bit hard to reproduce. You have to make an activity resolution happen at the same time as a query. Then the query comes over as a legacy query from the test server and the workflow responds to the query and does a start child workflow in the same response. Core responds to this with:

Lang SDK sent us a malformed workflow completion for run (a067d736-1f05-4217-8c4c-4c4c5674c605): Workflow completion had a legacy query response along with other commands. This is not allowed and constitutes an error in the lang SDK

Currently it's only possible to configure static HTTP headers on the Client, we need to add a way to specify dynamic ones. A typical use case for this would be to refresh an auth token and users should not be required to recreate their workers for that.

What was changed

• Moved protos with separate packages into separate dirs
• Changed inconsistent wf_* and Wf* to workflow_ and Workflow* respectively

One thing I didn't do but I want to do is change the coresdk package base to temporal.sdk.core. Some discussions need to be had here.

Why?

• It is common practice to not have different proto packages in the same dir
  • Often code generators may choose to use the proto dir/import path instead of the proto package name to choose where to place files
  • It is confusing for an importer to not know based on import what proto package is being used

Checklist

1. Closes #247

What was changed

Added a NonRetryableActivityError type so that an ActivityFunction can return this Error and the activity is not retried. Hence, the workflow will fail.

Why?

To be able to accommodate for the use-case where you as the user know that the activity should not be retried.

Checklist

1. Closes: https://github.com/temporalio/sdk-core/issues/454

2. How was this tested: Test was added activity_non_retryable_failure_with_error that uses the new function: Failure::application_failure_from_error. Also, created a manual test locally: Where an activity was used that returns the new error type. Not sure if a test could be added to local_activities to properly test the error conversion code? Could use some pointers here if this is deemed necessary :) Thanks!

3. Any docs updates needed? Not sure, as there is no currently published Rust docs.

What are you really trying to do?

I'm running workflow tests using the Temporal TypeScript SDK. The test output is littered with warning messages from the Core SDK like this:

2022-07-27T08:21:22.605721Z  WARN temporal_sdk_core::worker::workflow::workflow_stream: WFT poller died, shutting down

This is making the test output really hard to read, e.g.

> yarn test test/workflows/executeFullScan_test.ts
yarn run v1.22.18
$ NODE_ENV=test mocha test/workflows/executeFullScan_test.ts
choma: to re-use this ordering, run tests with CHOMA_SEED=IonALwEbIv


  workflows
    executeFullScan
  2022-07-27T08:23:55.738759Z  WARN temporal_sdk_core::worker::workflow::workflow_stream: WFT poller died, shutting down

  2022-07-27T08:23:55.754344Z  WARN temporal_sdk_core::worker::workflow::workflow_stream: WFT poller died, shutting down

      ✔ paginates the source and inspects each page (1342ms)
  2022-07-27T08:23:56.436774Z  WARN temporal_sdk_core::worker::workflow::workflow_stream: WFT poller died, shutting down

  2022-07-27T08:23:56.452200Z  WARN temporal_sdk_core::worker::workflow::workflow_stream: WFT poller died, shutting down

      ✔ syncs insights after all pages are processed (697ms)
      queries
        progress
  2022-07-27T08:23:57.223656Z  WARN temporal_sdk_core::worker::workflow::workflow_stream: WFT poller died, shutting down

  2022-07-27T08:23:57.241008Z  WARN temporal_sdk_core::worker::workflow::workflow_stream: WFT poller died, shutting down

          ✔ returns the workflow's progress (797ms)


  3 passing (3s)

✨  Done in 5.55s.

I'm trying to suppress that warning from the Core SDK, but have been unable to do so.

Describe the bug

In setting up my test env, I'm installing a custom logger into the Core SDK runtime, and with the log level set to ERROR:

import { TestWorkflowEnvironment } from '@temporalio/testing'
import { DefaultLogger, Runtime, NativeConnection } from '@temporalio/worker'
import { WorkflowClient } from '@temporalio/client'

let testEnv: TestWorkflowEnvironment
export let testClient: WorkflowClient
export let testConnection: NativeConnection

global.before('Create Test Environment', async () => {
  const logger = new DefaultLogger('ERROR')
  Runtime.install({ logger })
  testEnv = await TestWorkflowEnvironment.create({
    testServer: {
      stdio: 'ignore',
      // stdio: 'inherit'
    },
    logger
  })
  testConnection = testEnv.nativeConnection
  testClient = testEnv.workflowClient
})

global.after('Tear Down Test Environment', () => {
  return testEnv?.teardown()
})

To test my workflows, I create a bunch of workers running different (mock) activites and then run them all using the runUntil function, e.g.

      await insights.runUntil(() => {
        return inspection.runUntil(() => {
          return connector.runUntil(() => {
            return orchestrator.runUntil(() => {
              return testClient.execute(executeFullScan, {
                args: [...],
                workflowId: 'test-workflow',
                taskQueue: orchestrator.options.taskQueue
              })
            })
          })
        })
      })

The warnings are created when each of these workers shuts down.

Minimal Reproduction

https://github.com/jhecking/samples-typescript/pull/1

That PR adds a simple workflow test to the hello-world sample, which – when run – demonstrates the warning message generated by the Core SDK:

> yarn test
yarn run v1.22.18
$ ts-node src/test.ts
  2022-07-27T08:44:04.290368Z  WARN temporal_sdk_core::worker::workflow::workflow_stream: WFT poller died, shutting down

✨  Done in 2.67s.

Environment/Versions

• OS and processor: macOS on x86
• Temporal Version: Temporal TypeScript SDK v1.0.0
• Are you using Docker or Kubernetes or building Temporal from source? Doesn't apply since this issue occurs when running unit tests without any Temporal server.

Additional context

https://temporalio.slack.com/archives/C01DKSMU94L/p1658892545849429

What was changed

Initial impl of bridge FFI. This is still in development so lacks a lot of docs.

Why?

Go and others need a C API to communicate with core.

Notes

1. See #248
2. This adds a bridge set of protos which is essentially just the Core trait wrapped in proto form. It also provides a gRPC stream service proto.
3. This adds a bridge-ffi crate which exposes core over C API
4. This may add a bridge-grpc crate which exposes core over a gRPC stream
5. We have discussed and decided that protobuf is the encoding language of choice. The serialization/deserialization on both sides of the boundary comes with a known performance cost.
   • This performance cost already exists in core as protobuf is already being used as the encoding between core and lang
   • If we want to improve this, I suggest either https://google.github.io/flatbuffers/ or https://capnproto.org/, both of which operate on byte arrays without explicit serialization and have decent cross-language support
6. Since core calls are async, we have chosen C function pointer callbacks to report results. There are upsides and downsides to this approach:
   • Anything can be built on callbacks, including event loops or whatever
   • Callbacks do require the lang to respect speed inside the callback. The Rust thread is held up while a callback is executed, so lang must do what it needs to do inside the callback to get the data on its other thread for working (resolve a JS promise, put on a Go channel, etc).
   • As most C APIs do, we allow user data in the callback. This helps callers access data inside the callback and is a very common approach.
   • We could have done an event loop, but you essentially are using function pointers anyways, the only difference is you've now made the response handling single threaded which doesn't benefit languages that can use more than one thread.
7. This includes a Go example and may include examples of other languages. The examples may not ever be in the final product, we just need to prove things work

What was changed:

Return new activations from completing them, when required

Why?

• Eliminates complexity around pending activations
• When you call poll, you always poll the server now
• When you poll, your activation is always for that task queue
• Eliminates question about how to "buffer" server responses if lang is dealing with pending activations - so closes https://github.com/temporalio/sdk-core/issues/91

Checklist

TODO:

• [ ] Saw stalling behavior if lang side didn't deal with returned activations from a completion (I think this is because workflow task timeout isn't working right)
• [ ] Cleanup pass

1. Closes issue: Closes https://github.com/temporalio/sdk-core/issues/91

2. How was this tested: Existing & new tests

Currently all lang implementations have to manually cancel activities and have some logic for converting cancelled errors to application failures.

It'd be nice to move all of that logic into core and avoid some lang side duplication.

Is your feature request related to a problem? Please describe.

There is currently no easy way to know if a worker's poll calls are failing. Users want to make a call on the worker to know whether it's healthy or backing off due to server failure.

Describe the solution you'd like

TBD. Options:

• Create metrics like workflow_task_queue_poll_failed and activity_task_queue_poll_succeed/activity_task_queue_poll_failure and encourage checking those metrics
  • A bit hacky to ask users to do manual subtraction and state management
  • These metrics have value anyways, we should probably add them. long_request_failure is not very detailed (but technically good enough if we exposed a way to create custom metric labels per client).
• Populate some kind of internal std::sync::atomic::AtomicBool for whether the last poll calls are successful for a worker (or client) and expose some kind of getter to check them
• Support for general gRPC interceptors from lang through Rust could help advanced uses like this and others
• Some other on-poll-failed callback mechanism?
• Customize retry logic for workers so users can opt-in to eagerly failing workers a bit more aggressively

Is your feature request related to a problem? Please describe.

From a user:

We noticed the metric caps out at 10 seconds. If we start a large batch workflows we are generally fine waiting for them to process for 10-15 minutes. Given the 10 second maximum it’s pretty hard to tell how busy the workflow queue is.

(small number of workflow task slots)

Describe the solution you'd like

temporal_sdk_core::ephemeral_server has stuff for Temporalite right now. We are going to replace it with Temporal CLI which is now available at temporal.download. We should deprecate (not yet remove) Temporalite and make equivalent functions for Temporal CLI.

Just capturing notes, handful of things to fix that we learned about while refactoring Java.

• https://github.com/temporalio/sdk-core/issues/446
• Local retry threshold tied to WFT timeout - 3x or whatever, for default.
• Use retry state so I'm accepting of changes to retry policy or timeout adjustments w/o causing nondeterminism error.
• Cancel of LA if WFT already failed for some other reason - don't orphan LAs

Is your feature request related to a problem? Please describe.

If I just start an activity, cancel it, and wait on the task (which has TRY_CANCEL by default), and return from the workflow I get this warning:

Activity not found on completion. This may happen if the activity has already been cancelled but completed anyway.

At least I believe that is what is happening.

Describe the solution you'd like

Don't show that log if this is an activity cancel since sometimes it is the workflow leaving that is causing the cancel (and other times the workflow may be gone for other reasons). Or maybe reduce the log level.