calicoctl node diags grab logs from hosted installs #1702

heschlie · 2017-08-16T16:57:37Z

Description

Fixes #1690
Fixes projectcalico/calico#810

With this change calicoctl node diags will pickup logs from hosted installs. This will allow for easier and quicker debugging when a user sends us their debug logs with hosted installs.

There is also a small change to add some clarity when a command fails, as before it was simply saying exit status 1 will now tell you what command failed to run. This will give the user a better idea of what failed to run in the diags.

I've tested this via the Calico vagrant demo and verified it works with and without Calico containers (obviously not writing any logs when there are no Calico containers present).

Todos

Tests
Documentation
Release note

Release Note

The [`calicoctl node diags`](https://docs.projectcalico.org/v2.6/reference/calicoctl/commands/node/diags) command now returns logs even when Calico is configured to log to stdout (such as in a hosted install).

bcreane · 2017-08-16T18:46:56Z

calicoctl/commands/node/diags.go

+	// Get a list of Calico containers running on this Node.
+	out, err := exec.Command("docker", "ps", "-a", "--filter", "\"name=calico\"", "--format", "{{.Names}}").Output()
+	if err != nil {
+		fmt.Printf("Could not run docker command: %s\n", err)


does it make sense to capture these failures (170 and 175) in the diag output? it's possible the errors are too unlikely to bother trying to capture.

It certainly isn't much effort to do, and could shed light on a possible permissions issue if the user isn't running as root. As for the No Calico containers found it might not really be an error, as someone might not be running a hosted install.

Also, this should be short circuiting here, and it's not :(

bcreane · 2017-08-17T00:22:56Z

lgtm!

gunjan5

a few questions/suggestions, but this feature will be very useful!

gunjan5 · 2017-08-20T05:10:53Z

calicoctl/commands/node/diags.go

@@ -134,6 +136,9 @@ func runDiags(logDir string) {
 		fmt.Printf("No logs found in %s; skipping log copying", logDir)
 	}

+	// Try to copy logs from containers for hosted installs.
+	getDockerLogs(tmpLogDir)


I think we should call this getContainerLogs, because in future if we want to add rkt logs or any other container runtime logs it sounds more generic

I think getHostedLogs might be more appropriate? As it is what we are trying to get, WDYT?

I like that!

gunjan5 · 2017-08-20T05:32:39Z

calicoctl/commands/node/diags.go

+	// Get a list of Calico containers running on this Node.
+	var stderr bytes.Buffer
+	cmd := exec.Command("docker", "ps", "-a", "--filter", "\"name=calico\"", "--format", "{{.Names}}")
+	cmd.Stderr = &stderr


I'm not sure if this is necessary. I think you can just do the following:

out,err := cmd.Output() if err != nil { fmt.Println("blah: %s\n", err.Stderr) return }

it might be err.(*ExitError).Stderr, I haven't tried it 🍰
From Golang spec:

Any returned error will usually be of type *ExitError. If c.Stderr was nil, Output populates ExitError.Stderr.

This gives me a runtime error if docker doesn't exist, but works if docker throws an error. Whereas the other method works in both situations.

gunjan5 · 2017-08-20T05:34:06Z

calicoctl/commands/node/diags.go

+func getDockerLogs(logDir string) {
+	os.Mkdir(logDir, os.ModeDir)
+
+	fmt.Println("Copying logs from Calico containers")


we should move this after line 182, since if we don't find any Calico containers then we print this message suggesting we're collecting logs but in fact we are not (and the debug log goes silently unnoticed by the user)

gunjan5 · 2017-08-20T05:35:55Z

calicoctl/commands/node/diags.go

+	}
+
+	// No Calico containers found.
+	if string(out) == "" {


not a fan of this variable name out, I think it should be containerNames, containers or cNames or something similar. WDYT?

gunjan5 · 2017-08-20T05:40:31Z

calicoctl/commands/node/diags.go

+		name := scanner.Text()
+		cLog, err := exec.Command("docker", "logs", name).Output()
+		if err != nil {
+			fmt.Printf("Could not pull log for container %s: %s\n", name, err)


shouldn't we continue here if we get an error from line 188? else it will try to access cLog which might be a nil in line 192

gunjan5 · 2017-08-20T05:42:08Z

calicoctl/commands/node/diags.go

@@ -26,6 +26,8 @@ import (
 	"github.com/docopt/docopt-go"
 	log "github.com/sirupsen/logrus"
 	shutil "github.com/termie/go-shutil"
+	"bufio"


nit: not sure if you ran goimports on this, but the recommendation is to have all the Go native imports together at the top

gunjan5

one tiny nit, then looks good!

gunjan5 · 2017-08-24T00:21:29Z

calicoctl/commands/node/diags.go


 	"github.com/docopt/docopt-go"
 	log "github.com/sirupsen/logrus"
-	shutil "github.com/termie/go-shutil"


nit: I much rather explicitly name the import when import name is different than the package name (not a good practice) like in this case package is shutil (and import is go-shutil) and we use shutil in the code, so I like to make it explicit.

Hm, I missed that, I agree with what you're saying, my IDE must have thought different.

gunjan5 · 2017-08-24T00:22:30Z

squash it when you address the last bit of nit (if you agree with it)

gunjan5

LGTM

heschlie · 2017-08-30T23:43:21Z

@caseydavenport could I get you to do a once over of this PR to see if we can get it merged?

caseydavenport

@heschlie finally got around to this!

A couple of things I think we should do and a question or two. LMK what you think.

caseydavenport · 2017-09-08T07:18:33Z

calicoctl/commands/node/diags.go

@@ -169,7 +212,7 @@ func writeDiags(cmds diagCmd, dir string) {

 	content, err := command.Output()
 	if err != nil {
-		fmt.Println(err)


We're losing the error in this log the way it's written now. I think we need to keep that so we can tell what failed.

I'll get this setup so we see the returned error from the command,. Before we were only getting an unexplained exit status 1 here.

caseydavenport · 2017-09-08T07:19:31Z

calicoctl/commands/node/diags.go

@@ -134,6 +136,9 @@ func runDiags(logDir string) {
 		fmt.Printf("No logs found in %s; skipping log copying", logDir)
 	}

+	// Try to copy logs from containers for hosted installs.
+	getHostedLogs(tmpLogDir)


a nit: this isn't specific to "self-hosted" calico installs - this is just "get stdout logs from any calico containers"

So, basically a change to the comment and function name (e.g. getNodeContainerLogs)

caseydavenport · 2017-09-08T07:21:06Z

calicoctl/commands/node/diags.go

+
+	// Get a list of Calico containers running on this Node.
+	var stderr bytes.Buffer
+	cmd := exec.Command("docker", "ps", "-a", "--filter", "\"name=calico\"", "--format", "{{.Names}}")


Does this --filter name=calico actually work when Calico is deployed as a DaemonSet? I would think the name would be something like k8s_calico-node-asdfasfdksdflahsdfhsdf

That can be a partial match and will return any containers with "calico" in them, so it will match, I tested this on a Vagrant install and got the expected output.

caseydavenport · 2017-09-08T07:23:44Z

calicoctl/commands/node/diags.go

+
+	fmt.Println("Copying logs from Calico containers")
+
+	// Grab the log for each container and write it as <containerName>.log.


One thing we had talked about was also saving off the output of docker ps so that users could correlate containerName.log with a specific container / timestamp / etc.

i.e. if I'm looking at the directory this code generates, how do I know which of the 100 containers I'm interested in?

I recall talking about it, but at the moment I'm having trouble seeing what this would buy the user, at the moment the only output of the docker command is a list of container names that have "calico" in them, which we use for grabbing the logs and using that name for the logfile. I could run a similar query with more flags that could include some extra info, like start/creation time and save that out?

The main thing we're looking for is the ability to correlate a log file with a specific iteration of a container.

So, being able to see the start/creation time is important. Alternatively we can just encode that into the file name somehow.

The names are already pretty long, I'll dump a file with the format:

{{.Names}}: {{.CreatedAt}}

Which will give us a mapping. Dunno what a good name for this would be

container_creation_time
container_to_creation_map
when_logged_containers_were_created

Something better than that maybe?

heschlie · 2017-09-12T23:03:23Z

@caseydavenport I think we might be all set? Let me know if the changes to grabbing the container->created time mapping looks ok.

caseydavenport · 2017-09-14T01:33:24Z

calicoctl/commands/node/diags.go

+		return
+	}
+
+	fmt.Println("Copying logs from Calico containers")


Some output I got from running on a k8s system:

$ docker ps -a --filter name=calico --format "{{.Names}}: {{.CreatedAt}}" k8s_install-cni_calico-node-6p0xp_kube-system_603c4dd8-98c8-11e7-acf3-42010a800008_0: 2017-09-13 21:13:44 +0000 UTC k8s_calico-node_calico-node-6p0xp_kube-system_603c4dd8-98c8-11e7-acf3-42010a800008_0: 2017-09-13 21:13:36 +0000 UTC k8s_calico-etcd_calico-etcd-t6dwl_kube-system_5fe749f4-98c8-11e7-acf3-42010a800008_0: 2017-09-13 21:13:26 +0000 UTC k8s_POD_calico-node-6p0xp_kube-system_603c4dd8-98c8-11e7-acf3-42010a800008_0: 2017-09-13 21:13:23 +0000 UTC k8s_POD_calico-etcd-t6dwl_kube-system_5fe749f4-98c8-11e7-acf3-42010a800008_0: 2017-09-13 21:13:23 +0000 UTC

We should filter out anything with k8s_POD_ in it since those are just the infra containers and won't have useful logs.

Ah, did not know that, will filter them out.

heschlie · 2017-09-14T18:23:22Z

When trying to trim out k8s_POD containers I found that the policy controller log was empty, turns out we are only logging to stderr in that container, so I migrated to exec.Command.CombinedOutput() which coincidentally helped me cleanup a few other parts of the code.

caseydavenport

@heschlie this LGTM - could you please squash before merging?

With this change `calicoctl node diags` will pickup logs from hosted installs. There is also a small change to add some clarity when a command fails, as before it was simply saying `exit status 1` will now tell you what command failed to run.

heschlie added area/calicoctl kind/enhancement labels Aug 16, 2017

heschlie added this to the Calico v2.6.0 milestone Aug 16, 2017

heschlie self-assigned this Aug 16, 2017

heschlie requested a review from gunjan5 August 16, 2017 16:57

bcreane reviewed Aug 16, 2017

View reviewed changes

gunjan5 suggested changes Aug 20, 2017

View reviewed changes

gunjan5 reviewed Aug 24, 2017

View reviewed changes

heschlie force-pushed the node-diags-improvement branch from 351fda9 to 46de5d2 Compare August 25, 2017 17:50

gunjan5 approved these changes Aug 25, 2017

View reviewed changes

gunjan5 requested a review from robbrockbank August 25, 2017 18:04

heschlie requested review from caseydavenport and removed request for robbrockbank August 30, 2017 23:42

heschlie added the release-note-required label Sep 1, 2017

caseydavenport requested changes Sep 8, 2017

View reviewed changes

caseydavenport reviewed Sep 14, 2017

View reviewed changes

caseydavenport approved these changes Sep 15, 2017

View reviewed changes

heschlie force-pushed the node-diags-improvement branch from 7bdadf9 to 8bd70e7 Compare September 15, 2017 22:56

heschlie merged commit e03438a into projectcalico:master Sep 16, 2017

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

calicoctl node diags grab logs from hosted installs #1702

calicoctl node diags grab logs from hosted installs #1702

heschlie commented Aug 16, 2017 •

edited by emanic

bcreane Aug 16, 2017

heschlie Aug 16, 2017

bcreane commented Aug 17, 2017

gunjan5 left a comment

gunjan5 Aug 20, 2017

heschlie Aug 23, 2017

gunjan5 Aug 23, 2017

gunjan5 Aug 20, 2017 •

edited

heschlie Aug 23, 2017

gunjan5 Aug 20, 2017

gunjan5 Aug 20, 2017

gunjan5 Aug 20, 2017

gunjan5 Aug 20, 2017

gunjan5 left a comment

gunjan5 Aug 24, 2017

heschlie Aug 24, 2017

gunjan5 commented Aug 24, 2017

gunjan5 left a comment

heschlie commented Aug 30, 2017

caseydavenport left a comment

caseydavenport Sep 8, 2017

heschlie Sep 8, 2017

caseydavenport Sep 8, 2017

caseydavenport Sep 8, 2017

heschlie Sep 8, 2017

caseydavenport Sep 8, 2017

heschlie Sep 8, 2017

caseydavenport Sep 12, 2017

heschlie Sep 12, 2017 •

edited

heschlie commented Sep 12, 2017

caseydavenport Sep 14, 2017

heschlie Sep 14, 2017

heschlie commented Sep 14, 2017

caseydavenport left a comment


		fmt.Println("Copying logs from Calico containers")

		// Grab the log for each container and write it as <containerName>.log.

calicoctl node diags grab logs from hosted installs #1702

calicoctl node diags grab logs from hosted installs #1702

Conversation

heschlie commented Aug 16, 2017 • edited by emanic

Description

Todos

Release Note

Choose a reason for hiding this comment

Choose a reason for hiding this comment

bcreane commented Aug 17, 2017

gunjan5 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

gunjan5 Aug 20, 2017 • 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

gunjan5 left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

gunjan5 commented Aug 24, 2017

gunjan5 left a comment

Choose a reason for hiding this comment

heschlie commented Aug 30, 2017

caseydavenport 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

Choose a reason for hiding this comment

Choose a reason for hiding this comment

heschlie Sep 12, 2017 • edited

Choose a reason for hiding this comment

heschlie commented Sep 12, 2017

Choose a reason for hiding this comment

Choose a reason for hiding this comment

heschlie commented Sep 14, 2017

caseydavenport left a comment

Choose a reason for hiding this comment

heschlie commented Aug 16, 2017 •

edited by emanic

gunjan5 Aug 20, 2017 •

edited

heschlie Sep 12, 2017 •

edited