health: ensure /v1/health/service/:service endpoint returns the most recent results when a filter is used with streaming #12640

rboyer · 2022-03-29T14:25:03Z

The primary bug here is in the streaming subsystem that makes the overall v1/health/service/:service request behave incorrectly when servicing a blocking request with a filter provided.

There is a secondary non-streaming bug being fixed here that is much less obvious related to when to update the reply variable in a blockingQuery evaluation. It is unlikely that it is triggerable in practical environments and I could not actually get the bug to manifest, but I fixed it anyway while investigating the original issue.

Simple reproduction (streaming):

Register a service with a tag.

 curl -sL --request PUT 'http://localhost:8500/v1/agent/service/register' \
     --header 'Content-Type: application/json' \
     --data-raw '{ "ID": "ID1", "Name": "test", "Tags":[ "a" ], "EnableTagOverride": true }'

Do an initial filter query that matches on the tag.

 curl -sLi --get 'http://localhost:8500/v1/health/service/test' --data-urlencode 'filter=a in Service.Tags'

Note you get one result. Use the X-Consul-Index header to establish
a blocking query in another terminal, this should not return yet.
```
 curl -sLi --get 'http://localhost:8500/v1/health/service/test?index=$INDEX' --data-urlencode 'filter=a in Service.Tags'
```

Re-register that service with a different tag.

 curl -sL --request PUT 'http://localhost:8500/v1/agent/service/register' \
     --header 'Content-Type: application/json' \
     --data-raw '{ "ID": "ID1", "Name": "test", "Tags":[ "b" ], "EnableTagOverride": true }'

Your blocking query from (3) should return with a header
X-Consul-Query-Backend: streaming and empty results if it works
correctly [].

Attempts to reproduce with non-streaming failed (where you add &near=_agent to the read queries and ensure X-Consul-Query-Backend: blocking-query shows up in the results).

TODO:

rboyer · 2022-03-29T14:26:48Z

agent/consul/health_endpoint.go

@@ -241,16 +241,15 @@ func (h *Health) ServiceNodes(args *structs.ServiceSpecificRequest, reply *struc
 				return err
 			}

-			reply.Index, reply.Nodes = index, nodes
 			if len(args.NodeMetaFilters) > 0 {


In general it is not safe to mutate reply until just before returning. This is not the first time this kind of bug has manifested.

Ugh. This makes me sad. This basically means the entire endpoint is not thread-safe if the response (aka reply) pointer is mutated? It would only apply to those endpoints that handle blocking queries, correct? There are a lot of endpoints that are implemented this way afaict and seems like a trap.

There's only one thread/goroutine involved, but it loops around during retry without resetting the reply var, so depending upon how the access goes and how the body of the blocking query function proceeds you can get "carry over" between attempts that you didn't intend.

Example from the last time this kind of thing specifically caused a bug: #10239

rboyer · 2022-03-29T14:27:06Z

agent/rpcclient/health/view.go

 				return err
-			case passed:
+			} else if passed {


When the filter no longer matched an entry we did not GC the prior record.

kisunji · 2022-04-04T14:52:49Z

I'm assuming the test failures mean the previous behavior was codified incorrectly?

…recent results when a filter is used This is two bugs in two subsystems (blocking queries ; streaming) that make the overall endpoint behave brokenly in the same way to the end user. Simple reproduction (streaming): 1. Register a service with a tag. curl -sL --request PUT 'http://localhost:8500/v1/agent/service/register' \ --header 'Content-Type: application/json' \ --data-raw '{ "ID": "ID1", "Name": "test", "Tags":[ "a" ], "EnableTagOverride": true }' 2. Do an initial filter query that matches on the tag. curl -sLi --get 'http://localhost:8500/v1/health/service/test' --data-urlencode 'filter=a in Service.Tags' 3. Note you get one result. Use the `X-Consul-Index` header to establish a blocking query in another terminal, this should not return yet. curl -sLi --get 'http://localhost:8500/v1/health/service/test?index=$INDEX' --data-urlencode 'filter=a in Service.Tags' 4. Re-register that service with a different tag. curl -sL --request PUT 'http://localhost:8500/v1/agent/service/register' \ --header 'Content-Type: application/json' \ --data-raw '{ "ID": "ID1", "Name": "test", "Tags":[ "b" ], "EnableTagOverride": true }' 5. Your blocking query from (3) should return with a header `X-Consul-Query-Backend: streaming` and empty results if it works correctly `[]`. To reproduce for non-streaming, simply add `&near=_agent` to your read queries and ensure `X-Consul-Query-Backend: blocking-query` shows up in the results.

rboyer · 2022-04-12T18:01:45Z

agent/consul/health_endpoint_test.go

@@ -679,6 +679,85 @@ func TestHealth_ServiceNodes(t *testing.T) {
 	}
 }

+func TestHealth_ServiceNodes_BlockingQuery_withFilter(t *testing.T) {


Note: we can't test streaming here because streaming happens elsewhere.

eculver

after some live review, LGTM... I have separate sadness about net/rpc.

hc-github-team-consul-core · 2022-04-27T15:40:30Z

🍒 If backport labels were added before merging, cherry-picking will start automatically.

To retroactively trigger a backport after merging, add backport labels and re-run https://circleci.com/gh/hashicorp/consul/653596.

hc-github-team-consul-core · 2022-04-27T15:40:33Z

🍒✅ Cherry pick of commit 11213ae onto release/1.12.x succeeded!

hc-github-team-consul-core · 2022-04-27T15:40:34Z

🍒❌ Cherry pick of commit 11213ae onto release/1.11.x failed! Build Log

…recent results when a filter is used with streaming (#12640) The primary bug here is in the streaming subsystem that makes the overall v1/health/service/:service request behave incorrectly when servicing a blocking request with a filter provided. There is a secondary non-streaming bug being fixed here that is much less obvious related to when to update the `reply` variable in a `blockingQuery` evaluation. It is unlikely that it is triggerable in practical environments and I could not actually get the bug to manifest, but I fixed it anyway while investigating the original issue. Simple reproduction (streaming): 1. Register a service with a tag. curl -sL --request PUT 'http://localhost:8500/v1/agent/service/register' \ --header 'Content-Type: application/json' \ --data-raw '{ "ID": "ID1", "Name": "test", "Tags":[ "a" ], "EnableTagOverride": true }' 2. Do an initial filter query that matches on the tag. curl -sLi --get 'http://localhost:8500/v1/health/service/test' --data-urlencode 'filter=a in Service.Tags' 3. Note you get one result. Use the `X-Consul-Index` header to establish a blocking query in another terminal, this should not return yet. curl -sLi --get 'http://localhost:8500/v1/health/service/test?index=$INDEX' --data-urlencode 'filter=a in Service.Tags' 4. Re-register that service with a different tag. curl -sL --request PUT 'http://localhost:8500/v1/agent/service/register' \ --header 'Content-Type: application/json' \ --data-raw '{ "ID": "ID1", "Name": "test", "Tags":[ "b" ], "EnableTagOverride": true }' 5. Your blocking query from (3) should return with a header `X-Consul-Query-Backend: streaming` and empty results if it works correctly `[]`. Attempts to reproduce with non-streaming failed (where you add `&near=_agent` to the read queries and ensure `X-Consul-Query-Backend: blocking-query` shows up in the results).

hc-github-team-consul-core · 2022-04-27T15:40:37Z

🍒❌ Cherry pick of commit 11213ae onto release/1.10.x failed! Build Log

…the most recent results when a filter is used with streaming Backport of #12640 to 1.11.x

…the most recent results when a filter is used with streaming (#12866) Backport of #12640 to 1.11.x

…the most recent results when a filter is used with streaming Backport of #12640 to 1.10.x

…the most recent results when a filter is used with streaming (#12868) Backport of #12640 to 1.10.x

rboyer requested a review from a team March 29, 2022 14:25

rboyer self-assigned this Mar 29, 2022

rboyer commented Mar 29, 2022

View reviewed changes

kisunji self-requested a review March 29, 2022 14:30

rboyer force-pushed the fix-blocking-query-bug branch from 5057681 to 19d53aa Compare April 11, 2022 21:37

vercel bot temporarily deployed to Preview – consul April 11, 2022 21:37 Inactive

vercel bot temporarily deployed to Preview – consul-ui-staging April 11, 2022 21:37 Inactive

vercel bot temporarily deployed to Preview – consul April 11, 2022 22:08 Inactive

vercel bot temporarily deployed to Preview – consul-ui-staging April 11, 2022 22:08 Inactive

vercel bot temporarily deployed to Preview – consul April 11, 2022 22:30 Inactive

vercel bot temporarily deployed to Preview – consul-ui-staging April 11, 2022 22:30 Inactive

rboyer force-pushed the fix-blocking-query-bug branch from af60ad3 to 5011885 Compare April 12, 2022 18:00

vercel bot temporarily deployed to Preview – consul-ui-staging April 12, 2022 18:00 Inactive

vercel bot temporarily deployed to Preview – consul April 12, 2022 18:00 Inactive

rboyer commented Apr 12, 2022

View reviewed changes

rboyer added the pr/no-metrics-test label Apr 12, 2022

rboyer changed the title ~~health: ensure /v1/health/service/:service endpoint returns the most recent results when a filter is used~~ health: ensure /v1/health/service/:service endpoint returns the most recent results when a filter is used with streaming Apr 12, 2022

changelog

4411e2c

vercel bot temporarily deployed to Preview – consul-ui-staging April 12, 2022 18:27 Inactive

vercel bot temporarily deployed to Preview – consul April 12, 2022 18:27 Inactive

eculver approved these changes Apr 20, 2022

View reviewed changes

rboyer added backport/1.10 labels Apr 20, 2022

rboyer merged commit 11213ae into main Apr 27, 2022

rboyer deleted the fix-blocking-query-bug branch April 27, 2022 15:39

rboyer added a commit that referenced this pull request Apr 27, 2022

[1.11.x] health: ensure /v1/health/service/:service endpoint returns …

e31e1a2

…the most recent results when a filter is used with streaming Backport of #12640 to 1.11.x

rboyer mentioned this pull request Apr 27, 2022

[1.11.x] health: ensure /v1/health/service/:service endpoint returns the most recent results when a filter is used with streaming #12866

Merged

rboyer removed backport/1.10 labels Apr 27, 2022

rboyer added a commit that referenced this pull request Apr 27, 2022

[1.11.x] health: ensure /v1/health/service/:service endpoint returns …

637a054

…the most recent results when a filter is used with streaming (#12866) Backport of #12640 to 1.11.x

rboyer added a commit that referenced this pull request Apr 27, 2022

[1.10.x] health: ensure /v1/health/service/:service endpoint returns …

e39eef9

…the most recent results when a filter is used with streaming Backport of #12640 to 1.10.x

rboyer mentioned this pull request Apr 27, 2022

[1.10.x] health: ensure /v1/health/service/:service endpoint returns the most recent results when a filter is used with streaming #12868

Merged

rboyer added a commit that referenced this pull request Apr 27, 2022

[1.10.x] health: ensure /v1/health/service/:service endpoint returns …

bd0d70b

…the most recent results when a filter is used with streaming (#12868) Backport of #12640 to 1.10.x

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

health: ensure /v1/health/service/:service endpoint returns the most recent results when a filter is used with streaming #12640

health: ensure /v1/health/service/:service endpoint returns the most recent results when a filter is used with streaming #12640

rboyer commented Mar 29, 2022 •

edited

Loading

rboyer Mar 29, 2022

eculver Apr 20, 2022

rboyer Apr 20, 2022

rboyer Apr 20, 2022

rboyer Apr 20, 2022

rboyer Mar 29, 2022

kisunji commented Apr 4, 2022

rboyer Apr 12, 2022

eculver left a comment

hc-github-team-consul-core commented Apr 27, 2022

hc-github-team-consul-core commented Apr 27, 2022

hc-github-team-consul-core commented Apr 27, 2022

hc-github-team-consul-core commented Apr 27, 2022

health: ensure /v1/health/service/:service endpoint returns the most recent results when a filter is used with streaming #12640

health: ensure /v1/health/service/:service endpoint returns the most recent results when a filter is used with streaming #12640

Conversation

rboyer commented Mar 29, 2022 • edited Loading

rboyer Mar 29, 2022

Choose a reason for hiding this comment

eculver Apr 20, 2022

Choose a reason for hiding this comment

rboyer Apr 20, 2022

Choose a reason for hiding this comment

rboyer Apr 20, 2022

Choose a reason for hiding this comment

rboyer Apr 20, 2022

Choose a reason for hiding this comment

rboyer Mar 29, 2022

Choose a reason for hiding this comment

kisunji commented Apr 4, 2022

rboyer Apr 12, 2022

Choose a reason for hiding this comment

eculver left a comment

Choose a reason for hiding this comment

hc-github-team-consul-core commented Apr 27, 2022

hc-github-team-consul-core commented Apr 27, 2022

hc-github-team-consul-core commented Apr 27, 2022

hc-github-team-consul-core commented Apr 27, 2022

rboyer commented Mar 29, 2022 •

edited

Loading