Uploaded image for project: 'MariaDB Server'
  1. MariaDB Server
  2. MDEV-7484

Log Time not consistent with InnoDB errors nor with MySQL error log time format

    XMLWordPrintable

Details

    Description

      After troubleshooting various InnoDB errors, we noticed there was a difference in the log time formats for the InnoDB errors versus the normal error log entries.

      Here are 2 examples:

      150114 16:12:31 [Note] InnoDB: Initializing buffer pool, size = 512.0M
      150114 16:12:31 [Note] InnoDB: Completed initialization of buffer pool
      150114 16:12:31 [Note] InnoDB: Highest supported file format is Barracuda.
      150114 16:12:32 [Note] InnoDB: 128 rollback segment(s) are active.
      150114 16:12:32 [Note] InnoDB: Waiting for purge to start
      150114 16:12:32 [Note] InnoDB: Percona XtraDB (http://www.percona.com) 5.6.21-70.0 started; log sequence number 8733880113
      2015-01-14 16:12:32 7f552c9f8700 InnoDB: Loading buffer pool(s) from .//ib_buffer_pool
      2015-01-14 16:12:32 7f552c9f8700 InnoDB: Cannot open './/ib_buffer_pool' for reading: No such file or directory
      150114 16:12:32 [Note] Plugin 'FEEDBACK' is disabled.
      150114 16:12:32 [ERROR] Failed to create a socket for IPv6 '::': errno: 97.
      150114 16:12:32 [Note] Server socket created on IP: '0.0.0.0'.
      150114 16:12:32 [Note] Event Scheduler: Loaded 0 events
      150114 16:12:32 [Note] /usr/sbin/mysqld: ready for connections.

      150115 19:05:14 [Note] InnoDB: Completed initialization of buffer pool
      150115 19:05:14 [Note] InnoDB: Highest supported file format is Barracuda.
      2015-01-15 19:05:15 468c  InnoDB: Operating system error number 2 in a file operation.
      InnoDB: Some operating system error numbers are described at
      InnoDB: http://dev.mysql.com/doc/refman/5.6/en/operating-system-error-codes.html
      150115 19:05:15 [ERROR] InnoDB: Could not find a valid tablespace file for 'test/t'. See http://dev.mysql.com/doc/refman/5.6/en/innodb-troubleshooting-datadict.html for how to resolve the issue.
      150115 19:05:15 [ERROR] InnoDB: Tablespace open failed for '"test"."t"', ignored.
      150115 19:05:15 [Note] InnoDB: 128 rollback segment(s) are active.
      150115 19:05:15 [Note] InnoDB: Waiting for purge to start

      Long story short, we basically have "2015-01-15 19:05:15" versus "150115 19:05:15".

      The former appears to be what should be correct. This will make reading the error log more consistent, more readable, and in line with how MySQL performs this, as of 5.6.8 or 5.6.9 (and how InnoDB internal errors were already handled). Being consistent will be better for error log parsers as well.

      What needs to change in order to fix this are 2 lines in "sql/log.cc", in function "print_buffer_to_file()", lines 7954 and 7955.

      One needs to replace this:

      fprintf(stderr, "%02d%02d%02d %2d:%02d:%02d [%s] %.*s%.*s\n",
              start->tm_year % 100,

      With:

      fprintf(stderr, "%d-%02d-%02d %2d:%02d:%02d [%s] %.*s%.*s\n",
              start->tm_year + 1900,

      I would like for this to be my first MariaDB patch/code contribution, if accepted, and if possible!

      However, I'm not sure what steps I need to take from here.

      Here is my diff:

      Here is DIFF output:

      c:\mysql\mariadb-10.0.15\sql>diff log.cc log.cc.orig.cc
      7954,7955c7954,7955
      <   fprintf(stderr, "%d-%02d-%02d %2d:%02d:%02d [%s] %.*s%.*s\n",
      <                 start->tm_year + 1900,
      ---
      >   fprintf(stderr, "%02d%02d%02d %2d:%02d:%02d [%s] %.*s%.*s\n",
      >           start->tm_year % 100,

      Btw, I also re-compiled MariaDB and tested, and it works great:

      2015-01-16 22:53:24 [Note] Plugin 'FEEDBACK' is disabled.
      2015-01-16 22:53:24 [Note] Server socket created on IP: '::'.
      2015-01-16 22:53:24 [Note] Event Scheduler: Loaded 0 events
      2015-01-16 22:53:24 [Note] mysqld: ready for connections.

      Please advise what I need to do in order to have this be my first contribution.

      Attachments

        Activity

          People

            jplindst Jan Lindström (Inactive)
            ccalender Chris Calender (Inactive)
            Votes:
            1 Vote for this issue
            Watchers:
            7 Start watching this issue

            Dates

              Created:
              Updated:
              Resolved:

              Git Integration

                Error rendering 'com.xiplink.jira.git.jira_git_plugin:git-issue-webpanel'. Please contact your Jira administrators.