Problem/Motivation

I get an EntityStorageException when trying to install D8 on PG. All works well until you finish the "Configure Site" step and click finish. The following exception shows up and seems like a user storage issue.

Notice: A non well formed numeric value encountered in Drupal\Core\Entity\ContentEntityDatabaseStorage->save() (line 468 of core/lib/Drupal/Core/Entity/ContentEntityDatabaseStorage.php).
Drupal\Core\Entity\ContentEntityDatabaseStorage->save(Object)
Drupal\user\UserStorage->save(Object)
Drupal\Core\Entity\Entity->save()
Drupal\Core\Installer\Form\SiteConfigureForm->submitForm(Array, Array)
call_user_func_array(Array, Array)
Drupal\Core\Form\FormBuilder->executeHandlers('submit', Array, Array)
Drupal\Core\Form\FormBuilder->processForm('install_configure_form', Array, Array)
Drupal\Core\Form\FormBuilder->buildForm('Drupal\Core\Installer\Form\SiteConfigureForm', Array)
install_get_form('Drupal\Core\Installer\Form\SiteConfigureForm', Array)
install_run_task(Array, Array)
install_run_tasks(Array)
install_drupal()
Drupal\Core\Entity\EntityStorageException: SQLSTATE[25P02]: In failed sql transaction: 7 ERROR: current transaction is aborted, commands ignored until end of transaction block in Drupal\Core\Entity\ContentEntityDatabaseStorage->save() (line 468 of core/lib/Drupal/Core/Entity/ContentEntityDatabaseStorage.php).
Drupal\Core\Entity\ContentEntityDatabaseStorage->save(Object)
Drupal\user\UserStorage->save(Object)
Drupal\Core\Entity\Entity->save()
Drupal\Core\Installer\Form\SiteConfigureForm->submitForm(Array, Array)
call_user_func_array(Array, Array)
Drupal\Core\Form\FormBuilder->executeHandlers('submit', Array, Array)
Drupal\Core\Form\FormBuilder->processForm('install_configure_form', Array, Array)
Drupal\Core\Form\FormBuilder->buildForm('Drupal\Core\Installer\Form\SiteConfigureForm', Array)
install_get_form('Drupal\Core\Installer\Form\SiteConfigureForm', Array)
install_run_task(Array, Array)
install_run_tasks(Array)
install_drupal()

Going to the homepage the site shows up, but you can't login because of unknown user. Looking in the database the admin user is not created. All I can find is a temporary user (uid 1) named "placeholder-for-hid-1" and an entry (uid 0) with no user name at all. If one can point me in the right direction where to start I will do some digging.
I didn' follow the commit log over the last days but all was working fine until some days ago!

Comments

tetranz’s picture

tetranz commented

I can confirm the same problem. I started to do some simple debugging with echo statements and hitting refresh.

I haven't quite got to the bottom of it but the exception is thrown in toolbar_user_update in /core/modules/toolbar/toolbar.module

It gets past it if I comment out the _toolbar_clear_user_cache($user->id()) and hit refresh.

Drupal is then installed complete with admin user and is usable although it first comes up with a similar error for menu. All seems well after that.

Notice: A non well formed numeric value encountered in Drupal\menu_link\MenuLinkStorage->save() (line 107 of core/modules/menu_link/lib/Drupal/menu_link/MenuLinkStorage.php).

Drupal\menu_link\MenuLinkStorage->save(Object)
_menu_link_save_recursive(Object, 'system.admin', Array, Array)
menu_link_rebuild_defaults()
Drupal\Core\EventSubscriber\RouterRebuildSubscriber->menuLinksRebuild()
Drupal\Core\EventSubscriber\RouterRebuildSubscriber->onRouterRebuild(Object, 'routing.route_finished', Object)
call_user_func(Array, Object, 'routing.route_finished', Object)
Symfony\Component\EventDispatcher\EventDispatcher->doDispatch(Array, 'routing.route_finished', Object)
Symfony\Component\EventDispatcher\EventDispatcher->dispatch('routing.route_finished', Object)
Symfony\Component\EventDispatcher\ContainerAwareEventDispatcher->dispatch('routing.route_finished', Object)
Drupal\Core\Routing\RouteBuilder->rebuild()
install_finished(Array)
install_run_task(Array, Array)
install_run_tasks(Array)
install_drupal()

I don't know if it is significant but I wonder if it is correct for this to be calling hook_user_update rather than hook_user_insert.

If this is not solved tomorrow night, I might dig a little further.

bzrudi71’s picture

bzrudi71 commented

Thanks for looking a bit further on this. I have no time until next week, but still wondering why this could be caused by toolbar at all!? I mean toolbar isn't visible at all during install but is used to create admin user during install? This seems more than strange to me...
Maybe one of these commits could be the problem?
#2162837: Split up contextual.toolbar.js
#2236879: Broken condition in ContentEntityDatabaseStorage

Even so I see no problems with them while reading through.

tetranz’s picture

tetranz commented

Yes, it does seem strange for the toolbar to be involved.

It happens because hook_user_update is invoked whenever a user entity is saved, including the first user during installation. Toolbar uses that hook to clear a cache. In general, it probably does make sense to clear various caches when a user is saved but probably not for the first one. I'll try to dig a little further tonight.

tetranz’s picture

tetranz commented

Well ... I improved my understanding of this a little. I followed the toolbar_user_update and it eventually fails with a SQL error when the cache tests whether or not a database table exists. But .. that is not the real error. That exercise was a bit of a waste of time.

The part of the exception that says "SQLSTATE[25P02]: In failed sql transaction" means that it is already in a failed transaction before it gets to that point. That suggests something is failing earlier which is not caught. I have had no luck at finding where that happens. I think it could happen during the main install process before it redirects to display the final form.

I'll keep on it. I haven't used PostgreSQL with Drupal before but I have it installed I thought this would be a good learning exercise.

bzrudi71’s picture

bzrudi71 commented

While in transaction the actual queries are not send to PG, so you will see nothing in PostgreSQL error logs. Please remove the transaction start statements in Drupal\Core\Entity\ContentEntityDatabaseStorage->save() to see what actually breaks and set PG to verbose logging. That should help :-) I still have no time, sorry...

bzrudi71’s picture

bzrudi71 commented
Related issues: +#2181291: Prevent a query from aborting the entire transaction in pgsql
bzrudi71’s picture

bzrudi71 commented

Just found the time for another install and found this in the PG logs:

ERROR:  relation "cache_toolbar" does not exist at character 13
STATEMENT:  DELETE FROM cache_toolbar 
	WHERE  (expire <> '-1') AND (expire < '1399027746') 
ERROR:  current transaction is aborted, commands ignored until end of transaction block

Arg! So the problem is the toolbar module causing the transaction to break. As a quick test I disabled toolbar from the default install profile and installation went fine with no errors. I remember an "ensureBinExists()" method from another PG related cache bin issue to make sure the bins exist during install, maybe we need the method to take care of cache_toolbar too?
Anyway, now for sure no more time until Tuesday...

mradcliffe’s picture

mradcliffe
he/him
Primary language English
commented

Yes, cache_toolbar had issues before as well. The cache table creation should be firing on delete and deleteAll operations iirc as a part of #2181289: Prevent exceptions on missing cache table during cache clear for pgsql. I am not sure why it's not happening here.

bzrudi71’s picture

bzrudi71 commented
Title: PostgreSQL install broken again in HEAD » PostgreSQL install broken again in HEAD by toolbar module
bzrudi71’s picture

bzrudi71 commented
Related issues: +#2256877: Remove the API function to check if a cache bin is empty

Okay, did some more debugging and found the issue. The problem is the wrong isEmpty() cache check for toolbar. There is a related issue which will fix PG installation:
#2256877: Remove the API function to check if a cache bin is empty
So we just have to wait for (#2256877) to get in ;-) Going to add a note to (#2256877) that this will help with this issue.

bzrudi71’s picture

bzrudi71 commented

Since #2256877: Remove the API function to check if a cache bin is empty is in PG install works again for me. If anyone can confirm please we can close this issue :-) Yay!

tetranz’s picture

tetranz commented

Works well for me.

Great stuff!

bzrudi71’s picture

bzrudi71 commented
Component: entity system » toolbar.module
Status: Active » Fixed

Great!
@tetranz thanks for tracing this down to toolbar module and thanks for the review!

Status: Fixed » Closed (fixed)

Automatically closed - issue fixed for 2 weeks with no activity.