Jobsub ID 48268.1@dunegpschedd01.fnal.gov
Jobscript log (last 10,000 characters)
D [ glue ] <FrameFanin:nfsp> EOS at call=95 with 8
[11:33:27.801] D [ glue ] frame sink sees EOS
[11:33:27.801] D [ pgraph ] <Pgrapher:> graph execution complete
[11:33:27.801] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 10.35 sec
[11:33:27.801] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 9.91 sec
[11:33:27.801] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.78 sec
[11:33:27.801] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.64 sec
[11:33:27.801] I [ timer ] Timer: WireCell::Aux::Resampler : 0.61 sec
[11:33:27.801] I [ timer ] Timer: WireCell::Aux::Resampler : 0.61 sec
[11:33:27.801] I [ timer ] Timer: WireCell::Aux::Resampler : 0.59 sec
[11:33:27.801] I [ timer ] Timer: WireCell::Aux::Resampler : 0.45 sec
[11:33:27.801] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[11:33:27.801] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.01 sec
[11:33:27.801] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[11:33:27.801] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[11:33:27.801] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[11:33:27.801] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[11:33:27.801] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[11:33:27.801] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[11:33:27.801] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[11:33:27.801] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[11:33:27.801] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[11:33:27.801] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[11:33:27.801] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[11:33:27.801] I [ timer ] Timer: WireCell::Gen::Retagger : 0 sec
[11:33:27.801] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0 sec
[11:33:27.801] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[11:33:27.801] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[11:33:27.801] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[11:33:27.801] I [ timer ] Timer: Total node execution : 39.960000295192 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 20573 traces tagged "gauss"
FrameSaver: q=3.19115e+06 n=482109 tag=gauss
wclsFrameSaver: saving 25648 traces tagged "wiener"
FrameSaver: q=3.4977e+06 n=470438 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 10711 XUs and 12738 XVs -> 943 XUVs
C:0 T:1 2811 XUs and 3369 XVs -> 196 XUVs
C:0 T:2 1701 XUs and 1248 XVs -> 65 XUVs
C:0 T:3 355 XUs and 458 XVs -> 36 XUVs
C:0 T:4 478 XUs and 497 XVs -> 4 XUVs
C:0 T:5 885 XUs and 786 XVs -> 37 XUVs
C:0 T:6 341 XUs and 310 XVs -> 9 XUVs
C:0 T:7 1473 XUs and 1135 XVs -> 32 XUVs
1322 XUVs total
715 collection wire objects
1322 potential space points
Neighbour search...
44784 tests to find 12748 neighbours
Iterating with no regularization...
Begin: 5.32947e+08
0 4.96004e+08
1 4.94233e+08
2 4.94177e+08
Now with regularization...
Begin: 4.79489e+08
0 4.7946e+08
BdtBeamParticleIdTool::SliceFeatures::GetLeadingCaloHits - empty calo hit list
18-Sep-2025 11:34:07 BST Closed output file "np02vd_raw_run039433_0369_df-s05-d2_dw_0_20250918T063013_reco_stage1_20250918T103407_keepup.root"
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 89.0151 141.832 244.734 131.352 36.9916 48
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 8.4519e-05 0.000110417 0.000330443 0.000100048 3.75643e-05 48
produce:tpcrawdecoder:PDVDTPCReader 31.6639 41.7815 65.6105 40.2648 7.11559 48
produce:triggerrawdecoder:PDVDTriggerReader4 0.380352 0.432194 0.628247 0.416499 0.0529207 48
produce:pdvddaphne:DAPHNEReaderPDVD 6.04648 10.4695 14.5318 10.4045 1.65606 48
produce:ophit:OpHitFinder 0.0533264 0.0687525 0.0847665 0.0698093 0.00670847 48
produce:opflash:OpFlashFinderVerticalDrift 0.00663681 0.0178979 0.0316537 0.0176107 0.00508401 48
produce:wclsdatavd:WireCellToolkit 30.8581 48.3181 86.073 42.1059 13.9594 48
produce:gaushit:GausHitFinder 0.480672 0.929553 1.4726 0.894205 0.271375 48
produce:nhitsfilter:NumberOfHitsFilter 0.000111611 0.000227692 0.000647852 0.000198575 0.000101256 48
produce:reco3d:SpacePointSolver 2.61366 7.52651 17.223 6.56647 3.35959 48
produce:hitpdune:DisambigFromSpacePoints 0.0466595 0.11768 0.358619 0.0873496 0.0780995 48
produce:pandora:StandardPandora 7.11302 28.0015 121.973 19.6304 23.5289 48
produce:pandoraTrack:LArPandoraTrackCreation 0.120297 0.445718 1.22386 0.340809 0.254838 48
produce:pandoraGnocalo:GnocchiCalorimetry 0.0122057 0.0255327 0.0510502 0.0250854 0.00771379 48
[art]:TriggerResults:TriggerResultInserter 1.9046e-05 3.28559e-05 6.6926e-05 2.9651e-05 1.07334e-05 48
end_path:out1:RootOutput 4.098e-06 5.86775e-06 2.5909e-05 5.4255e-06 2.97635e-06 48
end_path:out1:RootOutput(write) 2.92238 3.6726 6.34735 3.50661 0.596884 48
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 4422.82 MB
Peak resident set size usage (VmHWM): 2484.08 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run039433_0369_df-s05-d2_dw_0_20250918T063013_reco_stage1_20250918T103407_keepup.root
\tHists: np02vd_raw_run039433_0369_df-s05-d2_dw_0_20250918T063013_reco_stage1_20250918T103407_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run039433_0369_df-s05-d2_dw_0_20250918T063013_reco_stage1_20250918T103407_keepup.root
Ran successfully
{
"name": "np02vd_raw_run039433_0369_df-s05-d2_dw_0_20250918T063013_reco_stage1_20250918T103407_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": 1758191648.0,
"core.end_time": 1758191648.0,
"core.events": [
105836,
105842,
105848,
105854,
105860,
105866,
105872,
105878,
105884,
105890,
105896,
105902,
105908,
105914,
105920,
105926,
105932,
105938,
105944,
105950,
105956,
105962,
105968,
105974,
105980,
105986,
105992,
105998,
106004,
106010,
106016,
106022,
106028,
106034,
106040,
106046,
106052,
106058,
106064,
106070,
106076,
106082,
106088,
106094,
106100,
106106,
106112,
106118
],
"core.event_count": 48,
"core.first_event_number": 105836,
"core.last_event_number": 106118,
"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_0369_df-s05-d2_dw_0_20250918T063013.hdf5"
}
]
}Forming hist metadata
formed
{
"name": "np02vd_raw_run039433_0369_df-s05-d2_dw_0_20250918T063013_reco_stage1_20250918T103407_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": 1758191648.0,
"core.end_time": 1758191648.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_0369_df-s05-d2_dw_0_20250918T063013.hdf5"
}
]
} 