matrixone: [Bug]: CN connection hang on login request

Is there an existing issue for the same bug?

  • I have checked the existing issues.

Environment

- Version or commit-id (e.g. v0.1.0 or 8b23a93): c929fdf9
- Hardware parameters:
- OS type:
- Others:

Actual Behavior

CN new connection hangs, login request does not receive response

tcpdump:

No.	Time	Source	Src Port	Destination	Dst Port	Protocol	Length	Info	DateTime
1	0.000000	127.0.0.1	62418	127.0.0.1	6001	TCP	68	62418 → 6001 [SYN] Seq=0 Win=65535 Len=0 MSS=16344 WS=64 TSval=3865120094 TSecr=0 SACK_PERM	2023-09-04 17:07:42.478437
2	0.000055	127.0.0.1	6001	127.0.0.1	62418	TCP	68	6001 → 62418 [SYN, ACK] Seq=0 Ack=1 Win=65535 Len=0 MSS=16344 WS=64 TSval=601219453 TSecr=3865120094 SACK_PERM	2023-09-04 17:07:42.478492
3	0.000064	127.0.0.1	62418	127.0.0.1	6001	TCP	56	62418 → 6001 [ACK] Seq=1 Ack=1 Win=408256 Len=0 TSval=3865120094 TSecr=601219453	2023-09-04 17:07:42.478501
4	0.000072	127.0.0.1	6001	127.0.0.1	62418	TCP	56	[TCP Window Update] 6001 → 62418 [ACK] Seq=1 Ack=1 Win=408256 Len=0 TSval=601219453 TSecr=3865120094	2023-09-04 17:07:42.478509
5	1.597543	127.0.0.1	6001	127.0.0.1	62418	MySQL	155	Server Greeting  proto=10 version=8.0.30-MatrixOne-v1.0.0-rc1 	2023-09-04 17:07:44.075980
6	1.597590	127.0.0.1	62418	127.0.0.1	6001	TCP	56	62418 → 6001 [ACK] Seq=1 Ack=100 Win=408192 Len=0 TSval=3865121692 TSecr=601221051	2023-09-04 17:07:44.076027
7	1.599145	127.0.0.1	62418	127.0.0.1	6001	MySQL	260	Login Request user=dump 	2023-09-04 17:07:44.077582
8	1.599166	127.0.0.1	6001	127.0.0.1	62418	TCP	56	6001 → 62418 [ACK] Seq=100 Ack=205 Win=408064 Len=0 TSval=601221052 TSecr=3865121693	2023-09-04 17:07:44.077603
9	16.599983	127.0.0.1	6001	127.0.0.1	62418	TCP	44	[TCP Keep-Alive] 6001 → 62418 [ACK] Seq=99 Ack=205 Win=408064 Len=0	2023-09-04 17:07:59.078420
10	16.600038	127.0.0.1	62418	127.0.0.1	6001	TCP	56	[TCP Keep-Alive ACK] 62418 → 6001 [ACK] Seq=205 Ack=100 Win=408192 Len=0 TSval=3865136694 TSecr=601221052	2023-09-04 17:07:59.078475
11	31.687748	127.0.0.1	6001	127.0.0.1	62418	TCP	44	[TCP Keep-Alive] 6001 → 62418 [ACK] Seq=99 Ack=205 Win=408064 Len=0	2023-09-04 17:08:14.166185
12	31.687805	127.0.0.1	62418	127.0.0.1	6001	TCP	56	[TCP Keep-Alive ACK] 62418 → 6001 [ACK] Seq=205 Ack=100 Win=408192 Len=0 TSval=3865151781 TSecr=601221052	2023-09-04 17:08:14.166242

Trace stack:

runtime.selectgo:327
net/http.(*Transport).getConn:1382
net/http.(*Transport).roundTrip:590
net/http.(*Transport).RoundTrip:17
net/http.send:252
net/http.(*Client).send:176
net/http.(*Client).do:716
net/http.(*Client).Do:582
github.com/aws/smithy-go/transport/http.ClientHandler.Handle:55
github.com/aws/smithy-go/middleware.deserializeWrapHandler.HandleDeserialize:190
github.com/aws/smithy-go/transport/http.(*RequestResponseLogger).HandleDeserialize:58
github.com/aws/smithy-go/middleware.decoratedDeserializeHandler.HandleDeserialize:206
github.com/aws/aws-sdk-go-v2/service/internal/checksum.(*validateOutputPayloadChecksum).HandleDeserialize:64
github.com/aws/smithy-go/middleware.decoratedDeserializeHandler.HandleDeserialize:206
github.com/aws/aws-sdk-go-v2/aws/middleware.RecordResponseTiming.HandleDeserialize:57
github.com/aws/smithy-go/middleware.decoratedDeserializeHandler.HandleDeserialize:206
github.com/aws/aws-sdk-go-v2/service/s3.(*awsRestxml_deserializeOpGetObject).HandleDeserialize:5175
github.com/aws/smithy-go/middleware.decoratedDeserializeHandler.HandleDeserialize:206
github.com/aws/aws-sdk-go-v2/service/internal/s3shared.(*metadataRetriever).HandleDeserialize:31
github.com/aws/smithy-go/middleware.decoratedDeserializeHandler.HandleDeserialize:206
github.com/aws/aws-sdk-go-v2/service/internal/s3shared.(*errorWrapper).HandleDeserialize:30
github.com/aws/smithy-go/middleware.decoratedDeserializeHandler.HandleDeserialize:206
github.com/aws/smithy-go/transport/http.(*errorCloseResponseBodyMiddleware).HandleDeserialize:29
github.com/aws/smithy-go/middleware.decoratedDeserializeHandler.HandleDeserialize:206
github.com/aws/aws-sdk-go-v2/aws/middleware.addRawResponse.HandleDeserialize:154
github.com/aws/smithy-go/middleware.decoratedDeserializeHandler.HandleDeserialize:206
github.com/aws/smithy-go/middleware.(*DeserializeStep).HandleMiddleware:120
github.com/aws/smithy-go/middleware.decoratedHandler.Handle:57
github.com/aws/smithy-go/middleware.finalizeWrapHandler.HandleFinalize:184
github.com/aws/aws-sdk-go-v2/aws/signer/v4.(*SignHTTPRequestMiddleware).HandleFinalize:315
github.com/aws/aws-sdk-go-v2/service/s3/internal/customizations.(*SignHTTPRequestMiddleware).HandleFinalize:106
github.com/aws/smithy-go/middleware.decoratedFinalizeHandler.HandleFinalize:200
github.com/aws/aws-sdk-go-v2/aws/retry.MetricsHeader.HandleFinalize:283
github.com/aws/smithy-go/middleware.decoratedFinalizeHandler.HandleFinalize:200
github.com/aws/aws-sdk-go-v2/aws/retry.(*Attempt).handleAttempt:165
github.com/aws/aws-sdk-go-v2/aws/retry.(*Attempt).HandleFinalize:89
github.com/aws/smithy-go/middleware.decoratedFinalizeHandler.HandleFinalize:200
github.com/aws/aws-sdk-go-v2/service/internal/accept-encoding.(*DisableGzip).HandleFinalize:67
github.com/aws/smithy-go/middleware.decoratedFinalizeHandler.HandleFinalize:200
github.com/aws/smithy-go/middleware.(*FinalizeStep).HandleMiddleware:114
github.com/aws/smithy-go/middleware.decoratedHandler.Handle:57
github.com/aws/smithy-go/middleware.buildWrapHandler.HandleBuild:184
github.com/aws/aws-sdk-go-v2/aws/middleware.(*RecursionDetection).HandleBuild:46
github.com/aws/smithy-go/middleware.decoratedBuildHandler.HandleBuild:200
github.com/aws/aws-sdk-go-v2/aws/middleware.(*requestUserAgent).HandleBuild:219
github.com/aws/smithy-go/middleware.decoratedBuildHandler.HandleBuild:200
github.com/aws/aws-sdk-go-v2/aws/signer/v4.(*contentSHA256Header).HandleBuild:249
github.com/aws/smithy-go/middleware.decoratedBuildHandler.HandleBuild:200
github.com/aws/aws-sdk-go-v2/aws/signer/v4.(*computePayloadSHA256).HandleBuild:200
github.com/aws/smithy-go/middleware.decoratedBuildHandler.HandleBuild:200
github.com/aws/smithy-go/transport/http.(*ComputeContentLength).HandleBuild:49
github.com/aws/smithy-go/middleware.decoratedBuildHandler.HandleBuild:200
github.com/aws/aws-sdk-go-v2/aws/middleware.ClientRequestID.HandleBuild:42
github.com/aws/smithy-go/middleware.decoratedBuildHandler.HandleBuild:200
github.com/aws/smithy-go/middleware.(*BuildStep).HandleMiddleware:114
github.com/aws/smithy-go/middleware.decoratedHandler.Handle:57
github.com/aws/smithy-go/middleware.serializeWrapHandler.HandleSerialize:192
github.com/aws/aws-sdk-go-v2/service/s3/internal/customizations.(*removeBucketFromPathMiddleware).HandleSerialize:27
github.com/aws/smithy-go/middleware.decoratedSerializeHandler.HandleSerialize:208
github.com/aws/aws-sdk-go-v2/service/s3/internal/customizations.(*updateEndpoint).HandleSerialize:183
github.com/aws/smithy-go/middleware.decoratedSerializeHandler.HandleSerialize:208
github.com/aws/aws-sdk-go-v2/service/s3.(*awsRestxml_serializeOpGetObject).HandleSerialize:3318
github.com/aws/smithy-go/middleware.decoratedSerializeHandler.HandleSerialize:208
github.com/aws/aws-sdk-go-v2/service/s3/internal/customizations.(*s3ObjectLambdaEndpoint).HandleSerialize:34
github.com/aws/smithy-go/middleware.decoratedSerializeHandler.HandleSerialize:208
github.com/aws/aws-sdk-go-v2/service/s3/internal/customizations.(*processARNResource).HandleSerialize:56
github.com/aws/smithy-go/middleware.decoratedSerializeHandler.HandleSerialize:208
github.com/aws/aws-sdk-go-v2/service/s3.(*ResolveEndpoint).HandleSerialize:116
github.com/aws/smithy-go/middleware.decoratedSerializeHandler.HandleSerialize:208
github.com/aws/smithy-go/middleware.(*SerializeStep).HandleMiddleware:122
github.com/aws/smithy-go/middleware.decoratedHandler.Handle:57
github.com/aws/smithy-go/middleware.initializeWrapHandler.HandleInitialize:184
github.com/aws/aws-sdk-go-v2/service/s3.(*validateOpGetObject).HandleInitialize:910
github.com/aws/smithy-go/middleware.decoratedInitializeHandler.HandleInitialize:200
github.com/aws/smithy-go/middleware.(*setLogger).HandleInitialize:45
github.com/aws/smithy-go/middleware.decoratedInitializeHandler.HandleInitialize:200
github.com/aws/aws-sdk-go-v2/aws/middleware.RegisterServiceMetadata.HandleInitialize:40
github.com/aws/smithy-go/middleware.decoratedInitializeHandler.HandleInitialize:200
github.com/aws/aws-sdk-go-v2/service/internal/checksum.(*setupOutputContext).HandleInitialize:95
github.com/aws/smithy-go/middleware.decoratedInitializeHandler.HandleInitialize:200
github.com/aws/aws-sdk-go-v2/service/internal/s3shared.(*ARNLookup).HandleInitialize:39
github.com/aws/smithy-go/middleware.decoratedInitializeHandler.HandleInitialize:200
github.com/aws/smithy-go/middleware.(*InitializeStep).HandleMiddleware:114
github.com/aws/smithy-go/middleware.decoratedHandler.Handle:57
github.com/aws/smithy-go/middleware.(*Stack).HandleMiddleware:109
github.com/aws/smithy-go/middleware.decoratedHandler.Handle:57
github.com/aws/aws-sdk-go-v2/service/s3.(*Client).invokeOperation:237
github.com/aws/aws-sdk-go-v2/service/s3.(*Client).GetObject:114
github.com/matrixorigin/matrixone/pkg/fileservice.(*S3FS).s3GetObject.func3.1:1176
github.com/matrixorigin/matrixone/pkg/fileservice.doWithRetry[...]:30
github.com/matrixorigin/matrixone/pkg/fileservice.(*S3FS).s3GetObject.func3:1173
github.com/matrixorigin/matrixone/pkg/fileservice.newRetryableReader:33
github.com/matrixorigin/matrixone/pkg/fileservice.(*S3FS).s3GetObject:1164
github.com/matrixorigin/matrixone/pkg/fileservice.(*S3FS).read.func1:556
github.com/matrixorigin/matrixone/pkg/fileservice.(*S3FS).read.func2:591
github.com/matrixorigin/matrixone/pkg/fileservice.(*S3FS).read.func3:631
github.com/matrixorigin/matrixone/pkg/fileservice.(*S3FS).read:703
github.com/matrixorigin/matrixone/pkg/fileservice.(*S3FS).Read:465
github.com/matrixorigin/matrixone/pkg/objectio.ReadExtent:48
github.com/matrixorigin/matrixone/pkg/objectio.LoadObjectMetaByExtent:149
github.com/matrixorigin/matrixone/pkg/objectio.FastLoadObjectMeta:196
github.com/matrixorigin/matrixone/pkg/vm/engine/disttae.getInfoFromZoneMap:110
github.com/matrixorigin/matrixone/pkg/vm/engine/disttae.CalcStats:179
github.com/matrixorigin/matrixone/pkg/vm/engine/disttae.(*txnTable).Stats:89
github.com/matrixorigin/matrixone/pkg/frontend.(*TxnCompilerContext).Stats:707
github.com/matrixorigin/matrixone/pkg/sql/plan.calcScanStats:720
github.com/matrixorigin/matrixone/pkg/sql/plan.ReCalcNodeStats:672
github.com/matrixorigin/matrixone/pkg/sql/plan.(*QueryBuilder).appendNode:2447
github.com/matrixorigin/matrixone/pkg/sql/plan.(*QueryBuilder).buildTable:2913
github.com/matrixorigin/matrixone/pkg/sql/plan.(*QueryBuilder).buildTable:2945
github.com/matrixorigin/matrixone/pkg/sql/plan.(*QueryBuilder).buildTable:2923
github.com/matrixorigin/matrixone/pkg/sql/plan.(*QueryBuilder).buildFrom:2466
github.com/matrixorigin/matrixone/pkg/sql/plan.(*QueryBuilder).buildSelect:1947
github.com/matrixorigin/matrixone/pkg/sql/plan.runBuildSelectByBinder:31
github.com/matrixorigin/matrixone/pkg/sql/plan.BuildPlan:64
github.com/matrixorigin/matrixone/pkg/sql/plan.(*BaseOptimizer).Optimize:56
github.com/matrixorigin/matrixone/pkg/sql/plan.getPreparePlan:41
github.com/matrixorigin/matrixone/pkg/sql/plan.buildPrepare:63
github.com/matrixorigin/matrixone/pkg/sql/plan.BuildPlan:164
github.com/matrixorigin/matrixone/pkg/frontend.buildPlan:1630
github.com/matrixorigin/matrixone/pkg/frontend.doPrepareStmt:1107
github.com/matrixorigin/matrixone/pkg/frontend.(*MysqlCmdExecutor).handlePrepareStmt:1126
github.com/matrixorigin/matrixone/pkg/frontend.(*MysqlCmdExecutor).executeStmt:2848
github.com/matrixorigin/matrixone/pkg/frontend.(*MysqlCmdExecutor).doComQuery:3584
github.com/matrixorigin/matrixone/pkg/frontend.(*MysqlCmdExecutor).ExecRequest:3776
github.com/matrixorigin/matrixone/pkg/frontend.(*Routine).handleRequest:218
github.com/matrixorigin/matrixone/pkg/frontend.(*RoutineManager).Handler:482

Expected Behavior

New connection can be established to CN.

Steps to Reproduce

MO Cloud, run TPCH 1G Q22 twice.

Additional information

full trace file: trace2.log

About this issue

  • Original URL
  • State: closed
  • Created 10 months ago
  • Comments: 48 (48 by maintainers)

Most upvoted comments

goroutines when hanging forever. 截屏2023-09-25 13 58 03