What's DigiKam? Kan you provide an isolated repro case , which only involved mariadb database, and mariadb client?
The database is managed wia Qt's mysql plugin - I don't know how to create a repro case. I can provide an affected database if needed.
Maybe Digikam folks know how to create a repro case- that's their software after all . I mean, if someone determined that MariaDB is a problem, with exact git hash, I'd think there was some analysis before that.
The git hash was found by bisection, no knowledge of the internals is needed for that. I'll ask downstream if some digikam dev can help providing a test case.
Thank you. While I would not exclude all possibility that the error is our (or, mine, as pointed by git hash), although on the first glance I'd tend to think it is more likely surrounding code.
Also with the alleged slowness, a repro, that can be easily reproduced, using just mariadb, rather than layers on layers of someone else's code would be very helpful.
In the meantime, another Qt application (mythtv) has been reported to be broken by the same commit, so everything points to a bad interaction between the metadata cache and Qt's mysql driver code. The mythtv bug report contains a minimal test case (using only Qt):
https://github.com/MythTV/mythtv/issues/373#issuecomment-891723028
Someone there will hopefully figure out, how to translate that into minimal test case (using only MariaDB), or, fix the bug inside their driver, if there is a bug there.
Also, reading all the QT errors,
MySQL time zone support is missing. Please install it and try again. See 'mysql_tzinfo_to_sql' for assistance.
that is server, not the client error, and whether the result set metadata is cached or not, has no influence on that
from https://github.com/MythTV/mythtv/issues/373#issuecomment-890342273
INSERT INTO recordedseek (chanid, starttime, type, mark, offset) VALUES (2004,'2021-07-31T12:18:00Z',33,2544,101760),(2004,'2021-07-31T12:18:00Z',33,2564,102560),(2004,'2021-07-31T12:18:00Z',33,2584,103360),(2004,'2021-07-31T12:18:00Z',33,2604,104160),(2004,'2021-07-31T12:18:00Z',33,2624,104960),(2004,'2021-07-31T12:18:00Z',33,2644,105760),(2004,'2021-07-31T12:18:00Z',33,2665,106600),(2004,'2021-07-31T12:18:00Z',33,2685,107400),(2004,'2021-07-31T12:18:00Z',33,2711,108440),(2004,'2021-07-31T12:18:00Z',33,2731,109240),(2004,'2021-07-31T12:18:00Z',33,2750,110000),(2004,'2021-07-31T12:18:00Z',33,2770,110800)
|
Fails, because someone is using an unquoted keyword offset, which was added in MariaDB server 10.6.0 (see https://mariadb.com/kb/en/reserved-words/ ) and so on.
So, there is some unrelated stuff, which seems to be collectively blamed as "bad interaction between metadata cache and QT " 
wlad, may be a tcpdump capture could help? They can collect it without digging into exactly how two pieces of software interact
I do not think it would be too helpful, in this case. It does not crash parsing something, it is a memory overwrite. I'd usually think a problem such as memory overwrite is easiest to analyze with ASAN or Valgrind, or MSAN or AppVerifier, or some other memory checker.
Came across https://bugreports.qt.io/browse/QTBUG-95071, because of CONC-509 its not using prepared statements any more.
arojas, if you're bisecting, that is, you compile MariaDB anyway, you can, perhaps, compile with -DWITH_ASAN=1 ?
> Also, reading all the QT errors,
> MySQL time zone support is missing. Please install it and try again. See 'mysql_tzinfo_to_sql' for assistance.
> that is server, not the client error, and whether the result set metadata is cached or not, has no influence on that
This error comes from mythtv (code is here [1] and here [2]) and fails because the Qt prepared query returns null. Running the same query on mysql directly works. This is what the minimal test case is testing, and I've bisected it to the same commit 295f3e4cfb4a8f132f (more specifically, to commit 6a763b90006c559 in mariadb-connector-c) and confirmed it by building the 10.6.3 release with that connector-c commit reverted, which fixes all issues.
[1] https://github.com/MythTV/mythtv/blob/master/mythtv/programs/mythtv-setup/main.cpp#L556
[2] https://github.com/MythTV/mythtv/blob/master/mythtv/libs/libmythbase/dbutil.cpp#L866
> Came across https://bugreports.qt.io/browse/QTBUG-95071, because of CONC-509 its not using prepared statements any more.
I'm aware (I'm the reporter of that bug) - all testing here has been done with a Qt patched to workaround that version check issue, to make sure prepared statements are used. In fact, with an unpatched Qt everything works (for the wrong reasons: the two bugs cancel each other out).
mysql> SELECT CONVERT_TZ(NOW(), 'SYSTEM', 'Etc/UTC');
|
+----------------------------------------+
|
| CONVERT_TZ(NOW(), 'SYSTEM', 'Etc/UTC') |
|
+----------------------------------------+
|
| NULL |
|
+----------------------------------------+
|
1 row in set (0.01 sec)
|
That's a newly built 10.6, with mysql 8.0 client . It returns NULL, because timezone support was not installed. It would return the same with prepared or unprepared statement, with any client , in fact
IIUC, this test should work regardless of timezone support, and it works for me from mysql:
> SELECT CONVERT_TZ(NOW(), 'SYSTEM', '+0:00'); |
+--------------------------------------+
|
| CONVERT_TZ(NOW(), 'SYSTEM', '+0:00') | |
+--------------------------------------+
|
| 2021-08-09 08:57:48 | |
+--------------------------------------+
|
1 row in set (0.002 sec) |
Now, with the Qt test case (using the same query):
./tzcheck
|
return was a null value |
This is how to execute a prepared statement using executables that are build with MariaDB - that is , let's leave the Qt examples aside, as we do not build Qt (or Digikam, or MythTV) here.
Prepared statement from command line can be executed with
|
echo "SOME QUERY;" | mysqltest --ps-protocol ...
|
ps-protocol is documented here
So, let's try
echo "SELECT CONVERT_TZ(NOW(), 'SYSTEM', '+0:00');" | ./client/mysqltest --ps-protocol -uroot
|
and here is the result (note - no NULLs) on pristine database
SELECT CONVERT_TZ(NOW(), 'SYSTEM', '+0:00');
|
CONVERT_TZ(NOW(), 'SYSTEM', '+0:00')
|
2021-08-09 12:03:55
|
ok
|
and here is how to check that prepared statement is used - allow general_log with the server, and dump the general log - in this case it will have something like that . Note the Prepare and Execute in the output.
Tcp port: 0 Unix socket: (null)
|
Time Id Command Argument
|
210809 14:03:55 3 Connect root@localhost on using Socket
|
3 Prepare SELECT CONVERT_TZ(NOW(), 'SYSTEM', '+0:00')
|
3 Execute SELECT CONVERT_TZ(NOW(), 'SYSTEM', '+0:00')
|
3 Close stmt
|
Now do the same with Etc/UTC
wlad@workpc:~/xxx$ echo "SELECT CONVERT_TZ(NOW(), 'SYSTEM', 'Etc/UTC');" | ./client/mysqltest --ps-protocol -uroot
|
SELECT CONVERT_TZ(NOW(), 'SYSTEM', 'Etc/UTC');
|
CONVERT_TZ(NOW(), 'SYSTEM', 'Etc/UTC')
|
NULL
|
ok
|
As expected, without loaded timezones, it returns NULL
Now load timezones.
wlad@workpc:~/xxx$ ./sql/mysql_tzinfo_to_sql /usr/share/zoneinfo |./client/mysql -uroot --protocol=tcp mysql
|
Warning: Unable to load '/usr/share/zoneinfo/leap-seconds.list' as time zone. Skipping it.
|
Now , repeat the SELECT with timezone name
wlad@workpc:~/xxx$ echo "SELECT CONVERT_TZ(NOW(), 'SYSTEM', 'Etc/UTC');" | ./client/mysqltest --ps-protocol -uroot
|
SELECT CONVERT_TZ(NOW(), 'SYSTEM', 'Etc/UTC');
|
CONVERT_TZ(NOW(), 'SYSTEM', 'Etc/UTC')
|
2021-08-09 12:14:28
|
ok
|
Make sure that it is 10.6 that I'm running.
./client/mysql -uroot -e "SHOW VARIABLES LIKE 'version%'"
|
+-------------------------+------------------------------------------+
|
| Variable_name | Value |
|
+-------------------------+------------------------------------------+
|
| version | 10.6.4-MariaDB-log |
|
| version_comment | Source distribution |
|
| version_compile_machine | x86_64 |
|
| version_compile_os | Linux |
|
| version_malloc_library | system |
|
| version_source_revision | 2db692f5b4d6bb31a331dab44544171c455f6aca |
|
| version_ssl_library | OpenSSL 1.1.1 11 Sep 2018 |
|
+-------------------------+------------------------------------------+
|
What does it all prove ? It proves that there is no bug in SELECT CONVERT_TZ(NOW(), 'SYSTEM', 'Etc/UTC');
and no bugs in SELECT CONVERT_TZ(NOW(), 'SYSTEM', '+0:00') , pertaining to prepared statements.
Qt developer here attempting to debug this issue. This problem appears to happen exclusively with connector-c 3.2 and the 10.6 server. If I try the older connector with 10.6 or the new connector with 10.5, no problem happens.
Here's an ltrace of the calls Qt made:
libqsqlmysql.t.so->mysql_stmt_init(0xdbd460) = 0xdb9810
|
libqsqlmysql.t.so->mysql_stmt_prepare(0xdb9810, "SELECT CONVERT_TZ(NOW(), 'SYSTEM"..., 45) = 0
|
libqsqlmysql.t.so->mysql_stmt_param_count(0xdb9810) = 0
|
libqsqlmysql.t.so->mysql_stmt_result_metadata(0xdb9810) = 0xdbb000
|
libqsqlmysql.t.so->mysql_num_fields(0xdbb000) = 1
|
libqsqlmysql.t.so->mysql_fetch_field(0xdbb000) = { "CONVERT_TZ(NOW(), 'SYSTEM', 'Etc"..., "", "", "", "", "def", nil, 19, 0, 38, 0, 0, 0, 0, 3, 0, 0x80, 0, 63, 0xc, nil }
|
libqsqlmysql.t.so->mysql_fetch_field(0xdbb000) = nil
|
libqsqlmysql.t.so->mysql_stmt_reset(0xdb9810) = 0
|
libqsqlmysql.t.so->mysql_stmt_param_count(0xdb9810) = 0
|
libqsqlmysql.t.so->mysql_stmt_execute(0xdb9810) = 0
|
libqsqlmysql.t.so->mysql_stmt_affected_rows(0xdb9810) = 18446744073709551615
|
libqsqlmysql.t.so->mysql_stmt_bind_result(0xdb9810, 0xdbdf20) = 0
|
libqsqlmysql.t.so->mysql_stmt_store_result(0xdb9810) = 0
|
libqsqlmysql.t.so->mysql_stmt_data_seek(0xdb9810, 0) = <void>
|
libqsqlmysql.t.so->mysql_stmt_fetch(0xdb9810) = 0
|
[259193.225] qtbug-95639(1829760 1829760)(unknown): ""
|
mysql_fetch_field call comes from QMYSQLResultPrivate::bindInValues. In this code:
MYSQL_BIND *bind = &inBinds[i];
|
char *field = new char[fieldInfo->length + 1];
|
memset(field, 0, fieldInfo->length + 1);
|
|
|
bind->buffer_type = fieldInfo->type;
|
bind->buffer = field;
|
bind->buffer_length = f.bufLength = fieldInfo->length + 1;
|
bind->is_null = &f.nullIndicator;
|
bind->length = &f.bufLength;
|
bind->is_unsigned = fieldInfo->flags & UNSIGNED_FLAG ? 1 : 0;
|
f.outField=field;
|
I can confirm by debugging with both connectors that:
- fieldInfo->length = 19
- fieldInfo->type = FIELD_TYPE_DATETIME before being overridden by Qt a few lines above.
As you can see, Qt stores the value length + 1 in the variable, so it starts as 20. With a hardware watchpoint, I can see where the value changes. With connector 3.1:
Old value = 20
|
New value = 19
|
0x00007ffff62a48f8 in mysql_set_local_infile_handler () from /lib64/libmariadb.so.3
|
(gdb) bt
|
#0 0x00007ffff62a48f8 in mysql_set_local_infile_handler () from /lib64/libmariadb.so.3
|
#1 0x00007ffff62a4d01 in mysql_set_local_infile_handler () from /lib64/libmariadb.so.3
|
#2 0x00007ffff629ef5f in ?? () from /lib64/libmariadb.so.3
|
#3 0x00007ffff62a0b40 in mysql_stmt_fetch () from /lib64/libmariadb.so.3
|
#4 0x00007ffff62ece08 in QMYSQLResult::fetch (this=0x45cf50, i=0) at /home/tjmaciei/src/qt/qt6/qtbase/src/plugins/sqldrivers/mysql/qsql_mysql.cpp:461
|
#5 0x00007ffff62ed251 in QMYSQLResult::fetchFirst (this=0x45cf50) at /home/tjmaciei/src/qt/qt6/qtbase/src/plugins/sqldrivers/mysql/qsql_mysql.cpp:532
|
#6 0x00007ffff7f72a2f in QSqlQuery::next (this=0x7fffffffd6a0) at /home/tjmaciei/src/qt/qt6/qtbase/src/sql/kernel/qsqlquery.cpp:687
|
#7 0x00000000004025e6 in main () at main.cpp:16
|
But with connector 3.2:
Old value = 20
|
New value = 7
|
0x00007ffff62a4a28 in mysql_set_local_infile_handler () from /lib64/libmariadb.so.3
|
(gdb) bt
|
#0 0x00007ffff62a4a28 in mysql_set_local_infile_handler () from /lib64/libmariadb.so.3
|
#1 0x00007ffff62a4d03 in mysql_set_local_infile_handler () from /lib64/libmariadb.so.3
|
#2 0x00007ffff629f32f in ?? () from /lib64/libmariadb.so.3
|
#3 0x00007ffff62a0f10 in mysql_stmt_fetch () from /lib64/libmariadb.so.3
|
#4 0x00007ffff62ece08 in QMYSQLResult::fetch (this=0x45cf50, i=0) at /home/tjmaciei/src/qt/qt6/qtbase/src/plugins/sqldrivers/mysql/qsql_mysql.cpp:461
|
#5 0x00007ffff62ed251 in QMYSQLResult::fetchFirst (this=0x45cf50) at /home/tjmaciei/src/qt/qt6/qtbase/src/plugins/sqldrivers/mysql/qsql_mysql.cpp:532
|
#6 0x00007ffff7f72a2f in QSqlQuery::next (this=0x7fffffffd6a0) at /home/tjmaciei/src/qt/qt6/qtbase/src/sql/kernel/qsqlquery.cpp:687
|
#7 0x00000000004025e6 in main () at main.cpp:16
|
So when Qt goes to convert the fetched data into its representable form, in QMYSQLResult::data():
if (f.type.id() != QMetaType::QByteArray)
|
val = QString::fromUtf8(f.outField, f.bufLength);
|
We see:
- f.bufLength = 7
- f.outField contains a garbage string (no pattern I could discern: e5 07 08 0d 13 1f 2c)
The byte pattern is actually obvious... It is the time stamp, expressed in bytes: 2021 7 8 13 19 31
Did you try the obvious, e.g loading the timezone tables?
I'm wondering why would Qt try to interpret every data it fetches as a string, but I leave up to you guys to figure out. I think the general rule for datetime is to fetch that into some MYSQL_TIME https://dev.mysql.com/doc/c-api/8.0/en/c-api-prepared-statement-data-structures.html
I don't see how it would be MYSQL_TIME, since the field length is 19 and the sizeof(MYSQL_TIME) is 40. I'll attempt to implement something bound to MYSQL_TIME at a later time.
Anyway, I've found it. This was it:
* fieldInfo->type = FIELD_TYPE_DATETIME before being overridden by Qt a few lines above.
The overriding was actually writing to the MYSQL_FIELD structure returned by mysql_fetch_field. That function returns a non-const pointer and our code had been using it to store some data for 15 years. After I changed all the variables to const MYSQL_FIELD *, the problem went away. Working now on cleaning up the patch for submission.
Testcase:
MYSQL *mysql = mysql_init(nullptr);
|
if ((mysql = mysql_real_connect(mysql, nullptr, nullptr, nullptr, nullptr, 0, "/tmp/mysql.socket", 0))) {
|
MYSQL_STMT *stmt = mysql_stmt_init(mysql);
|
if (mysql_stmt_prepare(stmt, querystr, strlen(querystr)) == 0) {
|
char result[64] = {};
|
unsigned long length = sizeof(result) - 1;
|
my_bool nullIndicator = false;
|
MYSQL_BIND bind = {
|
.length = &length,
|
.is_null = &nullIndicator,
|
.buffer = &result,
|
.buffer_length = sizeof(result),
|
.buffer_type = MYSQL_TYPE_STRING,
|
};
|
|
|
MYSQL_RES *meta = mysql_stmt_result_metadata(stmt);
|
if (mysql_num_fields(meta) == 1) {
|
MYSQL_FIELD *fieldInfo = mysql_fetch_field(meta);
|
Q_ASSERT(fieldInfo->length < length);
|
bind.buffer_length = length = fieldInfo->length + 1;
|
fieldInfo->type = MYSQL_TYPE_STRING; // <=== this is the problem
|
|
|
Q_ASSERT(mysql_fetch_field(meta) == nullptr);
|
|
|
mysql_stmt_reset(stmt);
|
Q_ASSERT(mysql_stmt_param_count(stmt) == 0);
|
mysql_stmt_execute(stmt);
|
mysql_stmt_bind_result(stmt, &bind);
|
mysql_stmt_store_result(stmt);
|
mysql_stmt_data_seek(stmt, 0);
|
mysql_stmt_fetch(stmt);
|
printf("Result: %.*s\n", length, result);
|
}
|
}
|
mysql_stmt_close(stmt);
|
}
|
fieldInfo->type = MYSQL_TYPE_STRING; // <=== this is the problem
|
Indeed, this is a problem. User of this API is not supposed to change MYSQL_FIELD * returned by mysql_fetch_field. What's the point? It is internally used by the server to know how to decipher the data in prepared statements.
The "field length" is not the data length used for storage, nor in the client-server protocol, nor in client structs.
Just like int(10) in "show create table t" does not represent 10-byte integers. It is "display length", the length in characters for textual representation.
Indeed, this is a problem. User of this API is not supposed to change MYSQL_FIELD * returned by mysql_fetch_field. What's the point? It is internally used by the server to know how to decipher the data in prepared statements.
Because the returned pointer wasn't pointing to const data, so whoever wrote the code to support binding results to output variables with the MySQL 4.1.8 API made a shortcut. It happened some time between Qt 3.3 (2004) and 4.5 (2009), for which there is no public Git history, so I can't pinpoint the exact commit. But you can see the oldest implementation at https://github.com/qt/qt/blob/v4.5.1/src/sql/drivers/mysql/qsql_mysql.cpp#L331-L376. So that developer realised that the output type had to be forced to string for some of the column types, they modified fieldInfo->type.
Not an excuse, but it's likely what happened.
I recommend adding const to data structures that the user shouldn't modify, when you have a chance to clean the API and apply const-correctness.
I'm closing as not a bug. I can't stop wondering how did that in Qt ever work, it could not have in my opinion. If all Qt wants are strings, there is a wonderful and easy API, mysql_query which gives strings. You do not need prepared statement for that..
Const is a good suggestion, but I'm not sure 20 year old APIs can be fixed like that.