Jobsub ID 48994.54@dunegpschedd01.fnal.gov
Jobscript log (last 10,000 characters)
:anode1sigproc1> EOS at call=81 anode=1
[22:39:04.915] D [ glue ] <ChannelSelector:chsel0> see EOS at call=40
[22:39:04.915] D [ aux ] <Resampler:resmp0> EOS at call=81
[22:39:04.915] D [sigproc ] <OmnibusSigProc:anode0sigproc0> EOS at call=81 anode=0
[22:39:04.915] D [ glue ] <FrameFanin:nfsp> EOS at call=81 with 8
[22:39:04.915] D [ glue ] frame sink sees EOS
[22:39:04.915] D [ pgraph ] <Pgrapher:> graph execution complete
[22:39:04.915] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.78 sec
[22:39:04.915] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.4 sec
[22:39:04.915] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.99 sec
[22:39:04.915] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.53 sec
[22:39:04.915] I [ timer ] Timer: WireCell::Aux::Resampler : 0.39 sec
[22:39:04.915] I [ timer ] Timer: WireCell::Aux::Resampler : 0.38 sec
[22:39:04.915] I [ timer ] Timer: WireCell::Aux::Resampler : 0.32 sec
[22:39:04.915] I [ timer ] Timer: WireCell::Aux::Resampler : 0.3 sec
[22:39:04.915] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[22:39:04.915] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[22:39:04.915] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[22:39:04.915] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[22:39:04.915] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[22:39:04.915] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[22:39:04.915] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0 sec
[22:39:04.915] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[22:39:04.915] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[22:39:04.915] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[22:39:04.915] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[22:39:04.916] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[22:39:04.916] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[22:39:04.916] I [ timer ] Timer: WireCell::Gen::Retagger : 0 sec
[22:39:04.916] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0 sec
[22:39:04.916] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[22:39:04.916] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[22:39:04.916] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[22:39:04.916] I [ timer ] Timer: Total node execution : 34.10999931767583 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 12812 traces tagged "gauss"
FrameSaver: q=2.34643e+06 n=321982 tag=gauss
wclsFrameSaver: saving 16647 traces tagged "wiener"
FrameSaver: q=2.5535e+06 n=312255 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 244 XUs and 287 XVs -> 8 XUVs
C:0 T:1 7884 XUs and 17657 XVs -> 743 XUVs
C:0 T:2 286 XUs and 261 XVs -> 24 XUVs
C:0 T:3 451 XUs and 438 XVs -> 25 XUVs
C:0 T:4 1392 XUs and 1557 XVs -> 68 XUVs
C:0 T:5 50 XUs and 43 XVs -> 0 XUVs
C:0 T:6 803 XUs and 2292 XVs -> 92 XUVs
C:0 T:7 50 XUs and 90 XVs -> 1 XUVs
961 XUVs total
648 collection wire objects
961 potential space points
Neighbour search...
27675 tests to find 7960 neighbours
Iterating with no regularization...
Begin: 1.44683e+09
0 1.40993e+09
1 1.40752e+09
2 1.40748e+09
Now with regularization...
Begin: 1.39907e+09
0 1.39906e+09
18-Sep-2025 22:39:20 BST Closed output file "np02vd_raw_run039499_0023_df-s05-d3_dw_0_20250918T182812_reco_stage1_20250918T213920_keepup.root"
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 89.4357 153.352 860.245 117.711 134.479 41
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 7.999e-05 0.000143674 0.000297299 0.000133511 4.9102e-05 41
produce:tpcrawdecoder:PDVDTPCReader 22.2068 34.1191 56.2001 32.3485 8.2094 41
produce:triggerrawdecoder:PDVDTriggerReader4 0.38216 0.458565 0.980953 0.437534 0.098673 41
produce:pdvddaphne:DAPHNEReaderPDVD 5.18786 8.06349 12.8881 8.04031 1.5864 41
produce:ophit:OpHitFinder 0.0455973 0.060136 0.0826224 0.0583777 0.00807957 41
produce:opflash:OpFlashFinderVerticalDrift 0.00675742 0.0154037 0.0294414 0.015722 0.00437836 41
produce:wclsdatavd:WireCellToolkit 32.6739 43.3678 84.4461 37.6142 12.0689 41
produce:gaushit:GausHitFinder 0.300596 0.790445 1.66014 0.766929 0.27436 41
produce:nhitsfilter:NumberOfHitsFilter 0.000126668 0.0002892 0.000721887 0.000241414 0.000133471 41
produce:reco3d:SpacePointSolver 1.56862 7.13451 24.8352 6.44147 3.97024 41
produce:hitpdune:DisambigFromSpacePoints 0.00981726 0.119918 0.489425 0.093116 0.0912526 41
produce:pandora:StandardPandora 2.91597 55.5311 738.12 20.5582 125.818 41
produce:pandoraTrack:LArPandoraTrackCreation 0.0747746 0.522208 3.97645 0.359049 0.648545 41
produce:pandoraGnocalo:GnocchiCalorimetry 0.00677263 0.0224192 0.0521636 0.0207983 0.00973334 41
[art]:TriggerResults:TriggerResultInserter 2.3434e-05 5.85278e-05 0.000114074 5.5935e-05 2.40216e-05 41
end_path:out1:RootOutput 4.338e-06 1.14994e-05 3.9203e-05 1.0259e-05 6.63839e-06 41
end_path:out1:RootOutput(write) 2.2568 3.09818 4.14655 3.1657 0.384584 41
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 4505.91 MB
Peak resident set size usage (VmHWM): 2562.55 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run039499_0023_df-s05-d3_dw_0_20250918T182812_reco_stage1_20250918T213920_keepup.root
\tHists: np02vd_raw_run039499_0023_df-s05-d3_dw_0_20250918T182812_reco_stage1_20250918T213920_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run039499_0023_df-s05-d3_dw_0_20250918T182812_reco_stage1_20250918T213920_keepup.root
Ran successfully
{
"name": "np02vd_raw_run039499_0023_df-s05-d3_dw_0_20250918T182812_reco_stage1_20250918T213920_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": 1758231561.0,
"core.end_time": 1758231561.0,
"core.events": [
5631,
5637,
5643,
5649,
5655,
5661,
5667,
5673,
5679,
5685,
5691,
5697,
5703,
5709,
5715,
5721,
5727,
5733,
5739,
5745,
5751,
5757,
5763,
5769,
5775,
5781,
5787,
5793,
5799,
5805,
5811,
5817,
5823,
5829,
5835,
5841,
5847,
5853,
5859,
5865,
5871
],
"core.event_count": 41,
"core.first_event_number": 5631,
"core.last_event_number": 5871,
"core.data_stream": "cosmics",
"core.file_content_status": "good",
"core.file_type": "detector",
"core.run_type": "vd-protodune",
"core.runs": [
39499
],
"core.runs_subruns": [
3949900001
],
"dune.daq_test": false,
"retention.status": "active",
"retention.class": "physics"
},
"parents": [
{
"did": "vd-protodune:np02vd_raw_run039499_0023_df-s05-d3_dw_0_20250918T182812.hdf5"
}
]
}Forming hist metadata
formed
{
"name": "np02vd_raw_run039499_0023_df-s05-d3_dw_0_20250918T182812_reco_stage1_20250918T213920_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": 1758231561.0,
"core.end_time": 1758231561.0,
"core.data_stream": "cosmics",
"core.file_content_status": "good",
"core.file_type": "detector",
"core.run_type": "vd-protodune",
"core.runs": [
39499
],
"core.runs_subruns": [
3949900001
],
"dune.daq_test": false,
"retention.status": "active",
"retention.class": "physics"
},
"parents": [
{
"did": "vd-protodune:np02vd_raw_run039499_0023_df-s05-d3_dw_0_20250918T182812.hdf5"
}
]
} 