Bug #6061 mysql-log-rotate script - error logging doesn't use new file
Submitted: 13 Oct 2004 11:53 Modified: 18 May 2006 13:21
Reporter: John Van Essen Email Updates:
Status: Closed Impact on me:
None 
Category:MySQL Server Severity:S4 (Feature request)
Version:4.0.18 OS:Linux (RedHat/Fedora)
Assigned to: Timothy Smith CPU Architecture:Any

[13 Oct 2004 11:53] John Van Essen
Description:
The mysql-log-rotate script does not have the intended effect.

After logrotate has moved the existing log to *.1 and created a new log file, it executes a "mysqladmin flush-logs" command, expecting mysqld to close its error log and reopen it, thus shifting from what is now the *.1 log back to the basename log.  However...

If mysqld_safe is being used (which is the standard installation on Linux) the error messages from mysqld go to stderr, which is redirected to the error log file by mysqld_safe.  Thus, the "mysqladmin flush-logs" command in the postrotate script has no effect, and the originally opened file (which is now *.1) continues to receive mysqld error messages.  Only a restart (stop/start) of mysqld_safe will cause it to use the new log file.

If mysqld_safe is not used and --log-error is used, then according to chapter 5.9.1, a flush logs will renamed the file to *-old and create a new file.  Also undesirable behavior in this case.

How to repeat:
This section intentionally left blank as it doesn't apply.

Suggested fix:
Provide an option to tell mysqld to not rotate the error log when a flush logs is done.  Then mysqld_safe can pass a --log-error option to mysqld, and a flush-logs should just close the error log and re-open it for appending.

Or, provide an option to tell mysqld to not keep the error log open.  mysqld would then open and close the logfile upon each instance of error message appending.  Then flush-logs would have no effect and would not be needed in the mysql-log-rotate script.

In either case, mysqld_safe should then pass --log-error={filename} to mysqld when it starts up and thus avoid the redirection that prevents error log rotation.
[15 Mar 2006 17:35] Peter Leonard
This has been silent for 18 months now, but I need to second this as a major issue.

Logfile rotation scripts are used heavily in any production environment, and it's impossible to safely rotate the mysqld.log files.  Shutting down the database (something proposed to me by Redhat support) is not an option (and should never be considered as one).

This is still broken.  Please take some time to fix it.
[24 Mar 2006 4:20] Brad Rubenstein
I still see no way to rotate /var/lib/mysql/mysqld.log in MySQL-server-4.1.15-0.glibc23 using the instructions embedded in /etc/logrotate.d/mysql.  Binary logs get rotated, error log does not (it gets renamed, but the output continues going to the old log file).
[30 Mar 2006 1:24] Timothy Smith
Hi.  I can verify that FLUSH LOGS does not behave properly when --log-error=<something> is passed to mysqld_safe.  The problem is with the mysqld_safe shell script, not with mysqld itself.

Here is a patch (not approved yet) which solves the problem (and makes argument passing a bit more robust in general, while I'm there).  It also makes the file name relative to the data directory, if it is not an absolute path.  I.e., --log-error=error-log.txt will use /path/to/your/data-directory/error-log.txt.  The current behavior, which isn't correct, is to create the file relative to the current working directory from which mysqld_safe was run.

--- bin/mysqld_safe.orig        Wed Mar 29 17:25:26 2006
+++ bin/mysqld_safe     Wed Mar 29 18:17:48 2006
@@ -46,6 +46,11 @@
         exit 1
 }
 
+shell_quote_string() {
+  # This sed command makes sure that any special chars are quoted,
+  # so the arg gets passed exactly to the server.
+  echo "$1" | sed -e 's,\([^a-zA-Z0-9/_.=-]\),\\\1,g'
+}
 
 parse_arguments() {
   # We only need to pass arguments through to the server if we don't
@@ -97,9 +102,7 @@
       *)
         if test -n "$pick_args"
         then
-          # This sed command makes sure that any special chars are quoted,
-          # so the arg gets passed exactly to the server.
-          args="$args "`echo "$arg" | sed -e 's,\([^a-zA-Z0-9_.-]\),\\\\\1,g'`
+          append_arg_to_args "$arg"
         fi
         ;;
     esac
@@ -194,6 +197,14 @@
   print_defaults="my_print_defaults"
 fi
 
+append_arg_to_args () {
+  args="$args "`shell_quote_string "$1"`
+}
+
+prepend_arg_to_args () {
+  args=`shell_quote_string "$1"`" $args"
+}
+
 args=
 SET_USER=2
 parse_arguments `$print_defaults $defaults --loose-verbose mysqld server`
@@ -244,15 +255,30 @@
     * )  pid_file="$DATADIR/$pid_file" ;;
   esac
 fi
-test -z "$err_log"  && err_log=$DATADIR/`/bin/hostname`.err
+
+if [ -z "$err_log" ]
+then
+  # Note: --log-error is not given to mysqld, because it was not specified on
+  # command line / options file.
+  err_log=$DATADIR/`/bin/hostname`.err
+else
+  case "$err_log" in
+    /* ) ;;
+    * ) err_log="$DATADIR/$err_log" ;;
+  esac
+
+  # Pass this option along to mysqld, so that the error log can be rotated
+  # by FLUSH LOGS
+  append_arg_to_args "--log-error=$err_log"
+fi
 
 if test -n "$mysql_unix_port"
 then
-  args="--socket=$mysql_unix_port $args"
+  prepend_arg_to_args "--socket=$mysql_unix_port"
 fi
 if test -n "$mysql_tcp_port"
 then
-  args="--port=$mysql_tcp_port $args"
+  prepend_arg_to_args "--port=$mysql_tcp_port"
 fi
 
 if test $niceness -eq 0
@@ -319,7 +345,7 @@
   if test -n "$open_files"
   then
     ulimit -n $open_files
-    args="--open-files-limit=$open_files $args"
+    prepend_arg_to_args "--open-files-limit=$open_files"
   fi
   if test -n "$core_file_size"
   then
@@ -377,12 +403,16 @@
 while true
 do
   rm -f $safe_mysql_unix_port $pid_file        # Some extra safety
-  if test -z "$args"
-  then
-    $NOHUP_NICENESS $ledir/$MYSQLD $defaults --basedir=$MY_BASEDIR_VERSION --da
tadir=$DATADIR $USER_OPTION --pid-file=$pid_file  >> $err_log 2>&1
-  else
-    eval "$NOHUP_NICENESS $ledir/$MYSQLD $defaults --basedir=$MY_BASEDIR_VERSIO
N --datadir=$DATADIR $USER_OPTION --pid-file=$pid_file  $args >> $err_log 2>&1"
-  fi
+
+  cmd=
+  for i in "$NOHUP_NICENESS" "$ledir/$MYSQLD" "$defaults" "--basedir=$MY_BASEDI
R_VERSION" "--datadir=$DATADIR" "$USER_OPTION" "--pid-file=$pid_file"
+  do
+    cmd="$cmd "`shell_quote_string "$i"`
+  done
+  cmd="$cmd $args >> "`shell_quote_string "$err_log"`" 2>&1"
+  #echo "Running mysqld: [$cmd]"
+  eval "$cmd"
+
   if test ! -f $pid_file               # This is removed if normal shutdown
   then
     echo "STOPPING server from pid file $pid_file"

Regards,

Timothy
[30 Mar 2006 8:25] Bugs System
A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/commits/4314
[6 Apr 2006 17:36] Timothy Smith
Oops, the patch I posted is broken for systems that use NOHUP_NICENESS.  That variable should *not* be quoted as shown.

The critical change is the following:

+  cmd="$NOHUP_NICENESS"
+
+  for i in  "$ledir/$MYSQLD" "$defaults" "--basedir=$MY_BASEDIR_VERSION" "--datadir=$DATADIR" "$USER_OPTION" "--pid-file=$pid_file"
+  do

That is, do *not* apply shell_quote_string to $NOHUP_NICENESS.

Regards,

Timothy
[6 May 2006 1:42] Bugs System
A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/commits/6035
[10 May 2006 17:33] Bugs System
A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/commits/6210
[12 May 2006 18:38] Timothy Smith
Fix for this pushed to MySQL 5.1 tree; will be included in 5.1.11.

The following problems with mysqld_safe were fixed:
- The --log-error argument was not handled consistently.  If a file name was given, mysqld_safe swallowed the argument, and did not pass it on to mysqld.  So mysqld wrote all error info to its stderr, and was unable to rotate the error log file when FLUSH LOGS was given.
- mysqld adds ".err" to the end of the --log-error=fname argument, if fname doesn't already have an extension.  mysqld_safe didn't do this, so it was possible that mysqld_safe would write to 'foo', but mysqld would write to 'foo.err'.
- mysqld treats file names relative to its datadir; mysqld_safe treated the --log-error argument relative to its current working directory.
- Some arguments to mysqld_safe were not being quoted properly; e.g., a data directory with a space in the path name could get mangled when starting mysqld.
[12 May 2006 18:40] Timothy Smith
I forgot to mention; this was fixed in the 5.1 tree, but not in 5.0 or earlier.  The same problems exist in 5.0 and earlier, but since this changes behavior, it was decided to not apply the fix there.

The 5.1 mysqld_safe can be copied into a 5.0 or earlier installation, if a workaround is needed.
[18 May 2006 13:21] Paul DuBois
Noted in 5.0.11 changelog.
[22 May 2006 5:37] Timothy Smith
I believe Paul meant to type "5.1.11".
[4 Jun 2007 15:09] Ralf Hauser
it would be great if the disappearing log files could not just be "unlinked" as inodes, but for security, it should be possible to optionally first have a wipe as in http://wipe.sourceforge.net/ on them!
[23 Jul 2007 9:47] Marinus Schraal
The mysqld_safe script from 5.1.20 does not fix this problem in the 5.0 series as suggested in the comment on the 12th of May. Any other suggestions ?
[10 May 2012 8:17] Honza Horak
Hi, I have some doubts about the commit http://lists.mysql.com/commits/6210. I'd appreciate if you could answer the following, even the bug is a bit older.

[12 May 2006 18:40] Timothy Smith wrote:
> I forgot to mention; this was fixed in the 5.1 tree, but not in 5.0 or earlier.  The same problems exist in 5.0 and earlier, but since this changes behavior, it was decided to not apply the fix there.

What behaviour exactly is different? I only see a difference in the .err extension to the error-log filename. Are there any other changes in behaviour?

And second, what happened with @MYSQLD_DEFAULT_SWITCHES@ in the evaluated command? The patch from commit http://lists.mysql.com/commits/6210 simply removes it. Was this intentional or an error?