Jobsub ID 269307.1@dunegpschedd01.fnal.gov
Jobscript log (last 10,000 characters)
ue ] <FrameFanin:sn_mag_nf> call=18 input 0: frame: ident=189 time=0 tick=512 with 62266 traces. frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss0":29791 [0] "wiener0":32475 [32475] ] cmm:[ bad:0 lf_noisy:192 ] input 1: frame: ident=189 time=0 tick=512 with 46651 traces. frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss1":19274 [0] "wiener1":27377 [27377] ] cmm:[ bad:0 ] input 2: frame: ident=189 time=0 tick=512 with 37988 traces. frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss2":16683 [0] "wiener2":21305 [21305] ] cmm:[ bad:0 ] input 3: frame: ident=189 time=0 tick=512 with 66816 traces. frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss3":27934 [0] "wiener3":38882 [38882] ] cmm:[ bad:0 ] output: frame: ident=189 time=0 tick=512 with 213721 traces. frame tags:[ "framefanin" ] 8 tagged trace sets:[ "gauss0":29791 [0] "gauss1":19274 [0] "gauss2":16683 [0] "gauss3":27934 [0] "wiener0":32475 [32475] "wiener1":27377 [27377] "wiener2":21305 [21305] "wiener3":38882 [38882] ] cmm:[ bad:0 lf_noisy:192 ]
Retagger: tagging trace set: wiener with 120039 traces, 120039 summary
Retagger: tagging trace set: gauss with 93682 traces, 0 summary
[08:09:37.837] D [ glue ] sink frame: #189 @0 with 213721 traces, frame tags:[retagger], trace tags:[gauss, wiener]
[08:09:37.837] D [ glue ] <FrameFanout:sn_mag_nf> call=19: see EOS
[08:09:37.837] D [ glue ] <ChannelSelector:chsel3> see EOS at call=9
[08:09:37.837] D [sigproc ] <OmnibusNoiseFilter:nf3> EOS at call=19
[08:09:37.837] D [sigproc ] <OmnibusSigProc:apa3sigproc3> EOS at call=19 anode=3
[08:09:37.837] D [ glue ] <ChannelSelector:chsel2> see EOS at call=9
[08:09:37.837] D [sigproc ] <OmnibusNoiseFilter:nf2> EOS at call=19
[08:09:37.837] D [sigproc ] <OmnibusSigProc:apa2sigproc2> EOS at call=19 anode=2
[08:09:37.837] D [ glue ] <ChannelSelector:chsel1> see EOS at call=9
[08:09:37.837] D [sigproc ] <OmnibusNoiseFilter:nf1> EOS at call=19
[08:09:37.837] D [sigproc ] <OmnibusSigProc:apa1sigproc1> EOS at call=19 anode=1
[08:09:37.837] D [ glue ] <ChannelSelector:chsel0> see EOS at call=9
[08:09:37.837] D [sigproc ] <OmnibusNoiseFilter:nf0> EOS at call=19
[08:09:37.837] D [sigproc ] <OmnibusSigProc:apa0sigproc0> EOS at call=19 anode=0
[08:09:37.837] D [ glue ] <FrameFanin:sn_mag_nf> EOS at call=19 with 4
[08:09:37.837] D [ glue ] frame sink sees EOS
[08:09:37.837] D [ pgraph ] <Pgrapher:> graph execution complete
[08:09:37.837] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 10.87 sec
[08:09:37.837] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 6.85 sec
[08:09:37.837] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 6.56 sec
[08:09:37.837] I [ timer ] Timer: WireCell::SigProc::OmnibusSigProc : 6.48 sec
[08:09:37.837] I [ timer ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.6 sec
[08:09:37.837] I [ timer ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.53 sec
[08:09:37.837] I [ timer ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.49 sec
[08:09:37.837] I [ timer ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.45 sec
[08:09:37.837] I [ timer ] Timer: WireCell::Gen::FrameFanin : 0.02 sec
[08:09:37.837] I [ timer ] Timer: WireCell::Gen::Retagger : 0.01 sec
[08:09:37.837] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[08:09:37.837] I [ timer ] Timer: WireCell::Gen::FrameFanout : 0 sec
[08:09:37.837] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[08:09:37.837] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[08:09:37.837] I [ timer ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[08:09:37.837] I [ timer ] Timer: wcls::RawFrameSource : 0 sec
[08:09:37.838] I [ timer ] Timer: wcls::FrameSaver : 0 sec
[08:09:37.838] I [ timer ] Timer: WireCell::Gen::DumpFrames : 0 sec
[08:09:37.838] I [ timer ] Timer: Total node execution : 40.85999968461692 sec
wclsFrameSaver saving cooked to 6000 ticks
wclsFrameSaver: saving 93682 traces tagged "gauss"
FrameSaver: q=3.0405e+06 n=1539802 tag=gauss
wclsFrameSaver: saving 120039 traces tagged "wiener"
FrameSaver: q=3.80807e+06 n=1502477 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:2 50197 XUs and 68720 XVs -> 1310 XUVs
C:0 T:3 18 XUs and 337 XVs -> 3 XUVs
C:0 T:4 3 XUs and 9 XVs -> 0 XUVs
C:0 T:5 14731 XUs and 17252 XVs -> 918 XUVs
C:0 T:6 91636 XUs and 125020 XVs -> 4105 XUVs
C:0 T:7 65 XUs and 47 XVs -> 3 XUVs
6339 XUVs total
2518 collection wire objects
6339 potential space points
Neighbour search...
182907 tests to find 107420 neighbours
Iterating with no regularization...
Begin: 3.20549e+07
0 2.86285e+07
1 2.83942e+07
2 2.83514e+07
3 2.83361e+07
Now with regularization...
Begin: 2.61649e+07
0 2.61559e+07
20-Dec-2025 08:10:25 PST Closed output file "pdhd_prod_beam__267379_71_1_20251212T161710Z_gen_g4_IonScintPDExt.root_262726_103_1_20251215T212449Z_PDInt.root_269307_1_1_20251219T182040Z_detsim_reco1.root"
20-Dec-2025 08:10:25 PST Closed input file "temp_detsim.root"
=====================================================================================================================================
TimeTracker printout (sec) Min Avg Max Median RMS nEvts
=====================================================================================================================================
Full event 64.3235 73.6508 88.6451 73.3802 7.92391 10
-------------------------------------------------------------------------------------------------------------------------------------
source:RootInput(read) 0.000580764 0.0032126 0.0066429 0.00330516 0.00160281 10
reco:wclsdatahd:WireCellToolkit 40.0412 41.5236 43.1142 41.594 0.895305 10
reco:wirefilter:WireFilter 0.011604 0.0144152 0.0199721 0.0132877 0.00276524 10
reco:gaushit:GausHitFinder 0.318409 0.518226 1.07922 0.486052 0.199246 10
reco:nhitsfilter:NumberOfHitsFilter 0.000131978 0.000217201 0.000368766 0.000193658 7.72354e-05 10
reco:reco3d:SpacePointSolver 0.161847 0.484431 1.68409 0.290885 0.445031 10
reco:hitpdune:DisambigFromSpacePoints 0.121476 0.322393 0.738686 0.300302 0.169496 10
reco:pandora:StandardPandora 3.38586 6.29726 10.3851 6.3252 2.35787 10
reco:pandoraWriter:StandardPandora 0.10192 0.149357 0.235989 0.139247 0.0412953 10
reco:pandoraTrack:LArPandoraTrackCreation 0.410853 0.652654 0.855223 0.674006 0.137163 10
reco:pandoraShower:LArPandoraShowerCreation 0.403306 0.695899 1.12524 0.642679 0.216895 10
reco:pandoracalo:Calorimetry 0.304166 0.400629 0.483613 0.404585 0.0615136 10
reco:pandoracalonosce:Calorimetry 0.29599 0.38715 0.461691 0.380887 0.0577349 10
reco:pandoraShowercalo:ShowerCalorimetry 0.462504 0.743255 1.32685 0.67316 0.264591 10
reco:pandoraShowercalonosce:ShowerCalorimetry 0.414537 0.707942 1.16681 0.660962 0.246644 10
reco:pandoraGnocchiCalo:GnocchiCalorimetry 0.0271402 0.0361696 0.0468564 0.035239 0.00639706 10
reco:pandoraGnocchiCalonosce:GnocchiCalorimetry 0.0295235 0.0367093 0.0486286 0.03526 0.00646912 10
reco:emtrkmichelid:EmTrackMichelId 15.629 19.5363 26.1248 19.4796 3.46677 10
[art]:TriggerResults:TriggerResultInserter 1.894e-05 4.57938e-05 0.000107329 3.0235e-05 2.94239e-05 10
end_path:out1:RootOutput 5.91e-06 1.05259e-05 2.745e-05 9.2895e-06 5.82558e-06 10
end_path:out1:RootOutput(write) 0.847886 1.10061 1.83801 1.00235 0.269009 10
=====================================================================================================================================
====================================================================================================
MemoryTracker summary (base-10 MB units used)
Peak virtual memory usage (VmPeak) : 6028.99 MB
Peak resident set size usage (VmHWM): 3780.68 MB
Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Reco returns 0
.:
total 12457224
-rw-r--r--. 1 cuser cuser 231250 Dec 20 08:10 jobscript.log
-rw-r--r--. 1 cuser cuser 201 Dec 20 08:10 justin-processed-pfns.txt
-rw-r--r--. 1 cuser cuser 519 Dec 20 08:10 reco_protodunehd_hist.root
-rw-r--r--. 1 cuser cuser 3574 Dec 20 08:10 Pandora_Geometry.xml
-rw-r--r--. 1 cuser cuser 139264 Dec 20 08:10 mem.db
-rw-r--r--. 1 cuser cuser 28672 Dec 20 08:10 time.db
-rw-r--r--. 1 cuser cuser 6457546313 Dec 20 08:10 pdhd_prod_beam__267379_71_1_20251212T161710Z_gen_g4_IonScintPDExt.root_262726_103_1_20251215T212449Z_PDInt.root_269307_1_1_20251219T182040Z_detsim_reco1.root
-rw-r--r--. 1 cuser cuser 36222030 Dec 20 08:09 Pandora_Events.pndr
-rw-r--r--. 1 cuser cuser 0 Dec 20 07:56 debugprod.log
-rw-r--r--. 1 cuser cuser 519 Dec 20 07:56 detsim_single_protodunehd_hist.root
-rw-r--r--. 1 cuser cuser 6261964994 Dec 20 07:56 temp_detsim.root
-rw-r--r--. 1 cuser cuser 122 Dec 19 10:20 all-input-dids.txt
