Jobsub ID 236970.0@dunegpschedd02.fnal.gov
Jobscript log (last 10,000 characters)
eFanin:sn_mag_nf> call=18 input 0: frame: ident=99 time=0 tick=512 with 72855 traces. frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss0":34303 [0] "wiener0":38552 [38552] ] cmm:[ bad:0 lf_noisy:168 ] input 1: frame: ident=99 time=0 tick=512 with 24373 traces. frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss1":11036 [0] "wiener1":13337 [13337] ] cmm:[ bad:0 ] input 2: frame: ident=99 time=0 tick=512 with 57099 traces. frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss2":24034 [0] "wiener2":33065 [33065] ] cmm:[ bad:0 ] input 3: frame: ident=99 time=0 tick=512 with 42143 traces. frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss3":18092 [0] "wiener3":24051 [24051] ] cmm:[ bad:0 ] output: frame: ident=99 time=0 tick=512 with 196470 traces. frame tags:[ "framefanin" ] 8 tagged trace sets:[ "gauss0":34303 [0] "gauss1":11036 [0] "gauss2":24034 [0] "gauss3":18092 [0] "wiener0":38552 [38552] "wiener1":13337 [13337] "wiener2":33065 [33065] "wiener3":24051 [24051] ] cmm:[ bad:0 lf_noisy:168 ]
Retagger: tagging trace set: wiener with 109005 traces, 109005 summary
Retagger: tagging trace set: gauss with 87465 traces, 0 summary
[16:46:15.829] D [ glue ] sink frame: #99 @0 with 196470 traces, frame tags:[retagger], trace tags:[gauss, wiener]
[16:46:15.830] D [ glue ] <FrameFanout:sn_mag_nf> call=19: see EOS
[16:46:15.831] D [ glue ] <ChannelSelector:chsel3> see EOS at call=9
[16:46:15.831] D [sigproc ] <OmnibusNoiseFilter:nf3> EOS at call=19
[16:46:15.831] D [sigproc ] <OmnibusSigProc:apa3sigproc3> EOS at call=19 anode=3
[16:46:15.831] D [ glue ] <ChannelSelector:chsel2> see EOS at call=9
[16:46:15.831] D [sigproc ] <OmnibusNoiseFilter:nf2> EOS at call=19
[16:46:15.831] D [sigproc ] <OmnibusSigProc:apa2sigproc2> EOS at call=19 anode=2
[16:46:15.831] D [ glue ] <ChannelSelector:chsel1> see EOS at call=9
[16:46:15.831] D [sigproc ] <OmnibusNoiseFilter:nf1> EOS at call=19
[16:46:15.831] D [sigproc ] <OmnibusSigProc:apa1sigproc1> EOS at call=19 anode=1
[16:46:15.831] D [ glue ] <ChannelSelector:chsel0> see EOS at call=9
[16:46:15.831] D [sigproc ] <OmnibusNoiseFilter:nf0> EOS at call=19
[16:46:15.831] D [sigproc ] <OmnibusSigProc:apa0sigproc0> EOS at call=19 anode=0
[16:46:15.831] D [ glue ] <FrameFanin:sn_mag_nf> EOS at call=19 with 4
[16:46:15.831] D [ glue ] frame sink sees EOS
[16:46:15.831] D [ pgraph ] <Pgrapher:> graph execution complete
[16:46:15.831] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 12.21 sec
[16:46:15.831] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 8.47 sec
[16:46:15.831] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.93 sec
[16:46:15.831] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.79 sec
[16:46:15.831] I [ timer ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.85 sec
[16:46:15.831] I [ timer ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.65 sec
[16:46:15.831] I [ timer ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.47 sec
[16:46:15.831] I [ timer ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.47 sec
[16:46:15.831] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.02 sec
[16:46:15.831] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[16:46:15.831] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[16:46:15.831] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[16:46:15.831] I [ timer ] Timer: WireCell::Gen::Retagger : 0.01 sec
[16:46:15.831] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[16:46:15.831] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0 sec
[16:46:15.831] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[16:46:15.831] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[16:46:15.831] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[16:46:15.831] I [ timer ] Timer: Total node execution : 46.900000151246786 sec
wclsFrameSaver saving cooked to 6000 ticks
wclsFrameSaver: saving 87465 traces tagged "gauss"
FrameSaver: q=2.73342e+06 n=1341285 tag=gauss
wclsFrameSaver: saving 109005 traces tagged "wiener"
FrameSaver: q=3.59414e+06 n=1298137 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:2 10092 XUs and 5051 XVs -> 521 XUVs
C:0 T:4 65 XUs and 32 XVs -> 1 XUVs
C:0 T:5 88455 XUs and 59949 XVs -> 1969 XUVs
C:0 T:6 20020 XUs and 20947 XVs -> 397 XUVs
C:0 T:7 0 XUs and 0 XVs -> 0 XUVs
2888 XUVs total
1258 collection wire objects
2888 potential space points
Neighbour search...
115764 tests to find 73426 neighbours
Iterating with no regularization...
Begin: 2.15804e+07
0 2.03722e+07
1 2.02813e+07
2 2.02689e+07
Now with regularization...
Begin: 1.89713e+07
0 1.89664e+07
03-Nov-2025 16:46:50 CST Closed output file "pdhd_prod_beam__226470_24_1_20251008T212457Z_gen_g4_IonScintPDExt.root_227040_153_1_20251010T171732Z_PDInt.root_236970_0_1_20251103T212706Z_detsim_reco1.root"
03-Nov-2025 16:46:50 CST Closed input file "temp_detsim.root"
=====================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
=====================================================================================================================================
Full event 71.4748 87.9179 104.336 89.1796 10.1522 10
-------------------------------------------------------------------------------------------------------------------------------------
source:RootInput(read) 0.000879419 0.00477184 0.0120654 0.00369182 0.0031129 10
reco:wclsdatahd:WireCellToolkit 46.772 48.9865 54.3767 48.2814 2.23949 10
reco:wirefilter:WireFilter 0.012051 0.0199617 0.027623 0.0205581 0.00451218 10
reco:gaushit:GausHitFinder 0.352977 0.530431 0.755092 0.516127 0.108961 10
reco:nhitsfilter:NumberOfHitsFilter 0.000172375 0.000336166 0.000454707 0.000350336 8.50981e-05 10
reco:reco3d:SpacePointSolver 0.189679 0.731354 2.02938 0.496739 0.551189 10
reco:hitpdune:DisambigFromSpacePoints 0.152898 0.418636 0.850584 0.368404 0.207867 10
reco:pandora:StandardPandora 4.52562 7.98471 12.8116 7.75497 2.87413 10
reco:pandoraWriter:StandardPandora 0.202718 0.309673 0.446039 0.285765 0.0858419 10
reco:pandoraTrack:LArPandoraTrackCreation 0.434634 0.986146 1.53397 0.95415 0.372724 10
reco:pandoraShower:LArPandoraShowerCreation 0.419831 0.829255 1.42825 0.764965 0.323228 10
reco:pandoracalo:Calorimetry 0.249595 0.538259 0.695036 0.585784 0.14442 10
reco:pandoracalonosce:Calorimetry 0.2408 0.517548 0.665311 0.587148 0.143609 10
reco:pandoraShowercalo:ShowerCalorimetry 0.357108 0.820264 1.50834 0.73124 0.345194 10
reco:pandoraShowercalonosce:ShowerCalorimetry 0.35057 0.836582 1.56085 0.753567 0.378979 10
reco:pandoraGnocchiCalo:GnocchiCalorimetry 0.0286768 0.0526022 0.0791808 0.0484845 0.0154412 10
reco:pandoraGnocchiCalonosce:GnocchiCalorimetry 0.0270511 0.0503474 0.0810252 0.0500659 0.0167542 10
reco:emtrkmichelid:EmTrackMichelId 15.7504 22.7529 30.6006 22.5242 4.3615 10
[art]:TriggerResults:TriggerResultInserter 2.3364e-05 4.09653e-05 0.000130586 2.9005e-05 3.10415e-05 10
end_path:out1:RootOutput 7.675e-06 2.11178e-05 9.7313e-05 9.2425e-06 2.71091e-05 10
end_path:out1:RootOutput(write) 1.03456 1.46644 2.15625 1.40624 0.323947 10
=====================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 6350.13 MB
Peak resident set size usage (VmHWM): 4140.47 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Reco returns 0
.:
total 12114384
-rw-r--r-- 1 slot1_55 slot1_55 230697 Nov 3 16:46 jobscript.log
-rw-r--r-- 1 slot1_55 slot1_55 195 Nov 3 16:46 justin-processed-pfns.txt
-rw-r--r-- 1 slot1_55 slot1_55 519 Nov 3 16:46 reco_protodunehd_hist.root
-rw-r--r-- 1 slot1_55 slot1_55 3574 Nov 3 16:46 Pandora_Geometry.xml
-rw-r--r-- 1 slot1_55 slot1_55 139264 Nov 3 16:46 mem.db
-rw-r--r-- 1 slot1_55 slot1_55 28672 Nov 3 16:46 time.db
-rw-r--r-- 1 slot1_55 slot1_55 6283620524 Nov 3 16:46 pdhd_prod_beam__226470_24_1_20251008T212457Z_gen_g4_IonScintPDExt.root_227040_153_1_20251010T171732Z_PDInt.root_236970_0_1_20251103T212706Z_detsim_reco1.root
-rw-r--r-- 1 slot1_55 slot1_55 37647740 Nov 3 16:46 Pandora_Events.pndr
-rw-r--r-- 1 slot1_55 slot1_55 0 Nov 3 16:29 debugprod.log
-rw-r--r-- 1 slot1_55 slot1_55 519 Nov 3 16:29 detsim_single_protodunehd_hist.root
-rw-r--r-- 1 slot1_55 slot1_55 6083387372 Nov 3 16:29 temp_detsim.root
-rw-r--r-- 1 slot1_55 slot1_55 122 Nov 3 15:27 all-input-dids.txt
