Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

*: should return exitCode even if cmd isn't nil #16137

Merged
merged 1 commit into from
Jun 26, 2023

Conversation

fuweid
Copy link
Member

@fuweid fuweid commented Jun 25, 2023

For the pkg/expect package, if the process has been stopped but there is no Close() call, the ExitCode() won't return exit code correctly. The ExitCode() should check exitErr and return exit code if cmd isn't nil.

And introduces exitCode to return correct exit code based on the process is signaled or exited.

Please read https://github.com/etcd-io/etcd/blob/main/CONTRIBUTING.md#contribution-flow.


Context: #16094 (comment)

cc @serathius @tjungblu

fixes: #16134

For the pkg/expect package, if the process has been stopped but there is
no `Close()` call, the `ExitCode()` won't return exit code correctly.
The `ExitCode()` should check `exitErr` and return exit code if cmd isn't nil.

And introduces `exitCode` to return correct exit code based on the
process is signaled or exited.

Signed-off-by: Wei Fu <fuweid89@gmail.com>
@fuweid
Copy link
Member Author

fuweid commented Jun 25, 2023

2023-06-25T02:49:32.3289837Z === RUN   TestV3CurlCipherSuitesMismatch
2023-06-25T02:49:32.3290272Z     before.go:36: Changing working directory to: /tmp/TestV3CurlCipherSuitesMismatch741203529/001
2023-06-25T02:49:32.3290849Z     logger.go:130: 2023-06-25T02:49:32.223Z	INFO	starting server...	{"name": "TestV3CurlCipherSuitesMismatch-test-0"}
2023-06-25T02:49:32.3298152Z     logger.go:130: 2023-06-25T02:49:32.223Z	INFO	spawning process	{"args": ["/home/runner/work/etcd/etcd/bin/etcd", "--name", "TestV3CurlCipherSuitesMismatch-test-0", "--listen-client-urls", "https://localhost:20000", "--advertise-client-urls", "https://localhost:20000", "--listen-peer-urls", "http://localhost:20001", "--initial-advertise-peer-urls", "http://localhost:20001", "--initial-cluster-token", "new", "--data-dir", "/tmp/TestV3CurlCipherSuitesMismatch741203529/002", "--snapshot-count", "10000", "--experimental-initial-corrupt-check", "--cert-file", "/home/runner/work/etcd/etcd/tests/fixtures/server.crt", "--key-file", "/home/runner/work/etcd/etcd/tests/fixtures/server.key.insecure", "--trusted-ca-file", "/home/runner/work/etcd/etcd/tests/fixtures/ca.crt", "--cipher-suites", "TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256,TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384,TLS_ECDHE_ECDSA_WITH_AES_128_GCM_SHA256,TLS_ECDHE_ECDSA_WITH_AES_256_GCM_SHA384,TLS_ECDHE_RSA_WITH_CHACHA20_POLY1305,TLS_ECDHE_ECDSA_WITH_CHACHA20_POLY1305", "--initial-cluster", "TestV3CurlCipherSuitesMismatch-test-0=http://localhost:20001", "--initial-cluster-state", "new"], "working-dir": "/tmp/TestV3CurlCipherSuitesMismatch741203529/001", "name": "TestV3CurlCipherSuitesMismatch-test-0", "environment-variables": ["ETCD_VERIFY=all", "EXPECT_DEBUG=true", "PATH=/opt/hostedtoolcache/go/1.19.10/x64/bin:/home/runner/go/bin:/opt/hostedtoolcache/go/1.19.10/x64/bin:/home/runner/.local/bin:/opt/pipx_bin:/home/runner/.cargo/bin:/home/runner/.config/composer/vendor/bin:/usr/local/.ghcup/bin:/home/runner/.dotnet/tools:/snap/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/games:/usr/local/games:/snap/bin", "ETCD_UNSUPPORTED_ARCH=386"]}
2023-06-25T02:49:32.3299143Z /home/runner/work/etcd/etcd/bin/etcd (TestV3CurlCipherSuitesMismatch-test-0) (23987): {"level":"info","ts":"2023-06-25T02:49:32.243574Z","caller":"etcdmain/etcd.go:274","msg":"running etcd on unsupported architecture since ETCD_UNSUPPORTED_ARCH is set","arch":"386"}
2023-06-25T02:49:32.3300016Z /home/runner/work/etcd/etcd/bin/etcd (TestV3CurlCipherSuitesMismatch-test-0) (23987): {"level":"warn","ts":"2023-06-25T02:49:32.244575Z","caller":"flags/flag.go:93","msg":"unrecognized environment variable","environment-variable":"ETCD_VERIFY=all"}
2023-06-25T02:49:32.3300900Z /home/runner/work/etcd/etcd/bin/etcd (TestV3CurlCipherSuitesMismatch-test-0) (23987): {"level":"warn","ts":"2023-06-25T02:49:32.244781Z","caller":"embed/config.go:708","msg":"Running http and grpc server on single port. This is not recommended for production."}
2023-06-25T02:49:32.3304882Z /home/runner/work/etcd/etcd/bin/etcd (TestV3CurlCipherSuitesMismatch-test-0) (23987): {"level":"info","ts":"2023-06-25T02:49:32.244896Z","caller":"etcdmain/etcd.go:64","msg":"Running: ","args":["/home/runner/work/etcd/etcd/bin/etcd","--name","TestV3CurlCipherSuitesMismatch-test-0","--listen-client-urls","https://localhost:20000","--advertise-client-urls","https://localhost:20000","--listen-peer-urls","http://localhost:20001","--initial-advertise-peer-urls","http://localhost:20001","--initial-cluster-token","new","--data-dir","/tmp/TestV3CurlCipherSuitesMismatch741203529/002","--snapshot-count","10000","--experimental-initial-corrupt-check","--cert-file","/home/runner/work/etcd/etcd/tests/fixtures/server.crt","--key-file","/home/runner/work/etcd/etcd/tests/fixtures/server.key.insecure","--trusted-ca-file","/home/runner/work/etcd/etcd/tests/fixtures/ca.crt","--cipher-suites","TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256,TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384,TLS_ECDHE_ECDSA_WITH_AES_128_GCM_SHA256,TLS_ECDHE_ECDSA_WITH_AES_256_GCM_SHA384,TLS_ECDHE_RSA_WITH_CHACHA20_POLY1305,TLS_ECDHE_ECDSA_WITH_CHACHA20_POLY1305","--initial-cluster","TestV3CurlCipherSuitesMismatch-test-0=http://localhost:20001","--initial-cluster-state","new"]}
2023-06-25T02:49:32.3305954Z /home/runner/work/etcd/etcd/bin/etcd (TestV3CurlCipherSuitesMismatch-test-0) (23987): {"level":"info","ts":"2023-06-25T02:49:32.24504Z","caller":"etcdmain/etcd.go:124","msg":"Initialize and start etcd server","data-dir":"/tmp/TestV3CurlCipherSuitesMismatch741203529/002","dir-type":"empty"}
2023-06-25T02:49:32.3306839Z /home/runner/work/etcd/etcd/bin/etcd (TestV3CurlCipherSuitesMismatch-test-0) (23987): {"level":"warn","ts":"2023-06-25T02:49:32.245173Z","caller":"embed/config.go:708","msg":"Running http and grpc server on single port. This is not recommended for production."}
2023-06-25T02:49:32.3307712Z /home/runner/work/etcd/etcd/bin/etcd (TestV3CurlCipherSuitesMismatch-test-0) (23987): {"level":"info","ts":"2023-06-25T02:49:32.245261Z","caller":"embed/etcd.go:125","msg":"configuring peer listeners","listen-peer-urls":["http://localhost:20001"]}
2023-06-25T02:49:32.3308578Z /home/runner/work/etcd/etcd/bin/etcd (TestV3CurlCipherSuitesMismatch-test-0) (23987): {"level":"info","ts":"2023-06-25T02:49:32.245932Z","caller":"embed/etcd.go:133","msg":"configuring client listeners","listen-client-urls":["https://localhost:20000"]}
2023-06-25T02:49:32.3314988Z /home/runner/work/etcd/etcd/bin/etcd (TestV3CurlCipherSuitesMismatch-test-0) (23987): {"level":"info","ts":"2023-06-25T02:49:32.246295Z","caller":"embed/etcd.go:313","msg":"starting an etcd server","etcd-version":"3.6.0-alpha.0","git-sha":"fcfdab9","go-version":"go1.19.10","go-os":"linux","go-arch":"386","max-cpu-set":2,"max-cpu-available":2,"member-initialized":false,"name":"TestV3CurlCipherSuitesMismatch-test-0","data-dir":"/tmp/TestV3CurlCipherSuitesMismatch741203529/002","wal-dir":"","wal-dir-dedicated":"","member-dir":"/tmp/TestV3CurlCipherSuitesMismatch741203529/002/member","force-new-cluster":false,"heartbeat-interval":"100ms","election-timeout":"1s","wait-cluster-ready-timeout":"5s","initial-election-tick-advance":true,"snapshot-count":10000,"max-wals":5,"max-snapshots":5,"snapshot-catchup-entries":5000,"initial-advertise-peer-urls":["http://localhost:20001"],"listen-peer-urls":["http://localhost:20001"],"advertise-client-urls":["https://localhost:20000"],"listen-client-urls":["https://localhost:20000"],"listen-metrics-urls":[],"cors":["*"],"host-whitelist":["*"],"initial-cluster":"TestV3CurlCipherSuitesMismatch-test-0=http://localhost:20001","initial-cluster-state":"new","initial-cluster-token":"new","quota-backend-bytes":2147483648,"max-request-bytes":1572864,"max-concurrent-streams":4294967295,"pre-vote":true,"initial-corrupt-check":true,"corrupt-check-time-interval":"0s","compact-check-time-enabled":false,"compact-check-time-interval":"1m0s","auto-compaction-mode":"periodic","auto-compaction-retention":"0s","auto-compaction-interval":"0s","discovery-url":"","discovery-proxy":"","discovery-token":"","discovery-endpoints":"","discovery-dial-timeout":"2s","discovery-request-timeout":"5s","discovery-keepalive-time":"2s","discovery-keepalive-timeout":"6s","discovery-insecure-transport":true,"discovery-insecure-skip-tls-verify":false,"discovery-cert":"","discovery-key":"","discovery-cacert":"","discovery-user":"","downgrade-check-interval":"5s","max-learners":1}
2023-06-25T02:49:32.3315999Z /home/runner/work/etcd/etcd/bin/etcd (TestV3CurlCipherSuitesMismatch-test-0) (23987): {"level":"info","ts":"2023-06-25T02:49:32.251172Z","caller":"storage/backend.go:80","msg":"opened backend db","path":"/tmp/TestV3CurlCipherSuitesMismatch741203529/002/member/snap/db","took":"4.247113ms"}
2023-06-25T02:49:32.3316906Z /home/runner/work/etcd/etcd/bin/etcd (TestV3CurlCipherSuitesMismatch-test-0) (23987): {"level":"info","ts":"2023-06-25T02:49:32.254082Z","caller":"etcdserver/bootstrap.go:493","msg":"starting local member","local-member-id":"ca50e9357181d758","cluster-id":"34f27e83b3bc2ff"}
2023-06-25T02:49:32.3317981Z /home/runner/work/etcd/etcd/bin/etcd (TestV3CurlCipherSuitesMismatch-test-0) (23987): {"level":"info","ts":"2023-06-25T02:49:32.254335Z","logger":"raft","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/raft.go:1697","msg":"ca50e9357181d758 switched to configuration voters=()"}
2023-06-25T02:49:32.3318852Z /home/runner/work/etcd/etcd/bin/etcd (TestV3CurlCipherSuitesMismatch-test-0) (23987): {"level":"info","ts":"2023-06-25T02:49:32.254472Z","logger":"raft","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/raft.go:728","msg":"ca50e9357181d758 became follower at term 0"}
2023-06-25T02:49:32.3319844Z /home/runner/work/etcd/etcd/bin/etcd (TestV3CurlCipherSuitesMismatch-test-0) (23987): {"level":"info","ts":"2023-06-25T02:49:32.254578Z","logger":"raft","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/raft.go:382","msg":"newRaft ca50e9357181d758 [peers: [], term: 0, commit: 0, applied: 0, lastindex: 0, lastterm: 0]"}
2023-06-25T02:49:32.3320711Z /home/runner/work/etcd/etcd/bin/etcd (TestV3CurlCipherSuitesMismatch-test-0) (23987): {"level":"info","ts":"2023-06-25T02:49:32.256967Z","logger":"raft","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/raft.go:728","msg":"ca50e9357181d758 became follower at term 1"}
2023-06-25T02:49:32.3321660Z /home/runner/work/etcd/etcd/bin/etcd (TestV3CurlCipherSuitesMismatch-test-0) (23987): {"level":"info","ts":"2023-06-25T02:49:32.257203Z","logger":"raft","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/raft.go:1697","msg":"ca50e9357181d758 switched to configuration voters=(14578408409545168728)"}
2023-06-25T02:49:32.3322521Z /home/runner/work/etcd/etcd/bin/etcd (TestV3CurlCipherSuitesMismatch-test-0) (23987): {"level":"warn","ts":"2023-06-25T02:49:32.259668Z","caller":"auth/store.go:1123","msg":"simple token is not cryptographically signed"}
2023-06-25T02:49:32.3323254Z /home/runner/work/etcd/etcd/bin/etcd (TestV3CurlCipherSuitesMismatch-test-0) (23987): {"level":"info","ts":"2023-06-25T02:49:32.26118Z","caller":"mvcc/kvstore.go:402","msg":"kvstore restored","current-rev":1}
2023-06-25T02:49:32.3324291Z /home/runner/work/etcd/etcd/bin/etcd (TestV3CurlCipherSuitesMismatch-test-0) (23987): {"level":"info","ts":"2023-06-25T02:49:32.262382Z","caller":"storage/quota.go:93","msg":"enabled backend quota with default value","quota-name":"v3-applier","quota-size-bytes":2147483648,"quota-size":"2.1 GB"}
2023-06-25T02:49:32.3325335Z /home/runner/work/etcd/etcd/bin/etcd (TestV3CurlCipherSuitesMismatch-test-0) (23987): {"level":"info","ts":"2023-06-25T02:49:32.26256Z","caller":"etcdserver/server.go:583","msg":"starting etcd server","local-member-id":"ca50e9357181d758","local-server-version":"3.6.0-alpha.0","cluster-version":"to_be_decided"}
2023-06-25T02:49:32.3327495Z /home/runner/work/etcd/etcd/bin/etcd (TestV3CurlCipherSuitesMismatch-test-0) (23987): {"level":"info","ts":"2023-06-25T02:49:32.262759Z","caller":"embed/etcd.go:734","msg":"starting with client TLS","tls-info":"cert = /home/runner/work/etcd/etcd/tests/fixtures/server.crt, key = /home/runner/work/etcd/etcd/tests/fixtures/server.key.insecure, client-cert=, client-key=, trusted-ca = /home/runner/work/etcd/etcd/tests/fixtures/ca.crt, client-cert-auth = false, crl-file = ","cipher-suites":["TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256","TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384","TLS_ECDHE_ECDSA_WITH_AES_128_GCM_SHA256","TLS_ECDHE_ECDSA_WITH_AES_256_GCM_SHA384","TLS_ECDHE_RSA_WITH_CHACHA20_POLY1305","TLS_ECDHE_ECDSA_WITH_CHACHA20_POLY1305"]}
2023-06-25T02:49:32.3329151Z /home/runner/work/etcd/etcd/bin/etcd (TestV3CurlCipherSuitesMismatch-test-0) (23987): {"level":"info","ts":"2023-06-25T02:49:32.262966Z","caller":"embed/etcd.go:282","msg":"now serving peer/client/metrics","local-member-id":"ca50e9357181d758","initial-advertise-peer-urls":["http://localhost:20001"],"listen-peer-urls":["http://localhost:20001"],"advertise-client-urls":["https://localhost:20000"],"listen-client-urls":["https://localhost:20000"],"listen-metrics-urls":[]}
2023-06-25T02:49:32.3330544Z /home/runner/work/etcd/etcd/bin/etcd (TestV3CurlCipherSuitesMismatch-test-0) (23987): {"level":"info","ts":"2023-06-25T02:49:32.263217Z","caller":"etcdserver/server.go:468","msg":"started as single-node; fast-forwarding election ticks","local-member-id":"ca50e9357181d758","forward-ticks":9,"forward-duration":"900ms","election-ticks":10,"election-timeout":"1s"}
2023-06-25T02:49:32.3331610Z /home/runner/work/etcd/etcd/bin/etcd (TestV3CurlCipherSuitesMismatch-test-0) (23987): {"level":"info","ts":"2023-06-25T02:49:32.263315Z","caller":"fileutil/purge.go:44","msg":"started to purge file","dir":"/tmp/TestV3CurlCipherSuitesMismatch741203529/002/member/snap","suffix":"snap.db","max":5,"interval":"30s"}
2023-06-25T02:49:32.3332650Z /home/runner/work/etcd/etcd/bin/etcd (TestV3CurlCipherSuitesMismatch-test-0) (23987): {"level":"info","ts":"2023-06-25T02:49:32.263345Z","caller":"fileutil/purge.go:44","msg":"started to purge file","dir":"/tmp/TestV3CurlCipherSuitesMismatch741203529/002/member/snap","suffix":"snap","max":5,"interval":"30s"}
2023-06-25T02:49:32.3333701Z /home/runner/work/etcd/etcd/bin/etcd (TestV3CurlCipherSuitesMismatch-test-0) (23987): {"level":"info","ts":"2023-06-25T02:49:32.263363Z","caller":"fileutil/purge.go:44","msg":"started to purge file","dir":"/tmp/TestV3CurlCipherSuitesMismatch741203529/002/member/wal","suffix":"wal","max":5,"interval":"30s"}
2023-06-25T02:49:33.2621615Z /home/runner/work/etcd/etcd/bin/etcd (TestV3CurlCipherSuitesMismatch-test-0) (23987): {"level":"info","ts":"2023-06-25T02:49:32.263567Z","logger":"raft","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/raft.go:1697","msg":"ca50e9357181d758 switched to configuration voters=(14578408409545168728)"}
2023-06-25T02:49:33.2645718Z /home/runner/work/etcd/etcd/bin/etcd (TestV3CurlCipherSuitesMismatch-test-0) (23987): {"level":"info","ts":"2023-06-25T02:49:32.263805Z","caller":"membership/cluster.go:403","msg":"added member","cluster-id":"34f27e83b3bc2ff","local-member-id":"ca50e9357181d758","added-peer-id":"ca50e9357181d758","added-peer-peer-urls":["http://localhost:20001"],"added-peer-is-learner":false}
2023-06-25T02:49:33.2648160Z /home/runner/work/etcd/etcd/bin/etcd (TestV3CurlCipherSuitesMismatch-test-0) (23987): {"level":"info","ts":"2023-06-25T02:49:32.263907Z","caller":"embed/etcd.go:607","msg":"serving peer traffic","address":"127.0.0.1:20001"}
2023-06-25T02:49:33.2650429Z /home/runner/work/etcd/etcd/bin/etcd (TestV3CurlCipherSuitesMismatch-test-0) (23987): {"level":"info","ts":"2023-06-25T02:49:32.263947Z","caller":"embed/etcd.go:579","msg":"cmux::serve","address":"127.0.0.1:20001"}
2023-06-25T02:49:33.2652292Z /home/runner/work/etcd/etcd/bin/etcd (TestV3CurlCipherSuitesMismatch-test-0) (23987): {"level":"info","ts":"2023-06-25T02:49:33.258124Z","logger":"raft","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/raft.go:819","msg":"ca50e9357181d758 is starting a new election at term 1"}
2023-06-25T02:49:33.2654143Z /home/runner/work/etcd/etcd/bin/etcd (TestV3CurlCipherSuitesMismatch-test-0) (23987): {"level":"info","ts":"2023-06-25T02:49:33.258177Z","logger":"raft","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/raft.go:757","msg":"ca50e9357181d758 became pre-candidate at term 1"}
2023-06-25T02:49:33.2656040Z /home/runner/work/etcd/etcd/bin/etcd (TestV3CurlCipherSuitesMismatch-test-0) (23987): {"level":"info","ts":"2023-06-25T02:49:33.258201Z","logger":"raft","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/raft.go:879","msg":"ca50e9357181d758 received MsgPreVoteResp from ca50e9357181d758 at term 1"}
2023-06-25T02:49:33.2657611Z /home/runner/work/etcd/etcd/bin/etcd (TestV3CurlCipherSuitesMismatch-test-0) (23987): {"level":"info","ts":"2023-06-25T02:49:33.258229Z","logger":"raft","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/raft.go:741","msg":"ca50e9357181d758 became candidate at term 2"}
2023-06-25T02:49:33.2659219Z /home/runner/work/etcd/etcd/bin/etcd (TestV3CurlCipherSuitesMismatch-test-0) (23987): {"level":"info","ts":"2023-06-25T02:49:33.258244Z","logger":"raft","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/raft.go:879","msg":"ca50e9357181d758 received MsgVoteResp from ca50e9357181d758 at term 2"}
2023-06-25T02:49:33.2660745Z /home/runner/work/etcd/etcd/bin/etcd (TestV3CurlCipherSuitesMismatch-test-0) (23987): {"level":"info","ts":"2023-06-25T02:49:33.25826Z","logger":"raft","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/raft.go:797","msg":"ca50e9357181d758 became leader at term 2"}
2023-06-25T02:49:33.2662066Z /home/runner/work/etcd/etcd/bin/etcd (TestV3CurlCipherSuitesMismatch-test-0) (23987): {"level":"info","ts":"2023-06-25T02:49:33.258277Z","logger":"raft","caller":"v3@v3.0.0-20221201111702-eaa6808e1f7a/node.go:330","msg":"raft.node: ca50e9357181d758 elected leader ca50e9357181d758 at term 2"}
2023-06-25T02:49:33.2663489Z /home/runner/work/etcd/etcd/bin/etcd (TestV3CurlCipherSuitesMismatch-test-0) (23987): {"level":"info","ts":"2023-06-25T02:49:33.259335Z","caller":"etcdserver/server.go:2314","msg":"setting up initial cluster version using v3 API","cluster-version":"3.6"}
2023-06-25T02:49:33.2665518Z /home/runner/work/etcd/etcd/bin/etcd (TestV3CurlCipherSuitesMismatch-test-0) (23987): {"level":"info","ts":"2023-06-25T02:49:33.260213Z","caller":"etcdserver/server.go:1746","msg":"published local member to cluster through raft","local-member-id":"ca50e9357181d758","local-member-attributes":"{Name:TestV3CurlCipherSuitesMismatch-test-0 ClientURLs:[https://localhost:20000]}","cluster-id":"34f27e83b3bc2ff","publish-timeout":"7s"}
2023-06-25T02:49:33.2667352Z /home/runner/work/etcd/etcd/bin/etcd (TestV3CurlCipherSuitesMismatch-test-0) (23987): {"level":"info","ts":"2023-06-25T02:49:33.260661Z","caller":"membership/cluster.go:546","msg":"set initial cluster version","cluster-id":"34f27e83b3bc2ff","local-member-id":"ca50e9357181d758","cluster-version":"3.6"}
2023-06-25T02:49:33.2852783Z /home/runner/work/etcd/etcd/bin/etcd (TestV3CurlCipherSuitesMismatch-test-0) (23987): {"level":"info","ts":"2023-06-25T02:49:33.261251Z","caller":"embed/serve.go:112","msg":"ready to serve client requests"}
2023-06-25T02:49:33.2855126Z /home/runner/work/etcd/etcd/bin/etcd (TestV3CurlCipherSuitesMismatch-test-0) (23987): {"level":"info","ts":"2023-06-25T02:49:33.262009Z","caller":"etcdmain/main.go:44","msg":"notifying init daemon"}
2023-06-25T02:49:33.2858707Z /home/runner/work/etcd/etcd/bin/etcd (TestV3CurlCipherSuitesMismatch-test-0) (23987): {"level":"info","ts":"2023-06-25T02:49:33.262066Z","caller":"etcdmain/main.go:50","msg":"successfully notified init daemon"}
2023-06-25T02:49:33.2860011Z /home/runner/work/etcd/etcd/bin/etcd (TestV3CurlCipherSuitesMismatch-test-0) (23987): {"level":"info","ts":"2023-06-25T02:49:33.264622Z","caller":"api/capability.go:77","msg":"enabled capabilities for version","cluster-version":"3.6"}
2023-06-25T02:49:33.2861325Z /home/runner/work/etcd/etcd/bin/etcd (TestV3CurlCipherSuitesMismatch-test-0) (23987): {"level":"info","ts":"2023-06-25T02:49:33.264696Z","caller":"etcdserver/server.go:2334","msg":"cluster version is updated","cluster-version":"3.6"}
2023-06-25T02:49:33.2862839Z /home/runner/work/etcd/etcd/bin/etcd (TestV3CurlCipherSuitesMismatch-test-0) (23987): {"level":"info","ts":"2023-06-25T02:49:33.26488Z","caller":"version/monitor.go:116","msg":"cluster version differs from storage version.","cluster-version":"3.6.0","storage-version":"3.5.0"}
2023-06-25T02:49:33.2864240Z /home/runner/work/etcd/etcd/bin/etcd (TestV3CurlCipherSuitesMismatch-test-0) (23987): {"level":"info","ts":"2023-06-25T02:49:33.265049Z","caller":"schema/migration.go:65","msg":"updated storage version","new-storage-version":"3.6.0"}
2023-06-25T02:49:33.2865583Z /home/runner/work/etcd/etcd/bin/etcd (TestV3CurlCipherSuitesMismatch-test-0) (23987): {"level":"info","ts":"2023-06-25T02:49:33.267955Z","caller":"embed/serve.go:259","msg":"serving client traffic securely","traffic":"grpc+http","address":"127.0.0.1:20000"}
2023-06-25T02:49:33.2866881Z     logger.go:130: 2023-06-25T02:49:33.271Z	INFO	started server.	{"name": "TestV3CurlCipherSuitesMismatch-test-0", "pid": 23987}
2023-06-25T02:49:33.2868214Z /home/runner/work/etcd/etcd/bin/etcd (TestV3CurlCipherSuitesMismatch-test-0) (23987): {"level":"warn","ts":"2023-06-25T02:49:33.284282Z","caller":"embed/config_logging.go:187","msg":"rejected connection","remote-addr":"127.0.0.1:50990","server-name":"","error":"EOF"}
2023-06-25T02:49:33.2869924Z /usr/bin/curl (curl_--cacert_/home/runner/work/etcd/etcd/tests/fixtures/ca.crt_--cert_/home/runner/work/etcd/etcd/tests/fixtures/server.crt_--key_/home/runner/work/etcd/etcd/tests/fixtures/server.key.insecure_-L_https://localhost:20000/metrics_--ciphers_ECDHE-RSA-DES-CBC3-SHA) (23994): curl: (59) failed setting cipher list: ECDHE-RSA-DES-CBC3-SHA
2023-06-25T02:49:33.2871621Z     v3_cipher_suite_test.go:65: 
2023-06-25T02:49:33.2872346Z         	Error Trace:	/home/runner/work/etcd/etcd/tests/e2e/v3_cipher_suite_test.go:65
2023-06-25T02:49:33.2873430Z         	            				/home/runner/work/etcd/etcd/tests/e2e/ctl_v3_test.go:267
2023-06-25T02:49:33.2874424Z         	            				/opt/hostedtoolcache/go/1.19.10/x64/src/runtime/asm_386.s:1326
2023-06-25T02:49:33.2879016Z         	Error:      	Error "[curl --cacert /home/runner/work/etcd/etcd/tests/fixtures/ca.crt --cert /home/runner/work/etcd/etcd/tests/fixtures/server.crt --key /home/runner/work/etcd/etcd/tests/fixtures/server.key.insecure -L https://localhost:20000/metrics --ciphers ECDHE-RSA-DES-CBC3-SHA] match not found.  Set EXPECT_DEBUG for more info Errs: [unexpected exit code [59] after running [/usr/bin/curl --cacert /home/runner/work/etcd/etcd/tests/fixtures/ca.crt --cert /home/runner/work/etcd/etcd/tests/fixtures/server.crt --key /home/runner/work/etcd/etcd/tests/fixtures/server.key.insecure -L https://localhost:20000/metrics --ciphers ECDHE-RSA-DES-CBC3-SHA]], last lines:\n (expected \"failed setting cipher list\", got []). Try EXPECT_DEBUG=TRUE" does not contain "curl: (59) failed setting cipher list"
2023-06-25T02:49:33.2880894Z         	Test:       	TestV3CurlCipherSuitesMismatch
2023-06-25T02:49:33.2881379Z     ctl_v3_test.go:279: closing test cluster...
2023-06-25T02:49:33.2894387Z     logger.go:130: 2023-06-25T02:49:33.284Z	INFO	stopping server...	{"name": "TestV3CurlCipherSuitesMismatch-test-0"}
2023-06-25T02:49:33.2897204Z /home/runner/work/etcd/etcd/bin/etcd (TestV3CurlCipherSuitesMismatch-test-0) (23987): {"level":"info","ts":"2023-06-25T02:49:33.284794Z","caller":"osutil/interrupt_unix.go:65","msg":"received signal; shutting down","signal":"terminated"}
2023-06-25T02:49:33.2899229Z /home/runner/work/etcd/etcd/bin/etcd (TestV3CurlCipherSuitesMismatch-test-0) (23987): {"level":"info","ts":"2023-06-25T02:49:33.284897Z","caller":"embed/etcd.go:396","msg":"closing etcd server","name":"TestV3CurlCipherSuitesMismatch-test-0","data-dir":"/tmp/TestV3CurlCipherSuitesMismatch741203529/002","advertise-peer-urls":["http://localhost:20001"],"advertise-client-urls":["https://localhost:20000"]}
2023-06-25T02:49:33.2901870Z /home/runner/work/etcd/etcd/bin/etcd (TestV3CurlCipherSuitesMismatch-test-0) (23987): {"level":"warn","ts":"2023-06-25T02:49:33.284996Z","caller":"embed/serve.go:221","msg":"stopping secure grpc server due to error","error":"accept tcp 127.0.0.1:20000: use of closed network connection"}
2023-06-25T02:49:33.2903528Z /home/runner/work/etcd/etcd/bin/etcd (TestV3CurlCipherSuitesMismatch-test-0) (23987): {"level":"warn","ts":"2023-06-25T02:49:33.285426Z","caller":"embed/serve.go:223","msg":"stopped secure grpc server due to error","error":"accept tcp 127.0.0.1:20000: use of closed network connection"}
2023-06-25T02:49:33.2905683Z /home/runner/work/etcd/etcd/bin/etcd (TestV3CurlCipherSuitesMismatch-test-0) (23987): {"level":"error","ts":"2023-06-25T02:49:33.285528Z","caller":"embed/etcd.go:862","msg":"setting up serving from embedded etcd failed.","error":"accept tcp 127.0.0.1:20000: use of closed network connection","stacktrace":"go.etcd.io/etcd/server/v3/embed.(*Etcd).errHandler\n\tgo.etcd.io/etcd/server/v3/embed/etcd.go:862\ngo.etcd.io/etcd/server/v3/embed.(*Etcd).serveClients.func1\n\tgo.etcd.io/etcd/server/v3/embed/etcd.go:773"}
2023-06-25T02:49:33.2907855Z /home/runner/work/etcd/etcd/bin/etcd (TestV3CurlCipherSuitesMismatch-test-0) (23987): {"level":"warn","ts":"2023-06-25T02:49:33.285694Z","caller":"embed/config_logging.go:187","msg":"rejected connection","remote-addr":"127.0.0.1:50976","server-name":"localhost","error":"read tcp 127.0.0.1:20000->127.0.0.1:50976: use of closed network connection"}
2023-06-25T02:49:33.2909967Z /home/runner/work/etcd/etcd/bin/etcd (TestV3CurlCipherSuitesMismatch-test-0) (23987): {"level":"error","ts":"2023-06-25T02:49:33.285988Z","caller":"embed/etcd.go:862","msg":"setting up serving from embedded etcd failed.","error":"http: Server closed","stacktrace":"go.etcd.io/etcd/server/v3/embed.(*Etcd).errHandler\n\tgo.etcd.io/etcd/server/v3/embed/etcd.go:862\ngo.etcd.io/etcd/server/v3/embed.(*serveCtx).serve.func7\n\tgo.etcd.io/etcd/server/v3/embed/serve.go:254"}
2023-06-25T02:49:33.2911913Z /home/runner/work/etcd/etcd/bin/etcd (TestV3CurlCipherSuitesMismatch-test-0) (23987): {"level":"info","ts":"2023-06-25T02:49:33.286222Z","caller":"etcdserver/server.go:1226","msg":"skipped leadership transfer for single voting member cluster","local-member-id":"ca50e9357181d758","current-leader-member-id":"ca50e9357181d758"}
2023-06-25T02:49:33.2913387Z /home/runner/work/etcd/etcd/bin/etcd (TestV3CurlCipherSuitesMismatch-test-0) (23987): {"level":"info","ts":"2023-06-25T02:49:33.286462Z","caller":"etcdserver/server.go:2213","msg":"server has stopped; stopping storage version's monitor"}
2023-06-25T02:49:33.2914677Z /home/runner/work/etcd/etcd/bin/etcd (TestV3CurlCipherSuitesMismatch-test-0) (23987): {"level":"info","ts":"2023-06-25T02:49:33.286552Z","caller":"etcdserver/server.go:2190","msg":"server has stopped; stopping cluster version's monitor"}
2023-06-25T02:49:33.2915905Z /home/runner/work/etcd/etcd/bin/etcd (TestV3CurlCipherSuitesMismatch-test-0) (23987): 2023/06/25 02:49:33 WARNING: [core] [Channel #1 SubChannel #2] grpc: addrConn.createTransport failed to connect to {
2023-06-25T02:49:33.2916859Z /home/runner/work/etcd/etcd/bin/etcd (TestV3CurlCipherSuitesMismatch-test-0) (23987):   "Addr": "localhost:20000",
2023-06-25T02:49:33.2917709Z /home/runner/work/etcd/etcd/bin/etcd (TestV3CurlCipherSuitesMismatch-test-0) (23987):   "ServerName": "localhost:20000",
2023-06-25T02:49:33.2918515Z /home/runner/work/etcd/etcd/bin/etcd (TestV3CurlCipherSuitesMismatch-test-0) (23987):   "Attributes": null,
2023-06-25T02:49:33.2919413Z /home/runner/work/etcd/etcd/bin/etcd (TestV3CurlCipherSuitesMismatch-test-0) (23987):   "BalancerAttributes": null,
2023-06-25T02:49:33.2920215Z /home/runner/work/etcd/etcd/bin/etcd (TestV3CurlCipherSuitesMismatch-test-0) (23987):   "Type": 0,
2023-06-25T02:49:33.2920992Z /home/runner/work/etcd/etcd/bin/etcd (TestV3CurlCipherSuitesMismatch-test-0) (23987):   "Metadata": null
2023-06-25T02:49:33.2922150Z /home/runner/work/etcd/etcd/bin/etcd (TestV3CurlCipherSuitesMismatch-test-0) (23987): }. Err: connection error: desc = "transport: authentication handshake failed: context canceled"
2023-06-25T02:49:33.2971774Z /home/runner/work/etcd/etcd/bin/etcd (TestV3CurlCipherSuitesMismatch-test-0) (23987): {"level":"info","ts":"2023-06-25T02:49:33.288288Z","caller":"embed/etcd.go:589","msg":"stopping serving peer traffic","address":"127.0.0.1:20001"}
2023-06-25T02:49:33.2975616Z /home/runner/work/etcd/etcd/bin/etcd (TestV3CurlCipherSuitesMismatch-test-0) (23987): {"level":"error","ts":"2023-06-25T02:49:33.288335Z","caller":"embed/etcd.go:862","msg":"setting up serving from embedded etcd failed.","error":"accept tcp 127.0.0.1:20001: use of closed network connection","stacktrace":"go.etcd.io/etcd/server/v3/embed.(*Etcd).errHandler\n\tgo.etcd.io/etcd/server/v3/embed/etcd.go:862\ngo.etcd.io/etcd/server/v3/embed.(*Etcd).servePeers.func3\n\tgo.etcd.io/etcd/server/v3/embed/etcd.go:611"}
2023-06-25T02:49:33.2977540Z /home/runner/work/etcd/etcd/bin/etcd (TestV3CurlCipherSuitesMismatch-test-0) (23987): {"level":"info","ts":"2023-06-25T02:49:33.288369Z","caller":"embed/etcd.go:594","msg":"stopped serving peer traffic","address":"127.0.0.1:20001"}
2023-06-25T02:49:33.2979962Z /home/runner/work/etcd/etcd/bin/etcd (TestV3CurlCipherSuitesMismatch-test-0) (23987): {"level":"info","ts":"2023-06-25T02:49:33.288383Z","caller":"embed/etcd.go:398","msg":"closed etcd server","name":"TestV3CurlCipherSuitesMismatch-test-0","data-dir":"/tmp/TestV3CurlCipherSuitesMismatch741203529/002","advertise-peer-urls":["http://localhost:20001"],"advertise-client-urls":["https://localhost:20000"]}
2023-06-25T02:49:33.2981981Z /home/runner/work/etcd/etcd/bin/etcd (TestV3CurlCipherSuitesMismatch-test-0) (23987): {"level":"info","ts":"2023-06-25T02:49:33.28841Z","caller":"verify/verify.go:64","msg":"verification of persisted state","data-dir":"/tmp/TestV3CurlCipherSuitesMismatch741203529/002"}
2023-06-25T02:49:33.2983555Z /home/runner/work/etcd/etcd/bin/etcd (TestV3CurlCipherSuitesMismatch-test-0) (23987): {"level":"info","ts":"2023-06-25T02:49:33.288662Z","caller":"verify/verify.go:132","msg":"verification: consistentIndex OK","backend-consistent-index":4,"hardstate-commit":4}
2023-06-25T02:49:33.2985266Z /home/runner/work/etcd/etcd/bin/etcd (TestV3CurlCipherSuitesMismatch-test-0) (23987): {"level":"info","ts":"2023-06-25T02:49:33.289113Z","caller":"verify/verify.go:75","msg":"verification of persisted state successful","data-dir":"/tmp/TestV3CurlCipherSuitesMismatch741203529/002"}
2023-06-25T02:49:33.2986593Z     logger.go:130: 2023-06-25T02:49:33.293Z	INFO	stopped server.	{"name": "TestV3CurlCipherSuitesMismatch-test-0"}
2023-06-25T02:49:33.2987434Z     logger.go:130: 2023-06-25T02:49:33.293Z	INFO	closing test cluster...
2023-06-25T02:49:33.2988442Z     logger.go:130: 2023-06-25T02:49:33.293Z	INFO	stopping server...	{"name": "TestV3CurlCipherSuitesMismatch-test-0"}
2023-06-25T02:49:33.2989415Z     logger.go:130: 2023-06-25T02:49:33.293Z	INFO	closing server...	{"name": "TestV3CurlCipherSuitesMismatch-test-0"}
2023-06-25T02:49:33.2990567Z     logger.go:130: 2023-06-25T02:49:33.293Z	INFO	stopping server...	{"name": "TestV3CurlCipherSuitesMismatch-test-0"}
2023-06-25T02:49:33.2991695Z     logger.go:130: 2023-06-25T02:49:33.293Z	INFO	removing directory	{"data-dir": "/tmp/TestV3CurlCipherSuitesMismatch741203529/002"}
2023-06-25T02:49:33.2992611Z     logger.go:130: 2023-06-25T02:49:33.293Z	INFO	closed test cluster.
2023-06-25T02:49:33.2993127Z     ctl_v3_test.go:283: closed test cluster...
2023-06-25T02:49:33.2993662Z --- FAIL: TestV3CurlCipherSuitesMismatch (1.07s)

It seem that the failure is not related to this change.


Updated: If the process exits, the read goroutine doesn't update the ep.lines in time. The Expect doesn't use the process's output and return error because exitErr isn't nil.

etcd/pkg/expect/expect.go

Lines 152 to 201 in 31b20ef

func (ep *ExpectProcess) ExpectFunc(ctx context.Context, f func(string) bool) (string, error) {
i := 0
for {
line, errsFound := func() (string, bool) {
ep.mu.Lock()
defer ep.mu.Unlock()
// check if this expect has been already closed
if ep.cmd == nil {
return "", true
}
for i < len(ep.lines) {
line := ep.lines[i]
i++
if f(line) {
return line, false
}
}
return "", ep.exitErr != nil
}()
if line != "" {
return line, nil
}
if errsFound {
break
}
select {
case <-ctx.Done():
return "", fmt.Errorf("failed to find match string: %w", ctx.Err())
case <-time.After(time.Millisecond * 10):
// continue loop
}
}
ep.mu.Lock()
defer ep.mu.Unlock()
lastLinesIndex := len(ep.lines) - DEBUG_LINES_TAIL
if lastLinesIndex < 0 {
lastLinesIndex = 0
}
lastLines := strings.Join(ep.lines[lastLinesIndex:], "")
return "", fmt.Errorf("match not found. "+
" Set EXPECT_DEBUG for more info Errs: [%v], last lines:\n%s",
ep.exitErr, lastLines)
}

Maybe we should wait for read goroutine closes in Expect and retry it, if there is exitErr.

@fuweid
Copy link
Member Author

fuweid commented Jun 26, 2023

ping @serathius @ahrtr @jmhbnz @chaochn47 please take a look when you have time. Thanks

@serathius serathius merged commit 3ea0cb8 into etcd-io:main Jun 26, 2023
@serathius
Copy link
Member

Merging as this is test only and it's causing flakes.

@fuweid fuweid deleted the deflake-failpoint-cases branch July 4, 2023 14:02
fuweid added a commit to fuweid/etcd that referenced this pull request Jul 4, 2023
Let's say there is command which outputs one line and exit with error.

There are three goroutines to acquire the lock:

1. ep.read()
2. ep.waitSaveExitErr()
3. ep.Expect()

When ep.read goroutine reads the log but it doesn't acquire the lock in
time, the ep.waitSaveExitErr acquires the lock and updates the
`exitErr`. And then ep.Expect acquires lock but it doesn't see any log
yet and then returns err.

It's hard to reproduce it in local. Add the extra sleep can reproduce it.

```diff
diff --git a/pkg/expect/expect.go b/pkg/expect/expect.go
index a512a3ce4..602bea73f 100644
--- a/pkg/expect/expect.go
+++ b/pkg/expect/expect.go
@@ -128,6 +128,7 @@ func (ep *ExpectProcess) tryReadNextLine(r *bufio.Reader) error {
    printDebugLines := os.Getenv("EXPECT_DEBUG") != ""
    l, err := r.ReadString('\n')

+       time.Sleep(10 * time.Millisecond)
    ep.mu.Lock()
    defer ep.mu.Unlock()
```

See it once in Github Action [1]. In order to fix it, the patch introduces
`readCloseCh` to wait for ep.read to get all the data and retry it.

[1]: etcd-io#16137 (comment)

Signed-off-by: Wei Fu <fuweid89@gmail.com>
fuweid added a commit to fuweid/etcd that referenced this pull request Jul 4, 2023
Let's say there is command which outputs one line and exit with error.

There are three goroutines to acquire the lock:

1. ep.read()
2. ep.waitSaveExitErr()
3. ep.Expect()

When ep.read goroutine reads the log but it doesn't acquire the lock in
time, the ep.waitSaveExitErr acquires the lock and updates the
`exitErr`. And then ep.Expect acquires lock but it doesn't see any log
yet and then returns err.

It's hard to reproduce it in local. Add the extra sleep can reproduce it.

```diff
diff --git a/pkg/expect/expect.go b/pkg/expect/expect.go
index a512a3ce4..602bea73f 100644
--- a/pkg/expect/expect.go
+++ b/pkg/expect/expect.go
@@ -128,6 +128,7 @@ func (ep *ExpectProcess) tryReadNextLine(r *bufio.Reader) error {
        printDebugLines := os.Getenv("EXPECT_DEBUG") != ""
        l, err := r.ReadString('\n')

+       time.Sleep(10 * time.Millisecond)
        ep.mu.Lock()
        defer ep.mu.Unlock()
```

See it once in Github Action [1]. In order to fix it, the patch introduces
`readCloseCh` to wait for ep.read to get all the data and retry it.

[1]: etcd-io#16137 (comment)

Signed-off-by: Wei Fu <fuweid89@gmail.com>
fuweid added a commit to fuweid/etcd that referenced this pull request Jul 8, 2023
Let's say there is command which outputs one line and exit with error.

There are three goroutines to acquire the lock:

1. ep.read()
2. ep.waitSaveExitErr()
3. ep.Expect()

When ep.read goroutine reads the log but it doesn't acquire the lock in
time, the ep.waitSaveExitErr acquires the lock and updates the
`exitErr`. And then ep.Expect acquires lock but it doesn't see any log
yet and then returns err.

It's hard to reproduce it in local. Add the extra sleep can reproduce it.

```diff
diff --git a/pkg/expect/expect.go b/pkg/expect/expect.go
index a512a3ce4..602bea73f 100644
--- a/pkg/expect/expect.go
+++ b/pkg/expect/expect.go
@@ -128,6 +128,7 @@ func (ep *ExpectProcess) tryReadNextLine(r *bufio.Reader) error {
        printDebugLines := os.Getenv("EXPECT_DEBUG") != ""
        l, err := r.ReadString('\n')

+       time.Sleep(10 * time.Millisecond)
        ep.mu.Lock()
        defer ep.mu.Unlock()
```

See it once in Github Action [1]. In order to fix it, the patch introduces
`readCloseCh` to wait for ep.read to get all the data and retry it.

[1]: etcd-io#16137 (comment)

Signed-off-by: Wei Fu <fuweid89@gmail.com>
fuweid added a commit to fuweid/etcd that referenced this pull request Jul 13, 2023
Let's say there is command which outputs one line and exit with error.

There are three goroutines to acquire the lock:

1. ep.read()
2. ep.waitSaveExitErr()
3. ep.Expect()

When ep.read goroutine reads the log but it doesn't acquire the lock in
time, the ep.waitSaveExitErr acquires the lock and updates the
`exitErr`. And then ep.Expect acquires lock but it doesn't see any log
yet and then returns err.

It's hard to reproduce it in local. Add the extra sleep can reproduce it.

```diff
diff --git a/pkg/expect/expect.go b/pkg/expect/expect.go
index a512a3ce4..602bea73f 100644
--- a/pkg/expect/expect.go
+++ b/pkg/expect/expect.go
@@ -128,6 +128,7 @@ func (ep *ExpectProcess) tryReadNextLine(r *bufio.Reader) error {
        printDebugLines := os.Getenv("EXPECT_DEBUG") != ""
        l, err := r.ReadString('\n')

+       time.Sleep(10 * time.Millisecond)
        ep.mu.Lock()
        defer ep.mu.Unlock()
```

See it once in Github Action [1]. In order to fix it, the patch introduces
`readCloseCh` to wait for ep.read to get all the data and retry it.

[1]: etcd-io#16137 (comment)

Signed-off-by: Wei Fu <fuweid89@gmail.com>
ArkaSaha30 pushed a commit to ArkaSaha30/etcd that referenced this pull request May 23, 2024
Let's say there is command which outputs one line and exit with error.

There are three goroutines to acquire the lock:

1. ep.read()
2. ep.waitSaveExitErr()
3. ep.Expect()

When ep.read goroutine reads the log but it doesn't acquire the lock in
time, the ep.waitSaveExitErr acquires the lock and updates the
`exitErr`. And then ep.Expect acquires lock but it doesn't see any log
yet and then returns err.

It's hard to reproduce it in local. Add the extra sleep can reproduce it.

```diff
diff --git a/pkg/expect/expect.go b/pkg/expect/expect.go
index a512a3ce4..602bea73f 100644
--- a/pkg/expect/expect.go
+++ b/pkg/expect/expect.go
@@ -128,6 +128,7 @@ func (ep *ExpectProcess) tryReadNextLine(r *bufio.Reader) error {
        printDebugLines := os.Getenv("EXPECT_DEBUG") != ""
        l, err := r.ReadString('\n')

+       time.Sleep(10 * time.Millisecond)
        ep.mu.Lock()
        defer ep.mu.Unlock()
```

See it once in Github Action [1]. In order to fix it, the patch introduces
`readCloseCh` to wait for ep.read to get all the data and retry it.

[1]: etcd-io#16137 (comment)

Signed-off-by: Wei Fu <fuweid89@gmail.com>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Development

Successfully merging this pull request may close these issues.

Issue in expect package causing a flakes in Robustness tests
2 participants