Update protobuf/grpc/tcnative dependencies

[garrettjonesgoogle]

Grpc: Now = 1.0.3; update to 1.2.0
Protobuf: Now = 3.0.0 & 3.0.2 (depending on where); update to 3.2.0
netty-tcnative: Now = 1.1.33.Fork19; update to 1.1.33.Fork26

Note: this also involves updating the generated grpc packages and gax.

[garrettjonesgoogle]

Also do googleapis/gax-java#186 while we're at it (move from grpc-all to more minimal grpc dependency set)

[kinow]

I'd suggest updating netty-tcnative to 2.x as per netty/netty#5766

Right now it is blocking using 0.9.4-alpha (or 0.8.0 or 0.7.0) in Linux+Tomcat / SpringBoot+TomcatEmbeddedServletContainer / or Elastic Beanstalk + Tomcat8

[garrettjonesgoogle]

@kinow , Is it blocking because of conflicting netty versions? What version of netty does your version of Tomcat depend on?

[kinow]

I have successfully deployed the application using Jetty, and packaging it as an executable war. I'm in the process of creating a smaller example that can be uploaded to GitHub, and also a blog post about it.

My guess is that google-cloud-java is using a version of netty lower than 2.x. Because of that this application is loading a version of netty-tcnative-boringssl-static that loads a class in a package from Apache Tomcat.

What happens in this application, is that it successfully starts up with Spring Boot, then during my first request it will create the authentication tokens and submit the first request. This request is simply never processed, and after a few moments I will see a DEADLINE_EXCEEDED exception (IIRC, at home right now).

I believe that updating to netty-tcnative 2.x, this issue will be gone, and google-cloud-java should be fully compatible with Spring Boot + Tomcat.

[kinow]

Here's an example project.

https://github.com/kinow/gs-spring-boot/tree/reproduce-google-nlp-issue/complete

Here's the diff: spring-guides/gs-spring-boot@master...kinow:reproduce-google-nlp-issue

I forked the Spring Boot Getting Started sample application, which is using the latest version of Spring Boot. Created a branch, and added google-cloud-language 0.9.4-alpha (used the sample code from https://cloud.google.com/natural-language/docs/samples).

If you start the original project with mvn clean spring-boot:run, you will see a page with just the "Greetings from Spring Boot!" text. Starting the branch (you may have to export JSON credentials location via envVar), instead of seeing that message, you will get a Whitelabel Error Page (default error handler page for SpringBoot apps). Looking at the logs, you will find the following exception:

io.grpc.StatusRuntimeException: DEADLINE_EXCEEDED
	at io.grpc.Status.asRuntimeException(Status.java:545) ~[grpc-core-1.0.3.jar:1.0.3]
	at io.grpc.stub.ClientCalls$UnaryStreamToFuture.onClose(ClientCalls.java:442) ~[grpc-stub-1.0.3.jar:1.0.3]
	at io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl.close(ClientCallImpl.java:481) ~[grpc-core-1.0.3.jar:1.0.3]
	at io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl.access$600(ClientCallImpl.java:398) ~[grpc-core-1.0.3.jar:1.0.3]
	at io.grpc.internal.ClientCallImpl$ClientStreamListenerImpl$1StreamClosed.runInContext(ClientCallImpl.java:513) ~[grpc-core-1.0.3.jar:1.0.3]
	at io.grpc.internal.ContextRunnable.run(ContextRunnable.java:52) ~[grpc-core-1.0.3.jar:1.0.3]
	at io.grpc.internal.SerializingExecutor$TaskRunner.run(SerializingExecutor.java:154) ~[grpc-core-1.0.3.jar:1.0.3]
	at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) ~[na:1.8.0_121]
	at java.util.concurrent.FutureTask.run(FutureTask.java:266) ~[na:1.8.0_121]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) ~[na:1.8.0_121]
	at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) ~[na:1.8.0_121]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) ~[na:1.8.0_121]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) ~[na:1.8.0_121]
	at java.lang.Thread.run(Thread.java:745) [na:1.8.0_121]

In the branch pom.xml, I added the entries to use Jetty instead of Tomcat embedded container. Uncommenting those lines and running again with mvn clean spring-boot:run, you will have Jetty embedded container, which works fine with Google Cloud NLP API.

Adding an exclusion to io.netty:netty-tcnative-boringssl-static to google-cloud-language does not work. The issue persists, and you still get a DEADLINE EXCEEDED exception.

I've cloned the google-cloud-java locally. Updated all dependencies as suggested in this issue, except for Grpc which was breaking the tests, installed a snapshot locally, and updated the example to use google-cloud-java:0.9.5-alpha-SNAPSHOT. All tests in google-cloud-java passed, and the application also started up successfully, but the issue persisted.

Simply updating netty-tcnative to 2.x won't fix the issue. My guess now is that with a version of grpc-netty (and hence a newer version of netty, compatible with netty-tcnative 2.x) the issue may be fixed. Will file a new issue for that, once I have some more time to debug the problem. Sorry for hijacking this issue.

Bruno

[garrettjonesgoogle]

This is blocked on artman updates to fix grpc package generation (googleapis/gapic-generator#803). cc @shinfan

[buchgr]

@kinow
the DEADLINE_EXCEEDED and any netty-tcnative issues seem unrelated.

• gRPC uses netty-tcnative to use openssl/boringssl instead of the JDK's (slower) TLS implementation.
• The gRPC protocol supports deadlines/timeouts, so that when making an RPC call you can set an upper limit on how long this call may take, if this time is exceeded you get the DEADLINE_EXCEEDED. Google Cloud NLP is likely just setting a timeout somewhere.

So while an updated tcnative might fix your tomcat issues, it won't fix any DEADLINE_EXCEEDED errors.

[kinow]

@buchgr

You could be right. If I find time next week I will debug what happens in the Google Cloud NLP API. So far what I noticed is that when using Tomcat with Google Cloud NLP, I can see that it

• instantiates the channel and executors thread
• successfully finds the credentials and crafts a request payload
• an asynchronous request is sent (or prepared to be sent? will use Wireshark or debug in Eclipse next time)
• the timeout expires (agree with what you said about a timeout being set somewhere), and then I receive the DEADLINE_EXCEEDED exception.

When I replace Tomcat by Jetty, the three first steps are successfully executed. And then the fourth step (where DEADLINE_EXCEEDED exception happens) works with no exception.

The first time I debugged in Eclipse I noticed either in the console or logs, a message with a Google Cloud URL and the 443 (can't really remember off the top of my head, but it was something like "opening connection to cloud.google.com 443").

Next time I debug it, I will work with the hypothesis that when I use Tomcat; some thing (interface/class/service loader/native library/etc) provided by both netty-tcnative and Tomcat fails when it tries to open a SSL connection to the google cloud server. Then either the connection is never successfully established, or maybe something else happens, and the Future class times out.

First thing I will do is probably fire Wireshark and just see what client / server are sending with Jetty and with Tomcat.

Cheers
Bruno

[kinow]

Had some time before going to sleep. Running the sample application with Tomcat embedded container, I still get the DEADLINE_EXCEEDED exception. Filtering packages in wireshark (query: (ip.src eq 192.168.20.3 and tcp.dstport eq 443 and ip.dst eq 172.217.25.45) or ip.src eq 172.217.25.45), I can see some TCP packages being transmitted. Among the initial ones I can see one that contains accounts.google.com.

So client is sending the packages to the server. For some reason it is getting stuck and timing out.

[garrettjonesgoogle]

cc @ejona86 here is another example of the DEADLINE_EXCEEDED issue.

@buchgr and @kinow , this is very likely caused by an issue with loading netty-tcnative, similar to #1430 and #1772 . Basically when netty-tcnative doesn't load right, there is some misbehavior somewhere and grpc accepts the request but it never successfully gets issued, so the only thing that stops it is whatever timeout is set. I filed issue grpc/grpc-java#2599 against grpc-java asking for them to make the error messaging more accurate.

To be sure, you need to set your logging level to FINE to see if you see logs that say Unable to load the library: netty-tcnative-linux-x86_64.