Jobsub ID 257863.10@dunegpschedd01.fnal.gov
Jobscript log (last 10,000 characters)
22
[00:18:27.832] D [ aux ] <Resampler:resmp0> EOS at call=45
[00:18:27.832] D [sigproc ] <OmnibusSigProc:anode0sigproc0> EOS at call=45 anode=0
[00:18:27.832] D [ glue ] <FrameFanin:nfsp> EOS at call=45 with 8
[00:18:27.832] D [ glue ] frame sink sees EOS
[00:18:27.832] D [ pgraph ] <Pgrapher:> graph execution complete
[00:18:27.832] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 12.55 sec
[00:18:27.832] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 11.92 sec
[00:18:27.832] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 11.48 sec
[00:18:27.832] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 11.09 sec
[00:18:27.832] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 10.93 sec
[00:18:27.832] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 10.89 sec
[00:18:27.832] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 10.35 sec
[00:18:27.832] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 9.55 sec
[00:18:27.832] I [ timer ] Timer: WireCell::Aux::Resampler : 0.97 sec
[00:18:27.832] I [ timer ] Timer: WireCell::Aux::Resampler : 0.96 sec
[00:18:27.832] I [ timer ] Timer: WireCell::Aux::Resampler : 0.96 sec
[00:18:27.832] I [ timer ] Timer: WireCell::Aux::Resampler : 0.9 sec
[00:18:27.832] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.04 sec
[00:18:27.832] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.02 sec
[00:18:27.832] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[00:18:27.832] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[00:18:27.832] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[00:18:27.832] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[00:18:27.832] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[00:18:27.832] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[00:18:27.832] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[00:18:27.832] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[00:18:27.832] I [ timer ] Timer: WireCell::Gen::Retagger : 0 sec
[00:18:27.832] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0 sec
[00:18:27.832] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[00:18:27.832] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[00:18:27.832] I [ timer ] Timer: Total node execution : 92.61000114306808 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 47116 traces tagged "gauss"
FrameSaver: q=1.12481e+07 n=950710 tag=gauss
wclsFrameSaver: saving 56711 traces tagged "wiener"
FrameSaver: q=1.18808e+07 n=913887 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 79 XUs and 92 XVs -> 0 XUVs
C:0 T:1 120 XUs and 104 XVs -> 4 XUVs
C:0 T:2 268 XUs and 479 XVs -> 18 XUVs
C:0 T:3 744 XUs and 842 XVs -> 66 XUVs
C:0 T:4 7175 XUs and 8897 XVs -> 545 XUVs
C:0 T:5 338 XUs and 884 XVs -> 15 XUVs
C:0 T:6 848 XUs and 1123 XVs -> 26 XUVs
C:0 T:7 1250 XUs and 2197 XVs -> 40 XUVs
C:0 T:8 412 XUs and 503 XVs -> 23 XUVs
C:0 T:9 237 XUs and 428 XVs -> 12 XUVs
C:0 T:10 1436 XUs and 1606 XVs -> 68 XUVs
C:0 T:11 759 XUs and 972 XVs -> 46 XUVs
C:0 T:12 1756 XUs and 1681 XVs -> 86 XUVs
C:0 T:13 1745 XUs and 1869 XVs -> 80 XUVs
C:0 T:14 482 XUs and 530 XVs -> 32 XUVs
C:0 T:15 303 XUs and 270 XVs -> 15 XUVs
1076 XUVs total
791 collection wire objects
1076 potential space points
Neighbour search...
23434 tests to find 6824 neighbours
Iterating with no regularization...
Begin: 1.86654e+10
0 1.85665e+10
1 1.85663e+10
Now with regularization...
Begin: 1.8347e+10
0 1.83468e+10
26-Nov-2025 00:19:09 CET Closed output file "np02vd_raw_run040880_0014_df-s04-d0_dw_0_20251125T185349_reco_stage1_20251125T231909_keepup.root"
==================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
==================================================================================================================================
Full event 103.951 152.307 386.685 139.15 55.0666 23
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read) 7.6534e-05 0.000123482 0.000264595 9.9138e-05 5.09805e-05 23
produce:tpcrawdecoder:PDVDTPCReader 5.28752 5.83546 6.78918 5.74592 0.476629 23
produce:triggerrawdecoder:PDVDTriggerReader4 0.131364 0.151188 0.348252 0.139558 0.0444504 23
produce:pdvddaphne:DAPHNEReaderPDVD 0.000302682 0.000417107 0.00100697 0.000379256 0.000135194 23
produce:ophit:OpHitFinder 7.5222e-05 0.000152352 0.000965631 0.000109803 0.000175526 23
produce:opflash:OpFlashFinderVerticalDrift 4.8242e-05 0.000121777 0.00133621 6.686e-05 0.00025914 23
produce:wclsdatavd:WireCellToolkit 75.9133 94.0075 141.215 87.6201 18.1715 23
produce:gaushit:GausHitFinder 0.746526 1.31799 1.79355 1.29373 0.285234 23
produce:nhitsfilter:NumberOfHitsFilter 0.00021482 0.000346566 0.00112877 0.000297945 0.00018388 23
produce:reco3d:SpacePointSolver 5.36335 11.4174 21.7287 11.2354 3.43065 23
produce:hitpdune:DisambigFromSpacePoints 0.0911559 0.194642 0.370195 0.175708 0.067474 23
produce:pandora:StandardPandora 8.7008 33.1407 206.12 22.7291 38.3145 23
produce:pandoraTrack:LArPandoraTrackCreation 0.445122 1.36987 3.97364 1.33019 0.802849 23
produce:pandoraGnocalo:GnocchiCalorimetry 0.0229983 0.039532 0.0561059 0.0377514 0.00997827 23
[art]:TriggerResults:TriggerResultInserter 4.2103e-05 7.32001e-05 0.000144676 7.0886e-05 2.23616e-05 23
end_path:out1:RootOutput 7.642e-06 1.711e-05 5.1928e-05 1.6335e-05 8.856e-06 23
end_path:out1:RootOutput(write) 4.1722 4.73213 5.91586 4.6774 0.443723 23
==================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 6173.33 MB
Peak resident set size usage (VmHWM): 4100.95 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run040880_0014_df-s04-d0_dw_0_20251125T185349_reco_stage1_20251125T231909_keepup.root
\tHists: np02vd_raw_run040880_0014_df-s04-d0_dw_0_20251125T185349_reco_stage1_20251125T231909_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run040880_0014_df-s04-d0_dw_0_20251125T185349_reco_stage1_20251125T231909_keepup.root
Ran successfully
{
"name": "np02vd_raw_run040880_0014_df-s04-d0_dw_0_20251125T185349_reco_stage1_20251125T231909_keepup.root",
"namespace": "vd-protodune-det-reco",
"metadata": {
"core.file_format": "artroot",
"core.application.name": "reco",
"core.application.family": "dunesw",
"core.application.version": "v10_13_00d00",
"core.data_tier": "full-reconstructed",
"dune.config_file": "standard_reco_stage1_protodunevd_keepup.fcl",
"dune.campaign": "vd-protodune-reco-keepup-v0",
"core.start_time": 1764112750.0,
"core.end_time": 1764112750.0,
"core.events": [
1280,
1284,
1288,
1292,
1296,
1300,
1304,
1308,
1312,
1316,
1320,
1324,
1328,
1332,
1336,
1340,
1344,
1348,
1352,
1356,
1360,
1364,
1368
],
"core.event_count": 23,
"core.first_event_number": 1280,
"core.last_event_number": 1368,
"core.data_stream": "cosmics",
"core.file_content_status": "good",
"core.file_type": "detector",
"core.run_type": "vd-protodune",
"core.runs": [
40880
],
"core.runs_subruns": [
4088000001
],
"dune.daq_test": false,
"retention.status": "active",
"retention.class": "physics"
},
"parents": [
{
"did": "vd-protodune:np02vd_raw_run040880_0014_df-s04-d0_dw_0_20251125T185349.hdf5"
}
]
}Forming hist metadata
formed
{
"name": "np02vd_raw_run040880_0014_df-s04-d0_dw_0_20251125T185349_reco_stage1_20251125T231909_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_13_00d00",
"core.data_tier": "root-tuple-virtual",
"dune.config_file": "standard_reco_stage1_protodunevd_keepup.fcl",
"dune.campaign": "vd-protodune-reco-keepup-v0",
"core.start_time": 1764112750.0,
"core.end_time": 1764112750.0,
"core.data_stream": "cosmics",
"core.file_content_status": "good",
"core.file_type": "detector",
"core.run_type": "vd-protodune",
"core.runs": [
40880
],
"core.runs_subruns": [
4088000001
],
"dune.daq_test": false,
"retention.status": "active",
"retention.class": "physics"
},
"parents": [
{
"did": "vd-protodune:np02vd_raw_run040880_0014_df-s04-d0_dw_0_20251125T185349.hdf5"
}
]
} 