logging: add debug logging for request and response #107

Merged
vtolstov merged 3 commits from logging into v3 2023-03-15 22:26:59 +03:00
5 changed files with 61 additions and 11 deletions

4
go.mod
View File

@ -1,5 +1,5 @@
module go.unistack.org/micro-client-http/v3
go 1.16
go 1.18
require go.unistack.org/micro/v3 v3.10.14
require go.unistack.org/micro/v3 v3.10.16

4
go.sum
View File

@ -1,8 +1,8 @@
github.com/imdario/mergo v0.3.13/go.mod h1:4lJ1jqUDcsbIECGy0RUJAXNIhg+6ocWgb1ALK2O4oXg=
github.com/patrickmn/go-cache v2.1.0+incompatible/go.mod h1:3Qf8kWWT7OJRJbdiICTKqZju1ZixQ/KpMGzzAfe6+WQ=
github.com/silas/dag v0.0.0-20211117232152-9d50aa809f35/go.mod h1:7RTUFBdIRC9nZ7/3RyRNH1bdqIShrDejd1YbLwgPS+I=
go.unistack.org/micro/v3 v3.10.14 h1:7fgLpwGlCN67twhwtngJDEQvrMkUBDSA5vzZqxIDqNE=
go.unistack.org/micro/v3 v3.10.14/go.mod h1:uMAc0U/x7dmtICCrblGf0ZLgYegu3VwQAquu+OFCw1Q=
go.unistack.org/micro/v3 v3.10.16 h1:2er/SKKYbV60M+UuJM4eYCF0MZYAIq/yNUrAbTfgq8Q=
go.unistack.org/micro/v3 v3.10.16/go.mod h1:uMAc0U/x7dmtICCrblGf0ZLgYegu3VwQAquu+OFCw1Q=
gopkg.in/check.v1 v0.0.0-20161208181325-20d25e280405/go.mod h1:Co6ibVJAznAaIkqp8huTwlJQCZ016jof/cbN4VW5Yz0=
gopkg.in/yaml.v3 v3.0.0/go.mod h1:K4uyk7z7BCEPqu6E+C64Yfv1cQ7kz7rIZviUmN+EgEM=
gopkg.in/yaml.v3 v3.0.1/go.mod h1:K4uyk7z7BCEPqu6E+C64Yfv1cQ7kz7rIZviUmN+EgEM=

14
http.go
View File

@ -19,6 +19,7 @@ import (
"go.unistack.org/micro/v3/client"
"go.unistack.org/micro/v3/codec"
"go.unistack.org/micro/v3/errors"
"go.unistack.org/micro/v3/logger"
"go.unistack.org/micro/v3/metadata"
"go.unistack.org/micro/v3/selector"
rutil "go.unistack.org/micro/v3/util/reflect"
@ -40,7 +41,7 @@ type httpClient struct {
init bool
}
func newRequest(ctx context.Context, addr string, req client.Request, ct string, cf codec.Codec, msg interface{}, opts client.CallOptions) (*http.Request, error) {
func newRequest(ctx context.Context, log logger.Logger, addr string, req client.Request, ct string, cf codec.Codec, msg interface{}, opts client.CallOptions) (*http.Request, error) {
var tags []string
var parameters map[string]map[string]string
scheme := "http"
@ -210,6 +211,10 @@ func newRequest(ctx context.Context, addr string, req client.Request, ct string,
hreq.AddCookie(cookie)
}
if log.V(logger.DebugLevel) {
log.Debugf(ctx, "request %s to %s with headers %v body %s", method, u.String(), hreq.Header, b)
}
return hreq, nil
}
@ -221,9 +226,9 @@ func (h *httpClient) call(ctx context.Context, addr string, req client.Request,
cf, err := h.newCodec(ct)
if err != nil {
return errors.InternalServerError("go.micro.client", err.Error())
return errors.BadRequest("go.micro.client", err.Error())
}
hreq, err := newRequest(ctx, addr, req, ct, cf, req.Body(), opts)
hreq, err := newRequest(ctx, h.opts.Logger, addr, req, ct, cf, req.Body(), opts)
if err != nil {
return err
}
@ -258,7 +263,7 @@ func (h *httpClient) stream(ctx context.Context, addr string, req client.Request
// get codec
cf, err := h.newCodec(ct)
if err != nil {
return nil, errors.InternalServerError("go.micro.client", err.Error())
return nil, errors.BadRequest("go.micro.client", err.Error())
}
cc, err := (h.httpcli.Transport).(*http.Transport).DialContext(ctx, "tcp", addr)
@ -268,6 +273,7 @@ func (h *httpClient) stream(ctx context.Context, addr string, req client.Request
return &httpStream{
address: addr,
logger: h.opts.Logger,
context: ctx,
closed: make(chan bool),
opts: opts,

View File

@ -2,9 +2,11 @@ package http
import (
"bufio"
"bytes"
"context"
"fmt"
"io"
"io/ioutil"
"net"
"net/http"
"sync"
@ -12,6 +14,7 @@ import (
"go.unistack.org/micro/v3/client"
"go.unistack.org/micro/v3/codec"
"go.unistack.org/micro/v3/errors"
"go.unistack.org/micro/v3/logger"
)
// Implements the streamer interface
@ -20,6 +23,7 @@ type httpStream struct {
conn net.Conn
cf codec.Codec
context context.Context
logger logger.Logger
request client.Request
closed chan bool
reader *bufio.Reader
@ -65,7 +69,7 @@ func (h *httpStream) Send(msg interface{}) error {
return errShutdown
}
hreq, err := newRequest(h.context, h.address, h.request, h.ct, h.cf, msg, h.opts)
hreq, err := newRequest(h.context, h.logger, h.address, h.request, h.ct, h.cf, msg, h.opts)
if err != nil {
return err
}
@ -92,7 +96,7 @@ func (h *httpStream) Recv(msg interface{}) error {
}
defer hrsp.Body.Close()
return h.parseRsp(h.context, hrsp, h.cf, msg, h.opts)
return h.parseRsp(h.context, h.logger, hrsp, h.cf, msg, h.opts)
}
func (h *httpStream) Error() error {
@ -115,7 +119,7 @@ func (h *httpStream) Close() error {
}
}
func (h *httpStream) parseRsp(ctx context.Context, hrsp *http.Response, cf codec.Codec, rsp interface{}, opts client.CallOptions) error {
func (h *httpStream) parseRsp(ctx context.Context, log logger.Logger, hrsp *http.Response, cf codec.Codec, rsp interface{}, opts client.CallOptions) error {
var err error
select {
@ -128,6 +132,14 @@ func (h *httpStream) parseRsp(ctx context.Context, hrsp *http.Response, cf codec
}
if hrsp.StatusCode < 400 {
if log.V(logger.DebugLevel) {
buf, rerr := io.ReadAll(hrsp.Body)
log.Debugf(ctx, "response %s with %v", buf, hrsp.Header)
if err != nil {
return errors.InternalServerError("go.micro.client", rerr.Error())
}
hrsp.Body = ioutil.NopCloser(bytes.NewBuffer(buf))
}
if err = cf.ReadBody(hrsp.Body, rsp); err != nil {
return errors.InternalServerError("go.micro.client", err.Error())
}
@ -142,12 +154,24 @@ func (h *httpStream) parseRsp(ctx context.Context, hrsp *http.Response, cf codec
}
if !ok || err == nil {
buf, cerr := io.ReadAll(hrsp.Body)
if log.V(logger.DebugLevel) {
log.Debugf(ctx, "response %s with %v", buf, hrsp.Header)
}
if cerr != nil {
return errors.InternalServerError("go.micro.client", cerr.Error())
}
return errors.New("go.micro.client", string(buf), int32(hrsp.StatusCode))
}
if log.V(logger.DebugLevel) {
buf, rerr := io.ReadAll(hrsp.Body)
log.Debugf(ctx, "response %s with %v", buf, hrsp.Header)
if err != nil {
return errors.InternalServerError("go.micro.client", rerr.Error())
}
hrsp.Body = ioutil.NopCloser(bytes.NewBuffer(buf))
}
if cerr := cf.ReadBody(hrsp.Body, err); cerr != nil {
err = errors.InternalServerError("go.micro.client", cerr.Error())
}

20
util.go
View File

@ -1,9 +1,11 @@
package http
import (
"bytes"
"context"
"fmt"
"io"
"io/ioutil"
"net/http"
"net/url"
"reflect"
@ -269,9 +271,15 @@ func (h *httpClient) parseRsp(ctx context.Context, hrsp *http.Response, rsp inte
h.opts.Logger.Errorf(ctx, "failed to read body: %v", err)
}
}
if h.opts.Logger.V(logger.DebugLevel) {
h.opts.Logger.Debugf(ctx, "response %s with %v", buf, hrsp.Header)
}
// response like text/plain or something else, return original error
return errors.New("go.micro.client", string(buf), int32(hrsp.StatusCode))
} else if cerr != nil {
if h.opts.Logger.V(logger.DebugLevel) {
h.opts.Logger.Debugf(ctx, "response with %v unknown content-type", hrsp.Header, ct)
}
return errors.InternalServerError("go.micro.client", cerr.Error())
}
@ -295,12 +303,24 @@ func (h *httpClient) parseRsp(ctx context.Context, hrsp *http.Response, rsp inte
if !ok || rerr == nil {
buf, rerr := io.ReadAll(hrsp.Body)
if h.opts.Logger.V(logger.DebugLevel) {
h.opts.Logger.Debugf(ctx, "response %s with %v", buf, hrsp.Header)
}
if rerr != nil {
return errors.InternalServerError("go.micro.client", rerr.Error())
}
return errors.New("go.micro.client", string(buf), int32(hrsp.StatusCode))
}
if h.opts.Logger.V(logger.DebugLevel) {
buf, rerr := io.ReadAll(hrsp.Body)
h.opts.Logger.Debugf(ctx, "response %s with %v", buf, hrsp.Header)
if err != nil {
return errors.InternalServerError("go.micro.client", rerr.Error())
}
hrsp.Body = ioutil.NopCloser(bytes.NewBuffer(buf))
}
if cerr := cf.ReadBody(hrsp.Body, rerr); cerr != nil {
return errors.InternalServerError("go.micro.client", cerr.Error())
}