Jobsub ID 237725.3@dunegpschedd02.fnal.gov
Jobscript log (last 10,000 characters)
<FrameFanin:nfsp> EOS at call=47 with 8
[13:09:02.938] D [ glue ] frame sink sees EOS
[13:09:02.938] D [ pgraph ] <Pgrapher:> graph execution complete
[13:09:02.938] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 26.1 sec
[13:09:02.938] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 24.49 sec
[13:09:02.938] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 14.89 sec
[13:09:02.938] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 14.48 sec
[13:09:02.938] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 14.17 sec
[13:09:02.938] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 13.29 sec
[13:09:02.938] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 12.96 sec
[13:09:02.938] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 12.7 sec
[13:09:02.938] I [ timer ] Timer: WireCell::Aux::Resampler : 0.25 sec
[13:09:02.938] I [ timer ] Timer: WireCell::Aux::Resampler : 0.24 sec
[13:09:02.938] I [ timer ] Timer: WireCell::Aux::Resampler : 0.24 sec
[13:09:02.938] I [ timer ] Timer: WireCell::Aux::Resampler : 0.24 sec
[13:09:02.938] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.02 sec
[13:09:02.938] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[13:09:02.938] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[13:09:02.938] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[13:09:02.939] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[13:09:02.939] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[13:09:02.939] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[13:09:02.939] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[13:09:02.939] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[13:09:02.939] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[13:09:02.939] I [ timer ] Timer: WireCell::Gen::Retagger : 0 sec
[13:09:02.939] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0 sec
[13:09:02.939] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[13:09:02.939] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[13:09:02.939] I [ timer ] Timer: Total node execution : 134.0999999064952 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 48084 traces tagged "gauss"
FrameSaver: q=2.95848e+07 n=1420845 tag=gauss
wclsFrameSaver: saving 60806 traces tagged "wiener"
FrameSaver: q=3.13041e+07 n=1373581 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 21831 XUs and 24671 XVs -> 1462 XUVs
C:0 T:1 321 XUs and 370 XVs -> 6 XUVs
C:0 T:2 561 XUs and 607 XVs -> 27 XUVs
C:0 T:3 597 XUs and 540 XVs -> 12 XUVs
C:0 T:4 172 XUs and 176 XVs -> 3 XUVs
C:0 T:5 783 XUs and 647 XVs -> 48 XUVs
C:0 T:6 1035 XUs and 689 XVs -> 26 XUVs
C:0 T:7 605 XUs and 501 XVs -> 15 XUVs
C:0 T:8 1269 XUs and 2323 XVs -> 82 XUVs
C:0 T:9 676 XUs and 1098 XVs -> 34 XUVs
C:0 T:10 1206 XUs and 1264 XVs -> 61 XUVs
C:0 T:11 1367 XUs and 2178 XVs -> 299 XUVs
C:0 T:12 1775 XUs and 1595 XVs -> 145 XUVs
C:0 T:13 14970 XUs and 25558 XVs -> 4009 XUVs
C:0 T:14 25885 XUs and 60252 XVs -> 6040 XUVs
C:0 T:15 12545 XUs and 17254 XVs -> 2463 XUVs
14732 XUVs total
2702 collection wire objects
14732 potential space points
Neighbour search...
1650390 tests to find 741690 neighbours
Iterating with no regularization...
Begin: 2.23381e+11
0 2.18936e+11
1 2.18578e+11
2 2.18561e+11
Now with regularization...
Begin: 2.1786e+11
0 2.17856e+11
BdtBeamParticleIdTool::SliceFeatures::GetLeadingCaloHits - empty calo hit list
05-Nov-2025 13:10:32 CET Closed output file "np02vd_raw_run040361_0554_df-s04-d2_dw_0_20251105T043621_reco_stage1_20251105T121032_keepup.root"
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 103.998 224.176 801.19 161.194 173.965 24
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 7.3772e-05 9.69629e-05 0.000289996 8.7166e-05 4.22216e-05 24
produce:tpcrawdecoder:PDVDTPCReader 14.6191 17.7592 43.1997 15.9497 5.59283 24
produce:triggerrawdecoder:PDVDTriggerReader4 0.544196 0.588622 0.762255 0.574249 0.0468691 24
produce:pdvddaphne:DAPHNEReaderPDVD 0.000333932 0.000389128 0.000700072 0.000366876 7.3189e-05 24
produce:ophit:OpHitFinder 7.8978e-05 0.000114628 0.00057941 8.41715e-05 9.8748e-05 24
produce:opflash:OpFlashFinderVerticalDrift 5.6065e-05 7.9167e-05 0.000376926 6.2033e-05 6.30713e-05 24
produce:wclsdatavd:WireCellToolkit 56.7311 103.199 148.046 99.3894 22.6281 24
produce:gaushit:GausHitFinder 0.779997 1.37814 2.3348 1.28727 0.436661 24
produce:nhitsfilter:NumberOfHitsFilter 0.00020663 0.000384893 0.000664569 0.000364133 0.000116763 24
produce:reco3d:SpacePointSolver 7.22172 16.3114 42.3855 13.7433 8.8253 24
produce:hitpdune:DisambigFromSpacePoints 0.0873401 0.275332 1.22497 0.194475 0.243934 24
produce:pandora:StandardPandora 10.8648 77.3097 617.484 26.5863 152.657 24
produce:pandoraTrack:LArPandoraTrackCreation 0.411868 1.85701 8.47291 1.38157 1.88845 24
produce:pandoraGnocalo:GnocchiCalorimetry 0.0195309 0.0363886 0.060753 0.0354947 0.00994731 24
[art]:TriggerResults:TriggerResultInserter 2.6621e-05 4.67832e-05 0.000118788 4.1162e-05 1.77383e-05 24
end_path:out1:RootOutput 5.888e-06 9.54971e-06 3.6514e-05 8.2275e-06 5.9242e-06 24
end_path:out1:RootOutput(write) 4.82278 5.35961 6.04336 5.26047 0.348754 24
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 7181.48 MB
Peak resident set size usage (VmHWM): 5290.52 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run040361_0554_df-s04-d2_dw_0_20251105T043621_reco_stage1_20251105T121032_keepup.root
\tHists: np02vd_raw_run040361_0554_df-s04-d2_dw_0_20251105T043621_reco_stage1_20251105T121033_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run040361_0554_df-s04-d2_dw_0_20251105T043621_reco_stage1_20251105T121032_keepup.root
Ran successfully
{
"name": "np02vd_raw_run040361_0554_df-s04-d2_dw_0_20251105T043621_reco_stage1_20251105T121032_keepup.root",
"namespace": "vd-protodune-det-reco",
"metadata": {
"core.file_format": "artroot",
"core.application.name": "reco",
"core.application.family": "dunesw",
"core.application.version": "v10_11_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": 1762344634.0,
"core.end_time": 1762344634.0,
"core.events": [
51382,
51386,
51390,
51394,
51398,
51402,
51406,
51410,
51414,
51418,
51422,
51426,
51430,
51434,
51438,
51442,
51446,
51450,
51454,
51458,
51462,
51466,
51470,
51474
],
"core.event_count": 24,
"core.first_event_number": 51382,
"core.last_event_number": 51474,
"core.data_stream": "cosmics",
"core.file_content_status": "good",
"core.file_type": "detector",
"core.run_type": "vd-protodune",
"core.runs": [
40361
],
"core.runs_subruns": [
4036100001
],
"dune.daq_test": true,
"retention.status": "active",
"retention.class": "physics"
},
"parents": [
{
"did": "vd-protodune:np02vd_raw_run040361_0554_df-s04-d2_dw_0_20251105T043621.hdf5"
}
]
}Forming hist metadata
formed
{
"name": "np02vd_raw_run040361_0554_df-s04-d2_dw_0_20251105T043621_reco_stage1_20251105T121033_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_11_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": 1762344634.0,
"core.end_time": 1762344634.0,
"core.data_stream": "cosmics",
"core.file_content_status": "good",
"core.file_type": "detector",
"core.run_type": "vd-protodune",
"core.runs": [
40361
],
"core.runs_subruns": [
4036100001
],
"dune.daq_test": true,
"retention.status": "active",
"retention.class": "physics"
},
"parents": [
{
"did": "vd-protodune:np02vd_raw_run040361_0554_df-s04-d2_dw_0_20251105T043621.hdf5"
}
]
} 