Ejemplo n.º 1
0
  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()
Ejemplo n.º 2
0
    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()
Ejemplo n.º 3
0
  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()
Ejemplo n.º 4
0
    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()
Ejemplo n.º 5
0
    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()
Ejemplo n.º 6
0
    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()
Ejemplo n.º 7
0
    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']))
Ejemplo n.º 8
0
  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()
Ejemplo n.º 9
0
  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'] ) )
Ejemplo n.º 10
0
  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()
Ejemplo n.º 11
0
    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()
Ejemplo n.º 12
0
  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()