Beispiel #1
0
// Logger returns a Goji web middleware that logs web transactions in the format
// I want.
func Logger(c *web.C, h http.Handler) http.Handler {

	fn := func(w http.ResponseWriter, r *http.Request) {
		startTime := time.Now()
		fields := log.Fields{
			"requestId": middleware.GetReqID(*c),
			"client":    r.RemoteAddr,
			"url":       r.URL.String(),
			"method":    r.Method,
			"protocol":  r.Proto,
			"referer":   r.Referer(),
			"start":     startTime,
		}
		log.WithFields(fields).Debug("Request started.")
		lw := mutil.WrapWriter(w)
		h.ServeHTTP(lw, r)
		endTime := time.Now()
		duration := endTime.Sub(startTime)
		fields["duration"] = duration.Nanoseconds()
		status := lw.Status()
		fields["status"] = status
		switch {
		case status < 300: // 100- and 200-series statuses
			log.WithFields(fields).Info("OK")
		case status < 400: // 300-series redirection
			log.WithFields(fields).Info("Redirected")
		case status < 500: // 400-series client error
			log.WithFields(fields).Warn("Client error")
		default: // 500-series server erorr
			log.WithFields(fields).Error("Server error!")
		}
	}
	return http.HandlerFunc(fn)
}
Beispiel #2
0
// WrapC wraps a handler to track request counts and response status
// code counts namespaced by goji Pattern. It will only include
// patterns that implemnt fmt.Stringer. For example, if a request
// matches the pattern /foo/:bar and returns a 204 status code, it
// will increment "foo.:bar.request" and "foo.:bar.response.204".
//
// WrapC is only safe to use once per request. If you have nested
// muxes, use WrapC in the outer mux and WrapSubmuxC on the inner mux.
func WrapC(h goji.Handler) goji.Handler {
	return goji.HandlerFunc(func(ctx context.Context, w http.ResponseWriter, r *http.Request) {
		var patterns []goji.Pattern

		curr := middleware.Pattern(ctx)
		if curr != nil {
			patterns = append(patterns, curr)
		}

		ctx = context.WithValue(ctx, patCtxKey, &patterns)
		w2 := mutil.WrapWriter(w)
		h.ServeHTTPC(ctx, w2, r)

		patStrs := make([]string, len(patterns))
		for i, pattern := range patterns {
			patStr, ok := pattern.(fmt.Stringer)
			if !ok {
				continue
			}

			patStrs[i] = strings.TrimSuffix(patStr.String(), "/*")
		}

		fullPatStr := strings.Trim(strings.Replace(path.Join(patStrs...), "/", ".", -1), ".")

		if fullPatStr != "" {
			Increment(fmt.Sprintf("%s.request", fullPatStr))
			Increment(fmt.Sprintf("%s.response.%d", fullPatStr, w2.Status()))
		}
	})
}
Beispiel #3
0
// bless is the meat of kami.
// It wraps a ContextHandler into an httprouter compatible request,
// in order to run all the middleware and other special handlers.
func bless(k ContextHandler, base *context.Context, m *middlewares, panicHandler *HandlerType, logHandler *func(context.Context, mutil.WriterProxy, *http.Request), closeHandler *func(context.Context, *http.Request)) httprouter.Handle {
	return func(w http.ResponseWriter, r *http.Request, params httprouter.Params) {
		ctx := defaultContext(*base, r)
		if len(params) > 0 {
			ctx = newContextWithParams(ctx, params)
		}
		ranLogHandler := false   // track this in case the log handler blows up
		ranCloseHandler := false // track this in case the log handler blows up

		writer := w
		var proxy mutil.WriterProxy
		if *logHandler != nil {
			proxy = mutil.WrapWriter(w)
			writer = proxy
		}

		if *panicHandler != nil {
			defer func() {
				if err := recover(); err != nil {
					ctx = newContextWithException(ctx, err)
					wrap(*panicHandler).ServeHTTPContext(ctx, writer, r)

					if *closeHandler != nil && !ranCloseHandler {
						(*closeHandler)(ctx, r)
					}

					if *logHandler != nil && !ranLogHandler {
						(*logHandler)(ctx, proxy, r)
						// should only happen if header hasn't been written
						proxy.WriteHeader(http.StatusInternalServerError)
					}

				}
			}()
		}

		ctx, ok := m.run(ctx, writer, r)
		if ok {
			k.ServeHTTPContext(ctx, writer, r)
		}

		if *closeHandler != nil {
			ranCloseHandler = true
			(*closeHandler)(ctx, r)
		}

		if *logHandler != nil {
			ranLogHandler = true
			(*logHandler)(ctx, proxy, r)
			// should only happen if header hasn't been written
			proxy.WriteHeader(http.StatusInternalServerError)
		}
	}
}
Beispiel #4
0
func (s *server) ServeHTTPC(ctx context.Context, w http.ResponseWriter, r *http.Request) {

	traceID, err := getTraceID(r)
	if err != nil {
		log.Error("cannot get trace ID")
		http.Error(w, "", http.StatusInternalServerError)
		return
	}

	reqLogger := log.WithField("trace", traceID)
	ctx = newGRPCTraceContext(ctx, traceID)
	ctx = NewLogContext(ctx, reqLogger)

	reqLogger.Info("request started")

	// Time request
	reqStart := time.Now()

	// Sniff the status and content size for logging
	lw := mutil.WrapWriter(w)

	defer func() {
		// Compute request duration
		reqDur := time.Since(reqStart)

		// Log access info
		reqLogger.WithFields(log.Fields{
			"method":      r.Method,
			"type":        "access",
			"status_code": lw.Status(),
			"duration":    reqDur.Seconds(),
			"size":        lw.BytesWritten(),
		}).Infof("%s %s %03d", r.Method, r.URL.String(), lw.Status())

		reqLogger.Info("request finished")

	}()

	if strings.ToUpper(r.Method) == "PUT" {
		reqLogger.WithField("op", "upload").Info()
		s.authHandler(ctx, lw, r, s.upload)
	} else if strings.ToUpper(r.Method) == "GET" {
		reqLogger.WithField("op", "download").Info()
		s.authHandler(ctx, lw, r, s.download)
	} else {
		w.WriteHeader(http.StatusNotFound)
		return
	}
}
// LoggerMiddleware is the middleware that logs http requests and resposnes
// to the logging subsytem of go-horizon.
func LoggerMiddleware(c *web.C, h http.Handler) http.Handler {
	fn := func(w http.ResponseWriter, r *http.Request) {
		ctx := gctx.FromC(*c)
		mw := mutil.WrapWriter(w)

		logStartOfRequest(ctx, r)

		then := time.Now()
		h.ServeHTTP(mw, r)
		duration := time.Now().Sub(then)

		logEndOfRequest(ctx, duration, mw)
	}

	return http.HandlerFunc(fn)
}
Beispiel #6
0
// WithAccessLog is a middleware that logs all access requests performed on the
// sub handler using github.com/corestoreio/csfw/net/ctxlog and
// github.com/rs/xstats stored in context.
func WithAccessLog() ctxhttp.Middleware {
	return func(h ctxhttp.HandlerFunc) ctxhttp.HandlerFunc {
		return func(ctx context.Context, w http.ResponseWriter, r *http.Request) error {

			// Time request
			reqStart := time.Now()

			// Sniff the status and content size for logging
			lw := mutil.WrapWriter(w)

			err := h.ServeHTTPContext(ctx, lw, r)

			// Compute request duration
			reqDur := time.Since(reqStart)

			// Get request status
			status := ResponseStatus(ctx, lw.Status())

			// Log request stats
			sts := xstats.FromContext(ctx)
			tags := []string{
				"status:" + status,
				"status_code:" + strconv.Itoa(lw.Status()),
			}
			sts.Timing("request_time", reqDur, tags...)
			sts.Histogram("request_size", float64(lw.BytesWritten()), tags...)

			ctxlog.FromContext(ctx).Info("request",
				"error", util.Errors(err),
				"method", r.Method,
				"uri", r.URL.String(),
				"type", "access",
				"status", status,
				"status_code", lw.Status(),
				"duration", reqDur.Seconds(),
				"size", lw.BytesWritten(),
				"remote_addr", httputil.GetRemoteAddr(r).String(),
				"user_agent", r.Header.Get("User-Agent"),
				"referer", r.Header.Get("Referer"),
			)
			return err
		}
	}
}
// Middleware that records metrics.
//
// It records success and failures using a meter, and times every request
func requestMetricsMiddleware(c *web.C, h http.Handler) http.Handler {
	return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
		app := c.Env["app"].(*App)
		mw := mutil.WrapWriter(w)

		app.web.requestTimer.Time(func() {
			h.ServeHTTP(mw.(http.ResponseWriter), r)
		})

		if 200 <= mw.Status() && mw.Status() < 400 {
			// a success is in [200, 400)
			app.web.successMeter.Mark(1)
		} else if 400 <= mw.Status() && mw.Status() < 600 {
			// a success is in [400, 600)
			app.web.failureMeter.Mark(1)
		}

	})
}
Beispiel #8
0
// bless is the meat of kami.
// It wraps a HandleFn into an httprouter compatible request,
// in order to run all the middleware and other special handlers.
func bless(k ContextHandler) httprouter.Handle {
	return func(w http.ResponseWriter, r *http.Request, params httprouter.Params) {
		ctx := Context
		if len(params) > 0 {
			ctx = newContextWithParams(Context, params)
		}
		ranLogHandler := false // track this in case the log handler blows up

		writer := w
		var proxy mutil.WriterProxy
		if LogHandler != nil {
			proxy = mutil.WrapWriter(w)
			writer = proxy
		}

		if PanicHandler != nil {
			defer func() {
				if err := recover(); err != nil {
					ctx = newContextWithException(ctx, err)
					wrap(PanicHandler).ServeHTTPContext(ctx, writer, r)

					if LogHandler != nil && !ranLogHandler {
						LogHandler(ctx, proxy, r)
						// should only happen if header hasn't been written
						proxy.WriteHeader(500)
					}
				}
			}()
		}

		ctx, ok := run(ctx, writer, r)
		if ok {
			k.ServeHTTPContext(ctx, writer, r)
		}

		if LogHandler != nil {
			ranLogHandler = true
			LogHandler(ctx, proxy, r)
			// should only happen if header hasn't been written
			proxy.WriteHeader(500)
		}
	}
}
Beispiel #9
0
// NewHandler returns a handler that log access information about each request performed
// on the provided sub-handlers. Uses context's github.com/rs/xlog and
// github.com/rs/xstats if present for logging.
func NewHandler() func(next xhandler.HandlerC) xhandler.HandlerC {
	return func(next xhandler.HandlerC) xhandler.HandlerC {
		return xhandler.HandlerFuncC(func(ctx context.Context, w http.ResponseWriter, r *http.Request) {
			// Time request
			reqStart := time.Now()

			// Sniff the status and content size for logging
			lw := mutil.WrapWriter(w)

			// Call the next handler
			next.ServeHTTPC(ctx, lw, r)

			// Conpute request duration
			reqDur := time.Since(reqStart)

			// Get request status
			status := responseStatus(ctx, lw.Status())

			// Log request stats
			sts := xstats.FromContext(ctx)
			tags := []string{
				"status:" + status,
				"status_code:" + strconv.Itoa(lw.Status()),
			}
			sts.Timing("request_time", reqDur, tags...)
			sts.Histogram("request_size", float64(lw.BytesWritten()), tags...)

			// Log access info
			log := xlog.FromContext(ctx)
			log.Infof("%s %s %03d", r.Method, ellipsize(r.URL.String(), 100), lw.Status(), xlog.F{
				"method":      r.Method,
				"uri":         r.URL.String(),
				"type":        "access",
				"status":      status,
				"status_code": lw.Status(),
				"duration":    reqDur.Seconds(),
				"size":        lw.BytesWritten(),
			})
		})
	}
}
Beispiel #10
0
// Logger is...
func Logger(h http.Handler) http.Handler {
	fn := func(w http.ResponseWriter, r *http.Request) {
		reqID := ""

		printStart(reqID, r)

		lw := mutil.WrapWriter(w)

		t1 := time.Now()
		h.ServeHTTP(lw, r)

		if lw.Status() == 0 {
			lw.WriteHeader(http.StatusOK)
		}
		t2 := time.Now()

		printEnd(reqID, lw, t2.Sub(t1))
	}

	return http.HandlerFunc(fn)
}
// Middleware logs the start and end of each request, along
// with some useful data about what was requested, what the response status was,
// and how long it took to return. When standard output is a TTY, Logger will
// print in color, otherwise it will print in black and white.
//
// Use like so with Goji2:
//	gLogger := gojilogger.New(nil, false)
//	yourGoji.UseC(gLogger.Middleware)
func (l *Logger) Middleware(next goji.Handler) goji.Handler {
	middleware := func(ctx context.Context, w http.ResponseWriter, r *http.Request) {
		l.printRequest(ctx, r)

		// WrapWriter lets us peek at ResponseWriter outputs
		lw := mutil.WrapWriter(w)

		startTime := time.Now()
		next.ServeHTTPC(ctx, lw, r)

		if lw.Status() == 0 {
			lw.WriteHeader(http.StatusOK)
		}

		finishTime := time.Now()

		l.printResponse(lw, finishTime.Sub(startTime))
	}

	return goji.HandlerFunc(middleware)
}
Beispiel #12
0
// WrapC wraps a goji.Handler to log to the provided logger after the
// request completes. It adds a request ID to the context for logging
// with other functions in this package.
func WrapC(h goji.Handler) goji.Handler {
	// this takes the request and response, and tees off a copy of both
	// (truncated to a configurable length), and stores them in the request context
	// for later logging
	return goji.HandlerFunc(func(ctx context.Context, w http.ResponseWriter, r *http.Request) {
		start := time.Now()

		// Generate a new request ID
		if _, ok := ctx.Value(idCtxKey).(string); !ok {
			id := mintActionID()
			ctx = context.WithValue(ctx, idCtxKey, id)
		}

		extra, ok := ctx.Value(extraCtxKey).(map[string]string)
		if !ok {
			extra = make(map[string]string)
			ctx = context.WithValue(ctx, extraCtxKey, extra)
		}

		w2 := mutil.WrapWriter(w)
		h.ServeHTTPC(ctx, w2, r)

		end := time.Now()

		remoteAddr, _, _ := net.SplitHostPort(r.RemoteAddr)
		reqTime := float64(end.Sub(start).Nanoseconds()) / float64(time.Second)

		var extraBuf bytes.Buffer
		for k, v := range extra {
			extraBuf.WriteString(fmt.Sprintf(" %s=%q", k, v))
		}

		Printf(ctx, "event=http_response time=%s remote_address=%q http_path=%q http_method=%q http_status=%d bytes_written=%d http_user_agent=%q request_time=%.6f%s",
			start.In(time.UTC).Format(httpDateFormat), remoteAddr, r.URL.Path, r.Method, w2.Status(), w2.BytesWritten(), r.UserAgent(), reqTime, extraBuf.String(),
		)
	})
}
Beispiel #13
0
// requestLogger handler emits access and trace log entries.
func requestLogger(c *web.C, h http.Handler) http.Handler {

	fn := func(w http.ResponseWriter, r *http.Request) {

		// Instrument the ResponseWriter with a wrapper, and time the rest of the handler chain.
		lw := mutil.WrapWriter(w)
		t1 := time.Now()
		h.ServeHTTP(lw, r)
		t2 := time.Now()
		if lw.Status() == 0 {
			lw.WriteHeader(http.StatusOK)
		}

		// Assemble the data for the access log entry.
		remoteHost := strings.Split(r.RemoteAddr, ":")[0]
		status := lw.Status()
		size := lw.BytesWritten()
		duration := t2.Sub(t1)

		// Assemble the data for the stats entry.
		stats := strings.Split(r.RequestURI, "?")
		stats = strings.Split(stats[0], "/")
		if stats[1] == "" {
			stats[1] = "root"
		}
		stats = []string{"api", stats[1], strings.ToLower(r.Method)}

		// Write the stats entry.
		logging.Statsd.Client.TimingDuration(strings.Join(stats, "."), duration, 1.0)

		// Write the log entry to the access log.
		config.G.Log.API.LogInfo("%s %s %s %s status=%d size=%d dur=%d",
			remoteHost, r.Method, r.Proto, r.RequestURI, status, size, duration.Nanoseconds()/1000)
	}

	return http.HandlerFunc(fn)
}
Beispiel #14
0
func main() {
	klog.Info("starting kahinah v4")

	// -- mux -----------------------------------------------------------------
	mux := goji.NewMux()

	// -- middleware ----------------------------------------------------------

	// logging middleware (base middleware)
	mux.UseC(func(inner goji.Handler) goji.Handler {
		return goji.HandlerFunc(func(ctx context.Context, rw http.ResponseWriter, r *http.Request) {
			klog.Debugf("req  (%v): path (%v), user-agent (%v), referrer (%v)", r.RemoteAddr, r.RequestURI, r.UserAgent(), r.Referer())
			wp := mutil.WrapWriter(rw) // proxy the rw for info later
			inner.ServeHTTPC(ctx, wp, r)
			klog.Debugf("resp (%v): status (%v), bytes written (%v)", r.RemoteAddr, wp.Status(), wp.BytesWritten())
		})
	})

	// rendering middleware (required by panic)
	renderer := urender.New(urender.Options{
		Directory:  "views",
		Layout:     "layout",
		Extensions: []string{".tmpl", ".tpl"},
		Funcs: []template.FuncMap{
			template.FuncMap{
				"rfc3339": func(t time.Time) string {
					return t.Format(time.RFC3339)
				},
				"since": func(t time.Time) string {
					hrs := time.Since(t).Hours()
					return fmt.Sprintf("%dd %02dhrs", int(hrs)/24, int(hrs)%24)
				},
				"emailat": func(s string) string {
					return strings.Replace(s, "@", " [@T] ", -1)
				},
				"mapaccess": func(s interface{}, m map[string]string) string {
					return m[to.String(s)]
				},
				"url":     render.ConvertURL,
				"urldata": render.ConvertURLWithData,
			},
		},
		IndentJSON:    true,
		IndentXML:     true,
		IsDevelopment: conf.GetDefault("runMode", "dev").(string) == "dev",
	})

	mux.UseC(func(inner goji.Handler) goji.Handler {
		return goji.HandlerFunc(func(ctx context.Context, rw http.ResponseWriter, r *http.Request) {
			newCtx := render.NewContext(ctx, renderer)
			inner.ServeHTTPC(newCtx, rw, r)
		})
	})

	// panic middleware
	mux.UseC(controllers.PanicMiddleware)

	// not found middleware
	mux.UseC(func(inner goji.Handler) goji.Handler {
		return goji.HandlerFunc(func(ctx context.Context, rw http.ResponseWriter, r *http.Request) {
			routeFound := middleware.Pattern(ctx)

			if routeFound != nil {
				inner.ServeHTTPC(ctx, rw, r)
				return
			}

			panic(controllers.ErrNotFound)
		})
	})

	// authentication (cas) middleware
	if enable, ok := conf.GetDefault("authentication.cas.enable", false).(bool); ok && enable {
		url, _ := url.Parse(conf.Get("authentication.cas.url").(string))

		casClient := cas.NewClient(&cas.Options{
			URL: url,
		})

		mux.Use(casClient.Handle)
	}

	// sessions middleware
	sessionConfig := &sessionmw.Config{
		Secret:      []byte(securecookie.GenerateRandomKey(64)),
		BlockSecret: []byte(securecookie.GenerateRandomKey(32)),
		Store:       kv.NewMemStore(),
		Name:        "kahinah",
	}
	mux.UseC(sessionConfig.Handler)

	// csrf middleware
	mux.UseC(csrf.Protect(securecookie.GenerateRandomKey(64), csrf.Secure(false)))

	// data rendering middleware
	mux.UseC(func(inner goji.Handler) goji.Handler {
		return goji.HandlerFunc(func(ctx context.Context, rw http.ResponseWriter, r *http.Request) {
			newCtx := data.RenderMiddleware(ctx, rw, r)
			inner.ServeHTTPC(newCtx, rw, r)
			data.RenderAfterware(newCtx, rw, r)
		})
	})

	// --------------------------------------------------------------------
	// HANDLERS
	// --------------------------------------------------------------------

	getHandlers := map[string]goji.HandlerFunc{

		// static paths
		"/static/*": controllers.StaticHandler,

		// main page
		"/": controllers.MainHandler,

		// builds - json
		"/i/list/json/": controllers.ListsAPIHandler,

		// builds
		"/i/list/": controllers.ListsHandler,

		// build - specific
		"/b/:id/": controllers.BuildGetHandler,

		// build - specific - json
		"/b/:id/json/": controllers.BuildGetJSONHandler,

		// activity - json
		"/i/activity/json/": controllers.ActivityJSONHandler,

		// activity - html
		"/i/activity/": controllers.ActivityHandler,

		// admin
		"/admin/": controllers.AdminGetHandler,

		// authentication - login
		"/u/login/": controllers.UserLoginHandler,

		// authentication - logout
		"/u/logout/": controllers.UserLogoutHandler,
	}

	postHandlers := map[string]goji.HandlerFunc{

		// webhooks
		"/hook/*": controllers.IntegrationHandler,

		// build - specific
		"/b/:id/": controllers.BuildPostHandler,

		// admin
		"/admin/": controllers.AdminPostHandler,
	}

	for k, v := range getHandlers {
		if len(k) > 1 && strings.HasSuffix(k, "/") {
			getHandlerRedirectName := render.ConvertURLRelative(k[:len(k)-1])
			klog.Debugf("get handler setup: redirecting %v", getHandlerRedirectName)
			mux.HandleFunc(pat.Get(getHandlerRedirectName), controllers.RedirectHandler)
		}
		getHandlerUseName := render.ConvertURLRelative(k)
		klog.Debugf("get handler setup: using %v", getHandlerUseName)
		mux.HandleC(pat.Get(getHandlerUseName), v)
	}

	for k, v := range postHandlers {
		if len(k) > 1 && strings.HasSuffix(k, "/") {
			postHandlerRedirectName := render.ConvertURLRelative(k[:len(k)-1])
			klog.Debugf("post handler setup: redirecting %v", postHandlerRedirectName)
			mux.HandleFunc(pat.Post(postHandlerRedirectName), controllers.RedirectHandler)
		}
		postHandlerUseName := render.ConvertURLRelative(k)
		klog.Debugf("post handler setup: using %v", postHandlerUseName)
		mux.HandleC(pat.Post(postHandlerUseName), v)
	}

	// -- cronjobs ----------------------------------------------------------

	cronRunner := cron.New()

	// integration polling
	if pollRate, ok := conf.Get("integration.poll").(string); ok && pollRate != "" {
		pollFunc := func() {
			pollAllErr := integration.PollAll()
			for name, err := range pollAllErr {
				klog.Warningf("integration polling failed for %v: %v", name, err)
			}
		}
		cronRunner.AddFunc(pollRate, pollFunc)

		// and do an initial poll
		pollFunc()
	}

	// process new stages/check processes every 10 seconds
	cronRunner.AddFunc("@every 10s", func() {
		models.CheckAllListStages()
	})

	// run the job scheduler every minute
	cronRunner.AddFunc("@every 1m", func() {
		job.ProcessQueue()
	})

	// start cron
	cronRunner.Start()

	// -- server setup --------------------------------------------------------

	// bind and listen
	listenAddr := conf.GetDefault("listenAddr", "0.0.0.0").(string)
	listenPort := conf.GetDefault("listenPort", 3000).(int64)

	klog.Infof("listening to %v:%v", listenAddr, listenPort)
	if err := http.ListenAndServe(fmt.Sprintf("%v:%v", listenAddr, listenPort), mux); err != nil {
		klog.Fatalf("unable to serve: %v", err)
	}

	cronRunner.Stop()

	klog.Info("processing leftover jobs...")
	close(job.Queue)
	for len(job.Queue) > 0 {
		job.ProcessQueue()
	}
}
Beispiel #15
0
func (s *server) ServeHTTPC(ctx context.Context, w http.ResponseWriter, r *http.Request) {
	// Force server to close connection
	r.Close = true

	traceID, err := getTraceID(r)
	if err != nil {
		log.Error("cannot get trace ID")
		http.Error(w, "", http.StatusInternalServerError)
		return
	}
	reqLogger := log.WithField("trace", traceID).WithField("svc", serviceID)
	ctx = NewLogContext(ctx, reqLogger)
	ctx = newGRPCTraceContext(ctx, traceID)

	reqLogger.Info("request started")

	// Time request
	reqStart := time.Now()

	// Sniff the status and content size for logging
	lw := mutil.WrapWriter(w)

	defer func() {
		// Compute request duration
		reqDur := time.Since(reqStart)

		// Log access info
		reqLogger.WithFields(log.Fields{
			"method":      r.Method,
			"type":        "access",
			"status_code": lw.Status(),
			"duration":    reqDur.Seconds(),
			"size":        lw.BytesWritten(),
		}).Infof("%s %s %03d", r.Method, r.URL.String(), lw.Status())

		reqLogger.Info("request finished")

	}()

	if strings.HasPrefix(r.URL.Path, statusURL) && strings.ToUpper(r.Method) == "GET" {
		reqLogger.WithField("op", "status").Info()
		s.status(ctx, lw, r)
	} else if strings.HasPrefix(r.URL.Path, capabilitiesURL) && strings.ToUpper(r.Method) == "GET" {
		reqLogger.WithField("op", "capabilities").Info()
		s.capabilities(ctx, lw, r)
	} else if strings.HasPrefix(r.URL.Path, remoteURL) && strings.ToUpper(r.Method) == "HEAD" {
		reqLogger.WithField("op", "head").Info()
		s.authHandler(ctx, lw, r, s.head)
	} else if strings.HasPrefix(r.URL.Path, remoteURL) && strings.ToUpper(r.Method) == "PROPFIND" {
		reqLogger.WithField("op", "propfind").Info()
		s.authHandler(ctx, lw, r, s.propfind)
	} else if strings.HasPrefix(r.URL.Path, remoteURL) && strings.ToUpper(r.Method) == "GET" {
		reqLogger.WithField("op", "get").Info()
		s.authHandler(ctx, lw, r, s.get)
	} else if strings.HasPrefix(r.URL.Path, remoteURL) && strings.ToUpper(r.Method) == "PUT" {
		reqLogger.WithField("op", "put").Info()
		p := getPathFromReq(r)
		chunked, err := isChunked(p)
		if err != nil {
			reqLogger.Error(err)
			http.Error(w, "", http.StatusInternalServerError)
			return
		}

		if chunked {
			reqLogger.Info("upload is chunked")
			s.authHandler(ctx, lw, r, s.putChunked)
			return
		}

		s.authHandler(ctx, lw, r, s.put)
	} else if strings.HasPrefix(r.URL.Path, remoteURL) && strings.ToUpper(r.Method) == "LOCK" {
		reqLogger.WithField("op", "lock").Info()
		s.authHandler(ctx, lw, r, s.lock)
	} else if strings.HasPrefix(r.URL.Path, remoteURL) && strings.ToUpper(r.Method) == "OPTIONS" {
		reqLogger.WithField("op", "options").Info()
		s.authHandler(ctx, lw, r, s.options)
	} else if strings.HasPrefix(r.URL.Path, remoteURL) && strings.ToUpper(r.Method) == "MKCOL" {
		reqLogger.WithField("op", "mkcol").Info()
		s.authHandler(ctx, lw, r, s.mkcol)
	} else if strings.HasPrefix(r.URL.Path, remoteURL) && strings.ToUpper(r.Method) == "MKCOL" {
		reqLogger.WithField("op", "proppatch").Info()
		s.authHandler(ctx, lw, r, s.proppatch)
	} else if strings.HasPrefix(r.URL.Path, remoteURL) && strings.ToUpper(r.Method) == "COPY" {
		reqLogger.WithField("op", "copy").Info()
		s.authHandler(ctx, lw, r, s.copy)
	} else if strings.HasPrefix(r.URL.Path, remoteURL) && strings.ToUpper(r.Method) == "MOVE" {
		reqLogger.WithField("op", "move").Info()
		s.authHandler(ctx, lw, r, s.move)
	} else if strings.HasPrefix(r.URL.Path, remoteURL) && strings.ToUpper(r.Method) == "DELETE" {
		reqLogger.WithField("op", "delete").Info()
		s.authHandler(ctx, lw, r, s.delete)
	} else {
		w.WriteHeader(http.StatusNotFound)
		return
	}
}