Skip to content

Commit b58ea67

Browse files
committedMar 24, 2020
terraform/exec: Allow exposure of Terraform logs
Closes hashicorp#30
1 parent 816872d commit b58ea67

File tree

8 files changed

+206
-90
lines changed

8 files changed

+206
-90
lines changed
 

‎README.md

+17-7
Original file line numberDiff line numberDiff line change
@@ -52,25 +52,35 @@ The language server produces detailed logs which are send to stderr by default.
5252
Most IDEs provide a way of inspecting these logs when server is launched in the standard
5353
stdin/stdout mode.
5454

55-
Logs can also be redirected into a file via `-log-file` option of `serve` command, e.g.
55+
Logs can also be redirected into file using flags of the `serve` command, e.g.
5656

5757
```sh
58-
$ terraform-ls serve -log-file=/tmp/terraform-ls.log
58+
$ terraform-ls serve -log-file=/tmp/terraform-ls-{{pid}}.log -tf-log-file=/tmp/tf-exec-{{lsPid}}-{{args}}.log
5959
```
6060

6161
It is recommended to inspect these logs when reporting bugs.
6262

63-
### Log Path Template
63+
### Log Path Templating
6464

65-
Log path supports template syntax to account for logging from multiple server instances
66-
and/or multiple clients, so that each client and/or server can be logged into a separate file.
65+
Log paths support template syntax. This allows sane separation of logs while accounting for:
6766

68-
Following functions are available
67+
- multiple server instances
68+
- multiple clients
69+
- multiple Terraform executions which may happen in parallel
70+
71+
**`-log-file`** supports the following functions:
6972

7073
- `timestamp` - current timestamp (formatted as [`Time.Unix()`](https://golang.org/pkg/time/#Time.Unix), i.e. the number of seconds elapsed since January 1, 1970 UTC)
71-
- `pid` - process ID of the server
74+
- `pid` - process ID of the language server
7275
- `ppid` - parent process ID (typically editor's or editor plugin's PID)
7376

77+
**`-tf-log-file`** supports the following functions:
78+
79+
- `timestamp` - current timestamp (formatted as [`Time.Unix()`](https://golang.org/pkg/time/#Time.Unix), i.e. the number of seconds elapsed since January 1, 1970 UTC)
80+
- `lsPid` - process ID of the language server
81+
- `lsPpid` - parent process ID of the language server (typically editor's or editor plugin's PID)
82+
- `args` - all arguments passed to `terraform` turned into a safe `-` separated string
83+
7484
The path is interpreted as [Go template](https://golang.org/pkg/text/template/), e.g. `/tmp/terraform-ls-{{timestamp}}.log`.
7585

7686
## Contributing/Development

‎commands/completion_command.go

+2-1
Original file line numberDiff line numberDiff line change
@@ -15,6 +15,7 @@ import (
1515
"github.com/hashicorp/terraform-ls/internal/terraform/exec"
1616
"github.com/hashicorp/terraform-ls/internal/terraform/schema"
1717
"github.com/hashicorp/terraform-ls/langserver/handlers"
18+
"github.com/hashicorp/terraform-ls/logging"
1819
"github.com/mitchellh/cli"
1920
lsp "github.com/sourcegraph/go-lsp"
2021
)
@@ -72,7 +73,7 @@ func (c *CompletionCommand) Run(args []string) int {
7273
}
7374
lspPos := lsp.Position{Line: line, Character: col}
7475

75-
logger := NewLogger(os.Stderr)
76+
logger := logging.NewLogger(os.Stderr)
7677

7778
fs := filesystem.NewFilesystem()
7879
fs.SetLogger(logger)

‎commands/logging.go

-73
This file was deleted.

‎commands/serve_command.go

+22-6
Original file line numberDiff line numberDiff line change
@@ -12,23 +12,28 @@ import (
1212
lsctx "github.com/hashicorp/terraform-ls/internal/context"
1313
"github.com/hashicorp/terraform-ls/langserver"
1414
"github.com/hashicorp/terraform-ls/langserver/handlers"
15+
"github.com/hashicorp/terraform-ls/logging"
1516
"github.com/mitchellh/cli"
1617
)
1718

1819
type ServeCommand struct {
1920
Ui cli.Ui
2021

2122
// flags
22-
port int
23-
logFile string
23+
port int
24+
logFilePath string
25+
tfExecLogPath string
2426
}
2527

2628
func (c *ServeCommand) flags() *flag.FlagSet {
2729
fs := defaultFlagSet("serve")
2830

2931
fs.IntVar(&c.port, "port", 0, "port number to listen on (turns server into TCP mode)")
30-
fs.StringVar(&c.logFile, "log-file", "", "path to file to log into with support "+
32+
fs.StringVar(&c.logFilePath, "log-file", "", "path to a file to log into with support "+
3133
"for variables (e.g. Timestamp, Pid, Ppid) via Go template syntax {{.VarName}}")
34+
fs.StringVar(&c.tfExecLogPath, "tf-log-file", "", "path to a file for Terraform executions"+
35+
" to be logged into with support for variables (e.g. Timestamp, Pid, Ppid) via Go template"+
36+
" syntax {{.VarName}}")
3237

3338
fs.Usage = func() { c.Ui.Error(c.Help()) }
3439

@@ -43,8 +48,8 @@ func (c *ServeCommand) Run(args []string) int {
4348
}
4449

4550
var logger *log.Logger
46-
if c.logFile != "" {
47-
fl, err := NewFileLogger(c.logFile)
51+
if c.logFilePath != "" {
52+
fl, err := logging.NewFileLogger(c.logFilePath)
4853
if err != nil {
4954
c.Ui.Error(fmt.Sprintf("Failed to setup file logging: %s\n", err.Error()))
5055
return 1
@@ -53,13 +58,24 @@ func (c *ServeCommand) Run(args []string) int {
5358

5459
logger = fl.Logger()
5560
} else {
56-
logger = NewLogger(os.Stderr)
61+
logger = logging.NewLogger(os.Stderr)
5762
}
5863

5964
ctx, cancelFunc := lsctx.WithSignalCancel(context.Background(), logger,
6065
syscall.SIGINT, syscall.SIGTERM)
6166
defer cancelFunc()
6267

68+
if c.tfExecLogPath != "" {
69+
err := logging.ValidateExecLogPath(c.tfExecLogPath)
70+
if err != nil {
71+
c.Ui.Error(fmt.Sprintf("Failed to setup logging for Terraform: %s\n", err.Error()))
72+
return 1
73+
}
74+
ctx = lsctx.WithTerraformExecLogPath(c.tfExecLogPath, ctx)
75+
logger.Printf("Terraform executions will be logged to %s "+
76+
"(interpolated at the time of execution)", c.tfExecLogPath)
77+
}
78+
6379
srv := langserver.NewLangServer(ctx, handlers.NewService)
6480
srv.SetLogger(logger)
6581

‎internal/context/context.go

+11
Original file line numberDiff line numberDiff line change
@@ -158,3 +158,14 @@ func SetTerraformVersion(ctx context.Context, v string) error {
158158

159159
return nil
160160
}
161+
162+
const ctxTfExecLogPath = "ctxTerraformExecLogPath"
163+
164+
func WithTerraformExecLogPath(path string, ctx context.Context) context.Context {
165+
return context.WithValue(ctx, ctxTfExecLogPath, path)
166+
}
167+
168+
func TerraformExecLogPath(ctx context.Context) (string, bool) {
169+
path, ok := ctx.Value(ctxTfExecLogPath).(string)
170+
return path, ok
171+
}

‎internal/terraform/exec/exec.go

+20-3
Original file line numberDiff line numberDiff line change
@@ -15,6 +15,7 @@ import (
1515

1616
"github.com/hashicorp/go-version"
1717
tfjson "github.com/hashicorp/terraform-json"
18+
"github.com/hashicorp/terraform-ls/logging"
1819
)
1920

2021
// cmdCtxFunc allows mocking of Terraform in tests while retaining
@@ -25,9 +26,10 @@ type Executor struct {
2526
ctx context.Context
2627
timeout time.Duration
2728

28-
execPath string
29-
workDir string
30-
logger *log.Logger
29+
execPath string
30+
workDir string
31+
logger *log.Logger
32+
execLogPath string
3133

3234
cmdCtxFunc cmdCtxFunc
3335
}
@@ -48,6 +50,10 @@ func (e *Executor) SetLogger(logger *log.Logger) {
4850
e.logger = logger
4951
}
5052

53+
func (e *Executor) SetExecLogPath(path string) {
54+
e.execLogPath = path
55+
}
56+
5157
func (e *Executor) SetTimeout(duration time.Duration) {
5258
e.timeout = duration
5359
}
@@ -94,6 +100,17 @@ func (e *Executor) run(args ...string) ([]byte, error) {
94100
cmd.Env = append(cmd.Env, "USER="+v)
95101
}
96102

103+
if e.execLogPath != "" {
104+
logPath, err := logging.ParseExecLogPath(cmd.Args, e.execLogPath)
105+
if err != nil {
106+
return nil, fmt.Errorf("failed to parse log path: %w", err)
107+
}
108+
cmd.Env = append(cmd.Env, "TF_LOG=TRACE")
109+
cmd.Env = append(cmd.Env, "TF_LOG_PATH="+logPath)
110+
111+
e.logger.Printf("Execution will be logged to %s", logPath)
112+
}
113+
97114
e.logger.Printf("Running %s %q in %q...", e.execPath, args, e.workDir)
98115
err := cmd.Run()
99116
if err != nil {

‎langserver/handlers/service.go

+5
Original file line numberDiff line numberDiff line change
@@ -87,6 +87,11 @@ func (svc *service) Assigner() (jrpc2.Assigner, error) {
8787
// on service shutdown, rather than response delivery or request cancellation
8888
// as some operations may run in isolated goroutines
8989
tf := svc.executorFunc(svc.svcCtx, tfPath)
90+
91+
// Log path is set via CLI flag, hence in the server context
92+
if path, ok := lsctx.TerraformExecLogPath(svc.srvCtx); ok {
93+
tf.SetExecLogPath(path)
94+
}
9095
tf.SetLogger(svc.logger)
9196

9297
ctx = lsctx.WithTerraformExecutor(tf, ctx)

‎logging/logging.go

+129
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,129 @@
1+
package logging
2+
3+
import (
4+
"fmt"
5+
"io"
6+
"log"
7+
"os"
8+
"path/filepath"
9+
"regexp"
10+
"strings"
11+
"text/template"
12+
"time"
13+
)
14+
15+
func NewLogger(w io.Writer) *log.Logger {
16+
return log.New(w, "", log.LstdFlags|log.Lshortfile)
17+
}
18+
19+
type fileLogger struct {
20+
l *log.Logger
21+
f *os.File
22+
}
23+
24+
func NewFileLogger(rawPath string) (*fileLogger, error) {
25+
path, err := parseLogPath(rawPath)
26+
if err != nil {
27+
return nil, fmt.Errorf("failed to parse path: %w", err)
28+
}
29+
30+
if !filepath.IsAbs(path) {
31+
return nil, fmt.Errorf("please provide absolute log path to prevent ambiguity (given: %q)",
32+
path)
33+
}
34+
35+
mode := os.O_TRUNC | os.O_CREATE | os.O_WRONLY
36+
file, err := os.OpenFile(path, mode, 0600)
37+
if err != nil {
38+
return nil, err
39+
}
40+
41+
return &fileLogger{
42+
l: NewLogger(file),
43+
f: file,
44+
}, nil
45+
}
46+
47+
func parseLogPath(rawPath string) (string, error) {
48+
tpl := template.New("log-file")
49+
tpl = tpl.Funcs(template.FuncMap{
50+
"timestamp": time.Now().Local().Unix,
51+
"pid": os.Getpid,
52+
"ppid": os.Getppid,
53+
})
54+
tpl, err := tpl.Parse(rawPath)
55+
if err != nil {
56+
return "", err
57+
}
58+
59+
buf := &strings.Builder{}
60+
err = tpl.Execute(buf, nil)
61+
if err != nil {
62+
return "", err
63+
}
64+
65+
return buf.String(), nil
66+
}
67+
68+
func ValidateExecLogPath(rawPath string) error {
69+
_, err := parseExecLogPathTemplate([]string{}, rawPath)
70+
return err
71+
}
72+
73+
func ParseExecLogPath(args []string, rawPath string) (string, error) {
74+
tpl, err := parseExecLogPathTemplate(args, rawPath)
75+
if err != nil {
76+
return "", err
77+
}
78+
79+
buf := &strings.Builder{}
80+
err = tpl.Execute(buf, nil)
81+
if err != nil {
82+
return "", err
83+
}
84+
85+
return buf.String(), nil
86+
}
87+
88+
func parseExecLogPathTemplate(args []string, rawPath string) (*template.Template, error) {
89+
tpl := template.New("tf-log-file")
90+
tpl = tpl.Funcs(template.FuncMap{
91+
"timestamp": time.Now().Local().Unix,
92+
"lsPid": os.Getpid,
93+
"lsPpid": os.Getppid,
94+
"args": func() string {
95+
return escapeArguments(args)
96+
},
97+
})
98+
return tpl.Parse(rawPath)
99+
}
100+
101+
// escapeArguments turns arguments into a string
102+
// which is safe to use in a filename without any side-effects
103+
func escapeArguments(rawArgs []string) string {
104+
unsafeCharsRe := regexp.MustCompile(`[^a-z-_]+`)
105+
106+
safeArgs := make([]string, len(rawArgs), len(rawArgs))
107+
for _, rawArg := range rawArgs {
108+
// Replace any unsafe character with a hyphen
109+
safeArg := unsafeCharsRe.ReplaceAllString(rawArg, "-")
110+
safeArgs = append(safeArgs, safeArg)
111+
}
112+
113+
args := strings.Join(safeArgs, "-")
114+
115+
// Reduce hyphens to just one
116+
hyphensRe := regexp.MustCompile(`[-]+`)
117+
reduced := hyphensRe.ReplaceAllString(args, "-")
118+
119+
// Trim hyphens from both ends
120+
return strings.Trim(reduced, "-")
121+
}
122+
123+
func (fl *fileLogger) Logger() *log.Logger {
124+
return fl.l
125+
}
126+
127+
func (fl *fileLogger) Close() error {
128+
return fl.f.Close()
129+
}

0 commit comments

Comments
 (0)
Please sign in to comment.