Jobsub ID 48994.40@dunegpschedd01.fnal.gov
Jobscript log (last 10,000 characters)
1> EOS at call=79 anode=1
[22:12:52.479] D [ glue ] <ChannelSelector:chsel0> see EOS at call=39
[22:12:52.479] D [ aux ] <Resampler:resmp0> EOS at call=79
[22:12:52.479] D [sigproc ] <OmnibusSigProc:anode0sigproc0> EOS at call=79 anode=0
[22:12:52.479] D [ glue ] <FrameFanin:nfsp> EOS at call=79 with 8
[22:12:52.479] D [ glue ] frame sink sees EOS
[22:12:52.479] D [ pgraph ] <Pgrapher:> graph execution complete
[22:12:52.479] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 21.82 sec
[22:12:52.479] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.69 sec
[22:12:52.480] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 6.72 sec
[22:12:52.480] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 6.7 sec
[22:12:52.480] I [ timer ] Timer: WireCell::Aux::Resampler : 0.31 sec
[22:12:52.480] I [ timer ] Timer: WireCell::Aux::Resampler : 0.26 sec
[22:12:52.480] I [ timer ] Timer: WireCell::Aux::Resampler : 0.22 sec
[22:12:52.480] I [ timer ] Timer: WireCell::Aux::Resampler : 0.2 sec
[22:12:52.480] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.01 sec
[22:12:52.480] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[22:12:52.480] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[22:12:52.480] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[22:12:52.480] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0.01 sec
[22:12:52.480] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[22:12:52.480] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[22:12:52.480] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[22:12:52.480] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[22:12:52.480] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[22:12:52.480] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[22:12:52.480] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[22:12:52.480] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[22:12:52.480] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[22:12:52.480] I [ timer ] Timer: WireCell::Gen::Retagger : 0 sec
[22:12:52.480] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[22:12:52.480] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[22:12:52.480] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[22:12:52.480] I [ timer ] Timer: Total node execution : 44.9699988681823 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 24396 traces tagged "gauss"
FrameSaver: q=9.73084e+06 n=684742 tag=gauss
wclsFrameSaver: saving 31414 traces tagged "wiener"
FrameSaver: q=1.08897e+07 n=674796 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 557 XUs and 793 XVs -> 37 XUVs
C:0 T:1 283 XUs and 598 XVs -> 18 XUVs
C:0 T:2 897 XUs and 1131 XVs -> 47 XUVs
C:0 T:3 3025 XUs and 2916 XVs -> 243 XUVs
C:0 T:4 34 XUs and 32 XVs -> 0 XUVs
C:0 T:5 1004 XUs and 1035 XVs -> 54 XUVs
C:0 T:6 853 XUs and 1000 XVs -> 76 XUVs
C:0 T:7 75677 XUs and 93706 XVs -> 7785 XUVs
8260 XUVs total
2335 collection wire objects
8260 potential space points
Neighbour search...
530152 tests to find 120198 neighbours
Iterating with no regularization...
Begin: 8.54318e+10
0 8.16148e+10
1 8.12783e+10
2 8.12628e+10
Now with regularization...
Begin: 8.08184e+10
0 8.08155e+10
18-Sep-2025 22:17:13 BST Closed output file "np02vd_raw_run039499_0014_df-s05-d4_dw_0_20250918T181008_reco_stage1_20250918T211713_keepup.root"
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 83.073 134.813 338.726 114.175 56.1847 40
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 7.5332e-05 0.000146986 0.000573278 0.000134744 8.01307e-05 40
produce:tpcrawdecoder:PDVDTPCReader 13.248 30.6384 48.7551 29.4991 9.36985 40
produce:triggerrawdecoder:PDVDTriggerReader4 0.378555 0.436561 0.92606 0.392826 0.102169 40
produce:pdvddaphne:DAPHNEReaderPDVD 4.43926 7.6853 11.283 7.90569 1.96948 40
produce:ophit:OpHitFinder 0.0436998 0.0603096 0.0980095 0.0582247 0.0107357 40
produce:opflash:OpFlashFinderVerticalDrift 0.00698914 0.015741 0.0272384 0.014732 0.00477765 40
produce:wclsdatavd:WireCellToolkit 34.2226 44.6229 77.3164 40.2019 10.6734 40
produce:gaushit:GausHitFinder 0.392142 0.851268 1.54541 0.841189 0.248093 40
produce:nhitsfilter:NumberOfHitsFilter 0.000155672 0.000287521 0.000738879 0.000247595 0.00013312 40
produce:reco3d:SpacePointSolver 2.82034 7.36791 19.4919 6.86234 3.48568 40
produce:hitpdune:DisambigFromSpacePoints 0.0268939 0.118552 0.403509 0.108425 0.0847138 40
produce:pandora:StandardPandora 5.54798 39.177 243.991 22.9307 47.7234 40
produce:pandoraTrack:LArPandoraTrackCreation 0.0968788 0.44906 2.67631 0.33226 0.429783 40
produce:pandoraGnocalo:GnocchiCalorimetry 0.0114225 0.0213664 0.0422539 0.020407 0.00746585 40
[art]:TriggerResults:TriggerResultInserter 2.2161e-05 4.88473e-05 9.1732e-05 4.9548e-05 1.5727e-05 40
end_path:out1:RootOutput 4.538e-06 1.36397e-05 4.2971e-05 1.1186e-05 8.09802e-06 40
end_path:out1:RootOutput(write) 2.49976 3.33453 3.94851 3.32548 0.3322 40
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 4725.97 MB
Peak resident set size usage (VmHWM): 2801.03 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run039499_0014_df-s05-d4_dw_0_20250918T181008_reco_stage1_20250918T211713_keepup.root
\tHists: np02vd_raw_run039499_0014_df-s05-d4_dw_0_20250918T181008_reco_stage1_20250918T211713_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run039499_0014_df-s05-d4_dw_0_20250918T181008_reco_stage1_20250918T211713_keepup.root
Ran successfully
{
"name": "np02vd_raw_run039499_0014_df-s05-d4_dw_0_20250918T181008_reco_stage1_20250918T211713_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": 1758230234.0,
"core.end_time": 1758230234.0,
"core.events": [
3406,
3412,
3418,
3424,
3430,
3436,
3442,
3448,
3454,
3460,
3466,
3472,
3478,
3484,
3490,
3496,
3502,
3508,
3514,
3520,
3526,
3532,
3538,
3544,
3550,
3556,
3562,
3568,
3574,
3580,
3586,
3592,
3598,
3604,
3610,
3616,
3622,
3628,
3634,
3640
],
"core.event_count": 40,
"core.first_event_number": 3406,
"core.last_event_number": 3640,
"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_0014_df-s05-d4_dw_0_20250918T181008.hdf5"
}
]
}Forming hist metadata
formed
{
"name": "np02vd_raw_run039499_0014_df-s05-d4_dw_0_20250918T181008_reco_stage1_20250918T211713_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": 1758230234.0,
"core.end_time": 1758230234.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_0014_df-s05-d4_dw_0_20250918T181008.hdf5"
}
]
} 