Blog Post

Azure Database Support Blog
6 MIN READ

Lesson Learned #371: Playing with the ODBC tracing file: connecting to the database

Jose_Manuel_Jurado's avatar
Jun 13, 2023

A few days ago, I encountered a case where our customer asked about the process of reading and reviewing all the ODBC traces generated by their application.  In this example, I would like to share the lessons I learned while connecting to the database.

 

You could see several articles written here:

 

Lesson Learned #188: Tracing/logging the JDBC and ODBC driver operation - Microsoft Community Hub

Lesson Learned #243: Enabling ODBC connection pooling in PHP - Microsoft Community Hub

Lesson Learned #258: Python vs Connection Refused with Login timeout expired - Microsoft Community Hub

Lesson Learned #359: TCP Provider: Error code 0x68 (104) (SQLExecDirectW) - Microsoft Community Hub

Lesson Learned #229: Hands-On-Labs - Connection is busy with results for another command - Microsoft Community Hub

Lesson Learned #200: Slow when fetching large volume of data compared with PYODBC. - Microsoft Community Hub

Lesson Learned #236: What? .... How much time you said? (CloudShell version) - Microsoft Community Hub

 

For this POC I developed the application called "DotNetExample", we are going to play with incorrect DSN Name, wrong user or password, an error in the connectivity and how is the looks like connecting succesfully to the database.

 

Let's start with incorrect DSN: DIAG [IM002] [Microsoft][ODBC Driver Manager] Data source name not found and no default driver specified (0). 

 

What is the content of ODBC tracing log:

 

1. DotNetExample.v 7294-8668 ENTER SQLAllocHandle
- This log entry indicates the start of a SQLAllocHandle function call.
- The function is being called with the handle type SQL_HANDLE_ENV, representing an environment handle.
- The subsequent lines provide additional information about the function call parameters.

2. DotNetExample.v 7294-8668 EXIT SQLAllocHandle with return code 0 (SQL_SUCCESS)
- This log entry indicates the completion of the SQLAllocHandle function call.
- The return code is 0, indicating SQL_SUCCESS, which means the function call was successful.

3. DotNetExample.v 7294-8668 ENTER SQLSetEnvAttr
- This log entry marks the start of an SQLSetEnvAttr function call.
- The SQLSetEnvAttr function is used to set attributes for the environment handle.
- The parameters for this function call are as follows:
- SQLHENV: The value 0x00B5C5D0, representing the environment handle.
- SQLINTEGER: The attribute being set is SQL_ATTR_ODBC_VERSION, with a value of 200.
- SQLPOINTER: The value 3, indicating SQL_OV_ODBC3, the requested ODBC version.
- SQLINTEGER: The value 0, representing an additional option.

4. DotNetExample.v 7294-8668 EXIT SQLSetEnvAttr with return code 0 (SQL_SUCCESS)
- This log entry indicates the completion of the SQLSetEnvAttr function call.
- The return code is 0, indicating SQL_SUCCESS, meaning the function call was successful.

5. DotNetExample.v 7294-8668 ENTER SQLAllocHandle
- This log entry marks the start of another SQLAllocHandle function call.
- The handle type being requested is SQL_HANDLE_DBC, representing a connection handle.
- The parameters for this function call are as follows:
- SQLSMALLINT: The value 2, indicating the handle type SQL_HANDLE_DBC.
- SQLHANDLE: The value 0x00B5C5D0, representing the environment handle.
- SQLHANDLE*: The value 0x066FE938, indicating the address where the allocated handle will be stored.

6. DotNetExample.v 7294-8668 EXIT SQLAllocHandle with return code 0 (SQL_SUCCESS)
- This log entry indicates the completion of the SQLAllocHandle function call.
- The return code is 0, indicating SQL_SUCCESS, meaning the function call was successful.

7. DotNetExample.v 7294-8668 ENTER SQLConnectW
- This log entry marks the start of an SQLConnectW function call.
- SQLConnectW is used to establish a connection to a data source.
- The parameters for this function call are as follows:
- HDBC: The value 0x00B5E2F0, representing the connection handle.
- WCHAR*: The value 0x00B505A8, representing the data source name (DNS) as "JM2".
- SWORD: The value 3, indicating the length of the data source name.
- WCHAR*: The value 0x7B092250, representing the username (masked as "******").
- SWORD: The value -3, indicating the length of the username.
- WCHAR*: The value 0x7B092250, representing the password (masked as "******").
- SWORD: The value -3, indicating the length of the password.

8. DotNetExample.v 7294-8668 EXIT SQLConnectW with return code -1 (SQL_ERROR)
- This log entry indicates the completion of the SQLConnectW function call.
- The return code is -1, indicating SQL_ERROR, which means the function call encountered an error.
- The subsequent lines provide additional information about the error that occurred.
- The error message states: "[IM002] [Microsoft][ODBC Driver Manager] Data source name not found and no default driver specified."

9. DotNetExample.v 7294-8668 ENTER SQLGetDiagRecW
- This log entry marks the start of an SQLGetDiagRecW function call.
- SQLGetDiagRecW is used to retrieve diagnostic information about the last function call.
- The parameters for this function call are as follows:
- SQLSMALLINT: The value 2, indicating the handle type SQL_HANDLE_DBC.
- SQLHANDLE: The value 0x00B5E2F0, representing the connection handle.
- SQLSMALLINT: The value 1, indicating the record number to retrieve.
- SQLWCHAR*: The value 0x066FE650, representing the buffer to store the SQLSTATE.
- SQLINTEGER*: The value 0x066FE76C, representing the buffer to store the native error code.
- SQLWCHAR*: The value 0x06800048, representing the buffer to store the error message.
- SQLSMALLINT: The value 1024, indicating the maximum length of the error message buffer.
- SQLSMALLINT*: The value 0x066FE768, indicating the buffer to store the actual length of the error message.

10. DotNetExample.v 7294-8668 EXIT SQLGetDiagRecW with return code 0 (SQL_SUCCESS)
- This log entry indicates the completion of the SQLGetDiagRecW function call.
- The return code is 0, indicating SQL_SUCCESS, meaning the function call was successful.
- The subsequent lines provide additional information about the retrieved diagnostic record.
- The SQLSTATE is "IM002".
- The native error code is 0.
- The error message is "[Microsoft][ODBC Driver Manager] Data source name not found and no default driver specified".

 

In another hand, when we have an error in the connectivity, for example, wrong user and password:

 

Based on the provided ODBC tracing file, let's analyze the details of the error that occurred due to a wrong username and password in an SQL database:

 

1. DotNetExample.v 95e4-1b3c ENTER SQLConnectW
- This log entry indicates the start of an SQLConnectW function call.
- SQLConnectW is used to establish a connection to a data source.
- The parameters for this function call are as follows:
- HDBC: The value 0x013EDFE8, representing the connection handle.
- WCHAR*: The value 0x013E05A8, representing the data source name as "JM".
- SWORD: The value 2, indicating the length of the data source name.
- WCHAR*: The value 0x7B092250, representing the username (masked as "******").
- SWORD: The value -3, indicating the length of the username.
- WCHAR*: The value 0x7B092250, representing the password (masked as "******").
- SWORD: The value -3, indicating the length of the password.

2. DotNetExample.v 95e4-1b3c EXIT SQLConnectW with return code -1 (SQL_ERROR)
- This log entry indicates the completion of the SQLConnectW function call.
- The return code is -1, indicating SQL_ERROR, which means the function call encountered an error.
- The subsequent lines provide additional information about the error that occurred.
- The error message states: "[28000] [Microsoft][ODBC Driver 17 for SQL Server][SQL Server] Login failed for user 'usrname'. (18456)"
- The error code 28000 indicates a general login failure.
- The error message specifically mentions that the login failed for the user 'username'.
- The error code 18456 is the SQL Server-specific error code for login failures.

Once a connection is stablished, the ODBC tracing log looks like as follows:

 

1. The function `SQLConnectW` is called with the following parameters:
- `HDBC` (Connection handle): 0x014ADFE8
- `WCHAR *` (Username): 0x014A05A8 [2] "JM"
- `SWORD` (Username length): 2
- `WCHAR *` (Password): 0x7B092250 [-3] "******\ 0"
- `SWORD` (Password length): -3
- `WCHAR *` (Server name): 0x7B092250 [-3] "******\ 0"
- `SWORD` (Server name length): -3

2. The function `SQLConnectW` returns with a return code of 1 (SQL_SUCCESS_WITH_INFO), indicating a successful connection with additional information.

3. The log includes two diagnostic messages (DIAG):
- DIAG [01000] [Microsoft][ODBC Driver 17 for SQL Server][SQL Server]Changed database context to 'dbname'. (5701)
- Indicates that the database context has been changed to 'dbname'.
- DIAG [01000] [Microsoft][ODBC Driver 17 for SQL Server][SQL Server]Changed language setting to us_english. (5703)
- Indicates that the language setting has been changed to 'us_english'.

 

Overall, the log confirms a successful connection to the SQL Server database, with additional information about the changed database context and language setting.

 

 

Updated Jun 13, 2023
Version 6.0
No CommentsBe the first to comment