Calling log4j's Logger.error from PeopleCode

A couple of years have passed since I first posted about using log4j as a logging framework for PeopleCode. In my post log4j and PeopleCode Part II, I noted that it is not possible to directly call the Logger.error method because error is a keyword in PeopleCode. I also mentioned that it would be possible to use reflection to call this method. Here is the PeopleCode required to call the error method using reflection:

Local JavaObject &logger = GetJavaClass("org.apache.log4j.Logger").getLogger("my.custom.logger");
Local JavaObject &jErrorArgTypes = CreateJavaObject("java.lang.Class[]", GetJavaClass("java.lang.Object"));
Local JavaObject &jErrorMethod = &logger.getClass().getMethod("error", &jErrorArgTypes);

&jErrorMethod.invoke(&logger, CreateJavaObject("java.lang.Object[]", "This is an error message"));

Want it all on one line?

Local JavaObject &logger = GetJavaClass("org.apache.log4j.Logger").getLogger("my.custom.logger");
&logger.getClass().getMethod("error", CreateJavaObject("java.lang.Class[]", GetJavaClass("java.lang.Object"))).invoke(&logger, CreateJavaObject("java.lang.Object[]", "This is another error message"));

Using reflection from PeopleCode can get ugly. If you are going to use Logger.error, then you may want to hide the Java implementation details in an app class.

AppEngine Output Tricks, Reporting, Logging, Etc

Reporting

When I took the AppEngine course several years ago, my instructor made sure his students knew that AppEngine was a batch processing tool, not a reporting tool, unlike SQR, which could do both. At that time, PeopleSoft offered Crystal Reports, PS/nVision, PS Query, and SQR as reporting options, and he encouraged us to use those tools for reporting. AppEngine was strictly labeled a batch processing tool. While debugging some jobs containing AppEngines (dunning letters, training letters, etc), I noticed that these AppEngines created and/or read files from the process output directory. Looking at the process monitor, I knew that those same files were available from the View Log/Trace link on the process details page. This got me thinking... if I could create a Microsoft Word file from AppEngine, I could place it in that process output directory and not have to run the WINWORD process on a headless server. Now, the trick, creating a Microsoft Word file from an AppEngine... Here are a couple of options

• Word HTML format
• Word XML format
• RTF

By using various methods, I can convert my mail merge source data into XML format and transform it into either of these three Microsoft Word recognized formats using XSL. Of course, as of PeopleTools 8.48, we can use XMLPublisher to generate the same result. Nevertheless, if you need to process your data prior to generating a report, then a multi-step AppEngine reporting solution might be easier for you to manage than a multi-step job.

The same options are available for creating Microsoft Excel and OpenOffice documents. If you want to create Microsoft Excel binary files from AppEngine, then you can use Apache's POI Java libraries from PeopleCode. If you are interested in creating OpenOffice documents, you can generate the appropriate XML files, and then use Java to zip them into a single file. In fact, you could use this same approach to generate OpenOffice Impress presentations or Microsoft PowerPoint 2007 presentations.

For reporting, why choose AppEngine over SQR? AppEngine components (PeopleCode, SQL, etc) are managed objects. PeopleTools managed objects participate in the change management features available in PeopleTools. SQR text files do not.

Can I create a PDF from an AppEngine? Yes. Using an XSL-FO processor, you can trasform XML into PDF using a user defined XSL template. Likewise, you can use one of the PDF Java libraries to print text to a PDF file using PeopleCode similar to the way you would print output to a PDF in SQR, but with rich text features. Other reporting options: Any reporting/output tool that has a Java API can be called from AppEngine PeopleCode. For example, JasperReports, BIRT, JFreeReport, FOP, etc.

File Output Location

Suppose I want to create a file (printable report, log file, etc), where should I create the file? If you want the file available from the View Log/Trace link, then use the following SQL to determine the process's output directory:

SELECT PRCSOUTPUTDIR FROM PSPRCSPARMS WHERE PRCSINSTANCE = %ProcessInstance

Logging

I've already mentioned using log4j from PeopleCode. You can read about that in my posts: Logging PeopleCode Using log4j to debug applications and log4j and PeopleCode Part II. Other options include the Peoplecode MessageBox function, the PeopleCode File object, and the Java System.out/System.err methods. I prefer the Java System output methods over the PeopleCode MessageBox function because Java gives me complete control over the output. Unfortunately, you can't call the Java System output methods directly because the PrintStream output methods are overloaded. Instead, we need to use reflection to call the print methods. Here are some functions you can place in a FUNCLIB that allow you to print to stdout and stderr from PeopleCode:

/*
 * Print a line of text to stdout
 */
Function println_to_stdout(&message As string)
   Local JavaObject &jSystem = GetJavaClass("java.lang.System");
   Local JavaObject &jOutStream = &jSystem.out;
   Local JavaObject &jCls = GetJavaClass("java.lang.Class");
   Local JavaObject &jStringClass = &jCls.forName("java.lang.String");
   Local JavaObject &jPrintStreamCls = &jOutStream.getClass();
   Local JavaObject &jPrintlnArgTypes = CreateJavaObject("java.lang.Class[]", &jStringClass);
   
   Local JavaObject &jPrintlnMethod = &jPrintStreamCls.getDeclaredMethod("println", &jPrintlnArgTypes);
   
   &jPrintlnMethod.invoke(&jOutStream, CreateJavaObject("java.lang.Object[]", &message));
   rem ** I didn't find flushing necessary, but here is where you would flush the buffer if desired;
   rem &jOutStream.flush();
End-Function;

/*
 * Print a line of text to stderr
 */
Function println_to_stderr(&message As string)
   Local JavaObject &jSystem = GetJavaClass("java.lang.System");
   Local JavaObject &jOutStream = &jSystem.err;
   Local JavaObject &jCls = GetJavaClass("java.lang.Class");
   Local JavaObject &jStringClass = &jCls.forName("java.lang.String");
   Local JavaObject &jPrintStreamCls = &jOutStream.getClass();
   Local JavaObject &jPrintlnArgTypes = CreateJavaObject("java.lang.Class[]", &jStringClass);
   
   Local JavaObject &jPrintlnMethod = &jPrintStreamCls.getDeclaredMethod("println", &jPrintlnArgTypes);
   
   &jPrintlnMethod.invoke(&jOutStream, CreateJavaObject("java.lang.Object[]", &message));
   rem ** I didn't find flushing necessary, but here is where you would flush the buffer if desired;
   rem &jOutStream.flush();
End-Function;

If you want to use the PrintStream.print method instead of the println method, copy the code above, rename the function, and change the &jPrintlnMethod assignment from "println" to "print".

If you've worked with Java, then you know that you can redirect stdout and stderr to another PrintStream. For example, you can redirect stdout to a file or a network socket connection. Here is some code demonstrating how to redirect stdout and stderr to a different file:

/*
 * Redirect stdout to file
 */
Function redirect_stdout(&fileName as string)
   Local JavaObject &jSystem = GetJavaClass("java.lang.System");
   Local JavaObject &jfos_out = CreateJavaObject("java.io.FileOutputStream", &fileName, True);
   Local JavaObject &jps_out = CreateJavaObject("java.io.PrintStream", &jfos_out, True);
   &jSystem.setOut(&jps_out);
End-Function;

/*
 * Redirect stderr to file
 */
Function redirect_stderr(&fileName as string)
   Local JavaObject &jSystem = GetJavaClass("java.lang.System");
   Local JavaObject &jfos_out = CreateJavaObject("java.io.FileOutputStream", &fileName, True);
   Local JavaObject &jps_out = CreateJavaObject("java.io.PrintStream", &jfos_out, True);
   &jSystem.setErr(&jps_out);
End-Function;

By redirecting stdout and stderr, you could actually create 3 separate output files without using the File object. The benefit of using a redirected stdout over a File object is that you can setup your stdout location in one step of your program and write to that same file from anywhere else in the program without having to open/close a File object on every step.

The App Server

Just a side note: Many of the techniques demonstrated in this post can be used online. Using System.out.println, you could print to the app server's stdout file. Likewise, the reporting solutions above could be used from an online PeopleCode event to generate reports online.

log4j and PeopleCode Part III

John Wagenleitner has posted some additional ways to configure log4j with PeopleCode in his post, appropriately titled, Log4j in PeopleCode. If you are considering using log4j with PeopleCode, you will want to take a look at the comments. Scheming together, John and I have come up with a couple of ways to store the log4j configuration in the PeopleSoft database. This is critical if you work in an environment where you don't have access to the application server's file system.

log4j and PeopleCode Part II

Last month I wrote about using log4j to debug PeopleCode. This is a tool that I use quite often. Here are a couple more hints to help you use log4j from PeopleCode.

One of the main benefits of log4j is the ability to configure, and reconfigure, log4j without modifying your code. However, sometimes a configuration file is not practical. Here is an example of configuring log4j from PeopleCode:

Local JavaObject &logger = GetJavaClass("org.apache.log4j.Logger").getLogger("my.custom.logger");
Local JavaObject &layout = CreateJavaObject("org.apache.log4j.PatternLayout", "%-4r %d [%t] %-5p %c [%x] - %m%n");
Local JavaObject &appender = CreateJavaObject("org.apache.log4j.ConsoleAppender", &layout);

&appender.setLayout(&layout);

&logger.addAppender(&appender);
&logger.setLevel(GetJavaClass("org.apache.log4j.Level").DEBUG);
&logger.debug("Hello from a PeopleCode configured logger.");

Running this code on the AppServer will write log messages to the AppServer's stdout file. log4j has several other appenders that may be more practical if the AppServer's stdout file is not accessible. Here is a configuration example that uses the SMTPAppender to send log messages to an e-mail address (preferrably your e-mail address).

Local JavaObject &logger = GetJavaClass("org.apache.log4j.Logger").getLogger("jjm.email.debugger");
Local JavaObject &layout = CreateJavaObject("org.apache.log4j.HTMLLayout");
Local JavaObject &appender = CreateJavaObject("org.apache.log4j.net.SMTPAppender");

&appender.setSMTPHost("mail.yourserver.com");
&appender.setFrom("log4j@yourserver.com");
&appender.setTo("you@yourserver.com");
&appender.setSubject("PeopleCode debug log");
&appender.setBufferSize(1);
&appender.setLayout(&layout);
&appender.activateOptions();

&logger.addAppender(&appender);
&logger.setLevel(GetJavaClass("org.apache.log4j.Level").DEBUG);

&logger.fatal("Hello from PeopleCode!");

One thing to note about the SMTPAppender is that it only sends error and fatal log messages to the specified e-mail address.

About error messages... As you know, error is a key word in PeopleCode. Therefore, it is not possible to execute the error method of the Logger object directly. However, you may be able to get around this by using Java's reflection to execute the method.

Logging PeopleCode

Using log4j to debug applications

Developers log many different things about applications for various reasons. For example, a developer may log application state, application execution, or application usage for the purposes of finding bugs, resolving errors, recovering from system failures, tracking usage, or auditing security. While all these reasons are necessary, this post is going to focus primarily on logging state and execution for the purposes of finding bugs and resolving errors.

PeopleTools 8.4 provides developers with a mechanism for tracing PeopleCode and SQL. I have found the SQL trace facility to be very valuable. I usually use an SQL trace value of 7 (the first 3 options: 1, 2, 4). This SQL trace value displays SQL statements, bind values, and commit/rollbacks.

While the verbosity of a PeopleCode trace provides a developer with all of the information necessary to debug a PeopleCode program, I find that it provides too much information to be valuable. Fortunately, there are alternatives for determining application state and "peeking" at variable values when debugging an application.


MessageBox

The MessageBox function is one of the most useful debugging tools available to a PeopleSoft developer. By inserting a single line of code into a program, a developer can instantly view information about a program's execution. Unlike a PeopleCode trace, the MessageBox function only displays the information that you, the developer, want to see.

What is wrong with the MessageBox function? The MessageBox function was my best PeopleCode debugging tool. Unfortunately, those MessageBox statements didn't disappear by themselves after I found and fixed a bug in a PeopleCode program. Rather, I had to manually find and remove those statements. Maybe it is the pack-rat in me, but I don't like to delete anything. You never know when you might need those MessageBox debugging statements again... right? Wouldn't it be nice if you could just turn off those debugging statements rather than delete them?

What about PeopleCode programs that don't have a user interface? Yes, the MessageBox function works fine for AppEngine PeopleCode programs. However, rather than just print the message to the message log, the MessageBox function prints several unwanted informational lines for each call to the MessageBox function.

What about additional targets? The MessageBox function is a user interface function. Don't expect to log to an SMTP or other Socket target from the MessageBox function.


log4j, An Alternative

Caveat: This post is not meant to be a log4j tutorial. Rather, with this post, I hope to demonstrate an alternative method for debugging and logging PeopleCode program executions. For a better understanding of the log4j framework, I refer you to the log4j web site.

I have used log4j for several years. It is my favorite Java logging framework. As you will see from the various ports of log4j, I'm not the only programmer that prefers log4j. Unfortunately, I didn't see a log4pc (pc=PeopleCode) on the list of ports.

Because I have had a lot of success using log4j, I took my turn at writing a PeopleCode port of log4j using Application Packages. I was quite pleased with my work! About half way through the code porting process, I ran into some log4j functionality that I couldn't seem to replicate in PeopleCode, specifically the MDC and NDC. To work past these, limitations, I thought I would just use the log4j Java compliments (not a pure PeopleCode approach, I know, but it worked). As I was considering this approach, I thought... Hmmm... Why not just use the log4j package as written directly from PeopleCode? PeopleCode supports Java objects and PeopleSoft delivers the log4j lib in the PS_HOME/class directory.


Why log4j instead of MessageBox?

The log4j framework is very flexible. With log4j you can litter your code with debug statements. Those debug statements will hide silently in your code until you turn on debugging. log4j also allows you to specify multiple targets. Delivered log4j targets include socket, database, file, e-mail, and system log appenders. log4j allows you to use layouts to configure how log statements are written to logging targets. You can configure some statements to log to one target while other statements log to a different target. Best of all, you can configure the log level, targets, and layouts from a configuration file without touching your production code.


Using log4j

The following is an example of some PeopleCode that creates a log4j logger and writes debug information to a target.

Local JavaObject &logger = GetJavaClass("org.apache.log4j.Logger").getLogger("com.mycompany.mydepartment.PS.Component.Record.Field.Event");
logger.debug("Logger created");
... do some processing ...
logger.info("Process completed successfully");

Line 1 creates a log4j logger with a name of com.mycompany.mydepartment.PS.Component.Record.Field.Event. log4j recommends using the Java class name of the object that is executing logging statements. Since we are using PeopleCode, not Java, I like to use a concatenation of my domain name, department name, PS (for PeopleSoft, or ERP for enterprise applications, etc), the object name (component, record, field), and event name.

Line 2 writes a debug level statement to the logger.

Line 4 writes an informational statement to the logger.

If the log level in the configuration file was specifically set to only display information, warnings, and errors, then statement 2 above would have executed silently. Using the log4j API from PeopleCode, your code can dynamically change the log4j configuration. For example, you could use &logger.setLevel(...) to set the log level to a level other than the configuration file value.

You can find a sample log4j.xml configuration file here. Place this file in your AppServer PS_HOME/class directory. If you are logging from an AppEngine program, then be sure to put your configuration file in your process scheduler's PS_HOME/class directory.

Because log4j uses the logger name to create an inheritance tree of loggers, you don't have to explicitly define every logger by name. Instead, you can define a short name logger and all loggers with the same prefix will inherit the definition of the shorter logger name. For example, if you defined a logger named com.mycompany.mydepartment.PS and then created a logger named com.mycompany.mydepartment.PS.Component.Record.Field.Event, then the com.mycompany.mydepartment.PS.Component.Record.Field.Event logger would inherit the definition of the com.mycompany.mydepartment named logger.


AppEngine log statements that communicate to users

Because the process scheduler redirects an AppEngine program's stdout to a a text file, any output written to the console by log4j is available to your users from the View log/trace link in the process scheduler. Using layout patterns and log4j, you can create logs that can be used by you, the developer, and your users to tell your users what happened and to tell you where that "what" happened.


Writing to the database

Rather than maintain a database user to log statements through the log4j JDBCAppender, I wrote a custom log4j appender that used PeopleSoft's Java PeopleCode objects. The benefit of using these PeopleSoft Java objects was that I could use the existing database session to write to the database. However, since database connectivity problems are something I have to occasionally debug, I never used this appender in production. Instead, I chose to use one of the delivered, simple appenders like the file or console appender.