Jobsub ID 263114.1@dunegpschedd02.fnal.gov
Jobscript log (last 10,000 characters)
race sets:[ "gauss0":29871 [0] "wiener0":33385 [33385] ] cmm:[ bad:0 lf_noisy:159 ]
[16:37:35.307] D [ glue ] <FrameFanin:sn_mag_nf> call=18 input 0: frame: ident=149 time=0 tick=512 with 63256 traces. frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss0":29871 [0] "wiener0":33385 [33385] ] cmm:[ bad:0 lf_noisy:159 ] input 1: frame: ident=149 time=0 tick=512 with 43407 traces. frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss1":19061 [0] "wiener1":24346 [24346] ] cmm:[ bad:0 ] input 2: frame: ident=149 time=0 tick=512 with 65627 traces. frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss2":26667 [0] "wiener2":38960 [38960] ] cmm:[ bad:0 ] input 3: frame: ident=149 time=0 tick=512 with 36066 traces. frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss3":15463 [0] "wiener3":20603 [20603] ] cmm:[ bad:0 ] output: frame: ident=149 time=0 tick=512 with 208356 traces. frame tags:[ "framefanin" ] 8 tagged trace sets:[ "gauss0":29871 [0] "gauss1":19061 [0] "gauss2":26667 [0] "gauss3":15463 [0] "wiener0":33385 [33385] "wiener1":24346 [24346] "wiener2":38960 [38960] "wiener3":20603 [20603] ] cmm:[ bad:0 lf_noisy:159 ]
Retagger: tagging trace set: wiener with 117294 traces, 117294 summary
Retagger: tagging trace set: gauss with 91062 traces, 0 summary
[16:37:35.322] D [ glue ] sink frame: #149 @0 with 208356 traces, frame tags:[retagger], trace tags:[gauss, wiener]
[16:37:35.323] D [ glue ] <FrameFanout:sn_mag_nf> call=19: see EOS
[16:37:35.323] D [ glue ] <ChannelSelector:chsel3> see EOS at call=9
[16:37:35.323] D [sigproc ] <OmnibusNoiseFilter:nf3> EOS at call=19
[16:37:35.323] D [sigproc ] <OmnibusSigProc:apa3sigproc3> EOS at call=19 anode=3
[16:37:35.323] D [ glue ] <ChannelSelector:chsel2> see EOS at call=9
[16:37:35.323] D [sigproc ] <OmnibusNoiseFilter:nf2> EOS at call=19
[16:37:35.323] D [sigproc ] <OmnibusSigProc:apa2sigproc2> EOS at call=19 anode=2
[16:37:35.323] D [ glue ] <ChannelSelector:chsel1> see EOS at call=9
[16:37:35.323] D [sigproc ] <OmnibusNoiseFilter:nf1> EOS at call=19
[16:37:35.323] D [sigproc ] <OmnibusSigProc:apa1sigproc1> EOS at call=19 anode=1
[16:37:35.323] D [ glue ] <ChannelSelector:chsel0> see EOS at call=9
[16:37:35.323] D [sigproc ] <OmnibusNoiseFilter:nf0> EOS at call=19
[16:37:35.323] D [sigproc ] <OmnibusSigProc:apa0sigproc0> EOS at call=19 anode=0
[16:37:35.323] D [ glue ] <FrameFanin:sn_mag_nf> EOS at call=19 with 4
[16:37:35.323] D [ glue ] frame sink sees EOS
[16:37:35.323] D [ pgraph ] <Pgrapher:> graph execution complete
[16:37:35.323] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 11.59 sec
[16:37:35.323] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.33 sec
[16:37:35.323] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.83 sec
[16:37:35.323] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.78 sec
[16:37:35.323] I [ timer ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.99 sec
[16:37:35.323] I [ timer ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.92 sec
[16:37:35.323] I [ timer ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.56 sec
[16:37:35.323] I [ timer ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.24 sec
[16:37:35.323] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.02 sec
[16:37:35.323] I [ timer ] Timer: WireCell::Gen::Retagger : 0.01 sec
[16:37:35.323] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.01 sec
[16:37:35.323] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[16:37:35.323] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0 sec
[16:37:35.323] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[16:37:35.323] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[16:37:35.323] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[16:37:35.323] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[16:37:35.323] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[16:37:35.323] I [ timer ] Timer: Total node execution : 46.28000024706125 sec
wclsFrameSaver saving cooked to 6000 ticks
wclsFrameSaver: saving 91062 traces tagged "gauss"
FrameSaver: q=3.03971e+06 n=1467702 tag=gauss
wclsFrameSaver: saving 117294 traces tagged "wiener"
FrameSaver: q=3.87436e+06 n=1397377 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:2 23804 XUs and 35117 XVs -> 1644 XUVs
C:0 T:4 29 XUs and 20 XVs -> 0 XUVs
C:0 T:5 80026 XUs and 48498 XVs -> 1620 XUVs
C:0 T:6 11921 XUs and 16576 XVs -> 403 XUVs
3667 XUVs total
2099 collection wire objects
3667 potential space points
Neighbour search...
78839 tests to find 47302 neighbours
Iterating with no regularization...
Begin: 2.97794e+07
0 2.85593e+07
1 2.84838e+07
2 2.84722e+07
Now with regularization...
Begin: 2.64977e+07
0 2.64933e+07
17-Dec-2025 16:38:43 EST Closed output file "pdhd_prod_beam__265010_24_1_20251208T181728Z_gen_g4_IonScintPDExt.root_260261_119_1_20251210T191025Z_PDInt.root_263114_1_1_20251217T200514Z_detsim_reco1.root"
17-Dec-2025 16:38:43 EST Closed input file "temp_detsim.root"
=====================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
=====================================================================================================================================
Full event 74.3894 102.51 123.391 104.392 15.6142 10
-------------------------------------------------------------------------------------------------------------------------------------
source:RootInput(read) 0.00122361 0.00893976 0.0531069 0.00374114 0.0148752 10
reco:wclsdatahd:WireCellToolkit 48.1784 53.6844 62.2227 54.0792 4.22193 10
reco:wirefilter:WireFilter 0.0136152 0.0239532 0.03345 0.023665 0.00624439 10
reco:gaushit:GausHitFinder 0.289974 0.710925 0.975671 0.710826 0.200722 10
reco:nhitsfilter:NumberOfHitsFilter 0.000176031 0.000335675 0.000595163 0.000310903 0.000118989 10
reco:reco3d:SpacePointSolver 0.228273 0.596733 0.950564 0.627097 0.224851 10
reco:hitpdune:DisambigFromSpacePoints 0.117971 0.492997 0.981143 0.42188 0.257597 10
reco:pandora:StandardPandora 3.4446 9.09328 13.6391 8.64408 2.8509 10
reco:pandoraWriter:StandardPandora 0.107207 0.212777 0.293206 0.215098 0.060605 10
reco:pandoraTrack:LArPandoraTrackCreation 0.517499 1.09485 2.53489 0.835655 0.653494 10
reco:pandoraShower:LArPandoraShowerCreation 0.411078 1.16222 2.30883 1.09638 0.619035 10
reco:pandoracalo:Calorimetry 0.358578 0.617289 1.14024 0.571145 0.243222 10
reco:pandoracalonosce:Calorimetry 0.329246 0.580096 0.986199 0.552285 0.192954 10
reco:pandoraShowercalo:ShowerCalorimetry 0.296688 1.13145 2.02467 1.02077 0.561733 10
reco:pandoraShowercalonosce:ShowerCalorimetry 0.319292 1.04713 1.80741 0.922244 0.506101 10
reco:pandoraGnocchiCalo:GnocchiCalorimetry 0.0232536 0.0530054 0.105413 0.0502056 0.0227531 10
reco:pandoraGnocchiCalonosce:GnocchiCalorimetry 0.0223786 0.0519745 0.102719 0.0487709 0.0227921 10
reco:emtrkmichelid:EmTrackMichelId 16.5136 30.5958 41.2988 30.9014 9.1947 10
[art]:TriggerResults:TriggerResultInserter 2.7962e-05 4.96891e-05 0.000132778 4.0812e-05 2.85262e-05 10
end_path:out1:RootOutput 7.775e-06 1.36041e-05 3.8251e-05 1.06045e-05 8.3777e-06 10
end_path:out1:RootOutput(write) 0.928926 1.27611 1.70122 1.24911 0.238346 10
=====================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 5879.51 MB
Peak resident set size usage (VmHWM): 3690.99 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Reco returns 0
.:
total 12203632
-rw-r--r-- 1 dune osgvo 231410 Dec 17 16:38 jobscript.log
-rw-r--r-- 1 dune osgvo 201 Dec 17 16:38 justin-processed-pfns.txt
-rw-r--r-- 1 dune osgvo 519 Dec 17 16:38 reco_protodunehd_hist.root
-rw-r--r-- 1 dune osgvo 3574 Dec 17 16:38 Pandora_Geometry.xml
-rw-r--r-- 1 dune osgvo 139264 Dec 17 16:38 mem.db
-rw-r--r-- 1 dune osgvo 28672 Dec 17 16:38 time.db
-rw-r--r-- 1 dune osgvo 6326936996 Dec 17 16:38 pdhd_prod_beam__265010_24_1_20251208T181728Z_gen_g4_IonScintPDExt.root_260261_119_1_20251210T191025Z_PDInt.root_263114_1_1_20251217T200514Z_detsim_reco1.root
-rw-r--r-- 1 dune osgvo 35948790 Dec 17 16:37 Pandora_Events.pndr
-rw-r--r-- 1 dune osgvo 0 Dec 17 16:19 debugprod.log
-rw-r--r-- 1 dune osgvo 519 Dec 17 16:19 detsim_single_protodunehd_hist.root
-rw-r--r-- 1 dune osgvo 6133190459 Dec 17 16:19 temp_detsim.root
-rw-r--r-- 1 dune osgvo 122 Dec 17 15:05 all-input-dids.txt