Jobsub ID 49050.146@dunegpschedd01.fnal.gov
Jobscript log (last 10,000 characters)
e ] <ChannelSelector:chsel0> see EOS at call=40
[01:08:09.649] D [ aux ] <Resampler:resmp0> EOS at call=81
[01:08:09.649] D [sigproc ] <OmnibusSigProc:anode0sigproc0> EOS at call=81 anode=0
[01:08:09.649] D [ glue ] <FrameFanin:nfsp> EOS at call=81 with 8
[01:08:09.649] D [ glue ] frame sink sees EOS
[01:08:09.649] D [ pgraph ] <Pgrapher:> graph execution complete
[01:08:09.649] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 14.71 sec
[01:08:09.649] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 13.51 sec
[01:08:09.649] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 13.47 sec
[01:08:09.649] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 12.28 sec
[01:08:09.649] I [ timer ] Timer: WireCell::Aux::Resampler : 0.54 sec
[01:08:09.649] I [ timer ] Timer: WireCell::Aux::Resampler : 0.48 sec
[01:08:09.649] I [ timer ] Timer: WireCell::Aux::Resampler : 0.48 sec
[01:08:09.649] I [ timer ] Timer: WireCell::Aux::Resampler : 0.43 sec
[01:08:09.649] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.03 sec
[01:08:09.649] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[01:08:09.649] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[01:08:09.649] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[01:08:09.649] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[01:08:09.649] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[01:08:09.649] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[01:08:09.649] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[01:08:09.649] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[01:08:09.649] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[01:08:09.649] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[01:08:09.649] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[01:08:09.649] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[01:08:09.649] I [ timer ] Timer: WireCell::Gen::Retagger : 0 sec
[01:08:09.649] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0 sec
[01:08:09.649] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[01:08:09.649] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[01:08:09.649] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[01:08:09.649] I [ timer ] Timer: Total node execution : 55.95000027306378 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 18980 traces tagged "gauss"
FrameSaver: q=3.15496e+06 n=423902 tag=gauss
wclsFrameSaver: saving 24772 traces tagged "wiener"
FrameSaver: q=3.37229e+06 n=406263 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 3106 XUs and 3648 XVs -> 386 XUVs
C:0 T:1 10195 XUs and 10621 XVs -> 896 XUVs
C:0 T:2 1011 XUs and 1242 XVs -> 42 XUVs
C:0 T:3 654 XUs and 1285 XVs -> 60 XUVs
C:0 T:4 992 XUs and 1205 XVs -> 108 XUVs
C:0 T:5 1059 XUs and 768 XVs -> 62 XUVs
C:0 T:6 264 XUs and 317 XVs -> 15 XUVs
C:0 T:7 18 XUs and 19 XVs -> 0 XUVs
1569 XUVs total
684 collection wire objects
1569 potential space points
Neighbour search...
48687 tests to find 18856 neighbours
Iterating with no regularization...
Begin: 8.88845e+08
0 7.99621e+08
1 7.93575e+08
2 7.932e+08
Now with regularization...
Begin: 7.7436e+08
0 7.74275e+08
19-Sep-2025 01:08:41 BST Closed output file "np02vd_raw_run039499_0076_df-s04-d3_dw_0_20250918T201610_reco_stage1_20250919T000841_keepup.root"
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 106.067 177.257 437.377 150.573 71.9913 41
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 9.1035e-05 0.000142868 0.000442358 0.000112582 6.20276e-05 41
produce:tpcrawdecoder:PDVDTPCReader 11.9669 37.0504 61.3448 36.1699 9.05678 41
produce:triggerrawdecoder:PDVDTriggerReader4 0.37313 0.415985 0.54662 0.397789 0.0482444 41
produce:pdvddaphne:DAPHNEReaderPDVD 8.46325 11.354 16.5463 11.1893 1.78542 41
produce:ophit:OpHitFinder 0.0428289 0.0766049 0.116233 0.0779255 0.0151083 41
produce:opflash:OpFlashFinderVerticalDrift 0.00681396 0.0202894 0.0404337 0.0195677 0.00626185 41
produce:wclsdatavd:WireCellToolkit 53.5059 70.8307 141.99 59.2797 21.5008 41
produce:gaushit:GausHitFinder 0.570441 1.10174 2.47485 1.00852 0.361092 41
produce:nhitsfilter:NumberOfHitsFilter 0.000176979 0.000285609 0.000549591 0.00027408 7.47006e-05 41
produce:reco3d:SpacePointSolver 3.12256 8.60524 22.932 8.07344 3.96588 41
produce:hitpdune:DisambigFromSpacePoints 0.031784 0.165752 0.607115 0.136042 0.11502 41
produce:pandora:StandardPandora 5.67409 42.5018 262.249 21.7455 53.84 41
produce:pandoraTrack:LArPandoraTrackCreation 0.234665 0.65295 1.86265 0.50899 0.34584 41
produce:pandoraGnocalo:GnocchiCalorimetry 0.0155377 0.0285922 0.0570792 0.0268952 0.00968296 41
[art]:TriggerResults:TriggerResultInserter 2.5872e-05 4.15032e-05 7.5344e-05 4.1297e-05 9.13648e-06 41
end_path:out1:RootOutput 4.018e-06 9.2121e-06 2.8527e-05 8.904e-06 3.64955e-06 41
end_path:out1:RootOutput(write) 3.39567 4.41911 5.78589 4.33867 0.513712 41
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 5815.07 MB
Peak resident set size usage (VmHWM): 3917.97 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run039499_0076_df-s04-d3_dw_0_20250918T201610_reco_stage1_20250919T000841_keepup.root
\tHists: np02vd_raw_run039499_0076_df-s04-d3_dw_0_20250918T201610_reco_stage1_20250919T000843_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run039499_0076_df-s04-d3_dw_0_20250918T201610_reco_stage1_20250919T000841_keepup.root
Ran successfully
{
"name": "np02vd_raw_run039499_0076_df-s04-d3_dw_0_20250918T201610_reco_stage1_20250919T000841_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": 1758240525.0,
"core.end_time": 1758240525.0,
"core.events": [
18548,
18554,
18560,
18566,
18572,
18578,
18584,
18590,
18596,
18602,
18608,
18614,
18620,
18626,
18632,
18638,
18644,
18650,
18656,
18662,
18668,
18674,
18680,
18686,
18692,
18698,
18704,
18710,
18716,
18722,
18728,
18734,
18740,
18746,
18752,
18758,
18764,
18770,
18776,
18782,
18788
],
"core.event_count": 41,
"core.first_event_number": 18548,
"core.last_event_number": 18788,
"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_0076_df-s04-d3_dw_0_20250918T201610.hdf5"
}
]
}Forming hist metadata
formed
{
"name": "np02vd_raw_run039499_0076_df-s04-d3_dw_0_20250918T201610_reco_stage1_20250919T000843_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": 1758240525.0,
"core.end_time": 1758240525.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_0076_df-s04-d3_dw_0_20250918T201610.hdf5"
}
]
} 