Jobsub ID 268756.1@dunegpschedd01.fnal.gov

Jobsub ID	268756.1@dunegpschedd01.fnal.gov
Workflow ID	11235
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-17 00:36:57
Site	US_PuertoRico
Entry	CMSHTPC_T3_US_PuertoRico_UPRM
Last heartbeat	2025-12-17 02:37:26
From worker node	Hostname	compute-1-1.local
	cpuinfo	Intel(R) Xeon(R) CPU W3550 @ 3.07GHz
	OS release	Scientific Linux release 7.9 (Nitrogen)
	Processors	1
	RSS bytes	10485760000 (10000 MiB)
	Wall seconds limit	171000 (47 hours)
	GPU
	Inner Apptainer?	True
Job state	finished
Started	2025-12-17 00:38:12
Input files	usertests:pdhd_prod_beam__261613_26_1_20251212T161232Z_gen_g4_IonScintPDExt.root_262728_46_1_20251215T220005Z_PDInt.root
Jobscript	Exit code	0
	Real time	1h (6977s)
	CPU time	1h (6548s = 93%)
	Max RSS bytes	6653427712 (6345 MiB)
Outputting started	2025-12-17 02:34:29
Output files	usertests:pdhd_prod_beam__261613_26_1_20251212T161232Z_gen_g4_IonScintPDExt.root_262728_46_1_20251215T220005Z_PDInt.root_268756_1_1_20251217T003821Z_detsim_reco1.root
Finished	2025-12-17 02:37:26
Saved logs	justin-logs:268756.1-dunegpschedd01.fnal.gov.logs.tgz
List job events Cached HTCondor job logs

Jobscript log (last 10,000 characters)

_nf> call=18 input 0: frame: ident=199 time=0 tick=512 with 35063 traces.  frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss0":16971 [0] "wiener0":18092 [18092] ] cmm:[ bad:0 lf_noisy:30 ] input 1: frame: ident=199 time=0 tick=512 with 32104 traces.  frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss1":14945 [0] "wiener1":17159 [17159] ] cmm:[ bad:0 ] input 2: frame: ident=199 time=0 tick=512 with 52788 traces.  frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss2":21189 [0] "wiener2":31599 [31599] ] cmm:[ bad:0 ] input 3: frame: ident=199 time=0 tick=512 with 35907 traces.  frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss3":15816 [0] "wiener3":20091 [20091] ] cmm:[ bad:0 ] output: frame: ident=199 time=0 tick=512 with 155862 traces.  frame tags:[ "framefanin" ] 8 tagged trace sets:[ "gauss0":16971 [0] "gauss1":14945 [0] "gauss2":21189 [0] "gauss3":15816 [0] "wiener0":18092 [18092] "wiener1":17159 [17159] "wiener2":31599 [31599] "wiener3":20091 [20091] ] cmm:[ bad:0 lf_noisy:30 ] 
Retagger: tagging trace set: wiener with 86941 traces, 86941 summary
Retagger: tagging trace set: gauss with 68921 traces, 0 summary
[22:33:03.971] D [  glue  ] sink frame: #199 @0 with 155862 traces, frame tags:[retagger], trace tags:[gauss, wiener]
[22:33:03.971] D [  glue  ] <FrameFanout:sn_mag_nf> call=19: see EOS 
[22:33:03.971] D [  glue  ] <ChannelSelector:chsel3> see EOS at call=9 
[22:33:03.971] D [sigproc ] <OmnibusNoiseFilter:nf3> EOS at call=19 
[22:33:03.971] D [sigproc ] <OmnibusSigProc:apa3sigproc3> EOS at call=19 anode=3 
[22:33:03.971] D [  glue  ] <ChannelSelector:chsel2> see EOS at call=9 
[22:33:03.971] D [sigproc ] <OmnibusNoiseFilter:nf2> EOS at call=19 
[22:33:03.971] D [sigproc ] <OmnibusSigProc:apa2sigproc2> EOS at call=19 anode=2 
[22:33:03.971] D [  glue  ] <ChannelSelector:chsel1> see EOS at call=9 
[22:33:03.971] D [sigproc ] <OmnibusNoiseFilter:nf1> EOS at call=19 
[22:33:03.972] D [sigproc ] <OmnibusSigProc:apa1sigproc1> EOS at call=19 anode=1 
[22:33:03.972] D [  glue  ] <ChannelSelector:chsel0> see EOS at call=9 
[22:33:03.972] D [sigproc ] <OmnibusNoiseFilter:nf0> EOS at call=19 
[22:33:03.972] D [sigproc ] <OmnibusSigProc:apa0sigproc0> EOS at call=19 anode=0 
[22:33:03.972] D [  glue  ] <FrameFanin:sn_mag_nf> EOS at call=19 with 4 
[22:33:03.972] D [  glue  ] frame sink sees EOS
[22:33:03.972] D [ pgraph ] <Pgrapher:> graph execution complete 
[22:33:03.972] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 19.52 sec
[22:33:03.972] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 13.89 sec
[22:33:03.972] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 13.25 sec
[22:33:03.972] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 13.23 sec
[22:33:03.972] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 3.99 sec
[22:33:03.972] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 3.97 sec
[22:33:03.972] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 3.92 sec
[22:33:03.972] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 3.91 sec
[22:33:03.972] I [ timer  ] Timer: WireCell::Gen::FrameFanin : 0.02 sec
[22:33:03.972] I [ timer  ] Timer: WireCell::Gen::Retagger : 0.02 sec
[22:33:03.972] I [ timer  ] Timer: wcls::FrameSaver : 0 sec
[22:33:03.972] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[22:33:03.972] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[22:33:03.972] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[22:33:03.972] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[22:33:03.972] I [ timer  ] Timer: WireCell::Gen::FrameFanout : 0 sec
[22:33:03.972] I [ timer  ] Timer: wcls::RawFrameSource : 0 sec
[22:33:03.972] I [ timer  ] Timer: WireCell::Gen::DumpFrames : 0 sec
[22:33:03.972] I [ timer  ] Timer: Total node execution : 75.72000054270029 sec
wclsFrameSaver saving cooked to 6000 ticks
wclsFrameSaver: saving 68921 traces tagged "gauss"
FrameSaver: q=2.19351e+06 n=1138808 tag=gauss
wclsFrameSaver: saving 86941 traces tagged "wiener"
FrameSaver: q=2.6251e+06 n=1121548 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:2 8690 XUs and 8712 XVs -> 375 XUVs
C:0 T:4 6 XUs and 13 XVs -> 0 XUVs
C:0 T:5 26335 XUs and 23631 XVs -> 1103 XUVs
C:0 T:6 9994 XUs and 13237 XVs -> 1097 XUVs
C:0 T:7 11 XUs and 7 XVs -> 0 XUVs
2575 XUVs total
1223 collection wire objects
2575 potential space points
Neighbour search...
44733 tests to find 25598 neighbours
Iterating with no regularization...
Begin: 2.66513e+07
0 2.55803e+07
1 2.55272e+07
2 2.55216e+07
Now with regularization...
Begin: 2.38958e+07
0 2.38945e+07
16-Dec-2025 22:34:26 AST  Closed output file "pdhd_prod_beam__261613_26_1_20251212T161232Z_gen_g4_IonScintPDExt.root_262728_46_1_20251215T220005Z_PDInt.root_268756_1_1_20251217T003821Z_detsim_reco1.root"
16-Dec-2025 22:34:26 AST  Closed input file "temp_detsim.root"

=====================================================================================================================================
TimeTracker printout (sec)                             Min           Avg           Max         Median          RMS         nEvts   
=====================================================================================================================================
Full event                                           131.041       150.579       176.426       151.999       11.9946        10     
-------------------------------------------------------------------------------------------------------------------------------------
source:RootInput(read)                             0.000730191   0.00304674    0.00476694    0.00320977    0.00122561       10     
reco:wclsdatahd:WireCellToolkit                      65.2416       74.1335       77.3519       74.7765       3.3872         10     
reco:wirefilter:WireFilter                          0.017307      0.0200612     0.0268365     0.0196479    0.00256727       10     
reco:gaushit:GausHitFinder                          0.549584      0.806317       1.12645      0.774605      0.172687        10     
reco:nhitsfilter:NumberOfHitsFilter                0.000214075   0.000323576   0.000427176   0.000308193   7.05287e-05      10     
reco:reco3d:SpacePointSolver                        0.229179       0.37252      0.557706      0.333736      0.116805        10     
reco:hitpdune:DisambigFromSpacePoints               0.395668      0.603479       1.25847      0.540506      0.246455        10     
reco:pandora:StandardPandora                         5.56665       9.56179       17.6627       8.35295       3.33798        10     
reco:pandoraWriter:StandardPandora                  0.141835      0.181461      0.254354      0.178677      0.0284803       10     
reco:pandoraTrack:LArPandoraTrackCreation           0.570098      0.951955       1.86653      0.898579      0.347358        10     
reco:pandoraShower:LArPandoraShowerCreation          0.56514      0.924158       1.79944      0.844164      0.340758        10     
reco:pandoracalo:Calorimetry                        0.366077      0.535583      0.895537      0.520209      0.145585        10     
reco:pandoracalonosce:Calorimetry                   0.360292      0.521475      0.869707      0.502803      0.140254        10     
reco:pandoraShowercalo:ShowerCalorimetry            0.577166      0.946518       1.72392      0.895673      0.325246        10     
reco:pandoraShowercalonosce:ShowerCalorimetry       0.559246      0.935377        1.704       0.888859      0.322317        10     
reco:pandoraGnocchiCalo:GnocchiCalorimetry          0.0386804     0.0494002     0.0672033     0.0474215    0.00773099       10     
reco:pandoraGnocchiCalonosce:GnocchiCalorimetry     0.0387932     0.0493414     0.0702327     0.0477946    0.00862966       10     
reco:emtrkmichelid:EmTrackMichelId                   44.3304       58.719        72.2038       60.0295       6.93494        10     
[art]:TriggerResults:TriggerResultInserter         1.9945e-05    2.43627e-05   6.0441e-05    2.03165e-05   1.20314e-05      10     
end_path:out1:RootOutput                             4.1e-06     7.1117e-06    2.0423e-05    4.1985e-06    5.89185e-06      10     
end_path:out1:RootOutput(write)                     0.992181       1.22697       1.74762       1.15165      0.224359        10     
=====================================================================================================================================

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

  Peak virtual memory usage (VmPeak)  : 5646.31 MB
  Peak resident set size usage (VmHWM): 3252.65 MB
  Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Reco returns 0
.:
total 11546008
-rw-r--r-- 1 dunepilot gridusers     231180 Dec 16 22:34 jobscript.log
-rw-r--r-- 1 dunepilot gridusers        194 Dec 16 22:34 justin-processed-pfns.txt
-rw-r--r-- 1 dunepilot gridusers        519 Dec 16 22:34 reco_protodunehd_hist.root
-rw-r--r-- 1 dunepilot gridusers       3574 Dec 16 22:34 Pandora_Geometry.xml
-rw-r--r-- 1 dunepilot gridusers     139264 Dec 16 22:34 mem.db
-rw-r--r-- 1 dunepilot gridusers      28672 Dec 16 22:34 time.db
-rw-r--r-- 1 dunepilot gridusers 5984524975 Dec 16 22:34 pdhd_prod_beam__261613_26_1_20251212T161232Z_gen_g4_IonScintPDExt.root_262728_46_1_20251215T220005Z_PDInt.root_268756_1_1_20251217T003821Z_detsim_reco1.root
-rw-r--r-- 1 dunepilot gridusers   33784210 Dec 16 22:33 Pandora_Events.pndr
-rw-r--r-- 1 dunepilot gridusers          0 Dec 16 22:06 debugprod.log
-rw-r--r-- 1 dunepilot gridusers        519 Dec 16 22:06 detsim_single_protodunehd_hist.root
-rw-r--r-- 1 dunepilot gridusers 5804353406 Dec 16 22:06 temp_detsim.root
-rw-r--r-- 1 dunepilot gridusers        121 Dec 16 20:38 all-input-dids.txt