justIN           Dashboard       Workflows       Jobs       AWT       Sites       Storages       Docs       Login

Jobsub ID 269049.72@dunegpschedd01.fnal.gov

Jobsub ID269049.72@dunegpschedd01.fnal.gov
Workflow ID11251
Stage ID1
User nameykermaid@fnal.gov
HTCondor Groupgroup_dune.prod_mcsim
RequestedProcessors4
GPUNo
RSS bytes6815744000 (6500 MiB)
Wall seconds limit80000 (22 hours)
Submitted time2025-12-18 15:20:56
SiteES_PIC
EntryDUNE_T1_ES_PIC_ce15-multicore
Last heartbeat2025-12-18 17:45:31
From worker nodeHostnametds418.pic.es
cpuinfoAMD EPYC 7502 32-Core Processor
OS releaseScientific Linux release 7.9 (Nitrogen)
Processors4
RSS bytes7864320000 (7500 MiB)
Wall seconds limit216000 (60 hours)
GPU
Inner Apptainer?True
Job statefinished
Started2025-12-18 15:42:56
Input filesvd-protodune-top:3430_23_a_pvdt.test
JobscriptExit code0
Real time2h (7226s)
CPU time1h (6967s = 96%)
Max RSS bytes4261920768 (4064 MiB)
Outputting started2025-12-18 17:43:23
Output filesvd-protodune-det-reco:3430_23_a_pvdt_reco_stage1_20251218T174301_reco.root
Finished2025-12-18 17:45:31
Saved logsjustin-logs:269049.72-dunegpschedd01.fnal.gov.logs.tgz
List job events     Cached HTCondor job logs

Jobscript log (last 10,000 characters)

ue  ] <ChannelSelector:chsel4> see EOS at call=29 
[18:42:41.710] D [sigproc ] <OmnibusNoiseFilter:nf4> EOS at call=59 
[18:42:41.710] D [sigproc ] <OmnibusSigProc:anode4sigproc4> EOS at call=59 anode=4 
[18:42:41.710] D [  glue  ] <ChannelSelector:chsel3> see EOS at call=29 
[18:42:41.710] D [  aux   ] <Resampler:resmp3> EOS at call=59 
[18:42:41.710] D [sigproc ] <OmnibusNoiseFilter:nf3> EOS at call=59 
[18:42:41.710] D [sigproc ] <OmnibusSigProc:anode3sigproc3> EOS at call=59 anode=3 
[18:42:41.710] D [  glue  ] <ChannelSelector:chsel2> see EOS at call=29 
[18:42:41.710] D [  aux   ] <Resampler:resmp2> EOS at call=59 
[18:42:41.710] D [sigproc ] <OmnibusNoiseFilter:nf2> EOS at call=59 
[18:42:41.710] D [sigproc ] <OmnibusSigProc:anode2sigproc2> EOS at call=59 anode=2 
[18:42:41.710] D [  glue  ] <ChannelSelector:chsel1> see EOS at call=29 
[18:42:41.710] D [  aux   ] <Resampler:resmp1> EOS at call=59 
[18:42:41.710] D [sigproc ] <OmnibusNoiseFilter:nf1> EOS at call=59 
[18:42:41.710] D [sigproc ] <OmnibusSigProc:anode1sigproc1> EOS at call=59 anode=1 
[18:42:41.710] D [  glue  ] <ChannelSelector:chsel0> see EOS at call=29 
[18:42:41.710] D [  aux   ] <Resampler:resmp0> EOS at call=59 
[18:42:41.710] D [sigproc ] <OmnibusNoiseFilter:nf0> EOS at call=59 
[18:42:41.711] D [sigproc ] <OmnibusSigProc:anode0sigproc0> EOS at call=59 anode=0 
[18:42:41.711] D [  glue  ] <FrameFanin:nfsp> EOS at call=59 with 8 
[18:42:41.711] D [  glue  ] frame sink sees EOS
[18:42:41.711] D [ pgraph ] <Pgrapher:> graph execution complete 
[18:42:41.711] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 13.58 sec
[18:42:41.711] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 9.82 sec
[18:42:41.711] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 9.65 sec
[18:42:41.711] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 9.2 sec
[18:42:41.711] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 3.01 sec
[18:42:41.711] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.53 sec
[18:42:41.711] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.45 sec
[18:42:41.711] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 2.45 sec
[18:42:41.711] I [ timer  ] Timer: WireCell::Aux::Resampler : 0.52 sec
[18:42:41.711] I [ timer  ] Timer: WireCell::Aux::Resampler : 0.51 sec
[18:42:41.711] I [ timer  ] Timer: WireCell::Aux::Resampler : 0.43 sec
[18:42:41.711] I [ timer  ] Timer: WireCell::Aux::Resampler : 0.4 sec
[18:42:41.711] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[18:42:41.711] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[18:42:41.711] I [ timer  ] Timer: WireCell::Gen::FrameFanin : 0.01 sec
[18:42:41.711] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[18:42:41.711] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[18:42:41.711] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 0 sec
[18:42:41.711] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 0 sec
[18:42:41.711] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 0 sec
[18:42:41.711] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[18:42:41.711] I [ timer  ] Timer: wcls::RawFrameSource : 0 sec
[18:42:41.711] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[18:42:41.711] I [ timer  ] Timer: WireCell::Gen::FrameFanout : 0 sec
[18:42:41.711] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[18:42:41.711] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[18:42:41.711] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[18:42:41.711] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[18:42:41.711] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[18:42:41.711] I [ timer  ] Timer: WireCell::SigProc::OmnibusNoiseFilter : 0 sec
[18:42:41.711] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[18:42:41.711] I [ timer  ] Timer: WireCell::Gen::Retagger : 0 sec
[18:42:41.711] I [ timer  ] Timer: wcls::FrameSaver : 0 sec
[18:42:41.711] I [ timer  ] Timer: WireCell::Gen::DumpFrames : 0 sec
[18:42:41.711] I [ timer  ] Timer: Total node execution : 54.57999908737838 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 6144 traces tagged "gauss"
FrameSaver: q=2.15344e+07 n=1053417 tag=gauss
wclsFrameSaver: saving 6144 traces tagged "wiener"
FrameSaver: q=2.1625e+07 n=1039722 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 2482 XUs and 5017 XVs -> 73 XUVs
C:0 T:1 1222 XUs and 1841 XVs -> 84 XUVs
C:0 T:2 796 XUs and 1263 XVs -> 23 XUVs
C:0 T:3 428 XUs and 413 XVs -> 4 XUVs
C:0 T:4 306 XUs and 430 XVs -> 41 XUVs
C:0 T:5 486 XUs and 365 XVs -> 8 XUVs
C:0 T:6 255 XUs and 323 XVs -> 18 XUVs
C:0 T:7 65 XUs and 107 XVs -> 5 XUVs
256 XUVs total
232 collection wire objects
256 potential space points
Neighbour search...
1136 tests to find 566 neighbours
Iterating with no regularization...
Begin: 4.82908e+09
0 4.82872e+09
Now with regularization...
Begin: 4.82767e+09
0 4.82767e+09
18-Dec-2025 18:43:01 CET  Closed output file "3430_23_a_pvdt_reco_stage1_20251218T174301_reco.root"
DataPrepModule::endJob: # events processed: 30
DataPrepModule::endJob:   # events skipped: 0

==================================================================================================================================
TimeTracker printout (sec)                          Min           Avg           Max         Median          RMS         nEvts   
==================================================================================================================================
Full event                                        55.7921       233.882       1141.89       76.7406       249.64         30     
----------------------------------------------------------------------------------------------------------------------------------
source:VDColdboxTDERawInput(read)               7.5212e-05    0.000125348   0.000342097   0.000106012   5.45317e-05      30     
produce:caldata:DataPrepModule                   0.149829      0.276166      0.679461      0.273568      0.0821472       30     
produce:wclsdatavd:WireCellToolkit                45.9142       71.7659       121.584       59.073        21.6945        30     
produce:gaushit:GausHitFinder                    0.642835       3.16849       8.00758       2.25342       2.44109        30     
produce:reco3d:SpacePointSolver                   2.55309       29.6424       108.708       5.47879       33.4904        30     
produce:hitpdune:DisambigFromSpacePoints         0.0142597     0.505434       1.8212       0.0439193     0.615341        30     
produce:pandora:StandardPandora                   2.97065       123.219       960.678       8.96433       201.044        30     
produce:pandoraTrack:LArPandoraTrackCreation     0.0833933      1.28911       4.20095       0.21133       1.48517        30     
produce:pandoraGnocalo:GnocchiCalorimetry        0.0121705     0.0596298     0.164551      0.0289026     0.0500319       30     
[art]:TriggerResults:TriggerResultInserter       2.139e-05    3.31501e-05   6.9581e-05    2.79105e-05   1.29647e-05      30     
end_path:out1:RootOutput                         3.55e-06     7.2788e-06    6.0802e-05     4.45e-06     1.01069e-05      30     
end_path:out1:RootOutput(write)                   2.25788       3.93087       6.44961       3.28105       1.18641        30     
==================================================================================================================================

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

  Peak virtual memory usage (VmPeak)  : 6644.38 MB
  Peak resident set size usage (VmHWM): 4261.92 MB
  Details saved in: 'mem.db'
====================================================================================================
ToolBasedRawDigitPrepService:dtor: Event count: 30
ToolBasedRawDigitPrepService:dtor:  Call count: 60
ToolBasedRawDigitPrepService:dtor: Time report for 3 tools.
ToolBasedRawDigitPrepService:dtor:                    digitReader:   0.08 sec/event
ToolBasedRawDigitPrepService:dtor:    vdcb_adcChannelRawRmsFiller:   0.17 sec/event
ToolBasedRawDigitPrepService:dtor:                adcSampleFiller:   0.00 sec/event
Art has completed and will exit with status 0.
Output files:
\tReco: 3430_23_a_pvdt_reco_stage1_20251218T174301_reco.root
Forming reco metadata
Successfully opened file 3430_23_a_pvdt_reco_stage1_20251218T174301_reco.root
Ran successfully
{
  "name": "3430_23_a_pvdt_reco_stage1_20251218T174301_reco.root",
  "namespace": "vd-protodune-det-reco",
  "metadata": {
    "core.file_format": "artroot",
    "core.application.name": "reco",
    "core.application.family": "dunesw",
    "core.application.version": "v10_14_01d00",
    "core.data_tier": "full-reconstructed",
    "dune.config_file": "tde_reco_stage1_protodunevd_keepup.fcl",
    "dune.campaign": "vd-protodune-top-det-reco",
    "core.start_time": 1766079788.0,
    "core.end_time": 1766079788.0,
    "core.events": [
      2641,
      2645,
      2649,
      2653,
      2657,
      2661,
      2665,
      2669,
      2673,
      2677,
      2681,
      2685,
      2689,
      2693,
      2697,
      2701,
      2705,
      2709,
      2713,
      2717,
      2721,
      2725,
      2729,
      2733,
      2737,
      2741,
      2745,
      2749,
      2753,
      2757
    ],
    "core.event_count": 30,
    "core.first_event_number": 2641,
    "core.last_event_number": 2757,
    "core.data_stream": "cosmics",
    "core.file_type": "detector",
    "core.run_type": "vd-protodune-top",
    "core.runs": [
      3430
    ],
    "core.runs_subruns": [
      343000023
    ],
    "retention.status": "active",
    "retention.class": "physics"
  },
  "parents": [
    {
      "did": "vd-protodune-top:3430_23_a_pvdt.test"
    }
  ]
}
justIN time: 2025-12-19 04:02:39 UTC       justIN version: 01.05.03