Quality Assurance

A component should be reusable and be able to be employed in a variety of applications under a variety of conditions. In accomplishing this, the component makes only its interface available, hiding its internal workings. Furthermore, it should be able to be aggregated with other components to form supercomponents or partial applications. A component can meet all of these demands only if the implementation is of sufficiently high quality. A proven tool in quality assurance for software is the use of automated tests. Tests can help in discovering errors in the implementation. With each error removed, the quality of the software improves. Automated tests can also be used for the quality assurance of components.

There are several procedures for finding errors detected by tests. A common method is to use a debugger. A debugger enables the developer to focus on a single process and observe and scrutinize it. During execution one can query the state of variables, and with many debuggers even change them. Another, no less common, procedure is the use of logging. By logging is generally meant the output of reports to the computer monitor or to a file. The developer chooses what reports are output, since they are developer-implemented. Usually, information is output by which the sequence of steps executed and the states of variables can be reconstructed. With logging, the developer has essentially the same information available as with the use of debugging software. However, with logging, the developer is dependent on the quality of the logging output in the code of the application. Furthermore, in following the execution of the program using logging data the developer has no opportunity to influence the running of the program. Debugging software permits the developer to stop program execution, run the program step by step, or to jump to a particular point in the code.

The use of debuggers is made difficult with Enterprise JavaBeans because one is dealing with distributed applications. The debugger must be able to shift into an external process. In the execution environment of Enterprise Beans, the application server represents a heavyweight process in which many threads are active simultaneously. The analysis of program flow within such a heavyweight process takes a great expenditure of time, is very exacting, and demands great expertise.

In this section we would like first to develop a small framework for testing Enterprise Beans. For this we shall write some test cases for the entity bean BankAccount from Chapter 3 and the entity bean Part from this chapter. What is special to the test framework is that for each test run, a result protocol is generated in HTML format. Thus the development history of an Enterprise Bean can be documented and the efficiency of the components put to the test. The test framework is small, easy to use, and easy to adapt to particular circumstances. We shall also show the use of logging in Enterprise Beans. With the aid of logging it is possible to localize errors that occur in tests or in later deployment. Logging and automated tests together form a significant part of the quality assurance of Enterprise Beans.

Tests

Software must undergo continual change. This applies to components as well. The requirements on software and thus on components grow with the experience gained in their use. Making changes to component software brings with it the danger of introducing errors. With the availability of tests one can check immediately after a change in the code has been implemented whether the component works as it did before the change (assuming, of course, that the tests are adequate).

In the development of applications one frequently uses third-party components. Developers have to rely on the correct behavior of the components employed. If a new version of a component suddenly exhibits altered behavior, this can endanger the functionality of the entire application. Thus it is sensible to institute tests for third-party components. These tests ensure that the components display the expected behavior over several versions. Before a new version of the component is put into use, one can check in advance whether the behavior of the component has changed. It can also simply be that components offered by a third party are defective, which would endanger the functionality of the system.

There are essentially two different types of test: black-box tests and white-box tests. Black-box tests test the correct functioning of a component by determining whether its interface functions according to its specifications. The internal states of the component are not tested. Moreover, no knowledge of the construction of the component is assumed in the selection of test cases. For Enterprise Beans this would mean that with a black-box test a component is tested only from the client viewpoint. White-box tests test the correct functioning of a component by testing the internal states of the component during execution, with test cases designed based on the implementation. As a rule, in testing software one uses a mixture of both elements. However, with Enterprise Beans white-box tests are difficult to execute. An Enterprise Bean always uses a run-time environment. For a white-box test one would have to simulate this run-time environment in order to observe the behavior and state of an Enterprise Bean, since it is otherwise completely shielded by the EJB container, which does not allow direct access to the instance of the Enterprise Bean. Such a process is very difficult to implement. In this chapter we restrict ourselves to black-box tests. Later, we will suggest a way in which one might institute white-box tests on Enterprise Beans with somewhat less effort than might otherwise be necessary.

The test framework for black-box tests of Enterprise Beans is made up, essentially, of two classes and three exceptions. One of the two classes forms the basis for the test cases. This class is called EJBTestCase and is shown in Listing 9-24.

Listing 9-24: The class EJBTestCase.

 package ejb.test; import java.util.Properties; import javax.naming.Context; import javax.naming.InitialContext; import javax.naming.NamingException; public abstract class EJBTestCase {     private Properties theProps;     private Context theContext;     public EJBTestCase() {     }     void setProperties(Properties p)         throws NamingException     {         if(p == null) {             throw new                 IllegalArgumentException("null is not allowed!");         }         theProps = p;         theContext = new InitialContext(theProps);     }     public Object lookup(String name)         throws NamingException     {         this.assertNotNull("name", name);         return theContext.lookup(name);     }     public Object narrow(String name, Class c)         throws NamingException     {         this.assertNotNull("name", name);         this.assertNotNull("class", c);         Object o = theContext.lookup(name);         return javax.rmi.PortableRemoteObject.narrow(o, c);     }     public void fail(String msg) {         throw new TestFailException(msg);     }     public void assertEquals(Object obj1, Object obj2) {         assertEquals("values do not match", obj1, obj2);     }     public void assertEquals(float f1, float f2) {         assertEquals("values do not match", f1, f2);     }     public void assertEquals(int i1, int i2) {         assertEquals("values do not match", i1, i2);     }     public void assertEquals(String msg, Object o1, Object o2) {         if(!o1.equals(o2)) {             throw new                 AssertionException(msg + ": " +o1+"!="+ o2);         }     }     public void assertEquals(String msg, float f1, float f2) {         if(f1 != f2) {             throw new                 AssertionException(msg + ": " +f1+"!="+ f2);         }     }     public void assertEquals(String msg, int i1, int i2) {         if(i1 != i2) {             throw new                 AssertionException(msg + ": " +i1+"!="+ i2);         }     }     public void assertNotNull(String name, Object obj) {         if(obj == null) {             throw new AssertionException(name+"is null");         }     }     public Properties getProperties() {         return theProps;     }     public abstract void prepareTest()         throws Exception;     public abstract void finalizeTest()         throws Exception;     } 

EJBTestCase is an abstract class and is the base class of all test cases. It is initialized with a Properties object, which is used primarily to generate a NamingContext. Derived classes can use this NamingContext indirectly via the methods lookup and narrow to obtain references to Enterprise Beans. The Properties object is generated from a configuration file. With this Properties object it would also be possible to parameterize a test case externally. The derived class must overwrite the methods prepareTest and finalizeTest. By convention, the actual tests must implement the derived class in methods whose names begin with test. These methods must be declared public and are not allowed to have parameters. The method prepareTest is called before the first test method is called, and it serves to initialize the test case. Then the individual test methods are called, and finally, the method finalizeTest, which carries out the housecleaning tasks. Readers familiar with the test framework Junit (see [12]) will recognize this process.

The class that takes care of executing the tests is called EJBTest and is shown in Listing 9-25. Because of its length we will show only the central methods of the class in all their gory detail, since it is these alone that are necessary for an understanding of the process. The full source code can be found at http://www.apress.com in the Downloads section.

Listing 9-25: The class EJBTest.

 package ejb.test; import java.io.*; import java.util.*; import java.text.DateFormat; import java.lang.reflect.Method; public final class EJBTest {     ...     //member variables     private static final String TC = "test.class.";     private Properties theProps;     private Object[] theClasses;     ...     public EJBTest() {         ...         //initialization of the member variables         ...     }     public void init(String propertyFile) {         Properties p;         ...         //read in the property file,         //store the values in the variable p, and         //relay to init(Properties)         ...         init(p);     }     public void init(Properties p) {         if(p == null) {         throw new IllegalArgumentException("null ...");         }         theProps = p;         ArrayList al = new ArrayList();         Enumeration e = theProps.propertyNames();         String name;         String cname;         Class c;         while(e.hasMoreElements()) {             name = (String)e.nextElement();             if(name.startsWith(TC)) {                 cname = theProps.getProperty(name);                 try {                     c = Class.forName(cname);                     al.add(c);                 } catch(Exception ex) {                     al.add(cname);                 }             }         }         theClasses = al.toArray();         initOutputBuffer();     }     private void initOutputBuffer() {         ...         //Initialization of the output buffer         //for the test report, which is created         //at the end of all test in HTML format.         ...     }     private void reportBeginSection (String name, Throwable t)     {         ...         //output of reports arising at the beginning         //of the test in HTML format.         ...     }     private void reportTestCase                    (String name, long time, Throwable t)     {         ...         //Output of reports that arise during a test         //in HTML format         ...     }     private void reportEndSection(String name) {         ...         //Output of reports that arise at the end of a test         //in HTML format         ...     }     private void closeOutputBuffer() {         ...         //Close the output buffer after execution         //of all tests         ...     }     private String formatThrowable(Throwable t) {         ...         //Format an exception for output         //in HTML format         ...     }     private String computeFileName(String path) {         ...         //Compute the file name for the test protocol         ...     }     private String format(int num) {         ...         //Format integers for output         //in HTML format         ...     }     public void runTests() {         Class cl;         EJBTestCase tc;         for(inti=0;i< theClasses.length; i++) {             if(theClasses[i] instanceof String) {                 try {                     cl = Class.forName                                  ((String)theClasses[i]);                 } catch(Exception ex) {                     reportBeginSection                              ((String)theClasses[i], ex);                     continue;                 }             } else {                 cl = (Class)theClasses[i];             }             try {                 tc = (EJBTestCase)cl.newInstance();                 tc.setProperties(theProps);             } catch(Exception ex) {                 reportBeginSection(cl.getName(), ex);                 continue;             }             reportBeginSection(cl.getName(), null);             runTest(tc);             reportEndSection(cl.getName());         }         closeOutputBuffer();     }     private void runTest(EJBTestCase tc) {         Class c = tc.getClass();         Method[] ms = c.getMethods();         String name;         Class[] params;         try {             tc.prepareTest();         } catch(Exception ex) {             reportTestCase("prepareTest", 0, ex);             return;         }         for(inti=0;i< ms.length; i++) {             name = ms[i].getName();             params = ms[i].getParameterTypes();             if(!(name.startsWith(MP) &&                 params.length == 0))             {                 continue;             }             try {                 long t1 = System.currentTimeMillis();                 ms[i].invoke(tc, params);                 long t2 = System.currentTimeMillis();                 reportTestCase(name, (t2 - t1), null);             } catch(Exception ex) {                 reportTestCase(name, 0, ex);             }         }         try {             tc.finalizeTest();         } catch(Exception ex) {             reportTestCase("finalizeTest", 0, ex);         }     }     public static void main(String[] args) {         EJBTest et = new EJBTest();         if(args.length == 1) {             et.init(args[0]);         } else {             et.init(new Properties());         }         et.runTests();     } } 

The class EJBTest is initialized with a configuration file, which is shown in Listing 9-26. It is available from the code source for this book.

Listing 9-26: Properties for the class EJBTest.

 # # JNDI settings # # The JNDI factory class java.naming.factory.initial=weblogic.jndi.WLInitialContextFactory # the JNDI URL java.naming.provider.url=t3://localhost:7001 # # database settings for test cases # that access the database directly # # The class of the database driver jdbc.driver=org.postgresql.Driver # the database URL jdbc.url=jdbc:postgresql://localhost/postgres # the user name for the databse login jdbc.user=postgres # the associated password jdbc.pwd=postgres # # the classes that contain the tests # test.class.0=ejb.testcases.TestPartBean test.class.1=ejb.testcases.TestBankAccount test.class.2=ejb.testcases.TestLogger test.class.3=ejb.testcases.TestCounterBean test.class.4=ejb.testcases.TestExchangeSLBean test.class.5=ejb.testcases.TestExchangeSFBean test.class.6=ejb.testcases.TestMigrationBean test.class.7=ejb.testcases.TestSupplychain # # the directory into which the reports # are to be written # test.output.dir=./ 

The method init is called via the main method of the class EJBTest. There the configuration file is loaded and read. The name of the classes that implement a test (they are entered in the configuration file with the name test.class.*) are stored separately. In the example these are, among others, the classes ejb.test.TestPartBean, and ejb.test.TestBankAccount (the implementation of the classes appears subsequently). After the initialization the tests are executed via the method runTests. For each test class an instance is generated. The instance is initialized via a call to the method setProperties. Tests are run in the method runTest. First, the test case is prepared with a call to the method prepareTest. Using the introspection mechanism of the programming language Java, all methods on this object are called that are declared public, whose names begin with test, and that expect no parameters. By convention, these methods implement the tests for the respective Enterprise Beans. After all test methods have been called, the test is finalized with a call to the method finalizeTest.

All information about the test (name, execution time, errors, etc.), are written to the logging file. For each test run a new logging file is created. The name of the file includes the date and time. An example of such a logging file appears later in this section.

Now that the foundation has been laid, we can write the tests for the Enterprise Beans. Listing 9-27 shows the test for the Enterprise Bean Part from earlier in this chapter.

Listing 9-27: The class TestPartBean.

 package ejb.testcases; import ejb.part.*; import ejb.test.*; import javax.ejb.*; public class TestPartBean extends EJBTestCase {     PartHome partHome;     Part p1;     Part p2;     Part p3;     public TestPartBean() {         super();     }     public void prepareTest()         throws Exception     {         partHome = (PartHome)narrow("Part", PartHome.class);     }     public void testCreate()         throws Exception     {         final String one = "11111";         p1 = partHome.create(one);         assertNotNull("Part", p1);     }     public void testDelete()         throws Exception     {         final String two = "22222";         p2 = partHome.create(two);         assertNotNull("Part", p2);         p2.remove();         try {             p2 = partHome.findByPrimaryKey(two);             fail("expected FinderException, part "                  + two + " should not exist");         } catch(FinderException fex) {             //expected         }     }     public void testUpdate()         throws Exception     {         final String three = "33333";         p3 = partHome.create(three);         assertNotNull("Part", p3);         TsPartDetails pd = p3.getPartDetails();         pd.setPartDescription("Test Part");         pd.setSupplierName("Test Supplier");         pd.setPrice(120);         TsPartDetails pd1 = p3.setPartDetails(pd);         assertEquals(pd.getPartNumber(),                      pd1.getPartNumber());         assertEquals(pd.getPartDescription(),                      pd1.getPartDescription());         assertEquals(pd.getSupplierName(),                      pd1.getSupplierName());         assertEquals(pd.getPrice(),                      pd1.getPrice());         try {             p3.setPartDetails(pd);             fail("expected OutOfDateException");         } catch(OutOfDateException ex) {             //expected         }     }     public void finalizeTest()         throws Exception     {         p1.remove();         p3.remove();     } } 

The test case checks the three main functions of the Enterprise Bean Part. These are the generation, alteration, and deletion of a product part. During the course of the test, first the method prepareTest is called via the class EJBTest. There the test obtains a reference to the home interface of the Part bean. Then through the introspection mechanism of the class EJBTest the three test methods testCreate, testDelete, and testUpdate of the class TestPartBean are called. The order of calls is random. To finalize the test, the method finalizeTest is called.

In the method testCreate, the method create of the home interface is tested. The method assertNotNull of the base class checks whether the passed object has the value null. If so, an exception of type AssertionException is triggered, and the test is terminated. The exception is trapped by EJBTest and logged in the output file.

In the method testDelete a newly generated Part bean is again deleted. After the deletion, an attempt is made to find precisely this Enterprise Bean via the method findByPrimaryKey. To be correct, the findByPrimaryKey method should trigger an exception of type FinderException, since this Enterprise Bean no longer exists. If it does not do this, the test has failed. The method fail of the base class triggers an exception of type TestFailException. This exception is also trapped by EJBTest and logged in the output file.

The method testUpdate generates a Part bean and changes its value. Then it ensures that the bean actually returns the changed values. The method assertEquals compares two objects or two values. If they are not equal, this method triggers an exception of type AssertionException, and the test is terminated. In this case, too, the exception is trapped by EJBTest and logged in the output file. Moreover, the method testUpdate tests the time-stamp mechanism that was introduced in the previous section of this chapter by way of the Part bean. If the method setPartDetails is called with an obsolete details object, then this method triggers an exception of type OutOfDateException. If it doesn't do this, then the test case is broken off with a call to the method fail (and the implicit throwing of an exception of type TestFailException).

As already mentioned, this is a black-box test. The only methods that are tested are those that are accessible via the public interface of the Enterprise Bean. The test does not go into the Enterprise Bean's internal states. In this example the tests are very simple, merely ensuring that the basic functions of the component are usable. Such tests can be made as extensive and complex as desired.

The test for the Enterprise Bean BankAccount is built on exactly the same plan and tests exactly the same aspects of the Enterprise Bean. Therefore, we shall omit a listing of this test. However, the source code can be found at http://www.apress.com in the Downloads section.

To execute a test run, both Enterprise Beans must be installed in an EJB container. The EJB container or application server must be started, since the Enterprise Bean requires a run-time environment. Then the test run can be carried out by a call to the method main in the class EJBTest. As argument the name of the configuration file is passed (Listing 9-26 shows an example). The result of the test run is a logging file in HTML format. Figure 9-17 shows the result of a test run for the test cases of the Part and BankAccount beans.

Figure 9-17: Test result for TestBankAccount and TestPartBean.

It is seen from the test protocol that all the tests were successful. Failed tests appear in red instead of green in the fields of the table. Instead of the word success, the exception that the aborted test caused is output.

After each change in one of the two components, tests should be run to ensure that the contract that binds the interface to the components is still being fulfilled.

Logging

Logging is a relatively easy method of detecting errors in software. Logging is used to limit errors and when no suitable debugger software is available (such as a production environment). If a customer reports an error in the software, it can usually be reconstructed with the help of the logging file. Even when one has suitable debugging software, it is often impossible to install it at a customer's site.

Logging is often criticized with the argument that it inflates the code and hampers the readability of the code. Another argument frequently voiced against logging relates to the effect on performance. The supporters of logging argue that logging code improves the readability of the remaining code, since the logging statements act as a form of documentation.

Moreover, the application of logging is often easier and less time-consuming than the use of complicated debugging software. The impact on performance is very small, and particularly with distributed applications it is easy to justify, since in such a segment logging is often the only way of finding and analyzing errors.

Many application servers offer logging services that can use an Enterprise Bean. These logging services can be more or less flexibly implemented, but in any case, they have the drawback that their interfaces are proprietary. If an Enterprise Bean uses such a proprietary logging service of an application server, then it cannot be deployed in any other application server without changing the code of the Enterprise Bean.

The reusability of an Enterprise Bean is thereby greatly reduced. In any case, Sun Microsystems has integrated a logging service into the run-time environment of Java 1.4. However, until this has been widely adopted in the application servers, the use of third-party logging tools remains a viable alternative. Should the Enterprise Bean be deployed in another application server, the logging tool of this third party must be made available to it. This dependency can be noted in the deployment descriptor of the Enterprise Bean. Such a logging tool should be freely available.

Such a tool exists in the form of the Logging for Java (log4j) library of the Apache project. This project (see [1]) is a development project, organized and coordinated over the Internet, for creating and maintaining software that is available free of charge. This type of software is called open-source software, since the source code is also freely available. Logging for Java offers a logging tool for the programming language Java. The flexibility of log4j is considerable, and the use of it relatively easy. Among other attributes, it possesses the capability of directing the logging output to various media (writing to file, output to the screen or to other servers). Log4j supports a variety of logging levels and hierarchical logging categories. An extensive description of the capabilities of log4j can be found at [2].

The output of reports via log4j, whether to the screen or a file, permits one to observe the behavior of an Enterprise Bean. For developers who are working with the component model of Enterprise JavaBeans for the first time, the use of logging offers an opportunity to learn about the behavior of the EJB container through the logging output of Enterprise Beans. Nonetheless, the primary purpose of logging is to detect errors.

To demonstrate the use of log4j we will equip the Enterprise Bean Part from the previous section with logging output. With the aid of the black-box test that we have implemented we will then generate a logging file. Listing 9-28 shows the altered class PartBean. The parts that are relevant to logging are shown in boldface. The method toString in the class TsPartDetails has been implemented to enable us to note the internal state of the Enterprise Bean (see Listing 9-18).

Listing 9-28: Class PartBean with logging output.

 package ejb.part; import javax.ejb.*; import org.apache.log4j.Category; import org.apache.log4j.BasicConfigurator; import org.apache.log4j.FileAppender; import org.apache.log4j.Layout; import org.apache.log4j.PatternLayout; import org.apache.log4j.Priority; public abstract class PartBean implements EntityBean {     private EntityContext theContext = null;     private TsPartDetails theDetails = null;     private Category log = null;     public PartBean() {         final String name = "PartBean";         BasicConfigurator.configure();         Category.getRoot().removeAllAppenders();         if((log = Category.exists(name)) == null) {             log = Category.getInstance(name);             log.setPriority(Priority.DEBUG);             Layout l = new PatternLayout(                             PatternLayout.TTCC_CONVERSION_PATTERN);             try {               log.addAppender(new FileAppender(l, name + ".log"));             } catch(java.io.IOException ioex) {                 throw new IllegalStateException(ioex.getMessage());             }         }         log.info("initialized instance successfully");     }     //the create method of the home interface     public String ejbCreate(String partNumber)         throws CreateException     {         log.info("entering ejbCreate (" + partNumber + ")");         this.setPartNumber(partNumber);         theDetails = new TsPartDetails();         theDetails.partNumber = partNumber;         theDetails.partDescription = "";         theDetails.supplierName = "";         theDetails.price = 0;         long tt = System.currentTimeMillis();         this.setLastModified(tt);         theDetails.updateTimestamp(theContext, tt);         log.debug("Created new part with part-no:" + partNumber);         log.info("leaving ejbCreate");         return null;     }     public void ejbPostCreate(String partNumber)         throws CreateException     {         log.debug("ejbPostCreate (" + partNumber + ")");     }     //abstract getter/setter methods     public abstract void setPartNumber(String num);     public abstract String getPartNumber();     public abstract void setPartDescription(String desc);     public abstract String getPartDescription();     public abstract void setSupplierName(String name);     public abstract String getSupplierName();     public abstract void setPrice(float p);     public abstract float getPrice();     public abstract long getLastModified();     public abstract void setLastModified(long tt);     //the method of the remote interface     public TsPartDetails setPartDetails(TsPartDetails pd)         throws OutOfDateException     {         log.info("entering setPartDetails " + pd);         if(theDetails.isOutDated(pd)) {             log.warn("out of date part-details-object");             log.info("leaving setPartDetails");             throw new OutOfDateException();         }         this.setPartDescription(pd.getPartDescription());         this.setSupplierName(pd.getSupplierName());         this.setPrice(pd.getPrice());         long tt = System.currentTimeMillis();         this.setLastModified(tt);         theDetails = pd;         theDetails.updateTimestamp(theContext, tt);         log.debug("part-data updated " + theDetails);         log.info("leaving setPartDetails");         return theDetails;     }     //public PartDetails getPartDetails() {     public TsPartDetails getPartDetails() {         log.debug("getPartDetails :" + theDetails);         return theDetails;     }     //the methods of the javax.ejb.EntityBean interface     public void setEntityContext(EntityContext ctx) {         log.debug("setEntityContext " + ctx);         theContext = ctx;     }     public void unsetEntityContext() {         log.debug("unsetEntityContext");         theContext = null;     }     public void ejbRemove()         throws RemoveException     {         log.debug("ejbRemove");     }     public void ejbActivate() {         log.debug("ejbActivate");     }     public void ejbPassivate() {         log.debug("ejbPassivate");     }     public void ejbLoad() {         log.info("entering ejbLoad");         if(theDetails == null) {             theDetails = new TsPartDetails();         }         theDetails.partNumber = this.getPartNumber();         theDetails.partDescription = this.getPartDescription();         theDetails.supplierName = this.getSupplierName();         theDetails.price = this.getPrice();         long tt = this.getLastModified();         theDetails.updateTimestamp(theContext, tt);         log.debug("data successfully loaded:" + theDetails);         log.info("leaving ejbLoad");     }     public void ejbStore() {         log.debug("ejbStore");     } } 

The log4j classes are initialized in the constructor of the Enterprise Bean with a call to the method configure of the class BasicConfigurator. This method can be called repeatedly. Then, if it does not already exist, a separate logging category for the Enterprise Bean Part is set up with the name of the class (another instance of this bean class could already have generated this category). The interface Category is the central interface of the log4j library. All logging output takes place over this interface.

The logging level of the category for the Part bean is set via the method setPriority to DEBUG. Log4j defines the logging levels DEBUG, INFO, WARN, ERROR, and FATAL, where DEBUG has the lowest priority, and FATAL the highest. For each category, the interface Category offers a separate method (debug,info, warn, error, and fatal). To create logging output with the priority WARN, the method warn on the interface Category must be called. If at run time the logging level is set to ERROR, then a call to the method warn generates no output. In our case, each of the logging methods will generate output, since the logging level is set to the lowest priority. In our example, the setting is hard coded to keep things simple. As a rule, the setting of the logging level is read from the configuration. One could even offer a method on the remote interface of the Enterprise Bean that allowed the logging level to be raised or lowered from the client side. The raising or lowering of the logging level can be used to change the amount of logging output at run time. The Enterprise Bean could also be equipped with a logic that would raise or lower the logging level automatically at the occurrence of particular events.

To write logging output to a file, an object of type FileAppender is added to the category. Appenders are objects that represent the various output channels. A category can have several appenders. Appenders can be added to or deleted from a category dynamically. The file appender is initialized with the file name of the output file and with an object that defines the layout of the output. In our example, a standard layout is used, which will be explained later when we see an example of a logging file. The logging output of all instances of the class PartBean are written into a single output file with the name PartBean.log.

One could certainly question the use of FileAppender here. Namely, an Enterprise Bean is forbidden from accessing the file system (see Chapter 3). However, the Enterprise Bean does not access the file system directly, but indirectly via the log4j library. If an error should occur in writing to the file, this would not be passed to the Enterprise Bean. Log4j traps the error and handles it internally. The probability that the Enterprise Bean would be blocked during writing a logging entry (for example, on account of synchronization problems with the file system) is in any case very small, since the output into the file system is buffered by log4j. Proprietary logging services of an application server generally also use the file system as the location for logging output. However, if one were opposed to the use of FileAppender, then as an alternative, the SocketAppender could be used, which sends the logging output over a network connection to another server, where it is then stored. Another option is the development of a custom appender, which, for example, could write to a database. The necessary details for alternative appenders can be found in the log4j documentation (see [2]).

As a final action, in the constructor of the PartBean there is logging output with the priority INFO upon the successful initialization of an instance. In the remaining methods, the category generated in the constructor is used to create logging output with various priorities about program execution and the internal state of the components.

Since there is no place in the deployment descriptor in which one can refer to the use of third-party libraries, it is recommended to make this reference to the use of log4j in the description of the Enterprise Bean. Since the deployment descriptor is the central documentation instance of the component, this information should be placed there in any case. It is also a good idea to name the source where the deployer (being answerable for the Enterprise Bean) can obtain the library. Tips for installing the library would also be helpful. In the case of log4j, it is necessary only that the archive file log4j.jar be located in the Classpath of the EJB container. Alternatively, log4j.jar can be packed into the appropriate ejb.jar.

We used the black-box test for the Part bean from earlier in this chapter to generate a logging file. Listing 9-29 shows the content of this file. The comments describe the relation of the logging output to the methods and actions of the test case.

Listing 9-29: Logging output of the class PartBean.

 //TestPartBean.testCreate //generate Part 11111 631 [ExecuteThread-14] INFO PartBean -     initialized instance successfully 631 [ExecuteThread-14] DEBUG PartBean -     setEntityContext EntityEJBContextImpl@795cce 631 [ExecuteThread-14] INFO PartBean -     entering ejbCreate (11111) 631 [ExecuteThread-14] DEBUG PartBean -     Created new part with part-no:11111 641 [ExecuteThread-14] INFO PartBean - leaving ejbCreate 671 [ExecuteThread-14] DEBUG PartBean -     ejbPostCreate (11111) 671 [ExecuteThread-14] DEBUG PartBean - ejbStore //TestPartBean.testDelete //generate Part 22222 731 [ExecuteThread-10] INFO PartBean -     initialized instance successfully 731 [ExecuteThread-10] DEBUG PartBean -     setEntityContext EntityEJBContextImpl@5507d3 731 [ExecuteThread-10] INFO PartBean -     entering ejbCreate (22222) 731 [ExecuteThread-10] DEBUG PartBean -     Created new part with part-no:22222 731 [ExecuteThread-10] INFO PartBean - leaving ejbCreate 761 [ExecuteThread-10] DEBUG PartBean -     ejbPostCreate (22222) 761 [ExecuteThread-10] DEBUG PartBean - ejbStore //delete Part 22222 781 [ExecuteThread-14] INFO PartBean - entering ejbLoad 811 [ExecuteThread-14] DEBUG PartBean -     data successfully loaded:     [[TsPartDetails]partNumber=22222;partDescription     =null;supplierName=null;price=0.0;] 811 [ExecuteThread-14] INFO PartBean - leaving ejbLoad 811 [ExecuteThread-14] DEBUG PartBean - ejbRemove //TestPartBean.testUpdate //generate Part 33333 901 [ExecuteThread-14] INFO PartBean -     initialized instance successfully 901 [ExecuteThread-14] DEBUG PartBean -     setEntityContext EntityEJBContextImpl@79781 901 [ExecuteThread-14] INFO PartBean -     entering ejbCreate (33333) 901 [ExecuteThread-14] DEBUG PartBean -     Created new part with part-no:33333 901 [ExecuteThread-14] INFO PartBean - leaving ejbCreate 911 [ExecuteThread-14] DEBUG PartBean -     ejbPostCreate (33333) 911 [ExecuteThread-14] DEBUG PartBean - ejbStore //call to PartBean.getPartDetails 921 [ExecuteThread-10] INFO PartBean - entering ejbLoad 921 [ExecuteThread-10] DEBUG PartBean -     data successfully loaded:     [[TsPartDetails]partNumber=33333;partDescription=     null;supplierName=null;price=0.0;] 921 [ExecuteThread-10] INFO PartBean - leaving ejbLoad 921 [ExecuteThread-10] DEBUG PartBean - getPartDetails :     [[TsPartDetails]partNumber=33333;partDescription=     null;supplierName=null;price=0.0;] 921 [ExecuteThread-10] DEBUG PartBean - ejbStore //call to PartBean.setPartDetails 941 [ExecuteThread-14] INFO PartBean - entering ejbLoad 941 [ExecuteThread-14] DEBUG PartBean -     data successfully loaded:     [[TsPartDetails]partNumber=33333;partDescription=     null;supplierName=null;price=0.0;] 941 [ExecuteThread-14] INFO PartBean - leaving ejbLoad 941 [ExecuteThread-14] INFO PartBean -     entering setPartDetails 941 [ExecuteThread-14] DEBUG PartBean - part-data updated     [[TsPartDetails]partNumber=33333;partDescription=     Test Part;supplierName=Test Supplier;price=120.0;] 941 [ExecuteThread-14] INFO PartBean -     leaving setPartDetails 941 [ExecuteThread-14] DEBUG PartBean - ejbStore //call to PartBean.setPartDetails with obsolete //TsPartDetails object 1001 [ExecuteThread-10] INFO PartBean - entering ejbLoad 1001 [ExecuteThread-10] DEBUG PartBean -     data successfully loaded:     [[TsPartDetails]partNumber=33333;partDescription=     Test Part;supplierName=Test Supplier;price=120.0;] 1001 [ExecuteThread-10] INFO PartBean - leaving ejbLoad 1001 [ExecuteThread-10] INFO PartBean -      entering setPartDetails 1001 [ExecuteThread-10] WARN PartBean -      out of date part-details-object 1001 [ExecuteThread-10] INFO PartBean -      leaving setPartDetails 1001 [ExecuteThread-10] DEBUG PartBean - ejbStore //TestPartBean.finalizeTest //delete Part 11111 1011 [ExecuteThread-10] INFO PartBean - entering ejbLoad 1011 [ExecuteThread-10] DEBUG PartBean -      data successfully loaded:      [[TsPartDetails]partNumber=11111;partDescription=      null;supplierName=null;price=0.0;] 1011 [ExecuteThread-10] INFO PartBean - leaving ejbLoad 1011 [ExecuteThread-10] DEBUG PartBean - ejbRemove //delete Part 33333 1021 [ExecuteThread-14] INFO PartBean - entering ejbLoad 1031 [ExecuteThread-14] DEBUG PartBean -      data successfully loaded:      [[TsPartDetails]partNumber=33333;partDescription=      Test Part;supplierName=Test Supplier;price=120.0;] 1031 [ExecuteThread-14] INFO PartBean - leaving ejbLoad 1031 [ExecuteThread-14] DEBUG PartBean - ejbRemove 

The format of the logging output can be customized. The Part bean uses a predefined format. In the first column, the time elapsed since the start of the application is given in milliseconds. The second column displays the name of the thread that has processed the client request. The third column contains the logging level (INFO, DEBUG, WARN, ERROR,or FATAL), and in the fourth column, the name of the logging category (in the case of the Part bean, it is the name PartBean). Finally, the text created in the various logging methods is output.

It can be seen from the example in Listing 9-29 that the processes taking place within an Enterprise Bean can be followed from the logging output. If an error occurs, it can be immediately localized. Errors can be logged either through the logging levels WARN, ERROR, and FATAL, or discovered by a logged exception in the logging file. If the internal state of the component and the program execution are logged together in advance of the occurrence of an error, the source of the error can be found relatively quickly. In our example, one can see at once from the WARN entry that a client has attempted to update the data of the Enterprise Bean with an invalid details object. It is assumed that the developer of the component has programmed the relevant informative logging output. For example, if an exception occurs that is trapped in the code but not written to the logging output, the error cannot be found through logging.

With logging, the behavior of the EJB container can be studied as well. From the knowledge obtained one can institute measures for optimization of the components. However, one should not do anything that causes a dependency on a particular EJB container.

White-box tests could be carried out with Enterprise Beans by analyzing logging files generated by black-box tests. The analysis of logging files requires a relatively large programming effort. Moreover, a protocol for logging output should be defined and adhered to. Since the programming effort occurs only once and can significantly improve the quality of the tests, it can be a worthwhile enterprise. For example, the entries in the logging file in Listing 9-29 are very homogeneous and would be suitable for a lexical analysis. For example, the directory in which the log files of the Enterprise Bean are located and which log file belongs to which test case could be made available to the class EJBTest via the configuration file. Furthermore, the class EJBTestCase could be extended to include the capability of analyzing (parsing) these log files according to a particular protocol. One could even go so far as to reconstruct objects from the entries in the logging file and analyze the derived classes. For example, the information [[TsPartDetails] partNumber = 33333; partDescription = Test Part; supplierName = Test Supplier; price = 120.0;] from the logging file immediately allows us reconstruct the object of type TsPartDetails. The derived class could then carry out the evaluation for the current test case and determine whether the internal state recorded in the logging file during the black-box test was correct.

It would also be interesting to investigate, using black-box and white-box tests, whether a component behaves the same way in different containers or whether the behavior of the EJB container corresponds to that described in the specification. This provides an indirect way of testing the EJB container.

Automated tests and logging are mechanisms that tend to improve the quality of a component. If the tests themselves are error-ridden or carelessly programmed, or if the logging output is incomplete or lacking in explanatory power, then it becomes questionable whether there is any real contribution to improved quality. To make testing and logging into a useful instrument, the developers of components and tests must exercise great care and discipline.