fix(chore): Add more logging for cloud instances

edgraph/server.go

@@ -865,8 +865,8 @@ func updateValInMutations(gmu *gql.Mutation, qc *queryContext) error {
 }
 
 // updateUIDInMutations does following transformations:
-//   * uid(v) -> 0x123     -- If v is defined in query block
-//   * uid(v) -> _:uid(v)  -- Otherwise
+//   - uid(v) -> 0x123     -- If v is defined in query block
+//   - uid(v) -> _:uid(v)  -- Otherwise
 func updateUIDInMutations(gmu *gql.Mutation, qc *queryContext) error {
 	// usedMutationVars keeps track of variables that are used in mutations.
 	getNewVals := func(s string) []string {
@@ -1157,20 +1157,19 @@ func (s *Server) doQuery(ctx context.Context, req *Request) (resp *api.Response,
 		return nil, serverOverloadErr
 	}
 
-	if bool(glog.V(3)) || worker.LogRequestEnabled() {
-		glog.Infof("Got a query: %+v", req.req)
-	}
-
 	isGraphQL, _ := ctx.Value(IsGraphql).(bool)
 	if isGraphQL {
 		atomic.AddUint64(&numGraphQL, 1)
 	} else {
 		atomic.AddUint64(&numGraphQLPM, 1)
 	}
-
 	l := &query.Latency{}
 	l.Start = time.Now()
 
+	if bool(glog.V(3)) || worker.LogDQLRequestEnabled() {
+		glog.Infof("Got a query, DQL form: %+v at %+v", req.req, l.Start.Format(time.RFC3339))
+	}
+
 	isMutation := len(req.req.Mutations) > 0
 	methodRequest := methodQuery
 	if isMutation {
@@ -1207,6 +1206,7 @@ func (s *Server) doQuery(ctx context.Context, req *Request) (resp *api.Response,
 		return nil, errors.Errorf("empty request")
 	}
 
+	span.AddAttributes(trace.StringAttribute("Query", req.req.Query))
 	span.Annotatef(nil, "Request received: %v", req.req)
 	if isQuery {
 		ostats.Record(ctx, x.PendingQueries.M(1), x.NumQueries.M(1))
@@ -1363,7 +1363,15 @@ func processQuery(ctx context.Context, qc *queryContext) (*api.Response, error)
 	// Core processing happens here.
 	er, err := qr.Process(ctx)
 
+	if bool(glog.V(3)) || worker.LogDQLRequestEnabled() {
+		glog.Infof("Finished a query that started at: %+v",
+			qr.Latency.Start.Format(time.RFC3339))
+	}
+
 	if err != nil {
+		if bool(glog.V(3)) {
+			glog.Infof("Error processing query: %+v\n", err.Error())
+		}
 		return resp, errors.Wrap(err, "")
 	}
 
@@ -1585,9 +1593,9 @@ func (s *Server) CheckVersion(ctx context.Context, c *api.Check) (v *api.Version
 	return v, nil
 }
 
-//-------------------------------------------------------------------------------------------------
+// -------------------------------------------------------------------------------------------------
 // HELPER FUNCTIONS
-//-------------------------------------------------------------------------------------------------
+// -------------------------------------------------------------------------------------------------
 func isMutationAllowed(ctx context.Context) bool {
 	if worker.Config.MutationsMode != worker.DisallowMutations {
 		return true

graphql/admin/admin.go

@@ -300,10 +300,10 @@ const (
 		cacheMb: Float
 
 		"""
-		True value of logRequest enables logging of all the requests coming to alphas.
-		False value of logRequest disables above.
+		True value of logDQLRequest enables logging of all the requests coming to alphas.
+		False value of logDQLRequest disables above.
 		"""
-		logRequest: Boolean
+		logDQLRequest: Boolean
 	}
 
 	type ConfigPayload {

graphql/admin/config.go

@@ -29,10 +29,10 @@ import (
 
 type configInput struct {
 	CacheMb *float64
-	// LogRequest is used to update WorkerOptions.LogRequest. true value of LogRequest enables
-	// logging of all requests coming to alphas. LogRequest type has been kept as *bool instead of
-	// bool to avoid updating WorkerOptions.LogRequest when it has default value of false.
-	LogRequest *bool
+	// LogDQLRequest is used to update WorkerOptions.LogDQLRequest. true value of LogDQLRequest enables
+	// logging of all requests coming to alphas. LogDQLRequest type has been kept as *bool instead of
+	// bool to avoid updating WorkerOptions.LogDQLRequest when it has default value of false.
+	LogDQLRequest *bool
 }
 
 func resolveUpdateConfig(ctx context.Context, m schema.Mutation) (*resolve.Resolved, bool) {
@@ -50,9 +50,9 @@ func resolveUpdateConfig(ctx context.Context, m schema.Mutation) (*resolve.Resol
 		}
 	}
 
-	// input.LogRequest will be nil, when it is not specified explicitly in config request.
-	if input.LogRequest != nil {
-		worker.UpdateLogRequest(*input.LogRequest)
+	// input.LogDQLRequest will be nil, when it is not specified explicitly in config request.
+	if input.LogDQLRequest != nil {
+		worker.UpdateLogDQLRequest(*input.LogDQLRequest)
 	}
 
 	return resolve.DataResult(

wiki/content/graphql/admin/index.md

@@ -251,10 +251,10 @@ Here are the important types, queries, and mutations from the `admin` schema.
 		cacheMb: Float
 
 		"""
-		True value of logRequest enables logging of all the requests coming to alphas.
-		False value of logRequest disables above.
+		True value of logDQLRequest enables logging of all the requests coming to alphas.
+		False value of logDQLRequest disables above.
 		"""
-		logRequest: Boolean
+		logDQLRequest: Boolean
 	}
 
 	type ConfigPayload {

worker/draft.go

@@ -1678,6 +1678,8 @@ func (n *node) calculateSnapshot(startIdx, lastIdx, minPendingStart uint64) (*pb
 	span.Annotatef(nil, "Found Raft entries: %d", lastIdx-first)
 
 	if num := posting.Oracle().NumPendingTxns(); num > 0 {
+		// TODO (Damon): this is associated with stuck alphas. Is there anything else we should log here
+		// such as the transaction IDs so we can see in logs if a specific tx is stuck for a long time and how long?
 		glog.V(2).Infof("Num pending txns: %d", num)
 	}
 

worker/worker.go

@@ -172,17 +172,17 @@ func UpdateCacheMb(memoryMB int64) error {
 	return nil
 }
 
-// UpdateLogRequest updates value of x.WorkerConfig.LogRequest.
-func UpdateLogRequest(val bool) {
+// UpdateLogDQLRequest updates value of x.WorkerConfig.LogDQLRequest.
+func UpdateLogDQLRequest(val bool) {
 	if val {
-		atomic.StoreInt32(&x.WorkerConfig.LogRequest, 1)
+		atomic.StoreInt32(&x.WorkerConfig.LogDQLRequest, 1)
 		return
 	}
 
-	atomic.StoreInt32(&x.WorkerConfig.LogRequest, 0)
+	atomic.StoreInt32(&x.WorkerConfig.LogDQLRequest, 0)
 }
 
-// LogRequestEnabled returns true if logging of requests is enabled otherwise false.
-func LogRequestEnabled() bool {
-	return atomic.LoadInt32(&x.WorkerConfig.LogRequest) > 0
+// LogDQLRequestEnabled returns true if logging of requests is enabled otherwise false.
+func LogDQLRequestEnabled() bool {
+	return atomic.LoadInt32(&x.WorkerConfig.LogDQLRequest) > 0
 }

x/config.go

@@ -137,7 +137,7 @@ type WorkerOptions struct {
 	// Ideally LogRequest should be a bool value. But we are reading it using atomics across
 	// queries hence it has been kept as int32. LogRequest value 1 enables logging of requests
 	// coming to alphas and 0 disables it.
-	LogRequest int32
+	LogDQLRequest int32
 	// If true, we should call msync or fsync after every write to survive hard reboots.
 	HardSync bool
 	// Audit contains the audit flags that enables the audit.

x/x.go

@@ -351,7 +351,7 @@ func SetStatus(w http.ResponseWriter, code, msg string) {
 	qr.Errors = append(qr.Errors, &GqlError{Message: msg, Extensions: ext})
 	if js, err := json.Marshal(qr); err == nil {
 		if _, err := w.Write(js); err != nil {
-			glog.Errorf("Error while writing: %+v", err)
+			glog.Errorf("Could not send error msg=%+v code=%+v due to http error %+v", msg, code, err)
 		}
 	} else {
 		Panic(errors.Errorf("Unable to marshal: %+v", qr))