Jobsub ID 49050.101@dunegpschedd01.fnal.gov
Jobscript log (last 10,000 characters)
lector:chsel0> see EOS at call=40
[01:24:00.932] D [ aux ] <Resampler:resmp0> EOS at call=81
[01:24:00.932] D [sigproc ] <OmnibusSigProc:anode0sigproc0> EOS at call=81 anode=0
[01:24:00.933] D [ glue ] <FrameFanin:nfsp> EOS at call=81 with 8
[01:24:00.933] D [ glue ] frame sink sees EOS
[01:24:00.933] D [ pgraph ] <Pgrapher:> graph execution complete
[01:24:00.933] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 17.06 sec
[01:24:00.933] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 14.2 sec
[01:24:00.933] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 13.91 sec
[01:24:00.933] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 13.81 sec
[01:24:00.933] I [ timer ] Timer: WireCell::Aux::Resampler : 0.64 sec
[01:24:00.933] I [ timer ] Timer: WireCell::Aux::Resampler : 0.55 sec
[01:24:00.933] I [ timer ] Timer: WireCell::Aux::Resampler : 0.43 sec
[01:24:00.933] I [ timer ] Timer: WireCell::Aux::Resampler : 0.42 sec
[01:24:00.933] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.03 sec
[01:24:00.933] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[01:24:00.933] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[01:24:00.933] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[01:24:00.933] I [ timer ] Timer: WireCell::Gen::Retagger : 0.01 sec
[01:24:00.933] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[01:24:00.933] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[01:24:00.933] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[01:24:00.933] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[01:24:00.933] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[01:24:00.933] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[01:24:00.933] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[01:24:00.933] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[01:24:00.933] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[01:24:00.933] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0 sec
[01:24:00.933] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[01:24:00.933] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[01:24:00.933] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[01:24:00.933] I [ timer ] Timer: Total node execution : 61.089999532327056 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 24098 traces tagged "gauss"
FrameSaver: q=7.08968e+06 n=597078 tag=gauss
wclsFrameSaver: saving 31220 traces tagged "wiener"
FrameSaver: q=7.54753e+06 n=576297 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 679 XUs and 1435 XVs -> 45 XUVs
C:0 T:1 339 XUs and 451 XVs -> 14 XUVs
C:0 T:2 14734 XUs and 16545 XVs -> 1234 XUVs
C:0 T:3 1751 XUs and 1769 XVs -> 112 XUVs
C:0 T:4 1351 XUs and 2290 XVs -> 92 XUVs
C:0 T:5 1477 XUs and 2408 XVs -> 146 XUVs
C:0 T:6 1026 XUs and 1453 XVs -> 46 XUVs
C:0 T:7 614 XUs and 1078 XVs -> 44 XUVs
1733 XUVs total
779 collection wire objects
1733 potential space points
Neighbour search...
46809 tests to find 13948 neighbours
Iterating with no regularization...
Begin: 1.2108e+10
0 1.15067e+10
1 1.14636e+10
2 1.14625e+10
Now with regularization...
Begin: 1.12631e+10
0 1.12626e+10
19-Sep-2025 01:25:00 BST Closed output file "np02vd_raw_run039499_0065_df-s04-d3_dw_0_20250918T195352_reco_stage1_20250919T002500_keepup.root"
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 115.585 241.748 1491.68 164.79 256.986 41
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 8.8475e-05 0.000142043 0.000350718 0.000119466 6.10461e-05 41
produce:tpcrawdecoder:PDVDTPCReader 25.2217 39.8096 97.2146 37.182 12.613 41
produce:triggerrawdecoder:PDVDTriggerReader4 0.37124 0.438278 0.826229 0.397134 0.0949197 41
produce:pdvddaphne:DAPHNEReaderPDVD 8.12653 11.8579 22.9877 11.5007 2.34878 41
produce:ophit:OpHitFinder 0.0709797 0.0835085 0.127866 0.0799357 0.0121808 41
produce:opflash:OpFlashFinderVerticalDrift 0.0122601 0.0264617 0.22266 0.0210008 0.0314798 41
produce:wclsdatavd:WireCellToolkit 48.4764 70.9686 127.341 60.354 22.7497 41
produce:gaushit:GausHitFinder 0.612816 1.30016 3.46944 1.22338 0.518064 41
produce:nhitsfilter:NumberOfHitsFilter 0.000216365 0.000355371 0.000664689 0.000329131 0.000104268 41
produce:reco3d:SpacePointSolver 2.01062 10.6171 39.038 8.52274 6.83894 41
produce:hitpdune:DisambigFromSpacePoints 0.0426402 0.227554 1.03716 0.149035 0.218951 41
produce:pandora:StandardPandora 8.23246 100.726 1289.75 29.7016 237.326 41
produce:pandoraTrack:LArPandoraTrackCreation 0.167883 1.30521 11.3102 0.722928 1.88843 41
produce:pandoraGnocalo:GnocchiCalorimetry 0.0120451 0.0341826 0.0829967 0.0312624 0.0133639 41
[art]:TriggerResults:TriggerResultInserter 3.1507e-05 5.47496e-05 0.000101587 4.8703e-05 1.56816e-05 41
end_path:out1:RootOutput 5.565e-06 1.21075e-05 3.8613e-05 1.0827e-05 5.58708e-06 41
end_path:out1:RootOutput(write) 2.77887 4.30881 6.27822 4.20921 0.660743 41
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 6010.92 MB
Peak resident set size usage (VmHWM): 4104.74 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run039499_0065_df-s04-d3_dw_0_20250918T195352_reco_stage1_20250919T002500_keepup.root
\tHists: np02vd_raw_run039499_0065_df-s04-d3_dw_0_20250918T195352_reco_stage1_20250919T002502_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run039499_0065_df-s04-d3_dw_0_20250918T195352_reco_stage1_20250919T002500_keepup.root
Ran successfully
{
"name": "np02vd_raw_run039499_0065_df-s04-d3_dw_0_20250918T195352_reco_stage1_20250919T002500_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": 1758241503.0,
"core.end_time": 1758241503.0,
"core.events": [
15860,
15866,
15872,
15878,
15884,
15890,
15896,
15902,
15908,
15914,
15920,
15926,
15932,
15938,
15944,
15950,
15956,
15962,
15968,
15974,
15980,
15986,
15992,
15998,
16004,
16010,
16016,
16022,
16028,
16034,
16040,
16046,
16052,
16058,
16064,
16070,
16076,
16082,
16088,
16094,
16100
],
"core.event_count": 41,
"core.first_event_number": 15860,
"core.last_event_number": 16100,
"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_0065_df-s04-d3_dw_0_20250918T195352.hdf5"
}
]
}Forming hist metadata
formed
{
"name": "np02vd_raw_run039499_0065_df-s04-d3_dw_0_20250918T195352_reco_stage1_20250919T002502_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": 1758241503.0,
"core.end_time": 1758241503.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_0065_df-s04-d3_dw_0_20250918T195352.hdf5"
}
]
} 