Create API to get last comms error message

Summary: Due to the fact that we log nccl "stack trace" (e.g. `NCCL WARN init.cc:1234 -> 2`) as warning, the ncclGetLastError will return those "stack traces" as the last error, making the message useless. Additionally, ncclGetLastError will not show errors that we log via XLOG. Implement last error in NcclLogFormatter to restore access to the last error string.

Reviewed By: minsii

Differential Revision: D85412934

fbshipit-source-id: bf552f81c106e1a61514753a71d742981875fb42

Author: YulunW

comms/ncclx/v2_27/meta/logger/tests/LoggingUT.cc

@@ -92,6 +92,105 @@ TEST_F(NcclLoggerTest, LogDisplay) {
   finishLogging();
 }
 
+TEST_F(NcclLoggerTest, GetLastCommsErrorTest) {
+  auto debugGuard = EnvRAII(NCCL_DEBUG, std::string{"INFO"});
+  ncclResetDebugInit();
+
+  initLogging();
+
+  // Initially, the last error should be empty
+  auto lastError = meta::comms::logger::getLastCommsError();
+  EXPECT_THAT(lastError, ::testing::StrEq(""));
+
+  // Log an info message - should not update last error
+  std::string infoMsg = "INFO MESSAGE";
+  INFO(NCCL_ALL, "%s", infoMsg.c_str());
+  sleep(1);
+  lastError = meta::comms::logger::getLastCommsError();
+  EXPECT_THAT(lastError, ::testing::StrEq(""));
+
+  // Log a warning message - should not update last error
+  std::string warnMsg = "WARN MESSAGE";
+  WARN("%s", warnMsg.c_str());
+  sleep(1);
+  lastError = meta::comms::logger::getLastCommsError();
+  EXPECT_THAT(lastError, ::testing::StrEq(""));
+
+  // Log an error message - should update last error
+  std::string errorMsg = "ERROR MESSAGE";
+  ERR("%s", errorMsg.c_str());
+  sleep(1);
+  lastError = meta::comms::logger::getLastCommsError();
+  EXPECT_THAT(lastError, ::testing::StrEq(errorMsg));
+
+  // Log another error message - should update to the new error
+  std::string errorMsg2 = "SECOND ERROR MESSAGE";
+  ERR("%s", errorMsg2.c_str());
+  sleep(1);
+  lastError = meta::comms::logger::getLastCommsError();
+  EXPECT_THAT(lastError, ::testing::StrEq(errorMsg2));
+
+  // Log info and warn - last error should remain unchanged
+  INFO(NCCL_ALL, "Another info");
+  WARN("Another warn");
+  sleep(1);
+  lastError = meta::comms::logger::getLastCommsError();
+  EXPECT_THAT(lastError, ::testing::StrEq(errorMsg2));
+
+  finishLogging();
+}
+
+TEST_F(NcclLoggerTest, GetLastCommsErrorMultilineTest) {
+  auto debugGuard = EnvRAII(NCCL_DEBUG, std::string{"INFO"});
+  ncclResetDebugInit();
+
+  initLogging();
+
+  // Log a multiline error message
+  std::string multilineError = "First line\nSecond line\nThird line";
+  ERR("%s", multilineError.c_str());
+  sleep(1);
+
+  auto lastError = meta::comms::logger::getLastCommsError();
+  EXPECT_THAT(lastError, ::testing::StrEq(multilineError));
+
+  finishLogging();
+}
+
+TEST_F(NcclLoggerTest, GetLastCommsErrorLongMessageTest) {
+  auto debugGuard = EnvRAII(NCCL_DEBUG, std::string{"INFO"});
+  ncclResetDebugInit();
+
+  initLogging();
+
+  // Create a long error message (but within the 1024 char buffer)
+  std::string longError(500, 'X');
+  ERR("%s", longError.c_str());
+  sleep(1);
+
+  auto lastError = meta::comms::logger::getLastCommsError();
+  EXPECT_THAT(lastError, ::testing::StrEq(longError));
+
+  finishLogging();
+}
+
+TEST_F(NcclLoggerTest, GetLastCommsErrorLongMessageTestXLOG) {
+  auto debugGuard = EnvRAII(NCCL_DEBUG, std::string{"INFO"});
+  ncclResetDebugInit();
+
+  initLogging();
+
+  // Create a long error message (but within the 1024 char buffer)
+  std::string longError(500, 'X');
+  XLOG(ERR) << longError;
+  sleep(1);
+
+  auto lastError = meta::comms::logger::getLastCommsError();
+  EXPECT_THAT(lastError, ::testing::StrEq(longError));
+
+  finishLogging();
+}
+
 TEST_F(NcclLoggerTest, WarnLogTest) {
   auto debugGuard = EnvRAII(NCCL_DEBUG, std::string{"WARN"});
   ncclResetDebugInit();

comms/ncclx/v2_27/src/init.cc

@@ -48,6 +48,7 @@
 
 #include "comms/utils/cvars/nccl_cvars.h"
 #include "comms/utils/logger/EventsScubaUtil.h"
+#include "comms/utils/logger/LoggingFormat.h"
 #include "comms/ctran/memory/SlabAllocator.h"
 #include "comms/ctran/memory/Utils.h"
 #include "meta/wrapper/MetaFactory.h"
@@ -2845,7 +2846,7 @@ const char* ncclGetErrorString(ncclResult_t code) {
  */
 NCCL_API(const char*, ncclGetLastError, const ncclComm_t comm);
 const char* ncclGetLastError(ncclComm_t comm) {
-  return ncclLastError;
+  return meta::comms::logger::getLastCommsError();
 }
 
 NCCL_API(ncclResult_t, ncclCommGetAsyncError, ncclComm_t comm, ncclResult_t *asyncError);

comms/utils/logger/LoggingFormat.cc

@@ -7,6 +7,7 @@
 
 #include <fmt/chrono.h>
 #include <fmt/format.h>
+#include <folly/Synchronized.h>
 #include <folly/logging/LogMessage.h>
 #include <folly/logging/LogName.h>
 #include <folly/synchronization/CallOnce.h>
@@ -33,6 +34,10 @@ struct ProcMetaData {
 folly::once_flag procMetaDataInitFlag;
 static thread_local std::string myThreadName = "main";
 
+// Using char array to ensure compatibility with NCCL GetLastError API
+static folly::Synchronized<std::array<char, 1024>> lastCommsError{
+    std::array<char, 1024>{'\0'}};
+
 } // Anonymous namespace
 
 namespace meta::comms::logger {
@@ -229,6 +234,16 @@ std::string NcclLogFormatter::formatMessage(
     const folly::LogCategory* /* handlerCategory */) {
   initProcMetaData();
 
+  bool isErrorMessage = message.getLevel() >= folly::LogLevel::ERR;
+  if (isErrorMessage) {
+    auto lastErrorLocked = lastCommsError.wlock();
+    std::snprintf(
+        lastErrorLocked->data(),
+        lastErrorLocked->size(),
+        "%s",
+        message.getMessage().c_str());
+  }
+
   auto timeSinceEpoch = message.getTimestamp().time_since_epoch();
   auto epochSeconds =
       std::chrono::duration_cast<std::chrono::seconds>(timeSinceEpoch);
@@ -310,6 +325,10 @@ std::string NcclLogFormatter::formatMessage(
   return buffer;
 }
 
+const char* getLastCommsError() {
+  return lastCommsError.rlock()->data();
+}
+
 NcclLogFormatter::NcclLogFormatter(
     std::string prefix,
     std::function<int(void)> threadContextFn)

comms/utils/logger/LoggingFormat.h

@@ -61,6 +61,8 @@ void initThreadMetaData(std::string_view threadName);
 
 fmt::memory_buffer getLogPrefix(LogLevel level);
 
+const char* getLastCommsError();
+
 class NcclLogFormatter : public folly::LogFormatter {
  public:
   NcclLogFormatter(