Jobsub ID 48994.2@dunegpschedd01.fnal.gov
Jobscript log (last 10,000 characters)
> EOS at call=79 anode=1
[22:34:28.909] D [ glue ] <ChannelSelector:chsel0> see EOS at call=39
[22:34:28.909] D [ aux ] <Resampler:resmp0> EOS at call=79
[22:34:28.909] D [sigproc ] <OmnibusSigProc:anode0sigproc0> EOS at call=79 anode=0
[22:34:28.909] D [ glue ] <FrameFanin:nfsp> EOS at call=79 with 8
[22:34:28.909] D [ glue ] frame sink sees EOS
[22:34:28.909] D [ pgraph ] <Pgrapher:> graph execution complete
[22:34:28.909] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 25.99 sec
[22:34:28.909] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 22.56 sec
[22:34:28.909] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 18.93 sec
[22:34:28.909] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 18.86 sec
[22:34:28.909] I [ timer ] Timer: WireCell::Aux::Resampler : 0.89 sec
[22:34:28.909] I [ timer ] Timer: WireCell::Aux::Resampler : 0.85 sec
[22:34:28.909] I [ timer ] Timer: WireCell::Aux::Resampler : 0.8 sec
[22:34:28.909] I [ timer ] Timer: WireCell::Aux::Resampler : 0.8 sec
[22:34:28.910] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.01 sec
[22:34:28.910] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[22:34:28.910] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[22:34:28.910] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[22:34:28.910] I [ timer ] Timer: WireCell::Gen::Retagger : 0.01 sec
[22:34:28.910] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[22:34:28.910] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[22:34:28.910] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[22:34:28.910] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[22:34:28.910] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[22:34:28.910] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[22:34:28.910] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[22:34:28.910] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[22:34:28.910] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[22:34:28.910] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[22:34:28.910] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0 sec
[22:34:28.910] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[22:34:28.910] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[22:34:28.910] I [ timer ] Timer: Total node execution : 89.7300001848489 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 25480 traces tagged "gauss"
FrameSaver: q=9.51007e+06 n=748439 tag=gauss
wclsFrameSaver: saving 31936 traces tagged "wiener"
FrameSaver: q=1.02146e+07 n=730388 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 298 XUs and 247 XVs -> 12 XUVs
C:0 T:1 22812 XUs and 40153 XVs -> 2255 XUVs
C:0 T:2 772 XUs and 635 XVs -> 48 XUVs
C:0 T:3 126 XUs and 129 XVs -> 4 XUVs
C:0 T:4 4715 XUs and 5470 XVs -> 307 XUVs
C:0 T:5 918 XUs and 1025 XVs -> 67 XUVs
C:0 T:6 1242 XUs and 1143 XVs -> 93 XUVs
C:0 T:7 423 XUs and 541 XVs -> 28 XUVs
2814 XUVs total
1376 collection wire objects
2814 potential space points
Neighbour search...
96732 tests to find 22830 neighbours
Iterating with no regularization...
Begin: 3.53343e+10
0 3.37576e+10
1 3.37141e+10
2 3.37126e+10
Now with regularization...
Begin: 3.31847e+10
0 3.31837e+10
18-Sep-2025 22:36:17 BST Closed output file "np02vd_raw_run039499_0010_df-s04-d1_dw_0_20250918T180223_reco_stage1_20250918T213617_keepup.root"
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 77.6346 205.338 3720.58 108.603 563.854 40
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 8.3527e-05 0.000118165 0.000353698 0.000104327 5.13621e-05 40
produce:tpcrawdecoder:PDVDTPCReader 7.60549 8.75792 10.667 8.37235 0.838547 40
produce:triggerrawdecoder:PDVDTriggerReader4 0.372946 0.388167 0.41766 0.389371 0.0105096 40
produce:pdvddaphne:DAPHNEReaderPDVD 3.95186 4.45672 4.92508 4.46812 0.185955 40
produce:ophit:OpHitFinder 0.0576334 0.0728652 0.0836221 0.0725943 0.00521365 40
produce:opflash:OpFlashFinderVerticalDrift 0.00971342 0.0215603 0.0358835 0.0213558 0.00562905 40
produce:wclsdatavd:WireCellToolkit 39.6325 59.3419 95.0927 54.0421 15.4116 40
produce:gaushit:GausHitFinder 0.468351 1.02038 2.80783 0.985049 0.379527 40
produce:nhitsfilter:NumberOfHitsFilter 0.000109387 0.000290848 0.000612957 0.000283961 0.000113644 40
produce:reco3d:SpacePointSolver 2.73045 8.71962 45.8274 7.52323 6.72276 40
produce:hitpdune:DisambigFromSpacePoints 0.0266611 0.128067 1.03041 0.0948203 0.153644 40
produce:pandora:StandardPandora 4.92877 117.579 3554.52 22.4381 550.773 40
produce:pandoraTrack:LArPandoraTrackCreation 0.11651 0.612777 6.63094 0.448015 0.988812 40
produce:pandoraGnocalo:GnocchiCalorimetry 0.0109762 0.0277172 0.0519623 0.0277463 0.00836328 40
[art]:TriggerResults:TriggerResultInserter 2.1631e-05 3.95259e-05 9.554e-05 3.02325e-05 2.02541e-05 40
end_path:out1:RootOutput 4.248e-06 7.9831e-06 4.6247e-05 5.6055e-06 7.7231e-06 40
end_path:out1:RootOutput(write) 2.96403 4.17667 4.88229 4.18662 0.428052 40
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 4518.6 MB
Peak resident set size usage (VmHWM): 2591.17 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run039499_0010_df-s04-d1_dw_0_20250918T180223_reco_stage1_20250918T213617_keepup.root
\tHists: np02vd_raw_run039499_0010_df-s04-d1_dw_0_20250918T180223_reco_stage1_20250918T213618_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run039499_0010_df-s04-d1_dw_0_20250918T180223_reco_stage1_20250918T213617_keepup.root
Ran successfully
{
"name": "np02vd_raw_run039499_0010_df-s04-d1_dw_0_20250918T180223_reco_stage1_20250918T213617_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": 1758231379.0,
"core.end_time": 1758231379.0,
"core.events": [
2430,
2436,
2442,
2448,
2454,
2460,
2466,
2472,
2478,
2484,
2490,
2496,
2502,
2508,
2514,
2520,
2526,
2532,
2538,
2544,
2550,
2556,
2562,
2568,
2574,
2580,
2586,
2592,
2598,
2604,
2610,
2616,
2622,
2628,
2634,
2640,
2646,
2652,
2658,
2664
],
"core.event_count": 40,
"core.first_event_number": 2430,
"core.last_event_number": 2664,
"core.data_stream": "cosmics",
"core.file_content_status": "good",
"core.file_type": "detector",
"core.run_type": "vd-protodune",
"core.runs": [
39499
],
"core.runs_subruns": [
3949900001
],
"dune.daq_test": false,
"retention.status": "active",
"retention.class": "physics"
},
"parents": [
{
"did": "vd-protodune:np02vd_raw_run039499_0010_df-s04-d1_dw_0_20250918T180223.hdf5"
}
]
}Forming hist metadata
formed
{
"name": "np02vd_raw_run039499_0010_df-s04-d1_dw_0_20250918T180223_reco_stage1_20250918T213618_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": 1758231379.0,
"core.end_time": 1758231379.0,
"core.data_stream": "cosmics",
"core.file_content_status": "good",
"core.file_type": "detector",
"core.run_type": "vd-protodune",
"core.runs": [
39499
],
"core.runs_subruns": [
3949900001
],
"dune.daq_test": false,
"retention.status": "active",
"retention.class": "physics"
},
"parents": [
{
"did": "vd-protodune:np02vd_raw_run039499_0010_df-s04-d1_dw_0_20250918T180223.hdf5"
}
]
} 