Jobsub ID 41596.143@dunegpschedd02.fnal.gov
Jobscript log (last 10,000 characters)
Proc:anode0sigproc0> EOS at call=95 anode=0
[09:13:19.085] D [ glue ] <FrameFanin:nfsp> EOS at call=95 with 8
[09:13:19.085] D [ glue ] frame sink sees EOS
[09:13:19.085] D [ pgraph ] <Pgrapher:> graph execution complete
[09:13:19.085] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.66 sec
[09:13:19.085] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.79 sec
[09:13:19.085] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.08 sec
[09:13:19.085] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 6.49 sec
[09:13:19.085] I [ timer ] Timer: WireCell::Aux::Resampler : 0.18 sec
[09:13:19.085] I [ timer ] Timer: WireCell::Aux::Resampler : 0.18 sec
[09:13:19.085] I [ timer ] Timer: WireCell::Aux::Resampler : 0.18 sec
[09:13:19.085] I [ timer ] Timer: WireCell::Aux::Resampler : 0.18 sec
[09:13:19.085] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.01 sec
[09:13:19.085] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[09:13:19.085] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[09:13:19.085] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[09:13:19.085] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[09:13:19.085] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[09:13:19.085] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[09:13:19.085] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[09:13:19.085] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[09:13:19.085] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[09:13:19.085] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[09:13:19.085] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[09:13:19.085] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[09:13:19.085] I [ timer ] Timer: WireCell::Gen::Retagger : 0 sec
[09:13:19.085] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0 sec
[09:13:19.085] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[09:13:19.085] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[09:13:19.085] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[09:13:19.085] I [ timer ] Timer: Total node execution : 30.749999532476068 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 22073 traces tagged "gauss"
FrameSaver: q=6.10182e+06 n=569927 tag=gauss
wclsFrameSaver: saving 27702 traces tagged "wiener"
FrameSaver: q=6.49023e+06 n=552343 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 51 XUs and 60 XVs -> 1 XUVs
C:0 T:1 540 XUs and 1104 XVs -> 31 XUVs
C:0 T:2 3731 XUs and 4463 XVs -> 237 XUVs
C:0 T:3 19139 XUs and 23947 XVs -> 1784 XUVs
C:0 T:4 1154 XUs and 1426 XVs -> 53 XUVs
C:0 T:5 1077 XUs and 869 XVs -> 49 XUVs
C:0 T:6 573 XUs and 752 XVs -> 44 XUVs
C:0 T:7 715 XUs and 1036 XVs -> 18 XUVs
2217 XUVs total
1222 collection wire objects
2217 potential space points
Neighbour search...
64845 tests to find 16562 neighbours
Iterating with no regularization...
Begin: 2.34109e+10
0 2.29557e+10
1 2.29424e+10
Now with regularization...
Begin: 2.25349e+10
0 2.25348e+10
BdtBeamParticleIdTool::SliceFeatures::GetLeadingCaloHits - empty calo hit list
18-Sep-2025 09:13:53 CEST Closed output file "np02vd_raw_run039433_0323_df-s05-d2_dw_0_20250918T043826_reco_stage1_20250918T071353_keepup.root"
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 71.2792 110.512 278.295 98.0459 34.2783 48
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 5.1407e-05 6.65086e-05 0.000200242 6.34805e-05 2.09708e-05 48
produce:tpcrawdecoder:PDVDTPCReader 25.0713 45.516 84.7361 44.2893 13.9259 48
produce:triggerrawdecoder:PDVDTriggerReader4 0.309475 0.405341 1.00413 0.365627 0.126285 48
produce:pdvddaphne:DAPHNEReaderPDVD 6.54598 11.3796 17.4418 11.1993 2.58409 48
produce:ophit:OpHitFinder 0.0275928 0.0392669 0.0690285 0.039196 0.00644286 48
produce:opflash:OpFlashFinderVerticalDrift 0.00413492 0.00848531 0.0149341 0.00836786 0.00242458 48
produce:wclsdatavd:WireCellToolkit 21.4121 31.0668 95.9174 25.5014 12.2642 48
produce:gaushit:GausHitFinder 0.291411 0.537105 1.32041 0.509744 0.169205 48
produce:nhitsfilter:NumberOfHitsFilter 7.8529e-05 0.000143162 0.00100919 0.000109268 0.00013624 48
produce:reco3d:SpacePointSolver 1.34237 4.4555 13.4167 4.19126 1.99453 48
produce:hitpdune:DisambigFromSpacePoints 0.0193108 0.0573761 0.224811 0.0486891 0.0354801 48
produce:pandora:StandardPandora 3.7222 14.7715 84.9904 10.6566 14.9929 48
produce:pandoraTrack:LArPandoraTrackCreation 0.0551303 0.224423 0.641596 0.200322 0.126571 48
produce:pandoraGnocalo:GnocchiCalorimetry 0.00611822 0.012125 0.0212826 0.0120068 0.00325963 48
[art]:TriggerResults:TriggerResultInserter 1.4588e-05 2.12167e-05 6.5705e-05 1.8686e-05 8.81194e-06 48
end_path:out1:RootOutput 3.396e-06 4.43904e-06 1.9426e-05 4.132e-06 2.21818e-06 48
end_path:out1:RootOutput(write) 1.7773 2.02296 2.62678 1.96349 0.223636 48
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 6856.19 MB
Peak resident set size usage (VmHWM): 4974.33 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run039433_0323_df-s05-d2_dw_0_20250918T043826_reco_stage1_20250918T071353_keepup.root
\tHists: np02vd_raw_run039433_0323_df-s05-d2_dw_0_20250918T043826_reco_stage1_20250918T071354_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run039433_0323_df-s05-d2_dw_0_20250918T043826_reco_stage1_20250918T071353_keepup.root
Ran successfully
{
"name": "np02vd_raw_run039433_0323_df-s05-d2_dw_0_20250918T043826_reco_stage1_20250918T071353_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": 1758179634.0,
"core.end_time": 1758179634.0,
"core.events": [
92678,
92684,
92690,
92696,
92702,
92708,
92714,
92720,
92726,
92732,
92738,
92744,
92750,
92756,
92762,
92768,
92774,
92780,
92786,
92792,
92798,
92804,
92810,
92816,
92822,
92828,
92834,
92840,
92846,
92852,
92858,
92864,
92870,
92876,
92882,
92888,
92894,
92900,
92906,
92912,
92918,
92924,
92930,
92936,
92942,
92948,
92954,
92960
],
"core.event_count": 48,
"core.first_event_number": 92678,
"core.last_event_number": 92960,
"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_0323_df-s05-d2_dw_0_20250918T043826.hdf5"
}
]
}Forming hist metadata
formed
{
"name": "np02vd_raw_run039433_0323_df-s05-d2_dw_0_20250918T043826_reco_stage1_20250918T071354_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": 1758179634.0,
"core.end_time": 1758179634.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_0323_df-s05-d2_dw_0_20250918T043826.hdf5"
}
]
} 