Jobsub ID 41655.90@dunegpschedd02.fnal.gov
Jobscript log (last 10,000 characters)
D [sigproc ] <OmnibusSigProc:anode0sigproc0> EOS at call=91 anode=0
[10:05:29.971] D [ glue ] <FrameFanin:nfsp> EOS at call=91 with 8
[10:05:29.971] D [ glue ] frame sink sees EOS
[10:05:29.971] D [ pgraph ] <Pgrapher:> graph execution complete
[10:05:29.971] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 6.21 sec
[10:05:29.971] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 5.94 sec
[10:05:29.971] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 5.91 sec
[10:05:29.971] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 5.68 sec
[10:05:29.971] I [ timer ] Timer: WireCell::Aux::Resampler : 0.26 sec
[10:05:29.971] I [ timer ] Timer: WireCell::Aux::Resampler : 0.26 sec
[10:05:29.971] I [ timer ] Timer: WireCell::Aux::Resampler : 0.26 sec
[10:05:29.971] I [ timer ] Timer: WireCell::Aux::Resampler : 0.26 sec
[10:05:29.972] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[10:05:29.972] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[10:05:29.972] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[10:05:29.972] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[10:05:29.972] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0 sec
[10:05:29.972] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[10:05:29.972] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[10:05:29.972] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[10:05:29.972] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[10:05:29.972] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[10:05:29.972] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[10:05:29.972] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[10:05:29.972] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[10:05:29.972] I [ timer ] Timer: WireCell::Gen::Retagger : 0 sec
[10:05:29.972] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0 sec
[10:05:29.972] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[10:05:29.972] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[10:05:29.972] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[10:05:29.972] I [ timer ] Timer: Total node execution : 24.77999973297119 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 15166 traces tagged "gauss"
FrameSaver: q=2.50151e+06 n=350074 tag=gauss
wclsFrameSaver: saving 19757 traces tagged "wiener"
FrameSaver: q=2.69303e+06 n=334521 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 3 XUs and 13 XVs -> 0 XUVs
C:0 T:1 1544 XUs and 2041 XVs -> 60 XUVs
C:0 T:2 1179 XUs and 1194 XVs -> 50 XUVs
C:0 T:3 755 XUs and 1010 XVs -> 47 XUVs
C:0 T:4 7154 XUs and 12755 XVs -> 724 XUVs
C:0 T:5 40 XUs and 45 XVs -> 0 XUVs
C:0 T:6 1338 XUs and 2365 XVs -> 120 XUVs
C:0 T:7 298 XUs and 588 XVs -> 25 XUVs
1026 XUVs total
641 collection wire objects
1026 potential space points
Neighbour search...
35774 tests to find 9064 neighbours
Iterating with no regularization...
Begin: 7.50169e+08
0 6.9819e+08
1 6.95867e+08
2 6.95812e+08
Now with regularization...
Begin: 6.85434e+08
0 6.85411e+08
BdtBeamParticleIdTool::SliceFeatures::GetLeadingCaloHits - empty calo hit list
18-Sep-2025 10:05:42 CEST Closed output file "np02vd_raw_run039433_0345_df-s05-d2_dw_0_20250918T053202_reco_stage1_20250918T080542_keepup.root"
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 83.4566 135.051 545.777 118.113 71.251 46
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 5.8457e-05 8.62267e-05 0.000230495 7.54515e-05 3.8203e-05 46
produce:tpcrawdecoder:PDVDTPCReader 34.8424 60.1121 100.701 57.964 16.3151 46
produce:triggerrawdecoder:PDVDTriggerReader4 0.31707 0.487789 0.858133 0.457096 0.125208 46
produce:pdvddaphne:DAPHNEReaderPDVD 8.83966 12.8857 18.2098 12.5914 2.38835 46
produce:ophit:OpHitFinder 0.0261643 0.0382158 0.0564314 0.0387112 0.00543318 46
produce:opflash:OpFlashFinderVerticalDrift 0.00287243 0.0077204 0.0190622 0.00720955 0.00290554 46
produce:wclsdatavd:WireCellToolkit 20.1041 30.139 55.9146 25.7958 9.23165 46
produce:gaushit:GausHitFinder 0.250436 0.449948 1.05249 0.428971 0.142691 46
produce:nhitsfilter:NumberOfHitsFilter 7.5704e-05 0.000200009 0.000811173 0.000148172 0.000147801 46
produce:reco3d:SpacePointSolver 1.71493 4.48825 11.7302 4.27865 2.09432 46
produce:hitpdune:DisambigFromSpacePoints 0.0126476 0.0543435 0.20521 0.0468032 0.0383579 46
produce:pandora:StandardPandora 2.06464 24.103 407.898 9.40451 62.794 46
produce:pandoraTrack:LArPandoraTrackCreation 0.064377 0.269198 1.14101 0.208128 0.204956 46
produce:pandoraGnocalo:GnocchiCalorimetry 0.00576011 0.0114613 0.0230142 0.0111162 0.00371667 46
[art]:TriggerResults:TriggerResultInserter 1.7657e-05 2.9082e-05 9.6695e-05 2.43515e-05 1.35747e-05 46
end_path:out1:RootOutput 4.557e-06 6.54839e-06 2.7111e-05 5.773e-06 3.39107e-06 46
end_path:out1:RootOutput(write) 1.651 1.9649 2.44103 1.86706 0.234258 46
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 5439.52 MB
Peak resident set size usage (VmHWM): 3552.06 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run039433_0345_df-s05-d2_dw_0_20250918T053202_reco_stage1_20250918T080542_keepup.root
\tHists: np02vd_raw_run039433_0345_df-s05-d2_dw_0_20250918T053202_reco_stage1_20250918T080543_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run039433_0345_df-s05-d2_dw_0_20250918T053202_reco_stage1_20250918T080542_keepup.root
Ran successfully
{
"name": "np02vd_raw_run039433_0345_df-s05-d2_dw_0_20250918T053202_reco_stage1_20250918T080542_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": 1758182743.0,
"core.end_time": 1758182743.0,
"core.events": [
98978,
98984,
98990,
98996,
99002,
99008,
99014,
99020,
99026,
99032,
99038,
99044,
99050,
99056,
99062,
99068,
99074,
99080,
99086,
99092,
99098,
99104,
99110,
99116,
99122,
99128,
99134,
99140,
99146,
99152,
99158,
99164,
99170,
99176,
99182,
99188,
99194,
99200,
99206,
99212,
99218,
99224,
99230,
99236,
99242,
99248
],
"core.event_count": 46,
"core.first_event_number": 98978,
"core.last_event_number": 99248,
"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_0345_df-s05-d2_dw_0_20250918T053202.hdf5"
}
]
}Forming hist metadata
formed
{
"name": "np02vd_raw_run039433_0345_df-s05-d2_dw_0_20250918T053202_reco_stage1_20250918T080543_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": 1758182743.0,
"core.end_time": 1758182743.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_0345_df-s05-d2_dw_0_20250918T053202.hdf5"
}
]
}