Jobsub ID 236601.40@dunegpschedd02.fnal.gov

Jobsub ID	236601.40@dunegpschedd02.fnal.gov
Workflow ID	9538
Stage ID	1
User name	ykermaid@fnal.gov
HTCondor Group	group_dune.prod_mcsim
Requested	Processors	2
	GPU	No
	RSS bytes	4193255424 (3999 MiB)
	Wall seconds limit	18000 (5 hours)
Submitted time	2025-11-03 10:42:44
Site	NL_SURFsara
Entry	DUNE_SurfSARA_arc03
Last heartbeat	2025-11-03 12:18:48
From worker node	Hostname	wn-lb-02.gina.surf.nl
	cpuinfo	AMD EPYC 9754 128-Core Processor
	OS release	Scientific Linux release 7.9 (Nitrogen)
	Processors	2
	RSS bytes	4194304000 (4000 MiB)
	Wall seconds limit	129600 (36 hours)
	GPU
	Inner Apptainer?	True
Job state	finished
Started	2025-11-03 10:55:00
Input files	vd-protodune:np02vd_raw_run040346_3306_df-s04-d1_dw_0_20251103T102302.hdf5
Jobscript	Exit code	0
	Real time	1h (4849s)
	CPU time	1h (4559s = 94%)
	Max RSS bytes	3996123136 (3811 MiB)
Outputting started	2025-11-03 12:15:50
Output files	vd-protodune-det-reco:np02vd_raw_run040346_3306_df-s04-d1_dw_0_20251103T102302_reco_stage1_20251103T121535_keepup.root
Finished	2025-11-03 12:18:48
Saved logs	justin-logs:236601.40-dunegpschedd02.fnal.gov.logs.tgz
List job events Cached HTCondor job logs

Jobscript log (last 10,000 characters)

14:44.091] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 14.42 sec
[13:14:44.091] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 14.24 sec
[13:14:44.091] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 14.08 sec
[13:14:44.091] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 13.71 sec
[13:14:44.091] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 13.57 sec
[13:14:44.091] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 13.25 sec
[13:14:44.091] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 12.87 sec
[13:14:44.091] I [ timer  ] Timer: WireCell::SigProc::OmnibusSigProc : 12.76 sec
[13:14:44.092] I [ timer  ] Timer: WireCell::Aux::Resampler : 0.25 sec
[13:14:44.092] I [ timer  ] Timer: WireCell::Aux::Resampler : 0.25 sec
[13:14:44.092] I [ timer  ] Timer: WireCell::Aux::Resampler : 0.24 sec
[13:14:44.092] I [ timer  ] Timer: WireCell::Aux::Resampler : 0.24 sec
[13:14:44.092] I [ timer  ] Timer: WireCell::Gen::FrameFanin : 0.02 sec
[13:14:44.092] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[13:14:44.092] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[13:14:44.092] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0.01 sec
[13:14:44.092] I [ timer  ] Timer: WireCell::Gen::FrameFanout : 0.01 sec
[13:14:44.092] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[13:14:44.092] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[13:14:44.092] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[13:14:44.092] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[13:14:44.092] I [ timer  ] Timer: WireCell::Gen::DumpFrames : 0 sec
[13:14:44.092] I [ timer  ] Timer: WireCell::SigProc::ChannelSelector : 0 sec
[13:14:44.092] I [ timer  ] Timer: WireCell::Gen::Retagger : 0 sec
[13:14:44.092] I [ timer  ] Timer: wcls::RawFrameSource : 0 sec
[13:14:44.092] I [ timer  ] Timer: wcls::FrameSaver : 0 sec
[13:14:44.092] I [ timer  ] Timer: Total node execution : 109.93999960646033 sec
wclsFrameSaver saving cooked to 10000 ticks
wclsFrameSaver: saving 47557 traces tagged "gauss"
FrameSaver: q=1.14359e+07 n=1007601 tag=gauss
wclsFrameSaver: saving 59610 traces tagged "wiener"
FrameSaver: q=1.23172e+07 n=966395 tag=wiener
0 X, 0 U, 0 V bad channels
Finding XUV coincidences...
C:0 T:0 1392 XUs and 543 XVs -> 92 XUVs
C:0 T:1 729 XUs and 839 XVs -> 39 XUVs
C:0 T:2 1477 XUs and 1398 XVs -> 84 XUVs
C:0 T:3 2130 XUs and 2409 XVs -> 87 XUVs
C:0 T:4 435 XUs and 474 XVs -> 11 XUVs
C:0 T:5 888 XUs and 768 XVs -> 25 XUVs
C:0 T:6 1170 XUs and 1171 XVs -> 72 XUVs
C:0 T:7 14323 XUs and 9027 XVs -> 891 XUVs
C:0 T:8 731 XUs and 721 XVs -> 58 XUVs
C:0 T:9 540 XUs and 381 XVs -> 16 XUVs
C:0 T:10 331 XUs and 367 XVs -> 30 XUVs
C:0 T:11 265 XUs and 377 XVs -> 34 XUVs
C:0 T:12 1331 XUs and 1568 XVs -> 48 XUVs
C:0 T:13 1851 XUs and 2073 XVs -> 106 XUVs
C:0 T:14 3386 XUs and 3383 XVs -> 178 XUVs
C:0 T:15 979 XUs and 1361 XVs -> 212 XUVs
1983 XUVs total
1285 collection wire objects
1983 potential space points
Neighbour search...
55593 tests to find 17076 neighbours
Iterating with no regularization...
Begin: 7.42709e+09
0 7.17091e+09
1 7.15627e+09
2 7.15599e+09
Now with regularization...
Begin: 7.12448e+09
0 7.12438e+09
BdtBeamParticleIdTool::SliceFeatures::GetLeadingCaloHits - empty calo hit list
BdtBeamParticleIdTool::SliceFeatures::GetLeadingCaloHits - empty calo hit list
BdtBeamParticleIdTool::SliceFeatures::GetLeadingCaloHits - empty calo hit list
03-Nov-2025 13:15:35 CET  Closed output file "np02vd_raw_run040346_3306_df-s04-d1_dw_0_20251103T102302_reco_stage1_20251103T121535_keepup.root"

==================================================================================================================================
TimeTracker printout (sec)                          Min           Avg           Max         Median          RMS         nEvts   
==================================================================================================================================
Full event                                        129.316       207.549       380.907       179.041       61.6603        23     
----------------------------------------------------------------------------------------------------------------------------------
source:HDF5RawInput3(read)                      7.6654e-05    9.8851e-05    0.000232466   9.1045e-05    3.08621e-05      23     
produce:tpcrawdecoder:PDVDTPCReader               13.2196       15.8143       45.1037       14.6264       6.29794        23     
produce:triggerrawdecoder:PDVDTriggerReader4     0.544332      0.583079       0.66561      0.568055      0.0364921       23     
produce:pdvddaphne:DAPHNEReaderPDVD             0.000347159   0.000395985   0.000755557   0.00036901    8.18464e-05      23     
produce:ophit:OpHitFinder                       7.9297e-05    0.000114127   0.000587717   8.6169e-05    0.000102044      23     
produce:opflash:OpFlashFinderVerticalDrift      5.7014e-05    8.02434e-05   0.000371224   6.4286e-05    6.32231e-05      23     
produce:wclsdatavd:WireCellToolkit                86.6477       121.718       212.523       110.613       30.0931        23     
produce:gaushit:GausHitFinder                     1.00199        1.537        2.42054       1.51638      0.360601        23     
produce:nhitsfilter:NumberOfHitsFilter          0.000204777   0.000544125   0.00092443    0.000577492   0.00018788       23     
produce:reco3d:SpacePointSolver                   8.52652       15.5788       28.0486       14.979        4.48653        23     
produce:hitpdune:DisambigFromSpacePoints         0.107903      0.236919      0.566546      0.227484       0.10455        23     
produce:pandora:StandardPandora                   12.7177       44.213        182.386       32.4959       40.2042        23     
produce:pandoraTrack:LArPandoraTrackCreation     0.651593       2.21265       8.31614       1.64726       1.95081        23     
produce:pandoraGnocalo:GnocchiCalorimetry        0.0267108     0.0386013     0.0538203     0.0378519    0.00708186       23     
[art]:TriggerResults:TriggerResultInserter       3.409e-05    5.24837e-05   0.000116673   4.8573e-05    1.56473e-05      23     
end_path:out1:RootOutput                         7.48e-06     1.12514e-05   3.2109e-05     9.865e-06    5.30121e-06      23     
end_path:out1:RootOutput(write)                   4.9602        5.49427       6.6616        5.35222      0.396291        23     
==================================================================================================================================

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

  Peak virtual memory usage (VmPeak)  : 6015.19 MB
  Peak resident set size usage (VmHWM): 3996.12 MB
  Details saved in: 'mem.db'
====================================================================================================
Art has completed and will exit with status 0.
Output files:
\tReco: np02vd_raw_run040346_3306_df-s04-d1_dw_0_20251103T102302_reco_stage1_20251103T121535_keepup.root
\tHists: np02vd_raw_run040346_3306_df-s04-d1_dw_0_20251103T102302_reco_stage1_20251103T121535_keepup_hists.root
Forming reco metadata
Successfully opened file np02vd_raw_run040346_3306_df-s04-d1_dw_0_20251103T102302_reco_stage1_20251103T121535_keepup.root
Ran successfully
{
  "name": "np02vd_raw_run040346_3306_df-s04-d1_dw_0_20251103T102302_reco_stage1_20251103T121535_keepup.root",
  "namespace": "vd-protodune-det-reco",
  "metadata": {
    "core.file_format": "artroot",
    "core.application.name": "reco",
    "core.application.family": "dunesw",
    "core.application.version": "v10_11_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": 1762172136.0,
    "core.end_time": 1762172136.0,
    "core.events": [
      305297,
      305301,
      305305,
      305309,
      305313,
      305317,
      305321,
      305325,
      305329,
      305333,
      305337,
      305341,
      305345,
      305349,
      305353,
      305357,
      305361,
      305365,
      305369,
      305373,
      305377,
      305381,
      305385
    ],
    "core.event_count": 23,
    "core.first_event_number": 305297,
    "core.last_event_number": 305385,
    "core.data_stream": "cosmics",
    "core.file_content_status": "good",
    "core.file_type": "detector",
    "core.run_type": "vd-protodune",
    "core.runs": [
      40346
    ],
    "core.runs_subruns": [
      4034600001
    ],
    "dune.daq_test": false,
    "retention.status": "active",
    "retention.class": "physics"
  },
  "parents": [
    {
      "did": "vd-protodune:np02vd_raw_run040346_3306_df-s04-d1_dw_0_20251103T102302.hdf5"
    }
  ]
}Forming hist metadata
formed
{
  "name": "np02vd_raw_run040346_3306_df-s04-d1_dw_0_20251103T102302_reco_stage1_20251103T121535_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_11_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": 1762172136.0,
    "core.end_time": 1762172136.0,
    "core.data_stream": "cosmics",
    "core.file_content_status": "good",
    "core.file_type": "detector",
    "core.run_type": "vd-protodune",
    "core.runs": [
      40346
    ],
    "core.runs_subruns": [
      4034600001
    ],
    "dune.daq_test": false,
    "retention.status": "active",
    "retention.class": "physics"
  },
  "parents": [
    {
      "did": "vd-protodune:np02vd_raw_run040346_3306_df-s04-d1_dw_0_20251103T102302.hdf5"
    }
  ]
}