2020-06-06

wrong LINE_NUMBER in v$diag_trace_file_contents

V$DIAG_TRACE_FILE_CONTENTS is a very nice way to access Oracle trace files without direct access to the instances host.
But for very long lines there is a problem, as PAYLOAD is limited to VARCHAR2(4000)

PAYLOAD
VARCHAR2(4000)
Displays the trace record payload (contents)

Oracle tries to do it's best and presents the one-line in multiple rows. In my 19.7 sandbox it looks like: 


This excerpt was created by a SQL which shows exactly the problem:
SELECT parsing_line,
       line_number,
       payload
FROM
    v$diag_trace_file_contents MATCH_RECOGNIZE (
        PARTITION BY trace_filename
        ORDER BY line_number, timestamp
        MEASURES
            parse.line_number AS parsing_line
        ALL ROWS PER MATCH
    PATTERN ( parse lines_ + endline nextline ) DEFINE
        parse    AS ( payload LIKE 'PARSING IN CURSOR%' ),
        lines_   AS ( line_number = prev(line_number) ),
        endline  AS ( line_number = prev(line_number) + 1 ),
        nextline AS ( line_number = prev(line_number) + 1 )
    )
WHERE trace_filename = '&trace_file'
/
Here you see the beauty of MATCH_RECOGNIZE: it describes quite clear, what I want to show. 
The pattern shown 
  • Starts with a row payload LIKE 'PARSING IN CURSOR%'
  • show all row where it's line_number is equal to previous rows line_number
  • the 2 lines afterwards which increases their line_number (in comparison to previous row) again

The wring line number can be seen easily: All the rows with the SQLs PAYLOAD have LINE_NUMBER 57. But in fact 57 is only 
PARSING IN CURSOR #140574625525808 len=20604 dep=1 uid=0 oct=3 lid=0 tim=529427750 hv=1387884324 ad='63388040' sqlid='9ygdp6j9bkvt4'
Only the last SQLs fragment is shown as LINE_NUMBER 58.

An additional problem is the missing capability of order these multiple rows properly. 
The ORDER BY line_number, timestamp is not sufficient, as all the lines 57 and 58 share the same timestamp. The fixed view x$DBGTFVIEW has a column INDX which is a good candidate for such purpose, but it's not available right now. 

For those who read my previous post: if the .trm file is missing, v$diag_trace_file_contents provides one row per line and the payload is truncated to 4000 characters. 


Update 2020-06-23: Oracle created Bug 31528203 - V$DIAG_TRACE_FILE_CONTENTS SHOWS WRONG LINE_NUMBER WHEN PAYLOAD > 4000 CHAR for this issue.

Keine Kommentare: