Call Level Interface Guide and Reference

Reading the Trace Information

The purpose of the trace is to display the sequence of calls, the input and output arguments and the return code for each function called. The trace is intended for people familiar (or looking to become familiar) with the DB2 CLI or ODBC function calls. Two things that are useful for anyone is the the SQL statement text being executed and any error messages that the application may not be reporting.

To locate:

• SQL statements:

  Search the trace file for the strings "SQLExecDirect" and "SQLPrepare", you will find the SQL Statement on the same line that contains the text and the "--->" input arrow (although your editor may wrap the line).

• Errors: (queried by the application)

  Search the trace file for "SQLError", the message text will be shown on the line that contains the string and the output arrow "<---".

• Errors: (Ignored by the application)

  Search for "Unretrieved error message=" This indicates that a previous call got an SQL_ERROR or SQL_SUCCESS_WITH_INFO return code, but that the application did not query for the error information.

  Note:

  An application may expect some error messages, you should look at all the error messages in the trace file and try to determine the serious ones.

Detailed Trace File Format

Refer to the example trace file below. Note that the line numbers have been added for this discussion, and do NOT appear in the trace.

• Line 1: The build date and product signature is shown to aid IBM Service.

• Lines 2-3: First of a common two line sequence showing the arguments on input (--->) to the function call. Integer arguments may be mapped to a defined value like "SQL_HANDLE_ENV", output arguments are usually shown as pointers, with an "&" prefix.

• Lines 4-5: Two line sequence showing ouput (<---) results of the function call. Only output arguments are shown, and the return code on the second line following the (--->). Match this with the preceding input lines.

• Line 7: Example of an elapsed time on input. This is the time in the application between CLI function calls, shown in seconds. (Note: the granularity or accuracy of these timmings vary between platforms).

• Line 8: Example of an elasped time on output. This is the time in DB2 CLI spent executing the function.

• Lines 18-20: Both SQLDriverConnect() and SQLConnect() display the keywords set on both the input connection string and set in the db2cli.ini file.

• Line 23: The output statement handle is shown as 1:1, the first number represents the connection handle, the second the statement handle on that connection. This also applies to descriptor handles, but not to connection or environment handles, where the first number is always zero.

• Line 29: Example of SQL statement text for SQLPrepare().

• Line 43-44: Deferred arguments from SQLBindParameter() calls (lines 33 - 40). This is the data sent for each of the sql parameter markers (?) in the prepared statement (line 29).

• Lines 79-81: The ouptut from the SQLFetch() call. (iCol = Column, rgbValue = data in char format, pcbValue=Length).

• Line 110: SQLError() output, showing message text. The pfNativeError is either the DB2 SQLCODE or -9999 if the error originated from DB2 CLI instead of the database server.

• Line 123: Shows an unretrived error message. This is shown whenever a function is called using a handle which had a previous error, but was never retrieved by the application. It is effectively "lost" (to the application) at this point but is captured in the trace.

Example Trace File

This example has line numbers added to aid the discussion, line numbers do NOT appear in the trace.

  1  Build Date: 97/05/13-Product: QDB2/6000 (4) - Driver Version: 05.00.0000
 
  2  SQLAllocHandle( fHandleType=SQL_HANDLE_ENV, hInput=0:0, 
           phOutput=&2ff7f388 )
  3      ---> Time elapsed - +1.399700E-002 seconds
 
  4  SQLAllocHandle( phOutput=0:1 )
  5      <--- SQL_SUCCESS   Time elapsed - +6.590000E-003 seconds
 
  6  SQLAllocHandle( fHandleType=SQL_HANDLE_DBC, hInput=0:1, 
           phOutput=&2ff7f378 )
  7      ---> Time elapsed - +1.120000E-002 seconds
 
  8  SQLAllocHandle( phOutput=0:1 )
  9      <--- SQL_SUCCESS   Time elapsed - +8.979000E-003 seconds
 
 10  SQLSetConnectOption( hDbc=0:1, fOption=SQL_ATTR_AUTOCOMMIT, vParam=0 )
 11      ---> Time elapsed - +6.638000E-003 seconds
 
 12  SQLSetConnectOption( )
 13      <--- SQL_SUCCESS   Time elapsed - +1.209000E-003 seconds
 
 14  SQLDriverConnect( hDbc=0:1, hwnd=0:0, szConnStrIn="DSN=loopback;
           uid=clitest1;pwd=*******", cbConnStrIn=-3, szConnStrOut=&2ff7e7b4,
           cbConnStrOutMax=250, pcbConnStrOut=&2ff7e7ae,
           fDriverCompletion=SQL_DRIVER_NOPROMPT )
 15      ---> Time elapsed - +1.382000E-003 seconds
 
 16  SQLDriverConnect( szConnStrOut="DSN=LOOPBACK;UID=clitest1;PWD=*******;", 
           pcbConnStrOut=38 )
 17      <--- SQL_SUCCESS   Time elapsed - +7.675910E-001 seconds
 18  ( DSN="LOOPBACK" )
 19  ( UID="clitest1" )
 20  ( PWD="*******" )
 
 21  SQLAllocHandle( fHandleType=SQL_HANDLE_STMT, hInput=0:1, 
           phOutput=&2ff7f378 )
 22      ---> Time elapsed - +1.459900E-002 seconds
 
 23  SQLAllocHandle( phOutput=1:1 )
 24      <--- SQL_SUCCESS   Time elapsed - +7.008300E-002 seconds
 
 25  SQLExecDirect( hStmt=1:1, pszSqlStr="create table test(id integer, 
           name char(20), created date)", cbSqlStr=-3 )
 26      ---> Time elapsed - +1.576899E-002 seconds
 
 27  SQLExecDirect( )
 28      <--- SQL_SUCCESS   Time elapsed - +1.017835E+000 seconds
 
 29  SQLPrepare( hStmt=1:1, pszSqlStr="insert into test 
           values (?, ?, current date)", cbSqlStr=-3 )
 30      ---> Time elapsed - +5.008000E-003 seconds
 
 31  SQLPrepare( )
 32      <--- SQL_SUCCESS   Time elapsed - +7.896000E-003 seconds
 
 33  SQLBindParameter( hStmt=1:1, iPar=1, fParamType=SQL_PARAM_INPUT,
           fCType=SQL_C_LONG, fSQLType=SQL_INTEGER, cbColDef=4, ibScale=0,
           rgbValue=&20714d88, cbValueMax=4, pcbValue=&20714d54 )
 34      ---> Time elapsed - +2.870000E-003 seconds
 
 35  SQLBindParameter( )
 36      <--- SQL_SUCCESS   Time elapsed - +3.803000E-003 seconds
 
 37  SQLBindParameter( hStmt=1:1, iPar=2, fParamType=SQL_PARAM_INPUT, 
           fCType=SQL_C_CHAR, fSQLType=SQL_CHAR, cbColDef=20, ibScale=0,
           rgbValue=&20714dd8, cbValueMax=21, pcbValue=&20714da4 )
 38      ---> Time elapsed - +2.649000E-003 seconds
 
 39  SQLBindParameter( )
 40      <--- SQL_SUCCESS   Time elapsed - +3.882000E-003 seconds
 
 41  SQLExecute( hStmt=1:1 )
 42      ---> Time elapsed - +3.681000E-003 seconds
 43  ( iPar=1, fCType=SQL_C_LONG, rgbValue=10, pcbValue=4, piIndicatorPtr=4 )
 44  ( iPar=2, fCType=SQL_C_CHAR, rgbValue="-3", pcbValue=2, piIndicatorPtr=2 )
 
 45  SQLExecute( )
 46      <--- SQL_SUCCESS   Time elapsed - +4.273490E-001 seconds
 
 47  SQLExecute( hStmt=1:1 )
 48      ---> Time elapsed - +5.483000E-003 seconds
 49  ( iPar=1, fCType=SQL_C_LONG, rgbValue=10, pcbValue=4, piIndicatorPtr=4 )
 50  ( iPar=2, fCType=SQL_C_CHAR, rgbValue="-3", pcbValue=2, piIndicatorPtr=2 )
 
 51  SQLExecute( )
 52      <--- SQL_SUCCESS   Time elapsed - +1.299300E-002 seconds
 
 53  SQLExecute( hStmt=1:1 )
 54      ---> Time elapsed - +3.702000E-003 seconds
 55  ( iPar=1, fCType=SQL_C_LONG, rgbValue=10, pcbValue=4, piIndicatorPtr=4 )
 56  ( iPar=2, fCType=SQL_C_CHAR, rgbValue="-3", pcbValue=2, piIndicatorPtr=2 )
 
 57  SQLExecute( )
 58      <--- SQL_SUCCESS   Time elapsed - +1.265700E-002 seconds
 
 59  SQLExecDirect( hStmt=1:1, pszSqlStr="select * from test", cbSqlStr=-3 )
 60      ---> Time elapsed - +2.983000E-003 seconds
 
 61  SQLExecDirect( )
 62      <--- SQL_SUCCESS   Time elapsed - +2.469180E-001 seconds
 
 63  SQLBindCol( hStmt=1:1, iCol=1, fCType=SQL_C_LONG, rgbValue=&20714e38,
           cbValueMax=4, pcbValue=&20714e04 )
 64      ---> Time elapsed - +5.069000E-003 seconds
 
 65  SQLBindCol( )
 66      <--- SQL_SUCCESS   Time elapsed - +2.660000E-003 seconds
 
 67  SQLBindCol( hStmt=1:1, iCol=2, fCType=SQL_C_CHAR, rgbValue=&20714e88,
           cbValueMax=21, pcbValue=&20714e54 )
 68      ---> Time elapsed - +2.492000E-003 seconds
 
 69  SQLBindCol( )
 70      <--- SQL_SUCCESS   Time elapsed - +2.795000E-003 seconds
 
 71  SQLBindCol( hStmt=1:1, iCol=3, fCType=SQL_C_CHAR, rgbValue=&20714ee8, 
           cbValueMax=21, pcbValue=&20714eb4 )
 72      ---> Time elapsed - +2.490000E-003 seconds
 
 73  SQLBindCol( )
 74      <--- SQL_SUCCESS   Time elapsed - +2.749000E-003 seconds
 
 75  SQLFetch( hStmt=1:1 )
 76      ---> Time elapsed - +2.660000E-003 seconds
 
 77  SQLFetch( )
 78      <--- SQL_SUCCESS   Time elapsed - +9.200000E-003 seconds
 79  ( iCol=1, fCType=SQL_C_LONG, rgbValue=10, pcbValue=4 )
 80  ( iCol=2, fCType=SQL_C_CHAR, rgbValue="-3                  ", 
         pcbValue=20 )
 81  ( iCol=3, fCType=SQL_C_CHAR, rgbValue="1997-05-23", pcbValue=10 )
 
 82  SQLFetch( hStmt=1:1 )
 83      ---> Time elapsed - +4.942000E-003 seconds
 
 84  SQLFetch( )
 85      <--- SQL_SUCCESS   Time elapsed - +7.860000E-003 seconds
 86  ( iCol=1, fCType=SQL_C_LONG, rgbValue=10, pcbValue=4 )
 87  ( iCol=2, fCType=SQL_C_CHAR, rgbValue="-3                  ", 
         pcbValue=20 )
 88  ( iCol=3, fCType=SQL_C_CHAR, rgbValue="1997-05-23", pcbValue=10 )
 
 89  SQLFetch( hStmt=1:1 )
 90      ---> Time elapsed - +4.872000E-003 seconds
 
 91  SQLFetch( )
 92      <--- SQL_SUCCESS   Time elapsed - +7.669000E-003 seconds
 93  ( iCol=1, fCType=SQL_C_LONG, rgbValue=10, pcbValue=4 )
 94  ( iCol=2, fCType=SQL_C_CHAR, rgbValue="-3                  ", 
         pcbValue=20 )
 95  ( iCol=3, fCType=SQL_C_CHAR, rgbValue="1997-05-23", pcbValue=10 )
 
 96  SQLFetch( hStmt=1:1 )
 97      ---> Time elapsed - +5.103000E-003 seconds
 
 98  SQLFetch( )
 99      <--- SQL_NO_DATA_FOUND   Time elapsed - +6.044000E-003 seconds
 
100  SQLCloseCursor( hStmt=1:1 )
101      ---> Time elapsed - +2.682000E-003 seconds
 
102  SQLCloseCursor( )
103      <--- SQL_SUCCESS   Time elapsed - +6.794000E-003 seconds
 
104  SQLExecDirect( hStmt=1:1, pszSqlStr="select * foo bad sql", cbSqlStr=-3 )
105      ---> Time elapsed - +2.967000E-003 seconds
 
106  SQLExecDirect( )
107      <--- SQL_ERROR   Time elapsed - +1.103700E-001 seconds
 
108  SQLError( hEnv=0:0, hDbc=0:0, hStmt=1:1, pszSqlState=&2ff6f19c, 
           pfNativeError=&2ff6ed00, pszErrorMsg=&2ff6ed9c, cbErrorMsgMax=1024, 
           pcbErrorMsg=&2ff6ed0a )
109      ---> Time elapsed - +2.267000E-003 seconds
 
110  SQLError( pszSqlState="42601", pfNativeError=-104, 
           pszErrorMsg="[IBM][CLI Driver][DB2/6000] SQL0104N  An unexpected 
           token "foo bad sql" was found following "select * ".  
           Expected tokens may include:  "<space>".  SQLSTATE=42601
111  ", pcbErrorMsg=163 )
112      <--- SQL_SUCCESS   Time elapsed - +5.299000E-003 seconds
 
113  SQLError( hEnv=0:0, hDbc=0:0, hStmt=1:1, pszSqlState=&2ff6f19c,
           pfNativeError=&2ff6ed00, pszErrorMsg=&2ff6ed9c, cbErrorMsgMax=1024,
           pcbErrorMsg=&2ff6ed0a )
114      ---> Time elapsed - +2.753000E-003 seconds
 
115  SQLError( )
116      <--- SQL_NO_DATA_FOUND   Time elapsed - +2.502000E-003 seconds
 
117  SQLExecDirect( hStmt=1:1, pszSqlStr="select * foo bad sql", cbSqlStr=-3 )
118      ---> Time elapsed - +3.292000E-003 seconds
 
119  SQLExecDirect( )
120      <--- SQL_ERROR   Time elapsed - +6.012500E-002 seconds
 
121  SQLFreeHandle( fHandleType=SQL_HANDLE_STMT, hHandle=1:1 )
122      ---> Time elapsed - +2.867000E-003 seconds
123  ( Unretrieved error message="SQL0104N  An unexpected token "foo bad sql" 
           was found following "select * ".  Expected tokens may 
           include:  "<space>".  SQLSTATE=42601
124  " )
 
125  SQLFreeHandle( )
126      <--- SQL_SUCCESS   Time elapsed - +4.936600E-002 seconds
 
127  SQLEndTran( fHandleType=SQL_HANDLE_DBC, hHandle=0:1, fType=SQL_ROLLBACK )
128      ---> Time elapsed - +2.968000E-003 seconds
 
129  SQLEndTran( )
130      <--- SQL_SUCCESS   Time elapsed - +1.643370E-001 seconds
 
131  SQLDisconnect( hDbc=0:1 )
132      ---> Time elapsed - +2.559000E-003 seconds
 
133  SQLDisconnect( )
134      <--- SQL_SUCCESS   Time elapsed - +8.253310E-001 seconds
 
135  SQLFreeHandle( fHandleType=SQL_HANDLE_DBC, hHandle=0:1 )
136      ---> Time elapsed - +4.247000E-003 seconds
 
137  SQLFreeHandle( )
138      <--- SQL_SUCCESS   Time elapsed - +4.742000E-003 seconds
 
139  SQLFreeHandle( fHandleType=SQL_HANDLE_ENV, hHandle=0:1 )
140      ---> Time elapsed - +2.023000E-003 seconds
 
141  SQLFreeHandle( )
142      <--- SQL_SUCCESS   Time elapsed - +4.420000E-003 seconds

[ DB2 List of Books | Search the DB2 Books ]