[MDEV-20261] NULL passed to String::eq, SEGV, server crash, regression in 10.4 Created: 2019-08-05  Updated: 2021-12-11  Resolved: 2020-05-13

Status: Closed
Project: MariaDB Server
Component/s: Character Sets, Prepared Statements
Affects Version/s: 10.4
Fix Version/s: 10.5.4, 10.4.14

Type: Bug Priority: Critical
Reporter: Kris Karas Assignee: Alexander Barkov
Resolution: Fixed Votes: 2
Labels: mythtv
Environment:

Linux, GCC 9.1, QT 5.12.4, MythTV 30+

Attachments: File error-3.log     File general-3.log     Text File mariadb-backtrace-1.txt     File mythbackend-3.log    
Issue Links:
Duplicate
is duplicated by MDEV-21629 MythTV query causes MariaDB crash Closed
is duplicated by MDEV-22050 OR + incorrect bound null causes segf... Closed
is duplicated by MDEV-23220 MythTV SELECT request causes Mariadb ... Closed

 Description   

On upgrade from MariaDB 10.3 to 10.4, merge_key_fields() calls eq_by_collation(), Item_const_eq() and finally String::eq(NULL, <String>, <charset>), and thus SEGV. MariaDB 10.3 and below are not affected. The bug is reliably reproduced, but hard to narrow down, as the same query will execute twice correctly, and crash the server on the third go.

The client in this case is "mythbackend," the server component to the MythTV DVR. It communicates with MariaDB via QT, using prepared statements. The statement that causes the crash is always the same:

SELECT recordid, category, (category = ?) AS catmatch, (category = ?) AS typematch FROM record WHERE type = ? AND (category = ? OR category = ? OR category = 'Default') ORDER BY catmatch DESC, typematch DESC

The mythbackend program reports the DB error as follows:

Query was:
SELECT recordid, category, (category = ?) AS catmatch, (category = ?) AS typematch FROM record WHERE type = ? AND (category = ? OR category = ? OR category = 'Default') ORDER BY catmatch DESC, typematch DESC
Bindings were:
:CAT1="", :CAT2="", :CATTYPE1="", :CATTYPE2="", :TEMPLATE=11
Driver error was:
QMYSQL3: Unable to execute statement
Database error was:
MySQL server has gone away

As mentioned, this query has been run twice before in the same session, successfully. Immediately prior to the third (and failing) execution is a "smoking gun" of sorts, this log entry in mythbackend's log file:

QMYSQLResult::cleanup: unable to free statement handle

Immediately afterwards, the SELECT statement is prepared, executed, and crashes. This suggests that the "Close stmt" operation from the immediately preceding prepared statement returned an error. I upgraded QT from 5.12.2 to 5.12.4 (and also MythTV), but the result was the same.

I am attaching the MariaDB error.log and general.log showing the SQL executed and the resulting crash. Also attaching the log generated by mythbackend/QT, showing its activity. I recompiled MariaDB with CMAKE_BUILD_TYPE=Debug, and used that with GDB to obtain a more useful backtrace, also attached.

 Comments   
Comment by Kris Karas [ 2019-09-12 ]

I had hoped that, with the update to 10.4.8, that perhaps this bug would have been fixed (from some other bug report). But the bug remains. I also just tested against 10.4.0, in case the bug was introduced somewhere along the 10.4.x timeline; but it is present in 10.4.0 as well. I have also upgraded to the latest gcc, 9.2.0, as there were reported ABI issues with gcc 9.1.0 (which was used when compiling mariadb 10.4.7). But again, no change.

Looks as if I may need to find some way to reproduce this via a script, something that can trivially be run on your side. Due to the complexity of the app, I'm not sure how feasible that will be. Another reasonable tack would be to bisect the code between 10.3.x and 10.4.0 and narrow it down to a particular commit. Any "howto" available for that? I don't have any MariaDB source available locally except for the released tarballs.

Comment by Elena Stepanova [ 2020-02-05 ]

I'm raising the priority because we now have two reports about this (also MDEV-21629) and because the failure affects the third-party software which might have a significant user base.

Comment by drew [ 2020-02-10 ]

I am also experiencing a similar issue running 10.3.22. Is it possible another commit also is causing the issue?

  1. apt-cache policy mariadb-server
    mariadb-server:
    Installed: (none)
    Candidate: 1:10.3.22-0+deb10u1
    Version table:

This issue deadlocks mythtv-backend and possible mythfilldatabase and requires a complete restart/start of maria-db and mythtv and sometimes connected frontends (depending on what they're doing).

My query is different however but completely reproducible.

2020-02-09 18:27:22.538841 I [33500/35282] HttpServer11 mythdbcon.cpp:643 (exec) - MySQL server disconnected
 
2020-02-09 18:27:22.538859 E [33500/35282] HttpServer11 mythdb.cpp:181 (DBError) - DB Error (GetAllScheduled):
 
Query was:
 
SELECT record.title,       record.subtitle,           record.description, record.season,             record.episode,     record.category,           record.chanid,      channel.channum,           record.station,     channel.name,              record.recgroup,    record.playgroup,          record.seriesid,    record.programid,          record.inetref,     record.recpriority,        record.startdate,   record.starttime,          record.enddate,     record.endtime,            record.recordid,    record.type,               record.dupin,       record.dupmethod,          record.findid,                                 channel.commmethod                      FROM record LEFT JOIN channel ON channel.callsign = record.station GROUP BY recordid ORDER BY record.title ASC
 
Driver error was [2/2006]:
 
QMYSQL3: Unable to prepare statement
 
Database error was:
 
MySQL server has gone away

Comment by Elena Stepanova [ 2020-02-10 ]

It doesn't look like the same problem, not just because it's a different query, but even a different stage. Please attach or paste your server error log.

Comment by Alexander Barkov [ 2020-05-12 ]

This script does not crash:

DROP TABLE IF EXISTS test.t1;
 
CREATE TABLE test.t1 (f varchar(64)) ENGINE=MyISAM;
 
EXECUTE IMMEDIATE "SELECT * FROM test.t1 WHERE f = ? OR f = 'foo'" USING NULL;

So these two cases work differenly:

  • binding a parameter in dynamic SQL with help of USING NULL
  • binding a parameter in PS protocol using the MYSQL_TYPE_STRING data type with the NULL indicator set to true.
Comment by Alexander Barkov [ 2020-05-12 ]

This script binding a null SP variable does not crash:

DROP TABLE IF EXISTS t1;
 
CREATE TABLE t1 (f varchar(64)) ENGINE=MyISAM;
 
DELIMITER $$
 
BEGIN NOT ATOMIC
 
  DECLARE a VARCHAR(10) DEFAULT NULL;
 
  EXECUTE IMMEDIATE "SELECT * FROM test.t1 WHERE f = ? OR f = 'foo'" USING a;
 
END;
 
$$
 
DELIMITER ;
 
SHOW CREATE TABLE t1;

Comment by Alexander Barkov [ 2020-05-13 ] 

commit 9f20968169e21fcf8941041a8a7ce06013a79bd9 (HEAD -> 10.4, origin/bb-10.4-bar, origin/10.4)
 
Author: Alexander Barkov <bar@mariadb.com>
 
Date:   Tue May 12 19:45:21 2020 +0400
 
 
 
    MDEV-20261 NULL passed to String::eq, SEGV, server crash, regression in 10.4
 
    
    Type_handler_xxx::Item_const_eq() can handle only non-NULL values.
 
    The code in Item_basic_value::eq() did not take this into account.
 
    
    Adding a test to detect three different combinations:
 
    - Both values are NULLs, return true.
 
    - Only one value is NULL, return false.
 
    - Both values are not NULL, call Type_handler::Item_const_eq()
 
      to check equality.

Comment by Louis Tim Larsen [ 2020-05-22 ]

This bug doesn't seem to have been fixed in MariaDB 10.4.13. I still have issues viewing live tv on some channels after upgrading MariaDB on my MythTV backend. When downgrading MariaDB to 10.3.23 it works fine.

Also there does not seem to be any reference to this bug in the 10.4.13 release notes: https://mariadb.com/kb/en/mariadb-10413-release-notes/

Comment by Elena Stepanova [ 2020-05-22 ]

I think that's true, the fix didn't make it to the release and was pushed very soon afterwards. bar, could you please double-check and fix the version accordingly?

Comment by Louis Tim Larsen [ 2020-06-10 ]

This ticket should be reopened as this issue appear unsolved in stable.

Comment by Alexander Barkov [ 2020-06-11 ]

This bug was fixed in 10.4.14.

The original fix version 10.4.13 was wrong. i pushed the fix after 10.4.13 was cloned off.

Comment by Kris Karas [ 2020-08-13 ]

This is the OP, just chiming in that the fix from Alexander has been tested (against 10.5.5) and appears to work fine.

Today I upgraded 5 instances running 10.4 to 10.5, and figured I'd give it a whirl on the MythTV server still running 10.3.24. Before the fix, reproducing the bug was trivial when changing channels while watching "Live TV" on the MythTV application. After the fix/upgrade, to test, I changed channels with abandon, and could not cause MariaDB to crash. (I did manage to crash the MythTV frontend a few times by asking it to change channels too frequently and to a station with a poor signal, but that's not MariaDB's fault.)

Interestingly, I noticed many more connection-aborted errors with 10.5 than with 10.3 during my testing today. The log output from mariadbd was peppered with, for example:
2020-08-13 2:29:22 385 [Warning] Aborted connection 385 to db: 'unconnected' user: 'unauthenticated' host: 'oakdale' (This connection closed normally without authentication)
2020-08-13 2:32:29 406 [Warning] Aborted connection 406 to db: 'mythconverg' user: 'mythtv' host: 'springdale' (Got an error reading communication packets)
I assume this is a logging enhancement in 10.5 (or 10.4) and not a new issue. In any case, it does hint at a problem in MythTV's connection management code.

Comment by Alexander Barkov [ 2020-08-13 ]

Hi ktk, thanks for confirming that the bugs has gone. Sorry for the confusion with the initial wrong fixVersion.

Generated at Thu Feb 08 08:58:06 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.