Skipping 12,212 KB.. Full Log

[2024/06/02 21:08:06.214 +08:00] [INFO] [resource_group.rs:145] ["add resource group"] [ru=2147483647] [name=default] [thread_id=1]
[2024/06/02 21:08:06.215 +08:00] [WARN] [worker.rs:353] ["adjust duration too small, skip adjustment."] [dur=0ns] [thread_id=17]
[2024/06/02 21:08:06.215 +08:00] [INFO] [resource_group.rs:145] ["add resource group"] [ru=2147483647] [name=default] [thread_id=18]
[2024/06/02 21:08:06.215 +08:00] [INFO] [service.rs:193] ["load controller config"] [config="RequestUnitConfig { read_base_cost: 0.125, read_cost_per_byte: 1.52587890625e-5, write_base_cost: 1.0, write_cost_per_byte: 0.0009765625, read_cpu_ms_cost: 0.3333333333333333 }"] [thread_id=17]
[2024/06/02 21:08:06.215 +08:00] [INFO] [service.rs:70] ["pd meta client creating watch stream."] [rev=12] [path=resource_group/settings] [thread_id=18]
[2024/06/02 21:08:06.215 +08:00] [WARN] [common.rs:209] ["failed to remove space holder on starting: No such file or directory (os error 2)"] [thread_id=1]
[2024/06/02 21:08:06.255 +08:00] [INFO] [mod.rs:130] ["encryption: none of key dictionary and file dictionary are found."] [thread_id=1]
[2024/06/02 21:08:06.255 +08:00] [INFO] [mod.rs:549] ["encryption is disabled."] [thread_id=1]
[2024/06/02 21:08:06.255 +08:00] [INFO] [engine.rs:93] ["Recovering raft logs takes 211.469µs"] [thread_id=1]
[2024/06/02 21:08:06.315 +08:00] [INFO] [mod.rs:298] ["Storage started."] [thread_id=1]
[2024/06/02 21:08:06.317 +08:00] [INFO] [snapshot_backup.rs:106] ["registered reject ingest and admin coprocessor to TiKV."] [thread_id=1]
[2024/06/02 21:08:06.317 +08:00] [INFO] [endpoint.rs:1138] ["create tokio runtime for backup stream"] [thread_count=2] [thread_name=backup-stream] [thread_id=1]
[2024/06/02 21:08:06.318 +08:00] [INFO] [endpoint.rs:154] ["the endpoint of stream backup started"] [path=/home/jenkins/agent/workspace/pingcap/tidb/periodics_integration_test/tidb/tikv3/log-backup-temp] [thread_id=1]
[2024/06/02 21:08:06.318 +08:00] [INFO] [checkpoint_manager.rs:67] ["subscription manager started!"] [thread_id=74]
[2024/06/02 21:08:06.318 +08:00] [INFO] [endpoint.rs:142] ["started task watcher!"] [thread_id=74]
[2024/06/02 21:08:06.318 +08:00] [INFO] [pd.rs:145] ["pd meta client creating watch stream."] [rev=13] [keys=Prefix(K(/tidb/br-stream/info/))] [thread_id=73]
[2024/06/02 21:08:06.318 +08:00] [INFO] [endpoint.rs:363] ["start watching the task changes."] [from_rev=12] [thread_id=73]
[2024/06/02 21:08:06.318 +08:00] [INFO] [pd.rs:145] ["pd meta client creating watch stream."] [rev=13] [keys=Prefix(K(/tidb/br-stream/pause/))] [thread_id=74]
[2024/06/02 21:08:06.318 +08:00] [INFO] [endpoint.rs:414] ["start watching the pausing events."] [from_rev=12] [thread_id=74]
[2024/06/02 21:08:06.318 +08:00] [INFO] [sst_importer.rs:187] ["sst importer memory limit when apply"] [size=10307921510] [ratio=0.3] [thread_id=1]
[2024/06/02 21:08:06.326 +08:00] [INFO] [raft_server.rs:187] ["trying to bootstrap cluster"] [region="id: 2 region_epoch { conf_ver: 1 version: 1 } peers { id: 3 store_id: 1 }"] [store_id=1] [thread_id=1]
[2024/06/02 21:08:06.334 +08:00] [INFO] [raft_server.rs:404] ["bootstrap cluster ok"] [cluster_id=7375892014646181758] [thread_id=1]
[2024/06/02 21:08:06.334 +08:00] [INFO] [raft_server.rs:196] ["put store to PD"] [store="id: 1 address: \"127.0.0.1:20180\" version: \"8.2.0-alpha\" peer_address: \"127.0.0.1:20180\" status_address: \"127.0.0.1:20185\" git_hash: \"44356c16acc47bf4f5cee733b5153cdeec3fff80\" start_timestamp: 1717333686 deploy_path: \"/home/jenkins/agent/workspace/pingcap/tidb/periodics_integration_test/tidb/bin\""] [thread_id=1]
[2024/06/02 21:08:06.336 +08:00] [INFO] [raft_server.rs:335] ["initializing replication mode"] [store_id=1] [status=Some()] [thread_id=1]
[2024/06/02 21:08:06.337 +08:00] [INFO] [replication_mode.rs:55] ["associated store labels"] [labels="[]"] [store_id=1] [thread_id=1]
[2024/06/02 21:08:06.337 +08:00] [INFO] [raft_server.rs:469] ["start raft store thread"] [store_id=1] [thread_id=1]
[2024/06/02 21:08:06.338 +08:00] [INFO] [snap.rs:1463] ["Initializing SnapManager, encryption is enabled: false"] [thread_id=1]
[2024/06/02 21:08:06.340 +08:00] [INFO] [write.rs:1041] ["starting store writer 0"] [thread_id=1]
[2024/06/02 21:08:06.340 +08:00] [INFO] [peer.rs:275] ["create peer"] [peer_id=3] [region_id=2] [thread_id=1]
[2024/06/02 21:08:06.340 +08:00] [INFO] [raft.rs:2684] ["switched to configuration"] [config="Configuration { voters: Configuration { incoming: Configuration { voters: {3} }, outgoing: Configuration { voters: {} } }, learners: {}, learners_next: {}, auto_leave: false }"] [raft_id=3] [region_id=2] [thread_id=1]
[2024/06/02 21:08:06.340 +08:00] [INFO] [raft.rs:1151] ["became follower at term 5"] [term=5] [raft_id=3] [region_id=2] [thread_id=1]
[2024/06/02 21:08:06.340 +08:00] [INFO] [raft.rs:387] [newRaft] [peers="Configuration { incoming: Configuration { voters: {3} }, outgoing: Configuration { voters: {} } }"] ["last term"=5] ["last index"=5] [applied=5] [commit=5] [term=5] [raft_id=3] [region_id=2] [thread_id=1]
[2024/06/02 21:08:06.340 +08:00] [INFO] [raw_node.rs:315] ["RawNode created with id 3."] [id=3] [raft_id=3] [region_id=2] [thread_id=1]
[2024/06/02 21:08:06.341 +08:00] [INFO] [raft.rs:1556] ["starting a new election"] [term=5] [raft_id=3] [region_id=2] [thread_id=1]
[2024/06/02 21:08:06.341 +08:00] [INFO] [raft.rs:1201] ["became pre-candidate at term 5"] [term=5] [raft_id=3] [region_id=2] [thread_id=1]
[2024/06/02 21:08:06.341 +08:00] [INFO] [raft.rs:1175] ["became candidate at term 6"] [term=6] [raft_id=3] [region_id=2] [thread_id=1]
[2024/06/02 21:08:06.341 +08:00] [INFO] [raft.rs:1259] ["became leader at term 6"] [term=6] [raft_id=3] [region_id=2] [thread_id=1]
[2024/06/02 21:08:06.341 +08:00] [INFO] [store.rs:1380] ["start store"] [takes=194.072µs] [merge_count=0] [applying_count=0] [tombstone_count=0] [region_count=1] [store_id=1] [thread_id=1]
[2024/06/02 21:08:06.341 +08:00] [INFO] [store.rs:1436] ["cleans up garbage data"] [takes=2.803µs] [garbage_range_count=2] [store_id=1] [thread_id=1]
[2024/06/02 21:08:06.342 +08:00] [INFO] [peer.rs:5712] ["require updating max ts"] [initial_status=25769803778] [region_id=2] [thread_id=101]
[2024/06/02 21:08:06.342 +08:00] [WARN] [store.rs:1905] ["set thread priority for raftstore failed"] [error="Os { code: 13, kind: PermissionDenied, message: \"Permission denied\" }"] [thread_id=1]
[2024/06/02 21:08:06.342 +08:00] [INFO] [gc_worker.rs:1248] ["initialize compaction filter to perform GC when necessary"] [thread_id=1]
[2024/06/02 21:08:06.342 +08:00] [INFO] [compaction_filter.rs:182] ["initialize GC context for compaction filter"] [thread_id=1]
[2024/06/02 21:08:06.343 +08:00] [INFO] [pd.rs:1705] ["succeed to update max timestamp"] [region_id=2] [thread_id=31]
[2024/06/02 21:08:06.345 +08:00] [INFO] [endpoint.rs:701] ["register observe region"] [region="id: 2 region_epoch { conf_ver: 1 version: 1 } peers { id: 3 store_id: 1 }"] [thread_id=68]
[2024/06/02 21:08:06.345 +08:00] [INFO] [endpoint.rs:358] ["Resolver initialized"] [pending_data_index=0] [snapshot_index=6] [observe_id=ObserveId(0)] [region=2] [thread_id=68]
[2024/06/02 21:08:06.346 +08:00] [INFO] [server.rs:1206] ["start register debug service"] [thread_id=1]
[2024/06/02 21:08:06.346 +08:00] [INFO] [future.rs:148] ["starting working thread"] [worker=waiter-manager] [thread_id=1]
[2024/06/02 21:08:06.347 +08:00] [INFO] [future.rs:148] ["starting working thread"] [worker=deadlock-detector] [thread_id=1]
[2024/06/02 21:08:06.347 +08:00] [INFO] [deadlock.rs:761] ["became the leader of deadlock detector!"] [self_id=1] [thread_id=127]
[2024/06/02 21:08:06.348 +08:00] [ERROR] [<unknown>] ["{\"created\":\"@1717333686.348098893\",\"description\":\"No address added out of total 1 resolved\",\"file\":\"/var/cache/cargohome/registry/src/index.crates.io-6f17d22bba15001f/grpcio-sys-0.10.3+1.44.0-patched/grpc/src/core/ext/transport/chttp2/server/chttp2_server.cc\",\"file_line\":936,\"referenced_errors\":[{\"created\":\"@1717333686.348095581\",\"description\":\"Failed to add any wildcard listeners\",\"file\":\"/var/cache/cargohome/registry/src/index.crates.io-6f17d22bba15001f/grpcio-sys-0.10.3+1.44.0-patched/grpc/src/core/lib/iomgr/tcp_server_posix.cc\",\"file_line\":349,\"referenced_errors\":[{\"created\":\"@1717333686.348082144\",\"description\":\"Unable to configure socket\",\"fd\":108,\"file\":\"/var/cache/cargohome/registry/src/index.crates.io-6f17d22bba15001f/grpcio-sys-0.10.3+1.44.0-patched/grpc/src/core/lib/iomgr/tcp_server_utils_posix_common.cc\",\"file_line\":218,\"referenced_errors\":[{\"created\":\"@1717333686.348078102\",\"description\":\"Address already in use\",\"errno\":98,\"file\":\"/var/cache/cargohome/registry/src/index.crates.io-6f17d22bba15001f/grpcio-sys-0.10.3+1.44.0-patched/grpc/src/core/lib/iomgr/tcp_server_utils_posix_common.cc\",\"file_line\":191,\"os_error\":\"Address already in use\",\"syscall\":\"bind\"}]},{\"created\":\"@1717333686.348095289\",\"description\":\"Unable to configure socket\",\"fd\":108,\"file\":\"/var/cache/cargohome/registry/src/index.crates.io-6f17d22bba15001f/grpcio-sys-0.10.3+1.44.0-patched/grpc/src/core/lib/iomgr/tcp_server_utils_posix_common.cc\",\"file_line\":218,\"referenced_errors\":[{\"created\":\"@1717333686.348091397\",\"description\":\"Address already in use\",\"errno\":98,\"file\":\"/var/cache/cargohome/registry/src/index.crates.io-6f17d22bba15001f/grpcio-sys-0.10.3+1.44.0-patched/grpc/src/core/lib/iomgr/tcp_server_utils_posix_common.cc\",\"file_line\":191,\"os_error\":\"Address already in use\",\"syscall\":\"bind\"}]}]}]}"] [thread_id=1]
[2024/06/02 21:08:06.348 +08:00] [FATAL] [server.rs:1551] ["failed to build server: BindFail(\"0.0.0.0\", 20180)"] [thread_id=1]
+ find . -name '*.out' -type f -exec tail -n 500 '{}' +
[2024/06/02 21:36:33.958 +08:00] [INFO] [analyze.go:748] ["analyze table `util__ranger`.`t` has finished"] [partition=] ["job info"="analyze table all columns with 256 buckets, 500 topn, 1 samplerate"] ["start time"=2024/06/02 21:36:33.936 +08:00] ["end time"=2024/06/02 21:36:33.957 +08:00] [cost=21.49338ms] ["sample rate reason"="use min(1, 110000/10000) as the sample-rate=1"]
[2024/06/02 21:36:33.973 +08:00] [INFO] [session.go:3985] [GENERAL_LOG] [conn=2464156092] [session_alias=] [user=root@127.0.0.1] [schemaVersion=24702] [txnStartTS=0] [forUpdateTS=0] [isReadConsistency=false] [currentDB=util__ranger] [isPessimistic=false] [sessionTxnMode=PESSIMISTIC] [sql="explain format='brief' select * from t where (a,b) in ((1,1),(2,2)) and c = 3;"]
[2024/06/02 21:36:33.973 +08:00] [INFO] [session.go:3985] [GENERAL_LOG] [conn=2464156092] [session_alias=] [user=root@127.0.0.1] [schemaVersion=24702] [txnStartTS=0] [forUpdateTS=0] [isReadConsistency=false] [currentDB=util__ranger] [isPessimistic=false] [sessionTxnMode=PESSIMISTIC] [sql="select * from t where (a,b) in ((1,1),(2,2)) and c = 3;"]
[2024/06/02 21:36:33.974 +08:00] [INFO] [session.go:3985] [GENERAL_LOG] [conn=2464156092] [session_alias=] [user=root@127.0.0.1] [schemaVersion=24702] [txnStartTS=0] [forUpdateTS=0] [isReadConsistency=false] [currentDB=util__ranger] [isPessimistic=false] [sessionTxnMode=PESSIMISTIC] [sql="explain format='brief' select * from t where ((a = 1 and b = 1) or (a = 2 and b = 2)) and c = 3;"]
[2024/06/02 21:36:33.974 +08:00] [INFO] [session.go:3985] [GENERAL_LOG] [conn=2464156092] [session_alias=] [user=root@127.0.0.1] [schemaVersion=24702] [txnStartTS=0] [forUpdateTS=0] [isReadConsistency=false] [currentDB=util__ranger] [isPessimistic=false] [sessionTxnMode=PESSIMISTIC] [sql="select * from t where ((a = 1 and b = 1) or (a = 2 and b = 2)) and c = 3;"]
[2024/06/02 21:36:33.975 +08:00] [INFO] [session.go:3985] [GENERAL_LOG] [conn=2464156092] [session_alias=] [user=root@127.0.0.1] [schemaVersion=24702] [txnStartTS=0] [forUpdateTS=0] [isReadConsistency=false] [currentDB=util__ranger] [isPessimistic=false] [sessionTxnMode=PESSIMISTIC] [sql="explain format='brief' select * from t use index(primary) where ((a = 1) or (a = 2 and b = 2)) and c = 3;"]
[2024/06/02 21:36:33.976 +08:00] [INFO] [session.go:3985] [GENERAL_LOG] [conn=2464156092] [session_alias=] [user=root@127.0.0.1] [schemaVersion=24702] [txnStartTS=0] [forUpdateTS=0] [isReadConsistency=false] [currentDB=util__ranger] [isPessimistic=false] [sessionTxnMode=PESSIMISTIC] [sql="select * from t use index(primary) where ((a = 1) or (a = 2 and b = 2)) and c = 3;"]
[2024/06/02 21:36:33.977 +08:00] [INFO] [session.go:3985] [GENERAL_LOG] [conn=2464156092] [session_alias=] [user=root@127.0.0.1] [schemaVersion=24702] [txnStartTS=0] [forUpdateTS=0] [isReadConsistency=false] [currentDB=util__ranger] [isPessimistic=false] [sessionTxnMode=PESSIMISTIC] [sql="explain format='brief' select * from t where ((a = 1 and b = 1) or (a = 2 and b = 2)) and c = 3 and (a = 1 or a = 2);"]
[2024/06/02 21:36:33.978 +08:00] [INFO] [session.go:3985] [GENERAL_LOG] [conn=2464156092] [session_alias=] [user=root@127.0.0.1] [schemaVersion=24702] [txnStartTS=0] [forUpdateTS=0] [isReadConsistency=false] [currentDB=util__ranger] [isPessimistic=false] [sessionTxnMode=PESSIMISTIC] [sql="select * from t where ((a = 1 and b = 1) or (a = 2 and b = 2)) and c = 3 and (a = 1 or a = 2);"]
[2024/06/02 21:36:33.979 +08:00] [INFO] [session.go:3985] [GENERAL_LOG] [conn=2464156092] [session_alias=] [user=root@127.0.0.1] [schemaVersion=24702] [txnStartTS=0] [forUpdateTS=0] [isReadConsistency=false] [currentDB=util__ranger] [isPessimistic=false] [sessionTxnMode=PESSIMISTIC] [sql="explain format='brief' select * from t where (a,b) in ((1,1),(2,2)) and c > 2;"]
[2024/06/02 21:36:33.979 +08:00] [INFO] [session.go:3985] [GENERAL_LOG] [conn=2464156092] [session_alias=] [user=root@127.0.0.1] [schemaVersion=24702] [txnStartTS=0] [forUpdateTS=0] [isReadConsistency=false] [currentDB=util__ranger] [isPessimistic=false] [sessionTxnMode=PESSIMISTIC] [sql="select * from t where (a,b) in ((1,1),(2,2)) and c > 2;"]
[2024/06/02 21:36:33.980 +08:00] [INFO] [session.go:3985] [GENERAL_LOG] [conn=2464156092] [session_alias=] [user=root@127.0.0.1] [schemaVersion=24702] [txnStartTS=0] [forUpdateTS=0] [isReadConsistency=false] [currentDB=util__ranger] [isPessimistic=false] [sessionTxnMode=PESSIMISTIC] [sql="explain format='brief' select * from t where ((a = 1 and b = 1) or (a = 2 and b = 2)) and c > 2;"]
[2024/06/02 21:36:33.981 +08:00] [INFO] [session.go:3985] [GENERAL_LOG] [conn=2464156092] [session_alias=] [user=root@127.0.0.1] [schemaVersion=24702] [txnStartTS=0] [forUpdateTS=0] [isReadConsistency=false] [currentDB=util__ranger] [isPessimistic=false] [sessionTxnMode=PESSIMISTIC] [sql="select * from t where ((a = 1 and b = 1) or (a = 2 and b = 2)) and c > 2;"]
[2024/06/02 21:36:33.981 +08:00] [INFO] [session.go:3985] [GENERAL_LOG] [conn=2464156092] [session_alias=] [user=root@127.0.0.1] [schemaVersion=24702] [txnStartTS=0] [forUpdateTS=0] [isReadConsistency=false] [currentDB=util__ranger] [isPessimistic=false] [sessionTxnMode=PESSIMISTIC] [sql="SET @@SESSION.`tidb_regard_null_as_point`=FALSE"]
[2024/06/02 21:36:33.981 +08:00] [INFO] [session.go:3959] ["CRUCIAL OPERATION"] [conn=2464156092] [schemaVersion=24702] [cur_db=util__ranger] [sql="drop table if exists t;"] [user=root@%]
[2024/06/02 21:36:33.992 +08:00] [INFO] [ddl_worker.go:261] ["add DDL jobs"] [category=ddl] ["batch count"=1] [jobs="ID:20635, Type:drop table, State:queueing, SchemaState:public, SchemaID:20607, TableID:20633, RowCount:0, ArgLen:2, start time: 2024-06-02 21:36:33.961 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:0, LocalMode: false; "] [table=true]
[2024/06/02 21:36:33.992 +08:00] [INFO] [ddl.go:1192] ["start DDL job"] [category=ddl] [job="ID:20635, Type:drop table, State:queueing, SchemaState:public, SchemaID:20607, TableID:20633, RowCount:0, ArgLen:2, start time: 2024-06-02 21:36:33.961 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:0, LocalMode: false"] [query="drop table if exists t;"]
[2024/06/02 21:36:34.011 +08:00] [INFO] [ddl_worker.go:1210] ["run DDL job"] [worker="worker 4, tp general"] [category=ddl] [jobID=20635] [conn=2464156092] [category=ddl] [job="ID:20635, Type:drop table, State:queueing, SchemaState:public, SchemaID:20607, TableID:20633, RowCount:0, ArgLen:0, start time: 2024-06-02 21:36:33.961 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:0, LocalMode: false"]
[2024/06/02 21:36:34.029 +08:00] [INFO] [ddl_worker.go:1210] ["run DDL job"] [worker="worker 4, tp general"] [category=ddl] [jobID=20635] [conn=2464156092] [category=ddl] [job="ID:20635, Type:drop table, State:running, SchemaState:write only, SchemaID:20607, TableID:20633, RowCount:0, ArgLen:0, start time: 2024-06-02 21:36:33.961 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:0, LocalMode: false"]
[2024/06/02 21:36:34.047 +08:00] [INFO] [ddl_worker.go:1210] ["run DDL job"] [worker="worker 4, tp general"] [category=ddl] [jobID=20635] [conn=2464156092] [category=ddl] [job="ID:20635, Type:drop table, State:running, SchemaState:delete only, SchemaID:20607, TableID:20633, RowCount:0, ArgLen:0, start time: 2024-06-02 21:36:33.961 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:0, LocalMode: false"]
[2024/06/02 21:36:34.065 +08:00] [INFO] [delete_range.go:447] ["insert into delete-range table"] [category=ddl] [jobID=20635] [tableIDs="[20633]"] [comment="drop table: table ID"]
[2024/06/02 21:36:34.066 +08:00] [INFO] [delete_range.go:112] ["add job into delete-range table"] [category=ddl] [jobID=20635] [jobType="drop table"]
[2024/06/02 21:36:34.067 +08:00] [INFO] [ddl_worker.go:763] ["finish DDL job"] [worker="worker 4, tp general"] [category=ddl] [jobID=20635] [conn=2464156092] [job="ID:20635, Type:drop table, State:synced, SchemaState:none, SchemaID:20607, TableID:20633, RowCount:0, ArgLen:3, start time: 2024-06-02 21:36:33.961 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:0, LocalMode: false"]
[2024/06/02 21:36:34.070 +08:00] [INFO] [ddl.go:1298] ["DDL job is finished"] [category=ddl] [jobID=20635]
[2024/06/02 21:36:34.070 +08:00] [INFO] [callback.go:140] ["performing DDL change, must reload"] [category=ddl]
[2024/06/02 21:36:34.071 +08:00] [INFO] [domain.go:288] ["diff load InfoSchema success"] [isV2=false] [currentSchemaVersion=24702] [neededSchemaVersion=24705] ["start time"=417.008µs] [gotSchemaVersion=24705] [phyTblIDs="[20633]"] [actionTypes="[4]"] [diffTypes="[\"drop table\",\"drop table\",\"drop table\"]"]
[2024/06/02 21:36:34.072 +08:00] [INFO] [session.go:3959] ["CRUCIAL OPERATION"] [conn=2464156092] [schemaVersion=24705] [cur_db=util__ranger] [sql="create table t(a int, b int, c int, key(a,b,c));"] [user=root@%]
[2024/06/02 21:36:34.084 +08:00] [INFO] [ddl_worker.go:261] ["add DDL jobs"] [category=ddl] ["batch count"=1] [jobs="ID:20637, Type:create table, State:queueing, SchemaState:none, SchemaID:20607, TableID:20636, RowCount:0, ArgLen:2, start time: 2024-06-02 21:36:34.061 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:0, LocalMode: false; "] [table=true]
[2024/06/02 21:36:34.084 +08:00] [INFO] [ddl.go:1192] ["start DDL job"] [category=ddl] [job="ID:20637, Type:create table, State:queueing, SchemaState:none, SchemaID:20607, TableID:20636, RowCount:0, ArgLen:2, start time: 2024-06-02 21:36:34.061 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:0, LocalMode: false"] [query="create table t(a int, b int, c int, key(a,b,c));"]
[2024/06/02 21:36:34.115 +08:00] [INFO] [ddl_worker.go:1210] ["run DDL job"] [worker="worker 4, tp general"] [category=ddl] [jobID=20637] [conn=2464156092] [category=ddl] [job="ID:20637, Type:create table, State:queueing, SchemaState:none, SchemaID:20607, TableID:20636, RowCount:0, ArgLen:0, start time: 2024-06-02 21:36:34.061 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:0, LocalMode: false"]
[2024/06/02 21:36:34.136 +08:00] [INFO] [ddl_worker.go:763] ["finish DDL job"] [worker="worker 4, tp general"] [category=ddl] [jobID=20637] [conn=2464156092] [job="ID:20637, Type:create table, State:synced, SchemaState:public, SchemaID:20607, TableID:20636, RowCount:0, ArgLen:0, start time: 2024-06-02 21:36:34.061 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:0, LocalMode: false"]
[2024/06/02 21:36:34.139 +08:00] [INFO] [ddl.go:1298] ["DDL job is finished"] [category=ddl] [jobID=20637]
[2024/06/02 21:36:34.139 +08:00] [INFO] [callback.go:140] ["performing DDL change, must reload"] [category=ddl]
[2024/06/02 21:36:34.139 +08:00] [INFO] [split_region.go:85] ["split batch regions request"] ["split key count"=1] ["batch count"=1] ["first batch, region ID"=14] ["first split key"=74800000000000509c]
[2024/06/02 21:36:34.140 +08:00] [INFO] [split_region.go:187] ["batch split regions complete"] ["batch region ID"=14] ["first at"=74800000000000509c] ["first new region left"="{Id:16812 StartKey:7480000000000050ff9900000000000000f8 EndKey:7480000000000050ff9c00000000000000f8 RegionEpoch:{ConfVer:1 Version:8098} Peers:[id:16813 store_id:1 ] EncryptionMeta:<nil> IsInFlashback:false FlashbackStartTs:0}"] ["new region count"=1]
[2024/06/02 21:36:34.140 +08:00] [INFO] [split_region.go:236] ["split regions complete"] ["region count"=1] ["region IDs"="[16812]"]
[2024/06/02 21:36:34.140 +08:00] [INFO] [domain.go:288] ["diff load InfoSchema success"] [isV2=false] [currentSchemaVersion=24705] [neededSchemaVersion=24706] ["start time"=547.705µs] [gotSchemaVersion=24706] [phyTblIDs="[20636]"] [actionTypes="[3]"] [diffTypes="[\"create table\"]"]
[2024/06/02 21:36:34.142 +08:00] [INFO] [session.go:3985] [GENERAL_LOG] [conn=2464156092] [session_alias=] [user=root@127.0.0.1] [schemaVersion=24706] [txnStartTS=0] [forUpdateTS=0] [isReadConsistency=false] [currentDB=util__ranger] [isPessimistic=false] [sessionTxnMode=PESSIMISTIC] [sql="insert into t values(1,2,2);"]
[2024/06/02 21:36:34.144 +08:00] [INFO] [session.go:3985] [GENERAL_LOG] [conn=2464156092] [session_alias=] [user=root@127.0.0.1] [schemaVersion=24706] [txnStartTS=0] [forUpdateTS=0] [isReadConsistency=false] [currentDB=util__ranger] [isPessimistic=false] [sessionTxnMode=PESSIMISTIC] [sql="explain format='brief' select * from t where a = 1 and b in (1, 2) and c > 1;"]
[2024/06/02 21:36:34.144 +08:00] [INFO] [session.go:3985] [GENERAL_LOG] [conn=2464156092] [session_alias=] [user=root@127.0.0.1] [schemaVersion=24706] [txnStartTS=0] [forUpdateTS=0] [isReadConsistency=false] [currentDB=util__ranger] [isPessimistic=false] [sessionTxnMode=PESSIMISTIC] [sql="select * from t where a = 1 and b in (1, 2) and c > 1;"]
[2024/06/02 21:36:34.145 +08:00] [INFO] [session.go:3985] [GENERAL_LOG] [conn=2464156092] [session_alias=] [user=root@127.0.0.1] [schemaVersion=24706] [txnStartTS=0] [forUpdateTS=0] [isReadConsistency=false] [currentDB=util__ranger] [isPessimistic=false] [sessionTxnMode=PESSIMISTIC] [sql="explain format='brief' select * from t where a = 1 and (b = 1 or b = 2) and c > 1;"]
[2024/06/02 21:36:34.146 +08:00] [INFO] [session.go:3985] [GENERAL_LOG] [conn=2464156092] [session_alias=] [user=root@127.0.0.1] [schemaVersion=24706] [txnStartTS=0] [forUpdateTS=0] [isReadConsistency=false] [currentDB=util__ranger] [isPessimistic=false] [sessionTxnMode=PESSIMISTIC] [sql="select * from t where a = 1 and (b = 1 or b = 2) and c > 1;"]
[2024/06/02 21:36:34.147 +08:00] [INFO] [session.go:3985] [GENERAL_LOG] [conn=2464156092] [session_alias=] [user=root@127.0.0.1] [schemaVersion=24706] [txnStartTS=0] [forUpdateTS=0] [isReadConsistency=false] [currentDB=util__ranger] [isPessimistic=false] [sessionTxnMode=PESSIMISTIC] [sql="explain format='brief' select * from t where a = 1 and (b = 1 or b in (2, 3)) and c > 1;"]
[2024/06/02 21:36:34.147 +08:00] [INFO] [session.go:3985] [GENERAL_LOG] [conn=2464156092] [session_alias=] [user=root@127.0.0.1] [schemaVersion=24706] [txnStartTS=0] [forUpdateTS=0] [isReadConsistency=false] [currentDB=util__ranger] [isPessimistic=false] [sessionTxnMode=PESSIMISTIC] [sql="select * from t where a = 1 and (b = 1 or b in (2, 3)) and c > 1;"]
[2024/06/02 21:36:34.148 +08:00] [INFO] [session.go:3985] [GENERAL_LOG] [conn=2464156092] [session_alias=] [user=root@127.0.0.1] [schemaVersion=24706] [txnStartTS=0] [forUpdateTS=0] [isReadConsistency=false] [currentDB=util__ranger] [isPessimistic=false] [sessionTxnMode=PESSIMISTIC] [sql="explain format='brief' select * from t where a = 1 and (b = 1 or b = 2) and b = 3 and c > 1;"]
[2024/06/02 21:36:34.148 +08:00] [INFO] [session.go:3985] [GENERAL_LOG] [conn=2464156092] [session_alias=] [user=root@127.0.0.1] [schemaVersion=24706] [txnStartTS=0] [forUpdateTS=0] [isReadConsistency=false] [currentDB=util__ranger] [isPessimistic=false] [sessionTxnMode=PESSIMISTIC] [sql="select * from t where a = 1 and (b = 1 or b = 2) and b = 3 and c > 1;"]
[2024/06/02 21:36:34.148 +08:00] [INFO] [session.go:3985] [GENERAL_LOG] [conn=2464156092] [session_alias=] [user=root@127.0.0.1] [schemaVersion=24706] [txnStartTS=0] [forUpdateTS=0] [isReadConsistency=false] [currentDB=util__ranger] [isPessimistic=false] [sessionTxnMode=PESSIMISTIC] [sql="explain format='brief' select * from t where a = 1 and (b is null or b = 2);"]
[2024/06/02 21:36:34.149 +08:00] [INFO] [session.go:3985] [GENERAL_LOG] [conn=2464156092] [session_alias=] [user=root@127.0.0.1] [schemaVersion=24706] [txnStartTS=0] [forUpdateTS=0] [isReadConsistency=false] [currentDB=util__ranger] [isPessimistic=false] [sessionTxnMode=PESSIMISTIC] [sql="select * from t where a = 1 and (b is null or b = 2);"]
[2024/06/02 21:36:34.150 +08:00] [INFO] [session.go:3985] [GENERAL_LOG] [conn=2464156092] [session_alias=] [user=root@127.0.0.1] [schemaVersion=24706] [txnStartTS=0] [forUpdateTS=0] [isReadConsistency=false] [currentDB=util__ranger] [isPessimistic=false] [sessionTxnMode=PESSIMISTIC] [sql="explain format='brief' select * from t where a = 1 and (b is null or b = 2) and c > 1;"]
[2024/06/02 21:36:34.150 +08:00] [INFO] [session.go:3985] [GENERAL_LOG] [conn=2464156092] [session_alias=] [user=root@127.0.0.1] [schemaVersion=24706] [txnStartTS=0] [forUpdateTS=0] [isReadConsistency=false] [currentDB=util__ranger] [isPessimistic=false] [sessionTxnMode=PESSIMISTIC] [sql="select * from t where a = 1 and (b is null or b = 2) and c > 1;"]
[2024/06/02 21:36:34.151 +08:00] [INFO] [session.go:3985] [GENERAL_LOG] [conn=2464156092] [session_alias=] [user=root@127.0.0.1] [schemaVersion=24706] [txnStartTS=0] [forUpdateTS=0] [isReadConsistency=false] [currentDB=util__ranger] [isPessimistic=false] [sessionTxnMode=PESSIMISTIC] [sql="explain format='brief' select * from t where a = 1 and b is null and c > 1;"]
[2024/06/02 21:36:34.151 +08:00] [INFO] [session.go:3985] [GENERAL_LOG] [conn=2464156092] [session_alias=] [user=root@127.0.0.1] [schemaVersion=24706] [txnStartTS=0] [forUpdateTS=0] [isReadConsistency=false] [currentDB=util__ranger] [isPessimistic=false] [sessionTxnMode=PESSIMISTIC] [sql="select * from t where a = 1 and b is null and c > 1;"]
[2024/06/02 21:36:34.152 +08:00] [INFO] [session.go:3985] [GENERAL_LOG] [conn=2464156092] [session_alias=] [user=root@127.0.0.1] [schemaVersion=24706] [txnStartTS=0] [forUpdateTS=0] [isReadConsistency=false] [currentDB=util__ranger] [isPessimistic=false] [sessionTxnMode=PESSIMISTIC] [sql="explain format='brief' select * from t where a = 1 and b is null and b is null and c > 1;"]
[2024/06/02 21:36:34.153 +08:00] [INFO] [session.go:3985] [GENERAL_LOG] [conn=2464156092] [session_alias=] [user=root@127.0.0.1] [schemaVersion=24706] [txnStartTS=0] [forUpdateTS=0] [isReadConsistency=false] [currentDB=util__ranger] [isPessimistic=false] [sessionTxnMode=PESSIMISTIC] [sql="select * from t where a = 1 and b is null and b is null and c > 1;"]
[2024/06/02 21:36:34.153 +08:00] [INFO] [session.go:3985] [GENERAL_LOG] [conn=2464156092] [session_alias=] [user=root@127.0.0.1] [schemaVersion=24706] [txnStartTS=0] [forUpdateTS=0] [isReadConsistency=false] [currentDB=util__ranger] [isPessimistic=false] [sessionTxnMode=PESSIMISTIC] [sql="explain format='brief' select * from t where a = 1 and b is null and b = 1 and c > 1;"]
[2024/06/02 21:36:34.154 +08:00] [INFO] [session.go:3985] [GENERAL_LOG] [conn=2464156092] [session_alias=] [user=root@127.0.0.1] [schemaVersion=24706] [txnStartTS=0] [forUpdateTS=0] [isReadConsistency=false] [currentDB=util__ranger] [isPessimistic=false] [sessionTxnMode=PESSIMISTIC] [sql="select * from t where a = 1 and b is null and b = 1 and c > 1;"]
[2024/06/02 21:36:34.154 +08:00] [INFO] [session.go:3985] [GENERAL_LOG] [conn=2464156092] [session_alias=] [user=root@127.0.0.1] [schemaVersion=24706] [txnStartTS=0] [forUpdateTS=0] [isReadConsistency=false] [currentDB=util__ranger] [isPessimistic=false] [sessionTxnMode=PESSIMISTIC] [sql="SET @@SESSION.`tidb_regard_null_as_point`=DEFAULT"]
[2024/06/02 21:36:34.154 +08:00] [INFO] [session.go:3985] [GENERAL_LOG] [conn=2464156092] [session_alias=] [user=root@127.0.0.1] [schemaVersion=24706] [txnStartTS=0] [forUpdateTS=0] [isReadConsistency=false] [currentDB=util__ranger] [isPessimistic=false] [sessionTxnMode=PESSIMISTIC] [sql="SET @@SESSION.`tidb_cost_model_version`=2"]
[2024/06/02 21:36:34.154 +08:00] [INFO] [session.go:3959] ["CRUCIAL OPERATION"] [conn=2464156092] [schemaVersion=24706] [cur_db=util__ranger] [sql="drop table if exists t0;"] [user=root@%]
[2024/06/02 21:36:34.154 +08:00] [INFO] [session.go:3959] ["CRUCIAL OPERATION"] [conn=2464156092] [schemaVersion=24706] [cur_db=util__ranger] [sql="CREATE TABLE t0(c0 TEXT(10));"] [user=root@%]
[2024/06/02 21:36:34.155 +08:00] [INFO] [ddl_api.go:1135] ["Automatically convert BLOB(10) to TINYBLOB"] [category=ddl]
[2024/06/02 21:36:34.167 +08:00] [INFO] [ddl_worker.go:261] ["add DDL jobs"] [category=ddl] ["batch count"=1] [jobs="ID:20639, Type:create table, State:queueing, SchemaState:none, SchemaID:20607, TableID:20638, RowCount:0, ArgLen:2, start time: 2024-06-02 21:36:34.161 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:0, LocalMode: false; "] [table=true]
[2024/06/02 21:36:34.167 +08:00] [INFO] [ddl.go:1192] ["start DDL job"] [category=ddl] [job="ID:20639, Type:create table, State:queueing, SchemaState:none, SchemaID:20607, TableID:20638, RowCount:0, ArgLen:2, start time: 2024-06-02 21:36:34.161 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:0, LocalMode: false"] [query="CREATE TABLE t0(c0 TEXT(10));"]
[2024/06/02 21:36:34.187 +08:00] [INFO] [ddl_worker.go:1210] ["run DDL job"] [worker="worker 4, tp general"] [category=ddl] [jobID=20639] [conn=2464156092] [category=ddl] [job="ID:20639, Type:create table, State:queueing, SchemaState:none, SchemaID:20607, TableID:20638, RowCount:0, ArgLen:0, start time: 2024-06-02 21:36:34.161 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:0, LocalMode: false"]
[2024/06/02 21:36:34.206 +08:00] [INFO] [ddl_worker.go:763] ["finish DDL job"] [worker="worker 4, tp general"] [category=ddl] [jobID=20639] [conn=2464156092] [job="ID:20639, Type:create table, State:synced, SchemaState:public, SchemaID:20607, TableID:20638, RowCount:0, ArgLen:0, start time: 2024-06-02 21:36:34.161 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:0, LocalMode: false"]
[2024/06/02 21:36:34.209 +08:00] [INFO] [ddl.go:1298] ["DDL job is finished"] [category=ddl] [jobID=20639]
[2024/06/02 21:36:34.209 +08:00] [INFO] [callback.go:140] ["performing DDL change, must reload"] [category=ddl]
[2024/06/02 21:36:34.209 +08:00] [INFO] [split_region.go:85] ["split batch regions request"] ["split key count"=1] ["batch count"=1] ["first batch, region ID"=14] ["first split key"=74800000000000509e]
[2024/06/02 21:36:34.210 +08:00] [INFO] [split_region.go:187] ["batch split regions complete"] ["batch region ID"=14] ["first at"=74800000000000509e] ["first new region left"="{Id:16814 StartKey:7480000000000050ff9c00000000000000f8 EndKey:7480000000000050ff9e00000000000000f8 RegionEpoch:{ConfVer:1 Version:8099} Peers:[id:16815 store_id:1 ] EncryptionMeta:<nil> IsInFlashback:false FlashbackStartTs:0}"] ["new region count"=1]
[2024/06/02 21:36:34.210 +08:00] [INFO] [split_region.go:236] ["split regions complete"] ["region count"=1] ["region IDs"="[16814]"]
[2024/06/02 21:36:34.210 +08:00] [INFO] [domain.go:288] ["diff load InfoSchema success"] [isV2=false] [currentSchemaVersion=24706] [neededSchemaVersion=24707] ["start time"=474.68µs] [gotSchemaVersion=24707] [phyTblIDs="[20638]"] [actionTypes="[3]"] [diffTypes="[\"create table\"]"]
[2024/06/02 21:36:34.211 +08:00] [INFO] [session.go:3985] [GENERAL_LOG] [conn=2464156092] [session_alias=] [user=root@127.0.0.1] [schemaVersion=24707] [txnStartTS=0] [forUpdateTS=0] [isReadConsistency=false] [currentDB=util__ranger] [isPessimistic=false] [sessionTxnMode=PESSIMISTIC] [sql="INSERT INTO t0(c0) VALUES (1);"]
[2024/06/02 21:36:34.213 +08:00] [INFO] [session.go:3959] ["CRUCIAL OPERATION"] [conn=2464156092] [schemaVersion=24707] [cur_db=util__ranger] [sql="CREATE INDEX i0 ON t0(c0(255));"] [user=root@%]
[2024/06/02 21:36:34.225 +08:00] [INFO] [ddl_worker.go:261] ["add DDL jobs"] [category=ddl] ["batch count"=1] [jobs="ID:20640, Type:add index, State:queueing, SchemaState:none, SchemaID:20607, TableID:20638, RowCount:0, ArgLen:6, start time: 2024-06-02 21:36:34.211 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:0, LocalMode: false, UniqueWarnings:0; "] [table=true]
[2024/06/02 21:36:34.225 +08:00] [INFO] [ddl.go:1192] ["start DDL job"] [category=ddl] [job="ID:20640, Type:add index, State:queueing, SchemaState:none, SchemaID:20607, TableID:20638, RowCount:0, ArgLen:6, start time: 2024-06-02 21:36:34.211 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:0, LocalMode: false, UniqueWarnings:0"] [query="CREATE INDEX i0 ON t0(c0(255));"]
[2024/06/02 21:36:34.260 +08:00] [INFO] [ddl_worker.go:1210] ["run DDL job"] [worker="worker 5, tp add index"] [category=ddl] [jobID=20640] [conn=2464156092] [category=ddl] [job="ID:20640, Type:add index, State:queueing, SchemaState:none, SchemaID:20607, TableID:20638, RowCount:0, ArgLen:0, start time: 2024-06-02 21:36:34.211 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:0, LocalMode: false, UniqueWarnings:0"]
[2024/06/02 21:36:34.261 +08:00] [INFO] [index.go:653] ["run add index job"] [category=ddl] [job="ID:20640, Type:add index, State:running, SchemaState:none, SchemaID:20607, TableID:20638, RowCount:0, ArgLen:6, start time: 2024-06-02 21:36:34.211 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:0, LocalMode: false, UniqueWarnings:0"] [indexInfo="{\"id\":1,\"idx_name\":{\"O\":\"i0\",\"L\":\"i0\"},\"tbl_name\":{\"O\":\"\",\"L\":\"\"},\"idx_cols\":[{\"name\":{\"O\":\"c0\",\"L\":\"c0\"},\"offset\":0,\"length\":255}],\"state\":0,\"backfill_state\":0,\"comment\":\"\",\"index_type\":1,\"is_unique\":false,\"is_primary\":false,\"is_invisible\":false,\"is_global\":false,\"mv_index\":false}"]
[2024/06/02 21:36:34.283 +08:00] [INFO] [ddl_worker.go:1210] ["run DDL job"] [worker="worker 6, tp add index"] [category=ddl] [jobID=20640] [conn=2464156092] [category=ddl] [job="ID:20640, Type:add index, State:running, SchemaState:delete only, SchemaID:20607, TableID:20638, RowCount:0, ArgLen:0, start time: 2024-06-02 21:36:34.211 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:0, LocalMode: false, UniqueWarnings:0"]
[2024/06/02 21:36:34.309 +08:00] [INFO] [ddl_worker.go:1210] ["run DDL job"] [worker="worker 5, tp add index"] [category=ddl] [jobID=20640] [conn=2464156092] [category=ddl] [job="ID:20640, Type:add index, State:running, SchemaState:write only, SchemaID:20607, TableID:20638, RowCount:0, ArgLen:0, start time: 2024-06-02 21:36:34.211 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:0, LocalMode: false, UniqueWarnings:0"]
[2024/06/02 21:36:34.334 +08:00] [INFO] [ddl_worker.go:1210] ["run DDL job"] [worker="worker 6, tp add index"] [category=ddl] [jobID=20640] [conn=2464156092] [category=ddl] [job="ID:20640, Type:add index, State:running, SchemaState:write reorganization, SchemaID:20607, TableID:20638, RowCount:0, ArgLen:0, start time: 2024-06-02 21:36:34.211 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:0, LocalMode: false, UniqueWarnings:0"]
[2024/06/02 21:36:34.334 +08:00] [INFO] [index.go:856] ["index backfill state running"] [category=ddl] ["job ID"=20640] [table=t0] ["ingest mode"=true] [index=i0]
[2024/06/02 21:36:34.335 +08:00] [INFO] [reorg.go:764] ["job get table range"] [category=ddl] [jobID=20640] [physicalTableID=20638] [startKey=74800000000000509e5f728000000000000001] [endKey=74800000000000509e5f72800000000000000100]
[2024/06/02 21:36:34.357 +08:00] [INFO] [ddl_worker.go:1210] ["run DDL job"] [worker="worker 5, tp add index"] [category=ddl] [jobID=20640] [conn=2464156092] [category=ddl] [job="ID:20640, Type:add index, State:running, SchemaState:write reorganization, SchemaID:20607, TableID:20638, RowCount:0, ArgLen:0, start time: 2024-06-02 21:36:34.211 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:450189169606262791, LocalMode: false, UniqueWarnings:0"]
[2024/06/02 21:36:34.357 +08:00] [INFO] [index.go:856] ["index backfill state running"] [category=ddl] ["job ID"=20640] [table=t0] ["ingest mode"=true] [index=i0]
[2024/06/02 21:36:34.361 +08:00] [INFO] [index.go:2104] ["adjusted add-index task concurrency"] [category=ddl] [worker-cnt=4] [task-concurrency=4] [task-key=ddl/backfill/20640]
[2024/06/02 21:36:34.368 +08:00] [INFO] [index.go:2188] ["estimate row size"] [tableID=20638] [size=0] [error="less than 3 regions"]
[2024/06/02 21:36:34.377 +08:00] [INFO] [scheduler_manager.go:355] ["task scheduler started"] [task-id=660001]
[2024/06/02 21:36:34.377 +08:00] [INFO] [scheduler.go:117] ["schedule task"] [task-id=660001] [task-type=backfill] [allocated-slots=true] [state=pending] [concurrency=4]
[2024/06/02 21:36:34.878 +08:00] [INFO] [scheduler.go:409] ["switch to next step"] [task-id=660001] [task-type=backfill] [allocated-slots=true] [current-step=init] [next-step=read-index]
[2024/06/02 21:36:34.878 +08:00] [INFO] [scheduler.go:433] ["eligible instances"] [task-id=660001] [task-type=backfill] [allocated-slots=true] [num=1]
[2024/06/02 21:36:34.879 +08:00] [INFO] [backfilling_dist_scheduler.go:95] ["on next subtasks batch"] [category=ddl] [type=backfill] [task-id=660001] [curr-step=init] [next-step=read-index]
[2024/06/02 21:36:34.880 +08:00] [INFO] [scheduler.go:459] ["schedule subtasks"] [task-id=660001] [task-type=backfill] [allocated-slots=true] [state=pending] [step=read-index] [concurrency=4] [subtasks=1]
[2024/06/02 21:36:35.166 +08:00] [INFO] [manager.go:328] ["task executor started"] [task-id=660001] [type=backfill] [remaining-slots=4]
[2024/06/02 21:36:35.469 +08:00] [INFO] [task_executor.go:291] ["execute task step start"] [task-id=660001] [task-type=backfill] [step=read-index] [mem-limit-percent=0.7] [server-mem-limit=80%] [resource="[CPU=4, Mem=16GiB]"]
[2024/06/02 21:36:35.470 +08:00] [INFO] [config.go:166] ["change memory setting for ingest"] ["local writer memory cache size"=134217728] ["engine memory cache size"=536870912] ["range concurrency"=4]
[2024/06/02 21:36:35.470 +08:00] [INFO] [backend_mgr.go:247] ["create local backend for adding index"] [category=ddl-ingest] [sortDir=/tmp/tidb/tmp_ddl-37215/20640] [keyspaceName=]
[2024/06/02 21:36:35.471 +08:00] [INFO] [pd_service_discovery.go:1016] ["[pd] switch leader"] [new-leader=http://127.0.0.1:2379] [old-leader=]
[2024/06/02 21:36:35.471 +08:00] [INFO] [pd_service_discovery.go:498] ["[pd] init cluster id"] [cluster-id=7375892013088395501]
[2024/06/02 21:36:35.471 +08:00] [INFO] [client.go:613] ["[pd] changing service mode"] [old-mode=UNKNOWN_SVC_MODE] [new-mode=PD_SVC_MODE]
[2024/06/02 21:36:35.471 +08:00] [INFO] [tso_client.go:293] ["[tso] switch dc tso global allocator serving url"] [dc-location=global] [new-url=http://127.0.0.1:2379]
[2024/06/02 21:36:35.472 +08:00] [INFO] [client.go:619] ["[pd] service mode changed"] [old-mode=UNKNOWN_SVC_MODE] [new-mode=PD_SVC_MODE]
[2024/06/02 21:36:35.472 +08:00] [INFO] [tso_dispatcher.go:119] ["[tso] start tso deadline watcher"] [dc-location=global]
[2024/06/02 21:36:35.472 +08:00] [INFO] [tso_dispatcher.go:168] ["[tso] tso dispatcher created"] [dc-location=global]
[2024/06/02 21:36:35.472 +08:00] [INFO] [tso_client.go:130] ["[tso] start tso dispatcher check loop"]
[2024/06/02 21:36:35.472 +08:00] [INFO] [tso_dispatcher.go:336] ["[tso] start tso connection contexts updater"] [dc-location=global]
[2024/06/02 21:36:35.473 +08:00] [INFO] [local.go:727] ["multi ingest support"] [category=ddl-ingest]
[2024/06/02 21:36:35.474 +08:00] [INFO] [local.go:749] ["TiKV server side free space check is enabled, so lightning will turn it off"] [category=ddl-ingest]
[2024/06/02 21:36:35.474 +08:00] [INFO] [backend_mgr.go:160] ["create one backend for an DDL job"] ["job ID"=20640] ["current memory usage"=136] ["max memory quota"=17179869184] ["is unique index"=false]
[2024/06/02 21:36:35.474 +08:00] [INFO] [backfilling_read_index.go:90] ["read index executor init subtask exec env"] [category=ddl]
[2024/06/02 21:36:35.478 +08:00] [INFO] [backfilling_read_index.go:95] ["read index executor run subtask"] [category=ddl] ["use cloud"=false]
[2024/06/02 21:36:35.480 +08:00] [INFO] [backend.go:260] ["open engine"] [category=ddl-ingest] [engineTag=t0:1] [engineUUID=4229afb8-665d-5dce-bb97-2afa316b67ba]
[2024/06/02 21:36:35.480 +08:00] [INFO] [engine_mgr.go:95] ["open an engine for index reorg task"] ["job ID"=20640] ["index IDs"="[1]"] ["current memory usage"=536871184] ["memory limitation"=17179869184]
[2024/06/02 21:36:35.480 +08:00] [INFO] [backfilling_operators.go:159] ["build add index local storage operators"] [task-id=660001] [subtask-id=60001] [jobID=20640] [avgRowSize=0] [reader=2] [writer=4]
[2024/06/02 21:36:35.480 +08:00] [INFO] [backfilling.go:432] ["split table range from PD"] [category=ddl] [physicalTableID=20638] ["start key"=74800000000000509e5f728000000000000001] ["end key"=74800000000000509e5f72800000000000000100]
[2024/06/02 21:36:35.480 +08:00] [INFO] [backfilling_operators.go:446] ["start a table scan task"] [task-id=660001] [subtask-id=60001] [id=1] [task="TableScanTask: id=1, startKey=74800000000000509e5f728000000000000001, endKey=74800000000000509e5f72800000000000000100"]
[2024/06/02 21:36:35.492 +08:00] [INFO] [engine.go:204] ["create one local writer for index reorg task"] ["job ID"=20640] ["index ID"=1] ["worker ID"=1] ["allocate memory"=40] ["current memory usage"=671088952] ["max memory quota"=17179869184]
[2024/06/02 21:36:35.498 +08:00] [INFO] [engine.go:204] ["create one local writer for index reorg task"] ["job ID"=20640] ["index ID"=1] ["worker ID"=2] ["allocate memory"=40] ["current memory usage"=805306720] ["max memory quota"=17179869184]
[2024/06/02 21:36:35.498 +08:00] [INFO] [backfilling_operators.go:690] ["finish a index ingest task"] [task-id=660001] [subtask-id=60001] [id=1]
[2024/06/02 21:36:35.502 +08:00] [INFO] [engine.go:204] ["create one local writer for index reorg task"] ["job ID"=20640] ["index ID"=1] ["worker ID"=3] ["allocate memory"=40] ["current memory usage"=940573064] ["max memory quota"=17179869184]
[2024/06/02 21:36:35.515 +08:00] [INFO] [engine.go:204] ["create one local writer for index reorg task"] ["job ID"=20640] ["index ID"=1] ["worker ID"=4] ["allocate memory"=40] ["current memory usage"=1074790832] ["max memory quota"=17179869184]
[2024/06/02 21:36:35.515 +08:00] [INFO] [engine.go:867] ["write data to local DB"] [category=ddl-ingest] [size=39] [kvs=1] [files=1] [sstFileSize=945] [file=/tmp/tidb/tmp_ddl-37215/20640/4229afb8-665d-5dce-bb97-2afa316b67ba.sst/e13080a6-9921-4348-8129-c9113dfcf583.sst] [firstKey=74800000000000509E5F698000000000000001013100000000000000F8038000000000000001] [lastKey=74800000000000509E5F698000000000000001013100000000000000F8038000000000000001]
[2024/06/02 21:36:35.517 +08:00] [INFO] [backend.go:229] ["acquire distributed flush lock success"] [jobID=20640]
[2024/06/02 21:36:35.517 +08:00] [INFO] [backend.go:262] ["do a partial import data into the storage"] [category=ddl-ingest] [engineUUID=4229afb8-665d-5dce-bb97-2afa316b67ba] ["index ID"=1] ["usage info"="disk usage: 765145427968/940431265792, backend usage: 0"]
[2024/06/02 21:36:35.517 +08:00] [INFO] [backend.go:386] ["import start"] [category=ddl-ingest] [engineUUID=4229afb8-665d-5dce-bb97-2afa316b67ba] [retryCnt=0]
[2024/06/02 21:36:35.518 +08:00] [WARN] [local.go:1739] ["get region split size and keys failed"] [category=ddl-ingest] [error="Get \"http://127.0.0.1:20165/config\": dial tcp 127.0.0.1:20165: connect: connection refused"] [store=127.0.0.1:20165]
[2024/06/02 21:36:35.518 +08:00] [WARN] [local.go:1315] ["fail to get region split keys and size"] [category=ddl-ingest] [error="get region split size and keys failed"]
[2024/06/02 21:36:35.518 +08:00] [INFO] [local.go:1325] ["pause pd scheduler of table scope"] [category=ddl-ingest]
[2024/06/02 21:36:35.538 +08:00] [INFO] [local.go:1363] ["start import engine"] [category=ddl-ingest] [uuid=4229afb8-665d-5dce-bb97-2afa316b67ba] ["region ranges"=1] [count=1] [size=39]
[2024/06/02 21:36:35.539 +08:00] [INFO] [local.go:880] ["import engine ranges"] [category=ddl-ingest] [count=1]
[2024/06/02 21:36:35.545 +08:00] [INFO] [local.go:1374] ["import engine success"] [category=ddl-ingest] [uuid=4229afb8-665d-5dce-bb97-2afa316b67ba] [size=39] [kvs=1] [importedSize=39] [importedCount=1]
[2024/06/02 21:36:35.546 +08:00] [INFO] [backend.go:392] ["import completed"] [category=ddl-ingest] [engineUUID=4229afb8-665d-5dce-bb97-2afa316b67ba] [retryCnt=0] [takeTime=29.048115ms] []
[2024/06/02 21:36:35.549 +08:00] [INFO] [backend.go:235] ["release distributed flush lock success"] [jobID=20640]
[2024/06/02 21:36:35.549 +08:00] [INFO] [backend.go:344] ["engine close start"] [category=ddl-ingest] [engineTag=t0:1] [engineUUID=4229afb8-665d-5dce-bb97-2afa316b67ba]
[2024/06/02 21:36:35.550 +08:00] [INFO] [backend.go:346] ["engine close completed"] [category=ddl-ingest] [engineTag=t0:1] [engineUUID=4229afb8-665d-5dce-bb97-2afa316b67ba] [takeTime=552.276µs] []
[2024/06/02 21:36:35.550 +08:00] [INFO] [backend.go:405] ["cleanup start"] [category=ddl-ingest] [engineTag=t0:1] [engineUUID=4229afb8-665d-5dce-bb97-2afa316b67ba]
[2024/06/02 21:36:35.550 +08:00] [INFO] [backend.go:407] ["cleanup completed"] [category=ddl-ingest] [engineTag=t0:1] [engineUUID=4229afb8-665d-5dce-bb97-2afa316b67ba] [takeTime=362.638µs] []
[2024/06/02 21:36:35.555 +08:00] [INFO] [backfilling_read_index.go:139] ["read index executor cleanup subtask exec env"]
[2024/06/02 21:36:35.555 +08:00] [INFO] [pd_service_discovery.go:550] ["[pd] exit member loop due to context canceled"]
[2024/06/02 21:36:35.555 +08:00] [INFO] [tso_dispatcher.go:137] ["[tso] exit tso deadline watcher"] [dc-location=global]
[2024/06/02 21:36:35.555 +08:00] [INFO] [tso_dispatcher.go:210] ["[tso] stop fetching the pending tso requests due to context canceled"] [dc-location=global]
[2024/06/02 21:36:35.555 +08:00] [INFO] [tso_dispatcher.go:171] ["[tso] exit tso dispatcher"] [dc-location=global]
[2024/06/02 21:36:35.555 +08:00] [INFO] [tso_client.go:145] ["[tso] exit tso dispatcher check loop"]
[2024/06/02 21:36:35.555 +08:00] [INFO] [tso_batch_controller.go:160] ["[pd] clear the tso batch controller"] [max-batch-size=10000] [best-batch-size=5] [collected-request-count=0] [pending-request-count=0]
[2024/06/02 21:36:35.555 +08:00] [INFO] [tso_dispatcher.go:350] ["[tso] exit tso connection contexts updater"] [dc-location=global]
[2024/06/02 21:36:35.555 +08:00] [INFO] [resource_manager_client.go:295] ["[resource manager] exit resource token dispatcher"]
[2024/06/02 21:36:35.556 +08:00] [INFO] [tso_client.go:155] ["[tso] closing tso client"]
[2024/06/02 21:36:35.556 +08:00] [INFO] [tso_client.go:160] ["[tso] close tso client"]
[2024/06/02 21:36:35.556 +08:00] [INFO] [tso_batch_controller.go:160] ["[pd] clear the tso batch controller"] [max-batch-size=10000] [best-batch-size=5] [collected-request-count=0] [pending-request-count=0]
[2024/06/02 21:36:35.556 +08:00] [INFO] [tso_client.go:162] ["[tso] tso client is closed"]
[2024/06/02 21:36:35.556 +08:00] [INFO] [pd_service_discovery.go:637] ["[pd] close pd service discovery client"]
[2024/06/02 21:36:35.556 +08:00] [INFO] [client.go:330] ["[pd] http client closed"] [source=lightning]
[2024/06/02 21:36:35.556 +08:00] [INFO] [tso_client.go:155] ["[tso] closing tso client"]
[2024/06/02 21:36:35.556 +08:00] [INFO] [tso_client.go:160] ["[tso] close tso client"]
[2024/06/02 21:36:35.556 +08:00] [INFO] [tso_batch_controller.go:160] ["[pd] clear the tso batch controller"] [max-batch-size=10000] [best-batch-size=5] [collected-request-count=0] [pending-request-count=0]
[2024/06/02 21:36:35.556 +08:00] [INFO] [tso_client.go:162] ["[tso] tso client is closed"]
[2024/06/02 21:36:35.556 +08:00] [INFO] [backend_mgr.go:307] ["close one backend for DDL job"] ["job ID"=20640] ["current memory usage"=0] ["max memory quota"=17179869184]
[2024/06/02 21:36:35.556 +08:00] [INFO] [task_executor.go:299] ["execute task step completed"] [task-id=660001] [task-type=backfill] [step=read-index] [mem-limit-percent=0.7] [server-mem-limit=80%] [resource="[CPU=4, Mem=16GiB]"] [takeTime=86.821956ms] []
[2024/06/02 21:36:35.878 +08:00] [INFO] [scheduler.go:409] ["switch to next step"] [task-id=660001] [task-type=backfill] [allocated-slots=true] [current-step=read-index] [next-step=done]
[2024/06/02 21:36:36.160 +08:00] [INFO] [manager.go:332] ["task executor exit"] [task-id=660001] [type=backfill]
[2024/06/02 21:36:36.179 +08:00] [INFO] [reorg.go:277] ["run reorg job done"] [category=ddl] ["handled rows"=1]
[2024/06/02 21:36:36.214 +08:00] [INFO] [ddl_worker.go:1210] ["run DDL job"] [worker="worker 6, tp add index"] [category=ddl] [jobID=20640] [conn=2464156092] [category=ddl] [job="ID:20640, Type:add index, State:running, SchemaState:write reorganization, SchemaID:20607, TableID:20638, RowCount:1, ArgLen:0, start time: 2024-06-02 21:36:34.211 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:450189169606262791, LocalMode: false, UniqueWarnings:0"]
[2024/06/02 21:36:36.215 +08:00] [INFO] [index.go:884] ["index backfill state ready to merge"] [category=ddl] ["job ID"=20640] [table=t0] [index=i0]
[2024/06/02 21:36:36.239 +08:00] [INFO] [ddl_worker.go:1210] ["run DDL job"] [worker="worker 5, tp add index"] [category=ddl] [jobID=20640] [conn=2464156092] [category=ddl] [job="ID:20640, Type:add index, State:running, SchemaState:write reorganization, SchemaID:20607, TableID:20638, RowCount:1, ArgLen:0, start time: 2024-06-02 21:36:34.211 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:0, LocalMode: false, UniqueWarnings:0"]
[2024/06/02 21:36:36.239 +08:00] [INFO] [reorg.go:764] ["job get table range"] [category=ddl] [jobID=20640] [physicalTableID=20638] [startKey=74800000000000509e5f69ffff000000000001] [endKey=74800000000000509e5f69ffff000000000001ff]
[2024/06/02 21:36:36.262 +08:00] [INFO] [ddl_worker.go:1210] ["run DDL job"] [worker="worker 6, tp add index"] [category=ddl] [jobID=20640] [conn=2464156092] [category=ddl] [job="ID:20640, Type:add index, State:running, SchemaState:write reorganization, SchemaID:20607, TableID:20638, RowCount:1, ArgLen:0, start time: 2024-06-02 21:36:34.211 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:450189170104336395, LocalMode: false, UniqueWarnings:0"]
[2024/06/02 21:36:36.264 +08:00] [INFO] [index.go:1951] ["start to merge temp index"] [category=ddl] [job="ID:20640, Type:add index, State:running, SchemaState:write reorganization, SchemaID:20607, TableID:20638, RowCount:1, ArgLen:6, start time: 2024-06-02 21:36:34.211 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:450189170104336395, LocalMode: false, UniqueWarnings:0"] [reorgInfo="CurrElementType:_idx_,CurrElementID:1,StartKey:74800000000000509e5f69ffff000000000001,EndKey:74800000000000509e5f69ffff000000000001ff,First:false,PhysicalTableID:20638,Ingest mode:false"]
[2024/06/02 21:36:36.265 +08:00] [INFO] [backfilling.go:432] ["split table range from PD"] [category=ddl] [physicalTableID=20638] ["start key"=74800000000000509e5f69ffff000000000001] ["end key"=74800000000000509e5f69ffff000000000001ff]
[2024/06/02 21:36:36.265 +08:00] [INFO] [backfilling.go:696] ["start backfill workers to reorg record"] [category=ddl] [type="merge temporary index"] [workerCnt=4] [regionCnt=1] [startKey=74800000000000509e5f69ffff000000000001] [endKey=74800000000000509e5f69ffff000000000001ff]
[2024/06/02 21:36:36.266 +08:00] [INFO] [backfilling.go:491] ["get backfill range task, change end key"] [category=ddl] [id=1] [pTbl=20638] ["end key"=74800000000000509e5f69ffff000000000001ff] ["current end key"=74800000000000509e5f69ffff00000000000100]
[2024/06/02 21:36:36.266 +08:00] [INFO] [backfilling.go:385] ["backfill worker exit"] [category=ddl] [worker="backfill-worker 1, tp merge temporary index"] [jobID=20640]
[2024/06/02 21:36:36.266 +08:00] [INFO] [backfilling.go:385] ["backfill worker exit"] [category=ddl] [worker="backfill-worker 2, tp merge temporary index"] [jobID=20640]
[2024/06/02 21:36:36.266 +08:00] [INFO] [backfilling.go:385] ["backfill worker exit"] [category=ddl] [worker="backfill-worker 3, tp merge temporary index"] [jobID=20640]
[2024/06/02 21:36:36.266 +08:00] [INFO] [backfilling.go:346] ["backfill worker finish task"] [category=ddl] [worker="backfill-worker 0, tp merge temporary index"] [task="taskID: 1, physicalTableID: 20638, range: [74800000000000509e5f69ffff000000000001, 74800000000000509e5f69ffff00000000000100), jobID: 20640"] ["added count"=0] ["scan count"=0] ["next key"=74800000000000509e5f69ffff0000000000010000] ["take time"=368.855µs]
[2024/06/02 21:36:36.266 +08:00] [INFO] [backfilling.go:385] ["backfill worker exit"] [category=ddl] [worker="backfill-worker 0, tp merge temporary index"] [jobID=20640]
[2024/06/02 21:36:36.266 +08:00] [INFO] [backfilling.go:636] ["backfill workers successfully processed"] [category=ddl] [element=ID:1,TypeKey:_idx_] ["total added count"=1] ["start key"=74800000000000509e5f69ffff000000000001]
[2024/06/02 21:36:36.266 +08:00] [INFO] [reorg.go:277] ["run reorg job done"] [category=ddl] ["handled rows"=1]
[2024/06/02 21:36:36.272 +08:00] [INFO] [index.go:780] ["run add index job done"] [category=ddl] [charset=utf8mb4] [collation=utf8mb4_general_ci]
[2024/06/02 21:36:36.296 +08:00] [INFO] [delete_range.go:422] ["insert into delete-range indices"] [category=ddl] [jobID=20640] [tableID=20638] [indexIDs="[9223090561878065153]"] [comment="add index: physical table ID(s)"]
[2024/06/02 21:36:36.297 +08:00] [INFO] [delete_range.go:112] ["add job into delete-range table"] [category=ddl] [jobID=20640] [jobType="add index"]
[2024/06/02 21:36:36.298 +08:00] [INFO] [ddl_worker.go:763] ["finish DDL job"] [worker="worker 5, tp add index"] [category=ddl] [jobID=20640] [conn=2464156092] [job="ID:20640, Type:add index, State:synced, SchemaState:public, SchemaID:20607, TableID:20638, RowCount:1, ArgLen:3, start time: 2024-06-02 21:36:34.211 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:450189170104336395, LocalMode: false, UniqueWarnings:0"]
[2024/06/02 21:36:36.303 +08:00] [INFO] [ddl.go:1298] ["DDL job is finished"] [category=ddl] [jobID=20640]
[2024/06/02 21:36:36.303 +08:00] [INFO] [callback.go:140] ["performing DDL change, must reload"] [category=ddl]
[2024/06/02 21:36:36.305 +08:00] [INFO] [domain.go:288] ["diff load InfoSchema success"] [isV2=false] [currentSchemaVersion=24707] [neededSchemaVersion=24713] ["start time"=1.675414ms] [gotSchemaVersion=24713] [phyTblIDs="[20638,20638,20638,20638,20638,20638]"] [actionTypes="[7,7,7,7,7,7]"] [diffTypes="[\"add index\",\"add index\",\"add index\",\"add index\",\"add index\",\"add index\"]"]
[2024/06/02 21:36:36.306 +08:00] [INFO] [session.go:3985] [GENERAL_LOG] [conn=2464156092] [session_alias=] [user=root@127.0.0.1] [schemaVersion=24713] [txnStartTS=0] [forUpdateTS=0] [isReadConsistency=false] [currentDB=util__ranger] [isPessimistic=false] [sessionTxnMode=PESSIMISTIC] [sql="analyze table t0;"]
[2024/06/02 21:36:36.330 +08:00] [INFO] [analyze.go:748] ["analyze table `util__ranger`.`t0` has finished"] [partition=] ["job info"="analyze table all columns with 256 buckets, 500 topn, 1 samplerate"] ["start time"=2024/06/02 21:36:36.310 +08:00] ["end time"=2024/06/02 21:36:36.329 +08:00] [cost=18.692134ms] ["sample rate reason"="use min(1, 110000/10000) as the sample-rate=1"]
[2024/06/02 21:36:36.341 +08:00] [INFO] [session.go:3985] [GENERAL_LOG] [conn=2464156092] [session_alias=] [user=root@127.0.0.1] [schemaVersion=24713] [txnStartTS=0] [forUpdateTS=0] [isReadConsistency=false] [currentDB=util__ranger] [isPessimistic=false] [sessionTxnMode=PESSIMISTIC] [sql="explain format = 'brief' select * from t0 where c0;"]
[2024/06/02 21:36:36.341 +08:00] [INFO] [session.go:3985] [GENERAL_LOG] [conn=2464156092] [session_alias=] [user=root@127.0.0.1] [schemaVersion=24713] [txnStartTS=0] [forUpdateTS=0] [isReadConsistency=false] [currentDB=util__ranger] [isPessimistic=false] [sessionTxnMode=PESSIMISTIC] [sql="explain format = 'brief' select * from t0 where c0 and c0 > '123';"]
[2024/06/02 21:36:36.342 +08:00] [INFO] [session.go:3985] [GENERAL_LOG] [conn=2464156092] [session_alias=] [user=root@127.0.0.1] [schemaVersion=24713] [txnStartTS=0] [forUpdateTS=0] [isReadConsistency=false] [currentDB=util__ranger] [isPessimistic=false] [sessionTxnMode=PESSIMISTIC] [sql="explain format = 'brief' select * from t0 where c0 and c0 <> '123';"]
[2024/06/02 21:36:36.342 +08:00] [INFO] [session.go:3985] [GENERAL_LOG] [conn=2464156092] [session_alias=] [user=root@127.0.0.1] [schemaVersion=24713] [txnStartTS=0] [forUpdateTS=0] [isReadConsistency=false] [currentDB=util__ranger] [isPessimistic=false] [sessionTxnMode=PESSIMISTIC] [sql="explain format = 'brief' select * from t0 where c0 is true;"]
[2024/06/02 21:36:36.342 +08:00] [INFO] [session.go:3985] [GENERAL_LOG] [conn=2464156092] [session_alias=] [user=root@127.0.0.1] [schemaVersion=24713] [txnStartTS=0] [forUpdateTS=0] [isReadConsistency=false] [currentDB=util__ranger] [isPessimistic=false] [sessionTxnMode=PESSIMISTIC] [sql="explain format = 'brief' select * from t0 where c0 is false;"]
[2024/06/02 21:36:36.343 +08:00] [INFO] [session.go:3985] [GENERAL_LOG] [conn=2464156092] [session_alias=] [user=root@127.0.0.1] [schemaVersion=24713] [txnStartTS=0] [forUpdateTS=0] [isReadConsistency=false] [currentDB=util__ranger] [isPessimistic=false] [sessionTxnMode=PESSIMISTIC] [sql="explain format = 'brief' select * from t0 where c0 and c0 in ('123','456','789');"]
[2024/06/02 21:36:36.343 +08:00] [INFO] [session.go:3985] [GENERAL_LOG] [conn=2464156092] [session_alias=] [user=root@127.0.0.1] [schemaVersion=24713] [txnStartTS=0] [forUpdateTS=0] [isReadConsistency=false] [currentDB=util__ranger] [isPessimistic=false] [sessionTxnMode=PESSIMISTIC] [sql="explain format = 'brief' select * FROM t0 WHERE ('a' != t0.c0) AND t0.c0;"]
[2024/06/02 21:36:36.343 +08:00] [INFO] [session.go:3985] [GENERAL_LOG] [conn=2464156092] [session_alias=] [user=root@127.0.0.1] [schemaVersion=24713] [txnStartTS=0] [forUpdateTS=0] [isReadConsistency=false] [currentDB=util__ranger] [isPessimistic=false] [sessionTxnMode=PESSIMISTIC] [sql="SET @@SESSION.`tidb_cost_model_version`=DEFAULT"]
[2024/06/02 21:36:36.343 +08:00] [INFO] [session.go:3985] [GENERAL_LOG] [conn=2464156092] [session_alias=] [user=root@127.0.0.1] [schemaVersion=24713] [txnStartTS=0] [forUpdateTS=0] [isReadConsistency=false] [currentDB=util__ranger] [isPessimistic=false] [sessionTxnMode=PESSIMISTIC] [sql="SET @@SESSION.`tidb_cost_model_version`=2"]
[2024/06/02 21:36:36.344 +08:00] [INFO] [session.go:3959] ["CRUCIAL OPERATION"] [conn=2464156092] [schemaVersion=24713] [cur_db=util__ranger] [sql="drop table if exists t;"] [user=root@%]
[2024/06/02 21:36:36.357 +08:00] [INFO] [ddl_worker.go:261] ["add DDL jobs"] [category=ddl] ["batch count"=1] [jobs="ID:20641, Type:drop table, State:queueing, SchemaState:public, SchemaID:20607, TableID:20636, RowCount:0, ArgLen:2, start time: 2024-06-02 21:36:36.311 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:0, LocalMode: false; "] [table=true]
[2024/06/02 21:36:36.357 +08:00] [INFO] [ddl.go:1192] ["start DDL job"] [category=ddl] [job="ID:20641, Type:drop table, State:queueing, SchemaState:public, SchemaID:20607, TableID:20636, RowCount:0, ArgLen:2, start time: 2024-06-02 21:36:36.311 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:0, LocalMode: false"] [query="drop table if exists t;"]
[2024/06/02 21:36:36.379 +08:00] [INFO] [scheduler_manager.go:364] ["task scheduler exit"] [task-id=660001]
[2024/06/02 21:36:36.381 +08:00] [INFO] [scheduler_manager.go:410] ["cleanup routine start"]
[2024/06/02 21:36:36.381 +08:00] [INFO] [scheduler_manager.go:426] ["cleanup task"] [task-id=660001]
[2024/06/02 21:36:36.381 +08:00] [INFO] [ddl_worker.go:1210] ["run DDL job"] [worker="worker 4, tp general"] [category=ddl] [jobID=20641] [conn=2464156092] [category=ddl] [job="ID:20641, Type:drop table, State:queueing, SchemaState:public, SchemaID:20607, TableID:20636, RowCount:0, ArgLen:0, start time: 2024-06-02 21:36:36.311 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:0, LocalMode: false"]
[2024/06/02 21:36:36.387 +08:00] [INFO] [scheduler_manager.go:419] ["cleanup routine success"]
[2024/06/02 21:36:36.401 +08:00] [INFO] [ddl_worker.go:1210] ["run DDL job"] [worker="worker 4, tp general"] [category=ddl] [jobID=20641] [conn=2464156092] [category=ddl] [job="ID:20641, Type:drop table, State:running, SchemaState:write only, SchemaID:20607, TableID:20636, RowCount:0, ArgLen:0, start time: 2024-06-02 21:36:36.311 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:0, LocalMode: false"]
[2024/06/02 21:36:36.420 +08:00] [INFO] [ddl_worker.go:1210] ["run DDL job"] [worker="worker 4, tp general"] [category=ddl] [jobID=20641] [conn=2464156092] [category=ddl] [job="ID:20641, Type:drop table, State:running, SchemaState:delete only, SchemaID:20607, TableID:20636, RowCount:0, ArgLen:0, start time: 2024-06-02 21:36:36.311 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:0, LocalMode: false"]
[2024/06/02 21:36:36.437 +08:00] [INFO] [delete_range.go:447] ["insert into delete-range table"] [category=ddl] [jobID=20641] [tableIDs="[20636]"] [comment="drop table: table ID"]
[2024/06/02 21:36:36.439 +08:00] [INFO] [delete_range.go:112] ["add job into delete-range table"] [category=ddl] [jobID=20641] [jobType="drop table"]
[2024/06/02 21:36:36.439 +08:00] [INFO] [ddl_worker.go:763] ["finish DDL job"] [worker="worker 4, tp general"] [category=ddl] [jobID=20641] [conn=2464156092] [job="ID:20641, Type:drop table, State:synced, SchemaState:none, SchemaID:20607, TableID:20636, RowCount:0, ArgLen:3, start time: 2024-06-02 21:36:36.311 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:0, LocalMode: false"]
[2024/06/02 21:36:36.442 +08:00] [INFO] [ddl.go:1298] ["DDL job is finished"] [category=ddl] [jobID=20641]
[2024/06/02 21:36:36.442 +08:00] [INFO] [callback.go:140] ["performing DDL change, must reload"] [category=ddl]
[2024/06/02 21:36:36.444 +08:00] [INFO] [domain.go:288] ["diff load InfoSchema success"] [isV2=false] [currentSchemaVersion=24713] [neededSchemaVersion=24716] ["start time"=416.169µs] [gotSchemaVersion=24716] [phyTblIDs="[20636]"] [actionTypes="[4]"] [diffTypes="[\"drop table\",\"drop table\",\"drop table\"]"]
[2024/06/02 21:36:36.444 +08:00] [INFO] [session.go:3959] ["CRUCIAL OPERATION"] [conn=2464156092] [schemaVersion=24716] [cur_db=util__ranger] [sql="create table t(a int primary key, b int, c int, d int, e int, index idx(b,c,d));"] [user=root@%]
[2024/06/02 21:36:36.457 +08:00] [INFO] [ddl_worker.go:261] ["add DDL jobs"] [category=ddl] ["batch count"=1] [jobs="ID:20643, Type:create table, State:queueing, SchemaState:none, SchemaID:20607, TableID:20642, RowCount:0, ArgLen:2, start time: 2024-06-02 21:36:36.411 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:0, LocalMode: false; "] [table=true]
[2024/06/02 21:36:36.457 +08:00] [INFO] [ddl.go:1192] ["start DDL job"] [category=ddl] [job="ID:20643, Type:create table, State:queueing, SchemaState:none, SchemaID:20607, TableID:20642, RowCount:0, ArgLen:2, start time: 2024-06-02 21:36:36.411 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:0, LocalMode: false"] [query="create table t(a int primary key, b int, c int, d int, e int, index idx(b,c,d));"]
[2024/06/02 21:36:36.482 +08:00] [INFO] [ddl_worker.go:1210] ["run DDL job"] [worker="worker 4, tp general"] [category=ddl] [jobID=20643] [conn=2464156092] [category=ddl] [job="ID:20643, Type:create table, State:queueing, SchemaState:none, SchemaID:20607, TableID:20642, RowCount:0, ArgLen:0, start time: 2024-06-02 21:36:36.411 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:0, LocalMode: false"]
[2024/06/02 21:36:36.501 +08:00] [INFO] [ddl_worker.go:763] ["finish DDL job"] [worker="worker 4, tp general"] [category=ddl] [jobID=20643] [conn=2464156092] [job="ID:20643, Type:create table, State:synced, SchemaState:public, SchemaID:20607, TableID:20642, RowCount:0, ArgLen:0, start time: 2024-06-02 21:36:36.411 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:0, LocalMode: false"]
[2024/06/02 21:36:36.504 +08:00] [INFO] [ddl.go:1298] ["DDL job is finished"] [category=ddl] [jobID=20643]
[2024/06/02 21:36:36.504 +08:00] [INFO] [callback.go:140] ["performing DDL change, must reload"] [category=ddl]
[2024/06/02 21:36:36.504 +08:00] [INFO] [split_region.go:85] ["split batch regions request"] ["split key count"=1] ["batch count"=1] ["first batch, region ID"=14] ["first split key"=7480000000000050a2]
[2024/06/02 21:36:36.505 +08:00] [INFO] [split_region.go:187] ["batch split regions complete"] ["batch region ID"=14] ["first at"=7480000000000050a2] ["first new region left"="{Id:16820 StartKey:7480000000000050ff9e5f698000000000ff0000010131000000ff00000000f8038000ff0000000000010000fe EndKey:7480000000000050ffa200000000000000f8 RegionEpoch:{ConfVer:1 Version:8102} Peers:[id:16821 store_id:1 ] EncryptionMeta:<nil> IsInFlashback:false FlashbackStartTs:0}"] ["new region count"=1]
[2024/06/02 21:36:36.505 +08:00] [INFO] [split_region.go:236] ["split regions complete"] ["region count"=1] ["region IDs"="[16820]"]
[2024/06/02 21:36:36.505 +08:00] [INFO] [domain.go:288] ["diff load InfoSchema success"] [isV2=false] [currentSchemaVersion=24716] [neededSchemaVersion=24717] ["start time"=496.577µs] [gotSchemaVersion=24717] [phyTblIDs="[20642]"] [actionTypes="[3]"] [diffTypes="[\"create table\"]"]
[2024/06/02 21:36:36.506 +08:00] [INFO] [session.go:3985] [GENERAL_LOG] [conn=2464156092] [session_alias=] [user=root@127.0.0.1] [schemaVersion=24717] [txnStartTS=0] [forUpdateTS=0] [isReadConsistency=false] [currentDB=util__ranger] [isPessimistic=false] [sessionTxnMode=PESSIMISTIC] [sql="insert into t values(1,1,1,1,2),(2,1,2,1,0);"]
[2024/06/02 21:36:36.507 +08:00] [WARN] [prewrite.go:382] ["1pc failed and fallbacks to normal commit procedure"] [conn=2464156092] [session_alias=] [startTS=450189170169872405]
[2024/06/02 21:36:36.508 +08:00] [INFO] [session.go:3985] [GENERAL_LOG] [conn=2464156092] [session_alias=] [user=root@127.0.0.1] [schemaVersion=24717] [txnStartTS=0] [forUpdateTS=0] [isReadConsistency=false] [currentDB=util__ranger] [isPessimistic=false] [sessionTxnMode=PESSIMISTIC] [sql="analyze table t;"]
[2024/06/02 21:36:36.543 +08:00] [INFO] [analyze.go:748] ["analyze table `util__ranger`.`t` has finished"] [partition=] ["job info"="analyze table all columns with 256 buckets, 500 topn, 1 samplerate"] ["start time"=2024/06/02 21:36:36.512 +08:00] ["end time"=2024/06/02 21:36:36.542 +08:00] [cost=29.999733ms] ["sample rate reason"="use min(1, 110000/10000) as the sample-rate=1"]
[2024/06/02 21:36:36.561 +08:00] [INFO] [session.go:3985] [GENERAL_LOG] [conn=2464156092] [session_alias=] [user=root@127.0.0.1] [schemaVersion=24717] [txnStartTS=0] [forUpdateTS=0] [isReadConsistency=false] [currentDB=util__ranger] [isPessimistic=false] [sessionTxnMode=PESSIMISTIC] [sql="explain format = 'brief' select t.e in (select count(*) from t s use index(idx), t t1 where s.b = 1 and s.c in (1, 2) and s.d = t.a and s.a = t1.a) from t;"]
[2024/06/02 21:36:36.562 +08:00] [INFO] [session.go:3985] [GENERAL_LOG] [conn=2464156092] [session_alias=] [user=root@127.0.0.1] [schemaVersion=24717] [txnStartTS=0] [forUpdateTS=0] [isReadConsistency=false] [currentDB=util__ranger] [isPessimistic=false] [sessionTxnMode=PESSIMISTIC] [sql="select t.e in (select count(*) from t s use index(idx), t t1 where s.b = 1 and s.c in (1, 2) and s.d = t.a and s.a = t1.a) from t;"]
[2024/06/02 21:36:36.564 +08:00] [INFO] [session.go:3985] [GENERAL_LOG] [conn=2464156092] [session_alias=] [user=root@127.0.0.1] [schemaVersion=24717] [txnStartTS=0] [forUpdateTS=0] [isReadConsistency=false] [currentDB=util__ranger] [isPessimistic=false] [sessionTxnMode=PESSIMISTIC] [sql="SET @@SESSION.`tidb_cost_model_version`=DEFAULT"]
[2024/06/02 21:36:36.564 +08:00] [INFO] [session.go:3959] ["CRUCIAL OPERATION"] [conn=2464156092] [schemaVersion=24717] [cur_db=util__ranger] [sql="drop table if exists t;"] [user=root@%]
[2024/06/02 21:36:36.577 +08:00] [INFO] [ddl_worker.go:261] ["add DDL jobs"] [category=ddl] ["batch count"=1] [jobs="ID:20644, Type:drop table, State:queueing, SchemaState:public, SchemaID:20607, TableID:20642, RowCount:0, ArgLen:2, start time: 2024-06-02 21:36:36.561 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:0, LocalMode: false; "] [table=true]
[2024/06/02 21:36:36.577 +08:00] [INFO] [ddl.go:1192] ["start DDL job"] [category=ddl] [job="ID:20644, Type:drop table, State:queueing, SchemaState:public, SchemaID:20607, TableID:20642, RowCount:0, ArgLen:2, start time: 2024-06-02 21:36:36.561 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:0, LocalMode: false"] [query="drop table if exists t;"]
[2024/06/02 21:36:36.597 +08:00] [INFO] [ddl_worker.go:1210] ["run DDL job"] [worker="worker 4, tp general"] [category=ddl] [jobID=20644] [conn=2464156092] [category=ddl] [job="ID:20644, Type:drop table, State:queueing, SchemaState:public, SchemaID:20607, TableID:20642, RowCount:0, ArgLen:0, start time: 2024-06-02 21:36:36.561 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:0, LocalMode: false"]
[2024/06/02 21:36:36.615 +08:00] [INFO] [ddl_worker.go:1210] ["run DDL job"] [worker="worker 4, tp general"] [category=ddl] [jobID=20644] [conn=2464156092] [category=ddl] [job="ID:20644, Type:drop table, State:running, SchemaState:write only, SchemaID:20607, TableID:20642, RowCount:0, ArgLen:0, start time: 2024-06-02 21:36:36.561 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:0, LocalMode: false"]
[2024/06/02 21:36:36.632 +08:00] [INFO] [ddl_worker.go:1210] ["run DDL job"] [worker="worker 4, tp general"] [category=ddl] [jobID=20644] [conn=2464156092] [category=ddl] [job="ID:20644, Type:drop table, State:running, SchemaState:delete only, SchemaID:20607, TableID:20642, RowCount:0, ArgLen:0, start time: 2024-06-02 21:36:36.561 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:0, LocalMode: false"]
[2024/06/02 21:36:36.650 +08:00] [INFO] [delete_range.go:447] ["insert into delete-range table"] [category=ddl] [jobID=20644] [tableIDs="[20642]"] [comment="drop table: table ID"]
[2024/06/02 21:36:36.651 +08:00] [INFO] [delete_range.go:112] ["add job into delete-range table"] [category=ddl] [jobID=20644] [jobType="drop table"]
[2024/06/02 21:36:36.652 +08:00] [INFO] [ddl_worker.go:763] ["finish DDL job"] [worker="worker 4, tp general"] [category=ddl] [jobID=20644] [conn=2464156092] [job="ID:20644, Type:drop table, State:synced, SchemaState:none, SchemaID:20607, TableID:20642, RowCount:0, ArgLen:3, start time: 2024-06-02 21:36:36.561 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:0, LocalMode: false"]
[2024/06/02 21:36:36.655 +08:00] [INFO] [ddl.go:1298] ["DDL job is finished"] [category=ddl] [jobID=20644]
[2024/06/02 21:36:36.655 +08:00] [INFO] [callback.go:140] ["performing DDL change, must reload"] [category=ddl]
[2024/06/02 21:36:36.656 +08:00] [INFO] [domain.go:288] ["diff load InfoSchema success"] [isV2=false] [currentSchemaVersion=24717] [neededSchemaVersion=24720] ["start time"=395.33µs] [gotSchemaVersion=24720] [phyTblIDs="[20642]"] [actionTypes="[4]"] [diffTypes="[\"drop table\",\"drop table\",\"drop table\"]"]
[2024/06/02 21:36:36.657 +08:00] [INFO] [session.go:3959] ["CRUCIAL OPERATION"] [conn=2464156092] [schemaVersion=24720] [cur_db=util__ranger] [sql="create table t(a int not null, b int not null, primary key(a,b));"] [user=root@%]
[2024/06/02 21:36:36.669 +08:00] [INFO] [ddl_worker.go:261] ["add DDL jobs"] [category=ddl] ["batch count"=1] [jobs="ID:20646, Type:create table, State:queueing, SchemaState:none, SchemaID:20607, TableID:20645, RowCount:0, ArgLen:2, start time: 2024-06-02 21:36:36.662 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:0, LocalMode: false; "] [table=true]
[2024/06/02 21:36:36.669 +08:00] [INFO] [ddl.go:1192] ["start DDL job"] [category=ddl] [job="ID:20646, Type:create table, State:queueing, SchemaState:none, SchemaID:20607, TableID:20645, RowCount:0, ArgLen:2, start time: 2024-06-02 21:36:36.662 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:0, LocalMode: false"] [query="create table t(a int not null, b int not null, primary key(a,b));"]
[2024/06/02 21:36:36.695 +08:00] [INFO] [ddl_worker.go:1210] ["run DDL job"] [worker="worker 4, tp general"] [category=ddl] [jobID=20646] [conn=2464156092] [category=ddl] [job="ID:20646, Type:create table, State:queueing, SchemaState:none, SchemaID:20607, TableID:20645, RowCount:0, ArgLen:0, start time: 2024-06-02 21:36:36.662 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:0, LocalMode: false"]
[2024/06/02 21:36:36.714 +08:00] [INFO] [ddl_worker.go:763] ["finish DDL job"] [worker="worker 4, tp general"] [category=ddl] [jobID=20646] [conn=2464156092] [job="ID:20646, Type:create table, State:synced, SchemaState:public, SchemaID:20607, TableID:20645, RowCount:0, ArgLen:0, start time: 2024-06-02 21:36:36.662 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:0, LocalMode: false"]
[2024/06/02 21:36:36.717 +08:00] [INFO] [ddl.go:1298] ["DDL job is finished"] [category=ddl] [jobID=20646]
[2024/06/02 21:36:36.717 +08:00] [INFO] [callback.go:140] ["performing DDL change, must reload"] [category=ddl]
[2024/06/02 21:36:36.717 +08:00] [INFO] [split_region.go:85] ["split batch regions request"] ["split key count"=1] ["batch count"=1] ["first batch, region ID"=14] ["first split key"=7480000000000050a5]
[2024/06/02 21:36:36.718 +08:00] [INFO] [split_region.go:187] ["batch split regions complete"] ["batch region ID"=14] ["first at"=7480000000000050a5] ["first new region left"="{Id:16822 StartKey:7480000000000050ffa200000000000000f8 EndKey:7480000000000050ffa500000000000000f8 RegionEpoch:{ConfVer:1 Version:8103} Peers:[id:16823 store_id:1 ] EncryptionMeta:<nil> IsInFlashback:false FlashbackStartTs:0}"] ["new region count"=1]
[2024/06/02 21:36:36.718 +08:00] [INFO] [split_region.go:236] ["split regions complete"] ["region count"=1] ["region IDs"="[16822]"]
[2024/06/02 21:36:36.719 +08:00] [INFO] [domain.go:288] ["diff load InfoSchema success"] [isV2=false] [currentSchemaVersion=24720] [neededSchemaVersion=24721] ["start time"=519.015µs] [gotSchemaVersion=24721] [phyTblIDs="[20645]"] [actionTypes="[3]"] [diffTypes="[\"create table\"]"]
[2024/06/02 21:36:36.719 +08:00] [INFO] [session.go:3985] [GENERAL_LOG] [conn=2464156092] [session_alias=] [user=root@127.0.0.1] [schemaVersion=24721] [txnStartTS=0] [forUpdateTS=0] [isReadConsistency=false] [currentDB=util__ranger] [isPessimistic=false] [sessionTxnMode=PESSIMISTIC] [sql="insert into t values(1,2);"]
[2024/06/02 21:36:36.722 +08:00] [INFO] [session.go:3985] [GENERAL_LOG] [conn=2464156092] [session_alias=] [user=root@127.0.0.1] [schemaVersion=24721] [txnStartTS=0] [forUpdateTS=0] [isReadConsistency=false] [currentDB=util__ranger] [isPessimistic=false] [sessionTxnMode=PESSIMISTIC] [sql="analyze table t;"]
[2024/06/02 21:36:36.744 +08:00] [INFO] [analyze.go:748] ["analyze table `util__ranger`.`t` has finished"] [partition=] ["job info"="analyze table all columns with 256 buckets, 500 topn, 1 samplerate"] ["start time"=2024/06/02 21:36:36.725 +08:00] ["end time"=2024/06/02 21:36:36.743 +08:00] [cost=17.585623ms] ["sample rate reason"="use min(1, 110000/10000) as the sample-rate=1"]
[2024/06/02 21:36:36.757 +08:00] [INFO] [session.go:3985] [GENERAL_LOG] [conn=2464156092] [session_alias=] [user=root@127.0.0.1] [schemaVersion=24721] [txnStartTS=0] [forUpdateTS=0] [isReadConsistency=false] [currentDB=util__ranger] [isPessimistic=false] [sessionTxnMode=PESSIMISTIC] [sql="explain format = 'brief' select * from (select * from t union all select a, b from t) sub where a > 0;"]
[2024/06/02 21:36:36.757 +08:00] [INFO] [session.go:3985] [GENERAL_LOG] [conn=2464156092] [session_alias=] [user=root@127.0.0.1] [schemaVersion=24721] [txnStartTS=0] [forUpdateTS=0] [isReadConsistency=false] [currentDB=util__ranger] [isPessimistic=false] [sessionTxnMode=PESSIMISTIC] [sql="select * from (select * from t union all select ifnull(a,b), b from t) sub where a > 0;"]
[2024/06/02 21:36:36.759 +08:00] [INFO] [session.go:3985] [GENERAL_LOG] [conn=2464156096] [session_alias=] [user=root@127.0.0.1] [schemaVersion=24721] [txnStartTS=0] [forUpdateTS=0] [isReadConsistency=false] [currentDB=] [isPessimistic=false] [sessionTxnMode=PESSIMISTIC] [sql="use `test`"]
[2024/06/02 21:36:36.759 +08:00] [INFO] [session.go:3985] [GENERAL_LOG] [conn=2464156096] [session_alias=] [user=root@127.0.0.1] [schemaVersion=24721] [txnStartTS=0] [forUpdateTS=0] [isReadConsistency=false] [currentDB=test] [isPessimistic=false] [sessionTxnMode=PESSIMISTIC] [sql="SET @@SESSION.`time_zone`=_UTF8MB4'Asia/Shanghai'"]
[2024/06/02 21:36:36.759 +08:00] [INFO] [session.go:3959] ["CRUCIAL OPERATION"] [conn=2464156096] [schemaVersion=24721] [cur_db=test] [sql="drop database `util__ranger`"] [user=root@%]
[2024/06/02 21:36:36.771 +08:00] [INFO] [ddl_worker.go:261] ["add DDL jobs"] [category=ddl] ["batch count"=1] [jobs="ID:20647, Type:drop schema, State:queueing, SchemaState:public, SchemaID:20607, TableID:0, RowCount:0, ArgLen:1, start time: 2024-06-02 21:36:36.761 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:0, LocalMode: false; "] [table=true]
[2024/06/02 21:36:36.771 +08:00] [INFO] [ddl.go:1192] ["start DDL job"] [category=ddl] [job="ID:20647, Type:drop schema, State:queueing, SchemaState:public, SchemaID:20607, TableID:0, RowCount:0, ArgLen:1, start time: 2024-06-02 21:36:36.761 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:0, LocalMode: false"] [query="drop database `util__ranger`"]
[2024/06/02 21:36:36.791 +08:00] [INFO] [ddl_worker.go:1210] ["run DDL job"] [worker="worker 4, tp general"] [category=ddl] [jobID=20647] [conn=2464156096] [category=ddl] [job="ID:20647, Type:drop schema, State:queueing, SchemaState:public, SchemaID:20607, TableID:0, RowCount:0, ArgLen:0, start time: 2024-06-02 21:36:36.761 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:0, LocalMode: false"]
[2024/06/02 21:36:36.809 +08:00] [INFO] [ddl_worker.go:1210] ["run DDL job"] [worker="worker 4, tp general"] [category=ddl] [jobID=20647] [conn=2464156096] [category=ddl] [job="ID:20647, Type:drop schema, State:running, SchemaState:write only, SchemaID:20607, TableID:0, RowCount:0, ArgLen:0, start time: 2024-06-02 21:36:36.761 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:0, LocalMode: false"]
[2024/06/02 21:36:36.827 +08:00] [INFO] [ddl_worker.go:1210] ["run DDL job"] [worker="worker 4, tp general"] [category=ddl] [jobID=20647] [conn=2464156096] [category=ddl] [job="ID:20647, Type:drop schema, State:running, SchemaState:delete only, SchemaID:20607, TableID:0, RowCount:0, ArgLen:0, start time: 2024-06-02 21:36:36.761 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:0, LocalMode: false"]
[2024/06/02 21:36:36.846 +08:00] [INFO] [delete_range.go:447] ["insert into delete-range table"] [category=ddl] [jobID=20647] [tableIDs="[20611,20613,20624,20638,20645]"] [comment="drop schema: table IDs"]
[2024/06/02 21:36:36.848 +08:00] [INFO] [delete_range.go:112] ["add job into delete-range table"] [category=ddl] [jobID=20647] [jobType="drop schema"]
[2024/06/02 21:36:36.848 +08:00] [INFO] [ddl_worker.go:763] ["finish DDL job"] [worker="worker 4, tp general"] [category=ddl] [jobID=20647] [conn=2464156096] [job="ID:20647, Type:drop schema, State:synced, SchemaState:none, SchemaID:20607, TableID:0, RowCount:0, ArgLen:1, start time: 2024-06-02 21:36:36.761 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:0, LocalMode: false"]
[2024/06/02 21:36:36.851 +08:00] [INFO] [ddl.go:1298] ["DDL job is finished"] [category=ddl] [jobID=20647]
[2024/06/02 21:36:36.851 +08:00] [INFO] [callback.go:140] ["performing DDL change, must reload"] [category=ddl]
[2024/06/02 21:36:36.853 +08:00] [INFO] [domain.go:288] ["diff load InfoSchema success"] [isV2=false] [currentSchemaVersion=24721] [neededSchemaVersion=24724] ["start time"=459.252µs] [gotSchemaVersion=24724] [phyTblIDs="[20611,20613,20624,20638,20645]"] [actionTypes="[2,2,2,2,2]"] [diffTypes="[\"drop schema\",\"drop schema\",\"drop schema\"]"]
[2024/06/02 21:36:36.854 +08:00] [INFO] [session.go:3985] [GENERAL_LOG] [conn=2464156098] [session_alias=] [user=root@127.0.0.1] [schemaVersion=24724] [txnStartTS=0] [forUpdateTS=0] [isReadConsistency=false] [currentDB=] [isPessimistic=false] [sessionTxnMode=PESSIMISTIC] [sql="use `test`"]
[2024/06/02 21:36:36.854 +08:00] [INFO] [session.go:3985] [GENERAL_LOG] [conn=2464156098] [session_alias=] [user=root@127.0.0.1] [schemaVersion=24724] [txnStartTS=0] [forUpdateTS=0] [isReadConsistency=false] [currentDB=test] [isPessimistic=false] [sessionTxnMode=PESSIMISTIC] [sql="SET @@SESSION.`time_zone`=_UTF8MB4'Asia/Shanghai'"]
[2024/06/02 21:36:36.855 +08:00] [INFO] [session.go:3959] ["CRUCIAL OPERATION"] [conn=2464156098] [schemaVersion=24724] [cur_db=test] [sql="create database `window_function`"] [user=root@%]
[2024/06/02 21:36:36.867 +08:00] [INFO] [ddl_worker.go:261] ["add DDL jobs"] [category=ddl] ["batch count"=1] [jobs="ID:20649, Type:create schema, State:queueing, SchemaState:none, SchemaID:20648, TableID:0, RowCount:0, ArgLen:1, start time: 2024-06-02 21:36:36.861 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:0, LocalMode: false; "] [table=true]
[2024/06/02 21:36:36.867 +08:00] [INFO] [ddl.go:1192] ["start DDL job"] [category=ddl] [job="ID:20649, Type:create schema, State:queueing, SchemaState:none, SchemaID:20648, TableID:0, RowCount:0, ArgLen:1, start time: 2024-06-02 21:36:36.861 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:0, LocalMode: false"] [query="create database `window_function`"]
[2024/06/02 21:36:36.892 +08:00] [INFO] [ddl_worker.go:1210] ["run DDL job"] [worker="worker 4, tp general"] [category=ddl] [jobID=20649] [conn=2464156098] [category=ddl] [job="ID:20649, Type:create schema, State:queueing, SchemaState:none, SchemaID:20648, TableID:0, RowCount:0, ArgLen:0, start time: 2024-06-02 21:36:36.861 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:0, LocalMode: false"]
[2024/06/02 21:36:36.911 +08:00] [INFO] [ddl_worker.go:763] ["finish DDL job"] [worker="worker 4, tp general"] [category=ddl] [jobID=20649] [conn=2464156098] [job="ID:20649, Type:create schema, State:synced, SchemaState:public, SchemaID:20648, TableID:0, RowCount:0, ArgLen:0, start time: 2024-06-02 21:36:36.861 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:0, LocalMode: false"]
[2024/06/02 21:36:36.914 +08:00] [INFO] [ddl.go:1298] ["DDL job is finished"] [category=ddl] [jobID=20649]
[2024/06/02 21:36:36.914 +08:00] [INFO] [callback.go:140] ["performing DDL change, must reload"] [category=ddl]
[2024/06/02 21:36:36.915 +08:00] [INFO] [domain.go:288] ["diff load InfoSchema success"] [isV2=false] [currentSchemaVersion=24724] [neededSchemaVersion=24725] ["start time"=257.254µs] [gotSchemaVersion=24725] [phyTblIDs="[]"] [actionTypes="[]"] [diffTypes="[\"create schema\"]"]
[2024/06/02 21:36:36.916 +08:00] [INFO] [session.go:3985] [GENERAL_LOG] [conn=2464156100] [session_alias=] [user=root@127.0.0.1] [schemaVersion=24725] [txnStartTS=0] [forUpdateTS=0] [isReadConsistency=false] [currentDB=] [isPessimistic=false] [sessionTxnMode=PESSIMISTIC] [sql="use `test`"]
[2024/06/02 21:36:36.917 +08:00] [INFO] [session.go:3985] [GENERAL_LOG] [conn=2464156100] [session_alias=] [user=root@127.0.0.1] [schemaVersion=24725] [txnStartTS=0] [forUpdateTS=0] [isReadConsistency=false] [currentDB=test] [isPessimistic=false] [sessionTxnMode=PESSIMISTIC] [sql="SET @@SESSION.`time_zone`=_UTF8MB4'Asia/Shanghai'"]
[2024/06/02 21:36:36.917 +08:00] [INFO] [session.go:3985] [GENERAL_LOG] [conn=2464156102] [session_alias=] [user=root@127.0.0.1] [schemaVersion=24725] [txnStartTS=0] [forUpdateTS=0] [isReadConsistency=false] [currentDB=] [isPessimistic=false] [sessionTxnMode=PESSIMISTIC] [sql="use `test`"]
[2024/06/02 21:36:36.918 +08:00] [INFO] [session.go:3985] [GENERAL_LOG] [conn=2464156102] [session_alias=] [user=root@127.0.0.1] [schemaVersion=24725] [txnStartTS=0] [forUpdateTS=0] [isReadConsistency=false] [currentDB=test] [isPessimistic=false] [sessionTxnMode=PESSIMISTIC] [sql="SET @@SESSION.`time_zone`=_UTF8MB4'Asia/Shanghai'"]
[2024/06/02 21:36:36.918 +08:00] [INFO] [session.go:3985] [GENERAL_LOG] [conn=2464156102] [session_alias=] [user=root@127.0.0.1] [schemaVersion=24725] [txnStartTS=0] [forUpdateTS=0] [isReadConsistency=false] [currentDB=test] [isPessimistic=false] [sessionTxnMode=PESSIMISTIC] [sql="SELECT tidb_version()"]
[2024/06/02 21:36:36.918 +08:00] [INFO] [session.go:3985] [GENERAL_LOG] [conn=2464156100] [session_alias=] [user=root@127.0.0.1] [schemaVersion=24725] [txnStartTS=0] [forUpdateTS=0] [isReadConsistency=false] [currentDB=test] [isPessimistic=false] [sessionTxnMode=PESSIMISTIC] [sql="SET @@SESSION.`tidb_init_chunk_size`=1"]
[2024/06/02 21:36:36.918 +08:00] [INFO] [session.go:3985] [GENERAL_LOG] [conn=2464156100] [session_alias=] [user=root@127.0.0.1] [schemaVersion=24725] [txnStartTS=0] [forUpdateTS=0] [isReadConsistency=false] [currentDB=test] [isPessimistic=false] [sessionTxnMode=PESSIMISTIC] [sql="SET @@SESSION.`tidb_max_chunk_size`=32"]
[2024/06/02 21:36:36.918 +08:00] [INFO] [session.go:3985] [GENERAL_LOG] [conn=2464156100] [session_alias=] [user=root@127.0.0.1] [schemaVersion=24725] [txnStartTS=0] [forUpdateTS=0] [isReadConsistency=false] [currentDB=test] [isPessimistic=false] [sessionTxnMode=PESSIMISTIC] [sql="SET @@SESSION.`tidb_multi_statement_mode`=1"]
[2024/06/02 21:36:36.918 +08:00] [INFO] [session.go:3985] [GENERAL_LOG] [conn=2464156100] [session_alias=] [user=root@127.0.0.1] [schemaVersion=24725] [txnStartTS=0] [forUpdateTS=0] [isReadConsistency=false] [currentDB=test] [isPessimistic=false] [sessionTxnMode=PESSIMISTIC] [sql="SET @@SESSION.`tidb_hash_join_concurrency`=1"]
[2024/06/02 21:36:36.918 +08:00] [INFO] [session.go:3985] [GENERAL_LOG] [conn=2464156100] [session_alias=] [user=root@127.0.0.1] [schemaVersion=24725] [txnStartTS=0] [forUpdateTS=0] [isReadConsistency=false] [currentDB=test] [isPessimistic=false] [sessionTxnMode=PESSIMISTIC] [sql="SET @@SESSION.`tidb_enable_pseudo_for_outdated_stats`=FALSE"]
[2024/06/02 21:36:36.919 +08:00] [INFO] [session.go:3985] [GENERAL_LOG] [conn=2464156100] [session_alias=] [user=root@127.0.0.1] [schemaVersion=24725] [txnStartTS=0] [forUpdateTS=0] [isReadConsistency=false] [currentDB=test] [isPessimistic=false] [sessionTxnMode=PESSIMISTIC] [sql="SET @@SESSION.`tidb_enable_analyze_snapshot`=1"]
[2024/06/02 21:36:36.919 +08:00] [INFO] [session.go:3985] [GENERAL_LOG] [conn=2464156100] [session_alias=] [user=root@127.0.0.1] [schemaVersion=24725] [txnStartTS=0] [forUpdateTS=0] [isReadConsistency=false] [currentDB=test] [isPessimistic=false] [sessionTxnMode=PESSIMISTIC] [sql="SET @@SESSION.`tidb_enable_clustered_index`=_UTF8MB4'int_only'"]
[2024/06/02 21:36:36.919 +08:00] [INFO] [session.go:3985] [GENERAL_LOG] [conn=2464156100] [session_alias=] [user=root@127.0.0.1] [schemaVersion=24725] [txnStartTS=0] [forUpdateTS=0] [isReadConsistency=false] [currentDB=test] [isPessimistic=false] [sessionTxnMode=PESSIMISTIC] [sql="use `window_function`"]
[2024/06/02 21:36:36.919 +08:00] [INFO] [session.go:3985] [GENERAL_LOG] [conn=2464156100] [session_alias=] [user=root@127.0.0.1] [schemaVersion=24725] [txnStartTS=0] [forUpdateTS=0] [isReadConsistency=false] [currentDB=window_function] [isPessimistic=false] [sessionTxnMode=PESSIMISTIC] [sql="SET @@SESSION.`tidb_cost_model_version`=1"]
[2024/06/02 21:36:36.919 +08:00] [INFO] [session.go:3959] ["CRUCIAL OPERATION"] [conn=2464156100] [schemaVersion=24725] [cur_db=window_function] [sql="drop table if exists t;"] [user=root@%]
[2024/06/02 21:36:36.920 +08:00] [INFO] [session.go:3959] ["CRUCIAL OPERATION"] [conn=2464156100] [schemaVersion=24725] [cur_db=window_function] [sql="create table t (a int, b int, c timestamp, index idx(a));"] [user=root@%]
[2024/06/02 21:36:36.932 +08:00] [INFO] [ddl_worker.go:261] ["add DDL jobs"] [category=ddl] ["batch count"=1] [jobs="ID:20651, Type:create table, State:queueing, SchemaState:none, SchemaID:20648, TableID:20650, RowCount:0, ArgLen:2, start time: 2024-06-02 21:36:36.911 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:0, LocalMode: false; "] [table=true]
[2024/06/02 21:36:36.932 +08:00] [INFO] [ddl.go:1192] ["start DDL job"] [category=ddl] [job="ID:20651, Type:create table, State:queueing, SchemaState:none, SchemaID:20648, TableID:20650, RowCount:0, ArgLen:2, start time: 2024-06-02 21:36:36.911 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:0, LocalMode: false"] [query="create table t (a int, b int, c timestamp, index idx(a));"]
[2024/06/02 21:36:36.961 +08:00] [INFO] [ddl_worker.go:1210] ["run DDL job"] [worker="worker 4, tp general"] [category=ddl] [jobID=20651] [conn=2464156100] [category=ddl] [job="ID:20651, Type:create table, State:queueing, SchemaState:none, SchemaID:20648, TableID:20650, RowCount:0, ArgLen:0, start time: 2024-06-02 21:36:36.911 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:0, LocalMode: false"]
[2024/06/02 21:36:36.982 +08:00] [INFO] [ddl_worker.go:763] ["finish DDL job"] [worker="worker 4, tp general"] [category=ddl] [jobID=20651] [conn=2464156100] [job="ID:20651, Type:create table, State:synced, SchemaState:public, SchemaID:20648, TableID:20650, RowCount:0, ArgLen:0, start time: 2024-06-02 21:36:36.911 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:0, LocalMode: false"]
[2024/06/02 21:36:36.986 +08:00] [INFO] [ddl.go:1298] ["DDL job is finished"] [category=ddl] [jobID=20651]
[2024/06/02 21:36:36.986 +08:00] [INFO] [callback.go:140] ["performing DDL change, must reload"] [category=ddl]
[2024/06/02 21:36:36.986 +08:00] [INFO] [split_region.go:85] ["split batch regions request"] ["split key count"=1] ["batch count"=1] ["first batch, region ID"=14] ["first split key"=7480000000000050aa]
[2024/06/02 21:36:36.987 +08:00] [INFO] [split_region.go:187] ["batch split regions complete"] ["batch region ID"=14] ["first at"=7480000000000050aa] ["first new region left"="{Id:16824 StartKey:7480000000000050ffa500000000000000f8 EndKey:7480000000000050ffaa00000000000000f8 RegionEpoch:{ConfVer:1 Version:8104} Peers:[id:16825 store_id:1 ] EncryptionMeta:<nil> IsInFlashback:false FlashbackStartTs:0}"] ["new region count"=1]
[2024/06/02 21:36:36.987 +08:00] [INFO] [split_region.go:236] ["split regions complete"] ["region count"=1] ["region IDs"="[16824]"]
[2024/06/02 21:36:36.987 +08:00] [INFO] [domain.go:288] ["diff load InfoSchema success"] [isV2=false] [currentSchemaVersion=24725] [neededSchemaVersion=24726] ["start time"=579.834µs] [gotSchemaVersion=24726] [phyTblIDs="[20650]"] [actionTypes="[3]"] [diffTypes="[\"create table\"]"]
[2024/06/02 21:36:36.988 +08:00] [INFO] [session.go:3985] [GENERAL_LOG] [conn=2464156100] [session_alias=] [user=root@127.0.0.1] [schemaVersion=24726] [txnStartTS=0] [forUpdateTS=0] [isReadConsistency=false] [currentDB=window_function] [isPessimistic=false] [sessionTxnMode=PESSIMISTIC] [sql="SET @@SESSION.`tidb_enable_window_function`=1"]
[2024/06/02 21:36:36.988 +08:00] [INFO] [session.go:3985] [GENERAL_LOG] [conn=2464156100] [session_alias=] [user=root@127.0.0.1] [schemaVersion=24726] [txnStartTS=0] [forUpdateTS=0] [isReadConsistency=false] [currentDB=window_function] [isPessimistic=false] [sessionTxnMode=PESSIMISTIC] [sql="SET @@SESSION.`tidb_window_concurrency`=1"]
[2024/06/02 21:36:36.989 +08:00] [INFO] [session.go:3985] [GENERAL_LOG] [conn=2464156100] [session_alias=] [user=root@127.0.0.1] [schemaVersion=24726] [txnStartTS=0] [forUpdateTS=0] [isReadConsistency=false] [currentDB=window_function] [isPessimistic=false] [sessionTxnMode=PESSIMISTIC] [sql="explain format = 'brief' select sum(a) over() from t;"]
[2024/06/02 21:36:36.989 +08:00] [INFO] [session.go:3985] [GENERAL_LOG] [conn=2464156100] [session_alias=] [user=root@127.0.0.1] [schemaVersion=24726] [txnStartTS=0] [forUpdateTS=0] [isReadConsistency=false] [currentDB=window_function] [isPessimistic=false] [sessionTxnMode=PESSIMISTIC] [sql="explain format = 'brief' select sum(a) over(partition by a) from t;"]
[2024/06/02 21:36:36.990 +08:00] [INFO] [session.go:3985] [GENERAL_LOG] [conn=2464156100] [session_alias=] [user=root@127.0.0.1] [schemaVersion=24726] [txnStartTS=0] [forUpdateTS=0] [isReadConsistency=false] [currentDB=window_function] [isPessimistic=false] [sessionTxnMode=PESSIMISTIC] [sql="explain format = 'brief' select sum(a) over(partition by a order by b) from t;"]
[2024/06/02 21:36:36.990 +08:00] [INFO] [session.go:3985] [GENERAL_LOG] [conn=2464156100] [session_alias=] [user=root@127.0.0.1] [schemaVersion=24726] [txnStartTS=0] [forUpdateTS=0] [isReadConsistency=false] [currentDB=window_function] [isPessimistic=false] [sessionTxnMode=PESSIMISTIC] [sql="explain format = 'brief' select sum(a) over(partition by a order by b rows unbounded preceding) from t;"]
[2024/06/02 21:36:36.991 +08:00] [INFO] [session.go:3985] [GENERAL_LOG] [conn=2464156100] [session_alias=] [user=root@127.0.0.1] [schemaVersion=24726] [txnStartTS=0] [forUpdateTS=0] [isReadConsistency=false] [currentDB=window_function] [isPessimistic=false] [sessionTxnMode=PESSIMISTIC] [sql="explain format = 'brief' select sum(a) over(partition by a order by b rows between 1 preceding and 1 following) from t;"]
[2024/06/02 21:36:36.991 +08:00] [INFO] [session.go:3985] [GENERAL_LOG] [conn=2464156100] [session_alias=] [user=root@127.0.0.1] [schemaVersion=24726] [txnStartTS=0] [forUpdateTS=0] [isReadConsistency=false] [currentDB=window_function] [isPessimistic=false] [sessionTxnMode=PESSIMISTIC] [sql="explain format = 'brief' select sum(a) over(partition by a order by b range between 1 preceding and 1 following) from t;"]
[2024/06/02 21:36:36.992 +08:00] [INFO] [session.go:3985] [GENERAL_LOG] [conn=2464156100] [session_alias=] [user=root@127.0.0.1] [schemaVersion=24726] [txnStartTS=0] [forUpdateTS=0] [isReadConsistency=false] [currentDB=window_function] [isPessimistic=false] [sessionTxnMode=PESSIMISTIC] [sql="explain format = 'brief' select sum(a) over(partition by a order by c range between interval '2:30' minute_second preceding and interval '2:30' minute_second following) from t;"]
[2024/06/02 21:36:36.992 +08:00] [INFO] [session.go:3985] [GENERAL_LOG] [conn=2464156100] [session_alias=] [user=root@127.0.0.1] [schemaVersion=24726] [txnStartTS=0] [forUpdateTS=0] [isReadConsistency=false] [currentDB=window_function] [isPessimistic=false] [sessionTxnMode=PESSIMISTIC] [sql="SET @@SESSION.`tidb_window_concurrency`=4"]
[2024/06/02 21:36:36.992 +08:00] [INFO] [session.go:3985] [GENERAL_LOG] [conn=2464156100] [session_alias=] [user=root@127.0.0.1] [schemaVersion=24726] [txnStartTS=0] [forUpdateTS=0] [isReadConsistency=false] [currentDB=window_function] [isPessimistic=false] [sessionTxnMode=PESSIMISTIC] [sql="explain format = 'brief' select sum(a) over() from t;"]
[2024/06/02 21:36:36.992 +08:00] [INFO] [session.go:3985] [GENERAL_LOG] [conn=2464156100] [session_alias=] [user=root@127.0.0.1] [schemaVersion=24726] [txnStartTS=0] [forUpdateTS=0] [isReadConsistency=false] [currentDB=window_function] [isPessimistic=false] [sessionTxnMode=PESSIMISTIC] [sql="explain format = 'brief' select sum(a) over(partition by a) from t;"]
[2024/06/02 21:36:36.993 +08:00] [INFO] [session.go:3985] [GENERAL_LOG] [conn=2464156100] [session_alias=] [user=root@127.0.0.1] [schemaVersion=24726] [txnStartTS=0] [forUpdateTS=0] [isReadConsistency=false] [currentDB=window_function] [isPessimistic=false] [sessionTxnMode=PESSIMISTIC] [sql="explain format = 'brief' select sum(a) over(partition by a order by b) from t;"]
[2024/06/02 21:36:36.993 +08:00] [INFO] [session.go:3985] [GENERAL_LOG] [conn=2464156100] [session_alias=] [user=root@127.0.0.1] [schemaVersion=24726] [txnStartTS=0] [forUpdateTS=0] [isReadConsistency=false] [currentDB=window_function] [isPessimistic=false] [sessionTxnMode=PESSIMISTIC] [sql="explain format = 'brief' select sum(a) over(partition by a order by b rows unbounded preceding) from t;"]
[2024/06/02 21:36:36.994 +08:00] [INFO] [session.go:3985] [GENERAL_LOG] [conn=2464156100] [session_alias=] [user=root@127.0.0.1] [schemaVersion=24726] [txnStartTS=0] [forUpdateTS=0] [isReadConsistency=false] [currentDB=window_function] [isPessimistic=false] [sessionTxnMode=PESSIMISTIC] [sql="explain format = 'brief' select sum(a) over(partition by a order by b rows between 1 preceding and 1 following) from t;"]
[2024/06/02 21:36:36.994 +08:00] [INFO] [session.go:3985] [GENERAL_LOG] [conn=2464156100] [session_alias=] [user=root@127.0.0.1] [schemaVersion=24726] [txnStartTS=0] [forUpdateTS=0] [isReadConsistency=false] [currentDB=window_function] [isPessimistic=false] [sessionTxnMode=PESSIMISTIC] [sql="explain format = 'brief' select sum(a) over(partition by a order by b range between 1 preceding and 1 following) from t;"]
[2024/06/02 21:36:36.995 +08:00] [INFO] [session.go:3985] [GENERAL_LOG] [conn=2464156100] [session_alias=] [user=root@127.0.0.1] [schemaVersion=24726] [txnStartTS=0] [forUpdateTS=0] [isReadConsistency=false] [currentDB=window_function] [isPessimistic=false] [sessionTxnMode=PESSIMISTIC] [sql="explain format = 'brief' select sum(a) over(partition by a order by c range between interval '2:30' minute_second preceding and interval '2:30' minute_second following) from t;"]
[2024/06/02 21:36:36.995 +08:00] [INFO] [session.go:3959] ["CRUCIAL OPERATION"] [conn=2464156100] [schemaVersion=24726] [cur_db=window_function] [sql="drop table if exists t1;"] [user=root@%]
[2024/06/02 21:36:36.996 +08:00] [INFO] [session.go:3959] ["CRUCIAL OPERATION"] [conn=2464156100] [schemaVersion=24726] [cur_db=window_function] [sql="create table t1(a int primary key, b int);"] [user=root@%]
[2024/06/02 21:36:37.008 +08:00] [INFO] [ddl_worker.go:261] ["add DDL jobs"] [category=ddl] ["batch count"=1] [jobs="ID:20653, Type:create table, State:queueing, SchemaState:none, SchemaID:20648, TableID:20652, RowCount:0, ArgLen:2, start time: 2024-06-02 21:36:36.961 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:0, LocalMode: false; "] [table=true]
[2024/06/02 21:36:37.008 +08:00] [INFO] [ddl.go:1192] ["start DDL job"] [category=ddl] [job="ID:20653, Type:create table, State:queueing, SchemaState:none, SchemaID:20648, TableID:20652, RowCount:0, ArgLen:2, start time: 2024-06-02 21:36:36.961 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:0, LocalMode: false"] [query="create table t1(a int primary key, b int);"]
[2024/06/02 21:36:37.028 +08:00] [INFO] [ddl_worker.go:1210] ["run DDL job"] [worker="worker 4, tp general"] [category=ddl] [jobID=20653] [conn=2464156100] [category=ddl] [job="ID:20653, Type:create table, State:queueing, SchemaState:none, SchemaID:20648, TableID:20652, RowCount:0, ArgLen:0, start time: 2024-06-02 21:36:36.961 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:0, LocalMode: false"]
[2024/06/02 21:36:37.047 +08:00] [INFO] [ddl_worker.go:763] ["finish DDL job"] [worker="worker 4, tp general"] [category=ddl] [jobID=20653] [conn=2464156100] [job="ID:20653, Type:create table, State:synced, SchemaState:public, SchemaID:20648, TableID:20652, RowCount:0, ArgLen:0, start time: 2024-06-02 21:36:36.961 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:0, LocalMode: false"]
[2024/06/02 21:36:37.050 +08:00] [INFO] [ddl.go:1298] ["DDL job is finished"] [category=ddl] [jobID=20653]
[2024/06/02 21:36:37.050 +08:00] [INFO] [callback.go:140] ["performing DDL change, must reload"] [category=ddl]
[2024/06/02 21:36:37.050 +08:00] [INFO] [split_region.go:85] ["split batch regions request"] ["split key count"=1] ["batch count"=1] ["first batch, region ID"=14] ["first split key"=7480000000000050ac]
[2024/06/02 21:36:37.052 +08:00] [INFO] [domain.go:288] ["diff load InfoSchema success"] [isV2=false] [currentSchemaVersion=24726] [neededSchemaVersion=24727] ["start time"=486.635µs] [gotSchemaVersion=24727] [phyTblIDs="[20652]"] [actionTypes="[3]"] [diffTypes="[\"create table\"]"]
[2024/06/02 21:36:37.052 +08:00] [INFO] [session.go:3985] [GENERAL_LOG] [conn=2464156100] [session_alias=] [user=root@127.0.0.1] [schemaVersion=24727] [txnStartTS=0] [forUpdateTS=0] [isReadConsistency=false] [currentDB=window_function] [isPessimistic=false] [sessionTxnMode=PESSIMISTIC] [sql="insert into t1 values(1, 1), (2, 1);"]
[2024/06/02 21:36:37.053 +08:00] [WARN] [prewrite.go:382] ["1pc failed and fallbacks to normal commit procedure"] [conn=2464156100] [session_alias=] [startTS=450189170314051603]
[2024/06/02 21:36:37.054 +08:00] [INFO] [split_region.go:187] ["batch split regions complete"] ["batch region ID"=14] ["first at"=7480000000000050ac] ["first new region left"="{Id:16826 StartKey:7480000000000050ffaa00000000000000f8 EndKey:7480000000000050ffac00000000000000f8 RegionEpoch:{ConfVer:1 Version:8105} Peers:[id:16827 store_id:1 ] EncryptionMeta:<nil> IsInFlashback:false FlashbackStartTs:0}"] ["new region count"=1]
[2024/06/02 21:36:37.054 +08:00] [INFO] [split_region.go:236] ["split regions complete"] ["region count"=1] ["region IDs"="[16826]"]
[2024/06/02 21:36:37.054 +08:00] [INFO] [session.go:3985] [GENERAL_LOG] [conn=2464156100] [session_alias=] [user=root@127.0.0.1] [schemaVersion=24727] [txnStartTS=0] [forUpdateTS=0] [isReadConsistency=false] [currentDB=window_function] [isPessimistic=false] [sessionTxnMode=PESSIMISTIC] [sql="analyze table t1;"]
[2024/06/02 21:36:37.076 +08:00] [INFO] [analyze.go:748] ["analyze table `window_function`.`t1` has finished"] [partition=] ["job info"="analyze table all columns with 256 buckets, 500 topn, 1 samplerate"] ["start time"=2024/06/02 21:36:37.061 +08:00] ["end time"=2024/06/02 21:36:37.075 +08:00] [cost=14.031593ms] ["sample rate reason"="use min(1, 110000/10000) as the sample-rate=1"]
[2024/06/02 21:36:37.086 +08:00] [INFO] [session.go:3985] [GENERAL_LOG] [conn=2464156100] [session_alias=] [user=root@127.0.0.1] [schemaVersion=24727] [txnStartTS=0] [forUpdateTS=0] [isReadConsistency=false] [currentDB=window_function] [isPessimistic=false] [sessionTxnMode=PESSIMISTIC] [sql="explain format = 'brief' select sum(a) over(partition by b) from t1;"]
[2024/06/02 21:36:37.086 +08:00] [INFO] [session.go:3985] [GENERAL_LOG] [conn=2464156100] [session_alias=] [user=root@127.0.0.1] [schemaVersion=24727] [txnStartTS=0] [forUpdateTS=0] [isReadConsistency=false] [currentDB=window_function] [isPessimistic=false] [sessionTxnMode=PESSIMISTIC] [sql="insert into t1 values(3, 3);"]
[2024/06/02 21:36:37.087 +08:00] [WARN] [prewrite.go:382] ["1pc failed and fallbacks to normal commit procedure"] [conn=2464156100] [session_alias=] [startTS=450189170327158804]
[2024/06/02 21:36:37.088 +08:00] [INFO] [session.go:3985] [GENERAL_LOG] [conn=2464156100] [session_alias=] [user=root@127.0.0.1] [schemaVersion=24727] [txnStartTS=0] [forUpdateTS=0] [isReadConsistency=false] [currentDB=window_function] [isPessimistic=false] [sessionTxnMode=PESSIMISTIC] [sql="analyze table t1;"]
[2024/06/02 21:36:37.094 +08:00] [INFO] [save.go:200] ["incrementally update modifyCount"] [category=stats] [tableID=20652] [curModifyCnt=0] [results.BaseModifyCnt=0] [modifyCount=0]
[2024/06/02 21:36:37.094 +08:00] [INFO] [save.go:211] ["incrementally update count"] [category=stats] [tableID=20652] [curCnt=2] [results.Count=3] [results.BaseCount=2] [count=3]
[2024/06/02 21:36:37.107 +08:00] [INFO] [analyze.go:748] ["analyze table `window_function`.`t1` has finished"] [partition=] ["job info"="analyze table all columns with 256 buckets, 500 topn, 1 samplerate"] ["start time"=2024/06/02 21:36:37.091 +08:00] ["end time"=2024/06/02 21:36:37.106 +08:00] [cost=14.902453ms] ["sample rate reason"="use min(1, 110000/2) as the sample-rate=1"]
[2024/06/02 21:36:37.116 +08:00] [INFO] [session.go:3985] [GENERAL_LOG] [conn=2464156100] [session_alias=] [user=root@127.0.0.1] [schemaVersion=24727] [txnStartTS=0] [forUpdateTS=0] [isReadConsistency=false] [currentDB=window_function] [isPessimistic=false] [sessionTxnMode=PESSIMISTIC] [sql="explain format = 'brief' select sum(a) over(partition by b) from t1;"]
[2024/06/02 21:36:37.117 +08:00] [INFO] [session.go:3985] [GENERAL_LOG] [conn=2464156104] [session_alias=] [user=root@127.0.0.1] [schemaVersion=24727] [txnStartTS=0] [forUpdateTS=0] [isReadConsistency=false] [currentDB=] [isPessimistic=false] [sessionTxnMode=PESSIMISTIC] [sql="use `test`"]
[2024/06/02 21:36:37.117 +08:00] [INFO] [session.go:3985] [GENERAL_LOG] [conn=2464156104] [session_alias=] [user=root@127.0.0.1] [schemaVersion=24727] [txnStartTS=0] [forUpdateTS=0] [isReadConsistency=false] [currentDB=test] [isPessimistic=false] [sessionTxnMode=PESSIMISTIC] [sql="SET @@SESSION.`time_zone`=_UTF8MB4'Asia/Shanghai'"]
[2024/06/02 21:36:37.117 +08:00] [INFO] [session.go:3959] ["CRUCIAL OPERATION"] [conn=2464156104] [schemaVersion=24727] [cur_db=test] [sql="drop database `window_function`"] [user=root@%]
[2024/06/02 21:36:37.128 +08:00] [INFO] [ddl_worker.go:261] ["add DDL jobs"] [category=ddl] ["batch count"=1] [jobs="ID:20654, Type:drop schema, State:queueing, SchemaState:public, SchemaID:20648, TableID:0, RowCount:0, ArgLen:1, start time: 2024-06-02 21:36:37.111 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:0, LocalMode: false; "] [table=true]
[2024/06/02 21:36:37.128 +08:00] [INFO] [ddl.go:1192] ["start DDL job"] [category=ddl] [job="ID:20654, Type:drop schema, State:queueing, SchemaState:public, SchemaID:20648, TableID:0, RowCount:0, ArgLen:1, start time: 2024-06-02 21:36:37.111 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:0, LocalMode: false"] [query="drop database `window_function`"]
[2024/06/02 21:36:37.151 +08:00] [INFO] [ddl_worker.go:1210] ["run DDL job"] [worker="worker 4, tp general"] [category=ddl] [jobID=20654] [conn=2464156104] [category=ddl] [job="ID:20654, Type:drop schema, State:queueing, SchemaState:public, SchemaID:20648, TableID:0, RowCount:0, ArgLen:0, start time: 2024-06-02 21:36:37.111 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:0, LocalMode: false"]
[2024/06/02 21:36:37.170 +08:00] [INFO] [ddl_worker.go:1210] ["run DDL job"] [worker="worker 4, tp general"] [category=ddl] [jobID=20654] [conn=2464156104] [category=ddl] [job="ID:20654, Type:drop schema, State:running, SchemaState:write only, SchemaID:20648, TableID:0, RowCount:0, ArgLen:0, start time: 2024-06-02 21:36:37.111 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:0, LocalMode: false"]
[2024/06/02 21:36:37.188 +08:00] [INFO] [ddl_worker.go:1210] ["run DDL job"] [worker="worker 4, tp general"] [category=ddl] [jobID=20654] [conn=2464156104] [category=ddl] [job="ID:20654, Type:drop schema, State:running, SchemaState:delete only, SchemaID:20648, TableID:0, RowCount:0, ArgLen:0, start time: 2024-06-02 21:36:37.111 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:0, LocalMode: false"]
[2024/06/02 21:36:37.206 +08:00] [INFO] [delete_range.go:447] ["insert into delete-range table"] [category=ddl] [jobID=20654] [tableIDs="[20650,20652]"] [comment="drop schema: table IDs"]
[2024/06/02 21:36:37.208 +08:00] [INFO] [delete_range.go:112] ["add job into delete-range table"] [category=ddl] [jobID=20654] [jobType="drop schema"]
[2024/06/02 21:36:37.208 +08:00] [INFO] [ddl_worker.go:763] ["finish DDL job"] [worker="worker 4, tp general"] [category=ddl] [jobID=20654] [conn=2464156104] [job="ID:20654, Type:drop schema, State:synced, SchemaState:none, SchemaID:20648, TableID:0, RowCount:0, ArgLen:1, start time: 2024-06-02 21:36:37.111 +0800 CST, Err:<nil>, ErrCount:0, SnapshotVersion:0, LocalMode: false"]
[2024/06/02 21:36:37.211 +08:00] [INFO] [ddl.go:1298] ["DDL job is finished"] [category=ddl] [jobID=20654]
[2024/06/02 21:36:37.211 +08:00] [INFO] [callback.go:140] ["performing DDL change, must reload"] [category=ddl]
[2024/06/02 21:36:37.212 +08:00] [INFO] [domain.go:288] ["diff load InfoSchema success"] [isV2=false] [currentSchemaVersion=24727] [neededSchemaVersion=24730] ["start time"=413.019µs] [gotSchemaVersion=24730] [phyTblIDs="[20650,20652]"] [actionTypes="[2,2]"] [diffTypes="[\"drop schema\",\"drop schema\",\"drop schema\"]"]
[2024/06/02 21:36:37.216 +08:00] [INFO] [signal_posix.go:54] ["got signal to exit"] [signal=terminated]
[2024/06/02 21:36:37.216 +08:00] [INFO] [server.go:584] ["setting tidb-server to report unhealthy (shutting-down)"]
[2024/06/02 21:36:37.216 +08:00] [ERROR] [http_status.go:531] ["start status/rpc server error"] [error="accept tcp 127.0.0.1:37119: use of closed network connection"]
[2024/06/02 21:36:37.216 +08:00] [ERROR] [http_status.go:526] ["http server error"] [error="http: Server closed"]
[2024/06/02 21:36:37.216 +08:00] [ERROR] [http_status.go:521] ["grpc server error"] [error="mux: server closed"]
[2024/06/02 21:36:37.216 +08:00] [INFO] [manager.go:232] ["retire owner"] ["owner info"="[autoid] tidb/autoid/leader ownerManager 127.0.0.1:37119"]
[2024/06/02 21:36:37.216 +08:00] [WARN] [manager.go:315] ["is not the owner"] ["owner info"="[autoid] tidb/autoid/leader ownerManager 127.0.0.1:37119"]
[2024/06/02 21:36:37.216 +08:00] [INFO] [manager.go:266] ["etcd session is done, creates a new one"] ["owner info"="[autoid] tidb/autoid/leader ownerManager 127.0.0.1:37119"]
[2024/06/02 21:36:37.216 +08:00] [INFO] [manager.go:270] ["break campaign loop, NewSession failed"] ["owner info"="[autoid] tidb/autoid/leader ownerManager 127.0.0.1:37119"] [error="context canceled"]
[2024/06/02 21:36:37.217 +08:00] [INFO] [manager.go:326] ["revoke session"] ["owner info"="[autoid] tidb/autoid/leader ownerManager 127.0.0.1:37119"] []
[2024/06/02 21:36:37.217 +08:00] [INFO] [server.go:978] ["start drain clients"]
[2024/06/02 21:36:37.217 +08:00] [INFO] [server.go:1007] ["all sessions quit in drain wait time"]
[2024/06/02 21:36:37.217 +08:00] [INFO] [server.go:959] ["kill all connections."] [category=server]
[2024/06/02 21:36:37.217 +08:00] [INFO] [syncer.go:485] ["schema version sync loop interrupted, retrying..."] [category=ddl]
[2024/06/02 21:36:37.217 +08:00] [INFO] [manager.go:232] ["retire owner"] ["owner info"="[ddl] /tidb/ddl/fg/owner ownerManager 60b54957-c640-457c-b1db-c4573fca1b68"]
[2024/06/02 21:36:37.232 +08:00] [INFO] [ddl_workerpool.go:82] ["closing workerPool"] [category=ddl]
[2024/06/02 21:36:37.232 +08:00] [INFO] [ddl_worker.go:188] ["DDL worker closed"] [worker="worker 5, tp add index"] [category=ddl] ["take time"=1.271µs]
[2024/06/02 21:36:37.232 +08:00] [INFO] [ddl_worker.go:188] ["DDL worker closed"] [worker="worker 6, tp add index"] [category=ddl] ["take time"=1.192µs]
[2024/06/02 21:36:37.232 +08:00] [INFO] [ddl_workerpool.go:82] ["closing workerPool"] [category=ddl]
[2024/06/02 21:36:37.232 +08:00] [INFO] [ddl_worker.go:188] ["DDL worker closed"] [worker="worker 4, tp general"] [category=ddl] ["take time"=483ns]
[2024/06/02 21:36:37.232 +08:00] [WARN] [manager.go:315] ["is not the owner"] ["owner info"="[ddl] /tidb/ddl/fg/owner ownerManager 60b54957-c640-457c-b1db-c4573fca1b68"]
[2024/06/02 21:36:37.232 +08:00] [INFO] [manager.go:266] ["etcd session is done, creates a new one"] ["owner info"="[ddl] /tidb/ddl/fg/owner ownerManager 60b54957-c640-457c-b1db-c4573fca1b68"]
[2024/06/02 21:36:37.232 +08:00] [INFO] [manager.go:270] ["break campaign loop, NewSession failed"] ["owner info"="[ddl] /tidb/ddl/fg/owner ownerManager 60b54957-c640-457c-b1db-c4573fca1b68"] [error="context canceled"]
[2024/06/02 21:36:37.233 +08:00] [INFO] [manager.go:326] ["revoke session"] ["owner info"="[ddl] /tidb/ddl/fg/owner ownerManager 60b54957-c640-457c-b1db-c4573fca1b68"] []
[2024/06/02 21:36:37.233 +08:00] [INFO] [ddl_workerpool.go:82] ["closing workerPool"] [category=ddl]
[2024/06/02 21:36:37.233 +08:00] [INFO] [delete_range.go:162] ["closing delRange"] [category=ddl]
[2024/06/02 21:36:37.233 +08:00] [INFO] [session_pool.go:91] ["closing session pool"] [category=ddl]
[2024/06/02 21:36:37.234 +08:00] [INFO] [ddl.go:959] ["DDL closed"] [category=ddl] [ID=60b54957-c640-457c-b1db-c4573fca1b68] ["take time"=17.473891ms]
[2024/06/02 21:36:37.234 +08:00] [INFO] [ddl.go:795] ["stop DDL"] [category=ddl] [ID=60b54957-c640-457c-b1db-c4573fca1b68]
[2024/06/02 21:36:37.235 +08:00] [INFO] [domain.go:1043] ["stopping ttlJobManager"]
[2024/06/02 21:36:37.235 +08:00] [INFO] [runtime.go:190] ["TimerGroupRuntime loop exit"] [groupID=ttl]
[2024/06/02 21:36:37.235 +08:00] [INFO] [notifier.go:227] ["etcd notify loop to watch timer events stopped"] [EtcdKey=/tidb/timer/cluster/1/notify/9d6b7791-4afc-44ba-bf31-8828bca0fbb3]
[2024/06/02 21:36:37.235 +08:00] [INFO] [notifier.go:142] ["etcd watcher exited to watch timer events"] [EtcdKey=/tidb/timer/cluster/1/notify/9d6b7791-4afc-44ba-bf31-8828bca0fbb3] [watcherID=757d4fe5-9af2-4a72-8b60-3c14f9d52030]
[2024/06/02 21:36:37.235 +08:00] [INFO] [task_manager.go:194] ["shrink ttl worker"] [ttl-worker=job-manager] [ttl-worker=task-manager] [originalCount=4] [newCount=0]
[2024/06/02 21:36:37.235 +08:00] [INFO] [scan.go:309] ["ttlScanWorker loop exited."]
[2024/06/02 21:36:37.235 +08:00] [INFO] [scan.go:309] ["ttlScanWorker loop exited."]
[2024/06/02 21:36:37.235 +08:00] [INFO] [scan.go:309] ["ttlScanWorker loop exited."]
[2024/06/02 21:36:37.235 +08:00] [INFO] [scan.go:309] ["ttlScanWorker loop exited."]
[2024/06/02 21:36:37.235 +08:00] [INFO] [task_manager.go:194] ["shrink ttl worker"] [ttl-worker=job-manager] [ttl-worker=task-manager] [originalCount=4] [newCount=0]
[2024/06/02 21:36:37.235 +08:00] [INFO] [del.go:261] ["ttlDeleteWorker loop exited."]
[2024/06/02 21:36:37.235 +08:00] [INFO] [del.go:261] ["ttlDeleteWorker loop exited."]
[2024/06/02 21:36:37.235 +08:00] [INFO] [del.go:261] ["ttlDeleteWorker loop exited."]
[2024/06/02 21:36:37.235 +08:00] [INFO] [del.go:261] ["ttlDeleteWorker loop exited."]
[2024/06/02 21:36:37.235 +08:00] [INFO] [job_manager.go:174] ["ttlJobManager loop exited."] [ttl-worker=job-manager]
[2024/06/02 21:36:37.235 +08:00] [INFO] [domain.go:1054] ["ttlJobManager exited."]
[2024/06/02 21:36:37.236 +08:00] [INFO] [domain.go:2854] ["releaseServerID succeed"] [serverID=1175]
[2024/06/02 21:36:37.236 +08:00] [INFO] [domain.go:2360] ["loadStatsWorker exited."]
[2024/06/02 21:36:37.236 +08:00] [INFO] [domain.go:1717] ["loadPrivilegeInLoop exited."]
[2024/06/02 21:36:37.236 +08:00] [INFO] [wait_group_wrapper.go:140] ["background process exited"] [source=domain] [process=loadStatsWorker]
[2024/06/02 21:36:37.236 +08:00] [INFO] [wait_group_wrapper.go:140] ["background process exited"] [source=domain] [process=loadSigningCertLoop]
[2024/06/02 21:36:37.236 +08:00] [INFO] [wait_group_wrapper.go:140] ["background process exited"] [source=domain] [process=loadPrivilegeInLoop]
[2024/06/02 21:36:37.236 +08:00] [INFO] [domain.go:2037] ["PlanReplayerTaskCollectHandle exited."]
[2024/06/02 21:36:37.236 +08:00] [INFO] [domain.go:2091] ["dumpFileGcChecker exited."]
[2024/06/02 21:36:37.236 +08:00] [INFO] [domain.go:2918] ["serverIDKeeper exited."]
[2024/06/02 21:36:37.236 +08:00] [INFO] [manager.go:232] ["retire owner"] ["owner info"="[bindinfo] /tidb/bindinfo/owner ownerManager 60b54957-c640-457c-b1db-c4573fca1b68"]
[2024/06/02 21:36:37.236 +08:00] [INFO] [domain.go:1767] ["LoadSysVarCacheLoop exited."]
[2024/06/02 21:36:37.236 +08:00] [INFO] [domain.go:754] ["globalConfigSyncerKeeper exited."]
[2024/06/02 21:36:37.236 +08:00] [INFO] [wait_group_wrapper.go:140] ["background process exited"] [source=domain] [process=LoadSysVarCacheLoop]
[2024/06/02 21:36:37.236 +08:00] [INFO] [domain.go:2122] ["HistoricalStatsWorker exited."]
[2024/06/02 21:36:37.236 +08:00] [INFO] [stats_syncload.go:216] ["SubLoadWorker exited."]
[2024/06/02 21:36:37.236 +08:00] [INFO] [wait_group_wrapper.go:140] ["background process exited"] [source=domain] [process=globalConfigSyncerKeeper]
[2024/06/02 21:36:37.236 +08:00] [INFO] [domain.go:2057] ["PlanReplayerTaskDumpHandle exited."]
[2024/06/02 21:36:37.236 +08:00] [INFO] [plan_replayer.go:413] ["planReplayerTaskDumpWorker exited."]
[2024/06/02 21:36:37.236 +08:00] [INFO] [manager.go:455] ["watcher is closed, no owner"] ["owner info"="[log-backup] ownerManager dfd9ba0a-5480-44f9-8e66-852b27fb65b8 watch owner key /tidb/br-stream/owner/6e648fd9106ad729"]
[2024/06/02 21:36:37.236 +08:00] [INFO] [manager.go:232] ["retire owner"] ["owner info"="[stats] /tidb/stats/owner ownerManager 60b54957-c640-457c-b1db-c4573fca1b68"]
[2024/06/02 21:36:37.236 +08:00] [INFO] [advancer.go:397] ["Meet task event"] [category="log backup advancer"] [event="Err(, err = EOF)"]
[2024/06/02 21:36:37.236 +08:00] [ERROR] [advancer.go:400] ["listen task meet error, would reopen."] [error=EOF]
[2024/06/02 21:36:37.236 +08:00] [INFO] [advancer.go:403] ["Task watcher exits due to some error."] [category="log backup advancer"] [error=EOF]
[2024/06/02 21:36:37.236 +08:00] [WARN] [manager.go:315] ["is not the owner"] ["owner info"="[bindinfo] /tidb/bindinfo/owner ownerManager 60b54957-c640-457c-b1db-c4573fca1b68"]
[2024/06/02 21:36:37.236 +08:00] [INFO] [manager.go:266] ["etcd session is done, creates a new one"] ["owner info"="[bindinfo] /tidb/bindinfo/owner ownerManager 60b54957-c640-457c-b1db-c4573fca1b68"]
[2024/06/02 21:36:37.236 +08:00] [INFO] [manager.go:270] ["break campaign loop, NewSession failed"] ["owner info"="[bindinfo] /tidb/bindinfo/owner ownerManager 60b54957-c640-457c-b1db-c4573fca1b68"] [error="context canceled"]
[2024/06/02 21:36:37.236 +08:00] [WARN] [manager.go:315] ["is not the owner"] ["owner info"="[stats] /tidb/stats/owner ownerManager 60b54957-c640-457c-b1db-c4573fca1b68"]
[2024/06/02 21:36:37.236 +08:00] [INFO] [manager.go:266] ["etcd session is done, creates a new one"] ["owner info"="[stats] /tidb/stats/owner ownerManager 60b54957-c640-457c-b1db-c4573fca1b68"]
[2024/06/02 21:36:37.236 +08:00] [INFO] [manager.go:270] ["break campaign loop, NewSession failed"] ["owner info"="[stats] /tidb/stats/owner ownerManager 60b54957-c640-457c-b1db-c4573fca1b68"] [error="context canceled"]
[2024/06/02 21:36:37.236 +08:00] [INFO] [domain.go:728] ["infoSyncerKeeper exited."]
[2024/06/02 21:36:37.236 +08:00] [INFO] [wait_group_wrapper.go:140] ["background process exited"] [source=domain] [process=infoSyncerKeeper]
[2024/06/02 21:36:37.236 +08:00] [INFO] [domain.go:2389] ["indexUsageWorker exited."]
[2024/06/02 21:36:37.236 +08:00] [INFO] [wait_group_wrapper.go:140] ["background process exited"] [source=domain] [process=indexUsageWorker]
[2024/06/02 21:36:37.236 +08:00] [INFO] [wait_group_wrapper.go:140] ["background process exited"] [source=domain] [process=dumpFileGcChecker]
[2024/06/02 21:36:37.236 +08:00] [INFO] [domain.go:778] ["topologySyncerKeeper exited."]
[2024/06/02 21:36:37.236 +08:00] [INFO] [wait_group_wrapper.go:140] ["background process exited"] [source=domain] [process=topologySyncerKeeper]
[2024/06/02 21:36:37.236 +08:00] [INFO] [domain.go:1559] ["stopping dist task scheduler manager because the current node is not DDL owner anymore"] [id=60b54957-c640-457c-b1db-c4573fca1b68]
[2024/06/02 21:36:37.236 +08:00] [INFO] [scheduler_manager.go:318] ["subtask history table gc loop exits"]
[2024/06/02 21:36:37.236 +08:00] [INFO] [scheduler_manager.go:459] ["collect loop exits"]
[2024/06/02 21:36:37.236 +08:00] [INFO] [wait_group_wrapper.go:140] ["background process exited"] [source=domain] [process=runawayWatchSyncLoop]
[2024/06/02 21:36:37.236 +08:00] [INFO] [scheduler_manager.go:206] ["schedule task loop exits"]
[2024/06/02 21:36:37.236 +08:00] [INFO] [scheduler_manager.go:379] ["cleanup loop exits"]
[2024/06/02 21:36:37.236 +08:00] [INFO] [wait_group_wrapper.go:140] ["background process exited"] [source=domain] [process=PlanReplayerTaskCollectHandle]
[2024/06/02 21:36:37.236 +08:00] [INFO] [stats_syncload.go:216] ["SubLoadWorker exited."]
[2024/06/02 21:36:37.236 +08:00] [INFO] [wait_group_wrapper.go:140] ["background process exited"] [source=domain] [process=HistoricalStatsWorker]
[2024/06/02 21:36:37.236 +08:00] [INFO] [domain.go:1561] ["dist task scheduler manager stopped"] [id=60b54957-c640-457c-b1db-c4573fca1b68]
[2024/06/02 21:36:37.236 +08:00] [INFO] [domain.go:1544] ["stopping dist task executor manager"]
[2024/06/02 21:36:37.236 +08:00] [INFO] [wait_group_wrapper.go:140] ["background process exited"] [source=domain] [process=mdlCheckLoop]
[2024/06/02 21:36:37.236 +08:00] [INFO] [manager.go:280] ["recoverMetaLoop done"]
[2024/06/02 21:36:37.236 +08:00] [INFO] [wait_group_wrapper.go:140] ["background process exited"] [source=domain] [process=runawayRecordFlushLoop]
[2024/06/02 21:36:37.236 +08:00] [INFO] [wait_group_wrapper.go:140] ["background process exited"] [source=domain] [process=requestUnitsWriterLoop]
[2024/06/02 21:36:37.236 +08:00] [INFO] [stats_syncload.go:216] ["SubLoadWorker exited."]
[2024/06/02 21:36:37.236 +08:00] [INFO] [flush_subscriber.go:109] [Clearing.] [category="log backup flush subscriber"] [timeout=1m0s]
[2024/06/02 21:36:37.236 +08:00] [INFO] [wait_group_wrapper.go:140] ["background process exited"] [source=domain] [process=PlanReplayerTaskDumpHandle]
[2024/06/02 21:36:37.236 +08:00] [INFO] [stats_syncload.go:216] ["SubLoadWorker exited."]
[2024/06/02 21:36:37.236 +08:00] [INFO] [stats_syncload.go:216] ["SubLoadWorker exited."]
[2024/06/02 21:36:37.236 +08:00] [INFO] [manager.go:232] ["retire owner"] ["owner info"="[log-backup] /tidb/br-stream/owner ownerManager dfd9ba0a-5480-44f9-8e66-852b27fb65b8"]
[2024/06/02 21:36:37.236 +08:00] [INFO] [owner_daemon.go:87] ["daemon loop exits"] [id=dfd9ba0a-5480-44f9-8e66-852b27fb65b8] [daemon-id=LogBackup::Advancer]
[2024/06/02 21:36:37.236 +08:00] [WARN] [manager.go:315] ["is not the owner"] ["owner info"="[log-backup] /tidb/br-stream/owner ownerManager dfd9ba0a-5480-44f9-8e66-852b27fb65b8"]
[2024/06/02 21:36:37.236 +08:00] [INFO] [wait_group_wrapper.go:140] ["background process exited"] [source=domain] [process=logBackupAdvancer]
[2024/06/02 21:36:37.236 +08:00] [INFO] [manager.go:266] ["etcd session is done, creates a new one"] ["owner info"="[log-backup] /tidb/br-stream/owner ownerManager dfd9ba0a-5480-44f9-8e66-852b27fb65b8"]
[2024/06/02 21:36:37.236 +08:00] [INFO] [domain.go:700] ["topNSlowQueryLoop exited."]
[2024/06/02 21:36:37.236 +08:00] [INFO] [domain.go:1378] ["closestReplicaReadCheckLoop exited."]
[2024/06/02 21:36:37.236 +08:00] [INFO] [wait_group_wrapper.go:140] ["background process exited"] [source=domain] [process=topNSlowQueryLoop]
[2024/06/02 21:36:37.236 +08:00] [INFO] [manager.go:179] ["handle tasks loop done"]
[2024/06/02 21:36:37.236 +08:00] [INFO] [wait_group_wrapper.go:140] ["background process exited"] [source=domain] [process=closestReplicaReadCheckLoop]
[2024/06/02 21:36:37.236 +08:00] [INFO] [domain.go:1546] ["dist task executor manager stopped"]
[2024/06/02 21:36:37.236 +08:00] [INFO] [wait_group_wrapper.go:140] ["background process exited"] [source=domain] [process=distTaskFrameworkLoop]
[2024/06/02 21:36:37.236 +08:00] [INFO] [manager.go:270] ["break campaign loop, NewSession failed"] ["owner info"="[log-backup] /tidb/br-stream/owner ownerManager dfd9ba0a-5480-44f9-8e66-852b27fb65b8"] [error="context canceled"]
[2024/06/02 21:36:39.745 +08:00] [INFO] [manager.go:326] ["revoke session"] ["owner info"="[log-backup] /tidb/br-stream/owner ownerManager dfd9ba0a-5480-44f9-8e66-852b27fb65b8"] [error="rpc error: code = Canceled desc = grpc: the client connection is closing"]
[2024/06/02 21:36:39.762 +08:00] [INFO] [manager.go:326] ["revoke session"] ["owner info"="[bindinfo] /tidb/bindinfo/owner ownerManager 60b54957-c640-457c-b1db-c4573fca1b68"] [error="rpc error: code = Canceled desc = grpc: the client connection is closing"]
[2024/06/02 21:36:39.762 +08:00] [INFO] [domain.go:1906] ["globalBindHandleWorkerLoop exited."]
[2024/06/02 21:36:39.762 +08:00] [INFO] [wait_group_wrapper.go:140] ["background process exited"] [source=domain] [process=globalBindHandleWorkerLoop]
[2024/06/02 21:36:39.781 +08:00] [INFO] [manager.go:326] ["revoke session"] ["owner info"="[stats] /tidb/stats/owner ownerManager 60b54957-c640-457c-b1db-c4573fca1b68"] [error="rpc error: code = Canceled desc = grpc: the client connection is closing"]
[2024/06/02 21:36:39.781 +08:00] [INFO] [wait_group_wrapper.go:140] ["background process exited"] [source=domain] [process=quitStatsOwner]
[2024/06/02 21:36:39.785 +08:00] [INFO] [domain.go:1091] ["domain closed"] ["take time"=2.568278855s]
[2024/06/02 21:36:39.786 +08:00] [INFO] [gc_worker.go:223] [quit] [category="gc worker"] [uuid=63f6441f35c0014]
[2024/06/02 21:36:39.786 +08:00] [INFO] [tso_dispatcher.go:137] ["[tso] exit tso deadline watcher"] [dc-location=global]
[2024/06/02 21:36:39.786 +08:00] [INFO] [tso_dispatcher.go:210] ["[tso] stop fetching the pending tso requests due to context canceled"] [dc-location=global]
[2024/06/02 21:36:39.786 +08:00] [INFO] [tso_dispatcher.go:171] ["[tso] exit tso dispatcher"] [dc-location=global]
[2024/06/02 21:36:39.786 +08:00] [INFO] [tso_batch_controller.go:160] ["[pd] clear the tso batch controller"] [max-batch-size=10000] [best-batch-size=1] [collected-request-count=0] [pending-request-count=0]
[2024/06/02 21:36:39.786 +08:00] [INFO] [resource_manager_client.go:295] ["[resource manager] exit resource token dispatcher"]
[2024/06/02 21:36:39.786 +08:00] [INFO] [tso_client.go:145] ["[tso] exit tso dispatcher check loop"]
[2024/06/02 21:36:39.786 +08:00] [INFO] [tso_dispatcher.go:350] ["[tso] exit tso connection contexts updater"] [dc-location=global]
[2024/06/02 21:36:39.786 +08:00] [INFO] [pd_service_discovery.go:550] ["[pd] exit member loop due to context canceled"]
[2024/06/02 21:36:39.786 +08:00] [INFO] [tso_client.go:155] ["[tso] closing tso client"]
[2024/06/02 21:36:39.786 +08:00] [INFO] [tso_client.go:160] ["[tso] close tso client"]
[2024/06/02 21:36:39.786 +08:00] [INFO] [tso_batch_controller.go:160] ["[pd] clear the tso batch controller"] [max-batch-size=10000] [best-batch-size=1] [collected-request-count=0] [pending-request-count=0]
[2024/06/02 21:36:39.786 +08:00] [INFO] [tso_client.go:162] ["[tso] tso client is closed"]
[2024/06/02 21:36:39.786 +08:00] [INFO] [pd_service_discovery.go:637] ["[pd] close pd service discovery client"]
[2024/06/02 21:36:39.786 +08:00] [INFO] [client.go:330] ["[pd] http client closed"] [source=tikv-driver]
[2024/06/02 21:36:39.787 +08:00] [INFO] [cpu.go:98] ["sql cpu collector stopped"]
[2024/06/02 21:36:39.787 +08:00] [INFO] [cgmon.go:77] ["cgroup monitor stopped"]
[2024/06/02 21:36:39.787 +08:00] [INFO] [cpuprofile.go:130] ["parallel cpu profiler stopped"]
[Pipeline] archiveArtifacts
Archiving artifacts
No test report files were found. Configuration error?
[Pipeline] }
[Pipeline] // dir
[Pipeline] }
[Pipeline] // stage
[Pipeline] }
[Pipeline] // container
[Pipeline] }
[Pipeline] // withEnv
[Pipeline] }
[Pipeline] // node
[Pipeline] }
[Pipeline] // podTemplate
[Pipeline] }
[Pipeline] // withEnv
[Pipeline] }
[Pipeline] // stage
[Pipeline] }
[Pipeline] // parallel
[Pipeline] }
[Pipeline] // stage
[Pipeline] stage
[Pipeline] { (Declarative: Post Actions)
[Pipeline] sh
+ echo 44356c16acc47bf4f5cee733b5153cdeec3fff80
+ echo 199b01792159e5d8e83ef419a5053401e998bb0e
+ echo 8483dc538be95234dde6d6c31d1bb3248488440e
+ curl -F refs/pingcap/tikv/master/sha1.verify=@tikv.sha1.verify http://fileserver.pingcap.net/upload
  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                 Dload  Upload   Total   Spent    Left  Speed

  0     0    0     0    0     0      0      0 --:--:-- --:--:-- --:--:--     0
100   382  100   101  100   281   2374   6605 --:--:-- --:--:-- --:--:--  6690
{"msg":"success","url":"http://fileserver.pingcap.net/download/refs/pingcap/tikv/master/sha1.verify"}+ curl -F refs/pingcap/pd/master/sha1.verify=@pd.sha1.verify http://fileserver.pingcap.net/upload
  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                 Dload  Upload   Total   Spent    Left  Speed

  0     0    0     0    0     0      0      0 --:--:-- --:--:-- --:--:--     0
100   376  100    99  100   277   3046   8525 --:--:-- --:--:-- --:--:--  8656
{"msg":"success","url":"http://fileserver.pingcap.net/download/refs/pingcap/pd/master/sha1.verify"}+ curl -F refs/pingcap/tidb/master/sha1.verify=@tidb.sha1.verify http://fileserver.pingcap.net/upload
  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                 Dload  Upload   Total   Spent    Left  Speed

  0     0    0     0    0     0      0      0 --:--:-- --:--:-- --:--:--     0
100   382  100   101  100   281   4175  11618 --:--:-- --:--:-- --:--:-- 11708
{"msg":"success","url":"http://fileserver.pingcap.net/download/refs/pingcap/tidb/master/sha1.verify"}
[Pipeline] }
[Pipeline] // stage
[Pipeline] }
[Pipeline] // timeout
[Pipeline] }
[Pipeline] // withEnv
[Pipeline] }
[Pipeline] // container
[Pipeline] }
[Pipeline] // withEnv
[Pipeline] }
[Pipeline] // node
[Pipeline] }
[Pipeline] // podTemplate
[Pipeline] End of Pipeline
Finished: SUCCESS