Jobsub ID 263305.14@dunegpschedd02.fnal.gov

Jobsub ID	263305.14@dunegpschedd02.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:31:07
Site	US_UChicago
Entry	Engage_US_MWT2_uct2_condce_mcore
Last heartbeat	2025-12-18 22:00:21
From worker node	Hostname	uct2-c511.mwt2.org
	cpuinfo	Intel(R) Xeon(R) Gold 6242 CPU @ 2.80GHz
	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:30:20
Input files	usertests:pdhd_prod_beam__261612_82_1_20251212T160138Z_gen_g4_IonScintPDExt.root_263290_1_1_20251218T172800Z_PDInt.root
Jobscript	Exit code	0
	Real time	1h (5295s)
	CPU time	1h (5110s = 96%)
	Max RSS bytes	6856024064 (6538 MiB)
Outputting started	2025-12-18 21:58:36
Output files	usertests:pdhd_prod_beam__261612_82_1_20251212T160138Z_gen_g4_IonScintPDExt.root_263290_1_1_20251218T172800Z_PDInt.root_263305_14_1_20251218T203026Z_detsim_reco1.root
Finished	2025-12-18 22:00:12
Saved logs	justin-logs:263305.14-dunegpschedd02.fnal.gov.logs.tgz
List job events Cached HTCondor job logs

Jobscript log (last 10,000 characters)

s:[ "gauss0":27262 [0] "wiener0":31276 [31276] ] cmm:[ bad:0 lf_noisy:61 ] 
[15:58:02.467] D [  glue  ] <FrameFanin:sn_mag_nf> call=18 input 0: frame: ident=179 time=0 tick=512 with 58538 traces.  frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss0":27262 [0] "wiener0":31276 [31276] ] cmm:[ bad:0 lf_noisy:61 ] input 1: frame: ident=179 time=0 tick=512 with 36576 traces.  frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss1":15839 [0] "wiener1":20737 [20737] ] cmm:[ bad:0 ] input 2: frame: ident=179 time=0 tick=512 with 40470 traces.  frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss2":17557 [0] "wiener2":22913 [22913] ] cmm:[ bad:0 ] input 3: frame: ident=179 time=0 tick=512 with 38391 traces.  frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss3":16672 [0] "wiener3":21719 [21719] ] cmm:[ bad:0 ] output: frame: ident=179 time=0 tick=512 with 173975 traces.  frame tags:[ "framefanin" ] 8 tagged trace sets:[ "gauss0":27262 [0] "gauss1":15839 [0] "gauss2":17557 [0] "gauss3":16672 [0] "wiener0":31276 [31276] "wiener1":20737 [20737] "wiener2":22913 [22913] "wiener3":21719 [21719] ] cmm:[ bad:0 lf_noisy:61 ] 
Retagger: tagging trace set: wiener with 96645 traces, 96645 summary
Retagger: tagging trace set: gauss with 77330 traces, 0 summary
[15:58:02.497] D [  glue  ] sink frame: #179 @0 with 173975 traces, frame tags:[retagger], trace tags:[gauss, wiener]
[15:58:02.497] D [  glue  ] <FrameFanout:sn_mag_nf> call=19: see EOS 
[15:58:02.497] D [  glue  ] <ChannelSelector:chsel3> see EOS at call=9 
[15:58:02.497] D [sigproc ] <OmnibusNoiseFilter:nf3> EOS at call=19 
[15:58:02.497] D [sigproc ] <OmnibusSigProc:apa3sigproc3> EOS at call=19 anode=3 
[15:58:02.497] D [  glue  ] <ChannelSelector:chsel2> see EOS at call=9 
[15:58:02.497] D [sigproc ] <OmnibusNoiseFilter:nf2> EOS at call=19 
[15:58:02.497] D [sigproc ] <OmnibusSigProc:apa2sigproc2> EOS at call=19 anode=2 
[15:58:02.497] D [  glue  ] <ChannelSelector:chsel1> see EOS at call=9 
[15:58:02.497] D [sigproc ] <OmnibusNoiseFilter:nf1> EOS at call=19 
[15:58:02.497] D [sigproc ] <OmnibusSigProc:apa1sigproc1> EOS at call=19 anode=1 
[15:58:02.497] D [  glue  ] <ChannelSelector:chsel0> see EOS at call=9 
[15:58:02.497] D [sigproc ] <OmnibusNoiseFilter:nf0> EOS at call=19 
[15:58:02.497] D [sigproc ] <OmnibusSigProc:apa0sigproc0> EOS at call=19 anode=0 
[15:58:02.497] D [  glue  ] <FrameFanin:sn_mag_nf> EOS at call=19 with 4 
[15:58:02.497] D [  glue  ] frame sink sees EOS
[15:58:02.497] D [ pgraph ] <Pgrapher:> graph execution complete 
[15:58:02.497] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 21.92 sec
[15:58:02.497] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 13.88 sec
[15:58:02.497] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 13.52 sec
[15:58:02.497] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 12.76 sec
[15:58:02.497] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 3.69 sec
[15:58:02.497] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 3.67 sec
[15:58:02.497] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 3.52 sec
[15:58:02.497] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 3.34 sec
[15:58:02.497] I [ timer  ] Timer: WireCell::Gen::FrameFanin : 0.04 sec
[15:58:02.497] I [ timer  ] Timer: WireCell::Gen::Retagger : 0.02 sec
[15:58:02.497] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[15:58:02.497] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[15:58:02.497] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[15:58:02.497] I [ timer  ] Timer: WireCell::Gen::FrameFanout : 0 sec
[15:58:02.497] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[15:58:02.497] I [ timer  ] Timer: wcls::RawFrameSource : 0 sec
[15:58:02.497] I [ timer  ] Timer: wcls::FrameSaver : 0 sec
[15:58:02.497] I [ timer  ] Timer: WireCell::Gen::DumpFrames : 0 sec
[15:58:02.497] I [ timer  ] Timer: Total node execution : 76.39000090397894 sec
wclsFrameSaver saving cooked to 6000 ticks
wclsFrameSaver: saving 77330 traces tagged "gauss"
FrameSaver: q=2.35156e+06 n=1228169 tag=gauss
wclsFrameSaver: saving 96645 traces tagged "wiener"
FrameSaver: q=2.98726e+06 n=1194204 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:2 16503 XUs and 22861 XVs -> 271 XUVs
C:0 T:4 17 XUs and 6 XVs -> 0 XUVs
C:0 T:5 28005 XUs and 19214 XVs -> 721 XUVs
C:0 T:6 10740 XUs and 24131 XVs -> 401 XUVs
1393 XUVs total
950 collection wire objects
1393 potential space points
Neighbour search...
21417 tests to find 12588 neighbours
Iterating with no regularization...
Begin: 1.51993e+07
0 1.45081e+07
1 1.44719e+07
2 1.44673e+07
Now with regularization...
Begin: 1.36219e+07
0 1.36204e+07
18-Dec-2025 15:58:35 CST  Closed output file "pdhd_prod_beam__261612_82_1_20251212T160138Z_gen_g4_IonScintPDExt.root_263290_1_1_20251218T172800Z_PDInt.root_263305_14_1_20251218T203026Z_detsim_reco1.root"
18-Dec-2025 15:58:35 CST  Closed input file "temp_detsim.root"

=====================================================================================================================================
TimeTracker printout (sec)                             Min           Avg           Max         Median          RMS         nEvts   
=====================================================================================================================================
Full event                                           98.597        112.338       139.519       111.272       12.177         10     
-------------------------------------------------------------------------------------------------------------------------------------
source:RootInput(read)                             0.00133879    0.00494667    0.00838218    0.00483064    0.00271115       10     
reco:wclsdatahd:WireCellToolkit                      76.573        79.6805       83.1168       79.0644       2.11208        10     
reco:wirefilter:WireFilter                          0.0178022     0.0354839     0.0519909     0.0353656    0.00881174       10     
reco:gaushit:GausHitFinder                          0.290167      0.730109       1.19214      0.742412      0.233437        10     
reco:nhitsfilter:NumberOfHitsFilter                0.000266761   0.000376596   0.000573584   0.000385316   8.39222e-05      10     
reco:reco3d:SpacePointSolver                        0.157985      0.542593       1.63681      0.382776      0.425304        10     
reco:hitpdune:DisambigFromSpacePoints               0.127196       0.56257       1.43842      0.432442      0.392711        10     
reco:pandora:StandardPandora                         4.83422       10.1507       21.4799       8.77992       4.60137        10     
reco:pandoraWriter:StandardPandora                  0.133344      0.220926      0.397003      0.197236      0.0757442       10     
reco:pandoraTrack:LArPandoraTrackCreation           0.589499       1.39804       2.87584       1.22482      0.729737        10     
reco:pandoraShower:LArPandoraShowerCreation         0.373835       1.31278       3.25653       1.15665      0.876927        10     
reco:pandoracalo:Calorimetry                        0.193956      0.717362       1.50071      0.610748      0.384195        10     
reco:pandoracalonosce:Calorimetry                   0.230979      0.648996       1.20623      0.577305       0.30948        10     
reco:pandoraShowercalo:ShowerCalorimetry            0.259825       1.21403       3.1163        1.16215      0.828807        10     
reco:pandoraShowercalonosce:ShowerCalorimetry       0.291152       1.21703       3.22948       1.18487      0.856954        10     
reco:pandoraGnocchiCalo:GnocchiCalorimetry          0.0276032     0.0589308     0.107573      0.053632      0.0230628       10     
reco:pandoraGnocchiCalonosce:GnocchiCalorimetry     0.0279529     0.061796      0.106296      0.0662868     0.0230656       10     
reco:emtrkmichelid:EmTrackMichelId                   8.88019       12.3083       18.9815       12.161        3.15329        10     
[art]:TriggerResults:TriggerResultInserter         3.1785e-05    4.91406e-05   0.000134552   3.9813e-05    2.92229e-05      10     
end_path:out1:RootOutput                             6.2e-06     1.13619e-05   3.3184e-05     8.575e-06    7.5754e-06       10     
end_path:out1:RootOutput(write)                     0.927145       1.40868       2.26865       1.43225      0.375357        10     
=====================================================================================================================================

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

  Peak virtual memory usage (VmPeak)  : 6085.06 MB
  Peak resident set size usage (VmHWM): 3667.1 MB
  Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Reco returns 0
.:
total 11011180
-rw-r--r--. 1 dune osgvo     232202 Dec 18 15:58 jobscript.log
-rw-r--r--. 1 dune osgvo        193 Dec 18 15:58 justin-processed-pfns.txt
-rw-r--r--. 1 dune osgvo        519 Dec 18 15:58 reco_protodunehd_hist.root
-rw-r--r--. 1 dune osgvo       3574 Dec 18 15:58 Pandora_Geometry.xml
-rw-r--r--. 1 dune osgvo     139264 Dec 18 15:58 mem.db
-rw-r--r--. 1 dune osgvo      28672 Dec 18 15:58 time.db
-rw-r--r--. 1 dune osgvo 5708579046 Dec 18 15:58 pdhd_prod_beam__261612_82_1_20251212T160138Z_gen_g4_IonScintPDExt.root_263290_1_1_20251218T172800Z_PDInt.root_263305_14_1_20251218T203026Z_detsim_reco1.root
-rw-r--r--. 1 dune osgvo   30537010 Dec 18 15:58 Pandora_Events.pndr
-rw-r--r--. 1 dune osgvo          0 Dec 18 15:37 debugprod.log
-rw-r--r--. 1 dune osgvo        519 Dec 18 15:37 detsim_single_protodunehd_hist.root
-rw-r--r--. 1 dune osgvo 5535879540 Dec 18 15:37 temp_detsim.root
-rw-r--r--. 1 dune osgvo        120 Dec 18 14:30 all-input-dids.txt