Merge pull request #4098 from gyuho/merge_log

*: use merge logger for repeating etcdserver error logs

etcdserver/etcdhttp/client.go

@@ -605,9 +605,9 @@ func writeKeyError(w http.ResponseWriter, err error) {
 	default:
 		switch err {
 		case etcdserver.ErrTimeoutDueToLeaderFail, etcdserver.ErrTimeoutDueToConnectionLost:
-			plog.Error(err)
+			mlog.MergeError(err)
 		default:
-			plog.Errorf("got unexpected response error (%v)", err)
+			mlog.MergeErrorf("got unexpected response error (%v)", err)
 		}
 		ee := etcdErr.NewError(etcdErr.EcodeRaftInternal, err.Error(), 0)
 		ee.WriteTo(w)

etcdserver/etcdhttp/http.go

@@ -26,6 +26,7 @@ import (
 	"github.com/coreos/etcd/etcdserver"
 	"github.com/coreos/etcd/etcdserver/auth"
 	"github.com/coreos/etcd/etcdserver/etcdhttp/httptypes"
+	"github.com/coreos/etcd/pkg/logutil"
 )
 
 const (
@@ -35,6 +36,7 @@ const (
 
 var (
 	plog      = capnslog.NewPackageLogger("github.com/coreos/etcd", "etcdhttp")
+	mlog      = logutil.NewMergeLogger(plog)
 	errClosed = errors.New("etcdhttp: client closed connection")
 )
 
@@ -60,9 +62,9 @@ func writeError(w http.ResponseWriter, r *http.Request, err error) {
 	default:
 		switch err {
 		case etcdserver.ErrTimeoutDueToLeaderFail, etcdserver.ErrTimeoutDueToConnectionLost, etcdserver.ErrNotEnoughStartedMembers:
-			plog.Error(err)
+			mlog.MergeError(err)
 		default:
-			plog.Errorf("got unexpected response error (%v)", err)
+			mlog.MergeErrorf("got unexpected response error (%v)", err)
 		}
 		herr := httptypes.NewHTTPError(http.StatusInternalServerError, "Internal Server Error")
 		if et := herr.WriteTo(w); et != nil {

pkg/logutil/merge_logger.go

@@ -24,7 +24,8 @@ import (
 )
 
 var (
-	defaultMergePeriod = time.Second
+	defaultMergePeriod     = time.Second
+	defaultTimeOutputScale = 10 * time.Millisecond
 
 	outputInterval = time.Second
 )
@@ -58,7 +59,9 @@ func (s *status) isInMergePeriod(now time.Time) bool {
 func (s *status) isEmpty() bool { return s.count == 0 }
 
 func (s *status) summary(now time.Time) string {
-	return fmt.Sprintf("[merged %d repeated lines in %s]", s.count, now.Sub(s.start))
+	ts := s.start.Round(defaultTimeOutputScale)
+	took := now.Round(defaultTimeOutputScale).Sub(ts)
+	return fmt.Sprintf("[merged %d repeated lines in %s]", s.count, took)
 }
 
 func (s *status) reset(now time.Time) {

pkg/logutil/merge_logger_test.go

@@ -0,0 +1,71 @@
+// Copyright 2015 CoreOS, Inc.
+//
+// Licensed under the Apache License, Version 2.0 (the "License");
+// you may not use this file except in compliance with the License.
+// You may obtain a copy of the License at
+//
+//     http://www.apache.org/licenses/LICENSE-2.0
+//
+// Unless required by applicable law or agreed to in writing, software
+// distributed under the License is distributed on an "AS IS" BASIS,
+// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+// See the License for the specific language governing permissions and
+// limitations under the License.
+
+package logutil
+
+import (
+	"fmt"
+	"strings"
+	"testing"
+	"time"
+
+	"github.com/coreos/etcd/Godeps/_workspace/src/github.com/coreos/pkg/capnslog"
+)
+
+var (
+	testLogger = capnslog.NewPackageLogger("github.com/coreos/etcd/pkg", "logutil")
+)
+
+func TestMergeLogger(t *testing.T) {
+	var (
+		txt      = "hello"
+		repeatN  = 6
+		duration = 2049843762 * time.Nanosecond
+		mg       = NewMergeLogger(testLogger)
+	)
+	// overwrite this for testing
+	defaultMergePeriod = time.Minute
+
+	for i := 0; i < repeatN; i++ {
+		mg.MergeError(txt)
+		if i == 0 {
+			time.Sleep(duration)
+		}
+	}
+
+	if len(mg.statusm) != 1 {
+		t.Errorf("got = %d, want = %d", len(mg.statusm), 1)
+	}
+
+	var l line
+	for k := range mg.statusm {
+		l = k
+		break
+	}
+
+	if l.level != capnslog.ERROR {
+		t.Errorf("got = %v, want = %v", l.level, capnslog.DEBUG)
+	}
+	if l.str != txt {
+		t.Errorf("got = %s, want = %s", l.str, txt)
+	}
+	if mg.statusm[l].count != repeatN-1 {
+		t.Errorf("got = %d, want = %d", mg.statusm[l].count, repeatN-1)
+	}
+	sum := mg.statusm[l].summary(time.Now())
+	pre := fmt.Sprintf("[merged %d repeated lines in ", repeatN-1)
+	if !strings.HasPrefix(sum, pre) {
+		t.Errorf("got = %s, want = %s...", sum, pre)
+	}
+}