Tuesday, 6 November 2012

The art of GWT logging

Basic option – GWT.log()

From the early times GWT provides one all purpose log method. GWT.log(“something something”). It is very basic, a static method requiring no special set up. List of benefits ends here.
Test of endurance is even to find the log. Nothing is printed to standard output. Nowhere to configure it. Numerous developers gave up here and resulted in all time favourite System.out.println().
The logs are displayed in Development Mode – an Eclipse view – in a form of bullet list! See the screenshot. If you click on it, you get the details like timestamp. It is easy to overlook. The is one nice feature compared to standard console – as-you-type filter. If you don't use Eclipse, or in older versions of the plugin, small helper Swing application showed them – GWT Shell.
What about web browsers? They do have various developer tools. Firefox has facility, called Web Console (Ctrl+Shift+K), it is to be found in main menu under Web Developer. However this console does not display GWT.log() messages. Similar functionality can be found in Chromium (Tools → JavaScript Console or Developer Tools). Same tool, same result, nothing is displayed from GWT.log(). Same with IE.
I don't have Firebug installed so I can tell if this plugin helps. Is it still considered the best product of its kind?
Also note, that log(), the very method calls, are automatically removed in Production Mode builds.

Proper GWT logging

So how we can see our logs? Conveniently in a web browser, in a console? We need to look for something more featured. Meet GWT Logger library.
GWT logging is based on standard Java Logging interfaces.
import java.util.logging.Logger;
In module configuration file (gwt.xml) needs to be set up:
<inherits name="com.google.gwt.logging.Logging" />
<set-property name="gwt.logging.logLevel" value="INFO"/>
<set-property name="gwt.logging.enabled" value="TRUE"/>
<set-property name="gwt.logging.consoleHandler" value="ENABLED"/>
<set-property name="gwt.logging.popupHandler" value="DISABLED" /><!-- LoggingPopup -->
<set-property name="gwt.logging.simpleRemoteHandler" value="DISABLED" />
This configuration cause logs to be printed only in to standard output, that is usually Eclipse console window.
Java code example:
import java.util.logging.Logger;

public final Logger logger = Logger.getLogger("test");
public void onModuleLoad() {
. . .
logger.info("Module is loading");
. . .
Or more conventional logger naming:
public final Logger logger = Logger.getLogger(MyModule.class.getName());
Note: Class.getSimpleName() and other similar methods (?) are not supported by GWT. You get run time exception if attempted. I often fall for this trick.
Now you can see your logs in console. Assuming you are in Developer Mode. Besides standard output, log messages are now printed to JavaScript console in Chrome or Chromium and Web Console in Firefox. I did not managed to see my logs in Internet Explorer 9, in its Developer Tools (F12), unfortunately. I am not much familiar with IE though.

LoggingPopup

Also known as popupHandler, after its configuration option name, or PopupLogHandler* - name creating an impression of a class, but no such class exists. The only relevant class is LoggingPopup and it does not implements a Logger Handler. It is a widget. It is a complex widget extending PopupPanel.
It is quite confusing since there are classes like ConsoleLogHandler or SimpleRemoteLogHandler with (mostly) matching names to logging properties and all of them are Handlers by nature. To make LoggingPopup a Handler, it needs to be wrapped using HasWidgetsLogHandler. Only after that it can be added to the Logger.
The LoggingPopup is by default enabled, the dialog box is always visible and is quite obtrusively visible, from the very start of the application, positioned on 0,0, potentially obscuring your content or breaking your layout. It is advisable step to switch it off in module configuration. However, the LoggingPopup has a valid usage. It can be shown only when needed and where needed. See my example below. See the screenshot.
Note: LoggingPopup is kind of competitor to my gwt-flexible-panel! It is draggable and resizable. And I would say my Panel is better ;)
*Note: see http://www.tutorialspoint.com/gwt/gwt_logging_framework.htm, clearly they mention PopupLogHandler in the listing table despite no such class exists.

How to explicitly show and position PopupLogger

When PopupLogger is disabled globally, it can be displayed only on explicit request, when is really needed. And you can also specify where to display it. It comes handy sometimes. See my example with logging mouse events. Originally the logger box overlapped both tested panels completely, they were not visible at all. Confusing.

Example of working code (for full see TwoClickMePanelsEventCaptureTestPage):

import java.util.logging.Logger;
import com.google.gwt.logging.client.HasWidgetsLogHandler;
import com.google.gwt.logging.client.LoggingPopup;

public final Logger logger = Logger.getLogger("test");
public void onModuleLoad() {
. . .
PopupPanel loggingPopup = new LoggingPopup();
loggingPopup.setPopupPosition(10, 240);
loggingPopup.setWidth("500px");
logger.addHandler(new HasWidgetsLogHandler(loggingPopup));
logger.info("Module is loading");
. . .


The class LoggingPopup is extends PopupPanel, there are plenty of styling methods to set width, height, top left position or to set CSS style name and externalize this to style sheet file.
The variant of class creation, using deferred binding :
HasWidgets loggingPopup = GWT.create(LoggingPopup.class);
cannot be used if set-property gwt.logging.popupHandler=DISABLED. Then NullLoggingPopup is created instead and using NullLoggingPopup cause various exceptions. It needs to be always class checked. See LogConfiguration::setDefaultHandlers(Logger l).
See in source code:
LogConfiguration::setDefaultHandlers(Logger l)
com.google.gwt.logging.client.LoggingPopup

Log message formatting

How to get custom log messages in a custom format, displaying full or shortened class name, timestamp format, something more compact then default “Fri Nov 02 15:10:09 GMT 2012”? Unfortunately, there is no straightforward way. There are no Patterns like in Log4J.
Blame Java Logging specification. It defines nothing about message formatting, only two simple formatters. All is left to vendor implementations and the GWT's provides only basic tools.
And GWT walks in Java Logging shoes, does not provides much either. If you look inside HtmlLogFormatter (GWT class), formatter customized for LoggingPopup (GWT class), it simply prints everything what is inside java.util.logging.LogRecord, field after field, decorating values with with HTML tags, including that stupid break line after INFO as you can see on my screenshots. That is not word wrapping. It is hard coded.
Basic Java Logging nor GWT logging is not that sophisticated as Log4J. Instead of a configuration option to set message formatting LayoutPattern in a nice DSL, like we do in Log4J, you have to implement Handler::setFormatter(Formatter f). See java.util.logging.Handler, java.util.logging.Formatter.

Alternative GWT logging framework - gwt-log

Besides build in GWT logging there is an alternative – gwt-log. It is provided by external independent project. The official library is relatively new addition to GWT, added in late 2010 since GWT 2.1 M2, before that in times when developers were limited to GWT.log() only, see my first paragraph, in this time gwt-log sprung up as DIY project.
I have not tested this framework personally. Logging popup panel is also provided, judging from the screenshot it looks a bit more sophisticated then the default one. It can utilize Log4J on the server side, however on the client side, you are not much better of then with, no PatternLayout here either.
Also see “gwt-log vs GWT logging” in project forum.

Production mode

GWT's Production Mode is even more tricky. What do you think, you get from these lines?

public void onModuleLoad() {
    System.out.println("Greetings from System.out");
    GWT.log("Greetings from GWT.log()");
    logger.info("Greetings from GWT logger");
}
In DevMode, it prints:

Greetings from System.out
Tue Nov 06 13:40:38 GMT 2012 test
INFO: Greetings from GWT logger
In Production Mode: nothing!
The System.out.println() is silently ignored in Production Mode. GWT.log() does not do much anytime, no surprise here, and Logger is configured by default to use ConsoleLogHandler, option consoleHandler is by default enabled, but this handler does silently nothing in Production Mode.
Does not expect anything to see in console in Production Mode from the client side code. Not by default. Not unless you invest some more time configuring remote logging and make the message to be printed on server side, via some client server communication.
In client only projects - like mine I am working on - your only saviour is Firefox Web Console or Chromium JavaScript console, only way to see log messages. And you have to use proper GWT Logger. Not simple GWT.log(). Alternative is to use native JavaScript, native method, but you are better off trying GWT Logger framework. It is not sophisticated as Log4J, but saves you some “reinventing the wheel” time.
Note: GWT supports Java System.out and System.err (see here). They do work as expected in Developer Mode. They are silently ignored in Production Mode.

Some more screenshots

Minor bug in PopupLogger (Chromium):
 GWT Logger in action - Web Console, Firefox:
 GWT Logger in action - JavaScript console, Chromium:

Links

Posted by at

No comments:

Post a Comment

Subscribe to: Post Comments (Atom)