Skip to content

testMySQLWithCustomIniFile failure in 1.1.4 #209

@dbyron0

Description

@dbyron0

I've seen the same failure twice with 1.1.4 (actually 45fa877 from master).

testMySQLWithCustomIniFile(org.testcontainers.junit.SimpleMySQLTest)  Time elapsed: 361.929 sec  <<< ERROR!
org.testcontainers.containers.ContainerLaunchException: Container startup failed
    at org.testcontainers.containers.GenericContainer.start(GenericContainer.java:174)
    at org.testcontainers.junit.SimpleMySQLTest.testMySQLWithCustomIniFile(SimpleMySQLTest.java:77)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:497)
    at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
    at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
    at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
    at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
    at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325)
    at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:78)
    at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:57)
    at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
    at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
    at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
    at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
    at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
    at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
    at org.apache.maven.surefire.junit4.JUnit4Provider.execute(JUnit4Provider.java:252)
    at org.apache.maven.surefire.junit4.JUnit4Provider.executeTestSet(JUnit4Provider.java:141)
    at org.apache.maven.surefire.junit4.JUnit4Provider.invoke(JUnit4Provider.java:112)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:497)
    at org.apache.maven.surefire.util.ReflectionUtils.invokeMethodWithArray(ReflectionUtils.java:189)
    at org.apache.maven.surefire.booter.ProviderFactory$ProviderProxy.invoke(ProviderFactory.java:165)
    at org.apache.maven.surefire.booter.ProviderFactory.invokeProvider(ProviderFactory.java:85)
    at org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:115)
    at org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:75)
Caused by: org.rnorth.ducttape.RetryCountExceededException: Retry limit hit with exception
    at org.rnorth.ducttape.unreliables.Unreliables.retryUntilSuccess(Unreliables.java:83)
    at org.testcontainers.containers.GenericContainer.start(GenericContainer.java:167)
    ... 30 more
Caused by: org.testcontainers.containers.ContainerLaunchException: Could not create/start container
    at org.testcontainers.containers.GenericContainer.tryStart(GenericContainer.java:240)
    at org.testcontainers.containers.GenericContainer.lambda$start$0(GenericContainer.java:169)
    at org.rnorth.ducttape.unreliables.Unreliables.retryUntilSuccess(Unreliables.java:76)
    ... 31 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.waitUntilContainerStarted(JdbcDatabaseContainer.java:67)
    at org.testcontainers.containers.GenericContainer.tryStart(GenericContainer.java:219)
    ... 33 more
Caused by: org.testcontainers.containers.ContainerLaunchException: Container failed to start
    at org.testcontainers.containers.JdbcDatabaseContainer.lambda$waitUntilContainerStarted$2(JdbcDatabaseContainer.java:70)
    at org.rnorth.ducttape.unreliables.Unreliables.lambda$retryUntilSuccess$0(Unreliables.java:41)
    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)

Once, I saw this repeated ~38 times afterwards:

09:55:18.502 DEBUG org.testcontainers.utility.ResourceReaper - Removed container and associated volume(s): mysql:latest
09:55:19.138 DEBUG org.testcontainers.utility.ResourceReaper - Removed container and associated volume(s): mysql:latest
09:55:20.003 DEBUG org.testcontainers.utility.ResourceReaper - Removed container and associated volume(s): mysql:5.6
09:55:20.208 DEBUG org.testcontainers.utility.ResourceReaper - Removed container and associated volume(s): mysql:5.6
09:55:21.022 DEBUG org.testcontainers.utility.ResourceReaper - Removed container and associated volume(s): mysql:latest
09:55:21.701 DEBUG org.testcontainers.utility.ResourceReaper - Removed container and associated volume(s): mysql:latest
09:55:22.011 DEBUG org.testcontainers.utility.ResourceReaper - Removed container and associated volume(s): mysql:5.6
09:55:22.016 ERROR org.testcontainers.shaded.com.github.dockerjava.core.async.ResultCallbackTemplate - Error during callback
org.testcontainers.shaded.com.github.dockerjava.api.exception.NotFoundException: {"message":"No such container: da8b5c8de86ccb56d518d2c15aac411c803626d75735275003fc9bfdcfe5bf37"}

    at org.testcontainers.shaded.com.github.dockerjava.netty.handler.HttpResponseHandler.channelRead0(HttpResponseHandler.java:103) [testcontainers-1.1.5-SNAPSHOT.jar:na]
    at org.testcontainers.shaded.com.github.dockerjava.netty.handler.HttpResponseHandler.channelRead0(HttpResponseHandler.java:33) [testcontainers-1.1.5-SNAPSHOT.jar:na]
    at org.testcontainers.shaded.io.netty.channel.SimpleChannelInboundHandler.channelRead(SimpleChannelInboundHandler.java:105) [testcontainers-1.1.5-SNAPSHOT.jar:na]
    at org.testcontainers.shaded.io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:372) [testcontainers-1.1.5-SNAPSHOT.jar:na]
    at org.testcontainers.shaded.io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:358) [testcontainers-1.1.5-SNAPSHOT.jar:na]
    at org.testcontainers.shaded.io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:350) [testcontainers-1.1.5-SNAPSHOT.jar:na]
    at org.testcontainers.shaded.io.netty.handler.logging.LoggingHandler.channelRead(LoggingHandler.java:233) [testcontainers-1.1.5-SNAPSHOT.jar:na]
    at org.testcontainers.shaded.io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:372) [testcontainers-1.1.5-SNAPSHOT.jar:na]
    at org.testcontainers.shaded.io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:358) [testcontainers-1.1.5-SNAPSHOT.jar:na]
    at org.testcontainers.shaded.io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:350) [testcontainers-1.1.5-SNAPSHOT.jar:na]
    at org.testcontainers.shaded.io.netty.channel.CombinedChannelDuplexHandler$DelegatingChannelHandlerContext.fireChannelRead(CombinedChannelDuplexHandler.java:435) [testcontainers-1.1.5-SNAPSHOT.jar:na]
    at org.testcontainers.shaded.io.netty.handler.codec.ByteToMessageDecoder.fireChannelRead(ByteToMessageDecoder.java:293) [testcontainers-1.1.5-SNAPSHOT.jar:na]
    at org.testcontainers.shaded.io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:267) [testcontainers-1.1.5-SNAPSHOT.jar:na]
    at org.testcontainers.shaded.io.netty.channel.CombinedChannelDuplexHandler.channelRead(CombinedChannelDuplexHandler.java:250) [testcontainers-1.1.5-SNAPSHOT.jar:na]
    at org.testcontainers.shaded.io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:372) [testcontainers-1.1.5-SNAPSHOT.jar:na]
    at org.testcontainers.shaded.io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:358) [testcontainers-1.1.5-SNAPSHOT.jar:na]
    at org.testcontainers.shaded.io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:350) [testcontainers-1.1.5-SNAPSHOT.jar:na]
    at org.testcontainers.shaded.io.netty.handler.ssl.SslHandler.unwrap(SslHandler.java:1066) [testcontainers-1.1.5-SNAPSHOT.jar:na]
    at org.testcontainers.shaded.io.netty.handler.ssl.SslHandler.decode(SslHandler.java:900) [testcontainers-1.1.5-SNAPSHOT.jar:na]
    at org.testcontainers.shaded.io.netty.handler.codec.ByteToMessageDecoder.callDecode(ByteToMessageDecoder.java:411) [testcontainers-1.1.5-SNAPSHOT.jar:na]
    at org.testcontainers.shaded.io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:248) [testcontainers-1.1.5-SNAPSHOT.jar:na]
    at org.testcontainers.shaded.io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:372) [testcontainers-1.1.5-SNAPSHOT.jar:na]
    at org.testcontainers.shaded.io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:358) [testcontainers-1.1.5-SNAPSHOT.jar:na]
    at org.testcontainers.shaded.io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:350) [testcontainers-1.1.5-SNAPSHOT.jar:na]
    at org.testcontainers.shaded.io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1334) [testcontainers-1.1.5-SNAPSHOT.jar:na]
    at org.testcontainers.shaded.io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:372) [testcontainers-1.1.5-SNAPSHOT.jar:na]
    at org.testcontainers.shaded.io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:358) [testcontainers-1.1.5-SNAPSHOT.jar:na]
    at org.testcontainers.shaded.io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:926) [testcontainers-1.1.5-SNAPSHOT.jar:na]
    at org.testcontainers.shaded.io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:123) [testcontainers-1.1.5-SNAPSHOT.jar:na]
    at org.testcontainers.shaded.io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:571) [testcontainers-1.1.5-SNAPSHOT.jar:na]
    at org.testcontainers.shaded.io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:512) [testcontainers-1.1.5-SNAPSHOT.jar:na]
    at org.testcontainers.shaded.io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:426) [testcontainers-1.1.5-SNAPSHOT.jar:na]
    at org.testcontainers.shaded.io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:398) [testcontainers-1.1.5-SNAPSHOT.jar:na]
    at org.testcontainers.shaded.io.netty.util.concurrent.SingleThreadEventExecutor$5.run(SingleThreadEventExecutor.java:877) [testcontainers-1.1.5-SNAPSHOT.jar:na]
    at org.testcontainers.shaded.io.netty.util.concurrent.DefaultThreadFactory$DefaultRunnableDecorator.run(DefaultThreadFactory.java:144) [testcontainers-1.1.5-SNAPSHOT.jar:na]
    at java.lang.Thread.run(Thread.java:745) [na:1.8.0_66]

Perhaps this earlier exception/log is relevant? I can't quite tell if it's from an earlier test. I see this in both failures. It's the callback errors that I saw only once.

09:53:56.577 ERROR 🐳 [mysql:5.6] - Could not start container
org.rnorth.ducttape.TimeoutException: Timeout waiting for result with exception
    at org.rnorth.ducttape.unreliables.Unreliables.retryUntilSuccess(Unreliables.java:51) ~[duct-tape-1.0.6.jar:na]
    at org.testcontainers.containers.JdbcDatabaseContainer.waitUntilContainerStarted(JdbcDatabaseContainer.java:67) ~[jdbc-1.1.5-SNAPSHOT.jar:na]
    at org.testcontainers.containers.GenericContainer.tryStart(GenericContainer.java:219) [testcontainers-1.1.5-SNAPSHOT.jar:na]
    at org.testcontainers.containers.GenericContainer.lambda$start$0(GenericContainer.java:169) [testcontainers-1.1.5-SNAPSHOT.jar:na]
    at org.rnorth.ducttape.unreliables.Unreliables.retryUntilSuccess(Unreliables.java:76) ~[duct-tape-1.0.6.jar:na]
    at org.testcontainers.containers.GenericContainer.start(GenericContainer.java:167) [testcontainers-1.1.5-SNAPSHOT.jar:na]
    at org.testcontainers.junit.SimpleMySQLTest.testMySQLWithCustomIniFile(SimpleMySQLTest.java:77) ~[test-classes/:na]
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.8.0_66]
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[na:1.8.0_66]
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_66]
    at java.lang.reflect.Method.invoke(Method.java:497) ~[na:1.8.0_66]
    at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50) ~[jdbc-1.1.5-SNAPSHOT.jar:na]
    at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12) ~[jdbc-1.1.5-SNAPSHOT.jar:na]
    at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47) ~[jdbc-1.1.5-SNAPSHOT.jar:na]
    at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17) ~[jdbc-1.1.5-SNAPSHOT.jar:na]
    at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325) ~[jdbc-1.1.5-SNAPSHOT.jar:na]
    at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:78) ~[jdbc-1.1.5-SNAPSHOT.jar:na]
    at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:57) ~[jdbc-1.1.5-SNAPSHOT.jar:na]
    at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290) ~[jdbc-1.1.5-SNAPSHOT.jar:na]
    at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71) ~[jdbc-1.1.5-SNAPSHOT.jar:na]
    at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288) ~[jdbc-1.1.5-SNAPSHOT.jar:na]
    at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58) ~[jdbc-1.1.5-SNAPSHOT.jar:na]
    at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268) ~[jdbc-1.1.5-SNAPSHOT.jar:na]
    at org.junit.runners.ParentRunner.run(ParentRunner.java:363) ~[jdbc-1.1.5-SNAPSHOT.jar:na]
    at org.apache.maven.surefire.junit4.JUnit4Provider.execute(JUnit4Provider.java:252) ~[na:na]
    at org.apache.maven.surefire.junit4.JUnit4Provider.executeTestSet(JUnit4Provider.java:141) ~[na:na]
    at org.apache.maven.surefire.junit4.JUnit4Provider.invoke(JUnit4Provider.java:112) ~[na:na]
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[na:1.8.0_66]
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[na:1.8.0_66]
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[na:1.8.0_66]
    at java.lang.reflect.Method.invoke(Method.java:497) ~[na:1.8.0_66]
    at org.apache.maven.surefire.util.ReflectionUtils.invokeMethodWithArray(ReflectionUtils.java:189) ~[surefire-api-2.12.4.jar:2.12.4]
    at org.apache.maven.surefire.booter.ProviderFactory$ProviderProxy.invoke(ProviderFactory.java:165) ~[surefire-booter-2.12.4.jar:2.12.4]
    at org.apache.maven.surefire.booter.ProviderFactory.invokeProvider(ProviderFactory.java:85) ~[surefire-booter-2.12.4.jar:2.12.4]
    at org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:115) ~[surefire-booter-2.12.4.jar:2.12.4]
    at org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:75) ~[surefire-booter-2.12.4.jar:2.12.4]
Caused by: org.testcontainers.containers.ContainerLaunchException: Container failed to start
    at org.testcontainers.containers.JdbcDatabaseContainer.lambda$waitUntilContainerStarted$2(JdbcDatabaseContainer.java:70) ~[jdbc-1.1.5-SNAPSHOT.jar:na]
    at org.rnorth.ducttape.unreliables.Unreliables.lambda$retryUntilSuccess$0(Unreliables.java:41) ~[duct-tape-1.0.6.jar:na]
    at java.util.concurrent.FutureTask.run(FutureTask.java:266) ~[na:1.8.0_66]
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) ~[na:1.8.0_66]
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) ~[na:1.8.0_66]
    at java.lang.Thread.run(Thread.java:745) ~[na:1.8.0_66]
09:53:56.593 ERROR 🐳 [mysql:5.6] - Container log output (if any) will follow:
09:53:56.700 INFO  🐳 [mysql:5.6] - STDOUT: Initializing database
09:53:56.701 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:51:55 0 [Note] /usr/sbin/mysqld (mysqld 5.6.32) starting as process 26 ...
09:53:56.701 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:51:55 26 [Note] InnoDB: Using atomics to ref count buffer pool pages
09:53:56.702 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:51:55 26 [Note] InnoDB: The InnoDB memory heap is disabled
09:53:56.702 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:51:55 26 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
09:53:56.703 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:51:55 26 [Note] InnoDB: Memory barrier is not used
09:53:56.703 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:51:55 26 [Note] InnoDB: Compressed tables use zlib 1.2.8
09:53:56.703 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:51:55 26 [Note] InnoDB: Using Linux native AIO
09:53:56.704 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:51:55 26 [Note] InnoDB: Using CPU crc32 instructions
09:53:56.704 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:51:55 26 [Note] InnoDB: Initializing buffer pool, size = 128.0M
09:53:56.705 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:51:55 26 [Note] InnoDB: Completed initialization of buffer pool
09:53:56.705 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:51:55 26 [Note] InnoDB: The first specified data file ./ibdata1 did not exist: a new database to be created!
09:53:56.706 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:51:55 26 [Note] InnoDB: Setting file ./ibdata1 size to 12 MB
09:53:56.706 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:51:55 26 [Note] InnoDB: Database physically writes the file full: wait...
09:53:56.707 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:51:55 26 [Note] InnoDB: Setting log file ./ib_logfile101 size to 48 MB
09:53:56.707 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:51:55 26 [Note] InnoDB: Setting log file ./ib_logfile1 size to 48 MB
09:53:56.708 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:51:55 26 [Note] InnoDB: Renaming log file ./ib_logfile101 to ./ib_logfile0
09:53:56.708 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:51:55 26 [Warning] InnoDB: New log files created, LSN=45781
09:53:56.709 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:51:55 26 [Note] InnoDB: Doublewrite buffer not found: creating new
09:53:56.709 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:51:55 26 [Note] InnoDB: Doublewrite buffer created
09:53:56.709 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:51:55 26 [Note] InnoDB: 128 rollback segment(s) are active.
09:53:56.710 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:51:55 26 [Warning] InnoDB: Creating foreign key constraint system tables.
09:53:56.710 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:51:55 26 [Note] InnoDB: Foreign key constraint system tables created
09:53:56.735 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:51:55 26 [Note] InnoDB: Creating tablespace and datafile system tables.
09:53:56.735 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:51:55 26 [Note] InnoDB: Tablespace and datafile system tables created.
09:53:56.736 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:51:55 26 [Note] InnoDB: Waiting for purge to start
09:53:56.736 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:51:55 26 [Note] InnoDB: 5.6.32 started; log sequence number 0
09:53:56.736 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:51:56 26 [Note] Binlog end
09:53:56.737 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:51:56 26 [Note] InnoDB: FTS optimize thread exiting.
09:53:56.738 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:51:56 26 [Note] InnoDB: Starting shutdown...
09:53:56.738 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:51:57 26 [Note] InnoDB: Shutdown completed; log sequence number 1625977
09:53:56.739 INFO  🐳 [mysql:5.6] - STDOUT: 
09:53:56.739 INFO  🐳 [mysql:5.6] - STDOUT: 
09:53:56.739 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:51:57 0 [Note] /usr/sbin/mysqld (mysqld 5.6.32) starting as process 49 ...
09:53:56.740 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:51:57 49 [Note] InnoDB: Using atomics to ref count buffer pool pages
09:53:56.741 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:51:57 49 [Note] InnoDB: The InnoDB memory heap is disabled
09:53:56.741 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:51:57 49 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
09:53:56.742 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:51:57 49 [Note] InnoDB: Memory barrier is not used
09:53:56.743 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:51:57 49 [Note] InnoDB: Compressed tables use zlib 1.2.8
09:53:56.743 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:51:57 49 [Note] InnoDB: Using Linux native AIO
09:53:56.744 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:51:57 49 [Note] InnoDB: Using CPU crc32 instructions
09:53:56.744 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:51:57 49 [Note] InnoDB: Initializing buffer pool, size = 128.0M
09:53:56.744 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:51:57 49 [Note] InnoDB: Completed initialization of buffer pool
09:53:56.745 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:51:57 49 [Note] InnoDB: Highest supported file format is Barracuda.
09:53:56.745 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:51:57 49 [Note] InnoDB: 128 rollback segment(s) are active.
09:53:56.745 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:51:57 49 [Note] InnoDB: Waiting for purge to start
09:53:56.746 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:51:57 49 [Note] InnoDB: 5.6.32 started; log sequence number 1625977
09:53:56.746 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:51:58 49 [Note] Binlog end
09:53:56.747 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:51:58 49 [Note] InnoDB: FTS optimize thread exiting.
09:53:56.747 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:51:58 49 [Note] InnoDB: Starting shutdown...
09:53:56.748 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:51:59 49 [Note] InnoDB: Shutdown completed; log sequence number 1625987
09:53:56.748 INFO  🐳 [mysql:5.6] - STDOUT: 
09:53:56.749 INFO  🐳 [mysql:5.6] - STDOUT: 
09:53:56.749 INFO  🐳 [mysql:5.6] - STDOUT: 
09:53:56.749 INFO  🐳 [mysql:5.6] - STDOUT: 
09:53:56.749 INFO  🐳 [mysql:5.6] - STDOUT: PLEASE REMEMBER TO SET A PASSWORD FOR THE MySQL root USER !
09:53:56.749 INFO  🐳 [mysql:5.6] - STDOUT: To do so, start the server, then issue the following commands:
09:53:56.750 INFO  🐳 [mysql:5.6] - STDOUT: 
09:53:56.750 INFO  🐳 [mysql:5.6] - STDOUT: /usr/bin/mysqladmin -u root password 'new-password'
09:53:56.750 INFO  🐳 [mysql:5.6] - STDOUT: /usr/bin/mysqladmin -u root -h da8b5c8de86c password 'new-password'
09:53:56.751 INFO  🐳 [mysql:5.6] - STDOUT: 
09:53:56.751 INFO  🐳 [mysql:5.6] - STDOUT: Alternatively you can run:
09:53:56.751 INFO  🐳 [mysql:5.6] - STDOUT: 
09:53:56.751 INFO  🐳 [mysql:5.6] - STDOUT: /usr/bin/mysql_secure_installation
09:53:56.752 INFO  🐳 [mysql:5.6] - STDOUT: 
09:53:56.752 INFO  🐳 [mysql:5.6] - STDOUT: which will also give you the option of removing the test
09:53:56.752 INFO  🐳 [mysql:5.6] - STDOUT: databases and anonymous user created by default.  This is
09:53:56.753 INFO  🐳 [mysql:5.6] - STDOUT: strongly recommended for production servers.
09:53:56.753 INFO  🐳 [mysql:5.6] - STDOUT: 
09:53:56.753 INFO  🐳 [mysql:5.6] - STDOUT: See the manual for more instructions.
09:53:56.754 INFO  🐳 [mysql:5.6] - STDOUT: 
09:53:56.754 INFO  🐳 [mysql:5.6] - STDOUT: Please report any problems at http://bugs.mysql.com/
09:53:56.754 INFO  🐳 [mysql:5.6] - STDOUT: 
09:53:56.755 INFO  🐳 [mysql:5.6] - STDOUT: The latest information about MySQL is available on the web at
09:53:56.755 INFO  🐳 [mysql:5.6] - STDOUT: 
09:53:56.755 INFO  🐳 [mysql:5.6] - STDOUT: http://www.mysql.com
09:53:56.756 INFO  🐳 [mysql:5.6] - STDOUT: 
09:53:56.756 INFO  🐳 [mysql:5.6] - STDOUT: Support MySQL by buying support/licenses at http://shop.mysql.com
09:53:56.756 INFO  🐳 [mysql:5.6] - STDOUT: 
09:53:56.756 INFO  🐳 [mysql:5.6] - STDOUT: Note: new default config file not created.
09:53:56.757 INFO  🐳 [mysql:5.6] - STDOUT: Please make sure your config file is current
09:53:56.757 INFO  🐳 [mysql:5.6] - STDOUT: 
09:53:56.758 INFO  🐳 [mysql:5.6] - STDOUT: WARNING: Default config file /etc/mysql/my.cnf exists on the system
09:53:56.759 INFO  🐳 [mysql:5.6] - STDOUT: This file will be read by default by the MySQL server
09:53:56.759 INFO  🐳 [mysql:5.6] - STDOUT: If you do not want to use this, either remove it, or use the
09:53:56.759 INFO  🐳 [mysql:5.6] - STDOUT: --defaults-file argument to mysqld_safe when starting the server
09:53:56.760 INFO  🐳 [mysql:5.6] - STDOUT: 
09:53:56.760 INFO  🐳 [mysql:5.6] - STDOUT: Database initialized
09:53:56.760 INFO  🐳 [mysql:5.6] - STDOUT: MySQL init process in progress...
09:53:56.761 INFO  🐳 [mysql:5.6] - STDOUT: MySQL init process in progress...
09:53:56.761 INFO  🐳 [mysql:5.6] - STDOUT: MySQL init process in progress...
09:53:56.761 INFO  🐳 [mysql:5.6] - STDOUT: MySQL init process in progress...
09:53:56.762 INFO  🐳 [mysql:5.6] - STDOUT: MySQL init process in progress...
09:53:56.762 INFO  🐳 [mysql:5.6] - STDOUT: MySQL init process in progress...
09:53:56.762 INFO  🐳 [mysql:5.6] - STDOUT: MySQL init process in progress...
09:53:56.762 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:52:06 0 [Note] mysqld (mysqld 5.6.32) starting as process 72 ...
09:53:56.763 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:52:06 72 [Note] Plugin 'FEDERATED' is disabled.
09:53:56.763 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:52:06 72 [Note] InnoDB: Using atomics to ref count buffer pool pages
09:53:56.764 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:52:06 72 [Note] InnoDB: The InnoDB memory heap is disabled
09:53:56.765 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:52:06 72 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
09:53:56.765 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:52:06 72 [Note] InnoDB: Memory barrier is not used
09:53:56.766 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:52:06 72 [Note] InnoDB: Compressed tables use zlib 1.2.8
09:53:56.766 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:52:06 72 [Note] InnoDB: Using Linux native AIO
09:53:56.766 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:52:06 72 [Note] InnoDB: Using CPU crc32 instructions
09:53:56.767 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:52:06 72 [Note] InnoDB: Initializing buffer pool, size = 128.0M
09:53:56.767 INFO  🐳 [mysql:5.6] - STDERR: InnoDB: mmap(137363456 bytes) failed; errno 12
09:53:56.768 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:52:06 72 [ERROR] InnoDB: Cannot allocate memory for the buffer pool
09:53:56.768 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:52:06 72 [ERROR] Plugin 'InnoDB' init function returned error.
09:53:56.769 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:52:06 72 [ERROR] Plugin 'InnoDB' registration as a STORAGE ENGINE failed.
09:53:56.769 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:52:06 72 [ERROR] Unknown/unsupported storage engine: InnoDB
09:53:56.770 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:52:06 72 [ERROR] Aborting
09:53:56.770 INFO  🐳 [mysql:5.6] - STDERR: 
09:53:56.770 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:52:06 72 [Note] Binlog end
09:53:56.771 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:52:06 72 [Note] Shutting down plugin 'partition'
09:53:56.771 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:52:06 72 [Note] Shutting down plugin 'INNODB_SYS_DATAFILES'
09:53:56.771 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:52:06 72 [Note] Shutting down plugin 'INNODB_SYS_TABLESPACES'
09:53:56.772 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:52:06 72 [Note] Shutting down plugin 'INNODB_SYS_FOREIGN_COLS'
09:53:56.772 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:52:06 72 [Note] Shutting down plugin 'INNODB_SYS_FOREIGN'
09:53:56.773 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:52:06 72 [Note] Shutting down plugin 'INNODB_SYS_FIELDS'
09:53:56.773 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:52:06 72 [Note] Shutting down plugin 'INNODB_SYS_COLUMNS'
09:53:56.774 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:52:06 72 [Note] Shutting down plugin 'INNODB_SYS_INDEXES'
09:53:56.774 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:52:06 72 [Note] Shutting down plugin 'INNODB_SYS_TABLESTATS'
09:53:56.774 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:52:06 72 [Note] Shutting down plugin 'INNODB_SYS_TABLES'
09:53:56.775 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:52:06 72 [Note] Shutting down plugin 'INNODB_FT_INDEX_TABLE'
09:53:56.775 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:52:06 72 [Note] Shutting down plugin 'INNODB_FT_INDEX_CACHE'
09:53:56.776 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:52:06 72 [Note] Shutting down plugin 'INNODB_FT_CONFIG'
09:53:56.776 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:52:06 72 [Note] Shutting down plugin 'INNODB_FT_BEING_DELETED'
09:53:56.777 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:52:06 72 [Note] Shutting down plugin 'INNODB_FT_DELETED'
09:53:56.777 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:52:06 72 [Note] Shutting down plugin 'INNODB_FT_DEFAULT_STOPWORD'
09:53:56.777 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:52:06 72 [Note] Shutting down plugin 'INNODB_METRICS'
09:53:56.778 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:52:06 72 [Note] Shutting down plugin 'INNODB_BUFFER_POOL_STATS'
09:53:56.778 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:52:06 72 [Note] Shutting down plugin 'INNODB_BUFFER_PAGE_LRU'
09:53:56.779 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:52:06 72 [Note] Shutting down plugin 'INNODB_BUFFER_PAGE'
09:53:56.779 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:52:06 72 [Note] Shutting down plugin 'INNODB_CMP_PER_INDEX_RESET'
09:53:56.780 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:52:06 72 [Note] Shutting down plugin 'INNODB_CMP_PER_INDEX'
09:53:56.780 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:52:06 72 [Note] Shutting down plugin 'INNODB_CMPMEM_RESET'
09:53:56.781 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:52:06 72 [Note] Shutting down plugin 'INNODB_CMPMEM'
09:53:56.781 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:52:06 72 [Note] Shutting down plugin 'INNODB_CMP_RESET'
09:53:56.782 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:52:06 72 [Note] Shutting down plugin 'INNODB_CMP'
09:53:56.782 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:52:06 72 [Note] Shutting down plugin 'INNODB_LOCK_WAITS'
09:53:56.783 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:52:06 72 [Note] Shutting down plugin 'INNODB_LOCKS'
09:53:56.783 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:52:06 72 [Note] Shutting down plugin 'INNODB_TRX'
09:53:56.783 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:52:06 72 [Note] Shutting down plugin 'BLACKHOLE'
09:53:56.784 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:52:06 72 [Note] Shutting down plugin 'ARCHIVE'
09:53:56.784 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:52:06 72 [Note] Shutting down plugin 'PERFORMANCE_SCHEMA'
09:53:56.784 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:52:06 72 [Note] Shutting down plugin 'MRG_MYISAM'
09:53:56.785 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:52:06 72 [Note] Shutting down plugin 'MyISAM'
09:53:56.785 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:52:06 72 [Note] Shutting down plugin 'CSV'
09:53:56.785 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:52:06 72 [Note] Shutting down plugin 'MEMORY'
09:53:56.786 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:52:06 72 [Note] Shutting down plugin 'sha256_password'
09:53:56.786 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:52:06 72 [Note] Shutting down plugin 'mysql_old_password'
09:53:56.787 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:52:06 72 [Note] Shutting down plugin 'mysql_native_password'
09:53:56.787 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:52:06 72 [Note] Shutting down plugin 'binlog'
09:53:56.787 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:52:06 72 [Note] mysqld: Shutdown complete
09:53:56.788 INFO  🐳 [mysql:5.6] - STDERR: 
09:53:56.788 INFO  🐳 [mysql:5.6] - STDOUT: MySQL init process in progress...
09:53:56.789 INFO  🐳 [mysql:5.6] - STDOUT: MySQL init process in progress...
09:53:56.789 INFO  🐳 [mysql:5.6] - STDOUT: MySQL init process in progress...
09:53:56.789 INFO  🐳 [mysql:5.6] - STDOUT: MySQL init process in progress...
09:53:56.790 INFO  🐳 [mysql:5.6] - STDOUT: MySQL init process in progress...
09:53:56.790 INFO  🐳 [mysql:5.6] - STDOUT: MySQL init process in progress...
09:53:56.790 INFO  🐳 [mysql:5.6] - STDOUT: MySQL init process in progress...
09:53:56.791 INFO  🐳 [mysql:5.6] - STDOUT: MySQL init process in progress...
09:53:56.791 INFO  🐳 [mysql:5.6] - STDOUT: MySQL init process in progress...
09:53:56.791 INFO  🐳 [mysql:5.6] - STDOUT: MySQL init process in progress...
09:53:56.792 INFO  🐳 [mysql:5.6] - STDOUT: MySQL init process in progress...
09:53:56.792 INFO  🐳 [mysql:5.6] - STDOUT: MySQL init process in progress...
09:53:56.792 INFO  🐳 [mysql:5.6] - STDOUT: MySQL init process in progress...
09:53:56.793 INFO  🐳 [mysql:5.6] - STDOUT: MySQL init process in progress...
09:53:56.793 INFO  🐳 [mysql:5.6] - STDOUT: MySQL init process in progress...
09:53:56.793 INFO  🐳 [mysql:5.6] - STDOUT: MySQL init process in progress...
09:53:56.794 INFO  🐳 [mysql:5.6] - STDOUT: MySQL init process in progress...
09:53:56.794 INFO  🐳 [mysql:5.6] - STDOUT: MySQL init process in progress...
09:53:56.795 INFO  🐳 [mysql:5.6] - STDOUT: MySQL init process in progress...
09:53:56.795 INFO  🐳 [mysql:5.6] - STDOUT: MySQL init process in progress...
09:53:56.795 INFO  🐳 [mysql:5.6] - STDOUT: MySQL init process in progress...
09:53:56.795 INFO  🐳 [mysql:5.6] - STDOUT: MySQL init process in progress...
09:53:56.795 INFO  🐳 [mysql:5.6] - STDOUT: MySQL init process in progress...
09:53:56.796 INFO  🐳 [mysql:5.6] - STDOUT: MySQL init process in progress...
09:53:56.796 INFO  🐳 [mysql:5.6] - STDERR: MySQL init process failed.

The relevant part of all of that appears to be:

09:53:56.767 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:52:06 72 [Note] InnoDB: Initializing buffer pool, size = 128.0M
09:53:56.767 INFO  🐳 [mysql:5.6] - STDERR: InnoDB: mmap(137363456 bytes) failed; errno 12
09:53:56.768 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:52:06 72 [ERROR] InnoDB: Cannot allocate memory for the buffer pool
09:53:56.768 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:52:06 72 [ERROR] Plugin 'InnoDB' init function returned error.
09:53:56.769 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:52:06 72 [ERROR] Plugin 'InnoDB' registration as a STORAGE ENGINE failed.
09:53:56.769 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:52:06 72 [ERROR] Unknown/unsupported storage engine: InnoDB
09:53:56.770 INFO  🐳 [mysql:5.6] - STDERR: 2016-08-17 16:52:06 72 [ERROR] Aborting

In case it's relevant:

$ docker images mysql
REPOSITORY          TAG                 IMAGE ID            CREATED             SIZE
mysql               5.5                 8d782bc197a5        2 weeks ago         255.7 MB
mysql               5.6                 5e0f1b09e25e        2 weeks ago         328.9 MB
mysql               latest              43c70d2fa278        2 weeks ago         384.5 MB
mysql               5.5.43              51b1c3df066a        15 months ago       214.5 MB

and

$ docker run -e MYSQL_ALLOW_EMPTY_PASSWORD=true mysql:5.6

gets way farther than the buffer pool initialization.

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type
    No fields configured for issues without a type.

    Projects

    No projects

    Milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions