Skip to content
This repository has been archived by the owner on Mar 21, 2022. It is now read-only.

ApacheUnixSocket throws Unimplemented instead of calling appropriate JNR-unixsocket methods #146

Closed
cholcombe973 opened this issue Mar 24, 2015 · 29 comments

Comments

@cholcombe973
Copy link

I'm running arch linux and I'm unable to get the example working. I'm using docker version:
Docker version 1.5.0, build a8a31ef

URI uri = URI.create(DefaultDockerClient.DEFAULT_UNIX_ENDPOINT);
DockerClient dockerClient = DefaultDockerClient.builder().uri(uri).build();

LOG.info("Ping: " + dockerClient.ping());

It seems to ignore this URI that I give it and tries to connect to localhost:80

[jersey-client-async-executor-0] DEBUG org.apache.http.impl.execchain.MainClientExec - Opening connection {}->unix://localhost:80
[jersey-client-async-executor-0] DEBUG org.apache.http.impl.conn.HttpClientConnectionOperator - Connecting to localhost/127.0.0.1:80
[jersey-client-async-executor-0] DEBUG org.apache.http.impl.conn.DefaultManagedHttpClientConnection - http-outgoing-0: Shutdown connection
[jersey-client-async-executor-0] DEBUG org.apache.http.impl.execchain.MainClientExec - Connection discarded
[jersey-client-async-executor-0] DEBUG org.apache.http.impl.conn.DefaultManagedHttpClientConnection - http-outgoing-0: Close connection
[jersey-client-async-executor-0] DEBUG org.apache.http.impl.conn.PoolingHttpClientConnectionManager - Connection released: [id: 0][route: {}->unix://localhost:80][total kept alive: 0; route allocated: 0 of 100; total allocated: 0 of 100]

Then it fails with this:

com.spotify.docker.client.DockerException: java.util.concurrent.ExecutionException: javax.ws.rs.ProcessingException: java.lang.UnsupportedOperationException: Unimplemented

Any insights? I went deep with the debugger but couldn't figure out why this was happening.

@rohansingh
Copy link
Contributor

localhost:80 here is actually just the dummy host we use when using the Unix sockets stuff. This is because most HTTP-aware libraries (Apache, Jersey, etc.) expect there to be a host, even though that concept doesn't make sense for Unix sockets.

So that Opening connection {}->unix://localhost:80 always gets logged, even when things aren't working. I guess the question is this UnsupportedOperationException — what is it actually being thrown by? Do you have a stack trace?

@cholcombe973
Copy link
Author

Yeah here's the stack trace:

 com.spotify.docker.client.DockerException: java.util.concurrent.ExecutionException: javax.ws.rs.ProcessingException: java.lang.UnsupportedOperationException: Unimplemented
        at com.spotify.docker.client.DefaultDockerClient.propagate(DefaultDockerClient.java:1082)
        at com.spotify.docker.client.DefaultDockerClient.request(DefaultDockerClient.java:1011)
        at com.spotify.docker.client.DefaultDockerClient.ping(DefaultDockerClient.java:274)

        Caused by:
        java.util.concurrent.ExecutionException: javax.ws.rs.ProcessingException: java.lang.UnsupportedOperationException: Unimplemented
            at jersey.repackaged.com.google.common.util.concurrent.AbstractFuture$Sync.getValue(AbstractFuture.java:306)
            at jersey.repackaged.com.google.common.util.concurrent.AbstractFuture$Sync.get(AbstractFuture.java:293)
            at jersey.repackaged.com.google.common.util.concurrent.AbstractFuture.get(AbstractFuture.java:116)
            at com.spotify.docker.client.DefaultDockerClient.request(DefaultDockerClient.java:1009)
            ... 5 more

            Caused by:
            javax.ws.rs.ProcessingException: java.lang.UnsupportedOperationException: Unimplemented

@cholcombe973
Copy link
Author

I should also mention that I do not have the docker remote api enabled. I'm running on arch linux

@davidxia
Copy link
Contributor

Are you running docker? If so, how can you run docker without the docker
remote api? All the docker-client does is speak HTTP[S] to the docker
remote api. Ha, I'm a little confused.

On Tue, Mar 24, 2015 at 12:50 PM, Chris Holcombe notifications@github.com
wrote:

I should also mention that I do not have the docker remote api enabled.
I'm running on arch linux


Reply to this email directly or view it on GitHub
#146 (comment)
.

David Xia
Software Engineer
dxia@spotify.com

@cholcombe973
Copy link
Author

Yup I'm running docker. I probably misspoke about the remote api.

My docker socket looks liked:
ls -lh /var/run/docker.sock
srw-rw---- 1 root docker 0 Mar 24 09:07 /var/run/docker.sock

Here's my systemd files:
docker.service:
1 [Unit]
2 Description=Docker Application Container Engine
3 Documentation=http://docs.docker.com
4 After=network.target docker.socket
5 Requires=docker.socket
6
7 [Service]
8 ExecStart=/usr/bin/docker -d -H fd://
9 MountFlags=slave
10 LimitNOFILE=1048576
11 LimitNPROC=1048576
12
13 [Install]
14 WantedBy=multi-user.target

docker.socket:
1 [Unit]
2 Description=Docker Socket for the API
3 PartOf=docker.service
4
5 [Socket]
6 ListenStream=/var/run/docker.sock
7 SocketMode=0660
8 SocketUser=root
9 SocketGroup=docker
10
11 [Install]
12 WantedBy=sockets.target

@davidxia
Copy link
Contributor

From the stack trace it seems like something is happening at "jersey.repackaged.com.google.common.util.concurrent.AbstractFuture". What version of java are you using?

@cholcombe973
Copy link
Author

java -version
java version "1.7.0_71"
OpenJDK Runtime Environment (IcedTea 2.5.3) (Arch Linux build 7.u71_2.5.3-1-x86_64)
OpenJDK 64-Bit Server VM (build 24.65-b04, mixed mode)

@shevek-nebula
Copy link

Hi, I'm second pair of eyes with Chris on this one:

When we type 'docker ps' at the commandline, we get both docker logs and a response.

When we run the docker test client, we get neither. It appears that Jersey is getting something which is causing it to throw Unimplemented (404?)

The ExecutionException is the consequence of async() going off and setting a SettableFuture. We didn't manage to debug into async() yet. That might be today's exercise - something is clearly going wrong in the async thread and is losing a stack trace.

Is it possible to either
a) Enable more logging in Jersey, so we can see what it thinks it's doing on the client, as it clearly isn't reaching the server?
b) Rewrite the request call, which is actually blocking, to use a synchronous call instead of an async call, and hence avoid the thread transition and future? Or is there some non-obvious reason for using async()?

And we will:
c) Debug into async() if we can.
d) Find out why much of the stack trace went away, and try to get it back. I assume this is because the JVM discards "common frames" when printing a stack trace, but it only knows they're common by count, so setting a cause on another thread's exception tends to fail...

Actually, (d) is the first thing we must do: Don't just log the exception; manually walk the cause chain and log each one. Might be something in there.

@cholcombe973
Copy link
Author

Update: i backed off to version 2.7.0 and that seems to work. I get a ping response back from the docker service.

@rohansingh
Copy link
Contributor

The reason for using async is to make the calls interruptible. That said, you could just rip out the async() part if it helps with debugging. That should definitely simplify things.

Another thing would be to check your docker.log and see if the request from Jersey actually makes it over to Docker at all. That could help narrow down whether it's a connection problem (maybe in in UnixConnectionSocketFactory or somewhere) or a req/rep problem.

@rohansingh
Copy link
Contributor

Interesting that 2.7.0 works. If you have time to do something kind of like git bisect and figure out what version things break at, that could be really useful.

Alternatively, if you're using Maven, perhaps you need the shaded artifact instead of the normal one:
https://github.com/spotify/docker-client#maven

The shaded artifact was the default with v2.7.0, but is not with the latest versions (see link above).

@cholcombe973
Copy link
Author

I'm using gradle for the build.

It looks like version 2.7.18 doesn't reach docker. The docker logs don't show any activity. With 2.7.0 it shows normal activity and gets the ping back.
Let me try a git bisect to see if I can narrow this down.

@rohansingh
Copy link
Contributor

With gradle it would still be the same thing with the shaded artifact being the default prior to v2.7.7. You can explicitly specify the shaded version for 2.7.18 like so: "com.spotify:docker-client:2.7.18:shaded". Might want to try that before you go through every version.

@rohansingh
Copy link
Contributor

Err, take my advice on gradle with a bit of salt actually — syntax might be wrong. But the basic idea is that you want to specify shaded as the dependency classifier.

@cholcombe973
Copy link
Author

2.7.6 is the broken version. I'll bisect to see what I can find.

@cholcombe973
Copy link
Author

2.7.5 works OK. :)

@rohansingh
Copy link
Contributor

This was introduced in 2.7.6:
335bfee

@shevek-nebula
Copy link

Heh. While I really love JNR and its implementations and policies, the gesellix unix socket code has always been my favourite for that particular task. We're working on finding you more information about this bug.

@shevek-nebula
Copy link

java.lang.UnsupportedOperationException: Unimplemented
at com.spotify.docker.client.ApacheUnixSocket.getRemoteSocketAddress(ApacheUnixSocket.java:103)
at org.apache.http.impl.BHttpConnectionBase.toString(BHttpConnectionBase.java:380)
at java.lang.String.valueOf(String.java:2847)
at java.lang.StringBuilder.append(StringBuilder.java:128)
at org.apache.http.impl.conn.HttpClientConnectionOperator.connect(HttpClientConnectionOperator.java:127)
at org.apache.http.impl.conn.PoolingHttpClientConnectionManager.connect(PoolingHttpClientConnectionManager.java:318)
at org.apache.http.impl.execchain.MainClientExec.establishRoute(MainClientExec.java:363)
at org.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:219)
at org.apache.http.impl.execchain.ProtocolExec.execute(ProtocolExec.java:195)
at org.apache.http.impl.execchain.RetryExec.execute(RetryExec.java:86)
at org.apache.http.impl.execchain.RedirectExec.execute(RedirectExec.java:108)
at org.apache.http.impl.client.InternalHttpClient.doExecute(InternalHttpClient.java:184)
at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:72)
at org.glassfish.jersey.apache.connector.ApacheConnector.apply(ApacheConnector.java:469)
at org.glassfish.jersey.apache.connector.ApacheConnector$1.run(ApacheConnector.java:527)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at jersey.repackaged.com.google.common.util.concurrent.MoreExecutors$SameThreadExecutorService.execute(MoreExecutors.java:293)
at jersey.repackaged.com.google.common.util.concurrent.AbstractListeningExecutorService.submit(AbstractListeningExecutorService.java:49)
at jersey.repackaged.com.google.common.util.concurrent.AbstractListeningExecutorService.submit(AbstractListeningExecutorService.java:45)
at org.glassfish.jersey.apache.connector.ApacheConnector.apply(ApacheConnector.java:523)
at org.glassfish.jersey.client.ClientRuntime$1.run(ClientRuntime.java:169)
at org.glassfish.jersey.internal.Errors$1.call(Errors.java:271)
at org.glassfish.jersey.internal.Errors$1.call(Errors.java:267)
at org.glassfish.jersey.internal.Errors.process(Errors.java:315)
at org.glassfish.jersey.internal.Errors.process(Errors.java:297)
at org.glassfish.jersey.internal.Errors.process(Errors.java:267)
at org.glassfish.jersey.process.internal.RequestScope.runInScope(RequestScope.java:320)
at org.glassfish.jersey.client.ClientRuntime$2.run(ClientRuntime.java:201)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.run(FutureTask.java:262)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745) 

@cholcombe973
Copy link
Author

apache httpclient version:
+--- com.spotify:docker-client:2.7.6
| +--- org.slf4j:slf4j-api:1.7.6 -> 1.7.7
| +--- com.google.guava:guava:17.0 -> 18.0
| +--- org.apache.commons:commons-compress:1.8.1
| +--- org.apache.httpcomponents:httpclient:4.3.5 (*)
| +--- commons-lang:commons-lang:2.4 -> 2.6
| --- org.bouncycastle:bcpkix-jdk15on:1.51
| --- org.bouncycastle:bcprov-jdk15on:1.51

@cholcombe973
Copy link
Author

@cholcombe973 cholcombe973 changed the title Unable to get the example working ApacheUnixSocket throws Unimplemented instead of calling appropriate JNR-unixsocket methods Mar 24, 2015
@rgrunber
Copy link
Contributor

Hey, sorry for missing this thread. I've run into this exact issue. In order for it to happen, one must be using httpclient > 4.3.2 and there needs to be some package that enables debug-level logging. Basically httpclient added an extra debug statement to print out connection information ( https://issues.apache.org/jira/browse/HTTPCLIENT-1462, apache/httpcomponents-client@338b0bd ). This seems to attempt to call getRemoteSocketAddress().

I started implementing some more methods that might be called somehow by other parts of httpclient : rgrunber@a9ca94e but got sidetracked for a while with other things so didn't have the chance to open a pull request. If it looks reasonable to you, I could open a pull request for review.

@cholcombe973
Copy link
Author

I'd love to review a pull request but I can't verify any longer that it works. The source I was working on a nebula is now gone. The company closed down :(

@davidxia
Copy link
Contributor

Is this still an issue for folks?

@rgrunber
Copy link
Contributor

I can reproduce by running

mvn clean verify -Dorg.apache.commons.logging.Log=org.apache.commons.logging.impl.SimpleLog -Dorg.apache.commons.logging.simplelog.log.org.apache.http.impl.conn.HttpClientConnectionOperator=DEBUG

from the master branch. The build should fail with the various test runs hitting

java.util.concurrent.ExecutionException: javax.ws.rs.ProcessingException: java.lang.UnsupportedOperationException: Unimplemented

If I apply rgrunber/docker-client@a9ca94e and re-run the command, things seem to work as expected.

@SaschaMoellering
Copy link

Yes, not working for me.

davidxia pushed a commit that referenced this issue Jun 6, 2015
ApacheUnixSocket provides API for a client to communicate with an
existing unix socket, so the API related to the server-side 'bind'
command isn't necessary. They can simply be made to return whichever
values indicate an unbound state.

Fixes #146
davidxia pushed a commit that referenced this issue Jun 6, 2015
ApacheUnixSocket provides API for a client to communicate with an
existing unix socket, so the API related to the server-side 'bind'
command isn't necessary. They can simply be made to return whichever
values indicate an unbound state.

Fixes #146
@davidxia
Copy link
Contributor

davidxia commented Jun 6, 2015

@rgrunber I'm unable to repro on my machine (Mac OSX 10.10.3, boot2docker 1.6.0, docker 1.6.0) with the command you gave above.

Nonetheless, I opened a PR here (#191).

@SaschaMoellering @cholcombe973 @shevek-nebula can you guys try the PR out and see if it fixes the issue for you?

@SaschaMoellering
Copy link

@davidxia On my Mac it's working perfectly fine, I just have problems on our Jenkins slaves running Debian Linux. Thanks for the PR, I'll try it.

@SaschaMoellering
Copy link

This seems to solve the problem, thx.

Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Projects
None yet
Development

No branches or pull requests

6 participants