Jobsub ID 268896.53@dunegpschedd01.fnal.gov

Jobsub ID	268896.53@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:25
Input files	usertests:pdhd_prod_beam__267379_53_1_20251212T160926Z_gen_g4_IonScintPDExt.root_262726_101_1_20251215T212453Z_PDInt.root
Jobscript	Exit code	0
	Real time	2h (8122s)
	CPU time	1h (6252s = 76%)
	Max RSS bytes	7201456128 (6867 MiB)
Outputting started	2025-12-17 20:47:47
Output files
Finished	2025-12-17 20:48:11
List job events Cached HTCondor job logs
Jobscript log (last 10,000 characters)

<FrameFanin:sn_mag_nf> call=18 input 0: frame: ident=189 time=0 tick=512 with 74555 traces.  frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss0":34761 [0] "wiener0":39794 [39794] ] cmm:[ bad:0 lf_noisy:392 ] input 1: frame: ident=189 time=0 tick=512 with 37545 traces.  frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss1":15716 [0] "wiener1":21829 [21829] ] cmm:[ bad:0 lf_noisy:1 ] input 2: frame: ident=189 time=0 tick=512 with 50276 traces.  frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss2":20568 [0] "wiener2":29708 [29708] ] cmm:[ bad:0 ] input 3: frame: ident=189 time=0 tick=512 with 32082 traces.  frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss3":14170 [0] "wiener3":17912 [17912] ] cmm:[ bad:0 ] output: frame: ident=189 time=0 tick=512 with 194458 traces.  frame tags:[ "framefanin" ] 8 tagged trace sets:[ "gauss0":34761 [0] "gauss1":15716 [0] "gauss2":20568 [0] "gauss3":14170 [0] "wiener0":39794 [39794] "wiener1":21829 [21829] "wiener2":29708 [29708] "wiener3":17912 [17912] ] cmm:[ bad:0 lf_noisy:393 ] 
Retagger: tagging trace set: wiener with 109243 traces, 109243 summary
Retagger: tagging trace set: gauss with 85215 traces, 0 summary
[20:47:06.945] D [  glue  ] sink frame: #189 @0 with 194458 traces, frame tags:[retagger], trace tags:[gauss, wiener]
[20:47:06.946] D [  glue  ] <FrameFanout:sn_mag_nf> call=19: see EOS 
[20:47:06.946] D [  glue  ] <ChannelSelector:chsel3> see EOS at call=9 
[20:47:06.946] D [sigproc ] <OmnibusNoiseFilter:nf3> EOS at call=19 
[20:47:06.946] D [sigproc ] <OmnibusSigProc:apa3sigproc3> EOS at call=19 anode=3 
[20:47:06.946] D [  glue  ] <ChannelSelector:chsel2> see EOS at call=9 
[20:47:06.946] D [sigproc ] <OmnibusNoiseFilter:nf2> EOS at call=19 
[20:47:06.946] D [sigproc ] <OmnibusSigProc:apa2sigproc2> EOS at call=19 anode=2 
[20:47:06.946] D [  glue  ] <ChannelSelector:chsel1> see EOS at call=9 
[20:47:06.946] D [sigproc ] <OmnibusNoiseFilter:nf1> EOS at call=19 
[20:47:06.946] D [sigproc ] <OmnibusSigProc:apa1sigproc1> EOS at call=19 anode=1 
[20:47:06.946] D [  glue  ] <ChannelSelector:chsel0> see EOS at call=9 
[20:47:06.946] D [sigproc ] <OmnibusNoiseFilter:nf0> EOS at call=19 
[20:47:06.946] D [sigproc ] <OmnibusSigProc:apa0sigproc0> EOS at call=19 anode=0 
[20:47:06.946] D [  glue  ] <FrameFanin:sn_mag_nf> EOS at call=19 with 4 
[20:47:06.946] D [  glue  ] frame sink sees EOS
[20:47:06.946] D [ pgraph ] <Pgrapher:> graph execution complete 
[20:47:06.946] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 11.52 sec
[20:47:06.946] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 8.11 sec
[20:47:06.946] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 8.1 sec
[20:47:06.946] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 7.78 sec
[20:47:06.946] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.83 sec
[20:47:06.946] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.77 sec
[20:47:06.946] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.76 sec
[20:47:06.946] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.73 sec
[20:47:06.946] I [ timer  ] Timer: WireCell::Gen::FrameFanin : 0.03 sec
[20:47:06.946] I [ timer  ] Timer: WireCell::Gen::Retagger : 0.01 sec
[20:47:06.946] I [ timer  ] Timer: wcls::RawFrameSource : 0 sec
[20:47:06.946] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[20:47:06.946] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[20:47:06.946] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[20:47:06.946] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[20:47:06.946] I [ timer  ] Timer: WireCell::Gen::FrameFanout : 0 sec
[20:47:06.946] I [ timer  ] Timer: wcls::FrameSaver : 0 sec
[20:47:06.946] I [ timer  ] Timer: WireCell::Gen::DumpFrames : 0 sec
[20:47:06.946] I [ timer  ] Timer: Total node execution : 46.640000618994236 sec
wclsFrameSaver saving cooked to 6000 ticks
wclsFrameSaver: saving 85215 traces tagged "gauss"
FrameSaver: q=2.93766e+06 n=1330942 tag=gauss
wclsFrameSaver: saving 109243 traces tagged "wiener"
FrameSaver: q=3.77457e+06 n=1279248 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:2 17843 XUs and 26163 XVs -> 684 XUVs
C:0 T:4 18 XUs and 10 XVs -> 0 XUVs
C:0 T:5 52588 XUs and 45616 XVs -> 941 XUVs
C:0 T:6 9834 XUs and 10487 XVs -> 452 XUVs
C:0 T:7 13 XUs and 7 XVs -> 1 XUVs
2078 XUVs total
1081 collection wire objects
2078 potential space points
Neighbour search...
46620 tests to find 25160 neighbours
Iterating with no regularization...
Begin: 3.3373e+07
0 3.22822e+07
1 3.22199e+07
2 3.22085e+07
Now with regularization...
Begin: 3.07291e+07
0 3.07249e+07
17-Dec-2025 20:47:45 UTC  Closed output file "pdhd_prod_beam__267379_53_1_20251212T160926Z_gen_g4_IonScintPDExt.root_262726_101_1_20251215T212453Z_PDInt.root_268896_53_1_20251217T183230Z_detsim_reco1.root"
17-Dec-2025 20:47:45 UTC  Closed input file "temp_detsim.root"

=====================================================================================================================================
TimeTracker printout (sec)                             Min           Avg           Max         Median          RMS         nEvts   
=====================================================================================================================================
Full event                                           79.3648       93.9377       124.813       91.5376       14.0809        10     
-------------------------------------------------------------------------------------------------------------------------------------
source:RootInput(read)                             0.000889005   0.00928472     0.0643493    0.00345919     0.0184083       10     
reco:wclsdatahd:WireCellToolkit                      43.4172       46.6614       51.6041       46.8911       2.21706        10     
reco:wirefilter:WireFilter                          0.0149978     0.0178252     0.0259082     0.0158681    0.00378028       10     
reco:gaushit:GausHitFinder                          0.444641      0.610811      0.854411      0.605067       0.13309        10     
reco:nhitsfilter:NumberOfHitsFilter                0.000225572   0.000311188   0.000475353   0.000269612   8.46504e-05      10     
reco:reco3d:SpacePointSolver                        0.238586      0.480375       1.11101      0.344722      0.265917        10     
reco:hitpdune:DisambigFromSpacePoints               0.203988      0.408254      0.932055      0.297701      0.227623        10     
reco:pandora:StandardPandora                         4.23928       8.47898       18.3411       7.93267       4.21854        10     
reco:pandoraWriter:StandardPandora                   0.13768      0.374688       2.07041      0.172531      0.566879        10     
reco:pandoraTrack:LArPandoraTrackCreation           0.400536      0.959268       1.80929      0.755268      0.493922        10     
reco:pandoraShower:LArPandoraShowerCreation         0.396828      0.988753       2.34542      0.786989      0.588818        10     
reco:pandoracalo:Calorimetry                        0.253156      0.473861      0.844876      0.374349      0.204108        10     
reco:pandoracalonosce:Calorimetry                   0.246079      0.461817      0.817165      0.367817      0.196146        10     
reco:pandoraShowercalo:ShowerCalorimetry            0.414873      0.921967       2.27851      0.771158      0.529671        10     
reco:pandoraShowercalonosce:ShowerCalorimetry       0.454203      0.938472       2.26609      0.786656      0.519936        10     
reco:pandoraGnocchiCalo:GnocchiCalorimetry          0.0371958     0.0480222     0.0754533     0.0434834     0.0114566       10     
reco:pandoraGnocchiCalonosce:GnocchiCalorimetry     0.0363272     0.046806      0.0738373     0.042066      0.0113813       10     
reco:emtrkmichelid:EmTrackMichelId                   23.0743       30.7219       43.9314       28.3621       7.08823        10     
[art]:TriggerResults:TriggerResultInserter         2.0071e-05    3.02793e-05   8.2251e-05    2.45805e-05   1.75812e-05      10     
end_path:out1:RootOutput                            9.61e-06     1.2061e-05     2.932e-05     1.013e-05    5.76803e-06      10     
end_path:out1:RootOutput(write)                      1.01528       1.28414       1.70272       1.16789      0.245498        10     
=====================================================================================================================================

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

  Peak virtual memory usage (VmPeak)  : 6051.68 MB
  Peak resident set size usage (VmHWM): 3829.48 MB
  Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Reco returns 0
.:
total 12361104
-rw-r--r-- 1 dunegli fnalgrid     231463 Dec 17 20:47 jobscript.log
-rw-r--r-- 1 dunegli fnalgrid        201 Dec 17 20:47 justin-processed-pfns.txt
-rw-r--r-- 1 dunegli fnalgrid        519 Dec 17 20:47 reco_protodunehd_hist.root
-rw-r--r-- 1 dunegli fnalgrid       3574 Dec 17 20:47 Pandora_Geometry.xml
-rw-r--r-- 1 dunegli fnalgrid     139264 Dec 17 20:47 mem.db
-rw-r--r-- 1 dunegli fnalgrid      28672 Dec 17 20:47 time.db
-rw-r--r-- 1 dunegli fnalgrid 6410888086 Dec 17 20:47 pdhd_prod_beam__267379_53_1_20251212T160926Z_gen_g4_IonScintPDExt.root_262726_101_1_20251215T212453Z_PDInt.root_268896_53_1_20251217T183230Z_detsim_reco1.root
-rw-r--r-- 1 dunegli fnalgrid   37838040 Dec 17 20:47 Pandora_Events.pndr
-rw-r--r-- 1 dunegli fnalgrid          0 Dec 17 20:14 debugprod.log
-rw-r--r-- 1 dunegli fnalgrid        519 Dec 17 20:13 detsim_single_protodunehd_hist.root
-rw-r--r-- 1 dunegli fnalgrid 6208593612 Dec 17 20:13 temp_detsim.root
-rw-r--r-- 1 dunegli fnalgrid        122 Dec 17 18:32 all-input-dids.txt