From 09ce0e5791d1a8dc608cb17e3a3e220faff91f60 Mon Sep 17 00:00:00 2001 From: Mahmood Ali Date: Fri, 4 Oct 2019 15:39:59 -0400 Subject: [PATCH 1/2] agent: report fs log errors as http errors This fixes two bugs: First, FS Logs API endpoint only propagated error back to user if it was encoded with code, which isn't common. Other errors get suppressed and callers get an empty response with 200 error code. Now, these endpoints return a 500 status code along with the error message. Before ``` $ curl -v "http://127.0.0.1:4646/v1/client/fs/logs/qwerqwera?follow=false&offset=0&origin=start®ion=global&task=redis&type=stdout"; echo * Trying 127.0.0.1... * TCP_NODELAY set * Connected to 127.0.0.1 (127.0.0.1) port 4646 (#0) > GET /v1/client/fs/logs/qwerqwera?follow=false&offset=0&origin=start®ion=global&task=redis&type=stdout HTTP/1.1 > Host: 127.0.0.1:4646 > User-Agent: curl/7.54.0 > Accept: */* > < HTTP/1.1 200 OK < Vary: Accept-Encoding < Vary: Origin < Date: Fri, 04 Oct 2019 19:47:21 GMT < Content-Length: 0 < * Connection #0 to host 127.0.0.1 left intact ``` After ``` $ curl -v "http://127.0.0.1:4646/v1/client/fs/logs/qwerqwera?follow=false&offset=0&origin=start®ion=global&task=redis&type=stdout"; echo * Trying 127.0.0.1... * TCP_NODELAY set * Connected to 127.0.0.1 (127.0.0.1) port 4646 (#0) > GET /v1/client/fs/logs/qwerqwera?follow=false&offset=0&origin=start®ion=global&task=redis&type=stdout HTTP/1.1 > Host: 127.0.0.1:4646 > User-Agent: curl/7.54.0 > Accept: */* > < HTTP/1.1 500 Internal Server Error < Vary: Accept-Encoding < Vary: Origin < Date: Fri, 04 Oct 2019 19:48:12 GMT < Content-Length: 60 < Content-Type: text/plain; charset=utf-8 < * Connection #0 to host 127.0.0.1 left intact alloc lookup failed: index error: UUID must be 36 characters ``` Second, we return 400 status code for request validation errors. Before ``` $ curl -v "http://127.0.0.1:4646/v1/client/fs/logs/qwerqwera"; echo * Trying 127.0.0.1... * TCP_NODELAY set * Connected to 127.0.0.1 (127.0.0.1) port 4646 (#0) > GET /v1/client/fs/logs/qwerqwera HTTP/1.1 > Host: 127.0.0.1:4646 > User-Agent: curl/7.54.0 > Accept: */* > < HTTP/1.1 500 Internal Server Error < Vary: Accept-Encoding < Vary: Origin < Date: Fri, 04 Oct 2019 19:47:29 GMT < Content-Length: 22 < Content-Type: text/plain; charset=utf-8 < * Connection #0 to host 127.0.0.1 left intact must provide task name ``` After ``` $ curl -v "http://127.0.0.1:4646/v1/client/fs/logs/qwerqwera"; echo * Trying 127.0.0.1... * TCP_NODELAY set * Connected to 127.0.0.1 (127.0.0.1) port 4646 (#0) > GET /v1/client/fs/logs/qwerqwera HTTP/1.1 > Host: 127.0.0.1:4646 > User-Agent: curl/7.54.0 > Accept: */* > < HTTP/1.1 400 Bad Request < Vary: Accept-Encoding < Vary: Origin < Date: Fri, 04 Oct 2019 19:49:18 GMT < Content-Length: 22 < Content-Type: text/plain; charset=utf-8 < * Connection #0 to host 127.0.0.1 left intact must provide task name ``` --- command/agent/fs_endpoint.go | 25 +++++++++------- command/agent/fs_endpoint_test.go | 50 +++++++++++++++++++++++-------- 2 files changed, 51 insertions(+), 24 deletions(-) diff --git a/command/agent/fs_endpoint.go b/command/agent/fs_endpoint.go index f36f3be8edbb..4a99a2531df9 100644 --- a/command/agent/fs_endpoint.go +++ b/command/agent/fs_endpoint.go @@ -17,12 +17,12 @@ import ( ) var ( - allocIDNotPresentErr = fmt.Errorf("must provide a valid alloc id") - fileNameNotPresentErr = fmt.Errorf("must provide a file name") - taskNotPresentErr = fmt.Errorf("must provide task name") - logTypeNotPresentErr = fmt.Errorf("must provide log type (stdout/stderr)") - clientNotRunning = fmt.Errorf("node is not running a Nomad Client") - invalidOrigin = fmt.Errorf("origin must be start or end") + allocIDNotPresentErr = CodedError(400, "must provide a valid alloc id") + fileNameNotPresentErr = CodedError(400, "must provide a file name") + taskNotPresentErr = CodedError(400, "must provide task name") + logTypeNotPresentErr = CodedError(400, "must provide log type (stdout/stderr)") + clientNotRunning = CodedError(400, "node is not running a Nomad Client") + invalidOrigin = CodedError(400, "origin must be start or end") ) func (s *HTTPServer) FsRequest(resp http.ResponseWriter, req *http.Request) (interface{}, error) { @@ -273,13 +273,13 @@ func (s *HTTPServer) Logs(resp http.ResponseWriter, req *http.Request) (interfac if followStr := q.Get("follow"); followStr != "" { if follow, err = strconv.ParseBool(followStr); err != nil { - return nil, fmt.Errorf("failed to parse follow field to boolean: %v", err) + return nil, CodedError(400, fmt.Sprintf("failed to parse follow field to boolean: %v", err)) } } if plainStr := q.Get("plain"); plainStr != "" { if plain, err = strconv.ParseBool(plainStr); err != nil { - return nil, fmt.Errorf("failed to parse plain field to boolean: %v", err) + return nil, CodedError(400, fmt.Sprintf("failed to parse plain field to boolean: %v", err)) } } @@ -295,7 +295,7 @@ func (s *HTTPServer) Logs(resp http.ResponseWriter, req *http.Request) (interfac if offsetString != "" { var err error if offset, err = strconv.ParseInt(offsetString, 10, 64); err != nil { - return nil, fmt.Errorf("error parsing offset: %v", err) + return nil, CodedError(400, fmt.Sprintf("error parsing offset: %v", err)) } } @@ -388,10 +388,13 @@ func (s *HTTPServer) fsStreamImpl(resp http.ResponseWriter, decoder.Reset(httpPipe) if err := res.Error; err != nil { + code := 500 if err.Code != nil { - errCh <- CodedError(int(*err.Code), err.Error()) - return + code = int(*err.Code) } + + errCh <- CodedError(code, err.Error()) + return } if _, err := io.Copy(output, bytes.NewReader(res.Payload)); err != nil { diff --git a/command/agent/fs_endpoint_test.go b/command/agent/fs_endpoint_test.go index e131c990a77d..98c154f12b3a 100644 --- a/command/agent/fs_endpoint_test.go +++ b/command/agent/fs_endpoint_test.go @@ -12,6 +12,7 @@ import ( "time" cstructs "github.com/hashicorp/nomad/client/structs" + "github.com/hashicorp/nomad/helper/uuid" "github.com/hashicorp/nomad/nomad/mock" "github.com/hashicorp/nomad/nomad/structs" "github.com/hashicorp/nomad/testutil" @@ -189,25 +190,26 @@ func TestHTTP_FS_Stream_MissingParams(t *testing.T) { require := require.New(t) httpTest(t, nil, func(s *TestAgent) { req, err := http.NewRequest("GET", "/v1/client/fs/stream/", nil) - require.Nil(err) + require.NoError(err) respW := httptest.NewRecorder() _, err = s.Server.Stream(respW, req) require.EqualError(err, allocIDNotPresentErr.Error()) req, err = http.NewRequest("GET", "/v1/client/fs/stream/foo", nil) - require.Nil(err) + require.NoError(err) respW = httptest.NewRecorder() _, err = s.Server.Stream(respW, req) require.EqualError(err, fileNameNotPresentErr.Error()) req, err = http.NewRequest("GET", "/v1/client/fs/stream/foo?path=/path/to/file", nil) - require.Nil(err) + require.NoError(err) respW = httptest.NewRecorder() _, err = s.Server.Stream(respW, req) - require.Nil(err) + require.Error(err) + require.Contains(err.Error(), "alloc lookup failed") }) } @@ -219,38 +221,39 @@ func TestHTTP_FS_Logs_MissingParams(t *testing.T) { httpTest(t, nil, func(s *TestAgent) { // AllocID Not Present req, err := http.NewRequest("GET", "/v1/client/fs/logs/", nil) - require.Nil(err) + require.NoError(err) respW := httptest.NewRecorder() s.Server.mux.ServeHTTP(respW, req) require.Equal(respW.Body.String(), allocIDNotPresentErr.Error()) - require.Equal(500, respW.Code) // 500 for backward compat + require.Equal(400, respW.Code) // Task Not Present req, err = http.NewRequest("GET", "/v1/client/fs/logs/foo", nil) - require.Nil(err) + require.NoError(err) respW = httptest.NewRecorder() s.Server.mux.ServeHTTP(respW, req) require.Equal(respW.Body.String(), taskNotPresentErr.Error()) - require.Equal(500, respW.Code) // 500 for backward compat + require.Equal(400, respW.Code) // Log Type Not Present req, err = http.NewRequest("GET", "/v1/client/fs/logs/foo?task=foo", nil) - require.Nil(err) + require.NoError(err) respW = httptest.NewRecorder() s.Server.mux.ServeHTTP(respW, req) require.Equal(respW.Body.String(), logTypeNotPresentErr.Error()) - require.Equal(500, respW.Code) // 500 for backward compat + require.Equal(400, respW.Code) - // Ok + // case where all parameters are set but alloc isn't found req, err = http.NewRequest("GET", "/v1/client/fs/logs/foo?task=foo&type=stdout", nil) - require.Nil(err) + require.NoError(err) respW = httptest.NewRecorder() s.Server.mux.ServeHTTP(respW, req) - require.Equal(200, respW.Code) + require.Equal(500, respW.Code) + require.Contains(respW.Body.String(), "alloc lookup failed") }) } @@ -518,3 +521,24 @@ func TestHTTP_FS_Logs_Follow(t *testing.T) { p.Close() }) } + +func TestHTTP_FS_Logs_PropagatesErrors(t *testing.T) { + t.Parallel() + httpTest(t, nil, func(s *TestAgent) { + path := fmt.Sprintf("/v1/client/fs/logs/%s?type=stdout&task=web&offset=0&origin=end&plain=true", + uuid.Generate()) + + p, _ := io.Pipe() + defer p.Close() + + req, err := http.NewRequest("GET", path, p) + require.NoError(t, err) + respW := testutil.NewResponseRecorder() + + _, err = s.Server.Logs(respW, req) + require.Error(t, err) + + _, ok := err.(HTTPCodedError) + require.Truef(t, ok, "expected a coded error but found: %#+v", err) + }) +} From 5282353e223516a4fdf3923efc3bb4138eadda0c Mon Sep 17 00:00:00 2001 From: Mahmood Ali Date: Tue, 15 Oct 2019 17:22:03 -0400 Subject: [PATCH 2/2] tests: avoid using unnecessary pipe --- command/agent/fs_endpoint_test.go | 27 +++++---------------------- 1 file changed, 5 insertions(+), 22 deletions(-) diff --git a/command/agent/fs_endpoint_test.go b/command/agent/fs_endpoint_test.go index 98c154f12b3a..67cda129fd17 100644 --- a/command/agent/fs_endpoint_test.go +++ b/command/agent/fs_endpoint_test.go @@ -3,7 +3,6 @@ package agent import ( "encoding/base64" "fmt" - "io" "io/ioutil" "net/http" "net/http/httptest" @@ -357,8 +356,7 @@ func TestHTTP_FS_Stream_NoFollow(t *testing.T) { path := fmt.Sprintf("/v1/client/fs/stream/%s?path=alloc/logs/web.stdout.0&offset=%d&origin=end&follow=false", a.ID, offset) - p, _ := io.Pipe() - req, err := http.NewRequest("GET", path, p) + req, err := http.NewRequest("GET", path, nil) require.Nil(err) respW := testutil.NewResponseRecorder() doneCh := make(chan struct{}) @@ -386,8 +384,6 @@ func TestHTTP_FS_Stream_NoFollow(t *testing.T) { case <-time.After(1 * time.Second): t.Fatal("should close but did not") } - - p.Close() }) } @@ -404,9 +400,7 @@ func TestHTTP_FS_Stream_Follow(t *testing.T) { path := fmt.Sprintf("/v1/client/fs/stream/%s?path=alloc/logs/web.stdout.0&offset=%d&origin=end", a.ID, offset) - p, _ := io.Pipe() - - req, err := http.NewRequest("GET", path, p) + req, err := http.NewRequest("GET", path, nil) require.Nil(err) respW := httptest.NewRecorder() doneCh := make(chan struct{}) @@ -434,8 +428,6 @@ func TestHTTP_FS_Stream_Follow(t *testing.T) { t.Fatal("shouldn't close") case <-time.After(1 * time.Second): } - - p.Close() }) } @@ -451,8 +443,7 @@ func TestHTTP_FS_Logs(t *testing.T) { path := fmt.Sprintf("/v1/client/fs/logs/%s?type=stdout&task=web&offset=%d&origin=end&plain=true", a.ID, offset) - p, _ := io.Pipe() - req, err := http.NewRequest("GET", path, p) + req, err := http.NewRequest("GET", path, nil) require.Nil(err) respW := testutil.NewResponseRecorder() go func() { @@ -472,8 +463,6 @@ func TestHTTP_FS_Logs(t *testing.T) { }, func(err error) { t.Fatal(err) }) - - p.Close() }) } @@ -489,8 +478,7 @@ func TestHTTP_FS_Logs_Follow(t *testing.T) { path := fmt.Sprintf("/v1/client/fs/logs/%s?type=stdout&task=web&offset=%d&origin=end&plain=true&follow=true", a.ID, offset) - p, _ := io.Pipe() - req, err := http.NewRequest("GET", path, p) + req, err := http.NewRequest("GET", path, nil) require.Nil(err) respW := testutil.NewResponseRecorder() errCh := make(chan error) @@ -517,8 +505,6 @@ func TestHTTP_FS_Logs_Follow(t *testing.T) { t.Fatalf("shouldn't exit: %v", err) case <-time.After(1 * time.Second): } - - p.Close() }) } @@ -528,10 +514,7 @@ func TestHTTP_FS_Logs_PropagatesErrors(t *testing.T) { path := fmt.Sprintf("/v1/client/fs/logs/%s?type=stdout&task=web&offset=0&origin=end&plain=true", uuid.Generate()) - p, _ := io.Pipe() - defer p.Close() - - req, err := http.NewRequest("GET", path, p) + req, err := http.NewRequest("GET", path, nil) require.NoError(t, err) respW := testutil.NewResponseRecorder()