Jobsub ID 257097.2@dunegpschedd02.fnal.gov
Jobscript log (last 10,000 characters)
:anode0sigproc0> EOS at call=97 anode=0
[01:14:43.351] D [ glue ] <FrameFanin:nfsp> EOS at call=97 with 8
[01:14:43.351] D [ glue ] frame sink sees EOS
[01:14:43.351] D [ pgraph ] <Pgrapher:> graph execution complete
[01:14:43.351] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 19.97 sec
[01:14:43.351] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 16.96 sec
[01:14:43.351] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 16.91 sec
[01:14:43.351] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 16.6 sec
[01:14:43.351] I [ timer ] Timer: WireCell::Aux::Resampler : 0.23 sec
[01:14:43.351] I [ timer ] Timer: WireCell::Aux::Resampler : 0.23 sec
[01:14:43.351] I [ timer ] Timer: WireCell::Aux::Resampler : 0.22 sec
[01:14:43.351] I [ timer ] Timer: WireCell::Aux::Resampler : 0.22 sec
[01:14:43.351] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.01 sec
[01:14:43.351] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[01:14:43.351] I [ timer ] Timer: WireCell::Gen::Retagger : 0.01 sec
[01:14:43.351] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[01:14:43.351] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[01:14:43.351] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[01:14:43.351] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[01:14:43.351] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[01:14:43.351] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[01:14:43.351] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[01:14:43.351] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[01:14:43.351] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[01:14:43.351] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[01:14:43.351] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[01:14:43.351] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0 sec
[01:14:43.351] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[01:14:43.351] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[01:14:43.351] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[01:14:43.351] I [ timer ] Timer: Total node execution : 71.3699986319989 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 27997 traces tagged "gauss"
FrameSaver: q=9.02261e+06 n=634569 tag=gauss
wclsFrameSaver: saving 34716 traces tagged "wiener"
FrameSaver: q=9.72223e+06 n=608393 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 47 XUs and 48 XVs -> 1 XUVs
C:0 T:1 761 XUs and 680 XVs -> 36 XUVs
C:0 T:2 509 XUs and 476 XVs -> 8 XUVs
C:0 T:3 770 XUs and 961 XVs -> 19 XUVs
C:0 T:4 1549 XUs and 1323 XVs -> 83 XUVs
C:0 T:5 19318 XUs and 22075 XVs -> 1193 XUVs
C:0 T:6 1112 XUs and 1011 XVs -> 45 XUVs
C:0 T:7 1326 XUs and 1379 XVs -> 41 XUVs
1426 XUVs total
962 collection wire objects
1426 potential space points
Neighbour search...
23968 tests to find 6294 neighbours
Iterating with no regularization...
Begin: 2.87296e+10
0 2.84043e+10
1 2.83797e+10
Now with regularization...
Begin: 2.81121e+10
0 2.81113e+10
BdtBeamParticleIdTool::SliceFeatures::GetLeadingCaloHits - empty calo hit list
04-Dec-2025 01:15:25 CET Closed output file "np02vd_raw_run041106_0696_df-s04-d0_dw_0_20251203T202005_reco_stage1_20251204T001525_keepup.root"
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 145.008 174.443 212.811 172.281 15.3983 49
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 5.6418e-05 7.55489e-05 0.000195521 6.9242e-05 2.54216e-05 49
produce:tpcrawdecoder:PDVDTPCReader 58.3094 71.2516 91.9718 70.179 7.20613 49
produce:triggerrawdecoder:PDVDTriggerReader4 0.357218 0.524283 1.40337 0.4931 0.15753 49
produce:pdvddaphne:DAPHNEReaderPDVD 0.000273161 0.000334115 0.000714171 0.000312845 7.85794e-05 49
produce:ophit:OpHitFinder 5.5195e-05 7.53155e-05 0.000501705 6.2649e-05 6.29336e-05 49
produce:opflash:OpFlashFinderVerticalDrift 3.9595e-05 5.73502e-05 0.000326502 4.5196e-05 4.3647e-05 49
produce:wclsdatavd:WireCellToolkit 50.7708 72.0827 88.2362 71.2968 6.99686 49
produce:gaushit:GausHitFinder 0.445506 0.666848 0.931838 0.662348 0.120922 49
produce:nhitsfilter:NumberOfHitsFilter 8.7236e-05 0.000169671 0.000342523 0.000155056 5.77437e-05 49
produce:reco3d:SpacePointSolver 3.70935 6.60159 10.3916 6.16001 1.79743 49
produce:hitpdune:DisambigFromSpacePoints 0.0280352 0.0748877 0.131523 0.0734865 0.0289358 49
produce:pandora:StandardPandora 6.00085 20.7902 55.1167 18.2918 10.1144 49
produce:pandoraTrack:LArPandoraTrackCreation 0.107658 0.307218 0.595102 0.280146 0.121223 49
produce:pandoraGnocalo:GnocchiCalorimetry 0.00783694 0.0152082 0.0243588 0.0144792 0.00360417 49
[art]:TriggerResults:TriggerResultInserter 1.5619e-05 2.73697e-05 9.6705e-05 2.0939e-05 1.55101e-05 49
end_path:out1:RootOutput 4.128e-06 5.80267e-06 2.2032e-05 4.9e-06 2.98736e-06 49
end_path:out1:RootOutput(write) 1.89039 2.09843 2.46298 2.08474 0.113204 49
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 4232.77 MB
Peak resident set size usage (VmHWM): 2202.12 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run041106_0696_df-s04-d0_dw_0_20251203T202005_reco_stage1_20251204T001525_keepup.root
\tHists: np02vd_raw_run041106_0696_df-s04-d0_dw_0_20251203T202005_reco_stage1_20251204T001525_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run041106_0696_df-s04-d0_dw_0_20251203T202005_reco_stage1_20251204T001525_keepup.root
Ran successfully
{
"name": "np02vd_raw_run041106_0696_df-s04-d0_dw_0_20251203T202005_reco_stage1_20251204T001525_keepup.root",
"namespace": "vd-protodune-det-reco",
"metadata": {
"core.file_format": "artroot",
"core.application.name": "reco",
"core.application.family": "dunesw",
"core.application.version": "v10_13_00d00",
"core.data_tier": "full-reconstructed",
"dune.config_file": "standard_reco_stage1_protodunevd_keepup.fcl",
"dune.campaign": "vd-protodune-reco-keepup-v0",
"core.start_time": 1764807326.0,
"core.end_time": 1764807326.0,
"core.events": [
33990,
33991,
33992,
33993,
33994,
33995,
33996,
33997,
33998,
33999,
34000,
34001,
34002,
34003,
34004,
34005,
34006,
34007,
34008,
34009,
34010,
34011,
34012,
34013,
34014,
34015,
34016,
34017,
34018,
34019,
34020,
34021,
34022,
34023,
34024,
34025,
34026,
34027,
34028,
34029,
34030,
34031,
34032,
34033,
34034,
34035,
34036,
34037,
34038
],
"core.event_count": 49,
"core.first_event_number": 33990,
"core.last_event_number": 34038,
"core.data_stream": "cosmics",
"core.file_content_status": "good",
"core.file_type": "detector",
"core.run_type": "vd-protodune",
"core.runs": [
41106
],
"core.runs_subruns": [
4110600001
],
"dune.daq_test": true,
"retention.status": "active",
"retention.class": "physics"
},
"parents": [
{
"did": "vd-protodune:np02vd_raw_run041106_0696_df-s04-d0_dw_0_20251203T202005.hdf5"
}
]
}Forming hist metadata
formed
{
"name": "np02vd_raw_run041106_0696_df-s04-d0_dw_0_20251203T202005_reco_stage1_20251204T001525_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_13_00d00",
"core.data_tier": "root-tuple-virtual",
"dune.config_file": "standard_reco_stage1_protodunevd_keepup.fcl",
"dune.campaign": "vd-protodune-reco-keepup-v0",
"core.start_time": 1764807326.0,
"core.end_time": 1764807326.0,
"core.data_stream": "cosmics",
"core.file_content_status": "good",
"core.file_type": "detector",
"core.run_type": "vd-protodune",
"core.runs": [
41106
],
"core.runs_subruns": [
4110600001
],
"dune.daq_test": true,
"retention.status": "active",
"retention.class": "physics"
},
"parents": [
{
"did": "vd-protodune:np02vd_raw_run041106_0696_df-s04-d0_dw_0_20251203T202005.hdf5"
}
]
}