Problem/Motivation

When saving entities with logging enabled, we are seeing a WSOD.

Steps to reproduce

I'm still working through all of the details, but it seems that saving any node or media entity with logging enabled triggers a fatal error.

The website encountered an unexpected error. Please try again later.

Drupal\Core\Entity\EntityStorageException: SQLSTATE[23000]: Integrity constraint violation: 1048 Column 'message' cannot be null: INSERT INTO "watchdog" ("uid", "type", "message", "variables", "severity", "link", "location", "referer", "hostname", "timestamp") VALUES (:db_insert_placeholder_0, :db_insert_placeholder_1, :db_insert_placeholder_2, :db_insert_placeholder_3, :db_insert_placeholder_4, :db_insert_placeholder_5, :db_insert_placeholder_6, :db_insert_placeholder_7, :db_insert_placeholder_8, :db_insert_placeholder_9); Array ( [:db_insert_placeholder_0] => 1 [:db_insert_placeholder_1] => elogger [:db_insert_placeholder_2] => [:db_insert_placeholder_3] => a:0:{} [:db_insert_placeholder_4] => 5 [:db_insert_placeholder_5] => [:db_insert_placeholder_6] => https://www.psh-content-staging-hpdlooi-6wpxgm77wdu6y.us-3.platformsh.site/node/1371/edit?destination=%2Fadmin%2Fcontent [:db_insert_placeholder_7] => https://www.psh-content-staging-hpdlooi-6wpxgm77wdu6y.us-3.platformsh.site/node/1371/edit?destination=/admin/content [:db_insert_placeholder_8] => 98.214.67.55 [:db_insert_placeholder_9] => 1647983736 ) in Drupal\Core\Entity\Sql\SqlContentEntityStorage->save() (line 811 of core/lib/Drupal/Core/Entity/Sql/SqlContentEntityStorage.php).
Drupal\Core\Database\StatementWrapper->execute(Array, Array) (Line: 937)
Drupal\Core\Database\Connection->query('INSERT INTO {watchdog} ("uid", "type", "message", "variables", "severity", "link", "location", "referer", "hostname", "timestamp") VALUES (:db_insert_placeholder_0, :db_insert_placeholder_1, :db_insert_placeholder_2, :db_insert_placeholder_3, :db_insert_placeholder_4, :db_insert_placeholder_5, :db_insert_placeholder_6, :db_insert_placeholder_7, :db_insert_placeholder_8, :db_insert_placeholder_9)', Array, Array) (Line: 32)
Drupal\Core\Database\Driver\mysql\Insert->execute() (Line: 78)
Drupal\dblog\Logger\DbLog->log(5, NULL, Array) (Line: 103)
Drupal\dblog\Logger\DbLog->log(5, NULL, Array) (Line: 127)
Drupal\Core\Logger\LoggerChannel->log(5, NULL, Array) (Line: 108)
Drupal\elogger\Logger\EventLog->logEvent(Array) (Line: 565)
Drupal\elogger\Services\Elogger->logEvent('entity_update') (Line: 43)
_log_entity_event('entity_update', Object) (Line: 27)
elogger_entity_update(Object)
call_user_func_array('elogger_entity_update', Array) (Line: 403)
Drupal\Core\Extension\ModuleHandler->invokeAll('entity_update', Array) (Line: 251)
Drupal\Core\Entity\EntityStorageBase->invokeHook('update', Object) (Line: 897)
Drupal\Core\Entity\ContentEntityStorageBase->invokeHook('update', Object) (Line: 602)
Drupal\Core\Entity\EntityStorageBase->doPostSave(Object, 1) (Line: 782)
Drupal\Core\Entity\ContentEntityStorageBase->doPostSave(Object, 1) (Line: 527)
Drupal\Core\Entity\EntityStorageBase->save(Object) (Line: 802)
Drupal\Core\Entity\Sql\SqlContentEntityStorage->save(Object) (Line: 339)
Drupal\Core\Entity\EntityBase->save() (Line: 746)
token_node_menu_link_submit('node', Object, Array, Object)
call_user_func_array('token_node_menu_link_submit', Array) (Line: 299)
Drupal\Core\Entity\EntityForm->buildEntity(Array, Object) (Line: 155)
Drupal\Core\Entity\ContentEntityForm->buildEntity(Array, Object) (Line: 278)
Drupal\Core\Entity\EntityForm->submitForm(Array, Object) (Line: 145)
Drupal\Core\Entity\ContentEntityForm->submitForm(Array, Object)
call_user_func_array(Array, Array) (Line: 114)
Drupal\Core\Form\FormSubmitter->executeSubmitHandlers(Array, Object) (Line: 52)
Drupal\Core\Form\FormSubmitter->doSubmitForm(Array, Object) (Line: 592)
Drupal\Core\Form\FormBuilder->processForm('node_page_edit_form', Array, Object) (Line: 320)
Drupal\Core\Form\FormBuilder->buildForm(Object, Object) (Line: 73)
Drupal\Core\Controller\FormController->getContentResult(Object, Object)
call_user_func_array(Array, Array) (Line: 123)
Drupal\Core\EventSubscriber\EarlyRenderingControllerWrapperSubscriber->Drupal\Core\EventSubscriber\{closure}() (Line: 564)
Drupal\Core\Render\Renderer->executeInRenderContext(Object, Object) (Line: 124)
Drupal\Core\EventSubscriber\EarlyRenderingControllerWrapperSubscriber->wrapControllerExecutionInRenderContext(Array, Array) (Line: 97)
Drupal\Core\EventSubscriber\EarlyRenderingControllerWrapperSubscriber->Drupal\Core\EventSubscriber\{closure}() (Line: 158)
Symfony\Component\HttpKernel\HttpKernel->handleRaw(Object, 1) (Line: 80)
Symfony\Component\HttpKernel\HttpKernel->handle(Object, 1, 1) (Line: 58)
Drupal\Core\StackMiddleware\Session->handle(Object, 1, 1) (Line: 48)
Drupal\Core\StackMiddleware\KernelPreHandle->handle(Object, 1, 1) (Line: 106)
Drupal\page_cache\StackMiddleware\PageCache->pass(Object, 1, 1) (Line: 85)
Drupal\page_cache\StackMiddleware\PageCache->handle(Object, 1, 1) (Line: 48)
Drupal\Core\StackMiddleware\ReverseProxyMiddleware->handle(Object, 1, 1) (Line: 51)
Drupal\Core\StackMiddleware\NegotiationMiddleware->handle(Object, 1, 1) (Line: 23)
Stack\StackedHttpKernel->handle(Object, 1, 1) (Line: 708)
Drupal\Core\DrupalKernel->handle(Object) (Line: 19)

WSOD

Proposed resolution

Ensure we aren't logging an empty string?

Remaining tasks

Fully understand the problem and implement a fix.

User interface changes

N/A

API changes

N/A

Data model changes

N/A

Issue fork elogger-3271092

Command icon Show commands

Start within a Git clone of the project using the version control instructions.

Or, if you do not have SSH keys set up on git.drupalcode.org:

Comments

adamzimmermann created an issue. See original summary.

adamzimmermann’s picture

Priority: Normal » Major

I don't see 1.1.2 as a version option, but that is the version we are on as of earlier today, which I think is when this became an issue.

Updating this to Major based upon what I know now, but feel free to alter that if you think this is a self inflicted user error.

1.1.2 <> 1.1.1 Diff
https://git.drupalcode.org/project/elogger/-/compare/1.1.1...1.1.2?from_...

adamzimmermann’s picture

It seems that we are missing elogger.settings format configuration, which would explain this.

I know that config was recently added to the config schema from the diffs. Perhaps an update hook or change in the admin UI + config export is needed to get that into tracked configuration?

smustgrave made their first commit to this issue’s fork.

smustgrave’s picture

Status: Active » Needs review

Can you test that update hook please. I added one for D8 + D9 not sure the standard right now for covering both.

adamzimmermann’s picture

StatusFileSize
new58.72 KB

Thanks for the quick reply and the MR!

I just added a commit to your MR and confirmed that it works. I also confirmed that we only need one update hook for it to work with D9, as both were firing before I reduced it to one.

updb hook output

https://www.drupal.org/docs/drupal-apis/update-api/introduction-to-updat...

I also added the other new configuration key to the update hook based upon the changes in this commit:

Let me know if that all makes sense and aligns with what you expect.

This is working from my perspective, but I also helped author it now so I don't want to say it's RTBC since it's partially my changes.

smustgrave’s picture

So this is what I don't know. Both hooks fired on D9. But the update hook 9100 won't fire on D8. So this may only fix it on D9. Which isnt' the end of the world just noting.

  • smustgrave committed f85af00 on 1.x
    Issue #3271092: Empty Watchdog text causing error 500 with WSOD
    
smustgrave’s picture

Status: Needs review » Fixed
smustgrave’s picture

Status: Fixed » Closed (fixed)

Released with 1.1.3