Magento2: Plugin execution order wrong, or documentation that describes the order is wrong

[gwharton]

Preconditions (*)

1. Magento 2.3.3+

Steps to reproduce (*)

1. Create a test plugin A with before and after methods and configure to intercept another class with sortOrder="10"
2. Create a second test plugin B with before and after methods and configure to intercept the same class with sortOrder="20"
3. Run the class that is intercepted and inspect the order of execution of plugins.

Expected result (*)

1. According to https://devdocs.magento.com/guides/v2.3/extension-dev-guide/plugins.html The order should be

PluginA-before method
PluginB-before method
Base Class
PluginB-after method
PluginA-after method

Actual result (*)

1. Order is actually

PluginA-before method
PluginB-before method
Base Class
PluginA-after method
PluginB-after method

Attached is proof of concept module. Run with php bin/magento Gw:consoletest and then inspect var/log/system.log for output

    <type name="Gw\ConsoleTest\Model\TestClass">
        <plugin name="TestPluginA" type="Gw\ConsoleTest\Model\TestPluginA" sortOrder="10"/>
    </type>
    <type name="Gw\ConsoleTest\Model\TestClass">
        <plugin name="TestPluginB" type="Gw\ConsoleTest\Model\TestPluginB" sortOrder="20"/>
    </type>

[2019-10-18 13:20:19] main.INFO: TestPluginA::beforeMainFunctionCall [] []
[2019-10-18 13:20:19] main.INFO: TestPluginB::beforeMainFunctionCall [] []
[2019-10-18 13:20:19] main.INFO: TestClass::mainFunctionCall [] []
[2019-10-18 13:20:19] main.INFO: TestPluginA::afterMainFunctionCall [] []
[2019-10-18 13:20:19] main.INFO: TestPluginB::afterMainFunctionCall [] []

ConsoleTest.zip

[m2-assistant[bot]]

Hi @gwharton. Thank you for your report.
To help us process this issue please make sure that you provided the following information:

• [x] Summary of the issue
• [x] Information on your environment
• [x] Steps to reproduce
• [x] Expected and actual results

Please make sure that the issue is reproducible on the vanilla Magento instance following Steps to reproduce. To deploy vanilla Magento instance on our environment, please, add a comment to the issue:

@magento give me 2.3-develop instance - upcoming 2.3.x release

For more details, please, review the Magento Contributor Assistant documentation.

@gwharton do you confirm that you were able to reproduce the issue on vanilla Magento instance following steps to reproduce?

• [x] yes
• [ ] no

---

• Join Magento Community Engineering Slack and ask your questions in #github channel.

[m2-assistant[bot]]

Hi @dmytro-ch. Thank you for working on this issue.
In order to make sure that issue has enough information and ready for development, please read and check the following instruction: :point_down:

• [x] 1. Verify that issue has all the required information. (Preconditions, Steps to reproduce, Expected result, Actual result).
  Details

  If the issue has a valid description, the label Issue: Format is valid will be added to the issue automatically. Please, edit issue description if needed, until label Issue: Format is valid appears.

• [x] 2. Verify that issue has a meaningful description and provides enough information to reproduce the issue. If the report is valid, add Issue: Clear Description label to the issue by yourself.

• [x] 3. Add Component: XXXXX label(s) to the ticket, indicating the components it may be related to.

• [x] 4. Verify that the issue is reproducible on 2.3-develop branch

  Details

  - Add the comment @magento give me 2.3-develop instance to deploy test instance on Magento infrastructure.
  - If the issue is reproducible on 2.3-develop branch, please, add the label Reproduced on 2.3.x.
  - If the issue is not reproducible, add your comment that issue is not reproducible and close the issue and _stop verification process here_!

• [ ] 5. Add label Issue: Confirmed once verification is complete.

• [ ] 6. Make sure that automatic system confirms that report has been added to the backlog.

[magento-engcom-team]

:white_check_mark: Confirmed by @dmytro-ch
Thank you for verifying the issue. Based on the provided information internal tickets MC-21985 were created

Issue Available: @dmytro-ch, _You will be automatically unassigned. Contributors/Maintainers can claim this issue to continue. To reclaim and continue work, reassign the ticket to yourself._

[atwixfirster]

Pretty good question. We discussed this problem with @shrielenee in https://github.com/magento/devdocs/issues/3200.

Per my debug I've detected the next plugins sequence :

For example, we have some class with execute method.

For this method we have 2 plugins:

• Plugin A (sortOrder = 10)
  
  
  
  • aroundExecute method
  
  
  • afterExecute method
  
  
• Plugin B (sortOrder = 20)
  
  
  
  • beforeExecute method
  
  
  • aroundExecute method
  
  
  • afterExecute method
  
  

Execution queue:

1. Plugin A::aroundExecute (sortOrder=10)
2. Plugin B::beforeExecute (sortOrder=20)
3. Plugin B::aroundExecute (sortOrder=20)
4. execute method of native class
5. Plugin B::afterExecute (sortOrder=20)
6. Plugin A::afterExecute (sortOrder=10)

CC: @dmytro-ch

[m2-assistant[bot]]

Hi @GDauer. Thank you for working on this issue.
Looks like this issue is already verified and confirmed. But if you want to validate it one more time, please, go though the following instruction:

• [x] 1. Add/Edit Component: XXXXX label(s) to the ticket, indicating the components it may be related to.

• [x] 2. Verify that the issue is reproducible on 2.3-develop branch

  Details

  - Add the comment @magento give me 2.3-develop instance to deploy test instance on Magento infrastructure.
  - If the issue is reproducible on 2.3-develop branch, please, add the label Reproduced on 2.3.x.
  - If the issue is not reproducible, add your comment that issue is not reproducible and close the issue and _stop verification process here_!

• [ ] 3. If the issue is not relevant or is not reproducible any more, feel free to close it.

---

• Join Magento Community Engineering Slack and ask your questions in #github channel.

[GDauer]

Just have tried the same example as the documentation and seems we have a bug. Apparently the problem is in the last two after Plugins:

[gwharton]

Still broken in 2.4.0

[2020-08-13 15:06:16] main.INFO: TestPluginA::beforeMainFunctionCall [] []
[2020-08-13 15:06:16] main.INFO: TestPluginB::beforeMainFunctionCall [] []
[2020-08-13 15:06:16] main.INFO: TestClass::mainFunctionCall [] []
[2020-08-13 15:06:16] main.INFO: TestPluginA::afterMainFunctionCall [] []
[2020-08-13 15:06:16] main.INFO: TestPluginB::afterMainFunctionCall [] []

[mrtuvn]

seem your case is scenario A like docs https://devdocs.magento.com/guides/v2.4/extension-dev-guide/plugins.html
What wrong with order executed

[gwharton]

Indeed, seems it was less intrusive/problematic to fix the documentation instead of the bug. 😀

[dmytro-ch]

It's really disappointing. The dev certification questions are still based on the original version of the scenario. While the official documentation does not reflect it anymore.
Updating the documentation instead of fixing the root of the issue is not the best idea.