docksal: CLI healthcheck fails on project create

Description

(Possibly related to #311 but this is on Ubuntu 17.04) My first time trying docksal, no problems with installation, but fails on project creation due to (bogus?) healthcheck failure.

Steps to reproduce the issue:

$  mkdir test
$  cd test
$  fin -v
WARNING: No swap limit support
1.22.0
$  docker -v
Docker version 17.06.0-ce, build 02c1d87
$  docker ps
CONTAINER ID        IMAGE                     COMMAND                  CREATED              STATUS              PORTS                                                    NAMES
8b7c131f269d        docksal/ssh-agent:1.0     "/run.sh ssh-agent"      About a minute ago   Up About a minute                                                            docksal-ssh-agent
22c647ea9559        docksal/dns:1.0           "/opt/entrypoint.s..."   About a minute ago   Up About a minute   192.168.64.100:53->53/udp                                docksal-dns
6c97d04f0e51        docksal/vhost-proxy:1.1   "docker-entrypoint..."   About a minute ago   Up About a minute   192.168.64.100:80->80/tcp, 192.168.64.100:443->443/tcp   docksal-vhost-proxy
~/temp/sal_sbl/test  $  fin project create
WARNING: No swap limit support
Please enter the name of your project (all one word, no spaces or slashes): mytest

What would you like to install?
[1] Drupal 7
[2] Drupal 8
[3] Wordpress
[4] Magento
[5] Static HTML site

: 1

Your site will be created at /home/marc/temp/sal_sbl/test/mytest
Your site will run Drupal 7
The URL of your site will be http://mytest.docksal

Do you wish to proceed? [y/n]: y
Cloning repository...
Cloning into 'mytest'...
remote: Counting objects: 2501, done.
remote: Compressing objects: 100% (7/7), done.
remote: Total 2501 (delta 2), reused 8 (delta 2), pack-reused 2492
Receiving objects: 100% (2501/2501), 3.87 MiB | 4.42 MiB/s, done.
Resolving deltas: 100% (1023/1023), done.
WARNING: No swap limit support
Step 1  Initializing local project configuration...
Making site directory writable...
Copying /home/marc/temp/sal_sbl/test/mytest/docroot/sites/default/settings.local.php...
Step 2  Recreating services...
WARNING: No swap limit support
Removing containers...
Removing network mytest_default
WARNING: Network mytest_default not found.
Removing volume mytest_project_root
WARNING: Volume mytest_project_root not found.
Volume docksal_ssh_agent is external, skipping
Enter passphrase for /root/.ssh/id_rsa: 
Identity added: id_rsa (id_rsa)
Starting services...
Creating network "mytest_default" with the default driver
Creating volume "mytest_project_root" with local driver
Creating mytest_db_1 ... 
Creating mytest_cli_1 ... 
Creating mytest_db_1
Creating mytest_cli_1 ... done
Creating mytest_web_1 ... 
Creating mytest_web_1 ... done
Waiting for mytest_cli_1 to become ready...
Waiting for mytest_cli_1 to become ready...
Waiting for mytest_cli_1 to become ready...
Waiting for mytest_cli_1 to become ready...
Waiting for mytest_cli_1 to become ready...
Waiting for mytest_cli_1 to become ready...
Waiting for mytest_cli_1 to become ready...
ERROR:  mytest_cli_1 heathcheck failed
        Container did not enter a healthy state within the expected amount of time.
        Try fin restart
~/temp/sal_sbl/test  $  docker ps
CONTAINER ID        IMAGE                       COMMAND                  CREATED             STATUS                    PORTS                                                    NAMES
c1497ba51a9f        docksal/web:2.0-apache2.4   "httpd-foreground"       47 seconds ago      Up 46 seconds             80/tcp, 443/tcp                                          mytest_web_1
8f5b16cdb62b        docksal/cli:1.3-php5        "/opt/startup.sh s..."   48 seconds ago      Up 47 seconds (healthy)   22/tcp, 9000/tcp                                         mytest_cli_1
9b9ee92b38b6        docksal/db:1.1-mysql-5.6    "/entrypoint.sh my..."   48 seconds ago      Up 48 seconds             0.0.0.0:32773->3306/tcp                                  mytest_db_1
8b7c131f269d        docksal/ssh-agent:1.0       "/run.sh ssh-agent"      3 minutes ago       Up 3 minutes                                                                       docksal-ssh-agent
22c647ea9559        docksal/dns:1.0             "/opt/entrypoint.s..."   3 minutes ago       Up 3 minutes              192.168.64.100:53->53/udp                                docksal-dns
6c97d04f0e51        docksal/vhost-proxy:1.1     "docker-entrypoint..."   3 minutes ago       Up 3 minutes              192.168.64.100:80->80/tcp, 192.168.64.100:443->443/tcp   docksal-vhost-proxy
~/temp/sal_sbl/test  $  docker exec -it mytest_cli_1 /bin/bash
root@cli:/var/www# /opt/healthcheck.sh ; echo $?
0
root@cli:/var/www# exit

Describe the results you received:

New docksal project fails to create

Describe the results you expected:

Expected behavior…

Output of fin config:

fin config output

$  fin config
WARNING: No swap limit support
---------------------
COMPOSE_PROJECT_NAME_SAFE: salsbl
COMPOSE_FILE:
/home/marc/.docksal/stacks/volumes-bind.yml
/home/marc/temp/sal_sbl/.docksal/docksal.yml
ENV_FILE:
/home/marc/temp/sal_sbl/.docksal/docksal.env

PROJECT_ROOT: /home/marc/temp/sal_sbl
DOCROOT: docroot
VIRTUAL_HOST: salsbl.docksal
VIRTUAL_HOST_ALIASES: *.salsbl.docksal
IP: 192.168.64.100
MYSQL:

Docker Compose configuration
---------------------
services:
  cli:
    dns:
    - 192.168.64.100
    - 8.8.8.8
    environment:
      HOST_GID: '1000'
      HOST_UID: '1000'
      XDEBUG_ENABLED: '0'
    hostname: cli
    image: docksal/cli:1.3-php7
    volumes:
    - docksal_ssh_agent:/.ssh-agent:ro
    - project_root:/var/www:rw,nocopy
  db:
    dns:
    - 192.168.64.100
    - 8.8.8.8
    environment:
      MYSQL_DATABASE: default
      MYSQL_PASSWORD: user
      MYSQL_ROOT_PASSWORD: root
      MYSQL_USER: user
    hostname: db
    image: docksal/db:1.1-mysql-5.6
    ports:
    - 3306/tcp
  web:
    depends_on:
      cli:
        condition: service_started
    dns:
    - 192.168.64.100
    - 8.8.8.8
    environment:
      APACHE_BASIC_AUTH_PASS: null
      APACHE_BASIC_AUTH_USER: null
      APACHE_DOCUMENTROOT: /var/www/docroot
    hostname: web
    image: docksal/web:2.0-apache2.4
    labels:
      io.docksal.project-root: /home/marc/temp/sal_sbl
      io.docksal.virtual-host: salsbl.docksal,*.salsbl.docksal
    volumes:
    - project_root:/var/www:ro,nocopy
version: '2.1'
volumes:
  docksal_ssh_agent:
    external: true
  project_root:
    driver: local
    driver_opts:
      device: /home/marc/temp/sal_sbl
      o: bind
      type: none

---------------------

Output of fin sysinfo:

fin sysinfo output

$  fin sysinfo
WARNING: No swap limit support
███  OS & BASICS
Linux 9360 4.12.6-041206-generic #201708111232 SMP Fri Aug 11 16:34:18 UTC 2017 x86_64 x86_64 x86_64 GNU/Linux
Ubuntu 17.04
fin version: 1.22.0
Mode:  Native / Docker for Mac/Windows
███  DOCKER
DOCKER_HOST:	

Docker: Client:
Version:      17.06.0-ce
API version:  1.30
Go version:   go1.8.3
Git commit:   02c1d87
Built:        Fri Jun 23 21:23:31 2017
OS/Arch:      linux/amd64

Server:
Version:      17.06.0-ce
API version:  1.30 (minimum version 1.12)
Go version:   go1.8.3
Git commit:   02c1d87
Built:        Fri Jun 23 21:19:04 2017
OS/Arch:      linux/amd64
Experimental: false
███  DOCKER COMPOSE
Docker Compose: docker-compose version 1.14.0, build c7bdf9e
docker-py version: 2.3.0
CPython version: 2.7.13
OpenSSL version: OpenSSL 1.0.1t  3 May 2016
WARNING: No swap limit support
███  DOCKER: IMAGES
REPOSITORY                    TAG                 IMAGE ID            CREATED             SIZE
docksal/web                   2.0-apache2.4       7f75db9a6aa7        2 weeks ago         87.5MB
docksal/vhost-proxy           1.1                 898fb21e7f2d        2 weeks ago         158MB
docksal/cli                   1.3-php7            1442dc481915        3 weeks ago         752MB
docksal/cli                   1.3-php5            77f9a2e141fa        3 weeks ago         808MB
docksal/db                    1.1-mysql-5.6       6feb79af9597        4 weeks ago         298MB
docksal/dns                   1.0                 20c7a535479d        7 months ago        61.6MB
docksal/ssh-agent             1.0                 148220cc033d        7 months ago        12.2MB
<<<RETRACTED>>>
███  DOCKER: CONTAINERS
CONTAINER ID        IMAGE                       COMMAND                  CREATED             STATUS                   PORTS                                                    NAMES
c1497ba51a9f        docksal/web:2.0-apache2.4   "httpd-foreground"       8 minutes ago       Up 8 minutes             80/tcp, 443/tcp                                          mytest_web_1
8f5b16cdb62b        docksal/cli:1.3-php5        "/opt/startup.sh s..."   8 minutes ago       Up 8 minutes (healthy)   22/tcp, 9000/tcp                                         mytest_cli_1
9b9ee92b38b6        docksal/db:1.1-mysql-5.6    "/entrypoint.sh my..."   8 minutes ago       Up 8 minutes             0.0.0.0:32773->3306/tcp                                  mytest_db_1
8b7c131f269d        docksal/ssh-agent:1.0       "/run.sh ssh-agent"      10 minutes ago      Up 10 minutes                                                                     docksal-ssh-agent
22c647ea9559        docksal/dns:1.0             "/opt/entrypoint.s..."   10 minutes ago      Up 10 minutes            192.168.64.100:53->53/udp                                docksal-dns
6c97d04f0e51        docksal/vhost-proxy:1.1     "docker-entrypoint..."   11 minutes ago      Up 10 minutes            192.168.64.100:80->80/tcp, 192.168.64.100:443->443/tcp   docksal-vhost-proxy
███  VIRTUALBOX
5.1.23r116680
███  NETWORK INTERFACES

About this issue

Original URL
State: closed
Created 7 years ago
Comments: 27 (18 by maintainers)

Commits related to this issue

Added /home/docker volume in cli. Fixes #325 This addresses slow fs performance issues with the overlay2 storage driver. Write-heavy directories should be in volumes. See https://github.com/docksal/d... — committed to docksal/docksal by deleted user 7 years ago
1.55.5 Added /home/docker volume in run-cli This speeds up run-cli startup time tremendously. Related to #325 and 0d522b1170d2d3dd38a0547453728455729e6346 — committed to docksal/docksal by deleted user 6 years ago

Most upvoted comments

Interestingly, the time for the chown once the container is up is minimal:

$  fin docker run -it --rm docksal/cli:1.3-php5 bash
WARNING: No swap limit support
WARNING: No swap limit support
docker@ab40c4737c7d:/var/www$ time sudo chown 1000:1000 -R /home/docker

real	0m0.139s
user	0m0.018s
sys	0m0.113s

However, it’s still taking over 35 seconds to actually reach the bash prompt in order to run that time command.

This led me to test a bit further, modifying startup.sh to add time to the chown command:

$  fin docker run -it --entrypoint /bin/bash clitest -x /opt/startup.sh supervisord
WARNING: No swap limit support
WARNING: No swap limit support
+ HOME_DIR=/home/docker
+ DEBUG=0
+ [[ supervisord == \s\u\p\e\r\v\i\s\o\r\d ]]
+ DEBUG=1
+ [[ '' != '' ]]
+ [[ 0 != '' ]]
+ [[ 0 != \0 ]]
+ echo-debug 'Resetting permissions on /home/docker and /var/www...'
+ [[ 1 != 0 ]]
+ echo 'Resetting permissions on /home/docker and /var/www...'
Resetting permissions on /home/docker and /var/www...
+ chown : -R /home/docker

real	0m37.844s
user	0m0.052s
sys	0m3.053s
+ chown : /var/www
+ echo-debug 'Preliminary initialization completed'
+ [[ 1 != 0 ]]
+ echo 'Preliminary initialization completed'
Preliminary initialization completed
+ touch /var/run/cli
+ echo-debug 'Executing the requested command...'
+ [[ 1 != 0 ]]
+ echo 'Executing the requested command...'
Executing the requested command...
+ [[ supervisord == \s\u\p\e\r\v\i\s\o\r\d ]]
+ gosu root supervisord -c /etc/supervisor/conf.d/supervisord.conf
2017-08-23 10:29:58,222 CRIT Supervisor running as root (no user in config file)
2017-08-23 10:29:58,233 INFO RPC interface 'supervisor' initialized
2017-08-23 10:29:58,233 INFO supervisord started with pid 51
2017-08-23 10:29:59,235 INFO spawned: 'sshd' with pid 58
2017-08-23 10:29:59,237 INFO spawned: 'php-fpm' with pid 59
2017-08-23 10:29:59,371 DEBG fd 10 closed, stopped monitoring <POutputDispatcher at 139819236666256 for <Subprocess at 139819236895632 with name php-fpm in state STARTING> (stdout)>
2017-08-23 10:29:59,380 DEBG fd 15 closed, stopped monitoring <POutputDispatcher at 139819236666544 for <Subproc

So, 37 seconds when it does it the first time. Also, that chown looks a bit wrong to me, there’s no UID or GID being passed. I hard-coded it to 1000:1000 and it made no difference, still over 35 seconds.

mf-lit on Aug 23, 2017