diff --git a/http/handler.go b/http/handler.go index b3d6339b8..579f66385 100644 --- a/http/handler.go +++ b/http/handler.go @@ -54,7 +54,7 @@ type Handler struct { logger logger.Logger - querylogger logger.Logger + queryLogger logger.Logger // Keeps the query argument validators for each handler validators map[string]*queryValidationSpec @@ -152,7 +152,7 @@ func OptHandlerLogger(logger logger.Logger) handlerOption { func OptHandlerQueryLogger(logger logger.Logger) handlerOption { return func(h *Handler) error { - h.querylogger = logger + h.queryLogger = logger return nil } } @@ -285,13 +285,8 @@ const ( contextKeyQueryRequest contextKeyQuery = iota contextKeyQueryError contextKeyGroupMembership - contextKeyPermission ) -func GetContextKeyPermission() contextKeyQuery { - return contextKeyPermission -} - // addQueryContext puts the results of handler.readQueryRequest into the Context for use by // both other middleware and any handlers. func (h *Handler) addQueryContext(next http.Handler) http.Handler { @@ -573,82 +568,112 @@ func (h *Handler) chkAuthN(handler http.HandlerFunc) http.HandlerFunc { func (h *Handler) chkAuthZ(handler http.HandlerFunc, perm authz.Permission) http.HandlerFunc { return func(w http.ResponseWriter, r *http.Request) { - lperm := perm - if h.auth != nil { - uinfo, err := h.auth.Authenticate(getToken(r)) - if err != nil { - http.Error(w, errors.Wrap(err, "authenticating").Error(), http.StatusForbidden) - return - } - - if h.permissions == nil { - h.logger.Errorf("authentication is turned on without authorization permissions set") - http.Error(w, "authorizing", http.StatusInternalServerError) - return - } - - ctx := context.WithValue(r.Context(), contextKeyGroupMembership, uinfo.Groups) - - if h.permissions.IsAdmin(uinfo.Groups) { - ctx = context.WithValue(ctx, contextKeyPermission, authz.Admin) - handler.ServeHTTP(w, r.WithContext(ctx)) - return - } else if lperm == authz.Admin { - http.Error(w, "Insufficient permissions: user does not have admin permission", http.StatusForbidden) - return - } - - var queryString string - queryRequest := r.Context().Value(contextKeyQueryRequest) - if req, ok := queryRequest.(*pilosa.QueryRequest); ok { - queryString = req.Query - - q, err := pql.ParseString(queryString) - if err != nil { - http.Error(w, errors.Wrap(err, "parsing query string").Error(), http.StatusBadRequest) - return - } - if q.WriteCallN() > 0 { - lperm = authz.Write - } - } - - queryString = strings.Replace(queryString, "\n", "", -1) - - if r.Method == "POST" { - h.querylogger.Infof("User ID: %s, User Name: %s, Endpoint: %s, Index: %s, Query: %s, Err: %v", uinfo.UserID, uinfo.UserName, r.URL.Path, "indexName", queryString, err) - } - - ctx = context.WithValue(r.Context(), contextKeyGroupMembership, uinfo.Groups) - indexName, ok := mux.Vars(r)["index"] - - if !ok { - indexName = r.URL.Query().Get("index") - } - - if indexName != "" { - p, err := h.permissions.GetPermissions(uinfo, indexName) - ctx = context.WithValue(r.Context(), contextKeyPermission, p) - if err != nil { - w.Header().Add("Content-Type", "text/plain") - http.Error(w, errors.Wrap(err, "Insufficient Permissions").Error(), http.StatusForbidden) - return - } - if !p.Satisfies(lperm) { - w.Header().Add("Content-Type", "text/plain") - http.Error(w, fmt.Sprintf("Insufficient permissions: user has %s permissions, but request requires %s permission", p, lperm), http.StatusForbidden) - return - } - } - - handler.ServeHTTP(w, r.WithContext(ctx)) - } else { + // if auth isn't turned on, just serve the request + if h.auth == nil { handler.ServeHTTP(w, r) + return } + // make a copy of the requested permissions + lperm := perm + + // check if the user is authenticated + uinfo, err := h.auth.Authenticate(getToken(r)) + if err != nil { + http.Error(w, errors.Wrap(err, "authenticating").Error(), http.StatusForbidden) + return + } + + // put the user's groups in the context + ctx := context.WithValue(r.Context(), contextKeyGroupMembership, uinfo.Groups) + + // unlikely h.permissions will be nil, but we'll check to be safe + if h.permissions == nil { + h.logger.Errorf("authentication is turned on without authorization permissions set") + http.Error(w, "authorizing", http.StatusInternalServerError) + return + } + + // figure out what the user is querying for + queryString := "" + queryRequest := r.Context().Value(contextKeyQueryRequest) + if req, ok := queryRequest.(*pilosa.QueryRequest); ok { + queryString = req.Query + + q, err := pql.ParseString(queryString) + if err != nil { + http.Error(w, errors.Wrap(err, "parsing query string").Error(), http.StatusBadRequest) + return + } + + // if there are write calls, and the needed perms don't already + // satisfy write permissions, then make them write permissions + if q.WriteCallN() > 0 && !lperm.Satisfies(authz.Write) { + lperm = authz.Write + } + } + // make the query string pretty + queryString = strings.Replace(queryString, "\n", "", -1) + + // figure out if we should log this query + toLog := true + for _, ep := range []string{"/status", "/metrics", "/info", "/internal"} { + if strings.HasPrefix(r.URL.Path, ep) { + toLog = false + break + } + } + if toLog { + h.queryLogger.Infof("%v, %v, %v, %v, %v, %v", GetIP(r), r.UserAgent(), r.URL.Path, uinfo.UserID, uinfo.UserName, queryString) + } + + // if they're an admin, they can do whatever they want + if h.permissions.IsAdmin(uinfo.Groups) { + handler.ServeHTTP(w, r.WithContext(ctx)) + return + } else if lperm == authz.Admin { + // if they're not an admin, and they need to be, we can just + // error right here + http.Error(w, "Insufficient permissions: user does not have admin permission", http.StatusForbidden) + return + } + + // try to get the index name + indexName, ok := mux.Vars(r)["index"] + if !ok { + indexName = r.URL.Query().Get("index") + } + + // if we have an index name, then we check the user permissions + // against that index + if indexName != "" { + p, err := h.permissions.GetPermissions(uinfo, indexName) + if err != nil { + w.Header().Add("Content-Type", "text/plain") + http.Error(w, errors.Wrap(err, "Insufficient Permissions").Error(), http.StatusForbidden) + return + } + + // if they're not permitted to access this index, error + if !p.Satisfies(lperm) { + w.Header().Add("Content-Type", "text/plain") + http.Error(w, "Insufficient permissions", http.StatusForbidden) + return + } + } + handler.ServeHTTP(w, r.WithContext(ctx)) + } } +func GetIP(r *http.Request) string { + forwarded := r.Header.Get("X-FORWARDED-FOR") + if forwarded != "" { + return forwarded + } + return r.RemoteAddr +} + // statikHandler implements the http.Handler interface, and responds to // requests for static assets with the appropriate file contents embedded // in a statik filesystem. diff --git a/http/handler_internal_test.go b/http/handler_internal_test.go index e23af836c..511079961 100644 --- a/http/handler_internal_test.go +++ b/http/handler_internal_test.go @@ -220,7 +220,7 @@ func TestAuthentication(t *testing.T) { h := Handler{ logger: logger.NewStandardLogger(os.Stdout), - querylogger: logger.NewStandardLogger(os.Stdout), + queryLogger: logger.NewStandardLogger(os.Stdout), auth: a, } diff --git a/server.go b/server.go index 351e3818c..23e760e19 100644 --- a/server.go +++ b/server.go @@ -67,7 +67,7 @@ type Server struct { // nolint: maligned systemInfo SystemInfo gcNotifier GCNotifier logger logger.Logger - querylogger logger.Logger + queryLogger logger.Logger snapshotQueue SnapshotQueue nodeID string @@ -115,7 +115,7 @@ func OptServerLogger(l logger.Logger) ServerOption { func OptServerQueryLogger(l logger.Logger) ServerOption { return func(s *Server) error { - s.querylogger = l + s.queryLogger = l return nil } } diff --git a/server/grpc.go b/server/grpc.go index 804dd91cd..f24823915 100644 --- a/server/grpc.go +++ b/server/grpc.go @@ -27,6 +27,7 @@ import ( "google.golang.org/grpc/codes" "google.golang.org/grpc/credentials" "google.golang.org/grpc/metadata" + "google.golang.org/grpc/peer" "google.golang.org/grpc/reflection" "google.golang.org/grpc/status" ) @@ -36,6 +37,7 @@ type GRPCHandler struct { api *pilosa.API perms *authz.GroupPermissions logger logger.Logger + queryLogger logger.Logger stats stats.StatsClient inspectDeprecated sync.Once } @@ -59,6 +61,11 @@ func (h *GRPCHandler) WithPerms(perms *authz.GroupPermissions) *GRPCHandler { return h } +func (h *GRPCHandler) WithQueryLogger(logger logger.Logger) *GRPCHandler { + h.queryLogger = logger + return h +} + // errorToStatusError appends an appropriate grpc status code // to the error (returning it as a status.Error). func errToStatusError(err error) error { @@ -166,6 +173,7 @@ func (h *GRPCHandler) QuerySQL(req *pb.QuerySQLRequest, stream pb.Pilosa_QuerySQ if err != nil { return errors.Wrap(err, "parsing SQL") } + allowed := h.perms.GetAuthorizedIndexList(uinfo.(*authn.UserInfo).Groups, authz.Read) if !h.perms.IsAdmin(uinfo.(*authn.UserInfo).Groups) { if !isAllowed(parsed.Tables, allowed) { @@ -1431,8 +1439,9 @@ type grpcServer struct { auth *authn.Auth perms *authz.GroupPermissions - logger logger.Logger - stats stats.StatsClient + logger logger.Logger + queryLogger logger.Logger + stats stats.StatsClient } type grpcServerOption func(s *grpcServer) error @@ -1486,6 +1495,13 @@ func OptGRPCServerPerm(gp *authz.GroupPermissions) grpcServerOption { } } +func OptGRPCServerQueryLogger(logger logger.Logger) grpcServerOption { + return func(s *grpcServer) error { + s.queryLogger = logger + return nil + } +} + func (s *grpcServer) Serve() error { s.logger.Infof("enabled grpc listening on %s", s.ln.Addr()) @@ -1545,7 +1561,7 @@ func NewGRPCServer(opts ...grpcServerOption) (*grpcServer, error) { if server.auth != nil { gopts = append(gopts, grpc.UnaryInterceptor( func(ctx context.Context, req interface{}, info *grpc.UnaryServerInfo, handler grpc.UnaryHandler) (interface{}, error) { - ctx, err := Valid(ctx, server.auth) + ctx, err := Valid(ctx, info.FullMethod, server.auth, req, server.queryLogger) if err != nil { return nil, err } @@ -1554,18 +1570,18 @@ func NewGRPCServer(opts ...grpcServerOption) (*grpcServer, error) { )) gopts = append(gopts, grpc.StreamInterceptor( func(srv interface{}, ss grpc.ServerStream, info *grpc.StreamServerInfo, handler grpc.StreamHandler) error { - ctx, err := Valid(ss.Context(), server.auth) + ctx, err := Valid(ss.Context(), info.FullMethod, server.auth, srv, server.queryLogger) if err != nil { return err } - return handler(srv, newWrappedStream(ss, ctx)) + return handler(srv, &wrappedStream{ss, ctx}) }, )) } // create grpc server server.grpcServer = grpc.NewServer(gopts...) - grpcHandler := NewGRPCHandler(server.api).WithLogger(server.logger).WithStats(server.stats) + grpcHandler := NewGRPCHandler(server.api).WithLogger(server.logger).WithStats(server.stats).WithQueryLogger(server.queryLogger) // add server permissions if we've got 'em if server.perms != nil { @@ -1591,6 +1607,7 @@ type wrappedStream struct { func (w *wrappedStream) Context() context.Context { return w.uiContext } + func (w *wrappedStream) RecvMsg(m interface{}) error { return w.ServerStream.RecvMsg(m) } @@ -1599,39 +1616,46 @@ func (w *wrappedStream) SendMsg(m interface{}) error { return w.ServerStream.SendMsg(m) } -func newWrappedStream(s grpc.ServerStream, ctx context.Context) grpc.ServerStream { - return &wrappedStream{s, ctx} -} - -func Valid(ctx context.Context, auth *authn.Auth) (context.Context, error) { +func Valid(ctx context.Context, method string, auth *authn.Auth, req interface{}, logger logger.Logger) (context.Context, error) { md, ok := metadata.FromIncomingContext(ctx) if !ok { return ctx, status.Errorf(codes.InvalidArgument, "missing metadata") } - authorization, ok := md["authorization"] + authorization, ok := md["authorization"] if !ok { - c, ok := md["cookie"] - if !ok { + c, there := md["cookie"] + if !there { return ctx, status.Errorf(codes.InvalidArgument, "missing authorization token") } cookies := strings.Split(c[0], "; ") for _, cookie := range cookies { if strings.HasPrefix(cookie, "molecula-chip") { authorization = strings.Split(cookie, "molecula-chip=")[1:] + break } } - if len(authorization) == 0 { - return ctx, status.Errorf(codes.InvalidArgument, "missing authorization token") - - } + } + if len(authorization) == 0 { + return ctx, status.Errorf(codes.InvalidArgument, "missing authorization token") } token := strings.TrimPrefix(authorization[0], "Bearer ") - userinfo, err := auth.Authenticate(token) + uinfo, err := auth.Authenticate(token) if err != nil { return ctx, status.Errorf(codes.Unauthenticated, err.Error()) } - return context.WithValue(ctx, "userinfo", userinfo), nil + p, ok := peer.FromContext(ctx) + ip := "" + if ok { + ip = p.Addr.String() + } + ua, ok := md["user-agent"] + if !ok { + ua = []string{""} + } + logger.Infof("GRPC: %v, %v, %v, %v, %v, %v", ip, ua, method, uinfo.UserID, uinfo.UserName, req) + + return context.WithValue(ctx, "userinfo", uinfo), nil } diff --git a/server/grpc_test.go b/server/grpc_test.go index da56b02ca..c2b993a96 100644 --- a/server/grpc_test.go +++ b/server/grpc_test.go @@ -18,6 +18,7 @@ import ( pilosa "github.com/molecula/featurebase/v2" "github.com/molecula/featurebase/v2/authn" "github.com/molecula/featurebase/v2/authz" + "github.com/molecula/featurebase/v2/logger" "github.com/molecula/featurebase/v2/pql" pb "github.com/molecula/featurebase/v2/proto" "github.com/molecula/featurebase/v2/server" @@ -1375,8 +1376,7 @@ func setUpTestQuerySQLUnary(ctx context.Context, t *testing.T) (gh *server.GRPCH t.Helper() m := test.RunCommand(t) - gh = server.NewGRPCHandler(m.API) - + gh = server.NewGRPCHandler(m.API).WithQueryLogger(logger.NewStandardLogger(os.Stdout)) // grouper grouper := m.MustCreateIndex(t, "grouper", pilosa.IndexOptions{Keys: false, TrackExistence: true}) m.MustCreateField(t, grouper.Name(), "color", pilosa.OptFieldKeys()) diff --git a/server/server.go b/server/server.go index c2dc433cd..781a1a216 100644 --- a/server/server.go +++ b/server/server.go @@ -70,9 +70,9 @@ type Command struct { done chan struct{} logOutput io.Writer - querylogOutput io.Writer + queryLogOutput io.Writer logger loggerLogger - querylogger loggerLogger + queryLogger loggerLogger Handler pilosa.Handler grpcServer *grpcServer @@ -476,7 +476,7 @@ func (m *Command) SetupServer() error { pilosa.OptServerOpenTranslateReader(http.GetOpenTranslateReaderWithLockerFunc(c, &sync.Mutex{})), pilosa.OptServerOpenIDAllocator(pilosa.OpenIDAllocator), pilosa.OptServerLogger(m.logger), - pilosa.OptServerQueryLogger(m.querylogger), + pilosa.OptServerQueryLogger(m.queryLogger), pilosa.OptServerSystemInfo(gopsutil.NewSystemInfo()), pilosa.OptServerGCNotifier(gcnotify.NewActiveGCNotifier()), pilosa.OptServerStatsClient(statsClient), @@ -545,11 +545,12 @@ func (m *Command) SetupServer() error { err = m.setupQueryLogger() if err != nil { - return errors.Wrap(err, "setting up querylogger") + return errors.Wrap(err, "setting up queryLogger") } - m.querylogger.Infof("Group with admin level access: %v", p.Admin) - m.querylogger.Infof("Permissions: %+v", p.Permissions) + m.queryLogger.Infof("Featurebase Server Started") + m.queryLogger.Infof("Group with admin level access: %v", p.Admin) + m.queryLogger.Infof("Permissions: %+v", p.Permissions) // disable postgres binding if auth is enabled m.Config.Postgres.Bind = "" @@ -569,13 +570,14 @@ func (m *Command) SetupServer() error { OptGRPCServerStats(statsClient), OptGRPCServerAuth(m.auth), OptGRPCServerPerm(&p), + OptGRPCServerQueryLogger(m.queryLogger), ) m.Handler, err = http.NewHandler( http.OptHandlerAllowedOrigins(m.Config.Handler.AllowedOrigins), http.OptHandlerAPI(m.API), http.OptHandlerLogger(m.logger), - http.OptHandlerQueryLogger(m.querylogger), + http.OptHandlerQueryLogger(m.queryLogger), http.OptHandlerFileSystem(&statik.FileSystem{}), http.OptHandlerListener(m.ln, m.Config.Advertise), http.OptHandlerCloseTimeout(m.closeTimeout), @@ -642,16 +644,16 @@ func (m *Command) setupQueryLogger() error { return errors.Wrap(err, "opening file") } } - m.querylogOutput = f + m.queryLogOutput = f - m.querylogger = logger.NewStandardLogger(m.querylogOutput) + m.queryLogger = logger.NewStandardLogger(m.queryLogOutput) sighup := make(chan os.Signal, 1) signal.Notify(sighup, syscall.SIGHUP) go func() { for range sighup { if err := f.Reopen(); err != nil { - m.querylogger.Infof("reopen: %s\n", err.Error()) + m.queryLogger.Infof("reopen: %s\n", err.Error()) } } }()