Merge lp:~axwalk/juju-core/lp1166863-debug-logs-all into lp:~go-bot/juju-core/trunk

[Andrew Wilkins]

debug-log: add flag to get last N log lines

Same format as expected by "tail".

Fixes bug 1166863

https://codereview.appspot.com/12241043/

debug-log: add flag to get last N log lines

Same format as expected by "tail".

Fixes bug 1166863

https://codereview.appspot.com/12241043/

[Andrew Wilkins (axwalk)]

Reviewers: mp+178028_code.launchpad.net,

Message:
Please take a look.

Description:
debug-log: add -a/--all to get entire log contents

Fixes bug 1166863

https://code.launchpad.net/~axwalk/juju-core/lp1166863-debug-logs-all/+merge/178028

(do not edit description out of merge proposal)

Please review this at https://codereview.appspot.com/12241043/

Affected files:
   A [revision details]
   M cmd/juju/debuglog.go
   M cmd/juju/debuglog_test.go

Index: [revision details]
=== added file '[revision details]'
--- [revision details] 2012-01-01 00:00:00 +0000
+++ [revision details] 2012-01-01 00:00:00 +0000
@@ -0,0 +1,2 @@
+Old revision: tarmac-20130801070802-cgvry3o76nnocyq9
+New revision: <email address hidden>

Index: cmd/juju/debuglog.go
=== modified file 'cmd/juju/debuglog.go'
--- cmd/juju/debuglog.go 2013-05-02 15:55:42 +0000
+++ cmd/juju/debuglog.go 2013-08-01 09:25:00 +0000
@@ -10,7 +10,8 @@

  type DebugLogCommand struct {
   // The debug log command simply invokes juju ssh with the required
arguments.
- sshCmd cmd.Command
+ sshCmd cmd.Command
+ showAll bool
  }

  const debuglogDoc = `
@@ -29,11 +30,19 @@

  func (c *DebugLogCommand) SetFlags(f *gnuflag.FlagSet) {
   c.sshCmd.SetFlags(f)
+ f.BoolVar(&c.showAll, "a", false, "show the complete log file contents")
+ f.BoolVar(&c.showAll, "all", false, "")
  }

  func (c *DebugLogCommand) Init(args []string) error {
- args = append([]string{"0"}, args...)
- args = append(args, "tail -f /var/log/juju/all-machines.log")
+ args = append([]string{"0"}, args...) // machine 0
+ tailcmd := "tail "
+ if c.showAll {
+ // tail starting from line 1
+ tailcmd += "-n +1 "
+ }
+ tailcmd += "-f /var/log/juju/all-machines.log"
+ args = append(args, tailcmd)
   return c.sshCmd.Init(args)
  }

Index: cmd/juju/debuglog_test.go
=== modified file 'cmd/juju/debuglog_test.go'
--- cmd/juju/debuglog_test.go 2013-05-10 20:55:57 +0000
+++ cmd/juju/debuglog_test.go 2013-08-01 09:25:00 +0000
@@ -42,4 +42,11 @@
   c.Assert(debugCmd.runCalled, Equals, true)
   c.Assert(debugCmd.Target, Equals, "0")
   c.Assert([]string{"tail -f /var/log/juju/all-machines.log"}, DeepEquals,
debugCmd.Args)
+
+ debugLogCmd, err = runDebugLog(c, "--all")
+ c.Assert(err, IsNil)
+ debugCmd = debugLogCmd.sshCmd.(*dummySSHCommand)
+ c.Assert(debugCmd.runCalled, Equals, true)
+ c.Assert(debugCmd.Target, Equals, "0")
+ c.Assert([]string{"tail -n +1 -f /var/log/juju/all-machines.log"},
DeepEquals, debugCmd.Args)
  }

[Ian Booth (wallyworld)]

LGTM with the suggested test change

https://codereview.appspot.com/12241043/diff/1/cmd/juju/debuglog_test.go
File cmd/juju/debuglog_test.go (right):

https://codereview.appspot.com/12241043/diff/1/cmd/juju/debuglog_test.go#newcode52
cmd/juju/debuglog_test.go:52: }
Please split this out to a separate test. A common pattern used is along
the lines of:

func (s *DebugLogSuite) assertDebugLogInvokesSSHCommand(arg, expected
string) {
  defer testing.MakeEmptyFakeHome(c).Restore()
  debugLogCmd, err := runDebugLog(c, arg)
  c.Assert(err, IsNil)
  // etc etc
}

func (s *DebugLogSuite) TestDebugLog(c *C) {
    s.assertDebugLogInvokesSSHCommand("", "........")
}

func (s *DebugLogSuite) TestDebugLogAll(c *C) {
    s.assertDebugLogInvokesSSHCommand("--all", "........")
}

https://codereview.appspot.com/12241043/

[Andrew Wilkins (axwalk)]

https://codereview.appspot.com/12241043/diff/1/cmd/juju/debuglog_test.go
File cmd/juju/debuglog_test.go (right):

https://codereview.appspot.com/12241043/diff/1/cmd/juju/debuglog_test.go#newcode52
cmd/juju/debuglog_test.go:52: }
On 2013/08/01 23:11:28, wallyworld wrote:
> Please split this out to a separate test. A common pattern used is
along the
> lines of:

> func (s *DebugLogSuite) assertDebugLogInvokesSSHCommand(arg, expected
string) {
> defer testing.MakeEmptyFakeHome(c).Restore()
> debugLogCmd, err := runDebugLog(c, arg)
> c.Assert(err, IsNil)
> // etc etc
> }

> func (s *DebugLogSuite) TestDebugLog(c *C) {
> s.assertDebugLogInvokesSSHCommand("", "........")
> }

> func (s *DebugLogSuite) TestDebugLogAll(c *C) {
> s.assertDebugLogInvokesSSHCommand("--all", "........")
> }

Done.

https://codereview.appspot.com/12241043/

[Andrew Wilkins (axwalk)]

Please take a look.

https://codereview.appspot.com/12241043/

[William Reade (fwereade)]

Implementation looks good, but I have some concerns. Thoughts?

https://codereview.appspot.com/12241043/diff/7001/cmd/juju/debuglog.go
File cmd/juju/debuglog.go (right):

https://codereview.appspot.com/12241043/diff/7001/cmd/juju/debuglog.go#newcode34
cmd/juju/debuglog.go:34: f.BoolVar(&c.showAll, "all", false, "")
Hmm, I'm a little bit uncertain about this behaviour -- the whole debug
log for a large and/or long-lived environment is *not* a dainty thing,
and I'm not sure it's very helpful to expose it here -- if you want
events as they happen you want debug-log, and if you want a complete
record you can just `juju scp`.

What may be useful, I think, is the ability to specify a certain number
of lines of context. Roger, what are your thoughts here? It's your bug,
and maybe I misunderstand your use case, but I'm reluctant to add this
to the interface without a bit more thought.

https://codereview.appspot.com/12241043/diff/7001/cmd/juju/debuglog.go#newcode38
cmd/juju/debuglog.go:38: args = append([]string{"0"}, args...) //
machine 0
Preexisting behaviour, so not a blocker for this CL, but I'm a bit
twitchy about passing arbitrary command line args through to the SSH
command. Is this something we just have to do across the board? Is there
any way we could kill this with fire, like by offering an
ssh-config-path in the config settings and using that where possible?

https://codereview.appspot.com/12241043/

[Andrew Wilkins (axwalk)]

On 2013/08/02 16:54:39, fwereade wrote:
> Implementation looks good, but I have some concerns. Thoughts?

> https://codereview.appspot.com/12241043/diff/7001/cmd/juju/debuglog.go
> File cmd/juju/debuglog.go (right):

https://codereview.appspot.com/12241043/diff/7001/cmd/juju/debuglog.go#newcode34
> cmd/juju/debuglog.go:34: f.BoolVar(&c.showAll, "all", false, "")
> Hmm, I'm a little bit uncertain about this behaviour -- the whole
debug log for
> a large and/or long-lived environment is *not* a dainty thing, and I'm
not sure
> it's very helpful to expose it here -- if you want events as they
happen you
> want debug-log, and if you want a complete record you can just `juju
scp`.

The only difference being that you don't get to follow updates after
that.
The bug report mentions the GUI requiring this, but I don't know what
the
requirements are specifically, so will have to leave it to rogpeppe to
speak up.

> What may be useful, I think, is the ability to specify a certain
number of lines
> of context. Roger, what are your thoughts here? It's your bug, and
maybe I
> misunderstand your use case, but I'm reluctant to add this to the
interface
> without a bit more thought.

https://codereview.appspot.com/12241043/diff/7001/cmd/juju/debuglog.go#newcode38
> cmd/juju/debuglog.go:38: args = append([]string{"0"}, args...) //
machine 0
> Preexisting behaviour, so not a blocker for this CL, but I'm a bit
twitchy about
> passing arbitrary command line args through to the SSH command. Is
this
> something we just have to do across the board? Is there any way we
could kill
> this with fire, like by offering an ssh-config-path in the config
settings and
> using that where possible?

I also this is a bit ugly, as it's exposing the implementation detail of
using SSH.
I'm not sure what you mean by "offering an ssh-config path in the config
settings",
though. Can you please elaborate?

https://codereview.appspot.com/12241043/

[John A Meinel (jameinel)]

I do think that bug #1166863 is more about having the ability to get the
recent items, rather than the ability to get the entire log file.

Currently we don't rotate the log file, which means the log file gets
*BIG*.

I'm not terribly opposed to having a '-a', but I think a '--recent'
would be more generally useful (tell me what just happened on my
environment). And '--recent 1000' or something like that.

For bonus points, we can just implement '--recent' and pass it through
to 'tail -n' so that we have "--recent +1" as a subtle way of actually
requesting All.

Thoughts?

https://codereview.appspot.com/12241043/

[Andrew Wilkins (axwalk)]

On 2013/08/08 17:11:26, jameinel wrote:
> I do think that bug #1166863 is more about having the ability to get
the recent
> items, rather than the ability to get the entire log file.

> Currently we don't rotate the log file, which means the log file gets
*BIG*.

> I'm not terribly opposed to having a '-a', but I think a '--recent'
would be
> more generally useful (tell me what just happened on my environment).
And
> '--recent 1000' or something like that.

> For bonus points, we can just implement '--recent' and pass it through
to 'tail
> -n' so that we have "--recent +1" as a subtle way of actually
requesting All.

> Thoughts?

SGTM. Mind if we just call it -n/--lines though (same as tail)?

https://codereview.appspot.com/12241043/

[William Reade (fwereade)]

On 2013/08/09 01:44:04, axw1 wrote:
> On 2013/08/08 17:11:26, jameinel wrote:
> > For bonus points, we can just implement '--recent' and pass it
through to
> 'tail
> > -n' so that we have "--recent +1" as a subtle way of actually
requesting All.
> >
> > Thoughts?

> SGTM. Mind if we just call it -n/--lines though (same as tail)?

-n/--lines SGTM. I'm not really that keen on supporting + but I can't
actually see any serious negative consequences so... go for it, I guess.
But please validate what we pass through, don't just leave it to tail
:).

https://codereview.appspot.com/12241043/

[Andrew Wilkins (axwalk)]

Please take a look.

https://codereview.appspot.com/12241043/

[William Reade (fwereade)]

LGTM, thanks

https://codereview.appspot.com/12241043/diff/16001/cmd/juju/debuglog.go
File cmd/juju/debuglog.go (right):

https://codereview.appspot.com/12241043/diff/16001/cmd/juju/debuglog.go#newcode84
cmd/juju/debuglog.go:84: "0", // machine 0
Heh, this is bad, but preexisting... so let's leave it as it is for now
:(.

https://codereview.appspot.com/12241043/

=== modified file 'cmd/juju/debuglog.go'
--- cmd/juju/debuglog.go	2013-05-02 15:55:42 +0000
+++ cmd/juju/debuglog.go	2013-08-13 09:25:16 +0000
@@ -4,13 +4,55 @@
 package main
 
 import (
+	"fmt"
+	"strconv"
+
 	"launchpad.net/gnuflag"
+
 	"launchpad.net/juju-core/cmd"
 )
 
 type DebugLogCommand struct {
 	// The debug log command simply invokes juju ssh with the required arguments.
 	sshCmd cmd.Command
+	lines  linesValue
+}
+
+// defaultLineCount is the default number of lines to
+// display, from the end of the consolidated log.
+const defaultLineCount = 10
+
+// linesValue implements gnuflag.Value, and represents
+// a -n/--lines flag value compatible with "tail".
+//
+// A negative value (-K) corresponds to --lines=K,
+// i.e. the last K lines; a positive value (+K)
+// corresponds to --lines=+K, i.e. from line K onwards.
+type linesValue int
+
+func (v *linesValue) String() string {
+	if *v > 0 {
+		return fmt.Sprintf("+%d", *v)
+	}
+	return fmt.Sprint(-*v)
+}
+
+func (v *linesValue) Set(value string) error {
+	if len(value) > 0 {
+		sign := -1
+		if value[0] == '+' {
+			value = value[1:]
+			sign = 1
+		}
+		n, err := strconv.ParseInt(value, 10, 0)
+		if err == nil && n > 0 {
+			*v = linesValue(sign * int(n))
+			return nil
+		}
+		// err is quite verbose, and doesn't convey
+		// any additional useful information.
+	}
+	return fmt.Errorf("invalid number of lines")
 }
 
 const debuglogDoc = `
@@ -21,7 +63,6 @@
 func (c *DebugLogCommand) Info() *cmd.Info {
 	return &cmd.Info{
 		Name:    "debug-log",
-		Args:    "[<ssh args>...]",
 		Purpose: "display the consolidated log file",
 		Doc:     debuglogDoc,
 	}
@@ -29,11 +70,16 @@
 
 func (c *DebugLogCommand) SetFlags(f *gnuflag.FlagSet) {
 	c.sshCmd.SetFlags(f)
+
+	c.lines = -defaultLineCount
+	f.Var(&c.lines, "n", "output the last K lines; or use -n +K to output lines starting with the Kth")
+	f.Var(&c.lines, "lines", "")
 }
 
 func (c *DebugLogCommand) Init(args []string) error {
+	tailcmd := fmt.Sprintf("tail -n %s -f /var/log/juju/all-machines.log", &c.lines)
 	args = append([]string{"0"}, args...)
-	args = append(args, "tail -f /var/log/juju/all-machines.log")
+	args = append(args, tailcmd)
 	return c.sshCmd.Init(args)
 }
 

=== modified file 'cmd/juju/debuglog_test.go'
--- cmd/juju/debuglog_test.go	2013-05-10 20:55:57 +0000
+++ cmd/juju/debuglog_test.go	2013-08-13 09:25:16 +0000
@@ -4,7 +4,8 @@
 package main
 
 import (
-	. "launchpad.net/gocheck"
+	gc "launchpad.net/gocheck"
+
 	"launchpad.net/juju-core/cmd"
 	"launchpad.net/juju-core/testing"
 )
@@ -12,9 +13,9 @@
 type DebugLogSuite struct {
 }
 
-var _ = Suite(&DebugLogSuite{})
+var _ = gc.Suite(&DebugLogSuite{})
 
-func runDebugLog(c *C, args ...string) (*DebugLogCommand, error) {
+func runDebugLog(c *gc.C, args ...string) (*DebugLogCommand, error) {
 	cmd := &DebugLogCommand{
 		sshCmd: &dummySSHCommand{},
 	}
@@ -33,13 +34,42 @@
 }
 
 // debug-log is implemented by invoking juju ssh with the correct arguments.
-// This test checks for the expected invocation.
-func (s *DebugLogSuite) TestDebugLogInvokesSSHCommand(c *C) {
+// This test helper checks for the expected invocation.
+func (s *DebugLogSuite) assertDebugLogInvokesSSHCommand(c *gc.C, expected string, args ...string) {
 	defer testing.MakeEmptyFakeHome(c).Restore()
-	debugLogCmd, err := runDebugLog(c)
-	c.Assert(err, IsNil)
+	debugLogCmd, err := runDebugLog(c, args...)
+	c.Assert(err, gc.IsNil)
 	debugCmd := debugLogCmd.sshCmd.(*dummySSHCommand)
-	c.Assert(debugCmd.runCalled, Equals, true)
-	c.Assert(debugCmd.Target, Equals, "0")
-	c.Assert([]string{"tail -f /var/log/juju/all-machines.log"}, DeepEquals, debugCmd.Args)
+	c.Assert(debugCmd.runCalled, gc.Equals, true)
+	c.Assert(debugCmd.Target, gc.Equals, "0")
+	c.Assert([]string{expected}, gc.DeepEquals, debugCmd.Args)
+}
+
+const logLocation = "/var/log/juju/all-machines.log"
+
+func (s *DebugLogSuite) TestDebugLog(c *gc.C) {
+	const expected = "tail -n 10 -f " + logLocation
+	s.assertDebugLogInvokesSSHCommand(c, expected)
+}
+
+func (s *DebugLogSuite) TestDebugLogFrom(c *gc.C) {
+	const expected = "tail -n +1 -f " + logLocation
+	s.assertDebugLogInvokesSSHCommand(c, expected, "-n", "+1")
+	s.assertDebugLogInvokesSSHCommand(c, expected, "--lines=+1")
+}
+
+func (s *DebugLogSuite) TestDebugLogLast(c *gc.C) {
+	const expected = "tail -n 100 -f " + logLocation
+	s.assertDebugLogInvokesSSHCommand(c, expected, "-n", "100")
+	s.assertDebugLogInvokesSSHCommand(c, expected, "--lines=100")
+}
+
+func (s *DebugLogSuite) TestDebugLogValidation(c *gc.C) {
+	defer testing.MakeEmptyFakeHome(c).Restore()
+	_, err := runDebugLog(c, "-n", "0")
+	c.Assert(err, gc.ErrorMatches, "invalid value \"0\" for flag -n: invalid number of lines")
+	_, err = runDebugLog(c, "-n", "-1")
+	c.Assert(err, gc.ErrorMatches, "invalid value \"-1\" for flag -n: invalid number of lines")
+	_, err = runDebugLog(c, "-n", "fnord")
+	c.Assert(err, gc.ErrorMatches, "invalid value \"fnord\" for flag -n: invalid number of lines")
 }