justIN           Dashboard       Workflows       Jobs       AWT       Sites       Storages       Docs       Login

Jobsub ID 268745.1@dunegpschedd01.fnal.gov

Jobsub ID268745.1@dunegpschedd01.fnal.gov
Workflow ID11227
Stage ID1
User nameavizcaya@fnal.gov
HTCondor Groupgroup_dune
RequestedProcessors1
GPUNo
RSS bytes9437184000 (9000 MiB)
Wall seconds limit80000 (22 hours)
Submitted time2025-12-16 23:30:54
SiteUS_UChicago
EntryEngage_US_MWT2_uiuc_gk02_condce_mcore
Last heartbeat2025-12-17 01:27:54
From worker nodeHostnamemwt2-c179.campuscluster.illinois.edu
cpuinfoIntel(R) Xeon(R) Gold 6248 CPU @ 2.50GHz
OS releaseScientific Linux release 7.9 (Nitrogen)
Processors1
RSS bytes10485760000 (10000 MiB)
Wall seconds limit86400 (24 hours)
GPU
Inner Apptainer?True
Job statefinished
Started2025-12-16 23:31:48
Input filesusertests:pdhd_prod_beam__265029_13_1_20251208T213855Z_gen_g4_IonScintPDExt.root_260262_24_1_20251210T192009Z_PDInt.root
JobscriptExit code0
Real time1h (6794s)
CPU time1h (6405s = 94%)
Max RSS bytes7201259520 (6867 MiB)
Outputting started2025-12-17 01:25:03
Output filesusertests:pdhd_prod_beam__265029_13_1_20251208T213855Z_gen_g4_IonScintPDExt.root_260262_24_1_20251210T192009Z_PDInt.root_268745_1_1_20251216T233206Z_detsim_reco1.root
Finished2025-12-17 01:27:54
Saved logsjustin-logs:268745.1-dunegpschedd01.fnal.gov.logs.tgz
List job events     Cached HTCondor job logs

Jobscript log (last 10,000 characters)

:0 lf_noisy:176 ] 
[19:24:11.587] D [  glue  ] <FrameFanin:sn_mag_nf> call=18 input 0: frame: ident=159 time=0 tick=512 with 57416 traces.  frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss0":27302 [0] "wiener0":30114 [30114] ] cmm:[ bad:0 lf_noisy:176 ] input 1: frame: ident=159 time=0 tick=512 with 37657 traces.  frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss1":16606 [0] "wiener1":21051 [21051] ] cmm:[ bad:0 lf_noisy:1 ] input 2: frame: ident=159 time=0 tick=512 with 47717 traces.  frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss2":19959 [0] "wiener2":27758 [27758] ] cmm:[ bad:0 ] input 3: frame: ident=159 time=0 tick=512 with 38350 traces.  frame tags:[ "sigproc" ] 2 tagged trace sets:[ "gauss3":16671 [0] "wiener3":21679 [21679] ] cmm:[ bad:0 ] output: frame: ident=159 time=0 tick=512 with 181140 traces.  frame tags:[ "framefanin" ] 8 tagged trace sets:[ "gauss0":27302 [0] "gauss1":16606 [0] "gauss2":19959 [0] "gauss3":16671 [0] "wiener0":30114 [30114] "wiener1":21051 [21051] "wiener2":27758 [27758] "wiener3":21679 [21679] ] cmm:[ bad:0 lf_noisy:177 ] 
Retagger: tagging trace set: wiener with 100602 traces, 100602 summary
Retagger: tagging trace set: gauss with 80538 traces, 0 summary
[19:24:11.624] D [  glue  ] sink frame: #159 @0 with 181140 traces, frame tags:[retagger], trace tags:[gauss, wiener]
[19:24:11.624] D [  glue  ] <FrameFanout:sn_mag_nf> call=19: see EOS 
[19:24:11.624] D [  glue  ] <ChannelSelector:chsel3> see EOS at call=9 
[19:24:11.625] D [sigproc ] <OmnibusNoiseFilter:nf3> EOS at call=19 
[19:24:11.625] D [sigproc ] <OmnibusSigProc:apa3sigproc3> EOS at call=19 anode=3 
[19:24:11.625] D [  glue  ] <ChannelSelector:chsel2> see EOS at call=9 
[19:24:11.625] D [sigproc ] <OmnibusNoiseFilter:nf2> EOS at call=19 
[19:24:11.625] D [sigproc ] <OmnibusSigProc:apa2sigproc2> EOS at call=19 anode=2 
[19:24:11.625] D [  glue  ] <ChannelSelector:chsel1> see EOS at call=9 
[19:24:11.625] D [sigproc ] <OmnibusNoiseFilter:nf1> EOS at call=19 
[19:24:11.625] D [sigproc ] <OmnibusSigProc:apa1sigproc1> EOS at call=19 anode=1 
[19:24:11.625] D [  glue  ] <ChannelSelector:chsel0> see EOS at call=9 
[19:24:11.625] D [sigproc ] <OmnibusNoiseFilter:nf0> EOS at call=19 
[19:24:11.625] D [sigproc ] <OmnibusSigProc:apa0sigproc0> EOS at call=19 anode=0 
[19:24:11.625] D [  glue  ] <FrameFanin:sn_mag_nf> EOS at call=19 with 4 
[19:24:11.625] D [  glue  ] frame sink sees EOS
[19:24:11.625] D [ pgraph ] <Pgrapher:> graph execution complete 
[19:24:11.625] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 22.89 sec
[19:24:11.625] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 17.35 sec
[19:24:11.625] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 15.99 sec
[19:24:11.625] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 15.13 sec
[19:24:11.625] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 3.92 sec
[19:24:11.625] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 3.82 sec
[19:24:11.626] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 3.65 sec
[19:24:11.626] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 3.36 sec
[19:24:11.626] I [ timer  ] Timer: WireCell::Gen::FrameFanin : 0.04 sec
[19:24:11.626] I [ timer  ] Timer: WireCell::Gen::Retagger : 0.03 sec
[19:24:11.626] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[19:24:11.626] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[19:24:11.627] I [ timer  ] Timer: wcls::FrameSaver : 0.01 sec
[19:24:11.627] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[19:24:11.627] I [ timer  ] Timer: WireCell::Gen::FrameFanout : 0 sec
[19:24:11.627] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[19:24:11.627] I [ timer  ] Timer: WireCell::Gen::DumpFrames : 0 sec
[19:24:11.627] I [ timer  ] Timer: wcls::RawFrameSource : 0 sec
[19:24:11.627] I [ timer  ] Timer: Total node execution : 86.20999965444207 sec
wclsFrameSaver saving cooked to 6000 ticks
wclsFrameSaver: saving 80538 traces tagged "gauss"
FrameSaver: q=2.33056e+06 n=1210171 tag=gauss
wclsFrameSaver: saving 100602 traces tagged "wiener"
FrameSaver: q=3.21758e+06 n=1166539 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:2 20649 XUs and 23312 XVs -> 352 XUVs
C:0 T:4 46 XUs and 53 XVs -> 19 XUVs
C:0 T:5 35624 XUs and 51328 XVs -> 2307 XUVs
C:0 T:6 36535 XUs and 21067 XVs -> 554 XUVs
C:0 T:7 3 XUs and 8 XVs -> 0 XUVs
3232 XUVs total
1268 collection wire objects
3232 potential space points
Neighbour search...
118786 tests to find 73506 neighbours
Iterating with no regularization...
Begin: 1.39086e+07
0 1.26069e+07
1 1.2526e+07
2 1.25129e+07
3 1.25086e+07
Now with regularization...
Begin: 1.15489e+07
0 1.15458e+07
16-Dec-2025 19:25:01 CST  Closed output file "pdhd_prod_beam__265029_13_1_20251208T213855Z_gen_g4_IonScintPDExt.root_260262_24_1_20251210T192009Z_PDInt.root_268745_1_1_20251216T233206Z_detsim_reco1.root"
16-Dec-2025 19:25:01 CST  Closed input file "temp_detsim.root"

=====================================================================================================================================
TimeTracker printout (sec)                             Min           Avg           Max         Median          RMS         nEvts   
=====================================================================================================================================
Full event                                           123.528       146.163       190.575       138.579       19.7311        10     
-------------------------------------------------------------------------------------------------------------------------------------
source:RootInput(read)                             0.00174996    0.00985095     0.0236651    0.00985776    0.00623163       10     
reco:wclsdatahd:WireCellToolkit                      82.8233       91.8136       103.544       91.7629       5.37246        10     
reco:wirefilter:WireFilter                          0.0395406     0.0539053     0.0744348     0.0512433    0.00961107       10     
reco:gaushit:GausHitFinder                          0.568625      0.963453       1.40194      0.948509      0.214217        10     
reco:nhitsfilter:NumberOfHitsFilter                0.000379134   0.000596079   0.000941651   0.000577637   0.000154561      10     
reco:reco3d:SpacePointSolver                        0.470363      0.981006       2.9848       0.705717      0.715024        10     
reco:hitpdune:DisambigFromSpacePoints               0.434786      0.743642       1.53788      0.689145      0.290941        10     
reco:pandora:StandardPandora                         9.02067       17.5875       35.1525       13.6691       8.67104        10     
reco:pandoraWriter:StandardPandora                  0.283859       0.39307      0.648134      0.389763      0.0965747       10     
reco:pandoraTrack:LArPandoraTrackCreation            1.68583       3.23716       5.5429        3.19121      0.962454        10     
reco:pandoraShower:LArPandoraShowerCreation          1.70312       3.16044       6.10038       2.97275       1.09737        10     
reco:pandoracalo:Calorimetry                        0.929384       1.66454        2.904        1.57222      0.552298        10     
reco:pandoracalonosce:Calorimetry                   0.865506       1.68011       2.6961        1.75155      0.478448        10     
reco:pandoraShowercalo:ShowerCalorimetry             1.73116       3.14585       6.01222       2.98904       1.10647        10     
reco:pandoraShowercalonosce:ShowerCalorimetry        1.4259        3.0142        5.83915       2.84509       1.12694        10     
reco:pandoraGnocchiCalo:GnocchiCalorimetry          0.0419282     0.0979603     0.122351      0.103337      0.0212454       10     
reco:pandoraGnocchiCalonosce:GnocchiCalorimetry     0.0419723     0.0930478      0.11773      0.0954733     0.0196998       10     
reco:emtrkmichelid:EmTrackMichelId                   10.2466       15.6872       25.5637       14.9222       3.79862        10     
[art]:TriggerResults:TriggerResultInserter         3.0899e-05    8.78844e-05   0.000183374   8.32305e-05   4.07727e-05      10     
end_path:out1:RootOutput                            8.228e-06    1.70128e-05   3.9355e-05    1.51715e-05   8.82616e-06      10     
end_path:out1:RootOutput(write)                      1.19416       1.73311       2.57518        1.709       0.375012        10     
=====================================================================================================================================

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

  Peak virtual memory usage (VmPeak)  : 6500.59 MB
  Peak resident set size usage (VmHWM): 4089.09 MB
  Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Reco returns 0
.:
total 11921628
-rw-r--r-- 1 dune osgvo     231397 Dec 16 19:25 jobscript.log
-rw-r--r-- 1 dune osgvo        200 Dec 16 19:25 justin-processed-pfns.txt
-rw-r--r-- 1 dune osgvo        519 Dec 16 19:25 reco_protodunehd_hist.root
-rw-r--r-- 1 dune osgvo       3574 Dec 16 19:25 Pandora_Geometry.xml
-rw-r--r-- 1 dune osgvo     139264 Dec 16 19:25 mem.db
-rw-r--r-- 1 dune osgvo      28672 Dec 16 19:25 time.db
-rw-r--r-- 1 dune osgvo 6178562458 Dec 16 19:25 pdhd_prod_beam__265029_13_1_20251208T213855Z_gen_g4_IonScintPDExt.root_260262_24_1_20251210T192009Z_PDInt.root_268745_1_1_20251216T233206Z_detsim_reco1.root
-rw-r--r-- 1 dune osgvo   34914350 Dec 16 19:24 Pandora_Events.pndr
-rw-r--r-- 1 dune osgvo          0 Dec 16 18:56 debugprod.log
-rw-r--r-- 1 dune osgvo        519 Dec 16 18:55 detsim_single_protodunehd_hist.root
-rw-r--r-- 1 dune osgvo 5993819280 Dec 16 18:55 temp_detsim.root
-rw-r--r-- 1 dune osgvo        121 Dec 16 17:32 all-input-dids.txt
justIN time: 2025-12-18 20:21:59 UTC       justIN version: 01.05.03