[logging][rfc] add RAY_LOG_EVERY_N and RAY_LOG_EVERY_MS (ray-project#…

…17018)

* introduce log-every-n

* add n

* linter

* add license

BUILD.bazel

@@ -998,6 +998,7 @@ cc_test(
     deps = [
         ":ray_util",
         "@boost//:asio",
+        "@com_google_absl//absl/strings:str_format",
         "@com_google_googletest//:gtest_main",
     ],
 )

LICENSE

@@ -307,3 +307,36 @@ distributed under the License is distributed on an "AS IS" BASIS,
 WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
 See the License for the specific language governing permissions and
 limitations under the License.
+
+--------------------------------------------------------------------------------
+Code in src/ray/util/logging.h is adapted from 
+https://github.com/google/glog/blob/master/src/glog/logging.h.in
+
+Copyright (c) 2008, Google Inc.
+All rights reserved.
+
+Redistribution and use in source and binary forms, with or without
+modification, are permitted provided that the following conditions are
+met:
+
+    * Redistributions of source code must retain the above copyright
+notice, this list of conditions and the following disclaimer.
+    * Redistributions in binary form must reproduce the above
+copyright notice, this list of conditions and the following disclaimer
+in the documentation and/or other materials provided with the
+distribution.
+    * Neither the name of Google Inc. nor the names of its
+contributors may be used to endorse or promote products derived from
+this software without specific prior written permission.
+
+THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS
+"AS IS" AND ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT
+LIMITED TO, THE IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR
+A PARTICULAR PURPOSE ARE DISCLAIMED. IN NO EVENT SHALL THE COPYRIGHT
+OWNER OR CONTRIBUTORS BE LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL,
+SPECIAL, EXEMPLARY, OR CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT
+LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES; LOSS OF USE,
+DATA, OR PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED AND ON ANY
+THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY, OR TORT
+(INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE
+OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE.

src/ray/util/logging.h

@@ -11,9 +11,45 @@
 // WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
 // See the License for the specific language governing permissions and
 // limitations under the License.
+//
+// --------------------------------------------------------------
+//
+// RAY_LOG_EVERY_N and RAY_LOG_EVERY_MS are adapted from
+// https://github.com/google/glog/blob/master/src/glog/logging.h.in
+//
+// Copyright (c) 2008, Google Inc.
+// All rights reserved.
+//
+// Redistribution and use in source and binary forms, with or without
+// modification, are permitted provided that the following conditions are
+// met:
+//
+//     * Redistributions of source code must retain the above copyright
+// notice, this list of conditions and the following disclaimer.
+//     * Redistributions in binary form must reproduce the above
+// copyright notice, this list of conditions and the following disclaimer
+// in the documentation and/or other materials provided with the
+// distribution.
+//     * Neither the name of Google Inc. nor the names of its
+// contributors may be used to endorse or promote products derived from
+// this software without specific prior written permission.
+//
+// THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS
+// "AS IS" AND ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT
+// LIMITED TO, THE IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR
+// A PARTICULAR PURPOSE ARE DISCLAIMED. IN NO EVENT SHALL THE COPYRIGHT
+// OWNER OR CONTRIBUTORS BE LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL,
+// SPECIAL, EXEMPLARY, OR CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT
+// LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES; LOSS OF USE,
+// DATA, OR PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED AND ON ANY
+// THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY, OR TORT
+// (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE
+// OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE.
 
 #pragma once
 
+#include <atomic>
+#include <chrono>
 #include <iostream>
 #include <string>
 
@@ -84,6 +120,40 @@ enum class RayLogLevel {
 
 #endif  // NDEBUG
 
+// RAY_LOG_EVERY_N/RAY_LOG_EVERY_MS, adaped from
+// https://github.com/google/glog/blob/master/src/glog/logging.h.in
+#define RAY_LOG_EVERY_N_VARNAME(base, line) RAY_LOG_EVERY_N_VARNAME_CONCAT(base, line)
+#define RAY_LOG_EVERY_N_VARNAME_CONCAT(base, line) base##line
+
+#define RAY_LOG_OCCURRENCES RAY_LOG_EVERY_N_VARNAME(occurrences_, __LINE__)
+
+#define RAY_LOG_EVERY_N(level, n)                             \
+  static std::atomic<uint64_t> RAY_LOG_OCCURRENCES(0);        \
+  if (ray::RayLog::IsLevelEnabled(ray::RayLogLevel::level) && \
+      RAY_LOG_OCCURRENCES.fetch_add(1) % n == 0)              \
+  RAY_LOG_INTERNAL(ray::RayLogLevel::level) << "[" << RAY_LOG_OCCURRENCES - 1 << "] "
+
+/// Macros for RAY_LOG_EVERY_MS
+#define RAY_LOG_TIME_PERIOD RAY_LOG_EVERY_N_VARNAME(timePeriod_, __LINE__)
+#define RAY_LOG_PREVIOUS_TIME_RAW RAY_LOG_EVERY_N_VARNAME(previousTimeRaw_, __LINE__)
+#define RAY_LOG_TIME_DELTA RAY_LOG_EVERY_N_VARNAME(deltaTime_, __LINE__)
+#define RAY_LOG_CURRENT_TIME RAY_LOG_EVERY_N_VARNAME(currentTime_, __LINE__)
+#define RAY_LOG_PREVIOUS_TIME RAY_LOG_EVERY_N_VARNAME(previousTime_, __LINE__)
+
+#define RAY_LOG_EVERY_MS(level, ms)                                                      \
+  constexpr std::chrono::milliseconds RAY_LOG_TIME_PERIOD(ms);                           \
+  static std::atomic<int64_t> RAY_LOG_PREVIOUS_TIME_RAW;                                 \
+  const auto RAY_LOG_CURRENT_TIME = std::chrono::steady_clock::now().time_since_epoch(); \
+  const decltype(RAY_LOG_CURRENT_TIME) RAY_LOG_PREVIOUS_TIME(                            \
+      RAY_LOG_PREVIOUS_TIME_RAW.load(std::memory_order_relaxed));                        \
+  const auto RAY_LOG_TIME_DELTA = RAY_LOG_CURRENT_TIME - RAY_LOG_PREVIOUS_TIME;          \
+  if (RAY_LOG_TIME_DELTA > RAY_LOG_TIME_PERIOD)                                          \
+    RAY_LOG_PREVIOUS_TIME_RAW.store(RAY_LOG_CURRENT_TIME.count(),                        \
+                                    std::memory_order_relaxed);                          \
+  if (ray::RayLog::IsLevelEnabled(ray::RayLogLevel::level) &&                            \
+      RAY_LOG_TIME_DELTA > RAY_LOG_TIME_PERIOD)                                          \
+  RAY_LOG_INTERNAL(ray::RayLogLevel::level)
+
 // To make the logging lib plugable with other logging libs and make
 // the implementation unawared by the user, RayLog is only a declaration
 // which hide the implementation into logging.cc file.

src/ray/util/logging_test.cc

@@ -18,9 +18,13 @@
 #include <cstdlib>
 #include <iostream>
 
+#include "absl/strings/str_format.h"
+#include "gmock/gmock.h"
 #include "gtest/gtest.h"
 #include "ray/util/filesystem.h"
 
+using namespace testing;
+
 namespace ray {
 
 int64_t current_time_ms() {
@@ -55,6 +59,51 @@ TEST(PrintLogTest, LogTestWithoutInit) {
   PrintLog();
 }
 
+#if GTEST_HAS_STREAM_REDIRECTION
+using testing::internal::CaptureStderr;
+using testing::internal::GetCapturedStderr;
+
+TEST(PrintLogTest, TestRayLogEveryN) {
+  CaptureStderr();
+  for (int i = 0; i < 10; i++) {
+    RAY_LOG_EVERY_N(INFO, 3) << "this is a test log";
+  }
+  std::string output = GetCapturedStderr();
+  for (int i = 0; i < 10; i++) {
+    std::string expected_str = absl::StrFormat("[%d] this is a test log", i);
+    if (i % 3 == 0) {
+      EXPECT_THAT(output, HasSubstr(expected_str));
+    } else {
+      EXPECT_THAT(output, Not(HasSubstr(expected_str)));
+    }
+  }
+}
+
+TEST(PrintLogTest, TestRayLogEveryMs) {
+  CaptureStderr();
+  const std::string kLogStr = "this is a test log";
+  auto start_time = std::chrono::steady_clock::now().time_since_epoch();
+  size_t num_iterations = 0;
+  while (std::chrono::steady_clock::now().time_since_epoch() - start_time <
+         std::chrono::milliseconds(100)) {
+    num_iterations++;
+    RAY_LOG_EVERY_MS(INFO, 10) << kLogStr;
+  }
+  std::string output = GetCapturedStderr();
+  size_t occurrences = 0;
+  std::string::size_type start = 0;
+
+  while ((start = output.find(kLogStr, start)) != std::string::npos) {
+    ++occurrences;
+    start += kLogStr.length();
+  }
+  EXPECT_LT(occurrences, num_iterations);
+  EXPECT_GT(occurrences, 5);
+  EXPECT_LT(occurrences, 15);
+}
+
+#endif /* GTEST_HAS_STREAM_REDIRECTION */
+
 TEST(PrintLogTest, LogTestWithInit) {
   // Test empty app name.
   RayLog::StartRayLog("", RayLogLevel::DEBUG, ray::GetUserTempDir() + ray::GetDirSep());