Enable device logging (#1179)

Add device and host-device logging functionality to parts of the code where the ACTS logger does not work. This will need a cleanup in the future

Author: niermann999

CMakeLists.txt

@@ -52,6 +52,10 @@ include( traccc-functions )
 set( TRACCC_CUSTOM_SCALARTYPE "float" CACHE STRING
    "Scalar type to use in the TRACCC code" )
 
+# Temporary setting for the traccc device log level, until it can be removed.
+set( TRACCC_DEVICE_LOG_LVL "NONE" CACHE STRING
+   "Log level for traccc and detray device code" )
+
 # Flags controlling which parts of traccc to build.
 option( TRACCC_BUILD_CUDA "Build the CUDA sources included in traccc" FALSE )
 option( TRACCC_BUILD_HIP "Build the HIP sources included in traccc" FALSE)

core/include/traccc/finding/actors/ckf_aborter.hpp

@@ -10,6 +10,7 @@
 // Project include(s)
 #include "traccc/definitions/primitives.hpp"
 #include "traccc/definitions/qualifiers.hpp"
+#include "traccc/utils/logging.hpp"
 
 // detray include(s)
 #include <detray/propagator/base_actor.hpp>
@@ -43,13 +44,18 @@ struct ckf_aborter : detray::actor {
         abrt_state.count++;
         abrt_state.path_from_surface += stepping.step_size();
 
+        TRACCC_VERBOSE_HOST_DEVICE("Checking CKF aborter");
+
         // Stop at the next sensitive surface
         if (navigation.is_on_sensitive() &&
             abrt_state.path_from_surface > abrt_state.min_step_length) {
             prop_state._heartbeat &= navigation.pause();
             abrt_state.success = true;
         }
 
+        TRACCC_VERBOSE_HOST_DEVICE("-> Found sensitive surface: %d",
+                                   navigation.barcode().index());
+
         // Reset path from surface
         if (navigation.is_on_sensitive()) {
             abrt_state.path_from_surface = 0.f;

core/include/traccc/finding/details/combinatorial_kalman_filter.hpp

@@ -63,7 +63,7 @@ combinatorial_kalman_filter(
     const measurement_collection_types::const_view& measurements_view,
     const bound_track_parameters_collection_types::const_view& seeds_view,
     const finding_config& config, vecmem::memory_resource& mr,
-    const Logger& log) {
+    const Logger& /*log*/) {
 
     assert(config.min_step_length_for_next_surface >
                math::fabs(config.propagation.navigation.overstep_tolerance) &&
@@ -77,7 +77,8 @@ combinatorial_kalman_filter(
     using scalar_type = detray::dscalar<algebra_type>;
 
     // Create a logger.
-    auto logger = [&log]() -> const Logger& { return log; };
+    // @TODO: Turn back on, once detray can use the ACTS logger
+    // auto logger = [&log]() -> const Logger& { return log; };
 
     /*****************************************************************
      * Measurement Operations
@@ -144,12 +145,13 @@ combinatorial_kalman_filter(
     for (unsigned int step = 0u; step < config.max_track_candidates_per_track;
          step++) {
 
-        TRACCC_VERBOSE("Starting step "
-                       << step + 1 << " / "
-                       << config.max_track_candidates_per_track);
+        TRACCC_VERBOSE_HOST("Starting step "
+                            << step + 1 << " / "
+                            << config.max_track_candidates_per_track);
 
         // Iterate over input parameters
         const std::size_t n_in_params = in_params.size();
+        TRACCC_VERBOSE_HOST("No. Params: " << n_in_params);
 
         // Terminate if there is no parameter to proceed
         if (n_in_params == 0) {
@@ -199,10 +201,13 @@ combinatorial_kalman_filter(
                      : links[step - 1][param_to_link[step - 1][in_param_id]]
                            .ndf_sum);
 
-            TRACCC_VERBOSE("Processing input parameter "
-                           << in_param_id + 1 << " / " << n_in_params << ": "
-                           << in_param << " (orig_param_id=" << orig_param_id
-                           << ", skip_counter=" << skip_counter << ")");
+            TRACCC_VERBOSE_HOST("Processing input parameter "
+                                << in_param_id + 1 << " / " << n_in_params);
+            TRACCC_VERBOSE_HOST("-> orig_param_id="
+                                << orig_param_id << ", skip_counter="
+                                << skip_counter << "\nVec:\n"
+                                << in_param.vector());
+            TRACCC_DEBUG_HOST("Cov:\n" << in_param.covariance());
 
             /*************************
              * Material interaction
@@ -211,8 +216,8 @@ combinatorial_kalman_filter(
             // Get surface corresponding to bound params
             const detray::tracking_surface sf{det, in_param.surface_link()};
 
-            TRACCC_VERBOSE(
-                "  free params: " << sf.bound_to_free_vector({}, in_param));
+            TRACCC_VERBOSE_HOST(" Free params:\n"
+                                << sf.bound_to_free_vector({}, in_param));
 
             // Apply interactor
             if (sf.has_material()) {
@@ -241,7 +246,10 @@ combinatorial_kalman_filter(
                 best_links;
 
             // Iterate over the measurements
+            TRACCC_VERBOSE_HOST("No. measurements: " << (up - lo));
             for (unsigned int meas_id = lo; meas_id < up; meas_id++) {
+                TRACCC_VERBOSE_HOST("Testing measurement: " << meas_id);
+
                 // The measurement on surface to handle.
                 const measurement& meas = measurements.at(meas_id);
 
@@ -258,9 +266,13 @@ combinatorial_kalman_filter(
 
                 const traccc::scalar chi2 = trk_state.filtered_chi2();
 
+                TRACCC_DEBUG_HOST("KF status: " << fitter_debug_msg{res}());
+
                 // The chi2 from Kalman update should be less than chi2_max
                 if (res == kalman_fitter_status::SUCCESS &&
-                    chi2 < config.chi2_max) {
+                    (chi2 < config.chi2_max)) {
+
+                    TRACCC_VERBOSE_HOST("Found measurement: " << meas_id);
 
                     best_links.push_back(
                         {{.step = step,
@@ -285,9 +297,9 @@ combinatorial_kalman_filter(
             const unsigned int n_branches =
                 std::min(config.max_num_branches_per_surface,
                          static_cast<unsigned int>(best_links.size()));
-            TRACCC_VERBOSE("Found " << n_branches << " branches for step "
-                                    << step << " and input parameter "
-                                    << in_param_id);
+            TRACCC_VERBOSE_HOST("Found " << n_branches << " branches for step "
+                                         << step << " and input parameter "
+                                         << in_param_id + 1);
             for (unsigned int i = 0; i < n_branches; ++i) {
                 const auto& [link, filtered_params] = best_links[i];
 
@@ -296,9 +308,9 @@ combinatorial_kalman_filter(
 
                 // Add the updated parameter to the updated parameters
                 updated_params.push_back(filtered_params);
-                TRACCC_VERBOSE("updated_params["
-                               << updated_params.size() - 1
-                               << "] = " << updated_params.back());
+                TRACCC_DEBUG_HOST("updated_params["
+                                  << updated_params.size() - 1
+                                  << "] = " << updated_params.back());
             }
 
             /*****************************************************************
@@ -319,10 +331,12 @@ combinatorial_kalman_filter(
                      .chi2_sum = prev_chi2_sum,
                      .ndf_sum = prev_ndf_sum});
 
+                TRACCC_VERBOSE_HOST("Hole state created");
+
                 updated_params.push_back(in_param);
-                TRACCC_VERBOSE("updated_params["
-                               << updated_params.size() - 1
-                               << "] = " << updated_params.back());
+                TRACCC_DEBUG_HOST("updated_params["
+                                  << updated_params.size() - 1
+                                  << "] = " << updated_params.back());
             }
         }
 
@@ -439,6 +453,8 @@ combinatorial_kalman_filter(
                         }
 
                         if (this_is_dominated) {
+                            TRACCC_VERBOSE_HOST(
+                                "Track is dead (deduplication)!");
                             param_liveness.at(tracks.at(i)) = 0u;
                             break;
                         }
@@ -466,11 +482,15 @@ combinatorial_kalman_filter(
             // link to be a tip
             if (links.at(step).at(link_id).n_skipped >
                 config.max_num_skipping_per_cand) {
+                TRACCC_WARNING_HOST(
+                    "Create tip: Max no. of holes reached! Bound param:\n"
+                    << updated_params[link_id].vector());
                 tips.push_back({step, link_id});
                 continue;
             }
 
             const auto& param = updated_params[link_id];
+
             // Create propagator state
             typename traccc::details::ckf_propagator_t<
                 detector_t, bfield_t>::state propagation(param, field, det);
@@ -489,15 +509,19 @@ combinatorial_kalman_filter(
                 typename detector_t::algebra_type>::state s3{prop_cfg};
             typename detray::momentum_aborter<scalar_type>::state s4{};
             typename ckf_aborter::state s5;
+
             // Update the actor config
             s4.min_pT(static_cast<scalar_type>(config.min_pT));
             s4.min_p(static_cast<scalar_type>(config.min_p));
             s5.min_step_length = config.min_step_length_for_next_surface;
             s5.max_count = config.max_step_counts_for_next_surface;
 
             // Propagate to the next surface
+            TRACCC_DEBUG_HOST("Propagating... ");
             propagator.propagate(propagation,
                                  detray::tie(s0, s1, s2, s3, s4, s5));
+            TRACCC_DEBUG_HOST("Finished propagation: On surface "
+                              << propagation._navigation.barcode());
 
             // If a surface found, add the parameter for the next
             // step
@@ -511,14 +535,18 @@ combinatorial_kalman_filter(
                 const scalar theta = out_param.theta();
                 if (theta <= 0.f ||
                     theta >= 2.f * constant<traccc::scalar>::pi) {
+                    TRACCC_ERROR_HOST("Theta is hit pole after propagation");
                     valid_track = false;
                 }
 
                 if (!std::isfinite(out_param.phi())) {
+                    TRACCC_ERROR_HOST(
+                        "Phi is infinite after propagation (Matrix inversion)");
                     valid_track = false;
                 }
 
                 if (math::fabs(out_param.qop()) == 0.f) {
+                    TRACCC_ERROR_HOST("q over p is zero after propagation");
                     valid_track = false;
                 }
 
@@ -531,13 +559,19 @@ combinatorial_kalman_filter(
             // tip
             if (!valid_track &&
                 (step >= (config.min_track_candidates_per_track - 1u))) {
+                if (!s5.success) {
+                    TRACCC_VERBOSE_HOST("Create tip: No next sensitive found");
+                } else {
+                    TRACCC_VERBOSE_HOST("Create tip: Encountered error");
+                }
                 tips.push_back({step, link_id});
             }
 
             // If no more CKF step is expected, current candidate is
             // kept as a tip
             if (s5.success &&
                 (step == (config.max_track_candidates_per_track - 1u))) {
+                TRACCC_ERROR_HOST("Create tip: Max no. candidates");
                 tips.push_back({step, link_id});
             }
         }

core/include/traccc/fitting/kalman_filter/gain_matrix_updater.hpp

@@ -14,6 +14,7 @@
 #include "traccc/edm/measurement_helpers.hpp"
 #include "traccc/edm/track_state_collection.hpp"
 #include "traccc/fitting/status_codes.hpp"
+#include "traccc/utils/logging.hpp"
 
 namespace traccc {
 
@@ -62,6 +63,9 @@ struct gain_matrix_updater {
 
         static constexpr unsigned int D = 2;
 
+        TRACCC_VERBOSE_HOST_DEVICE("In gain-matrix-updater...");
+        TRACCC_VERBOSE_HOST_DEVICE("Measurement dim: %d", dim);
+
         assert(dim == 1u || dim == 2u);
 
         assert(!bound_params.is_invalid());
@@ -79,6 +83,8 @@ struct gain_matrix_updater {
 
         assert((dim > 1) || (getter::element(meas_local, 1u, 0u) == 0.f));
 
+        TRACCC_DEBUG_HOST("Predicted param.: " << bound_params);
+
         // Predicted vector of bound track parameters
         const bound_vector_type& predicted_vec = bound_params.vector();
 
@@ -109,6 +115,11 @@ struct gain_matrix_updater {
             getter::element(V, 1u, 1u) = 1.f;
         }
 
+        TRACCC_DEBUG_HOST("Measurement position: " << meas_local);
+        TRACCC_DEBUG_HOST("Measurement variance:\n" << V);
+        TRACCC_DEBUG_HOST("Predicted residual: " << meas_local -
+                                                        H * predicted_vec);
+
         const matrix_type<e_bound_size, D> projected_cov =
             algebra::matrix::transposed_product<false, true>(predicted_cov, H);
 
@@ -118,22 +129,33 @@ struct gain_matrix_updater {
         assert(matrix::determinant(M) != 0.f);
         const matrix_type<6, D> K = projected_cov * matrix::inverse(M);
 
+        TRACCC_DEBUG_HOST("H:\n" << H);
+        TRACCC_DEBUG_HOST("K:\n" << K);
+
         // Calculate the filtered track parameters
         const matrix_type<6, 1> filtered_vec =
             predicted_vec + K * (meas_local - H * predicted_vec);
         const matrix_type<6, 6> filtered_cov = (I66 - K * H) * predicted_cov;
 
+        TRACCC_DEBUG_HOST("Filtered param:\n" << filtered_vec);
+        TRACCC_DEBUG_HOST("Filtered cov:\n" << filtered_cov);
+
         // Return false if track is parallel to z-axis or phi is not finite
         if (!std::isfinite(getter::element(filtered_vec, e_bound_theta, 0))) {
+            TRACCC_ERROR_HOST_DEVICE(
+                "Theta is infinite after filtering (Matrix inversion)");
             return kalman_fitter_status::ERROR_INVERSION;
         }
 
         if (!std::isfinite(getter::element(filtered_vec, e_bound_phi, 0))) {
+            TRACCC_ERROR_HOST_DEVICE(
+                "Phi is infinite after filtering (Matrix inversion)");
             return kalman_fitter_status::ERROR_INVERSION;
         }
 
         if (math::fabs(getter::element(filtered_vec, e_bound_qoverp, 0)) ==
             0.f) {
+            TRACCC_ERROR_HOST_DEVICE("q/p is zero after filtering");
             return kalman_fitter_status::ERROR_QOP_ZERO;
         }
 
@@ -149,11 +171,19 @@ struct gain_matrix_updater {
 
         const scalar chi2_val{getter::element(chi2, 0, 0)};
 
+        TRACCC_VERBOSE_HOST("Filtered residual: " << residual);
+        TRACCC_DEBUG_HOST("R:\n" << R);
+        TRACCC_DEBUG_HOST_DEVICE("det(R): %f", matrix::determinant(R));
+        TRACCC_DEBUG_HOST("R_inv:\n" << matrix::inverse(R));
+        TRACCC_VERBOSE_HOST_DEVICE("Chi2: %f", chi2_val);
+
         if (chi2_val < 0.f) {
+            TRACCC_ERROR_HOST_DEVICE("Chi2 negative");
             return kalman_fitter_status::ERROR_UPDATER_CHI2_NEGATIVE;
         }
 
         if (!std::isfinite(chi2_val)) {
+            TRACCC_ERROR_HOST_DEVICE("Chi2 infinite");
             return kalman_fitter_status::ERROR_UPDATER_CHI2_NOT_FINITE;
         }
 
@@ -167,6 +197,8 @@ struct gain_matrix_updater {
 
         const scalar theta = trk_state.filtered_params().theta();
         if (theta <= 0.f || theta >= 2.f * constant<traccc::scalar>::pi) {
+            TRACCC_ERROR_HOST_DEVICE("Hit theta pole after filtering : %f",
+                                     theta);
             return kalman_fitter_status::ERROR_THETA_POLE;
         }