#!/usr/bin/python2
#
# Copyright (c) 2013-2014 Rafael Martinez Guerrero / PostgreSQL-es
# rafael@postgresql.org.es / http://www.postgresql.org.es/
#
# Copyright (c) 2014 USIT-University of Oslo
#
# This file is part of PgBackMan
# https://github.com/rafaelma/pgbackman
#
# PgBackMan is free software: you can redistribute it and/or modify
# it under the terms of the GNU General Public License as published by
# the Free Software Foundation, either version 3 of the License, or
# (at your option) any later version.
#
# PgBackMan is distributed in the hope that it will be useful,
# but WITHOUT ANY WARRANTY; without even the implied warranty of
# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
# GNU General Public License for more details.
#
# You should have received a copy of the GNU General Public License
# along with Pgbackman.  If not, see <http://www.gnu.org/licenses/>.

import subprocess
import tempfile
import datetime
import sys
import os
import time
import socket
import signal
import argparse
import errno
import shutil

from pgbackman.logs import *
from pgbackman.database import *
from pgbackman.config import *

'''
This program is used by PgBackMan to run some maintenance tasks in this backup server.

These are the task implemented:

* Delete restore logs files when restore definitions/catalogs are deleted.
* Delete backup and log files from catalog entries associated to a backup definition after 
  this definition has been deleted with the force parameter.
* Enforce retentions for backup definitions.
* Enforce retentions of snapshot backups
* Process all pending backup catalog log files in the server
* Process all pending restore catalog log files in the server

'''

# ############################################
# Function delete_restore_logs()
# ############################################

def delete_restore_logs(db,backup_server_id):
    '''Delete restore log files after restore definitions/catalogs are deleted'''

    logs.logger.debug('## Deleting restore logs after restore definitions/catalogs are deleted ##')
    
    try:
        for record in db.get_restore_logs_to_delete(backup_server_id):
            
            error_cnt = 0

            #
            # record[2] is the file to delete
            #

            try:
                os.unlink(record[2])
                logs.logger.debug('File: %s deleted',record[2])
            
            except OSError as e:
                if e.errno != errno.ENOENT:
                    logs.logger.error('Problems deleting restore log files with DelID: %s - %s',record[0],e)
                    error_cnt = error_cnt + 1
                else:
                    pass

            #
            # We can delete the delID entry from the database only if we can 
            # delete all the files in the delID entry without errors
            #

            if error_cnt == 0:
                try:
                    db.delete_restore_logs_to_delete(record[0])
                    logs.logger.info('Restore Log file for DelID: %s deleted',record[0])
                    
                except psycopg2.OperationalError as e:
                    raise e
                except Exception as e:
                    logs.logger.error('Problems deleting restore logs to delete entry DelID: %s - %s',record[0],e)
                    
    except psycopg2.OperationalError as e:
        raise e
    except Exception as e:
        logs.logger.error('Could not get the restore log to delete information - %s',e)

            
# ############################################
# Function delete_files_from_force_deletes()
# ############################################

def delete_files_from_force_deletes(db,backup_server_id):
    '''Delete dump and log files from force deletions of backup definitions'''

    logs.logger.debug('## Deleting files from forced DefID deletions ##')
    
    try:
        for record in db.get_catalog_entries_to_delete(backup_server_id):
            
            error_cnt = 0

            #
            # record[5...10] are the files to delete
            #

            for index in range(5,11):

                try:

                    if os.path.isfile(record[index]):
                        os.unlink(record[index])
                        logs.logger.debug('File: %s deleted',record[index])

                    elif os.path.isdir(record[index]):
                        shutil.rmtree(record[index])
                        logs.logger.debug('Directory: %s deleted',record[index])
                                                
                except OSError as e:
                    if e.errno != errno.ENOENT:
                        logs.logger.error('Problems deleting files from force deletions of DefIDs: %s',e)
                        error_cnt = error_cnt + 1
                    else:
                        pass


            #
            # We can delete the delID entry from the database only if we can 
            # delete all the files in the delID entry without errors
            #

            if error_cnt == 0:
                try:
                    db.delete_catalog_entries_to_delete(record[0])
                    logs.logger.info('Files for catalog ID: %s / DefID: %s deleted',record[3],record[2])
                    
                except psycopg2.OperationalError as e:
                    raise e
                except Exception as e:
                    logs.logger.error('Problems deleting cataloginfo from force defid deletions - %s',e)
    
    except psycopg2.OperationalError as e:
        raise e
    except Exception as e:
        logs.logger.error('Could not get the catalog information for defid force deletions - %s',e)

            
# ############################################
# Function enforce_backup_retentions()
# ############################################

def enforce_backup_retentions(db,backup_server_id):
    '''Delete dump and log files according to retention_periods and retention_redundancies'''

    logs.logger.debug('## Enforce backup retentions ##')

    try:
        for record in db.get_cron_catalog_entries_to_delete_by_retention(backup_server_id):

            error_cnt = 0
            
            #
            # record[9...14] are the files to delete
            #

            for index in range(9,15):

                 try:

                     if os.path.isfile(record[index]):
                         os.unlink(record[index])
                         logs.logger.debug('File: %s deleted',record[index])

                     elif os.path.isdir(record[index]):
                         shutil.rmtree(record[index])
                         logs.logger.debug('Directory: %s deleted',record[index])
    
                 except OSError as e:
                    if e.errno != errno.ENOENT:
                        logs.logger.error('Problems deleting files from backup enforce retentions: %s',e)
                        error_cnt = error_cnt + 1
                    else:
                        pass
    
            #
            # We can delete the BckID entry from the catalog table only if we can 
            # delete all the files for the BckID entry without errors
            #

            if error_cnt == 0:
                try:
                    db.delete_backup_catalog(record[1])
                    logs.logger.info('Files for catalog ID: %s / DefID: %s deleted',record[1],record[2])

                except psycopg2.OperationalError as e:
                    raise e
                except Exception as e:
                    logs.logger.error('Problems deleting entry from backup job catalog - %s',e)

    except psycopg2.OperationalError as e:
        raise e
    except Exception as e:
        logs.logger.error('Could not get information to enforce backup file retentions - %s',e)
        

# ############################################
# Function enforce_snapshot_retentions()
# ############################################

def enforce_snapshot_retentions(db,backup_server_id):
    '''Delete dump and log snapshot files according to retention_periods'''

    logs.logger.debug('## Enforce snapshot retentions ##')

    try:
        for record in db.get_at_catalog_entries_to_delete_by_retention(backup_server_id):

            error_cnt = 0
            
            #
            # record[7...12] are the files to delete
            #

            for index in range(7,13):

                 try:
                     
                     if os.path.isfile(record[index]):
                         os.unlink(record[index])
                         logs.logger.debug('File: %s deleted',record[index])

                     elif os.path.isdir(record[index]):
                         shutil.rmtree(record[index])
                         logs.logger.debug('Directory: %s deleted',record[index])
    
                 except OSError as e:
                    if e.errno != errno.ENOENT:
                        logs.logger.error('Problems deleting files from snapshot enforce retentions: %s',e)
                        error_cnt = error_cnt + 1
                    else:
                        pass
    
            #
            # We can delete the snapshotID entry from the catalog and definition table only if we can 
            # delete all the files for the SnapshotID entry without errors
            #

            if error_cnt == 0:
                try:
                    db.delete_snapshot_definition(record[1])
                    logs.logger.info('Files for catalog ID: %s / SnapshotID: %s deleted',record[0],record[1])

                except psycopg2.OperationalError as e:
                    raise e
                except Exception as e:
                    logs.logger.error('Problems deleting entry from backup job catalog - %s',e)

    except psycopg2.OperationalError as e:
        raise e
    except Exception as e:
        logs.logger.error('Could not get information to enforce snapshot file retentions - %s',e)
        

# ##################################################
# Function process_pending_backup_catalog_log_file()
# ##################################################

def process_pending_backup_catalog_log_file(db,backup_server_id):
    '''Process all pending backup catalog log files in the server '''

    role_list = []

    logs.logger.debug('## Processing pending backup catalog log files ##')
    
    try:
        db.pg_connect()
        
        root_backup_partition = db.get_backup_server_config_value(backup_server_id,'root_backup_partition')
        pending_catalog = root_backup_partition + '/pending_updates'
        
        for pending_log_file in os.listdir(pending_catalog):
            if pending_log_file.find('backup_jobs_pending_log_updates_nodeid') != -1:
                with open(pending_catalog + '/' + pending_log_file,'r') as pending_file:
                    for line in pending_file:
                        parameters = line.split('::')
                    
                        if len(parameters) == 25:

                            #
                            # Fix when def_id and snapshot_id are like ''. This is not a valid
                            # integer value
                            #

                            def_id = parameters[0]
                            snapshot_id = parameters[21]
                        
                            if def_id == '':
                                def_id = None
                            elif snapshot_id == '':
                                snapshot_id = None
                        
                            # Generate role list    

                            role_list = parameters[22].split(' ')

                            #
                            # Updating the database with the information in the pending file
                            #

                            db.register_backup_catalog(def_id,
                                                       parameters[1],
                                                       parameters[2],
                                                       parameters[3],
                                                       parameters[4],
                                                       parameters[5],
                                                       parameters[6],
                                                       parameters[7],
                                                       parameters[8],
                                                       parameters[9],
                                                       parameters[10],
                                                       parameters[11],
                                                       parameters[12],
                                                       parameters[13],
                                                       parameters[14],
                                                       parameters[15],
                                                       parameters[16],
                                                       parameters[17],
                                                       parameters[18],
                                                       parameters[19],
                                                       parameters[20],
                                                       snapshot_id,
                                                       role_list,
                                                       parameters[23],
                                                       parameters[24].replace('\n',''))

                            logs.logger.info('Backup job catalog for DefID: %s or snapshotID: %s in pending file %s updated in the database',def_id,snapshot_id,pending_log_file)
                            
                            #
                            # Deleting the pending file if we can update the database with
                            # the information in the file
                            #
                        
                            os.unlink(pending_catalog + '/' + pending_log_file)
                            logs.logger.info('Pending backup file: %s deleted',pending_log_file)
                                                        
                        else:
                            logs.logger.error('Wrong format in pending backup file: %s',pending_log_file)

    except psycopg2.OperationalError as e:
        raise e
    except Exception as e:
        logs.logger.error('Problems processing pending backup files - %s',e)


# ##################################################
# Function process_pending_restore_catalog_log_file()
# ##################################################

def process_pending_restore_catalog_log_file(db,backup_server_id):
    '''Process all pending restore catalog log files in the server '''

    role_list = []

    logs.logger.debug('## Processing pending restore catalog log files ##')
    
    try:
        db.pg_connect()
        
        root_backup_partition = db.get_backup_server_config_value(backup_server_id,'root_backup_partition')
        pending_catalog = root_backup_partition + '/pending_updates'
        
        for pending_log_file in os.listdir(pending_catalog):
            if pending_log_file.find('restore_jobs_pending_log_updates_nodeid') != -1:
                with open(pending_catalog + '/' + pending_log_file,'r') as pending_file:
                    for line in pending_file:
                        parameters = line.split('::')
                    
                        if len(parameters) == 17:

                            #
                            # Updating the database with the information in the pending file
                            #

                            db.register_restore_catalog(parameters[0],
                                                        parameters[1],
                                                        parameters[2],
                                                        parameters[3],
                                                        parameters[4],
                                                        parameters[5],
                                                        parameters[6],
                                                        parameters[7],
                                                        parameters[8],
                                                        parameters[9],
                                                        parameters[10],
                                                        parameters[11],
                                                        parameters[12],
                                                        parameters[13],
                                                        parameters[14].split(' '),
                                                        parameters[15],
                                                        parameters[16].replace('\n',''))

                            logs.logger.info('Restore job catalog for restoreDef: %s in pending file %s updated in the database',parameters[0],pending_log_file)
                            
                            #
                            # Deleting the pending file if we can update the database with
                            # the information in the file
                            #
                        
                            os.unlink(pending_catalog + '/' + pending_log_file)
                            logs.logger.info('Pending restore file: %s deleted',pending_log_file)
                                                        
                        else:
                            logs.logger.error('Wrong format in pending restore file: %s',pending_log_file)

    except psycopg2.OperationalError as e:
        raise e
    except Exception as e:
        logs.logger.error('Problems processing pending restore files - %s',e)



# ############################################################
# Function process_backup_definitions_from_deleted_databases()
# ############################################################
    
def process_backup_definitions_from_deleted_databases(db,backup_server_id):
    '''
    This function stops backup definitions for databases that have been deleted
    in the PgSQL nodes running them.     
    '''

    logs.logger.debug('## Processing backup definitions for deleted databases  ##')
    
    #
    # Processing data for all PgSQL nodes with status "RUNNING"
    #

    try:
        for record in db.get_pgsql_nodes_list():

            backup_def_full_list = []
            backup_def_database_list = []
            backup_def_list_to_process = []
            database_list = []
            db_node = None

            pgsql_node_id = record[0]
            pgsql_node_fqdn = record[1]

            logs.logger.debug('Proccesing backup definitions for deleted databases on: %s',pgsql_node_fqdn)

            dsn_value = db.get_pgsql_node_dsn(pgsql_node_id)
            db_node = PgbackmanDB(dsn_value, 'pgbackman_maintenance')
            
            #
            # Get all backup definitions for this Backup server - PgSQL node
            #
            for backup_def_id in db.get_all_backup_definitions(backup_server_id,pgsql_node_id):
                backup_def_full_list.append(backup_def_id[0])

            #
            # Get backup definitions for databases that exist in the PgSQL_node
            #
            
            for database in db_node.get_pgsql_node_database_list():

                for backup_def_id in db.get_database_backup_definitions(backup_server_id,pgsql_node_id,database[0]):
                    backup_def_database_list.append(backup_def_id[0])

            #
            # List of backup definitions to process
            #
            
            backup_def_list_to_process =  set(backup_def_full_list) - set(backup_def_database_list)
            
            #
            # Update the backup def status to "DELETED"
            #

            for backup_def_id in backup_def_list_to_process:

                logs.logger.info('Updating status of bck_def: %s to DELETED',backup_def_id)
                db.update_backup_definition_status_to_delete(int(backup_def_id))

            #
            # Update catalog_entries_to_delete and delete def_id from backup_definition
            #
            # The files associated to the backup definition and the
            # backup definition entry will we deleted if the backup
            # definition got the DELETED status for more than the
            # period of time defined by the parameter
            # automatic_deletion_retention for the PgSQL node that was
            # running the deleted database.
            #
            
            for backup_def_id in db.get_deleted_backup_definitions_to_delete_by_retention():
                try:
                    db.delete_force_backup_definition_id(backup_def_id[0])
                    logs.logger.info('Updating catalog_entries_to_delete for DefID: %s with status DELETED',backup_def_id[0])
                except Exception as e:
                    logs.logger.error('Could not update catalog_entries_to_delete for DefID: %s with status DELETED - %s',backup_def_id[0],e)

    except psycopg2.OperationalError as e:
        raise e
    except Exception as e:
        logs.logger.error('Could not process backup definitions for deleted databases - %s',e)


# ############################################
# Function signal_handler()
# ############################################
    
def signal_handler(signum, frame):
    logs.logger.info('**** pgbackman_maintenance stopped. ****')
    sys.exit(0)


# ############################################
# Function check_database_connection()
# ############################################
  
def check_database_connection(db):
    '''Check if we can connect to the database server and the pgbackman database'''

    try:
        db.pg_connect()
        return True
    except Exception as e:    
        return False


# ############################################
# Function main()
# ############################################

def main():

    conf = PgbackmanConfiguration()
    dsn = conf.dsn

    logs.logger.debug('Backup server ID from config file: %s',conf.backup_server)
    logs.logger.debug('Backup server FQDN: %s',socket.getfqdn())
    logs.logger.debug('DSN: host=%s hostaddr=%s port=%s database=%s user=%s ',conf.dbhost,conf.dbhostaddr,conf.dbport,conf.dbname,conf.dbuser)
    logs.logger.debug('Maintenance interval: %s',conf.maintenance_interval)

    db = PgbackmanDB(dsn, 'pgbackman_maintenance')

    #
    # We check before starting if the database is available. 
    # If it is not available we will wait conf.pg_connect_retry_interval 
    # and try again 

    check_db = check_database_connection(db)

    while not check_db:
        logs.logger.critical('The pgbackman database is not available. Waiting %s seconds before trying again',conf.pg_connect_retry_interval)
        
        time.sleep(conf.pg_connect_retry_interval)
        check_db = check_database_connection(db)
        
    logs.logger.debug('Database server is up and running and pgbackman database is available')

    #
    # Check backup server information
    #

    if conf.backup_server != '':
        backup_server_fqdn = conf.backup_server
    else:
        backup_server_fqdn = socket.getfqdn()

    try:
        backup_server_id = db.get_backup_server_id(backup_server_fqdn)
        logs.logger.info('Backup server: %s is registered in pgbackman',backup_server_fqdn)
            
    except psycopg2.Error as e:
        logs.logger.critical('Cannot find backup server %s in pgbackman. Stopping pgbackman2cron.',backup_server_fqdn)
        logs.logger.info('**** pgbackman_maintenance stopped. ****')
        sys.exit(1)     
    
    loop = 0

    while loop == 0:
        try:
            delete_files_from_force_deletes(db,backup_server_id)
            enforce_backup_retentions(db,backup_server_id)
            enforce_snapshot_retentions(db,backup_server_id)
            delete_restore_logs(db,backup_server_id)
            process_pending_backup_catalog_log_file(db,backup_server_id)
            process_pending_restore_catalog_log_file(db,backup_server_id)
            process_backup_definitions_from_deleted_databases(db,backup_server_id)
    
        except psycopg2.OperationalError as e:

            #
            # If we lose the connection to the database, we will wait conf.pg_connect_retry_interval
            # before trying to connect again. 
            #

            logs.logger.critical('Operational error: %s',e)

            check_db = check_database_connection(db)
            
            while not check_db:
                logs.logger.critical('We have lost the connection to the database. Waiting %s seconds before trying again',conf.pg_connect_retry_interval)
                
                time.sleep(conf.pg_connect_retry_interval)
                check_db = check_database_connection(db)

        if cron:
            loop = 1
        else:
            # Wait for next maintenance run if in loop mode
            time.sleep(conf.maintenance_interval)
    
    db.pg_close()


# ############################################
# 
# ############################################

if __name__ == '__main__':

    logs = PgbackmanLogs("pgbackman_maintenance", "", "")

    signal.signal(signal.SIGINT,signal_handler)
    signal.signal(signal.SIGTERM,signal_handler)

    parser = argparse.ArgumentParser(prog=sys.argv[0])
    parser.add_argument('--cron', required=False, help='Single run to use via cron', action="store_true")

    args = parser.parse_args()    

    logs.logger.info('**** pgbackman_maintenance started. ****')
    
    if args.cron:
        cron = True
        logs.logger.info('Running in cron mode')
    else:
        cron = False
        logs.logger.info('Running in loop mode')

    main()

    logs.logger.info('**** pgbackman_maintenance finished. ****')
