Today we were trying to find the source of a problem at a client's site. Activating request-logging for some time gave us at least some hints. But we had some trouble interpreting the contents of the request log.

Can anyone point me to a description of the request log contents?

<snippet>
=,<,96,OPEN,131109
+10,>,96,OPEN,131110
+90,<,96,CLOSE,131110
=,I,96,0,1,0,NOSCROLL*+READONLY+HOLD
=,>,96,CLOSE
=,<,96,DROP_STMT,131109
=,>,96,DROP_STMT
=,<,96,PREPARE,SELECT cast(NULL AS CHAR(128)) AS TABLE_CAT,SYSUSERPERMS.user_name AS     TABLE_SCHEM,SYSTABLE.table_name AS TABLE_NAME,COLUMN_NAME,cast((select count(*) from SYS.SYSCOLUMN other where table_id = SYSTABLE.table_id and column_id <= SYSCOLUMN.column_id and pkey = 'Y') AS smallint) AS KEY_SEQ,SYSTABLE.table_name AS PK_NAME FROM SYS.SYSCOLUMN JOIN SYS.SYSTABLE JOIN SYS.SYSUSERPERMS WHERE user_name = 'sirius' AND table_name = 'ARTIKEL' AND pkey = 'Y' ORDER BY 1,2,3,5
+1,>,96,PREPARE,131111
+18,<,96,EXEC,131111
=,W,96,111,Anweisung kann nicht ausgeführt werden
=,>,96,EXEC
=,<,96,OPEN,131111
+3,>,96,OPEN,131112
=,<,96,CLOSE,131112
=,I,96,0,1,0,NOSCROLL*+READONLY+HOLD
+1,>,96,CLOSE
=,<,96,DROP_STMT,131111
=,>,96,DROP_STMT
=,<,96,CLOSE,65570
=,I,96,0,546,0,NOSCROLL*+READONLY+HOLD
=,>,96,CLOSE
+8,<,96,DROP_STMT,65569
=,>,96,DROP_STMT
=,<,96,PREPARE,select connection_property('TransactionStartTime')
=,>,96,PREPARE,65577
+1,<,96,EXEC,65577
=,W,96,111,Anweisung kann nicht ausgeführt werden
=,>,96,EXEC
=,<,96,OPEN,65577
</snippet>

asked 16 Jul '10, 15:53

Reimer%20Pods's gravatar image

Reimer Pods
4.2k334481
accept rate: 12%


Before I answer your question directly, I will mention that there are a number of tools available that you can use to analyze your request log file:

  • tracetime.pl - located in your SA install samples directory - in SA 12 it is in samples/sqlanywhere/performancetracetime/tracetime.pl

  • sa_get_request_profile - a procedure that will determine execution times of similar statements

  • sa_get_request_times - a procedure that will determine execution times of each statement

As for documentation on the format, there appears to be no good source (and we need to do something about this!). If you know PERL you can read through the tracetime.pl script and figure out the details, but here are the general rules:

Each line is a comma delimited set of fields:

  • timestamp - this will be one of

    • an absolute time in "MMDD HHMMSS.sss" format, or
    • '=' if the time is exactly the same as the previous line
    • +n to indicate 'n' milliseconds after the previous line
  • logging event type - one of:

    • '<' - start of a new request (sent to the server)
    • '>' - end of request
    • '>.' - connection dropped
    • 'C' - new connection
    • 'H' - hostvar information
    • 'E' - error
    • 'W' - warning
    • 'P' - plan
    • 'I' - info
    • 'X' - extra data/info
    • '[' - procedure call begin
    • ']' - procedure call end
  • connection id

  • request type (if a start/end of a request) or procedure name (if a proc call)

  • various other details depending on the log event type and request type - e.g. SQL text, statement id, or cursor id

permanent link

answered 16 Jul '10, 17:31

Mark%20Culp's gravatar image

Mark Culp
23.0k9129270
accept rate: 40%

@Mark: Thanks for your helpfull explanation. We would have liked to see the SQL statements with their host variables in chronological order, but for some unknown reason the SQL was missing. However, I was not able to reproduce that on my PC.

(19 Jul '10, 14:47) Reimer Pods
Your answer
toggle preview

Follow this question

By Email:

Once you sign in you will be able to subscribe for any updates here

By RSS:

Answers

Answers and Comments

Markdown Basics

  • *italic* or _italic_
  • **bold** or __bold__
  • link:[text](http://url.com/ "title")
  • image?![alt text](/path/img.jpg "title")
  • numbered list: 1. Foo 2. Bar
  • to add a line break simply add two spaces to where you would like the new line to be.
  • basic HTML tags are also supported

Question tags:

×15
×11

question asked: 16 Jul '10, 15:53

question was seen: 989 times

last updated: 16 Jul '10, 17:31