Jobsub ID 49243.96@dunegpschedd01.fnal.gov
Jobscript log (last 10,000 characters)
ode=1
[06:32:45.958] D [ glue ] <ChannelSelector:chsel0> see EOS at call=39
[06:32:45.958] D [ aux ] <Resampler:resmp0> EOS at call=79
[06:32:45.958] D [sigproc ] <OmnibusSigProc:anode0sigproc0> EOS at call=79 anode=0
[06:32:45.958] D [ glue ] <FrameFanin:nfsp> EOS at call=79 with 8
[06:32:45.958] D [ glue ] frame sink sees EOS
[06:32:45.958] D [ pgraph ] <Pgrapher:> graph execution complete
[06:32:45.959] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 18.26 sec
[06:32:45.959] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 16.5 sec
[06:32:45.959] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 16.48 sec
[06:32:45.959] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 15.54 sec
[06:32:45.959] I [ timer ] Timer: WireCell::Aux::Resampler : 2.13 sec
[06:32:45.959] I [ timer ] Timer: WireCell::Aux::Resampler : 2.12 sec
[06:32:45.959] I [ timer ] Timer: WireCell::Aux::Resampler : 1.98 sec
[06:32:45.959] I [ timer ] Timer: WireCell::Aux::Resampler : 1.91 sec
[06:32:45.959] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.02 sec
[06:32:45.959] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.02 sec
[06:32:45.959] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[06:32:45.959] I [ timer ] Timer: WireCell::Gen::Retagger : 0.01 sec
[06:32:45.959] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[06:32:45.959] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[06:32:45.959] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[06:32:45.959] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[06:32:45.959] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[06:32:45.959] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[06:32:45.959] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[06:32:45.959] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[06:32:45.959] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[06:32:45.959] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[06:32:45.959] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0 sec
[06:32:45.959] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[06:32:45.959] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[06:32:45.959] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[06:32:45.959] I [ timer ] Timer: Total node execution : 74.97999971732497 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 22085 traces tagged "gauss"
FrameSaver: q=2.69631e+06 n=456628 tag=gauss
wclsFrameSaver: saving 28212 traces tagged "wiener"
FrameSaver: q=2.85025e+06 n=434597 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 719 XUs and 903 XVs -> 68 XUVs
C:0 T:1 633 XUs and 619 XVs -> 31 XUVs
C:0 T:2 72 XUs and 89 XVs -> 12 XUVs
C:0 T:3 1588 XUs and 1343 XVs -> 44 XUVs
C:0 T:4 1619 XUs and 1356 XVs -> 73 XUVs
C:0 T:5 2665 XUs and 2342 XVs -> 171 XUVs
C:0 T:6 544 XUs and 396 XVs -> 41 XUVs
C:0 T:7 2229 XUs and 1847 XVs -> 109 XUVs
549 XUVs total
457 collection wire objects
549 potential space points
Neighbour search...
5505 tests to find 2760 neighbours
Iterating with no regularization...
Begin: 1.19652e+08
0 1.1722e+08
1 1.17169e+08
Now with regularization...
Begin: 1.15902e+08
0 1.15899e+08
19-Sep-2025 06:33:20 BST Closed output file "np02vd_raw_run039499_0179_df-s04-d2_dw_0_20250918T234135_reco_stage1_20250919T053320_keepup.root"
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 137.655 199.088 525.904 187.936 62.7065 40
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 8.2676e-05 0.000140153 0.000263961 0.000123759 4.7608e-05 40
produce:tpcrawdecoder:PDVDTPCReader 12.9074 38.8084 54.2161 39.4353 8.89962 40
produce:triggerrawdecoder:PDVDTriggerReader4 0.378421 0.424698 0.582033 0.409427 0.0486622 40
produce:pdvddaphne:DAPHNEReaderPDVD 7.60284 11.6586 16.7127 11.5225 2.32817 40
produce:ophit:OpHitFinder 0.0622542 0.0824936 0.126361 0.0810618 0.011999 40
produce:opflash:OpFlashFinderVerticalDrift 0.0128095 0.0218589 0.0450613 0.0206525 0.0064062 40
produce:wclsdatavd:WireCellToolkit 54.2399 78.8545 126.261 71.2318 18.4731 40
produce:gaushit:GausHitFinder 0.734829 1.41054 2.80765 1.36428 0.445859 40
produce:nhitsfilter:NumberOfHitsFilter 0.00017098 0.000297548 0.000592424 0.000288494 7.46693e-05 40
produce:reco3d:SpacePointSolver 3.8401 9.41735 20.0253 9.03658 3.45795 40
produce:hitpdune:DisambigFromSpacePoints 0.0524864 0.208276 0.763734 0.177704 0.132675 40
produce:pandora:StandardPandora 8.78321 52.4806 363.524 36.7309 57.3892 40
produce:pandoraTrack:LArPandoraTrackCreation 0.210488 0.910988 3.32914 0.857236 0.590234 40
produce:pandoraGnocalo:GnocchiCalorimetry 0.0186956 0.032502 0.0548569 0.0318316 0.00857741 40
[art]:TriggerResults:TriggerResultInserter 3.4171e-05 0.000195479 0.00589291 4.4074e-05 0.000912452 40
end_path:out1:RootOutput 4.791e-06 1.0547e-05 3.1426e-05 9.3275e-06 5.48784e-06 40
end_path:out1:RootOutput(write) 3.86816 4.73466 6.22546 4.7014 0.521237 40
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 4343.32 MB
Peak resident set size usage (VmHWM): 2436.03 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run039499_0179_df-s04-d2_dw_0_20250918T234135_reco_stage1_20250919T053320_keepup.root
\tHists: np02vd_raw_run039499_0179_df-s04-d2_dw_0_20250918T234135_reco_stage1_20250919T053321_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run039499_0179_df-s04-d2_dw_0_20250918T234135_reco_stage1_20250919T053320_keepup.root
Ran successfully
{
"name": "np02vd_raw_run039499_0179_df-s04-d2_dw_0_20250918T234135_reco_stage1_20250919T053320_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": 1758260002.0,
"core.end_time": 1758260002.0,
"core.events": [
43681,
43687,
43693,
43699,
43705,
43711,
43717,
43723,
43729,
43735,
43741,
43747,
43753,
43759,
43765,
43771,
43777,
43783,
43789,
43795,
43801,
43807,
43813,
43819,
43825,
43831,
43837,
43843,
43849,
43855,
43861,
43867,
43873,
43879,
43885,
43891,
43897,
43903,
43909,
43915
],
"core.event_count": 40,
"core.first_event_number": 43681,
"core.last_event_number": 43915,
"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_0179_df-s04-d2_dw_0_20250918T234135.hdf5"
}
]
}Forming hist metadata
formed
{
"name": "np02vd_raw_run039499_0179_df-s04-d2_dw_0_20250918T234135_reco_stage1_20250919T053321_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": 1758260002.0,
"core.end_time": 1758260002.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_0179_df-s04-d2_dw_0_20250918T234135.hdf5"
}
]
}