Merge lp:~axwalk/juju-core/lp1279710-cloudinitoutput-on-error into lp:~go-bot/juju-core/trunk

[Andrew Wilkins]

Dump cloud-init-output.log on failed bootstrap

Currently if bootstrap (or manual provisioning)
fails, we don't get a useful error message, just
"exit status 1" (because the SSH script failed).
This change is to dump the contents of the
cloud-init-output.log file to stderr when the SSH
script fails.

Fixes lp:1279710

https://codereview.appspot.com/75990043/

Dump cloud-init-output.log on failed bootstrap

Currently if bootstrap (or manual provisioning)
fails, we don't get a useful error message, just
"exit status 1" (because the SSH script failed).
This change is to dump the contents of the
cloud-init-output.log file to stderr when the SSH
script fails.

Fixes lp:1279710

https://codereview.appspot.com/75990043/

[Andrew Wilkins (axwalk)]

Reviewers: mp+211016_code.launchpad.net,

Message:
Please take a look.

Description:
Dump cloud-init-output.log on failed bootstrap

Currently if bootstrap (or manual provisioning)
fails, we don't get a useful error message, just
"exit status 1" (because the SSH script failed).
This change is to dump the contents of the
cloud-init-output.log file to stderr when the SSH
script fails.

Fixes lp:1279710

https://code.launchpad.net/~axwalk/juju-core/lp1279710-cloudinitoutput-on-error/+merge/211016

(do not edit description out of merge proposal)

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

Affected files (+76, -28 lines):
   A [revision details]
   M environs/cloudinit/cloudinit.go
   M environs/manual/provisioner.go
   M environs/manual/provisioner_test.go
   M provider/common/bootstrap.go
   M provider/local/environ.go
   M state/apiserver/client/client.go
   M state/apiserver/client/client_test.go

[Roger Peppe (rogpeppe)]

LGTM assuming you've tested it live, with a few superficial suggestions
below.

https://codereview.appspot.com/75990043/diff/1/environs/cloudinit/cloudinit.go
File environs/cloudinit/cloudinit.go (right):

https://codereview.appspot.com/75990043/diff/1/environs/cloudinit/cloudinit.go#newcode409
environs/cloudinit/cloudinit.go:409: func DumpLogOnError(mcfg
*MachineConfig) string {
This isn't really that deeply connected to MachineConfig,
or environs, and it's perhaps reasonable for the callers to know about
the cloudinit file, so perhaps this might be better in
utils, say, as:

// DumpFileOnErrorScript returns a script that
// prints the contents of the given file to
// standard error if any commands following it exit with an error.
// The returned script is newline terminated.
func DumpFileOnErrorScript(filename string) string

then the callers can use
utils.DumpFileOnErrorScript(mcfg.CloudInitOutputLog)

https://codereview.appspot.com/75990043/diff/1/environs/cloudinit/cloudinit.go#newcode418
environs/cloudinit/cloudinit.go:418: trap "dump_cloudinit_log" EXIT
i didn't know that EXIT works rather than 0, but as both dash and bash
seem to support it, i guess it's ok.

The quotes are unnecessary here BTW.

https://codereview.appspot.com/75990043/diff/1/environs/manual/provisioner.go
File environs/manual/provisioner.go (right):

https://codereview.appspot.com/75990043/diff/1/environs/manual/provisioner.go#newcode319
environs/manual/provisioner.go:319: script = fmt.Sprintf("rm -f %s\n",
utils.ShQuote(mcfg.CloudInitOutputLog)) + script
rather than doing thing backwards, i'd be tempted to build the script up
in order:

var buf bytes.Buffer
// Always remove the cloud-init-output.log file first, if it exists.
fmt.Fprintf(&buf, "rm -f %s\n", ...)
buf.WriteString(cloudinit.DumpLogOnError(mcfg))
configScript, err := sshinit.ConfigureScript(cloudcfg)
...
buf.WriteString(configScript)
return buf.String(), nil

https://codereview.appspot.com/75990043/

[Andrew Wilkins (axwalk)]

Please take a look.

https://codereview.appspot.com/75990043/diff/1/environs/cloudinit/cloudinit.go
File environs/cloudinit/cloudinit.go (right):

https://codereview.appspot.com/75990043/diff/1/environs/cloudinit/cloudinit.go#newcode409
environs/cloudinit/cloudinit.go:409: func DumpLogOnError(mcfg
*MachineConfig) string {
On 2014/03/14 12:11:39, rog wrote:
> This isn't really that deeply connected to MachineConfig,
> or environs, and it's perhaps reasonable for the callers to know about
> the cloudinit file, so perhaps this might be better in
> utils, say, as:

> // DumpFileOnErrorScript returns a script that
> // prints the contents of the given file to
> // standard error if any commands following it exit with an error.
> // The returned script is newline terminated.
> func DumpFileOnErrorScript(filename string) string

> then the callers can use
utils.DumpFileOnErrorScript(mcfg.CloudInitOutputLog)

Done, though I'm starting a new package: utils/shell. We can move
ShQuote and other shell related things in there over time.

https://codereview.appspot.com/75990043/diff/1/environs/cloudinit/cloudinit.go#newcode418
environs/cloudinit/cloudinit.go:418: trap "dump_cloudinit_log" EXIT
On 2014/03/14 12:11:39, rog wrote:
> i didn't know that EXIT works rather than 0, but as both dash and bash
seem to
> support it, i guess it's ok.

> The quotes are unnecessary here BTW.

Thanks, removed

https://codereview.appspot.com/75990043/diff/1/environs/manual/provisioner.go
File environs/manual/provisioner.go (right):

https://codereview.appspot.com/75990043/diff/1/environs/manual/provisioner.go#newcode319
environs/manual/provisioner.go:319: script = fmt.Sprintf("rm -f %s\n",
utils.ShQuote(mcfg.CloudInitOutputLog)) + script
On 2014/03/14 12:11:39, rog wrote:
> rather than doing thing backwards, i'd be tempted to build the script
up in
> order:

> var buf bytes.Buffer
> // Always remove the cloud-init-output.log file first, if it exists.
> fmt.Fprintf(&buf, "rm -f %s\n", ...)
> buf.WriteString(cloudinit.DumpLogOnError(mcfg))
> configScript, err := sshinit.ConfigureScript(cloudcfg)
> ...
> buf.WriteString(configScript)
> return buf.String(), nil

Done.

https://codereview.appspot.com/75990043/

[Roger Peppe (rogpeppe)]

On 2014/03/17 03:21:31, axw wrote:
> Please take a look.

https://codereview.appspot.com/75990043/diff/1/environs/cloudinit/cloudinit.go
> File environs/cloudinit/cloudinit.go (right):

https://codereview.appspot.com/75990043/diff/1/environs/cloudinit/cloudinit.go#newcode409
> environs/cloudinit/cloudinit.go:409: func DumpLogOnError(mcfg
*MachineConfig)
> string {
> On 2014/03/14 12:11:39, rog wrote:
> > This isn't really that deeply connected to MachineConfig,
> > or environs, and it's perhaps reasonable for the callers to know
about
> > the cloudinit file, so perhaps this might be better in
> > utils, say, as:
> >
> > // DumpFileOnErrorScript returns a script that
> > // prints the contents of the given file to
> > // standard error if any commands following it exit with an error.
> > // The returned script is newline terminated.
> > func DumpFileOnErrorScript(filename string) string
> >
> > then the callers can use
utils.DumpFileOnErrorScript(mcfg.CloudInitOutputLog)

> Done, though I'm starting a new package: utils/shell. We can move
ShQuote and
> other shell related things in there over time.

https://codereview.appspot.com/75990043/diff/1/environs/cloudinit/cloudinit.go#newcode418
> environs/cloudinit/cloudinit.go:418: trap "dump_cloudinit_log" EXIT
> On 2014/03/14 12:11:39, rog wrote:
> > i didn't know that EXIT works rather than 0, but as both dash and
bash seem to
> > support it, i guess it's ok.
> >
> > The quotes are unnecessary here BTW.

> Thanks, removed

https://codereview.appspot.com/75990043/diff/1/environs/manual/provisioner.go
> File environs/manual/provisioner.go (right):

https://codereview.appspot.com/75990043/diff/1/environs/manual/provisioner.go#newcode319
> environs/manual/provisioner.go:319: script = fmt.Sprintf("rm -f %s\n",
> utils.ShQuote(mcfg.CloudInitOutputLog)) + script
> On 2014/03/14 12:11:39, rog wrote:
> > rather than doing thing backwards, i'd be tempted to build the
script up in
> > order:
> >
> > var buf bytes.Buffer
> > // Always remove the cloud-init-output.log file first, if it exists.
> > fmt.Fprintf(&buf, "rm -f %s\n", ...)
> > buf.WriteString(cloudinit.DumpLogOnError(mcfg))
> > configScript, err := sshinit.ConfigureScript(cloudcfg)
> > ...
> > buf.WriteString(configScript)
> > return buf.String(), nil

> Done.

LGTM

https://codereview.appspot.com/75990043/

=== modified file 'environs/manual/provisioner.go'
--- environs/manual/provisioner.go	2014-03-05 19:41:34 +0000
+++ environs/manual/provisioner.go	2014-03-17 08:26:37 +0000
@@ -4,6 +4,7 @@
 package manual
 
 import (
+	"bytes"
 	"errors"
 	"fmt"
 	"io"
@@ -24,6 +25,7 @@
 	"launchpad.net/juju-core/state/statecmd"
 	"launchpad.net/juju-core/tools"
 	"launchpad.net/juju-core/utils"
+	"launchpad.net/juju-core/utils/shell"
 )
 
 const manualInstancePrefix = "manual:"
@@ -143,7 +145,7 @@
 	} else {
 		mcfg, err := statecmd.MachineConfig(stateConn.State, machineId, machineParams.Nonce, args.DataDir)
 		if err == nil {
-			provisioningScript, err = generateProvisioningScript(mcfg)
+			provisioningScript, err = ProvisioningScript(mcfg)
 		}
 		if err != nil {
 			return "", err
@@ -199,9 +201,6 @@
 	if err != nil {
 		return "", err
 	}
-	//if p.Series == "" {
-	//	p.Series = defaultSeries
-	//}
 	template := state.MachineTemplate{
 		Series:      machineParams.Series,
 		Constraints: machineParams.Constraints,
@@ -294,14 +293,17 @@
 }
 
 var provisionMachineAgent = func(host string, mcfg *cloudinit.MachineConfig, progressWriter io.Writer) error {
-	script, err := generateProvisioningScript(mcfg)
+	script, err := ProvisioningScript(mcfg)
 	if err != nil {
 		return err
 	}
 	return runProvisionScript(script, host, progressWriter)
 }
 
-func generateProvisioningScript(mcfg *cloudinit.MachineConfig) (string, error) {
+// ProvisioningScript generates a bash script that can be
+// executed on a remote host to carry out the cloud-init
+// configuration.
+func ProvisioningScript(mcfg *cloudinit.MachineConfig) (string, error) {
 	cloudcfg := coreCloudinit.New()
 	if err := cloudinit.ConfigureJuju(mcfg, cloudcfg); err != nil {
 		return "", err
@@ -309,7 +311,18 @@
 	// Explicitly disabling apt_upgrade so as not to trample
 	// the target machine's existing configuration.
 	cloudcfg.SetAptUpgrade(false)
-	return sshinit.ConfigureScript(cloudcfg)
+	configScript, err := sshinit.ConfigureScript(cloudcfg)
+	if err != nil {
+		return "", err
+	}
+
+	var buf bytes.Buffer
+	// Always remove the cloud-init-output.log file first, if it exists.
+	fmt.Fprintf(&buf, "rm -f %s\n", utils.ShQuote(mcfg.CloudInitOutputLog))
+	// If something goes wrong, dump cloud-init-output.log to stderr.
+	buf.WriteString(shell.DumpFileOnErrorScript(mcfg.CloudInitOutputLog))
+	buf.WriteString(configScript)
+	return buf.String(), nil
 }
 
 func runProvisionScript(script, host string, progressWriter io.Writer) error {

=== modified file 'environs/manual/provisioner_test.go'
--- environs/manual/provisioner_test.go	2014-03-13 07:54:56 +0000
+++ environs/manual/provisioner_test.go	2014-03-17 08:26:37 +0000
@@ -10,6 +10,9 @@
 	jc "github.com/juju/testing/checkers"
 	gc "launchpad.net/gocheck"
 
+	coreCloudinit "launchpad.net/juju-core/cloudinit"
+	"launchpad.net/juju-core/cloudinit/sshinit"
+	"launchpad.net/juju-core/environs/cloudinit"
 	"launchpad.net/juju-core/environs/manual"
 	envtesting "launchpad.net/juju-core/environs/testing"
 	"launchpad.net/juju-core/instance"
@@ -17,6 +20,7 @@
 	"launchpad.net/juju-core/state"
 	"launchpad.net/juju-core/state/api/params"
 	"launchpad.net/juju-core/state/statecmd"
+	"launchpad.net/juju-core/utils/shell"
 	"launchpad.net/juju-core/version"
 )
 
@@ -131,3 +135,31 @@
 	c.Check(mcfg.APIInfo.Addrs, gc.DeepEquals, apiInfo.Addrs)
 	c.Check(mcfg.StateInfo.Addrs, gc.DeepEquals, stateInfo.Addrs)
 }
+
+func (s *provisionerSuite) TestProvisioningScript(c *gc.C) {
+	const series = "precise"
+	const arch = "amd64"
+	defer fakeSSH{
+		Series:         series,
+		Arch:           arch,
+		InitUbuntuUser: true,
+	}.install(c).Restore()
+	machineId, err := manual.ProvisionMachine(s.getArgs(c))
+	c.Assert(err, gc.IsNil)
+
+	mcfg, err := statecmd.MachineConfig(s.State, machineId, state.BootstrapNonce, "/var/lib/juju")
+	c.Assert(err, gc.IsNil)
+	script, err := manual.ProvisioningScript(mcfg)
+	c.Assert(err, gc.IsNil)
+
+	cloudcfg := coreCloudinit.New()
+	err = cloudinit.ConfigureJuju(mcfg, cloudcfg)
+	c.Assert(err, gc.IsNil)
+	cloudcfg.SetAptUpgrade(false)
+	sshinitScript, err := sshinit.ConfigureScript(cloudcfg)
+	c.Assert(err, gc.IsNil)
+
+	removeLogFile := "rm -f '/var/log/cloud-init-output.log'\n"
+	expectedScript := removeLogFile + shell.DumpFileOnErrorScript("/var/log/cloud-init-output.log") + sshinitScript
+	c.Assert(script, gc.Equals, expectedScript)
+}

=== modified file 'provider/common/bootstrap.go'
--- provider/common/bootstrap.go	2014-03-13 05:09:14 +0000
+++ provider/common/bootstrap.go	2014-03-17 08:26:37 +0000
@@ -24,6 +24,7 @@
 	coretools "launchpad.net/juju-core/tools"
 	"launchpad.net/juju-core/utils"
 	"launchpad.net/juju-core/utils/parallel"
+	"launchpad.net/juju-core/utils/shell"
 	"launchpad.net/juju-core/utils/ssh"
 )
 
@@ -200,7 +201,12 @@
 	if err := cloudinit.ConfigureJuju(machineConfig, cloudcfg); err != nil {
 		return err
 	}
-	return sshinit.Configure(sshinit.ConfigureParams{
+	configScript, err := sshinit.ConfigureScript(cloudcfg)
+	if err != nil {
+		return err
+	}
+	script := shell.DumpFileOnErrorScript(machineConfig.CloudInitOutputLog) + configScript
+	return sshinit.RunConfigureScript(script, sshinit.ConfigureParams{
 		Host:           "ubuntu@" + addr,
 		Client:         client,
 		Config:         cloudcfg,

=== modified file 'provider/local/environ.go'
--- provider/local/environ.go	2014-03-14 02:19:35 +0000
+++ provider/local/environ.go	2014-03-17 08:26:37 +0000
@@ -38,6 +38,7 @@
 	"launchpad.net/juju-core/state"
 	"launchpad.net/juju-core/state/api"
 	"launchpad.net/juju-core/state/api/params"
+	"launchpad.net/juju-core/utils/shell"
 	"launchpad.net/juju-core/version"
 	"launchpad.net/juju-core/worker/terminationworker"
 )
@@ -177,10 +178,11 @@
 //
 // mcfg is supplied for testing purposes.
 var finishBootstrap = func(mcfg *cloudinit.MachineConfig, cloudcfg *coreCloudinit.Config, ctx environs.BootstrapContext) error {
-	script, err := sshinit.ConfigureScript(cloudcfg)
+	configScript, err := sshinit.ConfigureScript(cloudcfg)
 	if err != nil {
 		return nil
 	}
+	script := shell.DumpFileOnErrorScript(mcfg.CloudInitOutputLog) + configScript
 	cmd := exec.Command("sudo", "/bin/bash", "-s")
 	cmd.Stdin = strings.NewReader(script)
 	cmd.Stdout = ctx.GetStdout()

=== modified file 'state/apiserver/client/client.go'
--- state/apiserver/client/client.go	2014-03-11 03:00:49 +0000
+++ state/apiserver/client/client.go	2014-03-17 08:26:37 +0000
@@ -13,11 +13,9 @@
 	"github.com/juju/loggo"
 
 	"launchpad.net/juju-core/charm"
-	coreCloudinit "launchpad.net/juju-core/cloudinit"
-	"launchpad.net/juju-core/cloudinit/sshinit"
 	"launchpad.net/juju-core/environs"
-	"launchpad.net/juju-core/environs/cloudinit"
 	"launchpad.net/juju-core/environs/config"
+	"launchpad.net/juju-core/environs/manual"
 	envtools "launchpad.net/juju-core/environs/tools"
 	"launchpad.net/juju-core/errors"
 	"launchpad.net/juju-core/instance"
@@ -611,15 +609,7 @@
 		return result, err
 	}
 	mcfg.DisablePackageCommands = args.DisablePackageCommands
-	cloudcfg := coreCloudinit.New()
-	if err := cloudinit.ConfigureJuju(mcfg, cloudcfg); err != nil {
-		return result, err
-	}
-	// ProvisioningScript is run on an existing machine;
-	// we explicitly disable apt_upgrade so as not to
-	// trample the machine's existing configuration.
-	cloudcfg.SetAptUpgrade(false)
-	result.Script, err = sshinit.ConfigureScript(cloudcfg)
+	result.Script, err = manual.ProvisioningScript(mcfg)
 	return result, err
 }
 

=== modified file 'state/apiserver/client/client_test.go'
--- state/apiserver/client/client_test.go	2014-03-13 07:54:56 +0000
+++ state/apiserver/client/client_test.go	2014-03-17 08:26:37 +0000
@@ -15,12 +15,10 @@
 	gc "launchpad.net/gocheck"
 
 	"launchpad.net/juju-core/charm"
-	coreCloudinit "launchpad.net/juju-core/cloudinit"
-	"launchpad.net/juju-core/cloudinit/sshinit"
 	"launchpad.net/juju-core/constraints"
 	"launchpad.net/juju-core/environs"
-	"launchpad.net/juju-core/environs/cloudinit"
 	"launchpad.net/juju-core/environs/config"
+	"launchpad.net/juju-core/environs/manual"
 	envstorage "launchpad.net/juju-core/environs/storage"
 	ttesting "launchpad.net/juju-core/environs/tools/testing"
 	"launchpad.net/juju-core/errors"
@@ -1695,11 +1693,7 @@
 	c.Assert(err, gc.IsNil)
 	mcfg, err := statecmd.MachineConfig(s.State, machineId, apiParams.Nonce, "")
 	c.Assert(err, gc.IsNil)
-	cloudcfg := coreCloudinit.New()
-	err = cloudinit.ConfigureJuju(mcfg, cloudcfg)
-	c.Assert(err, gc.IsNil)
-	cloudcfg.SetAptUpgrade(false)
-	sshinitScript, err := sshinit.ConfigureScript(cloudcfg)
+	sshinitScript, err := manual.ProvisioningScript(mcfg)
 	c.Assert(err, gc.IsNil)
 	// ProvisioningScript internally calls MachineConfig,
 	// which allocates a new, random password. Everything

=== added directory 'utils/shell'
=== added file 'utils/shell/package_test.go'
--- utils/shell/package_test.go	1970-01-01 00:00:00 +0000
+++ utils/shell/package_test.go	2014-03-17 08:26:37 +0000
@@ -0,0 +1,14 @@
+// Copyright 2014 Canonical Ltd.
+// Licensed under the AGPLv3, see LICENCE file for details.
+
+package shell_test
+
+import (
+	"testing"
+
+	gc "launchpad.net/gocheck"
+)
+
+func Test(t *testing.T) {
+	gc.TestingT(t)
+}

=== added file 'utils/shell/script.go'
--- utils/shell/script.go	1970-01-01 00:00:00 +0000
+++ utils/shell/script.go	2014-03-17 08:26:37 +0000
@@ -0,0 +1,28 @@
+// Copyright 2014 Canonical Ltd.
+// Licensed under the AGPLv3, see LICENCE file for details.
+
+package shell
+
+import (
+	"fmt"
+
+	"launchpad.net/juju-core/utils"
+)
+
+// DumpFileOnErrorScript returns a bash script that
+// may be used to dump the contents of the specified
+// file to stderr when the shell exits with an error.
+func DumpFileOnErrorScript(filename string) string {
+	script := `
+dump_file() {
+    code=$?
+    if [ $code -ne 0 -a -e %s ]; then
+        cat %s >&2
+    fi
+    exit $code
+}
+trap dump_file EXIT
+`[1:]
+	filename = utils.ShQuote(filename)
+	return fmt.Sprintf(script, filename, filename)
+}

=== added file 'utils/shell/script_test.go'
--- utils/shell/script_test.go	1970-01-01 00:00:00 +0000
+++ utils/shell/script_test.go	2014-03-17 08:26:37 +0000
@@ -0,0 +1,71 @@
+// Copyright 2014 Canonical Ltd.
+// Licensed under the AGPLv3, see LICENCE file for details.
+
+package shell_test
+
+import (
+	"bytes"
+	"io/ioutil"
+	"os"
+	"os/exec"
+	"path/filepath"
+	"strings"
+
+	gc "launchpad.net/gocheck"
+
+	"launchpad.net/juju-core/testing/testbase"
+	"launchpad.net/juju-core/utils/shell"
+)
+
+type scriptSuite struct {
+	testbase.LoggingSuite
+}
+
+var _ = gc.Suite(&scriptSuite{})
+
+func (*scriptSuite) TestDumpFileOnErrorScriptOutput(c *gc.C) {
+	script := shell.DumpFileOnErrorScript("a b c")
+	c.Assert(script, gc.Equals, `
+dump_file() {
+    code=$?
+    if [ $code -ne 0 -a -e 'a b c' ]; then
+        cat 'a b c' >&2
+    fi
+    exit $code
+}
+trap dump_file EXIT
+`[1:])
+}
+
+func (*scriptSuite) TestDumpFileOnErrorScript(c *gc.C) {
+	tempdir := c.MkDir()
+	filename := filepath.Join(tempdir, "log.txt")
+	err := ioutil.WriteFile(filename, []byte("abc"), 0644)
+	c.Assert(err, gc.IsNil)
+
+	dumpScript := shell.DumpFileOnErrorScript(filename)
+	c.Logf("%s", dumpScript)
+	run := func(command string) (stdout, stderr string) {
+		var stdoutBuf, stderrBuf bytes.Buffer
+		cmd := exec.Command("/bin/bash", "-s")
+		cmd.Stdin = strings.NewReader(dumpScript + command)
+		cmd.Stdout = &stdoutBuf
+		cmd.Stderr = &stderrBuf
+		cmd.Run()
+		return stdoutBuf.String(), stderrBuf.String()
+	}
+
+	stdout, stderr := run("exit 0")
+	c.Assert(stdout, gc.Equals, "")
+	c.Assert(stderr, gc.Equals, "")
+
+	stdout, stderr = run("exit 1")
+	c.Assert(stdout, gc.Equals, "")
+	c.Assert(stderr, gc.Equals, "abc")
+
+	err = os.Remove(filename)
+	c.Assert(err, gc.IsNil)
+	stdout, stderr = run("exit 1")
+	c.Assert(stdout, gc.Equals, "")
+	c.Assert(stderr, gc.Equals, "")
+}