Jobsub ID 236805.173@dunegpschedd02.fnal.gov

Jobsub ID	236805.173@dunegpschedd02.fnal.gov
Workflow ID	9567
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-11-03 18:19:10
Site	US_Wisconsin
Entry	HCCHTPC_US_Wisconsin_osg01_rhel7
Last heartbeat	2025-11-03 21:10:28
From worker node	Hostname	e2627
	cpuinfo	AMD EPYC 7763 64-Core Processor
	OS release	Scientific Linux release 7.9 (Nitrogen)
	Processors	1
	RSS bytes	10485760000 (10000 MiB)
	Wall seconds limit	82800 (23 hours)
	GPU
	Inner Apptainer?	True
Job state	finished
Started	2025-11-03 20:03:48
Input files	usertests:pdhd_prod_beam__226699_7_1_20251009T172331Z_gen_g4_IonScintPDExt.root_227040_4_1_20251010T165942Z_PDInt.root
Jobscript	Exit code	0
	Real time	1h (3822s)
	CPU time	1h (3640s = 95%)
	Max RSS bytes	6723096576 (6411 MiB)
Outputting started	2025-11-03 21:07:31
Output files	usertests:pdhd_prod_beam__226699_7_1_20251009T172331Z_gen_g4_IonScintPDExt.root_227040_4_1_20251010T165942Z_PDInt.root_236805_173_1_20251103T200358Z_detsim_reco1.root
Finished	2025-11-03 21:10:28
Saved logs	justin-logs:236805.173-dunegpschedd02.fnal.gov.logs.tgz
List job events Cached HTCondor job logs

Jobscript log (last 10,000 characters)

ets:[ "gauss0":23891 [0] "wiener0":26238 [26238] ] cmm:[ bad:0 lf_noisy:241 ] 
[15:06:58.261] D [  glue  ] <FrameFanin:sn_mag_nf> call=18 input 0: frame: ident=99 time=0 tick=512 with 50129 traces.  frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss0":23891 [0] "wiener0":26238 [26238] ] cmm:[ bad:0 lf_noisy:241 ] input 1: frame: ident=99 time=0 tick=512 with 30611 traces.  frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss1":13972 [0] "wiener1":16639 [16639] ] cmm:[ bad:0 ] input 2: frame: ident=99 time=0 tick=512 with 42582 traces.  frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss2":17710 [0] "wiener2":24872 [24872] ] cmm:[ bad:0 ] input 3: frame: ident=99 time=0 tick=512 with 44407 traces.  frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss3":18657 [0] "wiener3":25750 [25750] ] cmm:[ bad:0 ] output: frame: ident=99 time=0 tick=512 with 167729 traces.  frame tags:[ "framefanin" ] 8 tagged trace sets:[ "gauss0":23891 [0] "gauss1":13972 [0] "gauss2":17710 [0] "gauss3":18657 [0] "wiener0":26238 [26238] "wiener1":16639 [16639] "wiener2":24872 [24872] "wiener3":25750 [25750] ] cmm:[ bad:0 lf_noisy:241 ] 
Retagger: tagging trace set: wiener with 93499 traces, 93499 summary
Retagger: tagging trace set: gauss with 74230 traces, 0 summary
[15:06:58.269] D [  glue  ] sink frame: #99 @0 with 167729 traces, frame tags:[retagger], trace tags:[gauss, wiener]
[15:06:58.269] D [  glue  ] <FrameFanout:sn_mag_nf> call=19: see EOS 
[15:06:58.269] D [  glue  ] <ChannelSelector:chsel3> see EOS at call=9 
[15:06:58.269] D [sigproc ] <OmnibusNoiseFilter:nf3> EOS at call=19 
[15:06:58.269] D [sigproc ] <OmnibusSigProc:apa3sigproc3> EOS at call=19 anode=3 
[15:06:58.269] D [  glue  ] <ChannelSelector:chsel2> see EOS at call=9 
[15:06:58.269] D [sigproc ] <OmnibusNoiseFilter:nf2> EOS at call=19 
[15:06:58.269] D [sigproc ] <OmnibusSigProc:apa2sigproc2> EOS at call=19 anode=2 
[15:06:58.270] D [  glue  ] <ChannelSelector:chsel1> see EOS at call=9 
[15:06:58.270] D [sigproc ] <OmnibusNoiseFilter:nf1> EOS at call=19 
[15:06:58.270] D [sigproc ] <OmnibusSigProc:apa1sigproc1> EOS at call=19 anode=1 
[15:06:58.270] D [  glue  ] <ChannelSelector:chsel0> see EOS at call=9 
[15:06:58.270] D [sigproc ] <OmnibusNoiseFilter:nf0> EOS at call=19 
[15:06:58.270] D [sigproc ] <OmnibusSigProc:apa0sigproc0> EOS at call=19 anode=0 
[15:06:58.270] D [  glue  ] <FrameFanin:sn_mag_nf> EOS at call=19 with 4 
[15:06:58.270] D [  glue  ] frame sink sees EOS
[15:06:58.270] D [ pgraph ] <Pgrapher:> graph execution complete 
[15:06:58.270] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 11.45 sec
[15:06:58.270] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 8.16 sec
[15:06:58.270] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 7.89 sec
[15:06:58.270] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 7.62 sec
[15:06:58.270] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.58 sec
[15:06:58.270] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.54 sec
[15:06:58.270] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.52 sec
[15:06:58.270] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.52 sec
[15:06:58.270] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[15:06:58.270] I [ timer  ] Timer: WireCell::Gen::Retagger : 0.01 sec
[15:06:58.270] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[15:06:58.270] I [ timer  ] Timer: WireCell::Gen::FrameFanout : 0 sec
[15:06:58.270] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[15:06:58.270] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[15:06:58.270] I [ timer  ] Timer: wcls::RawFrameSource : 0 sec
[15:06:58.270] I [ timer  ] Timer: WireCell::Gen::FrameFanin : 0 sec
[15:06:58.270] I [ timer  ] Timer: wcls::FrameSaver : 0 sec
[15:06:58.270] I [ timer  ] Timer: WireCell::Gen::DumpFrames : 0 sec
[15:06:58.271] I [ timer  ] Timer: Total node execution : 45.299999255687 sec
wclsFrameSaver saving cooked to 6000 ticks
wclsFrameSaver: saving 74230 traces tagged "gauss"
FrameSaver: q=2.33378e+06 n=1156474 tag=gauss
wclsFrameSaver: saving 93499 traces tagged "wiener"
FrameSaver: q=2.87491e+06 n=1112401 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:2 10338 XUs and 7247 XVs -> 292 XUVs
C:0 T:5 52411 XUs and 45187 XVs -> 1900 XUVs
C:0 T:6 31786 XUs and 18821 XVs -> 610 XUVs
2802 XUVs total
1556 collection wire objects
2802 potential space points
Neighbour search...
37182 tests to find 22270 neighbours
Iterating with no regularization...
Begin: 2.44045e+07
0 2.28676e+07
1 2.27455e+07
2 2.27403e+07
Now with regularization...
Begin: 2.09418e+07
0 2.09402e+07
03-Nov-2025 15:07:29 CST  Closed output file "pdhd_prod_beam__226699_7_1_20251009T172331Z_gen_g4_IonScintPDExt.root_227040_4_1_20251010T165942Z_PDInt.root_236805_173_1_20251103T200358Z_detsim_reco1.root"
03-Nov-2025 15:07:29 CST  Closed input file "temp_detsim.root"

=====================================================================================================================================
TimeTracker printout (sec)                             Min           Avg           Max         Median          RMS         nEvts   
=====================================================================================================================================
Full event                                           65.7276       78.787        100.892       75.1806       10.6962        10     
-------------------------------------------------------------------------------------------------------------------------------------
source:RootInput(read)                             0.00129333    0.00377022    0.00584965    0.00399498    0.00119408       10     
reco:wclsdatahd:WireCellToolkit                      42.0894       47.8844       63.1892       45.4433       6.40309        10     
reco:wirefilter:WireFilter                          0.0113317     0.0146755     0.0201481     0.013755     0.00280647       10     
reco:gaushit:GausHitFinder                          0.361934      0.433274      0.525109      0.424743      0.0581439       10     
reco:nhitsfilter:NumberOfHitsFilter                0.000169785   0.000276482   0.000751077   0.00022014    0.000164556      10     
reco:reco3d:SpacePointSolver                        0.180201      0.308036      0.487497      0.306871      0.0977838       10     
reco:hitpdune:DisambigFromSpacePoints                0.13161      0.252148      0.453446      0.226062      0.0892757       10     
reco:pandora:StandardPandora                         3.28439       5.25693       7.79966       5.02566       1.40268        10     
reco:pandoraWriter:StandardPandora                  0.119086      0.158217      0.253815       0.14979      0.0371561       10     
reco:pandoraTrack:LArPandoraTrackCreation           0.341029      0.531319      0.965016      0.484211      0.165212        10     
reco:pandoraShower:LArPandoraShowerCreation         0.249076      0.564692      0.865972      0.504051      0.178903        10     
reco:pandoracalo:Calorimetry                        0.240362      0.334914      0.491021      0.330055      0.0732107       10     
reco:pandoracalonosce:Calorimetry                   0.239026      0.329371      0.525518      0.314425      0.0798148       10     
reco:pandoraShowercalo:ShowerCalorimetry             0.22525      0.583119       0.85326      0.535326      0.182581        10     
reco:pandoraShowercalonosce:ShowerCalorimetry       0.227445      0.574974      0.835764       0.52267      0.180799        10     
reco:pandoraGnocchiCalo:GnocchiCalorimetry          0.0258207     0.0374347     0.0551741     0.0365801    0.00751059       10     
reco:pandoraGnocchiCalonosce:GnocchiCalorimetry     0.0257891     0.0377535     0.0592032     0.0362218    0.00863397       10     
reco:emtrkmichelid:EmTrackMichelId                   14.9674       20.2918       27.3017       19.0663       3.51523        10     
[art]:TriggerResults:TriggerResultInserter         2.7657e-05    4.79742e-05   0.000126134   4.3302e-05    2.70429e-05      10     
end_path:out1:RootOutput                           1.1384e-05    1.97302e-05    5.28e-05     1.61685e-05   1.16325e-05      10     
end_path:out1:RootOutput(write)                     0.814397       1.14275       1.61108       1.11526      0.246161        10     
=====================================================================================================================================

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

  Peak virtual memory usage (VmPeak)  : 5861.34 MB
  Peak resident set size usage (VmHWM): 3645.63 MB
  Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Reco returns 0
.:
total 11809864
-rw-r--r-- 1 slot1_8 slot1_8     230383 Nov  3 15:07 jobscript.log
-rw-r--r-- 1 slot1_8 slot1_8        198 Nov  3 15:07 justin-processed-pfns.txt
-rw-r--r-- 1 slot1_8 slot1_8        519 Nov  3 15:07 reco_protodunehd_hist.root
-rw-r--r-- 1 slot1_8 slot1_8       3574 Nov  3 15:07 Pandora_Geometry.xml
-rw-r--r-- 1 slot1_8 slot1_8     139264 Nov  3 15:07 mem.db
-rw-r--r-- 1 slot1_8 slot1_8      28672 Nov  3 15:07 time.db
-rw-r--r-- 1 slot1_8 slot1_8 6120736831 Nov  3 15:07 pdhd_prod_beam__226699_7_1_20251009T172331Z_gen_g4_IonScintPDExt.root_227040_4_1_20251010T165942Z_PDInt.root_236805_173_1_20251103T200358Z_detsim_reco1.root
-rw-r--r-- 1 slot1_8 slot1_8   32457280 Nov  3 15:07 Pandora_Events.pndr
-rw-r--r-- 1 slot1_8 slot1_8          0 Nov  3 14:51 debugprod.log
-rw-r--r-- 1 slot1_8 slot1_8        519 Nov  3 14:51 detsim_single_protodunehd_hist.root
-rw-r--r-- 1 slot1_8 slot1_8 5939652519 Nov  3 14:51 temp_detsim.root
-rw-r--r-- 1 slot1_8 slot1_8        119 Nov  3 14:03 all-input-dids.txt