def updateRequest( self, requestName, requestString ):
""" update request given its name and xml serilised string
:param str requestName: Requests.RequestName
:param str requestString: request serilised to xml
"""
request = RequestContainer( request = requestString )
requestTypes = ['transfer', 'register', 'removal', 'stage', 'diset', 'logupload']
requestID = request.getRequestID()['Value']
updateRequestFailed = False
for requestType in requestTypes:
res = request.getNumSubRequests( requestType )
if res['OK']:
numRequests = res['Value']
for ind in range( numRequests ):
res = request.getSubRequestAttributes( ind, requestType )
if res['OK']:
subRequestDict = res['Value']
if 'SubRequestID' in subRequestDict:
subRequestID = res['Value']['SubRequestID']
res = self.__updateSubRequestFiles( ind, requestType, subRequestID, request )
if res['OK']:
if request.isSubRequestDone( ind, requestType )['Value']:
res = self._setSubRequestAttribute( requestID, subRequestID, 'Status', 'Done' )
else:
res = self._setSubRequestAttribute( requestID, subRequestID, 'Status', 'Waiting' )
if not res['OK']:
updateRequestFailed = True
else:
updateRequestFailed = True
if "Error" in subRequestDict:
result = self._setSubRequestAttribute( requestID, subRequestID,
'Error', subRequestDict['Error'] )
if not result['OK']:
updateRequestFailed = True
else:
updateRequestFailed = True
else:
updateRequestFailed = True
else:
updateRequestFailed = True
if updateRequestFailed:
errStr = 'Failed to update request %s.' % requestID
return S_ERROR( errStr )
else:
requestStatus = self.getRequestStatus( requestID )
if not requestStatus["OK"]:
return requestStatus
requestStatus = requestStatus["Value"]
if requestStatus["SubRequestStatus"] not in ( "Waiting", "Assigned" ):
res = self._setRequestAttribute( requestID, 'Status', 'Done' )
if not res['OK']:
errStr = 'Failed to update request status of %s to Done.' % requestID
return S_ERROR( errStr )
return S_OK()
def updateRequest(self, requestName, requestString):
request = RequestContainer(request=requestString)
requestTypes = [
'transfer', 'register', 'removal', 'stage', 'diset', 'logupload'
]
requestID = request.getRequestID()['Value']
updateRequestFailed = False
for requestType in requestTypes:
res = request.getNumSubRequests(requestType)
if res['OK']:
numRequests = res['Value']
for ind in range(numRequests):
res = request.getSubRequestAttributes(ind, requestType)
if res['OK']:
subRequestDict = res['Value']
if 'SubRequestID' in subRequestDict:
subRequestID = res['Value']['SubRequestID']
res = self.__updateSubRequestFiles(
ind, requestType, subRequestID, request)
if res['OK']:
if request.isSubRequestDone(
ind, requestType)['Value']:
res = self._setSubRequestAttribute(
requestID, subRequestID, 'Status',
'Done')
else:
res = self._setSubRequestAttribute(
requestID, subRequestID, 'Status',
'Waiting')
if not res['OK']:
updateRequestFailed = True
else:
updateRequestFailed = True
if "Error" in subRequestDict:
result = self._setSubRequestAttribute(
requestID, subRequestID, 'Error',
subRequestDict['Error'])
if not result['OK']:
updateRequestFailed = True
else:
updateRequestFailed = True
else:
updateRequestFailed = True
else:
updateRequestFailed = True
if updateRequestFailed:
errStr = 'Failed to update request %s.' % requestID
return S_ERROR(errStr)
else:
if request.isRequestDone()['Value']:
res = self._setRequestAttribute(requestID, 'Status', 'Done')
if not res['OK']:
errStr = 'Failed to update request status of %s to Done.' % requestID
return S_ERROR(errStr)
return S_OK()
def updateRequest( self, requestName, requestString ):
request = RequestContainer( request = requestString )
requestTypes = ['transfer', 'register', 'removal', 'stage', 'diset', 'logupload']
requestID = request.getRequestID()['Value']
updateRequestFailed = False
for requestType in requestTypes:
res = request.getNumSubRequests( requestType )
if res['OK']:
numRequests = res['Value']
for ind in range( numRequests ):
res = request.getSubRequestAttributes( ind, requestType )
if res['OK']:
subRequestDict = res['Value']
if 'SubRequestID' in subRequestDict:
subRequestID = res['Value']['SubRequestID']
res = self.__updateSubRequestFiles( ind, requestType, subRequestID, request )
if res['OK']:
if request.isSubRequestDone( ind, requestType )['Value']:
res = self._setSubRequestAttribute( requestID, subRequestID, 'Status', 'Done' )
else:
res = self._setSubRequestAttribute( requestID, subRequestID, 'Status', 'Waiting' )
if not res['OK']:
updateRequestFailed = True
else:
updateRequestFailed = True
if "Error" in subRequestDict:
result = self._setSubRequestAttribute( requestID, subRequestID, 'Error', subRequestDict['Error'] )
if not result['OK']:
updateRequestFailed = True
else:
updateRequestFailed = True
else:
updateRequestFailed = True
else:
updateRequestFailed = True
if updateRequestFailed:
errStr = 'Failed to update request %s.' % requestID
return S_ERROR( errStr )
else:
if request.isRequestDone()['Value']:
res = self._setRequestAttribute( requestID, 'Status', 'Done' )
if not res['OK']:
errStr = 'Failed to update request status of %s to Done.' % requestID
return S_ERROR( errStr )
return S_OK()
class RequestTask( object ):
"""
.. class:: RequestTask
Base class for DMS 'transfer', 'removal' and 'register' Requests processing.
This class is meant to be executed as a ProcessTask inside ProcessPool.
The most important and common global DIRAC objects are created in RequestTask constructor.
This includes gLogger, gConfig, gProxyManager, S_OK and S_ERROR. The constructor also
imports a set of common modules: os, sys, re, time and everything from types module.
All other DIRAC tools and clients (i.e. RequestManager) are private in RequestTask class and will
be imported and instantiated on demand during first usage. They are accessible using proxied public methods, i.e.
if you are going to use ReplicaManager just call::
self.replicaManager().someMethod()
All currently proxied tools are::
DataLoggingClient -- self.dataLoggingClient()
ReplicaManager -- self.replicaManager()
RequestClient -- self.requestClient()
StorageFactory -- self.storageFactory()
SubLogger message handles for all levels are also proxied, so you can directly use them in your code, i.e.::
self.info("An info message")
self.debug("This will be shown only in debug")
For handling sub-request one has to register their actions handlers using :self.addOperationAction:
method. This method checks if handler is defined as a method of inherited class and then puts its
definition into internal operation dispatcher dictionary with a key of sub-request's operation name.
Each operation handler should have the signature::
def operationName( self, index, requestObj, subRequestAttrs, subRequestFiles )
where index is a sub-request counter, requestObj is a RequestContainer instance,
subRequestAttrs is a dict with sub-request attributes and subRequestFiles is a dict with
files attached to the sub-request.
Handlers shoudl always return S_OK with value of (modified or not) requestObj, S_ERROR with some
error message otherwise.
Processing of request is done automatically in self.__call__, one doesn't have to worry about changing
credentials, looping over subrequests or request finalizing -- only sub-request processing matters in
the all inherited classes.
Concerning :MonitringClient: (or better known its global instance :gMonitor:), if someone wants to send
some metric over there, she has to put in agent's code registration of activity and then in a particular
task use :RequestTask.addMark: to save monitoring data. All monitored activities are held in
:RequestTask.__monitor: dict which at the end of processing is returned from :RequestTask.__call__:.
The values are then processed and pushed to the gMonitor instance in the default callback function.
"""
## reference to ReplicaManager
__replicaManager = None
## reference to DataLoggingClient
__dataLoggingClient = None
## reference to RequestClient
__requestClient = None
## reference to StotageFactory
__storageFactory = None
## subLogger
__log = None
## request type
__requestType = None
## placeholder for request owner DB
requestOwnerDN = None
## placeholder for Request owner group
requestOwnerGroup = None
## operation dispatcher for SubRequests,
## a dictonary
## "operation" => methodToRun
##
__operationDispatcher = {}
## holder for DataManager proxy file
__dataManagerProxy = None
## monitoring dict
__monitor = {}
def __init__( self, requestString, requestName, executionOrder, jobID, configPath ):
""" c'tor
:param self: self reference
:param str requestString: XML serialised RequestContainer
:param str requestName: request name
:param list executionOrder: request execution order
:param int jobID: jobID
:param str sourceServer: request's source server
:param str configPath: path in CS for parent agent
"""
## fixtures
## python fixtures
import os, os.path, sys, time, re, types
self.makeGlobal( "os", os )
self.makeGlobal( "os.path", os.path )
self.makeGlobal( "sys", sys )
self.makeGlobal( "time", time )
self.makeGlobal( "re", re )
## export all Types from types
[ self.makeGlobal( item, getattr( types, item ) ) for item in dir(types) if "Type" in item ]
## DIRAC fixtures
from DIRAC.FrameworkSystem.Client.Logger import gLogger
self.__log = gLogger.getSubLogger( "%s/%s" % ( self.__class__.__name__, str(requestName) ) )
self.always = self.__log.always
self.notice = self.__log.notice
self.info = self.__log.info
self.debug = self.__log.debug
self.warn = self.__log.warn
self.error = self.__log.error
self.exception = self.__log.exception
self.fatal = self.__log.fatal
from DIRAC import S_OK, S_ERROR
from DIRAC.ConfigurationSystem.Client.Config import gConfig
from DIRAC.FrameworkSystem.Client.ProxyManagerClient import gProxyManager
from DIRAC.ConfigurationSystem.Client.Helpers.Registry import getGroupsWithVOMSAttribute
from DIRAC.ConfigurationSystem.Client.ConfigurationData import gConfigurationData
## export DIRAC global tools and functions
self.makeGlobal( "S_OK", S_OK )
self.makeGlobal( "S_ERROR", S_ERROR )
self.makeGlobal( "gLogger", gLogger )
self.makeGlobal( "gConfig", gConfig )
self.makeGlobal( "gProxyManager", gProxyManager )
self.makeGlobal( "getGroupsWithVOMSAttribute", getGroupsWithVOMSAttribute )
self.makeGlobal( "gConfigurationData", gConfigurationData )
## save request string
self.requestString = requestString
## build request object
from DIRAC.RequestManagementSystem.Client.RequestContainer import RequestContainer
self.requestObj = RequestContainer( init = False )
self.requestObj.parseRequest( request = self.requestString )
## save request name
self.requestName = requestName
## .. and jobID
self.jobID = jobID
## .. and execution order
self.executionOrder = executionOrder
## save config path
self.__configPath = configPath
## set requestType
self.setRequestType( gConfig.getValue( os.path.join( configPath, "RequestType" ), "" ) )
## get log level
self.__log.setLevel( gConfig.getValue( os.path.join( configPath, self.__class__.__name__, "LogLevel" ), "INFO" ) )
## clear monitoring
self.__monitor = {}
## save DataManager proxy
if "X509_USER_PROXY" in os.environ:
self.info("saving path to current proxy file")
self.__dataManagerProxy = os.environ["X509_USER_PROXY"]
else:
self.error("'X509_USER_PROXY' environment variable not set")
def dataManagerProxy( self ):
""" get dataManagerProxy file
:param self: self reference
"""
return self.__dataManagerProxy
def addMark( self, name, value = 1 ):
""" add mark to __monitor dict
:param self: self reference
:param name: mark name
:param value: value to be
"""
if name not in self.__monitor:
self.__monitor.setdefault( name, 0 )
self.__monitor[name] += value
def monitor( self ):
""" get monitoring dict
:param cls: class reference
"""
return self.__monitor
def makeGlobal( self, objName, objDef ):
""" export :objDef: to global name space using :objName: name
:param self: self reference
:param str objName: symbol name
:param mixed objDef: symbol definition
:throws: NameError if symbol of that name is already in
"""
if objName not in __builtins__:
if type( __builtins__) == type( {} ):
__builtins__[objName] = objDef
else:
setattr( __builtins__, objName, objDef )
return True
def requestType( self ):
""" get request type
:params self: self reference
"""
return self.__requestType
def setRequestType( self, requestType ):
""" set request type
:param self: self reference
"""
self.debug( "Setting requestType to %s" % str(requestType) )
self.__requestType = requestType
@classmethod
def replicaManager( cls ):
""" ReplicaManager getter
:param cls: class reference
"""
if not cls.__replicaManager:
from DIRAC.DataManagementSystem.Client.ReplicaManager import ReplicaManager
cls.__replicaManager = ReplicaManager()
return cls.__replicaManager
@classmethod
def dataLoggingClient( cls ):
""" DataLoggingClient getter
:param cls: class reference
"""
if not cls.__dataLoggingClient:
from DIRAC.DataManagementSystem.Client.DataLoggingClient import DataLoggingClient
cls.__dataLoggingClient = DataLoggingClient()
return cls.__dataLoggingClient
@classmethod
def requestClient( cls ):
""" RequestClient getter
:param cls: class reference
"""
if not cls.__requestClient:
from DIRAC.RequestManagementSystem.Client.RequestClient import RequestClient
cls.__requestClient = RequestClient()
return cls.__requestClient
@classmethod
def storageFactory( cls ):
""" StorageFactory getter
:param cls: class reference
"""
if not cls.__storageFactory:
from DIRAC.Resources.Storage.StorageFactory import StorageFactory
cls.__storageFactory = StorageFactory()
return cls.__storageFactory
def changeProxy( self, ownerDN, ownerGroup ):
""" get proxy from gProxyManager, save it to file
:param self: self reference
:param str ownerDN: request owner DN
:param str ownerGroup: request owner group
:return: S_OK with name of newly created owner proxy file
"""
ownerProxy = gProxyManager.downloadVOMSProxy( str(ownerDN), str(ownerGroup) )
if not ownerProxy["OK"] or not ownerProxy["Value"]:
reason = ownerProxy["Message"] if "Message" in ownerProxy else "No valid proxy found in ProxyManager."
return S_ERROR( "Change proxy error for '%s'@'%s': %s" % ( ownerDN, ownerGroup, reason ) )
ownerProxyFile = ownerProxy["Value"].dumpAllToFile()
if not ownerProxyFile["OK"]:
return S_ERROR( ownerProxyFile["Message"] )
ownerProxyFile = ownerProxyFile["Value"]
os.environ["X509_USER_PROXY"] = ownerProxyFile
return S_OK( ownerProxyFile )
######################################################################
# operationDispatcher
@classmethod
def operationDispatcher( cls ):
""" operation dispatcher getter
:param cls: class reference
"""
return cls.__operationDispatcher
@classmethod
def addOperationAction( cls, operation, methodToRun, overwrite = True ):
""" register handler :methodToRun: for SubRequest operation :operation:
:warn: all handlers should have the same signature
:param self: self reference
:param str operation: SubRequest operation name
:param MethodType methodToRun: handler to be executed for SubRequest
:param bool overwrite: flag to overwrite handler, if already present
:return: S_OK/S_ERROR
Every action handler should return S_OK with of a structure::
{ "OK" : True,
"Value" : requestObj # that has been sent to operation handler
}
otherwise S_ERROR.
"""
if operation in cls.__operationDispatcher and not overwrite:
return S_ERROR("addOperationAction: operation for '%s' is already registered" % operation )
if type(methodToRun) is not MethodType:
return S_ERROR("addOperationAction: wrong type (%s = types.MethodType) for '%s' operation" % \
( str(type(methodToRun)), operation ) )
cls.__operationDispatcher[operation] = methodToRun
return S_OK()
def __call__( self ):
""" generic function to process one Request of a type requestType
This method could be run in a thread.
:param self: self reference
:param str requestType: request type
:return: S_OK/S_ERROR
"""
self.always("executing request %s" % self.requestName )
################################################################
## get ownerDN and ownerGroup
ownerDN = self.requestObj.getAttribute( "OwnerDN" )
if not ownerDN["OK"]:
return ownerDN
ownerDN = ownerDN["Value"]
ownerGroup = self.requestObj.getAttribute( "OwnerGroup" )
if not ownerGroup["OK"]:
return ownerGroup
ownerGroup = ownerGroup["Value"]
## save request owner
self.requestOwnerDN = ownerDN if ownerDN else ""
self.requestOwnerGroup = ownerGroup if ownerGroup else ""
#################################################################
## change proxy
ownerProxyFile = None
if ownerDN and ownerGroup:
ownerProxyFile = self.changeProxy( ownerDN, ownerGroup )
if not ownerProxyFile["OK"]:
self.error( "handleReuqest: unable to get proxy for '%s'@'%s': %s" % ( ownerDN,
ownerGroup,
ownerProxyFile["Message"] ) )
update = self.putBackRequest( self.requestName, self.requestString )
if not update["OK"]:
self.error( "handleRequest: error when updating request: %s" % update["Message"] )
return update
return ownerProxyFile
ownerProxyFile = ownerProxyFile["Value"]
#self.ownerProxyFile = ownerProxyFile
self.info( "Will execute request for '%s'@'%s' using proxy file %s" % ( ownerDN, ownerGroup, ownerProxyFile ) )
else:
self.info( "Will execute request for DataManager using her/his proxy")
#################################################################
## execute handlers
ret = { "OK" : False, "Message" : "" }
useServerCert = gConfig.useServerCertificate()
try:
# Execute task with the owner proxy even for contacting DIRAC services
if useServerCert:
gConfigurationData.setOptionInCFG('/DIRAC/Security/UseServerCertificate','false')
ret = self.handleRequest()
finally:
if useServerCert:
gConfigurationData.setOptionInCFG('/DIRAC/Security/UseServerCertificate','true')
## delete owner proxy
if self.__dataManagerProxy:
os.environ["X509_USER_PROXY"] = self.__dataManagerProxy
if ownerProxyFile and os.path.exists( ownerProxyFile ):
os.unlink( ownerProxyFile )
if not ret["OK"]:
self.error( "handleRequest: error during request processing: %s" % ret["Message"] )
self.error( "handleRequest: will put original request back" )
update = self.putBackRequest( self.requestName, self.requestString )
if not update["OK"]:
self.error( "handleRequest: error when putting back request: %s" % update["Message"] )
## return at least
return ret
def handleRequest( self ):
""" read SubRequests and ExecutionOrder, fire registered handlers upon SubRequests operations
:param self: self reference
:param dict requestDict: request dictionary as read from self.readRequest
"""
##############################################################
# here comes the processing
##############################################################
res = self.requestObj.getNumSubRequests( self.__requestType )
if not res["OK"]:
errMsg = "handleRequest: failed to obtain number of '%s' subrequests." % self.__requestType
self.error( errMsg, res["Message"] )
return S_ERROR( res["Message"] )
## for gMonitor
self.addMark( "Execute", 1 )
## process sub requests
for index in range( res["Value"] ):
self.info( "handleRequest: processing subrequest %s." % str(index) )
subRequestAttrs = self.requestObj.getSubRequestAttributes( index, self.__requestType )["Value"]
if subRequestAttrs["ExecutionOrder"]:
subExecutionOrder = int( subRequestAttrs["ExecutionOrder"] )
else:
subExecutionOrder = 0
subRequestStatus = subRequestAttrs["Status"]
if subRequestStatus != "Waiting":
self.info( "handleRequest: subrequest %s has status '%s' and is not to be executed." % ( str(index),
subRequestStatus ) )
continue
if subExecutionOrder <= self.executionOrder:
operation = subRequestAttrs["Operation"]
if operation not in self.operationDispatcher():
self.error( "handleRequest: '%s' operation not supported" % operation )
else:
self.info( "handleRequest: will execute %s '%s' subrequest" % ( str(index), operation ) )
## get files
subRequestFiles = self.requestObj.getSubRequestFiles( index, self.__requestType )["Value"]
## execute operation action
ret = self.operationDispatcher()[operation].__call__( index,
self.requestObj,
subRequestAttrs,
subRequestFiles )
################################################
## error in operation action?
if not ret["OK"]:
self.error( "handleRequest: error when handling subrequest %s: %s" % ( str(index), ret["Message"] ) )
self.requestObj.setSubRequestAttributeValue( index, self.__requestType, "Error", ret["Message"] )
else:
## update ref to requestObj
self.requestObj = ret["Value"]
## check if subrequest status == Done, disable finalisation if not
subRequestDone = self.requestObj.isSubRequestDone( index, self.__requestType )
if not subRequestDone["OK"]:
self.error( "handleRequest: unable to determine subrequest status: %s" % subRequestDone["Message"] )
else:
if not subRequestDone["Value"]:
self.warn("handleRequest: subrequest %s is not done yet" % str(index) )
################################################
# Generate the new request string after operation
newRequestString = self.requestObj.toXML()['Value']
update = self.putBackRequest( self.requestName, newRequestString )
if not update["OK"]:
self.error( "handleRequest: error when updating request: %s" % update["Message"] )
return update
## get request status
if self.jobID:
requestStatus = self.requestClient().getRequestStatus( self.requestName )
if not requestStatus["OK"]:
return requestStatus
requestStatus = requestStatus["Value"]
## finalize request if jobID is present and request status = 'Done'
self.info("handleRequest: request status is %s" % requestStatus )
if ( requestStatus["RequestStatus"] == "Done" ) and ( requestStatus["SubRequestStatus"] not in ( "Waiting", "Assigned" ) ):
self.debug("handleRequest: request is going to be finalised")
finalize = self.requestClient().finalizeRequest( self.requestName, self.jobID )
if not finalize["OK"]:
self.error("handleRequest: error in request finalization: %s" % finalize["Message"] )
return finalize
self.info("handleRequest: request is finalised")
## for gMonitor
self.addMark( "Done", 1 )
## should return S_OK with monitor dict
return S_OK( { "monitor" : self.monitor() } )
def putBackRequest( self, requestName, requestString ):
""" put request back
:param self: self reference
:param str requestName: request name
:param str requestString: XML-serilised request
:param str sourceServer: request server URL
"""
update = self.requestClient().updateRequest( requestName, requestString )
if not update["OK"]:
self.error( "putBackRequest: error when updating request: %s" % update["Message"] )
return update
return S_OK()
def executeRequest(self):
"""
Do the actual work in the Thread
"""
################################################
# Get a request from request DB
gMonitor.addMark("Iteration", 1)
res = self.requestDBClient.getRequest('removal')
if not res['OK']:
gLogger.info(
"RemovalAgent.execute: Failed to get request from database.")
return S_OK()
elif not res['Value']:
gLogger.info(
"RemovalAgent.execute: No requests to be executed found.")
self.pendingRequests = False
return S_OK()
requestString = res['Value']['RequestString']
requestName = res['Value']['RequestName']
sourceServer = res['Value']['Server']
jobID = 0
try:
jobID = int(res['Value']['JobID'])
except:
gLogger.warn(
"RemovalAgent.execute: JobID not present or malformed in request '%s', will use 0 instead."
% requestName)
gLogger.info("RemovalAgent.execute: Obtained request %s" % requestName)
try:
result = self.requestDBClient.getCurrentExecutionOrder(
requestName, sourceServer)
if result['OK']:
currentOrder = result['Value']
else:
gLogger.error('Can not get the request execution order')
self.requestDBClient.updateRequest(requestName, requestString,
sourceServer)
return S_OK('Can not get the request execution order')
oRequest = RequestContainer(request=requestString)
################################################
# Find the number of sub-requests from the request
res = oRequest.getNumSubRequests('removal')
if not res['OK']:
errStr = "RemovalAgent.execute: Failed to obtain number of removal subrequests."
gLogger.error(errStr, res['Message'])
return S_OK()
gLogger.info("RemovalAgent.execute: Found %s sub requests." %
res['Value'])
################################################
# For all the sub-requests in the request
modified = False
for ind in range(res['Value']):
gMonitor.addMark("Execute", 1)
gLogger.info(
"RemovalAgent.execute: Processing sub-request %s." % ind)
subRequestAttributes = oRequest.getSubRequestAttributes(
ind, 'removal')['Value']
subExecutionOrder = int(subRequestAttributes['ExecutionOrder'])
subStatus = subRequestAttributes['Status']
if subStatus == 'Waiting' and subExecutionOrder <= currentOrder:
subRequestFiles = oRequest.getSubRequestFiles(
ind, 'removal')['Value']
operation = subRequestAttributes['Operation']
################################################
# If the sub-request is a physical removal operation
if operation == 'physicalRemoval':
gLogger.info(
"RemovalAgent.execute: Attempting to execute %s sub-request."
% operation)
diracSEs = subRequestAttributes['TargetSE'].split(',')
physicalFiles = []
pfnToLfn = {}
for subRequestFile in subRequestFiles:
if subRequestFile['Status'] == 'Waiting':
pfn = str(subRequestFile['PFN'])
lfn = str(subRequestFile['LFN'])
pfnToLfn[pfn] = lfn
physicalFiles.append(pfn)
gMonitor.addMark('PhysicalRemovalAtt',
len(physicalFiles))
failed = {}
errMsg = {}
for diracSE in diracSEs:
res = self.replicaManager.removeStorageFile(
physicalFiles, diracSE)
if res['OK']:
for pfn in res['Value']['Failed'].keys():
if not failed.has_key(pfn):
failed[pfn] = {}
failed[pfn][diracSE] = res['Value'][
'Failed'][pfn]
else:
errMsg[diracSE] = res['Message']
for pfn in physicalFiles:
if not failed.has_key(pfn):
failed[pfn] = {}
failed[pfn][diracSE] = 'Completely'
# Now analyse the results
failedPFNs = failed.keys()
pfnsOK = [
pfn for pfn in physicalFiles
if not pfn in failedPFNs
]
gMonitor.addMark('PhysicalRemovalDone', len(pfnsOK))
for pfn in pfnsOK:
gLogger.info(
"RemovalAgent.execute: Successfully removed %s at %s"
% (pfn, str(diracSEs)))
res = oRequest.setSubRequestFileAttributeValue(
ind, 'removal', pfnToLfn[pfn], 'Status',
'Done')
if not res['OK']:
gLogger.error(
"RemovalAgent.execute: Error setting status to %s for %s"
% ('Done', pfnToLfn[pfn]))
modified = True
if failed:
gMonitor.addMark('PhysicalRemovalFail',
len(failedPFNs))
for pfn in failedPFNs:
for diracSE in failed[pfn].keys():
if type(failed[pfn]
[diracSE]) in StringTypes:
if re.search(
'no such file or directory',
failed[pfn][diracSE].lower()):
gLogger.info(
"RemovalAgent.execute: File did not exist.",
pfn)
res = oRequest.setSubRequestFileAttributeValue(
ind, 'removal', pfnToLfn[pfn],
'Status', 'Done')
if not res['OK']:
gLogger.error(
"RemovalAgent.execute: Error setting status to %s for %s"
% ('Done', pfnToLfn[pfn]))
modified = True
else:
gLogger.info(
"RemovalAgent.execute: Failed to remove file.",
"%s at %s - %s" %
(pfn, diracSE,
failed[pfn][diracSE]))
if errMsg:
for diracSE in errMsg.keys():
errStr = "RemovalAgent.execute: Completely failed to remove replicas. At %s", diracSE
gLogger.error(errStr, errMsg[diracSE])
################################################
# If the sub-request is a physical removal operation
elif operation == 'removeFile':
gLogger.info(
"RemovalAgent.execute: Attempting to execute %s sub-request."
% operation)
lfns = []
for subRequestFile in subRequestFiles:
if subRequestFile['Status'] == 'Waiting':
lfn = str(subRequestFile['LFN'])
lfns.append(lfn)
gMonitor.addMark('RemoveFileAtt', len(lfns))
res = self.replicaManager.removeFile(lfns)
if res['OK']:
gMonitor.addMark(
'RemoveFileDone',
len(res['Value']['Successful'].keys()))
for lfn in res['Value']['Successful'].keys():
gLogger.info(
"RemovalAgent.execute: Successfully removed %s."
% lfn)
result = oRequest.setSubRequestFileAttributeValue(
ind, 'removal', lfn, 'Status', 'Done')
if not result['OK']:
gLogger.error(
"RemovalAgent.execute: Error setting status to %s for %s"
% ('Done', lfn))
modified = True
gMonitor.addMark(
'RemoveFileFail',
len(res['Value']['Failed'].keys()))
for lfn in res['Value']['Failed'].keys():
if type(res['Value']['Failed']
[lfn]) in StringTypes:
if re.search(
'no such file or directory',
res['Value']['Failed']
[lfn].lower()):
gLogger.info(
"RemovalAgent.execute: File did not exist.",
lfn)
result = oRequest.setSubRequestFileAttributeValue(
ind, 'removal', lfn, 'Status',
'Done')
if not result['OK']:
gLogger.error(
"RemovalAgent.execute: Error setting status to %s for %s"
% ('Done', lfn))
modified = True
else:
gLogger.info(
"RemovalAgent.execute: Failed to remove file:",
"%s %s" %
(lfn, res['Value']['Failed'][lfn]))
else:
gMonitor.addMark('RemoveFileFail', len(lfns))
errStr = "RemovalAgent.execute: Completely failed to remove files files."
gLogger.error(errStr, res['Message'])
################################################
# If the sub-request is a physical removal operation
elif operation == 'replicaRemoval':
gLogger.info(
"RemovalAgent.execute: Attempting to execute %s sub-request."
% operation)
diracSEs = subRequestAttributes['TargetSE'].split(',')
lfns = []
for subRequestFile in subRequestFiles:
if subRequestFile['Status'] == 'Waiting':
lfn = str(subRequestFile['LFN'])
lfns.append(lfn)
gMonitor.addMark('ReplicaRemovalAtt', len(lfns))
failed = {}
errMsg = {}
for diracSE in diracSEs:
res = self.replicaManager.removeReplica(
diracSE, lfns)
if res['OK']:
for lfn in res['Value']['Failed'].keys():
errorMessage = str(
res['Value']['Failed'][lfn])
if errorMessage.find(
'Write access not permitted for this credential.'
) != -1:
if self.__getProxyAndRemoveReplica(
diracSE, lfn):
continue
if errorMessage.find(
'seconds timeout for "__gfal_wrapper" call'
) != -1:
self.timeOutCounter += 1
if not failed.has_key(lfn):
failed[lfn] = {}
failed[lfn][diracSE] = res['Value'][
'Failed'][lfn]
else:
errMsg[diracSE] = res['Message']
for lfn in lfns:
if not failed.has_key(lfn):
failed[lfn] = {}
failed[lfn][diracSE] = 'Completely'
# Now analyse the results
failedLFNs = failed.keys()
lfnsOK = [lfn for lfn in lfns if not lfn in failedLFNs]
gMonitor.addMark('ReplicaRemovalDone', len(lfnsOK))
for lfn in lfnsOK:
gLogger.info(
"RemovalAgent.execute: Successfully removed %s at %s"
% (lfn, str(diracSEs)))
res = oRequest.setSubRequestFileAttributeValue(
ind, 'removal', lfn, 'Status', 'Done')
if not res['OK']:
gLogger.error(
"RemovalAgent.execute: Error setting status to %s for %s"
% ('Done', lfn))
modified = True
if failed:
gMonitor.addMark('PhysicalRemovalFail',
len(failedLFNs))
for lfn in failedLFNs:
for diracSE in failed[lfn].keys():
if type(failed[lfn]
[diracSE]) in StringTypes:
if re.search(
'no such file or directory',
failed[lfn][diracSE].lower()):
gLogger.info(
"RemovalAgent.execute: File did not exist.",
lfn)
res = oRequest.setSubRequestFileAttributeValue(
ind, 'removal', lfn, 'Status',
'Done')
if not res['OK']:
gLogger.error(
"RemovalAgent.execute: Error setting status to %s for %s"
% ('Done', lfn))
modified = True
else:
gLogger.info(
"RemovalAgent.execute: Failed to remove file.",
"%s at %s - %s" %
(lfn, diracSE,
failed[lfn][diracSE]))
if errMsg:
for diracSE in errMsg.keys():
errStr = "RemovalAgent.execute: Completely failed to remove replicas. At %s", diracSE
gLogger.error(errStr, errMsg[diracSE])
################################################
# If the sub-request is a request to the online system to retransfer
elif operation == 'reTransfer':
gLogger.info(
"RemovalAgent.execute: Attempting to execute %s sub-request."
% operation)
diracSE = subRequestAttributes['TargetSE']
for subRequestFile in subRequestFiles:
if subRequestFile['Status'] == 'Waiting':
pfn = str(subRequestFile['PFN'])
lfn = str(subRequestFile['LFN'])
res = self.replicaManager.onlineRetransfer(
diracSE, pfn)
if res['OK']:
if res['Value']['Successful'].has_key(pfn):
gLogger.info(
"RemovalAgent.execute: Successfully requested retransfer of %s."
% pfn)
result = oRequest.setSubRequestFileAttributeValue(
ind, 'removal', lfn, 'Status',
'Done')
if not result['OK']:
gLogger.error(
"RemovalAgent.execute: Error setting status to %s for %s"
% ('Done', lfn))
modified = True
else:
errStr = "RemovalAgent.execute: Failed to request retransfer."
gLogger.error(
errStr, "%s %s %s" %
(pfn, diracSE,
res['Value']['Failed'][pfn]))
else:
errStr = "RemovalAgent.execute: Completely failed to request retransfer."
gLogger.error(errStr, res['Message'])
else:
gLogger.info(
"RemovalAgent.execute: File already completed."
)
################################################
# If the sub-request is none of the above types
else:
gLogger.error(
"RemovalAgent.execute: Operation not supported.",
operation)
################################################
# Determine whether there are any active files
if oRequest.isSubRequestEmpty(ind, 'removal')['Value']:
oRequest.setSubRequestStatus(ind, 'removal', 'Done')
gMonitor.addMark("Done", 1)
################################################
# If the sub-request is already in terminal state
else:
gLogger.info(
"RemovalAgent.execute:",
"Sub-request %s is status '%s' and not to be executed."
% (ind, subRequestAttributes['Status']))
################################################
# Generate the new request string after operation
newrequestString = oRequest.toXML()['Value']
except:
# if something fails return the original request back to the server
res = self.requestDBClient.updateRequest(requestName,
requestString,
sourceServer)
return S_OK()
res = self.requestDBClient.updateRequest(requestName, newrequestString,
sourceServer)
if modified and jobID:
result = self.finalizeRequest(requestName, jobID, sourceServer)
return S_OK()
def execute_request( self ):
""" Takes one DISET request and forward it to the destination service
"""
gMonitor.addMark( "Iteration", 1 )
if self.RequestDB:
res = self.RequestDB.getRequest( 'diset' )
else:
res = self.RequestDBClient.getRequest( 'diset' )
if not res['OK']:
gLogger.error( "DISETForwardingAgent.execute: Failed to get request from database." )
return S_OK()
elif not res['Value']:
gLogger.info( "DISETForwardingAgent.execute: No requests to be executed found." )
return S_OK()
gMonitor.addMark( "Attempted", 1 )
requestString = res['Value']['RequestString']
requestName = res['Value']['RequestName']
try:
jobID = int( res['Value']['JobID'] )
except:
jobID = 0
gLogger.info( "DISETForwardingAgent.execute: Obtained request %s" % requestName )
if self.RequestDB:
result = self.RequestDB._getRequestAttribute( 'RequestID', requestName = requestName )
if not result['OK']:
return S_OK( 'Can not get the request execution order' )
requestID = result['Value']
result = self.RequestDB.getCurrentExecutionOrder( requestID )
else:
result = self.RequestDBClient.getCurrentExecutionOrder( requestName )
if result['OK']:
currentOrder = result['Value']
else:
return S_OK( 'Can not get the request execution order' )
oRequest = RequestContainer( request = requestString )
requestAttributes = oRequest.getRequestAttributes()['Value']
################################################
# Find the number of sub-requests from the request
res = oRequest.getNumSubRequests( 'diset' )
if not res['OK']:
errStr = "DISETForwardingAgent.execute: Failed to obtain number of diset subrequests."
gLogger.error( errStr, res['Message'] )
return S_OK()
gLogger.info( "DISETForwardingAgent.execute: Found %s sub requests for job %s" % ( res['Value'], jobID ) )
################################################
# For all the sub-requests in the request
modified = False
for ind in range( res['Value'] ):
subRequestAttributes = oRequest.getSubRequestAttributes( ind, 'diset' )['Value']
subExecutionOrder = int( subRequestAttributes['ExecutionOrder'] )
subStatus = subRequestAttributes['Status']
gLogger.info( "DISETForwardingAgent.execute: Processing sub-request %s with execution order %d" % ( ind, subExecutionOrder ) )
if subStatus == 'Waiting' and subExecutionOrder <= currentOrder:
operation = subRequestAttributes['Operation']
gLogger.info( "DISETForwardingAgent.execute: Attempting to forward %s type." % operation )
rpcStubString = subRequestAttributes['Arguments']
rpcStub, length = DEncode.decode( rpcStubString )
res = executeRPCStub( rpcStub )
if res['OK']:
gLogger.info( "DISETForwardingAgent.execute: Successfully forwarded." )
oRequest.setSubRequestStatus( ind, 'diset', 'Done' )
gMonitor.addMark( "Successful", 1 )
modified = True
elif res['Message'] == 'No Matching Job':
gLogger.warn( "DISETForwardingAgent.execute: No corresponding job found. Setting to done." )
oRequest.setSubRequestStatus( ind, 'diset', 'Done' )
else:
gLogger.error( "DISETForwardingAgent.execute: Failed to forward request.", res['Message'] )
else:
gLogger.info( "DISETForwardingAgent.execute: Sub-request %s is status '%s' and not to be executed." % ( ind, subRequestAttributes['Status'] ) )
################################################
# Generate the new request string after operation
requestString = oRequest.toXML()['Value']
if self.RequestDB:
res = self.RequestDB.updateRequest( requestName, requestString )
else:
res = self.RequestDBClient.updateRequest( requestName, requestString )
if res['OK']:
gLogger.info( "DISETForwardingAgent.execute: Successfully updated request." )
else:
gLogger.error( "DISETForwardingAgent.execute: Failed to update request" )
if modified and jobID:
result = self.RequestDBClient.finalizeRequest( requestName, jobID )
return S_OK()
class RequestTask( object ):
"""
.. class:: RequestTask
Base class for DMS 'transfer', 'removal' and 'register' Requests processing.
This class is meant to be executed as a ProcessTask inside ProcessPool.
The most important and common global DIRAC objects are created in RequestTask constructor.
This includes gLogger, gConfig, gProxyManager, S_OK and S_ERROR. The constructor also
imports a set of common modules: os, sys, re, time and everything from types module.
All other DIRAC tools and clients (i.e. RequestManager) are private in RequestTask class and will
be imported and instantiated on demand during first usage. They are accessible using proxied public methods, i.e.
if you are going to use ReplicaManager just call::
self.replicaManager().someMethod()
All currently proxied tools are::
DataLoggingClient -- self.dataLoggingClient()
ReplicaManager -- self.replicaManager()
RequestClient -- self.requestClient()
StorageFactory -- self.storageFactory()
SubLogger message handles for all levels are also proxied, so you can directly use them in your code, i.e.::
self.info("An info message")
self.debug("This will be shown only in debug")
For handling sub-request one has to register their actions handlers using :self.addOperationAction:
method. This method checks if handler is defined as a method of inherited class and then puts its
definition into internal operation dispatcher dictionary with a key of sub-request's operation name.
Each operation handler should have the signature::
def operationName( self, index, requestObj, subRequestAttrs, subRequestFiles )
where index is a sub-request counter, requestObj is a RequestContainer instance,
subRequestAttrs is a dict with sub-request attributes and subRequestFiles is a dict with
files attached to the sub-request.
Handlers shoudl always return S_OK with value of (modified or not) requestObj, S_ERROR with some
error message otherwise.
Processing of request is done automatically in self.__call__, one doesn't have to worry about changing
credentials, looping over subrequests or request finalizing -- only sub-request processing matters in
the all inherited classes.
Concerning :MonitringClient: (or better known its global instance :gMonitor:), if someone wants to send
some metric over there, she has to put in agent's code registration of activity and then in a particular
task use :RequestTask.addMark: to save monitoring data. All monitored activities are held in
:RequestTask.__monitor: dict which at the end of processing is returned from :RequestTask.__call__:.
The values are then processed and pushed to the gMonitor instance in the default callback function.
"""
## reference to ReplicaManager
__replicaManager = None
## reference to DataLoggingClient
__dataLoggingClient = None
## reference to RequestClient
__requestClient = None
## reference to StotageFactory
__storageFactory = None
## subLogger
__log = None
## request type
__requestType = None
## placeholder for request owner DB
requestOwnerDN = None
## placeholder for Request owner group
requestOwnerGroup = None
## operation dispatcher for SubRequests,
## a dictonary
## "operation" => methodToRun
##
__operationDispatcher = {}
## holder for DataManager proxy file
__dataManagerProxy = None
## monitoring dict
__monitor = {}
def __init__( self, requestString, requestName, executionOrder, jobID, configPath ):
""" c'tor
:param self: self reference
:param str requestString: XML serialised RequestContainer
:param str requestName: request name
:param list executionOrder: request execution order
:param int jobID: jobID
:param str sourceServer: request's source server
:param str configPath: path in CS for parent agent
"""
## fixtures
## python fixtures
import os, os.path, sys, time, re, types
self.makeGlobal( "os", os )
self.makeGlobal( "os.path", os.path )
self.makeGlobal( "sys", sys )
self.makeGlobal( "time", time )
self.makeGlobal( "re", re )
## export all Types from types
[ self.makeGlobal( item, getattr( types, item ) ) for item in dir(types) if "Type" in item ]
## DIRAC fixtures
from DIRAC.FrameworkSystem.Client.Logger import gLogger
self.__log = gLogger.getSubLogger( "%s/%s" % ( self.__class__.__name__, str(requestName) ) )
self.always = self.__log.always
self.notice = self.__log.notice
self.info = self.__log.info
self.debug = self.__log.debug
self.warn = self.__log.warn
self.error = self.__log.error
self.exception = self.__log.exception
self.fatal = self.__log.fatal
from DIRAC import S_OK, S_ERROR
from DIRAC.ConfigurationSystem.Client.Config import gConfig
from DIRAC.FrameworkSystem.Client.ProxyManagerClient import gProxyManager
from DIRAC.ConfigurationSystem.Client.Helpers.Registry import getGroupsWithVOMSAttribute
from DIRAC.ConfigurationSystem.Client.ConfigurationData import gConfigurationData
## export DIRAC global tools and functions
self.makeGlobal( "S_OK", S_OK )
self.makeGlobal( "S_ERROR", S_ERROR )
self.makeGlobal( "gLogger", gLogger )
self.makeGlobal( "gConfig", gConfig )
self.makeGlobal( "gProxyManager", gProxyManager )
self.makeGlobal( "getGroupsWithVOMSAttribute", getGroupsWithVOMSAttribute )
self.makeGlobal( "gConfigurationData", gConfigurationData )
## save request string
self.requestString = requestString
## build request object
from DIRAC.RequestManagementSystem.Client.RequestContainer import RequestContainer
self.requestObj = RequestContainer( init = False )
self.requestObj.parseRequest( request = self.requestString )
## save request name
self.requestName = requestName
## .. and jobID
self.jobID = jobID
## .. and execution order
self.executionOrder = executionOrder
## save config path
self.__configPath = configPath
## set requestType
self.setRequestType( gConfig.getValue( os.path.join( configPath, "RequestType" ), "" ) )
## get log level
self.__log.setLevel( gConfig.getValue( os.path.join( configPath, self.__class__.__name__, "LogLevel" ), "INFO" ) )
## clear monitoring
self.__monitor = {}
## save DataManager proxy
if "X509_USER_PROXY" in os.environ:
self.info("saving path to current proxy file")
self.__dataManagerProxy = os.environ["X509_USER_PROXY"]
else:
self.error("'X509_USER_PROXY' environment variable not set")
def dataManagerProxy( self ):
""" get dataManagerProxy file
:param self: self reference
"""
return self.__dataManagerProxy
def addMark( self, name, value = 1 ):
""" add mark to __monitor dict
:param self: self reference
:param name: mark name
:param value: value to be
"""
if name not in self.__monitor:
self.__monitor.setdefault( name, 0 )
self.__monitor[name] += value
def monitor( self ):
""" get monitoring dict
:param cls: class reference
"""
return self.__monitor
def makeGlobal( self, objName, objDef ):
""" export :objDef: to global name space using :objName: name
:param self: self reference
:param str objName: symbol name
:param mixed objDef: symbol definition
:throws: NameError if symbol of that name is already in
"""
if objName not in __builtins__:
if type( __builtins__) == type( {} ):
__builtins__[objName] = objDef
else:
setattr( __builtins__, objName, objDef )
return True
def requestType( self ):
""" get request type
:params self: self reference
"""
return self.__requestType
def setRequestType( self, requestType ):
""" set request type
:param self: self reference
"""
self.debug( "Setting requestType to %s" % str(requestType) )
self.__requestType = requestType
@classmethod
def replicaManager( cls ):
""" ReplicaManager getter
:param cls: class reference
"""
if not cls.__replicaManager:
from DIRAC.DataManagementSystem.Client.ReplicaManager import ReplicaManager
cls.__replicaManager = ReplicaManager()
return cls.__replicaManager
@classmethod
def dataLoggingClient( cls ):
""" DataLoggingClient getter
:param cls: class reference
"""
if not cls.__dataLoggingClient:
from DIRAC.DataManagementSystem.Client.DataLoggingClient import DataLoggingClient
cls.__dataLoggingClient = DataLoggingClient()
return cls.__dataLoggingClient
@classmethod
def requestClient( cls ):
""" RequestClient getter
:param cls: class reference
"""
if not cls.__requestClient:
from DIRAC.Core.DISET.RPCClient import RPCClient
from DIRAC.RequestManagementSystem.Client.RequestClient import RequestClient
cls.__requestClient = RequestClient()
return cls.__requestClient
@classmethod
def storageFactory( cls ):
""" StorageFactory getter
:param cls: class reference
"""
if not cls.__storageFactory:
from DIRAC.Resources.Storage.StorageFactory import StorageFactory
cls.__storageFactory = StorageFactory()
return cls.__storageFactory
def changeProxy( self, ownerDN, ownerGroup ):
""" get proxy from gProxyManager, save it to file
:param self: self reference
:param str ownerDN: request owner DN
:param str ownerGroup: request owner group
:return: S_OK with name of newly created owner proxy file
"""
ownerProxy = gProxyManager.downloadVOMSProxy( str(ownerDN), str(ownerGroup) )
if not ownerProxy["OK"] or not ownerProxy["Value"]:
reason = ownerProxy["Message"] if "Message" in ownerProxy else "No valid proxy found in ProxyManager."
return S_ERROR( "Change proxy error for '%s'@'%s': %s" % ( ownerDN, ownerGroup, reason ) )
ownerProxyFile = ownerProxy["Value"].dumpAllToFile()
if not ownerProxyFile["OK"]:
return S_ERROR( ownerProxyFile["Message"] )
ownerProxyFile = ownerProxyFile["Value"]
os.environ["X509_USER_PROXY"] = ownerProxyFile
return S_OK( ownerProxyFile )
######################################################################
# operationDispatcher
@classmethod
def operationDispatcher( cls ):
""" operation dispatcher getter
:param cls: class reference
"""
return cls.__operationDispatcher
@classmethod
def addOperationAction( cls, operation, methodToRun, overwrite = True ):
""" register handler :methodToRun: for SubRequest operation :operation:
:warn: all handlers should have the same signature
:param self: self reference
:param str operation: SubRequest operation name
:param MethodType methodToRun: handler to be executed for SubRequest
:param bool overwrite: flag to overwrite handler, if already present
:return: S_OK/S_ERROR
Every action handler should return S_OK with of a structure::
{ "OK" : True,
"Value" : requestObj # that has been sent to operation handler
}
otherwise S_ERROR.
"""
if operation in cls.__operationDispatcher and not overwrite:
return S_ERROR("addOperationAction: operation for '%s' is already registered" % operation )
if type(methodToRun) is not MethodType:
return S_ERROR("addOperationAction: wrong type (%s = types.MethodType) for '%s' operation" % \
( str(type(methodToRun)), operation ) )
cls.__operationDispatcher[operation] = methodToRun
return S_OK()
def __call__( self ):
""" generic function to process one Request of a type requestType
This method could be run in a thread.
:param self: self reference
:param str requestType: request type
:return: S_OK/S_ERROR
"""
self.always("executing request %s" % self.requestName )
################################################################
## get ownerDN and ownerGroup
ownerDN = self.requestObj.getAttribute( "OwnerDN" )
if not ownerDN["OK"]:
return ownerDN
ownerDN = ownerDN["Value"]
ownerGroup = self.requestObj.getAttribute( "OwnerGroup" )
if not ownerGroup["OK"]:
return ownerGroup
ownerGroup = ownerGroup["Value"]
## save request owner
self.requestOwnerDN = ownerDN if ownerDN else ""
self.requestOwnerGroup = ownerGroup if ownerGroup else ""
#################################################################
## change proxy
ownerProxyFile = None
if ownerDN and ownerGroup:
ownerProxyFile = self.changeProxy( ownerDN, ownerGroup )
if not ownerProxyFile["OK"]:
self.error( "handleReuqest: unable to get proxy for '%s'@'%s': %s" % ( ownerDN,
ownerGroup,
ownerProxyFile["Message"] ) )
update = self.putBackRequest( self.requestName, self.requestString )
if not update["OK"]:
self.error( "handleRequest: error when updating request: %s" % update["Message"] )
return update
return ownerProxyFile
ownerProxyFile = ownerProxyFile["Value"]
#self.ownerProxyFile = ownerProxyFile
self.info( "Will execute request for '%s'@'%s' using proxy file %s" % ( ownerDN, ownerGroup, ownerProxyFile ) )
else:
self.info( "Will execute request for DataManager using her/his proxy")
#################################################################
## execute handlers
ret = { "OK" : False, "Message" : "" }
useServerCert = gConfig.useServerCertificate()
try:
# Execute task with the owner proxy even for contacting DIRAC services
if useServerCert:
gConfigurationData.setOptionInCFG('/DIRAC/Security/UseServerCertificate','false')
ret = self.handleRequest()
finally:
if useServerCert:
gConfigurationData.setOptionInCFG('/DIRAC/Security/UseServerCertificate','true')
## delete owner proxy
if self.__dataManagerProxy:
os.environ["X509_USER_PROXY"] = self.__dataManagerProxy
if ownerProxyFile and os.path.exists( ownerProxyFile ):
os.unlink( ownerProxyFile )
if not ret["OK"]:
self.error( "handleRequest: error during request processing: %s" % ret["Message"] )
self.error( "handleRequest: will put original request back" )
update = self.putBackRequest( self.requestName, self.requestString )
if not update["OK"]:
self.error( "handleRequest: error when putting back request: %s" % update["Message"] )
## return at least
return ret
def handleRequest( self ):
""" read SubRequests and ExecutionOrder, fire registered handlers upon SubRequests operations
:param self: self reference
:param dict requestDict: request dictionary as read from self.readRequest
"""
##############################################################
# here comes the processing
##############################################################
res = self.requestObj.getNumSubRequests( self.__requestType )
if not res["OK"]:
errMsg = "handleRequest: failed to obtain number of '%s' subrequests." % self.__requestType
self.error( errMsg, res["Message"] )
return S_ERROR( res["Message"] )
## for gMonitor
self.addMark( "Execute", 1 )
## process sub requests
for index in range( res["Value"] ):
self.info( "handleRequest: processing subrequest %s." % str(index) )
subRequestAttrs = self.requestObj.getSubRequestAttributes( index, self.__requestType )["Value"]
if subRequestAttrs["ExecutionOrder"]:
subExecutionOrder = int( subRequestAttrs["ExecutionOrder"] )
else:
subExecutionOrder = 0
subRequestStatus = subRequestAttrs["Status"]
if subRequestStatus != "Waiting":
self.info( "handleRequest: subrequest %s has status '%s' and is not to be executed." % ( str(index),
subRequestStatus ) )
continue
if subExecutionOrder <= self.executionOrder:
operation = subRequestAttrs["Operation"]
if operation not in self.operationDispatcher():
self.error( "handleRequest: '%s' operation not supported" % operation )
else:
self.info( "handleRequest: will execute %s '%s' subrequest" % ( str(index), operation ) )
## get files
subRequestFiles = self.requestObj.getSubRequestFiles( index, self.__requestType )["Value"]
## execute operation action
ret = self.operationDispatcher()[operation].__call__( index,
self.requestObj,
subRequestAttrs,
subRequestFiles )
################################################
## error in operation action?
if not ret["OK"]:
self.error( "handleRequest: error when handling subrequest %s: %s" % ( str(index), ret["Message"] ) )
self.requestObj.setSubRequestAttributeValue( index, self.__requestType, "Error", ret["Message"] )
else:
## update ref to requestObj
self.requestObj = ret["Value"]
## check if subrequest status == Done, disable finalisation if not
subRequestDone = self.requestObj.isSubRequestDone( index, self.__requestType )
if not subRequestDone["OK"]:
self.error( "handleRequest: unable to determine subrequest status: %s" % subRequestDone["Message"] )
else:
if not subRequestDone["Value"]:
self.warn("handleRequest: subrequest %s is not done yet" % str(index) )
################################################
# Generate the new request string after operation
newRequestString = self.requestObj.toXML()['Value']
update = self.putBackRequest( self.requestName, newRequestString )
if not update["OK"]:
self.error( "handleRequest: error when updating request: %s" % update["Message"] )
return update
## get request status
if self.jobID:
requestStatus = self.requestClient().getRequestStatus( self.requestName )
if not requestStatus["OK"]:
return requestStatus
requestStatus = requestStatus["Value"]
## finalize request if jobID is present and request status = 'Done'
self.info("handleRequest: request status is %s" % requestStatus )
if ( requestStatus["RequestStatus"] == "Done" ) and ( requestStatus["SubRequestStatus"] not in ( "Waiting", "Assigned" ) ):
self.debug("handleRequest: request is going to be finalised")
finalize = self.requestClient().finalizeRequest( self.requestName, self.jobID )
if not finalize["OK"]:
self.error("handleRequest: error in request finalization: %s" % finalize["Message"] )
return finalize
self.info("handleRequest: request is finalised")
## for gMonitor
self.addMark( "Done", 1 )
## should return S_OK with monitor dict
return S_OK( { "monitor" : self.monitor() } )
def putBackRequest( self, requestName, requestString ):
""" put request back
:param self: self reference
:param str requestName: request name
:param str requestString: XML-serilised request
:param str sourceServer: request server URL
"""
update = self.requestClient().updateRequest( requestName, requestString )
if not update["OK"]:
self.error( "putBackRequest: error when updating request: %s" % update["Message"] )
return update
return S_OK()
def execute( self ):
IntegrityDB = RPCClient( 'DataManagement/DataIntegrity' )
res = self.RequestDBClient.getRequest( 'integrity' )
if not res['OK']:
gLogger.info( "SEvsLFCAgent.execute: Failed to get request from database." )
return S_OK()
elif not res['Value']:
gLogger.info( "SEvsLFCAgent.execute: No requests to be executed found." )
return S_OK()
requestString = res['Value']['requestString']
requestName = res['Value']['requestName']
sourceServer = res['Value']['Server']
gLogger.info( "SEvsLFCAgent.execute: Obtained request %s" % requestName )
oRequest = RequestContainer( request = requestString )
################################################
# Find the number of sub-requests from the request
res = oRequest.getNumSubRequests( 'integrity' )
if not res['OK']:
errStr = "SEvsLFCAgent.execute: Failed to obtain number of integrity subrequests."
gLogger.error( errStr, res['Message'] )
return S_OK()
gLogger.info( "SEvsLFCAgent.execute: Found %s sub requests." % res['Value'] )
################################################
# For all the sub-requests in the request
for ind in range( res['Value'] ):
gLogger.info( "SEvsLFCAgent.execute: Processing sub-request %s." % ind )
subRequestAttributes = oRequest.getSubRequestAttributes( ind, 'integrity' )['Value']
if subRequestAttributes['Status'] == 'Waiting':
subRequestFiles = oRequest.getSubRequestFiles( ind, 'integrity' )['Value']
operation = subRequestAttributes['Operation']
################################################
# If the sub-request is a lfcvsse operation
if operation == 'SEvsLFC':
gLogger.info( "SEvsLFCAgent.execute: Attempting to execute %s sub-request." % operation )
storageElementName = subRequestAttributes['StorageElement']
for subRequestFile in subRequestFiles:
if subRequestFile['Status'] == 'Waiting':
lfn = subRequestFile['LFN']
storageElement = StorageElement( storageElementName )
res = storageElement.isValid()
if not res['OK']:
errStr = "SEvsLFCAgent.execute: Failed to instantiate destination StorageElement."
gLogger.error( errStr, storageElement )
else:
res = storageElement.getPfnForLfn( lfn )
if not res['OK']:
gLogger.info( 'shit bugger do something.' )
else:
oNamespaceBrowser = NamespaceBrowser( res['Value'] )
# Loop over all the directories and sub-directories
while ( oNamespaceBrowser.isActive() ):
currentDir = oNamespaceBrowser.getActiveDir()
gLogger.info( "SEvsLFCAgent.execute: Attempting to list the contents of %s." % currentDir )
res = storageElement.listDirectory( currentDir )
if not res['Value']['Successful'].has_key( currentDir ):
gLogger.error( "SEvsLFCAgent.execute: Failed to list the directory contents.", "%s %s" % ( currentDir, res['Value']['Successful']['Failed'][currentDir] ) )
subDirs = [currentDir]
else:
subDirs = []
files = {}
for surl, surlDict in res['Value']['Successful'][currentDir]['Files'].items():
pfnRes = storageElement.getPfnForProtocol( surl, 'SRM2', withPort = False )
surl = pfnRes['Value']
files[surl] = surlDict
for surl, surlDict in res['Value']['Successful'][currentDir]['SubDirs'].items():
pfnRes = storageElement.getPfnForProtocol( surl, 'SRM2', withPort = False )
surl = pfnRes['Value']
subDirs.append( surl )
#subDirs = res['Value']['Successful'][currentDir]['SubDirs']
gLogger.info( "SEvsLFCAgent.execute: Successfully obtained %s sub-directories." % len( subDirs ) )
#files = res['Value']['Successful'][currentDir]['Files']
gLogger.info( "SEvsLFCAgent.execute: Successfully obtained %s files." % len( files ) )
selectedLfns = []
lfnPfnDict = {}
pfnSize = {}
for pfn, pfnDict in files.items():
res = storageElement.getPfnPath( pfn )
if not res['OK']:
gLogger.error( "SEvsLFCAgent.execute: Failed to get determine LFN from pfn.", "%s %s" % ( pfn, res['Message'] ) )
fileMetadata = {'Prognosis':'NonConventionPfn', 'LFN':'', 'PFN':pfn, 'StorageElement':storageElementName, 'Size':pfnDict['Size']}
res = IntegrityDB.insertProblematic( AGENT_NAME, fileMetadata )
if res['OK']:
gLogger.info( "SEvsLFCAgent.execute: Successfully added to IntegrityDB." )
gLogger.error( "Change the status in the LFC,ProcDB...." )
else:
gLogger.error( "Shit, f**k, bugger. Add the failover." )
else:
lfn = res['Value']
selectedLfns.append( lfn )
lfnPfnDict[lfn] = pfn
pfnSize[pfn] = pfnDict['Size']
res = self.ReplicaManager.getCatalogFileMetadata( selectedLfns )
if not res['OK']:
subDirs = [currentDir]
else:
for lfn in res['Value']['Failed'].keys():
gLogger.error( "SEvsLFCAgent.execute: Failed to get metadata.", "%s %s" % ( lfn, res['Value']['Failed'][lfn] ) )
pfn = lfnPfnDict[lfn]
fileMetadata = {'Prognosis':'SEPfnNoLfn', 'LFN':lfn, 'PFN':pfn, 'StorageElement':storageElementName, 'Size':pfnSize[pfn]}
res = IntegrityDB.insertProblematic( AGENT_NAME, fileMetadata )
if res['OK']:
gLogger.info( "SEvsLFCAgent.execute: Successfully added to IntegrityDB." )
gLogger.error( "Change the status in the LFC,ProcDB...." )
else:
gLogger.error( "Shit, f**k, bugger. Add the failover." )
for lfn, lfnDict in res['Value']['Successful'].items():
pfn = lfnPfnDict[lfn]
storageSize = pfnSize[pfn]
catalogSize = lfnDict['Size']
if int( catalogSize ) == int( storageSize ):
gLogger.info( "SEvsLFCAgent.execute: Catalog and storage sizes match.", "%s %s" % ( pfn, storageElementName ) )
gLogger.info( "Change the status in the LFC" )
elif int( storageSize ) == 0:
gLogger.error( "SEvsLFCAgent.execute: Physical file size is 0.", "%s %s" % ( pfn, storageElementName ) )
fileMetadata = {'Prognosis':'ZeroSizePfn', 'LFN':lfn, 'PFN':pfn, 'StorageElement':storageElementName}
res = IntegrityDB.insertProblematic( AGENT_NAME, fileMetadata )
if res['OK']:
gLogger.info( "SEvsLFCAgent.execute: Successfully added to IntegrityDB." )
gLogger.error( "Change the status in the LFC,ProcDB...." )
else:
gLogger.error( "Shit, f**k, bugger. Add the failover." )
else:
gLogger.error( "SEvsLFCAgent.execute: Catalog and storage size mis-match.", "%s %s" % ( pfn, storageElementName ) )
fileMetadata = {'Prognosis':'PfnSizeMismatch', 'LFN':lfn, 'PFN':pfn, 'StorageElement':storageElementName}
res = IntegrityDB.insertProblematic( AGENT_NAME, fileMetadata )
if res['OK']:
gLogger.info( "SEvsLFCAgent.execute: Successfully added to IntegrityDB." )
gLogger.error( "Change the status in the LFC,ProcDB...." )
else:
gLogger.error( "Shit, f**k, bugger. Add the failover." )
res = self.ReplicaManager.getCatalogReplicas( selectedLfns )
if not res['OK']:
subDirs = [currentDir]
else:
for lfn in res['Value']['Failed'].keys():
gLogger.error( "SEvsLFCAgent.execute: Failed to get replica information.", "%s %s" % ( lfn, res['Value']['Failed'][lfn] ) )
pfn = lfnPfnDict[lfn]
fileMetadata = {'Prognosis':'PfnNoReplica', 'LFN':lfn, 'PFN':pfn, 'StorageElement':storageElementName, 'Size':pfnSize[pfn]}
res = IntegrityDB.insertProblematic( AGENT_NAME, fileMetadata )
if res['OK']:
gLogger.info( "SEvsLFCAgent.execute: Successfully added to IntegrityDB." )
gLogger.error( "Change the status in the LFC,ProcDB...." )
else:
gLogger.error( "Shit, f**k, bugger. Add the failover." )
for lfn, repDict in res['Value']['Successful'].items():
pfn = lfnPfnDict[lfn]
registeredPfns = repDict.values()
if not pfn in registeredPfns:
gLogger.error( "SEvsLFCAgent.execute: SE PFN not registered.", "%s %s" % ( lfn, pfn ) )
fileMetadata = {'Prognosis':'PfnNoReplica', 'LFN':lfn, 'PFN':pfn, 'StorageElement':storageElementName}
res = IntegrityDB.insertProblematic( AGENT_NAME, fileMetadata )
if res['OK']:
gLogger.info( "SEvsLFCAgent.execute: Successfully added to IntegrityDB." )
gLogger.error( "Change the status in the LFC,ProcDB...." )
else:
gLogger.error( "Shit, f**k, bugger. Add the failover." )
else:
gLogger.info( "SEvsLFCAgent.execute: SE Pfn verified.", pfn )
oNamespaceBrowser.updateDirs( subDirs )
oRequest.setSubRequestFileAttributeValue( ind, 'integrity', lfn, 'Status', 'Done' )
################################################
# If the sub-request is none of the above types
else:
gLogger.info( "SEvsLFCAgent.execute: Operation not supported.", operation )
################################################
# Determine whether there are any active files
if oRequest.isSubRequestEmpty( ind, 'integrity' )['Value']:
oRequest.setSubRequestStatus( ind, 'integrity', 'Done' )
################################################
# If the sub-request is already in terminal state
else:
gLogger.info( "SEvsLFCAgent.execute: Sub-request %s is status '%s' and not to be executed." % ( ind, subRequestAttributes['Status'] ) )
################################################
# Generate the new request string after operation
requestString = oRequest.toXML()['Value']
res = self.RequestDBClient.updateRequest( requestName, requestString, sourceServer )
return S_OK()
def execute_request(self):
""" Takes one DISET request and forward it to the destination service
"""
gMonitor.addMark("Iteration", 1)
if self.RequestDB:
res = self.RequestDB.getRequest('diset')
else:
res = self.RequestDBClient.getRequest('diset', url=self.local)
if not res['OK']:
gLogger.error(
"DISETForwardingAgent.execute: Failed to get request from database.",
self.local)
return S_OK()
elif not res['Value']:
gLogger.info(
"DISETForwardingAgent.execute: No requests to be executed found."
)
return S_OK()
gMonitor.addMark("Attempted", 1)
requestString = res['Value']['RequestString']
requestName = res['Value']['RequestName']
try:
jobID = int(res['Value']['JobID'])
except:
jobID = 0
gLogger.info("DISETForwardingAgent.execute: Obtained request %s" %
requestName)
if self.RequestDB:
result = self.RequestDB._getRequestAttribute(
'RequestID', requestName=requestName)
if not result['OK']:
return S_OK('Can not get the request execution order')
requestID = result['Value']
result = self.RequestDB.getCurrentExecutionOrder(requestID)
else:
result = self.RequestDBClient.getCurrentExecutionOrder(
requestName, self.local)
if result['OK']:
currentOrder = result['Value']
else:
return S_OK('Can not get the request execution order')
oRequest = RequestContainer(request=requestString)
requestAttributes = oRequest.getRequestAttributes()['Value']
################################################
# Find the number of sub-requests from the request
res = oRequest.getNumSubRequests('diset')
if not res['OK']:
errStr = "DISETForwardingAgent.execute: Failed to obtain number of diset subrequests."
gLogger.error(errStr, res['Message'])
return S_OK()
gLogger.info(
"DISETForwardingAgent.execute: Found %s sub requests for job %s" %
(res['Value'], jobID))
################################################
# For all the sub-requests in the request
modified = False
for ind in range(res['Value']):
subRequestAttributes = oRequest.getSubRequestAttributes(
ind, 'diset')['Value']
subExecutionOrder = int(subRequestAttributes['ExecutionOrder'])
subStatus = subRequestAttributes['Status']
gLogger.info(
"DISETForwardingAgent.execute: Processing sub-request %s with execution order %d"
% (ind, subExecutionOrder))
if subStatus == 'Waiting' and subExecutionOrder <= currentOrder:
operation = subRequestAttributes['Operation']
gLogger.info(
"DISETForwardingAgent.execute: Attempting to forward %s type."
% operation)
rpcStubString = subRequestAttributes['Arguments']
rpcStub, length = DEncode.decode(rpcStubString)
res = executeRPCStub(rpcStub)
if res['OK']:
gLogger.info(
"DISETForwardingAgent.execute: Successfully forwarded."
)
oRequest.setSubRequestStatus(ind, 'diset', 'Done')
gMonitor.addMark("Successful", 1)
modified = True
elif res['Message'] == 'No Matching Job':
gLogger.warn(
"DISETForwardingAgent.execute: No corresponding job found. Setting to done."
)
oRequest.setSubRequestStatus(ind, 'diset', 'Done')
else:
gLogger.error(
"DISETForwardingAgent.execute: Failed to forward request.",
res['Message'])
else:
gLogger.info(
"DISETForwardingAgent.execute: Sub-request %s is status '%s' and not to be executed."
% (ind, subRequestAttributes['Status']))
################################################
# Generate the new request string after operation
requestString = oRequest.toXML()['Value']
if self.RequestDB:
res = self.RequestDB.updateRequest(requestName, requestString)
else:
res = self.RequestDBClient.updateRequest(requestName,
requestString, self.local)
if res['OK']:
gLogger.info(
"DISETForwardingAgent.execute: Successfully updated request.")
else:
gLogger.error(
"DISETForwardingAgent.execute: Failed to update request to",
self.local)
if modified and jobID:
result = self.RequestDBClient.finalizeRequest(
requestName, jobID, self.local)
return S_OK()
def execute(self):
IntegrityDB = RPCClient('DataManagement/DataIntegrity')
res = self.RequestDBClient.getRequest('integrity')
if not res['OK']:
gLogger.info(
"SEvsLFCAgent.execute: Failed to get request from database.")
return S_OK()
elif not res['Value']:
gLogger.info(
"SEvsLFCAgent.execute: No requests to be executed found.")
return S_OK()
requestString = res['Value']['requestString']
requestName = res['Value']['requestName']
sourceServer = res['Value']['Server']
gLogger.info("SEvsLFCAgent.execute: Obtained request %s" % requestName)
oRequest = RequestContainer(request=requestString)
################################################
# Find the number of sub-requests from the request
res = oRequest.getNumSubRequests('integrity')
if not res['OK']:
errStr = "SEvsLFCAgent.execute: Failed to obtain number of integrity subrequests."
gLogger.error(errStr, res['Message'])
return S_OK()
gLogger.info("SEvsLFCAgent.execute: Found %s sub requests." %
res['Value'])
################################################
# For all the sub-requests in the request
for ind in range(res['Value']):
gLogger.info("SEvsLFCAgent.execute: Processing sub-request %s." %
ind)
subRequestAttributes = oRequest.getSubRequestAttributes(
ind, 'integrity')['Value']
if subRequestAttributes['Status'] == 'Waiting':
subRequestFiles = oRequest.getSubRequestFiles(
ind, 'integrity')['Value']
operation = subRequestAttributes['Operation']
################################################
# If the sub-request is a lfcvsse operation
if operation == 'SEvsLFC':
gLogger.info(
"SEvsLFCAgent.execute: Attempting to execute %s sub-request."
% operation)
storageElementName = subRequestAttributes['StorageElement']
for subRequestFile in subRequestFiles:
if subRequestFile['Status'] == 'Waiting':
lfn = subRequestFile['LFN']
storageElement = StorageElement(storageElementName)
res = storageElement.isValid()
if not res['OK']:
errStr = "SEvsLFCAgent.execute: Failed to instantiate destination StorageElement."
gLogger.error(errStr, storageElement)
else:
res = storageElement.getPfnForLfn(lfn)
if not res['OK']:
gLogger.info('shit bugger do something.')
else:
oNamespaceBrowser = NamespaceBrowser(
res['Value'])
# Loop over all the directories and sub-directories
while (oNamespaceBrowser.isActive()):
currentDir = oNamespaceBrowser.getActiveDir(
)
gLogger.info(
"SEvsLFCAgent.execute: Attempting to list the contents of %s."
% currentDir)
res = storageElement.listDirectory(
currentDir)
if not res['Value'][
'Successful'].has_key(
currentDir):
gLogger.error(
"SEvsLFCAgent.execute: Failed to list the directory contents.",
"%s %s" %
(currentDir,
res['Value']['Successful']
['Failed'][currentDir]))
subDirs = [currentDir]
else:
subDirs = []
files = {}
for surl, surlDict in res['Value'][
'Successful'][currentDir][
'Files'].items():
pfnRes = storageElement.getPfnForProtocol(
surl,
'SRM2',
withPort=False)
surl = pfnRes['Value']
files[surl] = surlDict
for surl, surlDict in res['Value'][
'Successful'][currentDir][
'SubDirs'].items():
pfnRes = storageElement.getPfnForProtocol(
surl,
'SRM2',
withPort=False)
surl = pfnRes['Value']
subDirs.append(surl)
#subDirs = res['Value']['Successful'][currentDir]['SubDirs']
gLogger.info(
"SEvsLFCAgent.execute: Successfully obtained %s sub-directories."
% len(subDirs))
#files = res['Value']['Successful'][currentDir]['Files']
gLogger.info(
"SEvsLFCAgent.execute: Successfully obtained %s files."
% len(files))
selectedLfns = []
lfnPfnDict = {}
pfnSize = {}
for pfn, pfnDict in files.items():
res = storageElement.getPfnPath(
pfn)
if not res['OK']:
gLogger.error(
"SEvsLFCAgent.execute: Failed to get determine LFN from pfn.",
"%s %s" %
(pfn, res['Message']))
fileMetadata = {
'Prognosis':
'NonConventionPfn',
'LFN': '',
'PFN': pfn,
'StorageElement':
storageElementName,
'Size': pfnDict['Size']
}
res = IntegrityDB.insertProblematic(
AGENT_NAME,
fileMetadata)
if res['OK']:
gLogger.info(
"SEvsLFCAgent.execute: Successfully added to IntegrityDB."
)
gLogger.error(
"Change the status in the LFC,ProcDB...."
)
else:
gLogger.error(
"Shit, f**k, bugger. Add the failover."
)
else:
lfn = res['Value']
selectedLfns.append(lfn)
lfnPfnDict[lfn] = pfn
pfnSize[pfn] = pfnDict[
'Size']
res = self.ReplicaManager.getCatalogFileMetadata(
selectedLfns)
if not res['OK']:
subDirs = [currentDir]
else:
for lfn in res['Value'][
'Failed'].keys():
gLogger.error(
"SEvsLFCAgent.execute: Failed to get metadata.",
"%s %s" %
(lfn, res['Value']
['Failed'][lfn]))
pfn = lfnPfnDict[lfn]
fileMetadata = {
'Prognosis':
'SEPfnNoLfn',
'LFN': lfn,
'PFN': pfn,
'StorageElement':
storageElementName,
'Size': pfnSize[pfn]
}
res = IntegrityDB.insertProblematic(
AGENT_NAME,
fileMetadata)
if res['OK']:
gLogger.info(
"SEvsLFCAgent.execute: Successfully added to IntegrityDB."
)
gLogger.error(
"Change the status in the LFC,ProcDB...."
)
else:
gLogger.error(
"Shit, f**k, bugger. Add the failover."
)
for lfn, lfnDict in res[
'Value'][
'Successful'].items(
):
pfn = lfnPfnDict[lfn]
storageSize = pfnSize[pfn]
catalogSize = lfnDict[
'Size']
if int(catalogSize) == int(
storageSize):
gLogger.info(
"SEvsLFCAgent.execute: Catalog and storage sizes match.",
"%s %s" %
(pfn,
storageElementName
))
gLogger.info(
"Change the status in the LFC"
)
elif int(storageSize) == 0:
gLogger.error(
"SEvsLFCAgent.execute: Physical file size is 0.",
"%s %s" %
(pfn,
storageElementName
))
fileMetadata = {
'Prognosis':
'ZeroSizePfn',
'LFN':
lfn,
'PFN':
pfn,
'StorageElement':
storageElementName
}
res = IntegrityDB.insertProblematic(
AGENT_NAME,
fileMetadata)
if res['OK']:
gLogger.info(
"SEvsLFCAgent.execute: Successfully added to IntegrityDB."
)
gLogger.error(
"Change the status in the LFC,ProcDB...."
)
else:
gLogger.error(
"Shit, f**k, bugger. Add the failover."
)
else:
gLogger.error(
"SEvsLFCAgent.execute: Catalog and storage size mis-match.",
"%s %s" %
(pfn,
storageElementName
))
fileMetadata = {
'Prognosis':
'PfnSizeMismatch',
'LFN':
lfn,
'PFN':
pfn,
'StorageElement':
storageElementName
}
res = IntegrityDB.insertProblematic(
AGENT_NAME,
fileMetadata)
if res['OK']:
gLogger.info(
"SEvsLFCAgent.execute: Successfully added to IntegrityDB."
)
gLogger.error(
"Change the status in the LFC,ProcDB...."
)
else:
gLogger.error(
"Shit, f**k, bugger. Add the failover."
)
res = self.ReplicaManager.getCatalogReplicas(
selectedLfns)
if not res['OK']:
subDirs = [currentDir]
else:
for lfn in res['Value'][
'Failed'].keys():
gLogger.error(
"SEvsLFCAgent.execute: Failed to get replica information.",
"%s %s" %
(lfn, res['Value']
['Failed'][lfn]))
pfn = lfnPfnDict[lfn]
fileMetadata = {
'Prognosis':
'PfnNoReplica',
'LFN': lfn,
'PFN': pfn,
'StorageElement':
storageElementName,
'Size':
pfnSize[pfn]
}
res = IntegrityDB.insertProblematic(
AGENT_NAME,
fileMetadata)
if res['OK']:
gLogger.info(
"SEvsLFCAgent.execute: Successfully added to IntegrityDB."
)
gLogger.error(
"Change the status in the LFC,ProcDB...."
)
else:
gLogger.error(
"Shit, f**k, bugger. Add the failover."
)
for lfn, repDict in res[
'Value'][
'Successful'].items(
):
pfn = lfnPfnDict[lfn]
registeredPfns = repDict.values(
)
if not pfn in registeredPfns:
gLogger.error(
"SEvsLFCAgent.execute: SE PFN not registered.",
"%s %s" %
(lfn, pfn))
fileMetadata = {
'Prognosis':
'PfnNoReplica',
'LFN':
lfn,
'PFN':
pfn,
'StorageElement':
storageElementName
}
res = IntegrityDB.insertProblematic(
AGENT_NAME,
fileMetadata)
if res['OK']:
gLogger.info(
"SEvsLFCAgent.execute: Successfully added to IntegrityDB."
)
gLogger.error(
"Change the status in the LFC,ProcDB...."
)
else:
gLogger.error(
"Shit, f**k, bugger. Add the failover."
)
else:
gLogger.info(
"SEvsLFCAgent.execute: SE Pfn verified.",
pfn)
oNamespaceBrowser.updateDirs(subDirs)
oRequest.setSubRequestFileAttributeValue(
ind, 'integrity', lfn, 'Status',
'Done')
################################################
# If the sub-request is none of the above types
else:
gLogger.info(
"SEvsLFCAgent.execute: Operation not supported.",
operation)
################################################
# Determine whether there are any active files
if oRequest.isSubRequestEmpty(ind, 'integrity')['Value']:
oRequest.setSubRequestStatus(ind, 'integrity', 'Done')
################################################
# If the sub-request is already in terminal state
else:
gLogger.info(
"SEvsLFCAgent.execute: Sub-request %s is status '%s' and not to be executed."
% (ind, subRequestAttributes['Status']))
################################################
# Generate the new request string after operation
requestString = oRequest.toXML()['Value']
res = self.RequestDBClient.updateRequest(requestName, requestString,
sourceServer)
return S_OK()
def executeRequest( self ):
################################################
# Get a request from request DB
res = self.RequestDBClient.getRequest( 'register' )
if not res['OK']:
gLogger.info( "RegistrationAgent.execute: Failed to get request from database." )
return S_OK()
elif not res['Value']:
gLogger.info( "RegistrationAgent.execute: No requests to be executed found." )
return S_OK()
requestString = res['Value']['RequestString']
requestName = res['Value']['RequestName']
sourceServer = res['Value']['Server']
try:
jobID = int( res['Value']['JobID'] )
except:
jobID = 0
gLogger.info( "RegistrationAgent.execute: Obtained request %s" % requestName )
result = self.RequestDBClient.getCurrentExecutionOrder( requestName, sourceServer )
if result['OK']:
currentOrder = result['Value']
else:
return S_OK( 'Can not get the request execution order' )
oRequest = RequestContainer( request = requestString )
################################################
# Find the number of sub-requests from the request
res = oRequest.getNumSubRequests( 'register' )
if not res['OK']:
errStr = "RegistrationAgent.execute: Failed to obtain number of transfer subrequests."
gLogger.error( errStr, res['Message'] )
return S_OK()
gLogger.info( "RegistrationAgent.execute: Found %s sub requests." % res['Value'] )
################################################
# For all the sub-requests in the request
modified = False
for ind in range( res['Value'] ):
gLogger.info( "RegistrationAgent.execute: Processing sub-request %s." % ind )
subRequestAttributes = oRequest.getSubRequestAttributes( ind, 'register' )['Value']
subExecutionOrder = int( subRequestAttributes['ExecutionOrder'] )
subStatus = subRequestAttributes['Status']
if subStatus == 'Waiting' and subExecutionOrder <= currentOrder:
subRequestFiles = oRequest.getSubRequestFiles( ind, 'register' )['Value']
operation = subRequestAttributes['Operation']
################################################
# If the sub-request is a register file operation
if operation == 'registerFile':
gLogger.info( "RegistrationAgent.execute: Attempting to execute %s sub-request." % operation )
diracSE = str( subRequestAttributes['TargetSE'] )
if diracSE == 'SE':
# We do not care about SE, put any there
diracSE = "CERN-FAILOVER"
catalog = subRequestAttributes['Catalogue']
if catalog == "None":
catalog = ''
subrequest_done = True
for subRequestFile in subRequestFiles:
if subRequestFile['Status'] == 'Waiting':
lfn = subRequestFile.get( 'LFN', '' )
if lfn: lfn = str( lfn )
physicalFile = subRequestFile.get( 'PFN', '' )
if physicalFile: physicalFile = str( physicalFile )
fileSize = subRequestFile.get( 'Size', 0 )
if fileSize: fileSize = int( fileSize )
fileGuid = subRequestFile.get( 'GUID', '' )
if fileGuid: fileGuid = str( fileGuid )
checksum = subRequestFile.get( 'Addler', '' )
if checksum: checksum = str( checksum )
if catalog == 'BookkeepingDB':
diracSE = 'CERN-HIST'
fileTuple = ( lfn, physicalFile, fileSize, diracSE, fileGuid, checksum )
res = self.ReplicaManager.registerFile( fileTuple, catalog )
print res
if not res['OK']:
self.DataLog.addFileRecord( lfn, 'RegisterFail', diracSE, '', 'RegistrationAgent' )
errStr = "RegistrationAgent.execute: Completely failed to register file."
gLogger.error( errStr, res['Message'] )
subrequest_done = False
elif lfn in res['Value']['Failed'].keys():
self.DataLog.addFileRecord( lfn, 'RegisterFail', diracSE, '', 'RegistrationAgent' )
errStr = "RegistrationAgent.execute: Completely failed to register file."
gLogger.error( errStr, res['Value']['Failed'][lfn] )
subrequest_done = False
else:
self.DataLog.addFileRecord( lfn, 'Register', diracSE, '', 'TransferAgent' )
oRequest.setSubRequestFileAttributeValue( ind, 'transfer', lfn, 'Status', 'Done' )
modified = True
else:
gLogger.info( "RegistrationAgent.execute: File already completed." )
if subrequest_done:
oRequest.setSubRequestStatus( ind, 'register', 'Done' )
################################################
# If the sub-request is none of the above types
else:
gLogger.error( "RegistrationAgent.execute: Operation not supported.", operation )
################################################
# Determine whether there are any active files
if oRequest.isSubRequestEmpty( ind, 'register' )['Value']:
oRequest.setSubRequestStatus( ind, 'register', 'Done' )
################################################
# If the sub-request is already in terminal state
else:
gLogger.info( "RegistrationAgent.execute: Sub-request %s is status '%s' and not to be executed." % ( ind, subRequestAttributes['Status'] ) )
################################################
# Generate the new request string after operation
requestString = oRequest.toXML()['Value']
res = self.RequestDBClient.updateRequest( requestName, requestString, sourceServer )
if modified and jobID:
result = self.finalizeRequest( requestName, jobID, sourceServer )
return S_OK()
def execute( self ):
""" The main agent execution method """
# This allows dynamic changing of the throughput timescale
self.throughputTimescale = self.am_getOption( 'ThroughputTimescale', 3600 )
self.throughputTimescale = 60 * 60 * 1
#print 'ThroughputTimescale:',self.throughputTimescale
######################################################################################
#
# Obtain information on the current state of the channel queues
#
res = self.TransferDB.getChannelQueues()
if not res['OK']:
errStr = "ReplicationScheduler._execute: Failed to get channel queues from TransferDB."
gLogger.error( errStr, res['Message'] )
return S_OK()
if not res['Value']:
gLogger.info( "ReplicationScheduler._execute: No active channels found for replication." )
return S_OK()
channels = res['Value']
res = self.TransferDB.getChannelObservedThroughput( self.throughputTimescale )
if not res['OK']:
errStr = "ReplicationScheduler._execute: Failed to get observed throughput from TransferDB."
gLogger.error( errStr, res['Message'] )
return S_OK()
if not res['Value']:
gLogger.info( "ReplicationScheduler._execute: No active channels found for replication." )
return S_OK()
bandwidths = res['Value']
self.strategyHandler = StrategyHandler( bandwidths, channels, self.section )
processedRequests = []
requestsPresent = True
while requestsPresent:
######################################################################################
#
# The first step is to obtain a transfer request from the RequestDB which should be scheduled.
#
gLogger.info( "ReplicationScheduler._execute: Contacting RequestDB for suitable requests." )
res = self.RequestDB.getRequest( 'transfer' )
if not res['OK']:
gLogger.error( "ReplicationScheduler._execute: Failed to get a request list from RequestDB.", res['Message'] )
continue
if not res['Value']:
gLogger.info( "ReplicationScheduler._execute: No requests found in RequestDB." )
requestsPresent = False
return S_OK()
requestString = res['Value']['RequestString']
requestName = res['Value']['RequestName']
gLogger.info( "ReplicationScheduler._execute: Obtained Request %s from RequestDB." % ( requestName ) )
######################################################################################
#
# The request must then be parsed to obtain the sub-requests, their attributes and files.
#
logStr = 'ReplicationScheduler._execute: Parsing Request %s.' % ( requestName )
gLogger.info( logStr )
oRequest = RequestContainer( requestString )
res = oRequest.getAttribute( 'RequestID' )
if not res['OK']:
gLogger.error( 'ReplicationScheduler._execute: Failed to get requestID.', res['Message'] )
return S_ERROR( 'ReplicationScheduler._execute: Failed to get number of sub-requests.' )
requestID = res['Value']
if requestID in processedRequests:
# Break the loop once we have iterated once over all requests
res = self.RequestDB.updateRequest( requestName, requestString )
if not res['OK']:
gLogger.error( "Failed to update request", "%s %s" % ( requestName, res['Message'] ) )
return S_OK()
processedRequests.append( requestID )
res = oRequest.getNumSubRequests( 'transfer' )
if not res['OK']:
gLogger.error( 'ReplicationScheduler._execute: Failed to get number of sub-requests.', res['Message'] )
return S_ERROR( 'ReplicationScheduler._execute: Failed to get number of sub-requests.' )
numberRequests = res['Value']
gLogger.info( "ReplicationScheduler._execute: '%s' found with %s sub-requests." % ( requestName, numberRequests ) )
######################################################################################
#
# The important request attributes are the source and target SEs.
#
for ind in range( numberRequests ):
gLogger.info( "ReplicationScheduler._execute: Treating sub-request %s from '%s'." % ( ind, requestName ) )
attributes = oRequest.getSubRequestAttributes( ind, 'transfer' )['Value']
if attributes['Status'] != 'Waiting':
# If the sub-request is already in terminal state
gLogger.info( "ReplicationScheduler._execute: Sub-request %s is status '%s' and not to be executed." % ( ind, attributes['Status'] ) )
continue
sourceSE = attributes['SourceSE']
targetSE = attributes['TargetSE']
""" This section should go in the transfer request class """
if type( targetSE ) in types.StringTypes:
if re.search( ',', targetSE ):
targetSEs = targetSE.split( ',' )
else:
targetSEs = [targetSE]
"""----------------------------------------------------- """
operation = attributes['Operation']
reqRepStrategy = None
if operation in self.strategyHandler.getSupportedStrategies():
reqRepStrategy = operation
######################################################################################
#
# Then obtain the file attribute of interest are the LFN and FileID
#
res = oRequest.getSubRequestFiles( ind, 'transfer' )
if not res['OK']:
gLogger.error( 'ReplicationScheduler._execute: Failed to obtain sub-request files.' , res['Message'] )
continue
files = res['Value']
gLogger.info( "ReplicationScheduler._execute: Sub-request %s found with %s files." % ( ind, len( files ) ) )
filesDict = {}
for file in files:
lfn = file['LFN']
if file['Status'] != 'Waiting':
gLogger.debug( "ReplicationScheduler._execute: %s will not be scheduled because it is %s." % ( lfn, file['Status'] ) )
else:
fileID = file['FileID']
filesDict[lfn] = fileID
if not filesDict:
gLogger.info( "ReplicationScheduler._execute: No Waiting files found for request" )
continue
notSched = len( files ) - len( filesDict )
if notSched:
gLogger.info( "ReplicationScheduler._execute: %d files found not Waiting" % notSched )
######################################################################################
#
# Now obtain replica information for the files associated to the sub-request.
#
lfns = filesDict.keys()
gLogger.info( "ReplicationScheduler._execute: Obtaining replica information for %d sub-request files." % len( lfns ) )
res = self.rm.getCatalogReplicas( lfns )
if not res['OK']:
gLogger.error( "ReplicationScheduler._execute: Failed to get replica information.", res['Message'] )
continue
for lfn, failure in res['Value']['Failed'].items():
gLogger.error( "ReplicationScheduler._execute: Failed to get replicas.", '%s: %s' % ( lfn, failure ) )
replicas = res['Value']['Successful']
if not replicas.keys():
gLogger.error( "ReplicationScheduler._execute: Failed to get replica information for all files." )
continue
######################################################################################
#
# Now obtain the file sizes for the files associated to the sub-request.
#
lfns = replicas.keys()
gLogger.info( "ReplicationScheduler._execute: Obtaining file sizes for %d sub-request files." % len( lfns ) )
res = self.rm.getCatalogFileMetadata( lfns )
if not res['OK']:
gLogger.error( "ReplicationScheduler._execute: Failed to get file size information.", res['Message'] )
continue
for lfn, failure in res['Value']['Failed'].items():
gLogger.error( 'ReplicationScheduler._execute: Failed to get file size.', '%s: %s' % ( lfn, failure ) )
metadata = res['Value']['Successful']
if not metadata.keys():
gLogger.error( "ReplicationScheduler._execute: Failed to get metadata for all files." )
continue
######################################################################################
#
# For each LFN determine the replication tree
#
for lfn in sortList( metadata.keys() ):
fileSize = metadata[lfn]['Size']
lfnReps = replicas[lfn]
fileID = filesDict[lfn]
targets = []
for targetSE in targetSEs:
if targetSE in lfnReps.keys():
gLogger.debug( "ReplicationScheduler.execute: %s already present at %s." % ( lfn, targetSE ) )
else:
targets.append( targetSE )
if not targets:
gLogger.info( "ReplicationScheduler.execute: %s present at all targets." % lfn )
oRequest.setSubRequestFileAttributeValue( ind, 'transfer', lfn, 'Status', 'Done' )
continue
if not lfnReps:
gLogger.error( "ReplicationScheduler.execute: The file has no replicas.", lfn )
continue
res = self.strategyHandler.determineReplicationTree( sourceSE, targets, lfnReps, fileSize, strategy = reqRepStrategy )
if not res['OK']:
gLogger.error( "ReplicationScheduler.execute: Failed to determine replication tree.", res['Message'] )
continue
tree = res['Value']
######################################################################################
#
# For each item in the replication tree obtain the source and target SURLS
#
for channelID, dict in tree.items():
gLogger.info( "ReplicationScheduler.execute: processing for channel %d %s" % ( channelID, str( dict ) ) )
hopSourceSE = dict['SourceSE']
hopDestSE = dict['DestSE']
hopAncestor = dict['Ancestor']
# Get the sourceSURL
if hopAncestor:
status = 'Waiting%s' % ( hopAncestor )
res = self.obtainLFNSURL( hopSourceSE, lfn )
if not res['OK']:
errStr = res['Message']
gLogger.error( errStr )
return S_ERROR( errStr )
sourceSURL = res['Value']
else:
status = 'Waiting'
res = self.resolvePFNSURL( hopSourceSE, lfnReps[hopSourceSE] )
if not res['OK']:
sourceSURL = lfnReps[hopSourceSE]
else:
sourceSURL = res['Value']
# Get the targetSURL
res = self.obtainLFNSURL( hopDestSE, lfn )
if not res['OK']:
errStr = res['Message']
gLogger.error( errStr )
return S_ERROR( errStr )
targetSURL = res['Value']
######################################################################################
#
# For each item in the replication tree add the file to the channel
#
res = self.TransferDB.addFileToChannel( channelID, fileID, hopSourceSE, sourceSURL, hopDestSE, targetSURL, fileSize, fileStatus = status )
if not res['OK']:
errStr = res['Message']
gLogger.error( "ReplicationScheduler._execute: Failed to add File to Channel." , "%s %s" % ( fileID, channelID ) )
return S_ERROR( errStr )
res = self.TransferDB.addFileRegistration( channelID, fileID, lfn, targetSURL, hopDestSE )
if not res['OK']:
errStr = res['Message']
gLogger.error( "ReplicationScheduler._execute: Failed to add File registration." , "%s %s" % ( fileID, channelID ) )
result = self.TransferDB.removeFileFromChannel( channelID, fileID )
if not result['OK']:
errStr += result['Message']
gLogger.error( "ReplicationScheduler._execute: Failed to remove File." , "%s %s" % ( fileID, channelID ) )
return S_ERROR( errStr )
oRequest.setSubRequestFileAttributeValue( ind, 'transfer', lfn, 'Status', 'Scheduled' )
res = self.TransferDB.addReplicationTree( fileID, tree )
if oRequest.isSubRequestEmpty( ind, 'transfer' )['Value']:
oRequest.setSubRequestStatus( ind, 'transfer', 'Scheduled' )
################################################
# Generate the new request string after operation
requestString = oRequest.toXML()['Value']
res = self.RequestDB.updateRequest( requestName, requestString )
if not res['OK']:
gLogger.error( "ReplicationScheduler._execute: Failed to update request", "%s %s" % ( requestName, res['Message'] ) )
def executeRequest( self ):
"""
Do the actual work in the Thread
"""
################################################
# Get a request from request DB
gMonitor.addMark( "Iteration", 1 )
res = self.requestDBClient.getRequest( 'removal' )
if not res['OK']:
gLogger.info( "RemovalAgent.execute: Failed to get request from database." )
return S_OK()
elif not res['Value']:
gLogger.info( "RemovalAgent.execute: No requests to be executed found." )
self.pendingRequests = False
return S_OK()
requestString = res['Value']['RequestString']
requestName = res['Value']['RequestName']
sourceServer = res['Value']['Server']
try:
jobID = int( res['Value']['JobID'] )
except ValueError:
jobID = 0
gLogger.info( "RemovalAgent.execute: Obtained request %s" % requestName )
try:
result = self.requestDBClient.getCurrentExecutionOrder( requestName, sourceServer )
if result['OK']:
currentOrder = result['Value']
else:
gLogger.error( 'Can not get the request execution order' )
self.requestDBClient.updateRequest( requestName, requestString, sourceServer )
return S_OK( 'Can not get the request execution order' )
oRequest = RequestContainer( request = requestString )
################################################
# Find the number of sub-requests from the request
res = oRequest.getNumSubRequests( 'removal' )
if not res['OK']:
errStr = "RemovalAgent.execute: Failed to obtain number of removal subrequests."
gLogger.error( errStr, res['Message'] )
return S_OK()
gLogger.info( "RemovalAgent.execute: Found %s sub requests." % res['Value'] )
################################################
# For all the sub-requests in the request
modified = False
for ind in range( res['Value'] ):
gMonitor.addMark( "Execute", 1 )
gLogger.info( "RemovalAgent.execute: Processing sub-request %s." % ind )
subRequestAttributes = oRequest.getSubRequestAttributes( ind, 'removal' )['Value']
subExecutionOrder = int( subRequestAttributes['ExecutionOrder'] )
subStatus = subRequestAttributes['Status']
if subStatus == 'Waiting' and subExecutionOrder <= currentOrder:
subRequestFiles = oRequest.getSubRequestFiles( ind, 'removal' )['Value']
operation = subRequestAttributes['Operation']
################################################
# If the sub-request is a physical removal operation
if operation == 'physicalRemoval':
gLogger.info( "RemovalAgent.execute: Attempting to execute %s sub-request." % operation )
diracSEs = subRequestAttributes['TargetSE'].split( ',' )
physicalFiles = []
pfnToLfn = {}
for subRequestFile in subRequestFiles:
if subRequestFile['Status'] == 'Waiting':
pfn = str( subRequestFile['PFN'] )
lfn = str( subRequestFile['LFN'] )
pfnToLfn[pfn] = lfn
physicalFiles.append( pfn )
gMonitor.addMark( 'PhysicalRemovalAtt', len( physicalFiles ) )
failed = {}
errMsg = {}
for diracSE in diracSEs:
res = self.replicaManager.removeStorageFile( physicalFiles, diracSE )
if res['OK']:
for pfn in res['Value']['Failed'].keys():
if not failed.has_key( pfn ):
failed[pfn] = {}
failed[pfn][diracSE] = res['Value']['Failed'][pfn]
else:
errMsg[diracSE] = res['Message']
for pfn in physicalFiles:
if not failed.has_key( pfn ):
failed[pfn] = {}
failed[pfn][diracSE] = 'Completely'
# Now analyse the results
failedPFNs = failed.keys()
pfnsOK = [pfn for pfn in physicalFiles if not pfn in failedPFNs]
gMonitor.addMark( 'PhysicalRemovalDone', len( pfnsOK ) )
for pfn in pfnsOK:
gLogger.info( "RemovalAgent.execute: Successfully removed %s at %s" % ( pfn, str( diracSEs ) ) )
res = oRequest.setSubRequestFileAttributeValue( ind, 'removal', pfnToLfn[pfn], 'Status', 'Done' )
if not res['OK']:
gLogger.error( "RemovalAgent.execute: Error setting status to %s for %s" % ( 'Done', pfnToLfn[pfn] ) )
modified = True
if failed:
gMonitor.addMark( 'PhysicalRemovalFail', len( failedPFNs ) )
for pfn in failedPFNs:
for diracSE in failed[pfn].keys():
if type( failed[pfn][diracSE] ) in StringTypes:
if re.search( 'no such file or directory', failed[pfn][diracSE].lower() ):
gLogger.info( "RemovalAgent.execute: File did not exist.", pfn )
res = oRequest.setSubRequestFileAttributeValue( ind, 'removal', pfnToLfn[pfn], 'Status', 'Done' )
if not res['OK']:
gLogger.error( "RemovalAgent.execute: Error setting status to %s for %s" % ( 'Done', pfnToLfn[pfn] ) )
modified = True
else:
gLogger.info( "RemovalAgent.execute: Failed to remove file.", "%s at %s - %s" % ( pfn, diracSE, failed[pfn][diracSE] ) )
if errMsg:
for diracSE in errMsg.keys():
errStr = "RemovalAgent.execute: Completely failed to remove replicas. At %s", diracSE
gLogger.error( errStr, errMsg[diracSE] )
################################################
# If the sub-request is a physical removal operation
elif operation == 'removeFile':
gLogger.info( "RemovalAgent.execute: Attempting to execute %s sub-request." % operation )
lfns = []
for subRequestFile in subRequestFiles:
if subRequestFile['Status'] == 'Waiting':
lfn = str( subRequestFile['LFN'] )
lfns.append( lfn )
gMonitor.addMark( 'RemoveFileAtt', len( lfns ) )
res = self.replicaManager.removeFile( lfns )
if res['OK']:
gMonitor.addMark( 'RemoveFileDone', len( res['Value']['Successful'].keys() ) )
for lfn in res['Value']['Successful'].keys():
gLogger.info( "RemovalAgent.execute: Successfully removed %s." % lfn )
result = oRequest.setSubRequestFileAttributeValue( ind, 'removal', lfn, 'Status', 'Done' )
if not result['OK']:
gLogger.error( "RemovalAgent.execute: Error setting status to %s for %s" % ( 'Done', lfn ) )
modified = True
gMonitor.addMark( 'RemoveFileFail', len( res['Value']['Failed'].keys() ) )
for lfn in res['Value']['Failed'].keys():
if type( res['Value']['Failed'][lfn] ) in StringTypes:
if re.search( 'no such file or directory', res['Value']['Failed'][lfn].lower() ):
gLogger.info( "RemovalAgent.execute: File did not exist.", lfn )
result = oRequest.setSubRequestFileAttributeValue( ind, 'removal', lfn, 'Status', 'Done' )
if not result['OK']:
gLogger.error( "RemovalAgent.execute: Error setting status to %s for %s" % ( 'Done', lfn ) )
modified = True
else:
gLogger.info( "RemovalAgent.execute: Failed to remove file:",
"%s %s" % ( lfn, res['Value']['Failed'][lfn] ) )
else:
gMonitor.addMark( 'RemoveFileFail', len( lfns ) )
errStr = "RemovalAgent.execute: Completely failed to remove files files."
gLogger.error( errStr, res['Message'] )
################################################
# If the sub-request is a physical removal operation
elif operation == 'replicaRemoval':
gLogger.info( "RemovalAgent.execute: Attempting to execute %s sub-request." % operation )
diracSEs = subRequestAttributes['TargetSE'].split( ',' )
lfns = []
for subRequestFile in subRequestFiles:
if subRequestFile['Status'] == 'Waiting':
lfn = str( subRequestFile['LFN'] )
lfns.append( lfn )
gMonitor.addMark( 'ReplicaRemovalAtt', len( lfns ) )
failed = {}
errMsg = {}
for diracSE in diracSEs:
res = self.replicaManager.removeReplica( diracSE, lfns )
if res['OK']:
for lfn in res['Value']['Failed'].keys():
errorMessage = str( res['Value']['Failed'][lfn] )
if errorMessage.find( 'Write access not permitted for this credential.' ) != -1:
if self.__getProxyAndRemoveReplica( diracSE, lfn ):
continue
if errorMessage.find( 'seconds timeout for "__gfal_wrapper" call' ) != -1:
self.timeOutCounter += 1
if not failed.has_key( lfn ):
failed[lfn] = {}
failed[lfn][diracSE] = res['Value']['Failed'][lfn]
else:
errMsg[diracSE] = res['Message']
for lfn in lfns:
if not failed.has_key( lfn ):
failed[lfn] = {}
failed[lfn][diracSE] = 'Completely'
# Now analyse the results
failedLFNs = failed.keys()
lfnsOK = [lfn for lfn in lfns if not lfn in failedLFNs]
gMonitor.addMark( 'ReplicaRemovalDone', len( lfnsOK ) )
for lfn in lfnsOK:
gLogger.info( "RemovalAgent.execute: Successfully removed %s at %s" % ( lfn, str( diracSEs ) ) )
res = oRequest.setSubRequestFileAttributeValue( ind, 'removal', lfn, 'Status', 'Done' )
if not res['OK']:
gLogger.error( "RemovalAgent.execute: Error setting status to %s for %s" % ( 'Done', lfn ) )
modified = True
if failed:
gMonitor.addMark( 'PhysicalRemovalFail', len( failedLFNs ) )
for lfn in failedLFNs:
for diracSE in failed[lfn].keys():
if type( failed[lfn][diracSE] ) in StringTypes:
if re.search( 'no such file or directory', failed[lfn][diracSE].lower() ):
gLogger.info( "RemovalAgent.execute: File did not exist.", lfn )
res = oRequest.setSubRequestFileAttributeValue( ind, 'removal', lfn, 'Status', 'Done' )
if not res['OK']:
gLogger.error( "RemovalAgent.execute: Error setting status to %s for %s" % ( 'Done', lfn ) )
modified = True
else:
gLogger.info( "RemovalAgent.execute: Failed to remove file.", "%s at %s - %s" % ( lfn, diracSE, failed[lfn][diracSE] ) )
if errMsg:
for diracSE in errMsg.keys():
errStr = "RemovalAgent.execute: Completely failed to remove replicas. At %s", diracSE
gLogger.error( errStr, errMsg[diracSE] )
################################################
# If the sub-request is a request to the online system to retransfer
elif operation == 'reTransfer':
gLogger.info( "RemovalAgent.execute: Attempting to execute %s sub-request." % operation )
diracSE = subRequestAttributes['TargetSE']
for subRequestFile in subRequestFiles:
if subRequestFile['Status'] == 'Waiting':
pfn = str( subRequestFile['PFN'] )
lfn = str( subRequestFile['LFN'] )
res = self.replicaManager.onlineRetransfer( diracSE, pfn )
if res['OK']:
if res['Value']['Successful'].has_key( pfn ):
gLogger.info( "RemovalAgent.execute: Successfully requested retransfer of %s." % pfn )
result = oRequest.setSubRequestFileAttributeValue( ind, 'removal', lfn, 'Status', 'Done' )
if not result['OK']:
gLogger.error( "RemovalAgent.execute: Error setting status to %s for %s" % ( 'Done', lfn ) )
modified = True
else:
errStr = "RemovalAgent.execute: Failed to request retransfer."
gLogger.error( errStr, "%s %s %s" % ( pfn, diracSE, res['Value']['Failed'][pfn] ) )
else:
errStr = "RemovalAgent.execute: Completely failed to request retransfer."
gLogger.error( errStr, res['Message'] )
else:
gLogger.info( "RemovalAgent.execute: File already completed." )
################################################
# If the sub-request is none of the above types
else:
gLogger.error( "RemovalAgent.execute: Operation not supported.", operation )
################################################
# Determine whether there are any active files
if oRequest.isSubRequestEmpty( ind, 'removal' )['Value']:
oRequest.setSubRequestStatus( ind, 'removal', 'Done' )
gMonitor.addMark( "Done", 1 )
################################################
# If the sub-request is already in terminal state
else:
gLogger.info( "RemovalAgent.execute:",
"Sub-request %s is status '%s' and not to be executed." %
( ind, subRequestAttributes['Status'] ) )
################################################
# Generate the new request string after operation
newrequestString = oRequest.toXML()['Value']
except:
# if something fails return the original request back to the server
res = self.requestDBClient.updateRequest( requestName, requestString, sourceServer )
return S_OK()
res = self.requestDBClient.updateRequest( requestName, newrequestString, sourceServer )
if modified and jobID:
result = self.finalizeRequest( requestName, jobID, sourceServer )
return S_OK()
def executeRequest(self):
################################################
# Get a request from request DB
res = self.RequestDBClient.getRequest('register')
if not res['OK']:
gLogger.info(
"RegistrationAgent.execute: Failed to get request from database."
)
return S_OK()
elif not res['Value']:
gLogger.info(
"RegistrationAgent.execute: No requests to be executed found.")
return S_OK()
requestString = res['Value']['RequestString']
requestName = res['Value']['RequestName']
sourceServer = res['Value']['Server']
try:
jobID = int(res['Value']['JobID'])
except:
jobID = 0
gLogger.info("RegistrationAgent.execute: Obtained request %s" %
requestName)
result = self.RequestDBClient.getCurrentExecutionOrder(
requestName, sourceServer)
if result['OK']:
currentOrder = result['Value']
else:
return S_OK('Can not get the request execution order')
oRequest = RequestContainer(request=requestString)
################################################
# Find the number of sub-requests from the request
res = oRequest.getNumSubRequests('register')
if not res['OK']:
errStr = "RegistrationAgent.execute: Failed to obtain number of transfer subrequests."
gLogger.error(errStr, res['Message'])
return S_OK()
gLogger.info("RegistrationAgent.execute: Found %s sub requests." %
res['Value'])
################################################
# For all the sub-requests in the request
modified = False
for ind in range(res['Value']):
gLogger.info(
"RegistrationAgent.execute: Processing sub-request %s." % ind)
subRequestAttributes = oRequest.getSubRequestAttributes(
ind, 'register')['Value']
subExecutionOrder = int(subRequestAttributes['ExecutionOrder'])
subStatus = subRequestAttributes['Status']
if subStatus == 'Waiting' and subExecutionOrder <= currentOrder:
subRequestFiles = oRequest.getSubRequestFiles(
ind, 'register')['Value']
operation = subRequestAttributes['Operation']
################################################
# If the sub-request is a register file operation
if operation == 'registerFile':
gLogger.info(
"RegistrationAgent.execute: Attempting to execute %s sub-request."
% operation)
diracSE = str(subRequestAttributes['TargetSE'])
if diracSE == 'SE':
# We do not care about SE, put any there
diracSE = "CERN-FAILOVER"
catalog = subRequestAttributes['Catalogue']
if catalog == "None":
catalog = ''
subrequest_done = True
for subRequestFile in subRequestFiles:
if subRequestFile['Status'] == 'Waiting':
lfn = subRequestFile.get('LFN', '')
if lfn: lfn = str(lfn)
physicalFile = subRequestFile.get('PFN', '')
if physicalFile: physicalFile = str(physicalFile)
fileSize = subRequestFile.get('Size', 0)
if fileSize: fileSize = int(fileSize)
fileGuid = subRequestFile.get('GUID', '')
if fileGuid: fileGuid = str(fileGuid)
checksum = subRequestFile.get('Addler', '')
if checksum: checksum = str(checksum)
if catalog == 'BookkeepingDB':
diracSE = 'CERN-HIST'
fileTuple = (lfn, physicalFile, fileSize, diracSE,
fileGuid, checksum)
res = self.ReplicaManager.registerFile(
fileTuple, catalog)
print res
if not res['OK']:
self.DataLog.addFileRecord(
lfn, 'RegisterFail', diracSE, '',
'RegistrationAgent')
errStr = "RegistrationAgent.execute: Completely failed to register file."
gLogger.error(errStr, res['Message'])
subrequest_done = False
elif lfn in res['Value']['Failed'].keys():
self.DataLog.addFileRecord(
lfn, 'RegisterFail', diracSE, '',
'RegistrationAgent')
errStr = "RegistrationAgent.execute: Completely failed to register file."
gLogger.error(errStr,
res['Value']['Failed'][lfn])
subrequest_done = False
else:
self.DataLog.addFileRecord(
lfn, 'Register', diracSE, '',
'TransferAgent')
oRequest.setSubRequestFileAttributeValue(
ind, 'transfer', lfn, 'Status', 'Done')
modified = True
else:
gLogger.info(
"RegistrationAgent.execute: File already completed."
)
if subrequest_done:
oRequest.setSubRequestStatus(ind, 'register', 'Done')
################################################
# If the sub-request is none of the above types
else:
gLogger.error(
"RegistrationAgent.execute: Operation not supported.",
operation)
################################################
# Determine whether there are any active files
if oRequest.isSubRequestEmpty(ind, 'register')['Value']:
oRequest.setSubRequestStatus(ind, 'register', 'Done')
################################################
# If the sub-request is already in terminal state
else:
gLogger.info(
"RegistrationAgent.execute: Sub-request %s is status '%s' and not to be executed."
% (ind, subRequestAttributes['Status']))
################################################
# Generate the new request string after operation
requestString = oRequest.toXML()['Value']
res = self.RequestDBClient.updateRequest(requestName, requestString,
sourceServer)
if modified and jobID:
result = self.finalizeRequest(requestName, jobID, sourceServer)
return S_OK()
def execute(self):
res = self.RequestDBClient.getRequest('integrity')
if not res['OK']:
gLogger.info(
"LFCvsSEAgent.execute: Failed to get request from database.")
return S_OK()
elif not res['Value']:
gLogger.info(
"LFCvsSEAgent.execute: No requests to be executed found.")
return S_OK()
requestString = res['Value']['RequestString']
requestName = res['Value']['RequestName']
sourceServer = res['Value']['Server']
gLogger.info("LFCvsSEAgent.execute: Obtained request %s" % requestName)
oRequest = RequestContainer(request=requestString)
################################################
# Find the number of sub-requests from the request
res = oRequest.getNumSubRequests('integrity')
if not res['OK']:
errStr = "LFCvsSEAgent.execute: Failed to obtain number of integrity subrequests."
gLogger.error(errStr, res['Message'])
return S_OK()
gLogger.info("LFCvsSEAgent.execute: Found %s sub requests." %
res['Value'])
################################################
# For all the sub-requests in the request
for ind in range(res['Value']):
gLogger.info("LFCvsSEAgent.execute: Processing sub-request %s." %
ind)
subRequestAttributes = oRequest.getSubRequestAttributes(
ind, 'integrity')['Value']
if subRequestAttributes['Status'] == 'Waiting':
subRequestFiles = oRequest.getSubRequestFiles(
ind, 'integrity')['Value']
operation = subRequestAttributes['Operation']
################################################
# If the sub-request is a lfcvsse operation
if operation == 'LFCvsSE':
gLogger.info(
"LFCvsSEAgent.execute: Attempting to execute %s sub-request."
% operation)
for subRequestFile in subRequestFiles:
if subRequestFile['Status'] == 'Waiting':
lfn = subRequestFile['LFN']
oNamespaceBrowser = NamespaceBrowser(lfn)
# Loop over all the directories and sub-directories
while (oNamespaceBrowser.isActive()):
currentDir = oNamespaceBrowser.getActiveDir()
gLogger.info(
"LFCvsSEAgent.execute: Attempting to get contents of %s."
% currentDir)
res = self.ReplicaManager.getCatalogDirectoryContents(
currentDir)
if not res['OK']:
subDirs = [currentDir]
elif res['Value']['Failed'].has_key(
currentDir):
subDirs = [currentDir]
else:
subDirs = res['Value']['Successful'][
currentDir]['SubDirs']
files = res['Value']['Successful'][
currentDir]['Files']
lfnSizeDict = {}
pfnLfnDict = {}
pfnStatusDict = {}
sePfnDict = {}
for lfn, lfnDict in files.items():
lfnSizeDict[lfn] = lfnDict['MetaData'][
'Size']
for se in lfnDict['Replicas'].keys():
pfn = lfnDict['Replicas'][se][
'PFN']
status = lfnDict['Replicas'][se][
'Status']
pfnStatusDict[pfn] = status
pfnLfnDict[pfn] = lfn
if not sePfnDict.has_key(se):
sePfnDict[se] = []
sePfnDict[se].append(pfn)
for storageElementName, physicalFiles in sePfnDict.items(
):
gLogger.info(
"LFCvsSEAgent.execute: Attempting to get metadata for files on %s."
% storageElementName)
res = self.ReplicaManager.getStorageFileMetadata(
physicalFiles, storageElementName)
if not res['OK']:
gLogger.error(
"LFCvsSEAgent.execute: Completely failed to get physical file metadata.",
res['Message'])
else:
for pfn in res['Value'][
'Failed'].keys():
gLogger.error(
"LFCvsSEAgent.execute: Failed to get metadata.",
"%s %s" %
(pfn, res['Value']
['Failed'][pfn]))
lfn = pfnLfnDict[pfn]
fileMetadata = {
'Prognosis':
'MissingSEPfn',
'LFN': lfn,
'PFN': pfn,
'StorageElement':
storageElementName,
'Size': lfnSizeDict[lfn]
}
IntegrityDB = RPCClient(
'DataManagement/DataIntegrity'
)
resInsert = IntegrityDB.insertProblematic(
AGENT_NAME, fileMetadata)
if resInsert['OK']:
gLogger.info(
"LFCvsSEAgent.execute: Successfully added to IntegrityDB."
)
gLogger.error(
"Change the status in the LFC,ProcDB...."
)
else:
gLogger.error(
"Shit, f**k, bugger. Add the failover."
)
for pfn, pfnDict in res['Value'][
'Successful'].items():
lfn = pfnLfnDict[pfn]
catalogSize = int(
lfnSizeDict[lfn])
storageSize = int(
pfnDict['Size'])
if int(catalogSize) == int(
storageSize):
gLogger.info(
"LFCvsSEAgent.execute: Catalog and storage sizes match.",
"%s %s" %
(pfn,
storageElementName))
gLogger.info(
"Change the status in the LFC"
)
else:
gLogger.error(
"LFCvsSEAgent.execute: Catalog and storage size mis-match.",
"%s %s" %
(pfn,
storageElementName))
fileMetadata = {
'Prognosis':
'PfnSizeMismatch',
'LFN':
lfn,
'PFN':
pfn,
'StorageElement':
storageElementName
}
IntegrityDB = RPCClient(
'DataManagement/DataIntegrity'
)
resInsert = IntegrityDB.insertProblematic(
AGENT_NAME,
fileMetadata)
if resInsert['OK']:
gLogger.info(
"LFCvsSEAgent.execute: Successfully added to IntegrityDB."
)
gLogger.error(
"Change the status in the LFC,ProcDB...."
)
else:
gLogger.error(
"Shit, f**k, bugger. Add the failover."
)
oNamespaceBrowser.updateDirs(subDirs)
oRequest.setSubRequestFileAttributeValue(
ind, 'integrity', lfn, 'Status', 'Done')
################################################
# If the sub-request is none of the above types
else:
gLogger.info(
"LFCvsSEAgent.execute: Operation not supported.",
operation)
################################################
# Determine whether there are any active files
if oRequest.isSubRequestEmpty(ind, 'integrity')['Value']:
oRequest.setSubRequestStatus(ind, 'integrity', 'Done')
################################################
# If the sub-request is already in terminal state
else:
gLogger.info(
"LFCvsSEAgent.execute: Sub-request %s is status '%s' and not to be executed."
% (ind, subRequestAttributes['Status']))
################################################
# Generate the new request string after operation
requestString = oRequest.toXML()['Value']
res = self.RequestDBClient.updateRequest(requestName, requestString,
sourceServer)
return S_OK()
def execute(self):
""" The main agent execution method """
# This allows dynamic changing of the throughput timescale
self.throughputTimescale = self.am_getOption('ThroughputTimescale',
3600)
self.throughputTimescale = 60 * 60 * 1
#print 'ThroughputTimescale:',self.throughputTimescale
######################################################################################
#
# Obtain information on the current state of the channel queues
#
res = self.TransferDB.getChannelQueues()
if not res['OK']:
errStr = "ReplicationScheduler._execute: Failed to get channel queues from TransferDB."
gLogger.error(errStr, res['Message'])
return S_OK()
if not res['Value']:
gLogger.info(
"ReplicationScheduler._execute: No active channels found for replication."
)
return S_OK()
channels = res['Value']
res = self.TransferDB.getChannelObservedThroughput(
self.throughputTimescale)
if not res['OK']:
errStr = "ReplicationScheduler._execute: Failed to get observed throughput from TransferDB."
gLogger.error(errStr, res['Message'])
return S_OK()
if not res['Value']:
gLogger.info(
"ReplicationScheduler._execute: No active channels found for replication."
)
return S_OK()
bandwidths = res['Value']
self.strategyHandler = StrategyHandler(bandwidths, channels,
self.section)
processedRequests = []
requestsPresent = True
while requestsPresent:
######################################################################################
#
# The first step is to obtain a transfer request from the RequestDB which should be scheduled.
#
gLogger.info(
"ReplicationScheduler._execute: Contacting RequestDB for suitable requests."
)
res = self.RequestDB.getRequest('transfer')
if not res['OK']:
gLogger.error(
"ReplicationScheduler._execute: Failed to get a request list from RequestDB.",
res['Message'])
continue
if not res['Value']:
gLogger.info(
"ReplicationScheduler._execute: No requests found in RequestDB."
)
requestsPresent = False
return S_OK()
requestString = res['Value']['RequestString']
requestName = res['Value']['RequestName']
gLogger.info(
"ReplicationScheduler._execute: Obtained Request %s from RequestDB."
% (requestName))
######################################################################################
#
# The request must then be parsed to obtain the sub-requests, their attributes and files.
#
logStr = 'ReplicationScheduler._execute: Parsing Request %s.' % (
requestName)
gLogger.info(logStr)
oRequest = RequestContainer(requestString)
res = oRequest.getAttribute('RequestID')
if not res['OK']:
gLogger.error(
'ReplicationScheduler._execute: Failed to get requestID.',
res['Message'])
return S_ERROR(
'ReplicationScheduler._execute: Failed to get number of sub-requests.'
)
requestID = res['Value']
if requestID in processedRequests:
# Break the loop once we have iterated once over all requests
res = self.RequestDB.updateRequest(requestName, requestString)
if not res['OK']:
gLogger.error("Failed to update request",
"%s %s" % (requestName, res['Message']))
return S_OK()
processedRequests.append(requestID)
res = oRequest.getNumSubRequests('transfer')
if not res['OK']:
gLogger.error(
'ReplicationScheduler._execute: Failed to get number of sub-requests.',
res['Message'])
return S_ERROR(
'ReplicationScheduler._execute: Failed to get number of sub-requests.'
)
numberRequests = res['Value']
gLogger.info(
"ReplicationScheduler._execute: '%s' found with %s sub-requests."
% (requestName, numberRequests))
######################################################################################
#
# The important request attributes are the source and target SEs.
#
for ind in range(numberRequests):
gLogger.info(
"ReplicationScheduler._execute: Treating sub-request %s from '%s'."
% (ind, requestName))
attributes = oRequest.getSubRequestAttributes(
ind, 'transfer')['Value']
if attributes['Status'] != 'Waiting':
# If the sub-request is already in terminal state
gLogger.info(
"ReplicationScheduler._execute: Sub-request %s is status '%s' and not to be executed."
% (ind, attributes['Status']))
continue
sourceSE = attributes['SourceSE']
targetSE = attributes['TargetSE']
""" This section should go in the transfer request class """
if type(targetSE) in types.StringTypes:
if re.search(',', targetSE):
targetSEs = targetSE.split(',')
else:
targetSEs = [targetSE]
"""----------------------------------------------------- """
operation = attributes['Operation']
reqRepStrategy = None
if operation in self.strategyHandler.getSupportedStrategies():
reqRepStrategy = operation
######################################################################################
#
# Then obtain the file attribute of interest are the LFN and FileID
#
res = oRequest.getSubRequestFiles(ind, 'transfer')
if not res['OK']:
gLogger.error(
'ReplicationScheduler._execute: Failed to obtain sub-request files.',
res['Message'])
continue
files = res['Value']
gLogger.info(
"ReplicationScheduler._execute: Sub-request %s found with %s files."
% (ind, len(files)))
filesDict = {}
for file in files:
lfn = file['LFN']
if file['Status'] != 'Waiting':
gLogger.debug(
"ReplicationScheduler._execute: %s will not be scheduled because it is %s."
% (lfn, file['Status']))
else:
fileID = file['FileID']
filesDict[lfn] = fileID
if not filesDict:
gLogger.info(
"ReplicationScheduler._execute: No Waiting files found for request"
)
continue
notSched = len(files) - len(filesDict)
if notSched:
gLogger.info(
"ReplicationScheduler._execute: %d files found not Waiting"
% notSched)
######################################################################################
#
# Now obtain replica information for the files associated to the sub-request.
#
lfns = filesDict.keys()
gLogger.info(
"ReplicationScheduler._execute: Obtaining replica information for %d sub-request files."
% len(lfns))
res = self.rm.getCatalogReplicas(lfns)
if not res['OK']:
gLogger.error(
"ReplicationScheduler._execute: Failed to get replica information.",
res['Message'])
continue
for lfn, failure in res['Value']['Failed'].items():
gLogger.error(
"ReplicationScheduler._execute: Failed to get replicas.",
'%s: %s' % (lfn, failure))
replicas = res['Value']['Successful']
if not replicas.keys():
gLogger.error(
"ReplicationScheduler._execute: Failed to get replica information for all files."
)
continue
######################################################################################
#
# Now obtain the file sizes for the files associated to the sub-request.
#
lfns = replicas.keys()
gLogger.info(
"ReplicationScheduler._execute: Obtaining file sizes for %d sub-request files."
% len(lfns))
res = self.rm.getCatalogFileMetadata(lfns)
if not res['OK']:
gLogger.error(
"ReplicationScheduler._execute: Failed to get file size information.",
res['Message'])
continue
for lfn, failure in res['Value']['Failed'].items():
gLogger.error(
'ReplicationScheduler._execute: Failed to get file size.',
'%s: %s' % (lfn, failure))
metadata = res['Value']['Successful']
if not metadata.keys():
gLogger.error(
"ReplicationScheduler._execute: Failed to get metadata for all files."
)
continue
######################################################################################
#
# For each LFN determine the replication tree
#
for lfn in sortList(metadata.keys()):
fileSize = metadata[lfn]['Size']
lfnReps = replicas[lfn]
fileID = filesDict[lfn]
targets = []
for targetSE in targetSEs:
if targetSE in lfnReps.keys():
gLogger.debug(
"ReplicationScheduler.execute: %s already present at %s."
% (lfn, targetSE))
else:
targets.append(targetSE)
if not targets:
gLogger.info(
"ReplicationScheduler.execute: %s present at all targets."
% lfn)
oRequest.setSubRequestFileAttributeValue(
ind, 'transfer', lfn, 'Status', 'Done')
continue
if not lfnReps:
gLogger.error(
"ReplicationScheduler.execute: The file has no replicas.",
lfn)
continue
res = self.strategyHandler.determineReplicationTree(
sourceSE,
targets,
lfnReps,
fileSize,
strategy=reqRepStrategy)
if not res['OK']:
gLogger.error(
"ReplicationScheduler.execute: Failed to determine replication tree.",
res['Message'])
continue
tree = res['Value']
######################################################################################
#
# For each item in the replication tree obtain the source and target SURLS
#
for channelID, dict in tree.items():
gLogger.info(
"ReplicationScheduler.execute: processing for channel %d %s"
% (channelID, str(dict)))
hopSourceSE = dict['SourceSE']
hopDestSE = dict['DestSE']
hopAncestor = dict['Ancestor']
# Get the sourceSURL
if hopAncestor:
status = 'Waiting%s' % (hopAncestor)
res = self.obtainLFNSURL(hopSourceSE, lfn)
if not res['OK']:
errStr = res['Message']
gLogger.error(errStr)
return S_ERROR(errStr)
sourceSURL = res['Value']
else:
status = 'Waiting'
res = self.resolvePFNSURL(hopSourceSE,
lfnReps[hopSourceSE])
if not res['OK']:
sourceSURL = lfnReps[hopSourceSE]
else:
sourceSURL = res['Value']
# Get the targetSURL
res = self.obtainLFNSURL(hopDestSE, lfn)
if not res['OK']:
errStr = res['Message']
gLogger.error(errStr)
return S_ERROR(errStr)
targetSURL = res['Value']
######################################################################################
#
# For each item in the replication tree add the file to the channel
#
res = self.TransferDB.addFileToChannel(
channelID,
fileID,
hopSourceSE,
sourceSURL,
hopDestSE,
targetSURL,
fileSize,
fileStatus=status)
if not res['OK']:
errStr = res['Message']
gLogger.error(
"ReplicationScheduler._execute: Failed to add File to Channel.",
"%s %s" % (fileID, channelID))
return S_ERROR(errStr)
res = self.TransferDB.addFileRegistration(
channelID, fileID, lfn, targetSURL, hopDestSE)
if not res['OK']:
errStr = res['Message']
gLogger.error(
"ReplicationScheduler._execute: Failed to add File registration.",
"%s %s" % (fileID, channelID))
result = self.TransferDB.removeFileFromChannel(
channelID, fileID)
if not result['OK']:
errStr += result['Message']
gLogger.error(
"ReplicationScheduler._execute: Failed to remove File.",
"%s %s" % (fileID, channelID))
return S_ERROR(errStr)
oRequest.setSubRequestFileAttributeValue(
ind, 'transfer', lfn, 'Status', 'Scheduled')
res = self.TransferDB.addReplicationTree(fileID, tree)
if oRequest.isSubRequestEmpty(ind, 'transfer')['Value']:
oRequest.setSubRequestStatus(ind, 'transfer', 'Scheduled')
################################################
# Generate the new request string after operation
requestString = oRequest.toXML()['Value']
res = self.RequestDB.updateRequest(requestName, requestString)
if not res['OK']:
gLogger.error(
"ReplicationScheduler._execute: Failed to update request",
"%s %s" % (requestName, res['Message']))
def executeRequest(self):
################################################
# Get a request from request DB
gMonitor.addMark("Iteration", 1)
res = self.RequestDBClient.getRequest('transfer')
if not res['OK']:
gLogger.info(
"TransferAgent.execute: Failed to get request from database.")
return S_OK()
elif not res['Value']:
gLogger.info(
"TransferAgent.execute: No requests to be executed found.")
return S_OK()
requestString = res['Value']['RequestString']
requestName = res['Value']['RequestName']
sourceServer = res['Value']['Server']
try:
jobID = int(res['Value']['JobID'])
except:
jobID = 0
gLogger.info("TransferAgent.execute: Obtained request %s" %
requestName)
result = self.RequestDBClient.getCurrentExecutionOrder(
requestName, sourceServer)
if result['OK']:
currentOrder = result['Value']
else:
return S_OK('Can not get the request execution order')
oRequest = RequestContainer(request=requestString)
################################################
# Find the number of sub-requests from the request
res = oRequest.getNumSubRequests('transfer')
if not res['OK']:
errStr = "TransferAgent.execute: Failed to obtain number of transfer subrequests."
gLogger.error(errStr, res['Message'])
return S_OK()
gLogger.info("TransferAgent.execute: Found %s sub requests." %
res['Value'])
################################################
# For all the sub-requests in the request
modified = False
for ind in range(res['Value']):
gMonitor.addMark("Execute", 1)
gLogger.info("TransferAgent.execute: Processing sub-request %s." %
ind)
subRequestAttributes = oRequest.getSubRequestAttributes(
ind, 'transfer')['Value']
if subRequestAttributes['ExecutionOrder']:
subExecutionOrder = int(subRequestAttributes['ExecutionOrder'])
else:
subExecutionOrder = 0
subStatus = subRequestAttributes['Status']
if subStatus == 'Waiting' and subExecutionOrder <= currentOrder:
subRequestFiles = oRequest.getSubRequestFiles(
ind, 'transfer')['Value']
operation = subRequestAttributes['Operation']
subRequestError = ''
################################################
# If the sub-request is a put and register operation
if operation == 'putAndRegister' or operation == 'putAndRegisterAndRemove':
gLogger.info(
"TransferAgent.execute: Attempting to execute %s sub-request."
% operation)
diracSE = str(subRequestAttributes['TargetSE'])
catalog = ''
if subRequestAttributes.has_key('Catalogue'):
catalog = subRequestAttributes['Catalogue']
for subRequestFile in subRequestFiles:
if subRequestFile['Status'] == 'Waiting':
gMonitor.addMark("Put and register", 1)
lfn = str(subRequestFile['LFN'])
file = subRequestFile['PFN']
guid = subRequestFile['GUID']
addler = subRequestFile['Addler']
res = self.ReplicaManager.putAndRegister(
lfn,
file,
diracSE,
guid=guid,
checksum=addler,
catalog=catalog)
if res['OK']:
if res['Value']['Successful'].has_key(lfn):
if not res['Value']['Successful'][
lfn].has_key('put'):
gMonitor.addMark("Put failed", 1)
self.DataLog.addFileRecord(
lfn, 'PutFail', diracSE, '',
'TransferAgent')
gLogger.info(
"TransferAgent.execute: Failed to put %s to %s."
% (lfn, diracSE))
subRequestError = "Put operation failed for %s to %s" % (
lfn, diracSE)
oRequest.setSubRequestFileAttributeValue(
ind, 'transfer', lfn, 'Error',
'Put failed')
elif not res['Value']['Successful'][
lfn].has_key('register'):
gMonitor.addMark("Put successful", 1)
gMonitor.addMark(
"File registration failed", 1)
self.DataLog.addFileRecord(
lfn, 'Put', diracSE, '',
'TransferAgent')
self.DataLog.addFileRecord(
lfn, 'RegisterFail', diracSE, '',
'TransferAgent')
gLogger.info(
"TransferAgent.execute: Successfully put %s to %s in %s seconds."
% (lfn, diracSE, res['Value']
['Successful'][lfn]['put']))
gLogger.info(
"TransferAgent.execute: Failed to register %s to %s."
% (lfn, diracSE))
oRequest.setSubRequestFileAttributeValue(
ind, 'transfer', lfn, 'Status',
'Done')
oRequest.setSubRequestFileAttributeValue(
ind, 'transfer', lfn, 'Error',
'Registration failed')
subRequestError = "Registration failed for %s to %s" % (
lfn, diracSE)
fileDict = res['Value']['Failed'][lfn][
'register']
registerRequestDict = {
'Attributes': {
'TargetSE':
fileDict['TargetSE'],
'Operation': 'registerFile'
},
'Files': [{
'LFN':
fileDict['LFN'],
'PFN':
fileDict['PFN'],
'Size':
fileDict['Size'],
'Addler':
fileDict['Addler'],
'GUID':
fileDict['GUID']
}]
}
gLogger.info(
"TransferAgent.execute: Setting registration request for failed file."
)
oRequest.addSubRequest(
registerRequestDict, 'register')
modified = True
else:
gMonitor.addMark("Put successful", 1)
gMonitor.addMark(
"File registration successful", 1)
self.DataLog.addFileRecord(
lfn, 'Put', diracSE, '',
'TransferAgent')
self.DataLog.addFileRecord(
lfn, 'Register', diracSE, '',
'TransferAgent')
gLogger.info(
"TransferAgent.execute: Successfully put %s to %s in %s seconds."
% (lfn, diracSE, res['Value']
['Successful'][lfn]['put']))
gLogger.info(
"TransferAgent.execute: Successfully registered %s to %s in %s seconds."
%
(lfn, diracSE, res['Value']
['Successful'][lfn]['register']))
oRequest.setSubRequestFileAttributeValue(
ind, 'transfer', lfn, 'Status',
'Done')
modified = True
else:
gMonitor.addMark("Put failed", 1)
self.DataLog.addFileRecord(
lfn, 'PutFail', diracSE, '',
'TransferAgent')
errStr = "TransferAgent.execute: Failed to put and register file."
gLogger.error(
errStr, "%s %s %s" %
(lfn, diracSE,
res['Value']['Failed'][lfn]))
oRequest.setSubRequestFileAttributeValue(
ind, 'transfer', lfn, 'Error',
'Complete file failure')
subRequestError = "Failed to put and register file"
else:
gMonitor.addMark("Put failed", 1)
self.DataLog.addFileRecord(
lfn, 'PutFail', diracSE, '',
'TransferAgent')
errStr = "TransferAgent.execute: Completely failed to put and register file."
gLogger.error(errStr, res['Message'])
oRequest.setSubRequestFileAttributeValue(
ind, 'transfer', lfn, 'Error',
'RM call failure')
subRequestError = operation + " RM call file"
else:
gLogger.info(
"TransferAgent.execute: File already completed."
)
################################################
# If the sub-request is a put operation
elif operation == 'put':
gLogger.info(
"TransferAgent.execute: Attempting to execute %s sub-request."
% operation)
diracSE = subRequestAttributes['TargetSE']
for subRequestFile in subRequestFiles:
if subRequestFile['Status'] == 'Waiting':
gMonitor.addMark("Put", 1)
lfn = subRequestFile['LFN']
file = subRequestFile['PFN']
res = self.ReplicaManager.put(lfn, file, diracSE)
if res['OK']:
if res['Value']['Successful'].has_key(lfn):
gMonitor.addMark("Put successful", 1)
self.DataLog.addFileRecord(
lfn, 'Put', diracSE, '',
'TransferAgent')
gLogger.info(
"TransferAgent.execute: Successfully put %s to %s in %s seconds."
% (lfn, diracSE,
res['Value']['Successful'][lfn]))
oRequest.setSubRequestFileAttributeValue(
ind, 'transfer', lfn, 'Status', 'Done')
modified = True
else:
gMonitor.addMark("Put failed", 1)
self.DataLog.addFileRecord(
lfn, 'PutFail', diracSE, '',
'TransferAgent')
errStr = "TransferAgent.execute: Failed to put file."
gLogger.error(
errStr, "%s %s %s" %
(lfn, diracSE,
res['Value']['Failed'][lfn]))
subRequestError = "Put operation failed for %s to %s" % (
lfn, diracSE)
oRequest.setSubRequestFileAttributeValue(
ind, 'transfer', lfn, 'Error',
'Put failed')
else:
gMonitor.addMark("Put failed", 1)
self.DataLog.addFileRecord(
lfn, 'PutFail', diracSE, '',
'TransferAgent')
errStr = "TransferAgent.execute: Completely failed to put file."
gLogger.error(errStr, res['Message'])
subRequestError = "Put RM call failed for %s to %s" % (
lfn, diracSE)
oRequest.setSubRequestFileAttributeValue(
ind, 'transfer', lfn, 'Error',
'Put RM call failed')
else:
gLogger.info(
"TransferAgent.execute: File already completed."
)
################################################
# If the sub-request is a replicate and register operation
elif operation == 'replicateAndRegister' or operation == 'replicateAndRegisterAndRemove':
gLogger.info(
"TransferAgent.execute: Attempting to execute %s sub-request."
% operation)
targetSE = subRequestAttributes['TargetSE']
sourceSE = subRequestAttributes['SourceSE']
if sourceSE == "None":
sourceSE = ''
for subRequestFile in subRequestFiles:
if subRequestFile['Status'] == 'Waiting':
gMonitor.addMark("Replicate and register", 1)
lfn = subRequestFile['LFN']
res = self.ReplicaManager.replicateAndRegister(
lfn, targetSE, sourceSE=sourceSE)
if res['OK']:
if res['Value']['Successful'].has_key(lfn):
if not res['Value']['Successful'][
lfn].has_key('replicate'):
gLogger.info(
"TransferAgent.execute: Failed to replicate %s to %s."
% (lfn, targetSE))
gMonitor.addMark(
"Replication failed", 1)
oRequest.setSubRequestFileAttributeValue(
ind, 'transfer', lfn, "Error",
"Replication failed")
subRequestError = "Replication failed for %s to %s" % (
lfn, targetSE)
elif not res['Value']['Successful'][
lfn].has_key('register'):
gMonitor.addMark(
"Replication successful", 1)
gMonitor.addMark(
"Replica registration failed", 1)
gLogger.info(
"TransferAgent.execute: Successfully replicated %s to %s in %s seconds."
%
(lfn, targetSE, res['Value']
['Successful'][lfn]['replicate']))
gLogger.info(
"TransferAgent.execute: Failed to register %s to %s."
% (lfn, targetSE))
oRequest.setSubRequestFileAttributeValue(
ind, 'transfer', lfn, 'Status',
'Done')
oRequest.setSubRequestFileAttributeValue(
ind, 'transfer', lfn, 'Error',
'Registration failed')
subRequestError = "Registration failed for %s to %s" % (
lfn, targetSE)
fileDict = res['Value']['Failed'][lfn][
'register']
registerRequestDict = {
'Attributes': {
'TargetSE':
fileDict['TargetSE'],
'Operation': 'registerReplica'
},
'Files': [{
'LFN': fileDict['LFN'],
'PFN': fileDict['PFN']
}]
}
gLogger.info(
"TransferAgent.execute: Setting registration request for failed replica."
)
oRequest.addSubRequest(
registerRequestDict, 'register')
modified = True
else:
gMonitor.addMark(
"Replication successful", 1)
gMonitor.addMark(
"Replica registration successful",
1)
gLogger.info(
"TransferAgent.execute: Successfully replicated %s to %s in %s seconds."
%
(lfn, targetSE, res['Value']
['Successful'][lfn]['replicate']))
gLogger.info(
"TransferAgent.execute: Successfully registered %s to %s in %s seconds."
%
(lfn, targetSE, res['Value']
['Successful'][lfn]['register']))
oRequest.setSubRequestFileAttributeValue(
ind, 'transfer', lfn, 'Status',
'Done')
modified = True
else:
gMonitor.addMark("Replication failed", 1)
errStr = "TransferAgent.execute: Failed to replicate and register file."
gLogger.error(
errStr, "%s %s %s" %
(lfn, targetSE,
res['Value']['Failed'][lfn]))
else:
gMonitor.addMark("Replication failed", 1)
errStr = "TransferAgent.execute: Completely failed to replicate and register file."
gLogger.error(errStr, res['Message'])
oRequest.setSubRequestFileAttributeValue(
ind, 'transfer', lfn, 'Error',
'RM call failure')
subRequestError = operation + " RM call failed"
else:
gLogger.info(
"TransferAgent.execute: File already completed."
)
################################################
# If the sub-request is a replicate operation
elif operation == 'replicate':
gLogger.info(
"TransferAgent.execute: Attempting to execute %s sub-request."
% operation)
targetSE = subRequestAttributes['TargetSE']
sourceSE = subRequestAttributes['SourceSE']
for subRequestFile in subRequestFiles:
if subRequestFile['Status'] == 'Waiting':
gMonitor.addMark("Replicate", 1)
lfn = subRequestFile['LFN']
res = self.ReplicaManager.replicate(
lfn, targetSE, sourceSE=sourceSE)
if res['OK']:
if res['Value']['Successful'].has_key(lfn):
gMonitor.addMark("Replication successful",
1)
gLogger.info(
"TransferAgent.execute: Successfully replicated %s to %s in %s seconds."
% (lfn, diracSE,
res['Value']['Successful'][lfn]))
oRequest.setSubRequestFileAttributeValue(
ind, 'transfer', lfn, 'Status', 'Done')
modified = True
else:
gMonitor.addMark("Replication failed", 1)
errStr = "TransferAgent.execute: Failed to replicate file."
gLogger.error(
errStr, "%s %s %s" %
(lfn, targetSE,
res['Value']['Failed'][lfn]))
subRequestError = "Replicate operation failed for %s to %s" % (
lfn, targetSE)
oRequest.setSubRequestFileAttributeValue(
ind, 'transfer', lfn, 'Error',
'Put failed')
else:
gMonitor.addMark("Replication failed", 1)
errStr = "TransferAgent.execute: Completely failed to replicate file."
gLogger.error(errStr, res['Message'])
subRequestError = "Replicate RM call failed for %s to %s" % (
lfn, targetSE)
oRequest.setSubRequestFileAttributeValue(
ind, 'transfer', lfn, 'Error',
'Replicate RM call failed')
else:
gLogger.info(
"TransferAgent.execute: File already completed."
)
################################################
# If the sub-request is a get operation
elif operation == 'get':
gLogger.info(
"TransferAgent.execute: Attempting to execute %s sub-request."
% operation)
sourceSE = subRequestAttributes['TargetSE']
for subRequestFile in subRequestFiles:
if subRequestFile['Status'] == 'Waiting':
lfn = str(subRequestFile['LFN'])
pfn = str(subRequestFile['PFN'])
got = False
if sourceSE and pfn:
res = self.ReplicaManager.getStorageFile(
pfn, sourceSE)
if res['Value']['Successful'].has_key(pfn):
got = True
else:
res = self.ReplicaManager.getFile(lfn)
if res['Value']['Successful'].has_key(lfn):
got = False
if got:
gLogger.info(
"TransferAgent.execute: Successfully got %s."
% lfn)
oRequest.setSubRequestFileAttributeValue(
ind, 'transfer', lfn, 'Status', 'Done')
modified = True
else:
errStr = "TransferAgent.execute: Failed to get file."
gLogger.error(errStr, lfn)
else:
gLogger.info(
"TransferAgent.execute: File already completed."
)
################################################
# If the sub-request is none of the above types
else:
gLogger.error(
"TransferAgent.execute: Operation not supported.",
operation)
if subRequestError:
oRequest.setSubRequestAttributeValue(
ind, 'transfer', 'Error', subRequestError)
################################################
# Determine whether there are any active files
if oRequest.isSubRequestEmpty(ind, 'transfer')['Value']:
oRequest.setSubRequestStatus(ind, 'transfer', 'Done')
gMonitor.addMark("Done", 1)
################################################
# If the sub-request is already in terminal state
else:
gLogger.info(
"TransferAgent.execute: Sub-request %s is status '%s' and not to be executed."
% (ind, subRequestAttributes['Status']))
################################################
# Generate the new request string after operation
requestString = oRequest.toXML()['Value']
res = self.RequestDBClient.updateRequest(requestName, requestString,
sourceServer)
if modified and jobID:
result = self.finalizeRequest(requestName, jobID, sourceServer)
return S_OK()
def execute( self ):
res = self.RequestDBClient.getRequest( 'integrity' )
if not res['OK']:
gLogger.info( "LFCvsSEAgent.execute: Failed to get request from database." )
return S_OK()
elif not res['Value']:
gLogger.info( "LFCvsSEAgent.execute: No requests to be executed found." )
return S_OK()
requestString = res['Value']['RequestString']
requestName = res['Value']['RequestName']
sourceServer = res['Value']['Server']
gLogger.info( "LFCvsSEAgent.execute: Obtained request %s" % requestName )
oRequest = RequestContainer( request = requestString )
################################################
# Find the number of sub-requests from the request
res = oRequest.getNumSubRequests( 'integrity' )
if not res['OK']:
errStr = "LFCvsSEAgent.execute: Failed to obtain number of integrity subrequests."
gLogger.error( errStr, res['Message'] )
return S_OK()
gLogger.info( "LFCvsSEAgent.execute: Found %s sub requests." % res['Value'] )
################################################
# For all the sub-requests in the request
for ind in range( res['Value'] ):
gLogger.info( "LFCvsSEAgent.execute: Processing sub-request %s." % ind )
subRequestAttributes = oRequest.getSubRequestAttributes( ind, 'integrity' )['Value']
if subRequestAttributes['Status'] == 'Waiting':
subRequestFiles = oRequest.getSubRequestFiles( ind, 'integrity' )['Value']
operation = subRequestAttributes['Operation']
################################################
# If the sub-request is a lfcvsse operation
if operation == 'LFCvsSE':
gLogger.info( "LFCvsSEAgent.execute: Attempting to execute %s sub-request." % operation )
for subRequestFile in subRequestFiles:
if subRequestFile['Status'] == 'Waiting':
lfn = subRequestFile['LFN']
oNamespaceBrowser = NamespaceBrowser( lfn )
# Loop over all the directories and sub-directories
while ( oNamespaceBrowser.isActive() ):
currentDir = oNamespaceBrowser.getActiveDir()
gLogger.info( "LFCvsSEAgent.execute: Attempting to get contents of %s." % currentDir )
res = self.ReplicaManager.getCatalogDirectoryContents( currentDir )
if not res['OK']:
subDirs = [currentDir]
elif res['Value']['Failed'].has_key( currentDir ):
subDirs = [currentDir]
else:
subDirs = res['Value']['Successful'][currentDir]['SubDirs']
files = res['Value']['Successful'][currentDir]['Files']
lfnSizeDict = {}
pfnLfnDict = {}
pfnStatusDict = {}
sePfnDict = {}
for lfn, lfnDict in files.items():
lfnSizeDict[lfn] = lfnDict['MetaData']['Size']
for se in lfnDict['Replicas'].keys():
pfn = lfnDict['Replicas'][se]['PFN']
status = lfnDict['Replicas'][se]['Status']
pfnStatusDict[pfn] = status
pfnLfnDict[pfn] = lfn
if not sePfnDict.has_key( se ):
sePfnDict[se] = []
sePfnDict[se].append( pfn )
for storageElementName, physicalFiles in sePfnDict.items():
gLogger.info( "LFCvsSEAgent.execute: Attempting to get metadata for files on %s." % storageElementName )
res = self.ReplicaManager.getStorageFileMetadata( physicalFiles, storageElementName )
if not res['OK']:
gLogger.error( "LFCvsSEAgent.execute: Completely failed to get physical file metadata.", res['Message'] )
else:
for pfn in res['Value']['Failed'].keys():
gLogger.error( "LFCvsSEAgent.execute: Failed to get metadata.", "%s %s" % ( pfn, res['Value']['Failed'][pfn] ) )
lfn = pfnLfnDict[pfn]
fileMetadata = {'Prognosis':'MissingSEPfn', 'LFN':lfn, 'PFN':pfn, 'StorageElement':storageElementName, 'Size':lfnSizeDict[lfn]}
IntegrityDB = RPCClient( 'DataManagement/DataIntegrity' )
resInsert = IntegrityDB.insertProblematic( AGENT_NAME, fileMetadata )
if resInsert['OK']:
gLogger.info( "LFCvsSEAgent.execute: Successfully added to IntegrityDB." )
gLogger.error( "Change the status in the LFC,ProcDB...." )
else:
gLogger.error( "Shit, f**k, bugger. Add the failover." )
for pfn, pfnDict in res['Value']['Successful'].items():
lfn = pfnLfnDict[pfn]
catalogSize = int( lfnSizeDict[lfn] )
storageSize = int( pfnDict['Size'] )
if int( catalogSize ) == int( storageSize ):
gLogger.info( "LFCvsSEAgent.execute: Catalog and storage sizes match.", "%s %s" % ( pfn, storageElementName ) )
gLogger.info( "Change the status in the LFC" )
else:
gLogger.error( "LFCvsSEAgent.execute: Catalog and storage size mis-match.", "%s %s" % ( pfn, storageElementName ) )
fileMetadata = {'Prognosis':'PfnSizeMismatch', 'LFN':lfn, 'PFN':pfn, 'StorageElement':storageElementName}
IntegrityDB = RPCClient( 'DataManagement/DataIntegrity' )
resInsert = IntegrityDB.insertProblematic( AGENT_NAME, fileMetadata )
if resInsert['OK']:
gLogger.info( "LFCvsSEAgent.execute: Successfully added to IntegrityDB." )
gLogger.error( "Change the status in the LFC,ProcDB...." )
else:
gLogger.error( "Shit, f**k, bugger. Add the failover." )
oNamespaceBrowser.updateDirs( subDirs )
oRequest.setSubRequestFileAttributeValue( ind, 'integrity', lfn, 'Status', 'Done' )
################################################
# If the sub-request is none of the above types
else:
gLogger.info( "LFCvsSEAgent.execute: Operation not supported.", operation )
################################################
# Determine whether there are any active files
if oRequest.isSubRequestEmpty( ind, 'integrity' )['Value']:
oRequest.setSubRequestStatus( ind, 'integrity', 'Done' )
################################################
# If the sub-request is already in terminal state
else:
gLogger.info( "LFCvsSEAgent.execute: Sub-request %s is status '%s' and not to be executed." % ( ind, subRequestAttributes['Status'] ) )
################################################
# Generate the new request string after operation
requestString = oRequest.toXML()['Value']
res = self.RequestDBClient.updateRequest( requestName, requestString, sourceServer )
return S_OK()
def executeRequest( self ):
################################################
# Get a request from request DB
gMonitor.addMark( "Iteration", 1 )
res = self.RequestDBClient.getRequest( 'transfer' )
if not res['OK']:
gLogger.info( "TransferAgent.execute: Failed to get request from database." )
return S_OK()
elif not res['Value']:
gLogger.info( "TransferAgent.execute: No requests to be executed found." )
return S_OK()
requestString = res['Value']['RequestString']
requestName = res['Value']['RequestName']
sourceServer = res['Value']['Server']
try:
jobID = int( res['Value']['JobID'] )
except:
jobID = 0
gLogger.info( "TransferAgent.execute: Obtained request %s" % requestName )
result = self.RequestDBClient.getCurrentExecutionOrder( requestName, sourceServer )
if result['OK']:
currentOrder = result['Value']
else:
return S_OK( 'Can not get the request execution order' )
oRequest = RequestContainer( request = requestString )
################################################
# Find the number of sub-requests from the request
res = oRequest.getNumSubRequests( 'transfer' )
if not res['OK']:
errStr = "TransferAgent.execute: Failed to obtain number of transfer subrequests."
gLogger.error( errStr, res['Message'] )
return S_OK()
gLogger.info( "TransferAgent.execute: Found %s sub requests." % res['Value'] )
################################################
# For all the sub-requests in the request
modified = False
for ind in range( res['Value'] ):
gMonitor.addMark( "Execute", 1 )
gLogger.info( "TransferAgent.execute: Processing sub-request %s." % ind )
subRequestAttributes = oRequest.getSubRequestAttributes( ind, 'transfer' )['Value']
if subRequestAttributes['ExecutionOrder']:
subExecutionOrder = int( subRequestAttributes['ExecutionOrder'] )
else:
subExecutionOrder = 0
subStatus = subRequestAttributes['Status']
if subStatus == 'Waiting' and subExecutionOrder <= currentOrder:
subRequestFiles = oRequest.getSubRequestFiles( ind, 'transfer' )['Value']
operation = subRequestAttributes['Operation']
subRequestError = ''
################################################
# If the sub-request is a put and register operation
if operation == 'putAndRegister' or operation == 'putAndRegisterAndRemove':
gLogger.info( "TransferAgent.execute: Attempting to execute %s sub-request." % operation )
diracSE = str( subRequestAttributes['TargetSE'] )
catalog = ''
if subRequestAttributes.has_key( 'Catalogue' ):
catalog = subRequestAttributes['Catalogue']
for subRequestFile in subRequestFiles:
if subRequestFile['Status'] == 'Waiting':
gMonitor.addMark( "Put and register", 1 )
lfn = str( subRequestFile['LFN'] )
file = subRequestFile['PFN']
guid = subRequestFile['GUID']
addler = subRequestFile['Addler']
res = self.ReplicaManager.putAndRegister( lfn, file, diracSE, guid = guid, checksum = addler, catalog = catalog )
if res['OK']:
if res['Value']['Successful'].has_key( lfn ):
if not res['Value']['Successful'][lfn].has_key( 'put' ):
gMonitor.addMark( "Put failed", 1 )
self.DataLog.addFileRecord( lfn, 'PutFail', diracSE, '', 'TransferAgent' )
gLogger.info( "TransferAgent.execute: Failed to put %s to %s." % ( lfn, diracSE ) )
subRequestError = "Put operation failed for %s to %s" % ( lfn, diracSE )
oRequest.setSubRequestFileAttributeValue( ind, 'transfer', lfn,'Error', 'Put failed' )
elif not res['Value']['Successful'][lfn].has_key( 'register' ):
gMonitor.addMark( "Put successful", 1 )
gMonitor.addMark( "File registration failed", 1 )
self.DataLog.addFileRecord( lfn, 'Put', diracSE, '', 'TransferAgent' )
self.DataLog.addFileRecord( lfn, 'RegisterFail', diracSE, '', 'TransferAgent' )
gLogger.info( "TransferAgent.execute: Successfully put %s to %s in %s seconds." % ( lfn, diracSE, res['Value']['Successful'][lfn]['put'] ) )
gLogger.info( "TransferAgent.execute: Failed to register %s to %s." % ( lfn, diracSE ) )
oRequest.setSubRequestFileAttributeValue( ind, 'transfer', lfn, 'Status', 'Done' )
oRequest.setSubRequestFileAttributeValue( ind, 'transfer', lfn,'Error', 'Registration failed' )
subRequestError = "Registration failed for %s to %s" % ( lfn, diracSE )
fileDict = res['Value']['Failed'][lfn]['register']
registerRequestDict = {'Attributes':{'TargetSE': fileDict['TargetSE'], 'Operation':'registerFile'},
'Files':[{'LFN': fileDict['LFN'],
'PFN':fileDict['PFN'],
'Size':fileDict['Size'],
'Addler':fileDict['Addler'],
'GUID':fileDict['GUID']}]}
gLogger.info( "TransferAgent.execute: Setting registration request for failed file." )
oRequest.addSubRequest( registerRequestDict, 'register' )
modified = True
else:
gMonitor.addMark( "Put successful", 1 )
gMonitor.addMark( "File registration successful", 1 )
self.DataLog.addFileRecord( lfn, 'Put', diracSE, '', 'TransferAgent' )
self.DataLog.addFileRecord( lfn, 'Register', diracSE, '', 'TransferAgent' )
gLogger.info( "TransferAgent.execute: Successfully put %s to %s in %s seconds." % ( lfn, diracSE, res['Value']['Successful'][lfn]['put'] ) )
gLogger.info( "TransferAgent.execute: Successfully registered %s to %s in %s seconds." % ( lfn, diracSE, res['Value']['Successful'][lfn]['register'] ) )
oRequest.setSubRequestFileAttributeValue( ind, 'transfer', lfn, 'Status', 'Done' )
modified = True
else:
gMonitor.addMark( "Put failed", 1 )
self.DataLog.addFileRecord( lfn, 'PutFail', diracSE, '', 'TransferAgent' )
errStr = "TransferAgent.execute: Failed to put and register file."
gLogger.error( errStr, "%s %s %s" % ( lfn, diracSE, res['Value']['Failed'][lfn] ) )
oRequest.setSubRequestFileAttributeValue( ind, 'transfer', lfn,'Error', 'Complete file failure' )
subRequestError = "Failed to put and register file"
else:
gMonitor.addMark( "Put failed", 1 )
self.DataLog.addFileRecord( lfn, 'PutFail', diracSE, '', 'TransferAgent' )
errStr = "TransferAgent.execute: Completely failed to put and register file."
gLogger.error( errStr, res['Message'] )
oRequest.setSubRequestFileAttributeValue( ind, 'transfer', lfn,'Error', 'RM call failure' )
subRequestError = operation + " RM call file"
else:
gLogger.info( "TransferAgent.execute: File already completed." )
################################################
# If the sub-request is a put operation
elif operation == 'put':
gLogger.info( "TransferAgent.execute: Attempting to execute %s sub-request." % operation )
diracSE = subRequestAttributes['TargetSE']
for subRequestFile in subRequestFiles:
if subRequestFile['Status'] == 'Waiting':
gMonitor.addMark( "Put", 1 )
lfn = subRequestFile['LFN']
file = subRequestFile['PFN']
res = self.ReplicaManager.put( lfn, file, diracSE )
if res['OK']:
if res['Value']['Successful'].has_key( lfn ):
gMonitor.addMark( "Put successful", 1 )
self.DataLog.addFileRecord( lfn, 'Put', diracSE, '', 'TransferAgent' )
gLogger.info( "TransferAgent.execute: Successfully put %s to %s in %s seconds." % ( lfn, diracSE, res['Value']['Successful'][lfn] ) )
oRequest.setSubRequestFileAttributeValue( ind, 'transfer', lfn, 'Status', 'Done' )
modified = True
else:
gMonitor.addMark( "Put failed", 1 )
self.DataLog.addFileRecord( lfn, 'PutFail', diracSE, '', 'TransferAgent' )
errStr = "TransferAgent.execute: Failed to put file."
gLogger.error( errStr, "%s %s %s" % ( lfn, diracSE, res['Value']['Failed'][lfn] ) )
subRequestError = "Put operation failed for %s to %s" % ( lfn, diracSE )
oRequest.setSubRequestFileAttributeValue( ind, 'transfer', lfn,'Error', 'Put failed' )
else:
gMonitor.addMark( "Put failed", 1 )
self.DataLog.addFileRecord( lfn, 'PutFail', diracSE, '', 'TransferAgent' )
errStr = "TransferAgent.execute: Completely failed to put file."
gLogger.error( errStr, res['Message'] )
subRequestError = "Put RM call failed for %s to %s" % ( lfn, diracSE )
oRequest.setSubRequestFileAttributeValue( ind, 'transfer', lfn,'Error', 'Put RM call failed' )
else:
gLogger.info( "TransferAgent.execute: File already completed." )
################################################
# If the sub-request is a replicate and register operation
elif operation == 'replicateAndRegister' or operation == 'replicateAndRegisterAndRemove':
gLogger.info( "TransferAgent.execute: Attempting to execute %s sub-request." % operation )
targetSE = subRequestAttributes['TargetSE']
sourceSE = subRequestAttributes['SourceSE']
if sourceSE == "None":
sourceSE = ''
for subRequestFile in subRequestFiles:
if subRequestFile['Status'] == 'Waiting':
gMonitor.addMark( "Replicate and register", 1 )
lfn = subRequestFile['LFN']
res = self.ReplicaManager.replicateAndRegister( lfn, targetSE, sourceSE = sourceSE )
if res['OK']:
if res['Value']['Successful'].has_key( lfn ):
if not res['Value']['Successful'][lfn].has_key( 'replicate' ):
gLogger.info( "TransferAgent.execute: Failed to replicate %s to %s." % ( lfn, targetSE ) )
gMonitor.addMark( "Replication failed", 1 )
oRequest.setSubRequestFileAttributeValue( ind, 'transfer', lfn,"Error", "Replication failed" )
subRequestError = "Replication failed for %s to %s" % ( lfn, targetSE )
elif not res['Value']['Successful'][lfn].has_key( 'register' ):
gMonitor.addMark( "Replication successful", 1 )
gMonitor.addMark( "Replica registration failed", 1 )
gLogger.info( "TransferAgent.execute: Successfully replicated %s to %s in %s seconds." % ( lfn, targetSE, res['Value']['Successful'][lfn]['replicate'] ) )
gLogger.info( "TransferAgent.execute: Failed to register %s to %s." % ( lfn, targetSE ) )
oRequest.setSubRequestFileAttributeValue( ind, 'transfer', lfn, 'Status', 'Done' )
oRequest.setSubRequestFileAttributeValue( ind, 'transfer', lfn, 'Error', 'Registration failed' )
subRequestError = "Registration failed for %s to %s" % ( lfn, targetSE )
fileDict = res['Value']['Failed'][lfn]['register']
registerRequestDict = {'Attributes':{'TargetSE': fileDict['TargetSE'], 'Operation':'registerReplica'}, 'Files':[{'LFN': fileDict['LFN'], 'PFN':fileDict['PFN']}]}
gLogger.info( "TransferAgent.execute: Setting registration request for failed replica." )
oRequest.addSubRequest( registerRequestDict, 'register' )
modified = True
else:
gMonitor.addMark( "Replication successful", 1 )
gMonitor.addMark( "Replica registration successful", 1 )
gLogger.info( "TransferAgent.execute: Successfully replicated %s to %s in %s seconds." % ( lfn, targetSE, res['Value']['Successful'][lfn]['replicate'] ) )
gLogger.info( "TransferAgent.execute: Successfully registered %s to %s in %s seconds." % ( lfn, targetSE, res['Value']['Successful'][lfn]['register'] ) )
oRequest.setSubRequestFileAttributeValue( ind, 'transfer', lfn, 'Status', 'Done' )
modified = True
else:
gMonitor.addMark( "Replication failed", 1 )
errStr = "TransferAgent.execute: Failed to replicate and register file."
gLogger.error( errStr, "%s %s %s" % ( lfn, targetSE, res['Value']['Failed'][lfn] ) )
else:
gMonitor.addMark( "Replication failed", 1 )
errStr = "TransferAgent.execute: Completely failed to replicate and register file."
gLogger.error( errStr, res['Message'] )
oRequest.setSubRequestFileAttributeValue( ind, 'transfer', lfn,'Error', 'RM call failure' )
subRequestError = operation + " RM call failed"
else:
gLogger.info( "TransferAgent.execute: File already completed." )
################################################
# If the sub-request is a replicate operation
elif operation == 'replicate':
gLogger.info( "TransferAgent.execute: Attempting to execute %s sub-request." % operation )
targetSE = subRequestAttributes['TargetSE']
sourceSE = subRequestAttributes['SourceSE']
for subRequestFile in subRequestFiles:
if subRequestFile['Status'] == 'Waiting':
gMonitor.addMark( "Replicate", 1 )
lfn = subRequestFile['LFN']
res = self.ReplicaManager.replicate( lfn, targetSE, sourceSE = sourceSE )
if res['OK']:
if res['Value']['Successful'].has_key( lfn ):
gMonitor.addMark( "Replication successful", 1 )
gLogger.info( "TransferAgent.execute: Successfully replicated %s to %s in %s seconds." % ( lfn, diracSE, res['Value']['Successful'][lfn] ) )
oRequest.setSubRequestFileAttributeValue( ind, 'transfer', lfn, 'Status', 'Done' )
modified = True
else:
gMonitor.addMark( "Replication failed", 1 )
errStr = "TransferAgent.execute: Failed to replicate file."
gLogger.error( errStr, "%s %s %s" % ( lfn, targetSE, res['Value']['Failed'][lfn] ) )
subRequestError = "Replicate operation failed for %s to %s" % ( lfn, targetSE )
oRequest.setSubRequestFileAttributeValue( ind, 'transfer', lfn,'Error', 'Put failed' )
else:
gMonitor.addMark( "Replication failed", 1 )
errStr = "TransferAgent.execute: Completely failed to replicate file."
gLogger.error( errStr, res['Message'] )
subRequestError = "Replicate RM call failed for %s to %s" % ( lfn, targetSE )
oRequest.setSubRequestFileAttributeValue( ind, 'transfer', lfn,'Error', 'Replicate RM call failed' )
else:
gLogger.info( "TransferAgent.execute: File already completed." )
################################################
# If the sub-request is a get operation
elif operation == 'get':
gLogger.info( "TransferAgent.execute: Attempting to execute %s sub-request." % operation )
sourceSE = subRequestAttributes['TargetSE']
for subRequestFile in subRequestFiles:
if subRequestFile['Status'] == 'Waiting':
lfn = str( subRequestFile['LFN'] )
pfn = str( subRequestFile['PFN'] )
got = False
if sourceSE and pfn:
res = self.ReplicaManager.getStorageFile( pfn, sourceSE )
if res['Value']['Successful'].has_key( pfn ):
got = True
else:
res = self.ReplicaManager.getFile( lfn )
if res['Value']['Successful'].has_key( lfn ):
got = False
if got:
gLogger.info( "TransferAgent.execute: Successfully got %s." % lfn )
oRequest.setSubRequestFileAttributeValue( ind, 'transfer', lfn, 'Status', 'Done' )
modified = True
else:
errStr = "TransferAgent.execute: Failed to get file."
gLogger.error( errStr, lfn )
else:
gLogger.info( "TransferAgent.execute: File already completed." )
################################################
# If the sub-request is none of the above types
else:
gLogger.error( "TransferAgent.execute: Operation not supported.", operation )
if subRequestError:
oRequest.setSubRequestAttributeValue( ind, 'transfer', 'Error', subRequestError )
################################################
# Determine whether there are any active files
if oRequest.isSubRequestEmpty( ind, 'transfer' )['Value']:
oRequest.setSubRequestStatus( ind, 'transfer', 'Done' )
gMonitor.addMark( "Done", 1 )
################################################
# If the sub-request is already in terminal state
else:
gLogger.info( "TransferAgent.execute: Sub-request %s is status '%s' and not to be executed." % ( ind, subRequestAttributes['Status'] ) )
################################################
# Generate the new request string after operation
requestString = oRequest.toXML()['Value']
res = self.RequestDBClient.updateRequest( requestName, requestString, sourceServer )
if modified and jobID:
result = self.finalizeRequest( requestName, jobID, sourceServer )
return S_OK()
