SQL Logging

Overview

SQL Logging is the ability to view SQL statements submitted to SAS Federation Server, combined with other information such as the user who submitted the SQL and a breakdown of the SQL into prepare, execute and cursor phases. Metrics are also available, including elapsed time, number of rows fetched, and size of data moved (fetched or inserted). SQL Logging provides critical information for all server activity, so it can easily be determined who is accessing the system, when they were connected, and what work they performed.
Errors and informational messages that occur when writing SQL Log records to the EVENTS table are recorded in the server's log and appear with a prefix of DBAppender<SQL_LOG>:Append. See the Server Logging Configuration topic for more information about the logging facility for SAS Federation Server.

Configuring SQL_Logging

Introduction

Configuration of SQL Logging is facilitated using dfs_log_SQL_Logging.xml located in the /etc directory of the Federation Server installation path.

Enable SQL Logging

To enable SQL Logging, open dfs_log_SQL_Logging.xml for editing and set the top-level logger to TRACE. There is no need to change any of the configuration parameters. The logging level value should always be set at TRACE so that all information is captured.
Following top-level logging are transactions that you can use to control SQL Logging detail. Remove the comment marks from each line to display logging details:

Enable SQL Logging in SAS Federation Server Manager

SAS Federation Server always starts with SQL Logging set at the default level in the configuration file, but can be enabled or disabled dynamically for a server session. This is done through the SQL Log tab of the Federation Server Properties dialog box. When SQL Logging is modified from the SQL Log tab, it is active for the server session only. When the server is restarted, the level of logging reverts to the value specified in the SQL logging configuration file.
Note: Configuring SQL Logging in SAS Federation Server Manager activates logging for the server session only.
To enable SQL Logging in SAS Federation Server Manager:
  1. Select a Federation Server in the tree.
  2. Open the action menu in the upper left corner and select Properties.
  3. The Federation Server Properties window appears. Click the SQL Log tab.
  4. Click to select On. Log SESSION and select the events to record.

Configuring a 3rd Party DBMS for SQL Logging

If you are using a database other than the SQL_LOG database that installs with SAS Federation Server, set up your database according to vendor specifications. SAS Federation Server is shipped with example configuration files for a few select databases such as Oracle and DB2. These files are located in the /etc directory of the Federation Server installation path. After setting up your database and specifying the domain, configure a connection to the driver, and modify the data types to suit your environment as outlined below.
Change the Domain
Using the ALTER DATA SERVICE command, change the domain for SQL_LOG to the domain that was created for the data service. Here is an example:
ALTER DATA SERVICE SQL_LOG domain ORA1
Modify the Connection String
Modify the connection string to include the values for your SQL Logging database. Here is an example,
param name="connectionString"
value="CATALOG=*;DEFAULT_CATALOG=catalog_name;DRIVER=driver;
CONOPTS=(DSN={yourdsn};UID='your user id';PWD='your password')"
For a list of possible connection options see the Database Functionality and Driver Performance in this guide.
Create the Table / Modify Data Types
At the end of the CREATE TABLE statement, update 'IN <name of your table space>' to reflect the value for your setup.
Modify the columns that appear in the SQL Logging configuration file to map to data types supported by the new database. A complete list of SQL Logging columns and data types appears in The EVENTS Table. 
CREATE TABLE &DFS_DBAPPENDER_TABLE;
    (ARM_NAMESPACE VARCHAR(256),
    TRAN_TIMESTAMP TIMESTAMP,
    APP_HANDLE VARCHAR(36),
    APP_ID VARCHAR(36),
    APP_NAME VARCHAR(50),...
    ) IN <name of your table space>"/>
Note: For additional setup information, refer to the sample configuration files located in the /etc directory of the Federation Server installation path.

ARM Transactions

The table below shows the ARM transactions that are captured in SAS Federation Server. When SQL Logging is enabled, information in each of the transactions is captured. Following the table is a brief explanation of each of the transactions.
Name
Type
Associated Namespace
SESSION
Session transaction
Perf.ARM.FederationServer.Session.Transaction.SESSION
DBC
Database connection
Perf.ARM.SQLServices.Connection.Transaction.DBC
DBTRAN
Database transaction
Perf.ARM.SQLServices.Connection.Transaction.DBTRAN
SQL
SQL statement
Perf.ARM.SQLServices.Statement.Transaction.SQL
Prepare
SQL Statement
Perf.ARM.SQLServices.Statement.Prepare
Execute
SQL Statement
Perf.ARM.SQLServices.Statement.Execute
CURSOR
SQL Statement
Perf.ARM.SQLServices.Statement.Transaction.CURSOR
Fetch Scroll
SQL Statement
Perf.ARM.SQLServices.Statement.FetchScroll
SetPos
SQL Statement
Perf.ARM.SQLServices.Statement.SetPos
BulkOps
SQL Statement
Perf.ARM.SQLServices.Statement.BulkOperations
Fetch
SQL Statement
Perf.ARM.SQLServices.Statement.Fetch
  • SESSION: (Session Transaction) A session transaction starts when a user initiates a server session.
  • DBC: (Database Connection) A database connection transaction is a child object of the SESSION transaction. A database connection begins when a user connects to a data source and ends when the user disconnects from the data source.
  • DBTRAN: (RDBMS Transaction) DBTRAN is the actual database transaction. It is a child object of the DBC transaction. A DBTRAN transaction begins with an established driver connection, or when a previous transaction is committed or rolled back, such that a new one begins. DBTRAN records are written to the log only if AUTOCOMMIT is set to OFF. The DBTRAN transaction stops when AUTOCOMMIT is set to ON or when a COMMIT or ROLLBACK command is issued. SQL statements can span DBTRAN transaction boundaries.
  • SQL: (SQL Statement) SQL is a logical transaction. It encapsulates a series of activities related to one SQL statement. It is a child object of a DBC transaction. An SQL transaction starts when a user issues an SQL statement. Regardless of the statement type (DQL, DML or DDL) the SQL transaction stops when the statement is either closed, or the call to Prepare ends. Subsequent executions of the same statement are recorded under the same SQL transaction, even if the statement is a DQL and the result set associated with it has been is closed.
  • Prepare: The prepare transaction measures the Prepare phase of an SQL statement. It is a child object of an SQL transaction. The Prepare transaction starts when a user Prepares an SQL statement and stops when the call to prepare returns.
  • Execute: The execute transaction measures the Execute phase of an SQL statement. It is a child object of the SQL transaction. The EXEC transaction starts when a user executes an SQL statement and stops when the call to execute returns.
  • CURSOR: CURSOR is a logical transaction. CURSOR is a child object of an SQL transaction and it encapsulates all operations executed in a cursor, including reading, positioning and updates. The CURSOR transaction starts when the Execute transaction finishes. It stops when the cursor is closed. All operations on the same result set belong to the same CURSOR transaction.
  • Fetch/Fetch Scroll: The FETCH transaction is a child object of the CURSOR transaction. The FETCH transaction has an Execute transaction as its predecessor. It is started when a user issues the first fetch on a result set using Fetch or Fetch Scroll. It stops when the call to Fetch or Fetch Scroll returns.
  • SetPos: The SetPos transaction is a child object to a CURSOR transaction. The SetPos transaction has an execute transaction as its predecessor. It is started when a user issues a SetPos call and stops when the call returns.
  • BulkOperations : The BulkOperations transaction is a child object of a CURSOR transaction. The BulkOperations transaction has an Execute transaction as its predecessor. It is started when a user issues a call to BulkOperations and stops when the call returns.

The SQL_LOG Data Service and DSN

Whether SQL Logging is enabled or disabled on SAS Federation Server, the default configuration will automatically create an SQL_LOG data service and DSN. When the data service is created, the server also creates an SQL_LOG transactional database and creates an EVENTS table within the database. This table contains data captured for specific activity in the server, such as information about SQL statements submitted by connected users. The data service, DSN, database and table are always created so that they are available, even if the server is not initially invoked with SQL Logging enabled. As noted above, SQL Logging can be enabled or disabled dynamically at any time, so the server ensures that the SQL Logging constructs are always created when the server starts.
When connected to the SQL_LOG data service and DSN:
  • Catalog functions are restricted so that they only return the SQL_LOG table. Therefore, only the SQL_LOG catalog, schema, and table are visible.
  • Privileges will restrict access to anything other than the SQL_LOG table, therefore, only the SQL_LOG catalog, schema and table are visible.
  • The administrator can assign CONNECT privilege on the SQL_LOG DSN. Federation Server SQL Authorization Enforcement is enabled by default.
  • The administrator can assign CONNECT, SELECT, and DELETE privileges only.
  • You cannot create new tables or insert into tables through the SQL_LOG data service.
The valid privileges are CONNECT, SELECT and DELETE.
  • The SQL_LOG data service will allow SELECT or DELETE privileges for the active SQL Logging table and associated columns.
  • CONNECT is valid on the SQL_LOG data service, catalog, and DSN.
Use GRANT, REVOKE, or DENY to set privileges for the SQL_LOG data service, DSN, catalog, schema, table, and associated columns.

The EVENTS Table

About the EVENTS Table

The EVENTS table resides in the SQL_LOG database that is created with the SQL_LOG data service as a result of enabling SQL Logging. The EVENTS table contains transactional data records written from SAS Federation Server.
Data captured and stored in the EVENTS table includes the number of bytes inserted from an SQL transaction. This does not include any literal data sent to SAS Federation Server. Only data sent through bound memory buffers, such as parameter data, is included. Also, the number of bytes inserted reflects the amount of data stored in the bound memory locations. It does not reflect the size of the data on disk.

Managing the EVENTS Table

The EVENTS table must be managed manually. With SQL Logging enabled, data records are continuously written to the EVENTS table. Therefore, the table increases in size when the server is active and processing requests. SAS Federation Server maintains logging data indefinitely until the table is managed or purged. You can use the SQL console window to issue commands to manage the EVENTS table. By connecting with the SQL_LOG DSN which has FedSQL dialect enabled, use any SELECT or DELETE statement that is supported by the FedSQL language to manage the table.
CAUTION:
Do not change the name of the EVENTS table.

Determine the Size of the EVENTS Table

Because the size of the EVENTS table increases as activity is logged, you should check the size of the table periodically to determine whether records need to be archived or deleted. Use the following statement to calculate the amount of rows in the EVENTS table: 
SELECT COUNT(*) FROM EVENTS

Archiving Data in the EVENTS Table

As the EVENTS table grows in size, you can move data to another table for archive purposes. This is accomplished by creating a federated DSN to the SQL_LOG DSN and another data source to use for storing the archived data.
  • Use the following statement to move data to a new table:
    CREATE TABLE
<archive_catalog>.<archive_schema>.<archive_table> AS SELECT *
FROM SQL_LOG.SQL_LOG.EVENTS WHERE <where_condition>
  • To determine what records are needed, use the WHERE condition with dates:
    WHERE TRAN_TIMESTAMP > TIMESTAMP '2012-01-25 01:00:00'
  • To move data to an existing table, use the INSERT statement:
    INSERT INTO
<archive_catalog>.<archive_schema>.<archive_table> SELECT *
FROM SQL_LOG.SQL_LOG.EVENTS WHERE <where_condition>

Deleting Data in the EVENTS Table

Use the DELETE statement to remove outdated records that are no longer needed or have been archived. Here is an example: 
DELETE FROM SQL_LOG.SQL_LOG.EVENTS
WHERE TRAN_TIMESTAMP < TIMESTAMP ‘2011-04-11 12:00:00’

Columns and Data Types

The following table presents the columns and associated data types that reside in the EVENTS table.
Column and Data Types of the EVENTS Table  
Column
Data Type
Description
APP_HANDLE
VARCHAR(36)
A unique ID that is associated with an application instance.
APP_ID
VARCHAR(36)
The application ID.
APP_NAME
VARCHAR(50)
The application name.
ARM_NAMESPACE
VARCHAR(256)
The logger name (namespace) of the logging event.
AUTHORIZATION_ID
VARCHAR(128)
UUID for the user from the Authentication Server.
AUTHORIZATION_NAME
VARCHAR(128)
The user name from the Authentication Server.
BYTES_FETCHED
BIGINT
The size of data read in bytes.
BYTES_INSERTED
BIGINT
The size of data inserted in bytes.
CACHE_VIEW_CATALOG
VARCHAR(256)
The cache view catalog name.
CACHE_VIEW_NAME
VARCHAR(256)
The cache view name.
CACHE_VIEW_SCHEMA
VARCHAR(256)
The cache view schema name.
CATALOG_NAME
VARCHAR(256)
The catalog name.
CLIENT_CORRELATOR
VARCHAR(56)
The transaction’s client correlator (base64 encoded).
CONNECTION_DRIVER
VARCHAR(25)
The driver that was used for the connection. For example, FEDSQL, ORACLE, TERADATA, ODBC, MYSQL, DB2, and others.
CONNECTION_NAME
VARCHAR(256)
The expanded connection string.
CONNECTION_TRAN_HANDLE
VARCHAR(36)
The DBC transaction under which the current transaction is assigned to.
CURR_SAS_TIMEOFDAY
DOUBLE PRECISION
The current time-of-day for the ARM event.
CURR_SYSTEM_CPU_TIME
DOUBLE PRECISION
The process current system CPU time for the ARM event.
CURR_USER_CPU_TIME
DOUBLE PRECISION
The process current user CPU time for the ARM event.
CURRENT_CORRELATOR
VARCHAR(56)
The transaction’s correlator (base64 encoded).
CURSOR_TRAN_HANDLE
VARCHAR(36)
The CURSOR transaction under which the current transaction is assigned to.
DBTRAN_STATE
VARCHAR(15)
The state of the current transaction, such as OPEN, CLOSED.COMMIT, CLOSED.ROLLBACK.
DBTRAN_TRAN_HANDLE
VARCHAR(36)
The UUID that points to the driver’s DBTRAN transaction handle, which is not its parent (the CONNECTION handle is parent) since the SQL can span multiple DBMS transactions.
EVENT_SEQUENCE
BIGINT
A unique value associated with the ARM record. Values increase for each record, usually with an increment of 1 (database-specific).
EXEC_PARAM_DATA
VARCHAR(1024)
The XML format for encoding parameter array data.
GROUP_NAME
VARCHAR(128)
The group name of the application instances.
IO_COUNT
BIGINT
The total number of process disk, tape or related input and output operations for the transaction event.
IP_ADDRESS
VARCHAR(48)
The IP address of the client.
LOGIN_ID
VARCHAR(128)
The current user ID that is associated with the transaction.
MEM_CURRENT
BIGINT
The current process memory utilization for the transaction event.
MEM_HIGH
BIGINT
The highest amount of process memory used for the transaction event.
OBJECT_NAME
VARCHAR(256)
The object name used in the SQL statement.
OBJECT_TYPE
VARCHAR(60)
The type of object that was accessed.
PARENT_CORRELATOR
VARCHAR(56)
The transaction’s parent correlator (base64 encoded).
PREDECESSOR_TRAN_HANDLE
VARCHAR(36)
The driver’s Execute transaction handle. This ties the Fetch transaction to an execution and its metrics.
ROWS_DELETED
BIGINT
The number of rows deleted.
ROWS_FETCHED
BIGINT
The number or rows read.
ROWS_INSERTED
BIGINT
The number of rows inserted.
ROWS_UPDATED
BIGINT
The number of rows updated.
SCHEMA_NAME
VARCHAR(256)
The name of the schema being accessed.
SERVER_MESSAGE
VARCHAR(500)
The message associated with the event.
SESSION_TRAN_HANDLE
VARCHAR(36)
The SESSION transaction that the current transaction is assigned to.
SOURCE_FILE_NAME
VARCHAR(128)
The filename where the logging request was issued.
SQL_DIALECT
VARCHAR(15)
The dialect that is being used: FEDSQL or NATIVE.
SQL_TRAN_HANDLE
VARCHAR(36)
The SQL transaction that the current transaction is assigned to.
STATEMENT_ID
BIGINT
The SQL statement hash. The value derived from the SQL statement content.
STATEMENT_NAME
VARCHAR(256)
The SQL statement name.
STATEMENT_PLAN
VARCHAR(15000)
Column valued for SQL statement types only.
Note: The plan value can truncate if the character limit is exceeded. For example, Oracle has a VARCHAR limit of 4000 while SQL Server is 8000.
STATEMENT_STATE
VARCHAR(15)
The state of the SQL statement, such as S0, S1 and S2.
STATEMENT_TEXT
VARCHAR(15000)
The text of the SQL statement.
Note: The plan value can truncate if the character limit is exceeded. For example, Oracles’ VARCHAR limit is 4000 while SQL Server is 8000.
STATEMENT_TYPE
VARCHAR(15)
The type of SQL statement, such as DQL, DQL.Metadata (catalog methods), DML, or DDL. Empty if unknown.
THREAD_CURRENT
BIGINT
The current process thread count for the transaction event.
THREAD_HIGH
BIGINT
The process highest thread count for the transaction event.
TRAN_CLASS_ID
VARCHAR(36)
The UUID of transaction class.
TRAN_HANDLE
VARCHAR(36)
The UUID of transaction instance.
TRAN_NAME
VARCHAR(50)
SESSION, DBC, DBTRAN, SQL, Execute, Fetch, CURSOR. For additional information see ARM Transactions .
TRAN_START_SAS_TIMEOFDAY
DOUBLE PRECISION
The time-of-day value for the current transaction start event.
TRAN_STATE
VARCHAR(15)
The state of the transaction: START, STOP, UPDATE, BLOCK, UNBLOCK, DISCARD.
TRAN_STATUS
VARCHAR(15)
The transaction status: UNKNOWN, ABORTED, GOOD, FAILED, STOP.
TRAN_STOP_SAS_TIMEOFDAY
DOUBLE PRECISION
The time-of-day value for the current transaction stop event.
TRAN_TIMESTAMP
TIMESTAMP
The current timestamp of the transaction.
TRANRESP_SYS_CPU_TIME
DOUBLE PRECISION
The calculated system CPU time for the duration of the transaction.
TRANRESP_TIME
DOUBLE PRECISION
The calculated elapsed time for the duration of the transaction.
TRANRESP_USER_CPU_TIME
DOUBLE PRECISION
The calculated user CPU time for the duration of the transaction.
TRANSTART_SYS_CPU_TIME
DOUBLE PRECISION
The process system CPU time for the current transaction start event.
TRANSTART_USER_CPU_TIME
DOUBLE PRECISION
The process user CPU time for the current transaction start event.
TRANSTOP_SYS_CPU_TIME
DOUBLE PRECISION
The process system CPU time for the current transaction stop event.
TRANSTOP_USER_CPU
DOUBLE PRECISION
The process user CPU time for the current transaction stop event.

SQL Logging Performance Tuning

Introduction

You can configure SQL Logging so that it will have minimum impact on SAS Federation Server performance, especially during periods of heavy processing.

Using Maximum Buffered Events (MaxBufferedEvents)

Maximum buffered events tells the server how many events to buffer before writing them to the EVENTS database. You can set this option using the MaxBufferedEvents option in the SQL Logging configuration file. The default setting for MaxBufferedEvents is 100 meaning that 100 events are buffered before writing them to the EVENTS table. Setting MaxBufferedEvents to a higher number might consume server resources but will show improved performance during periods of heavy processing. A sustainable high value for MaxBufferedEvents is approximately 500. Here is the syntax used in the SQL Logging configuration file: 
 <param name="maxBufferedEvents" value="100" />

Configure Indexing on the EVENTS Table

When using the default configuration of the TRAN data store, writes to the SQL Logging database can sometimes affect overall performance, especially during periods of heavy processing. This is caused by the indexes that are present on the EVENTS table. During these high activity periods, you can drop indexes onto the EVENTS table by updating the SQL_LOG data service as shown here: 
alter service SQL_LOG {options AUTOINDEX off}
To activate indexing on the EVENTS table: 
alter service SQL_LOG {options AUTOINDEX on}
Because indexes are required to process SQL queries in SAS Federation Server Manager, it is not advisable to view SQL Logging information using SAS Federation Server Manager during periods when indexes are not active. You can re-enable indexes after processing activity decreases on SAS Federation Server. At that time, you should be able to view SQL Logging information in SAS Federation Server Manager.
An alternative to dropping indexes is to configure SQL Logging to use an external, or third party, database. For more information see Configuring a 3rd Party DBMS for SQL Logging.
Copyright © SAS Institute Inc. All rights reserved.