Jobsub ID 42563.44@dunegpschedd02.fnal.gov
Jobscript log (last 10,000 characters)
roc1> EOS at call=81 anode=1
[23:54:37.885] D [ glue ] <ChannelSelector:chsel0> see EOS at call=40
[23:54:37.885] D [ aux ] <Resampler:resmp0> EOS at call=81
[23:54:37.885] D [sigproc ] <OmnibusSigProc:anode0sigproc0> EOS at call=81 anode=0
[23:54:37.885] D [ glue ] <FrameFanin:nfsp> EOS at call=81 with 8
[23:54:37.885] D [ glue ] frame sink sees EOS
[23:54:37.885] D [ pgraph ] <Pgrapher:> graph execution complete
[23:54:37.886] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 13.11 sec
[23:54:37.886] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 10.34 sec
[23:54:37.886] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 10.3 sec
[23:54:37.886] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 9.48 sec
[23:54:37.886] I [ timer ] Timer: WireCell::Aux::Resampler : 0.43 sec
[23:54:37.886] I [ timer ] Timer: WireCell::Aux::Resampler : 0.43 sec
[23:54:37.886] I [ timer ] Timer: WireCell::Aux::Resampler : 0.41 sec
[23:54:37.886] I [ timer ] Timer: WireCell::Aux::Resampler : 0.41 sec
[23:54:37.886] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.01 sec
[23:54:37.886] I [ timer ] Timer: WireCell::Gen::Retagger : 0.01 sec
[23:54:37.886] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[23:54:37.886] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[23:54:37.886] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[23:54:37.886] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[23:54:37.886] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[23:54:37.886] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[23:54:37.886] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[23:54:37.886] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[23:54:37.886] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[23:54:37.886] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[23:54:37.886] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[23:54:37.886] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[23:54:37.886] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0 sec
[23:54:37.886] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[23:54:37.886] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[23:54:37.886] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[23:54:37.886] I [ timer ] Timer: Total node execution : 44.92999954894185 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 16592 traces tagged "gauss"
FrameSaver: q=2.97411e+06 n=384741 tag=gauss
wclsFrameSaver: saving 21547 traces tagged "wiener"
FrameSaver: q=3.25405e+06 n=371440 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 550 XUs and 719 XVs -> 58 XUVs
C:0 T:1 630 XUs and 1014 XVs -> 82 XUVs
C:0 T:2 199 XUs and 240 XVs -> 3 XUVs
C:0 T:3 27 XUs and 62 XVs -> 2 XUVs
C:0 T:4 6501 XUs and 7261 XVs -> 629 XUVs
C:0 T:5 5151 XUs and 6247 XVs -> 464 XUVs
C:0 T:6 535 XUs and 672 XVs -> 24 XUVs
C:0 T:7 178 XUs and 184 XVs -> 3 XUVs
1265 XUVs total
580 collection wire objects
1265 potential space points
Neighbour search...
39189 tests to find 11170 neighbours
Iterating with no regularization...
Begin: 1.32648e+09
0 1.24593e+09
1 1.24356e+09
2 1.24336e+09
Now with regularization...
Begin: 1.20364e+09
0 1.20352e+09
18-Sep-2025 23:55:04 CEST Closed output file "np02vd_raw_run039499_0026_df-s04-d1_dw_0_20250918T183340_reco_stage1_20250918T215504_keepup.root"
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 86.6682 166.496 665.807 150.44 105.909 41
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 0.000117563 0.000174468 0.000466229 0.000143353 6.44829e-05 41
produce:tpcrawdecoder:PDVDTPCReader 10.2668 13.672 16.2395 13.3999 1.3885 41
produce:triggerrawdecoder:PDVDTriggerReader4 0.506462 0.515158 0.541186 0.509901 0.00990332 41
produce:pdvddaphne:DAPHNEReaderPDVD 4.87445 5.32154 5.81715 5.29009 0.238363 41
produce:ophit:OpHitFinder 0.0629464 0.0769185 0.111989 0.0755319 0.00928867 41
produce:opflash:OpFlashFinderVerticalDrift 0.00973695 0.0210895 0.0277587 0.0209389 0.003629 41
produce:wclsdatavd:WireCellToolkit 46.6334 68.2015 123.379 56.7052 21.7478 41
produce:gaushit:GausHitFinder 0.572188 1.29992 2.58279 1.24743 0.38502 41
produce:nhitsfilter:NumberOfHitsFilter 0.000111473 0.000284672 0.000729294 0.000278206 0.000106969 41
produce:reco3d:SpacePointSolver 3.65538 10.9435 28.5647 9.95198 4.71508 41
produce:hitpdune:DisambigFromSpacePoints 0.0357784 0.172919 0.597072 0.143968 0.115692 41
produce:pandora:StandardPandora 6.69254 60.7837 486.708 40.9561 86.5724 41
produce:pandoraTrack:LArPandoraTrackCreation 0.181902 0.713709 3.89081 0.616498 0.61077 41
produce:pandoraGnocalo:GnocchiCalorimetry 0.0181663 0.0317437 0.0577202 0.0308746 0.00838108 41
[art]:TriggerResults:TriggerResultInserter 2.5291e-05 5.66596e-05 0.000264905 3.8351e-05 4.5669e-05 41
end_path:out1:RootOutput 4.74e-06 1.42578e-05 0.000100122 1.2011e-05 1.44921e-05 41
end_path:out1:RootOutput(write) 4.12271 4.71243 6.8413 4.61867 0.472576 41
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 5752.89 MB
Peak resident set size usage (VmHWM): 3734.36 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run039499_0026_df-s04-d1_dw_0_20250918T183340_reco_stage1_20250918T215504_keepup.root
\tHists: np02vd_raw_run039499_0026_df-s04-d1_dw_0_20250918T183340_reco_stage1_20250918T215505_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run039499_0026_df-s04-d1_dw_0_20250918T183340_reco_stage1_20250918T215504_keepup.root
Ran successfully
{
"name": "np02vd_raw_run039499_0026_df-s04-d1_dw_0_20250918T183340_reco_stage1_20250918T215504_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": 1758232506.0,
"core.end_time": 1758232506.0,
"core.events": [
6306,
6312,
6318,
6324,
6330,
6336,
6342,
6348,
6354,
6360,
6366,
6372,
6378,
6384,
6390,
6396,
6402,
6408,
6414,
6420,
6426,
6432,
6438,
6444,
6450,
6456,
6462,
6468,
6474,
6480,
6486,
6492,
6498,
6504,
6510,
6516,
6522,
6528,
6534,
6540,
6546
],
"core.event_count": 41,
"core.first_event_number": 6306,
"core.last_event_number": 6546,
"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_0026_df-s04-d1_dw_0_20250918T183340.hdf5"
}
]
}Forming hist metadata
formed
{
"name": "np02vd_raw_run039499_0026_df-s04-d1_dw_0_20250918T183340_reco_stage1_20250918T215505_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": 1758232506.0,
"core.end_time": 1758232506.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_0026_df-s04-d1_dw_0_20250918T183340.hdf5"
}
]
}