tidbTestSerialSuite.TestTLS takes more then 3 seconds

[zhouqiang-cl]

Bug Report

Please answer these questions before submitting your issue. Thanks!

[2021-08-06T02:30:41.127Z] grep '^PASS:' gotest.log | go run tools/check/check-timeout.go || { $(find $PWD/ -type d | grep -vE "(\.git|tools)" | xargs tools/bin/failpoint-ctl disable); exit 1; }

[2021-08-06T02:30:41.127Z] The following test cases take too long to finish:

[2021-08-06T02:30:41.127Z] PASS: tidb_test.go:874: tidbTestSerialSuite.TestTLS	9.182s

1. Minimal reproduce step (Required)

in ci https://ci.pingcap.net/blue/organizations/jenkins/tidb_ghpr_check_2/detail/tidb_ghpr_check_2/23436/pipeline

2. What did you expect to see? (Required)

3. What did you see instead (Required)

4. What is your TiDB version? (Required)

[dveeden]

$ for i in {0..9}; do go test -check.f '\.TestTLS$' | egrep '^PASS: '; done;
PASS: tidb_test.go:874: tidbTestSerialSuite.TestTLS	0.978s
PASS: tidb_test.go:874: tidbTestSerialSuite.TestTLS	1.499s
PASS: tidb_test.go:874: tidbTestSerialSuite.TestTLS	2.598s
PASS: tidb_test.go:874: tidbTestSerialSuite.TestTLS	2.562s
PASS: tidb_test.go:874: tidbTestSerialSuite.TestTLS	1.214s
PASS: tidb_test.go:874: tidbTestSerialSuite.TestTLS	1.381s
PASS: tidb_test.go:874: tidbTestSerialSuite.TestTLS	3.096s
PASS: tidb_test.go:874: tidbTestSerialSuite.TestTLS	1.571s
PASS: tidb_test.go:874: tidbTestSerialSuite.TestTLS	1.166s
PASS: tidb_test.go:874: tidbTestSerialSuite.TestTLS	1.359s

Some ideas and observations:

• TestTLS has three parts:
  • Without TLS: No TLS certificates configured: Let the server generate TLS certificates
  • With TLS, but no CA: One-way TLS
  • With TLS and CA: mTLS
• We could split this into three tests
• With separate tests it would be easier to spot which one is slow and each of these is more likely to stay under 3s
• The call to generateCert is part of TestTLS, this could be done in SetUp/TrearDownSuite instead.
• It might be possible to re-use some certificates more often.

[zhouqiang-cl]

$ for i in {0..9}; do go test -check.f '\.TestTLS$' | egrep '^PASS: '; done;
PASS: tidb_test.go:874: tidbTestSerialSuite.TestTLS	0.978s
PASS: tidb_test.go:874: tidbTestSerialSuite.TestTLS	1.499s
PASS: tidb_test.go:874: tidbTestSerialSuite.TestTLS	2.598s
PASS: tidb_test.go:874: tidbTestSerialSuite.TestTLS	2.562s
PASS: tidb_test.go:874: tidbTestSerialSuite.TestTLS	1.214s
PASS: tidb_test.go:874: tidbTestSerialSuite.TestTLS	1.381s
PASS: tidb_test.go:874: tidbTestSerialSuite.TestTLS	3.096s
PASS: tidb_test.go:874: tidbTestSerialSuite.TestTLS	1.571s
PASS: tidb_test.go:874: tidbTestSerialSuite.TestTLS	1.166s
PASS: tidb_test.go:874: tidbTestSerialSuite.TestTLS	1.359s

Some ideas and observations:

• TestTLS has three parts:

  • Without TLS: No TLS certificates configured: Let the server generate TLS certificates
  • With TLS, but no CA: One-way TLS
  • With TLS and CA: mTLS

• We could split this into three tests

• With separate tests it would be easier to spot which one is slow and each of these is more likely to stay under 3s

• The call to generateCert is part of TestTLS, this could be done in SetUp/TrearDownSuite instead.

• It might be possible to re-use some certificates more often.

great, and I think split this into three tests can be much help

[dveeden]

I looked into why the automatic creation (the first case after splitting TestTLS) is taking so long. Without proper profiling but just with a few extra log statements it show this:

[2021/08/11 09:22:42.873 +02:00] [INFO] [misc.go:593] ["TLS Certificates: Start"]
[2021/08/11 09:22:45.049 +02:00] [INFO] [misc.go:599] ["TLS Certificates: RSA privkey created"]
[2021/08/11 09:22:45.049 +02:00] [INFO] [misc.go:618] ["TLS Certificates: template created"]
[2021/08/11 09:22:45.059 +02:00] [INFO] [misc.go:625] ["TLS Certificates: cert created"]
[2021/08/11 09:22:45.059 +02:00] [INFO] [misc.go:637] ["TLS Certificates: cert encoded and written out"]
[2021/08/11 09:22:45.060 +02:00] [INFO] [misc.go:656] ["TLS Certificates: key encoded and written out"]

The generateCert that is only called in testing calls rsa.GenerateKey to create a 528 bits key and createTLSCertificates that is used outside of testing for AutoTLS calls this to create a 4096 bits key.

[dveeden]

What about something like this: dveeden@db99386 ?
This adds a setting for the RSA key size.

I don't like having more settings just for this. Is there some other way how we can override the keysize just for testing?

[zhouqiang-cl]

What about something like this: dveeden@db99386 ?
This adds a setting for the RSA key size.

I don't like having more settings just for this. Is there some other way how we can override the keysize just for testing?

I am sorry, I don't know how to answer it

[dveeden]

@morgo @tiancaiamao What is your opinion on adding a setting? Is there a better way to do this? Maybe build constraints that set a constant to 4096 for regular builds and to 528 when doing testing?

[ti-srebot]

Please edit this comment or add a new comment to complete the following information

Not a bug

1. Remove the 'type/bug' label
2. Add notes to indicate why it is not a bug

Duplicate bug

1. Add the 'type/duplicate' label
2. Add the link to the original bug

Bug

Note: Make Sure that 'component', and 'severity' labels are added
Example for how to fill out the template: #20100

1. Root Cause Analysis (RCA) (optional)

2. Symptom (optional)

3. All Trigger Conditions (optional)

4. Workaround (optional)

5. Affected versions

6. Fixed versions