| Home | Previous Lesson: Tracing PowerBuilder's Internal Execution Next Lesson: Tracing ODBC Driver Manager Calls |
All previously explained procedures follow the flow of execution and display the variable contents, as the program executes. However, this doesn't include anything about what is being sent to the connected database, the time it takes and so on.
To display this information, you can add the word 'trace' before the DBMS name in the database profile:
Remember to remove the 'trace' before distributing the application, as logging database information seriously affects the performance.
We can see how this works, by logging onto our application as follows:
When you type the password and click on the OK button, you'll get the following message box confirming that the log file has been created in the Windows directory:
If the log file already exists, new information will be appended to it, so, it gets big very quickly if you don't keep an eye on it.
PowerBuilder log contains parameters that are used to connect to the database, SQL statements, and the time taken to connect and execute the SQL statements. The following log was created when we executed our Product Management Application with a trace flag:
LOGIN: (342 MilliSeconds)
CONNECT TO TRACE ODBC:
USERID=DBA
DATA=product
DBPARM=Connectstring='DSN=product' (0 MilliSeconds)
Immediately after it connects to the database, it starts a transaction. We retrieved item master details into w_product_master window. When PowerBuilder encounters Retrieve() in the script, it sends the SQL statement defined in the DataWindow to the connected database, for parsing:
PREPARE:
SELECT "units"."unit" , "units"."unit_description"
FROM "units" (47 MilliSeconds)
PREPARE:
SELECT "product_master"."product_no",
"product_master"."product_description",
"product_master"."product_balance",
"product_master"."product_reorder_level",
"product_master"."product_measuring_unit"
FROM "product_master"
ORDER BY "product_master"."product_no" ASC (16 MilliSeconds)
Once the SQL statement is parsed, it gets the column descriptions, binds the data to the DataWindow columns and then asks the connected database to execute the statement:
BIND SELECT OUTPUT BUFFER (DataWindow): (0 MilliSeconds)
,len=4,type=CHAR,pbt1,dbt0,ct0,dec0
,len=12,type=CHAR,pbt1,dbt0,ct0,dec0
EXECUTE: (0 MilliSeconds)
BIND SELECT OUTPUT BUFFER (DataWindow): (0 MilliSeconds)
,len=44,type=LONG,pbt22,dbt0,ct0,dec0
,len=32,type=CHAR,pbt1,dbt0,ct0,dec0
,len=44,type=DECIMAL,pbt4,dbt0,ct0,dec3
,len=44,type=DECIMAL,pbt4,dbt0,ct0,dec3
,len=4,type=CHAR,pbt1,dbt0,ct0,dec0
EXECUTE: (0 MilliSeconds)
It fetches the data row by row, until it knows there are no more rows. The last line, rc 100, is a SQLCA.SQLCODE, which indicates that there are no more result rows for this command.
FETCH NEXT: (133 MilliSeconds)
COLUMN=1 COLUMN=Hard Disks1 COLUMN=487.000 COLUMN=20.000 COLUMN=U...
����
FETCH NEXT: (13 MilliSeconds)
Error 1 (rc 100)
When we changed the description of product_no 1 from 'Hard Disk1' to 'Optical Disk' and selected File/Save from the menu, the following was recorded in the log file:
PREPARE WITH BIND VARIABLES:
UPDATE "product_master"
SET "product_description" = ?
WHERE "product_no" = ? AND
"product_description" = ? AND
"product_balance" = ? AND
"product_reorder_level" = ? AND
"product_measuring_unit" = ? (47 MilliSeconds)
VCHAR Length12 ID:1 *Optical Disk*
LONG Length0 ID:2
VCHAR Length11 ID:3 *Hard Disks1*
DECIMAL Length0 ID:4 *487.000*
DECIMAL Length0 ID:5 *20.000*
VCHAR Length1 ID:6 *U* (0 MilliSeconds)
EXECUTE: (19 MilliSeconds)
GET AFFECTED ROWS: (0 MilliSeconds)
^ 1 Rows Affected
It simply sent the UPDATE statement to the database and recorded the number of rows affected by the UPDATE statement.
Finally, exiting from the database and disconnecting from the database produces the following:
BEGIN TRANSACTION: (3 MilliSeconds)
COMMIT: (164 MilliSeconds)
DISCONNECT: (1042 MilliSeconds)
SHUTDOWN DATABASE INTERFACE: (191 MilliSeconds)
Open the database painter and remove the TRACE keyword from the DBMS prompt.
| Home | Previous Lesson: Tracing PowerBuilder's Internal Execution Next Lesson: Tracing ODBC Driver Manager Calls |