diff --git a/pkg/graphql/graphql.go b/pkg/graphql/graphql.go index 24f3fcb..a5cd529 100644 --- a/pkg/graphql/graphql.go +++ b/pkg/graphql/graphql.go @@ -2,6 +2,7 @@ package graphql import ( "bytes" + "context" "encoding/json" "fmt" "io" @@ -15,6 +16,36 @@ import ( "github.com/stackql/any-sdk/pkg/stream_transform" ) +// httpLoggerCtxKey is the context key under which an optional io.Writer is +// attached so the GraphQL reader can emit the wire request body and the raw +// pre-transform response. Mirrors the REST acquire path which writes the same +// shape of lines to runtimeCtx.outErrFile when --http.log.enabled is set. +type httpLoggerCtxKey struct{} + +// ContextWithHTTPLogger returns a derived context that carries w as the sink +// for GraphQL wire request / raw response log lines. Consumers (e.g. stackql) +// should attach the same writer they use for REST HTTP logging when +// --http.log.enabled is true. Passing a nil writer is equivalent to not +// attaching one. +func ContextWithHTTPLogger(ctx context.Context, w io.Writer) context.Context { + if w == nil { + return ctx + } + return context.WithValue(ctx, httpLoggerCtxKey{}, w) +} + +func httpLoggerFromContext(ctx context.Context) io.Writer { + if ctx == nil { + return nil + } + v := ctx.Value(httpLoggerCtxKey{}) + if v == nil { + return nil + } + w, _ := v.(io.Writer) + return w +} + var ( _ template.ExecError = template.ExecError{} ) @@ -298,6 +329,14 @@ func (gq *StandardGQLReader) Read() ([]map[string]interface{}, error) { req.Body = rb req.URL.RawQuery = "" req.Header.Set("Content-Type", "application/json") + if logger := httpLoggerFromContext(req.Context()); logger != nil { + bodyBytes, readErr := io.ReadAll(req.Body) + if readErr == nil { + req.Body = io.NopCloser(bytes.NewReader(bodyBytes)) + fmt.Fprintf(logger, "http request url: '%s', method: '%s'\n", req.URL.String(), req.Method) + fmt.Fprintf(logger, "http request body = '%s'\n", string(bodyBytes)) + } + } r, err := gq.anySdkClient.Do( newAnySdkGraphQLHTTPDesignation(req.URL), newGraphqlAnySdkArgList(newAnySdkHTTPArg(req)), @@ -309,6 +348,13 @@ func (gq *StandardGQLReader) Read() ([]map[string]interface{}, error) { if httpResponseErr != nil { return nil, httpResponseErr } + if logger := httpLoggerFromContext(req.Context()); logger != nil && httpResponse != nil && httpResponse.Body != nil { + respBytes, readErr := io.ReadAll(httpResponse.Body) + if readErr == nil { + httpResponse.Body = io.NopCloser(bytes.NewReader(respBytes)) + fmt.Fprintf(logger, "%s\n", string(respBytes)) + } + } gq.pageCount++ var target map[string]interface{} err = json.NewDecoder(httpResponse.Body).Decode(&target) @@ -340,11 +386,11 @@ func (gq *StandardGQLReader) Read() ([]map[string]interface{}, error) { case map[string]interface{}: rv = append(rv, v) default: - return nil, fmt.Errorf("cannot accomodate GraphQL pocessed response item of type = '%T'", v) + return nil, fmt.Errorf("cannot accommodate GraphQL processed response item of type = '%T'", v) } } default: - return nil, fmt.Errorf("cannot accomodate GraphQL pocessed response of type = '%T'", pr) + return nil, fmt.Errorf("cannot accommodate GraphQL processed response of type = '%T'", pr) } gq.rowsReturned += len(rv) if returnErr == nil { diff --git a/pkg/graphql/graphql_test.go b/pkg/graphql/graphql_test.go index 25fcbf1..7f49e37 100644 --- a/pkg/graphql/graphql_test.go +++ b/pkg/graphql/graphql_test.go @@ -2,6 +2,7 @@ package graphql import ( "bytes" + "context" "io" "net/http" "net/url" @@ -590,6 +591,84 @@ func TestRead_GraphQLErrorWithoutMessage_FallsBackToJSON(t *testing.T) { } } +// TestRead_EmitsRequestBodyToHTTPLogWhenEnabled asserts that when a context +// logger is attached, the rendered GraphQL request body and wire URL are +// surfaced before the Do() call — closing the gap where --http.log.enabled +// previously only showed the post-transform projection. +func TestRead_EmitsRequestBodyToHTTPLogWhenEnabled(t *testing.T) { + var buf bytes.Buffer + c := &fakeAnySdkClient{bodyJSON: `{"data": {"rows": [{"id": 1}]}}`} + req := newTestRequest(t) + req = req.WithContext(ContextWithHTTPLogger(context.Background(), &buf)) + + r, err := NewStandardGQLReader( + c, req, 0, `query { rows { id } }`, map[string]interface{}{}, "", + "$.data.rows[*]", "$.data.__no_cursor[*]", + ) + if err != nil { + t.Fatalf("NewStandardGQLReader: %v", err) + } + if _, err := r.Read(); err != nil && err != io.EOF { + t.Fatalf("Read: %v", err) + } + + out := buf.String() + if !strings.Contains(out, "query { rows { id } }") { + t.Errorf("expected rendered request body in log, got:\n%s", out) + } + if !strings.Contains(out, "https://api.example.test/graphql") { + t.Errorf("expected wire URL in log, got:\n%s", out) + } +} + +// TestRead_EmitsRawResponseToHTTPLogWhenEnabled asserts that the naked +// pre-transform response body is surfaced when a context logger is attached. +// This is the diagnostic that was missing for transform / templating failures. +func TestRead_EmitsRawResponseToHTTPLogWhenEnabled(t *testing.T) { + var buf bytes.Buffer + c := &fakeAnySdkClient{bodyJSON: `{"data":{"rows":[{"id":1}]}}`} + req := newTestRequest(t) + req = req.WithContext(ContextWithHTTPLogger(context.Background(), &buf)) + + r, err := NewStandardGQLReader( + c, req, 0, `{ ignored }`, map[string]interface{}{}, "", + "$.data.rows[*]", "$.data.__no_cursor[*]", + ) + if err != nil { + t.Fatalf("NewStandardGQLReader: %v", err) + } + if _, err := r.Read(); err != nil && err != io.EOF { + t.Fatalf("Read: %v", err) + } + + out := buf.String() + if !strings.Contains(out, `"id":1`) { + t.Errorf("expected raw response body in log, got:\n%s", out) + } +} + +// TestRead_DoesNotLogWhenHTTPLogDisabled asserts that with no logger attached +// to the request context, Read() emits nothing — the opt-in shape mirrors the +// REST acquire path's gating on runtimeCtx.HTTPLogEnabled. +func TestRead_DoesNotLogWhenHTTPLogDisabled(t *testing.T) { + c := &fakeAnySdkClient{bodyJSON: `{"data":{"rows":[]}}`} + req := newTestRequest(t) // no logger in context + + r, err := NewStandardGQLReader( + c, req, 0, `{ ignored }`, map[string]interface{}{}, "", + "$.data.rows[*]", "$.data.__no_cursor[*]", + ) + if err != nil { + t.Fatalf("NewStandardGQLReader: %v", err) + } + if _, err := r.Read(); err != nil && err != io.EOF { + t.Fatalf("Read: %v", err) + } + // nothing to assert beyond "no panic and no log sink to fill" — the + // negative case is covered by the structural check that nil-logger + // branches in Read() are short-circuit. +} + // TestNewStandardGQLReaderWithCursor_KeysetRequiresFormat ensures a keyset // configuration without a format template is rejected at construction time. func TestNewStandardGQLReaderWithCursor_KeysetRequiresFormat(t *testing.T) {