Jobsub ID 48913.21@dunegpschedd01.fnal.gov
Jobscript log (last 10,000 characters)
EOS at call=81 anode=1
[20:34:20.890] D [ glue ] <ChannelSelector:chsel0> see EOS at call=40
[20:34:20.890] D [ aux ] <Resampler:resmp0> EOS at call=81
[20:34:20.890] D [sigproc ] <OmnibusSigProc:anode0sigproc0> EOS at call=81 anode=0
[20:34:20.890] D [ glue ] <FrameFanin:nfsp> EOS at call=81 with 8
[20:34:20.890] D [ glue ] frame sink sees EOS
[20:34:20.890] D [ pgraph ] <Pgrapher:> graph execution complete
[20:34:20.890] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.08 sec
[20:34:20.890] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 6.27 sec
[20:34:20.890] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 4.66 sec
[20:34:20.890] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 4.22 sec
[20:34:20.890] I [ timer ] Timer: WireCell::Aux::Resampler : 0.24 sec
[20:34:20.890] I [ timer ] Timer: WireCell::Aux::Resampler : 0.18 sec
[20:34:20.890] I [ timer ] Timer: WireCell::Aux::Resampler : 0.17 sec
[20:34:20.890] I [ timer ] Timer: WireCell::Aux::Resampler : 0.13 sec
[20:34:20.890] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[20:34:20.890] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[20:34:20.890] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[20:34:20.890] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0 sec
[20:34:20.890] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[20:34:20.890] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[20:34:20.890] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[20:34:20.890] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[20:34:20.890] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[20:34:20.890] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[20:34:20.890] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[20:34:20.890] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[20:34:20.890] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[20:34:20.890] I [ timer ] Timer: WireCell::Gen::Retagger : 0 sec
[20:34:20.890] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[20:34:20.890] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0 sec
[20:34:20.890] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[20:34:20.890] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[20:34:20.890] I [ timer ] Timer: Total node execution : 23.9699995405972 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 24300 traces tagged "gauss"
FrameSaver: q=3.75597e+06 n=548676 tag=gauss
wclsFrameSaver: saving 32099 traces tagged "wiener"
FrameSaver: q=4.10326e+06 n=520158 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 523 XUs and 595 XVs -> 15 XUVs
C:0 T:1 782 XUs and 922 XVs -> 68 XUVs
C:0 T:2 373 XUs and 475 XVs -> 21 XUVs
C:0 T:3 9 XUs and 21 XVs -> 0 XUVs
C:0 T:4 3198 XUs and 2809 XVs -> 152 XUVs
C:0 T:5 6858 XUs and 5374 XVs -> 996 XUVs
C:0 T:6 40212 XUs and 35011 XVs -> 2847 XUVs
C:0 T:7 1533 XUs and 1650 XVs -> 88 XUVs
4187 XUVs total
1715 collection wire objects
4187 potential space points
Neighbour search...
268517 tests to find 91710 neighbours
Iterating with no regularization...
Begin: 1.4934e+09
0 1.37286e+09
1 1.36477e+09
2 1.36452e+09
Now with regularization...
Begin: 1.35393e+09
0 1.35387e+09
18-Sep-2025 20:34:57 BST Closed output file "np02vd_raw_run039499_0006_df-s05-d4_dw_0_20250918T175433_reco_stage1_20250918T193457_keepup.root"
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 54.6738 122.361 1117.96 85.4538 166.876 41
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 7.4052e-05 0.000108771 0.000330091 9.921e-05 4.13251e-05 41
produce:tpcrawdecoder:PDVDTPCReader 8.19299 24.5094 37.2518 26.0633 6.51295 41
produce:triggerrawdecoder:PDVDTriggerReader4 0.30989 0.332811 0.486469 0.316651 0.036083 41
produce:pdvddaphne:DAPHNEReaderPDVD 3.7152 5.78559 10.3884 5.29811 1.57951 41
produce:ophit:OpHitFinder 0.0302518 0.0413712 0.0532551 0.0426126 0.00520907 41
produce:opflash:OpFlashFinderVerticalDrift 0.00608821 0.0105372 0.0172937 0.0104325 0.00212009 41
produce:wclsdatavd:WireCellToolkit 18.2766 30.5814 61.2775 28.0402 8.6023 41
produce:gaushit:GausHitFinder 0.298855 0.581911 1.29451 0.485858 0.227241 41
produce:nhitsfilter:NumberOfHitsFilter 9.214e-05 0.000146608 0.000378814 0.000133753 5.28032e-05 41
produce:reco3d:SpacePointSolver 2.58426 5.94967 25.2151 5.04492 4.09075 41
produce:hitpdune:DisambigFromSpacePoints 0.0177915 0.087802 0.431563 0.0673083 0.0839386 41
produce:pandora:StandardPandora 5.2256 51.7087 1023.02 14.7287 161.933 41
produce:pandoraTrack:LArPandoraTrackCreation 0.101057 0.365431 1.85383 0.267924 0.354152 41
produce:pandoraGnocalo:GnocchiCalorimetry 0.006843 0.0153061 0.0379766 0.0134785 0.00618375 41
[art]:TriggerResults:TriggerResultInserter 1.5433e-05 3.41655e-05 7.3682e-05 3.0476e-05 1.21885e-05 41
end_path:out1:RootOutput 4.697e-06 9.33507e-06 3.4522e-05 8.523e-06 4.36426e-06 41
end_path:out1:RootOutput(write) 1.66411 2.36795 2.91711 2.37699 0.305415 41
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 4639.64 MB
Peak resident set size usage (VmHWM): 2630.28 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run039499_0006_df-s05-d4_dw_0_20250918T175433_reco_stage1_20250918T193457_keepup.root
\tHists: np02vd_raw_run039499_0006_df-s05-d4_dw_0_20250918T175433_reco_stage1_20250918T193457_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run039499_0006_df-s05-d4_dw_0_20250918T175433_reco_stage1_20250918T193457_keepup.root
Ran successfully
{
"name": "np02vd_raw_run039499_0006_df-s05-d4_dw_0_20250918T175433_reco_stage1_20250918T193457_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": 1758224098.0,
"core.end_time": 1758224098.0,
"core.events": [
1450,
1456,
1462,
1468,
1474,
1480,
1486,
1492,
1498,
1504,
1510,
1516,
1522,
1528,
1534,
1540,
1546,
1552,
1558,
1564,
1570,
1576,
1582,
1588,
1594,
1600,
1606,
1612,
1618,
1624,
1630,
1636,
1642,
1648,
1654,
1660,
1666,
1672,
1678,
1684,
1690
],
"core.event_count": 41,
"core.first_event_number": 1450,
"core.last_event_number": 1690,
"core.data_stream": "cosmics",
"core.file_content_status": "good",
"core.file_type": "detector",
"core.run_type": "vd-protodune",
"core.runs": [
39499
],
"core.runs_subruns": [
3949900001
],
"dune.daq_test": false,
"retention.status": "active",
"retention.class": "physics"
},
"parents": [
{
"did": "vd-protodune:np02vd_raw_run039499_0006_df-s05-d4_dw_0_20250918T175433.hdf5"
}
]
}Forming hist metadata
formed
{
"name": "np02vd_raw_run039499_0006_df-s05-d4_dw_0_20250918T175433_reco_stage1_20250918T193457_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": 1758224098.0,
"core.end_time": 1758224098.0,
"core.data_stream": "cosmics",
"core.file_content_status": "good",
"core.file_type": "detector",
"core.run_type": "vd-protodune",
"core.runs": [
39499
],
"core.runs_subruns": [
3949900001
],
"dune.daq_test": false,
"retention.status": "active",
"retention.class": "physics"
},
"parents": [
{
"did": "vd-protodune:np02vd_raw_run039499_0006_df-s05-d4_dw_0_20250918T175433.hdf5"
}
]
} 