Jobsub ID 243684.0@dunegpschedd01.fnal.gov
Jobscript log (last 10,000 characters)
n_mag_nf> call=18 input 0: frame: ident=99 time=0 tick=512 with 68225 traces. frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss0":32040 [0] "wiener0":36185 [36185] ] cmm:[ bad:0 lf_noisy:382 ] input 1: frame: ident=99 time=0 tick=512 with 46011 traces. frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss1":20036 [0] "wiener1":25975 [25975] ] cmm:[ bad:0 ] input 2: frame: ident=99 time=0 tick=512 with 36884 traces. frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss2":16016 [0] "wiener2":20868 [20868] ] cmm:[ bad:0 ] input 3: frame: ident=99 time=0 tick=512 with 61907 traces. frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss3":27160 [0] "wiener3":34747 [34747] ] cmm:[ bad:0 lf_noisy:1 ] output: frame: ident=99 time=0 tick=512 with 213027 traces. frame tags:[ "framefanin" ] 8 tagged trace sets:[ "gauss0":32040 [0] "gauss1":20036 [0] "gauss2":16016 [0] "gauss3":27160 [0] "wiener0":36185 [36185] "wiener1":25975 [25975] "wiener2":20868 [20868] "wiener3":34747 [34747] ] cmm:[ bad:0 lf_noisy:383 ]
Retagger: tagging trace set: wiener with 117775 traces, 117775 summary
Retagger: tagging trace set: gauss with 95252 traces, 0 summary
[15:07:24.289] D [ glue ] sink frame: #99 @0 with 213027 traces, frame tags:[retagger], trace tags:[gauss, wiener]
[15:07:24.290] D [ glue ] <FrameFanout:sn_mag_nf> call=19: see EOS
[15:07:24.290] D [ glue ] <ChannelSelector:chsel3> see EOS at call=9
[15:07:24.290] D [sigproc ] <OmnibusNoiseFilter:nf3> EOS at call=19
[15:07:24.290] D [sigproc ] <OmnibusSigProc:apa3sigproc3> EOS at call=19 anode=3
[15:07:24.290] D [ glue ] <ChannelSelector:chsel2> see EOS at call=9
[15:07:24.290] D [sigproc ] <OmnibusNoiseFilter:nf2> EOS at call=19
[15:07:24.290] D [sigproc ] <OmnibusSigProc:apa2sigproc2> EOS at call=19 anode=2
[15:07:24.290] D [ glue ] <ChannelSelector:chsel1> see EOS at call=9
[15:07:24.290] D [sigproc ] <OmnibusNoiseFilter:nf1> EOS at call=19
[15:07:24.290] D [sigproc ] <OmnibusSigProc:apa1sigproc1> EOS at call=19 anode=1
[15:07:24.290] D [ glue ] <ChannelSelector:chsel0> see EOS at call=9
[15:07:24.290] D [sigproc ] <OmnibusNoiseFilter:nf0> EOS at call=19
[15:07:24.290] D [sigproc ] <OmnibusSigProc:apa0sigproc0> EOS at call=19 anode=0
[15:07:24.290] D [ glue ] <FrameFanin:sn_mag_nf> EOS at call=19 with 4
[15:07:24.290] D [ glue ] frame sink sees EOS
[15:07:24.290] D [ pgraph ] <Pgrapher:> graph execution complete
[15:07:24.290] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 11.91 sec
[15:07:24.290] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.89 sec
[15:07:24.290] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.63 sec
[15:07:24.290] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.14 sec
[15:07:24.290] I [ timer ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 3.12 sec
[15:07:24.290] I [ timer ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 3.1 sec
[15:07:24.290] I [ timer ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 3.07 sec
[15:07:24.290] I [ timer ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.92 sec
[15:07:24.290] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0.01 sec
[15:07:24.290] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[15:07:24.290] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[15:07:24.290] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.01 sec
[15:07:24.290] I [ timer ] Timer: WireCell::Gen::Retagger : 0.01 sec
[15:07:24.290] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[15:07:24.290] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[15:07:24.290] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[15:07:24.290] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[15:07:24.290] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[15:07:24.290] I [ timer ] Timer: Total node execution : 49.83000044710934 sec
wclsFrameSaver saving cooked to 6000 ticks
wclsFrameSaver: saving 95252 traces tagged "gauss"
FrameSaver: q=3.19858e+06 n=1614561 tag=gauss
wclsFrameSaver: saving 117775 traces tagged "wiener"
FrameSaver: q=4.02255e+06 n=1561526 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:2 26613 XUs and 35949 XVs -> 2000 XUVs
C:0 T:3 2 XUs and 4 XVs -> 0 XUVs
C:0 T:4 43 XUs and 23 XVs -> 0 XUVs
C:0 T:5 22678 XUs and 24522 XVs -> 634 XUVs
C:0 T:6 64563 XUs and 64310 XVs -> 1692 XUVs
4326 XUVs total
2401 collection wire objects
4326 potential space points
Neighbour search...
121436 tests to find 69584 neighbours
Iterating with no regularization...
Begin: 4.9564e+07
0 4.58185e+07
1 4.55389e+07
2 4.55173e+07
Now with regularization...
Begin: 4.31538e+07
0 4.31458e+07
05-Nov-2025 15:08:23 CST Closed output file "pdhd_prod_beam__226699_28_1_20251009T172356Z_gen_g4_IonScintPDExt.root_227040_42_1_20251010T170005Z_PDInt.root_243684_0_1_20251105T195703Z_detsim_reco1.root"
05-Nov-2025 15:08:23 CST Closed input file "temp_detsim.root"
=====================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
=====================================================================================================================================
Full event 75.0659 91.9687 110.731 90.4756 11.9826 10
-------------------------------------------------------------------------------------------------------------------------------------
source:RootInput(read) 0.00132905 0.00424912 0.00891204 0.00409051 0.00235024 10
reco:wclsdatahd:WireCellToolkit 46.4456 50.4014 56.0207 49.837 2.93439 10
reco:wirefilter:WireFilter 0.0101126 0.0148246 0.0196891 0.0145233 0.00237838 10
reco:gaushit:GausHitFinder 0.509954 0.631324 0.845278 0.572432 0.123164 10
reco:nhitsfilter:NumberOfHitsFilter 0.00015974 0.000246098 0.000441136 0.000221951 7.74924e-05 10
reco:reco3d:SpacePointSolver 0.27336 0.832219 1.45678 0.63896 0.443218 10
reco:hitpdune:DisambigFromSpacePoints 0.233165 0.529398 1.02416 0.534998 0.252368 10
reco:pandora:StandardPandora 4.58224 9.49408 18.613 8.45548 4.4513 10
reco:pandoraWriter:StandardPandora 0.158534 0.201904 0.264302 0.196004 0.036526 10
reco:pandoraTrack:LArPandoraTrackCreation 0.446012 0.82764 1.1538 0.8704 0.255457 10
reco:pandoraShower:LArPandoraShowerCreation 0.445044 0.879298 1.38128 0.908764 0.297086 10
reco:pandoracalo:Calorimetry 0.334236 0.521948 0.664583 0.54066 0.114484 10
reco:pandoracalonosce:Calorimetry 0.323878 0.503839 0.695231 0.486815 0.121883 10
reco:pandoraShowercalo:ShowerCalorimetry 0.510289 0.892771 1.43708 0.832947 0.291737 10
reco:pandoraShowercalonosce:ShowerCalorimetry 0.495643 0.870249 1.4079 0.777575 0.293016 10
reco:pandoraGnocchiCalo:GnocchiCalorimetry 0.0310696 0.0465265 0.062709 0.0472033 0.00869771 10
reco:pandoraGnocchiCalonosce:GnocchiCalorimetry 0.0376774 0.0481109 0.0637369 0.0458381 0.00938529 10
reco:emtrkmichelid:EmTrackMichelId 16.2642 23.9685 33.0561 22.0997 5.07324 10
[art]:TriggerResults:TriggerResultInserter 2.3003e-05 3.32896e-05 8.9748e-05 2.6565e-05 1.9064e-05 10
end_path:out1:RootOutput 8.255e-06 1.26697e-05 3.1489e-05 9.508e-06 7.21423e-06 10
end_path:out1:RootOutput(write) 0.9458 1.2635 1.57327 1.30589 0.175227 10
=====================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 5942.99 MB
Peak resident set size usage (VmHWM): 3766.48 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Reco returns 0
.:
total 11823116
-rw-r--r-- 1 slot1_18 slot1_18 230748 Nov 5 15:08 jobscript.log
-rw-r--r-- 1 slot1_18 slot1_18 200 Nov 5 15:08 justin-processed-pfns.txt
-rw-r--r-- 1 slot1_18 slot1_18 519 Nov 5 15:08 reco_protodunehd_hist.root
-rw-r--r-- 1 slot1_18 slot1_18 3574 Nov 5 15:08 Pandora_Geometry.xml
-rw-r--r-- 1 slot1_18 slot1_18 139264 Nov 5 15:08 mem.db
-rw-r--r-- 1 slot1_18 slot1_18 28672 Nov 5 15:08 time.db
-rw-r--r-- 1 slot1_18 slot1_18 6134348673 Nov 5 15:08 pdhd_prod_beam__226699_28_1_20251009T172356Z_gen_g4_IonScintPDExt.root_227040_42_1_20251010T170005Z_PDInt.root_243684_0_1_20251105T195703Z_detsim_reco1.root
-rw-r--r-- 1 slot1_18 slot1_18 37679750 Nov 5 15:07 Pandora_Events.pndr
-rw-r--r-- 1 slot1_18 slot1_18 0 Nov 5 14:51 debugprod.log
-rw-r--r-- 1 slot1_18 slot1_18 519 Nov 5 14:50 detsim_single_protodunehd_hist.root
-rw-r--r-- 1 slot1_18 slot1_18 5934393953 Nov 5 14:50 temp_detsim.root
-rw-r--r-- 1 slot1_18 slot1_18 121 Nov 5 13:57 all-input-dids.txt
