search

hashicorp / consul

Consul is a distributed, highly available, and data center aware solution to connect and configure applications across dynamic, distributed infrastructure.
https://www.consul.io
Other
28.1k stars 4.4k forks source link

unflake agent/consul TestConnectCAConfig_GetSetForceNoCrossSigning #7132

Open mkcp opened 4 years ago

mkcp commented 4 years ago

Overview of the Issue

https://github.com/hashicorp/consul/blob/b6219106188717a8813686030d6ddce256a9b3c6/agent/consul/connect_ca_endpoint_test.go#L150

Strangely enough this only seems to have a chance of breaking when running all of the agent/consul tests at once... could be shared state between them or some kind of resource starvation? Need to run it again w/ make test-flake.

Reproduction Steps

Test flake first occurred running the entire ./agent/consul suite gotestsum -f short-verbose -- ./agent/consul -timeout 0

Running: gotestsum -f short-verbose -- ./agent/consul -run TestConnectCAConfig_GetSetForceNoCrossSigning -timeout 0 -count 1000 was not enough to get a fail. Need to try to repro with make test-flake

Operating system and Environment details

macOS 10.14.6

Log Fragments

Logs from local run:

=== FAIL: agent/consul TestConnectCAConfig_GetSetForceNoCrossSigning (1.27s)
=== PAUSE TestConnectCAConfig_GetSetForceNoCrossSigning
=== CONT  TestConnectCAConfig_GetSetForceNoCrossSigning
    log.go:172: TestConnectCAConfig_GetSetForceNoCrossSigning-node-245 - 2020/01/24 14:44:20.200633 [DEBUG] tlsutil: Update with version 1
    log.go:172: TestConnectCAConfig_GetSetForceNoCrossSigning-node-245 - 2020/01/24 14:44:20.201076 [DEBUG] tlsutil: OutgoingRPCWrapper with version 1
    writer.go:21: 2020/01/24 14:44:20 [INFO]  raft: initial configuration: index=1 servers="[{Suffrage:Voter ID:fb1297cb-23a2-2f58-37c5-40d6dad29b68 Address:127.0.0.1:11818}]"
    writer.go:21: 2020/01/24 14:44:20 [INFO]  raft: entering follower state: follower="Node at 127.0.0.1:11818 [Follower]" leader=
    log.go:172: TestConnectCAConfig_GetSetForceNoCrossSigning-node-245 - 2020/01/24 14:44:20.501610 [INFO] serf: EventMemberJoin: TestConnectCAConfig_GetSetForceNoCrossSigning-node-245.dc1 127.0.0.1
    log.go:172: TestConnectCAConfig_GetSetForceNoCrossSigning-node-245 - 2020/01/24 14:44:20.508996 [INFO] serf: EventMemberJoin: TestConnectCAConfig_GetSetForceNoCrossSigning-node-245 127.0.0.1
    log.go:172: TestConnectCAConfig_GetSetForceNoCrossSigning-node-245 - 2020/01/24 14:44:20.509218 [INFO] consul: Handled member-join event for server "TestConnectCAConfig_GetSetForceNoCrossSigning-node-245.dc1" in area "wan"
    log.go:172: TestConnectCAConfig_GetSetForceNoCrossSigning-node-245 - 2020/01/24 14:44:20.509278 [INFO] consul: Adding LAN server TestConnectCAConfig_GetSetForceNoCrossSigning-node-245 (Addr: tcp/127.0.0.1:11818) (DC: dc1)
    writer.go:21: 2020/01/24 14:44:20 [WARN]  raft: heartbeat timeout reached, starting election: last-leader=
    writer.go:21: 2020/01/24 14:44:20 [INFO]  raft: entering candidate state: node="Node at 127.0.0.1:11818 [Candidate]" term=2
    writer.go:21: 2020/01/24 14:44:20 [INFO]  raft: election won: tally=1
    writer.go:21: 2020/01/24 14:44:20 [INFO]  raft: entering leader state: leader="Node at 127.0.0.1:11818 [Leader]"
    log.go:172: TestConnectCAConfig_GetSetForceNoCrossSigning-node-245 - 2020/01/24 14:44:20.777362 [INFO] consul: cluster leadership acquired
    log.go:172: TestConnectCAConfig_GetSetForceNoCrossSigning-node-245 - 2020/01/24 14:44:20.777480 [INFO] consul: New leader elected: TestConnectCAConfig_GetSetForceNoCrossSigning-node-245
    log.go:172: TestConnectCAConfig_GetSetForceNoCrossSigning-node-245 - 2020/01/24 14:44:20.945776 [DEBUG] tlsutil: OutgoingRPCWrapper with version 1
    log.go:172: TestConnectCAConfig_GetSetForceNoCrossSigning-node-245 - 2020/01/24 14:44:20.951599 [DEBUG] consul CA provider configured ID=07:80:c8:de:f6:41:86:29:8f:9c:b8:17:d6:48:c2:d5:c5:5c:7f:0c:03:f7:cf:97:5a:a7:c1:68:aa:23:ae:81 IsPrimary=true
    log.go:172: TestConnectCAConfig_GetSetForceNoCrossSigning-node-245 - 2020/01/24 14:44:21.116570 [INFO] connect: initialized primary datacenter CA with provider "consul"
    log.go:172: TestConnectCAConfig_GetSetForceNoCrossSigning-node-245 - 2020/01/24 14:44:21.116646 [INFO] leader: started CA root pruning routine
    log.go:172: TestConnectCAConfig_GetSetForceNoCrossSigning-node-245 - 2020/01/24 14:44:21.116773 [DEBUG] consul: Skipping self join check for "TestConnectCAConfig_GetSetForceNoCrossSigning-node-245" since the cluster is too small
    log.go:172: TestConnectCAConfig_GetSetForceNoCrossSigning-node-245 - 2020/01/24 14:44:21.116842 [INFO] consul: member 'TestConnectCAConfig_GetSetForceNoCrossSigning-node-245' joined, marking health alive
    log.go:172: TestConnectCAConfig_GetSetForceNoCrossSigning-node-245 - 2020/01/24 14:44:21.174415 [DEBUG] consul: Skipping self join check for "TestConnectCAConfig_GetSetForceNoCrossSigning-node-245" since the cluster is too small
    log.go:172: TestConnectCAConfig_GetSetForceNoCrossSigning-node-245 - 2020/01/24 14:44:21.201936 [DEBUG] consul CA provider configured ID=33:41:c3:80:0b:41:ed:06:31:34:85:33:ac:f9:e8:89:04:4f:64:fd:e8:59:8e:ce:b9:38:c2:85:3b:ac:7d:6e IsPrimary=true
    log.go:172: TestConnectCAConfig_GetSetForceNoCrossSigning-node-245 - 2020/01/24 14:44:21.256793 [WARN] current CA doesn't support cross signing but CA reconfiguration forced anyway with ForceWithoutCrossSigning
    log.go:172: TestConnectCAConfig_GetSetForceNoCrossSigning-node-245 - 2020/01/24 14:44:21.318524 [INFO] connect: pruning old unused root CA (ID: 34:04:3b:84:27:54:ae:ef:0d:ac:39:5b:90:81:8d:f1:45:77:23:93)
    log.go:172: TestConnectCAConfig_GetSetForceNoCrossSigning-node-245 - 2020/01/24 14:44:21.347759 [INFO] connect: CA rotated to new root under provider "consul"
    require.go:738: 
            Error Trace:    connect_ca_endpoint_test.go:232
            Error:          "[%!s(*structs.CARoot=&{a7:23:6d:ca:02:11:95:59:82:0b:38:39:8c:57:b0:3f:ff:36:4e:09 Consul CA Root Cert 8 fa:09:9c:03:db:3e:b5:f6:2c:fd:a1:d3:e3:37:78:84:01:d1:b6:f6:19:47:b3:bb:2c:6f:39:17:05:a6:dc:d8 11111111-2222-3333-4444-555555555555 {0 63715502661 <nil>} {0 64031121861 <nil>} -----BEGIN CERTIFICATE-----
                            MIICDTCCAbOgAwIBAgIBCDAKBggqhkjOPQQDAjAwMS4wLAYDVQQDEyVwcmkteGlr
                            bGFiZy5jb25zdWwuY2EuMTExMTExMTEuY29uc3VsMB4XDTIwMDEyNDIyNDQyMVoX
                            DTMwMDEyNDIyNDQyMVowMDEuMCwGA1UEAxMlcHJpLXhpa2xhYmcuY29uc3VsLmNh
                            LjExMTExMTExLmNvbnN1bDBZMBMGByqGSM49AgEGCCqGSM49AwEHA0IABK1nhG/T
                            /C+fOKNXfy7BFXjvTyd6KnZ2S+WHVY8Mqdx5BlIDztSWQcQphRWYaHuMCbOlEQ/g
                            Nd+HtzpZn1rl3a2jgb0wgbowDgYDVR0PAQH/BAQDAgGGMA8GA1UdEwEB/wQFMAMB
                            Af8wKQYDVR0OBCIEIPoJnAPbPrX2LP2h0+M3eIQB0bb2GUezuyxvORcFptzYMCsG
                            A1UdIwQkMCKAIPoJnAPbPrX2LP2h0+M3eIQB0bb2GUezuyxvORcFptzYMD8GA1Ud
                            EQQ4MDaGNHNwaWZmZTovLzExMTExMTExLTIyMjItMzMzMy00NDQ0LTU1NTU1NTU1
                            NTU1NS5jb25zdWwwCgYIKoZIzj0EAwIDSAAwRQIhAPtAR/OvX+7toGDuGLDZgJPf
                            +IxkK7fGx8Sitixyw65XAiB2xY5rHZKN0+1rRD+Kwbu12t2C52NTjE4E7d5I9EoD
                            7g==
                            -----END CERTIFICATE-----
                             []   true {0 0 <nil>} ec 256 {15 17}})]" should have 2 item(s), but has 1
            Test:           TestConnectCAConfig_GetSetForceNoCrossSigning
    log.go:172: TestConnectCAConfig_GetSetForceNoCrossSigning-node-245 - 2020/01/24 14:44:21.348801 [INFO] consul: shutting down server
    log.go:172: TestConnectCAConfig_GetSetForceNoCrossSigning-node-245 - 2020/01/24 14:44:21.348880 [DEBUG] leader: stopping CA root pruning routine
    log.go:172: TestConnectCAConfig_GetSetForceNoCrossSigning-node-245 - 2020/01/24 14:44:21.348924 [WARN] serf: Shutdown without a Leave
    log.go:172: TestConnectCAConfig_GetSetForceNoCrossSigning-node-245 - 2020/01/24 14:44:21.348947 [DEBUG] leader: stopped CA root pruning routine
    log.go:172: TestConnectCAConfig_GetSetForceNoCrossSigning-node-245 - 2020/01/24 14:44:21.369374 [WARN] serf: Shutdown without a Leave
    log.go:172: TestConnectCAConfig_GetSetForceNoCrossSigning-node-245 - 2020/01/24 14:44:21.383947 [INFO] manager: shutting down
mkcp commented 4 years ago

Related #7042