Jobsub ID 37528.3@dunegpschedd02.fnal.gov
Jobscript log (last 10,000 characters)
at call=35
[16:47:50.139] D [sigproc ] <OmnibusSigProc:anode0sigproc0> EOS at call=35 anode=0
[16:47:50.139] D [ glue ] <FrameFanin:nfsp> EOS at call=35 with 8
[16:47:50.139] D [ glue ] frame sink sees EOS
[16:47:50.139] D [ pgraph ] <Pgrapher:> graph execution complete
[16:47:50.139] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 13.5 sec
[16:47:50.139] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 12.74 sec
[16:47:50.139] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 11.11 sec
[16:47:50.139] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 9.04 sec
[16:47:50.139] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 6.95 sec
[16:47:50.139] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 6.29 sec
[16:47:50.139] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 5.73 sec
[16:47:50.139] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 5.64 sec
[16:47:50.139] I [ timer ] Timer: WireCell::Aux::Resampler : 0.85 sec
[16:47:50.139] I [ timer ] Timer: WireCell::Aux::Resampler : 0.78 sec
[16:47:50.139] I [ timer ] Timer: WireCell::Aux::Resampler : 0.7 sec
[16:47:50.139] I [ timer ] Timer: WireCell::Aux::Resampler : 0.62 sec
[16:47:50.139] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.02 sec
[16:47:50.139] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.02 sec
[16:47:50.139] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[16:47:50.139] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[16:47:50.139] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[16:47:50.139] I [ timer ] Timer: WireCell::Gen::Retagger : 0.01 sec
[16:47:50.139] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[16:47:50.139] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[16:47:50.139] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[16:47:50.139] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[16:47:50.139] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[16:47:50.139] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0 sec
[16:47:50.139] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[16:47:50.139] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[16:47:50.139] I [ timer ] Timer: Total node execution : 74.02999903261662 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 63582 traces tagged "gauss"
FrameSaver: q=1.32381e+07 n=1460343 tag=gauss
wclsFrameSaver: saving 82542 traces tagged "wiener"
FrameSaver: q=1.4365e+07 n=1385210 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 809 XUs and 1001 XVs -> 55 XUVs
C:0 T:1 85 XUs and 108 XVs -> 4 XUVs
C:0 T:2 2744 XUs and 2553 XVs -> 90 XUVs
C:0 T:3 41 XUs and 54 XVs -> 0 XUVs
C:0 T:4 353 XUs and 412 XVs -> 19 XUVs
C:0 T:5 1423 XUs and 1688 XVs -> 130 XUVs
C:0 T:6 922 XUs and 1095 XVs -> 68 XUVs
C:0 T:7 932 XUs and 958 XVs -> 45 XUVs
C:0 T:8 37382 XUs and 64935 XVs -> 12009 XUVs
C:0 T:9 13726 XUs and 16821 XVs -> 3062 XUVs
C:0 T:10 16072 XUs and 47564 XVs -> 4626 XUVs
C:0 T:11 12994 XUs and 12329 XVs -> 1608 XUVs
C:0 T:12 23229 XUs and 35114 XVs -> 3482 XUVs
C:0 T:13 2499 XUs and 3533 XVs -> 205 XUVs
C:0 T:14 3928 XUs and 5245 XVs -> 320 XUVs
C:0 T:15 4372 XUs and 7916 XVs -> 894 XUVs
26617 XUVs total
4048 collection wire objects
26617 potential space points
Neighbour search...
3605697 tests to find 1526486 neighbours
Iterating with no regularization...
Begin: 2.41563e+09
0 2.24462e+09
1 2.22922e+09
2 2.22758e+09
Now with regularization...
Begin: 2.19895e+09
0 2.19806e+09
10-Sep-2025 16:50:03 CEST Closed output file "np02vd_raw_run039255_0858_df-s03-d1_dw_0_20250830T193838_reco_stage1_20250910T145003_keepup.root"
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 131.671 215.949 531.06 206.423 87.9161 18
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 5.012e-05 9.95203e-05 0.000261232 8.1256e-05 5.59089e-05 18
produce:tpcrawdecoder:PDVDTPCReader 5.46758 6.26101 8.23998 6.17604 0.570359 18
produce:triggerrawdecoder:PDVDTriggerReader4 0.000689567 0.00458689 0.0483411 0.00111318 0.0108118 18
produce:pdvddaphne:DAPHNEReaderPDVD 2.79833 3.78183 4.94436 3.66343 0.549404 18
produce:ophit:OpHitFinder 0.0292126 0.0431062 0.0547446 0.0419037 0.00732829 18
produce:opflash:OpFlashFinderVerticalDrift 0.00590069 0.0111464 0.0163177 0.0112817 0.00259077 18
produce:wclsdatavd:WireCellToolkit 54.8479 69.6201 87.3542 68.5457 8.87607 18
produce:gaushit:GausHitFinder 1.0281 1.53266 2.34755 1.48751 0.354982 18
produce:nhitsfilter:NumberOfHitsFilter 0.000241872 0.00038738 0.000958128 0.000338412 0.000162329 18
produce:reco3d:SpacePointSolver 13.6298 21.0901 32.0383 21.3185 5.09133 18
produce:hitpdune:DisambigFromSpacePoints 0.150785 0.363854 0.83733 0.32866 0.16099 18
produce:pandora:StandardPandora 40.575 106.038 388.995 89.9103 77.3465 18
produce:pandoraTrack:LArPandoraTrackCreation 0.800065 1.81595 3.29983 1.49545 0.757392 18
produce:pandoraGnocalo:GnocchiCalorimetry 0.0203151 0.0377084 0.0764348 0.0323548 0.0147426 18
[art]:TriggerResults:TriggerResultInserter 1.766e-05 2.92279e-05 5.054e-05 2.53905e-05 1.04641e-05 18
end_path:out1:RootOutput 5.14e-06 8.7095e-06 2.43e-05 7.275e-06 4.29557e-06 18
end_path:out1:RootOutput(write) 4.22177 5.30861 7.32015 4.86574 0.979224 18
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 5373.35 MB
Peak resident set size usage (VmHWM): 3398.99 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run039255_0858_df-s03-d1_dw_0_20250830T193838_reco_stage1_20250910T145003_keepup.root
\tHists: np02vd_raw_run039255_0858_df-s03-d1_dw_0_20250830T193838_reco_stage1_20250910T145003_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run039255_0858_df-s03-d1_dw_0_20250830T193838_reco_stage1_20250910T145003_keepup.root
Ran successfully
{
"name": "np02vd_raw_run039255_0858_df-s03-d1_dw_0_20250830T193838_reco_stage1_20250910T145003_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": 1757515804.0,
"core.end_time": 1757515804.0,
"core.events": [
309600,
309620,
309640,
309660,
309680,
309700,
309720,
309740,
309760,
309780,
309800,
309820,
309840,
309860,
309880,
309900,
309920,
309940
],
"core.event_count": 18,
"core.first_event_number": 309600,
"core.last_event_number": 309940,
"core.data_stream": "physics",
"core.file_content_status": "good",
"core.file_type": "detector",
"core.run_type": "vd-protodune",
"core.runs": [
39255
],
"core.runs_subruns": [
3925500001
],
"dune.daq_test": false,
"retention.status": "active",
"retention.class": "physics"
},
"parents": [
{
"did": "vd-protodune:np02vd_raw_run039255_0858_df-s03-d1_dw_0_20250830T193838.hdf5"
}
]
}Forming hist metadata
formed
{
"name": "np02vd_raw_run039255_0858_df-s03-d1_dw_0_20250830T193838_reco_stage1_20250910T145003_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": 1757515804.0,
"core.end_time": 1757515804.0,
"core.data_stream": "physics",
"core.file_content_status": "good",
"core.file_type": "detector",
"core.run_type": "vd-protodune",
"core.runs": [
39255
],
"core.runs_subruns": [
3925500001
],
"dune.daq_test": false,
"retention.status": "active",
"retention.class": "physics"
},
"parents": [
{
"did": "vd-protodune:np02vd_raw_run039255_0858_df-s03-d1_dw_0_20250830T193838.hdf5"
}
]
} 