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

Flaky Test: xds/ServerSideXDS_RedundantUpdateSuppression #7713

Open
arjan-bal opened this issue Oct 9, 2024 · 2 comments
Open

Flaky Test: xds/ServerSideXDS_RedundantUpdateSuppression #7713

arjan-bal opened this issue Oct 9, 2024 · 2 comments
Labels
Area: Testing Includes tests and testing utilities that we have for unit and e2e tests within our repo. P2 Type: Bug

Comments

@arjan-bal
Copy link
Contributor

Example failure: https://github.com/grpc/grpc-go/actions/runs/11253051356/job/31287507377?pr=7498

Logs

--- FAIL: Test/ServerSideXDS_RedundantUpdateSuppression (0.08s)
        setup.go:45: Created new snapshot cache...
        tlogger.go:116: INFO server.go:684 [core] [Server #1427]Server created  (t=+390.751µs)
        setup.go:45: Registered Aggregated Discovery Service (ADS)...
        setup.go:45: xDS management server serving at: 127.0.0.1:36507...
        tlogger.go:116: INFO server.go:880 [core] [Server #1427 ListenSocket #1428]ListenSocket created  (t=+1.994634ms)
        tlogger.go:116: INFO server.go:684 [core] [Server #1429]Server created  (t=+2.279998ms)
        tlogger.go:116: INFO client_refcounted.go:84 [xds] [xds-client 0xc0008f6540] Created client with name "#server" and bootstrap configuration:
             {
              "xds_servers": [
               {
                "server_uri": "passthrough:///127.0.0.1:36507",
                "channel_creds": [
                 {
                  "type": "insecure"
                 }
                ]
               }
              ],
              "certificate_providers": {
               "client-side-certificate-provider-instance": {
                "plugin_name": "file_watcher",
                "config": {
                 "certificate_file": "/tmp/testClientSideXDS361233951/cert.pem",
                 "private_key_file": "/tmp/testClientSideXDS361233951/key.pem",
                 "ca_certificate_file": "/tmp/testClientSideXDS361233951/ca.pem",
                 "refresh_interval": "600s"
                }
               },
               "server-side-certificate-provider-instance": {
                "plugin_name": "file_watcher",
                "config": {
                 "certificate_file": "/tmp/testServerSideXDS1443769593/cert.pem",
                 "private_key_file": "/tmp/testServerSideXDS1443769593/key.pem",
                 "ca_certificate_file": "/tmp/testServerSideXDS1443769593/ca.pem",
                 "refresh_interval": "600s"
                }
               }
              },
              "server_listener_resource_name_template": "grpc/server?xds.resource.listening_address=%s",
              "client_default_listener_resource_name_template": "%s",
              "node": {
               "id": "d67efc3f-f3a5-4ebb-8bc2-fb0689613c70",
               "locality": {}
              }
             }  (t=+3.20514ms)
        tlogger.go:116: INFO client_refcounted.go:89 [xds] xDS node ID: d67efc3f-f3a5-4ebb-8bc2-fb0689613c70  (t=+3.627211ms)
        tlogger.go:116: INFO server.go:123 [xds] [xds-server 0xc000507340] Created xds.GRPCServer  (t=+3.67492ms)
        server.go:229: Created new resource snapshot...
        server.go:235: Updated snapshot cache with resource snapshot...
        tlogger.go:116: INFO server.go:182 [xds] [xds-server 0xc000507340] Serve() passed a net.Listener on 127.0.0.1:42403  (t=+4.211264ms)
        tlogger.go:116: INFO clientconn.go:1652 [core] original dial target is: "passthrough:///127.0.0.1:36507"  (t=+4.335546ms)
        tlogger.go:116: INFO clientconn.go:314 [core] [Channel #1430]Channel created  (t=+4.395709ms)
        tlogger.go:116: INFO clientconn.go:193 [core] [Channel #1430]parsed dial target is: resolver.Target{URL:url.URL{Scheme:"passthrough", Opaque:"", User:(*url.Userinfo)(nil), Host:"", Path:"/127.0.0.1:36507", RawPath:"", OmitHost:false, ForceQuery:false, RawQuery:"", Fragment:"", RawFragment:""}}  (t=+4.475839ms)
        tlogger.go:116: INFO clientconn.go:194 [core] [Channel #1430]Channel authority set to "127.0.0.1:36507"  (t=+4.524651ms)
                  "Attributes": null,
                  "BalancerAttributes": null,
                  "Metadata": null
                }
              ],
              "Endpoints": [
                {
                  "Addresses": [
                    {
                      "Addr": "127.0.0.1:42403",
                      "ServerName": "",
                      "Attributes": null,
                      "BalancerAttributes": null,
                      "Metadata": null
                    }
                  ],
                  "Attributes": null
                }
              ],
              "ServiceConfig": null,
              "Attributes": null
            } (resolver returned new addresses)  (t=+11.659879ms)
        tlogger.go:116: INFO balancer_wrapper.go:109 [core] [Channel #1435]Channel switches to new LB policy "pick_first"  (t=+11.760578ms)
        tlogger.go:116: INFO clientconn.go:841 [core] [Channel #1435 SubChannel #1436]Subchannel created  (t=+11.831671ms)
        tlogger.go:116: INFO clientconn.go:544 [core] [Channel #1435]Channel Connectivity change to CONNECTING  (t=+11.885091ms)
        logging.go:30: nodeID "d67efc3f-f3a5-4ebb-8bc2-fb0689613c70" requested type.googleapis.com/envoy.config.listener.v3.Listener[grpc/server?xds.resource.listening_address=127.0.0.1:42403] and known map[grpc/server?xds.resource.listening_address=127.0.0.1:42403:{}]. Diff []
        logging.go:30: open watch 1 for type.googleapis.com/envoy.config.listener.v3.Listener[grpc/server?xds.resource.listening_address=127.0.0.1:42403] from nodeID "d67efc3f-f3a5-4ebb-8bc2-fb0689613c70", version "1"
        tlogger.go:116: INFO clientconn.go:314 [core] [Channel #1435]Channel exiting idle mode  (t=+12.321588ms)
        tlogger.go:116: INFO clientconn.go:1[197](https://github.com/grpc/grpc-go/actions/runs/11253051356/job/31287507377?pr=7498#step:8:198) [core] [Channel #1435 SubChannel #1436]Subchannel Connectivity change to CONNECTING  (t=+18.041147ms)
        tlogger.go:116: INFO clientconn.go:1317 [core] [Channel #1435 SubChannel #1436]Subchannel picks a new address "127.0.0.1:42403" to connect  (t=+18.126386ms)
        tlogger.go:116: INFO clientconn.go:1197 [core] [Channel #1435 SubChannel #1436]Subchannel Connectivity change to READY  (t=+18.586358ms)
        server.go:229: Created new resource snapshot...
        logging.go:30: respond open watch 1 type.googleapis.com/envoy.config.listener.v3.Listener[grpc/server?xds.resource.listening_address=127.0.0.1:42403] with new version "2"
        logging.go:30: respond type.googleapis.com/envoy.config.listener.v3.Listener[grpc/server?xds.resource.listening_address=127.0.0.1:42403] version "1" with version "2"
        server.go:235: Updated snapshot cache with resource snapshot...
        logging.go:30: nodeID "d67efc3f-f3a5-4ebb-8bc2-fb0689613c70" requested type.googleapis.com/envoy.config.listener.v3.Listener[grpc/server?xds.resource.listening_address=127.0.0.1:42403] and known map[grpc/server?xds.resource.listening_address=127.0.0.1:42403:{}]. Diff []
        logging.go:30: open watch 2 for type.googleapis.com/envoy.config.listener.v3.Listener[grpc/server?xds.resource.listening_address=127.0.0.1:42403] from nodeID "d67efc3f-f3a5-4ebb-8bc2-fb0689613c70", version "2"
        tlogger.go:116: INFO clientconn.go:544 [core] [Channel #1435]Channel Connectivity change to READY  (t=+20.673245ms)
        xds_server_serving_mode_test.go:161: unexpected connectivity state change {READY --> CONNECTING} on the client connection
        tlogger.go:116: INFO clientconn.go:544 [core] [Channel #1435]Channel Connectivity change to SHUTDOWN  (t=+30.60551ms)
        tlogger.go:116: INFO resolver_wrapper.go:100 [core] [Channel #1435]Closing the name resolver  (t=+30.669921ms)
        tlogger.go:116: INFO balancer_wrapper.go:147 [core] [Channel #1435]ccBalancerWrapper: closing  (t=+30.747536ms)
        tlogger.go:116: INFO clientconn.go:1197 [core] [Channel #1435 SubChannel #1436]Subchannel Connectivity change to SHUTDOWN  (t=+30.921221ms)
        tlogger.go:116: INFO clientconn.go:1525 [core] [Channel #1435 SubChannel #1436]Subchannel deleted  (t=+31.026829ms)
        tlogger.go:116: INFO clientconn.go:314 [core] [Channel #1435]Channel deleted  (t=+31.367[206](https://github.com/grpc/grpc-go/actions/runs/11253051356/job/31287507377?pr=7498#step:8:207)ms)
        logging.go:30: nodeID "d67efc3f-f3a5-4ebb-8bc2-fb0689613c70" requested type.googleapis.com/envoy.config.listener.v3.Listener[] and known map[grpc/server?xds.resource.listening_address=127.0.0.1:42403:{}]. Diff []
        logging.go:30: open watch 3 for type.googleapis.com/envoy.config.listener.v3.Listener[] from nodeID "d67efc3f-f3a5-4ebb-8bc2-fb0689613c70", version "2"
        tlogger.go:116: INFO server.go:816 [core] [Server #1429 ListenSocket #1432]ListenSocket deleted  (t=+31.983119ms)
        tlogger.go:116: WARNING authority.go:457 [xds] [xds-client 0xc0008f6540] [passthrough:///127.0.0.1:36507] Watchers not notified since ADS stream failed after having received at least one response: rpc error: code = Canceled desc = context canceled  (t=+32.307066ms)
        tlogger.go:116: WARNING transport.go:498 [xds] [xds-client 0xc0008f6540] [passthrough:///127.0.0.1:36507] ADS stream closed: rpc error: code = Canceled desc = context canceled  (t=+32.356358ms)
        tlogger.go:116: INFO clientconn.go:544 [core] [Channel #1430]Channel Connectivity change to SHUTDOWN  (t=+32.458098ms)
        tlogger.go:116: INFO resolver_wrapper.go:100 [core] [Channel #1430]Closing the name resolver  (t=+32.513472ms)
        tlogger.go:116: INFO balancer_wrapper.go:147 [core] [Channel #1430]ccBalancerWrapper: closing  (t=+32.573595ms)
        tlogger.go:116: INFO clientconn.go:1197 [core] [Channel #1430 SubChannel #1431]Subchannel Connectivity change to SHUTDOWN  (t=+32.654076ms)
        tlogger.go:116: INFO clientconn.go:1525 [core] [Channel #1430 SubChannel #1431]Subchannel deleted  (t=+32.738163ms)
        tlogger.go:116: INFO clientconn.go:314 [core] [Channel #1430]Channel deleted  (t=+32.89694ms)
        tlogger.go:116: INFO clientimpl.go:101 [xds] [xds-client 0xc0008f6540] Shutdown  (t=+32.979805ms)
        tlogger.go:116: INFO server.go:816 [core] [Server #1427 ListenSocket #1428]ListenSocket deleted  (t=+33.076907ms)
@arjan-bal arjan-bal added Type: Bug Area: Testing Includes tests and testing utilities that we have for unit and e2e tests within our repo. labels Oct 9, 2024
@purnesh42H
Copy link
Contributor

3/10000 failed on forge run

@aranjans
Copy link
Contributor

0/100000 failed on forge run

@purnesh42H purnesh42H added the P2 label Oct 22, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Area: Testing Includes tests and testing utilities that we have for unit and e2e tests within our repo. P2 Type: Bug
Projects
None yet
Development

No branches or pull requests

3 participants