[#MDEV-5810] OQGRAPH causes MariaDB 100% CPU usage

[MDEV-5810] OQGRAPH causes MariaDB 100% CPU usage Created: 2014-03-10 Updated: 2014-05-26 Resolved: 2014-05-26
Status:	Closed
Project:	MariaDB Server
Component/s:	None
Affects Version/s:	10.0.8
Fix Version/s:	None

Type:

Bug

Priority:

Major

Reporter:

Ryan Holmes (Inactive)

Assignee:

Andrew McDonnell

Resolution:

Duplicate

Votes:

Labels:

oqgraph

Environment:

Debian Wheezy
MariaDB 10.0.8 (query cache disabled)

Issue Links:

Duplicate
duplicates	~~MDEV-5891~~	Assertion `! ((size_t)orig == (size_t...	Closed

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.

Comments

Comment by Ryan Holmes (Inactive) [ 2014-03-11 ]

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)

Comment by Arjen Lentz [ 2014-03-18 ]

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

Comment by Ryan Holmes (Inactive) [ 2014-03-18 ]

/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...

Comment by Ryan Holmes (Inactive) [ 2014-03-20 ]

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.

Comment by Ryan Holmes (Inactive) [ 2014-04-06 ]

Issue is still present with 10.0.10. =(

Comment by Elena Stepanova [ 2014-04-06 ]

[MDEV-5810] OQGRAPH causes MariaDB 100% CPU usage Created: 2014-03-10 Updated: 2014-05-26 Resolved: 2014-05-26