Add note to log when site put into and taken out of Offline mode

Hi
I just crossed the perfect example on why this issue should be taken much seriously: a admin user saw the "outdated message", so thinking doing the right thing he follows the link and follow the update process putting the site in maintenance mode... The update failed but he didn't notice was still in maintenance mode because he was already logged in.
He do it twice over several months...
It take a while to debug it since there is no drupal log, and webserver log didn't show any visit to maintenance page.

Ok, the fault is mainly on the dev team side (update module enable on production site and bad permissions) but still I think this issue shoul get a higher priority (or the first patch should be accepted)

See also: https://github.com/drush-ops/drush/issues/5365

FWIW the last patch still applies cleanly against 9.5.x.

Thanks, I just add it to my `composer.json`.

So the patch number 17 could be marked as RTBTC

The patch still applies cleanly. I don't see any outstanding requests for changes. Switching this to 'needs review.'

The issue summary is pretty bare.

Also could use some kind of test coverage. Even simply coverage.

I am running core version 9.5.11 I tested the patch from #21. I was not able to get anything in logs when setting the maintenance mode through the UI. I tried clearing caches with Drush a few times but it didn't have any effect.

Patch from #17 also applies cleanly and now I got log messages when it was set. But I think the solution in #21 would be better if it worked because we also set maintenance mode with Drush and would be good to catch those also.

As maintenance mode is stored in state, it is good to log message in Drupal\Core\State::set() method. So, moving the fix given in #21 to State.php. This way, there will be a log for both cases - drush and form save. Verified the attached patch with Drupal 10.1.4

@sumit_saini Thanks for the patch - tests are still needed, so moving back to Needs Work.

Aditi Saraf → made their first commit to this issue’s fork.

The last patch is still missing the test(s).

And it would be great to update to update the issue summary (see #42). We should also include the summary of possible solutions (State::set() vs CacheCollector:set() vs SiteMaintenanceModeForm ..), as there are multiple patches with different approaches, so better to have this summarized. Thanks!

Rerolled.

For the issue summary update and tests.

We encountered an error when using this patch in core with Redirect 404 submodule of Redirect.

After upgrading to Drupal 10.2, I get the following error when trying to disable the maintenance mode in en/admin/config/development/maintenance:

The website encountered an unexpected error. Try again later.

TypeError: Drupal\system\Form\SiteMaintenanceModeForm::__construct(): Argument #1 ($logger_factory) must be of type Drupal\Core\Logger\LoggerChannelFactory, Drupal\redirect_404\Render\Redirect404LogSuppressor given, called in /var/www/html/web/core/modules/system/src/Form/SiteMaintenanceModeForm.php on line 74 in Drupal\system\Form\SiteMaintenanceModeForm->__construct() (line 58 of core/modules/system/src/Form/SiteMaintenanceModeForm.php).

Drupal\system\Form\SiteMaintenanceModeForm::create(Object) (Line: 28)
Drupal\Core\DependencyInjection\ClassResolver->getInstanceFromDefinition('\Drupal\system\Form\SiteMaintenanceModeForm') (Line: 48)
Drupal\Core\Controller\HtmlFormController->getFormObject(Object, '\Drupal\system\Form\SiteMaintenanceModeForm') (Line: 58)
Drupal\Core\Controller\FormController->getContentResult(Object, Object)
call_user_func_array(Array, Array) (Line: 123)
Drupal\Core\EventSubscriber\EarlyRenderingControllerWrapperSubscriber->Drupal\Core\EventSubscriber\{closure}() (Line: 627)
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: 181)
Symfony\Component\HttpKernel\HttpKernel->handleRaw(Object, 1) (Line: 76)
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: 28)
Drupal\Core\StackMiddleware\ContentLength->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: 36)
Drupal\Core\StackMiddleware\AjaxPageState->handle(Object, 1, 1) (Line: 51)
Drupal\Core\StackMiddleware\StackedHttpKernel->handle(Object, 1, 1) (Line: 704)
Drupal\Core\DrupalKernel->handle(Object) (Line: 19)

I’m not convinced by the solution proposed in #21. While it’s nice that the message is logged when the site is put into maintenance mode using Drush, I don’t believe the State class should be responsible for that. Perhaps we could handle it in Drupal\Core\EventSubscriber\MaintenanceModeSubscriber by introducing a second state variable to store the last logged action, which would help prevent log flooding.

In the meantime, I’ve refined the SiteMaintenanceModeForm solution slightly and added a kernel test.

Do you think we should invest effort into covering the Drush case?

Left some small comments on the MR.

Thanks for the review @smustgrave :)

All threads resolved!

I think we should consider an architecture that allows us to log state keys set during a request / cli operation. We could add an property to store the keys that are set during the request to \Drupal\Core\State\State and then add a public method to get this information. Then add a service then subscribes to the terminate even and gets this value and logs any state changes for a list of keys defined in a container parameter. This container parameter should contain the value system.maintenance_mode be default.

This way we'll get consistent logging across Drush / admin UI and any other way of doing this and we'll have a generic system to solve this if we want logging for any other state changes.

We could add an property to store the keys that are set during the request to \Drupal\Core\State\State and then add a public method to get this information. Then add a service then subscribes to the terminate even and gets this value and logs any state changes for a list of keys defined in a container parameter.

In the case of state, and then perhaps generally, would there be a need to track the previous stored value for the key so it can be compared with the new value?

Umm, this is getting interesting. Some thoughts:

1. If system.maintenance_mode is set multiple times within the same request or CLI operation, the last change could be from 1 to 1, which wouldn’t be useful. However, that’s very unlikely to happen, though.
2. If you believe that the final value is what matters most, then storing the previous value isn’t relevant.
3. On the other hand, if you consider the previous value important, I start to worry about an edge case like the one mentioned in point 1.

I think we could just log the current value. However I also think there is a way around #60.1 If we want to also report the initial value then we could easily do something like

if (!isset($this->keySetDuringRequest[$key])) {
  $this->keySetDuringRequest[$key] = $value;
}

And then the method to get the keys set during the request could return the initial value too. I think we should only consider doing that if getting the initial value does not cost anything. I think it is okay to ignore multiple changes to a value during a request and only care about the initial and value value for the purposes of logging.

Sounds good. I'll work into this :)

I think one (small, probably) concern with not getting the initial stored value in the case of maintenance mode is that if the site was already put into maintenance in a prior request or CLI op, then the log will show successive messages indicating maintenance mode was enabled. This might be confusing to someone expecting to see a message about maintenance mode being disabled somewhere in between.

Maybe the log message for maintenance mode can be worded to acknowledge that maintenance mode state was set but not necessarily changed?

I'm not feeling as confident with naming as I usually do while writing this code… maybe it's just late, and I'm not thinking clearly. 🙂

• I'm unsure about the StateKeysSetLoggerSubscriber subscriber name.
• I'm also not completely sure about the service name state.keys_set_logger.
• I feel uneasy about not being able to provide a more specific log message when maintenance mode is set, rather than just logging "The state key system.maintenance_mode has been changed from 0 to 1."

Nonetheless, I believe this approach addresses #60 and the concerns discussed earlier.

Any feedback would be greatly appreciated!

I have no opinion on the class name, but made some comments on the MR.

Also:

I feel uneasy about not being able to provide a more specific log message when maintenance mode is set, rather than just logging "The state key system.maintenance_mode has been changed from 0 to 1."

Detecting what the value has changed from isn't possible without get() call, which I presumed was to be avoided. Though I'm also not sure about the performance impact.

I have another idea, although it's not exactly in linew with @alexpott suggested:

What if we fire a dedicated event for state changes, such as StateKeySetEvent, to which a MaintenanceModeEventSubscriber could listen and log a more specific message?

We could dispatch the event before the key is updated, allowing subscribers to retrieve the original value directly from the state instead of passing it within the event, only in case they need it. This would introduce a performance impact, but only for subscribers that actually need to access the original value. Given that there would only be a few subscribers, the impact wouldn’t be as significant as retrieving the original value for every key set in a request.

What do you think?

@vidorado I'm hesitant to have an event being triggered because this is during termination and only limited things will work as expected - for example you can't use the messenger service and expect something to make it to the page. That said this can be documented so maybe that is okay.

Oh... writing this makes me realise we can completely remove the generic logger and just have a logger for the maintenance mode. And we can change public function getKeysSetDuringRequest(): array; to public function getValueSetDuringRequest(string $key): ?array; and that can return the new and original value in an array or NULL if the key was not changed.

Thanks @alexpott,

I hadn't realized that firing another event during the termination event could be problematic. Thanks for pointing it out.

However, the termination event we were subscribing to was intended to collect all the state keys set during the request, since at that stage, it's very unlikely that any more keys would be set. In contrast, the StateKeySetEvent I suggested would be fired each time a state key is set, rather than at termination.

With this approach, a MaintenanceModeEventSubscriber could listen for system.maintenance_mode being set to 1 and log a message if the original value was 0. This might generate a log entry each time maintenance mode is set during a request, but it's highly unlikely that it would be set more than once.

Would this event subscriber align with the "maintenance mode logger" you suggested? Were you referring to a polling strategy rather than a publisher-subscriber approach?

@vidorado I don't think we should fire an event every time a state key is set. I think the solution suggested in #67 is the way to go. The maintenance mode subscriber can subscribe to the terminate event and do everything it needs. See new MR - https://git.drupalcode.org/project/drupal/-/merge_requests/11220

With the new MR you can see the logging in action with Drush if you are in verbose mode...

vendor/bin/drush -v sset system.maintenance_mode 1
 [info] Drush bootstrap phase: bootstrapDrupalRoot()
 [info] Change working directory to /Volumes/dev/sites/drupal8alt.dev
 [info] Initialized Drupal 11.2-dev root directory at /Volumes/dev/sites/drupal8alt.dev
 [info] Drush bootstrap phase: bootstrapDrupalSite()
 [info] Initialized Drupal site default at sites/default
 [info] Drush bootstrap phase: bootstrapDrupalConfiguration()
 [info] Drush bootstrap phase: bootstrapDrupalDatabase()
 [info] Successfully connected to the Drupal database.
 [info] Drush bootstrap phase: bootstrapDrupalFull()
 [info] Starting bootstrap to none
 [info] Drush bootstrap phase 0
 [info] Try to validate bootstrap phase 0
 [info] Maintenance mode enabled.

vendor/bin/drush -v sset system.maintenance_mode 0
 [info] Drush bootstrap phase: bootstrapDrupalRoot()
 [info] Change working directory to /Volumes/dev/sites/drupal8alt.dev
 [info] Initialized Drupal 11.2-dev root directory at /Volumes/dev/sites/drupal8alt.dev
 [info] Drush bootstrap phase: bootstrapDrupalSite()
 [info] Initialized Drupal site default at sites/default
 [info] Drush bootstrap phase: bootstrapDrupalConfiguration()
 [info] Drush bootstrap phase: bootstrapDrupalDatabase()
 [info] Successfully connected to the Drupal database.
 [info] Drush bootstrap phase: bootstrapDrupalFull()
 [info] Starting bootstrap to none
 [info] Drush bootstrap phase 0
 [info] Try to validate bootstrap phase 0
 [info] Maintenance mode disabled.

That's elegant! 🙂 Thanks for helping out!

Sorry, I wasn’t getting it at first when I read #67, but after view it in code, I got it! :)

I've also learned from it that a complete class constructor parameter promotion can be in the scope of an issue that modifies the class (which I think is cool), and also learned how to do a proper "autowire service promotion".

Overall, I think the code has turned out to be a very lean and clean change.

It works fine, either with Drush or the UI.

Only a question remains:

Should we be concerned about the performance impact of $this->registerKeySetDuringRequest($key, $value, parent::get($key)); being executed for each key set in State? (for the parent::get($key), which will have a cost).

A couple small typos and a question. One test failure as well, presumably unrelated.

godotislate → changed the visibility of the branch 229778-add-note-to to hidden.

godotislate → changed the visibility of the branch 11.x to hidden.

Should we be concerned about the performance impact of $this->registerKeySetDuringRequest($key, $value, parent::get($key)); being executed for each key set in State? (for the parent::get($key), which will have a cost).

I'm not concern because State is a cache collector and it has to get all the values before a set... - see the call to $this->lazyLoadCache(); in both get and set in the parent cache collector class.

One other note is that there is no explicit test with a pre-existing original value. It is tested implicitly in SiteMaintentanceTest, so maybe it's fine?

I added a test case for this.

This looks good now. There is one failing test, but I think it is unrelated and just needs re-running.

I'm not concern because State is a cache collector and it has to get all the values before a set... - see the call to $this->lazyLoadCache(); in both get and set in the parent cache collector class.

I see. State data is cached in-memory in the CacheCollector::$storage variable, so is cheap to retrieve the value with a get() :)

Since all threads and suggestions are resolved, the test are passing (I've launched another pipeline and it passed, the failing tests were the common ones that randomly fail and you must re-run), I believe we can switch to RTBC.

Thanks to all for your work! I've learned a lot from this ^^

We need a change record to detail the addition of StateInterface::getValuesSetDuringRequest() - https://www.drupal.org/node/add/changenotice?field_project=3060&field_is... →

Added CR: https://www.drupal.org/node/3519307 →

I added a couple minor comments on the MR after looking again while writing the CR.

Since the changes look good to me and the tests pass, I believe it's safe to switch back to RTBC.

Thanks @godotislate!

NW per https://git.drupalcode.org/project/drupal/-/merge_requests/11220#note_49.... We should accept that suggestion, then IMHO we should be good to go.

OK, I'll stop messing around. It's already fixed, just we can't resolve threads.

No worries @penyaskito 😁 you're not the only one who has been misleaded by unresolved threads. I don't really know what it depends on. Sometimes I see the "Resolve thread" button at GitLab, but sometimes not.

Everything looks in order here. I also updated credit.

I also tested the MR and it works as expected, it just needs a cache clear.

I did a first pass at reviewing this. I had mostly small formatting feedback, plus a couple coding standards questions I need to look up. Next I'm going to fire up some manual testing!

Effusive aside: Friends, this issue is from March of 2008! Back then, I hadn't even submitted my first security hardening (which would trigger a sequence of events that led to me eventually becoming a core release manager), nor ever logged into IRC. I had never logged into IRC, never attended a single Drupal user group meeting nor Drupal Camp. Very excited to finally fix this.

Anyway. Starting manual testing now.

Manually tested with the following steps:

1. Applied locally to 11.x and installed Standard.
2. Created a test user with the administrator role.
3. Navigated to /admin/config/development/maintenance and toggled the site into maintenance mode.
4. Navigated to http://127.0.0.1:8888/admin/reports/dblog and verified that it showed a message for admin putting the site into maintenance mode.
5. Visited the site in incognito and verified the maintenance status.
6. In another browser, logged in as my test user, and verified that user also saw the message.
7. As the test user, disabled maintenance mode.
8. Went back to the recent log messages and verified that both accounts saw the log message for maintenance mode being disabled, this time by the test user.

Beautiful! This does make me think, though: Should our functional test include assertions about who is listed as triggering the maintenance mode change? Back in the day this would involve some complicated CSS assertions, but I think we might have API already for asserting dblog messages in our test suite.

Not NWing yet, because I still need to:

1. Check out those coding standards things.
2. Review the issue comments to date.
3. Review the CR.
4. Double-check the constructor and autowiring things.

Oh, regarding:

No worries @penyaskito 😁 you're not the only one who has been misleaded by unresolved threads. I don't really know what it depends on. Sometimes I see the "Resolve thread" button at GitLab, but sometimes not.

You will see the button if you are the author of the merge request or a core committer. Most people are only ever one of those things. 😀

OK, finally done with my review.

Overall, this looks great. The new functionality for state is elegant, as is the implementation of the message setting and unsetting. It's excellent that it works both in the browser and on the CLI. The CR is good. I've also reviewed all the issue comments to verify that nothing is outstanding.

Most of my points and suggestions on the merge request are code style and documentation improvements. There are two point for additional test coverage (the status code and the user asserted; compare with my manual testing in #89). There is also sadly one point for a code style and documentation quality reduction WRT the array PHPDoc hinting. Tagging "Needs followup" to file (a) an issue in the coding standards issue queue for this, which would lead to getting api.d.o fixed once we adopt the standard etc. and (b) a followup postponed on that to re-add the nice phpdoc hint here.

Thanks everyone!

There is also sadly one point for a code style and documentation quality reduction WRT the array PHPDoc hinting.

Coding standards were updated to allow all documented PHPStan PHPdoc types per https://www.drupal.org/node/3505429 → .

Is fixing api.d.o to work with these types correctly a blocker?

@godotislate, thanks. There is no mention in that issue or the updated docs of the more complex array data typehinting, aside from (apparently) one comment from @donquixote saying that a certain example of it is "too much".

In the past, we definitely have blocked adopting a standard in core on api.d.o, Coder, and all related tooling supporting it.

I'll reach out to the committers who are on the coding standards committee for more feedback.

@xjm The problem/motivation in ✨ Adopt phpstan phpdoc types as canonical reference of allowed types Active has "I propose that anything included in https://phpstan.org/writing-php-code/phpdoc-types should be allowed", but I agree that the updates made to the CS docs are not as definitive.

I bring it up because the use of array shapes and similar has been begun to be adopted in pending MRs across quite a few core issues, so if tools needing to be in place is a blocker, there might need to be more general awareness of that.

OK, quick update. I discussed this with the release managers and so far we didn't really reach a conclusive decision about what's a hard blocker vs. soft blocker here in terms of adopting the array and object shapes.

However, this morning we also spoke with the DA, and we determined that api.d.o formatting is not a blocker. Upon further research:

1. The scope of usage in core is wider than I previously thought. I was only looking at @return, but there are also a few places the array shapes are used for @param in newer or recently improved code (particularly Recipes, the mysqli driver and related DB-layer improvements, something about SVGs, and the new Hook API).
2. @param types are formatted correctly, unlike return types. (Example: Block attribute.)
3. @var types are not the prettiest, but at least they are parsed correctly. (Example: UnpackOptions::$options.)
4. What's more, the issue with return type formatting isn't caused by this issue, only made worse by it. E.g. see BlockAttribute::__construct(). The return type doesn't have any special formatting there either. It's just that the lack of formatting is less confusing when it's one word.
5. Most of the types are still legible, simply displaying the data typing without formatting. I've only found one scenario where the parsing is actually broken: HookCollectorPass::$groupIncludes, which is a @var array<string, list<string>>.

So, based on all that, I've agreed with the DA to file an issue in api.d.o for the return type formatting (and a couple other type formatting bugs I found in the process of researching this). Since most of it already works and this issue is not using the nested angle bracket shape that seems to break parsing, we won't block this issue's doc formatting on fixing API.d.o.

We should still also address the documentation deficiency, and possibly adopt some standards about formatting and just how far we go in human- vs machine-readable here, but again, the use is wider than I thought in core and so we can descope that from being blocking. Just need to get the various followup tasks filed or commented on in the appropriate places.

NW for various other things that were still outstanding from my review, I believe. Thanks!

Finally finished writing up the issue for the API module.

I think open MR comments have been addressed.

xjm → credited catch → .

xjm → credited longwave → .

Forgot to credit the Slack discussion with the release managers.