Merge lp:~thumper/juju-core/logging-in-environment into lp:~go-bot/juju-core/trunk

[Tim Penhey]

Store logging config in the environ config.

There are two main changes here. Firstly is an environment variable for the
logging config. This provides a source for the default logging config should
none be explicity set. This is handled in two places: the Log command helper;
and the new config settings.

The second is to store the logging config in the environment config. This is
used in upcoming changes to configure the agents.

https://codereview.appspot.com/13269052/

Store logging config in the environ config.

There are two main changes here. Firstly is an environment variable for the
logging config. This provides a source for the default logging config should
none be explicity set. This is handled in two places: the Log command helper;
and the new config settings.

The second is to store the logging config in the environment config. This is
used in upcoming changes to configure the agents.

https://codereview.appspot.com/13269052/

[Tim Penhey (thumper)]

Reviewers: mp+185392_code.launchpad.net,

Message:
Please take a look.

Description:
Store logging config in the environ config.

There are two main changes here. Firstly is an environment variable for
the
logging config. This provides a source for the default logging config
should
none be explicity set. This is handled in two places: the Log command
helper;
and the new config settings.

The second is to store the logging config in the environment config.
This is
used in upcoming changes to configure the agents.

https://code.launchpad.net/~thumper/juju-core/logging-in-environment/+merge/185392

(do not edit description out of merge proposal)

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

Affected files (+135, -42 lines):
   A [revision details]
   M cmd/logging.go
   M cmd/logging_test.go
   M environs/config/config.go
   M environs/config/config_test.go
   M juju/osenv/vars.go
   M testing/environ.go

[Ian Booth (wallyworld)]

LGTM but I was confused when I read "environment", as in the Juju
context, that means something different to environment variables. eg we
talk about environment constraints as being stored in the environment,
which means in state in mgo. Could you consider changing the text to
talk about environment variables?

https://codereview.appspot.com/13269052/

=== modified file 'cmd/logging.go'
--- cmd/logging.go	2013-09-12 08:00:07 +0000
+++ cmd/logging.go	2013-09-13 01:27:52 +0000
@@ -11,6 +11,8 @@
 
 	"launchpad.net/gnuflag"
 	"launchpad.net/loggo"
+
+	"launchpad.net/juju-core/juju/osenv"
 )
 
 // Log supplies the necessary functionality for Commands that wish to set up
@@ -30,7 +32,8 @@
 	f.BoolVar(&l.Verbose, "v", false, "if set, log additional messages")
 	f.BoolVar(&l.Verbose, "verbose", false, "if set, log additional messages")
 	f.BoolVar(&l.Debug, "debug", false, "if set, log debugging messages")
-	f.StringVar(&l.Config, "log-config", "", "specify log levels for modules")
+	defaultLogConfig := os.Getenv(osenv.JujuLoggingConfig)
+	f.StringVar(&l.Config, "log-config", defaultLogConfig, "specify log levels for modules")
 	f.BoolVar(&l.ShowLog, "show-log", false, "if set, write the log file to stderr")
 }
 

=== modified file 'cmd/logging_test.go'
--- cmd/logging_test.go	2013-09-12 03:54:56 +0000
+++ cmd/logging_test.go	2013-09-13 01:27:52 +0000
@@ -11,39 +11,61 @@
 	"launchpad.net/loggo"
 
 	"launchpad.net/juju-core/cmd"
-	"launchpad.net/juju-core/log"
+	"launchpad.net/juju-core/juju/osenv"
 	"launchpad.net/juju-core/testing"
 )
 
+var logger = loggo.GetLogger("juju.test")
+
 type LogSuite struct {
+	testing.CleanupSuite
 }
 
 var _ = gc.Suite(&LogSuite{})
 
-func (s *LogSuite) TearDownTest(c *gc.C) {
-	loggo.ResetLoggers()
-	loggo.ResetWriters()
+func (s *LogSuite) SetUpTest(c *gc.C) {
+	restore := testing.PatchEnvironment(osenv.JujuLoggingConfig, "")
+	s.AddCleanup(func() {
+		restore()
+		loggo.ResetLoggers()
+		loggo.ResetWriters()
+	})
 }
 
-func (s *LogSuite) TestAddFlags(c *gc.C) {
-	l := &cmd.Log{}
-	f := testing.NewFlagSet()
-	l.AddFlags(f)
-
-	err := f.Parse(false, []string{})
+func newLogWithFlags(c *gc.C, flags []string) *cmd.Log {
+	log := &cmd.Log{}
+	flagSet := testing.NewFlagSet()
+	log.AddFlags(flagSet)
+	err := flagSet.Parse(false, flags)
 	c.Assert(err, gc.IsNil)
-	c.Assert(l.Path, gc.Equals, "")
-	c.Assert(l.Verbose, gc.Equals, false)
-	c.Assert(l.Debug, gc.Equals, false)
-	c.Assert(l.Config, gc.Equals, "")
-
-	err = f.Parse(false, []string{"--log-file", "foo", "--verbose", "--debug",
+	return log
+}
+
+func (s *LogSuite) TestNoFlags(c *gc.C) {
+	log := newLogWithFlags(c, []string{})
+	c.Assert(log.Path, gc.Equals, "")
+	c.Assert(log.Verbose, gc.Equals, false)
+	c.Assert(log.Debug, gc.Equals, false)
+	c.Assert(log.Config, gc.Equals, "")
+}
+
+func (s *LogSuite) TestFlags(c *gc.C) {
+	log := newLogWithFlags(c, []string{"--log-file", "foo", "--verbose", "--debug",
 		"--log-config=juju.cmd=INFO;juju.worker.deployer=DEBUG"})
-	c.Assert(err, gc.IsNil)
-	c.Assert(l.Path, gc.Equals, "foo")
-	c.Assert(l.Verbose, gc.Equals, true)
-	c.Assert(l.Debug, gc.Equals, true)
-	c.Assert(l.Config, gc.Equals, "juju.cmd=INFO;juju.worker.deployer=DEBUG")
+	c.Assert(log.Path, gc.Equals, "foo")
+	c.Assert(log.Verbose, gc.Equals, true)
+	c.Assert(log.Debug, gc.Equals, true)
+	c.Assert(log.Config, gc.Equals, "juju.cmd=INFO;juju.worker.deployer=DEBUG")
+}
+
+func (s *LogSuite) TestLogConfigFromEnvironment(c *gc.C) {
+	config := "juju.cmd=INFO;juju.worker.deployer=DEBUG"
+	testing.PatchEnvironment(osenv.JujuLoggingConfig, config)
+	log := newLogWithFlags(c, []string{})
+	c.Assert(log.Path, gc.Equals, "")
+	c.Assert(log.Verbose, gc.Equals, false)
+	c.Assert(log.Debug, gc.Equals, false)
+	c.Assert(log.Config, gc.Equals, config)
 }
 
 func (s *LogSuite) TestVerboseSetsLogLevel(c *gc.C) {
@@ -84,7 +106,7 @@
 	ctx := testing.Context(c)
 	err := l.Start(ctx)
 	c.Assert(err, gc.IsNil)
-	log.Infof("hello")
+	logger.Infof("hello")
 	c.Assert(testing.Stderr(ctx), gc.Matches, `^.* INFO .* hello\n`)
 }
 
@@ -93,7 +115,7 @@
 	ctx := testing.Context(c)
 	err := l.Start(ctx)
 	c.Assert(err, gc.IsNil)
-	log.Infof("hello")
+	logger.Infof("hello")
 	content, err := ioutil.ReadFile(filepath.Join(ctx.Dir, "foo.log"))
 	c.Assert(err, gc.IsNil)
 	c.Assert(string(content), gc.Matches, `^.* INFO .* hello\n`)
@@ -107,7 +129,7 @@
 	ctx := testing.Context(c)
 	err := l.Start(ctx)
 	c.Assert(err, gc.IsNil)
-	log.Infof("hello")
+	logger.Infof("hello")
 	c.Assert(testing.Stderr(ctx), gc.Equals, "")
 	content, err := ioutil.ReadFile(path)
 	c.Assert(err, gc.IsNil)
@@ -119,7 +141,7 @@
 	ctx := testing.Context(c)
 	err := l.Start(ctx)
 	c.Assert(err, gc.IsNil)
-	log.Infof("hello")
+	logger.Infof("hello")
 	content, err := ioutil.ReadFile(filepath.Join(ctx.Dir, "foo.log"))
 	c.Assert(err, gc.IsNil)
 	c.Assert(string(content), gc.Matches, `^.* INFO .* hello\n`)

=== modified file 'environs/config/config.go'
--- environs/config/config.go	2013-09-12 14:12:32 +0000
+++ environs/config/config.go	2013-09-13 01:27:52 +0000
@@ -14,6 +14,7 @@
 	"launchpad.net/loggo"
 
 	"launchpad.net/juju-core/cert"
+	"launchpad.net/juju-core/juju/osenv"
 	"launchpad.net/juju-core/schema"
 	"launchpad.net/juju-core/version"
 )
@@ -97,6 +98,16 @@
 			return nil, err
 		}
 	}
+	// If the logging config hasn't been set, then look for the os environment
+	// variable, and failing that, get the config from loggo itself.
+	if c.asString("logging-config") == "" {
+		if environmentValue := os.Getenv(osenv.JujuLoggingConfig); environmentValue != "" {
+			c.m["logging-config"] = environmentValue
+		} else {
+			c.m["logging-config"] = loggo.LoggerInfo()
+		}
+	}
+
 	// no old config to compare against
 	if err = Validate(c, nil); err != nil {
 		return nil, err
@@ -192,6 +203,13 @@
 		}
 	}
 
+	// If the logging config is set, make sure it is valid.
+	if v, ok := cfg.m["logging-config"].(string); ok {
+		if _, err := loggo.ParseConfigurationString(v); err != nil {
+			return err
+		}
+	}
+
 	// Check firewall mode.
 	if mode := cfg.FirewallMode(); mode != FwInstance && mode != FwGlobal {
 		return fmt.Errorf("invalid firewall mode in environment configuration: %q", mode)
@@ -414,6 +432,11 @@
 	return c.m["ssl-hostname-verification"].(bool)
 }
 
+// LoggingConfig returns the configuration string for the loggers.
+func (c *Config) LoggingConfig() string {
+	return c.asString("logging-config")
+}
+
 // UnknownAttrs returns a copy of the raw configuration attributes
 // that are supposedly specific to the environment type. They could
 // also be wrong attributes, though. Only the specific environment
@@ -463,6 +486,7 @@
 	"ssl-hostname-verification": schema.Bool(),
 	"state-port":                schema.ForceInt(),
 	"api-port":                  schema.ForceInt(),
+	"logging-config":            schema.String(),
 }
 
 // alwaysOptional holds configuration defaults for attributes that may
@@ -480,6 +504,7 @@
 	"authorized-keys-path": schema.Omit,
 	"ca-cert-path":         schema.Omit,
 	"ca-private-key-path":  schema.Omit,
+	"logging-config":       schema.Omit,
 
 	// For backward compatibility reasons, the following
 	// attributes default to empty strings rather than being

=== modified file 'environs/config/config_test.go'
--- environs/config/config_test.go	2013-09-09 15:09:50 +0000
+++ environs/config/config_test.go	2013-09-13 01:27:52 +0000
@@ -9,9 +9,11 @@
 	"time"
 
 	gc "launchpad.net/gocheck"
+	"launchpad.net/loggo"
 
 	"launchpad.net/juju-core/cert"
 	"launchpad.net/juju-core/environs/config"
+	"launchpad.net/juju-core/juju/osenv"
 	"launchpad.net/juju-core/schema"
 	"launchpad.net/juju-core/testing"
 	jc "launchpad.net/juju-core/testing/checkers"
@@ -419,6 +421,15 @@
 		},
 		err: `api-port: expected number, got "illegal"`,
 	}, {
+		about:       "Invalid logging configuration",
+		useDefaults: config.UseDefaults,
+		attrs: testing.Attrs{
+			"type":           "my-type",
+			"name":           "my-name",
+			"logging-config": "foo=bar",
+		},
+		err: `unknown severity level "bar"`,
+	}, {
 		about:       "Sample configuration",
 		useDefaults: config.UseDefaults,
 		attrs:       sampleConfig,
@@ -726,6 +737,8 @@
 }
 
 func (*ConfigSuite) TestConfigAttrs(c *gc.C) {
+	// Normally this is handled by testing.FakeHome
+	defer testing.PatchEnvironment(osenv.JujuLoggingConfig, "")()
 	attrs := map[string]interface{}{
 		"type":                      "my-type",
 		"name":                      "my-name",
@@ -746,6 +759,7 @@
 	// These attributes are added if not set.
 	attrs["development"] = false
 	attrs["default-series"] = config.DefaultSeries
+	attrs["logging-config"] = loggo.LoggerInfo()
 	attrs["ca-private-key"] = ""
 	attrs["image-metadata-url"] = ""
 	attrs["tools-url"] = ""
@@ -847,12 +861,16 @@
 	}
 }
 
-func (*ConfigSuite) TestValidateUnknownAttrs(c *gc.C) {
-	defer testing.MakeFakeHomeWithFiles(c, []testing.TestFile{
+func makeFakeHome(c *gc.C) *testing.FakeHome {
+	return testing.MakeFakeHomeWithFiles(c, []testing.TestFile{
 		{".ssh/id_rsa.pub", "rsa\n"},
 		{".juju/myenv-cert.pem", caCert},
 		{".juju/myenv-private-key.pem", caKey},
-	}).Restore()
+	})
+}
+
+func (*ConfigSuite) TestValidateUnknownAttrs(c *gc.C) {
+	defer makeFakeHome(c).Restore()
 	cfg, err := config.New(config.UseDefaults, map[string]interface{}{
 		"name":    "myenv",
 		"type":    "other",
@@ -904,6 +922,23 @@
 	return result
 }
 
+func (*ConfigSuite) TestLoggingConfig(c *gc.C) {
+	defer makeFakeHome(c).Restore()
+
+	logConfig := "<root>=WARNING;juju=DEBUG"
+	config := newTestConfig(c, testing.Attrs{"logging-config": logConfig})
+	c.Assert(config.LoggingConfig(), gc.Equals, logConfig)
+}
+
+func (*ConfigSuite) TestLoggingConfigFromEnvironment(c *gc.C) {
+	defer makeFakeHome(c).Restore()
+	logConfig := "<root>=INFO"
+	defer testing.PatchEnvironment(osenv.JujuLoggingConfig, logConfig)()
+
+	config := newTestConfig(c, nil)
+	c.Assert(config.LoggingConfig(), gc.Equals, logConfig)
+}
+
 func (*ConfigSuite) TestGenerateStateServerCertAndKey(c *gc.C) {
 	// In order to test missing certs, it checks the JUJU_HOME dir, so we need
 	// a fake home.

=== modified file 'juju/osenv/vars.go'
--- juju/osenv/vars.go	2013-09-11 22:12:29 +0000
+++ juju/osenv/vars.go	2013-09-13 01:27:52 +0000
@@ -10,9 +10,10 @@
 )
 
 const (
-	JujuEnv        = "JUJU_ENV"
-	JujuHome       = "JUJU_HOME"
-	JujuRepository = "JUJU_REPOSITORY"
+	JujuEnv           = "JUJU_ENV"
+	JujuHome          = "JUJU_HOME"
+	JujuRepository    = "JUJU_REPOSITORY"
+	JujuLoggingConfig = "JUJU_LOGGING_CONFIG"
 	// TODO(thumper): 2013-09-02 bug 1219630
 	// As much as I'd like to remove JujuContainerType now, it is still
 	// needed as MAAS still needs it at this stage, and we can't fix

=== modified file 'testing/environ.go'
--- testing/environ.go	2013-09-12 14:16:48 +0000
+++ testing/environ.go	2013-09-13 01:27:52 +0000
@@ -85,8 +85,7 @@
 
 type FakeHome struct {
 	oldHomeEnv     string
-	oldJujuEnv     string
-	oldJujuHomeEnv string
+	oldEnvironment map[string]string
 	oldJujuHome    string
 	files          []TestFile
 }
@@ -142,18 +141,24 @@
 
 func MakeEmptyFakeHomeWithoutJuju(c *C) *FakeHome {
 	oldHomeEnv := osenv.Home()
-	oldJujuHomeEnv := os.Getenv("JUJU_HOME")
-	oldJujuEnv := os.Getenv("JUJU_ENV")
+	oldEnvironment := make(map[string]string)
+	for _, name := range []string{
+		osenv.JujuHome,
+		osenv.JujuEnv,
+		osenv.JujuLoggingConfig,
+	} {
+		oldEnvironment[name] = os.Getenv(name)
+	}
 	fakeHome := c.MkDir()
 	osenv.SetHome(fakeHome)
-	os.Setenv("JUJU_HOME", "")
-	os.Setenv("JUJU_ENV", "")
+	os.Setenv(osenv.JujuHome, "")
+	os.Setenv(osenv.JujuEnv, "")
+	os.Setenv(osenv.JujuLoggingConfig, "")
 	jujuHome := filepath.Join(fakeHome, ".juju")
 	oldJujuHome := config.SetJujuHome(jujuHome)
 	return &FakeHome{
 		oldHomeEnv:     oldHomeEnv,
-		oldJujuEnv:     oldJujuEnv,
-		oldJujuHomeEnv: oldJujuHomeEnv,
+		oldEnvironment: oldEnvironment,
 		oldJujuHome:    oldJujuHome,
 		files:          []TestFile{},
 	}
@@ -166,8 +171,9 @@
 
 func (h *FakeHome) Restore() {
 	config.SetJujuHome(h.oldJujuHome)
-	os.Setenv("JUJU_ENV", h.oldJujuEnv)
-	os.Setenv("JUJU_HOME", h.oldJujuHomeEnv)
+	for name, value := range h.oldEnvironment {
+		os.Setenv(name, value)
+	}
 	osenv.SetHome(h.oldHomeEnv)
 }