Jobsub ID 38203.47@dunegpschedd02.fnal.gov
Jobscript log (last 10,000 characters)
igProc:anode0sigproc0> EOS at call=37 anode=0
[14:02:39.528] D [ glue ] <FrameFanin:nfsp> EOS at call=37 with 8
[14:02:39.528] D [ glue ] frame sink sees EOS
[14:02:39.528] D [ pgraph ] <Pgrapher:> graph execution complete
[14:02:39.528] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.37 sec
[14:02:39.528] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.36 sec
[14:02:39.528] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.92 sec
[14:02:39.528] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.85 sec
[14:02:39.528] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.84 sec
[14:02:39.528] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.72 sec
[14:02:39.528] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.16 sec
[14:02:39.528] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 6.83 sec
[14:02:39.528] I [ timer ] Timer: WireCell::Aux::Resampler : 1.11 sec
[14:02:39.528] I [ timer ] Timer: WireCell::Aux::Resampler : 1.11 sec
[14:02:39.528] I [ timer ] Timer: WireCell::Aux::Resampler : 1.1 sec
[14:02:39.528] I [ timer ] Timer: WireCell::Aux::Resampler : 1.08 sec
[14:02:39.528] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[14:02:39.528] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.01 sec
[14:02:39.528] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[14:02:39.528] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[14:02:39.528] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[14:02:39.528] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[14:02:39.528] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[14:02:39.528] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[14:02:39.528] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[14:02:39.528] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[14:02:39.528] I [ timer ] Timer: WireCell::Gen::Retagger : 0 sec
[14:02:39.528] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0 sec
[14:02:39.528] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[14:02:39.528] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[14:02:39.528] I [ timer ] Timer: Total node execution : 66.47999933175743 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 46753 traces tagged "gauss"
FrameSaver: q=7.20784e+06 n=880383 tag=gauss
wclsFrameSaver: saving 56991 traces tagged "wiener"
FrameSaver: q=7.58786e+06 n=835403 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 354 XUs and 396 XVs -> 9 XUVs
C:0 T:1 3653 XUs and 4966 XVs -> 164 XUVs
C:0 T:2 960 XUs and 953 XVs -> 50 XUVs
C:0 T:3 323 XUs and 562 XVs -> 19 XUVs
C:0 T:4 563 XUs and 699 XVs -> 24 XUVs
C:0 T:5 579 XUs and 637 XVs -> 45 XUVs
C:0 T:6 91 XUs and 106 XVs -> 5 XUVs
C:0 T:7 381 XUs and 565 XVs -> 15 XUVs
C:0 T:8 3515 XUs and 4195 XVs -> 168 XUVs
C:0 T:9 848 XUs and 1490 XVs -> 84 XUVs
C:0 T:10 919 XUs and 1486 XVs -> 81 XUVs
C:0 T:11 4309 XUs and 4954 XVs -> 264 XUVs
C:0 T:12 1063 XUs and 1151 XVs -> 65 XUVs
C:0 T:13 3292 XUs and 3322 XVs -> 176 XUVs
C:0 T:14 1118 XUs and 1182 XVs -> 71 XUVs
C:0 T:15 1947 XUs and 2299 XVs -> 105 XUVs
1345 XUVs total
1164 collection wire objects
1345 potential space points
Neighbour search...
12253 tests to find 5832 neighbours
Iterating with no regularization...
Begin: 3.85292e+08
0 3.69485e+08
1 3.68845e+08
2 3.68839e+08
Now with regularization...
Begin: 3.64323e+08
0 3.64322e+08
BdtBeamParticleIdTool::SliceFeatures::GetLeadingCaloHits - empty calo hit list
11-Sep-2025 14:03:42 CEST Closed output file "np02vd_raw_run039350_2184_df-s04-d3_dw_0_20250911T104340_reco_stage1_20250911T120342_keepup.root"
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 45.9828 134.195 191.313 136.803 29.7948 19
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 6.2921e-05 0.000124772 0.000179263 0.000137022 3.69463e-05 19
produce:tpcrawdecoder:PDVDTPCReader 1.34165 6.77371 8.17838 6.89139 1.36375 19
produce:triggerrawdecoder:PDVDTriggerReader4 0.00664193 0.00873261 0.0221819 0.00798923 0.00327612 19
produce:pdvddaphne:DAPHNEReaderPDVD 1.95927 2.43437 2.80647 2.46003 0.247138 19
produce:ophit:OpHitFinder 0.0284707 0.0422111 0.055067 0.041625 0.00641887 19
produce:opflash:OpFlashFinderVerticalDrift 0.00592668 0.0104997 0.0148741 0.0112165 0.00289791 19
produce:wclsdatavd:WireCellToolkit 16.1662 62.3594 75.9646 63.3649 11.7325 19
produce:gaushit:GausHitFinder 0.722939 1.29721 1.92178 1.25095 0.369737 19
produce:nhitsfilter:NumberOfHitsFilter 0.000182254 0.000320082 0.000490139 0.000320946 9.35881e-05 19
produce:reco3d:SpacePointSolver 3.5675 12.7668 22.8961 12.3826 4.58636 19
produce:hitpdune:DisambigFromSpacePoints 0.0552587 0.173822 0.340083 0.16704 0.065352 19
produce:pandora:StandardPandora 18.6134 41.466 79.4403 37.4641 16.1925 19
produce:pandoraTrack:LArPandoraTrackCreation 0.326341 0.885112 1.43116 0.895841 0.260397 19
produce:pandoraGnocalo:GnocchiCalorimetry 0.018587 0.0344181 0.0548842 0.0357583 0.00880968 19
[art]:TriggerResults:TriggerResultInserter 1.922e-05 3.47123e-05 6.5322e-05 2.839e-05 1.28653e-05 19
end_path:out1:RootOutput 5.1e-06 1.00792e-05 3.1711e-05 8.55e-06 5.35412e-06 19
end_path:out1:RootOutput(write) 1.88014 5.91254 7.07229 6.22205 1.09007 19
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 4815.84 MB
Peak resident set size usage (VmHWM): 2879.06 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run039350_2184_df-s04-d3_dw_0_20250911T104340_reco_stage1_20250911T120342_keepup.root
\tHists: np02vd_raw_run039350_2184_df-s04-d3_dw_0_20250911T104340_reco_stage1_20250911T120342_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run039350_2184_df-s04-d3_dw_0_20250911T104340_reco_stage1_20250911T120342_keepup.root
Ran successfully
{
"name": "np02vd_raw_run039350_2184_df-s04-d3_dw_0_20250911T104340_reco_stage1_20250911T120342_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": 1757592222.0,
"core.end_time": 1757592222.0,
"core.events": [
159519,
159523,
159527,
159531,
159535,
159539,
159543,
159547,
159551,
159555,
159559,
159563,
159567,
159571,
159575,
159579,
159583,
159587,
159591
],
"core.event_count": 19,
"core.first_event_number": 159519,
"core.last_event_number": 159591,
"core.data_stream": "cosmics",
"core.file_content_status": "good",
"core.file_type": "detector",
"core.run_type": "vd-protodune",
"core.runs": [
39350
],
"core.runs_subruns": [
3935000001
],
"dune.daq_test": false,
"retention.status": "active",
"retention.class": "physics"
},
"parents": [
{
"did": "vd-protodune:np02vd_raw_run039350_2184_df-s04-d3_dw_0_20250911T104340.hdf5"
}
]
}Forming hist metadata
formed
{
"name": "np02vd_raw_run039350_2184_df-s04-d3_dw_0_20250911T104340_reco_stage1_20250911T120342_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": 1757592222.0,
"core.end_time": 1757592222.0,
"core.data_stream": "cosmics",
"core.file_content_status": "good",
"core.file_type": "detector",
"core.run_type": "vd-protodune",
"core.runs": [
39350
],
"core.runs_subruns": [
3935000001
],
"dune.daq_test": false,
"retention.status": "active",
"retention.class": "physics"
},
"parents": [
{
"did": "vd-protodune:np02vd_raw_run039350_2184_df-s04-d3_dw_0_20250911T104340.hdf5"
}
]
}