Improve Log Management with OpenEdge SQL Logging

September 07, 2017 Application Development, OpenEdge

OpenEdge 11.7 includes new log management controls that let you fine-tune log levels and options, saving server resources and making it easier to find problems.

Progress OpenEdge 11.7 features improved SQL logging, giving better control over logging information. A user can fine-tune the SQL logging information when server or connection level logging is enabled on the SQL server or on the SQL client connection respectively. Users enable SQL logging for various purposes and sometimes may not require detailed logging information, so SQL logging helps users log only the information they need. Controlled logging information helps users to better utilize the server resources which best serve their requirements. 

Progress OpenEdge SQL is capable of turning on logging at server and connection levels. If a user turns on logging at server level, all the connections connected to the server log information about SQL statements, as per the defined logging option and level. If a user turns on logging at connection level, only the one connection that turned logging on writes information to a log file, and other connections remain unaffected.

Enable SQL Logging

A user can enable SQL logging using either the “SET PRO_SERVER LOG” or “SET PRO_CONNECT LOG” statement. In addition to logging levels, users can specify logging options. OpenEdge SQL supports four types of logging options: STATEMENT, INOUT, QUERY_PLAN and PRO_TABLESCAN_EVENT.

The logging options define content - the types and categories of information to log. The levels define volume, or amount and granularity, of information. The level is like a slider control – as you push it higher it shows more and more detail. Logging level 1 gives the least output, and level 4 gives the most detailed output. The level does not define the content by itself, and the set of options don't define the information by themselves. Together they define the logging output. The default logging option is set to STATEMENT and log level 1.

The syntax is as follows:


Enabling PRO_SERVER LOG writes information for all queries executed by the server. This means that information is logged for all client connections if the user enables PRO_SERVER LOG. On the other hand, enabling PRO_CONNECTION LOG writes information for all the queries which are executed only on the one client connection for which logging is enabled. Other client connections to the server will not be effected by this statement.

The following table describes logging level options:

Option

Logging information

STATEMENT

Logs information about SQL statement tracing

INOUT

Logs information about in and out parameters to query/procedure

QUERY_PLAN

Logs query plan information

PRO_TABLESCAN_EVENT

Logs information about all the table scans

 

Log Files

SET PRO_SERVER LOG writes information to a file with the name: SQL_server_<server-id>_<ddmmmyyyy>_<hhmmss>.log. SET PRO_CONNECTION LOG writes information to a file with the name: SQL_connection__<server-id>_<thread_id><ddmmmyyyy>_<hhmmss>.log

Trace information at each logging level

LOGGING OPTION

LOGGING LEVEL

Type of information logged

STATEMENT

LEVEL 1, 2 & 3

SQL statement and basic information about prepare and describe

LEVEL 4

Details of record fetching calls and connection time logging

INOUT

LEVEL 1 & 2

None

LEVEL 3

Input parameters to a query or statement

Output parameters from a query

LEVEL 4

LOB input/output parameters (between client and server)

QUERY_PLAN

LEVEL 1, 2, 3 & 4

Query and optimized query plan

PRO_TABLESCAN_EVENT

LEVEL 1, 2, 3 & 4

Information about tables on which table scan took place in the query

 

Examples for switching on logging:

SET PRO_SERVER LOG ON

 

Enables server logging with logging option set to STATEMENT and log level set to 1

SET PRO_SERVER LOG ON WITH (QUERY_PLAN)

 

Enables server logging with logging option set to QUERY_PLAN and log level set to 1

SET PRO_SERVER LOG ON WITH (STATEMENT, QUERY_PLAN) AND WITH LEVEL 2

 

Enables server logging with logging option set to STATEMENT and QUERY_PLAN and log level set to 2

SET PRO_SERVER LOG ON WITH LEVEL 2 AND WITH (STATEMENT, QUERY_PLAN)

 

Same as above example but with a change in syntax. The order of phrases doesn’t matter

SET PRO_CONNECTION LOG ON WITH (STATEMENT, QUERY_PLAN) AND WITH LEVEL 3

 

Enables connection logging with logging option set to STATEMENT and QUERY_PLAN and log level set to 3

 

Example log with level 1 and log option STATEMENT:

Create a copy of sports2000 database and connect to it using a client. Switch on logging using the following statement. This will create a new log file with name SQL_server_<server-id>_<ddmmmyyyy>_<hhmmss>.log:

SET PRO_SERVER LOG ON WITH (STATEMENT) AND WITH LEVEL 1;

 

Execute following SQL statement:

SELECT TOP 10 NAME FROM PUB.CUSTOMER ORDER BY 1;

 

SQL generates the following (similar) contents into the log file:

SQL LOG Section Started at xxx

 

SQL Environment Variable Settings:

CLASSPATH=<classpath>

 

SQL LOG CONFIGURATION

STATEMENT

LOGGING LEVEL 1

 

SQL LOG FILE MAXIMUM SIZE: 500000000 Bytes

 

SQL SERVER ID: 1

 

20170831_032427 140146796631808:

Returning from sql_fn() with code: 0

20170831_032506 140146796631808:

Freeing Cursor for SQL Statement id : 140146796631808150416426736862

20170831_032506 140146796631808:

Returning from sql_fn() with code: 0

20170831_032506 140146796631808:

Setting Cursor for SQL Statement :

20170831_032506 140146796631808:

Returning from sql_fn() with code: 0

20170831_032506 140146796631808:

Preparing SQL Statement id : 140146796631808150416430636862 : SELECT TOP 10 NAME FROM PUB.CUSTOMER ORDER BY 1

20170831_032506 140146796631808:

Returning from sql_fn() with code: 0

20170831_032506 140146796631808:

Describing SQL Statement id : 140146796631808150416430636862

20170831_032506 140146796631808:

Returning from sql_fn() with code: 0

20170831_032506 140146796631808:

Opening SQL Statement id : 140146796631808150416430636862

20170831_032506 140146796631808:

Returning from sql_fn() with code: 0

20170831_032506 140146796631808:

Returning from sql_fn() with code: 0

20170831_032506 140146796631808:

Closing SQL Statement id : 140146796631808150416430636862

20170831_032506 140146796631808:

Returning from sql_fn() with code: 0

 

In the above example, 20170831_032427 and 20170831_032506 are timestamps and 140146796631808 is the thread id.

Example log with level 3 and log option INOUT:

Create following stored procedure using sports2000 database. This procedure displays customer name for a given customer number:

DROP PROCEDURE getCustName;

COMMIT WORK;

CREATE PROCEDURE getCustName (IN cust_num INTEGER, OUT status_code INTEGER)

RESULT (

name CHARACTER(30)

)

BEGIN

String sname = "";

status_code = 0;

 

SQLCursor cust_cursor = new SQLCursor ("select name from pub.customer where custnum = ?");

 

cust_cursor.setParam (1, cust_num);

cust_cursor.open ();

cust_cursor.fetch ();

while (cust_cursor.found())

{

status_code = 1;

sname = (String) cust_cursor.getValue(1, CHARACTER);

 

SQLResultSet.set (1, sname);

SQLResultSet.insert ();

 

cust_cursor.fetch();

}

cust_cursor.close ();

END

COMMIT WORK;

 

Switch on logging. This will create a new log file with name SQL_server_<server-id>_<ddmmmyyyy>_<hhmmss>.log:

SET PRO_SERVER LOG ON WITH (INOUT) AND WITH LEVEL 4;

 

Create the following java program and run it after configuring “url”, “userid” and “passwd” (CustName.java):

import java.sql.*;

 

public class CustName {

public static void main(String[] args) {

try {

// initialize variables

String url = "jdbc:datadirect:openedge://localhost:8889;databaseName=sp";

String userid = "user";

String passwd = "password";

String callString = "{CALL getCustName (?, ?)}";

CallableStatement viewcustname;

int CustNum = 1;

ResultSet rs;

 

// loads the driver object

Class.forName("com.ddtek.jdbc.openedge.OpenEdgeDriver");

// creates a connection object

Connection con = DriverManager.getConnection(url, userid, passwd);

// Prepare the statement

viewcustname = con.prepareCall(callString);

// Bind the parameter

viewcustname.setInt(1, CustNum);

viewcustname.registerOutParameter(2, java.sql.Types.INTEGER);

// Execute the statement

viewcustname.execute();

rs = viewcustname.getResultSet();

while (rs.next()) {

String name = rs.getString(1);

System.out.println("Customer name with customer number " + CustNum + " is \"" + name + "\"");

}

System.out.println("\nStatus Code " + Integer.toString(viewcustname.getInt(2)));

 

viewcustname.close();

con.commit();

con.close();

}

catch (SQLException ex) {

// If an SQL Exception was generated. Catch it and display the error information.

// Note that there could be multiple error objects chained together.

// System.out.println ("** Error In SQLException: \n");

while (ex != null) {

System.out.println ("SQLState : " + ex.getSQLState ());

System.out.println ("Message : " + ex.getMessage ());

System.out.println ("VendorCode : " + ex.getErrorCode ());

ex = ex.getNextException ();

System.out.println ("");

}

}

 

catch (java.lang.Exception ex) {

System.out.println ("** Error In java.lang.exception: \n");

// Got some other type of exception - dump it.

ex.printStackTrace ();

}

}

}

 

 

SQL generates the following (similar) contents into the log file:

SQL LOG Section Started at xxx

 

SQL Environment Variable Settings:

CLASSPATH=<classpath>

 

SQL LOG CONFIGURATION

INOUT

LOGGING LEVEL 4

 

SQL LOG FILE MAXIMUM SIZE: 500000000 Bytes

 

SQL SERVER ID: 2

 

20170816_074456 140396435957504:

Input Parameters to Execute Statement id: 14039643595750415028838951265

[0]: cust_num = (1)

[1]: status_code = NULL

20170816_074456 140396435957504:

Input Parameters to Open Statement id: 14039643595750415028838981265

[0]: (1)

20170816_074456 140396435957504:

Output Parameters on Fetch for Statement id : 14039643595750415028838981265

[0]: (Lift Tours)

20170816_074456 140396435957504:

Output Parameters on Fetch for Statement id : 14039643595750415028838981265

[0]: (Lift Tours)

20170816_074457 140396435957504:

Input Parameters to Open Statement id: 14039643595750415028838951265

[0]: cust_num = (1)

[1]: status_code = (1)

20170816_074457 140396435957504:

Output Parameters on Fetch for Statement id : 14039643595750415028838951265

[0]: NAME = (Lift Tours)

 

In the above example, 20170816_074456 and 20170816_074457 are timestamps and 140396435957504 is the thread id.

Benefits of SQL Logging

There are many benefits to utilizing this level of control over SQL logging. The logging levels help make sure you only get the information you need, improving clarity and saving server resources. Along with the option to log information from a single client, this makes it easier to diagnose issues.

This new capability is one of a number of new additions to OpenEdge 11.7 that will help you build the applications your business needs. To learn more about the latest in OpenEdge, feel free to check out what’s new.

OpenEdge SQL

Dileep Dasa

Dileep Dasa was a Sr. Engineer at Progress.

Read next The Key Benefits of CI/CD - Continuous Integration and Delivery