Is there an existing issue for the same bug?
- [X] I have checked the existing issues.
Environment
- Version or commit-id (e.g. v0.1.0 or 8b23a93):
- Hardware parameters:
- OS type:
- Others:
Actual Behavior
https://github.com/matrixorigin/matrixone/actions/runs/5131230972/jobs/9231046817?pr=9771
2023-05-31T09:46:57.0192176Z === RUN TestGlobalCheckpoint5
2023-05-31T09:46:57.0192567Z 2023/05/31 09:46:17.178895 +0000 INFO db/open.go:51 open-tae {"operation": "Start", "operand": "open"}
2023-05-31T09:46:57.0193103Z 2023/05/31 09:46:17.216812 +0000 INFO db/open.go:137 open-tae {"operation": "replay", "operand": "checkpoints", "cost": "56.402µs", "checkpointed": "0-0"}
2023-05-31T09:46:57.0193705Z 2023/05/31 09:46:17.217002 +0000 INFO batchstoredriver/store.go:278 open-tae {"operation": "replay", "operand": "wal", "backend": "batchstore", "apply cost": "0s", "read cost": "26.101µs"}
2023-05-31T09:46:57.0194178Z 2023/05/31 09:46:17.217174 +0000 INFO db/replay.go:90 open-tae {"operation": "replay", "operand": "wal", "apply logentries cost": "0s"}
2023-05-31T09:46:57.0194553Z 2023/05/31 09:46:17.217250 +0000 INFO txnbase/txnmgr.go:135 init ts to 0-0
2023-05-31T09:46:57.0194858Z 2023/05/31 09:46:17.217299 +0000 INFO txnbase/txnmgr.go:137 [INIT] {"txnmgr": {}}
2023-05-31T09:46:57.0195312Z 2023/05/31 09:46:17.217379 +0000 INFO db/open.go:145 open-tae {"operation": "replay", "operand": "wal", "cost": "436.814µs"}
2023-05-31T09:46:57.0195770Z 2023/05/31 09:46:17.217712 +0000 INFO db/open.go:62 open-tae {"operation": "End", "operand": "open", "cost": "38.72376ms", "err": null}
2023-05-31T09:46:57.0196041Z 2023/05/31 09:46:17.223120 +0000 WARN objectio/writer.go:437 table_id unmatched length, expect 0, get 3
2023-05-31T09:46:57.0196336Z 2023/05/31 09:46:17.223289 +0000 WARN objectio/writer.go:437 block_insert_batch_start unmatched length, expect 0, get 3
2023-05-31T09:46:57.0196627Z 2023/05/31 09:46:17.223525 +0000 WARN objectio/writer.go:437 block_insert_batch_end unmatched length, expect 0, get 3
2023-05-31T09:46:57.0196927Z 2023/05/31 09:46:17.223609 +0000 WARN objectio/writer.go:437 block_delete_batch_start unmatched length, expect 0, get 3
2023-05-31T09:46:57.0197238Z 2023/05/31 09:46:17.223815 +0000 WARN objectio/writer.go:437 block_delete_batch_end unmatched length, expect 0, get 3
2023-05-31T09:46:57.0197530Z 2023/05/31 09:46:17.223897 +0000 WARN objectio/writer.go:437 seg_delete_batch_start unmatched length, expect 0, get 3
2023-05-31T09:46:57.0197897Z 2023/05/31 09:46:17.223963 +0000 WARN objectio/writer.go:437 seg_delete_batch_end unmatched length, expect 0, get 3
2023-05-31T09:46:57.0198144Z 2023/05/31 09:46:17.230668 +0000 INFO gc/diskcleaner.go:118 JobFactory is start
2023-05-31T09:46:57.0198399Z 2023/05/31 09:46:17.231461 +0000 WARN objectio/writer.go:437 id unmatched length, expect 0, get 3
2023-05-31T09:46:57.0198665Z 2023/05/31 09:46:17.231651 +0000 WARN objectio/writer.go:437 create_at unmatched length, expect 0, get 3
2023-05-31T09:46:57.0198929Z 2023/05/31 09:46:17.231784 +0000 WARN objectio/writer.go:437 seg_node unmatched length, expect 0, get 3
2023-05-31T09:46:57.0199194Z 2023/05/31 09:46:17.232373 +0000 WARN objectio/writer.go:437 start_ts unmatched length, expect 0, get 3
2023-05-31T09:46:57.0199471Z 2023/05/31 09:46:17.232497 +0000 WARN objectio/writer.go:437 prepare_ts unmatched length, expect 0, get 3
2023-05-31T09:46:57.0199752Z 2023/05/31 09:46:17.232576 +0000 WARN objectio/writer.go:437 commit_ts unmatched length, expect 0, get 3
2023-05-31T09:46:57.0200015Z 2023/05/31 09:46:17.232865 +0000 WARN objectio/writer.go:437 db_id unmatched length, expect 0, get 3
2023-05-31T09:46:57.0200280Z 2023/05/31 09:46:17.233110 +0000 WARN objectio/writer.go:437 table_id unmatched length, expect 0, get 3
2023-05-31T09:46:57.0200539Z 2023/05/31 09:46:17.237482 +0000 WARN objectio/writer.go:437 start_ts unmatched length, expect 0, get 3
2023-05-31T09:46:57.0200808Z 2023/05/31 09:46:17.237624 +0000 WARN objectio/writer.go:437 prepare_ts unmatched length, expect 0, get 3
2023-05-31T09:46:57.0201075Z 2023/05/31 09:46:17.237716 +0000 WARN objectio/writer.go:437 commit_ts unmatched length, expect 0, get 3
2023-05-31T09:46:57.0201339Z 2023/05/31 09:46:17.238066 +0000 WARN objectio/writer.go:437 db_id unmatched length, expect 0, get 3
2023-05-31T09:46:57.0201692Z 2023/05/31 09:46:17.238187 +0000 WARN objectio/writer.go:437 table_id unmatched length, expect 0, get 3
2023-05-31T09:46:57.0201984Z 2023/05/31 09:46:17.238422 +0000 WARN objectio/writer.go:437 %!%mo__meta_loc unmatched length, expect 0, get 3
2023-05-31T09:46:57.0202251Z 2023/05/31 09:46:17.238569 +0000 WARN objectio/writer.go:437 delta_loc unmatched length, expect 0, get 3
2023-05-31T09:46:57.0202733Z 2023/05/31 09:46:17.239278 +0000 WARN logtail/table.go:200 [logtail] fetch with too small ts {"ts": "1685526377230447326-1", "minTs": "0-0"}
2023-05-31T09:46:57.0202961Z 2023/05/31 09:46:17.240651 +0000 INFO gc/diskcleaner.go:118 JobFactory is start
2023-05-31T09:46:57.0203665Z 2023/05/31 09:46:17.246270 +0000 INFO blockio/writer.go:156 [WriteEnd] {"operation": "name: fd3e7afe-ff97-11ed-8fdf-00224809a69b_00000, block count: 24, size: 7342", "operand": [], "operand": 0}
2023-05-31T09:46:57.0204206Z 2023/05/31 09:46:17.249315 +0000 WARN logtail/table.go:200 [logtail] fetch with too small ts {"ts": "1685526377239216811-1", "minTs": "0-0"}
2023-05-31T09:46:57.0204433Z 2023/05/31 09:46:17.250786 +0000 INFO gc/diskcleaner.go:118 JobFactory is start
2023-05-31T09:46:57.0204879Z 2023/05/31 09:46:17.252251 +0000 INFO checkpoint/testutils.go:159 CKP[I]2 is done, takes 30.176882ms
2023-05-31T09:46:57.0205382Z 2023/05/31 09:46:17.259444 +0000 WARN logtail/table.go:200 [logtail] fetch with too small ts {"ts": "1685526377249279439-1", "minTs": "1685526377254584311-0"}
2023-05-31T09:46:57.0205650Z 2023/05/31 09:46:17.261242 +0000 WARN objectio/writer.go:437 table_id unmatched length, expect 0, get 3
2023-05-31T09:46:57.0205944Z 2023/05/31 09:46:17.261425 +0000 WARN objectio/writer.go:437 block_insert_batch_start unmatched length, expect 0, get 3
2023-05-31T09:46:57.0206239Z 2023/05/31 09:46:17.261553 +0000 WARN objectio/writer.go:437 block_insert_batch_end unmatched length, expect 0, get 3
2023-05-31T09:46:57.0206535Z 2023/05/31 09:46:17.261782 +0000 WARN objectio/writer.go:437 block_delete_batch_start unmatched length, expect 0, get 3
2023-05-31T09:46:57.0206830Z 2023/05/31 09:46:17.261870 +0000 WARN objectio/writer.go:437 block_delete_batch_end unmatched length, expect 0, get 3
2023-05-31T09:46:57.0207194Z 2023/05/31 09:46:17.261943 +0000 WARN objectio/writer.go:437 seg_delete_batch_start unmatched length, expect 0, get 3
2023-05-31T09:46:57.0207515Z 2023/05/31 09:46:17.262009 +0000 WARN objectio/writer.go:437 seg_delete_batch_end unmatched length, expect 0, get 3
2023-05-31T09:46:57.0207763Z 2023/05/31 09:46:17.282679 +0000 INFO db/scannerop.go:376 Mergeblocks available mem: 5g
2023-05-31T09:46:57.0208248Z 2023/05/31 09:46:17.283077 +0000 INFO jobs/compactblk.go:146 [Start] {"operation": "[1978]compact", "operand": "[A]BLK[<1000-1000-1-0>]"}
2023-05-31T09:46:57.0208467Z db_test.go:6176: CATALOG[CNT=2]
2023-05-31T09:46:57.0208903Z DB -> [1-0,1-0,1-0][C@1-0,D@0-0][name=0-mo_catalog]
2023-05-31T09:46:57.0209445Z TBL -> [1-0,1-0,1-0][C@1-0,D@0-0]schema.v0.s9.c9[name=mo_database]
2023-05-31T09:46:57.0210209Z [A-US/0/0]SEG[65000000-0000-0000-0000-000000000000] -> [1-0,1-0,1-0][C@1-0,D@0-0][MetaLoc="",DeltaLoc=""]
2023-05-31T09:46:57.0210992Z [A]BLK[65000000-0000-0000-0000-000000000000-0-0] -> [1-0,1-0,1-0][C@1-0,D@0-0][MetaLoc="",DeltaLoc=""]
2023-05-31T09:46:57.0211532Z TBL -> [1-0,1-0,1-0][C@1-0,D@0-0]schema.v0.s17.c17[name=mo_tables]
2023-05-31T09:46:57.0212357Z [A-US/0/0]SEG[66000000-0000-0000-0000-000000000000] -> [1-0,1-0,1-0][C@1-0,D@0-0][MetaLoc="",DeltaLoc=""]
2023-05-31T09:46:57.0213144Z [A]BLK[66000000-0000-0000-0000-000000000000-0-0] -> [1-0,1-0,1-0][C@1-0,D@0-0][MetaLoc="",DeltaLoc=""]
2023-05-31T09:46:57.0213688Z TBL -> [1-0,1-0,1-0][C@1-0,D@0-0]schema.v0.s23.c23[name=mo_columns]
2023-05-31T09:46:57.0214449Z [A-US/0/0]SEG[67000000-0000-0000-0000-000000000000] -> [1-0,1-0,1-0][C@1-0,D@0-0][MetaLoc="",DeltaLoc=""]
2023-05-31T09:46:57.0215229Z [A]BLK[67000000-0000-0000-0000-000000000000-0-0] -> [1-0,1-0,1-0][C@1-0,D@0-0][MetaLoc="",DeltaLoc=""]
2023-05-31T09:46:57.0216055Z DB -> [1685526377253315570-0,1685526377254599912-0,1685526377254599912-0][C@1685526377254599912-0,D@0-0][name=0-db]
2023-05-31T09:46:57.0217143Z TBL -> [1685526377253315570-0,1685526377254599912-0,1685526377254599912-0][C@1685526377254599912-0,D@0-0]schema.v0.s18.c19[name=2023-05-31 09:46:17.217792314 +0000 UTC m=+41.951133971]
2023-05-31T09:46:57.0218287Z [A-US/1000/2]SEG[fd434871-ff97-11ed-8fdf-00224809a69b] -> [1685526377253315570-0,1685526377254599912-0,1685526377254599912-0][C@1685526377254599912-0,D@0-0][MetaLoc="",DeltaLoc=""]
2023-05-31T09:46:57.0219552Z [A]BLK[fd434871-ff97-11ed-8fdf-00224809a69b-0-0] -> [1685526377253315570-0,1685526377254599912-0,1685526377254599912-0][C@1685526377254599912-0,D@0-0][MetaLoc="",DeltaLoc=""]
2023-05-31T09:46:57.0220804Z [A]BLK[fd434871-ff97-11ed-8fdf-00224809a69b-1-0] -> [1685526377253315570-0,1685526377254599912-0,1685526377254599912-0][C@1685526377254599912-0,D@0-0][MetaLoc="",DeltaLoc=""]
2023-05-31T09:46:57.0221964Z [A-US/1001/2]SEG[fd448bbc-ff97-11ed-8fdf-00224809a69b] -> [1685526377257861118-0,1685526377262833580-0,1685526377262833580-0][C@1685526377262833580-0,D@0-0][MetaLoc="",DeltaLoc=""]
2023-05-31T09:46:57.0223145Z [A]BLK[fd448bbc-ff97-11ed-8fdf-00224809a69b-0-0] -> [1685526377257861118-0,1685526377262833580-0,1685526377262833580-0][C@1685526377262833580-0,D@0-0][MetaLoc="",DeltaLoc=""]
2023-05-31T09:46:57.0224497Z [A]BLK[fd448bbc-ff97-11ed-8fdf-00224809a69b-1-0] -> [1685526377257861118-0,1685526377262833580-0,1685526377262833580-0][C@1685526377262833580-0,D@0-0][MetaLoc="",DeltaLoc=""]
2023-05-31T09:46:57.0224776Z 2023/05/31 09:46:17.284143 +0000 WARN objectio/writer.go:437 id unmatched length, expect 0, get 3
2023-05-31T09:46:57.0225074Z 2023/05/31 09:46:17.287343 +0000 WARN objectio/writer.go:437 create_at unmatched length, expect 0, get 3
2023-05-31T09:46:57.0225346Z 2023/05/31 09:46:17.287508 +0000 WARN objectio/writer.go:437 seg_node unmatched length, expect 0, get 3
2023-05-31T09:46:57.0225739Z 2023/05/31 09:46:17.287791 +0000 WARN objectio/writer.go:437 start_ts unmatched length, expect 0, get 3
2023-05-31T09:46:57.0226032Z 2023/05/31 09:46:17.287907 +0000 WARN objectio/writer.go:437 prepare_ts unmatched length, expect 0, get 3
2023-05-31T09:46:57.0226300Z 2023/05/31 09:46:17.288011 +0000 WARN objectio/writer.go:437 commit_ts unmatched length, expect 0, get 3
2023-05-31T09:46:57.0226562Z 2023/05/31 09:46:17.288166 +0000 WARN objectio/writer.go:437 db_id unmatched length, expect 0, get 3
2023-05-31T09:46:57.0226828Z 2023/05/31 09:46:17.288296 +0000 WARN objectio/writer.go:437 table_id unmatched length, expect 0, get 3
2023-05-31T09:46:57.0227566Z 2023/05/31 09:46:17.291454 +0000 INFO blockio/writer.go:156 [WriteEnd] {"operation": "name: fd434871-ff97-11ed-8fdf-00224809a69b_00002, block count: 1, size: 1723", "operand": [0, 1, 2, 3, 4, 5, 6, 7, 8, 9, 10, 11, 12, 13, 14, 15, 16, 17], "operand": 17}
2023-05-31T09:46:57.0227921Z 2023/05/31 09:46:17.291805 +0000 INFO gc/manager.go:152 gc-loop is going to exit
2023-05-31T09:46:57.0228389Z 2023/05/31 09:46:17.292255 +0000 INFO jobs/compactblk.go:146 [Start] {"operation": "[1980]compact", "operand": "[A]BLK[<1000-1000-0-0>]"}
2023-05-31T09:46:57.0228836Z 2023/05/31 09:46:17.293126 +0000 INFO jobs/compactblk.go:338 update metaloc for fd434871-ff97-11ed-8fdf-00224809a69b-2-0
2023-05-31T09:46:57.0229069Z 2023/05/31 09:46:17.293426 +0000 INFO gc/diskcleaner.go:118 JobFactory is start
2023-05-31T09:46:57.0229465Z 2023/05/31 09:46:17.293528 +0000 INFO logtail/mgr.go:185 [logtail] GC {"ts": "1685526377220597305-0", "deleted": 0}
2023-05-31T09:46:57.0229682Z 2023/05/31 09:46:17.300433 +0000 INFO db/scanner.go:55 DBScanner Stopped
2023-05-31T09:46:57.0230231Z 2023/05/31 09:46:17.307066 +0000 WARN checkpoint/runner.go:693 Block BLK<1000-1000-fd434871-ff97-11ed-8fdf-00224809a69b-0-0> Mutation Info: Changes=0/10:
2023-05-31T09:46:57.0230906Z 2023/05/31 09:46:17.307323 +0000 WARN checkpoint/runner.go:693 Block BLK<1000-1000-fd434871-ff97-11ed-8fdf-00224809a69b-1-0> Mutation Info: Changes=0/10:
2023-05-31T09:46:57.0231195Z 2023/05/31 09:46:17.314649 +0000 WARN objectio/writer.go:437 start_ts unmatched length, expect 0, get 3
2023-05-31T09:46:57.0231465Z 2023/05/31 09:46:17.314853 +0000 WARN objectio/writer.go:437 prepare_ts unmatched length, expect 0, get 3
2023-05-31T09:46:57.0231732Z 2023/05/31 09:46:17.314978 +0000 WARN objectio/writer.go:437 commit_ts unmatched length, expect 0, get 3
2023-05-31T09:46:57.0231991Z 2023/05/31 09:46:17.315379 +0000 WARN objectio/writer.go:437 db_id unmatched length, expect 0, get 3
2023-05-31T09:46:57.0232252Z 2023/05/31 09:46:17.315558 +0000 WARN objectio/writer.go:437 table_id unmatched length, expect 0, get 3
2023-05-31T09:46:57.0232614Z 2023/05/31 09:46:17.315718 +0000 WARN objectio/writer.go:437 %!%mo__meta_loc unmatched length, expect 0, get 3
2023-05-31T09:46:57.0232961Z 2023/05/31 09:46:17.315900 +0000 WARN objectio/writer.go:437 delta_loc unmatched length, expect 0, get 3
2023-05-31T09:46:57.0233688Z 2023/05/31 09:46:17.322664 +0000 INFO blockio/writer.go:156 [WriteEnd] {"operation": "name: fd434871-ff97-11ed-8fdf-00224809a69b_00003, block count: 1, size: 1691", "operand": [0, 1, 2, 3, 4, 5, 6, 7, 8, 9, 10, 11, 12, 13, 14, 15, 16, 17], "operand": 17}
2023-05-31T09:46:57.0234153Z 2023/05/31 09:46:17.322826 +0000 INFO jobs/compactblk.go:338 update metaloc for fd434871-ff97-11ed-8fdf-00224809a69b-3-0
2023-05-31T09:46:57.0234620Z 2023/05/31 09:46:17.323300 +0000 INFO jobs/compactblk.go:146 [Start] {"operation": "[1986]compact", "operand": "[A]BLK[<1000-1000-1-0>]"}
2023-05-31T09:46:57.0235082Z 2023/05/31 09:46:17.324331 +0000 INFO jobs/compactblk.go:146 [Start] {"operation": "[1988]compact", "operand": "[A]BLK[<1000-1000-0-0>]"}
2023-05-31T09:46:57.0235698Z 2023/05/31 09:46:17.337068 +0000 INFO blockio/writer.go:156 [WriteEnd] {"operation": "name: fd444de5-ff97-11ed-8fdf-00224809a69b_00000, block count: 24, size: 7342", "operand": [], "operand": 0}
2023-05-31T09:46:57.0236136Z 2023/05/31 09:46:17.343942 +0000 INFO checkpoint/runner.go:293 CKP[G]2 is done, takes 83.782127ms
2023-05-31T09:46:57.0236478Z 2023/05/31 09:46:17.345133 +0000 WARN objectio/writer.go:437 table_id unmatched length, expect 0, get 3
2023-05-31T09:46:57.0236784Z 2023/05/31 09:46:17.345260 +0000 WARN objectio/writer.go:437 block_insert_batch_start unmatched length, expect 0, get 3
2023-05-31T09:46:57.0237089Z 2023/05/31 09:46:17.345493 +0000 WARN objectio/writer.go:437 block_insert_batch_end unmatched length, expect 0, get 3
2023-05-31T09:46:57.0237383Z 2023/05/31 09:46:17.345570 +0000 WARN objectio/writer.go:437 block_delete_batch_start unmatched length, expect 0, get 3
2023-05-31T09:46:57.0237677Z 2023/05/31 09:46:17.345783 +0000 WARN objectio/writer.go:437 block_delete_batch_end unmatched length, expect 0, get 3
2023-05-31T09:46:57.0237965Z 2023/05/31 09:46:17.345871 +0000 WARN objectio/writer.go:437 seg_delete_batch_start unmatched length, expect 0, get 3
2023-05-31T09:46:57.0238251Z 2023/05/31 09:46:17.345937 +0000 WARN objectio/writer.go:437 seg_delete_batch_end unmatched length, expect 0, get 3
2023-05-31T09:46:57.0238996Z 2023/05/31 09:46:17.367443 +0000 INFO blockio/writer.go:156 [WriteEnd] {"operation": "name: fd434871-ff97-11ed-8fdf-00224809a69b_00001, block count: 1, size: 1918", "operand": [0, 1, 2, 3, 4, 5, 6, 7, 8, 9, 10, 11, 12, 13, 14, 15, 16, 17, 18, 19, 20], "operand": 17}
2023-05-31T09:46:57.0239794Z 2023/05/31 09:46:17.367763 +0000 INFO jobs/compactblk.go:289 [Done] {"txn-start-ts": "1685526377282932434-0", "operation": "[1978]compact", "compacted": "[A]BLK[<1000-1000-1-0>]", "created": "BLK<1000-1000-fd434871-ff97-11ed-8fdf-00224809a69b-2-0>", "duration": "84.610654ms"}
2023-05-31T09:46:57.0240073Z 2023/05/31 09:46:17.409498 +0000 WARN objectio/writer.go:437 id unmatched length, expect 0, get 3
2023-05-31T09:46:57.0240344Z 2023/05/31 09:46:17.409810 +0000 WARN objectio/writer.go:437 create_at unmatched length, expect 0, get 3
2023-05-31T09:46:57.0240704Z 2023/05/31 09:46:17.410035 +0000 WARN objectio/writer.go:437 seg_node unmatched length, expect 0, get 3
2023-05-31T09:46:57.0240970Z 2023/05/31 09:46:17.410487 +0000 WARN objectio/writer.go:437 start_ts unmatched length, expect 0, get 3
2023-05-31T09:46:57.0241240Z 2023/05/31 09:46:17.410695 +0000 WARN objectio/writer.go:437 prepare_ts unmatched length, expect 0, get 3
2023-05-31T09:46:57.0241711Z 2023/05/31 09:46:17.410933 +0000 INFO tables/mnode.go:70 Releasing Memorynode BLK-fd434871-ff97-11ed-8fdf-00224809a69b-1-0
2023-05-31T09:46:57.0241978Z 2023/05/31 09:46:17.411071 +0000 WARN objectio/writer.go:437 commit_ts unmatched length, expect 0, get 3
2023-05-31T09:46:57.0242315Z 2023/05/31 09:46:17.411273 +0000 WARN objectio/writer.go:437 db_id unmatched length, expect 0, get 3
2023-05-31T09:46:57.0242613Z 2023/05/31 09:46:17.411479 +0000 WARN objectio/writer.go:437 table_id unmatched length, expect 0, get 3
2023-05-31T09:46:57.0243434Z 2023/05/31 09:46:17.410657 +0000 INFO blockio/writer.go:156 [WriteEnd] {"operation": "name: fd434871-ff97-11ed-8fdf-00224809a69b_00000, block count: 1, size: 1885", "operand": [0, 1, 2, 3, 4, 5, 6, 7, 8, 9, 10, 11, 12, 13, 14, 15, 16, 17, 18, 19, 20], "operand": 17}
2023-05-31T09:46:57.0247601Z 2023/05/31 09:46:17.419985 +0000 INFO jobs/compactblk.go:289 [Done] {"txn-start-ts": "1685526377292123133-0", "operation": "[1980]compact", "compacted": "[A]BLK[<1000-1000-0-0>]", "created": "BLK<1000-1000-fd434871-ff97-11ed-8fdf-00224809a69b-3-0>", "duration": "127.649455ms"}
2023-05-31T09:46:57.0248182Z 2023/05/31 09:46:17.422438 +0000 INFO tables/mnode.go:70 Releasing Memorynode BLK-fd434871-ff97-11ed-8fdf-00224809a69b-0-0
2023-05-31T09:46:57.0248915Z 2023/05/31 09:46:17.423205 +0000 INFO blockio/writer.go:156 [WriteEnd] {"operation": "name: fd448bbc-ff97-11ed-8fdf-00224809a69b_00003, block count: 1, size: 1710", "operand": [0, 1, 2, 3, 4, 5, 6, 7, 8, 9, 10, 11, 12, 13, 14, 15, 16, 17], "operand": 17}
2023-05-31T09:46:57.0249191Z 2023/05/31 09:46:17.427197 +0000 WARN objectio/writer.go:437 start_ts unmatched length, expect 0, get 3
2023-05-31T09:46:57.0249663Z 2023/05/31 09:46:17.427359 +0000 WARN objectio/writer.go:437 prepare_ts unmatched length, expect 0, get 3
2023-05-31T09:46:57.0249958Z 2023/05/31 09:46:17.427632 +0000 WARN objectio/writer.go:437 commit_ts unmatched length, expect 0, get 3
2023-05-31T09:46:57.0250216Z 2023/05/31 09:46:17.427893 +0000 WARN objectio/writer.go:437 db_id unmatched length, expect 0, get 3
2023-05-31T09:46:57.0250479Z 2023/05/31 09:46:17.428175 +0000 WARN objectio/writer.go:437 table_id unmatched length, expect 0, get 3
2023-05-31T09:46:57.0250755Z 2023/05/31 09:46:17.428318 +0000 WARN objectio/writer.go:437 %!%mo__meta_loc unmatched length, expect 0, get 3
2023-05-31T09:46:57.0251023Z 2023/05/31 09:46:17.428470 +0000 WARN objectio/writer.go:437 delta_loc unmatched length, expect 0, get 3
2023-05-31T09:46:57.0251764Z 2023/05/31 09:46:17.433710 +0000 INFO blockio/writer.go:156 [WriteEnd] {"operation": "name: fd448bbc-ff97-11ed-8fdf-00224809a69b_00002, block count: 1, size: 1722", "operand": [0, 1, 2, 3, 4, 5, 6, 7, 8, 9, 10, 11, 12, 13, 14, 15, 16, 17], "operand": 17}
2023-05-31T09:46:57.0252230Z 2023/05/31 09:46:17.433879 +0000 INFO jobs/compactblk.go:338 update metaloc for fd448bbc-ff97-11ed-8fdf-00224809a69b-3-0
2023-05-31T09:46:57.0252705Z 2023/05/31 09:46:17.434242 +0000 INFO jobs/compactblk.go:338 update metaloc for fd448bbc-ff97-11ed-8fdf-00224809a69b-2-0
2023-05-31T09:46:57.0253440Z 2023/05/31 09:46:17.444448 +0000 INFO blockio/writer.go:156 [WriteEnd] {"operation": "name: fd448bbc-ff97-11ed-8fdf-00224809a69b_00000, block count: 1, size: 1904", "operand": [0, 1, 2, 3, 4, 5, 6, 7, 8, 9, 10, 11, 12, 13, 14, 15, 16, 17, 18, 19, 20], "operand": 17}
2023-05-31T09:46:57.0254044Z 2023/05/31 09:46:17.445347 +0000 INFO blockio/writer.go:156 [WriteEnd] {"operation": "name: fd512045-ff97-11ed-8fdf-00224809a69b_00000, block count: 24, size: 7344", "operand": [], "operand": 0}
2023-05-31T09:46:57.0254600Z 2023/05/31 09:46:17.453428 +0000 INFO checkpoint/runner.go:293 CKP[G]2 is done, takes 109.37166ms
2023-05-31T09:46:57.0255403Z 2023/05/31 09:46:17.456037 +0000 INFO jobs/compactblk.go:289 [Done] {"txn-start-ts": "1685526377324225678-0", "operation": "[1988]compact", "compacted": "[A]BLK[<1000-1000-0-0>]", "created": "BLK<1000-1000-fd448bbc-ff97-11ed-8fdf-00224809a69b-3-0>", "duration": "131.633184ms"}
2023-05-31T09:46:57.0255869Z 2023/05/31 09:46:17.457587 +0000 INFO tables/mnode.go:70 Releasing Memorynode BLK-fd448bbc-ff97-11ed-8fdf-00224809a69b-0-0
2023-05-31T09:46:57.0256695Z 2023/05/31 09:46:17.459740 +0000 INFO blockio/writer.go:156 [WriteEnd] {"operation": "name: fd448bbc-ff97-11ed-8fdf-00224809a69b_00001, block count: 1, size: 1917", "operand": [0, 1, 2, 3, 4, 5, 6, 7, 8, 9, 10, 11, 12, 13, 14, 15, 16, 17, 18, 19, 20], "operand": 17}
2023-05-31T09:46:57.0257585Z 2023/05/31 09:46:17.460148 +0000 INFO jobs/compactblk.go:289 [Done] {"txn-start-ts": "1685526377323168344-0", "operation": "[1986]compact", "compacted": "[A]BLK[<1000-1000-1-0>]", "created": "BLK<1000-1000-fd448bbc-ff97-11ed-8fdf-00224809a69b-2-0>", "duration": "136.767951ms"}
2023-05-31T09:46:57.0258056Z 2023/05/31 09:46:17.461917 +0000 INFO tables/mnode.go:70 Releasing Memorynode BLK-fd448bbc-ff97-11ed-8fdf-00224809a69b-1-0
2023-05-31T09:46:57.0258287Z 2023/05/31 09:46:17.462399 +0000 INFO db/scheduler.go:83 TaskScheduler Stopped
2023-05-31T09:46:57.0258507Z 2023/05/31 09:46:17.462513 +0000 INFO txnbase/txnmgr.go:567 [Stop] {"txnmgr": {}}
2023-05-31T09:46:57.0258888Z 2023/05/31 09:46:17.462978 +0000 INFO db/open.go:51 open-tae {"operation": "Start", "operand": "open"}
2023-05-31T09:46:57.0259303Z 2023/05/31 09:46:17.518306 +0000 INFO checkpoint/replay.go:170 replay checkpoint CKP[G]2
2023-05-31T09:46:57.0259891Z 2023/05/31 09:46:17.518539 +0000 INFO checkpoint/replay.go:205 open-tae {"operation": "replay", "operand": "checkpoint", "apply cost": "274.008µs", "read cost": "43.239208ms"}
2023-05-31T09:46:57.0260446Z 2023/05/31 09:46:17.546456 +0000 INFO db/open.go:137 open-tae {"operation": "replay", "operand": "checkpoints", "cost": "73.080779ms", "checkpointed": "1685526377220597305-1"}
2023-05-31T09:46:57.0261156Z 2023/05/31 09:46:17.562144 +0000 INFO batchstoredriver/store.go:278 open-tae {"operation": "replay", "operand": "wal", "backend": "batchstore", "apply cost": "10.384538ms", "read cost": "2.472279ms"}
2023-05-31T09:46:57.0261665Z 2023/05/31 09:46:17.562725 +0000 INFO db/replay.go:90 open-tae {"operation": "replay", "operand": "wal", "apply logentries cost": "6.111299ms"}
2023-05-31T09:46:57.0261957Z 2023/05/31 09:46:17.562950 +0000 INFO txnbase/txnmgr.go:135 init ts to 1685526377460499114-0
2023-05-31T09:46:57.0262180Z 2023/05/31 09:46:17.563240 +0000 INFO txnbase/txnmgr.go:137 [INIT] {"txnmgr": {}}
2023-05-31T09:46:57.0262615Z 2023/05/31 09:46:17.563670 +0000 INFO db/open.go:145 open-tae {"operation": "replay", "operand": "wal", "cost": "17.084856ms"}
2023-05-31T09:46:57.0263112Z 2023/05/31 09:46:17.575914 +0000 WARN logtail/table.go:200 [logtail] fetch with too small ts {"ts": "1685526377220597305-2", "minTs": "1685526377254599912-0"}
2023-05-31T09:46:57.0263780Z 2023/05/31 09:46:17.579309 +0000 INFO tables/mnode.go:70 Releasing Memorynode BLK-fd434871-ff97-11ed-8fdf-00224809a69b-0-0
2023-05-31T09:46:57.0264853Z 2023/05/31 09:46:17.579550 +0000 INFO tables/mnode.go:70 Releasing Memorynode BLK-fd434871-ff97-11ed-8fdf-00224809a69b-1-0
2023-05-31T09:46:57.0265397Z 2023/05/31 09:46:17.579797 +0000 INFO tables/mnode.go:70 Releasing Memorynode BLK-fd448bbc-ff97-11ed-8fdf-00224809a69b-0-0
2023-05-31T09:46:57.0265861Z 2023/05/31 09:46:17.580031 +0000 INFO tables/mnode.go:70 Releasing Memorynode BLK-fd448bbc-ff97-11ed-8fdf-00224809a69b-1-0
2023-05-31T09:46:57.0266331Z 2023/05/31 09:46:17.580461 +0000 INFO db/open.go:62 open-tae {"operation": "End", "operand": "open", "cost": "117.402121ms", "err": null}
2023-05-31T09:46:57.0266822Z 2023/05/31 09:46:17.580686 +0000 WARN logtail/table.go:200 [logtail] fetch with too small ts {"ts": "1685526377220597305-1", "minTs": "1685526377254599912-0"}
2023-05-31T09:46:57.0267259Z 2023/05/31 09:46:17.581366 +0000 INFO gc/diskcleaner.go:118 JobFactory is start
2023-05-31T09:46:57.0267589Z 2023/05/31 09:46:17.585805 +0000 INFO catalog/catalog.go:142 GC Catalog 1685526377220597305-0
2023-05-31T09:46:57.0267887Z 2023/05/31 09:46:17.585959 +0000 INFO catalog/catalog.go:142 GC Catalog 1685526377220597305-0
2023-05-31T09:46:57.0268105Z db_test.go:6180: CATALOG[CNT=2]
2023-05-31T09:46:57.0268539Z DB -> [1-0,1-0,1-0][C@1-0,D@0-0][name=0-mo_catalog]
2023-05-31T09:46:57.0269079Z TBL -> [1-0,1-0,1-0][C@1-0,D@0-0]schema.v0.s9.c9[name=mo_database]
2023-05-31T09:46:57.0269935Z [A-US/0/0]SEG[65000000-0000-0000-0000-000000000000] -> [1-0,1-0,1-0][C@1-0,D@0-0][MetaLoc="",DeltaLoc=""]
2023-05-31T09:46:57.0270806Z [A]BLK[65000000-0000-0000-0000-000000000000-0-0] -> [1-0,1-0,1-0][C@1-0,D@0-0][MetaLoc="",DeltaLoc=""]
2023-05-31T09:46:57.0271348Z TBL -> [1-0,1-0,1-0][C@1-0,D@0-0]schema.v0.s17.c17[name=mo_tables]
2023-05-31T09:46:57.0272109Z [A-US/0/0]SEG[66000000-0000-0000-0000-000000000000] -> [1-0,1-0,1-0][C@1-0,D@0-0][MetaLoc="",DeltaLoc=""]
2023-05-31T09:46:57.0274242Z [A]BLK[66000000-0000-0000-0000-000000000000-0-0] -> [1-0,1-0,1-0][C@1-0,D@0-0][MetaLoc="",DeltaLoc=""]
2023-05-31T09:46:57.0274862Z TBL -> [1-0,1-0,1-0][C@1-0,D@0-0]schema.v0.s23.c23[name=mo_columns]
2023-05-31T09:46:57.0275623Z [A-US/0/0]SEG[67000000-0000-0000-0000-000000000000] -> [1-0,1-0,1-0][C@1-0,D@0-0][MetaLoc="",DeltaLoc=""]
2023-05-31T09:46:57.0276397Z [A]BLK[67000000-0000-0000-0000-000000000000-0-0] -> [1-0,1-0,1-0][C@1-0,D@0-0][MetaLoc="",DeltaLoc=""]
2023-05-31T09:46:57.0277112Z DB -> [1685526377253315570-0,1685526377254599912-0,1685526377254599912-0][C@1685526377254599912-0,D@0-0][name=0-db]
2023-05-31T09:46:57.0278208Z TBL -> [1685526377253315570-0,1685526377254599912-0,1685526377254599912-0][C@1685526377254599912-0,D@0-0]schema.v0.s18.c19[name=2023-05-31 09:46:17.217792314 +0000 UTC m=+41.951133971]
2023-05-31T09:46:57.0279553Z [A-US/1000/4]SEG[fd434871-ff97-11ed-8fdf-00224809a69b] -> [1685526377253315570-0,1685526377254599912-0,1685526377254599912-0][C@1685526377254599912-0,D@0-0][MetaLoc="",DeltaLoc=""]
2023-05-31T09:46:57.0281904Z [A]BLK[fd434871-ff97-11ed-8fdf-00224809a69b-0-0] -> [1685526377292123133-0,1685526377420528513-0,1685526377420528513-0][C@1685526377254599912-0,D@1685526377420528513-0][MetaLoc="fd434871-ff97-11ed-8fdf-00224809a69b_00000_1_2566_1087_5582_10_0",DeltaLoc=""] -> [1685526377253315570-0,1685526377254599912-0,1685526377254599912-0][C@1685526377254599912-0,D@0-0][MetaLoc="",DeltaLoc=""]
2023-05-31T09:46:57.0284208Z [A]BLK[fd434871-ff97-11ed-8fdf-00224809a69b-1-0] -> [1685526377282932434-0,1685526377368102406-0,1685526377368102406-0][C@1685526377254599912-0,D@1685526377368102406-0][MetaLoc="fd434871-ff97-11ed-8fdf-00224809a69b_00001_1_2593_1100_5582_10_0",DeltaLoc=""] -> [1685526377253315570-0,1685526377254599912-0,1685526377254599912-0][C@1685526377254599912-0,D@0-0][MetaLoc="",DeltaLoc=""]
2023-05-31T09:46:57.0285765Z [NA]BLK[fd434871-ff97-11ed-8fdf-00224809a69b-2-0] -> [1685526377282932434-0,1685526377368102406-0,1685526377368102406-0][C@1685526377368102406-0,D@0-0][MetaLoc="fd434871-ff97-11ed-8fdf-00224809a69b_00002_1_2388_1025_4838_10_0",DeltaLoc=""]
2023-05-31T09:46:57.0287310Z [NA]BLK[fd434871-ff97-11ed-8fdf-00224809a69b-3-0] -> [1685526377292123133-0,1685526377420528513-0,1685526377420528513-0][C@1685526377420528513-0,D@0-0][MetaLoc="fd434871-ff97-11ed-8fdf-00224809a69b_00003_1_2354_1015_4838_10_0",DeltaLoc=""]
2023-05-31T09:46:57.0288461Z [A-US/1001/4]SEG[fd448bbc-ff97-11ed-8fdf-00224809a69b] -> [1685526377257861118-0,1685526377262833580-0,1685526377262833580-0][C@1685526377262833580-0,D@0-0][MetaLoc="",DeltaLoc=""]
2023-05-31T09:46:57.0290913Z [A]BLK[fd448bbc-ff97-11ed-8fdf-00224809a69b-0-0] -> [1685526377324225678-0,1685526377456315777-0,1685526377456315777-0][C@1685526377262833580-0,D@1685526377456315777-0][MetaLoc="fd448bbc-ff97-11ed-8fdf-00224809a69b_00000_1_2584_1096_5582_10_0",DeltaLoc=""] -> [1685526377257861118-0,1685526377262833580-0,1685526377262833580-0][C@1685526377262833580-0,D@0-0][MetaLoc="",DeltaLoc=""]
2023-05-31T09:46:57.0293225Z [A]BLK[fd448bbc-ff97-11ed-8fdf-00224809a69b-1-0] -> [1685526377323168344-0,1685526377460499114-0,1685526377460499114-0][C@1685526377262833580-0,D@1685526377460499114-0][MetaLoc="fd448bbc-ff97-11ed-8fdf-00224809a69b_00001_1_2604_1105_5582_10_0",DeltaLoc=""] -> [1685526377257861118-0,1685526377262833580-0,1685526377262833580-0][C@1685526377262833580-0,D@0-0][MetaLoc="",DeltaLoc=""]
2023-05-31T09:46:57.0294860Z [NA]BLK[fd448bbc-ff97-11ed-8fdf-00224809a69b-2-0] -> [1685526377323168344-0,1685526377460499114-0,1685526377460499114-0][C@1685526377460499114-0,D@0-0][MetaLoc="fd448bbc-ff97-11ed-8fdf-00224809a69b_00002_1_2396_1031_4838_10_0",DeltaLoc=""]
2023-05-31T09:46:57.0296510Z [NA]BLK[fd448bbc-ff97-11ed-8fdf-00224809a69b-3-0] -> [1685526377324225678-0,1685526377456315777-0,1685526377456315777-0][C@1685526377456315777-0,D@0-0][MetaLoc="fd448bbc-ff97-11ed-8fdf-00224809a69b_00003_1_2381_1020_4838_10_0",DeltaLoc=""]
2023-05-31T09:46:57.0296823Z 2023/05/31 09:46:17.587883 +0000 INFO catalog/catalog.go:142 GC Catalog 1685526377220597305-0
2023-05-31T09:46:57.0297137Z 2023/05/31 09:46:17.591941 +0000 INFO catalog/catalog.go:142 GC Catalog 1685526377220597305-0
2023-05-31T09:46:57.0297367Z 2023/05/31 09:46:17.592152 +0000 INFO gc/diskcleaner.go:118 JobFactory is start
2023-05-31T09:46:57.0297661Z 2023/05/31 09:46:17.593702 +0000 INFO catalog/catalog.go:142 GC Catalog 1685526377220597305-0
2023-05-31T09:46:57.0297961Z 2023/05/31 09:46:17.595342 +0000 INFO catalog/catalog.go:142 GC Catalog 1685526377220597305-0
2023-05-31T09:46:57.0298254Z 2023/05/31 09:46:17.599457 +0000 INFO catalog/catalog.go:142 GC Catalog 1685526377220597305-0
2023-05-31T09:46:57.0298547Z 2023/05/31 09:46:17.601747 +0000 INFO catalog/catalog.go:142 GC Catalog 1685526377220597305-0
2023-05-31T09:46:57.0298848Z 2023/05/31 09:46:17.602047 +0000 INFO gc/diskcleaner.go:118 JobFactory is start
2023-05-31T09:46:57.0299159Z 2023/05/31 09:46:17.603898 +0000 INFO catalog/catalog.go:142 GC Catalog 1685526377220597305-0
2023-05-31T09:46:57.0299451Z 2023/05/31 09:46:17.605565 +0000 INFO catalog/catalog.go:142 GC Catalog 1685526377220597305-0
2023-05-31T09:46:57.0299752Z 2023/05/31 09:46:17.606951 +0000 INFO catalog/catalog.go:142 GC Catalog 1685526377220597305-0
2023-05-31T09:46:57.0300039Z 2023/05/31 09:46:17.608368 +0000 INFO catalog/catalog.go:142 GC Catalog 1685526377220597305-0
2023-05-31T09:46:57.0300328Z 2023/05/31 09:46:17.609728 +0000 INFO catalog/catalog.go:142 GC Catalog 1685526377220597305-0
2023-05-31T09:46:57.0300622Z 2023/05/31 09:46:17.611159 +0000 INFO catalog/catalog.go:142 GC Catalog 1685526377220597305-0
2023-05-31T09:46:57.0300854Z 2023/05/31 09:46:17.612647 +0000 INFO gc/diskcleaner.go:118 JobFactory is start
2023-05-31T09:46:57.0301140Z 2023/05/31 09:46:17.612766 +0000 INFO catalog/catalog.go:142 GC Catalog 1685526377220597305-0
2023-05-31T09:46:57.0301428Z 2023/05/31 09:46:17.614163 +0000 INFO catalog/catalog.go:142 GC Catalog 1685526377220597305-0
2023-05-31T09:46:57.0301681Z 2023/05/31 09:46:17.614744 +0000 INFO db/scannerop.go:376 Mergeblocks available mem: 5g
2023-05-31T09:46:57.0301989Z 2023/05/31 09:46:17.616250 +0000 INFO catalog/catalog.go:142 GC Catalog 1685526377220597305-0
2023-05-31T09:46:57.0302272Z 2023/05/31 09:46:17.617563 +0000 INFO catalog/catalog.go:142 GC Catalog 1685526377220597305-0
2023-05-31T09:46:57.0302556Z 2023/05/31 09:46:17.618919 +0000 INFO catalog/catalog.go:142 GC Catalog 1685526377220597305-0
2023-05-31T09:46:57.0302844Z 2023/05/31 09:46:17.620480 +0000 INFO catalog/catalog.go:142 GC Catalog 1685526377220597305-0
2023-05-31T09:46:57.0303242Z 2023/05/31 09:46:17.621499 +0000 INFO catalog/catalog.go:142 GC Catalog 1685526377220597305-0
2023-05-31T09:46:57.0303690Z 2023/05/31 09:46:17.623751 +0000 INFO catalog/catalog.go:142 GC Catalog 1685526377220597305-0
2023-05-31T09:46:57.0303921Z 2023/05/31 09:46:17.623897 +0000 INFO gc/diskcleaner.go:118 JobFactory is start
2023-05-31T09:46:57.0304217Z 2023/05/31 09:46:17.625469 +0000 INFO catalog/catalog.go:142 GC Catalog 1685526377220597305-0
2023-05-31T09:46:57.0304690Z 2023/05/31 09:46:17.626383 +0000 INFO jobs/compactblk.go:146 [Start] {"operation": "[1994]compact", "operand": "[A]BLK[<1000-1000-1-0>]"}
2023-05-31T09:46:57.0304997Z 2023/05/31 09:46:17.627258 +0000 INFO catalog/catalog.go:142 GC Catalog 1685526377220597305-0
2023-05-31T09:46:57.0305574Z 2023/05/31 09:46:17.627569 +0000 INFO jobs/compactblk.go:146 [Start] {"operation": "[1996]compact", "operand": "[A]BLK[<1000-1000-0-0>]"}
2023-05-31T09:46:57.0305966Z 2023/05/31 09:46:17.646730 +0000 INFO catalog/catalog.go:142 GC Catalog 1685526377220597305-0
2023-05-31T09:46:57.0306199Z 2023/05/31 09:46:17.646925 +0000 INFO gc/diskcleaner.go:118 JobFactory is start
2023-05-31T09:46:57.0306760Z 2023/05/31 09:46:17.652495 +0000 WARN checkpoint/runner.go:693 Block BLK<1000-1000-fd7b0d16-ff97-11ed-8fdf-00224809a69b-0-0> Mutation Info: Changes=0/10:
2023-05-31T09:46:57.0307292Z 2023/05/31 09:46:17.652767 +0000 WARN checkpoint/runner.go:693 Block BLK<1000-1000-fd7b0d16-ff97-11ed-8fdf-00224809a69b-1-0> Mutation Info: Changes=0/10:
2023-05-31T09:46:57.0307585Z 2023/05/31 09:46:17.654055 +0000 INFO catalog/catalog.go:142 GC Catalog 1685526377220597305-0
2023-05-31T09:46:57.0307875Z 2023/05/31 09:46:17.655886 +0000 INFO catalog/catalog.go:142 GC Catalog 1685526377220597305-0
2023-05-31T09:46:57.0308442Z 2023/05/31 09:46:17.654848 +0000 WARN checkpoint/runner.go:693 Block BLK<1000-1000-fd7b0d16-ff97-11ed-8fdf-00224809a69b-1-0> Mutation Info: Changes=0/10:
2023-05-31T09:46:57.0309013Z 2023/05/31 09:46:17.656487 +0000 INFO catalog/catalog.go:142 GC Catalog 1685526377220597305-0
2023-05-31T09:46:57.0309263Z 2023/05/31 09:46:17.656928 +0000 INFO gc/diskcleaner.go:118 JobFactory is start
2023-05-31T09:46:57.0309941Z 2023/05/31 09:46:17.657290 +0000 WARN checkpoint/runner.go:693 Block BLK<1000-1000-fd7b0d16-ff97-11ed-8fdf-00224809a69b-0-0> Mutation Info: Changes=0/10:
2023-05-31T09:46:57.0310685Z 2023/05/31 09:46:17.657515 +0000 INFO blockio/writer.go:156 [WriteEnd] {"operation": "name: fd7b0d16-ff97-11ed-8fdf-00224809a69b_00002, block count: 1, size: 1712", "operand": [0, 1, 2, 3, 4, 5, 6, 7, 8, 9, 10, 11, 12, 13, 14, 15, 16, 17], "operand": 17}
2023-05-31T09:46:57.0311142Z 2023/05/31 09:46:17.657684 +0000 INFO jobs/compactblk.go:338 update metaloc for fd7b0d16-ff97-11ed-8fdf-00224809a69b-2-0
2023-05-31T09:46:57.0311433Z 2023/05/31 09:46:17.657947 +0000 INFO catalog/catalog.go:142 GC Catalog 1685526377220597305-0
2023-05-31T09:46:57.0311748Z 2023/05/31 09:46:17.659384 +0000 INFO catalog/catalog.go:142 GC Catalog 1685526377220597305-0
2023-05-31T09:46:57.0312046Z 2023/05/31 09:46:17.660683 +0000 INFO catalog/catalog.go:142 GC Catalog 1685526377220597305-0
2023-05-31T09:46:57.0312338Z 2023/05/31 09:46:17.662252 +0000 INFO catalog/catalog.go:142 GC Catalog 1685526377220597305-0
2023-05-31T09:46:57.0313058Z 2023/05/31 09:46:17.661304 +0000 INFO blockio/writer.go:156 [WriteEnd] {"operation": "name: fd7b0d16-ff97-11ed-8fdf-00224809a69b_00003, block count: 1, size: 1703", "operand": [0, 1, 2, 3, 4, 5, 6, 7, 8, 9, 10, 11, 12, 13, 14, 15, 16, 17], "operand": 17}
2023-05-31T09:46:57.0313514Z 2023/05/31 09:46:17.662776 +0000 INFO jobs/compactblk.go:338 update metaloc for fd7b0d16-ff97-11ed-8fdf-00224809a69b-3-0
2023-05-31T09:46:57.0313806Z 2023/05/31 09:46:17.665663 +0000 INFO catalog/catalog.go:142 GC Catalog 1685526377220597305-0
2023-05-31T09:46:57.0314157Z 2023/05/31 09:46:17.667617 +0000 INFO catalog/catalog.go:142 GC Catalog 1685526377220597305-0
2023-05-31T09:46:57.0314721Z 2023/05/31 09:46:17.666645 +0000 WARN checkpoint/runner.go:693 Block BLK<1000-1000-fd7b0d16-ff97-11ed-8fdf-00224809a69b-0-0> Mutation Info: Changes=0/10:
2023-05-31T09:46:57.0315394Z 2023/05/31 09:46:17.669726 +0000 WARN checkpoint/runner.go:693 Block BLK<1000-1000-fd7b0d16-ff97-11ed-8fdf-00224809a69b-1-0> Mutation Info: Changes=0/10:
2023-05-31T09:46:57.0315625Z 2023/05/31 09:46:17.670434 +0000 INFO gc/diskcleaner.go:118 JobFactory is start
2023-05-31T09:46:57.0315920Z 2023/05/31 09:46:17.671078 +0000 INFO catalog/catalog.go:142 GC Catalog 1685526377220597305-0
2023-05-31T09:46:57.0316211Z 2023/05/31 09:46:17.674540 +0000 INFO catalog/catalog.go:142 GC Catalog 1685526377220597305-0
2023-05-31T09:46:57.0316448Z 2023/05/31 09:46:17.674769 +0000 INFO db/scannerop.go:370 Mergeblocks stats: map[]
2023-05-31T09:46:57.0316692Z 2023/05/31 09:46:17.675142 +0000 INFO db/scannerop.go:376 Mergeblocks available mem: 5g
2023-05-31T09:46:57.0317065Z 2023/05/31 09:46:17.675512 +0000 INFO catalog/catalog.go:142 GC Catalog 1685526377220597305-0
2023-05-31T09:46:57.0317690Z 2023/05/31 09:46:17.675949 +0000 WARN checkpoint/runner.go:693 Block BLK<1000-1000-fd7b0d16-ff97-11ed-8fdf-00224809a69b-0-0> Mutation Info: Changes=0/10:
2023-05-31T09:46:57.0318239Z 2023/05/31 09:46:17.676126 +0000 WARN checkpoint/runner.go:693 Block BLK<1000-1000-fd7b0d16-ff97-11ed-8fdf-00224809a69b-1-0> Mutation Info: Changes=0/10:
2023-05-31T09:46:57.0318528Z 2023/05/31 09:46:17.676664 +0000 INFO catalog/catalog.go:142 GC Catalog 1685526377220597305-0
2023-05-31T09:46:57.0319262Z 2023/05/31 09:46:17.676942 +0000 INFO blockio/writer.go:156 [WriteEnd] {"operation": "name: fd7b0d16-ff97-11ed-8fdf-00224809a69b_00000, block count: 1, size: 1897", "operand": [0, 1, 2, 3, 4, 5, 6, 7, 8, 9, 10, 11, 12, 13, 14, 15, 16, 17, 18, 19, 20], "operand": 17}
2023-05-31T09:46:57.0320066Z 2023/05/31 09:46:17.677163 +0000 INFO jobs/compactblk.go:289 [Done] {"txn-start-ts": "1685526377627458848-0", "operation": "[1996]compact", "compacted": "[A]BLK[<1000-1000-0-0>]", "created": "BLK<1000-1000-fd7b0d16-ff97-11ed-8fdf-00224809a69b-3-0>", "duration": "49.522312ms"}
2023-05-31T09:46:57.0320879Z 2023/05/31 09:46:17.677182 +0000 INFO blockio/writer.go:156 [WriteEnd] {"operation": "name: fd7b0d16-ff97-11ed-8fdf-00224809a69b_00001, block count: 1, size: 1907", "operand": [0, 1, 2, 3, 4, 5, 6, 7, 8, 9, 10, 11, 12, 13, 14, 15, 16, 17, 18, 19, 20], "operand": 17}
2023-05-31T09:46:57.0321125Z 2023/05/31 09:46:17.677577 +0000 INFO gc/diskcleaner.go:118 JobFactory is start
2023-05-31T09:46:57.0321445Z 2023/05/31 09:46:17.677747 +0000 INFO catalog/catalog.go:142 GC Catalog 1685526377220597305-0
2023-05-31T09:46:57.0322247Z 2023/05/31 09:46:17.677975 +0000 INFO jobs/compactblk.go:289 [Done] {"txn-start-ts": "1685526377626226308-0", "operation": "[1994]compact", "compacted": "[A]BLK[<1000-1000-1-0>]", "created": "BLK<1000-1000-fd7b0d16-ff97-11ed-8fdf-00224809a69b-2-0>", "duration": "51.518577ms"}
2023-05-31T09:46:57.0322540Z 2023/05/31 09:46:17.679001 +0000 INFO catalog/catalog.go:142 GC Catalog 1685526377220597305-0
2023-05-31T09:46:57.0322835Z 2023/05/31 09:46:17.680021 +0000 INFO catalog/catalog.go:142 GC Catalog 1685526377220597305-0
2023-05-31T09:46:57.0323303Z 2023/05/31 09:46:17.680278 +0000 INFO tables/mnode.go:70 Releasing Memorynode BLK-fd7b0d16-ff97-11ed-8fdf-00224809a69b-0-0
2023-05-31T09:46:57.0323598Z 2023/05/31 09:46:17.681361 +0000 INFO catalog/catalog.go:142 GC Catalog 1685526377220597305-0
2023-05-31T09:46:57.0324061Z 2023/05/31 09:46:17.681545 +0000 INFO tables/mnode.go:70 Releasing Memorynode BLK-fd7b0d16-ff97-11ed-8fdf-00224809a69b-1-0
2023-05-31T09:46:57.0324352Z 2023/05/31 09:46:17.682996 +0000 INFO catalog/catalog.go:142 GC Catalog 1685526377220597305-0
2023-05-31T09:46:57.0324660Z 2023/05/31 09:46:17.684139 +0000 INFO catalog/catalog.go:142 GC Catalog 1685526377220597305-0
2023-05-31T09:46:57.0324949Z 2023/05/31 09:46:17.685312 +0000 INFO catalog/catalog.go:142 GC Catalog 1685526377220597305-0
2023-05-31T09:46:57.0325245Z 2023/05/31 09:46:17.686605 +0000 INFO catalog/catalog.go:142 GC Catalog 1685526377220597305-0
2023-05-31T09:46:57.0325579Z 2023/05/31 09:46:17.687821 +0000 INFO gc/diskcleaner.go:118 JobFactory is start
2023-05-31T09:46:57.0325877Z 2023/05/31 09:46:17.687940 +0000 INFO catalog/catalog.go:142 GC Catalog 1685526377220597305-0
2023-05-31T09:46:57.0326059Z base_test.go:231:
2023-05-31T09:46:57.0326617Z Error Trace: /home/runner/work/matrixone/matrixone/pkg/vm/engine/tae/db/base_test.go:231
2023-05-31T09:46:57.0327576Z /home/runner/work/matrixone/matrixone/pkg/vm/engine/tae/db/db_test.go:6189
2023-05-31T09:46:57.0327876Z Error: Received unexpected error:
2023-05-31T09:46:57.0328447Z internal error: prev checkpoint not finished
2023-05-31T09:46:57.0328725Z Test: TestGlobalCheckpoint5
2023-05-31T09:46:57.0329059Z 2023/05/31 09:46:17.688270 +0000 INFO gc/manager.go:152 gc-loop is going to exit
2023-05-31T09:46:57.0329358Z 2023/05/31 09:46:17.694007 +0000 INFO db/scanner.go:55 DBScanner Stopped
2023-05-31T09:46:57.0329684Z 2023/05/31 09:46:17.700232 +0000 INFO db/scheduler.go:83 TaskScheduler Stopped
2023-05-31T09:46:57.0329910Z 2023/05/31 09:46:17.700353 +0000 INFO txnbase/txnmgr.go:567 [Stop] {"txnmgr": {}}
2023-05-31T09:46:57.0330164Z --- FAIL: TestGlobalCheckpoint5 (0.53s)
Expected Behavior
No response
Steps to Reproduce
No response
Additional information
No response
matrixone copied to clipboard
matrixorigin
