Details

    • Bug
    • Status: Closed (View Workflow)
    • Major
    • Resolution: Fixed
    • 10.3.10, 10.3(EOL), 10.4(EOL)
    • 10.3.15, 10.4.5
    • Server
    • None
    • CentOs 7.4, xenforo 1.5.x

    Description

      Recently i upgraded to MariaDB 10.3.10 using directadmin custombuild function. And i noticed the mysql performance not very good. and while checking mysqltuner.pl suggestion, i found the number open file limit used extremely high.

      -------- Storage Engine Statistics -----------------------------------------------------------------
      [--] Status: +Aria +CSV +InnoDB +MEMORY +MRG_MyISAM +MyISAM +PERFORMANCE_SCHEMA +SEQUENCE
      [--] Data in MyISAM tables: 78.0M (Tables: 5)
      [--] Data in InnoDB tables: 21.1G (Tables: 236)
      [--] Data in MEMORY tables: 10.8M (Tables: 3)
      [!!] Total fragmented tables: 1

      -------- Analysis Performance Metrics --------------------------------------------------------------
      [--] innodb_stats_on_metadata: OFF
      [OK] No stat updates during querying INFORMATION_SCHEMA.

      -------- Security Recommendations ------------------------------------------------------------------
      [OK] There are no anonymous accounts for any database users
      [OK] All database users have passwords assigned
      [!!] There is no basic password file list!

      -------- CVE Security Recommendations --------------------------------------------------------------
      [--] Skipped due to --cvefile option undefined

      -------- Performance Metrics -----------------------------------------------------------------------
      [--] Up for: 14h 11m 59s (52M q [1K qps], 3M conn, TX: 1503G, RX: 15G)
      [--] Reads / Writes: 75% / 25%
      [--] Binary logging is disabled
      [--] Physical Memory : 94.2G
      [--] Max MySQL memory : 37.4G
      [--] Other process memory: 611.8M
      [--] Total buffers: 35.1G global + 2.9M per thread (620 max threads)
      [--] P_S Max memory usage: 531M
      [--] Galera GCache Max memory usage: 0B
      [OK] Maximum reached memory usage: 35.7G (37.94% of installed RAM)
      [OK] Maximum possible memory usage: 37.4G (39.68% of installed RAM)
      [OK] Overall possible memory usage with other process is compatible with memory available
      [OK] Slow queries: 0% (0/52M)
      [OK] Highest usage of available connections: 7% (45/620)
      [OK] Aborted connections: 0.00% (0/3451781)
      [--] Skipped name resolution test due to skip_networking=ON in system variables.
      [OK] Query cache is disabled by default due to mutex contention on multiprocessor machines.
      [OK] Sorts requiring temporary tables: 0% (78 temp sorts / 3M sorts)
      [!!] Joins performed without indexes: 837224
      [!!] Temporary tables created on disk: 50% (1M on disk / 3M total)
      [OK] Thread cache hit rate: 99% (45 created / 3M connections)
      [OK] Table cache hit rate: 90% (667 open / 735 opened)
      *[!!] Open file limit used: 28147927174348900% (18446744073B/65K)
      *[!!] Table locks acquired immediately: 86%

      -------- Performance schema ------------------------------------------------------------------------
      [--] Memory used by P_S: 531.1M
      [--] Sys schema isn't installed.

      -------- ThreadPool Metrics ------------------------------------------------------------------------
      [--] ThreadPool stat is enabled.
      [--] Thread Pool Size: 36 thread(s).
      [--] Using default value is good enough for your version (10.3.10-MariaDB)

      -------- MyISAM Metrics ----------------------------------------------------------------------------
      [!!] Key buffer used: 19.5% (516M used / 2B cache)
      [OK] Key buffer size / total MyISAM indexes: 2.5G/16.8M
      [OK] Read Key buffer hit rate: 100.0% (98M cached / 10K reads)
      [!!] Write Key buffer hit rate: 88.3% (7M cached / 6M writes)

      -------- InnoDB Metrics ----------------------------------------------------------------------------
      [--] InnoDB is enabled.
      [--] InnoDB Thread Concurrency: 0
      [OK] InnoDB File per table is activated
      [OK] InnoDB buffer pool / data size: 32.0G/21.1G
      [OK] Ratio InnoDB log file size / InnoDB Buffer pool size: 4.0G * 2/32.0G should be equal 25%
      [OK] InnoDB buffer pool instances: 32
      [--] Number of InnoDB Buffer Pool Chunk : 256 for 32 Buffer Pool Instance(s)
      [OK] Innodb_buffer_pool_size aligned with Innodb_buffer_pool_chunk_size & Innodb_buffer_pool_instances
      [OK] InnoDB Read buffer efficiency: 100.00% (36999275046 hits/ 37000117624 total)
      [!!] InnoDB Write Log efficiency: 86.04% (3658360 hits/ 4251694 total)
      [OK] InnoDB log waits: 0.00% (0 waits / 593334 writes)

      -------- AriaDB Metrics ----------------------------------------------------------------------------
      [--] AriaDB is enabled.
      [OK] Aria pagecache size / total Aria indexes: 128.0M/1B
      [OK] Aria pagecache hit rate: 98.5% (106M cached / 1M reads)

      -------- TokuDB Metrics ----------------------------------------------------------------------------
      [--] TokuDB is disabled.

      -------- XtraDB Metrics ----------------------------------------------------------------------------
      [--] XtraDB is disabled.

      -------- Galera Metrics ----------------------------------------------------------------------------
      [--] Galera is disabled.

      -------- Replication Metrics -----------------------------------------------------------------------
      [--] Galera Synchronous replication: NO
      [--] No replication slave(s) for this server.
      [--] Binlog format: MIXED
      [--] XA support enabled: ON
      [--] Semi synchronous replication Master: OFF
      [--] Semi synchronous replication Slave: OFF
      [--] This is a standalone server

      -------- Recommendations ---------------------------------------------------------------------------
      General recommendations:
      Run OPTIMIZE TABLE to defragment tables for better performance
      OPTIMIZE TABLE admin_xxxxx.`xf_search`; – can free 37 MB
      Total freed space after theses OPTIMIZE TABLE : 37 Mb
      MySQL was started within the last 24 hours - recommendations may be inaccurate
      Adjust your join queries to always utilize indexes
      Temporary table size is already large - reduce result set size
      Reduce your SELECT DISTINCT queries without LIMIT clauses
      Optimize queries and/or use InnoDB to reduce lock wait
      Consider installing Sys schema from https://github.com/mysql/mysql-sys
      Variables to adjust:
      join_buffer_size (> 256.0K, or always use indexes with JOINs)
      open_files_limit (> 65535)

      Attachments

        Activity

          Nhat Minh created issue -
          Nhat Minh added a comment -

          10.3.11 also similar issue.

          Nhat Minh added a comment - 10.3.11 also similar issue.

          When you connect to the server and run show global status like 'Open_files', what do you see?

          elenst Elena Stepanova added a comment - When you connect to the server and run show global status like 'Open_files' , what do you see?
          elenst Elena Stepanova made changes -
          Field Original Value New Value
          Labels need_feedback
          elenst Elena Stepanova made changes -
          Component/s Server [ 13907 ]
          Fix Version/s N/A [ 14700 ]
          Resolution Incomplete [ 4 ]
          Status Open [ 1 ] Closed [ 6 ]
          jarkkou Jarkko Uitti added a comment - - edited

          I am running 10.3.11 and have this issue too.

          show global status like 'open_files';

          Variable_name Value
          Open_files 18446744073709551172

          Rebooted db today and open_files was 40 minutes normal. Then again open_files jumped to extremely high.

          OS: Ubuntu 16.04.5 LTS
          DB: mysql Ver 15.1 Distrib 10.3.11-MariaDB, for debian-linux-gnu (x86_64) using readline 5.2

          jarkkou Jarkko Uitti added a comment - - edited I am running 10.3.11 and have this issue too. show global status like 'open_files'; Variable_name Value Open_files 18446744073709551172 Rebooted db today and open_files was 40 minutes normal. Then again open_files jumped to extremely high. OS: Ubuntu 16.04.5 LTS DB: mysql Ver 15.1 Distrib 10.3.11-MariaDB, for debian-linux-gnu (x86_64) using readline 5.2
          elenst Elena Stepanova made changes -
          Resolution Incomplete [ 4 ]
          Status Closed [ 6 ] Stalled [ 10000 ]
          elenst Elena Stepanova made changes -
          Fix Version/s N/A [ 14700 ]
          elenst Elena Stepanova made changes -
          Labels need_feedback

          jarkkou,

          After it jumps up, does it ever change back to normal (without server restart), or does it stay this way?
          Does FLUSH STATUS happen to have any effect?

          elenst Elena Stepanova added a comment - jarkkou , After it jumps up, does it ever change back to normal (without server restart), or does it stay this way? Does FLUSH STATUS happen to have any effect?
          elenst Elena Stepanova made changes -
          Labels need_feedback
          jarkkou Jarkko Uitti added a comment - - edited

          I am monitoring db status by nagios. Here is some statistics:
          db restart
          48 minutes normal
          23 hours high
          6 minutes normal
          6 minutes high
          5 hours normal
          2 minutes high
          12 minute normal
          6 minutes high
          4 minutes normal
          2 minutes high
          3 hours normal
          6 hours high

          Now it's
          show global status like 'open_files';

          Variable_name Value
          Open_files 18446744073709551356

          flush status doesn't have any effect.

          jarkkou Jarkko Uitti added a comment - - edited I am monitoring db status by nagios. Here is some statistics: db restart 48 minutes normal 23 hours high 6 minutes normal 6 minutes high 5 hours normal 2 minutes high 12 minute normal 6 minutes high 4 minutes normal 2 minutes high 3 hours normal 6 hours high Now it's show global status like 'open_files'; Variable_name Value Open_files 18446744073709551356 flush status doesn't have any effect.
          elenst Elena Stepanova made changes -
          Labels need_feedback

          Thank you.
          We've had some problems with status values temporarily going crazy before, although I don't think it has ever been about Open_files in particular. Some got fixed, some we couldn't reproduce. We'll see if we can figure out this one.

          elenst Elena Stepanova added a comment - Thank you. We've had some problems with status values temporarily going crazy before, although I don't think it has ever been about Open_files in particular. Some got fixed, some we couldn't reproduce. We'll see if we can figure out this one.
          elenst Elena Stepanova made changes -
          Assignee Elena Stepanova [ elenst ]

          ATTENTION: in the test case below, a wrong numeric comparison is used, due to a known bug in MTR: MDEV-18228.
          If the bug has been fixed, modify the condition to something like $val > 1000 or whatever, otherwise it won't fail, even though it will print bad values.

          MTR test case

          --let $iterations=1000000
           
          --exec $MYSQL_SLAP --create-schema=test --silent --concurrency=1 --number-of-queries=$iterations --query="ALTER TABLE mysql.plugin FORCE ; FLUSH TABLES" > /dev/null 2>&1 &
          --exec $MYSQL_SLAP --create-schema=test --silent --concurrency=1 --number-of-queries=$iterations --query="SELECT db FROM mysql.db ORDER BY db LIMIT 0" > /dev/null 2>&1 &
           
          --let $run= $iterations
          while ($run)
          {
            --dec $run
            --let $val= query_get_value(SHOW STATUS LIKE 'Open_files',Value,1)
            --echo Run $run: Open_files: $val
            
            # ATTENTION! It is an intentionally wrong comparison, due to MDEV-18228
            if ($val < 0)
            {
              --let $run= 0
              --die
            }
          }
           
          --echo # All done, except that slap might still be running
          

          Modify --run value at the beginning of the test as needed. It represents the number of queries which each thread will run.

          The problem appears as this:

          Run 997650: Open_files: 5
          Run 997649: Open_files: 3
          Run 997648: Open_files: 3
          Run 997647: Open_files: 1
          Run 997646: Open_files: 18446744073709551615
          bug.t2                                   [ fail ]
                  Test ended at 2019-01-14 16:56:13
           
          CURRENT_TEST: bug.t2
          mysqltest: At line 19:
          

          Reproducible on 10.3 and 10.4. Couldn't reproduce on 10.2.
          While the problem is not limited to non-debug builds, it is reproducible much easier and faster on RelWithDebInfo builds.

          Here is an alternative RQG test (modify the path to basedir as needed):

          git clone https://github.com/MariaDB/randgen --branch elenst-mdev17845 rqg-mdev17845
          cd rqg-mdev17845
          perl ./runall-new.pl --skip-gendata --grammar=mdev17845.yy --threads=3 --duration=300 --basedir=/data/bld/10.3-rel --vardir=/dev/shm/vardir --validators=CheckFieldValue
          

          or, for an already running server,

          perl ./gentest.pl --dsn="dbi:mysql:user=root:host=127.0.0.1:port=3306:database=test" --grammar=mdev17845.yy --threads=3 --duration=300   --validators=CheckFieldValue --queries=100M
          

          (modify port if needed and make sure the server is running in shm, it's much easier reproducible there).

          With the RQG test, the problem represents like this:

          # 2019-01-14T17:12:42 [9995] ERROR: For query 'SHOW STATUS LIKE 'Open_files' /* Validate 2 < 1000000000000 for row 1 */ /* QNO 35308 CON_ID 13 */ ' on row 1 result 18446744073709551615 does not meet the condition < 1000000000000
          # 2019-01-14T17:12:42 [9995] Full row: [1] : Open_files; [2] : 18446744073709551615;
          # 2019-01-14T17:12:42 [9995] GenTest: Server crash or critical failure (STATUS_REQUIREMENT_UNMET) reported, the child will be stopped
          

          elenst Elena Stepanova added a comment - ATTENTION: in the test case below, a wrong numeric comparison is used, due to a known bug in MTR: MDEV-18228 . If the bug has been fixed, modify the condition to something like $val > 1000 or whatever, otherwise it won't fail, even though it will print bad values. MTR test case --let $iterations=1000000   --exec $MYSQL_SLAP --create-schema=test --silent --concurrency=1 --number-of-queries=$iterations --query="ALTER TABLE mysql.plugin FORCE ; FLUSH TABLES" > /dev/null 2>&1 & --exec $MYSQL_SLAP --create-schema=test --silent --concurrency=1 --number-of-queries=$iterations --query="SELECT db FROM mysql.db ORDER BY db LIMIT 0" > /dev/null 2>&1 &   --let $run= $iterations while ($run) { --dec $run --let $val= query_get_value(SHOW STATUS LIKE 'Open_files',Value,1) --echo Run $run: Open_files: $val # ATTENTION! It is an intentionally wrong comparison, due to MDEV-18228 if ($val < 0) { --let $run= 0 --die } }   --echo # All done, except that slap might still be running Modify --run value at the beginning of the test as needed. It represents the number of queries which each thread will run. The problem appears as this: Run 997650: Open_files: 5 Run 997649: Open_files: 3 Run 997648: Open_files: 3 Run 997647: Open_files: 1 Run 997646: Open_files: 18446744073709551615 bug.t2 [ fail ] Test ended at 2019-01-14 16:56:13   CURRENT_TEST: bug.t2 mysqltest: At line 19: Reproducible on 10.3 and 10.4. Couldn't reproduce on 10.2. While the problem is not limited to non-debug builds, it is reproducible much easier and faster on RelWithDebInfo builds. Here is an alternative RQG test (modify the path to basedir as needed): git clone https://github.com/MariaDB/randgen --branch elenst-mdev17845 rqg-mdev17845 cd rqg-mdev17845 perl ./runall-new.pl --skip-gendata --grammar=mdev17845.yy --threads=3 --duration=300 --basedir=/data/bld/10.3-rel --vardir=/dev/shm/vardir --validators=CheckFieldValue or, for an already running server, perl ./gentest.pl --dsn="dbi:mysql:user=root:host=127.0.0.1:port=3306:database=test" --grammar=mdev17845.yy --threads=3 --duration=300 --validators=CheckFieldValue --queries=100M (modify port if needed and make sure the server is running in shm, it's much easier reproducible there). With the RQG test, the problem represents like this: # 2019-01-14T17:12:42 [9995] ERROR: For query 'SHOW STATUS LIKE 'Open_files' /* Validate 2 < 1000000000000 for row 1 */ /* QNO 35308 CON_ID 13 */ ' on row 1 result 18446744073709551615 does not meet the condition < 1000000000000 # 2019-01-14T17:12:42 [9995] Full row: [1] : Open_files; [2] : 18446744073709551615; # 2019-01-14T17:12:42 [9995] GenTest: Server crash or critical failure (STATUS_REQUIREMENT_UNMET) reported, the child will be stopped
          elenst Elena Stepanova made changes -
          Fix Version/s 10.3 [ 22126 ]
          Fix Version/s 10.4 [ 22408 ]
          Affects Version/s 10.3 [ 22126 ]
          Affects Version/s 10.4 [ 22408 ]
          Assignee Elena Stepanova [ elenst ] Sergei Golubchik [ serg ]
          elenst Elena Stepanova made changes -
          Status Stalled [ 10000 ] Open [ 1 ]
          elenst Elena Stepanova made changes -
          Status Open [ 1 ] Confirmed [ 10101 ]
          hholzgra Hartmut Holzgraefe made changes -
          Support case ID 27743
          serg Sergei Golubchik made changes -
          Status Confirmed [ 10101 ] In Progress [ 3 ]
          serg Sergei Golubchik made changes -
          Status In Progress [ 3 ] Stalled [ 10000 ]
          serg Sergei Golubchik added a comment - please, review https://github.com/MariaDB/server/commit/a7548c58a57
          serg Sergei Golubchik made changes -
          Assignee Sergei Golubchik [ serg ] Sergey Vojtovich [ svoj ]
          Status Stalled [ 10000 ] In Review [ 10002 ]

          Ok to push.

          svoj Sergey Vojtovich added a comment - Ok to push.
          svoj Sergey Vojtovich made changes -
          Assignee Sergey Vojtovich [ svoj ] Sergei Golubchik [ serg ]
          Status In Review [ 10002 ] Stalled [ 10000 ]
          serg Sergei Golubchik made changes -
          Fix Version/s 10.3.15 [ 23309 ]
          Fix Version/s 10.4.5 [ 23311 ]
          Fix Version/s 10.3 [ 22126 ]
          Fix Version/s 10.4 [ 22408 ]
          Resolution Fixed [ 1 ]
          Status Stalled [ 10000 ] Closed [ 6 ]
          serg Sergei Golubchik made changes -
          Workflow MariaDB v3 [ 90895 ] MariaDB v4 [ 155277 ]
          mariadb-jira-automation Jira Automation (IT) made changes -
          Zendesk Related Tickets 151373

          People

            serg Sergei Golubchik
            Nhat Minh
            Votes:
            1 Vote for this issue
            Watchers:
            8 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.