com.google.cloud.logging.LoggingException: io.grpc.StatusRuntimeException: DEADLINE_EXCEEDED while using Stackdriver logging library

[sanumandla]

Hi,

I have been experiencing an issue which is blocking me from writing logs to Stackdriver. I see an exception saying "SEVERE: RuntimeException while executing runnable com.reltio.gcp.google.common.util.concurrent.Futures$6@7a04e1cd with executor MoreExecutors.directExecutor()
java.lang.RuntimeException: com.google.cloud.logging.LoggingException: io.grpc.StatusRuntimeException: DEADLINE_EXCEEDED"

The issue happens only when we deploy a war file to tomcat. We can resolve this issue by adding ALPN jar to tomcat bootstrap file but it's not a feasible solution for us. Other approach is to add the following dependency which seemed to work until few days back but for some reason started failing.

<dependency>
    <groupId>io.netty</groupId>
    <artifactId>netty-tcnative-boringssl-static</artifactId>
    <version>1.1.33.Fork26</version>
</dependency>

I am using google-cloud-logging v1.2.0. I tried using the latest version (1.6.0) but see "Caused by: java.lang.IllegalArgumentException: Jetty ALPN/NPN has not been properly configured."

Attached are the screenshots with stacktace.

This seems to be client library related issues. Any suggestions are highly appreciated.

Thanks

[pongad]

For v1.6.0, could you try updating the tcnative dependency to 2.0.3-Final like we did here?

You said adding dependency worked until a few days back. Did it stop working after changing version? It seems unlikely that the same build randomly breaks.

[sanumandla]

@pongad Thanks for your inputs. Yes, I tried 2.0.3.Final. Actually, I haven't changed anything. But my guess is there are lot of google dependencies that are being pulled into the project as transitive dependencies. Something in the downstream project changed which is affecting it. Before when I encountered this issue I noticed that netty-tcnative-boringssl-static is being excluded. After adding it, the resolve got resolved. But unfortunately something changed and I started to see this issue again.

<dependency>
      <groupId>io.netty</groupId>
      <artifactId>netty-tcnative-boringssl-static</artifactId>
      <version>2.0.3.Final</version>
    </dependency>

Thank you

[pongad]

I see. I'll work to reproduce this.

[pongad]

@sanumandla I unfortunately cannot reproduce this issue. I created a fresh maven package and added dependency

  <dependencies>
    <dependency>
      <groupId>com.google.cloud</groupId>
      <artifactId>google-cloud</artifactId>
      <version>0.23.0-alpha</version>
    </dependency>
  </dependencies>

I then copied this sample code and executed it. It executed successfully and I can see the log "message" in my cloud console.

Could it be that some other dependency is conflicting with ours...?

[sanumandla]

@pongad Yes, my suspicion is it's interfering with some other libraries. Couldn't figure out what it could be. Some more context

1. When I run this code from tests everything works fine. The issue happens when I deploy to tomcat. Tried both tomcat 7 and 8
2. When I created a sample maven project with SpringBoot and embedded tomcat, initially I saw the same issue. But some online post recommended to order the dependencies i.e., move google-cloud-logging dependency before loading spring boot dependencies. After making that change everything worked fine. But in my current project we use Spring and deploy the war to tomcat. So I cannot control the order of dependencies as well.

I use other google services as well, SD monitoring and error reporting

<dependency>
            <groupId>com.google.apis</groupId>
            <artifactId>google-api-services-monitoring</artifactId>
            <version>v3-rev406-1.22.0</version>
</dependency>
<dependency>
            <groupId>com.google.cloud</groupId>
            <artifactId>google-cloud-logging</artifactId>
            <version>1.2.0</version>
</dependency>
<dependency>
            <groupId>com.google.apis</groupId>
            <artifactId>google-api-services-clouderrorreporting</artifactId>
            <version>v1beta1-rev269-1.22.0</version>
</dependency>

Here is the code that I use

Logging logging = LoggingOptions.newBuilder()
                    .setProjectId(projectId)
                    .setCredentials(reltioCredentialProvider.getCredentialsForLogging())
                    .build()
                    .getService();
LogEntry entry = LogEntry.newBuilder(Payload.JsonPayload.of(errorMap))
                .setLogName(getLogName())
                .setSeverity(getSeverity(loggingEvent.getLevel()))
                .setResource(getMonitoredResource())
                .build();
logging.write(Collections.singleton(entry), Logging.WriteOption.labels(ImmutableMap.of(
                        TENANT_ID, tenantId,
                        ENVIRONMENT, environment,
                        CLASS, className

Thank you

[pongad]

I have the following suspicion:

The error "Jetty ALPN/NPN has not been properly configured" is usually caused by gRPC not being able to find SSL libraries. Our libraries declare dependency on boringssl to satisfy this. This explains why you don't see it during tests.

Maybe that dependency gets removed from the classpath when you deploy to tomcat?

@vam-google You're more knowledgeable than I am about classpaths, do you think we're on the right track?

[sanumandla]

Hi,

@pongad I checked my dependency tree and boringssl is being picked up. But how can I make sure that the jar is picked up during runtime while deploying to tomcat if that is the case ?

One solution is to drop in jar to tomcat libs which is not a feasible solutions for production deployments.

Please share your thoughts. Thank you

[vam-google]

Hi @sanumandla. It is really hard to tell for sure what is happening, but here are some suggestions:

Try to add google-cloud-java root pom as BOM (bill of materials) in your pom:

<dependencyManagement>
  <dependencies>
    <dependency>
      <groupId>com.google.cloud</groupId>
      <artifactId>google-cloud-pom</artifactId>
      <version>0.23.0-alpha</version>
      <type>pom</type>
      <scope>import</scope>
    </dependency>
  </dependencies>
</dependencyManagement>

Check in runtime the actual jars added to your classpath (after it went through all the custom classloaders, used by tomcat). For example, if the used classloaders are URLClassLoaders, you can use the following servlet code to output runtime information about your environment (or modify the code accordingly, if the classloader is of different type):

@WebServlet(value = "/info")
public class GaeInfoServlet extends HttpServlet {

  private static final long serialVersionUID = -3598229312089602597L;

  @Override
  protected void doGet(HttpServletRequest req, HttpServletResponse resp)
      throws ServletException, IOException {
    resp.setContentType("text");
    PrintWriter out = resp.getWriter();

    ClassLoader cl = getClass().getClassLoader();
    out.append("CLASS LOADER:\n\n");
    out.append("Name: ").append(cl != null ? cl.getClass().getName() : null).append('\n');
    if (cl instanceof URLClassLoader) {
      URLClassLoader urlCl = (URLClassLoader) cl;
      out.append("Urls: ").append('\n');
      for (URL url : urlCl.getURLs()) {
        out.append(url.toString()).append('\n');
      }
    }

    out.append("\nENVIRONMENT VARIABLES:\n\n");
    Map<String, String> envVars = System.getenv();
    for (Map.Entry<String, String> entry : envVars.entrySet()) {
      out.append(entry.getKey()).append("=").append(entry.getValue()).append('\n');
    }

    out.append("\n\nSYSTEM PROPERTIES:\n\n");
    System.getProperties().list(out);

    out.close();
  }
}

This should allow you to check which netty-tcnative library is actually used in your appliation during runtime (if any).

I don't know many details about tcnative library, but it seems suspicious: netty-tcnative is a tomcat library fork, that we have dependency on, and at the same time, since you are running your app in tomcat, maybe tomcat itself automatically provides a version of that library for you "for free", and there can be a conflict of that sort (this is all just guesses and speculations, but I would not be surprised if the actual situation is similar to that).

[vam-google]

You may want to check the google-cloud-java/google-cloud-testing/google-cloud-managedtest module (and try to deploy it in your env), which is used for testing and troubleshooting google-cloud-java in managed environments (the servlet code above is copied from that module). That module is just a servlet, which allows you to deploy it in a managed environment (tomcat/jetty), and then run google-cloud-java tests in it and check environment information (classloaders, system properties etc).

[lesv]

grpc/grpc-java#3025 is the canonical issue for this.

[pongad]

I'll close this as duplicate. Please reopen if required.