Merge pull request #281 from jbw976/ROOK-269

Add default timeout to rook client network calls.  Log start and end …

cmd/rook/block/create.go

@@ -17,7 +17,6 @@ package block
 
 import (
 	"fmt"
-	"net/http"
 	"os"
 
 	"github.com/rook/rook/cmd/rook/rook"
@@ -59,7 +58,7 @@ func createBlockImagesEntry(cmd *cobra.Command, args []string) error {
 		return err
 	}
 
-	c := client.NewRookNetworkRestClient(client.GetRestURL(rook.APIServerEndpoint), http.DefaultClient)
+	c := rook.NewRookNetworkRestClient()
 	out, err := createBlockImage(newImageName, newImagePoolName, newImageSize, c)
 	if err != nil {
 		fmt.Fprintln(os.Stderr, err)

cmd/rook/block/list.go

@@ -18,7 +18,6 @@ package block
 import (
 	"bytes"
 	"fmt"
-	"net/http"
 	"os"
 	"runtime"
 	"strings"
@@ -48,7 +47,7 @@ func listBlocksEntry(cmd *cobra.Command, args []string) error {
 		return err
 	}
 
-	c := client.NewRookNetworkRestClient(client.GetRestURL(rook.APIServerEndpoint), http.DefaultClient)
+	c := rook.NewRookNetworkRestClient()
 	e := &exec.CommandExecutor{}
 	out, err := listBlocks(rbdSysBusPathDefault, c, e)
 	if err != nil {

cmd/rook/block/mount.go

@@ -18,7 +18,6 @@ package block
 import (
 	"fmt"
 	"io/ioutil"
-	"net/http"
 	"os"
 	"path/filepath"
 	"strings"
@@ -76,7 +75,7 @@ func mountBlockEntry(cmd *cobra.Command, args []string) error {
 		return err
 	}
 
-	c := client.NewRookNetworkRestClient(client.GetRestURL(rook.APIServerEndpoint), http.DefaultClient)
+	c := rook.NewRookNetworkRestClient()
 	e := &exec.CommandExecutor{}
 	out, err := mountBlock(mountImageName, mountImagePoolName, mountImagePath, rbdSysBusPathDefault, c, e)
 	if err != nil {

cmd/rook/filesystem/create.go

@@ -17,7 +17,6 @@ package filesystem
 
 import (
 	"fmt"
-	"net/http"
 	"os"
 
 	"github.com/rook/rook/cmd/rook/rook"
@@ -50,7 +49,7 @@ func createFilesystemEntry(cmd *cobra.Command, args []string) error {
 		return err
 	}
 
-	c := client.NewRookNetworkRestClient(client.GetRestURL(rook.APIServerEndpoint), http.DefaultClient)
+	c := rook.NewRookNetworkRestClient()
 	out, err := createFilesystem(newFilesystemName, c)
 	if err != nil {
 		fmt.Fprintln(os.Stderr, err)

cmd/rook/filesystem/delete.go

@@ -17,7 +17,6 @@ package filesystem
 
 import (
 	"fmt"
-	"net/http"
 	"os"
 
 	"github.com/rook/rook/cmd/rook/rook"
@@ -50,7 +49,7 @@ func deleteFilesystemEntry(cmd *cobra.Command, args []string) error {
 		return err
 	}
 
-	c := client.NewRookNetworkRestClient(client.GetRestURL(rook.APIServerEndpoint), http.DefaultClient)
+	c := rook.NewRookNetworkRestClient()
 	out, err := deleteFilesystem(deleteFilesystemName, c)
 	if err != nil {
 		fmt.Fprintln(os.Stderr, err)

cmd/rook/filesystem/list.go

@@ -18,7 +18,6 @@ package filesystem
 import (
 	"bytes"
 	"fmt"
-	"net/http"
 	"os"
 	"strings"
 
@@ -44,7 +43,7 @@ func listFilesystemEntry(cmd *cobra.Command, args []string) error {
 		return err
 	}
 
-	c := client.NewRookNetworkRestClient(client.GetRestURL(rook.APIServerEndpoint), http.DefaultClient)
+	c := rook.NewRookNetworkRestClient()
 	out, err := listFilesystems(c)
 	if err != nil {
 		fmt.Fprintln(os.Stderr, err)

cmd/rook/filesystem/mount.go

@@ -17,7 +17,6 @@ package filesystem
 
 import (
 	"fmt"
-	"net/http"
 	"os"
 	"strings"
 
@@ -56,7 +55,7 @@ func mountFilesystemEntry(cmd *cobra.Command, args []string) error {
 		return err
 	}
 
-	c := client.NewRookNetworkRestClient(client.GetRestURL(rook.APIServerEndpoint), http.DefaultClient)
+	c := rook.NewRookNetworkRestClient()
 	e := &exec.CommandExecutor{}
 	out, err := mountFilesystem(mountFilesystemName, mountFilesystemPath, c, e)
 	if err != nil {

cmd/rook/node/list.go

@@ -18,7 +18,6 @@ package node
 import (
 	"bytes"
 	"fmt"
-	"net/http"
 	"os"
 
 	"github.com/rook/rook/cmd/rook/rook"
@@ -42,7 +41,7 @@ func listNodesEntry(cmd *cobra.Command, args []string) error {
 
 	// verify required flags. currently there are none
 
-	c := client.NewRookNetworkRestClient(client.GetRestURL(rook.APIServerEndpoint), http.DefaultClient)
+	c := rook.NewRookNetworkRestClient()
 	out, err := listNodes(c)
 	if err != nil {
 		fmt.Fprintln(os.Stderr, err)

cmd/rook/object/connection.go

@@ -18,7 +18,6 @@ package object
 import (
 	"bytes"
 	"fmt"
-	"net/http"
 	"os"
 
 	"github.com/rook/rook/cmd/rook/rook"
@@ -62,7 +61,7 @@ func getConnectionInfoEntry(cmd *cobra.Command, args []string) error {
 		return err
 	}
 
-	c := client.NewRookNetworkRestClient(client.GetRestURL(rook.APIServerEndpoint), http.DefaultClient)
+	c := rook.NewRookNetworkRestClient()
 	out, err := getConnectionInfo(connOutputFormat, c)
 	if err != nil {
 		fmt.Fprintln(os.Stderr, err)

cmd/rook/object/create.go

@@ -17,7 +17,6 @@ package object
 
 import (
 	"fmt"
-	"net/http"
 	"os"
 
 	"github.com/rook/rook/cmd/rook/rook"
@@ -42,7 +41,7 @@ func createObjectStoreEntry(cmd *cobra.Command, args []string) error {
 		return err
 	}
 
-	c := client.NewRookNetworkRestClient(client.GetRestURL(rook.APIServerEndpoint), http.DefaultClient)
+	c := rook.NewRookNetworkRestClient()
 	out, err := createObjectStore(c)
 	if err != nil {
 		fmt.Fprintln(os.Stderr, err)

cmd/rook/pool/create.go

@@ -17,7 +17,6 @@ package pool
 
 import (
 	"fmt"
-	"net/http"
 	"os"
 
 	"github.com/rook/rook/cmd/rook/rook"
@@ -72,7 +71,7 @@ func createPoolsEntry(cmd *cobra.Command, args []string) error {
 		return err
 	}
 
-	c := client.NewRookNetworkRestClient(client.GetRestURL(rook.APIServerEndpoint), http.DefaultClient)
+	c := rook.NewRookNetworkRestClient()
 	out, err := createPool(newPoolName, newPoolType, newPoolReplicaCount, newPoolDataChunks, newPoolCodingChunks, c)
 	if err != nil {
 		fmt.Fprintln(os.Stderr, err)

cmd/rook/pool/list.go

@@ -18,7 +18,6 @@ package pool
 import (
 	"bytes"
 	"fmt"
-	"net/http"
 	"os"
 
 	"github.com/rook/rook/cmd/rook/rook"
@@ -45,7 +44,7 @@ func listPoolsEntry(cmd *cobra.Command, args []string) error {
 		return err
 	}
 
-	c := client.NewRookNetworkRestClient(client.GetRestURL(rook.APIServerEndpoint), http.DefaultClient)
+	c := rook.NewRookNetworkRestClient()
 	out, err := listPools(c)
 	if err != nil {
 		fmt.Fprintln(os.Stderr, err)

cmd/rook/rook/rook.go

@@ -18,10 +18,13 @@ package rook
 import (
 	"fmt"
 	"io"
+	"net/http"
 	"os"
 	"text/tabwriter"
+	"time"
 
 	"github.com/coreos/pkg/capnslog"
+	"github.com/rook/rook/pkg/rook/client"
 	"github.com/rook/rook/pkg/util/flags"
 	"github.com/spf13/cobra"
 )
@@ -36,6 +39,7 @@ const (
 	outputMinWidth = 10
 	outputTabWidth = 0
 	outputPadChar  = ' '
+	timeoutSecs    = 10
 )
 
 var RootCmd = &cobra.Command{
@@ -65,6 +69,16 @@ func SetupLogging() {
 	capnslog.SetGlobalLogLevel(logLevel)
 }
 
+func NewRookNetworkRestClient() client.RookRestClient {
+	return NewRookNetworkRestClientWithTimeout(time.Duration(timeoutSecs * time.Second))
+}
+
+func NewRookNetworkRestClientWithTimeout(timeout time.Duration) client.RookRestClient {
+	httpClient := http.DefaultClient
+	httpClient.Timeout = timeout
+	return client.NewRookNetworkRestClient(client.GetRestURL(APIServerEndpoint), httpClient)
+}
+
 func NewTableWriter(buffer io.Writer) *tabwriter.Writer {
 	return tabwriter.NewWriter(buffer, outputMinWidth, outputTabWidth, outputPadding, outputPadChar, 0)
 }

cmd/rook/status/status.go

@@ -18,7 +18,6 @@ package status
 import (
 	"bytes"
 	"fmt"
-	"net/http"
 	"os"
 
 	"github.com/rook/rook/cmd/rook/rook"
@@ -40,7 +39,7 @@ func init() {
 func getStatusEntry(cmd *cobra.Command, args []string) error {
 	rook.SetupLogging()
 
-	c := client.NewRookNetworkRestClient(client.GetRestURL(rook.APIServerEndpoint), http.DefaultClient)
+	c := rook.NewRookNetworkRestClient()
 	out, err := getStatus(c)
 	if err != nil {
 		fmt.Fprintln(os.Stderr, err)

pkg/api/logger.go

@@ -20,23 +20,58 @@ import (
 	"time"
 
 	"github.com/coreos/pkg/capnslog"
+	"github.com/google/uuid"
 )
 
 var logger = capnslog.NewPackageLogger("github.com/rook/rook", "api")
 
+// Implements the http.ResponseWriter interface to intercept response information
+// in order to log it later.
+type loggerResponseWriter struct {
+	innerWriter http.ResponseWriter
+	status      int
+}
+
+func newLoggerResponseWriter(w http.ResponseWriter) *loggerResponseWriter {
+	return &loggerResponseWriter{
+		innerWriter: w,
+		status:      http.StatusOK,
+	}
+}
+
+func (w *loggerResponseWriter) Header() http.Header {
+	return w.innerWriter.Header()
+}
+
+func (w *loggerResponseWriter) Write(d []byte) (int, error) {
+	return w.innerWriter.Write(d)
+}
+
+func (w *loggerResponseWriter) WriteHeader(status int) {
+	w.status = status
+	w.innerWriter.WriteHeader(status)
+}
+
 func Logger(inner http.Handler, name string) http.Handler {
 	return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
 		start := time.Now()
+		reqID, _ := uuid.NewRandom()
 
-		inner.ServeHTTP(w, r)
+		// logs the start of an API request/response in the form of:
+		//	e66d0e38-155b-4179-b343-e3881cd80386	GET	/status	GetStatusDetails	(start)
+		logger.Infof("%s\t%s\t%s\t%s\t(start)", reqID.String(), r.Method, r.RequestURI, name)
 
-		logger.Infof(
-			"(%s)\t%s\t%s\t%s",
-			time.Since(start),
-			r.Method,
-			r.RequestURI,
-			name,
-		)
+		// wrap the response writer with a loggerResponseWriter to catch details for logging that
+		// are written in the response
+		lrw := newLoggerResponseWriter(w)
+
+		// perform the inner ServeHTTP
+		inner.ServeHTTP(lrw, r)
+
+		// logs the end of an API request/response in the form of:
+		// 	e66d0e38-155b-4179-b343-e3881cd80386	GET	/status	GetStatusDetails	200 OK	10.012447ms
+		logger.Infof("%s\t%s\t%s\t%s\t%d %s\t%s", reqID.String(), r.Method, r.RequestURI, name,
+			lrw.status, http.StatusText(lrw.status), time.Since(start))
 	})
 }