Magento2: 2.1.x Whenever a Block throws an exception, the exception message is quietly logged, and then suddenly a UiComponent is attempted to be created instead, throwing an "Object DOMDocument should be created." error in result.

[korostii]

Preconditions

Magento 2.1.3, PHP 5.6, Apache

1. Create a Block that would throw an Exception while being rendered (in other words, throw an Exception from the template)
   Basically, the following code in any .phtml file being rendered on frontend would do:
   <?php throw new \Exception('your error message'); ?>

Steps to reproduce

1. Open the page containing the Block which would throw an Exception while rendering.

Expected result

1. Page gets rendered successfully (the erroneous block gets skipped).
2. The file var/log/system.log contains the error message from the Exception thrown:
   main.CRITICAL: your error message

Actual result

1. A "There has been an error processing your request" page appears.
   

The corresponding file in var/report contains an unrelated error, making it hide to understand what exactly went wrong:

` a:4:{i:0;s:37:"Object DOMDocument should be created.";i:1;s:12870:"#0 /var/www/html/magento/vendor/magento/framework/View/Element/UiComponent/Config/Reader.php(95): MagentoFrameworkViewElementUiComponentConfigDomMerger->getDom()

1 /var/www/html/magento/vendor/magento/module-ui/Model/Manager.php(261): MagentoFrameworkViewElementUiComponentConfigReader->read()

2 /var/www/html/magento/vendor/magento/module-ui/Model/Manager.php(169): MagentoUiModelManager->prepare('layered.loading...')

3 /var/www/html/magento/vendor/magento/framework/View/Element/UiComponentFactory.php(139): MagentoUiModelManager->prepareData('layered.loading...')

4 /var/www/html/magento/vendor/magento/framework/View/Layout/Generator/UiComponent.php(125): MagentoFrameworkViewElementUiComponentFactory->create('layered.loading...', NULL, Array)

5 /var/www/html/magento/vendor/magento/framework/View/Layout/Generator/UiComponent.php(93): MagentoFrameworkViewLayoutGeneratorUiComponent->generateComponent(Object(MagentoFrameworkViewLayoutDataStructure), 'layered.loading...', Array, Object(MagentoFrameworkViewLayoutInterceptor))

6 /var/www/html/magento/vendor/magento/framework/View/Layout/GeneratorPool.php(86): MagentoFrameworkViewLayoutGeneratorUiComponent->process(Object(MagentoFrameworkViewLayoutReaderContext), Object(MagentoFrameworkViewLayoutGeneratorContext))

7 /var/www/html/magento/vendor/magento/framework/View/Layout.php(327): MagentoFrameworkViewLayoutGeneratorPool->process(Object(MagentoFrameworkViewLayoutReaderContext), Object(MagentoFrameworkViewLayoutGeneratorContext))

8 /var/www/html/magento/vendor/magento/framework/View/Layout/Builder.php(129): MagentoFrameworkViewLayout->generateElements()

9 /var/www/html/magento/vendor/magento/framework/View/Page/Builder.php(55): MagentoFrameworkViewLayoutBuilder->generateLayoutBlocks()

10 /var/www/html/magento/vendor/magento/framework/View/Layout/Builder.php(65): MagentoFrameworkViewPageBuilder->generateLayoutBlocks()

11 /var/www/html/magento/vendor/magento/framework/View/Page/Config.php(187): MagentoFrameworkViewLayoutBuilder->build()

12 /var/www/html/magento/vendor/magento/framework/View/Page/Config.php(197): MagentoFrameworkViewPageConfig->build()

13 /var/www/html/magento/vendor/magento/framework/App/View.php(170): MagentoFrameworkViewPageConfig->publicBuild()

14 /var/www/html/magento/vendor/magento/framework/App/View.php(114): MagentoFrameworkAppView->loadLayoutUpdates()

15 /var/www/html/magento/vendor/magento/module-catalog-search/Controller/Result/Index.php(90): MagentoFrameworkAppView->loadLayout()

16 /var/www/html/magento/vendor/magento/framework/App/Action/Action.php(102): MagentoCatalogSearchControllerResultIndex->execute()...`

This is not just a theoretical thing, such a situation may happen for a number of reasons, including but not limited to buggy customized code, incompatible or badly tested 3rd party extensions.
It might even be triggered by an unforeseen combination of actions by the merchant on an out-of-the-box Magento instance, as shown in #5323

This behaviour is not just strange and unexpected, it's harmful:
While "your error message" might still be contained in the system.log, you have face a bigger error in front of you with and have no reason to look into system.log.
Thus, the actual issue gets obscured by the more obviously shown and unrelated one, making the debugging process frustrating and time-consuming.
As a developer, I personally can get through this, but to a newbie merchant having installed a broken or incompatible module or theme such a situation may present a real challenge.

What actually happens here

The Exception being thrown by the Block gets catched here
The unset() prvents the block from further processing by GeneratorBlock, yes.
However, the block remains inside the $scheduledStructure. An additional $scheduledStructure->unsetElement() call might be appropriate here.
Further on, the scheduledStructure gets passed on to the GeneratorUiComponent which happens to ignore element type completely.
Compare that to the Block generator which explicitly checks the element type to be compatible
If an identical additional check was performed in the UiComponent generator as well it would fix the issue reported here, as well.

[orlangur]

Oh, this one was tough :) Thanks for your analysis @korostii, I've read a lot of links mentioning "Object DOMDocument should be created" from Google but none of them pointed to a right direction.

[korostii]

Glad it helped you =)

This error seemed to appear randomly and it was driving me crazy for quite some time. Eventually I just had to dive into the source code head first in order to prevent my self from derailing completely.
At least now I know where to look when I see this confusing error message.

BTW I've seen a few issues out here fixed that were reporting the very same error (e.g. #5323). The thing that puzzles me is why core developers prefer to fix the underlying issue only and don't seem to care about Magento2's issues with logging and error reporting whatsoever. Fixing bugs like this one could make the debugging so much easier.

[magento-engcom-team]

@korostii, thank you for your report.
The issue is already fixed in develop branch, 2.1.9

[korostii]

The issue is already fixed in develop branch, 2.1.9

Hi @magento-engcom-team
No, it's not in 2.1 yet as far as I can see. The code is still the same: https://github.com/magento/magento2/blob/2.1/lib/internal/Magento/Framework/View/Layout/Generator/UiComponent.php#L92

Compare that to 2.2.0: https://github.com/magento/magento2/blob/2.2.0-preview/lib/internal/Magento/Framework/View/Layout/Generator/UiComponent.php#L91-L95

Please either double-check your information o provide a link to the commit fixing the issue on 2.1.x branch.

Thank you in advance.

[orlangur]

@korostii thanks for checking, Reproduced on 2.2.x - is it correct label? Should be not so hard to identify commit for backport if really fixed on develop only and still reproducible on 2.1.x.

[korostii]

Reproduced on 2.2.x - is it correct label?

Seems not.

Should be not so hard to identify commit for backport

Yep, simple blame does it, but the commit is rather monstrous: 5affd8aa4c44f2f137bb171887af000b9ef27d09
Personally, I' don't see how a commit like that could pass code review without some extra explanation.
I would guess backporting it "as is" won't be accepted. Good thing we know where to look (in this case).

The savage tactic of squashing everything into giant merge commits really messes up repo history =[

[orlangur]

@korostii squashed commits are perfectly fine until they contain related changes. It looks like here the issue you reported was fixed accidentally. If you see an exact part which fixed the problem (like mentioned lines), it would be best to prepare a backport PR.

[korostii]

Did you maybe mean _unrelated_?

Seriously though, IMHO "498 changed files with 50,061 additions and 1,401 deletions." is a little bit overboard.
I don't think such a PR from a community would pass into code base and I doubt this commit has had any kind of code review done on it.
Is there a way to find the separate commits which went into this squash? probably not.
There should be a sane limit to doing this.

Since the changes done don't seem to be having any kind of up-to-date publicly available online documentation (and I specifically mean everything _except_ security and bug fixes), commits become the primary and only source of knowledge about that.
IMHO Messing up repository history like that should be considered vandalism.

I'd rather see a subtree split into separate repositories for each of the magento's own composer-loaded modules. Now _that_ just might help manage stuff. By the way, here's some good related read on how Linux kernel development is managed.

[orlangur]

Did you maybe mean unrelated?

Nope, "related". This one seems to be some huge refactoring.

I don't think such a PR from a community would pass into code base

As far as I can see here most of added lines are just some XML config. Maybe they even were generated somehow.

I doubt this commit has had any kind of code review done on it

It is simply not possible according to development processes. Squash commits are just fine when you do pretty straightforward changes, like this commit, and you have a lot of conflict resolutions with mainline later. I don't know exact reason behind squash decision in this case and I don't think it's worth to waste on finding this out.

If there would be a separate effort to fix bug, I agree that it should be done as separate commit. Here, most likely, the bug was eliminated accidentally by the refactoring.

Now that just might help manage stuff.

I don't think so, at least until Magento 2 will be modular enough but even if that case splitting may introduce too much overhead. There are many open-source projects providing read-only subtree splits but accepting issues only for the main monolithic repo.

[korostii]

As far as I can see here most of added lines are just some XML config. Maybe they even were generated somehow.

Yes, and I've seen you personally split an automatically generated part of your pull request into a separate commit for the sake of readability. Such approach would seem helpful in this case as well.

But hey, what's done is done. Let's hope it improves in the future.

There are many open-source projects providing read-only subtree splits but accepting issues only for the main monolithic repo.

Whatever works. I was just trying to point out that "too many commits in a repo" is much, much less of an issue than "too many changes in a single commit".

[orlangur]

@korostii, let me show you another example: https://github.com/magento/magento2/search?p=1&q=MAGETWO-56062&type=Commits&utf8=✓

It would be sooo much easier to backport if it was squashed before merging :) Even if changes are turned out to be huge.

[korostii]

This example is a bit borderline, don't you think? xD
Anyway, you're right that squashing has it's use-cases. But I'd still say it should be kept to minimum.

Also, your example proves the point that the backporting should be done by the same person right after merging it into develop.
I mean, heshe would have direct access to the source branch, have intimate knowledge of the changes done and be able to resolve any possible conflicts in no time.
AND it'd be the same person's responsibility to keep the branch history sane since it would be hisher job to cherry-pick all the commits one-by-one to a 2.1-specific branch otherwise.