Jobsub ID 269119.109@dunegpschedd01.fnal.gov

Jobsub ID	269119.109@dunegpschedd01.fnal.gov
Workflow ID	11264
Stage ID	1
User name	avizcaya@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-12-18 19:29:50
Site	US_UChicago
Entry	Engage_US_MWT2_uiuc_gk02_condce_mcore
Last heartbeat	2025-12-18 23:08:04
From worker node	Hostname	uct2-c493.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-18 20:49:24
Input files	usertests:pdhd_prod_beam__267378_13_1_20251212T160737Z_gen_g4_IonScintPDExt.root_268535_6_1_20251215T213059Z_PDInt.root
Jobscript	Exit code	0
	Real time	2h (8149s)
	CPU time	2h (7994s = 98%)
	Max RSS bytes	6752030720 (6439 MiB)
Outputting started	2025-12-18 23:05:14
Output files	usertests:pdhd_prod_beam__267378_13_1_20251212T160737Z_gen_g4_IonScintPDExt.root_268535_6_1_20251215T213059Z_PDInt.root_269119_109_1_20251218T204932Z_detsim_reco1.root
Finished	2025-12-18 23:08:04
Saved logs	justin-logs:269119.109-dunegpschedd01.fnal.gov.logs.tgz
List job events Cached HTCondor job logs

Jobscript log (last 10,000 characters)

0678] ] cmm:[ bad:0 lf_noisy:253 ] 
[17:03:53.668] D [  glue  ] <FrameFanin:sn_mag_nf> call=18 input 0: frame: ident=179 time=0 tick=512 with 59137 traces.  frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss0":28459 [0] "wiener0":30678 [30678] ] cmm:[ bad:0 lf_noisy:253 ] input 1: frame: ident=179 time=0 tick=512 with 41551 traces.  frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss1":18417 [0] "wiener1":23134 [23134] ] cmm:[ bad:0 lf_noisy:7 ] input 2: frame: ident=179 time=0 tick=512 with 53968 traces.  frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss2":23772 [0] "wiener2":30196 [30196] ] cmm:[ bad:0 ] input 3: frame: ident=179 time=0 tick=512 with 29518 traces.  frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss3":13870 [0] "wiener3":15648 [15648] ] cmm:[ bad:0 ] output: frame: ident=179 time=0 tick=512 with 184174 traces.  frame tags:[ "framefanin" ] 8 tagged trace sets:[ "gauss0":28459 [0] "gauss1":18417 [0] "gauss2":23772 [0] "gauss3":13870 [0] "wiener0":30678 [30678] "wiener1":23134 [23134] "wiener2":30196 [30196] "wiener3":15648 [15648] ] cmm:[ bad:0 lf_noisy:260 ] 
Retagger: tagging trace set: wiener with 99656 traces, 99656 summary
Retagger: tagging trace set: gauss with 84518 traces, 0 summary
[17:03:53.695] D [  glue  ] sink frame: #179 @0 with 184174 traces, frame tags:[retagger], trace tags:[gauss, wiener]
[17:03:53.695] D [  glue  ] <FrameFanout:sn_mag_nf> call=19: see EOS 
[17:03:53.695] D [  glue  ] <ChannelSelector:chsel3> see EOS at call=9 
[17:03:53.695] D [sigproc ] <OmnibusNoiseFilter:nf3> EOS at call=19 
[17:03:53.695] D [sigproc ] <OmnibusSigProc:apa3sigproc3> EOS at call=19 anode=3 
[17:03:53.695] D [  glue  ] <ChannelSelector:chsel2> see EOS at call=9 
[17:03:53.695] D [sigproc ] <OmnibusNoiseFilter:nf2> EOS at call=19 
[17:03:53.695] D [sigproc ] <OmnibusSigProc:apa2sigproc2> EOS at call=19 anode=2 
[17:03:53.695] D [  glue  ] <ChannelSelector:chsel1> see EOS at call=9 
[17:03:53.695] D [sigproc ] <OmnibusNoiseFilter:nf1> EOS at call=19 
[17:03:53.695] D [sigproc ] <OmnibusSigProc:apa1sigproc1> EOS at call=19 anode=1 
[17:03:53.695] D [  glue  ] <ChannelSelector:chsel0> see EOS at call=9 
[17:03:53.695] D [sigproc ] <OmnibusNoiseFilter:nf0> EOS at call=19 
[17:03:53.695] D [sigproc ] <OmnibusSigProc:apa0sigproc0> EOS at call=19 anode=0 
[17:03:53.696] D [  glue  ] <FrameFanin:sn_mag_nf> EOS at call=19 with 4 
[17:03:53.696] D [  glue  ] frame sink sees EOS
[17:03:53.696] D [ pgraph ] <Pgrapher:> graph execution complete 
[17:03:53.696] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 15.54 sec
[17:03:53.696] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 11.6 sec
[17:03:53.696] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 10.51 sec
[17:03:53.696] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 10.02 sec
[17:03:53.696] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 3.07 sec
[17:03:53.696] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 3 sec
[17:03:53.696] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.76 sec
[17:03:53.696] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.73 sec
[17:03:53.696] I [ timer  ] Timer: WireCell::Gen::FrameFanin : 0.04 sec
[17:03:53.696] I [ timer  ] Timer: WireCell::Gen::Retagger : 0.01 sec
[17:03:53.696] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[17:03:53.696] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[17:03:53.696] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[17:03:53.696] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[17:03:53.696] I [ timer  ] Timer: WireCell::Gen::FrameFanout : 0 sec
[17:03:53.696] I [ timer  ] Timer: WireCell::Gen::DumpFrames : 0 sec
[17:03:53.696] I [ timer  ] Timer: wcls::RawFrameSource : 0 sec
[17:03:53.696] I [ timer  ] Timer: wcls::FrameSaver : 0 sec
[17:03:53.696] I [ timer  ] Timer: Total node execution : 59.280000971630216 sec
wclsFrameSaver saving cooked to 6000 ticks
wclsFrameSaver: saving 84518 traces tagged "gauss"
FrameSaver: q=2.85334e+06 n=1414244 tag=gauss
wclsFrameSaver: saving 99656 traces tagged "wiener"
FrameSaver: q=3.89621e+06 n=1408596 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:2 24038 XUs and 30830 XVs -> 786 XUVs
C:0 T:3 28 XUs and 25 XVs -> 2 XUVs
C:0 T:5 47737 XUs and 55440 XVs -> 1840 XUVs
C:0 T:6 8938 XUs and 10312 XVs -> 463 XUVs
C:0 T:7 3 XUs and 5 XVs -> 0 XUVs
3091 XUVs total
1864 collection wire objects
3091 potential space points
Neighbour search...
110129 tests to find 44028 neighbours
Iterating with no regularization...
Begin: 4.41307e+07
0 3.95988e+07
1 3.93071e+07
2 3.92813e+07
Now with regularization...
Begin: 3.61383e+07
0 3.61244e+07
18-Dec-2025 17:05:12 CST  Closed output file "pdhd_prod_beam__267378_13_1_20251212T160737Z_gen_g4_IonScintPDExt.root_268535_6_1_20251215T213059Z_PDInt.root_269119_109_1_20251218T204932Z_detsim_reco1.root"
18-Dec-2025 17:05:12 CST  Closed input file "temp_detsim.root"

=====================================================================================================================================
TimeTracker printout (sec)                             Min           Avg           Max         Median          RMS         nEvts   
=====================================================================================================================================
Full event                                           121.446       142.195       200.543       137.04        21.383         10     
-------------------------------------------------------------------------------------------------------------------------------------
source:RootInput(read)                             0.000839262   0.00421772    0.00817973    0.00387554    0.00200224       10     
reco:wclsdatahd:WireCellToolkit                      61.0739       77.9944       86.5474       78.8624       6.8248         10     
reco:wirefilter:WireFilter                          0.0324243     0.0449037     0.0607061     0.0454334    0.00722843       10     
reco:gaushit:GausHitFinder                          0.706398      0.978689       1.62893      0.965011      0.258897        10     
reco:nhitsfilter:NumberOfHitsFilter                0.000360788   0.000481574   0.000828027   0.000438715   0.000135405      10     
reco:reco3d:SpacePointSolver                        0.372699      0.765662       1.69685      0.550374      0.426047        10     
reco:hitpdune:DisambigFromSpacePoints               0.378094      0.912888       2.62128      0.726416      0.632833        10     
reco:pandora:StandardPandora                         6.47667       14.8735       43.7121       11.7222       10.1239        10     
reco:pandoraWriter:StandardPandora                  0.165797       0.30294       0.4726       0.301137      0.0864081       10     
reco:pandoraTrack:LArPandoraTrackCreation            1.05372       2.82843       5.80002       2.77829       1.23796        10     
reco:pandoraShower:LArPandoraShowerCreation          1.31837       2.65178       6.05068       2.2335        1.32459        10     
reco:pandoracalo:Calorimetry                        0.759611       1.41169       2.83751       1.2528       0.580613        10     
reco:pandoracalonosce:Calorimetry                   0.689529       1.3382        2.75087       1.16555      0.543273        10     
reco:pandoraShowercalo:ShowerCalorimetry             0.96566       2.20692       5.13377       1.89923       1.12374        10     
reco:pandoraShowercalonosce:ShowerCalorimetry        0.76317       2.3889        5.13366       2.04056       1.37034        10     
reco:pandoraGnocchiCalo:GnocchiCalorimetry          0.0384122     0.0801445     0.106011      0.0798294     0.0210903       10     
reco:pandoraGnocchiCalonosce:GnocchiCalorimetry     0.0392684     0.0784324     0.104427      0.0786799     0.0197671       10     
reco:emtrkmichelid:EmTrackMichelId                   23.5692       31.4291       40.9747       29.4631       6.18472        10     
[art]:TriggerResults:TriggerResultInserter          2.67e-05     6.07806e-05   9.6188e-05    6.5092e-05    1.97127e-05      10     
end_path:out1:RootOutput                            6.662e-06    1.15267e-05   2.5555e-05    9.6635e-06    5.03624e-06      10     
end_path:out1:RootOutput(write)                     0.949318       1.82124       2.81799       1.82228      0.465881        10     
=====================================================================================================================================

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

  Peak virtual memory usage (VmPeak)  : 5822.99 MB
  Peak resident set size usage (VmHWM): 3633.7 MB
  Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Reco returns 0
.:
total 11765488
-rw-r--r--. 1 dune osgvo     231427 Dec 18 17:05 jobscript.log
-rw-r--r--. 1 dune osgvo        199 Dec 18 17:05 justin-processed-pfns.txt
-rw-r--r--. 1 dune osgvo        519 Dec 18 17:05 reco_protodunehd_hist.root
-rw-r--r--. 1 dune osgvo       3574 Dec 18 17:05 Pandora_Geometry.xml
-rw-r--r--. 1 dune osgvo     139264 Dec 18 17:05 mem.db
-rw-r--r--. 1 dune osgvo      28672 Dec 18 17:05 time.db
-rw-r--r--. 1 dune osgvo 6098790779 Dec 18 17:05 pdhd_prod_beam__267378_13_1_20251212T160737Z_gen_g4_IonScintPDExt.root_268535_6_1_20251215T213059Z_PDInt.root_269119_109_1_20251218T204932Z_detsim_reco1.root
-rw-r--r--. 1 dune osgvo   34744070 Dec 18 17:04 Pandora_Events.pndr
-rw-r--r--. 1 dune osgvo          0 Dec 18 16:39 debugprod.log
-rw-r--r--. 1 dune osgvo        519 Dec 18 16:38 detsim_single_protodunehd_hist.root
-rw-r--r--. 1 dune osgvo 5913875238 Dec 18 16:38 temp_detsim.root
-rw-r--r--. 1 dune osgvo        120 Dec 18 14:49 all-input-dids.txt