Jobsub ID 40600.38@dunegpschedd02.fnal.gov
Jobscript log (last 10,000 characters)
[sigproc ] <OmnibusSigProc:anode0sigproc0> EOS at call=37 anode=0
[23:49:55.471] D [ glue ] <FrameFanin:nfsp> EOS at call=37 with 8
[23:49:55.471] D [ glue ] frame sink sees EOS
[23:49:55.471] D [ pgraph ] <Pgrapher:> graph execution complete
[23:49:55.471] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 10.49 sec
[23:49:55.471] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 10.1 sec
[23:49:55.471] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 10.07 sec
[23:49:55.471] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 9.19 sec
[23:49:55.471] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 9.04 sec
[23:49:55.471] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.8 sec
[23:49:55.471] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.68 sec
[23:49:55.471] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.03 sec
[23:49:55.471] I [ timer ] Timer: WireCell::Aux::Resampler : 0.96 sec
[23:49:55.471] I [ timer ] Timer: WireCell::Aux::Resampler : 0.93 sec
[23:49:55.471] I [ timer ] Timer: WireCell::Aux::Resampler : 0.88 sec
[23:49:55.471] I [ timer ] Timer: WireCell::Aux::Resampler : 0.77 sec
[23:49:55.471] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.04 sec
[23:49:55.471] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.02 sec
[23:49:55.471] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[23:49:55.471] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[23:49:55.471] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[23:49:55.471] I [ timer ] Timer: WireCell::Gen::Retagger : 0.01 sec
[23:49:55.471] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[23:49:55.471] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[23:49:55.471] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[23:49:55.471] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[23:49:55.471] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[23:49:55.471] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0 sec
[23:49:55.471] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[23:49:55.471] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[23:49:55.471] I [ timer ] Timer: Total node execution : 78.03999957814813 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 59783 traces tagged "gauss"
FrameSaver: q=9.20791e+06 n=1223162 tag=gauss
wclsFrameSaver: saving 72933 traces tagged "wiener"
FrameSaver: q=9.6773e+06 n=1178354 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 207 XUs and 229 XVs -> 16 XUVs
C:0 T:1 422 XUs and 440 XVs -> 32 XUVs
C:0 T:2 597 XUs and 632 XVs -> 27 XUVs
C:0 T:3 833 XUs and 754 XVs -> 36 XUVs
C:0 T:4 1852 XUs and 1653 XVs -> 51 XUVs
C:0 T:5 6112 XUs and 6027 XVs -> 288 XUVs
C:0 T:6 2922 XUs and 2289 XVs -> 182 XUVs
C:0 T:7 942 XUs and 1082 XVs -> 45 XUVs
C:0 T:8 800 XUs and 1174 XVs -> 80 XUVs
C:0 T:9 2987 XUs and 4424 XVs -> 270 XUVs
C:0 T:10 1677 XUs and 1562 XVs -> 101 XUVs
C:0 T:11 635 XUs and 870 XVs -> 41 XUVs
C:0 T:12 2819 XUs and 4309 XVs -> 256 XUVs
C:0 T:13 3661 XUs and 3744 XVs -> 185 XUVs
C:0 T:14 1139 XUs and 1656 XVs -> 64 XUVs
C:0 T:15 808 XUs and 926 XVs -> 51 XUVs
1725 XUVs total
1419 collection wire objects
1725 potential space points
Neighbour search...
15129 tests to find 8012 neighbours
Iterating with no regularization...
Begin: 3.73019e+08
0 3.59e+08
1 3.58687e+08
Now with regularization...
Begin: 3.51827e+08
0 3.51807e+08
BdtBeamParticleIdTool::SliceFeatures::GetLeadingCaloHits - empty calo hit list
16-Sep-2025 23:51:54 CEST Closed output file "np02vd_raw_run039388_0316_df-s05-d1_dw_0_20250916T195056_reco_stage1_20250916T215154_keepup.root"
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 133.678 189.141 349.228 174.372 49.5058 19
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 8.7543e-05 0.000157116 0.000648324 0.000120874 0.000122459 19
produce:tpcrawdecoder:PDVDTPCReader 8.51056 9.7285 11.1694 9.84901 0.75643 19
produce:triggerrawdecoder:PDVDTriggerReader4 0.0469684 0.0513532 0.0573712 0.0510714 0.00296354 19
produce:pdvddaphne:DAPHNEReaderPDVD 0.000223299 0.000451843 0.00146706 0.000379516 0.000264977 19
produce:ophit:OpHitFinder 0.000141705 0.000401131 0.00209067 0.000269609 0.000439902 19
produce:opflash:OpFlashFinderVerticalDrift 4.0322e-05 0.000126053 0.000980328 6.4288e-05 0.000205784 19
produce:wclsdatavd:WireCellToolkit 69.6064 78.4837 86.5978 77.7295 5.36162 19
produce:gaushit:GausHitFinder 0.896223 1.70411 2.27817 1.69589 0.347553 19
produce:nhitsfilter:NumberOfHitsFilter 0.000275197 0.000733796 0.00149916 0.000545539 0.000415378 19
produce:reco3d:SpacePointSolver 10.1195 16.9647 25.3471 17.6967 4.24503 19
produce:hitpdune:DisambigFromSpacePoints 0.156729 0.293007 0.51551 0.270409 0.0946187 19
produce:pandora:StandardPandora 22.0564 73.3989 219.824 59.8151 43.0777 19
produce:pandoraTrack:LArPandoraTrackCreation 0.561975 2.46785 4.81465 2.41509 1.17102 19
produce:pandoraGnocalo:GnocchiCalorimetry 0.0237531 0.0478736 0.0742363 0.049663 0.0129796 19
[art]:TriggerResults:TriggerResultInserter 3.3682e-05 8.81729e-05 0.00019709 7.9751e-05 4.41258e-05 19
end_path:out1:RootOutput 8.733e-06 1.96926e-05 6.6842e-05 1.5774e-05 1.25232e-05 19
end_path:out1:RootOutput(write) 4.48803 5.89278 6.47875 5.97748 0.425848 19
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 5408.25 MB
Peak resident set size usage (VmHWM): 3492.09 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run039388_0316_df-s05-d1_dw_0_20250916T195056_reco_stage1_20250916T215154_keepup.root
\tHists: np02vd_raw_run039388_0316_df-s05-d1_dw_0_20250916T195056_reco_stage1_20250916T215155_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run039388_0316_df-s05-d1_dw_0_20250916T195056_reco_stage1_20250916T215154_keepup.root
Ran successfully
{
"name": "np02vd_raw_run039388_0316_df-s05-d1_dw_0_20250916T195056_reco_stage1_20250916T215154_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": 1758059516.0,
"core.end_time": 1758059516.0,
"core.events": [
24353,
24357,
24361,
24365,
24369,
24373,
24377,
24381,
24385,
24389,
24393,
24397,
24401,
24405,
24409,
24413,
24417,
24421,
24425
],
"core.event_count": 19,
"core.first_event_number": 24353,
"core.last_event_number": 24425,
"core.data_stream": "cosmics",
"core.file_content_status": "good",
"core.file_type": "detector",
"core.run_type": "vd-protodune",
"core.runs": [
39388
],
"core.runs_subruns": [
3938800001
],
"dune.daq_test": false,
"retention.status": "active",
"retention.class": "physics"
},
"parents": [
{
"did": "vd-protodune:np02vd_raw_run039388_0316_df-s05-d1_dw_0_20250916T195056.hdf5"
}
]
}Forming hist metadata
formed
{
"name": "np02vd_raw_run039388_0316_df-s05-d1_dw_0_20250916T195056_reco_stage1_20250916T215155_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": 1758059516.0,
"core.end_time": 1758059516.0,
"core.data_stream": "cosmics",
"core.file_content_status": "good",
"core.file_type": "detector",
"core.run_type": "vd-protodune",
"core.runs": [
39388
],
"core.runs_subruns": [
3938800001
],
"dune.daq_test": false,
"retention.status": "active",
"retention.class": "physics"
},
"parents": [
{
"did": "vd-protodune:np02vd_raw_run039388_0316_df-s05-d1_dw_0_20250916T195056.hdf5"
}
]
} 