Open hnakamur opened 8 years ago
Basically, you've to read and cache both bodies io.ReadCloser
streams before they are processed by its final consumers, in this case the HTTP package itself. Given the design efficient nature of the streams in Go (an many other languages), once a stream consumer reads a chunk of data, the data itself is flushed and it will be available for GC free.
In certain scenarios you have to do some pre/post processing of steams data, so the typical strategy would be reading the whole stream, caching it and create a new stream to replace the original, already used one.
You can achieve this via ioutil.ReadAll()
. I do this multiple times in gentleman codebase. I use this helper function when I want to create a new io.ReadCloser
stream from a buffer or string.
Also, in order to read the response body data, you should perform all of this process before the h.Next(ctx)
call. To read the request body, I would suggest writing a simple middleware handler function for the request
phase responsible of reading the whole request body and exposing it via context.Set("req.body", buf)
. You should do this in the request
phase before the HTTP dispatcher process the Request instance.
I hope this help.
Thanks for your detailed explanation. I helps me a lot! I can read the response body now, but I cannot read the request body.
package main
import (
"bytes"
"io/ioutil"
"log"
"os"
"reflect"
kitlog "github.com/go-kit/kit/log"
"github.com/h2non/gentleman"
"github.com/h2non/gentleman/plugins/auth"
genlog "github.com/hnakamur/gentleman-log"
c "gopkg.in/h2non/gentleman.v1/context"
)
func main() {
logger := kitlog.NewLogfmtLogger(os.Stdout)
host := "http://localhost:8529"
user := "root"
password := "root"
cli := gentleman.New()
reqKey := "req.body"
//cli.Use(genlog.RequestSaver(reqKey))
cli.UseHandler("request", func(ctx *c.Context, h c.Handler) {
var body []byte
log.Printf("RequestSaver. ctx.Request.Body=%v, body type=%v", ctx.Request.Body, reflect.ValueOf(ctx.Request.Body).Type())
if ctx.Request.Body != nil {
var err error
body, err = ioutil.ReadAll(ctx.Request.Body)
if err != nil {
h.Error(ctx, err)
return
}
ctx.Request.Body = ioutil.NopCloser(bytes.NewBuffer(body))
}
log.Printf("RequestSaver. body=%s", string(body))
ctx.Set(reqKey, body)
h.Next(ctx)
})
cli.Use(genlog.Logger(logger, reqKey))
cli.URL(host)
cli.Use(auth.Basic(user, password))
//resp, err := cli.Request().Path("/_db/_system/_api/version").JSON(map[string]string{"dummy": "not_used"}).Send()
resp, err := cli.Request().Path("/_db/_system/_api/version").BodyString(`{"dummy":"not_used"}`).Send()
if err != nil {
log.Printf("got error. err=%v", err)
}
if !resp.Ok {
log.Printf("bad status. status=%v", resp.StatusCode)
}
}
package log
import (
"bytes"
"io/ioutil"
"log"
"reflect"
kitlog "github.com/go-kit/kit/log"
c "gopkg.in/h2non/gentleman.v1/context"
p "gopkg.in/h2non/gentleman.v1/plugin"
)
func RequestSaver(reqKey string) p.Plugin {
return p.NewRequestPlugin(func(ctx *c.Context, h c.Handler) {
var body []byte
log.Printf("RequestSaver. ctx.Request.Body=%v, body type=%v", ctx.Request.Body, reflect.ValueOf(ctx.Request.Body).Type())
if ctx.Request.Body != nil {
var err error
body, err = ioutil.ReadAll(ctx.Request.Body)
if err != nil {
h.Error(ctx, err)
return
}
ctx.Request.Body = ioutil.NopCloser(bytes.NewBuffer(body))
}
log.Printf("RequestSaver. body=%s", string(body))
ctx.Set(reqKey, body)
h.Next(ctx)
})
}
func Logger(logger kitlog.Logger, reqKey string) p.Plugin {
return p.NewResponsePlugin(func(ctx *c.Context, h c.Handler) {
req := ctx.Request
res := ctx.Response
var reqBody []byte
reqBodyVal := ctx.Get(reqKey)
if reqBodyVal != nil {
reqBody = reqBodyVal.([]byte)
}
var resBody []byte
if res.Body != nil {
var err error
resBody, err = ioutil.ReadAll(res.Body)
if err != nil {
h.Error(ctx, err)
return
}
res.Body = ioutil.NopCloser(bytes.NewBuffer(resBody))
}
h.Next(ctx)
logger.Log("method", req.Method, "url", req.URL, "payload", string(reqBody), "status", res.StatusCode, "body", string(resBody))
})
}
I don't know the difference between middlewares and plugins, so I tried both. The plugin case is comment-outed above at the line //cli.Use(genlog.RequestSaver(reqKey))
.
The output for both cases was the same.
$ go run main.go
2016/07/18 19:19:02 RequestSaver. ctx.Request.Body=&{{} map[$phase:request]}, body type=*context.contextReadCloser
2016/07/18 19:19:02 RequestSaver. body=
method=POST url=http://localhost:8529/_db/_system/_api/version payload= status=200 body="{\"server\":\"arango\",\"version\":\"3.0.2\"}"
Could you give me advice? Thanks!
I don't know the difference between middlewares and plugins.
gentleman is plugin-driven, but plugins require a bit of interface overhead, so middleware handlers are the simplified version of a phase-specific plugin without constructor/interface overhead, just define the phase name and function to execute. This is simply provided for convenience, but behind the scenes all are plugins.
You code is fine. The problem is due the plugin registration priority. Effectively, gentleman has no explicit plugin priority as sort of priority queue structure, so the execution order is defined by the developer, behaving as a simple FIFO queue. Since gentleman is fully plugin-driven, this affects to the whole library.
In this case you're registering the request log plugin before the body is defined to the Request instance, so that's why you can't read it.
Solutions:
cli.Request().
Path("/_db/_system/_api/version").
BodyString(`{"dummy":"not_used"}`).
Use(genlog.RequestSaver(reqKey)).
Send()
response
phase.body := `{"dummy":"not_used"}`
req := cli.Request()
req.Path("/_db/_system/_api/version")
req.Context.Set("req.body", body)
req.Body(body)
req.Send()
There are other approaches, but I think less convenient.
Thanks again for your detailed explanation! This time I can read the request body successfully using your first solution. I've not tried your other solutions, but I think I found a better alternative, a "before dial" phase plugin.
package main
import (
"log"
"os"
kitlog "github.com/go-kit/kit/log"
"github.com/h2non/gentleman"
"github.com/h2non/gentleman/plugins/auth"
genlog "github.com/hnakamur/gentleman-log"
)
func main() {
logger := kitlog.NewLogfmtLogger(os.Stdout)
host := "http://localhost:8529"
user := "root"
password := "root"
cli := gentleman.New()
reqKey := "req.body"
cli.Use(genlog.RequestSaver(reqKey))
cli.Use(genlog.Logger(logger, reqKey))
cli.URL(host)
cli.Use(auth.Basic(user, password))
resp, err := cli.Request().Path("/_db/_system/_api/version").BodyString(`{"dummy":"not_used"}`).Send()
if err != nil {
log.Printf("got error. err=%v", err)
}
if !resp.Ok {
log.Printf("bad status. status=%v", resp.StatusCode)
}
}
package log
import (
"bytes"
"io/ioutil"
kitlog "github.com/go-kit/kit/log"
c "gopkg.in/h2non/gentleman.v1/context"
p "gopkg.in/h2non/gentleman.v1/plugin"
)
func RequestSaver(reqKey string) p.Plugin {
return p.NewPhasePlugin("before dial", func(ctx *c.Context, h c.Handler) {
var body []byte
if ctx.Request.Body != nil {
var err error
body, err = ioutil.ReadAll(ctx.Request.Body)
if err != nil {
h.Error(ctx, err)
return
}
ctx.Request.Body = ioutil.NopCloser(bytes.NewBuffer(body))
}
ctx.Set(reqKey, body)
h.Next(ctx)
})
}
func Logger(logger kitlog.Logger, reqKey string) p.Plugin {
return p.NewResponsePlugin(func(ctx *c.Context, h c.Handler) {
req := ctx.Request
res := ctx.Response
var reqBody []byte
reqBodyVal := ctx.Get(reqKey)
if reqBodyVal != nil {
reqBody = reqBodyVal.([]byte)
}
var resBody []byte
if res.Body != nil {
var err error
resBody, err = ioutil.ReadAll(res.Body)
if err != nil {
h.Error(ctx, err)
return
}
res.Body = ioutil.NopCloser(bytes.NewBuffer(resBody))
}
h.Next(ctx)
logger.Log("method", req.Method, "url", req.URL, "payload", string(reqBody), "status", res.StatusCode, "body", string(resBody))
})
}
The output.
$ go run main.go
method=POST url=http://localhost:8529/_db/_system/_api/version payload="{\"dummy\":\"not_used\"}" status=200 body="{\"server\":\"arango\",\"version\":\"3.0.2\"}"
Could you tell me what do you think?
That's the perfect one. I completely forget about the before dial
phase :(
If you even want to have a cleaner and more elegant solution, you can write a generic log plugin who will trigger in both phases: before dial
and response
without registering both plugins twice. You can take a look to existent plugins and plugin package to have a better idea of the implementation details.
Also, if you want to contribute and you're open to, you can create an open source log plugin with a structured, modular design, giving the ability to developers to register its own log handlers, responsible of writing logs events to different outputs, such as stdout
, HTTP, statsd
, logstash
or whatever. That would be awesome!
Thanks for your comment. I updated my implementation.
A sample program.
package main
import (
"log"
"net/http"
"os"
kitlog "github.com/go-kit/kit/log"
"github.com/h2non/gentleman"
"github.com/h2non/gentleman/plugins/auth"
genlog "github.com/hnakamur/gentleman-log"
c "gopkg.in/h2non/gentleman.v1/context"
)
func main() {
logger := kitlog.NewLogfmtLogger(os.Stdout)
host := "http://localhost:8529"
user := "root"
password := "root"
cli := gentleman.New()
reqKey := "req.body"
resKey := "res.body"
cli.Use(auth.Basic(user, password))
cli.Use(genlog.SaveBody(reqKey, resKey))
cli.Use(genlog.Log(reqKey, resKey, func(ctx *c.Context, req *http.Request, res *http.Response, reqBody, resBody []byte) error {
keyvals := []interface{}{
"method", req.Method, "url", req.URL,
}
for k, v := range req.Header {
for _, vv := range v {
keyvals = append(keyvals, "reqHeader."+k, vv)
}
}
keyvals = append(keyvals,
"payload", string(reqBody), "status", res.StatusCode)
for k, v := range res.Header {
for _, vv := range v {
keyvals = append(keyvals, "resHeader."+k, vv)
}
}
keyvals = append(keyvals,
"body", string(resBody))
logger.Log(keyvals...)
return nil
}))
cli.URL(host)
resp, err := cli.Request().Path("/_db/_system/_api/version").BodyString(`{"dummy":"not_used"}`).Send()
if err != nil {
log.Printf("got error. err=%v", err)
}
if !resp.Ok {
log.Printf("bad status. status=%v", resp.StatusCode)
}
}
log plugin.
package log
import (
"bytes"
"io/ioutil"
"net/http"
c "gopkg.in/h2non/gentleman.v1/context"
p "gopkg.in/h2non/gentleman.v1/plugin"
)
func SaveBody(reqKey, resKey string) p.Plugin {
handleBeforeDial := func(ctx *c.Context, h c.Handler) {
var body []byte
if ctx.Request.Body != nil {
var err error
body, err = ioutil.ReadAll(ctx.Request.Body)
if err != nil {
h.Error(ctx, err)
return
}
ctx.Request.Body = ioutil.NopCloser(bytes.NewBuffer(body))
}
ctx.Set(reqKey, body)
h.Next(ctx)
}
handleResponse := func(ctx *c.Context, h c.Handler) {
var body []byte
if ctx.Response.Body != nil {
var err error
body, err = ioutil.ReadAll(ctx.Response.Body)
if err != nil {
h.Error(ctx, err)
return
}
ctx.Response.Body = ioutil.NopCloser(bytes.NewBuffer(body))
}
ctx.Set(resKey, body)
h.Next(ctx)
}
handlers := p.Handlers{
"before dial": handleBeforeDial,
"response": handleResponse,
}
return &p.Layer{Handlers: handlers}
}
func Log(reqKey, resKey string, logFunc func(ctx *c.Context, req *http.Request, res *http.Response, reqBody, resBody []byte) error) p.Plugin {
return p.NewResponsePlugin(func(ctx *c.Context, h c.Handler) {
var reqBody []byte
reqBodyVal := ctx.Get(reqKey)
if reqBodyVal != nil {
reqBody = reqBodyVal.([]byte)
}
var resBody []byte
resBodyVal := ctx.Get(resKey)
if resBodyVal != nil {
resBody = resBodyVal.([]byte)
}
err := logFunc(ctx, ctx.Request, ctx.Response, reqBody, resBody)
if err != nil {
h.Error(ctx, err)
}
h.Next(ctx)
})
}
example output.
$ go run main.go
method=POST url=http://localhost:8529/_db/_system/_api/version reqHeader.User-Agent=gentleman/1.0.0 reqHeader.Authorization="Basic cm9vdDpyb290" payload="{\"dummy\":\"not_used\"}" status=200 resHeader.Server=ArangoDB resHeader.Connection=Keep-Alive resHeader.Content-Typ
e="application/json; charset=utf-8" resHeader.Content-Length=37 body="{\"server\":\"arango\",\"version\":\"3.0.2\"}"
I made two separated plugins SaveBody
and Log
since users want to save the request body and the response body for other uses than logging.
And yes, I want to contribute this log plugin. Can I send a pull request to create the github.com/h2non/gentleman/plugins/log package?
Could you tell me what do you think?
Thanks for sharing the code.
I would suggest the following points:
I wrote a simple Apache-like HTTP logger for the server side that you can take a reference, however it's pretty simple not designed for versatility, just log things as Apache does: https://github.com/h2non/apachelog
Thanks for your suggestions. I created my custom log package at https://github.com/hnakamur/gentleman-log
Thanks again for you help!
That's nice. If you want to evolve it in the future, I would suggest to take an eye apex/log structured implemented as design reference point: https://github.com/apex/log
Once the package is mature and versatile enough, you can make a PR request to add it to the list of plugins.
First of all, thanks for creating and sharing a nice software!
I would like to have log plugin which will log requests and responses using github.com/go-kit/kig/log.Logger interface.
I tried to create such a plugin myself, but I'm stuck now.
Here is an example usage.
Here is my plugin code.
Could you tell me how to retrieve the request body and the response body?