error converting NULL to string is unsupported after upgrade to v1.27.0

[sergeimonakhov]

Expected Behavior

Actual Behavior

{"level":"info","ts":"2025-02-22T19:08:01.765Z","msg":"history client encountered error","service":"frontend","error":"lockCurrentExecutionIfExists failed. Failed to get current_executions row for (shard,namespace,workflow) = (216, 32049b68-7872-4094-8e63-d0dd59896a83, temporal-sys-history-scanner). Error: sql: Scan error on column index 10, name \"data_encoding\": converting NULL to string is unsupported","service-error-type":"serviceerror.Unavailable","logging-call-at":"/home/runner/work/docker-builds/docker-builds/temporal/client/history/metric_client.go:103"}
{"level":"info","ts":"2025-02-22T19:08:01.950Z","msg":"history client encountered error","service":"frontend","error":"lockCurrentExecutionIfExists failed. Failed to get current_executions row for (shard,namespace,workflow) = (216, 32049b68-7872-4094-8e63-d0dd59896a83, temporal-sys-history-scanner). Error: sql: Scan error on column index 10, name \"data_encoding\": converting NULL to string is unsupported","service-error-type":"serviceerror.Unavailable","logging-call-at":"/home/runner/work/docker-builds/docker-builds/temporal/client/history/metric_client.go:103"}
{"level":"error","ts":"2025-02-22T19:08:01.951Z","msg":"service failures","operation":"StartWorkflowExecution","wf-namespace":"temporal-system","grpc_code":"Unavailable","wf-id":"temporal-sys-history-scanner","error":"lockCurrentExecutionIfExists failed. Failed to get current_executions row for (shard,namespace,workflow) = (216, 32049b68-7872-4094-8e63-d0dd59896a83, temporal-sys-history-scanner). Error: sql: Scan error on column index 10, name \"data_encoding\": converting NULL to string is unsupported","logging-call-at":"/home/runner/work/docker-builds/docker-builds/temporal/common/rpc/interceptor/telemetry.go:423","stacktrace":"go.temporal.io/server/common/log.(*zapLogger).Error\n\t/home/runner/work/docker-builds/docker-builds/temporal/common/log/zap_logger.go:154\ngo.temporal.io/server/common/rpc/interceptor.(*TelemetryInterceptor).logErrors\n\t/home/runner/work/docker-builds/docker-builds/temporal/common/rpc/interceptor/telemetry.go:423\ngo.temporal.io/server/common/rpc/interceptor.(*TelemetryInterceptor).HandleError\n\t/home/runner/work/docker-builds/docker-builds/temporal/common/rpc/interceptor/telemetry.go:393\ngo.temporal.io/server/common/rpc/interceptor.(*TelemetryInterceptor).UnaryIntercept\n\t/home/runner/work/docker-builds/docker-builds/temporal/common/rpc/interceptor/telemetry.go:200\ngoogle.golang.org/grpc.getChainUnaryHandler.func1\n\t/home/runner/go/pkg/mod/google.golang.org/[email protected]/server.go:1212\ngo.temporal.io/server/common/rpc/interceptor.(*Redirection).handleRedirectAPIInvocation.func2\n\t/home/runner/work/docker-builds/docker-builds/temporal/common/rpc/interceptor/redirection.go:265\ngo.temporal.io/server/common/rpc/interceptor.(*NoopRedirectionPolicy).WithNamespaceRedirect\n\t/home/runner/work/docker-builds/docker-builds/temporal/common/rpc/interceptor/dc_redirection_policy.go:125\ngo.temporal.io/server/common/rpc/interceptor.(*Redirection).handleRedirectAPIInvocation\n\t/home/runner/work/docker-builds/docker-builds/temporal/common/rpc/interceptor/redirection.go:262\ngo.temporal.io/server/common/rpc/interceptor.(*Redirection).Intercept\n\t/home/runner/work/docker-builds/docker-builds/temporal/common/rpc/interceptor/redirection.go:222\ngoogle.golang.org/grpc.getChainUnaryHandler.func1\n\t/home/runner/go/pkg/mod/google.golang.org/[email protected]/server.go:1212\ngo.temporal.io/server/common/authorization.(*Interceptor).Intercept\n\t/home/runner/work/docker-builds/docker-builds/temporal/common/authorization/interceptor.go:178\ngoogle.golang.org/grpc.getChainUnaryHandler.func1\n\t/home/runner/go/pkg/mod/google.golang.org/[email protected]/server.go:1212\ngo.temporal.io/server/service/frontend.GrpcServerOptionsProvider.NewServerMetricsContextInjectorInterceptor.func2\n\t/home/runner/work/docker-builds/docker-builds/temporal/common/metrics/grpc.go:65\ngoogle.golang.org/grpc.getChainUnaryHandler.func1\n\t/home/runner/go/pkg/mod/google.golang.org/[email protected]/server.go:1212\ngo.temporal.io/server/common/rpc/interceptor.(*NamespaceLogInterceptor).Intercept\n\t/home/runner/work/docker-builds/docker-builds/temporal/common/rpc/interceptor/namespace_logger.go:84\ngoogle.golang.org/grpc.getChainUnaryHandler.func1\n\t/home/runner/go/pkg/mod/google.golang.org/[email protected]/server.go:1212\ngo.temporal.io/server/common/rpc/interceptor.(*NamespaceValidatorInterceptor).NamespaceValidateIntercept\n\t/home/runner/work/docker-builds/docker-builds/temporal/common/rpc/interceptor/namespace_validator.go:132\ngoogle.golang.org/grpc.getChainUnaryHandler.func1\n\t/home/runner/go/pkg/mod/google.golang.org/[email protected]/server.go:1212\ngo.temporal.io/server/service/frontend.GrpcServerOptionsProvider.NewFrontendServiceErrorInterceptor.func1\n\t/home/runner/work/docker-builds/docker-builds/temporal/common/rpc/grpc.go:178\ngoogle.golang.org/grpc.getChainUnaryHandler.func1\n\t/home/runner/go/pkg/mod/google.golang.org/[email protected]/server.go:1212\ngo.temporal.io/server/common/rpc.ServiceErrorInterceptor\n\t/home/runner/work/docker-builds/docker-builds/temporal/common/rpc/grpc.go:157\ngoogle.golang.org/grpc.getChainUnaryHandler.func1\n\t/home/runner/go/pkg/mod/google.golang.org/[email protected]/server.go:1212\ngo.temporal.io/server/common/rpc/interceptor.(*MaskInternalErrorDetailsInterceptor).Intercept\n\t/home/runner/work/docker-builds/docker-builds/temporal/common/rpc/interceptor/mask_internal_error.go:65\ngoogle.golang.org/grpc.NewServer.chainUnaryServerInterceptors.chainUnaryInterceptors.func1\n\t/home/runner/go/pkg/mod/google.golang.org/[email protected]/server.go:1203\ngo.temporal.io/api/workflowservice/v1._WorkflowService_StartWorkflowExecution_Handler\n\t/home/runner/go/pkg/mod/go.temporal.io/[email protected]/workflowservice/v1/service_grpc.pb.go:2405\ngoogle.golang.org/grpc.(*Server).processUnaryRPC\n\t/home/runner/go/pkg/mod/google.golang.org/[email protected]/server.go:1400\ngoogle.golang.org/grpc.(*Server).handleStream\n\t/home/runner/go/pkg/mod/google.golang.org/[email protected]/server.go:1810\ngoogle.golang.org/grpc.(*Server).serveStreams.func2.1\n\t/home/runner/go/pkg/mod/google.golang.org/[email protected]/server.go:1030"}

Steps to Reproduce the Problem

1. Upgrade to 1.27.0 from 1.26.2

Specifications

• Version: 1.27.0
• Platform:

[jeenadeepak]

@yycptt : Any update on this, I am facing same issue after upgrade.

[jeenadeepak]

Temporal history Error:

{"level":"info","ts":"2025-02-24T09:55:48.092Z","msg":"none","shard-id":205,"address":"10.11.82.208:7234","lifecycle":"Started","component":"shard-context","logging-call-at":"/home/runner/work/docker-builds/docker-builds/temporal/service/history/shard/context_impl.go:1631"}
{"level":"error","ts":"2025-02-24T09:55:48.092Z","msg":"Update workflow execution operation failed.","shard-id":205,"address":"10.11.82.208:7234","wf-namespace-id":"7d67fc38-8f86-484a-a1ee-cdaf4dcfa498","wf-id":"FBCAR5BOS0VIBTOG","wf-run-id":"2b8fbd29-ab84-40aa-ac59-ada2c6e1bf33","store-operation":"update-wf-execution","error":"assertCurrentExecution failed. Unable to load current record. Error: sql: Scan error on column index 10, name "data_encoding": converting NULL to string is unsupported","logging-call-at":"/home/runner/work/docker-builds/docker-builds/temporal/service/history/workflow/transaction_impl.go:510","stacktrace":"go.temporal.io/server/common/log.(*zapLogger).Error\n\t/home/runner/work/docker-builds/docker-builds/temporal/common/log/zap_logger.go:154\ngo.temporal.io/server/service/history/workflow.updateWorkflowExecution\n\t/home/runner/work/docker-builds/docker-builds/temporal/service/history/workflow/transaction_impl.go:510\ngo.temporal.io/server/service/history/workflow.(*TransactionImpl).UpdateWorkflowExecution\n\t/home/runner/work/docker-builds/docker-builds/temporal/service/history/workflow/transaction_impl.go:188\ngo.temporal.io/server/service/history/workflow.(*ContextImpl).UpdateWorkflowExecutionWithNew\n\t/home/runner/work/docker-builds/docker-builds/temporal/service/history/workflow/context.go:654\ngo.temporal.io/server/service/history/workflow.(*ContextImpl).UpdateWorkflowExecutionAsActive\n\t/home/runner/work/docker-builds/docker-builds/temporal/service/history/workflow/context.go:502\ngo.temporal.io/server/service/history/api.UpdateWorkflowWithNew\n\t/home/runner/work/docker-builds/docker-builds/temporal/service/history/api/update_workflow_util.go:138\ngo.temporal.io/server/service/history/api.GetAndUpdateWorkflowWithNew\n\t/home/runner/work/docker-builds/docker-builds/temporal/service/history/api/update_workflow_util.go:59\ngo.temporal.io/server/service/history/api/recordactivitytaskstarted.Invoke\n\t/home/runner/work/docker-builds/docker-builds/temporal/service/history/api/recordactivitytaskstarted/api.go:62\ngo.temporal.io/server/service/history.(*historyEngineImpl).RecordActivityTaskStarted\n\t/home/runner/work/docker-builds/docker-builds/temporal/service/history/history_engine.go:534\ngo.temporal.io/server/service/history.(*Handler).RecordActivityTaskStarted\n\t/home/runner/work/docker-builds/docker-builds/temporal/service/history/handler.go:342\ngo.temporal.io/server/api/historyservice/v1._HistoryService_RecordActivityTaskStarted_Handler.func1\n\t/home/runner/work/docker-builds/docker-builds/temporal/api/historyservice/v1/service_grpc.pb.go:1677\ngo.temporal.io/server/common/rpc/interceptor.(*RetryableInterceptor).Intercept.func1\n\t/home/runner/work/docker-builds/docker-builds/temporal/common/rpc/interceptor/retry.go:62\ngo.temporal.io/server/common/backoff.ThrottleRetryContext\n\t/home/runner/work/docker-builds/docker-builds/temporal/common/backoff/retry.go:89\ngo.temporal.io/server/common/rpc/interceptor.(*RetryableInterceptor).Intercept\n\t/home/runner/work/docker-builds/docker-builds/temporal/common/rpc/interceptor/retry.go:66\ngoogle.golang.org/grpc.getChainUnaryHandler.func1\n\t/home/runner/go/pkg/mod/google.golang.org/[email protected]/server.go:1212\ngo.temporal.io/server/common/rpc/interceptor.(*RateLimitInterceptor).Intercept\n\t/home/runner/work/docker-builds/docker-builds/temporal/common/rpc/interceptor/rate_limit.go:88\ngoogle.golang.org/grpc.getChainUnaryHandler.func1\n\t/home/runner/go/pkg/mod/google.golang.org/[email protected]/server.go:1212\ngo.temporal.io/server/common/rpc/interceptor.(*TelemetryInterceptor).UnaryIntercept\n\t/home/runner/work/docker-builds/docker-builds/temporal/common/rpc/interceptor/telemetry.go:197\ngoogle.golang.org/grpc.getChainUnaryHandler.func1\n\t/home/runner/go/pkg/mod/google.golang.org/[email protected]/server.go:1212\ngo.temporal.io/server/service.GrpcServerOptionsProvider.getUnaryInterceptors.NewServerMetricsTrailerPropagatorInterceptor.func6\n\t/home/runner/work/docker-builds/docker-builds/temporal/common/metrics/grpc.go:112\ngoogle.golang.org/grpc.getChainUnaryHandler.func1\n\t/home/runner/go/pkg/mod/google.golang.org/[email protected]/server.go:1212\ngo.temporal.io/server/service.GrpcServerOptionsProvider.getUnaryInterceptors.NewServerMetricsContextInjectorInterceptor.func5\n\t/home/runner/work/docker-builds/docker-builds/temporal/common/metrics/grpc.go:65\ngoogle.golang.org/grpc.getChainUnaryHandler.func1\n\t/home/runner/go/pkg/mod/google.golang.org/[email protected]/server.go:1212\ngo.temporal.io/server/common/rpc.ServiceErrorInterceptor\n\t/home/runner/work/docker-builds/docker-builds/temporal/common/rpc/grpc.go:157\ngoogle.golang.org/grpc.NewServer.chainUnaryServerInterceptors.chainUnaryInterceptors.func1\n\t/home/runner/go/pkg/mod/google.golang.org/[email protected]/server.go:1203\ngo.temporal.io/server/api/historyservice/v1._HistoryService_RecordActivityTaskStarted_Handler\n\t/home/runner/work/docker-builds/docker-builds/temporal/api/historyservice/v1/service_grpc.pb.go:1679\ngoogle.golang.org/grpc.(*Server).processUnaryRPC\n\t/home/runner/go/pkg/mod/google.golang.org/[email protected]/server.go:1400\ngoogle.golang.org/grpc.(*Server).handleStream\n\t/home/runner/go/pkg/mod/google.golang.org/[email protected]/server.go:1810\ngoogle.golang.org/grpc.(*Server).serveStreams.func2.1\n\t/home/runner/go/pkg/mod/google.golang.org/[email protected]/server.go:1030"}

Temporal matching error:

{"level":"info","ts":"2025-02-24T09:58:52.737Z","msg":"history client encountered error","service":"matching","error":"assertCurrentExecution failed. Unable to load current record. Error: sql: Scan error on column index 10, name "data_encoding": converting NULL to string is unsupported","service-error-type":"serviceerror.Unavailable","logging-call-at":"/home/runner/work/docker-builds/docker-builds/temporal/client/history/metric_client.go:103"}
{"level":"info","ts":"2025-02-24T09:58:52.771Z","msg":"history client encountered error","service":"matching","error":"assertCurrentExecution failed. Unable to load current record. Error: sql: Scan error on column index 10, name "data_encoding": converting NULL to string is unsupported","service-error-type":"serviceerror.Unavailable","logging-call-at":"/home/runner/work/docker-builds/docker-builds/temporal/client/history/metric_client.go:103"}

Also there is spike in database wait time and CPU, sharing screenshot for reference, below screenshot is for 90 minute, I have updated temporal 75 minute ago.

[danieljoos]

We're seeing the same error in our testing environment.

I believe it was introduced with #7080 as it adds the data_encoding column to the current_executions table as nullable.

However, the model in Go uses a string for that column. This fails to unmarshal when fetching a NULL value from the DB.

Pausing the upgrade to 1.27 for now.

[makholm]

Seeing the same thing here...

There seems to be some inconsistencies in the schema definitions as well...

Migrations for sqlite, mysql and postgresql all migrated to a nullable current_executions.data_encoding column:

https://github.com/temporalio/temporal/blob/main/schema/sqlite/v3/temporal/versioned/v0.7/add_current_executions_data.sql
https://github.com/temporalio/temporal/blob/main/schema/mysql/v8/temporal/versioned/v1.15/add_current_executions_data.sql
https://github.com/temporalio/temporal/blob/main/schema/postgresql/v12/temporal/versioned/v1.15/add_current_executions_data.sql

...but in the full schema definitions, current_executions.data_encoding is NOT NULL for sqlite:

https://github.com/temporalio/temporal/blob/main/schema/sqlite/v3/temporal/schema.sql#L59

...but nullable for mysql and postgresql:

https://github.com/temporalio/temporal/blob/main/schema/mysql/v8/temporal/schema.sql#L60
https://github.com/temporalio/temporal/blob/main/schema/postgresql/v12/temporal/schema.sql#L60

[saz]

There's a PR to resolve this issue.