More spdlog tests

rcl_logging_spdlog/CMakeLists.txt

@@ -47,9 +47,11 @@ if(BUILD_TESTING)
   ament_lint_auto_find_test_dependencies()
 
   find_package(ament_cmake_gtest REQUIRED)
+  find_package(rcpputils REQUIRED)
   ament_add_gtest(test_logging_interface test/test_logging_interface.cpp)
   if(TARGET test_logging_interface)
     target_link_libraries(test_logging_interface ${PROJECT_NAME})
+    ament_target_dependencies(test_logging_interface rcpputils)
   endif()
 endif()
 

rcl_logging_spdlog/package.xml

@@ -20,6 +20,7 @@
 
   <test_depend>ament_lint_auto</test_depend>
   <test_depend>ament_lint_common</test_depend>
+  <test_depend>rcpputils</test_depend>
 
   <member_of_group>rcl_logging_packages</member_of_group>
 

rcl_logging_spdlog/test/fixtures.hpp

@@ -0,0 +1,126 @@
+// Copyright 2020 Open Source Robotics Foundation, Inc.
+//
+// Licensed under the Apache License, Version 2.0 (the "License");
+// you may not use this file except in compliance with the License.
+// You may obtain a copy of the License at
+//
+//     http://www.apache.org/licenses/LICENSE-2.0
+//
+// Unless required by applicable law or agreed to in writing, software
+// 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.
+
+#ifndef FIXTURES_HPP_
+#define FIXTURES_HPP_
+
+#include <rcpputils/filesystem_helper.hpp>
+#include <rcutils/allocator.h>
+#include <rcutils/error_handling.h>
+#include <rcutils/get_env.h>
+#include <rcutils/process.h>
+#include <rcutils/types/string_array.h>
+
+#include <string>
+
+#include "gtest/gtest.h"
+
+#ifdef _WIN32
+#define popen _popen
+#define pclose _pclose
+#define DIR_CMD "dir /B"
+#else
+#define DIR_CMD "ls -d"
+#endif
+
+namespace fs = rcpputils::fs;
+
+class AllocatorTest : public ::testing::Test
+{
+public:
+  AllocatorTest()
+  : allocator(rcutils_get_default_allocator()),
+    bad_allocator(get_bad_allocator()),
+    invalid_allocator(rcutils_get_zero_initialized_allocator())
+  {
+  }
+
+  rcutils_allocator_t allocator;
+  rcutils_allocator_t bad_allocator;
+  rcutils_allocator_t invalid_allocator;
+
+private:
+  static rcutils_allocator_t get_bad_allocator()
+  {
+    rcutils_allocator_t bad_allocator = rcutils_get_default_allocator();
+    bad_allocator.allocate = AllocatorTest::bad_malloc;
+    bad_allocator.reallocate = AllocatorTest::bad_realloc;
+    return bad_allocator;
+  }
+
+  static void * bad_malloc(size_t, void *)
+  {
+    return nullptr;
+  }
+
+  static void * bad_realloc(void *, size_t, void *)
+  {
+    return nullptr;
+  }
+};
+
+class LoggingTest : public AllocatorTest
+{
+public:
+  LoggingTest()
+  : AllocatorTest()
+  {
+  }
+
+  fs::path find_single_log()
+  {
+    fs::path log_dir = get_log_dir();
+    std::stringstream dir_command;
+    dir_command << DIR_CMD << " " << (log_dir / get_expected_log_prefix()).string() << "*";
+
+    FILE * fp = popen(dir_command.str().c_str(), "r");
+    if (nullptr == fp) {
+      throw std::runtime_error("Failed to glob for log files");
+    }
+
+    char raw_line[2048];
+    while (fgets(raw_line, sizeof(raw_line), fp) != NULL) {
+      pclose(fp);
+
+      std::string line(raw_line);
+      fs::path line_path(line.substr(0, line.find_last_not_of(" \t\r\n") + 1));
+      // This should be changed once ros2/rcpputils#68 is resolved
+      return line_path.is_absolute() ? line_path : log_dir / line_path;
+    }
+
+    pclose(fp);
+    throw std::runtime_error("No log files were found");
+  }
+
+private:
+  std::string get_expected_log_prefix()
+  {
+    char * exe_name = rcutils_get_executable_name(allocator);
+    if (nullptr == exe_name) {
+      throw std::runtime_error("Failed to determine executable name");
+    }
+    std::stringstream prefix;
+    prefix << exe_name << "_" <<
+      rcutils_get_pid() << "_";
+    allocator.deallocate(exe_name, allocator.state);
+    return prefix.str();
+  }
+
+  fs::path get_log_dir()
+  {
+    return fs::path(rcutils_get_home_dir()) / ".ros" / "log";
+  }
+};
+
+#endif  // FIXTURES_HPP_

rcl_logging_spdlog/test/test_logging_interface.cpp

@@ -15,21 +15,16 @@
 #include <rcutils/allocator.h>
 #include <rcutils/error_handling.h>
 #include <rcutils/logging.h>
-#include "rcl_logging_spdlog/logging_interface.h"
-#include "gtest/gtest.h"
 
-static void * bad_malloc(size_t, void *)
-{
-  return nullptr;
-}
+#include <fstream>
+#include <string>
 
-TEST(logging_interface, init_invalid)
-{
-  rcutils_allocator_t allocator = rcutils_get_default_allocator();
-  rcutils_allocator_t bad_allocator = rcutils_get_default_allocator();
-  rcutils_allocator_t invalid_allocator = rcutils_get_zero_initialized_allocator();
-  bad_allocator.allocate = bad_malloc;
+#include "fixtures.hpp"
+#include "gtest/gtest.h"
+#include "rcl_logging_spdlog/logging_interface.h"
 
+TEST_F(LoggingTest, init_invalid)
+{
   // Config files are not supported by spdlog
   EXPECT_EQ(2, rcl_logging_external_initialize("anything", allocator));
   rcutils_reset_error();
@@ -39,12 +34,40 @@ TEST(logging_interface, init_invalid)
   rcutils_reset_error();
 }
 
-TEST(logging_interface, full_cycle)
+TEST_F(LoggingTest, full_cycle)
 {
-  rcutils_allocator_t allocator = rcutils_get_default_allocator();
+  ASSERT_EQ(0, rcl_logging_external_initialize(nullptr, allocator));
 
+  // Make sure we can call initialize more than once
   ASSERT_EQ(0, rcl_logging_external_initialize(nullptr, allocator));
-  EXPECT_EQ(0, rcl_logging_external_set_logger_level(nullptr, RCUTILS_LOG_SEVERITY_INFO));
-  rcl_logging_external_log(RCUTILS_LOG_SEVERITY_INFO, nullptr, "Log Message");
+
+  std::stringstream expected_log;
+  for (int level = RCUTILS_LOG_SEVERITY_UNSET; level <= RCUTILS_LOG_SEVERITY_FATAL; level += 10) {
+    EXPECT_EQ(0, rcl_logging_external_set_logger_level(nullptr, level));
+
+    for (int severity = RCUTILS_LOG_SEVERITY_UNSET; severity <= RCUTILS_LOG_SEVERITY_FATAL;
+      severity += 10)
+    {
+      std::stringstream ss;
+      ss << "Message of severity " << severity << " at level " << level;
+      rcl_logging_external_log(severity, nullptr, ss.str().c_str());
+
+      if (severity >= level) {
+        expected_log << ss.str() << std::endl;
+      } else if (severity == 0 && level == 10) {
+        // This is a special case - not sure what the right behavior is
+        expected_log << ss.str() << std::endl;
+      }
+    }
+  }
+
   EXPECT_EQ(0, rcl_logging_external_shutdown());
+
+  std::string log_file_path = find_single_log().string();
+  std::ifstream log_file(log_file_path);
+  std::stringstream actual_log;
+  actual_log << log_file.rdbuf();
+  EXPECT_EQ(
+    expected_log.str(),
+    actual_log.str()) << "Unexpected log contents in " << log_file_path;
 }