Cannot connect to MySQL image externally; Dockerize wait timeout occurs

support
mysql
config
#1

I’m unable to connect to a mysql database on another docker container. telnet 127.0.0.1 3306 gives “Unable to connect to remote host: Connection refused”. I was able to connect before I had to update from buildpack-deps:trusty to buildpack-deps:xenial due to ondrej/php PHP packages for Trusty getting removed (https://www.patreon.com/posts/ubuntu-14-04-php-22093917). Any idea what’s going on? I have used a dockerize wait to avoid race condition as many have suggested, but the console output from mysql image shows that it is running and ready for connections well before.

My circle.yml:

version: 2

#
jobs:
  build:
    environment:
      LC_ALL: C.UTF-8
      LANG: C.UTF-8
      CIRCLE_ARTIFACTS: ./tests
      CIRCLE_ENV: test
      APP_ENV: testing
    docker:
      - image: buildpack-deps:xenial
      - image: circleci/mysql:5.7.23
        environment:
          MYSQL_ALLOW_EMPTY_PASSWORD: yes
          MYSQL_ROOT_PASSWORD: ''
          MYSQL_ROOT_HOST: "%"
          MYSQL_USER: root
          MYSQL_DATABASE: app

    steps:
      - checkout

      - run:
          name: Run apt-get update
          command: apt-get update

      - run:
          name: Install sudo
          command: apt-get install -y sudo

      - run:
          name: Install add-apt-repository dependencies
          command: apt-get install -y software-properties-common

      - run:
          name: Add ondrej/php PPA
          command: add-apt-repository -y ppa:ondrej/php

      - run:
          name: Run apt-get update
          command: apt-get update

      - run:
          name: Install app dependencies
          command: apt-get install -y curl git libmagickwand-dev libmagickcore-dev php7.1 php7.1-common php7.1-curl php7.1-mbstring php7.1-xml php7.1-mysql php7.1-zip php7.1-gd php-imagick xvfb unzip nano

      - run:
          name: Install composer
          command: curl -sS https://getcomposer.org/installer | php -- --install-dir=/usr/local/bin --filename=composer

      - restore_cache:
          key: dependency-cache-{{ checksum "composer.json" }}

      - save_cache:
          key: dependency-cache-{{ checksum "composer.json" }}
          paths:
            - vendor

      - run:
          name: Run composer install
          command: composer install

      - run:
          name: Run composer dumpautoload
          command: composer dumpautoload

      - run:
          name: Install nvm
          command: |
            curl -o- https://raw.githubusercontent.com/creationix/nvm/v0.33.11/install.sh | bash
            echo 'export NVM_DIR=$HOME/.nvm' >> $BASH_ENV
            echo 'source $NVM_DIR/nvm.sh' >> $BASH_ENV

      - run:
          name: Set node version
          command: nvm install 8.12.0

      - restore_cache:
          key: dependency-cache-{{ checksum "package.json" }}

      - run:
          name: Run npm install
          command: npm install

      - save_cache:
          key: dependency-cache-{{ checksum "package.json" }}
          paths:
            - node_modules
     
       - run:
          name: install dockerize
          command: wget https://github.com/jwilder/dockerize/releases/download/$DOCKERIZE_VERSION/dockerize-linux-amd64-$DOCKERIZE_VERSION.tar.gz && sudo tar -C /usr/local/bin -xzvf dockerize-linux-amd64-$DOCKERIZE_VERSION.tar.gz && rm dockerize-linux-amd64-$DOCKERIZE_VERSION.tar.gz
          environment:
            DOCKERIZE_VERSION: v0.3.0

      - run:
          name: Wait for db to respond back before running migrations
          command: dockerize -wait tcp://localhost:3306 -timeout 1m  # Times out :frowning: 

Console output from container circleci/mysql:5.7.23:

Initializing database
2019-05-18T01:15:05.893285Z 0 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use --explicit_defaults_for_timestamp server option (see documentation for more details).
2019-05-18T01:15:06.269444Z 0 [Warning] InnoDB: New log files created, LSN=45790
2019-05-18T01:15:06.331190Z 0 [Warning] InnoDB: Creating foreign key constraint system tables.
2019-05-18T01:15:06.383664Z 0 [Warning] No existing UUID has been found, so we assume that this is the first time that this server has been started. Generating a new UUID: 5f1c5391-790a-11e9-ae7a-0242ac1d0004.
2019-05-18T01:15:06.383945Z 0 [Warning] Gtid table is not ready to be used. Table 'mysql.gtid_executed' cannot be opened.
2019-05-18T01:15:06.384342Z 1 [Warning] root@localhost is created with an empty password ! Please consider switching off the --initialize-insecure option.
2019-05-18T01:15:06.547921Z 1 [Warning] 'user' entry 'root@localhost' ignored in --skip-name-resolve mode.
2019-05-18T01:15:06.547945Z 1 [Warning] 'user' entry 'mysql.session@localhost' ignored in --skip-name-resolve mode.
2019-05-18T01:15:06.547953Z 1 [Warning] 'user' entry 'mysql.sys@localhost' ignored in --skip-name-resolve mode.
2019-05-18T01:15:06.547963Z 1 [Warning] 'db' entry 'performance_schema mysql.session@localhost' ignored in --skip-name-resolve mode.
2019-05-18T01:15:06.547967Z 1 [Warning] 'db' entry 'sys mysql.sys@localhost' ignored in --skip-name-resolve mode.
2019-05-18T01:15:06.547976Z 1 [Warning] 'proxies_priv' entry '@ root@localhost' ignored in --skip-name-resolve mode.
2019-05-18T01:15:06.547993Z 1 [Warning] 'tables_priv' entry 'user mysql.session@localhost' ignored in --skip-name-resolve mode.
2019-05-18T01:15:06.547999Z 1 [Warning] 'tables_priv' entry 'sys_config mysql.sys@localhost' ignored in --skip-name-resolve mode.
Database initialized
Initializing certificates
Generating a 2048 bit RSA private key
................................+++
.....+++
unable to write 'random state'
writing new private key to 'ca-key.pem'
-----
Generating a 2048 bit RSA private key
...+++
................................................................+++
unable to write 'random state'
writing new private key to 'server-key.pem'
-----
Generating a 2048 bit RSA private key
.........................................................+++
........+++
unable to write 'random state'
writing new private key to 'client-key.pem'
-----
Certificates initialized
MySQL init process in progress...
2019-05-18T01:15:08.323724Z 0 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use --explicit_defaults_for_timestamp server option (see documentation for more details).
2019-05-18T01:15:08.325747Z 0 [Note] mysqld (mysqld 5.7.23) starting as process 139 ...
2019-05-18T01:15:08.329284Z 0 [Note] InnoDB: PUNCH HOLE support available
2019-05-18T01:15:08.329312Z 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2019-05-18T01:15:08.329319Z 0 [Note] InnoDB: Uses event mutexes
2019-05-18T01:15:08.329325Z 0 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier
2019-05-18T01:15:08.329330Z 0 [Note] InnoDB: Compressed tables use zlib 1.2.3
2019-05-18T01:15:08.329615Z 0 [Note] InnoDB: Number of pools: 1
2019-05-18T01:15:08.329746Z 0 [Note] InnoDB: Using CPU crc32 instructions
2019-05-18T01:15:08.331548Z 0 [Note] InnoDB: Initializing buffer pool, total size = 128M, instances = 1, chunk size = 128M
2019-05-18T01:15:08.341699Z 0 [Note] InnoDB: Completed initialization of buffer pool
2019-05-18T01:15:08.344592Z 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
2019-05-18T01:15:08.356638Z 0 [Note] InnoDB: Highest supported file format is Barracuda.
2019-05-18T01:15:08.363511Z 0 [Note] InnoDB: Creating shared tablespace for temporary tables
2019-05-18T01:15:08.363586Z 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
2019-05-18T01:15:08.390180Z 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
2019-05-18T01:15:08.391038Z 0 [Note] InnoDB: 96 redo rollback segment(s) found. 96 redo rollback segment(s) are active.
2019-05-18T01:15:08.391054Z 0 [Note] InnoDB: 32 non-redo rollback segment(s) are active.
2019-05-18T01:15:08.391506Z 0 [Note] InnoDB: 5.7.23 started; log sequence number 2588944
2019-05-18T01:15:08.391629Z 0 [Note] InnoDB: Loading buffer pool(s) from /var/lib/mysql/ib_buffer_pool
2019-05-18T01:15:08.391824Z 0 [Note] Plugin 'FEDERATED' is disabled.
2019-05-18T01:15:08.393292Z 0 [Note] InnoDB: Buffer pool(s) load completed at 190518  1:15:08
2019-05-18T01:15:08.398249Z 0 [Note] Found ca.pem, server-cert.pem and server-key.pem in data directory. Trying to enable SSL support using them.
2019-05-18T01:15:08.398506Z 0 [Warning] CA certificate ca.pem is self signed.
2019-05-18T01:15:08.408588Z 0 [Warning] Insecure configuration for --pid-file: Location '/var/run/mysqld' in the path is accessible to all OS users. Consider choosing a different directory.
2019-05-18T01:15:08.409879Z 0 [Warning] 'user' entry 'root@localhost' ignored in --skip-name-resolve mode.
2019-05-18T01:15:08.409913Z 0 [Warning] 'user' entry 'mysql.session@localhost' ignored in --skip-name-resolve mode.
2019-05-18T01:15:08.409924Z 0 [Warning] 'user' entry 'mysql.sys@localhost' ignored in --skip-name-resolve mode.
2019-05-18T01:15:08.409940Z 0 [Warning] 'db' entry 'performance_schema mysql.session@localhost' ignored in --skip-name-resolve mode.
2019-05-18T01:15:08.409946Z 0 [Warning] 'db' entry 'sys mysql.sys@localhost' ignored in --skip-name-resolve mode.
2019-05-18T01:15:08.409967Z 0 [Warning] 'proxies_priv' entry '@ root@localhost' ignored in --skip-name-resolve mode.
2019-05-18T01:15:08.411327Z 0 [Warning] 'tables_priv' entry 'user mysql.session@localhost' ignored in --skip-name-resolve mode.
2019-05-18T01:15:08.411349Z 0 [Warning] 'tables_priv' entry 'sys_config mysql.sys@localhost' ignored in --skip-name-resolve mode.
2019-05-18T01:15:08.419947Z 0 [Note] Event Scheduler: Loaded 0 events
2019-05-18T01:15:08.420105Z 0 [Note] mysqld: ready for connections.
Version: '5.7.23'  socket: '/var/run/mysqld/mysqld.sock'  port: 0  MySQL Community Server (GPL)
Warning: Unable to load '/usr/share/zoneinfo/iso3166.tab' as time zone. Skipping it.
Warning: Unable to load '/usr/share/zoneinfo/leap-seconds.list' as time zone. Skipping it.
Warning: Unable to load '/usr/share/zoneinfo/zone.tab' as time zone. Skipping it.
Warning: Unable to load '/usr/share/zoneinfo/zone1970.tab' as time zone. Skipping it.
2019-05-18T01:15:10.491214Z 4 [Warning] 'user' entry 'root@localhost' ignored in --skip-name-resolve mode.
2019-05-18T01:15:10.491236Z 4 [Warning] 'user' entry 'mysql.session@localhost' ignored in --skip-name-resolve mode.
2019-05-18T01:15:10.491242Z 4 [Warning] 'user' entry 'mysql.sys@localhost' ignored in --skip-name-resolve mode.
2019-05-18T01:15:10.491256Z 4 [Warning] 'db' entry 'performance_schema mysql.session@localhost' ignored in --skip-name-resolve mode.
2019-05-18T01:15:10.491262Z 4 [Warning] 'db' entry 'sys mysql.sys@localhost' ignored in --skip-name-resolve mode.
2019-05-18T01:15:10.491271Z 4 [Warning] 'proxies_priv' entry '@ root@localhost' ignored in --skip-name-resolve mode.
2019-05-18T01:15:10.491296Z 4 [Warning] 'tables_priv' entry 'user mysql.session@localhost' ignored in --skip-name-resolve mode.
2019-05-18T01:15:10.491303Z 4 [Warning] 'tables_priv' entry 'sys_config mysql.sys@localhost' ignored in --skip-name-resolve mode.

2019-05-18T01:15:10.500873Z 0 [Note] Giving 0 client threads a chance to die gracefully
2019-05-18T01:15:10.500909Z 0 [Note] Shutting down slave threads
2019-05-18T01:15:10.500914Z 0 [Note] Forcefully disconnecting 0 remaining clients
2019-05-18T01:15:10.500920Z 0 [Note] Event Scheduler: Purging the queue. 0 events
2019-05-18T01:15:10.500965Z 0 [Note] Binlog end
2019-05-18T01:15:10.501582Z 0 [Note] Shutting down plugin 'ngram'
2019-05-18T01:15:10.501598Z 0 [Note] Shutting down plugin 'partition'
2019-05-18T01:15:10.501602Z 0 [Note] Shutting down plugin 'BLACKHOLE'
2019-05-18T01:15:10.501605Z 0 [Note] Shutting down plugin 'ARCHIVE'
2019-05-18T01:15:10.501607Z 0 [Note] Shutting down plugin 'PERFORMANCE_SCHEMA'
2019-05-18T01:15:10.501645Z 0 [Note] Shutting down plugin 'MRG_MYISAM'
2019-05-18T01:15:10.501648Z 0 [Note] Shutting down plugin 'MyISAM'
2019-05-18T01:15:10.501655Z 0 [Note] Shutting down plugin 'INNODB_SYS_VIRTUAL'
2019-05-18T01:15:10.501658Z 0 [Note] Shutting down plugin 'INNODB_SYS_DATAFILES'
2019-05-18T01:15:10.501661Z 0 [Note] Shutting down plugin 'INNODB_SYS_TABLESPACES'
2019-05-18T01:15:10.501664Z 0 [Note] Shutting down plugin 'INNODB_SYS_FOREIGN_COLS'
2019-05-18T01:15:10.501666Z 0 [Note] Shutting down plugin 'INNODB_SYS_FOREIGN'
2019-05-18T01:15:10.501668Z 0 [Note] Shutting down plugin 'INNODB_SYS_FIELDS'
2019-05-18T01:15:10.501671Z 0 [Note] Shutting down plugin 'INNODB_SYS_COLUMNS'
2019-05-18T01:15:10.501674Z 0 [Note] Shutting down plugin 'INNODB_SYS_INDEXES'
2019-05-18T01:15:10.501676Z 0 [Note] Shutting down plugin 'INNODB_SYS_TABLESTATS'
2019-05-18T01:15:10.501679Z 0 [Note] Shutting down plugin 'INNODB_SYS_TABLES'
2019-05-18T01:15:10.501682Z 0 [Note] Shutting down plugin 'INNODB_FT_INDEX_TABLE'
2019-05-18T01:15:10.501684Z 0 [Note] Shutting down plugin 'INNODB_FT_INDEX_CACHE'
2019-05-18T01:15:10.501687Z 0 [Note] Shutting down plugin 'INNODB_FT_CONFIG'
2019-05-18T01:15:10.501689Z 0 [Note] Shutting down plugin 'INNODB_FT_BEING_DELETED'
2019-05-18T01:15:10.501692Z 0 [Note] Shutting down plugin 'INNODB_FT_DELETED'
2019-05-18T01:15:10.501695Z 0 [Note] Shutting down plugin 'INNODB_FT_DEFAULT_STOPWORD'
2019-05-18T01:15:10.501697Z 0 [Note] Shutting down plugin 'INNODB_METRICS'
2019-05-18T01:15:10.501700Z 0 [Note] Shutting down plugin 'INNODB_TEMP_TABLE_INFO'
2019-05-18T01:15:10.501702Z 0 [Note] Shutting down plugin 'INNODB_BUFFER_POOL_STATS'
2019-05-18T01:15:10.501705Z 0 [Note] Shutting down plugin 'INNODB_BUFFER_PAGE_LRU'
2019-05-18T01:15:10.501708Z 0 [Note] Shutting down plugin 'INNODB_BUFFER_PAGE'
2019-05-18T01:15:10.501710Z 0 [Note] Shutting down plugin 'INNODB_CMP_PER_INDEX_RESET'
2019-05-18T01:15:10.501713Z 0 [Note] Shutting down plugin 'INNODB_CMP_PER_INDEX'
2019-05-18T01:15:10.501716Z 0 [Note] Shutting down plugin 'INNODB_CMPMEM_RESET'
2019-05-18T01:15:10.501718Z 0 [Note] Shutting down plugin 'INNODB_CMPMEM'
2019-05-18T01:15:10.501721Z 0 [Note] Shutting down plugin 'INNODB_CMP_RESET'
2019-05-18T01:15:10.501723Z 0 [Note] Shutting down plugin 'INNODB_CMP'
2019-05-18T01:15:10.501726Z 0 [Note] Shutting down plugin 'INNODB_LOCK_WAITS'
2019-05-18T01:15:10.501728Z 0 [Note] Shutting down plugin 'INNODB_LOCKS'
2019-05-18T01:15:10.501737Z 0 [Note] Shutting down plugin 'INNODB_TRX'
2019-05-18T01:15:10.501740Z 0 [Note] Shutting down plugin 'InnoDB'
2019-05-18T01:15:10.501794Z 0 [Note] InnoDB: FTS optimize thread exiting.
2019-05-18T01:15:10.501913Z 0 [Note] InnoDB: Starting shutdown...
2019-05-18T01:15:10.602115Z 0 [Note] InnoDB: Dumping buffer pool(s) to /var/lib/mysql/ib_buffer_pool
2019-05-18T01:15:10.602346Z 0 [Note] InnoDB: Buffer pool(s) dump completed at 190518  1:15:10
2019-05-18T01:15:11.909884Z 0 [Note] InnoDB: Shutdown completed; log sequence number 12359060
2019-05-18T01:15:11.912242Z 0 [Note] InnoDB: Removed temporary tablespace data file: "ibtmp1"
2019-05-18T01:15:11.912264Z 0 [Note] Shutting down plugin 'MEMORY'
2019-05-18T01:15:11.912271Z 0 [Note] Shutting down plugin 'CSV'
2019-05-18T01:15:11.912277Z 0 [Note] Shutting down plugin 'sha256_password'
2019-05-18T01:15:11.912281Z 0 [Note] Shutting down plugin 'mysql_native_password'
2019-05-18T01:15:11.912409Z 0 [Note] Shutting down plugin 'binlog'
2019-05-18T01:15:11.912809Z 0 [Note] mysqld: Shutdown complete


MySQL init process done. Ready for start up.

2019-05-18T01:15:12.133159Z 0 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use --explicit_defaults_for_timestamp server option (see documentation for more details).
2019-05-18T01:15:12.135216Z 0 [Note] mysqld (mysqld 5.7.23) starting as process 7 ...
2019-05-18T01:15:12.138550Z 0 [Note] InnoDB: PUNCH HOLE support available
2019-05-18T01:15:12.138578Z 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2019-05-18T01:15:12.138587Z 0 [Note] InnoDB: Uses event mutexes
2019-05-18T01:15:12.138593Z 0 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier
2019-05-18T01:15:12.138598Z 0 [Note] InnoDB: Compressed tables use zlib 1.2.3
2019-05-18T01:15:12.138892Z 0 [Note] InnoDB: Number of pools: 1
2019-05-18T01:15:12.139023Z 0 [Note] InnoDB: Using CPU crc32 instructions
2019-05-18T01:15:12.140855Z 0 [Note] InnoDB: Initializing buffer pool, total size = 128M, instances = 1, chunk size = 128M
2019-05-18T01:15:12.151198Z 0 [Note] InnoDB: Completed initialization of buffer pool
2019-05-18T01:15:12.153926Z 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
2019-05-18T01:15:12.165887Z 0 [Note] InnoDB: Highest supported file format is Barracuda.
2019-05-18T01:15:12.172723Z 0 [Note] InnoDB: Creating shared tablespace for temporary tables
2019-05-18T01:15:12.172793Z 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
2019-05-18T01:15:12.195437Z 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
2019-05-18T01:15:12.196184Z 0 [Note] InnoDB: 96 redo rollback segment(s) found. 96 redo rollback segment(s) are active.
2019-05-18T01:15:12.196198Z 0 [Note] InnoDB: 32 non-redo rollback segment(s) are active.
2019-05-18T01:15:12.196480Z 0 [Note] InnoDB: Waiting for purge to start
2019-05-18T01:15:12.246652Z 0 [Note] InnoDB: 5.7.23 started; log sequence number 12359060
2019-05-18T01:15:12.246872Z 0 [Note] InnoDB: Loading buffer pool(s) from /var/lib/mysql/ib_buffer_pool
2019-05-18T01:15:12.247079Z 0 [Note] Plugin 'FEDERATED' is disabled.
2019-05-18T01:15:12.250755Z 0 [Note] InnoDB: Buffer pool(s) load completed at 190518  1:15:12
2019-05-18T01:15:12.253351Z 0 [Note] Found ca.pem, server-cert.pem and server-key.pem in data directory. Trying to enable SSL support using them.
2019-05-18T01:15:12.253539Z 0 [Warning] CA certificate ca.pem is self signed.
2019-05-18T01:15:12.255842Z 0 [Note] Server hostname (bind-address): '*'; port: 3306
2019-05-18T01:15:12.255891Z 0 [Note] IPv6 is available.
2019-05-18T01:15:12.255899Z 0 [Note]   - '::' resolves to '::';
2019-05-18T01:15:12.255923Z 0 [Note] Server socket created on IP: '::'.
2019-05-18T01:15:12.256271Z 0 [Warning] Insecure configuration for --pid-file: Location '/var/run/mysqld' in the path is accessible to all OS users. Consider choosing a different directory.
2019-05-18T01:15:12.257460Z 0 [Warning] 'user' entry 'root@localhost' ignored in --skip-name-resolve mode.
2019-05-18T01:15:12.257498Z 0 [Warning] 'user' entry 'mysql.session@localhost' ignored in --skip-name-resolve mode.
2019-05-18T01:15:12.257509Z 0 [Warning] 'user' entry 'mysql.sys@localhost' ignored in --skip-name-resolve mode.
2019-05-18T01:15:12.257523Z 0 [Warning] 'db' entry 'performance_schema mysql.session@localhost' ignored in --skip-name-resolve mode.
2019-05-18T01:15:12.257528Z 0 [Warning] 'db' entry 'sys mysql.sys@localhost' ignored in --skip-name-resolve mode.
2019-05-18T01:15:12.257537Z 0 [Warning] 'proxies_priv' entry '@ root@localhost' ignored in --skip-name-resolve mode.
2019-05-18T01:15:12.259077Z 0 [Warning] 'tables_priv' entry 'user mysql.session@localhost' ignored in --skip-name-resolve mode.
2019-05-18T01:15:12.259091Z 0 [Warning] 'tables_priv' entry 'sys_config mysql.sys@localhost' ignored in --skip-name-resolve mode.
2019-05-18T01:15:12.262980Z 0 [Note] Event Scheduler: Loaded 0 events
2019-05-18T01:15:12.263132Z 0 [Note] mysqld: ready for connections.
Version: '5.7.23'  socket: '/var/run/mysqld/mysqld.sock'  port: 3306  MySQL Community Server (GPL)
#2

It seems to me that the MySQL server you have shuts down and then restarts. That might be something to look into.

That said, I vaguely remember having problems with putting MySQL in a secondary container. If you are not stuck for memory, try installing it in your primary build container instead. I did that successfully here.

#3

Upgrading to circleci/mysql:5.7.26 works properly, believe it or not… I guess I’ll stick with that until I’m forced to do another upgrade somewhere else. Thanks

1 Like