From e640361c9a1461d33cb7f09da7586c8addbbab36 Mon Sep 17 00:00:00 2001 From: Davi Arnaut Date: Thu, 21 Jun 2012 13:17:49 -0700 Subject: [PATCH 1/9] Print ISO date and PID with all error log messages. The problem is that the currently available fields that compromise the header of error log messages, which are the date and time, plus the severity of the message, do not provide the enough information to identify discontinuity in reporting or which process generated a message. To make such identification possible, this change includes the process ID in the header so that any changes in its value will identify the source (process) of the message and also indicate any discontinuity in reporting. Additionally, the format of the date and time is changed to the ISO format (YYYY-MM-DD hh:mm:ss). The previous format was non-standard and difficult to read. --- sql/log.cc | 7 ++++--- storage/innobase/log/log0log.c | 2 +- storage/innobase/srv/srv0start.c | 2 +- storage/innobase/ut/ut0ut.c | 18 ++++++++++++------ 4 files changed, 18 insertions(+), 11 deletions(-) diff --git a/sql/log.cc b/sql/log.cc index 54112b1..c094437 100644 --- a/sql/log.cc +++ b/sql/log.cc @@ -5891,13 +5891,14 @@ static void print_buffer_to_file(enum loglevel level, const char *buffer, localtime_r(&skr, &tm_tmp); start=&tm_tmp; - fprintf(stderr, "%02d%02d%02d %2d:%02d:%02d [%s] %.*s\n", - start->tm_year % 100, - start->tm_mon+1, + fprintf(stderr, "%d-%02d-%02d %02d:%02d:%02d %lu [%s] %.*s\n", + start->tm_year + 1900, + start->tm_mon + 1, start->tm_mday, start->tm_hour, start->tm_min, start->tm_sec, + current_pid, (level == ERROR_LEVEL ? "ERROR" : level == WARNING_LEVEL ? "Warning" : "Note"), (int) length, buffer); diff --git a/storage/innobase/log/log0log.c b/storage/innobase/log/log0log.c index 72da8f8..c90e749 100644 --- a/storage/innobase/log/log0log.c +++ b/storage/innobase/log/log0log.c @@ -3087,7 +3087,7 @@ logs_empty_and_mark_files_at_shutdown(void) if (srv_print_verbose_log) { ut_print_timestamp(stderr); - fprintf(stderr, " InnoDB: Starting shutdown...\n"); + fprintf(stderr, " InnoDB: Starting shutdown...\n"); } /* Wait until the master thread and all other operations are idle: our algorithm only works if the server is idle at shutdown */ diff --git a/storage/innobase/srv/srv0start.c b/storage/innobase/srv/srv0start.c index 47145e1..ca0416c 100644 --- a/storage/innobase/srv/srv0start.c +++ b/storage/innobase/srv/srv0start.c @@ -2269,7 +2269,7 @@ innobase_shutdown_for_mysql(void) if (srv_print_verbose_log) { ut_print_timestamp(stderr); fprintf(stderr, - " InnoDB: Shutdown completed;" + " InnoDB: Shutdown completed;" " log sequence number %llu\n", srv_shutdown_lsn); } diff --git a/storage/innobase/ut/ut0ut.c b/storage/innobase/ut/ut0ut.c index a9da6a6..2dbbfd8 100644 --- a/storage/innobase/ut/ut0ut.c +++ b/storage/innobase/ut/ut0ut.c @@ -39,6 +39,8 @@ Created 5/11/1994 Heikki Tuuri # include "mysql_com.h" /* NAME_LEN */ #endif /* UNIV_HOTBACKUP */ +#include "os0proc.h" /* os_proc_get_number */ + /** A constant to prevent the compiler from optimizing ut_delay() away. */ UNIV_INTERN ibool ut_always_false = FALSE; @@ -232,18 +234,21 @@ ut_print_timestamp( /*===============*/ FILE* file) /*!< in: file where to print */ { + ulint proc_number = os_proc_get_number(); + #ifdef __WIN__ SYSTEMTIME cal_tm; GetLocalTime(&cal_tm); - fprintf(file,"%02d%02d%02d %2d:%02d:%02d", - (int)cal_tm.wYear % 100, + fprintf(file, "%d-%02d-%02d %02d:%02d:%02d %lu", + (int)cal_tm.wYear, (int)cal_tm.wMonth, (int)cal_tm.wDay, (int)cal_tm.wHour, (int)cal_tm.wMinute, - (int)cal_tm.wSecond); + (int)cal_tm.wSecond, + proc_number); #else struct tm cal_tm; struct tm* cal_tm_ptr; @@ -257,13 +262,14 @@ ut_print_timestamp( #else cal_tm_ptr = localtime(&tm); #endif - fprintf(file,"%02d%02d%02d %2d:%02d:%02d", - cal_tm_ptr->tm_year % 100, + fprintf(file, "%d-%02d-%02d %02d:%02d:%02d %lu", + cal_tm_ptr->tm_year + 1900, cal_tm_ptr->tm_mon + 1, cal_tm_ptr->tm_mday, cal_tm_ptr->tm_hour, cal_tm_ptr->tm_min, - cal_tm_ptr->tm_sec); + cal_tm_ptr->tm_sec, + proc_number); #endif } -- 1.7.4.4