Upgrade client_golang to get POST support

In addition this changes the access logging to always print the first
256 bytes of form data (query params or post form), this way POST query
or query_range have some information in the logs

Fixes #48

logging/logging.go

@@ -4,14 +4,63 @@ import (
 	"fmt"
 	"io"
 	"net/http"
+	"net/url"
 	"runtime/debug"
 	"strings"
 	"time"
 
 	"github.com/pkg/errors"
 )
 
-const ApacheFormatPattern = "%s - - [%s] \"%s %d %d\" %f\n"
+const MaxFormPrefix = 256
+
+func FormPrefix(form url.Values) string {
+	var buf strings.Builder
+
+	// appendBuf will append s to buf until it is "filled" (based on MaxFormPrefix)
+	appendBuf := func(s string) bool {
+		if buf.Len()+len(s) >= MaxFormPrefix {
+			remaining := MaxFormPrefix - buf.Len()
+			if remaining > 0 {
+				buf.WriteString(s[:remaining])
+			}
+			return false
+		}
+
+		buf.WriteString(s)
+		return true
+	}
+	for k, values := range form {
+		keyEscaped := url.QueryEscape(k)
+		for _, v := range values {
+			if buf.Len() >= MaxFormPrefix {
+				return buf.String()
+			}
+			if buf.Len() > 0 {
+				buf.WriteByte('&')
+			}
+			if !appendBuf(keyEscaped) {
+				return buf.String()
+			}
+			buf.WriteByte('=')
+			if buf.Len()+len(v) >= MaxFormPrefix {
+				remaining := MaxFormPrefix - buf.Len()
+				if remaining > 0 {
+					if !appendBuf(url.QueryEscape(v[:remaining])) {
+						return buf.String()
+					}
+				}
+			} else {
+				if !appendBuf(url.QueryEscape(v)) {
+					return buf.String()
+				}
+			}
+		}
+	}
+	return buf.String()
+}
+
+const ApacheFormatPattern = "%s - - [%s] \"%s %d %d\" %f %s\n"
 
 type ApacheLogRecord struct {
 	http.ResponseWriter
@@ -22,13 +71,14 @@ type ApacheLogRecord struct {
 	Status                int
 	ResponseBytes         int64
 	ElapsedTime           time.Duration
+	FormPrefix            string
 }
 
 func (r *ApacheLogRecord) Log(out io.Writer) {
 	timeFormatted := r.Time.Format("02/Jan/2006 15:04:05")
 	requestLine := fmt.Sprintf("%s %s %s", r.Method, r.URI, r.Protocol)
 	fmt.Fprintf(out, ApacheFormatPattern, r.IP, timeFormatted, requestLine, r.Status, r.ResponseBytes,
-		r.ElapsedTime.Seconds())
+		r.ElapsedTime.Seconds(), r.FormPrefix)
 }
 
 func (r *ApacheLogRecord) Write(p []byte) (int, error) {
@@ -79,13 +129,16 @@ func (h *ApacheLoggingHandler) ServeHTTP(rw http.ResponseWriter, r *http.Request
 		clientIP = clientIP[:colon]
 	}
 
+	r.ParseForm()
+
 	record := &ApacheLogRecord{
 		ResponseWriter: rw,
 		IP:             clientIP,
 		Method:         r.Method,
-		URI:            r.RequestURI,
+		URI:            r.URL.Path,
 		Protocol:       r.Proto,
 		Status:         http.StatusOK,
+		FormPrefix:     FormPrefix(r.Form),
 	}
 
 	startTime := time.Now()

logging/logging_test.go

@@ -0,0 +1,54 @@
+package logging
+
+import (
+	"net/url"
+	"strconv"
+	"testing"
+)
+
+func TestFormPrefix(t *testing.T) {
+	tooManyValues := make(url.Values)
+
+	for i := 0; i < MaxFormPrefix; i++ {
+		k := strconv.Itoa(i)
+		tooManyValues[k] = []string{k}
+	}
+
+	tests := []struct {
+		f url.Values
+		v string
+	}{
+		// Basic one
+		{
+			f: url.Values(map[string][]string{
+				"a": {"a"},
+			}),
+			v: `a=a`,
+		},
+		// where a single value is too long
+		{
+			f: url.Values(map[string][]string{
+				"a": {"aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa"},
+			}),
+			v: `a=aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa`,
+		},
+		// Where there are too many values
+		{
+			f: tooManyValues,
+		},
+	}
+
+	for i, test := range tests {
+		t.Run(strconv.Itoa(i), func(t *testing.T) {
+			v := FormPrefix(test.f)
+			if len(v) > MaxFormPrefix {
+				t.Fatalf("Value over MaxFormPrefix: expected=%d actual=%d", MaxFormPrefix, len(v))
+			}
+			if test.v != "" {
+				if v != test.v {
+					t.Fatalf("Mismatch in values expected=%s actual=%s", test.v, v)
+				}
+			}
+		})
+	}
+}