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

[35/100k] Flaky test: ProducerMultipleListeners #6637

Open
easwars opened this issue Sep 15, 2023 · 6 comments
Open

[35/100k] Flaky test: ProducerMultipleListeners #6637

easwars opened this issue Sep 15, 2023 · 6 comments

Comments

@easwars
Copy link
Contributor

easwars commented Sep 15, 2023

--- FAIL: Test (5.28s)
    --- FAIL: Test/ProducerMultipleListeners (5.00s)
        tlogger.go:116: INFO server.go:667 [core] [Server #91] Server created  (t=+374.323µs)
        tlogger.go:116: INFO clientconn.go:318 [core] [Channel #92] Channel created  (t=+462.128µs)
        tlogger.go:116: INFO clientconn.go:1839 [core] [Channel #92] original dial target is: "whatever:///whatever"  (t=+577.935µs)
        tlogger.go:116: INFO clientconn.go:1846 [core] [Channel #92] parsed dial target is: {URL:{Scheme:whatever Opaque: User: Host: Path:/whatever RawPath: OmitHost:false ForceQuery:false RawQuery: Fragment: RawFragment:}}  (t=+645.44µs)
        tlogger.go:116: INFO clientconn.go:2001 [core] [Channel #92] Channel authority set to "whatever"  (t=+699.643µs)
        tlogger.go:116: INFO server.go:855 [core] [Server #91 ListenSocket #93] ListenSocket created  (t=+788.848µs)
        tlogger.go:116: INFO resolver_conn_wrapper.go:246 [core] [Channel #92] Resolver state updated: {
              "Addresses": [
                {
                  "Addr": "127.0.0.1:42531",
                  "ServerName": "",
                  "Attributes": {
                    "\u003c%!p(orca_test.listenerInfoKey={})\u003e": "\u003c0xc00019e2a0\u003e"
                  },
                  "BalancerAttributes": null,
                  "Metadata": null
                }
              ],
              "Endpoints": [
                {
                  "Addresses": [
                    {
                      "Addr": "127.0.0.1:42531",
                      "ServerName": "",
                      "Attributes": {
                        "\u003c%!p(orca_test.listenerInfoKey={})\u003e": "\u003c0xc00019e2a0\u003e"
                      },
                      "BalancerAttributes": null,
                      "Metadata": null
                    }
                  ],
                  "Attributes": null
                }
              ],
              "ServiceConfig": null,
              "Attributes": null
            } (resolver returned new addresses)  (t=+1.081566ms)
        tlogger.go:116: INFO balancer_conn_wrappers.go:180 [core] [Channel #92] Channel switches to new LB policy "customLB"  (t=+1.178072ms)
        tlogger.go:116: INFO clientconn.go:956 [core] [Channel #92 SubChannel #94] Subchannel created  (t=+1.250476ms)
        tlogger.go:116: INFO roundrobin.go:50 [roundrobin] roundrobinPicker: Build called with info: {map[]}  (t=+1.375784ms)
        tlogger.go:116: INFO clientconn.go:592 [core] [Channel #92] Channel Connectivity change to CONNECTING  (t=+1.421287ms)
        tlogger.go:116: INFO clientconn.go:1338 [core] [Channel #92 SubChannel #94] Subchannel Connectivity change to CONNECTING  (t=+1.508392ms)
        tlogger.go:116: INFO clientconn.go:1453 [core] [Channel #92 SubChannel #94] Subchannel picks a new address "127.0.0.1:42531" to connect  (t=+1.552895ms)
        tlogger.go:116: INFO clientconn.go:1338 [core] [Channel #92 SubChannel #94] Subchannel Connectivity change to READY  (t=+2.738467ms)
        tlogger.go:116: INFO roundrobin.go:50 [roundrobin] roundrobinPicker: Build called with info: {map[SubConn(id:94):{{Addr: "127.0.0.1:42531", ServerName: "", Attributes: {"<%!p(orca_test.listenerInfoKey={})>": "<0xc00019e2a0>" }, }}]}  (t=+2.883876ms)
        tlogger.go:116: INFO clientconn.go:592 [core] [Channel #92] Channel Connectivity change to READY  (t=+2.93828ms)
        producer_test.go:458: Load report 1 received:  cpu_utilization:10 mem_utilization:0.1 utilization:{key:"bob" value:0.555}
        producer_test.go:458: Load report 1 received:  cpu_utilization:10 mem_utilization:0.1 utilization:{key:"bob" value:0.555}
        producer_test.go:466: Load report 2 received:  cpu_utilization:10 mem_utilization:0.1 utilization:{key:"bob" value:0.555}
        producer_test.go:458: Load report 1 received:  cpu_utilization:10 mem_utilization:0.1 utilization:{key:"bob" value:0.555}
        producer_test.go:466: Load report 2 received:  cpu_utilization:10 mem_utilization:0.1 utilization:{key:"bob" value:0.555}
        producer_test.go:474: Load report 3 received:  cpu_utilization:10 mem_utilization:0.1 utilization:{key:"bob" value:0.555}
        producer_test.go:466: Load report 2 received:  cpu_utilization:10 mem_utilization:0.1 utilization:{key:"bob" value:0.555}
        producer_test.go:474: Load report 3 received:  cpu_utilization:10 mem_utilization:0.1 utilization:{key:"bob" value:0.555}
        producer_test.go:458: Load report 1 received:  cpu_utilization:10 mem_utilization:0.1 utilization:{key:"bob" value:0.555}
        producer_test.go:474: Load report 3 received:  cpu_utilization:10 mem_utilization:0.1 utilization:{key:"bob" value:0.555}
        producer_test.go:458: Load report 1 received:  cpu_utilization:10 mem_utilization:0.1 utilization:{key:"bob" value:0.555}
        producer_test.go:543: timed out waiting for reports received. got 5 3 3; want 6 3 3
        tlogger.go:116: INFO clientconn.go:592 [core] [Channel #92] Channel Connectivity change to SHUTDOWN  (t=+5.001404657s)
        tlogger.go:116: INFO balancer_conn_wrappers.go:191 [core] [Channel #92] ccBalancerWrapper: closing  (t=+5.001467561s)
        tlogger.go:116: INFO resolver_conn_wrapper.go:126 [core] [Channel #92] Closing the name resolver  (t=+5.001551966s)
        tlogger.go:116: INFO clientconn.go:1338 [core] [Channel #92 SubChannel #94] Subchannel Connectivity change to SHUTDOWN  (t=+5.001645372s)
        tlogger.go:116: INFO clientconn.go:1684 [core] [Channel #92 SubChannel #94] Subchannel deleted  (t=+5.001722577s)
        tlogger.go:116: INFO clientconn.go:318 [core] [Channel #92] Channel deleted  (t=+5.00[189](https://github.com/grpc/grpc-go/actions/runs/6191873520/job/16810932491?pr=6634#step:8:190)0887s)
        tlogger.go:116: INFO server.go:806 [core] [Server #91 ListenSocket #93] ListenSocket deleted  (t=+5.00[203](https://github.com/grpc/grpc-go/actions/runs/6191873520/job/16810932491?pr=6634#step:8:204)2696s)
FAIL
FAIL	google.golang.org/grpc/orca	5.882s

https://github.com/grpc/grpc-go/actions/runs/6191873520/job/16810932491?pr=6634

@zasweq
Copy link
Contributor

zasweq commented Sep 19, 2023

Made P2 since it doesn't look like this is occurring too frequently. I reviewed this PR, Doug wrote the test, thus assigning to Doug.

@easwars
Copy link
Contributor Author

easwars commented Sep 26, 2023

https://github.com/grpc/grpc-go/actions/runs/6317329369/job/17153865917?pr=6665

@easwars
Copy link
Contributor Author

easwars commented Oct 3, 2023

https://github.com/grpc/grpc-go/actions/runs/6399400068/job/17371377399?pr=6681

@zasweq
Copy link
Contributor

zasweq commented Oct 10, 2023

https://github.com/grpc/grpc-go/actions/runs/6473390734/job/17575983599?pr=6705

@zasweq
Copy link
Contributor

zasweq commented Oct 18, 2023

https://github.com/grpc/grpc-go/actions/runs/6566180296/job/17836303715

@dfawley dfawley added P1 and removed P2 labels Oct 18, 2023
@arvindbr8 arvindbr8 changed the title Flaky test: ProducerMultipleListeners [35/100k] Flaky test: ProducerMultipleListeners Oct 19, 2023
@arvindbr8
Copy link
Member

low flake rate on forge [35/100k] - sponge2/e9e27ddd-2d25-4338-bb20-9946440453da

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests

5 participants
@easwars @arvindbr8 @dfawley @zasweq and others