From 171765c8c58a3ffde4c1e1a0a783dc6015eb09bd Mon Sep 17 00:00:00 2001 From: Teodora Sandu Date: Mon, 15 Apr 2024 18:00:17 +0100 Subject: [PATCH] refactor: logging improvements --- http/http.go | 28 +++++++----- internal/analysis/analysis.go | 12 ++++- internal/analysis/analysis_test.go | 73 +++++++++++++++++++++++++++++- 3 files changed, 98 insertions(+), 15 deletions(-) diff --git a/http/http.go b/http/http.go index e94abd9a..4000a260 100644 --- a/http/http.go +++ b/http/http.go @@ -104,16 +104,7 @@ func (s *httpClient) Do(req *http.Request) (response *http.Response, err error) requestId := span.GetTraceId() req.Header.Set("snyk-request-id", requestId) - s.logger.Trace().Str("snyk-request-id", requestId).Msg("SEND TO REMOTE") - response, err = s.httpCall(req) - - if response != nil { - s.logger.Trace().Str("response.Status", response.Status).Str("snyk-request-id", requestId).Msg("RECEIVED FROM REMOTE") - } else { - s.logger.Trace().Str("snyk-request-id", requestId).Msg("RECEIVED FROM REMOTE") - } - if err != nil { return nil, err // no retries for errors } @@ -134,17 +125,30 @@ func (s *httpClient) Do(req *http.Request) (response *http.Response, err error) func (s *httpClient) httpCall(req *http.Request) (*http.Response, error) { log := s.logger.With().Str("method", "http.httpCall").Logger() + requestId := req.Header.Get("snyk-request-id") // store the request body so that after retrying it can be read again var copyReqBody io.ReadCloser + var reqBuf []byte if req.Body != nil { - buf, _ := io.ReadAll(req.Body) - reqBody := io.NopCloser(bytes.NewBuffer(buf)) - copyReqBody = io.NopCloser(bytes.NewBuffer(buf)) + reqBuf, _ = io.ReadAll(req.Body) + reqBody := io.NopCloser(bytes.NewBuffer(reqBuf)) + copyReqBody = io.NopCloser(bytes.NewBuffer(reqBuf)) req.Body = reqBody + s.logger.Debug().Str("url", req.URL.String()).Str("snyk-request-id", requestId).Str("requestBody", string(reqBuf)).Msg("SEND TO REMOTE") } response, err := s.clientFactory().Do(req) req.Body = copyReqBody + if response != nil { + var copyResBody io.ReadCloser + var resBuf []byte + resBuf, _ = io.ReadAll(response.Body) + copyResBody = io.NopCloser(bytes.NewBuffer(resBuf)) + response.Body = copyResBody + s.logger.Debug().Str("url", req.URL.String()).Str("response.Status", response.Status).Str("snyk-request-id", requestId).Str("responseBody", string(resBuf)).Msg("RECEIVED FROM REMOTE") + } else { + s.logger.Debug().Str("url", req.URL.String()).Str("snyk-request-id", requestId).Msg("RECEIVED FROM REMOTE") + } if err != nil { log.Error().Err(err).Msg("got http error") diff --git a/internal/analysis/analysis.go b/internal/analysis/analysis.go index 980dc072..c0345177 100644 --- a/internal/analysis/analysis.go +++ b/internal/analysis/analysis.go @@ -32,6 +32,7 @@ import ( externalRef3 "github.com/snyk/code-client-go/internal/workspace/2024-03-12/workspaces" "github.com/snyk/code-client-go/observability" "github.com/snyk/code-client-go/sarif" + "strings" ) //go:embed fake.json @@ -83,9 +84,10 @@ func (a *analysisOrchestrator) CreateWorkspace(ctx context.Context, orgId string return "", fmt.Errorf("workspace is not a repository, cannot scan, %w", err) } - a.logger.Info().Str("path", path).Str("repositoryUri", repositoryUri).Str("bundleHash", bundleHash).Msg("creating workspace") + host := a.host() + a.logger.Info().Str("host", host).Str("path", path).Str("repositoryUri", repositoryUri).Msg("creating workspace") - workspace, err := workspaceClient.NewClientWithResponses(fmt.Sprintf("%s/hidden", a.config.SnykApi()), workspaceClient.WithHTTPClient(a.httpClient)) + workspace, err := workspaceClient.NewClientWithResponses(host, workspaceClient.WithHTTPClient(a.httpClient)) if err != nil { a.errorReporter.CaptureError(err, observability.ErrorReporterOptions{ErrorDiagnosticPath: path}) return "", fmt.Errorf("failed to connect to the workspace API %w", err) @@ -128,6 +130,7 @@ func (a *analysisOrchestrator) CreateWorkspace(ctx context.Context, orgId string }), }) if err != nil { + a.logger.Error().Err(err).Msg("could not create workspace") return "", err } @@ -158,3 +161,8 @@ func (*analysisOrchestrator) RunAnalysis() (*sarif.SarifResponse, error) { } return &response, nil } + +func (a *analysisOrchestrator) host() string { + apiUrl := strings.TrimRight(a.config.SnykApi(), "/") + return fmt.Sprintf("%s/hidden", apiUrl) +} diff --git a/internal/analysis/analysis_test.go b/internal/analysis/analysis_test.go index 689ab8c5..cc95e675 100644 --- a/internal/analysis/analysis_test.go +++ b/internal/analysis/analysis_test.go @@ -18,6 +18,7 @@ package analysis_test import ( "bytes" "context" + "fmt" "github.com/stretchr/testify/mock" "io" "net/http" @@ -104,7 +105,8 @@ func TestAnalysis_CreateWorkspace_NotARepository(t *testing.T) { "4a72d1db-b465-4764-99e1-ecedad03b06a", "b372d1db-b465-4764-99e1-ecedad03b06a", repoDir, - "testBundleHash") + "testBundleHash", + ) assert.ErrorContains(t, err, "open local repository") } @@ -151,6 +153,75 @@ func TestAnalysis_CreateWorkspace_Failure(t *testing.T) { assert.ErrorContains(t, err, "error detail") } +func TestAnalysis_CreateWorkspace_KnownErrors(t *testing.T) { + type testCase struct { + name string + expectedStatus int + expectedError string + } + + testCases := []testCase{ + { + name: "StatusBadRequest", + expectedStatus: http.StatusBadRequest, + expectedError: "400", + }, + { + name: "StatusUnauthorized", + expectedStatus: http.StatusUnauthorized, + expectedError: "401", + }, + { + name: "StatusForbidden", + expectedStatus: http.StatusForbidden, + expectedError: "403", + }, + { + name: "StatusInternalServerError", + expectedStatus: http.StatusInternalServerError, + expectedError: "500", + }, + } + + for _, tc := range testCases { + t.Run(tc.name, func(t *testing.T) { + ctrl := gomock.NewController(t) + mockSpan := mocks.NewMockSpan(ctrl) + mockSpan.EXPECT().GetTraceId().AnyTimes() + mockSpan.EXPECT().Context().AnyTimes() + mockConfig := confMocks.NewMockConfig(ctrl) + mockConfig.EXPECT().Organization().AnyTimes().Return("") + mockConfig.EXPECT().SnykApi().AnyTimes().Return("http://localhost") + + mockHTTPClient := httpmocks.NewMockHTTPClient(ctrl) + mockHTTPClient.EXPECT().Do(gomock.Any()).Times(1).Return(&http.Response{ + StatusCode: tc.expectedStatus, + Header: http.Header{ + "Content-Type": []string{"application/vnd.api+json"}, + }, + Body: io.NopCloser(bytes.NewReader([]byte(fmt.Sprintf(`{"jsonapi":{"version":"1.0"},"errors":[{"id":"05ebb47a-631a-485a-8db6-5ed0b3943eb0","detail":"%s"}]}`, tc.expectedError)))), + }, nil) + + mockInstrumentor := mocks.NewMockInstrumentor(ctrl) + mockInstrumentor.EXPECT().StartSpan(gomock.Any(), gomock.Any()).Return(mockSpan).AnyTimes() + mockInstrumentor.EXPECT().Finish(gomock.Any()).AnyTimes() + mockErrorReporter := mocks.NewMockErrorReporter(ctrl) + + logger := zerolog.Nop() + + analysisOrchestrator := analysis.NewAnalysisOrchestrator(&logger, mockHTTPClient, mockInstrumentor, mockErrorReporter, mockConfig) + _, err := analysisOrchestrator.CreateWorkspace( + context.Background(), + "4a72d1db-b465-4764-99e1-ecedad03b06a", + "b372d1db-b465-4764-99e1-ecedad03b06a", + "../../", + "testBundleHash", + ) + assert.ErrorContains(t, err, tc.expectedError) + }) + } +} + func TestAnalysis_RunAnalysis(t *testing.T) { ctrl := gomock.NewController(t) mockSpan := mocks.NewMockSpan(ctrl)