Jobsub ID 268896.48@dunegpschedd01.fnal.gov

Jobsub ID	268896.48@dunegpschedd01.fnal.gov
Workflow ID	11239
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 17:53:51
Site	US_FNAL-T1
Entry	CMSHTPC_T1_US_FNAL_condce_opp1_whole
Last heartbeat	2025-12-17 20:48:11
From worker node	Hostname	dunegli-49199-0-cmswn2413.fnal.gov
	cpuinfo	AMD EPYC 7551 32-Core Processor
	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	outputting_failed
Started	2025-12-17 18:32:54
Input files	usertests:pdhd_prod_beam__267379_36_1_20251212T160935Z_gen_g4_IonScintPDExt.root_262726_56_1_20251215T212458Z_PDInt.root
Jobscript	Exit code	0
	Real time	2h (8013s)
	CPU time	1h (5966s = 74%)
	Max RSS bytes	7293493248 (6955 MiB)
Outputting started	2025-12-17 20:46:27
Output files
Finished	2025-12-17 20:48:11
List job events Cached HTCondor job logs
Jobscript log (last 10,000 characters)

ener0":19856 [19856] ] cmm:[ bad:0 lf_noisy:149 ] 
[20:45:56.714] D [  glue  ] <FrameFanin:sn_mag_nf> call=18 input 0: frame: ident=189 time=0 tick=512 with 37897 traces.  frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss0":18041 [0] "wiener0":19856 [19856] ] cmm:[ bad:0 lf_noisy:149 ] input 1: frame: ident=189 time=0 tick=512 with 33834 traces.  frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss1":14986 [0] "wiener1":18848 [18848] ] cmm:[ bad:0 ] input 2: frame: ident=189 time=0 tick=512 with 32847 traces.  frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss2":14632 [0] "wiener2":18215 [18215] ] cmm:[ bad:0 ] input 3: frame: ident=189 time=0 tick=512 with 27674 traces.  frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss3":12776 [0] "wiener3":14898 [14898] ] cmm:[ bad:0 ] output: frame: ident=189 time=0 tick=512 with 132252 traces.  frame tags:[ "framefanin" ] 8 tagged trace sets:[ "gauss0":18041 [0] "gauss1":14986 [0] "gauss2":14632 [0] "gauss3":12776 [0] "wiener0":19856 [19856] "wiener1":18848 [18848] "wiener2":18215 [18215] "wiener3":14898 [14898] ] cmm:[ bad:0 lf_noisy:149 ] 
Retagger: tagging trace set: wiener with 71817 traces, 71817 summary
Retagger: tagging trace set: gauss with 60435 traces, 0 summary
[20:45:56.723] D [  glue  ] sink frame: #189 @0 with 132252 traces, frame tags:[retagger], trace tags:[gauss, wiener]
[20:45:56.723] D [  glue  ] <FrameFanout:sn_mag_nf> call=19: see EOS 
[20:45:56.723] D [  glue  ] <ChannelSelector:chsel3> see EOS at call=9 
[20:45:56.723] D [sigproc ] <OmnibusNoiseFilter:nf3> EOS at call=19 
[20:45:56.723] D [sigproc ] <OmnibusSigProc:apa3sigproc3> EOS at call=19 anode=3 
[20:45:56.723] D [  glue  ] <ChannelSelector:chsel2> see EOS at call=9 
[20:45:56.723] D [sigproc ] <OmnibusNoiseFilter:nf2> EOS at call=19 
[20:45:56.723] D [sigproc ] <OmnibusSigProc:apa2sigproc2> EOS at call=19 anode=2 
[20:45:56.723] D [  glue  ] <ChannelSelector:chsel1> see EOS at call=9 
[20:45:56.723] D [sigproc ] <OmnibusNoiseFilter:nf1> EOS at call=19 
[20:45:56.723] D [sigproc ] <OmnibusSigProc:apa1sigproc1> EOS at call=19 anode=1 
[20:45:56.723] D [  glue  ] <ChannelSelector:chsel0> see EOS at call=9 
[20:45:56.724] D [sigproc ] <OmnibusNoiseFilter:nf0> EOS at call=19 
[20:45:56.724] D [sigproc ] <OmnibusSigProc:apa0sigproc0> EOS at call=19 anode=0 
[20:45:56.724] D [  glue  ] <FrameFanin:sn_mag_nf> EOS at call=19 with 4 
[20:45:56.724] D [  glue  ] frame sink sees EOS
[20:45:56.724] D [ pgraph ] <Pgrapher:> graph execution complete 
[20:45:56.724] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 11.26 sec
[20:45:56.724] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 7.61 sec
[20:45:56.724] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 7.35 sec
[20:45:56.724] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 7.3 sec
[20:45:56.724] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 3.08 sec
[20:45:56.724] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.96 sec
[20:45:56.724] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.77 sec
[20:45:56.724] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.76 sec
[20:45:56.724] I [ timer  ] Timer: WireCell::Gen::FrameFanin : 0.01 sec
[20:45:56.724] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[20:45:56.724] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[20:45:56.724] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[20:45:56.724] I [ timer  ] Timer: WireCell::Gen::FrameFanout : 0 sec
[20:45:56.724] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[20:45:56.724] I [ timer  ] Timer: wcls::RawFrameSource : 0 sec
[20:45:56.724] I [ timer  ] Timer: WireCell::Gen::Retagger : 0 sec
[20:45:56.724] I [ timer  ] Timer: wcls::FrameSaver : 0 sec
[20:45:56.724] I [ timer  ] Timer: WireCell::Gen::DumpFrames : 0 sec
[20:45:56.724] I [ timer  ] Timer: Total node execution : 45.110000390559435 sec
wclsFrameSaver saving cooked to 6000 ticks
wclsFrameSaver: saving 60435 traces tagged "gauss"
FrameSaver: q=1.58847e+06 n=909781 tag=gauss
wclsFrameSaver: saving 71817 traces tagged "wiener"
FrameSaver: q=1.97496e+06 n=886182 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:2 18631 XUs and 18892 XVs -> 919 XUVs
C:0 T:5 18149 XUs and 8211 XVs -> 231 XUVs
C:0 T:6 4951 XUs and 4685 XVs -> 316 XUVs
1466 XUVs total
864 collection wire objects
1466 potential space points
Neighbour search...
24888 tests to find 14016 neighbours
Iterating with no regularization...
Begin: 3.14939e+07
0 2.91336e+07
1 2.888e+07
2 2.88498e+07
3 2.88452e+07
Now with regularization...
Begin: 2.68921e+07
0 2.68869e+07
17-Dec-2025 20:46:25 UTC  Closed output file "pdhd_prod_beam__267379_36_1_20251212T160935Z_gen_g4_IonScintPDExt.root_262726_56_1_20251215T212458Z_PDInt.root_268896_48_1_20251217T183259Z_detsim_reco1.root"
17-Dec-2025 20:46:25 UTC  Closed input file "temp_detsim.root"

=====================================================================================================================================
TimeTracker printout (sec)                             Min           Avg           Max         Median          RMS         nEvts   
=====================================================================================================================================
Full event                                           64.1279       92.4349       118.834       88.5316       16.5011        10     
-------------------------------------------------------------------------------------------------------------------------------------
source:RootInput(read)                             0.00108041     0.0099719     0.0683809    0.00398663     0.0195106       10     
reco:wclsdatahd:WireCellToolkit                      44.2005       46.5458       49.6609       46.129        2.13668        10     
reco:wirefilter:WireFilter                          0.0128407     0.0177069     0.029993      0.0163739    0.00502965       10     
reco:gaushit:GausHitFinder                          0.321811      0.619078      0.933699      0.623285      0.179217        10     
reco:nhitsfilter:NumberOfHitsFilter                0.000132901   0.000302058   0.000459154   0.000309677   9.94515e-05      10     
reco:reco3d:SpacePointSolver                        0.0833796     0.407239      0.817116      0.306351      0.227914        10     
reco:hitpdune:DisambigFromSpacePoints               0.127583      0.401785      0.881291      0.326328      0.212041        10     
reco:pandora:StandardPandora                         2.08083       8.56257       19.6374       6.70042       5.05659        10     
reco:pandoraWriter:StandardPandora                  0.0912036      0.19796       0.28251      0.210994      0.0592808       10     
reco:pandoraTrack:LArPandoraTrackCreation           0.333502      0.959437       1.55408       0.87707      0.459529        10     
reco:pandoraShower:LArPandoraShowerCreation         0.189141      0.990676       1.87257      0.759574      0.609967        10     
reco:pandoracalo:Calorimetry                        0.178128      0.457061      0.725109      0.437807      0.190744        10     
reco:pandoracalonosce:Calorimetry                   0.166128       0.4434        0.6738        0.42054      0.185086        10     
reco:pandoraShowercalo:ShowerCalorimetry            0.174031      0.879303       1.63888      0.760832      0.480346        10     
reco:pandoraShowercalonosce:ShowerCalorimetry       0.168928      0.890986       1.49075      0.839913      0.461924        10     
reco:pandoraGnocchiCalo:GnocchiCalorimetry          0.0249401     0.0477335     0.0574225     0.0528661     0.0105674       10     
reco:pandoraGnocchiCalonosce:GnocchiCalorimetry     0.024832      0.048822      0.0744792     0.0505612     0.0130401       10     
reco:emtrkmichelid:EmTrackMichelId                   14.7562       29.5199       39.9269       28.8883       8.1993         10     
[art]:TriggerResults:TriggerResultInserter          2.507e-05    3.61251e-05   9.3811e-05    2.8695e-05    1.9923e-05       10     
end_path:out1:RootOutput                            7.74e-06     1.04291e-05   2.7741e-05     8.47e-06     5.78323e-06      10     
end_path:out1:RootOutput(write)                     0.765516       1.38787       2.03726       1.42089      0.339575        10     
=====================================================================================================================================

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

  Peak virtual memory usage (VmPeak)  : 5885.42 MB
  Peak resident set size usage (VmHWM): 3665.89 MB
  Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Reco returns 0
.:
total 12073724
-rw-r--r-- 1 dunegli fnalgrid     231110 Dec 17 20:46 jobscript.log
-rw-r--r-- 1 dunegli fnalgrid        200 Dec 17 20:46 justin-processed-pfns.txt
-rw-r--r-- 1 dunegli fnalgrid        519 Dec 17 20:46 reco_protodunehd_hist.root
-rw-r--r-- 1 dunegli fnalgrid       3574 Dec 17 20:46 Pandora_Geometry.xml
-rw-r--r-- 1 dunegli fnalgrid     139264 Dec 17 20:46 mem.db
-rw-r--r-- 1 dunegli fnalgrid      28672 Dec 17 20:46 time.db
-rw-r--r-- 1 dunegli fnalgrid 6259240184 Dec 17 20:46 pdhd_prod_beam__267379_36_1_20251212T160935Z_gen_g4_IonScintPDExt.root_262726_56_1_20251215T212458Z_PDInt.root_268896_48_1_20251217T183259Z_detsim_reco1.root
-rw-r--r-- 1 dunegli fnalgrid   35786540 Dec 17 20:46 Pandora_Events.pndr
-rw-r--r-- 1 dunegli fnalgrid          0 Dec 17 20:09 debugprod.log
-rw-r--r-- 1 dunegli fnalgrid        519 Dec 17 20:09 detsim_single_protodunehd_hist.root
-rw-r--r-- 1 dunegli fnalgrid 6068013514 Dec 17 20:09 temp_detsim.root
-rw-r--r-- 1 dunegli fnalgrid        121 Dec 17 18:32 all-input-dids.txt