Accessing the getDatabasePlatform triggers unexpected behaviour

Question

Accessing the getDatabasePlatform triggers unexpected behaviour

alexander-schranz opened this issue 2 years ago · 20 comments

The current jackalope versions 1.8.0, 1.8.1, 1.9.0 are failing as accessing the DatabasePlatform seems create an unexpected access.

The database platform seems to be needed detected differently as the getDatabasePlatform seems to trigger something unexpected.

I think the getDatabasePlatform does some unexpected query to the database which maybe make the transaction submitted in an unexpected time. Doctrine/dbal 3.6.0 is used so that is on latest version.

Answer 1 · 2023-02-24T14:48:48.000Z

that must be this change: 1.7.6...1.8.0#diff-13bb0fe16ba6f697f931eeaeb0f46c943b5066dc9bb0906f3889debebc96455cR94

do you configure what database you have or do you rely on doctrine autodetecting it?

Answer 2 · 2023-02-24T15:10:46.000Z

we have several places in the Client and other code that call getDatabasePlatform. this new call is in the bootstrapping of the system, so it seems surprising to me that it would break anything.

do you get the exception in the getDatabasePlatform call, or only later?
can you copy the stack trace into the ticket so i can read it? (the gif keeps cycling and i can't copy paste from it to find files).
or even better, do you manage to create a reproducer in a functional test in this repository?

from looking at the code, i think a workaround could be to specify the serverVersion when you instantiate doctrine dbal. then it will not need to do any query. (that would also in general make your application a bit more efficient as it avoids a database access in each request.)

Answer 3 · 2023-02-24T15:27:19.000Z

I will check if I can share a repository with you. Strange is that the serverVersion is in our case defined:

But yeah it has TODO with the ?serverVersion

Interesting is that we have the ?serverVersion correctly defined in all our projects and skeletons like this:

DATABASE_URL="mysql://root:ChangeMe@127.0.0.1:3306/su_myapp?serverVersion=8.0.27&charset=utf8mb4"

And it work like expected when using php -S 127.0.0.1:8000 -t public:
But our preferred and recommended way for developing using Symfony CLI (symfony serve) seems overwrite the serverVersion and the $_ENV['DATABASE_URL']; and $_SERVER['DATABASE_URL']; outputs a totally different value:

mysql://root:ChangeMe@127.0.0.1:3306/su_myapp?sslmode=disable&charset=utf8mb4

I don't understand where this magic is happening and why.

Answer 4 · 2023-02-24T15:33:00.000Z

strange indeed that the DSN changes. but that is probably not related to jackalope...

but anyways, things should work if you do not specify the version, so if we can find where this goes wrong it would be interesting.

Answer 5 · 2023-02-24T19:34:27.000Z

I pushed minimal repo where it happens here: https://github.com/alexander-schranz/reproducer-jackalope-error-1-9-0. It strange as it does only appear in that specific combination with the FormBundle that an error happens now, without it, it does not happen.

Here what is inside the symfony profiler. It also only happens when creating a new page. Editing existing ones work like expected. It feels like it also could be a priority problem now but not sure, but still strange that the getDatabasePlatform call has effects on this.

Answer 6 · 2023-02-27T15:57:41.000Z

thanks for the reproducer. i installed it as you described:

git clone git@github.com:alexander-schranz/reproducer-jackalope-error-1-9-0.git
cd reproducer-jackalope-error-1-9-0
composer install

docker compose up -d

bin/console sulu:build dev

symfony serve

i can reproduce the problem. it is tricky, what i found so far is that when i comment out the oracle code, the codepath seems to be the same but the event subscriber can find the node it expects to find. which means the problem happens before we see the error.

comparing the logs, i did not find any log for the query to store the node. when i comment out the platform thing, i do see a log for the INSERT query. i will try to find why no insert is happening.

Answer 7 · 2023-02-27T16:30:39.000Z

can you help me a bit more what should happen?

i see that there is an ajax call on PageController::postAction . if i understand correctly, $this->documentManage->create on line 326 does create an object but not yet save the node. so the save would only happen during the $this->persistDocument on line 329. but during persistDocument there is event handling which assumes that the node already exists.

is there another event listener that should store the node with the phpcr session that is expected to happen before the setWorkflowStage? or should it have been stored even earlier?

the other thing i could imagine (though i don't see how) is that we would somehow end up with 2 phpcr sessions, where the node is known to one session and the listener tries to get it from the other session before the flush happened.

Answer 8 · 2023-02-27T17:19:13.000Z

The persist event should not save any nodes. The flush is doing that all events and subscribers of persist and flush can be listed here:

bin/console sulu:document:subscriber:debug persist
bin/console sulu:document:subscriber:debug flush

If I see it correctly the GeneralSubscriber is doing the "real Save" to PHPCR here: https://github.com/sulu/sulu/blob/57bf8c4dcc59361033ef6d7acc5898b850f15b5c/src/Sulu/Component/DocumentManager/Subscriber/Phpcr/GeneralSubscriber.php#L90

Before only existing in-memory nodes are changed.

Answer 9 · 2023-02-27T20:16:44.000Z

still not sure what exactly happens. the jackalope session is instantiated twice while handling the POST call (both with the working code as well as the non-working code). this feels unexpected to me, at the very least it means unnecessary database queries.

when no oracle check is done, and on the first instantiation without oracle, i see this trace in the debugger:

ObjectManager.php:172, Jackalope\ObjectManager->__construct()
Factory.php:62, ReflectionClass->newInstanceArgs()
Factory.php:62, Jackalope\Factory->get()
Session.php:131, Jackalope\Session->__construct()
Factory.php:62, ReflectionClass->newInstanceArgs()
Factory.php:62, Jackalope\Factory->get()
Repository.php:155, Jackalope\Repository->login()
App_KernelDevDebugContainer.php:1430, ContainerTqpZCZm\App_KernelDevDebugContainer->getDoctrinePhpcr_SessionService()
App_KernelDevDebugContainer.php:5170, ContainerTqpZCZm\App_KernelDevDebugContainer->getSuluDocumentManager_NodeManagerService()
App_KernelDevDebugContainer.php:2505, ContainerTqpZCZm\App_KernelDevDebugContainer->getSuluDocumentManager_DocumentManagerService()
App_KernelDevDebugContainer.php:1971, ContainerTqpZCZm\App_KernelDevDebugContainer->getSulu_Content_MapperService()
App_KernelDevDebugContainer.php:5741, ContainerTqpZCZm\App_KernelDevDebugContainer->getTwigService()
App_KernelDevDebugContainer.php:5312, ContainerTqpZCZm\App_KernelDevDebugContainer->getSuluForm_RequestListenerService()
App_KernelDevDebugContainer.php:1472, ContainerTqpZCZm\App_KernelDevDebugContainer->ContainerTqpZCZm\{closure:/home/david/tmp/reproducer-jackalope-error-1-9-0/var/cache/admin/dev/ContainerTqpZCZm/App_KernelDevDebugContainer.php:1471-1473}()
EventDispatcher.php:221, Symfony\Component\EventDispatcher\EventDispatcher->sortListeners()
EventDispatcher.php:70, Symfony\Component\EventDispatcher\EventDispatcher->getListeners()
TraceableEventDispatcher.php:257, Symfony\Component\EventDispatcher\Debug\TraceableEventDispatcher->preProcess()
TraceableEventDispatcher.php:121, Symfony\Component\EventDispatcher\Debug\TraceableEventDispatcher->dispatch()
HttpKernel.php:139, Symfony\Component\HttpKernel\HttpKernel->handleRaw()
HttpKernel.php:74, Symfony\Component\HttpKernel\HttpKernel->handle()
Kernel.php:184, Symfony\Component\HttpKernel\Kernel->handle()
index.php:68, {main}()

things fail after seeing this other trace:

ObjectManager.php:172, Jackalope\ObjectManager->__construct()
Factory.php:62, ReflectionClass->newInstanceArgs()
Factory.php:62, Jackalope\Factory->get()
Session.php:131, Jackalope\Session->__construct()
Factory.php:62, ReflectionClass->newInstanceArgs()
Factory.php:62, Jackalope\Factory->get()
Repository.php:155, Jackalope\Repository->login()
App_KernelDevDebugContainer.php:1430, ContainerTqpZCZm\App_KernelDevDebugContainer->getDoctrinePhpcr_SessionService()
App_KernelDevDebugContainer.php:5170, ContainerTqpZCZm\App_KernelDevDebugContainer->getSuluDocumentManager_NodeManagerService()
App_KernelDevDebugContainer.php:2505, ContainerTqpZCZm\App_KernelDevDebugContainer->getSuluDocumentManager_DocumentManagerService()
App_KernelDevDebugContainer.php:5498, ContainerTqpZCZm\App_KernelDevDebugContainer->getSuluSecurity_AccessControlManagerService()
getSuluSecurity_PermissionInheritanceSubscriberService.php:23, ContainerTqpZCZm\getSuluSecurity_PermissionInheritanceSubscriberService::do()
App_KernelDevDebugContainer.php:1118, ContainerTqpZCZm\App_KernelDevDebugContainer->load()
Container.php:381, Symfony\Component\DependencyInjection\Container->getService()
ServiceLocator.php:40, Symfony\Component\DependencyInjection\Argument\ServiceLocator->get()
ContainerAwareEventManager.php:191, Symfony\Bridge\Doctrine\ContainerAwareEventManager->initializeSubscribers()
ContainerAwareEventManager.php:105, Symfony\Bridge\Doctrine\ContainerAwareEventManager->hasListeners()
Connection.php:384, Doctrine\DBAL\Connection->connect()
Connection.php:446, Doctrine\DBAL\Connection->getDatabasePlatformVersion()
Connection.php:408, Doctrine\DBAL\Connection->detectDatabasePlatform()
Connection.php:316, Doctrine\DBAL\Connection->getDatabasePlatform()
RepositoryFactoryDoctrineDBAL.php:94, Jackalope\RepositoryFactoryDoctrineDBAL->getRepository()
App_KernelDevDebugContainer.php:1430, ContainerTqpZCZm\App_KernelDevDebugContainer->getDoctrinePhpcr_SessionService()
App_KernelDevDebugContainer.php:5170, ContainerTqpZCZm\App_KernelDevDebugContainer->getSuluDocumentManager_NodeManagerService()
App_KernelDevDebugContainer.php:2505, ContainerTqpZCZm\App_KernelDevDebugContainer->getSuluDocumentManager_DocumentManagerService()
App_KernelDevDebugContainer.php:1971, ContainerTqpZCZm\App_KernelDevDebugContainer->getSulu_Content_MapperService()
App_KernelDevDebugContainer.php:5741, ContainerTqpZCZm\App_KernelDevDebugContainer->getTwigService()
App_KernelDevDebugContainer.php:5312, ContainerTqpZCZm\App_KernelDevDebugContainer->getSuluForm_RequestListenerService()
App_KernelDevDebugContainer.php:1472, ContainerTqpZCZm\App_KernelDevDebugContainer->ContainerTqpZCZm\{closure:/home/david/tmp/reproducer-jackalope-error-1-9-0/var/cache/admin/dev/ContainerTqpZCZm/App_KernelDevDebugContainer.php:1471-1473}()
EventDispatcher.php:221, Symfony\Component\EventDispatcher\EventDispatcher->sortListeners()
EventDispatcher.php:70, Symfony\Component\EventDispatcher\EventDispatcher->getListeners()
TraceableEventDispatcher.php:257, Symfony\Component\EventDispatcher\Debug\TraceableEventDispatcher->preProcess()
TraceableEventDispatcher.php:121, Symfony\Component\EventDispatcher\Debug\TraceableEventDispatcher->dispatch()
HttpKernel.php:139, Symfony\Component\HttpKernel\HttpKernel->handleRaw()
HttpKernel.php:74, Symfony\Component\HttpKernel\HttpKernel->handle()
Kernel.php:184, Symfony\Component\HttpKernel\Kernel->handle()
index.php:68, {main}()

Answer 10 · 2023-02-27T20:21:49.000Z

ok, its not exactly the same. when things work, the second instantiation is creating a live session:

App_KernelDevDebugContainer.php:2527, ContainerTqpZCZm\App_KernelDevDebugContainer->getSuluDocumentManager_LiveSessionService()
App_KernelDevDebugContainer.php:5222, ContainerTqpZCZm\App_KernelDevDebugContainer->getSuluDocumentManager_SessionManagerService()
App_KernelDevDebugContainer.php:2888, ContainerTqpZCZm\App_KernelDevDebugContainer->getSuluSnippet_DefaultSnippet_ManagerService()

Answer 11 · 2023-02-27T20:42:40.000Z

i wonder if there is a bug in the symfony DI container when we have this sort of cyclic dependencies. if i understand correctly what is happening, the session is created a second time because PermissionInheritanceSubscriberService depends on the session and is created during the doctrine bridge checking for listeners when a session is about to be created (due to the session trying to dbal-connect).

Answer 12 · 2023-02-27T20:46:35.000Z

seems i am on the right track: i found a workaround: if we $defaultSessionDefinition->setLazy(true); after line https://github.com/sulu/sulu/blob/57bf8c4dcc59361033ef6d7acc5898b850f15b5c/src/Sulu/Bundle/DocumentManagerBundle/DependencyInjection/SuluDocumentManagerExtension.php#L160, the bug does not occur.

but i think this is only a workaround, not really the solution - it seems to me to be a convoluted bug in symfony DI container creating a service and while creating dependencies not realizing it now also created the service itself... i will stop for today, but will check if i can find the mistake in symfony DI logic.

i suggest to make the service lazy at least for now - i am not super familiar with the details of symfony container. i am not sure if there is a drawback in that workaround.

Answer 13 · 2023-03-01T13:37:01.000Z

Okay that is very intersting. I think we can currently set the service to lazy: true but think we should do it for both the default and the live session else I think the same can occur also for the live session.

For me it sounds like a cycling dependency error should happen here in Symfon yDI, but that would in our case not be a solution as I currently don't know how we could avoid that cycling dependency or do you had any idea about that?

Answer 14 · 2023-03-01T17:14:14.000Z

i am very surprised that we do not end up in either an infinite loop or with an error because the loop is not prevented. maybe the exact recursive cycle is somehow discovered and prevented, but the "request the session from a different stack trace" is not discovered and handled.

Answer 15 · 2023-03-03T08:50:55.000Z

@alexander-schranz i dug into the code and i think the problem is that sulu seems to be using the repository factory service and calls login on it.

this is what is in the container:

    /**
     * Gets the public 'doctrine_phpcr.session' shared service.
     *
     * @return \Sulu\Bundle\DocumentManagerBundle\Session\Session
     */
    protected function getDoctrinePhpcr_SessionService()
    {
        $a = ($this->services['doctrine.dbal.default_connection'] ?? $this->getDoctrine_Dbal_DefaultConnectionService());

        if (isset($this->services['doctrine_phpcr.session'])) {
            return $this->services['doctrine_phpcr.session'];
        }

        return $this->services['doctrine_phpcr.session'] = new \Sulu\Bundle\DocumentManagerBundle\Session\Session([($this->privates['doctrine_phpcr.jackalope.repository.factory.service.doctrinedbal'] ??= new \Jackalope\RepositoryFactoryDoctrineDBAL())->getRepository(['jackalope.doctrine_dbal_connection' => $a, 'jackalope.check_login_on_server' => false]), 'login'](new \PHPCR\SimpleCredentials('admin', 'admin'), $this->getEnv('PHPCR_WORKSPACE')));
    }

the factory instance is shared, but getRepository is called whenever the session does not yet exist.

if i rewrite that to the following, the error is gone:

    /**
     * Gets the public 'doctrine_phpcr.session' shared service.
     *
     * @return \Sulu\Bundle\DocumentManagerBundle\Session\Session
     */
    protected function getDoctrinePhpcr_SessionService()
    {
        $a = ($this->services['doctrine.dbal.default_connection'] ?? $this->getDoctrine_Dbal_DefaultConnectionService());

        if (isset($this->services['doctrine_phpcr.session'])) {
            return $this->services['doctrine_phpcr.session'];
        }

        $b = [($this->privates['doctrine_phpcr.jackalope.repository.factory.service.doctrinedbal'] ??= new \Jackalope\RepositoryFactoryDoctrineDBAL())->getRepository(['jackalope.doctrine_dbal_connection' => $a, 'jackalope.check_login_on_server' => false]), 'login'](new \PHPCR\SimpleCredentials('admin', 'admin'), $this->getEnv('PHPCR_WORKSPACE'));

        if (isset($this->services['doctrine_phpcr.session'])) {
            return $this->services['doctrine_phpcr.session'];
        }

        return $this->services['doctrine_phpcr.session'] = new \Sulu\Bundle\DocumentManagerBundle\Session\Session($b);
    }

if you have a contact into symfony core, we could ping that person here to ask if the symfony container can be improved to do something like that. we can see that $this->services['doctrine_phpcr.session'] is written twice, which seems incorrect to me.

the tricky bit is that $b should not be above the first check if we have a session service, as it would create overhead if we already have it. i guess the idea with $a is that if we already have the service, its super cheap as it must be in the container already.

Answer 16 · 2023-03-03T08:51:23.000Z

separate comment to not mix up with the symfony core discussion:

on sulu side, i wonder if it is correct that the factory is invoked like this. if there was a service definition for the phpcr session, i think that the container would already cache the result of the factory. when using the phpcr-odm bundle, the session is configured to be created with the factory. but it makes sense that you want configuration in sulu_document_manager and not split over sulu_document_manager and doctrine_phpcr. would it be complicated to have the sulu side still define the service for plain phpcr session separately?

Answer 17 · 2023-03-03T11:17:15.000Z

sulu_document_manager and not split over sulu_document_manager and doctrine_phpcr ...

The sulu_document_manager forwards the configuration directly to the doctrine_phpcr as I know here: https://github.com/sulu/sulu/blob/57bf8c4dcc59361033ef6d7acc5898b850f15b5c/src/Sulu/Bundle/DocumentManagerBundle/DependencyInjection/SuluDocumentManagerExtension.php#L69-L80

so it currently seems not if I understand the code correctly creating the sessions itself, but uses the sessions then create by the doctrine_phpcr bundle. Or I'm missing something here?

Answer 18 · 2023-03-03T16:08:15.000Z

oh, i missed that bit.

then i think the problem lies entirely in the symfony container code. it generates code that uses the factory and does not define a service for it, and does not account for the outer service being created while creating the inner service. if it would register the inner service in the container, it could do with it as with the doctrine connection service and use it from cache to notice if the decorating service is created while accessing the inner service.

Answer 19 · 2023-03-03T16:28:48.000Z

i created symfony/symfony#49591 in the symfony issue tracker. maybe its a known issue, or i can get some help to figure out where to fix it in symfony.

Answer 20 · 2023-03-04T10:50:07.000Z

i close the issue here, as we identified it as a problem with symfony container.