Jobsub ID 40372.140@dunegpschedd02.fnal.gov
Jobscript log (last 10,000 characters)
r:chsel0> see EOS at call=18
[11:41:43.827] D [ aux ] <Resampler:resmp0> EOS at call=37
[11:41:43.827] D [sigproc ] <OmnibusSigProc:anode0sigproc0> EOS at call=37 anode=0
[11:41:43.827] D [ glue ] <FrameFanin:nfsp> EOS at call=37 with 8
[11:41:43.827] D [ glue ] frame sink sees EOS
[11:41:43.827] D [ pgraph ] <Pgrapher:> graph execution complete
[11:41:43.828] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.5 sec
[11:41:43.828] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.49 sec
[11:41:43.828] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.34 sec
[11:41:43.828] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 6.88 sec
[11:41:43.828] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 6.8 sec
[11:41:43.828] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 6.7 sec
[11:41:43.828] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 6.7 sec
[11:41:43.828] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 6.52 sec
[11:41:43.828] I [ timer ] Timer: WireCell::Aux::Resampler : 1.15 sec
[11:41:43.828] I [ timer ] Timer: WireCell::Aux::Resampler : 1.12 sec
[11:41:43.828] I [ timer ] Timer: WireCell::Aux::Resampler : 1.11 sec
[11:41:43.828] I [ timer ] Timer: WireCell::Aux::Resampler : 0.97 sec
[11:41:43.828] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[11:41:43.828] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.01 sec
[11:41:43.828] I [ timer ] Timer: WireCell::Gen::Retagger : 0.01 sec
[11:41:43.828] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[11:41:43.828] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[11:41:43.828] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[11:41:43.828] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[11:41:43.828] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[11:41:43.828] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[11:41:43.828] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[11:41:43.828] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[11:41:43.828] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0 sec
[11:41:43.828] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[11:41:43.828] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[11:41:43.828] I [ timer ] Timer: Total node execution : 60.30999985150993 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 39941 traces tagged "gauss"
FrameSaver: q=6.23847e+06 n=799166 tag=gauss
wclsFrameSaver: saving 47171 traces tagged "wiener"
FrameSaver: q=6.5194e+06 n=775196 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 376 XUs and 426 XVs -> 15 XUVs
C:0 T:1 276 XUs and 242 XVs -> 9 XUVs
C:0 T:2 432 XUs and 478 XVs -> 15 XUVs
C:0 T:3 416 XUs and 394 XVs -> 28 XUVs
C:0 T:4 415 XUs and 469 XVs -> 31 XUVs
C:0 T:5 2353 XUs and 2382 XVs -> 46 XUVs
C:0 T:6 12 XUs and 19 XVs -> 0 XUVs
C:0 T:7 334 XUs and 304 XVs -> 21 XUVs
C:0 T:8 1570 XUs and 1688 XVs -> 111 XUVs
C:0 T:9 1066 XUs and 1216 XVs -> 69 XUVs
C:0 T:10 3392 XUs and 3200 XVs -> 177 XUVs
C:0 T:11 481 XUs and 869 XVs -> 47 XUVs
C:0 T:12 2157 XUs and 1997 XVs -> 133 XUVs
C:0 T:13 525 XUs and 721 XVs -> 31 XUVs
C:0 T:14 603 XUs and 650 XVs -> 54 XUVs
C:0 T:15 1526 XUs and 1728 XVs -> 91 XUVs
878 XUVs total
780 collection wire objects
878 potential space points
Neighbour search...
3844 tests to find 1688 neighbours
Iterating with no regularization...
Begin: 6.94851e+08
0 6.9149e+08
1 6.91461e+08
Now with regularization...
Begin: 6.87458e+08
0 6.87457e+08
16-Sep-2025 11:42:30 CEST Closed output file "np02vd_raw_run039353_0794_df-s05-d2_dw_0_20250916T074330_reco_stage1_20250916T094230_keepup.root"
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 107.718 158.842 271.805 147.055 47.3806 19
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 4.51e-05 9.86584e-05 0.000255163 7.8041e-05 5.46866e-05 19
produce:tpcrawdecoder:PDVDTPCReader 4.97867 6.46444 7.62365 7.01867 1.03642 19
produce:triggerrawdecoder:PDVDTriggerReader4 0.00638234 0.0109349 0.0495581 0.00794596 0.00951584 19
produce:pdvddaphne:DAPHNEReaderPDVD 0.000230853 0.000346424 0.000666357 0.000334593 8.69882e-05 19
produce:ophit:OpHitFinder 0.000136902 0.000271937 0.000913219 0.000229232 0.000165937 19
produce:opflash:OpFlashFinderVerticalDrift 5.1321e-05 8.16498e-05 0.000379934 6.4661e-05 7.05134e-05 19
produce:wclsdatavd:WireCellToolkit 56.3491 65.7244 77.7541 65.4417 5.28427 19
produce:gaushit:GausHitFinder 0.779454 1.32809 2.24391 1.30822 0.427068 19
produce:nhitsfilter:NumberOfHitsFilter 0.000197432 0.000310801 0.000487055 0.000275812 8.68537e-05 19
produce:reco3d:SpacePointSolver 8.68737 15.7818 28.0595 15.1053 5.23749 19
produce:hitpdune:DisambigFromSpacePoints 0.0981871 0.207947 0.3937 0.215 0.076305 19
produce:pandora:StandardPandora 21.6933 63.3298 169.345 54.0688 39.5706 19
produce:pandoraTrack:LArPandoraTrackCreation 0.528709 1.08575 2.08756 1.08561 0.436748 19
produce:pandoraGnocalo:GnocchiCalorimetry 0.0183369 0.0301751 0.056412 0.0270827 0.0103622 19
[art]:TriggerResults:TriggerResultInserter 1.385e-05 2.74455e-05 8.9341e-05 2.329e-05 1.54725e-05 19
end_path:out1:RootOutput 3.92e-06 9.24805e-06 2.8521e-05 9.1e-06 5.06608e-06 19
end_path:out1:RootOutput(write) 4.01887 4.84333 6.33643 4.54883 0.729323 19
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 5048.49 MB
Peak resident set size usage (VmHWM): 3103.13 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run039353_0794_df-s05-d2_dw_0_20250916T074330_reco_stage1_20250916T094230_keepup.root
\tHists: np02vd_raw_run039353_0794_df-s05-d2_dw_0_20250916T074330_reco_stage1_20250916T094231_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run039353_0794_df-s05-d2_dw_0_20250916T074330_reco_stage1_20250916T094230_keepup.root
Ran successfully
{
"name": "np02vd_raw_run039353_0794_df-s05-d2_dw_0_20250916T074330_reco_stage1_20250916T094230_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": 1758015751.0,
"core.end_time": 1758015751.0,
"core.events": [
61222,
61226,
61230,
61234,
61238,
61242,
61246,
61250,
61254,
61258,
61262,
61266,
61270,
61274,
61278,
61282,
61286,
61290,
61294
],
"core.event_count": 19,
"core.first_event_number": 61222,
"core.last_event_number": 61294,
"core.data_stream": "cosmics",
"core.file_content_status": "good",
"core.file_type": "detector",
"core.run_type": "vd-protodune",
"core.runs": [
39353
],
"core.runs_subruns": [
3935300001
],
"dune.daq_test": false,
"retention.status": "active",
"retention.class": "physics"
},
"parents": [
{
"did": "vd-protodune:np02vd_raw_run039353_0794_df-s05-d2_dw_0_20250916T074330.hdf5"
}
]
}Forming hist metadata
formed
{
"name": "np02vd_raw_run039353_0794_df-s05-d2_dw_0_20250916T074330_reco_stage1_20250916T094231_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": 1758015751.0,
"core.end_time": 1758015751.0,
"core.data_stream": "cosmics",
"core.file_content_status": "good",
"core.file_type": "detector",
"core.run_type": "vd-protodune",
"core.runs": [
39353
],
"core.runs_subruns": [
3935300001
],
"dune.daq_test": false,
"retention.status": "active",
"retention.class": "physics"
},
"parents": [
{
"did": "vd-protodune:np02vd_raw_run039353_0794_df-s05-d2_dw_0_20250916T074330.hdf5"
}
]
} 