Review comments

docs/operational_guide/monitoring.md

@@ -1,20 +1,21 @@
 ## Metrics
 
-TODO
+TODO: document how to retrieve metrics for M3DB components.
 
 ## Logs
 
-TODO
+TODO: document how to retrieve logs for M3DB components.
 
 ## Tracing
 
 M3DB is integrated with [opentracing](https://opentracing.io/) to provide
 insight into query performance and errors.
 
 ### Configuration
-Currently, only https://www.jaegertracing.io/ is supported as a backend.
+Currently, only [Jaeger](https://www.jaegertracing.io/) is supported as a backend.
 
-To enable it, set tracing.backend to "jaeger":
+To enable it, set tracing.backend to "jaeger" (see also our
+[sample local config](https://github.com/m3db/m3/blob/master/src/query/config/m3query-local-etcd.yml):
 
 ```
 tracing:
@@ -34,6 +35,11 @@ using the all-in-one jaeger container, they will be accessible at
 
 http://localhost:16686
 
+N.B.: for production workloads, you will almost certainly want to use
+sampler.type=remote with 
+[adaptive sampling](https://www.jaegertracing.io/docs/1.10/sampling/#adaptive-sampler)
+for Jaeger, as write volumes are likely orders of magnitude higher than
+read volumes in most timeseries systems.
 
 #### Alternative backends
 

src/query/api/v1/handler/prometheus/native/read.go

@@ -127,7 +127,7 @@ func (h *PromReadHandler) ServeHTTP(w http.ResponseWriter, r *http.Request) {
 
 	result, params, respErr := h.ServeHTTPWithEngine(w, r, h.engine)
 	if respErr != nil {
-		httperrors.ErrorWithReqID(w, r, respErr.Err, respErr.Code)
+		httperrors.ErrorWithReqInfo(w, r, respErr.Code, respErr.Err)
 		return
 	}
 

src/query/api/v1/handler/prometheus/native/read_instantaneous.go

@@ -69,7 +69,7 @@ func (h *PromReadInstantHandler) ServeHTTP(w http.ResponseWriter, r *http.Reques
 	logger := logging.WithContext(ctx)
 	params, rErr := parseInstantaneousParams(r, h.timeoutOpts)
 	if rErr != nil {
-		httperrors.ErrorWithReqID(w, r, rErr, rErr.Code())
+		httperrors.ErrorWithReqInfo(w, r, rErr.Code(), rErr)
 		return
 	}
 
@@ -80,7 +80,7 @@ func (h *PromReadInstantHandler) ServeHTTP(w http.ResponseWriter, r *http.Reques
 	result, err := read(ctx, h.engine, h.tagOpts, w, params)
 	if err != nil {
 		logger.Error("unable to fetch data", zap.Error(err))
-		httperrors.ErrorWithReqID(w, r, rErr, http.StatusBadRequest)
+		httperrors.ErrorWithReqInfo(w, r, http.StatusBadRequest, rErr)
 		return
 	}
 

src/query/api/v1/httpd/handler.go

@@ -105,19 +105,7 @@ func NewHandler(
 ) (*Handler, error) {
 	r := mux.NewRouter()
 
-	// apply middleware.
-	withMiddleware := http.Handler(&cors.Handler{
-		Handler: r,
-		Info: &cors.Info{
-			"*": true,
-		},
-	})
-
-	// add jaeger tracing to our endpoints
-	withMiddleware = nethttp.Middleware(opentracing.GlobalTracer(), withMiddleware,
-		nethttp.OperationNameFunc(func(r *http.Request) string {
-			return fmt.Sprintf("%s %s", r.Method, r.URL.Path)
-		}))
+	handlerWithMiddleware := applyMiddleware(r, opentracing.GlobalTracer())
 
 	var timeoutOpts = &prometheus.TimeoutOpts{}
 	if embeddedDbCfg == nil || embeddedDbCfg.Client.FetchTimeout == nil {
@@ -132,7 +120,7 @@ func NewHandler(
 
 	h := &Handler{
 		router:               r,
-		handler:              withMiddleware,
+		handler:              handlerWithMiddleware,
 		storage:              downsamplerAndWriter.Storage(),
 		downsamplerAndWriter: downsamplerAndWriter,
 		engine:               engine,
@@ -148,6 +136,23 @@ func NewHandler(
 	return h, nil
 }
 
+func applyMiddleware(base *mux.Router, tracer opentracing.Tracer) http.Handler {
+	withMiddleware := http.Handler(&cors.Handler{
+		Handler: base,
+		Info: &cors.Info{
+			"*": true,
+		},
+	})
+
+	// apply jaeger middleware, which will start a span
+	// for each incoming request
+	withMiddleware = nethttp.Middleware(tracer, withMiddleware,
+		nethttp.OperationNameFunc(func(r *http.Request) string {
+			return fmt.Sprintf("%s %s", r.Method, r.URL.Path)
+		}))
+	return withMiddleware
+}
+
 // RegisterRoutes registers all http routes.
 func (h *Handler) RegisterRoutes() error {
 	// Wrap requests with response time logging as well as panic recovery.

src/query/api/v1/httpd/handler_test.go

@@ -43,6 +43,8 @@ import (
 	xsync "github.com/m3db/m3x/sync"
 
 	"github.com/golang/mock/gomock"
+	"github.com/gorilla/mux"
+	"github.com/opentracing/opentracing-go/mocktracer"
 	"github.com/stretchr/testify/assert"
 	"github.com/stretchr/testify/require"
 	"github.com/uber-go/tally"
@@ -60,8 +62,15 @@ func makeTagOptions() models.TagOptions {
 
 func setupHandler(store storage.Storage) (*Handler, error) {
 	downsamplerAndWriter := ingest.NewDownsamplerAndWriter(store, nil, testWorkerPool)
-	return NewHandler(downsamplerAndWriter, makeTagOptions(), executor.NewEngine(store, tally.NewTestScope("test", nil), time.Minute), nil, nil,
-		config.Configuration{LookbackDuration: &defaultLookbackDuration}, nil, tally.NewTestScope("", nil))
+	return NewHandler(
+		downsamplerAndWriter,
+		makeTagOptions(),
+		executor.NewEngine(store, tally.NewTestScope("test", nil), time.Minute),
+		nil,
+		nil,
+		config.Configuration{LookbackDuration: &defaultLookbackDuration},
+		nil,
+		tally.NewTestScope("", nil))
 }
 
 func TestHandlerFetchTimeoutError(t *testing.T) {
@@ -240,18 +249,39 @@ func TestCORSMiddleware(t *testing.T) {
 	h, err := setupHandler(s)
 	require.NoError(t, err, "unable to setup handler")
 
-	testRoute := "/foobar"
-	h.router.HandleFunc(testRoute, func(writer http.ResponseWriter, r *http.Request) {
-		writer.WriteHeader(http.StatusOK)
-		writer.Write([]byte("hello!"))
-	})
+	setupTestRoute(h.router)
+	res := doTestRequest(h.Router())
+
+	assert.Equal(t, "hello!", res.Body.String())
+	assert.Equal(t, "*", res.Header().Get("Access-Control-Allow-Origin"))
+}
+
+func doTestRequest(handler http.Handler) *httptest.ResponseRecorder {
 
 	req, _ := http.NewRequest("GET", testRoute, nil)
 	res := httptest.NewRecorder()
-	h.Router().ServeHTTP(res, req)
+	handler.ServeHTTP(res, req)
+	return res
+}
 
-	assert.Equal(t, "hello!", res.Body.String())
-	assert.Equal(t, "*", res.Header().Get("Access-Control-Allow-Origin"))
+func TestTracingMiddleware(t *testing.T) {
+	mtr := mocktracer.New()
+	router := mux.NewRouter()
+	setupTestRoute(router)
+
+	handler := applyMiddleware(router, mtr)
+	doTestRequest(handler)
+
+	assert.NotEmpty(t, mtr.FinishedSpans())
+}
+
+const testRoute = "/foobar"
+
+func setupTestRoute(r *mux.Router) {
+	r.HandleFunc(testRoute, func(writer http.ResponseWriter, r *http.Request) {
+		writer.WriteHeader(http.StatusOK)
+		writer.Write([]byte("hello!"))
+	})
 }
 
 func init() {

src/query/config/m3query-local-etcd.yml

@@ -52,3 +52,9 @@ clusters:
         jitter: true
       backgroundHealthCheckFailLimit: 4
       backgroundHealthCheckFailThrottleFactor: 0.5
+
+# Uncomment this to enable local jaeger tracing. See https://www.jaegertracing.io/docs/1.9/getting-started/
+# for quick local setup (which this config will send data to).
+
+# tracing:
+#  backend: jaeger

src/query/util/httperrors/errors.go

@@ -32,10 +32,13 @@ type errorWithID struct {
 	RqID string `json:"rqID"`
 }
 
-// ErrorWithReqID writes an xhttp.ErrorResponse with an added request id (RqId) field read from the request
-// context. NB: RqID is currently a query specific concept, which is why this doesn't exist in xhttp proper.
+// ErrorWithReqInfo writes an xhttp.ErrorResponse with an added request id (
+// RqId) field read from the request context.
+//
+// NB: RqID is currently a query specific concept,
+// which is why this doesn't exist in xhttp proper.
 // We can add it later if we propagate the request id concept to that package as well.
-func ErrorWithReqID(w http.ResponseWriter, r *http.Request, err error, code int) {
+func ErrorWithReqInfo(w http.ResponseWriter, r *http.Request, code int, err error) {
 	ctx := r.Context()
 	w.WriteHeader(code)
 	xhttp.WriteJSONResponse(w, errorWithID{

src/query/util/logging/log.go

@@ -128,11 +128,11 @@ func withResponseTimeLoggingFunc(
 	return func(w http.ResponseWriter, r *http.Request) {
 		startTime := time.Now()
 		rqCtx := NewContextWithGeneratedID(r.Context())
-		rqID := ReadContextID(rqCtx)
 		logger := WithContext(rqCtx)
 
 		sp := opentracing.SpanFromContext(rqCtx)
 		if sp != nil {
+			rqID := ReadContextID(rqCtx)
 			sp.SetTag("rqID", rqID)
 		}
 

src/query/util/opentracing/context.go

@@ -33,7 +33,8 @@ import (
 // alias GlobalTracer() so we can mock out the tracer without impacting tests outside the package
 var getGlobalTracer = opentracing.GlobalTracer
 
-// SpanFromContextOrRoot is the same as opentracing.SpanFromContext, but instead of returning nil,
+// SpanFromContextOrNoop is the same as opentracing.SpanFromContext,
+// but instead of returning nil,
 // it returns a NoopTracer span if ctx doesn't already have an associated span.
 // Use this over opentracing.StartSpanFromContext if you need access to the
 // current span, (e.g. if you don't want to start a child span).
@@ -56,16 +57,16 @@ func SpanFromContextOrNoop(ctx context.Context) opentracing.Span {
 // a locally set tracer to be used when needed (as in tests)--while being equivalent to the original in most contexts.
 // See https://github.com/opentracing/opentracing-go/issues/149 for more discussion.
 func StartSpanFromContext(ctx context.Context, operationName string, opts ...opentracing.StartSpanOption) (opentracing.Span, context.Context) {
-	var span opentracing.Span
+	var tracer opentracing.Tracer
 	if parentSpan := opentracing.SpanFromContext(ctx); parentSpan != nil {
 		opts = append(opts, opentracing.ChildOf(parentSpan.Context()))
-		tracer := parentSpan.Tracer()
-		span = tracer.StartSpan(operationName, opts...)
+		tracer = parentSpan.Tracer()
 	} else {
-		tracer := getGlobalTracer()
-		span = tracer.StartSpan(operationName, opts...)
+		tracer = getGlobalTracer()
 	}
 
+	span := tracer.StartSpan(operationName, opts...)
+
 	return span, opentracing.ContextWithSpan(ctx, span)
 }
 

src/query/util/opentracing/context_test.go

@@ -65,7 +65,6 @@ func TestStartSpanFromContext(t *testing.T) {
 }
 
 func TestStartSpanFromContextOrRoot(t *testing.T) {
-
 	t.Run("uses noop tracer if nothing passed in", func(t *testing.T) {
 		assert.Equal(t, opentracing.NoopTracer{}.StartSpan(""),
 			SpanFromContextOrNoop(context.