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):
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 ):
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
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 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(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(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
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 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()