Jobsub ID 264091.1@dunegpschedd01.fnal.gov

Jobsub ID	264091.1@dunegpschedd01.fnal.gov
Workflow ID	11047
Stage ID	1
User name	avizcaya@fnal.gov
Requested	Processors	1
	GPU	No
	RSS bytes	9437184000 (9000 MiB)
	Wall seconds limit	80000 (22 hours)
Submitted time	2025-12-05 22:27:15
Site	US_UChicago
Entry	Engage_US_MWT2_uct2_gk02_condce_mcore
Last heartbeat	2025-12-06 03:41:42
From worker node	Hostname	uct2-c499.mwt2.org
	cpuinfo	Intel(R) Xeon(R) Gold 6148 CPU @ 2.40GHz
	OS release	Scientific Linux release 7.9 (Nitrogen)
	Processors	1
	RSS bytes	10485760000 (10000 MiB)
	Wall seconds limit	86400 (24 hours)
	GPU
	Inner Apptainer?	True
Job state	finished
Started	2025-12-06 01:16:44
Input files	usertests:pdhd_prod_beam__247543_39_1_20251112T023328Z_gen_g4_IonScintPDExt.root_263961_60_1_20251205T175254Z_PDInt.root
Jobscript	Exit code	0
	Real time	2h (8241s)
	CPU time	2h (8039s = 97%)
	Max RSS bytes	7508193280 (7160 MiB)
Outputting started	2025-12-06 03:34:05
Output files	usertests:pdhd_prod_beam__247543_39_1_20251112T023328Z_gen_g4_IonScintPDExt.root_263961_60_1_20251205T175254Z_PDInt.root_264091_1_1_20251206T011654Z_detsim_reco1.root
Finished	2025-12-06 03:41:42
Saved logs	justin-logs:264091.1-dunegpschedd01.fnal.gov.logs.tgz
List job events Cached HTCondor job logs

Jobscript log (last 10,000 characters)

" ] 2 tagged trace sets:[ "gauss0":19383 [0] "wiener0":21794 [21794] ] cmm:[ bad:0 lf_noisy:166 ] 
[21:32:54.802] D [  glue  ] <FrameFanin:sn_mag_nf> call=18 input 0: frame: ident=109 time=0 tick=512 with 41177 traces.  frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss0":19383 [0] "wiener0":21794 [21794] ] cmm:[ bad:0 lf_noisy:166 ] input 1: frame: ident=109 time=0 tick=512 with 45614 traces.  frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss1":20129 [0] "wiener1":25485 [25485] ] cmm:[ bad:0 lf_noisy:1 ] input 2: frame: ident=109 time=0 tick=512 with 45173 traces.  frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss2":18472 [0] "wiener2":26701 [26701] ] cmm:[ bad:0 ] input 3: frame: ident=109 time=0 tick=512 with 36666 traces.  frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss3":16637 [0] "wiener3":20029 [20029] ] cmm:[ bad:0 ] output: frame: ident=109 time=0 tick=512 with 168630 traces.  frame tags:[ "framefanin" ] 8 tagged trace sets:[ "gauss0":19383 [0] "gauss1":20129 [0] "gauss2":18472 [0] "gauss3":16637 [0] "wiener0":21794 [21794] "wiener1":25485 [25485] "wiener2":26701 [26701] "wiener3":20029 [20029] ] cmm:[ bad:0 lf_noisy:167 ] 
Retagger: tagging trace set: wiener with 94009 traces, 94009 summary
Retagger: tagging trace set: gauss with 74621 traces, 0 summary
[21:32:54.833] D [  glue  ] sink frame: #109 @0 with 168630 traces, frame tags:[retagger], trace tags:[gauss, wiener]
[21:32:54.833] D [  glue  ] <FrameFanout:sn_mag_nf> call=19: see EOS 
[21:32:54.833] D [  glue  ] <ChannelSelector:chsel3> see EOS at call=9 
[21:32:54.833] D [sigproc ] <OmnibusNoiseFilter:nf3> EOS at call=19 
[21:32:54.833] D [sigproc ] <OmnibusSigProc:apa3sigproc3> EOS at call=19 anode=3 
[21:32:54.833] D [  glue  ] <ChannelSelector:chsel2> see EOS at call=9 
[21:32:54.833] D [sigproc ] <OmnibusNoiseFilter:nf2> EOS at call=19 
[21:32:54.833] D [sigproc ] <OmnibusSigProc:apa2sigproc2> EOS at call=19 anode=2 
[21:32:54.834] D [  glue  ] <ChannelSelector:chsel1> see EOS at call=9 
[21:32:54.834] D [sigproc ] <OmnibusNoiseFilter:nf1> EOS at call=19 
[21:32:54.834] D [sigproc ] <OmnibusSigProc:apa1sigproc1> EOS at call=19 anode=1 
[21:32:54.834] D [  glue  ] <ChannelSelector:chsel0> see EOS at call=9 
[21:32:54.834] D [sigproc ] <OmnibusNoiseFilter:nf0> EOS at call=19 
[21:32:54.834] D [sigproc ] <OmnibusSigProc:apa0sigproc0> EOS at call=19 anode=0 
[21:32:54.834] D [  glue  ] <FrameFanin:sn_mag_nf> EOS at call=19 with 4 
[21:32:54.834] D [  glue  ] frame sink sees EOS
[21:32:54.834] D [ pgraph ] <Pgrapher:> graph execution complete 
[21:32:54.834] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 19.66 sec
[21:32:54.834] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 16.6 sec
[21:32:54.834] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 14.15 sec
[21:32:54.834] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 13.43 sec
[21:32:54.834] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 4.7 sec
[21:32:54.834] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 4.4 sec
[21:32:54.834] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 4.21 sec
[21:32:54.834] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 3.88 sec
[21:32:54.834] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0.04 sec
[21:32:54.834] I [ timer  ] Timer: WireCell::Gen::FrameFanin : 0.04 sec
[21:32:54.834] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0.02 sec
[21:32:54.834] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0.02 sec
[21:32:54.834] I [ timer  ] Timer: WireCell::Gen::Retagger : 0.01 sec
[21:32:54.834] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[21:32:54.834] I [ timer  ] Timer: WireCell::Gen::FrameFanout : 0 sec
[21:32:54.834] I [ timer  ] Timer: wcls::RawFrameSource : 0 sec
[21:32:54.834] I [ timer  ] Timer: wcls::FrameSaver : 0 sec
[21:32:54.834] I [ timer  ] Timer: WireCell::Gen::DumpFrames : 0 sec
[21:32:54.834] I [ timer  ] Timer: Total node execution : 81.16000020690262 sec
wclsFrameSaver saving cooked to 6000 ticks
wclsFrameSaver: saving 74621 traces tagged "gauss"
FrameSaver: q=2.20846e+06 n=1167058 tag=gauss
wclsFrameSaver: saving 94009 traces tagged "wiener"
FrameSaver: q=2.63582e+06 n=1103261 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:2 37741 XUs and 26254 XVs -> 1013 XUVs
C:0 T:5 19040 XUs and 19408 XVs -> 425 XUVs
C:0 T:6 15556 XUs and 8758 XVs -> 328 XUVs
1766 XUVs total
1287 collection wire objects
1766 potential space points
Neighbour search...
19840 tests to find 10756 neighbours
Iterating with no regularization...
Begin: 1.22402e+07
0 1.17135e+07
1 1.16835e+07
2 1.16807e+07
Now with regularization...
Begin: 1.07988e+07
0 1.07978e+07
05-Dec-2025 21:34:03 CST  Closed output file "pdhd_prod_beam__247543_39_1_20251112T023328Z_gen_g4_IonScintPDExt.root_263961_60_1_20251205T175254Z_PDInt.root_264091_1_1_20251206T011654Z_detsim_reco1.root"
05-Dec-2025 21:34:03 CST  Closed input file "temp_detsim.root"

=====================================================================================================================================
TimeTracker printout (sec)                             Min           Avg           Max         Median          RMS         nEvts   
=====================================================================================================================================
Full event                                           110.056       140.531       196.246       144.087       24.8963        10     
-------------------------------------------------------------------------------------------------------------------------------------
source:RootInput(read)                             0.00143138    0.00541462     0.0128317    0.00490981    0.00308524       10     
reco:wclsdatahd:WireCellToolkit                      69.1686       79.5514       88.0439       81.006        5.64663        10     
reco:wirefilter:WireFilter                          0.0274981     0.0459425     0.059646      0.048205      0.0104123       10     
reco:gaushit:GausHitFinder                          0.569497      0.920846       1.3805       0.933412       0.2651         10     
reco:nhitsfilter:NumberOfHitsFilter                0.000313322   0.000494141   0.000885797   0.000481805   0.000157115      10     
reco:reco3d:SpacePointSolver                        0.279831       1.53846       7.41825      0.749945       2.05614        10     
reco:hitpdune:DisambigFromSpacePoints               0.269086      0.835177       2.0177        0.81227      0.509086        10     
reco:pandora:StandardPandora                         6.27657       12.9199       29.4003       11.1877       6.80992        10     
reco:pandoraWriter:StandardPandora                  0.186952      0.319138      0.459949      0.325624      0.0801687       10     
reco:pandoraTrack:LArPandoraTrackCreation            1.49378       2.77605       6.48119       2.49763       1.38131        10     
reco:pandoraShower:LArPandoraShowerCreation          1.05005       2.46298       4.45962       2.07487       1.06921        10     
reco:pandoracalo:Calorimetry                        0.499374        1.217        2.05931       1.16189      0.422732        10     
reco:pandoracalonosce:Calorimetry                   0.600411       1.23523       3.09958       1.04806      0.702519        10     
reco:pandoraShowercalo:ShowerCalorimetry            0.918355       2.27478       5.60288        1.757        1.31453        10     
reco:pandoraShowercalonosce:ShowerCalorimetry       0.923911       2.14496       5.37066       1.72866       1.26339        10     
reco:pandoraGnocchiCalo:GnocchiCalorimetry          0.0435001     0.0786374     0.103297      0.0832946     0.0210095       10     
reco:pandoraGnocchiCalonosce:GnocchiCalorimetry     0.0428811     0.0804978     0.105562      0.0902282     0.0230339       10     
reco:emtrkmichelid:EmTrackMichelId                   19.7769       30.2247       43.6132       31.5966       6.75038        10     
[art]:TriggerResults:TriggerResultInserter         4.6076e-05    7.59988e-05   9.9866e-05    7.88865e-05   1.64655e-05      10     
end_path:out1:RootOutput                            8.277e-06    1.34847e-05   2.2579e-05    1.1762e-05    4.79075e-06      10     
end_path:out1:RootOutput(write)                      1.04627       1.8115        2.23377       1.81447      0.339888        10     
=====================================================================================================================================

====================================================================================================
MemoryTracker summary (base-10 MB units used)

  Peak virtual memory usage (VmPeak)  : 6154.48 MB
  Peak resident set size usage (VmHWM): 3967.47 MB
  Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Reco returns 0
.:
total 12733864
-rw-r--r--. 1 dune osgvo     231629 Dec  5 21:34 jobscript.log
-rw-r--r--. 1 dune osgvo        200 Dec  5 21:34 justin-processed-pfns.txt
-rw-r--r--. 1 dune osgvo        519 Dec  5 21:34 reco_protodunehd_hist.root
-rw-r--r--. 1 dune osgvo       3574 Dec  5 21:34 Pandora_Geometry.xml
-rw-r--r--. 1 dune osgvo     139264 Dec  5 21:34 mem.db
-rw-r--r--. 1 dune osgvo      28672 Dec  5 21:34 time.db
-rw-r--r--. 1 dune osgvo 6594861637 Dec  5 21:34 pdhd_prod_beam__247543_39_1_20251112T023328Z_gen_g4_IonScintPDExt.root_263961_60_1_20251205T175254Z_PDInt.root_264091_1_1_20251206T011654Z_detsim_reco1.root
-rw-r--r--. 1 dune osgvo   33743400 Dec  5 21:33 Pandora_Events.pndr
-rw-r--r--. 1 dune osgvo          0 Dec  5 21:07 debugprod.log
-rw-r--r--. 1 dune osgvo        519 Dec  5 21:07 detsim_single_protodunehd_hist.root
-rw-r--r--. 1 dune osgvo 6410427829 Dec  5 21:07 temp_detsim.root
-rw-r--r--. 1 dune osgvo        121 Dec  5 19:16 all-input-dids.txt