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

"[ERROR] Failed to write to mysql.slow_log:" without reason

Details

    • Bug
    • Status: Closed (View Workflow)
    • Major
    • Resolution: Incomplete
    • 10.3.17, 10.3.23, 10.2.40
    • N/A
    • None
    • None
    • Centos7

    Description

      MariaDB is leaving error logs like below, without a cause of the error

      2020-12-03 9:04:49 18292544 [ERROR] Failed to write to mysql.slow_log:
      2020-12-03 12:45:52 18365665 [ERROR] Failed to write to mysql.slow_log:

      There were no such huge queries or load at the given time.

      I have no clue why this error occurs.

      Please reply if you know anything about it

      Attachments

        Issue Links

          Activity

            danblack Daniel Black added a comment -

            looking at the code there is mean to be an error after these messages. What is the table structure of `show create table mysql.slow_log`?

            It should be this structure: https://github.com/MariaDB/server/blob/10.3/scripts/mysql_system_tables.sql#L100

            danblack Daniel Black added a comment - looking at the code there is mean to be an error after these messages. What is the table structure of `show create table mysql.slow_log`? It should be this structure: https://github.com/MariaDB/server/blob/10.3/scripts/mysql_system_tables.sql#L100
            hyo9lee Hyo Lee added a comment - - edited

            Thank you for the response Daniel Black

            This is the table structure

            CREATE TABLE `slow_log` (
              `start_time` timestamp(6) NOT NULL DEFAULT current_timestamp(6) ON UPDATE current_timestamp(6),
              `user_host` mediumtext NOT NULL,
              `query_time` time(6) NOT NULL,
              `lock_time` time(6) NOT NULL,
              `rows_sent` int(11) NOT NULL,
              `rows_examined` int(11) NOT NULL,
              `db` varchar(512) NOT NULL,
              `last_insert_id` int(11) NOT NULL,
              `insert_id` int(11) NOT NULL,
              `server_id` int(10) unsigned NOT NULL,
              `sql_text` mediumtext NOT NULL,
              `thread_id` bigint(21) unsigned NOT NULL,
              `rows_affected` int(11) NOT NULL,
              KEY `slow_log_01` (`start_time`),
              KEY `IX_SLOW_LOG_01` (`thread_id`)
            ) ENGINE=MyISAM DEFAULT CHARSET=utf8 COMMENT='Slow log'
            

            I think it is not a table structure problem... but if you think it is, please let me know.

            Thanks again

            hyo9lee Hyo Lee added a comment - - edited Thank you for the response Daniel Black This is the table structure CREATE TABLE `slow_log` ( `start_time` timestamp( 6 ) NOT NULL DEFAULT current_timestamp( 6 ) ON UPDATE current_timestamp( 6 ), `user_host` mediumtext NOT NULL, `query_time` time( 6 ) NOT NULL, `lock_time` time( 6 ) NOT NULL, `rows_sent` int ( 11 ) NOT NULL, `rows_examined` int ( 11 ) NOT NULL, `db` varchar( 512 ) NOT NULL, `last_insert_id` int ( 11 ) NOT NULL, `insert_id` int ( 11 ) NOT NULL, `server_id` int ( 10 ) unsigned NOT NULL, `sql_text` mediumtext NOT NULL, `thread_id` bigint( 21 ) unsigned NOT NULL, `rows_affected` int ( 11 ) NOT NULL, KEY `slow_log_01` (`start_time`), KEY `IX_SLOW_LOG_01` (`thread_id`) ) ENGINE=MyISAM DEFAULT CHARSET=utf8 COMMENT= 'Slow log' I think it is not a table structure problem... but if you think it is, please let me know. Thanks again
            alice Alice Sherepa added a comment - I guess it might be the same bug as here https://bugs.mysql.com/bug.php?id=71377 ( https://bugs.mysql.com/bug.php?id=37132 )
            danblack Daniel Black added a comment -

            alice you're probably right. Any of these int fields could quite easily (or time - 35 days - maybe less easily) overflow and caused the error.

            danblack Daniel Black added a comment - alice you're probably right. Any of these int fields could quite easily (or time - 35 days - maybe less easily) overflow and caused the error.
            danblack Daniel Black added a comment -

            Reproduced on 10.2

            $ mariadblocal --log_output=TABLE --long_query_time=0.00001 --slow_query_log=1
            Installing MariaDB/MySQL system tables in '/tmp/build-mariadb-server-10.2-datadir' ...
            2021-09-14 21:11:07 140566304090304 [Note] /home/dan/repos/build-mariadb-server-10.2/sql/mysqld (mysqld 10.2.41-MariaDB) starting as process 2265527 ...
             
            MariaDB [(none)]> set global log_output='FILE'; alter table mysql.slow_log engine=myisam;  set global log_output='TABLE';
            Query OK, 0 rows affected (0.00 sec)
             
            MariaDB [test]> select sum(seq) from seq_1_to_18446744073709551619 union all select sleep(1);
            +----------+
            | sum(seq) |
            +----------+
            |        0 |
            |        0 |
            +----------+
            2 rows in set (1.01 sec)
             
            MariaDB [test]> select * from mysql.slow_log ;
            +----------------------------+---------------------------+-----------------+-----------------+-----------+---------------+------+----------------+-----------+-----------+------------------------------------------------------------------------------+-----------+---------------+
            | start_time                 | user_host                 | query_time      | lock_time       | rows_sent | rows_examined | db   | last_insert_id | insert_id | server_id | sql_text                                                                     | thread_id | rows_affected |
            +----------------------------+---------------------------+-----------------+-----------------+-----------+---------------+------+----------------+-----------+-----------+------------------------------------------------------------------------------+-----------+---------------+
            | 2021-09-14 21:32:03.287764 | root[root] @ localhost [] | 00:00:00.000164 | 00:00:00.000000 |         0 |             0 |      |              0 |         0 |         1 | truncate table mysql.slow_log                                                |        20 |             0 |
            | 2021-09-14 21:32:07.477644 | root[root] @ localhost [] | 00:00:00.000201 | 00:00:00.000000 |         0 |             0 |      |              0 |         0 |         1 | show create table mysql.slow_log                                             |        20 |             0 |
            | 2021-09-14 21:32:10.395192 | root[root] @ localhost [] | 00:00:00.000051 | 00:00:00.000000 |         0 |          NULL |      |              0 |         0 |         1 | set global log_output='TABLE'                                                |        20 |             0 |
            | 2021-09-14 21:32:25.007978 | root[root] @ localhost [] | 00:00:00.000116 | 00:00:00.000000 |         0 |          NULL |      |              0 |         0 |         1 | select sum(seq) from seq_1_to_18446744073709551619                           |        20 |             0 |
            | 2021-09-14 21:32:28.586502 | root[root] @ localhost [] | 00:00:00.000048 | 00:00:00.000000 |         1 |          NULL |      |              0 |         0 |         1 | SELECT DATABASE()                                                            |        20 |             0 |
            | 2021-09-14 21:32:28.587404 | root[root] @ localhost [] | 00:00:00.000102 | 00:00:00.000033 |         4 |          NULL | test |              0 |         0 |         1 | show databases                                                               |        20 |             0 |
            | 2021-09-14 21:32:28.587562 | root[root] @ localhost [] | 00:00:00.000051 | 00:00:00.000019 |         0 |          NULL | test |              0 |         0 |         1 | show tables                                                                  |        20 |             0 |
            | 2021-09-14 21:32:29.699222 | root[root] @ localhost [] | 00:00:00.000235 | 00:00:00.000099 |         1 |          NULL | test |              0 |         0 |         1 | select sum(seq) from seq_1_to_18446744073709551619                           |        20 |             0 |
            | 2021-09-14 21:33:00.803729 | root[root] @ localhost [] | 00:00:00.000021 | 00:00:00.000000 |         0 |          NULL |      |              0 |         0 |         1 | KILL QUERY 20                                                                |        21 |             0 |
            | 2021-09-14 21:33:21.390550 | root[root] @ localhost [] | 00:00:01.000593 | 00:00:00.000139 |         2 |          NULL | test |              0 |         0 |         1 | select sum(seq) from seq_1_to_18446744073709551619 union all select sleep(1) |        20 |             0 |
            | 2021-09-14 21:33:40.134965 | root[root] @ localhost [] | 00:00:00.000051 | 00:00:00.000000 |         0 |          NULL | test |              0 |         0 |         1 | set global log_output='TABLE'                                                |        20 |             0 |
            | 2021-09-14 21:33:44.595045 | root[root] @ localhost [] | 00:00:01.000540 | 00:00:00.000136 |         2 |          NULL | test |              0 |         0 |         1 | select sum(seq) from seq_1_to_18446744073709551619 union all select sleep(1) |        20 |             0 |
            | 2021-09-14 21:34:46.141738 | root[root] @ localhost [] | 00:00:00.000155 | 00:00:00.000000 |         0 |          NULL | test |              0 |         0 |         1 | show create table mysql.slow_log                                             |        20 |             0 |
            +----------------------------+---------------------------+-----------------+-----------------+-----------+---------------+------+----------------+-----------+-----------+------------------------------------------------------------------------------+-----------+---------------+
            13 rows in set (0.00 sec)
             
             
             
            error log:
             
            Version: '10.2.41-MariaDB-log'  socket: '/tmp/build-mariadb-server-10.2.sock'  port: 0  Source distribution
            2021-09-14 21:33:00 139666930255424 [ERROR] Failed to write to mysql.slow_log: 
            
            

            danblack Daniel Black added a comment - Reproduced on 10.2 $ mariadblocal --log_output=TABLE --long_query_time=0.00001 --slow_query_log=1 Installing MariaDB/MySQL system tables in '/tmp/build-mariadb-server-10.2-datadir' ... 2021-09-14 21:11:07 140566304090304 [Note] /home/dan/repos/build-mariadb-server-10.2/sql/mysqld (mysqld 10.2.41-MariaDB) starting as process 2265527 ...   MariaDB [(none)]> set global log_output='FILE'; alter table mysql.slow_log engine=myisam; set global log_output='TABLE'; Query OK, 0 rows affected (0.00 sec)   MariaDB [test]> select sum(seq) from seq_1_to_18446744073709551619 union all select sleep(1); +----------+ | sum(seq) | +----------+ | 0 | | 0 | +----------+ 2 rows in set (1.01 sec)   MariaDB [test]> select * from mysql.slow_log ; +----------------------------+---------------------------+-----------------+-----------------+-----------+---------------+------+----------------+-----------+-----------+------------------------------------------------------------------------------+-----------+---------------+ | start_time | user_host | query_time | lock_time | rows_sent | rows_examined | db | last_insert_id | insert_id | server_id | sql_text | thread_id | rows_affected | +----------------------------+---------------------------+-----------------+-----------------+-----------+---------------+------+----------------+-----------+-----------+------------------------------------------------------------------------------+-----------+---------------+ | 2021-09-14 21:32:03.287764 | root[root] @ localhost [] | 00:00:00.000164 | 00:00:00.000000 | 0 | 0 | | 0 | 0 | 1 | truncate table mysql.slow_log | 20 | 0 | | 2021-09-14 21:32:07.477644 | root[root] @ localhost [] | 00:00:00.000201 | 00:00:00.000000 | 0 | 0 | | 0 | 0 | 1 | show create table mysql.slow_log | 20 | 0 | | 2021-09-14 21:32:10.395192 | root[root] @ localhost [] | 00:00:00.000051 | 00:00:00.000000 | 0 | NULL | | 0 | 0 | 1 | set global log_output='TABLE' | 20 | 0 | | 2021-09-14 21:32:25.007978 | root[root] @ localhost [] | 00:00:00.000116 | 00:00:00.000000 | 0 | NULL | | 0 | 0 | 1 | select sum(seq) from seq_1_to_18446744073709551619 | 20 | 0 | | 2021-09-14 21:32:28.586502 | root[root] @ localhost [] | 00:00:00.000048 | 00:00:00.000000 | 1 | NULL | | 0 | 0 | 1 | SELECT DATABASE() | 20 | 0 | | 2021-09-14 21:32:28.587404 | root[root] @ localhost [] | 00:00:00.000102 | 00:00:00.000033 | 4 | NULL | test | 0 | 0 | 1 | show databases | 20 | 0 | | 2021-09-14 21:32:28.587562 | root[root] @ localhost [] | 00:00:00.000051 | 00:00:00.000019 | 0 | NULL | test | 0 | 0 | 1 | show tables | 20 | 0 | | 2021-09-14 21:32:29.699222 | root[root] @ localhost [] | 00:00:00.000235 | 00:00:00.000099 | 1 | NULL | test | 0 | 0 | 1 | select sum(seq) from seq_1_to_18446744073709551619 | 20 | 0 | | 2021-09-14 21:33:00.803729 | root[root] @ localhost [] | 00:00:00.000021 | 00:00:00.000000 | 0 | NULL | | 0 | 0 | 1 | KILL QUERY 20 | 21 | 0 | | 2021-09-14 21:33:21.390550 | root[root] @ localhost [] | 00:00:01.000593 | 00:00:00.000139 | 2 | NULL | test | 0 | 0 | 1 | select sum(seq) from seq_1_to_18446744073709551619 union all select sleep(1) | 20 | 0 | | 2021-09-14 21:33:40.134965 | root[root] @ localhost [] | 00:00:00.000051 | 00:00:00.000000 | 0 | NULL | test | 0 | 0 | 1 | set global log_output='TABLE' | 20 | 0 | | 2021-09-14 21:33:44.595045 | root[root] @ localhost [] | 00:00:01.000540 | 00:00:00.000136 | 2 | NULL | test | 0 | 0 | 1 | select sum(seq) from seq_1_to_18446744073709551619 union all select sleep(1) | 20 | 0 | | 2021-09-14 21:34:46.141738 | root[root] @ localhost [] | 00:00:00.000155 | 00:00:00.000000 | 0 | NULL | test | 0 | 0 | 1 | show create table mysql.slow_log | 20 | 0 | +----------------------------+---------------------------+-----------------+-----------------+-----------+---------------+------+----------------+-----------+-----------+------------------------------------------------------------------------------+-----------+---------------+ 13 rows in set (0.00 sec)       error log:   Version: '10.2.41-MariaDB-log' socket: '/tmp/build-mariadb-server-10.2.sock' port: 0 Source distribution 2021-09-14 21:33:00 139666930255424 [ERROR] Failed to write to mysql.slow_log:
            danblack Daniel Black added a comment -

            actually test case above is not the reproductions. It may have been the alter table to myisam.

            danblack Daniel Black added a comment - actually test case above is not the reproductions. It may have been the alter table to myisam.

            People

              sanja Oleksandr Byelkin
              hyo9lee Hyo Lee
              Votes:
              0 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.