Jobsub ID 47708.128@dunegpschedd01.fnal.gov
Jobscript log (last 10,000 characters)
ler:resmp0> EOS at call=37
[22:37:00.664] D [sigproc ] <OmnibusSigProc:anode0sigproc0> EOS at call=37 anode=0
[22:37:00.664] D [ glue ] <FrameFanin:nfsp> EOS at call=37 with 8
[22:37:00.664] D [ glue ] frame sink sees EOS
[22:37:00.664] D [ pgraph ] <Pgrapher:> graph execution complete
[22:37:00.664] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 18.65 sec
[22:37:00.664] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 15.73 sec
[22:37:00.664] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 14.2 sec
[22:37:00.664] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 14.04 sec
[22:37:00.664] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 12.98 sec
[22:37:00.664] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 12.56 sec
[22:37:00.664] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 11.28 sec
[22:37:00.664] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 11.17 sec
[22:37:00.664] I [ timer ] Timer: WireCell::Aux::Resampler : 1.75 sec
[22:37:00.664] I [ timer ] Timer: WireCell::Aux::Resampler : 1.71 sec
[22:37:00.664] I [ timer ] Timer: WireCell::Aux::Resampler : 1.7 sec
[22:37:00.664] I [ timer ] Timer: WireCell::Aux::Resampler : 1.65 sec
[22:37:00.664] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.04 sec
[22:37:00.664] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.03 sec
[22:37:00.664] I [ timer ] Timer: WireCell::Gen::Retagger : 0.02 sec
[22:37:00.664] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[22:37:00.664] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[22:37:00.664] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[22:37:00.664] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[22:37:00.664] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0.01 sec
[22:37:00.664] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[22:37:00.664] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[22:37:00.664] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[22:37:00.664] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[22:37:00.664] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[22:37:00.664] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[22:37:00.664] I [ timer ] Timer: Total node execution : 117.55999876186252 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 52129 traces tagged "gauss"
FrameSaver: q=9.50911e+06 n=1063384 tag=gauss
wclsFrameSaver: saving 64788 traces tagged "wiener"
FrameSaver: q=1.0094e+07 n=1009887 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 841 XUs and 1071 XVs -> 66 XUVs
C:0 T:1 129 XUs and 230 XVs -> 4 XUVs
C:0 T:2 1880 XUs and 2641 XVs -> 94 XUVs
C:0 T:3 143 XUs and 172 XVs -> 9 XUVs
C:0 T:4 297 XUs and 243 XVs -> 13 XUVs
C:0 T:5 431 XUs and 398 XVs -> 15 XUVs
C:0 T:6 237 XUs and 294 XVs -> 4 XUVs
C:0 T:7 1007 XUs and 1716 XVs -> 67 XUVs
C:0 T:8 2382 XUs and 2592 XVs -> 133 XUVs
C:0 T:9 14863 XUs and 15838 XVs -> 1742 XUVs
C:0 T:10 549 XUs and 824 XVs -> 62 XUVs
C:0 T:11 1277 XUs and 1676 XVs -> 120 XUVs
C:0 T:12 5737 XUs and 5215 XVs -> 428 XUVs
C:0 T:13 2852 XUs and 1751 XVs -> 157 XUVs
C:0 T:14 10772 XUs and 11848 XVs -> 637 XUVs
C:0 T:15 1112 XUs and 1160 XVs -> 74 XUVs
3625 XUVs total
1993 collection wire objects
3625 potential space points
Neighbour search...
165595 tests to find 72966 neighbours
Iterating with no regularization...
Begin: 1.69652e+09
0 1.59226e+09
1 1.58731e+09
2 1.58707e+09
Now with regularization...
Begin: 1.56963e+09
0 1.56954e+09
17-Sep-2025 22:42:04 CEST Closed output file "np02vd_raw_run039388_0434_df-s05-d2_dw_0_20250916T222010_reco_stage1_20250917T204204_keepup.root"
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 187.704 327.564 581.773 315.467 95.7795 19
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 8.2265e-05 0.000184098 0.000589136 0.000146755 0.000113505 19
produce:tpcrawdecoder:PDVDTPCReader 14.5461 17.2743 20.4712 17.6893 1.53464 19
produce:triggerrawdecoder:PDVDTriggerReader4 0.270327 0.27704 0.304286 0.274928 0.00743128 19
produce:pdvddaphne:DAPHNEReaderPDVD 0.000453672 0.00057835 0.00135641 0.000510137 0.000203608 19
produce:ophit:OpHitFinder 0.00023454 0.000495342 0.00172648 0.000388599 0.000313656 19
produce:opflash:OpFlashFinderVerticalDrift 8.2384e-05 0.000153912 0.000856197 0.000109886 0.000167522 19
produce:wclsdatavd:WireCellToolkit 86.9159 123.537 170.077 123.12 19.0413 19
produce:gaushit:GausHitFinder 1.1938 2.56278 3.96546 2.5069 0.71066 19
produce:nhitsfilter:NumberOfHitsFilter 0.000320622 0.000555313 0.00085213 0.000518884 0.000155435 19
produce:reco3d:SpacePointSolver 11.7294 24.7539 43.0774 25.0819 8.04094 19
produce:hitpdune:DisambigFromSpacePoints 0.159065 0.427054 0.930187 0.396961 0.180612 19
produce:pandora:StandardPandora 53.9406 147.514 334.155 126.783 75.5086 19
produce:pandoraTrack:LArPandoraTrackCreation 0.949715 2.94947 6.68523 2.73183 1.28434 19
produce:pandoraGnocalo:GnocchiCalorimetry 0.0330661 0.0627035 0.11433 0.0624311 0.0176736 19
[art]:TriggerResults:TriggerResultInserter 2.8924e-05 7.60057e-05 0.00018671 6.931e-05 3.53632e-05 19
end_path:out1:RootOutput 6.081e-06 1.96452e-05 9.9747e-05 1.4557e-05 1.9895e-05 19
end_path:out1:RootOutput(write) 6.60031 8.13632 9.84022 8.04016 0.883452 19
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 5686.34 MB
Peak resident set size usage (VmHWM): 3763.94 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run039388_0434_df-s05-d2_dw_0_20250916T222010_reco_stage1_20250917T204204_keepup.root
\tHists: np02vd_raw_run039388_0434_df-s05-d2_dw_0_20250916T222010_reco_stage1_20250917T204204_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run039388_0434_df-s05-d2_dw_0_20250916T222010_reco_stage1_20250917T204204_keepup.root
Ran successfully
{
"name": "np02vd_raw_run039388_0434_df-s05-d2_dw_0_20250916T222010_reco_stage1_20250917T204204_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": 1758141725.0,
"core.end_time": 1758141725.0,
"core.events": [
33406,
33410,
33414,
33418,
33422,
33426,
33430,
33434,
33438,
33442,
33446,
33450,
33454,
33458,
33462,
33466,
33470,
33474,
33478
],
"core.event_count": 19,
"core.first_event_number": 33406,
"core.last_event_number": 33478,
"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_0434_df-s05-d2_dw_0_20250916T222010.hdf5"
}
]
}Forming hist metadata
formed
{
"name": "np02vd_raw_run039388_0434_df-s05-d2_dw_0_20250916T222010_reco_stage1_20250917T204204_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": 1758141725.0,
"core.end_time": 1758141725.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_0434_df-s05-d2_dw_0_20250916T222010.hdf5"
}
]
} 