// dumpResponse dumps the response and the request.
func (c *Client) dumpResponse(ctx context.Context, resp *http.Response) {
respBody, _ := dumpRespBody(resp)
goa.LogInfo(ctx, "response headers", headersToSlice(resp.Header)...)
if respBody != nil {
goa.LogInfo(ctx, "response", "body", string(respBody))
}
}
// Do wraps the underlying http client Do method and adds logging.
// The logger should be in the context.
func (c *Client) Do(ctx context.Context, req *http.Request) (*http.Response, error) {
// TODO: setting the request ID should be done via client middleware. For now only set it if the
// caller provided one in the ctx.
if ctxreqid := ContextRequestID(ctx); ctxreqid != "" {
req.Header.Set("X-Request-Id", ctxreqid)
}
if c.UserAgent != "" {
req.Header.Set("User-Agent", c.UserAgent)
}
startedAt := time.Now()
ctx, id := ContextWithRequestID(ctx)
goa.LogInfo(ctx, "started", "id", id, req.Method, req.URL.String())
if c.Dump {
c.dumpRequest(ctx, req)
}
resp, err := c.Doer.Do(ctx, req)
if err != nil {
goa.LogError(ctx, "failed", "err", err)
return nil, err
}
goa.LogInfo(ctx, "completed", "id", id, "status", resp.StatusCode, "time", time.Since(startedAt).String())
if c.Dump {
c.dumpResponse(ctx, resp)
}
return resp, err
}
// Refresh makes a OAuth2 refresh access token request.
func (s *OAuth2Signer) Refresh(ctx context.Context) error {
url := fmt.Sprintf(s.RefreshURLFormat, s.RefreshToken)
req, err := http.NewRequest("POST", url, nil)
if err != nil {
return err
}
id := shortID()
goa.LogInfo(ctx, "refresh", "id", id, "url", fmt.Sprintf(s.RefreshURLFormat, "*****"))
resp, err := http.DefaultClient.Do(req)
if err != nil {
goa.LogError(ctx, "failed", "id", id, "err", err)
return err
}
goa.LogInfo(ctx, "completed", "id", id, "status", resp.Status)
defer resp.Body.Close()
var r oauth2RefreshResponse
respBody, err := ioutil.ReadAll(resp.Body)
if err != nil {
return fmt.Errorf("failed to read response body: %s", err)
}
err = json.Unmarshal(respBody, &r)
if err != nil {
return fmt.Errorf("failed to decode refresh request response: %s", err)
}
s.accessToken = r.AccessToken
if r.ExpiresIn > 0 {
s.expiresAt = time.Now().Add(time.Duration(r.ExpiresIn) * time.Second)
goa.LogInfo(ctx, "refreshed", "expires", s.expiresAt)
}
if r.RefreshToken != "" {
s.RefreshToken = r.RefreshToken
}
return nil
}
// Dump request if needed.
func (c *Client) dumpRequest(ctx context.Context, req *http.Request) {
reqBody, err := dumpReqBody(req)
if err != nil {
goa.LogError(ctx, "Failed to load request body for dump", "err", err.Error())
}
goa.LogInfo(ctx, "request headers", headersToSlice(req.Header)...)
if reqBody != nil {
goa.LogInfo(ctx, "request", "body", string(reqBody))
}
}
// Do wraps the underlying http client Do method and adds logging.
// The logger should be in the context.
func (c *Client) Do(ctx context.Context, req *http.Request) (*http.Response, error) {
req.Header.Set("User-Agent", c.UserAgent)
startedAt := time.Now()
id := shortID()
goa.LogInfo(ctx, "started", "id", id, req.Method, req.URL.String())
if c.Dump {
c.dumpRequest(ctx, req)
}
resp, err := c.Client.Do(req)
if err != nil {
goa.LogError(ctx, "failed", "err", err)
return nil, err
}
goa.LogInfo(ctx, "completed", "id", id, "status", resp.StatusCode, "time", time.Since(startedAt).String())
if c.Dump {
c.dumpResponse(ctx, resp)
}
return resp, err
}
// LogRequest creates a request logger middleware.
// This middleware is aware of the RequestID middleware and if registered after it leverages the
// request ID for logging.
// If verbose is true then the middlware logs the request and response bodies.
func LogRequest(verbose bool) goa.Middleware {
return func(h goa.Handler) goa.Handler {
return func(ctx context.Context, rw http.ResponseWriter, req *http.Request) error {
reqID := ctx.Value(reqIDKey)
if reqID == nil {
reqID = shortID()
}
ctx = goa.WithLogContext(ctx, "req_id", reqID)
startedAt := time.Now()
r := goa.ContextRequest(ctx)
goa.LogInfo(ctx, "started", r.Method, r.URL.String(), "from", from(req),
"ctrl", goa.ContextController(ctx), "action", goa.ContextAction(ctx))
if verbose {
if len(r.Params) > 0 {
logCtx := make([]interface{}, 2*len(r.Params))
i := 0
for k, v := range r.Params {
logCtx[i] = k
logCtx[i+1] = interface{}(strings.Join(v, ", "))
i = i + 2
}
goa.LogInfo(ctx, "params", logCtx...)
}
if r.ContentLength > 0 {
if mp, ok := r.Payload.(map[string]interface{}); ok {
logCtx := make([]interface{}, 2*len(mp))
i := 0
for k, v := range mp {
logCtx[i] = k
logCtx[i+1] = interface{}(v)
i = i + 2
}
goa.LogInfo(ctx, "payload", logCtx...)
} else {
// Not the most efficient but this is used for debugging
js, err := json.Marshal(r.Payload)
if err != nil {
js = []byte("<invalid JSON>")
}
goa.LogInfo(ctx, "payload", "raw", string(js))
}
}
}
err := h(ctx, rw, req)
resp := goa.ContextResponse(ctx)
if code := resp.ErrorCode; code != "" {
goa.LogInfo(ctx, "completed", "status", resp.Status, "error", code,
"bytes", resp.Length, "time", time.Since(startedAt).String())
} else {
goa.LogInfo(ctx, "completed", "status", resp.Status,
"bytes", resp.Length, "time", time.Since(startedAt).String())
}
return err
}
}
}
// Write will write raw data to logger and response writer.
func (lrw *loggingResponseWriter) Write(buf []byte) (int, error) {
goa.LogInfo(lrw.ctx, "response", "body", string(buf))
return lrw.ResponseWriter.Write(buf)
}
// New returns a middleware to be used with the `JWTSecurity()` DSL
// definitions of `goa`. It supports the `scopes` claim in the JWT
// and ensures goa-defined `Security()` DSLs are properly validated.
//
// The `exp` (expiration) and `nbf` (not before) date checks are
// validated by the JWT library.
//
// validationKeys can be one of these:
//
// * a single string
// * a single []byte
// * a list of string
// * a list of []byte
// * a single *rsa.PublicKey
// * a list of *rsa.PublicKey
//
// The type of the keys determine the algorithms that will be checked.
// The goal of having lists of keys is to allow for key rotation,
// still check the previous keys until rotation has been completed.
//
// You can define an optional function to do additional validations on
// the token once the signature and the claims requirements are proven
// to be valid. Example:
//
// validationHandler, _ := goa.NewMiddleware(func(ctx context.Context, w http.ResponseWriter, r *http.Request) error {
// token := jwt.ContextJWT(ctx)
// if val, ok := token.Claims["is_uncle"].(string); !ok || val != "ben" {
// return jwt.ErrJWTError.Errorf("you are not uncle ben's")
// }
// })
// app.MyJWTSecurity.Use(jwt.New("secret", validationHandler))
//
func New(validationKeys interface{}, validationFunc goa.Middleware) goa.JWTSecurityConfigFunc {
return func(scheme *goa.JWTSecurity, getScopes func(context.Context) []string) goa.Middleware {
var algo string
var rsaKeys []*rsa.PublicKey
var hmacKeys []string
switch keys := validationKeys.(type) {
case []*rsa.PublicKey:
rsaKeys = keys
algo = "RS"
case *rsa.PublicKey:
rsaKeys = []*rsa.PublicKey{keys}
algo = "RS"
case string:
hmacKeys = []string{keys}
algo = "HS"
case []string:
hmacKeys = keys
algo = "HS"
default:
panic("invalid parameter to `jwt.New()`, only accepts *rsa.publicKey, []*rsa.PublicKey (for RSA-based algorithms) or a signing secret string (for HS algorithms)")
}
return func(nextHandler goa.Handler) goa.Handler {
return func(ctx context.Context, rw http.ResponseWriter, req *http.Request) error {
// TODO: implement the QUERY string handler too
if scheme.In != goa.LocHeader {
return fmt.Errorf("whoops, security scheme with in = %q not supported", scheme.In)
}
val := req.Header.Get(scheme.Name)
if val == "" {
return ErrJWTError("missing header %q", scheme.Name)
}
if !strings.HasPrefix(strings.ToLower(val), "bearer ") {
return ErrJWTError("invalid or malformed %q header, expected 'Authorization: Bearer JWT-token...'", val)
}
incomingToken := strings.Split(val, " ")[1]
var token *jwt.Token
var err error
switch algo {
case "RS":
token, err = validateRSAKeys(rsaKeys, algo, incomingToken)
case "HS":
token, err = validateHMACKeys(hmacKeys, algo, incomingToken)
default:
panic("how did this happen ? unsupported algo in jwt middleware")
}
if err != nil {
goa.LogInfo(ctx, "JWT token validation failed", "err", err)
return ErrJWTError("JWT validation failed")
}
scopesInClaim, scopesInClaimList, err := parseClaimScopes(token)
if err != nil {
goa.LogError(ctx, err.Error())
return ErrJWTError(err)
}
requiredScopes := getScopes(ctx)
for _, scope := range requiredScopes {
if !scopesInClaim[scope] {
goa.LogInfo(ctx, "missing required scope in JWT token", "missing_scope", scope, "required_scopes", requiredScopes, "scopes_in_claim", scopesInClaimList)
return ErrJWTError("authorization failed: required 'scopes' not present in JWT claim").Meta("required_scopes", requiredScopes, "scopes_in_claim", scopesInClaimList)
}
}
ctx = context.WithValue(ctx, jwtKey, token)
if validationFunc != nil {
nextHandler = validationFunc(nextHandler)
}
return nextHandler(ctx, rw, req)
}
}
}
}
package goa_test
import (
"bytes"
"log"
"github.com/goadesign/goa"
. "github.com/onsi/ginkgo"
. "github.com/onsi/gomega"
"golang.org/x/net/context"
)
var _ = Describe("Info", func() {
Context("with a nil Log", func() {
It("doesn't log and doesn't crash", func() {
Ω(func() { goa.LogInfo(context.Background(), "foo", "bar") }).ShouldNot(Panic())
})
})
})
var _ = Describe("Error", func() {
Context("with a nil Log", func() {
It("doesn't log and doesn't crash", func() {
Ω(func() { goa.LogError(context.Background(), "foo", "bar") }).ShouldNot(Panic())
})
})
})
var _ = Describe("LogAdapter", func() {
Context("with a valid Log", func() {
var logger goa.LogAdapter
