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. 

I have created a Database Idea for this issue:
extend v$diag_trace_file_contents so multiple chunks of a line can be ordered

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.

Oracle WINDOW FUNCTION XOR SDO_GEOMETRY

Recently a friend asked me how to write a query for a SQL query which was slightly above simple SQL demo cases you can find all around. For me it was a good reason to brush my SQL (and in the process I had to reach out to Kim Berg Hansen for a beautiful match_return solution, but that's not this posts content). As this friend has his data in a postgres database, I managed to get a free DB at Alwaysdata and play with this. 

But as I was asking Kim for some help, it was obvious to work in Oracle world. I supposed most solutions should be able to transfer to Posgres easily. How wrong I was ...

A striped down testcase uses a table like 

create table gps (
   train          integer
 , gpstimestamp   timestamp with time zone
 , geom           sdo_geometry
);

Train describes a series of measurements: every second a GPS point is measured. On part of the problematic question is to find the distance between 2 consecutive points. As I didn't stop in 1992, the LAG function came to my mind. 

But in Kims testcase, LAG did not work at all: 

select
train, gpstimestamp, geom
  , nvl(sdo_geom.sdo_distance(geom, LAG(geom) 
                                      OVER (PARTITION BY train 
                                            ORDER BY  gpstimestamp), 0.005)
      , 0) as prev_dist
from gps
;

throws 

ORA-22901: cannot compare VARRAY or LOB attributes of an object type 

This error just does not makes any sense, as the geomertry does not need to be sorted at all. gpstimestamp is used for sorting, and oracle is quite capable of sorting timestamps of any kind. 

Maybe train needs to be sorted internally - PARTITION BY in theory just needs a comparison for equality, but Oracle often sorts in such cases. Even here train is of type integer - nothing easier to sort than this. 

But Kim knows SQL, and if one solution fails for any obscure reason, there is another one: 

   select
      train, gpstimestamp, geom, prev_dist
   from gps
   match_recognize (
      partition by train
      order by gpstimestamp
      measures
         nvl(sdo_geom.sdo_distance(geom, prev(geom), 0.005), 0) as prev_dist
      all rows per match
      pattern (any_row)
      define
         any_row as 1=1
   )

A beautiful workaround. - Funnily in livesql, even this workaround fails, this time with ORA-932:

Of course there are other solutions also: scalar subqueries, correlating inline views and many others. 

I also opened SR 3-23171402921 at Oracle - with the result it works as designed / expected. 

---

OK, back to my initial task: helping my friend with his query.

First I tried to port Kims MATCH_RECOGNIZE solution, but Postgres does not understand MATCH_RECOGNIZE yet. 

So I gave the LAG syntax a chance - and it worked: 

                lag(geom) over
   ( PARTITION BY train
     ORDER BY gpstimestamp ) AS prev_geom ,

is flawless accepted by Postgres!

There are several lessons learned: 

• It's not as easy as I hoped to transfer SQL between DB-engines.
• If my SQL seems to be over complicated, for sure it is - ask Kim ;-) 
• If you want to do analytical functions with spatial data, use Postgres, not Oracle. 

flipping performance

Recently I had a request to check "if there is any problem with the database at <specific times>".
You can imagine, there was no problem. Nothing in alert.log, no tracefiles, no locks or oddities in ASH/AWR.

I had to ask back & forth to get some more information about the issue. The information I got was:
"we use a statement SELECT * FROM table(some_function('P1', 'P2')) - and it took longer than 10 sec at the given times". Of course there were no bind variables used but constants every time.
This situation helps a lot as obviously there is nothing to do with SQL_IDs now, and the real issue is (probably) within the function.
The function just generated 1 SELECT (no BINDs again - but PL/SQL did the "auto-binding").
With this SQL it's easy to identify the SQL_ID.
This SQL_ID has 3 childs with different plans. That is sufficient to check, if the specific times somehow match a flip of plans. This was done by a simle query:

with gash as (
select sql_id, sql_child_number, sample_time, LAG(sql_child_number, 1, 0) OVER (ORDER BY sample_time) AS prev_child
from gv$active_session_history
where sql_id='&sql_id'
order by sample_time
)
select *
from gash
where sql_child_number != prev_child
order by sample_time

For a longer observation dba_hist_active_sess_history can be used as well.

The result easily showed a flip between childs/plans at the given times.

(solution was to generate "outline-hints" with dbms_xplan.display_cursor for the good plan and so hint the SQL inside of some_function).

This was no complex task to analyze or big deal to execute. Just a small example where GUIs might not help so much. By the (little) information given it would have been pure luck to see the problematic pattern in a ASH-graph. As ther was nothing to filter, all the other "noise" in the DB would have wiped the information out.

Sometimes it's good to know the architecture and views, not only the GUI.

PS: The statement above is ugly. A MATCH_RECOGNIZE would be more elegant. Unfortunately this DB is 11.2