From aebe75cf62ad237fe05fc0501b89661ee01a1ee5 Mon Sep 17 00:00:00 2001
From: Matt Reiferson <mreiferson@gmail.com>
Date: Tue, 7 Apr 2015 16:22:28 -0700
Subject: [PATCH] consumer/producer: improve debug logging

---
 consumer.go      | 12 +++++++++---
 producer_test.go |  2 +-
 2 files changed, 10 insertions(+), 4 deletions(-)

diff --git a/consumer.go b/consumer.go
index 9077cc1e..285ce779 100644
--- a/consumer.go
+++ b/consumer.go
@@ -817,7 +817,8 @@ func (r *Consumer) resume() {
 	// pick a random connection to test the waters
 	conns := r.conns()
 	if len(conns) == 0 {
-		// backoff again
+		r.log(LogLevelWarning, "no connection available to resume")
+		r.log(LogLevelWarning, "backing off for %.04f seconds", 1)
 		r.backoff(time.Second)
 		return
 	}
@@ -831,7 +832,8 @@ func (r *Consumer) resume() {
 	// while in backoff only ever let 1 message at a time through
 	err := r.updateRDY(choice, 1)
 	if err != nil {
-		r.log(LogLevelWarning, "(%s) error updating RDY - %s", choice.String(), err)
+		r.log(LogLevelWarning, "(%s) error resuming RDY 1 - %s", choice.String(), err)
+		r.log(LogLevelWarning, "backing off for %.04f seconds", 1)
 		r.backoff(time.Second)
 		return
 	}
@@ -848,7 +850,11 @@ func (r *Consumer) inBackoffTimeout() bool {
 }
 
 func (r *Consumer) maybeUpdateRDY(conn *Conn) {
-	if r.inBackoff() || r.inBackoffTimeout() {
+	inBackoff := r.inBackoff()
+	inBackoffTimeout := r.inBackoffTimeout()
+	if inBackoff || inBackoffTimeout {
+		r.log(LogLevelDebug, "(%s) skip sending RDY inBackoff:%v || inBackoffTimeout:%v",
+			conn, inBackoff, inBackoffTimeout)
 		return
 	}
 
diff --git a/producer_test.go b/producer_test.go
index 111177f8..820ce96d 100644
--- a/producer_test.go
+++ b/producer_test.go
@@ -51,7 +51,7 @@ func TestProducerConnection(t *testing.T) {
 
 	err := w.Publish("write_test", []byte("test"))
 	if err != nil {
-		t.Fatalf("should lazily connect")
+		t.Fatalf("should lazily connect - %s", err)
 	}
 
 	conn := w.conn.(*Conn)