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