Bug 483060 - Akonadi sending UTC timestamps as local time to MySQL (and this failing around DST change) - QMYSQL bug?
Summary: Akonadi sending UTC timestamps as local time to MySQL (and this failing aroun...
Status: RESOLVED FIXED
Alias: None
Product: Akonadi
Classification: Frameworks and Libraries
Component: server (show other bugs)
Version: 5.24.4
Platform: Other Linux
: NOR normal
Target Milestone: ---
Assignee: kdepim bugs
URL:
Keywords:
: 483061 (view as bug list)
Depends on:
Blocks:
 
Reported: 2024-03-10 03:01 UTC by Thiago Macieira
Modified: 2024-03-12 07:50 UTC (History)
3 users (show)

See Also:
Latest Commit:
Version Fixed In:


Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description Thiago Macieira 2024-03-10 03:01:43 UTC
SUMMARY
KMail started failing to send emails for me with a message saying the item couldn't be stored. I did find this in the journal:

Mar 09 21:10:09 tjmaciei-mobl5 akonadiserver[745525]: org.kde.pim.akonadiserver: DATABASE ERROR:
Mar 09 21:10:09 tjmaciei-mobl5 akonadiserver[745525]: org.kde.pim.akonadiserver:   Error code: "1292"
Mar 09 21:10:09 tjmaciei-mobl5 akonadiserver[745525]: org.kde.pim.akonadiserver:   DB error:  "Incorrect datetime value: '2024-03-10 02:10:09.341000' for column `akonadi`.`pimitemtable`.`atime` at row 1"
Mar 09 21:10:09 tjmaciei-mobl5 akonadiserver[745525]: org.kde.pim.akonadiserver:   Error text: "Incorrect datetime value: '2024-03-10 02:10:09.341000' for column `akonadi`.`pimitemtable`.`atime` at row 1 QMYSQL3: Unable to execute statement"
Mar 09 21:10:09 tjmaciei-mobl5 akonadiserver[745525]: org.kde.pim.akonadiserver:   Values: QMap((":0", QVariant(QDateTime, QDateTime(2024-03-10 02:10:09.341 UTC Qt::UTC)))(":1", QVariant(qlonglong, 770803)))
Mar 09 21:10:09 tjmaciei-mobl5 akonadiserver[745525]: org.kde.pim.akonadiserver:   Query: "UPDATE PimItemTable SET atime = :0 WHERE ( ( PimItemTable.id = :1 ) )"
Mar 09 21:10:09 tjmaciei-mobl5 akonadiserver[745525]: org.kde.pim.akonadiserver: Unable to update item access time

After stressing a bit about whether this was a database or filesystem corruption, I figured out that the issue was the actual time in that timestamp. MySQL rejects it:

MariaDB [akonadi]> UPDATE PimItemTable SET atime = timestamp('2024-03-10 02:10:55.625000') WHERE ( ( PimItemTable.id = 770804 ) );
ERROR 1292 (22007): Incorrect datetime value: '2024-03-10 02:10:55.625000' for column `akonadi`.`pimitemtable`.`atime` at row 1

If you look at the error message in the log, as well as the journalctl timestamp, 02:10:55 is an UTC time. But when this was sent to the DB server, there's no information that it is UTC. Thus the server rejects it thinking it's local time.


STEPS TO REPRODUCE
1. Set your system time such that the universal time, if computed as local time, would fall into the spring forward gap
2. Try to send an email

OBSERVED RESULT
Email sending fails.

EXPECTED RESULT
Email sending works.

SOFTWARE/OS VERSIONS
KDE Plasma Version: 5.27.10
KDE Frameworks Version: 5.115.0
Qt Version: 5.15.2

ADDITIONAL INFORMATION
This is probably a QMYSQL bug, because the QVariant as printed did have UTC time. The toMySqlDate() function was added for Qt 6.6, but I don't see a way to specify the timezone with MYSQL_TIME.

But maybe Akonadi can work around the issue by starting mysqld with TZ=UTC.
Comment 1 Thiago Macieira 2024-03-10 03:04:25 UTC
Or use the SET GLOBAL time_zone command.
Comment 2 Christophe Marin 2024-03-11 17:23:40 UTC
Duplicate of 483061?
Comment 3 Thiago Macieira 2024-03-11 19:20:43 UTC
(In reply to Christophe Marin from comment #2)
> Duplicate of 483061?

Looks like two people experienced the same problem at around the same time, yes.
Comment 4 Thiago Macieira 2024-03-11 19:22:13 UTC
*** Bug 483061 has been marked as a duplicate of this bug. ***
Comment 5 Thiago Macieira 2024-03-11 19:24:15 UTC
My reading of the MySQL API is that there's no way to pass the timestamp in prepared queries as UTC. You can only pass it as a local timestamp. Feels so 1980s...
Comment 6 Joshua J. Kugler 2024-03-11 19:35:42 UTC
When I was debugging this, someone in the #maria IRC channel said:
> As a workaround SQL mode flag ALLOW_INVALID_DATES should help, but it is better to store the UTC values properply as UTC.

So, there is that...but that does seem ugly. Can you even specify a TZ on a TIMESTAMP column in MySQL/MariaDB (it's been too long since I've actively used MySQL).

Another idea: have Akonadi set the client time zone to UTC when it connects. BUT: I don't know what that might do to the times it returns in other queries, so would require investigation, and if code would have to be changed elsewhere.
Comment 7 Joshua J. Kugler 2024-03-11 19:37:40 UTC
(In reply to Christophe Marin from comment #2)
> Duplicate of 483061?

That's quite funny. Mine is even the very next bug filed after this one. :)
Comment 8 Thiago Macieira 2024-03-11 20:03:42 UTC
> Another idea: have Akonadi set the client time zone to UTC when it connects. BUT: I don't know what that might do to the times it returns in other queries, so would require investigation, and if code would have to be changed elsewhere.

Applying that fix to QMYSQL instead. https://codereview.qt-project.org/c/qt/qtbase/+/546954
Comment 9 Daniel Vrátil 2024-03-12 07:50:45 UTC
Git commit c98b05b79aa849ebba2f4c309484428dd08df042 by Daniel Vrátil.
Committed on 12/03/2024 at 07:41.
Pushed by dvratil into branch 'master'.

Fix handling of UTC vs. local time for database engines

Each database handles datetimes slightly differently. Our biggest
problem was MySQL, where the QMYSQL driver strips timezone, so
the MySQL server assumes the time is a local time. Akonadi was,
however, passing a UTC time, which then MySQL tried to interpret
as local time, which lead to two issues:
  1) it failed if the time was not a valid time in local timezone (DST)
  2) it required special handling when reading the time back from DB
     because MySQL returned UTC time but with local timezone set.

So instead we make sure we handle datetime properly when insert it
into the database. This can be handled from a singular place in
QueryBuilder, so it's fully transparent to the caller.

There's no migration for the existing database, since at worst the
time is slightly off and shouldn't have actual impact on functionality.

This has also been fixed independently in Qt, so in the future
we might be able to drop this completely.

M  +2    -0    autotests/server/CMakeLists.txt
A  +139  -0    autotests/server/dbdatetimetest.cpp     [License: LGPL(v2.0+)]
A  +1    -0    autotests/server/unittestenv
M  +1    -1    src/server/dbmigrator/dbmigrator.cpp
M  +1    -1    src/server/handler/itemfetchhelper.cpp
M  +0    -3    src/server/storage/entities-source.xsl
M  +0    -3    src/server/storage/entities.xsl
M  +6    -1    src/server/storage/querybuilder.cpp
M  +34   -24   src/server/utils.h

https://invent.kde.org/pim/akonadi/-/commit/c98b05b79aa849ebba2f4c309484428dd08df042