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

Dumping buffer pool noisy in the logs.

Details

    • 10.1.6-1

    Description

      Hi,

      Dumping the buffer pool on shutdown is very noisy when having large buffer pool:

      [...]
      		 
      2015-06-10 15:14:43 140091534046976 [Warning] InnoDB: Dumping buffer pool(s) to .//ib_buffer_pool
      		 
      2015-06-10 15:14:43 140091534046976 [Note] InnoDB: Dumping buffer pool 1/35, page 1/124296
      		 
      2015-06-10 15:14:43 140091534046976 [Note] InnoDB: Dumping buffer pool 1/35, page 129/124296
      		 
      [...]
      		 
      2015-06-10 15:14:45 140091534046976 [Note] InnoDB: Dumping buffer pool 35/35, page 123905/124054
      		 
      2015-06-10 15:14:45 140091534046976 [Note] InnoDB: Dumping buffer pool 35/35, page 124033/124054
      		 
      2015-06-10 15:14:45 140091534046976 [Warning] InnoDB: Buffer pool(s) dump completed at 150610 15:14:45
      		 
      [...]
      		 

      cat mysqld2.log | wc --lines --bytes
      		 
        33824 3241720
      		 

      cat mysqld2.log | grep -v "Dumping buffer pool" | wc --lines --bytes
      		 
           41    3938

      So the logs for the dump account for 3MB and more than 33K lines on a less than 3 seconds dump.

      In 10.0.16, I do not have all those lines when doing MariaDB restart:

      150611 12:50:05 [Note] /usr/sbin/mysqld: Normal shutdown
      		 
      [...]
      		 
      150611 12:50:05 [Note] InnoDB: Starting shutdown...
      		 
      2015-06-11 12:50:06 7ee566df7700 InnoDB: Dumping buffer pool(s) to .//ib_buffer_pool
      		 
      2015-06-11 12:50:09 7ee566df7700 InnoDB: Buffer pool(s) dump completed at 150611 12:50:09
      		 
      [...]
      		 
      150611 12:50:30 [Note] /usr/sbin/mysqld: Shutdown complete
      		 
      [...]
      		 
      150611 12:50:31 mysqld_safe Starting mysqld_wrapper daemon with databases from [...]
      		 
      [...]
      		 
      Version: '10.0.16-MariaDB-log'  socket: 'mysql.sock'  port: 3306  MariaDB Server

      Thanks for looking into that,

      JFG

      Attachments

        Activity

          Ascending order - Click to sort in descending order
          jgagne Jean-François Gagné created issue -
          elenst Elena Stepanova made changes -
          Field Original Value New Value
          Description Hi,

          Dumping the buffer pool on shutdown is very noisy when having large buffer pool:

          [...]
          2015-06-10 15:14:43 140091534046976 [Warning] InnoDB: Dumping buffer pool(s) to .//ib_buffer_pool
          2015-06-10 15:14:43 140091534046976 [Note] InnoDB: Dumping buffer pool 1/35, page 1/124296
          2015-06-10 15:14:43 140091534046976 [Note] InnoDB: Dumping buffer pool 1/35, page 129/124296
          [...]
          2015-06-10 15:14:45 140091534046976 [Note] InnoDB: Dumping buffer pool 35/35, page 123905/124054
          2015-06-10 15:14:45 140091534046976 [Note] InnoDB: Dumping buffer pool 35/35, page 124033/124054
          2015-06-10 15:14:45 140091534046976 [Warning] InnoDB: Buffer pool(s) dump completed at 150610 15:14:45
          [...]

          cat mysqld2.log | wc --lines --bytes
            33824 3241720

          cat mysqld2.log | grep -v "Dumping buffer pool" | wc --lines --bytes
               41 3938

          So the logs for the dump account for 3MB and more than 33K lines on a less than 3 seconds dump.

          In 10.0.16, I do not have all those lines when doing MariaDB restart:

          150611 12:50:05 [Note] /usr/sbin/mysqld: Normal shutdown
          [...]
          150611 12:50:05 [Note] InnoDB: Starting shutdown...
          2015-06-11 12:50:06 7ee566df7700 InnoDB: Dumping buffer pool(s) to .//ib_buffer_pool
          2015-06-11 12:50:09 7ee566df7700 InnoDB: Buffer pool(s) dump completed at 150611 12:50:09
          [...]
          150611 12:50:30 [Note] /usr/sbin/mysqld: Shutdown complete
          [...]
          150611 12:50:31 mysqld_safe Starting mysqld_wrapper daemon with databases from [...]
          [...]
          Version: '10.0.16-MariaDB-log' socket: 'mysql.sock' port: 3306 MariaDB Server

          Thanks for looking into that,

          JFG           		Hi,

          Dumping the buffer pool on shutdown is very noisy when having large buffer pool:

          {noformat}
          [...]
          2015-06-10 15:14:43 140091534046976 [Warning] InnoDB: Dumping buffer pool(s) to .//ib_buffer_pool
          2015-06-10 15:14:43 140091534046976 [Note] InnoDB: Dumping buffer pool 1/35, page 1/124296
          2015-06-10 15:14:43 140091534046976 [Note] InnoDB: Dumping buffer pool 1/35, page 129/124296
          [...]
          2015-06-10 15:14:45 140091534046976 [Note] InnoDB: Dumping buffer pool 35/35, page 123905/124054
          2015-06-10 15:14:45 140091534046976 [Note] InnoDB: Dumping buffer pool 35/35, page 124033/124054
          2015-06-10 15:14:45 140091534046976 [Warning] InnoDB: Buffer pool(s) dump completed at 150610 15:14:45
          [...]
          {noformat}

          {noformat}
          cat mysqld2.log | wc --lines --bytes
            33824 3241720
          {noformat}

          {noformat}
          cat mysqld2.log | grep -v "Dumping buffer pool" | wc --lines --bytes
               41 3938
          {noformat}

          So the logs for the dump account for 3MB and more than 33K lines on a less than 3 seconds dump.

          In 10.0.16, I do not have all those lines when doing MariaDB restart:

          {noformat}
          150611 12:50:05 [Note] /usr/sbin/mysqld: Normal shutdown
          [...]
          150611 12:50:05 [Note] InnoDB: Starting shutdown...
          2015-06-11 12:50:06 7ee566df7700 InnoDB: Dumping buffer pool(s) to .//ib_buffer_pool
          2015-06-11 12:50:09 7ee566df7700 InnoDB: Buffer pool(s) dump completed at 150611 12:50:09
          [...]
          150611 12:50:30 [Note] /usr/sbin/mysqld: Shutdown complete
          [...]
          150611 12:50:31 mysqld_safe Starting mysqld_wrapper daemon with databases from [...]
          [...]
          Version: '10.0.16-MariaDB-log' socket: 'mysql.sock' port: 3306 MariaDB Server
          {noformat}

          Thanks for looking into that,

          JFG
          elenst Elena Stepanova made changes -
          Status Open [ 1 ] Confirmed [ 10101 ]
          elenst Elena Stepanova added a comment -

          It does not happen in 10.0, or MySQL 5.6/5.7, but in 10.1 it happens both with XtraDB and InnoDB.

          elenst Elena Stepanova added a comment - It does not happen in 10.0, or MySQL 5.6/5.7, but in 10.1 it happens both with XtraDB and InnoDB.
          elenst Elena Stepanova made changes -
          Fix Version/s 10.1 [ 16100 ]
          Assignee Jan Lindström [ jplindst ]
          jplindst Jan Lindström (Inactive) made changes -
          Sprint 10.1.6-1 [ 6 ]
          jplindst Jan Lindström (Inactive) made changes -
          Rank Ranked lower
          jplindst Jan Lindström (Inactive) made changes -
          Status Confirmed [ 10101 ] In Progress [ 3 ]
          jplindst Jan Lindström (Inactive) added a comment -

          I will add a way to select how often buffer pool status dump is printed and set default to 0 i.e. only start and end is printed.

          jplindst Jan Lindström (Inactive) added a comment - I will add a way to select how often buffer pool status dump is printed and set default to 0 i.e. only start and end is printed.
          jplindst Jan Lindström (Inactive) added a comment -

          hor: Jan Lindström <jan.lindstrom@mariadb.com>
          Date: Thu Jun 18 08:38:33 2015 +0300

          MDEV-8303; Dumping buffer pool noisy in the logs.

          Added new dynamic configuration variable innodb_buf_dump_status_frequency
          to configure how often buffer pool dump status is printed in the logs.
          A number between [0, 100] that tells how oftern buffer pool dump status
          in percentages should be printed. E.g. 10 means that buffer pool dump
          status is printed when every 10% of number of buffer pool pages are
          dumped. Default is 0 (only start and end status is printed).

          jplindst Jan Lindström (Inactive) added a comment - hor: Jan Lindström <jan.lindstrom@mariadb.com> Date: Thu Jun 18 08:38:33 2015 +0300 MDEV-8303 ; Dumping buffer pool noisy in the logs. Added new dynamic configuration variable innodb_buf_dump_status_frequency to configure how often buffer pool dump status is printed in the logs. A number between [0, 100] that tells how oftern buffer pool dump status in percentages should be printed. E.g. 10 means that buffer pool dump status is printed when every 10% of number of buffer pool pages are dumped. Default is 0 (only start and end status is printed).
          jplindst Jan Lindström (Inactive) made changes -
          Component/s Storage Engine - XtraDB [ 10135 ]
          Fix Version/s 10.1.6 [ 19401 ]
          Fix Version/s 10.1 [ 16100 ]
          Resolution Fixed [ 1 ]
          Status In Progress [ 3 ] Closed [ 6 ]
          serg Sergei Golubchik made changes -
          Workflow MariaDB v3 [ 69889 ] MariaDB v4 [ 149261 ]

          People

            jplindst Jan Lindström (Inactive)
            jgagne Jean-François Gagné
            Votes:
            0 Vote for this issue
            Watchers:
            3 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.