Skip to content

Commit

Permalink
[azcore] Remove logger from azcore (Azure#15160)
Browse files Browse the repository at this point in the history
* initial work, issues with using internal package

* fixing up errors in logger file

* adding logger test file

* removed an example

* feedback and removing circular dependency

* moving logclassification to be in logger, type alias in azcore

* update internal version

* fixes in azcore

* fixes to azcore, works now

* linter false positive

* catalina's comments

* more feedback

* update version

* Update sdk/azcore/version.go

Co-authored-by: catalinaperalta <catalinaperaltah@hotmail.com>

Co-authored-by: catalinaperalta <catalinaperaltah@hotmail.com>
  • Loading branch information
2 people authored and vindicatesociety committed Sep 18, 2021
1 parent 8aa47ff commit ea8efa6
Show file tree
Hide file tree
Showing 10 changed files with 94 additions and 136 deletions.
19 changes: 6 additions & 13 deletions sdk/azcore/example_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -48,23 +48,16 @@ func ExampleRequest_SetBody() {
}
}

func ExampleLogger_Should() {
// you can create your own logging classification as needed
const LogExpensiveThing azcore.LogClassification = "ExpensiveThing"
if azcore.Log().Should(LogExpensiveThing) {
// perform expensive calculation only when enabled
azcore.Log().Write(LogExpensiveThing, "expensive log message")
}
}

func ExampleLogger_SetClassifications() {
// false positive by linter
func ExampleLogger_SetClassifications() { //nolint:govet
// only log HTTP requests and responses
azcore.Log().SetClassifications(azcore.LogRequest, azcore.LogResponse)
azcore.SetClassifications(azcore.LogRequest, azcore.LogResponse)
}

func ExampleLogger_SetListener() {
// false positive by linter
func ExampleLogger_SetListener() { //nolint:govet
// a simple logger that writes to stdout
azcore.Log().SetListener(func(cls azcore.LogClassification, msg string) {
azcore.SetListener(func(cls azcore.LogClassification, msg string) {
fmt.Printf("%s: %s\n", cls, msg)
})
}
Expand Down
4 changes: 2 additions & 2 deletions sdk/azcore/go.mod
Original file line number Diff line number Diff line change
@@ -1,8 +1,8 @@
module github.com/Azure/azure-sdk-for-go/sdk/azcore

require (
github.com/Azure/azure-sdk-for-go/sdk/internal v0.5.1
golang.org/x/net v0.0.0-20201010224723-4f7140c49acb
github.com/Azure/azure-sdk-for-go/sdk/internal v0.5.2
golang.org/x/net v0.0.0-20210610132358-84b48f89b13b
)

go 1.14
35 changes: 21 additions & 14 deletions sdk/azcore/go.sum
Original file line number Diff line number Diff line change
@@ -1,15 +1,22 @@
github.com/Azure/azure-sdk-for-go/sdk/internal v0.5.1 h1:vx8McI56N5oLSQu8xa+xdiE0fjQq8W8Zt49vHP8Rygw=
github.com/Azure/azure-sdk-for-go/sdk/internal v0.5.1/go.mod h1:k4KbFSunV/+0hOHL1vyFaPsiYQ1Vmvy1TBpmtvCDLZM=
golang.org/x/crypto v0.0.0-20190308221718-c2843e01d9a2/go.mod h1:djNgcEr1/C05ACkg1iLfiJU5Ep61QUkGW8qpdssI0+w=
golang.org/x/crypto v0.0.0-20200622213623-75b288015ac9/go.mod h1:LzIPMQfyMNhhGPhUkYOs5KpL4U8rLKemX1yGLhDgUto=
golang.org/x/net v0.0.0-20190404232315-eb5bcb51f2a3/go.mod h1:t9HGtf8HONx5eT2rtn7q6eTqICYqUVnKs3thJo3Qplg=
golang.org/x/net v0.0.0-20201010224723-4f7140c49acb h1:mUVeFHoDKis5nxCAzoAi7E8Ghb86EXh/RK6wtvJIqRY=
golang.org/x/net v0.0.0-20201010224723-4f7140c49acb/go.mod h1:sp8m0HH+o8qH0wwXwYZr8TS3Oi6o0r6Gce1SSxlDquU=
golang.org/x/sys v0.0.0-20190215142949-d0b11bdaac8a/go.mod h1:STP8DvDyc/dI5b8T5hshtkjS+E42TnysNCUPdjciGhY=
golang.org/x/sys v0.0.0-20190412213103-97732733099d/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs=
golang.org/x/sys v0.0.0-20200930185726-fdedc70b468f/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs=
golang.org/x/text v0.3.0 h1:g61tztE5qeGQ89tm6NTjjM9VPIm088od1l6aSorWRWg=
golang.org/x/text v0.3.0/go.mod h1:NqM8EUOU14njkJ3fqMW+pc6Ldnwhi/IjpwHt7yyuwOQ=
golang.org/x/text v0.3.3 h1:cokOdA+Jmi5PJGXLlLllQSgYigAEfHXJAERHVMaCc2k=
golang.org/x/text v0.3.3/go.mod h1:5Zoc/QRtKVWzQhOtBMvqHzDpF6irO9z98xDceosuGiQ=
github.com/Azure/azure-sdk-for-go/sdk/internal v0.5.2 h1:E2xwjsWU81O/XuSaxAGa8Jmqz4Vm4NmrpMSO9/XevDg=
github.com/Azure/azure-sdk-for-go/sdk/internal v0.5.2/go.mod h1:Hl9Vte0DDolj9zqzmfnmY9/zfZbiT5KnvXqVwAvnR8Q=
github.com/davecgh/go-spew v1.1.0/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38=
github.com/davecgh/go-spew v1.1.1/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38=
github.com/dnaeon/go-vcr v1.2.0/go.mod h1:R4UdLID7HZT3taECzJs4YgbbH6PIGXB6W/sc5OLb6RQ=
github.com/modocache/gover v0.0.0-20171022184752-b58185e213c5/go.mod h1:caMODM3PzxT8aQXRPkAt8xlV/e7d7w8GM5g0fa5F0D8=
github.com/pmezard/go-difflib v1.0.0/go.mod h1:iKH77koFhYxTK1pcRnkKkqfTogsbg7gZNVY4sRDYZ/4=
github.com/stretchr/objx v0.1.0/go.mod h1:HFkY916IF+rwdDfMAkV7OtwuqBVzrE8GR6GFx+wExME=
github.com/stretchr/testify v1.7.0/go.mod h1:6Fq8oRcR53rry900zMqJjRRixrwX3KX962/h/Wwjteg=
golang.org/x/net v0.0.0-20210610132358-84b48f89b13b h1:k+E048sYJHyVnsr1GDrRZWQ32D2C7lWs9JRc0bel53A=
golang.org/x/net v0.0.0-20210610132358-84b48f89b13b/go.mod h1:9nx3DQGgdP8bBQD5qxJ1jj9UTztislL4KSBs9R2vV5Y=
golang.org/x/sys v0.0.0-20201119102817-f84b799fce68/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs=
golang.org/x/sys v0.0.0-20210423082822-04245dca01da/go.mod h1:h1NjWce9XRLGQEsW7wpKNCjG9DtNlClVuFLEZdDNbEs=
golang.org/x/term v0.0.0-20201126162022-7de9c90e9dd1/go.mod h1:bj7SfCRtBDWHUb9snDiAeCFNEtKQo2Wmx5Cou7ajbmo=
golang.org/x/text v0.3.6 h1:aRYxNxv6iGQlyVaZmk6ZgYEDa+Jg18DxebPSrd6bg1M=
golang.org/x/text v0.3.6/go.mod h1:5Zoc/QRtKVWzQhOtBMvqHzDpF6irO9z98xDceosuGiQ=
golang.org/x/tools v0.0.0-20180917221912-90fa682c2a6e/go.mod h1:n7NCudcB/nEzxVGmLbDWY5pfWTLqBcC2KZ6jyYvM4mQ=
gopkg.in/check.v1 v0.0.0-20161208181325-20d25e280405/go.mod h1:Co6ibVJAznAaIkqp8huTwlJQCZ016jof/cbN4VW5Yz0=
gopkg.in/yaml.v2 v2.2.8/go.mod h1:hI93XBmqTisBFMUTm0b8Fm+jr3Dg1NNxqwp+5A1VGuI=
gopkg.in/yaml.v2 v2.4.0/go.mod h1:RDklbk79AGWmwhnvt/jBztapEOGDOx6ZbXqjP6csGnQ=
gopkg.in/yaml.v3 v3.0.0-20200313102051-9f266ea9e77c/go.mod h1:K4uyk7z7BCEPqu6E+C64Yfv1cQ7kz7rIZviUmN+EgEM=
gopkg.in/yaml.v3 v3.0.0-20210107192922-496545a6307b/go.mod h1:K4uyk7z7BCEPqu6E+C64Yfv1cQ7kz7rIZviUmN+EgEM=
105 changes: 28 additions & 77 deletions sdk/azcore/log.go
Original file line number Diff line number Diff line change
Expand Up @@ -6,13 +6,11 @@
package azcore

import (
"fmt"
"os"
"time"
"github.com/Azure/azure-sdk-for-go/sdk/internal/logger"
)

// LogClassification is used to group entries. Each group can be toggled on or off.
type LogClassification string
// LogClassification is used to group entries. Each group can be toggled on or off
type LogClassification logger.LogClassification

const (
// LogRequest entries contain information about HTTP requests.
Expand All @@ -31,86 +29,39 @@ const (
LogLongRunningOperation LogClassification = "LongRunningOperation"
)

// Listener is the function signature invoked when writing log entries.
// A Listener is required to perform its own synchronization if it's
// expected to be called from multiple Go routines.
type Listener func(LogClassification, string)

// Logger controls which classifications to log and writing to the underlying log.
type Logger struct {
cls []LogClassification
lst Listener
}

// SetClassifications is used to control which classifications are written to
// the log. By default all log classifications are written.
func (l *Logger) SetClassifications(cls ...LogClassification) {
l.cls = cls
}

// SetListener will set the Logger to write to the specified Listener.
func (l *Logger) SetListener(lst Listener) {
l.lst = lst
}

// Should returns true if the specified log classification should be written to the log.
// By default all log classifications will be logged. Call SetClassification() to limit
// the log classifications for logging.
// If no listener has been set this will return false.
// Calling this method is useful when the message to log is computationally expensive
// and you want to avoid the overhead if its log classification is not enabled.
func (l *Logger) Should(cls LogClassification) bool {
if l.lst == nil {
return false
}
if l.cls == nil || len(l.cls) == 0 {
return true
// the log. By default all log classifications are writen.
func SetClassifications(cls ...LogClassification) {
input := make([]logger.LogClassification, 0)
for _, l := range cls {
input = append(input, logger.LogClassification(l))
}
for _, c := range l.cls {
if c == cls {
return true
}
}
return false
logger.Log().SetClassifications(input...)
}

// Write invokes the underlying Listener with the specified classification and message.
// If the classification shouldn't be logged or there is no listener then Write does nothing.
func (l *Logger) Write(cls LogClassification, message string) {
if !l.Should(cls) {
return
}
l.lst(cls, message)
}
// Listener is the function signature invoked when writing log entries.
// A Listener is required to perform its own synchronization if it's expected to be called
// from multiple Go routines
type Listener func(LogClassification, string)

// Writef invokes the underlying Listener with the specified classification and formatted message.
// If the classification shouldn't be logged or there is no listener then Writef does nothing.
func (l *Logger) Writef(cls LogClassification, format string, a ...interface{}) {
if !l.Should(cls) {
return
// transform to convert the azcore.Listener type into a usable one for internal.logger module
func transform(lst Listener) logger.Listener {
return func(l logger.LogClassification, msg string) {
azcoreL := LogClassification(l)
lst(azcoreL, msg)
}
l.lst(cls, fmt.Sprintf(format, a...))
}

// for testing purposes, nolint is a false positive
func (l *Logger) resetClassifications() { //nolint:unused
l.cls = nil
}

var logger Logger

// Log returns the process-wide logger.
func Log() *Logger {
return &logger
// SetListener will set the Logger to write to the specified Listener.
func SetListener(lst Listener) {
if lst == nil {
logger.Log().SetListener(nil)
} else {
logger.Log().SetListener(transform(lst))
}
}

func init() {
if cls := os.Getenv("AZURE_SDK_GO_LOGGING"); cls == "all" {
// cls could be enhanced to support a comma-delimited list of log classifications
logger.lst = func(cls LogClassification, msg string) {
// simple console logger, it writes to stderr in the following format:
// [time-stamp] Classification: message
fmt.Fprintf(os.Stderr, "[%s] %s: %s\n", time.Now().Format(time.StampMicro), cls, msg)
}
}
// for testing purposes
func resetClassifications() {
logger.Log().SetClassifications([]logger.LogClassification{}...)
}
22 changes: 12 additions & 10 deletions sdk/azcore/log_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -9,21 +9,23 @@ import (
"fmt"
"net/http"
"testing"

"github.com/Azure/azure-sdk-for-go/sdk/internal/logger"
)

func TestLoggingDefault(t *testing.T) {
// ensure logging with nil listener doesn't fail
Log().SetListener(nil)
Log().Write(LogRequest, "this should work just fine")
SetListener(nil)
logger.Log().Write(logger.LogRequest, "this should work just fine")

log := map[LogClassification]string{}
Log().SetListener(func(cls LogClassification, msg string) {
SetListener(func(cls LogClassification, msg string) {
log[cls] = msg
})
const req = "this is a request"
Log().Write(LogRequest, req)
logger.Log().Write(logger.LogRequest, req)
const resp = "this is a response: %d"
Log().Writef(LogResponse, resp, http.StatusOK)
logger.Log().Writef(logger.LogResponse, resp, http.StatusOK)
if l := len(log); l != 2 {
t.Fatalf("unexpected log entry count: %d", l)
}
Expand All @@ -37,17 +39,17 @@ func TestLoggingDefault(t *testing.T) {

func TestLoggingClassification(t *testing.T) {
log := map[LogClassification]string{}
Log().SetListener(func(cls LogClassification, msg string) {
SetListener(func(cls LogClassification, msg string) {
log[cls] = msg
})
Log().SetClassifications(LogRequest)
defer Log().resetClassifications()
Log().Write(LogResponse, "this shouldn't be in the log")
SetClassifications(LogRequest)
defer resetClassifications()
logger.Log().Write(logger.LogResponse, "this shouldn't be in the log")
if s, ok := log[LogResponse]; ok {
t.Fatalf("unexpected log entry %s", s)
}
const req = "this is a request"
Log().Write(LogRequest, req)
logger.Log().Write(logger.LogRequest, req)
if log[LogRequest] != req {
t.Fatalf("unexpected log entry: %s", log[LogRequest])
}
Expand Down
9 changes: 5 additions & 4 deletions sdk/azcore/policy_logging.go
Original file line number Diff line number Diff line change
Expand Up @@ -11,6 +11,7 @@ import (
"strings"
"time"

"github.com/Azure/azure-sdk-for-go/sdk/internal/logger"
"github.com/Azure/azure-sdk-for-go/sdk/internal/runtime"
)

Expand Down Expand Up @@ -51,15 +52,15 @@ func (p *logPolicy) Do(req *Request) (*Response, error) {
req.SetOperationValue(opValues)

// Log the outgoing request as informational
if Log().Should(LogRequest) {
if logger.Log().Should(logger.LogRequest) {
b := &bytes.Buffer{}
fmt.Fprintf(b, "==> OUTGOING REQUEST (Try=%d)\n", opValues.try)
writeRequestWithResponse(b, req, nil, nil)
var err error
if p.options.IncludeBody {
err = req.writeBody(b)
}
Log().Write(LogRequest, b.String())
logger.Log().Write(logger.LogRequest, b.String())
if err != nil {
return nil, err
}
Expand All @@ -72,7 +73,7 @@ func (p *logPolicy) Do(req *Request) (*Response, error) {
tryDuration := tryEnd.Sub(tryStart)
opDuration := tryEnd.Sub(opValues.start)

if Log().Should(LogResponse) {
if logger.Log().Should(logger.LogResponse) {
// We're going to log this; build the string to log
b := &bytes.Buffer{}
fmt.Fprintf(b, "==> REQUEST/RESPONSE (Try=%d/%v, OpTime=%v) -- ", opValues.try, tryDuration, opDuration)
Expand All @@ -89,7 +90,7 @@ func (p *logPolicy) Do(req *Request) (*Response, error) {
} else if p.options.IncludeBody {
err = response.writeBody(b)
}
Log().Write(LogResponse, b.String())
logger.Log().Write(logger.LogResponse, b.String())
}
return response, err
}
Expand Down
4 changes: 2 additions & 2 deletions sdk/azcore/policy_logging_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -18,7 +18,7 @@ import (

func TestPolicyLoggingSuccess(t *testing.T) {
log := map[LogClassification]string{}
Log().SetListener(func(cls LogClassification, s string) {
SetListener(func(cls LogClassification, s string) {
log[cls] = s
})
srv, close := mock.NewServer()
Expand Down Expand Up @@ -68,7 +68,7 @@ func TestPolicyLoggingSuccess(t *testing.T) {

func TestPolicyLoggingError(t *testing.T) {
log := map[LogClassification]string{}
Log().SetListener(func(cls LogClassification, s string) {
SetListener(func(cls LogClassification, s string) {
log[cls] = s
})
srv, close := mock.NewServer()
Expand Down
18 changes: 10 additions & 8 deletions sdk/azcore/policy_retry.go
Original file line number Diff line number Diff line change
Expand Up @@ -13,6 +13,8 @@ import (
"math/rand"
"net/http"
"time"

"github.com/Azure/azure-sdk-for-go/sdk/internal/logger"
)

const (
Expand Down Expand Up @@ -149,7 +151,7 @@ func (p *retryPolicy) Do(req *Request) (resp *Response, err error) {
try := int32(1)
for {
resp = nil // reset
Log().Writef(LogRetryPolicy, "\n=====> Try=%d %s %s", try, req.Method, req.URL.String())
logger.Log().Writef(logger.LogRetryPolicy, "\n=====> Try=%d %s %s", try, req.Method, req.URL.String())

// For each try, seek to the beginning of the Body stream. We do this even for the 1st try because
// the stream may not be at offset 0 when we first get it and we want the same behavior for the
Expand All @@ -169,9 +171,9 @@ func (p *retryPolicy) Do(req *Request) (resp *Response, err error) {
tryCancel()
}
if err == nil {
Log().Writef(LogRetryPolicy, "response %d", resp.StatusCode)
logger.Log().Writef(logger.LogRetryPolicy, "response %d", resp.StatusCode)
} else {
Log().Writef(LogRetryPolicy, "error %v", err)
logger.Log().Writef(logger.LogRetryPolicy, "error %v", err)
}

if err == nil && !resp.HasStatusCode(options.StatusCodes...) {
Expand All @@ -180,21 +182,21 @@ func (p *retryPolicy) Do(req *Request) (resp *Response, err error) {
} else if ctxErr := req.Context().Err(); ctxErr != nil {
// don't retry if the parent context has been cancelled or its deadline exceeded
err = ctxErr
Log().Writef(LogRetryPolicy, "abort due to %v", err)
logger.Log().Writef(logger.LogRetryPolicy, "abort due to %v", err)
return
}

// check if the error is not retriable
var nre NonRetriableError
if errors.As(err, &nre) {
// the error says it's not retriable so don't retry
Log().Writef(LogRetryPolicy, "non-retriable error %T", nre)
logger.Log().Writef(logger.LogRetryPolicy, "non-retriable error %T", nre)
return
}

if try == options.MaxRetries+1 {
// max number of tries has been reached, don't sleep again
Log().Writef(LogRetryPolicy, "MaxRetries %d exceeded", options.MaxRetries)
logger.Log().Writef(logger.LogRetryPolicy, "MaxRetries %d exceeded", options.MaxRetries)
return
}

Expand All @@ -206,13 +208,13 @@ func (p *retryPolicy) Do(req *Request) (resp *Response, err error) {
if delay <= 0 {
delay = options.calcDelay(try)
}
Log().Writef(LogRetryPolicy, "End Try #%d, Delay=%v", try, delay)
logger.Log().Writef(logger.LogRetryPolicy, "End Try #%d, Delay=%v", try, delay)
select {
case <-time.After(delay):
try++
case <-req.Context().Done():
err = req.Context().Err()
Log().Writef(LogRetryPolicy, "abort due to %v", err)
logger.Log().Writef(logger.LogRetryPolicy, "abort due to %v", err)
return
}
}
Expand Down
Loading

0 comments on commit ea8efa6

Please sign in to comment.