Jobsub ID 47410.93@dunegpschedd01.fnal.gov
Jobscript log (last 10,000 characters)
SigProc:anode0sigproc0> EOS at call=39 anode=0
[10:08:16.804] D [ glue ] <FrameFanin:nfsp> EOS at call=39 with 8
[10:08:16.804] D [ glue ] frame sink sees EOS
[10:08:16.804] D [ pgraph ] <Pgrapher:> graph execution complete
[10:08:16.804] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.61 sec
[10:08:16.804] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.28 sec
[10:08:16.804] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.09 sec
[10:08:16.804] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.59 sec
[10:08:16.804] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.19 sec
[10:08:16.804] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.16 sec
[10:08:16.804] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 6.71 sec
[10:08:16.804] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 6.03 sec
[10:08:16.804] I [ timer ] Timer: WireCell::Aux::Resampler : 0.97 sec
[10:08:16.804] I [ timer ] Timer: WireCell::Aux::Resampler : 0.93 sec
[10:08:16.804] I [ timer ] Timer: WireCell::Aux::Resampler : 0.74 sec
[10:08:16.804] I [ timer ] Timer: WireCell::Aux::Resampler : 0.63 sec
[10:08:16.804] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.02 sec
[10:08:16.804] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[10:08:16.804] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[10:08:16.804] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[10:08:16.804] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[10:08:16.804] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[10:08:16.804] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[10:08:16.804] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[10:08:16.804] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[10:08:16.804] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[10:08:16.804] I [ timer ] Timer: WireCell::Gen::Retagger : 0 sec
[10:08:16.804] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0 sec
[10:08:16.804] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[10:08:16.804] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[10:08:16.804] I [ timer ] Timer: Total node execution : 62.94999988749623 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 56453 traces tagged "gauss"
FrameSaver: q=8.68167e+06 n=1121362 tag=gauss
wclsFrameSaver: saving 67889 traces tagged "wiener"
FrameSaver: q=9.05409e+06 n=1078019 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 1038 XUs and 1178 XVs -> 52 XUVs
C:0 T:1 132 XUs and 188 XVs -> 8 XUVs
C:0 T:2 905 XUs and 792 XVs -> 43 XUVs
C:0 T:3 1285 XUs and 1077 XVs -> 39 XUVs
C:0 T:4 2035 XUs and 2096 XVs -> 90 XUVs
C:0 T:5 1227 XUs and 1020 XVs -> 64 XUVs
C:0 T:6 1114 XUs and 900 XVs -> 53 XUVs
C:0 T:7 863 XUs and 1162 XVs -> 42 XUVs
C:0 T:8 1525 XUs and 2097 XVs -> 111 XUVs
C:0 T:9 2367 XUs and 2680 XVs -> 149 XUVs
C:0 T:10 763 XUs and 1140 XVs -> 51 XUVs
C:0 T:11 873 XUs and 1008 XVs -> 80 XUVs
C:0 T:12 3354 XUs and 3388 XVs -> 137 XUVs
C:0 T:13 2617 XUs and 2791 XVs -> 216 XUVs
C:0 T:14 4466 XUs and 4151 XVs -> 183 XUVs
C:0 T:15 918 XUs and 832 XVs -> 39 XUVs
1357 XUVs total
1206 collection wire objects
1357 potential space points
Neighbour search...
6531 tests to find 3216 neighbours
Iterating with no regularization...
Begin: 3.93899e+08
0 3.87648e+08
1 3.87396e+08
Now with regularization...
Begin: 3.82804e+08
0 3.82803e+08
PcaShowerParticleBuildingAlgorithm::OpeningAngle - principal eigenvalue less than or equal to 0.
17-Sep-2025 10:09:54 UTC Closed output file "np02vd_raw_run039388_0493_df-s05-d3_dw_0_20250916T233436_reco_stage1_20250917T100954_keepup.root"
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 48.5773 165.786 258.28 164.152 40.2706 20
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 7.0387e-05 0.000116006 0.000254465 0.000107593 3.81894e-05 20
produce:tpcrawdecoder:PDVDTPCReader 11.9618 19.7474 29.1243 19.0231 3.46668 20
produce:triggerrawdecoder:PDVDTriggerReader4 0.387053 0.421613 0.833969 0.394269 0.0956288 20
produce:pdvddaphne:DAPHNEReaderPDVD 0.000284871 0.000359765 0.00100116 0.000323013 0.000149742 20
produce:ophit:OpHitFinder 0.000147443 0.000272994 0.00157213 0.00018469 0.000314544 20
produce:opflash:OpFlashFinderVerticalDrift 3.8218e-05 9.02457e-05 0.000755744 5.1112e-05 0.000153353 20
produce:wclsdatavd:WireCellToolkit 15.7788 69.4344 81.6667 71.5456 12.9907 20
produce:gaushit:GausHitFinder 0.501947 1.55476 2.28005 1.54636 0.36445 20
produce:nhitsfilter:NumberOfHitsFilter 0.000179902 0.000371773 0.000861794 0.000329768 0.000148884 20
produce:reco3d:SpacePointSolver 4.16642 14.1683 23.4887 14.2965 4.35116 20
produce:hitpdune:DisambigFromSpacePoints 0.128037 0.22988 0.420074 0.221622 0.0655343 20
produce:pandora:StandardPandora 13.9092 53.5559 129.735 48.115 28.0205 20
produce:pandoraTrack:LArPandoraTrackCreation 0.379657 1.20369 2.26458 1.30619 0.467359 20
produce:pandoraGnocalo:GnocchiCalorimetry 0.0152132 0.0369539 0.0530455 0.0377164 0.0085424 20
[art]:TriggerResults:TriggerResultInserter 3.6646e-05 6.07039e-05 0.000107843 5.96205e-05 1.80442e-05 20
end_path:out1:RootOutput 5.438e-06 1.41922e-05 3.1778e-05 1.30755e-05 5.13127e-06 20
end_path:out1:RootOutput(write) 1.31308 5.3809 6.52872 5.55128 0.996621 20
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 4757.84 MB
Peak resident set size usage (VmHWM): 2651.18 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run039388_0493_df-s05-d3_dw_0_20250916T233436_reco_stage1_20250917T100954_keepup.root
\tHists: np02vd_raw_run039388_0493_df-s05-d3_dw_0_20250916T233436_reco_stage1_20250917T100954_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run039388_0493_df-s05-d3_dw_0_20250916T233436_reco_stage1_20250917T100954_keepup.root
Ran successfully
{
"name": "np02vd_raw_run039388_0493_df-s05-d3_dw_0_20250916T233436_reco_stage1_20250917T100954_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": 1758103795.0,
"core.end_time": 1758103795.0,
"core.events": [
37991,
37995,
37999,
38003,
38007,
38011,
38015,
38019,
38023,
38027,
38031,
38035,
38039,
38043,
38047,
38051,
38055,
38059,
38063,
38067
],
"core.event_count": 20,
"core.first_event_number": 37991,
"core.last_event_number": 38067,
"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_0493_df-s05-d3_dw_0_20250916T233436.hdf5"
}
]
}Forming hist metadata
formed
{
"name": "np02vd_raw_run039388_0493_df-s05-d3_dw_0_20250916T233436_reco_stage1_20250917T100954_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": 1758103795.0,
"core.end_time": 1758103795.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_0493_df-s05-d3_dw_0_20250916T233436.hdf5"
}
]
}