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

fix watch event behavior #5265

Merged
merged 5 commits into from
Dec 10, 2019

Conversation

ogidow
Copy link
Contributor

@ogidow ogidow commented Jan 24, 2019

Fixes: #3742

consul watch holds the index of the previous event.
If the index of this event is smaller than the index of the previous event, execute the handler once, give the event that can be acquired by the event list api, and execute handler again.
since index is calculated based on event id and event id is completely randomly generated by uuid, it is not guaranteed that the index of the new event is larger than the index of the old event.

In other words, handler will be executed multiple times at random by firing one event.
In order to prevent this problem, I monotonously increase ltime as metadata of event list api, and consider ltime with logic to initialize index to 0.

@hashicorp-cla
Copy link

hashicorp-cla commented Jan 24, 2019

CLA assistant check
All committers have signed the CLA.

watch/watch.go Outdated
return wil
}
prevWil, ok := previous.(WaitIndexAndLtimeVal)
if ok && prevWil.Index > wil.Index && prevWil.Ltime > wil.Ltime {
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

If index is effectively random then surely prevWil.Index > wil.Index will be true half the time. But may or may not be true in the event that Ltime actually does go backwards (e.g. agent restart).

I suspect we'd need to remove that second term but still do the reset if Ltime ever goes backwards.

I have other questions but if we decide to go ahead with this approach just wanted to note this.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

That's exactly right!

By the way, I do not understand correctly, but I would like you to tell me that the existing code will be reset when the index goes in the opposite direction, but what kind of situation is it intended for?

Whether or not index goes backwards is random.
If index does not need to be reset even if it is backwards, it may be the easiest way to prevent handler from being executed twice.

Copy link
Member

@banks banks Jan 25, 2019

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

In normal blocking the index can go backwards in some regular cases (KV listing where keys are deleted after the GC window) and generally if the servers are restored from a snapshot. It's rare but a case that needs to be handled so clients don't just get stuck in those cases.

Reseting the index here will cause the next request NOT to block even if nothing changed - effectively starting the loop again.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@banks

Since snapshot does not hold data of event, even when server is restored from snapshot, data of event held by server will not be rewound. Therefore, it seems unnecessary to initialize the event loop.

It was impossible to reproduce the procedure where the index always goes backward in the local environment.
If there is a case where it is possible to reproduce that index surely goes backwards, it would be nice if you could tell me

I checked the pull request when the index was reset.
The problem mentioned in this pull request is that when the server is restarted the client will not reconnect until a new event occurs.
For this problem, https: // github.com/hashicorp/consul/blob/master/watch/plan.go#L78 is always true for event watch.
Therefore, when an error occurs, the event loop is reset immediately, and the client is guaranteed to reconnect.


Although I mentioned a few times, index is not guaranteed monotonously because it is completely randomly generated by uuid.
It is shown below.

// test.go
package main

import(
	"fmt"
	"strconv"

	"github.com/hashicorp/go-uuid"
)

func main(){
	for i := 1; i <= 10; i++ {
		uuid, _ := uuid.GenerateUUID()
	    fmt.Println(IDToIndex(uuid))
	}
}

// Implemented by referring to https://github.com/hashicorp/consul/blob/master/api/event.go#L92-L104
func IDToIndex(uuid string) uint64 {
	lower := uuid[0:8] + uuid[9:13] + uuid[14:18]
	upper := uuid[19:23] + uuid[24:36]
	lowVal, err := strconv.ParseUint(lower, 16, 64)
	if err != nil {
		panic("Failed to convert " + lower)
	}
	highVal, err := strconv.ParseUint(upper, 16, 64)
	if err != nil {
		panic("Failed to convert " + upper)
	}
	return lowVal ^ highVal
}
$ go run test.go
14805484469619311927
18361606342644028951
7641949632114442332
5158521267128917138
3464233816796319261
1658475967534741711
13618032119971498876
8217686710200730108
1010599251150574682
1968815759883026800

Therefore, whether an event loop is initialized or not is completely random.
In addition, event loops are unintentionally initialized with high probability.
Probably this is a bug.

Since the index value is random, since index goes backward, it can not be inferred what kind of action occurred.
Therefore, it is better to compare only monotonically increasing ltime and use it for index initialization. What do you think

@banks
Copy link
Member

banks commented Jan 24, 2019

Hey thanks @ogidow for this contribution!

I think the implementation you've come up with is smart! I'm not totally sure if it makes sense to include this for a couple of reasons though so I've flagged it for more discussion. My initial thoughts are:

  1. Is Ltime really monotonic in Serf? Serf is weakly consistent so it's impossible that it can have globally consistent monotonic properties in a single int - the guarantee raft indexes have. If it doesn't then I'm not sure all this extra machinery actually does what we want. I need to go recap how Serf uses that to be sure of the subtelties.
  2. Another slight variation on blocking query params makes me a bit nervous - medium term I plan to change how blocking works and having more edges and complicated cases in the code to keep supporting isn't ideal.
  3. In general Serf events are unordered, best effort and weakly consistent. I realise this probably does make them behave more like one might expect but it's not obvious to me that the extra complexity is worth it when it doesn't actually guarantee delivery in order as with Raft-based state.

If you have any opinions on those things and have looked into this deeply, we'd be glad to hear them! Otherwise we'll add it to the queue to take a deeper look.

Thanks again!

@banks banks added the needs-discussion Topic needs discussion with the larger Consul maintainers before committing to for a release label Jan 24, 2019
@ogidow
Copy link
Contributor Author

ogidow commented Jan 25, 2019

@banks

thank you for your comment.
I am worried that I can correctly understand the intention of the question, but prepared an answer.
What I am troubled as a precondition is that the handler is executed multiple times with one event firing.
If you have any other reasonable solutions, please let me tell

  1. When a user event occurs, it is communicated to the leader node by rpc communication. And the leader node processes the event
    ref https://github.com/hashicorp/consul/blob/master/agent/consul/internal_endpoint.go#L68
    https://www.consul.io/docs/internals/consensus.html#raft-in-consul
    All events are handled by the leader node.
    Since lamport time is counted as atomic when processing an event, I think that it is guaranteed that the leader node will monotonically increase in the order in which events are processed
    ref: https://github.com/hashicorp/serf/blob/master/serf/serf.go#L444-L445
    https://github.com/hashicorp/serf/blob/master/serf/lamport.go

  2. Blocking queries have been issued with half the probability of the current situation, Also, even in the case of blocking queries, if the event of index different from the current index is fired then the query will come back so we do not think there is any problem to that
    ref: https://github.com/hashicorp/consul/blob/master/agent/event_endpoint.go#L174

  3. best efrrort recognizes that it means that events are not guaranteed to be propagated to all nodes.
    I do not feel that it is not a problem that it is not guaranteed that the event will reach all nodes.
    It is a problem that it is a problem that multiple handlers are executed with one event, and it is the purpose of this PR to prevent it

@ogidow
Copy link
Contributor Author

ogidow commented Jan 31, 2019

@banks

by b6772cd , the reset of the index is now determined by ltime
I would like to ask your opinion

@banks
Copy link
Member

banks commented Mar 21, 2019

  1. When a user event occurs, it is communicated to the leader node by rpc communication. And the leader node processes the event

Hmmmm, that's not quite right. In normal cases Events are propagated only by Serf (gossip) in the local datacenter - they don't go through the leader and so there is no notion of consistent order for any two events triggered on different nodes. The delivery is best-effort, and may be duplicated or dropped without reaching everyone.

The code you linked to in the leader RPC is only used for relaying User events from one DC to another. That cross-DC RPC can be made to any other server in the other DC not just the leader, and then that server simply publishes the event through Serf/gossip in its own DC.

This is what I mean by events not having strong guarantees by design. This PR might improve things a bit but it can't make it perfectly reliable as it just isn't inherently which is why I'm wary of the added complication - no one should rely on Events for anything that requires either reliable delivery or at-most-once etc.

It is a problem that it is a problem that multiple handlers are executed with one event, and it is the purpose of this PR to prevent it

Even our raft-based blocking queries don't make an exactly-once guarantee and can deliver the same payload twice due to idempotent updates and other details of how they are implemented. I don't think it's possible to do so with eventually consistent events either.

Suggestion

Wouldn't it be possible to fix the random nature of the triggering just by using equality match on the last event ID instead of less than? It's not perfect but then we established it can't be anyway. That is in fact the same thing we do for "hash based" blocking so we could re-use the same mechanism and turn events into "hash based" but then encode the int into a hash instead of treating it like an integer index. I think that solves the issue here without exposing logical time counters which don't really provide strong guarantees and are very hard to understand.

@ogidow
Copy link
Contributor Author

ogidow commented Mar 22, 2019

Thanks for the detailed description and suggestions for corrections!

Wouldn't it be possible to fix the random nature of the triggering just by using equality match on the last event ID instead of less than?

When I tried it, I was able to correct the random property by the method of suggestion

@hanshasselberg hanshasselberg force-pushed the fix-fire-multiple-handler branch from 3be7f60 to 3de2bf5 Compare December 9, 2019 11:29
@hanshasselberg hanshasselberg self-assigned this Dec 9, 2019
@codecov
Copy link

codecov bot commented Dec 9, 2019

Codecov Report

Merging #5265 into master will increase coverage by <.01%.
The diff coverage is 0%.

Impacted file tree graph

@@            Coverage Diff            @@
##           master   #5265      +/-   ##
=========================================
+ Coverage   65.79%   65.8%   +<.01%     
=========================================
  Files         439     439              
  Lines       52741   52741              
=========================================
+ Hits        34702   34707       +5     
+ Misses      13868   13861       -7     
- Partials     4171    4173       +2
Impacted Files Coverage Δ
api/watch/watch.go 49.57% <0%> (ø) ⬆️
command/monitor/monitor.go 52% <0%> (-4%) ⬇️
agent/consul/operator_autopilot_endpoint.go 46% <0%> (-4%) ⬇️
agent/cache/watch.go 78.75% <0%> (-2.5%) ⬇️
agent/consul/leader_connect.go 71.02% <0%> (-1.31%) ⬇️
api/watch/funcs.go 75.64% <0%> (-1.04%) ⬇️
agent/consul/acl.go 87.9% <0%> (-0.11%) ⬇️
agent/consul/acl_replication.go 75.9% <0%> (ø) ⬆️
command/debug/debug.go 66.56% <0%> (ø) ⬆️
agent/consul/acl_endpoint.go 56.69% <0%> (+0.15%) ⬆️
... and 7 more

Continue to review full report at Codecov.

Legend - Click here to learn more
Δ = absolute <relative> (impact), ø = not affected, ? = missing data
Powered by Codecov. Last update 34649b8...3de2bf5. Read the comment docs.

Copy link
Member

@banks banks left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

It's been a long time - apologies for that, but I'm glad this simpler fix worked without adding extra complexity!

Thanks for your contribution!

@hanshasselberg hanshasselberg merged commit dfa8d91 into hashicorp:master Dec 10, 2019
@ghost
Copy link

ghost commented Jan 25, 2020

Hey there,

This issue has been automatically locked because it is closed and there hasn't been any activity for at least 30 days.

If you are still experiencing problems, or still have questions, feel free to open a new one 👍.

@ghost ghost locked and limited conversation to collaborators Jan 25, 2020
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
needs-discussion Topic needs discussion with the larger Consul maintainers before committing to for a release
Projects
None yet
Development

Successfully merging this pull request may close these issues.

Confused by watch event behavior. Maybe bug?
4 participants