The documentation for interface SupportsColor doesn't give hints to libraries which expose an io.Writer which implement this interface. Is it purely abstract (just a facility with no yet known implementation)?

JSON doesn't properly marshal error types, causing the logger to essentially print out an empty JSON object whenever an error is part of the arg value. Potentially related GH issue: golang/go#10748

Example:

package main

import (
	"errors"
	"os"

	hclog "github.com/hashicorp/go-hclog"
)

func main() {
	err := errors.New("this is an error")
	logger := hclog.New(&hclog.LoggerOptions{
		Level:      hclog.Info,
		Output:     os.Stdout,
		JSONFormat: true,
	})

	logger.Info("hello from logger", "err", err)
}

Output:

{"@level":"info","@message":"hello from logger","@timestamp":"2017-08-26T22:02:31.816599-04:00","err":{}}

I've been using this lib for a while now, and I've really enjoyed it. To the point that it has become part of my standard kit.
One piece of code I find myself writing and transplanting to different projects is being able to respond to an environment variable being set to change a logger's level at configuration time (generally when the service starts up).

I'd be happy to create a PR to add this functionality, and my first thought on how to add it would be something like this.

// Function definition
func DebugEnv(envvar string, level Level) Level {
  val, ok := os.LookupEnv(envvar)
  if !ok {
    return level
  }
  switch val {
    case "1":
      fallthrough
    case "yes":
      fallthrough
    case "true":
      return Debug
    default:
      return level
  }
}

It would likely be helpful to make a function like this for debug and trace, but others may be desired too. The caller could chain invocations to easily express override logic. This example would override debug with trace if it was called for, and default to info if no environment variables are found.

level := hclog.TraceEnv("MY_APP_TRACE", hclog.DebugEnv("MY_APP_DEBUG", hclog.Info))

It could also be chained sequentially if that's clearer, or there are a lot of environment variables or override paths needed.

level := hclog.DebugEnv("MY_APP_DEBUG", hclog.Info)
level = hclog.TraceEnv("MY_APP_TRACE", level)

This could also follow a similar pattern to what is already used of delegating to a more general function.

func LevelEnv(conditional Level, envvar string, level Level) Level {
  val, ok := os.LookupEnv(envvar)
  if !ok {
    return level
  }
  switch val {
    case "1":
      fallthrough
    case "yes":
      fallthrough
    case "true":
      return conditional
    default:
      return level
  }
}

func DebugEnv(envvar string, level Level) Level {
  return LevelEnv(Debug, envvar, level)
}

Let me know what your thoughts are. 😃

I know this is not an issue but I'm writing a provider and I'm not really sure where to ask this.

Is this the future proof way of handling logs in terraform providers?

Thanks!

Is there any option to change default time format? I've found it's declared as a const now

const TimeFormat = "2006-01-02T15:04:05.000Z0700"

It would be very helpful to have an option to pass format with LoggerOptions.

similar to https://golang.org/pkg/log/#Writer

While working on hashicorp/nomad#11291 I wasn't able to get InferLevels to work properly because the log lines generated by external dependencies still had the timestamp.

Maybe we can extend the search scope from HasPrefix to Contains?

I would like to point out that there is a small syntax error in an example in the readme of the project, minor correction required.

Corrected version -

var totalBandwidth int = 200

This is sort of a redux of #11

Recently, https://github.com/hashicorp/raft switched to using hclog (hashicorp/raft#321), which broke our client code as we use https://github.com/uber-go/zap for logging.

The original author of #11 was able to solve his problem, but I don't think it's possible to use the same approach with zap.

It would be nice if go-hclog has a function that can wrap around a stdlib logger (zap can derive a stdlib logger), which can then be used with other loggers. This is useful for projects that has standardized on a logger other than hclog and do not wan to introduce a new logger to the stack.

A temporary workaround is to be write a wrapper for each project, but I think this is something that's generalized enough, so it should be possible to implement a function to turn a stdlib logger into a hclog.

I am using hashicorp's go-plugin, which asks for hclog logger. I am not using hclog elsewhere, and wish to wrap the hclog interface around my stdlib-compliant logger, but it seems this is not possible?

I can set Output writer, however I cannot specify a mutex which is shared with my core logger as the hclog mutex is unexported. The only fix I can think of is to send a change which exposes a configurable mutex in LoggerOptions. Is this... kosher?

The whole thing is unfortunate really because it makes integrating with go-plugin very difficult if you're not using hclog, which is likely the case. It makes me wonder how others outside hashicorp are using these tools...? Anyways, please let me know if exposing an optional mutex is acceptable - I can send a patch if so. Thanks in advance

Hi there,

Today I found that my libraries were breaking because of undefined: hclog.TimeFormat error.
Did some quick investigation and found that this const name changed and is making hashicorp/go-plugin to break.
Would you mind taking a look at this?

Cheers

Plugin errors weren't being printed in terraform, because the error values are being dropped directly into the logger arguments. Since error.errorString has no exported fields, when JSONFormat is used it's marshaled as an empty object.

Should hclog detect error and Stringer` and marshal them as strings instead?

Hello fellow HashiCorporeals!

Have we discussed color-coding log levels? In the research team, we wrapped hc-log to colorize INFO as blue, WARN as RED, etc. I imagine Mitchell's colorstring library would probably do the trick.

Is there a world in which this becomes a possible, opt-in feature of hc-log?

Hi folks,

I am using hclog in a project and instantiate the logger with a custom io.Writer, which should be fine according to the struct:

If ColorOption is set to AutoColor, we get only a collored output, if Output from the previous line is a true io.File

But, if Output is not an io.File, hclog panics, instead of a fail-safe operation and omitting colouring.

As a fail-safe option, we can always switch to ColorOff, instead of panic.

Or, might i miss something?

Currently, when intLogger log in json format. It will call json.NewEncoder and do Encode.

But, the escapeHTML in json.Encoder is default to true. So when I want to log some info which will refer these symbol: &, <, and >, the log result is unexpected.

I would like to submit a PR to enhance it.

Hi,

There is a wrong index in this method (https://github.com/hashicorp/go-hclog/blob/master/stdlog.go#L67) to strip the log level,
it should be 6 to strip "[WARN]"

Anyway, congratulation for your work

The json logger unexpectedly panics when writing json format to writer backend fails:

We noticed it because json logger paniced when writing to Stderr, a closed pipe at the time. You can find more details in hashicorp/go-plugin#114 .

I'd suggest treating logging here as best-effort (like in the non-json case), or returning and propagating the error back to make it an application concern.

Also, I may suggest distinguishing between write failures (ignore these) and json marshaling failures (in which case, add a log line indicating a log line was dropped due to json incompatibility).

I'd be happy to submit a PR with the suggested changes if they seem reasonable to maintainers.

is there a way to set the logger to always print hex values for data (bytes) instead of decimal? I'm trying to avoid always adding hclog.fmt()'s would like to just specify this in the configuration?

thanks

Any options in this package to output logs to a log file?

I am trying to capture logs from a plugin and keep getting 2023-05-17T13:46:44.006-0400 [WARN] some.module: some log message: timestamp=2023-05-17T13:46:44.006-0400.

When I set DisableTime: true in hclog.LoggerOptions
I get 2023-05-17T13:46:44.006-0400 [WARN] some.module: some log message: timestamp=0001-01-01T00:00:00.000Z

Is there a way around this? It makes reading the logs quiet messy

logr provides a generic interface for loggers in go and is being used in a lot of places now e.g. kubernetes, etc.
Would it be possible to provide an implementation using hclog?

There seems to have been an attempt to do so but the project has not been updated for a while https://github.com/alauda/logr-hclog

Instead of imposing that all loggers implement methods like IsTrace() bool, I think we should instead have top-level package helpers like log.IsTrace(Level) bool, then just require the loggers to respond to like a Level(). It feels like this logic is going to be common across all of the implementations.

When using hclog with the system-wide logger, the file name and location always refers to a file in the hclog library.

I suspect the call depth must be manipulated to account for the additional indirection, as hinted to in the documentation for the standard logger Output function.

Hi,

Similarly to #82 that got fixed for the default Logger, using an InterceptLogger and StandardWriter will return a wrong fixed location.

Here is a patch to add a failing test:

diff --git a/interceptlogger_test.go b/interceptlogger_test.go
index 7b5a86d..8c0dee2 100644
--- a/interceptlogger_test.go
+++ b/interceptlogger_test.go
@@ -304,6 +304,44 @@ func TestInterceptLogger(t *testing.T) {
 		assert.Equal(t, expected, rest)
 	})
 
+	t.Run("derived standard loggers includes the caller location", func(t *testing.T) {
+		var buf bytes.Buffer
+		var sbuf bytes.Buffer
+
+		logger := NewInterceptLogger(&LoggerOptions{
+			Name:            "test",
+			Level:           Debug,
+			Output:          &buf,
+			IncludeLocation: true,
+		})
+
+		standard := logger.StandardLogger(&StandardLoggerOptions{InferLevels: true})
+
+		sink := NewSinkAdapter(&LoggerOptions{
+			IncludeLocation: true,
+			Level:           Debug,
+			Output:          &sbuf,
+		})
+		logger.RegisterSink(sink)
+		defer logger.DeregisterSink(sink)
+
+		standard.Println("[DEBUG] test log")
+		_, _, line, ok := runtime.Caller(0)
+		require.True(t, ok)
+
+		output := buf.String()
+		dataIdx := strings.IndexByte(output, ' ')
+		rest := output[dataIdx+1:]
+
+		expected := fmt.Sprintf("[DEBUG] go-hclog/interceptlogger_test.go:%d: test log\n", line-1)
+		assert.Equal(t, expected, rest)
+
+		output = sbuf.String()
+		dataIdx = strings.IndexByte(output, ' ')
+		rest = output[dataIdx+1:]
+		assert.Equal(t, expected, rest)
+	})
+
 	t.Run("supports resetting the output", func(t *testing.T) {
 		var first, second bytes.Buffer

Running tests with this patch will get the following output:

--- FAIL: TestInterceptLogger (0.00s)
    --- FAIL: TestInterceptLogger/derived_standard_loggers_includes_the_caller_location (0.00s)
        interceptlogger_test.go:337:
            	Error Trace:	interceptlogger_test.go:337
            	Error:      	Not equal:
            	            	expected: "[DEBUG] go-hclog/interceptlogger_test.go:328: test log\n"
            	            	actual  : "[DEBUG] go-hclog/stdlog.go:45: test: test log\n"
            	            	
            	            	Diff:
            	            	--- Expected
            	            	+++ Actual
            	            	@@ -1,2 +1,2 @@
            	            	-[DEBUG] go-hclog/interceptlogger_test.go:328: test log
            	            	+[DEBUG] go-hclog/stdlog.go:45: test: test log
            	            	
            	Test:       	TestInterceptLogger/derived_standard_loggers_includes_the_caller_location
        interceptlogger_test.go:342:
            	Error Trace:	interceptlogger_test.go:342
            	Error:      	Not equal:
            	            	expected: "[DEBUG] go-hclog/interceptlogger_test.go:328: test log\n"
            	            	actual  : "[DEBUG] go-hclog/stdlog.go:45: test: test log\n"
            	            	
            	            	Diff:
            	            	--- Expected
            	            	+++ Actual
            	            	@@ -1,2 +1,2 @@
            	            	-[DEBUG] go-hclog/interceptlogger_test.go:328: test log
            	            	+[DEBUG] go-hclog/stdlog.go:45: test: test log
            	            	
            	Test:       	TestInterceptLogger/derived_standard_loggers_includes_the_caller_location
FAIL
exit status 1
FAIL	github.com/hashicorp/go-hclog	0.004s

The underlying issue is the same as #82: the callerOffset should be increased to take into account the additional frames.

However, interceptLogger embeds the Logger interface and has no knowledge of callerOffset.

Thanks,

See https://github.com/hashicorp/go-hclog/releases/tag/list

git tag -d list
git push origin :list

Is there any option to log with UTC instead of the location time zone?

I found a time.Now() in https://github.com/hashicorp/go-hclog/blob/master/intlogger.go#L155, but couldn't find anything else

Hello,

consider the case when you don't really have a message, just a list of k/v pairs:

log.Debug("", "dbVersion", dbVersion)

this will print

2022-04-12T21:24:54+0200 [DEBUG] myprog: : dbVersion=0

I would like instead to see simply:

2022-04-12T21:24:54+0200 [DEBUG] myprog: dbVersion=0

What do you think?

See https://play.golang.org/p/BLpvFfNxGIR

Expected output:

2009-11-10T23:00:00.000Z [ERROR] An error occurred!: msg="\"foo\" is not a valid name"

This format isn't formally described anywhere but it currently doesn't allow unambiguous parsing. Using \ as an escape char seems to be common enough that many existing parsers will have a way to do that.

Actual output:

2009-11-10T23:00:00.000Z [ERROR] An error occurred!: msg=""foo" is not a valid name"

If LoggerOptions enables both DisableTime and JSONFormat, the timestamp is still printed (bug); on the other hand if JSONFormat is not enabled, then the timestamp is (correctly) not printed.

hclog version: latest at the time of this writing, v0.14.1.

Sample code (available at https://play.golang.org/p/B1FkucAOu8G)

package main

import (
	"github.com/hashicorp/go-hclog"
)

func main() {
	log1 := hclog.New(&hclog.LoggerOptions{
		DisableTime: true,
	})

	log2 := hclog.New(&hclog.LoggerOptions{
		JSONFormat:  true,
		DisableTime: true,
	})

	log1.Info("hello")
	log2.Info("hello")
}

it prints:

[INFO]  hello
{"@level":"info","@message":"hello","@timestamp":"2009-11-10T23:00:00.000000Z"}

   --- FAIL: TestLogger/includes_the_caller_location (0.00s) 
        logger_test.go:154:  
                Error Trace:    logger_test.go:154 
                Error:          Not equal:  
                                expected: "[INFO]  go-hclog/logger_test.go:129: test: this is test: who=programmer why=\"testing is fun\"\n" 
                                actual  : "[INFO]  go-hclog/logger_test.go:147: test: this is test: who=programmer why=\"testing is fun\"\n" 
                                 
                                Diff: 
                                --- Expected 
                                +++ Actual 
                                @@ -1,2 +1,2 @@ 
                                -[INFO]  go-hclog/logger_test.go:129: test: this is test: who=programmer why="testing is fun" 
                                +[INFO]  go-hclog/logger_test.go:147: test: this is test: who=programmer why="testing is fun" 
                                  
                Test:           TestLogger/includes_the_caller_location 

This is a regression from 0.11.0.

Steps to reproduce:

% export GOPATH=/tmp/gp
% go get github.com/hashicorp/go-hclog
% cd /tmp/gp/src/github.com/hashicorp/go-hclog
% go test -v ./...
[…]
=== RUN   TestInterceptLogger/includes_the_caller_location
    TestInterceptLogger/includes_the_caller_location: interceptlogger_test.go:287: 
        	Error Trace:	interceptlogger_test.go:287
        	Error:      	Not equal: 
        	            	expected: "[INFO]  go-hclog/interceptlogger.go:76: test: this is test: who=programmer why=\"testing is fun\"\n"
        	            	actual  : "[INFO]  go-hclog/interceptlogger_test.go:280: test: this is test: who=programmer why=\"testing is fun\"\n"
        	            	
        	            	Diff:
        	            	--- Expected
        	            	+++ Actual
        	            	@@ -1,2 +1,2 @@
        	            	-[INFO]  go-hclog/interceptlogger.go:76: test: this is test: who=programmer why="testing is fun"
        	            	+[INFO]  go-hclog/interceptlogger_test.go:280: test: this is test: who=programmer why="testing is fun"
        	            	 
        	Test:       	TestInterceptLogger/includes_the_caller_location
    TestInterceptLogger/includes_the_caller_location: interceptlogger_test.go:292: 
        	Error Trace:	interceptlogger_test.go:292
        	Error:      	Not equal: 
        	            	expected: "[INFO]  go-hclog/interceptlogger.go:84: test: this is test: who=programmer why=\"testing is fun\"\n"
        	            	actual  : "[INFO]  go-hclog/interceptlogger_test.go:280: test: this is test: who=programmer why=\"testing is fun\"\n"
        	            	
        	            	Diff:
        	            	--- Expected
        	            	+++ Actual
        	            	@@ -1,2 +1,2 @@
        	            	-[INFO]  go-hclog/interceptlogger.go:84: test: this is test: who=programmer why="testing is fun"
        	            	+[INFO]  go-hclog/interceptlogger_test.go:280: test: this is test: who=programmer why="testing is fun"
        	            	 
        	Test:       	TestInterceptLogger/includes_the_caller_location
=== RUN   TestInterceptLogger/supports_resetting_the_output
=== RUN   TestInterceptLogger/supports_resetting_the_output_with_flushing
--- FAIL: TestInterceptLogger (0.00s)
    --- PASS: TestInterceptLogger/sends_output_to_registered_sinks (0.00s)
    --- PASS: TestInterceptLogger/sink_includes_with_arguments (0.00s)
    --- PASS: TestInterceptLogger/sink_includes_name (0.00s)
    --- PASS: TestInterceptLogger/intercepting_logger_can_create_logger_with_reset_name (0.00s)
    --- PASS: TestInterceptLogger/Intercepting_logger_sink_can_deregister_itself (0.00s)
    --- PASS: TestInterceptLogger/Sinks_accept_different_log_formats (0.00s)
    --- PASS: TestInterceptLogger/handles_parent_with_arguments_and_log_level_args (0.00s)
    --- PASS: TestInterceptLogger/derived_standard_loggers_send_output_to_sinks (0.00s)
    --- FAIL: TestInterceptLogger/includes_the_caller_location (0.00s)
    --- PASS: TestInterceptLogger/supports_resetting_the_output (0.00s)
    --- PASS: TestInterceptLogger/supports_resetting_the_output_with_flushing (0.00s)
[…]

PR #68 might be related

In general, why not just use strings.HasSuffix() instead of a regexp? It’ll be quicker to run and easier to understand.

cc @evanphx @drewbailey

Hello! 👋

I'm currently in the process of implementing a monitor command for Vault, similar to the Nomad and Consul commands of the same name. I'm using InterceptLogger but there are a few places where it needs to be OutputResettable. Does that feel like something appropriate to add? If so, I'm happy to author a PR that makes those changes. If not, I'd appreciate any suggestions y'all might have.