From 02cce7ab96bbe9802a70ac9f04d22f9833256ea1 Mon Sep 17 00:00:00 2001
From: Arthur Barr <arthur.barr@uk.ibm.com>
Date: Wed, 21 Feb 2018 09:58:49 +0000
Subject: [PATCH] Tidy up debug logging

---
 cmd/runmqserver/main.go   |  8 ++++----
 cmd/runmqserver/mirror.go | 19 +++++++++----------
 2 files changed, 13 insertions(+), 14 deletions(-)

diff --git a/cmd/runmqserver/main.go b/cmd/runmqserver/main.go
index af9413a..c56960c 100644
--- a/cmd/runmqserver/main.go
+++ b/cmd/runmqserver/main.go
@@ -68,6 +68,10 @@ func doMain() error {
 		return err
 	}
 	var wg sync.WaitGroup
+	defer func() {
+		log.Debugln("Waiting for log mirroring to complete")
+		wg.Wait()
+	}()
 	ctx, cancelMirror := context.WithCancel(context.Background())
 	defer func() {
 		log.Debugln("Cancel log mirroring")
@@ -78,10 +82,6 @@ func doMain() error {
 	if err != nil {
 		return err
 	}
-	defer func() {
-		log.Debugln("Waiting for log mirroring to complete")
-		wg.Wait()
-	}()
 	err = updateCommandLevel()
 	if err != nil {
 		return err
diff --git a/cmd/runmqserver/mirror.go b/cmd/runmqserver/mirror.go
index 5fd30b8..0fd1542 100644
--- a/cmd/runmqserver/mirror.go
+++ b/cmd/runmqserver/mirror.go
@@ -18,7 +18,6 @@ package main
 import (
 	"bufio"
 	"context"
-	"fmt"
 	"os"
 	"sync"
 	"time"
@@ -63,10 +62,10 @@ func mirrorAvailableMessages(f *os.File, mf mirrorFunc) {
 		mf(t)
 		count++
 	}
-	log.Debugf("Mirrored %v log entries", count)
+	log.Debugf("Mirrored %v log entries from %v", count, f.Name())
 	err := scanner.Err()
 	if err != nil {
-		log.Errorf("Error reading file: %v", err)
+		log.Errorf("Error reading file %v: %v", f.Name(), err)
 		return
 	}
 }
@@ -139,7 +138,7 @@ func mirrorLog(ctx context.Context, wg *sync.WaitGroup, path string, fromStart b
 		// The file now exists.  If it didn't exist before we started, offset=0
 		// Always start at the beginning if we've been told to go from the start
 		if offset != 0 && !fromStart {
-			log.Debugf("Seeking %v", offset)
+			log.Debugf("Seeking offset %v in file %v", offset, path)
 			f.Seek(offset, 0)
 		}
 		closing := false
@@ -153,7 +152,7 @@ func mirrorLog(ctx context.Context, wg *sync.WaitGroup, path string, fromStart b
 				return
 			}
 			if !os.SameFile(fi, newFI) {
-				log.Debugln("Detected log rotation")
+				log.Debugf("Detected log rotation in file %v", path)
 				// WARNING: There is a possible race condition here.  If *another*
 				// log rotation happens before we can open the new file, then we
 				// could skip all those messages.  This could happen with a very small
@@ -161,11 +160,11 @@ func mirrorLog(ctx context.Context, wg *sync.WaitGroup, path string, fromStart b
 				mirrorAvailableMessages(f, mf)
 				f.Close()
 				// Re-open file
-				log.Debugln("Re-opening error log file")
-				// Used to work with this: f, err = waitForFile2(path)
+				log.Debugf("Re-opening error log file %v", path)
 				f, err = os.OpenFile(path, os.O_RDONLY, 0)
 				if err != nil {
-					fmt.Printf("ERROR: %v", err)
+					log.Error(err)
+					errorChannel <- err
 					return
 				}
 				fi = newFI
@@ -174,9 +173,9 @@ func mirrorLog(ctx context.Context, wg *sync.WaitGroup, path string, fromStart b
 			}
 			select {
 			case <-ctx.Done():
-				log.Debug("Context cancelled")
+				log.Debugf("Context cancelled for mirroring %v", path)
 				if closing {
-					log.Debug("Shutting down mirror")
+					log.Debugf("Shutting down mirror for %v", path)
 					return
 				}
 				// Set a flag, to allow one more time through the loop