Jobsub ID 40875.92@dunegpschedd02.fnal.gov
Jobscript log (last 10,000 characters)
> see EOS at call=18
[13:42:27.892] D [ aux ] <Resampler:resmp0> EOS at call=37
[13:42:27.892] D [sigproc ] <OmnibusSigProc:anode0sigproc0> EOS at call=37 anode=0
[13:42:27.892] D [ glue ] <FrameFanin:nfsp> EOS at call=37 with 8
[13:42:27.892] D [ glue ] frame sink sees EOS
[13:42:27.892] D [ pgraph ] <Pgrapher:> graph execution complete
[13:42:27.892] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8 sec
[13:42:27.892] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 6.73 sec
[13:42:27.892] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 6.64 sec
[13:42:27.892] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 6.45 sec
[13:42:27.892] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 6.42 sec
[13:42:27.892] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 6.19 sec
[13:42:27.892] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 5.91 sec
[13:42:27.892] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 5.75 sec
[13:42:27.892] I [ timer ] Timer: WireCell::Aux::Resampler : 0.79 sec
[13:42:27.892] I [ timer ] Timer: WireCell::Aux::Resampler : 0.79 sec
[13:42:27.892] I [ timer ] Timer: WireCell::Aux::Resampler : 0.78 sec
[13:42:27.892] I [ timer ] Timer: WireCell::Aux::Resampler : 0.77 sec
[13:42:27.892] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.01 sec
[13:42:27.892] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[13:42:27.892] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[13:42:27.892] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[13:42:27.892] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[13:42:27.892] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[13:42:27.892] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[13:42:27.892] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[13:42:27.892] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[13:42:27.892] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[13:42:27.892] I [ timer ] Timer: WireCell::Gen::Retagger : 0 sec
[13:42:27.892] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0 sec
[13:42:27.892] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[13:42:27.892] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[13:42:27.892] I [ timer ] Timer: Total node execution : 55.25999967008829 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 35882 traces tagged "gauss"
FrameSaver: q=5.7071e+06 n=710927 tag=gauss
wclsFrameSaver: saving 43104 traces tagged "wiener"
FrameSaver: q=5.99088e+06 n=681756 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 306 XUs and 377 XVs -> 24 XUVs
C:0 T:1 314 XUs and 219 XVs -> 22 XUVs
C:0 T:2 471 XUs and 724 XVs -> 35 XUVs
C:0 T:3 235 XUs and 238 XVs -> 8 XUVs
C:0 T:4 241 XUs and 245 XVs -> 11 XUVs
C:0 T:5 1234 XUs and 1009 XVs -> 72 XUVs
C:0 T:6 154 XUs and 212 XVs -> 10 XUVs
C:0 T:7 40 XUs and 37 XVs -> 1 XUVs
C:0 T:8 1569 XUs and 1685 XVs -> 100 XUVs
C:0 T:9 522 XUs and 521 XVs -> 30 XUVs
C:0 T:10 1216 XUs and 965 XVs -> 55 XUVs
C:0 T:11 2264 XUs and 2244 XVs -> 176 XUVs
C:0 T:12 1666 XUs and 2134 XVs -> 79 XUVs
C:0 T:13 1615 XUs and 970 XVs -> 129 XUVs
C:0 T:14 1512 XUs and 1403 XVs -> 61 XUVs
C:0 T:15 2142 XUs and 2417 XVs -> 161 XUVs
974 XUVs total
831 collection wire objects
974 potential space points
Neighbour search...
6978 tests to find 3550 neighbours
Iterating with no regularization...
Begin: 3.27299e+08
0 3.18357e+08
1 3.18146e+08
Now with regularization...
Begin: 3.11889e+08
0 3.11884e+08
17-Sep-2025 13:43:10 CEST Closed output file "np02vd_raw_run039388_0864_df-s05-d1_dw_0_20250917T072440_reco_stage1_20250917T114310_keepup.root"
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 229.517 380.154 471.751 386.453 60.3507 19
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 6.2557e-05 8.09713e-05 0.000151805 7.7916e-05 1.7917e-05 19
produce:tpcrawdecoder:PDVDTPCReader 133.268 239.67 288.452 248.779 41.6729 19
produce:triggerrawdecoder:PDVDTriggerReader4 0.301654 0.450829 0.654492 0.460308 0.0936495 19
produce:pdvddaphne:DAPHNEReaderPDVD 0.00036741 0.000422808 0.000839944 0.000392847 0.000100483 19
produce:ophit:OpHitFinder 0.000139051 0.000189957 0.00089071 0.000146134 0.00016656 19
produce:opflash:OpFlashFinderVerticalDrift 5.2418e-05 7.4554e-05 0.00038431 5.7208e-05 7.30626e-05 19
produce:wclsdatavd:WireCellToolkit 54.7207 68.9273 80.6697 69.0425 6.60716 19
produce:gaushit:GausHitFinder 0.786142 1.26101 1.86851 1.19245 0.306721 19
produce:nhitsfilter:NumberOfHitsFilter 0.000218409 0.000626519 0.00116623 0.000564258 0.000273278 19
produce:reco3d:SpacePointSolver 8.02234 15.1014 25.6503 14.6938 4.8184 19
produce:hitpdune:DisambigFromSpacePoints 0.103421 0.208931 0.377512 0.193051 0.0788819 19
produce:pandora:StandardPandora 22.7471 48.8209 110.648 42.9394 23.2071 19
produce:pandoraTrack:LArPandoraTrackCreation 0.384198 1.03613 1.91784 0.906993 0.433513 19
produce:pandoraGnocalo:GnocchiCalorimetry 0.0198558 0.0312919 0.0409524 0.0327817 0.0067007 19
[art]:TriggerResults:TriggerResultInserter 1.3285e-05 1.89445e-05 4.7048e-05 1.7884e-05 7.17199e-06 19
end_path:out1:RootOutput 3.777e-06 5.32832e-06 1.9556e-05 4.509e-06 3.36929e-06 19
end_path:out1:RootOutput(write) 4.05777 4.60126 4.97652 4.59985 0.274369 19
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 4706.25 MB
Peak resident set size usage (VmHWM): 2816.07 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run039388_0864_df-s05-d1_dw_0_20250917T072440_reco_stage1_20250917T114310_keepup.root
\tHists: np02vd_raw_run039388_0864_df-s05-d1_dw_0_20250917T072440_reco_stage1_20250917T114310_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run039388_0864_df-s05-d1_dw_0_20250917T072440_reco_stage1_20250917T114310_keepup.root
Ran successfully
{
"name": "np02vd_raw_run039388_0864_df-s05-d1_dw_0_20250917T072440_reco_stage1_20250917T114310_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": 1758109391.0,
"core.end_time": 1758109391.0,
"core.events": [
66641,
66645,
66649,
66653,
66657,
66661,
66665,
66669,
66673,
66677,
66681,
66685,
66689,
66693,
66697,
66701,
66705,
66709,
66713
],
"core.event_count": 19,
"core.first_event_number": 66641,
"core.last_event_number": 66713,
"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_0864_df-s05-d1_dw_0_20250917T072440.hdf5"
}
]
}Forming hist metadata
formed
{
"name": "np02vd_raw_run039388_0864_df-s05-d1_dw_0_20250917T072440_reco_stage1_20250917T114310_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": 1758109391.0,
"core.end_time": 1758109391.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_0864_df-s05-d1_dw_0_20250917T072440.hdf5"
}
]
} 