docker/sdk up fails when tideways service is enabled

[ghost]

Which release, branch or hash of Docker SDK are you using?

Latest master ee7e4aa

Which operating system (platform/version/architecture) are you using?

Linux

What is the issue that you're experiencing?

docker/sdk up fails with "Aborted install..." when having the tideways service enabled

What are the steps to reproduce the issue?

git clone https://github.com/spryker-shop/b2c-demo-shop.git

cd b2c-demo-shop

git clone https://github.com/spryker/docker-sdk.git docker

cat <<EOF | git apply
> diff --git a/deploy.dev.yml b/deploy.dev.yml
index e6263864d..d7323a8d6 100644
--- a/deploy.dev.yml
+++ b/deploy.dev.yml
@@ -7,8 +7,11 @@ environment: docker.dev
 image:
     tag: spryker/php:7.4-alpine3.12
     php:
+        ini:
+            "tideways.connection": "tcp://tideways:9135"
         enabled-extensions:
             - blackfire
+            - tideways
     environment:
         STORE_NAME_REFERENCE_MAP: '{"DE":"dev-DE","AT":"dev-AT","US":"dev-US"}'

@@ -199,6 +202,11 @@ services:
         engine: dashboard
         endpoints:
             spryker.local:
+    tideways:
+        engine: tideways
+        apikey: abcdefg
+        environment: development
+        cli-enabled: false

 docker:

EOF

docker/sdk bootstrap deploy.dev.yml ; docker/sdk up

What is the expected result of these steps in the absence of the issue?

Environment gets built completely and started.

What is the actual result?

Install docker environment
========================================================================================================================


 Section build


Command generate-transfers [vendor/bin/console transfer:generate] (In progress...)
Store: DE | Environment: docker.dev

In CommandLineExecutable.php line 107:

  Aborted install...


install [-r|--recipe RECIPE] [-d|--dry-run] [-s|--sections SECTIONS] [-g|--groups GROUPS] [-x|--exclude EXCLUDE] [-e|--include-excluded INCLUDE-EXCLUDED] [-i|--interactive] [-b|--breakpoint] [-a|--ask-before-continue] [-l|--log] [--] [<store>]

What possible solutions and/or workarounds for the issue do you see?

A workaround to solve the issue is to apply this patch into the docker-sdk repo:

cat <<'EOF' | git apply
diff --git a/bin/sdk/compose.sh b/bin/sdk/compose.sh
index fb9e4cc..067ac99 100644
--- a/bin/sdk/compose.sh
+++ b/bin/sdk/compose.sh
@@ -35,7 +35,7 @@ function Compose::ensureRunning() {
 function Compose::ensureCliRunning() {
     local isCliRunning=$(docker ps --filter 'status=running' --filter "ancestor=${SPRYKER_DOCKER_PREFIX}_run_cli:${SPRYKER_DOCKER_TAG}" --filter "name=${SPRYKER_DOCKER_PREFIX}_cli_*" --format "{{.Names}}")
     if [ -z "${isCliRunning}" ]; then
-        Compose::run --no-deps cli cli_ssh_relay
+        Compose::run --no-deps cli cli_ssh_relay tideways
         Registry::Flow::runAfterCliReady
     fi
 }
EOF

Is there any other information that might be helpful?

Why does the above workaround fix the issue; what is the original problem? The problem is that if we enable the tideways integration and set tideways.connection to "tcp://tideways:9135" in the php cli container, then all php processes that gets started on the container will try to reach the tideways container on port 9135.

This can be proven by executing above "steps to reproduce", and afterwards (after the error occured) jumping into the cli container and running a simple script:

docker/sdk cli

cat <<'EOF' > foobar.php
<?php
set_error_handler(function($errno, $errstr, $errfile, $errline, $errcontext) {
    var_dump($errno);
    var_dump($errstr);
    var_dump($errfile);
    var_dump($errline);
    var_dump($errcontext);
    throw new Exception();
});
EOF

time php foobar.php
echo $?

Output:

int(2)
string(76) "Unknown: php_network_getaddresses: getaddrinfo failed: Name does not resolve"
string(7) "Unknown"
int(0)
NULL

real    0m5.044s
user    0m0.016s
sys     0m0.023s
255

What happens here? Apparently an error gets thrown with "Unkown" origin. To understand the issue better, try to run a very simple php script:

cat <<'EOF' > foobar.php
<?php
var_dump('Hello world');
EOF

time php foobar.php
echo $?

Output:

string(11) "Hello world"

real    0m10.042s
user    0m0.010s
sys     0m0.023s
0

Why didn't we see an error here? Because we have not configured error handling, and the error that is being thrown is coming from the tideways php extension, which will throw the error after the script already has run. Also note the very long script running time of 5-10 seconds.

So, what is the problem? The problem is that we configure the php cli container to talk to a tideways container via "tcp://tideways:9135", but this container is not yet started at this point of the build process. A workaround would be to start the tideways container together with the cli container, see above workaround. But I hope the maintainers of this project will find a better solution.

Why this is an issue for Spryker projects

Spryker overrides the default error handler in all console commands via the \Spryker\Zed\Console\Communication\Bootstrap\ConsoleBootstrap::__construct call to Environment::initialize, which will forward to ErrorHandlerEnvironment::initialize, which in ::setErrorHandler will set a custom error handler, that exactly will do what the above proof showed: It will throw an exception when it receives an error. That is also why the steps to reproduce produce the "Aborted install..." error: In the process of docker/sdk up, vendor/bin/console will be called for the first time, and this is a php script. This script does it's job (in this generating the transfers correctly), and afterwards the tideways extension tries to reach the tideways container, but doesn't find the dns record because the container is not started, hence a php error is thrown, which will be caught by the Spryker error handler, converted into an exception, and the console command will then return a non-zero exitcode (because of an uncaught exception). As this all happens within the shutdown procedure of the php script already, we don't see any real "Uncaught exception" message anymore.

Another example to prove the problem is to run the console command manually again, after the above steps to reproduce lead to the problem:

time docker/sdk console transfer:generate
echo $?

Output:

-->  DEVELOPMENT MODE
Store: DE | Environment: docker.dev

real    0m9.216s
user    0m1.862s
sys     0m0.247s
255

^ Note: No error visible (exception gets swallowed), but exit-code 255.

[alexanderM91]

Hey @zyuzka,
can you please check it out?
Thank you.

[ghost]

@zyuzka @alexanderM91 did you have time to look at this?

[zyuzka]

@bomensal thank you for the detailed description. I'll check it today/tomorrow and provide a solution

[alexanderM91]

Hey @bomensal,
do you have a chance to verify the fix and test it on your local environment?
Thank you.

[alexanderM91]

Hey, an issue isn't reproducible after the Tideways extension update.
Close an issue. Let's reopen it in case of relevance.

Note: Please use the latest version of the base image + docker/sdk.

Thank you.