Log ErrUnexpectedEOF from watches as warnings

Watches are often established via long-running HTTP GET requests which will inevitably time out during the normal course of operations. When the watches time out, an io.EOF or an io.ErrUnexpectedEOF will bubble up to client components such as StreamWatcher and Reflector. Treat EOF as a clean watch termination. Treat ErrUnexpectedEOF as a less-clean but non-fatal watch termination and log the event at the warning level. This greatly reduces the amount of log noise generated during what is ultimately normal operation, and adds the flexibility for the operator to make a distinction between the EOF conditions if so desired (by adjusting the logging level).

Log ErrUnexpectedEOF from watches as warnings
0ad8342a · Dan Mace · 993ef88e · 0ad8342a · 0ad8342a
Commit 0ad8342a authored Dec 05, 2014 by Dan Mace
Hide whitespace changes
Inline Side-by-side

Showing with 16 additions and 3 deletions

reflector.go pkg/client/cache/reflector.go +10 -2

iowatcher.go pkg/watch/iowatcher.go +6 -1

No files found.
--- a/pkg/client/cache/reflector.go
+++ b/pkg/client/cache/reflector.go
@@ -19,6 +19,7 @@ package cache
 import (
 	"errors"
 	"fmt"
+	"io"
 	"reflect"
 	"time"

@@ -99,7 +100,14 @@ func (r *Reflector) listAndWatch() {
 	for {
 		w, err := r.listerWatcher.Watch(resourceVersion)
 		if err != nil {
-			glog.Errorf("failed to watch %v: %v", r.expectedType, err)
+			switch err {
+			case io.EOF:
+				// watch closed normally
+			case io.ErrUnexpectedEOF:
+				glog.V(1).Infof("Watch for %v closed with unexpected EOF: %v", r.expectedType, err)
+			default:
+				glog.Errorf("Failed to watch %v: %v", r.expectedType, err)
+			}
 			return
 		}
 		if err := r.watchHandler(w, &resourceVersion); err != nil {
@@ -167,6 +175,6 @@ func (r *Reflector) watchHandler(w watch.Interface, resourceVersion *string) err
 		glog.Errorf("unexpected watch close - watch lasted less than a second and no items received")
 		return errors.New("very short watch")
 	}
-	glog.V(4).Infof("watch close - %v total items received", eventCount)
+	glog.V(4).Infof("Watch close - %v total %v items received", r.expectedType, eventCount)
 	return nil
 }
--- a/pkg/watch/iowatcher.go
+++ b/pkg/watch/iowatcher.go
@@ -84,7 +84,12 @@ func (sw *StreamWatcher) receive() {
 	for {
 		action, obj, err := sw.source.Decode()
 		if err != nil {
-			if err != io.EOF {
+			switch err {
+			case io.EOF:
+				// watch closed normally
+			case io.ErrUnexpectedEOF:
+				glog.V(1).Infof("Unexpected EOF during watch stream event decoding: %v", err)
+			default:
 				glog.Errorf("Unable to decode an event from the watch stream: %v", err)
 			}
 			return