• No results found

public boolean authenticate(String uname, String pw) 40: throws AccessException

In document And Son More Java Pitfalls pdf (Page 66-74)

Non-Blocking Server IO

Item 4: When Information Hiding Hides Too Much When you are developing a framework that will be used by a large project, it is some-

39: public boolean authenticate(String uname, String pw) 40: throws AccessException

41: {

42: boolean result = false;

43: String dn = “uid=” + uname + “,ou=People,dc=pitfalls.org”; 44: try 45: { 46: createConnection(); 47: m_ld.authenticate( m_ldapversion, dn, pw ); 48: result = true; 49: } 50: catch ( LDAPException e ) 51: {

52: throw new AccessException(e); 53: }

54: return (result); 55: }

56: }

Listing 4.4 (continued)

This pitfall showed the traps that can present themselves when you try to hide the implementation details when creating an API for use by other developers. The key points that you should keep in mind are as follows:

■■ Take advantage of interfaces when hiding your implementation details.

■■ Be wary of not handling exceptions properly. Instead of returning a value from a method (such as false or null), think about the cause of your returning these values. If there could be multiple causes, throw an exception.

■■ Instead of taking some information from one exception and placing it a new exception, take advantage of the new JDK 1.4 changes to Throwable and add the original exception to your new exception.

Item 5: Avoiding Granularity

Pitfalls in java.util.logging

The release of J2SDK 1.4 brought us a new logging API—java.util.logging. For those of us who have been frustrated by our own implementations of logging over the years, this can be a powerful package that comes out of the box with the J2SE. An appli- cation can create a logger to log information, and several handlers (or objects that “log” the data) can send logging information to the outside world (over a network, to a file, to a console, etc.) Loggers and handlers can filter out information, and handlers can use Formatter objects to format the resulting output of the Handler object.

Figure 5.1 Levels of granularity.

At first glance, adding a logging solution into your application looks incredibly easy and quite intuitive. When you start changing the granularity of logging, however, there are some potential pitfalls that lie in your path. Figure 5.1 shows the levels of granularity from the class java.util.logging.Level, with the lowest level of granularity being Level.FINEST. The key point to know is that when a logger is set to show messages at a level of granularity, it will show messages labeled at that level and above. For example, a logger set to the FINESTlevel of granularity will show all messages labeled Level.FINESTand above in Figure 5.1. When a logger is set to show messages at Level.INFO, it will show messages labeled Label.INFO,

Label.WARNING, and Label.SEVERE. Of course, as Figure 5.1 shows, the Level

class also includes “ALL” for logging all messages and “OFF” for logging no messages. A first attempt at using this log package, experimenting with levels of granularity, can be shown in Listing 5.1.

01: package org.javapitfalls.item5; 02:

03: import java.io.*;

04: import java.util.logging.*; 05:

06: public class BadLoggerExample1 07: {

08: private Logger m_log = null; 09:

10: public BadLoggerExample1(Level l)

Listing 5.1 BadLoggerExample 1 (continued)

Level.OFF Level.SEVERE Level.WARNING Level.INFO Level.CONFIG Level.FINE Level.FINER Level.FINEST Level.ALL SHOWS

11: { 12: 13:

14: //This creates the logger!

15: m_log = Æ Logger.getLogger(“org.pitfalls.BadLoggerExample1.logger”); 16: 17: m_log.setLevel(l); 18: } 19: /*

20: * This tests the levels of granularity! 21: */

22: public void test()

23: {

24: System.out.println(“The level for the log is: “ 25: + m_log.getLevel()); 26: m_log.finest(“This is a test for finest”); 27: m_log.finer(“This is a test for finer”); 28: m_log.fine(“This is a test for fine”); 29: m_log.info(“This is a test for info”); 30: m_log.warning(“This is a warning test”); 31: m_log.severe(“This is a severe test”); 32: }

33: 34: /*

35: * A very simple example, where we will optionally 36: * pass in the level of granularity to our application 37: */

38: public static void main(String[] args) 39: {

40: Level loglevel = Level.INFO; 41: 42: if ( args.length !=0 ) 43: { 44: if ( args[0].equals(“ALL”) ) 45: { 46: loglevel = Level.ALL; 47: } 48: else if ( args[0].equals(“FINE”) ) 49: { 50: loglevel = Level.FINE; 51: } 52: else if ( args[0].equals(“FINEST”) ) 53: { 54: loglevel = Level.FINEST; 55: } 56: else if ( args[0].equals(“WARNING”) ) 57: { 58: loglevel = Level.WARNING; Listing 5.1 (continued)

59: } 60: else if ( args[0].equals(“SEVERE”) ) 61: { 62: loglevel = Level.SEVERE; 63: } 64: 65: }

66: BadLoggerExample1 logex = new BadLoggerExample1(loglevel); 67: logex.test();

68: } 69:}

Listing 5.1 (continued)

In Listing 5.1, you can see that we create a simple logger and call a test function that tests the levels of granularity. In the main()method of this class, we pass it an argu- ment pertaining to the level of granularity (ALL, FINE, FINEST, WARNING, SEVERE), or if there is no argument, the loglevel defaults to INFO. If you run this program with- out an argument, you will see the following printed to standard error, which is correct output:

The level for the log is: INFO

Feb 16, 2002 3:42:08 PM org.pitfalls.logging.BadLoggerExample1 test INFO: This is a test for info

Feb 16, 2002 3:42:08 PM org.pitfalls.logging.BadLoggerExample1 test WARNING: This is a warning test

Feb 16, 2002 3:42:08 PM org.pitfalls.logging.BadLoggerExample1 test SEVERE: This is a severe test

Additionally, if you pass SEVERE as an argument, you will see the following correct output:

The level for the log is: SEVERE

Feb 16, 2002 3:42:09 PM org.pitfalls.logging.BadLoggerExample1 test SEVERE: This is a severe test

However, if you run this program with the argument FINE, you will see the following:

The level for the log is: FINE

Feb 16, 2002 3:42:10 PM org.pitfalls.logging.BadLoggerExample1 test INFO: This is a test for info

Feb 16, 2002 3:42:10 PM org.pitfalls.logging.BadLoggerExample1 test WARNING: This is a warning test

Feb 16, 2002 3:42:10 PM org.pitfalls.logging.BadLoggerExample1 test SEVERE: This is a severe test

What happened? Where are the “fine” messages? Is something wrong with the Log- ger? We set the level of granularity to FINE, but it still acts as if its level is INFO. We know that is wrong, because we printed out the level with the Logger’s getLevel()

method. Let us add a FileHandlerto our example, so that it will write the log to a file, and see if we see the same output. Listing 5.2 shows the BadLoggerExample2, where we add a FileHandlerto test this. On lines 20 and 21 of Listing 5.2, we create a new FileHandlerto write to the log file log.xml, and we add that handler to our

Loggerobject. 01: package org.javapitfalls.item5; 02: 03: import java.io.*; 04: import java.util.logging.*; 05:

06: public class BadLoggerExample2 07: {

08: private Logger m_log = null; 09:

10: public BadLoggerExample2(Level l) 11: {

12: FileHandler fh = null;

13:

14: //This creates the logger!

15: m_log = Æ

Logger.getLogger(“org.pitfalls.BadLoggerExample2.logger”); 16:

17: //Try to create a FileHandler that writes it to file! 18: try

19: {

20: fh = new FileHandler(“log.xml”); 21: m_log.addHandler(fh);

22: }

23: catch ( IOException ioexc ) 24: { 25: ioexc.printStackTrace(); 26: } 27: 28: m_log.setLevel(l); 29: } 30: /*

31: * This tests the levels of granularity! 32: */

33: public void test()

34: {

35: System.out.println(“The level for the log is: “

36: + m_log.getLevel()); 37: m_log.finest(“This is a test for finest”); 38: m_log.finer(“This is a test for finer”); 39: m_log.fine(“This is a test for fine”); 40: m_log.info(“This is a test for info”); 41: m_log.warning(“This is a warning test”); 42: m_log.severe(“This is a severe test”); 43: }

44: 45: /*

46: * A very simple example, where we will optionally 47: * pass in the level of granularity to our application 48: */

49: public static void main(String[] args) 50: {

51: Level loglevel = Level.INFO; 52: 53: if ( args.length !=0 ) 54: { 55: if ( args[0].equals(“ALL”) ) 56: { 57: loglevel = Level.ALL; 58: } 59: else if ( args[0].equals(“FINE”) ) 60: { 61: loglevel = Level.FINE; 62: } 63: else if ( args[0].equals(“FINEST”) ) 64: { 65: loglevel = Level.FINEST; 66: } 67: else if ( args[0].equals(“WARNING”) ) 68: { 69: loglevel = Level.WARNING; 70: } 71: else if ( args[0].equals(“SEVERE”) ) 72: { 73: loglevel = Level.SEVERE; 74: } 75: 76: }

77: BadLoggerExample2 logex = new BadLoggerExample2(loglevel); 78: logex.test();

79: } 80: }

This time, we see the same output as before when we pass in the FINEargument, but a log file is generated, showing the XML output, shown in Listing 5.3! Now, stan- dard error prints out the same seemingly incorrect thing as before, not showing the

FINEtest, and the FileHandlerseems to write the correct output. What is going on? Why does the file output not match the output written to standard error?

<?xml version=”1.0” encoding=”windows-1252” standalone=”no”?> <!DOCTYPE log SYSTEM “logger.dtd”>

<log> <record> <date>2002-02-16T15:51:00</date> <millis>1013892660502</millis> <sequence>0</sequence> <logger>org.pitfalls.BadLoggerExample2.logger</logger> <level>FINE</level> <class>org.pitfalls.logging.BadLoggerExample2</class> <method>test</method> <thread>10</thread>

<message>This is a test for fine</message> </record> <record> <date>2002-02-16T15:51:00</date> <millis>1013892660522</millis> <sequence>1</sequence> <level>INFO</level>

... <logger> <class>, <method> and <thread> elements same as above ... <message>This is a test for info</message>

</record> <record> <date>2002-02-16T15:51:00</date> <millis>1013892660612</millis> <sequence>2</sequence> <level>WARNING</level>

<message>This is a warning test</message> </record> <record> <date>2002-02-16T15:51:00</date> <millis>1013892660622</millis> <sequence>3</sequence> <level>SEVERE</level>

<message>This is a severe test</message> </record>

</log>

Figure 5.2 Logger/handler relationship diagram.

This behavior is quite strange. What happened? There are actually three things that we need to understand in order to understand this strange behavior:

Default Configurations of Loggers and Handlers. Loggers and handlers have default configurations, read from a preference file in your JRE’s lib directory. A key thing to understand is that granularities may be set for each, using the

setLevel()method.

Inheritance of Loggers. Another key thing to understand about the logging API is that each logger has a parent, and all data sent to a logger will go to its parent as well. The top parent is always the Root Logger, and you can create an inheri- tance tree descending from the Root Logger. In our initial example in Listing 5.1, we did not set a handler, but we still had output. Why? The reason is the Root Logger had a ConsoleHandler, whose default content level is Level.INFO. You can disable sending log messages to your parent’s handler by calling the

setUseParentHandlers(false)on the Loggerclass.

The Relationship between Handlers and Loggers. As we mentioned before, there are default levels of handlers. By default, all ConsoleHandlers log at the

Level.INFOlevel, and all FileHandlers log at the Level.ALLlevel. The log- ger itself can set its level, and you can also set the level of the handlers. The key is that the level of the handler can never show a lower level of granularity than the logger itself. For example, if the logger’s level is set to Level.INFO, the attached handlers will only see Level.INFOlevels and above (from our diagram in Fig- ure 5.1). In our example in Listing 5.2, we set our logger level to Level.FINE, and because the FileHandler’s level was the default level (Level.ALL), it only saw what the logger was able to pass through (FINEand below).

GRANULARITY Level.SEVERE Level.WARNING Level.INFO Level.CONFIG Level.FINE Level.FINER Level.FINEST Level.ALL Parent Logger Granularity A New Logger Granularity B Handler Granularity C Handler Granularity D Log Messages

higher than and equal to Granularity B are sent to Logger Parent

Log Messages higher than and equal to Granularity C

are logged Log Messages

higher than and equal to Granularity A are sent to

Handlers

Log Messages higher than and equal to Granularity B are sent to

Handlers

Log Messages higher than and equal to Granularity D

Confusing? We have presented this graphically in Figure 5.2 for your convenience. In our earlier example tests with BadLoggerExample1.java in Listing 5.1, everything seemed to work when we set the level to Level.INFOand Level.SEVERE, because those levels were higher than Level.INFO, the default level for the parent logger. However, when we set the level to Level.FINE, the parent’s logger’s handler was only passed messages higher than and equal to Level.INFO.

Luckily, it is very simple to set the levels for your handlers and loggers with the

setLevel()method, and it is possible to not send messages to your logger’s parent with the logger’s setUseParentsHandlers(false)method. Listing 5.4 shows our changes to Listing 5.2, where we modify the constructor to set all of the handlers at the same level.

10: public GoodLoggerExample(Level l) 11: {

12: FileHandler fh = null;

13: ConsoleHandler ch = new ConsoleHandler();

14:

15: //This creates the logger!

16: m_log = Æ

Logger.getLogger(“org.pitfalls.GoodLoggerExample.logger”);

In document And Son More Java Pitfalls pdf (Page 66-74)