Jobsub ID 48913.31@dunegpschedd01.fnal.gov
Jobscript log (last 10,000 characters)
D [ glue ] <ChannelSelector:chsel0> see EOS at call=40
[21:09:00.916] D [ aux ] <Resampler:resmp0> EOS at call=81
[21:09:00.916] D [sigproc ] <OmnibusSigProc:anode0sigproc0> EOS at call=81 anode=0
[21:09:00.916] D [ glue ] <FrameFanin:nfsp> EOS at call=81 with 8
[21:09:00.916] D [ glue ] frame sink sees EOS
[21:09:00.916] D [ pgraph ] <Pgrapher:> graph execution complete
[21:09:00.917] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 11.89 sec
[21:09:00.917] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 11.8 sec
[21:09:00.917] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 11.62 sec
[21:09:00.917] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 11.44 sec
[21:09:00.917] I [ timer ] Timer: WireCell::Aux::Resampler : 0.39 sec
[21:09:00.917] I [ timer ] Timer: WireCell::Aux::Resampler : 0.37 sec
[21:09:00.917] I [ timer ] Timer: WireCell::Aux::Resampler : 0.37 sec
[21:09:00.917] I [ timer ] Timer: WireCell::Aux::Resampler : 0.25 sec
[21:09:00.917] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[21:09:00.917] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.01 sec
[21:09:00.917] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[21:09:00.917] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[21:09:00.917] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[21:09:00.917] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[21:09:00.917] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[21:09:00.917] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[21:09:00.917] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[21:09:00.917] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[21:09:00.917] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[21:09:00.917] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[21:09:00.917] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[21:09:00.917] I [ timer ] Timer: WireCell::Gen::Retagger : 0 sec
[21:09:00.917] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0 sec
[21:09:00.917] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[21:09:00.917] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[21:09:00.917] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[21:09:00.917] I [ timer ] Timer: Total node execution : 48.159999994561076 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 25157 traces tagged "gauss"
FrameSaver: q=3.64253e+06 n=530778 tag=gauss
wclsFrameSaver: saving 31903 traces tagged "wiener"
FrameSaver: q=3.88791e+06 n=509254 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 1101 XUs and 1354 XVs -> 60 XUVs
C:0 T:1 7360 XUs and 6406 XVs -> 497 XUVs
C:0 T:2 301 XUs and 335 XVs -> 21 XUVs
C:0 T:3 994 XUs and 1640 XVs -> 61 XUVs
C:0 T:4 1722 XUs and 1509 XVs -> 136 XUVs
C:0 T:5 798 XUs and 979 XVs -> 44 XUVs
C:0 T:6 798 XUs and 583 XVs -> 29 XUVs
C:0 T:7 1154 XUs and 809 XVs -> 49 XUVs
897 XUVs total
605 collection wire objects
897 potential space points
Neighbour search...
15957 tests to find 4868 neighbours
Iterating with no regularization...
Begin: 7.45027e+08
0 6.88236e+08
1 6.87094e+08
2 6.87088e+08
Now with regularization...
Begin: 6.71748e+08
0 6.71717e+08
BdtBeamParticleIdTool::SliceFeatures::GetLeadingCaloHits - empty calo hit list
18-Sep-2025 21:09:41 BST Closed output file "np02vd_raw_run039499_0003_df-s04-d3_dw_0_20250918T174856_reco_stage1_20250918T200941_keepup.root"
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 110.616 175.355 613.384 150.077 95.3684 41
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 8.0622e-05 0.00010494 0.000275909 9.3035e-05 3.87241e-05 41
produce:tpcrawdecoder:PDVDTPCReader 24.4534 38.9914 59.0325 36.8597 8.59601 41
produce:triggerrawdecoder:PDVDTriggerReader4 0.385681 0.448937 0.642252 0.422561 0.0607001 41
produce:pdvddaphne:DAPHNEReaderPDVD 6.58222 9.27329 12.5355 9.19635 1.6378 41
produce:ophit:OpHitFinder 0.0548216 0.0653777 0.0763163 0.0656176 0.0047701 41
produce:opflash:OpFlashFinderVerticalDrift 0.00961359 0.0176293 0.0241623 0.0179742 0.00330144 41
produce:wclsdatavd:WireCellToolkit 44.2801 60.713 94.714 53.3167 14.7884 41
produce:gaushit:GausHitFinder 0.424249 0.987188 2.2175 0.992272 0.304409 41
produce:nhitsfilter:NumberOfHitsFilter 0.000106241 0.000211878 0.000484984 0.000204935 7.30654e-05 41
produce:reco3d:SpacePointSolver 1.85637 8.93101 33.2693 8.27918 5.3519 41
produce:hitpdune:DisambigFromSpacePoints 0.0240229 0.144771 0.758827 0.108755 0.13525 41
produce:pandora:StandardPandora 5.29021 51.1522 467.289 25.0727 83.4917 41
produce:pandoraTrack:LArPandoraTrackCreation 0.127334 0.584333 3.9893 0.4238 0.620138 41
produce:pandoraGnocalo:GnocchiCalorimetry 0.0120459 0.0289381 0.0619519 0.0274411 0.00981177 41
[art]:TriggerResults:TriggerResultInserter 2.092e-05 3.01964e-05 8.1103e-05 2.7662e-05 9.50328e-06 41
end_path:out1:RootOutput 3.767e-06 5.48588e-06 2.8323e-05 4.909e-06 3.65385e-06 41
end_path:out1:RootOutput(write) 3.49476 3.99354 4.78469 3.93569 0.292638 41
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 5499.08 MB
Peak resident set size usage (VmHWM): 3578.75 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run039499_0003_df-s04-d3_dw_0_20250918T174856_reco_stage1_20250918T200941_keepup.root
\tHists: np02vd_raw_run039499_0003_df-s04-d3_dw_0_20250918T174856_reco_stage1_20250918T200941_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run039499_0003_df-s04-d3_dw_0_20250918T174856_reco_stage1_20250918T200941_keepup.root
Ran successfully
{
"name": "np02vd_raw_run039499_0003_df-s04-d3_dw_0_20250918T174856_reco_stage1_20250918T200941_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": 1758226182.0,
"core.end_time": 1758226182.0,
"core.events": [
740,
746,
752,
758,
764,
770,
776,
782,
788,
794,
800,
806,
812,
818,
824,
830,
836,
842,
848,
854,
860,
866,
872,
878,
884,
890,
896,
902,
908,
914,
920,
926,
932,
938,
944,
950,
956,
962,
968,
974,
980
],
"core.event_count": 41,
"core.first_event_number": 740,
"core.last_event_number": 980,
"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_0003_df-s04-d3_dw_0_20250918T174856.hdf5"
}
]
}Forming hist metadata
formed
{
"name": "np02vd_raw_run039499_0003_df-s04-d3_dw_0_20250918T174856_reco_stage1_20250918T200941_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": 1758226182.0,
"core.end_time": 1758226182.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_0003_df-s04-d3_dw_0_20250918T174856.hdf5"
}
]
} 