Jobsub ID 41596.138@dunegpschedd02.fnal.gov
Jobscript log (last 10,000 characters)
[10:28:43.690] D [sigproc ] <OmnibusSigProc:anode0sigproc0> EOS at call=95 anode=0
[10:28:43.690] D [ glue ] <FrameFanin:nfsp> EOS at call=95 with 8
[10:28:43.690] D [ glue ] frame sink sees EOS
[10:28:43.690] D [ pgraph ] <Pgrapher:> graph execution complete
[10:28:43.690] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 25.88 sec
[10:28:43.690] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 24.82 sec
[10:28:43.690] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 23.27 sec
[10:28:43.691] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 21.74 sec
[10:28:43.691] I [ timer ] Timer: WireCell::Aux::Resampler : 1.66 sec
[10:28:43.691] I [ timer ] Timer: WireCell::Aux::Resampler : 1.62 sec
[10:28:43.691] I [ timer ] Timer: WireCell::Aux::Resampler : 1.61 sec
[10:28:43.691] I [ timer ] Timer: WireCell::Aux::Resampler : 1.52 sec
[10:28:43.691] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.03 sec
[10:28:43.691] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.03 sec
[10:28:43.691] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[10:28:43.691] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[10:28:43.691] I [ timer ] Timer: WireCell::Gen::Retagger : 0.01 sec
[10:28:43.691] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0.01 sec
[10:28:43.691] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[10:28:43.691] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[10:28:43.691] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[10:28:43.691] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[10:28:43.691] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[10:28:43.691] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[10:28:43.692] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[10:28:43.692] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[10:28:43.692] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[10:28:43.692] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[10:28:43.692] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[10:28:43.692] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[10:28:43.692] I [ timer ] Timer: Total node execution : 102.21999904885888 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 17759 traces tagged "gauss"
FrameSaver: q=2.81295e+06 n=380008 tag=gauss
wclsFrameSaver: saving 22437 traces tagged "wiener"
FrameSaver: q=3.06212e+06 n=367456 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 455 XUs and 425 XVs -> 8 XUVs
C:0 T:1 1501 XUs and 1231 XVs -> 56 XUVs
C:0 T:2 586 XUs and 992 XVs -> 36 XUVs
C:0 T:3 123 XUs and 204 XVs -> 4 XUVs
C:0 T:4 146 XUs and 190 XVs -> 5 XUVs
C:0 T:5 489 XUs and 469 XVs -> 61 XUVs
C:0 T:6 2107 XUs and 1941 XVs -> 146 XUVs
C:0 T:7 11653 XUs and 9971 XVs -> 857 XUVs
1173 XUVs total
569 collection wire objects
1173 potential space points
Neighbour search...
36295 tests to find 10412 neighbours
Iterating with no regularization...
Begin: 7.12065e+08
0 6.14881e+08
1 6.04408e+08
2 6.03383e+08
3 6.03252e+08
Now with regularization...
Begin: 5.8888e+08
0 5.88768e+08
18-Sep-2025 10:29:57 BST Closed output file "np02vd_raw_run039433_0324_df-s05-d1_dw_0_20250918T044016_reco_stage1_20250918T092957_keepup.root"
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 170.588 277.915 874.874 238.84 128.683 48
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 0.000222689 0.00034943 0.000755182 0.000310929 0.000117776 48
produce:tpcrawdecoder:PDVDTPCReader 16.5418 18.2811 25.5878 17.463 2.27699 48
produce:triggerrawdecoder:PDVDTriggerReader4 0.312752 0.334317 0.492581 0.32731 0.0266342 48
produce:pdvddaphne:DAPHNEReaderPDVD 12.9112 14.0962 15.5314 14.0937 0.596584 48
produce:ophit:OpHitFinder 0.140088 0.18059 0.232972 0.177904 0.0164376 48
produce:opflash:OpFlashFinderVerticalDrift 0.0187009 0.0463325 0.0820972 0.0420051 0.0145573 48
produce:wclsdatavd:WireCellToolkit 99.9007 127.976 231.77 111.932 31.5909 48
produce:gaushit:GausHitFinder 1.62947 2.9998 6.31798 2.86875 0.929309 48
produce:nhitsfilter:NumberOfHitsFilter 0.000263095 0.000467996 0.00104536 0.000449938 0.000141346 48
produce:reco3d:SpacePointSolver 6.87576 17.1177 44.4556 15.5378 7.78294 48
produce:hitpdune:DisambigFromSpacePoints 0.111013 0.387018 1.39649 0.336377 0.260077 48
produce:pandora:StandardPandora 18.6998 85.8969 667.789 57.5324 112.89 48
produce:pandoraTrack:LArPandoraTrackCreation 0.51555 1.46668 5.84956 1.25432 0.991503 48
produce:pandoraGnocalo:GnocchiCalorimetry 0.043995 0.0763776 0.128655 0.0743575 0.0193712 48
[art]:TriggerResults:TriggerResultInserter 5.569e-05 7.73188e-05 0.000185701 7.4953e-05 1.91754e-05 48
end_path:out1:RootOutput 1.684e-05 2.45164e-05 7.4933e-05 2.37415e-05 7.60734e-06 48
end_path:out1:RootOutput(write) 7.82192 9.00097 12.1252 8.70984 1.08111 48
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 5397.62 MB
Peak resident set size usage (VmHWM): 3493.92 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run039433_0324_df-s05-d1_dw_0_20250918T044016_reco_stage1_20250918T092957_keepup.root
\tHists: np02vd_raw_run039433_0324_df-s05-d1_dw_0_20250918T044016_reco_stage1_20250918T092959_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run039433_0324_df-s05-d1_dw_0_20250918T044016_reco_stage1_20250918T092957_keepup.root
Ran successfully
{
"name": "np02vd_raw_run039433_0324_df-s05-d1_dw_0_20250918T044016_reco_stage1_20250918T092957_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": 1758187800.0,
"core.end_time": 1758187800.0,
"core.events": [
92911,
92917,
92923,
92929,
92935,
92941,
92947,
92953,
92959,
92965,
92971,
92977,
92983,
92989,
92995,
93001,
93007,
93013,
93019,
93025,
93031,
93037,
93043,
93049,
93055,
93061,
93067,
93073,
93079,
93085,
93091,
93097,
93103,
93109,
93115,
93121,
93127,
93133,
93139,
93145,
93151,
93157,
93163,
93169,
93175,
93181,
93187,
93193
],
"core.event_count": 48,
"core.first_event_number": 92911,
"core.last_event_number": 93193,
"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_0324_df-s05-d1_dw_0_20250918T044016.hdf5"
}
]
}Forming hist metadata
formed
{
"name": "np02vd_raw_run039433_0324_df-s05-d1_dw_0_20250918T044016_reco_stage1_20250918T092959_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": 1758187800.0,
"core.end_time": 1758187800.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_0324_df-s05-d1_dw_0_20250918T044016.hdf5"
}
]
} 