LucidDbErrorHandling

From Eigenpedia

Jump to: navigation, search

Contents

Introduction

All LucidDB statements either execute to completion or are rolled back if an error occurs. This can be quite cumbersome if you have a DML statement that affects a large number of rows, a few of which have errors in them. To address this, LucidDB provides a mechanism that allows errors to be logged while still allowing the statement to run through to completion. This mechanism only applies to errors that can later be corrected by modifying the input rows. These are errors that occur during the actual runtime execution of the statement while individual rows are being processed. Syntax and statement validation errors do not apply, since those are statement-level errors. Severe errors, such as encountering a corrupted index, also are not covered by this mechanism.

Errors are logged so after the statement has completed, you can identify the cause of each error. The information includes the source of each error, and the inputs and/or outputs applicable to the error. Currently, only two general categories of errors are logged explicitly by LucidDB:

  • Unique constraint violations
  • Expression evaluation errors

It's also possible to log errors and warnings associated with application-specific constraints using the UDX APPLIB.ENFORCE_ROW_CONSTRAINTS.

To enable error logging, at a minimum, you need to execute the following statement:

 alter session set "errorMax" = <number>;

where <number> refers to the maximum number of errors that can be logged before the statement fails.

Logfiles

The error logs are placed in a log directory. By default, this directory is named log and is located in the directory where your LucidDB instance is installed. You can change the default log directory by issuing the following statement:

  alter session set "logDir" = '<log-directory>';

If any errors are encountered, a summary record is inserted into the file Summary.log in the specified or default log directory. The first record in the file is a header record that labels the comma-separated entries in the file. They are as follows:

  • LE_TIMESTAMP - Timestamp indicating when the error occurred
  • PROCESS_ID - Identifier corresponding to the session that caused the error. This defaults to an internal session id and will look like Sess followed by a number.
  • ACTION_ID - Action id corresponding to the statement that caused the error. This defaults to an internal statement id and will look like Stmt followed by a number.
  • ERROR_COUNT - Number of errors of a specific type encountered by the statement.
  • WARNING_COUNT - Number of warnings encountered by the statement.
  • FILENAME - Name of the file containing error details.
  • SQL - Text of the SQL statement that caused the error.

The name of the file containing error details is also located in the specified log directory. Its name follows the following format:

  <PROCESS_ID>_<ACTION_ID>_<ACTION_TAG>.log

<PROCESS_ID> and <ACTION_ID> are as described above. <ACTION_TAG> is a unique tag that's intended to provide information on the source of the error. More details will be provided below.

Again, the first line in the detailed log file is a header record, indicating the following:

  • LE_TIMESTAMP - Timestamp indicating when the error occurred
  • LE_LEVEL - Set to either Error or Warning, depending on whether the row corresponds to an error or warning entry.
  • LE_EXCEPTION - The specific error message. E.g., Unique constraint violation or Overflow during calculation or cast.
  • LE_TARGET_COLUMN - If available, either an ordinal indicating the column number that caused the error, or possibly the name of column. If not available, -1.
  • <column names> - One or more columns corresponding to the input that caused the error.

Interpreting the Detailed Log Files

The name and content in the detailed log files depends on the type of error and the context in which in the error occurred. This section details the different scenarios.

Unique Constraint Violations

The <ACTION_TAG> in the detailed log filename for unique constraint violations either will be

  LcsTableMergeRel.#<id1>:<id2>_<timestamp>

for violations that occurred during a MERGE statement, or

  LcsTableAppendRel.#<id1>:<id2>_<timestamp>

for errors that occurred during an INSERT statement.

<id1> and <id2> are internal ids, and <timestamp> is the timestamp corresponding to when the error occurred.

The LE_TARGET_COLUMN field for unique constraint violations will be -1, since a unique constraint violation can span more than one column. The names of the columns that comprise the unique constraint appear starting at the 5th column. The values in those columns correspond to the values that caused the unique constraint violation. At the very end of each record is a SRID column. This is the rowid of the row that caused the violation. You probably won't need to use this value.

For example, if you have the following entry in a detailed file named Sess2_Stmt8_LcsTableAppendRel.#96:904_2007-10-02_09_55_36.log

  LE_TIMESTAMP,LE_LEVEL,LE_EXCEPTION,LE_TARGET_COLUMN,A,B,SRID
  2007-10-02 09:55:36,Error,Unique constraint violation,-1,100,101,1

then you can conclude the following:

  • The violating statement was an INSERT.
  • The error was a unique constraint violation.
  • The unique constraint is on columns (A, B).
  • The duplicate key values are (100, 101).

Expression Evaluation Errors

Expression evaluation errors are a bit more complicated to interpret. Since expression evaluation can occur in a number of places in a query execution plan, the name of the detailed error log file is intended to provide more context on the source of the error. The following table outlines the naming conventions for the different expression evaluation instances.

<ACTION_TAG> for Expression Evaluation Errors
Expression Evaluation Context <ACTION_TAG>
Occurs on the result of a table scan. Table scans include scans of column store tables as well as flatfile tables. Read.<tablename>.<relId>_<timestamp>
Occurs on the result of data accessed from a JDBC data source JdbcIterCalcRel<relId>_<timestamp>
Occurs on the result of a UDX call JavaUdxIterCalcRel<relId>_timestamp
Computes the column values for the rows to be inserted by an INSERT statement Insert.<tablename>.<relId>_<timestamp>
Computes the insert and update rows for a MERGE statement Merge.<tablename>.<relId>_<timestamp>
Occurs post-join processing PostJoinIterCalcRel<relId>_<timestamp>
All other expression evaluation not covered above IterCalcRel<relId>_<timestamp>

<relId> is an internal runtime id. <tablename> is the target table of the operation.

Additional conventions are:

  • LE_TARGET_COLUMN
    • If the specific expression that caused the error is a conditional expression originating from a WHERE clause, then LE_TARGET_COLUMN is set to CONDITION.
    • If the error is associated with an INSERT or MERGE, then LE_TARGET_COLUMN is set to the name of the target column that the expression is being computed for.
    • Otherwise, LE_TARGET_COLUMN refers to the column ordinal in the output row of the expression evaluator that contains the faulty expression. Note that this column ordinal is 1-based, not 0-based.
  • Column names - The column names and values correspond to the input row passed into the expression evaluator.

In the cases where the error log record references ordinals instead of column names, you likely will have to run EXPLAIN PLAN and interpret the contents of the IterCalcRel that contains the faulty expression. The input and output rows noted above refer to the input and output of an IterCalcRel. These are recorded in the explain plan output.

Expression Evaluation Error Example

Here's a very simple example. Assume that the proper error logging parameters have been enabled.

  CREATE TABLE t(a INT, b INT, c INT);
  INSERT INTO t VALUES(100, 200, 300);
  SELECT b, CAST(a*c AS TINYINT) FROM t;

The SELECT statement above generates an overflow error. The error is recorded in a file named Sess2_Stmt13_Read.T.184_2007-10-02_12_40_33.log. The contents of the file is as follows:

  LE_TIMESTAMP,LE_LEVEL,LE_EXCEPTION,LE_TARGET_COLUMN,A,B,C
  2007-10-02 12:40:34,Error,Overflow during calculation or cast.,2,100,200,300

The explain plan output for the SELECT statement is:

 'column0'
 'IterCalcRel(expr#0..2=[{inputs}], expr#3=[*($t0, $t2)], expr#4=[CAST($t3):TINYINT], B=[$t1], EXPR$1=[$t4])'
 '  FennelToIteratorConverter'
 '    LcsRowScanRel(table=[[LOCALDB, S, T]], projection=[*], clustered indexes=[[SYS$CLUSTERED_INDEX$T$A, SYS$CLUSTERED_INDEX$T$B, SYS$CLUSTERED_INDEX$T$C]])'

The error is in column ordinal 2 in the output row. From the explain plan, this corresponds to EXPR$1, since the column ordinal from the error log is 1-based, but the explain output ordinals are 0-based. Working backwards through the explain output, we know that EXPR$1 eventually maps to:

  CAST(*($t0, $t2):TINYINT)

$t0 and $t2 refer to columns in the input row. Since the input into the IterCalcRel is a scan of table T where all columns are referenced, we can conclude that $t0 refers to the first column in T, which is A, and $t2 refers to the 3rd column, column C. Therefore, this corresponds to the following expression from the original statement:

  CAST(a*c AS TINYINT)

We can then match the identified column names against the column names/values in the error log record and conclude that the input row that caused the error is the one where A = 100 and C = 300.

Row Constraint Violations

This section describes errors and warnings logged by APPLIB.ENFORCE_ROW_CONSTRAINTS. This UDX takes an optional 'tag' parameter. The value of that parameter is used as the <ACTION_TAG> in the detailed log filename for violations generated by the UDX. If the parameter is not specified, then the tag defaults to:

  EnforceRowConstraintsUDX_<id>_<timestamp>

where <id> is an internally generated unique identifier.

Additional conventions are:

  • LE_TARGET_COLUMN - This field contains the name of the constraint check column corresponding to the violation
  • Column names - All column names and values passed in as input via the cursor parameter in the UDX are recorded in the log file, except for columns corresponding to constraint check columns.

Row Constraint Violation Example

To better understand what the contents of the detailed logfile look like, here's a simple example.

Suppose, you have a table named EMPS with the following columns and values:

+--------+--------+-----------+------+---------+----------+--------+--------+-------------+----------------+
| EMPNO  | FNAME  |   LNAME   | SEX  | DEPTNO  | MANAGER  | LOCID  |  SAL   | COMMISSION  |     HOBBY      |
+--------+--------+-----------+------+---------+----------+--------+--------+-------------+----------------+
| 100    | Bill   | Bush      | M    | 30      |          | HQ     | 50000  |             | Piano          |
| 101    | Bob    | Brown     | M    | 50      | 100      | SJ     | 50000  |             | Skiing         |
| 102    | Julie  | Andrews   | F    | 30      | 104      | MP     | 50000  |             | Rugby          |
| 103    | Frank  | Webber    | M    | 20      | 102      | MP     | 50000  |             | Piano          |
| 104    | Fritz  | Fratz     | M    | 10      | 100      | HQ     | 50000  |             | Rugby          |
| 105    | Rich   | Guy       | M    | 30      | 102      | HQ     | 50000  |             | Gambling       |
| 106    | Rob    | Roy       | M    | 40      | 102      | SF     | 50000  | 7           | Karate         |
| 107    | Robin  | Williams  | M    | 40      | 103      | HQ     | 50000  | 10          | Telling Jokes  |
| 108    | Mary   | Reynolds  | F    | 50      | 104      | SF     | 50000  |             |                |
| 109    | Jack   | Nife      | M    | 40      | 100      | SF     | 50000  | 5           |                |
| 110    | Jill   | Jones     | F    | 30      | 101      | MP     | 50000  |             |                |
+--------+--------+-----------+------+---------+----------+--------+--------+-------------+----------------+

Suppose you want to log errors for all rows in EMPS where LOCID is equal to HQ. The following select, which includes a call to APPLIB.ENFORCE_ROW_CONSTRAINTS(), will do so.

  select * from table(
     APPLIB.ENFORCE_ROW_CONSTRAINTS(
        cursor(
           select *,
              case
                 when LOCID = 'HQ' then 'RejHQErr'
                 else cast(null as varchar(128))
              end as LOCCHECK
           from EMPS),
        row(LOCCHECK),
        'MsgCatalog',
        'HQConstraint'));

RejHQErr is an error code defined in the resource jar file named MsgCatalog. The text of that error is:

  Location Id is head quarters

Therefore, the contents of the detailed log named Sess2_Stmt10_HQConstraint.log is as follows:

LE_TIMESTAMP,LE_LEVEL,LE_ERROR_CODE,LE_EXCEPTION,LE_TARGET_COLUMN,EMPNO,FNAME,LNAME,SEX,DEPTNO,MANAGER,LOCID,SAL,COMMISSION,HOBBY
2007-10-10 11:07:00,Error,RejHQErr,Location Id is head quarters,LOCCHECK,100,Bill,Bush,M,30,,HQ,50000,,Piano
2007-10-10 11:07:00,Error,RejHQErr,Location Id is head quarters,LOCCHECK,104,Fritz,Fratz,M,10,100,HQ,50000,,Rugby
2007-10-10 11:07:00,Error,RejHQErr,Location Id is head quarters,LOCCHECK,105,Rich,Guy,M,30,102,HQ,50000,,Gambling
2007-10-10 11:07:00,Error,RejHQErr,Location Id is head quarters,LOCCHECK,107,Robin,Williams,M,40,103,HQ,50000,10,Telling Jokes

All of the columns and values passed in as input via the cursor parameter in the UDX, excluding the constraint checking columns, are recorded in the file. I.e., in our example, this includes all columns from EMPS but excludes the LOCCHECK constraint column. Instead, that column name populates the LE_TARGET_COLUMN field, indicating that the errors are associated with that constraint.

The query, on the other hand, returns all rows where LOCID is not equal to HQ:

+--------+--------+-----------+------+---------+----------+--------+--------+-------------+---------+-----------+
| EMPNO  | FNAME  |   LNAME   | SEX  | DEPTNO  | MANAGER  | LOCID  |  SAL   | COMMISSION  |  HOBBY  | LOCCHECK  |
+--------+--------+-----------+------+---------+----------+--------+--------+-------------+---------+-----------+
| 101    | Bob    | Brown     | M    | 50      | 100      | SJ     | 50000  |             | Skiing  |           |
| 102    | Julie  | Andrews   | F    | 30      | 104      | MP     | 50000  |             | Rugby   |           |
| 103    | Frank  | Webber    | M    | 20      | 102      | MP     | 50000  |             | Piano   |           |
| 106    | Rob    | Roy       | M    | 40      | 102      | SF     | 50000  | 7           | Karate  |           |
| 108    | Mary   | Reynolds  | F    | 50      | 104      | SF     | 50000  |             |         |           |
| 109    | Jack   | Nife      | M    | 40      | 100      | SF     | 50000  | 5           |         |           |
| 110    | Jill   | Jones     | F    | 30      | 101      | MP     | 50000  |             |         |           |
+--------+--------+-----------+------+---------+----------+--------+--------+-------------+---------+-----------+

Rejected row count

If an INSERT, MERGE, or DELETE statement encounters erroneous rows (for example, rows that violate a constraint), the statement will still go through if errorMax is set to a value greater than or equal to the number of such bad rows. The count of such rejected rows can be fetched after any INSERT, MERGE, or DELETE statement by querying the session parameters view:

select * from sys_boot.mgmt.session_parameters_view where param_name = 'lastRowsRejected';

Example

Consider the following SQL example:

alter session set "errorMax" = 1;
create schema s;
set schema 's';
create table t(col1 int, col2 int unique);
insert into t values (1, 1);
insert into t values (2, 1);

Now, the second insert will violate the unique constraint on column "col2", but since errorMax is set to 1, the statement will not fail. Instead, the row will be considered rejected, and the query below, executed after the second insert, will return a non-zero value.

0: jdbc:luciddb:> select * from sys_boot.mgmt.session_parameters_view where param_name = 'lastRowsRejected';
+-------------------+--------------+
|    PARAM_NAME     | PARAM_VALUE  |
+-------------------+--------------+
| lastRowsRejected  | 1            |
+-------------------+--------------+
1 row selected (0.186 seconds)
0: jdbc:luciddb:> 

Configuration

In addition to errorMax and logDir, other session parameters also affect error logging. The following table summarizes these parameters.

Error Logging Parameters
Parameter Name Default Value Description
logDir SERVER_INSTALL_ROOT/log The logical root directory in which to store all log files
etlProcessId System-generated session id An identifier for an ETL process instance
etlActionId System-generated statement id An identifier for an action within an ETL process
errorMax 0 The number of errors to allow before a statement fails. 0 means allow no errors.
errorLogMax null The maximum number of errors to log for a statement. 0 means to log no errors; null means to log all errors.

To modify these parameters, execute:

  ALTER SESSION SET "<parameter-name>" = <value>;