Using the Remote Logging Facility

Table of Contents

Quick Start: Runnng the Demos

1. Get copies of logging.tar and logdemo.tar
2. Untar logging.tar in a clean directory.
   You can use any name you like for this directory, say logdir.
3. Untar logdemo.tar in another directory.
   You can use any name you like for this directory, say demodir.
4. In logdir execute runit
   This should start the logging GUI.
   You should see a small window called Control Frame
   Click on the Output button.
   This should pop up another window, called Output Frame.
5. In the logdemo directory, you may have to edit the file makefile.
       Under Linux:
                remove the -lsocket from the third line of makefile.
       Under MAC OS X:
                remove the -lnsl -lsocket from the third line of makefile.
   
6. In the logdemo directory, execute make.
   This should compile all of the demo programs.
   If this gives some errors, try just make chain.
7. In the logdemo directory, try a demo program:      chain

The Demos

chain
The chain program makes a connection to the GUI, and logs a start message giving the time of day. It then creates 3 children. Each process (including the parent) then wastes a random amount of time (up to 100 ms.) and logs a message giving its process ID, its parent's process ID and the time.

Right after the connection is made, chain calls lsendtime which causes the time (in seconds and microseconds) to be sent with each message. (This feature was added after the above paper was published.) In the Output window, pushing the Show Receive Time button changes the label of thsi button to Show Send Time and the time the message was sent (rather the the time it was received) is shown in the Time column of the output window. This demo illustrates logging from related processes on the same machine.

threadi
The threadi program creates 4 threads, each executing do_it. This function reads 3 tokens from standard input and logs a message after each token is read. All 4 threads are competing to read from standard input. After reading a token, the thread wastes a random amount of time up to 100 ms. The main program calls lsendtime adter making the connection, so the GUI can report either the time the message was received or the time the message was sent.

reply_server and request_client
These programs work as a pair. Start the reply server with a command line argument giving the port number it will use for listening. For example:
     reply_server 12345
Then start the request_client giving the name of the host that reply_server was started on and the port number used to start reply_server. For example:
     request_client localhost 12345
The request_client makes a connection to the reply_server The reply_server sends the current time to the request_client which recieves the reply and exits. The reply_server then waits for another request.

Each process opens a connection to the logging GUI and logs messages when action is taken.

This demo illustrates the logging from independent processes.

It is possible to run the demos on a machine other than the one running the logging GUI. The reply_server and request_client do not have to be on the same machine.

It is suggested that you read the paper described above if you are serious about using this library.

Overview

A logging GUI can be run on any machine that has a Java runtime library. It allows several windows to be displayed that give different views that the data being logged.

The C language interface consists of a number of files that give remote logging capability to any C program that is compiled with these files. First a connnection to the GUI is established with the lopen function that takes a hostname and port number as parameters. This is assigned a unique connection number by the GUI. The host name is the name of the host running the GUI and the port number is the one used by the GUI. The lopen returns a pointer of type LFILE which is used as a parameter in the other logging functions. Messages are sent to the GUI using the lprintf functions which has syntax similar to that of fprintf. Each message is sent with along with a generator string that identifies the sender. This may be the process ID and/or thread ID of the sender, or some other string the sender wants to include.

Messages can be organized by the order in which they are received, by the generator string, or by the connection number. In addition, the sender can automatically attach the time the message was sent (using the local time of the sender) and this can be displayed by the GUI. This is usefull when all messages are sent from the same machine or form machines that have synchronized clocks.

Using the Logging GUI

• Speicify the port number on the command line when you start the GUI, e.g.
       java LoggingServer 12345
  starts the GUI using port number 12345.
• Specify the port number with the LOGGINGPORT environment variable:
       setenv LOGGINGPORT 12345
       java LoggingServer
  
• Use the default port number, 20100. To do this, do not set and environment variable and start the GUI without a port number argument:
       java LoggingServer
  The demos use this last method.

When the GUI is started, a window called the Control Frame similar to the one shown below appears.

The three windows that can be opened from the Control Frame are the Output Frame, the Connections Frame and the Generators Frame.

The Output Frame shows all of the output received by the GUI in the order it was received. Below are several views of the Output Frame.

• Each message recieved by the GUI, including the opening and closing of connections is given a message number and this is shown in the first column.
• Each connection is given a unique connection number and the connection number for each message is shown in the second column.
• Each message is sent with a generator string that identifes the sender. The generator string is shown in the third column. By default, this string is the process ID of the sending process. In a threaded environment, the thread ID is also included in the generator string. The sender can send any string as the generator string.
• The fourth column show a time corresponding to the message. By default, the number of seconds since the first message was received is displayed, using three decimal places. This indicates when the message was received, not when it was sent. This is illustrated in the first view of the Control Frame given below which shows output from the chain demo.
• The fifth column shows the acutal message sent, or an indication that the connection was opened or closed.

The button below the time format button just described can be used to show the send time rather than the receive time. The send time is an optional part of the message the the sender may send. Not all message will have a send time. If no send time is available, nothing will be displayed in the time column when this display option is chosen. To show the send time instead of the receive time, click on Show Receive Time. This changes the button to Show Send Time and the send time is displayed in a format corresponding to the time format button. The three views of the send time are displayed below. The send time is always dispayed with 6 decimal places of accuracy, giving time in microsecond resolution. Note that this time is based on the sender's clock, so if more than one host is sending messages, the clocks may not be synchronized.

The Connections Frame shows one line for each connection made to the GUI. The connection number, the time the conneciton was opened, and the number of messages for the connection are shown. If the connection was closed, the time it was closed and the number of seconds it was open are also shown. All times shown in the Connection Frame are relative to the GUI, not the sender. The same three options for displaying the time as in the Output Frame are available for the Open Time and Close Time. The button labeled Show Receive Time does not afftect times displayed in the Connections Frame but sets the default for each Conneciton Frame as described below. A typical Connections Frame is shown below.

Saving output to a file By clicking on the button in the Control Frame a file can be created to hold the output data shown in any of the other windows. Once open, the Log button in the upper right corner of these windows puts the contents of the window in the log file in HTML format.

The < and > in the top corners of these windows allow you to increase or decrease the size of the font used for the display in these windows.

Compiling a C Program

The makefile shows how to link a non-threaded program such as chain to the logging library. Under Linux you will need to remove references to the socket library (-lsocket) and under MAC OS X you will need to remove references to both the socket and the nsl library (-lnsl -lsocket).

To compile with a program using POSIX threads, use the -DLUSETHREAD compiler option as shown in the makefile for the threadi demo. This allows the thread ID to be sent as part of the generator and makes the library thread-safe by locking some very small critical sections.

Using the Logger from a C Program

The connection to the GUI can be closed with the lclose function.
             int lclose(LFILE *mf);
This returns 0 on success and -1 on failure. The lclose function is not thread-safe. You should not close the connection while other threads can send messages to the GUI. Making this function therad-safe would add considerable overhead to the logging functions and it was decided that this was not necessary.

The lsendtime function causes future messages to include the time the message was sent. The time is sent as two integer values, one representing the number of seconds since the epoch and the other representing a number of microseconds. The values are those returned from gettimeofday. This adds some extra overhead to each logged message and should be avoided unless this information is useful.

Each message is sent with a generator string describing the sender of the message. Be default, the generator is the process ID of the process sending the message. In a threaded environment (compiled with -DLUSETHREAD) the generator is the process ID following by a period followed by the thread ID. The lgenerator function can be used to change the default generator.
             int lgenerator(LFILE *mf, char *gen);
The gen is a string that will be the new generator. The first ocurrence of %p is replaced with the process ID of the process sending the message. In a threaded environment, the first occurrence of %t is also replaced by the thread ID.

Messages are sent either with lprintf or lprintfg.
             int lprintf(LFILE *mf, char *fmt, ...);
             int lprintfg(LFILE *mf, char *gen, char *fmt, ...);
These are identical except that the latter uses gen for the generator of this message only. The former uses the default generator. These functions return 0 on success and -1 on failure. The syntax and paramters are similar to fprintf where fmt specifies a format string and the remaining parameters are values to be included in the message. These functions allow one additional format specification, %t which is replaced by the current time with a precision of milliseconds. If the messages are automatically including the time (because of a previous call to lsendtime), the same time is used.