diff --git a/cmd/apiserver/main.go b/cmd/apiserver/main.go index a247163806..3deb64935f 100644 --- a/cmd/apiserver/main.go +++ b/cmd/apiserver/main.go @@ -3,16 +3,17 @@ package main import ( goflag "flag" "fmt" - "log" "os" - "github.com/golang/glog" + kitLog "github.com/go-kit/kit/log" + "github.com/go-stack/stack" "github.com/spf13/pflag" apipkg "github.com/sapcc/kubernikus/pkg/api" "github.com/sapcc/kubernikus/pkg/api/rest" "github.com/sapcc/kubernikus/pkg/api/rest/operations" "github.com/sapcc/kubernikus/pkg/api/spec" + logutil "github.com/sapcc/kubernikus/pkg/util/log" "github.com/sapcc/kubernikus/pkg/version" ) @@ -23,10 +24,17 @@ func init() { } func main() { + var logger kitLog.Logger + logger = kitLog.NewLogfmtLogger(kitLog.NewSyncWriter(os.Stderr)) + logger = logutil.NewTrailingNilFilter(logger) + logger = kitLog.With(logger, "ts", kitLog.DefaultTimestampUTC, "caller", Caller(3)) swaggerSpec, err := spec.Spec() if err != nil { - log.Fatalln(err) + logger.Log( + "msg", "failed to spec swagger spec", + "err", err) + os.Exit(1) } var server *rest.Server // make sure init is called @@ -53,12 +61,21 @@ func main() { api := operations.NewKubernikusAPI(swaggerSpec) - rt := &apipkg.Runtime{Namespace: namespace} + rt := &apipkg.Runtime{ + Namespace: namespace, + Logger: logger, + } rt.Kubernikus, rt.Kubernetes = rest.NewKubeClients() if err := rest.Configure(api, rt); err != nil { - glog.Fatalf("Failed to configure apiserver :%s", err) + logger.Log( + "msg", "failed to configure API server", + "err", err) + os.Exit(1) } - glog.Infof("Starting kubernikus apiserver v%v. Using namespace %s", version.GitCommit, namespace) + logger.Log( + "msg", "starting Kubernikus API", + "namespace", namespace, + "version", version.GitCommit) // get server with flag values filled out server = rest.NewServer(api) @@ -67,7 +84,14 @@ func main() { server.ConfigureAPI() if err := server.Serve(); err != nil { - log.Fatalln(err) + logger.Log( + "msg", "failed to start API server", + "err", err) + os.Exit(1) } } + +func Caller(depth int) kitLog.Valuer { + return func() interface{} { return fmt.Sprintf("%+v", stack.Caller(depth)) } +} diff --git a/pkg/api/handlers/get_openstack_metadata.go b/pkg/api/handlers/get_openstack_metadata.go index e0ef530c6c..853ad6241c 100644 --- a/pkg/api/handlers/get_openstack_metadata.go +++ b/pkg/api/handlers/get_openstack_metadata.go @@ -6,7 +6,7 @@ import ( "github.com/sapcc/kubernikus/pkg/api" "github.com/sapcc/kubernikus/pkg/api/models" "github.com/sapcc/kubernikus/pkg/api/rest/operations" - "github.com/sapcc/kubernikus/pkg/client/openstack" + "github.com/sapcc/kubernikus/pkg/client/openstack/scoped" ) func NewGetOpenstackMetadata(rt *api.Runtime) operations.GetOpenstackMetadataHandler { @@ -29,7 +29,7 @@ func (d *getOpenstackMetadata) Handle(params operations.GetOpenstackMetadataPara }, } - client, err := openstack.NewScopedClient(authOptions) + client, err := scoped.NewClient(authOptions, d.Logger) if err != nil { return NewErrorResponse(&operations.GetOpenstackMetadataDefault{}, 500, err.Error()) } diff --git a/pkg/api/rest/api_test.go b/pkg/api/rest/api_test.go index 629ae4f9c8..77ada3da0f 100644 --- a/pkg/api/rest/api_test.go +++ b/pkg/api/rest/api_test.go @@ -9,6 +9,7 @@ import ( "strings" "testing" + kitlog "github.com/go-kit/kit/log" errors "github.com/go-openapi/errors" "github.com/stretchr/testify/assert" metav1 "k8s.io/apimachinery/pkg/apis/meta/v1" @@ -57,6 +58,7 @@ func createTestHandler(t *testing.T) (http.Handler, *apipkg.Runtime) { Namespace: NAMESPACE, Kubernikus: kubernikusfake.NewSimpleClientset(), Kubernetes: fake.NewSimpleClientset(), + Logger: kitlog.NewNopLogger(), } if err := Configure(api, rt); err != nil { t.Fatal(err) diff --git a/pkg/api/rest/configure.go b/pkg/api/rest/configure.go index eca69228b7..7ef24446b0 100644 --- a/pkg/api/rest/configure.go +++ b/pkg/api/rest/configure.go @@ -2,16 +2,21 @@ package rest import ( "fmt" + "net/http" + "strings" "github.com/go-openapi/errors" runtime "github.com/go-openapi/runtime" - "github.com/golang/glog" + "github.com/go-openapi/runtime/middleware" + "github.com/justinas/alice" + "github.com/rs/cors" apipkg "github.com/sapcc/kubernikus/pkg/api" "github.com/sapcc/kubernikus/pkg/api/auth" "github.com/sapcc/kubernikus/pkg/api/handlers" "github.com/sapcc/kubernikus/pkg/api/rest/operations" "github.com/sapcc/kubernikus/pkg/api/spec" + logutil "github.com/sapcc/kubernikus/pkg/util/log" ) func Configure(api *operations.KubernikusAPI, rt *apipkg.Runtime) error { @@ -23,7 +28,7 @@ func Configure(api *operations.KubernikusAPI, rt *apipkg.Runtime) error { // // Example: api.Logger = func(msg string, args ...interface{}) { - glog.InfoDepth(2, fmt.Sprintf(msg, args...)) + rt.Logger.Log("msg", fmt.Sprintf(msg, args...)) } api.JSONConsumer = runtime.JSONConsumer() @@ -60,5 +65,39 @@ func Configure(api *operations.KubernikusAPI, rt *apipkg.Runtime) error { api.GetClusterEventsHandler = handlers.NewGetClusterEvents(rt) api.ServerShutdown = func() {} + + api.Middleware = func(builder middleware.Builder) http.Handler { + return setupGlobalMiddleware(api.Context().APIHandler(builder), rt) + } return nil } + +// The middleware configuration happens before anything, this middleware also applies to serving the swagger.json document. +// So this is a good place to plug in a panic handling middleware, logging and metrics +func setupGlobalMiddleware(handler http.Handler, rt *apipkg.Runtime) http.Handler { + corsHandler := cors.New(cors.Options{ + AllowedHeaders: []string{"X-Auth-Token", "Content-Type", "Accept"}, + AllowedMethods: []string{"GET", "HEAD", "POST", "DELETE", "PUT"}, + MaxAge: 600, + }).Handler + + loggingHandler := func(next http.Handler) http.Handler { + return logutil.LoggingHandler(rt.Logger, next) + } + + redocHandler := func(next http.Handler) http.Handler { + return middleware.Redoc(middleware.RedocOpts{Path: "swagger"}, next) + } + + staticHandler := func(next http.Handler) http.Handler { + return http.HandlerFunc(func(rw http.ResponseWriter, r *http.Request) { + if strings.HasPrefix(r.URL.Path, "/docs") { + http.StripPrefix("/docs", http.FileServer(http.Dir("static/docs"))).ServeHTTP(rw, r) + return + } + next.ServeHTTP(rw, r) + }) + } + + return alice.New(loggingHandler, handlers.RootHandler, redocHandler, staticHandler, corsHandler).Then(handler) +} diff --git a/pkg/api/rest/configure_kubernikus.go b/pkg/api/rest/configure_kubernikus.go index 68a0e892e1..3a5b23e944 100644 --- a/pkg/api/rest/configure_kubernikus.go +++ b/pkg/api/rest/configure_kubernikus.go @@ -3,16 +3,9 @@ package rest import ( "crypto/tls" "net/http" - "os" - "strings" - "github.com/go-openapi/runtime/middleware" - gmiddleware "github.com/gorilla/handlers" - "github.com/justinas/alice" - "github.com/rs/cors" graceful "github.com/tylerb/graceful" - "github.com/sapcc/kubernikus/pkg/api/handlers" "github.com/sapcc/kubernikus/pkg/api/rest/operations" ) @@ -25,8 +18,9 @@ func configureFlags(api *operations.KubernikusAPI) { } func configureAPI(api *operations.KubernikusAPI) http.Handler { - - return setupGlobalMiddleware(api.Serve(setupMiddlewares)) + return api.Serve(func(handler http.Handler) http.Handler { + return handler + }) } // The TLS configuration before HTTPS server starts. @@ -40,38 +34,3 @@ func configureTLS(tlsConfig *tls.Config) { // scheme value will be set accordingly: "http", "https" or "unix" func configureServer(s *graceful.Server, scheme, addr string) { } - -// The middleware configuration is for the handler executors. These do not apply to the swagger.json document. -// The middleware executes after routing but before authentication, binding and validation -func setupMiddlewares(handler http.Handler) http.Handler { - return handler -} - -// The middleware configuration happens before anything, this middleware also applies to serving the swagger.json document. -// So this is a good place to plug in a panic handling middleware, logging and metrics -func setupGlobalMiddleware(handler http.Handler) http.Handler { - corsHandler := cors.New(cors.Options{ - AllowedHeaders: []string{"X-Auth-Token", "Content-Type", "Accept"}, - AllowedMethods: []string{"GET", "HEAD", "POST", "DELETE", "PUT"}, - MaxAge: 600, - }).Handler - - loggingHandler := func(next http.Handler) http.Handler { - return gmiddleware.LoggingHandler(os.Stdout, next) - } - redocHandler := func(next http.Handler) http.Handler { - return middleware.Redoc(middleware.RedocOpts{Path: "swagger"}, next) - } - - return alice.New(loggingHandler, handlers.RootHandler, redocHandler, StaticFiles, corsHandler).Then(handler) -} - -func StaticFiles(next http.Handler) http.Handler { - return http.HandlerFunc(func(rw http.ResponseWriter, r *http.Request) { - if strings.HasPrefix(r.URL.Path, "/docs") { - http.StripPrefix("/docs", http.FileServer(http.Dir("static/docs"))).ServeHTTP(rw, r) - return - } - next.ServeHTTP(rw, r) - }) -} diff --git a/pkg/api/runtime.go b/pkg/api/runtime.go index 54fc060b1d..137de915b3 100644 --- a/pkg/api/runtime.go +++ b/pkg/api/runtime.go @@ -1,6 +1,8 @@ package api import ( + "github.com/go-kit/kit/log" + "github.com/sapcc/kubernikus/pkg/generated/clientset" "k8s.io/client-go/kubernetes" ) @@ -9,4 +11,5 @@ type Runtime struct { Kubernikus clientset.Interface Kubernetes kubernetes.Interface Namespace string + Logger log.Logger } diff --git a/pkg/client/openstack/metadata.go b/pkg/client/openstack/scoped/client.go similarity index 55% rename from pkg/client/openstack/metadata.go rename to pkg/client/openstack/scoped/client.go index 47cb0635c2..407cd1dc40 100644 --- a/pkg/client/openstack/metadata.go +++ b/pkg/client/openstack/scoped/client.go @@ -1,6 +1,7 @@ -package openstack +package scoped import ( + "github.com/go-kit/kit/log" "github.com/gophercloud/gophercloud" "github.com/gophercloud/gophercloud/openstack" "github.com/gophercloud/gophercloud/openstack/compute/v2/extensions/keypairs" @@ -13,73 +14,85 @@ import ( "github.com/gophercloud/gophercloud/openstack/networking/v2/subnets" "github.com/gophercloud/gophercloud/pagination" "github.com/sapcc/kubernikus/pkg/api/models" + "github.com/sapcc/kubernikus/pkg/client/openstack/util" + utillog "github.com/sapcc/kubernikus/pkg/util/log" ) -type scopedClient struct { - providerClient *gophercloud.ProviderClient - networkClient *gophercloud.ServiceClient - computeClient *gophercloud.ServiceClient - identityClient *gophercloud.ServiceClient +type client struct { + util.AuthenticatedClient + Logger log.Logger } -type ScopedClient interface { +type Client interface { + Authenticate(*tokens.AuthOptions) error GetMetadata() (*models.OpenstackMetadata, error) } -func NewScopedClient(authOptions *tokens.AuthOptions) (ScopedClient, error) { - var err error - client := &scopedClient{} +func NewClient(authOptions *tokens.AuthOptions, logger log.Logger) (Client, error) { + logger = utillog.NewAuthLogger(logger, authOptions) - if client.providerClient, err = openstack.NewClient(authOptions.IdentityEndpoint); err != nil { - return nil, err + var c Client + c = &client{Logger: logger} + c = LoggingClient{c, logger} + + return c, c.Authenticate(authOptions) +} + +func (c *client) Authenticate(authOptions *tokens.AuthOptions) error { + providerClient, err := utillog.NewLoggingProviderClient(authOptions.IdentityEndpoint, c.Logger) + if err != nil { + return err } - if err := openstack.AuthenticateV3(client.providerClient, authOptions, gophercloud.EndpointOpts{}); err != nil { - return nil, err + if err := openstack.AuthenticateV3(providerClient, authOptions, gophercloud.EndpointOpts{}); err != nil { + return err } - if client.identityClient, err = openstack.NewIdentityV3(client.providerClient, gophercloud.EndpointOpts{}); err != nil { - return nil, err + if c.IdentityClient, err = openstack.NewIdentityV3(providerClient, gophercloud.EndpointOpts{}); err != nil { + return err } - if client.computeClient, err = openstack.NewComputeV2(client.providerClient, gophercloud.EndpointOpts{}); err != nil { - return nil, err + if c.ComputeClient, err = openstack.NewComputeV2(providerClient, gophercloud.EndpointOpts{}); err != nil { + return err } - if client.networkClient, err = openstack.NewNetworkV2(client.providerClient, gophercloud.EndpointOpts{}); err != nil { - return nil, err + if c.NetworkClient, err = openstack.NewNetworkV2(providerClient, gophercloud.EndpointOpts{}); err != nil { + return err } - return client, nil + return nil } -func (c *scopedClient) GetMetadata() (*models.OpenstackMetadata, error) { - var err error - metadata := &models.OpenstackMetadata{} +func (c *client) GetMetadata() (metadata *models.OpenstackMetadata, err error) { + metadata = &models.OpenstackMetadata{ + Flavors: make([]*models.Flavor, 0), + KeyPairs: make([]*models.KeyPair, 0), + Routers: make([]*models.Router, 0), + SecurityGroups: make([]*models.SecurityGroup, 0), + } if metadata.Routers, err = c.getRouters(); err != nil { - return nil, err + return metadata, err } if metadata.KeyPairs, err = c.getKeyPairs(); err != nil { - return nil, err + return metadata, err } if metadata.SecurityGroups, err = c.getSecurityGroups(); err != nil { - return nil, err + return metadata, err } if metadata.Flavors, err = c.getFlavors(); err != nil { - return nil, err + return metadata, err } - return metadata, nil } -func (c *scopedClient) getRouters() ([]*models.Router, error) { +func (c *client) getRouters() ([]*models.Router, error) { result := []*models.Router{} - err := routers.List(c.networkClient, routers.ListOpts{}).EachPage(func(page pagination.Page) (bool, error) { + err := routers.List(c.NetworkClient, routers.ListOpts{}).EachPage(func(page pagination.Page) (bool, error) { if routerList, err := routers.ExtractRouters(page); err != nil { return false, err } else { @@ -91,30 +104,30 @@ func (c *scopedClient) getRouters() ([]*models.Router, error) { }) if err != nil { - return nil, err + return result, err } for _, router := range result { if router.Networks, err = c.getNetworks(router); err != nil { - return nil, err + return result, err } } return result, nil } -func (c *scopedClient) getNetworks(router *models.Router) ([]*models.Network, error) { +func (c *client) getNetworks(router *models.Router) ([]*models.Network, error) { result := []*models.Network{} networkIDs, err := c.getRouterNetworkIDs(router) if err != nil { - return nil, err + return result, err } for _, networkID := range networkIDs { - network, err := networks.Get(c.networkClient, networkID).Extract() + network, err := networks.Get(c.NetworkClient, networkID).Extract() if err != nil { - return nil, err + return result, err } result = append(result, &models.Network{ID: network.ID, Name: network.Name}) } @@ -128,10 +141,10 @@ func (c *scopedClient) getNetworks(router *models.Router) ([]*models.Network, er return result, nil } -func (c *scopedClient) getRouterNetworkIDs(router *models.Router) ([]string, error) { +func (c *client) getRouterNetworkIDs(router *models.Router) ([]string, error) { result := []string{} - err := ports.List(c.networkClient, ports.ListOpts{DeviceID: router.ID, DeviceOwner: "network:router_interface"}).EachPage(func(page pagination.Page) (bool, error) { + err := ports.List(c.NetworkClient, ports.ListOpts{DeviceID: router.ID, DeviceOwner: "network:router_interface"}).EachPage(func(page pagination.Page) (bool, error) { portList, err := ports.ExtractPorts(page) if err != nil { return false, err @@ -145,27 +158,27 @@ func (c *scopedClient) getRouterNetworkIDs(router *models.Router) ([]string, err return result, err } -func (c *scopedClient) getSubnetIDs(network *models.Network) ([]string, error) { - result, err := networks.Get(c.networkClient, network.ID).Extract() +func (c *client) getSubnetIDs(network *models.Network) ([]string, error) { + result, err := networks.Get(c.NetworkClient, network.ID).Extract() if err != nil { - return nil, err + return []string{}, err } return result.Subnets, nil } -func (c *scopedClient) getSubnets(network *models.Network) ([]*models.Subnet, error) { +func (c *client) getSubnets(network *models.Network) ([]*models.Subnet, error) { result := []*models.Subnet{} subnetIDs, err := c.getSubnetIDs(network) if err != nil { - return nil, err + return result, err } for _, subnetID := range subnetIDs { - subnet, err := subnets.Get(c.networkClient, subnetID).Extract() + subnet, err := subnets.Get(c.NetworkClient, subnetID).Extract() if err != nil { - return nil, err + return result, err } result = append(result, &models.Subnet{ID: subnet.ID, Name: subnet.Name, CIDR: subnet.CIDR}) } @@ -173,17 +186,17 @@ func (c *scopedClient) getSubnets(network *models.Network) ([]*models.Subnet, er return result, nil } -func (c *scopedClient) getKeyPairs() ([]*models.KeyPair, error) { +func (c *client) getKeyPairs() ([]*models.KeyPair, error) { result := []*models.KeyPair{} - pager, err := keypairs.List(c.computeClient).AllPages() + pager, err := keypairs.List(c.ComputeClient).AllPages() if err != nil { - return nil, err + return result, err } keyList, err := keypairs.ExtractKeyPairs(pager) if err != nil { - return nil, err + return result, err } for _, key := range keyList { @@ -193,10 +206,10 @@ func (c *scopedClient) getKeyPairs() ([]*models.KeyPair, error) { return result, nil } -func (c *scopedClient) getSecurityGroups() ([]*models.SecurityGroup, error) { +func (c *client) getSecurityGroups() ([]*models.SecurityGroup, error) { result := []*models.SecurityGroup{} - err := secgroups.List(c.computeClient).EachPage(func(page pagination.Page) (bool, error) { + err := secgroups.List(c.ComputeClient).EachPage(func(page pagination.Page) (bool, error) { secGroupList, err := secgroups.ExtractSecurityGroups(page) if err != nil { return false, err @@ -210,10 +223,10 @@ func (c *scopedClient) getSecurityGroups() ([]*models.SecurityGroup, error) { return result, err } -func (c *scopedClient) getFlavors() ([]*models.Flavor, error) { +func (c *client) getFlavors() ([]*models.Flavor, error) { result := []*models.Flavor{} - err := flavors.ListDetail(c.computeClient, &flavors.ListOpts{}).EachPage(func(page pagination.Page) (bool, error) { + err := flavors.ListDetail(c.ComputeClient, &flavors.ListOpts{}).EachPage(func(page pagination.Page) (bool, error) { list, err := flavors.ExtractFlavors(page) if err != nil { return false, err diff --git a/pkg/client/openstack/scoped/logging.go b/pkg/client/openstack/scoped/logging.go new file mode 100644 index 0000000000..dcbe07ed46 --- /dev/null +++ b/pkg/client/openstack/scoped/logging.go @@ -0,0 +1,48 @@ +package scoped + +import ( + "time" + + "github.com/go-kit/kit/log" + "github.com/gophercloud/gophercloud/openstack/identity/v3/tokens" + + "github.com/sapcc/kubernikus/pkg/api/models" +) + +type LoggingClient struct { + Client Client + Logger log.Logger +} + +func (c LoggingClient) GetMetadata() (metadata *models.OpenstackMetadata, err error) { + defer func(begin time.Time) { + c.Logger.Log( + "msg", "fetched metadata", + "flavors", len(metadata.Flavors), + "keypairs", len(metadata.KeyPairs), + "routers", len(metadata.Routers), + "security_groups", len(metadata.SecurityGroups), + "took", time.Since(begin), + "v", 1, + "err", err, + ) + }(time.Now()) + + return c.Client.GetMetadata() +} + +func (c LoggingClient) Authenticate(authOptions *tokens.AuthOptions) (err error) { + defer func(begin time.Time) { + v := 2 + if err != nil { + v = 0 + } + c.Logger.Log( + "msg", "authenticated", + "took", time.Since(begin), + "v", v, + "err", err, + ) + }(time.Now()) + return c.Client.Authenticate(authOptions) +} diff --git a/pkg/client/openstack/util/factory.go b/pkg/client/openstack/util/factory.go new file mode 100644 index 0000000000..0678bf3bb7 --- /dev/null +++ b/pkg/client/openstack/util/factory.go @@ -0,0 +1,12 @@ +package util + +import ( + "github.com/gophercloud/gophercloud" +) + +type AuthenticatedClient struct { + providerClient *gophercloud.ProviderClient + NetworkClient *gophercloud.ServiceClient + ComputeClient *gophercloud.ServiceClient + IdentityClient *gophercloud.ServiceClient +} diff --git a/pkg/util/log/authlogger.go b/pkg/util/log/authlogger.go new file mode 100644 index 0000000000..b1ae6ea9f2 --- /dev/null +++ b/pkg/util/log/authlogger.go @@ -0,0 +1,69 @@ +package log + +import ( + "fmt" + + kitlog "github.com/go-kit/kit/log" + "github.com/gophercloud/gophercloud/openstack/identity/v3/tokens" +) + +func NewAuthLogger(logger kitlog.Logger, authOptions *tokens.AuthOptions) kitlog.Logger { + if project := getProject(authOptions); project != "" { + logger = kitlog.With(logger, "project", project) + } + + if authMethod := getAuthMethod(authOptions); authMethod != "" { + logger = kitlog.With(logger, "auth", authMethod) + } + + if principal := getPrincipal(authOptions); principal != "" { + logger = kitlog.With(logger, "principal", principal) + } + return logger +} + +func getProject(authOptions *tokens.AuthOptions) string { + if authOptions.Scope.ProjectID != "" { + return authOptions.Scope.ProjectID + } + + domain := "" + if authOptions.Scope.DomainID != "" { + domain = authOptions.Scope.DomainID + } else { + domain = authOptions.Scope.DomainName + } + + return fmt.Sprintf("%s/%s", domain, authOptions.Scope.ProjectName) +} + +func getAuthMethod(authOptions *tokens.AuthOptions) string { + if authOptions.TokenID != "" { + return "token" + } + + if authOptions.Password != "" { + return "password" + } + + return "" +} + +func getPrincipal(authOptions *tokens.AuthOptions) string { + if authOptions.TokenID != "" { + return "" + } + + if authOptions.UserID != "" { + return authOptions.UserID + } + + domain := "" + if authOptions.DomainID != "" { + domain = authOptions.DomainID + } else { + domain = authOptions.DomainName + } + + return fmt.Sprintf("%s/%s", domain, authOptions.Username) +} diff --git a/pkg/util/log/gophercloud.go b/pkg/util/log/gophercloud.go new file mode 100644 index 0000000000..39f7c148e2 --- /dev/null +++ b/pkg/util/log/gophercloud.go @@ -0,0 +1,70 @@ +package log + +import ( + "net/http" + "strings" + "time" + + kitlog "github.com/go-kit/kit/log" + "github.com/gophercloud/gophercloud" + "github.com/gophercloud/gophercloud/openstack" +) + +func NewLoggingProviderClient(endpoint string, logger kitlog.Logger) (*gophercloud.ProviderClient, error) { + providerClient, err := openstack.NewClient(endpoint) + if err != nil { + return nil, err + } + + transport := providerClient.HTTPClient.Transport + if transport == nil { + transport = http.DefaultTransport + } + providerClient.HTTPClient.Transport = &loggingRoundTripper{ + transport, + kitlog.With(logger, "api", "egress"), + } + + return providerClient, err +} + +type loggingRoundTripper struct { + rt http.RoundTripper + Logger kitlog.Logger +} + +func (lrt *loggingRoundTripper) RoundTrip(request *http.Request) (response *http.Response, err error) { + defer func(begin time.Time) { + keyvals := make([]interface{}, 0, 6) + + if response != nil { + keyvals = append(keyvals, + "status", response.StatusCode, + "openstack_id", strings.Join(requestIds(response), ",")) + } + + keyvals = append(keyvals, + "took", time.Since(begin), + "v", 2, + "err", err, + ) + + log(lrt.Logger, request, keyvals...) + }(time.Now()) + + return lrt.rt.RoundTrip(request) +} + +func requestIds(response *http.Response) []string { + ids := []string{} + + if id := response.Header.Get("X-Openstack-Request-ID"); id != "" { + ids = append(ids, id) + } + + if id := response.Header.Get("X-Compute-Request-ID"); id != "" { + ids = append(ids, id) + } + + return ids +} diff --git a/pkg/util/log/middleware.go b/pkg/util/log/middleware.go new file mode 100644 index 0000000000..80e48f48b8 --- /dev/null +++ b/pkg/util/log/middleware.go @@ -0,0 +1,165 @@ +package log + +import ( + "bufio" + "fmt" + "net" + "net/http" + "strings" + "time" + + kitlog "github.com/go-kit/kit/log" +) + +func LoggingHandler(logger kitlog.Logger, next http.Handler) http.Handler { + logger = kitlog.With(logger, "api", "ingress") + return http.HandlerFunc(func(rw http.ResponseWriter, request *http.Request) { + wrapper := makeWrapper(rw) + + defer func(begin time.Time) { + log(logger, request, + "status", wrapper.Status(), + "size", wrapper.Size(), + "took", time.Since(begin)) + }(time.Now()) + + next.ServeHTTP(wrapper, request) + }) +} + +func log(logger kitlog.Logger, request *http.Request, extra ...interface{}) { + var keyvals []interface{} + + source_ip, _, err := net.SplitHostPort(request.RemoteAddr) + if err != nil { + source_ip = request.RemoteAddr + } + + if source_ip != "" { + keyvals = append(keyvals, "source_ip", source_ip) + } + + keyvals = append(keyvals, "method", request.Method) + + host, host_port, err := net.SplitHostPort(request.Host) + if err == nil { + if host != "" { + keyvals = append(keyvals, + "host", host) + } + if host_port != "" { + keyvals = append(keyvals, + "port", host_port) + } + } + + keyvals = append(keyvals, "path", request.URL.EscapedPath()) + + for i, k := range request.URL.Query() { + keyvals = append(keyvals, i, strings.Join(k, ",")) + } + + keyvals = append(keyvals, "user_agent", request.UserAgent()) + keyvals = append(keyvals, extra...) + logger.Log(keyvals...) +} + +// this stuff is copied from gorilla + +func makeWrapper(w http.ResponseWriter) loggingResponseWriter { + var logger loggingResponseWriter = &responseLogger{w: w, status: http.StatusOK} + if _, ok := w.(http.Hijacker); ok { + logger = &hijackLogger{responseLogger{w: w, status: http.StatusOK}} + } + h, ok1 := logger.(http.Hijacker) + c, ok2 := w.(http.CloseNotifier) + if ok1 && ok2 { + return hijackCloseNotifier{logger, h, c} + } + if ok2 { + return &closeNotifyWriter{logger, c} + } + return logger +} + +type hijackLogger struct { + responseLogger +} + +func (l *hijackLogger) Hijack() (net.Conn, *bufio.ReadWriter, error) { + h := l.responseLogger.w.(http.Hijacker) + conn, rw, err := h.Hijack() + if err == nil && l.responseLogger.status == 0 { + // The status will be StatusSwitchingProtocols if there was no error and + // WriteHeader has not been called yet + l.responseLogger.status = http.StatusSwitchingProtocols + } + return conn, rw, err +} + +type closeNotifyWriter struct { + loggingResponseWriter + http.CloseNotifier +} + +type hijackCloseNotifier struct { + loggingResponseWriter + http.Hijacker + http.CloseNotifier +} + +type loggingResponseWriter interface { + commonLoggingResponseWriter + http.Pusher +} + +type commonLoggingResponseWriter interface { + http.ResponseWriter + http.Flusher + Status() int + Size() int +} + +type responseLogger struct { + w http.ResponseWriter + status int + size int +} + +func (l *responseLogger) Header() http.Header { + return l.w.Header() +} + +func (l *responseLogger) Write(b []byte) (int, error) { + size, err := l.w.Write(b) + l.size += size + return size, err +} + +func (l *responseLogger) WriteHeader(s int) { + l.w.WriteHeader(s) + l.status = s +} + +func (l *responseLogger) Status() int { + return l.status +} + +func (l *responseLogger) Size() int { + return l.size +} + +func (l *responseLogger) Flush() { + f, ok := l.w.(http.Flusher) + if ok { + f.Flush() + } +} + +func (l *responseLogger) Push(target string, opts *http.PushOptions) error { + p, ok := l.w.(http.Pusher) + if !ok { + return fmt.Errorf("responseLogger does not implement http.Pusher") + } + return p.Push(target, opts) +}