silverstripe / silverstripe-framework

Silverstripe Framework, the MVC framework that powers Silverstripe CMS
https://www.silverstripe.org
BSD 3-Clause "New" or "Revised" License
721 stars 822 forks source link

UTF8MB4 Breaks cron tasks #9811

Closed Firesphere closed 3 years ago

Firesphere commented 3 years ago

Affected Version

4.x latest

Description

Using MariaDB on Ubuntu 18.04, the " quoted queries ran from a cron job, throw an error

Steps to Reproduce

Run a cron job that requires querying the database

Firesphere commented 3 years ago

As per multiple comments in the Slack workspace, this is not just cronjobs, but it has deeper impacts on multiple users.

In my opinion, this is quite high impact, given at least 10 people (if my count is correct, and it's not including those that just don't complain), it breaks quite a few websites.

I think, the immediate solution is reverting to UTF8 (non-MB4), until a working solution has been found.

kinglozzer commented 3 years ago

Can you describe the issue in more detail? Code samples/examples of errors would probably help here đź‘Ť

Firesphere commented 3 years ago

vendor/bin/sake dev/tasks/crontask will throw an error, saying "Error near " at SELECT "Table"."Column" Same for the crontask for QueuedJobs, I don't know the exact command.

builds will break if the DB is not the latest version of MySQL. For example, MariaDB will break on indexes

emteknetnz commented 3 years ago

I cannot replicate this issue using framework 4.7.x-dev or 4.x-dev and crontask 2.1.3, using mariadb 10.5.2 and php 7.1.33

Could you please provide further replication steps?

Test run and code below:

www-data@www:/var/www$ vendor/bin/sake dev/cron
2021-01-08 12:40:24 - TestCron will start now.
TestCron::process
my-title

CronTest.php

<?php

use SilverStripe\CronTask\Interfaces\CronTask;

class TestCron implements CronTask
{
    public function getSchedule()
    {
        return "* * * * *";
    }

    public function process()
    {
        echo __CLASS__ . '::' . __FUNCTION__ . chr(10);
        echo MyModel::get()->first()->MyTitle . chr(10);
    }
}

MyModel.php

<?php

use SilverStripe\ORM\DataObject;

class MyModel extends DataObject
{
    private static $db = [
        'MyTitle' => 'Varchar'
    ];

    private static $indexes = [
        'MyTitle' => true
    ];

    public function requireDefaultRecords()
    {
        parent::requireDefaultRecords();
        if (self::get()->count() == 0) {
            $record = self::create();
            $record->MyTitle = 'my-title';
            $record->write();
        }
    }
}
Firesphere commented 3 years ago

Issue is on Ubuntu 18.04, which is at MariaDB 10.1, also, check the Slack Silverstripe Users workspace for details, as it's been mentioned there.

This is a crucial difference in the Ubuntu supported MariaDB version for the used server.

Firesphere commented 3 years ago

Furthermore, indexes of 255 characters, will break the build. MariaDB's support for longer indexes or unique, do not work.

Firesphere commented 3 years ago

The example you created, will throw the following error: Error near " at "TableName"."MyTitle", aka, same error.

emteknetnz commented 3 years ago

Community slack discussions

emteknetnz commented 3 years ago

I tried dropping mariadb down to 10.1.10 (docker container uses ubuntu 18.04 as far as I'm aware) though I am still unable to replicate this issue using the code sample above. I'm not sure what further I can do here without further replication steps.

Firesphere commented 3 years ago

Full stack trace from one of my machines:

SilverStripe\ORM\Connect\DatabaseException: Couldn't run query:

SELECT DISTINCT "STMessage"."ClassName", "STMessage"."LastEdited", "STMessage"."Created", "STMessage"."Text", "STMessage"."IsAddress", "STMessage"."Encrypted", "STMessage"."RequestRead", "STMessage"."ProvideRead", "STMessage"."RequesterID", "STMessage"."ProviderID", "STMessage"."MessageGroupID", "STMessage"."ID", 
            CASE WHEN "STMessage"."ClassName" IS NOT NULL THEN "STMessage"."ClassName"
            ELSE 'Firesphere\\StickerTrade\\Models\\Message' END AS "RecordClassName"

FROM "STMessage"

WHERE ("STMessage"."IsAddress" = ?)
 AND ("STMessage"."Created" < ?)

You have an error in your SQL syntax; check the manual that corresponds to your MariaDB server version for the right syntax to use near '."ClassName", "STMessage"."LastEdited", "STMessage"."Created", "STMessage"."Text' at line 1
#55 /ORM/Connect/DBConnector.php(64): SilverStripe\ORM\Connect\DBConnector::databaseError
#54 /ORM/Connect/MySQLiConnector.php(300): SilverStripe\ORM\Connect\MySQLiConnector::preparedQuery
#53 /ORM/Connect/Database.php(185): SilverStripe\ORM\Connect\Database::SilverStripe\ORM\Connect\{closure}
#52 /ORM/Connect/Database.php(258): SilverStripe\ORM\Connect\Database::benchmarkQuery
#51 /ORM/Connect/Database.php(183): SilverStripe\ORM\Connect\Database::preparedQuery
#50 /ORM/Connect/MySQLDatabase.php(402): SilverStripe\ORM\Connect\MySQLDatabase::preparedQuery
#49 /ORM/DB.php(445): SilverStripe\ORM\DB::prepared_query
#48 /ORM/Queries/SQLExpression.php(115): SilverStripe\ORM\Queries\SQLExpression::execute
#47 /ORM/DataList.php(743): SilverStripe\ORM\DataList::toArray
#46 /ORM/DataList.php(871): SilverStripe\ORM\DataList::getIterator
#45 /Tasks/ClearPrivateMessages.php(29): Firesphere\StickerTrade\Jobs\ClearPrivateMessages::run
#44 /Dev/TaskRunner.php(127): SilverStripe\Dev\TaskRunner::runTask
#43 /Control/RequestHandler.php(323): SilverStripe\Control\RequestHandler::handleAction
#42 /Control/Controller.php(286): SilverStripe\Control\Controller::handleAction
#41 /Control/RequestHandler.php(202): SilverStripe\Control\RequestHandler::handleRequest
#40 /Control/Controller.php(212): SilverStripe\Control\Controller::handleRequest
#39 /Control/RequestHandler.php(226): SilverStripe\Control\RequestHandler::handleRequest
#38 /Control/Controller.php(212): SilverStripe\Control\Controller::handleRequest
#37 /Control/Director.php(360): SilverStripe\Control\Director::SilverStripe\Control\{closure}
#36 /VersionedHTTPMiddleware.php(41): SilverStripe\Versioned\VersionedHTTPMiddleware::process
#35 /Control/Middleware/HTTPMiddlewareAware.php(62): SilverStripe\Control\Director::SilverStripe\Control\Middleware\{closure}
#34 /Control/Middleware/ConfirmationMiddleware.php(254): SilverStripe\Control\Middleware\ConfirmationMiddleware::process
#33 /Control/Middleware/HTTPMiddlewareAware.php(62): SilverStripe\Control\Director::SilverStripe\Control\Middleware\{closure}
#32 /Control/Middleware/ConfirmationMiddleware.php(254): SilverStripe\Control\Middleware\ConfirmationMiddleware::process
#31 /Control/Middleware/HTTPMiddlewareAware.php(62): SilverStripe\Control\Director::SilverStripe\Control\Middleware\{closure}
#30 /Security/PasswordExpirationMiddleware.php(84): SilverStripe\Security\PasswordExpirationMiddleware::process
#29 /Control/Middleware/HTTPMiddlewareAware.php(62): SilverStripe\Control\Director::SilverStripe\Control\Middleware\{closure}
#28 /Security/BasicAuthMiddleware.php(68): SilverStripe\Security\BasicAuthMiddleware::process
#27 /Control/Middleware/HTTPMiddlewareAware.php(62): SilverStripe\Control\Director::SilverStripe\Control\Middleware\{closure}
#26 /Security/AuthenticationMiddleware.php(61): SilverStripe\Security\AuthenticationMiddleware::process
#25 /Control/Middleware/HTTPMiddlewareAware.php(62): SilverStripe\Control\Director::SilverStripe\Control\Middleware\{closure}
#24 /Control/Middleware/CanonicalURLMiddleware.php(190): SilverStripe\Control\Middleware\CanonicalURLMiddleware::process
#23 /Control/Middleware/HTTPMiddlewareAware.php(62): SilverStripe\Control\Director::SilverStripe\Control\Middleware\{closure}
#22 /Control/Middleware/HTTPCacheControlMiddleware.php(42): SilverStripe\Control\Middleware\HTTPCacheControlMiddleware::process
#21 /Control/Middleware/HTTPMiddlewareAware.php(62): SilverStripe\Control\Director::SilverStripe\Control\Middleware\{closure}
#20 /Control/Middleware/ChangeDetectionMiddleware.php(28): SilverStripe\Control\Middleware\ChangeDetectionMiddleware::process
#19 /Control/Middleware/HTTPMiddlewareAware.php(62): SilverStripe\Control\Director::SilverStripe\Control\Middleware\{closure}
#18 /Control/Middleware/FlushMiddleware.php(27): SilverStripe\Control\Middleware\FlushMiddleware::process
#17 /Control/Middleware/HTTPMiddlewareAware.php(62): SilverStripe\Control\Director::SilverStripe\Control\Middleware\{closure}
#16 /Control/RequestProcessor.php(66): SilverStripe\Control\RequestProcessor::process
#15 /Control/Middleware/HTTPMiddlewareAware.php(62): SilverStripe\Control\Director::SilverStripe\Control\Middleware\{closure}
#14 /Control/Middleware/SessionMiddleware.php(20): SilverStripe\Control\Middleware\SessionMiddleware::process
#13 /Control/Middleware/HTTPMiddlewareAware.php(62): SilverStripe\Control\Director::SilverStripe\Control\Middleware\{closure}
#12 /Control/Middleware/AllowedHostsMiddleware.php(60): SilverStripe\Control\Middleware\AllowedHostsMiddleware::process
#11 /Control/Middleware/HTTPMiddlewareAware.php(62): SilverStripe\Control\Director::SilverStripe\Control\Middleware\{closure}
#10 /Control/Middleware/TrustedProxyMiddleware.php(176): SilverStripe\Control\Middleware\TrustedProxyMiddleware::process
#9 /Control/Middleware/HTTPMiddlewareAware.php(62): SilverStripe\Control\Director::SilverStripe\Control\Middleware\{closure}
#8 /Control/Middleware/HTTPMiddlewareAware.php(65): SilverStripe\Control\Director::callMiddleware
#7 /Control/Director.php(369): SilverStripe\Control\Director::handleRequest
#6 /Control/HTTPApplication.php(117): SilverStripe\Control\HTTPApplication::SilverStripe\Control\{closure}
#5 [internal](0): call_user_func
#4 /Control/HTTPApplication.php(136): SilverStripe\Control\HTTPApplication::SilverStripe\Control\{closure}
#3 /Control/Middleware/HTTPMiddlewareAware.php(65): SilverStripe\Control\HTTPApplication::callMiddleware
#2 /Control/HTTPApplication.php(137): SilverStripe\Control\HTTPApplication::execute
#1 /Control/HTTPApplication.php(116): SilverStripe\Control\HTTPApplication::handle
#0 /vendor/silverstripe/framework/cli-script.php(22): null

Details:


Kernel Version | Linux vps278100 4.15.0-128-generic #131-Ubuntu SMP Wed Dec 9 06:57:35 UTC 2020 x86_64
Name | Linux
Version | 4.15.0-128-generic(#131-Ubuntu SMP Wed Dec 9 06:57:35 UTC 2020)
Name | php
Version | 7.4.13
Database | mariadb | Ver 15.1 Distrib 10.1.47-MariaDB, for debian-linux-gnu (x86_64) using readline 5.2

This is with UTF8MB4 enabled. Switching back to UTF8 fixes it.

Firesphere commented 3 years ago

Related code:

class Clear extends BuildTask {
    public function run($HTTPRequest)
    {
        $date = date('Y-m-d 00:00:00', strtotime('-3 days'));
        /** @var DataList|Message[] $msgs */
        $msgs = Message::get()->filter(['IsAddress' => true, 'Created:LessThan' => $date]);
    }
}

Relevant part of the Message class:

    private static $table_name = 'STMessage';

    private static $db = [
        'IsAddress'   => 'Boolean',
    ];

    private static $indexes = [
        'Created'    => true,
        'LastEdited' => true,
        'Encrypted'  => true,
    ];
emteknetnz commented 3 years ago

The release notes https://docs.silverstripe.org/en/4/changelogs/4.7.0/#default-mysql-collation-updated say that only new sites installed via silverstripe/installer should have ut8mb4 enabled unless you choose to switch in over yourself manually.

Was this an existing site with content already in the database that was on 4.6.x or less and was upgraded to 4.7.0 and the database collation automatically changed without you intending it to? Or was this a brand new site?

Firesphere commented 3 years ago

Both.

emteknetnz commented 3 years ago

So, by both does that mean it was a newly deployed site on 4.7.0 installed with silverstripe/installer, and, with a database snapshot restored from a different website that was on 4.6.x or less?

Firesphere commented 3 years ago

So, by both does that mean it was a newly deployed site on 4.7.0 installed with silverstripe/installer, and, with a database snapshot restored from a different website that was on 4.6.x or less?

The change is literally a breaking change, for multiple people.

Yes, a clean installation does break. Yes, an update of 4.6 to 4.7 breaks things Yes, Uniques, Indexes, etc. are unable to be ported

"YoU sHoUlD uPdAtE yOuR dAtAbAsE". Insert Spongebob meme here. For a lot of people, that is not an option. And, updating the database, includes migrating them off, and then on to the next version.

This change is a breaking change. If you can't replicate it, then, that's not my problem. It is not my problem, to solve your problems, so to speak.

@chillu , @unclecheese , @bergice , I would appreciate your input and more thorough testing.

Firesphere commented 3 years ago

I'm, to be honest, mildly fed up, with the responses given here so far. It's "I can't replicate, goodbye", by what is supposed to be a senior dev. However, the actual input and responses, are not that. The given responses is "Can't reproduce because we can't match your environment, goodbye". And that is not worthy an open source project kind of response.

unclecheese commented 3 years ago

I would appreciate your input and more thorough testing

With all due respect, I don't think you would. This thread evidences someone clearly taking a lot to time to understand your issue, and the level of "appreciation" you've shown is sarcastic barbs and a public indictment of his job title.

We all have a common interest to make the ecosystem healthier and more stable overall, but a lot of open source is about community and relationships, and the way you're interacting with others here leaves little incentive for anyone to offer up their time on your behalf.

Please afford some civility and respect. Not every issue can be understood and actioned immediately.

Firesphere commented 3 years ago

With all due respect, I don't think you would. This thread evidences someone clearly taking a lot to time to understand your issue, and the level of "appreciation" you've shown is sarcastic barbs and a public indictment of his job title.

Yes, I do.

My level of "appreciation" comes from the sheer amount of frustration with how PR's and/or issues are handled in general. It has nothing to do with a person, I have nothing against @emteknetnz , at all. I'm not questioning his knowledge or skills. The feedback however, is minimised, and in a way mostly "turning away from it".

But the sheer amount of effort that is asked for, is a burden on any OSS dev. You are asking for free time. And if you don't want to bother, then, don't bother.

This is a breaking change, and the closest to an investigation is "can't replicate against these two or three specific sets of data", without incentive to investigate.

This is not my issue, it's a wider issue. I've encouraged everyone that encountered it to add their problem. But the fact nobody did, puts it all on me.

I'm closing this one. I do not have confidence in a possible solution being drawn up.

chillu commented 3 years ago

Trying to catch up on this. Reopening this, to signal our willingness to support this process.

The issue has been observed by Simon on MariaDB 10.1.47. I'm assuming that Simon opted into the change for an existing project when upgrading to 4.7. The issue has also been observed by @Mac on Slack on MySQL 5.7

We currently state support for MySQL 5.6+. While MariaDB isn't explicitly supported, it's assumed to be a limited drop in replacement starting from MariaDB 10.0 for MySQL 5.6.

4.7 introduced an opt-in change for existing projects (which are perfectly fine under semver even if they turn out to be breaking changes). Nobody is forced to use it, but if there's known caveats we should document these. 4.7 sets utf8mb4 a new default for new projects (via the installer). New projects should work with supported database versions (so MySQL 5.6+). If they don't, that might be considered a breaking change. Apparently there's more impacted users on Slack, but it's hard to find out details.

We need to be able to reproduce to fix the issue, and that requires patience and input from the people experiencing the issues - that's pretty uncontroversial, right? But it sounds like Steve is stuck at the moment and needs help in being able to reproduce this. Maybe we need more isolation, e.g. running the same Docker image with a default codebase plus the specific code mentioned above? It'll get complicated if the issue can only be reproduced on an existing database snapshot.

P.S.: Unless it's related to the failures, I propose that we discuss the issue about MariaDB index sizes on a separate Github issue - this one is already complicated enough :)

Cheddam commented 3 years ago

We've determined that due to the collation adjustment being introduced in a separate config file, it is currently being installed in projects during upgrades, making this an opt-out change as of Recipe 4.7.0. I've raised two PRs to address this:

Sincere apologies for the confusion, @Firesphere - this was always seen and intended as an opt-in change.

Firesphere commented 3 years ago

Reopening this, to signal our willingness to support this process.

I closed the issue out of pure frustration. I openly admit that. The change to switch to MB4 is understandable, but I just wanted a breaking change to be fixed, and all I got initially was "I can't reproduce". I hope you understand that it's a frustrating thing, which, in a way, is similar to walking in to a wall.

The issue has been observed by Simon on MariaDB 10.1.47. I'm assuming that Simon opted into the change for an existing project when upgrading to 4.7. The issue has also been observed by @Mac on Slack on MySQL 5.7

I did not opt in, it was "forced" upon me. If it wasn't for me noticing the database.yml file being added to the installation, I would've pulled my hair out even more. (Any 10.1.x MariaDB and 6.4 or lower MySQL seems to have this issue, by the way, but some don't. It's a tad weird and I don't have a definitive answer to what is or isn't causing the problem)

Unrelated, I prefer to be called Firesphere on GitHub/GitLab etc. ;)

The issue has been observed by Simon on MariaDB 10.1.47. I'm assuming that Simon opted into the change for an existing project when upgrading to 4.7. The issue has also been observed by @Mac on Slack on MySQL 5.7

It was not just me, multiple people have observed the issue. Sadly, despite my efforts to have them chip in, nobody actually did. This may or may not (spoiler alert, it is), a reason why people don't chip in or open PR's or issues. As they don't feel taken seriously (as I do), which is why I resorted to sarcasm. I have nothing against the team, but if I keep running in to a wall.... something's gotta give.

4.7 introduced an opt-in change for existing projects (which are perfectly fine under semver even if they turn out to be breaking changes).

Despite best efforts on your side, it was, and is, an opt-out, not an opt-in, at the moment. This caused quite some issues which are, as you say, per semver, not to be expected. I do not mean anything bad, but I do stand with my frustration.

P.S.: Unless it's related to the failures, I propose that we discuss the issue about MariaDB index sizes on a separate Github issue - this one is already complicated enough :)

This is an issue I'm not sure about. Some MariaDB instances of 10.1+ seem to work, others don't, despite the large index setting. Right now, I feel it's more random. For example my local Vagrant machine on Ubuntu 18.04-latest works just fine, but one of my clients machines on production, doesn't. With exactly the same config files, except for the memory limit. It's confusing me at best.

this was always seen and intended as an opt-in change.

I expected that was the case. But it caused a lot of headache for quite a few people. Which is a shame. May I suggest, checking if the DB engine supports the change, for such impactful systems in the future. E.g. if "Ubuntu.OS <= 18.04 { Don't do anything };

@Cheddam Cheers!

I'm closing this issue, again, because it has taken up a lot of my time, which I should not have spent at it, in the end.

kinglozzer commented 3 years ago

As Firesphere doesn’t want to continue discussion here, I’ve opened a new issue for tracking this: https://github.com/silverstripe/silverstripe-framework/issues/9822

Cheddam commented 3 years ago

@Firesphere I appreciate that you've invested a lot of time and are keen to move on from this, but I've done some further testing against the same distro and MariaDB version you reported, and I have a theory about what the issue is.

When running the SQL query listed in the debug output you provided directly via the MariaDB CLI client, I get the same syntax error you encountered. The reason I get this is that the default sql_mode setting in the MariaDB CLI client doesn't include ANSI / ANSI_QUOTES, which is set by Silverstripe to allow the use of double quotes in place of backticks in queries.

In 4.7.0, alongside the collation change, sql_mode became configurable. The code that consumes this configuration does not check to see whether it is set correctly before using it, so if it was blank for some reason, queries in Silverstripe would start outputting that same syntax error.

My theory about the cause of your troubles is that the configuration cache used in the CLI environment of your servers needs to be flushed in order to populate the sql_mode configuration. This might explain the inconsistent results, as some servers may have had their cache flushed and others not.

If you have any further time to spare, I'd really appreciate if you could try running a dev/build via the CLI on an affected server, and then re-running the task.

Firesphere commented 3 years ago

Hi @kinglozzer It's not about not wanting to discuss, but now that it's properly opt-in in the next release, and I don't feel like I have the time or energy to discuss further. I've given every bit of information I have, and I left it at that. Discussion should continue on the PR made by @Cheddam , not here, in my opinion. You're free to disagree, of course.

@Cheddam My default set-up for this client flushes when updating the code twice, before and after the pull from the repository. And only if those are successful, runs a dev/build with flush. I've tried this multiple times, it has the same result.

martinduparc commented 3 years ago

FWIW, running a dev/build in the CLI (via sake) solved the issue for me. Running 10.3.7-MariaDB