Jobsub ID 47676.99@dunegpschedd01.fnal.gov
Jobscript log (last 10,000 characters)
fsp> EOS at call=37 with 8
[20:58:14.583] D [ glue ] frame sink sees EOS
[20:58:14.583] D [ pgraph ] <Pgrapher:> graph execution complete
[20:58:14.583] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 11.52 sec
[20:58:14.583] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.54 sec
[20:58:14.583] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.42 sec
[20:58:14.583] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 6.69 sec
[20:58:14.583] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 6.5 sec
[20:58:14.583] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 6.42 sec
[20:58:14.583] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 6.34 sec
[20:58:14.583] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 6.26 sec
[20:58:14.583] I [ timer ] Timer: WireCell::Aux::Resampler : 0.77 sec
[20:58:14.583] I [ timer ] Timer: WireCell::Aux::Resampler : 0.77 sec
[20:58:14.583] I [ timer ] Timer: WireCell::Aux::Resampler : 0.76 sec
[20:58:14.583] I [ timer ] Timer: WireCell::Aux::Resampler : 0.76 sec
[20:58:14.583] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[20:58:14.583] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.01 sec
[20:58:14.583] I [ timer ] Timer: WireCell::Gen::Retagger : 0.01 sec
[20:58:14.583] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[20:58:14.583] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[20:58:14.583] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[20:58:14.583] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[20:58:14.583] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[20:58:14.583] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[20:58:14.583] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[20:58:14.583] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[20:58:14.583] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0 sec
[20:58:14.584] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[20:58:14.584] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[20:58:14.584] I [ timer ] Timer: Total node execution : 61.780000953003764 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 49689 traces tagged "gauss"
FrameSaver: q=9.52638e+06 n=1114823 tag=gauss
wclsFrameSaver: saving 60835 traces tagged "wiener"
FrameSaver: q=1.02397e+07 n=1075673 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 67 XUs and 101 XVs -> 1 XUVs
C:0 T:1 313 XUs and 402 XVs -> 23 XUVs
C:0 T:2 434 XUs and 369 XVs -> 11 XUVs
C:0 T:3 299 XUs and 464 XVs -> 14 XUVs
C:0 T:4 205 XUs and 208 XVs -> 6 XUVs
C:0 T:5 978 XUs and 804 XVs -> 14 XUVs
C:0 T:6 494 XUs and 553 XVs -> 27 XUVs
C:0 T:7 1118 XUs and 1309 XVs -> 68 XUVs
C:0 T:8 32806 XUs and 77492 XVs -> 10441 XUVs
C:0 T:9 8913 XUs and 20302 XVs -> 1594 XUVs
C:0 T:10 7315 XUs and 11440 XVs -> 2579 XUVs
C:0 T:11 2754 XUs and 2069 XVs -> 120 XUVs
C:0 T:12 311 XUs and 311 XVs -> 57 XUVs
C:0 T:13 1763 XUs and 1969 XVs -> 111 XUVs
C:0 T:14 669 XUs and 717 XVs -> 40 XUVs
C:0 T:15 3680 XUs and 3404 XVs -> 159 XUVs
15265 XUVs total
1977 collection wire objects
15265 potential space points
Neighbour search...
2143961 tests to find 881598 neighbours
Iterating with no regularization...
Begin: 6.44688e+08
0 5.58586e+08
1 5.51971e+08
2 5.50948e+08
3 5.50575e+08
Now with regularization...
Begin: 5.3814e+08
0 5.37807e+08
BdtBeamParticleIdTool::SliceFeatures::GetLeadingCaloHits - empty calo hit list
BdtBeamParticleIdTool::SliceFeatures::GetLeadingCaloHits - empty calo hit list
17-Sep-2025 21:00:05 CEST Closed output file "np02vd_raw_run039388_0221_df-s05-d1_dw_0_20250916T175036_reco_stage1_20250917T190005_keepup.root"
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 194.332 293.907 390.304 295.537 54.5995 19
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 6.3018e-05 7.0424e-05 0.00014889 6.5533e-05 1.86239e-05 19
produce:tpcrawdecoder:PDVDTPCReader 63.0857 164.733 232.459 170.339 50.9845 19
produce:triggerrawdecoder:PDVDTriggerReader4 0.293867 0.383926 0.842571 0.340472 0.127621 19
produce:pdvddaphne:DAPHNEReaderPDVD 0.000331353 0.000372265 0.000681651 0.000358053 7.43703e-05 19
produce:ophit:OpHitFinder 0.000133481 0.000178605 0.000795405 0.000139061 0.000147149 19
produce:opflash:OpFlashFinderVerticalDrift 5.3029e-05 7.60239e-05 0.00036217 5.4823e-05 6.9541e-05 19
produce:wclsdatavd:WireCellToolkit 52.7412 60.3776 71.5253 60.2752 5.46708 19
produce:gaushit:GausHitFinder 0.752294 1.16627 1.47291 1.15033 0.184278 19
produce:nhitsfilter:NumberOfHitsFilter 0.000333417 0.000636106 0.000977998 0.000583717 0.000171023 19
produce:reco3d:SpacePointSolver 8.082 13.978 20.2908 12.8129 3.47316 19
produce:hitpdune:DisambigFromSpacePoints 0.0990547 0.192446 0.354221 0.188262 0.064597 19
produce:pandora:StandardPandora 16.8477 48.0959 90.4375 39.8151 20.9827 19
produce:pandoraTrack:LArPandoraTrackCreation 0.482366 0.791802 1.3413 0.734282 0.251367 19
produce:pandoraGnocalo:GnocchiCalorimetry 0.0219855 0.028476 0.0370703 0.0274259 0.004633 19
[art]:TriggerResults:TriggerResultInserter 1.2854e-05 1.54986e-05 4.276e-05 1.4036e-05 6.45431e-06 19
end_path:out1:RootOutput 3.677e-06 4.86221e-06 1.8304e-05 4.148e-06 3.17796e-06 19
end_path:out1:RootOutput(write) 3.93808 4.12972 4.39589 4.11089 0.128285 19
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 4850.97 MB
Peak resident set size usage (VmHWM): 2961.74 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run039388_0221_df-s05-d1_dw_0_20250916T175036_reco_stage1_20250917T190005_keepup.root
\tHists: np02vd_raw_run039388_0221_df-s05-d1_dw_0_20250916T175036_reco_stage1_20250917T190005_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run039388_0221_df-s05-d1_dw_0_20250916T175036_reco_stage1_20250917T190005_keepup.root
Ran successfully
{
"name": "np02vd_raw_run039388_0221_df-s05-d1_dw_0_20250916T175036_reco_stage1_20250917T190005_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": 1758135605.0,
"core.end_time": 1758135605.0,
"core.events": [
17061,
17065,
17069,
17073,
17077,
17081,
17085,
17089,
17093,
17097,
17101,
17105,
17109,
17113,
17117,
17121,
17125,
17129,
17133
],
"core.event_count": 19,
"core.first_event_number": 17061,
"core.last_event_number": 17133,
"core.data_stream": "cosmics",
"core.file_content_status": "good",
"core.file_type": "detector",
"core.run_type": "vd-protodune",
"core.runs": [
39388
],
"core.runs_subruns": [
3938800001
],
"dune.daq_test": false,
"retention.status": "active",
"retention.class": "physics"
},
"parents": [
{
"did": "vd-protodune:np02vd_raw_run039388_0221_df-s05-d1_dw_0_20250916T175036.hdf5"
}
]
}Forming hist metadata
formed
{
"name": "np02vd_raw_run039388_0221_df-s05-d1_dw_0_20250916T175036_reco_stage1_20250917T190005_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": 1758135605.0,
"core.end_time": 1758135605.0,
"core.data_stream": "cosmics",
"core.file_content_status": "good",
"core.file_type": "detector",
"core.run_type": "vd-protodune",
"core.runs": [
39388
],
"core.runs_subruns": [
3938800001
],
"dune.daq_test": false,
"retention.status": "active",
"retention.class": "physics"
},
"parents": [
{
"did": "vd-protodune:np02vd_raw_run039388_0221_df-s05-d1_dw_0_20250916T175036.hdf5"
}
]
} 