Jobsub ID 235524.0@dunegpschedd02.fnal.gov

Jobsub ID	235524.0@dunegpschedd02.fnal.gov
Workflow ID	9455
Stage ID	1
User name	mwrobel@fnal.gov
HTCondor Group	group_dune
Requested	Processors	1
	GPU	No
	RSS bytes	9437184000 (9000 MiB)
	Wall seconds limit	80000 (22 hours)
Submitted time	2025-10-30 19:48:48
Site	US_UChicago
Entry	Engage_US_MWT2_iut2_condce_mcore
Last heartbeat	2025-10-30 22:32:28
From worker node	Hostname	uct2-c497.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-10-30 20:00:18
Input files	usertests:pdhd_prod_beam__226242_57_1_20251008T182925Z_gen_g4_IonScintPDExt.root_227038_180_1_20251010T165634Z_PDInt.root
Jobscript	Exit code	0
	Real time	2h (9009s)
	CPU time	2h (8769s = 97%)
	Max RSS bytes	6839156736 (6522 MiB)
Outputting started	2025-10-30 22:30:28
Output files	usertests:pdhd_prod_beam__226242_57_1_20251008T182925Z_gen_g4_IonScintPDExt.root_227038_180_1_20251010T165634Z_PDInt.root_235524_0_1_20251030T200031Z_detsim_reco1.root
Finished	2025-10-30 22:32:28
Saved logs	justin-logs:235524.0-dunegpschedd02.fnal.gov.logs.tgz
List job events Cached HTCondor job logs

Jobscript log (last 10,000 characters)

s:[ "gauss0":26018 [0] "wiener0":30025 [30025] ] cmm:[ bad:0 lf_noisy:264 ] 
[17:29:36.386] D [  glue  ] <FrameFanin:sn_mag_nf> call=18 input 0: frame: ident=89 time=0 tick=512 with 56043 traces.  frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss0":26018 [0] "wiener0":30025 [30025] ] cmm:[ bad:0 lf_noisy:264 ] input 1: frame: ident=89 time=0 tick=512 with 25757 traces.  frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss1":11552 [0] "wiener1":14205 [14205] ] cmm:[ bad:0 ] input 2: frame: ident=89 time=0 tick=512 with 36490 traces.  frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss2":15682 [0] "wiener2":20808 [20808] ] cmm:[ bad:0 ] input 3: frame: ident=89 time=0 tick=512 with 39812 traces.  frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss3":16908 [0] "wiener3":22904 [22904] ] cmm:[ bad:0 ] output: frame: ident=89 time=0 tick=512 with 158102 traces.  frame tags:[ "framefanin" ] 8 tagged trace sets:[ "gauss0":26018 [0] "gauss1":11552 [0] "gauss2":15682 [0] "gauss3":16908 [0] "wiener0":30025 [30025] "wiener1":14205 [14205] "wiener2":20808 [20808] "wiener3":22904 [22904] ] cmm:[ bad:0 lf_noisy:264 ] 
Retagger: tagging trace set: wiener with 87942 traces, 87942 summary
Retagger: tagging trace set: gauss with 70160 traces, 0 summary
[17:29:36.421] D [  glue  ] sink frame: #89 @0 with 158102 traces, frame tags:[retagger], trace tags:[gauss, wiener]
[17:29:36.421] D [  glue  ] <FrameFanout:sn_mag_nf> call=19: see EOS 
[17:29:36.421] D [  glue  ] <ChannelSelector:chsel3> see EOS at call=9 
[17:29:36.421] D [sigproc ] <OmnibusNoiseFilter:nf3> EOS at call=19 
[17:29:36.421] D [sigproc ] <OmnibusSigProc:apa3sigproc3> EOS at call=19 anode=3 
[17:29:36.421] D [  glue  ] <ChannelSelector:chsel2> see EOS at call=9 
[17:29:36.421] D [sigproc ] <OmnibusNoiseFilter:nf2> EOS at call=19 
[17:29:36.421] D [sigproc ] <OmnibusSigProc:apa2sigproc2> EOS at call=19 anode=2 
[17:29:36.422] D [  glue  ] <ChannelSelector:chsel1> see EOS at call=9 
[17:29:36.422] D [sigproc ] <OmnibusNoiseFilter:nf1> EOS at call=19 
[17:29:36.422] D [sigproc ] <OmnibusSigProc:apa1sigproc1> EOS at call=19 anode=1 
[17:29:36.422] D [  glue  ] <ChannelSelector:chsel0> see EOS at call=9 
[17:29:36.422] D [sigproc ] <OmnibusNoiseFilter:nf0> EOS at call=19 
[17:29:36.422] D [sigproc ] <OmnibusSigProc:apa0sigproc0> EOS at call=19 anode=0 
[17:29:36.422] D [  glue  ] <FrameFanin:sn_mag_nf> EOS at call=19 with 4 
[17:29:36.422] D [  glue  ] frame sink sees EOS
[17:29:36.422] D [ pgraph ] <Pgrapher:> graph execution complete 
[17:29:36.422] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 22.37 sec
[17:29:36.422] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 15.97 sec
[17:29:36.422] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 15.48 sec
[17:29:36.422] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 15.41 sec
[17:29:36.422] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 4.76 sec
[17:29:36.422] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 4.35 sec
[17:29:36.422] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 4.32 sec
[17:29:36.422] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 3.87 sec
[17:29:36.422] I [ timer  ] Timer: WireCell::Gen::FrameFanin : 0.05 sec
[17:29:36.422] I [ timer  ] Timer: WireCell::Gen::Retagger : 0.03 sec
[17:29:36.422] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0.02 sec
[17:29:36.422] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[17:29:36.422] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[17:29:36.422] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[17:29:36.422] I [ timer  ] Timer: WireCell::Gen::FrameFanout : 0 sec
[17:29:36.422] I [ timer  ] Timer: wcls::RawFrameSource : 0 sec
[17:29:36.422] I [ timer  ] Timer: wcls::FrameSaver : 0 sec
[17:29:36.422] I [ timer  ] Timer: WireCell::Gen::DumpFrames : 0 sec
[17:29:36.422] I [ timer  ] Timer: Total node execution : 86.65000068582594 sec
wclsFrameSaver saving cooked to 6000 ticks
wclsFrameSaver: saving 70160 traces tagged "gauss"
FrameSaver: q=2.0361e+06 n=1076040 tag=gauss
wclsFrameSaver: saving 87942 traces tagged "wiener"
FrameSaver: q=2.6395e+06 n=1047508 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:2 4654 XUs and 5737 XVs -> 301 XUVs
C:0 T:4 12 XUs and 10 XVs -> 0 XUVs
C:0 T:5 19989 XUs and 37659 XVs -> 1207 XUVs
C:0 T:6 60597 XUs and 32907 XVs -> 1202 XUVs
2710 XUVs total
1158 collection wire objects
2710 potential space points
Neighbour search...
87530 tests to find 53754 neighbours
Iterating with no regularization...
Begin: 1.74036e+07
0 1.50941e+07
1 1.49738e+07
2 1.49624e+07
Now with regularization...
Begin: 1.42345e+07
0 1.42315e+07
30-Oct-2025 17:30:26 CDT  Closed output file "pdhd_prod_beam__226242_57_1_20251008T182925Z_gen_g4_IonScintPDExt.root_227038_180_1_20251010T165634Z_PDInt.root_235524_0_1_20251030T200031Z_detsim_reco1.root"
30-Oct-2025 17:30:26 CDT  Closed input file "temp_detsim.root"

=====================================================================================================================================
TimeTracker printout (sec)                             Min           Avg           Max         Median          RMS         nEvts   
=====================================================================================================================================
Full event                                           124.896       154.49        172.814       157.149       14.3325        10     
-------------------------------------------------------------------------------------------------------------------------------------
source:RootInput(read)                             0.00172213     0.024822      0.188713      0.0063748     0.054744        10     
reco:wclsdatahd:WireCellToolkit                      86.6467       94.6626       108.551       90.0874       8.1579         10     
reco:wirefilter:WireFilter                          0.0349127     0.0533469     0.0687158     0.0539419    0.00952895       10     
reco:gaushit:GausHitFinder                           0.59685      0.928871       1.25587      0.900717       0.18603        10     
reco:nhitsfilter:NumberOfHitsFilter                0.000437183   0.000533976   0.000716733   0.000524638   8.32128e-05      10     
reco:reco3d:SpacePointSolver                        0.326328       1.02906       1.88884       1.04231      0.491739        10     
reco:hitpdune:DisambigFromSpacePoints               0.331501      0.735809       1.67046      0.576498      0.397165        10     
reco:pandora:StandardPandora                         7.70933       11.7769       16.621        11.4227       2.61736        10     
reco:pandoraWriter:StandardPandora                  0.240359      0.359337      0.465138      0.364818      0.0776747       10     
reco:pandoraTrack:LArPandoraTrackCreation            1.42357       2.81719       4.14715       2.85457       1.03919        10     
reco:pandoraShower:LArPandoraShowerCreation          1.06519       2.48059       3.80576       2.46123      0.898677        10     
reco:pandoracalo:Calorimetry                        0.660427       1.47469       2.48755       1.42343      0.592733        10     
reco:pandoracalonosce:Calorimetry                    0.4836        1.39586       2.39702       1.40664      0.586728        10     
reco:pandoraShowercalo:ShowerCalorimetry            0.812173       2.32825       4.32407       2.20066        1.076         10     
reco:pandoraShowercalonosce:ShowerCalorimetry       0.755027       2.32468       4.07011       2.27333       1.0295         10     
reco:pandoraGnocchiCalo:GnocchiCalorimetry          0.0573946     0.0984428     0.181002      0.0924839     0.0323103       10     
reco:pandoraGnocchiCalonosce:GnocchiCalorimetry     0.0586555     0.0982797     0.179492      0.095129      0.0317914       10     
reco:emtrkmichelid:EmTrackMichelId                   18.8938       30.0358       39.0511       30.8983       5.25215        10     
[art]:TriggerResults:TriggerResultInserter         7.7339e-05    0.000131451   0.000392259   9.5022e-05    8.9632e-05       10     
end_path:out1:RootOutput                            6.615e-06    3.12246e-05   0.000176109   1.3721e-05    4.88796e-05      10     
end_path:out1:RootOutput(write)                      1.38405       1.76053       2.13685       1.79737      0.267468        10     
=====================================================================================================================================

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

  Peak virtual memory usage (VmPeak)  : 5888.14 MB
  Peak resident set size usage (VmHWM): 3678.01 MB
  Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Reco returns 0
.:
total 12025408
-rw-r--r--. 1 dune osgvo     230822 Oct 30 17:30 jobscript.log
-rw-r--r--. 1 dune osgvo        201 Oct 30 17:30 justin-processed-pfns.txt
-rw-r--r--. 1 dune osgvo        519 Oct 30 17:30 reco_protodunehd_hist.root
-rw-r--r--. 1 dune osgvo       3574 Oct 30 17:30 Pandora_Geometry.xml
-rw-r--r--. 1 dune osgvo     139264 Oct 30 17:30 mem.db
-rw-r--r--. 1 dune osgvo      28672 Oct 30 17:30 time.db
-rw-r--r--. 1 dune osgvo 6228840491 Oct 30 17:30 pdhd_prod_beam__226242_57_1_20251008T182925Z_gen_g4_IonScintPDExt.root_227038_180_1_20251010T165634Z_PDInt.root_235524_0_1_20251030T200031Z_detsim_reco1.root
-rw-r--r--. 1 dune osgvo   31299970 Oct 30 17:29 Pandora_Events.pndr
-rw-r--r--. 1 dune osgvo          0 Oct 30 17:01 debugprod.log
-rw-r--r--. 1 dune osgvo        519 Oct 30 17:00 detsim_single_protodunehd_hist.root
-rw-r--r--. 1 dune osgvo 6053429416 Oct 30 17:00 temp_detsim.root
-rw-r--r--. 1 dune osgvo        122 Oct 30 15:00 all-input-dids.txt