Jobsub ID 38932.39@dunegpschedd02.fnal.gov
Jobscript log (last 10,000 characters)
ll=35
[18:59:13.482] D [sigproc ] <OmnibusSigProc:anode0sigproc0> EOS at call=35 anode=0
[18:59:13.482] D [ glue ] <FrameFanin:nfsp> EOS at call=35 with 8
[18:59:13.482] D [ glue ] frame sink sees EOS
[18:59:13.482] D [ pgraph ] <Pgrapher:> graph execution complete
[18:59:13.482] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 13.61 sec
[18:59:13.482] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 10.79 sec
[18:59:13.482] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 10.19 sec
[18:59:13.482] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 9.85 sec
[18:59:13.482] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 9.43 sec
[18:59:13.482] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 9.2 sec
[18:59:13.482] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 9.06 sec
[18:59:13.482] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.85 sec
[18:59:13.482] I [ timer ] Timer: WireCell::Aux::Resampler : 0.68 sec
[18:59:13.482] I [ timer ] Timer: WireCell::Aux::Resampler : 0.66 sec
[18:59:13.482] I [ timer ] Timer: WireCell::Aux::Resampler : 0.66 sec
[18:59:13.482] I [ timer ] Timer: WireCell::Aux::Resampler : 0.65 sec
[18:59:13.482] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.03 sec
[18:59:13.482] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.02 sec
[18:59:13.482] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[18:59:13.482] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0.01 sec
[18:59:13.482] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[18:59:13.482] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[18:59:13.482] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[18:59:13.482] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[18:59:13.482] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[18:59:13.482] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[18:59:13.482] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[18:59:13.482] I [ timer ] Timer: WireCell::Gen::Retagger : 0 sec
[18:59:13.482] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[18:59:13.482] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[18:59:13.482] I [ timer ] Timer: Total node execution : 83.70000053010881 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 63247 traces tagged "gauss"
FrameSaver: q=1.20766e+07 n=1407218 tag=gauss
wclsFrameSaver: saving 79556 traces tagged "wiener"
FrameSaver: q=1.28854e+07 n=1335547 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 480 XUs and 798 XVs -> 36 XUVs
C:0 T:1 453 XUs and 622 XVs -> 25 XUVs
C:0 T:2 573 XUs and 408 XVs -> 27 XUVs
C:0 T:3 1084 XUs and 1382 XVs -> 58 XUVs
C:0 T:4 1206 XUs and 1104 XVs -> 63 XUVs
C:0 T:5 916 XUs and 846 XVs -> 54 XUVs
C:0 T:6 252 XUs and 212 XVs -> 7 XUVs
C:0 T:7 2185 XUs and 2837 XVs -> 141 XUVs
C:0 T:8 31870 XUs and 71476 XVs -> 12986 XUVs
C:0 T:9 9429 XUs and 15721 XVs -> 2392 XUVs
C:0 T:10 14141 XUs and 22921 XVs -> 2242 XUVs
C:0 T:11 4362 XUs and 5330 XVs -> 654 XUVs
C:0 T:12 10270 XUs and 11540 XVs -> 1609 XUVs
C:0 T:13 3445 XUs and 3254 XVs -> 163 XUVs
C:0 T:14 4877 XUs and 4533 XVs -> 199 XUVs
C:0 T:15 766 XUs and 680 XVs -> 47 XUVs
20703 XUVs total
2974 collection wire objects
20703 potential space points
Neighbour search...
3100591 tests to find 1254644 neighbours
Iterating with no regularization...
Begin: 7.92502e+08
0 6.8138e+08
1 6.73897e+08
2 6.72641e+08
3 6.72211e+08
Now with regularization...
Begin: 6.53056e+08
0 6.52682e+08
12-Sep-2025 19:01:27 CEST Closed output file "np02vd_raw_run039273_1343_df-s02-d2_dw_0_20250901T040032_reco_stage1_20250912T170127_keepup.root"
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 166.064 239.491 352.416 239.988 47.409 18
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 7.7728e-05 0.000118263 0.000194033 0.00010648 3.5439e-05 18
produce:tpcrawdecoder:PDVDTPCReader 10.9678 21.2461 39.053 20.3415 5.5673 18
produce:triggerrawdecoder:PDVDTriggerReader4 0.0216978 0.0253748 0.0456276 0.0222384 0.00653307 18
produce:pdvddaphne:DAPHNEReaderPDVD 4.71816 5.54156 6.94292 5.30707 0.611422 18
produce:ophit:OpHitFinder 0.0337741 0.043494 0.0522345 0.0450622 0.00545282 18
produce:opflash:OpFlashFinderVerticalDrift 0.00615197 0.0134457 0.0192532 0.0138611 0.00299679 18
produce:wclsdatavd:WireCellToolkit 72.0822 89.7442 110.734 89.3514 7.74538 18
produce:gaushit:GausHitFinder 0.937765 1.36567 1.77925 1.38973 0.242819 18
produce:nhitsfilter:NumberOfHitsFilter 0.000425963 0.000602552 0.000947675 0.000586451 0.000110827 18
produce:reco3d:SpacePointSolver 13.6352 21.1621 34.0618 21.2861 4.96417 18
produce:hitpdune:DisambigFromSpacePoints 0.16073 0.289844 0.462214 0.284534 0.0759259 18
produce:pandora:StandardPandora 42.0654 93.1486 185.699 87.3442 39.4193 18
produce:pandoraTrack:LArPandoraTrackCreation 0.982128 2.20658 4.8378 2.10603 0.814405 18
produce:pandoraGnocalo:GnocchiCalorimetry 0.0233313 0.0332372 0.0484384 0.033448 0.00617948 18
[art]:TriggerResults:TriggerResultInserter 4.1782e-05 5.30851e-05 9.3772e-05 4.9655e-05 1.13399e-05 18
end_path:out1:RootOutput 9.521e-06 1.68557e-05 4.054e-05 1.48025e-05 6.5894e-06 18
end_path:out1:RootOutput(write) 4.22102 4.59353 5.23424 4.55296 0.250343 18
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 5326.51 MB
Peak resident set size usage (VmHWM): 3430.98 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run039273_1343_df-s02-d2_dw_0_20250901T040032_reco_stage1_20250912T170127_keepup.root
\tHists: np02vd_raw_run039273_1343_df-s02-d2_dw_0_20250901T040032_reco_stage1_20250912T170127_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run039273_1343_df-s02-d2_dw_0_20250901T040032_reco_stage1_20250912T170127_keepup.root
Ran successfully
{
"name": "np02vd_raw_run039273_1343_df-s02-d2_dw_0_20250901T040032_reco_stage1_20250912T170127_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": 1757696487.0,
"core.end_time": 1757696487.0,
"core.events": [
483484,
483504,
483524,
483544,
483564,
483584,
483604,
483624,
483644,
483664,
483684,
483704,
483724,
483744,
483764,
483784,
483804,
483824
],
"core.event_count": 18,
"core.first_event_number": 483484,
"core.last_event_number": 483824,
"core.data_stream": "physics",
"core.file_content_status": "good",
"core.file_type": "detector",
"core.run_type": "vd-protodune",
"core.runs": [
39273
],
"core.runs_subruns": [
3927300001
],
"dune.daq_test": false,
"retention.status": "active",
"retention.class": "physics"
},
"parents": [
{
"did": "vd-protodune:np02vd_raw_run039273_1343_df-s02-d2_dw_0_20250901T040032.hdf5"
}
]
}Forming hist metadata
formed
{
"name": "np02vd_raw_run039273_1343_df-s02-d2_dw_0_20250901T040032_reco_stage1_20250912T170127_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": 1757696487.0,
"core.end_time": 1757696487.0,
"core.data_stream": "physics",
"core.file_content_status": "good",
"core.file_type": "detector",
"core.run_type": "vd-protodune",
"core.runs": [
39273
],
"core.runs_subruns": [
3927300001
],
"dune.daq_test": false,
"retention.status": "active",
"retention.class": "physics"
},
"parents": [
{
"did": "vd-protodune:np02vd_raw_run039273_1343_df-s02-d2_dw_0_20250901T040032.hdf5"
}
]
}