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

Better handling of stream retries on fast disconnects #1006

Merged
merged 1 commit into from
Jun 21, 2024

Conversation

PapaCharlie
Copy link
Member

Copied from the Slack context (thanks Bohan for the writeup):

Summary: we looked into the bad host's log and our xds client code. There is an issue in the reconnect logic. When a reconnect ads stream is closed/rejected for stream limit on an observer A, the stream ready timeout for this stream was not cancelled before it retries with another observer B. So that after the stream with observer B becomes ready, the ready timeout for observer A was executed which cleaned the stream with observer B. This leads to the client enables backup (FS) store and never tries to connect with the observer again.

2024/06/20 10:07:00.204 INFO [XdsClientImpl] [Indis xDS client executor-4-1] [followfeed-query] [AAYbT3nOcB56sIf0OjkOIg==] ADS stream started, connected to server: main.indis-registry-observer.prod-lor1.atd.disco.linkedin.com:32123
2024/06/20 10:07:00.367 ERROR [XdsClientImpl] [Indis xDS client executor-4-1] [followfeed-query] [AAYbT3nQ9CeWMXpo8cQEFg==] ADS stream closed with status UNAVAILABLE: Network closed for unknown reason. Cause: null
2024/06/20 10:07:00.367 INFO [XdsClientImpl] [Indis xDS client executor-4-1] [followfeed-query] [AAYbT3nQ9CeWMXpo8cQEFg==] Retry ADS stream in 859991762 ns

2024/06/20 10:07:01.228 INFO [XdsClientImpl] [Indis xDS client executor-4-1] [followfeed-query] [AAYbT3neFIsVPcAaz2Yv3w==] ADS stream started, connected to server: main.indis-registry-observer.prod-lor1.atd.disco.linkedin.com:32123
2024/06/20 10:07:01.240 INFO [XdsClientImpl] [Indis xDS client executor-4-1] [followfeed-query] [AAYbT3neRq29/jeDmOPBqw==] Successfully established stream with ADS server: lor1-app104284.prod.linkedin.com
2024/06/20 10:07:01.240 INFO [XdsClientImpl] [Indis xDS client executor-4-1] [followfeed-query] [AAYbT3neRe10FiykxUBBow==] ADS stream ready, cancelled timeout task: true
2024/06/20 10:07:01.240 INFO [XdsLoadBalancer] [Indis xDS client executor-4-1] [followfeed-query] [AAYbT3neRe10FiykxUBBow==] Enabled primary stores
2024/06/20 10:07:02.202 WARN [XdsClientImpl] [Indis xDS client executor-4-1] [followfeed-query] [AAYbT3ns9W3jJPwtvqLIlw==] ADS stream not ready within 2000 milliseconds
2024/06/20 10:07:02.202 INFO [XdsLoadBalancer] [Indis xDS client executor-4-1] [followfeed-query] [AAYbT3ns9W3jJPwtvqLIlw==] Enabled backup stores

Copied from the Slack context (thanks Bohan for the writeup):

Summary: we looked into the bad host's log and our xds client code. There is an issue in the reconnect logic. When a reconnect ads stream is closed/rejected for stream limit on an observer A, the stream ready timeout for this stream was not cancelled before it retries with another observer B. So that after the stream with observer B becomes ready, the ready timeout for observer A was executed which cleaned the stream with observer B. This leads to the client enables backup (FS) store and never tries to connect with the observer again.
```
2024/06/20 10:07:00.204 INFO [XdsClientImpl] [Indis xDS client executor-4-1] [followfeed-query] [AAYbT3nOcB56sIf0OjkOIg==] ADS stream started, connected to server: main.indis-registry-observer.prod-lor1.atd.disco.linkedin.com:32123
2024/06/20 10:07:00.367 ERROR [XdsClientImpl] [Indis xDS client executor-4-1] [followfeed-query] [AAYbT3nQ9CeWMXpo8cQEFg==] ADS stream closed with status UNAVAILABLE: Network closed for unknown reason. Cause: null
2024/06/20 10:07:00.367 INFO [XdsClientImpl] [Indis xDS client executor-4-1] [followfeed-query] [AAYbT3nQ9CeWMXpo8cQEFg==] Retry ADS stream in 859991762 ns

2024/06/20 10:07:01.228 INFO [XdsClientImpl] [Indis xDS client executor-4-1] [followfeed-query] [AAYbT3neFIsVPcAaz2Yv3w==] ADS stream started, connected to server: main.indis-registry-observer.prod-lor1.atd.disco.linkedin.com:32123
2024/06/20 10:07:01.240 INFO [XdsClientImpl] [Indis xDS client executor-4-1] [followfeed-query] [AAYbT3neRq29/jeDmOPBqw==] Successfully established stream with ADS server: lor1-app104284.prod.linkedin.com
2024/06/20 10:07:01.240 INFO [XdsClientImpl] [Indis xDS client executor-4-1] [followfeed-query] [AAYbT3neRe10FiykxUBBow==] ADS stream ready, cancelled timeout task: true
2024/06/20 10:07:01.240 INFO [XdsLoadBalancer] [Indis xDS client executor-4-1] [followfeed-query] [AAYbT3neRe10FiykxUBBow==] Enabled primary stores
2024/06/20 10:07:02.202 WARN [XdsClientImpl] [Indis xDS client executor-4-1] [followfeed-query] [AAYbT3ns9W3jJPwtvqLIlw==] ADS stream not ready within 2000 milliseconds
2024/06/20 10:07:02.202 INFO [XdsLoadBalancer] [Indis xDS client executor-4-1] [followfeed-query] [AAYbT3ns9W3jJPwtvqLIlw==] Enabled backup stores
```
@PapaCharlie PapaCharlie merged commit 9643b60 into master Jun 21, 2024
2 checks passed
@PapaCharlie PapaCharlie deleted the pc/adsstream branch June 21, 2024 21:28
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

2 participants