From f870f9cbcb26ceb71d01bf263eaeaa53990bf816 Mon Sep 17 00:00:00 2001 From: Ivana Huckova <30407135+ivanahuckova@users.noreply.github.com> Date: Mon, 15 Jul 2024 13:59:12 +0200 Subject: [PATCH] Instrumentation: Always log with context (#929) --- pkg/infinity/client.go | 54 ++++++++++++++++++++---------------- pkg/infinity/googleSheets.go | 8 ++++-- pkg/infinity/jsonBackend.go | 3 +- pkg/infinity/postprocess.go | 5 ++-- pkg/infinity/remote.go | 5 ++-- pkg/infinity/request.go | 2 +- 6 files changed, 44 insertions(+), 33 deletions(-) diff --git a/pkg/infinity/client.go b/pkg/infinity/client.go index 4f037c7e..b72e86af 100644 --- a/pkg/infinity/client.go +++ b/pkg/infinity/client.go @@ -58,7 +58,8 @@ func GetTLSConfigFromSettings(settings models.InfinitySettings) (*tls.Config, er return tlsConfig, nil } -func getBaseHTTPClient(_ context.Context, settings models.InfinitySettings) *http.Client { +func getBaseHTTPClient(ctx context.Context, settings models.InfinitySettings) *http.Client { + logger := backend.Logger.FromContext(ctx) tlsConfig, err := GetTLSConfigFromSettings(settings) if err != nil { return nil @@ -66,12 +67,12 @@ func getBaseHTTPClient(_ context.Context, settings models.InfinitySettings) *htt transport := &http.Transport{TLSClientConfig: tlsConfig} switch settings.ProxyType { case models.ProxyTypeNone: - backend.Logger.Debug("proxy type is set to none. Not using the proxy") + logger.Debug("proxy type is set to none. Not using the proxy") case models.ProxyTypeUrl: - backend.Logger.Debug("proxy type is set to url. Using the proxy", "proxy_url", settings.ProxyUrl) + logger.Debug("proxy type is set to url. Using the proxy", "proxy_url", settings.ProxyUrl) u, err := url.Parse(settings.ProxyUrl) if err != nil { - backend.Logger.Error("error parsing proxy url", "err", err.Error(), "proxy_url", settings.ProxyUrl) + logger.Error("error parsing proxy url", "err", err.Error(), "proxy_url", settings.ProxyUrl) return nil } transport.Proxy = http.ProxyURL(u) @@ -86,6 +87,7 @@ func getBaseHTTPClient(_ context.Context, settings models.InfinitySettings) *htt } func NewClient(ctx context.Context, settings models.InfinitySettings) (client *Client, err error) { + logger := backend.Logger.FromContext(ctx) _, span := tracing.DefaultTracer().Start(ctx, "NewClient") defer span.End() if settings.AuthenticationMethod == "" { @@ -100,7 +102,7 @@ func NewClient(ctx context.Context, settings models.InfinitySettings) (client *C httpClient := getBaseHTTPClient(ctx, settings) if httpClient == nil { span.RecordError(errors.New("invalid http client")) - backend.Logger.Error("invalid http client", "datasource uid", settings.UID, "datasource name", settings.Name) + logger.Error("invalid http client", "datasource uid", settings.UID, "datasource name", settings.Name) return client, errors.New("invalid http client") } httpClient = ApplyDigestAuth(ctx, httpClient, settings) @@ -108,9 +110,9 @@ func NewClient(ctx context.Context, settings models.InfinitySettings) (client *C httpClient = ApplyOAuthJWT(ctx, httpClient, settings) httpClient = ApplyAWSAuth(ctx, httpClient, settings) - httpClient, err = ApplySecureSocksProxyConfiguration(httpClient, settings) + httpClient, err = ApplySecureSocksProxyConfiguration(ctx, httpClient, settings) if err != nil { - backend.Logger.Error("error applying secure socks proxy", "datasource uid", settings.UID, "datasource name", settings.Name) + logger.Error("error applying secure socks proxy", "datasource uid", settings.UID, "datasource name", settings.Name) return client, err } @@ -124,7 +126,7 @@ func NewClient(ctx context.Context, settings models.InfinitySettings) (client *C if err != nil { span.RecordError(err) span.SetStatus(500, err.Error()) - backend.Logger.Error("invalid azure blob credentials", "datasource uid", settings.UID, "datasource name", settings.Name) + logger.Error("invalid azure blob credentials", "datasource uid", settings.UID, "datasource name", settings.Name) return client, errors.New("invalid azure blob credentials") } clientUrl := "https://%s.blob.core.windows.net/" @@ -138,13 +140,13 @@ func NewClient(ctx context.Context, settings models.InfinitySettings) (client *C if err != nil { span.RecordError(err) span.SetStatus(500, err.Error()) - backend.Logger.Error("error creating azure blob client", "datasource uid", settings.UID, "datasource name", settings.Name) + logger.Error("error creating azure blob client", "datasource uid", settings.UID, "datasource name", settings.Name) return client, fmt.Errorf("error creating azure blob client. %s", err) } if azClient == nil { span.RecordError(errors.New("invalid/empty azure blob client")) span.SetStatus(500, "invalid/empty azure blob client") - backend.Logger.Error("invalid/empty azure blob client", "datasource uid", settings.UID, "datasource name", settings.Name) + logger.Error("invalid/empty azure blob client", "datasource uid", settings.UID, "datasource name", settings.Name) return client, errors.New("invalid/empty azure blob client") } client.AzureBlobClient = azClient @@ -155,7 +157,8 @@ func NewClient(ctx context.Context, settings models.InfinitySettings) (client *C return client, err } -func ApplySecureSocksProxyConfiguration(httpClient *http.Client, settings models.InfinitySettings) (*http.Client, error) { +func ApplySecureSocksProxyConfiguration(ctx context.Context, httpClient *http.Client, settings models.InfinitySettings) (*http.Client, error) { + logger := backend.Logger.FromContext(ctx) if IsAwsAuthConfigured(settings) { return httpClient, nil } @@ -171,7 +174,7 @@ func ApplySecureSocksProxyConfiguration(httpClient *http.Client, settings models // secure socks proxy configuration - checks if enabled inside the function err := proxy.New(settings.ProxyOpts.ProxyOptions).ConfigureSecureSocksHTTPProxy(t.(*http.Transport)) if err != nil { - backend.Logger.Error("error configuring secure socks proxy", "err", err.Error()) + logger.Error("error configuring secure socks proxy", "err", err.Error()) return nil, fmt.Errorf("error configuring secure socks proxy. %s", err) } return httpClient, nil @@ -191,29 +194,30 @@ func replaceSect(input string, settings models.InfinitySettings, includeSect boo func (client *Client) req(ctx context.Context, url string, body io.Reader, settings models.InfinitySettings, query models.Query, requestHeaders map[string]string) (obj any, statusCode int, duration time.Duration, err error) { ctx, span := tracing.DefaultTracer().Start(ctx, "client.req") + logger := backend.Logger.FromContext(ctx) defer span.End() req, _ := GetRequest(ctx, settings, body, query, requestHeaders, true) startTime := time.Now() if !CanAllowURL(req.URL.String(), settings.AllowedHosts) { - backend.Logger.Error("url is not in the allowed list. make sure to match the base URL with the settings", "url", req.URL.String()) + logger.Error("url is not in the allowed list. make sure to match the base URL with the settings", "url", req.URL.String()) return nil, http.StatusUnauthorized, 0, errorsource.DownstreamError(errors.New("requested URL is not allowed. To allow this URL, update the datasource config Security -> Allowed Hosts section"), false) } - backend.Logger.Debug("yesoreyeram-infinity-datasource plugin is now requesting URL", "url", req.URL.String()) + logger.Debug("yesoreyeram-infinity-datasource plugin is now requesting URL", "url", req.URL.String()) res, err := client.HttpClient.Do(req) duration = time.Since(startTime) if res != nil { defer res.Body.Close() } if err != nil && res != nil { - backend.Logger.Error("error getting response from server", "url", url, "method", req.Method, "error", err.Error(), "status code", res.StatusCode) + logger.Error("error getting response from server", "url", url, "method", req.Method, "error", err.Error(), "status code", res.StatusCode) return nil, res.StatusCode, duration, errorsource.SourceError(backend.ErrorSourceFromHTTPStatus(res.StatusCode), fmt.Errorf("error getting response from %s", url), false) } if err != nil && res == nil { - backend.Logger.Error("error getting response from server. no response received", "url", url, "error", err.Error()) + logger.Error("error getting response from server. no response received", "url", url, "error", err.Error()) return nil, http.StatusInternalServerError, duration, errorsource.DownstreamError(fmt.Errorf("error getting response from url %s. no response received. Error: %w", url, err), false) } if err == nil && res == nil { - backend.Logger.Error("invalid response from server and also no error", "url", url, "method", req.Method) + logger.Error("invalid response from server and also no error", "url", url, "method", req.Method) return nil, http.StatusInternalServerError, duration, errorsource.DownstreamError(fmt.Errorf("invalid response received for the URL %s", url), false) } if res.StatusCode >= http.StatusBadRequest { @@ -221,7 +225,7 @@ func (client *Client) req(ctx context.Context, url string, body io.Reader, setti } bodyBytes, err := io.ReadAll(res.Body) if err != nil { - backend.Logger.Error("error reading response body", "url", url, "error", err.Error()) + logger.Error("error reading response body", "url", url, "error", err.Error()) return nil, res.StatusCode, duration, errorsource.DownstreamError(err, false) } bodyBytes = removeBOMContent(bodyBytes) @@ -230,7 +234,7 @@ func (client *Client) req(ctx context.Context, url string, body io.Reader, setti err := json.Unmarshal(bodyBytes, &out) if err != nil { err = errorsource.PluginError(err, false) - backend.Logger.Error("error un-marshaling JSON response", "url", url, "error", err.Error()) + logger.Error("error un-marshaling JSON response", "url", url, "error", err.Error()) } return out, res.StatusCode, duration, err } @@ -243,6 +247,7 @@ func removeBOMContent(input []byte) []byte { } func (client *Client) GetResults(ctx context.Context, query models.Query, requestHeaders map[string]string) (o any, statusCode int, duration time.Duration, err error) { + logger := backend.Logger.FromContext(ctx) if query.Source == "azure-blob" { if strings.TrimSpace(query.AzBlobContainerName) == "" || strings.TrimSpace(query.AzBlobName) == "" { return nil, http.StatusBadRequest, 0, errorsource.DownstreamError(errors.New("invalid/empty container name/blob name"), false) @@ -264,7 +269,7 @@ func (client *Client) GetResults(ctx context.Context, query models.Query, reques var out any err := json.Unmarshal(bodyBytes, &out) if err != nil { - backend.Logger.Error("error un-marshaling blob content", "error", err.Error()) + logger.Error("error un-marshaling blob content", "error", err.Error()) err = errorsource.PluginError(err, false) } return out, http.StatusOK, duration, err @@ -273,7 +278,7 @@ func (client *Client) GetResults(ctx context.Context, query models.Query, reques } switch strings.ToUpper(query.URLOptions.Method) { case http.MethodPost: - body := GetQueryBody(query) + body := GetQueryBody(ctx, query) return client.req(ctx, query.URL, body, client.Settings, query, requestHeaders) default: return client.req(ctx, query.URL, nil, client.Settings, query, requestHeaders) @@ -306,7 +311,8 @@ func CanAllowURL(url string, allowedHosts []string) bool { return allow } -func GetQueryBody(query models.Query) io.Reader { +func GetQueryBody(ctx context.Context, query models.Query) io.Reader { + logger := backend.Logger.FromContext(ctx) var body io.Reader if strings.EqualFold(query.URLOptions.Method, http.MethodPost) { switch query.URLOptions.BodyType { @@ -319,7 +325,7 @@ func GetQueryBody(query models.Query) io.Reader { _ = writer.WriteField(f.Key, f.Value) } if err := writer.Close(); err != nil { - backend.Logger.Error("error closing the query body reader") + logger.Error("error closing the query body reader") return nil } body = payload @@ -334,7 +340,7 @@ func GetQueryBody(query models.Query) io.Reader { if query.URLOptions.BodyGraphQLVariables != "" { err := json.Unmarshal([]byte(query.URLOptions.BodyGraphQLVariables), &variables) if err != nil { - backend.Logger.Error("Error parsing graphql variable json", err) + logger.Error("Error parsing graphql variable json", err) } } jsonData := map[string]interface{}{ diff --git a/pkg/infinity/googleSheets.go b/pkg/infinity/googleSheets.go index b5279ece..22873ddf 100644 --- a/pkg/infinity/googleSheets.go +++ b/pkg/infinity/googleSheets.go @@ -1,6 +1,7 @@ package infinity import ( + "context" "encoding/json" "errors" "fmt" @@ -38,11 +39,12 @@ type CellData struct { NullFields []string `json:"-"` } -func GetGoogleSheetsResponse(urlResponseObject any, query models.Query) (*data.Frame, error) { +func GetGoogleSheetsResponse(ctx context.Context, urlResponseObject any, query models.Query) (*data.Frame, error) { + logger := backend.Logger.FromContext(ctx) frame := GetDummyFrame(query) sheetsString, ok := urlResponseObject.(string) if !ok { - backend.Logger.Error("error getting response for query", "error", "invalid response received from google sheets") + logger.Error("error getting response for query", "error", "invalid response received from google sheets") frame.Meta.Custom = &CustomMeta{ Query: query, Error: "invalid response received from google sheets", @@ -51,7 +53,7 @@ func GetGoogleSheetsResponse(urlResponseObject any, query models.Query) (*data.F } sheet := &Spreadsheet{} if err := json.Unmarshal([]byte(sheetsString), &sheet); err != nil { - backend.Logger.Error("error getting response for query", "error", "invalid response received from google sheets") + logger.Error("error getting response for query", "error", "invalid response received from google sheets") frame.Meta.Custom = &CustomMeta{ Query: query, Error: "invalid response received from google sheets", diff --git a/pkg/infinity/jsonBackend.go b/pkg/infinity/jsonBackend.go index e31421f2..88b7a49e 100644 --- a/pkg/infinity/jsonBackend.go +++ b/pkg/infinity/jsonBackend.go @@ -15,11 +15,12 @@ import ( func GetJSONBackendResponse(ctx context.Context, urlResponseObject any, query models.Query) (*data.Frame, error) { _, span := tracing.DefaultTracer().Start(ctx, "GetJSONBackendResponse") + logger := backend.Logger.FromContext(ctx) defer span.End() frame := GetDummyFrame(query) responseString, err := json.Marshal(urlResponseObject) if err != nil { - backend.Logger.Error("error json parsing root data", "error", err.Error()) + logger.Error("error json parsing root data", "error", err.Error()) frame.Meta.Custom = &CustomMeta{Query: query, Error: err.Error()} return frame, errorsource.PluginError(fmt.Errorf("error parsing json root data"), false) } diff --git a/pkg/infinity/postprocess.go b/pkg/infinity/postprocess.go index 4a1dc519..e980565b 100644 --- a/pkg/infinity/postprocess.go +++ b/pkg/infinity/postprocess.go @@ -15,6 +15,7 @@ import ( func PostProcessFrame(ctx context.Context, frame *data.Frame, query models.Query) (*data.Frame, error) { ctx, span := tracing.DefaultTracer().Start(ctx, "PostProcessFrame") + logger := backend.Logger.FromContext(ctx) defer span.End() cc := []transformations.ComputedColumn{} for _, c := range query.ComputedColumns { @@ -22,13 +23,13 @@ func PostProcessFrame(ctx context.Context, frame *data.Frame, query models.Query } frame, err := transformations.GetFrameWithComputedColumns(frame, cc) if err != nil { - backend.Logger.Error("error getting computed column", "error", err.Error()) + logger.Error("error getting computed column", "error", err.Error()) frame.Meta.Custom = &CustomMeta{Query: query, Error: err.Error()} return frame, errorsource.PluginError(err, false) } frame, err = transformations.ApplyFilter(frame, query.FilterExpression) if err != nil { - backend.Logger.Error("error applying filter", "error", err.Error()) + logger.Error("error applying filter", "error", err.Error()) frame.Meta.Custom = &CustomMeta{Query: query, Error: err.Error()} return frame, errorsource.PluginError(fmt.Errorf("error applying filter. %w", err), false) } diff --git a/pkg/infinity/remote.go b/pkg/infinity/remote.go index 1ac28aa2..24ee28d6 100644 --- a/pkg/infinity/remote.go +++ b/pkg/infinity/remote.go @@ -137,6 +137,7 @@ func ApplyPaginationItemToQuery(currentQuery models.Query, fieldType models.Pagi func GetFrameForURLSourcesWithPostProcessing(ctx context.Context, query models.Query, infClient Client, requestHeaders map[string]string, postProcessingRequired bool) (*data.Frame, string, error) { ctx, span := tracing.DefaultTracer().Start(ctx, "GetFrameForURLSourcesWithPostProcessing") + logger := backend.Logger.FromContext(ctx) defer span.End() frame := GetDummyFrame(query) cursor := "" @@ -158,7 +159,7 @@ func GetFrameForURLSourcesWithPostProcessing(ctx context.Context, query models.Q return frame, cursor, err } if query.Type == models.QueryTypeGSheets { - if frame, err = GetGoogleSheetsResponse(urlResponseObject, query); err != nil { + if frame, err = GetGoogleSheetsResponse(ctx, urlResponseObject, query); err != nil { return frame, cursor, err } } @@ -200,7 +201,7 @@ func GetFrameForURLSourcesWithPostProcessing(ctx context.Context, query models.Q Duration: duration, } if err != nil { - backend.Logger.Error("error getting response for query", "error", err.Error()) + logger.Error("error getting response for query", "error", err.Error()) frame.Meta.Custom = &CustomMeta{ Data: urlResponseObject, ResponseCodeFromServer: statusCode, diff --git a/pkg/infinity/request.go b/pkg/infinity/request.go index f481e418..6e3985ea 100644 --- a/pkg/infinity/request.go +++ b/pkg/infinity/request.go @@ -95,7 +95,7 @@ func NormalizeURL(u string) string { func (client *Client) GetExecutedURL(ctx context.Context, query models.Query) string { out := []string{} if query.Source != "inline" && query.Source != "azure-blob" { - req, err := GetRequest(ctx, client.Settings, GetQueryBody(query), query, map[string]string{}, false) + req, err := GetRequest(ctx, client.Settings, GetQueryBody(ctx, query), query, map[string]string{}, false) if err != nil { return fmt.Sprintf("error retrieving full url. %s", query.URL) }