justIN           Dashboard       Workflows       Jobs       AWT       Sites       Storages       Docs       Login

Jobsub ID 48054.50@dunegpschedd01.fnal.gov

Jobsub ID48054.50@dunegpschedd01.fnal.gov
Workflow ID2862
Stage ID1
User nameykermaid@fnal.gov
HTCondor Groupgroup_dune.prod_mcsim
RequestedProcessors1
GPUNo
RSS bytes4193255424 (3999 MiB)
Wall seconds limit18000 (5 hours)
Submitted time2025-09-18 03:53:59
SiteUK_QMUL
EntryDUNE_UK_London_QMUL_arcce03
Last heartbeat2025-09-18 06:36:58
From worker nodeHostnamecn093.htc.esc.qmul
cpuinfoIntel(R) Xeon(R) Gold 6248R CPU @ 3.00GHz
OS releaseScientific Linux release 7.9 (Nitrogen)
Processors1
RSS bytes4194304000 (4000 MiB)
Wall seconds limit171000 (47 hours)
GPU
Inner Apptainer?True
Job statefinished
Started2025-09-18 04:09:13
Input filesvd-protodune:np02vd_raw_run039433_0293_df-s05-d4_dw_0_20250918T032602.hdf5
JobscriptExit code0
Real time2h (8512s)
CPU time1h (6283s = 73%)
Max RSS bytes3112394752 (2968 MiB)
Outputting started2025-09-18 06:31:06
Output filesvd-protodune-det-reco:np02vd_raw_run039433_0293_df-s05-d4_dw_0_20250918T032602_reco_stage1_20250918T063050_keepup.root
Finished2025-09-18 06:36:58
Saved logsjustin-logs:48054.50-dunegpschedd01.fnal.gov.logs.tgz
List job events     Cached HTCondor job logs

Jobscript log (last 10,000 characters)

smp0> EOS at call=95 
[07:29:57.488] D [sigproc ] <OmnibusSigProc:anode0sigproc0> EOS at call=95 anode=0 
[07:29:57.488] D [  glue  ] <FrameFanin:nfsp> EOS at call=95 with 8 
[07:29:57.488] D [  glue  ] frame sink sees EOS
[07:29:57.488] D [ pgraph ] <Pgrapher:> graph execution complete 
[07:29:57.488] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 10.25 sec
[07:29:57.488] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 9.64 sec
[07:29:57.488] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 8.1 sec
[07:29:57.488] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 7.83 sec
[07:29:57.488] I [ timer  ] Timer: WireCell::Aux::Resampler : 0.57 sec
[07:29:57.489] I [ timer  ] Timer: WireCell::Aux::Resampler : 0.56 sec
[07:29:57.489] I [ timer  ] Timer: WireCell::Aux::Resampler : 0.55 sec
[07:29:57.489] I [ timer  ] Timer: WireCell::Aux::Resampler : 0.55 sec
[07:29:57.489] I [ timer  ] Timer: WireCell::Gen::FrameFanin : 0.03 sec
[07:29:57.489] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[07:29:57.489] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[07:29:57.489] I [ timer  ] Timer: WireCell::Gen::Retagger : 0.01 sec
[07:29:57.489] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[07:29:57.489] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[07:29:57.489] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[07:29:57.489] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[07:29:57.489] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[07:29:57.489] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[07:29:57.489] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[07:29:57.489] I [ timer  ] Timer: WireCell::Gen::DumpFrames : 0 sec
[07:29:57.489] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[07:29:57.489] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[07:29:57.489] I [ timer  ] Timer: WireCell::Gen::FrameFanout : 0 sec
[07:29:57.489] I [ timer  ] Timer: wcls::RawFrameSource : 0 sec
[07:29:57.489] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 0 sec
[07:29:57.489] I [ timer  ] Timer: wcls::FrameSaver : 0 sec
[07:29:57.489] I [ timer  ] Timer: Total node execution : 38.11000066623092 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 25156 traces tagged "gauss"
FrameSaver: q=3.60669e+06 n=528719 tag=gauss
wclsFrameSaver: saving 31629 traces tagged "wiener"
FrameSaver: q=3.87008e+06 n=508596 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 1730 XUs and 2335 XVs -> 42 XUVs
C:0 T:1 1921 XUs and 4023 XVs -> 84 XUVs
C:0 T:2 13483 XUs and 13380 XVs -> 871 XUVs
C:0 T:3 2324 XUs and 2771 XVs -> 83 XUVs
C:0 T:4 570 XUs and 1416 XVs -> 68 XUVs
C:0 T:5 5 XUs and 7 XVs -> 0 XUVs
C:0 T:6 805 XUs and 1551 XVs -> 44 XUVs
C:0 T:7 545 XUs and 1285 XVs -> 96 XUVs
1288 XUVs total
846 collection wire objects
1288 potential space points
Neighbour search...
42304 tests to find 10180 neighbours
Iterating with no regularization...
Begin: 6.31607e+08
0 5.94738e+08
1 5.93832e+08
2 5.93812e+08
Now with regularization...
Begin: 5.84058e+08
0 5.84045e+08
18-Sep-2025 07:30:50 BST  Closed output file "np02vd_raw_run039433_0293_df-s05-d4_dw_0_20250918T032602_reco_stage1_20250918T063050_keepup.root"

==================================================================================================================================
TimeTracker printout (sec)                          Min           Avg           Max         Median          RMS         nEvts   
==================================================================================================================================
Full event                                        81.6023       175.639       1299.87       120.77        216.64         48     
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read)                      6.4554e-05    0.000101938   0.000246084   9.3194e-05    2.67796e-05      48     
produce:tpcrawdecoder:PDVDTPCReader               24.9866       40.1754       61.439        39.105        9.77981        48     
produce:triggerrawdecoder:PDVDTriggerReader4     0.281246      0.371098      0.889953       0.33961      0.115647        48     
produce:pdvddaphne:DAPHNEReaderPDVD               7.98589       11.7972       17.5492       11.5501       1.98443        48     
produce:ophit:OpHitFinder                        0.0351718     0.0619533     0.0748575     0.064114     0.00902336       48     
produce:opflash:OpFlashFinderVerticalDrift      0.00427939     0.0137054     0.0260567     0.0132659     0.0049258       48     
produce:wclsdatavd:WireCellToolkit                30.5225       45.3301       105.022       40.7228       12.9923        48     
produce:gaushit:GausHitFinder                    0.329127      0.796179       2.34848      0.742134      0.356328        48     
produce:nhitsfilter:NumberOfHitsFilter          0.000141016   0.000281681   0.000711313   0.000252125   0.000111696      48     
produce:reco3d:SpacePointSolver                   1.0391        6.07133       30.0428        5.112        4.93466        48     
produce:hitpdune:DisambigFromSpacePoints         0.0286718     0.141106      0.978206      0.0881966     0.180719        48     
produce:pandora:StandardPandora                   3.03826       67.2488       1113.01       16.7146        203.2         48     
produce:pandoraTrack:LArPandoraTrackCreation     0.108382      0.775023       10.6171      0.365737       1.57982        48     
produce:pandoraGnocalo:GnocchiCalorimetry        0.0068158     0.0200455     0.0723183     0.0175481     0.0105406       48     
[art]:TriggerResults:TriggerResultInserter      1.7229e-05    3.99066e-05   8.7464e-05    3.7601e-05    1.30854e-05      48     
end_path:out1:RootOutput                         3.874e-06    7.53821e-06   2.8757e-05     6.478e-06    4.28443e-06      48     
end_path:out1:RootOutput(write)                   1.60016       2.80436       4.02197       2.84597      0.543942        48     
==================================================================================================================================

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

  Peak virtual memory usage (VmPeak)  : 5000.81 MB
  Peak resident set size usage (VmHWM): 3112.39 MB
  Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run039433_0293_df-s05-d4_dw_0_20250918T032602_reco_stage1_20250918T063050_keepup.root
\tHists: np02vd_raw_run039433_0293_df-s05-d4_dw_0_20250918T032602_reco_stage1_20250918T063053_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run039433_0293_df-s05-d4_dw_0_20250918T032602_reco_stage1_20250918T063050_keepup.root
Ran successfully
{
  "name": "np02vd_raw_run039433_0293_df-s05-d4_dw_0_20250918T032602_reco_stage1_20250918T063050_keepup.root",
  "namespace": "vd-protodune-det-reco",
  "metadata": {
    "core.file_format": "artroot",
    "core.application.name": "reco",
    "core.application.family": "dunesw",
    "core.application.version": "v10_10_00d00",
    "core.data_tier": "full-reconstructed",
    "dune.config_file": "standard_reco_stage1_protodunevd_keepup_all.fcl",
    "dune.campaign": "vd-protodune-reco-keepup-v0",
    "core.start_time": 1758177054.0,
    "core.end_time": 1758177054.0,
    "core.events": [
      84004,
      84010,
      84016,
      84022,
      84028,
      84034,
      84040,
      84046,
      84052,
      84058,
      84064,
      84070,
      84076,
      84082,
      84088,
      84094,
      84100,
      84106,
      84112,
      84118,
      84124,
      84130,
      84136,
      84142,
      84148,
      84154,
      84160,
      84166,
      84172,
      84178,
      84184,
      84190,
      84196,
      84202,
      84208,
      84214,
      84220,
      84226,
      84232,
      84238,
      84244,
      84250,
      84256,
      84262,
      84268,
      84274,
      84280,
      84286
    ],
    "core.event_count": 48,
    "core.first_event_number": 84004,
    "core.last_event_number": 84286,
    "core.data_stream": "cosmics",
    "core.file_content_status": "good",
    "core.file_type": "detector",
    "core.run_type": "vd-protodune",
    "core.runs": [
      39433
    ],
    "core.runs_subruns": [
      3943300001
    ],
    "dune.daq_test": false,
    "retention.status": "active",
    "retention.class": "physics"
  },
  "parents": [
    {
      "did": "vd-protodune:np02vd_raw_run039433_0293_df-s05-d4_dw_0_20250918T032602.hdf5"
    }
  ]
}Forming hist metadata
formed
{
  "name": "np02vd_raw_run039433_0293_df-s05-d4_dw_0_20250918T032602_reco_stage1_20250918T063053_keepup_hists.root",
  "namespace": "vd-protodune-det-reco",
  "metadata": {
    "core.file_format": "root",
    "core.application.name": "reco",
    "core.application.family": "dunesw",
    "core.application.version": "v10_10_00d00",
    "core.data_tier": "root-tuple-virtual",
    "dune.config_file": "standard_reco_stage1_protodunevd_keepup_all.fcl",
    "dune.campaign": "vd-protodune-reco-keepup-v0",
    "core.start_time": 1758177054.0,
    "core.end_time": 1758177054.0,
    "core.data_stream": "cosmics",
    "core.file_content_status": "good",
    "core.file_type": "detector",
    "core.run_type": "vd-protodune",
    "core.runs": [
      39433
    ],
    "core.runs_subruns": [
      3943300001
    ],
    "dune.daq_test": false,
    "retention.status": "active",
    "retention.class": "physics"
  },
  "parents": [
    {
      "did": "vd-protodune:np02vd_raw_run039433_0293_df-s05-d4_dw_0_20250918T032602.hdf5"
    }
  ]
}
justIN time: 2025-09-18 23:29:24 UTC       justIN version: 01.05.00