airbyte-server StatusRuntimeException: DEADLINE_EXCEEDED on Initial Deployment

nullmaxwell commented 1 year ago

Environment

Airbyte version: v0.40.17

OS Version / Instance: Ubuntu 20.04.5

Additional info:

OS: Ubuntu 20.04.5 LTS x86_64
Kernel: 5.4.0-125-generic
CPU: 11th Gen Intel i9-11900K (16) @ 5.100GHz
Memory: 26046MiB / 64187MiB

Deployment: Docker version 20.10.18
Source Connector and version: N/A
Destination Connector and version: N/A
Step where the error happened: Deployment

Current Behavior

airbyte-server container hangs on grpc.StatusRuntimeException: DEADLINE_EXCEEDED as a result of i.t.i.r.GrpcSyncRetryer(retry):56 - Retrying after failure which stalls the UI with the "Cannot reach server" splash page.

Expected Behavior

airbyte-server should create the GRPC client, initialize the temporal namespace default and finish deploying.

Logs

From airbyte-server container:

2022-10-26 17:55:43,319 main INFO Loading mask data from '/seed/specs_secrets_mask.yaml
2022-10-26 17:55:43 INFO i.a.c.EnvConfigs(getEnvOrDefault):1079 - Using default value for environment variable CONFIG_DATABASE_USER: 'docker'
2022-10-26 17:55:43 INFO i.a.c.EnvConfigs(getEnvOrDefault):1079 - Using default value for environment variable CONFIG_DATABASE_PASSWORD: '*****'
2022-10-26 17:55:43 INFO i.a.c.EnvConfigs(getEnvOrDefault):1079 - Using default value for environment variable CONFIG_DATABASE_URL: 'jdbc:postgresql://db:5432/airbyte'
2022-10-26 17:55:43 INFO c.z.h.HikariDataSource(<init>):80 - HikariPool-1 - Starting...
2022-10-26 17:55:43 INFO c.z.h.HikariDataSource(<init>):82 - HikariPool-1 - Start completed.
2022-10-26 17:55:43 INFO c.z.h.HikariDataSource(<init>):80 - HikariPool-2 - Starting...
2022-10-26 17:55:43 INFO c.z.h.HikariDataSource(<init>):82 - HikariPool-2 - Start completed.
2022-10-26 17:55:43 INFO i.a.c.EnvConfigs(getEnvOrDefault):1079 - Using default value for environment variable WORKER_ENVIRONMENT: 'DOCKER'
2022-10-26 17:55:43 INFO i.a.s.ServerApp(getServer):179 - Checking databases..
2022-10-26 17:55:43 INFO i.a.s.ServerApp(assertDatabasesReady):156 - Checking configs database flyway migration version..
2022-10-26 17:55:43 INFO i.a.c.EnvConfigs(getEnvOrDefault):1079 - Using default value for environment variable CONFIGS_DATABASE_INITIALIZATION_TIMEOUT_MS: '60000'
2022-10-26 17:55:43 WARN i.a.d.c.DatabaseAvailabilityCheck(check):38 - Waiting for database to become available...
2022-10-26 17:55:43 INFO i.a.d.c.DatabaseAvailabilityCheck(lambda$isDatabaseConnected$1):75 - Testing airbyte configs database connection...
2022-10-26 17:55:44 INFO i.a.d.c.DatabaseAvailabilityCheck(check):57 - Database available.
2022-10-26 17:55:44 INFO o.f.c.i.l.s.Slf4jLog(info):37 - Flyway Community Edition 8.5.13 by Redgate
2022-10-26 17:55:44 INFO o.f.c.i.l.s.Slf4jLog(info):37 - See what's new here: https://flywaydb.org/documentation/learnmore/releaseNotes#8.5.13
2022-10-26 17:55:44 INFO o.f.c.i.l.s.Slf4jLog(info):37 - 
2022-10-26 17:55:44 INFO o.f.c.i.l.s.Slf4jLog(info):37 - Database: jdbc:postgresql://db:5432/airbyte (PostgreSQL 13.8)
2022-10-26 17:55:44 INFO o.f.c.i.l.s.Slf4jLog(info):37 - Flyway Community Edition 8.5.13 by Redgate
2022-10-26 17:55:44 INFO o.f.c.i.l.s.Slf4jLog(info):37 - See what's new here: https://flywaydb.org/documentation/learnmore/releaseNotes#8.5.13
2022-10-26 17:55:44 INFO o.f.c.i.l.s.Slf4jLog(info):37 - 
2022-10-26 17:55:44 INFO i.a.d.c.DatabaseMigrationCheck(check):46 - Current database migration version 0.40.12.001.
2022-10-26 17:55:44 INFO i.a.d.c.DatabaseMigrationCheck(check):47 - Minimum Flyway version required 0.35.15.001.
2022-10-26 17:55:44 INFO i.a.d.c.DatabaseMigrationCheck(check):62 - Verified that database has been migrated to the required minimum version 60000.
2022-10-26 17:55:44 INFO i.a.s.ServerApp(assertDatabasesReady):162 - Checking jobs database flyway migration version..
2022-10-26 17:55:44 INFO i.a.c.EnvConfigs(getEnvOrDefault):1079 - Using default value for environment variable JOBS_DATABASE_INITIALIZATION_TIMEOUT_MS: '60000'
2022-10-26 17:55:44 WARN i.a.d.c.DatabaseAvailabilityCheck(check):38 - Waiting for database to become available...
2022-10-26 17:55:44 INFO i.a.d.c.DatabaseAvailabilityCheck(lambda$isDatabaseConnected$1):75 - Testing airbyte jobs database connection...
2022-10-26 17:55:44 INFO i.a.d.c.DatabaseAvailabilityCheck(check):57 - Database available.
2022-10-26 17:55:44 INFO o.f.c.i.l.s.Slf4jLog(info):37 - Flyway Community Edition 8.5.13 by Redgate
2022-10-26 17:55:44 INFO o.f.c.i.l.s.Slf4jLog(info):37 - See what's new here: https://flywaydb.org/documentation/learnmore/releaseNotes#8.5.13
2022-10-26 17:55:44 INFO o.f.c.i.l.s.Slf4jLog(info):37 - 
2022-10-26 17:55:44 INFO o.f.c.i.l.s.Slf4jLog(info):37 - Database: jdbc:postgresql://db:5432/airbyte (PostgreSQL 13.8)
2022-10-26 17:55:44 INFO o.f.c.i.l.s.Slf4jLog(info):37 - Flyway Community Edition 8.5.13 by Redgate
2022-10-26 17:55:44 INFO o.f.c.i.l.s.Slf4jLog(info):37 - See what's new here: https://flywaydb.org/documentation/learnmore/releaseNotes#8.5.13
2022-10-26 17:55:44 INFO o.f.c.i.l.s.Slf4jLog(info):37 - 
2022-10-26 17:55:44 INFO i.a.d.c.DatabaseMigrationCheck(check):46 - Current database migration version 0.40.14.001.
2022-10-26 17:55:44 INFO i.a.d.c.DatabaseMigrationCheck(check):47 - Minimum Flyway version required 0.29.15.001.
2022-10-26 17:55:44 INFO i.a.d.c.DatabaseMigrationCheck(check):62 - Verified that database has been migrated to the required minimum version 60000.
2022-10-26 17:55:44 INFO i.a.s.ServerApp(getServer):182 - Creating config repository...
2022-10-26 17:55:44 INFO i.a.c.EnvConfigs(getEnvOrDefault):1079 - Using default value for environment variable SECRET_PERSISTENCE: 'TESTING_CONFIG_DB_TABLE'
2022-10-26 17:55:44 INFO i.a.c.EnvConfigs(getEnvOrDefault):1079 - Using default value for environment variable SECRET_PERSISTENCE: 'TESTING_CONFIG_DB_TABLE'
2022-10-26 17:55:44 INFO i.a.c.EnvConfigs(getEnvOrDefault):1079 - Using default value for environment variable SECRET_PERSISTENCE: 'TESTING_CONFIG_DB_TABLE'
2022-10-26 17:55:44 INFO i.a.s.ServerApp(getServer):196 - Creating jobs persistence...
2022-10-26 17:55:44 INFO i.a.c.EnvConfigs(getEnvOrDefault):1079 - Using default value for environment variable DEPLOYMENT_MODE: 'OSS'
2022-10-26 17:55:44 INFO i.a.c.EnvConfigs(getEnvOrDefault):1079 - Using default value for environment variable WORKER_ENVIRONMENT: 'DOCKER'
2022-10-26 17:55:44 INFO i.a.c.EnvConfigs(getEnvOrDefault):1079 - Using default value for environment variable DEPLOYMENT_MODE: 'OSS'
2022-10-26 17:55:44 INFO i.a.c.EnvConfigs(getEnvOrDefault):1079 - Using default value for environment variable TEMPORAL_CLOUD_CLIENT_CERT: ''
2022-10-26 17:55:44 INFO i.a.c.EnvConfigs(getEnvOrDefault):1079 - Using default value for environment variable TEMPORAL_CLOUD_CLIENT_KEY: ''
2022-10-26 17:55:44 INFO i.a.c.EnvConfigs(getEnvOrDefault):1079 - Using default value for environment variable TEMPORAL_CLOUD_ENABLED: 'false'
2022-10-26 17:55:44 INFO i.a.c.EnvConfigs(getEnvOrDefault):1079 - Using default value for environment variable TEMPORAL_CLOUD_HOST: ''
2022-10-26 17:55:44 INFO i.a.c.EnvConfigs(getEnvOrDefault):1079 - Using default value for environment variable TEMPORAL_CLOUD_NAMESPACE: ''
2022-10-26 17:55:44 INFO i.a.c.EnvConfigs(getEnvOrDefault):1079 - Using default value for environment variable TEMPORAL_HISTORY_RETENTION_IN_DAYS: '30'
2022-10-26 17:55:44 INFO i.a.c.t.TemporalUtils(getTemporalClientWhenConnected):224 - Waiting for temporal server...
2022-10-26 17:55:44 WARN i.a.c.t.TemporalUtils(getTemporalClientWhenConnected):235 - Waiting for namespace default to be initialized in temporal...
2022-10-26 17:55:51 WARN i.t.i.r.GrpcSyncRetryer(retry):56 - Retrying after failure
io.grpc.StatusRuntimeException: DEADLINE_EXCEEDED: Deadline exceeded after 4.992691438s. 
    at io.grpc.stub.ClientCalls.toStatusRuntimeException(ClientCalls.java:271) ~[grpc-stub-1.49.0.jar:1.49.0]
    at io.grpc.stub.ClientCalls.getUnchecked(ClientCalls.java:252) ~[grpc-stub-1.49.0.jar:1.49.0]
    at io.grpc.stub.ClientCalls.blockingUnaryCall(ClientCalls.java:165) ~[grpc-stub-1.49.0.jar:1.49.0]
    at io.grpc.health.v1.HealthGrpc$HealthBlockingStub.check(HealthGrpc.java:252) ~[grpc-services-1.49.0.jar:1.49.0]
    at io.temporal.serviceclient.WorkflowServiceStubsImpl.lambda$checkHealth$2(WorkflowServiceStubsImpl.java:286) ~[temporal-serviceclient-1.8.1.jar:?]
    at io.temporal.internal.retryer.GrpcSyncRetryer.retry(GrpcSyncRetryer.java:61) ~[temporal-serviceclient-1.8.1.jar:?]
    at io.temporal.internal.retryer.GrpcRetryer.retryWithResult(GrpcRetryer.java:51) ~[temporal-serviceclient-1.8.1.jar:?]
    at io.temporal.serviceclient.WorkflowServiceStubsImpl.checkHealth(WorkflowServiceStubsImpl.java:279) ~[temporal-serviceclient-1.8.1.jar:?]
    at io.temporal.serviceclient.WorkflowServiceStubsImpl.<init>(WorkflowServiceStubsImpl.java:186) ~[temporal-serviceclient-1.8.1.jar:?]
    at io.temporal.serviceclient.WorkflowServiceStubs.newInstance(WorkflowServiceStubs.java:51) ~[temporal-serviceclient-1.8.1.jar:?]
    at io.temporal.serviceclient.WorkflowServiceStubs.newInstance(WorkflowServiceStubs.java:41) ~[temporal-serviceclient-1.8.1.jar:?]
    at io.airbyte.commons.temporal.TemporalUtils.lambda$createTemporalService$0(TemporalUtils.java:96) ~[io.airbyte-airbyte-commons-temporal-0.40.17.jar:?]
    at io.airbyte.commons.temporal.TemporalUtils.getTemporalClientWhenConnected(TemporalUtils.java:240) ~[io.airbyte-airbyte-commons-temporal-0.40.17.jar:?]
    at io.airbyte.commons.temporal.TemporalUtils.createTemporalService(TemporalUtils.java:92) ~[io.airbyte-airbyte-commons-temporal-0.40.17.jar:?]
    at io.airbyte.commons.temporal.TemporalUtils.createTemporalService(TemporalUtils.java:107) ~[io.airbyte-airbyte-commons-temporal-0.40.17.jar:?]
    at io.airbyte.commons.temporal.TemporalUtils.createTemporalService(TemporalUtils.java:111) ~[io.airbyte-airbyte-commons-temporal-0.40.17.jar:?]
    at io.airbyte.server.ServerApp.getServer(ServerApp.java:232) ~[io.airbyte-airbyte-server-0.40.17.jar:?]
    at io.airbyte.server.ServerApp.main(ServerApp.java:323) ~[io.airbyte-airbyte-server-0.40.17.jar:?]

Steps to Reproduce

git clone https://github.com/airbytehq/airbyte.git
cd air byte
docker-compose up -d

Are you willing to submit a PR?

Yes

Additional Notes:

The following issues mention similar behavior as a result of a heartbeat failure (ActivityExecutionContextImpl(doHeartBeat):153 - Heartbeat failed) :

4975
6417
10053

Error messages are looking similar to that of those mentioned in the following comment that references issues #4536 and #6417: https://github.com/airbytehq/airbyte/issues/4975#issuecomment-981645888

However, the main issue I am experiencing is unrelated to a heartbeat failure, suggesting this as not a duplicate of #4975, #6417, or #10053.

This discussion thread is also relevant.

Each of these issues were closed with the suggestion of upgrading to the latest version/release or increasing the amount of resources, however, doing either seems to have made no difference in standing up a deployment.

Troubleshooting Performed

Deployment on another machine I have deployed the equivalent Airbyte version on a smaller machine with less resources using the same environment without any issues.
- Airbyte version: v0.40.17
- OS Version / Instance: Ubuntu 20.04.5
  - Additional info:
```
OS: Ubuntu 20.04.5 LTS x86_64
Host: 10M2S0A200 ThinkCentre M715q
Kernel: 5.4.0-131-generic
CPU: AMD PRO A10-8770E R7 4C+6G (4) @ 2.800GHz
Memory: 1833MiB / 6962MiB
```
- Deployment: Docker version 20.10.18
- Source Connector and version: N/A
- Destination Connector and version: N/A

Asserting no memory limit on containers $ docker stats --no-stream

CONTAINER ID   NAME                                         CPU %     MEM USAGE / LIMIT     MEM %     NET I/O           BLOCK I/O         PIDS
97e16f2b5c50   airbyte-proxy                                0.00%     4.547MiB / 62.68GiB   0.01%     8.09kB / 0B       0B / 16.4kB       3
b4369b8d499c   airbyte-worker                               0.53%     342.6MiB / 62.68GiB   0.53%     19kB / 18.5kB     0B / 393kB        99
fe09701dced9   airbyte-webapp                               0.00%     15.08MiB / 62.68GiB   0.02%     4.25kB / 0B       0B / 8.19kB       17
bfced5e6bbf1   airbyte-cron                                 0.75%     313.1MiB / 62.68GiB   0.49%     17.2kB / 16.9kB   0B / 393kB        85
133a2f8e9af6   airbyte-db                                   0.42%     95.16MiB / 62.68GiB   0.15%     1.08MB / 993kB    0B / 5.05MB       49
73ff9391bd9a   airbyte-temporal                             1.37%     61.62MiB / 62.68GiB   0.10%     289kB / 403kB     401kB / 16.4kB    21
db4c2ffabe3f   airbyte-server                               0.66%     282.9MiB / 62.68GiB   0.44%     45.7kB / 37.3kB   0B / 197kB        67

Ensuring no memory limit set within repository's .env

...
### JOBS ###
# Relevant to scaling.
SYNC_JOB_MAX_ATTEMPTS=3
SYNC_JOB_MAX_TIMEOUT_DAYS=3
JOB_MAIN_CONTAINER_CPU_REQUEST=
JOB_MAIN_CONTAINER_CPU_LIMIT=
JOB_MAIN_CONTAINER_MEMORY_REQUEST=
JOB_MAIN_CONTAINER_MEMORY_LIMIT=

NORMALIZATION_JOB_MAIN_CONTAINER_MEMORY_LIMIT=
NORMALIZATION_JOB_MAIN_CONTAINER_MEMORY_REQUEST=
NORMALIZATION_JOB_MAIN_CONTAINER_CPU_LIMIT=
NORMALIZATION_JOB_MAIN_CONTAINER_CPU_REQUEST=

### LOGGING/MONITORING/TRACKING ###
TRACKING_STRATEGY=segment
JOB_ERROR_REPORTING_STRATEGY=logging
# Although not present as an env var, expected by Log4J configuration.
LOG_LEVEL=INFO

### APPLICATIONS ###
# Worker #
WORKERS_MICRONAUT_ENVIRONMENTS=control-plane
# Cron #
CRON_MICRONAUT_ENVIRONMENTS=control-plane
# Relevant to scaling.
MAX_SYNC_WORKERS=5
MAX_SPEC_WORKERS=5
MAX_CHECK_WORKERS=5
MAX_DISCOVER_WORKERS=5
# Temporal Activity configuration
ACTIVITY_MAX_ATTEMPT=
ACTIVITY_INITIAL_DELAY_BETWEEN_ATTEMPTS_SECONDS=
ACTIVITY_MAX_DELAY_BETWEEN_ATTEMPTS_SECONDS=
WORKFLOW_FAILURE_RESTART_DELAY_SECONDS=
...

While is genuinely unclear to me what the problem could be, any help would be greatly appreciated as I would love to experiment with Airbyte more.

sh4sh commented 1 year ago

Hey @nullmaxwell , do you have any failure logs from the temporal container?

nullmaxwell commented 1 year ago

@sh4sh here's a log dump from the airbyte-temporal after reproducing the error this AM:

Start init
t
Waiting for PostgreSQL to startup.
PostgreSQL started.
touch: CONTAINER_ALREADY_STARTED_PLACEHOLDER: Permission denied
2022-10-31T15:18:40.539Z    INFO    Starting schema setup   {"config": {"SchemaFilePath":"","InitialVersion":"0.0","Overwrite":false,"DisableVersioning":false}, "logging-call-at": "setuptask.go:57"}
2022-10-31T15:18:40.539Z    DEBUG   Setting up version tables   {"logging-call-at": "setuptask.go:67"}
2022-10-31T15:18:40.545Z    DEBUG   Setting initial schema version to 0.0   {"logging-call-at": "setuptask.go:118"}
2022-10-31T15:18:40.545Z    DEBUG   Updating schema update log  {"logging-call-at": "setuptask.go:123"}
2022-10-31T15:18:40.546Z    INFO    Schema setup complete   {"logging-call-at": "setuptask.go:131"}
2022-10-31T15:18:40.632Z    INFO    Starting schema setup   {"config": {"SchemaFilePath":"","InitialVersion":"0.0","Overwrite":false,"DisableVersioning":false}, "logging-call-at": "setuptask.go:57"}
2022-10-31T15:18:40.632Z    DEBUG   Setting up version tables   {"logging-call-at": "setuptask.go:67"}
2022-10-31T15:18:40.638Z    DEBUG   Setting initial schema version to 0.0   {"logging-call-at": "setuptask.go:118"}
2022-10-31T15:18:40.638Z    DEBUG   Updating schema update log  {"logging-call-at": "setuptask.go:123"}
2022-10-31T15:18:40.639Z    INFO    Schema setup complete   {"logging-call-at": "setuptask.go:131"}
Starting to update the temporal DB
2022-10-31T15:18:40.647Z    INFO    UpdateSchemeTask started    {"config": {"DBName":"","TargetVersion":"","SchemaDir":"/etc/temporal/schema/postgresql/v96/temporal/versioned","IsDryRun":false}, "logging-call-at": "updatetask.go:98"}
2022-10-31T15:18:40.650Z    DEBUG   ---- Executing updates for version 1.0 ---- {"logging-call-at": "updatetask.go:151"}
2022-10-31T15:18:40.651Z    DEBUG   CREATE TABLE namespaces(partition_id INTEGER NOT NULL,id BYTEA NOT NULL,name VARCHAR(255) UNIQUE NOT NULL,notification_version BIGINT NOT NULL,data BYTEA NOT NULL,data_encoding VARCHAR(16) NOT NULL,is_global BOOLEAN NOT NULL,PRIMARY KEY(partition_id, id));    {"logging-call-at": "updatetask.go:153"}
2022-10-31T15:18:40.656Z    DEBUG   CREATE TABLE namespace_metadata (partition_id INTEGER NOT NULL,notification_version BIGINT NOT NULL,PRIMARY KEY(partition_id)); {"logging-call-at": "updatetask.go:153"}
2022-10-31T15:18:40.657Z    DEBUG   INSERT INTO namespace_metadata (partition_id, notification_version) VALUES (54321, 1);  {"logging-call-at": "updatetask.go:153"}
2022-10-31T15:18:40.658Z    DEBUG   CREATE TABLE shards (shard_id INTEGER NOT NULL,range_id BIGINT NOT NULL,data BYTEA NOT NULL,data_encoding VARCHAR(16) NOT NULL,PRIMARY KEY (shard_id)); {"logging-call-at": "updatetask.go:153"}
2022-10-31T15:18:40.660Z    DEBUG   CREATE TABLE transfer_tasks(shard_id INTEGER NOT NULL,task_id BIGINT NOT NULL,data BYTEA NOT NULL,data_encoding VARCHAR(16) NOT NULL,PRIMARY KEY (shard_id, task_id));  {"logging-call-at": "updatetask.go:153"}
2022-10-31T15:18:40.663Z    DEBUG   CREATE TABLE executions(shard_id INTEGER NOT NULL,namespace_id BYTEA NOT NULL,workflow_id VARCHAR(255) NOT NULL,run_id BYTEA NOT NULL,next_event_id BIGINT NOT NULL,last_write_version BIGINT NOT NULL,data BYTEA NOT NULL,data_encoding VARCHAR(16) NOT NULL,state BYTEA NOT NULL,state_encoding VARCHAR(16) NOT NULL,PRIMARY KEY (shard_id, namespace_id, workflow_id, run_id));  {"logging-call-at": "updatetask.go:153"}
2022-10-31T15:18:40.667Z    DEBUG   CREATE TABLE current_executions(shard_id INTEGER NOT NULL,namespace_id BYTEA NOT NULL,workflow_id VARCHAR(255) NOT NULL,run_id BYTEA NOT NULL,create_request_id VARCHAR(64) NOT NULL,state INTEGER NOT NULL,status INTEGER NOT NULL,start_version BIGINT NOT NULL,last_write_version BIGINT NOT NULL,PRIMARY KEY (shard_id, namespace_id, workflow_id));    {"logging-call-at": "updatetask.go:153"}
2022-10-31T15:18:40.669Z    DEBUG   CREATE TABLE buffered_events (shard_id INTEGER NOT NULL,namespace_id BYTEA NOT NULL,workflow_id VARCHAR(255) NOT NULL,run_id BYTEA NOT NULL,id BIGSERIAL NOT NULL UNIQUE,data BYTEA NOT NULL,data_encoding VARCHAR(16) NOT NULL,PRIMARY KEY (shard_id, namespace_id, workflow_id, run_id, id)); {"logging-call-at": "updatetask.go:153"}
2022-10-31T15:18:40.674Z    DEBUG   CREATE TABLE tasks (range_hash BIGINT NOT NULL,task_queue_id BYTEA NOT NULL,task_id BIGINT NOT NULL,data BYTEA NOT NULL,data_encoding VARCHAR(16) NOT NULL,PRIMARY KEY (range_hash, task_queue_id, task_id));   {"logging-call-at": "updatetask.go:153"}
2022-10-31T15:18:40.676Z    DEBUG   CREATE TABLE task_queues (range_hash BIGINT NOT NULL,task_queue_id BYTEA NOT NULL,range_id BIGINT NOT NULL,data BYTEA NOT NULL,data_encoding VARCHAR(16) NOT NULL,PRIMARY KEY (range_hash, task_queue_id)); {"logging-call-at": "updatetask.go:153"}
2022-10-31T15:18:40.679Z    DEBUG   CREATE TABLE replication_tasks (shard_id INTEGER NOT NULL,task_id BIGINT NOT NULL,data BYTEA NOT NULL,data_encoding VARCHAR(16) NOT NULL,PRIMARY KEY (shard_id, task_id));  {"logging-call-at": "updatetask.go:153"}
2022-10-31T15:18:40.681Z    DEBUG   CREATE TABLE replication_tasks_dlq (source_cluster_name VARCHAR(255) NOT NULL,shard_id INTEGER NOT NULL,task_id BIGINT NOT NULL,data BYTEA NOT NULL,data_encoding VARCHAR(16) NOT NULL,PRIMARY KEY (source_cluster_name, shard_id, task_id));   {"logging-call-at": "updatetask.go:153"}
2022-10-31T15:18:40.684Z    DEBUG   CREATE TABLE timer_tasks (shard_id INTEGER NOT NULL,visibility_timestamp TIMESTAMP NOT NULL,task_id BIGINT NOT NULL,data BYTEA NOT NULL,data_encoding VARCHAR(16) NOT NULL,PRIMARY KEY (shard_id, visibility_timestamp, task_id));  {"logging-call-at": "updatetask.go:153"}
2022-10-31T15:18:40.687Z    DEBUG   CREATE TABLE activity_info_maps (shard_id INTEGER NOT NULL,namespace_id BYTEA NOT NULL,workflow_id VARCHAR(255) NOT NULL,run_id BYTEA NOT NULL,schedule_id BIGINT NOT NULL,data BYTEA NOT NULL,data_encoding VARCHAR(16),PRIMARY KEY (shard_id, namespace_id, workflow_id, run_id, schedule_id));   {"logging-call-at": "updatetask.go:153"}
2022-10-31T15:18:40.689Z    DEBUG   CREATE TABLE timer_info_maps (shard_id INTEGER NOT NULL,namespace_id BYTEA NOT NULL,workflow_id VARCHAR(255) NOT NULL,run_id BYTEA NOT NULL,timer_id VARCHAR(255) NOT NULL,data BYTEA NOT NULL,data_encoding VARCHAR(16),PRIMARY KEY (shard_id, namespace_id, workflow_id, run_id, timer_id));  {"logging-call-at": "updatetask.go:153"}
2022-10-31T15:18:40.692Z    DEBUG   CREATE TABLE child_execution_info_maps (shard_id INTEGER NOT NULL,namespace_id BYTEA NOT NULL,workflow_id VARCHAR(255) NOT NULL,run_id BYTEA NOT NULL,initiated_id BIGINT NOT NULL,data BYTEA NOT NULL,data_encoding VARCHAR(16),PRIMARY KEY (shard_id, namespace_id, workflow_id, run_id, initiated_id));  {"logging-call-at": "updatetask.go:153"}
2022-10-31T15:18:40.695Z    DEBUG   CREATE TABLE request_cancel_info_maps (shard_id INTEGER NOT NULL,namespace_id BYTEA NOT NULL,workflow_id VARCHAR(255) NOT NULL,run_id BYTEA NOT NULL,initiated_id BIGINT NOT NULL,data BYTEA NOT NULL,data_encoding VARCHAR(16),PRIMARY KEY (shard_id, namespace_id, workflow_id, run_id, initiated_id));   {"logging-call-at": "updatetask.go:153"}
2022-10-31T15:18:40.698Z    DEBUG   CREATE TABLE signal_info_maps (shard_id INTEGER NOT NULL,namespace_id BYTEA NOT NULL,workflow_id VARCHAR(255) NOT NULL,run_id BYTEA NOT NULL,initiated_id BIGINT NOT NULL,data BYTEA NOT NULL,data_encoding VARCHAR(16),PRIMARY KEY (shard_id, namespace_id, workflow_id, run_id, initiated_id));   {"logging-call-at": "updatetask.go:153"}
2022-10-31T15:18:40.701Z    DEBUG   CREATE TABLE signals_requested_sets (shard_id INTEGER NOT NULL,namespace_id BYTEA NOT NULL,workflow_id VARCHAR(255) NOT NULL,run_id BYTEA NOT NULL,signal_id VARCHAR(64) NOT NULL,PRIMARY KEY (shard_id, namespace_id, workflow_id, run_id, signal_id));    {"logging-call-at": "updatetask.go:153"}
2022-10-31T15:18:40.704Z    DEBUG   CREATE TABLE history_node (shard_id INTEGER NOT NULL,tree_id BYTEA NOT NULL,branch_id BYTEA NOT NULL,node_id BIGINT NOT NULL,txn_id BIGINT NOT NULL,data BYTEA NOT NULL,data_encoding VARCHAR(16) NOT NULL,PRIMARY KEY (shard_id, tree_id, branch_id, node_id, txn_id));    {"logging-call-at": "updatetask.go:153"}
2022-10-31T15:18:40.707Z    DEBUG   CREATE TABLE history_tree (shard_id INTEGER NOT NULL,tree_id BYTEA NOT NULL,branch_id BYTEA NOT NULL,data BYTEA NOT NULL,data_encoding VARCHAR(16) NOT NULL,PRIMARY KEY (shard_id, tree_id, branch_id));    {"logging-call-at": "updatetask.go:153"}
2022-10-31T15:18:40.710Z    DEBUG   CREATE TABLE queue (queue_type INTEGER NOT NULL,message_id BIGINT NOT NULL,message_payload BYTEA NOT NULL,PRIMARY KEY(queue_type, message_id)); {"logging-call-at": "updatetask.go:153"}
2022-10-31T15:18:40.712Z    DEBUG   CREATE TABLE queue_metadata (queue_type INTEGER NOT NULL,data BYTEA NOT NULL,PRIMARY KEY(queue_type));  {"logging-call-at": "updatetask.go:153"}
2022-10-31T15:18:40.715Z    DEBUG   CREATE TABLE cluster_metadata (metadata_partition INTEGER NOT NULL,immutable_data BYTEA NOT NULL,immutable_data_encoding VARCHAR(16) NOT NULL,PRIMARY KEY(metadata_partition)); {"logging-call-at": "updatetask.go:153"}
2022-10-31T15:18:40.718Z    DEBUG   CREATE TABLE cluster_membership(membership_partition INTEGER NOT NULL,host_id BYTEA NOT NULL,rpc_address VARCHAR(15) NOT NULL,rpc_port SMALLINT NOT NULL,role SMALLINT NOT NULL,session_start TIMESTAMP DEFAULT '1970-01-01 00:00:01',last_heartbeat TIMESTAMP DEFAULT '1970-01-01 00:00:01',record_expiry TIMESTAMP DEFAULT '1970-01-01 00:00:01',PRIMARY KEY (membership_partition, host_id));    {"logging-call-at": "updatetask.go:153"}
2022-10-31T15:18:40.721Z    DEBUG   CREATE UNIQUE INDEX cm_idx_rolehost ON cluster_membership (role, host_id);  {"logging-call-at": "updatetask.go:153"}
2022-10-31T15:18:40.722Z    DEBUG   CREATE INDEX cm_idx_rolelasthb ON cluster_membership (role, last_heartbeat);    {"logging-call-at": "updatetask.go:153"}
2022-10-31T15:18:40.724Z    DEBUG   CREATE INDEX cm_idx_rpchost ON cluster_membership (rpc_address, role);  {"logging-call-at": "updatetask.go:153"}
2022-10-31T15:18:40.725Z    DEBUG   CREATE INDEX cm_idx_lasthb ON cluster_membership (last_heartbeat);  {"logging-call-at": "updatetask.go:153"}
2022-10-31T15:18:40.726Z    DEBUG   CREATE INDEX cm_idx_recordexpiry ON cluster_membership (record_expiry); {"logging-call-at": "updatetask.go:153"}
2022-10-31T15:18:40.728Z    DEBUG   ---- Done ----  {"logging-call-at": "updatetask.go:159"}
2022-10-31T15:18:40.729Z    DEBUG   Schema updated from 0.0 to 1.0  {"logging-call-at": "updatetask.go:143"}
2022-10-31T15:18:40.729Z    DEBUG   ---- Executing updates for version 1.1 ---- {"logging-call-at": "updatetask.go:151"}
2022-10-31T15:18:40.729Z    DEBUG   ALTER TABLE cluster_metadata ADD data BYTEA NOT NULL DEFAULT '';    {"logging-call-at": "updatetask.go:153"}
2022-10-31T15:18:40.729Z    DEBUG   ALTER TABLE cluster_metadata ADD data_encoding VARCHAR(16) NOT NULL DEFAULT 'Proto3';   {"logging-call-at": "updatetask.go:153"}
2022-10-31T15:18:40.730Z    DEBUG   ALTER TABLE cluster_metadata ADD version BIGINT NOT NULL DEFAULT 1; {"logging-call-at": "updatetask.go:153"}
2022-10-31T15:18:40.731Z    DEBUG   ---- Done ----  {"logging-call-at": "updatetask.go:159"}
2022-10-31T15:18:40.732Z    DEBUG   Schema updated from 1.0 to 1.1  {"logging-call-at": "updatetask.go:143"}
2022-10-31T15:18:40.732Z    DEBUG   ---- Executing updates for version 1.2 ---- {"logging-call-at": "updatetask.go:151"}
2022-10-31T15:18:40.732Z    DEBUG   ALTER TABLE queue ADD message_encoding VARCHAR(16) NOT NULL DEFAULT 'Json'; {"logging-call-at": "updatetask.go:153"}
2022-10-31T15:18:40.733Z    DEBUG   ALTER TABLE queue_metadata ADD data_encoding VARCHAR(16) NOT NULL DEFAULT 'Json';   {"logging-call-at": "updatetask.go:153"}
2022-10-31T15:18:40.733Z    DEBUG   ---- Done ----  {"logging-call-at": "updatetask.go:159"}
2022-10-31T15:18:40.734Z    DEBUG   Schema updated from 1.1 to 1.2  {"logging-call-at": "updatetask.go:143"}
2022-10-31T15:18:40.734Z    DEBUG   ---- Executing updates for version 1.3 ---- {"logging-call-at": "updatetask.go:151"}
2022-10-31T15:18:40.734Z    DEBUG   CREATE TABLE visibility_tasks(shard_id INTEGER NOT NULL,task_id BIGINT NOT NULL,data BYTEA NOT NULL,data_encoding VARCHAR(16) NOT NULL,PRIMARY KEY (shard_id, task_id));    {"logging-call-at": "updatetask.go:153"}
2022-10-31T15:18:40.737Z    DEBUG   ---- Done ----  {"logging-call-at": "updatetask.go:159"}
2022-10-31T15:18:40.738Z    DEBUG   Schema updated from 1.2 to 1.3  {"logging-call-at": "updatetask.go:143"}
2022-10-31T15:18:40.738Z    DEBUG   ---- Executing updates for version 1.4 ---- {"logging-call-at": "updatetask.go:151"}
2022-10-31T15:18:40.738Z    DEBUG   ALTER TABLE cluster_metadata DROP immutable_data;   {"logging-call-at": "updatetask.go:153"}
2022-10-31T15:18:40.739Z    DEBUG   ALTER TABLE cluster_metadata DROP immutable_data_encoding;  {"logging-call-at": "updatetask.go:153"}
2022-10-31T15:18:40.739Z    DEBUG   ---- Done ----  {"logging-call-at": "updatetask.go:159"}
2022-10-31T15:18:40.740Z    DEBUG   Schema updated from 1.3 to 1.4  {"logging-call-at": "updatetask.go:143"}
2022-10-31T15:18:40.740Z    DEBUG   ---- Executing updates for version 1.5 ---- {"logging-call-at": "updatetask.go:151"}
2022-10-31T15:18:40.740Z    DEBUG   ALTER TABLE history_node ADD prev_txn_id BIGINT NOT NULL DEFAULT 0; {"logging-call-at": "updatetask.go:153"}
2022-10-31T15:18:40.741Z    DEBUG   ALTER TABLE executions ADD db_record_version BIGINT NOT NULL DEFAULT 0; {"logging-call-at": "updatetask.go:153"}
2022-10-31T15:18:40.741Z    DEBUG   ALTER TABLE cluster_membership ALTER COLUMN rpc_address TYPE VARCHAR(128);  {"logging-call-at": "updatetask.go:153"}
2022-10-31T15:18:40.742Z    DEBUG   ---- Done ----  {"logging-call-at": "updatetask.go:159"}
2022-10-31T15:18:40.743Z    DEBUG   Schema updated from 1.4 to 1.5  {"logging-call-at": "updatetask.go:143"}
2022-10-31T15:18:40.743Z    DEBUG   ---- Executing updates for version 1.6 ---- {"logging-call-at": "updatetask.go:151"}
2022-10-31T15:18:40.743Z    DEBUG   ALTER TABLE queue_metadata ADD version BIGINT NOT NULL DEFAULT 0;   {"logging-call-at": "updatetask.go:153"}
2022-10-31T15:18:40.744Z    DEBUG   ---- Done ----  {"logging-call-at": "updatetask.go:159"}
2022-10-31T15:18:40.745Z    DEBUG   Schema updated from 1.5 to 1.6  {"logging-call-at": "updatetask.go:143"}
2022-10-31T15:18:40.745Z    INFO    UpdateSchemeTask done   {"logging-call-at": "updatetask.go:121"}
Update the temporal DB is done
Starting to update the temporal visibility DB
2022-10-31T15:18:40.753Z    INFO    UpdateSchemeTask started    {"config": {"DBName":"","TargetVersion":"","SchemaDir":"/etc/temporal/schema/postgresql/v96/visibility/versioned","IsDryRun":false}, "logging-call-at": "updatetask.go:98"}
2022-10-31T15:18:40.755Z    DEBUG   ---- Executing updates for version 1.0 ---- {"logging-call-at": "updatetask.go:151"}
2022-10-31T15:18:40.755Z    DEBUG   CREATE TABLE executions_visibility (namespace_id CHAR(64) NOT NULL,run_id CHAR(64) NOT NULL,start_time TIMESTAMP NOT NULL,execution_time TIMESTAMP NOT NULL,workflow_id VARCHAR(255) NOT NULL,workflow_type_name VARCHAR(255) NOT NULL,status INTEGER NOT NULL, close_time TIMESTAMP NULL,history_length BIGINT,memo BYTEA,encoding VARCHAR(64) NOT NULL,task_queue VARCHAR(255) DEFAULT '' NOT NULL,PRIMARY KEY (namespace_id, run_id));   {"logging-call-at": "updatetask.go:153"}
2022-10-31T15:18:40.759Z    DEBUG   CREATE INDEX by_type_start_time ON executions_visibility (namespace_id, workflow_type_name, status, start_time DESC, run_id);   {"logging-call-at": "updatetask.go:153"}
2022-10-31T15:18:40.761Z    DEBUG   CREATE INDEX by_workflow_id_start_time ON executions_visibility (namespace_id, workflow_id, status, start_time DESC, run_id);   {"logging-call-at": "updatetask.go:153"}
2022-10-31T15:18:40.763Z    DEBUG   CREATE INDEX by_status_by_start_time ON executions_visibility (namespace_id, status, start_time DESC, run_id);  {"logging-call-at": "updatetask.go:153"}
2022-10-31T15:18:40.764Z    DEBUG   CREATE INDEX by_type_close_time ON executions_visibility (namespace_id, workflow_type_name, status, close_time DESC, run_id);   {"logging-call-at": "updatetask.go:153"}
2022-10-31T15:18:40.766Z    DEBUG   CREATE INDEX by_workflow_id_close_time ON executions_visibility (namespace_id, workflow_id, status, close_time DESC, run_id);   {"logging-call-at": "updatetask.go:153"}
2022-10-31T15:18:40.767Z    DEBUG   CREATE INDEX by_status_by_close_time ON executions_visibility (namespace_id, status, close_time DESC, run_id);  {"logging-call-at": "updatetask.go:153"}
2022-10-31T15:18:40.769Z    DEBUG   ---- Done ----  {"logging-call-at": "updatetask.go:159"}
2022-10-31T15:18:40.770Z    DEBUG   Schema updated from 0.0 to 1.0  {"logging-call-at": "updatetask.go:143"}
2022-10-31T15:18:40.770Z    DEBUG   ---- Executing updates for version 1.1 ---- {"logging-call-at": "updatetask.go:151"}
2022-10-31T15:18:40.770Z    DEBUG   CREATE INDEX by_close_time_by_status ON executions_visibility (namespace_id, close_time DESC, run_id, status);  {"logging-call-at": "updatetask.go:153"}
2022-10-31T15:18:40.771Z    DEBUG   ---- Done ----  {"logging-call-at": "updatetask.go:159"}
2022-10-31T15:18:40.772Z    DEBUG   Schema updated from 1.0 to 1.1  {"logging-call-at": "updatetask.go:143"}
2022-10-31T15:18:40.772Z    INFO    UpdateSchemeTask done   {"logging-call-at": "updatetask.go:121"}
Update the temporal visibility DB is done
starting temporal server
Temporal CLI address: 172.25.0.6:7233.
2022/10/31 15:18:40 Loading config; env=docker,zone=,configDir=config
2022/10/31 15:18:40 Loading config files=[config/docker.yaml]
Waiting for Temporal server to start...
{"level":"info","ts":"2022-10-31T15:18:40.790Z","msg":"Updated dynamic config","logging-call-at":"file_based_client.go:143"}
{"level":"info","ts":"2022-10-31T15:18:40.790Z","msg":"Starting server for services","value":["history","matching","frontend","worker"],"logging-call-at":"server.go:123"}
{"level":"info","ts":"2022-10-31T15:18:40.797Z","msg":"PProf not started due to port not set","logging-call-at":"pprof.go:67"}
{"level":"info","ts":"2022-10-31T15:18:40.800Z","msg":"Successfully saved cluster metadata.","component":"metadata-initializer","logging-call-at":"server.go:526"}
[Fx] SUPPLY *resource.BootstrapParams
[Fx] SUPPLY chan struct {}
[Fx] PROVIDE    *client.factoryImpl <= go.temporal.io/server/common/persistence/client.NewFactoryImplProvider()
[Fx] PROVIDE    client.Factory <= go.temporal.io/server/common/persistence/client.BindFactory()
[Fx] PROVIDE    resource.SnTaggedLogger <= go.temporal.io/server/common/resource.SnTaggedLoggerProvider()
[Fx] PROVIDE    resource.ThrottledLogger <= go.temporal.io/server/common/resource.ThrottledLoggerProvider()
[Fx] PROVIDE    *config.Persistence <= go.temporal.io/server/common/resource.PersistenceConfigProvider()
[Fx] PROVIDE    tally.Scope <= go.temporal.io/server/common/resource.MetricsScopeProvider()
[Fx] PROVIDE    resource.HostName <= go.temporal.io/server/common/resource.HostNameProvider()
[Fx] PROVIDE    resource.ServiceName <= go.temporal.io/server/common/resource.ServiceNameProvider()
[Fx] PROVIDE    cluster.Metadata <= go.temporal.io/server/common/resource.ClusterMetadataProvider()
[Fx] PROVIDE    *config.ClusterMetadata <= go.temporal.io/server/common/resource.ClusterMetadataConfigProvider()
[Fx] PROVIDE    clock.TimeSource <= go.temporal.io/server/common/resource.TimeSourceProvider()
[Fx] PROVIDE    persistence.ClusterMetadataManager <= go.temporal.io/server/common/resource.ClusterMetadataManagerProvider()
[Fx] PROVIDE    resolver.ServiceResolver <= go.temporal.io/server/common/resource.PersistenceServiceResolverProvider()
[Fx] PROVIDE    client.AbstractDataStoreFactory <= go.temporal.io/server/common/resource.AbstractDatastoreFactoryProvider()
[Fx] PROVIDE    client.ClusterName <= go.temporal.io/server/common/resource.ClusterNameProvider()
[Fx] PROVIDE    metrics.Client <= go.temporal.io/server/common/resource.MetricsClientProvider()
[Fx] PROVIDE    searchattribute.Provider <= go.temporal.io/server/common/resource.SearchAttributeProviderProvider()
[Fx] PROVIDE    searchattribute.Manager <= go.temporal.io/server/common/resource.SearchAttributeManagerProvider()
[Fx] PROVIDE    searchattribute.Mapper <= go.temporal.io/server/common/resource.SearchAttributeMapperProvider()
[Fx] PROVIDE    persistence.MetadataManager <= go.temporal.io/server/common/resource.MetadataManagerProvider()
[Fx] PROVIDE    namespace.Registry <= go.temporal.io/server/common/resource.NamespaceCacheProvider()
[Fx] PROVIDE    serialization.Serializer <= go.temporal.io/server/common/persistence/serialization.NewSerializer()
[Fx] PROVIDE    archiver.ArchivalMetadata <= go.temporal.io/server/common/resource.ArchivalMetadataProvider()
[Fx] PROVIDE    provider.ArchiverProvider <= go.temporal.io/server/common/resource.ArchiverProviderProvider()
[Fx] PROVIDE    *archiver.HistoryBootstrapContainer <= go.temporal.io/server/common/resource.HistoryBootstrapContainerProvider()
[Fx] PROVIDE    *archiver.VisibilityBootstrapContainer <= go.temporal.io/server/common/resource.VisibilityBootstrapContainerProvider()
[Fx] PROVIDE    client.Bean <= go.temporal.io/server/common/resource.PersistenceBeanProvider()
[Fx] PROVIDE    resource.MembershipMonitorFactory <= go.temporal.io/server/common/resource.MembershipFactoryProvider()
[Fx] PROVIDE    membership.Monitor <= go.temporal.io/server/common/resource.MembershipMonitorProvider()
[Fx] PROVIDE    client.FactoryProvider <= go.temporal.io/server/common/resource.ClientFactoryProvider()
[Fx] PROVIDE    client.Bean <= go.temporal.io/server/common/resource.ClientBeanProvider()
[Fx] PROVIDE    client.Client <= go.temporal.io/server/common/resource.SdkClientProvider()
[Fx] PROVIDE    workflowservice.WorkflowServiceClient <= go.temporal.io/server/common/resource.FrontedClientProvider()
[Fx] PROVIDE    *client.FaultInjectionDataStoreFactory <= go.temporal.io/server/common/resource.PersistenceFaultInjectionFactoryProvider()
[Fx] PROVIDE    net.Listener <= go.temporal.io/server/common/resource.GrpcListenerProvider()
[Fx] PROVIDE    resource.InstanceID <= go.temporal.io/server/common/resource.InstanceIDProvider()
[Fx] PROVIDE    *tchannel.Channel <= go.temporal.io/server/common/resource.RingpopChannelProvider()
[Fx] PROVIDE    *metrics.RuntimeMetricsReporter <= go.temporal.io/server/common/resource.RuntimeMetricsReporterProvider()
[Fx] PROVIDE    resource.Resource <= go.temporal.io/server/common/resource.NewFromDI()
[Fx] PROVIDE    workflow.NewCacheFn <= go.temporal.io/server/service/history/workflow.NewCacheFnProvider()
[Fx] PROVIDE    log.Logger <= go.temporal.io/server/service/history.ParamsExpandProvider()
[Fx] PROVIDE    dynamicconfig.Client <= go.temporal.io/server/service/history.ParamsExpandProvider()
[Fx] PROVIDE    config.Persistence <= go.temporal.io/server/service/history.ParamsExpandProvider()
[Fx] PROVIDE    *client.Config <= go.temporal.io/server/service/history.ParamsExpandProvider()
[Fx] PROVIDE    common.RPCFactory <= go.temporal.io/server/service/history.ParamsExpandProvider()
[Fx] PROVIDE    *dynamicconfig.Collection <= go.temporal.io/server/common/dynamicconfig.NewCollection()
[Fx] PROVIDE    *configs.Config <= go.temporal.io/server/service/history.ConfigProvider()
[Fx] PROVIDE    *interceptor.TelemetryInterceptor <= go.temporal.io/server/service/history.TelemetryInterceptorProvider()
[Fx] PROVIDE    *interceptor.RateLimitInterceptor <= go.temporal.io/server/service/history.RateLimitInterceptorProvider()
[Fx] PROVIDE    []grpc.ServerOption <= go.temporal.io/server/service.GrpcServerOptionsProvider()
[Fx] PROVIDE    *elasticsearch.ProcessorConfig <= go.temporal.io/server/service/history.ESProcessorConfigProvider()
[Fx] PROVIDE    manager.VisibilityManager <= go.temporal.io/server/service/history.VisibilityManagerProvider()
[Fx] PROVIDE    resource.ThrottledLoggerRpsFn <= go.temporal.io/server/service/history.ThrottledLoggerRpsFnProvider()
[Fx] PROVIDE    client.PersistenceMaxQps <= go.temporal.io/server/service/history.PersistenceMaxQpsProvider()
[Fx] PROVIDE    *history.Service <= go.temporal.io/server/service/history.NewService()
[Fx] PROVIDE    fx.Lifecycle <= go.uber.org/fx.New.func1()
[Fx] PROVIDE    fx.Shutdowner <= go.uber.org/fx.(*App).shutdowner-fm()
[Fx] PROVIDE    fx.DotGraph <= go.uber.org/fx.(*App).dotGraph-fm()
[Fx] INVOKE     go.temporal.io/server/common/resource.RegisterBootstrapContainer()
{"level":"info","ts":"2022-10-31T15:18:40.805Z","msg":"Get dynamic config","name":"history.persistenceMaxQPS","value":3000,"default-value":9000,"logging-call-at":"config.go:79"}
[Fx] INVOKE     go.temporal.io/server/service/history.ServiceLifetimeHooks()
{"level":"info","ts":"2022-10-31T15:18:40.809Z","msg":"Get dynamic config","name":"system.enableRingpopTLS","value":false,"default-value":false,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.810Z","msg":"Get dynamic config","name":"history.throttledLogRPS","value":4,"default-value":4,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.810Z","msg":"Created gRPC listener","service":"history","address":"172.25.0.6:7234","logging-call-at":"rpc.go:139"}
{"level":"info","ts":"2022-10-31T15:18:40.810Z","msg":"Get dynamic config","name":"history.rps","value":3000,"default-value":3000,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.811Z","msg":"Get dynamic config","name":"system.standardVisibilityPersistenceMaxReadQPS","value":9000,"default-value":9000,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.811Z","msg":"Get dynamic config","name":"system.standardVisibilityPersistenceMaxWriteQPS","value":9000,"default-value":9000,"logging-call-at":"config.go:79"}
[Fx] HOOK OnStart       go.temporal.io/server/service/history.ServiceLifetimeHooks.func1() executing (caller: go.temporal.io/server/service/history.ServiceLifetimeHooks)
[Fx] HOOK OnStart       go.temporal.io/server/service/history.ServiceLifetimeHooks.func1() called by go.temporal.io/server/service/history.ServiceLifetimeHooks ran successfully in 3.84µs
[Fx] RUNNING
{"level":"info","ts":"2022-10-31T15:18:40.812Z","msg":"Get dynamic config","name":"system.enableDBRecordVersion","value":true,"default-value":true,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.812Z","msg":"history starting","service":"history","logging-call-at":"service.go:88"}
{"level":"info","ts":"2022-10-31T15:18:40.812Z","msg":"RuntimeMetricsReporter started","service":"history","logging-call-at":"runtime.go:154"}
[Fx] SUPPLY *resource.BootstrapParams
[Fx] SUPPLY chan struct {}
[Fx] PROVIDE    log.Logger <= go.temporal.io/server/service/matching.ParamsExpandProvider()
[Fx] PROVIDE    dynamicconfig.Client <= go.temporal.io/server/service/matching.ParamsExpandProvider()
[Fx] PROVIDE    config.Persistence <= go.temporal.io/server/service/matching.ParamsExpandProvider()
[Fx] PROVIDE    *client.Config <= go.temporal.io/server/service/matching.ParamsExpandProvider()
[Fx] PROVIDE    common.RPCFactory <= go.temporal.io/server/service/matching.ParamsExpandProvider()
[Fx] PROVIDE    *dynamicconfig.Collection <= go.temporal.io/server/common/dynamicconfig.NewCollection()
[Fx] PROVIDE    *matching.Config <= go.temporal.io/server/service/matching.NewConfig()
[Fx] PROVIDE    client.PersistenceMaxQps <= go.temporal.io/server/service/matching.PersistenceMaxQpsProvider()
[Fx] PROVIDE    resource.ThrottledLoggerRpsFn <= go.temporal.io/server/service/matching.ThrottledLoggerRpsFnProvider()
[Fx] PROVIDE    *interceptor.TelemetryInterceptor <= go.temporal.io/server/service/matching.TelemetryInterceptorProvider()
[Fx] PROVIDE    *interceptor.RateLimitInterceptor <= go.temporal.io/server/service/matching.RateLimitInterceptorProvider()
[Fx] PROVIDE    []grpc.ServerOption <= go.temporal.io/server/service.GrpcServerOptionsProvider()
[Fx] PROVIDE    *client.factoryImpl <= go.temporal.io/server/common/persistence/client.NewFactoryImplProvider()
[Fx] PROVIDE    client.Factory <= go.temporal.io/server/common/persistence/client.BindFactory()
[Fx] PROVIDE    resource.SnTaggedLogger <= go.temporal.io/server/common/resource.SnTaggedLoggerProvider()
[Fx] PROVIDE    resource.ThrottledLogger <= go.temporal.io/server/common/resource.ThrottledLoggerProvider()
[Fx] PROVIDE    *config.Persistence <= go.temporal.io/server/common/resource.PersistenceConfigProvider()
[Fx] PROVIDE    tally.Scope <= go.temporal.io/server/common/resource.MetricsScopeProvider()
[Fx] PROVIDE    resource.HostName <= go.temporal.io/server/common/resource.HostNameProvider()
[Fx] PROVIDE    resource.ServiceName <= go.temporal.io/server/common/resource.ServiceNameProvider()
[Fx] PROVIDE    cluster.Metadata <= go.temporal.io/server/common/resource.ClusterMetadataProvider()
[Fx] PROVIDE    *config.ClusterMetadata <= go.temporal.io/server/common/resource.ClusterMetadataConfigProvider()
[Fx] PROVIDE    clock.TimeSource <= go.temporal.io/server/common/resource.TimeSourceProvider()
[Fx] PROVIDE    persistence.ClusterMetadataManager <= go.temporal.io/server/common/resource.ClusterMetadataManagerProvider()
[Fx] PROVIDE    resolver.ServiceResolver <= go.temporal.io/server/common/resource.PersistenceServiceResolverProvider()
[Fx] PROVIDE    client.AbstractDataStoreFactory <= go.temporal.io/server/common/resource.AbstractDatastoreFactoryProvider()
[Fx] PROVIDE    client.ClusterName <= go.temporal.io/server/common/resource.ClusterNameProvider()
[Fx] PROVIDE    metrics.Client <= go.temporal.io/server/common/resource.MetricsClientProvider()
[Fx] PROVIDE    searchattribute.Provider <= go.temporal.io/server/common/resource.SearchAttributeProviderProvider()
[Fx] PROVIDE    searchattribute.Manager <= go.temporal.io/server/common/resource.SearchAttributeManagerProvider()
[Fx] PROVIDE    searchattribute.Mapper <= go.temporal.io/server/common/resource.SearchAttributeMapperProvider()
[Fx] PROVIDE    persistence.MetadataManager <= go.temporal.io/server/common/resource.MetadataManagerProvider()
[Fx] PROVIDE    namespace.Registry <= go.temporal.io/server/common/resource.NamespaceCacheProvider()
[Fx] PROVIDE    serialization.Serializer <= go.temporal.io/server/common/persistence/serialization.NewSerializer()
[Fx] PROVIDE    archiver.ArchivalMetadata <= go.temporal.io/server/common/resource.ArchivalMetadataProvider()
[Fx] PROVIDE    provider.ArchiverProvider <= go.temporal.io/server/common/resource.ArchiverProviderProvider()
[Fx] PROVIDE    *archiver.HistoryBootstrapContainer <= go.temporal.io/server/common/resource.HistoryBootstrapContainerProvider()
[Fx] PROVIDE    *archiver.VisibilityBootstrapContainer <= go.temporal.io/server/common/resource.VisibilityBootstrapContainerProvider()
[Fx] PROVIDE    client.Bean <= go.temporal.io/server/common/resource.PersistenceBeanProvider()
[Fx] PROVIDE    resource.MembershipMonitorFactory <= go.temporal.io/server/common/resource.MembershipFactoryProvider()
[Fx] PROVIDE    membership.Monitor <= go.temporal.io/server/common/resource.MembershipMonitorProvider()
[Fx] PROVIDE    client.FactoryProvider <= go.temporal.io/server/common/resource.ClientFactoryProvider()
[Fx] PROVIDE    client.Bean <= go.temporal.io/server/common/resource.ClientBeanProvider()
[Fx] PROVIDE    client.Client <= go.temporal.io/server/common/resource.SdkClientProvider()
[Fx] PROVIDE    workflowservice.WorkflowServiceClient <= go.temporal.io/server/common/resource.FrontedClientProvider()
[Fx] PROVIDE    *client.FaultInjectionDataStoreFactory <= go.temporal.io/server/common/resource.PersistenceFaultInjectionFactoryProvider()
[Fx] PROVIDE    net.Listener <= go.temporal.io/server/common/resource.GrpcListenerProvider()
[Fx] PROVIDE    resource.InstanceID <= go.temporal.io/server/common/resource.InstanceIDProvider()
[Fx] PROVIDE    *tchannel.Channel <= go.temporal.io/server/common/resource.RingpopChannelProvider()
[Fx] PROVIDE    *metrics.RuntimeMetricsReporter <= go.temporal.io/server/common/resource.RuntimeMetricsReporterProvider()
[Fx] PROVIDE    resource.Resource <= go.temporal.io/server/common/resource.NewFromDI()
[Fx] PROVIDE    *matching.Service <= go.temporal.io/server/service/matching.ServiceProvider()
[Fx] PROVIDE    fx.Lifecycle <= go.uber.org/fx.New.func1()
[Fx] PROVIDE    fx.Shutdowner <= go.uber.org/fx.(*App).shutdowner-fm()
[Fx] PROVIDE    fx.DotGraph <= go.uber.org/fx.(*App).dotGraph-fm()
[Fx] INVOKE     go.temporal.io/server/common/resource.RegisterBootstrapContainer()
{"level":"info","ts":"2022-10-31T15:18:40.813Z","msg":"Get dynamic config","name":"matching.persistenceMaxQPS","value":3000,"default-value":3000,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.813Z","msg":"Membership heartbeat upserted successfully","service":"history","address":"172.25.0.6","port":6934,"hostId":"4cf9606c-592f-11ed-927c-0242ac190006","logging-call-at":"rpMonitor.go:222"}
{"level":"info","ts":"2022-10-31T15:18:40.814Z","msg":"bootstrap hosts fetched","service":"history","bootstrap-hostports":"172.25.0.6:6934","logging-call-at":"rpMonitor.go:263"}
{"level":"info","ts":"2022-10-31T15:18:40.814Z","msg":"Current reachable members","service":"history","component":"service-resolver","service":"history","addresses":["172.25.0.6:7234"],"logging-call-at":"rpServiceResolver.go:266"}
{"level":"info","ts":"2022-10-31T15:18:40.816Z","msg":"Service resources started","service":"history","address":"172.25.0.6:7234","logging-call-at":"resourceImpl.go:398"}
{"level":"info","ts":"2022-10-31T15:18:40.816Z","msg":"Replication task fetchers started.","service":"history","logging-call-at":"replicationTaskFetcher.go:155"}
{"level":"info","ts":"2022-10-31T15:18:40.816Z","msg":"Get dynamic config","name":"system.enablePriorityTaskProcessor","value":false,"default-value":false,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.816Z","msg":"Get dynamic config","name":"history.acquireShardConcurrency","value":10,"default-value":10,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.816Z","msg":"none","service":"history","shard-id":1,"address":"172.25.0.6:7234","shard-item":"0xc00003ab80","lifecycle":"Started","component":"shard-item","logging-call-at":"controller_impl.go:265"}
{"level":"info","ts":"2022-10-31T15:18:40.816Z","msg":"none","service":"history","shard-id":1,"address":"172.25.0.6:7234","shard-item":"0xc00003ab80","lifecycle":"Starting","component":"shard-engine","logging-call-at":"controller_impl.go:425"}
{"level":"info","ts":"2022-10-31T15:18:40.816Z","msg":"none","service":"history","shard-id":2,"address":"172.25.0.6:7234","shard-item":"0xc00003ad80","lifecycle":"Started","component":"shard-item","logging-call-at":"controller_impl.go:265"}
{"level":"info","ts":"2022-10-31T15:18:40.816Z","msg":"none","service":"history","shard-id":2,"address":"172.25.0.6:7234","shard-item":"0xc00003ad80","lifecycle":"Starting","component":"shard-engine","logging-call-at":"controller_impl.go:425"}
{"level":"info","ts":"2022-10-31T15:18:40.816Z","msg":"none","service":"history","shard-id":4,"address":"172.25.0.6:7234","shard-item":"0xc000816400","lifecycle":"Started","component":"shard-item","logging-call-at":"controller_impl.go:265"}
{"level":"info","ts":"2022-10-31T15:18:40.816Z","msg":"none","service":"history","shard-id":4,"address":"172.25.0.6:7234","shard-item":"0xc000816400","lifecycle":"Starting","component":"shard-engine","logging-call-at":"controller_impl.go:425"}
{"level":"info","ts":"2022-10-31T15:18:40.816Z","msg":"none","service":"history","shard-id":3,"address":"172.25.0.6:7234","shard-item":"0xc000816600","lifecycle":"Started","component":"shard-item","logging-call-at":"controller_impl.go:265"}
{"level":"info","ts":"2022-10-31T15:18:40.816Z","msg":"none","service":"history","shard-id":3,"address":"172.25.0.6:7234","shard-item":"0xc000816600","lifecycle":"Starting","component":"shard-engine","logging-call-at":"controller_impl.go:425"}
[Fx] INVOKE     go.temporal.io/server/service/matching.ServiceLifetimeHooks()
{"level":"info","ts":"2022-10-31T15:18:40.817Z","msg":"Get dynamic config","name":"matching.throttledLogRPS","value":20,"default-value":20,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.817Z","msg":"Created gRPC listener","service":"matching","address":"172.25.0.6:7235","logging-call-at":"rpc.go:139"}
{"level":"info","ts":"2022-10-31T15:18:40.817Z","msg":"Get dynamic config","name":"matching.rps","value":1200,"default-value":1200,"logging-call-at":"config.go:79"}
[Fx] HOOK OnStart       go.temporal.io/server/service/matching.ServiceLifetimeHooks.func1() executing (caller: go.temporal.io/server/service/matching.ServiceLifetimeHooks)
[Fx] HOOK OnStart       go.temporal.io/server/service/matching.ServiceLifetimeHooks.func1() called by go.temporal.io/server/service/matching.ServiceLifetimeHooks ran successfully in 1.8µs
[Fx] RUNNING
{"level":"info","ts":"2022-10-31T15:18:40.817Z","msg":"matching starting","service":"matching","logging-call-at":"service.go:117"}
{"level":"info","ts":"2022-10-31T15:18:40.817Z","msg":"RuntimeMetricsReporter started","service":"matching","logging-call-at":"runtime.go:154"}
{"level":"info","ts":"2022-10-31T15:18:40.818Z","msg":"Get dynamic config","name":"history.eventsCacheInitialSize","value":128,"default-value":128,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.818Z","msg":"Get dynamic config","name":"history.eventsCacheMaxSize","value":512,"default-value":512,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.818Z","msg":"Get dynamic config","name":"history.eventsCacheTTL","value":3600,"default-value":3600,"logging-call-at":"config.go:79"}
[Fx] SUPPLY *resource.BootstrapParams
[Fx] SUPPLY chan struct {}
[Fx] PROVIDE    *client.factoryImpl <= go.temporal.io/server/common/persistence/client.NewFactoryImplProvider()
[Fx] PROVIDE    client.Factory <= go.temporal.io/server/common/persistence/client.BindFactory()
[Fx] PROVIDE    resource.SnTaggedLogger <= go.temporal.io/server/common/resource.SnTaggedLoggerProvider()
[Fx] PROVIDE    resource.ThrottledLogger <= go.temporal.io/server/common/resource.ThrottledLoggerProvider()
[Fx] PROVIDE    *config.Persistence <= go.temporal.io/server/common/resource.PersistenceConfigProvider()
[Fx] PROVIDE    tally.Scope <= go.temporal.io/server/common/resource.MetricsScopeProvider()
[Fx] PROVIDE    resource.HostName <= go.temporal.io/server/common/resource.HostNameProvider()
[Fx] PROVIDE    resource.ServiceName <= go.temporal.io/server/common/resource.ServiceNameProvider()
[Fx] PROVIDE    cluster.Metadata <= go.temporal.io/server/common/resource.ClusterMetadataProvider()
[Fx] PROVIDE    *config.ClusterMetadata <= go.temporal.io/server/common/resource.ClusterMetadataConfigProvider()
[Fx] PROVIDE    clock.TimeSource <= go.temporal.io/server/common/resource.TimeSourceProvider()
[Fx] PROVIDE    persistence.ClusterMetadataManager <= go.temporal.io/server/common/resource.ClusterMetadataManagerProvider()
[Fx] PROVIDE    resolver.ServiceResolver <= go.temporal.io/server/common/resource.PersistenceServiceResolverProvider()
[Fx] PROVIDE    client.AbstractDataStoreFactory <= go.temporal.io/server/common/resource.AbstractDatastoreFactoryProvider()
[Fx] PROVIDE    client.ClusterName <= go.temporal.io/server/common/resource.ClusterNameProvider()
[Fx] PROVIDE    metrics.Client <= go.temporal.io/server/common/resource.MetricsClientProvider()
[Fx] PROVIDE    searchattribute.Provider <= go.temporal.io/server/common/resource.SearchAttributeProviderProvider()
[Fx] PROVIDE    searchattribute.Manager <= go.temporal.io/server/common/resource.SearchAttributeManagerProvider()
[Fx] PROVIDE    searchattribute.Mapper <= go.temporal.io/server/common/resource.SearchAttributeMapperProvider()
[Fx] PROVIDE    persistence.MetadataManager <= go.temporal.io/server/common/resource.MetadataManagerProvider()
[Fx] PROVIDE    namespace.Registry <= go.temporal.io/server/common/resource.NamespaceCacheProvider()
[Fx] PROVIDE    serialization.Serializer <= go.temporal.io/server/common/persistence/serialization.NewSerializer()
[Fx] PROVIDE    archiver.ArchivalMetadata <= go.temporal.io/server/common/resource.ArchivalMetadataProvider()
[Fx] PROVIDE    provider.ArchiverProvider <= go.temporal.io/server/common/resource.ArchiverProviderProvider()
[Fx] PROVIDE    *archiver.HistoryBootstrapContainer <= go.temporal.io/server/common/resource.HistoryBootstrapContainerProvider()
[Fx] PROVIDE    *archiver.VisibilityBootstrapContainer <= go.temporal.io/server/common/resource.VisibilityBootstrapContainerProvider()
[Fx] PROVIDE    client.Bean <= go.temporal.io/server/common/resource.PersistenceBeanProvider()
[Fx] PROVIDE    resource.MembershipMonitorFactory <= go.temporal.io/server/common/resource.MembershipFactoryProvider()
[Fx] PROVIDE    membership.Monitor <= go.temporal.io/server/common/resource.MembershipMonitorProvider()
[Fx] PROVIDE    client.FactoryProvider <= go.temporal.io/server/common/resource.ClientFactoryProvider()
[Fx] PROVIDE    client.Bean <= go.temporal.io/server/common/resource.ClientBeanProvider()
[Fx] PROVIDE    client.Client <= go.temporal.io/server/common/resource.SdkClientProvider()
[Fx] PROVIDE    workflowservice.WorkflowServiceClient <= go.temporal.io/server/common/resource.FrontedClientProvider()
[Fx] PROVIDE    *client.FaultInjectionDataStoreFactory <= go.temporal.io/server/common/resource.PersistenceFaultInjectionFactoryProvider()
[Fx] PROVIDE    net.Listener <= go.temporal.io/server/common/resource.GrpcListenerProvider()
[Fx] PROVIDE    resource.InstanceID <= go.temporal.io/server/common/resource.InstanceIDProvider()
[Fx] PROVIDE    *tchannel.Channel <= go.temporal.io/server/common/resource.RingpopChannelProvider()
[Fx] PROVIDE    *metrics.RuntimeMetricsReporter <= go.temporal.io/server/common/resource.RuntimeMetricsReporterProvider()
[Fx] PROVIDE    resource.Resource <= go.temporal.io/server/common/resource.NewFromDI()
[Fx] PROVIDE    log.Logger <= go.temporal.io/server/service/frontend.ParamsExpandProvider()
[Fx] PROVIDE    dynamicconfig.Client <= go.temporal.io/server/service/frontend.ParamsExpandProvider()
[Fx] PROVIDE    config.Persistence <= go.temporal.io/server/service/frontend.ParamsExpandProvider()
[Fx] PROVIDE    *client.Config <= go.temporal.io/server/service/frontend.ParamsExpandProvider()
[Fx] PROVIDE    common.RPCFactory <= go.temporal.io/server/service/frontend.ParamsExpandProvider()
[Fx] PROVIDE    *dynamicconfig.Collection <= go.temporal.io/server/common/dynamicconfig.NewCollection()
[Fx] PROVIDE    *frontend.Config <= go.temporal.io/server/service/frontend.ConfigProvider()
[Fx] PROVIDE    *interceptor.NamespaceLogInterceptor <= go.temporal.io/server/service/frontend.NamespaceLogInterceptorProvider()
[Fx] PROVIDE    *interceptor.TelemetryInterceptor <= go.temporal.io/server/service/frontend.TelemetryInterceptorProvider()
[Fx] PROVIDE    *interceptor.RateLimitInterceptor <= go.temporal.io/server/service/frontend.RateLimitInterceptorProvider()
[Fx] PROVIDE    *interceptor.NamespaceCountLimitInterceptor <= go.temporal.io/server/service/frontend.NamespaceCountLimitInterceptorProvider()
[Fx] PROVIDE    *interceptor.NamespaceRateLimitInterceptor <= go.temporal.io/server/service/frontend.NamespaceRateLimitInterceptorProvider()
[Fx] PROVIDE    []grpc.ServerOption <= go.temporal.io/server/service/frontend.GrpcServerOptionsProvider()
[Fx] PROVIDE    manager.VisibilityManager <= go.temporal.io/server/service/frontend.VisibilityManagerProvider()
[Fx] PROVIDE    resource.ThrottledLoggerRpsFn <= go.temporal.io/server/service/frontend.ThrottledLoggerRpsFnProvider()
[Fx] PROVIDE    client.PersistenceMaxQps <= go.temporal.io/server/service/frontend.PersistenceMaxQpsProvider()
{"level":"info","ts":"2022-10-31T15:18:40.819Z","msg":"Range updated for shardID","service":"history","shard-id":1,"address":"172.25.0.6:7234","shard-item":"0xc00003ab80","shard-range-id":1,"previous-shard-range-id":0,"number":0,"next-number":0,"logging-call-at":"context_impl.go:746"}
{"level":"info","ts":"2022-10-31T15:18:40.819Z","msg":"Acquired shard","service":"history","shard-id":1,"address":"172.25.0.6:7234","shard-item":"0xc00003ab80","logging-call-at":"context_impl.go:1143"}
[Fx] PROVIDE    persistence.NamespaceReplicationQueue <= go.temporal.io/server/service/frontend.NamespaceReplicationQueueProvider()
[Fx] PROVIDE    frontend.Handler <= go.temporal.io/server/service/frontend.HandlerProvider()
{"level":"info","ts":"2022-10-31T15:18:40.819Z","msg":"Get dynamic config","name":"history.cacheInitialSize","value":128,"default-value":128,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.819Z","msg":"Get dynamic config","name":"history.cacheTTL","value":3600,"default-value":3600,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.819Z","msg":"Get dynamic config","name":"history.cacheMaxSize","value":512,"default-value":512,"logging-call-at":"config.go:79"}
[Fx] PROVIDE    *grpc.Server <= go.temporal.io/server/service/frontend.glob..func1()
[Fx] PROVIDE    *frontend.AdminHandler <= go.temporal.io/server/service/frontend.NewAdminHandler()
{"level":"info","ts":"2022-10-31T15:18:40.819Z","msg":"Get dynamic config","name":"history.archiveRequestRPS","value":300,"default-value":300,"logging-call-at":"config.go:79"}
[Fx] PROVIDE    *frontend.VersionChecker <= go.temporal.io/server/service/frontend.NewVersionChecker()
{"level":"info","ts":"2022-10-31T15:18:40.819Z","msg":"Get dynamic config","name":"history.numParentClosePolicySystemWorkflows","value":10,"default-value":10,"logging-call-at":"config.go:79"}
[Fx] PROVIDE    *frontend.Service <= go.temporal.io/server/service/frontend.NewService()
{"level":"info","ts":"2022-10-31T15:18:40.819Z","msg":"Get dynamic config","name":"history.transferProcessorEnablePriorityTaskProcessor","value":false,"default-value":false,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.819Z","msg":"Get dynamic config","name":"history.transferTaskBatchSize","value":100,"default-value":100,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.819Z","msg":"Get dynamic config","name":"history.transferTaskWorkerCount","value":10,"default-value":10,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.819Z","msg":"Get dynamic config","name":"history.transferProcessorMaxPollRPS","value":20,"default-value":20,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.819Z","msg":"Get dynamic config","name":"history.timerProcessorEnablePriorityTaskProcessor","value":false,"default-value":false,"logging-call-at":"config.go:79"}
[Fx] PROVIDE    fx.Lifecycle <= go.uber.org/fx.New.func1()
[Fx] PROVIDE    fx.Shutdowner <= go.uber.org/fx.(*App).shutdowner-fm()
[Fx] PROVIDE    fx.DotGraph <= go.uber.org/fx.(*App).dotGraph-fm()
[Fx] INVOKE     go.temporal.io/server/common/resource.RegisterBootstrapContainer()
{"level":"info","ts":"2022-10-31T15:18:40.819Z","msg":"Get dynamic config","name":"history.timerTaskWorkerCount","value":10,"default-value":10,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.819Z","msg":"Get dynamic config","name":"history.timerTaskBatchSize","value":100,"default-value":100,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.819Z","msg":"Get dynamic config","name":"history.timerProcessorMaxPollRPS","value":20,"default-value":20,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.819Z","msg":"Get dynamic config","name":"history.visibilityProcessorEnablePriorityTaskProcessor","value":false,"default-value":false,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.819Z","msg":"Get dynamic config","name":"history.visibilityTaskBatchSize","value":100,"default-value":100,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.819Z","msg":"Get dynamic config","name":"history.visibilityTaskWorkerCount","value":10,"default-value":10,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.819Z","msg":"Get dynamic config","name":"history.visibilityProcessorMaxPollRPS","value":20,"default-value":20,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.819Z","msg":"Get dynamic config","name":"limit.maxIDLength","value":1000,"default-value":1000,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.819Z","msg":"none","service":"history","shard-id":1,"address":"172.25.0.6:7234","shard-item":"0xc00003ab80","component":"history-engine","lifecycle":"Starting","logging-call-at":"historyEngine.go:281"}
{"level":"info","ts":"2022-10-31T15:18:40.819Z","msg":"none","service":"history","shard-id":1,"address":"172.25.0.6:7234","shard-item":"0xc00003ab80","component":"transfer-queue-processor","cluster-name":"active","lifecycle":"Starting","component":"transfer-queue-processor","logging-call-at":"queueProcessor.go:150"}
{"level":"info","ts":"2022-10-31T15:18:40.819Z","msg":"Task processor started.","service":"history","shard-id":1,"address":"172.25.0.6:7234","shard-item":"0xc00003ab80","component":"transfer-queue-processor","cluster-name":"active","logging-call-at":"taskProcessor.go:147"}
{"level":"info","ts":"2022-10-31T15:18:40.819Z","msg":"none","service":"history","shard-id":1,"address":"172.25.0.6:7234","shard-item":"0xc00003ab80","component":"transfer-queue-processor","cluster-name":"active","lifecycle":"Started","component":"transfer-queue-processor","logging-call-at":"queueProcessor.go:159"}
{"level":"info","ts":"2022-10-31T15:18:40.819Z","msg":"Task processor started.","service":"history","shard-id":1,"address":"172.25.0.6:7234","shard-item":"0xc00003ab80","component":"timer-queue-processor","cluster-name":"active","component":"timer-queue-processor","logging-call-at":"taskProcessor.go:147"}
{"level":"info","ts":"2022-10-31T15:18:40.819Z","msg":"Timer queue processor started.","service":"history","shard-id":1,"address":"172.25.0.6:7234","shard-item":"0xc00003ab80","component":"timer-queue-processor","cluster-name":"active","component":"timer-queue-processor","logging-call-at":"timerQueueProcessorBase.go:165"}
{"level":"info","ts":"2022-10-31T15:18:40.819Z","msg":"none","service":"history","shard-id":1,"address":"172.25.0.6:7234","shard-item":"0xc00003ab80","component":"visibility-queue-processor","lifecycle":"Starting","component":"transfer-queue-processor","logging-call-at":"queueProcessor.go:150"}
{"level":"info","ts":"2022-10-31T15:18:40.819Z","msg":"Task processor started.","service":"history","shard-id":1,"address":"172.25.0.6:7234","shard-item":"0xc00003ab80","component":"visibility-queue-processor","logging-call-at":"taskProcessor.go:147"}
{"level":"info","ts":"2022-10-31T15:18:40.819Z","msg":"none","service":"history","shard-id":1,"address":"172.25.0.6:7234","shard-item":"0xc00003ab80","component":"visibility-queue-processor","lifecycle":"Started","component":"transfer-queue-processor","logging-call-at":"queueProcessor.go:159"}
{"level":"info","ts":"2022-10-31T15:18:40.819Z","msg":"Get dynamic config","name":"frontend.persistenceMaxQPS","value":3000,"default-value":2000,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.819Z","msg":"Get dynamic config","name":"history.shardUpdateMinInterval","value":300,"default-value":300,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.819Z","msg":"Get dynamic config","name":"history.transferProcessorMaxPollInterval","value":60,"default-value":60,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.819Z","msg":"Membership heartbeat upserted successfully","service":"matching","address":"172.25.0.6","port":6935,"hostId":"4cfa789e-592f-11ed-927c-0242ac190006","logging-call-at":"rpMonitor.go:222"}
{"level":"info","ts":"2022-10-31T15:18:40.819Z","msg":"Get dynamic config","name":"history.transferProcessorMaxPollIntervalJitterCoefficient","value":0.15,"default-value":0.15,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.819Z","msg":"Get dynamic config","name":"history.emitShardDiffLog","value":false,"default-value":false,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.819Z","msg":"Get dynamic config","name":"history.visibilityProcessorMaxPollInterval","value":60,"default-value":60,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.819Z","msg":"Get dynamic config","name":"history.transferProcessorCompleteTransferInterval","value":60,"default-value":60,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.819Z","msg":"Get dynamic config","name":"history.transferProcessorUpdateAckInterval","value":30,"default-value":30,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.819Z","msg":"Get dynamic config","name":"history.transferProcessorUpdateAckIntervalJitterCoefficient","value":0.15,"default-value":0.15,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.819Z","msg":"Get dynamic config","name":"history.transferProcessorRedispatchInterval","value":5,"default-value":5,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.819Z","msg":"Get dynamic config","name":"history.transferProcessorRedispatchIntervalJitterCoefficient","value":0.15,"default-value":0.15,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.819Z","msg":"Get dynamic config","name":"history.visibilityProcessorMaxPollIntervalJitterCoefficient","value":0.15,"default-value":0.15,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.819Z","msg":"Get dynamic config","name":"history.visibilityProcessorCompleteTaskInterval","value":60,"default-value":60,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.819Z","msg":"Get dynamic config","name":"history.visibilityProcessorUpdateAckInterval","value":30,"default-value":30,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.819Z","msg":"Get dynamic config","name":"history.visibilityProcessorUpdateAckIntervalJitterCoefficient","value":0.15,"default-value":0.15,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.819Z","msg":"Get dynamic config","name":"history.visibilityProcessorRedispatchInterval","value":5,"default-value":5,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.819Z","msg":"Get dynamic config","name":"history.visibilityProcessorRedispatchIntervalJitterCoefficient","value":0.15,"default-value":0.15,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.819Z","msg":"Get dynamic config","name":"history.timerProcessorCompleteTimerInterval","value":60,"default-value":60,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.819Z","msg":"Get dynamic config","name":"history.timerProcessorMaxPollInterval","value":300,"default-value":300,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.819Z","msg":"Get dynamic config","name":"history.timerProcessorMaxPollIntervalJitterCoefficient","value":0.15,"default-value":0.15,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.819Z","msg":"Get dynamic config","name":"history.timerProcessorUpdateAckInterval","value":30,"default-value":30,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.819Z","msg":"Get dynamic config","name":"history.timerProcessorUpdateAckIntervalJitterCoefficient","value":0.15,"default-value":0.15,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.819Z","msg":"Get dynamic config","name":"history.timerProcessorRedispatchInterval","value":5,"default-value":5,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.819Z","msg":"Get dynamic config","name":"history.timerProcessorRedispatchIntervalJitterCoefficient","value":0.15,"default-value":0.15,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.820Z","msg":"bootstrap hosts fetched","service":"matching","bootstrap-hostports":"172.25.0.6:6934,172.25.0.6:6935","logging-call-at":"rpMonitor.go:263"}
{"level":"info","ts":"2022-10-31T15:18:40.820Z","msg":"none","service":"history","shard-id":1,"address":"172.25.0.6:7234","shard-item":"0xc00003ab80","component":"history-engine","lifecycle":"Started","logging-call-at":"historyEngine.go:300"}
{"level":"info","ts":"2022-10-31T15:18:40.820Z","msg":"none","service":"history","shard-id":1,"address":"172.25.0.6:7234","shard-item":"0xc00003ab80","lifecycle":"Started","component":"shard-engine","logging-call-at":"controller_impl.go:440"}
{"level":"info","ts":"2022-10-31T15:18:40.820Z","msg":"Get dynamic config","name":"history.timerProcessorMaxTimeShift","value":1,"default-value":1,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.821Z","msg":"Range updated for shardID","service":"history","shard-id":3,"address":"172.25.0.6:7234","shard-item":"0xc000816600","shard-range-id":1,"previous-shard-range-id":0,"number":0,"next-number":0,"logging-call-at":"context_impl.go:746"}
{"level":"info","ts":"2022-10-31T15:18:40.821Z","msg":"Acquired shard","service":"history","shard-id":3,"address":"172.25.0.6:7234","shard-item":"0xc000816600","logging-call-at":"context_impl.go:1143"}
{"level":"info","ts":"2022-10-31T15:18:40.821Z","msg":"none","service":"history","shard-id":3,"address":"172.25.0.6:7234","shard-item":"0xc000816600","component":"history-engine","lifecycle":"Starting","logging-call-at":"historyEngine.go:281"}
{"level":"info","ts":"2022-10-31T15:18:40.821Z","msg":"none","service":"history","shard-id":3,"address":"172.25.0.6:7234","shard-item":"0xc000816600","component":"transfer-queue-processor","cluster-name":"active","lifecycle":"Starting","component":"transfer-queue-processor","logging-call-at":"queueProcessor.go:150"}
{"level":"info","ts":"2022-10-31T15:18:40.821Z","msg":"Task processor started.","service":"history","shard-id":3,"address":"172.25.0.6:7234","shard-item":"0xc000816600","component":"transfer-queue-processor","cluster-name":"active","logging-call-at":"taskProcessor.go:147"}
{"level":"info","ts":"2022-10-31T15:18:40.821Z","msg":"none","service":"history","shard-id":3,"address":"172.25.0.6:7234","shard-item":"0xc000816600","component":"transfer-queue-processor","cluster-name":"active","lifecycle":"Started","component":"transfer-queue-processor","logging-call-at":"queueProcessor.go:159"}
{"level":"info","ts":"2022-10-31T15:18:40.821Z","msg":"Task processor started.","service":"history","shard-id":3,"address":"172.25.0.6:7234","shard-item":"0xc000816600","component":"timer-queue-processor","cluster-name":"active","component":"timer-queue-processor","logging-call-at":"taskProcessor.go:147"}
{"level":"info","ts":"2022-10-31T15:18:40.821Z","msg":"Timer queue processor started.","service":"history","shard-id":3,"address":"172.25.0.6:7234","shard-item":"0xc000816600","component":"timer-queue-processor","cluster-name":"active","component":"timer-queue-processor","logging-call-at":"timerQueueProcessorBase.go:165"}
{"level":"info","ts":"2022-10-31T15:18:40.821Z","msg":"none","service":"history","shard-id":3,"address":"172.25.0.6:7234","shard-item":"0xc000816600","component":"visibility-queue-processor","lifecycle":"Starting","component":"transfer-queue-processor","logging-call-at":"queueProcessor.go:150"}
{"level":"info","ts":"2022-10-31T15:18:40.821Z","msg":"Task processor started.","service":"history","shard-id":3,"address":"172.25.0.6:7234","shard-item":"0xc000816600","component":"visibility-queue-processor","logging-call-at":"taskProcessor.go:147"}
{"level":"info","ts":"2022-10-31T15:18:40.821Z","msg":"none","service":"history","shard-id":3,"address":"172.25.0.6:7234","shard-item":"0xc000816600","component":"visibility-queue-processor","lifecycle":"Started","component":"transfer-queue-processor","logging-call-at":"queueProcessor.go:159"}
{"level":"info","ts":"2022-10-31T15:18:40.821Z","msg":"Range updated for shardID","service":"history","shard-id":4,"address":"172.25.0.6:7234","shard-item":"0xc000816400","shard-range-id":1,"previous-shard-range-id":0,"number":0,"next-number":0,"logging-call-at":"context_impl.go:746"}
{"level":"info","ts":"2022-10-31T15:18:40.821Z","msg":"Acquired shard","service":"history","shard-id":4,"address":"172.25.0.6:7234","shard-item":"0xc000816400","logging-call-at":"context_impl.go:1143"}
{"level":"info","ts":"2022-10-31T15:18:40.821Z","msg":"Current reachable members","service":"matching","component":"service-resolver","service":"history","addresses":["172.25.0.6:7234"],"logging-call-at":"rpServiceResolver.go:266"}
{"level":"info","ts":"2022-10-31T15:18:40.821Z","msg":"none","service":"history","shard-id":4,"address":"172.25.0.6:7234","shard-item":"0xc000816400","component":"history-engine","lifecycle":"Starting","logging-call-at":"historyEngine.go:281"}
{"level":"info","ts":"2022-10-31T15:18:40.821Z","msg":"none","service":"history","shard-id":4,"address":"172.25.0.6:7234","shard-item":"0xc000816400","component":"transfer-queue-processor","cluster-name":"active","lifecycle":"Starting","component":"transfer-queue-processor","logging-call-at":"queueProcessor.go:150"}
{"level":"info","ts":"2022-10-31T15:18:40.821Z","msg":"Task processor started.","service":"history","shard-id":4,"address":"172.25.0.6:7234","shard-item":"0xc000816400","component":"transfer-queue-processor","cluster-name":"active","logging-call-at":"taskProcessor.go:147"}
{"level":"info","ts":"2022-10-31T15:18:40.821Z","msg":"none","service":"history","shard-id":4,"address":"172.25.0.6:7234","shard-item":"0xc000816400","component":"transfer-queue-processor","cluster-name":"active","lifecycle":"Started","component":"transfer-queue-processor","logging-call-at":"queueProcessor.go:159"}
{"level":"info","ts":"2022-10-31T15:18:40.821Z","msg":"Task processor started.","service":"history","shard-id":4,"address":"172.25.0.6:7234","shard-item":"0xc000816400","component":"timer-queue-processor","cluster-name":"active","component":"timer-queue-processor","logging-call-at":"taskProcessor.go:147"}
{"level":"info","ts":"2022-10-31T15:18:40.821Z","msg":"Timer queue processor started.","service":"history","shard-id":4,"address":"172.25.0.6:7234","shard-item":"0xc000816400","component":"timer-queue-processor","cluster-name":"active","component":"timer-queue-processor","logging-call-at":"timerQueueProcessorBase.go:165"}
{"level":"info","ts":"2022-10-31T15:18:40.821Z","msg":"Current reachable members","service":"matching","component":"service-resolver","service":"matching","addresses":["172.25.0.6:7235"],"logging-call-at":"rpServiceResolver.go:266"}
{"level":"info","ts":"2022-10-31T15:18:40.821Z","msg":"none","service":"history","shard-id":4,"address":"172.25.0.6:7234","shard-item":"0xc000816400","component":"visibility-queue-processor","lifecycle":"Starting","component":"transfer-queue-processor","logging-call-at":"queueProcessor.go:150"}
{"level":"info","ts":"2022-10-31T15:18:40.821Z","msg":"Task processor started.","service":"history","shard-id":4,"address":"172.25.0.6:7234","shard-item":"0xc000816400","component":"visibility-queue-processor","logging-call-at":"taskProcessor.go:147"}
{"level":"info","ts":"2022-10-31T15:18:40.821Z","msg":"none","service":"history","shard-id":4,"address":"172.25.0.6:7234","shard-item":"0xc000816400","component":"visibility-queue-processor","lifecycle":"Started","component":"transfer-queue-processor","logging-call-at":"queueProcessor.go:159"}
{"level":"info","ts":"2022-10-31T15:18:40.821Z","msg":"Range updated for shardID","service":"history","shard-id":2,"address":"172.25.0.6:7234","shard-item":"0xc00003ad80","shard-range-id":1,"previous-shard-range-id":0,"number":0,"next-number":0,"logging-call-at":"context_impl.go:746"}
{"level":"info","ts":"2022-10-31T15:18:40.821Z","msg":"Acquired shard","service":"history","shard-id":2,"address":"172.25.0.6:7234","shard-item":"0xc00003ad80","logging-call-at":"context_impl.go:1143"}
{"level":"info","ts":"2022-10-31T15:18:40.821Z","msg":"none","service":"history","shard-id":2,"address":"172.25.0.6:7234","shard-item":"0xc00003ad80","component":"history-engine","lifecycle":"Starting","logging-call-at":"historyEngine.go:281"}
{"level":"info","ts":"2022-10-31T15:18:40.821Z","msg":"none","service":"history","shard-id":2,"address":"172.25.0.6:7234","shard-item":"0xc00003ad80","component":"transfer-queue-processor","cluster-name":"active","lifecycle":"Starting","component":"transfer-queue-processor","logging-call-at":"queueProcessor.go:150"}
{"level":"info","ts":"2022-10-31T15:18:40.821Z","msg":"Task processor started.","service":"history","shard-id":2,"address":"172.25.0.6:7234","shard-item":"0xc00003ad80","component":"transfer-queue-processor","cluster-name":"active","logging-call-at":"taskProcessor.go:147"}
{"level":"info","ts":"2022-10-31T15:18:40.821Z","msg":"none","service":"history","shard-id":2,"address":"172.25.0.6:7234","shard-item":"0xc00003ad80","component":"transfer-queue-processor","cluster-name":"active","lifecycle":"Started","component":"transfer-queue-processor","logging-call-at":"queueProcessor.go:159"}
{"level":"info","ts":"2022-10-31T15:18:40.821Z","msg":"Task processor started.","service":"history","shard-id":2,"address":"172.25.0.6:7234","shard-item":"0xc00003ad80","component":"timer-queue-processor","cluster-name":"active","component":"timer-queue-processor","logging-call-at":"taskProcessor.go:147"}
{"level":"info","ts":"2022-10-31T15:18:40.821Z","msg":"Timer queue processor started.","service":"history","shard-id":2,"address":"172.25.0.6:7234","shard-item":"0xc00003ad80","component":"timer-queue-processor","cluster-name":"active","component":"timer-queue-processor","logging-call-at":"timerQueueProcessorBase.go:165"}
{"level":"info","ts":"2022-10-31T15:18:40.821Z","msg":"none","service":"history","shard-id":2,"address":"172.25.0.6:7234","shard-item":"0xc00003ad80","component":"visibility-queue-processor","lifecycle":"Starting","component":"transfer-queue-processor","logging-call-at":"queueProcessor.go:150"}
{"level":"info","ts":"2022-10-31T15:18:40.821Z","msg":"Received a ring changed event","service":"history","component":"service-resolver","service":"frontend","logging-call-at":"rpServiceResolver.go:219"}
{"level":"info","ts":"2022-10-31T15:18:40.821Z","msg":"Task processor started.","service":"history","shard-id":2,"address":"172.25.0.6:7234","shard-item":"0xc00003ad80","component":"visibility-queue-processor","logging-call-at":"taskProcessor.go:147"}
{"level":"info","ts":"2022-10-31T15:18:40.821Z","msg":"Received a ring changed event","service":"history","component":"service-resolver","service":"matching","logging-call-at":"rpServiceResolver.go:219"}
{"level":"info","ts":"2022-10-31T15:18:40.821Z","msg":"Received a ring changed event","service":"history","component":"service-resolver","service":"history","logging-call-at":"rpServiceResolver.go:219"}
{"level":"info","ts":"2022-10-31T15:18:40.821Z","msg":"none","service":"history","shard-id":2,"address":"172.25.0.6:7234","shard-item":"0xc00003ad80","component":"visibility-queue-processor","lifecycle":"Started","component":"transfer-queue-processor","logging-call-at":"queueProcessor.go:159"}
{"level":"info","ts":"2022-10-31T15:18:40.821Z","msg":"Current reachable members","service":"history","component":"service-resolver","service":"matching","addresses":["172.25.0.6:7235"],"logging-call-at":"rpServiceResolver.go:266"}
{"level":"info","ts":"2022-10-31T15:18:40.821Z","msg":"Received a ring changed event","service":"history","component":"service-resolver","service":"worker","logging-call-at":"rpServiceResolver.go:219"}
{"level":"info","ts":"2022-10-31T15:18:40.825Z","msg":"none","service":"history","shard-id":4,"address":"172.25.0.6:7234","shard-item":"0xc000816400","component":"history-engine","lifecycle":"Started","logging-call-at":"historyEngine.go:300"}
{"level":"info","ts":"2022-10-31T15:18:40.825Z","msg":"none","service":"history","shard-id":4,"address":"172.25.0.6:7234","shard-item":"0xc000816400","lifecycle":"Started","component":"shard-engine","logging-call-at":"controller_impl.go:440"}
{"level":"info","ts":"2022-10-31T15:18:40.825Z","msg":"Service resources started","service":"matching","address":"172.25.0.6:7235","logging-call-at":"resourceImpl.go:398"}
{"level":"info","ts":"2022-10-31T15:18:40.826Z","msg":"Starting to serve on matching listener","service":"matching","logging-call-at":"service.go:127"}
[Fx] INVOKE     go.temporal.io/server/service/frontend.ServiceLifetimeHooks()
{"level":"info","ts":"2022-10-31T15:18:40.826Z","msg":"Get dynamic config","name":"frontend.throttledLogRPS","value":20,"default-value":20,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.826Z","msg":"Created gRPC listener","service":"frontend","address":"172.25.0.6:7233","logging-call-at":"rpc.go:139"}
{"level":"info","ts":"2022-10-31T15:18:40.827Z","msg":"none","service":"history","shard-id":2,"address":"172.25.0.6:7234","shard-item":"0xc00003ad80","component":"history-engine","lifecycle":"Started","logging-call-at":"historyEngine.go:300"}
{"level":"info","ts":"2022-10-31T15:18:40.827Z","msg":"none","service":"history","shard-id":2,"address":"172.25.0.6:7234","shard-item":"0xc00003ad80","lifecycle":"Started","component":"shard-engine","logging-call-at":"controller_impl.go:440"}
{"level":"info","ts":"2022-10-31T15:18:40.827Z","msg":"Get dynamic config","name":"frontend.rps","value":2400,"default-value":2400,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.827Z","msg":"Get dynamic config","name":"frontend.keepAliveMinTime","value":10,"default-value":10,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.827Z","msg":"Get dynamic config","name":"frontend.keepAlivePermitWithoutStream","value":true,"default-value":true,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.827Z","msg":"none","service":"history","shard-id":3,"address":"172.25.0.6:7234","shard-item":"0xc000816600","component":"history-engine","lifecycle":"Started","logging-call-at":"historyEngine.go:300"}
{"level":"info","ts":"2022-10-31T15:18:40.827Z","msg":"Get dynamic config","name":"frontend.keepAliveMaxConnectionIdle","value":120,"default-value":120,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.827Z","msg":"none","service":"history","shard-id":3,"address":"172.25.0.6:7234","shard-item":"0xc000816600","lifecycle":"Started","component":"shard-engine","logging-call-at":"controller_impl.go:440"}
{"level":"info","ts":"2022-10-31T15:18:40.827Z","msg":"Get dynamic config","name":"frontend.keepAliveMaxConnectionAge","value":300,"default-value":300,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.827Z","msg":"Get dynamic config","name":"frontend.keepAliveMaxConnectionAgeGrace","value":70,"default-value":70,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.827Z","msg":"none","service":"history","component":"shard-controller","address":"172.25.0.6:7234","lifecycle":"Started","logging-call-at":"controller_impl.go:154"}
{"level":"info","ts":"2022-10-31T15:18:40.827Z","msg":"Get dynamic config","name":"frontend.keepAliveTime","value":60,"default-value":60,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.827Z","msg":"Get dynamic config","name":"frontend.keepAliveTimeout","value":10,"default-value":10,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.827Z","msg":"Starting to serve on history listener","service":"history","logging-call-at":"service.go:98"}
{"level":"info","ts":"2022-10-31T15:18:40.827Z","msg":"Get dynamic config","name":"history.acquireShardInterval","value":60,"default-value":60,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.829Z","msg":"Get dynamic config","name":"system.standardVisibilityPersistenceMaxReadQPS","value":9000,"default-value":9000,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.829Z","msg":"Get dynamic config","name":"system.standardVisibilityPersistenceMaxWriteQPS","value":9000,"default-value":9000,"logging-call-at":"config.go:79"}
[Fx] HOOK OnStart       go.temporal.io/server/service/frontend.ServiceLifetimeHooks.func1() executing (caller: go.temporal.io/server/service/frontend.ServiceLifetimeHooks)
[Fx] HOOK OnStart       go.temporal.io/server/service/frontend.ServiceLifetimeHooks.func1() called by go.temporal.io/server/service/frontend.ServiceLifetimeHooks ran successfully in 1.317µs
[Fx] RUNNING
{"level":"info","ts":"2022-10-31T15:18:40.830Z","msg":"frontend starting","service":"frontend","logging-call-at":"service.go:222"}
{"level":"info","ts":"2022-10-31T15:18:40.830Z","msg":"RuntimeMetricsReporter started","service":"frontend","logging-call-at":"runtime.go:154"}
[Fx] SUPPLY *resource.BootstrapParams
[Fx] SUPPLY chan struct {}
[Fx] PROVIDE    *client.factoryImpl <= go.temporal.io/server/common/persistence/client.NewFactoryImplProvider()
[Fx] PROVIDE    client.Factory <= go.temporal.io/server/common/persistence/client.BindFactory()
[Fx] PROVIDE    resource.SnTaggedLogger <= go.temporal.io/server/common/resource.SnTaggedLoggerProvider()
[Fx] PROVIDE    resource.ThrottledLogger <= go.temporal.io/server/common/resource.ThrottledLoggerProvider()
[Fx] PROVIDE    *config.Persistence <= go.temporal.io/server/common/resource.PersistenceConfigProvider()
[Fx] PROVIDE    tally.Scope <= go.temporal.io/server/common/resource.MetricsScopeProvider()
[Fx] PROVIDE    resource.HostName <= go.temporal.io/server/common/resource.HostNameProvider()
[Fx] PROVIDE    resource.ServiceName <= go.temporal.io/server/common/resource.ServiceNameProvider()
[Fx] PROVIDE    cluster.Metadata <= go.temporal.io/server/common/resource.ClusterMetadataProvider()
[Fx] PROVIDE    *config.ClusterMetadata <= go.temporal.io/server/common/resource.ClusterMetadataConfigProvider()
[Fx] PROVIDE    clock.TimeSource <= go.temporal.io/server/common/resource.TimeSourceProvider()
[Fx] PROVIDE    persistence.ClusterMetadataManager <= go.temporal.io/server/common/resource.ClusterMetadataManagerProvider()
[Fx] PROVIDE    resolver.ServiceResolver <= go.temporal.io/server/common/resource.PersistenceServiceResolverProvider()
[Fx] PROVIDE    client.AbstractDataStoreFactory <= go.temporal.io/server/common/resource.AbstractDatastoreFactoryProvider()
[Fx] PROVIDE    client.ClusterName <= go.temporal.io/server/common/resource.ClusterNameProvider()
[Fx] PROVIDE    metrics.Client <= go.temporal.io/server/common/resource.MetricsClientProvider()
[Fx] PROVIDE    searchattribute.Provider <= go.temporal.io/server/common/resource.SearchAttributeProviderProvider()
[Fx] PROVIDE    searchattribute.Manager <= go.temporal.io/server/common/resource.SearchAttributeManagerProvider()
[Fx] PROVIDE    searchattribute.Mapper <= go.temporal.io/server/common/resource.SearchAttributeMapperProvider()
[Fx] PROVIDE    persistence.MetadataManager <= go.temporal.io/server/common/resource.MetadataManagerProvider()
[Fx] PROVIDE    namespace.Registry <= go.temporal.io/server/common/resource.NamespaceCacheProvider()
[Fx] PROVIDE    serialization.Serializer <= go.temporal.io/server/common/persistence/serialization.NewSerializer()
[Fx] PROVIDE    archiver.ArchivalMetadata <= go.temporal.io/server/common/resource.ArchivalMetadataProvider()
[Fx] PROVIDE    provider.ArchiverProvider <= go.temporal.io/server/common/resource.ArchiverProviderProvider()
[Fx] PROVIDE    *archiver.HistoryBootstrapContainer <= go.temporal.io/server/common/resource.HistoryBootstrapContainerProvider()
[Fx] PROVIDE    *archiver.VisibilityBootstrapContainer <= go.temporal.io/server/common/resource.VisibilityBootstrapContainerProvider()
[Fx] PROVIDE    client.Bean <= go.temporal.io/server/common/resource.PersistenceBeanProvider()
[Fx] PROVIDE    resource.MembershipMonitorFactory <= go.temporal.io/server/common/resource.MembershipFactoryProvider()
[Fx] PROVIDE    membership.Monitor <= go.temporal.io/server/common/resource.MembershipMonitorProvider()
[Fx] PROVIDE    client.FactoryProvider <= go.temporal.io/server/common/resource.ClientFactoryProvider()
[Fx] PROVIDE    client.Bean <= go.temporal.io/server/common/resource.ClientBeanProvider()
[Fx] PROVIDE    client.Client <= go.temporal.io/server/common/resource.SdkClientProvider()
[Fx] PROVIDE    workflowservice.WorkflowServiceClient <= go.temporal.io/server/common/resource.FrontedClientProvider()
[Fx] PROVIDE    *client.FaultInjectionDataStoreFactory <= go.temporal.io/server/common/resource.PersistenceFaultInjectionFactoryProvider()
[Fx] PROVIDE    net.Listener <= go.temporal.io/server/common/resource.GrpcListenerProvider()
[Fx] PROVIDE    resource.InstanceID <= go.temporal.io/server/common/resource.InstanceIDProvider()
[Fx] PROVIDE    *tchannel.Channel <= go.temporal.io/server/common/resource.RingpopChannelProvider()
[Fx] PROVIDE    *metrics.RuntimeMetricsReporter <= go.temporal.io/server/common/resource.RuntimeMetricsReporterProvider()
[Fx] PROVIDE    resource.Resource <= go.temporal.io/server/common/resource.NewFromDI()
[Fx] PROVIDE    log.Logger <= go.temporal.io/server/service/worker.ParamsExpandProvider()
[Fx] PROVIDE    client.Client <= go.temporal.io/server/service/worker.ParamsExpandProvider()
[Fx] PROVIDE    common.RPCFactory <= go.temporal.io/server/service/worker.ParamsExpandProvider()
[Fx] PROVIDE    dynamicconfig.Client <= go.temporal.io/server/service/worker.ParamsExpandProvider()
[Fx] PROVIDE    *dynamicconfig.Collection <= go.temporal.io/server/common/dynamicconfig.NewCollection()
[Fx] PROVIDE    resource.ThrottledLoggerRpsFn <= go.temporal.io/server/service/worker.ThrottledLoggerRpsFnProvider()
[Fx] PROVIDE    *worker.Config <= go.temporal.io/server/service/worker.NewConfig()
[Fx] PROVIDE    client.PersistenceMaxQps <= go.temporal.io/server/service/worker.PersistenceMaxQpsProvider()
[Fx] PROVIDE    *worker.Service <= go.temporal.io/server/service/worker.NewService()
[Fx] PROVIDE    fx.Lifecycle <= go.uber.org/fx.New.func1()
[Fx] PROVIDE    fx.Shutdowner <= go.uber.org/fx.(*App).shutdowner-fm()
[Fx] PROVIDE    fx.DotGraph <= go.uber.org/fx.(*App).dotGraph-fm()
[Fx] INVOKE     go.temporal.io/server/common/resource.RegisterBootstrapContainer()
{"level":"info","ts":"2022-10-31T15:18:40.830Z","msg":"Get dynamic config","name":"worker.persistenceMaxQPS","value":500,"default-value":500,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.831Z","msg":"Membership heartbeat upserted successfully","service":"frontend","address":"172.25.0.6","port":6933,"hostId":"4cfbecd3-592f-11ed-927c-0242ac190006","logging-call-at":"rpMonitor.go:222"}
{"level":"info","ts":"2022-10-31T15:18:40.832Z","msg":"bootstrap hosts fetched","service":"frontend","bootstrap-hostports":"172.25.0.6:6934,172.25.0.6:6935,172.25.0.6:6933","logging-call-at":"rpMonitor.go:263"}
[Fx] INVOKE     go.temporal.io/server/service/worker.ServiceLifetimeHooks()
{"level":"info","ts":"2022-10-31T15:18:40.833Z","msg":"Current reachable members","service":"frontend","component":"service-resolver","service":"frontend","addresses":["172.25.0.6:7233"],"logging-call-at":"rpServiceResolver.go:266"}
{"level":"info","ts":"2022-10-31T15:18:40.833Z","msg":"Current reachable members","service":"frontend","component":"service-resolver","service":"matching","addresses":["172.25.0.6:7235"],"logging-call-at":"rpServiceResolver.go:266"}
{"level":"info","ts":"2022-10-31T15:18:40.833Z","msg":"Current reachable members","service":"frontend","component":"service-resolver","service":"history","addresses":["172.25.0.6:7234"],"logging-call-at":"rpServiceResolver.go:266"}
{"level":"info","ts":"2022-10-31T15:18:40.834Z","msg":"Received a ring changed event","service":"matching","component":"service-resolver","service":"worker","logging-call-at":"rpServiceResolver.go:219"}
{"level":"info","ts":"2022-10-31T15:18:40.834Z","msg":"Received a ring changed event","service":"matching","component":"service-resolver","service":"frontend","logging-call-at":"rpServiceResolver.go:219"}
{"level":"info","ts":"2022-10-31T15:18:40.834Z","msg":"Received a ring changed event","service":"matching","component":"service-resolver","service":"matching","logging-call-at":"rpServiceResolver.go:219"}
{"level":"info","ts":"2022-10-31T15:18:40.834Z","msg":"Received a ring changed event","service":"matching","component":"service-resolver","service":"history","logging-call-at":"rpServiceResolver.go:219"}
{"level":"info","ts":"2022-10-31T15:18:40.834Z","msg":"Current reachable members","service":"matching","component":"service-resolver","service":"frontend","addresses":["172.25.0.6:7233"],"logging-call-at":"rpServiceResolver.go:266"}
{"level":"info","ts":"2022-10-31T15:18:40.834Z","msg":"Get dynamic config","name":"worker.throttledLogRPS","value":20,"default-value":20,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.834Z","msg":"Created gRPC listener","service":"worker","address":"172.25.0.6:7239","logging-call-at":"rpc.go:139"}
[Fx] HOOK OnStart       go.temporal.io/server/service/worker.ServiceLifetimeHooks.func1() executing (caller: go.temporal.io/server/service/worker.ServiceLifetimeHooks)
[Fx] HOOK OnStart       go.temporal.io/server/service/worker.ServiceLifetimeHooks.func1() called by go.temporal.io/server/service/worker.ServiceLifetimeHooks ran successfully in 3.044µs
[Fx] RUNNING
{"level":"info","ts":"2022-10-31T15:18:40.834Z","msg":"worker starting","service":"worker","component":"worker","logging-call-at":"service.go:148"}
{"level":"info","ts":"2022-10-31T15:18:40.834Z","msg":"RuntimeMetricsReporter started","service":"worker","logging-call-at":"runtime.go:154"}
{"level":"info","ts":"2022-10-31T15:18:40.834Z","msg":"Service resources started","service":"frontend","address":"172.25.0.6:7233","logging-call-at":"resourceImpl.go:398"}
{"level":"info","ts":"2022-10-31T15:18:40.834Z","msg":"Get dynamic config","name":"frontend.enableServerVersionCheck","value":true,"default-value":true,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.834Z","msg":"Starting to serve on frontend listener","service":"frontend","logging-call-at":"service.go:237"}
{"level":"info","ts":"2022-10-31T15:18:40.836Z","msg":"Membership heartbeat upserted successfully","service":"worker","address":"172.25.0.6","port":6939,"hostId":"4cfd1046-592f-11ed-927c-0242ac190006","logging-call-at":"rpMonitor.go:222"}
{"level":"info","ts":"2022-10-31T15:18:40.836Z","msg":"bootstrap hosts fetched","service":"worker","bootstrap-hostports":"172.25.0.6:6934,172.25.0.6:6935,172.25.0.6:6933,172.25.0.6:6939","logging-call-at":"rpMonitor.go:263"}
{"level":"info","ts":"2022-10-31T15:18:40.837Z","msg":"Current reachable members","service":"worker","component":"service-resolver","service":"worker","addresses":["172.25.0.6:7239"],"logging-call-at":"rpServiceResolver.go:266"}
{"level":"info","ts":"2022-10-31T15:18:40.837Z","msg":"Current reachable members","service":"worker","component":"service-resolver","service":"frontend","addresses":["172.25.0.6:7233"],"logging-call-at":"rpServiceResolver.go:266"}
{"level":"info","ts":"2022-10-31T15:18:40.837Z","msg":"Current reachable members","service":"worker","component":"service-resolver","service":"matching","addresses":["172.25.0.6:7235"],"logging-call-at":"rpServiceResolver.go:266"}
{"level":"info","ts":"2022-10-31T15:18:40.837Z","msg":"Current reachable members","service":"worker","component":"service-resolver","service":"history","addresses":["172.25.0.6:7234"],"logging-call-at":"rpServiceResolver.go:266"}
{"level":"info","ts":"2022-10-31T15:18:40.837Z","msg":"Received a ring changed event","service":"history","component":"service-resolver","service":"frontend","logging-call-at":"rpServiceResolver.go:219"}
{"level":"info","ts":"2022-10-31T15:18:40.837Z","msg":"Received a ring changed event","service":"history","component":"service-resolver","service":"matching","logging-call-at":"rpServiceResolver.go:219"}
{"level":"info","ts":"2022-10-31T15:18:40.837Z","msg":"Received a ring changed event","service":"history","component":"service-resolver","service":"history","logging-call-at":"rpServiceResolver.go:219"}
{"level":"info","ts":"2022-10-31T15:18:40.837Z","msg":"none","service":"history","component":"shard-controller","address":"172.25.0.6:7234","shard-update":"RingMembershipChangedEvent","number-processed":1,"number-deleted":0,"number":0,"logging-call-at":"controller_impl.go:321"}
{"level":"info","ts":"2022-10-31T15:18:40.837Z","msg":"Received a ring changed event","service":"history","component":"service-resolver","service":"worker","logging-call-at":"rpServiceResolver.go:219"}
{"level":"info","ts":"2022-10-31T15:18:40.837Z","msg":"Current reachable members","service":"history","component":"service-resolver","service":"worker","addresses":["172.25.0.6:7239"],"logging-call-at":"rpServiceResolver.go:266"}
{"level":"info","ts":"2022-10-31T15:18:40.838Z","msg":"Service resources started","service":"worker","address":"172.25.0.6:7239","logging-call-at":"resourceImpl.go:398"}
{"level":"info","ts":"2022-10-31T15:18:40.839Z","msg":"Get dynamic config","name":"worker.ScannerMaxConcurrentActivityExecutionSize","value":10,"default-value":10,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.839Z","msg":"Get dynamic config","name":"worker.ScannerMaxConcurrentWorkflowTaskExecutionSize","value":10,"default-value":10,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.839Z","msg":"Get dynamic config","name":"worker.ScannerMaxConcurrentActivityTaskPollers","value":8,"default-value":8,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.839Z","msg":"Get dynamic config","name":"worker.ScannerMaxConcurrentWorkflowTaskPollers","value":8,"default-value":8,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.839Z","msg":"Get dynamic config","name":"worker.executionsScannerEnabled","value":false,"default-value":false,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.839Z","msg":"Get dynamic config","name":"worker.taskQueueScannerEnabled","value":true,"default-value":true,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.843Z","msg":"Received a ring changed event","service":"matching","component":"service-resolver","service":"matching","logging-call-at":"rpServiceResolver.go:219"}
{"level":"info","ts":"2022-10-31T15:18:40.843Z","msg":"Received a ring changed event","service":"matching","component":"service-resolver","service":"worker","logging-call-at":"rpServiceResolver.go:219"}
{"level":"info","ts":"2022-10-31T15:18:40.843Z","msg":"Received a ring changed event","service":"matching","component":"service-resolver","service":"frontend","logging-call-at":"rpServiceResolver.go:219"}
{"level":"info","ts":"2022-10-31T15:18:40.843Z","msg":"Received a ring changed event","service":"matching","component":"service-resolver","service":"history","logging-call-at":"rpServiceResolver.go:219"}
{"level":"info","ts":"2022-10-31T15:18:40.843Z","msg":"Current reachable members","service":"matching","component":"service-resolver","service":"worker","addresses":["172.25.0.6:7239"],"logging-call-at":"rpServiceResolver.go:266"}
{"level":"info","ts":"2022-10-31T15:18:40.843Z","msg":"Received a ring changed event","service":"history","component":"service-resolver","service":"frontend","logging-call-at":"rpServiceResolver.go:219"}
{"level":"info","ts":"2022-10-31T15:18:40.843Z","msg":"Received a ring changed event","service":"history","component":"service-resolver","service":"matching","logging-call-at":"rpServiceResolver.go:219"}
{"level":"info","ts":"2022-10-31T15:18:40.843Z","msg":"Received a ring changed event","service":"history","component":"service-resolver","service":"history","logging-call-at":"rpServiceResolver.go:219"}
{"level":"info","ts":"2022-10-31T15:18:40.843Z","msg":"none","service":"history","component":"shard-controller","address":"172.25.0.6:7234","shard-update":"RingMembershipChangedEvent","number-processed":1,"number-deleted":0,"number":0,"logging-call-at":"controller_impl.go:321"}
{"level":"info","ts":"2022-10-31T15:18:40.843Z","msg":"Received a ring changed event","service":"history","component":"service-resolver","service":"worker","logging-call-at":"rpServiceResolver.go:219"}
{"level":"info","ts":"2022-10-31T15:18:40.843Z","msg":"Current reachable members","service":"history","component":"service-resolver","service":"frontend","addresses":["172.25.0.6:7233"],"logging-call-at":"rpServiceResolver.go:266"}
{"level":"info","ts":"2022-10-31T15:18:40.877Z","msg":"Received a ring changed event","service":"frontend","component":"service-resolver","service":"frontend","logging-call-at":"rpServiceResolver.go:219"}
{"level":"info","ts":"2022-10-31T15:18:40.877Z","msg":"Received a ring changed event","service":"frontend","component":"service-resolver","service":"matching","logging-call-at":"rpServiceResolver.go:219"}
{"level":"info","ts":"2022-10-31T15:18:40.877Z","msg":"Received a ring changed event","service":"frontend","component":"service-resolver","service":"worker","logging-call-at":"rpServiceResolver.go:219"}
{"level":"info","ts":"2022-10-31T15:18:40.877Z","msg":"Current reachable members","service":"frontend","component":"service-resolver","service":"worker","addresses":["172.25.0.6:7239"],"logging-call-at":"rpServiceResolver.go:266"}
{"level":"info","ts":"2022-10-31T15:18:40.877Z","msg":"Received a ring changed event","service":"frontend","component":"service-resolver","service":"history","logging-call-at":"rpServiceResolver.go:219"}
{"level":"info","ts":"2022-10-31T15:18:40.918Z","msg":"Get dynamic config","name":"frontend.namespaceRPS","value":2400,"default-value":2400,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.918Z","msg":"Get dynamic config","name":"frontend.globalNamespacerps","value":0,"default-value":0,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.918Z","msg":"Get dynamic config","name":"frontend.enableClientVersionCheck","value":true,"default-value":true,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.920Z","msg":"Get dynamic config","name":"frontend.namespaceCount","value":1200,"default-value":1200,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.920Z","msg":"Get dynamic config","name":"limit.maxIDLength","value":1000,"default-value":1000,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.921Z","msg":"Get dynamic config","name":"matching.numTaskqueueReadPartitions","value":4,"default-value":4,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.922Z","msg":"Started Worker","Namespace":"temporal-system","TaskQueue":"temporal-sys-tq-scanner-taskqueue-0","WorkerID":"76@2a272dc9eb65@","logging-call-at":"scanner.go:147"}
{"level":"info","ts":"2022-10-31T15:18:40.922Z","msg":"Get dynamic config","name":"system.historyArchivalState","value":"enabled","default-value":"enabled","logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.922Z","msg":"Get dynamic config","name":"worker.ArchiverMaxConcurrentActivityExecutionSize","value":1000,"default-value":1000,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.922Z","msg":"Get dynamic config","name":"worker.ArchiverMaxConcurrentWorkflowTaskExecutionSize","value":1000,"default-value":1000,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.922Z","msg":"Get dynamic config","name":"worker.ArchiverMaxConcurrentActivityTaskPollers","value":4,"default-value":4,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.922Z","msg":"Get dynamic config","name":"worker.ArchiverMaxConcurrentWorkflowTaskPollers","value":4,"default-value":4,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.922Z","msg":"Get dynamic config","name":"matching.idleTaskqueueCheckInterval","value":300,"default-value":300,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.922Z","msg":"Get dynamic config","name":"matching.outstandingTaskAppendsThreshold","value":250,"default-value":250,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.922Z","msg":"Get dynamic config","name":"matching.getTasksBatchSize","value":1000,"default-value":1000,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.922Z","msg":"Get dynamic config","name":"matching.forwarderMaxOutstandingTasks","value":1,"default-value":1,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.922Z","msg":"Get dynamic config","name":"matching.forwarderMaxOutstandingPolls","value":1,"default-value":1,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.922Z","msg":"Get dynamic config","name":"matching.forwarderMaxRatePerSecond","value":10,"default-value":10,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.922Z","msg":"Get dynamic config","name":"admin.matchingNamespaceTaskqueueToPartitionDispatchRate","value":1000,"default-value":1000,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.922Z","msg":"Get dynamic config","name":"admin.matchingNamespaceToPartitionDispatchRate","value":10000,"default-value":10000,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.922Z","msg":"none","service":"matching","component":"matching-engine","wf-task-queue-name":"/_sys/temporal-sys-tq-scanner-taskqueue-0/3","wf-task-queue-type":"Workflow","lifecycle":"Starting","logging-call-at":"taskQueueManager.go:238"}
{"level":"info","ts":"2022-10-31T15:18:40.922Z","msg":"none","service":"matching","component":"matching-engine","wf-task-queue-name":"/_sys/temporal-sys-tq-scanner-taskqueue-0/3","wf-task-queue-type":"Workflow","lifecycle":"Started","logging-call-at":"taskQueueManager.go:242"}
{"level":"info","ts":"2022-10-31T15:18:40.922Z","msg":"Get dynamic config","name":"matching.longPollExpirationInterval","value":60,"default-value":60,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.922Z","msg":"Get dynamic config","name":"matching.forwarderMaxChildrenPerNode","value":20,"default-value":20,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.922Z","msg":"none","service":"matching","component":"matching-engine","wf-task-queue-name":"2a272dc9eb65:6e1aaca5-9d96-43ca-a671-ba60ee29eaf5","wf-task-queue-type":"Workflow","lifecycle":"Starting","logging-call-at":"taskQueueManager.go:238"}
{"level":"info","ts":"2022-10-31T15:18:40.922Z","msg":"none","service":"matching","component":"matching-engine","wf-task-queue-name":"2a272dc9eb65:6e1aaca5-9d96-43ca-a671-ba60ee29eaf5","wf-task-queue-type":"Workflow","lifecycle":"Started","logging-call-at":"taskQueueManager.go:242"}
{"level":"info","ts":"2022-10-31T15:18:40.922Z","msg":"Get dynamic config","name":"matching.updateAckInterval","value":60,"default-value":60,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.922Z","msg":"none","service":"matching","component":"matching-engine","wf-task-queue-name":"temporal-sys-tq-scanner-taskqueue-0","wf-task-queue-type":"Activity","lifecycle":"Starting","logging-call-at":"taskQueueManager.go:238"}
{"level":"info","ts":"2022-10-31T15:18:40.922Z","msg":"none","service":"matching","component":"matching-engine","wf-task-queue-name":"temporal-sys-tq-scanner-taskqueue-0","wf-task-queue-type":"Activity","lifecycle":"Started","logging-call-at":"taskQueueManager.go:242"}
{"level":"info","ts":"2022-10-31T15:18:40.922Z","msg":"Get dynamic config","name":"matching.numTaskqueueReadPartitions","value":4,"default-value":4,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.922Z","msg":"Get dynamic config","name":"matching.minTaskThrottlingBurstSize","value":1,"default-value":1,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.923Z","msg":"none","service":"matching","component":"matching-engine","wf-task-queue-name":"temporal-sys-tq-scanner-taskqueue-0","wf-task-queue-type":"Workflow","lifecycle":"Starting","logging-call-at":"taskQueueManager.go:238"}
{"level":"info","ts":"2022-10-31T15:18:40.923Z","msg":"none","service":"matching","component":"matching-engine","wf-task-queue-name":"temporal-sys-tq-scanner-taskqueue-0","wf-task-queue-type":"Workflow","lifecycle":"Started","logging-call-at":"taskQueueManager.go:242"}
{"level":"info","ts":"2022-10-31T15:18:40.923Z","msg":"none","service":"matching","component":"matching-engine","wf-task-queue-name":"/_sys/temporal-sys-tq-scanner-taskqueue-0/2","wf-task-queue-type":"Activity","lifecycle":"Starting","logging-call-at":"taskQueueManager.go:238"}
{"level":"info","ts":"2022-10-31T15:18:40.923Z","msg":"none","service":"matching","component":"matching-engine","wf-task-queue-name":"/_sys/temporal-sys-tq-scanner-taskqueue-0/2","wf-task-queue-type":"Activity","lifecycle":"Started","logging-call-at":"taskQueueManager.go:242"}
{"level":"info","ts":"2022-10-31T15:18:40.923Z","msg":"none","service":"matching","component":"matching-engine","wf-task-queue-name":"2a272dc9eb65:381ea76e-b984-45e3-9583-07066ec631ba","wf-task-queue-type":"Workflow","lifecycle":"Starting","logging-call-at":"taskQueueManager.go:238"}
{"level":"info","ts":"2022-10-31T15:18:40.923Z","msg":"none","service":"matching","component":"matching-engine","wf-task-queue-name":"2a272dc9eb65:381ea76e-b984-45e3-9583-07066ec631ba","wf-task-queue-type":"Workflow","lifecycle":"Started","logging-call-at":"taskQueueManager.go:242"}
{"level":"info","ts":"2022-10-31T15:18:40.923Z","msg":"none","service":"matching","component":"matching-engine","wf-task-queue-name":"/_sys/temporal-sys-tq-scanner-taskqueue-0/1","wf-task-queue-type":"Workflow","lifecycle":"Starting","logging-call-at":"taskQueueManager.go:238"}
{"level":"info","ts":"2022-10-31T15:18:40.923Z","msg":"none","service":"matching","component":"matching-engine","wf-task-queue-name":"/_sys/temporal-sys-tq-scanner-taskqueue-0/1","wf-task-queue-type":"Workflow","lifecycle":"Started","logging-call-at":"taskQueueManager.go:242"}
{"level":"info","ts":"2022-10-31T15:18:40.923Z","msg":"Started Worker","Namespace":"temporal-system","TaskQueue":"temporal-archival-tq","WorkerID":"76@2a272dc9eb65@","logging-call-at":"client_worker.go:130"}
{"level":"info","ts":"2022-10-31T15:18:40.923Z","msg":"Get dynamic config","name":"worker.enableBatcher","value":true,"default-value":true,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.923Z","msg":"Get dynamic config","name":"worker.BatcherMaxConcurrentActivityExecutionSize","value":1000,"default-value":1000,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.923Z","msg":"Get dynamic config","name":"worker.BatcherMaxConcurrentWorkflowTaskExecutionSize","value":1000,"default-value":1000,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.923Z","msg":"Get dynamic config","name":"worker.BatcherMaxConcurrentActivityTaskPollers","value":4,"default-value":4,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.923Z","msg":"Get dynamic config","name":"worker.BatcherMaxConcurrentWorkflowTaskPollers","value":4,"default-value":4,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.924Z","msg":"none","service":"matching","component":"matching-engine","wf-task-queue-name":"temporal-archival-tq","wf-task-queue-type":"Activity","lifecycle":"Starting","logging-call-at":"taskQueueManager.go:238"}
{"level":"info","ts":"2022-10-31T15:18:40.924Z","msg":"none","service":"matching","component":"matching-engine","wf-task-queue-name":"temporal-archival-tq","wf-task-queue-type":"Activity","lifecycle":"Started","logging-call-at":"taskQueueManager.go:242"}
{"level":"info","ts":"2022-10-31T15:18:40.924Z","msg":"none","service":"matching","component":"matching-engine","wf-task-queue-name":"/_sys/temporal-sys-tq-scanner-taskqueue-0/1","wf-task-queue-type":"Activity","lifecycle":"Starting","logging-call-at":"taskQueueManager.go:238"}
{"level":"info","ts":"2022-10-31T15:18:40.924Z","msg":"none","service":"matching","component":"matching-engine","wf-task-queue-name":"/_sys/temporal-sys-tq-scanner-taskqueue-0/1","wf-task-queue-type":"Activity","lifecycle":"Started","logging-call-at":"taskQueueManager.go:242"}
{"level":"info","ts":"2022-10-31T15:18:40.924Z","msg":"none","service":"matching","component":"matching-engine","wf-task-queue-name":"/_sys/temporal-archival-tq/3","wf-task-queue-type":"Workflow","lifecycle":"Starting","logging-call-at":"taskQueueManager.go:238"}
{"level":"info","ts":"2022-10-31T15:18:40.924Z","msg":"none","service":"matching","component":"matching-engine","wf-task-queue-name":"/_sys/temporal-archival-tq/3","wf-task-queue-type":"Workflow","lifecycle":"Started","logging-call-at":"taskQueueManager.go:242"}
{"level":"info","ts":"2022-10-31T15:18:40.925Z","msg":"none","service":"matching","component":"matching-engine","wf-task-queue-name":"temporal-archival-tq","wf-task-queue-type":"Workflow","lifecycle":"Starting","logging-call-at":"taskQueueManager.go:238"}
{"level":"info","ts":"2022-10-31T15:18:40.925Z","msg":"none","service":"matching","component":"matching-engine","wf-task-queue-name":"temporal-archival-tq","wf-task-queue-type":"Workflow","lifecycle":"Started","logging-call-at":"taskQueueManager.go:242"}
{"level":"info","ts":"2022-10-31T15:18:40.925Z","msg":"none","service":"matching","component":"matching-engine","wf-task-queue-name":"/_sys/temporal-archival-tq/3","wf-task-queue-type":"Activity","lifecycle":"Starting","logging-call-at":"taskQueueManager.go:238"}
{"level":"info","ts":"2022-10-31T15:18:40.925Z","msg":"none","service":"matching","component":"matching-engine","wf-task-queue-name":"/_sys/temporal-archival-tq/3","wf-task-queue-type":"Activity","lifecycle":"Started","logging-call-at":"taskQueueManager.go:242"}
{"level":"info","ts":"2022-10-31T15:18:40.925Z","msg":"none","service":"matching","component":"matching-engine","wf-task-queue-name":"/_sys/temporal-sys-tq-scanner-taskqueue-0/3","wf-task-queue-type":"Activity","lifecycle":"Starting","logging-call-at":"taskQueueManager.go:238"}
{"level":"info","ts":"2022-10-31T15:18:40.925Z","msg":"none","service":"matching","component":"matching-engine","wf-task-queue-name":"/_sys/temporal-sys-tq-scanner-taskqueue-0/3","wf-task-queue-type":"Activity","lifecycle":"Started","logging-call-at":"taskQueueManager.go:242"}
{"level":"info","ts":"2022-10-31T15:18:40.926Z","msg":"none","service":"matching","component":"matching-engine","wf-task-queue-name":"2a272dc9eb65:24ba1cfe-51b3-463f-8ffe-cf77fc73ddce","wf-task-queue-type":"Workflow","lifecycle":"Starting","logging-call-at":"taskQueueManager.go:238"}
{"level":"info","ts":"2022-10-31T15:18:40.926Z","msg":"none","service":"matching","component":"matching-engine","wf-task-queue-name":"2a272dc9eb65:24ba1cfe-51b3-463f-8ffe-cf77fc73ddce","wf-task-queue-type":"Workflow","lifecycle":"Started","logging-call-at":"taskQueueManager.go:242"}
{"level":"info","ts":"2022-10-31T15:18:40.927Z","msg":"Started Worker","Namespace":"temporal-system","TaskQueue":"temporal-sys-batcher-taskqueue","WorkerID":"76@2a272dc9eb65@","logging-call-at":"batcher.go:104"}
{"level":"info","ts":"2022-10-31T15:18:40.928Z","msg":"Get dynamic config","name":"system.enableParentClosePolicyWorker","value":true,"default-value":true,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.928Z","msg":"Get dynamic config","name":"worker.ParentCloseMaxConcurrentActivityExecutionSize","value":1000,"default-value":1000,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.928Z","msg":"Get dynamic config","name":"worker.ParentCloseMaxConcurrentWorkflowTaskExecutionSize","value":1000,"default-value":1000,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.928Z","msg":"Get dynamic config","name":"worker.ParentCloseMaxConcurrentActivityTaskPollers","value":4,"default-value":4,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.928Z","msg":"Get dynamic config","name":"worker.ParentCloseMaxConcurrentWorkflowTaskPollers","value":4,"default-value":4,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:40.927Z","msg":"none","service":"matching","component":"matching-engine","wf-task-queue-name":"/_sys/temporal-sys-tq-scanner-taskqueue-0/2","wf-task-queue-type":"Workflow","lifecycle":"Starting","logging-call-at":"taskQueueManager.go:238"}
{"level":"info","ts":"2022-10-31T15:18:40.929Z","msg":"none","service":"matching","component":"matching-engine","wf-task-queue-name":"/_sys/temporal-sys-tq-scanner-taskqueue-0/2","wf-task-queue-type":"Workflow","lifecycle":"Started","logging-call-at":"taskQueueManager.go:242"}
{"level":"info","ts":"2022-10-31T15:18:40.929Z","msg":"none","service":"matching","component":"matching-engine","wf-task-queue-name":"/_sys/temporal-archival-tq/2","wf-task-queue-type":"Activity","lifecycle":"Starting","logging-call-at":"taskQueueManager.go:238"}
{"level":"info","ts":"2022-10-31T15:18:40.929Z","msg":"none","service":"matching","component":"matching-engine","wf-task-queue-name":"/_sys/temporal-archival-tq/2","wf-task-queue-type":"Activity","lifecycle":"Started","logging-call-at":"taskQueueManager.go:242"}
{"level":"info","ts":"2022-10-31T15:18:40.929Z","msg":"none","service":"matching","component":"matching-engine","wf-task-queue-name":"/_sys/temporal-sys-batcher-taskqueue/1","wf-task-queue-type":"Workflow","lifecycle":"Starting","logging-call-at":"taskQueueManager.go:238"}
{"level":"info","ts":"2022-10-31T15:18:40.929Z","msg":"none","service":"matching","component":"matching-engine","wf-task-queue-name":"/_sys/temporal-sys-batcher-taskqueue/1","wf-task-queue-type":"Workflow","lifecycle":"Started","logging-call-at":"taskQueueManager.go:242"}
{"level":"info","ts":"2022-10-31T15:18:40.929Z","msg":"none","service":"matching","component":"matching-engine","wf-task-queue-name":"/_sys/temporal-sys-batcher-taskqueue/1","wf-task-queue-type":"Activity","lifecycle":"Starting","logging-call-at":"taskQueueManager.go:238"}
{"level":"info","ts":"2022-10-31T15:18:40.929Z","msg":"none","service":"matching","component":"matching-engine","wf-task-queue-name":"/_sys/temporal-sys-batcher-taskqueue/1","wf-task-queue-type":"Activity","lifecycle":"Started","logging-call-at":"taskQueueManager.go:242"}
:"info","ts":"2022-10-31T15:18:40.930Z","msg":"none","service":"matching","component":"matching-engine","wf-task-queue-name":"temporal-sys-batcher-taskqueue","wf-task-queue-type":"Activity","lifecycle":"Starting","logging-call-at":"taskQueueManager.go:238"}
{"level":"info","ts":"2022-10-31T15:18:40.930Z","msg":"none","service":"matching","component":"matching-engine","wf-task-queue-name":"temporal-sys-batcher-taskqueue","wf-task-queue-type":"Activity","lifecycle":"Started","logging-call-at":"taskQueueManager.go:242"}
:"info","ts":"2022-10-31T15:18:40.930Z","msg":"none","service":"matching","component":"matching-engine","wf-task-queue-name":"temporal-sys-batcher-taskqueue","wf-task-queue-type":"Workflow","lifecycle":"Starting","logging-call-at":"taskQueueManager.go:238"}
{"level":"info","ts":"2022-10-31T15:18:40.930Z","msg":"none","service":"matching","component":"matching-engine","wf-task-queue-name":"temporal-sys-batcher-taskqueue","wf-task-queue-type":"Workflow","lifecycle":"Started","logging-call-at":"taskQueueManager.go:242"}
{"level":"info","ts":"2022-10-31T15:18:40.931Z","msg":"none","service":"matching","component":"matching-engine","wf-task-queue-name":"/_sys/temporal-sys-batcher-taskqueue/2","wf-task-queue-type":"Activity","lifecycle":"Starting","logging-call-at":"taskQueueManager.go:238"}
{"level":"info","ts":"2022-10-31T15:18:40.931Z","msg":"none","service":"matching","component":"matching-engine","wf-task-queue-name":"/_sys/temporal-sys-batcher-taskqueue/2","wf-task-queue-type":"Activity","lifecycle":"Started","logging-call-at":"taskQueueManager.go:242"}
{"level":"info","ts":"2022-10-31T15:18:40.931Z","msg":"none","service":"matching","component":"matching-engine","wf-task-queue-name":"/_sys/temporal-sys-batcher-taskqueue/2","wf-task-queue-type":"Workflow","lifecycle":"Starting","logging-call-at":"taskQueueManager.go:238"}
{"level":"info","ts":"2022-10-31T15:18:40.931Z","msg":"none","service":"matching","component":"matching-engine","wf-task-queue-name":"/_sys/temporal-sys-batcher-taskqueue/2","wf-task-queue-type":"Workflow","lifecycle":"Started","logging-call-at":"taskQueueManager.go:242"}
{"level":"info","ts":"2022-10-31T15:18:40.932Z","msg":"Started Worker","Namespace":"temporal-system","TaskQueue":"temporal-sys-processor-parent-close-policy","WorkerID":"76@2a272dc9eb65@","logging-call-at":"processor.go:103"}
{"level":"info","ts":"2022-10-31T15:18:40.932Z","msg":"none","service":"matching","component":"matching-engine","wf-task-queue-name":"2a272dc9eb65:bd296afc-b0f4-4773-8d9f-595627f443c4","wf-task-queue-type":"Workflow","lifecycle":"Starting","logging-call-at":"taskQueueManager.go:238"}
{"level":"info","ts":"2022-10-31T15:18:40.932Z","msg":"none","service":"matching","component":"matching-engine","wf-task-queue-name":"2a272dc9eb65:bd296afc-b0f4-4773-8d9f-595627f443c4","wf-task-queue-type":"Workflow","lifecycle":"Started","logging-call-at":"taskQueueManager.go:242"}
{"level":"info","ts":"2022-10-31T15:18:40.933Z","msg":"none","service":"matching","component":"matching-engine","wf-task-queue-name":"/_sys/temporal-sys-processor-parent-close-policy/3","wf-task-queue-type":"Activity","lifecycle":"Starting","logging-call-at":"taskQueueManager.go:238"}
{"level":"info","ts":"2022-10-31T15:18:40.933Z","msg":"none","service":"matching","component":"matching-engine","wf-task-queue-name":"/_sys/temporal-sys-processor-parent-close-policy/3","wf-task-queue-type":"Activity","lifecycle":"Started","logging-call-at":"taskQueueManager.go:242"}
{"level":"info","ts":"2022-10-31T15:18:40.933Z","msg":"none","service":"matching","component":"matching-engine","wf-task-queue-name":"/_sys/temporal-sys-processor-parent-close-policy/1","wf-task-queue-type":"Workflow","lifecycle":"Starting","logging-call-at":"taskQueueManager.go:238"}
{"level":"info","ts":"2022-10-31T15:18:40.933Z","msg":"none","service":"matching","component":"matching-engine","wf-task-queue-name":"/_sys/temporal-sys-processor-parent-close-policy/1","wf-task-queue-type":"Workflow","lifecycle":"Started","logging-call-at":"taskQueueManager.go:242"}
{"level":"info","ts":"2022-10-31T15:18:40.933Z","msg":"none","service":"matching","component":"matching-engine","wf-task-queue-name":"temporal-sys-processor-parent-close-policy","wf-task-queue-type":"Activity","lifecycle":"Starting","logging-call-at":"taskQueueManager.go:238"}
{"level":"info","ts":"2022-10-31T15:18:40.933Z","msg":"none","service":"matching","component":"matching-engine","wf-task-queue-name":"temporal-sys-processor-parent-close-policy","wf-task-queue-type":"Activity","lifecycle":"Started","logging-call-at":"taskQueueManager.go:242"}
{"level":"info","ts":"2022-10-31T15:18:40.933Z","msg":"none","service":"matching","component":"matching-engine","wf-task-queue-name":"temporal-sys-processor-parent-close-policy","wf-task-queue-type":"Workflow","lifecycle":"Starting","logging-call-at":"taskQueueManager.go:238"}
{"level":"info","ts":"2022-10-31T15:18:40.933Z","msg":"none","service":"matching","component":"matching-engine","wf-task-queue-name":"temporal-sys-processor-parent-close-policy","wf-task-queue-type":"Workflow","lifecycle":"Started","logging-call-at":"taskQueueManager.go:242"}
{"level":"info","ts":"2022-10-31T15:18:40.934Z","msg":"none","service":"matching","component":"matching-engine","wf-task-queue-name":"2a272dc9eb65:3887b191-d5d6-4c01-b32e-20bb676f69de","wf-task-queue-type":"Workflow","lifecycle":"Starting","logging-call-at":"taskQueueManager.go:238"}
{"level":"info","ts":"2022-10-31T15:18:40.934Z","msg":"none","service":"matching","component":"matching-engine","wf-task-queue-name":"2a272dc9eb65:3887b191-d5d6-4c01-b32e-20bb676f69de","wf-task-queue-type":"Workflow","lifecycle":"Started","logging-call-at":"taskQueueManager.go:242"}
{"level":"info","ts":"2022-10-31T15:18:40.934Z","msg":"Started Worker","Namespace":"temporal-system","TaskQueue":"temporal-sys-add-search-attributes-task-queue","WorkerID":"76@2a272dc9eb65@","logging-call-at":"addsearchattributes.go:86"}
{"level":"info","ts":"2022-10-31T15:18:40.934Z","msg":"worker started","service":"worker","component":"worker","logging-call-at":"service.go:170"}
{"level":"info","ts":"2022-10-31T15:18:40.934Z","msg":"none","service":"matching","component":"matching-engine","wf-task-queue-name":"temporal-sys-add-search-attributes-task-queue","wf-task-queue-type":"Activity","lifecycle":"Starting","logging-call-at":"taskQueueManager.go:238"}
{"level":"info","ts":"2022-10-31T15:18:40.934Z","msg":"none","service":"matching","component":"matching-engine","wf-task-queue-name":"temporal-sys-add-search-attributes-task-queue","wf-task-queue-type":"Activity","lifecycle":"Started","logging-call-at":"taskQueueManager.go:242"}
{"level":"info","ts":"2022-10-31T15:18:40.934Z","msg":"none","service":"matching","component":"matching-engine","wf-task-queue-name":"temporal-sys-add-search-attributes-task-queue","wf-task-queue-type":"Workflow","lifecycle":"Starting","logging-call-at":"taskQueueManager.go:238"}
{"level":"info","ts":"2022-10-31T15:18:40.934Z","msg":"none","service":"matching","component":"matching-engine","wf-task-queue-name":"temporal-sys-add-search-attributes-task-queue","wf-task-queue-type":"Workflow","lifecycle":"Started","logging-call-at":"taskQueueManager.go:242"}
{"level":"info","ts":"2022-10-31T15:18:40.935Z","msg":"none","service":"matching","component":"matching-engine","wf-task-queue-name":"/_sys/temporal-sys-processor-parent-close-policy/2","wf-task-queue-type":"Activity","lifecycle":"Starting","logging-call-at":"taskQueueManager.go:238"}
{"level":"info","ts":"2022-10-31T15:18:40.935Z","msg":"none","service":"matching","component":"matching-engine","wf-task-queue-name":"/_sys/temporal-sys-processor-parent-close-policy/2","wf-task-queue-type":"Activity","lifecycle":"Started","logging-call-at":"taskQueueManager.go:242"}
{"level":"info","ts":"2022-10-31T15:18:40.935Z","msg":"none","service":"matching","component":"matching-engine","wf-task-queue-name":"/_sys/temporal-sys-add-search-attributes-task-queue/2","wf-task-queue-type":"Activity","lifecycle":"Starting","logging-call-at":"taskQueueManager.go:238"}
{"level":"info","ts":"2022-10-31T15:18:40.935Z","msg":"none","service":"matching","component":"matching-engine","wf-task-queue-name":"/_sys/temporal-sys-add-search-attributes-task-queue/2","wf-task-queue-type":"Activity","lifecycle":"Started","logging-call-at":"taskQueueManager.go:242"}
{"level":"info","ts":"2022-10-31T15:18:40.936Z","msg":"none","service":"matching","component":"matching-engine","wf-task-queue-name":"/_sys/temporal-sys-processor-parent-close-policy/1","wf-task-queue-type":"Activity","lifecycle":"Starting","logging-call-at":"taskQueueManager.go:238"}
{"level":"info","ts":"2022-10-31T15:18:40.936Z","msg":"none","service":"matching","component":"matching-engine","wf-task-queue-name":"/_sys/temporal-sys-processor-parent-close-policy/1","wf-task-queue-type":"Activity","lifecycle":"Started","logging-call-at":"taskQueueManager.go:242"}
temporal.api.workflowservice.v1.WorkflowService: SERVING
Temporal server started.
Registering default namespace: default.
Error: Operation DescribeNamespace failed.
Error Details: rpc error: code = NotFound desc = Namespace default does not exist.
('export TEMPORAL_CLI_SHOW_STACKS=1' to see stack traces)
Default namespace default not found. Creating...
{"level":"info","ts":"2022-10-31T15:18:41.826Z","msg":"Get dynamic config","name":"system.visibilityArchivalState","value":"enabled","default-value":"enabled","logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:41.828Z","msg":"Register namespace succeeded","service":"frontend","wf-namespace":"default","wf-namespace-id":"9838de98-4c2d-4fc0-9c0c-09c574e33276","logging-call-at":"handler.go:296"}
Namespace default successfully registered.
Default namespace default registration complete.
Adding Custom*Field search attributes.
You are about to add search attributes [CustomBoolField:Bool CustomDatetimeField:Datetime CustomDoubleField:Double CustomIntField:Int CustomKeywordField:Keyword CustomStringField:Text CustomTextField:Text]. Continue? Y/N y
{"level":"info","ts":"2022-10-31T15:18:41.842Z","msg":"Get dynamic config","name":"history.defaultWorkflowTaskTimeout","value":10,"default-value":10,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:41.842Z","msg":"Get dynamic config","name":"limit.blobSize.error","value":15728640,"default-value":2097152,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:41.842Z","msg":"Get dynamic config","name":"limit.blobSize.warn","value":10485760,"default-value":524288,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:41.842Z","msg":"Get dynamic config","name":"limit.memoSize.error","value":2097152,"default-value":2097152,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:41.842Z","msg":"Get dynamic config","name":"limit.memoSize.warn","value":2048,"default-value":2048,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:41.843Z","msg":"Get dynamic config","name":"history.maximumBufferedEventsBatch","value":100,"default-value":100,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:41.843Z","msg":"Get dynamic config","name":"history.mutableStateChecksumGenProbability","value":0,"default-value":0,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:41.843Z","msg":"Get dynamic config","name":"system.transactionSizeLimit","value":4194304,"default-value":4194304,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:41.847Z","msg":"Get dynamic config","name":"frontend.historyMaxPageSize","value":256,"default-value":256,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:41.853Z","msg":"Get dynamic config","name":"history.longPollExpirationInterval","value":20,"default-value":20,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:41.853Z","msg":"Get dynamic config","name":"matching.numTaskqueueWritePartitions","value":4,"default-value":4,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:41.853Z","msg":"Get dynamic config","name":"matching.syncMatchWaitDuration","value":0.2,"default-value":0.2,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:41.853Z","msg":"Get dynamic config","name":"limit.historySize.warn","value":10485760,"default-value":10485760,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:41.853Z","msg":"Get dynamic config","name":"limit.historySize.error","value":52428800,"default-value":52428800,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:41.853Z","msg":"Get dynamic config","name":"limit.historyCount.warn","value":10240,"default-value":10240,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:41.853Z","msg":"Get dynamic config","name":"limit.historyCount.error","value":51200,"default-value":51200,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:41.857Z","msg":"Workflow started.","Namespace":"temporal-system","TaskQueue":"temporal-sys-add-search-attributes-task-queue","WorkerID":"76@2a272dc9eb65@","WorkflowType":"temporal-sys-add-search-attributes-workflow","WorkflowID":"temporal-sys-add-search-attributes-workflow","RunID":"d3a747f2-2613-4ec7-9edc-eefcda44ccf4","Attempt":1,"wf-type":"temporal-sys-add-search-attributes-workflow","logging-call-at":"value.go:543"}
{"level":"info","ts":"2022-10-31T15:18:41.857Z","msg":"none","service":"matching","component":"matching-engine","wf-task-queue-name":"/_sys/temporal-sys-add-search-attributes-task-queue/1","wf-task-queue-type":"Workflow","lifecycle":"Starting","logging-call-at":"taskQueueManager.go:238"}
{"level":"info","ts":"2022-10-31T15:18:41.857Z","msg":"none","service":"matching","component":"matching-engine","wf-task-queue-name":"/_sys/temporal-sys-add-search-attributes-task-queue/1","wf-task-queue-type":"Workflow","lifecycle":"Started","logging-call-at":"taskQueueManager.go:242"}
{"level":"info","ts":"2022-10-31T15:18:41.857Z","msg":"Get dynamic config","name":"frontend.enableTokenNamespaceEnforcement","value":false,"default-value":false,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:41.857Z","msg":"Get dynamic config","name":"history.historyMaxAutoResetPoints","value":20,"default-value":20,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:41.857Z","msg":"Get dynamic config","name":"system.advancedVisibilityWritingMode","value":"off","default-value":"off","logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:41.857Z","msg":"Get dynamic config","name":"history.defaultActivityRetryPolicy","value":{"BackoffCoefficient":2,"InitialIntervalInSeconds":1,"MaximumAttempts":0,"MaximumIntervalCoefficient":100},"default-value":{"BackoffCoefficient":2,"InitialIntervalInSeconds":1,"MaximumAttempts":0,"MaximumIntervalCoefficient":100},"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:41.860Z","msg":"Get dynamic config","name":"history.stickyTTL","value":31536000,"default-value":31536000,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:41.860Z","msg":"none","service":"matching","component":"matching-engine","wf-task-queue-name":"/_sys/temporal-sys-add-search-attributes-task-queue/1","wf-task-queue-type":"Activity","lifecycle":"Starting","logging-call-at":"taskQueueManager.go:238"}
{"level":"info","ts":"2022-10-31T15:18:41.860Z","msg":"none","service":"matching","component":"matching-engine","wf-task-queue-name":"/_sys/temporal-sys-add-search-attributes-task-queue/1","wf-task-queue-type":"Activity","lifecycle":"Started","logging-call-at":"taskQueueManager.go:242"}
{"level":"info","ts":"2022-10-31T15:18:41.863Z","msg":"Elasticsearch client is not configured. Skipping mapping update.","service":"worker","component":"add-search-attributes","wf-id":"temporal-sys-add-search-attributes-workflow","logging-call-at":"workflow.go:149"}
{"level":"info","ts":"2022-10-31T15:18:41.863Z","msg":"Get dynamic config","name":"limit.blobSize.error","value":15728640,"default-value":2097152,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:41.863Z","msg":"Get dynamic config","name":"limit.blobSize.warn","value":10485760,"default-value":262144,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:41.863Z","msg":"none","service":"matching","component":"matching-engine","wf-task-queue-name":"/_sys/temporal-sys-add-search-attributes-task-queue/3","wf-task-queue-type":"Activity","lifecycle":"Starting","logging-call-at":"taskQueueManager.go:238"}
{"level":"info","ts":"2022-10-31T15:18:41.863Z","msg":"none","service":"matching","component":"matching-engine","wf-task-queue-name":"/_sys/temporal-sys-add-search-attributes-task-queue/3","wf-task-queue-type":"Activity","lifecycle":"Started","logging-call-at":"taskQueueManager.go:242"}
{"level":"info","ts":"2022-10-31T15:18:41.873Z","msg":"Elasticsearch client is not configured. Skipping Elasticsearch status check.","service":"worker","component":"add-search-attributes","wf-id":"temporal-sys-add-search-attributes-workflow","logging-call-at":"workflow.go:171"}
{"level":"info","ts":"2022-10-31T15:18:41.884Z","msg":"Search attributes saved to cluster metadata.","service":"worker","component":"add-search-attributes","wf-id":"temporal-sys-add-search-attributes-workflow","es-index":"","logging-call-at":"workflow.go:204"}
{"level":"info","ts":"2022-10-31T15:18:41.888Z","msg":"Workflow finished successfully.","Namespace":"temporal-system","TaskQueue":"temporal-sys-add-search-attributes-task-queue","WorkerID":"76@2a272dc9eb65@","WorkflowType":"temporal-sys-add-search-attributes-workflow","WorkflowID":"temporal-sys-add-search-attributes-workflow","RunID":"d3a747f2-2613-4ec7-9edc-eefcda44ccf4","Attempt":1,"wf-type":"temporal-sys-add-search-attributes-workflow","logging-call-at":"value.go:543"}
{"level":"info","ts":"2022-10-31T15:18:41.891Z","msg":"Get dynamic config","name":"frontend.sendRawWorkflowHistory","value":false,"default-value":false,"logging-call-at":"config.go:79"}
Custom search attributes:
+---------------------+----------+
|        NAME         |   TYPE   |
+---------------------+----------+
| CustomBoolField     | Bool     |
| CustomDatetimeField | Datetime |
| CustomDoubleField   | Double   |
| CustomIntField      | Int      |
| CustomKeywordField  | Keyword  |
| CustomStringField   | Text     |
| CustomTextField     | Text     |
+---------------------+----------+
System search attributes:
+-----------------------+----------+
|         NAME          |   TYPE   |
+-----------------------+----------+
| BatcherNamespace      | Keyword  |
| BatcherUser           | Keyword  |
| BinaryChecksums       | Keyword  |
| CloseTime             | Datetime |
| ExecutionDuration     | Int      |
| ExecutionStatus       | Keyword  |
| ExecutionTime         | Datetime |
| HistoryLength         | Int      |
| RunId                 | Keyword  |
| StartTime             | Datetime |
| StateTransitionCount  | Int      |
| TaskQueue             | Keyword  |
| TemporalChangeVersion | Keyword  |
| WorkflowId            | Keyword  |
| WorkflowType          | Keyword  |
+-----------------------+----------+
Storage mappings:
+-------------+-------------+
| COLUMN NAME | COLUMN TYPE |
+-------------+-------------+
+-------------+-------------+
Workflow info:
{
  "execution": {
    "workflowId": "temporal-sys-add-search-attributes-workflow",
    "runId": "d3a747f2-2613-4ec7-9edc-eefcda44ccf4"
  },
  "startTime": "2022-10-31T15:18:41.842994009Z",
  "closeTime": "2022-10-31T15:18:41.889062854Z",
  "status": "Completed"
}
Search attributes have been added successfully.
{"level":"info","ts":"2022-10-31T15:18:44.856Z","msg":"temporal-sys-tq-scanner-workflow workflow successfully started","service":"worker","logging-call-at":"scanner.go:194"}
{"level":"info","ts":"2022-10-31T15:19:39.931Z","msg":"none","service":"matching","component":"matching-engine","wf-task-queue-name":"/_sys/temporal-archival-tq/1","wf-task-queue-type":"Activity","lifecycle":"Starting","logging-call-at":"taskQueueManager.go:238"}
{"level":"info","ts":"2022-10-31T15:19:39.932Z","msg":"none","service":"matching","component":"matching-engine","wf-task-queue-name":"/_sys/temporal-archival-tq/1","wf-task-queue-type":"Activity","lifecycle":"Started","logging-call-at":"taskQueueManager.go:242"}
{"level":"info","ts":"2022-10-31T15:19:39.932Z","msg":"none","service":"matching","component":"matching-engine","wf-task-queue-name":"/_sys/temporal-sys-batcher-taskqueue/3","wf-task-queue-type":"Workflow","lifecycle":"Starting","logging-call-at":"taskQueueManager.go:238"}
{"level":"info","ts":"2022-10-31T15:19:39.932Z","msg":"none","service":"matching","component":"matching-engine","wf-task-queue-name":"/_sys/temporal-sys-batcher-taskqueue/3","wf-task-queue-type":"Workflow","lifecycle":"Started","logging-call-at":"taskQueueManager.go:242"}
{"level":"info","ts":"2022-10-31T15:19:39.932Z","msg":"none","service":"matching","component":"matching-engine","wf-task-queue-name":"/_sys/temporal-sys-batcher-taskqueue/3","wf-task-queue-type":"Activity","lifecycle":"Starting","logging-call-at":"taskQueueManager.go:238"}
{"level":"info","ts":"2022-10-31T15:19:39.932Z","msg":"none","service":"matching","component":"matching-engine","wf-task-queue-name":"/_sys/temporal-sys-batcher-taskqueue/3","wf-task-queue-type":"Activity","lifecycle":"Started","logging-call-at":"taskQueueManager.go:242"}
{"level":"info","ts":"2022-10-31T15:19:39.933Z","msg":"none","service":"matching","component":"matching-engine","wf-task-queue-name":"/_sys/temporal-sys-processor-parent-close-policy/3","wf-task-queue-type":"Workflow","lifecycle":"Starting","logging-call-at":"taskQueueManager.go:238"}
{"level":"info","ts":"2022-10-31T15:19:39.933Z","msg":"none","service":"matching","component":"matching-engine","wf-task-queue-name":"/_sys/temporal-sys-processor-parent-close-policy/3","wf-task-queue-type":"Workflow","lifecycle":"Started","logging-call-at":"taskQueueManager.go:242"}
{"level":"info","ts":"2022-10-31T15:19:40.820Z","msg":"Get dynamic config","name":"history.timerProcessorCompleteTimerFailureRetryCount","value":10,"default-value":10,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:19:40.820Z","msg":"Get dynamic config","name":"history.transferProcessorCompleteTransferFailureRetryCount","value":10,"default-value":10,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:19:40.820Z","msg":"Get dynamic config","name":"history.visibilityProcessorCompleteTaskFailureRetryCount","value":10,"default-value":10,"logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:20:38.929Z","msg":"none","service":"matching","component":"matching-engine","wf-task-queue-name":"/_sys/temporal-archival-tq/1","wf-task-queue-type":"Workflow","lifecycle":"Starting","logging-call-at":"taskQueueManager.go:238"}
{"level":"info","ts":"2022-10-31T15:20:38.929Z","msg":"none","service":"matching","component":"matching-engine","wf-task-queue-name":"/_sys/temporal-archival-tq/1","wf-task-queue-type":"Workflow","lifecycle":"Started","logging-call-at":"taskQueueManager.go:242"}

Let me know if you need anything to complement these

nullmaxwell commented 1 year ago

To add some context to the timeline, I am adding an excerpt that describes the first instance of the io.grpc.StatusRuntimeException: DEADLINE_EXCEEDED exception.

From airbyte-server container:

...
2022-10-31 15:18:46 INFO i.a.c.t.TemporalUtils(getTemporalClientWhenConnected):224 - Waiting for temporal server...
2022-10-31 15:18:46 WARN i.a.c.t.TemporalUtils(getTemporalClientWhenConnected):235 - Waiting for namespace default to be initialized in temporal...
2022-10-31 15:18:53 WARN i.t.i.r.GrpcSyncRetryer(retry):56 - Retrying after failure
io.grpc.StatusRuntimeException: DEADLINE_EXCEEDED: Deadline exceeded after 4.993337405s. 
...

sh4sh commented 1 year ago

Hmm interesting, this is hard to pin down. As far as I can tell temporal started successfully, after this snippet it appears to successfully talk to the airbyte db:

Temporal server started.
Registering default namespace: default.
Error: Operation DescribeNamespace failed.
Error Details: rpc error: code = NotFound desc = Namespace default does not exist.
('export TEMPORAL_CLI_SHOW_STACKS=1' to see stack traces)
Default namespace default not found. Creating...
{"level":"info","ts":"2022-10-31T15:18:41.826Z","msg":"Get dynamic config","name":"system.visibilityArchivalState","value":"enabled","default-value":"enabled","logging-call-at":"config.go:79"}
{"level":"info","ts":"2022-10-31T15:18:41.828Z","msg":"Register namespace succeeded","service":"frontend","wf-namespace":"default","wf-namespace-id":"9838de98-4c2d-4fc0-9c0c-09c574e33276","logging-call-at":"handler.go:296"}
Namespace default successfully registered.
Default namespace default registration complete.

So if it's not temporal container failure, or resource limit related, then my guess is that there's something weird going on with communication between the temporal and airbyte-server containers.

Few quick questions:

Have you ever gotten Airbyte working on this machine before?
Can you confirm that you're using the latest docker-compose or if there's a version difference between both machines?
Sorry if you've already tried, but can you see if restarting the Docker service would help? Either systemctl restart docker or equivalent, or restarting the machine itself.

Also, depending on how you last shut down Airbyte, it might still have some volumes and networks leftover in Docker. To completely remove these resources, you may need to run docker-compose down -v https://docs.docker.com/engine/reference/commandline/compose_down/#options

nullmaxwell commented 1 year ago

Thanks for taking the time to look into this with me.

To answer your questions:

Unfortunately not; I've attempted to make deployments with several different versions/tagged releases to no avail.
Yes, both machines are using docker-compose v1.29.2, there is currently no version difference between the two. Machine A (non-working Airbyte deployment):
```
> docker-compose -version
    docker-compose version 1.29.2
```
Machine B (working Airbyte deployment):
```
> docker-compose -version
    docker-compose version 1.29.2
```
I've tried manually restarting the service, bare metal reboot, and even purging stale containers with docker volume prune when re-composing alongside the command you suggested.

It's reassuring that you suspect there's no temporal failure here, but on the consideration that it could be a communication issue between containers, do you have any troubleshooting I can perform?

sh4sh commented 1 year ago

I am not too sure about troubleshooting that, but if restarting doesn't fix it then I'm not sure if that's the issue to be honest. Something we haven't checked is the worker container, which Temporal appears to communicate with successfully. Can you share logs from that container to see if there is anything there? (At this point, if you can share logs from any/all containers other than the server and temporal that would be very helpful!)

Also, it might be worth trying the latest Airbyte in case there has been relevant changes.

It looks like the same issue here: https://github.com/airbytehq/airbyte/issues/10053

Just to double check, can you confirm you have >= 30GB disk space? Also, if you're able to take a look at the Scaling Airbyte document and try some settings that might improve the behaviour.

nullmaxwell commented 1 year ago

Sure, I've attached archives of logs from all containers on v0.40.17 and v0.40.18. The issue persists in v0.40.18. If more logging is necessary just let me know!

I made a reference to #10053 in my original post as well. I do not believe it's a similar issue considering the amount of resources available on the host machine in addition to the fact that the StatusRuntimeException is not caused as a result of a heartbeat failure. Please see my notes and the 'troubleshooting performed' section on my original comment for more detail.

Also, for the sake of being thorough here are the results of df -h showing well above 30G available on the host:

...
Filesystem      Size  Used Avail Use% Mounted on
/dev/md2p1      883G  247G  592G  30% /
...

airbyte_deployment_logs_v04018.zip airbyte_deployment_logs_v04017.zip

sh4sh commented 1 year ago

I am stuck on this, I've assigned it to the team's backlog in hopes they might know what's going on. 🙏🏽 Feel free to ping me if I can help with anything.

andyjih commented 1 year ago

@benmoriceau Can you take a look? I'd timebox the investigation. Thanks!

nullmaxwell commented 1 year ago

I'm happy to provide more information if it's needed. Thanks for taking the time to triage

seyal84 commented 1 year ago

any update on this ?

airbytehq / airbyte