Inconsistent Runserver in Testing

[mikemadison13]

Describe the bug
I'm getting varied results with the runserver command. I believe some of this is related to #3994.

Scenario 1: Tests "Work"
In this scenario, the CI environment detection isn't actually working properly because of the Envrionment Detector issue raised in #3994. HOWEVER, if you look at the output, a few interesting things should be noted:

1. Behat tests run (and pass)
2. the tests:server:start command is not run
3. Config is mismatched and regenerated
4. The tests:behat:run process waits for a response from http://localhost:9222 and then continues, and works

vendor/bin/blt tests:all --define drush.alias='${drush.aliases.ci}' -D behat.web-driver=chrome --no-interaction --ansi --verbose
[warning] The xDebug extension is loaded. This will significantly decrease performance.
> tests:behat:run
[warning] project.local.uri in blt.yml does not match local.extensions.Behat\MinkExtension.base_url in local.yml.
[warning] project.local.uri = http://local.<project>.com
[warning] local.extensions.Behat\MinkExtension.base_url = http://127.0.0.1:8888
[warning] Behat is not configured properly.
BLT can (re)generate tests/behat/local.yml using tests/behat/example.local.yml.
> tests:behat:init:config
Generating Behat configuration files...
[Filesystem\FilesystemStack] _copy ["/home/vsts/work/1/s/tests/behat/example.local.yml","/home/vsts/work/1/s/tests/behat/local.yml"]
[Filesystem\FilesystemStack] mkdir ["/home/vsts/work/1/s/reports"]
[info] Killing running google-chrome processes...
[info] Killing all processes on port '9222'...
[info] Launching headless chrome...

[Robo\Common\ProcessExecutor] Running 'google-chrome' --headless --disable-web-security --remote-debugging-port=9222  http://localhost in /home/vsts/work/1/s
[info] Waiting for response from http://localhost:9222...
[info] Waiting for response from http://localhost:9222...
[info] Waiting for response from http://localhost:9222...
[info] Waiting for response from http://localhost:9222...
[info] Waiting for response from http://localhost:9222...
[info] Waiting for response from http://localhost:9222...
[info] Waiting for response from http://localhost:9222...
[info] Waiting for response from http://localhost:9222...
[info] Waiting for response from http://localhost:9222...
[info] Waiting for response from http://localhost:9222...
[info] Waiting for response from http://localhost:9222...
[Testing\Behat] Running behat  --format pretty /home/vsts/work/1/s/tests/behat --colors --no-interaction --stop-on-failure --strict --config /home/vsts/work/1/s/tests/behat/local.yml --profile local --tags '~ajax&&~experimental&&~lightningextension' -v
@api
Feature: Baseline Tests

  Scenario: Ensure Site is Accessible           # features/Base.feature:3
    Given I am on "/"                           # Drupal\DrupalExtension\Context\MinkContext::visit()
    Then the response status code should be 200 # Drupal\DrupalExtension\Context\MinkContext::assertResponseStatus()

1 scenario (1 passed)
2 steps (2 passed)
0m11.48s (108.48Mb)
[info] Killing running google-chrome processes...
[info] Killing all processes on port '9222'...

Scenario 2: Tests Don't Work

The notable difference between Scenario 1 and Scenario 2 is that I "fixed" Environment Detection (so the build now "knows" it's in CI. Note that in this scenario, it does attempt to do the drush runserver (and cannot connect to it). This is related to #3968 as it's the same issue (unclear if it's the same root cause as this is a brand new BLT Project).

Note that config does not mismatch here (good, theoretically) but still doesn't seem to work.

vendor/bin/blt tests:all --define drush.alias='${drush.aliases.ci}' -D behat.web-driver=chrome --no-interaction --ansi --verbose
[warning] The xDebug extension is loaded. This will significantly decrease performance.
> tests:behat:run
> tests:server:start
[info] Killing all processing containing string 'runserver'...
[info] Killing all processes on port '8888'...
Launching PHP's internal web server via drush.
[info] Running server at http://127.0.0.1:8888...
[info] Waiting for response from http://127.0.0.1:8888...
[info] Waiting for response from http://127.0.0.1:8888...
[info] Waiting for response from http://127.0.0.1:8888...
[info] Waiting for response from http://127.0.0.1:8888...
[info] Waiting for response from http://127.0.0.1:8888...
[info] Waiting for response from http://127.0.0.1:8888...
[info] Waiting for response from http://127.0.0.1:8888...
[info] Waiting for response from http://127.0.0.1:8888...
[info] Waiting for response from http://127.0.0.1:8888...
[info] Waiting for response from http://127.0.0.1:8888...
[info] Waiting for response from http://127.0.0.1:8888...
[info] Waiting for response from http://127.0.0.1:8888...
[info] Waiting for response from http://127.0.0.1:8888...
[info] Waiting for response from http://127.0.0.1:8888...
[info] Waiting for response from http://127.0.0.1:8888...
[info] Waiting for response from http://127.0.0.1:8888...
[info] Waiting for response from http://127.0.0.1:8888...
[info] Waiting for response from http://127.0.0.1:8888...
[info] Waiting for response from http://127.0.0.1:8888...
[info] Waiting for response from http://127.0.0.1:8888...
[info] Waiting for response from http://127.0.0.1:8888...
[error]  Timed out.

Scenario 3: Runserver Disabled
In Scenario 3, I have manually disabled the runserver command. Note the difference in output. However, in this scenario, the tests fail (likely because the server isn't running).

vendor/bin/blt tests:all --define drush.alias='${drush.aliases.ci}' -D behat.web-driver=chrome --no-interaction --ansi --verbose
[warning] The xDebug extension is loaded. This will significantly decrease performance.
> tests:behat:run
[Filesystem\FilesystemStack] mkdir ["/home/vsts/work/1/s/reports"]
[info] Killing running google-chrome processes...
[info] Killing all processes on port '9222'...

[info] Launching headless chrome...
[Robo\Common\ProcessExecutor] Running 'google-chrome' --headless --disable-web-security --remote-debugging-port=9222  http://localhost in /home/vsts/work/1/s
[info] Waiting for response from http://localhost:9222...
[info] Waiting for response from http://localhost:9222...
[info] Waiting for response from http://localhost:9222...
[info] Waiting for response from http://localhost:9222...
[info] Waiting for response from http://localhost:9222...
[info] Waiting for response from http://localhost:9222...
[Testing\Behat] Running behat  --format pretty /home/vsts/work/1/s/tests/behat --colors --no-interaction --stop-on-failure --strict --config /home/vsts/work/1/s/tests/behat/local.yml --profile local --tags '~ajax&&~experimental&&~lightningextension' -v
@api
Feature: Baseline Tests

  Scenario: Ensure Site is Accessible           # features/Base.feature:3
    Given I am on "/"                           # Drupal\DrupalExtension\Context\MinkContext::visit()
      GuzzleHttp\Exception\ConnectException: cURL error 7: Failed to connect to 127.0.0.1 port 8888: Connection refused (see http://curl.haxx.se/libcurl/c/libcurl-errors.html) in /home/vsts/work/1/s/vendor/guzzlehttp/guzzle/src/Handler/CurlFactory.php:185
      Stack trace:
#0 /home/vsts/work/1/s/vendor/guzzlehttp/guzzle/src/Handler/CurlFactory.php(149): GuzzleHttp\Handler\CurlFactory::createRejection(Object(GuzzleHttp\Handler\EasyHandle), Array)
      #1 /home/vsts/work/1/s/vendor/guzzlehttp/guzzle/src/Handler/CurlFactory.php(102): GuzzleHttp\Handler\CurlFactory::finishError(Object(GuzzleHttp\Handler\CurlHandler), Object(GuzzleHttp\Handler\EasyHandle), Object(GuzzleHttp\Handler\CurlFactory))
      #2 /home/vsts/work/1/s/vendor/guzzlehttp/guzzle/src/Handler/CurlHandler.php(43): GuzzleHttp\Handler\CurlFactory::finish(Object(GuzzleHttp\Handler\CurlHandler), Object(GuzzleHttp\Handler\EasyHandle), Object(GuzzleHttp\Handler\CurlFactory))
      #3 /home/vsts/work/1/s/vendor/guzzlehttp/guzzle/src/Handler/Proxy.php(28): GuzzleHttp\Handler\CurlHandler->__invoke(Object(GuzzleHttp\Psr7\Request), Array)
      #4 /home/vsts/work/1/s/vendor/guzzlehttp/guzzle/src/Handler/Proxy.php(51): GuzzleHttp\Handler\Proxy::GuzzleHttp\Handler\{closure}(Object(GuzzleHttp\Psr7\Request), Array)
      #5 /home/vsts/work/1/s/vendor/guzzlehttp/guzzle/src/PrepareBodyMiddleware.php(37): GuzzleHttp\Handler\Proxy::GuzzleHttp\Handler\{closure}(Object(GuzzleHttp\Psr7\Request), Array)
      #6 /home/vsts/work/1/s/vendor/guzzlehttp/guzzle/src/Middleware.php(36): GuzzleHttp\PrepareBodyMiddleware->__invoke(Object(GuzzleHttp\Psr7\Request), Array)
      #7 /home/vsts/work/1/s/vendor/guzzlehttp/guzzle/src/RedirectMiddleware.php(54): GuzzleHttp\Middleware::GuzzleHttp\{closure}(Object(GuzzleHttp\Psr7\Request), Array)
      #8 /home/vsts/work/1/s/vendor/guzzlehttp/guzzle/src/Middleware.php(60): GuzzleHttp\RedirectMiddleware->__invoke(Object(GuzzleHttp\Psr7\Request), Array)
      #9 /home/vsts/work/1/s/vendor/guzzlehttp/guzzle/src/HandlerStack.php(67): GuzzleHttp\Middleware::GuzzleHttp\{closure}(Object(GuzzleHttp\Psr7\Request), Array)
      #10 /home/vsts/work/1/s/vendor/guzzlehttp/guzzle/src/Client.php(277): GuzzleHttp\HandlerStack->__invoke(Object(GuzzleHttp\Psr7\Request), Array)
      #11 /home/vsts/work/1/s/vendor/guzzlehttp/guzzle/src/Client.php(125): GuzzleHttp\Client->transfer(Object(GuzzleHttp\Psr7\Request), Array)
      #12 /home/vsts/work/1/s/vendor/guzzlehttp/guzzle/src/Client.php(131): GuzzleHttp\Client->requestAsync('GET', Object(GuzzleHttp\Psr7\Uri), Array)
      #13 /home/vsts/work/1/s/vendor/fabpot/goutte/Goutte/Client.php(180): GuzzleHttp\Client->request('GET', 'http://127.0.0....', Array)
#14 /home/vsts/work/1/s/vendor/symfony/browser-kit/Client.php(404): Goutte\Client->doRequest(Object(Symfony\Component\BrowserKit\Request))
      #15 /home/vsts/work/1/s/vendor/behat/mink-browserkit-driver/src/BrowserKitDriver.php(144): Symfony\Component\BrowserKit\Client->request('GET', 'http://127.0.0....', Array, Array, Array)
      #16 /home/vsts/work/1/s/vendor/behat/mink/src/Session.php(143): Behat\Mink\Driver\BrowserKitDriver->visit('http://127.0.0....')
      #17 /home/vsts/work/1/s/vendor/behat/mink-extension/src/Behat/MinkExtension/Context/RawMinkContext.php(131): Behat\Mink\Session->visit('http://127.0.0....')
      #18 /home/vsts/work/1/s/vendor/behat/mink-extension/src/Behat/MinkExtension/Context/MinkContext.php(49): Behat\MinkExtension\Context\RawMinkContext->visitPath('/')
      #19 [internal function]: Behat\MinkExtension\Context\MinkContext->visit('/')
      #20 /home/vsts/work/1/s/vendor/behat/behat/src/Behat/Testwork/Call/Handler/RuntimeCallHandler.php(103): call_user_func_array(Array, Array)
      #21 /home/vsts/work/1/s/vendor/behat/behat/src/Behat/Testwork/Call/Handler/RuntimeCallHandler.php(59): Behat\Testwork\Call\Handler\RuntimeCallHandler->executeCall(Object(Behat\Behat\Definition\Call\DefinitionCall))
      #22 /home/vsts/work/1/s/vendor/behat/behat/src/Behat/Testwork/Call/CallCenter.php(140): Behat\Testwork\Call\Handler\RuntimeCallHandler->handleCall(Object(Behat\Behat\Definition\Call\DefinitionCall))
      #23 /home/vsts/work/1/s/vendor/behat/behat/src/Behat/Testwork/Call/CallCenter.php(96): Behat\Testwork\Call\CallCenter->handleCall(Object(Behat\Behat\Definition\Call\DefinitionCall))
      #24 /home/vsts/work/1/s/vendor/behat/behat/src/Behat/Behat/Tester/Runtime/RuntimeStepTester.php(125): Behat\Testwork\Call\CallCenter->makeCall(Object(Behat\Behat\Definition\Call\DefinitionCall))
      #25 /home/vsts/work/1/s/vendor/behat/behat/src/Behat/Behat/Tester/Runtime/RuntimeStepTester.php(73): Behat\Behat\Tester\Runtime\RuntimeStepTester->testDefinition(Object(Behat\Behat\Context\Environment\InitializedContextEnvironment), Object(Behat\Gherkin\Node\FeatureNode), Object(Behat\Gherkin\Node\StepNode), Object(Behat\Behat\Definition\SearchResult), false)
      #26 /home/vsts/work/1/s/vendor/behat/behat/src/Behat/Behat/Hook/Tester/HookableStepTester.php(74): Behat\Behat\Tester\Runtime\RuntimeStepTester->test(Object(Behat\Behat\Context\Environment\InitializedContextEnvironment), Object(Behat\Gherkin\Node\FeatureNode), Object(Behat\Gherkin\Node\StepNode), false)
      #27 /home/vsts/work/1/s/vendor/behat/behat/src/Behat/Behat/EventDispatcher/Tester/TickingStepTester.php(59): Behat\Behat\Hook\Tester\HookableStepTester->test(Object(Behat\Behat\Context\Environment\InitializedContextEnvironment), Object(Behat\Gherkin\Node\FeatureNode), Object(Behat\Gherkin\Node\StepNode), false)
      #28 /home/vsts/work/1/s/vendor/behat/behat/src/Behat/Behat/EventDispatcher/Tester/EventDispatchingStepTester.php(73): Behat\Behat\EventDispatcher\Tester\TickingStepTester->test(Object(Behat\Behat\Context\Environment\InitializedContextEnvironment), Object(Behat\Gherkin\Node\FeatureNode), Object(Behat\Gherkin\Node\StepNode), false)
      #29 /home/vsts/work/1/s/vendor/behat/behat/src/Behat/Behat/Tester/StepContainerTester.php(59): Behat\Behat\EventDispatcher\Tester\EventDispatchingStepTester->test(Object(Behat\Behat\Context\Environment\InitializedContextEnvironment), Object(Behat\Gherkin\Node\FeatureNode), Object(Behat\Gherkin\Node\StepNode), false)
      #30 /home/vsts/work/1/s/vendor/behat/behat/src/Behat/Behat/Tester/Runtime/RuntimeScenarioTester.php(76): Behat\Behat\Tester\StepContainerTester->test(Object(Behat\Behat\Context\Environment\InitializedContextEnvironment), Object(Behat\Gherkin\Node\FeatureNode), Object(Behat\Gherkin\Node\ScenarioNode), false)
      #31 /home/vsts/work/1/s/vendor/behat/behat/src/Behat/Behat/Hook/Tester/HookableScenarioTester.php(74): Behat\Behat\Tester\Runtime\RuntimeScenarioTester->test(Object(Behat\Behat\Context\Environment\InitializedContextEnvironment), Object(Behat\Gherkin\Node\FeatureNode), Object(Behat\Gherkin\Node\ScenarioNode), false)
      #32 /home/vsts/work/1/s/vendor/behat/behat/src/Behat/Behat/EventDispatcher/Tester/EventDispatchingScenarioTester.php(103): Behat\Behat\Hook\Tester\HookableScenarioTester->test(Object(Behat\Behat\Context\Environment\InitializedContextEnvironment), Object(Behat\Gherkin\Node\FeatureNode), Object(Behat\Gherkin\Node\ScenarioNode), false)
      #33 /home/vsts/work/1/s/vendor/behat/behat/src/Behat/Behat/Tester/Runtime/IsolatingScenarioTester.php(69): Behat\Behat\EventDispatcher\Tester\EventDispatchingScenarioTester->test(Object(Behat\Behat\Context\Environment\InitializedContextEnvironment), Object(Behat\Gherkin\Node\FeatureNode), Object(Behat\Gherkin\Node\ScenarioNode), false)
      #34 /home/vsts/work/1/s/vendor/behat/behat/src/Behat/Behat/Tester/Runtime/RuntimeFeatureTester.php(84): Behat\Behat\Tester\Runtime\IsolatingScenarioTester->test(Object(Behat\Behat\Context\Environment\UninitializedContextEnvironment), Object(Behat\Gherkin\Node\FeatureNode), Object(Behat\Gherkin\Node\ScenarioNode), false)
#35 /home/vsts/work/1/s/vendor/behat/behat/src/Behat/Behat/Hook/Tester/HookableFeatureTester.php(72): Behat\Behat\Tester\Runtime\RuntimeFeatureTester->test(Object(Behat\Behat\Context\Environment\UninitializedContextEnvironment), Object(Behat\Gherkin\Node\FeatureNode), false)
      #36 /home/vsts/work/1/s/vendor/behat/behat/src/Behat/Behat/EventDispatcher/Tester/EventDispatchingFeatureTester.php(71): Behat\Behat\Hook\Tester\HookableFeatureTester->test(Object(Behat\Behat\Context\Environment\UninitializedContextEnvironment), Object(Behat\Gherkin\Node\FeatureNode), false)
      #37 /home/vsts/work/1/s/vendor/behat/behat/src/Behat/Testwork/Tester/Runtime/RuntimeSuiteTester.php(63): Behat\Behat\EventDispatcher\Tester\EventDispatchingFeatureTester->test(Object(Behat\Behat\Context\Environment\UninitializedContextEnvironment), Object(Behat\Gherkin\Node\FeatureNode), false)
      #38 /home/vsts/work/1/s/vendor/behat/behat/src/Behat/Testwork/Hook/Tester/HookableSuiteTester.php(73): Behat\Testwork\Tester\Runtime\RuntimeSuiteTester->test(Object(Behat\Behat\Context\Environment\UninitializedContextEnvironment), Object(Behat\Testwork\Specification\GroupedSpecificationIterator), false)
      #39 /home/vsts/work/1/s/vendor/behat/behat/src/Behat/Testwork/EventDispatcher/Tester/EventDispatchingSuiteTester.php(72): Behat\Testwork\Hook\Tester\HookableSuiteTester->test(Object(Behat\Behat\Context\Environment\UninitializedContextEnvironment), Object(Behat\Testwork\Specification\GroupedSpecificationIterator), false)
      #40 /home/vsts/work/1/s/vendor/behat/behat/src/Behat/Testwork/Tester/Runtime/RuntimeExercise.php(71): Behat\Testwork\EventDispatcher\Tester\EventDispatchingSuiteTester->test(Object(Behat\Behat\Context\Environment\UninitializedContextEnvironment), Object(Behat\Testwork\Specification\GroupedSpecificationIterator), false)
      #41 /home/vsts/work/1/s/vendor/behat/behat/src/Behat/Testwork/EventDispatcher/Tester/EventDispatchingExercise.php(70): Behat\Testwork\Tester\Runtime\RuntimeExercise->test(Array, false)
      #42 /home/vsts/work/1/s/vendor/behat/behat/src/Behat/Testwork/Ordering/OrderedExercise.php(80): Behat\Testwork\EventDispatcher\Tester\EventDispatchingExercise->test(Array, false)
      /home/vsts/work/1/s/vendor/behat/behat/src/Behat/Testwork/Ordering/OrderedExercise.php(80): Behat\Testwork\EventDispatcher\Tester\EventDispatchingExercise->test(Array, false)
      #43 /home/vsts/work/1/s/vendor/behat/behat/src/Behat/Testwork/Tester/Cli/ExerciseController.php(149): Behat\Testwork\Ordering\OrderedExercise->test(Array, false)
      #44 /home/vsts/work/1/s/vendor/behat/behat/src/Behat/Testwork/Tester/Cli/ExerciseController.php(108): Behat\Testwork\Tester\Cli\ExerciseController->testSpecifications(Object(Symfony\Component\Console\Input\ArgvInput), Array)
      #45 /home/vsts/work/1/s/vendor/behat/behat/src/Behat/Testwork/Cli/Command.php(63): Behat\Testwork\Tester\Cli\ExerciseController->execute(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
      #46 /home/vsts/work/1/s/vendor/symfony/console/Command/Command.php(255): Behat\Testwork\Cli\Command->execute(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
      #47 /home/vsts/work/1/s/vendor/symfony/console/Application.php(982): Symfony\Component\Console\Command\Command->run(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
      #48 /home/vsts/work/1/s/vendor/symfony/console/Application.php(255): Symfony\Component\Console\Application->doRunCommand(Object(Behat\Testwork\Cli\Command), Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
      #49 /home/vsts/work/1/s/vendor/behat/behat/src/Behat/Testwork/Cli/Application.php(124): Symfony\Component\Console\Application->doRun(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
      #50 /home/vsts/work/1/s/vendor/symfony/console/Application.php(148): Behat\Testwork\Cli\Application->doRun(Object(Symfony\Component\Console\Input\ArgvInput), Object(Symfony\Component\Console\Output\ConsoleOutput))
      #51 /home/vsts/work/1/s/vendor/behat/behat/bin/behat(34): Symfony\Component\Console\Application->run()
      #52 {main}
    Then the response status code should be 200 # Drupal\DrupalExtension\Context\MinkContext::assertResponseStatus()

--- Failed scenarios:

    features/Base.feature:3

1 scenario (1 failed)
2 steps (1 failed, 1 skipped)
0m1.65s (41.16Mb)
[Testing\Behat]  Exit code 1 

[mikemadison13]

Note that all 3 scenarios come from the same project. I have attempted to downgrade Drush here as I did in #3968 to resolve the issue, but to no avail. I think this all comes back to one of a few things:

• Why can't we tell that runserver is actually running (could be that 500 error we identified)
• Why in Scenario 1 do we instead listen directly to the Chrome port (not the drush runserver) and how is the server run if not explicitly shown in the log as running? Are we somehow starting it, but not validating that it's started?

[mikemadison13]

Further / expansive digging on this issue seems to indicate that at "some point" during behat testing, the drush runserver command pulls the database credentials out of the docroot/sites/default/settings/local.settings.php instead of vendor/acquia/blt/settings/ci.settings.php

This was tested by:

• creating a version of blt.yml with "lando specific" credentials for the database (e.g. drupal8)
• creating a version of ci.blt.yml with "ci" specific credentials for the database (e.g. drupal).

When I have hardcoded credentials in the settings.php file for Lando, I get the 500 error and timeout with the `http://127.0.0.1:8888 url. When I have variables in the settings.php file and local (lando) and ci (not lando) credentials in the yml files, it seems to work fine.

Note that in order to make this work, I have a PR in to "fix" #3994 (see #4013).

[mikemadison13]

Paths forward:

• Figure out why the drush runserver / blt behat commands are not using ci.settings.php properly (that could be a fun rabbit hole)
• change the stock ci.blt.yml file to include the stock database credentials for "drupal"
• update ADS to write the necessary lando credentials into the blt.yml file upon ads init and other commands to spin up a new, shiny local with ADS / Lando.
• ?

[mikemadison13]

@danepowell FYI the above solution does work with Drush 9.7 but does not appear to work with Drush 10.x. For some reason I'm still getting a 500 status with Drush 10.

[mikemadison13]

@danepowell there is definitely something going on with settings here. when i removed database config from blt.yml and ci.blt.yml (so stock config) and instead did the local in example.local.blt.yml / local.blt.yml things started working again. shoutout to @lcatlett for her DDev plugin... made me think to try that here and it worked.

i think we continue to get bit by something related to environment detection (and it's further exacerbated in Drush 10 FOR SOME REASON).

i don't think we need to keep this issue open at this point. put your lando / ddev specific config in the local blt files and this shouldn't happen in CI.

[gauravmanerkar]

Hello,
I have facing this issue