==>Running the container with these arguments: '-endorsed -Dalma.MicroArchive.DbDir=/alma/ACS-3.0/acsdata/config/MicroArchive alma.acs.container.AcsContainerRunner -containerName frodoContainer -OAport 3050 '
Starting Java/abeans application
Using endorsed jar files in: -Djava.endorsed.dirs=/alma/ACS-3.0/ACSSW/lib/endorsed:
exported ACS_ABEANS_CONFIG=/alma/ACS-3.0/acsdata/config/abeans/Config
ACS abeans configuration directory: /alma/ACS-3.0/acsdata/config/abeans/Config
exported CLASSPATH
exported MANAGER_REFERENCE=corbaloc::te49:3000/Manager
ACS Manager: corbaloc::te49:3000/Manager
exported MANAGER_COMPUTER_NAME=te49
exported ACS_NAME_SERVICE=corbaloc::te49:3001/NameService
ACS Name Service: corbaloc::te49:3001/NameService
exported ACS_INTERFACE_REPOSITORY=corbaloc::te49:3004/InterfaceRepository
ACS Interface Repository: corbaloc::te49:3004/InterfaceRepository
exported ACS_TMP=/alma/ACS-3.0/acsdata/tmp/ACS_INSTANCE.0
Running the following command:
java -classpath ../lib/schedulingTest.jar:/alma/ACS-3.0/ACSSW/lib/abeansACSPlug.jar:/alma/ACS-3.0/ACSSW/lib/abeansBaciModel.jar:/alma/ACS-3.0/ACSSW/lib/abeansgen.jar:/alma/ACS-3.0/ACSSW/lib/abeansNetBeansModule.jar:/alma/ACS-3.0/ACSSW/lib/abeansR2Components.jar:/alma/ACS-3.0/ACSSW/lib/ac.jar:/alma/ACS-3.0/ACSSW/lib/acsabeansExamples.jar:/alma/ACS-3.0/ACSSW/lib/AcsCommandCenterEntities.jar:/alma/ACS-3.0/ACSSW/lib/acscommandcenter.jar:/alma/ACS-3.0/ACSSW/lib/acscomponent.jar:/alma/ACS-3.0/ACSSW/lib/acserr.jar:/alma/ACS-3.0/ACSSW/lib/acserrj.jar:/alma/ACS-3.0/ACSSW/lib/ACSErrTICS.jar:/alma/ACS-3.0/ACSSW/lib/ACSErrTicsTCorr.jar:/alma/ACS-3.0/ACSSW/lib/ACSErrTypeAlarm.jar:/alma/ACS-3.0/ACSSW/lib/ACSErrTypeCommon.jar:/alma/ACS-3.0/ACSSW/lib/ACSErrTypeCORBA.jar:/alma/ACS-3.0/ACSSW/lib/ACSErrTypeCppNative.jar:/alma/ACS-3.0/ACSSW/lib/ACSErrTypeDevIO.jar:/alma/ACS-3.0/ACSSW/lib/ACSErrTypeJavaNative.jar:/alma/ACS-3.0/ACSSW/lib/ACSErrTypeMonitor.jar:/alma/ACS-3.0/ACSSW/lib/ACSErrTypeOK.jar:/alma/ACS-3.0/ACSSW/lib/ACSErrTypePythonNative.jar:/alma/ACS-3.0/ACSSW/lib/ACSErrTypeTest.jar:/alma/ACS-3.0/ACSSW/lib/acsexmplAmsSeqAbeans.jar:/alma/ACS-3.0/ACSSW/lib/acsexmplAmsSeq.jar:/alma/ACS-3.0/ACSSW/lib/acsexmplBuildingAbeans.jar:/alma/ACS-3.0/ACSSW/lib/acsexmplBuilding.jar:/alma/ACS-3.0/ACSSW/lib/acsexmplCalendarAbeans.jar:/alma/ACS-3.0/ACSSW/lib/acsexmplCalendar.jar:/alma/ACS-3.0/ACSSW/lib/acsexmplFridgeAbeans.jar:/alma/ACS-3.0/ACSSW/lib/acsexmplFridge.jar:/alma/ACS-3.0/ACSSW/lib/acsexmplHelloWorldAbeans.jar:/alma/ACS-3.0/ACSSW/lib/acsexmplHelloWorld.jar:/alma/ACS-3.0/ACSSW/lib/acsexmplLampAbeans.jar:/alma/ACS-3.0/ACSSW/lib/acsexmplLamp.jar:/alma/ACS-3.0/ACSSW/lib/acsexmplMountAbeans.jar:/alma/ACS-3.0/ACSSW/lib/acsexmplMount.jar:/alma/ACS-3.0/ACSSW/lib/acsexmplPowerSupplyAbeans.jar:/alma/ACS-3.0/ACSSW/lib/acsexmplPowerSupply.jar:/alma/ACS-3.0/ACSSW/lib/acsexmplRampedPowerSupplyAbeans.jar:/alma/ACS-3.0/ACSSW/lib/acsexmplRampedPowerSupply.jar:/alma/ACS-3.0/ACSSW/lib/acsjlog.jar:/alma/ACS-3.0/ACSSW/lib/acslog.jar:/alma/ACS-3.0/ACSSW/lib/acsnc.jar:/alma/ACS-3.0/ACSSW/lib/acspytest.jar:/alma/ACS-3.0/ACSSW/lib/acssamp.jar:/alma/ACS-3.0/ACSSW/lib/acsTestEntities.jar:/alma/ACS-3.0/ACSSW/lib/ACSTimeError.jar:/alma/ACS-3.0/ACSSW/lib/acstime.jar:/alma/ACS-3.0/ACSSW/lib/activation.jar:/alma/ACS-3.0/ACSSW/lib/AlmaAdminIF.jar:/alma/ACS-3.0/ACSSW/lib/AntennaNumberMap.jar:/alma/ACS-3.0/ACSSW/lib/antlr.jar:/alma/ACS-3.0/ACSSW/lib/archive_administration_if.jar:/alma/ACS-3.0/ACSSW/lib/archive_database.jar:/alma/ACS-3.0/ACSSW/lib/archive.jar:/alma/ACS-3.0/ACSSW/lib/archive_manager.jar:/alma/ACS-3.0/ACSSW/lib/ArchivePipeline.jar:/alma/ACS-3.0/ACSSW/lib/ArchivePipelineJar.jar:/alma/ACS-3.0/ACSSW/lib/archive_xmlstore_if.jar:/alma/ACS-3.0/ACSSW/lib/ArrayTime.jar:/alma/ACS-3.0/ACSSW/lib/avalon-framework.jar:/alma/ACS-3.0/ACSSW/lib/baci.jar:/alma/ACS-3.0/ACSSW/lib/bulk_stream_if.jar:/alma/ACS-3.0/ACSSW/lib/bulk_stream_store.jar:/alma/ACS-3.0/ACSSW/lib/CCC_Monitor.jar:/alma/ACS-3.0/ACSSW/lib/CDBBrowser.jar:/alma/ACS-3.0/ACSSW/lib/cdbDAL.jar:/alma/ACS-3.0/ACSSW/lib/CDB.jar:/alma/ACS-3.0/ACSSW/lib/CDP_Control.jar:/alma/ACS-3.0/ACSSW/lib/CDP_Maintenance.jar:/alma/ACS-3.0/ACSSW/lib/CDP_Monitor.jar:/alma/ACS-3.0/ACSSW/lib/ChannelStatus.jar:/alma/ACS-3.0/ACSSW/lib/commons-collections-3.0.jar:/alma/ACS-3.0/ACSSW/lib/commons-dbcp-1.1.jar:/alma/ACS-3.0/ACSSW/lib/commons-fileupload-1.0.jar:/alma/ACS-3.0/ACSSW/lib/commons-logging-1.0.1.jar:/alma/ACS-3.0/ACSSW/lib/commons-logging.jar:/alma/ACS-3.0/ACSSW/lib/commons-pool-1.1.jar:/alma/ACS-3.0/ACSSW/lib/comphelpgen.jar:/alma/ACS-3.0/ACSSW/lib/ComponentLifeCycle.jar:/alma/ACS-3.0/ACSSW/lib/concurrent.jar:/alma/ACS-3.0/ACSSW/lib/ConfigurationValidatorImpl.jar:/alma/ACS-3.0/ACSSW/lib/ConfigurationValidator.jar:/alma/ACS-3.0/ACSSW/lib/ControlEntities.jar:/alma/ACS-3.0/ACSSW/lib/ControlInterfaces.jar:/alma/ACS-3.0/ACSSW/lib/Control.jar:/alma/ACS-3.0/ACSSW/lib/CorrXMLEntity.jar:/alma/ACS-3.0/ACSSW/lib/cosyframework.jar:/alma/ACS-3.0/ACSSW/lib/cosyicons.jar:/alma/ACS-3.0/ACSSW/lib/db2jcc.jar:/alma/ACS-3.0/ACSSW/lib/db2jcc_license_cisuz.jar:/alma/ACS-3.0/ACSSW/lib/DelayServerImpl.jar:/alma/ACS-3.0/ACSSW/lib/DelayServer.jar:/alma/ACS-3.0/ACSSW/lib/diva.jar:/alma/ACS-3.0/ACSSW/lib/EventComponent.jar:/alma/ACS-3.0/ACSSW/lib/execApplications.jar:/alma/ACS-3.0/ACSSW/lib/execCommon.jar:/alma/ACS-3.0/ACSSW/lib/ExecEntities.jar:/alma/ACS-3.0/ACSSW/lib/execMaster.jar:/alma/ACS-3.0/ACSSW/lib/exist.jar:/alma/ACS-3.0/ACSSW/lib/fits.jar:/alma/ACS-3.0/ACSSW/lib/getTelCalResultsImpl.jar:/alma/ACS-3.0/ACSSW/lib/hcompress.jar:/alma/ACS-3.0/ACSSW/lib/HelloDemo.jar:/alma/ACS-3.0/ACSSW/lib/icons.jar:/alma/ACS-3.0/ACSSW/lib/image.jar:/alma/ACS-3.0/ACSSW/lib/infobus.jar:/alma/ACS-3.0/ACSSW/lib/IntegrationEvent.jar:/alma/ACS-3.0/ACSSW/lib/j2ssh-core-0.2.6.jar:/alma/ACS-3.0/ACSSW/lib/jACSCommon.jar:/alma/ACS-3.0/ACSSW/lib/jACSUtil.jar:/alma/ACS-3.0/ACSSW/lib/jai_codec.jar:/alma/ACS-3.0/ACSSW/lib/jai_core.jar:/alma/ACS-3.0/ACSSW/lib/jakarta-oro-2.0.5.jar:/alma/ACS-3.0/ACSSW/lib/jakarta-oro-2.0.6.jar:/alma/ACS-3.0/ACSSW/lib/jakarta-regexp-1.2.jar:/alma/ACS-3.0/ACSSW/lib/jaxen-full.jar:/alma/ACS-3.0/ACSSW/lib/jcchart451K.jar:/alma/ACS-3.0/ACSSW/lib/jcommon.jar:/alma/ACS-3.0/ACSSW/lib/jcontexmpl.jar:/alma/ACS-3.0/ACSSW/lib/jcont.jar:/alma/ACS-3.0/ACSSW/lib/jcontnc.jar:/alma/ACS-3.0/ACSSW/lib/jdom.jar:/alma/ACS-3.0/ACSSW/lib/jel.jar:/alma/ACS-3.0/ACSSW/lib/jfreechart.jar:/alma/ACS-3.0/ACSSW/lib/jManagerConfig.jar:/alma/ACS-3.0/ACSSW/lib/jManager.jar:/alma/ACS-3.0/ACSSW/lib/jnlp.jar:/alma/ACS-3.0/ACSSW/lib/jsky.jar:/alma/ACS-3.0/ACSSW/lib/jta.jar:/alma/ACS-3.0/ACSSW/lib/junit.jar:/alma/ACS-3.0/ACSSW/lib/jython.jar:/alma/ACS-3.0/ACSSW/lib/LampAccess.jar:/alma/ACS-3.0/ACSSW/lib/LampCallback.jar:/alma/ACS-3.0/ACSSW/lib/lc.jar:/alma/ACS-3.0/ACSSW/lib/log4j.jar:/alma/ACS-3.0/ACSSW/lib/logkit.jar:/alma/ACS-3.0/ACSSW/lib/maci.jar:/alma/ACS-3.0/ACSSW/lib/MailerIF.jar:/alma/ACS-3.0/ACSSW/lib/mail.jar:/alma/ACS-3.0/ACSSW/lib/Maintenance.jar:/alma/ACS-3.0/ACSSW/lib/mlibwrapper_jai.jar:/alma/ACS-3.0/ACSSW/lib/monitor_stream_if.jar:/alma/ACS-3.0/ACSSW/lib/monitor_stream_store.jar:/alma/ACS-3.0/ACSSW/lib/ObservationControl.jar:/alma/ACS-3.0/ACSSW/lib/ObservationQuery.jar:/alma/ACS-3.0/ACSSW/lib/ObservingTool.jar:/alma/ACS-3.0/ACSSW/lib/ObsPrepEntities.jar:/alma/ACS-3.0/ACSSW/lib/oe.jar:/alma/ACS-3.0/ACSSW/lib/OffLineOperation.jar:/alma/ACS-3.0/ACSSW/lib/openorb13Debug.jar:/alma/ACS-3.0/ACSSW/lib/OperatorIF.jar:/alma/ACS-3.0/ACSSW/lib/otproto.jar:/alma/ACS-3.0/ACSSW/lib/ParameterTuning.jar:/alma/ACS-3.0/ACSSW/lib/PathCorrResult.jar:/alma/ACS-3.0/ACSSW/lib/prevayler-1.02.001.jar:/alma/ACS-3.0/ACSSW/lib/ProjectRepositoryIF.jar:/alma/ACS-3.0/ACSSW/lib/ProjectRepository.jar:/alma/ACS-3.0/ACSSW/lib/QlPipeline.jar:/alma/ACS-3.0/ACSSW/lib/QlPipelineJar.jar:/alma/ACS-3.0/ACSSW/lib/QuickLookEntities.jar:/alma/ACS-3.0/ACSSW/lib/resolver-20030708.jar:/alma/ACS-3.0/ACSSW/lib/saxpath.jar:/alma/ACS-3.0/ACSSW/lib/SchedPlanningModeSimulator.jar:/alma/ACS-3.0/ACSSW/lib/SchedulingEntities.jar:/alma/ACS-3.0/ACSSW/lib/SchedulingInterfaces.jar:/alma/ACS-3.0/ACSSW/lib/scheduling.jar:/alma/ACS-3.0/ACSSW/lib/SciencePipeline.jar:/alma/ACS-3.0/ACSSW/lib/SciencePipelineJar.jar:/alma/ACS-3.0/ACSSW/lib/SecurityIF.jar:/alma/ACS-3.0/ACSSW/lib/servlet.jar:/alma/ACS-3.0/ACSSW/lib/skinlf.jar:/alma/ACS-3.0/ACSSW/lib/SubArray.jar:/alma/ACS-3.0/ACSSW/lib/systementities.jar:/alma/ACS-3.0/ACSSW/lib/tablelayout.jar:/alma/ACS-3.0/ACSSW/lib/telcalArchiveImpl.jar:/alma/ACS-3.0/ACSSW/lib/TelCalArchive.jar:/alma/ACS-3.0/ACSSW/lib/TelCalEntities.jar:/alma/ACS-3.0/ACSSW/lib/TelCalPublisher.jar:/alma/ACS-3.0/ACSSW/lib/TelCalReceivedNC.jar:/alma/ACS-3.0/ACSSW/lib/TelCalResults.jar:/alma/ACS-3.0/ACSSW/lib/UserAdminIF.jar:/alma/ACS-3.0/ACSSW/lib/UserAdminPrivilegedIF.jar:/alma/ACS-3.0/ACSSW/lib/UserInfoIF.jar:/alma/ACS-3.0/ACSSW/lib/util.jar:/alma/ACS-3.0/ACSSW/lib/xindice-1.1b.jar:/alma/ACS-3.0/ACSSW/lib/XmlComponent.jar:/alma/ACS-3.0/ACSSW/lib/xmldb.jar:/alma/ACS-3.0/ACSSW/lib/xmlentity.jar:/alma/ACS-3.0/ACSSW/lib/xmlidl.jar:/alma/ACS-3.0/ACSSW/lib/xmljbind.jar:/alma/ACS-3.0/ACSSW/lib/xmlrpc-1.2.jar:/alma/ACS-3.0/JacORB/lib/jacorb.jar:/alma/ACS-3.0/JacORB/lib/idl.jar::/alma/ACS-3.0/acsdata/config/abeans/Config:/alma/ACS-3.0/acsdata/config -Djava.endorsed.dirs=/alma/ACS-3.0/ACSSW/lib/endorsed: -Dorg.omg.CORBA.ORBClass=org.jacorb.orb.ORB -Dorg.omg.CORBA.ORBSingletonClass=org.jacorb.orb.ORBSingleton -Duser.timezone=UTC -Dabeans.home=/alma/ACS-3.0/acsdata/config/abeans/Config -DACS.manager=corbaloc::te49:3000/Manager -DORBInitRef.NameService=corbaloc::te49:3001/NameService -DACS.repository=corbaloc::te49:3004/InterfaceRepository -DACS.tmp=/alma/ACS-3.0/acsdata/tmp/ACS_INSTANCE.0 -DACS.baseport=0 -Dalma.MicroArchive.DbDir=/alma/ACS-3.0/acsdata/config/MicroArchive alma.acs.container.AcsContainerRunner -containerName frodoContainer -OAport 3050
May 26, 2004 7:09:51 AM alma.acs.container.AcsContainerRunner run
INFO: AcsContainerRunner#run
May 26, 2004 7:09:51 AM alma.acs.container.corba.AcsCorba initCorba
FINER: ENTRY
May 26, 2004 7:09:51 AM alma.acs.container.corba.AcsCorba initCorba
FINER: ORB options -containerName frodoContainer -OAport 3050 ORB properties: {org.omg.CORBA.ORBClass=org.jacorb.orb.ORB, OAPort=3050, org.omg.CORBA.ORBSingletonClass=org.jacorb.orb.ORBSingleton}
JacORB V 1.4.1, www.jacorb.org
(C) Gerald Brose, FU Berlin/XTRADYNE Technologies, July 2002
May 26, 2004 7:09:51 AM alma.acs.container.corba.AcsCorba initCorba
FINER: ORB initialized.
[ POA RootPOA - ready ]
May 26, 2004 7:09:51 AM alma.acs.container.corba.AcsCorba initRootPOA
FINEST: RootPOA initialized.
[ POA ContainerPOA - ready ]
May 26, 2004 7:09:51 AM alma.acs.container.corba.AcsCorba initPOAForContainer
FINEST: ContainerPOA created.
[ POA ComponentPOA - ready ]
May 26, 2004 7:09:51 AM alma.acs.container.corba.AcsCorba initPOAForComponents
FINEST: ComponentPOA created.
May 26, 2004 7:09:51 AM alma.acs.container.corba.AcsCorba initCorba
FINER: RETURN
May 26, 2004 7:09:51 AM alma.acs.container.AcsManagerProxy getManager
FINE: Manager reference not available. Trying to resolve...
May 26, 2004 7:09:51 AM alma.acs.container.AcsManagerProxy findManager
FINEST: manager corbaloc 'corbaloc::te49:3000/Manager' resolved.
[ Connected to 134.171.12.100:3000 ]
May 26, 2004 7:09:52 AM alma.acs.container.AcsManagerProxy findManager
FINEST: manager narrow successful.
May 26, 2004 7:09:52 AM alma.acs.container.AcsContainerRunner createContainer
FINE: creating the AcsContainer frodoContainer
May 26, 2004 7:09:52 AM alma.acs.container.corba.AcsCorba activateContainer
FINER: entering activateContainer name=frodoContainer
May 26, 2004 7:09:52 AM alma.acs.container.AcsContainer registerWithCorba
FINER: AcsContainer successfully registered with the ORB as a Container
May 26, 2004 7:09:52 AM alma.acs.container.AcsContainerRunner createContainer
FINE: AcsContainer 'frodoContainer' created.
May 26, 2004 7:09:52 AM alma.acs.container.AcsContainerRunner initAcsLogging
FINE: init ACS logging...
[ Connected to 134.171.12.100:3003 ]
May 26, 2004 7:09:52 AM alma.acs.logging.ClientLogManager init
FINE: CORBA logging service handle obtained.
May 26, 2004 7:09:52 AM alma.acs.container.AcsContainerRunner initAcsLogging
FINE: done init ACS logging
May 26, 2004 7:09:52 AM alma.acs.container.AcsContainer name
FINE: call to name() answered with 'frodoContainer'.
May 26, 2004 7:09:52 AM alma.acs.container.AcsContainer authenticate
FINE: call to authenticate() answered with 'A frodoContainer'.
May 26, 2004 7:09:52 AM alma.acs.container.AcsContainer name
FINE: call to name() answered with 'frodoContainer'.
May 26, 2004 7:09:52 AM alma.acs.container.AcsManagerProxy loginToManager
FINE: Manager login done, handle '81002497' obtained.
May 26, 2004 7:09:52 AM alma.acs.container.AcsContainerRunner run
FINE: entering orb loop
May 26, 2004 7:09:52 AM alma.acs.util.StopWatch logLapTime
FINE: elapsed time in ms to start the container: 1089
May 26, 2004 7:09:55 AM alma.acs.container.AcsContainer message
INFO: Info message from the manager: Startup statistics: 5 components queued to be activated.
May 26, 2004 7:09:55 AM alma.acs.container.AcsContainer activate_component
INFO: <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
May 26, 2004 7:09:55 AM alma.acs.container.AcsContainer activate_component
INFO: activate_component: handle=16777217 name=GETTELCALRESULTS1 helperClass=alma.TelCalPublisher.GetTelCalResultsImpl.GetTelCalResultsHelper type=IDL:alma/TelCalPublisher/GetTelCalResults:1.0
May 26, 2004 7:09:55 AM alma.acs.container.AcsContainer createComponentHelper
FINER: creating component helper instance of type alma.TelCalPublisher.GetTelCalResultsImpl.GetTelCalResultsHelper
May 26, 2004 7:09:55 AM alma.acs.container.ComponentHelper getComponentImpl
FINER: component implementation class 'alma.TelCalPublisher.GetTelCalResultsImpl.GetTelCalResultsImpl' instantiated.
May 26, 2004 7:09:55 AM alma.acs.container.AcsContainer activate_component
FINER: component GETTELCALRESULTS1 implements operations interface directly; no dynamic translator proxy used.
[ POA ComponentPOAGETTELCALRESULTS1 - ready ]
May 26, 2004 7:09:55 AM alma.acs.container.ComponentAdapter activateComponent
FINER: entering ComponentAdapter#activateComponent for GETTELCALRESULTS1
May 26, 2004 7:09:55 AM alma.acs.container.corba.AcsCorba activateComponent
FINER: entering activateComponent: name=GETTELCALRESULTS1
May 26, 2004 7:09:55 AM alma.acs.container.corba.AcsCorba activateComponent
FINER: component 'GETTELCALRESULTS1' activated as CORBA object.
May 26, 2004 7:09:55 AM alma.acs.container.ComponentAdapter _getInterfaces
FINE: interfaces of component 'GETTELCALRESULTS1': IDL:alma/TelCalPublisher/GetTelCalResults:1.0IDL:alma/ACS/ACSComponent:1.0IDL:omg.org/CORBA/Object:1.0
May 26, 2004 7:09:55 AM alma.acs.container.AcsContainer activate_component
FINE: about to initialize component GETTELCALRESULTS1
May 26, 2004 7:09:55 AM alma.acs.container.ComponentStateManagerImpl setState
FINER: switching state of component GETTELCALRESULTS1 from NEW to INITIALIZING
May 26, 2004 7:09:55 AM alma.acs.logging.ClientLogManager getLoggerForComponent
FINE: a logger for component .GETTELCALRESULTS1 is available.
May 26, 2004 7:09:55 AM alma.TelCalPublisher.GetTelCalResultsImpl.GetTelCalResultsImpl initialize
INFO: initialize() called...
May 26, 2004 7:09:55 AM alma.acs.container.ContainerServicesImpl getComponent
FINE: will retrieve remote component 'ARCHIVE_CONNECTION' using ACS Manager#get_component
May 26, 2004 7:09:55 AM alma.acs.container.AcsContainer activate_component
INFO: <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
May 26, 2004 7:09:55 AM alma.acs.container.AcsContainer activate_component
INFO: activate_component: handle=16777218 name=ARCHIVE_CONNECTION helperClass=alma.archive.helpers.ArchiveConnectionHelper type=IDL:alma/xmlstore/ArchiveConnection:1.0
May 26, 2004 7:09:55 AM alma.acs.container.AcsContainer createComponentHelper
FINER: creating component helper instance of type alma.archive.helpers.ArchiveConnectionHelper
May 26, 2004 7:09:55 AM alma.acs.container.ComponentHelper getComponentImpl
FINER: component implementation class 'alma.archive.components.ArchiveConnectionImpl' instantiated.
May 26, 2004 7:09:55 AM alma.acs.container.AcsContainer activate_component
FINER: component ARCHIVE_CONNECTION implements operations interface directly; no dynamic translator proxy used.
[ POA ComponentPOAARCHIVE_CONNECTION - ready ]
May 26, 2004 7:09:55 AM alma.acs.container.ComponentAdapter activateComponent
FINER: entering ComponentAdapter#activateComponent for ARCHIVE_CONNECTION
May 26, 2004 7:09:55 AM alma.acs.container.corba.AcsCorba activateComponent
FINER: entering activateComponent: name=ARCHIVE_CONNECTION
May 26, 2004 7:09:55 AM alma.acs.container.corba.AcsCorba activateComponent
FINER: component 'ARCHIVE_CONNECTION' activated as CORBA object.
May 26, 2004 7:09:55 AM alma.acs.container.ComponentAdapter _getInterfaces
FINE: interfaces of component 'ARCHIVE_CONNECTION': IDL:alma/xmlstore/ArchiveConnection:1.0IDL:omg.org/CORBA/Object:1.0
May 26, 2004 7:09:55 AM alma.acs.container.AcsContainer activate_component
FINE: about to initialize component ARCHIVE_CONNECTION
May 26, 2004 7:09:55 AM alma.acs.container.ComponentStateManagerImpl setState
FINER: switching state of component ARCHIVE_CONNECTION from NEW to INITIALIZING
May 26, 2004 7:09:55 AM alma.acs.logging.ClientLogManager getLoggerForComponent
FINE: a logger for component .ARCHIVE_CONNECTION is available.
May 26, 2004 7:09:55 AM alma.acs.container.ComponentStateManagerImpl setState
FINER: switching state of component ARCHIVE_CONNECTION from INITIALIZING to INITIALIZED
May 26, 2004 7:09:55 AM alma.acs.container.ComponentStateManagerImpl setState
FINER: switching state of component ARCHIVE_CONNECTION from INITIALIZED to OPERATIONAL
May 26, 2004 7:09:55 AM alma.acs.container.AcsContainer activate_component
INFO: component ARCHIVE_CONNECTION activated and initialized in 43 ms.
May 26, 2004 7:09:55 AM alma.acs.container.AcsContainer activate_component
INFO: >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
May 26, 2004 7:09:55 AM alma.acs.container.ContainerServicesImpl getComponent
FINE: component ARCHIVE_CONNECTION retrieved successfully.
May 26, 2004 7:09:55 AM alma.acs.container.ContainerSealant invoke
INFO: intercepted a call to 'ARCHIVE_CONNECTION#getOperational'...
May 26, 2004 7:09:55 AM alma.archive.database.helpers.DBConfiguration searchConfigFile
WARNING: Property archive.config.file not set, using default config file: /alma/ACS-3.0/acsdata/config/dbConfig.xml
May 26, 2004 7:09:55 AM alma.archive.database.helpers.DBConfiguration readConfig
INFO: Setting database configuration.
May 26, 2004 7:09:56 AM alma.archive.database.helpers.DBConfiguration readConfig
INFO: Using database backend xindice
May 26, 2004 7:09:56 AM alma.archive.database.helpers.DBConfiguration searchConfigFile
WARNING: Property archive.config.file not set, using default config file: /alma/ACS-3.0/acsdata/config/dbConfig.xml
May 26, 2004 7:09:56 AM alma.archive.database.helpers.DBConfiguration readConfig
INFO: Setting database configuration.
May 26, 2004 7:09:56 AM alma.archive.database.helpers.DBConfiguration readConfig
INFO: Using database backend xindice
May 26, 2004 7:09:56 AM alma.archive.database.xmldb.XmldbConnector setLocation
INFO: Xindice home set to /alma/ACS-3.0/acsdata/config/MicroArchive
0 [RequestProcessor-5] INFO client.embed - No configuration file specified, going with the default configuration
144 [RequestProcessor-5] INFO client.embed - Database name: 'db'
144 [RequestProcessor-5] INFO xindice.core - Database points to /alma/ACS-3.0/acsdata/config/MicroArchive/./db
May 26, 2004 7:09:56 AM alma.archive.database.helpers.DBConfiguration searchConfigFile
WARNING: Property archive.config.file not set, using default config file: /alma/ACS-3.0/acsdata/config/dbConfig.xml
May 26, 2004 7:09:56 AM alma.archive.database.helpers.DBConfiguration readConfig
INFO: Setting database configuration.
May 26, 2004 7:09:56 AM alma.archive.database.helpers.DBConfiguration readConfig
INFO: Using database backend xindice
May 26, 2004 7:09:56 AM alma.archive.components.OperationalImpl connect
INFO: Connected to the internal interface
May 26, 2004 7:09:56 AM alma.acs.logging.ClientLogManager getLoggerForComponent
FINE: a logger for component .ARCHIVE_CONNECTION is available.
May 26, 2004 7:09:56 AM alma.archive.commands.ListenerManager load
INFO: ARCHIVE: Problem retriving the string
May 26, 2004 7:09:56 AM alma.archive.components.OperationalImpl connect
INFO: Connected to the Liatener Manager
May 26, 2004 7:09:56 AM alma.archive.commands.PathManager load
INFO: ARCHIVE: Problem retriving the string
May 26, 2004 7:09:56 AM alma.acs.container.corba.AcsCorba createPOAForOffshoots
FINEST: will have to create offshoot POA
[ POA offshootPoa - ready ]
May 26, 2004 7:09:56 AM alma.acs.container.corba.AcsCorba createPOAForOffshoots
FINEST: successfully created offshoot POA
May 26, 2004 7:09:56 AM alma.acs.container.corba.AcsCorba activateOffShoot
FINER: offshoot of type 'alma.archive.components.OperationalImpl' activated as a CORBA object.
May 26, 2004 7:09:56 AM alma.acs.container.ContainerSealant invoke
INFO: returning from ARCHIVE_CONNECTION#getOperational after 1036 ms.
JacORB V 1.4.1, www.jacorb.org
(C) Gerald Brose, FU Berlin/XTRADYNE Technologies, July 2002
[ POA RootPOA - ready ]
[ Connected to 134.171.12.100:3001 ]
[ Connected to 134.171.12.100:3001 ]
Attempting to create the TelCalPublisherEventNC channel.
[ Connected to 134.171.12.100:3002 ]
May 26, 2004 7:09:57 AM alma.acs.container.ComponentStateManagerImpl setState
FINER: switching state of component GETTELCALRESULTS1 from INITIALIZING to INITIALIZED
May 26, 2004 7:09:57 AM alma.TelCalPublisher.GetTelCalResultsImpl.GetTelCalResultsImpl execute
INFO: execute() called...
May 26, 2004 7:09:57 AM alma.acs.container.ComponentStateManagerImpl setState
FINER: switching state of component GETTELCALRESULTS1 from INITIALIZED to OPERATIONAL
May 26, 2004 7:09:57 AM alma.acs.container.AcsContainer activate_component
INFO: component GETTELCALRESULTS1 activated and initialized in 1578 ms.
May 26, 2004 7:09:57 AM alma.acs.container.AcsContainer activate_component
INFO: >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
May 26, 2004 7:09:57 AM alma.acs.container.AcsContainer activate_component
INFO: <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
May 26, 2004 7:09:57 AM alma.acs.container.AcsContainer activate_component
INFO: activate_component: handle=16777219 name=IDENTIFIER_ARCHIVE helperClass=alma.archive.helpers.IdentifierHelper type=IDL:alma/xmlstore/Identifier:1.0
May 26, 2004 7:09:57 AM alma.acs.container.AcsContainer createComponentHelper
FINER: creating component helper instance of type alma.archive.helpers.IdentifierHelper
May 26, 2004 7:09:57 AM alma.acs.container.ComponentHelper getComponentImpl
FINER: component implementation class 'alma.archive.components.IdentifierImpl' instantiated.
May 26, 2004 7:09:57 AM alma.acs.container.AcsContainer activate_component
FINER: component IDENTIFIER_ARCHIVE implements operations interface directly; no dynamic translator proxy used.
[ POA ComponentPOAIDENTIFIER_ARCHIVE - ready ]
May 26, 2004 7:09:57 AM alma.acs.container.ComponentAdapter activateComponent
FINER: entering ComponentAdapter#activateComponent for IDENTIFIER_ARCHIVE
May 26, 2004 7:09:57 AM alma.acs.container.corba.AcsCorba activateComponent
FINER: entering activateComponent: name=IDENTIFIER_ARCHIVE
May 26, 2004 7:09:57 AM alma.acs.container.corba.AcsCorba activateComponent
FINER: component 'IDENTIFIER_ARCHIVE' activated as CORBA object.
May 26, 2004 7:09:57 AM alma.acs.container.ComponentAdapter _getInterfaces
FINE: interfaces of component 'IDENTIFIER_ARCHIVE': IDL:alma/xmlstore/Identifier:1.0IDL:alma/ACS/ACSComponent:1.0IDL:omg.org/CORBA/Object:1.0
May 26, 2004 7:09:57 AM alma.acs.container.AcsContainer activate_component
FINE: about to initialize component IDENTIFIER_ARCHIVE
May 26, 2004 7:09:57 AM alma.acs.container.ComponentStateManagerImpl setState
FINER: switching state of component IDENTIFIER_ARCHIVE from NEW to INITIALIZING
May 26, 2004 7:09:57 AM alma.acs.logging.ClientLogManager getLoggerForComponent
FINE: a logger for component .IDENTIFIER_ARCHIVE is available.
May 26, 2004 7:09:57 AM alma.archive.components.IdentifierImpl connect
INFO: Connecting to the identifier manager
May 26, 2004 7:09:57 AM alma.archive.database.helpers.DBConfiguration searchConfigFile
WARNING: Property archive.config.file not set, using default config file: /alma/ACS-3.0/acsdata/config/dbConfig.xml
May 26, 2004 7:09:57 AM alma.archive.database.helpers.DBConfiguration readConfig
INFO: Setting database configuration.
May 26, 2004 7:09:57 AM alma.archive.database.helpers.DBConfiguration readConfig
INFO: Using database backend xindice
May 26, 2004 7:09:57 AM alma.archive.components.IdentifierImpl connect
INFO: Connected to the identifier manager
May 26, 2004 7:09:57 AM alma.acs.container.ComponentStateManagerImpl setState
FINER: switching state of component IDENTIFIER_ARCHIVE from INITIALIZING to INITIALIZED
May 26, 2004 7:09:57 AM alma.acs.container.ComponentStateManagerImpl setState
FINER: switching state of component IDENTIFIER_ARCHIVE from INITIALIZED to OPERATIONAL
May 26, 2004 7:09:57 AM alma.acs.container.AcsContainer activate_component
INFO: component IDENTIFIER_ARCHIVE activated and initialized in 38 ms.
May 26, 2004 7:09:57 AM alma.acs.container.AcsContainer activate_component
INFO: >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
May 26, 2004 7:09:57 AM alma.acs.container.AcsContainer activate_component
INFO: <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
May 26, 2004 7:09:57 AM alma.acs.container.AcsContainer activate_component
INFO: activate_component: handle=16777220 name=ControlSystem1 helperClass=alma.Control.masterController.ControlSystemHelper type=IDL:alma/Control/ControlSystem:1.0
May 26, 2004 7:09:57 AM alma.acs.container.AcsContainer createComponentHelper
FINER: creating component helper instance of type alma.Control.masterController.ControlSystemHelper
May 26, 2004 7:09:57 AM alma.acs.container.ComponentHelper getComponentImpl
FINER: component implementation class 'alma.Control.masterController.ControlSystemImpl' instantiated.
May 26, 2004 7:09:57 AM alma.acs.container.AcsContainer activate_component
FINER: component ControlSystem1 implements operations interface directly; no dynamic translator proxy used.
[ POA ComponentPOAControlSystem1 - ready ]
May 26, 2004 7:09:57 AM alma.acs.container.ComponentAdapter activateComponent
FINER: entering ComponentAdapter#activateComponent for ControlSystem1
May 26, 2004 7:09:57 AM alma.acs.container.corba.AcsCorba activateComponent
FINER: entering activateComponent: name=ControlSystem1
May 26, 2004 7:09:57 AM alma.acs.container.corba.AcsCorba activateComponent
FINER: component 'ControlSystem1' activated as CORBA object.
May 26, 2004 7:09:57 AM alma.acs.container.ComponentAdapter _getInterfaces
FINE: interfaces of component 'ControlSystem1': IDL:alma/Control/ControlSystem:1.0IDL:alma/ACS/ACSComponent:1.0IDL:alma/Control/ControlStatus:1.0IDL:omg.org/CORBA/Object:1.0
May 26, 2004 7:09:57 AM alma.acs.container.AcsContainer activate_component
FINE: about to initialize component ControlSystem1
May 26, 2004 7:09:57 AM alma.acs.container.ComponentStateManagerImpl setState
FINER: switching state of component ControlSystem1 from NEW to INITIALIZING
May 26, 2004 7:09:57 AM alma.acs.logging.ClientLogManager getLoggerForComponent
FINE: a logger for component .ControlSystem1 is available.
May 26, 2004 7:09:57 AM alma.Control.masterController.ControlStatusImpl initialize
INFO: initialize() called...
Attempting to create the CONTROLSYSTEM channel.
May 26, 2004 7:09:57 AM alma.acs.container.ComponentStateManagerImpl setState
FINER: switching state of component ControlSystem1 from INITIALIZING to INITIALIZED
May 26, 2004 7:09:57 AM alma.Control.masterController.ControlStatusImpl execute
INFO: execute() called...
May 26, 2004 7:09:57 AM alma.acs.container.ComponentStateManagerImpl setState
FINER: switching state of component ControlSystem1 from INITIALIZED to OPERATIONAL
May 26, 2004 7:09:57 AM alma.acs.container.AcsContainer activate_component
INFO: component ControlSystem1 activated and initialized in 93 ms.
May 26, 2004 7:09:57 AM alma.acs.container.AcsContainer activate_component
INFO: >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
May 26, 2004 7:09:57 AM alma.acs.container.AcsContainer activate_component
INFO: <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
May 26, 2004 7:09:57 AM alma.acs.container.AcsContainer activate_component
INFO: activate_component: handle=16777221 name=SCIENCE_PIPELINE helperClass=alma.pipelinescience.components.SciencePipelineHelper type=IDL:alma/pipelinescience/SciencePipeline:1.0
May 26, 2004 7:09:57 AM alma.acs.container.AcsContainer createComponentHelper
FINER: creating component helper instance of type alma.pipelinescience.components.SciencePipelineHelper
May 26, 2004 7:09:57 AM alma.acs.container.ComponentHelper getComponentImpl
FINER: component implementation class 'alma.pipelinescience.components.SciencePipelineImpl' instantiated.
May 26, 2004 7:09:57 AM alma.acs.container.AcsContainer activate_component
FINER: component SCIENCE_PIPELINE implements operations interface directly; no dynamic translator proxy used.
[ POA ComponentPOASCIENCE_PIPELINE - ready ]
May 26, 2004 7:09:57 AM alma.acs.container.ComponentAdapter activateComponent
FINER: entering ComponentAdapter#activateComponent for SCIENCE_PIPELINE
May 26, 2004 7:09:57 AM alma.acs.container.corba.AcsCorba activateComponent
FINER: entering activateComponent: name=SCIENCE_PIPELINE
May 26, 2004 7:09:57 AM alma.acs.container.corba.AcsCorba activateComponent
FINER: component 'SCIENCE_PIPELINE' activated as CORBA object.
May 26, 2004 7:09:57 AM alma.acs.container.ComponentAdapter _getInterfaces
FINE: interfaces of component 'SCIENCE_PIPELINE': IDL:alma/pipelinescience/SciencePipeline:1.0IDL:alma/ACS/ACSComponent:1.0IDL:omg.org/CORBA/Object:1.0
May 26, 2004 7:09:57 AM alma.acs.container.AcsContainer activate_component
FINE: about to initialize component SCIENCE_PIPELINE
May 26, 2004 7:09:57 AM alma.acs.container.ComponentStateManagerImpl setState
FINER: switching state of component SCIENCE_PIPELINE from NEW to INITIALIZING
May 26, 2004 7:09:57 AM alma.acs.logging.ClientLogManager getLoggerForComponent
FINE: a logger for component .SCIENCE_PIPELINE is available.
May 26, 2004 7:09:57 AM alma.pipelinescience.components.SciencePipelineImpl initialize
INFO: SCIENCE_PIPELINE: initialize() method called
May 26, 2004 7:09:57 AM alma.acs.container.ComponentStateManagerImpl setState
FINER: switching state of component SCIENCE_PIPELINE from INITIALIZING to INITIALIZED
May 26, 2004 7:09:57 AM alma.pipelinescience.components.SciencePipelineImpl execute
INFO: SCIENCE_PIPELINE: execute() method called
May 26, 2004 7:09:57 AM alma.acs.container.ContainerServicesImpl getComponent
FINE: will retrieve remote component 'IDENTIFIER_ARCHIVE' using ACS Manager#get_component
May 26, 2004 7:09:57 AM alma.acs.container.ContainerServicesImpl getComponent
FINE: component IDENTIFIER_ARCHIVE retrieved successfully.
May 26, 2004 7:09:57 AM alma.acs.container.ContainerServicesImpl getComponent
FINE: will retrieve remote component 'ARCHIVE_CONNECTION' using ACS Manager#get_component
May 26, 2004 7:09:57 AM alma.acs.container.ContainerServicesImpl getComponent
FINE: component ARCHIVE_CONNECTION retrieved successfully.
May 26, 2004 7:09:57 AM alma.acs.container.ContainerSealant invoke
INFO: intercepted a call to 'ARCHIVE_CONNECTION#getOperational'...
May 26, 2004 7:09:57 AM alma.archive.components.OperationalImpl connect
INFO: Connected to the internal interface
May 26, 2004 7:09:57 AM alma.archive.components.OperationalImpl connect
INFO: Connected to the Liatener Manager
May 26, 2004 7:09:57 AM alma.acs.container.corba.AcsCorba activateOffShoot
FINER: offshoot of type 'alma.archive.components.OperationalImpl' activated as a CORBA object.
May 26, 2004 7:09:57 AM alma.acs.container.ContainerSealant invoke
INFO: returning from ARCHIVE_CONNECTION#getOperational after 6 ms.
Attempting to create the sciencepipeline channel.
May 26, 2004 7:09:57 AM alma.acs.container.ComponentStateManagerImpl setState
FINER: switching state of component SCIENCE_PIPELINE from INITIALIZED to OPERATIONAL
May 26, 2004 7:09:57 AM alma.acs.container.AcsContainer activate_component
INFO: component SCIENCE_PIPELINE activated and initialized in 102 ms.
May 26, 2004 7:09:57 AM alma.acs.container.AcsContainer activate_component
INFO: >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
May 26, 2004 7:09:57 AM alma.acs.container.AcsContainer message
INFO: Info message from the manager: Startup statistics: 5 of 5 components activated.
Suppler.subscription_change(...) the 'CONTROLSYSTEM' channel: override to do something useful.
Suppler.subscription_change(...) the 'CONTROLSYSTEM' channel: override to do something useful.
May 26, 2004 7:10:20 AM alma.acs.container.ContainerSealant invoke
INFO: intercepted a call to 'IDENTIFIER_ARCHIVE#getIdNamespace'...
May 26, 2004 7:10:20 AM alma.acs.container.ContainerSealant invoke
INFO: returning from IDENTIFIER_ARCHIVE#getIdNamespace after 6 ms.
May 26, 2004 7:10:20 AM alma.acs.container.ContainerSealant invoke
INFO: intercepted a call to 'IDENTIFIER_ARCHIVE#name'...
May 26, 2004 7:10:20 AM alma.acs.container.ContainerSealant invoke
INFO: returning from IDENTIFIER_ARCHIVE#name after 1 ms.
May 26, 2004 7:10:21 AM alma.acs.container.AcsContainer activate_component
INFO: <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
May 26, 2004 7:10:21 AM alma.acs.container.AcsContainer activate_component
INFO: activate_component: handle=16777225 name=OBS_PROJ_REP helperClass=alma.ProjectRepositoryIF.LightweightProjectRepositoryImpl.LightweightProjectRepositoryHelper type=IDL:alma/ProjectRepositoryIF/LightweightProjectRepository:1.0
May 26, 2004 7:10:21 AM alma.acs.container.AcsContainer createComponentHelper
FINER: creating component helper instance of type alma.ProjectRepositoryIF.LightweightProjectRepositoryImpl.LightweightProjectRepositoryHelper
May 26, 2004 7:10:21 AM alma.acs.container.ComponentHelper getComponentImpl
FINER: component implementation class 'alma.ProjectRepositoryIF.LightweightProjectRepositoryImpl.LightweightProjectRepositoryImpl' instantiated.
May 26, 2004 7:10:21 AM alma.acs.container.AcsContainer activate_component
FINER: creating dynamic proxy to map corba interface calls to component OBS_PROJ_REP.
May 26, 2004 7:10:21 AM alma.acs.util.StopWatch logLapTime
FINE: elapsed time in ms to verify automatic translation for methods in alma.ProjectRepositoryIF.LightweightProjectRepositoryOperations: 221
[ POA ComponentPOAOBS_PROJ_REP - ready ]
May 26, 2004 7:10:21 AM alma.acs.container.ComponentAdapter activateComponent
FINER: entering ComponentAdapter#activateComponent for OBS_PROJ_REP
May 26, 2004 7:10:21 AM alma.acs.container.corba.AcsCorba activateComponent
FINER: entering activateComponent: name=OBS_PROJ_REP
May 26, 2004 7:10:21 AM alma.acs.container.corba.AcsCorba activateComponent
FINER: component 'OBS_PROJ_REP' activated as CORBA object.
May 26, 2004 7:10:21 AM alma.acs.container.ComponentAdapter _getInterfaces
FINE: interfaces of component 'OBS_PROJ_REP': IDL:alma/ProjectRepositoryIF/LightweightProjectRepository:1.0IDL:alma/ACS/ACSComponent:1.0IDL:omg.org/CORBA/Object:1.0
May 26, 2004 7:10:21 AM alma.acs.container.AcsContainer activate_component
FINE: about to initialize component OBS_PROJ_REP
May 26, 2004 7:10:21 AM alma.acs.container.ComponentStateManagerImpl setState
FINER: switching state of component OBS_PROJ_REP from NEW to INITIALIZING
May 26, 2004 7:10:21 AM alma.acs.logging.ClientLogManager getLoggerForComponent
FINE: a logger for component .OBS_PROJ_REP is available.
May 26, 2004 7:10:21 AM alma.acs.container.ContainerServicesImpl getComponent
FINE: will retrieve remote component 'ARCHIVE_CONNECTION' using ACS Manager#get_component
May 26, 2004 7:10:21 AM alma.acs.container.ContainerServicesImpl getComponent
FINE: component ARCHIVE_CONNECTION retrieved successfully.
May 26, 2004 7:10:21 AM alma.acs.container.ContainerSealant invoke
INFO: intercepted a call to 'ARCHIVE_CONNECTION#getOperational'...
May 26, 2004 7:10:21 AM alma.archive.components.OperationalImpl connect
INFO: Connected to the internal interface
May 26, 2004 7:10:21 AM alma.archive.components.OperationalImpl connect
INFO: Connected to the Liatener Manager
May 26, 2004 7:10:21 AM alma.acs.container.corba.AcsCorba activateOffShoot
FINER: offshoot of type 'alma.archive.components.OperationalImpl' activated as a CORBA object.
May 26, 2004 7:10:21 AM alma.acs.container.ContainerSealant invoke
INFO: returning from ARCHIVE_CONNECTION#getOperational after 3 ms.
May 26, 2004 7:10:21 AM alma.acs.container.ContainerSealant invoke
INFO: intercepted a call to 'ARCHIVE_CONNECTION#getAdministrative'...
May 26, 2004 7:10:21 AM alma.archive.components.AdministrativeImpl connect
INFO: Connected to the internal interface
May 26, 2004 7:10:21 AM alma.acs.container.corba.AcsCorba activateOffShoot
FINER: offshoot of type 'alma.archive.components.AdministrativeImpl' activated as a CORBA object.
May 26, 2004 7:10:21 AM alma.acs.container.ContainerSealant invoke
INFO: returning from ARCHIVE_CONNECTION#getAdministrative after 9 ms.
May 26, 2004 7:10:21 AM alma.acs.container.ComponentStateManagerImpl setState
FINER: switching state of component OBS_PROJ_REP from INITIALIZING to INITIALIZED
May 26, 2004 7:10:21 AM alma.acs.container.ComponentStateManagerImpl setState
FINER: switching state of component OBS_PROJ_REP from INITIALIZED to OPERATIONAL
May 26, 2004 7:10:21 AM alma.acs.container.AcsContainer activate_component
INFO: component OBS_PROJ_REP activated and initialized in 324 ms.
May 26, 2004 7:10:21 AM alma.acs.container.AcsContainer activate_component
INFO: >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
May 26, 2004 7:10:22 AM alma.acs.container.AcsContainer ping
FINER: ping received.
May 26, 2004 7:10:22 AM alma.acs.container.ContainerSealant invoke
INFO: intercepted a call to 'OBS_PROJ_REP#store'...
@@@@@@@@ storeWithoutPars... @@@@@@@@@@@
@@@@@ entityId: 'uid://X0000000000000065/X00000000'
@@@@@ xmlString:alma.xmlentity.XmlEntityStruct@1a0225b
<?xml version="1.0" encoding="UTF-8"?>
<ObsProject>
<ObsProjectEntity
entityIdEncrypted="-- id encryption not yet implemented --"
entityId="uid://X0000000000000065/X00000000" documentVersion="1"
entityTypeName="ObsProject" schemaVersion="1"/>
<ObsProposalRef entityId="uid://X0000000000000065/X00000001" entityTypeName="ObsProposal"/>
<ProjectName>My beautiful project</ProjectName>
<Version>1.0</Version>
<PI>Magnum P.I.</PI>
<ObsProgram code="">
<Preconditions>
<WeatherConstraints>
<Opacity></Opacity>
<Seeing></Seeing>
<PhaseStability></PhaseStability>
</WeatherConstraints>
<Polarization></Polarization>
<BaselineCal></BaselineCal>
</Preconditions>
<ObsUnitControl schedStatus="ready">
<PerformanceGoal></PerformanceGoal>
<CalibrationRequirements>
<PointingAccuracy></PointingAccuracy>
<Bandpass></Bandpass>
</CalibrationRequirements>
</ObsUnitControl>
<FlowControl controlScript=""/>
<ObsUnitSet>
<Preconditions>
<WeatherConstraints>
<Opacity></Opacity>
<Seeing></Seeing>
<PhaseStability></PhaseStability>
</WeatherConstraints>
<Polarization></Polarization>
<BaselineCal></BaselineCal>
</Preconditions>
<ObsUnitControl schedStatus="ready">
<PerformanceGoal></PerformanceGoal>
<CalibrationRequirements>
<PointingAccuracy></PointingAccuracy>
<Bandpass></Bandpass>
</CalibrationRequirements>
</ObsUnitControl>
<FlowControl controlScript=""/>
<SchedBlockRef
entityId="uid://X0000000000000065/X00000002" entityTypeName=""/>
<SchedBlockRef
entityId="uid://X0000000000000065/X00000003" entityTypeName=""/>
</ObsUnitSet>
<ObsUnitSet>
<Preconditions>
<WeatherConstraints>
<Opacity></Opacity>
<Seeing></Seeing>
<PhaseStability></PhaseStability>
</WeatherConstraints>
<Polarization></Polarization>
<BaselineCal></BaselineCal>
</Preconditions>
<ObsUnitControl schedStatus="ready">
<PerformanceGoal></PerformanceGoal>
<CalibrationRequirements>
<PointingAccuracy></PointingAccuracy>
<Bandpass></Bandpass>
</CalibrationRequirements>
</ObsUnitControl>
<FlowControl controlScript=""/>
<SchedBlockRef
entityId="uid://X0000000000000065/X00000004" entityTypeName=""/>
<SchedBlockRef
entityId="uid://X0000000000000065/X00000005" entityTypeName=""/>
</ObsUnitSet>
<TargetSpace name="First TargetSpace">
<RegionOfInterest name="">
<Circle name="Pickwick">
<Centre system="J2000">
<Longitude unit="hour">326.275</Longitude>
<Latitude unit="deg">12.698888888888888</Latitude>
</Centre>
<Radius unit="arcsec">15.0</Radius>
</Circle>
<SpectralSetup name="">
<SpectralElement name="SpectralSetupElement # 0">
<FrequencySetup name="FreqSetup # 0">
<CenterFrequency unit="GHz">335.0</CenterFrequency>
<FrequencyResolution unit="MHz">100.0</FrequencyResolution>
</FrequencySetup>
<CorrelatorSetup name="">
<Bandwidth unit="GHz">2.0</Bandwidth>
<Sensitivity unit="Jy">1.0E-5</Sensitivity>
</CorrelatorSetup>
</SpectralElement>
</SpectralSetup>
<ReductionProcedures imageScript="<default>"/>
<ObsUnitSetReference></ObsUnitSetReference>
</RegionOfInterest>
<RegionOfInterest name="">
<Circle name="Stonehenge">
<Centre system="J2000">
<Longitude unit="hour">346.66249999999997</Longitude>
<Latitude unit="deg">10.0</Latitude>
</Centre>
<Radius unit="arcsec">15.0</Radius>
</Circle>
<SpectralSetup name="">
<SpectralElement name="SpectralSetupElement # 1">
<FrequencySetup name="FreqSetup # 1">
<CenterFrequency unit="GHz">335.0</CenterFrequency>
<FrequencyResolution unit="MHz">100.0</FrequencyResolution>
</FrequencySetup>
<CorrelatorSetup name="">
<Bandwidth unit="GHz">2.0</Bandwidth>
<Sensitivity unit="Jy">1.0E-5</Sensitivity>
</CorrelatorSetup>
</SpectralElement>
</SpectralSetup>
<ReductionProcedures imageScript="<default>"/>
<ObsUnitSetReference></ObsUnitSetReference>
</RegionOfInterest>
<ObservationTime unit="s">1200.0</ObservationTime>
</TargetSpace>
<TargetSpace name="YATS">
<RegionOfInterest name="">
<Circle name="YATS 1">
<Centre system="J2000">
<Longitude unit="hour">3.845833333333333</Longitude>
<Latitude unit="deg">-32.04555555555555</Latitude>
</Centre>
<Radius unit="arcsec">15.0</Radius>
</Circle>
<SpectralSetup name="">
<SpectralElement name="SpectralSetupElement # 2">
<FrequencySetup name="FreqSetup # 2">
<CenterFrequency unit="GHz">335.0</CenterFrequency>
<FrequencyResolution unit="MHz">100.0</FrequencyResolution>
</FrequencySetup>
<CorrelatorSetup name="">
<Bandwidth unit="GHz">2.0</Bandwidth>
<Sensitivity unit="Jy">1.0E-5</Sensitivity>
</CorrelatorSetup>
</SpectralElement>
</SpectralSetup>
<ReductionProcedures imageScript="<default>"/>
<ObsUnitSetReference></ObsUnitSetReference>
</RegionOfInterest>
<RegionOfInterest name="">
<Circle name="YATS 2">
<Centre system="J2000">
<Longitude unit="hour">39.35</Longitude>
<Latitude unit="deg">-26.9775</Latitude>
</Centre>
<Radius unit="arcsec">15.0</Radius>
</Circle>
<SpectralSetup name="">
<SpectralElement name="SpectralSetupElement # 3">
<FrequencySetup name="FreqSetup # 3">
<CenterFrequency unit="GHz">335.0</CenterFrequency>
<FrequencyResolution unit="MHz">100.0</FrequencyResolution>
</FrequencySetup>
<CorrelatorSetup name="">
<Bandwidth unit="GHz">2.0</Bandwidth>
<Sensitivity unit="Jy">1.0E-5</Sensitivity>
</CorrelatorSetup>
</SpectralElement>
</SpectralSetup>
<ReductionProcedures imageScript="<default>"/>
<ObsUnitSetReference></ObsUnitSetReference>
</RegionOfInterest>
<ObservationTime unit="s">2200.0</ObservationTime>
</TargetSpace>
<ProgramImaging imageScript="<default>"/>
</ObsProgram>
</ObsProject>
@@@@@ timeStamp: ''
@@@@@ entityTypeName:alma.xmlentity.XmlEntityStruct@1a0225b
ObsProject
@@@@@ schemaVersion:alma.xmlentity.XmlEntityStruct@1a0225b
1
@@@@@@@@@@@@@@@@@@@@@@@
May 26, 2004 7:10:22 AM alma.archive.components.OperationalImpl retrieve
FINEST: Getting URI: uid://X0000000000000065/X00000000
May 26, 2004 7:10:22 AM alma.archive.components.OperationalImpl retrieve
FINEST: Fetching Xml: uid://X0000000000000065/X00000000
entityId exists in archive: id=uid://X0000000000000065/X00000000
May 26, 2004 7:10:22 AM alma.archive.components.OperationalImpl store
FINEST: Storing URI: uid://X0000000000000065/X00000000 Type: ObsProject
May 26, 2004 7:10:22 AM alma.archive.components.OperationalImpl store
FINEST: Schema Location for Type ObsProject is uid://X0000000000000064/X0000000a
May 26, 2004 7:10:22 AM alma.archive.components.OperationalImpl store
FINEST: Stored: uid://X0000000000000065/X00000000 successfully
May 26, 2004 7:10:22 AM alma.archive.components.OperationalImpl retrieve
FINEST: Getting URI: uid://X0000000000000065/X00000001
May 26, 2004 7:10:22 AM alma.archive.components.OperationalImpl retrieve
FINEST: Fetching Xml: uid://X0000000000000065/X00000001
entityId exists in archive: id=uid://X0000000000000065/X00000001
May 26, 2004 7:10:22 AM alma.archive.components.OperationalImpl store
FINEST: Storing URI: uid://X0000000000000065/X00000001 Type: ObsProposal
May 26, 2004 7:10:22 AM alma.archive.components.OperationalImpl store
FINEST: Schema Location for Type ObsProposal is uid://X0000000000000064/X0000000b
May 26, 2004 7:10:22 AM alma.archive.components.OperationalImpl store
FINEST: Stored: uid://X0000000000000065/X00000001 successfully
May 26, 2004 7:10:22 AM alma.archive.components.OperationalImpl retrieve
FINEST: Getting URI: uid://X0000000000000065/X00000002
May 26, 2004 7:10:22 AM alma.archive.components.OperationalImpl retrieve
FINEST: Fetching Xml: uid://X0000000000000065/X00000002
entityId exists in archive: id=uid://X0000000000000065/X00000002
May 26, 2004 7:10:22 AM alma.archive.components.OperationalImpl store
FINEST: Storing URI: uid://X0000000000000065/X00000002 Type: SchedBlock
May 26, 2004 7:10:22 AM alma.archive.components.OperationalImpl store
FINEST: Schema Location for Type SchedBlock is uid://X0000000000000064/X0000000f
May 26, 2004 7:10:22 AM alma.archive.components.OperationalImpl store
FINEST: Stored: uid://X0000000000000065/X00000002 successfully
May 26, 2004 7:10:22 AM alma.archive.components.OperationalImpl retrieve
FINEST: Getting URI: uid://X0000000000000065/X00000003
May 26, 2004 7:10:22 AM alma.archive.components.OperationalImpl retrieve
FINEST: Fetching Xml: uid://X0000000000000065/X00000003
entityId exists in archive: id=uid://X0000000000000065/X00000003
May 26, 2004 7:10:23 AM alma.archive.components.OperationalImpl store
FINEST: Storing URI: uid://X0000000000000065/X00000003 Type: SchedBlock
May 26, 2004 7:10:23 AM alma.archive.components.OperationalImpl store
FINEST: Schema Location for Type SchedBlock is uid://X0000000000000064/X0000000f
May 26, 2004 7:10:23 AM alma.archive.components.OperationalImpl store
FINEST: Stored: uid://X0000000000000065/X00000003 successfully
May 26, 2004 7:10:23 AM alma.archive.components.OperationalImpl retrieve
FINEST: Getting URI: uid://X0000000000000065/X00000004
May 26, 2004 7:10:23 AM alma.archive.components.OperationalImpl retrieve
FINEST: Fetching Xml: uid://X0000000000000065/X00000004
entityId exists in archive: id=uid://X0000000000000065/X00000004
May 26, 2004 7:10:23 AM alma.archive.components.OperationalImpl store
FINEST: Storing URI: uid://X0000000000000065/X00000004 Type: SchedBlock
May 26, 2004 7:10:23 AM alma.archive.components.OperationalImpl store
FINEST: Schema Location for Type SchedBlock is uid://X0000000000000064/X0000000f
May 26, 2004 7:10:23 AM alma.archive.components.OperationalImpl store
FINEST: Stored: uid://X0000000000000065/X00000004 successfully
May 26, 2004 7:10:23 AM alma.archive.components.OperationalImpl retrieve
FINEST: Getting URI: uid://X0000000000000065/X00000005
May 26, 2004 7:10:23 AM alma.archive.components.OperationalImpl retrieve
FINEST: Fetching Xml: uid://X0000000000000065/X00000005
entityId exists in archive: id=uid://X0000000000000065/X00000005
May 26, 2004 7:10:23 AM alma.archive.components.OperationalImpl store
FINEST: Storing URI: uid://X0000000000000065/X00000005 Type: SchedBlock
May 26, 2004 7:10:23 AM alma.archive.components.OperationalImpl store
FINEST: Schema Location for Type SchedBlock is uid://X0000000000000064/X0000000f
May 26, 2004 7:10:23 AM alma.archive.components.OperationalImpl store
FINEST: Stored: uid://X0000000000000065/X00000005 successfully
May 26, 2004 7:10:23 AM alma.acs.container.ContainerSealant invoke
INFO: returning from OBS_PROJ_REP#store after 523 ms.
May 26, 2004 7:10:52 AM alma.acs.container.AcsContainer ping
FINER: ping received.
May 26, 2004 7:11:11 AM alma.acs.container.AcsContainer activate_component
INFO: <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
May 26, 2004 7:11:11 AM alma.acs.container.AcsContainer activate_component
INFO: activate_component: handle=16777226 name=MASTER_SCHEDULER helperClass=alma.scheduling.master_scheduler.MSHelper type=IDL:alma/scheduling/MS:1.0
May 26, 2004 7:11:11 AM alma.acs.container.AcsContainer createComponentHelper
FINER: creating component helper instance of type alma.scheduling.master_scheduler.MSHelper
SCHEDULING: The MasterScheduler has been constructed.
May 26, 2004 7:11:11 AM alma.acs.container.ComponentHelper getComponentImpl
FINER: component implementation class 'alma.scheduling.master_scheduler.MasterScheduler' instantiated.
May 26, 2004 7:11:11 AM alma.acs.container.AcsContainer activate_component
FINER: component MASTER_SCHEDULER implements operations interface directly; no dynamic translator proxy used.
[ POA ComponentPOAMASTER_SCHEDULER - ready ]
May 26, 2004 7:11:11 AM alma.acs.container.ComponentAdapter activateComponent
FINER: entering ComponentAdapter#activateComponent for MASTER_SCHEDULER
May 26, 2004 7:11:11 AM alma.acs.container.corba.AcsCorba activateComponent
FINER: entering activateComponent: name=MASTER_SCHEDULER
May 26, 2004 7:11:11 AM alma.acs.container.corba.AcsCorba activateComponent
FINER: component 'MASTER_SCHEDULER' activated as CORBA object.
May 26, 2004 7:11:11 AM alma.acs.container.ComponentAdapter _getInterfaces
FINE: interfaces of component 'MASTER_SCHEDULER': IDL:alma/scheduling/MS:1.0IDL:alma/ACS/ACSComponent:1.0IDL:alma/scheduling/Executive_to_Scheduling:1.0IDL:alma/scheduling/TelescopeOperator_to_Scheduling:1.0IDL:omg.org/CORBA/Object:1.0
May 26, 2004 7:11:11 AM alma.acs.container.AcsContainer activate_component
FINE: about to initialize component MASTER_SCHEDULER
May 26, 2004 7:11:11 AM alma.acs.container.ComponentStateManagerImpl setState
FINER: switching state of component MASTER_SCHEDULER from NEW to INITIALIZING
May 26, 2004 7:11:11 AM alma.acs.logging.ClientLogManager getLoggerForComponent
FINE: a logger for component .MASTER_SCHEDULER is available.
May 26, 2004 7:11:11 AM alma.scheduling.master_scheduler.SchedulingPublisher <init>
INFO: SCHEDULING: Scheduling Publisher has been created
Attempting to create the SCHEDULING_CHANNEL channel.
May 26, 2004 7:11:12 AM alma.acs.logging.ClientLogManager getLoggerForComponent
FINE: a logger for component .MASTER_SCHEDULER is available.
SCHEDULING: Message queue created
May 26, 2004 7:11:12 AM alma.acs.logging.ClientLogManager getLoggerForComponent
FINE: a logger for component .MASTER_SCHEDULER is available.
May 26, 2004 7:11:12 AM alma.acs.container.ContainerServicesImpl getComponent
FINE: will retrieve remote component 'ARCHIVE_CONNECTION' using ACS Manager#get_component
May 26, 2004 7:11:12 AM alma.acs.container.ContainerServicesImpl getComponent
FINE: component ARCHIVE_CONNECTION retrieved successfully.
May 26, 2004 7:11:12 AM alma.acs.container.ContainerSealant invoke
INFO: intercepted a call to 'ARCHIVE_CONNECTION#getOperational'...
May 26, 2004 7:11:12 AM alma.archive.components.OperationalImpl connect
INFO: Connected to the internal interface
May 26, 2004 7:11:12 AM alma.archive.components.OperationalImpl connect
INFO: Connected to the Liatener Manager
May 26, 2004 7:11:12 AM alma.acs.container.corba.AcsCorba activateOffShoot
FINER: offshoot of type 'alma.archive.components.OperationalImpl' activated as a CORBA object.
May 26, 2004 7:11:12 AM alma.acs.container.ContainerSealant invoke
INFO: returning from ARCHIVE_CONNECTION#getOperational after 5 ms.
May 26, 2004 7:11:12 AM alma.acs.logging.ClientLogManager getLoggerForComponent
FINE: a logger for component .MASTER_SCHEDULER is available.
May 26, 2004 7:11:12 AM alma.acs.logging.ClientLogManager getLoggerForComponent
FINE: a logger for component .MASTER_SCHEDULER is available.
May 26, 2004 7:11:12 AM alma.scheduling.master_scheduler.ALMAArchive <init>
FINE: SCHEDULING: The ALMAArchive has been constructed.
May 26, 2004 7:11:12 AM alma.acs.logging.ClientLogManager getLoggerForComponent
FINE: a logger for component .MASTER_SCHEDULER is available.
May 26, 2004 7:11:12 AM alma.acs.logging.ClientLogManager getLoggerForComponent
FINE: a logger for component .MASTER_SCHEDULER is available.
May 26, 2004 7:11:12 AM alma.scheduling.master_scheduler.ALMATelescopeOperator <init>
INFO: SCHEDULING: The ALMATelescopeOperator has been constructed.
SCHEDULING: The PIProxy has been constructed.
May 26, 2004 7:11:12 AM alma.acs.logging.ClientLogManager getLoggerForComponent
FINE: a logger for component .MASTER_SCHEDULER is available.
May 26, 2004 7:11:12 AM alma.scheduling.master_scheduler.ALMADispatcher <init>
INFO: SCHEDULING: The Dispatcher has been constructed.
May 26, 2004 7:11:12 AM alma.acs.logging.ClientLogManager getLoggerForComponent
FINE: a logger for component .MASTER_SCHEDULER is available.
May 26, 2004 7:11:12 AM alma.acs.logging.ClientLogManager getLoggerForComponent
FINE: a logger for component .MASTER_SCHEDULER is available.
May 26, 2004 7:11:12 AM alma.scheduling.master_scheduler.SchedulingPublisher <init>
INFO: SCHEDULING: Scheduling Publisher has been created
SCHEDULING: The PipelineProxy has been constructed.
May 26, 2004 7:11:12 AM alma.acs.logging.ClientLogManager getLoggerForComponent
FINE: a logger for component .MASTER_SCHEDULER is available.
May 26, 2004 7:11:12 AM alma.acs.logging.ClientLogManager getLoggerForComponent
FINE: a logger for component .MASTER_SCHEDULER is available.
#########ControlEventReceiver created######
May 26, 2004 7:11:12 AM alma.acs.logging.ClientLogManager getLoggerForComponent
FINE: a logger for component .MASTER_SCHEDULER is available.
May 26, 2004 7:11:12 AM alma.scheduling.receivers.PipelineEventReceiver <init>
INFO: SCHEDULING: PipelineEventListener created.
May 26, 2004 7:11:12 AM alma.acs.logging.ClientLogManager getLoggerForComponent
FINE: a logger for component .MASTER_SCHEDULER is available.
May 26, 2004 7:11:12 AM alma.acs.logging.ClientLogManager getLoggerForComponent
FINE: a logger for component .MASTER_SCHEDULER is available.
May 26, 2004 7:11:12 AM alma.scheduling.project_manager.ProjectManager <init>
INFO: SCHEDULING: Trying to get NCs
Suppler.subscription_change(...) the 'CONTROLSYSTEM' channel: override to do something useful.
May 26, 2004 7:11:12 AM alma.scheduling.project_manager.ProjectManager <init>
INFO: SCHEDULING: Subscribed to CONTROL
Suppler.subscription_change(...) the 'sciencepipeline' channel: override to do something useful.
May 26, 2004 7:11:12 AM alma.scheduling.project_manager.ProjectManager <init>
INFO: SCHEDULING: Subscribed to PIPELINE
Suppler.subscription_change(...) the 'TelCalPublisherEventNC' channel: override to do something useful.
Suppler.subscription_change(...) the 'TelCalPublisherEventNC' channel: override to do something useful.
Suppler.subscription_change(...) the 'TelCalPublisherEventNC' channel: override to do something useful.
Suppler.subscription_change(...) the 'TelCalPublisherEventNC' channel: override to do something useful.
May 26, 2004 7:11:12 AM alma.scheduling.project_manager.ProjectManager <init>
INFO: SCHEDULING: Subscribed to TELCAL PointingReducedEvent
Suppler.subscription_change(...) the 'TelCalPublisherEventNC' channel: override to do something useful.
Suppler.subscription_change(...) the 'TelCalPublisherEventNC' channel: override to do something useful.
Suppler.subscription_change(...) the 'TelCalPublisherEventNC' channel: override to do something useful.
Suppler.subscription_change(...) the 'TelCalPublisherEventNC' channel: override to do something useful.
May 26, 2004 7:11:12 AM alma.scheduling.project_manager.ProjectManager <init>
INFO: SCHEDULING: Subscribed to TELCAL FocusReducedEvent
May 26, 2004 7:11:12 AM alma.scheduling.project_manager.ProjectManager <init>
INFO: SCHEDULING: Got NCs
SCHEDULING: The Clock has been constructed.
May 26, 2004 7:11:12 AM alma.acs.logging.ClientLogManager getLoggerForComponent
FINE: a logger for component .MASTER_SCHEDULER is available.
May 26, 2004 7:11:12 AM alma.scheduling.master_scheduler.MasterScheduler initialize
INFO: SCHEDULING: The MasterScheduler has been initialized.
May 26, 2004 7:11:12 AM alma.acs.container.ComponentStateManagerImpl setState
FINER: switching state of component MASTER_SCHEDULER from INITIALIZING to INITIALIZED
May 26, 2004 7:11:12 AM alma.scheduling.master_scheduler.MasterScheduler execute
INFO: SCHEDULING: starting execute
May 26, 2004 7:11:12 AM alma.archive.components.OperationalImpl query
FINE: Querying XPath: /sbl:SchedBlock Schema: SchedBlock
May 26, 2004 7:11:12 AM alma.archive.components.OperationalImpl query
FINEST: Schema location for SchedBlock is uid://X0000000000000064/X0000000f
May 26, 2004 7:11:12 AM alma.archive.database.helpers.DBConfiguration searchConfigFile
WARNING: Property archive.config.file not set, using default config file: /alma/ACS-3.0/acsdata/config/dbConfig.xml
May 26, 2004 7:11:12 AM alma.archive.database.helpers.DBConfiguration readConfig
INFO: Setting database configuration.
May 26, 2004 7:11:12 AM alma.archive.database.helpers.DBConfiguration readConfig
INFO: Using database backend xindice
May 26, 2004 7:11:13 AM alma.archive.components.OperationalImpl query
FINE: Returning cursor to user
May 26, 2004 7:11:13 AM alma.acs.container.corba.AcsCorba activateOffShoot
FINER: offshoot of type 'alma.archive.components.CursorImpl' activated as a CORBA object.
May 26, 2004 7:11:13 AM alma.scheduling.master_scheduler.MasterScheduler pollArchive
INFO: SCHEDULING: Getting SBs from archive. There are 4
May 26, 2004 7:11:13 AM alma.scheduling.master_scheduler.MasterScheduler pollArchive
INFO: SCHEDULING: sbs not null storing into sbQueue
May 26, 2004 7:11:13 AM alma.scheduling.master_scheduler.MasterScheduler run
INFO: MSsleeping!
May 26, 2004 7:11:13 AM alma.scheduling.master_scheduler.ALMATelescopeOperator setMessageQueue
INFO: SCHEDULING: Message queue set in operator
May 26, 2004 7:11:13 AM alma.scheduling.master_scheduler.MasterScheduler execute
INFO: SCHEDULING: The MasterScheduler is executing.
May 26, 2004 7:11:13 AM alma.acs.container.ComponentStateManagerImpl setState
FINER: switching state of component MASTER_SCHEDULER from INITIALIZED to OPERATIONAL
May 26, 2004 7:11:13 AM alma.acs.container.AcsContainer activate_component
INFO: component MASTER_SCHEDULER activated and initialized in 1552 ms.
May 26, 2004 7:11:13 AM alma.acs.container.AcsContainer activate_component
INFO: >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
May 26, 2004 7:11:17 AM alma.acs.container.ContainerSealant invoke
INFO: intercepted a call to 'MASTER_SCHEDULER#startScheduling'...
May 26, 2004 7:11:17 AM alma.scheduling.master_scheduler.MasterScheduler startScheduler
INFO: SCHEDULING: MODE == dynamic
May 26, 2004 7:11:17 AM alma.acs.logging.ClientLogManager getLoggerForComponent
FINE: a logger for component .MASTER_SCHEDULER is available.
May 26, 2004 7:11:17 AM alma.scheduling.master_scheduler.MasterScheduler startScheduler
INFO: SCHEDULING: New scheduler started.
May 26, 2004 7:11:17 AM alma.scheduling.master_scheduler.MasterScheduler startScheduler
INFO: SCHEDULING: Start of new project.
SCHEDULING: SchedulerEventReceiver created.
May 26, 2004 7:11:17 AM alma.acs.container.ContainerSealant invoke
INFO: returning from MASTER_SCHEDULER#startScheduling after 24 ms.
May 26, 2004 7:11:17 AM alma.scheduling.scheduler.Scheduler run
INFO: SCHEDULING: Scheduler is running in dynamic mode!
SCHEDULING SUB QUEUE size = 4
May 26, 2004 7:11:17 AM alma.acs.container.archive.ArchiveProxy getUid
FINE: trying to access the identifier archive...
May 26, 2004 7:11:17 AM alma.acs.container.archive.ArchiveProxy getUid
FINE: about to call getIdNamespace()...
May 26, 2004 7:11:17 AM alma.acs.container.ContainerSealant invoke
INFO: intercepted a call to 'IDENTIFIER_ARCHIVE#getIdNamespace'...
May 26, 2004 7:11:17 AM alma.acs.container.ContainerSealant invoke
INFO: returning from IDENTIFIER_ARCHIVE#getIdNamespace after 7 ms.
May 26, 2004 7:11:17 AM alma.acs.container.archive.ArchiveProxy getUid
FINE: getIdNamespace() returned uid://X0000000000000066/X00000000
May 26, 2004 7:11:17 AM alma.acs.container.ContainerSealant invoke
INFO: intercepted a call to 'IDENTIFIER_ARCHIVE#name'...
May 26, 2004 7:11:17 AM alma.acs.container.ContainerSealant invoke
INFO: returning from IDENTIFIER_ARCHIVE#name after 1 ms.
May 26, 2004 7:11:17 AM alma.acs.container.ContainerServicesImpl releaseComponent
FINE: about to release component IDENTIFIER_ARCHIVE
May 26, 2004 7:11:17 AM alma.acs.container.AcsManagerProxy release_component
FINER: released 'IDENTIFIER_ARCHIVE' with the manager. Remaining clients: 1
May 26, 2004 7:11:17 AM alma.acs.container.ContainerServicesImpl releaseComponent
INFO: client 'MASTER_SCHEDULER' has successfully released a component with curl=IDENTIFIER_ARCHIVE
May 26, 2004 7:11:17 AM alma.scheduling.master_scheduler.ALMATelescopeOperator sortSBs
INFO: SCHEDULING: sorting SBs!
May 26, 2004 7:11:17 AM alma.archive.components.OperationalImpl query
FINE: Querying XPath: /sbl:SchedBlock Schema: SchedBlock
May 26, 2004 7:11:17 AM alma.archive.components.OperationalImpl query
FINEST: Schema location for SchedBlock is uid://X0000000000000064/X0000000f
May 26, 2004 7:11:18 AM alma.archive.components.OperationalImpl query
FINE: Returning cursor to user
May 26, 2004 7:11:18 AM alma.acs.container.corba.AcsCorba activateOffShoot
FINER: offshoot of type 'alma.archive.components.CursorImpl' activated as a CORBA object.
May 26, 2004 7:11:18 AM alma.scheduling.master_scheduler.ALMATelescopeOperator isCompletedSb
INFO: SCHEDULING: checking for non-complete SB
May 26, 2004 7:11:18 AM alma.archive.components.OperationalImpl query
FINE: Querying XPath: /sbl:SchedBlock Schema: SchedBlock
May 26, 2004 7:11:18 AM alma.archive.components.OperationalImpl query
FINEST: Schema location for SchedBlock is uid://X0000000000000064/X0000000f
May 26, 2004 7:11:19 AM alma.archive.components.OperationalImpl query
FINE: Returning cursor to user
May 26, 2004 7:11:19 AM alma.acs.container.corba.AcsCorba activateOffShoot
FINER: offshoot of type 'alma.archive.components.CursorImpl' activated as a CORBA object.
May 26, 2004 7:11:19 AM alma.scheduling.master_scheduler.ALMATelescopeOperator isCompletedSb
INFO: SCHEDULING: checking for non-complete SB
May 26, 2004 7:11:19 AM alma.scheduling.master_scheduler.ALMATelescopeOperator selectSB
INFO: SCHEDULING: in TO. reply =uid://X0000000000000065/X00000002
May 26, 2004 7:11:19 AM alma.acs.container.ContainerServicesImpl getComponent
FINE: will retrieve remote component 'MASTER_SCHEDULER' using ACS Manager#get_component
May 26, 2004 7:11:19 AM alma.acs.container.ContainerServicesImpl getComponent
FINE: component MASTER_SCHEDULER retrieved successfully.
May 26, 2004 7:11:19 AM alma.scheduling.master_scheduler.ALMATelescopeOperator selectSB
INFO: SCHEDULING: in TO. ms response about to be called
May 26, 2004 7:11:19 AM alma.acs.container.ContainerSealant invoke
INFO: intercepted a call to 'MASTER_SCHEDULER#response'...
May 26, 2004 7:11:19 AM alma.scheduling.master_scheduler.MasterScheduler response
INFO: SCHEDULING: in MS. MessageID = uid://X0000000000000066/X00000000
May 26, 2004 7:11:19 AM alma.scheduling.master_scheduler.MasterScheduler response
INFO: SCHEDULING: in MS. Reply (sb id) = uid://X0000000000000065/X00000002
May 26, 2004 7:11:19 AM alma.scheduling.master_scheduler.MasterScheduler response
INFO: SCHEDULING: in MS. messageQueue size = 1
May 26, 2004 7:11:19 AM alma.scheduling.master_scheduler.MasterScheduler response
INFO: SCHEDULING: in MS. Got message with id=uid://X0000000000000066/X00000000
May 26, 2004 7:11:19 AM alma.scheduling.master_scheduler.MasterScheduler response
INFO: SCHEDULING: in MS. message = uid://X0000000000000066/X00000000 gotten and reply = uid://X0000000000000065/X00000002 sent.
May 26, 2004 7:11:19 AM alma.acs.container.ContainerSealant invoke
INFO: returning from MASTER_SCHEDULER#response after 28 ms.
May 26, 2004 7:11:19 AM alma.scheduling.master_scheduler.ALMATelescopeOperator selectSB
INFO: SCHEDULING: in TO. ms response called
May 26, 2004 7:11:19 AM alma.scheduling.master_scheduler.ALMATelescopeOperator selectSB
INFO: SCHEDULING: in TO. timer.join()
May 26, 2004 7:11:19 AM alma.scheduling.scheduler.Scheduler run
INFO: SCHEDULING: in scheduler. selectedSB = uid://X0000000000000065/X00000002
May 26, 2004 7:11:19 AM alma.scheduling.scheduler.Scheduler run
INFO: SCHEDULING: Message uid://X0000000000000066/X00000000 removed from queue.
May 26, 2004 7:11:19 AM alma.scheduling.master_scheduler.ALMADispatcher sendToControl
INFO: SCHEDULING: Sending SB with id = uid://X0000000000000065/X00000002 to controller.
May 26, 2004 7:11:19 AM alma.acs.container.ContainerServicesImpl getComponent
FINE: will retrieve remote component 'ControlSystem1' using ACS Manager#get_component
May 26, 2004 7:11:19 AM alma.acs.container.ContainerServicesImpl getComponent
FINE: component ControlSystem1 retrieved successfully.
May 26, 2004 7:11:19 AM alma.scheduling.master_scheduler.ALMADispatcher sendToControl
INFO: SCHEDULING: Got control system
May 26, 2004 7:11:19 AM alma.acs.container.ContainerSealant invoke
INFO: intercepted a call to 'ControlSystem1#createSubArray'...
May 26, 2004 7:11:19 AM alma.Control.masterController.ControlSystemImpl createSubArray
INFO: createSubArray() called
May 26, 2004 7:11:19 AM alma.acs.container.ContainerServicesImpl getDynamicComponent
FINE: getDynamicComponent called with compName=ArrayController0 compType=IDL:alma/Control/ArrayController:1.0 compCode=* compContainer=* markAsDefault=false
May 26, 2004 7:11:19 AM alma.acs.container.AcsContainer activate_component
INFO: <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
May 26, 2004 7:11:19 AM alma.acs.container.AcsContainer activate_component
INFO: activate_component: handle=16777227 name=ArrayController0 helperClass=alma.Control.arrayInterfaces.ArrayControllerHelper type=IDL:alma/Control/ArrayController:1.0
May 26, 2004 7:11:19 AM alma.acs.container.AcsContainer createComponentHelper
FINER: creating component helper instance of type alma.Control.arrayInterfaces.ArrayControllerHelper
May 26, 2004 7:11:19 AM alma.acs.container.ComponentHelper getComponentImpl
FINER: component implementation class 'alma.Control.arrayInterfaces.ArrayControllerImpl' instantiated.
May 26, 2004 7:11:19 AM alma.acs.container.AcsContainer activate_component
FINER: component ArrayController0 implements operations interface directly; no dynamic translator proxy used.
[ POA ComponentPOAArrayController0 - ready ]
May 26, 2004 7:11:19 AM alma.acs.container.ComponentAdapter activateComponent
FINER: entering ComponentAdapter#activateComponent for ArrayController0
May 26, 2004 7:11:19 AM alma.acs.container.corba.AcsCorba activateComponent
FINER: entering activateComponent: name=ArrayController0
May 26, 2004 7:11:19 AM alma.acs.container.corba.AcsCorba activateComponent
FINER: component 'ArrayController0' activated as CORBA object.
May 26, 2004 7:11:19 AM alma.acs.container.ComponentAdapter _getInterfaces
FINE: interfaces of component 'ArrayController0': IDL:alma/Control/ArrayController:1.0IDL:alma/ACS/ACSComponent:1.0IDL:omg.org/CORBA/Object:1.0IDL:alma/Control/ArrayMonitor:1.0
May 26, 2004 7:11:19 AM alma.acs.container.AcsContainer activate_component
FINE: about to initialize component ArrayController0
May 26, 2004 7:11:19 AM alma.acs.container.ComponentStateManagerImpl setState
FINER: switching state of component ArrayController0 from NEW to INITIALIZING
May 26, 2004 7:11:19 AM alma.acs.logging.ClientLogManager getLoggerForComponent
FINE: a logger for component .ArrayController0 is available.
May 26, 2004 7:11:19 AM alma.Control.arrayInterfaces.ArrayMonitorImpl initialize
INFO: CONTROL: ArrayMonitorImpl.initialize() called...
May 26, 2004 7:11:19 AM alma.acs.container.ContainerServicesImpl getComponent
FINE: will retrieve remote component 'ARCHIVE_CONNECTION' using ACS Manager#get_component
May 26, 2004 7:11:19 AM alma.acs.container.ContainerServicesImpl getComponent
FINE: component ARCHIVE_CONNECTION retrieved successfully.
May 26, 2004 7:11:19 AM alma.acs.container.ContainerSealant invoke
INFO: intercepted a call to 'ARCHIVE_CONNECTION#getOperational'...
May 26, 2004 7:11:19 AM alma.archive.components.OperationalImpl connect
INFO: Connected to the internal interface
May 26, 2004 7:11:19 AM alma.archive.components.OperationalImpl connect
INFO: Connected to the Liatener Manager
May 26, 2004 7:11:19 AM alma.acs.container.corba.AcsCorba activateOffShoot
FINER: offshoot of type 'alma.archive.components.OperationalImpl' activated as a CORBA object.
May 26, 2004 7:11:19 AM alma.acs.container.ContainerSealant invoke
INFO: returning from ARCHIVE_CONNECTION#getOperational after 3 ms.
May 26, 2004 7:11:19 AM alma.acs.logging.ClientLogManager getLoggerForComponent
FINE: a logger for component .ArrayController0 is available.
May 26, 2004 7:11:19 AM alma.acs.logging.ClientLogManager getLoggerForComponent
FINE: a logger for component .ArrayController0 is available.
May 26, 2004 7:11:19 AM alma.Control.arrayInterfaces.ArrayControllerImpl initialize
INFO: CONTROL: ArrayControllerImpl.initialize() called...
Suppler.subscription_change(...) the 'CONTROLSYSTEM' channel: override to do something useful.
Suppler.subscription_change(...) the 'CONTROLSYSTEM' channel: override to do something useful.
Suppler.subscription_change(...) the 'CONTROLSYSTEM' channel: override to do something useful.
May 26, 2004 7:11:19 AM alma.acs.container.ComponentStateManagerImpl setState
FINER: switching state of component ArrayController0 from INITIALIZING to INITIALIZED
May 26, 2004 7:11:19 AM alma.Control.arrayInterfaces.ArrayMonitorImpl execute
INFO: eArrayMonitorImpl.xecute() called...
May 26, 2004 7:11:19 AM alma.acs.container.ComponentStateManagerImpl setState
FINER: switching state of component ArrayController0 from INITIALIZED to OPERATIONAL
May 26, 2004 7:11:19 AM alma.acs.container.AcsContainer activate_component
INFO: component ArrayController0 activated and initialized in 85 ms.
May 26, 2004 7:11:19 AM alma.acs.container.AcsContainer activate_component
INFO: >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
May 26, 2004 7:11:21 AM alma.acs.container.ContainerSealant invoke
INFO: returning from ControlSystem1#createSubArray after 2409 ms.
May 26, 2004 7:11:21 AM alma.scheduling.master_scheduler.ALMADispatcher sendToControl
INFO: SCHEDULING: Got array controller
May 26, 2004 7:11:21 AM alma.acs.container.ContainerSealant invoke
INFO: intercepted a call to 'ArrayController0#observeNow'...
May 26, 2004 7:11:21 AM alma.Control.arrayInterfaces.ArrayControllerImpl observe
INFO: observe() called...
May 26, 2004 7:11:21 AM alma.archive.components.OperationalImpl retrieve
FINEST: Getting URI: uid://X0000000000000065/X00000002
May 26, 2004 7:11:21 AM alma.archive.components.OperationalImpl retrieve
FINEST: Fetching Xml: uid://X0000000000000065/X00000002
May 26, 2004 7:11:21 AM alma.archive.components.OperationalImpl retrieve
FINEST: Fetching Status: uid://X0000000000000065/X00000002
May 26, 2004 7:11:21 AM alma.acs.container.AcsContainer logManagerRequest
FINE: received call to deactivate_components; handles = 16777225
May 26, 2004 7:11:21 AM alma.acs.container.ComponentStateManagerImpl setState
FINER: switching state of component OBS_PROJ_REP from OPERATIONAL to DESTROYING
May 26, 2004 7:11:21 AM alma.acs.container.AcsContainer deactivate_components
FINER: deactivating component 'OBS_PROJ_REP' with handle 16777225
May 26, 2004 7:11:21 AM alma.acs.container.ComponentAdapter deactivateComponent
FINER: about to deactivate component OBS_PROJ_REP
May 26, 2004 7:11:21 AM alma.archive.components.OperationalImpl retrieve
FINEST: Building Result: uid://X0000000000000065/X00000002
May 26, 2004 7:11:21 AM alma.archive.components.OperationalImpl retrieve
FINEST: Schema: uid://X0000000000000064/X0000000f
May 26, 2004 7:11:21 AM alma.archive.components.OperationalImpl retrieve
FINEST: Type name: SchedBlock
May 26, 2004 7:11:21 AM alma.archive.components.OperationalImpl retrieve
FINEST: Version: 0
May 26, 2004 7:11:21 AM alma.archive.components.OperationalImpl retrieve
FINEST: Time Stamp: 2004-05-26T07:10:22.978
May 26, 2004 7:11:21 AM alma.acs.container.ContainerServicesImpl releaseComponent
FINE: about to release component ARCHIVE_CONNECTION
May 26, 2004 7:11:21 AM alma.acs.container.AcsManagerProxy release_component
FINER: released 'ARCHIVE_CONNECTION' with the manager. Remaining clients: 1
May 26, 2004 7:11:21 AM alma.acs.container.ContainerServicesImpl releaseComponent
INFO: client 'OBS_PROJ_REP' has successfully released a component with curl=ARCHIVE_CONNECTION
May 26, 2004 7:11:21 AM alma.acs.container.ContainerServicesImpl releaseComponent
INFO: ignoring request by client 'OBS_PROJ_REP' to release other component with unknown curl='ADMINISTRATIVE_ARCHIVE'.
May 26, 2004 7:11:21 AM alma.acs.container.ComponentStateManagerImpl setState
FINER: switching state of component OBS_PROJ_REP from DESTROYING to DEFUNCT
May 26, 2004 7:11:21 AM alma.acs.container.ComponentAdapter deactivateComponent
FINER: done deactivating component OBS_PROJ_REP
[ POA ComponentPOAOBS_PROJ_REP - destroyed ]
May 26, 2004 7:11:21 AM alma.archive.components.OperationalImpl store
FINEST: Storing URI: uid://X0000000000000066/X00000001 Type: ExecBlock
May 26, 2004 7:11:21 AM alma.archive.components.OperationalImpl store
FINEST: Schema Location for Type ExecBlock is uid://X0000000000000064/X00000010
May 26, 2004 7:11:21 AM alma.archive.components.OperationalImpl store
FINEST: Stored: uid://X0000000000000066/X00000001 successfully
May 26, 2004 7:11:22 AM alma.acs.container.AcsContainer ping
FINER: ping received.
May 26, 2004 7:11:23 AM alma.Control.arrayInterfaces.ArrayControllerImpl observe
INFO: CONTROL: send ExecBlockEvent
May 26, 2004 7:11:23 AM alma.scheduling.receivers.ControlEventReceiver push_structured_event
INFO: SCHEDULING: Got event from control
May 26, 2004 7:11:23 AM alma.scheduling.receivers.ControlEventReceiver push_structured_event
INFO: SCHEDULING: Event reason = started
SCHEDULING: Control event received in scheduler receiver!
May 26, 2004 7:11:23 AM alma.scheduling.receivers.ControlEventReceiver push_structured_event
INFO: SCHEDULING: Received sb start event from control.
SCHEDULING: Got event from Control (scheduler receiver)
SCHEDULING: process sched event started
SCHEDULING: in scheduler, id=uid://X0000000000000065/X00000002
SCHEDULING: Sb ids match!
SCHEDULING: id is in queue.. do something
May 26, 2004 7:11:25 AM alma.Control.arrayInterfaces.ArrayControllerImpl observe
INFO: CONTROL: send ObsEvent
May 26, 2004 7:11:31 AM alma.acs.container.ContainerSealant invoke
INFO: intercepted a call to 'GETTELCALRESULTS1#publishPointingResult'...
May 26, 2004 7:11:31 AM alma.TelCalPublisher.GetTelCalResultsImpl.GetTelCalResultsImpl publishPointingResult
INFO: publishPointingResult...
PointingResultConverter...
May 26, 2004 7:11:31 AM alma.acs.container.ContainerSealant invoke
INFO: intercepted a call to 'GETTELCALRESULTS1#publishPointingResult'...
May 26, 2004 7:11:31 AM alma.TelCalPublisher.GetTelCalResultsImpl.GetTelCalResultsImpl publishPointingResult
INFO: publishPointingResult...
PointingResultConverter...
May 26, 2004 7:11:31 AM alma.TelCalPublisher.GetTelCalResultsImpl.GetTelCalResultsImpl storeResultInList
INFO: list size=2
May 26, 2004 7:11:31 AM alma.TelCalPublisher.GetTelCalResultsImpl.GetTelCalResultsImpl sendEvent
INFO: sendEvent
pointing event
May 26, 2004 7:11:31 AM alma.TelCalPublisher.GetTelCalResultsImpl.GetTelCalResultsImpl storeResultInList
INFO: list size=2
May 26, 2004 7:11:31 AM alma.TelCalPublisher.GetTelCalResultsImpl.GetTelCalResultsImpl sendEvent
INFO: sendEvent
pointing event
SCHEDULING: Got PointingReduced event
SCHEDULING: Starting to process the PointingReduced event
pointing event: end
SCHEDULING: Got PointingReduced event
SCHEDULING: Starting to process the PointingReduced event
pointing event: end
May 26, 2004 7:11:31 AM alma.archive.components.OperationalImpl store
FINEST: Storing URI: uid://X0000000000000066/X00000002 Type: PointingResult
May 26, 2004 7:11:31 AM alma.archive.components.OperationalImpl store
FINEST: Storing URI: uid://X0000000000000066/X00000003 Type: PointingResult
May 26, 2004 7:11:31 AM alma.archive.components.OperationalImpl store
FINEST: Schema Location for Type PointingResult is uid://X0000000000000064/X00000014
May 26, 2004 7:11:31 AM alma.archive.components.OperationalImpl store
FINEST: Schema Location for Type PointingResult is uid://X0000000000000064/X00000014
May 26, 2004 7:11:31 AM alma.archive.components.OperationalImpl store
FINEST: Stored: uid://X0000000000000066/X00000003 successfully
xmlEntity= alma.xmlentity.XmlEntityStruct@127f79d
May 26, 2004 7:11:31 AM alma.acs.container.ContainerSealant invoke
INFO: returning from GETTELCALRESULTS1#publishPointingResult after 384 ms.
May 26, 2004 7:11:31 AM alma.archive.components.OperationalImpl store
FINEST: Stored: uid://X0000000000000066/X00000002 successfully
xmlEntity= alma.xmlentity.XmlEntityStruct@9260ee
May 26, 2004 7:11:31 AM alma.acs.container.ContainerSealant invoke
INFO: returning from GETTELCALRESULTS1#publishPointingResult after 402 ms.
May 26, 2004 7:11:31 AM alma.acs.container.ContainerSealant invoke
INFO: returning from ArrayController0#observeNow after 10318 ms.
May 26, 2004 7:11:31 AM alma.scheduling.receivers.ControlEventReceiver push_structured_event
INFO: SCHEDULING: Got event from control
May 26, 2004 7:11:31 AM alma.scheduling.scheduler.Scheduler run
INFO: SCHEDULING: waiting til sb is done processing
May 26, 2004 7:11:31 AM alma.scheduling.receivers.ControlEventReceiver push_structured_event
INFO: SCHEDULING: Event reason = end
SCHEDULING: Control event received in scheduler receiver!
May 26, 2004 7:11:31 AM alma.scheduling.receivers.ControlEventReceiver push_structured_event
INFO: SCHEDULING: Received sb end event from control.
SCHEDULING: Got event from Control (scheduler receiver)
SCHEDULING: process sched event started
SCHEDULING: in scheduler, id=uid://X0000000000000065/X00000002
SCHEDULING: Sb ids match!
SCHEDULING: id is in queue.. do something
May 26, 2004 7:11:31 AM alma.scheduling.receivers.ControlEventReceiver receive
INFO: SCHEDULING: Starting to process the control event
May 26, 2004 7:11:31 AM alma.scheduling.receivers.ControlEventReceiver receive
INFO: SCHEDULING: Event reason = end
May 26, 2004 7:11:31 AM alma.scheduling.scheduler.Scheduler run
INFO: SCHEDULING: scheduler woken up!
May 26, 2004 7:11:31 AM alma.scheduling.receivers.ControlEventReceiver receive
INFO: SCHEDULING: Received sb end event from control.
May 26, 2004 7:11:31 AM alma.scheduling.master_scheduler.ALMATelescopeOperator sortSBs
INFO: SCHEDULING: sorting SBs!
May 26, 2004 7:11:31 AM alma.archive.components.OperationalImpl query
FINE: Querying XPath: /sbl:SchedBlock Schema: SchedBlock
SCHEDULING: process control event started
May 26, 2004 7:11:31 AM alma.scheduling.master_scheduler.ALMAArchive updateSchedBlock
INFO: SCHEDULING: sb id=uid://X0000000000000065/X00000002
May 26, 2004 7:11:31 AM alma.archive.components.OperationalImpl query
FINEST: Schema location for SchedBlock is uid://X0000000000000064/X0000000f
May 26, 2004 7:11:31 AM alma.scheduling.master_scheduler.ALMAArchive updateSchedBlock
INFO: SCHEDULING: ** This is where the sb will be linked to its execblock **
May 26, 2004 7:11:31 AM alma.archive.components.OperationalImpl retrieve
FINEST: Getting URI: uid://X0000000000000065/X00000002
May 26, 2004 7:11:31 AM alma.archive.components.OperationalImpl retrieve
FINEST: Fetching Xml: uid://X0000000000000065/X00000002
May 26, 2004 7:11:32 AM alma.archive.components.OperationalImpl query
FINE: Returning cursor to user
May 26, 2004 7:11:32 AM alma.archive.components.OperationalImpl retrieve
FINEST: Fetching Status: uid://X0000000000000065/X00000002
May 26, 2004 7:11:32 AM alma.acs.container.corba.AcsCorba activateOffShoot
FINER: offshoot of type 'alma.archive.components.CursorImpl' activated as a CORBA object.
May 26, 2004 7:11:32 AM alma.archive.components.OperationalImpl retrieve
FINEST: Building Result: uid://X0000000000000065/X00000002
May 26, 2004 7:11:32 AM alma.archive.components.OperationalImpl retrieve
FINEST: Schema: uid://X0000000000000064/X0000000f
May 26, 2004 7:11:32 AM alma.archive.components.OperationalImpl retrieve
FINEST: Type name: SchedBlock
May 26, 2004 7:11:32 AM alma.archive.components.OperationalImpl retrieve
FINEST: Version: 0
May 26, 2004 7:11:32 AM alma.archive.components.OperationalImpl retrieve
FINEST: Time Stamp: 2004-05-26T07:10:22.978
May 26, 2004 7:11:32 AM alma.archive.components.OperationalImpl retrieve
FINEST: Getting URI: uid://X0000000000000065/X00000002
May 26, 2004 7:11:32 AM alma.archive.components.OperationalImpl retrieve
FINEST: Fetching Xml: uid://X0000000000000065/X00000002
May 26, 2004 7:11:32 AM alma.scheduling.master_scheduler.ALMATelescopeOperator isCompletedSb
INFO: SCHEDULING: checking for non-complete SB
May 26, 2004 7:11:32 AM alma.archive.components.OperationalImpl retrieve
FINEST: Fetching Status: uid://X0000000000000065/X00000002
May 26, 2004 7:11:32 AM alma.archive.components.OperationalImpl query
FINE: Querying XPath: /sbl:SchedBlock Schema: SchedBlock
May 26, 2004 7:11:32 AM alma.archive.components.OperationalImpl query
FINEST: Schema location for SchedBlock is uid://X0000000000000064/X0000000f
May 26, 2004 7:11:32 AM alma.archive.components.OperationalImpl retrieve
FINEST: Building Result: uid://X0000000000000065/X00000002
May 26, 2004 7:11:32 AM alma.archive.components.OperationalImpl retrieve
FINEST: Schema: uid://X0000000000000064/X0000000f
May 26, 2004 7:11:32 AM alma.archive.components.OperationalImpl retrieve
FINEST: Type name: SchedBlock
May 26, 2004 7:11:32 AM alma.archive.components.OperationalImpl retrieve
FINEST: Version: 0
May 26, 2004 7:11:32 AM alma.archive.components.OperationalImpl retrieve
FINEST: Time Stamp: 2004-05-26T07:10:22.978
May 26, 2004 7:11:32 AM alma.archive.components.OperationalImpl update
FINEST: Updating: uid://X0000000000000065/X00000002
May 26, 2004 7:11:33 AM alma.archive.components.OperationalImpl query
FINE: Returning cursor to user
May 26, 2004 7:11:33 AM alma.acs.container.corba.AcsCorba activateOffShoot
FINER: offshoot of type 'alma.archive.components.CursorImpl' activated as a CORBA object.
May 26, 2004 7:11:33 AM alma.scheduling.master_scheduler.ALMATelescopeOperator isCompletedSb
INFO: SCHEDULING: checking for non-complete SB
May 26, 2004 7:11:33 AM alma.scheduling.master_scheduler.ALMATelescopeOperator selectSB
INFO: SCHEDULING: in TO. reply =uid://X0000000000000065/X00000002
May 26, 2004 7:11:33 AM alma.acs.container.ContainerServicesImpl getComponent
INFO: client 'MASTER_SCHEDULER' attempts to retrieve component 'MASTER_SCHEDULER' more than once; will return existing reference.
May 26, 2004 7:11:33 AM alma.scheduling.master_scheduler.ALMATelescopeOperator selectSB
INFO: SCHEDULING: in TO. ms response about to be called
May 26, 2004 7:11:33 AM alma.acs.container.ContainerSealant invoke
INFO: intercepted a call to 'MASTER_SCHEDULER#response'...
May 26, 2004 7:11:33 AM alma.scheduling.master_scheduler.MasterScheduler response
INFO: SCHEDULING: in MS. MessageID = uid://X0000000000000066/X00000004
May 26, 2004 7:11:33 AM alma.scheduling.master_scheduler.MasterScheduler response
INFO: SCHEDULING: in MS. Reply (sb id) = uid://X0000000000000065/X00000002
May 26, 2004 7:11:33 AM alma.scheduling.master_scheduler.MasterScheduler response
INFO: SCHEDULING: in MS. messageQueue size = 1
May 26, 2004 7:11:33 AM alma.scheduling.master_scheduler.MasterScheduler response
INFO: SCHEDULING: in MS. Got message with id=uid://X0000000000000066/X00000004
May 26, 2004 7:11:33 AM alma.scheduling.master_scheduler.MasterScheduler response
INFO: SCHEDULING: in MS. message = uid://X0000000000000066/X00000004 gotten and reply = uid://X0000000000000065/X00000002 sent.
May 26, 2004 7:11:33 AM alma.acs.container.ContainerSealant invoke
INFO: returning from MASTER_SCHEDULER#response after 3 ms.
May 26, 2004 7:11:33 AM alma.scheduling.master_scheduler.ALMATelescopeOperator selectSB
INFO: SCHEDULING: in TO. ms response called
May 26, 2004 7:11:33 AM alma.scheduling.master_scheduler.ALMATelescopeOperator selectSB
INFO: SCHEDULING: in TO. timer.join()
May 26, 2004 7:11:33 AM alma.scheduling.scheduler.Scheduler run
INFO: SCHEDULING: in scheduler. selectedSB = uid://X0000000000000065/X00000002
May 26, 2004 7:11:33 AM alma.scheduling.scheduler.Scheduler run
INFO: SCHEDULING: Message uid://X0000000000000066/X00000004 removed from queue.
May 26, 2004 7:11:33 AM alma.scheduling.master_scheduler.ALMADispatcher sendToControl
INFO: SCHEDULING: Sending SB with id = uid://X0000000000000065/X00000002 to controller.
May 26, 2004 7:11:33 AM alma.acs.container.ContainerServicesImpl getComponent
INFO: client 'MASTER_SCHEDULER' attempts to retrieve component 'ControlSystem1' more than once; will return existing reference.
May 26, 2004 7:11:33 AM alma.scheduling.master_scheduler.ALMADispatcher sendToControl
INFO: SCHEDULING: Got control system
May 26, 2004 7:11:33 AM alma.acs.container.ContainerSealant invoke
INFO: intercepted a call to 'ControlSystem1#createSubArray'...
May 26, 2004 7:11:33 AM alma.Control.masterController.ControlSystemImpl createSubArray
INFO: createSubArray() called
May 26, 2004 7:11:33 AM alma.acs.container.ContainerServicesImpl getDynamicComponent
FINE: getDynamicComponent called with compName=ArrayController1 compType=IDL:alma/Control/ArrayController:1.0 compCode=* compContainer=* markAsDefault=false
May 26, 2004 7:11:33 AM alma.archive.components.OperationalImpl store
FINEST: Storing URI: uid://X0000000000000066/X00000005 Type: PipelineProcessingRequest
May 26, 2004 7:11:33 AM alma.archive.components.OperationalImpl store
FINEST: Schema Location for Type PipelineProcessingRequest is uid://X0000000000000064/X00000015
May 26, 2004 7:11:33 AM alma.archive.components.OperationalImpl store
FINEST: Stored: uid://X0000000000000066/X00000005 successfully
May 26, 2004 7:11:33 AM alma.scheduling.master_scheduler.ALMAArchive getPipelineProcessingRequest
INFO: ALMAArchive: getting ppr
May 26, 2004 7:11:33 AM alma.archive.components.OperationalImpl retrieve
FINEST: Getting URI: uid://X0000000000000066/X00000005
May 26, 2004 7:11:33 AM alma.archive.components.OperationalImpl retrieve
FINEST: Fetching Xml: uid://X0000000000000066/X00000005
May 26, 2004 7:11:33 AM alma.archive.components.OperationalImpl retrieve
FINEST: Fetching Status: uid://X0000000000000066/X00000005
May 26, 2004 7:11:33 AM alma.archive.components.OperationalImpl retrieve
FINEST: Building Result: uid://X0000000000000066/X00000005
May 26, 2004 7:11:33 AM alma.archive.components.OperationalImpl retrieve
FINEST: Schema: uid://X0000000000000064/X00000015
May 26, 2004 7:11:33 AM alma.archive.components.OperationalImpl retrieve
FINEST: Type name: PipelineProcessingRequest
May 26, 2004 7:11:33 AM alma.archive.components.OperationalImpl retrieve
FINEST: Version: 0
May 26, 2004 7:11:33 AM alma.archive.components.OperationalImpl retrieve
FINEST: Time Stamp: 2004-05-26T07:11:33.458
May 26, 2004 7:11:33 AM alma.acs.container.ContainerServicesImpl getComponent
FINE: will retrieve remote component 'SCIENCE_PIPELINE' using ACS Manager#get_component
May 26, 2004 7:11:33 AM alma.acs.container.ContainerServicesImpl getComponent
FINE: component SCIENCE_PIPELINE retrieved successfully.
May 26, 2004 7:11:33 AM alma.acs.container.ContainerSealant invoke
INFO: intercepted a call to 'SCIENCE_PIPELINE#processRequest'...
May 26, 2004 7:11:33 AM alma.pipelinescience.components.SciencePipelineImpl processRequest
INFO: SCIENCE_PIPELINE: processRequest() method initiated
May 26, 2004 7:11:33 AM alma.acs.container.ContainerSealant invoke
INFO: intercepted a call to 'IDENTIFIER_ARCHIVE#getIdNamespace'...
May 26, 2004 7:11:33 AM alma.acs.container.ContainerSealant invoke
INFO: returning from IDENTIFIER_ARCHIVE#getIdNamespace after 5 ms.
May 26, 2004 7:11:33 AM alma.pipelinescience.components.SciencePipelineImpl processRequest
INFO: SCIENCE_PIPELINE: identifier archive accessed
May 26, 2004 7:11:33 AM alma.pipelinescience.components.SciencePipelineImpl processRequest
INFO: SCIENCE_PIPELINE: listobject created
May 26, 2004 7:11:33 AM alma.acs.container.ContainerSealant invoke
INFO: returning from SCIENCE_PIPELINE#processRequest after 14 ms.
May 26, 2004 7:11:33 AM alma.scheduling.project_manager.ALMAPipeline processRequest
INFO: SCHEDULING: uid://X0000000000000067/X00000000
SCHEDULING: uid://X0000000000000067/X00000000
uid://X0000000000000066/X00000005 uid://X0000000000000067/X00000000 queued
uid://X0000000000000066/X00000005 uid://X0000000000000067/X00000000 queued
May 26, 2004 7:11:33 AM alma.acs.container.AcsContainer activate_component
INFO: <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
May 26, 2004 7:11:33 AM alma.acs.container.AcsContainer activate_component
INFO: activate_component: handle=16777228 name=ArrayController1 helperClass=alma.Control.arrayInterfaces.ArrayControllerHelper type=IDL:alma/Control/ArrayController:1.0
May 26, 2004 7:11:33 AM alma.acs.container.AcsContainer createComponentHelper
FINER: creating component helper instance of type alma.Control.arrayInterfaces.ArrayControllerHelper
May 26, 2004 7:11:33 AM alma.acs.container.ComponentHelper getComponentImpl
FINER: component implementation class 'alma.Control.arrayInterfaces.ArrayControllerImpl' instantiated.
May 26, 2004 7:11:33 AM alma.acs.container.AcsContainer activate_component
FINER: component ArrayController1 implements operations interface directly; no dynamic translator proxy used.
[ POA ComponentPOAArrayController1 - ready ]
May 26, 2004 7:11:33 AM alma.acs.container.ComponentAdapter activateComponent
FINER: entering ComponentAdapter#activateComponent for ArrayController1
May 26, 2004 7:11:33 AM alma.acs.container.corba.AcsCorba activateComponent
FINER: entering activateComponent: name=ArrayController1
May 26, 2004 7:11:33 AM alma.acs.container.corba.AcsCorba activateComponent
FINER: component 'ArrayController1' activated as CORBA object.
May 26, 2004 7:11:33 AM alma.acs.container.ComponentAdapter _getInterfaces
FINE: interfaces of component 'ArrayController1': IDL:alma/Control/ArrayController:1.0IDL:alma/ACS/ACSComponent:1.0IDL:omg.org/CORBA/Object:1.0IDL:alma/Control/ArrayMonitor:1.0
May 26, 2004 7:11:33 AM alma.acs.container.AcsContainer activate_component
FINE: about to initialize component ArrayController1
May 26, 2004 7:11:33 AM alma.acs.container.ComponentStateManagerImpl setState
FINER: switching state of component ArrayController1 from NEW to INITIALIZING
May 26, 2004 7:11:33 AM alma.acs.logging.ClientLogManager getLoggerForComponent
FINE: a logger for component .ArrayController1 is available.
May 26, 2004 7:11:33 AM alma.Control.arrayInterfaces.ArrayMonitorImpl initialize
INFO: CONTROL: ArrayMonitorImpl.initialize() called...
May 26, 2004 7:11:33 AM alma.acs.container.ContainerServicesImpl getComponent
FINE: will retrieve remote component 'ARCHIVE_CONNECTION' using ACS Manager#get_component
May 26, 2004 7:11:33 AM alma.acs.container.ContainerServicesImpl getComponent
FINE: component ARCHIVE_CONNECTION retrieved successfully.
May 26, 2004 7:11:33 AM alma.acs.container.ContainerSealant invoke
INFO: intercepted a call to 'ARCHIVE_CONNECTION#getOperational'...
May 26, 2004 7:11:33 AM alma.archive.components.OperationalImpl connect
INFO: Connected to the internal interface
May 26, 2004 7:11:33 AM alma.archive.components.OperationalImpl connect
INFO: Connected to the Liatener Manager
May 26, 2004 7:11:33 AM alma.acs.container.corba.AcsCorba activateOffShoot
FINER: offshoot of type 'alma.archive.components.OperationalImpl' activated as a CORBA object.
May 26, 2004 7:11:33 AM alma.acs.container.ContainerSealant invoke
INFO: returning from ARCHIVE_CONNECTION#getOperational after 3 ms.
May 26, 2004 7:11:33 AM alma.acs.logging.ClientLogManager getLoggerForComponent
FINE: a logger for component .ArrayController1 is available.
May 26, 2004 7:11:33 AM alma.acs.logging.ClientLogManager getLoggerForComponent
FINE: a logger for component .ArrayController1 is available.
May 26, 2004 7:11:33 AM alma.Control.arrayInterfaces.ArrayControllerImpl initialize
INFO: CONTROL: ArrayControllerImpl.initialize() called...
Suppler.subscription_change(...) the 'CONTROLSYSTEM' channel: override to do something useful.
Suppler.subscription_change(...) the 'CONTROLSYSTEM' channel: override to do something useful.
Suppler.subscription_change(...) the 'CONTROLSYSTEM' channel: override to do something useful.
May 26, 2004 7:11:33 AM alma.acs.container.ComponentStateManagerImpl setState
FINER: switching state of component ArrayController1 from INITIALIZING to INITIALIZED
May 26, 2004 7:11:33 AM alma.Control.arrayInterfaces.ArrayMonitorImpl execute
INFO: eArrayMonitorImpl.xecute() called...
May 26, 2004 7:11:33 AM alma.acs.container.ComponentStateManagerImpl setState
FINER: switching state of component ArrayController1 from INITIALIZED to OPERATIONAL
May 26, 2004 7:11:33 AM alma.acs.container.AcsContainer activate_component
INFO: component ArrayController1 activated and initialized in 70 ms.
May 26, 2004 7:11:33 AM alma.acs.container.AcsContainer activate_component
INFO: >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
May 26, 2004 7:11:34 AM alma.acs.container.ContainerSealant invoke
INFO: returning from ControlSystem1#createSubArray after 600 ms.
May 26, 2004 7:11:34 AM alma.scheduling.master_scheduler.ALMADispatcher sendToControl
INFO: SCHEDULING: Got array controller
May 26, 2004 7:11:34 AM alma.acs.container.ContainerSealant invoke
INFO: intercepted a call to 'ArrayController1#observeNow'...
May 26, 2004 7:11:34 AM alma.Control.arrayInterfaces.ArrayControllerImpl observe
INFO: observe() called...
May 26, 2004 7:11:34 AM alma.archive.components.OperationalImpl retrieve
FINEST: Getting URI: uid://X0000000000000065/X00000002
May 26, 2004 7:11:34 AM alma.archive.components.OperationalImpl retrieve
FINEST: Fetching Xml: uid://X0000000000000065/X00000002
May 26, 2004 7:11:34 AM alma.archive.components.OperationalImpl retrieve
FINEST: Fetching Status: uid://X0000000000000065/X00000002
May 26, 2004 7:11:34 AM alma.archive.components.OperationalImpl retrieve
FINEST: Building Result: uid://X0000000000000065/X00000002
May 26, 2004 7:11:34 AM alma.archive.components.OperationalImpl retrieve
FINEST: Schema: uid://X0000000000000064/X0000000f
May 26, 2004 7:11:34 AM alma.archive.components.OperationalImpl retrieve
FINEST: Type name: SchedBlock
May 26, 2004 7:11:34 AM alma.archive.components.OperationalImpl retrieve
FINEST: Version: 0
May 26, 2004 7:11:34 AM alma.archive.components.OperationalImpl retrieve
FINEST: Time Stamp: 2004-05-26T07:11:33.353
May 26, 2004 7:11:34 AM alma.archive.components.OperationalImpl store
FINEST: Storing URI: uid://X0000000000000066/X00000006 Type: ExecBlock
May 26, 2004 7:11:34 AM alma.archive.components.OperationalImpl store
FINEST: Schema Location for Type ExecBlock is uid://X0000000000000064/X00000010
May 26, 2004 7:11:34 AM alma.archive.components.OperationalImpl store
FINEST: Stored: uid://X0000000000000066/X00000006 successfully
May 26, 2004 7:11:36 AM alma.Control.arrayInterfaces.ArrayControllerImpl observe
INFO: CONTROL: send ExecBlockEvent
SCHEDULING: Control event received in scheduler receiver!
May 26, 2004 7:11:36 AM alma.scheduling.receivers.ControlEventReceiver push_structured_event
INFO: SCHEDULING: Got event from control
May 26, 2004 7:11:36 AM alma.scheduling.receivers.ControlEventReceiver push_structured_event
INFO: SCHEDULING: Event reason = started
May 26, 2004 7:11:36 AM alma.scheduling.receivers.ControlEventReceiver push_structured_event
INFO: SCHEDULING: Received sb start event from control.
SCHEDULING: Got event from Control (scheduler receiver)
SCHEDULING: process sched event started
SCHEDULING: in scheduler, id=uid://X0000000000000065/X00000002
SCHEDULING: Sb ids match!
SCHEDULING: id is in queue.. do something
May 26, 2004 7:11:38 AM alma.Control.arrayInterfaces.ArrayControllerImpl observe
INFO: CONTROL: send ObsEvent
May 26, 2004 7:11:43 AM alma.acs.container.ContainerSealant invoke
INFO: intercepted a call to 'GETTELCALRESULTS1#publishPointingResult'...
May 26, 2004 7:11:43 AM alma.TelCalPublisher.GetTelCalResultsImpl.GetTelCalResultsImpl publishPointingResult
INFO: publishPointingResult...
PointingResultConverter...
May 26, 2004 7:11:43 AM alma.TelCalPublisher.GetTelCalResultsImpl.GetTelCalResultsImpl storeResultInList
INFO: list size=3
May 26, 2004 7:11:43 AM alma.TelCalPublisher.GetTelCalResultsImpl.GetTelCalResultsImpl sendEvent
INFO: sendEvent
pointing event
May 26, 2004 7:11:43 AM alma.acs.container.ContainerSealant invoke
INFO: intercepted a call to 'GETTELCALRESULTS1#publishPointingResult'...
May 26, 2004 7:11:43 AM alma.TelCalPublisher.GetTelCalResultsImpl.GetTelCalResultsImpl publishPointingResult
INFO: publishPointingResult...
PointingResultConverter...
May 26, 2004 7:11:43 AM alma.TelCalPublisher.GetTelCalResultsImpl.GetTelCalResultsImpl storeResultInList
INFO: list size=4
May 26, 2004 7:11:43 AM alma.TelCalPublisher.GetTelCalResultsImpl.GetTelCalResultsImpl sendEvent
INFO: sendEvent
pointing event
SCHEDULING: Got PointingReduced event
SCHEDULING: Starting to process the PointingReduced event
pointing event: end
pointing event: end
May 26, 2004 7:11:43 AM alma.archive.components.OperationalImpl store
FINEST: Storing URI: uid://X0000000000000066/X00000007 Type: PointingResult
May 26, 2004 7:11:43 AM alma.archive.components.OperationalImpl store
FINEST: Schema Location for Type PointingResult is uid://X0000000000000064/X00000014
SCHEDULING: Got PointingReduced event
SCHEDULING: Starting to process the PointingReduced event
May 26, 2004 7:11:43 AM alma.archive.components.OperationalImpl store
FINEST: Storing URI: uid://X0000000000000066/X00000008 Type: PointingResult
May 26, 2004 7:11:43 AM alma.archive.components.OperationalImpl store
FINEST: Schema Location for Type PointingResult is uid://X0000000000000064/X00000014
May 26, 2004 7:11:43 AM alma.archive.components.OperationalImpl store
FINEST: Stored: uid://X0000000000000066/X00000007 successfully
xmlEntity= alma.xmlentity.XmlEntityStruct@106df95
May 26, 2004 7:11:43 AM alma.acs.container.ContainerSealant invoke
INFO: returning from GETTELCALRESULTS1#publishPointingResult after 118 ms.
May 26, 2004 7:11:43 AM alma.archive.components.OperationalImpl store
FINEST: Stored: uid://X0000000000000066/X00000008 successfully
xmlEntity= alma.xmlentity.XmlEntityStruct@40afb9
May 26, 2004 7:11:43 AM alma.acs.container.ContainerSealant invoke
INFO: returning from GETTELCALRESULTS1#publishPointingResult after 123 ms.
uid://X0000000000000066/X00000005 uid://X0000000000000067/X00000000 running
SCHEDULING: Control event received in scheduler receiver!
May 26, 2004 7:11:44 AM alma.scheduling.receivers.ControlEventReceiver push_structured_event
INFO: SCHEDULING: Got event from control
May 26, 2004 7:11:44 AM alma.acs.container.ContainerSealant invoke
INFO: returning from ArrayController1#observeNow after 10061 ms.
May 26, 2004 7:11:44 AM alma.scheduling.receivers.ControlEventReceiver push_structured_event
INFO: SCHEDULING: Event reason = end
May 26, 2004 7:11:44 AM alma.scheduling.scheduler.Scheduler run
INFO: SCHEDULING: waiting til sb is done processing
May 26, 2004 7:11:44 AM alma.scheduling.receivers.ControlEventReceiver push_structured_event
INFO: SCHEDULING: Received sb end event from control.
SCHEDULING: Got event from Control (scheduler receiver)
SCHEDULING: process sched event started
SCHEDULING: in scheduler, id=uid://X0000000000000065/X00000002
SCHEDULING: Sb ids match!
SCHEDULING: id is in queue.. do something
May 26, 2004 7:11:44 AM alma.scheduling.receivers.ControlEventReceiver receive
INFO: SCHEDULING: Starting to process the control event
May 26, 2004 7:11:44 AM alma.scheduling.receivers.ControlEventReceiver receive
INFO: SCHEDULING: Event reason = end
May 26, 2004 7:11:44 AM alma.scheduling.scheduler.Scheduler run
INFO: SCHEDULING: scheduler woken up!
May 26, 2004 7:11:44 AM alma.scheduling.receivers.ControlEventReceiver receive
INFO: SCHEDULING: Received sb end event from control.
SCHEDULING: process control event started
May 26, 2004 7:11:44 AM alma.scheduling.master_scheduler.ALMAArchive updateSchedBlock
INFO: SCHEDULING: sb id=uid://X0000000000000065/X00000002
May 26, 2004 7:11:44 AM alma.scheduling.master_scheduler.ALMAArchive updateSchedBlock
INFO: SCHEDULING: ** This is where the sb will be linked to its execblock **
May 26, 2004 7:11:44 AM alma.scheduling.master_scheduler.ALMATelescopeOperator sortSBs
INFO: SCHEDULING: sorting SBs!
May 26, 2004 7:11:44 AM alma.archive.components.OperationalImpl retrieve
FINEST: Getting URI: uid://X0000000000000065/X00000002
May 26, 2004 7:11:44 AM alma.archive.components.OperationalImpl retrieve
FINEST: Fetching Xml: uid://X0000000000000065/X00000002
May 26, 2004 7:11:44 AM alma.archive.components.OperationalImpl query
FINE: Querying XPath: /sbl:SchedBlock Schema: SchedBlock
May 26, 2004 7:11:44 AM alma.archive.components.OperationalImpl query
FINEST: Schema location for SchedBlock is uid://X0000000000000064/X0000000f
May 26, 2004 7:11:44 AM alma.archive.components.OperationalImpl retrieve
FINEST: Fetching Status: uid://X0000000000000065/X00000002
May 26, 2004 7:11:44 AM alma.archive.components.OperationalImpl retrieve
FINEST: Building Result: uid://X0000000000000065/X00000002
May 26, 2004 7:11:44 AM alma.archive.components.OperationalImpl retrieve
FINEST: Schema: uid://X0000000000000064/X0000000f
May 26, 2004 7:11:44 AM alma.archive.components.OperationalImpl retrieve
FINEST: Type name: SchedBlock
May 26, 2004 7:11:44 AM alma.archive.components.OperationalImpl retrieve
FINEST: Version: 0
May 26, 2004 7:11:44 AM alma.archive.components.OperationalImpl retrieve
FINEST: Time Stamp: 2004-05-26T07:11:33.353
May 26, 2004 7:11:44 AM alma.archive.components.OperationalImpl retrieve
FINEST: Getting URI: uid://X0000000000000065/X00000002
May 26, 2004 7:11:44 AM alma.archive.components.OperationalImpl retrieve
FINEST: Fetching Xml: uid://X0000000000000065/X00000002
May 26, 2004 7:11:44 AM alma.archive.components.OperationalImpl retrieve
FINEST: Fetching Status: uid://X0000000000000065/X00000002
May 26, 2004 7:11:44 AM alma.archive.components.OperationalImpl query
FINE: Returning cursor to user
May 26, 2004 7:11:44 AM alma.acs.container.corba.AcsCorba activateOffShoot
FINER: offshoot of type 'alma.archive.components.CursorImpl' activated as a CORBA object.
May 26, 2004 7:11:44 AM alma.archive.components.OperationalImpl retrieve
FINEST: Building Result: uid://X0000000000000065/X00000002
May 26, 2004 7:11:44 AM alma.archive.components.OperationalImpl retrieve
FINEST: Schema: uid://X0000000000000064/X0000000f
May 26, 2004 7:11:44 AM alma.archive.components.OperationalImpl retrieve
FINEST: Type name: SchedBlock
May 26, 2004 7:11:44 AM alma.archive.components.OperationalImpl retrieve
FINEST: Version: 0
May 26, 2004 7:11:44 AM alma.archive.components.OperationalImpl retrieve
FINEST: Time Stamp: 2004-05-26T07:11:33.353
May 26, 2004 7:11:44 AM alma.archive.components.OperationalImpl update
FINEST: Updating: uid://X0000000000000065/X00000002
May 26, 2004 7:11:44 AM alma.scheduling.master_scheduler.ALMATelescopeOperator isCompletedSb
INFO: SCHEDULING: checking for non-complete SB
May 26, 2004 7:11:44 AM alma.archive.components.OperationalImpl query
FINE: Querying XPath: /sbl:SchedBlock Schema: SchedBlock
May 26, 2004 7:11:44 AM alma.archive.components.OperationalImpl query
FINEST: Schema location for SchedBlock is uid://X0000000000000064/X0000000f
May 26, 2004 7:11:44 AM alma.archive.components.OperationalImpl store
FINEST: Storing URI: uid://X0000000000000066/X0000000a Type: PipelineProcessingRequest
May 26, 2004 7:11:44 AM alma.archive.components.OperationalImpl store
FINEST: Schema Location for Type PipelineProcessingRequest is uid://X0000000000000064/X00000015
May 26, 2004 7:11:45 AM alma.archive.components.OperationalImpl query
FINE: Returning cursor to user
May 26, 2004 7:11:45 AM alma.acs.container.corba.AcsCorba activateOffShoot
FINER: offshoot of type 'alma.archive.components.CursorImpl' activated as a CORBA object.
May 26, 2004 7:11:45 AM alma.archive.components.OperationalImpl store
FINEST: Stored: uid://X0000000000000066/X0000000a successfully
May 26, 2004 7:11:45 AM alma.scheduling.master_scheduler.ALMAArchive getPipelineProcessingRequest
INFO: ALMAArchive: getting ppr
May 26, 2004 7:11:45 AM alma.archive.components.OperationalImpl retrieve
FINEST: Getting URI: uid://X0000000000000066/X0000000a
May 26, 2004 7:11:45 AM alma.archive.components.OperationalImpl retrieve
FINEST: Fetching Xml: uid://X0000000000000066/X0000000a
May 26, 2004 7:11:45 AM alma.archive.components.OperationalImpl retrieve
FINEST: Fetching Status: uid://X0000000000000066/X0000000a
May 26, 2004 7:11:45 AM alma.archive.components.OperationalImpl retrieve
FINEST: Building Result: uid://X0000000000000066/X0000000a
May 26, 2004 7:11:45 AM alma.archive.components.OperationalImpl retrieve
FINEST: Schema: uid://X0000000000000064/X00000015
May 26, 2004 7:11:45 AM alma.archive.components.OperationalImpl retrieve
FINEST: Type name: PipelineProcessingRequest
May 26, 2004 7:11:45 AM alma.archive.components.OperationalImpl retrieve
FINEST: Version: 0
May 26, 2004 7:11:45 AM alma.archive.components.OperationalImpl retrieve
FINEST: Time Stamp: 2004-05-26T07:11:44.812
May 26, 2004 7:11:45 AM alma.acs.container.ContainerServicesImpl getComponent
INFO: client 'MASTER_SCHEDULER' attempts to retrieve component 'SCIENCE_PIPELINE' more than once; will return existing reference.
May 26, 2004 7:11:45 AM alma.acs.container.ContainerSealant invoke
INFO: intercepted a call to 'SCIENCE_PIPELINE#processRequest'...
May 26, 2004 7:11:45 AM alma.pipelinescience.components.SciencePipelineImpl processRequest
INFO: SCIENCE_PIPELINE: processRequest() method initiated
May 26, 2004 7:11:45 AM alma.acs.container.ContainerSealant invoke
INFO: intercepted a call to 'IDENTIFIER_ARCHIVE#getIdNamespace'...
May 26, 2004 7:11:45 AM alma.acs.container.ContainerSealant invoke
INFO: returning from IDENTIFIER_ARCHIVE#getIdNamespace after 8 ms.
May 26, 2004 7:11:45 AM alma.pipelinescience.components.SciencePipelineImpl processRequest
INFO: SCIENCE_PIPELINE: identifier archive accessed
May 26, 2004 7:11:45 AM alma.pipelinescience.components.SciencePipelineImpl processRequest
INFO: SCIENCE_PIPELINE: listobject created
uid://X0000000000000066/X0000000a uid://X0000000000000068/X00000000 queued
uid://X0000000000000066/X0000000a uid://X0000000000000068/X00000000 queued
May 26, 2004 7:11:45 AM alma.acs.container.ContainerSealant invoke
INFO: returning from SCIENCE_PIPELINE#processRequest after 33 ms.
May 26, 2004 7:11:45 AM alma.scheduling.project_manager.ALMAPipeline processRequest
INFO: SCHEDULING: uid://X0000000000000068/X00000000
SCHEDULING: uid://X0000000000000068/X00000000
May 26, 2004 7:11:45 AM alma.scheduling.master_scheduler.ALMATelescopeOperator isCompletedSb
INFO: SCHEDULING: checking for non-complete SB
May 26, 2004 7:11:45 AM alma.scheduling.master_scheduler.ALMATelescopeOperator selectSB
INFO: SCHEDULING: in TO. reply =uid://X0000000000000065/X00000003
May 26, 2004 7:11:45 AM alma.acs.container.ContainerServicesImpl getComponent
INFO: client 'MASTER_SCHEDULER' attempts to retrieve component 'MASTER_SCHEDULER' more than once; will return existing reference.
May 26, 2004 7:11:45 AM alma.scheduling.master_scheduler.ALMATelescopeOperator selectSB
INFO: SCHEDULING: in TO. ms response about to be called
May 26, 2004 7:11:45 AM alma.acs.container.ContainerSealant invoke
INFO: intercepted a call to 'MASTER_SCHEDULER#response'...
May 26, 2004 7:11:45 AM alma.scheduling.master_scheduler.MasterScheduler response
INFO: SCHEDULING: in MS. MessageID = uid://X0000000000000066/X00000009
May 26, 2004 7:11:45 AM alma.scheduling.master_scheduler.MasterScheduler response
INFO: SCHEDULING: in MS. Reply (sb id) = uid://X0000000000000065/X00000003
May 26, 2004 7:11:45 AM alma.scheduling.master_scheduler.MasterScheduler response
INFO: SCHEDULING: in MS. messageQueue size = 1
May 26, 2004 7:11:45 AM alma.scheduling.master_scheduler.MasterScheduler response
INFO: SCHEDULING: in MS. Got message with id=uid://X0000000000000066/X00000009
May 26, 2004 7:11:45 AM alma.scheduling.master_scheduler.MasterScheduler response
INFO: SCHEDULING: in MS. message = uid://X0000000000000066/X00000009 gotten and reply = uid://X0000000000000065/X00000003 sent.
May 26, 2004 7:11:45 AM alma.acs.container.ContainerSealant invoke
INFO: returning from MASTER_SCHEDULER#response after 3 ms.
May 26, 2004 7:11:45 AM alma.scheduling.master_scheduler.ALMATelescopeOperator selectSB
INFO: SCHEDULING: in TO. ms response called
May 26, 2004 7:11:45 AM alma.scheduling.master_scheduler.ALMATelescopeOperator selectSB
INFO: SCHEDULING: in TO. timer.join()
May 26, 2004 7:11:45 AM alma.scheduling.scheduler.Scheduler run
INFO: SCHEDULING: in scheduler. selectedSB = uid://X0000000000000065/X00000003
May 26, 2004 7:11:45 AM alma.scheduling.scheduler.Scheduler run
INFO: SCHEDULING: Message uid://X0000000000000066/X00000009 removed from queue.
May 26, 2004 7:11:45 AM alma.scheduling.master_scheduler.ALMADispatcher sendToControl
INFO: SCHEDULING: Sending SB with id = uid://X0000000000000065/X00000003 to controller.
May 26, 2004 7:11:45 AM alma.acs.container.ContainerServicesImpl getComponent
INFO: client 'MASTER_SCHEDULER' attempts to retrieve component 'ControlSystem1' more than once; will return existing reference.
May 26, 2004 7:11:45 AM alma.scheduling.master_scheduler.ALMADispatcher sendToControl
INFO: SCHEDULING: Got control system
May 26, 2004 7:11:45 AM alma.acs.container.ContainerSealant invoke
INFO: intercepted a call to 'ControlSystem1#createSubArray'...
May 26, 2004 7:11:45 AM alma.Control.masterController.ControlSystemImpl createSubArray
INFO: createSubArray() called
May 26, 2004 7:11:45 AM alma.acs.container.ContainerServicesImpl getDynamicComponent
FINE: getDynamicComponent called with compName=ArrayController2 compType=IDL:alma/Control/ArrayController:1.0 compCode=* compContainer=* markAsDefault=false
May 26, 2004 7:11:46 AM alma.acs.container.AcsContainer activate_component
INFO: <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
May 26, 2004 7:11:46 AM alma.acs.container.AcsContainer activate_component
INFO: activate_component: handle=16777229 name=ArrayController2 helperClass=alma.Control.arrayInterfaces.ArrayControllerHelper type=IDL:alma/Control/ArrayController:1.0
May 26, 2004 7:11:46 AM alma.acs.container.AcsContainer createComponentHelper
FINER: creating component helper instance of type alma.Control.arrayInterfaces.ArrayControllerHelper
May 26, 2004 7:11:46 AM alma.acs.container.ComponentHelper getComponentImpl
FINER: component implementation class 'alma.Control.arrayInterfaces.ArrayControllerImpl' instantiated.
May 26, 2004 7:11:46 AM alma.acs.container.AcsContainer activate_component
FINER: component ArrayController2 implements operations interface directly; no dynamic translator proxy used.
[ POA ComponentPOAArrayController2 - ready ]
May 26, 2004 7:11:46 AM alma.acs.container.ComponentAdapter activateComponent
FINER: entering ComponentAdapter#activateComponent for ArrayController2
May 26, 2004 7:11:46 AM alma.acs.container.corba.AcsCorba activateComponent
FINER: entering activateComponent: name=ArrayController2
May 26, 2004 7:11:46 AM alma.acs.container.corba.AcsCorba activateComponent
FINER: component 'ArrayController2' activated as CORBA object.
May 26, 2004 7:11:46 AM alma.acs.container.ComponentAdapter _getInterfaces
FINE: interfaces of component 'ArrayController2': IDL:alma/Control/ArrayController:1.0IDL:alma/ACS/ACSComponent:1.0IDL:omg.org/CORBA/Object:1.0IDL:alma/Control/ArrayMonitor:1.0
May 26, 2004 7:11:46 AM alma.acs.container.AcsContainer activate_component
FINE: about to initialize component ArrayController2
May 26, 2004 7:11:46 AM alma.acs.container.ComponentStateManagerImpl setState
FINER: switching state of component ArrayController2 from NEW to INITIALIZING
May 26, 2004 7:11:46 AM alma.acs.logging.ClientLogManager getLoggerForComponent
FINE: a logger for component .ArrayController2 is available.
May 26, 2004 7:11:46 AM alma.Control.arrayInterfaces.ArrayMonitorImpl initialize
INFO: CONTROL: ArrayMonitorImpl.initialize() called...
May 26, 2004 7:11:46 AM alma.acs.container.ContainerServicesImpl getComponent
FINE: will retrieve remote component 'ARCHIVE_CONNECTION' using ACS Manager#get_component
May 26, 2004 7:11:46 AM alma.acs.container.ContainerServicesImpl getComponent
FINE: component ARCHIVE_CONNECTION retrieved successfully.
May 26, 2004 7:11:46 AM alma.acs.container.ContainerSealant invoke
INFO: intercepted a call to 'ARCHIVE_CONNECTION#getOperational'...
May 26, 2004 7:11:46 AM alma.archive.components.OperationalImpl connect
INFO: Connected to the internal interface
May 26, 2004 7:11:46 AM alma.archive.components.OperationalImpl connect
INFO: Connected to the Liatener Manager
May 26, 2004 7:11:46 AM alma.acs.container.corba.AcsCorba activateOffShoot
FINER: offshoot of type 'alma.archive.components.OperationalImpl' activated as a CORBA object.
May 26, 2004 7:11:46 AM alma.acs.container.ContainerSealant invoke
INFO: returning from ARCHIVE_CONNECTION#getOperational after 3 ms.
May 26, 2004 7:11:46 AM alma.acs.logging.ClientLogManager getLoggerForComponent
FINE: a logger for component .ArrayController2 is available.
May 26, 2004 7:11:46 AM alma.acs.logging.ClientLogManager getLoggerForComponent
FINE: a logger for component .ArrayController2 is available.
May 26, 2004 7:11:46 AM alma.Control.arrayInterfaces.ArrayControllerImpl initialize
INFO: CONTROL: ArrayControllerImpl.initialize() called...
Suppler.subscription_change(...) the 'CONTROLSYSTEM' channel: override to do something useful.
Suppler.subscription_change(...) the 'CONTROLSYSTEM' channel: override to do something useful.
Suppler.subscription_change(...) the 'CONTROLSYSTEM' channel: override to do something useful.
May 26, 2004 7:11:46 AM alma.acs.container.ComponentStateManagerImpl setState
FINER: switching state of component ArrayController2 from INITIALIZING to INITIALIZED
May 26, 2004 7:11:46 AM alma.Control.arrayInterfaces.ArrayMonitorImpl execute
INFO: eArrayMonitorImpl.xecute() called...
May 26, 2004 7:11:46 AM alma.acs.container.ComponentStateManagerImpl setState
FINER: switching state of component ArrayController2 from INITIALIZED to OPERATIONAL
May 26, 2004 7:11:46 AM alma.acs.container.AcsContainer activate_component
INFO: component ArrayController2 activated and initialized in 46 ms.
May 26, 2004 7:11:46 AM alma.acs.container.AcsContainer activate_component
INFO: >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
May 26, 2004 7:11:46 AM alma.acs.container.ContainerSealant invoke
INFO: returning from ControlSystem1#createSubArray after 567 ms.
May 26, 2004 7:11:46 AM alma.scheduling.master_scheduler.ALMADispatcher sendToControl
INFO: SCHEDULING: Got array controller
May 26, 2004 7:11:46 AM alma.acs.container.ContainerSealant invoke
INFO: intercepted a call to 'ArrayController2#observeNow'...
May 26, 2004 7:11:46 AM alma.Control.arrayInterfaces.ArrayControllerImpl observe
INFO: observe() called...
May 26, 2004 7:11:46 AM alma.archive.components.OperationalImpl retrieve
FINEST: Getting URI: uid://X0000000000000065/X00000003
May 26, 2004 7:11:46 AM alma.archive.components.OperationalImpl retrieve
FINEST: Fetching Xml: uid://X0000000000000065/X00000003
May 26, 2004 7:11:46 AM alma.archive.components.OperationalImpl retrieve
FINEST: Fetching Status: uid://X0000000000000065/X00000003
May 26, 2004 7:11:46 AM alma.archive.components.OperationalImpl retrieve
FINEST: Building Result: uid://X0000000000000065/X00000003
May 26, 2004 7:11:46 AM alma.archive.components.OperationalImpl retrieve
FINEST: Schema: uid://X0000000000000064/X0000000f
May 26, 2004 7:11:46 AM alma.archive.components.OperationalImpl retrieve
FINEST: Type name: SchedBlock
May 26, 2004 7:11:46 AM alma.archive.components.OperationalImpl retrieve
FINEST: Version: 0
May 26, 2004 7:11:46 AM alma.archive.components.OperationalImpl retrieve
FINEST: Time Stamp: 2004-05-26T07:10:23.006
May 26, 2004 7:11:46 AM alma.archive.components.OperationalImpl store
FINEST: Storing URI: uid://X0000000000000066/X0000000b Type: ExecBlock
May 26, 2004 7:11:46 AM alma.archive.components.OperationalImpl store
FINEST: Schema Location for Type ExecBlock is uid://X0000000000000064/X00000010
May 26, 2004 7:11:46 AM alma.archive.components.OperationalImpl store
FINEST: Stored: uid://X0000000000000066/X0000000b successfully
May 26, 2004 7:11:48 AM alma.Control.arrayInterfaces.ArrayControllerImpl observe
INFO: CONTROL: send ExecBlockEvent
SCHEDULING: Control event received in scheduler receiver!
SCHEDULING: Got event from Control (scheduler receiver)
SCHEDULING: process sched event started
SCHEDULING: in scheduler, id=uid://X0000000000000065/X00000003
SCHEDULING: Sb ids match!
SCHEDULING: id is in queue.. do something
May 26, 2004 7:11:48 AM alma.scheduling.receivers.ControlEventReceiver push_structured_event
INFO: SCHEDULING: Got event from control
May 26, 2004 7:11:48 AM alma.scheduling.receivers.ControlEventReceiver push_structured_event
INFO: SCHEDULING: Event reason = started
May 26, 2004 7:11:48 AM alma.scheduling.receivers.ControlEventReceiver push_structured_event
INFO: SCHEDULING: Received sb start event from control.
May 26, 2004 7:11:50 AM alma.Control.arrayInterfaces.ArrayControllerImpl observe
INFO: CONTROL: send ObsEvent
May 26, 2004 7:11:52 AM alma.acs.container.AcsContainer ping
FINER: ping received.
May 26, 2004 7:11:55 AM alma.acs.container.ContainerSealant invoke
INFO: intercepted a call to 'GETTELCALRESULTS1#publishPointingResult'...
May 26, 2004 7:11:55 AM alma.acs.container.ContainerSealant invoke
INFO: intercepted a call to 'GETTELCALRESULTS1#publishPointingResult'...
May 26, 2004 7:11:55 AM alma.TelCalPublisher.GetTelCalResultsImpl.GetTelCalResultsImpl publishPointingResult
INFO: publishPointingResult...
May 26, 2004 7:11:55 AM alma.TelCalPublisher.GetTelCalResultsImpl.GetTelCalResultsImpl publishPointingResult
INFO: publishPointingResult...
PointingResultConverter...
PointingResultConverter...
May 26, 2004 7:11:55 AM alma.TelCalPublisher.GetTelCalResultsImpl.GetTelCalResultsImpl storeResultInList
INFO: list size=5
May 26, 2004 7:11:55 AM alma.TelCalPublisher.GetTelCalResultsImpl.GetTelCalResultsImpl storeResultInList
INFO: list size=6
May 26, 2004 7:11:55 AM alma.TelCalPublisher.GetTelCalResultsImpl.GetTelCalResultsImpl sendEvent
INFO: sendEvent
May 26, 2004 7:11:55 AM alma.TelCalPublisher.GetTelCalResultsImpl.GetTelCalResultsImpl sendEvent
INFO: sendEvent
pointing event
pointing event
pointing event: end
May 26, 2004 7:11:55 AM alma.archive.components.OperationalImpl store
FINEST: Storing URI: uid://X0000000000000066/X0000000c Type: PointingResult
pointing event: end
May 26, 2004 7:11:55 AM alma.archive.components.OperationalImpl store
FINEST: Schema Location for Type PointingResult is uid://X0000000000000064/X00000014
SCHEDULING: Got PointingReduced event
SCHEDULING: Starting to process the PointingReduced event
May 26, 2004 7:11:55 AM alma.archive.components.OperationalImpl store
FINEST: Stored: uid://X0000000000000066/X0000000c successfully
xmlEntity= alma.xmlentity.XmlEntityStruct@1321f5
May 26, 2004 7:11:55 AM alma.acs.container.ContainerSealant invoke
INFO: returning from GETTELCALRESULTS1#publishPointingResult after 109 ms.
uid://X0000000000000066/X0000000a uid://X0000000000000068/X00000000 running
SCHEDULING: Got PointingReduced event
SCHEDULING: Starting to process the PointingReduced event
May 26, 2004 7:11:55 AM alma.archive.components.OperationalImpl store
FINEST: Storing URI: uid://X0000000000000066/X0000000d Type: PointingResult
May 26, 2004 7:11:55 AM alma.archive.components.OperationalImpl store
FINEST: Schema Location for Type PointingResult is uid://X0000000000000064/X00000014
May 26, 2004 7:11:55 AM alma.archive.components.OperationalImpl store
FINEST: Stored: uid://X0000000000000066/X0000000d successfully
xmlEntity= alma.xmlentity.XmlEntityStruct@e31e33
May 26, 2004 7:11:55 AM alma.acs.container.ContainerSealant invoke
INFO: returning from GETTELCALRESULTS1#publishPointingResult after 386 ms.
May 26, 2004 7:11:56 AM alma.scheduling.receivers.ControlEventReceiver push_structured_event
INFO: SCHEDULING: Got event from control
May 26, 2004 7:11:56 AM alma.scheduling.receivers.ControlEventReceiver push_structured_event
INFO: SCHEDULING: Event reason = end
May 26, 2004 7:11:56 AM alma.scheduling.receivers.ControlEventReceiver push_structured_event
INFO: SCHEDULING: Received sb end event from control.
SCHEDULING: Control event received in scheduler receiver!
May 26, 2004 7:11:56 AM alma.scheduling.receivers.ControlEventReceiver receive
INFO: SCHEDULING: Starting to process the control event
SCHEDULING: Got event from Control (scheduler receiver)
May 26, 2004 7:11:56 AM alma.scheduling.receivers.ControlEventReceiver receive
INFO: SCHEDULING: Event reason = end
SCHEDULING: process sched event started
SCHEDULING: in scheduler, id=uid://X0000000000000065/X00000003
SCHEDULING: Sb ids match!
SCHEDULING: id is in queue.. do something
May 26, 2004 7:11:56 AM alma.scheduling.receivers.ControlEventReceiver receive
INFO: SCHEDULING: Received sb end event from control.
SCHEDULING: process control event started
May 26, 2004 7:11:56 AM alma.scheduling.master_scheduler.ALMAArchive updateSchedBlock
INFO: SCHEDULING: sb id=uid://X0000000000000065/X00000003
May 26, 2004 7:11:56 AM alma.acs.container.ContainerSealant invoke
INFO: returning from ArrayController2#observeNow after 10075 ms.
May 26, 2004 7:11:56 AM alma.scheduling.scheduler.Scheduler run
INFO: SCHEDULING: waiting til sb is done processing
May 26, 2004 7:11:56 AM alma.scheduling.master_scheduler.ALMAArchive updateSchedBlock
INFO: SCHEDULING: ** This is where the sb will be linked to its execblock **
May 26, 2004 7:11:56 AM alma.archive.components.OperationalImpl retrieve
FINEST: Getting URI: uid://X0000000000000065/X00000003
May 26, 2004 7:11:56 AM alma.scheduling.scheduler.Scheduler run
INFO: SCHEDULING: scheduler woken up!
May 26, 2004 7:11:56 AM alma.archive.components.OperationalImpl retrieve
FINEST: Fetching Xml: uid://X0000000000000065/X00000003
May 26, 2004 7:11:56 AM alma.scheduling.master_scheduler.ALMATelescopeOperator sortSBs
INFO: SCHEDULING: sorting SBs!
May 26, 2004 7:11:56 AM alma.archive.components.OperationalImpl query
FINE: Querying XPath: /sbl:SchedBlock Schema: SchedBlock
May 26, 2004 7:11:56 AM alma.archive.components.OperationalImpl retrieve
FINEST: Fetching Status: uid://X0000000000000065/X00000003
May 26, 2004 7:11:56 AM alma.archive.components.OperationalImpl query
FINEST: Schema location for SchedBlock is uid://X0000000000000064/X0000000f
May 26, 2004 7:11:56 AM alma.archive.components.OperationalImpl retrieve
FINEST: Building Result: uid://X0000000000000065/X00000003
May 26, 2004 7:11:56 AM alma.archive.components.OperationalImpl retrieve
FINEST: Schema: uid://X0000000000000064/X0000000f
May 26, 2004 7:11:56 AM alma.archive.components.OperationalImpl retrieve
FINEST: Type name: SchedBlock
May 26, 2004 7:11:56 AM alma.archive.components.OperationalImpl retrieve
FINEST: Version: 0
May 26, 2004 7:11:56 AM alma.archive.components.OperationalImpl retrieve
FINEST: Time Stamp: 2004-05-26T07:10:23.006
May 26, 2004 7:11:56 AM alma.archive.components.OperationalImpl retrieve
FINEST: Getting URI: uid://X0000000000000065/X00000003
May 26, 2004 7:11:56 AM alma.archive.components.OperationalImpl retrieve
FINEST: Fetching Xml: uid://X0000000000000065/X00000003
May 26, 2004 7:11:56 AM alma.archive.components.OperationalImpl retrieve
FINEST: Fetching Status: uid://X0000000000000065/X00000003
May 26, 2004 7:11:56 AM alma.archive.components.OperationalImpl query
FINE: Returning cursor to user
May 26, 2004 7:11:56 AM alma.acs.container.corba.AcsCorba activateOffShoot
FINER: offshoot of type 'alma.archive.components.CursorImpl' activated as a CORBA object.
May 26, 2004 7:11:56 AM alma.archive.components.OperationalImpl retrieve
FINEST: Building Result: uid://X0000000000000065/X00000003
May 26, 2004 7:11:56 AM alma.archive.components.OperationalImpl retrieve
FINEST: Schema: uid://X0000000000000064/X0000000f
May 26, 2004 7:11:56 AM alma.archive.components.OperationalImpl retrieve
FINEST: Type name: SchedBlock
May 26, 2004 7:11:56 AM alma.archive.components.OperationalImpl retrieve
FINEST: Version: 0
May 26, 2004 7:11:56 AM alma.archive.components.OperationalImpl retrieve
FINEST: Time Stamp: 2004-05-26T07:10:23.006
May 26, 2004 7:11:56 AM alma.archive.components.OperationalImpl update
FINEST: Updating: uid://X0000000000000065/X00000003
May 26, 2004 7:11:57 AM alma.archive.components.OperationalImpl store
FINEST: Storing URI: uid://X0000000000000066/X0000000f Type: PipelineProcessingRequest
May 26, 2004 7:11:57 AM alma.archive.components.OperationalImpl store
FINEST: Schema Location for Type PipelineProcessingRequest is uid://X0000000000000064/X00000015
May 26, 2004 7:11:57 AM alma.scheduling.master_scheduler.ALMATelescopeOperator isCompletedSb
INFO: SCHEDULING: checking for non-complete SB
May 26, 2004 7:11:57 AM alma.archive.components.OperationalImpl store
FINEST: Stored: uid://X0000000000000066/X0000000f successfully
May 26, 2004 7:11:57 AM alma.archive.components.OperationalImpl query
FINE: Querying XPath: /sbl:SchedBlock Schema: SchedBlock
May 26, 2004 7:11:57 AM alma.scheduling.master_scheduler.ALMAArchive getPipelineProcessingRequest
INFO: ALMAArchive: getting ppr
May 26, 2004 7:11:57 AM alma.archive.components.OperationalImpl retrieve
FINEST: Getting URI: uid://X0000000000000066/X0000000f
May 26, 2004 7:11:57 AM alma.archive.components.OperationalImpl retrieve
FINEST: Fetching Xml: uid://X0000000000000066/X0000000f
May 26, 2004 7:11:57 AM alma.archive.components.OperationalImpl query
FINEST: Schema location for SchedBlock is uid://X0000000000000064/X0000000f
May 26, 2004 7:11:57 AM alma.archive.components.OperationalImpl query
FINE: Returning cursor to user
May 26, 2004 7:11:57 AM alma.archive.components.OperationalImpl retrieve
FINEST: Fetching Status: uid://X0000000000000066/X0000000f
May 26, 2004 7:11:57 AM alma.acs.container.corba.AcsCorba activateOffShoot
FINER: offshoot of type 'alma.archive.components.CursorImpl' activated as a CORBA object.
May 26, 2004 7:11:57 AM alma.archive.components.OperationalImpl retrieve
FINEST: Building Result: uid://X0000000000000066/X0000000f
May 26, 2004 7:11:57 AM alma.archive.components.OperationalImpl retrieve
FINEST: Schema: uid://X0000000000000064/X00000015
May 26, 2004 7:11:57 AM alma.archive.components.OperationalImpl retrieve
FINEST: Type name: PipelineProcessingRequest
May 26, 2004 7:11:57 AM alma.archive.components.OperationalImpl retrieve
FINEST: Version: 0
May 26, 2004 7:11:57 AM alma.scheduling.master_scheduler.ALMATelescopeOperator isCompletedSb
INFO: SCHEDULING: checking for non-complete SB
May 26, 2004 7:11:57 AM alma.archive.components.OperationalImpl retrieve
FINEST: Time Stamp: 2004-05-26T07:11:57.055
May 26, 2004 7:11:57 AM alma.archive.components.OperationalImpl query
FINE: Querying XPath: /sbl:SchedBlock Schema: SchedBlock
May 26, 2004 7:11:57 AM alma.archive.components.OperationalImpl query
FINEST: Schema location for SchedBlock is uid://X0000000000000064/X0000000f
May 26, 2004 7:11:57 AM alma.acs.container.ContainerServicesImpl getComponent
INFO: client 'MASTER_SCHEDULER' attempts to retrieve component 'SCIENCE_PIPELINE' more than once; will return existing reference.
May 26, 2004 7:11:57 AM alma.acs.container.ContainerSealant invoke
INFO: intercepted a call to 'SCIENCE_PIPELINE#processRequest'...
May 26, 2004 7:11:57 AM alma.pipelinescience.components.SciencePipelineImpl processRequest
INFO: SCIENCE_PIPELINE: processRequest() method initiated
May 26, 2004 7:11:57 AM alma.acs.container.ContainerSealant invoke
INFO: intercepted a call to 'IDENTIFIER_ARCHIVE#getIdNamespace'...
May 26, 2004 7:11:57 AM alma.acs.container.ContainerSealant invoke
INFO: returning from IDENTIFIER_ARCHIVE#getIdNamespace after 7 ms.
May 26, 2004 7:11:57 AM alma.pipelinescience.components.SciencePipelineImpl processRequest
INFO: SCIENCE_PIPELINE: identifier archive accessed
May 26, 2004 7:11:57 AM alma.pipelinescience.components.SciencePipelineImpl processRequest
INFO: SCIENCE_PIPELINE: listobject created
May 26, 2004 7:11:57 AM alma.acs.container.ContainerSealant invoke
INFO: returning from SCIENCE_PIPELINE#processRequest after 10 ms.
May 26, 2004 7:11:57 AM alma.scheduling.project_manager.ALMAPipeline processRequest
INFO: SCHEDULING: uid://X0000000000000069/X00000000
SCHEDULING: uid://X0000000000000069/X00000000
uid://X0000000000000066/X0000000f uid://X0000000000000069/X00000000 queued
uid://X0000000000000066/X0000000f uid://X0000000000000069/X00000000 queued
May 26, 2004 7:11:58 AM alma.archive.components.OperationalImpl query
FINE: Returning cursor to user
May 26, 2004 7:11:58 AM alma.acs.container.corba.AcsCorba activateOffShoot
FINER: offshoot of type 'alma.archive.components.CursorImpl' activated as a CORBA object.
May 26, 2004 7:11:58 AM alma.scheduling.master_scheduler.ALMATelescopeOperator isCompletedSb
INFO: SCHEDULING: checking for non-complete SB
May 26, 2004 7:11:58 AM alma.scheduling.master_scheduler.ALMATelescopeOperator selectSB
INFO: SCHEDULING: in TO. reply =uid://X0000000000000065/X00000004
May 26, 2004 7:11:58 AM alma.acs.container.ContainerServicesImpl getComponent
INFO: client 'MASTER_SCHEDULER' attempts to retrieve component 'MASTER_SCHEDULER' more than once; will return existing reference.
May 26, 2004 7:11:58 AM alma.scheduling.master_scheduler.ALMATelescopeOperator selectSB
INFO: SCHEDULING: in TO. ms response about to be called
May 26, 2004 7:11:58 AM alma.acs.container.ContainerSealant invoke
INFO: intercepted a call to 'MASTER_SCHEDULER#response'...
May 26, 2004 7:11:58 AM alma.scheduling.master_scheduler.MasterScheduler response
INFO: SCHEDULING: in MS. MessageID = uid://X0000000000000066/X0000000e
May 26, 2004 7:11:58 AM alma.scheduling.master_scheduler.MasterScheduler response
INFO: SCHEDULING: in MS. Reply (sb id) = uid://X0000000000000065/X00000004
May 26, 2004 7:11:58 AM alma.scheduling.master_scheduler.MasterScheduler response
INFO: SCHEDULING: in MS. messageQueue size = 1
May 26, 2004 7:11:58 AM alma.scheduling.master_scheduler.MasterScheduler response
INFO: SCHEDULING: in MS. Got message with id=uid://X0000000000000066/X0000000e
May 26, 2004 7:11:58 AM alma.scheduling.master_scheduler.MasterScheduler response
INFO: SCHEDULING: in MS. message = uid://X0000000000000066/X0000000e gotten and reply = uid://X0000000000000065/X00000004 sent.
May 26, 2004 7:11:58 AM alma.acs.container.ContainerSealant invoke
INFO: returning from MASTER_SCHEDULER#response after 3 ms.
May 26, 2004 7:11:58 AM alma.scheduling.master_scheduler.ALMATelescopeOperator selectSB
INFO: SCHEDULING: in TO. ms response called
May 26, 2004 7:11:58 AM alma.scheduling.master_scheduler.ALMATelescopeOperator selectSB
INFO: SCHEDULING: in TO. timer.join()
May 26, 2004 7:11:58 AM alma.scheduling.scheduler.Scheduler run
INFO: SCHEDULING: in scheduler. selectedSB = uid://X0000000000000065/X00000004
May 26, 2004 7:11:58 AM alma.scheduling.scheduler.Scheduler run
INFO: SCHEDULING: Message uid://X0000000000000066/X0000000e removed from queue.
May 26, 2004 7:11:58 AM alma.scheduling.master_scheduler.ALMADispatcher sendToControl
INFO: SCHEDULING: Sending SB with id = uid://X0000000000000065/X00000004 to controller.
May 26, 2004 7:11:58 AM alma.acs.container.ContainerServicesImpl getComponent
INFO: client 'MASTER_SCHEDULER' attempts to retrieve component 'ControlSystem1' more than once; will return existing reference.
May 26, 2004 7:11:58 AM alma.scheduling.master_scheduler.ALMADispatcher sendToControl
INFO: SCHEDULING: Got control system
May 26, 2004 7:11:58 AM alma.acs.container.ContainerSealant invoke
INFO: intercepted a call to 'ControlSystem1#createSubArray'...
May 26, 2004 7:11:58 AM alma.Control.masterController.ControlSystemImpl createSubArray
INFO: createSubArray() called
May 26, 2004 7:11:58 AM alma.acs.container.ContainerServicesImpl getDynamicComponent
FINE: getDynamicComponent called with compName=ArrayController3 compType=IDL:alma/Control/ArrayController:1.0 compCode=* compContainer=* markAsDefault=false
May 26, 2004 7:11:58 AM alma.acs.container.AcsContainer activate_component
INFO: <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
May 26, 2004 7:11:58 AM alma.acs.container.AcsContainer activate_component
INFO: activate_component: handle=16777230 name=ArrayController3 helperClass=alma.Control.arrayInterfaces.ArrayControllerHelper type=IDL:alma/Control/ArrayController:1.0
May 26, 2004 7:11:58 AM alma.acs.container.AcsContainer createComponentHelper
FINER: creating component helper instance of type alma.Control.arrayInterfaces.ArrayControllerHelper
May 26, 2004 7:11:58 AM alma.acs.container.ComponentHelper getComponentImpl
FINER: component implementation class 'alma.Control.arrayInterfaces.ArrayControllerImpl' instantiated.
May 26, 2004 7:11:58 AM alma.acs.container.AcsContainer activate_component
FINER: component ArrayController3 implements operations interface directly; no dynamic translator proxy used.
[ POA ComponentPOAArrayController3 - ready ]
May 26, 2004 7:11:58 AM alma.acs.container.ComponentAdapter activateComponent
FINER: entering ComponentAdapter#activateComponent for ArrayController3
May 26, 2004 7:11:58 AM alma.acs.container.corba.AcsCorba activateComponent
FINER: entering activateComponent: name=ArrayController3
May 26, 2004 7:11:58 AM alma.acs.container.corba.AcsCorba activateComponent
FINER: component 'ArrayController3' activated as CORBA object.
May 26, 2004 7:11:58 AM alma.acs.container.ComponentAdapter _getInterfaces
FINE: interfaces of component 'ArrayController3': IDL:alma/Control/ArrayController:1.0IDL:alma/ACS/ACSComponent:1.0IDL:omg.org/CORBA/Object:1.0IDL:alma/Control/ArrayMonitor:1.0
May 26, 2004 7:11:58 AM alma.acs.container.AcsContainer activate_component
FINE: about to initialize component ArrayController3
May 26, 2004 7:11:58 AM alma.acs.container.ComponentStateManagerImpl setState
FINER: switching state of component ArrayController3 from NEW to INITIALIZING
May 26, 2004 7:11:58 AM alma.acs.logging.ClientLogManager getLoggerForComponent
FINE: a logger for component .ArrayController3 is available.
May 26, 2004 7:11:58 AM alma.Control.arrayInterfaces.ArrayMonitorImpl initialize
INFO: CONTROL: ArrayMonitorImpl.initialize() called...
May 26, 2004 7:11:58 AM alma.acs.container.ContainerServicesImpl getComponent
FINE: will retrieve remote component 'ARCHIVE_CONNECTION' using ACS Manager#get_component
May 26, 2004 7:11:58 AM alma.acs.container.ContainerServicesImpl getComponent
FINE: component ARCHIVE_CONNECTION retrieved successfully.
May 26, 2004 7:11:58 AM alma.acs.container.ContainerSealant invoke
INFO: intercepted a call to 'ARCHIVE_CONNECTION#getOperational'...
May 26, 2004 7:11:58 AM alma.archive.components.OperationalImpl connect
INFO: Connected to the internal interface
May 26, 2004 7:11:58 AM alma.archive.components.OperationalImpl connect
INFO: Connected to the Liatener Manager
May 26, 2004 7:11:58 AM alma.acs.container.corba.AcsCorba activateOffShoot
FINER: offshoot of type 'alma.archive.components.OperationalImpl' activated as a CORBA object.
May 26, 2004 7:11:58 AM alma.acs.container.ContainerSealant invoke
INFO: returning from ARCHIVE_CONNECTION#getOperational after 4 ms.
May 26, 2004 7:11:58 AM alma.acs.logging.ClientLogManager getLoggerForComponent
FINE: a logger for component .ArrayController3 is available.
May 26, 2004 7:11:58 AM alma.acs.logging.ClientLogManager getLoggerForComponent
FINE: a logger for component .ArrayController3 is available.
May 26, 2004 7:11:58 AM alma.Control.arrayInterfaces.ArrayControllerImpl initialize
INFO: CONTROL: ArrayControllerImpl.initialize() called...
Suppler.subscription_change(...) the 'CONTROLSYSTEM' channel: override to do something useful.
Suppler.subscription_change(...) the 'CONTROLSYSTEM' channel: override to do something useful.
Suppler.subscription_change(...) the 'CONTROLSYSTEM' channel: override to do something useful.
May 26, 2004 7:11:58 AM alma.acs.container.ComponentStateManagerImpl setState
FINER: switching state of component ArrayController3 from INITIALIZING to INITIALIZED
May 26, 2004 7:11:58 AM alma.Control.arrayInterfaces.ArrayMonitorImpl execute
INFO: eArrayMonitorImpl.xecute() called...
May 26, 2004 7:11:58 AM alma.acs.container.ComponentStateManagerImpl setState
FINER: switching state of component ArrayController3 from INITIALIZED to OPERATIONAL
May 26, 2004 7:11:58 AM alma.acs.container.AcsContainer activate_component
INFO: component ArrayController3 activated and initialized in 35 ms.
May 26, 2004 7:11:58 AM alma.acs.container.AcsContainer activate_component
INFO: >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
May 26, 2004 7:11:58 AM alma.acs.container.ContainerSealant invoke
INFO: returning from ControlSystem1#createSubArray after 472 ms.
May 26, 2004 7:11:58 AM alma.scheduling.master_scheduler.ALMADispatcher sendToControl
INFO: SCHEDULING: Got array controller
May 26, 2004 7:11:58 AM alma.acs.container.ContainerSealant invoke
INFO: intercepted a call to 'ArrayController3#observeNow'...
May 26, 2004 7:11:58 AM alma.Control.arrayInterfaces.ArrayControllerImpl observe
INFO: observe() called...
May 26, 2004 7:11:58 AM alma.archive.components.OperationalImpl retrieve
FINEST: Getting URI: uid://X0000000000000065/X00000004
May 26, 2004 7:11:58 AM alma.archive.components.OperationalImpl retrieve
FINEST: Fetching Xml: uid://X0000000000000065/X00000004
May 26, 2004 7:11:58 AM alma.archive.components.OperationalImpl retrieve
FINEST: Fetching Status: uid://X0000000000000065/X00000004
May 26, 2004 7:11:58 AM alma.archive.components.OperationalImpl retrieve
FINEST: Building Result: uid://X0000000000000065/X00000004
May 26, 2004 7:11:58 AM alma.archive.components.OperationalImpl retrieve
FINEST: Schema: uid://X0000000000000064/X0000000f
May 26, 2004 7:11:58 AM alma.archive.components.OperationalImpl retrieve
FINEST: Type name: SchedBlock
May 26, 2004 7:11:58 AM alma.archive.components.OperationalImpl retrieve
FINEST: Version: 0
May 26, 2004 7:11:58 AM alma.archive.components.OperationalImpl retrieve
FINEST: Time Stamp: 2004-05-26T07:10:23.026
May 26, 2004 7:11:58 AM alma.archive.components.OperationalImpl store
FINEST: Storing URI: uid://X0000000000000066/X00000010 Type: ExecBlock
May 26, 2004 7:11:58 AM alma.archive.components.OperationalImpl store
FINEST: Schema Location for Type ExecBlock is uid://X0000000000000064/X00000010
May 26, 2004 7:11:58 AM alma.archive.components.OperationalImpl store
FINEST: Stored: uid://X0000000000000066/X00000010 successfully
May 26, 2004 7:12:00 AM alma.Control.arrayInterfaces.ArrayControllerImpl observe
INFO: CONTROL: send ExecBlockEvent
SCHEDULING: Control event received in scheduler receiver!
SCHEDULING: Got event from Control (scheduler receiver)
May 26, 2004 7:12:00 AM alma.scheduling.receivers.ControlEventReceiver push_structured_event
INFO: SCHEDULING: Got event from control
SCHEDULING: process sched event started
SCHEDULING: in scheduler, id=uid://X0000000000000065/X00000004
SCHEDULING: Sb ids match!
SCHEDULING: id is in queue.. do somethingMay 26, 2004 7:12:00 AM alma.scheduling.receivers.ControlEventReceiver push_structured_event
INFO: SCHEDULING: Event reason = started
May 26, 2004 7:12:00 AM alma.scheduling.receivers.ControlEventReceiver push_structured_event
INFO: SCHEDULING: Received sb start event from control.
May 26, 2004 7:12:02 AM alma.Control.arrayInterfaces.ArrayControllerImpl observe
INFO: CONTROL: send ObsEvent
uid://X0000000000000066/X00000005 uid://X0000000000000067/X00000000 completed
uid://X0000000000000066/X0000000f uid://X0000000000000069/X00000000 running
May 26, 2004 7:12:07 AM alma.acs.container.ContainerSealant invoke
INFO: intercepted a call to 'GETTELCALRESULTS1#publishPointingResult'...
May 26, 2004 7:12:07 AM alma.TelCalPublisher.GetTelCalResultsImpl.GetTelCalResultsImpl publishPointingResult
INFO: publishPointingResult...
PointingResultConverter...
May 26, 2004 7:12:07 AM alma.acs.container.ContainerSealant invoke
INFO: intercepted a call to 'GETTELCALRESULTS1#publishPointingResult'...
May 26, 2004 7:12:07 AM alma.TelCalPublisher.GetTelCalResultsImpl.GetTelCalResultsImpl storeResultInList
INFO: list size=7
May 26, 2004 7:12:07 AM alma.TelCalPublisher.GetTelCalResultsImpl.GetTelCalResultsImpl publishPointingResult
INFO: publishPointingResult...
PointingResultConverter...
May 26, 2004 7:12:07 AM alma.TelCalPublisher.GetTelCalResultsImpl.GetTelCalResultsImpl sendEvent
INFO: sendEvent
pointing event
May 26, 2004 7:12:07 AM alma.TelCalPublisher.GetTelCalResultsImpl.GetTelCalResultsImpl storeResultInList
INFO: list size=8
May 26, 2004 7:12:07 AM alma.TelCalPublisher.GetTelCalResultsImpl.GetTelCalResultsImpl sendEvent
INFO: sendEvent
pointing event
SCHEDULING: Got PointingReduced event
SCHEDULING: Starting to process the PointingReduced event
pointing event: end
pointing event: end
May 26, 2004 7:12:07 AM alma.archive.components.OperationalImpl store
FINEST: Storing URI: uid://X0000000000000066/X00000012 Type: PointingResult
May 26, 2004 7:12:08 AM alma.archive.components.OperationalImpl store
FINEST: Storing URI: uid://X0000000000000066/X00000011 Type: PointingResult
May 26, 2004 7:12:08 AM alma.archive.components.OperationalImpl store
FINEST: Schema Location for Type PointingResult is uid://X0000000000000064/X00000014
May 26, 2004 7:12:08 AM alma.archive.components.OperationalImpl store
FINEST: Schema Location for Type PointingResult is uid://X0000000000000064/X00000014
SCHEDULING: Got PointingReduced event
SCHEDULING: Starting to process the PointingReduced event
May 26, 2004 7:12:08 AM alma.archive.components.OperationalImpl store
FINEST: Stored: uid://X0000000000000066/X00000011 successfully
xmlEntity= alma.xmlentity.XmlEntityStruct@2f1e75
May 26, 2004 7:12:08 AM alma.acs.container.ContainerSealant invoke
INFO: returning from GETTELCALRESULTS1#publishPointingResult after 194 ms.
May 26, 2004 7:12:08 AM alma.archive.components.OperationalImpl store
FINEST: Stored: uid://X0000000000000066/X00000012 successfully
xmlEntity= alma.xmlentity.XmlEntityStruct@178b64b
May 26, 2004 7:12:08 AM alma.acs.container.ContainerSealant invoke
INFO: returning from GETTELCALRESULTS1#publishPointingResult after 198 ms.
May 26, 2004 7:12:08 AM alma.acs.container.ContainerSealant invoke
INFO: returning from ArrayController3#observeNow after 10082 ms.
May 26, 2004 7:12:08 AM alma.scheduling.scheduler.Scheduler run
INFO: SCHEDULING: waiting til sb is done processing
May 26, 2004 7:12:08 AM alma.scheduling.receivers.ControlEventReceiver push_structured_event
INFO: SCHEDULING: Got event from control
SCHEDULING: Control event received in scheduler receiver!
SCHEDULING: Got event from Control (scheduler receiver)May 26, 2004 7:12:08 AM alma.scheduling.receivers.ControlEventReceiver push_structured_event
INFO: SCHEDULING: Event reason = end
SCHEDULING: process sched event started
SCHEDULING: in scheduler, id=uid://X0000000000000065/X00000004
SCHEDULING: Sb ids match!
SCHEDULING: id is in queue.. do something
May 26, 2004 7:12:08 AM alma.scheduling.receivers.ControlEventReceiver push_structured_event
INFO: SCHEDULING: Received sb end event from control.
May 26, 2004 7:12:08 AM alma.scheduling.scheduler.Scheduler run
INFO: SCHEDULING: scheduler woken up!
May 26, 2004 7:12:08 AM alma.scheduling.receivers.ControlEventReceiver receive
INFO: SCHEDULING: Starting to process the control event
May 26, 2004 7:12:08 AM alma.scheduling.receivers.ControlEventReceiver receive
INFO: SCHEDULING: Event reason = end
May 26, 2004 7:12:08 AM alma.scheduling.master_scheduler.ALMATelescopeOperator sortSBs
INFO: SCHEDULING: sorting SBs!
May 26, 2004 7:12:08 AM alma.scheduling.receivers.ControlEventReceiver receive
INFO: SCHEDULING: Received sb end event from control.
May 26, 2004 7:12:08 AM alma.archive.components.OperationalImpl query
FINE: Querying XPath: /sbl:SchedBlock Schema: SchedBlock
SCHEDULING: process control event started
May 26, 2004 7:12:08 AM alma.archive.components.OperationalImpl query
FINEST: Schema location for SchedBlock is uid://X0000000000000064/X0000000f
May 26, 2004 7:12:08 AM alma.scheduling.master_scheduler.ALMAArchive updateSchedBlock
INFO: SCHEDULING: sb id=uid://X0000000000000065/X00000004
May 26, 2004 7:12:08 AM alma.scheduling.master_scheduler.ALMAArchive updateSchedBlock
INFO: SCHEDULING: ** This is where the sb will be linked to its execblock **
May 26, 2004 7:12:08 AM alma.archive.components.OperationalImpl retrieve
FINEST: Getting URI: uid://X0000000000000065/X00000004
May 26, 2004 7:12:08 AM alma.archive.components.OperationalImpl retrieve
FINEST: Fetching Xml: uid://X0000000000000065/X00000004
May 26, 2004 7:12:09 AM alma.archive.components.OperationalImpl retrieve
FINEST: Fetching Status: uid://X0000000000000065/X00000004
May 26, 2004 7:12:09 AM alma.archive.components.OperationalImpl query
FINE: Returning cursor to user
May 26, 2004 7:12:09 AM alma.acs.container.corba.AcsCorba activateOffShoot
FINER: offshoot of type 'alma.archive.components.CursorImpl' activated as a CORBA object.
May 26, 2004 7:12:09 AM alma.archive.components.OperationalImpl retrieve
FINEST: Building Result: uid://X0000000000000065/X00000004
May 26, 2004 7:12:09 AM alma.archive.components.OperationalImpl retrieve
FINEST: Schema: uid://X0000000000000064/X0000000f
May 26, 2004 7:12:09 AM alma.archive.components.OperationalImpl retrieve
FINEST: Type name: SchedBlock
May 26, 2004 7:12:09 AM alma.archive.components.OperationalImpl retrieve
FINEST: Version: 0
May 26, 2004 7:12:09 AM alma.archive.components.OperationalImpl retrieve
FINEST: Time Stamp: 2004-05-26T07:10:23.026
May 26, 2004 7:12:09 AM alma.archive.components.OperationalImpl retrieve
FINEST: Getting URI: uid://X0000000000000065/X00000004
May 26, 2004 7:12:09 AM alma.archive.components.OperationalImpl retrieve
FINEST: Fetching Xml: uid://X0000000000000065/X00000004
May 26, 2004 7:12:09 AM alma.archive.components.OperationalImpl retrieve
FINEST: Fetching Status: uid://X0000000000000065/X00000004
May 26, 2004 7:12:09 AM alma.archive.components.OperationalImpl retrieve
FINEST: Building Result: uid://X0000000000000065/X00000004
May 26, 2004 7:12:09 AM alma.archive.components.OperationalImpl retrieve
FINEST: Schema: uid://X0000000000000064/X0000000f
May 26, 2004 7:12:09 AM alma.archive.components.OperationalImpl retrieve
FINEST: Type name: SchedBlock
May 26, 2004 7:12:09 AM alma.scheduling.master_scheduler.ALMATelescopeOperator isCompletedSb
INFO: SCHEDULING: checking for non-complete SB
May 26, 2004 7:12:09 AM alma.archive.components.OperationalImpl retrieve
FINEST: Version: 0
May 26, 2004 7:12:09 AM alma.archive.components.OperationalImpl retrieve
FINEST: Time Stamp: 2004-05-26T07:10:23.026
May 26, 2004 7:12:09 AM alma.archive.components.OperationalImpl update
FINEST: Updating: uid://X0000000000000065/X00000004
May 26, 2004 7:12:09 AM alma.archive.components.OperationalImpl query
FINE: Querying XPath: /sbl:SchedBlock Schema: SchedBlock
May 26, 2004 7:12:09 AM alma.archive.components.OperationalImpl query
FINEST: Schema location for SchedBlock is uid://X0000000000000064/X0000000f
May 26, 2004 7:12:10 AM alma.archive.components.OperationalImpl query
FINE: Returning cursor to user
May 26, 2004 7:12:10 AM alma.acs.container.corba.AcsCorba activateOffShoot
FINER: offshoot of type 'alma.archive.components.CursorImpl' activated as a CORBA object.
May 26, 2004 7:12:10 AM alma.archive.components.OperationalImpl store
FINEST: Storing URI: uid://X0000000000000066/X00000014 Type: PipelineProcessingRequest
May 26, 2004 7:12:10 AM alma.archive.components.OperationalImpl store
FINEST: Schema Location for Type PipelineProcessingRequest is uid://X0000000000000064/X00000015
May 26, 2004 7:12:10 AM alma.archive.components.OperationalImpl store
FINEST: Stored: uid://X0000000000000066/X00000014 successfully
May 26, 2004 7:12:10 AM alma.scheduling.master_scheduler.ALMAArchive getPipelineProcessingRequest
INFO: ALMAArchive: getting ppr
May 26, 2004 7:12:10 AM alma.archive.components.OperationalImpl retrieve
FINEST: Getting URI: uid://X0000000000000066/X00000014
May 26, 2004 7:12:10 AM alma.archive.components.OperationalImpl retrieve
FINEST: Fetching Xml: uid://X0000000000000066/X00000014
May 26, 2004 7:12:10 AM alma.scheduling.master_scheduler.ALMATelescopeOperator isCompletedSb
INFO: SCHEDULING: checking for non-complete SB
May 26, 2004 7:12:10 AM alma.archive.components.OperationalImpl retrieve
FINEST: Fetching Status: uid://X0000000000000066/X00000014
May 26, 2004 7:12:10 AM alma.archive.components.OperationalImpl query
FINE: Querying XPath: /sbl:SchedBlock Schema: SchedBlock
May 26, 2004 7:12:10 AM alma.archive.components.OperationalImpl retrieve
FINEST: Building Result: uid://X0000000000000066/X00000014
May 26, 2004 7:12:10 AM alma.archive.components.OperationalImpl retrieve
FINEST: Schema: uid://X0000000000000064/X00000015
May 26, 2004 7:12:10 AM alma.archive.components.OperationalImpl query
FINEST: Schema location for SchedBlock is uid://X0000000000000064/X0000000f
May 26, 2004 7:12:10 AM alma.archive.components.OperationalImpl retrieve
FINEST: Type name: PipelineProcessingRequest
May 26, 2004 7:12:10 AM alma.archive.components.OperationalImpl retrieve
FINEST: Version: 0
May 26, 2004 7:12:10 AM alma.archive.components.OperationalImpl retrieve
FINEST: Time Stamp: 2004-05-26T07:12:10.305
May 26, 2004 7:12:10 AM alma.acs.container.ContainerServicesImpl getComponent
INFO: client 'MASTER_SCHEDULER' attempts to retrieve component 'SCIENCE_PIPELINE' more than once; will return existing reference.
May 26, 2004 7:12:10 AM alma.acs.container.ContainerSealant invoke
INFO: intercepted a call to 'SCIENCE_PIPELINE#processRequest'...
May 26, 2004 7:12:10 AM alma.pipelinescience.components.SciencePipelineImpl processRequest
INFO: SCIENCE_PIPELINE: processRequest() method initiated
May 26, 2004 7:12:10 AM alma.acs.container.ContainerSealant invoke
INFO: intercepted a call to 'IDENTIFIER_ARCHIVE#getIdNamespace'...
May 26, 2004 7:12:10 AM alma.archive.components.OperationalImpl query
FINE: Returning cursor to user
May 26, 2004 7:12:10 AM alma.acs.container.corba.AcsCorba activateOffShoot
FINER: offshoot of type 'alma.archive.components.CursorImpl' activated as a CORBA object.
May 26, 2004 7:12:10 AM alma.acs.container.ContainerSealant invoke
INFO: returning from IDENTIFIER_ARCHIVE#getIdNamespace after 624 ms.
May 26, 2004 7:12:10 AM alma.pipelinescience.components.SciencePipelineImpl processRequest
INFO: SCIENCE_PIPELINE: identifier archive accessed
May 26, 2004 7:12:10 AM alma.pipelinescience.components.SciencePipelineImpl processRequest
INFO: SCIENCE_PIPELINE: listobject created
May 26, 2004 7:12:10 AM alma.acs.container.ContainerSealant invoke
INFO: returning from SCIENCE_PIPELINE#processRequest after 627 ms.
May 26, 2004 7:12:10 AM alma.scheduling.project_manager.ALMAPipeline processRequest
INFO: SCHEDULING: uid://X000000000000006a/X00000000
SCHEDULING: uid://X000000000000006a/X00000000
uid://X0000000000000066/X00000014 uid://X000000000000006a/X00000000 queued
uid://X0000000000000066/X00000014 uid://X000000000000006a/X00000000 queued
May 26, 2004 7:12:11 AM alma.scheduling.master_scheduler.ALMATelescopeOperator isCompletedSb
INFO: SCHEDULING: checking for non-complete SB
May 26, 2004 7:12:11 AM alma.archive.components.OperationalImpl query
FINE: Querying XPath: /sbl:SchedBlock Schema: SchedBlock
May 26, 2004 7:12:11 AM alma.archive.components.OperationalImpl query
FINEST: Schema location for SchedBlock is uid://X0000000000000064/X0000000f
May 26, 2004 7:12:11 AM alma.archive.components.OperationalImpl query
FINE: Returning cursor to user
May 26, 2004 7:12:11 AM alma.acs.container.corba.AcsCorba activateOffShoot
FINER: offshoot of type 'alma.archive.components.CursorImpl' activated as a CORBA object.
May 26, 2004 7:12:11 AM alma.scheduling.master_scheduler.ALMATelescopeOperator isCompletedSb
INFO: SCHEDULING: checking for non-complete SB
May 26, 2004 7:12:11 AM alma.scheduling.master_scheduler.ALMATelescopeOperator selectSB
INFO: SCHEDULING: in TO. reply =uid://X0000000000000065/X00000005
May 26, 2004 7:12:11 AM alma.acs.container.ContainerServicesImpl getComponent
INFO: client 'MASTER_SCHEDULER' attempts to retrieve component 'MASTER_SCHEDULER' more than once; will return existing reference.
May 26, 2004 7:12:11 AM alma.scheduling.master_scheduler.ALMATelescopeOperator selectSB
INFO: SCHEDULING: in TO. ms response about to be called
May 26, 2004 7:12:11 AM alma.acs.container.ContainerSealant invoke
INFO: intercepted a call to 'MASTER_SCHEDULER#response'...
May 26, 2004 7:12:11 AM alma.scheduling.master_scheduler.MasterScheduler response
INFO: SCHEDULING: in MS. MessageID = uid://X0000000000000066/X00000013
May 26, 2004 7:12:11 AM alma.scheduling.master_scheduler.MasterScheduler response
INFO: SCHEDULING: in MS. Reply (sb id) = uid://X0000000000000065/X00000005
May 26, 2004 7:12:11 AM alma.scheduling.master_scheduler.MasterScheduler response
INFO: SCHEDULING: in MS. messageQueue size = 1
May 26, 2004 7:12:11 AM alma.scheduling.master_scheduler.MasterScheduler response
INFO: SCHEDULING: in MS. Got message with id=uid://X0000000000000066/X00000013
May 26, 2004 7:12:11 AM alma.scheduling.master_scheduler.MasterScheduler response
INFO: SCHEDULING: in MS. message = uid://X0000000000000066/X00000013 gotten and reply = uid://X0000000000000065/X00000005 sent.
May 26, 2004 7:12:11 AM alma.acs.container.ContainerSealant invoke
INFO: returning from MASTER_SCHEDULER#response after 5 ms.
May 26, 2004 7:12:11 AM alma.scheduling.master_scheduler.ALMATelescopeOperator selectSB
INFO: SCHEDULING: in TO. ms response called
May 26, 2004 7:12:11 AM alma.scheduling.master_scheduler.ALMATelescopeOperator selectSB
INFO: SCHEDULING: in TO. timer.join()
May 26, 2004 7:12:11 AM alma.scheduling.scheduler.Scheduler run
INFO: SCHEDULING: in scheduler. selectedSB = uid://X0000000000000065/X00000005
May 26, 2004 7:12:11 AM alma.scheduling.scheduler.Scheduler run
INFO: SCHEDULING: Message uid://X0000000000000066/X00000013 removed from queue.
May 26, 2004 7:12:11 AM alma.scheduling.master_scheduler.ALMADispatcher sendToControl
INFO: SCHEDULING: Sending SB with id = uid://X0000000000000065/X00000005 to controller.
May 26, 2004 7:12:11 AM alma.acs.container.ContainerServicesImpl getComponent
INFO: client 'MASTER_SCHEDULER' attempts to retrieve component 'ControlSystem1' more than once; will return existing reference.
May 26, 2004 7:12:11 AM alma.scheduling.master_scheduler.ALMADispatcher sendToControl
INFO: SCHEDULING: Got control system
May 26, 2004 7:12:11 AM alma.acs.container.ContainerSealant invoke
INFO: intercepted a call to 'ControlSystem1#createSubArray'...
May 26, 2004 7:12:11 AM alma.Control.masterController.ControlSystemImpl createSubArray
INFO: createSubArray() called
May 26, 2004 7:12:11 AM alma.acs.container.ContainerServicesImpl getDynamicComponent
FINE: getDynamicComponent called with compName=ArrayController4 compType=IDL:alma/Control/ArrayController:1.0 compCode=* compContainer=* markAsDefault=false
May 26, 2004 7:12:12 AM alma.acs.container.AcsContainer activate_component
INFO: <<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<<
May 26, 2004 7:12:12 AM alma.acs.container.AcsContainer activate_component
INFO: activate_component: handle=16777231 name=ArrayController4 helperClass=alma.Control.arrayInterfaces.ArrayControllerHelper type=IDL:alma/Control/ArrayController:1.0
May 26, 2004 7:12:12 AM alma.acs.container.AcsContainer createComponentHelper
FINER: creating component helper instance of type alma.Control.arrayInterfaces.ArrayControllerHelper
May 26, 2004 7:12:12 AM alma.acs.container.ComponentHelper getComponentImpl
FINER: component implementation class 'alma.Control.arrayInterfaces.ArrayControllerImpl' instantiated.
May 26, 2004 7:12:12 AM alma.acs.container.AcsContainer activate_component
FINER: component ArrayController4 implements operations interface directly; no dynamic translator proxy used.
[ POA ComponentPOAArrayController4 - ready ]
May 26, 2004 7:12:12 AM alma.acs.container.ComponentAdapter activateComponent
FINER: entering ComponentAdapter#activateComponent for ArrayController4
May 26, 2004 7:12:12 AM alma.acs.container.corba.AcsCorba activateComponent
FINER: entering activateComponent: name=ArrayController4
May 26, 2004 7:12:12 AM alma.acs.container.corba.AcsCorba activateComponent
FINER: component 'ArrayController4' activated as CORBA object.
May 26, 2004 7:12:12 AM alma.acs.container.ComponentAdapter _getInterfaces
FINE: interfaces of component 'ArrayController4': IDL:alma/Control/ArrayController:1.0IDL:alma/ACS/ACSComponent:1.0IDL:omg.org/CORBA/Object:1.0IDL:alma/Control/ArrayMonitor:1.0
May 26, 2004 7:12:12 AM alma.acs.container.AcsContainer activate_component
FINE: about to initialize component ArrayController4
May 26, 2004 7:12:12 AM alma.acs.container.ComponentStateManagerImpl setState
FINER: switching state of component ArrayController4 from NEW to INITIALIZING
May 26, 2004 7:12:12 AM alma.acs.logging.ClientLogManager getLoggerForComponent
FINE: a logger for component .ArrayController4 is available.
May 26, 2004 7:12:12 AM alma.Control.arrayInterfaces.ArrayMonitorImpl initialize
INFO: CONTROL: ArrayMonitorImpl.initialize() called...
May 26, 2004 7:12:12 AM alma.acs.container.ContainerServicesImpl getComponent
FINE: will retrieve remote component 'ARCHIVE_CONNECTION' using ACS Manager#get_component
May 26, 2004 7:12:12 AM alma.acs.container.ContainerServicesImpl getComponent
FINE: component ARCHIVE_CONNECTION retrieved successfully.
May 26, 2004 7:12:12 AM alma.acs.container.ContainerSealant invoke
INFO: intercepted a call to 'ARCHIVE_CONNECTION#getOperational'...
May 26, 2004 7:12:12 AM alma.archive.components.OperationalImpl connect
INFO: Connected to the internal interface
May 26, 2004 7:12:12 AM alma.archive.components.OperationalImpl connect
INFO: Connected to the Liatener Manager
May 26, 2004 7:12:12 AM alma.acs.container.corba.AcsCorba activateOffShoot
FINER: offshoot of type 'alma.archive.components.OperationalImpl' activated as a CORBA object.
May 26, 2004 7:12:12 AM alma.acs.container.ContainerSealant invoke
INFO: returning from ARCHIVE_CONNECTION#getOperational after 3 ms.
May 26, 2004 7:12:12 AM alma.acs.logging.ClientLogManager getLoggerForComponent
FINE: a logger for component .ArrayController4 is available.
May 26, 2004 7:12:12 AM alma.acs.logging.ClientLogManager getLoggerForComponent
FINE: a logger for component .ArrayController4 is available.
May 26, 2004 7:12:12 AM alma.Control.arrayInterfaces.ArrayControllerImpl initialize
INFO: CONTROL: ArrayControllerImpl.initialize() called...
Suppler.subscription_change(...) the 'CONTROLSYSTEM' channel: override to do something useful.
Suppler.subscription_change(...) the 'CONTROLSYSTEM' channel: override to do something useful.
Suppler.subscription_change(...) the 'CONTROLSYSTEM' channel: override to do something useful.
May 26, 2004 7:12:12 AM alma.acs.container.ComponentStateManagerImpl setState
FINER: switching state of component ArrayController4 from INITIALIZING to INITIALIZED
May 26, 2004 7:12:12 AM alma.Control.arrayInterfaces.ArrayMonitorImpl execute
INFO: eArrayMonitorImpl.xecute() called...
May 26, 2004 7:12:12 AM alma.acs.container.ComponentStateManagerImpl setState
FINER: switching state of component ArrayController4 from INITIALIZED to OPERATIONAL
May 26, 2004 7:12:12 AM alma.acs.container.AcsContainer activate_component
INFO: component ArrayController4 activated and initialized in 81 ms.
May 26, 2004 7:12:12 AM alma.acs.container.AcsContainer activate_component
INFO: >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
May 26, 2004 7:12:12 AM alma.acs.container.ContainerSealant invoke
INFO: returning from ControlSystem1#createSubArray after 555 ms.
May 26, 2004 7:12:12 AM alma.scheduling.master_scheduler.ALMADispatcher sendToControl
INFO: SCHEDULING: Got array controller
May 26, 2004 7:12:12 AM alma.acs.container.ContainerSealant invoke
INFO: intercepted a call to 'ArrayController4#observeNow'...
May 26, 2004 7:12:12 AM alma.Control.arrayInterfaces.ArrayControllerImpl observe
INFO: observe() called...
May 26, 2004 7:12:12 AM alma.archive.components.OperationalImpl retrieve
FINEST: Getting URI: uid://X0000000000000065/X00000005
May 26, 2004 7:12:12 AM alma.archive.components.OperationalImpl retrieve
FINEST: Fetching Xml: uid://X0000000000000065/X00000005
May 26, 2004 7:12:12 AM alma.archive.components.OperationalImpl retrieve
FINEST: Fetching Status: uid://X0000000000000065/X00000005
May 26, 2004 7:12:12 AM alma.archive.components.OperationalImpl retrieve
FINEST: Building Result: uid://X0000000000000065/X00000005
May 26, 2004 7:12:12 AM alma.archive.components.OperationalImpl retrieve
FINEST: Schema: uid://X0000000000000064/X0000000f
May 26, 2004 7:12:12 AM alma.archive.components.OperationalImpl retrieve
FINEST: Type name: SchedBlock
May 26, 2004 7:12:12 AM alma.archive.components.OperationalImpl retrieve
FINEST: Version: 0
May 26, 2004 7:12:12 AM alma.archive.components.OperationalImpl retrieve
FINEST: Time Stamp: 2004-05-26T07:10:23.073
May 26, 2004 7:12:12 AM alma.archive.components.OperationalImpl store
FINEST: Storing URI: uid://X0000000000000066/X00000015 Type: ExecBlock
May 26, 2004 7:12:12 AM alma.archive.components.OperationalImpl store
FINEST: Schema Location for Type ExecBlock is uid://X0000000000000064/X00000010
May 26, 2004 7:12:12 AM alma.archive.components.OperationalImpl store
FINEST: Stored: uid://X0000000000000066/X00000015 successfully
May 26, 2004 7:12:13 AM alma.archive.components.OperationalImpl update
FINEST: Updating: uid://X0000000000000066/X00000005
May 26, 2004 7:12:13 AM alma.pipelinescience.components.SciencePipelineImpl$RunProcess run
INFO: SCIENCE_PIPELINE: completion event issued
May 26, 2004 7:12:13 AM alma.scheduling.receivers.PipelineEventReceiver receive
INFO: SCHEDULING: PipelineEnd event received!
May 26, 2004 7:12:13 AM alma.scheduling.receivers.PipelineEventReceiver push_structured_event
INFO: SCHEDULING: Got event from Pipeline
May 26, 2004 7:12:14 AM alma.Control.arrayInterfaces.ArrayControllerImpl observe
INFO: CONTROL: send ExecBlockEvent
SCHEDULING: Control event received in scheduler receiver!
May 26, 2004 7:12:14 AM alma.scheduling.receivers.ControlEventReceiver push_structured_event
INFO: SCHEDULING: Got event from control
May 26, 2004 7:12:14 AM alma.scheduling.receivers.ControlEventReceiver push_structured_event
INFO: SCHEDULING: Event reason = started
May 26, 2004 7:12:14 AM alma.scheduling.receivers.ControlEventReceiver push_structured_event
INFO: SCHEDULING: Received sb start event from control.
SCHEDULING: Got event from Control (scheduler receiver)
SCHEDULING: process sched event started
SCHEDULING: in scheduler, id=uid://X0000000000000065/X00000005
SCHEDULING: Sb ids match!
SCHEDULING: id is in queue.. do something
uid://X0000000000000066/X0000000a uid://X0000000000000068/X00000000 completed
May 26, 2004 7:12:16 AM alma.Control.arrayInterfaces.ArrayControllerImpl observe
INFO: CONTROL: send ObsEvent
uid://X0000000000000066/X00000014 uid://X000000000000006a/X00000000 running
May 26, 2004 7:12:21 AM alma.acs.container.ContainerSealant invoke
INFO: intercepted a call to 'GETTELCALRESULTS1#publishPointingResult'...
May 26, 2004 7:12:21 AM alma.TelCalPublisher.GetTelCalResultsImpl.GetTelCalResultsImpl publishPointingResult
INFO: publishPointingResult...
PointingResultConverter...
May 26, 2004 7:12:21 AM alma.TelCalPublisher.GetTelCalResultsImpl.GetTelCalResultsImpl storeResultInList
INFO: list size=9
May 26, 2004 7:12:21 AM alma.TelCalPublisher.GetTelCalResultsImpl.GetTelCalResultsImpl sendEvent
INFO: sendEvent
pointing event
SCHEDULING: Got PointingReduced event
SCHEDULING: Starting to process the PointingReduced event
pointing event: end
May 26, 2004 7:12:21 AM alma.archive.components.OperationalImpl store
FINEST: Storing URI: uid://X0000000000000066/X00000016 Type: PointingResult
May 26, 2004 7:12:21 AM alma.archive.components.OperationalImpl store
FINEST: Schema Location for Type PointingResult is uid://X0000000000000064/X00000014
May 26, 2004 7:12:21 AM alma.archive.components.OperationalImpl store
FINEST: Stored: uid://X0000000000000066/X00000016 successfully
xmlEntity= alma.xmlentity.XmlEntityStruct@db3331
May 26, 2004 7:12:21 AM alma.acs.container.ContainerSealant invoke
INFO: returning from GETTELCALRESULTS1#publishPointingResult after 48 ms.
May 26, 2004 7:12:21 AM alma.acs.container.ContainerSealant invoke
INFO: intercepted a call to 'GETTELCALRESULTS1#publishPointingResult'...
May 26, 2004 7:12:21 AM alma.TelCalPublisher.GetTelCalResultsImpl.GetTelCalResultsImpl publishPointingResult
INFO: publishPointingResult...
PointingResultConverter...
May 26, 2004 7:12:21 AM alma.TelCalPublisher.GetTelCalResultsImpl.GetTelCalResultsImpl storeResultInList
INFO: list size=10
May 26, 2004 7:12:21 AM alma.TelCalPublisher.GetTelCalResultsImpl.GetTelCalResultsImpl sendEvent
INFO: sendEvent
pointing event
SCHEDULING: Got PointingReduced event
SCHEDULING: Starting to process the PointingReduced event
pointing event: end
May 26, 2004 7:12:21 AM alma.archive.components.OperationalImpl store
FINEST: Storing URI: uid://X0000000000000066/X00000017 Type: PointingResult
May 26, 2004 7:12:21 AM alma.archive.components.OperationalImpl store
FINEST: Schema Location for Type PointingResult is uid://X0000000000000064/X00000014
May 26, 2004 7:12:21 AM alma.archive.components.OperationalImpl store
FINEST: Stored: uid://X0000000000000066/X00000017 successfully
xmlEntity= alma.xmlentity.XmlEntityStruct@9c8c3f
May 26, 2004 7:12:21 AM alma.acs.container.ContainerSealant invoke
INFO: returning from GETTELCALRESULTS1#publishPointingResult after 49 ms.
SCHEDULING: Control event received in scheduler receiver!
SCHEDULING: Got event from Control (scheduler receiver)
May 26, 2004 7:12:22 AM alma.scheduling.receivers.ControlEventReceiver push_structured_event
INFO: SCHEDULING: Got event from control
SCHEDULING: process sched event started
SCHEDULING: in scheduler, id=uid://X0000000000000065/X00000005
SCHEDULING: Sb ids match!
SCHEDULING: id is in queue.. do something
May 26, 2004 7:12:22 AM alma.scheduling.receivers.ControlEventReceiver push_structured_event
INFO: SCHEDULING: Event reason = end
May 26, 2004 7:12:22 AM alma.acs.container.ContainerSealant invoke
INFO: returning from ArrayController4#observeNow after 10049 ms.
May 26, 2004 7:12:22 AM alma.scheduling.receivers.ControlEventReceiver push_structured_event
INFO: SCHEDULING: Received sb end event from control.
May 26, 2004 7:12:22 AM alma.scheduling.scheduler.Scheduler run
INFO: SCHEDULING: waiting til sb is done processing
May 26, 2004 7:12:22 AM alma.scheduling.receivers.ControlEventReceiver receive
INFO: SCHEDULING: Starting to process the control event
May 26, 2004 7:12:22 AM alma.scheduling.scheduler.Scheduler run
INFO: SCHEDULING: scheduler woken up!
May 26, 2004 7:12:22 AM alma.scheduling.receivers.ControlEventReceiver receive
INFO: SCHEDULING: Event reason = end
May 26, 2004 7:12:22 AM alma.scheduling.receivers.ControlEventReceiver receive
INFO: SCHEDULING: Received sb end event from control.
SCHEDULING: process control event started
May 26, 2004 7:12:22 AM alma.scheduling.master_scheduler.ALMATelescopeOperator sortSBs
INFO: SCHEDULING: sorting SBs!
May 26, 2004 7:12:22 AM alma.scheduling.master_scheduler.ALMAArchive updateSchedBlock
INFO: SCHEDULING: sb id=uid://X0000000000000065/X00000005
May 26, 2004 7:12:22 AM alma.scheduling.master_scheduler.ALMAArchive updateSchedBlock
INFO: SCHEDULING: ** This is where the sb will be linked to its execblock **
May 26, 2004 7:12:22 AM alma.archive.components.OperationalImpl query
FINE: Querying XPath: /sbl:SchedBlock Schema: SchedBlock
May 26, 2004 7:12:22 AM alma.archive.components.OperationalImpl retrieve
FINEST: Getting URI: uid://X0000000000000065/X00000005
May 26, 2004 7:12:22 AM alma.archive.components.OperationalImpl retrieve
FINEST: Fetching Xml: uid://X0000000000000065/X00000005
May 26, 2004 7:12:22 AM alma.archive.components.OperationalImpl query
FINEST: Schema location for SchedBlock is uid://X0000000000000064/X0000000f
May 26, 2004 7:12:22 AM alma.acs.container.AcsContainer ping
FINER: ping received.
May 26, 2004 7:12:22 AM alma.archive.components.OperationalImpl retrieve
FINEST: Fetching Status: uid://X0000000000000065/X00000005
May 26, 2004 7:12:22 AM alma.archive.components.OperationalImpl query
FINE: Returning cursor to user
May 26, 2004 7:12:22 AM alma.acs.container.corba.AcsCorba activateOffShoot
FINER: offshoot of type 'alma.archive.components.CursorImpl' activated as a CORBA object.
May 26, 2004 7:12:22 AM alma.archive.components.OperationalImpl retrieve
FINEST: Building Result: uid://X0000000000000065/X00000005
May 26, 2004 7:12:22 AM alma.archive.components.OperationalImpl retrieve
FINEST: Schema: uid://X0000000000000064/X0000000f
May 26, 2004 7:12:22 AM alma.archive.components.OperationalImpl retrieve
FINEST: Type name: SchedBlock
May 26, 2004 7:12:22 AM alma.archive.components.OperationalImpl retrieve
FINEST: Version: 0
May 26, 2004 7:12:22 AM alma.archive.components.OperationalImpl retrieve
FINEST: Time Stamp: 2004-05-26T07:10:23.073
May 26, 2004 7:12:22 AM alma.archive.components.OperationalImpl retrieve
FINEST: Getting URI: uid://X0000000000000065/X00000005
May 26, 2004 7:12:22 AM alma.archive.components.OperationalImpl retrieve
FINEST: Fetching Xml: uid://X0000000000000065/X00000005
May 26, 2004 7:12:22 AM alma.scheduling.master_scheduler.ALMATelescopeOperator isCompletedSb
INFO: SCHEDULING: checking for non-complete SB
May 26, 2004 7:12:22 AM alma.archive.components.OperationalImpl retrieve
FINEST: Fetching Status: uid://X0000000000000065/X00000005
May 26, 2004 7:12:22 AM alma.archive.components.OperationalImpl query
FINE: Querying XPath: /sbl:SchedBlock Schema: SchedBlock
May 26, 2004 7:12:22 AM alma.archive.components.OperationalImpl query
FINEST: Schema location for SchedBlock is uid://X0000000000000064/X0000000f
May 26, 2004 7:12:22 AM alma.archive.components.OperationalImpl retrieve
FINEST: Building Result: uid://X0000000000000065/X00000005
May 26, 2004 7:12:22 AM alma.archive.components.OperationalImpl retrieve
FINEST: Schema: uid://X0000000000000064/X0000000f
May 26, 2004 7:12:22 AM alma.archive.components.OperationalImpl retrieve
FINEST: Type name: SchedBlock
May 26, 2004 7:12:23 AM alma.archive.components.OperationalImpl retrieve
FINEST: Version: 0
May 26, 2004 7:12:23 AM alma.archive.components.OperationalImpl retrieve
FINEST: Time Stamp: 2004-05-26T07:10:23.073
May 26, 2004 7:12:23 AM alma.archive.components.OperationalImpl update
FINEST: Updating: uid://X0000000000000065/X00000005
May 26, 2004 7:12:23 AM alma.archive.components.OperationalImpl query
FINE: Returning cursor to user
May 26, 2004 7:12:23 AM alma.acs.container.corba.AcsCorba activateOffShoot
FINER: offshoot of type 'alma.archive.components.CursorImpl' activated as a CORBA object.
May 26, 2004 7:12:23 AM alma.scheduling.master_scheduler.ALMATelescopeOperator isCompletedSb
INFO: SCHEDULING: checking for non-complete SB
May 26, 2004 7:12:23 AM alma.archive.components.OperationalImpl query
FINE: Querying XPath: /sbl:SchedBlock Schema: SchedBlock
May 26, 2004 7:12:23 AM alma.archive.components.OperationalImpl query
FINEST: Schema location for SchedBlock is uid://X0000000000000064/X0000000f
May 26, 2004 7:12:23 AM alma.archive.components.OperationalImpl store
FINEST: Storing URI: uid://X0000000000000066/X00000019 Type: PipelineProcessingRequest
May 26, 2004 7:12:23 AM alma.archive.components.OperationalImpl store
FINEST: Schema Location for Type PipelineProcessingRequest is uid://X0000000000000064/X00000015
May 26, 2004 7:12:24 AM alma.archive.components.OperationalImpl query
FINE: Returning cursor to user
May 26, 2004 7:12:24 AM alma.acs.container.corba.AcsCorba activateOffShoot
FINER: offshoot of type 'alma.archive.components.CursorImpl' activated as a CORBA object.
May 26, 2004 7:12:24 AM alma.archive.components.OperationalImpl store
FINEST: Stored: uid://X0000000000000066/X00000019 successfully
May 26, 2004 7:12:24 AM alma.scheduling.master_scheduler.ALMAArchive getPipelineProcessingRequest
INFO: ALMAArchive: getting ppr
May 26, 2004 7:12:24 AM alma.archive.components.OperationalImpl retrieve
FINEST: Getting URI: uid://X0000000000000066/X00000019
May 26, 2004 7:12:24 AM alma.archive.components.OperationalImpl retrieve
FINEST: Fetching Xml: uid://X0000000000000066/X00000019
May 26, 2004 7:12:24 AM alma.archive.components.OperationalImpl retrieve
FINEST: Fetching Status: uid://X0000000000000066/X00000019
May 26, 2004 7:12:24 AM alma.archive.components.OperationalImpl retrieve
FINEST: Building Result: uid://X0000000000000066/X00000019
May 26, 2004 7:12:24 AM alma.archive.components.OperationalImpl retrieve
FINEST: Schema: uid://X0000000000000064/X00000015
May 26, 2004 7:12:24 AM alma.archive.components.OperationalImpl retrieve
FINEST: Type name: PipelineProcessingRequest
May 26, 2004 7:12:24 AM alma.archive.components.OperationalImpl retrieve
FINEST: Version: 0
May 26, 2004 7:12:24 AM alma.archive.components.OperationalImpl retrieve
FINEST: Time Stamp: 2004-05-26T07:12:23.687
May 26, 2004 7:12:24 AM alma.acs.container.ContainerServicesImpl getComponent
INFO: client 'MASTER_SCHEDULER' attempts to retrieve component 'SCIENCE_PIPELINE' more than once; will return existing reference.
May 26, 2004 7:12:24 AM alma.acs.container.ContainerSealant invoke
INFO: intercepted a call to 'SCIENCE_PIPELINE#processRequest'...
May 26, 2004 7:12:24 AM alma.pipelinescience.components.SciencePipelineImpl processRequest
INFO: SCIENCE_PIPELINE: processRequest() method initiated
May 26, 2004 7:12:24 AM alma.acs.container.ContainerSealant invoke
INFO: intercepted a call to 'IDENTIFIER_ARCHIVE#getIdNamespace'...
May 26, 2004 7:12:24 AM alma.acs.container.ContainerSealant invoke
INFO: returning from IDENTIFIER_ARCHIVE#getIdNamespace after 4 ms.
May 26, 2004 7:12:24 AM alma.pipelinescience.components.SciencePipelineImpl processRequest
INFO: SCIENCE_PIPELINE: identifier archive accessed
May 26, 2004 7:12:24 AM alma.pipelinescience.components.SciencePipelineImpl processRequest
INFO: SCIENCE_PIPELINE: listobject created
May 26, 2004 7:12:24 AM alma.acs.container.ContainerSealant invoke
INFO: returning from SCIENCE_PIPELINE#processRequest after 9 ms.
May 26, 2004 7:12:24 AM alma.scheduling.project_manager.ALMAPipeline processRequest
INFO: SCHEDULING: uid://X000000000000006b/X00000000
SCHEDULING: uid://X000000000000006b/X00000000
uid://X0000000000000066/X00000019 uid://X000000000000006b/X00000000 queued
uid://X0000000000000066/X00000019 uid://X000000000000006b/X00000000 queued
May 26, 2004 7:12:24 AM alma.scheduling.master_scheduler.ALMATelescopeOperator isCompletedSb
INFO: SCHEDULING: checking for non-complete SB
May 26, 2004 7:12:24 AM alma.archive.components.OperationalImpl query
FINE: Querying XPath: /sbl:SchedBlock Schema: SchedBlock
May 26, 2004 7:12:24 AM alma.archive.components.OperationalImpl query
FINEST: Schema location for SchedBlock is uid://X0000000000000064/X0000000f
May 26, 2004 7:12:25 AM alma.archive.components.OperationalImpl query
FINE: Returning cursor to user
May 26, 2004 7:12:25 AM alma.acs.container.corba.AcsCorba activateOffShoot
FINER: offshoot of type 'alma.archive.components.CursorImpl' activated as a CORBA object.
May 26, 2004 7:12:25 AM alma.scheduling.master_scheduler.ALMATelescopeOperator isCompletedSb
INFO: SCHEDULING: checking for non-complete SB
May 26, 2004 7:12:25 AM alma.archive.components.OperationalImpl query
FINE: Querying XPath: /sbl:SchedBlock Schema: SchedBlock
May 26, 2004 7:12:25 AM alma.archive.components.OperationalImpl query
FINEST: Schema location for SchedBlock is uid://X0000000000000064/X0000000f
May 26, 2004 7:12:25 AM alma.archive.components.OperationalImpl update
FINEST: Updating: uid://X0000000000000066/X0000000a
May 26, 2004 7:12:25 AM alma.archive.components.OperationalImpl query
FINE: Returning cursor to user
May 26, 2004 7:12:25 AM alma.acs.container.corba.AcsCorba activateOffShoot
FINER: offshoot of type 'alma.archive.components.CursorImpl' activated as a CORBA object.
May 26, 2004 7:12:25 AM alma.scheduling.receivers.PipelineEventReceiver receive
INFO: SCHEDULING: PipelineEnd event received!
May 26, 2004 7:12:25 AM alma.scheduling.receivers.PipelineEventReceiver push_structured_event
INFO: SCHEDULING: Got event from Pipeline
May 26, 2004 7:12:25 AM alma.pipelinescience.components.SciencePipelineImpl$RunProcess run
INFO: SCIENCE_PIPELINE: completion event issued
May 26, 2004 7:12:25 AM alma.scheduling.master_scheduler.ALMATelescopeOperator isCompletedSb
INFO: SCHEDULING: checking for non-complete SB
May 26, 2004 7:12:25 AM alma.scheduling.scheduler.Scheduler run
INFO: SCHEDULING: No more SBs to process!
May 26, 2004 7:12:25 AM alma.scheduling.master_scheduler.SchedulingPublisher publishEvent
INFO: SCHEDULING: Event sent!
May 26, 2004 7:12:25 AM alma.scheduling.scheduler.Scheduler stop
INFO: SCHEDULING: About to stop scheduler.
May 26, 2004 7:12:25 AM alma.scheduling.master_scheduler.MasterScheduler run
INFO: SCHEDULING: MS Thread interrupted.
May 26, 2004 7:12:25 AM alma.scheduling.master_scheduler.MasterScheduler run
INFO: MSsleeping!
May 26, 2004 7:12:25 AM alma.scheduling.scheduler.Scheduler stop
INFO: SCHEDULING: Scheduler is stopped
uid://X0000000000000066/X0000000f uid://X0000000000000069/X00000000 completed
uid://X0000000000000066/X00000019 uid://X000000000000006b/X00000000 running
May 26, 2004 7:12:37 AM alma.archive.components.OperationalImpl update
FINEST: Updating: uid://X0000000000000066/X0000000f
May 26, 2004 7:12:37 AM alma.scheduling.receivers.PipelineEventReceiver receive
INFO: SCHEDULING: PipelineEnd event received!
May 26, 2004 7:12:37 AM alma.scheduling.receivers.PipelineEventReceiver push_structured_event
INFO: SCHEDULING: Got event from Pipeline
May 26, 2004 7:12:37 AM alma.pipelinescience.components.SciencePipelineImpl$RunProcess run
INFO: SCIENCE_PIPELINE: completion event issued
uid://X0000000000000066/X00000014 uid://X000000000000006a/X00000000 completed
May 26, 2004 7:12:51 AM alma.archive.components.OperationalImpl update
FINEST: Updating: uid://X0000000000000066/X00000014
May 26, 2004 7:12:51 AM alma.scheduling.receivers.PipelineEventReceiver receive
INFO: SCHEDULING: PipelineEnd event received!
May 26, 2004 7:12:51 AM alma.scheduling.receivers.PipelineEventReceiver push_structured_event
INFO: SCHEDULING: Got event from Pipeline
May 26, 2004 7:12:51 AM alma.pipelinescience.components.SciencePipelineImpl$RunProcess run
INFO: SCIENCE_PIPELINE: completion event issued
May 26, 2004 7:12:52 AM alma.acs.container.AcsContainer ping
FINER: ping received.
uid://X0000000000000066/X00000019 uid://X000000000000006b/X00000000 completed
May 26, 2004 7:13:04 AM alma.archive.components.OperationalImpl update
FINEST: Updating: uid://X0000000000000066/X00000019
May 26, 2004 7:13:04 AM alma.pipelinescience.components.SciencePipelineImpl$RunProcess run
INFO: SCIENCE_PIPELINE: completion event issued
May 26, 2004 7:13:04 AM alma.scheduling.receivers.PipelineEventReceiver receive
INFO: SCHEDULING: PipelineEnd event received!
May 26, 2004 7:13:04 AM alma.scheduling.receivers.PipelineEventReceiver push_structured_event
INFO: SCHEDULING: Got event from Pipeline
May 26, 2004 7:13:22 AM alma.acs.container.AcsContainer ping
FINER: ping received.
May 26, 2004 7:13:52 AM alma.acs.container.AcsContainer ping
FINER: ping received.
May 26, 2004 7:14:22 AM alma.acs.container.AcsContainer ping
FINER: ping received.
May 26, 2004 7:14:52 AM alma.acs.container.AcsContainer ping
FINER: ping received.
May 26, 2004 7:15:22 AM alma.acs.container.AcsContainer ping
FINER: ping received.
May 26, 2004 7:15:52 AM alma.acs.container.AcsContainer ping
FINER: ping received.
May 26, 2004 7:16:13 AM alma.scheduling.master_scheduler.ALMAArchive checkNewSB
INFO: SCHEDULING: checking for new sbs
May 26, 2004 7:16:13 AM alma.archive.components.OperationalImpl query
FINE: Querying XPath: /sbl:SchedBlock Schema: SchedBlock
May 26, 2004 7:16:13 AM alma.archive.components.OperationalImpl query
FINEST: Schema location for SchedBlock is uid://X0000000000000064/X0000000f
May 26, 2004 7:16:13 AM alma.scheduling.project_manager.ProjectManager run
INFO: SCHEDULING: PM woken up
May 26, 2004 7:16:14 AM alma.archive.components.OperationalImpl query
FINE: Returning cursor to user
May 26, 2004 7:16:14 AM alma.acs.container.corba.AcsCorba activateOffShoot
FINER: offshoot of type 'alma.archive.components.CursorImpl' activated as a CORBA object.
May 26, 2004 7:16:14 AM alma.scheduling.master_scheduler.ALMAArchive checkNewProjectDefs
INFO: SCHEDULING: checking for new project defs
May 26, 2004 7:16:14 AM alma.archive.components.OperationalImpl query
FINE: Querying XPath: /prj:ObsProject Schema: ObsProject
May 26, 2004 7:16:14 AM alma.archive.components.OperationalImpl query
FINEST: Schema location for ObsProject is uid://X0000000000000064/X0000000a
May 26, 2004 7:16:14 AM alma.archive.components.OperationalImpl query
FINE: Returning cursor to user
May 26, 2004 7:16:14 AM alma.acs.container.corba.AcsCorba activateOffShoot
FINER: offshoot of type 'alma.archive.components.CursorImpl' activated as a CORBA object.
SCHEDULING: MB Action running
May 26, 2004 7:16:22 AM alma.acs.container.AcsContainer ping
FINER: ping received.
May 26, 2004 7:16:52 AM alma.acs.container.AcsContainer ping
FINER: ping received.
May 26, 2004 7:17:08 AM alma.acs.container.AcsContainer shutdown
INFO: received call to 'shutdown', action=2 (encryptedAction=512), gracefully=true.
May 26, 2004 7:17:08 AM alma.acs.container.AcsContainer logManagerRequest
FINE: received call to deactivate_components; handles = 16777228 16777221 16777226 16777230 16777219 16777217 16777227 16777229 16777220 16777231 16777218
May 26, 2004 7:17:08 AM alma.acs.container.ComponentStateManagerImpl setState
FINER: switching state of component ArrayController1 from OPERATIONAL to DESTROYING
May 26, 2004 7:17:08 AM alma.acs.container.ComponentStateManagerImpl setState
FINER: switching state of component SCIENCE_PIPELINE from OPERATIONAL to DESTROYING
May 26, 2004 7:17:08 AM alma.acs.container.ComponentStateManagerImpl setState
FINER: switching state of component MASTER_SCHEDULER from OPERATIONAL to DESTROYING
May 26, 2004 7:17:08 AM alma.acs.container.ComponentStateManagerImpl setState
FINER: switching state of component ArrayController3 from OPERATIONAL to DESTROYING
May 26, 2004 7:17:08 AM alma.acs.container.ComponentStateManagerImpl setState
FINER: switching state of component IDENTIFIER_ARCHIVE from OPERATIONAL to DESTROYING
May 26, 2004 7:17:08 AM alma.acs.container.ComponentStateManagerImpl setState
FINER: switching state of component GETTELCALRESULTS1 from OPERATIONAL to DESTROYING
May 26, 2004 7:17:08 AM alma.acs.container.ComponentStateManagerImpl setState
FINER: switching state of component ArrayController0 from OPERATIONAL to DESTROYING
May 26, 2004 7:17:08 AM alma.acs.container.ComponentStateManagerImpl setState
FINER: switching state of component ArrayController2 from OPERATIONAL to DESTROYING
May 26, 2004 7:17:08 AM alma.acs.container.ComponentStateManagerImpl setState
FINER: switching state of component ControlSystem1 from OPERATIONAL to DESTROYING
May 26, 2004 7:17:08 AM alma.acs.container.ComponentStateManagerImpl setState
FINER: switching state of component ArrayController4 from OPERATIONAL to DESTROYING
May 26, 2004 7:17:08 AM alma.acs.container.ComponentStateManagerImpl setState
FINER: switching state of component ARCHIVE_CONNECTION from OPERATIONAL to DESTROYING
May 26, 2004 7:17:08 AM alma.acs.container.AcsContainer deactivate_components
FINER: deactivating component 'ArrayController1' with handle 16777228
May 26, 2004 7:17:08 AM alma.acs.container.ComponentAdapter deactivateComponent
FINER: about to deactivate component ArrayController1
May 26, 2004 7:17:08 AM alma.Control.arrayInterfaces.ArrayMonitorImpl cleanUp
INFO: ArrayMonitorImpl.cleanUp() called...
May 26, 2004 7:17:08 AM alma.acs.container.ComponentStateManagerImpl setState
FINER: switching state of component ArrayController1 from DESTROYING to DEFUNCT
May 26, 2004 7:17:08 AM alma.acs.container.ComponentAdapter deactivateComponent
FINER: done deactivating component ArrayController1
May 26, 2004 7:17:08 AM alma.acs.container.AcsContainer deactivate_components
FINER: deactivating component 'SCIENCE_PIPELINE' with handle 16777221
May 26, 2004 7:17:08 AM alma.acs.container.ComponentAdapter deactivateComponent
FINER: about to deactivate component SCIENCE_PIPELINE
May 26, 2004 7:17:08 AM alma.pipelinescience.components.SciencePipelineImpl cleanUp
INFO: SCIENCE_PIPELINE: cleanUp() method called
[ POA ComponentPOAArrayController1 - destroyed ]
May 26, 2004 7:17:08 AM alma.acs.container.ComponentStateManagerImpl setState
FINER: switching state of component SCIENCE_PIPELINE from DESTROYING to DEFUNCT
May 26, 2004 7:17:08 AM alma.acs.container.ComponentAdapter deactivateComponent
FINER: done deactivating component SCIENCE_PIPELINE
May 26, 2004 7:17:08 AM alma.acs.container.AcsContainer deactivate_components
FINER: deactivating component 'MASTER_SCHEDULER' with handle 16777226
May 26, 2004 7:17:08 AM alma.acs.container.ComponentAdapter deactivateComponent
FINER: about to deactivate component MASTER_SCHEDULER
[ POA ComponentPOASCIENCE_PIPELINE - destroyed ]
SCHEDULING: MB Action stopped
May 26, 2004 7:17:08 AM alma.scheduling.project_manager.ProjectManager stop
INFO: SCHEDULING: PM Stopped!
May 26, 2004 7:17:08 AM alma.scheduling.master_scheduler.MasterScheduler stopScheduling
INFO: SCHEDULING: Scheduler already stopped.
May 26, 2004 7:17:08 AM alma.scheduling.master_scheduler.SchedulingPublisher shutdown
INFO: SCHEDULING: Shutting down SCHEDULING notification channel.
May 26, 2004 7:17:08 AM alma.scheduling.master_scheduler.MasterScheduler cleanUp
INFO: SCHEDULING: The MasterScheduler has been cleaned up and is now stopped.
May 26, 2004 7:17:08 AM alma.acs.container.ComponentStateManagerImpl setState
FINER: switching state of component MASTER_SCHEDULER from DESTROYING to DEFUNCT
May 26, 2004 7:17:08 AM alma.acs.container.ComponentAdapter deactivateComponent
FINER: done deactivating component MASTER_SCHEDULER
May 26, 2004 7:17:08 AM alma.acs.container.AcsContainer deactivate_components
FINER: deactivating component 'ArrayController3' with handle 16777230
[ POA ComponentPOAMASTER_SCHEDULER - destroyed ]
May 26, 2004 7:17:08 AM alma.acs.container.ComponentAdapter deactivateComponent
FINER: about to deactivate component ArrayController3
May 26, 2004 7:17:08 AM alma.Control.arrayInterfaces.ArrayMonitorImpl cleanUp
INFO: ArrayMonitorImpl.cleanUp() called...
May 26, 2004 7:17:08 AM alma.acs.container.ComponentStateManagerImpl setState
FINER: switching state of component ArrayController3 from DESTROYING to DEFUNCT
May 26, 2004 7:17:08 AM alma.acs.container.ComponentAdapter deactivateComponent
FINER: done deactivating component ArrayController3
May 26, 2004 7:17:08 AM alma.acs.container.AcsContainer deactivate_components
FINER: deactivating component 'IDENTIFIER_ARCHIVE' with handle 16777219
[ POA ComponentPOAArrayController3 - destroyed ]
May 26, 2004 7:17:08 AM alma.acs.container.ComponentAdapter deactivateComponent
FINER: about to deactivate component IDENTIFIER_ARCHIVE
May 26, 2004 7:17:08 AM alma.archive.components.IdentifierImpl close
INFO: Disconnected from the identifier manager
May 26, 2004 7:17:08 AM alma.acs.container.ComponentStateManagerImpl setState
FINER: switching state of component IDENTIFIER_ARCHIVE from DESTROYING to DEFUNCT
May 26, 2004 7:17:08 AM alma.acs.container.ComponentAdapter deactivateComponent
FINER: done deactivating component IDENTIFIER_ARCHIVE
May 26, 2004 7:17:08 AM alma.acs.container.AcsContainer deactivate_components
FINER: deactivating component 'GETTELCALRESULTS1' with handle 16777217
May 26, 2004 7:17:08 AM alma.acs.container.ComponentAdapter deactivateComponent
FINER: about to deactivate component GETTELCALRESULTS1
May 26, 2004 7:17:08 AM alma.TelCalPublisher.GetTelCalResultsImpl.GetTelCalResultsImpl cleanUp
INFO: cleanUp() called.
May 26, 2004 7:17:08 AM alma.acs.container.ContainerServicesImpl releaseComponent
FINE: about to release component ARCHIVE_CONNECTION
May 26, 2004 7:17:08 AM alma.acs.container.AcsManagerProxy release_component
FINER: released 'ARCHIVE_CONNECTION' with the manager. Remaining clients: 1
May 26, 2004 7:17:08 AM alma.acs.container.ContainerServicesImpl releaseComponent
INFO: client 'GETTELCALRESULTS1' has successfully released a component with curl=ARCHIVE_CONNECTION
[ POA ComponentPOAIDENTIFIER_ARCHIVE - destroyed ]
May 26, 2004 7:17:08 AM alma.acs.container.ComponentStateManagerImpl setState
FINER: switching state of component GETTELCALRESULTS1 from DESTROYING to DEFUNCT
May 26, 2004 7:17:08 AM alma.acs.container.ComponentAdapter deactivateComponent
FINER: done deactivating component GETTELCALRESULTS1
May 26, 2004 7:17:08 AM alma.acs.container.AcsContainer deactivate_components
FINER: deactivating component 'ArrayController0' with handle 16777227
May 26, 2004 7:17:08 AM alma.acs.container.ComponentAdapter deactivateComponent
FINER: about to deactivate component ArrayController0
May 26, 2004 7:17:08 AM alma.Control.arrayInterfaces.ArrayMonitorImpl cleanUp
INFO: ArrayMonitorImpl.cleanUp() called...
May 26, 2004 7:17:08 AM alma.acs.container.ComponentStateManagerImpl setState
FINER: switching state of component ArrayController0 from DESTROYING to DEFUNCT
May 26, 2004 7:17:08 AM alma.acs.container.ComponentAdapter deactivateComponent
FINER: done deactivating component ArrayController0
May 26, 2004 7:17:08 AM alma.acs.container.AcsContainer deactivate_components
FINER: deactivating component 'ArrayController2' with handle 16777229
May 26, 2004 7:17:08 AM alma.acs.container.ComponentAdapter deactivateComponent
FINER: about to deactivate component ArrayController2
[ POA ComponentPOAArrayController0 - destroyed ]
May 26, 2004 7:17:08 AM alma.Control.arrayInterfaces.ArrayMonitorImpl cleanUp
INFO: ArrayMonitorImpl.cleanUp() called...
May 26, 2004 7:17:08 AM alma.acs.container.ComponentStateManagerImpl setState
FINER: switching state of component ArrayController2 from DESTROYING to DEFUNCT
May 26, 2004 7:17:08 AM alma.acs.container.ComponentAdapter deactivateComponent
FINER: done deactivating component ArrayController2
May 26, 2004 7:17:08 AM alma.acs.container.AcsContainer deactivate_components
FINER: deactivating component 'ControlSystem1' with handle 16777220
May 26, 2004 7:17:08 AM alma.acs.container.ComponentAdapter deactivateComponent
FINER: about to deactivate component ControlSystem1
[ POA ComponentPOAArrayController2 - destroyed ]
May 26, 2004 7:17:08 AM alma.Control.masterController.ControlStatusImpl cleanUp
INFO: cleanUp() called...
May 26, 2004 7:17:08 AM alma.acs.container.ComponentStateManagerImpl setState
FINER: switching state of component ControlSystem1 from DESTROYING to DEFUNCT
[ POA ComponentPOAGETTELCALRESULTS1 - destroyed ]
May 26, 2004 7:17:08 AM alma.acs.container.ComponentAdapter deactivateComponent
FINER: done deactivating component ControlSystem1
May 26, 2004 7:17:08 AM alma.acs.container.AcsContainer deactivate_components
FINER: deactivating component 'ArrayController4' with handle 16777231
May 26, 2004 7:17:08 AM alma.acs.container.ComponentAdapter deactivateComponent
FINER: about to deactivate component ArrayController4
[ POA ComponentPOAControlSystem1 - destroyed ]
May 26, 2004 7:17:08 AM alma.Control.arrayInterfaces.ArrayMonitorImpl cleanUp
INFO: ArrayMonitorImpl.cleanUp() called...
May 26, 2004 7:17:08 AM alma.acs.container.ComponentStateManagerImpl setState
FINER: switching state of component ArrayController4 from DESTROYING to DEFUNCT
May 26, 2004 7:17:08 AM alma.acs.container.ComponentAdapter deactivateComponent
FINER: done deactivating component ArrayController4
May 26, 2004 7:17:08 AM alma.acs.container.AcsContainer deactivate_components
FINER: deactivating component 'ARCHIVE_CONNECTION' with handle 16777218
May 26, 2004 7:17:08 AM alma.acs.container.ComponentAdapter deactivateComponent
FINER: about to deactivate component ARCHIVE_CONNECTION
[ POA ComponentPOAArrayController4 - destroyed ]
May 26, 2004 7:17:08 AM alma.acs.container.ComponentStateManagerImpl setState
FINER: switching state of component ARCHIVE_CONNECTION from DESTROYING to DEFUNCT
[ POA offshootPoa - destroyed ]
May 26, 2004 7:17:08 AM alma.acs.container.ComponentAdapter deactivateComponent
FINER: done deactivating component ARCHIVE_CONNECTION
May 26, 2004 7:17:08 AM alma.acs.container.AcsManagerProxy logoutFromManager
FINE: about to log out from manager...
[ POA ComponentPOAARCHIVE_CONNECTION - destroyed ]
May 26, 2004 7:17:08 AM alma.acs.container.AcsManagerProxy logoutFromManager
FINE: logged out from manager.
[ POA ComponentPOA - destroyed ]
May 26, 2004 7:17:08 AM alma.acs.container.AcsContainerRunner run
FINE: orb loop over.
[ POA ContainerPOA - destroyed ]
[ POA RootPOA - destroyed ]
May 26, 2004 7:17:08 AM alma.acs.container.AcsContainerRunner run
FINER: RETURN
[ Connected to 134.171.12.100:3003 ]