Jobsub ID 303729.118@dunegpschedd01.fnal.gov

Jobsub ID	303729.118@dunegpschedd01.fnal.gov
Workflow ID	12717
Stage ID	2
User name	ykermaid@fnal.gov
Requested	Processors	1
	GPU	No
	RSS bytes	4194304000 (4000 MiB)
	Wall seconds limit	86400 (24 hours)
Submitted time	2026-02-04 01:20:31
Site	US_FNAL-T1
Entry	CMSHTPC_T1_US_FNAL_condce_opp1_whole
Last heartbeat	2026-02-04 04:25:31
From worker node	Hostname	dunegli-50891-0-cmswn2381.fnal.gov
	cpuinfo	Intel(R) Xeon(R) CPU E5-2670 v3 @ 2.30GHz
	OS release	Scientific Linux release 7.9 (Nitrogen)
	Processors	1
	RSS bytes	4194304000 (4000 MiB)
	Wall seconds limit	171000 (47 hours)
	GPU
	Inner Apptainer?	True
Job state	jobscript_error
Started	2026-02-04 04:15:22
Input files	usertests:np02vd_raw_run042421_0006_df-s03-d1_dw_0_20260203T133408_reco_stage0_20260204T013954_offline.root
Jobscript	Exit code	1
	Real time	0m (0s)
	CPU time	0m (0s = 0%)
	Max RSS bytes	0 (0 MiB)
Outputting started
Output files
Finished	2026-02-04 04:25:31
Saved logs	justin-logs:303729.118-dunegpschedd01.fnal.gov.logs.tgz
List job events Cached HTCondor job logs
Jobscript log (last 10,000 characters)

::L416 Saving sparse3d_reco_tpc_tree entry 2
     [94m[DEBUG][00m [0m [94m<IOManager::save_entry>[00m IOManager.cxx::L416 Saving sparse3d_reco_hit_charge0_tree entry 2
     [94m[DEBUG][00m [0m [94m<IOManager::save_entry>[00m IOManager.cxx::L416 Saving sparse3d_reco_hit_charge1_tree entry 2
     [94m[DEBUG][00m [0m [94m<IOManager::save_entry>[00m IOManager.cxx::L416 Saving sparse3d_reco_hit_charge2_tree entry 2
     [94m[DEBUG][00m [0m [94m<IOManager::save_entry>[00m IOManager.cxx::L416 Saving sparse3d_reco_hit_key0_tree entry 2
     [94m[DEBUG][00m [0m [94m<IOManager::save_entry>[00m IOManager.cxx::L416 Saving sparse3d_reco_hit_key1_tree entry 2
     [94m[DEBUG][00m [0m [94m<IOManager::save_entry>[00m IOManager.cxx::L416 Saving sparse3d_reco_hit_key2_tree entry 2
     [94m[DEBUG][00m [0m [94m<IOManager::clear_entry>[00m IOManager.cxx::L460 Set _last_event_id to externally set values: run = 42421 subrun = 1 event = 987
Begin processing the 4th record. run: 42421 subRun: 1 event: 993 at 04-Feb-2026 04:25:19 UTC
PandoraContentApi::GetList(*this, m_inputHitListName, pCaloHitList) return STATUS_CODE_NOT_INITIALIZED
    in function: GetVolumeIdToHitListMap
    in file:     /scratch/workspace/build-larsoft/BUILDTYPE/prof/QUAL/s131-e26/label1/swarm/label2/ALMA9/build/larpandoracontent/v04_18_01-buildFW/src/larpandoracontent/LArControlFlow/MasterAlgorithm.cc line#: 271
this->GetVolumeIdToHitListMap(volumeIdToHitListMap) return STATUS_CODE_NOT_INITIALIZED
    in function: Run
    in file:     /scratch/workspace/build-larsoft/BUILDTYPE/prof/QUAL/s131-e26/label1/swarm/label2/ALMA9/build/larpandoracontent/v04_18_01-buildFW/src/larpandoracontent/LArControlFlow/MasterAlgorithm.cc line#: 165
iter->second->Run() throw STATUS_CODE_NOT_INITIALIZED
    in function: RunAlgorithm
    in file:     /scratch/workspace/build-larsoft/BUILDTYPE/prof/QUAL/s131-e26/label1/swarm/label2/ALMA9/build/pandora/v04_17_05/src/pandora-v04-17-05/PandoraSDK-v04-01-00/src/Api/PandoraContentApiImpl.cc line#: 263
Failure in algorithm Alg0003, LArMaster, STATUS_CODE_NOT_INITIALIZED
     [94m[DEBUG][00m [0m [94m<ProcessDriver::process_ptr>[00m ProcessDriver.cxx::L84 Called
     [94m[DEBUG][00m [0m [94m<ProcessDriver::process_ptr>[00m ProcessDriver.cxx::L84 Called
Attempted to load data: cluster3d
      [92m[INFO][00m [0m [94m<IOManager::set_id::L569>[00m Request to set event id: 0042421_00001_000993
     [94m[DEBUG][00m [0m [94m<ProcessDriver::process_entry>[00m ProcessDriver.cxx::L314 Called
      [92m[INFO][00m [0m [94m<SuperaBBoxInteraction::process::L173>[00m 3D Meta:X range: -514.08 => 514.08 ... 1344 bins
Y range: -342.72 => 342.72 ... 896 bins
Z range: -21.71 => 321.01 ... 448 bins

     [94m[DEBUG][00m [0m [94m<IOManager::get_data>[00m IOManager.cxx::L499 start
     [94m[DEBUG][00m [0m [94m<IOManager::producer_id>[00m IOManager.cxx::L479 start
     [94m[DEBUG][00m [0m [94m<IOManager::get_data>[00m IOManager.cxx::L519 start
     [94m[DEBUG][00m [0m [94m<IOManager::get_data>[00m IOManager.cxx::L499 start
     [94m[DEBUG][00m [0m [94m<IOManager::producer_id>[00m IOManager.cxx::L479 start
     [94m[DEBUG][00m [0m [94m<IOManager::get_data>[00m IOManager.cxx::L519 start
      [92m[INFO][00m [0m [94m<SuperaSpacePoint::process::L83>[00m Voxel3DMeta: X range: -514.08 => 514.08 ... 1344 bins
Y range: -342.72 => 342.72 ... 896 bins
Z range: -21.71 => 321.01 ... 448 bins
     [94m[DEBUG][00m [0m [94m<ProcessDriver::finalize>[00m ProcessDriver.cxx::L424 called
      [92m[INFO][00m [0m [94m<ProcessDriver::finalize::L427>[00m Finalizing: SuperaBBoxInteraction
      [92m[INFO][00m [0m [94m<ProcessDriver::finalize::L427>[00m Finalizing: SuperaSpacePoint
      [92m[INFO][00m [0m [94m<ProcessDriver::finalize::L434>[00m Compiling time profile...
      [92m[INFO][00m [0m [94m<ProcessDriver::finalize::L457>[00m Finalizing IO...
     [94m[DEBUG][00m [0m [94m<IOManager::finalize>[00m IOManager.cxx::L611 start
    [95m[NORMAL][00m [0m [94m<IOManager::finalize>[00m Writing sparse3d_reco_tree with 3 entries
    [95m[NORMAL][00m [0m [94m<IOManager::finalize>[00m Writing sparse3d_reco_chi2_tree with 3 entries
    [95m[NORMAL][00m [0m [94m<IOManager::finalize>[00m Writing sparse3d_reco_cryo_tree with 3 entries
    [95m[NORMAL][00m [0m [94m<IOManager::finalize>[00m Writing sparse3d_reco_tpc_tree with 3 entries
    [95m[NORMAL][00m [0m [94m<IOManager::finalize>[00m Writing sparse3d_reco_hit_charge0_tree with 3 entries
    [95m[NORMAL][00m [0m [94m<IOManager::finalize>[00m Writing sparse3d_reco_hit_charge1_tree with 3 entries
    [95m[NORMAL][00m [0m [94m<IOManager::finalize>[00m Writing sparse3d_reco_hit_charge2_tree with 3 entries
    [95m[NORMAL][00m [0m [94m<IOManager::finalize>[00m Writing sparse3d_reco_hit_key0_tree with 3 entries
    [95m[NORMAL][00m [0m [94m<IOManager::finalize>[00m Writing sparse3d_reco_hit_key1_tree with 3 entries
    [95m[NORMAL][00m [0m [94m<IOManager::finalize>[00m Writing sparse3d_reco_hit_key2_tree with 3 entries
    [95m[NORMAL][00m [0m [94m<IOManager::finalize>[00m Closing output file
      [92m[INFO][00m [0m [94m<IOManager::finalize::L639>[00m Deleting data pointers
     [94m[DEBUG][00m [0m [94m<IOManager::reset>[00m IOManager.cxx::L647 start
      [92m[INFO][00m [0m [94m<ProcessDriver::finalize::L459>[00m Resetting...
     [94m[DEBUG][00m [0m [94m<ProcessDriver::reset>[00m ProcessDriver.cxx::L25 Called
     [94m[DEBUG][00m [0m [94m<IOManager::reset>[00m IOManager.cxx::L647 start
04-Feb-2026 04:25:20 UTC  Closed input file "root://fndcadoor.fnal.gov:1094/pnfs/fnal.gov/usr/dune/persistent/staging/usertests/4d/96/np02vd_raw_run042421_0006_df-s03-d1_dw_0_20260203T133408_reco_stage0_20260204T013954_offline.root"

===========================================================================================================================================
TimeTracker printout (sec)                                   Min           Avg           Max         Median          RMS         nEvts   
===========================================================================================================================================
Full event                                               0.000840853     108.986       217.94        109.002       77.8916         4     
-------------------------------------------------------------------------------------------------------------------------------------------
source:RootInput(read)                                   0.00039936    0.000783315   0.00116004    0.000786928   0.000271655       4     
produce:opflash:OpFlashFinderVerticalDrift                0.0143215     0.0295897     0.0525584     0.0257394     0.014149         4     
produce:pandora:StandardPandora                           0.0015935      103.928       211.417       102.147       75.6401         4     
produce:pandoraWriter:StandardPandora                    0.000195808    0.586697       1.86646      0.240067      0.745416         4     
produce:pandoraTrack:LArPandoraTrackCreation             0.000234063     1.91428       3.60465       2.02612       1.4241          4     
produce:pandoraShower:LArPandoraModularShowerCreation    0.000298193    0.470616      0.855562      0.513302      0.309039         4     
produce:pandoraGnocalo:GnocchiCalorimetry                0.000226473    0.0461859     0.075978      0.0542695     0.029075         4     
produce:pandorapid:Chi2ParticleID                        6.9073e-05    0.00327343    0.00520506    0.00390979    0.00197204        4     
[art]:TriggerResults:TriggerResultInserter               2.3268e-05    3.45278e-05   4.9815e-05    3.2514e-05    9.82884e-06       4     
end_path:out1:RootOutput                                  5.398e-06    1.19535e-05    1.982e-05    1.1298e-05    5.1425e-06        4     
end_path:supera:LArSoftSuperaDriver                        1.70752       2.17076       2.45317       2.3516       0.330178         3     
end_path:out1:RootOutput(write)                           0.429705      0.498116      0.537713      0.526929      0.0485736        3     
===========================================================================================================================================

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

  Peak virtual memory usage (VmPeak)  : 2157.16 MB
  Peak resident set size usage (VmHWM): 1040.43 MB
  Details saved in: 'mem.db'
====================================================================================================
%MSG-s ArtException:  PostEndJob 04-Feb-2026 04:25:20 UTC ModuleEndJob
---- EventProcessorFailure BEGIN
  EventProcessor: an exception occurred during current event processing
  ---- EventProcessorFailure BEGIN
    EndPathExecutor: an exception occurred during current event processing
    ---- ScheduleExecutionFailure BEGIN
      Path: ProcessingStopped.
      ---- ProductNotFound BEGIN
        Found zero products matching all selection criteria
          C++ type: std::vector<recob::SpacePoint>
          Module label: 'cluster3d'
          Product instance name: ''
          Process name: (empty)
        The above exception was thrown while processing module LArSoftSuperaDriver/supera run: 42421 subRun: 1 event: 993
      ---- ProductNotFound END
      Exception going through path end_path
    ---- ScheduleExecutionFailure END
  ---- EventProcessorFailure END
---- EventProcessorFailure END
---- FatalRootError BEGIN
  Fatal Root Error: TTree::SetEntries
  Tree branches have different numbers of entries, eg EventAuxiliary has 3 entries while recob::SpacePoints_cluster3d_Vertex_pdvdofflinestage0. has 28 entries.
  ROOT severity: 2000
---- FatalRootError END
%MSG
Art has completed and will exit with status 1.
Error in reco1