Jobsub ID 48994.64@dunegpschedd01.fnal.gov
Jobscript log (last 10,000 characters)
e1sigproc1> EOS at call=79 anode=1
[22:36:27.120] D [ glue ] <ChannelSelector:chsel0> see EOS at call=39
[22:36:27.120] D [ aux ] <Resampler:resmp0> EOS at call=79
[22:36:27.120] D [sigproc ] <OmnibusSigProc:anode0sigproc0> EOS at call=79 anode=0
[22:36:27.120] D [ glue ] <FrameFanin:nfsp> EOS at call=79 with 8
[22:36:27.120] D [ glue ] frame sink sees EOS
[22:36:27.120] D [ pgraph ] <Pgrapher:> graph execution complete
[22:36:27.121] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 10.21 sec
[22:36:27.121] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.34 sec
[22:36:27.121] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.21 sec
[22:36:27.121] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.1 sec
[22:36:27.121] I [ timer ] Timer: WireCell::Aux::Resampler : 0.32 sec
[22:36:27.121] I [ timer ] Timer: WireCell::Aux::Resampler : 0.31 sec
[22:36:27.121] I [ timer ] Timer: WireCell::Aux::Resampler : 0.31 sec
[22:36:27.121] I [ timer ] Timer: WireCell::Aux::Resampler : 0.25 sec
[22:36:27.121] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.01 sec
[22:36:27.121] I [ timer ] Timer: WireCell::Gen::Retagger : 0.01 sec
[22:36:27.121] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[22:36:27.121] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[22:36:27.121] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[22:36:27.121] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[22:36:27.121] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[22:36:27.121] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[22:36:27.121] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[22:36:27.121] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[22:36:27.121] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[22:36:27.121] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[22:36:27.121] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[22:36:27.121] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[22:36:27.121] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0 sec
[22:36:27.121] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[22:36:27.121] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[22:36:27.121] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[22:36:27.121] I [ timer ] Timer: Total node execution : 36.07000060752034 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 22559 traces tagged "gauss"
FrameSaver: q=3.65548e+06 n=504352 tag=gauss
wclsFrameSaver: saving 28521 traces tagged "wiener"
FrameSaver: q=3.93917e+06 n=484694 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 855 XUs and 1255 XVs -> 48 XUVs
C:0 T:1 434 XUs and 213 XVs -> 13 XUVs
C:0 T:2 1005 XUs and 1038 XVs -> 68 XUVs
C:0 T:3 439 XUs and 748 XVs -> 30 XUVs
C:0 T:4 1560 XUs and 1758 XVs -> 72 XUVs
C:0 T:5 9408 XUs and 9018 XVs -> 685 XUVs
C:0 T:6 1563 XUs and 1378 XVs -> 99 XUVs
C:0 T:7 3210 XUs and 2691 XVs -> 278 XUVs
1293 XUVs total
844 collection wire objects
1293 potential space points
Neighbour search...
50663 tests to find 13038 neighbours
Iterating with no regularization...
Begin: 1.63518e+09
0 1.55053e+09
1 1.54723e+09
2 1.54722e+09
Now with regularization...
Begin: 1.53412e+09
0 1.5341e+09
18-Sep-2025 22:37:00 BST Closed output file "np02vd_raw_run039499_0028_df-s04-d1_dw_0_20250918T183801_reco_stage1_20250918T213700_keepup.root"
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 82.4274 136.555 247.453 128.753 38.7019 40
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 9.2644e-05 0.000134849 0.000325682 0.00012 4.52636e-05 40
produce:tpcrawdecoder:PDVDTPCReader 23.7456 39.1268 65.9788 38.1502 10.5608 40
produce:triggerrawdecoder:PDVDTriggerReader4 0.386381 0.447683 0.74901 0.420437 0.0755265 40
produce:pdvddaphne:DAPHNEReaderPDVD 5.03906 9.22512 29.1354 8.68609 3.63674 40
produce:ophit:OpHitFinder 0.0425132 0.0575968 0.0748023 0.0576905 0.0065157 40
produce:opflash:OpFlashFinderVerticalDrift 0.00725722 0.013759 0.0245754 0.0141501 0.00378807 40
produce:wclsdatavd:WireCellToolkit 27.6955 41.7001 70.6583 38.1994 10.6621 40
produce:gaushit:GausHitFinder 0.320563 0.746468 1.13651 0.773675 0.21493 40
produce:nhitsfilter:NumberOfHitsFilter 0.000102462 0.000269876 0.000673376 0.000236339 0.000124589 40
produce:reco3d:SpacePointSolver 1.71091 7.38586 13.5882 7.47935 2.761 40
produce:hitpdune:DisambigFromSpacePoints 0.0178478 0.108445 0.333137 0.0882128 0.0654342 40
produce:pandora:StandardPandora 2.65567 34.1255 133.585 22.5556 29.8565 40
produce:pandoraTrack:LArPandoraTrackCreation 0.0957404 0.433148 1.19301 0.375166 0.247495 40
produce:pandoraGnocalo:GnocchiCalorimetry 0.00935436 0.0225374 0.0432585 0.0232791 0.00871648 40
[art]:TriggerResults:TriggerResultInserter 1.8755e-05 3.98018e-05 0.000147126 3.4891e-05 2.111e-05 40
end_path:out1:RootOutput 4.208e-06 1.0073e-05 5.4342e-05 8.406e-06 8.02647e-06 40
end_path:out1:RootOutput(write) 2.31801 3.13582 3.96529 3.19244 0.413515 40
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 4957.99 MB
Peak resident set size usage (VmHWM): 3034.2 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run039499_0028_df-s04-d1_dw_0_20250918T183801_reco_stage1_20250918T213700_keepup.root
\tHists: np02vd_raw_run039499_0028_df-s04-d1_dw_0_20250918T183801_reco_stage1_20250918T213701_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run039499_0028_df-s04-d1_dw_0_20250918T183801_reco_stage1_20250918T213700_keepup.root
Ran successfully
{
"name": "np02vd_raw_run039499_0028_df-s04-d1_dw_0_20250918T183801_reco_stage1_20250918T213700_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": 1758231421.0,
"core.end_time": 1758231421.0,
"core.events": [
6798,
6804,
6810,
6816,
6822,
6828,
6834,
6840,
6846,
6852,
6858,
6864,
6870,
6876,
6882,
6888,
6894,
6900,
6906,
6912,
6918,
6924,
6930,
6936,
6942,
6948,
6954,
6960,
6966,
6972,
6978,
6984,
6990,
6996,
7002,
7008,
7014,
7020,
7026,
7032
],
"core.event_count": 40,
"core.first_event_number": 6798,
"core.last_event_number": 7032,
"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_0028_df-s04-d1_dw_0_20250918T183801.hdf5"
}
]
}Forming hist metadata
formed
{
"name": "np02vd_raw_run039499_0028_df-s04-d1_dw_0_20250918T183801_reco_stage1_20250918T213701_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": 1758231421.0,
"core.end_time": 1758231421.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_0028_df-s04-d1_dw_0_20250918T183801.hdf5"
}
]
}