Jobsub ID 42699.26@dunegpschedd02.fnal.gov
Jobscript log (last 10,000 characters)
:56:28.825] D [ glue ] <ChannelSelector:chsel0> see EOS at call=39
[01:56:28.825] D [ aux ] <Resampler:resmp0> EOS at call=79
[01:56:28.825] D [sigproc ] <OmnibusSigProc:anode0sigproc0> EOS at call=79 anode=0
[01:56:28.825] D [ glue ] <FrameFanin:nfsp> EOS at call=79 with 8
[01:56:28.825] D [ glue ] frame sink sees EOS
[01:56:28.825] D [ pgraph ] <Pgrapher:> graph execution complete
[01:56:28.825] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 10.65 sec
[01:56:28.825] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.19 sec
[01:56:28.825] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.19 sec
[01:56:28.825] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.84 sec
[01:56:28.825] I [ timer ] Timer: WireCell::Aux::Resampler : 0.43 sec
[01:56:28.825] I [ timer ] Timer: WireCell::Aux::Resampler : 0.41 sec
[01:56:28.825] I [ timer ] Timer: WireCell::Aux::Resampler : 0.4 sec
[01:56:28.825] I [ timer ] Timer: WireCell::Aux::Resampler : 0.38 sec
[01:56:28.825] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0.01 sec
[01:56:28.825] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[01:56:28.825] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[01:56:28.825] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[01:56:28.825] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[01:56:28.825] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0 sec
[01:56:28.825] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[01:56:28.825] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[01:56:28.825] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[01:56:28.825] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[01:56:28.825] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[01:56:28.825] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[01:56:28.825] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[01:56:28.825] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[01:56:28.825] I [ timer ] Timer: WireCell::Gen::Retagger : 0 sec
[01:56:28.825] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[01:56:28.825] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[01:56:28.825] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[01:56:28.825] I [ timer ] Timer: Total node execution : 36.49999893642962 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 22814 traces tagged "gauss"
FrameSaver: q=5.8979e+06 n=528459 tag=gauss
wclsFrameSaver: saving 28569 traces tagged "wiener"
FrameSaver: q=6.41391e+06 n=511628 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 467 XUs and 353 XVs -> 10 XUVs
C:0 T:1 234 XUs and 284 XVs -> 14 XUVs
C:0 T:2 1068 XUs and 873 XVs -> 51 XUVs
C:0 T:3 1619 XUs and 1937 XVs -> 70 XUVs
C:0 T:4 287 XUs and 306 XVs -> 18 XUVs
C:0 T:5 23750 XUs and 28616 XVs -> 2277 XUVs
C:0 T:6 1642 XUs and 1792 XVs -> 76 XUVs
C:0 T:7 673 XUs and 640 XVs -> 44 XUVs
2560 XUVs total
1075 collection wire objects
2560 potential space points
Neighbour search...
99252 tests to find 22400 neighbours
Iterating with no regularization...
Begin: 1.96386e+10
0 1.91695e+10
1 1.91305e+10
2 1.91295e+10
Now with regularization...
Begin: 1.87018e+10
0 1.87009e+10
19-Sep-2025 01:56:59 BST Closed output file "np02vd_raw_run039499_0109_df-s04-d1_dw_0_20250918T212124_reco_stage1_20250919T005659_keepup.root"
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 59.9917 124.801 1309.2 84.273 192.867 40
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 5.9881e-05 9.65082e-05 0.000318993 8.876e-05 3.7743e-05 40
produce:tpcrawdecoder:PDVDTPCReader 8.48093 26.2203 73.2303 25.5345 9.12081 40
produce:triggerrawdecoder:PDVDTriggerReader4 0.308854 0.342963 0.454218 0.328935 0.0376056 40
produce:pdvddaphne:DAPHNEReaderPDVD 3.4101 6.04647 11.7051 5.64774 1.58093 40
produce:ophit:OpHitFinder 0.0219221 0.0368551 0.0563731 0.0370726 0.00611766 40
produce:opflash:OpFlashFinderVerticalDrift 0.00324368 0.00921301 0.0149798 0.00941738 0.00250479 40
produce:wclsdatavd:WireCellToolkit 21.087 29.218 64.8384 26.5163 9.05472 40
produce:gaushit:GausHitFinder 0.220342 0.59448 1.44078 0.56629 0.180612 40
produce:nhitsfilter:NumberOfHitsFilter 7.277e-05 0.000146224 0.000474819 0.000134369 6.12293e-05 40
produce:reco3d:SpacePointSolver 1.74249 6.05167 22.3569 5.43481 3.49573 40
produce:hitpdune:DisambigFromSpacePoints 0.0139509 0.083173 0.335468 0.0693515 0.059498 40
produce:pandora:StandardPandora 4.23746 53.4449 1178.17 15.9604 182.519 40
produce:pandoraTrack:LArPandoraTrackCreation 0.087403 0.342326 1.68825 0.268749 0.271489 40
produce:pandoraGnocalo:GnocchiCalorimetry 0.00766976 0.0155539 0.0467991 0.0150101 0.00651188 40
[art]:TriggerResults:TriggerResultInserter 1.985e-05 3.73588e-05 0.000132621 3.2875e-05 1.80029e-05 40
end_path:out1:RootOutput 4.657e-06 8.4453e-06 3.5685e-05 7.7415e-06 4.90344e-06 40
end_path:out1:RootOutput(write) 1.71217 2.36857 3.30842 2.36448 0.269916 40
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 6263.48 MB
Peak resident set size usage (VmHWM): 4246.88 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run039499_0109_df-s04-d1_dw_0_20250918T212124_reco_stage1_20250919T005659_keepup.root
\tHists: np02vd_raw_run039499_0109_df-s04-d1_dw_0_20250918T212124_reco_stage1_20250919T005659_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run039499_0109_df-s04-d1_dw_0_20250918T212124_reco_stage1_20250919T005659_keepup.root
Ran successfully
{
"name": "np02vd_raw_run039499_0109_df-s04-d1_dw_0_20250918T212124_reco_stage1_20250919T005659_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": 1758243420.0,
"core.end_time": 1758243420.0,
"core.events": [
26544,
26550,
26556,
26562,
26568,
26574,
26580,
26586,
26592,
26598,
26604,
26610,
26616,
26622,
26628,
26634,
26640,
26646,
26652,
26658,
26664,
26670,
26676,
26682,
26688,
26694,
26700,
26706,
26712,
26718,
26724,
26730,
26736,
26742,
26748,
26754,
26760,
26766,
26772,
26778
],
"core.event_count": 40,
"core.first_event_number": 26544,
"core.last_event_number": 26778,
"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_0109_df-s04-d1_dw_0_20250918T212124.hdf5"
}
]
}Forming hist metadata
formed
{
"name": "np02vd_raw_run039499_0109_df-s04-d1_dw_0_20250918T212124_reco_stage1_20250919T005659_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": 1758243420.0,
"core.end_time": 1758243420.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_0109_df-s04-d1_dw_0_20250918T212124.hdf5"
}
]
}