Jobsub ID 236952.0@dunegpschedd02.fnal.gov
Jobscript log (last 10,000 characters)
> call=18 input 0: frame: ident=99 time=0 tick=512 with 52627 traces. frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss0":25200 [0] "wiener0":27427 [27427] ] cmm:[ bad:0 lf_noisy:73 ] input 1: frame: ident=99 time=0 tick=512 with 34911 traces. frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss1":15220 [0] "wiener1":19691 [19691] ] cmm:[ bad:0 ] input 2: frame: ident=99 time=0 tick=512 with 63565 traces. frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss2":25577 [0] "wiener2":37988 [37988] ] cmm:[ bad:0 lf_noisy:2 ] input 3: frame: ident=99 time=0 tick=512 with 49084 traces. frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss3":20561 [0] "wiener3":28523 [28523] ] cmm:[ bad:0 ] output: frame: ident=99 time=0 tick=512 with 200187 traces. frame tags:[ "framefanin" ] 8 tagged trace sets:[ "gauss0":25200 [0] "gauss1":15220 [0] "gauss2":25577 [0] "gauss3":20561 [0] "wiener0":27427 [27427] "wiener1":19691 [19691] "wiener2":37988 [37988] "wiener3":28523 [28523] ] cmm:[ bad:0 lf_noisy:75 ]
Retagger: tagging trace set: wiener with 113629 traces, 113629 summary
Retagger: tagging trace set: gauss with 86558 traces, 0 summary
[20:02:49.989] D [ glue ] sink frame: #99 @0 with 200187 traces, frame tags:[retagger], trace tags:[gauss, wiener]
[20:02:49.989] D [ glue ] <FrameFanout:sn_mag_nf> call=19: see EOS
[20:02:49.989] D [ glue ] <ChannelSelector:chsel3> see EOS at call=9
[20:02:49.989] D [sigproc ] <OmnibusNoiseFilter:nf3> EOS at call=19
[20:02:49.989] D [sigproc ] <OmnibusSigProc:apa3sigproc3> EOS at call=19 anode=3
[20:02:49.989] D [ glue ] <ChannelSelector:chsel2> see EOS at call=9
[20:02:49.989] D [sigproc ] <OmnibusNoiseFilter:nf2> EOS at call=19
[20:02:49.989] D [sigproc ] <OmnibusSigProc:apa2sigproc2> EOS at call=19 anode=2
[20:02:49.989] D [ glue ] <ChannelSelector:chsel1> see EOS at call=9
[20:02:49.989] D [sigproc ] <OmnibusNoiseFilter:nf1> EOS at call=19
[20:02:49.989] D [sigproc ] <OmnibusSigProc:apa1sigproc1> EOS at call=19 anode=1
[20:02:49.989] D [ glue ] <ChannelSelector:chsel0> see EOS at call=9
[20:02:49.989] D [sigproc ] <OmnibusNoiseFilter:nf0> EOS at call=19
[20:02:49.989] D [sigproc ] <OmnibusSigProc:apa0sigproc0> EOS at call=19 anode=0
[20:02:49.989] D [ glue ] <FrameFanin:sn_mag_nf> EOS at call=19 with 4
[20:02:49.989] D [ glue ] frame sink sees EOS
[20:02:49.989] D [ pgraph ] <Pgrapher:> graph execution complete
[20:02:49.989] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 14.77 sec
[20:02:49.989] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 11.22 sec
[20:02:49.989] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 10.57 sec
[20:02:49.989] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 10.2 sec
[20:02:49.989] I [ timer ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 3.49 sec
[20:02:49.989] I [ timer ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 3.49 sec
[20:02:49.989] I [ timer ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 3.08 sec
[20:02:49.989] I [ timer ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.68 sec
[20:02:49.989] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.02 sec
[20:02:49.989] I [ timer ] Timer: WireCell::Gen::Retagger : 0.01 sec
[20:02:49.989] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[20:02:49.989] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[20:02:49.989] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0 sec
[20:02:49.989] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[20:02:49.989] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[20:02:49.989] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[20:02:49.989] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[20:02:49.989] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[20:02:49.989] I [ timer ] Timer: Total node execution : 59.54000023752451 sec
wclsFrameSaver saving cooked to 6000 ticks
wclsFrameSaver: saving 86558 traces tagged "gauss"
FrameSaver: q=2.9671e+06 n=1363010 tag=gauss
wclsFrameSaver: saving 113629 traces tagged "wiener"
FrameSaver: q=3.92961e+06 n=1291133 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:2 9733 XUs and 21712 XVs -> 740 XUVs
C:0 T:3 7 XUs and 16 XVs -> 2 XUVs
C:0 T:4 11 XUs and 20 XVs -> 3 XUVs
C:0 T:5 47031 XUs and 73428 XVs -> 3337 XUVs
C:0 T:6 34033 XUs and 52107 XVs -> 1330 XUVs
C:0 T:7 14 XUs and 21 XVs -> 0 XUVs
5412 XUVs total
2201 collection wire objects
5412 potential space points
Neighbour search...
201746 tests to find 121814 neighbours
Iterating with no regularization...
Begin: 2.80589e+07
0 2.55275e+07
1 2.5359e+07
2 2.5336e+07
Now with regularization...
Begin: 2.31367e+07
0 2.31279e+07
03-Nov-2025 20:03:52 CST Closed output file "pdhd_prod_beam__231902_28_1_20251008T212507Z_gen_g4_IonScintPDExt.root_227040_170_1_20251010T172309Z_PDInt.root_236952_0_1_20251103T205359Z_detsim_reco1.root"
03-Nov-2025 20:03:52 CST Closed input file "temp_detsim.root"
=====================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
=====================================================================================================================================
Full event 106.789 122 145.989 117.804 12.9695 10
-------------------------------------------------------------------------------------------------------------------------------------
source:RootInput(read) 0.00123388 0.0138005 0.0212164 0.0164709 0.00667414 10
reco:wclsdatahd:WireCellToolkit 62.3551 65.5306 69.8877 64.7747 2.49224 10
reco:wirefilter:WireFilter 0.0155659 0.0261784 0.0391658 0.0240716 0.00690576 10
reco:gaushit:GausHitFinder 0.548907 0.845379 1.16157 0.826285 0.168588 10
reco:nhitsfilter:NumberOfHitsFilter 0.000234142 0.000345841 0.000563305 0.000325279 9.49371e-05 10
reco:reco3d:SpacePointSolver 0.436921 0.735288 1.51469 0.554726 0.336486 10
reco:hitpdune:DisambigFromSpacePoints 0.330212 0.623016 1.13216 0.5483 0.255711 10
reco:pandora:StandardPandora 6.57832 11.4262 19.6313 10.768 3.99545 10
reco:pandoraWriter:StandardPandora 0.2278 0.309563 0.390461 0.31058 0.0490531 10
reco:pandoraTrack:LArPandoraTrackCreation 0.684431 1.2892 2.19392 1.09845 0.477112 10
reco:pandoraShower:LArPandoraShowerCreation 0.730769 1.26584 2.07915 1.15136 0.469388 10
reco:pandoracalo:Calorimetry 0.394318 0.761147 1.41265 0.671327 0.286801 10
reco:pandoracalonosce:Calorimetry 0.376525 0.712121 1.15229 0.655024 0.236542 10
reco:pandoraShowercalo:ShowerCalorimetry 0.693981 1.26343 1.89039 1.18192 0.411867 10
reco:pandoraShowercalonosce:ShowerCalorimetry 0.527136 1.19059 1.88215 1.17826 0.402056 10
reco:pandoraGnocchiCalo:GnocchiCalorimetry 0.035336 0.0698894 0.0983228 0.074127 0.0221535 10
reco:pandoraGnocchiCalonosce:GnocchiCalorimetry 0.0354949 0.0709142 0.096765 0.074429 0.020862 10
reco:emtrkmichelid:EmTrackMichelId 27.2222 33.9667 45.6136 33.8572 5.79171 10
[art]:TriggerResults:TriggerResultInserter 4.1428e-05 6.25651e-05 0.000120908 5.7519e-05 2.22707e-05 10
end_path:out1:RootOutput 1.0971e-05 1.65493e-05 3.7902e-05 1.44725e-05 7.55699e-06 10
end_path:out1:RootOutput(write) 1.61621 1.83479 2.26306 1.74227 0.216688 10
=====================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 5751.68 MB
Peak resident set size usage (VmHWM): 3569.17 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Reco returns 0
.:
total 12086656
-rw-r--r-- 1 slot1_7 slot1_7 230712 Nov 3 20:03 jobscript.log
-rw-r--r-- 1 slot1_7 slot1_7 201 Nov 3 20:03 justin-processed-pfns.txt
-rw-r--r-- 1 slot1_7 slot1_7 519 Nov 3 20:03 reco_protodunehd_hist.root
-rw-r--r-- 1 slot1_7 slot1_7 3574 Nov 3 20:03 Pandora_Geometry.xml
-rw-r--r-- 1 slot1_7 slot1_7 139264 Nov 3 20:03 mem.db
-rw-r--r-- 1 slot1_7 slot1_7 28672 Nov 3 20:03 time.db
-rw-r--r-- 1 slot1_7 slot1_7 6270680247 Nov 3 20:03 pdhd_prod_beam__231902_28_1_20251008T212507Z_gen_g4_IonScintPDExt.root_227040_170_1_20251010T172309Z_PDInt.root_236952_0_1_20251103T205359Z_detsim_reco1.root
-rw-r--r-- 1 slot1_7 slot1_7 38125250 Nov 3 20:03 Pandora_Events.pndr
-rw-r--r-- 1 slot1_7 slot1_7 0 Nov 3 19:41 debugprod.log
-rw-r--r-- 1 slot1_7 slot1_7 519 Nov 3 19:40 detsim_single_protodunehd_hist.root
-rw-r--r-- 1 slot1_7 slot1_7 6067485402 Nov 3 19:40 temp_detsim.root
-rw-r--r-- 1 slot1_7 slot1_7 122 Nov 3 14:53 all-input-dids.txt