updated to use a common logging library and enable log level configuration
Change-Id: Ib473615f25318c3b40cd6cf3bd49248e8a3d4fb1
diff --git a/automation/Dockerfile b/automation/Dockerfile
index 22ce5f7..c864076 100644
--- a/automation/Dockerfile
+++ b/automation/Dockerfile
@@ -1,4 +1,4 @@
-FROM golang:alpine
+FROM golang:1.6-alpine
RUN apk --update add openssh-client git
@@ -7,13 +7,9 @@
ADD . /go/src/gerrit.opencord.org/maas/cord-maas-automation
WORKDIR /go/src/gerrit.opencord.org/maas/cord-maas-automation
-RUN /go/bin/godep restore
+RUN /go/bin/godep restore || true
WORKDIR /go
-
RUN go install gerrit.opencord.org/maas/cord-maas-automation
-RUN mkdir -p /root/.ssh
-COPY ssh-config /root/.ssh/config
-
ENTRYPOINT ["/go/bin/cord-maas-automation"]
diff --git a/automation/Godeps/Godeps.json b/automation/Godeps/Godeps.json
index 88da63d..c601bc6 100644
--- a/automation/Godeps/Godeps.json
+++ b/automation/Godeps/Godeps.json
@@ -24,6 +24,10 @@
"ImportPath": "github.com/kelseyhightower/envconfig",
"Comment": "1.1.0-17-g91921eb",
"Rev": "91921eb4cf999321cdbeebdba5a03555800d493b"
+ },
+ {
+ "ImportPath": "github.com/Sirupsen/logrus",
+ "Rev": "f3cfb454f4c209e6668c95216c4744b8fddb2356"
}
]
}
diff --git a/automation/maas-flow.go b/automation/maas-flow.go
index be9459f..7bacddb 100644
--- a/automation/maas-flow.go
+++ b/automation/maas-flow.go
@@ -3,8 +3,8 @@
import (
"encoding/json"
"flag"
+ "github.com/Sirupsen/logrus"
"github.com/kelseyhightower/envconfig"
- "log"
"net/url"
"os"
"strings"
@@ -35,6 +35,8 @@
PowerHelperScript string `default:"" envconfig:"POWER_HELPER_SCRIPT"`
ProvisionUrl string `default:"" envconfig:"PROVISION_URL"`
ProvisionTtl string `default:"1h" envconfig:"PROVISION_TTL"`
+ LogLevel string `default:"warning" envconfig:"LOG_LEVEL"`
+ LogFormat string `default:"text" envconfig:"LOG_FORMAT"`
}
var apiKey = flag.String("apikey", "", "key with which to access MAAS server")
@@ -44,7 +46,6 @@
var preview = flag.Bool("preview", false, "displays the action that would be taken, but does not do the action, in this mode the nodes are processed only once")
var mappings = flag.String("mappings", "{}", "the mac to name mappings")
var always = flag.Bool("always-rename", true, "attempt to rename at every stage of workflow")
-var verbose = flag.Bool("verbose", false, "display verbose logging")
var filterSpec = flag.String("filter", strings.Map(func(r rune) rune {
if unicode.IsSpace(r) {
return -1
@@ -56,7 +57,7 @@
// return false.
func checkError(err error, message string, v ...interface{}) bool {
if err != nil {
- log.Fatalf("[error] "+message, v)
+ log.Fatalf(message, v...)
}
return false
}
@@ -65,7 +66,7 @@
// return true, else return false.
func checkWarn(err error, message string, v ...interface{}) bool {
if err != nil {
- log.Printf("[warn] "+message, v)
+ log.Warningf(message, v...)
return true
}
return false
@@ -93,16 +94,19 @@
return nodes, nil
}
+var log = logrus.New()
+
func main() {
flag.Parse()
config := Config{}
err := envconfig.Process("AUTOMATION", &config)
- checkError(err, "[error] unable to parse environment options : %s", err)
+ if err != nil {
+ log.Fatalf("Unable to parse configuration options : %s", err)
+ }
options := ProcessingOptions{
Preview: *preview,
- Verbose: *verbose,
AlwaysRename: *always,
Provisioner: NewProvisioner(&ProvisionerConfig{Url: config.ProvisionUrl}),
ProvisionURL: config.ProvisionUrl,
@@ -111,8 +115,24 @@
PowerHelperHost: config.PowerHelperHost,
}
+ switch config.LogFormat {
+ case "json":
+ log.Formatter = &logrus.JSONFormatter{}
+ default:
+ log.Formatter = &logrus.TextFormatter{
+ FullTimestamp: true,
+ ForceColors: true,
+ }
+ }
+
+ level, err := logrus.ParseLevel(config.LogLevel)
+ if err != nil {
+ level = logrus.WarnLevel
+ }
+ log.Level = level
+
options.ProvisionTTL, err = time.ParseDuration(config.ProvisionTtl)
- checkError(err, "[error] unable to parse specified duration of '%s' : %s", err)
+ checkError(err, "unable to parse specified duration of '%s' : %s", err)
// Determine the filter, this can either be specified on the the command
// line as a value or a file reference. If none is specified the default
@@ -121,17 +141,17 @@
if (*filterSpec)[0] == '@' {
name := os.ExpandEnv((*filterSpec)[1:])
file, err := os.OpenFile(name, os.O_RDONLY, 0)
- checkError(err, "[error] unable to open file '%s' to load the filter : %s", name, err)
+ checkError(err, "unable to open file '%s' to load the filter : %s", name, err)
decoder := json.NewDecoder(file)
err = decoder.Decode(&options.Filter)
- checkError(err, "[error] unable to parse filter configuration from file '%s' : %s", name, err)
+ checkError(err, "unable to parse filter configuration from file '%s' : %s", name, err)
} else {
err := json.Unmarshal([]byte(*filterSpec), &options.Filter)
- checkError(err, "[error] unable to parse filter specification: '%s' : %s", *filterSpec, err)
+ checkError(err, "unable to parse filter specification: '%s' : %s", *filterSpec, err)
}
} else {
err := json.Unmarshal([]byte(defaultFilter), &options.Filter)
- checkError(err, "[error] unable to parse default filter specificiation: '%s' : %s", defaultFilter, err)
+ checkError(err, "unable to parse default filter specificiation: '%s' : %s", defaultFilter, err)
}
// Determine the mac to name mapping, this can either be specified on the the command
@@ -141,44 +161,45 @@
if (*mappings)[0] == '@' {
name := os.ExpandEnv((*mappings)[1:])
file, err := os.OpenFile(name, os.O_RDONLY, 0)
- checkError(err, "[error] unable to open file '%s' to load the mac name mapping : %s", name, err)
+ checkError(err, "unable to open file '%s' to load the mac name mapping : %s", name, err)
decoder := json.NewDecoder(file)
err = decoder.Decode(&options.Mappings)
- checkError(err, "[error] unable to parse filter configuration from file '%s' : %s", name, err)
+ checkError(err, "unable to parse filter configuration from file '%s' : %s", name, err)
} else {
err := json.Unmarshal([]byte(*mappings), &options.Mappings)
- checkError(err, "[error] unable to parse mac name mapping: '%s' : %s", *mappings, err)
+ checkError(err, "unable to parse mac name mapping: '%s' : %s", *mappings, err)
}
} else {
err := json.Unmarshal([]byte(defaultMapping), &options.Mappings)
- checkError(err, "[error] unable to parse default mac name mappings: '%s' : %s", defaultMapping, err)
+ checkError(err, "unable to parse default mac name mappings: '%s' : %s", defaultMapping, err)
}
// Verify the specified period for queries can be converted into a Go duration
period, err := time.ParseDuration(*queryPeriod)
- checkError(err, "[error] unable to parse specified query period duration: '%s': %s", queryPeriod, err)
+ checkError(err, "unable to parse specified query period duration: '%s': %s", queryPeriod, err)
- log.Printf(`Configuration:
+ log.Infof(`Configuration:
MAAS URL: %s
MAAS API Version: %s
MAAS Query Interval: %s
Node Filter: %s
Node Name Mappings: %s
Preview: %v
- Verbose: %v
Always Rename: %v
Provision URL: %s
Provision TTL: %s
Power Helper: %s
Power Helper User: %s
- Power Helper Host: %s`,
+ Power Helper Host: %s
+ Log Level: %s
+ Log Format: %s`,
*maasURL, *apiVersion, *queryPeriod, *filterSpec, *mappings, options.Preview,
- options.Verbose, options.AlwaysRename, options.ProvisionURL, options.ProvisionTTL,
- options.PowerHelper, options.PowerHelperUser, options.PowerHelperHost)
+ options.AlwaysRename, options.ProvisionURL, options.ProvisionTTL,
+ options.PowerHelper, options.PowerHelperUser, options.PowerHelperHost, config.LogLevel, config.LogFormat)
authClient, err := maas.NewAuthenticatedClient(*maasURL, *apiKey, *apiVersion)
if err != nil {
- checkError(err, "[error] Unable to use specified client key, '%s', to authenticate to the MAAS server: %s", *apiKey, err)
+ checkError(err, "Unable to use specified client key, '%s', to authenticate to the MAAS server: %s", *apiKey, err)
}
// Create an object through which we will communicate with MAAS
@@ -197,7 +218,7 @@
// Create a ticker and fetch and process the nodes every "period"
ticker := time.NewTicker(period)
for t := range ticker.C {
- log.Printf("[info] query server at %s", t)
+ log.Infof("query server at %s", t)
nodes, _ := fetchNodes(client)
ProcessAll(client, nodes, options)
}
diff --git a/automation/node.go b/automation/node.go
index 9e045e6..a54579a 100644
--- a/automation/node.go
+++ b/automation/node.go
@@ -2,8 +2,6 @@
import (
"fmt"
- "log"
-
maas "github.com/juju/gomaasapi"
"net/url"
)
@@ -89,7 +87,7 @@
}
_, err := n.Update(values)
if err != nil {
- log.Printf("[error] error updating power settings : %s", err.Error())
+ log.Errorf("error updating power settings : %s", err.Error())
}
}
diff --git a/automation/state.go b/automation/state.go
index 7fe1760..5058d17 100644
--- a/automation/state.go
+++ b/automation/state.go
@@ -3,7 +3,6 @@
import (
"encoding/json"
"fmt"
- "log"
"net/url"
"os/exec"
"regexp"
@@ -44,7 +43,6 @@
}
}
Mappings map[string]interface{}
- Verbose bool
Preview bool
AlwaysRename bool
Provisioner Provisioner
@@ -130,7 +128,7 @@
if name, ok := entry.(map[string]interface{})["hostname"]; ok && current != name.(string) {
nodesObj := client.GetSubObject("nodes")
nodeObj := nodesObj.GetSubObject(node.ID())
- log.Printf("RENAME '%s' to '%s'\n", node.Hostname(), name.(string))
+ log.Infof("RENAME '%s' to '%s'\n", node.Hostname(), name.(string))
if !options.Preview {
nodeObj.Update(url.Values{"hostname": []string{name.(string)}})
@@ -143,9 +141,7 @@
// Reset we are at the target state, nothing to do
var Reset = func(client *maas.MAASObject, node MaasNode, options ProcessingOptions) error {
- if options.Verbose {
- log.Printf("RESET: %s", node.Hostname())
- }
+ log.Debugf("RESET: %s", node.Hostname())
if options.AlwaysRename {
updateNodeName(client, node, options)
@@ -158,9 +154,7 @@
// Provision we are at the target state, nothing to do
var Provision = func(client *maas.MAASObject, node MaasNode, options ProcessingOptions) error {
- if options.Verbose {
- log.Printf("CHECK PROVISION: %s", node.Hostname())
- }
+ log.Debugf("CHECK PROVISION: %s", node.Hostname())
if options.AlwaysRename {
updateNodeName(client, node, options)
@@ -168,7 +162,7 @@
record, err := options.Provisioner.Get(node.ID())
if err != nil {
- log.Printf("[warn] unable to retrieve provisioning state of node '%s' : %s", node.Hostname(), err)
+ log.Warningf("unable to retrieve provisioning state of node '%s' : %s", node.Hostname(), err)
} else if record == nil || record.Status == Failed {
var label string
if record == nil {
@@ -176,9 +170,7 @@
} else {
label = record.Status.String()
}
- if options.Verbose {
- log.Printf("[info] Current state of node '%s' is '%s'", node.Hostname(), label)
- }
+ log.Debugf("Current state of node '%s' is '%s'", node.Hostname(), label)
ips := node.IPs()
ip := ""
if len(ips) > 0 {
@@ -189,10 +181,7 @@
if len(macs) > 0 {
mac = macs[0]
}
- if options.Verbose {
- log.Printf("[info] POSTing '%s' (%s) to '%s'", node.Hostname(),
- node.ID(), options.ProvisionURL)
- }
+ log.Debugf("POSTing '%s' (%s) to '%s'", node.Hostname(), node.ID(), options.ProvisionURL)
err = options.Provisioner.Provision(&ProvisionRequest{
Id: node.ID(),
Name: node.Hostname(),
@@ -201,16 +190,16 @@
})
if err != nil {
- log.Printf("[error] unable to provision '%s' (%s) : %s", node.ID, node.Hostname(), err)
+ log.Errorf("unable to provision '%s' (%s) : %s", node.ID, node.Hostname(), err)
}
} else if options.ProvisionTTL > 0 &&
record.Status == Running && time.Since(time.Unix(record.Timestamp, 0)) > options.ProvisionTTL {
- log.Printf("[error] Provisioning of node '%s' has passed provisioning TTL of '%v'",
+ log.Errorf("Provisioning of node '%s' has passed provisioning TTL of '%v'",
node.Hostname(), options.ProvisionTTL)
options.Provisioner.Clear(node.ID())
- } else if options.Verbose {
- log.Printf("[info] Not invoking provisioning for '%s', current state is '%s'", node.Hostname(),
+ } else {
+ log.Debugf("Not invoking provisioning for '%s', current state is '%s'", node.Hostname(),
record.Status.String())
}
@@ -223,9 +212,7 @@
// log this fact unless we are in verbose mode. I suspect it would be
// nice to log it once when the device transitions from a non COMPLETE
// state to a complete state, but that would require keeping state.
- if options.Verbose {
- log.Printf("COMPLETE: %s", node.Hostname())
- }
+ log.Debugf("COMPLETE: %s", node.Hostname())
if options.AlwaysRename {
updateNodeName(client, node, options)
@@ -236,7 +223,7 @@
// Deploy cause a node to deploy
var Deploy = func(client *maas.MAASObject, node MaasNode, options ProcessingOptions) error {
- log.Printf("DEPLOY: %s", node.Hostname())
+ log.Infof("DEPLOY: %s", node.Hostname())
if options.AlwaysRename {
updateNodeName(client, node, options)
@@ -249,7 +236,7 @@
// a parameter default
_, err := myNode.CallPost("start", url.Values{"distro_series": []string{"trusty"}})
if err != nil {
- log.Printf("ERROR: DEPLOY '%s' : '%s'", node.Hostname(), err)
+ log.Errorf("DEPLOY '%s' : '%s'", node.Hostname(), err)
return err
}
}
@@ -258,7 +245,7 @@
// Aquire aquire a machine to a specific operator
var Aquire = func(client *maas.MAASObject, node MaasNode, options ProcessingOptions) error {
- log.Printf("AQUIRE: %s", node.Hostname())
+ log.Infof("AQUIRE: %s", node.Hostname())
nodesObj := client.GetSubObject("nodes")
if options.AlwaysRename {
@@ -352,7 +339,7 @@
_, err = nodesObj.CallPost("acquire",
url.Values{"name": []string{node.Hostname()}})
if err != nil {
- log.Printf("ERROR: AQUIRE '%s' : '%s'", node.Hostname(), err)
+ log.Errorf("AQUIRE '%s' : '%s'", node.Hostname(), err)
return err
}
}
@@ -369,21 +356,21 @@
switch state {
case "on":
// Attempt to turn the node off
- log.Printf("POWER DOWN: %s", node.Hostname())
+ log.Infof("POWER DOWN: %s", node.Hostname())
if !options.Preview {
//POST /api/1.0/nodes/{system_id}/ op=stop
nodesObj := client.GetSubObject("nodes")
nodeObj := nodesObj.GetSubObject(node.ID())
_, err := nodeObj.CallPost("stop", url.Values{"stop_mode": []string{"soft"}})
if err != nil {
- log.Printf("ERROR: Commission '%s' : changing power start to off : '%s'", node.Hostname(), err)
+ log.Errorf("Commission '%s' : changing power start to off : '%s'", node.Hostname(), err)
}
return err
}
break
case "off":
// We are off so move to commissioning
- log.Printf("COMISSION: %s", node.Hostname())
+ log.Infof("COMISSION: %s", node.Hostname())
if !options.Preview {
nodesObj := client.GetSubObject("nodes")
nodeObj := nodesObj.GetSubObject(node.ID())
@@ -392,14 +379,14 @@
_, err := nodeObj.CallPost("commission", url.Values{})
if err != nil {
- log.Printf("ERROR: Commission '%s' : '%s'", node.Hostname(), err)
+ log.Errorf("Commission '%s' : '%s'", node.Hostname(), err)
}
return err
}
break
default:
// We are in a state from which we can't move forward.
- log.Printf("[warn]: %s has invalid power state '%s'", node.Hostname(), state)
+ log.Warningf("%s has invalid power state '%s'", node.Hostname(), state)
// If a power helper script is set, we have an unknown power state, and
// we have not power type then attempt to use the helper script to discover
@@ -410,14 +397,14 @@
node.MACs()...)...)
stdout, err := cmd.Output()
if err != nil {
- log.Printf("[error] Failed while executing power helper script '%s' : %s",
+ log.Errorf("Failed while executing power helper script '%s' : %s",
options.PowerHelper, err)
return err
}
power := Power{}
err = json.Unmarshal(stdout, &power)
if err != nil {
- log.Printf("[error] Failed to parse output of power helper script '%s' : %s",
+ log.Errorf("Failed to parse output of power helper script '%s' : %s",
options.PowerHelper, err)
return err
}
@@ -430,7 +417,7 @@
}
node.UpdatePowerParameters(power.Name, params)
default:
- log.Printf("[warn] Unsupported power type discovered '%s'", power.Name)
+ log.Warningf("Unsupported power type discovered '%s'", power.Name)
}
}
break
@@ -440,32 +427,32 @@
// Wait a do nothing state, while work is being done
var Wait = func(client *maas.MAASObject, node MaasNode, options ProcessingOptions) error {
- log.Printf("WAIT: %s", node.Hostname())
+ log.Infof("WAIT: %s", node.Hostname())
return nil
}
// Fail a state from which we cannot, currently, automatically recover
var Fail = func(client *maas.MAASObject, node MaasNode, options ProcessingOptions) error {
- log.Printf("FAIL: %s", node.Hostname())
+ log.Infof("FAIL: %s", node.Hostname())
return nil
}
// AdminState an administrative state from which we should make no automatic transition
var AdminState = func(client *maas.MAASObject, node MaasNode, options ProcessingOptions) error {
- log.Printf("ADMIN: %s", node.Hostname())
+ log.Infof("ADMIN: %s", node.Hostname())
return nil
}
func findActions(target string, current string) ([]Action, error) {
targets, ok := Transitions[target]
if !ok {
- log.Printf("[warn] unable to find transitions to target state '%s'", target)
+ log.Warningf("unable to find transitions to target state '%s'", target)
return nil, fmt.Errorf("Could not find transition to target state '%s'", target)
}
actions, ok := targets[current]
if !ok {
- log.Printf("[warn] unable to find transition from current state '%s' to target state '%s'",
+ log.Warningf("unable to find transition from current state '%s' to target state '%s'",
current, target)
return nil, fmt.Errorf("Could not find transition from current state '%s' to target state '%s'",
current, target)
@@ -479,7 +466,7 @@
var err error
for _, action := range actions {
if err = action(client, node, options); err != nil {
- log.Printf("[error] Error while processing action for node '%s' : %s",
+ log.Errorf("Error while processing action for node '%s' : %s",
node.Hostname(), err)
break
}
@@ -554,16 +541,12 @@
errors[i] = nil
}
} else {
- if options.Verbose {
- log.Printf("[info] ignoring node '%s' as its zone '%s' didn't match include zone name filter '%v'",
- node.Hostname(), node.Zone(), options.Filter.Zones.Include)
- }
+ log.Debugf("ignoring node '%s' as its zone '%s' didn't match include zone name filter '%v'",
+ node.Hostname(), node.Zone(), options.Filter.Zones.Include)
}
} else {
- if options.Verbose {
- log.Printf("[info] ignoring node '%s' as it didn't match include hostname filter '%v'",
- node.Hostname(), options.Filter.Hosts.Include)
- }
+ log.Debugf("ignoring node '%s' as it didn't match include hostname filter '%v'",
+ node.Hostname(), options.Filter.Hosts.Include)
}
}
return errors