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.

2020-06-05

one purpose of trm files

Since Oracle version 11g, beside trace files (.trc) there are also trace metadata files (.trm). They are often quite small. Still often they are seen as useless and cleaned up. 

Oracle Support Document TRM Trace Files Getting Generated (Doc ID 750982.1) claims:

The metadata in .trm files describes the trace records stored inside of .trc trace files.
The Trace metadata allows tools, such as Adrci, to post-process the trace information.

By deleting the .trm file, you make the .trc file unusable for post processing from ADR using ADRCI tool.
One additional purpose is to assist in proper results in V$DIAG_TRACE_FILE_CONTENTS.

Here a small example of a SQL_TRACE file: 
In a text editor, you can see the line numbers and it's content:



But V$DIAG_TRACE_FILE_CONTENTS shows it slightly different:


You can see a gap between LINE_NUMBER 28 and 40. 
The full payload of line 40 is 
declare
    stm varchar2(32767) := 'select payload from v$diag_trace_file_contents where trace_filename = ''cdb1_ora_3435.trc'' and rownum = 1';
    app varchar2(1000) := ' and trace_filename = ''cdb1_ora_3435.trc''';
    val varchar2(4000);
    n number;
begin
    for i in 1 .. 500 loop
        stm := stm || app;
    end loop;
    execute immediate stm into val;
end;

The full content of original lines 29..40 is proposed in only 1 line here - with the real line number of it's last line as LINE_NUMBER

This can be useful, e.g. to identify the SQL at one entity, instead of parsing the result set line by line. 
It is one of several ways how trace metadata files help interpreting the trace files content. 



If the .trm file is removed, the result looks slightly different: 


every line on the tracefile is a real line in V$DIAG_TRACE_FILE_CONTENTS
There is also no COMPONENT_NAME visible. 
The simple content if the tracefile without any additional metadata or interpretation.

2020-06-04

patch the unpatchable

Oracle provides several VM for demo and training purpose. One of them is the Database Virtual Box Appliance / Virtual Machine. 
It's very clear these VMs are only for testing purpose. 

But they are limited even more.
(at least) this specific VM can not even be patched. 
For some reason I wanted to apply Patch:29649694
First of all, there is no OPatch in the VM. This can be mitigated :-) 

But a first try with opatch lsinventory shows a strange result:
Oracle Interim Patch Installer version 12.2.0.1.21
Copyright (c) 2020, Oracle Corporation.  All rights reserved.


Oracle Home       : /u01/app/oracle/product/version/db_1
Central Inventory : /u01/app/oraInventory
   from           : /u01/app/oracle/product/version/db_1/oraInst.loc
OPatch version    : 12.2.0.1.21
OUI version       : 12.2.0.7.0
Log file location : /u01/app/oracle/product/version/db_1/cfgtoollogs/opatch/opatch2020-06-04_08-24-42AM_1.log

Lsinventory Output file location : /u01/app/oracle/product/version/db_1/cfgtoollogs/opatch/lsinv/lsinventory2020-06-04_08-24-42AM.txt
--------------------------------------------------------------------------------
Local Machine Information::
Hostname: localhost
ARU platform id: 0
ARU platform description:: 

There are no Interim patches installed in this Oracle Home.


--------------------------------------------------------------------------------

OPatch succeeded.
[oracle@localhost OPatch]$ 


The most important part here is the missing of ARU platform id and description.

With some comparison of a good sandbox, I identified the missing directory $ORACLE_HOME/inventory
The first file of interest there is $ORACLE_HOME/inventory/invDetails.properties
#invDetails.properties
#Wed May 13 17:46:16 UTC 2020
XML_VER=4.1
CompsXML=comps.xml
LibsXML=libs.xml
configXML=config.xml
ReleaseNotesXML=releaseNotes.xml
OHPropsXML=oraclehomeproperties.xml

This now shows even more required files.
$ORACLE_HOME/inventory/ContentsXML/oraclehomeproperties.xml contains the ARU id and description:
<?xml version = '1.0' encoding = 'UTF-8'?>
<!-- Copyright (c) 1999, 2019, Oracle and/or its affiliates.
All rights reserved. -->
<!-- Do not modify the contents of this file by hand. -->
<ORACLEHOME_INFO>
   <GUID>685938240#.1069264794</GUID>
   <HOME/>
   <ARU_PLATFORM_INFO>
      <ARU_ID>226</ARU_ID>
      <ARU_ID_DESCRIPTION>Linux x86-64</ARU_ID_DESCRIPTION>
   </ARU_PLATFORM_INFO>
   <PROPERTY_LIST>
     <PROPERTY NAME="ARCHITECTURE" VAL="64"/>
     <PROPERTY NAME="ORACLE_BASE" VAL="/u01/app/oracle"/>
   </PROPERTY_LIST>
</ORACLEHOME_INFO>

This is only the first step. Especially as the real patches applied are not known (DBA_REGISTRY_HISTORY  is of limited help, and DBA_REGISTRY_SQLPATCH relies on OPatch) it's to complicated for me

My approach here is to mimic OPatch and just do it on my own. 

I'm lucky: the patch only contains 1 file to be applied:
files/lib/libserver19.a/kpdbc.o 

and etc/config/actions.xml only says
<oneoff_actions>
    <oracle .rdbms="" opt_req="O" patch_level="3" version="19.0.0.0.0">
        <archive backup_in_zip="false" name="libserver19.a" object_name="lib/libserver19.a/kpdbc.o" path="%ORACLE_HOME%/lib" shaolue="E2CB4E2A994EB8B59E24471B719EA8F2A0079E66">
        <make change_dir="%ORACLE_HOME%/rdbms/lib" make_file="ins_rdbms.mk" make_target="ioracle">
    </make></archive></oracle>
</oneoff_actions>
Doesn't look difficult.
First of course, make sure no binaries are running. Then copy kpdbc.o to $ORACLE_HOME/lib.
There (after backup of libserver19.a) in this archive, kpbdc.o is replaced:
ar -r libserver19.a kpdbc.o
It should be possible to complete with
relink all
But it fails with
  Can't open perl script "/u01/app/oracle/product/version/db_1/install/modmakedeps.pl": (null)
This file also mist be provided from another installation. To cut it short, also $ORACLE_HOME/inventory/make/makeorder.xml is required.
With the help of these files, relink is happy. 


It can be done without the help of these 2 files.
cd $ORACLE_HOME/rdbms/lib
make -f ins_rdbms.mk ioracle
also does the trick.

2020-06-01

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:
ORA-00932: inconsistent datatypes: expected an IN argument at position 1 that is an instance of an Oracle type convertible to an instance of a user defined Java class got an Oracle type that could not be converted to a java class

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. 

2020-05-09

Oracle EUS authentication with LSA activated on AD

Are there to many abbrevations in a posts title possible? If you think so, you might see this post a good example.


The setting I'm talking about is an Oracle Universal Directory (OUD) which works as a proxy between Oracle databases and Active Directory (AD) where the users are managed. Unfortunately it stopped working. Even when a user changed the password in AD, it could not log in with this password to the database, but always got
 ORA-01017: invalid username/password; logon denied  
This can have many reasons.
A check in Middleware/instances/euist_inst/OUD/logs/access(.log)  shows
[03/Mar/2020:13:09:00 +0100] MODIFY PROXY_REQ conn=1654 op=5 msgID=6 s_credmode=use-specific-identity dn="cn=Username,ou=...,dc=..." s_conn=1002 s_msgid=7983
[03/Mar/2020:13:09:00 +0100] MODIFY PROXY_RES conn=1654 op=5 msgID=6 result=53 Message="00000057: LdapErr: DSID-0C090F64, comment: Error in attribute conversion operation, data 0, v3839^@" etime=1 s_authdn=CN=Oracle 
...
[03/Mar/2020:13:09:02 +0100] DISCONNECT conn=1654 reason="Client Disconnect"
there is a MOs Note which describes the situation EUS Login Failure of AD Users Proxied by OUD: LdapErr: DSID-0C090CE0, comment: Error in attribute conversion operation (Doc ID 2612535.1) But neither the cause
They are not OUD-native. They have an AD format and indicate some problem with the passwords in AD.
nor the solution
Contact your AD administrator to determine the meaning of the AD portion of the error to fix this problem.
helps a lot.
Still asking the AD admin is a good idea. After some back & forth this line in eventlog on AD Server is an important step:
Code Integrity determined that a process (\...4\Windows\System32\lsass.exe) attempted to load \...\Windows\System32\oidpwdcn.dll that did not meet the Microsoft signing level requirements.

And it can be proved with signtool.exe - there is no certificate on the ddl:
"c:\Program Files (x86)\Windows Kits\10\bin\10.0.18362.0\x64\signtool.exe" verify oidpwdcn.dll 


File: oidpwdcn.dll 
Index  Algorithm  Timestamp

========================================

SignTool Error: No signature found.

 

Number of errors: 1

Of course Oracle Support has a solution for this situation in UD 11g - OIDPWDCN.DLL Plug-in Fails On AD 2012 R2 With Error "The password notification DLL oidpwdcn failed to load with error 577" (Doc ID 2616566.1) - but disabeling any security feature is not an acceptable solution in 2020. Sorry guys [NOT] !

The first attempt was to replace (quite old) oidpwdcn.dll with orapwdfltr.dll from modern opwdintg.exe
But a first check with signtool.exe didn't show any signature, and LSA also refused it. 

At that point, a SR at MOS was required. It went quite fast and Oracle confirmed, there is no signed version at that time. To get the latest orapwdfltr.dll, Bug 31134430 : NEED TO HAVE ORAPWDFLTR.DLL SIGNED BY MICROSOFT was opened and after reasonable time a signed ddl was provided. (I can not confirm nor decline, if additional contacts to Oracle were involved)


"C:\Program Files (x86)\Windows Kits\10\bin\10.0.18362.0\x64\signtool.exe" verify /v  orapwdfltr.dll
Verifying: orapwdfltr.dll
Signature Index: 0 (Primary Signature)
Hash of file (sha256): 2A14712107D424FF5577EF5C3D111CF66DB40F6226047ADC4F31389D69F437EB
Signing Certificate Chain:
    Issued to: VeriSign Class 3 Public Primary Certification Authority - G5
    Issued by: VeriSign Class 3 Public Primary Certification Authority - G5
    Expires:   Thu Jul 17 01:59:59 2036
    SHA1 hash: 4EB6D578499B1CCF5F581EAD56BE3D9B6744A5E5
        Issued to: Symantec Class 3 Extended Validation Code Signing CA - G2
        Issued by: VeriSign Class 3 Public Primary Certification Authority - G5
        Expires:   Mon Mar 04 01:59:59 2024
        SHA1 hash: 5B8F88C80A73D35F76CD412A9E74E916594DFA67
            Issued to: Oracle America Inc.
            Issued by: Symantec Class 3 Extended Validation Code Signing CA - G2
            Expires:   Thu Jan 28 01:59:59 2021
            SHA1 hash: 1CB08E9B70B917E64407A4F2665799D58B171F89
The signature is timestamped: Thu Apr 23 03:33:05 2020
Timestamp Verified by:
    Issued to: DigiCert Assured ID Root CA
    Issued by: DigiCert Assured ID Root CA
    Expires:   Mon Nov 10 02:00:00 2031
    SHA1 hash: 0563B8630D62D75ABBC8AB1E4BDFB5A899B24D43
        Issued to: DigiCert SHA2 Assured ID Timestamping CA
        Issued by: DigiCert Assured ID Root CA
        Expires:   Tue Jan 07 14:00:00 2031
        SHA1 hash: 3BA63A6E4841355772DEBEF9CDCF4D5AF353A297
            Issued to: TIMESTAMP-SHA256-2019-10-15
            Issued by: DigiCert SHA2 Assured ID Timestamping CA
            Expires:   Thu Oct 17 02:00:00 2030
            SHA1 hash: 0325BD505EDA96302DC22F4FA01E4C28BE2834C5
SignTool Error: A certificate chain processed, but terminated in a root
        certificate which is not trusted by the trust provider.
Number of files successfully Verified: 0
Number of warnings: 0
Number of errors: 1
Also the AD accepted the dll.
Still a proper login was not possible as orclCommonAttribute was not populated after a password change. It's important to read the documentation to opwdintg.exe as this installation program not only applies the ddl (instpflt.bat), but also extends the schema (etadschm.bat). (beside other changes) 3 groups are added: ORA_VFR_11G, ORA_VFR_12C and ORA_VFR_MD5. Only if users belong to the proper group, it's matching password algorithm is used to populate orclCommonAttribute.
After the test user was added to the first group (and it's password was changed again) login on th etest-DB was possible again.   

If you want to use this new, signed ddl, at the time of this post, no regular source is available (afaik). I recommend to open a SR at MOS and ask for a signed version of orapwdfltr.dll. Maybe it helps to drop a comment about Bug 31134430 😉




A bit THANK YOU to Stefa Oehrli who answered uncountable number of questions.

2020-04-13

Agent has been blocked manually. Unblock the Agent.

As it's easter weekend (at the time I write this blog) and it's a nice tradition here to hide some small items (often colored eggs or sweets) so other can find them, this story perfectly matches.
In Enterprise Manager 13c I had an agent with status

Agent has been blocked manually. Unblock the Agent.

Unfortunately In the Agents drop down menu, there is no (sub-) entry to unblock the agent. A well hidden entry!
After several attempts I was hinted where to look. It's in the "Setup" => "Manage Cloud Control" => "Agents" area:

There all agents are listed, and when selected the blocked one, it can be unblocked in the top action list.


I did not find a useful entry in the documentation (but that's probably my lack of search-foo). At least there is a Note EM 12c: How to Block or Unblock an Enterprise Manager 12c Cloud Control Agent if Agent Status is Shown as Blocked in EM Console or Emctl Status Agent Command Shows Heartbeat Status : Agent Is Blocked ? (Doc ID 1392601.1)




2020-04-08

Γνῶθι σεαυτόν


Sometimes it might be interesting to understand, what's the SQL statement which is currently executed.
In an Oracle instance, for any other session it's quite simple by accessing some v$ views. But from "within" the statement, it's not straight forward. Nevertheless it's possible, by a creative combination of some features.

Here is the example.

First let's create a proper user:

CREATE USER know IDENTIFIED BY "thyself";

GRANT connect, resource    TO know;

GRANT UNLIMITED TABLESPACE TO know;

GRANT    CREATE VIEW       TO know;

GRANT imp_full_database    TO know;

That's slightly more than really needed - so if you evern require this funcitonality, please be careful with required permissions!
In this example, we do not even need a table.
But a Package to keep some variables:

CREATE OR REPLACE PACKAGE other_color_injector AS
-- package OCI
    text_keeper   VARCHAR2(4000 CHAR) := '--';
    current_color VARCHAR2(100 CHAR)  := 'white';
    FUNCTION rls_hook (
        p_schema  IN  VARCHAR2,
        p_object  IN  VARCHAR2
    ) RETURN VARCHAR2;

END other_color_injector;
/

CREATE OR REPLACE PACKAGE BODY other_color_injector AS

    FUNCTION rls_hook (
        p_schema  IN  VARCHAR2,
        p_object  IN  VARCHAR2
    ) RETURN VARCHAR2 AS
        PRAGMA autonomous_transaction;
        chk_color VARCHAR2(100 CHAR);
    BEGIN
        text_keeper := sys_context('userenv', 'CURRENT_SQL');

        -- first word in /* comment 
        chk_color := regexp_substr(regexp_substr(text_keeper, '/\*.*\*'), '[[:alpha:]]+');
        dbms_output.put_line(' SQL Text:' || text_keeper || '---');
        IF chk_color IS NOT NULL THEN
            current_color := chk_color;
        END IF;
        RETURN NULL;
    END;

END other_color_injector;
/

And a function which gives us some feedback about the SQL in which it's called:
CREATE OR REPLACE TYPE rain_tab IS    TABLE OF VARCHAR2(100 CHAR);

create or replace FUNCTION rain_bow 
-- RETURN t_tf_tab 
return rain_tab
PIPELINED AS
BEGIN
    PIPE ROW ( other_color_injector.current_color );   

  RETURN;
END;
/

create or replace view cloud as select column_value as color from rain_bow();


The view is somehow important for the next step whihc puts all the pieces together:


BEGIN
    dbms_rls.add_policy(object_schema =>   'KNOW', 
                        object_name =>     'CLOUD', 
                        policy_name =>     'RAIN', 
                        function_schema => 'KNOW', 
                        policy_function => 'OTHER_COLOR_INJECTOR.RLS_HOOK',
                        statement_types => 'select', 
                        update_check => false);
END;
/

With this objects in place, a beautiful, but maybe confusing result can be created:
Enter user-name: know/thyself@pdb1

Connected to:
Oracle Database 19c Enterprise Edition Release 19.0.0.0.0 - Production
Version 19.3.0.0.0

SQL> select * from cloud;

COLOR
-------------------------------------------
white

SQL> select /* red */  * from cloud;

COLOR
-------------------------------------------
red

SQL> select * from cloud;

COLOR
-------------------------------------------
red

SQL> select /* green */  * from cloud;

COLOR
-------------------------------------------
green

SQL> select * from cloud;

COLOR
-------------------------------------------
green

SQL>

The important part is this line in OTHER_COLOR_INJECTOR.RLS_HOOK:
text_keeper := sys_context('userenv', 'CURRENT_SQL');

SYS_CONTEXT has access to CURRENT_SQL (and some other useful parameters) -  but only in fine grained audot / RLS events. So all the other objects are required to make this information available in my view rain_bow.

I also created a small twitter quiz where I asked for methods to identify the current SQL and create values based on the SQL.
Rene Jeruschkat suggested a solution based on latest v$sqlstats:


Mathias Rogel suggested to get the latest cursor from v$open_cursor which belongs to the current session:


Both are great solutions and show: there is quite often more than one way to solve a problem!


If you are curious about the greek letters in the title: Γνῶθι σεαυτόν they can be translated to know thyself - something which is often hard - not only for SQL statements.