fix: print exceptions when they happen, and summarize failed collections at the end #1053

wdconinc · 2023-10-05T16:44:04Z

Briefly, what does this PR introduce?

Instead of silently eating the exception, this modifies the JEventProcessorPODIO to print the failed collection and its exception when it first happens, and then prints the failed collections again at the end, all using the error log stream. That results in log streams such as:

[acts_init] [info] DD4Hep geometry converted!
[acts_init] [info] Checking surfaces...
[acts_init] [info] Loading magnetic field...
[acts_init] [info] ActsGeometryProvider initialization complete
[JEventProcessorPODIO] [error] Failed to get CentralTrackSeedingResults due to exception: Object already in a collection. Cannot add it to a second collection
[INFO] Status: 7 events processed  7.0 Hz (0.1 Hz avg)
[INFO] Status: 21 events processed  14.0 Hz (0.4 Hz avg)
[INFO] Status: 33 events processed  12.0 Hz (0.7 Hz avg)
[INFO] Status: 45 events processed  12.0 Hz (0.9 Hz avg)
[INFO] Status: 61 events processed  16.0 Hz (1.2 Hz avg)
[INFO] Status: 70 events processed  9.0 Hz (1.3 Hz avg)
[INFO] Status: 80 events processed  10.0 Hz (1.5 Hz avg)
[INFO] Status: 89 events processed  9.0 Hz (1.6 Hz avg)
[INFO] Status: 98 events processed  9.0 Hz (1.7 Hz avg)
[INFO] Status: 100 events processed  8.8 Hz (1.8 Hz avg)
[INFO] All workers have stopped.
[INFO] Merging threads ...
[JEventProcessorPODIO] [error] Failed to get the following collections at least once:
[JEventProcessorPODIO] [error] Failed collection 'CentralTrackSeedingResults'
[INFO] JArrow: Finalized JEventProcessor 'JEventProcessorPODIO'

(obtained with $PWD/bin/eicrecon -Ppodio:output_include_collections=CentralTrackSeedingResults -Ppodio:output_file=rec_e_1GeV_20GeV_craterlake.edm4eic.root sim_e_1GeV_20GeV_craterlake.edm4hep.root with reverted #1050)

We may be able to go further and not allow any exceptions at all now. I don't think we need that functionality anymore since we now expect algorithms to catch their exceptions and we don't have any unused factories.

What kind of change does this PR introduce?

Bug fix (issue Exception emitted in a JChainFactoryT::Process() gets silently absorbed #1052)
New feature (issue #__)
Documentation update
Other: __

Please check if this PR fulfills the following:

Tests for the changes have been added
Documentation has been added / updated
Changes have been communicated to collaborators

Does this PR introduce breaking changes? What changes might users need to make to their code?

No.

Does this PR change default behavior?

No.

nathanwbrei · 2023-10-05T17:44:12Z

Some thoughts:

Thanks for moving the log messages to the spdlog. I'm tempted to add the option to redirect all JANA-internal logging to spdlog. (This might be a good task for our new hire, Ayan...) It would be nice to have as many messages as possible formatted the same for the sake of searching and filtering them.
I personally wouldn't mind going even further and terminating execution upon encountering an exception. (I honestly thought you or Dmitry had already done this!) It's not all that possible to catch and recover from an exception when stuff is happening asynchronously and on different threads. Maybe we could add an option to terminate on exception simply for the CI.

wdconinc · 2023-10-05T18:13:05Z

Maybe we could add an option to terminate on exception simply for the CI.

I was thinking in this direction as well. Essentially I was going to suggest a boolean parameter allow_failing_collections inside JEventProcessorPODIO that configures whether to fail on exceptions (well, rethrows the exception, and JANA2 should then fail).

wdconinc · 2023-10-05T22:51:15Z

I'm tempted to add the option to redirect all JANA-internal logging to spdlog.

I think it would be interesting to develop an interface where someone can provide a JANA2 compatible logger that is then used for all JANA2 logging (and if not provided it falls back to the current default). We already do something like that with Acts::Logger. For JANA2 my question would be when we pass this to JANA2: we can't exactly wait until we have a Log_service.

wdconinc · 2023-10-06T13:56:44Z

Moved Nathan's comment 2 to separate issue, #1056, to be implemented in different PR.

…ore, use LFHCAL https://github.com/eic/EICrecon/actions/runs/6421965316/job/17439067008?pr=1053#step:5:577 as discovered in #1053

veprbl · 2023-10-09T01:22:14Z

src/services/io/podio/JEventProcessorPODIO.cc

@@ -281,41 +281,47 @@ void JEventProcessorPODIO::Process(const std::shared_ptr<const JEvent> &event) {
    //            that are determined by hash, we have to ensure they are reproducible
    //            even if the collections are filled in unpredictable order (or not at
    //            all). See also below, at "TODO: NWB:".


From CI, it doesn't look like any exceptions are triggered by missing collection id's. So we can delete this, perhaps?

I am certainly open to making it a requirement that factories have to catch exceptions due to missing collections, instead of catching this in the event processor.

I meant something like #1069

veprbl · 2023-10-09T01:23:05Z

src/services/io/podio/JEventProcessorPODIO.h

@@ -32,4 +32,6 @@ class JEventProcessorPODIO : public JEventProcessor {
    std::vector<std::string> m_collections_to_write;  // derived from above config. parameters
    std::vector<std::string> m_collections_to_print;

+  private:
+    std::set<std::string> m_failed_collections;


I've submitted a few PRs for HcalEndcapP. With those merged, we could fail immediately instead of just making warnings.

…FHCAL (#1061) https://github.com/eic/EICrecon/actions/runs/6421965316/job/17439067008?pr=1053#step:5:577 as discovered in #1053 This fixes track propagations.

That detector was removed from the geometry configurations long time ago. cc #1053

…ore, use LFHCAL https://github.com/eic/EICrecon/actions/runs/6421965316/job/17439067008?pr=1053#step:5:577 as discovered in #1053 (cherry picked from commit 373305a)

github-actions · 2023-11-25T17:28:49Z

Capybara summary for PR 1053

wdconinc linked an issue Oct 5, 2023 that may be closed by this pull request

Exception emitted in a JChainFactoryT::Process() gets silently absorbed #1052

Open

wdconinc requested review from veprbl and nathanwbrei October 5, 2023 16:44

wdconinc enabled auto-merge October 5, 2023 17:12

wdconinc temporarily deployed to github-pages October 5, 2023 20:03 — with GitHub Actions Inactive

wdconinc mentioned this pull request Oct 6, 2023

Add JEventProcessorPODIO option to terminate on exception #1056

Closed

nathanwbrei mentioned this pull request Oct 6, 2023

Feature request: JLogger optionally redirects to spdlog JeffersonLab/JANA2#250

Open

veprbl added a commit that referenced this pull request Oct 9, 2023

TrackPropagation_factory: HcalEndcapN is not defined in geometry anym…

373305a

…ore, use LFHCAL https://github.com/eic/EICrecon/actions/runs/6421965316/job/17439067008?pr=1053#step:5:577 as discovered in #1053

This was referenced Oct 9, 2023

TrackPropagation_factory: HcalEndcapN_* is not defined anymore, use LFHCAL #1061

Merged

Remove factories for HcalEndcapP #1062

Merged

veprbl reviewed Oct 9, 2023

View reviewed changes

github-merge-queue bot pushed a commit that referenced this pull request Oct 9, 2023

Remove factories for HcalEndcapP (#1062)

a7665de

That detector was removed from the geometry configurations long time ago. cc #1053

veprbl temporarily deployed to github-pages October 11, 2023 05:54 — with GitHub Actions Inactive

veprbl mentioned this pull request Oct 11, 2023

JEventProcessorPODIO: treat all unhandled exceptions as fatal #1069

Open

wdconinc added 3 commits November 25, 2023 10:20

fix: print thrown exceptions, keep track of failed collections

eb15f93

feat: print any failed collections again at end of run

1181711

feat: switch from JANA2 LOG to spdlog for printed collections

f4f5741

wdconinc force-pushed the 1052-exception-emitted-in-a-jchainfactorytprocess-gets-silently-absorbed branch from b1f956b to f4f5741 Compare November 25, 2023 16:20

wdconinc temporarily deployed to github-pages November 25, 2023 18:30 — with GitHub Actions Inactive

auto-merge was automatically disabled April 20, 2024 00:14
Merge queue setting changed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

fix: print exceptions when they happen, and summarize failed collections at the end #1053

fix: print exceptions when they happen, and summarize failed collections at the end #1053

wdconinc commented Oct 5, 2023 •

edited

Loading

nathanwbrei commented Oct 5, 2023

wdconinc commented Oct 5, 2023

wdconinc commented Oct 5, 2023

wdconinc commented Oct 6, 2023 •

edited

Loading

veprbl Oct 9, 2023

wdconinc Oct 9, 2023

veprbl Oct 11, 2023

veprbl Oct 9, 2023

github-actions bot commented Nov 25, 2023

fix: print exceptions when they happen, and summarize failed collections at the end #1053

Are you sure you want to change the base?

fix: print exceptions when they happen, and summarize failed collections at the end #1053

Conversation

wdconinc commented Oct 5, 2023 • edited Loading

Briefly, what does this PR introduce?

What kind of change does this PR introduce?

Please check if this PR fulfills the following:

Does this PR introduce breaking changes? What changes might users need to make to their code?

Does this PR change default behavior?

nathanwbrei commented Oct 5, 2023

wdconinc commented Oct 5, 2023

wdconinc commented Oct 5, 2023

wdconinc commented Oct 6, 2023 • edited Loading

veprbl Oct 9, 2023

Choose a reason for hiding this comment

wdconinc Oct 9, 2023

Choose a reason for hiding this comment

veprbl Oct 11, 2023

Choose a reason for hiding this comment

veprbl Oct 9, 2023

Choose a reason for hiding this comment

github-actions bot commented Nov 25, 2023

Capybara summary for PR 1053

wdconinc commented Oct 5, 2023 •

edited

Loading

wdconinc commented Oct 6, 2023 •

edited

Loading