Bug #9363
Cannot read multiple events from file produced by aggregating several files in art v1_14_03, nu release v1_13_00
Occurs In:
Scope:
Internal
Experiment:
LArSoft
SSI Package:
art
Description
The LArIAT raw data files produced by artdaq each contain a single event. The files from the same run have a common run number and the subrun number is the same as the event number.
A file created from a job that reads the artdaq fragments from multiple files and then creates a single file containing LArSoft data products can be found at
/afs/fnal.gov/files/home/room1/brebel/lar/lariat/develop/standard_reco.root
When the file is viewed with the larsoft event display the following error is produced when attempting to advance past the first event in the file:
evd [0] lar: /scratch/workspace/nu-release-build/v1_13_00/s12-e7/debug/build/art/v1_14_03/src/art/Framework/Core/DecrepitRelicInputSourceImplementation.cc:304: std::vector<std::shared_ptr<art::SubRunPrincipal> > art::DecrepitRelicInputSourceImplementation::readSubRunFromSecondaryFiles(std::shared_ptr<art::RunPrincipal>): Assertion `state_ == input::IsSubRun' failed.
Instructions for checking out and building the LArIAT code (which depends on larsoft) can be found at
https://cdcvs.fnal.gov/redmine/projects/lardbt/wiki/Setting_up_the_Offline_Software
The develop branch of the repository builds version v01_05_02 of lariatsoft. The following command runs the event display
lar -c evd_lariat.fcl standard_reco.root
Running
lar -c eventdump.fcl standard_reco.root
does not trigger the problem, but I am not sure it would/should.
Associated revisions
Merge tag 'v1_15_01'
Tag for release with fix for issue #9363.
History
#1 Updated by Christopher Green about 4 years ago
- Status changed from New to Feedback
Are you able run Tracer so we can see event IDs of each event as they are being dumped? Ditto for the files from which this file was made? A preliminary check of the file structure suggests that the event ID's are all identical: 6099 / 0 / 0. The latter 0 makes no sense, as that is the invalid ID, so I'm hoping I did something wrong with the diagnostics.
Please also attach the .fcl files (original or via one of art's command-line options to dump the post-processed configuration) used to generate the files at every stage of the process.
#2 Updated by Brian Rebel about 4 years ago
- File standard_fragmenttodigit.fcl standard_fragmenttodigit.fcl added
- File evd_lariat.fcl evd_lariat.fcl added
Here is the output when running the event dump with the Tracer:
-bash-4.1$ lar -c eventdump.fcl --trace standard_reco.root %MSG-i MF_INIT_OK: lar 06-Jul-2015 10:27:52 CDT JobSetup Messagelogger initialization complete. %MSG 06-Jul-2015 10:27:54 CDT Initiating request to open file standard_reco.root 06-Jul-2015 10:27:55 CDT Successfully opened file standard_reco.root ++ constructing module:out1 ++ construction finished:out1 ++ beginJob module:out1 ++ beginJob finished:out1 ++ Job started ++++open input file ++++finished: open input file standard_reco.root ++++opened output file from out1 ++++source run ++++finished: source run ++++ processing begin run:run: 6099 time:1434052338 ++++++ processing path for begin run:end_path ++++++++ module for begin run:out1 ++++++++ finished for begin run:out1 ++++++ finished path for begin run: ++++ finished begin run: ++++source subRun ++++finished: source subRun ++++ processing begin subRun:run: 6099 subRun: 606 time:1434088847 ++++++ processing path for begin subRun:end_path ++++++++ module for begin subRun:out1 ++++++++ finished for begin subRun:out1 ++++++ finished path for begin subRun: ++++ finished begin subRun: ++++source event ++++finished: source event Begin processing the 1st record. run: 6099 subRun: 606 event: 606 at 06-Jul-2015 10:27:55 CDT ++++ processing event:run: 6099 subRun: 606 event: 606 time:1434088847 ++++++ processing path for event:end_path ++++++++ module for event:out1 PROCESS NAME.. | MODULE LABEL... | PRODUCT INSTANCE NAME | DATA PRODUCT TYPE............................. | SIZE LariatProducer | FragmentToDigit | ..................... | art::Assns<raw::Trigger,raw::OpDetPulse,void>. | ...8 LariatProducer | FragmentToDigit | ..................... | art::Assns<raw::Trigger,raw::RawDigit,void>... | 1920 LariatProducer | FragmentToDigit | ..................... | art::Assns<raw::Trigger,raw::AuxDetDigit,void> | .204 LariatProducer | FragmentToDigit | ..................... | std::vector<raw::OpDetPulse>.................. | ...8 LariatProducer | FragmentToDigit | ..................... | std::vector<raw::Trigger>..................... | ...5 DAQ........... | daq............ | unidentified......... | std::vector<artdaq::Fragment>................. | ...? LariatProducer | TriggerResults. | ..................... | art::TriggerResults........................... | ...- DAQ........... | daq............ | SPILL................ | std::vector<artdaq::Fragment>................. | ...1 DAQAG......... | TriggerResults. | ..................... | art::TriggerResults........................... | ...- LariatProducer | FragmentToDigit | ..................... | std::vector<raw::AuxDetDigit>................. | .204 LariatProducer | FragmentToDigit | ..................... | std::vector<raw::RawDigit>.................... | 1920 Total products (present, not present): 11 (10, 1). ++++++++ finished for event:out1 ++++++ finished path for event: ++++ finished event: ++++ processing end subRun:run: 6099 subRun: 606 time:1434088847 ++++++ processing path for end subRun:end_path ++++++++ module for end subRun:out1 ++++++++ finished for end subRun:out1 ++++++ finished path for end subRun: ++++ finished end subRun: ++++source subRun ++++finished: source subRun ++++ processing begin subRun:run: 6099 subRun: 607 time:1434088907 ++++++ processing path for begin subRun:end_path ++++++++ module for begin subRun:out1 ++++++++ finished for begin subRun:out1 ++++++ finished path for begin subRun: ++++ finished begin subRun: ++++source event Begin processing the 2nd record. run: 6099 subRun: 607 event: 607 at 06-Jul-2015 10:27:55 CDT ++++finished: source event ++++ processing event:run: 6099 subRun: 607 event: 607 time:1434088907 ++++++ processing path for event:end_path ++++++++ module for event:out1 PROCESS NAME.. | MODULE LABEL... | PRODUCT INSTANCE NAME | DATA PRODUCT TYPE............................. | SIZE LariatProducer | FragmentToDigit | ..................... | art::Assns<raw::Trigger,raw::OpDetPulse,void>. | ...8 LariatProducer | FragmentToDigit | ..................... | art::Assns<raw::Trigger,raw::RawDigit,void>... | 1920 LariatProducer | FragmentToDigit | ..................... | art::Assns<raw::Trigger,raw::AuxDetDigit,void> | .542 LariatProducer | FragmentToDigit | ..................... | std::vector<raw::OpDetPulse>.................. | ...8 LariatProducer | FragmentToDigit | ..................... | std::vector<raw::Trigger>..................... | ...5 DAQ........... | daq............ | unidentified......... | std::vector<artdaq::Fragment>................. | ...? LariatProducer | TriggerResults. | ..................... | art::TriggerResults........................... | ...- DAQ........... | daq............ | SPILL................ | std::vector<artdaq::Fragment>................. | ...1 DAQAG......... | TriggerResults. | ..................... | art::TriggerResults........................... | ...- LariatProducer | FragmentToDigit | ..................... | std::vector<raw::AuxDetDigit>................. | .542 LariatProducer | FragmentToDigit | ..................... | std::vector<raw::RawDigit>.................... | 1920 Total products (present, not present): 11 (10, 1). ++++++++ finished for event:out1 ++++++ finished path for event: ++++ finished event: ++++ processing end subRun:run: 6099 subRun: 607 time:1434088907 ++++++ processing path for end subRun:end_path ++++++++ module for end subRun:out1 ++++++++ finished for end subRun:out1 ++++++ finished path for end subRun: ++++ finished end subRun: ++++source subRun ++++finished: source subRun ++++ processing begin subRun:run: 6099 subRun: 608 time:1434088967 ++++++ processing path for begin subRun:end_path ++++++++ module for begin subRun:out1 ++++++++ finished for begin subRun:out1 ++++++ finished path for begin subRun: ++++ finished begin subRun: ++++source event Begin processing the 3rd record. run: 6099 subRun: 608 event: 608 at 06-Jul-2015 10:27:56 CDT ++++finished: source event ++++ processing event:run: 6099 subRun: 608 event: 608 time:1434088967 ++++++ processing path for event:end_path ++++++++ module for event:out1 PROCESS NAME.. | MODULE LABEL... | PRODUCT INSTANCE NAME | DATA PRODUCT TYPE............................. | SIZE LariatProducer | FragmentToDigit | ..................... | art::Assns<raw::Trigger,raw::OpDetPulse,void>. | ...6 LariatProducer | FragmentToDigit | ..................... | art::Assns<raw::Trigger,raw::RawDigit,void>... | .960 LariatProducer | FragmentToDigit | ..................... | art::Assns<raw::Trigger,raw::AuxDetDigit,void> | .103 LariatProducer | FragmentToDigit | ..................... | std::vector<raw::OpDetPulse>.................. | ...6 LariatProducer | FragmentToDigit | ..................... | std::vector<raw::Trigger>..................... | ...6 DAQ........... | daq............ | unidentified......... | std::vector<artdaq::Fragment>................. | ...? LariatProducer | TriggerResults. | ..................... | art::TriggerResults........................... | ...- DAQ........... | daq............ | SPILL................ | std::vector<artdaq::Fragment>................. | ...1 DAQAG......... | TriggerResults. | ..................... | art::TriggerResults........................... | ...- LariatProducer | FragmentToDigit | ..................... | std::vector<raw::AuxDetDigit>................. | .103 LariatProducer | FragmentToDigit | ..................... | std::vector<raw::RawDigit>.................... | .960 Total products (present, not present): 11 (10, 1). ++++++++ finished for event:out1 ++++++ finished path for event: ++++ finished event: ++++ processing end subRun:run: 6099 subRun: 608 time:1434088967 ++++++ processing path for end subRun:end_path ++++++++ module for end subRun:out1 ++++++++ finished for end subRun:out1 ++++++ finished path for end subRun: ++++ finished end subRun: ++++source subRun ++++finished: source subRun ++++ processing begin subRun:run: 6099 subRun: 609 time:1434089028 ++++++ processing path for begin subRun:end_path ++++++++ module for begin subRun:out1 ++++++++ finished for begin subRun:out1 ++++++ finished path for begin subRun: ++++ finished begin subRun: ++++source event Begin processing the 4th record. run: 6099 subRun: 609 event: 609 at 06-Jul-2015 10:27:56 CDT ++++finished: source event ++++ processing event:run: 6099 subRun: 609 event: 609 time:1434089028 ++++++ processing path for event:end_path ++++++++ module for event:out1 PROCESS NAME.. | MODULE LABEL... | PRODUCT INSTANCE NAME | DATA PRODUCT TYPE............................. | SIZE LariatProducer | FragmentToDigit | ..................... | art::Assns<raw::Trigger,raw::OpDetPulse,void>. | ...4 LariatProducer | FragmentToDigit | ..................... | art::Assns<raw::Trigger,raw::RawDigit,void>... | .960 LariatProducer | FragmentToDigit | ..................... | art::Assns<raw::Trigger,raw::AuxDetDigit,void> | ..84 LariatProducer | FragmentToDigit | ..................... | std::vector<raw::OpDetPulse>.................. | ...4 LariatProducer | FragmentToDigit | ..................... | std::vector<raw::Trigger>..................... | ...4 DAQ........... | daq............ | unidentified......... | std::vector<artdaq::Fragment>................. | ...? LariatProducer | TriggerResults. | ..................... | art::TriggerResults........................... | ...- DAQ........... | daq............ | SPILL................ | std::vector<artdaq::Fragment>................. | ...1 DAQAG......... | TriggerResults. | ..................... | art::TriggerResults........................... | ...- LariatProducer | FragmentToDigit | ..................... | std::vector<raw::AuxDetDigit>................. | ..84 LariatProducer | FragmentToDigit | ..................... | std::vector<raw::RawDigit>.................... | .960 Total products (present, not present): 11 (10, 1). ++++++++ finished for event:out1 ++++++ finished path for event: ++++ finished event: ++++ processing end subRun:run: 6099 subRun: 609 time:1434089028 ++++++ processing path for end subRun:end_path ++++++++ module for end subRun:out1 ++++++++ finished for end subRun:out1 ++++++ finished path for end subRun: ++++ finished end subRun: ++++source subRun ++++finished: source subRun ++++ processing begin subRun:run: 6099 subRun: 625 time:1434089991 ++++++ processing path for begin subRun:end_path ++++++++ module for begin subRun:out1 ++++++++ finished for begin subRun:out1 ++++++ finished path for begin subRun: ++++ finished begin subRun: ++++source event Begin processing the 5th record. run: 6099 subRun: 625 event: 625 at 06-Jul-2015 10:27:56 CDT ++++finished: source event ++++ processing event:run: 6099 subRun: 625 event: 625 time:1434089991 ++++++ processing path for event:end_path ++++++++ module for event:out1 PROCESS NAME.. | MODULE LABEL... | PRODUCT INSTANCE NAME | DATA PRODUCT TYPE............................. | SIZE LariatProducer | FragmentToDigit | ..................... | art::Assns<raw::Trigger,raw::OpDetPulse,void>. | ..18 LariatProducer | FragmentToDigit | ..................... | art::Assns<raw::Trigger,raw::RawDigit,void>... | 3840 LariatProducer | FragmentToDigit | ..................... | art::Assns<raw::Trigger,raw::AuxDetDigit,void> | .408 LariatProducer | FragmentToDigit | ..................... | std::vector<raw::OpDetPulse>.................. | ..18 LariatProducer | FragmentToDigit | ..................... | std::vector<raw::Trigger>..................... | ..11 DAQ........... | daq............ | unidentified......... | std::vector<artdaq::Fragment>................. | ...? LariatProducer | TriggerResults. | ..................... | art::TriggerResults........................... | ...- DAQ........... | daq............ | SPILL................ | std::vector<artdaq::Fragment>................. | ...1 DAQAG......... | TriggerResults. | ..................... | art::TriggerResults........................... | ...- LariatProducer | FragmentToDigit | ..................... | std::vector<raw::AuxDetDigit>................. | .408 LariatProducer | FragmentToDigit | ..................... | std::vector<raw::RawDigit>.................... | 3840 Total products (present, not present): 11 (10, 1). ++++++++ finished for event:out1 ++++++ finished path for event: ++++ finished event: ++++ processing end subRun:run: 6099 subRun: 625 time:1434089991 ++++++ processing path for end subRun:end_path ++++++++ module for end subRun:out1 ++++++++ finished for end subRun:out1 ++++++ finished path for end subRun: ++++ finished end subRun: ++++source subRun ++++finished: source subRun ++++ processing begin subRun:run: 6099 subRun: 626 time:1434090051 ++++++ processing path for begin subRun:end_path ++++++++ module for begin subRun:out1 ++++++++ finished for begin subRun:out1 ++++++ finished path for begin subRun: ++++ finished begin subRun: ++++source event Begin processing the 6th record. run: 6099 subRun: 626 event: 626 at 06-Jul-2015 10:27:58 CDT ++++finished: source event ++++ processing event:run: 6099 subRun: 626 event: 626 time:1434090051 ++++++ processing path for event:end_path ++++++++ module for event:out1 PROCESS NAME.. | MODULE LABEL... | PRODUCT INSTANCE NAME | DATA PRODUCT TYPE............................. | SIZE LariatProducer | FragmentToDigit | ..................... | art::Assns<raw::Trigger,raw::OpDetPulse,void>. | ...4 LariatProducer | FragmentToDigit | ..................... | art::Assns<raw::Trigger,raw::RawDigit,void>... | .960 LariatProducer | FragmentToDigit | ..................... | art::Assns<raw::Trigger,raw::AuxDetDigit,void> | ..84 LariatProducer | FragmentToDigit | ..................... | std::vector<raw::OpDetPulse>.................. | ...4 LariatProducer | FragmentToDigit | ..................... | std::vector<raw::Trigger>..................... | ...3 DAQ........... | daq............ | unidentified......... | std::vector<artdaq::Fragment>................. | ...? LariatProducer | TriggerResults. | ..................... | art::TriggerResults........................... | ...- DAQ........... | daq............ | SPILL................ | std::vector<artdaq::Fragment>................. | ...1 DAQAG......... | TriggerResults. | ..................... | art::TriggerResults........................... | ...- LariatProducer | FragmentToDigit | ..................... | std::vector<raw::AuxDetDigit>................. | ..84 LariatProducer | FragmentToDigit | ..................... | std::vector<raw::RawDigit>.................... | .960 Total products (present, not present): 11 (10, 1). ++++++++ finished for event:out1 ++++++ finished path for event: ++++ finished event: ++++ processing end subRun:run: 6099 subRun: 626 time:1434090051 ++++++ processing path for end subRun:end_path ++++++++ module for end subRun:out1 ++++++++ finished for end subRun:out1 ++++++ finished path for end subRun: ++++ finished end subRun: ++++source subRun ++++finished: source subRun ++++ processing begin subRun:run: 6099 subRun: 627 time:1434090111 ++++++ processing path for begin subRun:end_path ++++++++ module for begin subRun:out1 ++++++++ finished for begin subRun:out1 ++++++ finished path for begin subRun: ++++ finished begin subRun: ++++source event Begin processing the 7th record. run: 6099 subRun: 627 event: 627 at 06-Jul-2015 10:27:58 CDT ++++finished: source event ++++ processing event:run: 6099 subRun: 627 event: 627 time:1434090111 ++++++ processing path for event:end_path ++++++++ module for event:out1 PROCESS NAME.. | MODULE LABEL... | PRODUCT INSTANCE NAME | DATA PRODUCT TYPE............................. | SIZE LariatProducer | FragmentToDigit | ..................... | art::Assns<raw::Trigger,raw::OpDetPulse,void>. | ...2 LariatProducer | FragmentToDigit | ..................... | art::Assns<raw::Trigger,raw::RawDigit,void>... | .480 LariatProducer | FragmentToDigit | ..................... | art::Assns<raw::Trigger,raw::AuxDetDigit,void> | ..42 LariatProducer | FragmentToDigit | ..................... | std::vector<raw::OpDetPulse>.................. | ...2 LariatProducer | FragmentToDigit | ..................... | std::vector<raw::Trigger>..................... | ...4 DAQ........... | daq............ | unidentified......... | std::vector<artdaq::Fragment>................. | ...? LariatProducer | TriggerResults. | ..................... | art::TriggerResults........................... | ...- DAQ........... | daq............ | SPILL................ | std::vector<artdaq::Fragment>................. | ...1 DAQAG......... | TriggerResults. | ..................... | art::TriggerResults........................... | ...- LariatProducer | FragmentToDigit | ..................... | std::vector<raw::AuxDetDigit>................. | ..42 LariatProducer | FragmentToDigit | ..................... | std::vector<raw::RawDigit>.................... | .480 Total products (present, not present): 11 (10, 1). ++++++++ finished for event:out1 ++++++ finished path for event: ++++ finished event: ++++ processing end subRun:run: 6099 subRun: 627 time:1434090111 ++++++ processing path for end subRun:end_path ++++++++ module for end subRun:out1 ++++++++ finished for end subRun:out1 ++++++ finished path for end subRun: ++++ finished end subRun: ++++source subRun ++++finished: source subRun ++++ processing begin subRun:run: 6099 subRun: 628 time:1434090171 ++++++ processing path for begin subRun:end_path ++++++++ module for begin subRun:out1 ++++++++ finished for begin subRun:out1 ++++++ finished path for begin subRun: ++++ finished begin subRun: ++++source event Begin processing the 8th record. run: 6099 subRun: 628 event: 628 at 06-Jul-2015 10:27:58 CDT ++++finished: source event ++++ processing event:run: 6099 subRun: 628 event: 628 time:1434090171 ++++++ processing path for event:end_path ++++++++ module for event:out1 PROCESS NAME.. | MODULE LABEL... | PRODUCT INSTANCE NAME | DATA PRODUCT TYPE............................. | SIZE LariatProducer | FragmentToDigit | ..................... | art::Assns<raw::Trigger,raw::OpDetPulse,void>. | ...0 LariatProducer | FragmentToDigit | ..................... | art::Assns<raw::Trigger,raw::RawDigit,void>... | ...0 LariatProducer | FragmentToDigit | ..................... | art::Assns<raw::Trigger,raw::AuxDetDigit,void> | ...0 LariatProducer | FragmentToDigit | ..................... | std::vector<raw::OpDetPulse>.................. | ...0 LariatProducer | FragmentToDigit | ..................... | std::vector<raw::Trigger>..................... | ...2 DAQ........... | daq............ | unidentified......... | std::vector<artdaq::Fragment>................. | ...? LariatProducer | TriggerResults. | ..................... | art::TriggerResults........................... | ...- DAQ........... | daq............ | SPILL................ | std::vector<artdaq::Fragment>................. | ...1 DAQAG......... | TriggerResults. | ..................... | art::TriggerResults........................... | ...- LariatProducer | FragmentToDigit | ..................... | std::vector<raw::AuxDetDigit>................. | ...0 LariatProducer | FragmentToDigit | ..................... | std::vector<raw::RawDigit>.................... | ...0 Total products (present, not present): 11 (10, 1). ++++++++ finished for event:out1 ++++++ finished path for event: ++++ finished event: ++++ processing end subRun:run: 6099 subRun: 628 time:1434090171 ++++++ processing path for end subRun:end_path ++++++++ module for end subRun:out1 ++++++++ finished for end subRun:out1 ++++++ finished path for end subRun: ++++ finished end subRun: ++++source subRun ++++finished: source subRun ++++ processing begin subRun:run: 6099 subRun: 629 time:1434090232 ++++++ processing path for begin subRun:end_path ++++++++ module for begin subRun:out1 ++++++++ finished for begin subRun:out1 ++++++ finished path for begin subRun: ++++ finished begin subRun: ++++source event Begin processing the 9th record. run: 6099 subRun: 629 event: 629 at 06-Jul-2015 10:27:58 CDT ++++finished: source event ++++ processing event:run: 6099 subRun: 629 event: 629 time:1434090232 ++++++ processing path for event:end_path ++++++++ module for event:out1 PROCESS NAME.. | MODULE LABEL... | PRODUCT INSTANCE NAME | DATA PRODUCT TYPE............................. | SIZE LariatProducer | FragmentToDigit | ..................... | art::Assns<raw::Trigger,raw::OpDetPulse,void>. | ..12 LariatProducer | FragmentToDigit | ..................... | art::Assns<raw::Trigger,raw::RawDigit,void>... | 2400 LariatProducer | FragmentToDigit | ..................... | art::Assns<raw::Trigger,raw::AuxDetDigit,void> | .307 LariatProducer | FragmentToDigit | ..................... | std::vector<raw::OpDetPulse>.................. | ..12 LariatProducer | FragmentToDigit | ..................... | std::vector<raw::Trigger>..................... | ...7 DAQ........... | daq............ | unidentified......... | std::vector<artdaq::Fragment>................. | ...? LariatProducer | TriggerResults. | ..................... | art::TriggerResults........................... | ...- DAQ........... | daq............ | SPILL................ | std::vector<artdaq::Fragment>................. | ...1 DAQAG......... | TriggerResults. | ..................... | art::TriggerResults........................... | ...- LariatProducer | FragmentToDigit | ..................... | std::vector<raw::AuxDetDigit>................. | .307 LariatProducer | FragmentToDigit | ..................... | std::vector<raw::RawDigit>.................... | 2400 Total products (present, not present): 11 (10, 1). ++++++++ finished for event:out1 ++++++ finished path for event: ++++ finished event: ++++ processing end subRun:run: 6099 subRun: 629 time:1434090232 ++++++ processing path for end subRun:end_path ++++++++ module for end subRun:out1 ++++++++ finished for end subRun:out1 ++++++ finished path for end subRun: ++++ finished end subRun: ++++source subRun ++++finished: source subRun ++++ processing begin subRun:run: 6099 subRun: 630 time:1434090292 ++++++ processing path for begin subRun:end_path ++++++++ module for begin subRun:out1 ++++++++ finished for begin subRun:out1 ++++++ finished path for begin subRun: ++++ finished begin subRun: ++++source event Begin processing the 10th record. run: 6099 subRun: 630 event: 630 at 06-Jul-2015 10:27:59 CDT ++++finished: source event ++++ processing event:run: 6099 subRun: 630 event: 630 time:1434090292 ++++++ processing path for event:end_path ++++++++ module for event:out1 PROCESS NAME.. | MODULE LABEL... | PRODUCT INSTANCE NAME | DATA PRODUCT TYPE............................. | SIZE LariatProducer | FragmentToDigit | ..................... | art::Assns<raw::Trigger,raw::OpDetPulse,void>. | ...2 LariatProducer | FragmentToDigit | ..................... | art::Assns<raw::Trigger,raw::RawDigit,void>... | .480 LariatProducer | FragmentToDigit | ..................... | art::Assns<raw::Trigger,raw::AuxDetDigit,void> | ..42 LariatProducer | FragmentToDigit | ..................... | std::vector<raw::OpDetPulse>.................. | ...2 LariatProducer | FragmentToDigit | ..................... | std::vector<raw::Trigger>..................... | ...4 DAQ........... | daq............ | unidentified......... | std::vector<artdaq::Fragment>................. | ...? LariatProducer | TriggerResults. | ..................... | art::TriggerResults........................... | ...- DAQ........... | daq............ | SPILL................ | std::vector<artdaq::Fragment>................. | ...1 DAQAG......... | TriggerResults. | ..................... | art::TriggerResults........................... | ...- LariatProducer | FragmentToDigit | ..................... | std::vector<raw::AuxDetDigit>................. | ..42 LariatProducer | FragmentToDigit | ..................... | std::vector<raw::RawDigit>.................... | .480 Total products (present, not present): 11 (10, 1). ++++++++ finished for event:out1 ++++++ finished path for event: ++++ finished event: ++++ processing end subRun:run: 6099 subRun: 630 time:1434090292 ++++++ processing path for end subRun:end_path ++++++++ module for end subRun:out1 ++++++++ finished for end subRun:out1 ++++++ finished path for end subRun: ++++ finished end subRun: ++++ processing end run:run: 6099 time:1434090292 ++++++ processing path for end run:end_path ++++++++ module for end run:out1 ++++++++ finished for end run:out1 ++++++ finished path for end run: ++++ finished end run: PROCESS NAME.. | MODULE LABEL......... | PRODUCT INSTANCE NAME | DATA PRODUCT TYPE.................... | SIZE DAQAG......... | lariatOnlineBuildInfo | LariatOnlineBuildInfo | std::vector<artdaq::PackageBuildInfo> | ...3 LariatProducer | FragmentToDigit...... | ..................... | sumdata::RunData..................... | ...- Total products (present, not present): 2 (2, 0). ++++close output file from out1 ++++finished close output file <none> from out1 ++++close input file 06-Jul-2015 10:27:59 CDT Closed file standard_reco.root ++++finished: close input file ++ endJob module:out1 ++ endJob finished:out1 TrigReport ---------- Event Summary ------------ TrigReport Events total = 10 passed = 10 failed = 0 TrigReport ------ Modules in End-Path: end_path ------------ TrigReport Trig Bit# Visited Passed Failed Error Name TrigReport 0 0 10 10 0 0 out1 TimeReport ---------- Time Summary ---[sec]---- TimeReport CPU = 4.058186 Real = 4.054382 ++ Job ended Art has completed and will exit with status 0.
The process used to create the file was
lar -c standard_fragmenttodigit.fcl /pnfs/lariat/pnfs/fnal.gov/usr/lariat/raw/000/541/lariat_r006099_sr0* -n 10
I run the event dump.fcl along with --trace on the input files, I see
-bash-4.1$ lar -c eventdump.fcl --trace /pnfs/lariat/pnfs/fnal.gov/usr/lariat/raw/000/541/lariat_r006099_sr0* -n 10 %MSG-i MF_INIT_OK: lar 06-Jul-2015 10:33:39 CDT JobSetup Messagelogger initialization complete. %MSG 06-Jul-2015 10:33:41 CDT Initiating request to open file /pnfs/lariat/pnfs/fnal.gov/usr/lariat/raw/000/541/lariat_r006099_sr0606.root 06-Jul-2015 10:33:41 CDT Successfully opened file /pnfs/lariat/pnfs/fnal.gov/usr/lariat/raw/000/541/lariat_r006099_sr0606.root ++ constructing module:out1 ++ construction finished:out1 ++ beginJob module:out1 ++ beginJob finished:out1 ++ Job started ++++open input file ++++finished: open input file /pnfs/lariat/pnfs/fnal.gov/usr/lariat/raw/000/541/lariat_r006099_sr0606.root ++++opened output file from out1 ++++source run ++++finished: source run ++++ processing begin run:run: 6099 time:1434052338 ++++++ processing path for begin run:end_path ++++++++ module for begin run:out1 ++++++++ finished for begin run:out1 ++++++ finished path for begin run: ++++ finished begin run: ++++source subRun ++++finished: source subRun ++++ processing begin subRun:run: 6099 subRun: 606 time:1434088847 ++++++ processing path for begin subRun:end_path ++++++++ module for begin subRun:out1 ++++++++ finished for begin subRun:out1 ++++++ finished path for begin subRun: ++++ finished begin subRun: ++++source event ++++finished: source event Begin processing the 1st record. run: 6099 subRun: 606 event: 606 at 06-Jul-2015 10:33:42 CDT ++++ processing event:run: 6099 subRun: 606 event: 606 time:1434088847 ++++++ processing path for event:end_path ++++++++ module for event:out1 PROCESS NAME | MODULE LABEL.. | PRODUCT INSTANCE NAME | DATA PRODUCT TYPE............ | SIZE DAQ......... | daq........... | unidentified......... | std::vector<artdaq::Fragment> | ...? DAQ......... | daq........... | SPILL................ | std::vector<artdaq::Fragment> | ...1 DAQAG....... | TriggerResults | ..................... | art::TriggerResults.......... | ...- Total products (present, not present): 3 (2, 1). ++++++++ finished for event:out1 ++++++ finished path for event: ++++ finished event: ++++close input file 06-Jul-2015 10:33:42 CDT Closed file /pnfs/lariat/pnfs/fnal.gov/usr/lariat/raw/000/541/lariat_r006099_sr0606.root ++++finished: close input file ++++open input file 06-Jul-2015 10:33:42 CDT Initiating request to open file /pnfs/lariat/pnfs/fnal.gov/usr/lariat/raw/000/541/lariat_r006099_sr0607.root 06-Jul-2015 10:33:42 CDT Successfully opened file /pnfs/lariat/pnfs/fnal.gov/usr/lariat/raw/000/541/lariat_r006099_sr0607.root ++++finished: open input file /pnfs/lariat/pnfs/fnal.gov/usr/lariat/raw/000/541/lariat_r006099_sr0607.root ++++source run %MSG-w RunMerging: SourceRun 06-Jul-2015 10:33:42 CDT PostProcessEvent Problem found while adding product provenance, product already exists for (artdaq::PackageBuildInfos,lariatOnlineBuildInfo,LariatOnlineBuildInfo,DAQAG) %MSG ++++finished: source run ++++ processing end subRun:run: 6099 subRun: 606 time:1434088847 ++++++ processing path for end subRun:end_path ++++++++ module for end subRun:out1 ++++++++ finished for end subRun:out1 ++++++ finished path for end subRun: ++++ finished end subRun: ++++source subRun ++++finished: source subRun ++++ processing begin subRun:run: 6099 subRun: 607 time:1434088907 ++++++ processing path for begin subRun:end_path ++++++++ module for begin subRun:out1 ++++++++ finished for begin subRun:out1 ++++++ finished path for begin subRun: ++++ finished begin subRun: ++++source event Begin processing the 2nd record. run: 6099 subRun: 607 event: 607 at 06-Jul-2015 10:33:42 CDT ++++finished: source event ++++ processing event:run: 6099 subRun: 607 event: 607 time:1434088907 ++++++ processing path for event:end_path ++++++++ module for event:out1 PROCESS NAME | MODULE LABEL.. | PRODUCT INSTANCE NAME | DATA PRODUCT TYPE............ | SIZE DAQ......... | daq........... | unidentified......... | std::vector<artdaq::Fragment> | ...? DAQ......... | daq........... | SPILL................ | std::vector<artdaq::Fragment> | ...1 DAQAG....... | TriggerResults | ..................... | art::TriggerResults.......... | ...- Total products (present, not present): 3 (2, 1). ++++++++ finished for event:out1 ++++++ finished path for event: ++++ finished event: ++++close input file 06-Jul-2015 10:33:42 CDT Closed file /pnfs/lariat/pnfs/fnal.gov/usr/lariat/raw/000/541/lariat_r006099_sr0607.root ++++finished: close input file ++++open input file 06-Jul-2015 10:33:42 CDT Initiating request to open file /pnfs/lariat/pnfs/fnal.gov/usr/lariat/raw/000/541/lariat_r006099_sr0608.root 06-Jul-2015 10:33:42 CDT Successfully opened file /pnfs/lariat/pnfs/fnal.gov/usr/lariat/raw/000/541/lariat_r006099_sr0608.root ++++finished: open input file /pnfs/lariat/pnfs/fnal.gov/usr/lariat/raw/000/541/lariat_r006099_sr0608.root ++++source run ++++finished: source run %MSG-w RunMerging: SourceRun 06-Jul-2015 10:33:42 CDT PostProcessEvent Problem found while adding product provenance, product already exists for (artdaq::PackageBuildInfos,lariatOnlineBuildInfo,LariatOnlineBuildInfo,DAQAG) %MSG ++++ processing end subRun:run: 6099 subRun: 607 time:1434088907 ++++++ processing path for end subRun:end_path ++++++++ module for end subRun:out1 ++++++++ finished for end subRun:out1 ++++++ finished path for end subRun: ++++ finished end subRun: ++++source subRun ++++finished: source subRun ++++ processing begin subRun:run: 6099 subRun: 608 time:1434088967 ++++++ processing path for begin subRun:end_path ++++++++ module for begin subRun:out1 ++++++++ finished for begin subRun:out1 ++++++ finished path for begin subRun: ++++ finished begin subRun: ++++source event Begin processing the 3rd record. run: 6099 subRun: 608 event: 608 at 06-Jul-2015 10:33:42 CDT ++++finished: source event ++++ processing event:run: 6099 subRun: 608 event: 608 time:1434088967 ++++++ processing path for event:end_path ++++++++ module for event:out1 PROCESS NAME | MODULE LABEL.. | PRODUCT INSTANCE NAME | DATA PRODUCT TYPE............ | SIZE DAQ......... | daq........... | unidentified......... | std::vector<artdaq::Fragment> | ...? DAQ......... | daq........... | SPILL................ | std::vector<artdaq::Fragment> | ...1 DAQAG....... | TriggerResults | ..................... | art::TriggerResults.......... | ...- Total products (present, not present): 3 (2, 1). ++++++++ finished for event:out1 ++++++ finished path for event: ++++ finished event: ++++close input file 06-Jul-2015 10:33:42 CDT Closed file /pnfs/lariat/pnfs/fnal.gov/usr/lariat/raw/000/541/lariat_r006099_sr0608.root ++++finished: close input file ++++open input file 06-Jul-2015 10:33:42 CDT Initiating request to open file /pnfs/lariat/pnfs/fnal.gov/usr/lariat/raw/000/541/lariat_r006099_sr0609.root 06-Jul-2015 10:33:42 CDT Successfully opened file /pnfs/lariat/pnfs/fnal.gov/usr/lariat/raw/000/541/lariat_r006099_sr0609.root ++++finished: open input file /pnfs/lariat/pnfs/fnal.gov/usr/lariat/raw/000/541/lariat_r006099_sr0609.root ++++source run ++++finished: source run %MSG-w RunMerging: SourceRun 06-Jul-2015 10:33:42 CDT PostProcessEvent Problem found while adding product provenance, product already exists for (artdaq::PackageBuildInfos,lariatOnlineBuildInfo,LariatOnlineBuildInfo,DAQAG) %MSG ++++ processing end subRun:run: 6099 subRun: 608 time:1434088967 ++++++ processing path for end subRun:end_path ++++++++ module for end subRun:out1 ++++++++ finished for end subRun:out1 ++++++ finished path for end subRun: ++++ finished end subRun: ++++source subRun ++++finished: source subRun ++++ processing begin subRun:run: 6099 subRun: 609 time:1434089028 ++++++ processing path for begin subRun:end_path ++++++++ module for begin subRun:out1 ++++++++ finished for begin subRun:out1 ++++++ finished path for begin subRun: ++++ finished begin subRun: ++++source event ++++finished: source event Begin processing the 4th record. run: 6099 subRun: 609 event: 609 at 06-Jul-2015 10:33:42 CDT ++++ processing event:run: 6099 subRun: 609 event: 609 time:1434089028 ++++++ processing path for event:end_path ++++++++ module for event:out1 PROCESS NAME | MODULE LABEL.. | PRODUCT INSTANCE NAME | DATA PRODUCT TYPE............ | SIZE DAQ......... | daq........... | unidentified......... | std::vector<artdaq::Fragment> | ...? DAQ......... | daq........... | SPILL................ | std::vector<artdaq::Fragment> | ...1 DAQAG....... | TriggerResults | ..................... | art::TriggerResults.......... | ...- Total products (present, not present): 3 (2, 1). ++++++++ finished for event:out1 ++++++ finished path for event: ++++ finished event: ++++close input file 06-Jul-2015 10:33:42 CDT Closed file /pnfs/lariat/pnfs/fnal.gov/usr/lariat/raw/000/541/lariat_r006099_sr0609.root ++++finished: close input file ++++open input file 06-Jul-2015 10:33:42 CDT Initiating request to open file /pnfs/lariat/pnfs/fnal.gov/usr/lariat/raw/000/541/lariat_r006099_sr0625.root 06-Jul-2015 10:33:43 CDT Successfully opened file /pnfs/lariat/pnfs/fnal.gov/usr/lariat/raw/000/541/lariat_r006099_sr0625.root ++++finished: open input file /pnfs/lariat/pnfs/fnal.gov/usr/lariat/raw/000/541/lariat_r006099_sr0625.root ++++source run ++++finished: source run %MSG-w RunMerging: SourceRun 06-Jul-2015 10:33:43 CDT PostProcessEvent Problem found while adding product provenance, product already exists for (artdaq::PackageBuildInfos,lariatOnlineBuildInfo,LariatOnlineBuildInfo,DAQAG) %MSG ++++ processing end subRun:run: 6099 subRun: 609 time:1434089028 ++++++ processing path for end subRun:end_path ++++++++ module for end subRun:out1 ++++++++ finished for end subRun:out1 ++++++ finished path for end subRun: ++++ finished end subRun: ++++source subRun ++++finished: source subRun ++++ processing begin subRun:run: 6099 subRun: 625 time:1434089991 ++++++ processing path for begin subRun:end_path ++++++++ module for begin subRun:out1 ++++++++ finished for begin subRun:out1 ++++++ finished path for begin subRun: ++++ finished begin subRun: ++++source event Begin processing the 5th record. run: 6099 subRun: 625 event: 625 at 06-Jul-2015 10:33:43 CDT ++++finished: source event ++++ processing event:run: 6099 subRun: 625 event: 625 time:1434089991 ++++++ processing path for event:end_path ++++++++ module for event:out1 PROCESS NAME | MODULE LABEL.. | PRODUCT INSTANCE NAME | DATA PRODUCT TYPE............ | SIZE DAQ......... | daq........... | unidentified......... | std::vector<artdaq::Fragment> | ...? DAQ......... | daq........... | SPILL................ | std::vector<artdaq::Fragment> | ...1 DAQAG....... | TriggerResults | ..................... | art::TriggerResults.......... | ...- Total products (present, not present): 3 (2, 1). ++++++++ finished for event:out1 ++++++ finished path for event: ++++ finished event: ++++close input file 06-Jul-2015 10:33:43 CDT Closed file /pnfs/lariat/pnfs/fnal.gov/usr/lariat/raw/000/541/lariat_r006099_sr0625.root ++++finished: close input file ++++open input file 06-Jul-2015 10:33:43 CDT Initiating request to open file /pnfs/lariat/pnfs/fnal.gov/usr/lariat/raw/000/541/lariat_r006099_sr0626.root 06-Jul-2015 10:33:43 CDT Successfully opened file /pnfs/lariat/pnfs/fnal.gov/usr/lariat/raw/000/541/lariat_r006099_sr0626.root ++++finished: open input file /pnfs/lariat/pnfs/fnal.gov/usr/lariat/raw/000/541/lariat_r006099_sr0626.root ++++source run ++++finished: source run ++++ processing end subRun:run: 6099 subRun: 625 time:1434089991 ++++++ processing path for end subRun:end_path ++++++++ module for end subRun:out1 ++++++++ finished for end subRun:out1 ++++++ finished path for end subRun: ++++ finished end subRun: ++++source subRun %MSG-w RunMerging: SourceRun 06-Jul-2015 10:33:43 CDT PostProcessEvent Problem found while adding product provenance, product already exists for (artdaq::PackageBuildInfos,lariatOnlineBuildInfo,LariatOnlineBuildInfo,DAQAG) %MSG ++++finished: source subRun ++++ processing begin subRun:run: 6099 subRun: 626 time:1434090051 ++++++ processing path for begin subRun:end_path ++++++++ module for begin subRun:out1 ++++++++ finished for begin subRun:out1 ++++++ finished path for begin subRun: ++++ finished begin subRun: ++++source event Begin processing the 6th record. run: 6099 subRun: 626 event: 626 at 06-Jul-2015 10:33:43 CDT ++++finished: source event ++++ processing event:run: 6099 subRun: 626 event: 626 time:1434090051 ++++++ processing path for event:end_path ++++++++ module for event:out1 PROCESS NAME | MODULE LABEL.. | PRODUCT INSTANCE NAME | DATA PRODUCT TYPE............ | SIZE DAQ......... | daq........... | unidentified......... | std::vector<artdaq::Fragment> | ...? DAQ......... | daq........... | SPILL................ | std::vector<artdaq::Fragment> | ...1 DAQAG....... | TriggerResults | ..................... | art::TriggerResults.......... | ...- Total products (present, not present): 3 (2, 1). ++++++++ finished for event:out1 ++++++ finished path for event: ++++ finished event: ++++close input file 06-Jul-2015 10:33:43 CDT Closed file /pnfs/lariat/pnfs/fnal.gov/usr/lariat/raw/000/541/lariat_r006099_sr0626.root ++++finished: close input file ++++open input file 06-Jul-2015 10:33:43 CDT Initiating request to open file /pnfs/lariat/pnfs/fnal.gov/usr/lariat/raw/000/541/lariat_r006099_sr0627.root 06-Jul-2015 10:33:43 CDT Successfully opened file /pnfs/lariat/pnfs/fnal.gov/usr/lariat/raw/000/541/lariat_r006099_sr0627.root ++++finished: open input file /pnfs/lariat/pnfs/fnal.gov/usr/lariat/raw/000/541/lariat_r006099_sr0627.root ++++source run ++++finished: source run %MSG-w RunMerging: SourceRun 06-Jul-2015 10:33:43 CDT PostProcessEvent Problem found while adding product provenance, product already exists for (artdaq::PackageBuildInfos,lariatOnlineBuildInfo,LariatOnlineBuildInfo,DAQAG) %MSG ++++ processing end subRun:run: 6099 subRun: 626 time:1434090051 ++++++ processing path for end subRun:end_path ++++++++ module for end subRun:out1 ++++++++ finished for end subRun:out1 ++++++ finished path for end subRun: ++++ finished end subRun: ++++source subRun ++++finished: source subRun ++++ processing begin subRun:run: 6099 subRun: 627 time:1434090111 ++++++ processing path for begin subRun:end_path ++++++++ module for begin subRun:out1 ++++++++ finished for begin subRun:out1 ++++++ finished path for begin subRun: ++++ finished begin subRun: ++++source event Begin processing the 7th record. run: 6099 subRun: 627 event: 627 at 06-Jul-2015 10:33:43 CDT ++++finished: source event ++++ processing event:run: 6099 subRun: 627 event: 627 time:1434090111 ++++++ processing path for event:end_path ++++++++ module for event:out1 PROCESS NAME | MODULE LABEL.. | PRODUCT INSTANCE NAME | DATA PRODUCT TYPE............ | SIZE DAQ......... | daq........... | unidentified......... | std::vector<artdaq::Fragment> | ...? DAQ......... | daq........... | SPILL................ | std::vector<artdaq::Fragment> | ...1 DAQAG....... | TriggerResults | ..................... | art::TriggerResults.......... | ...- Total products (present, not present): 3 (2, 1). ++++++++ finished for event:out1 ++++++ finished path for event: ++++ finished event: ++++close input file 06-Jul-2015 10:33:43 CDT Closed file /pnfs/lariat/pnfs/fnal.gov/usr/lariat/raw/000/541/lariat_r006099_sr0627.root ++++finished: close input file ++++open input file 06-Jul-2015 10:33:43 CDT Initiating request to open file /pnfs/lariat/pnfs/fnal.gov/usr/lariat/raw/000/541/lariat_r006099_sr0628.root 06-Jul-2015 10:33:43 CDT Successfully opened file /pnfs/lariat/pnfs/fnal.gov/usr/lariat/raw/000/541/lariat_r006099_sr0628.root ++++finished: open input file /pnfs/lariat/pnfs/fnal.gov/usr/lariat/raw/000/541/lariat_r006099_sr0628.root ++++source run ++++finished: source run %MSG-w RunMerging: SourceRun 06-Jul-2015 10:33:43 CDT PostProcessEvent Problem found while adding product provenance, product already exists for (artdaq::PackageBuildInfos,lariatOnlineBuildInfo,LariatOnlineBuildInfo,DAQAG) %MSG ++++ processing end subRun:run: 6099 subRun: 627 time:1434090111 ++++++ processing path for end subRun:end_path ++++++++ module for end subRun:out1 ++++++++ finished for end subRun:out1 ++++++ finished path for end subRun: ++++ finished end subRun: ++++source subRun ++++finished: source subRun ++++ processing begin subRun:run: 6099 subRun: 628 time:1434090171 ++++++ processing path for begin subRun:end_path ++++++++ module for begin subRun:out1 ++++++++ finished for begin subRun:out1 ++++++ finished path for begin subRun: ++++ finished begin subRun: ++++source event Begin processing the 8th record. run: 6099 subRun: 628 event: 628 at 06-Jul-2015 10:33:43 CDT ++++finished: source event ++++ processing event:run: 6099 subRun: 628 event: 628 time:1434090171 ++++++ processing path for event:end_path ++++++++ module for event:out1 PROCESS NAME | MODULE LABEL.. | PRODUCT INSTANCE NAME | DATA PRODUCT TYPE............ | SIZE DAQ......... | daq........... | unidentified......... | std::vector<artdaq::Fragment> | ...? DAQ......... | daq........... | SPILL................ | std::vector<artdaq::Fragment> | ...1 DAQAG....... | TriggerResults | ..................... | art::TriggerResults.......... | ...- Total products (present, not present): 3 (2, 1). ++++++++ finished for event:out1 ++++++ finished path for event: ++++ finished event: ++++close input file 06-Jul-2015 10:33:43 CDT Closed file /pnfs/lariat/pnfs/fnal.gov/usr/lariat/raw/000/541/lariat_r006099_sr0628.root ++++finished: close input file ++++open input file 06-Jul-2015 10:33:43 CDT Initiating request to open file /pnfs/lariat/pnfs/fnal.gov/usr/lariat/raw/000/541/lariat_r006099_sr0629.root 06-Jul-2015 10:33:43 CDT Successfully opened file /pnfs/lariat/pnfs/fnal.gov/usr/lariat/raw/000/541/lariat_r006099_sr0629.root ++++finished: open input file /pnfs/lariat/pnfs/fnal.gov/usr/lariat/raw/000/541/lariat_r006099_sr0629.root ++++source run ++++finished: source run %MSG-w RunMerging: SourceRun 06-Jul-2015 10:33:43 CDT PostProcessEvent Problem found while adding product provenance, product already exists for (artdaq::PackageBuildInfos,lariatOnlineBuildInfo,LariatOnlineBuildInfo,DAQAG) %MSG ++++ processing end subRun:run: 6099 subRun: 628 time:1434090171 ++++++ processing path for end subRun:end_path ++++++++ module for end subRun:out1 ++++++++ finished for end subRun:out1 ++++++ finished path for end subRun: ++++ finished end subRun: ++++source subRun ++++finished: source subRun ++++ processing begin subRun:run: 6099 subRun: 629 time:1434090232 ++++++ processing path for begin subRun:end_path ++++++++ module for begin subRun:out1 ++++++++ finished for begin subRun:out1 ++++++ finished path for begin subRun: ++++ finished begin subRun: ++++source event ++++finished: source event Begin processing the 9th record. run: 6099 subRun: 629 event: 629 at 06-Jul-2015 10:33:43 CDT ++++ processing event:run: 6099 subRun: 629 event: 629 time:1434090232 ++++++ processing path for event:end_path ++++++++ module for event:out1 PROCESS NAME | MODULE LABEL.. | PRODUCT INSTANCE NAME | DATA PRODUCT TYPE............ | SIZE DAQ......... | daq........... | unidentified......... | std::vector<artdaq::Fragment> | ...? DAQ......... | daq........... | SPILL................ | std::vector<artdaq::Fragment> | ...1 DAQAG....... | TriggerResults | ..................... | art::TriggerResults.......... | ...- Total products (present, not present): 3 (2, 1). ++++++++ finished for event:out1 ++++++ finished path for event: ++++ finished event: ++++close input file 06-Jul-2015 10:33:44 CDT Closed file /pnfs/lariat/pnfs/fnal.gov/usr/lariat/raw/000/541/lariat_r006099_sr0629.root ++++finished: close input file ++++open input file 06-Jul-2015 10:33:44 CDT Initiating request to open file /pnfs/lariat/pnfs/fnal.gov/usr/lariat/raw/000/541/lariat_r006099_sr0630.root 06-Jul-2015 10:33:44 CDT Successfully opened file /pnfs/lariat/pnfs/fnal.gov/usr/lariat/raw/000/541/lariat_r006099_sr0630.root ++++finished: open input file /pnfs/lariat/pnfs/fnal.gov/usr/lariat/raw/000/541/lariat_r006099_sr0630.root ++++source run ++++finished: source run %MSG-w RunMerging: SourceRun 06-Jul-2015 10:33:44 CDT PostProcessEvent Problem found while adding product provenance, product already exists for (artdaq::PackageBuildInfos,lariatOnlineBuildInfo,LariatOnlineBuildInfo,DAQAG) %MSG ++++ processing end subRun:run: 6099 subRun: 629 time:1434090232 ++++++ processing path for end subRun:end_path ++++++++ module for end subRun:out1 ++++++++ finished for end subRun:out1 ++++++ finished path for end subRun: ++++ finished end subRun: ++++source subRun ++++finished: source subRun ++++ processing begin subRun:run: 6099 subRun: 630 time:1434090292 ++++++ processing path for begin subRun:end_path ++++++++ module for begin subRun:out1 ++++++++ finished for begin subRun:out1 ++++++ finished path for begin subRun: ++++ finished begin subRun: ++++source event Begin processing the 10th record. run: 6099 subRun: 630 event: 630 at 06-Jul-2015 10:33:44 CDT ++++finished: source event ++++ processing event:run: 6099 subRun: 630 event: 630 time:1434090292 ++++++ processing path for event:end_path ++++++++ module for event:out1 PROCESS NAME | MODULE LABEL.. | PRODUCT INSTANCE NAME | DATA PRODUCT TYPE............ | SIZE DAQ......... | daq........... | unidentified......... | std::vector<artdaq::Fragment> | ...? DAQ......... | daq........... | SPILL................ | std::vector<artdaq::Fragment> | ...1 DAQAG....... | TriggerResults | ..................... | art::TriggerResults.......... | ...- Total products (present, not present): 3 (2, 1). ++++++++ finished for event:out1 ++++++ finished path for event: ++++ finished event: ++++ processing end subRun:run: 6099 subRun: 630 time:1434090292 ++++++ processing path for end subRun:end_path ++++++++ module for end subRun:out1 ++++++++ finished for end subRun:out1 ++++++ finished path for end subRun: ++++ finished end subRun: ++++ processing end run:run: 6099 time:1434090292 ++++++ processing path for end run:end_path ++++++++ module for end run:out1 ++++++++ finished for end run:out1 ++++++ finished path for end run: ++++ finished end run: PROCESS NAME | MODULE LABEL......... | PRODUCT INSTANCE NAME | DATA PRODUCT TYPE.................... | SIZE DAQAG....... | lariatOnlineBuildInfo | LariatOnlineBuildInfo | std::vector<artdaq::PackageBuildInfo> | ...3 Total products (present, not present): 1 (1, 0). ++++close output file from out1 ++++finished close output file <none> from out1 ++++close input file 06-Jul-2015 10:33:44 CDT Closed file /pnfs/lariat/pnfs/fnal.gov/usr/lariat/raw/000/541/lariat_r006099_sr0630.root ++++finished: close input file ++ endJob module:out1 ++ endJob finished:out1 TrigReport ---------- Event Summary ------------ TrigReport Events total = 10 passed = 10 failed = 0 TrigReport ------ Modules in End-Path: end_path ------------ TrigReport Trig Bit# Visited Passed Failed Error Name TrigReport 0 0 10 10 0 0 out1 TimeReport ---------- Time Summary ---[sec]---- ++ Job ended TimeReport CPU = 1.760061 Real = 1.757732 Art has completed and will exit with status 0.
The relevant .fcl files are attached.
#3 Updated by Christopher Green about 4 years ago
- Status changed from Feedback to Assigned
- Assignee set to Kyle Knoepfel
- SSI Package art added
- SSI Package deleted (
)
Thanks for providing this information.
We will need to study this issue to analyze the behavior further.
#4 Updated by Kyle Knoepfel about 4 years ago
Upon investigation, the art::EventID objects of each of the input files have invalid member values. In other words, if one of the files is opened in a TBrowser, and one looks at the values of the FileIndex branch of the MetaData tree, the following numbers are obtained (in C++ish syntax):
RunNumber_t run_; // ... run_ actually isn't used so no worries here
SubRunNumber_t subRun_ = { 6099, INVALID }; // where 6099 is the run number, but the subrun number is invalid
EventNumber_t event_ = INVALID;
where INVALID is a constant literal of value -1.
To debug further we would need to know how the EventID was assigned in the source. Can you point us to the relevant code and FHiCL files?
#5 Updated by Brian Rebel about 4 years ago
The EventID was assigned by artdaq. Perhaps we have a problem there? The code is somewhere in lariatonline, but I don't know where. Perhaps John Freeman can help you?
#6 Updated by Kyle Knoepfel about 4 years ago
Our first analysis of the problem was incorrect -- after debugging with gdb, it appears the FileIndex elements for the individual input files have well-formed values. The confusion stemmed from the ROOT TBrowser printing incorrect values for the subrun and event numbers of the FileIndex branch. The next step is to verify that the aggregated file is well-formed.
Thanks for your patience.
#7 Updated by Kyle Knoepfel about 4 years ago
I have been able to reproduce the behavior described above: namely an assertion failure when attempting to access the next event through the event display, and no problems when running the eventdump.fcl job.
The aggregated file standard_reco.root has well-formed art::FileIndex::Element values, so I confirm that that is not the problem. Will now run the event-display process through gdb.
#8 Updated by Kyle Knoepfel about 4 years ago
- % Done changed from 0 to 100
The problem is now understood. The details of the observed behavior are somewhat esoteric, but briefly speaking, since the EventDisplay::postProcessEvent callback calls RootInput::seekToEvent, the state of the event processor and the state as determined by RootInput get out-of-sync. This asynchrony is not a problem since the state machine is designed to handle it. However, an extra function that unnecessarily tests for this mismatch was added in art 1.14 to support secondary file reading. We will remove the assert call, which is not necessary here, and release a new version of art, 1.14.04, that does not have this problem.
In the meantime, since the problem is triggered by an assert, you can sidestep it entirely by using the prof build of art 1.14.03.
#9 Updated by Brian Rebel about 4 years ago
Thanks for the answer, Kyle.
We'll use a prof build for now, and update when the new art version is ready.
#10 Updated by Christopher Green about 4 years ago
- Target version set to 1.15.01
#11 Updated by Christopher Green about 4 years ago
- Status changed from Assigned to Resolved
Fix applied with 406626b.
#12 Updated by Kyle Knoepfel about 4 years ago
- Status changed from Resolved to Closed
Fix for issue #9363.