Jobsub ID 41739.112@dunegpschedd02.fnal.gov
Jobscript log (last 10,000 characters)
D [sigproc ] <OmnibusSigProc:anode0sigproc0> EOS at call=97 anode=0
[11:31:17.011] D [ glue ] <FrameFanin:nfsp> EOS at call=97 with 8
[11:31:17.011] D [ glue ] frame sink sees EOS
[11:31:17.011] D [ pgraph ] <Pgrapher:> graph execution complete
[11:31:17.011] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 10.21 sec
[11:31:17.011] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 9.13 sec
[11:31:17.011] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.67 sec
[11:31:17.011] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.7 sec
[11:31:17.011] I [ timer ] Timer: WireCell::Aux::Resampler : 0.62 sec
[11:31:17.011] I [ timer ] Timer: WireCell::Aux::Resampler : 0.59 sec
[11:31:17.011] I [ timer ] Timer: WireCell::Aux::Resampler : 0.59 sec
[11:31:17.011] I [ timer ] Timer: WireCell::Aux::Resampler : 0.42 sec
[11:31:17.011] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[11:31:17.011] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[11:31:17.011] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[11:31:17.011] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[11:31:17.011] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0 sec
[11:31:17.012] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[11:31:17.012] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[11:31:17.012] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[11:31:17.012] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[11:31:17.012] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[11:31:17.012] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[11:31:17.012] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[11:31:17.012] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[11:31:17.012] I [ timer ] Timer: WireCell::Gen::Retagger : 0 sec
[11:31:17.012] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0 sec
[11:31:17.012] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[11:31:17.012] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[11:31:17.012] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[11:31:17.012] I [ timer ] Timer: Total node execution : 37.929999977350235 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 11761 traces tagged "gauss"
FrameSaver: q=2.01142e+06 n=254569 tag=gauss
wclsFrameSaver: saving 14676 traces tagged "wiener"
FrameSaver: q=2.15473e+06 n=243734 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 97 XUs and 120 XVs -> 3 XUVs
C:0 T:1 629 XUs and 729 XVs -> 24 XUVs
C:0 T:2 735 XUs and 579 XVs -> 53 XUVs
C:0 T:3 609 XUs and 813 XVs -> 53 XUVs
C:0 T:4 6503 XUs and 6885 XVs -> 654 XUVs
C:0 T:5 360 XUs and 411 XVs -> 29 XUVs
C:0 T:6 69 XUs and 80 XVs -> 1 XUVs
C:0 T:7 11 XUs and 19 XVs -> 0 XUVs
817 XUVs total
527 collection wire objects
817 potential space points
Neighbour search...
30425 tests to find 8576 neighbours
Iterating with no regularization...
Begin: 1.39642e+09
0 1.36281e+09
1 1.36055e+09
2 1.36054e+09
Now with regularization...
Begin: 1.32421e+09
0 1.32419e+09
18-Sep-2025 11:31:34 BST Closed output file "np02vd_raw_run039433_0391_df-s05-d2_dw_0_20250918T072424_reco_stage1_20250918T103134_keepup.root"
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 101.314 166.765 509.157 137.458 73.197 49
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 7.7978e-05 0.000115525 0.000793208 9.7033e-05 9.94814e-05 49
produce:tpcrawdecoder:PDVDTPCReader 33.4317 47.4463 69.1594 47.0527 6.84771 49
produce:triggerrawdecoder:PDVDTriggerReader4 0.380334 0.469459 0.881167 0.446411 0.100564 49
produce:pdvddaphne:DAPHNEReaderPDVD 7.8499 11.9395 17.703 11.478 2.37875 49
produce:ophit:OpHitFinder 0.053669 0.067696 0.102283 0.0667178 0.00763171 49
produce:opflash:OpFlashFinderVerticalDrift 0.00686136 0.0156961 0.0227553 0.015416 0.00408809 49
produce:wclsdatavd:WireCellToolkit 31.8106 52.103 86.8557 45.5718 13.8072 49
produce:gaushit:GausHitFinder 0.396683 0.967881 2.40271 0.932751 0.33495 49
produce:nhitsfilter:NumberOfHitsFilter 0.000111931 0.000227204 0.000583281 0.000214054 9.12984e-05 49
produce:reco3d:SpacePointSolver 3.04119 8.39963 27.2156 7.79826 4.62064 49
produce:hitpdune:DisambigFromSpacePoints 0.0251667 0.136902 0.49678 0.101398 0.0950762 49
produce:pandora:StandardPandora 3.36148 41.1094 336.428 21.848 62.9395 49
produce:pandoraTrack:LArPandoraTrackCreation 0.132791 0.529038 1.95088 0.387518 0.371806 49
produce:pandoraGnocalo:GnocchiCalorimetry 0.0125442 0.0256354 0.0453444 0.0259399 0.00725845 49
[art]:TriggerResults:TriggerResultInserter 1.9196e-05 3.5968e-05 0.000156366 2.8995e-05 2.16782e-05 49
end_path:out1:RootOutput 4.218e-06 6.1481e-06 3.5597e-05 5.5e-06 4.29718e-06 49
end_path:out1:RootOutput(write) 2.42878 3.52785 4.57771 3.51904 0.352846 49
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 4542.43 MB
Peak resident set size usage (VmHWM): 2628.06 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run039433_0391_df-s05-d2_dw_0_20250918T072424_reco_stage1_20250918T103134_keepup.root
\tHists: np02vd_raw_run039433_0391_df-s05-d2_dw_0_20250918T072424_reco_stage1_20250918T103135_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run039433_0391_df-s05-d2_dw_0_20250918T072424_reco_stage1_20250918T103134_keepup.root
Ran successfully
{
"name": "np02vd_raw_run039433_0391_df-s05-d2_dw_0_20250918T072424_reco_stage1_20250918T103134_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": 1758191496.0,
"core.end_time": 1758191496.0,
"core.events": [
112166,
112172,
112178,
112184,
112190,
112196,
112202,
112208,
112214,
112220,
112226,
112232,
112238,
112244,
112250,
112256,
112262,
112268,
112274,
112280,
112286,
112292,
112298,
112304,
112310,
112316,
112322,
112328,
112334,
112340,
112346,
112352,
112358,
112364,
112370,
112376,
112382,
112388,
112394,
112400,
112406,
112412,
112418,
112424,
112430,
112436,
112442,
112448,
112454
],
"core.event_count": 49,
"core.first_event_number": 112166,
"core.last_event_number": 112454,
"core.data_stream": "cosmics",
"core.file_content_status": "good",
"core.file_type": "detector",
"core.run_type": "vd-protodune",
"core.runs": [
39433
],
"core.runs_subruns": [
3943300001
],
"dune.daq_test": false,
"retention.status": "active",
"retention.class": "physics"
},
"parents": [
{
"did": "vd-protodune:np02vd_raw_run039433_0391_df-s05-d2_dw_0_20250918T072424.hdf5"
}
]
}Forming hist metadata
formed
{
"name": "np02vd_raw_run039433_0391_df-s05-d2_dw_0_20250918T072424_reco_stage1_20250918T103135_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": 1758191496.0,
"core.end_time": 1758191496.0,
"core.data_stream": "cosmics",
"core.file_content_status": "good",
"core.file_type": "detector",
"core.run_type": "vd-protodune",
"core.runs": [
39433
],
"core.runs_subruns": [
3943300001
],
"dune.daq_test": false,
"retention.status": "active",
"retention.class": "physics"
},
"parents": [
{
"did": "vd-protodune:np02vd_raw_run039433_0391_df-s05-d2_dw_0_20250918T072424.hdf5"
}
]
} 