Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Fix deadlock waiting on docker log pattern to match #965

Merged
merged 1 commit into from Apr 3, 2018
Merged

Fix deadlock waiting on docker log pattern to match #965

merged 1 commit into from Apr 3, 2018

Conversation

romank8k
Copy link
Contributor

@romank8k romank8k commented Mar 6, 2018

This fixes a regression introduced in the 0.24.0 version of the plugin.
I have a small test program to demonstrate the problem below.

Normally, Apache HTTP Client will drain an http request upon closing the input stream.
In this case we consume the docker logs in 'follow' mode which will cause the docker daemon to never close the connection on its end.
Thus the http client close() call will block forever.
The main thread is responsible for calling request.abort(), which will signal Apache HTTP Client to close the socket on it's end and thus the close() call can unblock.
Due to the refactoring in 0.24.0, there is a deadlock on this object in LogRequestor.java

    // Lock for synchronizing closing of requests
    private final Object lock = new Object();

Since the log requestor thread is waiting on close() and the main thread cannot reach the code to call request.abort()

I believe this is the same issue as #767 .

In the patch, I removed the lock completely, as I made sure that request.abort() is only called from the main thread. It doesn't seem necessary anymore.

I have been testing my build of the plugin for a few days and it's been working on Docker for Mac and on our Linux build boxes.
I have briefly tested on Docker for Windows and seems to work as well...but I will run some more tests there.

package io.fabric8.maven.docker.access.log;

import io.fabric8.maven.docker.access.UrlBuilder;
import io.fabric8.maven.docker.access.hc.unix.UnixSocketClientBuilder;
import io.fabric8.maven.docker.util.Logger;
import io.fabric8.maven.docker.util.Timestamp;
import org.apache.commons.lang3.mutable.MutableBoolean;
import org.apache.commons.lang3.mutable.MutableObject;

public class LogWaitDeadlockTest {
    // Replace this with the container ID of a running container on your system.
    private static final String CONTAINER_ID = "35193bc7c489";

    public static void main(String[] args) throws Exception {
        final UnixSocketClientBuilder builder = new UnixSocketClientBuilder("/var/run/docker.sock", 2, new Logger() {
            @Override
            public void debug(String format, Object... params) {

            }

            @Override
            public void info(String format, Object... params) {

            }

            @Override
            public void verbose(String format, Object... params) {

            }

            @Override
            public void warn(String format, Object... params) {

            }

            @Override
            public void error(String format, Object... params) {

            }

            @Override
            public String errorMessage(String message) {
                return null;
            }

            @Override
            public boolean isDebugEnabled() {
                return false;
            }

            @Override
            public boolean isVerboseEnabled() {
                return false;
            }

            @Override
            public void progressStart() {

            }

            @Override
            public void progressUpdate(String layerId, String status, String progressMessage) {

            }

            @Override
            public void progressFinished() {

            }
        });

        final UrlBuilder urlBuilder = new UrlBuilder("unix://127.0.0.1:1/", "v1.18");
        final MutableBoolean stop = new MutableBoolean(false);

        // Plugin normally launches the LogRequestor in it's own thread...
        // The main thread checks every 500ms whether the LogRequestor thread has matched something...

        final MutableObject<LogRequestor> logRequestorHandle = new MutableObject<>();
        new Thread(new Runnable() {
            @Override
            public void run() {
                try {
                    LogRequestor logRequestor = new LogRequestor(builder.buildBasicClient(), urlBuilder, CONTAINER_ID, new LogCallback() {
                        @Override
                        public void log(int type, Timestamp timestamp, String txt) throws DoneException {
                            // Simulate matching on the first log line.
                            if (!stop.booleanValue()) {
                                stop.setTrue();
                                throw new LogCallback.DoneException();
                            }
                        }

                        @Override
                        public void error(String error) {
                            System.err.println(error);
                        }

                        @Override
                        public void open() {
                        }

                        @Override
                        public void close() {
                        }
                    });
                    logRequestorHandle.setValue(logRequestor);
                    logRequestor.run();
                } catch (Exception e) {
                    e.printStackTrace();
                }
            }
        }).start();

        boolean done = false;
        while (!done) {
            if (stop.booleanValue()) {
                LogRequestor logRequestor = logRequestorHandle.getValue();
                logRequestor.finish();
                done = true;
            }
            Thread.sleep(100);
        }

        System.out.println("FINISHED!");
    }
}

…ed in 0.24.0

Apache HTTP Client will drain an http request upon closing the input stream.
In this case we consume the docker logs in 'follow' mode which will cause the docker daemon to never close the connection on its end.
Thus the close() call will block forever.
The main thread is responsible for calling request.abort() will will signal Apache HTTP Client to close the socket on it's end and thus the close() call can unblock.
@codecov
Copy link

codecov bot commented Mar 6, 2018

Codecov Report

Merging #965 into master will increase coverage by <.01%.
The diff coverage is 71.42%.

@@             Coverage Diff              @@
##             master     #965      +/-   ##
============================================
+ Coverage     51.57%   51.58%   +<.01%     
  Complexity     1232     1232              
============================================
  Files           144      144              
  Lines          7251     7243       -8     
  Branches        981      980       -1     
============================================
- Hits           3740     3736       -4     
+ Misses         3195     3191       -4     
  Partials        316      316
Impacted Files Coverage Δ Complexity Δ
.../fabric8/maven/docker/access/log/LogRequestor.java 80.24% <71.42%> (+2.71%) 13 <1> (ø) ⬇️

@rhuss
Copy link
Collaborator

rhuss commented Mar 12, 2018

@rkhmelichek sorry, for the delay. I'm just on the road, but hopefully will have a look to the PR later on. My plan is to get to it before this weekend, please ping me again, if I dont make it.

@jpraet
Copy link
Contributor

jpraet commented Mar 31, 2018

This also fixes #947

Copy link
Collaborator

@rhuss rhuss left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

thanks a lot for the PR and the analysis, looks perfectly fine for me. Sorry for the long delay, but I nearly forgot this (very important) PR.

I'm going to cut a release this evening or tomorrow morning.

@rhuss rhuss merged commit 6afcb82 into fabric8io:master Apr 3, 2018
@romank8k
Copy link
Contributor Author

romank8k commented Apr 4, 2018

Great, thanks for all your work on this awesome maven plugin!

@rhuss
Copy link
Collaborator

rhuss commented Apr 4, 2018

thanks ;-) fyi, 0.25.0 has just been released, should bubble up to Maven central very soon.

ncelerier added a commit to ncelerier/docker-maven-plugin that referenced this pull request Jun 21, 2021
ncelerier added a commit to ncelerier/docker-maven-plugin that referenced this pull request Jun 21, 2021
rohanKanojia pushed a commit that referenced this pull request Jun 26, 2021
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

Successfully merging this pull request may close these issues.

None yet

3 participants