Jobsub ID 268759.1@dunegpschedd01.fnal.gov

Jobsub ID	268759.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:50:58
Site	US_PuertoRico
Entry	CMSHTPC_T3_US_PuertoRico_UPRM
Last heartbeat	2025-12-17 03:08:52
From worker node	Hostname	compute-0-5.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:52:24
Input files	usertests:pdhd_prod_beam__261613_97_1_20251212T161514Z_gen_g4_IonScintPDExt.root_262784_1_1_20251216T013525Z_PDInt.root
Jobscript	Exit code	0
	Real time	2h (8001s)
	CPU time	2h (7451s = 93%)
	Max RSS bytes	6861955072 (6544 MiB)
Outputting started	2025-12-17 03:05:46
Output files	usertests:pdhd_prod_beam__261613_97_1_20251212T161514Z_gen_g4_IonScintPDExt.root_262784_1_1_20251216T013525Z_PDInt.root_268759_1_1_20251217T005300Z_detsim_reco1.root
Finished	2025-12-17 03:08:52
Saved logs	justin-logs:268759.1-dunegpschedd01.fnal.gov.logs.tgz
List job events Cached HTCondor job logs

Jobscript log (last 10,000 characters)

512 with 62611 traces.  frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss0":29129 [0] "wiener0":33482 [33482] ] cmm:[ bad:0 lf_noisy:88 ] input 1: frame: ident=199 time=0 tick=512 with 51253 traces.  frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss1":21701 [0] "wiener1":29552 [29552] ] cmm:[ bad:0 ] input 2: frame: ident=199 time=0 tick=512 with 52930 traces.  frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss2":22704 [0] "wiener2":30226 [30226] ] cmm:[ bad:0 lf_noisy:3 ] input 3: frame: ident=199 time=0 tick=512 with 40690 traces.  frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss3":17859 [0] "wiener3":22831 [22831] ] cmm:[ bad:0 ] output: frame: ident=199 time=0 tick=512 with 207484 traces.  frame tags:[ "framefanin" ] 8 tagged trace sets:[ "gauss0":29129 [0] "gauss1":21701 [0] "gauss2":22704 [0] "gauss3":17859 [0] "wiener0":33482 [33482] "wiener1":29552 [29552] "wiener2":30226 [30226] "wiener3":22831 [22831] ] cmm:[ bad:0 lf_noisy:91 ] 
Retagger: tagging trace set: wiener with 116091 traces, 116091 summary
Retagger: tagging trace set: gauss with 91393 traces, 0 summary
[23:03:49.556] D [  glue  ] sink frame: #199 @0 with 207484 traces, frame tags:[retagger], trace tags:[gauss, wiener]
[23:03:49.556] D [  glue  ] <FrameFanout:sn_mag_nf> call=19: see EOS 
[23:03:49.556] D [  glue  ] <ChannelSelector:chsel3> see EOS at call=9 
[23:03:49.556] D [sigproc ] <OmnibusNoiseFilter:nf3> EOS at call=19 
[23:03:49.556] D [sigproc ] <OmnibusSigProc:apa3sigproc3> EOS at call=19 anode=3 
[23:03:49.556] D [  glue  ] <ChannelSelector:chsel2> see EOS at call=9 
[23:03:49.556] D [sigproc ] <OmnibusNoiseFilter:nf2> EOS at call=19 
[23:03:49.556] D [sigproc ] <OmnibusSigProc:apa2sigproc2> EOS at call=19 anode=2 
[23:03:49.556] D [  glue  ] <ChannelSelector:chsel1> see EOS at call=9 
[23:03:49.556] D [sigproc ] <OmnibusNoiseFilter:nf1> EOS at call=19 
[23:03:49.556] D [sigproc ] <OmnibusSigProc:apa1sigproc1> EOS at call=19 anode=1 
[23:03:49.556] D [  glue  ] <ChannelSelector:chsel0> see EOS at call=9 
[23:03:49.556] D [sigproc ] <OmnibusNoiseFilter:nf0> EOS at call=19 
[23:03:49.556] D [sigproc ] <OmnibusSigProc:apa0sigproc0> EOS at call=19 anode=0 
[23:03:49.556] D [  glue  ] <FrameFanin:sn_mag_nf> EOS at call=19 with 4 
[23:03:49.556] D [  glue  ] frame sink sees EOS
[23:03:49.556] D [ pgraph ] <Pgrapher:> graph execution complete 
[23:03:49.556] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 21.35 sec
[23:03:49.557] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 14.61 sec
[23:03:49.557] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 14.56 sec
[23:03:49.557] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 14.09 sec
[23:03:49.557] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 4.04 sec
[23:03:49.557] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 4.04 sec
[23:03:49.557] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 3.96 sec
[23:03:49.557] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 3.94 sec
[23:03:49.557] I [ timer  ] Timer: WireCell::Gen::FrameFanin : 0.04 sec
[23:03:49.557] I [ timer  ] Timer: WireCell::Gen::Retagger : 0.01 sec
[23:03:49.557] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[23:03:49.557] I [ timer  ] Timer: WireCell::Gen::FrameFanout : 0 sec
[23:03:49.557] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[23:03:49.557] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[23:03:49.557] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[23:03:49.557] I [ timer  ] Timer: wcls::RawFrameSource : 0 sec
[23:03:49.557] I [ timer  ] Timer: wcls::FrameSaver : 0 sec
[23:03:49.557] I [ timer  ] Timer: WireCell::Gen::DumpFrames : 0 sec
[23:03:49.557] I [ timer  ] Timer: Total node execution : 80.64000062830746 sec
wclsFrameSaver saving cooked to 6000 ticks
wclsFrameSaver: saving 91393 traces tagged "gauss"
FrameSaver: q=2.78821e+06 n=1449114 tag=gauss
wclsFrameSaver: saving 116091 traces tagged "wiener"
FrameSaver: q=3.7165e+06 n=1383542 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:2 61217 XUs and 55012 XVs -> 1670 XUVs
C:0 T:3 53 XUs and 29 XVs -> 0 XUVs
C:0 T:4 15 XUs and 16 XVs -> 0 XUVs
C:0 T:5 56651 XUs and 48903 XVs -> 1585 XUVs
C:0 T:6 28884 XUs and 25619 XVs -> 619 XUVs
C:0 T:7 7 XUs and 7 XVs -> 0 XUVs
3874 XUVs total
1915 collection wire objects
3874 potential space points
Neighbour search...
136406 tests to find 72286 neighbours
Iterating with no regularization...
Begin: 2.07836e+07
0 1.93469e+07
1 1.92628e+07
2 1.92498e+07
Now with regularization...
Begin: 1.8126e+07
0 1.81219e+07
16-Dec-2025 23:05:42 AST  Closed output file "pdhd_prod_beam__261613_97_1_20251212T161514Z_gen_g4_IonScintPDExt.root_262784_1_1_20251216T013525Z_PDInt.root_268759_1_1_20251217T005300Z_detsim_reco1.root"
16-Dec-2025 23:05:42 AST  Closed input file "temp_detsim.root"

=====================================================================================================================================
TimeTracker printout (sec)                             Min           Avg           Max         Median          RMS         nEvts   
=====================================================================================================================================
Full event                                           142.753       170.72        210.796       163.943       23.2702        10     
-------------------------------------------------------------------------------------------------------------------------------------
source:RootInput(read)                             0.000870842   0.00393462    0.00621152    0.00408792    0.00169004       10     
reco:wclsdatahd:WireCellToolkit                      80.8454       82.9477       86.8056       81.6944       2.04781        10     
reco:wirefilter:WireFilter                          0.0184858     0.0233065     0.0288961     0.0220149    0.00358015       10     
reco:gaushit:GausHitFinder                          0.593105      0.860586       1.17524      0.878965      0.178399        10     
reco:nhitsfilter:NumberOfHitsFilter                0.00023735    0.000353603   0.000575713   0.000316488   0.000108322      10     
reco:reco3d:SpacePointSolver                         0.18157      0.519912       1.34038      0.331657      0.365201        10     
reco:hitpdune:DisambigFromSpacePoints               0.343773      0.722229       1.18904      0.589424      0.305536        10     
reco:pandora:StandardPandora                         5.99022       12.2046       20.189        12.3097       5.22528        10     
reco:pandoraWriter:StandardPandora                  0.149371      0.206144      0.270855      0.195208      0.042781        10     
reco:pandoraTrack:LArPandoraTrackCreation           0.766621       1.26556       1.91742       1.16852       0.40293        10     
reco:pandoraShower:LArPandoraShowerCreation         0.562969       1.25936       1.95369       1.23266      0.509404        10     
reco:pandoracalo:Calorimetry                        0.429422      0.679301      0.979781      0.660855      0.177427        10     
reco:pandoracalonosce:Calorimetry                    0.41109      0.659542       0.9424       0.639794      0.172353        10     
reco:pandoraShowercalo:ShowerCalorimetry            0.592525       1.27658       1.9196        1.32975      0.477059        10     
reco:pandoraShowercalonosce:ShowerCalorimetry        0.58549       1.26254       1.89582       1.31088      0.472106        10     
reco:pandoraGnocchiCalo:GnocchiCalorimetry          0.0403707     0.055817      0.0704455     0.0548538     0.010532        10     
reco:pandoraGnocchiCalonosce:GnocchiCalorimetry     0.0405145     0.0555883     0.0706288     0.0547502     0.0103482       10     
reco:emtrkmichelid:EmTrackMichelId                   48.5817       65.3449       91.1591       61.2543       14.2427        10     
[art]:TriggerResults:TriggerResultInserter          2.693e-05    3.33579e-05   7.8177e-05    2.8743e-05    1.49599e-05      10     
end_path:out1:RootOutput                            5.455e-06    7.3696e-06    2.2778e-05     5.68e-06     5.13759e-06      10     
end_path:out1:RootOutput(write)                      1.01688       1.32718       1.73235       1.27708      0.238764        10     
=====================================================================================================================================

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

  Peak virtual memory usage (VmPeak)  : 6073.38 MB
  Peak resident set size usage (VmHWM): 3674.48 MB
  Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Reco returns 0
.:
total 12399096
-rw-r--r-- 1 dunepilot gridusers     231663 Dec 16 23:05 jobscript.log
-rw-r--r-- 1 dunepilot gridusers        193 Dec 16 23:05 justin-processed-pfns.txt
-rw-r--r-- 1 dunepilot gridusers        519 Dec 16 23:05 reco_protodunehd_hist.root
-rw-r--r-- 1 dunepilot gridusers       3574 Dec 16 23:05 Pandora_Geometry.xml
-rw-r--r-- 1 dunepilot gridusers     139264 Dec 16 23:05 mem.db
-rw-r--r-- 1 dunepilot gridusers      28672 Dec 16 23:05 time.db
-rw-r--r-- 1 dunepilot gridusers 6429077864 Dec 16 23:05 pdhd_prod_beam__261613_97_1_20251212T161514Z_gen_g4_IonScintPDExt.root_262784_1_1_20251216T013525Z_PDInt.root_268759_1_1_20251217T005300Z_detsim_reco1.root
-rw-r--r-- 1 dunepilot gridusers   36913710 Dec 16 23:04 Pandora_Events.pndr
-rw-r--r-- 1 dunepilot gridusers          0 Dec 16 22:33 debugprod.log
-rw-r--r-- 1 dunepilot gridusers        519 Dec 16 22:33 detsim_single_protodunehd_hist.root
-rw-r--r-- 1 dunepilot gridusers 6230233019 Dec 16 22:33 temp_detsim.root
-rw-r--r-- 1 dunepilot gridusers        120 Dec 16 20:53 all-input-dids.txt