Jobsub ID 269119.22@dunegpschedd01.fnal.gov
Jobscript log (last 10,000 characters)
gproc" ] 2 tagged trace sets:[ "gauss0":25774 [0] "wiener0":28178 [28178] ] cmm:[ bad:0 lf_noisy:189 ]
[13:37:58.435] D [ glue ] <FrameFanin:sn_mag_nf> call=18 input 0: frame: ident=179 time=0 tick=512 with 53952 traces. frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss0":25774 [0] "wiener0":28178 [28178] ] cmm:[ bad:0 lf_noisy:189 ] input 1: frame: ident=179 time=0 tick=512 with 30761 traces. frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss1":13836 [0] "wiener1":16925 [16925] ] cmm:[ bad:0 ] input 2: frame: ident=179 time=0 tick=512 with 32108 traces. frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss2":14618 [0] "wiener2":17490 [17490] ] cmm:[ bad:0 ] input 3: frame: ident=179 time=0 tick=512 with 50689 traces. frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss3":21433 [0] "wiener3":29256 [29256] ] cmm:[ bad:0 ] output: frame: ident=179 time=0 tick=512 with 167510 traces. frame tags:[ "framefanin" ] 8 tagged trace sets:[ "gauss0":25774 [0] "gauss1":13836 [0] "gauss2":14618 [0] "gauss3":21433 [0] "wiener0":28178 [28178] "wiener1":16925 [16925] "wiener2":17490 [17490] "wiener3":29256 [29256] ] cmm:[ bad:0 lf_noisy:189 ]
Retagger: tagging trace set: wiener with 91849 traces, 91849 summary
Retagger: tagging trace set: gauss with 75661 traces, 0 summary
[13:37:58.442] D [ glue ] sink frame: #179 @0 with 167510 traces, frame tags:[retagger], trace tags:[gauss, wiener]
[13:37:58.442] D [ glue ] <FrameFanout:sn_mag_nf> call=19: see EOS
[13:37:58.443] D [ glue ] <ChannelSelector:chsel3> see EOS at call=9
[13:37:58.443] D [sigproc ] <OmnibusNoiseFilter:nf3> EOS at call=19
[13:37:58.443] D [sigproc ] <OmnibusSigProc:apa3sigproc3> EOS at call=19 anode=3
[13:37:58.443] D [ glue ] <ChannelSelector:chsel2> see EOS at call=9
[13:37:58.443] D [sigproc ] <OmnibusNoiseFilter:nf2> EOS at call=19
[13:37:58.443] D [sigproc ] <OmnibusSigProc:apa2sigproc2> EOS at call=19 anode=2
[13:37:58.443] D [ glue ] <ChannelSelector:chsel1> see EOS at call=9
[13:37:58.443] D [sigproc ] <OmnibusNoiseFilter:nf1> EOS at call=19
[13:37:58.443] D [sigproc ] <OmnibusSigProc:apa1sigproc1> EOS at call=19 anode=1
[13:37:58.443] D [ glue ] <ChannelSelector:chsel0> see EOS at call=9
[13:37:58.443] D [sigproc ] <OmnibusNoiseFilter:nf0> EOS at call=19
[13:37:58.443] D [sigproc ] <OmnibusSigProc:apa0sigproc0> EOS at call=19 anode=0
[13:37:58.443] D [ glue ] <FrameFanin:sn_mag_nf> EOS at call=19 with 4
[13:37:58.443] D [ glue ] frame sink sees EOS
[13:37:58.443] D [ pgraph ] <Pgrapher:> graph execution complete
[13:37:58.443] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 11.39 sec
[13:37:58.443] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.17 sec
[13:37:58.443] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 7.17 sec
[13:37:58.443] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 6.97 sec
[13:37:58.443] I [ timer ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 3.29 sec
[13:37:58.443] I [ timer ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 3.14 sec
[13:37:58.443] I [ timer ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.61 sec
[13:37:58.443] I [ timer ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.54 sec
[13:37:58.443] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[13:37:58.443] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.01 sec
[13:37:58.443] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[13:37:58.443] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[13:37:58.443] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[13:37:58.443] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0 sec
[13:37:58.443] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[13:37:58.443] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[13:37:58.443] I [ timer ] Timer: WireCell::Gen::Retagger : 0 sec
[13:37:58.443] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[13:37:58.443] I [ timer ] Timer: Total node execution : 44.300000209361315 sec
wclsFrameSaver saving cooked to 6000 ticks
wclsFrameSaver: saving 75661 traces tagged "gauss"
FrameSaver: q=2.39423e+06 n=1201517 tag=gauss
wclsFrameSaver: saving 91849 traces tagged "wiener"
FrameSaver: q=3.11546e+06 n=1175432 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:2 7876 XUs and 17854 XVs -> 214 XUVs
C:0 T:5 14460 XUs and 11070 XVs -> 486 XUVs
C:0 T:6 41665 XUs and 46533 XVs -> 2094 XUVs
2794 XUVs total
1469 collection wire objects
2794 potential space points
Neighbour search...
51520 tests to find 27522 neighbours
Iterating with no regularization...
Begin: 2.78909e+07
0 2.60509e+07
1 2.59036e+07
2 2.58915e+07
Now with regularization...
Begin: 2.37761e+07
0 2.37733e+07
18-Dec-2025 13:38:31 PST Closed output file "pdhd_prod_beam__261612_11_1_20251212T155442Z_gen_g4_IonScintPDExt.root_268535_11_1_20251215T214344Z_PDInt.root_269119_22_1_20251218T193135Z_detsim_reco1.root"
18-Dec-2025 13:38:31 PST Closed input file "temp_detsim.root"
=====================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
=====================================================================================================================================
Full event 63.9443 74.2443 88.4066 75.215 8.79064 10
-------------------------------------------------------------------------------------------------------------------------------------
source:RootInput(read) 0.00123688 0.00277729 0.00404192 0.0027056 0.0010769 10
reco:wclsdatahd:WireCellToolkit 40.4846 43.9035 48.5453 43.3487 2.86036 10
reco:wirefilter:WireFilter 0.0107843 0.0129381 0.0147192 0.0130465 0.00133058 10
reco:gaushit:GausHitFinder 0.317184 0.463088 0.757425 0.450604 0.12356 10
reco:nhitsfilter:NumberOfHitsFilter 0.000124338 0.000198691 0.000334176 0.000191868 6.16683e-05 10
reco:reco3d:SpacePointSolver 0.150491 0.325193 0.78154 0.240183 0.193957 10
reco:hitpdune:DisambigFromSpacePoints 0.11738 0.300869 0.567033 0.288942 0.128534 10
reco:pandora:StandardPandora 3.1656 5.94734 9.38554 6.31875 2.00998 10
reco:pandoraWriter:StandardPandora 0.0981259 0.149535 0.234319 0.1355 0.0451908 10
reco:pandoraTrack:LArPandoraTrackCreation 0.350604 0.54649 0.913801 0.49718 0.178319 10
reco:pandoraShower:LArPandoraShowerCreation 0.261066 0.55824 0.781625 0.565298 0.169717 10
reco:pandoracalo:Calorimetry 0.207696 0.35065 0.53391 0.341002 0.0903316 10
reco:pandoracalonosce:Calorimetry 0.198483 0.346313 0.52391 0.354286 0.0921927 10
reco:pandoraShowercalo:ShowerCalorimetry 0.248462 0.622524 1.10564 0.607214 0.240903 10
reco:pandoraShowercalonosce:ShowerCalorimetry 0.245666 0.635595 1.07556 0.62989 0.249004 10
reco:pandoraGnocchiCalo:GnocchiCalorimetry 0.0243344 0.0421572 0.0698523 0.0351063 0.0157693 10
reco:pandoraGnocchiCalonosce:GnocchiCalorimetry 0.0244729 0.0417544 0.0687239 0.034903 0.0154785 10
reco:emtrkmichelid:EmTrackMichelId 13.3617 18.8861 24.5346 19.2436 3.29494 10
[art]:TriggerResults:TriggerResultInserter 1.994e-05 4.32435e-05 8.4209e-05 3.50895e-05 2.17492e-05 10
end_path:out1:RootOutput 7.38e-06 1.13506e-05 2.975e-05 9.6645e-06 6.29517e-06 10
end_path:out1:RootOutput(write) 0.727856 1.07312 1.50384 1.04498 0.253568 10
=====================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 5776.89 MB
Peak resident set size usage (VmHWM): 3524.65 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Reco returns 0
.:
total 10875284
-rw-r--r--. 1 cuser cuser 231211 Dec 18 13:38 jobscript.log
-rw-r--r--. 1 cuser cuser 200 Dec 18 13:38 justin-processed-pfns.txt
-rw-r--r--. 1 cuser cuser 519 Dec 18 13:38 reco_protodunehd_hist.root
-rw-r--r--. 1 cuser cuser 3574 Dec 18 13:38 Pandora_Geometry.xml
-rw-r--r--. 1 cuser cuser 139264 Dec 18 13:38 mem.db
-rw-r--r--. 1 cuser cuser 28672 Dec 18 13:38 time.db
-rw-r--r--. 1 cuser cuser 5643432729 Dec 18 13:38 pdhd_prod_beam__261612_11_1_20251212T155442Z_gen_g4_IonScintPDExt.root_268535_11_1_20251215T214344Z_PDInt.root_269119_22_1_20251218T193135Z_detsim_reco1.root
-rw-r--r--. 1 cuser cuser 32883090 Dec 18 13:38 Pandora_Events.pndr
-rw-r--r--. 1 cuser cuser 0 Dec 18 13:25 debugprod.log
-rw-r--r--. 1 cuser cuser 519 Dec 18 13:24 detsim_single_protodunehd_hist.root
-rw-r--r--. 1 cuser cuser 5459505087 Dec 18 13:24 temp_detsim.root
-rw-r--r--. 1 cuser cuser 121 Dec 18 11:31 all-input-dids.txt