search

exasol / spark-connector

A connector for Apache Spark to access Exasol
Apache License 2.0
12 stars 7 forks source link

ExasolDockerContainer is not configured to respect startup timeout #51

Closed 3cham closed 5 years ago

3cham commented 5 years ago

Generally exasol/docker-db requires some time to start up completely. This is already targeted in ExasolDockerContainer.configure() method. However this configuration isn't considered by JdbcDatabaseContainer (extended by ExasolDockerContainer) class. Source code from JdbcDatabaseContainer class:

    @Override
    protected void waitUntilContainerStarted() {
        // Repeatedly try and open a connection to the DB and execute a test query
        logger().info("Waiting for database connection to become available at {} using query \'{}\'", getJdbcUrl(), getTestQueryString());
        Unreliables.retryUntilSuccess(getStartupTimeoutSeconds(), TimeUnit.SECONDS, () -> {
            if (!isRunning()) {
                throw new ContainerLaunchException("Container failed to start");
            }
            try (Connection connection = createConnection("")) {
                boolean success = connection.createStatement().execute(JdbcDatabaseContainer.this.getTestQueryString());
                if (success) {
                    logger().info("Obtained a connection to container ({})", JdbcDatabaseContainer.this.getJdbcUrl());
                    return null;
                } else {
                    throw new SQLException("Failed to execute test query");
                }
            }
        });
    }

Per default startupTimeoutSeconds = 120. This causes integration tests will fail if the db could not start up within 2 minutes.

Solution: startupTimeoutSeconds could be set by calling withStartupTimeoutSeconds instead of withStartupTimeout in the configure method

3cham commented 5 years ago

On the other side, I am having trouble with integration tests on Mac OS, some how the test container could not speak with the exasok container using the test query. I changed to use the latest images 6.1.4 but it did not help. Do you have any idea @morazow ?

morazow commented 5 years ago

Hey @3cham, No idea. Do you have an error logs? I also occasionally see startup errors, but I cannot reproduce on next runs.

3cham commented 5 years ago

Here you can see that the exasol container was started, but the test query failed.

2019-07-11 21:38:27,239 INFO  [pool-1-thread-1] testcontainers.DockerClientFactory (DockerClientFactory.java:client(108)) - Docker host IP address is localhost
2019-07-11 21:38:27,475 INFO  [pool-1-thread-1] testcontainers.DockerClientFactory (DockerClientFactory.java:client(116)) - Connected to docker:
  Server Version: 18.09.2
  API Version: 1.39
  Operating System: Docker for Mac
  Total Memory: 7973 MB
2019-07-11 21:38:28,639 INFO  [pool-1-thread-1] testcontainers.DockerClientFactory (DockerClientFactory.java:client(125)) - Ryuk started - will monitor and terminate Testcontainers containers on JVM exit
        ℹ︎ Checking the system...
        ✔ Docker version should be at least 1.6.0
        ✔ Docker environment should have more than 2GB free disk space
[info] LoadSuite:
2019-07-11 21:38:34,040 INFO  [pool-1-thread-1] spark.SparkContext (Logging.scala:logInfo(54)) - Running Spark version 2.4.0
2019-07-11 21:38:34,441 WARN  [pool-1-thread-1] util.NativeCodeLoader (NativeCodeLoader.java:<clinit>(62)) - Unable to load native-hadoop library for your platform... using builtin-java classes where applicable
2019-07-11 21:38:34,521 INFO  [pool-1-thread-1] spark.SparkContext (Logging.scala:logInfo(54)) - Submitted application: test
2019-07-11 21:38:34,579 INFO  [pool-1-thread-1] spark.SecurityManager (Logging.scala:logInfo(54)) - Changing view acls to: tdang
2019-07-11 21:38:34,579 INFO  [pool-1-thread-1] spark.SecurityManager (Logging.scala:logInfo(54)) - Changing modify acls to: tdang
2019-07-11 21:38:34,579 INFO  [pool-1-thread-1] spark.SecurityManager (Logging.scala:logInfo(54)) - Changing view acls groups to:
2019-07-11 21:38:34,580 INFO  [pool-1-thread-1] spark.SecurityManager (Logging.scala:logInfo(54)) - Changing modify acls groups to:
2019-07-11 21:38:34,580 INFO  [pool-1-thread-1] spark.SecurityManager (Logging.scala:logInfo(54)) - SecurityManager: authentication disabled; ui acls disabled; users  with view permissions: Set(tdang); groups with view permissions: Set(); users  with modify permissions: Set(tdang); groups with modify permissions: Set()
2019-07-11 21:38:39,924 INFO  [pool-1-thread-1] util.Utils (Logging.scala:logInfo(54)) - Successfully started service 'sparkDriver' on port 60032.
2019-07-11 21:38:39,949 INFO  [pool-1-thread-1] spark.SparkEnv (Logging.scala:logInfo(54)) - Registering MapOutputTracker
2019-07-11 21:38:39,966 INFO  [pool-1-thread-1] spark.SparkEnv (Logging.scala:logInfo(54)) - Registering BlockManagerMaster
2019-07-11 21:38:39,969 INFO  [pool-1-thread-1] storage.BlockManagerMasterEndpoint (Logging.scala:logInfo(54)) - Using org.apache.spark.storage.DefaultTopologyMapper for getting topology information
2019-07-11 21:38:39,969 INFO  [pool-1-thread-1] storage.BlockManagerMasterEndpoint (Logging.scala:logInfo(54)) - BlockManagerMasterEndpoint up
2019-07-11 21:38:39,979 INFO  [pool-1-thread-1] storage.DiskBlockManager (Logging.scala:logInfo(54)) - Created local directory at /private/var/folders/g8/xjq6gqbj0bx2k66cp5k697pm0000gn/T/blockmgr-2de4156d-834f-4c79-a789-8ef2129e739d
2019-07-11 21:38:40,011 INFO  [pool-1-thread-1] memory.MemoryStore (Logging.scala:logInfo(54)) - MemoryStore started with capacity 2004.6 MB
2019-07-11 21:38:40,024 INFO  [pool-1-thread-1] spark.SparkEnv (Logging.scala:logInfo(54)) - Registering OutputCommitCoordinator
2019-07-11 21:38:40,101 INFO  [pool-1-thread-1] executor.Executor (Logging.scala:logInfo(54)) - Starting executor ID driver on host localhost
2019-07-11 21:38:40,161 INFO  [pool-1-thread-1] util.Utils (Logging.scala:logInfo(54)) - Successfully started service 'org.apache.spark.network.netty.NettyBlockTransferService' on port 60033.
2019-07-11 21:38:40,162 INFO  [pool-1-thread-1] netty.NettyBlockTransferService (Logging.scala:logInfo(54)) - Server created on localhost:60033
2019-07-11 21:38:40,163 INFO  [pool-1-thread-1] storage.BlockManager (Logging.scala:logInfo(54)) - Using org.apache.spark.storage.RandomBlockReplicationPolicy for block replication policy
2019-07-11 21:38:40,181 INFO  [pool-1-thread-1] storage.BlockManagerMaster (Logging.scala:logInfo(54)) - Registering BlockManager BlockManagerId(driver, localhost, 60033, None)
2019-07-11 21:38:40,183 INFO  [dispatcher-event-loop-2] storage.BlockManagerMasterEndpoint (Logging.scala:logInfo(54)) - Registering block manager localhost:60033 with 2004.6 MB RAM, BlockManagerId(driver, localhost, 60033, None)
2019-07-11 21:38:40,187 INFO  [pool-1-thread-1] storage.BlockManagerMaster (Logging.scala:logInfo(54)) - Registered BlockManager BlockManagerId(driver, localhost, 60033, None)
2019-07-11 21:38:40,187 INFO  [pool-1-thread-1] storage.BlockManager (Logging.scala:logInfo(54)) - Initialized BlockManager: BlockManagerId(driver, localhost, 60033, None)
2019-07-11 21:38:40,333 INFO  [pool-1-thread-1] util.log (Log.java:initialized(192)) - Logging initialized @20407ms
2019-07-11 21:38:40,636 WARN  [pool-1-thread-1] spark.SparkContext (Logging.scala:logWarning(66)) - Using an existing SparkContext; some configuration may not take effect.
2019-07-11 21:38:40,648 INFO  [pool-1-thread-1] 🐳 [exasol/docker-db:latest] (GenericContainer.java:tryStart(230)) - Creating container for image: exasol/docker-db:latest
2019-07-11 21:38:40,873 INFO  [pool-1-thread-1] 🐳 [exasol/docker-db:latest] (GenericContainer.java:tryStart(242)) - Starting container with ID: ee05deb8c76eee80553b88ad87e0a3f87f981d55cc77e891c688737d7d1e87bf
2019-07-11 21:38:41,446 INFO  [pool-1-thread-1] 🐳 [exasol/docker-db:latest] (GenericContainer.java:tryStart(248)) - Container exasol/docker-db:latest is starting: ee05deb8c76eee80553b88ad87e0a3f87f981d55cc77e891c688737d7d1e87bf
2019-07-11 21:38:41,461 INFO  [pool-1-thread-1] 🐳 [exasol/docker-db:latest] (JdbcDatabaseContainer.java:waitUntilContainerStarted(128)) - Waiting for database connection to become available at jdbc:exa:192.168.0.2:8888 using query 'SELECT 1'
2019-07-11 21:41:41,462 ERROR [pool-1-thread-1] 🐳 [exasol/docker-db:latest] (GenericContainer.java:tryStart(268)) - Could not start container
org.rnorth.ducttape.TimeoutException: Timeout waiting for result with exception
    at org.rnorth.ducttape.unreliables.Unreliables.retryUntilSuccess(Unreliables.java:51)
    at org.testcontainers.containers.JdbcDatabaseContainer.waitUntilContainerStarted(JdbcDatabaseContainer.java:129)
    at org.testcontainers.containers.GenericContainer.tryStart(GenericContainer.java:263)
    at org.testcontainers.containers.GenericContainer.lambda$doStart$0(GenericContainer.java:216)
    at org.rnorth.ducttape.unreliables.Unreliables.retryUntilSuccess(Unreliables.java:76)
    at org.testcontainers.containers.GenericContainer.doStart(GenericContainer.java:214)
    at org.testcontainers.containers.GenericContainer.start(GenericContainer.java:203)
    at org.testcontainers.containers.GenericContainer.starting(GenericContainer.java:723)
    at org.testcontainers.containers.TestContainerAccessor$.starting(TestContainerAccessor.scala:13)
    at com.dimafeng.testcontainers.TestContainerProxy$class.starting(TestContainer.scala:106)
    at com.dimafeng.testcontainers.SingleContainer.starting(TestContainer.scala:111)
    at com.dimafeng.testcontainers.ForAllTestContainer$class.run(TestContainer.scala:67)
    at com.exasol.spark.LoadSuite.org$scalatest$BeforeAndAfterAll$$super$run(LoadSuite.scala:11)
    at org.scalatest.BeforeAndAfterAll$class.liftedTree1$1(BeforeAndAfterAll.scala:213)
    at org.scalatest.BeforeAndAfterAll$class.run(BeforeAndAfterAll.scala:210)
    at com.exasol.spark.LoadSuite.run(LoadSuite.scala:11)
    at org.scalatest.tools.Framework.org$scalatest$tools$Framework$$runSuite(Framework.scala:314)
    at org.scalatest.tools.Framework$ScalaTestTask.execute(Framework.scala:480)
    at sbt.ForkMain$Run.lambda$runTest$1(ForkMain.java:304)
    at java.util.concurrent.FutureTask.run(FutureTask.java:266)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
    at java.lang.Thread.run(Thread.java:745)
Caused by: java.sql.SQLException: Could not create new connection
    at org.testcontainers.containers.JdbcDatabaseContainer.createConnection(JdbcDatabaseContainer.java:194)
    at org.testcontainers.containers.JdbcDatabaseContainer.lambda$waitUntilContainerStarted$0(JdbcDatabaseContainer.java:135)
    at org.rnorth.ducttape.unreliables.Unreliables.lambda$retryUntilSuccess$0(Unreliables.java:41)
    ... 4 more
Caused by: org.rnorth.ducttape.TimeoutException: Timeout waiting for result with exception
    at org.rnorth.ducttape.unreliables.Unreliables.retryUntilSuccess(Unreliables.java:51)
    at org.testcontainers.containers.JdbcDatabaseContainer.createConnection(JdbcDatabaseContainer.java:190)
    ... 6 more
Caused by: com.exasol.jdbc.ConnectFailed: Connection refused
    at com.exasol.jdbc.AbstractEXAConnection.setupConnection(AbstractEXAConnection.java:1295)
    at com.exasol.jdbc.AbstractEXAConnection.Connect(AbstractEXAConnection.java:1177)
    at com.exasol.jdbc.AbstractEXAConnection.<init>(AbstractEXAConnection.java:435)
    at com.exasol.jdbc.EXAConnection.<init>(EXAConnection.java:38)
    at com.exasol.jdbc.EXADriver.connect(EXADriver.java:159)
    at org.testcontainers.containers.JdbcDatabaseContainer.lambda$null$1(JdbcDatabaseContainer.java:192)
    at org.rnorth.ducttape.ratelimits.RateLimiter.getWhenReady(RateLimiter.java:51)
    at org.testcontainers.containers.JdbcDatabaseContainer.lambda$createConnection$2(JdbcDatabaseContainer.java:191)
    ... 5 more
2019-07-11 21:41:41,465 ERROR [pool-1-thread-1] 🐳 [exasol/docker-db:latest] (GenericContainer.java:tryStart(272)) - Container log output (if any) will follow:
2019-07-11 21:41:41,481 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 19:38:42] exadt:: '/exa/etc' does not exist! Doing full initialization.
2019-07-11 21:41:41,481 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 19:38:42] exadt:: searching for the first interface with state UP
2019-07-11 21:41:41,481 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 19:38:42] exadt:: copying license file '/.license.xml' to '/exa/etc/license.xml'
2019-07-11 21:41:41,482 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 19:38:42] exadt:: initializing EXAConf
2019-07-11 21:41:41,482 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 19:38:42] exadt:: using interface 'eth0@if72' with address '192.168.0.2/24'.
2019-07-11 21:41:41,482 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 19:38:42] exadt:: setting hostname to 'n11'
2019-07-11 21:41:41,482 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 19:38:42] exadt:: creating EXAStorage devices
2019-07-11 21:41:41,482 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 19:38:42] exadt:: changing file ownership to 500:500
2019-07-11 21:41:41,483 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 19:38:42] exadt:: calling '('/usr/opt/EXASuite-6/EXARuntime-6.1.4/bin/numactl', ['--interleave=all', '/usr/opt/EXASuite-6/EXAClusterOS-6.1.4/libexec/exainit.py'])'
2019-07-11 21:41:41,483 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDERR: [2019-07-11 19:38:43] stage0: Output redirected to '/exa/logs/cored/exainit.log'
2019-07-11 21:41:41,483 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 19:38:43] stage0: Run service prepare_update
2019-07-11 21:41:41,483 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 19:38:43] stage0: Run service next_stage
2019-07-11 21:41:41,483 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 19:38:43] stage0: Current environment settings:
2019-07-11 21:41:41,484 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 19:38:43] stage0: >>> [('COS_CONF_DIR', '/exa'),
2019-07-11 21:41:41,484 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 19:38:43] stage0: >>>  ('COS_DIRECTORY', '/usr/opt/EXASuite-6/EXAClusterOS-6.1.4'),
2019-07-11 21:41:41,484 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 19:38:43] stage0: >>>  ('EXA_DB_VERSION', '6.1.4'),
2019-07-11 21:41:41,484 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 19:38:43] stage0: >>>  ('EXA_IMG_VERSION', '6.1.4-d1'),
2019-07-11 21:41:41,485 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 19:38:43] stage0: >>>  ('EXA_NODE_ID', '11'),
2019-07-11 21:41:41,485 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 19:38:43] stage0: >>>  ('EXA_OS_VERSION', '6.1.4'),
2019-07-11 21:41:41,485 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 19:38:43] stage0: >>>  ('EXA_RE_VERSION', '6.1.4'),
2019-07-11 21:41:41,485 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 19:38:43] stage0: >>>  ('HOME', '/'),
2019-07-11 21:41:41,485 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 19:38:43] stage0: >>>  ('HOSTNAME', 'n11'),
2019-07-11 21:41:41,486 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 19:38:43] stage0: >>>  ('LANG', 'C'),
2019-07-11 21:41:41,486 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 19:38:43] stage0: >>>  ('LC_ADDRESS', 'C'),
2019-07-11 21:41:41,486 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 19:38:43] stage0: >>>  ('LC_COLLATE', 'C'),
2019-07-11 21:41:41,486 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 19:38:43] stage0: >>>  ('LC_CTYPE', 'en_US.utf8'),
2019-07-11 21:41:41,487 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 19:38:43] stage0: >>>  ('LC_IDENTIFICATION', 'C'),
2019-07-11 21:41:41,487 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 19:38:43] stage0: >>>  ('LC_MEASUREMENT', 'C'),
2019-07-11 21:41:41,487 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 19:38:43] stage0: >>>  ('LC_MESSAGES', 'C'),
2019-07-11 21:41:41,487 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 19:38:43] stage0: >>>  ('LC_MONETARY', 'C'),
2019-07-11 21:41:41,487 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 19:38:43] stage0: >>>  ('LC_NAME', 'C'),
2019-07-11 21:41:41,487 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 19:38:43] stage0: >>>  ('LC_NUMERIC', 'C'),
2019-07-11 21:41:41,487 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 19:38:43] stage0: >>>  ('LC_PAPER', 'C'),
2019-07-11 21:41:41,487 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 19:38:43] stage0: >>>  ('LC_TELEPHONE', 'C'),
2019-07-11 21:41:41,488 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 19:38:43] stage0: >>>  ('LC_TIME', 'C'),
2019-07-11 21:41:41,488 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 19:38:43] stage0: >>>  ('MANPATH',
2019-07-11 21:41:41,488 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 19:38:43] stage0: >>>   '/usr/opt/EXASuite-6/EXAClusterOS-6.1.4/man:/usr/local/share/man:/usr/share/man'),
2019-07-11 21:41:41,488 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 19:38:43] stage0: >>>  ('PATH',
2019-07-11 21:41:41,488 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 19:38:43] stage0: >>>   '/usr/opt/EXASuite-6/EXAClusterOS-6.1.4/bin:/usr/opt/EXASuite-6/EXAClusterOS-6.1.4/sbin:/usr/opt/EXASuite-6/EXARuntime-6.1.4/bin:/usr/opt/EXASuite-6/EXARuntime-6.1.4/sbin:/bin:/sbin:/usr/bin:/usr/sbin'),
2019-07-11 21:41:41,488 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 19:38:43] stage0: >>>  ('PWD', '/'),
2019-07-11 21:41:41,488 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 19:38:43] stage0: >>>  ('RE_PATH', '/usr/opt/EXASuite-6/EXARuntime-6.1.4'),
2019-07-11 21:41:41,488 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 19:38:43] stage0: >>>  ('SHLVL', '0')]
2019-07-11 21:41:41,488 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 19:38:43] stage0: You have following license limits:
2019-07-11 21:41:41,489 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 19:38:43] stage0: >>>     Database memory (GiB):        200 Main memory (RAM) usable by databases
2019-07-11 21:41:41,489 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 19:38:43] stage0: >>>             Cluster nodes:          1 Number of usable cluster nodes
2019-07-11 21:41:41,489 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 19:38:43] stage0: >>>   Database raw size (GiB):  unlimited Raw Size of Databases (see Value RAW_OBJECT_SIZE in System Tables)
2019-07-11 21:41:41,489 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 19:38:43] stage0: >>>   Database mem size (GiB):  unlimited Compressed Size of Databases (see Value MEM_OBJECT_SIZE in System Tables)
2019-07-11 21:41:41,489 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 19:38:43] stage0: >>>           Expiration date:  unlimited Date of license expiration
2019-07-11 21:41:41,489 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 19:38:43] stage0: Next stage will be 'stage1'.
2019-07-11 21:41:41,490 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 19:38:43] stage1: Output redirected to '/exa/logs/cored/exainit.log'
2019-07-11 21:41:41,490 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 19:38:43] stage1: Run stage 'stage1'
2019-07-11 21:41:41,490 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 19:38:43] stage1: Ignore service environment_conf
2019-07-11 21:41:41,490 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 19:38:43] stage1: Run service node_options
2019-07-11 21:41:41,490 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 19:38:43] stage1: Run service prepare_update
2019-07-11 21:41:41,490 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 19:38:43] stage1: Run service timezone
2019-07-11 21:41:41,490 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:43] stage1: Run service create_users
2019-07-11 21:41:41,491 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:43] stage1: Run service node_etc_cos
2019-07-11 21:41:41,491 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:43] stage1: Run service name_resolution
2019-07-11 21:41:41,491 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:44] stage1: Run service sysctl
2019-07-11 21:41:41,491 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:44] stage1: Run service hugepages_support
2019-07-11 21:41:41,491 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:44] stage1: Run service diskconf
2019-07-11 21:41:41,492 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:44] stage1: Run service broadcast_peers
2019-07-11 21:41:41,492 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:44] stage1: Run service lvm_config
2019-07-11 21:41:41,492 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:44] stage1: Run service devshm_config
2019-07-11 21:41:41,492 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:44] stage1: Run service root_bashrc
2019-07-11 21:41:41,492 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:44] stage1: Run service rsyslogd
2019-07-11 21:41:41,492 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:44] stage1: Run service crond
2019-07-11 21:41:41,493 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:44] stage1: Run service super_cored
2019-07-11 21:41:41,493 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:44] stage1: Run service cored_command
2019-07-11 21:41:41,493 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:44] stage1: Run service next_stage
2019-07-11 21:41:41,493 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:44] stage1: Current node id is '11'
2019-07-11 21:41:41,493 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:44] stage1: Current node options are:
2019-07-11 21:41:41,493 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:44] stage1: >>> [('disks',
2019-07-11 21:41:41,493 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:44] stage1: >>>   <config at 0x7f0fb4990d08: [('disk1', <config at 0x7f0fb4990e30: [('name', 'disk1'), ('component', 'exastorage'), ('devices', ['dev.1']), ('mapping', [('dev.1', '/exa/data/storage')]), ('mapped_devices', [('/exa/data/storage/dev.1', '/exa/data/storage/dev.1')]), ('direct_io', True)]>)]>),
2019-07-11 21:41:41,494 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:44] stage1: >>>  ('docker_volume', '/exa/etc/n11'),
2019-07-11 21:41:41,494 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:44] stage1: >>>  ('exposed_ports', [(8888, 8899), (6583, 6594)]),
2019-07-11 21:41:41,494 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:44] stage1: >>>  ('id', '11'),
2019-07-11 21:41:41,494 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:44] stage1: >>>  ('name', 'n11'),
2019-07-11 21:41:41,494 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:44] stage1: >>>  ('private_ip', '192.168.0.2'),
2019-07-11 21:41:41,494 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:44] stage1: >>>  ('private_net', '192.168.0.2/24'),
2019-07-11 21:41:41,495 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:44] stage1: >>>  ('uuid', '31D42C5EC8D3447CA0A5AC552B71F36A7A405C58')]
2019-07-11 21:41:41,495 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:44] stage1: Configure OS timezone Europe/Berlin
2019-07-11 21:41:41,495 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:44] stage1: >>> is configured with wrong file '../usr/share/zoneinfo/UTC'
2019-07-11 21:41:41,495 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:44] stage1: >>> changed OS timezone to Europe/Berlin with file '/usr/opt/EXASuite-6/EXARuntime-6.1.4/share/zoneinfo/Europe/Berlin'
2019-07-11 21:41:41,495 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:44] stage1: Following user/group entries are configured:
2019-07-11 21:41:41,495 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:44] stage1: >>> users: exadefusr, exameta, root
2019-07-11 21:41:41,495 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:44] stage1: >>> groups: exaadm, exabfsadm, exadbadm, exameta, exastoradm, exausers, root
2019-07-11 21:41:41,495 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:44] stage1: Current node UUID is '31D42C5EC8D3447CA0A5AC552B71F36A7A405C58' (EXAConf)
2019-07-11 21:41:41,496 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:44] stage1: /etc/hosts content:
2019-07-11 21:41:41,496 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:44] stage1: >>> # hosts is generated by exaconf
2019-07-11 21:41:41,496 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:44] stage1: >>> 127.0.0.1 localhost localhost.localdomain
2019-07-11 21:41:41,496 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:44] stage1: >>> 192.168.0.2 n11
2019-07-11 21:41:41,496 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:44] stage1: /etc/resolv.conf content:
2019-07-11 21:41:41,496 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:44] stage1: >>> # Generated by exaconf
2019-07-11 21:41:41,496 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:44] stage1: Following sysctl parameters have incorrect values (should != is):
2019-07-11 21:41:41,497 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:44] stage1: net.core.rmem_default: '4194304' != None
2019-07-11 21:41:41,497 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:44] stage1: net.core.wmem_default: '524288' != None
2019-07-11 21:41:41,497 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:44] stage1: net.ipv4.tcp_rmem: '4096\t87380\t1048576' != None
2019-07-11 21:41:41,497 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:44] stage1: net.core.rmem_max: '4194304' != None
2019-07-11 21:41:41,497 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:44] stage1: kernel.threads-max: '274432' != '63786'
2019-07-11 21:41:41,497 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:44] stage1: net.ipv4.tcp_wmem: '4096\t16384\t4194304' != None
2019-07-11 21:41:41,497 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:44] stage1: net.core.wmem_max: '1048576' != None
2019-07-11 21:41:41,497 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:44] stage1: net.core.netdev_max_backlog: '1000' != None
2019-07-11 21:41:41,497 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:44] stage1: /sys/kernel/mm/transparent_hugepage/defrag: 'never' != 'always defer madvise [never]'
2019-07-11 21:41:41,497 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:44] stage1: kernel.numa_balancing: '0' != None
2019-07-11 21:41:41,497 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:44] stage1: Hugetable filesystem successfully mounted.
2019-07-11 21:41:41,498 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:44] stage1: Hugetable group is already configured.
2019-07-11 21:41:41,498 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:44] stage1: Registering device '/exa/data/storage/dev.1'
2019-07-11 21:41:41,498 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:44] stage1: Following nodes are registered: 192.168.0.2:10001
2019-07-11 21:41:41,498 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:44] stage1: Wrong configured LVM parameters:
2019-07-11 21:41:41,498 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:44] stage1: >>> 'cache_dir' = "/run/lvm" (before "/etc/lvm/cache")
2019-07-11 21:41:41,498 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:44] stage1: >>> 'udev_rules' = 0 (before 1)
2019-07-11 21:41:41,498 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:44] stage1: >>> 'udev_sync' = 0 (before 1)
2019-07-11 21:41:41,498 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:44] stage1: /dev/shm was remounted to the proper size of 1048576 KiB
2019-07-11 21:41:41,498 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:44] stage1: rsyslogd was configured
2019-07-11 21:41:41,498 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:44] stage1: crond was configured
2019-07-11 21:41:41,499 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:44] stage1: super_cored started with return code: 0
2019-07-11 21:41:41,499 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:44] stage1: Call cored with following command: '/usr/opt/EXASuite-6/EXAClusterOS-6.1.4/libexec/cos_cored -n 11 --renice -10 --auth-sock-dir /var/lock --oom-adjustment -350 -m 224.0.0.1 -s 192.168.0.2 -t 10001 -l /exa/logs/cored --default-file-mode 644 /usr/opt/EXASuite-6/EXAClusterOS-6.1.4/libexec/exainit.py stage2'
2019-07-11 21:41:41,499 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:44] stage1: Next stage will be 'stage2'.
2019-07-11 21:41:41,499 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:44] stage2: Run stage 'stage2'
2019-07-11 21:41:41,499 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:44] stage2: Ignore service environment_conf
2019-07-11 21:41:41,499 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:44] stage2: Ignore service create_users
2019-07-11 21:41:41,499 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:44] stage2: Run service node_options
2019-07-11 21:41:41,499 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:44] stage2: Run service prepare_update
2019-07-11 21:41:41,499 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:44] stage2: Run service init_dev_structure
2019-07-11 21:41:41,500 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: init_dev_structure: Skipping LVM device initialization due to device_type 'file'
2019-07-11 21:41:41,500 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:44] stage2: Run service remote_volumes
2019-07-11 21:41:41,500 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:44] stage2: Run service wait_for_nodes
2019-07-11 21:41:41,500 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:44] stage2: Run service next_stage_for_slave
2019-07-11 21:41:41,500 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: Waiting for 0 slave nodes to reach the barrier (13000)
2019-07-11 21:41:41,500 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:44] stage2: Run service rsyslogd
2019-07-11 21:41:41,500 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:44] stage2: Run service sshd
2019-07-11 21:41:41,500 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:44] Starting with PID 1
2019-07-11 21:41:41,500 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:44] Core Daemon v6.1.4  (build 735632017d01b09b818de49e0699d13fdf850458)
2019-07-11 21:41:41,500 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:44] Using multicast address 224.0.0.1.
2019-07-11 21:41:41,501 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:44] Receive socket is bind to interface eth0.
2019-07-11 21:41:41,501 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:44] Started UNIX socket authentication engine (authentication socket directory is /var/lock).
2019-07-11 21:41:41,501 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:44] Core Engine started ... logdir=/exa/logs/cored
2019-07-11 21:41:41,501 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:44] Received transitional Config Change Message: rid=0 seq=0 conf=3 <>
2019-07-11 21:41:41,501 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:44] Received regular Config Change Message: rid=4 seq=0 conf=3 < ip://n11:10001>
2019-07-11 21:41:41,501 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:44] Self information: NID = <invalid>, address = <none>; event_id: 0; no. of cluster nodes: 0
2019-07-11 21:41:41,501 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:44]   11: ip://n11:10001 (offline) usage: 0
2019-07-11 21:41:41,501 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:44] No partitions known.
2019-07-11 21:41:41,501 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:44] Active Nodes: 1 - ip://n11:10001
2019-07-11 21:41:41,501 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:44] Nodes of last Configuration: 0 -
2019-07-11 21:41:41,501 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:44] Config Change completed.
2019-07-11 21:41:41,502 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:44] Self information: NID = 11, address = ip://n11:10001; event_id: 2; no. of cluster nodes: 1
2019-07-11 21:41:41,502 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:44]   11: ip://n11:10001 (available) usage: 0
2019-07-11 21:41:41,502 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:44] No partitions known.
2019-07-11 21:41:41,502 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:44] Started /usr/opt/EXASuite-6/EXAClusterOS-6.1.4/libexec/exainit.py with PID:204 UID:0 GID:0 Part:0 Node:11
2019-07-11 21:41:41,502 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:44] Started /sbin/rsyslogd with PID:219 UID:0 GID:0 Part:1 Node:0
2019-07-11 21:41:41,502 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:44] Started /bin/sh with PID:220 UID:0 GID:0 Part:2 Node:0
2019-07-11 21:41:41,502 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:44] child 220 (Part:2 Node:0 sh) returned with state 0.
2019-07-11 21:41:41,502 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:45] Started /bin/sh with PID:260 UID:0 GID:0 Part:3 Node:0
2019-07-11 21:41:41,502 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:45] child 260 (Part:3 Node:0 sh) returned with state 0.
2019-07-11 21:41:41,502 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: Thu Jul 11 21:38:45 CEST 2019: start script '/usr/opt/EXASuite-6/EXAClusterOS-6.1.4/sbin/cos_sync_files'.
2019-07-11 21:41:41,503 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: Thu Jul 11 21:38:45 CEST 2019: pack files for sync.
2019-07-11 21:41:41,503 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: root/.ssh/id_rsa
2019-07-11 21:41:41,503 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: root/.ssh/id_rsa.pub
2019-07-11 21:41:41,503 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: root/.ssh/authorized_keys
2019-07-11 21:41:41,503 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: root/.ssh/config
2019-07-11 21:41:41,503 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: No nodes to synchronize.
2019-07-11 21:41:41,503 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: Thu Jul 11 21:38:45 CEST 2019: start script '/usr/opt/EXASuite-6/EXAClusterOS-6.1.4/sbin/cos_sync_files'.
2019-07-11 21:41:41,503 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: Thu Jul 11 21:38:45 CEST 2019: pack files for sync.
2019-07-11 21:41:41,503 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: home/exadefusr/.ssh/id_rsa
2019-07-11 21:41:41,503 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: home/exadefusr/.ssh/id_rsa.pub
2019-07-11 21:41:41,504 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: home/exadefusr/.ssh/authorized_keys
2019-07-11 21:41:41,504 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: home/exadefusr/.ssh/config
2019-07-11 21:41:41,504 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: No nodes to synchronize.
2019-07-11 21:41:41,504 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:46] stage2: Run service crond
2019-07-11 21:41:41,504 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:46] stage2: Run service None
2019-07-11 21:41:41,504 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:45] Started /usr/sbin/sshd with PID:347 UID:0 GID:0 Part:4 Node:0
2019-07-11 21:41:41,504 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:46] Started /sbin/crond with PID:349 UID:0 GID:0 Part:5 Node:0
2019-07-11 21:41:41,505 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:46] stage2: Run service merge_and_sync_exaconf
2019-07-11 21:41:41,505 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: FILE_SYNC: Starting partition with shell and command 'scp /exa/etc/EXAConf "n11:/exa/spool/sync/EXAConf_hKdPzA/EXAConf_$EXA_NODE_ID" 2>&1' on all nodes.
2019-07-11 21:41:41,505 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: FILE_SYNC: Synchronizing file '/exa/etc/EXAConf' between all nodes.
2019-07-11 21:41:41,505 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: FILE_SYNC: Generated temporary filename '/exa/etc/EXAConf_0.11.1562873926.49'.
2019-07-11 21:41:41,505 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: FILE_SYNC: Starting partition with shell and command 'tee /exa/etc/EXAConf_0.11.1562873926.49 2>&1 1>/dev/null' on all nodes.
2019-07-11 21:41:41,505 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: FILE_SYNC: 'tee' wrote 5482 bytes.
2019-07-11 21:41:41,505 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: FILE_SYNC: Transferring access rights of file '/exa/etc/EXAConf' to file '/exa/etc/EXAConf_0.11.1562873926.49' .
2019-07-11 21:41:41,505 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: FILE_SYNC: Starting partition with shell and command 'if [ -e /exa/etc/EXAConf ]; then chmod --reference=/exa/etc/EXAConf /exa/etc/EXAConf_0.11.1562873926.49 && chown --reference=/exa/etc/EXAConf /exa/etc/EXAConf_0.11.1562873926.49; fi 2>&1' on all nodes.
2019-07-11 21:41:41,505 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: FILE_SYNC: Moving file '/exa/etc/EXAConf_0.11.1562873926.49' to '/exa/etc/EXAConf'.
2019-07-11 21:41:41,505 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: FILE_SYNC: Starting partition with shell and command 'mv -f /exa/etc/EXAConf_0.11.1562873926.49 /exa/etc/EXAConf 2>&1' on all nodes.
2019-07-11 21:41:41,505 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:46] stage2: Run service slave_unblock
2019-07-11 21:41:41,506 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:46] stage2: Run service next_stage
2019-07-11 21:41:41,506 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:46] stage2: Current node id is '11'
2019-07-11 21:41:41,506 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:46] stage2: Skipping LVM device initialization due to device_type 'file'
2019-07-11 21:41:41,506 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:46] stage2: All nodes are online: ('n11',)
2019-07-11 21:41:41,506 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:46] stage2: Current node is a master node.
2019-07-11 21:41:41,506 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:46] stage2: Next stage will be 'stage3'.
2019-07-11 21:41:41,506 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:46] stage2: rsyslogd was started with PID 1
2019-07-11 21:41:41,506 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:46] stage2: sshd was started with PID 4
2019-07-11 21:41:41,506 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:46] stage2: SSH keys for following users was generated: 0, 500
2019-07-11 21:41:41,506 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:46] stage2: crond was started with PID 5
2019-07-11 21:41:41,507 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:46] stage2: None was started with PID 6
2019-07-11 21:41:41,507 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:46] stage2: Merged the EXAConf of 1 nodes.
2019-07-11 21:41:41,507 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:46] stage2: Next stage will be 'stage3'.
2019-07-11 21:41:41,507 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:46] Started /usr/opt/EXASuite-6/EXAClusterOS-6.1.4/libexec/sysd with PID:350 UID:0 GID:0 Part:6 Node:0
2019-07-11 21:41:41,507 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:46] Started /bin/sh with PID:351 UID:0 GID:0 Part:7 Node:0
2019-07-11 21:41:41,507 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:46] child 351 (Part:7 Node:0 sh) returned with state 0.
2019-07-11 21:41:41,507 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:46] Started /bin/sh with PID:362 UID:0 GID:0 Part:8 Node:0
2019-07-11 21:41:41,507 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:46] child 362 (Part:8 Node:0 sh) returned with state 0.
2019-07-11 21:41:41,508 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:46] Started /bin/sh with PID:364 UID:0 GID:0 Part:9 Node:0
2019-07-11 21:41:41,508 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:46] child 364 (Part:9 Node:0 sh) returned with state 0.
2019-07-11 21:41:41,508 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:46] Started /bin/sh with PID:367 UID:0 GID:0 Part:10 Node:0
2019-07-11 21:41:41,508 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:46] child 367 (Part:10 Node:0 sh) returned with state 0.
2019-07-11 21:41:41,508 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:47] stage3: Output redirected to '/exa/logs/cored/exainit.log'
2019-07-11 21:41:41,508 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:47] stage3: Run stage 'stage3'
2019-07-11 21:41:41,508 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:47] stage3: Ignore service environment_conf
2019-07-11 21:41:41,508 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:47] stage3: Ignore service hugepages
2019-07-11 21:41:41,508 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:47] stage3: Run service node_options
2019-07-11 21:41:41,508 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:47] stage3: Run service prepare_update
2019-07-11 21:41:41,509 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:47] stage3: Run service storaged_conf
2019-07-11 21:41:41,509 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:47] stage3: Run service databases_conf
2019-07-11 21:41:41,509 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:47] stage3: Run service wait_for_nodes
2019-07-11 21:41:41,509 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:47] stage3: Run service bucketfs
2019-07-11 21:41:41,509 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:47] stage3: Run service storaged_conf
2019-07-11 21:41:41,509 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:47] stage3: Run service next_stage_for_slave
2019-07-11 21:41:41,509 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: Waiting for 0 slave nodes to reach the barrier (13001)
2019-07-11 21:41:41,509 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:47] stage3: Run service logd
2019-07-11 21:41:41,509 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:47] stage3: Run service lockd
2019-07-11 21:41:41,509 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:47] stage3: Run service dwad
2019-07-11 21:41:41,510 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:47] Started /usr/opt/EXASuite-6/EXAClusterOS-6.1.4/libexec/bucketfsd with PID:383 UID:0 GID:0 Part:11 Node:0
2019-07-11 21:41:41,510 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:47] Started /usr/opt/EXASuite-6/EXAClusterOS-6.1.4/libexec/logd with PID:384 UID:0 GID:0 Part:12 Node:0
2019-07-11 21:41:41,510 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:47] Started /usr/opt/EXASuite-6/EXAClusterOS-6.1.4/libexec/lockd with PID:385 UID:0 GID:0 Part:13 Node:0
2019-07-11 21:41:41,510 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:47] Started /usr/opt/EXASuite-6/EXAClusterOS-6.1.4/libexec/dwad with PID:389 UID:0 GID:0 Part:14 Node:0
2019-07-11 21:41:41,510 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:48] stage3: Run service storaged
2019-07-11 21:41:41,510 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:48] Started /usr/opt/EXASuite-6/EXAClusterOS-6.1.4/bin/csctrl with PID:430 UID:0 GID:0 Part:15 Node:0
2019-07-11 21:41:41,510 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:48] Started /usr/opt/EXASuite-6/EXAClusterOS-6.1.4/libexec/cos_storage with PID:437 UID:0 GID:0 Part:16 Node:0
2019-07-11 21:41:41,511 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:48] child 430 (Part:15 Node:0 csctrl) returned with state 0.
2019-07-11 21:41:41,511 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:48] Force new cluster synchronization upon user request from partition 16.
2019-07-11 21:41:41,511 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:48] Force new cluster configuration upon user request on node n11.
2019-07-11 21:41:41,511 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:49] Received transitional Config Change Message: rid=4 seq=67 conf=7 < ip://n11:10001>
2019-07-11 21:41:41,511 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:49] Received regular Config Change Message: rid=8 seq=0 conf=7 < ip://n11:10001>
2019-07-11 21:41:41,511 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:49] Self information: NID = 11, address = ip://n11:10001; event_id: 41; no. of cluster nodes: 1
2019-07-11 21:41:41,511 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:49]   11: ip://n11:10001 (available) usage: 9
2019-07-11 21:41:41,512 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:49]   Partition 1 contains 1 nodes: [ 11 ]
2019-07-11 21:41:41,512 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:49]   Partition 4 contains 1 nodes: [ 11 ]
2019-07-11 21:41:41,512 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:49]   Partition 5 contains 1 nodes: [ 11 ]
2019-07-11 21:41:41,512 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:49]   Partition 6 contains 1 nodes: [ 11 ]
2019-07-11 21:41:41,512 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:49]   Partition 11 contains 1 nodes: [ 11 ]
2019-07-11 21:41:41,512 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:49]   Partition 12 contains 1 nodes: [ 11 ]
2019-07-11 21:41:41,512 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:49]   Partition 13 contains 1 nodes: [ 11 ]
2019-07-11 21:41:41,512 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:49]   Partition 14 contains 1 nodes: [ 11 ]
2019-07-11 21:41:41,513 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:49]   Partition 16 contains 1 nodes: [ 11 ]
2019-07-11 21:41:41,513 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:49] Registered local processes:
2019-07-11 21:41:41,513 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:49] PID: 204 (PID: 0, NID: 11)
2019-07-11 21:41:41,513 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:49] PID: 219 (PID: 1, NID: 0)
2019-07-11 21:41:41,513 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:49] PID: 347 (PID: 4, NID: 0)
2019-07-11 21:41:41,513 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:49] PID: 349 (PID: 5, NID: 0)
2019-07-11 21:41:41,513 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:49] PID: 350 (PID: 6, NID: 0)
2019-07-11 21:41:41,513 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:49] PID: 383 (PID: 11, NID: 0)
2019-07-11 21:41:41,513 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:49] PID: 384 (PID: 12, NID: 0)
2019-07-11 21:41:41,514 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:49] PID: 385 (PID: 13, NID: 0)
2019-07-11 21:41:41,514 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:49] PID: 389 (PID: 14, NID: 0)
2019-07-11 21:41:41,514 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:49] PID: 437 (PID: 16, NID: 0)
2019-07-11 21:41:41,514 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:49] Active Nodes: 1 - ip://n11:10001
2019-07-11 21:41:41,514 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:49] Nodes of last Configuration: 1 - ip://n11:10001
2019-07-11 21:41:41,514 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:49] Config Change completed.
2019-07-11 21:41:41,514 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:49] Self information: NID = 11, address = ip://n11:10001; event_id: 52; no. of cluster nodes: 1
2019-07-11 21:41:41,515 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:49]   11: ip://n11:10001 (available) usage: 9
2019-07-11 21:41:41,515 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:49]   Partition 1 contains 1 nodes: [ 11 ]
2019-07-11 21:41:41,515 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:49]   Partition 4 contains 1 nodes: [ 11 ]
2019-07-11 21:41:41,515 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:49]   Partition 5 contains 1 nodes: [ 11 ]
2019-07-11 21:41:41,515 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:49]   Partition 6 contains 1 nodes: [ 11 ]
2019-07-11 21:41:41,515 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:49]   Partition 11 contains 1 nodes: [ 11 ]
2019-07-11 21:41:41,515 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:49]   Partition 12 contains 1 nodes: [ 11 ]
2019-07-11 21:41:41,515 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:49]   Partition 13 contains 1 nodes: [ 11 ]
2019-07-11 21:41:41,515 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:49]   Partition 14 contains 1 nodes: [ 11 ]
2019-07-11 21:41:41,515 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:49]   Partition 16 contains 1 nodes: [ 11 ]
2019-07-11 21:41:41,516 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:49] Registered local processes:
2019-07-11 21:41:41,516 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:49] PID: 204 (PID: 0, NID: 11)
2019-07-11 21:41:41,516 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:49] PID: 219 (PID: 1, NID: 0)
2019-07-11 21:41:41,516 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:49] PID: 347 (PID: 4, NID: 0)
2019-07-11 21:41:41,516 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:49] PID: 349 (PID: 5, NID: 0)
2019-07-11 21:41:41,516 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:49] PID: 350 (PID: 6, NID: 0)
2019-07-11 21:41:41,516 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:49] PID: 383 (PID: 11, NID: 0)
2019-07-11 21:41:41,516 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:49] PID: 384 (PID: 12, NID: 0)
2019-07-11 21:41:41,516 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:49] PID: 385 (PID: 13, NID: 0)
2019-07-11 21:41:41,516 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:49] PID: 389 (PID: 14, NID: 0)
2019-07-11 21:41:41,516 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:49] PID: 437 (PID: 16, NID: 0)
2019-07-11 21:41:41,517 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:52] stage3: Run service confd
2019-07-11 21:41:41,517 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:52] stage3: Run service storage_volumes
2019-07-11 21:41:41,517 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:52] stage3: Run service databases
2019-07-11 21:41:41,517 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:52] stage3: Run service slave_unblock
2019-07-11 21:41:41,517 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:52] stage3: Run service next_stage
2019-07-11 21:41:41,517 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:52] stage3: Current node id is '11'
2019-07-11 21:41:41,517 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:52] stage3: storaged config file genarated here: '/exa/etc/cos_storage.conf'
2019-07-11 21:41:41,517 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:52] stage3: Database configuration: nsexec(0106775), /usr/opt/mountjail, /exa/logs/db/DB1
2019-07-11 21:41:41,517 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:52] stage3: All nodes are online: ('n11',)
2019-07-11 21:41:41,518 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:52] stage3: bucketfs was not started
2019-07-11 21:41:41,518 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:52] stage3: Current node is a master node.
2019-07-11 21:41:41,518 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:52] stage3: Next stage will be 'stage4'.
2019-07-11 21:41:41,518 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:52] stage3: logd was started with PID 12
2019-07-11 21:41:41,518 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:52] stage3: lockd was started with PID 13
2019-07-11 21:41:41,518 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:52] stage3: dwad was started with PID 14
2019-07-11 21:41:41,518 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:52] stage3: storaged was started with PID 16
2019-07-11 21:41:41,518 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:52] stage3: EXAStorage devices added: /exa/data/storage/dev.1
2019-07-11 21:41:41,518 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:52] stage3: confd was started with PID 17
2019-07-11 21:41:41,518 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:52] stage3: Volumes created: DataVolume1:0
2019-07-11 21:41:41,519 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:52] stage3: The following databases were created: DB1
2019-07-11 21:41:41,519 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:52] stage3: Next stage will be 'stage4'.
2019-07-11 21:41:41,519 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:52] Started /usr/opt/EXASuite-6/EXAClusterOS-6.1.4/libexec/confd with PID:472 UID:0 GID:0 Part:17 Node:0
2019-07-11 21:41:41,519 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:52] Started /usr/opt/EXASuite-6/EXAClusterOS-6.1.4/bin/dwa_wrapper with PID:473 UID:500 GID:500 Part:18 Node:0
2019-07-11 21:41:41,519 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:53] Started /usr/opt/EXASuite-6/EXASolution-6.1.4/bin/pddserver with PID:504 UID:500 GID:500 Part:19 Node:0
2019-07-11 21:41:41,519 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:55] stage4: Output redirected to '/exa/logs/cored/exainit.log'
2019-07-11 21:41:41,519 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:55] stage4: Run stage 'stage4'
2019-07-11 21:41:41,519 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:55] stage4: Ignore service environment_conf
2019-07-11 21:41:41,519 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:55] stage4: Run service node_options
2019-07-11 21:41:41,519 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:55] stage4: Run service prepare_update
2019-07-11 21:41:41,519 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:55] stage4: Run service wait_for_nodes
2019-07-11 21:41:41,519 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:55] stage4: Current node id is '11'
2019-07-11 21:41:41,519 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:55] stage4: All nodes are online: ('n11',)
2019-07-11 21:41:41,520 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:55] stage4: All stages finished.
2019-07-11 21:41:41,520 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:56] root child 204 (exainit.py) returned with state 0.
2019-07-11 21:41:41,520 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:57] Started /usr/opt/EXASuite-6/EXASolution-6.1.4/bin/objectserver with PID:618 UID:500 GID:500 Part:20 Node:0
2019-07-11 21:41:41,520 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:38:58] Started /usr/opt/EXASuite-6/EXASolution-6.1.4/bin/exasqlinit with PID:645 UID:500 GID:500 Part:21 Node:0
2019-07-11 21:41:41,520 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:39:03] child 645 (Part:21 Node:0 exasqlinit) returned with state 0.
2019-07-11 21:41:41,520 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:39:03] Started /usr/opt/EXASuite-6/EXASolution-6.1.4/bin/exasqllog with PID:686 UID:500 GID:500 Part:22 Node:0
2019-07-11 21:41:41,520 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:39:18] Started /usr/opt/EXASuite-6/EXASolution-6.1.4/bin/loaderd with PID:717 UID:500 GID:500 Part:23 Node:0
2019-07-11 21:41:41,520 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:39:18] Started /usr/opt/EXASuite-6/EXASolution-6.1.4/bin/exaetl with PID:738 UID:500 GID:500 Part:24 Node:0
2019-07-11 21:41:41,520 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:39:18] Started /usr/opt/EXASuite-6/EXASolution-6.1.4/bin/exacs with PID:739 UID:500 GID:500 Part:25 Node:0
2019-07-11 21:41:41,520 INFO  [tc-okhttp-stream-386619672] 🐳 [exasol/docker-db:latest] (Slf4jLogConsumer.java:accept(32)) - STDOUT: [2019-07-11 21:39:19] Started /usr/opt/EXASuite-6/EXASolution-6.1.4/bin/exasql with PID:780 UID:500 GID:500 Part:26 Node:0
2019-07-11 21:41:41,537 INFO  [dispatcher-event-loop-3] spark.MapOutputTrackerMasterEndpoint (Logging.scala:logInfo(54)) - MapOutputTrackerMasterEndpoint stopped!
2019-07-11 21:41:41,557 INFO  [pool-1-thread-1] memory.MemoryStore (Logging.scala:logInfo(54)) - MemoryStore cleared
2019-07-11 21:41:41,558 INFO  [pool-1-thread-1] storage.BlockManager (Logging.scala:logInfo(54)) - BlockManager stopped
2019-07-11 21:41:41,558 INFO  [pool-1-thread-1] storage.BlockManagerMaster (Logging.scala:logInfo(54)) - BlockManagerMaster stopped
2019-07-11 21:41:41,561 INFO  [dispatcher-event-loop-0] scheduler.OutputCommitCoordinator$OutputCommitCoordinatorEndpoint (Logging.scala:logInfo(54)) - OutputCommitCoordinator stopped!
2019-07-11 21:41:41,570 INFO  [pool-1-thread-1] spark.SparkContext (Logging.scala:logInfo(54)) - Successfully stopped SparkContext
[info] com.exasol.spark.LoadSuite *** ABORTED ***
[info]   org.testcontainers.containers.ContainerLaunchException: Container startup failed
[info]   at org.testcontainers.containers.GenericContainer.doStart(GenericContainer.java:221)
[info]   at org.testcontainers.containers.GenericContainer.start(GenericContainer.java:203)
[info]   at org.testcontainers.containers.GenericContainer.starting(GenericContainer.java:723)
[info]   at org.testcontainers.containers.TestContainerAccessor$.starting(TestContainerAccessor.scala:13)
[info]   at com.dimafeng.testcontainers.TestContainerProxy$class.starting(TestContainer.scala:106)
[info]   at com.dimafeng.testcontainers.SingleContainer.starting(TestContainer.scala:111)
[info]   at com.dimafeng.testcontainers.ForAllTestContainer$class.run(TestContainer.scala:67)
[info]   at com.exasol.spark.LoadSuite.org$scalatest$BeforeAndAfterAll$$super$run(LoadSuite.scala:11)
[info]   at org.scalatest.BeforeAndAfterAll$class.liftedTree1$1(BeforeAndAfterAll.scala:213)
[info]   at org.scalatest.BeforeAndAfterAll$class.run(BeforeAndAfterAll.scala:210)
[info]   ...
[info]   Cause: org.rnorth.ducttape.RetryCountExceededException: Retry limit hit with exception
[info]   at org.rnorth.ducttape.unreliables.Unreliables.retryUntilSuccess(Unreliables.java:83)
[info]   at org.testcontainers.containers.GenericContainer.doStart(GenericContainer.java:214)
[info]   at org.testcontainers.containers.GenericContainer.start(GenericContainer.java:203)
[info]   at org.testcontainers.containers.GenericContainer.starting(GenericContainer.java:723)
[info]   at org.testcontainers.containers.TestContainerAccessor$.starting(TestContainerAccessor.scala:13)
[info]   at com.dimafeng.testcontainers.TestContainerProxy$class.starting(TestContainer.scala:106)
[info]   at com.dimafeng.testcontainers.SingleContainer.starting(TestContainer.scala:111)
[info]   at com.dimafeng.testcontainers.ForAllTestContainer$class.run(TestContainer.scala:67)
[info]   at com.exasol.spark.LoadSuite.org$scalatest$BeforeAndAfterAll$$super$run(LoadSuite.scala:11)
[info]   at org.scalatest.BeforeAndAfterAll$class.liftedTree1$1(BeforeAndAfterAll.scala:213)
[info]   ...
[info]   Cause: org.testcontainers.containers.ContainerLaunchException: Could not create/start container
[info]   at org.testcontainers.containers.GenericContainer.tryStart(GenericContainer.java:286)
[info]   at org.testcontainers.containers.GenericContainer.lambda$doStart$0(GenericContainer.java:216)
[info]   at org.rnorth.ducttape.unreliables.Unreliables.retryUntilSuccess(Unreliables.java:76)
[info]   at org.testcontainers.containers.GenericContainer.doStart(GenericContainer.java:214)
[info]   at org.testcontainers.containers.GenericContainer.start(GenericContainer.java:203)
[info]   at org.testcontainers.containers.GenericContainer.starting(GenericContainer.java:723)
[info]   at org.testcontainers.containers.TestContainerAccessor$.starting(TestContainerAccessor.scala:13)
[info]   at com.dimafeng.testcontainers.TestContainerProxy$class.starting(TestContainer.scala:106)
[info]   at com.dimafeng.testcontainers.SingleContainer.starting(TestContainer.scala:111)
[info]   at com.dimafeng.testcontainers.ForAllTestContainer$class.run(TestContainer.scala:67)
[info]   ...
[info]   Cause: org.rnorth.ducttape.TimeoutException: Timeout waiting for result with exception
[info]   at org.rnorth.ducttape.unreliables.Unreliables.retryUntilSuccess(Unreliables.java:51)
[info]   at org.testcontainers.containers.JdbcDatabaseContainer.waitUntilContainerStarted(JdbcDatabaseContainer.java:129)
[info]   at org.testcontainers.containers.GenericContainer.tryStart(GenericContainer.java:263)
[info]   at org.testcontainers.containers.GenericContainer.lambda$doStart$0(GenericContainer.java:216)
[info]   at org.rnorth.ducttape.unreliables.Unreliables.retryUntilSuccess(Unreliables.java:76)
[info]   at org.testcontainers.containers.GenericContainer.doStart(GenericContainer.java:214)
[info]   at org.testcontainers.containers.GenericContainer.start(GenericContainer.java:203)
[info]   at org.testcontainers.containers.GenericContainer.starting(GenericContainer.java:723)
[info]   at org.testcontainers.containers.TestContainerAccessor$.starting(TestContainerAccessor.scala:13)
[info]   at com.dimafeng.testcontainers.TestContainerProxy$class.starting(TestContainer.scala:106)
[info]   ...
[info]   Cause: java.sql.SQLException: Could not create new connection
[info]   at org.testcontainers.containers.JdbcDatabaseContainer.createConnection(JdbcDatabaseContainer.java:194)
[info]   at org.testcontainers.containers.JdbcDatabaseContainer.lambda$waitUntilContainerStarted$0(JdbcDatabaseContainer.java:135)
[info]   at org.rnorth.ducttape.unreliables.Unreliables.lambda$retryUntilSuccess$0(Unreliables.java:41)
[info]   at java.util.concurrent.FutureTask.run(FutureTask.java:266)
[info]   at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
[info]   at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
[info]   at java.lang.Thread.run(Thread.java:745)
[info]   ...
[info]   Cause: org.rnorth.ducttape.TimeoutException: Timeout waiting for result with exception
[info]   at org.rnorth.ducttape.unreliables.Unreliables.retryUntilSuccess(Unreliables.java:51)
[info]   at org.testcontainers.containers.JdbcDatabaseContainer.createConnection(JdbcDatabaseContainer.java:190)
[info]   at org.testcontainers.containers.JdbcDatabaseContainer.lambda$waitUntilContainerStarted$0(JdbcDatabaseContainer.java:135)
[info]   at org.rnorth.ducttape.unreliables.Unreliables.lambda$retryUntilSuccess$0(Unreliables.java:41)
[info]   at java.util.concurrent.FutureTask.run(FutureTask.java:266)
[info]   at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
[info]   at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
[info]   at java.lang.Thread.run(Thread.java:745)
[info]   ...
[info]   Cause: com.exasol.jdbc.ConnectFailed: Connection refused
[info]   at com.exasol.jdbc.AbstractEXAConnection.setupConnection(AbstractEXAConnection.java:1295)
[info]   at com.exasol.jdbc.AbstractEXAConnection.Connect(AbstractEXAConnection.java:1177)
[info]   at com.exasol.jdbc.AbstractEXAConnection.<init>(AbstractEXAConnection.java:435)
[info]   at com.exasol.jdbc.EXAConnection.<init>(EXAConnection.java:38)
[info]   at com.exasol.jdbc.EXADriver.connect(EXADriver.java:159)
[info]   at org.testcontainers.containers.JdbcDatabaseContainer.lambda$null$1(JdbcDatabaseContainer.java:192)
[info]   at org.rnorth.ducttape.ratelimits.RateLimiter.getWhenReady(RateLimiter.java:51)
[info]   at org.testcontainers.containers.JdbcDatabaseContainer.lambda$createConnection$2(JdbcDatabaseContainer.java:191)
[info]   at org.rnorth.ducttape.unreliables.Unreliables.lambda$retryUntilSuccess$0(Unreliables.java:41)
[info]   at java.util.concurrent.FutureTask.run(FutureTask.java:266)
[info]   ...
IP: ==========> 192.168.0.3
morazow commented 5 years ago

Yes, the container seems to be running but maybe the Exasol database is not started properly.

This might be issue related to O_DIRECT not being available on macOS. It is one of the requirements for the Exasol docker-db.

Could you please check it? And maybe try to run from regular cli, 

docker run --name exasoldb -p 127.0.0.1:8899:8888 --detach --privileged --stop-timeout 120  exasol/docker-db:<version>

and see if everything works.

3cham commented 5 years ago

Yes, I visited the troubleshooting link from exasol-docker db as well, but in the container log above I didn't see any error. I could even used exaplus client to connect to the db, so I didn't think it is related to O_DIRECT.