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

OQGRAPH causes MariaDB 100% CPU usage

Details

    • Bug
    • Status: Closed (View Workflow)
    • Major
    • Resolution: Duplicate
    • 10.0.8
    • None
    • None
    • Debian Wheezy
      MariaDB 10.0.8 (query cache disabled)

    Description

      This does not happen every time, unfortunately. I've tried to google this issue - 've found similar problems, but most of them revolve around MariaDB 5 series with OQGRAPH v2, not v3.

      Create a test database with the information listed here:

      https://mariadb.com/kb/en/oqgraph-overview/

      MariaDB [test]> SELECT * FROM oq_graph;
      		 
      Killed

      It takes over a minute for it to return "Killed", all the while mysqld uses as much CPU as possible. But then, if I try to access it again:

      MariaDB [test]> SELECT * FROM oq_graph;
      		 
      ERROR 2013 (HY000): Lost connection to MySQL server during query
      		 
      MariaDB [test]> SELECT * FROM oq_graph;
      		 
      ERROR 2006 (HY000): MySQL server has gone away
      		 
      No connection. Trying to reconnect...
      		 
      Connection id:    3
      		 
      Current database: test
      		 
       
      		 
      +-------+--------+--------+--------+------+--------+
      		 
      | latch | origid | destid | weight | seq  | linkid |
      		 
      +-------+--------+--------+--------+------+--------+
      		 
      | NULL  |      1 |      2 |      1 | NULL |   NULL |
      		 
      | NULL  |      2 |      3 |      1 | NULL |   NULL |
      		 
      | NULL  |      2 |      6 |      1 | NULL |   NULL |
      		 
      | NULL  |      3 |      4 |      1 | NULL |   NULL |
      		 
      | NULL  |      4 |      5 |      1 | NULL |   NULL |
      		 
      | NULL  |      5 |      6 |      1 | NULL |   NULL |
      		 
      +-------+--------+--------+--------+------+--------+
      		 
      6 rows in set (0.02 sec)

      And then sometimes, it works as expected.

      Accessing from PHP or Python has the same effect: 100% CPU load. I've yet to get a proper result returned from these environments.

      Selecting from oq_backing works fine.

      Attachments

        Issue Links

          duplicates

          Bug - A problem which impairs or prevents the functions of the product. MDEV-5891 Assertion `! ((size_t)orig == (size_t)-1 && (size_t)dest == (size_t)-1)' failed in open_query::edges_cursor::fetch_row(..) with InnoDB backing table

          • Major - Major loss of function.
          • Closed

          Activity

            Ascending order - Click to sort in descending order
            blitzmann Ryan Holmes (Inactive) created issue -
            blitzmann Ryan Holmes (Inactive) made changes -
            Field Original Value New Value
            Description This does not happen every time, unfortunately.

            Create a test database with the information listed here:

            https://mariadb.com/kb/en/oqgraph-overview/

            MariaDB [test]> SELECT * FROM oq_graph;
            Killed

            It takes over a minute for it to return "Killed", all the while mysqld uses as much CPU as possible. But then, if I try to access it again:

            MariaDB [test]> SELECT * FROM oq_graph;
            ERROR 2013 (HY000): Lost connection to MySQL server during query
            MariaDB [test]> SELECT * FROM oq_graph;
            ERROR 2006 (HY000): MySQL server has gone away
            No connection. Trying to reconnect...
            Connection id: 3
            Current database: test

            +-------+--------+--------+--------+------+--------+
            | latch | origid | destid | weight | seq | linkid |
            +-------+--------+--------+--------+------+--------+
            | NULL | 1 | 2 | 1 | NULL | NULL |
            | NULL | 2 | 3 | 1 | NULL | NULL |
            | NULL | 2 | 6 | 1 | NULL | NULL |
            | NULL | 3 | 4 | 1 | NULL | NULL |
            | NULL | 4 | 5 | 1 | NULL | NULL |
            | NULL | 5 | 6 | 1 | NULL | NULL |
            +-------+--------+--------+--------+------+--------+
            6 rows in set (0.02 sec)

            And then sometimes, it works as expected.

            Accessing from PHP or Python has the same effect: 100% CPU load. I've yet to get a proper result returned from these environments.


            Selecting from oq_backing works fine.             		This does not happen every time, unfortunately.

            Create a test database with the information listed here:

            https://mariadb.com/kb/en/oqgraph-overview/

            MariaDB [test]> SELECT * FROM oq_graph;
            Killed

            It takes over a minute for it to return "Killed", all the while mysqld uses as much CPU as possible. But then, if I try to access it again:
            {code:xml}
            MariaDB [test]> SELECT * FROM oq_graph;
            ERROR 2013 (HY000): Lost connection to MySQL server during query
            MariaDB [test]> SELECT * FROM oq_graph;
            ERROR 2006 (HY000): MySQL server has gone away
            No connection. Trying to reconnect...
            Connection id: 3
            Current database: test

            +-------+--------+--------+--------+------+--------+
            | latch | origid | destid | weight | seq | linkid |
            +-------+--------+--------+--------+------+--------+
            | NULL | 1 | 2 | 1 | NULL | NULL |
            | NULL | 2 | 3 | 1 | NULL | NULL |
            | NULL | 2 | 6 | 1 | NULL | NULL |
            | NULL | 3 | 4 | 1 | NULL | NULL |
            | NULL | 4 | 5 | 1 | NULL | NULL |
            | NULL | 5 | 6 | 1 | NULL | NULL |
            +-------+--------+--------+--------+------+--------+
            6 rows in set (0.02 sec)
            {code}
            And then sometimes, it works as expected.

            Accessing from PHP or Python has the same effect: 100% CPU load. I've yet to get a proper result returned from these environments.


            Selecting from oq_backing works fine.
            blitzmann Ryan Holmes (Inactive) made changes -
            Description This does not happen every time, unfortunately.

            Create a test database with the information listed here:

            https://mariadb.com/kb/en/oqgraph-overview/

            MariaDB [test]> SELECT * FROM oq_graph;
            Killed

            It takes over a minute for it to return "Killed", all the while mysqld uses as much CPU as possible. But then, if I try to access it again:
            {code:xml}
            MariaDB [test]> SELECT * FROM oq_graph;
            ERROR 2013 (HY000): Lost connection to MySQL server during query
            MariaDB [test]> SELECT * FROM oq_graph;
            ERROR 2006 (HY000): MySQL server has gone away
            No connection. Trying to reconnect...
            Connection id: 3
            Current database: test

            +-------+--------+--------+--------+------+--------+
            | latch | origid | destid | weight | seq | linkid |
            +-------+--------+--------+--------+------+--------+
            | NULL | 1 | 2 | 1 | NULL | NULL |
            | NULL | 2 | 3 | 1 | NULL | NULL |
            | NULL | 2 | 6 | 1 | NULL | NULL |
            | NULL | 3 | 4 | 1 | NULL | NULL |
            | NULL | 4 | 5 | 1 | NULL | NULL |
            | NULL | 5 | 6 | 1 | NULL | NULL |
            +-------+--------+--------+--------+------+--------+
            6 rows in set (0.02 sec)
            {code}
            And then sometimes, it works as expected.

            Accessing from PHP or Python has the same effect: 100% CPU load. I've yet to get a proper result returned from these environments.


            Selecting from oq_backing works fine.             		This does not happen every time, unfortunately.

            Create a test database with the information listed here:

            https://mariadb.com/kb/en/oqgraph-overview/
            {code:xml}
            MariaDB [test]> SELECT * FROM oq_graph;
            Killed
            {code}
            It takes over a minute for it to return "Killed", all the while mysqld uses as much CPU as possible. But then, if I try to access it again:
            {code:xml}
            MariaDB [test]> SELECT * FROM oq_graph;
            ERROR 2013 (HY000): Lost connection to MySQL server during query
            MariaDB [test]> SELECT * FROM oq_graph;
            ERROR 2006 (HY000): MySQL server has gone away
            No connection. Trying to reconnect...
            Connection id: 3
            Current database: test

            +-------+--------+--------+--------+------+--------+
            | latch | origid | destid | weight | seq | linkid |
            +-------+--------+--------+--------+------+--------+
            | NULL | 1 | 2 | 1 | NULL | NULL |
            | NULL | 2 | 3 | 1 | NULL | NULL |
            | NULL | 2 | 6 | 1 | NULL | NULL |
            | NULL | 3 | 4 | 1 | NULL | NULL |
            | NULL | 4 | 5 | 1 | NULL | NULL |
            | NULL | 5 | 6 | 1 | NULL | NULL |
            +-------+--------+--------+--------+------+--------+
            6 rows in set (0.02 sec)
            {code}
            And then sometimes, it works as expected.

            Accessing from PHP or Python has the same effect: 100% CPU load. I've yet to get a proper result returned from these environments.


            Selecting from oq_backing works fine.
            blitzmann Ryan Holmes (Inactive) made changes -
            Description This does not happen every time, unfortunately.

            Create a test database with the information listed here:

            https://mariadb.com/kb/en/oqgraph-overview/
            {code:xml}
            MariaDB [test]> SELECT * FROM oq_graph;
            Killed
            {code}
            It takes over a minute for it to return "Killed", all the while mysqld uses as much CPU as possible. But then, if I try to access it again:
            {code:xml}
            MariaDB [test]> SELECT * FROM oq_graph;
            ERROR 2013 (HY000): Lost connection to MySQL server during query
            MariaDB [test]> SELECT * FROM oq_graph;
            ERROR 2006 (HY000): MySQL server has gone away
            No connection. Trying to reconnect...
            Connection id: 3
            Current database: test

            +-------+--------+--------+--------+------+--------+
            | latch | origid | destid | weight | seq | linkid |
            +-------+--------+--------+--------+------+--------+
            | NULL | 1 | 2 | 1 | NULL | NULL |
            | NULL | 2 | 3 | 1 | NULL | NULL |
            | NULL | 2 | 6 | 1 | NULL | NULL |
            | NULL | 3 | 4 | 1 | NULL | NULL |
            | NULL | 4 | 5 | 1 | NULL | NULL |
            | NULL | 5 | 6 | 1 | NULL | NULL |
            +-------+--------+--------+--------+------+--------+
            6 rows in set (0.02 sec)
            {code}
            And then sometimes, it works as expected.

            Accessing from PHP or Python has the same effect: 100% CPU load. I've yet to get a proper result returned from these environments.


            Selecting from oq_backing works fine.             		This does not happen every time, unfortunately. I've tried to google this issue - 've found similar problems, but most of them revolve around MariaDB 5 series with OQGRAPH v2, not v3.

            Create a test database with the information listed here:

            https://mariadb.com/kb/en/oqgraph-overview/
            {code:xml}
            MariaDB [test]> SELECT * FROM oq_graph;
            Killed
            {code}
            It takes over a minute for it to return "Killed", all the while mysqld uses as much CPU as possible. But then, if I try to access it again:
            {code:xml}
            MariaDB [test]> SELECT * FROM oq_graph;
            ERROR 2013 (HY000): Lost connection to MySQL server during query
            MariaDB [test]> SELECT * FROM oq_graph;
            ERROR 2006 (HY000): MySQL server has gone away
            No connection. Trying to reconnect...
            Connection id: 3
            Current database: test

            +-------+--------+--------+--------+------+--------+
            | latch | origid | destid | weight | seq | linkid |
            +-------+--------+--------+--------+------+--------+
            | NULL | 1 | 2 | 1 | NULL | NULL |
            | NULL | 2 | 3 | 1 | NULL | NULL |
            | NULL | 2 | 6 | 1 | NULL | NULL |
            | NULL | 3 | 4 | 1 | NULL | NULL |
            | NULL | 4 | 5 | 1 | NULL | NULL |
            | NULL | 5 | 6 | 1 | NULL | NULL |
            +-------+--------+--------+--------+------+--------+
            6 rows in set (0.02 sec)
            {code}
            And then sometimes, it works as expected.

            Accessing from PHP or Python has the same effect: 100% CPU load. I've yet to get a proper result returned from these environments.


            Selecting from oq_backing works fine.
            serg Sergei Golubchik made changes -
            Assignee Arjen Lentz [ arjen ]
            blitzmann Ryan Holmes (Inactive) added a comment - - edited

            Upgraded to the recent 10.0.9, and for the most part is seems to be working at the cli level. However, I occasionally get a "Lost connection to server while processing query" (or something to that effect). I also still cannot access the data via python or php (mariadb shoots to 100% CPU still)

            blitzmann Ryan Holmes (Inactive) added a comment - - edited Upgraded to the recent 10.0.9, and for the most part is seems to be working at the cli level. However, I occasionally get a "Lost connection to server while processing query" (or something to that effect). I also still cannot access the data via python or php (mariadb shoots to 100% CPU still)
            arjen Arjen Lentz made changes -
            Labels oqgraph
            arjen Arjen Lentz added a comment -

            Ryan - thanks for that report.
            When you get "lost connection to server" that tends to indicate a segfault which is always a bug. Your MariaDB error log should contain some info, possibly even a stack trace - even an unresolved stacktrace would provide us with some valuable information, but if you can resolve it that'd be fabulous and really be a great help.
            thanks

            arjen Arjen Lentz added a comment - Ryan - thanks for that report. When you get "lost connection to server" that tends to indicate a segfault which is always a bug. Your MariaDB error log should contain some info, possibly even a stack trace - even an unresolved stacktrace would provide us with some valuable information, but if you can resolve it that'd be fabulous and really be a great help. thanks
            blitzmann Ryan Holmes (Inactive) added a comment - - edited

            /var/log/mysql.log or mysql.err is blank, no logs. =/

            EDIT: I may have incorrect logging settings... I will take a look at this later today and reply with results...

            blitzmann Ryan Holmes (Inactive) added a comment - - edited /var/log/mysql.log or mysql.err is blank, no logs. =/ EDIT: I may have incorrect logging settings... I will take a look at this later today and reply with results...
            blitzmann Ryan Holmes (Inactive) added a comment -

            Okay, I got some errors. Using PHPMyAdmin, I accessed the `oq_graph` tables, this immediately popped up in the error log:

            http://pastebin.com/kgiYeS8N

            This did not cause 100% CPU tho. It immediately error's out, and PHPMyAdmin when to the login screen with a "#1045 Cannot log in to the MySQL server".

            I can still query the table from the cli client - I have not yet reproduced "Lost Connection" on the CLI yet.

            I deleted the log file, reboot the machine, and tried again: access `oq_graph` from PHPMyAdmin. mysqld goes up to 99.4% and stays there, nothing gets printed to the logfile. While it's nearing 100%, I am still able to log in via CLI and print table. I finally restart the service. The only thing printed to log at this is:

            140320 0:07:34 [Note] /usr/sbin/mysqld: Normal shutdown
            140320 0:07:34 [Note] Event Scheduler: Purging the queue. 0 events
            140320 0:07:34 [Note] InnoDB: FTS optimize thread exiting.
            140320 0:07:34 [Note] InnoDB: Starting shutdown...

            I kill the restart after it takes 1 minutes, and just try to start it again. Service starts fails, next log entries are:

            140320 0:08:34 [Note] InnoDB: Waiting for 2 active transactions to finish
            140320 00:08:57 mysqld_safe A mysqld process already exists
            140320 0:09:34 [Note] InnoDB: Waiting for 2 active transactions to finish

            After rebooting again, going back to PHPMyAdmin to that table causes spike in CPU again.

            Reboot again, access the table via CLI first, THEN go to PHPMyAdmin. Access to table is fine in PHPMyAdmin this time. I try to access my own projects OQGRAPH table via PHPMyAdmin, hangs at 100% CPU...

            Reboot, I again try to CLI first (which works), then again PHPMyAdmin, which works. This time, I access my project table first via CLI, and then PHPMyAdmin: it works.

            Here's another log:
            http://pastebin.com/1PicQ5yu
            Not sure when that one happened unfortunately.

            blitzmann Ryan Holmes (Inactive) added a comment - Okay, I got some errors. Using PHPMyAdmin, I accessed the `oq_graph` tables, this immediately popped up in the error log: http://pastebin.com/kgiYeS8N This did not cause 100% CPU tho. It immediately error's out, and PHPMyAdmin when to the login screen with a "#1045 Cannot log in to the MySQL server". I can still query the table from the cli client - I have not yet reproduced "Lost Connection" on the CLI yet. I deleted the log file, reboot the machine, and tried again: access `oq_graph` from PHPMyAdmin. mysqld goes up to 99.4% and stays there, nothing gets printed to the logfile. While it's nearing 100%, I am still able to log in via CLI and print table. I finally restart the service. The only thing printed to log at this is: 140320 0:07:34 [Note] /usr/sbin/mysqld: Normal shutdown 140320 0:07:34 [Note] Event Scheduler: Purging the queue. 0 events 140320 0:07:34 [Note] InnoDB: FTS optimize thread exiting. 140320 0:07:34 [Note] InnoDB: Starting shutdown... I kill the restart after it takes 1 minutes, and just try to start it again. Service starts fails, next log entries are: 140320 0:08:34 [Note] InnoDB: Waiting for 2 active transactions to finish 140320 00:08:57 mysqld_safe A mysqld process already exists 140320 0:09:34 [Note] InnoDB: Waiting for 2 active transactions to finish After rebooting again, going back to PHPMyAdmin to that table causes spike in CPU again. Reboot again, access the table via CLI first, THEN go to PHPMyAdmin. Access to table is fine in PHPMyAdmin this time. I try to access my own projects OQGRAPH table via PHPMyAdmin, hangs at 100% CPU... Reboot, I again try to CLI first (which works), then again PHPMyAdmin, which works. This time, I access my project table first via CLI, and then PHPMyAdmin: it works. Here's another log: http://pastebin.com/1PicQ5yu Not sure when that one happened unfortunately.
            blitzmann Ryan Holmes (Inactive) added a comment -

            Issue is still present with 10.0.10. =(

            blitzmann Ryan Holmes (Inactive) added a comment - Issue is still present with 10.0.10. =(
            elenst Elena Stepanova added a comment -

            See also MDEV-5891 and MDEV-5988.

            elenst Elena Stepanova added a comment - See also MDEV-5891 and MDEV-5988 .
            elenst Elena Stepanova made changes -
            Fix Version/s 10.0.11 [ 15200 ]
            arjen Arjen Lentz added a comment -

            Ryan, which storage engine is the backing table?

            If you are able to run a debug version of mysqld, that'd be really helpful - upload the trace file in this issue so that we can see the flow of the system before it crashes.
            For the crash, just checking your errorlog will already help - the backtrace provides good information for us. You may need to resolve the stacktrace (see manual) before submitting it here.

            Basically the more detail you are able to provide us with regarding what steps cause the issue and then what happens exactly behind the scenes on your system, the faster we might be able to track down the issue and fix it!
            Thanks

            arjen Arjen Lentz added a comment - Ryan, which storage engine is the backing table? If you are able to run a debug version of mysqld, that'd be really helpful - upload the trace file in this issue so that we can see the flow of the system before it crashes. For the crash, just checking your errorlog will already help - the backtrace provides good information for us. You may need to resolve the stacktrace (see manual) before submitting it here. Basically the more detail you are able to provide us with regarding what steps cause the issue and then what happens exactly behind the scenes on your system, the faster we might be able to track down the issue and fix it! Thanks
            arjen Arjen Lentz made changes -
            Assignee Arjen Lentz [ arjen ] Andrew McDonnell [ andymc73 ]
            blitzmann Ryan Holmes (Inactive) added a comment -

            I believe it's InnoDB. I'll look into running debug.

            blitzmann Ryan Holmes (Inactive) added a comment - I believe it's InnoDB. I'll look into running debug.
            andymc73 Andrew McDonnell added a comment -

            I suspect this is the same bug as (patch proposed) MDEV-5891, especially if you tried to select on an empty table...

            andymc73 Andrew McDonnell added a comment - I suspect this is the same bug as (patch proposed) MDEV-5891 , especially if you tried to select on an empty table...
            andymc73 Andrew McDonnell made changes -
            serg Sergei Golubchik made changes -
            Fix Version/s 10.0.12 [ 15201 ]
            Fix Version/s 10.0.11 [ 15200 ]
            andymc73 Andrew McDonnell added a comment -

            In the absence of further information, I think this is a duplicate of MDEV-5891. Please open a new issue if new information is available.

            andymc73 Andrew McDonnell added a comment - In the absence of further information, I think this is a duplicate of MDEV-5891 . Please open a new issue if new information is available.
            andymc73 Andrew McDonnell made changes -
            Fix Version/s 10.0.12 [ 15201 ]
            Resolution Duplicate [ 3 ]
            Status Open [ 1 ] Closed [ 6 ]
            serg Sergei Golubchik made changes -
            Workflow defaullt [ 36300 ] MariaDB v2 [ 44387 ]
            ratzpo Rasmus Johansson (Inactive) made changes -
            Workflow MariaDB v2 [ 44387 ] MariaDB v3 [ 61496 ]
            serg Sergei Golubchik made changes -
            Workflow MariaDB v3 [ 61496 ] MariaDB v4 [ 147598 ]

            People

              andymc73 Andrew McDonnell
              blitzmann Ryan Holmes (Inactive)
              Votes:
              0 Vote for this issue
              Watchers:
              5 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.