Hide known warnings and reduce verbosity related to Geant4 geometry and tracker (#2151)

* Have scoped logger truncate and remove colors from debug messages

This is why the "turds" error was still showing up

* Note and suppress g4 track warning messages

* Improve debug  message about regions

* Reduce verbosity of debug messages

* Suppress acknowledged warning

* Fix comment

* Update test to allow for fewer tangent normals

Author: sethrj

src/geocel/GeantGeoParams.cc

@@ -532,10 +532,22 @@ std::vector<inp::Region> make_inp_regions(GeantGeoParams const& geo)
             result.push_back(region);
         }
     }
-    CELER_LOG(debug) << "Loaded " << region_map.size() << " regions out of "
-                     << G4RegionStore::GetInstance()->size()
-                     << " Geant4 regions and created " << result.size()
-                     << " new regions";
+
+    auto* region_store = G4RegionStore::GetInstance();
+    CELER_ASSERT(region_store);
+
+    if (!region_store->empty() || !result.empty())
+    {
+        CELER_LOG(debug) << "Loaded " << region_map.size()
+                         << " regions out of "
+                         << G4RegionStore::GetInstance()->size()
+                         << " Geant4 regions and created " << result.size()
+                         << " new regions";
+    }
+    else
+    {
+        CELER_LOG(debug) << "Geant4 has no regions, and none were created";
+    }
 
     // Add regions to result vector
     for (auto&& [g4reg, volumes] : region_map)

src/geocel/GeantGeoUtils.cc

@@ -128,7 +128,7 @@ std::ostream& operator<<(std::ostream& os, StreamableLV const& plv)
  */
 void reset_geant_geometry()
 {
-    CELER_LOG(status) << "Resetting Geant4 geometry stores";
+    CELER_LOG(debug) << "Resetting Geant4 geometry stores";
 
     std::string msg;
     {

test/PersistentSP.hh

@@ -152,8 +152,8 @@ void PersistentSP<T>::Env::TearDown()
     }
     else if (use_count == 1)
     {
-        CELER_LOG(info) << "Clearing persistent " << this->desc << " '"
-                        << this->key << "'";
+        CELER_LOG(debug) << "Clearing persistent " << this->desc << " '"
+                         << this->key << "'";
     }
     else
     {

test/corecel/ScopedLogStorer.cc

@@ -13,13 +13,23 @@
 #include "corecel/io/Logger.hh"
 #include "corecel/io/LoggerTypes.hh"
 #include "corecel/io/Repr.hh"
+#include "corecel/sys/Environment.hh"
 
 #include "StringSimplifier.hh"
 
 namespace celeritas
 {
 namespace test
 {
+namespace
+{
+void debug_clog(LogProvenance, LogLevel lev, std::string msg)
+{
+    std::clog << color_code('x') << to_cstring(lev) << ": " << msg
+              << color_code(' ') << std::endl;
+}
+}  // namespace
+
 //---------------------------------------------------------------------------//
 /*!
  * Construct reference to log to temporarily replace.
@@ -59,15 +69,36 @@ ScopedLogStorer::~ScopedLogStorer()
 
 //---------------------------------------------------------------------------//
 //! Save a log message
-void ScopedLogStorer::operator()(LogProvenance, LogLevel lev, std::string msg)
+void ScopedLogStorer::operator()(LogProvenance prov,
+                                 LogLevel lev,
+                                 std::string msg)
 {
     static LogLevel const debug_level
         = log_level_from_env("CELER_LOG_SCOPED", LogLevel::warning);
     if (lev >= debug_level)
     {
-        std::clog << color_code('x') << to_cstring(lev) << ": " << msg
-                  << color_code(' ') << std::endl;
+        if (getenv_flag("CELER_LOG_SCOPED_VERBOSE", false).value)
+        {
+            // Print entire message
+            debug_clog(prov, lev, msg);
+        }
+        else
+        {
+            // Strip colors and only write the first line
+            static std::regex const strip_ansi_regex("\033\\[[0-9;]*m");
+            auto temp_msg = std::regex_replace(msg, strip_ansi_regex, "");
+            auto newline_pos = temp_msg.find_first_of('\n');
+            if (newline_pos != std::string::npos)
+            {
+                // Erase newline and after
+                temp_msg.erase(newline_pos);
+                temp_msg
+                    += "... [truncated: set CELER_LOG_SCOPED_VERBOSE to show]";
+            }
+            debug_clog(prov, lev, temp_msg);
+        }
     }
+
     if (lev < min_level_)
     {
         return;

test/geocel/CheckedGeoTrackView.cc

@@ -421,8 +421,9 @@ void CheckedGeoTrackView::cross_boundary()
         // Check for tangent crossing warning
         if (soft_zero(dot_product(t_->dir(), post_norm)))
         {
-            CELER_LOG(warning) << "Crossed at a tangent normal "
-                               << repr(post_norm) << ": " << *this;
+            CELER_LOG_LOCAL(warning)
+                << "Crossed at a tangent normal " << repr(post_norm)
+                << ": post-crossing state is " << *this;
         }
     }
 }

test/geocel/g4/GeantGeo.test.cc

@@ -7,6 +7,7 @@
 #include <regex>
 #include <string_view>
 #include <G4LogicalVolume.hh>
+#include <G4StateManager.hh>
 #include <G4VSensitiveDetector.hh>
 
 #include "corecel/Config.hh"
@@ -25,10 +26,8 @@
 #include "geocel/ScopedGeantExceptionHandler.hh"
 #include "geocel/ScopedGeantLogger.hh"
 #include "geocel/UnitUtils.hh"
-#include "geocel/VolumeParams.hh"
-#include "geocel/g4/GeantGeoData.hh"
-#include "geocel/g4/GeantGeoTrackView.hh"
-#include "geocel/inp/Model.hh"
+#include "geocel/VolumeParams.hh"  // IWYU pragma: keep
+#include "geocel/inp/Model.hh"  // IWYU pragma: keep
 #include "geocel/rasterize/SafetyImager.hh"
 
 #include "GeantGeoTestBase.hh"
@@ -84,6 +83,27 @@ class GeantGeoTest : public GeantGeoTestBase
 
     ScopedGeantExceptionHandler exception_handler;
     ScopedGeantLogger logger{celeritas::world_logger()};
+
+    void SetUp() override
+    {
+        GeantGeoTestBase::SetUp();
+        ASSERT_TRUE(this->geometry());
+
+        auto* sm = G4StateManager::GetStateManager();
+        CELER_ASSERT(sm);
+        // Have ScopedGeantExceptionHandler treat tracking errors like runtime
+        EXPECT_TRUE(sm->SetNewState(G4ApplicationState::G4State_EventProc));
+    }
+
+    void TearDown() override
+    {
+        ASSERT_TRUE(this->geometry());
+
+        // Restore G4 state just in case it matters
+        auto* sm = G4StateManager::GetStateManager();
+        EXPECT_TRUE(sm->SetNewState(G4ApplicationState::G4State_PreInit));
+        GeantGeoTestBase::TearDown();
+    }
 };
 
 //---------------------------------------------------------------------------//
@@ -295,7 +315,13 @@ TEST_F(FourLevelsTest, consecutive_compute)
 
 TEST_F(FourLevelsTest, detailed_track)
 {
+    ScopedLogStorer scoped_log_{&self_logger()};
     this->impl().test_detailed_tracking();
+
+    // "Finding next step up to ... when previous step 4 was already
+    // calculated"
+    static char const* const expected_log_levels[] = {"warning", "warning"};
+    EXPECT_VEC_EQ(expected_log_levels, scoped_log_.levels()) << scoped_log_;
 }
 
 TEST_F(FourLevelsTest, safety)
@@ -803,11 +829,14 @@ TEST_F(SimpleCmsTest, trace)
 
 TEST_F(SimpleCmsTest, detailed_track)
 {
-    if (CELERITAS_USE_VECGEOM && !CELERITAS_VECGEOM_SURFACE)
+    ScopedLogStorer scoped_log_{&self_logger()};
+    this->impl().test_detailed_tracking();
+    if (geant4_version >= Version{11})
     {
-        GTEST_SKIP() << "FIXME: VecGeom surface v1,v2 both trigger a G4 error";
+        // G4 11.3: "Accuracy error or slightly inaccurate position shift."
+        static char const* const expected_log_levels[] = {"error", "error"};
+        EXPECT_VEC_EQ(expected_log_levels, scoped_log_.levels()) << scoped_log_;
     }
-    this->impl().test_detailed_tracking();
 }
 
 //---------------------------------------------------------------------------//
@@ -851,7 +880,15 @@ TEST_F(SolidsTest, accessors)
 
 TEST_F(SolidsTest, trace)
 {
+    ScopedLogStorer scoped_log_{&self_logger()};
     TestImpl(this).test_trace();
+    if (geant4_version >= Version{11})
+    {
+        // G4 11.3 report normal directions perpendicular to track direction
+        // due to coincident surfaces; and at least one of the tangents is
+        // machine-dependent
+        EXPECT_GE(scoped_log_.levels().size(), 3) << scoped_log_;
+    }
 }
 
 //---------------------------------------------------------------------------//