Jobsub ID 263305.27@dunegpschedd02.fnal.gov
Jobscript log (last 10,000 characters)
e tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss0":22877 [0] "wiener0":26173 [26173] ] cmm:[ bad:0 lf_noisy:58 ] input 1: frame: ident=179 time=0 tick=512 with 42438 traces. frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss1":17851 [0] "wiener1":24587 [24587] ] cmm:[ bad:0 ] input 2: frame: ident=179 time=0 tick=512 with 34647 traces. frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss2":14848 [0] "wiener2":19799 [19799] ] cmm:[ bad:0 ] input 3: frame: ident=179 time=0 tick=512 with 45284 traces. frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss3":18922 [0] "wiener3":26362 [26362] ] cmm:[ bad:0 lf_noisy:11 ] output: frame: ident=179 time=0 tick=512 with 171419 traces. frame tags:[ "framefanin" ] 8 tagged trace sets:[ "gauss0":22877 [0] "gauss1":17851 [0] "gauss2":14848 [0] "gauss3":18922 [0] "wiener0":26173 [26173] "wiener1":24587 [24587] "wiener2":19799 [19799] "wiener3":26362 [26362] ] cmm:[ bad:0 lf_noisy:69 ]
Retagger: tagging trace set: wiener with 96921 traces, 96921 summary
Retagger: tagging trace set: gauss with 74498 traces, 0 summary
[16:17:50.028] D [ glue ] sink frame: #179 @0 with 171419 traces, frame tags:[retagger], trace tags:[gauss, wiener]
[16:17:50.028] D [ glue ] <FrameFanout:sn_mag_nf> call=19: see EOS
[16:17:50.028] D [ glue ] <ChannelSelector:chsel3> see EOS at call=9
[16:17:50.028] D [sigproc ] <OmnibusNoiseFilter:nf3> EOS at call=19
[16:17:50.028] D [sigproc ] <OmnibusSigProc:apa3sigproc3> EOS at call=19 anode=3
[16:17:50.028] D [ glue ] <ChannelSelector:chsel2> see EOS at call=9
[16:17:50.028] D [sigproc ] <OmnibusNoiseFilter:nf2> EOS at call=19
[16:17:50.028] D [sigproc ] <OmnibusSigProc:apa2sigproc2> EOS at call=19 anode=2
[16:17:50.028] D [ glue ] <ChannelSelector:chsel1> see EOS at call=9
[16:17:50.028] D [sigproc ] <OmnibusNoiseFilter:nf1> EOS at call=19
[16:17:50.028] D [sigproc ] <OmnibusSigProc:apa1sigproc1> EOS at call=19 anode=1
[16:17:50.028] D [ glue ] <ChannelSelector:chsel0> see EOS at call=9
[16:17:50.028] D [sigproc ] <OmnibusNoiseFilter:nf0> EOS at call=19
[16:17:50.028] D [sigproc ] <OmnibusSigProc:apa0sigproc0> EOS at call=19 anode=0
[16:17:50.028] D [ glue ] <FrameFanin:sn_mag_nf> EOS at call=19 with 4
[16:17:50.028] D [ glue ] frame sink sees EOS
[16:17:50.028] D [ pgraph ] <Pgrapher:> graph execution complete
[16:17:50.029] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 12 sec
[16:17:50.029] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.17 sec
[16:17:50.029] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.64 sec
[16:17:50.029] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.51 sec
[16:17:50.029] I [ timer ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 3.18 sec
[16:17:50.029] I [ timer ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 3.09 sec
[16:17:50.029] I [ timer ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.85 sec
[16:17:50.029] I [ timer ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.68 sec
[16:17:50.029] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0.01 sec
[16:17:50.029] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[16:17:50.029] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[16:17:50.029] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.01 sec
[16:17:50.029] I [ timer ] Timer: WireCell::Gen::Retagger : 0.01 sec
[16:17:50.029] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[16:17:50.029] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[16:17:50.029] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[16:17:50.029] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[16:17:50.029] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[16:17:50.029] I [ timer ] Timer: Total node execution : 47.170000122860074 sec
wclsFrameSaver saving cooked to 6000 ticks
wclsFrameSaver: saving 74498 traces tagged "gauss"
FrameSaver: q=2.30042e+06 n=1108786 tag=gauss
wclsFrameSaver: saving 96921 traces tagged "wiener"
FrameSaver: q=2.99004e+06 n=1089717 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:2 22920 XUs and 18288 XVs -> 1024 XUVs
C:0 T:3 25 XUs and 19 XVs -> 0 XUVs
C:0 T:4 60 XUs and 20 XVs -> 0 XUVs
C:0 T:5 38089 XUs and 21818 XVs -> 1321 XUVs
C:0 T:6 35454 XUs and 60467 XVs -> 8248 XUVs
C:0 T:7 10 XUs and 15 XVs -> 2 XUVs
10595 XUVs total
1998 collection wire objects
10595 potential space points
Neighbour search...
1457111 tests to find 709934 neighbours
Iterating with no regularization...
Begin: 5.66051e+07
0 4.89846e+07
1 4.84639e+07
2 4.83724e+07
3 4.83461e+07
Now with regularization...
Begin: 4.47342e+07
0 4.47088e+07
TestBeamParticleCreationAlgorithm::SetupTestBeamVertex - Test beam particle has no initial vertex
18-Dec-2025 16:18:32 CST Closed output file "pdhd_prod_beam__267378_34_1_20251212T160729Z_gen_g4_IonScintPDExt.root_262727_1_1_20251215T214235Z_PDInt.root_263305_27_1_20251218T205550Z_detsim_reco1.root"
18-Dec-2025 16:18:32 CST Closed input file "temp_detsim.root"
=====================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
=====================================================================================================================================
Full event 77.2656 88.4113 95.4621 87.7627 5.47166 10
-------------------------------------------------------------------------------------------------------------------------------------
source:RootInput(read) 0.00118774 0.00533573 0.0136807 0.0055517 0.00321845 10
reco:wclsdatahd:WireCellToolkit 49.2561 56.2599 61.6532 57.9366 4.98879 10
reco:wirefilter:WireFilter 0.0151945 0.0202251 0.0263175 0.0197742 0.00375153 10
reco:gaushit:GausHitFinder 0.383433 0.485015 0.696726 0.444326 0.0939151 10
reco:nhitsfilter:NumberOfHitsFilter 0.000236882 0.000363569 0.000529078 0.000350876 7.6425e-05 10
reco:reco3d:SpacePointSolver 0.162058 0.394876 0.861936 0.297649 0.224865 10
reco:hitpdune:DisambigFromSpacePoints 0.14286 0.274185 0.451999 0.220803 0.0988698 10
reco:pandora:StandardPandora 3.58961 6.00874 9.0099 6.00228 1.99054 10
reco:pandoraWriter:StandardPandora 0.142596 0.198097 0.257532 0.182731 0.0410559 10
reco:pandoraTrack:LArPandoraTrackCreation 0.426259 0.692705 1.13868 0.703174 0.20333 10
reco:pandoraShower:LArPandoraShowerCreation 0.277488 0.534574 0.937428 0.43652 0.227548 10
reco:pandoracalo:Calorimetry 0.22039 0.37612 0.518871 0.375375 0.0824534 10
reco:pandoracalonosce:Calorimetry 0.201251 0.360369 0.476052 0.362761 0.0808438 10
reco:pandoraShowercalo:ShowerCalorimetry 0.250928 0.520957 0.846753 0.442534 0.218914 10
reco:pandoraShowercalonosce:ShowerCalorimetry 0.229473 0.544287 1.03408 0.439411 0.275369 10
reco:pandoraGnocchiCalo:GnocchiCalorimetry 0.0247015 0.044767 0.0661751 0.0434666 0.0142508 10
reco:pandoraGnocchiCalonosce:GnocchiCalorimetry 0.0257204 0.0453034 0.0634107 0.0440249 0.0138346 10
reco:emtrkmichelid:EmTrackMichelId 15.005 20.4359 27.5692 19.3599 4.44727 10
[art]:TriggerResults:TriggerResultInserter 3.4555e-05 6.46218e-05 0.000109154 5.96565e-05 2.39501e-05 10
end_path:out1:RootOutput 7.574e-06 1.82551e-05 6.3769e-05 1.0269e-05 1.68341e-05 10
end_path:out1:RootOutput(write) 0.916823 1.13689 1.4506 1.1252 0.187923 10
=====================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 5634.7 MB
Peak resident set size usage (VmHWM): 3431.05 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Reco returns 0
.:
total 10298484
-rw-r--r--. 1 dune osgvo 231435 Dec 18 16:18 jobscript.log
-rw-r--r--. 1 dune osgvo 199 Dec 18 16:18 justin-processed-pfns.txt
-rw-r--r--. 1 dune osgvo 519 Dec 18 16:18 reco_protodunehd_hist.root
-rw-r--r--. 1 dune osgvo 3574 Dec 18 16:18 Pandora_Geometry.xml
-rw-r--r--. 1 dune osgvo 139264 Dec 18 16:18 mem.db
-rw-r--r--. 1 dune osgvo 28672 Dec 18 16:18 time.db
-rw-r--r--. 1 dune osgvo 5337535846 Dec 18 16:18 pdhd_prod_beam__267378_34_1_20251212T160729Z_gen_g4_IonScintPDExt.root_262727_1_1_20251215T214235Z_PDInt.root_263305_27_1_20251218T205550Z_detsim_reco1.root
-rw-r--r--. 1 dune osgvo 28681640 Dec 18 16:18 Pandora_Events.pndr
-rw-r--r--. 1 dune osgvo 0 Dec 18 16:02 debugprod.log
-rw-r--r--. 1 dune osgvo 519 Dec 18 16:01 detsim_single_protodunehd_hist.root
-rw-r--r--. 1 dune osgvo 5178974417 Dec 18 16:01 temp_detsim.root
-rw-r--r--. 1 dune osgvo 120 Dec 18 14:55 all-input-dids.txt