Jobsub ID 268763.12@dunegpschedd01.fnal.gov
Jobscript log (last 10,000 characters)
10:13.805] D [ glue ] <FrameFanin:sn_mag_nf> call=18 input 0: frame: ident=199 time=0 tick=512 with 52861 traces. frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss0":24762 [0] "wiener0":28099 [28099] ] cmm:[ bad:0 lf_noisy:280 ] input 1: frame: ident=199 time=0 tick=512 with 57766 traces. frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss1":23641 [0] "wiener1":34125 [34125] ] cmm:[ bad:0 ] input 2: frame: ident=199 time=0 tick=512 with 34763 traces. frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss2":15246 [0] "wiener2":19517 [19517] ] cmm:[ bad:0 ] input 3: frame: ident=199 time=0 tick=512 with 49850 traces. frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss3":20908 [0] "wiener3":28942 [28942] ] cmm:[ bad:0 ] output: frame: ident=199 time=0 tick=512 with 195240 traces. frame tags:[ "framefanin" ] 8 tagged trace sets:[ "gauss0":24762 [0] "gauss1":23641 [0] "gauss2":15246 [0] "gauss3":20908 [0] "wiener0":28099 [28099] "wiener1":34125 [34125] "wiener2":19517 [19517] "wiener3":28942 [28942] ] cmm:[ bad:0 lf_noisy:280 ]
Retagger: tagging trace set: wiener with 110683 traces, 110683 summary
Retagger: tagging trace set: gauss with 84557 traces, 0 summary
[04:10:13.820] D [ glue ] sink frame: #199 @0 with 195240 traces, frame tags:[retagger], trace tags:[gauss, wiener]
[04:10:13.820] D [ glue ] <FrameFanout:sn_mag_nf> call=19: see EOS
[04:10:13.820] D [ glue ] <ChannelSelector:chsel3> see EOS at call=9
[04:10:13.820] D [sigproc ] <OmnibusNoiseFilter:nf3> EOS at call=19
[04:10:13.820] D [sigproc ] <OmnibusSigProc:apa3sigproc3> EOS at call=19 anode=3
[04:10:13.820] D [ glue ] <ChannelSelector:chsel2> see EOS at call=9
[04:10:13.820] D [sigproc ] <OmnibusNoiseFilter:nf2> EOS at call=19
[04:10:13.820] D [sigproc ] <OmnibusSigProc:apa2sigproc2> EOS at call=19 anode=2
[04:10:13.820] D [ glue ] <ChannelSelector:chsel1> see EOS at call=9
[04:10:13.820] D [sigproc ] <OmnibusNoiseFilter:nf1> EOS at call=19
[04:10:13.821] D [sigproc ] <OmnibusSigProc:apa1sigproc1> EOS at call=19 anode=1
[04:10:13.821] D [ glue ] <ChannelSelector:chsel0> see EOS at call=9
[04:10:13.821] D [sigproc ] <OmnibusNoiseFilter:nf0> EOS at call=19
[04:10:13.821] D [sigproc ] <OmnibusSigProc:apa0sigproc0> EOS at call=19 anode=0
[04:10:13.821] D [ glue ] <FrameFanin:sn_mag_nf> EOS at call=19 with 4
[04:10:13.821] D [ glue ] frame sink sees EOS
[04:10:13.821] D [ pgraph ] <Pgrapher:> graph execution complete
[04:10:13.821] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 12.96 sec
[04:10:13.821] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 9.75 sec
[04:10:13.821] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 9.56 sec
[04:10:13.821] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 9.48 sec
[04:10:13.821] I [ timer ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 4.33 sec
[04:10:13.821] I [ timer ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 3.19 sec
[04:10:13.821] I [ timer ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 3.19 sec
[04:10:13.821] I [ timer ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 3.15 sec
[04:10:13.821] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.02 sec
[04:10:13.821] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[04:10:13.821] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[04:10:13.821] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0 sec
[04:10:13.821] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[04:10:13.821] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[04:10:13.821] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[04:10:13.821] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[04:10:13.821] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[04:10:13.821] I [ timer ] Timer: WireCell::Gen::Retagger : 0 sec
[04:10:13.821] I [ timer ] Timer: Total node execution : 55.64000013284385 sec
wclsFrameSaver saving cooked to 6000 ticks
wclsFrameSaver: saving 84557 traces tagged "gauss"
FrameSaver: q=2.93402e+06 n=1388340 tag=gauss
wclsFrameSaver: saving 110683 traces tagged "wiener"
FrameSaver: q=3.56613e+06 n=1323362 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:2 57414 XUs and 54307 XVs -> 1656 XUVs
C:0 T:3 32 XUs and 28 XVs -> 4 XUVs
C:0 T:4 7 XUs and 11 XVs -> 2 XUVs
C:0 T:5 18275 XUs and 22152 XVs -> 682 XUVs
C:0 T:6 35640 XUs and 53911 XVs -> 1852 XUVs
C:0 T:7 10 XUs and 23 XVs -> 0 XUVs
4196 XUVs total
2393 collection wire objects
4196 potential space points
Neighbour search...
94270 tests to find 55866 neighbours
Iterating with no regularization...
Begin: 3.8687e+07
0 3.64157e+07
1 3.6279e+07
2 3.62691e+07
Now with regularization...
Begin: 3.39558e+07
0 3.39522e+07
17-Dec-2025 04:11:21 PST Closed output file "pdhd_prod_beam__261613_113_1_20251212T161722Z_gen_g4_IonScintPDExt.root_262728_44_1_20251215T215841Z_PDInt.root_268763_12_1_20251217T010046Z_detsim_reco1.root"
17-Dec-2025 04:11:21 PST Closed input file "temp_detsim.root"
=====================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
=====================================================================================================================================
Full event 88.5769 110.604 126.363 114.598 12.1802 10
-------------------------------------------------------------------------------------------------------------------------------------
source:RootInput(read) 0.00137011 0.00421148 0.00599503 0.00434241 0.00144892 10
reco:wclsdatahd:WireCellToolkit 54.6834 58.7062 64.098 59.4892 2.585 10
reco:wirefilter:WireFilter 0.0163818 0.0199522 0.0252929 0.0189206 0.0031682 10
reco:gaushit:GausHitFinder 0.574824 0.684875 0.825355 0.688546 0.077718 10
reco:nhitsfilter:NumberOfHitsFilter 0.000201834 0.000292493 0.000516241 0.00027738 8.9051e-05 10
reco:reco3d:SpacePointSolver 0.288042 0.591103 1.52376 0.508211 0.341146 10
reco:hitpdune:DisambigFromSpacePoints 0.282214 0.523714 0.968681 0.485177 0.207555 10
reco:pandora:StandardPandora 5.77837 10.4088 14.4965 10.393 2.94087 10
reco:pandoraWriter:StandardPandora 0.15476 0.250676 0.350045 0.240469 0.0604729 10
reco:pandoraTrack:LArPandoraTrackCreation 0.657009 1.19641 1.77487 1.19303 0.299153 10
reco:pandoraShower:LArPandoraShowerCreation 0.661134 1.2386 1.96638 1.24386 0.394215 10
reco:pandoracalo:Calorimetry 0.388781 0.707759 1.17816 0.667567 0.214922 10
reco:pandoracalonosce:Calorimetry 0.361523 0.705773 1.27401 0.665154 0.240155 10
reco:pandoraShowercalo:ShowerCalorimetry 0.65836 1.24395 2.22939 1.32048 0.44369 10
reco:pandoraShowercalonosce:ShowerCalorimetry 0.653912 1.24517 2.27954 1.32959 0.461487 10
reco:pandoraGnocchiCalo:GnocchiCalorimetry 0.0447058 0.075165 0.118435 0.0712429 0.0214443 10
reco:pandoraGnocchiCalonosce:GnocchiCalorimetry 0.045142 0.0751259 0.118811 0.0714685 0.0213394 10
reco:emtrkmichelid:EmTrackMichelId 19.4844 31.1061 40.0894 32.4024 6.64688 10
[art]:TriggerResults:TriggerResultInserter 1.874e-05 4.34868e-05 0.000123423 3.6825e-05 2.75332e-05 10
end_path:out1:RootOutput 9.451e-06 1.53546e-05 3.6971e-05 1.22055e-05 8.21726e-06 10
end_path:out1:RootOutput(write) 1.14294 1.76164 2.2508 1.81702 0.416662 10
=====================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 5989 MB
Peak resident set size usage (VmHWM): 3762.04 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Reco returns 0
.:
total 12692528
-rw-r--r--. 1 cuser cuser 231597 Dec 17 04:11 jobscript.log
-rw-r--r--. 1 cuser cuser 201 Dec 17 04:11 justin-processed-pfns.txt
-rw-r--r--. 1 cuser cuser 519 Dec 17 04:11 reco_protodunehd_hist.root
-rw-r--r--. 1 cuser cuser 3574 Dec 17 04:11 Pandora_Geometry.xml
-rw-r--r--. 1 cuser cuser 139264 Dec 17 04:11 mem.db
-rw-r--r--. 1 cuser cuser 28672 Dec 17 04:11 time.db
-rw-r--r--. 1 cuser cuser 6579600051 Dec 17 04:11 pdhd_prod_beam__261613_113_1_20251212T161722Z_gen_g4_IonScintPDExt.root_262728_44_1_20251215T215841Z_PDInt.root_268763_12_1_20251217T010046Z_detsim_reco1.root
-rw-r--r--. 1 cuser cuser 36847820 Dec 17 04:10 Pandora_Events.pndr
-rw-r--r--. 1 cuser cuser 0 Dec 17 03:50 debugprod.log
-rw-r--r--. 1 cuser cuser 519 Dec 17 03:50 detsim_single_protodunehd_hist.root
-rw-r--r--. 1 cuser cuser 6380239403 Dec 17 03:50 temp_detsim.root
-rw-r--r--. 1 cuser cuser 122 Dec 16 17:00 all-input-dids.txt
