Can't see my custom logs in Google App Engine

Question

I'm trying to do some simple logging in GAE, though I think I must be missing some simple step.

I have followed the instructions here: https://developers.google.com/appengine/docs/java/runtime#Logging

I wish to write a simple message to the log, like so:

public class InsertServlet extends HttpServlet {
    private static final long serialVersionUID = 1L;
    private static final Logger log = Logger.getLogger(InsertServlet.class.getName());

    public void doGet(HttpServletRequest req, HttpServletResponse resp) throws IOException {

            log.info("Handled GET request - custom message");
            resp.setContentType("text/plain");
            resp.getWriter().println("HELLO");

    }

}

If I visit my app with the web browser, I can see that it is working (get the "HELLO" message in the browser).

However after this, if I visit the logs in the console, I can see that it is logging the event, but I don't see my message anywhere.

I have selected "Show: All Requests", but this is all I see in the logs after my visit:

012-08-19 13:34:56.488 /insert 200 2922ms 0kb Mozilla/5.0 (Windows NT 6.1; WOW64; rv:14.0) Gecko/20100101 Firefox/14.0.1

2602:306:ce97:de40:8dbd:ace7:14c3:89e2 - - [19/Aug/2012:13:34:56 -0700] "GET /insert HTTP/1.1" 200 52 - "Mozilla/5.0 (Windows NT 6.1; WOW64; rv:14.0) Gecko/20100101 Firefox/14.0.1" "karwosts-helloworld.appspot.com" ms=2923 cpu_ms=1213 api_cpu_ms=0 cpm_usd=0.000006 loading_request=1 instance=00c61b117cf339fa358dc217b91a9f45b8c30f

I 2012-08-19 13:34:56.487

This request caused a new process to be started for your application, and thus caused your application code to be loaded for the first time. This request may thus take longer and use more CPU than a typical request for your application.

Logging.Properties (only one line):

.level = WARNING

appengine-web.xml

<?xml version="1.0" encoding="utf-8"?>
<appengine-web-app xmlns="http://appengine.google.com/ns/1.0">
  <application>karwosts-helloworld</application>
  <version>1</version>

  <threadsafe>true</threadsafe>

  <!-- Configure java.util.logging -->
  <system-properties>
    <property name="java.util.logging.config.file" value="WEB-INF/logging.properties"/>
  </system-properties>

</appengine-web-app>

Where is my custom log.info string? Am I not looking at the right place?

Answer 1

A first glance, I would say that as you use this setup in your "logging.properties" file :

.level = WARNING

And, you (don't specify any level when you log in your code, the default level would be used, which is certainly not 'WARNING' (I would guess INFO^^) do specify a logging level with this line :

log.info(msg);

/* which is same as */
log.log(Level.INFO, msg);

So the result is that you log only at 'INFO' level (in your example), but your config file says to log at WARNING level and above. As 'info' level is below 'warning', they are discarded from you log file and not shown in your server's log.

I suggest trying this method instead, which forces you to specify the level of logging.

import java.util.logging.Level;
import java.util.logging.Logger;
/* ... */
log.log(Level.INFO, "a info msg"); //info
log.log(Level.WARNING, "a warning msg"); //warning
log.log(Level.FINEST, "a fine(st) msg"); //debug (as finest)

After that you can use the logging.properties file to set the levels of logging you want for the classes you want :

# Set the default logging level for all loggers to WARNING
.level = WARNING

# Set level for your app
oed.server.level = INFO
oed.server.data.datastore.myInjector.level = FINEST

---

Edit2 : This logging configuration has no impact when running on the client side. When you want to log message in GWT, there is this GWT.log(message);, but no level can be specified.

It's no entirely correct, it depends on the configuration in the your-app.gwt.xml file. All details can be found on google dev guilde logging. I found it very usefull and well done. Still, in a nut shell, there are various default loggers in GWT (around 5-6); all are configurable in the *.gwt.xml through their handlers (or can be done pragmatically). After having the invasive popup logger been there for too long ... I choose to remotely log from the client to the server to enjoy the use of logging.properties, here is the config when using gwt.xml:

<!-- Logging configuration -->
  <inherits name="com.google.gwt.logging.Logging"/>

  <set-property name="gwt.logging.logLevel" value="INFO"/>  <!-- # To change the default logLevel -->
  <set-property name="gwt.logging.enabled" value="TRUE"/>  
  <set-property name="gwt.logging.simpleRemoteHandler" value="ENABLED" /> <!-- Remote logging (linked with servlet) -->
  <set-property name="gwt.logging.popupHandler" value="DISABLED" />
  <set-property name="gwt.logging.developmentModeHandler" value="ENABLED" />  
  <set-property name="gwt.logging.systemHandler" value="ENABLED" />
  <set-property name="gwt.logging.firebugHandler" value="DISABLED" />
  <set-property name="gwt.logging.consoleHandler" value="ENABLED"/>

If you use this setup, don't forget to configure your web.xml with a servlet definition to handle the logging (it's not provided in the documentation, sadly) :

<servlet>
        <servlet-name>remoteLogging</servlet-name>
        <servlet-class>com.google.gwt.logging.server.RemoteLoggingServiceImpl</servlet-class>
    </servlet>
    <servlet-mapping>
        <servlet-name>remoteLogging</servlet-name>
        <url-pattern>/your-app-name/remote_logging</url-pattern>
    </servlet-mapping>

---

Good luck !