when starting more than 2 images, the log printout doesn't appear in the terminal

[mason]

I am trying to start 4 images and the log printout never appears for all 4 on ubuntu. I tried on mac and it works perfect. all 4 images are printing out logs to the terminal. On ubuntu I can only manage to get 2 logs printing out to terminal. I tried reordering the images and I always just get 2 images printing out logs. any ideas?

Client version: 1.7.1
Client API version: 1.19

mvn docker plugin: 0.13.0 and 0.13.2

[rhuss]

How do you you start the container ? With mvn docker:start -Ddocker.follow ? Could you also please post the plugin configuration so that I can try to reproduce it ?

thx ....

[mason]

Hey @rhuss Thanks for responding so quickly :) I've setup a small app that shows the bug. Also, I found that 0.13.2 hangs forever when running mvn clean install with my setup. only 0.13.0 works for me.

I start it with mvn clean install.

https://github.com/mason/mvn-docker-plugin-bug

[jgangemi]

hrm - i wonder if having all the zookeeper containers share the same alias is causing issues. a different manifestation of #182. i'll try that out in the morning if @rhuss doesn't investigate first.

[jgangemi]

i just ran this on my mac w/ #245 applied against the latest integration branch and all 4 containers started w/o hanging.

all 4 container have logging output but i think the problem is the plugin dumps all available log content to stdout and the last two containers haven't produced enough.

if i run this command mvn clean install -Ddocker.follow, i see the full output of all the containers.

[mason]

@jgangemi It doesn't matter what the alias is. In my real app I use 4 different images with 4 different aliases. Also, on mac everything works perfect. Ubuntu is the one with the issues. I've confirmed with a coworker that on ubuntu it doesn't behave the same as mac.

[rhuss]

@mason with what version of Ubuntu and Docker do you have the issue ? I will try to reproduce it ...

[rhuss]

Another question: How many memory do you have on the Ubuntu machine ? And is the Docker Host running on the same machine ?

[rhuss]

I just tested it with the following setup:

• Ubuntu 14-05 Server (Vagrant image)
• 512 MB RAM
• Java 1.8
• Maven 3.3.3
• Docker

In fact when starting it with mvn docker:start -Ddocker.follow Maven blocks in a POST request. This is described in bug #227 and fixed with PR #232 which will be included in the next release 0.13.3.

However this fix works still only when using the TCP socket when talking with the Docker daemon. By default, when on Ubuntu only the UNIX socket is enabled which is used then by the plugin.

To make the example work now I did:

• Add the following to the pom.xml and increased version number to 0.13.3-SNAPSHOT in the plugin config

 <pluginRepositories>
    <pluginRepository>
      <id>apache.snapshots</id>
      <url>https://oss.sonatype.org/content/repositories/snapshots/</url>
    </pluginRepository>
  </pluginRepositories>

• Added -H tcp://127.0.0.1:2375 to /etc/defaults/docker in DOCKER_OPTIONS
• Set export DOCKER_HOST="tcp://127.0.0.1:2375" before starting maven
• Call mvn docker:start -Ddocker.follow : Everything starts up fine

Does this work for you, too ?

Another tip: Use a <wait><log>binding to port</log></wait> to sequentially startup the containers in order to easier follow the logs.

I will investigate the issue with unix socket in the meantime and let you know when it is fixed. A final 0.13.3 should follow soon then, too.

[rhuss]

Another remark: In you portmappings you should always use port 2181 for the container port and only increase the host port part.

[rhuss]

Fixed it now for the unix socket, too. So no need to switch to TCP anymore.

[mason]

@rhuss PERFECT :) 👍 0.13.3-SNAPSHOT works! I didn't make the /etc/defaults/docker changes

[mason]

I did however get this exception (It didn't fail the build however)

Exception in thread "Thread-10" java.lang.IllegalArgumentException: Invalid format: "11T12:02:22.812Z" is malformed at "T12:02:22.812Z"
    at org.joda.time.format.DateTimeFormatter.parseDateTime(DateTimeFormatter.java:873)
    at org.jolokia.docker.maven.util.Timestamp.<init>(Timestamp.java:53)
    at org.jolokia.docker.maven.access.log.LogRequestor.callLogCallback(LogRequestor.java:142)
    at org.jolokia.docker.maven.access.log.LogRequestor.parseResponse(LogRequestor.java:121)
    at org.jolokia.docker.maven.access.log.LogRequestor.run(LogRequestor.java:97)

[rhuss]

Interesting. Could you please do a mvn -X for this build and gist it ? Looks like some minor issue with a chunked response which is not chunked on newlines.

[mason]

@rhuss I don't think I will be able to provide that as the application I am working on is a little too sensitive to be sharing that printout. I can however try to replicate it. I am about to head to work so I probably can't get back to you until much later.

@jgangemi thanks for the feedback. the sample app isn't supposed to be functioning, but to illustrate the issues I was having. In my real app I only use 1 zookeeper instance. During my debugging I thought it was an issue with my app since only 2 apps appeared to start. The first two apps were zookeeper and kafka. The third was my app. I got the bright idea that I should try just starting 4 zookeepers to see what happened and I experienced the same issues. Also, I'm not sure if these problems exist in other distros but I assume it will based off the tcp/unix comment by rhuss. I wasn't aware that was how it worked.

[rhuss]

@mason: No problem, I already have a feeling whats going on with the timestamp issue (since it seems to be truncated its probably really an chunking issue which I've seen also at other places.

To clarify things: The problem occurs only when using the Unix socket because the default of 4 max. parallel connections was not increased. For the TCP based setup the limit was 10 (still to small for many images). That also explains why it works on OS X (which has to use the TCP based setup). Also: For each image which wants to print out logs a permanent connections needs to be opened to receive the log output plus the ones you need for other ops.

[mason]

Hey, so I was able to replicate the issue. It's in my test project: https://github.com/mason/mvn-docker-plugin-bug. Just run mvn clean install. I attempt to run some tests in a container and it errors out due to misconfiguration but that's fine. I wanted to just show the error. Run mvn clean install a few times if you don't see it. It's not deterministic but it happens at least 50% of the time.

I also see the maven docker plugin not able to process the <wait><log></log></wait> tag. I believe it may be connected to this.

Invalid log format for '2015-08-12T23:09:31.346825197Z at org.apache.maven.surefire.junit4.JUnit4Provider.invoke(JUnit4Provider.java:124) [surefire-junit4-2.17.ja8 �' (expected: "<timestamp> <txt>")