MonitoredResourceUtil#getResource throws error when running locally

[averikitsch]

Environment details

1. Specify the API at the beginning of the title. For example, "BigQuery: ...").
   General, Core, and Other are also allowed as types
2. OS type and version: MacOS
3. Java version: 11
4. logging version(s): 2.3.1

Steps to reproduce

Call MonitoredResourceUtil.getResource() directly or through using LoggingHandler.addHandler(LOGGER, new LoggingHandler()); for example with java.util.logging.Logger.

When running locally in a docker container, this library throws a NullPointerException due to the "zone" being null:

PORT=8080 && docker run \
-p 9090:${PORT} \
-e PORT=${PORT} \
-e K_SERVICE=dev \
-e K_CONFIGURATION=dev \
-e K_REVISION=dev-00001 \
-e GOOGLE_APPLICATION_CREDENTIALS=/tmp/keys/key.json \
-v $GOOGLE_APPLICATION_CREDENTIALS:/tmp/keys/key.json:ro \
java-log-test

Code example

private final static Logger LOGGER = Logger.getLogger("HelloWorldApplication");
LoggingHandler.addHandler(LOGGER, new LoggingHandler());
LOGGER.log(new LogRecord(Level.FINEST, "my message!"));

Stack trace

java.util.logging.ErrorManager: 4
java.lang.NullPointerException
	at com.google.cloud.logging.MonitoredResourceUtil.getCloudRunLocation(MonitoredResourceUtil.java:257)
	at com.google.cloud.logging.MonitoredResourceUtil.getValue(MonitoredResourceUtil.java:175)
	at com.google.cloud.logging.MonitoredResourceUtil.getResource(MonitoredResourceUtil.java:133)
	at com.google.cloud.logging.LoggingConfig.getMonitoredResource(LoggingConfig.java:80)
	at com.google.cloud.logging.LoggingHandler.<init>(LoggingHandler.java:182)
	at com.google.cloud.logging.LoggingHandler.<init>(LoggingHandler.java:151)
	at com.google.cloud.logging.LoggingHandler.<init>(LoggingHandler.java:120)
	at com.example.helloworld.HelloworldApplication$HelloworldController.hello(HelloworldApplication.java:53)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
	at java.base/java.lang.reflect.Method.invoke(Unknown Source)
	at org.springframework.web.method.support.InvocableHandlerMethod.doInvoke(InvocableHandlerMethod.java:197)
	at org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:141)
	at org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:106)
	at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:894)
	at org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:808)
	at org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:87)
	at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:1063)
	at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:963)
	at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:1006)
	at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:898)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:655)
	at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:883)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:764)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:228)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:163)
	at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:53)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:190)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:163)
	at org.springframework.web.filter.RequestContextFilter.doFilterInternal(RequestContextFilter.java:100)
	at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:190)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:163)
	at org.springframework.web.filter.FormContentFilter.doFilterInternal(FormContentFilter.java:93)
	at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:190)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:163)
	at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:201)
	at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:119)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:190)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:163)
	at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:202)
	at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:97)
	at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:542)
	at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:143)
	at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:92)
	at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:78)
	at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:357)
	at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:382)
	at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:65)
	at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:893)
	at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1723)
	at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
	at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
	at java.base/java.lang.Thread.run(Unknown Source)
2021-07-02 17:32:31.242 ERROR 1 --- [nio-8080-exec-1] o.a.c.c.C.[.[.[/].[dispatcherServlet]    : Servlet.service() for servlet [dispatcherServlet] in context with path [] threw exception [Request processing failed; nested exception is java.lang.NullPointerException] with root cause

[minherz]

@averikitsch can you provide the rest of the configuration like what Logger do you use, its configuration together with the handler implementation?

Thank you

[averikitsch]

@averikitsch can you provide the rest of the configuration like what Logger do you use, its configuration together with the handler implementation?

Thank you

See Steps to reproduce or Add a Cloud Logging handler to a logger

[minherz]

I am sorry, @averikitsch but I cannot reproduce the error. Would it be possible for you to capture all steps starting with git clone command? From the call stack it looks like you do not run the example but try to use it within some Web app that runs over Spring.
The usual reason for this failure is when a client identifies an environment as GCE and expect to access a metadata server and pull some information. Would it be possible for you to try and run the example locally and let us know if your reproduce the problem?

[averikitsch]

Hi I've pushed the code here: https://github.com/averikitsch/java-docs-samples/tree/cloud-logging/run/helloworld.
You can build the container: docker built -t java-log-test .
Then run the container (make sure to have ADC set via an env var):

PORT=8080 && docker run \
-p 9090:${PORT} \
-e PORT=${PORT} \
-e K_SERVICE=dev \
-e K_CONFIGURATION=dev \
-e K_REVISION=dev-00001 \
-e GOOGLE_APPLICATION_CREDENTIALS=/tmp/keys/key.json \
-v $GOOGLE_APPLICATION_CREDENTIALS:/tmp/keys/key.json:ro \
java-log-test

Then go to: http://localhost:9090/

The failure makes sense, since we are running locally and there is no metadata server. However, this shouldn't throw an error, it should gracefully handle the lack of metadata server or try to retrieve more info from the local environment.

[minherz]

Thank you, @averikitsch . After reviewing it, the core reason for the failure is that the described way to run the application confuses a resource type auto-detecting mechanism. You can mitigate this behavior by explicitly defining the com.google.cloud.logging.LoggingHandler.resourceType to be "global" or "k8s_container".

There is a work in progress to improve the auto-detection mechanism which will resolve a situation when emulated CloudRun fails due to lack of connectivity to a metadata server.

[minherz]

@simonz130 should we keep this bug and to close it after finishing the work on the auto-detection, WDYT?

[simonz130]

We discussed changing the behavior of Resource Auto-detection to be:

1. Ask metadata server. If getting response - set the resource accordingly and stop
2. If no response/error - try env vars detection. If set - set the resource and stop
3. If env var is not set - set the resource type as global.

If we change the implementation this way, it will eliminate the null ref.
I suggest we do it and then close the bug when merged.

[minherz]

A question remains to what resource type the log entries should be tagged if the app runs like described: using environment variables to fake Cloud Run environment. Should it be tagged as a cloud run but without resource name, project, location, etc?

[minherz]

New resource type discovery resolves the described case (#708). Placing validation of the metadata server as part of the detection mechanism will report local environment as "global" resource type unless a user provides a custom resource type explicitly via WriteOption.resource() construction method.