From 3d94082b07ebb820eda9c4a29740d72ca50e6567 Mon Sep 17 00:00:00 2001 From: Alfonso Acosta Date: Fri, 5 Feb 2016 12:25:16 +0000 Subject: [PATCH] Add debug logging --- README.md | 6 +++++ app/api_topology.go | 2 +- app/controls.go | 6 ++--- app/pipes.go | 10 ++++---- app/server_helpers.go | 5 ++-- common/sanitize/sanitize.go | 5 ++-- docker/entrypoint.sh | 16 +++++++----- probe/appclient/app_client.go | 18 +++++++------- probe/appclient/multi_client.go | 7 +++--- probe/appclient/resolver.go | 5 ++-- probe/docker/container.go | 18 +++++++------- probe/docker/container_test.go | 2 +- probe/docker/controls.go | 26 +++++++++---------- probe/docker/registry.go | 16 ++++++------ probe/docker/reporter.go | 4 +-- probe/endpoint/conntrack.go | 37 ++++++++++++++-------------- probe/endpoint/procspy/proc_linux.go | 4 +-- probe/endpoint/procspy/spy_darwin.go | 2 +- probe/kubernetes/client.go | 4 +-- probe/overlay/weave.go | 6 ++--- probe/probe.go | 10 ++++---- prog/app.go | 20 +++++++-------- prog/main.go | 37 ++++++++++++++++++++++++++++ prog/probe.go | 37 ++++++++++++++-------------- 24 files changed, 176 insertions(+), 127 deletions(-) diff --git a/README.md b/README.md index 0472e9343f..adaf5b8fad 100644 --- a/README.md +++ b/README.md @@ -238,6 +238,12 @@ Then, run the local build via Scope has a collection of built in debugging tools to aid Scope delevopers. +- To get debug information in the logs launch Scope with `--debug`: +``` +scope launch --debug +docker logs weavescope +``` + - To have the Scope App or Scope Probe dump their goroutine stacks, run: ``` kill -QUIT $(pgrep -f scope-(app|probe)) diff --git a/app/api_topology.go b/app/api_topology.go index f0769976f6..65cc42c5fb 100644 --- a/app/api_topology.go +++ b/app/api_topology.go @@ -77,7 +77,7 @@ func handleWebsocket( ) { conn, err := upgrader.Upgrade(w, r, nil) if err != nil { - // log.Println("Upgrade:", err) + // log.Info("Upgrade:", err) return } defer conn.Close() diff --git a/app/controls.go b/app/controls.go index 354afd7030..0f5c38f6b1 100644 --- a/app/controls.go +++ b/app/controls.go @@ -1,12 +1,12 @@ package app import ( - "log" "math/rand" "net/http" "net/rpc" "sync" + log "github.com/Sirupsen/logrus" "github.com/gorilla/mux" "github.com/weaveworks/scope/common/xfer" @@ -73,7 +73,7 @@ func (cr *controlRouter) handleControl(w http.ResponseWriter, r *http.Request) { ) handler, ok := cr.get(probeID) if !ok { - log.Printf("Probe %s is not connected right now...", probeID) + log.Errorf("Probe %s is not connected right now...", probeID) http.NotFound(w, r) return } @@ -101,7 +101,7 @@ func (cr *controlRouter) handleProbeWS(w http.ResponseWriter, r *http.Request) { conn, err := upgrader.Upgrade(w, r, nil) if err != nil { - log.Printf("Error upgrading to websocket: %v", err) + log.Errorf("Error upgrading to websocket: %v", err) return } defer conn.Close() diff --git a/app/pipes.go b/app/pipes.go index f3dcadbd8c..bed35309b7 100644 --- a/app/pipes.go +++ b/app/pipes.go @@ -2,11 +2,11 @@ package app import ( "io" - "log" "net/http" "sync" "time" + log "github.com/Sirupsen/logrus" "github.com/gorilla/mux" "github.com/weaveworks/scope/common/mtime" @@ -99,7 +99,7 @@ func (pr *PipeRouter) timeout() { if (pipe.ui.refCount == 0 && now.Sub(pipe.ui.lastUsedTime) >= pipeTimeout) || (pipe.probe.refCount == 0 && now.Sub(pipe.probe.lastUsedTime) >= pipeTimeout) { - log.Printf("Timing out pipe %s", id) + log.Infof("Timing out pipe %s", id) pipe.Close() pipe.tombstoneTime = now } @@ -122,7 +122,7 @@ func (pr *PipeRouter) getOrCreate(id string) (*pipe, bool) { defer pr.Unlock() p, ok := pr.pipes[id] if !ok { - log.Printf("Creating pipe id %s", id) + log.Infof("Creating pipe id %s", id) p = &pipe{ ui: end{lastUsedTime: mtime.Now()}, probe: end{lastUsedTime: mtime.Now()}, @@ -178,7 +178,7 @@ func (pr *PipeRouter) handleWs(endSelector func(*pipe) (*end, io.ReadWriter)) fu conn, err := upgrader.Upgrade(w, r, nil) if err != nil { - log.Printf("Error upgrading to websocket: %v", err) + log.Errorf("Error upgrading to websocket: %v", err) return } defer conn.Close() @@ -191,7 +191,7 @@ func (pr *PipeRouter) delete(w http.ResponseWriter, r *http.Request) { pipeID := mux.Vars(r)["pipeID"] pipe, ok := pr.getOrCreate(pipeID) if ok && pr.retain(pipeID, pipe, &pipe.ui) { - log.Printf("Closing pipe %s", pipeID) + log.Infof("Closing pipe %s", pipeID) pipe.Close() pipe.tombstoneTime = mtime.Now() pr.release(pipeID, pipe, &pipe.ui) diff --git a/app/server_helpers.go b/app/server_helpers.go index 92b1221e77..815ceb4a50 100644 --- a/app/server_helpers.go +++ b/app/server_helpers.go @@ -2,8 +2,9 @@ package app import ( "encoding/json" - "log" "net/http" + + log "github.com/Sirupsen/logrus" ) func respondWith(w http.ResponseWriter, code int, response interface{}) { @@ -11,6 +12,6 @@ func respondWith(w http.ResponseWriter, code int, response interface{}) { w.Header().Add("Cache-Control", "no-cache") w.WriteHeader(code) if err := json.NewEncoder(w).Encode(response); err != nil { - log.Print(err) + log.Error(err) } } diff --git a/common/sanitize/sanitize.go b/common/sanitize/sanitize.go index 6f2c081e0b..0ba4eae074 100644 --- a/common/sanitize/sanitize.go +++ b/common/sanitize/sanitize.go @@ -2,10 +2,11 @@ package sanitize import ( "fmt" - "log" "net" "net/url" "strings" + + log "github.com/Sirupsen/logrus" ) // URL returns a function that sanitizes a URL string. It lets underspecified @@ -23,7 +24,7 @@ func URL(defaultScheme string, defaultPort int, defaultPath string) func(string) } u, err := url.Parse(s) if err != nil { - log.Printf("%q: %v", s, err) + log.Errorf("%q: %v", s, err) return s // oh well } if _, port, err := net.SplitHostPort(u.Host); err != nil && defaultPort > 0 { diff --git a/docker/entrypoint.sh b/docker/entrypoint.sh index a58e0f5bf8..b799958e18 100755 --- a/docker/entrypoint.sh +++ b/docker/entrypoint.sh @@ -88,6 +88,16 @@ while true; do fi APP_ARGS="$APP_ARGS -$ARG_NAME=$ARG_VALUE" ;; + --debug) + APP_ARGS="$APP_ARGS -log.level=debug" + PROBE_ARGS="$PROBE_ARGS -log.level=debug" + ;; + --no-app) + touch /etc/service/app/down + ;; + --no-probe) + touch /etc/service/probe/down + ;; --probe.*) if echo "$1" | grep "=" 1>/dev/null; then ARG_NAME=$(echo "$1" | sed 's/\-\-probe\.\([^=]*\)=\(.*\)/\1/') @@ -112,12 +122,6 @@ while true; do TOKEN_PROVIDED=true touch /etc/service/app/down ;; - --no-app) - touch /etc/service/app/down - ;; - --no-probe) - touch /etc/service/probe/down - ;; *) break ;; diff --git a/probe/appclient/app_client.go b/probe/appclient/app_client.go index 43cac073da..c20e3d80a4 100644 --- a/probe/appclient/app_client.go +++ b/probe/appclient/app_client.go @@ -4,12 +4,12 @@ import ( "encoding/json" "fmt" "io" - "log" "net/http" "net/rpc" "sync" "time" + log "github.com/Sirupsen/logrus" "github.com/gorilla/websocket" "github.com/weaveworks/scope/common/sanitize" @@ -170,7 +170,7 @@ func (c *appClient) doWithBackoff(msg string, f func() (bool, error)) { continue } - log.Printf("Error doing %s for %s, backing off %s: %v", msg, c.target, backoff, err) + log.Errorf("Error doing %s for %s, backing off %s: %v", msg, c.target, backoff, err) select { case <-time.After(backoff): case <-c.quit: @@ -192,7 +192,7 @@ func (c *appClient) controlConnection() (bool, error) { return false, err } defer func() { - log.Printf("Closing control connection to %s", c.target) + log.Infof("Closing control connection to %s", c.target) conn.Close() }() @@ -214,8 +214,8 @@ func (c *appClient) controlConnection() (bool, error) { func (c *appClient) ControlConnection() { go func() { - log.Printf("Control connection to %s starting", c.target) - defer log.Printf("Control connection to %s exiting", c.target) + log.Infof("Control connection to %s starting", c.target) + defer log.Infof("Control connection to %s exiting", c.target) c.doWithBackoff("controls", c.controlConnection) }() } @@ -242,8 +242,8 @@ func (c *appClient) publish(r io.Reader) error { func (c *appClient) startPublishing() { go func() { - log.Printf("Publish loop for %s starting", c.target) - defer log.Printf("Publish loop for %s exiting", c.target) + log.Infof("Publish loop for %s starting", c.target) + defer log.Infof("Publish loop for %s exiting", c.target) c.doWithBackoff("publish", func() (bool, error) { r := <-c.readers if r == nil { @@ -291,8 +291,8 @@ func (c *appClient) pipeConnection(id string, pipe xfer.Pipe) (bool, error) { func (c *appClient) PipeConnection(id string, pipe xfer.Pipe) { go func() { - log.Printf("Pipe %s connection to %s starting", id, c.target) - defer log.Printf("Pipe %s connection to %s exiting", id, c.target) + log.Infof("Pipe %s connection to %s starting", id, c.target) + defer log.Infof("Pipe %s connection to %s exiting", id, c.target) c.doWithBackoff(id, func() (bool, error) { return c.pipeConnection(id, pipe) }) diff --git a/probe/appclient/multi_client.go b/probe/appclient/multi_client.go index 7ee020bbac..3fc9fa6d6f 100644 --- a/probe/appclient/multi_client.go +++ b/probe/appclient/multi_client.go @@ -6,10 +6,11 @@ import ( "fmt" "io" "io/ioutil" - "log" "strings" "sync" + log "github.com/Sirupsen/logrus" + "github.com/weaveworks/scope/common/xfer" "github.com/weaveworks/scope/report" ) @@ -75,13 +76,13 @@ func (c *multiClient) Set(hostname string, endpoints []string) { client, err := c.clientFactory(hostname, endpoint) if err != nil { - log.Printf("Error creating new app client: %v", err) + log.Errorf("Error creating new app client: %v", err) return } details, err := client.Details() if err != nil { - log.Printf("Error fetching app details: %v", err) + log.Errorf("Error fetching app details: %v", err) } clients <- clientTuple{details, client} diff --git a/probe/appclient/resolver.go b/probe/appclient/resolver.go index f37909adae..6990e1f189 100644 --- a/probe/appclient/resolver.go +++ b/probe/appclient/resolver.go @@ -1,12 +1,13 @@ package appclient import ( - "log" "net" "strconv" "strings" "time" + log "github.com/Sirupsen/logrus" + "github.com/weaveworks/scope/common/xfer" ) @@ -74,7 +75,7 @@ func prepare(strs []string) []target { var err error host, port, err = net.SplitHostPort(s) if err != nil { - log.Printf("invalid address %s: %v", s, err) + log.Errorf("invalid address %s: %v", s, err) continue } } else { diff --git a/probe/docker/container.go b/probe/docker/container.go index 050fbb9a09..b5e89f8f8e 100644 --- a/probe/docker/container.go +++ b/probe/docker/container.go @@ -5,7 +5,6 @@ import ( "encoding/json" "fmt" "io" - "log" "net" "net/http" "net/http/httputil" @@ -15,6 +14,7 @@ import ( "sync" "time" + log "github.com/Sirupsen/logrus" docker "github.com/fsouza/go-dockerclient" "github.com/weaveworks/scope/common/mtime" @@ -162,30 +162,30 @@ func (c *container) StartGatheringStats() error { } go func() { - log.Printf("docker container: collecting stats for %s", c.container.ID) + log.Infof("docker container: collecting stats for %s", c.container.ID) req, err := http.NewRequest("GET", fmt.Sprintf("/containers/%s/stats", c.container.ID), nil) if err != nil { - log.Printf("docker container: %v", err) + log.Errorf("docker container: %v", err) return } req.Header.Set("User-Agent", "weavescope") url, err := url.Parse(endpoint) if err != nil { - log.Printf("docker container: %v", err) + log.Errorf("docker container: %v", err) return } dial, err := DialStub(url.Scheme, url.Path) if err != nil { - log.Printf("docker container: %v", err) + log.Errorf("docker container: %v", err) return } conn := NewClientConnStub(dial, nil) resp, err := conn.Do(req) if err != nil { - log.Printf("docker container: %v", err) + log.Errorf("docker container: %v", err) return } defer resp.Body.Close() @@ -198,7 +198,7 @@ func (c *container) StartGatheringStats() error { c.Lock() defer c.Unlock() - log.Printf("docker container: stopped collecting stats for %s", c.container.ID) + log.Infof("docker container: stopped collecting stats for %s", c.container.ID) c.statsConn = nil }() @@ -206,13 +206,13 @@ func (c *container) StartGatheringStats() error { decoder := json.NewDecoder(resp.Body) for err := decoder.Decode(&stats); err != io.EOF; err = decoder.Decode(&stats) { if err != nil { - log.Printf("docker container: error reading event, did container stop? %v", err) + log.Errorf("docker container: error reading event, did container stop? %v", err) return } c.Lock() if c.numPending >= len(c.pendingStats) { - log.Printf("docker container: dropping stats.") + log.Warnf("docker container: dropping stats.") } else { c.latestStats = stats c.pendingStats[c.numPending] = stats diff --git a/probe/docker/container_test.go b/probe/docker/container_test.go index d4e79d37f8..e2c52f64e4 100644 --- a/probe/docker/container_test.go +++ b/probe/docker/container_test.go @@ -5,12 +5,12 @@ import ( "encoding/json" "io" "io/ioutil" - "log" "net" "net/http" "testing" "time" + log "github.com/Sirupsen/logrus" client "github.com/fsouza/go-dockerclient" "github.com/weaveworks/scope/common/mtime" diff --git a/probe/docker/controls.go b/probe/docker/controls.go index c6e7149465..293bc36eed 100644 --- a/probe/docker/controls.go +++ b/probe/docker/controls.go @@ -1,10 +1,10 @@ package docker import ( - "log" - docker_client "github.com/fsouza/go-dockerclient" + log "github.com/Sirupsen/logrus" + "github.com/weaveworks/scope/common/xfer" "github.com/weaveworks/scope/probe/controls" "github.com/weaveworks/scope/report" @@ -24,27 +24,27 @@ const ( ) func (r *registry) stopContainer(containerID string, _ xfer.Request) xfer.Response { - log.Printf("Stopping container %s", containerID) + log.Infof("Stopping container %s", containerID) return xfer.ResponseError(r.client.StopContainer(containerID, waitTime)) } func (r *registry) startContainer(containerID string, _ xfer.Request) xfer.Response { - log.Printf("Starting container %s", containerID) + log.Infof("Starting container %s", containerID) return xfer.ResponseError(r.client.StartContainer(containerID, nil)) } func (r *registry) restartContainer(containerID string, _ xfer.Request) xfer.Response { - log.Printf("Restarting container %s", containerID) + log.Infof("Restarting container %s", containerID) return xfer.ResponseError(r.client.RestartContainer(containerID, waitTime)) } func (r *registry) pauseContainer(containerID string, _ xfer.Request) xfer.Response { - log.Printf("Pausing container %s", containerID) + log.Infof("Pausing container %s", containerID) return xfer.ResponseError(r.client.PauseContainer(containerID)) } func (r *registry) unpauseContainer(containerID string, _ xfer.Request) xfer.Response { - log.Printf("Unpausing container %s", containerID) + log.Infof("Unpausing container %s", containerID) return xfer.ResponseError(r.client.UnpauseContainer(containerID)) } @@ -76,14 +76,14 @@ func (r *registry) attachContainer(containerID string, req xfer.Request) xfer.Re } pipe.OnClose(func() { if err := cw.Close(); err != nil { - log.Printf("Error closing attachment: %v", err) + log.Errorf("Error closing attachment: %v", err) return } - log.Printf("Attachment to container %s closed.", containerID) + log.Infof("Attachment to container %s closed.", containerID) }) go func() { if err := cw.Wait(); err != nil { - log.Printf("Error waiting on exec: %v", err) + log.Errorf("Error waiting on exec: %v", err) } pipe.Close() }() @@ -123,14 +123,14 @@ func (r *registry) execContainer(containerID string, req xfer.Request) xfer.Resp } pipe.OnClose(func() { if err := cw.Close(); err != nil { - log.Printf("Error closing exec: %v", err) + log.Errorf("Error closing exec: %v", err) return } - log.Printf("Exec on container %s closed.", containerID) + log.Infof("Exec on container %s closed.", containerID) }) go func() { if err := cw.Wait(); err != nil { - log.Printf("Error waiting on exec: %v", err) + log.Errorf("Error waiting on exec: %v", err) } pipe.Close() }() diff --git a/probe/docker/registry.go b/probe/docker/registry.go index a605897934..c9e06c73bc 100644 --- a/probe/docker/registry.go +++ b/probe/docker/registry.go @@ -1,10 +1,10 @@ package docker import ( - "log" "sync" "time" + log "github.com/Sirupsen/logrus" docker_client "github.com/fsouza/go-dockerclient" "github.com/weaveworks/scope/probe/controls" @@ -139,22 +139,22 @@ func (r *registry) listenForEvents() bool { // after listing but before listening for events. events := make(chan *docker_client.APIEvents) if err := r.client.AddEventListener(events); err != nil { - log.Printf("docker registry: %s", err) + log.Errorf("docker registry: %s", err) return true } defer func() { if err := r.client.RemoveEventListener(events); err != nil { - log.Printf("docker registry: %s", err) + log.Errorf("docker registry: %s", err) } }() if err := r.updateContainers(); err != nil { - log.Printf("docker registry: %s", err) + log.Errorf("docker registry: %s", err) return true } if err := r.updateImages(); err != nil { - log.Printf("docker registry: %s", err) + log.Errorf("docker registry: %s", err) return true } @@ -166,7 +166,7 @@ func (r *registry) listenForEvents() bool { case <-otherUpdates: if err := r.updateImages(); err != nil { - log.Printf("docker registry: %s", err) + log.Errorf("docker registry: %s", err) return true } @@ -241,7 +241,7 @@ func (r *registry) updateContainerState(containerID string) { if err != nil { // Don't spam the logs if the container was short lived if _, ok := err.(*docker_client.NoSuchContainer); !ok { - log.Printf("Error processing event for container %s: %v", containerID, err) + log.Errorf("Error processing event for container %s: %v", containerID, err) return } @@ -281,7 +281,7 @@ func (r *registry) updateContainerState(containerID string) { // And finally, ensure we gather stats for it if dockerContainer.State.Running { if err := c.StartGatheringStats(); err != nil { - log.Printf("Error gather stats for container: %s", containerID) + log.Errorf("Error gather stats for container: %s", containerID) return } } else { diff --git a/probe/docker/reporter.go b/probe/docker/reporter.go index b19111f9c3..6cab0728df 100644 --- a/probe/docker/reporter.go +++ b/probe/docker/reporter.go @@ -1,9 +1,9 @@ package docker import ( - "log" "net" + log "github.com/Sirupsen/logrus" docker_client "github.com/fsouza/go-dockerclient" "github.com/weaveworks/scope/probe" @@ -41,7 +41,7 @@ func (Reporter) Name() string { return "Docker" } func (r *Reporter) ContainerUpdated(c Container) { localAddrs, err := report.LocalAddresses() if err != nil { - log.Printf("Error getting local address: %v", err) + log.Errorf("Error getting local address: %v", err) return } diff --git a/probe/endpoint/conntrack.go b/probe/endpoint/conntrack.go index cb0eb5f946..2b2f51051d 100644 --- a/probe/endpoint/conntrack.go +++ b/probe/endpoint/conntrack.go @@ -4,12 +4,13 @@ import ( "bufio" "encoding/xml" "io" - "log" "os" "strings" "sync" "time" + log "github.com/Sirupsen/logrus" + "github.com/weaveworks/scope/common/exec" ) @@ -86,7 +87,7 @@ type conntrackWalker struct { // newConntracker creates and starts a new conntracker. func newConntrackFlowWalker(useConntrack bool, args ...string) flowWalker { if !ConntrackModulePresent() { - log.Printf("Not using conntrack: module not present") + log.Info("Not using conntrack: module not present") return nilFlowWalker{} } else if !useConntrack { return nilFlowWalker{} @@ -117,10 +118,10 @@ var ConntrackModulePresent = func() bool { } } if err := scanner.Err(); err != nil { - log.Printf("conntrack error: %v", err) + log.Errorf("conntrack error: %v", err) } - log.Printf("conntrack: failed to find module %s", conntrackModule) + log.Errorf("conntrack: failed to find module %s", conntrackModule) return false } @@ -156,10 +157,10 @@ func (c *conntrackWalker) clearFlows() { func logPipe(prefix string, reader io.Reader) { scanner := bufio.NewScanner(reader) for scanner.Scan() { - log.Println(prefix, scanner.Text()) + log.Error(prefix, scanner.Text()) } if err := scanner.Err(); err != nil { - log.Println(prefix, err) + log.Error(prefix, err) } } @@ -168,7 +169,7 @@ func (c *conntrackWalker) run() { // for which we don't get events existingFlows, err := c.existingConnections() if err != nil { - log.Printf("conntrack existingConnections error: %v", err) + log.Errorf("conntrack existingConnections error: %v", err) return } for _, flow := range existingFlows { @@ -179,25 +180,25 @@ func (c *conntrackWalker) run() { cmd := exec.Command("conntrack", args...) stdout, err := cmd.StdoutPipe() if err != nil { - log.Printf("conntrack error: %v", err) + log.Errorf("conntrack error: %v", err) return } stderr, err := cmd.StderrPipe() if err != nil { - log.Printf("conntrack error: %v", err) + log.Errorf("conntrack error: %v", err) return } go logPipe("conntrack stderr:", stderr) if err := cmd.Start(); err != nil { - log.Printf("conntrack error: %v", err) + log.Errorf("conntrack error: %v", err) return } defer func() { if err := cmd.Wait(); err != nil { - log.Printf("conntrack error: %v", err) + log.Errorf("conntrack error: %v", err) } }() @@ -216,28 +217,28 @@ func (c *conntrackWalker) run() { // Swallow the first two lines reader := bufio.NewReader(stdout) if line, err := reader.ReadString('\n'); err != nil { - log.Printf("conntrack error: %v", err) + log.Errorf("conntrack error: %v", err) return } else if line != xmlHeader { - log.Printf("conntrack invalid output: '%s'", line) + log.Errorf("conntrack invalid output: '%s'", line) return } if line, err := reader.ReadString('\n'); err != nil { - log.Printf("conntrack error: %v", err) + log.Errorf("conntrack error: %v", err) return } else if line != conntrackOpenTag { - log.Printf("conntrack invalid output: '%s'", line) + log.Errorf("conntrack invalid output: '%s'", line) return } - defer log.Printf("contrack exiting") + defer log.Infof("contrack exiting") // Now loop on the output stream decoder := xml.NewDecoder(reader) for { var f flow if err := decoder.Decode(&f); err != nil { - log.Printf("conntrack error: %v", err) + log.Errorf("conntrack error: %v", err) return } c.handleFlow(f, false) @@ -256,7 +257,7 @@ func (c *conntrackWalker) existingConnections() ([]flow, error) { } defer func() { if err := cmd.Wait(); err != nil { - log.Printf("conntrack existingConnections exit error: %v", err) + log.Errorf("conntrack existingConnections exit error: %v", err) } }() var result conntrack diff --git a/probe/endpoint/procspy/proc_linux.go b/probe/endpoint/procspy/proc_linux.go index d74975080c..87ac4bd43e 100644 --- a/probe/endpoint/procspy/proc_linux.go +++ b/probe/endpoint/procspy/proc_linux.go @@ -4,11 +4,11 @@ package procspy import ( "bytes" - "log" "path/filepath" "strconv" "syscall" + log "github.com/Sirupsen/logrus" "github.com/armon/go-metrics" "github.com/hashicorp/go-version" @@ -54,7 +54,7 @@ func getNetNamespacePathSuffix() string { v, err := getKernelVersion() if err != nil { - log.Printf("error: getNeNameSpacePath: cannot get kernel version: %s\n", err) + log.Errorf("getNeNameSpacePath: cannot get kernel version: %s\n", err) netNamespacePathSuffix = post38Path return netNamespacePathSuffix } diff --git a/probe/endpoint/procspy/spy_darwin.go b/probe/endpoint/procspy/spy_darwin.go index 9883301855..56edb52a7d 100644 --- a/probe/endpoint/procspy/spy_darwin.go +++ b/probe/endpoint/procspy/spy_darwin.go @@ -25,7 +25,7 @@ var cbConnections = func(processes bool, walker process.Walker) (ConnIter, error "-p", "tcp", // only TCP ).CombinedOutput() if err != nil { - // log.Printf("lsof error: %s", err) + // Log.Infof("lsof error: %s", err) return nil, err } connections := parseDarwinNetstat(string(out)) diff --git a/probe/kubernetes/client.go b/probe/kubernetes/client.go index a6b605a0cf..4f527c3150 100644 --- a/probe/kubernetes/client.go +++ b/probe/kubernetes/client.go @@ -1,9 +1,9 @@ package kubernetes import ( - "log" "time" + log "github.com/Sirupsen/logrus" "k8s.io/kubernetes/pkg/api" "k8s.io/kubernetes/pkg/client/cache" "k8s.io/kubernetes/pkg/client/unversioned" @@ -38,7 +38,7 @@ type client struct { func runReflectorUntil(r *cache.Reflector, resyncPeriod time.Duration, stopCh <-chan struct{}) { loggingListAndWatch := func() { if err := r.ListAndWatch(stopCh); err != nil { - log.Printf("Kubernetes reflector error: %v", err) + log.Errorf("Kubernetes reflector: %v", err) } } go util.Until(loggingListAndWatch, resyncPeriod, stopCh) diff --git a/probe/overlay/weave.go b/probe/overlay/weave.go index bbcc8845fb..c53949406f 100644 --- a/probe/overlay/weave.go +++ b/probe/overlay/weave.go @@ -4,13 +4,13 @@ import ( "bufio" "encoding/json" "fmt" - "log" "net/http" "regexp" "strings" "sync" "time" + log "github.com/Sirupsen/logrus" "github.com/weaveworks/scope/common/exec" "github.com/weaveworks/scope/common/sanitize" "github.com/weaveworks/scope/probe/docker" @@ -99,7 +99,7 @@ func (w *Weave) loop() { for { psEntries, err := w.getPSEntries() if err != nil { - log.Printf("Error running weave ps: %v", err) + log.Errorf("Error running weave ps: %v", err) break } @@ -166,7 +166,7 @@ func (w *Weave) getPSEntries() ([]psEntry, error) { } defer func() { if err := cmd.Wait(); err != nil { - log.Printf("Weave tagger, cmd failed: %v", err) + log.Errorf("Weave tagger, cmd failed: %v", err) } }() scanner := bufio.NewScanner(out) diff --git a/probe/probe.go b/probe/probe.go index bf244a7b0a..716876004c 100644 --- a/probe/probe.go +++ b/probe/probe.go @@ -1,10 +1,10 @@ package probe import ( - "log" "sync" "time" + log "github.com/Sirupsen/logrus" "github.com/armon/go-metrics" "github.com/weaveworks/scope/probe/appclient" @@ -123,7 +123,7 @@ func (p *Probe) tick() { err := ticker.Tick() metrics.MeasureSince([]string{ticker.Name(), "ticker"}, t) if err != nil { - log.Printf("error doing ticker: %v", err) + log.Errorf("error doing ticker: %v", err) } } } @@ -136,7 +136,7 @@ func (p *Probe) report() report.Report { newReport, err := rep.Report() metrics.MeasureSince([]string{rep.Name(), "reporter"}, t) if err != nil { - log.Printf("error generating report: %v", err) + log.Errorf("error generating report: %v", err) newReport = report.MakeReport() // empty is OK to merge } reports <- newReport @@ -157,7 +157,7 @@ func (p *Probe) tag(r report.Report) report.Report { r, err = tagger.Tag(r) metrics.MeasureSince([]string{tagger.Name(), "tagger"}, t) if err != nil { - log.Printf("error applying tagger: %v", err) + log.Errorf("error applying tagger: %v", err) } } return r @@ -175,7 +175,7 @@ ForLoop: } if err := p.publisher.Publish(rpt); err != nil { - log.Printf("publish: %v", err) + log.Infof("publish: %v", err) } } diff --git a/prog/app.go b/prog/app.go index 55f504de8a..e7aa737e61 100644 --- a/prog/app.go +++ b/prog/app.go @@ -2,14 +2,13 @@ package main import ( "flag" - "log" "math/rand" "net/http" _ "net/http/pprof" "strconv" - "strings" "time" + log "github.com/Sirupsen/logrus" "github.com/gorilla/mux" "github.com/weaveworks/go-checkpoint" "github.com/weaveworks/weave/common" @@ -32,16 +31,15 @@ func appMain() { var ( window = flag.Duration("window", 15*time.Second, "window") listen = flag.String("http.address", ":"+strconv.Itoa(xfer.AppPort), "webserver listen address") + logLevel = flag.String("log.level", "info", "logging threshold level: debug|info|warn|error|fatal|panic") logPrefix = flag.String("log.prefix", "", "prefix for each log line") ) flag.Parse() - if !strings.HasSuffix(*logPrefix, " ") { - *logPrefix += " " - } - log.SetPrefix(*logPrefix) + setLogLevel(*logLevel) + setLogFormatter(*logPrefix) - defer log.Print("app exiting") + defer log.Info("app exiting") // Start background version checking checkpoint.CheckInterval(&checkpoint.CheckParams{ @@ -50,7 +48,7 @@ func appMain() { SignatureFile: signatureFile, }, versionCheckPeriod, func(r *checkpoint.CheckResponse, err error) { if r.Outdated { - log.Printf("Scope version %s is available; please update at %s", + log.Infof("Scope version %s is available; please update at %s", r.CurrentVersion, r.CurrentDownloadURL) } }) @@ -58,11 +56,11 @@ func appMain() { rand.Seed(time.Now().UnixNano()) app.UniqueID = strconv.FormatInt(rand.Int63(), 16) app.Version = version - log.Printf("app starting, version %s, ID %s", app.Version, app.UniqueID) + log.Infof("app starting, version %s, ID %s", app.Version, app.UniqueID) handler := router(app.NewCollector(*window)) go func() { - log.Printf("listening on %s", *listen) - log.Print(http.ListenAndServe(*listen, handler)) + log.Infof("listening on %s", *listen) + log.Info(http.ListenAndServe(*listen, handler)) }() common.SignalHandlerLoop() diff --git a/prog/main.go b/prog/main.go index cc66dd26ae..36e48467c7 100644 --- a/prog/main.go +++ b/prog/main.go @@ -3,10 +3,47 @@ package main import ( "fmt" "os" + "strings" + + log "github.com/Sirupsen/logrus" + weavecommon "github.com/weaveworks/weave/common" ) var version = "dev" // set at build time +type prefixFormatter struct { + prefix []byte + next log.Formatter +} + +func (f *prefixFormatter) Format(entry *log.Entry) ([]byte, error) { + formatted, err := f.next.Format(entry) + if err != nil { + return formatted, err + } + return append(f.prefix, formatted...), nil +} + +func setLogFormatter(prefix string) { + if !strings.HasSuffix(prefix, " ") { + prefix += " " + } + f := prefixFormatter{ + prefix: []byte(prefix), + // reuse weave's log format + next: weavecommon.Log.Formatter, + } + log.SetFormatter(&f) +} + +func setLogLevel(levelname string) { + level, err := log.ParseLevel(levelname) + if err != nil { + log.Fatal(err) + } + log.SetLevel(level) +} + func usage() { fmt.Fprintf(os.Stderr, "usage: %s (app|probe|version) args...\n", os.Args[0]) os.Exit(1) diff --git a/prog/probe.go b/prog/probe.go index 0a3fe757fb..51081a6aab 100644 --- a/prog/probe.go +++ b/prog/probe.go @@ -3,7 +3,6 @@ package main import ( "flag" "fmt" - "log" "math/rand" "net" "net/http" @@ -13,6 +12,7 @@ import ( "strings" "time" + log "github.com/Sirupsen/logrus" "github.com/armon/go-metrics" "github.com/weaveworks/go-checkpoint" "github.com/weaveworks/weave/common" @@ -39,9 +39,9 @@ const ( func check() { handleResponse := func(r *checkpoint.CheckResponse, err error) { if err != nil { - log.Printf("Error checking version: %v", err) + log.Errorf("Error checking version: %v", err) } else if r.Outdated { - log.Printf("Scope version %s is available; please update at %s", + log.Infof("Scope version %s is available; please update at %s", r.CurrentVersion, r.CurrentDownloadURL) } } @@ -77,24 +77,23 @@ func probeMain() { useConntrack = flag.Bool("conntrack", true, "also use conntrack to track connections") insecure = flag.Bool("insecure", false, "(SSL) explicitly allow \"insecure\" SSL connections and transfers") logPrefix = flag.String("log.prefix", "", "prefix for each log line") + logLevel = flag.String("log.level", "info", "logging threshold level: debug|info|warn|error|fatal|panic") ) flag.Parse() + setLogLevel(*logLevel) + setLogFormatter(*logPrefix) + // Setup in memory metrics sink inm := metrics.NewInmemSink(time.Minute, 2*time.Minute) sig := metrics.DefaultInmemSignal(inm) defer sig.Stop() metrics.NewGlobal(metrics.DefaultConfig("scope-probe"), inm) - if !strings.HasSuffix(*logPrefix, " ") { - *logPrefix += " " - } - log.SetPrefix(*logPrefix) - - defer log.Print("probe exiting") + defer log.Info("probe exiting") if *spyProcs && os.Getegid() != 0 { - log.Printf("warning: -process=true, but that requires root to find everything") + log.Warn("-process=true, but that requires root to find everything") } rand.Seed(time.Now().UnixNano()) @@ -103,7 +102,7 @@ func probeMain() { hostName = hostname.Get() hostID = hostName // TODO(pb): we should sanitize the hostname ) - log.Printf("probe starting, version %s, ID %s", version, probeID) + log.Infof("probe starting, version %s, ID %s", version, probeID) go check() addrs, err := net.InterfaceAddrs() @@ -121,7 +120,7 @@ func probeMain() { if len(flag.Args()) > 0 { targets = flag.Args() } - log.Printf("publishing to: %s", strings.Join(targets, ", ")) + log.Infof("publishing to: %s", strings.Join(targets, ", ")) probeConfig := appclient.ProbeConfig{ Token: *token, @@ -155,14 +154,14 @@ func probeMain() { if *dockerEnabled { if err := report.AddLocalBridge(*dockerBridge); err != nil { - log.Printf("Docker: problem with bridge %s: %v", *dockerBridge, err) + log.Errorf("Docker: problem with bridge %s: %v", *dockerBridge, err) } if registry, err := docker.NewRegistry(*dockerInterval, clients); err == nil { defer registry.Stop() p.AddTagger(docker.NewTagger(registry, processCache)) p.AddReporter(docker.NewReporter(registry, hostID, p)) } else { - log.Printf("Docker: failed to start registry: %v", err) + log.Errorf("Docker: failed to start registry: %v", err) } } @@ -171,8 +170,8 @@ func probeMain() { defer client.Stop() p.AddReporter(kubernetes.NewReporter(client)) } else { - log.Printf("Kubernetes: failed to start client: %v", err) - log.Printf("Kubernetes: make sure to run Scope inside a POD with a service account or provide a valid kubernetes.api url") + log.Errorf("Kubernetes: failed to start client: %v", err) + log.Errorf("Kubernetes: make sure to run Scope inside a POD with a service account or provide a valid kubernetes.api url") } } @@ -186,9 +185,9 @@ func probeMain() { if *httpListen != "" { go func() { - log.Printf("Profiling data being exported to %s", *httpListen) - log.Printf("go tool pprof http://%s/debug/pprof/{profile,heap,block}", *httpListen) - log.Printf("Profiling endpoint %s terminated: %v", *httpListen, http.ListenAndServe(*httpListen, nil)) + log.Infof("Profiling data being exported to %s", *httpListen) + log.Infof("go tool pprof http://%s/debug/pprof/{profile,heap,block}", *httpListen) + log.Infof("Profiling endpoint %s terminated: %v", *httpListen, http.ListenAndServe(*httpListen, nil)) }() }