Jobsub ID 49050.125@dunegpschedd01.fnal.gov
Jobscript log (last 10,000 characters)
p0> EOS at call=81
[02:19:54.455] D [sigproc ] <OmnibusSigProc:anode0sigproc0> EOS at call=81 anode=0
[02:19:54.455] D [ glue ] <FrameFanin:nfsp> EOS at call=81 with 8
[02:19:54.455] D [ glue ] frame sink sees EOS
[02:19:54.455] D [ pgraph ] <Pgrapher:> graph execution complete
[02:19:54.455] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 13.28 sec
[02:19:54.455] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 12.19 sec
[02:19:54.455] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 12.16 sec
[02:19:54.455] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 11.13 sec
[02:19:54.455] I [ timer ] Timer: WireCell::Aux::Resampler : 0.41 sec
[02:19:54.455] I [ timer ] Timer: WireCell::Aux::Resampler : 0.39 sec
[02:19:54.455] I [ timer ] Timer: WireCell::Aux::Resampler : 0.39 sec
[02:19:54.455] I [ timer ] Timer: WireCell::Aux::Resampler : 0.26 sec
[02:19:54.455] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.01 sec
[02:19:54.455] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[02:19:54.455] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[02:19:54.455] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[02:19:54.455] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[02:19:54.455] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[02:19:54.455] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[02:19:54.455] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[02:19:54.455] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[02:19:54.455] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[02:19:54.455] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[02:19:54.455] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[02:19:54.455] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[02:19:54.455] I [ timer ] Timer: WireCell::Gen::Retagger : 0 sec
[02:19:54.455] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0 sec
[02:19:54.455] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[02:19:54.455] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[02:19:54.455] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[02:19:54.455] I [ timer ] Timer: Total node execution : 50.2499992325902 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 30875 traces tagged "gauss"
FrameSaver: q=6.96048e+06 n=759161 tag=gauss
wclsFrameSaver: saving 40360 traces tagged "wiener"
FrameSaver: q=7.44463e+06 n=725866 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 791 XUs and 940 XVs -> 24 XUVs
C:0 T:1 19690 XUs and 29277 XVs -> 1575 XUVs
C:0 T:2 2182 XUs and 2037 XVs -> 76 XUVs
C:0 T:3 9184 XUs and 10433 XVs -> 645 XUVs
C:0 T:4 368 XUs and 454 XVs -> 26 XUVs
C:0 T:5 2532 XUs and 3928 XVs -> 189 XUVs
C:0 T:6 1054 XUs and 976 XVs -> 33 XUVs
C:0 T:7 3876 XUs and 4593 XVs -> 271 XUVs
2839 XUVs total
1806 collection wire objects
2839 potential space points
Neighbour search...
79001 tests to find 18712 neighbours
Iterating with no regularization...
Begin: 2.25882e+10
0 2.19432e+10
1 2.19146e+10
2 2.19141e+10
Now with regularization...
Begin: 2.18306e+10
0 2.18304e+10
BdtBeamParticleIdTool::SliceFeatures::GetLeadingCaloHits - empty calo hit list
19-Sep-2025 02:21:31 BST Closed output file "np02vd_raw_run039499_0071_df-s04-d1_dw_0_20250918T200549_reco_stage1_20250919T012131_keepup.root"
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 69.9253 296.546 3215.61 122.508 659.479 41
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 9.3536e-05 0.000118942 0.000372473 0.000105098 5.27937e-05 41
produce:tpcrawdecoder:PDVDTPCReader 7.83006 8.64984 11.9751 8.34962 0.772873 41
produce:triggerrawdecoder:PDVDTriggerReader4 0.377022 0.390623 0.44993 0.384775 0.0148743 41
produce:pdvddaphne:DAPHNEReaderPDVD 4.09241 4.75381 6.09473 4.60376 0.420422 41
produce:ophit:OpHitFinder 0.0501153 0.0705229 0.0960556 0.0694792 0.00814951 41
produce:opflash:OpFlashFinderVerticalDrift 0.0117962 0.0192873 0.0464376 0.0183157 0.0063566 41
produce:wclsdatavd:WireCellToolkit 41.4584 65.0891 136.684 55.4345 23.1414 41
produce:gaushit:GausHitFinder 0.571013 1.26515 3.00203 1.17749 0.493885 41
produce:nhitsfilter:NumberOfHitsFilter 0.000115248 0.000317901 0.000761547 0.000267204 0.000132788 41
produce:reco3d:SpacePointSolver 3.15985 12.4561 47.328 10.2083 8.3549 41
produce:hitpdune:DisambigFromSpacePoints 0.0372471 0.224316 1.0686 0.139622 0.220907 41
produce:pandora:StandardPandora 8.3946 198.358 3005.42 35.5429 637.888 41
produce:pandoraTrack:LArPandoraTrackCreation 0.162329 0.920725 3.71395 0.583773 0.854151 41
produce:pandoraGnocalo:GnocchiCalorimetry 0.0143803 0.0356541 0.10617 0.0318829 0.0151573 41
[art]:TriggerResults:TriggerResultInserter 2.2081e-05 3.9299e-05 0.000140014 3.168e-05 1.91055e-05 41
end_path:out1:RootOutput 4.489e-06 6.52512e-06 3.5808e-05 5.701e-06 4.69379e-06 41
end_path:out1:RootOutput(write) 2.84225 4.28317 5.38704 4.28133 0.538509 41
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 7026.55 MB
Peak resident set size usage (VmHWM): 5100.25 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run039499_0071_df-s04-d1_dw_0_20250918T200549_reco_stage1_20250919T012131_keepup.root
\tHists: np02vd_raw_run039499_0071_df-s04-d1_dw_0_20250918T200549_reco_stage1_20250919T012132_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run039499_0071_df-s04-d1_dw_0_20250918T200549_reco_stage1_20250919T012131_keepup.root
Ran successfully
{
"name": "np02vd_raw_run039499_0071_df-s04-d1_dw_0_20250918T200549_reco_stage1_20250919T012131_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": 1758244893.0,
"core.end_time": 1758244893.0,
"core.events": [
17268,
17274,
17280,
17286,
17292,
17298,
17304,
17310,
17316,
17322,
17328,
17334,
17340,
17346,
17352,
17358,
17364,
17370,
17376,
17382,
17388,
17394,
17400,
17406,
17412,
17418,
17424,
17430,
17436,
17442,
17448,
17454,
17460,
17466,
17472,
17478,
17484,
17490,
17496,
17502,
17508
],
"core.event_count": 41,
"core.first_event_number": 17268,
"core.last_event_number": 17508,
"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_0071_df-s04-d1_dw_0_20250918T200549.hdf5"
}
]
}Forming hist metadata
formed
{
"name": "np02vd_raw_run039499_0071_df-s04-d1_dw_0_20250918T200549_reco_stage1_20250919T012132_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": 1758244893.0,
"core.end_time": 1758244893.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_0071_df-s04-d1_dw_0_20250918T200549.hdf5"
}
]
}