I’m writing my first workflows & activities in Python using Temporal, I have pytest cases that I use for testing. Logging is important to receive feedback. The tests appear to work fine but the problem I noticed is that Temporal is spamming my log console with irrelevant messages, giving errors that don’t mean anything to me (these errors don’t break anything, the tests work fine).
e.g.
DEBUG temporalio.worker._activity:_activity.py:265 Running activity check_has_workflow_ended"
DEBUG temporalio.worker._activity:_activity.py:506 Completing activity with completion: task_token: "\n$e9d562f9-df8a-4e49-b247-eacb0bf69388\022\025agent-semaphore-12313\032$f16a05af-5ba7-46e9-a700-1e81ef741cde \023(\0012\0011B\030check_has_workflow_endedJ\010\010\001\020\347\200@\030\001"
result {
completed {
result {
metadata {
key: "encoding"
value: "json/plain"
}
data: "false"
}
}
}
...
2023-10-05T12:05:56.974+0300 WARN Failed to poll for task. {"service": "worker", "Namespace": "temporal-system", "TaskQueue": "temporal-sys-per-ns-tq", "WorkerID": "server-worker@94166@Gintass-MacBook-Pro.local@temporal-system", "WorkerType": "WorkflowWorker", "Error": "worker stopping", "logging-call-at": "internal_worker_base.go:308"}
2023-10-05T12:05:56.975+0300 ERROR Error looking up host for shardID {"component": "shard-controller", "address": "127.0.0.1:63296", "error": "Not enough hosts to serve the request", "operation-result": "OperationFailed", "shard-id": 1, "logging-call-at": "controller_impl.go:388"}
go.temporal.io/server/common/log.(*zapLogger).Error
/home/runner/go/pkg/mod/go.temporal.io/server@v1.21.4/common/log/zap_logger.go:156
go.temporal.io/server/service/history/shard.(*ControllerImpl).acquireShards.func2
/home/runner/go/pkg/mod/go.temporal.io/server@v1.21.4/service/history/shard/controller_impl.go:388
go.temporal.io/server/service/history/shard.(*ControllerImpl).acquireShards.func3
/home/runner/go/pkg/mod/go.temporal.io/server@v1.21.4/service/history/shard/controller_impl.go:430
2023-10-05T11:58:24.496+0300 ERROR Unable to call matching.PollActivityTaskQueue. {"service": "frontend", "wf-task-queue-name": "/_sys/temporal-sys-history-scanner-taskqueue-0/2", "timeout": "1m9.999694s", "error": "error reading from server: EOF", "logging-call-at": "workflow_handler.go:1133"}
go.temporal.io/server/common/log.(*zapLogger).Error
/home/runner/go/pkg/mod/go.temporal.io/server@v1.21.4/common/log/zap_logger.go:156
go.temporal.io/server/service/frontend.(*WorkflowHandler).PollActivityTaskQueue
/home/runner/go/pkg/mod/go.temporal.io/server@v1.21.4/service/frontend/workflow_handler.go:1133
go.temporal.io/api/workflowservice/v1._WorkflowService_PollActivityTaskQueue_Handler.func1
/home/runner/go/pkg/mod/go.temporal.io/api@v1.23.0/workflowservice/v1/service.pb.go:1657
go.temporal.io/server/common/rpc/interceptor.(*RetryableInterceptor).Intercept.func1
/home/runner/go/pkg/mod/go.temporal.io/server@v1.21.4/common/rpc/interceptor/retry.go:63
go.temporal.io/server/common/backoff.ThrottleRetryContext
/home/runner/go/pkg/mod/go.temporal.io/server@v1.21.4/common/backoff/retry.go:145
go.temporal.io/server/common/rpc/interceptor.(*RetryableInterceptor).Intercept
/home/runner/go/pkg/mod/go.temporal.io/server@v1.21.4/common/rpc/interceptor/retry.go:67
google.golang.org/grpc.getChainUnaryHandler.func1
/home/runner/go/pkg/mod/google.golang.org/grpc@v1.57.0/server.go:1179
go.temporal.io/server/common/rpc/interceptor.(*CallerInfoInterceptor).Intercept
/home/runner/go/pkg/mod/go.temporal.io/server@v1.21.4/common/rpc/interceptor/caller_info.go:80
google.golang.org/grpc.getChainUnaryHandler.func1
/home/runner/go/pkg/mod/google.golang.org/grpc@v1.57.0/server.go:1179
go.temporal.io/server/common/rpc/interceptor.(*SDKVersionInterceptor).Intercept
/home/runner/go/pkg/mod/go.temporal.io/server@v1.21.4/common/rpc/interceptor/sdk_version.go:69
google.golang.org/grpc.getChainUnaryHandler.func1
/home/runner/go/pkg/mod/google.golang.org/grpc@v1.57.0/server.go:1179
go.temporal.io/server/common/rpc/interceptor.(*RateLimitInterceptor).Intercept
/home/runner/go/pkg/mod/go.temporal.io/server@v1.21.4/common/rpc/interceptor/rate_limit.go:87
google.golang.org/grpc.getChainUnaryHandler.func1
/home/runner/go/pkg/mod/google.golang.org/grpc@v1.57.0/server.go:1179
go.temporal.io/server/common/rpc/interceptor.(*NamespaceRateLimitInterceptor).Intercept
/home/runner/go/pkg/mod/go.temporal.io/server@v1.21.4/common/rpc/interceptor/namespace_rate_limit.go:92
google.golang.org/grpc.getChainUnaryHandler.func1
/home/runner/go/pkg/mod/google.golang.org/grpc@v1.57.0/server.go:1179
go.temporal.io/server/common/rpc/interceptor.(*NamespaceCountLimitInterceptor).Intercept
/home/runner/go/pkg/mod/go.temporal.io/server@v1.21.4/common/rpc/interceptor/namespace_count_limit.go:111
google.golang.org/grpc.getChainUnaryHandler.func1
/home/runner/go/pkg/mod/google.golang.org/grpc@v1.57.0/server.go:1179
go.temporal.io/server/common/rpc/interceptor.(*NamespaceValidatorInterceptor).StateValidationIntercept
/home/runner/go/pkg/mod/go.temporal.io/server@v1.21.4/common/rpc/interceptor/namespace_validator.go:194
google.golang.org/grpc.getChainUnaryHandler.func1
/home/runner/go/pkg/mod/google.golang.org/grpc@v1.57.0/server.go:1179
go.temporal.io/server/common/authorization.(*interceptor).Interceptor
/home/runner/go/pkg/mod/go.temporal.io/server@v1.21.4/common/authorization/interceptor.go:158
google.golang.org/grpc.getChainUnaryHandler.func1
/home/runner/go/pkg/mod/google.golang.org/grpc@v1.57.0/server.go:1179
go.temporal.io/server/common/rpc/interceptor.(*TelemetryInterceptor).UnaryIntercept
/home/runner/go/pkg/mod/go.temporal.io/server@v1.21.4/common/rpc/interceptor/telemetry.go:162
google.golang.org/grpc.getChainUnaryHandler.func1
/home/runner/go/pkg/mod/google.golang.org/grpc@v1.57.0/server.go:1179
go.temporal.io/server/service/frontend.(*RedirectionInterceptor).handleRedirectAPIInvocation.func2
/home/runner/go/pkg/mod/go.temporal.io/server@v1.21.4/service/frontend/redirection_interceptor.go:238
go.temporal.io/server/service/frontend.(*NoopRedirectionPolicy).WithNamespaceRedirect
/home/runner/go/pkg/mod/go.temporal.io/server@v1.21.4/service/frontend/dcRedirectionPolicy.go:125
go.temporal.io/server/service/frontend.(*RedirectionInterceptor).handleRedirectAPIInvocation
/home/runner/go/pkg/mod/go.temporal.io/server@v1.21.4/service/frontend/redirection_interceptor.go:235
go.temporal.io/server/service/frontend.(*RedirectionInterceptor).Intercept
/home/runner/go/pkg/mod/go.temporal.io/server@v1.21.4/service/frontend/redirection_interceptor.go:195
google.golang.org/grpc.getChainUnaryHandler.func1
/home/runner/go/pkg/mod/google.golang.org/grpc@v1.57.0/server.go:1179
go.temporal.io/server/common/metrics.NewServerMetricsContextInjectorInterceptor.func1
/home/runner/go/pkg/mod/go.temporal.io/server@v1.21.4/common/metrics/grpc.go:66
google.golang.org/grpc.getChainUnaryHandler.func1
/home/runner/go/pkg/mod/google.golang.org/grpc@v1.57.0/server.go:1179
go.opentelemetry.io/contrib/instrumentation/google.golang.org/grpc/otelgrpc.UnaryServerInterceptor.func1
/home/runner/go/pkg/mod/go.opentelemetry.io/contrib/instrumentation/google.golang.org/grpc/otelgrpc@v0.42.0/interceptor.go:344
google.golang.org/grpc.getChainUnaryHandler.func1
/home/runner/go/pkg/mod/google.golang.org/grpc@v1.57.0/server.go:1179
go.temporal.io/server/common/rpc/interceptor.(*NamespaceLogInterceptor).Intercept
/home/runner/go/pkg/mod/go.temporal.io/server@v1.21.4/common/rpc/interceptor/namespace_logger.go:84
google.golang.org/grpc.getChainUnaryHandler.func1
/home/runner/go/pkg/mod/google.golang.org/grpc@v1.57.0/server.go:1179
go.temporal.io/server/common/rpc/interceptor.(*NamespaceValidatorInterceptor).NamespaceValidateIntercept
/home/runner/go/pkg/mod/go.temporal.io/server@v1.21.4/common/rpc/interceptor/namespace_validator.go:111
google.golang.org/grpc.getChainUnaryHandler.func1
/home/runner/go/pkg/mod/google.golang.org/grpc@v1.57.0/server.go:1179
go.temporal.io/server/common/rpc.ServiceErrorInterceptor
/home/runner/go/pkg/mod/go.temporal.io/server@v1.21.4/common/rpc/grpc.go:141
google.golang.org/grpc.chainUnaryInterceptors.func1
/home/runner/go/pkg/mod/google.golang.org/grpc@v1.57.0/server.go:1170
go.temporal.io/api/workflowservice/v1._WorkflowService_PollActivityTaskQueue_Handler
/home/runner/go/pkg/mod/go.temporal.io/api@v1.23.0/workflowservice/v1/service.pb.go:1659
google.golang.org/grpc.(*Server).processUnaryRPC
/home/runner/go/pkg/mod/google.golang.org/grpc@v1.57.0/server.go:1360
google.golang.org/grpc.(*Server).handleStream
/home/runner/go/pkg/mod/google.golang.org/grpc@v1.57.0/server.go:1737
google.golang.org/grpc.(*Server).serveStreams.func1.1
/home/runner/go/pkg/mod/google.golang.org/grpc@v1.57.0/server.go:982
2023-10-05T11:58:24.496+0300 ERROR Unable to call matching.PollWorkflowTaskQueue. {"service": "frontend", "wf-task-queue-name": "/_sys/temporal-sys-tq-scanner-taskqueue-0/3", "timeout": "1m9.999793s", "error": "error reading from server: EOF", "logging-call-at": "workflow_handler.go:894"}
go.temporal.io/server/common/log.(*zapLogger).Error
/home/runner/go/pkg/mod/go.temporal.io/server@v1.21.4/common/log/zap_logger.go:156
go.temporal.io/server/service/frontend.(*WorkflowHandler).PollWorkflowTaskQueue
/home/runner/go/pkg/mod/go.temporal.io/server@v1.21.4/service/frontend/workflow_handler.go:894
go.temporal.io/api/workflowservice/v1._WorkflowService_PollWorkflowTaskQueue_Handler.func1
/home/runner/go/pkg/mod/go.temporal.io/api@v1.23.0/workflowservice/v1/service.pb.go:1603
go.temporal.io/server/common/rpc/interceptor.(*RetryableInterceptor).Intercept.func1
/home/runner/go/pkg/mod/go.temporal.io/server@v1.21.4/common/rpc/interceptor/retry.go:63
go.temporal.io/server/common/backoff.ThrottleRetryContext
/home/runner/go/pkg/mod/go.temporal.io/server@v1.21.4/common/backoff/retry.go:145
go.temporal.io/server/common/rpc/interceptor.(*RetryableInterceptor).Intercept
/home/runner/go/pkg/mod/go.temporal.io/server@v1.21.4/common/rpc/interceptor/retry.go:67
google.golang.org/grpc.getChainUnaryHandler.func1
/home/runner/go/pkg/mod/google.golang.org/grpc@v1.57.0/server.go:1179
go.temporal.io/server/common/rpc/interceptor.(*CallerInfoInterceptor).Intercept
/home/runner/go/pkg/mod/go.temporal.io/server@v1.21.4/common/rpc/interceptor/caller_info.go:80
google.golang.org/grpc.getChainUnaryHandler.func1
/home/runner/go/pkg/mod/google.golang.org/grpc@v1.57.0/server.go:1179
go.temporal.io/server/common/rpc/interceptor.(*SDKVersionInterceptor).Intercept
/home/runner/go/pkg/mod/go.temporal.io/server@v1.21.4/common/rpc/interceptor/sdk_version.go:69
google.golang.org/grpc.getChainUnaryHandler.func1
/home/runner/go/pkg/mod/google.golang.org/grpc@v1.57.0/server.go:1179
go.temporal.io/server/common/rpc/interceptor.(*RateLimitInterceptor).Intercept
/home/runner/go/pkg/mod/go.temporal.io/server@v1.21.4/common/rpc/interceptor/rate_limit.go:87
google.golang.org/grpc.getChainUnaryHandler.func1
/home/runner/go/pkg/mod/google.golang.org/grpc@v1.57.0/server.go:1179
go.temporal.io/server/common/rpc/interceptor.(*NamespaceRateLimitInterceptor).Intercept
/home/runner/go/pkg/mod/go.temporal.io/server@v1.21.4/common/rpc/interceptor/namespace_rate_limit.go:92
google.golang.org/grpc.getChainUnaryHandler.func1
/home/runner/go/pkg/mod/google.golang.org/grpc@v1.57.0/server.go:1179
go.temporal.io/server/common/rpc/interceptor.(*NamespaceCountLimitInterceptor).Intercept
/home/runner/go/pkg/mod/go.temporal.io/server@v1.21.4/common/rpc/interceptor/namespace_count_limit.go:111
google.golang.org/grpc.getChainUnaryHandler.func1
/home/runner/go/pkg/mod/google.golang.org/grpc@v1.57.0/server.go:1179
go.temporal.io/server/common/rpc/interceptor.(*NamespaceValidatorInterceptor).StateValidationIntercept
/home/runner/go/pkg/mod/go.temporal.io/server@v1.21.4/common/rpc/interceptor/namespace_validator.go:194
google.golang.org/grpc.getChainUnaryHandler.func1
/home/runner/go/pkg/mod/google.golang.org/grpc@v1.57.0/server.go:1179
go.temporal.io/server/common/authorization.(*interceptor).Interceptor
/home/runner/go/pkg/mod/go.temporal.io/server@v1.21.4/common/authorization/interceptor.go:158
google.golang.org/grpc.getChainUnaryHandler.func1
/home/runner/go/pkg/mod/google.golang.org/grpc@v1.57.0/server.go:1179
go.temporal.io/server/common/rpc/interceptor.(*TelemetryInterceptor).UnaryIntercept
/home/runner/go/pkg/mod/go.temporal.io/server@v1.21.4/common/rpc/interceptor/telemetry.go:162
google.golang.org/grpc.getChainUnaryHandler.func1
/home/runner/go/pkg/mod/google.golang.org/grpc@v1.57.0/server.go:1179
go.temporal.io/server/service/frontend.(*RedirectionInterceptor).handleRedirectAPIInvocation.func2
/home/runner/go/pkg/mod/go.temporal.io/server@v1.21.4/service/frontend/redirection_interceptor.go:238
go.temporal.io/server/service/frontend.(*NoopRedirectionPolicy).WithNamespaceRedirect
/home/runner/go/pkg/mod/go.temporal.io/server@v1.21.4/service/frontend/dcRedirectionPolicy.go:125
go.temporal.io/server/service/frontend.(*RedirectionInterceptor).handleRedirectAPIInvocation
/home/runner/go/pkg/mod/go.temporal.io/server@v1.21.4/service/frontend/redirection_interceptor.go:235
go.temporal.io/server/service/frontend.(*RedirectionInterceptor).Intercept
/home/runner/go/pkg/mod/go.temporal.io/server@v1.21.4/service/frontend/redirection_interceptor.go:195
google.golang.org/grpc.getChainUnaryHandler.func1
/home/runner/go/pkg/mod/google.golang.org/grpc@v1.57.0/server.go:1179
go.temporal.io/server/common/metrics.NewServerMetricsContextInjectorInterceptor.func1
/home/runner/go/pkg/mod/go.temporal.io/server@v1.21.4/common/metrics/grpc.go:66
google.golang.org/grpc.getChainUnaryHandler.func1
/home/runner/go/pkg/mod/google.golang.org/grpc@v1.57.0/server.go:1179
go.opentelemetry.io/contrib/instrumentation/google.golang.org/grpc/otelgrpc.UnaryServerInterceptor.func1
/home/runner/go/pkg/mod/go.opentelemetry.io/contrib/instrumentation/google.golang.org/grpc/otelgrpc@v0.42.0/interceptor.go:344
google.golang.org/grpc.getChainUnaryHandler.func1
/home/runner/go/pkg/mod/google.golang.org/grpc@v1.57.0/server.go:1179
go.temporal.io/server/common/rpc/interceptor.(*NamespaceLogInterceptor).Intercept
/home/runner/go/pkg/mod/go.temporal.io/server@v1.21.4/common/rpc/interceptor/namespace_logger.go:84
google.golang.org/grpc.getChainUnaryHandler.func1
/home/runner/go/pkg/mod/google.golang.org/grpc@v1.57.0/server.go:1179
go.temporal.io/server/common/rpc/interceptor.(*NamespaceValidatorInterceptor).NamespaceValidateIntercept
/home/runner/go/pkg/mod/go.temporal.io/server@v1.21.4/common/rpc/interceptor/namespace_validator.go:111
google.golang.org/grpc.getChainUnaryHandler.func1
/home/runner/go/pkg/mod/google.golang.org/grpc@v1.57.0/server.go:1179
go.temporal.io/server/common/rpc.ServiceErrorInterceptor
/home/runner/go/pkg/mod/go.temporal.io/server@v1.21.4/common/rpc/grpc.go:141
google.golang.org/grpc.chainUnaryInterceptors.func1
/home/runner/go/pkg/mod/google.golang.org/grpc@v1.57.0/server.go:1170
go.temporal.io/api/workflowservice/v1._WorkflowService_PollWorkflowTaskQueue_Handler
/home/runner/go/pkg/mod/go.temporal.io/api@v1.23.0/workflowservice/v1/service.pb.go:1605
google.golang.org/grpc.(*Server).processUnaryRPC
/home/runner/go/pkg/mod/google.golang.org/grpc@v1.57.0/server.go:1360
google.golang.org/grpc.(*Server).handleStream
/home/runner/go/pkg/mod/google.golang.org/grpc@v1.57.0/server.go:1737
google.golang.org/grpc.(*Server).serveStreams.func1.1
/home/runner/go/pkg/mod/google.golang.org/grpc@v1.57.0/server.go:982
Full log with more spam: ============================= test session starts ============================== - Pastebin.com
To hide these temporal’s DEBUG level messages, I could set a pytest logging level to INFO but then I’d lose DEBUG level messages coming from other parts of the code that I want to see. And then there are these WARNING and ERROR level messages that I cannot hide. I don’t want to hide all ERROR messages from temporal as I suspect in the future I may experience some issue that would require me to notice a relevant ERROR message.
conftest.py:
# Due to https://github.com/python/cpython/issues/77906, multiprocessing on
# macOS starting with Python 3.8 has changed from "fork" to "spawn". For
# pre-3.8, we are changing it for them.
if sys.version_info < (3, 8) and sys.platform.startswith("darwin"):
multiprocessing.set_start_method("spawn", True)
@pytest.fixture(scope="session")
def event_loop(): # type: ignore
# See https://github.com/pytest-dev/pytest-asyncio/issues/68
# See https://github.com/pytest-dev/pytest-asyncio/issues/257
# Also need ProactorEventLoop on older versions of Python with Windows so
# that asyncio subprocess works properly
if sys.version_info < (3, 8) and sys.platform == "win32":
loop = asyncio.ProactorEventLoop()
else:
loop = asyncio.get_event_loop_policy().new_event_loop()
yield loop
loop.close()
def pytest_addoption(parser) -> None: # type: ignore
parser.addoption(
"--workflow-environment",
default="local",
help="Which workflow environment to use ('local', 'time-skipping', or target to existing server)",
)
@pytest_asyncio.fixture(scope="session")
async def env(request) -> AsyncGenerator[WorkflowEnvironment, None]: # type: ignore
env_type = request.config.getoption("--workflow-environment")
if env_type == "local":
env = await WorkflowEnvironment.start_local()
elif env_type == "time-skipping":
env = await WorkflowEnvironment.start_time_skipping()
else:
env = WorkflowEnvironment.from_client(await Client.connect(env_type))
yield env
await env.shutdown()
@pytest_asyncio.fixture
async def temporal_client(env: WorkflowEnvironment) -> Client:
return env.client
test file (I did try to disable debug_mode in Worker):
@pytest.mark.asyncio
async def test_asdasdasd(
temporal_client: Client,
temporal_workflow_types: List[type[Any]],
temporal_activity_types: List[type[Any]],
) -> None:
agent_id = "12313"
async with Worker(
temporal_client,
task_queue="q1",
workflows=temporal_workflow_types,
activities=temporal_activity_types,
debug_mode=True,
):
handle = await temporal_client.start_workflow(
AgentTaskExecutionSemaphoreWorkflow.run,
agent_id,
id=f"agent-semaphore-{agent_id}",
task_queue="q1",
)
res = await temporal_client.execute_workflow(
SampleAgentTask.run,
agent_id,
id=f"{uuid.uuid4()}",
task_queue=f"q1",
)
assert res == "res"
await asyncio.sleep(10)