Jobsub ID 41541.102@dunegpschedd02.fnal.gov
Jobscript log (last 10,000 characters)
proc ] <OmnibusSigProc:anode0sigproc0> EOS at call=95 anode=0
[10:22:43.226] D [ glue ] <FrameFanin:nfsp> EOS at call=95 with 8
[10:22:43.226] D [ glue ] frame sink sees EOS
[10:22:43.226] D [ pgraph ] <Pgrapher:> graph execution complete
[10:22:43.226] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 15.16 sec
[10:22:43.226] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 14.15 sec
[10:22:43.226] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 13.93 sec
[10:22:43.226] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 13.45 sec
[10:22:43.226] I [ timer ] Timer: WireCell::Aux::Resampler : 2.02 sec
[10:22:43.226] I [ timer ] Timer: WireCell::Aux::Resampler : 1.92 sec
[10:22:43.226] I [ timer ] Timer: WireCell::Aux::Resampler : 1.87 sec
[10:22:43.226] I [ timer ] Timer: WireCell::Aux::Resampler : 1.86 sec
[10:22:43.226] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[10:22:43.226] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.01 sec
[10:22:43.226] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[10:22:43.226] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[10:22:43.226] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[10:22:43.226] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[10:22:43.226] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[10:22:43.226] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[10:22:43.226] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[10:22:43.226] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[10:22:43.226] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[10:22:43.226] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[10:22:43.226] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[10:22:43.226] I [ timer ] Timer: WireCell::Gen::Retagger : 0 sec
[10:22:43.226] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0 sec
[10:22:43.226] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[10:22:43.226] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[10:22:43.226] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[10:22:43.226] I [ timer ] Timer: Total node execution : 64.3899995367974 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 13296 traces tagged "gauss"
FrameSaver: q=1.65947e+06 n=296641 tag=gauss
wclsFrameSaver: saving 16036 traces tagged "wiener"
FrameSaver: q=1.73558e+06 n=289903 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 250 XUs and 291 XVs -> 9 XUVs
C:0 T:1 265 XUs and 476 XVs -> 8 XUVs
C:0 T:2 563 XUs and 759 XVs -> 24 XUVs
C:0 T:3 40 XUs and 40 XVs -> 0 XUVs
C:0 T:4 644 XUs and 797 XVs -> 29 XUVs
C:0 T:5 279 XUs and 332 XVs -> 11 XUVs
C:0 T:6 383 XUs and 737 XVs -> 23 XUVs
C:0 T:7 395 XUs and 451 XVs -> 13 XUVs
117 XUVs total
111 collection wire objects
117 potential space points
Neighbour search...
223 tests to find 86 neighbours
Iterating with no regularization...
Begin: 1.30562e+07
0 1.2963e+07
1 1.2963e+07
Now with regularization...
Begin: 1.27588e+07
0 1.27588e+07
BdtBeamParticleIdTool::SliceFeatures::GetLeadingCaloHits - empty calo hit list
18-Sep-2025 10:23:02 CEST Closed output file "np02vd_raw_run039433_0294_df-s05-d2_dw_0_20250918T032851_reco_stage1_20250918T082302_keepup.root"
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 73.2869 311.673 9291.34 115.821 1310.44 48
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 6.2101e-05 0.000107341 0.000241491 9.63075e-05 3.37767e-05 48
produce:tpcrawdecoder:PDVDTPCReader 5.77521 12.7227 51.7817 10.408 7.97543 48
produce:triggerrawdecoder:PDVDTriggerReader4 0.174951 0.407708 0.478673 0.416639 0.0613359 48
produce:pdvddaphne:DAPHNEReaderPDVD 5.25277 6.57068 11.0955 6.27886 1.09675 48
produce:ophit:OpHitFinder 0.0357768 0.060222 0.0694616 0.0614335 0.00633894 48
produce:opflash:OpFlashFinderVerticalDrift 0.00588174 0.0189015 0.0281522 0.0189128 0.00496826 48
produce:wclsdatavd:WireCellToolkit 37.0186 60.8532 143.751 50.8685 22.2744 48
produce:gaushit:GausHitFinder 0.306295 1.05501 4.70475 0.980449 0.589397 48
produce:nhitsfilter:NumberOfHitsFilter 8.8692e-05 0.000197669 0.000749811 0.000174995 0.000100629 48
produce:reco3d:SpacePointSolver 1.60688 7.92196 54.6127 6.33655 7.49372 48
produce:hitpdune:DisambigFromSpacePoints 0.0129866 0.20678 2.08426 0.136921 0.297287 48
produce:pandora:StandardPandora 4.69049 217.514 9057.59 22.2551 1289.64 48
produce:pandoraTrack:LArPandoraTrackCreation 0.162533 0.678004 5.23134 0.513889 0.72529 48
produce:pandoraGnocalo:GnocchiCalorimetry 0.0136689 0.028066 0.126058 0.0252858 0.0158486 48
[art]:TriggerResults:TriggerResultInserter 2.8207e-05 3.7848e-05 6.0942e-05 3.70185e-05 7.13952e-06 48
end_path:out1:RootOutput 4.337e-06 6.10294e-06 2.1973e-05 5.244e-06 3.31878e-06 48
end_path:out1:RootOutput(write) 2.35693 3.61733 5.31131 3.4795 0.543549 48
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 7476.92 MB
Peak resident set size usage (VmHWM): 5589.73 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run039433_0294_df-s05-d2_dw_0_20250918T032851_reco_stage1_20250918T082302_keepup.root
\tHists: np02vd_raw_run039433_0294_df-s05-d2_dw_0_20250918T032851_reco_stage1_20250918T082302_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run039433_0294_df-s05-d2_dw_0_20250918T032851_reco_stage1_20250918T082302_keepup.root
Ran successfully
{
"name": "np02vd_raw_run039433_0294_df-s05-d2_dw_0_20250918T032851_reco_stage1_20250918T082302_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": 1758183783.0,
"core.end_time": 1758183783.0,
"core.events": [
84326,
84332,
84338,
84344,
84350,
84356,
84362,
84368,
84374,
84380,
84386,
84392,
84398,
84404,
84410,
84416,
84422,
84428,
84434,
84440,
84446,
84452,
84458,
84464,
84470,
84476,
84482,
84488,
84494,
84500,
84506,
84512,
84518,
84524,
84530,
84536,
84542,
84548,
84554,
84560,
84566,
84572,
84578,
84584,
84590,
84596,
84602,
84608
],
"core.event_count": 48,
"core.first_event_number": 84326,
"core.last_event_number": 84608,
"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_0294_df-s05-d2_dw_0_20250918T032851.hdf5"
}
]
}Forming hist metadata
formed
{
"name": "np02vd_raw_run039433_0294_df-s05-d2_dw_0_20250918T032851_reco_stage1_20250918T082302_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": 1758183783.0,
"core.end_time": 1758183783.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_0294_df-s05-d2_dw_0_20250918T032851.hdf5"
}
]
}