resilien
/
terraform
2
0
Fork 0
Code Issues Pull Requests Projects Releases Wiki Activity

Merge pull request #26632 from hashicorp/jbardin/logging 

Structured logging
This commit is contained in:
James Bardin 2020-10-20 09:23:57 -04:00 committed by GitHub
parent 18f676ea11 a3a20e0396
commit d9ac57ffae
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
32 changed files with 102 additions and 614 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

13
backend/local/local_test.go
View File

@ -2,24 +2,13 @@ package local
import (
"flag"
"io/ioutil"
"log"
"os"
"testing"
"github.com/hashicorp/terraform/helper/logging"
_ "github.com/hashicorp/terraform/internal/logging"
)
func TestMain(m *testing.M) {
flag.Parse()
if testing.Verbose() {
// if we're verbose, use the logging requested by TF_LOG
logging.SetOutput()
} else {
// otherwise silence all logs
log.SetOutput(ioutil.Discard)
}
os.Exit(m.Run())
}

2
backend/remote-state/azure/sender.go
View File

@ -6,7 +6,7 @@ import (
"net/http/httputil"
"github.com/Azure/go-autorest/autorest"
"github.com/hashicorp/terraform/helper/logging"
"github.com/hashicorp/terraform/internal/logging"
)
func buildSender() autorest.Sender {

14
backend/remote-state/inmem/backend_test.go
View File

@ -2,30 +2,20 @@ package inmem
import (
"flag"
"io/ioutil"
"log"
"os"
"testing"
"github.com/hashicorp/hcl/v2"
"github.com/hashicorp/terraform/backend"
"github.com/hashicorp/terraform/helper/logging"
statespkg "github.com/hashicorp/terraform/states"
"github.com/hashicorp/terraform/states/remote"
_ "github.com/hashicorp/terraform/internal/logging"
)
func TestMain(m *testing.M) {
flag.Parse()
if testing.Verbose() {
// if we're verbose, use the logging requested by TF_LOG
logging.SetOutput()
} else {
// otherwise silence all logs
log.SetOutput(ioutil.Discard)
}
os.Exit(m.Run())
}

2
backend/remote-state/s3/backend.go
View File

@ -12,8 +12,8 @@ import (
"github.com/aws/aws-sdk-go/service/s3"
awsbase "github.com/hashicorp/aws-sdk-go-base"
"github.com/hashicorp/terraform/backend"
"github.com/hashicorp/terraform/helper/logging"
"github.com/hashicorp/terraform/helper/schema"
"github.com/hashicorp/terraform/internal/logging"
"github.com/hashicorp/terraform/version"
)

12
backend/remote/remote_test.go
View File

@ -2,25 +2,15 @@ package remote
import (
"flag"
"io/ioutil"
"log"
"os"
"testing"
"github.com/hashicorp/terraform/helper/logging"
_ "github.com/hashicorp/terraform/internal/logging"
)
func TestMain(m *testing.M) {
flag.Parse()
if testing.Verbose() {
// if we're verbose, use the logging requested by TF_LOG
logging.SetOutput()
} else {
// otherwise silence all logs
log.SetOutput(ioutil.Discard)
}
// Make sure TF_FORCE_LOCAL_BACKEND is unset
os.Unsetenv("TF_FORCE_LOCAL_BACKEND")

13
command/command_test.go
View File

@ -5,11 +5,9 @@ import (
"crypto/md5"
"encoding/base64"
"encoding/json"
"flag"
"fmt"
"io"
"io/ioutil"
"log"
"net/http"
"net/http/httptest"
"os"
@ -29,7 +27,6 @@ import (
"github.com/hashicorp/terraform/configs"
"github.com/hashicorp/terraform/configs/configload"
"github.com/hashicorp/terraform/configs/configschema"
"github.com/hashicorp/terraform/helper/logging"
"github.com/hashicorp/terraform/internal/copy"
"github.com/hashicorp/terraform/plans"
"github.com/hashicorp/terraform/plans/planfile"
@ -44,6 +41,7 @@ import (
backendInit "github.com/hashicorp/terraform/backend/init"
backendLocal "github.com/hashicorp/terraform/backend/local"
_ "github.com/hashicorp/terraform/internal/logging"
)
// These are the directories for our test data and fixtures.
@ -83,15 +81,6 @@ func init() {
func TestMain(m *testing.M) {
defer os.RemoveAll(testingDir)
flag.Parse()
if testing.Verbose() {
// if we're verbose, use the logging requested by TF_LOG
logging.SetOutput()
} else {
// otherwise silence all logs
log.SetOutput(ioutil.Discard)
}
// Make sure backend init is initialized, since our tests tend to assume it.
backendInit.Init(nil)

17
command/meta_providers.go
View File

@ -8,13 +8,13 @@ import (
"path/filepath"
"strings"
hclog "github.com/hashicorp/go-hclog"
"github.com/hashicorp/go-multierror"
plugin "github.com/hashicorp/go-plugin"
"github.com/hashicorp/terraform/addrs"
terraformProvider "github.com/hashicorp/terraform/builtin/providers/terraform"
"github.com/hashicorp/terraform/internal/getproviders"
"github.com/hashicorp/terraform/internal/logging"
"github.com/hashicorp/terraform/internal/providercache"
tfplugin "github.com/hashicorp/terraform/plugin"
"github.com/hashicorp/terraform/providers"
@ -328,12 +328,6 @@ func (m *Meta) internalProviders() map[string]providers.Factory {
// providers.Interface against it.
func providerFactory(meta *providercache.CachedProvider) providers.Factory {
return func() (providers.Interface, error) {
logger := hclog.New(&hclog.LoggerOptions{
Name: "plugin",
Level: hclog.Trace,
Output: os.Stderr,
})
execFile, err := meta.ExecutableFile()
if err != nil {
return nil, err
@ -341,7 +335,7 @@ func providerFactory(meta *providercache.CachedProvider) providers.Factory {
config := &plugin.ClientConfig{
HandshakeConfig: tfplugin.Handshake,
Logger: logger,
Logger: logging.NewHCLogger("plugin"),
AllowedProtocols: []plugin.Protocol{plugin.ProtocolGRPC},
Managed: true,
Cmd: exec.Command(execFile),
@ -386,15 +380,10 @@ func devOverrideProviderFactory(provider addrs.Provider, localDir getproviders.P
// running, and implements providers.Interface against it.
func unmanagedProviderFactory(provider addrs.Provider, reattach *plugin.ReattachConfig) providers.Factory {
return func() (providers.Interface, error) {
logger := hclog.New(&hclog.LoggerOptions{
Name: "unmanaged-plugin",
Level: hclog.Trace,
Output: os.Stderr,
})
config := &plugin.ClientConfig{
HandshakeConfig: tfplugin.Handshake,
Logger: logger,
Logger: logging.NewHCLogger("unmanaged-plugin"),
AllowedProtocols: []plugin.Protocol{plugin.ProtocolGRPC},
Managed: false,
Reattach: reattach,

14
command/plugins.go
View File

@ -14,6 +14,7 @@ import (
plugin "github.com/hashicorp/go-plugin"
"github.com/kardianos/osext"
"github.com/hashicorp/terraform/internal/logging"
tfplugin "github.com/hashicorp/terraform/plugin"
"github.com/hashicorp/terraform/plugin/discovery"
"github.com/hashicorp/terraform/provisioners"
@ -167,6 +168,8 @@ func internalPluginClient(kind, name string) (*plugin.Client, error) {
Managed: true,
VersionedPlugins: tfplugin.VersionedPlugins,
AllowedProtocols: []plugin.Protocol{plugin.ProtocolGRPC},
AutoMTLS: enableProviderAutoMTLS,
Logger: logging.NewHCLogger("plugin"),
}
return plugin.NewClient(cfg), nil
@ -174,7 +177,16 @@ func internalPluginClient(kind, name string) (*plugin.Client, error) {
func provisionerFactory(meta discovery.PluginMeta) terraform.ProvisionerFactory {
return func() (provisioners.Interface, error) {
client := tfplugin.Client(meta)
cfg := &plugin.ClientConfig{
Cmd: exec.Command(meta.Path),
HandshakeConfig: tfplugin.Handshake,
VersionedPlugins: tfplugin.VersionedPlugins,
Managed: true,
Logger: logging.NewHCLogger("provisioner"),
AllowedProtocols: []plugin.Protocol{plugin.ProtocolGRPC},
AutoMTLS: enableProviderAutoMTLS,
}
client := plugin.NewClient(cfg)
return newProvisionerClient(client)
}
}

12
dag/dag_test.go
View File

@ -3,8 +3,6 @@ package dag
import (
"flag"
"fmt"
"io/ioutil"
"log"
"os"
"reflect"
"strconv"
@ -14,19 +12,11 @@ import (
"github.com/hashicorp/terraform/tfdiags"
"github.com/hashicorp/terraform/helper/logging"
_ "github.com/hashicorp/terraform/internal/logging"
)
func TestMain(m *testing.M) {
flag.Parse()
if testing.Verbose() {
// if we're verbose, use the logging requested by TF_LOG
logging.SetOutput()
} else {
// otherwise silence all logs
log.SetOutput(ioutil.Discard)
}
os.Exit(m.Run())
}

1
dag/walk.go
View File

@ -383,7 +383,6 @@ func (w *Walker) walkVertex(v Vertex, info *walkerVertex) {
var diags tfdiags.Diagnostics
var upstreamFailed bool
if depsSuccess {
log.Printf("[TRACE] dag/walk: visiting %q", VertexName(v))
diags = w.Callback(v)
} else {
log.Printf("[TRACE] dag/walk: upstream of %q errored, so skipping", VertexName(v))

2
go.mod
View File

@ -55,7 +55,7 @@ require (
github.com/hashicorp/go-checkpoint v0.5.0
github.com/hashicorp/go-cleanhttp v0.5.1
github.com/hashicorp/go-getter v1.4.2-0.20200106182914-9813cbd4eb02
github.com/hashicorp/go-hclog v0.9.2
github.com/hashicorp/go-hclog v0.14.1
github.com/hashicorp/go-immutable-radix v0.0.0-20180129170900-7f3cd4390caa // indirect
github.com/hashicorp/go-msgpack v0.5.4 // indirect
github.com/hashicorp/go-multierror v1.0.0

12
go.sum
View File

@ -238,8 +238,8 @@ github.com/hashicorp/go-cleanhttp v0.5.1/go.mod h1:JpRdi6/HCYpAwUzNwuwqhbovhLtng
github.com/hashicorp/go-getter v1.4.2-0.20200106182914-9813cbd4eb02 h1:l1KB3bHVdvegcIf5upQ5mjcHjs2qsWnKh4Yr9xgIuu8=
github.com/hashicorp/go-getter v1.4.2-0.20200106182914-9813cbd4eb02/go.mod h1:7qxyCd8rBfcShwsvxgIguu4KbS3l8bUCwg2Umn7RjeY=
github.com/hashicorp/go-hclog v0.0.0-20180709165350-ff2cf002a8dd/go.mod h1:9bjs9uLqI8l75knNv3lV1kA55veR+WUPSiKIWcQHudI=
github.com/hashicorp/go-hclog v0.9.2 h1:CG6TE5H9/JXsFWJCfoIVpKFIkFe6ysEuHirp4DxCsHI=
github.com/hashicorp/go-hclog v0.9.2/go.mod h1:5CU+agLiy3J7N7QjHK5d05KxGsuXiQLrjA0H7acj2lQ=
github.com/hashicorp/go-hclog v0.14.1 h1:nQcJDQwIAGnmoUWp8ubocEX40cCml/17YkF6csQLReU=
github.com/hashicorp/go-hclog v0.14.1/go.mod h1:whpDNt7SSdeAju8AWKIWsul05p54N/39EeqMAyrmvFQ=
github.com/hashicorp/go-immutable-radix v0.0.0-20180129170900-7f3cd4390caa h1:0nA8i+6Rwqaq9xlpmVxxTwk6rxiEhX+E6Wh4vPNHiS8=
github.com/hashicorp/go-immutable-radix v0.0.0-20180129170900-7f3cd4390caa/go.mod h1:6ij3Z20p+OhOkCSrA0gImAWoHYQRGbnlcuk6XYTiaRw=
github.com/hashicorp/go-msgpack v0.5.4 h1:SFT72YqIkOcLdWJUYcriVX7hbrZpwc/f7h8aW2NUqrA=
@ -343,14 +343,13 @@ github.com/masterzen/simplexml v0.0.0-20190410153822-31eea3082786/go.mod h1:kCEb
github.com/masterzen/winrm v0.0.0-20200615185753-c42b5136ff88 h1:cxuVcCvCLD9yYDbRCWw0jSgh1oT6P6mv3aJDKK5o7X4=
github.com/masterzen/winrm v0.0.0-20200615185753-c42b5136ff88/go.mod h1:a2HXwefeat3evJHxFXSayvRHpYEPJYtErl4uIzfaUqY=
github.com/mattn/go-colorable v0.0.9/go.mod h1:9vuHe8Xs5qXnSaW/c/ABM9alt+Vo+STaOChaDxuIBZU=
github.com/mattn/go-colorable v0.1.1 h1:G1f5SKeVxmagw/IyvzvtZE4Gybcc4Tr1tf7I8z0XgOg=
github.com/mattn/go-colorable v0.1.1/go.mod h1:FuOcm+DKB9mbwrcAfNl7/TZVBZ6rcnceauSikq3lYCQ=
github.com/mattn/go-colorable v0.1.4/go.mod h1:U0ppj6V5qS13XJ6of8GYAs25YV2eR4EVcfRqFIhoBtE=
github.com/mattn/go-colorable v0.1.8 h1:c1ghPdyEDarC70ftn0y+A/Ee++9zz8ljHG1b13eJ0s8=
github.com/mattn/go-colorable v0.1.8/go.mod h1:u6P/XSegPjTcexA+o6vUJrdnUu04hMope9wVRipJSqc=
github.com/mattn/go-isatty v0.0.3/go.mod h1:M+lRXTBqGeGNdLjl/ufCoiOlB5xdOkqRJdNxMWT7Zi4=
github.com/mattn/go-isatty v0.0.4/go.mod h1:M+lRXTBqGeGNdLjl/ufCoiOlB5xdOkqRJdNxMWT7Zi4=
github.com/mattn/go-isatty v0.0.5 h1:tHXDdz1cpzGaovsTB+TVB8q90WEokoVmfMqoVcrLUgw=
github.com/mattn/go-isatty v0.0.5/go.mod h1:Iq45c/XA43vh69/j3iqttzPXn0bhXyGjM0Hdxcsrc5s=
github.com/mattn/go-isatty v0.0.8/go.mod h1:Iq45c/XA43vh69/j3iqttzPXn0bhXyGjM0Hdxcsrc5s=
github.com/mattn/go-isatty v0.0.10/go.mod h1:qgIWMr58cqv1PHHyhnkY9lrL7etaEgOFcMEpPG5Rm84=
github.com/mattn/go-isatty v0.0.12 h1:wuysRhFDzyxgEmMf5xjvJ2M9dZoWAXNNr5LSBS7uHXY=
github.com/mattn/go-isatty v0.0.12/go.mod h1:cbi8OIDigv2wuxKPP5vlRcQ1OAZbq2CE4Kysco4FUpU=
github.com/mattn/go-runewidth v0.0.4/go.mod h1:LwmH8dsx7+W8Uxz3IHJYH5QSwggIsqBzpuz5H//U1FU=
@ -590,6 +589,7 @@ golang.org/x/sys v0.0.0-20190509141414-a5b02f93d862/go.mod h1:h1NjWce9XRLGQEsW7w
golang.org/x/sys v0.0.0-20190606165138-5da285871e9c/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs=
golang.org/x/sys v0.0.0-20190616124812-15dcb6c0061f/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs=
golang.org/x/sys v0.0.0-20190624142023-c5567b49c5d0/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs=
golang.org/x/sys v0.0.0-20191008105621-543471e840be/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs=
golang.org/x/sys v0.0.0-20191128015809-6d18c012aee9 h1:ZBzSG/7F4eNKz2L3GE9o300RX0Az1Bw5HF7PDraD+qU=
golang.org/x/sys v0.0.0-20191128015809-6d18c012aee9/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs=
golang.org/x/sys v0.0.0-20200116001909-b77594299b42/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs=

159
helper/logging/level.go
View File

@ -1,159 +0,0 @@
package logging
import (
"bytes"
"io"
"sync"
)
// LogLevel is a special string, conventionally written all in uppercase, that
// can be used to mark a log line for filtering and to specify filtering
// levels in the LevelFilter type.
type LogLevel string
// LevelFilter is an io.Writer that can be used with a logger that
// will attempt to filter out log messages that aren't at least a certain
// level.
//
// This filtering is HEURISTIC-BASED, and so will not be 100% reliable. The
// assumptions it makes are:
//
// - Individual log messages are never split across multiple calls to the
// Write method.
//
// - Messages that carry levels are marked by a sequence starting with "[",
// then the level name string, and then "]". Any message without a sequence
// like this is an un-levelled message, and is not subject to filtering.
//
// - Each \n-delimited line in a write is a separate log message, unless a
// line starts with at least one space in which case it is interpreted
// as a continuation of the previous line.
//
// - If a log line starts with a non-whitespace character that isn't a digit
// then it's recognized as a degenerate continuation, because "real" log
// lines should start with a date/time and thus always have a leading
// digit. (This also cleans up after some situations where the assumptuion
// that messages arrive atomically aren't met, which is sadly sometimes
// true for longer messages that trip over some buffering behavior in
// panicwrap.)
//
// Because logging is a cross-cutting concern and not fully under the control
// of Terraform itself, there will certainly be cases where the above
// heuristics will fail. For example, it is likely that LevelFilter will
// occasionally misinterpret a continuation line as a new message because the
// code generating it doesn't know about our indentation convention.
//
// Our goal here is just to make a best effort to reduce the log volume,
// accepting that the results will not be 100% correct.
//
// Logging calls within Terraform Core should follow the above conventions so
// that the log output is broadly correct, however.
//
// Once the filter is in use somewhere, it is not safe to modify
// the structure.
type LevelFilter struct {
// Levels is the list of log levels, in increasing order of
// severity. Example might be: {"DEBUG", "WARN", "ERROR"}.
Levels []LogLevel
// MinLevel is the minimum level allowed through
MinLevel LogLevel
// The underlying io.Writer where log messages that pass the filter
// will be set.
Writer io.Writer
badLevels map[LogLevel]struct{}
show bool
once sync.Once
}
// Check will check a given line if it would be included in the level
// filter.
func (f *LevelFilter) Check(line []byte) bool {
f.once.Do(f.init)
// Check for a log level
var level LogLevel
x := bytes.IndexByte(line, '[')
if x >= 0 {
y := bytes.IndexByte(line[x:], ']')
if y >= 0 {
level = LogLevel(line[x+1 : x+y])
}
}
//return level == ""
_, ok := f.badLevels[level]
return !ok
}
// Write is a specialized implementation of io.Writer suitable for being
// the output of a logger from the "log" package.
//
// This Writer implementation assumes that it will only recieve byte slices
// containing one or more entire lines of log output, each one terminated by
// a newline. This is compatible with the behavior of the "log" package
// directly, and is also tolerant of intermediaries that might buffer multiple
// separate writes together, as long as no individual log line is ever
// split into multiple slices.
//
// Behavior is undefined if any log line is split across multiple writes or
// written without a trailing '\n' delimiter.
func (f *LevelFilter) Write(p []byte) (n int, err error) {
for len(p) > 0 {
// Split at the first \n, inclusive
idx := bytes.IndexByte(p, '\n')
if idx == -1 {
// Invalid, undelimited write. We'll tolerate it assuming that
// our assumptions are being violated, but the results may be
// non-ideal.
idx = len(p) - 1
break
}
var l []byte
l, p = p[:idx+1], p[idx+1:]
// Lines starting with characters other than decimal digits (including
// whitespace) are assumed to be continuations lines. This is an
// imprecise heuristic, but experimentally it seems to generate
// "good enough" results from Terraform Core's own logging. Its mileage
// may vary with output from other systems.
if l[0] >= '0' && l[0] <= '9' {
f.show = f.Check(l)
}
if f.show {
_, err = f.Writer.Write(l)
if err != nil {
// Technically it's not correct to say we've written the whole
// buffer, but for our purposes here it's good enough as we're
// only implementing io.Writer enough to satisfy logging
// use-cases.
return len(p), err
}
}
}
// We always behave as if we wrote the whole of the buffer, even if
// we actually skipped some lines. We're only implementiong io.Writer
// enough to satisfy logging use-cases.
return len(p), nil
}
// SetMinLevel is used to update the minimum log level
func (f *LevelFilter) SetMinLevel(min LogLevel) {
f.MinLevel = min
f.init()
}
func (f *LevelFilter) init() {
badLevels := make(map[LogLevel]struct{})
for _, level := range f.Levels {
if level == f.MinLevel {
break
}
badLevels[level] = struct{}{}
}
f.badLevels = badLevels
f.show = true
}

93
helper/logging/level_test.go
View File

@ -1,93 +0,0 @@
package logging
import (
"bytes"
"io"
"log"
"testing"
)
func TestLevelFilter_impl(t *testing.T) {
var _ io.Writer = new(LevelFilter)
}
func TestLevelFilter(t *testing.T) {
buf := new(bytes.Buffer)
filter := &LevelFilter{
Levels: []LogLevel{"DEBUG", "WARN", "ERROR"},
MinLevel: "WARN",
Writer: buf,
}
logger := log.New(filter, "", 0)
logger.Print("2019/01/01 00:00:00 [WARN] foo")
logger.Println("2019/01/01 00:00:00 [ERROR] bar\n2019/01/01 00:00:00 [DEBUG] buzz")
logger.Println("2019/01/01 00:00:00 [DEBUG] baz\n continuation\n2019/01/01 00:00:00 [WARN] buzz\n more\n2019/01/01 00:00:00 [DEBUG] fizz")
result := buf.String()
expected := "2019/01/01 00:00:00 [WARN] foo\n2019/01/01 00:00:00 [ERROR] bar\n2019/01/01 00:00:00 [WARN] buzz\n more\n"
if result != expected {
t.Fatalf("wrong result\ngot:\n%s\nwant:\n%s", result, expected)
}
}
func TestLevelFilterCheck(t *testing.T) {
filter := &LevelFilter{
Levels: []LogLevel{"DEBUG", "WARN", "ERROR"},
MinLevel: "WARN",
Writer: nil,
}
testCases := []struct {
line string
check bool
}{
{"[WARN] foo\n", true},
{"[ERROR] bar\n", true},
{"[DEBUG] baz\n", false},
{"[WARN] buzz\n", true},
}
for _, testCase := range testCases {
result := filter.Check([]byte(testCase.line))
if result != testCase.check {
t.Errorf("Fail: %s", testCase.line)
}
}
}
func TestLevelFilter_SetMinLevel(t *testing.T) {
filter := &LevelFilter{
Levels: []LogLevel{"DEBUG", "WARN", "ERROR"},
MinLevel: "ERROR",
Writer: nil,
}
testCases := []struct {
line string
checkBefore bool
checkAfter bool
}{
{"[WARN] foo\n", false, true},
{"[ERROR] bar\n", true, true},
{"[DEBUG] baz\n", false, false},
{"[WARN] buzz\n", false, true},
}
for _, testCase := range testCases {
result := filter.Check([]byte(testCase.line))
if result != testCase.checkBefore {
t.Errorf("Fail: %s", testCase.line)
}
}
// Update the minimum level to WARN
filter.SetMinLevel("WARN")
for _, testCase := range testCases {
result := filter.Check([]byte(testCase.line))
if result != testCase.checkAfter {
t.Errorf("Fail: %s", testCase.line)
}
}
}

70
helper/logging/transport.go
View File

@ -1,70 +0,0 @@
package logging
import (
"bytes"
"encoding/json"
"log"
"net/http"
"net/http/httputil"
"strings"
)
type transport struct {
name string
transport http.RoundTripper
}
func (t *transport) RoundTrip(req *http.Request) (*http.Response, error) {
if IsDebugOrHigher() {
reqData, err := httputil.DumpRequestOut(req, true)
if err == nil {
log.Printf("[DEBUG] "+logReqMsg, t.name, prettyPrintJsonLines(reqData))
} else {
log.Printf("[ERROR] %s API Request error: %#v", t.name, err)
}
}
resp, err := t.transport.RoundTrip(req)
if err != nil {
return resp, err
}
if IsDebugOrHigher() {
respData, err := httputil.DumpResponse(resp, true)
if err == nil {
log.Printf("[DEBUG] "+logRespMsg, t.name, prettyPrintJsonLines(respData))
} else {
log.Printf("[ERROR] %s API Response error: %#v", t.name, err)
}
}
return resp, nil
}
func NewTransport(name string, t http.RoundTripper) *transport {
return &transport{name, t}
}
// prettyPrintJsonLines iterates through a []byte line-by-line,
// transforming any lines that are complete json into pretty-printed json.
func prettyPrintJsonLines(b []byte) string {
parts := strings.Split(string(b), "\n")
for i, p := range parts {
if b := []byte(p); json.Valid(b) {
var out bytes.Buffer
json.Indent(&out, b, "", " ")
parts[i] = out.String()
}
}
return strings.Join(parts, "\n")
}
const logReqMsg = `%s API Request Details:
---[ REQUEST ]---------------------------------------
%s
-----------------------------------------------------`
const logRespMsg = `%s API Response Details:
---[ RESPONSE ]--------------------------------------
%s
-----------------------------------------------------`

51
helper/resource/testing.go
View File

@ -4,7 +4,6 @@ import (
"bytes"
"flag"
"fmt"
"io"
"io/ioutil"
"log"
"os"
@ -12,7 +11,6 @@ import (
"reflect"
"regexp"
"strings"
"syscall"
"testing"
"github.com/davecgh/go-spew/spew"
@ -24,12 +22,13 @@ import (
"github.com/hashicorp/terraform/command/format"
"github.com/hashicorp/terraform/configs"
"github.com/hashicorp/terraform/configs/configload"
"github.com/hashicorp/terraform/helper/logging"
"github.com/hashicorp/terraform/internal/initwd"
"github.com/hashicorp/terraform/providers"
"github.com/hashicorp/terraform/states"
"github.com/hashicorp/terraform/terraform"
"github.com/hashicorp/terraform/tfdiags"
_ "github.com/hashicorp/terraform/internal/logging"
)
// flagSweep is a flag available when running tests on the command line. It
@ -392,46 +391,6 @@ type TestStep struct {
// Set to a file mask in sprintf format where %s is test name
const EnvLogPathMask = "TF_LOG_PATH_MASK"
func LogOutput(t TestT) (logOutput io.Writer, err error) {
logOutput = ioutil.Discard
logLevel := logging.CurrentLogLevel()
if logLevel == "" {
return
}
logOutput = os.Stderr
if logPath := os.Getenv(logging.EnvLogFile); logPath != "" {
var err error
logOutput, err = os.OpenFile(logPath, syscall.O_CREAT|syscall.O_RDWR|syscall.O_APPEND, 0666)
if err != nil {
return nil, err
}
}
if logPathMask := os.Getenv(EnvLogPathMask); logPathMask != "" {
// Escape special characters which may appear if we have subtests
testName := strings.Replace(t.Name(), "/", "__", -1)
logPath := fmt.Sprintf(logPathMask, testName)
var err error
logOutput, err = os.OpenFile(logPath, syscall.O_CREAT|syscall.O_RDWR|syscall.O_APPEND, 0666)
if err != nil {
return nil, err
}
}
// This was the default since the beginning
logOutput = &logging.LevelFilter{
Levels: logging.ValidLevels,
MinLevel: logging.LogLevel(logLevel),
Writer: logOutput,
}
return
}
// ParallelTest performs an acceptance test on a resource, allowing concurrency
// with other ParallelTest.
//
@ -464,12 +423,6 @@ func Test(t TestT, c TestCase) {
return
}
logWriter, err := LogOutput(t)
if err != nil {
t.Error(fmt.Errorf("error setting up logging: %s", err))
}
log.SetOutput(logWriter)
// We require verbose mode so that the user knows what is going on.
if !testTesting && !testing.Verbose() && !c.IsUnitTest {
t.Fatal("Acceptance tests must be run with the -v flag on tests")

8
internal/getproviders/http_mirror_source.go
View File

@ -18,8 +18,8 @@ import (
"golang.org/x/net/idna"
"github.com/hashicorp/terraform/addrs"
"github.com/hashicorp/terraform/helper/logging"
"github.com/hashicorp/terraform/httpclient"
"github.com/hashicorp/terraform/internal/logging"
"github.com/hashicorp/terraform/version"
)
@ -68,11 +68,7 @@ func newHTTPMirrorSourceWithHTTPClient(baseURL *url.URL, creds svcauth.Credentia
retryableClient.RequestLogHook = requestLogHook
retryableClient.ErrorHandler = maxRetryErrorHandler
logOutput, err := logging.LogOutput()
if err != nil {
log.Printf("[WARN] Failed to set up provider HTTP mirror logger, so continuing without client logging: %s", err)
}
retryableClient.Logger = log.New(logOutput, "", log.Flags())
retryableClient.Logger = log.New(logging.LogOutput(), "", log.Flags())
return &HTTPMirrorSource{
baseURL: baseURL,

9
internal/getproviders/registry_client.go
View File

@ -21,8 +21,8 @@ import (
svcauth "github.com/hashicorp/terraform-svchost/auth"
"github.com/hashicorp/terraform/addrs"
"github.com/hashicorp/terraform/helper/logging"
"github.com/hashicorp/terraform/httpclient"
"github.com/hashicorp/terraform/internal/logging"
"github.com/hashicorp/terraform/version"
)
@ -77,12 +77,7 @@ func newRegistryClient(baseURL *url.URL, creds svcauth.HostCredentials) *registr
retryableClient.RequestLogHook = requestLogHook
retryableClient.ErrorHandler = maxRetryErrorHandler
logOutput, err := logging.LogOutput()
if err != nil {
log.Printf("[WARN] Failed to set up registry client logger, "+
"continuing without client logging: %s", err)
}
retryableClient.Logger = log.New(logOutput, "", log.Flags())
retryableClient.Logger = log.New(logging.LogOutput(), "", log.Flags())
return &registryClient{
baseURL: baseURL,

12
internal/initwd/module_install_test.go
View File

@ -4,7 +4,6 @@ import (
"flag"
"fmt"
"io/ioutil"
"log"
"os"
"path/filepath"
"strings"
@ -14,22 +13,15 @@ import (
version "github.com/hashicorp/go-version"
"github.com/hashicorp/terraform/configs"
"github.com/hashicorp/terraform/configs/configload"
"github.com/hashicorp/terraform/helper/logging"
"github.com/hashicorp/terraform/internal/copy"
"github.com/hashicorp/terraform/registry"
"github.com/hashicorp/terraform/tfdiags"
_ "github.com/hashicorp/terraform/internal/logging"
)
func TestMain(m *testing.M) {
flag.Parse()
if testing.Verbose() {
// if we're verbose, use the logging requested by TF_LOG
logging.SetOutput()
} else {
// otherwise silence all logs
log.SetOutput(ioutil.Discard)
}
os.Exit(m.Run())
}

0
helper/logging/indent.go → internal/logging/indent.go
View File

0
helper/logging/indent_test.go → internal/logging/indent_test.go
View File

89
helper/logging/logging.go → internal/logging/logging.go
View File

@ -1,12 +1,15 @@
package logging
import (
"fmt"
"io"
"io/ioutil"
"log"
"os"
"strings"
"syscall"
"github.com/hashicorp/go-hclog"
)
// These are the environmental variables that determine if we log, and if
@ -17,70 +20,68 @@ const (
)
// ValidLevels are the log level names that Terraform recognizes.
var ValidLevels = []LogLevel{"TRACE", "DEBUG", "INFO", "WARN", "ERROR"}
var ValidLevels = []string{"TRACE", "DEBUG", "INFO", "WARN", "ERROR"}
// LogOutput determines where we should send logs (if anywhere) and the log level.
func LogOutput() (logOutput io.Writer, err error) {
logOutput = ioutil.Discard
// logger is the global hclog logger
var logger hclog.Logger
// logWriter is a global writer for logs, to be used with the std log package
var logWriter io.Writer
func init() {
logger = NewHCLogger("")
logWriter = logger.StandardWriter(&hclog.StandardLoggerOptions{InferLevels: true})
// setup the default std library logger to use our output
log.SetFlags(0)
log.SetPrefix("")
log.SetOutput(logWriter)
}
// LogOutput return the default global log io.Writer
func LogOutput() io.Writer {
return logWriter
}
// HCLogger returns the default global hclog logger
func HCLogger() hclog.Logger {
return logger
}
// NewHCLogger returns a new hclog.Logger instance with the given name
func NewHCLogger(name string) hclog.Logger {
logOutput := io.Writer(os.Stderr)
logLevel := CurrentLogLevel()
if logLevel == "" {
return
logOutput = ioutil.Discard
}
logOutput = os.Stderr
if logPath := os.Getenv(EnvLogFile); logPath != "" {
var err error
logOutput, err = os.OpenFile(logPath, syscall.O_CREAT|syscall.O_RDWR|syscall.O_APPEND, 0666)
f, err := os.OpenFile(logPath, syscall.O_CREAT|syscall.O_RDWR|syscall.O_APPEND, 0666)
if err != nil {
return nil, err
fmt.Fprintf(os.Stderr, "Error opening log file: %v\n", err)
} else {
logOutput = f
}
}
if logLevel == "TRACE" {
// Just pass through logs directly then, without any level filtering at all.
return logOutput, nil
}
// Otherwise we'll use our level filter, which is a heuristic-based
// best effort thing that is not totally reliable but helps to reduce
// the volume of logs in some cases.
logOutput = &LevelFilter{
Levels: ValidLevels,
MinLevel: LogLevel(logLevel),
Writer: logOutput,
}
return logOutput, nil
}
// SetOutput checks for a log destination with LogOutput, and calls
// log.SetOutput with the result. If LogOutput returns nil, SetOutput uses
// ioutil.Discard. Any error from LogOutout is fatal.
func SetOutput() {
out, err := LogOutput()
if err != nil {
log.Fatal(err)
}
if out == nil {
out = ioutil.Discard
}
log.SetOutput(out)
return hclog.New(&hclog.LoggerOptions{
Name: name,
Level: hclog.LevelFromString(logLevel),
Output: logOutput,
})
}
// CurrentLogLevel returns the current log level string based the environment vars
func CurrentLogLevel() string {
envLevel := os.Getenv(EnvLog)
envLevel := strings.ToUpper(os.Getenv(EnvLog))
if envLevel == "" {
return ""
}
logLevel := "TRACE"
if isValidLogLevel(envLevel) {
// allow following for better ux: info, Info or INFO
logLevel = strings.ToUpper(envLevel)
logLevel = envLevel
} else {
log.Printf("[WARN] Invalid log level: %q. Defaulting to level: TRACE. Valid levels are: %+v",
envLevel, ValidLevels)
@ -100,7 +101,7 @@ func IsDebugOrHigher() bool {
func isValidLogLevel(level string) bool {
for _, l := range ValidLevels {
if strings.ToUpper(level) == string(l) {
if level == string(l) {
return true
}
}

13
main.go
View File

@ -18,7 +18,6 @@ import (
"github.com/hashicorp/terraform/addrs"
"github.com/hashicorp/terraform/command/cliconfig"
"github.com/hashicorp/terraform/command/format"
"github.com/hashicorp/terraform/helper/logging"
"github.com/hashicorp/terraform/httpclient"
"github.com/hashicorp/terraform/version"
"github.com/mattn/go-colorable"
@ -37,8 +36,6 @@ const (
)
func main() {
// Override global prefix set by go-dynect during init()
log.SetPrefix("")
os.Exit(realMain())
}
@ -51,13 +48,6 @@ func realMain() int {
}
if !panicwrap.Wrapped(&wrapConfig) {
// Determine where logs should go in general (requested by the user)
logWriter, err := logging.LogOutput()
if err != nil {
fmt.Fprintf(os.Stderr, "Couldn't setup log output: %s", err)
return 1
}
// We always send logs to a temporary file that we use in case
// there is a panic. Otherwise, we delete it.
logTempFile, err := ioutil.TempFile("", "terraform-log")
@ -76,7 +66,7 @@ func realMain() int {
// Create the configuration for panicwrap and wrap our executable
wrapConfig.Handler = panicHandler(logTempFile)
wrapConfig.Writer = io.MultiWriter(logTempFile, logWriter)
wrapConfig.Writer = os.Stderr
wrapConfig.Stdout = outW
wrapConfig.IgnoreSignals = ignoreSignals
wrapConfig.ForwardSignals = forwardSignals
@ -122,7 +112,6 @@ func init() {
func wrappedMain() int {
var err error
log.SetOutput(os.Stderr)
log.Printf(
"[INFO] Terraform version: %s %s %s",
Version, VersionPrerelease, GitCommit)

40
plugin/client.go
View File

@ -1,40 +0,0 @@
package plugin
import (
"os"
"os/exec"
hclog "github.com/hashicorp/go-hclog"
plugin "github.com/hashicorp/go-plugin"
"github.com/hashicorp/terraform/plugin/discovery"
)
// The TF_DISABLE_PLUGIN_TLS environment variable is intended only for use by
// the plugin SDK test framework. We do not recommend Terraform CLI end-users
// set this variable.
var enableAutoMTLS = os.Getenv("TF_DISABLE_PLUGIN_TLS") == ""
// ClientConfig returns a configuration object that can be used to instantiate
// a client for the plugin described by the given metadata.
func ClientConfig(m discovery.PluginMeta) *plugin.ClientConfig {
logger := hclog.New(&hclog.LoggerOptions{
Name: "plugin",
Level: hclog.Trace,
Output: os.Stderr,
})
return &plugin.ClientConfig{
Cmd: exec.Command(m.Path),
HandshakeConfig: Handshake,
VersionedPlugins: VersionedPlugins,
Managed: true,
Logger: logger,
AllowedProtocols: []plugin.Protocol{plugin.ProtocolGRPC},
AutoMTLS: enableAutoMTLS,
}
}
// Client returns a plugin client for the plugin described by the given metadata.
func Client(m discovery.PluginMeta) *plugin.Client {
return plugin.NewClient(ClientConfig(m))
}

8
registry/client.go
View File

@ -16,8 +16,8 @@ import (
"github.com/hashicorp/go-retryablehttp"
svchost "github.com/hashicorp/terraform-svchost"
"github.com/hashicorp/terraform-svchost/disco"
"github.com/hashicorp/terraform/helper/logging"
"github.com/hashicorp/terraform/httpclient"
"github.com/hashicorp/terraform/internal/logging"
"github.com/hashicorp/terraform/registry/regsrc"
"github.com/hashicorp/terraform/registry/response"
"github.com/hashicorp/terraform/version"
@ -87,11 +87,7 @@ func NewClient(services *disco.Disco, client *http.Client) *Client {
retryableClient.RequestLogHook = requestLogHook
retryableClient.ErrorHandler = maxRetryErrorHandler
logOutput, err := logging.LogOutput()
if err != nil {
log.Printf("[WARN] Failed to set up registry client logger, "+
"continuing without client logging: %s", err)
}
logOutput := logging.LogOutput()
retryableClient.Logger = log.New(logOutput, "", log.Flags())
services.Transport = retryableClient.HTTPClient.Transport

14
repl/session_test.go
View File

@ -2,8 +2,6 @@ package repl
import (
"flag"
"io/ioutil"
"log"
"os"
"strings"
"testing"
@ -12,24 +10,16 @@ import (
"github.com/hashicorp/terraform/addrs"
"github.com/hashicorp/terraform/configs/configschema"
"github.com/hashicorp/terraform/helper/logging"
"github.com/hashicorp/terraform/internal/initwd"
"github.com/hashicorp/terraform/providers"
"github.com/hashicorp/terraform/states"
"github.com/hashicorp/terraform/terraform"
_ "github.com/hashicorp/terraform/internal/logging"
)
func TestMain(m *testing.M) {
flag.Parse()
if testing.Verbose() {
// if we're verbose, use the logging requested by TF_LOG
logging.SetOutput()
} else {
// otherwise silence all logs
log.SetOutput(ioutil.Discard)
}
os.Exit(m.Run())
}

11
states/statemgr/statemgr_test.go
View File

@ -4,13 +4,11 @@ import (
"context"
"encoding/json"
"flag"
"io/ioutil"
"log"
"os"
"testing"
"time"
"github.com/hashicorp/terraform/helper/logging"
_ "github.com/hashicorp/terraform/internal/logging"
)
func TestNewLockInfo(t *testing.T) {
@ -91,12 +89,5 @@ func TestLockWithContext(t *testing.T) {
func TestMain(m *testing.M) {
flag.Parse()
if testing.Verbose() {
// if we're verbose, use the logging requested by TF_LOG
logging.SetOutput()
} else {
// otherwise silence all logs
log.SetOutput(ioutil.Discard)
}
os.Exit(m.Run())
}

2
terraform/context.go
View File

@ -18,6 +18,8 @@ import (
"github.com/hashicorp/terraform/states/statefile"
"github.com/hashicorp/terraform/tfdiags"
"github.com/zclconf/go-cty/cty"
_ "github.com/hashicorp/terraform/internal/logging"
)
// InputMode defines what sort of input will be asked for when Input

7
terraform/graph.go
View File

@ -2,6 +2,7 @@ package terraform
import (
"log"
"strings"
"github.com/hashicorp/terraform/tfdiags"
@ -77,7 +78,11 @@ func (g *Graph) walk(walker GraphWalker) tfdiags.Diagnostics {
subDiags := g.walk(walker)
diags = diags.Append(subDiags)
if subDiags.HasErrors() {
log.Printf("[TRACE] vertex %q: dynamic subgraph encountered errors", dag.VertexName(v))
var errs []string
for _, d := range subDiags {
errs = append(errs, d.Description().Summary)
}
log.Printf("[TRACE] vertex %q: dynamic subgraph encountered errors: %s", dag.VertexName(v), strings.Join(errs, ","))
return
}
log.Printf("[TRACE] vertex %q: dynamic subgraph completed successfully", dag.VertexName(v))

2
terraform/graph_builder.go
View File

@ -6,7 +6,7 @@ import (
"strings"
"github.com/hashicorp/terraform/addrs"
"github.com/hashicorp/terraform/helper/logging"
"github.com/hashicorp/terraform/internal/logging"
"github.com/hashicorp/terraform/tfdiags"
)

12
terraform/terraform_test.go
View File

@ -4,7 +4,6 @@ import (
"flag"
"io"
"io/ioutil"
"log"
"os"
"path/filepath"
"strings"
@ -19,13 +18,14 @@ import (
"github.com/hashicorp/terraform/configs"
"github.com/hashicorp/terraform/configs/configload"
"github.com/hashicorp/terraform/helper/experiment"
"github.com/hashicorp/terraform/helper/logging"
"github.com/hashicorp/terraform/internal/initwd"
"github.com/hashicorp/terraform/plans"
"github.com/hashicorp/terraform/providers"
"github.com/hashicorp/terraform/provisioners"
"github.com/hashicorp/terraform/registry"
"github.com/hashicorp/terraform/states"
_ "github.com/hashicorp/terraform/internal/logging"
)
// This is the directory where our test fixtures are.
@ -39,14 +39,6 @@ func TestMain(m *testing.M) {
experiment.Flag(flag.CommandLine)
flag.Parse()
if testing.Verbose() {
// if we're verbose, use the logging requested by TF_LOG
logging.SetOutput()
} else {
// otherwise silence all logs
log.SetOutput(ioutil.Discard)
}
// Make sure shadow operations fail our real tests
contextFailOnShadowError = true

2
terraform/transform.go
View File

@ -4,7 +4,7 @@ import (
"log"
"github.com/hashicorp/terraform/dag"
"github.com/hashicorp/terraform/helper/logging"
"github.com/hashicorp/terraform/internal/logging"
)
// GraphTransformer is the interface that transformers implement. This