From 62e4e90e2c8876969ea5ef88058421597c636c83 Mon Sep 17 00:00:00 2001 From: Arthur Zakirov Date: Wed, 26 Apr 2017 17:00:06 +0300 Subject: [PATCH] Add log file functions --- Makefile | 6 +- backup.c | 30 ++-- data.c | 10 +- delete.c | 7 +- pg_probackup.c | 18 ++- pg_probackup.h | 4 +- pgut/logger.c | 82 ----------- restore.c | 7 +- utils/logger.c | 288 +++++++++++++++++++++++++++++++++++++ {pgut => utils}/logger.h | 8 +- parray.c => utils/parray.c | 0 parray.h => utils/parray.h | 0 {pgut => utils}/pgut.c | 54 +------ {pgut => utils}/pgut.h | 1 - 14 files changed, 329 insertions(+), 186 deletions(-) delete mode 100644 pgut/logger.c create mode 100644 utils/logger.c rename {pgut => utils}/logger.h (80%) rename parray.c => utils/parray.c (100%) rename parray.h => utils/parray.h (100%) rename {pgut => utils}/pgut.c (97%) rename {pgut => utils}/pgut.h (99%) diff --git a/Makefile b/Makefile index 8030e1e6..3d22f701 100644 --- a/Makefile +++ b/Makefile @@ -8,7 +8,6 @@ OBJS = backup.o \ fetch.o \ help.o \ init.o \ - parray.o \ pg_probackup.o \ restore.o \ show.o \ @@ -20,8 +19,9 @@ OBJS = backup.o \ xlogreader.o \ streamutil.o \ receivelog.o \ - pgut/pgut.o \ - pgut/logger.o + utils/parray.o \ + utils/pgut.o \ + utils/logger.o EXTRA_CLEAN = datapagemap.c datapagemap.h xlogreader.c receivelog.c receivelog.h streamutil.c streamutil.h logging.h diff --git a/backup.c b/backup.c index f502bfd6..ae06605b 100644 --- a/backup.c +++ b/backup.c @@ -276,8 +276,7 @@ do_backup_database(parray *backup_list) char dirpath[MAXPGPATH]; char *dir_name = GetRelativePath(file->path, pgdata); - if (verbose) - elog(LOG, "Create directory \"%s\"", dir_name); + elog(LOG, "Create directory \"%s\"", dir_name); join_path_components(dirpath, database_path, dir_name); dir_create_dir(dirpath, DIR_PERMISSION); @@ -305,8 +304,7 @@ do_backup_database(parray *backup_list) /* Run threads */ for (i = 0; i < num_threads; i++) { - if (verbose) - elog(WARNING, "Start thread num:%li", parray_num(backup_threads_args[i]->backup_files_list)); + elog(LOG, "Start thread num:%li", parray_num(backup_threads_args[i]->backup_files_list)); pthread_create(&backup_threads[i], NULL, (void *(*)(void *)) backup_files, backup_threads_args[i]); } @@ -1157,9 +1155,8 @@ backup_files(void *arg) if (prev_file && false) { file->write_size = BYTES_INVALID; - if (verbose) - elog(LOG, "File \"%s\" has not changed since previous backup", - file->path); + elog(LOG, "File \"%s\" has not changed since previous backup", + file->path); continue; } } @@ -1554,10 +1551,9 @@ stop_streaming(XLogRecPtr xlogpos, uint32 timeline, bool segment_finished) static XLogRecPtr prevpos = InvalidXLogRecPtr; /* we assume that we get called once at the end of each segment */ - if (verbose && segment_finished) - fprintf(stderr, _("%s: finished segment at %X/%X (timeline %u)\n"), - PROGRAM_NAME, (uint32) (xlogpos >> 32), (uint32) xlogpos, - timeline); + if (segment_finished) + elog(LOG, _("finished segment at %X/%X (timeline %u)\n"), + (uint32) (xlogpos >> 32), (uint32) xlogpos, timeline); /* * Note that we report the previous, not current, position here. After a @@ -1568,9 +1564,8 @@ stop_streaming(XLogRecPtr xlogpos, uint32 timeline, bool segment_finished) * timeline, but it's close enough for reporting purposes. */ if (prevtimeline != 0 && prevtimeline != timeline) - fprintf(stderr, _("%s: switched to timeline %u at %X/%X\n"), - PROGRAM_NAME, timeline, - (uint32) (prevpos >> 32), (uint32) prevpos); + elog(LOG, _("switched to timeline %u at %X/%X\n"), + timeline, (uint32) (prevpos >> 32), (uint32) prevpos); if (stop_backup_lsn != InvalidXLogRecPtr && xlogpos > stop_backup_lsn) return true; @@ -1637,11 +1632,8 @@ StreamLog(void *arg) /* * Start the replication */ - if (verbose) - fprintf(stderr, - _("%s: starting log streaming at %X/%X (timeline %u)\n"), - PROGRAM_NAME, (uint32) (startpos >> 32), (uint32) startpos, - starttli); + elog(LOG, _("starting log streaming at %X/%X (timeline %u)\n"), + (uint32) (startpos >> 32), (uint32) startpos, starttli); #if PG_VERSION_NUM >= 90600 { diff --git a/data.c b/data.c index c44873e0..562e123d 100644 --- a/data.c +++ b/data.c @@ -119,9 +119,8 @@ backup_data_page(pgFile *file, XLogRecPtr prev_backup_start_lsn, /* Try to read and verify this page again several times. */ if (try_checksum) { - if (verbose) - elog(WARNING, "File: %s blknum %u have wrong page header, try again", - file->path, blknum); + elog(WARNING, "File: %s blknum %u have wrong page header, try again", + file->path, blknum); usleep(100); continue; } @@ -150,9 +149,8 @@ backup_data_page(pgFile *file, XLogRecPtr prev_backup_start_lsn, { if (try_checksum) { - if (verbose) - elog(WARNING, "File: %s blknum %u have wrong checksum, try again", - file->path, blknum); + elog(WARNING, "File: %s blknum %u have wrong checksum, try again", + file->path, blknum); usleep(100); } else diff --git a/delete.c b/delete.c index 55118fc3..db748bd7 100644 --- a/delete.c +++ b/delete.c @@ -356,8 +356,7 @@ delete_walfiles(XLogRecPtr oldest_lsn, TimeLineID oldest_tli, bool delete_all) wal_file, strerror(errno)); break; } - if (verbose) - elog(LOG, "removed WAL segment \"%s\"", wal_file); + elog(LOG, "removed WAL segment \"%s\"", wal_file); if (max_wal_file[0] == '\0' || strcmp(max_wal_file + 8, arcde->d_name + 8) < 0) @@ -370,9 +369,9 @@ delete_walfiles(XLogRecPtr oldest_lsn, TimeLineID oldest_tli, bool delete_all) } } - if (!verbose && min_wal_file[0] != '\0') + if (min_wal_file[0] != '\0') elog(INFO, "removed min WAL segment \"%s\"", min_wal_file); - if (!verbose && max_wal_file[0] != '\0') + if (max_wal_file[0] != '\0') elog(INFO, "removed max WAL segment \"%s\"", max_wal_file); if (errno) diff --git a/pg_probackup.c b/pg_probackup.c index deb2934b..a2b17b68 100644 --- a/pg_probackup.c +++ b/pg_probackup.c @@ -98,8 +98,6 @@ static pgut_option options[] = { 's', 'h', "pghost" , &host, SOURCE_CMDLINE }, { 's', 'p', "pgport" , &port, SOURCE_CMDLINE }, { 's', 'U', "pguser" , &username, SOURCE_CMDLINE }, - { 'b', 'q', "quiet" , &quiet, SOURCE_CMDLINE }, - { 'b', 'v', "verbose" , &verbose, SOURCE_CMDLINE }, { 'B', 'w', "no-password" , &prompt_password, SOURCE_CMDLINE }, { 0 } }; @@ -197,6 +195,13 @@ main(int argc, char *argv[]) pgut_getopt_env(options); } + /* + * We read backup path from command line or from configuration file. + * Do final check. + */ + if (!is_absolute_path(backup_path)) + elog(ERROR, "-B, --backup-path must be an absolute path"); + if (backup_id_string_param != NULL) { current.backup_id = base36dec(backup_id_string_param); @@ -204,7 +209,7 @@ main(int argc, char *argv[]) elog(ERROR, "Invalid backup-id"); } - /* setup stream options */ + /* Setup stream options. They are used in streamutil.c. */ if (pgut_dbname != NULL) dbname = pstrdup(pgut_dbname); if (host != NULL) @@ -214,9 +219,10 @@ main(int argc, char *argv[]) if (username != NULL) dbuser = pstrdup(username); - /* path must be absolute */ - if (!is_absolute_path(backup_path)) - elog(ERROR, "-B, --backup-path must be an absolute path"); + /* + * We read pgdata path from command line or from configuration file. + * Do final check. + */ if (pgdata != NULL && !is_absolute_path(pgdata)) elog(ERROR, "-D, --pgdata must be an absolute path"); diff --git a/pg_probackup.h b/pg_probackup.h index 33a6a8a5..9b96a5cd 100644 --- a/pg_probackup.h +++ b/pg_probackup.h @@ -28,10 +28,10 @@ #include "storage/checksum.h" #include "utils/pg_crc.h" -#include "pgut/pgut.h" +#include "utils/parray.h" +#include "utils/pgut.h" #include "datapagemap.h" -#include "parray.h" /* Directory/File names */ diff --git a/pgut/logger.c b/pgut/logger.c deleted file mode 100644 index 05be2fd3..00000000 --- a/pgut/logger.c +++ /dev/null @@ -1,82 +0,0 @@ -/*------------------------------------------------------------------------- - * - * logger.c: - log events into csv-file or stderr. - * - * Portions Copyright (c) 2017-2017, Postgres Professional - * - *------------------------------------------------------------------------- - */ - -#include "postgres_fe.h" - -#include "logger.h" - -/* Logger parameters */ - -int log_destination = LOG_DESTINATION_STDERR; -int log_level = INFO; -bool quiet = false; - -char *log_filename = NULL; -char *log_error_filename = NULL; -char *log_directory = NULL; - -int log_rotation_size = 0; -int log_rotation_age = 0; - -/* - * elog - log to stderr or to log file and exit if ERROR or FATAL - */ -void -elog(int elevel, const char *fmt, ...) -{ - va_list args; - - /* Do not log message if severity level is less than log_level */ - if (elevel < log_level) - { - /* But exit with code it severity level is higher than WARNING */ - if (elevel > WARNING) - exit(elevel); - - return; - } - - if (quiet && elevel < WARNING) - return; - - switch (elevel) - { - case LOG: - fputs("LOG: ", stderr); - break; - case INFO: - fputs("INFO: ", stderr); - break; - case NOTICE: - fputs("NOTICE: ", stderr); - break; - case WARNING: - fputs("WARNING: ", stderr); - break; - case FATAL: - fputs("FATAL: ", stderr); - break; - case PANIC: - fputs("PANIC: ", stderr); - break; - default: - if (elevel >= ERROR) - fputs("ERROR: ", stderr); - break; - } - - va_start(args, fmt); - vfprintf(stderr, fmt, args); - fputc('\n', stderr); - fflush(stderr); - va_end(args); - - if (elevel > WARNING) - exit(elevel); -} diff --git a/restore.c b/restore.c index 617cdb4f..ba98b794 100644 --- a/restore.c +++ b/restore.c @@ -332,8 +332,7 @@ restore_backup(pgBackup *backup) arg->files = files; arg->backup = backup; - if (verbose) - elog(LOG, "Start thread for num:%li", parray_num(files)); + elog(LOG, "Start thread for num:%li", parray_num(files)); restore_threads_args[i] = arg; pthread_create(&restore_threads[i], NULL, (void *(*)(void *)) restore_files, arg); @@ -350,7 +349,7 @@ restore_backup(pgBackup *backup) parray_walk(files, pgFileFree); parray_free(files); - if (verbose) + if (log_level <= LOG) { char *backup_id; @@ -395,7 +394,7 @@ remove_deleted_files(pgBackup *backup) if (parray_bsearch(files, file, pgFileComparePathDesc) == NULL) { pgFileDelete(file); - if (verbose) + if (log_level <= LOG) elog(LOG, "deleted %s", GetRelativePath(file->path, pgdata)); } } diff --git a/utils/logger.c b/utils/logger.c new file mode 100644 index 00000000..626c8fbf --- /dev/null +++ b/utils/logger.c @@ -0,0 +1,288 @@ +/*------------------------------------------------------------------------- + * + * logger.c: - log events into log file or stderr. + * + * Portions Copyright (c) 2017-2017, Postgres Professional + * + *------------------------------------------------------------------------- + */ + +#include "postgres_fe.h" +#include "pgtime.h" + +#include +#include +#include +#include +#include + +#include "logger.h" + +/* Logger parameters */ + +int log_level = INFO; + +char *log_filename = NULL; +char *error_log_filename = NULL; +char *log_directory = NULL; + +int log_rotation_size = 0; +int log_rotation_age = 0; + +/* Implementation for logging.h */ + +typedef enum +{ + PG_DEBUG, + PG_PROGRESS, + PG_WARNING, + PG_FATAL +} eLogType; + +void pg_log(eLogType type, const char *fmt,...) pg_attribute_printf(2, 3); + +static void elog_internal(int elevel, const char *fmt, va_list args) + pg_attribute_printf(2, 0); + +/* Functions to work with log files */ +static void open_logfile(void); +static void release_logfile(void); +static char *logfile_getname(pg_time_t timestamp); +static FILE *logfile_open(const char *filename, const char *mode); + +/* Static variables */ + +static FILE *log_file = NULL; +static char *last_file_name = NULL; +static bool exit_hook_registered = false; +/* Logging to file is in progress */ +static bool logging_to_file = false; + +static pthread_mutex_t log_file_mutex = PTHREAD_MUTEX_INITIALIZER; + +/* + * Logs to stderr or to log file and exit if ERROR or FATAL. + * + * Actual implementation for elog() and pg_log(). + */ +static void +elog_internal(int elevel, const char *fmt, va_list args) +{ + bool wrote_to_file = false; + + switch (elevel) + { + case LOG: + fputs("LOG: ", stderr); + break; + case INFO: + fputs("INFO: ", stderr); + break; + case NOTICE: + fputs("NOTICE: ", stderr); + break; + case WARNING: + fputs("WARNING: ", stderr); + break; + case ERROR: + fputs("ERROR: ", stderr); + break; + case FATAL: + fputs("FATAL: ", stderr); + break; + case PANIC: + fputs("PANIC: ", stderr); + break; + default: + elog(ERROR, "invalid logging level: %d", elevel); + break; + } + + pthread_mutex_lock(&log_file_mutex); + + /* + * Write message to log file. + * Do not write to file if this error was raised during write previous + * message. + */ + if (log_filename && !logging_to_file) + { + logging_to_file = true; + + if (log_file == NULL) + open_logfile(); + + vfprintf(log_file, fmt, args); + fputc('\n', log_file); + fflush(log_file); + + logging_to_file = false; + wrote_to_file = true; + } + + /* + * Write to stderr if the message was not written to log file. + * Write to stderr if the message level is greater than WARNING anyway. + */ + if (!wrote_to_file || + elevel >= ERROR) + { + vfprintf(stderr, fmt, args); + fputc('\n', stderr); + fflush(stderr); + } + + pthread_mutex_unlock(&log_file_mutex); + + /* Exit with code if it is an error */ + if (elevel > WARNING) + exit(elevel); +} + +/* + * Logs to stderr or to log file and exit if ERROR or FATAL. + */ +void +elog(int elevel, const char *fmt, ...) +{ + va_list args; + + /* + * Do not log message if severity level is less than log_level. + * It is the little optimisation to put it here not in elog_internal(). + */ + if (elevel < log_level && elevel < ERROR) + return; + + va_start(args, fmt); + elog_internal(elevel, fmt, args); + va_end(args); +} + +/* + * Implementation of pg_log() from logging.h. + */ +void +pg_log(eLogType type, const char *fmt, ...) +{ + va_list args; + int elevel; + + /* Transform logging level from eLogType to utils/logger.h levels */ + switch (type) + { + case PG_DEBUG: + elevel = LOG; + break; + case PG_PROGRESS: + elevel = INFO; + break; + case PG_WARNING: + elevel = WARNING; + break; + case PG_FATAL: + elevel = ERROR; + break; + } + + /* + * Do not log message if severity level is less than log_level. + * It is the little optimisation to put it here not in elog_internal(). + */ + if (elevel < log_level && elevel < ERROR) + return; + + va_start(args, fmt); + elog_internal(elevel, fmt, args); + va_end(args); +} + +/* + * Construct logfile name using timestamp information. + * + * Result is palloc'd. + */ +static char * +logfile_getname(pg_time_t timestamp) +{ + char *filename; + size_t len; + + filename = (char *) palloc(MAXPGPATH); + + snprintf(filename, MAXPGPATH, "%s/", log_directory); + + len = strlen(filename); + + /* treat pgaudit.log_filename as a strftime pattern */ + pg_strftime(filename + len, MAXPGPATH - len, log_filename, + pg_localtime(×tamp, log_timezone)); + + return filename; +} + +/* + * Open a new log file. + */ +static FILE * +logfile_open(const char *filename, const char *mode) +{ + FILE *fh; + + fh = fopen(filename, mode); + + if (fh) + setvbuf(fh, NULL, PG_IOLBF, 0); + else + { + int save_errno = errno; + + elog(FATAL, "could not open log file \"%s\": %s", + filename, strerror(errno)); + errno = save_errno; + } + + return fh; +} + +/* + * Open the log file. + */ +static void +open_logfile(void) +{ + char *filename; + + filename = logfile_getname(time(NULL)); + + log_file = logfile_open(filename, "a"); + + if (last_file_name != NULL) /* probably shouldn't happen */ + pfree(last_file_name); + + last_file_name = filename; + + /* + * Arrange to close opened file at proc_exit. + */ + if (!exit_hook_registered) + { + atexit(release_logfile); + exit_hook_registered = true; + } +} + +/* + * Closes opened file. + */ +static void +release_logfile(void) +{ + if (log_file) + { + fclose(log_file); + log_file = NULL; + } + if (last_file_name != NULL) + pfree(last_file_name); +} diff --git a/pgut/logger.h b/utils/logger.h similarity index 80% rename from pgut/logger.h rename to utils/logger.h index bd2c3add..1e46136a 100644 --- a/pgut/logger.h +++ b/utils/logger.h @@ -10,10 +10,6 @@ #ifndef LOGGER_H #define LOGGER_H -/* Log destination bitmap */ -#define LOG_DESTINATION_STDERR 1 -#define LOG_DESTINATION_LOGFILE 2 - /* Log level */ #define VERBOSE (-5) #define LOG (-4) @@ -26,12 +22,10 @@ /* Logger parameters */ -extern int log_destination; extern int log_level; -extern bool quiet; extern char *log_filename; -extern char *log_error_filename; +extern char *error_log_filename; extern char *log_directory; extern int log_rotation_size; diff --git a/parray.c b/utils/parray.c similarity index 100% rename from parray.c rename to utils/parray.c diff --git a/parray.h b/utils/parray.h similarity index 100% rename from parray.h rename to utils/parray.h diff --git a/pgut/pgut.c b/utils/pgut.c similarity index 97% rename from pgut/pgut.c rename to utils/pgut.c index 77396c72..90e22686 100644 --- a/pgut/pgut.c +++ b/utils/pgut.c @@ -34,7 +34,6 @@ const char *host = NULL; const char *port = NULL; const char *username = NULL; char *password = NULL; -bool verbose = false; bool prompt_password = true; /* Database connections */ @@ -46,16 +45,6 @@ static bool in_cleanup = false; static bool parse_pair(const char buffer[], char key[], char value[]); -typedef enum -{ - PG_DEBUG, - PG_PROGRESS, - PG_WARNING, - PG_FATAL -} eLogType; - -void pg_log(eLogType type, const char *fmt,...) pg_attribute_printf(2, 3); - /* Connection routines */ static void init_cancel_handler(void); static void on_before_exec(PGconn *conn); @@ -896,7 +885,7 @@ pgut_execute(PGconn* conn, const char *query, int nParams, const char **params) elog(ERROR, "interrupted"); /* write query to elog if verbose */ - if (verbose) + if (log_level <= LOG) { int i; @@ -945,7 +934,7 @@ pgut_send(PGconn* conn, const char *query, int nParams, const char **params, int elog(ERROR, "interrupted"); /* write query to elog if verbose */ - if (verbose) + if (log_level <= LOG) { int i; @@ -1032,45 +1021,6 @@ pgut_wait(int num, PGconn *connections[], struct timeval *timeout) return -1; } -void pg_log(eLogType type, const char *fmt, ...) -{ - va_list args; - - if (!verbose && type <= PG_PROGRESS) - return; - if (quiet && type < PG_WARNING) - return; - - switch (type) - { - case PG_DEBUG: - fputs("DEBUG: ", stderr); - break; - case PG_PROGRESS: - fputs("PROGRESS: ", stderr); - break; - case PG_WARNING: - fputs("WARNING: ", stderr); - break; - case PG_FATAL: - fputs("FATAL: ", stderr); - break; - default: - if (type >= PG_FATAL) - fputs("ERROR: ", stderr); - break; - } - - va_start(args, fmt); - vfprintf(stderr, fmt, args); - fputc('\n', stderr); - fflush(stderr); - va_end(args); - - if (type > 0) - exit_or_abort(type); -} - #ifdef WIN32 static CRITICAL_SECTION cancelConnLock; #endif diff --git a/pgut/pgut.h b/utils/pgut.h similarity index 99% rename from pgut/pgut.h rename to utils/pgut.h index 0f0faefb..7b188d4d 100644 --- a/pgut/pgut.h +++ b/utils/pgut.h @@ -85,7 +85,6 @@ extern const char *host; extern const char *port; extern const char *username; extern char *password; -extern bool verbose; extern bool prompt_password; extern bool interrupted;