farmOS / farmOS

farmOS: A web-based farm record keeping application.
https://farmOS.org
GNU General Public License v2.0
975 stars 272 forks source link

Troubleshooting tests with 2.x #372

Closed symbioquine closed 3 years ago

symbioquine commented 3 years ago

I started to play around with the tests for farmOS 2.x with some successes. The tests which hit the database seem to be passing locally, however those which are based on web requests aren't. I'm sure there's something about my configuration which is breaking them, but I'm less concerned about that than the experience of working with the tests.

I may have been spoiled by Java, Python, and even Javascript test frameworks which tend to produce concise, informative stack traces and assertion failures.

Some frustrations here;

I'm hoping there's some magic bullet or tricks that makes phpunit and the Drupal test scaffolding more sane to work with - hopefully without depending on a proprietary IDE - but at worst I guess this issue can just capture the frustration I'm experiencing :)

Examples console output;

$ docker-compose exec -u www-data -e SIMPLETEST_DB="pgsql://farm:farm@pgsql/farm" -e SIMPLETEST_BASE_URL="https://v2.farmos.test" www2 phpunit --verbose --debug --group farm

...

Time: 27.77 minutes, Memory: 931.00 MB

There were 6 failures:

1) Drupal\Tests\asset\Functional\AssetCRUDTest::testFieldsVisibility
User <em class="placeholder">jEvqh5lo</em> successfully logged in.
Failed asserting that false is true.

/opt/drupal/vendor/phpunit/phpunit/src/Framework/Constraint/Constraint.php:118
/opt/drupal/vendor/phpunit/phpunit/src/Framework/Constraint/Constraint.php:54
/opt/drupal/vendor/phpunit/phpunit/src/Framework/Assert.php:2887
/opt/drupal/vendor/phpunit/phpunit/src/Framework/Assert.php:1541
/opt/drupal/web/core/tests/Drupal/Tests/UiHelperTrait.php:254
/opt/drupal/web/profiles/farm/modules/core/asset/tests/src/Functional/AssetTestBase.php:44
/opt/drupal/vendor/phpunit/phpunit/src/Framework/TestResult.php:691

2) Drupal\Tests\asset\Functional\AssetCRUDTest::testCreateAsset
User <em class="placeholder">lrnPvSdj</em> successfully logged in.
Failed asserting that false is true.

/opt/drupal/vendor/phpunit/phpunit/src/Framework/Constraint/Constraint.php:118
/opt/drupal/vendor/phpunit/phpunit/src/Framework/Constraint/Constraint.php:54
/opt/drupal/vendor/phpunit/phpunit/src/Framework/Assert.php:2887
/opt/drupal/vendor/phpunit/phpunit/src/Framework/Assert.php:1541
/opt/drupal/web/core/tests/Drupal/Tests/UiHelperTrait.php:254
/opt/drupal/web/profiles/farm/modules/core/asset/tests/src/Functional/AssetTestBase.php:44
/opt/drupal/vendor/phpunit/phpunit/src/Framework/TestResult.php:691

3) Drupal\Tests\asset\Functional\AssetCRUDTest::testViewAsset
User <em class="placeholder">yYNBkwSG</em> successfully logged in.
Failed asserting that false is true.

/opt/drupal/vendor/phpunit/phpunit/src/Framework/Constraint/Constraint.php:118
/opt/drupal/vendor/phpunit/phpunit/src/Framework/Constraint/Constraint.php:54
/opt/drupal/vendor/phpunit/phpunit/src/Framework/Assert.php:2887
/opt/drupal/vendor/phpunit/phpunit/src/Framework/Assert.php:1541
/opt/drupal/web/core/tests/Drupal/Tests/UiHelperTrait.php:254
/opt/drupal/web/profiles/farm/modules/core/asset/tests/src/Functional/AssetTestBase.php:44
/opt/drupal/vendor/phpunit/phpunit/src/Framework/TestResult.php:691

4) Drupal\Tests\asset\Functional\AssetCRUDTest::testEditAsset
User <em class="placeholder">y0zhm2Rw</em> successfully logged in.
Failed asserting that false is true.

/opt/drupal/vendor/phpunit/phpunit/src/Framework/Constraint/Constraint.php:118
/opt/drupal/vendor/phpunit/phpunit/src/Framework/Constraint/Constraint.php:54
/opt/drupal/vendor/phpunit/phpunit/src/Framework/Assert.php:2887
/opt/drupal/vendor/phpunit/phpunit/src/Framework/Assert.php:1541
/opt/drupal/web/core/tests/Drupal/Tests/UiHelperTrait.php:254
/opt/drupal/web/profiles/farm/modules/core/asset/tests/src/Functional/AssetTestBase.php:44
/opt/drupal/vendor/phpunit/phpunit/src/Framework/TestResult.php:691

5) Drupal\Tests\asset\Functional\AssetCRUDTest::testDeleteAsset
User <em class="placeholder">nQ1ULBrP</em> successfully logged in.
Failed asserting that false is true.

/opt/drupal/vendor/phpunit/phpunit/src/Framework/Constraint/Constraint.php:118
/opt/drupal/vendor/phpunit/phpunit/src/Framework/Constraint/Constraint.php:54
/opt/drupal/vendor/phpunit/phpunit/src/Framework/Assert.php:2887
/opt/drupal/vendor/phpunit/phpunit/src/Framework/Assert.php:1541
/opt/drupal/web/core/tests/Drupal/Tests/UiHelperTrait.php:254
/opt/drupal/web/profiles/farm/modules/core/asset/tests/src/Functional/AssetTestBase.php:44
/opt/drupal/vendor/phpunit/phpunit/src/Framework/TestResult.php:691

6) Drupal\Tests\asset\Functional\AssetCRUDTest::testArchiveAsset
User <em class="placeholder">ghszAoXW</em> successfully logged in.
Failed asserting that false is true.

/opt/drupal/vendor/phpunit/phpunit/src/Framework/Constraint/Constraint.php:118
/opt/drupal/vendor/phpunit/phpunit/src/Framework/Constraint/Constraint.php:54
/opt/drupal/vendor/phpunit/phpunit/src/Framework/Assert.php:2887
/opt/drupal/vendor/phpunit/phpunit/src/Framework/Assert.php:1541
/opt/drupal/web/core/tests/Drupal/Tests/UiHelperTrait.php:254
/opt/drupal/web/profiles/farm/modules/core/asset/tests/src/Functional/AssetTestBase.php:44
/opt/drupal/vendor/phpunit/phpunit/src/Framework/TestResult.php:691

FAILURES!
Tests: 18, Assertions: 235, Failures: 6.

HTML output was generated
https://v2.farmos.test/sites/simpletest/browser_output/Drupal_Tests_asset_Functional_AssetCRUDTest-54-15703790.html
https://v2.farmos.test/sites/simpletest/browser_output/Drupal_Tests_asset_Functional_AssetCRUDTest-55-15703790.html
https://v2.farmos.test/sites/simpletest/browser_output/Drupal_Tests_asset_Functional_AssetCRUDTest-56-15703790.html
https://v2.farmos.test/sites/simpletest/browser_output/Drupal_Tests_asset_Functional_AssetCRUDTest-57-15703790.html
https://v2.farmos.test/sites/simpletest/browser_output/Drupal_Tests_asset_Functional_AssetCRUDTest-58-18356352.html
https://v2.farmos.test/sites/simpletest/browser_output/Drupal_Tests_asset_Functional_AssetCRUDTest-59-18356352.html
https://v2.farmos.test/sites/simpletest/browser_output/Drupal_Tests_asset_Functional_AssetCRUDTest-60-18356352.html
https://v2.farmos.test/sites/simpletest/browser_output/Drupal_Tests_asset_Functional_AssetCRUDTest-61-18356352.html
https://v2.farmos.test/sites/simpletest/browser_output/Drupal_Tests_asset_Functional_AssetCRUDTest-62-86967973.html
https://v2.farmos.test/sites/simpletest/browser_output/Drupal_Tests_asset_Functional_AssetCRUDTest-63-86967973.html
https://v2.farmos.test/sites/simpletest/browser_output/Drupal_Tests_asset_Functional_AssetCRUDTest-64-86967973.html
https://v2.farmos.test/sites/simpletest/browser_output/Drupal_Tests_asset_Functional_AssetCRUDTest-65-86967973.html
https://v2.farmos.test/sites/simpletest/browser_output/Drupal_Tests_asset_Functional_AssetCRUDTest-66-69730071.html
https://v2.farmos.test/sites/simpletest/browser_output/Drupal_Tests_asset_Functional_AssetCRUDTest-67-69730071.html
https://v2.farmos.test/sites/simpletest/browser_output/Drupal_Tests_asset_Functional_AssetCRUDTest-68-69730071.html
https://v2.farmos.test/sites/simpletest/browser_output/Drupal_Tests_asset_Functional_AssetCRUDTest-69-69730071.html
https://v2.farmos.test/sites/simpletest/browser_output/Drupal_Tests_asset_Functional_AssetCRUDTest-70-15555351.html
https://v2.farmos.test/sites/simpletest/browser_output/Drupal_Tests_asset_Functional_AssetCRUDTest-71-15555351.html
https://v2.farmos.test/sites/simpletest/browser_output/Drupal_Tests_asset_Functional_AssetCRUDTest-72-15555351.html
https://v2.farmos.test/sites/simpletest/browser_output/Drupal_Tests_asset_Functional_AssetCRUDTest-73-15555351.html
https://v2.farmos.test/sites/simpletest/browser_output/Drupal_Tests_asset_Functional_AssetCRUDTest-74-10511596.html
https://v2.farmos.test/sites/simpletest/browser_output/Drupal_Tests_asset_Functional_AssetCRUDTest-75-10511596.html
https://v2.farmos.test/sites/simpletest/browser_output/Drupal_Tests_asset_Functional_AssetCRUDTest-76-10511596.html
https://v2.farmos.test/sites/simpletest/browser_output/Drupal_Tests_asset_Functional_AssetCRUDTest-77-10511596.html
$ docker-compose exec -u www-data -e SIMPLETEST_DB="pgsql://farm:farm@pgsql/farm" -e SIMPLETEST_BASE_URL="https://v2.farmos.test" www2 phpunit --verbose --debug --group farm --filter AssetCRUDTest::testCreateAsset
PHPUnit 8.5.9 by Sebastian Bergmann and contributors.

Runtime:       PHP 7.4.12 with Xdebug 2.9.8
Configuration: /opt/drupal/phpunit.xml

Testing 
Test 'Drupal\Tests\asset\Functional\AssetCRUDTest::testCreateAsset' started
Test 'Drupal\Tests\asset\Functional\AssetCRUDTest::testCreateAsset' ended

Time: 3.48 minutes, Memory: 931.00 MB

There was 1 error:

1) Drupal\Tests\asset\Functional\AssetCRUDTest::testCreateAsset
PHPUnit\Framework\Exception: Killed

/opt/drupal/vendor/phpunit/phpunit/src/Util/PHP/AbstractPhpProcess.php:254
/opt/drupal/vendor/phpunit/phpunit/src/Util/PHP/AbstractPhpProcess.php:171
/opt/drupal/vendor/phpunit/phpunit/src/Framework/TestSuite.php:601
/opt/drupal/vendor/phpunit/phpunit/src/Framework/TestSuite.php:601
/opt/drupal/vendor/phpunit/phpunit/src/Framework/TestSuite.php:601
/opt/drupal/vendor/phpunit/phpunit/src/Framework/TestSuite.php:601
/opt/drupal/vendor/phpunit/phpunit/src/TextUI/TestRunner.php:627
/opt/drupal/vendor/phpunit/phpunit/src/TextUI/Command.php:204
/opt/drupal/vendor/phpunit/phpunit/src/TextUI/Command.php:163

ERRORS!
Tests: 1, Assertions: 0, Errors: 1.
mstenta commented 3 years ago

Tests take a really long time

Agreed - and part of this may be due to the fact that XDebug is installed in the dev image, which is also used for running tests currently. We need to change this. It was just a result of the way I set up the Docker containers and testing instructions originally, and now that our tests are growing it's becoming a problem. That said, I'm not exactly sure how much of an impact it's having, and/or if there are other optimization options.

Everything else you describe is outside the scope of farmOS/Drupal I think, however. We are basically just running phpunit in the recommended way. But I'd certainly love to see some improvements! All of the points you make are valid! This might need to be explored upstream.

Here is where the PHPUnit configuration is set up in our Dockerfile currently: https://github.com/farmOS/farmOS/blob/2ce6c8eac09540ba683a910da37285e5d7e6d3b4/docker/dev/Dockerfile#L56

You may have noticed, but we also have a GitHub Action for building the Docker images from scratch and running the tests: https://github.com/farmOS/farmOS/blob/2.x/.github/workflows/run-tests.yml

This seems to take ~20 minutes on average to run right now. That includes building the images. Tests themselves run in ~15 minutes on GitHub's servers: https://github.com/farmOS/farmOS/actions?query=workflow%3A%22Run+2.x+PHPUnit+tests%22

mstenta commented 3 years ago

FWIW the SIMPLETEST_DB="pgsql://farm:farm@pgsql/farm" -e SIMPLETEST_BASE_URL="https://v2.farmos.test" parameters shouldn't be necessary in the command you're running. Those are set in phpunit.xml: https://github.com/farmOS/farmOS/blob/2ce6c8eac09540ba683a910da37285e5d7e6d3b4/docker/dev/Dockerfile#L59

Notably, SIMPLETEST_BASE_URL is set to http://localhost. I wonder if that's what's breaking your browser tests?

mstenta commented 3 years ago

All that said, I welcome suggestions from anyone who has more knowledge and experience with Druapl PHPUnit testing than I do! :-)

symbioquine commented 3 years ago

Thanks for taking time to respond to my rant @mstenta!

Everything else you describe is outside the scope of farmOS/Drupal I think, however. We are basically just running phpunit in the recommended way. But I'd certainly love to see some improvements! All of the points you make are valid! This might need to be explored upstream.

That makes sense. Exploring many of these upstream would definitely be a reasonable strategy.

I think tracking these pain points here is also worthwhile though since the farmOS project itself is also responsible for the developer experience consequences of the technology/configuration choices involved.

In addition to the idea you mentioned about experimenting with disabling xdebug, one strategy I can imagine would be to split the tests into more finely grained groups and run all the groups as separate jobs in parallel for the GitHub action. As long as we don't run into some sort of usage limit that would probably scale pretty well to larger numbers of tests at the cost of some additional complexity in the GitHub action. It might also improve the developer experience prior to check in by providing a more structured way beyond custom test filters for devs to run a smaller set of tests more frequently and only run the full set just before check in.

FWIW the SIMPLETEST_DB="pgsql://farm:farm@pgsql/farm" -e SIMPLETEST_BASE_URL="https://v2.farmos.test" parameters shouldn't be necessary in the command you're running.

I set those because my docker container names differ right now from the defaults and I'm running farmOS behind a reverse proxy, but I see what you mean now about how I could leave SIMPLETEST_BASE_URL alone since the tests are running from within the same container.

mstenta commented 3 years ago

In addition to the idea you mentioned about experimenting with disabling xdebug, one strategy I can imagine would be to split the tests into more finely grained groups and run all the groups as separate jobs in parallel for the GitHub action.

Oh this is a really interesting idea! How would this work? Multiple action YML files that all get triggered by the same push, but execute a different test? Or could it be done all in one YML?

We might need to think about splitting the Docker image build process out, so it's not repeated every time. I kinda like how it's an "end to end build+test" right now, but probably not the best approach in the long run.

But yea getting XDebug out of there should probably be step 1.

I think tracking these pain points here is also worthwhile though since the farmOS project itself is also responsible for the developer experience consequences of the technology/configuration choices involved.

Agreed - looking back my reply was a bit too much on the "not my problem" side of things. :-)

That may still be true generally, but I'm curious if there are optimizations we can make with our PHPUnit config as well.

Found this: https://kriswallsmith.net/post/27979797907/get-fast-an-easy-symfony2-phpunit-optimization

I wonder if Drupal core is already doing that...

symbioquine commented 3 years ago

How would this work? Multiple action YML files that all get triggered by the same push, but execute a different test? Or could it be done all in one YML?

It is feasible to do it in one YML file - it might even be preferable to combine the existing ones such that the docs/release actions only happen once the tests have passed...

I've created a test repository demonstrating how tests could be run in parallel in separate jobs, then feed into the docs/release steps.

image

From some example test runs 1, 2 we can see that each of the test cases runs in a little over 1 minute - thus demonstrating that it didn't incur the cost of the docker image build again. Also the total workflow runs in about 3 - 4 minutes - thus demonstrating that, at least for this test case, the parallelism produced a speed-up over running all test cases sequentially (presumed to take more than 5 minutes).

mstenta commented 3 years ago

This is great @symbioquine ! Thanks for demonstrating!

We've been using the drupal.org issue queue for specific 2.x development tasks. I opened a new issue over there for running tests in parallel, under the "2.x build process" roadmap: https://www.drupal.org/project/farm/issues/3183682

I also created a dedicated issue for running tests without Xdebug: https://www.drupal.org/project/farm/issues/3183687

Interesting idea to combine the tests+docs+release scripts too. I'd like let that idea simmer a bit in my head - but maybe we can spin up a meta issue to think about that as well. I kind of like that they are separate and "do one thing" right now, but let's think about it!

mstenta commented 3 years ago

@symbioquine I just discovered another reason why the tests are taking a long time!

TL;DR: A whole bunch of farmOS modules are being installed with every test, and they shouldn't be.

Edit: This is only an issue with functional tests (that inherit from BrowserTestBase. Kernel and Unit tests are not affected.

This is happening because the farm profile is being installed with many of the tests (so that the profile's modules are available to the testing environment). This should be fine, because the profile itself doesn't install many modules on its own (limited dependencies declared in farm.info.yml). However, the profile also implements hook_install_tasks(), which installs a set of default modules. I didn't think that would run with tests, but it does.

I stumbled across this while debugging this recent test failure: https://github.com/mstenta/farmOS/runs/1430866938

Working on a fix for it now... this should help to speed things up quite a bit too. :-)

paul121 commented 3 years ago

@symbioquine very cool!

One other improvement we could do is change some of the BrowserTests to Kernel tests. Its possible to make requests and check responses without all the overhead of BrowserTest. I suppose this would be for anything that doesn't need to explicitly be tested in the browser window, like API requests or checking for the existence of text.

I used this technique recently for the data stream API tests. We should do this for the farm_api tests too.

mstenta commented 3 years ago

+1 to Kernel tests wherever possible!

Worth noting, the issue I described above ("A whole bunch of farmOS modules are being installed with every test, and they shouldn't be.") is only happening with Functional tests, not Kernel tests.

mstenta commented 3 years ago

FYI I opened a new issue for that: https://www.drupal.org/project/farm/issues/3183739

A bit tricky to solve... thinking through options...

symbioquine commented 3 years ago

Wow thanks, this is awesome! Glad this has prompted so many avenues of investigation...

I think this issue should be tagged with the farmOS 2.x tag also.

Interesting idea to combine the tests+docs+release scripts too. I'd like let that idea simmer a bit in my head - but maybe we can spin up a meta issue to think about that as well. I kind of like that they are separate and "do one thing" right now, but let's think about it!

Yeah, that's definitely a trade-off. One hybrid strategy could potentially be to use the repository-dispatch pattern to kick off the docs/release workflows only upon successful completion of the build/test workflows. This would have the advantage of decoupling the success of the docs/release workflows from each other and reduce the size of each YAML file.

mstenta commented 3 years ago

Good to know!

Worth noting: the tests and docs workflows both run whenever the 2.x branch is pushed. But the release workflow only runs when a 2.* tag is pushed. So to start we can at least push 2.x, wait for the tests to pass, then tag and push a release.

The docs being built is less urgent to tie to tests, I think, because it's just running mkdocs build and pushing it to https://2x.farmos.org

mstenta commented 3 years ago

FYI I pushed a temporary (UGLY) fix for the functional tests. See comment here: https://www.drupal.org/project/farm/issues/3183739#comment-13910556

Unfortunately, that revealed that another one of our tests was implicitly depending on a module that is no longer being enabled, so now tests are failing again. :-)

mstenta commented 3 years ago

Tests ran in ~8 mins with that fix (roughly cut the time in half)!

Next steps for optimization:

Tests will be pretty speedy after that!

symbioquine commented 3 years ago

Next steps for optimization:

  • Run without XDebug
  • Run in parallel

@mstenta if you haven't already started on them, I'd be happy to experiment with putting together a PR for those next steps...

mstenta commented 3 years ago

I have not! Go for it! I have some thoughts regarding the xdebug one, but might help from some fresh eyes as well. If you feel confident with the parallel processing one that might have the most impact.

symbioquine commented 3 years ago

If you feel confident with the parallel processing one that might have the most impact.

Yeah, I'll probably start there.

I have some thoughts regarding the xdebug one, but might help from some fresh eyes as well.

My tentative plan was building a separate Docker image based on the production one similar to how the "dev" image is built in the tests currently - minus the xdebug installation step obviously. When I played around with it previously, I didn't see a good way to disable xdebug once it is installed without more complicated php configuration changes.

mstenta commented 3 years ago

I posted my thoughts here: https://www.drupal.org/project/farm/issues/3183687#comment-13910778

mstenta commented 3 years ago

Are there other things worth discussing or spinning off as todos? Or do you think we can close this issue?

symbioquine commented 3 years ago

Not that I'm aware of. I'm comfortable tracking this going forward with the Drupal.org issues.