Jobsub ID 41697.32@dunegpschedd02.fnal.gov
Jobscript log (last 10,000 characters)
c ] <OmnibusSigProc:anode0sigproc0> EOS at call=95 anode=0
[09:19:37.915] D [ glue ] <FrameFanin:nfsp> EOS at call=95 with 8
[09:19:37.915] D [ glue ] frame sink sees EOS
[09:19:37.915] D [ pgraph ] <Pgrapher:> graph execution complete
[09:19:37.915] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.79 sec
[09:19:37.915] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 6.53 sec
[09:19:37.915] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 6.01 sec
[09:19:37.915] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 5.55 sec
[09:19:37.915] I [ timer ] Timer: WireCell::Aux::Resampler : 0.43 sec
[09:19:37.915] I [ timer ] Timer: WireCell::Aux::Resampler : 0.43 sec
[09:19:37.915] I [ timer ] Timer: WireCell::Aux::Resampler : 0.43 sec
[09:19:37.915] I [ timer ] Timer: WireCell::Aux::Resampler : 0.41 sec
[09:19:37.915] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[09:19:37.915] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[09:19:37.915] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[09:19:37.915] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[09:19:37.915] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[09:19:37.915] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[09:19:37.915] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0 sec
[09:19:37.915] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[09:19:37.915] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[09:19:37.915] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[09:19:37.915] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[09:19:37.915] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[09:19:37.915] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[09:19:37.915] I [ timer ] Timer: WireCell::Gen::Retagger : 0 sec
[09:19:37.915] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0 sec
[09:19:37.915] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[09:19:37.915] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[09:19:37.915] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[09:19:37.915] I [ timer ] Timer: Total node execution : 27.600000608712435 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 20831 traces tagged "gauss"
FrameSaver: q=3.17419e+06 n=478655 tag=gauss
wclsFrameSaver: saving 25978 traces tagged "wiener"
FrameSaver: q=3.37742e+06 n=462014 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 393 XUs and 410 XVs -> 13 XUVs
C:0 T:1 20794 XUs and 24450 XVs -> 1247 XUVs
C:0 T:2 1438 XUs and 1063 XVs -> 52 XUVs
C:0 T:3 1527 XUs and 1359 XVs -> 62 XUVs
C:0 T:4 851 XUs and 842 XVs -> 48 XUVs
C:0 T:5 1075 XUs and 1171 XVs -> 35 XUVs
C:0 T:6 108 XUs and 94 XVs -> 1 XUVs
C:0 T:7 1084 XUs and 1306 XVs -> 31 XUVs
1489 XUVs total
898 collection wire objects
1489 potential space points
Neighbour search...
29109 tests to find 7892 neighbours
Iterating with no regularization...
Begin: 1.4334e+09
0 1.40231e+09
1 1.40088e+09
2 1.40084e+09
Now with regularization...
Begin: 1.38034e+09
0 1.38032e+09
18-Sep-2025 09:20:08 BST Closed output file "np02vd_raw_run039433_0350_df-s05-d0_dw_0_20250918T054428_reco_stage1_20250918T082008_keepup.root"
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 42.7844 115.037 1095.44 67.7775 171.47 48
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 7.0953e-05 0.000190229 0.00185667 0.000113918 0.000314491 48
produce:tpcrawdecoder:PDVDTPCReader 5.94798 7.46098 20.4536 6.50404 2.91798 48
produce:triggerrawdecoder:PDVDTriggerReader4 0.30089 0.308008 0.344713 0.305904 0.00755945 48
produce:pdvddaphne:DAPHNEReaderPDVD 3.07491 3.55084 8.92476 3.43116 0.844321 48
produce:ophit:OpHitFinder 0.0353831 0.0505893 0.0619598 0.0513182 0.00608996 48
produce:opflash:OpFlashFinderVerticalDrift 0.00408637 0.0117448 0.0231926 0.0115983 0.00387541 48
produce:wclsdatavd:WireCellToolkit 23.1668 35.1251 72.0893 29.8068 10.1854 48
produce:gaushit:GausHitFinder 0.328111 0.733595 1.50342 0.65964 0.26981 48
produce:nhitsfilter:NumberOfHitsFilter 8.9037e-05 0.00019402 0.000485561 0.000179366 6.87451e-05 48
produce:reco3d:SpacePointSolver 1.98257 6.6117 26.148 5.02822 4.91049 48
produce:hitpdune:DisambigFromSpacePoints 0.0196129 0.115515 0.605714 0.0696747 0.132587 48
produce:pandora:StandardPandora 4.10394 57.8957 999.284 14.9616 161.668 48
produce:pandoraTrack:LArPandoraTrackCreation 0.102314 0.402158 2.07002 0.26104 0.427052 48
produce:pandoraGnocalo:GnocchiCalorimetry 0.00739951 0.0184395 0.0460284 0.0169858 0.0085016 48
[art]:TriggerResults:TriggerResultInserter 1.7754e-05 3.33937e-05 0.000119113 3.185e-05 1.37047e-05 48
end_path:out1:RootOutput 4.288e-06 1.02006e-05 3.9094e-05 9.964e-06 4.53338e-06 48
end_path:out1:RootOutput(write) 2.23285 2.72309 3.67739 2.60786 0.331023 48
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 5378.24 MB
Peak resident set size usage (VmHWM): 3420.54 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run039433_0350_df-s05-d0_dw_0_20250918T054428_reco_stage1_20250918T082008_keepup.root
\tHists: np02vd_raw_run039433_0350_df-s05-d0_dw_0_20250918T054428_reco_stage1_20250918T082008_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run039433_0350_df-s05-d0_dw_0_20250918T054428_reco_stage1_20250918T082008_keepup.root
Ran successfully
{
"name": "np02vd_raw_run039433_0350_df-s05-d0_dw_0_20250918T054428_reco_stage1_20250918T082008_keepup.root",
"namespace": "vd-protodune-det-reco",
"metadata": {
"core.file_format": "artroot",
"core.application.name": "reco",
"core.application.family": "dunesw",
"core.application.version": "v10_10_00d00",
"core.data_tier": "full-reconstructed",
"dune.config_file": "standard_reco_stage1_protodunevd_keepup_all.fcl",
"dune.campaign": "vd-protodune-reco-keepup-v0",
"core.start_time": 1758183609.0,
"core.end_time": 1758183609.0,
"core.events": [
100458,
100464,
100470,
100476,
100482,
100488,
100494,
100500,
100506,
100512,
100518,
100524,
100530,
100536,
100542,
100548,
100554,
100560,
100566,
100572,
100578,
100584,
100590,
100596,
100602,
100608,
100614,
100620,
100626,
100632,
100638,
100644,
100650,
100656,
100662,
100668,
100674,
100680,
100686,
100692,
100698,
100704,
100710,
100716,
100722,
100728,
100734,
100740
],
"core.event_count": 48,
"core.first_event_number": 100458,
"core.last_event_number": 100740,
"core.data_stream": "cosmics",
"core.file_content_status": "good",
"core.file_type": "detector",
"core.run_type": "vd-protodune",
"core.runs": [
39433
],
"core.runs_subruns": [
3943300001
],
"dune.daq_test": false,
"retention.status": "active",
"retention.class": "physics"
},
"parents": [
{
"did": "vd-protodune:np02vd_raw_run039433_0350_df-s05-d0_dw_0_20250918T054428.hdf5"
}
]
}Forming hist metadata
formed
{
"name": "np02vd_raw_run039433_0350_df-s05-d0_dw_0_20250918T054428_reco_stage1_20250918T082008_keepup_hists.root",
"namespace": "vd-protodune-det-reco",
"metadata": {
"core.file_format": "root",
"core.application.name": "reco",
"core.application.family": "dunesw",
"core.application.version": "v10_10_00d00",
"core.data_tier": "root-tuple-virtual",
"dune.config_file": "standard_reco_stage1_protodunevd_keepup_all.fcl",
"dune.campaign": "vd-protodune-reco-keepup-v0",
"core.start_time": 1758183609.0,
"core.end_time": 1758183609.0,
"core.data_stream": "cosmics",
"core.file_content_status": "good",
"core.file_type": "detector",
"core.run_type": "vd-protodune",
"core.runs": [
39433
],
"core.runs_subruns": [
3943300001
],
"dune.daq_test": false,
"retention.status": "active",
"retention.class": "physics"
},
"parents": [
{
"did": "vd-protodune:np02vd_raw_run039433_0350_df-s05-d0_dw_0_20250918T054428.hdf5"
}
]
}