matrixone icon indicating copy to clipboard operation
matrixone copied to clipboard

[Bug]: dn failed to start, panic: ExpectedEOB

Open aylei opened this issue 2 years ago • 6 comments

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): 5a8f96374a532c5671f03118fb27ce7360188ce7
- Hardware parameters:
- OS type:
- Others:

Actual Behavior

DN failed to start after change the config:

config change:

     [dn]
     listen-address = "0.0.0.0:41010"
+    port-base = 41010
     uuid = "${UUID}"
     service-address = "${ADDR}:41010"
+    service-host = "${ADDR}"

panic log:

panic: ExpectedEOB

goroutine 492 [running]:
github.com/matrixorigin/matrixone/pkg/vm/engine/tae/txn/txnimpl.(*replayTxnStore).replayAppend(0x2?, 0x2?, {0x2a61f80?, 0xc00168c620?})
	/go/src/github.com/matrixorigin/matrixone/pkg/vm/engine/tae/txn/txnimpl/replaystore.go:230 +0x114
github.com/matrixorigin/matrixone/pkg/vm/engine/tae/txn/txnimpl.(*replayTxnStore).replayDataCmds(0x0?, 0x7?, {0x2f8a0c0?, 0xc020968fc0?})
	/go/src/github.com/matrixorigin/matrixone/pkg/vm/engine/tae/txn/txnimpl/replaystore.go:183 +0x45
github.com/matrixorigin/matrixone/pkg/vm/engine/tae/txn/txnimpl.(*replayTxnStore).prepareCmd(0xc01219bdb0, {0x2fda830, 0xc011e1ced0})
	/go/src/github.com/matrixorigin/matrixone/pkg/vm/engine/tae/txn/txnimpl/replaystore.go:117 +0x325
github.com/matrixorigin/matrixone/pkg/vm/engine/tae/txn/txnimpl.(*replayTxnStore).prepareCommit(0xc01219bdb0, {0x30188f8, 0xc0121e2150})
	/go/src/github.com/matrixorigin/matrixone/pkg/vm/engine/tae/txn/txnimpl/replaystore.go:82 +0xc5
github.com/matrixorigin/matrixone/pkg/vm/engine/tae/txn/txnbase.(*Txn).PrepareCommit(0xc0121e2150)
	/go/src/github.com/matrixorigin/matrixone/pkg/vm/engine/tae/txn/txnbase/txn.go:323 +0x82
github.com/matrixorigin/matrixone/pkg/vm/engine/tae/txn/txnbase.(*TxnManager).onPreparCommit(0x1840320?, {0x30188f8, 0xc0121e2150})
	/go/src/github.com/matrixorigin/matrixone/pkg/vm/engine/tae/txn/txnbase/txnmgr.go:331 +0x2a
github.com/matrixorigin/matrixone/pkg/vm/engine/tae/txn/txnbase.(*TxnManager).onPrepare(0x0?, 0xc01228b380, {0x0, 0x0, 0x0, 0x0, 0x64, 0xe4, 0xf9, 0x39, ...})
	/go/src/github.com/matrixorigin/matrixone/pkg/vm/engine/tae/txn/txnbase/txnmgr.go:385 +0x32
github.com/matrixorigin/matrixone/pkg/vm/engine/tae/txn/txnbase.(*TxnManager).onPrepare1PC(0xc00181a9c0?, 0xc01228b380?, {0x0, 0x0, 0x0, 0x0, 0x64, 0xe4, 0xf9, 0x39, ...})
	/go/src/github.com/matrixorigin/matrixone/pkg/vm/engine/tae/txn/txnbase/txnmgr.go:410 +0x4b
github.com/matrixorigin/matrixone/pkg/vm/engine/tae/txn/txnbase.(*TxnManager).dequeuePreparing(0xc00181a9c0, {0xc004ad0000?, 0x1, 0x3e8})
	/go/src/github.com/matrixorigin/matrixone/pkg/vm/engine/tae/txn/txnbase/txnmgr.go:498 +0x290
github.com/matrixorigin/matrixone/pkg/vm/engine/tae/logstore/sm.(*safeQueue).Start.func1()
	/go/src/github.com/matrixorigin/matrixone/pkg/vm/engine/tae/logstore/sm/safeq.go:89 +0x1ec
created by github.com/matrixorigin/matrixone/pkg/vm/engine/tae/logstore/sm.(*safeQueue).Start
	/go/src/github.com/matrixorigin/matrixone/pkg/vm/engine/tae/logstore/sm/safeq.go:68 +0xea

full log:

/mo-service -cfg /tmp/tmp.Mo7r0y1k0S -debug-http=:6060
{"level":"INFO","time":"2023/09/07 09:07:50.409935 +0000","caller":"logutil/internal.go:37","msg":"MO logger init, level=, log file=, stackLevel=panic"}
{"level":"INFO","time":"2023/09/07 09:07:50.410043 +0000","caller":"fileservice/local_fs.go:109","msg":"fileservice: memory cache initialized","fs-name":"LOCAL","configError":"json: unsupported type: func(fileservice.CacheKey, fileservice.CacheData)"}
{"level":"INFO","time":"2023/09/07 09:07:51.408541 +0000","caller":"fileservice/s3_fs.go:149","msg":"fileservice: memory cache initialized","fs-name":"SHARED","capacity":15300820992}
{"level":"INFO","time":"2023/09/07 09:07:51.408597 +0000","caller":"fileservice/s3_fs.go:169","msg":"fileservice: disk cache initialized","fs-name":"SHARED","configError":"json: unsupported type: func(fileservice.CacheKey, fileservice.CacheData)"}
{"level":"INFO","time":"2023/09/07 09:07:51.671654 +0000","caller":"fileservice/s3_fs.go:169","msg":"fileservice: disk cache initialized","fs-name":"ETL","configError":"json: unsupported type: func(fileservice.CacheKey, fileservice.CacheData)"}
{"level":"INFO","time":"2023/09/07 09:07:51.672709 +0000","caller":"motrace/trace.go:138","msg":"init GlobalBatchProcessor"}
{"level":"INFO","time":"2023/09/07 09:07:51.672772 +0000","caller":"export/batch_processor.go:365","msg":"MOCollector Start"}
{"level":"INFO","time":"2023/09/07 09:07:51.672977 +0000","caller":"motrace/trace.go:143","msg":"init trace span processor"}
{"level":"INFO","time":"2023/09/07 09:07:51.675382 +0000","name":"rpc-client[hakeeper-client([connectToHAKeeper])]","caller":"morpc/client.go:379","msg":"gc idle backends task started"}
{"level":"INFO","time":"2023/09/07 09:07:51.675442 +0000","name":"rpc-client[hakeeper-client([connectToHAKeeper])]","caller":"morpc/client.go:343","msg":"print active backends task started"}
{"level":"INFO","time":"2023/09/07 09:07:51.675690 +0000","caller":"logservice/hakeeper_client.go:582","msg":"isHAKeeper: true, err: <nil>"}
{"level":"ERROR","time":"2023/09/07 09:07:51.680540 +0000","name":"hakeeper-client-backend","caller":"morpc/backend.go:515","msg":"read from backend failed","remote":"default-log-0.default-log-headless.freetier-01.svc:32001","backend-id":"b92f17ba-dda0-4e24-a3ce-0f9938c4e06b","error":"read tcp4 172.20.113.132:48626->172.20.113.3:32001: use of closed network connection"}
{"level":"ERROR","time":"2023/09/07 09:07:51.680572 +0000","name":"hakeeper-client-backend","caller":"morpc/backend.go:519","msg":"read loop stopped","remote":"default-log-0.default-log-headless.freetier-01.svc:32001","backend-id":"b92f17ba-dda0-4e24-a3ce-0f9938c4e06b"}
{"level":"ERROR","time":"2023/09/07 09:07:51.685642 +0000","name":"hakeeper-client-backend","caller":"[email protected]/session.go:515","msg":"close conneciton failed","remote":"default-log-0.default-log-headless.freetier-01.svc:32001","backend-id":"b92f17ba-dda0-4e24-a3ce-0f9938c4e06b","session-id":0,"error":"close tcp4 172.20.113.132:48626->172.20.113.3:32001: use of closed network connection"}
{"level":"ERROR","time":"2023/09/07 09:07:51.690773 +0000","name":"rpc-client[hakeeper-client([connectToHAKeeper])]","caller":"morpc/client.go:352","msg":"print active backends task stopped"}
{"level":"ERROR","time":"2023/09/07 09:07:51.690780 +0000","name":"rpc-client[hakeeper-client([connectToHAKeeper])]","caller":"morpc/client.go:411","msg":"gc inactive backends task stopped"}
{"level":"ERROR","time":"2023/09/07 09:07:51.690782 +0000","name":"rpc-client[hakeeper-client([connectToHAKeeper])]","caller":"morpc/client.go:388","msg":"gc idle backends task stopped"}
{"level":"INFO","time":"2023/09/07 09:07:51.698015 +0000","name":"rpc-client[hakeeper-client([connectToHAKeeper])]","caller":"morpc/client.go:379","msg":"gc idle backends task started"}
{"level":"INFO","time":"2023/09/07 09:07:51.698019 +0000","name":"rpc-client[hakeeper-client([connectToHAKeeper])]","caller":"morpc/client.go:343","msg":"print active backends task started"}
{"level":"INFO","time":"2023/09/07 09:07:51.698631 +0000","caller":"logservice/hakeeper_client.go:582","msg":"isHAKeeper: true, err: <nil>"}
{"level":"INFO","time":"2023/09/07 09:07:51.698873 +0000","name":"tn-service.txn-rpc-sender.rpc-client[txn-rpc-sender]","caller":"morpc/client.go:379","msg":"gc idle backends task started","uuid":"33376565-3237-3162-3439-323631326537"}
{"level":"INFO","time":"2023/09/07 09:07:51.698887 +0000","name":"tn-service.txn-rpc-sender.rpc-client[txn-rpc-sender]","caller":"morpc/client.go:343","msg":"print active backends task started","uuid":"33376565-3237-3162-3439-323631326537"}
{"level":"INFO","time":"2023/09/07 09:07:51.698932 +0000","name":"tn-service","caller":"tnservice/store_metadata.go:53","msg":"local DNShard loaded","uuid":"33376565-3237-3162-3439-323631326537","metadata":"33376565-3237-3162-3439-323631326537/1 DNShards[2-262148-1-default-dn-0.default-dn-headless.freetier-01.svc:41010]"}
{"level":"INFO","time":"2023/09/07 09:07:51.699031 +0000","name":"tn-service.morpc.ctlservice.rpc-client[ctlservice]","caller":"morpc/client.go:379","msg":"gc idle backends task started","uuid":"33376565-3237-3162-3439-323631326537"}
{"level":"INFO","time":"2023/09/07 09:07:51.699040 +0000","name":"tn-service.morpc.ctlservice.rpc-client[ctlservice]","caller":"morpc/client.go:343","msg":"print active backends task started","uuid":"33376565-3237-3162-3439-323631326537"}
{"level":"INFO","time":"2023/09/07 09:07:51.699260 +0000","caller":"db/open.go:52","msg":"open-tae","operation":"Start","operand":"open"}
{"level":"INFO","time":"2023/09/07 09:07:51.699858 +0000","name":"tn-service","caller":"tnservice/store.go:204","msg":"dn heartbeat task started","uuid":"33376565-3237-3162-3439-323631326537","process":"system-init"}
{"level":"INFO","time":"2023/09/07 09:07:51.702624 +0000","name":"rpc-client[hakeeper-client([])]","caller":"morpc/client.go:343","msg":"print active backends task started"}
{"level":"INFO","time":"2023/09/07 09:07:51.702661 +0000","name":"rpc-client[hakeeper-client([])]","caller":"morpc/client.go:379","msg":"gc idle backends task started"}
{"level":"INFO","time":"2023/09/07 09:07:51.711851 +0000","name":"rpc-client[hakeeper-client([])]","caller":"morpc/client.go:379","msg":"gc idle backends task started"}
{"level":"INFO","time":"2023/09/07 09:07:51.711857 +0000","name":"rpc-client[hakeeper-client([])]","caller":"morpc/client.go:343","msg":"print active backends task started"}
{"level":"INFO","time":"2023/09/07 09:07:51.721690 +0000","name":"rpc-client[hakeeper-client([])]","caller":"morpc/client.go:379","msg":"gc idle backends task started"}
{"level":"INFO","time":"2023/09/07 09:07:51.721698 +0000","name":"rpc-client[hakeeper-client([])]","caller":"morpc/client.go:343","msg":"print active backends task started"}
{"level":"INFO","time":"2023/09/07 09:07:51.730656 +0000","name":"rpc-client[hakeeper-client([])]","caller":"morpc/client.go:379","msg":"gc idle backends task started"}
{"level":"INFO","time":"2023/09/07 09:07:51.730660 +0000","name":"rpc-client[hakeeper-client([])]","caller":"morpc/client.go:343","msg":"print active backends task started"}
{"level":"INFO","time":"2023/09/07 09:07:51.737927 +0000","name":"rpc-client[hakeeper-client([])]","caller":"morpc/client.go:343","msg":"print active backends task started"}
{"level":"INFO","time":"2023/09/07 09:07:51.737943 +0000","name":"rpc-client[hakeeper-client([])]","caller":"morpc/client.go:379","msg":"gc idle backends task started"}
{"level":"INFO","time":"2023/09/07 09:07:51.741532 +0000","name":"rpc-client[hakeeper-client([])]","caller":"morpc/client.go:379","msg":"gc idle backends task started"}
{"level":"INFO","time":"2023/09/07 09:07:51.741578 +0000","name":"rpc-client[hakeeper-client([])]","caller":"morpc/client.go:343","msg":"print active backends task started"}
{"level":"INFO","time":"2023/09/07 09:07:51.744704 +0000","name":"rpc-client[hakeeper-client([])]","caller":"morpc/client.go:379","msg":"gc idle backends task started"}
{"level":"INFO","time":"2023/09/07 09:07:51.744710 +0000","name":"rpc-client[hakeeper-client([])]","caller":"morpc/client.go:343","msg":"print active backends task started"}
{"level":"INFO","time":"2023/09/07 09:07:51.748428 +0000","name":"rpc-client[hakeeper-client([])]","caller":"morpc/client.go:343","msg":"print active backends task started"}
{"level":"INFO","time":"2023/09/07 09:07:51.748462 +0000","name":"rpc-client[hakeeper-client([])]","caller":"morpc/client.go:379","msg":"gc idle backends task started"}
{"level":"INFO","time":"2023/09/07 09:07:51.751843 +0000","name":"rpc-client[hakeeper-client([])]","caller":"morpc/client.go:343","msg":"print active backends task started"}
{"level":"INFO","time":"2023/09/07 09:07:51.751873 +0000","name":"rpc-client[hakeeper-client([])]","caller":"morpc/client.go:379","msg":"gc idle backends task started"}
{"level":"INFO","time":"2023/09/07 09:07:51.755553 +0000","name":"rpc-client[hakeeper-client([])]","caller":"morpc/client.go:343","msg":"print active backends task started"}
{"level":"INFO","time":"2023/09/07 09:07:51.755584 +0000","name":"rpc-client[hakeeper-client([])]","caller":"morpc/client.go:379","msg":"gc idle backends task started"}
{"level":"INFO","time":"2023/09/07 09:07:51.987545 +0000","caller":"checkpoint/replay.go:236","msg":"replay checkpoint CKP[I][2](0-0->1694062075222016734-0)"}
{"level":"INFO","time":"2023/09/07 09:07:51.989776 +0000","caller":"checkpoint/replay.go:236","msg":"replay checkpoint CKP[I][2](1694062075222016734-1->1694062370221306411-0)"}
{"level":"INFO","time":"2023/09/07 09:07:52.002544 +0000","caller":"checkpoint/replay.go:236","msg":"replay checkpoint CKP[I][2](1694062370221306411-1->1694062675225655959-0)"}
{"level":"INFO","time":"2023/09/07 09:07:52.041743 +0000","caller":"checkpoint/replay.go:236","msg":"replay checkpoint CKP[I][2](1694062675225655959-1->1694062970221981107-0)"}
{"level":"INFO","time":"2023/09/07 09:07:52.046694 +0000","caller":"checkpoint/replay.go:236","msg":"replay checkpoint CKP[I][2](1694062970221981107-1->1694063280221687470-0)"}
{"level":"INFO","time":"2023/09/07 09:07:52.049120 +0000","caller":"checkpoint/replay.go:236","msg":"replay checkpoint CKP[I][2](1694063280221687470-1->1694063575221176876-0)"}
{"level":"INFO","time":"2023/09/07 09:07:52.049805 +0000","caller":"checkpoint/replay.go:236","msg":"replay checkpoint CKP[I][2](1694063575221176876-1->1694063880222188100-0)"}
{"level":"INFO","time":"2023/09/07 09:07:52.050585 +0000","caller":"checkpoint/replay.go:236","msg":"replay checkpoint CKP[I][2](1694063880222188100-1->1694064210221522402-0)"}
{"level":"INFO","time":"2023/09/07 09:07:52.051937 +0000","caller":"checkpoint/replay.go:236","msg":"replay checkpoint CKP[I][2](1694064210221522402-1->1694064505223004911-0)"}
{"level":"INFO","time":"2023/09/07 09:07:52.053431 +0000","caller":"checkpoint/replay.go:236","msg":"replay checkpoint CKP[I][2](1694064505223004911-1->1694064830221897203-0)"}
{"level":"INFO","time":"2023/09/07 09:07:52.054961 +0000","caller":"checkpoint/replay.go:236","msg":"replay checkpoint CKP[I][2](1694064830221897203-1->1694065115221714322-0)"}
{"level":"INFO","time":"2023/09/07 09:07:52.055166 +0000","caller":"checkpoint/replay.go:236","msg":"replay checkpoint CKP[I][2](1694065115221714322-1->1694065410222011389-0)"}
{"level":"INFO","time":"2023/09/07 09:07:52.055653 +0000","caller":"checkpoint/replay.go:236","msg":"replay checkpoint CKP[I][2](1694065410222011389-1->1694065700221555944-0)"}
{"level":"INFO","time":"2023/09/07 09:07:52.057103 +0000","caller":"checkpoint/replay.go:236","msg":"replay checkpoint CKP[I][2](1694065700221555944-1->1694066015221971788-0)"}
{"level":"INFO","time":"2023/09/07 09:07:52.059052 +0000","caller":"checkpoint/replay.go:236","msg":"replay checkpoint CKP[I][2](1694066015221971788-1->1694066345221286170-0)"}
{"level":"INFO","time":"2023/09/07 09:07:52.059700 +0000","caller":"checkpoint/replay.go:236","msg":"replay checkpoint CKP[I][2](1694066345221286170-1->1694066630222167475-0)"}
{"level":"INFO","time":"2023/09/07 09:07:52.062207 +0000","caller":"checkpoint/replay.go:236","msg":"replay checkpoint CKP[I][2](1694066630222167475-1->1694066955251989827-0)"}
{"level":"INFO","time":"2023/09/07 09:07:52.078959 +0000","caller":"checkpoint/replay.go:236","msg":"replay checkpoint CKP[I][2](1694066955251989827-1->1694067250239314625-0)"}
{"level":"INFO","time":"2023/09/07 09:07:52.094268 +0000","caller":"checkpoint/replay.go:236","msg":"replay checkpoint CKP[I][2](1694067250239314625-1->1694067575221380541-0)"}
{"level":"INFO","time":"2023/09/07 09:07:52.106992 +0000","caller":"checkpoint/replay.go:236","msg":"replay checkpoint CKP[I][2](1694067575221380541-1->1694067905249072568-0)"}
{"level":"INFO","time":"2023/09/07 09:07:52.125772 +0000","caller":"checkpoint/replay.go:236","msg":"replay checkpoint CKP[I][2](1694067905249072568-1->1694068235244549030-0)"}
{"level":"INFO","time":"2023/09/07 09:07:52.145403 +0000","caller":"checkpoint/replay.go:236","msg":"replay checkpoint CKP[I][2](1694068235244549030-1->1694068570238440184-0)"}
{"level":"INFO","time":"2023/09/07 09:07:52.164889 +0000","caller":"checkpoint/replay.go:236","msg":"replay checkpoint CKP[I][2](1694068570238440184-1->1694068910236200317-0)"}
{"level":"INFO","time":"2023/09/07 09:07:52.184375 +0000","caller":"checkpoint/replay.go:236","msg":"replay checkpoint CKP[I][2](1694068910236200317-1->1694069245237358709-0)"}
{"level":"INFO","time":"2023/09/07 09:07:52.201663 +0000","caller":"checkpoint/replay.go:236","msg":"replay checkpoint CKP[I][2](1694069245237358709-1->1694069575237840886-0)"}
{"level":"INFO","time":"2023/09/07 09:07:52.228374 +0000","caller":"checkpoint/replay.go:236","msg":"replay checkpoint CKP[I][2](1694069575237840886-1->1694069895243031075-0)"}
{"level":"INFO","time":"2023/09/07 09:07:52.252089 +0000","caller":"checkpoint/replay.go:236","msg":"replay checkpoint CKP[I][2](1694069895243031075-1->1694070230242742016-0)"}
{"level":"INFO","time":"2023/09/07 09:07:52.274774 +0000","caller":"checkpoint/replay.go:236","msg":"replay checkpoint CKP[I][2](1694070230242742016-1->1694070550245306416-0)"}
{"level":"INFO","time":"2023/09/07 09:07:52.298440 +0000","caller":"checkpoint/replay.go:236","msg":"replay checkpoint CKP[I][2](1694070550245306416-1->1694070880249179070-0)"}
{"level":"INFO","time":"2023/09/07 09:07:52.320730 +0000","caller":"checkpoint/replay.go:236","msg":"replay checkpoint CKP[I][2](1694070880249179070-1->1694071215251159614-0)"}
{"level":"INFO","time":"2023/09/07 09:07:52.340421 +0000","caller":"checkpoint/replay.go:236","msg":"replay checkpoint CKP[I][2](1694071215251159614-1->1694071545249911419-0)"}
{"level":"INFO","time":"2023/09/07 09:07:52.364856 +0000","caller":"checkpoint/replay.go:236","msg":"replay checkpoint CKP[I][2](1694071545249911419-1->1694071885248370361-0)"}
{"level":"INFO","time":"2023/09/07 09:07:52.385077 +0000","caller":"checkpoint/replay.go:236","msg":"replay checkpoint CKP[I][2](1694071885248370361-1->1694072220244630058-0)"}
{"level":"INFO","time":"2023/09/07 09:07:52.405958 +0000","caller":"checkpoint/replay.go:236","msg":"replay checkpoint CKP[I][2](1694072220244630058-1->1694072555245479270-0)"}
{"level":"INFO","time":"2023/09/07 09:07:52.422142 +0000","caller":"checkpoint/replay.go:236","msg":"replay checkpoint CKP[I][2](1694072555245479270-1->1694072885243849445-0)"}
{"level":"INFO","time":"2023/09/07 09:07:52.440495 +0000","caller":"checkpoint/replay.go:236","msg":"replay checkpoint CKP[I][2](1694072885243849445-1->1694073215247110557-0)"}
{"level":"INFO","time":"2023/09/07 09:07:52.456259 +0000","caller":"checkpoint/replay.go:236","msg":"replay checkpoint CKP[I][2](1694073215247110557-1->1694073550246866655-0)"}
{"level":"INFO","time":"2023/09/07 09:07:52.469206 +0000","caller":"checkpoint/replay.go:236","msg":"replay checkpoint CKP[I][2](1694073550246866655-1->1694073875247891560-0)"}
{"level":"INFO","time":"2023/09/07 09:07:52.483454 +0000","caller":"checkpoint/replay.go:236","msg":"replay checkpoint CKP[I][2](1694073875247891560-1->1694074210248340674-0)"}
{"level":"INFO","time":"2023/09/07 09:07:52.496105 +0000","caller":"checkpoint/replay.go:236","msg":"replay checkpoint CKP[I][2](1694074210248340674-1->1694074540253059051-0)"}
{"level":"INFO","time":"2023/09/07 09:07:52.506391 +0000","caller":"checkpoint/replay.go:236","msg":"replay checkpoint CKP[I][2](1694074540253059051-1->1694074880248041186-0)"}
{"level":"INFO","time":"2023/09/07 09:07:52.520307 +0000","caller":"checkpoint/replay.go:236","msg":"replay checkpoint CKP[I][2](1694074880248041186-1->1694075210248070196-0)"}
{"level":"INFO","time":"2023/09/07 09:07:52.532938 +0000","caller":"checkpoint/replay.go:236","msg":"replay checkpoint CKP[I][2](1694075210248070196-1->1694075545248638561-0)"}
{"level":"INFO","time":"2023/09/07 09:07:52.546635 +0000","caller":"checkpoint/replay.go:236","msg":"replay checkpoint CKP[I][2](1694075545248638561-1->1694075870246402755-0)"}
{"level":"INFO","time":"2023/09/07 09:07:52.588267 +0000","caller":"checkpoint/replay.go:236","msg":"replay checkpoint CKP[I][2](1694075870246402755-1->1694076200246257738-0)"}
{"level":"INFO","time":"2023/09/07 09:07:52.613938 +0000","caller":"checkpoint/replay.go:236","msg":"replay checkpoint CKP[I][2](1694076200246257738-1->1694076535245190118-0)"}
{"level":"INFO","time":"2023/09/07 09:07:52.635657 +0000","caller":"checkpoint/replay.go:236","msg":"replay checkpoint CKP[I][2](1694076535245190118-1->1694076870246914896-0)"}
{"level":"INFO","time":"2023/09/07 09:07:52.653235 +0000","caller":"checkpoint/replay.go:246","msg":"open-tae","operation":"replay","operand":"checkpoint","apply cost":"665.713842ms","read cost":"215.822921ms"}
{"level":"INFO","time":"2023/09/07 09:07:52.653288 +0000","caller":"db/open.go:148","msg":"open-tae","operation":"replay","operand":"checkpoints","cost":"891.553146ms","checkpointed":"1694076870246914896-0"}
{"level":"INFO","time":"2023/09/07 09:07:52.654696 +0000","caller":"logservicedriver/truncate.go:116","msg":"Logservice Driver: Get Truncate 706711"}
{"level":"INFO","time":"2023/09/07 09:07:52.654724 +0000","caller":"logservicedriver/replay.go:62","msg":"truncated 706711"}
panic: ExpectedEOB

goroutine 492 [running]:
github.com/matrixorigin/matrixone/pkg/vm/engine/tae/txn/txnimpl.(*replayTxnStore).replayAppend(0x2?, 0x2?, {0x2a61f80?, 0xc00168c620?})
	/go/src/github.com/matrixorigin/matrixone/pkg/vm/engine/tae/txn/txnimpl/replaystore.go:230 +0x114
github.com/matrixorigin/matrixone/pkg/vm/engine/tae/txn/txnimpl.(*replayTxnStore).replayDataCmds(0x0?, 0x7?, {0x2f8a0c0?, 0xc020968fc0?})
	/go/src/github.com/matrixorigin/matrixone/pkg/vm/engine/tae/txn/txnimpl/replaystore.go:183 +0x45
github.com/matrixorigin/matrixone/pkg/vm/engine/tae/txn/txnimpl.(*replayTxnStore).prepareCmd(0xc01219bdb0, {0x2fda830, 0xc011e1ced0})
	/go/src/github.com/matrixorigin/matrixone/pkg/vm/engine/tae/txn/txnimpl/replaystore.go:117 +0x325
github.com/matrixorigin/matrixone/pkg/vm/engine/tae/txn/txnimpl.(*replayTxnStore).prepareCommit(0xc01219bdb0, {0x30188f8, 0xc0121e2150})
	/go/src/github.com/matrixorigin/matrixone/pkg/vm/engine/tae/txn/txnimpl/replaystore.go:82 +0xc5
github.com/matrixorigin/matrixone/pkg/vm/engine/tae/txn/txnbase.(*Txn).PrepareCommit(0xc0121e2150)
	/go/src/github.com/matrixorigin/matrixone/pkg/vm/engine/tae/txn/txnbase/txn.go:323 +0x82
github.com/matrixorigin/matrixone/pkg/vm/engine/tae/txn/txnbase.(*TxnManager).onPreparCommit(0x1840320?, {0x30188f8, 0xc0121e2150})
	/go/src/github.com/matrixorigin/matrixone/pkg/vm/engine/tae/txn/txnbase/txnmgr.go:331 +0x2a
github.com/matrixorigin/matrixone/pkg/vm/engine/tae/txn/txnbase.(*TxnManager).onPrepare(0x0?, 0xc01228b380, {0x0, 0x0, 0x0, 0x0, 0x64, 0xe4, 0xf9, 0x39, ...})
	/go/src/github.com/matrixorigin/matrixone/pkg/vm/engine/tae/txn/txnbase/txnmgr.go:385 +0x32
github.com/matrixorigin/matrixone/pkg/vm/engine/tae/txn/txnbase.(*TxnManager).onPrepare1PC(0xc00181a9c0?, 0xc01228b380?, {0x0, 0x0, 0x0, 0x0, 0x64, 0xe4, 0xf9, 0x39, ...})
	/go/src/github.com/matrixorigin/matrixone/pkg/vm/engine/tae/txn/txnbase/txnmgr.go:410 +0x4b
github.com/matrixorigin/matrixone/pkg/vm/engine/tae/txn/txnbase.(*TxnManager).dequeuePreparing(0xc00181a9c0, {0xc004ad0000?, 0x1, 0x3e8})
	/go/src/github.com/matrixorigin/matrixone/pkg/vm/engine/tae/txn/txnbase/txnmgr.go:498 +0x290
github.com/matrixorigin/matrixone/pkg/vm/engine/tae/logstore/sm.(*safeQueue).Start.func1()
	/go/src/github.com/matrixorigin/matrixone/pkg/vm/engine/tae/logstore/sm/safeq.go:89 +0x1ec
created by github.com/matrixorigin/matrixone/pkg/vm/engine/tae/logstore/sm.(*safeQueue).Start
	/go/src/github.com/matrixorigin/matrixone/pkg/vm/engine/tae/logstore/sm/safeq.go:68 +0xea

Expected Behavior

DN should start

Steps to Reproduce

No response

Additional information

No response

aylei avatar Sep 07 '23 09:09 aylei

@XuPeng-SH 帮忙处理一下这个问题。

nnsgmsone avatar Sep 07 '23 09:09 nnsgmsone

加日志打印出来,重启之后的WAL LSN连续,应该是重启前ckp的数据写错了,要等复现 image image image

tmp.txt tmp2.txt

jiangxinmeng1 avatar Sep 08 '23 10:09 jiangxinmeng1

日志备份前不关,暂无法复现

florashi181 avatar Sep 25 '23 01:09 florashi181

在尝试复现

jiangxinmeng1 avatar Oct 07 '23 10:10 jiangxinmeng1

日志备份前不关,暂无法复现

Since the problem is no longer reproduce in last month, I'd close this issue and track the log archive enhancement in https://github.com/matrixorigin/matrixone/issues/11753

aylei avatar Oct 08 '23 03:10 aylei

还没复现

jiangxinmeng1 avatar Jun 27 '24 01:06 jiangxinmeng1

Closing this issue due to inactivity. Feel free to reopen or create a new issue if needed. Thanks!

sukki37 avatar Jul 02 '24 15:07 sukki37