Jobsub ID 49050.30@dunegpschedd01.fnal.gov
Jobscript log (last 10,000 characters)
D [ glue ] <FrameFanin:nfsp> EOS at call=81 with 8
[23:57:39.066] D [ glue ] frame sink sees EOS
[23:57:39.066] D [ pgraph ] <Pgrapher:> graph execution complete
[23:57:39.066] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.29 sec
[23:57:39.066] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.66 sec
[23:57:39.066] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.63 sec
[23:57:39.066] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 6.4 sec
[23:57:39.066] I [ timer ] Timer: WireCell::Aux::Resampler : 0.28 sec
[23:57:39.066] I [ timer ] Timer: WireCell::Aux::Resampler : 0.28 sec
[23:57:39.066] I [ timer ] Timer: WireCell::Aux::Resampler : 0.27 sec
[23:57:39.066] I [ timer ] Timer: WireCell::Aux::Resampler : 0.27 sec
[23:57:39.066] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[23:57:39.066] I [ timer ] Timer: WireCell::Gen::Retagger : 0.01 sec
[23:57:39.066] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[23:57:39.066] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0 sec
[23:57:39.066] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[23:57:39.066] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[23:57:39.066] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[23:57:39.066] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[23:57:39.066] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[23:57:39.066] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[23:57:39.066] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[23:57:39.066] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[23:57:39.066] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[23:57:39.066] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[23:57:39.066] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[23:57:39.066] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0 sec
[23:57:39.066] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[23:57:39.066] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[23:57:39.066] I [ timer ] Timer: Total node execution : 31.10000004246831 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 22221 traces tagged "gauss"
FrameSaver: q=3.8385e+06 n=500286 tag=gauss
wclsFrameSaver: saving 27434 traces tagged "wiener"
FrameSaver: q=4.13015e+06 n=487197 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 81 XUs and 96 XVs -> 5 XUVs
C:0 T:1 219 XUs and 387 XVs -> 17 XUVs
C:0 T:2 7867 XUs and 8235 XVs -> 582 XUVs
C:0 T:3 1517 XUs and 1144 XVs -> 49 XUVs
C:0 T:4 1304 XUs and 1521 XVs -> 126 XUVs
C:0 T:5 1831 XUs and 1884 XVs -> 121 XUVs
C:0 T:6 1178 XUs and 1499 XVs -> 40 XUVs
C:0 T:7 360 XUs and 472 XVs -> 27 XUVs
967 XUVs total
626 collection wire objects
967 potential space points
Neighbour search...
24549 tests to find 6712 neighbours
Iterating with no regularization...
Begin: 1.88027e+09
0 1.84872e+09
1 1.8473e+09
Now with regularization...
Begin: 1.81268e+09
0 1.81263e+09
BdtBeamParticleIdTool::SliceFeatures::GetLeadingCaloHits - empty calo hit list
BdtBeamParticleIdTool::SliceFeatures::GetLeadingCaloHits - empty calo hit list
BdtBeamParticleIdTool::SliceFeatures::GetLeadingCaloHits - empty calo hit list
18-Sep-2025 23:58:03 CEST Closed output file "np02vd_raw_run039499_0042_df-s05-d4_dw_0_20250918T190710_reco_stage1_20250918T215803_keepup.root"
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 50.3795 123.144 1029.1 73.131 170.477 41
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 6.859e-05 0.000186712 0.00243326 8.615e-05 0.00039142 41
produce:tpcrawdecoder:PDVDTPCReader 5.08115 5.73921 7.85427 5.44029 0.69536 41
produce:triggerrawdecoder:PDVDTriggerReader4 0.263053 0.268385 0.302987 0.26639 0.00662027 41
produce:pdvddaphne:DAPHNEReaderPDVD 2.37523 3.2049 3.70743 3.22678 0.248949 41
produce:ophit:OpHitFinder 0.0410479 0.0508663 0.09309 0.0499401 0.00812968 41
produce:opflash:OpFlashFinderVerticalDrift 0.0052891 0.0133801 0.0371863 0.0125042 0.00456654 41
produce:wclsdatavd:WireCellToolkit 26.3265 39.0786 91.073 34.0017 12.8263 41
produce:gaushit:GausHitFinder 0.328774 0.73247 1.65467 0.69913 0.250653 41
produce:nhitsfilter:NumberOfHitsFilter 0.00010549 0.000175315 0.00044638 0.00016574 5.95058e-05 41
produce:reco3d:SpacePointSolver 2.19915 6.94166 25.6123 6.12676 4.00958 41
produce:hitpdune:DisambigFromSpacePoints 0.0199556 0.113042 0.588159 0.0778355 0.100433 41
produce:pandora:StandardPandora 3.89962 63.5475 930.123 19.9528 158.914 41
produce:pandoraTrack:LArPandoraTrackCreation 0.116576 0.392082 2.06491 0.295809 0.322036 41
produce:pandoraGnocalo:GnocchiCalorimetry 0.0101317 0.017796 0.0312442 0.0170304 0.004505 41
[art]:TriggerResults:TriggerResultInserter 1.455e-05 2.67625e-05 4.773e-05 2.535e-05 6.26509e-06 41
end_path:out1:RootOutput 4.79e-06 8.84146e-06 2.253e-05 8.48e-06 2.90125e-06 41
end_path:out1:RootOutput(write) 2.02549 3.02579 4.10072 2.90838 0.384789 41
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 7363.9 MB
Peak resident set size usage (VmHWM): 5451.05 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run039499_0042_df-s05-d4_dw_0_20250918T190710_reco_stage1_20250918T215803_keepup.root
\tHists: np02vd_raw_run039499_0042_df-s05-d4_dw_0_20250918T190710_reco_stage1_20250918T215803_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run039499_0042_df-s05-d4_dw_0_20250918T190710_reco_stage1_20250918T215803_keepup.root
Ran successfully
{
"name": "np02vd_raw_run039499_0042_df-s05-d4_dw_0_20250918T190710_reco_stage1_20250918T215803_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": 1758232684.0,
"core.end_time": 1758232684.0,
"core.events": [
10228,
10234,
10240,
10246,
10252,
10258,
10264,
10270,
10276,
10282,
10288,
10294,
10300,
10306,
10312,
10318,
10324,
10330,
10336,
10342,
10348,
10354,
10360,
10366,
10372,
10378,
10384,
10390,
10396,
10402,
10408,
10414,
10420,
10426,
10432,
10438,
10444,
10450,
10456,
10462,
10468
],
"core.event_count": 41,
"core.first_event_number": 10228,
"core.last_event_number": 10468,
"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_0042_df-s05-d4_dw_0_20250918T190710.hdf5"
}
]
}Forming hist metadata
formed
{
"name": "np02vd_raw_run039499_0042_df-s05-d4_dw_0_20250918T190710_reco_stage1_20250918T215803_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": 1758232684.0,
"core.end_time": 1758232684.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_0042_df-s05-d4_dw_0_20250918T190710.hdf5"
}
]
}