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 with the CLI/ODBC/JDBC function calls. Two important items, are the SQL statement text being executed, and any error messages that the application may not be reporting.
To locate:
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 (your editor may wrap the line).
Search the trace file for "SQLError", the message text will be shown on the line that contains the string and the output arrow "<---".
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. |
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.
| Note: | the granularity or accuracy of these timings vary between platforms. |
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