Repository: buchgr/bazel-remote
Pull request #114 (2019-10-30 10:23:56)

grpc: log GetCapabilities calls for debugging purposes


Patch:
diff --git a/cache/disk/disk.go b/cache/disk/disk.go
index c4e0feb..3c6d983 100644
--- a/cache/disk/disk.go
+++ b/cache/disk/disk.go
@@ -150,7 +150,7 @@ func (c *diskCache) loadExistingFiles() error {
 	return nil
 }
 
-func (c *diskCache) Put(kind cache.EntryKind, hash string, expectedSize int64, r io.Reader) (err error) {
+func (c *diskCache) Put(kind cache.EntryKind, hash string, expectedSize int64, r io.Reader) error {
 	c.mux.Lock()
 
 	key := cacheKey(kind, hash)
@@ -163,7 +163,7 @@ func (c *diskCache) Put(kind cache.EntryKind, hash string, expectedSize int64, r
 		if !existingItem.(*lruItem).committed {
 			c.mux.Unlock()
 			io.Copy(ioutil.Discard, r)
-			return
+			return nil
 		}
 	}
 
@@ -199,7 +199,7 @@ func (c *diskCache) Put(kind cache.EntryKind, hash string, expectedSize int64, r
 	// Download to a temporary file
 	f, err := ioutil.TempFile(c.dir, "upload")
 	if err != nil {
-		return
+		return err
 	}
 	defer func() {
 		if !shouldCommit {
@@ -214,17 +214,16 @@ func (c *diskCache) Put(kind cache.EntryKind, hash string, expectedSize int64, r
 	if kind == cache.CAS {
 		hasher := sha256.New()
 		if bytesCopied, err = io.Copy(io.MultiWriter(f, hasher), r); err != nil {
-			return
+			return err
 		}
 		actualHash := hex.EncodeToString(hasher.Sum(nil))
 		if actualHash != hash {
-			err = fmt.Errorf(
+			return fmt.Errorf(
 				"hashsums don't match. Expected %s, found %s", key, actualHash)
-			return
 		}
 	} else {
 		if bytesCopied, err = io.Copy(f, r); err != nil {
-			return
+			return err
 		}
 	}
 
@@ -237,9 +236,8 @@ func (c *diskCache) Put(kind cache.EntryKind, hash string, expectedSize int64, r
 	}
 
 	if bytesCopied != expectedSize {
-		err = fmt.Errorf(
+		return fmt.Errorf(
 			"sizes don't match. Expected %d, found %d", expectedSize, bytesCopied)
-		return err
 	}
 
 	// Rename to the final path
@@ -251,28 +249,28 @@ func (c *diskCache) Put(kind cache.EntryKind, hash string, expectedSize int64, r
 		shouldCommit = true
 	}
 
-	return
+	return err
 }
 
 func (c *diskCache) Get(kind cache.EntryKind, hash string) (rdr io.ReadCloser, sizeBytes int64, err error) {
 	if !c.Contains(kind, hash) {
-		return
+		return nil, 0, nil
 	}
 
 	blobPath := cacheFilePath(kind, c.dir, hash)
 
 	fileInfo, err := os.Stat(blobPath)
 	if err != nil {
-		return
+		return nil, 0, err
 	}
 	sizeBytes = fileInfo.Size()
 
 	rdr, err = os.Open(blobPath)
 	if err != nil {
-		return
+		return nil, 0, err
 	}
 
-	return
+	return rdr, sizeBytes, nil
 }
 
 func (c *diskCache) Contains(kind cache.EntryKind, hash string) (ok bool) {
diff --git a/cache/http/http.go b/cache/http/http.go
index 197762b..33f3ed5 100644
--- a/cache/http/http.go
+++ b/cache/http/http.go
@@ -54,6 +54,9 @@ func uploadFile(remote *http.Client, baseURL *url.URL, local cache.Cache, access
 	if err != nil {
 		return
 	}
+	io.Copy(ioutil.Discard, rsp.Body)
+	rsp.Body.Close()
+
 	logResponse(accessLogger, "PUT", rsp.StatusCode, url)
 	return
 }
diff --git a/main.go b/main.go
index f6d1a66..478d40d 100644
--- a/main.go
+++ b/main.go
@@ -27,7 +27,14 @@ import (
 	"google.golang.org/grpc/credentials"
 )
 
+const (
+	logFlags = log.Ldate | log.Ltime | log.LUTC
+)
+
 func main() {
+
+	log.SetFlags(logFlags)
+
 	app := cli.NewApp()
 	app.Description = "A remote build cache for Bazel."
 	app.Usage = "A remote build cache for Bazel"
@@ -181,8 +188,8 @@ func main() {
 			return nil
 		}
 
-		accessLogger := log.New(os.Stdout, "", log.Ldate|log.Ltime|log.LUTC)
-		errorLogger := log.New(os.Stderr, "", log.Ldate|log.Ltime|log.LUTC)
+		accessLogger := log.New(os.Stdout, "", logFlags)
+		errorLogger := log.New(os.Stderr, "", logFlags)
 
 		diskCache := disk.New(c.Dir, int64(c.MaxSize)*1024*1024*1024)
 
@@ -227,6 +234,11 @@ func main() {
 		mux.HandleFunc("/", cacheHandler)
 
 		if c.GRPCPort > 0 {
+
+			if c.GRPCPort == c.Port {
+				log.Fatalf("Error: gRPC and HTTP ports (%d) conflict", c.Port)
+			}
+
 			go func() {
 				addr := c.Host + ":" + strconv.Itoa(c.GRPCPort)
 
@@ -241,6 +253,8 @@ func main() {
 					opts = append(opts, grpc.Creds(creds))
 				}
 
+				log.Printf("Starting gRPC server on address %s", addr)
+
 				err = server.ListenAndServeGRPC(addr, opts,
 					proxyCache, accessLogger, errorLogger)
 				if err != nil {
@@ -250,8 +264,11 @@ func main() {
 		}
 
 		if len(c.TLSCertFile) > 0 && len(c.TLSKeyFile) > 0 {
+			log.Printf("Starting HTTPS server on address %s", httpServer.Addr)
 			return httpServer.ListenAndServeTLS(c.TLSCertFile, c.TLSKeyFile)
 		}
+
+		log.Printf("Starting HTTP server on address %s", httpServer.Addr)
 		return httpServer.ListenAndServe()
 	}
 
diff --git a/server/grpc.go b/server/grpc.go
index a44da8e..b49fda5 100644
--- a/server/grpc.go
+++ b/server/grpc.go
@@ -84,6 +84,8 @@ func (s *grpcServer) GetCapabilities(ctx context.Context,
 		HighApiVersion: &semver.SemVer{Major: int32(2)},
 	}
 
+	s.accessLogger.Printf("GRPC GETCAPABILITIES")
+
 	return &resp, nil
 }
 
diff --git a/server/grpc_ac.go b/server/grpc_ac.go
index 8ae1893..3dfd737 100644
--- a/server/grpc_ac.go
+++ b/server/grpc_ac.go
@@ -13,6 +13,11 @@ import (
 	"github.com/buchgr/bazel-remote/cache"
 )
 
+var (
+	errEmptyActionResult = status.Error(codes.InvalidArgument,
+		"rejecting empty ActionResult")
+)
+
 // ActionCache interface:
 
 func (s *grpcServer) GetActionResult(ctx context.Context,
@@ -57,6 +62,12 @@ func (s *grpcServer) UpdateActionResult(ctx context.Context,
 		return nil, status.Error(codes.Unknown, err.Error())
 	}
 
+	if len(data) == 0 {
+		s.accessLogger.Printf("%s %s %s", errorPrefix, req.ActionDigest.Hash,
+			errEmptyActionResult.Error())
+		return nil, errEmptyActionResult
+	}
+
 	err = s.cache.Put(cache.AC, req.ActionDigest.Hash,
 		int64(len(data)), bytes.NewReader(data))
 	if err != nil {
diff --git a/server/http.go b/server/http.go
index 2f70d03..00dac8a 100644
--- a/server/http.go
+++ b/server/http.go
@@ -196,7 +196,7 @@ func (h *httpCache) CacheHandler(w http.ResponseWriter, r *http.Request) {
 			// We need the content-length header to make sure we have enough disk space.
 			msg := fmt.Sprintf("PUT without Content-Length (key = %s)", path(kind, hash))
 			http.Error(w, msg, http.StatusBadRequest)
-			h.errorLogger.Printf("%s", msg)
+			h.errorLogger.Printf("PUT %s: %s", path(kind, hash), msg)
 			return
 		}
 
@@ -206,17 +206,25 @@ func (h *httpCache) CacheHandler(w http.ResponseWriter, r *http.Request) {
 
 			data, err := ioutil.ReadAll(rc)
 			if err != nil {
-				msg := "Failed to read request body"
-				http.Error(w, msg, http.StatusBadRequest) // find a better status
-				h.errorLogger.Printf("%s", msg)
+				msg := "failed to read request body"
+				http.Error(w, msg, http.StatusInternalServerError)
+				h.errorLogger.Printf("PUT %s: %s", path(kind, hash), msg)
+				return
+			}
+
+			if len(data) == 0 {
+				msg := "rejecting empty ActionResult"
+				http.Error(w, msg, http.StatusBadRequest)
+				h.errorLogger.Printf("PUT %s: %s", path(kind, hash), msg)
+				return
 			}
 
 			ar := &pb.ActionResult{}
 			err = proto.Unmarshal(data, ar)
 			if err != nil {
-				msg := "Put received an invalid ActionResult"
+				msg := "received an invalid ActionResult"
 				http.Error(w, msg, http.StatusBadRequest)
-				h.errorLogger.Printf("%s", msg)
+				h.errorLogger.Printf("PUT %s: %s", path(kind, hash), msg)
 				return
 			}
 


Test patch:
diff --git a/server/grpc_test.go b/server/grpc_test.go
index a65cf43..9cb00e0 100644
--- a/server/grpc_test.go
+++ b/server/grpc_test.go
@@ -185,6 +185,30 @@ func TestGrpcAc(t *testing.T) {
 		checkBadDigestErr(t, err, tc)
 	}
 
+	zeroActionResult := pb.ActionResult{}
+	zeroData, err := proto.Marshal(&zeroActionResult)
+	if err != nil {
+		t.Fatal(err)
+	}
+	if len(zeroData) != 0 {
+		t.Fatal("expected a zero-sized test blob")
+	}
+	_, zeroHash := testutils.RandomDataAndHash(0)
+	zeroDigest := pb.Digest{
+		Hash:      zeroHash,
+		SizeBytes: 0,
+	}
+	zeroReq := pb.UpdateActionResultRequest{
+		ActionDigest: &zeroDigest,
+		ActionResult: &zeroActionResult,
+	}
+	_, err = acClient.UpdateActionResult(ctx, &zeroReq)
+	s, ok = status.FromError(err)
+	if !ok || s.Code() != codes.InvalidArgument ||
+		err.Error() != errEmptyActionResult.Error() {
+		t.Fatal("expected empty ActionResult to be rejected", err)
+	}
+
 	// GetActionResultRequest again, expect cache hit.
 
 	gacrResp, err = acClient.GetActionResult(ctx, &getReq)
diff --git a/server/http_test.go b/server/http_test.go
index ec99258..250c067 100644
--- a/server/http_test.go
+++ b/server/http_test.go
@@ -212,6 +212,47 @@ func TestUploadCorruptedFile(t *testing.T) {
 	}
 }
 
+func TestUploadEmptyActionResult(t *testing.T) {
+	cacheDir := testutils.CreateTmpCacheDirs(t)
+	defer os.RemoveAll(cacheDir)
+
+	data, hash := testutils.RandomDataAndHash(0)
+
+	r, err := http.NewRequest("PUT", "/ac/"+hash, bytes.NewReader(data))
+	if err != nil {
+		t.Error(err)
+	}
+
+	c := disk.New(cacheDir, 2048)
+	validate := true
+	h := NewHTTPCache(c, testutils.NewSilentLogger(), testutils.NewSilentLogger(), validate)
+	rr := httptest.NewRecorder()
+	handler := http.HandlerFunc(h.CacheHandler)
+	handler.ServeHTTP(rr, r)
+
+	if status := rr.Code; status != http.StatusBadRequest {
+		t.Error("Handler returned wrong status code",
+			"expected ", http.StatusBadRequest,
+			"got ", status)
+	}
+
+	// Check that no file was saved in the cache
+	f, err := os.Open(cacheDir)
+	defer f.Close()
+	if err != nil {
+		t.Fatal(err)
+	}
+	entries, err := f.Readdir(-1)
+	if err != nil {
+		t.Fatal(err)
+	}
+	for _, fileEntry := range entries {
+		if !fileEntry.IsDir() {
+			t.Error("Unexpected file in the cache ", fileEntry.Name())
+		}
+	}
+}
+
 func TestStatusPage(t *testing.T) {
 	cacheDir := testutils.CreateTmpCacheDirs(t)
 	defer os.RemoveAll(cacheDir)