refactor: Make intersection verbose logging a lot more verbose (#827)

Debugging intersection issues is tricky. This PR adds `LoggerWrapper` to the surface update function, enabling it to provide more granular verbose log output. The output is structured to make it easy to understand what is going on during the intersection calculation.

Core/include/Acts/Propagator/AtlasStepper.hpp

@@ -519,9 +519,10 @@ class AtlasStepper {
   /// @param surface [in] The surface provided
   /// @param bcheck [in] The boundary check for this status update
   Intersection3D::Status updateSurfaceStatus(
-      State& state, const Surface& surface, const BoundaryCheck& bcheck) const {
-    return detail::updateSingleSurfaceStatus<AtlasStepper>(*this, state,
-                                                           surface, bcheck);
+      State& state, const Surface& surface, const BoundaryCheck& bcheck,
+      LoggerWrapper logger = getDummyLogger()) const {
+    return detail::updateSingleSurfaceStatus<AtlasStepper>(
+        *this, state, surface, bcheck, logger);
   }
 
   /// Update step size

Core/include/Acts/Propagator/EigenStepper.hpp

@@ -237,9 +237,10 @@ class EigenStepper {
   /// @param surface [in] The surface provided
   /// @param bcheck [in] The boundary check for this status update
   Intersection3D::Status updateSurfaceStatus(
-      State& state, const Surface& surface, const BoundaryCheck& bcheck) const {
-    return detail::updateSingleSurfaceStatus<EigenStepper>(*this, state,
-                                                           surface, bcheck);
+      State& state, const Surface& surface, const BoundaryCheck& bcheck,
+      LoggerWrapper logger = getDummyLogger()) const {
+    return detail::updateSingleSurfaceStatus<EigenStepper>(
+        *this, state, surface, bcheck, logger);
   }
 
   /// Update step size

Core/include/Acts/Propagator/Navigator.hpp

@@ -345,8 +345,8 @@ class Navigator {
       }
     } else if (state.navigation.currentVolume ==
                state.navigation.targetVolume) {
-      ACTS_VERBOSE(volInfo(state)
-                   << "No further navigation action, proceed to target.");
+      ACTS_WARNING(volInfo(state) << "No further navigation action, proceed to "
+                                     "target. This is very likely an error");
       // Set navigation break and release the navigation step size
       state.navigation.navigationBreak = true;
       stepper.releaseStepSize(state.stepping);
@@ -529,7 +529,7 @@ class Navigator {
     // If we are on the surface pointed at by the iterator, we can make
     // it the current one to pass it to the other actors
     auto surfaceStatus =
-        stepper.updateSurfaceStatus(state.stepping, *surface, true);
+        stepper.updateSurfaceStatus(state.stepping, *surface, true, logger);
     if (surfaceStatus == Intersection3D::Status::onSurface) {
       ACTS_VERBOSE(volInfo(state)
                    << "Status Surface successfully hit, storing it.");
@@ -621,8 +621,8 @@ class Navigator {
           break;
         }
       }
-      auto surfaceStatus =
-          stepper.updateSurfaceStatus(state.stepping, *surface, boundaryCheck);
+      auto surfaceStatus = stepper.updateSurfaceStatus(state.stepping, *surface,
+                                                       boundaryCheck, logger);
       if (surfaceStatus == Intersection3D::Status::reachable) {
         ACTS_VERBOSE(volInfo(state)
                      << "Surface reachable, step size updated to "
@@ -781,8 +781,8 @@ class Navigator {
         }
       }
       // Try to step towards it
-      auto layerStatus =
-          stepper.updateSurfaceStatus(state.stepping, *layerSurface, true);
+      auto layerStatus = stepper.updateSurfaceStatus(
+          state.stepping, *layerSurface, true, logger);
       if (layerStatus == Intersection3D::Status::reachable) {
         ACTS_VERBOSE(volInfo(state) << "Layer reachable, step size updated to "
                                     << stepper.outputStepSize(state.stepping));
@@ -924,8 +924,8 @@ class Navigator {
       // That is the current boundary surface
       auto boundarySurface = state.navigation.navBoundaryIter->representation;
       // Step towards the boundary surfrace
-      auto boundaryStatus =
-          stepper.updateSurfaceStatus(state.stepping, *boundarySurface, true);
+      auto boundaryStatus = stepper.updateSurfaceStatus(
+          state.stepping, *boundarySurface, true, logger);
       if (boundaryStatus == Intersection3D::Status::reachable) {
         ACTS_VERBOSE(volInfo(state)
                      << "Boundary reachable, step size updated to "
@@ -940,6 +940,10 @@ class Navigator {
           os << " out of " << state.navigation.navBoundaries.size();
           os << " not reachable anymore, switching to next.";
           logger.log(Logging::VERBOSE, os.str());
+          os.str("");
+          os << "Targeted boundary surface was: \n";
+          boundarySurface->toStream(state.geoContext, os);
+          logger.log(Logging::VERBOSE, os.str());
         }
       }
       // Increase the iterator to the next one
@@ -1230,7 +1234,7 @@ class Navigator {
         return true;
       }
       auto targetStatus = stepper.updateSurfaceStatus(
-          state.stepping, *state.navigation.targetSurface, true);
+          state.stepping, *state.navigation.targetSurface, true, logger);
       // the only advance could have been to the target
       if (targetStatus == Intersection3D::Status::onSurface) {
         // set the target surface

Core/include/Acts/Propagator/StepperConcept.hpp

@@ -14,6 +14,7 @@
 #include "Acts/Surfaces/BoundaryCheck.hpp"
 #include "Acts/Surfaces/Surface.hpp"
 #include "Acts/Utilities/Intersection.hpp"
+#include "Acts/Utilities/Logger.hpp"
 #include "Acts/Utilities/TypeTraits.hpp"
 
 namespace Acts {
@@ -115,7 +116,7 @@ using step_size_t = decltype(std::declval<T>().stepSize);
         constexpr static bool covariance_transport_exists = require<has_method<const S, void, covariance_transport_curvilinear_t, state&>,
                                                                     has_method<const S, void, covariance_transport_bound_t, state&, const Surface&>>;
         static_assert(covariance_transport_exists, "covarianceTransport method not found");
-        constexpr static bool update_surface_exists = has_method<const S, Intersection3D::Status, update_surface_status_t, state&, const Surface&, const BoundaryCheck&>;
+        constexpr static bool update_surface_exists = has_method<const S, Intersection3D::Status, update_surface_status_t, state&, const Surface&, const BoundaryCheck&, LoggerWrapper>;
         static_assert(update_surface_exists, "updateSurfaceStatus method not found");
         constexpr static bool set_step_size_exists = has_method<const S, void, set_step_size_t, state&, double, ConstrainedStep::Type>;
         static_assert(set_step_size_exists, "setStepSize method not found");

Core/include/Acts/Propagator/StraightLineStepper.hpp

@@ -213,9 +213,10 @@ class StraightLineStepper {
   /// @param surface [in] The surface provided
   /// @param bcheck [in] The boundary check for this status update
   Intersection3D::Status updateSurfaceStatus(
-      State& state, const Surface& surface, const BoundaryCheck& bcheck) const {
+      State& state, const Surface& surface, const BoundaryCheck& bcheck,
+      LoggerWrapper logger = getDummyLogger()) const {
     return detail::updateSingleSurfaceStatus<StraightLineStepper>(
-        *this, state, surface, bcheck);
+        *this, state, surface, bcheck, logger);
   }
 
   /// Update step size

Core/include/Acts/Propagator/detail/SteppingHelper.hpp

@@ -13,6 +13,7 @@
 #include "Acts/Surfaces/BoundaryCheck.hpp"
 #include "Acts/Surfaces/Surface.hpp"
 #include "Acts/Utilities/Intersection.hpp"
+#include "Acts/Utilities/Logger.hpp"
 
 namespace Acts {
 
@@ -31,7 +32,9 @@ namespace detail {
 template <typename stepper_t>
 Acts::Intersection3D::Status updateSingleSurfaceStatus(
     const stepper_t& stepper, typename stepper_t::State& state,
-    const Surface& surface, const BoundaryCheck& bcheck) {
+    const Surface& surface, const BoundaryCheck& bcheck, LoggerWrapper logger) {
+  ACTS_VERBOSE("Update single surface status for surface: " << &surface);
+
   auto sIntersection =
       surface.intersect(state.geoContext, stepper.position(state),
                         state.navDir * stepper.direction(state), bcheck);
@@ -40,26 +43,48 @@ Acts::Intersection3D::Status updateSingleSurfaceStatus(
   if (sIntersection.intersection.status == Intersection3D::Status::onSurface) {
     // Release navigation step size
     state.stepSize.release(ConstrainedStep::actor);
+    ACTS_VERBOSE("Intersection: state is ON SURFACE");
     return Intersection3D::Status::onSurface;
   } else if (sIntersection.intersection or sIntersection.alternative) {
     // Path and overstep limit checking
     double pLimit = state.stepSize.value(ConstrainedStep::aborter);
     double oLimit = stepper.overstepLimit(state);
     auto checkIntersection = [&](const Intersection3D& intersection) -> bool {
       double cLimit = intersection.pathLength;
+      ACTS_VERBOSE(" -> pLimit, oLimit, cLimit: " << pLimit << ", " << oLimit
+                                                  << ", " << cLimit);
       bool accept = (cLimit > oLimit and cLimit * cLimit < pLimit * pLimit);
       if (accept) {
+        ACTS_VERBOSE("Intersection is WITHIN limit");
         stepper.setStepSize(state, state.navDir * cLimit);
       }
+
+      else {
+        ACTS_VERBOSE("Intersection is OUTSIDE limit because: ");
+        if (cLimit <= oLimit) {
+          ACTS_VERBOSE("- intersection path length "
+                       << cLimit << " <= overstep limit " << oLimit);
+        }
+        if (cLimit * cLimit > pLimit * pLimit + s_onSurfaceTolerance) {
+          ACTS_VERBOSE("- intersection path length "
+                       << std::abs(cLimit) << " is over the path limit "
+                       << (std::abs(pLimit) + s_onSurfaceTolerance)
+                       << " (including tolerance of "
+                       << s_curvilinearProjTolerance << ")");
+        }
+      }
+
       return accept;
     };
     // If either of the two intersections are viable return reachable
     if (checkIntersection(sIntersection.intersection) or
         (sIntersection.alternative and
          checkIntersection(sIntersection.alternative))) {
+      ACTS_VERBOSE("Surface is reachable");
       return Intersection3D::Status::reachable;
     }
   }
+  ACTS_VERBOSE("Surface is NOT reachable");
   return Intersection3D::Status::unreachable;
 }
 

Core/src/Geometry/TrackingVolume.cpp

@@ -516,7 +516,18 @@ Acts::TrackingVolume::compatibleBoundaries(
       return BoundaryIntersection(sIntersection.intersection, bSurface,
                                   sIntersection.object);
     } else {
-      ACTS_VERBOSE("Intersection is OUTSIDE limit");
+      ACTS_VERBOSE("Intersection is OUTSIDE limit because: ");
+      if (cLimit <= oLimit) {
+        ACTS_VERBOSE("- intersection path length "
+                     << cLimit << " <= overstep limit " << oLimit);
+      }
+      if (cLimit * cLimit > pLimit * pLimit + s_onSurfaceTolerance) {
+        ACTS_VERBOSE("- intersection path length "
+                     << std::abs(cLimit) << " is over the path limit "
+                     << (std::abs(pLimit) + s_onSurfaceTolerance)
+                     << " (including tolerance of "
+                     << s_curvilinearProjTolerance << ")");
+      }
     }
 
     // Check the alternative
@@ -535,7 +546,18 @@ Acts::TrackingVolume::compatibleBoundaries(
         return BoundaryIntersection(sIntersection.alternative, bSurface,
                                     sIntersection.object);
       } else {
-        ACTS_VERBOSE("Intersection is OUTSIDE limit");
+        ACTS_VERBOSE("Intersection is OUTSIDE limit because: ");
+        if (cLimit <= oLimit) {
+          ACTS_VERBOSE("- intersection path length "
+                       << cLimit << " <= overstep limit " << oLimit);
+        }
+        if (cLimit * cLimit > pLimit * pLimit + s_onSurfaceTolerance) {
+          ACTS_VERBOSE("- intersection path length "
+                       << std::abs(cLimit) << " is over the path limit "
+                       << (std::abs(pLimit) + s_onSurfaceTolerance)
+                       << " (including tolerance of "
+                       << s_curvilinearProjTolerance << ")");
+        }
       }
     } else {
       ACTS_VERBOSE("No alternative for intersection");

Tests/UnitTests/Core/Propagator/NavigatorTests.cpp

@@ -115,11 +115,12 @@ struct PropagatorState {
       return s_onSurfaceTolerance;
     }
 
-    Intersection3D::Status updateSurfaceStatus(
-        State& state, const Surface& surface,
-        const BoundaryCheck& bcheck) const {
+    Intersection3D::Status updateSurfaceStatus(State& state,
+                                               const Surface& surface,
+                                               const BoundaryCheck& bcheck,
+                                               LoggerWrapper logger) const {
       return detail::updateSingleSurfaceStatus<Stepper>(*this, state, surface,
-                                                        bcheck);
+                                                        bcheck, logger);
     }
 
     template <typename object_intersection_t>