From 1f15441103caab1b41317a6107fc2560eb109a4a Mon Sep 17 00:00:00 2001
From: John Ericson <John.Ericson@Obsidian.Systems>
Date: Tue, 30 Nov 2021 20:23:13 +0000
Subject: [PATCH] Tidy up the logging

Use the macros more, so we properly skip work when the log level
excludes. Also log the daemon operation number on the daemon side.
---
 src/libstore/daemon.cc    | 4 +++-
 src/libstore/store-api.cc | 2 +-
 src/libutil/logging.hh    | 5 +++--
 3 files changed, 7 insertions(+), 4 deletions(-)

diff --git a/src/libstore/daemon.cc b/src/libstore/daemon.cc
index 2eb566080..58c567b05 100644
--- a/src/libstore/daemon.cc
+++ b/src/libstore/daemon.cc
@@ -951,7 +951,7 @@ void processConnection(
 
     Finally finally([&]() {
         _isInterrupted = false;
-        prevLogger->log(lvlDebug, fmt("%d operations", opCount));
+        printMsgUsing(prevLogger, lvlDebug, "%d operations", opCount);
     });
 
     if (GET_PROTOCOL_MINOR(clientVersion) >= 14 && readInt(from)) {
@@ -984,6 +984,8 @@ void processConnection(
                 break;
             }
 
+            printMsgUsing(prevLogger, lvlDebug, "received daemon op %d", op);
+
             opCount++;
 
             try {
diff --git a/src/libstore/store-api.cc b/src/libstore/store-api.cc
index 71350906e..aab4ce94c 100644
--- a/src/libstore/store-api.cc
+++ b/src/libstore/store-api.cc
@@ -1079,7 +1079,7 @@ std::map<StorePath, StorePath> copyPaths(
                     nrFailed++;
                     if (!settings.keepGoing)
                         throw e;
-                    logger->log(lvlError, fmt("could not copy %s: %s", dstStore.printStorePath(storePath), e.what()));
+                    printMsg(lvlError, "could not copy %s: %s", dstStore.printStorePath(storePath), e.what());
                     showProgress();
                     return;
                 }
diff --git a/src/libutil/logging.hh b/src/libutil/logging.hh
index 96ad69790..ce9c3dfed 100644
--- a/src/libutil/logging.hh
+++ b/src/libutil/logging.hh
@@ -189,13 +189,14 @@ extern Verbosity verbosity; /* suppress msgs > this */
 /* Print a string message if the current log level is at least the specified
    level. Note that this has to be implemented as a macro to ensure that the
    arguments are evaluated lazily. */
-#define printMsg(level, args...) \
+#define printMsgUsing(loggerParam, level, args...) \
     do { \
         auto __lvl = level; \
         if (__lvl <= nix::verbosity) { \
-            logger->log(__lvl, fmt(args)); \
+            loggerParam->log(__lvl, fmt(args)); \
         } \
     } while (0)
+#define printMsg(level, args...) printMsgUsing(logger, level, args)
 
 #define printError(args...) printMsg(lvlError, args)
 #define notice(args...) printMsg(lvlNotice, args)