-
Notifications
You must be signed in to change notification settings - Fork 2.9k
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
Reduce "stale identity observed" warnings #27894
Reduce "stale identity observed" warnings #27894
Conversation
This is great, thanks for the PR! I'm tagging some folks who are more familiar with datapath along with Hubble to help review since this touches on both aspects. |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
This is an amazing piece of work, thanks so much for the investigation and detailed description.
Overall, I think the cases you found all sound reasonable. But I do agree that there is some fragility introduced here, the code is very likely to desync with the datapath over time.
Maybe another option to explore would be if we can find some simple heuristic that works "well enough" to cover most cases. Looking at all the different cases you mentioned, all of the either involve a reserved identity or a world identity.
In the end, assuming there will never be perfect parity due to the information asymmetry between datapath and userspace, I think we need to decide if we want to live with false positives or false negatives.
At the moment, we have lots of false positives (i.e. "stale" log lines for entries that are not actually stale), but no false negatives, because we just log everything.
The current solution in this PR at the removes most of the false positives, while also probably introducing some rare false negatives. It's clearly an improvement, but it has the downside that it's a complex heuristic that can become obsolete if the datapath changes.
A extreme on the other side could be to only log it if both identities are neither reserved nor world, since it seems that this would cover most of the cases here too. In such an implementation, we would have as few false positives as your current solution, at the cost of some false negatives (i.e. we might actually miss some stale IPCache entries if we do that).
I don't really where we should land on the false positive vs false negative tradeoff. I'm tempted to accept a decent amount of false negatives if the false positive rate low. In the end, any logging with lots of false positives will not provide much value, because it just comes too noisy.
I'll also bring this up with some other @cilium/sig-hubble members.
Thanks for the review! I agree, I think a simpler and more general heuristic would be easier to maintain and hopefully work well enough. It got me thinking: what are the cases that we are trying to notice with this log warning? I think there is perhaps one case where the BPF map is not updated quickly enough and userspace has a different view of the ip/identity mapping than the datapath has. Is that the only case? If it is, another option might be putting a special trace/debug event after each call to |
The main motivation was to collect some data to understand why datapath and Hubble would diverge. Unfortunately, no one ever followed up on that until you did, so thanks a lot for that!
Yeah, I think besides the logical discrepancies that you documented, this map sync lag the only major reason why we would observe "stale identities".
I'm not sure what you mean by this? Could you elaborate a bit? On a more high-level note: We've discussed this PR with some members of the Hubble team and we think the approach PR strikes a good balance between false positives and negatives. It provides a lot of value to have those cases documented in the code, so having them as separate cases is probably more meaningful than having a heuristic. So we're fine to merge this as is, assuming the issue with the endpoint manager is fixed. |
There is a "legitimate" CI error: https://github.com/cilium/cilium/actions/runs/6055381175/job/16434222880?pr=27894#step:4:23 |
I'm converting this to Draft since there is outstanding feedback to be addressed. Please click on "Ready for review" once you've made the necessary changes. |
Thanks! |
Sorry for the delay.
The idea is similar to this section of code: Lines 486 to 504 in 9aa5068
Whenever we call I can fix up the local endpoint check and address the test failures. |
I see, thanks for the clarification! While I think we could add a trace message there, I actually think the existing debug message already serves that purpose. What we could consider is making it a "debug capture" message, so we also have packet context if needed. I think it becomes more clear to me now that the
As outlined in the amazing PR description, I think you've identified quite a few gaps where Hubble annotates potentially misleading data. Therefore one could argue that the log message has now mostly outlived it's purpose at this point. Instead, the it might be more useful to understand how can we fix the identified mismatches such that Hubble correctly annotates flows going forward. Having said that, I'm more than happy to accept the overall PR (assuming fixed endpoint lookup and tests). Even if I mentioned that I believe the log message kind of became obsolete thanks to the fact that we now know where the discrepancies are coming from, there might still be more cases out there in the wild that we haven't discovered yet. For the Hubble project in general, I think the plan forward here should be:
|
In Hubble, ignore certain cases where the datapath security ID does not match the userspace security ID. Signed-off-by: Lucas Leblow <lucasleblow@mailbox.org>
d401cc3
to
c7b653a
Compare
Thanks! That makes sense. I think I've fixed up the PR. |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Awesome work, this looks good now! Thanks a lot
/test |
(Awaiting two unresolved conversations to be resolved before merging) |
Mine has been resolved. cc @chancez if you want to take a look |
To be honest, most of it's incomprehensible to me, so I'll just remove myself as a reviewer 😅 |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I guess I cannot remove myself, so ✅
@chancez your review was requested specifically on behalf of hubble, so I think the minimum is just the mechanical aspects of changes to those specific files. It looks like @gandro already engaged from a broader perspective so we're probably good on the general feedback side. Thanks for the review! EDIT: Ah I see what happened now, Sebastian reviewed on behalf of the same codeowner and at that point you can't drop your review request. Never mind my post above :) |
Let's backport this in order to improve the situation in CI #15283 |
Please ensure your pull request adheres to the following guidelines:
description and a
Fixes: #XXX
line if the commit addresses a particularGitHub issue.
Fixes: <commit-id>
tag, thenplease add the commit author[s] as reviewer[s] to this issue.
Overview
Hi, I've been looking into the "stale identity observed" issues (#14427 and #15283) and documented some of the situations where I've seen these log messages in my setup. Ultimately, I think the log messages arise from a misunderstanding between the datapath and Hubble. In the cases I studied, the datapath looks like it's using an appropriate identity. However Hubble has a limited amount of information and isn't really aware of what the datapath is doing in these situations. It just recieves an IP and security identity from the datapath and warns if the security identity doesn't match the IP cache security identity. However, in some cases, the datapath doesn't use the IP cache security identity, or it sends trace notify events before resolving a security identity via the IP cache, or hardcodes an identity when tunneling a packet, or when a proxy is involved, the datapath doesn't know the original IP for a given security identity.
Currently, this warning is not very helpful. There are so many warnings that it's easy to ignore them.
One solution is to see if we can create various conditions on the Hubble side so that it can tell when to send a warning, such that the warnings are actually meaningful. That's what I've explored in this PR.
Case 1
When encapsulating a packet for sending via the overlay network, if the source seclabel = HOST_ID, then we reassign seclabel with LOCAL_NODE_ID and then send a trace notify:
cilium/bpf/lib/encap.h
Line 39 in c7bf490
In this case any packets with identity HOST_ID, are going to result in warnings from Hubble.
A simple solution is to ignore stale TRACE_TO_OVERLAY events when datapath security ID = remote_node && userspace security ID = host.
Here is an example:
In this case 10.244.1.40 is the IP address of cilium_host.
Case 2
Sometimes packets from endpoint link-local addresses are intercepted by cil_from_container. Because link-local addresses are not stored in the IP cache, Hubble assigns them ID 2 (WORLD_ID) (edit: now 9 or 10 for WORLD_IPV4/IPV6).
Here is an example:
fe80::c809:60ff:fecd:ab08 is the link-local address of the cilium-health-responder namespace. I've also observed endpoint link-local addresses.
A simple solution is to ignore stale TRACE_FROM_ENDPOINT events when datapath source security ID = {4 | !reserved} && userspace security ID is a world ID. Alternatively, in this case, I wonder if we can just add link-local addresses to the IP cache or prevent endpoints from sending these packets.
Case 3
When a pod sends a packet to the Kubernetes API its IP is masqueraded and then when it receives a response and the masquerade is reversed, cil_from_host determines that the source ID is 2 (edit: now 2, 9 or 10) because there is no packet mark.
Here is an example:
In this case, we can see 10.244.1.242 (a CoreDNS instance) is reaching out to 10.96.0.1 (the ClusterIP for the Kubernetes API). 10.96.0.1 get's resolved to 172.20.0.3. And then 10.244.1.242 get's masqueraded to 172.20.0.2 when it's being sent out via eth0. When the response is recieved, 172.20.0.2 is reversed to 10.244.1.242 and then it's routed to cilium_host. It's at this point that the datapath considers the ID as 2 because there isn't any mark on the packet.
A simple solution is to ignore stale TRACE_FROM_HOST events when datapath source security ID = 2 (edit: now 2, 9 or 10) and userspace security ID = 7. In general, if packets are picked up by cil_from_host and they do not have a packet mark, the TRACE_FROM_HOST event will contain ID = 2 (edit: now 2, 9 or 10), as that's the default in inherit_identity_from_host, and the trace happens before any IP cache resolution. Should inherit_identity_from_host return unknown by default?
Case 4
When proxied packets (via Cilium DNS proxy) are sent from the host their source IP is that of the host, yet their security identity is retained from the original source pod.
Here is an example:
In this case, 10.244.1.11 sends a DNS request to 10.96.0.10, which get's resolved to 10.244.0.127. The Cilium DNS proxy recieves the packet and sends it back out via cilium_host with address 10.244.1.40. Since the packet retains it's original source security ID, we recieve a warning from both TRACE_FROM_HOST and TRACE_TO_OVERLAY events.
A simple solution is to ignore stale TRACE_FROM_HOST/TRACE_TO_OVERLAY events when datapath source security ID is a local endpoint ID and userspace security ID = 1.
Case 5
When proxied packets (via Cilium DNS proxy) are recieved by the destination host their source IP is that of the proxy, yet their security identity is retained from the original source pod. This is a similar case to #4, but on the receiving side.
In one case, the packet is sent to a DNS instance on the same host:
And alternatively, to a separate host:
This results in a stale identity warning from TO_ENDPOINT when delivering to DNS servers on the same host and remote hosts.
A simple solution is to ignore stale TRACE_TO_ENDPOINT events where the datapath source security ID isn't reserved (must be an endpoint) and the userspace security ID is either 1 (host) or 6 (remote-node).
Case 6
When reinstalling Cilium and the agent is just starting, packets arrive via tunnel for the health responder, for some reason instead of going directly to the health responder endpoint, they are passed to the stack.
In this case 10.244.1.104 is the health endpoint.
Perhaps because the endpoint map is not updated quickly enough, these packets get routed to the host and appear to enter a routing loop.
The reason we get a warning is because at the beginning of cil_from_host, it only checks the packet mark for a security ID and then immediately sends a trace notify. These packets are coming from another host so they don't have a packet mark. After cilium get's up and going these warnings go away. In this instance I think we have an actual issue, due to a race condition at startup, though I'm not entirely sure how it could be solved or if it needs to be.
Case 7
Link-local packets appear to be dropped and drop-notify events also cause stale identity (due to them missing from the ipcache). I haven't addressed this case yet.
Alternatives
This PR does limit the warnings, but it seems like there is also a possibility that it limits legitimate warnings. I'm not sure I know enough about the various datapath cases to tell for sure. But, ignoring certain messages based on assumptions of how the datapath is working seems fragile. Just during the time I was preparing this PR, we added new identities for WORLD_IPV4 and WORLD_IPV6 which broke the logic. Perhaps a better solution would be to use different events besides trace/drop notify for these warnings. That way we can emit events from specific points in the datapath and warn on all of these events if they contain stale/incorrect information. It seems like another solution would be to potentially change some of the trace notify calls in the datapath, so they emit information that's more in sync with what userspace expects. But that seems like it would obscure the actual workings of the datapath.