Jobsub ID 42563.101@dunegpschedd02.fnal.gov
Jobscript log (last 10,000 characters)
] D [ glue ] <ChannelSelector:chsel0> see EOS at call=41
[22:54:21.616] D [ aux ] <Resampler:resmp0> EOS at call=83
[22:54:21.616] D [sigproc ] <OmnibusSigProc:anode0sigproc0> EOS at call=83 anode=0
[22:54:21.616] D [ glue ] <FrameFanin:nfsp> EOS at call=83 with 8
[22:54:21.616] D [ glue ] frame sink sees EOS
[22:54:21.616] D [ pgraph ] <Pgrapher:> graph execution complete
[22:54:21.616] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 9.1 sec
[22:54:21.616] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.24 sec
[22:54:21.616] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.18 sec
[22:54:21.616] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.74 sec
[22:54:21.616] I [ timer ] Timer: WireCell::Aux::Resampler : 0.33 sec
[22:54:21.616] I [ timer ] Timer: WireCell::Aux::Resampler : 0.32 sec
[22:54:21.616] I [ timer ] Timer: WireCell::Aux::Resampler : 0.32 sec
[22:54:21.616] I [ timer ] Timer: WireCell::Aux::Resampler : 0.32 sec
[22:54:21.616] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[22:54:21.616] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[22:54:21.616] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[22:54:21.616] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[22:54:21.616] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[22:54:21.616] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[22:54:21.616] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0 sec
[22:54:21.616] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[22:54:21.616] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[22:54:21.616] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[22:54:21.616] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[22:54:21.616] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[22:54:21.616] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[22:54:21.616] I [ timer ] Timer: WireCell::Gen::Retagger : 0 sec
[22:54:21.616] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0 sec
[22:54:21.616] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[22:54:21.616] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[22:54:21.616] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[22:54:21.616] I [ timer ] Timer: Total node execution : 34.57000022009015 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 18059 traces tagged "gauss"
FrameSaver: q=3.50586e+06 n=442604 tag=gauss
wclsFrameSaver: saving 21843 traces tagged "wiener"
FrameSaver: q=3.70928e+06 n=432997 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 1278 XUs and 1520 XVs -> 70 XUVs
C:0 T:1 236 XUs and 355 XVs -> 18 XUVs
C:0 T:2 967 XUs and 1213 XVs -> 24 XUVs
C:0 T:3 1556 XUs and 1665 XVs -> 40 XUVs
C:0 T:4 287 XUs and 290 XVs -> 12 XUVs
C:0 T:5 1911 XUs and 1550 XVs -> 114 XUVs
C:0 T:6 518 XUs and 334 XVs -> 20 XUVs
C:0 T:7 1639 XUs and 1832 XVs -> 128 XUVs
426 XUVs total
351 collection wire objects
426 potential space points
Neighbour search...
5358 tests to find 1706 neighbours
Iterating with no regularization...
Begin: 1.98465e+10
0 1.96253e+10
1 1.96252e+10
Now with regularization...
Begin: 1.95555e+10
0 1.95555e+10
18-Sep-2025 22:54:48 BST Closed output file "np02vd_raw_run039499_0046_df-s05-d3_dw_0_20250918T191539_reco_stage1_20250918T215448_keepup.root"
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 61.0597 96.7912 277.933 79.5909 46.9394 42
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 7.5672e-05 0.000127088 0.000380004 0.000119159 5.0852e-05 42
produce:tpcrawdecoder:PDVDTPCReader 10.1059 11.6429 13.3531 11.5281 0.705134 42
produce:triggerrawdecoder:PDVDTriggerReader4 0.3784 0.39043 0.408202 0.390401 0.00657099 42
produce:pdvddaphne:DAPHNEReaderPDVD 3.61507 4.22976 4.87716 4.22681 0.300305 42
produce:ophit:OpHitFinder 0.0385633 0.0568538 0.0642119 0.0576854 0.00526698 42
produce:opflash:OpFlashFinderVerticalDrift 0.00719953 0.013776 0.0236039 0.0136523 0.00360693 42
produce:wclsdatavd:WireCellToolkit 29.0122 38.8315 71.8832 34.3511 10.7458 42
produce:gaushit:GausHitFinder 0.39832 0.74998 1.51677 0.730762 0.239637 42
produce:nhitsfilter:NumberOfHitsFilter 0.000120115 0.00021346 0.000528604 0.000184948 8.72867e-05 42
produce:reco3d:SpacePointSolver 2.83728 6.69963 17.3656 5.45359 3.52348 42
produce:hitpdune:DisambigFromSpacePoints 0.0295509 0.104483 0.405526 0.0731529 0.0813314 42
produce:pandora:StandardPandora 6.51538 30.6265 197.533 16.4791 37.2272 42
produce:pandoraTrack:LArPandoraTrackCreation 0.0815319 0.386166 1.3799 0.313966 0.275372 42
produce:pandoraGnocalo:GnocchiCalorimetry 0.00806403 0.0190748 0.0313263 0.0185223 0.00642861 42
[art]:TriggerResults:TriggerResultInserter 2.0389e-05 3.54776e-05 8.3286e-05 3.6098e-05 1.0186e-05 42
end_path:out1:RootOutput 3.527e-06 8.417e-06 2.8123e-05 6.577e-06 4.6206e-06 42
end_path:out1:RootOutput(write) 2.18048 3.01422 3.74794 3.09561 0.395441 42
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 4810.82 MB
Peak resident set size usage (VmHWM): 2856.51 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run039499_0046_df-s05-d3_dw_0_20250918T191539_reco_stage1_20250918T215448_keepup.root
\tHists: np02vd_raw_run039499_0046_df-s05-d3_dw_0_20250918T191539_reco_stage1_20250918T215448_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run039499_0046_df-s05-d3_dw_0_20250918T191539_reco_stage1_20250918T215448_keepup.root
Ran successfully
{
"name": "np02vd_raw_run039499_0046_df-s05-d3_dw_0_20250918T191539_reco_stage1_20250918T215448_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": 1758232489.0,
"core.end_time": 1758232489.0,
"core.events": [
11259,
11265,
11271,
11277,
11283,
11289,
11295,
11301,
11307,
11313,
11319,
11325,
11331,
11337,
11343,
11349,
11355,
11361,
11367,
11373,
11379,
11385,
11391,
11397,
11403,
11409,
11415,
11421,
11427,
11433,
11439,
11445,
11451,
11457,
11463,
11469,
11475,
11481,
11487,
11493,
11499,
11505
],
"core.event_count": 42,
"core.first_event_number": 11259,
"core.last_event_number": 11505,
"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_0046_df-s05-d3_dw_0_20250918T191539.hdf5"
}
]
}Forming hist metadata
formed
{
"name": "np02vd_raw_run039499_0046_df-s05-d3_dw_0_20250918T191539_reco_stage1_20250918T215448_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": 1758232489.0,
"core.end_time": 1758232489.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_0046_df-s05-d3_dw_0_20250918T191539.hdf5"
}
]
} 