Jobsub ID 268917.0@dunegpschedd01.fnal.gov
Jobscript log (last 10,000 characters)
:45 ]
[17:05:49.549] D [ glue ] <FrameFanin:sn_mag_nf> call=18 input 0: frame: ident=189 time=0 tick=512 with 54056 traces. frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss0":24862 [0] "wiener0":29194 [29194] ] cmm:[ bad:0 lf_noisy:45 ] input 1: frame: ident=189 time=0 tick=512 with 22202 traces. frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss1":10492 [0] "wiener1":11710 [11710] ] cmm:[ bad:0 ] input 2: frame: ident=189 time=0 tick=512 with 48221 traces. frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss2":19619 [0] "wiener2":28602 [28602] ] cmm:[ bad:0 ] input 3: frame: ident=189 time=0 tick=512 with 26819 traces. frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss3":11945 [0] "wiener3":14874 [14874] ] cmm:[ bad:0 ] output: frame: ident=189 time=0 tick=512 with 151298 traces. frame tags:[ "framefanin" ] 8 tagged trace sets:[ "gauss0":24862 [0] "gauss1":10492 [0] "gauss2":19619 [0] "gauss3":11945 [0] "wiener0":29194 [29194] "wiener1":11710 [11710] "wiener2":28602 [28602] "wiener3":14874 [14874] ] cmm:[ bad:0 lf_noisy:45 ]
Retagger: tagging trace set: wiener with 84380 traces, 84380 summary
Retagger: tagging trace set: gauss with 66918 traces, 0 summary
[17:05:49.559] D [ glue ] sink frame: #189 @0 with 151298 traces, frame tags:[retagger], trace tags:[gauss, wiener]
[17:05:49.559] D [ glue ] <FrameFanout:sn_mag_nf> call=19: see EOS
[17:05:49.559] D [ glue ] <ChannelSelector:chsel3> see EOS at call=9
[17:05:49.559] D [sigproc ] <OmnibusNoiseFilter:nf3> EOS at call=19
[17:05:49.559] D [sigproc ] <OmnibusSigProc:apa3sigproc3> EOS at call=19 anode=3
[17:05:49.559] D [ glue ] <ChannelSelector:chsel2> see EOS at call=9
[17:05:49.560] D [sigproc ] <OmnibusNoiseFilter:nf2> EOS at call=19
[17:05:49.560] D [sigproc ] <OmnibusSigProc:apa2sigproc2> EOS at call=19 anode=2
[17:05:49.560] D [ glue ] <ChannelSelector:chsel1> see EOS at call=9
[17:05:49.560] D [sigproc ] <OmnibusNoiseFilter:nf1> EOS at call=19
[17:05:49.560] D [sigproc ] <OmnibusSigProc:apa1sigproc1> EOS at call=19 anode=1
[17:05:49.560] D [ glue ] <ChannelSelector:chsel0> see EOS at call=9
[17:05:49.560] D [sigproc ] <OmnibusNoiseFilter:nf0> EOS at call=19
[17:05:49.560] D [sigproc ] <OmnibusSigProc:apa0sigproc0> EOS at call=19 anode=0
[17:05:49.560] D [ glue ] <FrameFanin:sn_mag_nf> EOS at call=19 with 4
[17:05:49.560] D [ glue ] frame sink sees EOS
[17:05:49.560] D [ pgraph ] <Pgrapher:> graph execution complete
[17:05:49.560] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 14.4 sec
[17:05:49.560] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 9.92 sec
[17:05:49.560] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 9.62 sec
[17:05:49.560] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 9.43 sec
[17:05:49.560] I [ timer ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.83 sec
[17:05:49.560] I [ timer ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.79 sec
[17:05:49.560] I [ timer ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.77 sec
[17:05:49.560] I [ timer ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.73 sec
[17:05:49.560] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.03 sec
[17:05:49.560] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[17:05:49.560] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[17:05:49.560] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[17:05:49.560] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[17:05:49.560] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0 sec
[17:05:49.560] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[17:05:49.560] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[17:05:49.560] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[17:05:49.560] I [ timer ] Timer: WireCell::Gen::Retagger : 0 sec
[17:05:49.560] I [ timer ] Timer: Total node execution : 54.529999770224094 sec
wclsFrameSaver saving cooked to 6000 ticks
wclsFrameSaver: saving 66918 traces tagged "gauss"
FrameSaver: q=1.81656e+06 n=944297 tag=gauss
wclsFrameSaver: saving 84380 traces tagged "wiener"
FrameSaver: q=2.52416e+06 n=924952 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:2 3388 XUs and 2199 XVs -> 85 XUVs
C:0 T:5 33987 XUs and 81794 XVs -> 4304 XUVs
C:0 T:6 4246 XUs and 8934 XVs -> 728 XUVs
C:0 T:7 4 XUs and 9 XVs -> 0 XUVs
5117 XUVs total
1644 collection wire objects
5117 potential space points
Neighbour search...
304823 tests to find 187914 neighbours
Iterating with no regularization...
Begin: 1.34607e+07
0 1.20033e+07
1 1.18808e+07
2 1.18599e+07
3 1.18528e+07
Now with regularization...
Begin: 1.05595e+07
0 1.05546e+07
17-Dec-2025 17:06:04 EST Closed output file "pdhd_prod_beam__267379_72_1_20251212T161640Z_gen_g4_IonScintPDExt.root_263025_1_1_20251217T050229Z_PDInt.root_268917_0_1_20251217T205306Z_detsim_reco1.root"
17-Dec-2025 17:06:04 EST Closed input file "temp_detsim.root"
=====================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
=====================================================================================================================================
Full event 69.9637 79.5038 88.6445 79.2298 5.22408 10
-------------------------------------------------------------------------------------------------------------------------------------
source:RootInput(read) 0.000794955 0.00406291 0.0066045 0.00457984 0.00207647 10
reco:wclsdatahd:WireCellToolkit 55.3411 56.8596 59.3925 56.4149 1.35679 10
reco:wirefilter:WireFilter 0.0138599 0.0179498 0.020898 0.0179383 0.00198266 10
reco:gaushit:GausHitFinder 0.362894 0.587206 0.780379 0.585624 0.123553 10
reco:nhitsfilter:NumberOfHitsFilter 0.00015664 0.000234839 0.000396005 0.00022356 6.18989e-05 10
reco:reco3d:SpacePointSolver 0.209995 0.429278 0.785296 0.387857 0.160324 10
reco:hitpdune:DisambigFromSpacePoints 0.219693 0.370343 0.534454 0.375898 0.0854569 10
reco:pandora:StandardPandora 3.47196 6.87381 10.5412 6.55669 2.1502 10
reco:pandoraWriter:StandardPandora 0.107346 0.14673 0.182179 0.151525 0.0227471 10
reco:pandoraTrack:LArPandoraTrackCreation 0.341844 0.776261 1.08141 0.77914 0.204867 10
reco:pandoraShower:LArPandoraShowerCreation 0.312399 0.705789 1.05959 0.718922 0.241484 10
reco:pandoracalo:Calorimetry 0.20801 0.420751 0.589694 0.445369 0.100521 10
reco:pandoracalonosce:Calorimetry 0.201854 0.408341 0.565633 0.435163 0.0987367 10
reco:pandoraShowercalo:ShowerCalorimetry 0.278627 0.665715 1.02363 0.658627 0.240673 10
reco:pandoraShowercalonosce:ShowerCalorimetry 0.271929 0.664166 1.01176 0.684098 0.243449 10
reco:pandoraGnocchiCalo:GnocchiCalorimetry 0.032188 0.0417824 0.0487876 0.0425712 0.00541586 10
reco:pandoraGnocchiCalonosce:GnocchiCalorimetry 0.0321638 0.0430104 0.0620667 0.0415455 0.00817633 10
reco:emtrkmichelid:EmTrackMichelId 6.88775 9.42305 11.412 9.49887 1.36325 10
[art]:TriggerResults:TriggerResultInserter 1.638e-05 2.74847e-05 7.2253e-05 2.06605e-05 1.56871e-05 10
end_path:out1:RootOutput 5.949e-06 8.514e-06 2.2673e-05 6.9435e-06 4.76384e-06 10
end_path:out1:RootOutput(write) 0.847832 1.03658 1.25354 1.00746 0.128853 10
=====================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 6161.03 MB
Peak resident set size usage (VmHWM): 3722.07 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Reco returns 0
.:
total 10524768
-rw-r--r-- 1 fermipro fermilab 231170 Dec 17 17:06 jobscript.log
-rw-r--r-- 1 fermipro fermilab 193 Dec 17 17:06 justin-processed-pfns.txt
-rw-r--r-- 1 fermipro fermilab 519 Dec 17 17:06 reco_protodunehd_hist.root
-rw-r--r-- 1 fermipro fermilab 3574 Dec 17 17:06 Pandora_Geometry.xml
-rw-r--r-- 1 fermipro fermilab 139264 Dec 17 17:06 mem.db
-rw-r--r-- 1 fermipro fermilab 28672 Dec 17 17:06 time.db
-rw-r--r-- 1 fermipro fermilab 5460323712 Dec 17 17:06 pdhd_prod_beam__267379_72_1_20251212T161640Z_gen_g4_IonScintPDExt.root_263025_1_1_20251217T050229Z_PDInt.root_268917_0_1_20251217T205306Z_detsim_reco1.root
-rw-r--r-- 1 fermipro fermilab 31194810 Dec 17 17:05 Pandora_Events.pndr
-rw-r--r-- 1 fermipro fermilab 0 Dec 17 16:51 debugprod.log
-rw-r--r-- 1 fermipro fermilab 519 Dec 17 16:50 detsim_single_protodunehd_hist.root
-rw-r--r-- 1 fermipro fermilab 5285399196 Dec 17 16:50 temp_detsim.root
-rw-r--r-- 1 fermipro fermilab 120 Dec 17 15:53 all-input-dids.txt
