Skip to content

Commit

Permalink
improve error formatting (#188)
Browse files Browse the repository at this point in the history
Improved errors following guidelines here https://pkg.go.dev/errors#Is
* Standardized error message formatting
* Type checking (`errors.Is(err, ErrFailedLogEvent)`)
* Sharable metadata (e.g. `StatusCode`, `Endpoint`)

This was the original ask from Monzo https://statsigconnect.slack.com/archives/C05SN05C4N8/p1714723168057799?thread_ts=1714654581.641249&cid=C05SN05C4N8

Example:
```
[2024-06-14T12:35:11-07:00][Statsig] Failed to log 1 events: Failed request to /log_event after 0 retries: 400 Bad Request
```
  • Loading branch information
kenny-statsig authored Jun 17, 2024
1 parent f53d35e commit 3c9f008
Show file tree
Hide file tree
Showing 6 changed files with 183 additions and 34 deletions.
12 changes: 6 additions & 6 deletions error_boundary.go
Original file line number Diff line number Diff line change
Expand Up @@ -22,16 +22,16 @@ type errorBoundary struct {
}

type logExceptionRequestBody struct {
Exception string `json:"exception"`
Info string `json:"info"`
StatsigMetadata statsigMetadata `json:"statsigMetadata"`
Extra *map[string]interface{} `json:"extra"`
Tag string `json:"tag"`
Exception string `json:"exception"`
Info string `json:"info"`
StatsigMetadata statsigMetadata `json:"statsigMetadata"`
Extra map[string]interface{} `json:"extra"`
Tag string `json:"tag"`
}

type logExceptionOptions struct {
Tag string
Extra *map[string]interface{}
Extra map[string]interface{}
BypassDedupe bool
LogToOutput bool
}
Expand Down
51 changes: 51 additions & 0 deletions errors.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,51 @@
package statsig

import (
"errors"
"fmt"
)

// Error Variables
type StatsigError error

var (
ErrFailedLogEvent StatsigError = errors.New("failed to log events")
)

type RequestMetadata struct {
StatusCode int
Endpoint string
Retries int
}

type TransportError struct {
RequestMetadata *RequestMetadata
Err error
}

func (e *TransportError) Error() string {
if e.RequestMetadata != nil {
return fmt.Sprintf("Failed request to %s after %d retries: %s", e.RequestMetadata.Endpoint, e.RequestMetadata.Retries, e.Err.Error())
} else {
return e.Err.Error()
}
}

func (e *TransportError) Unwrap() error { return e.Err }

type LogEventError struct {
Err *TransportError
Events int
}

func (e *LogEventError) Error() string {
if e.Err != nil {
return fmt.Sprintf("Failed to log %d events: %s", e.Events, e.Err.Error())
} else {
return fmt.Sprintf("Failed to log %d events", e.Events)
}
}

func (e *LogEventError) Unwrap() error { return e.Err }

func (e *LogEventError) Is(target error) bool { return target == ErrFailedLogEvent }
9 changes: 6 additions & 3 deletions logger.go
Original file line number Diff line number Diff line change
Expand Up @@ -249,17 +249,20 @@ func (l *logger) sendEvents(events []interface{}) {
var res logEventResponse
_, err := l.transport.log_event(events, &res, RequestOptions{retries: maxRetries})
if err != nil {
message := fmt.Sprintf("Failed to log %d events afrer %d retries, dropping the request", len(events), maxRetries)
extra := map[string]interface{}{
"eventCount": len(events),
}
options := logExceptionOptions{
Tag: "statsig::log_event_failed",
Extra: &extra,
Extra: extra,
BypassDedupe: true,
LogToOutput: true,
}
l.errorBoundary.logExceptionWithOptions(toError(message), options)
err := &LogEventError{
Events: len(events),
Err: err,
}
l.errorBoundary.logExceptionWithOptions(err, options)
}
}

Expand Down
19 changes: 9 additions & 10 deletions output_logger.go
Original file line number Diff line number Diff line change
Expand Up @@ -3,6 +3,7 @@ package statsig
import (
"encoding/json"
"fmt"
"os"
"time"
)

Expand All @@ -21,15 +22,14 @@ func (o *OutputLogger) Log(msg string, err error) {
if o.isInitialized() && o.options.LogCallback != nil {
o.options.LogCallback(msg, err)
} else {
formatted := msg
timestamp := time.Now().Format(time.RFC3339)

formatted := fmt.Sprintf("[%s][Statsig] %s", timestamp, msg)
if err != nil {
if formatted != "" {
formatted += "\n"
}
formatted += err.Error()
}
if formatted != "" {
fmt.Print(formatted)
fmt.Fprintln(os.Stderr, formatted)
} else if msg != "" {
fmt.Println(formatted)
}
}
}
Expand All @@ -50,8 +50,7 @@ func (o *OutputLogger) LogStep(process StatsigProcess, msg string) {
if o.options.DisableSyncDiagnostics && process == StatsigProcessSync {
return
}
timestamp := time.Now().Format(time.RFC3339)
o.Log(fmt.Sprintf("[%s][Statsig] %s: %s\n", timestamp, process, msg), nil)
o.Log(fmt.Sprintf("%s: %s", process, msg), nil)
}

func (o *OutputLogger) LogError(err interface{}) {
Expand All @@ -61,7 +60,7 @@ func (o *OutputLogger) LogError(err interface{}) {
case error:
o.Log("", errTyped)
default:
fmt.Print(err)
fmt.Fprintln(os.Stderr, err)
}
}

Expand Down
69 changes: 69 additions & 0 deletions output_logger_test.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,69 @@
package statsig

import (
"errors"
"net/http"
"net/http/httptest"
"testing"
)

func TestLogEventErrors(t *testing.T) {
testServer := httptest.NewServer(http.HandlerFunc(func(res http.ResponseWriter, req *http.Request) {
res.WriteHeader(http.StatusBadRequest)
}))
defer testServer.Close()

errs := make([]error, 0)
opts := &Options{
API: testServer.URL,
StatsigLoggerOptions: StatsigLoggerOptions{
DisableInitDiagnostics: true,
DisableSyncDiagnostics: true,
DisableApiDiagnostics: true,
},
OutputLoggerOptions: OutputLoggerOptions{
EnableDebug: true,
LogCallback: func(message string, err error) {
errs = append(errs, err)
},
},
}
diagnostics := newDiagnostics(opts)
transport := newTransport("secret", opts)
errorBoundary := newErrorBoundary("secret", opts, nil)
logger := newLogger(transport, opts, diagnostics, errorBoundary)

user := User{
UserID: "123",
}
event := Event{
EventName: "test_event",
User: user,
Value: "3",
}

stderrLogs := swallow_stderr(func() {
logger.logCustom(event)
logger.flush(true)
})

if stderrLogs == "" {
t.Errorf("Expected output to stderr")
}

InitializeGlobalOutputLogger(opts.OutputLoggerOptions)
logger.logCustom(event)
logger.flush(true)

if len(errs) == 0 {
t.Errorf("Expected output to callback")
}

if !errors.Is(errs[0], ErrFailedLogEvent) {
t.Errorf("Expected error to match ErrFailedLogEvent")
}

if errs[0].Error() != "Failed to log 1 events: Failed request to /log_event after 0 retries: 400 Bad Request" {
t.Errorf("Expected error message")
}
}
57 changes: 42 additions & 15 deletions transport.go
Original file line number Diff line number Diff line change
Expand Up @@ -64,7 +64,7 @@ func (opts *RequestOptions) fill_defaults() {
}
}

func (transport *transport) download_config_specs(sinceTime int64, responseBody interface{}) (*http.Response, error) {
func (transport *transport) download_config_specs(sinceTime int64, responseBody interface{}) (*http.Response, *TransportError) {
var endpoint string
if transport.options.DisableCDN {
endpoint = fmt.Sprintf("/download_config_specs?sinceTime=%d", sinceTime)
Expand All @@ -74,24 +74,36 @@ func (transport *transport) download_config_specs(sinceTime int64, responseBody
return transport.get(endpoint, responseBody, RequestOptions{})
}

func (transport *transport) get_id_lists(responseBody interface{}) (*http.Response, error) {
func (transport *transport) get_id_lists(responseBody interface{}) (*http.Response, *TransportError) {
return transport.post("/get_id_lists", nil, responseBody, RequestOptions{})
}

func (transport *transport) get_id_list(url string, headers map[string]string) (*http.Response, error) {
func (transport *transport) get_id_list(url string, headers map[string]string) (*http.Response, *TransportError) {
req, err := http.NewRequest("GET", url, nil)
if err != nil {
return nil, err
return nil, &TransportError{Err: err}
}

for k, v := range headers {
req.Header.Set(k, v)
}

return transport.client.Do(req)
res, err := transport.client.Do(req)

if err != nil {
return res, &TransportError{
RequestMetadata: &RequestMetadata{
StatusCode: res.StatusCode,
Endpoint: url,
Retries: 0,
},
Err: err}
}

return res, nil
}

func (transport *transport) log_event(event []interface{}, responseBody interface{}, options RequestOptions) (*http.Response, error) {
func (transport *transport) log_event(event []interface{}, responseBody interface{}, options RequestOptions) (*http.Response, *TransportError) {
input := logEventInput{
Events: event,
StatsigMetadata: transport.metadata,
Expand All @@ -104,11 +116,11 @@ func (transport *transport) log_event(event []interface{}, responseBody interfac

}

func (transport *transport) post(endpoint string, body interface{}, responseBody interface{}, options RequestOptions) (*http.Response, error) {
func (transport *transport) post(endpoint string, body interface{}, responseBody interface{}, options RequestOptions) (*http.Response, *TransportError) {
return transport.doRequest("POST", endpoint, body, responseBody, options)
}

func (transport *transport) get(endpoint string, responseBody interface{}, options RequestOptions) (*http.Response, error) {
func (transport *transport) get(endpoint string, responseBody interface{}, options RequestOptions) (*http.Response, *TransportError) {
return transport.doRequest("GET", endpoint, nil, responseBody, options)
}

Expand Down Expand Up @@ -173,13 +185,13 @@ func (transport *transport) doRequest(
in interface{},
out interface{},
options RequestOptions,
) (*http.Response, error) {
) (*http.Response, *TransportError) {
request, err := transport.buildRequest(method, endpoint, in, options.header)
if request == nil || err != nil {
return nil, err
return nil, &TransportError{Err: err}
}
options.fill_defaults()
return retry(options.retries, time.Duration(options.backoff), func() (*http.Response, bool, error) {
response, err, retried := retry(options.retries, time.Duration(options.backoff), func() (*http.Response, bool, error) {
response, err := transport.client.Do(request)
if err != nil {
return response, response != nil, err
Expand All @@ -197,8 +209,21 @@ func (transport *transport) doRequest(
return response, false, transport.parseResponse(response, out)
}

return response, retryableStatusCode(response.StatusCode), fmt.Errorf("http response error code: %d", response.StatusCode)
return response, retryableStatusCode(response.StatusCode), fmt.Errorf(response.Status)
})

if err != nil {
return response, &TransportError{
RequestMetadata: &RequestMetadata{
StatusCode: response.StatusCode,
Endpoint: endpoint,
Retries: retried,
},
Err: err,
}
}

return response, nil
}

func (transport *transport) parseResponse(response *http.Response, out interface{}) error {
Expand All @@ -208,18 +233,20 @@ func (transport *transport) parseResponse(response *http.Response, out interface
return json.NewDecoder(response.Body).Decode(&out)
}

func retry(retries int, backoff time.Duration, fn func() (*http.Response, bool, error)) (*http.Response, error) {
func retry(retries int, backoff time.Duration, fn func() (*http.Response, bool, error)) (*http.Response, error, int) {
retried := 0
for {
if response, retry, err := fn(); retry {
if retries <= 0 {
return response, err
return response, err, retried
}

retries--
retried++
time.Sleep(backoff)
backoff = backoff * backoffMultiplier
} else {
return response, err
return response, err, retried
}
}
}
Expand Down

0 comments on commit 3c9f008

Please sign in to comment.