Jobsub ID 48951.0@dunegpschedd01.fnal.gov
Jobscript log (last 10,000 characters)
[21:51:08.587] D [sigproc ] <OmnibusSigProc:anode1sigproc1> EOS at call=81 anode=1
[21:51:08.587] D [ glue ] <ChannelSelector:chsel0> see EOS at call=40
[21:51:08.587] D [ aux ] <Resampler:resmp0> EOS at call=81
[21:51:08.587] D [sigproc ] <OmnibusSigProc:anode0sigproc0> EOS at call=81 anode=0
[21:51:08.587] D [ glue ] <FrameFanin:nfsp> EOS at call=81 with 8
[21:51:08.587] D [ glue ] frame sink sees EOS
[21:51:08.587] D [ pgraph ] <Pgrapher:> graph execution complete
[21:51:08.587] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 10.25 sec
[21:51:08.587] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.26 sec
[21:51:08.587] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.22 sec
[21:51:08.587] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.01 sec
[21:51:08.587] I [ timer ] Timer: WireCell::Aux::Resampler : 0.28 sec
[21:51:08.587] I [ timer ] Timer: WireCell::Aux::Resampler : 0.25 sec
[21:51:08.587] I [ timer ] Timer: WireCell::Aux::Resampler : 0.25 sec
[21:51:08.587] I [ timer ] Timer: WireCell::Aux::Resampler : 0.24 sec
[21:51:08.587] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.01 sec
[21:51:08.587] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[21:51:08.587] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[21:51:08.587] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[21:51:08.587] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[21:51:08.587] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[21:51:08.587] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[21:51:08.587] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[21:51:08.587] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[21:51:08.587] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[21:51:08.587] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[21:51:08.587] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[21:51:08.587] I [ timer ] Timer: WireCell::Gen::Retagger : 0 sec
[21:51:08.587] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0 sec
[21:51:08.587] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[21:51:08.587] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[21:51:08.587] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[21:51:08.587] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[21:51:08.587] I [ timer ] Timer: Total node execution : 35.7900007199496 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 20337 traces tagged "gauss"
FrameSaver: q=2.94821e+06 n=413184 tag=gauss
wclsFrameSaver: saving 26737 traces tagged "wiener"
FrameSaver: q=3.16422e+06 n=387983 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 12644 XUs and 14847 XVs -> 791 XUVs
C:0 T:1 1196 XUs and 1466 XVs -> 80 XUVs
C:0 T:2 356 XUs and 639 XVs -> 13 XUVs
C:0 T:3 806 XUs and 1042 XVs -> 68 XUVs
C:0 T:4 647 XUs and 1011 XVs -> 39 XUVs
C:0 T:5 748 XUs and 644 XVs -> 27 XUVs
C:0 T:6 1320 XUs and 1020 XVs -> 74 XUVs
C:0 T:7 708 XUs and 837 XVs -> 49 XUVs
1141 XUVs total
850 collection wire objects
1141 potential space points
Neighbour search...
16611 tests to find 5114 neighbours
Iterating with no regularization...
Begin: 1.46368e+09
0 1.39693e+09
1 1.39552e+09
2 1.39547e+09
Now with regularization...
Begin: 1.38164e+09
0 1.38163e+09
18-Sep-2025 21:51:31 CEST Closed output file "np02vd_raw_run039491_0000_df-s04-d2_dw_0_20250918T164933_reco_stage1_20250918T195131_keepup.root"
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 58.9685 89.0283 162.192 86.6487 20.2555 41
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 6.6522e-05 0.000145153 0.00191396 9.2193e-05 0.000280922 41
produce:tpcrawdecoder:PDVDTPCReader 9.52134 11.1936 16.2813 10.6814 1.7157 41
produce:triggerrawdecoder:PDVDTriggerReader4 0.581101 0.702439 1.52233 0.5945 0.19266 41
produce:pdvddaphne:DAPHNEReaderPDVD 2.81413 3.9331 5.54371 3.82813 0.540672 41
produce:ophit:OpHitFinder 0.0332324 0.0507182 0.0883526 0.0483799 0.0118225 41
produce:opflash:OpFlashFinderVerticalDrift 0.00586459 0.0135771 0.0244109 0.0131747 0.0039526 41
produce:wclsdatavd:WireCellToolkit 31.0491 43.2738 78.2238 39.0306 11.1242 41
produce:gaushit:GausHitFinder 0.318414 0.66804 1.29488 0.669079 0.182383 41
produce:nhitsfilter:NumberOfHitsFilter 6.2012e-05 0.000409604 0.00124978 0.000390042 0.000233383 41
produce:reco3d:SpacePointSolver 2.29485 5.70588 10.5506 5.73181 1.75626 41
produce:hitpdune:DisambigFromSpacePoints 0.039446 0.0767993 0.16845 0.0720552 0.0279852 41
produce:pandora:StandardPandora 4.73055 20.429 89.2916 17.7166 13.7307 41
produce:pandoraTrack:LArPandoraTrackCreation 0.124387 0.383053 1.52307 0.330429 0.245443 41
produce:pandoraGnocalo:GnocchiCalorimetry 0.00942612 0.0180691 0.0313187 0.0173777 0.00457983 41
[art]:TriggerResults:TriggerResultInserter 1.7611e-05 3.90052e-05 0.000115554 3.1351e-05 2.1392e-05 41
end_path:out1:RootOutput 3.99e-06 6.3631e-06 2.3541e-05 5.27e-06 3.3977e-06 41
end_path:out1:RootOutput(write) 2.21214 2.54168 3.76021 2.44565 0.295516 41
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 5177.57 MB
Peak resident set size usage (VmHWM): 3264.41 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run039491_0000_df-s04-d2_dw_0_20250918T164933_reco_stage1_20250918T195131_keepup.root
\tHists: np02vd_raw_run039491_0000_df-s04-d2_dw_0_20250918T164933_reco_stage1_20250918T195132_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run039491_0000_df-s04-d2_dw_0_20250918T164933_reco_stage1_20250918T195131_keepup.root
Ran successfully
{
"name": "np02vd_raw_run039491_0000_df-s04-d2_dw_0_20250918T164933_reco_stage1_20250918T195131_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": 1758225093.0,
"core.end_time": 1758225093.0,
"core.events": [
1,
7,
13,
19,
25,
31,
37,
43,
49,
55,
61,
67,
73,
79,
85,
91,
97,
103,
109,
115,
121,
127,
133,
139,
145,
151,
157,
163,
169,
175,
181,
187,
193,
199,
205,
211,
217,
223,
229,
235,
241
],
"core.event_count": 41,
"core.first_event_number": 1,
"core.last_event_number": 241,
"core.data_stream": "cosmics",
"core.file_content_status": "good",
"core.file_type": "detector",
"core.run_type": "vd-protodune",
"core.runs": [
39491
],
"core.runs_subruns": [
3949100001
],
"dune.daq_test": false,
"retention.status": "active",
"retention.class": "physics"
},
"parents": [
{
"did": "vd-protodune:np02vd_raw_run039491_0000_df-s04-d2_dw_0_20250918T164933.hdf5"
}
]
}Forming hist metadata
formed
{
"name": "np02vd_raw_run039491_0000_df-s04-d2_dw_0_20250918T164933_reco_stage1_20250918T195132_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": 1758225093.0,
"core.end_time": 1758225093.0,
"core.data_stream": "cosmics",
"core.file_content_status": "good",
"core.file_type": "detector",
"core.run_type": "vd-protodune",
"core.runs": [
39491
],
"core.runs_subruns": [
3949100001
],
"dune.daq_test": false,
"retention.status": "active",
"retention.class": "physics"
},
"parents": [
{
"did": "vd-protodune:np02vd_raw_run039491_0000_df-s04-d2_dw_0_20250918T164933.hdf5"
}
]
} 