Add agent notifications & access log records to monitor #2667

tgraf · 2018-01-28T15:42:14Z

This heavily extends the notifications sent via the monitor protocol to include:

Agent notifications for events such as agent start, endpoint regeneration, and so on.
L7 log records for API call access notifications

Examples:

Endpoint to endpoint:

<- endpoint 56326 flow 0x98e163f identity 264->0 state new ifindex 0: 10.11.129.91:36188 -> 10.0.2.3:53 udp
-> 0: 10.11.129.91:36188 -> 10.0.2.3:53 udp
<- host flow 0x2dd24244 identity 1->0 state new ifindex enp0s3: 10.0.2.3:53 -> 10.11.129.91:36188 udp
-> endpoint 56326 flow 0x2dd24244 identity 1->264 state reply ifindex lxca3056: 10.0.2.3:53 -> 10.11.129.91:36188 udp

<- endpoint 56326 flow 0xe0f8d00c identity 268->0 state new ifindex 0: 10.11.129.91 -> 213.144.137.178 EchoRequest
-> 0: 10.11.129.91 -> 213.144.137.178 EchoRequest
<- host flow 0xe0f8d00c identity 1->0 state new ifindex enp0s3: 213.144.137.178 -> 10.11.129.91 EchoReply
-> endpoint 56326 flow 0xe0f8d00c identity 1->268 state reply ifindex lxca3056: 213.144.137.178 -> 10.11.129.91 EchoReply

Proxy redirection

<- endpoint 56326 flow 0xd4316c25 identity 268->0 state new ifindex 0: 10.11.129.91:55334 -> 172.217.19.14:80 tcp SYN
-> proxy flow 0xd4316c25 identity 268->0 state new ifindex cilium_net: 10.11.129.91:55334 -> 172.217.19.14:80 tcp SYN
-> proxy port 10000: 10.11.129.91:55334 -> 10.11.28.238:10000 tcp SYN
-> cilium_net: 10.11.129.91:55334 -> 10.11.28.238:10000 tcp SYN
<- host flow 0x68f94f8f identity 1->0 state new ifindex 0: 10.11.28.238:10000 -> 10.11.129.91:55334 tcp SYN, ACK
-> proxy port 0: 172.217.19.14:80 -> 10.11.129.91:55334 tcp SYN, ACK
-> endpoint 56326 flow 0x68f94f8f identity 1->268 state reply ifindex lxca3056: 172.217.19.14:80 -> 10.11.129.91:55334 tcp SYN, ACK

Endpoint regeneration messages:

-> endpoint 29381 flow 0x2a545f24 identity 1->322 state reply ifindex lxcc8154: 10.0.2.3:53 -> 10.11.193.100:56446 udp
>> Endpoint regenerated: 29381 (container:id.foo)
<- endpoint 29381 flow 0xb0cb1cf6 identity 322->0 state new ifindex 0: 10.11.193.100:48454 -> 10.0.2.3:53 udp

L7 access log:

-> endpoint 29381 flow 0x37a5c90b identity 1->322 state reply ifindex lxcc8154: 172.217.19.14:80 -> 10.11.193.100:41252 tcp ACK
-> http from 29381 ([container:id.foo]) to 0 ([reserved:world]), identity 322->2, verdict Forwarded GET http://google.com/ => 0
<- proxy flow 0x8922ff53 identity 322->0 state new ifindex 0: 10.11.28.238:43064 -> 172.217.19.14:80 tcp SYN

Fixes: #2379

Add agent notifications & access log records to monitor

tgraf · 2018-01-28T15:42:21Z

test-me-please

tgraf · 2018-01-28T15:49:42Z

test-me-please

houndci-bot · 2018-01-29T13:29:47Z

pkg/monitor/types.go

+
+// Must be synchronized with <bpf/lib/common.h>
+const (
+	// 0-128 are reserved for BPF datapath events


comment on exported const MessageTypeUnspec should be of the form "MessageTypeUnspec ..."

houndci-bot · 2018-01-29T13:29:47Z

pkg/monitor/agent.go

+type AgentNotification uint32
+
+const (
+	AgentNotifyUnspec AgentNotification = iota


exported const AgentNotifyUnspec should have comment (or a comment on this block) or be unexported

houndci-bot · 2018-01-29T13:29:47Z

monitor/launch/launcher.go

@@ -37,9 +47,25 @@ func (m *NodeMonitor) GetPid() int {
 }

 // Run starts the node monitor.
-func (nm *NodeMonitor) Run() {
+func (nm *NodeMonitor) Run(sockPath string) {


receiver name nm should be consistent with previous receiver name m for NodeMonitor

houndci-bot · 2018-01-29T13:29:48Z

daemon/daemon.go

@@ -1345,3 +1349,62 @@ func (d *Daemon) GetServiceList() []*models.Service {
 	}
 	return list
 }
+
+func (d *Daemon) SendNotification(typ monitor.AgentNotification, text string) error {


exported method Daemon.SendNotification should have comment or be unexported

tgraf · 2018-01-29T13:30:47Z

test-me-please

tgraf · 2018-01-29T13:40:20Z

test-me-please

tgraf · 2018-01-29T13:43:02Z

test-me-please

tgraf · 2018-01-29T14:06:52Z

test-me-please

aanm · 2018-01-29T14:28:38Z

pkg/bpfdebug/ifindex.go

+			mutex.Unlock()
+
+		sleep:
+			time.Sleep(time.Duration(15) * time.Second)


Wouldn't be easier to have a function to add/remove interfaces whenever a new endpoint is added or removed?

This allows resolving of all interface names including cilium_host, cilium_net, cilium_vxlan, and native interfaces.

aanm · 2018-01-29T14:37:45Z

pkg/bpfdebug/trace.go

 		n.traceSummary(), n.Hash, n.SrcLabel, n.DstLabel,
-		connState(n.Reason), GetConnectionSummary(data[TraceNotifyLen:]))


There's going to be a lock/unlock for every single packet now. Won't this make the monitor slower and the connections slower as well?

The bottleneck will be the gob decode/encode. The lock is absolutely fine here.

aanm · 2018-01-29T14:40:12Z

pkg/endpoint/endpoint.go

+		labels = e.SecLabel.Labels.String()
+	}
+
+	return fmt.Sprintf("%d (%s)", e.ID, labels)


Maybe the labels are not important. I would replace it with the security ID + container ID (or perhaps name) to be less verbose.

I think the labels are absolutely ideal as they typically contain the application name. Happy to add the container ID but I think it will matter less and less in a cluster enviroment where such IDs are meaningless as they have a scope of a node.

On second thought, we should try to hide runtime specific identification such as the container ID as we are very likely to handle non containerised endpoints in the future.

* TRACE_TO_HOST was only emitted if policy enforcement was disabled * Add TRACE_FROM_* traces to enable monitor to show any packet being processed and to provide the initial processing context. This guarantees that ever packet being processed is being shown in the monitor. Signed-off-by: Thomas Graf <thomas@cilium.io>

Signed-off-by: Thomas Graf <thomas@cilium.io>

The monitor will now notify on endpoint regenerations: >> Endpoint regenerated: 29898 (reserved:health) >> Endpoint regenerated: 29381 (container:id.foo) and accesslog entries: -> http from 29381 ([container:id.foo]) to 0 ([reserved:world]), identity 322->2, verdict Forwarded GET http://google.com/ => 0 Signed-off-by: Thomas Graf <thomas@cilium.io>

ianvernon

CLI / CI / API changes look fine. Have a few questions, nothing blocking though.

ianvernon · 2018-01-29T18:02:57Z

pkg/endpoint/policy.go

@@ -766,9 +767,12 @@ func (e *Endpoint) Regenerate(owner Owner, reason string) <-chan bool {
 				buildSuccess = false
 				scopedLog.WithError(err).Warn("Regeneration of endpoint program failed")
 				e.LogStatus(BPF, Failure, "Error regenerating endpoint: "+err.Error())
+				owner.SendNotification(monitor.AgentNotifyEndpointRegenerateFail,


The return value of this function is being ignored - should we log at debug level if it fails? Potential downside of clogging the logs, though.

I thought about it and initially decided against it. This is still low volume so I have nothing against logging as debug. Will add it.

ianvernon · 2018-01-29T18:03:29Z

pkg/endpoint/policy.go

 			} else {
 				buildSuccess = true
 				e.LogStatusOK(BPF, "Successfully regenerated endpoint program due to "+reason)
+				owner.SendNotification(monitor.AgentNotifyEndpointRegenerateSuccess, e.getIDandLabels())


Same as above:
The return value of this function is being ignored - should we log at debug level if it fails? Potential downside of clogging the logs, though.

manalibhutiyani · 2018-01-29T18:20:31Z

@tgraf I believe this will also fix #2379 ?

joestringer

LGTM, minor IPv4/IPv6 tracing discrepancy introduced by rearranging POLICY_EGRESS.

joestringer · 2018-01-29T20:36:30Z

bpf/bpf_lxc.c

 		send_trace_notify(skb, TRACE_TO_HOST, SECLABEL, HOST_ID, 0, HOST_IFINDEX,
 				  forwarding_reason);
+
+#ifndef POLICY_EGRESS


I think previously these POLICY_EGRESS ifdefs avoided calling send_trace_notify() because it was expected that the cilium_reserved_policy tail call would do the appropriate tracing.

If we want the tracing like this patch has changed it, we should apply the same to IPv4; otherwise we should probably drop these changes.

@joestringer I assume you are talking about the following:

if (policy_can_access(&POLICY_MAP, skb, src_label, 0, 0, 0, NULL) != TC_ACT_OK) { return send_drop_notify(skb, src_label, SECLABEL, 0, ifindex, DROP_POLICY, TC_ACT_SHOT); } else { cilium_dbg_capture(skb, DBG_CAPTURE_DELIVERY, ifindex);

The main issue I have with the current code is that the TO_HOST trace is only emitted if policy is disabled. The policy code will later emit a debug capture but it is subject to debugging being enabled whereas tracing is not.

I will add a debug capture just before the redirect() in the policy disabled case so we have symmetry and also emit a debug capture for the policy disabled case.

Regarding IPv6, good catch!

joestringer · 2018-01-29T20:39:23Z

bpf/bpf_netdev.c

@@ -427,6 +448,7 @@ int from_netdev(struct __sk_buff *skb)

 #ifdef ENABLE_IPV4
 	case bpf_htons(ETH_P_IP):
+		skb->cb[0] = proxy_identity;


skb->cb[CB_SRC_LABEL], perhaps?

joestringer · 2018-01-29T20:39:45Z

bpf/bpf_netdev.c

@@ -395,7 +398,8 @@ static inline int handle_ipv4(struct __sk_buff *skb)

 __section_tail(CILIUM_MAP_CALLS, CILIUM_CALL_IPV4) int tail_handle_ipv4(struct __sk_buff *skb)
 {
-	int ret = handle_ipv4(skb);
+	__u32 proxy_identity = skb->cb[0];


skb->cb[CB_SRC_LABEL], perhaps?

tgraf · 2018-01-29T22:44:44Z

@tgraf I believe this will also fix #2379 ?

Correct. Will add Fixes tag.

manalibhutiyani · 2018-01-29T22:48:04Z

Adding release notes as well

tgraf · 2018-01-29T23:21:01Z

test-me-please

tgraf · 2018-01-29T23:21:33Z

@manalibhutiyani Label is present, I'm using the title of the PR. Do you think it needs to be more verbose?

@joestringer Feedback addressed

@aanm Let me know if you are OK as-is.

manalibhutiyani · 2018-01-29T23:23:44Z

@tgraf :I actually meant "I am adding the label". It wasn't there before, hence added it. Looks good 👍

joestringer · 2018-01-30T00:35:47Z

bpf/bpf_netdev.c

@@ -393,9 +396,12 @@ static inline int handle_ipv4(struct __sk_buff *skb)
 	return TC_ACT_OK;
 }

+#define CB_SRC_IDENTITY 0


Would be nice to organise this next to the bpf/lib/common.h CB* declarations just so it's easier to trace them through the code.

I actually want to move away from that as the single declaration doesn't make it clear what it is used where. I'd rather list it above the tail call to make it super clear which cb fields are being used.

Ah yep, cool. We can move towards that.

(Not sure how we can try to make this verifiable that we don't accidentally reuse some field for an unintended purpose.. something to think about)

tgraf requested a review from a team January 28, 2018 15:42

tgraf requested a review from a team as a code owner January 28, 2018 15:42

tgraf force-pushed the fix-monitor branch from e975292 to fa10b58 Compare January 28, 2018 15:49

tgraf force-pushed the fix-monitor branch from fa10b58 to 17f7c1e Compare January 29, 2018 13:29

tgraf requested a review from a team January 29, 2018 13:29

tgraf requested review from a team as code owners January 29, 2018 13:29

houndci-bot reviewed Jan 29, 2018

View reviewed changes

tgraf added release-note/major This PR introduces major new functionality to Cilium. and removed release-note/minor This PR changes functionality that users may find relevant to operating Cilium. labels Jan 29, 2018

tgraf changed the title ~~Improved trace messages for the monitor~~ Add agent notifications & access log records to monitor Jan 29, 2018

tgraf force-pushed the fix-monitor branch from 17f7c1e to f4f2f24 Compare January 29, 2018 13:42

tgraf force-pushed the fix-monitor branch from f4f2f24 to 229a48b Compare January 29, 2018 14:06

aanm requested changes Jan 29, 2018

View reviewed changes

tgraf added the pending-review label Jan 29, 2018

tgraf added 3 commits January 29, 2018 08:22

monitor: Resolve interface index to interface names

aeb4a3d

Signed-off-by: Thomas Graf <thomas@cilium.io>

ianvernon approved these changes Jan 29, 2018

View reviewed changes

joestringer approved these changes Jan 29, 2018

View reviewed changes

manalibhutiyani approved these changes Jan 29, 2018

View reviewed changes

tgraf force-pushed the fix-monitor branch from 229a48b to 3d5724b Compare January 29, 2018 23:20

tgraf requested review from joestringer and aanm January 29, 2018 23:21

aanm approved these changes Jan 29, 2018

View reviewed changes

joestringer reviewed Jan 30, 2018

View reviewed changes

tgraf merged commit a1b5404 into master Jan 30, 2018

tgraf deleted the fix-monitor branch January 30, 2018 02:24

		n.traceSummary(), n.Hash, n.SrcLabel, n.DstLabel,
		connState(n.Reason), GetConnectionSummary(data[TraceNotifyLen:]))

Add agent notifications & access log records to monitor #2667

Add agent notifications & access log records to monitor #2667

Conversation

tgraf commented Jan 28, 2018 • edited by manalibhutiyani

tgraf commented Jan 28, 2018

tgraf commented Jan 28, 2018

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

tgraf commented Jan 29, 2018

tgraf commented Jan 29, 2018

tgraf commented Jan 29, 2018

tgraf commented Jan 29, 2018

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

ianvernon left a comment • edited

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

manalibhutiyani commented Jan 29, 2018

joestringer left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

tgraf commented Jan 29, 2018

manalibhutiyani commented Jan 29, 2018

tgraf commented Jan 29, 2018

tgraf commented Jan 29, 2018

manalibhutiyani commented Jan 29, 2018

Choose a reason for hiding this comment

Choose a reason for hiding this comment

joestringer Jan 30, 2018 • edited

Choose a reason for hiding this comment

tgraf commented Jan 28, 2018 •

edited by manalibhutiyani

ianvernon left a comment •

edited

joestringer Jan 30, 2018 •

edited