Jobsub ID 41596.106@dunegpschedd02.fnal.gov
Jobscript log (last 10,000 characters)
] <Resampler:resmp0> EOS at call=97
[09:38:32.982] D [sigproc ] <OmnibusSigProc:anode0sigproc0> EOS at call=97 anode=0
[09:38:32.982] D [ glue ] <FrameFanin:nfsp> EOS at call=97 with 8
[09:38:32.982] D [ glue ] frame sink sees EOS
[09:38:32.982] D [ pgraph ] <Pgrapher:> graph execution complete
[09:38:32.982] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.78 sec
[09:38:32.982] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.53 sec
[09:38:32.982] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.01 sec
[09:38:32.982] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8 sec
[09:38:32.982] I [ timer ] Timer: WireCell::Aux::Resampler : 0.56 sec
[09:38:32.982] I [ timer ] Timer: WireCell::Aux::Resampler : 0.5 sec
[09:38:32.982] I [ timer ] Timer: WireCell::Aux::Resampler : 0.49 sec
[09:38:32.982] I [ timer ] Timer: WireCell::Aux::Resampler : 0.49 sec
[09:38:32.982] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.01 sec
[09:38:32.982] I [ timer ] Timer: WireCell::Gen::Retagger : 0.01 sec
[09:38:32.982] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0.01 sec
[09:38:32.982] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[09:38:32.982] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[09:38:32.982] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[09:38:32.982] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[09:38:32.982] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[09:38:32.982] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[09:38:32.982] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[09:38:32.982] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[09:38:32.982] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[09:38:32.982] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[09:38:32.982] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[09:38:32.982] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[09:38:32.982] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[09:38:32.982] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[09:38:32.982] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[09:38:32.982] I [ timer ] Timer: Total node execution : 35.38999971561134 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 13592 traces tagged "gauss"
FrameSaver: q=2.3594e+06 n=302356 tag=gauss
wclsFrameSaver: saving 16784 traces tagged "wiener"
FrameSaver: q=2.50565e+06 n=291002 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 1106 XUs and 1364 XVs -> 59 XUVs
C:0 T:1 568 XUs and 573 XVs -> 22 XUVs
C:0 T:2 1981 XUs and 3526 XVs -> 164 XUVs
C:0 T:3 221 XUs and 222 XVs -> 11 XUVs
C:0 T:4 219 XUs and 320 XVs -> 20 XUVs
C:0 T:5 449 XUs and 690 XVs -> 22 XUVs
C:0 T:6 196 XUs and 257 XVs -> 18 XUVs
C:0 T:7 449 XUs and 667 XVs -> 23 XUVs
339 XUVs total
302 collection wire objects
339 potential space points
Neighbour search...
2703 tests to find 1094 neighbours
Iterating with no regularization...
Begin: 5.30874e+09
0 5.2961e+09
1 5.29605e+09
Now with regularization...
Begin: 5.27289e+09
0 5.27289e+09
18-Sep-2025 09:38:46 BST Closed output file "np02vd_raw_run039433_0318_df-s05-d5_dw_0_20250918T042555_reco_stage1_20250918T083846_keepup.root"
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 75.2253 225.159 5344.85 110.358 739.528 49
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 6.6645e-05 9.57354e-05 0.000272762 8.8725e-05 2.97339e-05 49
produce:tpcrawdecoder:PDVDTPCReader 17.8675 34.9363 61.4483 33.6162 9.71577 49
produce:triggerrawdecoder:PDVDTriggerReader4 0.27908 0.358525 0.594651 0.329667 0.083326 49
produce:pdvddaphne:DAPHNEReaderPDVD 7.63262 11.4475 17.0379 11.3538 1.99078 49
produce:ophit:OpHitFinder 0.0372839 0.0617117 0.0769174 0.0609204 0.00901195 49
produce:opflash:OpFlashFinderVerticalDrift 0.00533661 0.0139184 0.0209357 0.0144602 0.00341788 49
produce:wclsdatavd:WireCellToolkit 28.6616 44.2599 137.904 35.9208 19.3462 49
produce:gaushit:GausHitFinder 0.38149 0.7935 3.04723 0.706999 0.382435 49
produce:nhitsfilter:NumberOfHitsFilter 0.000147036 0.000283122 0.000775236 0.000260762 0.000106006 49
produce:reco3d:SpacePointSolver 1.97032 5.95857 43.936 4.72468 5.91562 49
produce:hitpdune:DisambigFromSpacePoints 0.0361542 0.149678 2.14212 0.0940275 0.292802 49
produce:pandora:StandardPandora 5.72139 123.682 5112.98 17.2203 720.26 49
produce:pandoraTrack:LArPandoraTrackCreation 0.0769606 0.627903 8.41806 0.36526 1.1713 49
produce:pandoraGnocalo:GnocchiCalorimetry 0.00774481 0.0202101 0.0750725 0.0177418 0.0104792 49
[art]:TriggerResults:TriggerResultInserter 1.8475e-05 3.38995e-05 9.0225e-05 3.1447e-05 1.16409e-05 49
end_path:out1:RootOutput 3.712e-06 7.61963e-06 2.774e-05 7.39e-06 3.77696e-06 49
end_path:out1:RootOutput(write) 1.69364 2.82041 4.46388 2.83968 0.523811 49
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 6782.42 MB
Peak resident set size usage (VmHWM): 4892.06 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run039433_0318_df-s05-d5_dw_0_20250918T042555_reco_stage1_20250918T083846_keepup.root
\tHists: np02vd_raw_run039433_0318_df-s05-d5_dw_0_20250918T042555_reco_stage1_20250918T083848_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run039433_0318_df-s05-d5_dw_0_20250918T042555_reco_stage1_20250918T083846_keepup.root
Ran successfully
{
"name": "np02vd_raw_run039433_0318_df-s05-d5_dw_0_20250918T042555_reco_stage1_20250918T083846_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": 1758184728.0,
"core.end_time": 1758184728.0,
"core.events": [
91151,
91157,
91163,
91169,
91175,
91181,
91187,
91193,
91199,
91205,
91211,
91217,
91223,
91229,
91235,
91241,
91247,
91253,
91259,
91265,
91271,
91277,
91283,
91289,
91295,
91301,
91307,
91313,
91319,
91325,
91331,
91337,
91343,
91349,
91355,
91361,
91367,
91373,
91379,
91385,
91391,
91397,
91403,
91409,
91415,
91421,
91427,
91433,
91439
],
"core.event_count": 49,
"core.first_event_number": 91151,
"core.last_event_number": 91439,
"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_0318_df-s05-d5_dw_0_20250918T042555.hdf5"
}
]
}Forming hist metadata
formed
{
"name": "np02vd_raw_run039433_0318_df-s05-d5_dw_0_20250918T042555_reco_stage1_20250918T083848_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": 1758184728.0,
"core.end_time": 1758184728.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_0318_df-s05-d5_dw_0_20250918T042555.hdf5"
}
]
}