Build log

The build generated 96,796 lines of output.The output is too long and has been truncated to the last 1,000 lines. Download or view full build log.

28-Mar-2025 08:58:13	2025-03-28 08:58:13 INFO MPICommandServer::command_request_handler_service::AWProjectFT2::getImage[R&D]::MPIServer-2+ [8838.74]
28-Mar-2025 08:58:13	2025-03-28 08:58:13 INFO MPICommandServer::command_request_handler_service::AWProjectFT2::getImage[R&D]::MPIServer-2+ (3.56723,0.306554) (0,0)
28-Mar-2025 08:58:13	2025-03-28 08:58:13 INFO MPICommandServer::command_request_handler_service::AWProjectFT2::getImage[R&D]::MPIServer-1 Sum of weights: Axis Lengths: [1, 1] (NB: Matrix in Row/Column order)
28-Mar-2025 08:58:13	2025-03-28 08:58:13 INFO MPICommandServer::command_request_handler_service::AWProjectFT2::getImage[R&D]::MPIServer-1+ [8830.19]
28-Mar-2025 08:58:13	2025-03-28 08:58:13 INFO MPICommandServer::command_request_handler_service::AWProjectFT2::getImage[R&D]::MPIServer-1+ (3.45109,0.0280062) (0,0)
28-Mar-2025 08:58:13	2025-03-28 08:58:13 WARN MPICommandServer::command_request_handler_service::AWProjectFT::finalizeToSky::MPIServer-3 time to massage data 0.04
28-Mar-2025 08:58:13	2025-03-28 08:58:13 WARN MPICommandServer::command_request_handler_service::AWProjectFT::finalizeToSky::MPIServer-3 time gridding 0.03
28-Mar-2025 08:58:13	2025-03-28 08:58:13 INFO MPICommandServer::command_request_handler_service::AWProjectFT2::getImage[R&D]::MPIServer-3 Sum of weights: Axis Lengths: [1, 1] (NB: Matrix in Row/Column order)
28-Mar-2025 08:58:13	2025-03-28 08:58:13 INFO MPICommandServer::command_request_handler_service::AWProjectFT2::getImage[R&D]::MPIServer-3+ [-7.52245]
28-Mar-2025 08:58:13	2025-03-28 08:58:13 INFO MPICommandServer::command_request_handler_service::AWProjectFT2::getImage[R&D]::MPIServer-3+ (-0.292432,-0.0043994) (0,0)
28-Mar-2025 08:58:13	2025-03-28 08:58:13 WARN MPICommandServer::command_request_handler_service::AWProjectFT::finalizeToSky::MPIServer-2 time to massage data 0.03
28-Mar-2025 08:58:13	2025-03-28 08:58:13 WARN MPICommandServer::command_request_handler_service::AWProjectFT::finalizeToSky::MPIServer-2 time gridding 0.04
28-Mar-2025 08:58:13	2025-03-28 08:58:13 WARN MPICommandServer::command_request_handler_service::AWProjectFT::finalizeToSky::MPIServer-1 time to massage data 0.02
28-Mar-2025 08:58:13	2025-03-28 08:58:13 WARN MPICommandServer::command_request_handler_service::AWProjectFT::finalizeToSky::MPIServer-1 time gridding 0.01
28-Mar-2025 08:58:13	2025-03-28 08:58:13 INFO MPICommandServer::command_request_handler_service::AWProjectFT2::getImage[R&D]::MPIServer-2 Sum of weights: Axis Lengths: [1, 1] (NB: Matrix in Row/Column order)
28-Mar-2025 08:58:13	2025-03-28 08:58:13 INFO MPICommandServer::command_request_handler_service::AWProjectFT2::getImage[R&D]::MPIServer-2+ [-9.40991]
28-Mar-2025 08:58:13	2025-03-28 08:58:13 INFO MPICommandServer::command_request_handler_service::AWProjectFT2::getImage[R&D]::MPIServer-2+ (0.304551,0.025521) (0,0)
28-Mar-2025 08:58:13	2025-03-28 08:58:13 INFO MPICommandServer::command_request_handler_service::AWProjectFT2::getImage[R&D]::MPIServer-1 Sum of weights: Axis Lengths: [1, 1] (NB: Matrix in Row/Column order)
28-Mar-2025 08:58:13	2025-03-28 08:58:13 INFO MPICommandServer::command_request_handler_service::AWProjectFT2::getImage[R&D]::MPIServer-1+ [-8.47029]
28-Mar-2025 08:58:13	2025-03-28 08:58:13 INFO MPICommandServer::command_request_handler_service::AWProjectFT2::getImage[R&D]::MPIServer-1+ (0.293382,-0.0470198) (0,0)
28-Mar-2025 08:58:13	2025-03-28 08:58:14 INFO tclean::::casa ...done
28-Mar-2025 08:58:13	2025-03-28 08:58:14 INFO SynthesisNormalizer::gatherImages Gather residual images : [/home/casatest/work/test_task_tclean/tst.workdirectory/tst.n1, /home/casatest/work/test_task_tclean/tst.workdirectory/tst.n2, /home/casatest/work/test_task_tclean/tst.workdirectory/tst.n3] onto :tst
28-Mar-2025 08:58:13	2025-03-28 08:58:14 WARN SIImageStore::Open existing Images (file /source/casa6/casatools/src/code/synthesis/ImagerObjects/SIImageStore.cc, line 618) Mismatch in Csys latpoles between existing image on disk ([299.869, 40.7338, 180, 40.7338]) and current imaging run ([299.869, 40.7337, 180, 40.7337]) : The DirectionCoordinates have differing latpoles -- Resetting to match image on disk
28-Mar-2025 08:58:13	2025-03-28 08:58:14 WARN SIImageStore::Open existing Images (file /source/casa6/casatools/src/code/synthesis/ImagerObjects/SIImageStore.cc, line 618) Mismatch in Csys latpoles between existing image on disk ([299.869, 40.7337, 180, 40.7337]) and current imaging run ([299.869, 40.7338, 180, 40.7338]) : The DirectionCoordinates have differing latpoles -- Resetting to match image on disk
28-Mar-2025 08:58:13	2025-03-28 08:58:14 WARN SIImageStore::Open existing Images (file /source/casa6/casatools/src/code/synthesis/ImagerObjects/SIImageStore.cc, line 618) Mismatch in Csys latpoles between existing image on disk ([299.869, 40.7338, 180, 40.7338]) and current imaging run ([299.869, 40.7337, 180, 40.7337]) : The DirectionCoordinates have differing latpoles -- Resetting to match image on disk
28-Mar-2025 08:58:13	2025-03-28 08:58:14 WARN SIImageStore::Open existing Images (file /source/casa6/casatools/src/code/synthesis/ImagerObjects/SIImageStore.cc, line 618) Mismatch in Csys latpoles between existing image on disk ([299.869, 40.7337, 180, 40.7337]) and current imaging run ([299.869, 40.7338, 180, 40.7338]) : The DirectionCoordinates have differing latpoles -- Resetting to match image on disk
28-Mar-2025 08:58:13	2025-03-28 08:58:14 INFO task_tclean::SynthesisDeconvolver::initMinorCycle Absolute Peak residual within mask : 0.136883, over full image : 0.136883
28-Mar-2025 08:58:13	2025-03-28 08:58:14 INFO tclean::::casa Minor Cycle controls : {'cycleniter': 9, 'cyclethreshold': 0.017156723886728287, 'loopgain': 0.10000000149011612, 'nsigma': 0.0, 'thresholdreached': False}
28-Mar-2025 08:58:13	2025-03-28 08:58:14 INFO SDAlgorithmBase::deconvolve [tst] Run mtmfs minor-cycle \| CycleThreshold=0.0171567, CycleNiter=9, Gain=0.1
28-Mar-2025 08:58:13	2025-03-28 08:58:14 WARN SIImageStore::Open existing Images (file /source/casa6/casatools/src/code/synthesis/ImagerObjects/SIImageStore.cc, line 618) Mismatch in Csys latpoles between existing image on disk ([299.869, 40.7338, 180, 40.7338]) and current imaging run ([299.869, 40.7337, 180, 40.7337]) : The DirectionCoordinates have differing latpoles -- Resetting to match image on disk
28-Mar-2025 08:58:13	2025-03-28 08:58:14 WARN SIImageStore::Open existing Images (file /source/casa6/casatools/src/code/synthesis/ImagerObjects/SIImageStore.cc, line 618) Mismatch in Csys latpoles between existing image on disk ([299.869, 40.7337, 180, 40.7337]) and current imaging run ([299.869, 40.7338, 180, 40.7338]) : The DirectionCoordinates have differing latpoles -- Resetting to match image on disk
28-Mar-2025 08:58:13	2025-03-28 08:58:14 WARN SIImageStore::Open existing Images (file /source/casa6/casatools/src/code/synthesis/ImagerObjects/SIImageStore.cc, line 618) Mismatch in Csys latpoles between existing image on disk ([299.869, 40.7338, 180, 40.7338]) and current imaging run ([299.869, 40.7337, 180, 40.7337]) : The DirectionCoordinates have differing latpoles -- Resetting to match image on disk
28-Mar-2025 08:58:13	2025-03-28 08:58:14 WARN SIImageStore::Open existing Images (file /source/casa6/casatools/src/code/synthesis/ImagerObjects/SIImageStore.cc, line 618) Mismatch in Csys latpoles between existing image on disk ([299.869, 40.7337, 180, 40.7337]) and current imaging run ([299.869, 40.7338, 180, 40.7338]) : The DirectionCoordinates have differing latpoles -- Resetting to match image on disk
28-Mar-2025 08:58:13	2025-03-28 08:58:14 INFO SIImageStoreMultiTerm::calcFractionalBandwidth MFS frequency range : 1.04999 GHz -> 1.94998GHz.Fractional Bandwidth : 60.0001 %.Reference Frequency for Taylor Expansion : 1.49998GHz.
28-Mar-2025 08:58:13	2025-03-28 08:58:14 INFO MultiTermMatrixCleaner::mtclean() Calculating convolutions of residual images with scales
28-Mar-2025 08:58:13	2025-03-28 08:58:14 INFO MultiTermMatrixCleaner::mtclean() Peak convolved residual (within mask) : 0.136883
28-Mar-2025 08:58:13	2025-03-28 08:58:14 INFO MultiTermMatrixCleaner::mtclean() Reached max number of iterations for this minor cycle
28-Mar-2025 08:58:13	2025-03-28 08:58:14 INFO MultiTermMatrixCleaner::mtclean() Total flux by scale : [0]: 0.910652 (in this run)
28-Mar-2025 08:58:13	2025-03-28 08:58:14 INFO MultiTermMatrixCleaner::mtclean() Total flux by Taylor coefficient : [0]: 0.910652 [1]: 0.0487351
28-Mar-2025 08:58:13	2025-03-28 08:58:14 INFO SDAlgorithmBase::deconvolve [tst] iters=0->9 [9], model=0.8268->0.910652, peakres=0.136883->0.0530315, Reached cycleniter.
28-Mar-2025 08:58:14	2025-03-28 08:58:14 INFO grpcInteractiveCleanManager::mergeCycleExecutionRecord Completed 30 iterations.
28-Mar-2025 08:58:14	2025-03-28 08:58:14 INFO task_tclean::SynthesisNormalizer::scatterModel Send the model from : tst to all nodes :[/home/casatest/work/test_task_tclean/tst.workdirectory/tst.n1, /home/casatest/work/test_task_tclean/tst.workdirectory/tst.n2, /home/casatest/work/test_task_tclean/tst.workdirectory/tst.n3]
28-Mar-2025 08:58:14	2025-03-28 08:58:14 INFO task_tclean::SIImageStore::setModelImageOne Copying input model tst.model.tt0 to /home/casatest/work/test_task_tclean/tst.workdirectory/tst.n1.model.tt0
28-Mar-2025 08:58:14	2025-03-28 08:58:14 INFO task_tclean::SIImageStore::setModelImageOne Copying input model tst.model.tt1 to /home/casatest/work/test_task_tclean/tst.workdirectory/tst.n1.model.tt1
28-Mar-2025 08:58:14	2025-03-28 08:58:14 INFO task_tclean::SIImageStore::setModelImageOne Copying input model tst.model.tt0 to /home/casatest/work/test_task_tclean/tst.workdirectory/tst.n2.model.tt0
28-Mar-2025 08:58:14	2025-03-28 08:58:14 INFO task_tclean::SIImageStore::setModelImageOne Copying input model tst.model.tt1 to /home/casatest/work/test_task_tclean/tst.workdirectory/tst.n2.model.tt1
28-Mar-2025 08:58:14	2025-03-28 08:58:14 INFO task_tclean::SIImageStore::setModelImageOne Copying input model tst.model.tt0 to /home/casatest/work/test_task_tclean/tst.workdirectory/tst.n3.model.tt0
28-Mar-2025 08:58:14	2025-03-28 08:58:14 INFO task_tclean::SIImageStore::setModelImageOne Copying input model tst.model.tt1 to /home/casatest/work/test_task_tclean/tst.workdirectory/tst.n3.model.tt1
28-Mar-2025 08:58:14	2025-03-28 08:58:14 INFO tclean::::casa ----------------------------- Running Parallel Major Cycle ----------------------------
28-Mar-2025 08:58:14	2025-03-28 08:58:14 INFO tclean::::casa checkJobs. Blocking for nodes to finish
28-Mar-2025 08:58:14	2025-03-28 08:58:14 INFO MPICommandServer::command_request_handler_service::SynthesisImager::executeMajorCycle::MPIServer-2 ----------------------------------------------------------- Run Major Cycle 3 -------------------------------------
28-Mar-2025 08:58:14	2025-03-28 08:58:14 INFO MPICommandServer::command_request_handler_service::SynthesisImager::executeMajorCycle::MPIServer-1 ----------------------------------------------------------- Run Major Cycle 3 -------------------------------------
28-Mar-2025 08:58:14	2025-03-28 08:58:14 INFO MPICommandServer::command_request_handler_service::AWProjectFT2::init[R&D]::MPIServer-2 Using CPUResampler visibility resampler (a.k.a. "gridder/degridder")
28-Mar-2025 08:58:14	2025-03-28 08:58:14 INFO MPICommandServer::command_request_handler_service::PhaseGrad::computeAntennaPointingGrad::MPIServer-2 Computing Phase Grad for Field : 0 for spw :0
28-Mar-2025 08:58:14	2025-03-28 08:58:14 INFO MPICommandServer::command_request_handler_service::SynthesisImager::executeMajorCycle::MPIServer-3 ----------------------------------------------------------- Run Major Cycle 3 -------------------------------------
28-Mar-2025 08:58:14	2025-03-28 08:58:14 INFO MPICommandServer::command_request_handler_service::AWProjectFT2::init[R&D]::MPIServer-1 Using CPUResampler visibility resampler (a.k.a. "gridder/degridder")
28-Mar-2025 08:58:14	2025-03-28 08:58:14 INFO MPICommandServer::command_request_handler_service::PhaseGrad::computeAntennaPointingGrad::MPIServer-1 Computing Phase Grad for Field : 0 for spw :0
28-Mar-2025 08:58:14	2025-03-28 08:58:14 INFO MPICommandServer::command_request_handler_service::AWProjectFT2::init[R&D]::MPIServer-3 Using CPUResampler visibility resampler (a.k.a. "gridder/degridder")
28-Mar-2025 08:58:14	2025-03-28 08:58:14 INFO MPICommandServer::command_request_handler_service::PhaseGrad::computeAntennaPointingGrad::MPIServer-3 Computing Phase Grad for Field : 0 for spw :0
28-Mar-2025 08:58:14	2025-03-28 08:58:14 INFO MPICommandServer::command_request_handler_service::AWProjectFT2::init[R&D]::MPIServer-2 Using CPUResampler visibility resampler (a.k.a. "gridder/degridder")
28-Mar-2025 08:58:14	2025-03-28 08:58:14 INFO MPICommandServer::command_request_handler_service::AWProjectFT2::init[R&D]::MPIServer-3 Using CPUResampler visibility resampler (a.k.a. "gridder/degridder")
28-Mar-2025 08:58:14	2025-03-28 08:58:14 INFO MPICommandServer::command_request_handler_service::AWProjectFT2::init[R&D]::MPIServer-1 Using CPUResampler visibility resampler (a.k.a. "gridder/degridder")
28-Mar-2025 08:58:14	2025-03-28 08:58:15 INFO MPICommandServer::command_request_handler_service::AWProjectFT2::init[R&D]::MPIServer-2 Using CPUResampler visibility resampler (a.k.a. "gridder/degridder")
28-Mar-2025 08:58:14	2025-03-28 08:58:15 INFO MPICommandServer::command_request_handler_service::AWProjectFT2::initializeToSky[R&D]::MPIServer-2 Computed maps using FTMachine::initMaps. polMap = [0, 0]
28-Mar-2025 08:58:14	2025-03-28 08:58:15 INFO MPICommandServer::command_request_handler_service::AWProjectFT2::init[R&D]::MPIServer-2 Using CPUResampler visibility resampler (a.k.a. "gridder/degridder")
28-Mar-2025 08:58:14	2025-03-28 08:58:15 INFO MPICommandServer::command_request_handler_service::AWProjectFT2::initializeToSky[R&D]::MPIServer-2 Computed maps using FTMachine::initMaps. polMap = [0, 0]
28-Mar-2025 08:58:14	2025-03-28 08:58:15 INFO MPICommandServer::command_request_handler_service::AWProjectFT2::init[R&D]::MPIServer-3 Using CPUResampler visibility resampler (a.k.a. "gridder/degridder")
28-Mar-2025 08:58:14	2025-03-28 08:58:15 INFO MPICommandServer::command_request_handler_service::AWProjectFT2::initializeToSky[R&D]::MPIServer-3 Computed maps using FTMachine::initMaps. polMap = [0, 0]
28-Mar-2025 08:58:14	2025-03-28 08:58:15 INFO MPICommandServer::command_request_handler_service::AWProjectFT2::init[R&D]::MPIServer-3 Using CPUResampler visibility resampler (a.k.a. "gridder/degridder")
28-Mar-2025 08:58:14	2025-03-28 08:58:15 INFO MPICommandServer::command_request_handler_service::AWProjectFT2::initializeToSky[R&D]::MPIServer-3 Computed maps using FTMachine::initMaps. polMap = [0, 0]
28-Mar-2025 08:58:14	2025-03-28 08:58:15 INFO MPICommandServer::command_request_handler_service::AWProjectFT2::init[R&D]::MPIServer-1 Using CPUResampler visibility resampler (a.k.a. "gridder/degridder")
28-Mar-2025 08:58:14	2025-03-28 08:58:15 INFO MPICommandServer::command_request_handler_service::AWProjectFT2::initializeToSky[R&D]::MPIServer-1 Computed maps using FTMachine::initMaps. polMap = [0, 0]
28-Mar-2025 08:58:14	2025-03-28 08:58:15 INFO MPICommandServer::command_request_handler_service::AWProjectFT2::init[R&D]::MPIServer-1 Using CPUResampler visibility resampler (a.k.a. "gridder/degridder")
28-Mar-2025 08:58:14	2025-03-28 08:58:15 INFO MPICommandServer::command_request_handler_service::AWProjectFT2::initializeToSky[R&D]::MPIServer-1 Computed maps using FTMachine::initMaps. polMap = [0, 0]
28-Mar-2025 08:58:14	2025-03-28 08:58:15 INFO MPICommandServer::command_request_handler_service::PhaseGrad::computeAntennaPointingGrad::MPIServer-2 Computing Phase Grad for Field : 1 for spw :0
28-Mar-2025 08:58:14	2025-03-28 08:58:15 INFO MPICommandServer::command_request_handler_service::PhaseGrad::computeAntennaPointingGrad::MPIServer-3 Computing Phase Grad for Field : 1 for spw :0
28-Mar-2025 08:58:14	2025-03-28 08:58:15 INFO MPICommandServer::command_request_handler_service::PhaseGrad::computeAntennaPointingGrad::MPIServer-1 Computing Phase Grad for Field : 1 for spw :0
28-Mar-2025 08:58:14	2025-03-28 08:58:15 INFO MPICommandServer::command_request_handler_service::PhaseGrad::computeAntennaPointingGrad::MPIServer-2 Computing Phase Grad for Field : 0 for spw :1
28-Mar-2025 08:58:14	2025-03-28 08:58:15 INFO MPICommandServer::command_request_handler_service::PhaseGrad::computeAntennaPointingGrad::MPIServer-3 Computing Phase Grad for Field : 0 for spw :1
28-Mar-2025 08:58:14	2025-03-28 08:58:15 INFO MPICommandServer::command_request_handler_service::PhaseGrad::computeAntennaPointingGrad::MPIServer-1 Computing Phase Grad for Field : 0 for spw :1
28-Mar-2025 08:58:14	2025-03-28 08:58:15 INFO MPICommandServer::command_request_handler_service::PhaseGrad::computeAntennaPointingGrad::MPIServer-2 Computing Phase Grad for Field : 1 for spw :1
28-Mar-2025 08:58:14	2025-03-28 08:58:15 INFO MPICommandServer::command_request_handler_service::PhaseGrad::computeAntennaPointingGrad::MPIServer-3 Computing Phase Grad for Field : 1 for spw :1
28-Mar-2025 08:58:14	2025-03-28 08:58:15 INFO MPICommandServer::command_request_handler_service::PhaseGrad::computeAntennaPointingGrad::MPIServer-1 Computing Phase Grad for Field : 1 for spw :1
28-Mar-2025 08:58:14	2025-03-28 08:58:15 INFO MPICommandServer::command_request_handler_service::PhaseGrad::computeAntennaPointingGrad::MPIServer-2 Computing Phase Grad for Field : 0 for spw :2
28-Mar-2025 08:58:14	2025-03-28 08:58:15 INFO MPICommandServer::command_request_handler_service::PhaseGrad::computeAntennaPointingGrad::MPIServer-1 Computing Phase Grad for Field : 0 for spw :2
28-Mar-2025 08:58:16	2025-03-28 08:58:15 INFO MPICommandServer::command_request_handler_service::PhaseGrad::computeAntennaPointingGrad::MPIServer-3 Computing Phase Grad for Field : 0 for spw :2
28-Mar-2025 08:58:16	2025-03-28 08:58:15 INFO MPICommandServer::command_request_handler_service::PhaseGrad::computeAntennaPointingGrad::MPIServer-2 Computing Phase Grad for Field : 1 for spw :2
28-Mar-2025 08:58:16	2025-03-28 08:58:15 INFO MPICommandServer::command_request_handler_service::PhaseGrad::computeAntennaPointingGrad::MPIServer-1 Computing Phase Grad for Field : 1 for spw :2
28-Mar-2025 08:58:16	2025-03-28 08:58:15 INFO MPICommandServer::command_request_handler_service::PhaseGrad::computeAntennaPointingGrad::MPIServer-3 Computing Phase Grad for Field : 1 for spw :2
28-Mar-2025 08:58:16	2025-03-28 08:58:15 WARN MPICommandServer::command_request_handler_service::AWProjectFT::finalizeToVis::MPIServer-1 Time degrid 0.01
28-Mar-2025 08:58:16	2025-03-28 08:58:15 WARN MPICommandServer::command_request_handler_service::AWProjectFT::finalizeToVis::MPIServer-1 Time degrid 0.02
28-Mar-2025 08:58:16	2025-03-28 08:58:15 WARN MPICommandServer::command_request_handler_service::AWProjectFT::finalizeToSky::MPIServer-1 time to massage data 0.05
28-Mar-2025 08:58:16	2025-03-28 08:58:15 WARN MPICommandServer::command_request_handler_service::AWProjectFT::finalizeToSky::MPIServer-1 time gridding 0.02
28-Mar-2025 08:58:16	2025-03-28 08:58:15 WARN MPICommandServer::command_request_handler_service::AWProjectFT::finalizeToVis::MPIServer-2 Time degrid 0.02
28-Mar-2025 08:58:16	2025-03-28 08:58:15 WARN MPICommandServer::command_request_handler_service::AWProjectFT::finalizeToVis::MPIServer-2 Time degrid 0.02
28-Mar-2025 08:58:16	2025-03-28 08:58:15 WARN MPICommandServer::command_request_handler_service::AWProjectFT::finalizeToSky::MPIServer-2 time to massage data 0.04
28-Mar-2025 08:58:16	2025-03-28 08:58:15 WARN MPICommandServer::command_request_handler_service::AWProjectFT::finalizeToSky::MPIServer-2 time gridding 0.02
28-Mar-2025 08:58:16	2025-03-28 08:58:15 INFO MPICommandServer::command_request_handler_service::AWProjectFT2::getImage[R&D]::MPIServer-1 Sum of weights: Axis Lengths: [1, 1] (NB: Matrix in Row/Column order)
28-Mar-2025 08:58:16	2025-03-28 08:58:15 INFO MPICommandServer::command_request_handler_service::AWProjectFT2::getImage[R&D]::MPIServer-1+ [8830.19]
28-Mar-2025 08:58:16	2025-03-28 08:58:15 INFO MPICommandServer::command_request_handler_service::AWProjectFT2::getImage[R&D]::MPIServer-1+ (1.40217,-0.00871974) (0,0)
28-Mar-2025 08:58:16	2025-03-28 08:58:15 INFO MPICommandServer::command_request_handler_service::AWProjectFT2::getImage[R&D]::MPIServer-2 Sum of weights: Axis Lengths: [1, 1] (NB: Matrix in Row/Column order)
28-Mar-2025 08:58:16	2025-03-28 08:58:15 INFO MPICommandServer::command_request_handler_service::AWProjectFT2::getImage[R&D]::MPIServer-2+ [8838.74]
28-Mar-2025 08:58:16	2025-03-28 08:58:15 INFO MPICommandServer::command_request_handler_service::AWProjectFT2::getImage[R&D]::MPIServer-2+ (1.39209,0.161258) (0,0)
28-Mar-2025 08:58:16	2025-03-28 08:58:15 WARN MPICommandServer::command_request_handler_service::AWProjectFT::finalizeToVis::MPIServer-3 Time degrid 0.03
28-Mar-2025 08:58:16	2025-03-28 08:58:15 WARN MPICommandServer::command_request_handler_service::AWProjectFT::finalizeToVis::MPIServer-3 Time degrid 0.03
28-Mar-2025 08:58:16	2025-03-28 08:58:15 WARN MPICommandServer::command_request_handler_service::AWProjectFT::finalizeToSky::MPIServer-3 time to massage data 0.09
28-Mar-2025 08:58:16	2025-03-28 08:58:15 WARN MPICommandServer::command_request_handler_service::AWProjectFT::finalizeToSky::MPIServer-3 time gridding 0.02
28-Mar-2025 08:58:16	2025-03-28 08:58:15 INFO MPICommandServer::command_request_handler_service::AWProjectFT2::getImage[R&D]::MPIServer-3 Sum of weights: Axis Lengths: [1, 1] (NB: Matrix in Row/Column order)
28-Mar-2025 08:58:16	2025-03-28 08:58:15 INFO MPICommandServer::command_request_handler_service::AWProjectFT2::getImage[R&D]::MPIServer-3+ [8583.62]
28-Mar-2025 08:58:16	2025-03-28 08:58:15 INFO MPICommandServer::command_request_handler_service::AWProjectFT2::getImage[R&D]::MPIServer-3+ (1.44659,0.0437157) (0,0)
28-Mar-2025 08:58:16	2025-03-28 08:58:15 WARN MPICommandServer::command_request_handler_service::AWProjectFT::finalizeToSky::MPIServer-1 time to massage data 0.05
28-Mar-2025 08:58:16	2025-03-28 08:58:15 WARN MPICommandServer::command_request_handler_service::AWProjectFT::finalizeToSky::MPIServer-1 time gridding 0.02
28-Mar-2025 08:58:16	2025-03-28 08:58:15 WARN MPICommandServer::command_request_handler_service::AWProjectFT::finalizeToSky::MPIServer-2 time to massage data 0.07
28-Mar-2025 08:58:16	2025-03-28 08:58:15 WARN MPICommandServer::command_request_handler_service::AWProjectFT::finalizeToSky::MPIServer-2 time gridding 0.02
28-Mar-2025 08:58:16	2025-03-28 08:58:15 INFO MPICommandServer::command_request_handler_service::AWProjectFT2::getImage[R&D]::MPIServer-1 Sum of weights: Axis Lengths: [1, 1] (NB: Matrix in Row/Column order)
28-Mar-2025 08:58:16	2025-03-28 08:58:15 INFO MPICommandServer::command_request_handler_service::AWProjectFT2::getImage[R&D]::MPIServer-1+ [-8.47029]
28-Mar-2025 08:58:16	2025-03-28 08:58:15 INFO MPICommandServer::command_request_handler_service::AWProjectFT2::getImage[R&D]::MPIServer-1+ (0.119333,-0.0197033) (0,0)
28-Mar-2025 08:58:16	2025-03-28 08:58:15 INFO MPICommandServer::command_request_handler_service::AWProjectFT2::getImage[R&D]::MPIServer-2 Sum of weights: Axis Lengths: [1, 1] (NB: Matrix in Row/Column order)
28-Mar-2025 08:58:16	2025-03-28 08:58:15 INFO MPICommandServer::command_request_handler_service::AWProjectFT2::getImage[R&D]::MPIServer-2+ [-9.40991]
28-Mar-2025 08:58:16	2025-03-28 08:58:15 INFO MPICommandServer::command_request_handler_service::AWProjectFT2::getImage[R&D]::MPIServer-2+ (0.114298,-0.0140878) (0,0)
28-Mar-2025 08:58:16	2025-03-28 08:58:15 WARN MPICommandServer::command_request_handler_service::AWProjectFT::finalizeToSky::MPIServer-3 time to massage data 0.02
28-Mar-2025 08:58:16	2025-03-28 08:58:15 WARN MPICommandServer::command_request_handler_service::AWProjectFT::finalizeToSky::MPIServer-3 time gridding 0.03
28-Mar-2025 08:58:16	2025-03-28 08:58:15 INFO MPICommandServer::command_request_handler_service::AWProjectFT2::getImage[R&D]::MPIServer-3 Sum of weights: Axis Lengths: [1, 1] (NB: Matrix in Row/Column order)
28-Mar-2025 08:58:16	2025-03-28 08:58:15 INFO MPICommandServer::command_request_handler_service::AWProjectFT2::getImage[R&D]::MPIServer-3+ [-7.52245]
28-Mar-2025 08:58:16	2025-03-28 08:58:15 INFO MPICommandServer::command_request_handler_service::AWProjectFT2::getImage[R&D]::MPIServer-3+ (-0.121316,-0.00238232) (0,0)
28-Mar-2025 08:58:16	2025-03-28 08:58:16 INFO tclean::::casa ...done
28-Mar-2025 08:58:16	2025-03-28 08:58:16 INFO SynthesisNormalizer::gatherImages Gather residual images : [/home/casatest/work/test_task_tclean/tst.workdirectory/tst.n1, /home/casatest/work/test_task_tclean/tst.workdirectory/tst.n2, /home/casatest/work/test_task_tclean/tst.workdirectory/tst.n3] onto :tst
28-Mar-2025 08:58:16	2025-03-28 08:58:16 WARN SIImageStore::Open existing Images (file /source/casa6/casatools/src/code/synthesis/ImagerObjects/SIImageStore.cc, line 618) Mismatch in Csys latpoles between existing image on disk ([299.869, 40.7338, 180, 40.7338]) and current imaging run ([299.869, 40.7337, 180, 40.7337]) : The DirectionCoordinates have differing latpoles -- Resetting to match image on disk
28-Mar-2025 08:58:16	2025-03-28 08:58:16 WARN SIImageStore::Open existing Images (file /source/casa6/casatools/src/code/synthesis/ImagerObjects/SIImageStore.cc, line 618) Mismatch in Csys latpoles between existing image on disk ([299.869, 40.7337, 180, 40.7337]) and current imaging run ([299.869, 40.7338, 180, 40.7338]) : The DirectionCoordinates have differing latpoles -- Resetting to match image on disk
28-Mar-2025 08:58:16	2025-03-28 08:58:16 WARN SIImageStore::Open existing Images (file /source/casa6/casatools/src/code/synthesis/ImagerObjects/SIImageStore.cc, line 618) Mismatch in Csys latpoles between existing image on disk ([299.869, 40.7338, 180, 40.7338]) and current imaging run ([299.869, 40.7337, 180, 40.7337]) : The DirectionCoordinates have differing latpoles -- Resetting to match image on disk
28-Mar-2025 08:58:16	2025-03-28 08:58:16 WARN SIImageStore::Open existing Images (file /source/casa6/casatools/src/code/synthesis/ImagerObjects/SIImageStore.cc, line 618) Mismatch in Csys latpoles between existing image on disk ([299.869, 40.7337, 180, 40.7337]) and current imaging run ([299.869, 40.7338, 180, 40.7338]) : The DirectionCoordinates have differing latpoles -- Resetting to match image on disk
28-Mar-2025 08:58:16	2025-03-28 08:58:16 INFO task_tclean::SynthesisDeconvolver::initMinorCycle Absolute Peak residual within mask : 0.0555073, over full image : 0.0555073
28-Mar-2025 08:58:16	2025-03-28 08:58:16 INFO tclean::::casa Reached global stopping criterion : iteration limit
28-Mar-2025 08:58:16	2025-03-28 08:58:16 INFO tclean::::casa getSummary call: fullsummary=False
28-Mar-2025 08:58:41	2025-03-28 08:58:16 WARN SIImageStore::Open existing Images (file /source/casa6/casatools/src/code/synthesis/ImagerObjects/SIImageStore.cc, line 618) Mismatch in Csys latpoles between existing image on disk ([299.869, 40.7338, 180, 40.7338]) and current imaging run ([299.869, 40.7337, 180, 40.7337]) : The DirectionCoordinates have differing latpoles -- Resetting to match image on disk
28-Mar-2025 08:58:41	2025-03-28 08:58:16 INFO MultiTermMatrixCleaner::computeprincipalsolution() MTMC :: Computing principal solution on residuals
28-Mar-2025 08:58:41	2025-03-28 08:58:16 INFO SDAlgorithmBase::restore [tst] : Restoring model image.
28-Mar-2025 08:58:41	2025-03-28 08:58:16 WARN SIImageStore::Open existing Images (file /source/casa6/casatools/src/code/synthesis/ImagerObjects/SIImageStore.cc, line 618) Mismatch in Csys latpoles between existing image on disk ([299.869, 40.7337, 180, 40.7337]) and current imaging run ([299.869, 40.7338, 180, 40.7338]) : The DirectionCoordinates have differing latpoles -- Resetting to match image on disk
28-Mar-2025 08:58:41	2025-03-28 08:58:16 INFO SIImageStore::restore Beam for chan : 0 : 139.82 arcsec, 129.968 arcsec, -86.7085 deg
28-Mar-2025 08:58:41	2025-03-28 08:58:16 INFO SIImageStore::restore Beam for chan : 0 : 139.82 arcsec, 129.968 arcsec, -86.7085 deg
28-Mar-2025 08:58:41	2025-03-28 08:58:16 INFO SIImageStoreMultiTerm::calculateAlphaBeta Calculating spectral parameters for Intensity > peakresidual/10 = 0.00555073 Jy/beam
28-Mar-2025 08:58:41	2025-03-28 08:58:17 INFO SIImageStoreMultiTerm::calculateAlphaBeta Written Spectral Index Error Image : /home/casatest/work/test_task_tclean/tst.alpha.error
28-Mar-2025 08:58:41	2025-03-28 08:58:17 INFO SDAlgorithmMSMFS::restore Restored images :
28-Mar-2025 08:58:41	2025-03-28 08:58:17 WARN SIImageStore::Open existing Images (file /source/casa6/casatools/src/code/synthesis/ImagerObjects/SIImageStore.cc, line 618) Mismatch in Csys latpoles between existing image on disk ([299.869, 40.7337, 180, 40.7337]) and current imaging run ([299.869, 40.7338, 180, 40.7338]) : The DirectionCoordinates have differing latpoles -- Resetting to match image on disk
28-Mar-2025 08:58:41	2025-03-28 08:58:17 INFO SDAlgorithmMSMFS::restore /home/casatest/work/test_task_tclean/tst.image.tt0 (model=/home/casatest/work/test_task_tclean/tst.model.tt0)
28-Mar-2025 08:58:41	2025-03-28 08:58:17 INFO SDAlgorithmMSMFS::restore /home/casatest/work/test_task_tclean/tst.image.tt1 (model=/home/casatest/work/test_task_tclean/tst.model.tt1)
28-Mar-2025 08:58:41	2025-03-28 08:58:17 INFO SDAlgorithmMSMFS::restore
28-Mar-2025 08:58:41	2025-03-28 08:58:17 INFO MPICommandServer::command_request_handler_service::VB2CFBMap::~VB2CFMap[R&D]::MPIServer-3 Total extra cost of heterogeneous array pointing correction = 0.29sec. Total VBs processed = 72791. The pointingoffsetsigdev used was = []
28-Mar-2025 08:58:41	2025-03-28 08:58:17 INFO MPICommandServer::command_request_handler_service::VB2CFBMap::~VB2CFMap[R&D]::MPIServer-1 Total extra cost of heterogeneous array pointing correction = 0.31sec. Total VBs processed = 72865. The pointingoffsetsigdev used was = []
28-Mar-2025 08:58:41	2025-03-28 08:58:17 INFO MPICommandServer::command_request_handler_service::VB2CFBMap::~VB2CFMap[R&D]::MPIServer-2 Total extra cost of heterogeneous array pointing correction = 0.29sec. Total VBs processed = 72852. The pointingoffsetsigdev used was = []
28-Mar-2025 08:58:41	2025-03-28 08:58:35 INFO tclean::::casa checkJobs. Blocking for nodes to finish
28-Mar-2025 08:58:41	2025-03-28 08:58:35 INFO ::casa::MPIServer-2 node 2 has completed its job
28-Mar-2025 08:58:41	2025-03-28 08:58:35 INFO ::casa::MPIServer-1 node 1 has completed its job
28-Mar-2025 08:58:41	2025-03-28 08:58:35 INFO ::casa::MPIServer-3 node 3 has completed its job
28-Mar-2025 08:58:41	2025-03-28 08:58:36 INFO tclean::::casa ...done
28-Mar-2025 08:58:41	2025-03-28 08:58:36 INFO tclean::::casa Ending use of cluster, but not closing it. Call clustermanager.stop_cluster() to close it if needed.
28-Mar-2025 08:58:41	2025-03-28 08:58:36 INFO tclean::::casa Searching for images with prefix 'tst'... Found these, writing history into them: ['tst.alpha', 'tst.sumwt.tt0', 'tst.sumwt.tt2', 'tst.weight.tt2', 'tst.model.tt1', 'tst.image.tt1', 'tst.psf.tt0', 'tst.sumwt.tt1', 'tst.weight.tt0', 'tst.pb.tt0', 'tst.residual.tt1', 'tst.alpha.error', 'tst.residual.tt0', 'tst.psf.tt1', 'tst.psf.tt2', 'tst.weight.tt1', 'tst.model.tt0', 'tst.mask', 'tst.image.tt0']
28-Mar-2025 08:58:41	2025-03-28 08:58:37 INFO tclean::::casa Task tclean complete. Start time: 2025-03-28 08:56:22.276531 End time: 2025-03-28 08:58:36.741107
28-Mar-2025 08:58:41	2025-03-28 08:58:37 INFO tclean::::casa ##### End Task: tclean #####
28-Mar-2025 08:58:41	2025-03-28 08:58:37 INFO tclean::::casa ##########################################
28-Mar-2025 08:58:41	2025-03-28 08:58:37 INFO name:: No table opened.
28-Mar-2025 08:58:41	2025-03-28 08:58:37 INFO showcache:: The Table Cache is empty.
28-Mar-2025 08:58:41	2025-03-28 08:58:37 INFO tclean::::casa [ checkall ]
28-Mar-2025 08:58:41	2025-03-28 08:58:37 INFO tclean::::casa+ [ check_ims ] Image made : ['tst.image.tt0', 'tst.psf.tt0', 'tst.weight.tt0'] = [True, True, True] ( Pass : should all be True )
28-Mar-2025 08:58:41	2025-03-28 08:58:37 INFO tclean::::casa+ All expected keywords in imageinfo, miscinfo, and coords found. (check_keywords)
28-Mar-2025 08:58:41	2025-03-28 08:58:37 INFO tclean::::casa+ [check_history] All expected history entries found. (Pass)
28-Mar-2025 08:58:41	2025-03-28 08:58:37 INFO tclean::::casa+ [ check_pix_val ] tst.image.tt0 : Value is 0.9574441909790039 at [256, 256, 0, 0] ( Pass : should be 0.96 , Epsilon: 0.05)
28-Mar-2025 08:58:41	2025-03-28 08:58:37 INFO tclean::::casa+ [ check_pix_val ] tst.weight.tt0 : Value is 0.48626992106437683 at [256, 256, 0, 0] ( Pass : should be 0.486 , Epsilon: 0.05)
28-Mar-2025 08:58:41	2025-03-28 08:58:37 INFO tclean::::casa+ [ check_pix_val ] tst.alpha : Value is -0.004446295090019703 at [256, 256, 0, 0] ( Pass : should be 0.0 , Epsilon: 0.05)
28-Mar-2025 08:58:41	.2025-03-28 08:58:39 INFO MPICommandServer::serve::MPICommandServer::serve::casa::MPIServer-3 Control signal MPIEnvironment.command_handling_log_level = 'DEBUG' successfully handled by server 3
28-Mar-2025 08:58:41	2025-03-28 08:58:39 INFO MPICommandServer::serve::MPICommandServer::serve::casa::MPIServer-2 Control signal MPIEnvironment.command_handling_log_level = 'DEBUG' successfully handled by server 2
28-Mar-2025 08:58:41	2025-03-28 08:58:39 INFO MPICommandServer::serve::MPICommandServer::serve::casa::MPIServer-1 Control signal MPIEnvironment.command_handling_log_level = 'DEBUG' successfully handled by server 1
28-Mar-2025 08:58:41	2025-03-28 08:58:40 INFO tclean::::casa setupCluster, Setting up 3 engines.
28-Mar-2025 08:58:41	2025-03-28 08:58:40 INFO tclean::::casa ##########################################
28-Mar-2025 08:58:41	2025-03-28 08:58:40 INFO tclean::::casa ##### Begin Task: tclean #####
28-Mar-2025 08:58:41	2025-03-28 08:58:40 INFO tclean::::casa tclean( vis='vla_wideband_2ptg_w_squint.ms', selectdata=True, field='1', spw='', timerange='', uvrange='', antenna='', scan='', observation='', intent='', datacolumn='corrected', imagename='tst.awp2', imsize=1200, cell='1.6arcsec', phasecenter='', stokes='I', projection='SIN', startmodel='', specmode='mfs', reffreq='', nchan=-1, start='', width='', outframe='LSRK', veltype='radio', restfreq=[], interpolation='linear', perchanweightdensity=True, gridder='awp2', facets=1, psfphasecenter='', wprojplanes=6, vptable='', mosweight=True, aterm=True, psterm=False, wbawp=True, conjbeams=False, cfcache='', usepointing=False, computepastep=360.0, rotatepastep=360.0, pointingoffsetsigdev=[], pblimit=-0.1, normtype='flatnoise', deconvolver='hogbom', scales=[], nterms=2, smallscalebias=0.0, fusedthreshold=0.0, largestscale=-1, restoration=True, restoringbeam=[], pbcor=True, outlierfile='', weighting='uniform', robust=0.5, noise='1.0Jy', npixels=0, uvtaper=[''], niter=20, gain=0.1, threshold=0.0, nsigma=0.0, cycleniter=-1, cyclefactor=1.0, minpsffraction=0.05, maxpsffraction=0.8, interactive=False, nmajor=-1, fullsummary=False, usemask='user', mask='', pbmask=0.0, sidelobethreshold=3.0, noisethreshold=5.0, lownoisethreshold=1.5, negativethreshold=0.0, smoothfactor=1.0, minbeamfrac=0.3, cutthreshold=0.01, growiterations=75, dogrowprune=True, minpercentchange=-1.0, verbose=False, fastnoise=True, restart=True, savemodel='none', calcres=True, calcpsf=True, psfcutoff=0.35, parallel=True )
28-Mar-2025 08:58:41	2025-03-28 08:58:40 INFO tclean::::casa Verifying Input Parameters
28-Mar-2025 08:58:41	2025-03-28 08:58:42 INFO MPICommandServer::serve::MPICommandServer::serve::casa::MPIServer-3 Control signal MPIEnvironment.command_handling_log_level = 'DEBUG' successfully handled by server 3
28-Mar-2025 08:58:46	2025-03-28 08:58:42 INFO MPICommandServer::serve::MPICommandServer::serve::casa::MPIServer-2 Control signal MPIEnvironment.command_handling_log_level = 'DEBUG' successfully handled by server 2
28-Mar-2025 08:58:46	2025-03-28 08:58:42 INFO MPICommandServer::serve::MPICommandServer::serve::casa::MPIServer-1 Control signal MPIEnvironment.command_handling_log_level = 'DEBUG' successfully handled by server 1
28-Mar-2025 08:58:46	2025-03-28 08:58:43 INFO tclean::::casa setupCluster, Setting up 3 engines.
28-Mar-2025 08:58:46	2025-03-28 08:58:43 INFO SynthesisUtilMethods::continuumDataPartition
28-Mar-2025 08:58:46	2025-03-28 08:58:43 INFO SynthesisUtilMethods::continuumDataPartition + Rows = 4683 7020 [P][M]: 0:2 ROWNUMBER() >= 4683 && ROWNUMBER() <= 7020
28-Mar-2025 08:58:46	2025-03-28 08:58:43 INFO tclean::::casa Partitioned Selection : {'0': {'ms0': {'antenna': '', 'datacolumn': 'corrected', 'field': '1', 'freqbeg': '', 'freqend': '', 'freqframe': 'LSRK', 'incrmodel': False, 'msname': 'vla_wideband_2ptg_w_squint.ms', 'obs': '', 'outframe': 'LSRK', 'readonly': True, 'scan': '', 'spw': '', 'state': '', 'taql': 'ROWNUMBER() >= 1 && ROWNUMBER() <= 2341', 'timestr': '', 'usescratch': False, 'uvdist': ''}}, '1': {'ms0': {'antenna': '', 'datacolumn': 'corrected', 'field': '1', 'freqbeg': '', 'freqend': '', 'freqframe': 'LSRK', 'incrmodel': False, 'msname': 'vla_wideband_2ptg_w_squint.ms', 'obs': '', 'outframe': 'LSRK', 'readonly': True, 'scan': '', 'spw': '', 'state': '', 'taql': 'ROWNUMBER() >= 2342 && ROWNUMBER() <= 4682', 'timestr': '', 'usescratch': False, 'uvdist': ''}}, '2': {'ms0': {'antenna': '', 'datacolumn': 'corrected', 'field': '1', 'freqbeg': '', 'freqend': '', 'freqframe': 'LSRK', 'incrmodel': False, 'msname': 'vla_wideband_2ptg_w_squint.ms', 'obs': '', 'outframe': 'LSRK', 'readonly': True, 'scan': '', 'spw': '', 'state': '', 'taql': 'ROWNUMBER() >= 4683 && ROWNUMBER() <= 7020', 'timestr': '', 'usescratch': False, 'uvdist': ''}}}
28-Mar-2025 08:58:46	2025-03-28 08:58:43 INFO SynthesisImagerVi2::selectData MS : vla_wideband_2ptg_w_squint.ms \| Selecting on fields : 1 \| [Opened in readonly mode]
28-Mar-2025 08:58:46	2025-03-28 08:58:43 INFO SynthesisImagerVi2::selectData NRows selected : 7020
28-Mar-2025 08:58:46	2025-03-28 08:58:43 INFO SynthesisImagerVi2::defineImage Define image coordinates for [tst.awp2] :
28-Mar-2025 08:58:46	2025-03-28 08:58:43 INFO SynthesisImagerVi2::defineImage Define image coordinates for [tst.awp2] :
28-Mar-2025 08:58:46	2025-03-28 08:58:43 INFO SynthesisImagerVi2::defineImage Impars: start
28-Mar-2025 08:58:46	2025-03-28 08:58:43 INFO SynthesisImagerVi2::defineImage Shape: [1200, 1200, 1, 1] Spectral: [1.48111e+09] at [0] with increment [5.99947e+08]
28-Mar-2025 08:58:46	2025-03-28 08:58:43 INFO SynthesisImagerVi2::defineImage Set Gridding options for [tst.awp2] with ftmachine : awp2
28-Mar-2025 08:58:46	2025-03-28 08:58:43 INFO SynthesisImager::getVPRecord Using default Voltage Patterns from the VPManager
28-Mar-2025 08:58:46	2025-03-28 08:58:43 INFO SynthesisImagerVi2::nSubCubeFitInMemory Required memory: 0.6798 GB. Available mem.: 387.2 GB (rc, mem. fraction: 80%, memory: -) => Subcubes: 1. Processes on node: 4.
28-Mar-2025 08:58:46	2025-03-28 08:58:43 INFO SynthesisImagerVi2::weight() Set imaging weights : Uniform weighting: sidelobes will be suppressed over full image
28-Mar-2025 08:58:46	2025-03-28 08:58:43 INFO tclean::::casa checkJobs. Blocking for nodes to finish
28-Mar-2025 08:58:46	2025-03-28 08:58:44 INFO tclean::::casa ...done
28-Mar-2025 08:58:46	2025-03-28 08:58:44 INFO tclean::::casa checkJobs. Blocking for nodes to finish
28-Mar-2025 08:58:46	2025-03-28 08:58:44 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::selectData::MPIServer-2 MS : vla_wideband_2ptg_w_squint.ms \| Selecting on fields : 1 \| [Opened in readonly mode]
28-Mar-2025 08:58:46	2025-03-28 08:58:44 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::selectData::MPIServer-1 MS : vla_wideband_2ptg_w_squint.ms \| Selecting on fields : 1 \| [Opened in readonly mode]
28-Mar-2025 08:58:46	2025-03-28 08:58:44 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::selectData::MPIServer-2 Selecting via TaQL : ROWNUMBER() >= 2342 && ROWNUMBER() <= 4682 \| NRows selected : 2341
28-Mar-2025 08:58:46	2025-03-28 08:58:44 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::selectData::MPIServer-1 Selecting via TaQL : ROWNUMBER() >= 1 && ROWNUMBER() <= 2341 \| NRows selected : 2341
28-Mar-2025 08:58:46	2025-03-28 08:58:44 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::selectData::MPIServer-3 MS : vla_wideband_2ptg_w_squint.ms \| Selecting on fields : 1 \| [Opened in readonly mode]
28-Mar-2025 08:58:46	2025-03-28 08:58:44 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::selectData::MPIServer-3 Selecting via TaQL : ROWNUMBER() >= 4683 && ROWNUMBER() <= 7020 \| NRows selected : 2338
28-Mar-2025 08:58:46	2025-03-28 08:58:45 INFO tclean::::casa ...done
28-Mar-2025 08:58:46	2025-03-28 08:58:46 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::defineImage::MPIServer-1 Define image coordinates for [/home/casatest/work/test_task_tclean/tst.awp2.workdirectory/tst.awp2.n1] :
28-Mar-2025 08:58:46	2025-03-28 08:58:46 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::defineImage::MPIServer-1 Define image coordinates for [/home/casatest/work/test_task_tclean/tst.awp2.workdirectory/tst.awp2.n1] :
28-Mar-2025 08:58:46	2025-03-28 08:58:46 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::defineImage::MPIServer-1 Impars: start
28-Mar-2025 08:58:46	2025-03-28 08:58:46 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::defineImage::MPIServer-1 Shape: [1200, 1200, 1, 1] Spectral: [1.48111e+09] at [0] with increment [5.99947e+08]
28-Mar-2025 08:58:46	2025-03-28 08:58:46 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::defineImage::MPIServer-1 Set Gridding options for [/home/casatest/work/test_task_tclean/tst.awp2.workdirectory/tst.awp2.n1] with ftmachine : awp2
28-Mar-2025 08:58:46	2025-03-28 08:58:46 INFO MPICommandServer::command_request_handler_service::SynthesisImager::getVPRecord::MPIServer-1 Using default Voltage Patterns from the VPManager
28-Mar-2025 08:58:46	2025-03-28 08:58:46 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::nSubCubeFitInMemory::MPIServer-1 Required memory: 0.6798 GB. Available mem.: 387.2 GB (rc, mem. fraction: 80%, memory: -) => Subcubes: 1. Processes on node: 4.
28-Mar-2025 08:58:46	2025-03-28 08:58:46 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::defineImage::MPIServer-2 Define image coordinates for [/home/casatest/work/test_task_tclean/tst.awp2.workdirectory/tst.awp2.n2] :
28-Mar-2025 08:58:46	2025-03-28 08:58:46 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::defineImage::MPIServer-2 Define image coordinates for [/home/casatest/work/test_task_tclean/tst.awp2.workdirectory/tst.awp2.n2] :
28-Mar-2025 08:58:46	2025-03-28 08:58:46 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::defineImage::MPIServer-2 Impars: start
28-Mar-2025 08:58:46	2025-03-28 08:58:46 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::defineImage::MPIServer-2 Shape: [1200, 1200, 1, 1] Spectral: [1.48111e+09] at [0] with increment [5.99947e+08]
28-Mar-2025 08:58:46	2025-03-28 08:58:46 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::defineImage::MPIServer-2 Set Gridding options for [/home/casatest/work/test_task_tclean/tst.awp2.workdirectory/tst.awp2.n2] with ftmachine : awp2
28-Mar-2025 08:58:46	2025-03-28 08:58:46 INFO MPICommandServer::command_request_handler_service::SynthesisImager::getVPRecord::MPIServer-2 Using default Voltage Patterns from the VPManager
28-Mar-2025 08:58:46	2025-03-28 08:58:46 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::nSubCubeFitInMemory::MPIServer-2 Required memory: 0.6798 GB. Available mem.: 387.2 GB (rc, mem. fraction: 80%, memory: -) => Subcubes: 1. Processes on node: 4.
28-Mar-2025 08:58:46	2025-03-28 08:58:47 INFO tclean::::casa checkJobs. Blocking for nodes to finish
28-Mar-2025 08:58:46	2025-03-28 08:58:47 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::defineImage::MPIServer-3 Define image coordinates for [/home/casatest/work/test_task_tclean/tst.awp2.workdirectory/tst.awp2.n3] :
28-Mar-2025 08:58:46	2025-03-28 08:58:47 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::defineImage::MPIServer-3 Define image coordinates for [/home/casatest/work/test_task_tclean/tst.awp2.workdirectory/tst.awp2.n3] :
28-Mar-2025 08:58:46	2025-03-28 08:58:47 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::defineImage::MPIServer-3 Impars: start
28-Mar-2025 09:00:40	2025-03-28 08:58:47 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::defineImage::MPIServer-3 Shape: [1200, 1200, 1, 1] Spectral: [1.48111e+09] at [0] with increment [5.99947e+08]
28-Mar-2025 09:00:40	2025-03-28 08:58:47 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::defineImage::MPIServer-3 Set Gridding options for [/home/casatest/work/test_task_tclean/tst.awp2.workdirectory/tst.awp2.n3] with ftmachine : awp2
28-Mar-2025 09:00:40	2025-03-28 08:58:47 INFO MPICommandServer::command_request_handler_service::SynthesisImager::getVPRecord::MPIServer-3 Using default Voltage Patterns from the VPManager
28-Mar-2025 09:00:40	2025-03-28 08:58:47 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::nSubCubeFitInMemory::MPIServer-3 Required memory: 0.6798 GB. Available mem.: 387.2 GB (rc, mem. fraction: 80%, memory: -) => Subcubes: 1. Processes on node: 4.
28-Mar-2025 09:00:40	2025-03-28 08:58:48 INFO tclean::::casa ...done
28-Mar-2025 09:00:40	2025-03-28 08:58:50 INFO SynthesisImagerVi2::selectData MS : vla_wideband_2ptg_w_squint.ms \| Selecting on fields : 1 \| [Opened in readonly mode]
28-Mar-2025 09:00:40	2025-03-28 08:58:50 INFO SynthesisImagerVi2::selectData NRows selected : 7020
28-Mar-2025 09:00:40	2025-03-28 08:58:50 INFO SynthesisImagerVi2::defineImage Define image coordinates for [tst.awp2] :
28-Mar-2025 09:00:40	2025-03-28 08:58:50 INFO SynthesisImagerVi2::defineImage Define image coordinates for [tst.awp2] :
28-Mar-2025 09:00:40	2025-03-28 08:58:50 INFO SynthesisImagerVi2::defineImage Impars: start
28-Mar-2025 09:00:40	2025-03-28 08:58:50 INFO SynthesisImagerVi2::defineImage Shape: [1200, 1200, 1, 1] Spectral: [1.48111e+09] at [0] with increment [5.99947e+08]
28-Mar-2025 09:00:40	2025-03-28 08:58:50 INFO SynthesisImagerVi2::defineImage Set Gridding options for [tst.awp2] with ftmachine : awp2
28-Mar-2025 09:00:40	2025-03-28 08:58:50 INFO SynthesisImager::getVPRecord Using default Voltage Patterns from the VPManager
28-Mar-2025 09:00:40	2025-03-28 08:58:50 INFO SynthesisImagerVi2::nSubCubeFitInMemory Required memory: 0.6798 GB. Available mem.: 387.2 GB (rc, mem. fraction: 80%, memory: -) => Subcubes: 1. Processes on node: 4.
28-Mar-2025 09:00:40	2025-03-28 08:58:50 INFO SynthesisImagerVi2::weight() Set imaging weights : Uniform weighting: sidelobes will be suppressed over full image
28-Mar-2025 09:00:40	2025-03-28 08:58:50 INFO tclean::::casa checkJobs. Blocking for nodes to finish
28-Mar-2025 09:00:40	2025-03-28 08:58:51 INFO tclean::::casa ...done
28-Mar-2025 09:00:40	2025-03-28 08:58:51 INFO task_tclean::SynthesisDeconvolver::setupDeconvolution Set Deconvolution Options for [tst.awp2] : hogbom
28-Mar-2025 09:00:40	2025-03-28 08:58:51 INFO tclean::::casa checkJobs. Blocking for nodes to finish
28-Mar-2025 09:00:40	2025-03-28 08:58:52 INFO tclean::::casa ...done
28-Mar-2025 09:00:40	2025-03-28 08:58:52 INFO tclean::::casa checkJobs. Blocking for nodes to finish
28-Mar-2025 09:00:40	2025-03-28 08:58:52 INFO MPICommandServer::command_request_handler_service::SynthesisImager::makePSF::MPIServer-1 ----------------------------------------------------------- Make PSF ---------------------------------------------
28-Mar-2025 09:00:40	2025-03-28 08:58:52 INFO MPICommandServer::command_request_handler_service::SynthesisImager::makePSF::MPIServer-3 ----------------------------------------------------------- Make PSF ---------------------------------------------
28-Mar-2025 09:00:40	2025-03-28 08:58:52 INFO MPICommandServer::command_request_handler_service::SynthesisImager::makePSF::MPIServer-2 ----------------------------------------------------------- Make PSF ---------------------------------------------
28-Mar-2025 09:00:40
28-Mar-2025 09:00:40	0%....10....20....30....40....50....60....70....80....90....100%
28-Mar-2025 09:00:40
28-Mar-2025 09:00:40	0%....10....20....30....40....50....60....70....80....90....100%
28-Mar-2025 09:00:40	2025-03-28 08:59:48 INFO tclean::::casa ...done
28-Mar-2025 09:00:40	2025-03-28 08:59:48 INFO SynthesisNormalizer::gatherImages Gather psf,weight images : [/home/casatest/work/test_task_tclean/tst.awp2.workdirectory/tst.awp2.n1, /home/casatest/work/test_task_tclean/tst.awp2.workdirectory/tst.awp2.n2, /home/casatest/work/test_task_tclean/tst.awp2.workdirectory/tst.awp2.n3] onto :tst.awp2
28-Mar-2025 09:00:40	2025-03-28 08:59:49 INFO SIImageStore::calcSensitivity [tst.awp2] Theoretical sensitivity (Jy/bm):0.00282974
28-Mar-2025 09:00:40	2025-03-28 08:59:49 INFO SIImageStore::getPSFGaussian Time to fit Gaussian to PSF 0.019911
28-Mar-2025 09:00:40	2025-03-28 08:59:49 INFO SIImageStore::printBeamSet Beam : 5.34877 arcsec, 4.3664 arcsec, -84.4348 deg
28-Mar-2025 09:00:40	2025-03-28 08:59:49 INFO tclean::::casa checkJobs. Blocking for nodes to finish
28-Mar-2025 09:00:40	2025-03-28 08:59:50 INFO tclean::::casa ...done
28-Mar-2025 09:00:40	2025-03-28 08:59:50 INFO SynthesisNormalizer::scatterModel Send the model from : tst.awp2 to all nodes :[/home/casatest/work/test_task_tclean/tst.awp2.workdirectory/tst.awp2.n1, /home/casatest/work/test_task_tclean/tst.awp2.workdirectory/tst.awp2.n2, /home/casatest/work/test_task_tclean/tst.awp2.workdirectory/tst.awp2.n3]
28-Mar-2025 09:00:40	2025-03-28 08:59:50 INFO SIImageStore::setModelImageOne Copying input model tst.awp2.model to /home/casatest/work/test_task_tclean/tst.awp2.workdirectory/tst.awp2.n1.model
28-Mar-2025 09:00:40	2025-03-28 08:59:50 INFO SIImageStore::setModelImageOne Copying input model tst.awp2.model to /home/casatest/work/test_task_tclean/tst.awp2.workdirectory/tst.awp2.n2.model
28-Mar-2025 09:00:40	2025-03-28 08:59:50 INFO SIImageStore::setModelImageOne Copying input model tst.awp2.model to /home/casatest/work/test_task_tclean/tst.awp2.workdirectory/tst.awp2.n3.model
28-Mar-2025 09:00:40	2025-03-28 08:59:50 INFO tclean::::casa ----------------------------- Running Parallel Major Cycle ----------------------------
28-Mar-2025 09:00:40	2025-03-28 08:59:50 INFO tclean::::casa checkJobs. Blocking for nodes to finish
28-Mar-2025 09:00:40	2025-03-28 08:59:50 INFO MPICommandServer::command_request_handler_service::SynthesisImager::executeMajorCycle::MPIServer-2 ----------------------------------------------------------- Run Major Cycle 1 -------------------------------------
28-Mar-2025 09:00:40	2025-03-28 08:59:50 INFO MPICommandServer::command_request_handler_service::SynthesisImager::executeMajorCycle::MPIServer-3 ----------------------------------------------------------- Run Major Cycle 1 -------------------------------------
28-Mar-2025 09:00:40	2025-03-28 08:59:50 INFO MPICommandServer::command_request_handler_service::SynthesisImager::executeMajorCycle::MPIServer-1 ----------------------------------------------------------- Run Major Cycle 1 -------------------------------------
28-Mar-2025 09:00:40
28-Mar-2025 09:00:40	0%....10....20....30....40....50....60..
28-Mar-2025 09:00:40	0%....10....20....
28-Mar-2025 09:00:40	0%....10....20....30......70....80....90....100%
28-Mar-2025 09:00:40	30....40..40....50....60......50....70....80..60....70....90....100%
28-Mar-2025 09:00:40	..80....90....100%
28-Mar-2025 09:00:40	2025-03-28 09:00:40 INFO tclean::::casa ...done
28-Mar-2025 09:00:40	2025-03-28 09:00:40 INFO SynthesisNormalizer::gatherImages Gather residual images : [/home/casatest/work/test_task_tclean/tst.awp2.workdirectory/tst.awp2.n1, /home/casatest/work/test_task_tclean/tst.awp2.workdirectory/tst.awp2.n2, /home/casatest/work/test_task_tclean/tst.awp2.workdirectory/tst.awp2.n3] onto :tst.awp2
28-Mar-2025 09:00:40	2025-03-28 09:00:41 INFO task_tclean::SynthesisDeconvolver::initMinorCycle Absolute Peak residual within mask : 0, over full image : 0.477512
28-Mar-2025 09:00:40	2025-03-28 09:00:41 INFO SynthesisDeconvolver::setupMask [tst.awp2] Initializing new mask to 1.0 for the full image
28-Mar-2025 09:00:40	2025-03-28 09:00:41 INFO SynthesisDeconvolver::setupMask [tst.awp2] Number of pixels in the clean mask : 1.44e+06 out of a total of 1.44e+06 pixels. [ 100 % ]
28-Mar-2025 09:00:40	2025-03-28 09:00:41 INFO SynthesisDeconvolver::initMinorCycle Absolute Peak residual within mask : 0.477512, over full image : 0.477512
28-Mar-2025 09:00:40	2025-03-28 09:00:41 INFO tclean::::casa Minor Cycle controls : {'cycleniter': 20, 'cyclethreshold': 0.023875603452324867, 'loopgain': 0.10000000149011612, 'nsigma': 0.0, 'thresholdreached': False}
28-Mar-2025 09:00:40	2025-03-28 09:00:41 INFO SDAlgorithmBase::deconvolve [tst.awp2] Run Hogbom minor-cycle \| CycleThreshold=0.0238756, CycleNiter=20, Gain=0.1
28-Mar-2025 09:00:40	2025-03-28 09:00:41 INFO SDAlgorithmBase::deconvolve [tst.awp2] iters=0->20 [20], model=0->0.425263, peakres=0.477512->0.0522489, Reached cycleniter.
28-Mar-2025 09:00:40	2025-03-28 09:00:41 INFO grpcInteractiveCleanManager::mergeCycleExecutionRecord Completed 20 iterations.
28-Mar-2025 09:00:40	2025-03-28 09:00:41 INFO task_tclean::SynthesisNormalizer::scatterModel Send the model from : tst.awp2 to all nodes :[/home/casatest/work/test_task_tclean/tst.awp2.workdirectory/tst.awp2.n1, /home/casatest/work/test_task_tclean/tst.awp2.workdirectory/tst.awp2.n2, /home/casatest/work/test_task_tclean/tst.awp2.workdirectory/tst.awp2.n3]
28-Mar-2025 09:02:46	2025-03-28 09:00:41 INFO task_tclean::SIImageStore::setModelImageOne Copying input model tst.awp2.model to /home/casatest/work/test_task_tclean/tst.awp2.workdirectory/tst.awp2.n1.model
28-Mar-2025 09:02:46	2025-03-28 09:00:41 INFO task_tclean::SIImageStore::setModelImageOne Copying input model tst.awp2.model to /home/casatest/work/test_task_tclean/tst.awp2.workdirectory/tst.awp2.n2.model
28-Mar-2025 09:02:46	2025-03-28 09:00:41 INFO task_tclean::SIImageStore::setModelImageOne Copying input model tst.awp2.model to /home/casatest/work/test_task_tclean/tst.awp2.workdirectory/tst.awp2.n3.model
28-Mar-2025 09:02:46	2025-03-28 09:00:41 INFO tclean::::casa ----------------------------- Running Parallel Major Cycle ----------------------------
28-Mar-2025 09:02:46	2025-03-28 09:00:41 INFO tclean::::casa checkJobs. Blocking for nodes to finish
28-Mar-2025 09:02:46	2025-03-28 09:00:41 INFO MPICommandServer::command_request_handler_service::SynthesisImager::executeMajorCycle::MPIServer-3 ----------------------------------------------------------- Run Major Cycle 2 -------------------------------------
28-Mar-2025 09:02:46	2025-03-28 09:00:41 INFO MPICommandServer::command_request_handler_service::SynthesisImager::executeMajorCycle::MPIServer-1 ----------------------------------------------------------- Run Major Cycle 2 -------------------------------------
28-Mar-2025 09:02:46	2025-03-28 09:00:41 INFO MPICommandServer::command_request_handler_service::SynthesisImager::executeMajorCycle::MPIServer-2 ----------------------------------------------------------- Run Major Cycle 2 -------------------------------------
28-Mar-2025 09:02:46
28-Mar-2025 09:02:46	0%....10....20....30..
28-Mar-2025 09:02:46	0%....10....20....40....50....60....70......30....
28-Mar-2025 09:02:46	0%....10....20....80....90....100%
28-Mar-2025 09:02:46	40....50..30....40....60......50....70....80..60....70....90....100%
28-Mar-2025 09:02:46	..80....90....100%
28-Mar-2025 09:02:46	2025-03-28 09:02:29 INFO tclean::::casa ...done
28-Mar-2025 09:02:46	2025-03-28 09:02:29 INFO SynthesisNormalizer::gatherImages Gather residual images : [/home/casatest/work/test_task_tclean/tst.awp2.workdirectory/tst.awp2.n1, /home/casatest/work/test_task_tclean/tst.awp2.workdirectory/tst.awp2.n2, /home/casatest/work/test_task_tclean/tst.awp2.workdirectory/tst.awp2.n3] onto :tst.awp2
28-Mar-2025 09:02:46	2025-03-28 09:02:29 INFO task_tclean::SynthesisDeconvolver::initMinorCycle Absolute Peak residual within mask : 0.0560291, over full image : 0.0560291
28-Mar-2025 09:02:46	2025-03-28 09:02:29 INFO tclean::::casa Reached global stopping criterion : iteration limit
28-Mar-2025 09:02:46	2025-03-28 09:02:29 INFO tclean::::casa getSummary call: fullsummary=False
28-Mar-2025 09:02:46	2025-03-28 09:02:29 INFO SDAlgorithmBase::restore [tst.awp2] : Restoring model image.
28-Mar-2025 09:02:46	2025-03-28 09:02:29 INFO SIImageStore::restore Beam for chan : 0 : 5.34877 arcsec, 4.3664 arcsec, -84.4348 deg
28-Mar-2025 09:02:46	2025-03-28 09:02:29 INFO task_tclean::SDAlgorithmBase::pbcor [tst.awp2] : Applying PB correction
28-Mar-2025 09:02:46	2025-03-28 09:02:39 INFO tclean::::casa checkJobs. Blocking for nodes to finish
28-Mar-2025 09:02:46	2025-03-28 09:02:39 INFO ::casa::MPIServer-2 node 2 has completed its job
28-Mar-2025 09:02:46	2025-03-28 09:02:39 INFO ::casa::MPIServer-1 node 1 has completed its job
28-Mar-2025 09:02:46	2025-03-28 09:02:39 INFO ::casa::MPIServer-3 node 3 has completed its job
28-Mar-2025 09:02:46	2025-03-28 09:02:40 INFO tclean::::casa ...done
28-Mar-2025 09:02:46	2025-03-28 09:02:40 INFO tclean::::casa Ending use of cluster, but not closing it. Call clustermanager.stop_cluster() to close it if needed.
28-Mar-2025 09:02:46	2025-03-28 09:02:40 INFO tclean::::casa Searching for images with prefix 'tst.awp2'... Found these, writing history into them: ['tst.awp2.psf', 'tst.awp2.pb', 'tst.awp2.residual', 'tst.awp2.gridwt_moswt', 'tst.awp2.sumwt', 'tst.awp2.model', 'tst.awp2.image', 'tst.awp2.weight', 'tst.awp2.mask', 'tst.awp2.image.pbcor']
28-Mar-2025 09:02:46	2025-03-28 09:02:40 INFO tclean::::casa Task tclean complete. Start time: 2025-03-28 08:58:40.227903 End time: 2025-03-28 09:02:39.964060
28-Mar-2025 09:02:46	2025-03-28 09:02:40 INFO tclean::::casa ##### End Task: tclean #####
28-Mar-2025 09:02:46	2025-03-28 09:02:40 INFO tclean::::casa ##########################################
28-Mar-2025 09:02:46	2025-03-28 09:02:40 INFO name:: No table opened.
28-Mar-2025 09:02:46	2025-03-28 09:02:40 INFO showcache:: The Table Cache is empty.
28-Mar-2025 09:02:46	2025-03-28 09:02:40 INFO tclean::::casa [ checkall ]
28-Mar-2025 09:02:46	2025-03-28 09:02:40 INFO tclean::::casa+ [ check_ims ] Image made : ['tst.awp2.image'] = [True] ( Pass : should all be True )
28-Mar-2025 09:02:46	2025-03-28 09:02:40 INFO tclean::::casa+ All expected keywords in imageinfo, miscinfo, and coords found. (check_keywords)
28-Mar-2025 09:02:46	2025-03-28 09:02:40 INFO tclean::::casa+ [check_history] All expected history entries found. (Pass)
28-Mar-2025 09:02:46	2025-03-28 09:02:40 INFO tclean::::casa+ [ check_pix_val ] tst.awp2.pb : Value is 0.6862621307373047 at [323, 858, 0, 0] ( Pass : should be 0.66 , Epsilon: 0.1)
28-Mar-2025 09:02:46	2025-03-28 09:02:40 INFO tclean::::casa+ [ check_pix_val ] tst.awp2.image.pbcor : Value is 0.7013242840766907 at [323, 858, 0, 0] ( Pass : should be 0.75 , Epsilon: 0.1)
28-Mar-2025 09:02:46	.s2025-03-28 09:02:42 INFO MPICommandServer::serve::MPICommandServer::serve::casa::MPIServer-3 Control signal MPIEnvironment.command_handling_log_level = 'DEBUG' successfully handled by server 3
28-Mar-2025 09:02:46	2025-03-28 09:02:42 INFO MPICommandServer::serve::MPICommandServer::serve::casa::MPIServer-1 Control signal MPIEnvironment.command_handling_log_level = 'DEBUG' successfully handled by server 1
28-Mar-2025 09:02:46	2025-03-28 09:02:42 INFO MPICommandServer::serve::MPICommandServer::serve::casa::MPIServer-2 Control signal MPIEnvironment.command_handling_log_level = 'DEBUG' successfully handled by server 2
28-Mar-2025 09:02:46	2025-03-28 09:02:43 INFO tclean::::casa setupCluster, Setting up 3 engines.
28-Mar-2025 09:02:46	2025-03-28 09:02:43 INFO tclean::::casa ##########################################
28-Mar-2025 09:02:46	2025-03-28 09:02:43 INFO tclean::::casa ##### Begin Task: tclean #####
28-Mar-2025 09:02:46	2025-03-28 09:02:43 INFO tclean::::casa tclean( vis='refim_point_wterm_vlad.ms', selectdata=True, field='', spw='', timerange='', uvrange='', antenna='', scan='', observation='', intent='', datacolumn='corrected', imagename='tst.awp', imsize=2048, cell='10.0arcsec', phasecenter='', stokes='I', projection='SIN', startmodel='', specmode='mfs', reffreq='', nchan=-1, start='', width='', outframe='LSRK', veltype='radio', restfreq=[], interpolation='linear', perchanweightdensity=True, gridder='awproject', facets=1, psfphasecenter='', wprojplanes=16, vptable='', mosweight=True, aterm=False, psterm=True, wbawp=False, conjbeams=False, cfcache='tst_use_awp.cf', usepointing=False, computepastep=360.0, rotatepastep=360.0, pointingoffsetsigdev=[], pblimit=-0.1, normtype='flatnoise', deconvolver='hogbom', scales=[], nterms=2, smallscalebias=0.0, fusedthreshold=0.0, largestscale=-1, restoration=True, restoringbeam=[], pbcor=False, outlierfile='', weighting='uniform', robust=0.5, noise='1.0Jy', npixels=0, uvtaper=[''], niter=0, gain=0.1, threshold=0.0, nsigma=0.0, cycleniter=-1, cyclefactor=1.0, minpsffraction=0.05, maxpsffraction=0.8, interactive=False, nmajor=-1, fullsummary=False, usemask='user', mask='', pbmask=0.0, sidelobethreshold=3.0, noisethreshold=5.0, lownoisethreshold=1.5, negativethreshold=0.0, smoothfactor=1.0, minbeamfrac=0.3, cutthreshold=0.01, growiterations=75, dogrowprune=True, minpercentchange=-1.0, verbose=False, fastnoise=True, restart=True, savemodel='none', calcres=True, calcpsf=True, psfcutoff=0.35, parallel=True )
28-Mar-2025 09:02:46	2025-03-28 09:02:43 INFO tclean::::casa Verifying Input Parameters
28-Mar-2025 09:02:46	2025-03-28 09:02:45 INFO MPICommandServer::serve::MPICommandServer::serve::casa::MPIServer-3 Control signal MPIEnvironment.command_handling_log_level = 'DEBUG' successfully handled by server 3
28-Mar-2025 09:02:46	2025-03-28 09:02:45 INFO MPICommandServer::serve::MPICommandServer::serve::casa::MPIServer-1 Control signal MPIEnvironment.command_handling_log_level = 'DEBUG' successfully handled by server 1
28-Mar-2025 09:02:46	2025-03-28 09:02:45 INFO MPICommandServer::serve::MPICommandServer::serve::casa::MPIServer-2 Control signal MPIEnvironment.command_handling_log_level = 'DEBUG' successfully handled by server 2
28-Mar-2025 09:02:46	2025-03-28 09:02:46 INFO tclean::::casa setupCluster, Setting up 3 engines.
28-Mar-2025 09:02:46	2025-03-28 09:02:46 INFO SynthesisUtilMethods::continuumDataPartition
28-Mar-2025 09:02:46	2025-03-28 09:02:46 INFO SynthesisUtilMethods::continuumDataPartition + Rows = 10065 15093 [P][M]: 0:2 ROWNUMBER() >= 10065 && ROWNUMBER() <= 15093
28-Mar-2025 09:02:49	2025-03-28 09:02:46 INFO tclean::::casa Partitioned Selection : {'0': {'ms0': {'antenna': '', 'datacolumn': 'corrected', 'field': '', 'freqbeg': '', 'freqend': '', 'freqframe': 'LSRK', 'incrmodel': False, 'msname': 'refim_point_wterm_vlad.ms', 'obs': '', 'outframe': 'LSRK', 'readonly': True, 'scan': '', 'spw': '', 'state': '', 'taql': 'ROWNUMBER() >= 1 && ROWNUMBER() <= 5032', 'timestr': '', 'usescratch': False, 'uvdist': ''}}, '1': {'ms0': {'antenna': '', 'datacolumn': 'corrected', 'field': '', 'freqbeg': '', 'freqend': '', 'freqframe': 'LSRK', 'incrmodel': False, 'msname': 'refim_point_wterm_vlad.ms', 'obs': '', 'outframe': 'LSRK', 'readonly': True, 'scan': '', 'spw': '', 'state': '', 'taql': 'ROWNUMBER() >= 5033 && ROWNUMBER() <= 10064', 'timestr': '', 'usescratch': False, 'uvdist': ''}}, '2': {'ms0': {'antenna': '', 'datacolumn': 'corrected', 'field': '', 'freqbeg': '', 'freqend': '', 'freqframe': 'LSRK', 'incrmodel': False, 'msname': 'refim_point_wterm_vlad.ms', 'obs': '', 'outframe': 'LSRK', 'readonly': True, 'scan': '', 'spw': '', 'state': '', 'taql': 'ROWNUMBER() >= 10065 && ROWNUMBER() <= 15093', 'timestr': '', 'usescratch': False, 'uvdist': ''}}}
28-Mar-2025 09:02:49	2025-03-28 09:02:46 INFO SynthesisImagerVi2::selectData MS : refim_point_wterm_vlad.ms \| [Opened in readonly mode]
28-Mar-2025 09:02:49	2025-03-28 09:02:46 INFO SynthesisImagerVi2::selectData NRows selected : 15093
28-Mar-2025 09:02:49	2025-03-28 09:02:46 INFO SynthesisImagerVi2::defineImage Define image coordinates for [tst.awp] :
28-Mar-2025 09:02:49	2025-03-28 09:02:46 INFO SynthesisImagerVi2::defineImage Define image coordinates for [tst.awp] :
28-Mar-2025 09:02:49	2025-03-28 09:02:46 INFO SynthesisImagerVi2::defineImage Impars: start
28-Mar-2025 09:02:49	2025-03-28 09:02:46 INFO SynthesisImagerVi2::defineImage Shape: [2048, 2048, 1, 1] Spectral: [9.99981e+08] at [0] with increment [1.00218e+06]
28-Mar-2025 09:02:49	2025-03-28 09:02:46 INFO SynthesisImagerVi2::defineImage Set Gridding options for [tst.awp] with ftmachine : awprojectft
28-Mar-2025 09:02:49	2025-03-28 09:02:46 INFO CFCache2::fillCFSFromDisk No. of CFS* found in tst_use_awp.cf: 0
28-Mar-2025 09:02:49	2025-03-28 09:02:46 INFO CFCache2::fillCFSFromDisk No. of WTCFS* found in tst_use_awp.cf: 0
28-Mar-2025 09:02:49	2025-03-28 09:02:46 INFO AWProjectFT2::setPAIncrement[R&D] Setting PA increment to 360 deg
28-Mar-2025 09:02:49	2025-03-28 09:02:46 INFO SynthesisImagerVi2::createAWPFTMachine Sending frequency selection information Axis Lengths: [1, 4] (NB: Matrix in Row/Column order)
28-Mar-2025 09:02:49	2025-03-28 09:02:46 INFO SynthesisImagerVi2::createAWPFTMachine + [0, 1e+09, 1e+09, 1e+06]
28-Mar-2025 09:02:49	2025-03-28 09:02:46 INFO SynthesisImagerVi2::createAWPFTMachine + to AWP FTM.
28-Mar-2025 09:02:49	2025-03-28 09:02:46 INFO SynthesisImagerVi2::nSubCubeFitInMemory Required memory: 1.537 GB. Available mem.: 387.1 GB (rc, mem. fraction: 80%, memory: -) => Subcubes: 1. Processes on node: 4.
28-Mar-2025 09:02:49	2025-03-28 09:02:46 INFO tclean::::casa checkJobs. Blocking for nodes to finish
28-Mar-2025 09:02:49	2025-03-28 09:02:47 INFO tclean::::casa ...done
28-Mar-2025 09:02:49	2025-03-28 09:02:47 INFO tclean::::casa checkJobs. Blocking for nodes to finish
28-Mar-2025 09:02:49	2025-03-28 09:02:47 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::selectData::MPIServer-3 MS : refim_point_wterm_vlad.ms \| [Opened in readonly mode]
28-Mar-2025 09:02:49	2025-03-28 09:02:47 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::selectData::MPIServer-3 Selecting via TaQL : ROWNUMBER() >= 10065 && ROWNUMBER() <= 15093 \| NRows selected : 5029
28-Mar-2025 09:02:49	2025-03-28 09:02:47 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::selectData::MPIServer-2 MS : refim_point_wterm_vlad.ms \| [Opened in readonly mode]
28-Mar-2025 09:02:49	2025-03-28 09:02:47 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::selectData::MPIServer-2 Selecting via TaQL : ROWNUMBER() >= 5033 && ROWNUMBER() <= 10064 \| NRows selected : 5032
28-Mar-2025 09:02:49	2025-03-28 09:02:47 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::selectData::MPIServer-1 MS : refim_point_wterm_vlad.ms \| [Opened in readonly mode]
28-Mar-2025 09:02:49	2025-03-28 09:02:47 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::selectData::MPIServer-1 Selecting via TaQL : ROWNUMBER() >= 1 && ROWNUMBER() <= 5032 \| NRows selected : 5032
28-Mar-2025 09:02:49	2025-03-28 09:02:48 INFO tclean::::casa ...done
28-Mar-2025 09:02:49	2025-03-28 09:02:49 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::defineImage::MPIServer-1 Define image coordinates for [/home/casatest/work/test_task_tclean/tst.awp.workdirectory/tst.awp.n1] :
28-Mar-2025 09:02:49	2025-03-28 09:02:49 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::defineImage::MPIServer-1 Define image coordinates for [/home/casatest/work/test_task_tclean/tst.awp.workdirectory/tst.awp.n1] :
28-Mar-2025 09:02:49	2025-03-28 09:02:49 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::defineImage::MPIServer-1 Impars: start
28-Mar-2025 09:02:49	2025-03-28 09:02:49 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::defineImage::MPIServer-1 Shape: [2048, 2048, 1, 1] Spectral: [9.99981e+08] at [0] with increment [1.00218e+06]
28-Mar-2025 09:02:49	2025-03-28 09:02:49 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::defineImage::MPIServer-1 Set Gridding options for [/home/casatest/work/test_task_tclean/tst.awp.workdirectory/tst.awp.n1] with ftmachine : awprojectft
28-Mar-2025 09:02:49	2025-03-28 09:02:49 INFO MPICommandServer::command_request_handler_service::CFCache2::fillCFSFromDisk::MPIServer-1 No. of CFS* found in tst_use_awp.cf: 0
28-Mar-2025 09:02:49	2025-03-28 09:02:49 INFO MPICommandServer::command_request_handler_service::CFCache2::fillCFSFromDisk::MPIServer-1 No. of WTCFS* found in tst_use_awp.cf: 0
28-Mar-2025 09:02:49	2025-03-28 09:02:49 INFO MPICommandServer::command_request_handler_service::AWProjectFT2::setPAIncrement[R&D]::MPIServer-1 Setting PA increment to 360 deg
28-Mar-2025 09:02:49	2025-03-28 09:02:49 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::createAWPFTMachine::MPIServer-1 Sending frequency selection information Axis Lengths: [1, 4] (NB: Matrix in Row/Column order)
28-Mar-2025 09:02:49	2025-03-28 09:02:49 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::createAWPFTMachine::MPIServer-1 + [0, 1e+09, 1e+09, 1e+06]
28-Mar-2025 09:02:49	2025-03-28 09:02:49 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::createAWPFTMachine::MPIServer-1 + to AWP FTM.
28-Mar-2025 09:02:49	2025-03-28 09:02:49 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::nSubCubeFitInMemory::MPIServer-1 Required memory: 1.537 GB. Available mem.: 387.1 GB (rc, mem. fraction: 80%, memory: -) => Subcubes: 1. Processes on node: 4.
28-Mar-2025 09:02:49	2025-03-28 09:02:49 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::defineImage::MPIServer-2 Define image coordinates for [/home/casatest/work/test_task_tclean/tst.awp.workdirectory/tst.awp.n2] :
28-Mar-2025 09:02:49	2025-03-28 09:02:49 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::defineImage::MPIServer-2 Define image coordinates for [/home/casatest/work/test_task_tclean/tst.awp.workdirectory/tst.awp.n2] :
28-Mar-2025 09:02:49	2025-03-28 09:02:49 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::defineImage::MPIServer-2 Impars: start
28-Mar-2025 09:02:49	2025-03-28 09:02:49 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::defineImage::MPIServer-2 Shape: [2048, 2048, 1, 1] Spectral: [9.99981e+08] at [0] with increment [1.00218e+06]
28-Mar-2025 09:02:49	2025-03-28 09:02:49 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::defineImage::MPIServer-2 Set Gridding options for [/home/casatest/work/test_task_tclean/tst.awp.workdirectory/tst.awp.n2] with ftmachine : awprojectft
28-Mar-2025 09:02:49	2025-03-28 09:02:49 INFO MPICommandServer::command_request_handler_service::CFCache2::fillCFSFromDisk::MPIServer-2 No. of CFS* found in tst_use_awp.cf: 0
28-Mar-2025 09:02:49	2025-03-28 09:02:49 INFO MPICommandServer::command_request_handler_service::CFCache2::fillCFSFromDisk::MPIServer-2 No. of WTCFS* found in tst_use_awp.cf: 0
28-Mar-2025 09:02:49	2025-03-28 09:02:49 INFO MPICommandServer::command_request_handler_service::AWProjectFT2::setPAIncrement[R&D]::MPIServer-2 Setting PA increment to 360 deg
28-Mar-2025 09:02:49	2025-03-28 09:02:49 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::createAWPFTMachine::MPIServer-2 Sending frequency selection information Axis Lengths: [1, 4] (NB: Matrix in Row/Column order)
28-Mar-2025 09:04:17	2025-03-28 09:02:49 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::createAWPFTMachine::MPIServer-2 + [0, 1e+09, 1e+09, 1e+06]
28-Mar-2025 09:04:17	2025-03-28 09:02:49 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::createAWPFTMachine::MPIServer-2 + to AWP FTM.
28-Mar-2025 09:04:17	2025-03-28 09:02:49 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::nSubCubeFitInMemory::MPIServer-2 Required memory: 1.537 GB. Available mem.: 387.1 GB (rc, mem. fraction: 80%, memory: -) => Subcubes: 1. Processes on node: 4.
28-Mar-2025 09:04:17	2025-03-28 09:02:49 INFO tclean::::casa checkJobs. Blocking for nodes to finish
28-Mar-2025 09:04:17	2025-03-28 09:02:50 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::defineImage::MPIServer-3 Define image coordinates for [/home/casatest/work/test_task_tclean/tst.awp.workdirectory/tst.awp.n3] :
28-Mar-2025 09:04:17	2025-03-28 09:02:50 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::defineImage::MPIServer-3 Define image coordinates for [/home/casatest/work/test_task_tclean/tst.awp.workdirectory/tst.awp.n3] :
28-Mar-2025 09:04:17	2025-03-28 09:02:50 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::defineImage::MPIServer-3 Impars: start
28-Mar-2025 09:04:17	2025-03-28 09:02:50 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::defineImage::MPIServer-3 Shape: [2048, 2048, 1, 1] Spectral: [9.99981e+08] at [0] with increment [1.00218e+06]
28-Mar-2025 09:04:17	2025-03-28 09:02:50 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::defineImage::MPIServer-3 Set Gridding options for [/home/casatest/work/test_task_tclean/tst.awp.workdirectory/tst.awp.n3] with ftmachine : awprojectft
28-Mar-2025 09:04:17	2025-03-28 09:02:50 INFO MPICommandServer::command_request_handler_service::CFCache2::fillCFSFromDisk::MPIServer-3 No. of CFS* found in tst_use_awp.cf: 0
28-Mar-2025 09:04:17	2025-03-28 09:02:50 INFO MPICommandServer::command_request_handler_service::CFCache2::fillCFSFromDisk::MPIServer-3 No. of WTCFS* found in tst_use_awp.cf: 0
28-Mar-2025 09:04:17	2025-03-28 09:02:50 INFO MPICommandServer::command_request_handler_service::AWProjectFT2::setPAIncrement[R&D]::MPIServer-3 Setting PA increment to 360 deg
28-Mar-2025 09:04:17	2025-03-28 09:02:50 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::createAWPFTMachine::MPIServer-3 Sending frequency selection information Axis Lengths: [1, 4] (NB: Matrix in Row/Column order)
28-Mar-2025 09:04:17	2025-03-28 09:02:50 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::createAWPFTMachine::MPIServer-3 + [0, 1e+09, 1e+09, 1e+06]
28-Mar-2025 09:04:17	2025-03-28 09:02:50 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::createAWPFTMachine::MPIServer-3 + to AWP FTM.
28-Mar-2025 09:04:17	2025-03-28 09:02:50 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::nSubCubeFitInMemory::MPIServer-3 Required memory: 1.537 GB. Available mem.: 387.1 GB (rc, mem. fraction: 80%, memory: -) => Subcubes: 1. Processes on node: 4.
28-Mar-2025 09:04:17	2025-03-28 09:02:50 INFO tclean::::casa ...done
28-Mar-2025 09:04:17	2025-03-28 09:02:50 INFO SynthesisImagerVi2::dryGridding ---------------------------------------------------- Dry Gridding ---------------------------------------------
28-Mar-2025 09:04:17	2025-03-28 09:02:51 INFO AWProjectFT2::init[R&D] Using CPUResampler visibility resampler (a.k.a. "gridder/degridder")
28-Mar-2025 09:04:17	2025-03-28 09:02:51 INFO AWProjectFT2::initializeToSky[R&D] Computed maps using FTMachine::initMaps. polMap = [0, 0]
28-Mar-2025 09:04:17	2025-03-28 09:02:51 WARN SynthesisImagerVi2::dryGridding (file /source/casa6/casatools/src/code/synthesis/ImagerObjects/SynthesisImagerVi2.cc, line 3148) Making a "blank" CFCache (without the A-Term)
28-Mar-2025 09:04:17	2025-03-28 09:02:51 INFO VB2CFBMap::makeVBRow2CFBMap[R&D] CFs not cached for -64.1134 deg, dPA = 360 Field ID = 0 Ant1Type, Ant2Type = 0,0
28-Mar-2025 09:04:17	2025-03-28 09:02:51 INFO AWConvFunc2::makeConvFunction[R&D] Making a new convolution function for PA=-64.1134deg for field ID 0
28-Mar-2025 09:04:17	2025-03-28 09:02:51 INFO AWConvFunc2::makeConvFunction[R&D] Using 16 planes for W-projection
28-Mar-2025 09:04:17	2025-03-28 09:02:51 INFO AWConvFunc2::makeConvFunction[R&D] Estimating maximum possible W = 5156.62 (wavelengths)
28-Mar-2025 09:04:17	2025-03-28 09:02:51 INFO AWConvFunc2::makeConvFunction[R&D] Scaling in W (at maximum W) = 22.9183 wavelengths per pixel
28-Mar-2025 09:04:17	2025-03-28 09:02:51 INFO AWConvFunc2::makeConvFunction[R&D] Making 16 w plane(s).
28-Mar-2025 09:04:17	2025-03-28 09:02:51 INFO AWConvFunc2::makeConvFunction[R&D] Making 1 frequency plane(s).
28-Mar-2025 09:04:17	2025-03-28 09:02:51 INFO AWConvFunc2::makeConvFunction[R&D] CFB Freq. axis [N, Min, Max, Incr. (GHz)]: 1 0.999981 0.999981 0.1
28-Mar-2025 09:04:17	2025-03-28 09:02:51 INFO AWConvFunc2::makeConvFunction[R&D] Making empty CFs for baseline type 0
28-Mar-2025 09:04:17	2025-03-28 09:02:51 WARN AWProjectWBFT2::makeSensitivityImage(Complex)[R&D] Setting up for weights accumulation during gridding to compute sensitivity pattern.
28-Mar-2025 09:04:17	2025-03-28 09:02:51 WARN AWProjectWBFT2::makeSensitivityImage(Complex)[R&D]+ Consequently, the first gridding cycle will be slower than the subsequent ones.
28-Mar-2025 09:04:17	2025-03-28 09:02:51 INFO CFStore2::makePersistent(pa)[R&D] Saving CFStore of shape [1, 16, 2] for PA = -64.1134 BaselineType(antType1, antType2) = (0,0)
28-Mar-2025 09:04:17	2025-03-28 09:02:52 INFO CFStore2::makePersistent(pa)[R&D] Saving CFStore of shape [1, 16, 2] for PA = -64.1134 BaselineType(antType1, antType2) = (0,0)
28-Mar-2025 09:04:17	2025-03-28 09:02:53 INFO AWProjectFT2::findConvFunction[R&D] Convolution function memory footprint:0 KB out of a maximum of 515201 MB
28-Mar-2025 09:04:17	2025-03-28 09:02:53 INFO SynthesisImagerVi2::fillCFCache ---------------------------------------------------- fillCFCache ---------------------------------------------
28-Mar-2025 09:04:17	2025-03-28 09:02:53 WARN SynthesisImagerVi2::fillCFCache (file /source/casa6/casatools/src/code/synthesis/ImagerObjects/SynthesisImagerVi2.cc, line 3232) Re-loading the "blank" CFCache for filling
28-Mar-2025 09:04:17	2025-03-28 09:02:53 INFO CFCache2::fillCFListFromDisk Loading misc info from CFs
28-Mar-2025 09:04:17	2025-03-28 09:02:53 INFO CFCache2::fillCFListFromDisk Loading misc info from CFs
28-Mar-2025 09:04:17	2025-03-28 09:02:53 WARN crustaceans::makeConvFunction2[R&D] Filling CFs for baseline type 0, PA slot 0
28-Mar-2025 09:04:17	2025-03-28 09:02:53 INFO BeamCalc::setBeamCalcGeometries() Initialisation of geometries for observatory VLA, antenna type STANDARD
28-Mar-2025 09:04:17	2025-03-28 09:02:53 INFO BeamCalc::setBeamCalcGeometries() Will use default geometries for VLA STANDARD.
28-Mar-2025 09:04:17	Processing request for geometries from observatory VLA, antenna type STANDARD
28-Mar-2025 09:04:17	2025-03-28 09:02:58 INFO Moluscs::fillConvFuncBuffer2[R&D] CF(M:0,C:0.999981,W:0): CF Support: 4 (6) pixels
28-Mar-2025 09:04:17	2025-03-28 09:03:03 INFO Moluscs::fillConvFuncBuffer2[R&D] CF(M:0,C:0.999981,W:22.9183): CF Support: 5 (6) pixels
28-Mar-2025 09:04:17	2025-03-28 09:03:08 INFO Moluscs::fillConvFuncBuffer2[R&D] CF(M:0,C:0.999981,W:91.6732): CF Support: 5 (6) pixels
28-Mar-2025 09:04:17	2025-03-28 09:03:13 INFO Moluscs::fillConvFuncBuffer2[R&D] CF(M:0,C:0.999981,W:206.265): CF Support: 5 (6) pixels
28-Mar-2025 09:04:17	2025-03-28 09:03:18 INFO Moluscs::fillConvFuncBuffer2[R&D] CF(M:0,C:0.999981,W:366.693): CF Support: 6 (6) pixels
28-Mar-2025 09:04:17	2025-03-28 09:03:23 INFO Moluscs::fillConvFuncBuffer2[R&D] CF(M:0,C:0.999981,W:572.958): CF Support: 7 (6) pixels
28-Mar-2025 09:04:17	2025-03-28 09:03:28 INFO Moluscs::fillConvFuncBuffer2[R&D] CF(M:0,C:0.999981,W:825.059): CF Support: 9 (6) pixels
28-Mar-2025 09:04:17	2025-03-28 09:03:33 INFO Moluscs::fillConvFuncBuffer2[R&D] CF(M:0,C:0.999981,W:1123): CF Support: 10 (6) pixels
28-Mar-2025 09:04:17	2025-03-28 09:03:38 INFO Moluscs::fillConvFuncBuffer2[R&D] CF(M:0,C:0.999981,W:1466.77): CF Support: 12 (6) pixels
28-Mar-2025 09:04:17	2025-03-28 09:03:43 INFO Moluscs::fillConvFuncBuffer2[R&D] CF(M:0,C:0.999981,W:1856.38): CF Support: 14 (6) pixels
28-Mar-2025 09:04:17	2025-03-28 09:03:48 INFO Moluscs::fillConvFuncBuffer2[R&D] CF(M:0,C:0.999981,W:2291.83): CF Support: 17 (6) pixels
28-Mar-2025 09:04:17	2025-03-28 09:03:53 INFO Moluscs::fillConvFuncBuffer2[R&D] CF(M:0,C:0.999981,W:2773.12): CF Support: 19 (6) pixels
28-Mar-2025 09:04:17	2025-03-28 09:03:58 INFO Moluscs::fillConvFuncBuffer2[R&D] CF(M:0,C:0.999981,W:3300.24): CF Support: 22 (6) pixels
28-Mar-2025 09:04:17	2025-03-28 09:04:03 INFO Moluscs::fillConvFuncBuffer2[R&D] CF(M:0,C:0.999981,W:3873.19): CF Support: 26 (6) pixels
28-Mar-2025 09:04:17	2025-03-28 09:04:07 INFO Moluscs::fillConvFuncBuffer2[R&D] CF(M:0,C:0.999981,W:4491.99): CF Support: 29 (6) pixels
28-Mar-2025 09:04:17	2025-03-28 09:04:12 INFO Moluscs::fillConvFuncBuffer2[R&D] CF(M:0,C:0.999981,W:5156.62): CF Support: 33 (6) pixels
28-Mar-2025 09:05:35	2025-03-28 09:04:17 INFO Moluscs::fillConvFuncBuffer2[R&D] CF(M:15,C:0.999981,W:0): CF Support: 4 (6) pixels
28-Mar-2025 09:05:35	2025-03-28 09:04:22 INFO Moluscs::fillConvFuncBuffer2[R&D] CF(M:15,C:0.999981,W:22.9183): CF Support: 5 (6) pixels
28-Mar-2025 09:05:35	2025-03-28 09:04:27 INFO Moluscs::fillConvFuncBuffer2[R&D] CF(M:15,C:0.999981,W:91.6732): CF Support: 5 (6) pixels
28-Mar-2025 09:05:35	2025-03-28 09:04:32 INFO Moluscs::fillConvFuncBuffer2[R&D] CF(M:15,C:0.999981,W:206.265): CF Support: 5 (6) pixels
28-Mar-2025 09:05:35	2025-03-28 09:04:37 INFO Moluscs::fillConvFuncBuffer2[R&D] CF(M:15,C:0.999981,W:366.693): CF Support: 6 (6) pixels
28-Mar-2025 09:05:35	2025-03-28 09:04:42 INFO Moluscs::fillConvFuncBuffer2[R&D] CF(M:15,C:0.999981,W:572.958): CF Support: 7 (6) pixels
28-Mar-2025 09:05:35	2025-03-28 09:04:47 INFO Moluscs::fillConvFuncBuffer2[R&D] CF(M:15,C:0.999981,W:825.059): CF Support: 9 (6) pixels
28-Mar-2025 09:05:35	2025-03-28 09:04:52 INFO Moluscs::fillConvFuncBuffer2[R&D] CF(M:15,C:0.999981,W:1123): CF Support: 10 (6) pixels
28-Mar-2025 09:05:35	2025-03-28 09:04:57 INFO Moluscs::fillConvFuncBuffer2[R&D] CF(M:15,C:0.999981,W:1466.77): CF Support: 12 (6) pixels
28-Mar-2025 09:05:35	2025-03-28 09:05:02 INFO Moluscs::fillConvFuncBuffer2[R&D] CF(M:15,C:0.999981,W:1856.38): CF Support: 14 (6) pixels
28-Mar-2025 09:05:35	2025-03-28 09:05:07 INFO Moluscs::fillConvFuncBuffer2[R&D] CF(M:15,C:0.999981,W:2291.83): CF Support: 17 (6) pixels
28-Mar-2025 09:05:35	2025-03-28 09:05:12 INFO Moluscs::fillConvFuncBuffer2[R&D] CF(M:15,C:0.999981,W:2773.12): CF Support: 19 (6) pixels
28-Mar-2025 09:05:35	2025-03-28 09:05:17 INFO Moluscs::fillConvFuncBuffer2[R&D] CF(M:15,C:0.999981,W:3300.24): CF Support: 22 (6) pixels
28-Mar-2025 09:05:35	2025-03-28 09:05:22 INFO Moluscs::fillConvFuncBuffer2[R&D] CF(M:15,C:0.999981,W:3873.19): CF Support: 26 (6) pixels
28-Mar-2025 09:05:35	2025-03-28 09:05:27 INFO Moluscs::fillConvFuncBuffer2[R&D] CF(M:15,C:0.999981,W:4491.99): CF Support: 29 (6) pixels
28-Mar-2025 09:05:35	2025-03-28 09:05:32 INFO Moluscs::fillConvFuncBuffer2[R&D] CF(M:15,C:0.999981,W:5156.62): CF Support: 33 (6) pixels
28-Mar-2025 09:05:35	2025-03-28 09:05:32 INFO CFStore2.2::makePersistent[R&D] Writing CFStore(0,0) of shape [1, 16, 2]
28-Mar-2025 09:05:35	2025-03-28 09:05:33 INFO CFStore2.2::makePersistent[R&D] Writing CFStore(0,0) of shape [1, 16, 2]
28-Mar-2025 09:05:35	2025-03-28 09:05:34 INFO tclean::::casa reloadCFCache, CMD = 1 toolsi.reloadcfcache()
28-Mar-2025 09:05:35	2025-03-28 09:05:34 INFO tclean::::casa reloadCFCache, CMD = 2 toolsi.reloadcfcache()
28-Mar-2025 09:05:35	2025-03-28 09:05:34 INFO tclean::::casa reloadCFCache, CMD = 3 toolsi.reloadcfcache()
28-Mar-2025 09:05:35	2025-03-28 09:05:34 INFO tclean::::casa checkJobs. Blocking for nodes to finish
28-Mar-2025 09:05:35	2025-03-28 09:05:34 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::reloadCFCache::MPIServer-3 -------------------------------------------- Re-load CFCache ---------------------------------------------
28-Mar-2025 09:05:35	2025-03-28 09:05:34 INFO MPICommandServer::command_request_handler_service::CFCache::setLazyFill::MPIServer-3 Lazy fill is On
28-Mar-2025 09:05:35	2025-03-28 09:05:34 INFO MPICommandServer::command_request_handler_service::CFCache2::fillCFSFromDisk::MPIServer-3 No. of CFS* found in tst_use_awp.cf: 32
28-Mar-2025 09:05:35	2025-03-28 09:05:34 INFO MPICommandServer::command_request_handler_service::CFCache2::fillCFListFromDisk::MPIServer-3 Loading misc info from CFs
28-Mar-2025 09:05:35	2025-03-28 09:05:34 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::reloadCFCache::MPIServer-2 -------------------------------------------- Re-load CFCache ---------------------------------------------
28-Mar-2025 09:05:35	2025-03-28 09:05:34 INFO MPICommandServer::command_request_handler_service::CFCache::setLazyFill::MPIServer-2 Lazy fill is On
28-Mar-2025 09:05:35	2025-03-28 09:05:35 INFO MPICommandServer::command_request_handler_service::CFCache2::fillCFSFromDisk::MPIServer-2 No. of CFS* found in tst_use_awp.cf: 32
28-Mar-2025 09:05:35	2025-03-28 09:05:35 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::reloadCFCache::MPIServer-1 -------------------------------------------- Re-load CFCache ---------------------------------------------
28-Mar-2025 09:05:35	2025-03-28 09:05:35 INFO MPICommandServer::command_request_handler_service::CFCache::setLazyFill::MPIServer-1 Lazy fill is On
28-Mar-2025 09:05:35	2025-03-28 09:05:35 INFO MPICommandServer::command_request_handler_service::CFCache2::fillCFSFromDisk::MPIServer-1 No. of CFS* found in tst_use_awp.cf: 32
28-Mar-2025 09:05:35	2025-03-28 09:05:35 INFO MPICommandServer::command_request_handler_service::CFCache2::fillCFListFromDisk::MPIServer-2 Loading misc info from CFs
28-Mar-2025 09:05:35	2025-03-28 09:05:35 INFO MPICommandServer::command_request_handler_service::CFCache2::fillCFListFromDisk::MPIServer-1 Loading misc info from CFs
28-Mar-2025 09:05:35	2025-03-28 09:05:35 INFO MPICommandServer::command_request_handler_service::CFCache2::fillCFSFromDisk::MPIServer-3 No. of WTCFS* found in tst_use_awp.cf: 32
28-Mar-2025 09:05:35	2025-03-28 09:05:35 INFO MPICommandServer::command_request_handler_service::CFCache2::fillCFListFromDisk::MPIServer-3 Loading misc info from CFs
28-Mar-2025 09:05:35	2025-03-28 09:05:35 INFO MPICommandServer::command_request_handler_service::CFCache2::fillCFSFromDisk::MPIServer-2 No. of WTCFS* found in tst_use_awp.cf: 32
28-Mar-2025 09:05:35	2025-03-28 09:05:35 INFO MPICommandServer::command_request_handler_service::CFCache2::fillCFSFromDisk::MPIServer-1 No. of WTCFS* found in tst_use_awp.cf: 32
28-Mar-2025 09:05:35	2025-03-28 09:05:35 INFO MPICommandServer::command_request_handler_service::CFCache2::fillCFListFromDisk::MPIServer-2 Loading misc info from CFs
28-Mar-2025 09:05:35	2025-03-28 09:05:35 INFO MPICommandServer::command_request_handler_service::CFCache2::fillCFListFromDisk::MPIServer-1 Loading misc info from CFs
28-Mar-2025 09:05:35	2025-03-28 09:05:35 INFO tclean::::casa ...done
28-Mar-2025 09:05:35	2025-03-28 09:05:35 INFO tclean::::casa reloadCFCache, CMD = 1 toolsi.reloadcfcache()
28-Mar-2025 09:05:35	2025-03-28 09:05:35 INFO tclean::::casa reloadCFCache, CMD = 2 toolsi.reloadcfcache()
28-Mar-2025 09:05:35	2025-03-28 09:05:35 INFO tclean::::casa reloadCFCache, CMD = 3 toolsi.reloadcfcache()
28-Mar-2025 09:05:35	2025-03-28 09:05:35 INFO tclean::::casa checkJobs. Blocking for nodes to finish
28-Mar-2025 09:05:35	2025-03-28 09:05:35 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::reloadCFCache::MPIServer-1 -------------------------------------------- Re-load CFCache ---------------------------------------------
28-Mar-2025 09:05:35	2025-03-28 09:05:35 INFO MPICommandServer::command_request_handler_service::CFCache::setLazyFill::MPIServer-1 Lazy fill is On
28-Mar-2025 09:05:35	2025-03-28 09:05:35 INFO MPICommandServer::command_request_handler_service::CFCache2::fillCFSFromDisk::MPIServer-1 No. of CFS* found in tst_use_awp.cf: 32
28-Mar-2025 09:05:35	2025-03-28 09:05:35 INFO MPICommandServer::command_request_handler_service::CFCache2::fillCFListFromDisk::MPIServer-1 Loading misc info from CFs
28-Mar-2025 09:05:35	2025-03-28 09:05:35 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::reloadCFCache::MPIServer-3 -------------------------------------------- Re-load CFCache ---------------------------------------------
28-Mar-2025 09:05:35	2025-03-28 09:05:35 INFO MPICommandServer::command_request_handler_service::CFCache::setLazyFill::MPIServer-3 Lazy fill is On
28-Mar-2025 09:05:35	2025-03-28 09:05:35 INFO MPICommandServer::command_request_handler_service::CFCache2::fillCFSFromDisk::MPIServer-3 No. of CFS* found in tst_use_awp.cf: 32
28-Mar-2025 09:05:35	2025-03-28 09:05:35 INFO MPICommandServer::command_request_handler_service::CFCache2::fillCFListFromDisk::MPIServer-3 Loading misc info from CFs
28-Mar-2025 09:05:35	2025-03-28 09:05:36 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::reloadCFCache::MPIServer-2 -------------------------------------------- Re-load CFCache ---------------------------------------------
28-Mar-2025 09:05:35	2025-03-28 09:05:36 INFO MPICommandServer::command_request_handler_service::CFCache::setLazyFill::MPIServer-2 Lazy fill is On
28-Mar-2025 09:05:35	2025-03-28 09:05:36 INFO MPICommandServer::command_request_handler_service::CFCache2::fillCFSFromDisk::MPIServer-2 No. of CFS* found in tst_use_awp.cf: 32
28-Mar-2025 09:05:35	2025-03-28 09:05:36 INFO MPICommandServer::command_request_handler_service::CFCache2::fillCFSFromDisk::MPIServer-1 No. of WTCFS* found in tst_use_awp.cf: 32
28-Mar-2025 09:05:35	2025-03-28 09:05:36 INFO MPICommandServer::command_request_handler_service::CFCache2::fillCFListFromDisk::MPIServer-2 Loading misc info from CFs
28-Mar-2025 09:05:35	2025-03-28 09:05:36 INFO MPICommandServer::command_request_handler_service::CFCache2::fillCFListFromDisk::MPIServer-1 Loading misc info from CFs
28-Mar-2025 09:05:35	2025-03-28 09:05:36 INFO MPICommandServer::command_request_handler_service::CFCache2::fillCFSFromDisk::MPIServer-3 No. of WTCFS* found in tst_use_awp.cf: 32
28-Mar-2025 09:05:44	2025-03-28 09:05:36 INFO MPICommandServer::command_request_handler_service::CFCache2::fillCFListFromDisk::MPIServer-3 Loading misc info from CFs
28-Mar-2025 09:05:44	2025-03-28 09:05:36 INFO MPICommandServer::command_request_handler_service::CFCache2::fillCFSFromDisk::MPIServer-2 No. of WTCFS* found in tst_use_awp.cf: 32
28-Mar-2025 09:05:44	2025-03-28 09:05:36 INFO MPICommandServer::command_request_handler_service::CFCache2::fillCFListFromDisk::MPIServer-2 Loading misc info from CFs
28-Mar-2025 09:05:44	2025-03-28 09:05:36 INFO tclean::::casa ...done
28-Mar-2025 09:05:44	2025-03-28 09:05:36 INFO VB2CFBMap::~VB2CFMap[R&D] Total extra cost of heterogeneous array pointing correction = 0sec. Total VBs processed = 0. The pointingoffsetsigdev used was = []
28-Mar-2025 09:05:44	2025-03-28 09:05:39 INFO tclean::::casa checkJobs. Blocking for nodes to finish
28-Mar-2025 09:05:44	2025-03-28 09:05:39 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::weight()::MPIServer-3 Set imaging weights : Uniform weighting: sidelobes will be suppressed over full image
28-Mar-2025 09:05:44	2025-03-28 09:05:39 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::weight()::MPIServer-2 Set imaging weights : Uniform weighting: sidelobes will be suppressed over full image
28-Mar-2025 09:05:44	2025-03-28 09:05:39 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::weight()::MPIServer-1 Set imaging weights : Uniform weighting: sidelobes will be suppressed over full image
28-Mar-2025 09:05:44	2025-03-28 09:05:40 INFO tclean::::casa ...done
28-Mar-2025 09:05:44	2025-03-28 09:05:40 INFO tclean::::casa Gathering/Merging/Scattering Weight Density for PSF generation
28-Mar-2025 09:05:44	2025-03-28 09:05:40 INFO tclean::::casa checkJobs. Blocking for nodes to finish
28-Mar-2025 09:05:44	2025-03-28 09:05:41 INFO tclean::::casa ...done
28-Mar-2025 09:05:44	2025-03-28 09:05:41 INFO tclean::::casa ******************************************************
28-Mar-2025 09:05:44	2025-03-28 09:05:41 INFO tclean::::casa gather and scatter now
28-Mar-2025 09:05:44	2025-03-28 09:05:41 INFO tclean::::casa ******************************************************
28-Mar-2025 09:05:44	2025-03-28 09:05:41 INFO SynthesisNormalizer::scatterWeightDensity Send the gridded weight from : tst.awp to all nodes :[/home/casatest/work/test_task_tclean/tst.awp.workdirectory/tst.awp.n1, /home/casatest/work/test_task_tclean/tst.awp.workdirectory/tst.awp.n2, /home/casatest/work/test_task_tclean/tst.awp.workdirectory/tst.awp.n3]
28-Mar-2025 09:05:44	2025-03-28 09:05:41 INFO tclean::::casa checkJobs. Blocking for nodes to finish
28-Mar-2025 09:05:44	2025-03-28 09:05:42 INFO tclean::::casa ...done
28-Mar-2025 09:05:44	2025-03-28 09:05:42 INFO task_tclean::SynthesisDeconvolver::setupDeconvolution Set Deconvolution Options for [tst.awp] : hogbom
28-Mar-2025 09:05:44	2025-03-28 09:05:42 INFO tclean::::casa checkJobs. Blocking for nodes to finish
28-Mar-2025 09:05:44	2025-03-28 09:05:43 INFO tclean::::casa ...done
28-Mar-2025 09:05:44	2025-03-28 09:05:43 INFO tclean::::casa checkJobs. Blocking for nodes to finish
28-Mar-2025 09:05:44	2025-03-28 09:05:43 INFO MPICommandServer::command_request_handler_service::SynthesisImager::makePSF::MPIServer-3 ----------------------------------------------------------- Make PSF ---------------------------------------------
28-Mar-2025 09:05:44	2025-03-28 09:05:43 INFO MPICommandServer::command_request_handler_service::SynthesisImager::makePSF::MPIServer-2 ----------------------------------------------------------- Make PSF ---------------------------------------------
28-Mar-2025 09:05:44	2025-03-28 09:05:43 INFO MPICommandServer::command_request_handler_service::SynthesisImager::makePSF::MPIServer-1 ----------------------------------------------------------- Make PSF ---------------------------------------------
28-Mar-2025 09:05:44	2025-03-28 09:05:43 INFO MPICommandServer::command_request_handler_service::AWProjectFT2::init[R&D]::MPIServer-3 Using CPUResampler visibility resampler (a.k.a. "gridder/degridder")
28-Mar-2025 09:05:44	2025-03-28 09:05:43 INFO MPICommandServer::command_request_handler_service::AWProjectFT2::initializeToSky[R&D]::MPIServer-3 Computed maps using FTMachine::initMaps. polMap = [0, 0]
28-Mar-2025 09:05:44	2025-03-28 09:05:43 INFO MPICommandServer::command_request_handler_service::AWProjectFT2::init[R&D]::MPIServer-1 Using CPUResampler visibility resampler (a.k.a. "gridder/degridder")
28-Mar-2025 09:05:44	2025-03-28 09:05:43 INFO MPICommandServer::command_request_handler_service::AWProjectFT2::initializeToSky[R&D]::MPIServer-1 Computed maps using FTMachine::initMaps. polMap = [0, 0]
28-Mar-2025 09:05:44	2025-03-28 09:05:43 INFO MPICommandServer::command_request_handler_service::AWProjectFT2::init[R&D]::MPIServer-2 Using CPUResampler visibility resampler (a.k.a. "gridder/degridder")
28-Mar-2025 09:05:44	2025-03-28 09:05:43 INFO MPICommandServer::command_request_handler_service::AWProjectFT2::initializeToSky[R&D]::MPIServer-2 Computed maps using FTMachine::initMaps. polMap = [0, 0]
28-Mar-2025 09:05:44	2025-03-28 09:05:43 INFO MPICommandServer::command_request_handler_service::PhaseGrad::computeAntennaPointingGrad::MPIServer-3 Computing Phase Grad for Field : 0 for spw :0
28-Mar-2025 09:05:44	2025-03-28 09:05:43 WARN MPICommandServer::command_request_handler_service::AWProjectWBFT2::makeSensitivityImage(Complex)[R&D]::MPIServer-3 Setting up for weights accumulation during gridding to compute sensitivity pattern.
28-Mar-2025 09:05:44	2025-03-28 09:05:43 WARN MPICommandServer::command_request_handler_service::AWProjectWBFT2::makeSensitivityImage(Complex)[R&D]::MPIServer-3+ Consequently, the first gridding cycle will be slower than the subsequent ones.
28-Mar-2025 09:05:44	2025-03-28 09:05:44 INFO MPICommandServer::command_request_handler_service::PhaseGrad::computeAntennaPointingGrad::MPIServer-1 Computing Phase Grad for Field : 0 for spw :0
28-Mar-2025 09:05:44	2025-03-28 09:05:44 WARN MPICommandServer::command_request_handler_service::AWProjectWBFT2::makeSensitivityImage(Complex)[R&D]::MPIServer-1 Setting up for weights accumulation during gridding to compute sensitivity pattern.
28-Mar-2025 09:05:44	2025-03-28 09:05:44 WARN MPICommandServer::command_request_handler_service::AWProjectWBFT2::makeSensitivityImage(Complex)[R&D]::MPIServer-1+ Consequently, the first gridding cycle will be slower than the subsequent ones.
28-Mar-2025 09:05:44	2025-03-28 09:05:44 INFO MPICommandServer::command_request_handler_service::PhaseGrad::computeAntennaPointingGrad::MPIServer-2 Computing Phase Grad for Field : 0 for spw :0
28-Mar-2025 09:05:44	2025-03-28 09:05:44 WARN MPICommandServer::command_request_handler_service::AWProjectWBFT2::makeSensitivityImage(Complex)[R&D]::MPIServer-2 Setting up for weights accumulation during gridding to compute sensitivity pattern.
28-Mar-2025 09:05:44	2025-03-28 09:05:44 WARN MPICommandServer::command_request_handler_service::AWProjectWBFT2::makeSensitivityImage(Complex)[R&D]::MPIServer-2+ Consequently, the first gridding cycle will be slower than the subsequent ones.
28-Mar-2025 09:05:44	2025-03-28 09:05:44 WARN MPICommandServer::command_request_handler_service::AWProjectFT::finalizeToSky::MPIServer-3 time to massage data 0.12
28-Mar-2025 09:05:44	2025-03-28 09:05:44 WARN MPICommandServer::command_request_handler_service::AWProjectFT::finalizeToSky::MPIServer-3 time gridding 0.1
28-Mar-2025 09:05:44	2025-03-28 09:05:44 WARN MPICommandServer::command_request_handler_service::AWProjectFT::finalizeToSky::MPIServer-1 time to massage data 0.14
28-Mar-2025 09:05:44	2025-03-28 09:05:44 WARN MPICommandServer::command_request_handler_service::AWProjectFT::finalizeToSky::MPIServer-1 time gridding 0.09
28-Mar-2025 09:05:44	2025-03-28 09:05:44 WARN MPICommandServer::command_request_handler_service::AWProjectFT::finalizeToSky::MPIServer-2 time to massage data 0.14
28-Mar-2025 09:05:44	2025-03-28 09:05:44 WARN MPICommandServer::command_request_handler_service::AWProjectFT::finalizeToSky::MPIServer-2 time gridding 0.09
28-Mar-2025 09:05:44	2025-03-28 09:05:45 INFO MPICommandServer::command_request_handler_service::AWProjectFT2::getImage[R&D]::MPIServer-3 Sum of weights: Axis Lengths: [1, 1] (NB: Matrix in Row/Column order)
28-Mar-2025 09:05:44	2025-03-28 09:05:45 INFO MPICommandServer::command_request_handler_service::AWProjectFT2::getImage[R&D]::MPIServer-3+ [8234.25]
28-Mar-2025 09:05:44	2025-03-28 09:05:45 INFO MPICommandServer::command_request_handler_service::AWProjectFT2::getImage[R&D]::MPIServer-3+ (1.39154,-7.1218e-08) (0,0)
28-Mar-2025 09:05:44	2025-03-28 09:05:45 INFO MPICommandServer::command_request_handler_service::AWProjectFT2::getImage[R&D]::MPIServer-1 Sum of weights: Axis Lengths: [1, 1] (NB: Matrix in Row/Column order)
28-Mar-2025 09:05:44	2025-03-28 09:05:45 INFO MPICommandServer::command_request_handler_service::AWProjectFT2::getImage[R&D]::MPIServer-1+ [8258.9]
28-Mar-2025 09:05:44	2025-03-28 09:05:45 INFO MPICommandServer::command_request_handler_service::AWProjectFT2::getImage[R&D]::MPIServer-1+ (1.39034,-2.92298e-08) (0,0)
28-Mar-2025 09:05:53	2025-03-28 09:05:45 INFO MPICommandServer::command_request_handler_service::AWProjectFT2::getImage[R&D]::MPIServer-2 Sum of weights: Axis Lengths: [1, 1] (NB: Matrix in Row/Column order)
28-Mar-2025 09:05:53	2025-03-28 09:05:45 INFO MPICommandServer::command_request_handler_service::AWProjectFT2::getImage[R&D]::MPIServer-2+ [8474.84]
28-Mar-2025 09:05:53	2025-03-28 09:05:45 INFO MPICommandServer::command_request_handler_service::AWProjectFT2::getImage[R&D]::MPIServer-2+ (0.992538,2.75834e-08) (0,0)
28-Mar-2025 09:05:53	2025-03-28 09:05:46 INFO tclean::::casa ...done
28-Mar-2025 09:05:53	2025-03-28 09:05:46 INFO SynthesisNormalizer::gatherImages Gather psf,weight images : [/home/casatest/work/test_task_tclean/tst.awp.workdirectory/tst.awp.n1, /home/casatest/work/test_task_tclean/tst.awp.workdirectory/tst.awp.n2, /home/casatest/work/test_task_tclean/tst.awp.workdirectory/tst.awp.n3] onto :tst.awp
28-Mar-2025 09:05:53	2025-03-28 09:05:47 INFO SIImageStore::calcSensitivity [tst.awp] Theoretical sensitivity (Jy/bm):0.00632861
28-Mar-2025 09:05:53	2025-03-28 09:05:47 INFO SIImageStore::getPSFGaussian Time to fit Gaussian to PSF 0.039398
28-Mar-2025 09:05:53	2025-03-28 09:05:47 INFO SIImageStore::printBeamSet Beam : 85.3879 arcsec, 71.2449 arcsec, -89.0476 deg
28-Mar-2025 09:05:53	2025-03-28 09:05:47 INFO tclean::::casa checkJobs. Blocking for nodes to finish
28-Mar-2025 09:05:53	2025-03-28 09:05:48 INFO tclean::::casa ...done
28-Mar-2025 09:05:53	2025-03-28 09:05:49 INFO SynthesisNormalizer::scatterModel Send the model from : tst.awp to all nodes :[/home/casatest/work/test_task_tclean/tst.awp.workdirectory/tst.awp.n1, /home/casatest/work/test_task_tclean/tst.awp.workdirectory/tst.awp.n2, /home/casatest/work/test_task_tclean/tst.awp.workdirectory/tst.awp.n3]
28-Mar-2025 09:05:53	2025-03-28 09:05:49 INFO SIImageStore::setModelImageOne Copying input model tst.awp.model to /home/casatest/work/test_task_tclean/tst.awp.workdirectory/tst.awp.n1.model
28-Mar-2025 09:05:53	2025-03-28 09:05:49 INFO SIImageStore::setModelImageOne Copying input model tst.awp.model to /home/casatest/work/test_task_tclean/tst.awp.workdirectory/tst.awp.n2.model
28-Mar-2025 09:05:53	2025-03-28 09:05:49 INFO SIImageStore::setModelImageOne Copying input model tst.awp.model to /home/casatest/work/test_task_tclean/tst.awp.workdirectory/tst.awp.n3.model
28-Mar-2025 09:05:53	2025-03-28 09:05:49 INFO tclean::::casa ----------------------------- Running Parallel Major Cycle ----------------------------
28-Mar-2025 09:05:53	2025-03-28 09:05:49 INFO tclean::::casa checkJobs. Blocking for nodes to finish
28-Mar-2025 09:05:53	2025-03-28 09:05:49 INFO MPICommandServer::command_request_handler_service::SynthesisImager::executeMajorCycle::MPIServer-1 ----------------------------------------------------------- Run Major Cycle 1 -------------------------------------
28-Mar-2025 09:05:53	2025-03-28 09:05:49 INFO MPICommandServer::command_request_handler_service::SynthesisImager::executeMajorCycle::MPIServer-3 ----------------------------------------------------------- Run Major Cycle 1 -------------------------------------
28-Mar-2025 09:05:53	2025-03-28 09:05:49 INFO MPICommandServer::command_request_handler_service::SynthesisImager::executeMajorCycle::MPIServer-2 ----------------------------------------------------------- Run Major Cycle 1 -------------------------------------
28-Mar-2025 09:05:53	2025-03-28 09:05:49 INFO MPICommandServer::command_request_handler_service::AWProjectFT2::init[R&D]::MPIServer-1 Using CPUResampler visibility resampler (a.k.a. "gridder/degridder")
28-Mar-2025 09:05:53	2025-03-28 09:05:49 INFO MPICommandServer::command_request_handler_service::AWProjectFT2::initializeToSky[R&D]::MPIServer-1 Computed maps using FTMachine::initMaps. polMap = [0, 0]
28-Mar-2025 09:05:53	2025-03-28 09:05:49 INFO MPICommandServer::command_request_handler_service::AWProjectFT2::init[R&D]::MPIServer-3 Using CPUResampler visibility resampler (a.k.a. "gridder/degridder")
28-Mar-2025 09:05:53	2025-03-28 09:05:49 INFO MPICommandServer::command_request_handler_service::AWProjectFT2::initializeToSky[R&D]::MPIServer-3 Computed maps using FTMachine::initMaps. polMap = [0, 0]
28-Mar-2025 09:05:53	2025-03-28 09:05:49 INFO MPICommandServer::command_request_handler_service::AWProjectFT2::init[R&D]::MPIServer-2 Using CPUResampler visibility resampler (a.k.a. "gridder/degridder")
28-Mar-2025 09:05:53	2025-03-28 09:05:49 INFO MPICommandServer::command_request_handler_service::AWProjectFT2::initializeToSky[R&D]::MPIServer-2 Computed maps using FTMachine::initMaps. polMap = [0, 0]
28-Mar-2025 09:05:53	2025-03-28 09:05:50 WARN MPICommandServer::command_request_handler_service::AWProjectFT::finalizeToSky::MPIServer-1 time to massage data 0.04
28-Mar-2025 09:05:53	2025-03-28 09:05:50 WARN MPICommandServer::command_request_handler_service::AWProjectFT::finalizeToSky::MPIServer-1 time gridding 0.1
28-Mar-2025 09:05:53	2025-03-28 09:05:50 WARN MPICommandServer::command_request_handler_service::AWProjectFT::finalizeToSky::MPIServer-3 time to massage data 0.05
28-Mar-2025 09:05:53	2025-03-28 09:05:50 WARN MPICommandServer::command_request_handler_service::AWProjectFT::finalizeToSky::MPIServer-3 time gridding 0.07
28-Mar-2025 09:05:53	2025-03-28 09:05:50 WARN MPICommandServer::command_request_handler_service::AWProjectFT::finalizeToSky::MPIServer-2 time to massage data 0.07
28-Mar-2025 09:05:53	2025-03-28 09:05:50 WARN MPICommandServer::command_request_handler_service::AWProjectFT::finalizeToSky::MPIServer-2 time gridding 0.04
28-Mar-2025 09:05:53	2025-03-28 09:05:50 INFO MPICommandServer::command_request_handler_service::AWProjectFT2::getImage[R&D]::MPIServer-1 Sum of weights: Axis Lengths: [1, 1] (NB: Matrix in Row/Column order)
28-Mar-2025 09:05:53	2025-03-28 09:05:50 INFO MPICommandServer::command_request_handler_service::AWProjectFT2::getImage[R&D]::MPIServer-1+ [8259.7]
28-Mar-2025 09:05:53	2025-03-28 09:05:50 INFO MPICommandServer::command_request_handler_service::AWProjectFT2::getImage[R&D]::MPIServer-1+ (-1.08331,0.295812) (0,0)
28-Mar-2025 09:05:53	2025-03-28 09:05:50 INFO MPICommandServer::command_request_handler_service::AWProjectFT2::getImage[R&D]::MPIServer-3 Sum of weights: Axis Lengths: [1, 1] (NB: Matrix in Row/Column order)
28-Mar-2025 09:05:53	2025-03-28 09:05:50 INFO MPICommandServer::command_request_handler_service::AWProjectFT2::getImage[R&D]::MPIServer-3+ [8235.06]
28-Mar-2025 09:05:53	2025-03-28 09:05:50 INFO MPICommandServer::command_request_handler_service::AWProjectFT2::getImage[R&D]::MPIServer-3+ (-0.996398,0.392974) (0,0)
28-Mar-2025 09:05:53	2025-03-28 09:05:50 INFO MPICommandServer::command_request_handler_service::AWProjectFT2::getImage[R&D]::MPIServer-2 Sum of weights: Axis Lengths: [1, 1] (NB: Matrix in Row/Column order)
28-Mar-2025 09:05:53	2025-03-28 09:05:50 INFO MPICommandServer::command_request_handler_service::AWProjectFT2::getImage[R&D]::MPIServer-2+ [8475.52]
28-Mar-2025 09:05:53	2025-03-28 09:05:50 INFO MPICommandServer::command_request_handler_service::AWProjectFT2::getImage[R&D]::MPIServer-2+ (-0.4708,-1.04899) (0,0)
28-Mar-2025 09:05:53	2025-03-28 09:05:53 INFO tclean::::casa ...done
28-Mar-2025 09:05:53	2025-03-28 09:05:53 INFO SynthesisNormalizer::gatherImages Gather residual images : [/home/casatest/work/test_task_tclean/tst.awp.workdirectory/tst.awp.n1, /home/casatest/work/test_task_tclean/tst.awp.workdirectory/tst.awp.n2, /home/casatest/work/test_task_tclean/tst.awp.workdirectory/tst.awp.n3] onto :tst.awp
28-Mar-2025 09:05:53	2025-03-28 09:05:53 WARN SIImageStore::Open existing Images (file /source/casa6/casatools/src/code/synthesis/ImagerObjects/SIImageStore.cc, line 618) Mismatch in Csys latpoles between existing image on disk ([299.869, 40.7226, 180, 40.7226]) and current imaging run ([299.869, 40.7226, 180, 40.7226]) : The DirectionCoordinates have differing latpoles -- Resetting to match image on disk
28-Mar-2025 09:05:53	2025-03-28 09:05:54 WARN SIImageStore::Open existing Images (file /source/casa6/casatools/src/code/synthesis/ImagerObjects/SIImageStore.cc, line 618) Mismatch in Csys latpoles between existing image on disk ([299.869, 40.7226, 180, 40.7226]) and current imaging run ([299.869, 40.7226, 180, 40.7226]) : The DirectionCoordinates have differing latpoles -- Resetting to match image on disk
28-Mar-2025 09:05:53	2025-03-28 09:05:54 INFO task_tclean::SDAlgorithmBase::restore [tst.awp] : Restoring model image.
28-Mar-2025 09:05:53	2025-03-28 09:05:54 WARN task_tclean::SIImageStore::restore (file /source/casa6/casatools/src/code/synthesis/ImagerObjects/SIImageStore.cc, line 2345) Restoring with an empty model image. Only residuals will be processed to form the output restored image.
28-Mar-2025 09:06:10	2025-03-28 09:05:54 WARN task_tclean::SIImageStore::Open existing Images (file /source/casa6/casatools/src/code/synthesis/ImagerObjects/SIImageStore.cc, line 618) Mismatch in Csys latpoles between existing image on disk ([299.869, 40.7226, 180, 40.7226]) and current imaging run ([299.869, 40.7226, 180, 40.7226]) : The DirectionCoordinates have differing latpoles -- Resetting to match image on disk
28-Mar-2025 09:06:10	2025-03-28 09:05:54 INFO task_tclean::SIImageStore::restore Beam for chan : 0 : 85.3879 arcsec, 71.2449 arcsec, -89.0476 deg
28-Mar-2025 09:06:10	2025-03-28 09:05:54 INFO MPICommandServer::command_request_handler_service::VB2CFBMap::~VB2CFMap[R&D]::MPIServer-2 Total extra cost of heterogeneous array pointing correction = 0.08sec. Total VBs processed = 15562. The pointingoffsetsigdev used was = []
28-Mar-2025 09:06:10	2025-03-28 09:05:54 INFO MPICommandServer::command_request_handler_service::VB2CFBMap::~VB2CFMap[R&D]::MPIServer-3 Total extra cost of heterogeneous array pointing correction = 0.03sec. Total VBs processed = 15317. The pointingoffsetsigdev used was = []
28-Mar-2025 09:06:10	2025-03-28 09:05:54 INFO MPICommandServer::command_request_handler_service::VB2CFBMap::~VB2CFMap[R&D]::MPIServer-1 Total extra cost of heterogeneous array pointing correction = 0.03sec. Total VBs processed = 15798. The pointingoffsetsigdev used was = []
28-Mar-2025 09:06:10	2025-03-28 09:06:04 INFO tclean::::casa checkJobs. Blocking for nodes to finish
28-Mar-2025 09:06:10	2025-03-28 09:06:04 INFO ::casa::MPIServer-2 node 2 has completed its job
28-Mar-2025 09:06:10	2025-03-28 09:06:04 INFO ::casa::MPIServer-3 node 3 has completed its job
28-Mar-2025 09:06:10	2025-03-28 09:06:04 INFO ::casa::MPIServer-1 node 1 has completed its job
28-Mar-2025 09:06:10	2025-03-28 09:06:05 INFO tclean::::casa ...done
28-Mar-2025 09:06:10	2025-03-28 09:06:05 INFO tclean::::casa Ending use of cluster, but not closing it. Call clustermanager.stop_cluster() to close it if needed.
28-Mar-2025 09:06:10	2025-03-28 09:06:05 INFO tclean::::casa Searching for images with prefix 'tst.awp'... Found these, writing history into them: ['tst.awp.psf', 'tst.awp.weight', 'tst.awp.residual', 'tst.awp.gridwt_temp', 'tst.awp.pb', 'tst.awp.image', 'tst.awp.sumwt', 'tst.awp.model']
28-Mar-2025 09:06:10	2025-03-28 09:06:05 INFO tclean::::casa Task tclean complete. Start time: 2025-03-28 09:02:43.182910 End time: 2025-03-28 09:06:05.102930
28-Mar-2025 09:06:10	2025-03-28 09:06:05 INFO tclean::::casa ##### End Task: tclean #####
28-Mar-2025 09:06:10	2025-03-28 09:06:05 INFO tclean::::casa ##########################################
28-Mar-2025 09:06:10	2025-03-28 09:06:05 INFO name:: No table opened.
28-Mar-2025 09:06:10	2025-03-28 09:06:05 INFO showcache:: The Table Cache is empty.
28-Mar-2025 09:06:10	2025-03-28 09:06:05 INFO tclean::::casa [ checkall ]
28-Mar-2025 09:06:10	2025-03-28 09:06:05 INFO tclean::::casa+ [ check_ims ] Image made : ['tst.awp.image'] = [True] ( Pass : should all be True )
28-Mar-2025 09:06:10	2025-03-28 09:06:05 INFO tclean::::casa+ All expected keywords in imageinfo, miscinfo, and coords found. (check_keywords)
28-Mar-2025 09:06:10	2025-03-28 09:06:05 INFO tclean::::casa+ [check_history] All expected history entries found. (Pass)
28-Mar-2025 09:06:10	2025-03-28 09:06:05 INFO tclean::::casa+ [ check_pix_val ] tst.awp.psf : Value is 1.0 at [1024, 1024, 0, 0] ( Pass : should be 1.0 , Epsilon: 0.05)
28-Mar-2025 09:06:10	2025-03-28 09:06:05 INFO tclean::::casa+ [ check_pix_val ] tst.awp.image : Value is 0.9958506226539612 at [1158, 1384, 0, 0] ( Pass : should be 1.0 , Epsilon: 0.05)
28-Mar-2025 09:06:10	.s2025-03-28 09:06:06 INFO MPICommandServer::serve::MPICommandServer::serve::casa::MPIServer-3 Control signal MPIEnvironment.command_handling_log_level = 'DEBUG' successfully handled by server 3
28-Mar-2025 09:06:10	2025-03-28 09:06:06 INFO MPICommandServer::serve::MPICommandServer::serve::casa::MPIServer-1 Control signal MPIEnvironment.command_handling_log_level = 'DEBUG' successfully handled by server 1
28-Mar-2025 09:06:10	2025-03-28 09:06:06 INFO MPICommandServer::serve::MPICommandServer::serve::casa::MPIServer-2 Control signal MPIEnvironment.command_handling_log_level = 'DEBUG' successfully handled by server 2
28-Mar-2025 09:06:10	2025-03-28 09:06:07 INFO tclean::::casa setupCluster, Setting up 3 engines.
28-Mar-2025 09:06:10	2025-03-28 09:06:07 INFO tclean::::casa ##########################################
28-Mar-2025 09:06:10	2025-03-28 09:06:07 INFO tclean::::casa ##### Begin Task: tclean #####
28-Mar-2025 09:06:10	2025-03-28 09:06:07 INFO tclean::::casa tclean( vis='vla_wideband_2ptg_w_squint.ms', selectdata=True, field='1', spw='', timerange='', uvrange='', antenna='', scan='', observation='', intent='', datacolumn='corrected', imagename='tst.awp2', imsize=1200, cell='1.6arcsec', phasecenter='', stokes='IV', projection='SIN', startmodel='', specmode='mfs', reffreq='', nchan=-1, start='', width='', outframe='LSRK', veltype='radio', restfreq=[], interpolation='linear', perchanweightdensity=True, gridder='awp2', facets=1, psfphasecenter='', wprojplanes=2, vptable='', mosweight=True, aterm=True, psterm=False, wbawp=True, conjbeams=False, cfcache='', usepointing=False, computepastep=15.0, rotatepastep=360.0, pointingoffsetsigdev=[], pblimit=-0.1, normtype='flatnoise', deconvolver='hogbom', scales=[], nterms=2, smallscalebias=0.0, fusedthreshold=0.0, largestscale=-1, restoration=True, restoringbeam=[], pbcor=True, outlierfile='', weighting='uniform', robust=0.5, noise='1.0Jy', npixels=0, uvtaper=[''], niter=20, gain=0.1, threshold=0.0, nsigma=0.0, cycleniter=-1, cyclefactor=1.0, minpsffraction=0.05, maxpsffraction=0.8, interactive=False, nmajor=-1, fullsummary=False, usemask='user', mask='', pbmask=0.0, sidelobethreshold=3.0, noisethreshold=5.0, lownoisethreshold=1.5, negativethreshold=0.0, smoothfactor=1.0, minbeamfrac=0.3, cutthreshold=0.01, growiterations=75, dogrowprune=True, minpercentchange=-1.0, verbose=False, fastnoise=True, restart=True, savemodel='none', calcres=True, calcpsf=True, psfcutoff=0.35, parallel=True )
28-Mar-2025 09:06:10	2025-03-28 09:06:07 INFO tclean::::casa Verifying Input Parameters
28-Mar-2025 09:06:10	2025-03-28 09:06:09 INFO MPICommandServer::serve::MPICommandServer::serve::casa::MPIServer-3 Control signal MPIEnvironment.command_handling_log_level = 'DEBUG' successfully handled by server 3
28-Mar-2025 09:06:10	2025-03-28 09:06:09 INFO MPICommandServer::serve::MPICommandServer::serve::casa::MPIServer-1 Control signal MPIEnvironment.command_handling_log_level = 'DEBUG' successfully handled by server 1
28-Mar-2025 09:06:10	2025-03-28 09:06:09 INFO MPICommandServer::serve::MPICommandServer::serve::casa::MPIServer-2 Control signal MPIEnvironment.command_handling_log_level = 'DEBUG' successfully handled by server 2
28-Mar-2025 09:06:10	2025-03-28 09:06:10 INFO tclean::::casa setupCluster, Setting up 3 engines.
28-Mar-2025 09:06:10	2025-03-28 09:06:10 INFO SynthesisUtilMethods::continuumDataPartition
28-Mar-2025 09:06:10	2025-03-28 09:06:10 INFO SynthesisUtilMethods::continuumDataPartition + Rows = 4683 7020 [P][M]: 0:2 ROWNUMBER() >= 4683 && ROWNUMBER() <= 7020
28-Mar-2025 09:06:10	2025-03-28 09:06:10 INFO tclean::::casa Partitioned Selection : {'0': {'ms0': {'antenna': '', 'datacolumn': 'corrected', 'field': '1', 'freqbeg': '', 'freqend': '', 'freqframe': 'LSRK', 'incrmodel': False, 'msname': 'vla_wideband_2ptg_w_squint.ms', 'obs': '', 'outframe': 'LSRK', 'readonly': True, 'scan': '', 'spw': '', 'state': '', 'taql': 'ROWNUMBER() >= 1 && ROWNUMBER() <= 2341', 'timestr': '', 'usescratch': False, 'uvdist': ''}}, '1': {'ms0': {'antenna': '', 'datacolumn': 'corrected', 'field': '1', 'freqbeg': '', 'freqend': '', 'freqframe': 'LSRK', 'incrmodel': False, 'msname': 'vla_wideband_2ptg_w_squint.ms', 'obs': '', 'outframe': 'LSRK', 'readonly': True, 'scan': '', 'spw': '', 'state': '', 'taql': 'ROWNUMBER() >= 2342 && ROWNUMBER() <= 4682', 'timestr': '', 'usescratch': False, 'uvdist': ''}}, '2': {'ms0': {'antenna': '', 'datacolumn': 'corrected', 'field': '1', 'freqbeg': '', 'freqend': '', 'freqframe': 'LSRK', 'incrmodel': False, 'msname': 'vla_wideband_2ptg_w_squint.ms', 'obs': '', 'outframe': 'LSRK', 'readonly': True, 'scan': '', 'spw': '', 'state': '', 'taql': 'ROWNUMBER() >= 4683 && ROWNUMBER() <= 7020', 'timestr': '', 'usescratch': False, 'uvdist': ''}}}
28-Mar-2025 09:06:10	2025-03-28 09:06:10 INFO SynthesisImagerVi2::selectData MS : vla_wideband_2ptg_w_squint.ms \| Selecting on fields : 1 \| [Opened in readonly mode]
28-Mar-2025 09:06:10	2025-03-28 09:06:10 INFO SynthesisImagerVi2::selectData NRows selected : 7020
28-Mar-2025 09:06:10	2025-03-28 09:06:10 INFO SynthesisImagerVi2::defineImage Define image coordinates for [tst.awp2] :
28-Mar-2025 09:06:10	2025-03-28 09:06:10 INFO SynthesisImagerVi2::defineImage Define image coordinates for [tst.awp2] :
28-Mar-2025 09:06:10	2025-03-28 09:06:10 INFO SynthesisImagerVi2::defineImage Impars: start
28-Mar-2025 09:06:18	2025-03-28 09:06:10 INFO SynthesisImagerVi2::defineImage Shape: [1200, 1200, 2, 1] Spectral: [1.48111e+09] at [0] with increment [5.99947e+08]
28-Mar-2025 09:06:18	2025-03-28 09:06:10 INFO SynthesisImagerVi2::defineImage Set Gridding options for [tst.awp2] with ftmachine : awp2
28-Mar-2025 09:06:18	2025-03-28 09:06:10 INFO SynthesisImager::getVPRecord Using default Voltage Patterns from the VPManager
28-Mar-2025 09:06:18	2025-03-28 09:06:10 INFO SynthesisImagerVi2::nSubCubeFitInMemory Required memory: 1.36 GB. Available mem.: 387.1 GB (rc, mem. fraction: 80%, memory: -) => Subcubes: 1. Processes on node: 4.
28-Mar-2025 09:06:18	2025-03-28 09:06:10 INFO SynthesisImagerVi2::weight() Set imaging weights : Uniform weighting: sidelobes will be suppressed over full image
28-Mar-2025 09:06:18	2025-03-28 09:06:10 INFO tclean::::casa checkJobs. Blocking for nodes to finish
28-Mar-2025 09:06:18	2025-03-28 09:06:11 INFO tclean::::casa ...done
28-Mar-2025 09:06:18	2025-03-28 09:06:11 INFO tclean::::casa checkJobs. Blocking for nodes to finish
28-Mar-2025 09:06:18	2025-03-28 09:06:11 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::selectData::MPIServer-2 MS : vla_wideband_2ptg_w_squint.ms \| Selecting on fields : 1 \| [Opened in readonly mode]
28-Mar-2025 09:06:18	2025-03-28 09:06:11 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::selectData::MPIServer-2 Selecting via TaQL : ROWNUMBER() >= 2342 && ROWNUMBER() <= 4682 \| NRows selected : 2341
28-Mar-2025 09:06:18	2025-03-28 09:06:11 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::selectData::MPIServer-3 MS : vla_wideband_2ptg_w_squint.ms \| Selecting on fields : 1 \| [Opened in readonly mode]
28-Mar-2025 09:06:18	2025-03-28 09:06:11 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::selectData::MPIServer-3 Selecting via TaQL : ROWNUMBER() >= 4683 && ROWNUMBER() <= 7020 \| NRows selected : 2338
28-Mar-2025 09:06:18	2025-03-28 09:06:11 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::selectData::MPIServer-1 MS : vla_wideband_2ptg_w_squint.ms \| Selecting on fields : 1 \| [Opened in readonly mode]
28-Mar-2025 09:06:18	2025-03-28 09:06:11 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::selectData::MPIServer-1 Selecting via TaQL : ROWNUMBER() >= 1 && ROWNUMBER() <= 2341 \| NRows selected : 2341
28-Mar-2025 09:06:18	2025-03-28 09:06:12 INFO tclean::::casa ...done
28-Mar-2025 09:06:18	2025-03-28 09:06:13 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::defineImage::MPIServer-1 Define image coordinates for [/home/casatest/work/test_task_tclean/tst.awp2.workdirectory/tst.awp2.n1] :
28-Mar-2025 09:06:18	2025-03-28 09:06:13 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::defineImage::MPIServer-1 Define image coordinates for [/home/casatest/work/test_task_tclean/tst.awp2.workdirectory/tst.awp2.n1] :
28-Mar-2025 09:06:18	2025-03-28 09:06:13 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::defineImage::MPIServer-1 Impars: start
28-Mar-2025 09:06:18	2025-03-28 09:06:13 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::defineImage::MPIServer-1 Shape: [1200, 1200, 2, 1] Spectral: [1.48111e+09] at [0] with increment [5.99947e+08]
28-Mar-2025 09:06:18	2025-03-28 09:06:13 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::defineImage::MPIServer-1 Set Gridding options for [/home/casatest/work/test_task_tclean/tst.awp2.workdirectory/tst.awp2.n1] with ftmachine : awp2
28-Mar-2025 09:06:18	2025-03-28 09:06:13 INFO MPICommandServer::command_request_handler_service::SynthesisImager::getVPRecord::MPIServer-1 Using default Voltage Patterns from the VPManager
28-Mar-2025 09:06:18	2025-03-28 09:06:13 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::nSubCubeFitInMemory::MPIServer-1 Required memory: 1.36 GB. Available mem.: 387.1 GB (rc, mem. fraction: 80%, memory: -) => Subcubes: 1. Processes on node: 4.
28-Mar-2025 09:06:18	2025-03-28 09:06:13 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::defineImage::MPIServer-2 Define image coordinates for [/home/casatest/work/test_task_tclean/tst.awp2.workdirectory/tst.awp2.n2] :
28-Mar-2025 09:06:18	2025-03-28 09:06:13 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::defineImage::MPIServer-2 Define image coordinates for [/home/casatest/work/test_task_tclean/tst.awp2.workdirectory/tst.awp2.n2] :
28-Mar-2025 09:06:18	2025-03-28 09:06:13 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::defineImage::MPIServer-2 Impars: start
28-Mar-2025 09:06:18	2025-03-28 09:06:13 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::defineImage::MPIServer-2 Shape: [1200, 1200, 2, 1] Spectral: [1.48111e+09] at [0] with increment [5.99947e+08]
28-Mar-2025 09:06:18	2025-03-28 09:06:13 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::defineImage::MPIServer-2 Set Gridding options for [/home/casatest/work/test_task_tclean/tst.awp2.workdirectory/tst.awp2.n2] with ftmachine : awp2
28-Mar-2025 09:06:18	2025-03-28 09:06:13 INFO MPICommandServer::command_request_handler_service::SynthesisImager::getVPRecord::MPIServer-2 Using default Voltage Patterns from the VPManager
28-Mar-2025 09:06:18	2025-03-28 09:06:13 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::nSubCubeFitInMemory::MPIServer-2 Required memory: 1.36 GB. Available mem.: 387.1 GB (rc, mem. fraction: 80%, memory: -) => Subcubes: 1. Processes on node: 4.
28-Mar-2025 09:06:18	2025-03-28 09:06:14 INFO tclean::::casa checkJobs. Blocking for nodes to finish
28-Mar-2025 09:06:18	2025-03-28 09:06:14 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::defineImage::MPIServer-3 Define image coordinates for [/home/casatest/work/test_task_tclean/tst.awp2.workdirectory/tst.awp2.n3] :
28-Mar-2025 09:06:18	2025-03-28 09:06:14 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::defineImage::MPIServer-3 Define image coordinates for [/home/casatest/work/test_task_tclean/tst.awp2.workdirectory/tst.awp2.n3] :
28-Mar-2025 09:06:18	2025-03-28 09:06:14 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::defineImage::MPIServer-3 Impars: start
28-Mar-2025 09:06:18	2025-03-28 09:06:14 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::defineImage::MPIServer-3 Shape: [1200, 1200, 2, 1] Spectral: [1.48111e+09] at [0] with increment [5.99947e+08]
28-Mar-2025 09:06:18	2025-03-28 09:06:14 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::defineImage::MPIServer-3 Set Gridding options for [/home/casatest/work/test_task_tclean/tst.awp2.workdirectory/tst.awp2.n3] with ftmachine : awp2
28-Mar-2025 09:06:18	2025-03-28 09:06:14 INFO MPICommandServer::command_request_handler_service::SynthesisImager::getVPRecord::MPIServer-3 Using default Voltage Patterns from the VPManager
28-Mar-2025 09:06:18	2025-03-28 09:06:14 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::nSubCubeFitInMemory::MPIServer-3 Required memory: 1.36 GB. Available mem.: 387.1 GB (rc, mem. fraction: 80%, memory: -) => Subcubes: 1. Processes on node: 4.
28-Mar-2025 09:06:18	2025-03-28 09:06:15 INFO tclean::::casa ...done
28-Mar-2025 09:06:18	2025-03-28 09:06:17 INFO SynthesisImagerVi2::selectData MS : vla_wideband_2ptg_w_squint.ms \| Selecting on fields : 1 \| [Opened in readonly mode]
28-Mar-2025 09:06:18	2025-03-28 09:06:17 INFO SynthesisImagerVi2::selectData NRows selected : 7020
28-Mar-2025 09:06:18	2025-03-28 09:06:17 INFO SynthesisImagerVi2::defineImage Define image coordinates for [tst.awp2] :
28-Mar-2025 09:06:18	2025-03-28 09:06:17 INFO SynthesisImagerVi2::defineImage Define image coordinates for [tst.awp2] :
28-Mar-2025 09:06:18	2025-03-28 09:06:17 INFO SynthesisImagerVi2::defineImage Impars: start
28-Mar-2025 09:06:18	2025-03-28 09:06:17 INFO SynthesisImagerVi2::defineImage Shape: [1200, 1200, 2, 1] Spectral: [1.48111e+09] at [0] with increment [5.99947e+08]
28-Mar-2025 09:06:18	2025-03-28 09:06:17 INFO SynthesisImagerVi2::defineImage Set Gridding options for [tst.awp2] with ftmachine : awp2
28-Mar-2025 09:06:18	2025-03-28 09:06:17 INFO SynthesisImager::getVPRecord Using default Voltage Patterns from the VPManager
28-Mar-2025 09:06:18	2025-03-28 09:06:17 INFO SynthesisImagerVi2::nSubCubeFitInMemory Required memory: 1.36 GB. Available mem.: 387.1 GB (rc, mem. fraction: 80%, memory: -) => Subcubes: 1. Processes on node: 4.
28-Mar-2025 09:06:18	2025-03-28 09:06:17 INFO SynthesisImagerVi2::weight() Set imaging weights : Uniform weighting: sidelobes will be suppressed over full image
28-Mar-2025 09:06:18	2025-03-28 09:06:17 INFO tclean::::casa checkJobs. Blocking for nodes to finish
28-Mar-2025 09:06:18	2025-03-28 09:06:18 INFO tclean::::casa ...done
28-Mar-2025 09:08:49	2025-03-28 09:06:18 INFO task_tclean::SynthesisDeconvolver::setupDeconvolution Set Deconvolution Options for [tst.awp2] : hogbom
28-Mar-2025 09:08:49	2025-03-28 09:06:18 INFO tclean::::casa checkJobs. Blocking for nodes to finish
28-Mar-2025 09:08:49	2025-03-28 09:06:19 INFO tclean::::casa ...done
28-Mar-2025 09:08:49	2025-03-28 09:06:19 INFO tclean::::casa checkJobs. Blocking for nodes to finish
28-Mar-2025 09:08:49	2025-03-28 09:06:19 INFO MPICommandServer::command_request_handler_service::SynthesisImager::makePSF::MPIServer-2 ----------------------------------------------------------- Make PSF ---------------------------------------------
28-Mar-2025 09:08:49	2025-03-28 09:06:19 INFO MPICommandServer::command_request_handler_service::SynthesisImager::makePSF::MPIServer-3 ----------------------------------------------------------- Make PSF ---------------------------------------------
28-Mar-2025 09:08:49	2025-03-28 09:06:19 INFO MPICommandServer::command_request_handler_service::SynthesisImager::makePSF::MPIServer-1 ----------------------------------------------------------- Make PSF ---------------------------------------------
28-Mar-2025 09:08:49	paMax 3.13298 painc 0.261799
28-Mar-2025 09:08:49	paMax 1.89109 painc 0.261799
28-Mar-2025 09:08:49	paMax 1.69476 painc 0.261799
28-Mar-2025 09:08:49
28-Mar-2025 09:08:49	0%....10....20....30....40....50....60....70....80....90....100%
28-Mar-2025 09:08:49
28-Mar-2025 09:08:49	0%....10....20....30....40....50....60....70....80....90....100%
28-Mar-2025 09:08:49
28-Mar-2025 09:08:49	0%....10....20....30....40....50....60....70....80....90....100%
28-Mar-2025 09:08:49	2025-03-28 09:08:14 INFO tclean::::casa ...done
28-Mar-2025 09:08:49	2025-03-28 09:08:14 INFO SynthesisNormalizer::gatherImages Gather psf,weight images : [/home/casatest/work/test_task_tclean/tst.awp2.workdirectory/tst.awp2.n1, /home/casatest/work/test_task_tclean/tst.awp2.workdirectory/tst.awp2.n2, /home/casatest/work/test_task_tclean/tst.awp2.workdirectory/tst.awp2.n3] onto :tst.awp2
28-Mar-2025 09:08:49	2025-03-28 09:08:15 INFO SIImageStore::calcSensitivity [tst.awp2] Theoretical sensitivity (Jy/bm):p0:0.00400186 p1:0.00400186
28-Mar-2025 09:08:49	2025-03-28 09:08:15 INFO SIImageStore::getPSFGaussian Time to fit Gaussian to PSF 0.024728
28-Mar-2025 09:08:49	2025-03-28 09:08:15 INFO SIImageStore::printBeamSet Restoring Beams
28-Mar-2025 09:08:49	2025-03-28 09:08:15 INFO SIImageStore::printBeamSet + Chan Freq Vel Pol
28-Mar-2025 09:08:49	2025-03-28 09:08:15 INFO SIImageStore::printBeamSet + 0 1.5e+09 -70230 I 5.3459 arcsec x 4.3663 arcsec pa=-84.5374 deg
28-Mar-2025 09:08:49	2025-03-28 09:08:15 INFO SIImageStore::printBeamSet + 0 1.5e+09 -70230 V 5.3459 arcsec x 4.3663 arcsec pa=-84.5374 deg
28-Mar-2025 09:08:49	2025-03-28 09:08:15 INFO tclean::::casa checkJobs. Blocking for nodes to finish
28-Mar-2025 09:08:49	2025-03-28 09:08:16 INFO tclean::::casa ...done
28-Mar-2025 09:08:49	2025-03-28 09:08:16 INFO SynthesisNormalizer::scatterModel Send the model from : tst.awp2 to all nodes :[/home/casatest/work/test_task_tclean/tst.awp2.workdirectory/tst.awp2.n1, /home/casatest/work/test_task_tclean/tst.awp2.workdirectory/tst.awp2.n2, /home/casatest/work/test_task_tclean/tst.awp2.workdirectory/tst.awp2.n3]
28-Mar-2025 09:08:49	2025-03-28 09:08:16 INFO SIImageStore::setModelImageOne Copying input model tst.awp2.model to /home/casatest/work/test_task_tclean/tst.awp2.workdirectory/tst.awp2.n1.model
28-Mar-2025 09:08:49	2025-03-28 09:08:16 INFO SIImageStore::setModelImageOne Copying input model tst.awp2.model to /home/casatest/work/test_task_tclean/tst.awp2.workdirectory/tst.awp2.n2.model
28-Mar-2025 09:08:49	2025-03-28 09:08:16 INFO SIImageStore::setModelImageOne Copying input model tst.awp2.model to /home/casatest/work/test_task_tclean/tst.awp2.workdirectory/tst.awp2.n3.model
28-Mar-2025 09:08:49	2025-03-28 09:08:16 INFO tclean::::casa ----------------------------- Running Parallel Major Cycle ----------------------------
28-Mar-2025 09:08:49	2025-03-28 09:08:16 INFO tclean::::casa checkJobs. Blocking for nodes to finish
28-Mar-2025 09:08:49	2025-03-28 09:08:17 INFO MPICommandServer::command_request_handler_service::SynthesisImager::executeMajorCycle::MPIServer-2 ----------------------------------------------------------- Run Major Cycle 1 -------------------------------------
28-Mar-2025 09:08:49	2025-03-28 09:08:17 INFO MPICommandServer::command_request_handler_service::SynthesisImager::executeMajorCycle::MPIServer-3 ----------------------------------------------------------- Run Major Cycle 1 -------------------------------------
28-Mar-2025 09:08:49	2025-03-28 09:08:17 INFO MPICommandServer::command_request_handler_service::SynthesisImager::executeMajorCycle::MPIServer-1 ----------------------------------------------------------- Run Major Cycle 1 -------------------------------------
28-Mar-2025 09:08:49
28-Mar-2025 09:08:49	0%....10....20....30....40....50....60....70....80....90....100%
28-Mar-2025 09:08:49
28-Mar-2025 09:08:49	0%....10....20....30....40....50....60....70....80....90....100%
28-Mar-2025 09:08:49	2025-03-28 09:08:30 INFO tclean::::casa ...done
28-Mar-2025 09:08:49	2025-03-28 09:08:30 INFO SynthesisNormalizer::gatherImages Gather residual images : [/home/casatest/work/test_task_tclean/tst.awp2.workdirectory/tst.awp2.n1, /home/casatest/work/test_task_tclean/tst.awp2.workdirectory/tst.awp2.n2, /home/casatest/work/test_task_tclean/tst.awp2.workdirectory/tst.awp2.n3] onto :tst.awp2
28-Mar-2025 09:08:49	2025-03-28 09:08:31 INFO task_tclean::SynthesisDeconvolver::initMinorCycle Absolute Peak residual within mask : 0, over full image : 0.458242
28-Mar-2025 09:08:49	2025-03-28 09:08:31 INFO SynthesisDeconvolver::setupMask [tst.awp2] Initializing new mask to 1.0 for the full image
28-Mar-2025 09:08:49	2025-03-28 09:08:31 INFO SynthesisDeconvolver::setupMask [tst.awp2] Number of pixels in the clean mask : 2.88e+06 out of a total of 2.88e+06 pixels. [ 100 % ]
28-Mar-2025 09:08:49	2025-03-28 09:08:31 INFO SynthesisDeconvolver::initMinorCycle Absolute Peak residual within mask : 0.458242, over full image : 0.458242
28-Mar-2025 09:08:49	2025-03-28 09:08:31 INFO tclean::::casa Minor Cycle controls : {'cycleniter': 20, 'cyclethreshold': 0.02291209064424038, 'loopgain': 0.10000000149011612, 'nsigma': 0.0, 'thresholdreached': False}
28-Mar-2025 09:08:49	2025-03-28 09:08:31 INFO SDAlgorithmBase::deconvolve [tst.awp2] Run Hogbom minor-cycle on 2 pols \| CycleThreshold=0.0229121, CycleNiter=20, Gain=0.1
28-Mar-2025 09:08:49	2025-03-28 09:08:31 INFO SDAlgorithmBase::deconvolve [tst.awp2:P0] iters=0->20 [20], model=0->0.408101, peakres=0.458242->0.0501404, Reached cycleniter.
28-Mar-2025 09:08:49	2025-03-28 09:08:31 INFO SDAlgorithmBase::deconvolve [tst.awp2:P1] iters=20->20 [0], model=0->0, peakres=0.00489715->0.00489715, Reached cyclethreshold.
28-Mar-2025 09:08:49	2025-03-28 09:08:31 INFO SDAlgorithmBase::deconvolve [tst.awp2] Total model flux (over all planes) : 0.408101 Peak Residual (over all planes) : 0.0501404 in C0:P0
28-Mar-2025 09:08:49	2025-03-28 09:08:31 INFO grpcInteractiveCleanManager::mergeCycleExecutionRecord Completed 20 iterations.
28-Mar-2025 09:08:49	2025-03-28 09:08:31 INFO task_tclean::SynthesisNormalizer::scatterModel Send the model from : tst.awp2 to all nodes :[/home/casatest/work/test_task_tclean/tst.awp2.workdirectory/tst.awp2.n1, /home/casatest/work/test_task_tclean/tst.awp2.workdirectory/tst.awp2.n2, /home/casatest/work/test_task_tclean/tst.awp2.workdirectory/tst.awp2.n3]
28-Mar-2025 09:08:49	2025-03-28 09:08:31 INFO task_tclean::SIImageStore::setModelImageOne Copying input model tst.awp2.model to /home/casatest/work/test_task_tclean/tst.awp2.workdirectory/tst.awp2.n1.model
28-Mar-2025 09:08:49	2025-03-28 09:08:31 INFO task_tclean::SIImageStore::setModelImageOne Copying input model tst.awp2.model to /home/casatest/work/test_task_tclean/tst.awp2.workdirectory/tst.awp2.n2.model
28-Mar-2025 09:08:49	2025-03-28 09:08:31 INFO task_tclean::SIImageStore::setModelImageOne Copying input model tst.awp2.model to /home/casatest/work/test_task_tclean/tst.awp2.workdirectory/tst.awp2.n3.model
28-Mar-2025 09:08:49	2025-03-28 09:08:31 INFO tclean::::casa ----------------------------- Running Parallel Major Cycle ----------------------------
28-Mar-2025 09:08:49	2025-03-28 09:08:31 INFO tclean::::casa checkJobs. Blocking for nodes to finish
28-Mar-2025 09:08:49	2025-03-28 09:08:32 INFO MPICommandServer::command_request_handler_service::SynthesisImager::executeMajorCycle::MPIServer-3 ----------------------------------------------------------- Run Major Cycle 2 -------------------------------------
28-Mar-2025 09:08:49	2025-03-28 09:08:32 INFO MPICommandServer::command_request_handler_service::SynthesisImager::executeMajorCycle::MPIServer-1 ----------------------------------------------------------- Run Major Cycle 2 -------------------------------------
28-Mar-2025 09:08:49	2025-03-28 09:08:32 INFO MPICommandServer::command_request_handler_service::SynthesisImager::executeMajorCycle::MPIServer-2 ----------------------------------------------------------- Run Major Cycle 2 -------------------------------------
28-Mar-2025 09:08:49
28-Mar-2025 09:08:49	0%....10....20....30....40....50....60....70....80....90....100%
28-Mar-2025 09:08:49
28-Mar-2025 09:08:49	0%....10....20....30....40....50....60....
28-Mar-2025 09:09:19	0%....10....20....30....40..70....80....50......90....100%
28-Mar-2025 09:09:19	60....70....80....90....100%
28-Mar-2025 09:09:19	2025-03-28 09:09:00 INFO tclean::::casa ...done
28-Mar-2025 09:09:19	2025-03-28 09:09:00 INFO SynthesisNormalizer::gatherImages Gather residual images : [/home/casatest/work/test_task_tclean/tst.awp2.workdirectory/tst.awp2.n1, /home/casatest/work/test_task_tclean/tst.awp2.workdirectory/tst.awp2.n2, /home/casatest/work/test_task_tclean/tst.awp2.workdirectory/tst.awp2.n3] onto :tst.awp2
28-Mar-2025 09:09:19	2025-03-28 09:09:01 INFO task_tclean::SynthesisDeconvolver::initMinorCycle Absolute Peak residual within mask : 0.0626301, over full image : 0.0626301
28-Mar-2025 09:09:19	2025-03-28 09:09:01 INFO tclean::::casa Reached global stopping criterion : iteration limit
28-Mar-2025 09:09:19	2025-03-28 09:09:01 INFO tclean::::casa getSummary call: fullsummary=False
28-Mar-2025 09:09:19	2025-03-28 09:09:01 INFO SDAlgorithmBase::restore [tst.awp2] : Restoring model image.
28-Mar-2025 09:09:19	2025-03-28 09:09:01 INFO SIImageStore::restore Beam for chan : 0 : 5.34588 arcsec, 4.36629 arcsec, -84.5374 deg
28-Mar-2025 09:09:19	2025-03-28 09:09:01 INFO SIImageStore::restore Beam for chan : 0 : 5.34588 arcsec, 4.36629 arcsec, -84.5374 deg
28-Mar-2025 09:09:19	2025-03-28 09:09:01 INFO task_tclean::SDAlgorithmBase::pbcor [tst.awp2] : Applying PB correction
28-Mar-2025 09:09:19	2025-03-28 09:09:10 INFO tclean::::casa checkJobs. Blocking for nodes to finish
28-Mar-2025 09:09:19	2025-03-28 09:09:11 INFO ::casa::MPIServer-1 node 1 has completed its job
28-Mar-2025 09:09:19	2025-03-28 09:09:11 INFO ::casa::MPIServer-3 node 3 has completed its job
28-Mar-2025 09:09:19	2025-03-28 09:09:11 INFO ::casa::MPIServer-2 node 2 has completed its job
28-Mar-2025 09:09:19	2025-03-28 09:09:11 INFO tclean::::casa ...done
28-Mar-2025 09:09:19	2025-03-28 09:09:11 INFO tclean::::casa Ending use of cluster, but not closing it. Call clustermanager.stop_cluster() to close it if needed.
28-Mar-2025 09:09:19	2025-03-28 09:09:11 INFO tclean::::casa Searching for images with prefix 'tst.awp2'... Found these, writing history into them: ['tst.awp2.gridwt_moswt', 'tst.awp2.sumwt', 'tst.awp2.model', 'tst.awp2.image', 'tst.awp2.psf', 'tst.awp2.pb', 'tst.awp2.residual', 'tst.awp2.image.pbcor', 'tst.awp2.weight', 'tst.awp2.mask']
28-Mar-2025 09:09:19	2025-03-28 09:09:12 INFO tclean::::casa Task tclean complete. Start time: 2025-03-28 09:06:07.182083 End time: 2025-03-28 09:09:11.625716
28-Mar-2025 09:09:19	2025-03-28 09:09:12 INFO tclean::::casa ##### End Task: tclean #####
28-Mar-2025 09:09:19	2025-03-28 09:09:12 INFO tclean::::casa ##########################################
28-Mar-2025 09:09:19	2025-03-28 09:09:12 INFO name:: No table opened.
28-Mar-2025 09:09:19	2025-03-28 09:09:12 INFO showcache:: The Table Cache is empty.
28-Mar-2025 09:09:19	2025-03-28 09:09:12 INFO tclean::::casa [ checkall ]
28-Mar-2025 09:09:19	2025-03-28 09:09:12 INFO tclean::::casa+ [ check_ims ] Image made : ['tst.awp2.image'] = [True] ( Pass : should all be True )
28-Mar-2025 09:09:19	2025-03-28 09:09:12 INFO tclean::::casa+ All expected keywords in imageinfo, miscinfo, and coords found. (check_keywords)
28-Mar-2025 09:09:19	2025-03-28 09:09:12 INFO tclean::::casa+ [check_history] All expected history entries found. (Pass)
28-Mar-2025 09:09:19	2025-03-28 09:09:12 INFO tclean::::casa+ [ check_pix_val ] tst.awp2.pb : Value is 0.6791475415229797 at [323, 858, 0, 0] ( Pass : should be 0.654 , Epsilon: 0.05)
28-Mar-2025 09:09:19	2025-03-28 09:09:12 INFO tclean::::casa+ [ check_pix_val ] tst.awp2.image.pbcor : Value is 0.6931212544441223 at [323, 858, 0, 0] ( Pass : should be 0.7 , Epsilon: 0.05)
28-Mar-2025 09:09:19	2025-03-28 09:09:12 INFO tclean::::casa+ [ check_pix_val ] tst.awp2.image.pbcor : Value is -0.020268484950065613 at [323, 858, 1, 0] ( Pass : should be -0.01 , Epsilon: 0.05)
28-Mar-2025 09:09:19	[ checkall ]
28-Mar-2025 09:09:19	[ check_ims ] Image made : ['tst.awp2.image'] = [True] ( Pass : should all be True )
28-Mar-2025 09:09:19	All expected keywords in imageinfo, miscinfo, and coords found. (check_keywords)
28-Mar-2025 09:09:19	[check_history] All expected history entries found. (Pass)
28-Mar-2025 09:09:19	[ check_pix_val ] tst.awp2.pb : Value is 0.6791475415229797 at [323, 858, 0, 0] ( Pass : should be 0.654 , Epsilon: 0.05)
28-Mar-2025 09:09:19	[ check_pix_val ] tst.awp2.image.pbcor : Value is 0.6931212544441223 at [323, 858, 0, 0] ( Pass : should be 0.7 , Epsilon: 0.05)
28-Mar-2025 09:09:19	[ check_pix_val ] tst.awp2.image.pbcor : Value is -0.020268484950065613 at [323, 858, 1, 0] ( Pass : should be -0.01 , Epsilon: 0.05)
28-Mar-2025 09:09:19
28-Mar-2025 09:09:19	.2025-03-28 09:09:15 INFO MPICommandServer::serve::MPICommandServer::serve::casa::MPIServer-1 Control signal MPIEnvironment.command_handling_log_level = 'DEBUG' successfully handled by server 1
28-Mar-2025 09:09:19	2025-03-28 09:09:15 INFO MPICommandServer::serve::MPICommandServer::serve::casa::MPIServer-3 Control signal MPIEnvironment.command_handling_log_level = 'DEBUG' successfully handled by server 3
28-Mar-2025 09:09:19	2025-03-28 09:09:15 INFO MPICommandServer::serve::MPICommandServer::serve::casa::MPIServer-2 Control signal MPIEnvironment.command_handling_log_level = 'DEBUG' successfully handled by server 2
28-Mar-2025 09:09:19	2025-03-28 09:09:16 INFO tclean::::casa setupCluster, Setting up 3 engines.
28-Mar-2025 09:09:19	2025-03-28 09:09:16 INFO tclean::::casa ##########################################
28-Mar-2025 09:09:19	2025-03-28 09:09:16 INFO tclean::::casa ##### Begin Task: tclean #####
28-Mar-2025 09:09:19	2025-03-28 09:09:16 INFO tclean::::casa tclean( vis='refim_point_wterm_vlad.ms', selectdata=True, field='', spw='', timerange='', uvrange='', antenna='', scan='', observation='', intent='', datacolumn='corrected', imagename='tst.wyes', imsize=2048, cell='10.0arcsec', phasecenter='', stokes='I', projection='SIN', startmodel='', specmode='mfs', reffreq='', nchan=-1, start='', width='', outframe='LSRK', veltype='radio', restfreq=[], interpolation='linear', perchanweightdensity=True, gridder='wproject', facets=1, psfphasecenter='', wprojplanes=16, vptable='', mosweight=True, aterm=True, psterm=False, wbawp=True, conjbeams=False, cfcache='', usepointing=False, computepastep=360.0, rotatepastep=360.0, pointingoffsetsigdev=[], pblimit=-0.1, normtype='flatnoise', deconvolver='hogbom', scales=[], nterms=2, smallscalebias=0.0, fusedthreshold=0.0, largestscale=-1, restoration=True, restoringbeam=[], pbcor=False, outlierfile='', weighting='uniform', robust=0.5, noise='1.0Jy', npixels=0, uvtaper=[''], niter=0, gain=0.1, threshold=0.0, nsigma=0.0, cycleniter=-1, cyclefactor=1.0, minpsffraction=0.05, maxpsffraction=0.8, interactive=False, nmajor=-1, fullsummary=False, usemask='user', mask='', pbmask=0.0, sidelobethreshold=3.0, noisethreshold=5.0, lownoisethreshold=1.5, negativethreshold=0.0, smoothfactor=1.0, minbeamfrac=0.3, cutthreshold=0.01, growiterations=75, dogrowprune=True, minpercentchange=-1.0, verbose=False, fastnoise=True, restart=True, savemodel='none', calcres=True, calcpsf=True, psfcutoff=0.35, parallel=True )
28-Mar-2025 09:09:19	2025-03-28 09:09:16 INFO tclean::::casa Verifying Input Parameters
28-Mar-2025 09:09:19	2025-03-28 09:09:18 INFO MPICommandServer::serve::MPICommandServer::serve::casa::MPIServer-1 Control signal MPIEnvironment.command_handling_log_level = 'DEBUG' successfully handled by server 1
28-Mar-2025 09:09:19	2025-03-28 09:09:18 INFO MPICommandServer::serve::MPICommandServer::serve::casa::MPIServer-3 Control signal MPIEnvironment.command_handling_log_level = 'DEBUG' successfully handled by server 3
28-Mar-2025 09:09:19	2025-03-28 09:09:18 INFO MPICommandServer::serve::MPICommandServer::serve::casa::MPIServer-2 Control signal MPIEnvironment.command_handling_log_level = 'DEBUG' successfully handled by server 2
28-Mar-2025 09:09:19	2025-03-28 09:09:19 INFO tclean::::casa setupCluster, Setting up 3 engines.
28-Mar-2025 09:09:19	2025-03-28 09:09:19 INFO SynthesisUtilMethods::continuumDataPartition
28-Mar-2025 09:09:19	2025-03-28 09:09:19 INFO SynthesisUtilMethods::continuumDataPartition + Rows = 10065 15093 [P][M]: 0:2 ROWNUMBER() >= 10065 && ROWNUMBER() <= 15093
28-Mar-2025 09:09:25	2025-03-28 09:09:19 INFO tclean::::casa Partitioned Selection : {'0': {'ms0': {'antenna': '', 'datacolumn': 'corrected', 'field': '', 'freqbeg': '', 'freqend': '', 'freqframe': 'LSRK', 'incrmodel': False, 'msname': 'refim_point_wterm_vlad.ms', 'obs': '', 'outframe': 'LSRK', 'readonly': True, 'scan': '', 'spw': '', 'state': '', 'taql': 'ROWNUMBER() >= 1 && ROWNUMBER() <= 5032', 'timestr': '', 'usescratch': False, 'uvdist': ''}}, '1': {'ms0': {'antenna': '', 'datacolumn': 'corrected', 'field': '', 'freqbeg': '', 'freqend': '', 'freqframe': 'LSRK', 'incrmodel': False, 'msname': 'refim_point_wterm_vlad.ms', 'obs': '', 'outframe': 'LSRK', 'readonly': True, 'scan': '', 'spw': '', 'state': '', 'taql': 'ROWNUMBER() >= 5033 && ROWNUMBER() <= 10064', 'timestr': '', 'usescratch': False, 'uvdist': ''}}, '2': {'ms0': {'antenna': '', 'datacolumn': 'corrected', 'field': '', 'freqbeg': '', 'freqend': '', 'freqframe': 'LSRK', 'incrmodel': False, 'msname': 'refim_point_wterm_vlad.ms', 'obs': '', 'outframe': 'LSRK', 'readonly': True, 'scan': '', 'spw': '', 'state': '', 'taql': 'ROWNUMBER() >= 10065 && ROWNUMBER() <= 15093', 'timestr': '', 'usescratch': False, 'uvdist': ''}}}
28-Mar-2025 09:09:25	2025-03-28 09:09:19 INFO SynthesisImagerVi2::selectData MS : refim_point_wterm_vlad.ms \| [Opened in readonly mode]
28-Mar-2025 09:09:25	2025-03-28 09:09:19 INFO SynthesisImagerVi2::selectData NRows selected : 15093
28-Mar-2025 09:09:25	2025-03-28 09:09:19 INFO SynthesisImagerVi2::defineImage Define image coordinates for [tst.wyes] :
28-Mar-2025 09:09:25	2025-03-28 09:09:19 INFO SynthesisImagerVi2::defineImage Define image coordinates for [tst.wyes] :
28-Mar-2025 09:09:25	2025-03-28 09:09:19 INFO SynthesisImagerVi2::defineImage Impars: start
28-Mar-2025 09:09:25	2025-03-28 09:09:19 INFO SynthesisImagerVi2::defineImage Shape: [2048, 2048, 1, 1] Spectral: [9.99981e+08] at [0] with increment [1.00218e+06]
28-Mar-2025 09:09:25	2025-03-28 09:09:19 INFO SynthesisImagerVi2::defineImage Set Gridding options for [tst.wyes] with ftmachine : wprojectft
28-Mar-2025 09:09:25	2025-03-28 09:09:19 INFO SynthesisImagerVi2::nSubCubeFitInMemory Required memory: 1.537 GB. Available mem.: 387.1 GB (rc, mem. fraction: 80%, memory: -) => Subcubes: 1. Processes on node: 4.
28-Mar-2025 09:09:25	2025-03-28 09:09:19 INFO tclean::::casa checkJobs. Blocking for nodes to finish
28-Mar-2025 09:09:25	2025-03-28 09:09:20 INFO tclean::::casa ...done
28-Mar-2025 09:09:25	2025-03-28 09:09:20 INFO tclean::::casa checkJobs. Blocking for nodes to finish
28-Mar-2025 09:09:25	2025-03-28 09:09:20 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::selectData::MPIServer-1 MS : refim_point_wterm_vlad.ms \| [Opened in readonly mode]
28-Mar-2025 09:09:25	2025-03-28 09:09:20 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::selectData::MPIServer-1 Selecting via TaQL : ROWNUMBER() >= 1 && ROWNUMBER() <= 5032 \| NRows selected : 5032
28-Mar-2025 09:09:25	2025-03-28 09:09:20 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::selectData::MPIServer-3 MS : refim_point_wterm_vlad.ms \| [Opened in readonly mode]
28-Mar-2025 09:09:25	2025-03-28 09:09:20 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::selectData::MPIServer-3 Selecting via TaQL : ROWNUMBER() >= 10065 && ROWNUMBER() <= 15093 \| NRows selected : 5029
28-Mar-2025 09:09:25	2025-03-28 09:09:20 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::selectData::MPIServer-2 MS : refim_point_wterm_vlad.ms \| [Opened in readonly mode]
28-Mar-2025 09:09:25	2025-03-28 09:09:20 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::selectData::MPIServer-2 Selecting via TaQL : ROWNUMBER() >= 5033 && ROWNUMBER() <= 10064 \| NRows selected : 5032
28-Mar-2025 09:09:25	2025-03-28 09:09:21 INFO tclean::::casa ...done
28-Mar-2025 09:09:25	2025-03-28 09:09:22 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::defineImage::MPIServer-1 Define image coordinates for [/home/casatest/work/test_task_tclean/tst.wyes.workdirectory/tst.wyes.n1] :
28-Mar-2025 09:09:25	2025-03-28 09:09:22 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::defineImage::MPIServer-1 Define image coordinates for [/home/casatest/work/test_task_tclean/tst.wyes.workdirectory/tst.wyes.n1] :
28-Mar-2025 09:09:25	2025-03-28 09:09:22 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::defineImage::MPIServer-1 Impars: start
28-Mar-2025 09:09:25	2025-03-28 09:09:22 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::defineImage::MPIServer-1 Shape: [2048, 2048, 1, 1] Spectral: [9.99981e+08] at [0] with increment [1.00218e+06]
28-Mar-2025 09:09:25	2025-03-28 09:09:22 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::defineImage::MPIServer-1 Set Gridding options for [/home/casatest/work/test_task_tclean/tst.wyes.workdirectory/tst.wyes.n1] with ftmachine : wprojectft
28-Mar-2025 09:09:25	2025-03-28 09:09:22 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::nSubCubeFitInMemory::MPIServer-1 Required memory: 1.537 GB. Available mem.: 387.1 GB (rc, mem. fraction: 80%, memory: -) => Subcubes: 1. Processes on node: 4.
28-Mar-2025 09:09:25	2025-03-28 09:09:22 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::defineImage::MPIServer-2 Define image coordinates for [/home/casatest/work/test_task_tclean/tst.wyes.workdirectory/tst.wyes.n2] :
28-Mar-2025 09:09:25	2025-03-28 09:09:22 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::defineImage::MPIServer-2 Define image coordinates for [/home/casatest/work/test_task_tclean/tst.wyes.workdirectory/tst.wyes.n2] :
28-Mar-2025 09:09:25	2025-03-28 09:09:22 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::defineImage::MPIServer-2 Impars: start
28-Mar-2025 09:09:25	2025-03-28 09:09:22 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::defineImage::MPIServer-2 Shape: [2048, 2048, 1, 1] Spectral: [9.99981e+08] at [0] with increment [1.00218e+06]
28-Mar-2025 09:09:25	2025-03-28 09:09:22 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::defineImage::MPIServer-2 Set Gridding options for [/home/casatest/work/test_task_tclean/tst.wyes.workdirectory/tst.wyes.n2] with ftmachine : wprojectft
28-Mar-2025 09:09:25	2025-03-28 09:09:22 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::nSubCubeFitInMemory::MPIServer-2 Required memory: 1.537 GB. Available mem.: 387.1 GB (rc, mem. fraction: 80%, memory: -) => Subcubes: 1. Processes on node: 4.
28-Mar-2025 09:09:25	2025-03-28 09:09:22 INFO tclean::::casa checkJobs. Blocking for nodes to finish
28-Mar-2025 09:09:25	2025-03-28 09:09:22 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::defineImage::MPIServer-3 Define image coordinates for [/home/casatest/work/test_task_tclean/tst.wyes.workdirectory/tst.wyes.n3] :
28-Mar-2025 09:09:25	2025-03-28 09:09:22 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::defineImage::MPIServer-3 Define image coordinates for [/home/casatest/work/test_task_tclean/tst.wyes.workdirectory/tst.wyes.n3] :
28-Mar-2025 09:09:25	2025-03-28 09:09:22 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::defineImage::MPIServer-3 Impars: start
28-Mar-2025 09:09:25	2025-03-28 09:09:22 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::defineImage::MPIServer-3 Shape: [2048, 2048, 1, 1] Spectral: [9.99981e+08] at [0] with increment [1.00218e+06]
28-Mar-2025 09:09:25	2025-03-28 09:09:22 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::defineImage::MPIServer-3 Set Gridding options for [/home/casatest/work/test_task_tclean/tst.wyes.workdirectory/tst.wyes.n3] with ftmachine : wprojectft
28-Mar-2025 09:09:25	2025-03-28 09:09:22 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::nSubCubeFitInMemory::MPIServer-3 Required memory: 1.537 GB. Available mem.: 387.1 GB (rc, mem. fraction: 80%, memory: -) => Subcubes: 1. Processes on node: 4.
28-Mar-2025 09:09:25	2025-03-28 09:09:23 INFO tclean::::casa ...done
28-Mar-2025 09:09:25	2025-03-28 09:09:26 INFO tclean::::casa checkJobs. Blocking for nodes to finish
28-Mar-2025 09:09:25	2025-03-28 09:09:26 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::weight()::MPIServer-1 Set imaging weights : Uniform weighting: sidelobes will be suppressed over full image
28-Mar-2025 09:09:25	2025-03-28 09:09:26 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::weight()::MPIServer-3 Set imaging weights : Uniform weighting: sidelobes will be suppressed over full image
28-Mar-2025 09:09:39	2025-03-28 09:09:26 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::weight()::MPIServer-2 Set imaging weights : Uniform weighting: sidelobes will be suppressed over full image
28-Mar-2025 09:09:39	2025-03-28 09:09:27 INFO tclean::::casa ...done
28-Mar-2025 09:09:39	2025-03-28 09:09:27 INFO tclean::::casa Gathering/Merging/Scattering Weight Density for PSF generation
28-Mar-2025 09:09:39	2025-03-28 09:09:27 INFO tclean::::casa checkJobs. Blocking for nodes to finish
28-Mar-2025 09:09:39	2025-03-28 09:09:28 INFO tclean::::casa ...done
28-Mar-2025 09:09:39	2025-03-28 09:09:28 INFO tclean::::casa ******************************************************
28-Mar-2025 09:09:39	2025-03-28 09:09:28 INFO tclean::::casa gather and scatter now
28-Mar-2025 09:09:39	2025-03-28 09:09:28 INFO tclean::::casa ******************************************************
28-Mar-2025 09:09:39	2025-03-28 09:09:28 INFO SynthesisNormalizer::scatterWeightDensity Send the gridded weight from : tst.wyes to all nodes :[/home/casatest/work/test_task_tclean/tst.wyes.workdirectory/tst.wyes.n1, /home/casatest/work/test_task_tclean/tst.wyes.workdirectory/tst.wyes.n2, /home/casatest/work/test_task_tclean/tst.wyes.workdirectory/tst.wyes.n3]
28-Mar-2025 09:09:39	2025-03-28 09:09:28 INFO tclean::::casa checkJobs. Blocking for nodes to finish
28-Mar-2025 09:09:39	2025-03-28 09:09:29 INFO tclean::::casa ...done
28-Mar-2025 09:09:39	2025-03-28 09:09:29 INFO task_tclean::SynthesisDeconvolver::setupDeconvolution Set Deconvolution Options for [tst.wyes] : hogbom
28-Mar-2025 09:09:39	2025-03-28 09:09:29 INFO tclean::::casa checkJobs. Blocking for nodes to finish
28-Mar-2025 09:09:39	2025-03-28 09:09:30 INFO tclean::::casa ...done
28-Mar-2025 09:09:39	2025-03-28 09:09:30 INFO tclean::::casa checkJobs. Blocking for nodes to finish
28-Mar-2025 09:09:39	2025-03-28 09:09:30 INFO MPICommandServer::command_request_handler_service::SynthesisImager::makePSF::MPIServer-3 ----------------------------------------------------------- Make PSF ---------------------------------------------
28-Mar-2025 09:09:39	2025-03-28 09:09:30 INFO MPICommandServer::command_request_handler_service::SynthesisImager::makePSF::MPIServer-2 ----------------------------------------------------------- Make PSF ---------------------------------------------
28-Mar-2025 09:09:39	2025-03-28 09:09:30 INFO MPICommandServer::command_request_handler_service::SynthesisImager::makePSF::MPIServer-1 ----------------------------------------------------------- Make PSF ---------------------------------------------
28-Mar-2025 09:09:39	2025-03-28 09:09:30 INFO MPICommandServer::command_request_handler_service::WPConvFunc::findConvFunction::MPIServer-3 W projection using 16 planes
28-Mar-2025 09:09:39	2025-03-28 09:09:30 INFO MPICommandServer::command_request_handler_service::WPConvFunc::findConvFunction::MPIServer-3 Using maximum possible W = 5156.62 (wavelengths)
28-Mar-2025 09:09:39	2025-03-28 09:09:30 INFO MPICommandServer::command_request_handler_service::WPConvFunc::findConvFunction::MPIServer-3 Typical wavelength = 0.299798 (m)
28-Mar-2025 09:09:39	2025-03-28 09:09:30 INFO MPICommandServer::command_request_handler_service::WPConvFunc::findConvFunction::MPIServer-3 Scaling in W (at maximum W) = 22.9183 wavelengths per pixel
28-Mar-2025 09:09:39	2025-03-28 09:09:30 INFO MPICommandServer::command_request_handler_service::WPConvFunc::findConvFunction::MPIServer-1 W projection using 16 planes
28-Mar-2025 09:09:39	2025-03-28 09:09:30 INFO MPICommandServer::command_request_handler_service::WPConvFunc::findConvFunction::MPIServer-1 Using maximum possible W = 5156.62 (wavelengths)
28-Mar-2025 09:09:39	2025-03-28 09:09:30 INFO MPICommandServer::command_request_handler_service::WPConvFunc::findConvFunction::MPIServer-1 Typical wavelength = 0.299798 (m)
28-Mar-2025 09:09:39	2025-03-28 09:09:30 INFO MPICommandServer::command_request_handler_service::WPConvFunc::findConvFunction::MPIServer-1 Scaling in W (at maximum W) = 22.9183 wavelengths per pixel
28-Mar-2025 09:09:39	2025-03-28 09:09:30 INFO MPICommandServer::command_request_handler_service::WPConvFunc::findConvFunction::MPIServer-2 W projection using 16 planes
28-Mar-2025 09:09:39	2025-03-28 09:09:30 INFO MPICommandServer::command_request_handler_service::WPConvFunc::findConvFunction::MPIServer-2 Using maximum possible W = 5156.62 (wavelengths)
28-Mar-2025 09:09:39	2025-03-28 09:09:30 INFO MPICommandServer::command_request_handler_service::WPConvFunc::findConvFunction::MPIServer-2 Typical wavelength = 0.299798 (m)
28-Mar-2025 09:09:39	2025-03-28 09:09:30 INFO MPICommandServer::command_request_handler_service::WPConvFunc::findConvFunction::MPIServer-2 Scaling in W (at maximum W) = 22.9183 wavelengths per pixel
28-Mar-2025 09:09:39	2025-03-28 09:09:35 INFO MPICommandServer::command_request_handler_service::WPConvFunc::findConvFunction::MPIServer-3 Convolution support = [16, 16, 20, 20, 24, 32, 36, 44, 52, 64, 72, 84, 96, 112, 124, 140] pixels in Fourier plane
28-Mar-2025 09:09:39	2025-03-28 09:09:35 INFO MPICommandServer::command_request_handler_service::WPConvFunc::findConvFunction::MPIServer-3 Memory used in gridding function = 2 MB from maximum 515201 MB
28-Mar-2025 09:09:39	2025-03-28 09:09:35 INFO MPICommandServer::command_request_handler_service::WPConvFunc::findConvFunction::MPIServer-1 Convolution support = [16, 16, 20, 20, 24, 32, 36, 44, 52, 64, 72, 84, 96, 112, 124, 140] pixels in Fourier plane
28-Mar-2025 09:09:39	2025-03-28 09:09:35 INFO MPICommandServer::command_request_handler_service::WPConvFunc::findConvFunction::MPIServer-1 Memory used in gridding function = 2 MB from maximum 515201 MB
28-Mar-2025 09:09:39	2025-03-28 09:09:35 INFO MPICommandServer::command_request_handler_service::WPConvFunc::findConvFunction::MPIServer-2 Convolution support = [16, 16, 20, 20, 24, 32, 36, 44, 52, 64, 72, 84, 96, 112, 124, 140] pixels in Fourier plane
28-Mar-2025 09:09:39	2025-03-28 09:09:35 INFO MPICommandServer::command_request_handler_service::WPConvFunc::findConvFunction::MPIServer-2 Memory used in gridding function = 2 MB from maximum 515201 MB
28-Mar-2025 09:09:39	2025-03-28 09:09:36 INFO tclean::::casa ...done
28-Mar-2025 09:09:39	2025-03-28 09:09:36 INFO SynthesisNormalizer::gatherImages Gather psf,weight images : [/home/casatest/work/test_task_tclean/tst.wyes.workdirectory/tst.wyes.n1, /home/casatest/work/test_task_tclean/tst.wyes.workdirectory/tst.wyes.n2, /home/casatest/work/test_task_tclean/tst.wyes.workdirectory/tst.wyes.n3] onto :tst.wyes
28-Mar-2025 09:09:39	2025-03-28 09:09:37 INFO SIImageStore::calcSensitivity [tst.wyes] Theoretical sensitivity (Jy/bm):0.00632763
28-Mar-2025 09:09:39	2025-03-28 09:09:37 INFO SIImageStore::getPSFGaussian Time to fit Gaussian to PSF 0.038533
28-Mar-2025 09:09:39	2025-03-28 09:09:37 INFO SIImageStore::printBeamSet Beam : 85.3971 arcsec, 71.2504 arcsec, -89.0441 deg
28-Mar-2025 09:09:39	2025-03-28 09:09:37 INFO tclean::::casa checkJobs. Blocking for nodes to finish
28-Mar-2025 09:09:39	2025-03-28 09:09:37 INFO MPICommandServer::command_request_handler_service::SynthesisImagerVi2::makePrimaryBeam::MPIServer-1 vi2 : Evaluating Primary Beam model onto image grid(s)
28-Mar-2025 09:09:39	2025-03-28 09:09:38 INFO tclean::::casa ...done
28-Mar-2025 09:09:39	2025-03-28 09:09:38 INFO SynthesisNormalizer::scatterModel Send the model from : tst.wyes to all nodes :[/home/casatest/work/test_task_tclean/tst.wyes.workdirectory/tst.wyes.n1, /home/casatest/work/test_task_tclean/tst.wyes.workdirectory/tst.wyes.n2, /home/casatest/work/test_task_tclean/tst.wyes.workdirectory/tst.wyes.n3]
28-Mar-2025 09:09:39	2025-03-28 09:09:38 INFO SIImageStore::setModelImageOne Starting model image tst.wyes.model does not exist. No initial prediction will be done
28-Mar-2025 09:09:39	2025-03-28 09:09:38 INFO SIImageStore::setModelImageOne Starting model image tst.wyes.model does not exist. No initial prediction will be done
28-Mar-2025 09:09:39	2025-03-28 09:09:38 INFO SIImageStore::setModelImageOne Starting model image tst.wyes.model does not exist. No initial prediction will be done
28-Mar-2025 09:09:39	2025-03-28 09:09:38 INFO tclean::::casa ----------------------------- Running Parallel Major Cycle ----------------------------
28-Mar-2025 09:09:39	2025-03-28 09:09:38 INFO tclean::::casa checkJobs. Blocking for nodes to finish
28-Mar-2025 09:09:39	2025-03-28 09:09:38 INFO MPICommandServer::command_request_handler_service::SynthesisImager::executeMajorCycle::MPIServer-2 ----------------------------------------------------------- Run Major Cycle 1 -------------------------------------
28-Mar-2025 09:09:39	2025-03-28 09:09:38 INFO MPICommandServer::command_request_handler_service::SynthesisImager::executeMajorCycle::MPIServer-3 ----------------------------------------------------------- Run Major Cycle 1 -------------------------------------
28-Mar-2025 09:09:39	2025-03-28 09:09:38 INFO MPICommandServer::command_request_handler_service::SynthesisImager::executeMajorCycle::MPIServer-1 ----------------------------------------------------------- Run Major Cycle 1 -------------------------------------
28-Mar-2025 09:09:39	2025-03-28 09:09:40 INFO tclean::::casa ...done
28-Mar-2025 09:10:03	2025-03-28 09:09:40 INFO SynthesisNormalizer::gatherImages Gather residual images : [/home/casatest/work/test_task_tclean/tst.wyes.workdirectory/tst.wyes.n1, /home/casatest/work/test_task_tclean/tst.wyes.workdirectory/tst.wyes.n2, /home/casatest/work/test_task_tclean/tst.wyes.workdirectory/tst.wyes.n3] onto :tst.wyes
28-Mar-2025 09:10:03	2025-03-28 09:09:40 INFO task_tclean::SDAlgorithmBase::restore [tst.wyes] : Restoring model image.
28-Mar-2025 09:10:03	2025-03-28 09:09:40 WARN task_tclean::SIImageStore::restore (file /source/casa6/casatools/src/code/synthesis/ImagerObjects/SIImageStore.cc, line 2345) Restoring with an empty model image. Only residuals will be processed to form the output restored image.
28-Mar-2025 09:10:03	2025-03-28 09:09:40 INFO task_tclean::SIImageStore::restore Beam for chan : 0 : 85.3971 arcsec, 71.2504 arcsec, -89.0441 deg
28-Mar-2025 09:10:03	2025-03-28 09:09:48 INFO tclean::::casa checkJobs. Blocking for nodes to finish
28-Mar-2025 09:10:03	2025-03-28 09:09:48 INFO ::casa::MPIServer-2 node 2 has completed its job
28-Mar-2025 09:10:03	2025-03-28 09:09:48 INFO ::casa::MPIServer-3 node 3 has completed its job
28-Mar-2025 09:10:03	2025-03-28 09:09:48 INFO ::casa::MPIServer-1 node 1 has completed its job
28-Mar-2025 09:10:03	2025-03-28 09:09:49 INFO tclean::::casa ...done
28-Mar-2025 09:10:03	2025-03-28 09:09:49 INFO tclean::::casa Ending use of cluster, but not closing it. Call clustermanager.stop_cluster() to close it if needed.
28-Mar-2025 09:10:03	2025-03-28 09:09:49 INFO tclean::::casa Searching for images with prefix 'tst.wyes'... Found these, writing history into them: ['tst.wyes.gridwt_temp', 'tst.wyes.residual', 'tst.wyes.sumwt', 'tst.wyes.image', 'tst.wyes.psf', 'tst.wyes.pb', 'tst.wyes.model']
28-Mar-2025 09:10:03	2025-03-28 09:09:49 INFO tclean::::casa Task tclean complete. Start time: 2025-03-28 09:09:16.314187 End time: 2025-03-28 09:09:49.273566
28-Mar-2025 09:10:03	2025-03-28 09:09:49 INFO tclean::::casa ##### End Task: tclean #####
28-Mar-2025 09:10:03	2025-03-28 09:09:49 INFO tclean::::casa ##########################################
28-Mar-2025 09:10:03	2025-03-28 09:09:49 INFO name:: No table opened.
28-Mar-2025 09:10:03	2025-03-28 09:09:49 INFO showcache:: The Table Cache is empty.
28-Mar-2025 09:10:03	[check_tfmask] T/F mask name for tst.wyes.image is : ['T'] (Pass : should be ['T'])
28-Mar-2025 09:10:03
28-Mar-2025 09:10:03	2025-03-28 09:09:49 INFO tclean::::casa [ checkall ]
28-Mar-2025 09:10:03	2025-03-28 09:09:49 INFO tclean::::casa+ [ check_ims ] Image made : ['tst.wyes.image'] = [True] ( Pass : should all be True )
28-Mar-2025 09:10:03	2025-03-28 09:09:49 INFO tclean::::casa+ All expected keywords in imageinfo, miscinfo, and coords found. (check_keywords)
28-Mar-2025 09:10:03	2025-03-28 09:09:49 INFO tclean::::casa+ [check_history] All expected history entries found. (Pass)
28-Mar-2025 09:10:03	2025-03-28 09:09:49 INFO tclean::::casa+ [ check_pix_val ] tst.wyes.psf : Value is 1.0 at [1024, 1024, 0, 0] ( Pass : should be 1.0 , Epsilon: 0.05)
28-Mar-2025 09:10:03	2025-03-28 09:09:49 INFO tclean::::casa+ [ check_pix_val ] tst.wyes.image : Value is 0.9963294267654419 at [1158, 1384, 0, 0] ( Pass : should be 1.0 , Epsilon: 0.05)
28-Mar-2025 09:10:03	2025-03-28 09:09:49 INFO tclean::::casa+ [check_tfmask] T/F mask name for tst.wyes.image is : ['T'] (Pass : should be ['T'])
28-Mar-2025 09:10:03	.s
28-Mar-2025 09:10:03	----------------------------------------------------------------------
28-Mar-2025 09:10:03	Ran 336 tests in 14135.637s
28-Mar-2025 09:10:03
28-Mar-2025 09:10:03	OK (skipped=32)
28-Mar-2025 09:10:03	Marking test as passed.
28-Mar-2025 09:10:03	2025-03-28 09:09:54 INFO MPICommandServer::serve::MPICommandServer::serve::casa::MPIServer-1 Control signal self.signal_stop_virtual_frame_buffer() successfully handled by server 1
28-Mar-2025 09:10:03	2025-03-28 09:09:54 INFO MPICommandServer::serve::MPICommandServer::serve::casa::MPIServer-3 Control signal self.signal_stop_virtual_frame_buffer() successfully handled by server 3
28-Mar-2025 09:10:03	2025-03-28 09:09:54 INFO MPICommandServer::serve::MPICommandServer::serve::casa::MPIServer-2 Control signal self.signal_stop_virtual_frame_buffer() successfully handled by server 2
28-Mar-2025 09:10:03	2025-03-28 09:09:57 INFO MPICommandServer::serve::MPICommandServer::serve::casa::MPIServer-1 Control signal self.signal_stop_service_request() successfully handled by server 1
28-Mar-2025 09:10:03	2025-03-28 09:09:57 INFO MPICommandServer::serve::MPICommandServer::serve::casa::MPIServer-3 Control signal self.signal_stop_service_request() successfully handled by server 3
28-Mar-2025 09:10:03	2025-03-28 09:09:57 INFO MPICommandServer::serve::MPICommandServer::serve::casa::MPIServer-2 Control signal self.signal_stop_service_request() successfully handled by server 2
28-Mar-2025 09:10:03	2025-03-28 09:10:00 INFO MPICommandServer::serve::MPICommandServer::serve::casa::MPIServer-1 stop service signal received, stopping services...
28-Mar-2025 09:10:03	2025-03-28 09:10:00 INFO MPICommandServer::serve::MPICommandServer::serve::casa::MPIServer-3 stop service signal received, stopping services...
28-Mar-2025 09:10:03	2025-03-28 09:10:00 INFO MPICommandServer::serve::MPICommandServer::serve::casa::MPIServer-2 stop service signal received, stopping services...
28-Mar-2025 09:10:03	2025-03-28 09:10:03 INFO MPICommandServer::stop_command_request_handler_service::MPICommandServer::stop_command_request_handler_service::casa::MPIServer-3 MPI command request handler service stopped
28-Mar-2025 09:10:03	2025-03-28 09:10:03 INFO MPICommandServer::stop_command_request_handler_service::MPICommandServer::stop_command_request_handler_service::casa::MPIServer-1 MPI command request handler service stopped
28-Mar-2025 09:10:03	2025-03-28 09:10:03 INFO MPICommandServer::serve::MPICommandServer::serve::casa::MPIServer-3 Going to finalize MPI environment
28-Mar-2025 09:10:03	2025-03-28 09:10:03 INFO MPICommandServer::serve::MPICommandServer::serve::casa::MPIServer-1 Going to finalize MPI environment
28-Mar-2025 09:10:03	2025-03-28 09:10:03 INFO MPICommandServer::stop_command_request_handler_service::MPICommandServer::stop_command_request_handler_service::casa::MPIServer-2 MPI command request handler service stopped
28-Mar-2025 09:10:03	2025-03-28 09:10:03 INFO MPICommandServer::serve::MPICommandServer::serve::casa::MPIServer-2 Going to finalize MPI environment
28-Mar-2025 09:10:03	2025-03-28 09:10:03 INFO MPICommandServer::serve::MPICommandServer::serve::casa::MPIServer-3 Exiting
28-Mar-2025 09:10:03	2025-03-28 09:10:03 INFO MPICommandServer::serve::MPICommandServer::serve::casa::MPIServer-1 Exiting
28-Mar-2025 09:10:03	2025-03-28 09:10:03 INFO MPICommandServer::serve::MPICommandServer::serve::casa::MPIServer-2 Exiting
28-Mar-2025 09:10:03	Executor result: 0
28-Mar-2025 09:10:03	Failed tests:[]
28-Mar-2025 09:10:03
28-Mar-2025 09:10:03	Results: [{'testname': 'test_task_tclean', 'runtime': '3:55:52.094281', 'returncode': 0, 'testerr': []}]
28-Mar-2025 09:10:03	Stopping Xvfb.
28-Mar-2025 09:10:03	Stopping framebuffer <Popen: returncode: None args: ['Xvfb', ':143', '-screen', '0', '2048x2048x2...>
28-Mar-2025 09:10:03	Virtual frame buffer deployed at :143 with pid 154 successfully shutdown
28-Mar-2025 09:10:03	Xvfb stopped.
28-Mar-2025 09:10:03	total 1018212
28-Mar-2025 09:10:03	-rw-r--r-- 1 casaci 15001 1042641296 Mar 28 05:12 casa-6.7.2-9-py3.12.el8.tar.xz
28-Mar-2025 09:10:03	-rw-r--r-- 1 casaci casatest 327 Mar 28 09:10 xUnit-suite-mpi-8.xml
28-Mar-2025 09:10:03	Finished task 'MPI Tasks Tests on EL8' with result: Success
28-Mar-2025 09:10:03	Starting task 'Parse test results' of type 'com.atlassian.bamboo.plugins.testresultparser:task.testresultparser.junit'
28-Mar-2025 09:10:03	Parsing test results under /export/cvpost134-nvme/casa/bamboohome/xml-data/build-dir/CASASPECS-MASTERTESTCASALITHPY312-MTTR93D...
28-Mar-2025 09:10:03	Finished task 'Parse test results' with result: Success
28-Mar-2025 09:10:03	Substituting variable: ${bamboo.capability.hostname} with cvpost134
28-Mar-2025 09:10:03	Substituting variable: ${bamboo.capability.hostname} with cvpost134
28-Mar-2025 09:10:03	Starting task 'Cleanup' of type 'com.atlassian.bamboo.plugins.scripttask:task.builder.script'
28-Mar-2025 09:10:03	Beginning to execute external process for build 'CASASPECS - Master Test Casalith 3.12 - Test MPI Task Tclean Many Linux 2.28 Rocky 9.5 Docker #132 (CASASPECS-MASTERTESTCASALITHPY312-MTTR93D-132)' ... running command line: /export/cvpost134-nvme/casa/bamboohome/temp/CASASPECS-MASTERTESTCASALITHPY312-MTTR93D-132-ScriptBuildTask-3876403760085857248.sh ... in: /export/cvpost134-nvme/casa/bamboohome/xml-data/build-dir/CASASPECS-MASTERTESTCASALITHPY312-MTTR93D
28-Mar-2025 09:10:03	Starting cleanup
28-Mar-2025 09:10:13	test-container
28-Mar-2025 09:10:19	test-container
28-Mar-2025 09:10:19	Error response from daemon: No such container: test-container-cvpost134
28-Mar-2025 09:10:19	Error response from daemon: No such container: test-container-cvpost134
28-Mar-2025 09:10:19	Cleanup complete
28-Mar-2025 09:10:19	Finished task 'Cleanup' with result: Success
28-Mar-2025 09:10:19	Running post build plugin 'Docker Container Cleanup'
28-Mar-2025 09:10:19	Running post build plugin 'NCover Results Collector'
28-Mar-2025 09:10:19	Running post build plugin 'Build Results Label Collector'
28-Mar-2025 09:10:19	Running post build plugin 'Clover Results Collector'
28-Mar-2025 09:10:19	Running post build plugin 'npm Cache Cleanup'
28-Mar-2025 09:10:19	Running post build plugin 'Artifact Copier'
28-Mar-2025 09:10:19	Finalising the build...
28-Mar-2025 09:10:19	Stopping timer.
28-Mar-2025 09:10:19	Build CASASPECS-MASTERTESTCASALITHPY312-MTTR93D-132 completed.
28-Mar-2025 05:10:19	Running on server: post build plugin 'Build Hanging Detection Configuration'
28-Mar-2025 05:10:19	Running on server: post build plugin 'NCover Results Collector'
28-Mar-2025 05:10:19	Running on server: post build plugin 'Build Labeller'
28-Mar-2025 05:10:19	Running on server: post build plugin 'Clover Delta Calculator'
28-Mar-2025 05:10:19	Running on server: post build plugin 'Maven Dependencies Postprocessor'
28-Mar-2025 05:10:19	All post build plugins have finished
28-Mar-2025 05:10:19	Generating build results summary...
28-Mar-2025 05:10:19	Saving build results to disk...
28-Mar-2025 05:10:19	Store variable context...
28-Mar-2025 05:10:19	Finished building CASASPECS-MASTERTESTCASALITHPY312-MTTR93D-132.

Build: #132 was successful

Job: Test MPI Task Tclean Many Linux 2.28 Rocky 9.5 Docker was successful

Stages & jobs

Default Stage

Build log

Build #132

Build: #132 was successful

Job: Test MPI Task Tclean Many Linux 2.28 Rocky 9.5 Docker was successful

Stages & jobs

Default Stage

Build log