Moved logger back to cerr (#4702)

* Moved logger back to cerr

* Simplified stream logger experience; removed need for std::endl

sdk/core/azure-core-amqp/src/amqp/claim_based_security.cpp

@@ -121,7 +121,7 @@ namespace Azure { namespace Core { namespace Amqp { namespace _detail {
     if (cbs->m_traceEnabled)
     {
       Log::Stream(Logger::Level::Informational)
-          << "OnCbsOpenComplete: " << OpenResultStringFromLowLevel(openCompleteResult) << std::endl;
+          << "OnCbsOpenComplete: " << OpenResultStringFromLowLevel(openCompleteResult);
     }
     cbs->m_openResultQueue.CompleteOperation(CbsOpenResultStateFromLowLevel(openCompleteResult));
   }
@@ -161,7 +161,7 @@ namespace Azure { namespace Core { namespace Amqp { namespace _detail {
           << "OnCbsOperationComplete: "
           << OperationResultStringFromLowLevel(operationCompleteResult)
           << " StatusCode: " << statusCode << " StatusDescription: "
-          << (statusDescription ? std::string(statusDescription) : "(NULL)") << std::endl;
+          << (statusDescription ? std::string(statusDescription) : "(NULL)");
     }
 
     cbs->m_operationResultQueue.CompleteOperation(

sdk/core/azure-core-amqp/src/amqp/management.cpp

@@ -184,7 +184,7 @@ namespace Azure { namespace Core { namespace Amqp { namespace _detail {
     if (management->m_options.EnableTrace)
     {
       Log::Stream(Logger::Level::Informational)
-          << "OnManagementOpenComplete: " << std::to_string(openResult) << std::endl;
+          << "OnManagementOpenComplete: " << std::to_string(openResult);
     }
     management->m_openCompleteQueue.CompleteOperation(openResult);
   }

sdk/core/azure-core-amqp/src/amqp/message_receiver.cpp

@@ -109,7 +109,7 @@ namespace Azure { namespace Core { namespace Amqp { namespace _detail {
       // Log that an error occurred.
       Log::Stream(Logger::Level::Error)
           << "Message receiver link detached: " + error.Condition.ToString() << ": "
-          << error.Description << std::endl;
+          << error.Description;
 
       // Cache the error we received in the OnDetach notification so we can return it to the user on
       // the next send which fails.
@@ -237,7 +237,7 @@ namespace Azure { namespace Core { namespace Amqp { namespace _detail {
     {
       Log::Stream(Logger::Level::Verbose)
           << "Message receiver changed state. New: " << MESSAGE_RECEIVER_STATEStrings[newState]
-          << " Old: " << MESSAGE_RECEIVER_STATEStrings[oldState] << std::endl;
+          << " Old: " << MESSAGE_RECEIVER_STATEStrings[oldState];
       ;
     }
 

sdk/core/azure-core-amqp/src/amqp/message_sender.cpp

@@ -123,7 +123,7 @@ namespace Azure { namespace Core { namespace Amqp { namespace _detail {
       // Log that an error occurred.
       Log::Stream(Logger::Level::Error)
           << "Message sender link detached: " << error.Condition.ToString() << ": "
-          << error.Description << std::endl;
+          << error.Description;
 
       // Cache the error we received in the OnDetach notification so we can return it to the user on
       // the next send which fails.

sdk/core/azure-core-amqp/src/amqp/session.cpp

@@ -238,7 +238,7 @@ namespace Azure { namespace Core { namespace Amqp { namespace _detail {
     }
     auto accessToken = GetConnection()->GetSecurityToken(audience, context);
     Log::Stream(Logger::Level::Informational)
-        << "Authenticate with audience: " << audience << ", token: " << accessToken << std::endl;
+        << "Authenticate with audience: " << audience << ", token: " << accessToken;
 
     m_claimsBasedSecurity->SetTrace(GetConnection()->EnableTrace());
     if (!m_cbsOpen)

sdk/core/azure-core-amqp/src/network/socket_transport.cpp

@@ -25,7 +25,7 @@ namespace Azure { namespace Core { namespace Amqp { namespace Network { namespac
       TransportEvents* eventHandler)
   {
     Log::Stream(Logger::Level::Verbose)
-        << "Create socket transport for host " << host << " port: " << port << std::endl;
+        << "Create socket transport for host " << host << " port: " << port;
 
     SOCKETIO_CONFIG socketConfig{host.c_str(), port, nullptr};
     return _detail::TransportImpl::CreateFromXioHandle(

sdk/core/azure-core/CHANGELOG.md

@@ -10,7 +10,7 @@
 
 ### Other Changes
 
-- The default logger now logs all non-error outputs to `stdout` instead of `stderr`. Log level `Error` is still logged to `stderr`.
+Empty diagnostic messages will no longer be generated.
 
 ## 1.10.0 (2023-06-01)
 

sdk/core/azure-core/README.md

@@ -117,7 +117,8 @@ int main()
 
 Note, the listener callback is executed on the same thread as the operation that triggered the log message. 
  It is recommended implementation due the minimal amount of log message processing on the callback thread.
-Where message processing is required, consider implementing in a way that the callback pushes the message string into a thread-safe queue, so that another thread would pick the messages from that queue and handle them.
+Where message processing is required, consider implementing in a way that the callback pushes the message 
+string into a thread-safe queue, so that another thread would pick the messages from that queue and handle them.
 
 ## Next steps
 

sdk/core/azure-core/inc/azure/core/internal/diagnostics/log.hpp

@@ -50,6 +50,19 @@ namespace Azure { namespace Core { namespace Diagnostics { namespace _internal {
       LoggerStringBuffer m_stringBuffer;
     };
 
+    class Stream {
+    public:
+      Stream(Logger::Level level) : m_stream(GetStream(level)) {}
+      ~Stream() { m_stream.flush(); }
+      Stream(Stream const&) = delete;
+      Stream& operator=(Stream const&) = delete;
+
+      template <typename T> std::ostream& operator<<(T val) { return m_stream << val; }
+
+    private:
+      LoggerStream& m_stream;
+    };
+
     static bool ShouldWrite(Logger::Level level)
     {
       return g_isLoggingEnabled && level >= g_logLevel;
@@ -59,6 +72,8 @@ namespace Azure { namespace Core { namespace Diagnostics { namespace _internal {
 
     static void EnableLogging(bool isEnabled);
     static void SetLogLevel(Logger::Level logLevel);
-    static LoggerStream& Stream(Logger::Level level);
+
+  private:
+    static LoggerStream& GetStream(Logger::Level level);
   };
 }}}} // namespace Azure::Core::Diagnostics::_internal

sdk/core/azure-core/src/environment_log_level_listener.cpp

@@ -120,15 +120,12 @@ EnvironmentLogLevelListener::GetLogListener()
 
   static std::function<void(Logger::Level level, std::string const& message)> const consoleLogger =
       [](auto level, auto message) {
-        std::ostream* os = &std::cout;
-        if (level == Logger::Level::Error)
-        {
-          os = &std::cerr;
-        }
-        *os << '['
-            << Azure::DateTime(std::chrono::system_clock::now())
-                   .ToString(DateTime::DateFormat::Rfc3339, DateTime::TimeFractionFormat::AllDigits)
-            << "] " << LogLevelToConsoleString(level) << " : " << message;
+        // Log diagnostics to cerr rather than cout.
+        std::cerr << '['
+                  << Azure::DateTime(std::chrono::system_clock::now())
+                         .ToString(
+                             DateTime::DateFormat::Rfc3339, DateTime::TimeFractionFormat::AllDigits)
+                  << "] " << LogLevelToConsoleString(level) << " : " << message;
 
         // If the message ends with a new line, flush the stream otherwise insert a new line to
         // terminate the message.
@@ -138,11 +135,11 @@ EnvironmentLogLevelListener::GetLogListener()
         // insert unnecessary new lines.
         if (!message.empty() && message.back() == '\n')
         {
-          *os << std::flush;
+          std::cerr << std::flush;
         }
         else
         {
-          *os << std::endl;
+          std::cerr << std::endl;
         }
       };
 

sdk/core/azure-core/src/logger.cpp

@@ -32,7 +32,7 @@ inline void Log::SetLogLevel(Logger::Level logLevel) { g_logLevel = logLevel; }
 
 void Log::Write(Logger::Level level, std::string const& message)
 {
-  if (ShouldWrite(level))
+  if (ShouldWrite(level) && !message.empty())
   {
     std::shared_lock<std::shared_timed_mutex> loggerLock(g_logListenerMutex);
     if (g_logListener)
@@ -54,21 +54,25 @@ void Logger::SetLevel(Logger::Level level) { Log::SetLogLevel(level); }
 
 int Log::LoggerStringBuffer::sync()
 {
+  // Note that in the case of the caller inserting std::endl, the buffer will be flushed twice, once
+  // with the \n terminated string, the second time with an empty string (from the destructor of
+  // Log::Stream). This depends on the code in Log::Write which discards empty strings.
   Log::Write(m_level, str());
   str(std::string());
   return 0;
 }
-
+namespace {
 static Log::LoggerStream g_verboseLogger{Logger::Level::Verbose};
 static Log::LoggerStream g_informationalLogger{Logger::Level::Informational};
 static Log::LoggerStream g_warningLogger{Logger::Level::Warning};
 static Log::LoggerStream g_errorLogger{Logger::Level::Error};
+} // namespace
 
 /** Returns a custom ostream implementation with a logger based stream buffer.
  *  @param level The level of the log message.
  *  @return A custom ostream implementation.
  */
-Log::LoggerStream& Log::Stream(Logger::Level level)
+Log::LoggerStream& Log::GetStream(Logger::Level level)
 {
   switch (level)
   {

sdk/core/azure-core/test/ut/environment_log_level_listener_test.cpp

@@ -127,7 +127,7 @@ TEST_F(EnvironmentLogLevelListenerTest, GetLogListenerVerbose)
   SetLogLevel("verbose");
 
   std::stringstream buffer;
-  std::streambuf* old = std::cout.rdbuf(buffer.rdbuf());
+  std::streambuf* old = std::cerr.rdbuf(buffer.rdbuf());
 
   auto listener = EnvironmentLogLevelListener::GetLogListener();
 
@@ -135,7 +135,7 @@ TEST_F(EnvironmentLogLevelListenerTest, GetLogListenerVerbose)
 
   listener(Logger::Level::Verbose, "message");
   EXPECT_NE(buffer.str().find("DEBUG : message"), std::string::npos);
-  std::cout.rdbuf(old);
+  std::cerr.rdbuf(old);
 }
 
 TEST_F(EnvironmentLogLevelListenerTest, GetLogListenerError)
@@ -143,7 +143,6 @@ TEST_F(EnvironmentLogLevelListenerTest, GetLogListenerError)
   EnvironmentLogLevelListener::SetInitialized(false);
   SetLogLevel("verbose");
 
-  // Error logging goes to cerr, all other logging goes to cout.
   std::stringstream buffer;
   std::streambuf* old = std::cerr.rdbuf(buffer.rdbuf());
 
@@ -161,9 +160,8 @@ TEST_F(EnvironmentLogLevelListenerTest, GetLogListenerWarning)
   EnvironmentLogLevelListener::SetInitialized(false);
   SetLogLevel("verbose");
 
-  // Error logging goes to cerr, all other logging goes to cout.
   std::stringstream buffer;
-  std::streambuf* old = std::cout.rdbuf(buffer.rdbuf());
+  std::streambuf* old = std::cerr.rdbuf(buffer.rdbuf());
 
   auto listener = EnvironmentLogLevelListener::GetLogListener();
 
@@ -171,7 +169,7 @@ TEST_F(EnvironmentLogLevelListenerTest, GetLogListenerWarning)
 
   listener(Logger::Level::Warning, "message");
   EXPECT_NE(buffer.str().find("WARN  : message"), std::string::npos);
-  std::cout.rdbuf(old);
+  std::cerr.rdbuf(old);
 }
 
 TEST_F(EnvironmentLogLevelListenerTest, GetLogListenerInformational)
@@ -179,9 +177,8 @@ TEST_F(EnvironmentLogLevelListenerTest, GetLogListenerInformational)
   EnvironmentLogLevelListener::SetInitialized(false);
   SetLogLevel("verbose");
 
-  // Error logging goes to cerr, all other logging goes to cout.
   std::stringstream buffer;
-  std::streambuf* old = std::cout.rdbuf(buffer.rdbuf());
+  std::streambuf* old = std::cerr.rdbuf(buffer.rdbuf());
 
   auto listener = EnvironmentLogLevelListener::GetLogListener();
 
@@ -189,7 +186,7 @@ TEST_F(EnvironmentLogLevelListenerTest, GetLogListenerInformational)
 
   listener(Logger::Level::Informational, "message");
   EXPECT_NE(buffer.str().find("INFO  : message"), std::string::npos);
-  std::cout.rdbuf(old);
+  std::cerr.rdbuf(old);
 }
 
 TEST_F(EnvironmentLogLevelListenerTest, GetLogListenerUnknown)
@@ -197,9 +194,8 @@ TEST_F(EnvironmentLogLevelListenerTest, GetLogListenerUnknown)
   EnvironmentLogLevelListener::SetInitialized(false);
   SetLogLevel("verbose");
 
-  // Error logging goes to cerr, all other logging goes to cout.
   std::stringstream buffer;
-  std::streambuf* old = std::cout.rdbuf(buffer.rdbuf());
+  std::streambuf* old = std::cerr.rdbuf(buffer.rdbuf());
 
   auto listener = EnvironmentLogLevelListener::GetLogListener();
 
@@ -207,7 +203,7 @@ TEST_F(EnvironmentLogLevelListenerTest, GetLogListenerUnknown)
 
   listener(static_cast<Logger::Level>(42), "message");
   EXPECT_NE(buffer.str().find("????? : message"), std::string::npos);
-  std::cout.rdbuf(old);
+  std::cerr.rdbuf(old);
 }
 
 // Verify that the log listener inserts a crlf at the end of the message if none is provided.
@@ -218,7 +214,7 @@ TEST_F(EnvironmentLogLevelListenerTest, GetLogListenerWithNoCrlf)
 
   // Error logging goes to cerr, all other logging goes to cout.
   std::stringstream buffer;
-  std::streambuf* old = std::cout.rdbuf(buffer.rdbuf());
+  std::streambuf* old = std::cerr.rdbuf(buffer.rdbuf());
 
   auto listener = EnvironmentLogLevelListener::GetLogListener();
 
@@ -226,7 +222,7 @@ TEST_F(EnvironmentLogLevelListenerTest, GetLogListenerWithNoCrlf)
 
   listener(Logger::Level::Informational, "message");
   EXPECT_NE(buffer.str().find("INFO  : message\n"), std::string::npos);
-  std::cout.rdbuf(old);
+  std::cerr.rdbuf(old);
 }
 
 // Verify that the log listener does not insert a crlf at the end of the message if one is provided.
@@ -237,7 +233,7 @@ TEST_F(EnvironmentLogLevelListenerTest, GetLogListenerWithCrlf)
 
   // Error logging goes to cerr, all other logging goes to cout.
   std::stringstream buffer;
-  std::streambuf* old = std::cout.rdbuf(buffer.rdbuf());
+  std::streambuf* old = std::cerr.rdbuf(buffer.rdbuf());
 
   auto listener = EnvironmentLogLevelListener::GetLogListener();
 
@@ -246,7 +242,7 @@ TEST_F(EnvironmentLogLevelListenerTest, GetLogListenerWithCrlf)
   listener(Logger::Level::Informational, "message\n");
   EXPECT_NE(buffer.str().find("INFO  : message\n"), std::string::npos);
   EXPECT_EQ(buffer.str().find("INFO  : message\n\n"), std::string::npos);
-  std::cout.rdbuf(old);
+  std::cerr.rdbuf(old);
 }
 
 // Verify that the log listener handles empty strings correctly.
@@ -257,7 +253,7 @@ TEST_F(EnvironmentLogLevelListenerTest, GetLogListenerWithEmptyString)
 
   std::stringstream buffer;
   // Error logging goes to cerr, all other logging goes to cout.
-  std::streambuf* old = std::cout.rdbuf(buffer.rdbuf());
+  std::streambuf* old = std::cerr.rdbuf(buffer.rdbuf());
 
   auto listener = EnvironmentLogLevelListener::GetLogListener();
 
@@ -266,5 +262,5 @@ TEST_F(EnvironmentLogLevelListenerTest, GetLogListenerWithEmptyString)
   listener(Logger::Level::Informational, "");
   EXPECT_NE(buffer.str().find("INFO  : \n"), std::string::npos);
   EXPECT_EQ(buffer.str().find("INFO  : \n\n"), std::string::npos);
-  std::cout.rdbuf(old);
+  std::cerr.rdbuf(old);
 }

sdk/core/azure-core/test/ut/logging_test.cpp

@@ -215,24 +215,20 @@ TEST(Logger, LoggerStream)
 
   Logger::SetLevel(Logger::Level::Verbose);
   {
-    Log::Stream(Logger::Level::Verbose) << "Verbose" << std::endl;
-    EXPECT_EQ(message, "Verbose\n");
-    Log::Stream(Logger::Level::Informational) << "Informational" << std::endl;
-    EXPECT_EQ(message, "Informational\n");
+    Log::Stream(Logger::Level::Verbose) << "Verbose";
+    EXPECT_EQ(message, "Verbose");
+    message.clear();
+
+    Log::Stream(Logger::Level::Informational) << "Informational" << 10;
+    EXPECT_EQ(message, "Informational10");
     message.clear();
 
     Log::Stream(Logger::Level::Warning) << "Warning" << std::endl;
     EXPECT_EQ(message, "Warning\n");
     message.clear();
 
-    Log::Stream(Logger::Level::Error) << "Error" << std::endl;
-    EXPECT_EQ(message, "Error\n");
-    message.clear();
-
-    Log::Stream(Logger::Level::Verbose) << "Test";
-    // std::endl flushes the stream, so we need to manually flush the ostream.
-    Log::Stream(Logger::Level::Verbose).flush();
-    EXPECT_EQ(message, "Test");
+    Log::Stream(Logger::Level::Error) << "Error";
+    EXPECT_EQ(message, "Error");
     message.clear();
   }
 
@@ -242,54 +238,54 @@ TEST(Logger, LoggerStream)
     EXPECT_EQ(message, "");
     message.clear();
 
-    Log::Stream(Logger::Level::Informational) << "Informational" << std::endl;
-    EXPECT_EQ(message, "Informational\n");
+    Log::Stream(Logger::Level::Informational) << "Informational";
+    EXPECT_EQ(message, "Informational");
     message.clear();
 
-    Log::Stream(Logger::Level::Warning) << "Warning" << std::endl;
-    EXPECT_EQ(message, "Warning\n");
+    Log::Stream(Logger::Level::Warning) << "Warning";
+    EXPECT_EQ(message, "Warning");
     message.clear();
 
-    Log::Stream(Logger::Level::Error) << "Error" << std::endl;
-    EXPECT_EQ(message, "Error\n");
+    Log::Stream(Logger::Level::Error) << "Error";
+    EXPECT_EQ(message, "Error");
     message.clear();
   }
 
   Logger::SetLevel(Logger::Level::Warning);
   {
-    Log::Stream(Logger::Level::Verbose) << "Verbose" << std::endl;
+    Log::Stream(Logger::Level::Verbose) << "Verbose";
     EXPECT_EQ(message, "");
     message.clear();
 
-    Log::Stream(Logger::Level::Informational) << "Informational" << std::endl;
+    Log::Stream(Logger::Level::Informational) << "Informational";
     EXPECT_EQ(message, "");
     message.clear();
 
-    Log::Stream(Logger::Level::Warning) << "Warning" << std::endl;
-    EXPECT_EQ(message, "Warning\n");
+    Log::Stream(Logger::Level::Warning) << "Warning";
+    EXPECT_EQ(message, "Warning");
     message.clear();
 
-    Log::Stream(Logger::Level::Error) << "Error" << std::endl;
-    EXPECT_EQ(message, "Error\n");
+    Log::Stream(Logger::Level::Error) << "Error";
+    EXPECT_EQ(message, "Error");
     message.clear();
   }
 
   Logger::SetLevel(Logger::Level::Error);
   {
-    Log::Stream(Logger::Level::Verbose) << "Verbose" << std::endl;
+    Log::Stream(Logger::Level::Verbose) << "Verbose";
     EXPECT_EQ(message, "");
     message.clear();
 
-    Log::Stream(Logger::Level::Informational) << "Informational" << std::endl;
+    Log::Stream(Logger::Level::Informational) << "Informational";
     EXPECT_EQ(message, "");
     message.clear();
 
-    Log::Stream(Logger::Level::Warning) << "Warning" << std::endl;
+    Log::Stream(Logger::Level::Warning) << "Warning";
     EXPECT_EQ(message, "");
     message.clear();
 
-    Log::Stream(Logger::Level::Error) << "Error" << std::endl;
-    EXPECT_EQ(message, "Error\n");
+    Log::Stream(Logger::Level::Error) << "Error";
+    EXPECT_EQ(message, "Error");
     message.clear();
   }
 }