Jobsub ID 37469.56@dunegpschedd02.fnal.gov
Jobscript log (last 10,000 characters)
7
[15:50:26.071] D [ aux ] <Resampler:resmp0> EOS at call=35
[15:50:26.071] D [sigproc ] <OmnibusSigProc:anode0sigproc0> EOS at call=35 anode=0
[15:50:26.071] D [ glue ] <FrameFanin:nfsp> EOS at call=35 with 8
[15:50:26.071] D [ glue ] frame sink sees EOS
[15:50:26.071] D [ pgraph ] <Pgrapher:> graph execution complete
[15:50:26.071] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 9.9 sec
[15:50:26.071] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 9.15 sec
[15:50:26.071] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.55 sec
[15:50:26.071] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.3 sec
[15:50:26.071] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.88 sec
[15:50:26.071] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.44 sec
[15:50:26.071] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.38 sec
[15:50:26.071] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 6.66 sec
[15:50:26.071] I [ timer ] Timer: WireCell::Aux::Resampler : 0.8 sec
[15:50:26.071] I [ timer ] Timer: WireCell::Aux::Resampler : 0.79 sec
[15:50:26.071] I [ timer ] Timer: WireCell::Aux::Resampler : 0.79 sec
[15:50:26.071] I [ timer ] Timer: WireCell::Aux::Resampler : 0.78 sec
[15:50:26.071] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.01 sec
[15:50:26.071] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[15:50:26.071] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[15:50:26.071] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[15:50:26.071] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[15:50:26.071] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0.01 sec
[15:50:26.071] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[15:50:26.071] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[15:50:26.071] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[15:50:26.071] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[15:50:26.071] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[15:50:26.071] I [ timer ] Timer: WireCell::Gen::Retagger : 0 sec
[15:50:26.071] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[15:50:26.071] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[15:50:26.071] I [ timer ] Timer: Total node execution : 68.47999977692962 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 46432 traces tagged "gauss"
FrameSaver: q=1.0284e+07 n=1209945 tag=gauss
wclsFrameSaver: saving 56849 traces tagged "wiener"
FrameSaver: q=1.07476e+07 n=1169444 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 368 XUs and 540 XVs -> 19 XUVs
C:0 T:1 602 XUs and 817 XVs -> 54 XUVs
C:0 T:2 10 XUs and 8 XVs -> 0 XUVs
C:0 T:3 256 XUs and 213 XVs -> 22 XUVs
C:0 T:4 343 XUs and 603 XVs -> 21 XUVs
C:0 T:5 406 XUs and 396 XVs -> 31 XUVs
C:0 T:6 299 XUs and 617 XVs -> 23 XUVs
C:0 T:7 1092 XUs and 1258 XVs -> 46 XUVs
C:0 T:8 1840 XUs and 2523 XVs -> 93 XUVs
C:0 T:9 379 XUs and 297 XVs -> 27 XUVs
C:0 T:10 1371 XUs and 2003 XVs -> 93 XUVs
C:0 T:11 2997 XUs and 2332 XVs -> 138 XUVs
C:0 T:12 13730 XUs and 25324 XVs -> 1073 XUVs
C:0 T:13 1089 XUs and 2060 XVs -> 81 XUVs
C:0 T:14 1957 XUs and 805 XVs -> 90 XUVs
C:0 T:15 7451 XUs and 9499 XVs -> 1350 XUVs
3161 XUVs total
1493 collection wire objects
3161 potential space points
Neighbour search...
264721 tests to find 108282 neighbours
Iterating with no regularization...
Begin: 2.17585e+09
0 1.93722e+09
1 1.9185e+09
2 1.91823e+09
Now with regularization...
Begin: 1.90614e+09
0 1.90608e+09
10-Sep-2025 15:51:53 CEST Closed output file "np02vd_raw_run039255_0248_df-s05-d2_dw_0_20250830T132503_reco_stage1_20250910T135153_keepup.root"
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 140.302 214.172 277.437 214.502 41.8684 18
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 6.4802e-05 8.11118e-05 0.000182473 7.3618e-05 2.55719e-05 18
produce:tpcrawdecoder:PDVDTPCReader 15.8713 16.4331 17.1877 16.3792 0.312588 18
produce:triggerrawdecoder:PDVDTriggerReader4 0.0341681 0.034885 0.0438018 0.034335 0.00218056 18
produce:pdvddaphne:DAPHNEReaderPDVD 4.20352 4.6286 5.02075 4.64777 0.26855 18
produce:ophit:OpHitFinder 0.0322249 0.0411105 0.0484929 0.0414494 0.00417185 18
produce:opflash:OpFlashFinderVerticalDrift 0.0076328 0.0130544 0.0165598 0.0132015 0.00251603 18
produce:wclsdatavd:WireCellToolkit 58.4571 74.4234 87.9591 73.184 7.78436 18
produce:gaushit:GausHitFinder 1.08377 1.51769 1.95391 1.55071 0.256807 18
produce:nhitsfilter:NumberOfHitsFilter 0.000299883 0.000458966 0.00102991 0.000427107 0.000151823 18
produce:reco3d:SpacePointSolver 11.5196 20.3779 30.6149 20.7668 5.1482 18
produce:hitpdune:DisambigFromSpacePoints 0.16694 0.324942 0.490359 0.348537 0.0923792 18
produce:pandora:StandardPandora 39.0275 89.7952 141.484 89.0129 32.0214 18
produce:pandoraTrack:LArPandoraTrackCreation 0.814058 1.61941 3.89884 1.38729 0.72159 18
produce:pandoraGnocalo:GnocchiCalorimetry 0.0238483 0.0386831 0.0766946 0.0372602 0.0116913 18
[art]:TriggerResults:TriggerResultInserter 1.3826e-05 2.01519e-05 5.4122e-05 1.7809e-05 8.50039e-06 18
end_path:out1:RootOutput 3.166e-06 4.79239e-06 2.3004e-05 3.6365e-06 4.43776e-06 18
end_path:out1:RootOutput(write) 4.54318 4.87758 5.18151 4.91803 0.179699 18
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 5128.56 MB
Peak resident set size usage (VmHWM): 3249.98 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run039255_0248_df-s05-d2_dw_0_20250830T132503_reco_stage1_20250910T135153_keepup.root
\tHists: np02vd_raw_run039255_0248_df-s05-d2_dw_0_20250830T132503_reco_stage1_20250910T135153_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run039255_0248_df-s05-d2_dw_0_20250830T132503_reco_stage1_20250910T135153_keepup.root
Ran successfully
{
"name": "np02vd_raw_run039255_0248_df-s05-d2_dw_0_20250830T132503_reco_stage1_20250910T135153_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": 1757512313.0,
"core.end_time": 1757512313.0,
"core.events": [
89296,
89316,
89336,
89356,
89376,
89396,
89416,
89436,
89456,
89476,
89496,
89516,
89536,
89556,
89576,
89596,
89616,
89636
],
"core.event_count": 18,
"core.first_event_number": 89296,
"core.last_event_number": 89636,
"core.data_stream": "physics",
"core.file_content_status": "good",
"core.file_type": "detector",
"core.run_type": "vd-protodune",
"core.runs": [
39255
],
"core.runs_subruns": [
3925500001
],
"dune.daq_test": false,
"retention.status": "active",
"retention.class": "physics"
},
"parents": [
{
"did": "vd-protodune:np02vd_raw_run039255_0248_df-s05-d2_dw_0_20250830T132503.hdf5"
}
]
}Forming hist metadata
formed
{
"name": "np02vd_raw_run039255_0248_df-s05-d2_dw_0_20250830T132503_reco_stage1_20250910T135153_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": 1757512313.0,
"core.end_time": 1757512313.0,
"core.data_stream": "physics",
"core.file_content_status": "good",
"core.file_type": "detector",
"core.run_type": "vd-protodune",
"core.runs": [
39255
],
"core.runs_subruns": [
3925500001
],
"dune.daq_test": false,
"retention.status": "active",
"retention.class": "physics"
},
"parents": [
{
"did": "vd-protodune:np02vd_raw_run039255_0248_df-s05-d2_dw_0_20250830T132503.hdf5"
}
]
} 